2019-07-02T18:58:19.865Z,1562093899.865 [CommandLine](IMPORTANT): got command restart logs 2019-07-02T18:59:56.422Z,1562093996.422 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout. 2019-07-02T18:59:56.422Z,1562093996.422 [DVL_micro] Data Fault, FailCount= 1 2019-07-02T18:59:56.422Z,1562093996.422 [DVL_micro](ERROR): Data Fault 2019-07-02T18:59:56.479Z,1562093996.480 [CBIT](ERROR): Data Fault in component: DVL_micro 2019-07-02T18:59:56.889Z,1562093996.889 [DVL_micro](INFO): uninitialize:Powering down 2019-07-02T18:59:57.668Z,1562093997.668 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-07-02T18:59:57.668Z,1562093997.668 [DVL_micro] No Fault, FailCount= 1 2019-07-02T18:59:58.048Z,1562093998.048 [DVL_micro](INFO): Initializing 2019-07-02T19:02:25.133Z,1562094145.133 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-07-02T19:02:25.133Z,1562094145.133 [Default:CheckIn:C.Wait] Stopped 2019-07-02T19:02:25.133Z,1562094145.133 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-07-02T19:02:25.134Z,1562094145.134 [Default:CheckIn:D] Running Loop=1 2019-07-02T19:02:25.541Z,1562094145.541 [Default:CheckIn:D] Stopped 2019-07-02T19:02:25.541Z,1562094145.541 [Default:CheckIn:E] Running Loop=1 2019-07-02T19:02:25.934Z,1562094145.934 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 35.007796 min 2019-07-02T19:02:25.934Z,1562094145.934 [Default:CheckIn:E] Stopped 2019-07-02T19:02:25.934Z,1562094145.934 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-07-02T19:02:25.934Z,1562094145.934 [Default:CheckIn] Stopped 2019-07-02T19:02:25.934Z,1562094145.934 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-07-02T19:02:25.934Z,1562094145.934 [Default:CheckIn](INFO): Running loop #7 2019-07-02T19:02:25.934Z,1562094145.934 [Default:CheckIn] Running Loop=7 2019-07-02T19:02:25.934Z,1562094145.934 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-07-02T19:02:25.934Z,1562094145.934 [Default:CheckIn:Read_GPS] Running Loop=1 2019-07-02T19:02:27.533Z,1562094147.533 [NAL9602](DEBUG): Fix Requested 2019-07-02T19:02:27.924Z,1562094147.924 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190228.00,A,3648.01143,N,12148.32637,W,20.994,68.40,020719,,,D*7B 2019-07-02T19:02:27.926Z,1562094147.926 [NAL9602](INFO): GPS fix at 20190702T190228: (36.800190, -121.805440) 2019-07-02T19:02:27.993Z,1562094147.993 [Default:CheckIn:Read_GPS] Stopped 2019-07-02T19:02:27.993Z,1562094147.993 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-07-02T19:02:33.179Z,1562094153.179 [DVL_micro](ERROR): only read 42 of 46 data items 2019-07-02T19:02:33.179Z,1562094153.179 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 -1559 -2667 -1232 -4151 2 2 2 2 -436.4 1980.6 -2590.9 2 1584. -2590.9 2 -436 1980 -2590 2 1584 1265 -2590 2 7.70 -20.29 296.2 -3.0 16.35.0 1489 87 2019-07-02T19:02:35.684Z,1562094155.684 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190702T031749/Courier0096.lzma 2019-07-02T19:02:36.491Z,1562094156.491 [DataOverHttps](INFO): Moved sent file to Logs/20190702T031749/Courier0096.lzma.bak 2019-07-02T19:02:36.491Z,1562094156.491 [DataOverHttps](INFO): SBD MOMSN=11422066 2019-07-02T19:02:51.192Z,1562094171.192 [DataOverHttps](INFO): Sending 215 bytes from file Logs/20190702T185819/Courier0000.lzma 2019-07-02T19:02:51.998Z,1562094171.998 [DataOverHttps](INFO): Moved sent file to Logs/20190702T185819/Courier0000.lzma.bak 2019-07-02T19:02:51.998Z,1562094171.998 [DataOverHttps](INFO): SBD MOMSN=11422068 2019-07-02T19:03:02.262Z,1562094182.262 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout. 2019-07-02T19:03:02.262Z,1562094182.262 [DVL_micro] Data Fault, FailCount= 1 2019-07-02T19:03:02.262Z,1562094182.262 [DVL_micro](ERROR): Data Fault 2019-07-02T19:03:02.338Z,1562094182.338 [CBIT](ERROR): Data Fault in component: DVL_micro 2019-07-02T19:03:02.737Z,1562094182.737 [DVL_micro](INFO): uninitialize:Powering down 2019-07-02T19:03:03.548Z,1562094183.548 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-07-02T19:03:03.548Z,1562094183.548 [DVL_micro] No Fault, FailCount= 1 2019-07-02T19:03:03.884Z,1562094183.884 [DVL_micro](INFO): Initializing 2019-07-02T19:03:05.044Z,1562094185.044 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190702T185819/Courier0003.lzma 2019-07-02T19:03:05.850Z,1562094185.850 [DataOverHttps](INFO): Moved sent file to Logs/20190702T185819/Courier0003.lzma.bak 2019-07-02T19:03:05.850Z,1562094185.850 [DataOverHttps](INFO): SBD MOMSN=11422072 2019-07-02T19:03:07.114Z,1562094187.114 [NAL9602](INFO): SBD MO Status=2, MOMSN=781, MT Status=2, MTMSN=0 2019-07-02T19:03:07.114Z,1562094187.114 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-07-02T19:03:20.784Z,1562094200.784 [DataOverHttps](INFO): Sending 96 bytes from file Logs/20190702T031749/Express0097.lzma 2019-07-02T19:03:21.591Z,1562094201.591 [DataOverHttps](INFO): Moved sent file to Logs/20190702T031749/Express0097.lzma.bak 2019-07-02T19:03:21.591Z,1562094201.591 [DataOverHttps](INFO): SBD MOMSN=11422074 2019-07-02T19:03:28.931Z,1562094208.931 [NAL9602](INFO): SBD MO Status=0, MOMSN=781, MT Status=0, MTMSN=0 2019-07-02T19:03:28.931Z,1562094208.931 [NAL9602](INFO): No messages in MT queue 2019-07-02T19:03:36.649Z,1562094216.649 [DataOverHttps](INFO): Sending 402 bytes from file Logs/20190702T185819/Express0001.lzma 2019-07-02T19:03:37.454Z,1562094217.454 [DataOverHttps](INFO): Moved sent file to Logs/20190702T185819/Express0001.lzma.bak 2019-07-02T19:03:37.454Z,1562094217.454 [DataOverHttps](INFO): SBD MOMSN=11422077 2019-07-02T19:03:53.080Z,1562094233.080 [DataOverHttps](INFO): Sending 52 bytes from file Logs/20190702T185819/Express0002.lzma 2019-07-02T19:03:53.886Z,1562094233.886 [DataOverHttps](INFO): Moved sent file to Logs/20190702T185819/Express0002.lzma.bak 2019-07-02T19:03:53.886Z,1562094233.886 [DataOverHttps](INFO): SBD MOMSN=11422082 2019-07-02T19:03:59.630Z,1562094239.630 [NAL9602](INFO): Not Powering down - fast GPS 2019-07-02T19:04:08.828Z,1562094248.828 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190702T185819/Express0004.lzma 2019-07-02T19:04:09.634Z,1562094249.634 [DataOverHttps](INFO): Moved sent file to Logs/20190702T185819/Express0004.lzma.bak 2019-07-02T19:04:09.634Z,1562094249.634 [DataOverHttps](INFO): SBD MOMSN=11422085 2019-07-02T19:04:13.832Z,1562094253.832 [Default:CheckIn:Read_Iridium] Stopped 2019-07-02T19:04:13.869Z,1562094253.869 [Default:CheckIn:C.Wait] Running Loop=1 2019-07-02T19:04:13.869Z,1562094253.869 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-07-02T19:06:08.119Z,1562094368.119 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout. 2019-07-02T19:06:08.119Z,1562094368.119 [DVL_micro] Data Fault, FailCount= 1 2019-07-02T19:06:08.119Z,1562094368.119 [DVL_micro](ERROR): Data Fault 2019-07-02T19:06:08.179Z,1562094368.179 [CBIT](ERROR): Data Fault in component: DVL_micro 2019-07-02T19:06:08.593Z,1562094368.593 [DVL_micro](INFO): uninitialize:Powering down 2019-07-02T19:06:09.369Z,1562094369.369 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-07-02T19:06:09.369Z,1562094369.369 [DVL_micro] No Fault, FailCount= 1 2019-07-02T19:06:09.748Z,1562094369.748 [DVL_micro](INFO): Initializing 2019-07-02T19:06:28.762Z,1562094388.762 [CBIT](IMPORTANT): Beginning ground fault scan 2019-07-02T19:06:39.671Z,1562094399.671 [CBIT](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): 0.087753 CHAN A1 (24V): -0.032544 CHAN A2 (12V): 0.063446 CHAN A3 (5V): 0.000344 CHAN B0 (3.3V): 0.006581 CHAN B1 (3.15aV): 0.009326 CHAN B2 (3.15bV): 0.012199 CHAN B3 (GND): -0.006044 OPEN: 0.011079 Full Scale Calc: 4.765 mA, -1.589 mA 2019-07-02T19:09:13.982Z,1562094553.982 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout. 2019-07-02T19:09:13.982Z,1562094553.982 [DVL_micro] Data Fault, FailCount= 1 2019-07-02T19:09:13.982Z,1562094553.982 [DVL_micro](ERROR): Data Fault 2019-07-02T19:09:14.045Z,1562094554.045 [CBIT](ERROR): Data Fault in component: DVL_micro 2019-07-02T19:09:14.457Z,1562094554.457 [DVL_micro](INFO): uninitialize:Powering down 2019-07-02T19:09:14.531Z,1562094554.531 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-07-02T19:09:14.532Z,1562094554.532 [Default:CheckIn:C.Wait] Stopped 2019-07-02T19:09:14.532Z,1562094554.532 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-07-02T19:09:14.532Z,1562094554.532 [Default:CheckIn:D] Running Loop=1 2019-07-02T19:09:14.821Z,1562094554.821 [Default:CheckIn:D] Stopped 2019-07-02T19:09:14.821Z,1562094554.821 [Default:CheckIn:E] Running Loop=1 2019-07-02T19:09:15.224Z,1562094555.224 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 41.829134 min 2019-07-02T19:09:15.224Z,1562094555.224 [Default:CheckIn:E] Stopped 2019-07-02T19:09:15.224Z,1562094555.224 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-07-02T19:09:15.224Z,1562094555.224 [Default:CheckIn] Stopped 2019-07-02T19:09:15.225Z,1562094555.225 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-07-02T19:09:15.225Z,1562094555.225 [Default:CheckIn](INFO): Running loop #8 2019-07-02T19:09:15.225Z,1562094555.225 [Default:CheckIn] Running Loop=8 2019-07-02T19:09:15.225Z,1562094555.225 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-07-02T19:09:15.225Z,1562094555.225 [Default:CheckIn:Read_GPS] Running Loop=1 2019-07-02T19:09:15.233Z,1562094555.233 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-07-02T19:09:15.234Z,1562094555.234 [DVL_micro] No Fault, FailCount= 1 2019-07-02T19:09:15.604Z,1562094555.604 [DVL_micro](INFO): Initializing 2019-07-02T19:09:16.821Z,1562094556.821 [NAL9602](DEBUG): Fix Requested 2019-07-02T19:09:17.216Z,1562094557.216 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190918.00,A,3648.24891,N,12147.14360,W,3.732,194.95,020719,,,D*77 2019-07-02T19:09:17.218Z,1562094557.218 [NAL9602](INFO): GPS fix at 20190702T190918: (36.804148, -121.785727) 2019-07-02T19:09:17.242Z,1562094557.242 [Default:CheckIn:Read_GPS] Stopped 2019-07-02T19:09:17.242Z,1562094557.242 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-07-02T19:09:24.832Z,1562094564.832 [DataOverHttps](INFO): Sending 64 bytes from file Logs/20190702T185819/Courier0005.lzma 2019-07-02T19:09:25.638Z,1562094565.638 [DataOverHttps](INFO): Moved sent file to Logs/20190702T185819/Courier0005.lzma.bak 2019-07-02T19:09:25.638Z,1562094565.638 [DataOverHttps](INFO): SBD MOMSN=11422134 2019-07-02T19:09:35.403Z,1562094575.403 [NAL9602](INFO): SBD MO Status=0, MOMSN=782, MT Status=0, MTMSN=0 2019-07-02T19:09:35.403Z,1562094575.403 [NAL9602](INFO): No messages in MT queue 2019-07-02T19:09:40.949Z,1562094580.949 [DataOverHttps](INFO): Sending 405 bytes from file Logs/20190702T185819/Express0007.lzma 2019-07-02T19:09:41.754Z,1562094581.754 [DataOverHttps](INFO): Moved sent file to Logs/20190702T185819/Express0007.lzma.bak 2019-07-02T19:09:41.754Z,1562094581.754 [DataOverHttps](INFO): SBD MOMSN=11422137 2019-07-02T19:09:45.962Z,1562094585.962 [Default:CheckIn:Read_Iridium] Stopped 2019-07-02T19:09:45.962Z,1562094585.962 [Default:CheckIn:C.Wait] Running Loop=1 2019-07-02T19:09:45.963Z,1562094585.963 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-07-02T19:10:06.098Z,1562094606.098 [NAL9602](INFO): Not Powering down - fast GPS 2019-07-02T19:12:19.822Z,1562094739.822 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout. 2019-07-02T19:12:19.822Z,1562094739.822 [DVL_micro] Data Fault, FailCount= 1 2019-07-02T19:12:19.822Z,1562094739.822 [DVL_micro](ERROR): Data Fault 2019-07-02T19:12:19.861Z,1562094739.861 [CBIT](ERROR): Data Fault in component: DVL_micro 2019-07-02T19:12:20.305Z,1562094740.305 [DVL_micro](INFO): uninitialize:Powering down 2019-07-02T19:12:21.077Z,1562094741.077 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-07-02T19:12:21.077Z,1562094741.077 [DVL_micro] No Fault, FailCount= 1 2019-07-02T19:12:21.448Z,1562094741.448 [DVL_micro](INFO): Initializing 2019-07-02T19:14:46.513Z,1562094886.513 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-07-02T19:14:46.513Z,1562094886.513 [Default:CheckIn:C.Wait] Stopped 2019-07-02T19:14:46.513Z,1562094886.513 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-07-02T19:14:46.513Z,1562094886.513 [Default:CheckIn:D] Running Loop=1 2019-07-02T19:14:46.957Z,1562094886.957 [Default:CheckIn:D] Stopped 2019-07-02T19:14:46.957Z,1562094886.957 [Default:CheckIn:E] Running Loop=1 2019-07-02T19:14:47.325Z,1562094887.325 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 47.364730 min 2019-07-02T19:14:47.325Z,1562094887.325 [Default:CheckIn:E] Stopped 2019-07-02T19:14:47.325Z,1562094887.325 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-07-02T19:14:47.325Z,1562094887.325 [Default:CheckIn] Stopped 2019-07-02T19:14:47.325Z,1562094887.325 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-07-02T19:14:47.326Z,1562094887.326 [Default:CheckIn](INFO): Running loop #9 2019-07-02T19:14:47.326Z,1562094887.326 [Default:CheckIn] Running Loop=9 2019-07-02T19:14:47.326Z,1562094887.326 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-07-02T19:14:47.326Z,1562094887.326 [Default:CheckIn:Read_GPS] Running Loop=1 2019-07-02T19:14:48.925Z,1562094888.925 [NAL9602](DEBUG): Fix Requested 2019-07-02T19:14:49.320Z,1562094889.320 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191450.00,A,3648.13855,N,12147.20635,W,0.000,302.37,020719,,,D*79 2019-07-02T19:14:49.322Z,1562094889.322 [NAL9602](INFO): GPS fix at 20190702T191450: (36.802309, -121.786772) 2019-07-02T19:14:49.365Z,1562094889.365 [Default:CheckIn:Read_GPS] Stopped 2019-07-02T19:14:49.365Z,1562094889.365 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-07-02T19:14:57.376Z,1562094897.376 [DataOverHttps](INFO): Sending 64 bytes from file Logs/20190702T185819/Courier0009.lzma 2019-07-02T19:14:58.182Z,1562094898.182 [DataOverHttps](INFO): Moved sent file to Logs/20190702T185819/Courier0009.lzma.bak 2019-07-02T19:14:58.182Z,1562094898.182 [DataOverHttps](INFO): SBD MOMSN=11422160 2019-07-02T19:15:14.290Z,1562094914.290 [DataOverHttps](INFO): Sending 168 bytes from file Logs/20190702T185819/Express0010.lzma 2019-07-02T19:15:15.026Z,1562094915.026 [DataOverHttps](INFO): Moved sent file to Logs/20190702T185819/Express0010.lzma.bak 2019-07-02T19:15:15.027Z,1562094915.027 [DataOverHttps](INFO): SBD MOMSN=11422163 2019-07-02T19:15:19.357Z,1562094919.357 [Default:CheckIn:Read_Iridium] Stopped 2019-07-02T19:15:19.357Z,1562094919.357 [Default:CheckIn:C.Wait] Running Loop=1 2019-07-02T19:15:19.358Z,1562094919.358 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-07-02T19:15:22.509Z,1562094922.509 [DVL_micro](ERROR): only read 45 of 46 data items 2019-07-02T19:15:22.510Z,1562094922.510 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 0 0 0 0 -1180 -120 -1199 645 2 2 2 2 25.4 -1021.0 -499.9 2 -1013.4 -126.7 -499.9 2 25 -1021 -499 2 -1013 -126 -499 2 10.05 -19.56 275.7 -3.0 16.75.0 1489 76 2019-07-02T19:15:25.722Z,1562094925.722 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout. 2019-07-02T19:15:25.722Z,1562094925.722 [DVL_micro] Data Fault, FailCount= 1 2019-07-02T19:15:25.722Z,1562094925.722 [DVL_micro](ERROR): Data Fault 2019-07-02T19:15:25.778Z,1562094925.778 [CBIT](ERROR): Data Fault in component: DVL_micro 2019-07-02T19:15:26.209Z,1562094926.209 [DVL_micro](INFO): uninitialize:Powering down 2019-07-02T19:15:26.983Z,1562094926.983 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-07-02T19:15:26.983Z,1562094926.983 [DVL_micro] No Fault, FailCount= 1 2019-07-02T19:15:27.344Z,1562094927.344 [DVL_micro](INFO): Initializing 2019-07-02T19:15:32.592Z,1562094932.592 [NAL9602](INFO): SBD MO Status=0, MOMSN=783, MT Status=0, MTMSN=0 2019-07-02T19:15:32.592Z,1562094932.592 [NAL9602](INFO): No messages in MT queue 2019-07-02T19:16:03.299Z,1562094963.299 [NAL9602](INFO): Not Powering down - fast GPS 2019-07-02T19:18:23.505Z,1562095103.505 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-07-02T19:18:23.553Z,1562095103.553 [BPC1](INFO): Calculating totals. Valid battery stick count: 54. Valid reserve battery stick count: 6. 2019-07-02T19:18:23.555Z,1562095103.555 [BPC1](INFO): Received data from all battery sticks. 2019-07-02T19:18:31.566Z,1562095111.566 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout. 2019-07-02T19:18:31.566Z,1562095111.566 [DVL_micro] Data Fault, FailCount= 1 2019-07-02T19:18:31.566Z,1562095111.566 [DVL_micro](ERROR): Data Fault 2019-07-02T19:18:31.605Z,1562095111.605 [CBIT](ERROR): Data Fault in component: DVL_micro 2019-07-02T19:18:32.041Z,1562095112.041 [DVL_micro](INFO): uninitialize:Powering down 2019-07-02T19:18:32.821Z,1562095112.821 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-07-02T19:18:32.821Z,1562095112.821 [DVL_micro] No Fault, FailCount= 1 2019-07-02T19:18:33.185Z,1562095113.185 [DVL_micro](INFO): Initializing 2019-07-02T19:20:19.889Z,1562095219.889 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-07-02T19:20:19.889Z,1562095219.889 [Default:CheckIn:C.Wait] Stopped 2019-07-02T19:20:19.889Z,1562095219.889 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-07-02T19:20:19.889Z,1562095219.889 [Default:CheckIn:D] Running Loop=1 2019-07-02T19:20:20.281Z,1562095220.281 [Default:CheckIn:D] Stopped 2019-07-02T19:20:20.281Z,1562095220.281 [Default:CheckIn:E] Running Loop=1 2019-07-02T19:20:20.694Z,1562095220.694 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 52.920138 min 2019-07-02T19:20:20.694Z,1562095220.694 [Default:CheckIn:E] Stopped 2019-07-02T19:20:20.694Z,1562095220.694 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-07-02T19:20:20.694Z,1562095220.694 [Default:CheckIn] Stopped 2019-07-02T19:20:20.694Z,1562095220.694 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-07-02T19:20:20.695Z,1562095220.695 [Default:CheckIn](INFO): Running loop #10 2019-07-02T19:20:20.695Z,1562095220.695 [Default:CheckIn] Running Loop=10 2019-07-02T19:20:20.695Z,1562095220.695 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-07-02T19:20:20.695Z,1562095220.695 [Default:CheckIn:Read_GPS] Running Loop=1 2019-07-02T19:20:22.277Z,1562095222.277 [NAL9602](DEBUG): Fix Requested 2019-07-02T19:20:22.668Z,1562095222.668 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,192023.00,A,3648.13838,N,12147.20480,W,0.039,317.73,020719,,,D*73 2019-07-02T19:20:22.670Z,1562095222.670 [NAL9602](INFO): GPS fix at 20190702T192023: (36.802306, -121.786747) 2019-07-02T19:20:22.712Z,1562095222.712 [Default:CheckIn:Read_GPS] Stopped 2019-07-02T19:20:22.717Z,1562095222.717 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-07-02T19:20:33.433Z,1562095233.433 [DataOverHttps](INFO): Sending 223 bytes from file Logs/20190702T185819/Courier0012.lzma 2019-07-02T19:20:34.238Z,1562095234.238 [DataOverHttps](INFO): Moved sent file to Logs/20190702T185819/Courier0012.lzma.bak 2019-07-02T19:20:34.238Z,1562095234.238 [DataOverHttps](INFO): SBD MOMSN=11422229 2019-07-02T19:20:42.470Z,1562095242.470 [NAL9602](INFO): SBD MO Status=2, MOMSN=784, MT Status=2, MTMSN=0 2019-07-02T19:20:42.470Z,1562095242.470 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-07-02T19:20:50.172Z,1562095250.172 [DataOverHttps](INFO): Sending 175 bytes from file Logs/20190702T185819/Express0013.lzma 2019-07-02T19:20:50.978Z,1562095250.978 [DataOverHttps](INFO): Moved sent file to Logs/20190702T185819/Express0013.lzma.bak 2019-07-02T19:20:50.978Z,1562095250.978 [DataOverHttps](INFO): SBD MOMSN=11422236 2019-07-02T19:20:54.977Z,1562095254.977 [Default:CheckIn:Read_Iridium] Stopped 2019-07-02T19:20:54.977Z,1562095254.977 [Default:CheckIn:C.Wait] Running Loop=1 2019-07-02T19:20:54.977Z,1562095254.977 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-07-02T19:21:07.460Z,1562095267.460 [NAL9602](INFO): SBD MO Status=2, MOMSN=784, MT Status=2, MTMSN=0 2019-07-02T19:21:07.460Z,1562095267.460 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-07-02T19:21:26.856Z,1562095286.856 [NAL9602](INFO): SBD MO Status=0, MOMSN=784, MT Status=0, MTMSN=0 2019-07-02T19:21:26.856Z,1562095286.856 [NAL9602](INFO): No messages in MT queue 2019-07-02T19:21:37.360Z,1562095297.360 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout. 2019-07-02T19:21:37.360Z,1562095297.360 [DVL_micro] Data Fault, FailCount= 1 2019-07-02T19:21:37.360Z,1562095297.360 [DVL_micro](ERROR): Data Fault 2019-07-02T19:21:37.392Z,1562095297.392 [CBIT](ERROR): Data Fault in component: DVL_micro 2019-07-02T19:21:37.833Z,1562095297.833 [DVL_micro](INFO): uninitialize:Powering down 2019-07-02T19:21:38.599Z,1562095298.599 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-07-02T19:21:38.599Z,1562095298.599 [DVL_micro] No Fault, FailCount= 1 2019-07-02T19:21:38.980Z,1562095298.980 [DVL_micro](INFO): Initializing 2019-07-02T19:21:57.564Z,1562095317.564 [NAL9602](INFO): Not Powering down - fast GPS 2019-07-02T19:24:43.202Z,1562095483.202 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout. 2019-07-02T19:24:43.202Z,1562095483.202 [DVL_micro] Data Fault, FailCount= 1 2019-07-02T19:24:43.202Z,1562095483.202 [DVL_micro](ERROR): Data Fault 2019-07-02T19:24:43.235Z,1562095483.235 [CBIT](ERROR): Data Fault in component: DVL_micro 2019-07-02T19:24:43.665Z,1562095483.665 [DVL_micro](INFO): uninitialize:Powering down 2019-07-02T19:24:44.466Z,1562095484.466 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-07-02T19:24:44.466Z,1562095484.466 [DVL_micro] No Fault, FailCount= 1 2019-07-02T19:24:44.816Z,1562095484.816 [DVL_micro](INFO): Initializing 2019-07-02T19:25:55.537Z,1562095555.537 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-07-02T19:25:55.537Z,1562095555.537 [Default:CheckIn:C.Wait] Stopped 2019-07-02T19:25:55.537Z,1562095555.537 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-07-02T19:25:55.538Z,1562095555.538 [Default:CheckIn:D] Running Loop=1 2019-07-02T19:25:55.961Z,1562095555.961 [Default:CheckIn:D] Stopped 2019-07-02T19:25:55.961Z,1562095555.961 [Default:CheckIn:E] Running Loop=1 2019-07-02T19:25:56.349Z,1562095556.349 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 58.514803 min 2019-07-02T19:25:56.350Z,1562095556.350 [Default:CheckIn:E] Stopped 2019-07-02T19:25:56.350Z,1562095556.350 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-07-02T19:25:56.350Z,1562095556.350 [Default:CheckIn] Stopped 2019-07-02T19:25:56.350Z,1562095556.350 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-07-02T19:25:56.350Z,1562095556.350 [Default:CheckIn](INFO): Running loop #11 2019-07-02T19:25:56.350Z,1562095556.350 [Default:CheckIn] Running Loop=11 2019-07-02T19:25:56.350Z,1562095556.350 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-07-02T19:25:56.350Z,1562095556.350 [Default:CheckIn:Read_GPS] Running Loop=1 2019-07-02T19:25:57.949Z,1562095557.949 [NAL9602](DEBUG): Fix Requested 2019-07-02T19:25:58.344Z,1562095558.344 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,192559.00,A,3648.15725,N,12147.24755,W,2.683,12.64,020719,,,D*44 2019-07-02T19:25:58.346Z,1562095558.346 [NAL9602](INFO): GPS fix at 20190702T192559: (36.802621, -121.787459) 2019-07-02T19:25:58.395Z,1562095558.395 [Default:CheckIn:Read_GPS] Stopped 2019-07-02T19:25:58.396Z,1562095558.396 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-07-02T19:26:05.944Z,1562095565.944 [DataOverHttps](INFO): Sending 64 bytes from file Logs/20190702T185819/Courier0015.lzma 2019-07-02T19:26:06.750Z,1562095566.750 [DataOverHttps](INFO): Moved sent file to Logs/20190702T185819/Courier0015.lzma.bak 2019-07-02T19:26:06.751Z,1562095566.751 [DataOverHttps](INFO): SBD MOMSN=11422246 2019-07-02T19:26:12.109Z,1562095572.109 [NAL9602](INFO): SBD MO Status=0, MOMSN=785, MT Status=0, MTMSN=0 2019-07-02T19:26:12.109Z,1562095572.109 [NAL9602](INFO): No messages in MT queue 2019-07-02T19:26:23.355Z,1562095583.355 [DataOverHttps](INFO): Sending 175 bytes from file Logs/20190702T185819/Express0016.lzma 2019-07-02T19:26:24.158Z,1562095584.158 [DataOverHttps](INFO): Moved sent file to Logs/20190702T185819/Express0016.lzma.bak 2019-07-02T19:26:24.158Z,1562095584.158 [DataOverHttps](INFO): SBD MOMSN=11422249 2019-07-02T19:26:28.301Z,1562095588.301 [Default:CheckIn:Read_Iridium] Stopped 2019-07-02T19:26:28.302Z,1562095588.302 [Default:CheckIn:C.Wait] Running Loop=1 2019-07-02T19:26:28.302Z,1562095588.302 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-07-02T19:26:42.778Z,1562095602.778 [NAL9602](INFO): Not Powering down - fast GPS 2019-07-02T19:26:44.472Z,1562095604.472 [DVL_micro](ERROR): checksum mismatch: reported104 , calculated:119 2019-07-02T19:26:44.472Z,1562095604.472 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 0 0 0 0 -1629 -11 -1746 2 2 2 2 15.6 -1471.2 2 1223.4 -3.2 -1471.2 2 -811 915 -1471 2 1223 -3 -1471 2 0.62 -0.79 228.3 -3.0 17.5 0.005 35.0 1489 104 2019-07-02T19:27:49.034Z,1562095669.034 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout. 2019-07-02T19:27:49.034Z,1562095669.034 [DVL_micro] Data Fault, FailCount= 1 2019-07-02T19:27:49.034Z,1562095669.034 [DVL_micro](ERROR): Data Fault 2019-07-02T19:27:49.098Z,1562095669.098 [CBIT](ERROR): Data Fault in component: DVL_micro 2019-07-02T19:27:49.505Z,1562095669.505 [DVL_micro](INFO): uninitialize:Powering down 2019-07-02T19:27:50.317Z,1562095670.317 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-07-02T19:27:50.317Z,1562095670.317 [DVL_micro] No Fault, FailCount= 1 2019-07-02T19:27:50.656Z,1562095670.656 [DVL_micro](INFO): Initializing 2019-07-02T19:30:54.874Z,1562095854.874 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout. 2019-07-02T19:30:54.874Z,1562095854.874 [DVL_micro] Data Fault, FailCount= 1 2019-07-02T19:30:54.874Z,1562095854.874 [DVL_micro](ERROR): Data Fault 2019-07-02T19:30:54.907Z,1562095854.907 [CBIT](ERROR): Data Fault in component: DVL_micro 2019-07-02T19:30:55.353Z,1562095855.353 [DVL_micro](INFO): uninitialize:Powering down 2019-07-02T19:30:56.143Z,1562095856.143 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-07-02T19:30:56.143Z,1562095856.143 [DVL_micro] No Fault, FailCount= 1 2019-07-02T19:30:56.500Z,1562095856.500 [DVL_micro](INFO): Initializing 2019-07-02T19:31:28.857Z,1562095888.857 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-07-02T19:31:28.857Z,1562095888.857 [Default:CheckIn:C.Wait] Stopped 2019-07-02T19:31:28.857Z,1562095888.857 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-07-02T19:31:28.857Z,1562095888.857 [Default:CheckIn:D] Running Loop=1 2019-07-02T19:31:29.257Z,1562095889.257 [Default:CheckIn:D] Stopped 2019-07-02T19:31:29.257Z,1562095889.257 [Default:CheckIn:E] Running Loop=1 2019-07-02T19:31:29.657Z,1562095889.657 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 64.069727 min 2019-07-02T19:31:29.657Z,1562095889.657 [Default:CheckIn:E] Stopped 2019-07-02T19:31:29.658Z,1562095889.658 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-07-02T19:31:29.658Z,1562095889.658 [Default:CheckIn] Stopped 2019-07-02T19:31:29.658Z,1562095889.658 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-07-02T19:31:29.658Z,1562095889.658 [Default:CheckIn](INFO): Running loop #12 2019-07-02T19:31:29.658Z,1562095889.658 [Default:CheckIn] Running Loop=12 2019-07-02T19:31:29.658Z,1562095889.658 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-07-02T19:31:29.658Z,1562095889.658 [Default:CheckIn:Read_GPS] Running Loop=1 2019-07-02T19:31:31.249Z,1562095891.249 [NAL9602](DEBUG): Fix Requested 2019-07-02T19:31:31.644Z,1562095891.644 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,193132.00,A,3648.16623,N,12147.28046,W,0.661,308.06,020719,,,D*73 2019-07-02T19:31:31.646Z,1562095891.646 [NAL9602](INFO): GPS fix at 20190702T193132: (36.802771, -121.788008) 2019-07-02T19:31:31.670Z,1562095891.670 [Default:CheckIn:Read_GPS] Stopped 2019-07-02T19:31:31.670Z,1562095891.670 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-07-02T19:31:40.724Z,1562095900.724 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20190702T185819/Courier0018.lzma 2019-07-02T19:31:41.530Z,1562095901.530 [DataOverHttps](INFO): Moved sent file to Logs/20190702T185819/Courier0018.lzma.bak 2019-07-02T19:31:41.530Z,1562095901.530 [DataOverHttps](INFO): SBD MOMSN=11422280 2019-07-02T19:31:48.608Z,1562095908.608 [NAL9602](INFO): SBD MO Status=0, MOMSN=786, MT Status=0, MTMSN=0 2019-07-02T19:31:48.608Z,1562095908.608 [NAL9602](INFO): No messages in MT queue 2019-07-02T19:31:56.413Z,1562095916.413 [DataOverHttps](INFO): Sending 172 bytes from file Logs/20190702T185819/Express0019.lzma 2019-07-02T19:31:57.218Z,1562095917.218 [DataOverHttps](INFO): Moved sent file to Logs/20190702T185819/Express0019.lzma.bak 2019-07-02T19:31:57.218Z,1562095917.218 [DataOverHttps](INFO): SBD MOMSN=11422283 2019-07-02T19:32:01.233Z,1562095921.233 [Default:CheckIn:Read_Iridium] Stopped 2019-07-02T19:32:01.233Z,1562095921.233 [Default:CheckIn:C.Wait] Running Loop=1 2019-07-02T19:32:01.233Z,1562095921.233 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-07-02T19:32:19.307Z,1562095939.307 [NAL9602](INFO): Not Powering down - fast GPS 2019-07-02T19:34:00.713Z,1562096040.713 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout. 2019-07-02T19:34:00.713Z,1562096040.713 [DVL_micro] Data Fault, FailCount= 1 2019-07-02T19:34:00.713Z,1562096040.713 [DVL_micro](ERROR): Data Fault 2019-07-02T19:34:00.764Z,1562096040.764 [CBIT](ERROR): Data Fault in component: DVL_micro 2019-07-02T19:34:01.185Z,1562096041.185 [DVL_micro](INFO): uninitialize:Powering down 2019-07-02T19:34:01.993Z,1562096041.993 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-07-02T19:34:01.993Z,1562096041.993 [DVL_micro] No Fault, FailCount= 1 2019-07-02T19:34:02.333Z,1562096042.333 [DVL_micro](INFO): Initializing 2019-07-02T19:37:01.733Z,1562096221.733 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-07-02T19:37:01.733Z,1562096221.733 [Default:CheckIn:C.Wait] Stopped 2019-07-02T19:37:01.733Z,1562096221.733 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-07-02T19:37:01.734Z,1562096221.734 [Default:CheckIn:D] Running Loop=1 2019-07-02T19:37:02.141Z,1562096222.141 [Default:CheckIn:D] Stopped 2019-07-02T19:37:02.141Z,1562096222.141 [Default:CheckIn:E] Running Loop=1 2019-07-02T19:37:02.542Z,1562096222.542 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 69.617790 min 2019-07-02T19:37:02.542Z,1562096222.542 [Default:CheckIn:E] Stopped 2019-07-02T19:37:02.542Z,1562096222.542 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-07-02T19:37:02.542Z,1562096222.542 [Default:CheckIn] Stopped 2019-07-02T19:37:02.542Z,1562096222.542 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-07-02T19:37:02.543Z,1562096222.543 [Default:CheckIn](INFO): Running loop #13 2019-07-02T19:37:02.543Z,1562096222.543 [Default:CheckIn] Running Loop=13 2019-07-02T19:37:02.543Z,1562096222.543 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-07-02T19:37:02.543Z,1562096222.543 [Default:CheckIn:Read_GPS] Running Loop=1 2019-07-02T19:37:04.147Z,1562096224.147 [NAL9602](DEBUG): Fix Requested 2019-07-02T19:37:04.540Z,1562096224.540 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,193705.00,A,3648.16794,N,12147.27870,W,0.330,155.64,020719,,,A*74 2019-07-02T19:37:04.542Z,1562096224.542 [NAL9602](INFO): GPS fix at 20190702T193705: (36.802799, -121.787978) 2019-07-02T19:37:04.586Z,1562096224.586 [Default:CheckIn:Read_GPS] Stopped 2019-07-02T19:37:04.587Z,1562096224.587 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-07-02T19:37:06.630Z,1562096226.630 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout. 2019-07-02T19:37:06.630Z,1562096226.630 [DVL_micro] Data Fault, FailCount= 1 2019-07-02T19:37:06.630Z,1562096226.630 [DVL_micro](ERROR): Data Fault 2019-07-02T19:37:06.713Z,1562096226.713 [CBIT](ERROR): Data Fault in component: DVL_micro 2019-07-02T19:37:07.109Z,1562096227.109 [DVL_micro](INFO): uninitialize:Powering down 2019-07-02T19:37:07.872Z,1562096227.872 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-07-02T19:37:07.872Z,1562096227.872 [DVL_micro] No Fault, FailCount= 1 2019-07-02T19:37:08.252Z,1562096228.252 [DVL_micro](INFO): Initializing 2019-07-02T19:37:12.044Z,1562096232.044 [DataOverHttps](INFO): Sending 64 bytes from file Logs/20190702T185819/Courier0021.lzma 2019-07-02T19:37:14.274Z,1562096234.274 [DataOverHttps](INFO): Moved sent file to Logs/20190702T185819/Courier0021.lzma.bak 2019-07-02T19:37:14.274Z,1562096234.274 [DataOverHttps](INFO): SBD MOMSN=11422289 2019-07-02T19:37:27.646Z,1562096247.646 [DVL_micro](ERROR): only read 45 of 46 data items 2019-07-02T19:37:27.646Z,1562096247.646 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 0 0 0 0 -1563 -842 -1000 -1697 2 2 2 2 -751.4 1141.1 -1375.7 2 634.3 -1210.1 -1375.7 2 -751 1142 634 -1210 -1375 2 8.89 -2.81 174.3 -3.0 18.2 0.005 35.0 1489 90 2019-07-02T19:37:29.041Z,1562096249.041 [DataOverHttps](INFO): Sending 168 bytes from file Logs/20190702T185819/Express0022.lzma 2019-07-02T19:37:29.846Z,1562096249.846 [DataOverHttps](INFO): Moved sent file to Logs/20190702T185819/Express0022.lzma.bak 2019-07-02T19:37:29.846Z,1562096249.846 [DataOverHttps](INFO): SBD MOMSN=11422292 2019-07-02T19:37:34.213Z,1562096254.213 [Default:CheckIn:Read_Iridium] Stopped 2019-07-02T19:37:34.214Z,1562096254.214 [Default:CheckIn:C.Wait] Running Loop=1 2019-07-02T19:37:34.214Z,1562096254.214 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-07-02T19:39:13.492Z,1562096353.492 [NAL9602](INFO): SBD MO Status=2, MOMSN=787, MT Status=2, MTMSN=0 2019-07-02T19:39:13.492Z,1562096353.492 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-07-02T19:39:23.188Z,1562096363.188 [NAL9602](INFO): SBD MO Status=0, MOMSN=787, MT Status=0, MTMSN=0 2019-07-02T19:39:23.188Z,1562096363.188 [NAL9602](INFO): No messages in MT queue 2019-07-02T19:39:53.890Z,1562096393.890 [NAL9602](INFO): Not Powering down - fast GPS 2019-07-02T19:40:12.470Z,1562096412.470 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout. 2019-07-02T19:40:12.470Z,1562096412.470 [DVL_micro] Data Fault, FailCount= 1 2019-07-02T19:40:12.470Z,1562096412.470 [DVL_micro](ERROR): Data Fault 2019-07-02T19:40:12.537Z,1562096412.537 [CBIT](ERROR): Data Fault in component: DVL_micro 2019-07-02T19:40:12.949Z,1562096412.949 [DVL_micro](INFO): uninitialize:Powering down 2019-07-02T19:40:13.717Z,1562096413.717 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-07-02T19:40:13.717Z,1562096413.717 [DVL_micro] No Fault, FailCount= 1 2019-07-02T19:40:14.096Z,1562096414.096 [DVL_micro](INFO): Initializing 2019-07-02T19:42:34.705Z,1562096554.705 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-07-02T19:42:34.705Z,1562096554.705 [Default:CheckIn:C.Wait] Stopped 2019-07-02T19:42:34.706Z,1562096554.706 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-07-02T19:42:34.706Z,1562096554.706 [Default:CheckIn:D] Running Loop=1 2019-07-02T19:42:35.114Z,1562096555.114 [Default:CheckIn:D] Stopped 2019-07-02T19:42:35.114Z,1562096555.114 [Default:CheckIn:E] Running Loop=1 2019-07-02T19:42:35.509Z,1562096555.509 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 75.167342 min 2019-07-02T19:42:35.509Z,1562096555.509 [Default:CheckIn:E] Stopped 2019-07-02T19:42:35.509Z,1562096555.509 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-07-02T19:42:35.509Z,1562096555.509 [Default:CheckIn] Stopped 2019-07-02T19:42:35.510Z,1562096555.510 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-07-02T19:42:35.510Z,1562096555.510 [Default:CheckIn](INFO): Running loop #14 2019-07-02T19:42:35.510Z,1562096555.510 [Default:CheckIn] Running Loop=14 2019-07-02T19:42:35.510Z,1562096555.510 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-07-02T19:42:35.510Z,1562096555.510 [Default:CheckIn:Read_GPS] Running Loop=1 2019-07-02T19:42:37.121Z,1562096557.121 [NAL9602](DEBUG): Fix Requested 2019-07-02T19:42:37.512Z,1562096557.512 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194238.00,A,3648.17006,N,12147.27727,W,0.447,118.63,020719,,,A*71 2019-07-02T19:42:37.514Z,1562096557.514 [NAL9602](INFO): GPS fix at 20190702T194238: (36.802834, -121.787954) 2019-07-02T19:42:37.538Z,1562096557.538 [Default:CheckIn:Read_GPS] Stopped 2019-07-02T19:42:37.538Z,1562096557.538 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-07-02T19:42:45.132Z,1562096565.132 [DataOverHttps](INFO): Sending 64 bytes from file Logs/20190702T185819/Courier0024.lzma 2019-07-02T19:42:45.938Z,1562096565.938 [DataOverHttps](INFO): Moved sent file to Logs/20190702T185819/Courier0024.lzma.bak 2019-07-02T19:42:45.938Z,1562096565.938 [DataOverHttps](INFO): SBD MOMSN=11422322 2019-07-02T19:43:00.632Z,1562096580.632 [DataOverHttps](INFO): Sending 173 bytes from file Logs/20190702T185819/Express0025.lzma 2019-07-02T19:43:01.438Z,1562096581.438 [DataOverHttps](INFO): Moved sent file to Logs/20190702T185819/Express0025.lzma.bak 2019-07-02T19:43:01.439Z,1562096581.439 [DataOverHttps](INFO): SBD MOMSN=11422326 2019-07-02T19:43:05.457Z,1562096585.457 [Default:CheckIn:Read_Iridium] Stopped 2019-07-02T19:43:05.457Z,1562096585.457 [Default:CheckIn:C.Wait] Running Loop=1 2019-07-02T19:43:05.457Z,1562096585.457 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-07-02T19:43:18.310Z,1562096598.310 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout. 2019-07-02T19:43:18.310Z,1562096598.310 [DVL_micro] Data Fault, FailCount= 1 2019-07-02T19:43:18.310Z,1562096598.310 [DVL_micro](ERROR): Data Fault 2019-07-02T19:43:18.393Z,1562096598.393 [CBIT](ERROR): Data Fault in component: DVL_micro 2019-07-02T19:43:18.785Z,1562096598.785 [DVL_micro](INFO): uninitialize:Powering down 2019-07-02T19:43:19.566Z,1562096599.566 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-07-02T19:43:19.566Z,1562096599.566 [DVL_micro] No Fault, FailCount= 1 2019-07-02T19:43:19.936Z,1562096599.936 [DVL_micro](INFO): Initializing 2019-07-02T19:46:24.160Z,1562096784.160 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout. 2019-07-02T19:46:24.160Z,1562096784.160 [DVL_micro] Data Fault, FailCount= 1 2019-07-02T19:46:24.160Z,1562096784.160 [DVL_micro](ERROR): Data Fault 2019-07-02T19:46:24.193Z,1562096784.193 [CBIT](ERROR): Data Fault in component: DVL_micro 2019-07-02T19:46:24.625Z,1562096784.625 [DVL_micro](INFO): uninitialize:Powering down 2019-07-02T19:46:25.397Z,1562096785.397 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-07-02T19:46:25.397Z,1562096785.397 [DVL_micro] No Fault, FailCount= 1 2019-07-02T19:46:25.772Z,1562096785.772 [DVL_micro](INFO): Initializing 2019-07-02T19:46:47.584Z,1562096807.584 [NAL9602](INFO): SBD MO Status=2, MOMSN=788, MT Status=2, MTMSN=0 2019-07-02T19:46:47.584Z,1562096807.584 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-07-02T19:47:19.912Z,1562096839.912 [NAL9602](INFO): SBD MO Status=2, MOMSN=788, MT Status=2, MTMSN=0 2019-07-02T19:47:19.912Z,1562096839.912 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-07-02T19:47:46.612Z,1562096866.612 [NAL9602](INFO): SBD MO Status=0, MOMSN=788, MT Status=0, MTMSN=0 2019-07-02T19:47:46.612Z,1562096866.612 [NAL9602](INFO): No messages in MT queue 2019-07-02T19:48:06.009Z,1562096886.009 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-07-02T19:48:06.009Z,1562096886.009 [Default:CheckIn:C.Wait] Stopped 2019-07-02T19:48:06.009Z,1562096886.009 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-07-02T19:48:06.009Z,1562096886.009 [Default:CheckIn:D] Running Loop=1 2019-07-02T19:48:06.398Z,1562096886.398 [Default:CheckIn:D] Stopped 2019-07-02T19:48:06.399Z,1562096886.399 [Default:CheckIn:E] Running Loop=1 2019-07-02T19:48:06.802Z,1562096886.802 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 80.688753 min 2019-07-02T19:48:06.802Z,1562096886.802 [Default:CheckIn:E] Stopped 2019-07-02T19:48:06.802Z,1562096886.802 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-07-02T19:48:06.802Z,1562096886.802 [Default:CheckIn] Stopped 2019-07-02T19:48:06.802Z,1562096886.802 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-07-02T19:48:06.802Z,1562096886.802 [Default:CheckIn](INFO): Running loop #15 2019-07-02T19:48:06.802Z,1562096886.802 [Default:CheckIn] Running Loop=15 2019-07-02T19:48:06.802Z,1562096886.802 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-07-02T19:48:06.802Z,1562096886.802 [Default:CheckIn:Read_GPS] Running Loop=1 2019-07-02T19:48:08.393Z,1562096888.393 [NAL9602](DEBUG): Fix Requested 2019-07-02T19:48:08.788Z,1562096888.788 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194809.00,A,3648.16744,N,12147.28177,W,0.175,188.40,020719,,,A*79 2019-07-02T19:48:08.791Z,1562096888.791 [NAL9602](INFO): GPS fix at 20190702T194809: (36.802791, -121.788029) 2019-07-02T19:48:08.821Z,1562096888.821 [Default:CheckIn:Read_GPS] Stopped 2019-07-02T19:48:08.821Z,1562096888.821 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-07-02T19:48:16.544Z,1562096896.544 [DataOverHttps](INFO): Sending 64 bytes from file Logs/20190702T185819/Courier0027.lzma 2019-07-02T19:48:17.350Z,1562096897.350 [DataOverHttps](INFO): Moved sent file to Logs/20190702T185819/Courier0027.lzma.bak 2019-07-02T19:48:17.350Z,1562096897.350 [DataOverHttps](INFO): SBD MOMSN=11422332 2019-07-02T19:48:32.725Z,1562096912.725 [DataOverHttps](INFO): Sending 174 bytes from file Logs/20190702T185819/Express0028.lzma 2019-07-02T19:48:33.530Z,1562096913.530 [DataOverHttps](INFO): Moved sent file to Logs/20190702T185819/Express0028.lzma.bak 2019-07-02T19:48:33.530Z,1562096913.530 [DataOverHttps](INFO): SBD MOMSN=11422335 2019-07-02T19:48:37.505Z,1562096917.505 [Default:CheckIn:Read_Iridium] Stopped 2019-07-02T19:48:37.506Z,1562096917.506 [Default:CheckIn:C.Wait] Running Loop=1 2019-07-02T19:48:37.506Z,1562096917.506 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-07-02T19:48:40.702Z,1562096920.702 [NAL9602](INFO): Not Powering down - fast GPS 2019-07-02T19:49:29.990Z,1562096969.990 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout. 2019-07-02T19:49:29.990Z,1562096969.990 [DVL_micro] Data Fault, FailCount= 1 2019-07-02T19:49:29.990Z,1562096969.990 [DVL_micro](ERROR): Data Fault 2019-07-02T19:49:30.053Z,1562096970.053 [CBIT](ERROR): Data Fault in component: DVL_micro 2019-07-02T19:49:30.465Z,1562096970.465 [DVL_micro](INFO): uninitialize:Powering down 2019-07-02T19:49:31.246Z,1562096971.246 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-07-02T19:49:31.246Z,1562096971.246 [DVL_micro] No Fault, FailCount= 1 2019-07-02T19:49:31.609Z,1562096971.609 [DVL_micro](INFO): Initializing 2019-07-02T19:52:35.830Z,1562097155.830 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout. 2019-07-02T19:52:35.830Z,1562097155.830 [DVL_micro] Data Fault, FailCount= 1 2019-07-02T19:52:35.830Z,1562097155.830 [DVL_micro](ERROR): Data Fault 2019-07-02T19:52:35.872Z,1562097155.872 [CBIT](ERROR): Data Fault in component: DVL_micro 2019-07-02T19:52:36.305Z,1562097156.305 [DVL_micro](INFO): uninitialize:Powering down 2019-07-02T19:52:37.086Z,1562097157.086 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-07-02T19:52:37.086Z,1562097157.086 [DVL_micro] No Fault, FailCount= 1 2019-07-02T19:52:37.449Z,1562097157.449 [DVL_micro](INFO): Initializing 2019-07-02T19:53:38.067Z,1562097218.067 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-07-02T19:53:38.067Z,1562097218.067 [Default:CheckIn:C.Wait] Stopped 2019-07-02T19:53:38.067Z,1562097218.067 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-07-02T19:53:38.067Z,1562097218.067 [Default:CheckIn:D] Running Loop=1 2019-07-02T19:53:38.485Z,1562097218.485 [Default:CheckIn:D] Stopped 2019-07-02T19:53:38.485Z,1562097218.485 [Default:CheckIn:E] Running Loop=1 2019-07-02T19:53:38.920Z,1562097218.920 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 86.223527 min 2019-07-02T19:53:38.920Z,1562097218.920 [Default:CheckIn:E] Stopped 2019-07-02T19:53:38.920Z,1562097218.920 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-07-02T19:53:38.921Z,1562097218.921 [Default:CheckIn] Stopped 2019-07-02T19:53:38.921Z,1562097218.921 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-07-02T19:53:38.921Z,1562097218.921 [Default:CheckIn](INFO): Running loop #16 2019-07-02T19:53:38.921Z,1562097218.921 [Default:CheckIn] Running Loop=16 2019-07-02T19:53:38.921Z,1562097218.921 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-07-02T19:53:38.921Z,1562097218.921 [Default:CheckIn:Read_GPS] Running Loop=1 2019-07-02T19:53:40.481Z,1562097220.481 [NAL9602](DEBUG): Fix Requested 2019-07-02T19:53:40.880Z,1562097220.880 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,195341.00,A,3648.16517,N,12147.28278,W,0.272,302.31,020719,,,A*75 2019-07-02T19:53:40.886Z,1562097220.886 [NAL9602](INFO): GPS fix at 20190702T195341: (36.802753, -121.788046) 2019-07-02T19:53:40.917Z,1562097220.917 [Default:CheckIn:Read_GPS] Stopped 2019-07-02T19:53:40.917Z,1562097220.917 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-07-02T19:53:50.480Z,1562097230.480 [DataOverHttps](INFO): Sending 64 bytes from file Logs/20190702T185819/Courier0030.lzma 2019-07-02T19:53:51.286Z,1562097231.286 [DataOverHttps](INFO): Moved sent file to Logs/20190702T185819/Courier0030.lzma.bak 2019-07-02T19:53:51.286Z,1562097231.286 [DataOverHttps](INFO): SBD MOMSN=11422367 2019-07-02T19:54:11.692Z,1562097251.692 [DataOverHttps](INFO): Sending 173 bytes from file Logs/20190702T185819/Express0031.lzma 2019-07-02T19:54:12.498Z,1562097252.498 [DataOverHttps](INFO): Moved sent file to Logs/20190702T185819/Express0031.lzma.bak 2019-07-02T19:54:12.498Z,1562097252.498 [DataOverHttps](INFO): SBD MOMSN=11422370 2019-07-02T19:54:16.869Z,1562097256.869 [Default:CheckIn:Read_Iridium] Stopped 2019-07-02T19:54:16.870Z,1562097256.870 [Default:CheckIn:C.Wait] Running Loop=1 2019-07-02T19:54:16.870Z,1562097256.870 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-07-02T19:54:24.913Z,1562097264.913 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2019-07-02T19:54:24.913Z,1562097264.913 [DropWeight] Hardware Fault, FailCount= 1 2019-07-02T19:54:24.914Z,1562097264.914 [DropWeight](ERROR): Hardware Fault 2019-07-02T19:54:24.983Z,1562097264.983 [CommandLine](FAULT): Scheduling is paused 2019-07-02T19:54:24.984Z,1562097264.984 [CBIT](INFO): Critical error at 20190702T195424 2019-07-02T19:54:24.986Z,1562097264.986 [CBIT](ERROR): Hardware Fault in component: DropWeight 2019-07-02T19:54:24.986Z,1562097264.986 [CBIT](CRITICAL): Hardware Fault in component: DropWeight 2019-07-02T19:54:25.345Z,1562097265.345 [CBIT](INFO): Critical error at 20190702T195424 2019-07-02T19:55:41.670Z,1562097341.670 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout. 2019-07-02T19:55:41.670Z,1562097341.670 [DVL_micro] Data Fault, FailCount= 1 2019-07-02T19:55:41.670Z,1562097341.670 [DVL_micro](ERROR): Data Fault 2019-07-02T19:55:41.724Z,1562097341.724 [CBIT](ERROR): Data Fault in component: DVL_micro 2019-07-02T19:55:42.149Z,1562097342.149 [DVL_micro](INFO): uninitialize:Powering down 2019-07-02T19:55:42.918Z,1562097342.918 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-07-02T19:55:42.918Z,1562097342.918 [DVL_micro] No Fault, FailCount= 1 2019-07-02T19:55:43.291Z,1562097343.291 [DVL_micro](INFO): Initializing 2019-07-02T19:56:28.941Z,1562097388.941 [NAL9602](INFO): SBD MO Status=2, MOMSN=789, MT Status=2, MTMSN=0 2019-07-02T19:56:28.941Z,1562097388.941 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-07-02T19:56:51.185Z,1562097411.185 [DVL_micro](ERROR): only read 45 of 46 data items 2019-07-02T19:56:51.185Z,1562097411.185 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 0 0 0 0 -9-673 -602 2 2 2 2 -393.7 -356.3 -839.1 2 -375.8 -375.1 -839.1 2 -393 -35 -375 -375 -839 2 4.21 -2.81 2.8 -3.0 18.9 0.005 35.0 1489 111 2019-07-02T19:57:04.108Z,1562097424.108 [NAL9602](INFO): SBD MO Status=2, MOMSN=789, MT Status=2, MTMSN=0 2019-07-02T19:57:04.108Z,1562097424.108 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-07-02T19:58:08.733Z,1562097488.733 [DVL_micro](ERROR): only read 45 of 46 data items 2019-07-02T19:58:08.733Z,1562097488.733 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 0 0 0 0 -528 -718 -781 -616 2 2 2 2 337.7 -136.1 -712.7 2 344.2 -118.92 337 -136 -712 2 344 -118 -712 2 4.22 -2.76 2.9 -3.0 18.9 0.005 35.0 1489 109 2019-07-02T19:58:10.343Z,1562097490.343 [NAL9602](INFO): SBD MO Status=0, MOMSN=789, MT Status=0, MTMSN=0 2019-07-02T19:58:10.344Z,1562097490.344 [NAL9602](INFO): No messages in MT queue 2019-07-02T19:58:41.129Z,1562097521.129 [NAL9602](INFO): Not Powering down - fast GPS 2019-07-02T19:58:47.510Z,1562097527.510 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout. 2019-07-02T19:58:47.510Z,1562097527.510 [DVL_micro] Data Fault, FailCount= 1 2019-07-02T19:58:47.510Z,1562097527.510 [DVL_micro](ERROR): Data Fault 2019-07-02T19:58:47.585Z,1562097527.585 [CBIT](ERROR): Data Fault in component: DVL_micro 2019-07-02T19:58:47.987Z,1562097527.987 [DVL_micro](INFO): uninitialize:Powering down 2019-07-02T19:58:48.795Z,1562097528.795 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-07-02T19:58:48.795Z,1562097528.795 [DVL_micro] No Fault, FailCount= 1 2019-07-02T19:58:49.136Z,1562097529.136 [DVL_micro](INFO): Initializing 2019-07-02T19:59:17.440Z,1562097557.440 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-07-02T19:59:17.440Z,1562097557.440 [Default:CheckIn:C.Wait] Stopped 2019-07-02T19:59:17.440Z,1562097557.440 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-07-02T19:59:17.445Z,1562097557.445 [Default:CheckIn:D] Running Loop=1 2019-07-02T19:59:17.854Z,1562097557.854 [Default:CheckIn:D] Stopped 2019-07-02T19:59:17.854Z,1562097557.854 [Default:CheckIn:E] Running Loop=1 2019-07-02T19:59:18.310Z,1562097558.310 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 91.879679 min 2019-07-02T19:59:18.310Z,1562097558.310 [Default:CheckIn:E] Stopped 2019-07-02T19:59:18.310Z,1562097558.310 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-07-02T19:59:18.310Z,1562097558.310 [Default:CheckIn] Stopped 2019-07-02T19:59:18.310Z,1562097558.310 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-07-02T19:59:18.311Z,1562097558.311 [Default:CheckIn](INFO): Running loop #17 2019-07-02T19:59:18.311Z,1562097558.311 [Default:CheckIn] Running Loop=17 2019-07-02T19:59:18.311Z,1562097558.311 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-07-02T19:59:18.311Z,1562097558.311 [Default:CheckIn:Read_GPS] Running Loop=1 2019-07-02T19:59:19.841Z,1562097559.841 [NAL9602](DEBUG): Fix Requested 2019-07-02T19:59:20.236Z,1562097560.236 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,195921.00,A,3648.16207,N,12147.28706,W,0.233,359.48,020719,,,A*76 2019-07-02T19:59:20.238Z,1562097560.238 [NAL9602](INFO): GPS fix at 20190702T195921: (36.802701, -121.788118) 2019-07-02T19:59:20.301Z,1562097560.301 [Default:CheckIn:Read_GPS] Stopped 2019-07-02T19:59:20.301Z,1562097560.301 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-07-02T19:59:21.438Z,1562097561.438 [DVL_micro](ERROR): checksum mismatch: reported101 , calculated:121 2019-07-02T19:59:21.438Z,1562097561.438 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 0 0 0 0 -586 -794 -761 -709 2 2 2 2 233.6 -113.4 -768.5 -101.9 -768.5 2 233 -113 -768 2 238 -101 -768 2 4.24 -2.77 2.8 -3.0 18.9 0.005 35.0 1489 101 2019-07-02T19:59:36.177Z,1562097576.177 [DataOverHttps](INFO): Sending 169 bytes from file Logs/20190702T185819/Courier0033.lzma 2019-07-02T19:59:36.983Z,1562097576.983 [DataOverHttps](INFO): Moved sent file to Logs/20190702T185819/Courier0033.lzma.bak 2019-07-02T19:59:36.983Z,1562097576.983 [DataOverHttps](INFO): SBD MOMSN=11422381 2019-07-02T20:00:06.929Z,1562097606.929 [DataOverHttps](INFO): Sending 198 bytes from file Logs/20190702T185819/Express0034.lzma 2019-07-02T20:00:09.460Z,1562097609.460 [DataOverHttps](INFO): Moved sent file to Logs/20190702T185819/Express0034.lzma.bak 2019-07-02T20:00:09.460Z,1562097609.460 [DataOverHttps](INFO): SBD MOMSN=11422400 2019-07-02T20:00:18.377Z,1562097618.377 [Default:CheckIn:Read_Iridium] Stopped 2019-07-02T20:00:18.378Z,1562097618.378 [Default:CheckIn:C.Wait] Running Loop=1 2019-07-02T20:00:18.378Z,1562097618.378 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-07-02T20:01:36.949Z,1562097696.949 [CommandLine](IMPORTANT): got command quit 2019-07-02T20:01:37.957Z,1562097697.957 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2019-07-02T20:01:37.957Z,1562097697.957 [CommandLine ThreadHandler](INFO): Thread cancelled. 2019-07-02T20:01:38.133Z,1562097698.133 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2019-07-02T20:01:38.133Z,1562097698.133 [CommandLine ThreadHandler](INFO): Thread cancelled. 2019-07-02T20:01:38.155Z,1562097698.155 [CommandLine](INFO): Join timeout helper Thread ID is 3725 2019-07-02T20:01:38.162Z,1562097698.162 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2019-07-02T20:01:38.163Z,1562097698.163 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2019-07-02T20:01:38.163Z,1562097698.163 [NavChartDb](INFO): Join timeout helper Thread ID is 3726 2019-07-02T20:01:38.365Z,1562097698.365 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2019-07-02T20:01:38.365Z,1562097698.365 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2019-07-02T20:01:38.369Z,1562097698.369 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2019-07-02T20:01:38.369Z,1562097698.369 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2019-07-02T20:01:38.369Z,1562097698.369 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 3727 2019-07-02T20:01:38.642Z,1562097698.642 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2019-07-02T20:01:38.642Z,1562097698.642 [WetLabsBB2FL](INFO): Powering down 2019-07-02T20:01:38.643Z,1562097698.643 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2019-07-02T20:01:38.645Z,1562097698.645 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2019-07-02T20:01:38.645Z,1562097698.645 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2019-07-02T20:01:38.645Z,1562097698.645 [CTD_Seabird](INFO): Join timeout helper Thread ID is 3728 2019-07-02T20:01:38.933Z,1562097698.933 [CTD_Seabird](INFO): Powering down 2019-07-02T20:01:38.945Z,1562097698.945 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread. 2019-07-02T20:01:38.945Z,1562097698.945 [CTD_Seabird](INFO): Powering down 2019-07-02T20:01:38.958Z,1562097698.958 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2019-07-02T20:01:38.973Z,1562097698.973 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2019-07-02T20:01:38.973Z,1562097698.973 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2019-07-02T20:01:38.973Z,1562097698.973 [Radio_Surface](INFO): Join timeout helper Thread ID is 3729 2019-07-02T20:01:39.013Z,1562097699.013 [Radio_Surface](INFO): Powering down 2019-07-02T20:01:39.014Z,1562097699.014 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2019-07-02T20:01:39.014Z,1562097699.014 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2019-07-02T20:01:39.015Z,1562097699.015 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2019-07-02T20:01:39.015Z,1562097699.015 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2019-07-02T20:01:39.016Z,1562097699.016 [DataOverHttps](INFO): Join timeout helper Thread ID is 3730 2019-07-02T20:01:39.069Z,1562097699.069 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2019-07-02T20:01:39.069Z,1562097699.069 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2019-07-02T20:01:39.082Z,1562097699.082 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2019-07-02T20:01:39.082Z,1562097699.082 [logger ThreadHandler](INFO): Thread cancelled. 2019-07-02T20:01:39.083Z,1562097699.083 [logger](INFO): Join timeout helper Thread ID is 3731 2019-07-02T20:01:39.109Z,1562097699.109 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2019-07-02T20:01:39.109Z,1562097699.109 [logger ThreadHandler](INFO): Thread cancelled. 2019-07-02T20:01:39.136Z,1562097699.136 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2019-07-02T20:01:39.137Z,1562097699.137 [CommandLine ThreadHandler](INFO): Thread cancelled. 2019-07-02T20:01:39.137Z,1562097699.137 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2019-07-02T20:01:39.137Z,1562097699.137 [controlThread ThreadHandler](INFO): Thread cancelled. 2019-07-02T20:01:39.137Z,1562097699.137 [controlThread](INFO): Join timeout helper Thread ID is 3732 2019-07-02T20:01:39.204Z,1562097699.204 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2019-07-02T20:01:39.204Z,1562097699.204 [controlThread](DEBUG): Uninitializing ControlThread 2019-07-02T20:01:39.204Z,1562097699.204 [AHRS_M2](INFO): Powering down 2019-07-02T20:01:39.354Z,1562097699.354 [DVL_micro](INFO): uninitialize:Powering down 2019-07-02T20:01:39.355Z,1562097699.355 [NAL9602](INFO): Powering down 2019-07-02T20:01:39.357Z,1562097699.357 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2019-07-02T20:01:39.358Z,1562097699.358 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2019-07-02T20:01:39.359Z,1562097699.359 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2019-07-02T20:01:39.359Z,1562097699.359 [MissionManager](INFO): Uninitializing Mission Default 2019-07-02T20:01:39.359Z,1562097699.359 [Default] Stopped 2019-07-02T20:01:39.359Z,1562097699.359 [Default](DEBUG): Aggregate::uninitialize Default 2019-07-02T20:01:39.359Z,1562097699.359 [Default:B.GoToSurface] Stopped 2019-07-02T20:01:39.359Z,1562097699.359 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2019-07-02T20:01:39.360Z,1562097699.360 [Default:CheckIn] Stopped 2019-07-02T20:01:39.360Z,1562097699.360 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-07-02T20:01:39.360Z,1562097699.360 [Default:CheckIn:C.Wait] Stopped 2019-07-02T20:01:39.360Z,1562097699.360 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-07-02T20:01:39.363Z,1562097699.363 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2019-07-02T20:01:39.363Z,1562097699.363 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2019-07-02T20:01:39.363Z,1562097699.363 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2019-07-02T20:01:39.364Z,1562097699.364 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2019-07-02T20:01:39.364Z,1562097699.364 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2019-07-02T20:01:39.364Z,1562097699.364 [BuoyancyServo](INFO): Powering down 2019-07-02T20:01:39.381Z,1562097699.381 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2019-07-02T20:01:39.381Z,1562097699.381 [ElevatorServo](INFO): Powering down 2019-07-02T20:01:39.382Z,1562097699.382 [MassServo](DEBUG): Uninitialize Mass Servo. 2019-07-02T20:01:39.382Z,1562097699.382 [MassServo](INFO): Powering down 2019-07-02T20:01:39.383Z,1562097699.383 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2019-07-02T20:01:39.383Z,1562097699.383 [RudderServo](INFO): Powering down 2019-07-02T20:01:39.384Z,1562097699.384 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2019-07-02T20:01:39.384Z,1562097699.384 [ThrusterServo](INFO): Powering down 2019-07-02T20:01:39.385Z,1562097699.385 [SBIT](DEBUG): Uninitialize SBIT Component. 2019-07-02T20:01:39.385Z,1562097699.385 [IBIT](DEBUG): Uninitialize IBIT Component. 2019-07-02T20:01:39.385Z,1562097699.385 [CBIT](DEBUG): Uninitialize CBIT Component. 2019-07-02T20:01:39.386Z,1562097699.386 [CBIT](DEBUG): Powering off loads. 2019-07-02T20:01:39.397Z,1562097699.397 [CBIT](DEBUG): Disabling WDT. 2019-07-02T20:01:39.409Z,1562097699.409 [CBIT](DEBUG): Opening all GF detection circuits. 2019-07-02T20:01:39.410Z,1562097699.410 [controlThread ThreadHandler](INFO): Thread cancelled. 2019-07-02T20:01:39.856Z,1562097699.856 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2019-07-02T20:01:39.882Z,1562097699.882 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2019-07-02T20:01:39.970Z,1562097699.970 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2019-07-02T20:01:39.976Z,1562097699.976 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2019-07-02T20:01:40.066Z,1562097700.066 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2019-07-02T20:01:40.225Z,1562097700.225 [logger ThreadHandler](INFO): Thread cancelled.