2019-09-25T17:32:34.779Z,1569432754.779 [CommandLine](IMPORTANT): got command restart logs 2019-09-25T17:32:44.046Z,1569432764.046 [DVL_micro](ERROR): Failed to parse: :WI,+00443,-00037,00000,A 2019-09-25T17:32:51.764Z,1569432771.764 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2019-09-25T17:32:51.765Z,1569432771.765 [DVL_micro](ERROR): Failed to parse: :TS,000000,35.0000.0,148 2019-09-25T17:32:59.402Z,1569432779.402 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2019-09-25T17:32:59.402Z,1569432779.402 [DVL_micro](ERROR): Failed to parse: :TS,00000000000,+16.2,089.0,000 2019-09-25T17:34:13.342Z,1569432853.342 [DVL_micro](ERROR): Failed to parse:278,-00281,+00584,+00000,I 2019-09-25T17:34:18.581Z,1569432858.581 [DVL_micro](ERROR): only read 3 of 4 data items 2019-09-25T17:34:18.582Z,1569432858.582 [DVL_micro](ERROR): Failed to parse: :BI,+00188,-0762,+00000,I 2019-09-25T17:35:29.334Z,1569432929.334 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-09-25T17:35:29.334Z,1569432929.334 [Default:CheckIn:C.Wait] Stopped 2019-09-25T17:35:29.334Z,1569432929.334 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-09-25T17:35:29.334Z,1569432929.334 [Default:CheckIn:D] Running Loop=1 2019-09-25T17:35:29.710Z,1569432929.710 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2019-09-25T17:35:29.710Z,1569432929.710 [DVL_micro](ERROR): Failed to parse: :TS,000000000000006.4,0000.0,1489.0,000 2019-09-25T17:35:29.760Z,1569432929.760 [Default:CheckIn:D] Stopped 2019-09-25T17:35:29.760Z,1569432929.760 [Default:CheckIn:E] Running Loop=1 2019-09-25T17:35:30.136Z,1569432930.136 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 18.199640 min 2019-09-25T17:35:30.136Z,1569432930.136 [Default:CheckIn:E] Stopped 2019-09-25T17:35:30.136Z,1569432930.136 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-09-25T17:35:30.136Z,1569432930.136 [Default:CheckIn] Stopped 2019-09-25T17:35:30.136Z,1569432930.136 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-09-25T17:35:30.136Z,1569432930.136 [Default:CheckIn](INFO): Running loop #4 2019-09-25T17:35:30.136Z,1569432930.136 [Default:CheckIn] Running Loop=4 2019-09-25T17:35:30.137Z,1569432930.137 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-09-25T17:35:30.137Z,1569432930.137 [Default:CheckIn:Read_GPS] Running Loop=1 2019-09-25T17:35:31.734Z,1569432931.734 [NAL9602](DEBUG): Fix Requested 2019-09-25T17:35:32.128Z,1569432932.128 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173530.00,A,3648.33514,N,12149.40771,W,17.475,168.62,250919,,,D*44 2019-09-25T17:35:32.130Z,1569432932.130 [NAL9602](INFO): GPS fix at 20190925T173530: (36.805586, -121.823462) 2019-09-25T17:35:32.194Z,1569432932.194 [Default:CheckIn:Read_GPS] Stopped 2019-09-25T17:35:32.195Z,1569432932.195 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-09-25T17:35:47.893Z,1569432947.893 [DVL_micro](ERROR): only read 3 of 4 data items 2019-09-25T17:35:47.893Z,1569432947.893 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+9999.99,+9999.999 2019-09-25T17:35:47.895Z,1569432947.895 [NAL9602](INFO): SBD MO Status=0, MOMSN=2054, MT Status=0, MTMSN=0 2019-09-25T17:35:47.895Z,1569432947.895 [NAL9602](INFO): No messages in MT queue 2019-09-25T17:35:50.739Z,1569432950.739 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-09-25T17:35:53.751Z,1569432953.751 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.287849 2019-09-25T17:36:15.835Z,1569432975.835 [NAL9602](INFO): SBD MO Status=1, MOMSN=2055, MT Status=0, MTMSN=0 2019-09-25T17:36:15.883Z,1569432975.883 [NAL9602](INFO): Sent 25 bytes from file Logs/20190925T162134/Courier0039.lzma 2019-09-25T17:36:15.883Z,1569432975.883 [NAL9602](INFO): Packets left to send: 0 2019-09-25T17:36:24.875Z,1569432984.875 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-09-25T17:36:31.256Z,1569432991.256 [DVL_micro](ERROR): Failed to parse: :0,-00164,+00533,+00000,I 2019-09-25T17:36:32.469Z,1569432992.469 [NAL9602](INFO): SBD MO Status=2, MOMSN=2056, MT Status=2, MTMSN=0 2019-09-25T17:36:32.469Z,1569432992.469 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-09-25T17:36:41.195Z,1569433001.195 [DVL_micro](ERROR): Failed to parse: :BI,+00062,+00093,+00609,+00000,I 2019-09-25T17:36:47.715Z,1569433007.715 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003277 2019-09-25T17:36:56.806Z,1569433016.806 [DataOverHttps](INFO): Sending 213 bytes from file Logs/20190925T173234/Courier0000.lzma 2019-09-25T17:36:58.812Z,1569433018.812 [DataOverHttps](INFO): Moved sent file to Logs/20190925T173234/Courier0000.lzma.bak 2019-09-25T17:36:58.812Z,1569433018.812 [DataOverHttps](INFO): SBD MOMSN=11815425 2019-09-25T17:36:58.917Z,1569433018.917 [NAL9602](INFO): SBD MO Status=2, MOMSN=2056, MT Status=2, MTMSN=0 2019-09-25T17:36:58.917Z,1569433018.917 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-09-25T17:36:59.323Z,1569433019.323 [DVL_micro](ERROR): DVL BIT error. See manual. Result code: -5 2019-09-25T17:36:59.325Z,1569433019.325 [DVL_micro](ERROR): Failed to parse: :BD,+00000000.00,+00000000.00,+00000000.00,9999.99,000.00 2019-09-25T17:37:24.534Z,1569433044.534 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190925T173234/Courier0004.lzma 2019-09-25T17:37:26.540Z,1569433046.540 [DataOverHttps](INFO): Moved sent file to Logs/20190925T173234/Courier0004.lzma.bak 2019-09-25T17:37:26.540Z,1569433046.540 [DataOverHttps](INFO): SBD MOMSN=11815429 2019-09-25T17:37:29.639Z,1569433049.639 [NAL9602](INFO): Not Powering down - fast GPS 2019-09-25T17:37:46.514Z,1569433066.514 [DataOverHttps](INFO): Sending 104 bytes from file Logs/20190925T162134/Express0040.lzma 2019-09-25T17:37:48.520Z,1569433068.520 [DataOverHttps](INFO): Moved sent file to Logs/20190925T162134/Express0040.lzma.bak 2019-09-25T17:37:48.520Z,1569433068.520 [DataOverHttps](INFO): SBD MOMSN=11815431 2019-09-25T17:38:06.055Z,1569433086.055 [CBIT](INFO): Clearing failed state for component BPC1 2019-09-25T17:38:06.055Z,1569433086.055 [BPC1] No Fault, FailCount= 1 2019-09-25T17:38:08.139Z,1569433088.139 [DataOverHttps](INFO): Sending 378 bytes from file Logs/20190925T173234/Express0001.lzma 2019-09-25T17:38:10.144Z,1569433090.144 [DataOverHttps](INFO): Moved sent file to Logs/20190925T173234/Express0001.lzma.bak 2019-09-25T17:38:10.144Z,1569433090.144 [DataOverHttps](INFO): SBD MOMSN=11815436 2019-09-25T17:38:34.038Z,1569433114.038 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190925T173234/Express0006.lzma 2019-09-25T17:38:36.044Z,1569433116.044 [DataOverHttps](INFO): Moved sent file to Logs/20190925T173234/Express0006.lzma.bak 2019-09-25T17:38:36.044Z,1569433116.044 [DataOverHttps](INFO): SBD MOMSN=11815445 2019-09-25T17:38:40.386Z,1569433120.386 [Default:CheckIn:Read_Iridium] Stopped 2019-09-25T17:38:40.395Z,1569433120.395 [Default:CheckIn:C.Wait] Running Loop=1 2019-09-25T17:38:40.395Z,1569433120.395 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-09-25T17:40:00.333Z,1569433200.333 [DVL_micro](ERROR): Failed to parse: :WI,+01837,+00064,+00531,+00000,A 2019-09-25T17:40:41.142Z,1569433241.142 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2019-09-25T17:40:41.142Z,1569433241.142 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,00.0,1489.0,000 2019-09-25T17:41:47.399Z,1569433307.399 [DVL_micro](ERROR): only read 0 of 4 data items 2019-09-25T17:41:47.400Z,1569433307.400 [DVL_micro](ERROR): Failed to parse: :RD9,+9999..99,+9999.99 2019-09-25T17:42:22.956Z,1569433342.956 [DVL_micro](ERROR): only read 3 of 4 data items 2019-09-25T17:42:22.956Z,1569433342.956 [DVL_micro](ERROR): Failed to parse: :BI,+00216,-0177,+000D,+0000000000000.00,+00000000.00,9999.99,000.00 2019-09-25T17:42:48.428Z,1569433368.428 [DVL_micro](ERROR): Failed to parse: :WI,+00447,-00118,+00851,+00000,A 2019-09-25T17:43:40.987Z,1569433420.987 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-09-25T17:43:40.987Z,1569433420.987 [Default:CheckIn:C.Wait] Stopped 2019-09-25T17:43:40.987Z,1569433420.987 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-09-25T17:43:40.988Z,1569433420.988 [Default:CheckIn:D] Running Loop=1 2019-09-25T17:43:41.375Z,1569433421.375 [Default:CheckIn:D] Stopped 2019-09-25T17:43:41.375Z,1569433421.375 [Default:CheckIn:E] Running Loop=1 2019-09-25T17:43:41.831Z,1569433421.831 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 26.393229 min 2019-09-25T17:43:41.831Z,1569433421.831 [Default:CheckIn:E] Stopped 2019-09-25T17:43:41.831Z,1569433421.831 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-09-25T17:43:41.831Z,1569433421.831 [Default:CheckIn] Stopped 2019-09-25T17:43:41.831Z,1569433421.831 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-09-25T17:43:41.831Z,1569433421.831 [Default:CheckIn](INFO): Running loop #5 2019-09-25T17:43:41.831Z,1569433421.831 [Default:CheckIn] Running Loop=5 2019-09-25T17:43:41.831Z,1569433421.831 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-09-25T17:43:41.831Z,1569433421.831 [Default:CheckIn:Read_GPS] Running Loop=1 2019-09-25T17:43:43.386Z,1569433423.386 [NAL9602](DEBUG): Fix Requested 2019-09-25T17:43:43.770Z,1569433423.770 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174342.00,A,3647.96353,N,12148.98216,W,0.583,291.27,250919,,,A*7A 2019-09-25T17:43:43.772Z,1569433423.772 [NAL9602](INFO): GPS fix at 20190925T174342: (36.799392, -121.816369) 2019-09-25T17:43:43.820Z,1569433423.820 [Default:CheckIn:Read_GPS] Stopped 2019-09-25T17:43:43.820Z,1569433423.820 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-09-25T17:43:53.738Z,1569433433.738 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20190925T173234/Courier0003.lzma 2019-09-25T17:43:54.809Z,1569433434.809 [DVL_micro](ERROR): Failed to parse: :0000000006.8,0000.0,1489.0,000 2019-09-25T17:43:55.744Z,1569433435.744 [DataOverHttps](INFO): Moved sent file to Logs/20190925T173234/Courier0003.lzma.bak 2019-09-25T17:43:55.744Z,1569433435.744 [DataOverHttps](INFO): SBD MOMSN=11815510 2019-09-25T17:44:02.178Z,1569433442.178 [NAL9602](INFO): SBD MO Status=1, MOMSN=2056, MT Status=0, MTMSN=0 2019-09-25T17:44:02.178Z,1569433442.178 [NAL9602](INFO): No messages in MT queue 2019-09-25T17:44:16.274Z,1569433456.274 [DataOverHttps](INFO): Sending 144 bytes from file Logs/20190925T173234/Express0005.lzma 2019-09-25T17:44:18.280Z,1569433458.280 [DataOverHttps](INFO): Moved sent file to Logs/20190925T173234/Express0005.lzma.bak 2019-09-25T17:44:18.280Z,1569433458.280 [DataOverHttps](INFO): SBD MOMSN=11815513 2019-09-25T17:44:21.943Z,1569433461.943 [Default:CheckIn:Read_Iridium] Stopped 2019-09-25T17:44:21.943Z,1569433461.943 [Default:CheckIn:C.Wait] Running Loop=1 2019-09-25T17:44:21.943Z,1569433461.943 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-09-25T17:44:32.817Z,1569433472.817 [NAL9602](INFO): Not Powering down - fast GPS 2019-09-25T17:45:31.451Z,1569433531.451 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2019-09-25T17:45:31.454Z,1569433531.454 [BPC1](INFO): Received data from all battery sticks. 2019-09-25T17:46:55.828Z,1569433615.828 [DVL_micro](ERROR): only read 3 of 4 data items 2019-09-25T17:46:55.828Z,1569433615.828 [DVL_micro](ERROR): Failed to parse: :BI,+00876,-00679,00000,I 2019-09-25T17:47:54.405Z,1569433674.405 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2019-09-25T17:47:54.405Z,1569433674.405 [DVL_micro](ERROR): Failed to parse: :TS,000000035.0,+170,1489.0,000 2019-09-25T17:48:27.548Z,1569433707.548 [DVL_micro](ERROR): only read 3 of 4 data items 2019-09-25T17:48:27.548Z,1569433707.548 [DVL_micro](ERROR): Failed to parse: :BI,-0325,+00355,+00000,I 2019-09-25T17:49:00.671Z,1569433740.671 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2019-09-25T17:49:00.671Z,1569433740.671 [DVL_micro](ERROR): Failed to parse::TS,000000000.0,+17.1,0000.0,1489.0,000 2019-09-25T17:49:22.527Z,1569433762.527 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-09-25T17:49:22.527Z,1569433762.527 [Default:CheckIn:C.Wait] Stopped 2019-09-25T17:49:22.527Z,1569433762.527 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-09-25T17:49:22.528Z,1569433762.528 [Default:CheckIn:D] Running Loop=1 2019-09-25T17:49:22.913Z,1569433762.913 [Default:CheckIn:D] Stopped 2019-09-25T17:49:22.913Z,1569433762.913 [Default:CheckIn:E] Running Loop=1 2019-09-25T17:49:23.328Z,1569433763.328 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 32.085527 min 2019-09-25T17:49:23.329Z,1569433763.329 [Default:CheckIn:E] Stopped 2019-09-25T17:49:23.329Z,1569433763.329 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-09-25T17:49:23.329Z,1569433763.329 [Default:CheckIn] Stopped 2019-09-25T17:49:23.329Z,1569433763.329 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-09-25T17:49:23.329Z,1569433763.329 [Default:CheckIn](INFO): Running loop #6 2019-09-25T17:49:23.329Z,1569433763.329 [Default:CheckIn] Running Loop=6 2019-09-25T17:49:23.329Z,1569433763.329 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-09-25T17:49:23.329Z,1569433763.329 [Default:CheckIn:Read_GPS] Running Loop=1 2019-09-25T17:49:24.934Z,1569433764.934 [NAL9602](DEBUG): Fix Requested 2019-09-25T17:49:25.315Z,1569433765.315 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174923.00,A,3648.33599,N,12147.50060,W,10.050,55.13,250919,,,A*78 2019-09-25T17:49:25.317Z,1569433765.317 [NAL9602](INFO): GPS fix at 20190925T174923: (36.805600, -121.791677) 2019-09-25T17:49:25.364Z,1569433765.364 [Default:CheckIn:Read_GPS] Stopped 2019-09-25T17:49:25.364Z,1569433765.364 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-09-25T17:49:31.037Z,1569433771.037 [DVL_micro](ERROR): Failed to parse: :BD,+00000000.00,+00000000.00,+00000000.00,9999.99,000.00 2019-09-25T17:49:34.183Z,1569433774.183 [DataOverHttps](INFO): Sending 223 bytes from file Logs/20190925T173234/Courier0009.lzma 2019-09-25T17:49:39.521Z,1569433779.521 [NAL9602](INFO): SBD MO Status=1, MOMSN=2057, MT Status=0, MTMSN=0 2019-09-25T17:49:39.522Z,1569433779.522 [NAL9602](INFO): No messages in MT queue 2019-09-25T17:49:40.204Z,1569433780.204 [DataOverHttps](INFO): Moved sent file to Logs/20190925T173234/Courier0009.lzma.bak 2019-09-25T17:49:40.204Z,1569433780.204 [DataOverHttps](INFO): SBD MOMSN=11815562 2019-09-25T17:49:59.323Z,1569433799.323 [DVL_micro](ERROR): only read 1 of 4 data items 2019-09-25T17:49:59.323Z,1569433799.323 [DVL_micro](ERROR): Failed to parse: :BI,+01299+00701,+00BD,+0000000000000.0000.00,900.00 2019-09-25T17:50:00.087Z,1569433800.087 [DataOverHttps](INFO): Sending 146 bytes from file Logs/20190925T173234/Express0010.lzma 2019-09-25T17:50:02.092Z,1569433802.092 [DataOverHttps](INFO): Moved sent file to Logs/20190925T173234/Express0010.lzma.bak 2019-09-25T17:50:02.092Z,1569433802.092 [DataOverHttps](INFO): SBD MOMSN=11815566 2019-09-25T17:50:05.822Z,1569433805.822 [Default:CheckIn:Read_Iridium] Stopped 2019-09-25T17:50:05.822Z,1569433805.822 [Default:CheckIn:C.Wait] Running Loop=1 2019-09-25T17:50:05.826Z,1569433805.826 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-09-25T17:50:10.220Z,1569433810.220 [NAL9602](INFO): Not Powering down - fast GPS 2019-09-25T17:50:50.229Z,1569433850.229 [DVL_micro](ERROR): Failed to parse: :R99,+9999.99,+9999.99,+9999.99 2019-09-25T17:52:19.509Z,1569433939.509 [DVL_micro](ERROR): only read 3 of 4 data items 2019-09-25T17:52:19.509Z,1569433939.509 [DVL_micro](ERROR): Failed to parse: :BI,-0084,+00123,+00BD,+0000+0000000000000.00,9999.99,000.00 2019-09-25T17:52:44.978Z,1569433964.978 [DVL_micro](ERROR): only read 3 of 4 data items 2019-09-25T17:52:44.978Z,1569433964.978 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+99999.99,+9999.99 2019-09-25T17:53:10.432Z,1569433990.432 [DVL_micro](ERROR): only read 3 of 4 data items 2019-09-25T17:53:10.432Z,1569433990.432 [DVL_micro](ERROR): Failed to parse: :BI,-00278,-0097,+00000,I 2019-09-25T17:55:06.422Z,1569434106.422 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-09-25T17:55:06.422Z,1569434106.422 [Default:CheckIn:C.Wait] Stopped 2019-09-25T17:55:06.422Z,1569434106.422 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-09-25T17:55:06.426Z,1569434106.426 [Default:CheckIn:D] Running Loop=1 2019-09-25T17:55:06.834Z,1569434106.834 [Default:CheckIn:D] Stopped 2019-09-25T17:55:06.834Z,1569434106.834 [Default:CheckIn:E] Running Loop=1 2019-09-25T17:55:07.249Z,1569434107.249 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 37.817537 min 2019-09-25T17:55:07.249Z,1569434107.249 [Default:CheckIn:E] Stopped 2019-09-25T17:55:07.249Z,1569434107.249 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-09-25T17:55:07.249Z,1569434107.249 [Default:CheckIn] Stopped 2019-09-25T17:55:07.250Z,1569434107.250 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-09-25T17:55:07.250Z,1569434107.250 [Default:CheckIn](INFO): Running loop #7 2019-09-25T17:55:07.250Z,1569434107.250 [Default:CheckIn] Running Loop=7 2019-09-25T17:55:07.250Z,1569434107.250 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-09-25T17:55:07.250Z,1569434107.250 [Default:CheckIn:Read_GPS] Running Loop=1 2019-09-25T17:55:08.818Z,1569434108.818 [NAL9602](DEBUG): Fix Requested 2019-09-25T17:55:09.210Z,1569434109.210 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175507.00,A,3648.20977,N,12147.16793,W,5.423,207.82,250919,,,A*7D 2019-09-25T17:55:09.223Z,1569434109.223 [NAL9602](INFO): GPS fix at 20190925T175507: (36.803496, -121.786132) 2019-09-25T17:55:09.247Z,1569434109.247 [Default:CheckIn:Read_GPS] Stopped 2019-09-25T17:55:09.247Z,1569434109.247 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-09-25T17:55:15.270Z,1569434115.270 [DVL_micro](ERROR): only read 3 of 4 data items 2019-09-25T17:55:15.270Z,1569434115.270 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+99999.99,+9999.99 2019-09-25T17:55:18.198Z,1569434118.198 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20190925T173234/Courier0012.lzma 2019-09-25T17:55:21.668Z,1569434121.668 [DataOverHttps](INFO): Moved sent file to Logs/20190925T173234/Courier0012.lzma.bak 2019-09-25T17:55:21.669Z,1569434121.669 [DataOverHttps](INFO): SBD MOMSN=11815584 2019-09-25T17:55:22.133Z,1569434122.133 [NAL9602](INFO): SBD MO Status=1, MOMSN=2058, MT Status=0, MTMSN=0 2019-09-25T17:55:22.133Z,1569434122.133 [NAL9602](INFO): No messages in MT queue 2019-09-25T17:55:40.735Z,1569434140.735 [DataOverHttps](INFO): Sending 142 bytes from file Logs/20190925T173234/Express0013.lzma 2019-09-25T17:55:42.741Z,1569434142.741 [DataOverHttps](INFO): Moved sent file to Logs/20190925T173234/Express0013.lzma.bak 2019-09-25T17:55:42.741Z,1569434142.741 [DataOverHttps](INFO): SBD MOMSN=11815587 2019-09-25T17:55:46.827Z,1569434146.827 [Default:CheckIn:Read_Iridium] Stopped 2019-09-25T17:55:46.827Z,1569434146.827 [Default:CheckIn:C.Wait] Running Loop=1 2019-09-25T17:55:46.827Z,1569434146.827 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-09-25T17:55:48.408Z,1569434148.408 [DVL_micro](ERROR): only read 3 of 4 data items 2019-09-25T17:55:48.408Z,1569434148.408 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+9999.99,+99999.99 2019-09-25T17:55:52.836Z,1569434152.836 [NAL9602](INFO): Not Powering down - fast GPS 2019-09-25T17:57:22.561Z,1569434242.561 [DVL_micro](ERROR): Failed to parse: 20,-00190,+00406,+00000,I 2019-09-25T17:57:53.310Z,1569434273.310 [DVL_micro](ERROR): DVL uart error: serial timeout 2019-09-25T17:57:53.311Z,1569434273.311 [DVL_micro] Communications Fault, FailCount= 1 2019-09-25T17:57:53.311Z,1569434273.311 [DVL_micro](ERROR): Communications Fault 2019-09-25T17:57:53.311Z,1569434273.311 [DVL_micro](ERROR): Failed to parse: 2019-09-25T17:57:53.371Z,1569434273.371 [CBIT](ERROR): Communications Fault in component: DVL_micro 2019-09-25T17:57:53.723Z,1569434273.723 [DVL_micro](INFO): Powering down 2019-09-25T17:57:54.497Z,1569434274.497 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-09-25T17:57:54.497Z,1569434274.497 [DVL_micro] No Fault, FailCount= 1 2019-09-25T17:58:00.526Z,1569434280.526 [DVL_micro](ERROR): only read 3 of 4 data items 2019-09-25T17:58:00.526Z,1569434280.526 [DVL_micro](ERROR): Failed to parse: :BI,-00133,-01743,+0000,I 2019-09-25T17:59:09.226Z,1569434349.226 [DVL_micro](ERROR): Failed to parse:99.99,+9999.99,+9999.99,+9999.99 2019-09-25T17:59:32.251Z,1569434372.251 [DVL_micro](ERROR): Failed to parse: :WI,+00356,+01525,+00264,+00000,A 2019-09-25T18:00:47.439Z,1569434447.439 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-09-25T18:00:47.439Z,1569434447.439 [Default:CheckIn:C.Wait] Stopped 2019-09-25T18:00:47.439Z,1569434447.439 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-09-25T18:00:47.439Z,1569434447.439 [Default:CheckIn:D] Running Loop=1 2019-09-25T18:00:47.839Z,1569434447.839 [Default:CheckIn:D] Stopped 2019-09-25T18:00:47.839Z,1569434447.839 [Default:CheckIn:E] Running Loop=1 2019-09-25T18:00:48.280Z,1569434448.280 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 43.500956 min 2019-09-25T18:00:48.280Z,1569434448.280 [Default:CheckIn:E] Stopped 2019-09-25T18:00:48.280Z,1569434448.280 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-09-25T18:00:48.280Z,1569434448.280 [Default:CheckIn] Stopped 2019-09-25T18:00:48.280Z,1569434448.280 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-09-25T18:00:48.280Z,1569434448.280 [Default:CheckIn](INFO): Running loop #8 2019-09-25T18:00:48.280Z,1569434448.280 [Default:CheckIn] Running Loop=8 2019-09-25T18:00:48.281Z,1569434448.281 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-09-25T18:00:48.281Z,1569434448.281 [Default:CheckIn:Read_GPS] Running Loop=1 2019-09-25T18:00:49.838Z,1569434449.838 [NAL9602](DEBUG): Fix Requested 2019-09-25T18:00:50.226Z,1569434450.226 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180048.00,A,3648.15377,N,12147.22209,W,0.894,217.52,250919,,,D*78 2019-09-25T18:00:50.228Z,1569434450.228 [NAL9602](INFO): GPS fix at 20190925T180048: (36.802563, -121.787035) 2019-09-25T18:00:50.253Z,1569434450.253 [Default:CheckIn:Read_GPS] Stopped 2019-09-25T18:00:50.253Z,1569434450.253 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-09-25T18:01:00.258Z,1569434460.258 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20190925T173234/Courier0015.lzma 2019-09-25T18:01:02.264Z,1569434462.264 [DataOverHttps](INFO): Moved sent file to Logs/20190925T173234/Courier0015.lzma.bak 2019-09-25T18:01:02.264Z,1569434462.264 [DataOverHttps](INFO): SBD MOMSN=11815615 2019-09-25T18:01:03.181Z,1569434463.181 [NAL9602](INFO): SBD MO Status=1, MOMSN=2059, MT Status=0, MTMSN=0 2019-09-25T18:01:03.181Z,1569434463.181 [NAL9602](INFO): No messages in MT queue 2019-09-25T18:01:21.834Z,1569434481.834 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20190925T173234/Express0016.lzma 2019-09-25T18:01:23.840Z,1569434483.840 [DataOverHttps](INFO): Moved sent file to Logs/20190925T173234/Express0016.lzma.bak 2019-09-25T18:01:23.840Z,1569434483.840 [DataOverHttps](INFO): SBD MOMSN=11815618 2019-09-25T18:01:27.463Z,1569434487.463 [Default:CheckIn:Read_Iridium] Stopped 2019-09-25T18:01:27.463Z,1569434487.463 [Default:CheckIn:C.Wait] Running Loop=1 2019-09-25T18:01:27.463Z,1569434487.463 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-09-25T18:01:33.884Z,1569434493.884 [NAL9602](INFO): Not Powering down - fast GPS 2019-09-25T18:02:58.338Z,1569434578.338 [DVL_micro](ERROR): only read 3 of 4 data items 2019-09-25T18:02:58.339Z,1569434578.339 [DVL_micro](ERROR): Failed to parse: :BI,-00790,+0089,+00000,I 2019-09-25T18:03:23.796Z,1569434603.796 [DVL_micro](ERROR): Failed to parse: :.99,+99999.99,+9999.99 2019-09-25T18:03:46.814Z,1569434626.814 [DVL_micro](ERROR): Failed to parse: :WI,+00092,+00146,00000,A 2019-09-25T18:04:12.270Z,1569434652.270 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2019-09-25T18:04:12.270Z,1569434652.270 [DVL_micro](ERROR): Failed to parse: :TS,000000035.0,+18.4,0000.0,1489.0,000 2019-09-25T18:05:03.183Z,1569434703.183 [DVL_micro](ERROR): Failed to parse: :WI,+01338,+01402,+00453,+00000,A 2019-09-25T18:06:28.100Z,1569434788.100 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-09-25T18:06:28.100Z,1569434788.100 [Default:CheckIn:C.Wait] Stopped 2019-09-25T18:06:28.100Z,1569434788.100 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-09-25T18:06:28.100Z,1569434788.100 [Default:CheckIn:D] Running Loop=1 2019-09-25T18:06:28.502Z,1569434788.502 [Default:CheckIn:D] Stopped 2019-09-25T18:06:28.502Z,1569434788.502 [Default:CheckIn:E] Running Loop=1 2019-09-25T18:06:28.931Z,1569434788.931 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 49.178674 min 2019-09-25T18:06:28.931Z,1569434788.931 [Default:CheckIn:E] Stopped 2019-09-25T18:06:28.931Z,1569434788.931 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-09-25T18:06:28.931Z,1569434788.931 [Default:CheckIn] Stopped 2019-09-25T18:06:28.931Z,1569434788.931 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-09-25T18:06:28.932Z,1569434788.932 [Default:CheckIn](INFO): Running loop #9 2019-09-25T18:06:28.932Z,1569434788.932 [Default:CheckIn] Running Loop=9 2019-09-25T18:06:28.932Z,1569434788.932 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-09-25T18:06:28.932Z,1569434788.932 [Default:CheckIn:Read_GPS] Running Loop=1 2019-09-25T18:06:30.463Z,1569434790.463 [NAL9602](DEBUG): Fix Requested 2019-09-25T18:06:30.858Z,1569434790.858 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180629.00,A,3648.15919,N,12147.24900,W,2.177,16.74,250919,,,D*4E 2019-09-25T18:06:30.860Z,1569434790.860 [NAL9602](INFO): GPS fix at 20190925T180629: (36.802653, -121.787483) 2019-09-25T18:06:30.926Z,1569434790.926 [Default:CheckIn:Read_GPS] Stopped 2019-09-25T18:06:30.926Z,1569434790.926 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-09-25T18:06:36.328Z,1569434796.328 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20190925T173234/Courier0018.lzma 2019-09-25T18:06:38.336Z,1569434798.336 [DataOverHttps](INFO): Moved sent file to Logs/20190925T173234/Courier0018.lzma.bak 2019-09-25T18:06:38.336Z,1569434798.336 [DataOverHttps](INFO): SBD MOMSN=11815640 2019-09-25T18:06:45.002Z,1569434805.002 [DVL_micro](ERROR): only read 2 of 4 data items 2019-09-25T18:06:45.003Z,1569434805.003 [DVL_micro](ERROR): Failed to parse: :BI,-00074,+00104+00000,I 2019-09-25T18:06:59.522Z,1569434819.522 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20190925T173234/Express0019.lzma 2019-09-25T18:07:01.528Z,1569434821.528 [DataOverHttps](INFO): Moved sent file to Logs/20190925T173234/Express0019.lzma.bak 2019-09-25T18:07:01.529Z,1569434821.529 [DataOverHttps](INFO): SBD MOMSN=11815643 2019-09-25T18:07:05.207Z,1569434825.207 [NAL9602](INFO): SBD MO Status=1, MOMSN=2060, MT Status=0, MTMSN=0 2019-09-25T18:07:05.207Z,1569434825.207 [NAL9602](INFO): No messages in MT queue 2019-09-25T18:07:05.279Z,1569434825.279 [Default:CheckIn:Read_Iridium] Stopped 2019-09-25T18:07:05.279Z,1569434825.279 [Default:CheckIn:C.Wait] Running Loop=1 2019-09-25T18:07:05.279Z,1569434825.279 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-09-25T18:07:35.898Z,1569434855.898 [NAL9602](INFO): Not Powering down - fast GPS 2019-09-25T18:09:14.920Z,1569434954.920 [DVL_micro](ERROR): Failed to parse: :WI,+01637,-00465,+00840,+00000,A 2019-09-25T18:10:15.929Z,1569435015.929 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2019-09-25T18:10:15.930Z,1569435015.930 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+19.9,0000.0,10 2019-09-25T18:11:42.379Z,1569435102.379 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2019-09-25T18:11:42.380Z,1569435102.380 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,.2,0000.0000 2019-09-25T18:12:05.866Z,1569435125.866 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-09-25T18:12:05.866Z,1569435125.866 [Default:CheckIn:C.Wait] Stopped 2019-09-25T18:12:05.866Z,1569435125.866 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-09-25T18:12:05.866Z,1569435125.866 [Default:CheckIn:D] Running Loop=1 2019-09-25T18:12:06.259Z,1569435126.259 [Default:CheckIn:D] Stopped 2019-09-25T18:12:06.259Z,1569435126.259 [Default:CheckIn:E] Running Loop=1 2019-09-25T18:12:06.674Z,1569435126.674 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 54.807951 min 2019-09-25T18:12:06.674Z,1569435126.674 [Default:CheckIn:E] Stopped 2019-09-25T18:12:06.675Z,1569435126.675 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-09-25T18:12:06.675Z,1569435126.675 [Default:CheckIn] Stopped 2019-09-25T18:12:06.675Z,1569435126.675 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-09-25T18:12:06.675Z,1569435126.675 [Default:CheckIn](INFO): Running loop #10 2019-09-25T18:12:06.675Z,1569435126.675 [Default:CheckIn] Running Loop=10 2019-09-25T18:12:06.675Z,1569435126.675 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-09-25T18:12:06.675Z,1569435126.675 [Default:CheckIn:Read_GPS] Running Loop=1 2019-09-25T18:12:08.250Z,1569435128.250 [NAL9602](DEBUG): Fix Requested 2019-09-25T18:12:08.646Z,1569435128.646 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181206.00,A,3648.16978,N,12147.28475,W,0.156,199.40,250919,,,D*71 2019-09-25T18:12:08.648Z,1569435128.648 [NAL9602](INFO): GPS fix at 20190925T181206: (36.802830, -121.788079) 2019-09-25T18:12:08.696Z,1569435128.696 [Default:CheckIn:Read_GPS] Stopped 2019-09-25T18:12:08.696Z,1569435128.696 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-09-25T18:12:18.506Z,1569435138.506 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20190925T173234/Courier0021.lzma 2019-09-25T18:12:20.512Z,1569435140.512 [DataOverHttps](INFO): Moved sent file to Logs/20190925T173234/Courier0021.lzma.bak 2019-09-25T18:12:20.512Z,1569435140.512 [DataOverHttps](INFO): SBD MOMSN=11815671 2019-09-25T18:12:43.394Z,1569435163.394 [DVL_micro](ERROR): only read 1 of 4 data items 2019-09-25T18:12:43.394Z,1569435163.394 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,,+9999.99,+9999.99 2019-09-25T18:12:47.058Z,1569435167.058 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20190925T173234/Express0022.lzma 2019-09-25T18:12:49.068Z,1569435169.068 [DataOverHttps](INFO): Moved sent file to Logs/20190925T173234/Express0022.lzma.bak 2019-09-25T18:12:49.068Z,1569435169.068 [DataOverHttps](INFO): SBD MOMSN=11815674 2019-09-25T18:12:52.732Z,1569435172.732 [Default:CheckIn:Read_Iridium] Stopped 2019-09-25T18:12:52.732Z,1569435172.732 [Default:CheckIn:C.Wait] Running Loop=1 2019-09-25T18:12:52.732Z,1569435172.732 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-09-25T18:13:14.497Z,1569435194.497 [NAL9602](INFO): SBD MO Status=2, MOMSN=2061, MT Status=2, MTMSN=0 2019-09-25T18:13:14.498Z,1569435194.498 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-09-25T18:13:46.833Z,1569435226.833 [NAL9602](INFO): SBD MO Status=2, MOMSN=2061, MT Status=2, MTMSN=0 2019-09-25T18:13:46.834Z,1569435226.834 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-09-25T18:14:12.281Z,1569435252.281 [DVL_micro](ERROR): only read 3 of 4 data items 2019-09-25T18:14:12.281Z,1569435252.281 [DVL_micro](ERROR): Failed to parse: :BI,-00295,+01428,+0124,I 2019-09-25T18:14:50.263Z,1569435290.263 [DVL_micro](ERROR): Failed to parse: 9.99,+9999.999,+9999.99 2019-09-25T18:15:08.026Z,1569435308.026 [DVL_micro](ERROR): only read 3 of 4 data items 2019-09-25T18:15:08.026Z,1569435308.026 [DVL_micro](ERROR): Failed to parse: :BI,+01093,-00670,+01213I 2019-09-25T18:15:25.799Z,1569435325.799 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2019-09-25T18:15:25.799Z,1569435325.799 [DVL_micro](ERROR): Failed to parse: :TS,000000,35.0,+20.,1489.0,000 2019-09-25T18:15:41.154Z,1569435341.154 [DVL_micro](ERROR): only read 3 of 4 data items 2019-09-25T18:15:41.154Z,1569435341.154 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+9999.99,+9999.99, 2019-09-25T18:16:16.710Z,1569435376.710 [DVL_micro](ERROR): only read 2 of 4 data items 2019-09-25T18:16:16.710Z,1569435376.710 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+9999..99,+9999.99 2019-09-25T18:16:44.591Z,1569435404.591 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2019-09-25T18:16:44.591Z,1569435404.591 [DVL_micro](ERROR): Failed to parse: :TS,000000,35.0,+0.0,1489.0I,+00201,-00064,+00930,+00000,A 2019-09-25T18:17:10.448Z,1569435430.448 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-09-25T18:17:40.352Z,1569435460.352 [DVL_micro](ERROR): Failed to parse: :SA,-01.87,-04.24,162.9 2019-09-25T18:17:41.148Z,1569435461.148 [NAL9602](INFO): Not Powering down - fast GPS 2019-09-25T18:17:53.315Z,1569435473.315 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-09-25T18:17:53.315Z,1569435473.315 [Default:CheckIn:C.Wait] Stopped 2019-09-25T18:17:53.315Z,1569435473.315 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-09-25T18:17:53.315Z,1569435473.315 [Default:CheckIn:D] Running Loop=1 2019-09-25T18:17:53.718Z,1569435473.718 [Default:CheckIn:D] Stopped 2019-09-25T18:17:53.718Z,1569435473.718 [Default:CheckIn:E] Running Loop=1 2019-09-25T18:17:54.132Z,1569435474.132 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 60.598938 min 2019-09-25T18:17:54.132Z,1569435474.132 [Default:CheckIn:E] Stopped 2019-09-25T18:17:54.132Z,1569435474.132 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-09-25T18:17:54.132Z,1569435474.132 [Default:CheckIn] Stopped 2019-09-25T18:17:54.132Z,1569435474.132 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-09-25T18:17:54.133Z,1569435474.133 [Default:CheckIn](INFO): Running loop #11 2019-09-25T18:17:54.133Z,1569435474.133 [Default:CheckIn] Running Loop=11 2019-09-25T18:17:54.133Z,1569435474.133 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-09-25T18:17:54.133Z,1569435474.133 [Default:CheckIn:Read_GPS] Running Loop=1 2019-09-25T18:17:55.710Z,1569435475.710 [NAL9602](DEBUG): Fix Requested 2019-09-25T18:17:56.102Z,1569435476.102 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181754.00,A,3648.17595,N,12147.28393,W,0.447,292.44,250919,,,A*7E 2019-09-25T18:17:56.104Z,1569435476.104 [NAL9602](INFO): GPS fix at 20190925T181754: (36.802932, -121.788066) 2019-09-25T18:17:56.129Z,1569435476.129 [Default:CheckIn:Read_GPS] Stopped 2019-09-25T18:17:56.129Z,1569435476.129 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-09-25T18:18:07.450Z,1569435487.450 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20190925T173234/Courier0024.lzma 2019-09-25T18:18:09.456Z,1569435489.456 [DataOverHttps](INFO): Moved sent file to Logs/20190925T173234/Courier0024.lzma.bak 2019-09-25T18:18:09.456Z,1569435489.456 [DataOverHttps](INFO): SBD MOMSN=11815687 2019-09-25T18:18:15.895Z,1569435495.895 [DVL_micro](ERROR): Failed to parse: :WI,+01182,+00109,+01062,+00000,A 2019-09-25T18:18:34.974Z,1569435514.974 [DataOverHttps](INFO): Sending 229 bytes from file Logs/20190925T173234/Express0025.lzma 2019-09-25T18:18:36.980Z,1569435516.980 [DataOverHttps](INFO): Moved sent file to Logs/20190925T173234/Express0025.lzma.bak 2019-09-25T18:18:36.980Z,1569435516.980 [DataOverHttps](INFO): SBD MOMSN=11815706 2019-09-25T18:18:40.610Z,1569435520.610 [Default:CheckIn:Read_Iridium] Stopped 2019-09-25T18:18:40.614Z,1569435520.614 [Default:CheckIn:C.Wait] Running Loop=1 2019-09-25T18:18:40.615Z,1569435520.615 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-09-25T18:19:24.584Z,1569435564.584 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2019-09-25T18:19:24.584Z,1569435564.584 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,.7,0000.0,14 2019-09-25T18:20:00.141Z,1569435600.141 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2019-09-25T18:20:00.142Z,1569435600.142 [DVL_micro](ERROR): Failed to parse: :TS,000000,35.0,+2.0,1489.0,000 2019-09-25T18:20:17.914Z,1569435617.914 [DVL_micro](ERROR): Failed to parse: :BD00.00,+00000000.00,+00000000.00,9999.99,000.00 2019-09-25T18:20:35.723Z,1569435635.723 [DVL_micro](ERROR): Failed to parse: :BI,-00280,+0000,+00000,I 2019-09-25T18:21:05.648Z,1569435665.648 [NAL9602](INFO): SBD MO Status=2, MOMSN=2061, MT Status=2, MTMSN=0 2019-09-25T18:21:05.648Z,1569435665.648 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-09-25T18:21:36.727Z,1569435696.727 [DVL_micro](ERROR): Failed to parse:000,35.0,+20.8,0000.0,1489.0,000 2019-09-25T18:21:46.011Z,1569435706.011 [NAL9602](INFO): SBD MO Status=2, MOMSN=2061, MT Status=2, MTMSN=0 2019-09-25T18:21:46.012Z,1569435706.012 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-09-25T18:22:58.330Z,1569435778.330 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-09-25T18:23:15.705Z,1569435795.705 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2019-09-25T18:23:15.706Z,1569435795.706 [DVL_micro](ERROR): Failed to parse: :TS0000000,39,0000.0,00 2019-09-25T18:23:29.046Z,1569435809.046 [NAL9602](INFO): Not Powering down - fast GPS 2019-09-25T18:23:41.218Z,1569435821.218 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-09-25T18:23:41.218Z,1569435821.218 [Default:CheckIn:C.Wait] Stopped 2019-09-25T18:23:41.218Z,1569435821.218 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-09-25T18:23:41.243Z,1569435821.243 [Default:CheckIn:D] Running Loop=1 2019-09-25T18:23:41.606Z,1569435821.606 [Default:CheckIn:D] Stopped 2019-09-25T18:23:41.606Z,1569435821.606 [Default:CheckIn:E] Running Loop=1 2019-09-25T18:23:42.003Z,1569435822.003 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 66.397074 min 2019-09-25T18:23:42.003Z,1569435822.003 [Default:CheckIn:E] Stopped 2019-09-25T18:23:42.003Z,1569435822.003 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-09-25T18:23:42.003Z,1569435822.003 [Default:CheckIn] Stopped 2019-09-25T18:23:42.003Z,1569435822.003 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-09-25T18:23:42.003Z,1569435822.003 [Default:CheckIn](INFO): Running loop #12 2019-09-25T18:23:42.003Z,1569435822.003 [Default:CheckIn] Running Loop=12 2019-09-25T18:23:42.004Z,1569435822.004 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-09-25T18:23:42.004Z,1569435822.004 [Default:CheckIn:Read_GPS] Running Loop=1 2019-09-25T18:23:43.602Z,1569435823.602 [NAL9602](DEBUG): Fix Requested 2019-09-25T18:23:43.990Z,1569435823.990 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182342.00,A,3648.16650,N,12147.28155,W,0.175,329.19,250919,,,A*70 2019-09-25T18:23:43.000Z,1569435824.000 [NAL9602](INFO): GPS fix at 20190925T182342: (36.802775, -121.788026) 2019-09-25T18:23:44.031Z,1569435824.031 [Default:CheckIn:Read_GPS] Stopped 2019-09-25T18:23:44.031Z,1569435824.031 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-09-25T18:23:53.910Z,1569435833.910 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20190925T173234/Courier0027.lzma 2019-09-25T18:23:55.916Z,1569435835.916 [DataOverHttps](INFO): Moved sent file to Logs/20190925T173234/Courier0027.lzma.bak 2019-09-25T18:23:55.916Z,1569435835.916 [DataOverHttps](INFO): SBD MOMSN=11815719 2019-09-25T18:24:00.176Z,1569435840.176 [CBIT](IMPORTANT): Beginning ground fault scan 2019-09-25T18:24:11.253Z,1569435851.253 [CBIT](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): 0.077178 CHAN A1 (24V): 0.317588 CHAN A2 (12V): 0.029600 CHAN A3 (5V): -0.008829 CHAN B0 (3.3V): -0.001520 CHAN B1 (3.15aV): 0.003779 CHAN B2 (3.15bV): 0.005680 CHAN B3 (GND): -0.012696 OPEN: 0.008325 Full Scale Calc: 4.765 mA, -1.589 mA 2019-09-25T18:24:14.688Z,1569435854.688 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2019-09-25T18:24:14.762Z,1569435854.762 [NAL9602](FAULT): received: +CSQ:0 OK61, 2, 0, 0, 0 OK 2019-09-25T18:24:14.763Z,1569435854.763 [NAL9602] Data Fault, FailCount= 1 2019-09-25T18:24:14.763Z,1569435854.763 [NAL9602](ERROR): Data Fault 2019-09-25T18:24:14.852Z,1569435854.852 [CBIT](ERROR): Data Fault in component: NAL9602 2019-09-25T18:24:15.092Z,1569435855.092 [NAL9602](INFO): Powering down 2019-09-25T18:24:15.947Z,1569435855.947 [CBIT](INFO): Clearing failed state for component NAL9602 2019-09-25T18:24:15.947Z,1569435855.947 [NAL9602] No Fault, FailCount= 1 2019-09-25T18:24:16.823Z,1569435856.823 [DataOverHttps](INFO): Sending 205 bytes from file Logs/20190925T173234/Express0028.lzma 2019-09-25T18:24:18.827Z,1569435858.827 [DataOverHttps](INFO): Moved sent file to Logs/20190925T173234/Express0028.lzma.bak 2019-09-25T18:24:18.827Z,1569435858.827 [DataOverHttps](INFO): SBD MOMSN=11815722 2019-09-25T18:24:22.410Z,1569435862.410 [Default:CheckIn:Read_Iridium] Stopped 2019-09-25T18:24:22.414Z,1569435862.414 [Default:CheckIn:C.Wait] Running Loop=1 2019-09-25T18:24:22.414Z,1569435862.414 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-09-25T18:24:36.922Z,1569435876.922 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2019-09-25T18:24:36.922Z,1569435876.922 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+20.9,00000,000 2019-09-25T18:24:45.401Z,1569435885.401 [NAL9602](INFO): Powering up NAL9602 2019-09-25T18:24:56.306Z,1569435896.306 [NAL9602](INFO): NAL9602 initialized 2019-09-25T18:25:14.894Z,1569435914.894 [DVL_micro](ERROR): Failed to parse: :WI,+02147,-00020,+01000,+00000,A 2019-09-25T18:25:27.446Z,1569435927.446 [NAL9602](INFO): Not Powering down - fast GPS 2019-09-25T18:25:48.025Z,1569435948.025 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2019-09-25T18:25:48.026Z,1569435948.026 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+21.0,489.0,000 2019-09-25T18:26:08.236Z,1569435968.236 [DVL_micro](ERROR): Failed to parse: :SA,-01.87,-04.13,138.2 2019-09-25T18:26:51.454Z,1569436011.454 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2019-09-25T18:26:51.462Z,1569436011.462 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+21.01489.0,000 2019-09-25T18:27:09.229Z,1569436029.229 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2019-09-25T18:27:09.230Z,1569436029.230 [DVL_micro](ERROR): Failed to parse: :TS,000000,30,0000.0,1489.0,000 2019-09-25T18:28:09.278Z,1569436089.278 [CommandLine](IMPORTANT): got command gfscan 2019-09-25T18:28:09.485Z,1569436089.485 [CBIT](IMPORTANT): Beginning ground fault scan 2019-09-25T18:28:20.387Z,1569436100.387 [CBIT](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): 0.073742 CHAN A1 (24V): 0.306945 CHAN A2 (12V): 0.024555 CHAN A3 (5V): -0.010096 CHAN B0 (3.3V): -0.001632 CHAN B1 (3.15aV): 0.002761 CHAN B2 (3.15bV): 0.005725 CHAN B3 (GND): -0.012295 OPEN: 0.008060 Full Scale Calc: 4.765 mA, -1.589 mA 2019-09-25T18:28:57.071Z,1569436137.071 [CommandLine](IMPORTANT): got command ! echo i > /dev/loadB4; gfscan 2019-09-25T18:29:05.581Z,1569436145.581 [DVL_micro](ERROR): No DVL communication! Re-initializing 2019-09-25T18:29:05.581Z,1569436145.581 [DVL_micro] Communications Fault, FailCount= 1 2019-09-25T18:29:05.581Z,1569436145.581 [DVL_micro](ERROR): Communications Fault 2019-09-25T18:29:05.675Z,1569436145.675 [CBIT](ERROR): Communications Fault in component: DVL_micro 2019-09-25T18:29:06.051Z,1569436146.051 [DVL_micro](INFO): Powering down 2019-09-25T18:29:06.186Z,1569436146.186 [CommandLine](IMPORTANT): got command gfscan 2019-09-25T18:29:06.432Z,1569436146.432 [CBIT](IMPORTANT): Beginning ground fault scan 2019-09-25T18:29:06.820Z,1569436146.820 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-09-25T18:29:06.821Z,1569436146.821 [DVL_micro] No Fault, FailCount= 1 2019-09-25T18:29:17.333Z,1569436157.333 [CBIT](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): 0.085768 CHAN A1 (24V): 0.301519 CHAN A2 (12V): 0.023176 CHAN A3 (5V): -0.011277 CHAN B0 (3.3V): -0.002467 CHAN B1 (3.15aV): 0.001399 CHAN B2 (3.15bV): 0.004616 CHAN B3 (GND): -0.012760 OPEN: 0.007240 Full Scale Calc: 4.765 mA, -1.589 mA 2019-09-25T18:29:20.529Z,1569436160.529 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2019-09-25T18:29:20.530Z,1569436160.530 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+21.1,009.0,000 2019-09-25T18:29:23.040Z,1569436163.040 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-09-25T18:29:23.041Z,1569436163.041 [Default:CheckIn:C.Wait] Stopped 2019-09-25T18:29:23.041Z,1569436163.041 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-09-25T18:29:23.041Z,1569436163.041 [Default:CheckIn:D] Running Loop=1 2019-09-25T18:29:23.414Z,1569436163.414 [Default:CheckIn:D] Stopped 2019-09-25T18:29:23.414Z,1569436163.414 [Default:CheckIn:E] Running Loop=1 2019-09-25T18:29:23.800Z,1569436163.800 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 72.093872 min 2019-09-25T18:29:23.800Z,1569436163.800 [Default:CheckIn:E] Stopped 2019-09-25T18:29:23.800Z,1569436163.800 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-09-25T18:29:23.800Z,1569436163.800 [Default:CheckIn] Stopped 2019-09-25T18:29:23.800Z,1569436163.800 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-09-25T18:29:23.800Z,1569436163.800 [Default:CheckIn](INFO): Running loop #13 2019-09-25T18:29:23.800Z,1569436163.800 [Default:CheckIn] Running Loop=13 2019-09-25T18:29:23.800Z,1569436163.800 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-09-25T18:29:23.801Z,1569436163.801 [Default:CheckIn:Read_GPS] Running Loop=1 2019-09-25T18:29:25.414Z,1569436165.414 [NAL9602](DEBUG): Fix Requested 2019-09-25T18:29:28.204Z,1569436168.204 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-09-25T18:29:29.026Z,1569436169.026 [NAL9602](DEBUG): Fix Requested 2019-09-25T18:29:31.442Z,1569436171.442 [NAL9602](DEBUG): Fix Requested 2019-09-25T18:29:34.678Z,1569436174.678 [NAL9602](DEBUG): Fix Requested 2019-09-25T18:29:37.510Z,1569436177.510 [NAL9602](DEBUG): Fix Requested 2019-09-25T18:29:40.332Z,1569436180.332 [NAL9602](DEBUG): Fix Requested 2019-09-25T18:29:43.562Z,1569436183.562 [NAL9602](DEBUG): Fix Requested 2019-09-25T18:29:46.394Z,1569436186.394 [NAL9602](DEBUG): Fix Requested 2019-09-25T18:29:49.630Z,1569436189.630 [NAL9602](DEBUG): Fix Requested 2019-09-25T18:29:52.454Z,1569436192.454 [NAL9602](DEBUG): Fix Requested 2019-09-25T18:29:55.698Z,1569436195.698 [NAL9602](DEBUG): Fix Requested 2019-09-25T18:29:58.530Z,1569436198.530 [NAL9602](DEBUG): Fix Requested 2019-09-25T18:30:01.350Z,1569436201.350 [NAL9602](DEBUG): Fix Requested 2019-09-25T18:30:04.570Z,1569436204.570 [NAL9602](DEBUG): Fix Requested 2019-09-25T18:30:07.406Z,1569436207.406 [NAL9602](DEBUG): Fix Requested 2019-09-25T18:30:10.634Z,1569436210.634 [NAL9602](DEBUG): Fix Requested 2019-09-25T18:30:13.467Z,1569436213.467 [NAL9602](DEBUG): Fix Requested 2019-09-25T18:30:16.694Z,1569436216.694 [NAL9602](DEBUG): Fix Requested 2019-09-25T18:30:19.530Z,1569436219.530 [NAL9602](DEBUG): Fix Requested 2019-09-25T18:30:22.359Z,1569436222.359 [NAL9602](DEBUG): Fix Requested 2019-09-25T18:30:25.594Z,1569436225.594 [NAL9602](DEBUG): Fix Requested 2019-09-25T18:30:28.431Z,1569436228.431 [NAL9602](DEBUG): Fix Requested 2019-09-25T18:30:31.658Z,1569436231.658 [NAL9602](DEBUG): Fix Requested 2019-09-25T18:30:34.490Z,1569436234.490 [NAL9602](DEBUG): Fix Requested 2019-09-25T18:30:37.722Z,1569436237.722 [NAL9602](DEBUG): Fix Requested 2019-09-25T18:30:40.546Z,1569436240.546 [NAL9602](DEBUG): Fix Requested 2019-09-25T18:30:43.378Z,1569436243.378 [NAL9602](DEBUG): Fix Requested 2019-09-25T18:30:46.626Z,1569436246.626 [NAL9602](DEBUG): Fix Requested 2019-09-25T18:30:49.434Z,1569436249.434 [NAL9602](DEBUG): Fix Requested 2019-09-25T18:30:52.670Z,1569436252.670 [NAL9602](DEBUG): Fix Requested 2019-09-25T18:30:55.505Z,1569436255.505 [NAL9602](DEBUG): Fix Requested 2019-09-25T18:30:58.330Z,1569436258.330 [NAL9602](DEBUG): Fix Requested 2019-09-25T18:30:59.529Z,1569436259.529 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2019-09-25T18:30:59.529Z,1569436259.529 [DVL_micro](ERROR): Failed to parse: :TS0000000,35,0000.0,00 2019-09-25T18:31:01.558Z,1569436261.558 [NAL9602](DEBUG): Fix Requested 2019-09-25T18:31:04.394Z,1569436264.394 [NAL9602](DEBUG): Fix Requested 2019-09-25T18:31:07.618Z,1569436267.618 [NAL9602](DEBUG): Fix Requested 2019-09-25T18:31:10.446Z,1569436270.446 [NAL9602](DEBUG): Fix Requested 2019-09-25T18:31:13.674Z,1569436273.674 [NAL9602](DEBUG): Fix Requested 2019-09-25T18:31:16.506Z,1569436276.506 [NAL9602](DEBUG): Fix Requested 2019-09-25T18:31:19.335Z,1569436279.335 [NAL9602](DEBUG): Fix Requested 2019-09-25T18:31:22.570Z,1569436282.570 [NAL9602](DEBUG): Fix Requested 2019-09-25T18:31:25.398Z,1569436285.398 [NAL9602](DEBUG): Fix Requested 2019-09-25T18:31:28.630Z,1569436288.630 [NAL9602](DEBUG): Fix Requested 2019-09-25T18:31:31.454Z,1569436291.454 [NAL9602](DEBUG): Fix Requested 2019-09-25T18:31:34.690Z,1569436294.690 [NAL9602](DEBUG): Fix Requested 2019-09-25T18:31:35.082Z,1569436295.082 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2019-09-25T18:31:35.082Z,1569436295.082 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+21.1,0000.0,10 2019-09-25T18:31:35.085Z,1569436295.085 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183132.00,A,3648.15964,N,12147.29312,W,2.702,203.02,250919,,,A*78 2019-09-25T18:31:35.087Z,1569436295.087 [NAL9602](INFO): GPS fix at 20190925T183132: (36.802661, -121.788219) 2019-09-25T18:31:35.112Z,1569436295.112 [Default:CheckIn:Read_GPS] Stopped 2019-09-25T18:31:35.112Z,1569436295.112 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-09-25T18:31:44.030Z,1569436304.030 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20190925T173234/Courier0030.lzma 2019-09-25T18:31:46.036Z,1569436306.036 [DataOverHttps](INFO): Moved sent file to Logs/20190925T173234/Courier0030.lzma.bak 2019-09-25T18:31:46.036Z,1569436306.036 [DataOverHttps](INFO): SBD MOMSN=11815760 2019-09-25T18:32:05.743Z,1569436325.743 [DataOverHttps](INFO): Sending 608 bytes from file Logs/20190925T173234/Express0031.lzma 2019-09-25T18:32:07.396Z,1569436327.396 [NAL9602](INFO): Not Powering down - fast GPS 2019-09-25T18:32:07.748Z,1569436327.748 [DataOverHttps](INFO): Moved sent file to Logs/20190925T173234/Express0031.lzma.bak 2019-09-25T18:32:07.748Z,1569436327.748 [DataOverHttps](INFO): SBD MOMSN=11815763 2019-09-25T18:32:10.634Z,1569436330.634 [DVL_micro](ERROR): only read 3 of 4 data items 2019-09-25T18:32:10.634Z,1569436330.634 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+99999.99,+9999.99 2019-09-25T18:32:13.091Z,1569436333.091 [Default:CheckIn:Read_Iridium] Stopped 2019-09-25T18:32:13.091Z,1569436333.091 [Default:CheckIn:C.Wait] Running Loop=1 2019-09-25T18:32:13.091Z,1569436333.091 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-09-25T18:34:42.836Z,1569436482.836 [CommandLine](IMPORTANT): got command quit 2019-09-25T18:34:43.843Z,1569436483.843 [Supervisor](INFO): Stop Mission called by Supervisor::terminate 2019-09-25T18:34:43.843Z,1569436483.843 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2019-09-25T18:34:43.844Z,1569436483.844 [CommandLine ThreadHandler](INFO): Thread cancelled. 2019-09-25T18:34:43.962Z,1569436483.962 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2019-09-25T18:34:43.963Z,1569436483.963 [CommandLine ThreadHandler](INFO): Thread cancelled. 2019-09-25T18:34:43.963Z,1569436483.963 [CommandLine](INFO): Join timeout helper Thread ID is 2534 2019-09-25T18:34:43.964Z,1569436483.964 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2019-09-25T18:34:43.964Z,1569436483.964 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2019-09-25T18:34:43.964Z,1569436483.964 [NavChartDb](INFO): Join timeout helper Thread ID is 2535 2019-09-25T18:34:44.363Z,1569436484.363 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2019-09-25T18:34:44.363Z,1569436484.363 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2019-09-25T18:34:44.366Z,1569436484.366 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2019-09-25T18:34:44.366Z,1569436484.366 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2019-09-25T18:34:44.367Z,1569436484.367 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 2536 2019-09-25T18:34:44.627Z,1569436484.627 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2019-09-25T18:34:44.627Z,1569436484.627 [WetLabsBB2FL](INFO): Powering down 2019-09-25T18:34:44.628Z,1569436484.628 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2019-09-25T18:34:44.638Z,1569436484.638 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2019-09-25T18:34:44.639Z,1569436484.639 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2019-09-25T18:34:44.639Z,1569436484.639 [CTD_Seabird](INFO): Join timeout helper Thread ID is 2537 2019-09-25T18:34:45.423Z,1569436485.423 [CTD_Seabird](INFO): Powering down 2019-09-25T18:34:45.434Z,1569436485.434 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread. 2019-09-25T18:34:45.435Z,1569436485.435 [CTD_Seabird](INFO): Powering down 2019-09-25T18:34:45.447Z,1569436485.447 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2019-09-25T18:34:45.459Z,1569436485.459 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2019-09-25T18:34:45.459Z,1569436485.459 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2019-09-25T18:34:45.459Z,1569436485.459 [Radio_Surface](INFO): Join timeout helper Thread ID is 2538 2019-09-25T18:34:45.646Z,1569436485.646 [Radio_Surface](INFO): Powering down 2019-09-25T18:34:45.647Z,1569436485.647 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2019-09-25T18:34:45.648Z,1569436485.648 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2019-09-25T18:34:45.655Z,1569436485.655 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2019-09-25T18:34:45.655Z,1569436485.655 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2019-09-25T18:34:45.656Z,1569436485.656 [DataOverHttps](INFO): Join timeout helper Thread ID is 2539 2019-09-25T18:34:46.591Z,1569436486.591 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2019-09-25T18:34:46.592Z,1569436486.592 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2019-09-25T18:34:46.607Z,1569436486.607 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2019-09-25T18:34:46.607Z,1569436486.607 [logger ThreadHandler](INFO): Thread cancelled. 2019-09-25T18:34:46.608Z,1569436486.608 [logger](INFO): Join timeout helper Thread ID is 2540 2019-09-25T18:34:46.608Z,1569436486.608 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2019-09-25T18:34:46.608Z,1569436486.608 [logger ThreadHandler](INFO): Thread cancelled. 2019-09-25T18:34:46.610Z,1569436486.610 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2019-09-25T18:34:46.610Z,1569436486.610 [CommandLine ThreadHandler](INFO): Thread cancelled. 2019-09-25T18:34:46.610Z,1569436486.610 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2019-09-25T18:34:46.610Z,1569436486.610 [controlThread ThreadHandler](INFO): Thread cancelled. 2019-09-25T18:34:46.611Z,1569436486.611 [controlThread](INFO): Join timeout helper Thread ID is 2541 2019-09-25T18:34:46.632Z,1569436486.632 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2019-09-25T18:34:46.632Z,1569436486.632 [controlThread](DEBUG): Uninitializing ControlThread 2019-09-25T18:34:46.632Z,1569436486.632 [AHRS_M2](INFO): Powering down 2019-09-25T18:34:46.775Z,1569436486.775 [DVL_micro](INFO): Powering down 2019-09-25T18:34:46.776Z,1569436486.776 [NAL9602](INFO): Powering down 2019-09-25T18:34:46.777Z,1569436486.777 [DAT](INFO): Powering down 2019-09-25T18:34:46.895Z,1569436486.895 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2019-09-25T18:34:46.896Z,1569436486.896 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2019-09-25T18:34:46.897Z,1569436486.897 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2019-09-25T18:34:46.897Z,1569436486.897 [MissionManager](INFO): Uninitializing Mission Default 2019-09-25T18:34:46.897Z,1569436486.897 [Default] Stopped 2019-09-25T18:34:46.898Z,1569436486.898 [Default](DEBUG): Aggregate::uninitialize Default 2019-09-25T18:34:46.898Z,1569436486.898 [Default:B.GoToSurface] Stopped 2019-09-25T18:34:46.898Z,1569436486.898 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2019-09-25T18:34:46.898Z,1569436486.898 [Default:CheckIn] Stopped 2019-09-25T18:34:46.898Z,1569436486.898 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-09-25T18:34:46.898Z,1569436486.898 [Default:CheckIn:C.Wait] Stopped 2019-09-25T18:34:46.898Z,1569436486.898 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-09-25T18:34:46.900Z,1569436486.900 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2019-09-25T18:34:46.901Z,1569436486.901 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2019-09-25T18:34:46.901Z,1569436486.901 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2019-09-25T18:34:46.901Z,1569436486.901 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2019-09-25T18:34:46.902Z,1569436486.902 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2019-09-25T18:34:46.902Z,1569436486.902 [BuoyancyServo](INFO): Powering down 2019-09-25T18:34:46.914Z,1569436486.914 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2019-09-25T18:34:46.915Z,1569436486.915 [ElevatorServo](INFO): Powering down 2019-09-25T18:34:46.915Z,1569436486.915 [MassServo](DEBUG): Uninitialize Mass Servo. 2019-09-25T18:34:46.916Z,1569436486.916 [MassServo](INFO): Powering down 2019-09-25T18:34:46.916Z,1569436486.916 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2019-09-25T18:34:46.916Z,1569436486.916 [RudderServo](INFO): Powering down 2019-09-25T18:34:46.917Z,1569436486.917 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2019-09-25T18:34:46.917Z,1569436486.917 [ThrusterServo](INFO): Powering down 2019-09-25T18:34:46.918Z,1569436486.918 [SBIT](DEBUG): Uninitialize SBIT Component. 2019-09-25T18:34:46.918Z,1569436486.918 [IBIT](DEBUG): Uninitialize IBIT Component. 2019-09-25T18:34:46.919Z,1569436486.919 [CBIT](DEBUG): Uninitialize CBIT Component. 2019-09-25T18:34:46.919Z,1569436486.919 [CBIT](DEBUG): Powering off loads. 2019-09-25T18:34:46.930Z,1569436486.930 [CBIT](DEBUG): Disabling WDT. 2019-09-25T18:34:46.942Z,1569436486.942 [CBIT](DEBUG): Opening all GF detection circuits. 2019-09-25T18:34:46.943Z,1569436486.943 [controlThread ThreadHandler](INFO): Thread cancelled. 2019-09-25T18:34:47.028Z,1569436487.028 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2019-09-25T18:34:47.036Z,1569436487.036 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2019-09-25T18:34:47.081Z,1569436487.081 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2019-09-25T18:34:47.083Z,1569436487.083 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2019-09-25T18:34:47.117Z,1569436487.117 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2019-09-25T18:34:47.201Z,1569436487.201 [logger ThreadHandler](INFO): Thread cancelled.