2019-11-26T18:56:25.517Z,1574794585.517 [CommandLine](IMPORTANT): got command restart logs 2019-11-26T18:56:27.426Z,1574794587.426 [DataOverHttps](INFO): Moved sent file to Logs/20191126T181924/Courier0018.lzma.bak 2019-11-26T18:56:27.426Z,1574794587.426 [DataOverHttps](INFO): SBD MOMSN=12107478 2019-11-26T18:56:49.496Z,1574794609.496 [NAL9602](INFO): SBD MO Status=2, MOMSN=10054, MT Status=2, MTMSN=0 2019-11-26T18:56:49.496Z,1574794609.496 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-11-26T18:57:08.484Z,1574794628.484 [NAL9602](INFO): SBD MO Status=2, MOMSN=10054, MT Status=2, MTMSN=0 2019-11-26T18:57:08.484Z,1574794628.484 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-11-26T18:57:25.051Z,1574794645.051 [NAL9602](INFO): SBD MO Status=0, MOMSN=10054, MT Status=0, MTMSN=0 2019-11-26T18:57:25.051Z,1574794645.051 [NAL9602](INFO): No messages in MT queue 2019-11-26T18:57:27.506Z,1574794647.506 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.079666 2019-11-26T18:57:41.634Z,1574794661.634 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2019-11-26T18:57:41.634Z,1574794661.634 [RDI_Pathfinder](ERROR): Failed to parse: :TS,191126125.0, -0.1, 0.0,1448.9, 0 2019-11-26T18:57:55.751Z,1574794675.751 [NAL9602](INFO): Not Powering down - fast GPS 2019-11-26T18:57:58.641Z,1574794678.641 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-11-26T18:58:33.797Z,1574794713.797 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-11-26T18:59:07.272Z,1574794747.272 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2019-11-26T18:59:07.272Z,1574794747.272 [RDI_Pathfinder](ERROR): Failed to parse: :TS,19112612110726,35.0, 0.0,1448.9, 0 2019-11-26T18:59:23.725Z,1574794763.725 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003197 2019-11-26T18:59:31.437Z,1574794771.437 [DataOverHttps](INFO): Sending 493 bytes from file Logs/20191126T181924/Express0019.lzma 2019-11-26T18:59:33.442Z,1574794773.442 [DataOverHttps](INFO): Moved sent file to Logs/20191126T181924/Express0019.lzma.bak 2019-11-26T18:59:33.442Z,1574794773.442 [DataOverHttps](INFO): SBD MOMSN=12107483 2019-11-26T18:59:52.012Z,1574794792.012 [DataOverHttps](INFO): Sending 157 bytes from file Logs/20191126T181924/Express0022.lzma 2019-11-26T18:59:54.019Z,1574794794.019 [DataOverHttps](INFO): Moved sent file to Logs/20191126T181924/Express0022.lzma.bak 2019-11-26T18:59:54.019Z,1574794794.019 [DataOverHttps](INFO): SBD MOMSN=12107487 2019-11-26T18:59:56.196Z,1574794796.196 [Default:CheckIn:Read_Iridium] Stopped 2019-11-26T18:59:56.196Z,1574794796.196 [Default:CheckIn:C.Wait] Running Loop=1 2019-11-26T18:59:56.196Z,1574794796.196 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-11-26T19:00:07.926Z,1574794807.926 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2019-11-26T19:00:07.926Z,1574794807.926 [RDI_Pathfinder](ERROR): Failed to parse: :TS,19112612120826,35.0, -0.1, 0., 0 2019-11-26T19:01:08.085Z,1574794868.085 [RDI_Pathfinder](ERROR): DVL BIT error. See manual. Result code: 2651 2019-11-26T19:01:08.087Z,1574794868.087 [RDI_Pathfinder](ERROR): Failed to parse: :SA, +0.00, +0.00, 0.00 2019-11-26T19:02:26.901Z,1574794946.901 [RDI_Pathfinder](ERROR): only read 2 of 4 data items 2019-11-26T19:02:26.901Z,1574794946.901 [RDI_Pathfinder](ERROR): Failed to parse: :BS,-3278,-32768,V 2019-11-26T19:04:56.777Z,1574795096.777 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-11-26T19:04:56.777Z,1574795096.777 [Default:CheckIn:C.Wait] Stopped 2019-11-26T19:04:56.777Z,1574795096.777 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-11-26T19:04:56.777Z,1574795096.777 [Default:CheckIn:D] Running Loop=1 2019-11-26T19:04:57.201Z,1574795097.201 [Default:CheckIn:D] Stopped 2019-11-26T19:04:57.201Z,1574795097.201 [Default:CheckIn:E] Running Loop=1 2019-11-26T19:04:57.584Z,1574795097.584 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 46.619633 min 2019-11-26T19:04:57.584Z,1574795097.584 [Default:CheckIn:E] Stopped 2019-11-26T19:04:57.584Z,1574795097.584 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-11-26T19:04:57.585Z,1574795097.585 [Default:CheckIn] Stopped 2019-11-26T19:04:57.585Z,1574795097.585 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-11-26T19:04:57.585Z,1574795097.585 [Default:CheckIn](INFO): Running loop #8 2019-11-26T19:04:57.585Z,1574795097.585 [Default:CheckIn] Running Loop=8 2019-11-26T19:04:57.585Z,1574795097.585 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-11-26T19:04:57.585Z,1574795097.585 [Default:CheckIn:Read_GPS] Running Loop=1 2019-11-26T19:04:59.569Z,1574795099.569 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190452.00,A,3648.40291,N,12147.44421,W,6.551,54.71,261119,,,A*4A 2019-11-26T19:04:59.571Z,1574795099.571 [NAL9602](INFO): GPS fix at 20191126T190452: (36.806715, -121.790737) 2019-11-26T19:04:59.613Z,1574795099.613 [Default:CheckIn:Read_GPS] Stopped 2019-11-26T19:04:59.613Z,1574795099.613 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-11-26T19:05:07.264Z,1574795107.264 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2019-11-26T19:05:07.264Z,1574795107.264 [RDI_Pathfinder](ERROR): Failed to parse: :TS,19112612170726,35, 0.0,1448.9, 0 2019-11-26T19:05:07.617Z,1574795107.617 [DataOverHttps](INFO): Sending 212 bytes from file Logs/20191126T185625/Courier0003.lzma 2019-11-26T19:05:09.622Z,1574795109.622 [DataOverHttps](INFO): Moved sent file to Logs/20191126T185625/Courier0003.lzma.bak 2019-11-26T19:05:09.622Z,1574795109.622 [DataOverHttps](INFO): SBD MOMSN=12107490 2019-11-26T19:05:15.320Z,1574795115.320 [NAL9602](INFO): SBD MO Status=0, MOMSN=10055, MT Status=0, MTMSN=0 2019-11-26T19:05:15.320Z,1574795115.320 [NAL9602](INFO): No messages in MT queue 2019-11-26T19:05:27.098Z,1574795127.098 [DataOverHttps](INFO): Sending 823 bytes from file Logs/20191126T185625/Express0004.lzma 2019-11-26T19:05:29.102Z,1574795129.102 [DataOverHttps](INFO): Moved sent file to Logs/20191126T185625/Express0004.lzma.bak 2019-11-26T19:05:29.103Z,1574795129.103 [DataOverHttps](INFO): SBD MOMSN=12107494 2019-11-26T19:05:31.113Z,1574795131.113 [Default:CheckIn:Read_Iridium] Stopped 2019-11-26T19:05:31.114Z,1574795131.114 [Default:CheckIn:C.Wait] Running Loop=1 2019-11-26T19:05:31.121Z,1574795131.121 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-11-26T19:05:46.027Z,1574795146.027 [NAL9602](INFO): Not Powering down - fast GPS 2019-11-26T19:07:08.071Z,1574795228.071 [RDI_Pathfinder](ERROR): only read -1 of 1 data item for BIT error 2019-11-26T19:07:08.071Z,1574795228.071 [RDI_Pathfinder](ERROR): Failed to parse: :TS,19112612190726,35.0, -0.1, 2019-11-26T19:10:31.721Z,1574795431.721 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-11-26T19:10:31.721Z,1574795431.721 [Default:CheckIn:C.Wait] Stopped 2019-11-26T19:10:31.721Z,1574795431.721 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-11-26T19:10:31.721Z,1574795431.721 [Default:CheckIn:D] Running Loop=1 2019-11-26T19:10:32.125Z,1574795432.125 [Default:CheckIn:D] Stopped 2019-11-26T19:10:32.125Z,1574795432.125 [Default:CheckIn:E] Running Loop=1 2019-11-26T19:10:32.560Z,1574795432.560 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 52.202043 min 2019-11-26T19:10:32.560Z,1574795432.560 [Default:CheckIn:E] Stopped 2019-11-26T19:10:32.560Z,1574795432.560 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-11-26T19:10:32.560Z,1574795432.560 [Default:CheckIn] Stopped 2019-11-26T19:10:32.561Z,1574795432.561 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-11-26T19:10:32.561Z,1574795432.561 [Default:CheckIn](INFO): Running loop #9 2019-11-26T19:10:32.561Z,1574795432.561 [Default:CheckIn] Running Loop=9 2019-11-26T19:10:32.561Z,1574795432.561 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-11-26T19:10:32.561Z,1574795432.561 [Default:CheckIn:Read_GPS] Running Loop=1 2019-11-26T19:10:34.612Z,1574795434.612 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191027.00,A,3648.18941,N,12147.17300,W,4.276,193.34,261119,,,D*7A 2019-11-26T19:10:34.641Z,1574795434.641 [NAL9602](INFO): GPS fix at 20191126T191027: (36.803157, -121.786217) 2019-11-26T19:10:34.765Z,1574795434.765 [Default:CheckIn:Read_GPS] Stopped 2019-11-26T19:10:34.766Z,1574795434.766 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-11-26T19:10:43.492Z,1574795443.492 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20191126T185625/Courier0006.lzma 2019-11-26T19:10:45.498Z,1574795445.498 [DataOverHttps](INFO): Moved sent file to Logs/20191126T185625/Courier0006.lzma.bak 2019-11-26T19:10:45.498Z,1574795445.498 [DataOverHttps](INFO): SBD MOMSN=12107500 2019-11-26T19:10:48.360Z,1574795448.360 [NAL9602](INFO): SBD MO Status=0, MOMSN=10056, MT Status=0, MTMSN=0 2019-11-26T19:10:48.360Z,1574795448.360 [NAL9602](INFO): No messages in MT queue 2019-11-26T19:11:04.161Z,1574795464.161 [DataOverHttps](INFO): Sending 249 bytes from file Logs/20191126T185625/Express0007.lzma 2019-11-26T19:11:06.166Z,1574795466.166 [DataOverHttps](INFO): Moved sent file to Logs/20191126T185625/Express0007.lzma.bak 2019-11-26T19:11:06.167Z,1574795466.167 [DataOverHttps](INFO): SBD MOMSN=12107503 2019-11-26T19:11:08.244Z,1574795468.244 [Default:CheckIn:Read_Iridium] Stopped 2019-11-26T19:11:08.244Z,1574795468.244 [Default:CheckIn:C.Wait] Running Loop=1 2019-11-26T19:11:08.244Z,1574795468.244 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-11-26T19:11:19.067Z,1574795479.067 [NAL9602](INFO): Not Powering down - fast GPS 2019-11-26T19:12:32.619Z,1574795552.619 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2019-11-26T19:12:32.619Z,1574795552.619 [RDI_Pathfinder](ERROR): Failed to parse: :TS,19112612243226,35.0, -0.1, 09, 0 2019-11-26T19:14:57.278Z,1574795697.278 [RDI_Pathfinder](ERROR): only read 2 of 4 data items 2019-11-26T19:14:57.278Z,1574795697.278 [RDI_Pathfinder](ERROR): Failed to parse: :BS,-3268,-32768,V 2019-11-26T19:16:08.898Z,1574795768.898 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-11-26T19:16:08.899Z,1574795768.899 [Default:CheckIn:C.Wait] Stopped 2019-11-26T19:16:08.899Z,1574795768.899 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-11-26T19:16:08.899Z,1574795768.899 [Default:CheckIn:D] Running Loop=1 2019-11-26T19:16:09.267Z,1574795769.267 [Default:CheckIn:D] Stopped 2019-11-26T19:16:09.267Z,1574795769.267 [Default:CheckIn:E] Running Loop=1 2019-11-26T19:16:09.650Z,1574795769.650 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 57.821073 min 2019-11-26T19:16:09.650Z,1574795769.650 [Default:CheckIn:E] Stopped 2019-11-26T19:16:09.650Z,1574795769.650 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-11-26T19:16:09.650Z,1574795769.650 [Default:CheckIn] Stopped 2019-11-26T19:16:09.650Z,1574795769.650 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-11-26T19:16:09.650Z,1574795769.650 [Default:CheckIn](INFO): Running loop #10 2019-11-26T19:16:09.650Z,1574795769.650 [Default:CheckIn] Running Loop=10 2019-11-26T19:16:09.651Z,1574795769.651 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-11-26T19:16:09.651Z,1574795769.651 [Default:CheckIn:Read_GPS] Running Loop=1 2019-11-26T19:16:11.672Z,1574795771.672 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191604.00,A,3648.13673,N,12147.20598,W,0.039,328.66,261119,,,D*73 2019-11-26T19:16:11.682Z,1574795771.682 [NAL9602](INFO): GPS fix at 20191126T191604: (36.802279, -121.786766) 2019-11-26T19:16:11.798Z,1574795771.798 [Default:CheckIn:Read_GPS] Stopped 2019-11-26T19:16:11.798Z,1574795771.798 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-11-26T19:16:14.201Z,1574795774.201 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20191126T185625/Courier0009.lzma 2019-11-26T19:16:15.682Z,1574795775.682 [DataOverHttps](INFO): Moved sent file to Logs/20191126T185625/Courier0009.lzma.bak 2019-11-26T19:16:15.682Z,1574795775.682 [DataOverHttps](INFO): SBD MOMSN=12107508 2019-11-26T19:16:34.537Z,1574795794.537 [DataOverHttps](INFO): Sending 231 bytes from file Logs/20191126T185625/Express0010.lzma 2019-11-26T19:16:36.542Z,1574795796.542 [DataOverHttps](INFO): Moved sent file to Logs/20191126T185625/Express0010.lzma.bak 2019-11-26T19:16:36.543Z,1574795796.543 [DataOverHttps](INFO): SBD MOMSN=12107511 2019-11-26T19:16:38.614Z,1574795798.614 [Default:CheckIn:Read_Iridium] Stopped 2019-11-26T19:16:38.614Z,1574795798.614 [Default:CheckIn:C.Wait] Running Loop=1 2019-11-26T19:16:38.615Z,1574795798.615 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-11-26T19:18:35.704Z,1574795915.704 [NAL9602](INFO): SBD MO Status=2, MOMSN=10057, MT Status=2, MTMSN=0 2019-11-26T19:18:35.705Z,1574795915.705 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-11-26T19:18:51.464Z,1574795931.464 [NAL9602](INFO): SBD MO Status=2, MOMSN=10057, MT Status=2, MTMSN=0 2019-11-26T19:18:51.464Z,1574795931.464 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-11-26T19:19:07.624Z,1574795947.624 [NAL9602](INFO): SBD MO Status=0, MOMSN=10057, MT Status=0, MTMSN=0 2019-11-26T19:19:07.624Z,1574795947.624 [NAL9602](INFO): No messages in MT queue 2019-11-26T19:19:12.926Z,1574795952.926 [RDI_Pathfinder](ERROR): only read 3 of 4 data items 2019-11-26T19:19:12.926Z,1574795952.926 [RDI_Pathfinder](ERROR): Failed to parse: :BS,-32768,-32768,-32768-32768,-32768,-32768,V 2019-11-26T19:19:38.335Z,1574795978.335 [NAL9602](INFO): Not Powering down - fast GPS 2019-11-26T19:20:55.601Z,1574796055.601 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2019-11-26T19:20:55.603Z,1574796055.603 [BPC1](INFO): Received data from all battery sticks. 2019-11-26T19:21:39.239Z,1574796099.239 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-11-26T19:21:39.239Z,1574796099.239 [Default:CheckIn:C.Wait] Stopped 2019-11-26T19:21:39.239Z,1574796099.239 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-11-26T19:21:39.240Z,1574796099.240 [Default:CheckIn:D] Running Loop=1 2019-11-26T19:21:39.625Z,1574796099.625 [Default:CheckIn:D] Stopped 2019-11-26T19:21:39.626Z,1574796099.626 [Default:CheckIn:E] Running Loop=1 2019-11-26T19:21:40.066Z,1574796100.066 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 63.327047 min 2019-11-26T19:21:40.067Z,1574796100.067 [Default:CheckIn:E] Stopped 2019-11-26T19:21:40.067Z,1574796100.067 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-11-26T19:21:40.067Z,1574796100.067 [Default:CheckIn] Stopped 2019-11-26T19:21:40.067Z,1574796100.067 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-11-26T19:21:40.067Z,1574796100.067 [Default:CheckIn](INFO): Running loop #11 2019-11-26T19:21:40.067Z,1574796100.067 [Default:CheckIn] Running Loop=11 2019-11-26T19:21:40.067Z,1574796100.067 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-11-26T19:21:40.067Z,1574796100.067 [Default:CheckIn:Read_GPS] Running Loop=1 2019-11-26T19:21:42.019Z,1574796102.019 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,192134.00,A,3648.13590,N,12147.21164,W,0.097,297.80,261119,,,D*75 2019-11-26T19:21:42.021Z,1574796102.021 [NAL9602](INFO): GPS fix at 20191126T192134: (36.802265, -121.786861) 2019-11-26T19:21:42.065Z,1574796102.065 [Default:CheckIn:Read_GPS] Stopped 2019-11-26T19:21:42.065Z,1574796102.065 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-11-26T19:21:50.125Z,1574796110.125 [DataOverHttps](INFO): Sending 222 bytes from file Logs/20191126T185625/Courier0012.lzma 2019-11-26T19:21:52.131Z,1574796112.131 [DataOverHttps](INFO): Moved sent file to Logs/20191126T185625/Courier0012.lzma.bak 2019-11-26T19:21:52.131Z,1574796112.131 [DataOverHttps](INFO): SBD MOMSN=12107516 2019-11-26T19:21:56.200Z,1574796116.200 [NAL9602](INFO): SBD MO Status=0, MOMSN=10058, MT Status=0, MTMSN=0 2019-11-26T19:21:56.201Z,1574796116.201 [NAL9602](INFO): No messages in MT queue 2019-11-26T19:21:57.008Z,1574796117.008 [RDI_Pathfinder](ERROR): Failed to parse: :B +0.00, +0.00, +0.00, 0.00,3900.38 2019-11-26T19:22:04.278Z,1574796124.278 [RDI_Pathfinder](ERROR): only read 2 of 4 data items 2019-11-26T19:22:04.278Z,1574796124.278 [RDI_Pathfinder](ERROR): Failed to parse: :RA, 0.00, 0.00, 0.00 2019-11-26T19:22:14.629Z,1574796134.629 [DataOverHttps](INFO): Sending 411 bytes from file Logs/20191126T185625/Express0013.lzma 2019-11-26T19:22:16.630Z,1574796136.630 [DataOverHttps](INFO): Moved sent file to Logs/20191126T185625/Express0013.lzma.bak 2019-11-26T19:22:16.630Z,1574796136.630 [DataOverHttps](INFO): SBD MOMSN=12107519 2019-11-26T19:22:18.837Z,1574796138.837 [Default:CheckIn:Read_Iridium] Stopped 2019-11-26T19:22:18.837Z,1574796138.837 [Default:CheckIn:C.Wait] Running Loop=1 2019-11-26T19:22:18.837Z,1574796138.837 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-11-26T19:22:26.889Z,1574796146.889 [NAL9602](INFO): Not Powering down - fast GPS 2019-11-26T19:23:22.252Z,1574796202.252 [RDI_Pathfinder](ERROR): Failed to parse: :BE,-32768,-32768,-32768,V 2019-11-26T19:24:02.265Z,1574796242.265 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude 2019-11-26T19:24:02.265Z,1574796242.265 [RDI_Pathfinder](ERROR): Failed to parse: :BD, +0.00, +0.00, , 0.00,4026.35 2019-11-26T19:26:02.627Z,1574796362.627 [RDI_Pathfinder](ERROR): Failed to parse: :BE,-32768,-32768,-32768,V 2019-11-26T19:27:19.429Z,1574796439.429 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-11-26T19:27:19.429Z,1574796439.429 [Default:CheckIn:C.Wait] Stopped 2019-11-26T19:27:19.429Z,1574796439.429 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-11-26T19:27:19.430Z,1574796439.430 [Default:CheckIn:D] Running Loop=1 2019-11-26T19:27:19.841Z,1574796439.841 [Default:CheckIn:D] Stopped 2019-11-26T19:27:19.841Z,1574796439.841 [Default:CheckIn:E] Running Loop=1 2019-11-26T19:27:20.247Z,1574796440.247 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 68.997306 min 2019-11-26T19:27:20.247Z,1574796440.247 [Default:CheckIn:E] Stopped 2019-11-26T19:27:20.247Z,1574796440.247 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-11-26T19:27:20.248Z,1574796440.248 [Default:CheckIn] Stopped 2019-11-26T19:27:20.248Z,1574796440.248 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-11-26T19:27:20.248Z,1574796440.248 [Default:CheckIn](INFO): Running loop #12 2019-11-26T19:27:20.248Z,1574796440.248 [Default:CheckIn] Running Loop=12 2019-11-26T19:27:20.248Z,1574796440.248 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-11-26T19:27:20.248Z,1574796440.248 [Default:CheckIn:Read_GPS] Running Loop=1 2019-11-26T19:27:22.250Z,1574796442.250 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,192714.00,A,3648.15871,N,12147.24941,W,0.292,19.80,261119,,,D*4C 2019-11-26T19:27:22.252Z,1574796442.252 [NAL9602](INFO): GPS fix at 20191126T192714: (36.802645, -121.787490) 2019-11-26T19:27:22.304Z,1574796442.304 [Default:CheckIn:Read_GPS] Stopped 2019-11-26T19:27:22.305Z,1574796442.305 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-11-26T19:27:29.824Z,1574796449.824 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20191126T185625/Courier0015.lzma 2019-11-26T19:27:31.830Z,1574796451.830 [DataOverHttps](INFO): Moved sent file to Logs/20191126T185625/Courier0015.lzma.bak 2019-11-26T19:27:31.830Z,1574796451.830 [DataOverHttps](INFO): SBD MOMSN=12107524 2019-11-26T19:27:49.385Z,1574796469.385 [DataOverHttps](INFO): Sending 380 bytes from file Logs/20191126T185625/Express0016.lzma 2019-11-26T19:27:51.390Z,1574796471.390 [DataOverHttps](INFO): Moved sent file to Logs/20191126T185625/Express0016.lzma.bak 2019-11-26T19:27:51.391Z,1574796471.391 [DataOverHttps](INFO): SBD MOMSN=12107527 2019-11-26T19:27:53.393Z,1574796473.393 [Default:CheckIn:Read_Iridium] Stopped 2019-11-26T19:27:53.393Z,1574796473.393 [Default:CheckIn:C.Wait] Running Loop=1 2019-11-26T19:27:53.393Z,1574796473.393 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-11-26T19:28:15.180Z,1574796495.180 [NAL9602](INFO): SBD MO Status=0, MOMSN=10059, MT Status=0, MTMSN=0 2019-11-26T19:28:15.180Z,1574796495.180 [NAL9602](INFO): No messages in MT queue 2019-11-26T19:28:29.338Z,1574796509.338 [RDI_Pathfinder](ERROR): only read 3 of 4 data items 2019-11-26T19:28:29.338Z,1574796509.338 [RDI_Pathfinder](ERROR): Failed to parse: :RA, 0.00, 0.00, 0.00, 0.00 2019-11-26T19:28:45.895Z,1574796525.895 [NAL9602](INFO): Not Powering down - fast GPS 2019-11-26T19:31:09.338Z,1574796669.338 [RDI_Pathfinder](ERROR): Failed to parse: :BE,-32768,-32768,-32768,V 2019-11-26T19:32:54.002Z,1574796774.002 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-11-26T19:32:54.002Z,1574796774.002 [Default:CheckIn:C.Wait] Stopped 2019-11-26T19:32:54.002Z,1574796774.002 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-11-26T19:32:54.002Z,1574796774.002 [Default:CheckIn:D] Running Loop=1 2019-11-26T19:32:54.405Z,1574796774.405 [Default:CheckIn:D] Stopped 2019-11-26T19:32:54.405Z,1574796774.405 [Default:CheckIn:E] Running Loop=1 2019-11-26T19:32:54.801Z,1574796774.801 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 74.573364 min 2019-11-26T19:32:54.801Z,1574796774.801 [Default:CheckIn:E] Stopped 2019-11-26T19:32:54.801Z,1574796774.801 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-11-26T19:32:54.801Z,1574796774.801 [Default:CheckIn] Stopped 2019-11-26T19:32:54.801Z,1574796774.801 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-11-26T19:32:54.801Z,1574796774.801 [Default:CheckIn](INFO): Running loop #13 2019-11-26T19:32:54.801Z,1574796774.801 [Default:CheckIn] Running Loop=13 2019-11-26T19:32:54.802Z,1574796774.802 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-11-26T19:32:54.802Z,1574796774.802 [Default:CheckIn:Read_GPS] Running Loop=1 2019-11-26T19:32:56.793Z,1574796776.793 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,193249.00,A,3648.17368,N,12147.27693,W,0.330,252.63,261119,,,D*7B 2019-11-26T19:32:56.795Z,1574796776.795 [NAL9602](INFO): GPS fix at 20191126T193249: (36.802895, -121.787949) 2019-11-26T19:32:56.846Z,1574796776.846 [Default:CheckIn:Read_GPS] Stopped 2019-11-26T19:32:56.846Z,1574796776.846 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-11-26T19:33:00.076Z,1574796780.076 [RDI_Pathfinder](ERROR): only read 3 of 4 data items 2019-11-26T19:33:00.087Z,1574796780.087 [RDI_Pathfinder](ERROR): Failed to parse: :RA, 0.00, 0.00, 0.00, 0.00 2019-11-26T19:33:04.845Z,1574796784.845 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20191126T185625/Courier0018.lzma 2019-11-26T19:33:06.849Z,1574796786.849 [DataOverHttps](INFO): Moved sent file to Logs/20191126T185625/Courier0018.lzma.bak 2019-11-26T19:33:06.850Z,1574796786.850 [DataOverHttps](INFO): SBD MOMSN=12107532 2019-11-26T19:33:24.365Z,1574796804.365 [DataOverHttps](INFO): Sending 297 bytes from file Logs/20191126T185625/Express0019.lzma 2019-11-26T19:33:26.370Z,1574796806.370 [DataOverHttps](INFO): Moved sent file to Logs/20191126T185625/Express0019.lzma.bak 2019-11-26T19:33:26.370Z,1574796806.370 [DataOverHttps](INFO): SBD MOMSN=12107535 2019-11-26T19:33:26.692Z,1574796806.692 [NAL9602](INFO): SBD MO Status=0, MOMSN=10060, MT Status=0, MTMSN=0 2019-11-26T19:33:26.692Z,1574796806.692 [NAL9602](INFO): No messages in MT queue 2019-11-26T19:33:28.347Z,1574796808.347 [Default:CheckIn:Read_Iridium] Stopped 2019-11-26T19:33:28.347Z,1574796808.347 [Default:CheckIn:C.Wait] Running Loop=1 2019-11-26T19:33:28.347Z,1574796808.347 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-11-26T19:33:49.335Z,1574796829.335 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2019-11-26T19:33:49.335Z,1574796829.335 [RDI_Pathfinder](ERROR): Failed to parse: :TS,19112612454926,35.0, -0.1, 09, 0 2019-11-26T19:33:57.400Z,1574796837.400 [NAL9602](INFO): Not Powering down - fast GPS 2019-11-26T19:34:29.341Z,1574796869.341 [RDI_Pathfinder](ERROR): Failed to parse: :BE,-32768,-32768,-32768,V 2019-11-26T19:36:20.437Z,1574796980.437 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2019-11-26T19:36:20.437Z,1574796980.437 [RDI_Pathfinder](ERROR): Failed to parse: :TS,191126124820 -0.1, 0.0,1448.9, 0 2019-11-26T19:38:28.942Z,1574797108.942 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-11-26T19:38:28.943Z,1574797108.943 [Default:CheckIn:C.Wait] Stopped 2019-11-26T19:38:28.943Z,1574797108.943 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-11-26T19:38:28.944Z,1574797108.944 [Default:CheckIn:D] Running Loop=1 2019-11-26T19:38:29.327Z,1574797109.327 [Default:CheckIn:D] Stopped 2019-11-26T19:38:29.327Z,1574797109.327 [Default:CheckIn:E] Running Loop=1 2019-11-26T19:38:29.732Z,1574797109.732 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 80.155412 min 2019-11-26T19:38:29.732Z,1574797109.732 [Default:CheckIn:E] Stopped 2019-11-26T19:38:29.732Z,1574797109.732 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-11-26T19:38:29.732Z,1574797109.732 [Default:CheckIn] Stopped 2019-11-26T19:38:29.732Z,1574797109.732 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-11-26T19:38:29.733Z,1574797109.733 [Default:CheckIn](INFO): Running loop #14 2019-11-26T19:38:29.733Z,1574797109.733 [Default:CheckIn] Running Loop=14 2019-11-26T19:38:29.733Z,1574797109.733 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-11-26T19:38:29.733Z,1574797109.733 [Default:CheckIn:Read_GPS] Running Loop=1 2019-11-26T19:38:31.729Z,1574797111.729 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,193824.00,A,3648.16676,N,12147.27855,W,0.233,252.63,261119,,,A*72 2019-11-26T19:38:31.731Z,1574797111.731 [NAL9602](INFO): GPS fix at 20191126T193824: (36.802779, -121.787976) 2019-11-26T19:38:31.777Z,1574797111.777 [Default:CheckIn:Read_GPS] Stopped 2019-11-26T19:38:31.777Z,1574797111.777 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-11-26T19:38:39.968Z,1574797119.968 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20191126T185625/Courier0021.lzma 2019-11-26T19:38:41.974Z,1574797121.974 [DataOverHttps](INFO): Moved sent file to Logs/20191126T185625/Courier0021.lzma.bak 2019-11-26T19:38:41.974Z,1574797121.974 [DataOverHttps](INFO): SBD MOMSN=12107540 2019-11-26T19:39:00.533Z,1574797140.533 [DataOverHttps](INFO): Sending 322 bytes from file Logs/20191126T185625/Express0022.lzma 2019-11-26T19:39:02.538Z,1574797142.538 [DataOverHttps](INFO): Moved sent file to Logs/20191126T185625/Express0022.lzma.bak 2019-11-26T19:39:02.539Z,1574797142.539 [DataOverHttps](INFO): SBD MOMSN=12107543 2019-11-26T19:39:04.920Z,1574797144.920 [Default:CheckIn:Read_Iridium] Stopped 2019-11-26T19:39:04.920Z,1574797144.920 [Default:CheckIn:C.Wait] Running Loop=1 2019-11-26T19:39:04.929Z,1574797144.929 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-11-26T19:39:36.364Z,1574797176.364 [NAL9602](INFO): SBD MO Status=0, MOMSN=10061, MT Status=0, MTMSN=0 2019-11-26T19:39:36.364Z,1574797176.364 [NAL9602](INFO): No messages in MT queue 2019-11-26T19:40:07.091Z,1574797207.091 [NAL9602](INFO): Not Powering down - fast GPS 2019-11-26T19:40:21.274Z,1574797221.274 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2019-11-26T19:40:21.274Z,1574797221.274 [RDI_Pathfinder](ERROR): Failed to parse: :TS,191126.89 2019-11-26T19:40:43.897Z,1574797243.897 [RDI_Pathfinder](ERROR): only read 3 of 4 data items 2019-11-26T19:40:43.897Z,1574797243.897 [RDI_Pathfinder](ERROR): Failed to parse: :RA, 0.00, 0.00, 0.00, 0.00 2019-11-26T19:42:07.099Z,1574797327.099 [RDI_Pathfinder](ERROR): Failed to parse: :SA, +0.00, +0.00, 0.00 2019-11-26T19:43:04.895Z,1574797384.895 [RDI_Pathfinder](ERROR): only read 2 of 4 data items 2019-11-26T19:43:04.895Z,1574797384.895 [RDI_Pathfinder](ERROR): Failed to parse: :BS,-32768,-32768, 2019-11-26T19:44:05.568Z,1574797445.568 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-11-26T19:44:05.568Z,1574797445.568 [Default:CheckIn:C.Wait] Stopped 2019-11-26T19:44:05.568Z,1574797445.568 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-11-26T19:44:05.568Z,1574797445.568 [Default:CheckIn:D] Running Loop=1 2019-11-26T19:44:06.002Z,1574797446.002 [Default:CheckIn:D] Stopped 2019-11-26T19:44:06.002Z,1574797446.002 [Default:CheckIn:E] Running Loop=1 2019-11-26T19:44:06.369Z,1574797446.369 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 85.766659 min 2019-11-26T19:44:06.369Z,1574797446.369 [Default:CheckIn:E] Stopped 2019-11-26T19:44:06.369Z,1574797446.369 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-11-26T19:44:06.369Z,1574797446.369 [Default:CheckIn] Stopped 2019-11-26T19:44:06.369Z,1574797446.369 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-11-26T19:44:06.370Z,1574797446.370 [Default:CheckIn](INFO): Running loop #15 2019-11-26T19:44:06.370Z,1574797446.370 [Default:CheckIn] Running Loop=15 2019-11-26T19:44:06.370Z,1574797446.370 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-11-26T19:44:06.370Z,1574797446.370 [Default:CheckIn:Read_GPS] Running Loop=1 2019-11-26T19:44:08.293Z,1574797448.293 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194400.00,A,3648.15767,N,12147.28443,W,0.583,0.00,261119,,,A*75 2019-11-26T19:44:08.295Z,1574797448.295 [NAL9602](INFO): GPS fix at 20191126T194400: (36.802628, -121.788074) 2019-11-26T19:44:08.376Z,1574797448.376 [Default:CheckIn:Read_GPS] Stopped 2019-11-26T19:44:08.376Z,1574797448.376 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-11-26T19:44:11.582Z,1574797451.582 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20191126T185625/Courier0024.lzma 2019-11-26T19:44:13.590Z,1574797453.590 [DataOverHttps](INFO): Moved sent file to Logs/20191126T185625/Courier0024.lzma.bak 2019-11-26T19:44:13.590Z,1574797453.590 [DataOverHttps](INFO): SBD MOMSN=12107548 2019-11-26T19:44:25.033Z,1574797465.033 [RDI_Pathfinder](ERROR): DVL uart error: serial timeout 2019-11-26T19:44:25.033Z,1574797465.033 [RDI_Pathfinder] Communications Fault, FailCount= 1 2019-11-26T19:44:25.033Z,1574797465.033 [RDI_Pathfinder](ERROR): Communications Fault 2019-11-26T19:44:25.033Z,1574797465.033 [RDI_Pathfinder](ERROR): Failed to parse: 2019-11-26T19:44:25.085Z,1574797465.085 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder 2019-11-26T19:44:25.441Z,1574797465.441 [RDI_Pathfinder](INFO): Powering down 2019-11-26T19:44:26.186Z,1574797466.186 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder 2019-11-26T19:44:26.187Z,1574797466.187 [RDI_Pathfinder] No Fault, FailCount= 1 2019-11-26T19:44:32.149Z,1574797472.149 [DataOverHttps](INFO): Sending 181 bytes from file Logs/20191126T185625/Express0025.lzma 2019-11-26T19:44:34.154Z,1574797474.154 [DataOverHttps](INFO): Moved sent file to Logs/20191126T185625/Express0025.lzma.bak 2019-11-26T19:44:34.155Z,1574797474.155 [DataOverHttps](INFO): SBD MOMSN=12107552 2019-11-26T19:44:36.296Z,1574797476.296 [Default:CheckIn:Read_Iridium] Stopped 2019-11-26T19:44:36.296Z,1574797476.296 [Default:CheckIn:C.Wait] Running Loop=1 2019-11-26T19:44:36.296Z,1574797476.296 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-11-26T19:44:39.528Z,1574797479.528 [RDI_Pathfinder](ERROR): Failed to parse:Pathfinder 2019-11-26T19:45:11.466Z,1574797511.466 [RDI_Pathfinder](ERROR): Failed to parse: :RA, 0.00, 0.00, 0.00, 0.00 2019-11-26T19:46:14.852Z,1574797574.852 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2019-11-26T19:46:14.852Z,1574797574.852 [RDI_Pathfinder](ERROR): Failed to parse: :TS,191126125.0, -0.1, 0.0,1448.9, 0 2019-11-26T19:47:19.072Z,1574797639.072 [NAL9602](INFO): SBD MO Status=2, MOMSN=10062, MT Status=2, MTMSN=0 2019-11-26T19:47:19.072Z,1574797639.072 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-11-26T19:47:38.472Z,1574797658.472 [NAL9602](INFO): SBD MO Status=2, MOMSN=10062, MT Status=2, MTMSN=0 2019-11-26T19:47:38.472Z,1574797658.472 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-11-26T19:48:46.352Z,1574797726.352 [NAL9602](INFO): SBD MO Status=2, MOMSN=10062, MT Status=2, MTMSN=0 2019-11-26T19:48:46.352Z,1574797726.352 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-11-26T19:49:10.195Z,1574797750.195 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-11-26T19:49:36.905Z,1574797776.905 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-11-26T19:49:36.905Z,1574797776.905 [Default:CheckIn:C.Wait] Stopped 2019-11-26T19:49:36.905Z,1574797776.905 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-11-26T19:49:36.905Z,1574797776.905 [Default:CheckIn:D] Running Loop=1 2019-11-26T19:49:37.301Z,1574797777.301 [Default:CheckIn:D] Stopped 2019-11-26T19:49:37.301Z,1574797777.301 [Default:CheckIn:E] Running Loop=1 2019-11-26T19:49:37.717Z,1574797777.717 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 91.288298 min 2019-11-26T19:49:37.717Z,1574797777.717 [Default:CheckIn:E] Stopped 2019-11-26T19:49:37.717Z,1574797777.717 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-11-26T19:49:37.717Z,1574797777.717 [Default:CheckIn] Stopped 2019-11-26T19:49:37.718Z,1574797777.718 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-11-26T19:49:37.718Z,1574797777.718 [Default:CheckIn](INFO): Running loop #16 2019-11-26T19:49:37.718Z,1574797777.718 [Default:CheckIn] Running Loop=16 2019-11-26T19:49:37.718Z,1574797777.718 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-11-26T19:49:37.718Z,1574797777.718 [Default:CheckIn:Read_GPS] Running Loop=1 2019-11-26T19:49:39.711Z,1574797779.711 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194932.00,A,3648.16795,N,12147.28221,W,0.330,0.00,261119,,,A*7B 2019-11-26T19:49:39.713Z,1574797779.713 [NAL9602](INFO): GPS fix at 20191126T194932: (36.802799, -121.788037) 2019-11-26T19:49:39.758Z,1574797779.758 [Default:CheckIn:Read_GPS] Stopped 2019-11-26T19:49:39.758Z,1574797779.758 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-11-26T19:49:47.404Z,1574797787.404 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20191126T185625/Courier0027.lzma 2019-11-26T19:49:49.410Z,1574797789.410 [DataOverHttps](INFO): Moved sent file to Logs/20191126T185625/Courier0027.lzma.bak 2019-11-26T19:49:49.411Z,1574797789.411 [DataOverHttps](INFO): SBD MOMSN=12107555 2019-11-26T19:50:09.997Z,1574797809.997 [DataOverHttps](INFO): Sending 255 bytes from file Logs/20191126T185625/Express0028.lzma 2019-11-26T19:50:12.002Z,1574797812.002 [DataOverHttps](INFO): Moved sent file to Logs/20191126T185625/Express0028.lzma.bak 2019-11-26T19:50:12.002Z,1574797812.002 [DataOverHttps](INFO): SBD MOMSN=12107558 2019-11-26T19:50:12.467Z,1574797812.467 [NAL9602](INFO): Not Powering down - fast GPS 2019-11-26T19:50:14.109Z,1574797814.109 [Default:CheckIn:Read_Iridium] Stopped 2019-11-26T19:50:14.109Z,1574797814.109 [Default:CheckIn:C.Wait] Running Loop=1 2019-11-26T19:50:14.109Z,1574797814.109 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-11-26T19:50:29.483Z,1574797829.483 [RDI_Pathfinder](ERROR): only read 2 of 4 data items 2019-11-26T19:50:29.483Z,1574797829.483 [RDI_Pathfinder](ERROR): Failed to parse: :BS,-32768,32768,V 2019-11-26T19:51:30.472Z,1574797890.472 [RDI_Pathfinder](ERROR): Failed to parse: :BE,-32768,-32768,-32768,V 2019-11-26T19:51:55.532Z,1574797915.532 [RDI_Pathfinder](ERROR): Failed to parse: :BI,-32768,-32768,-32768,-32768,V 2019-11-26T19:53:01.776Z,1574797981.776 [Micromodem](ERROR): Response from modem failed NMEA checksum: $CAREV,195302,COP.0.46*4C expected 21 2019-11-26T19:55:14.734Z,1574798114.734 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-11-26T19:55:14.734Z,1574798114.734 [Default:CheckIn:C.Wait] Stopped 2019-11-26T19:55:14.734Z,1574798114.734 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-11-26T19:55:14.734Z,1574798114.734 [Default:CheckIn:D] Running Loop=1 2019-11-26T19:55:15.135Z,1574798115.135 [Default:CheckIn:D] Stopped 2019-11-26T19:55:15.135Z,1574798115.135 [Default:CheckIn:E] Running Loop=1 2019-11-26T19:55:15.569Z,1574798115.569 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 96.918872 min 2019-11-26T19:55:15.569Z,1574798115.569 [Default:CheckIn:E] Stopped 2019-11-26T19:55:15.569Z,1574798115.569 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-11-26T19:55:15.570Z,1574798115.570 [Default:CheckIn] Stopped 2019-11-26T19:55:15.570Z,1574798115.570 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-11-26T19:55:15.570Z,1574798115.570 [Default:CheckIn](INFO): Running loop #17 2019-11-26T19:55:15.570Z,1574798115.570 [Default:CheckIn] Running Loop=17 2019-11-26T19:55:15.570Z,1574798115.570 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-11-26T19:55:15.570Z,1574798115.570 [Default:CheckIn:Read_GPS] Running Loop=1 2019-11-26T19:55:17.525Z,1574798117.525 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,195510.00,A,3648.16990,N,12147.27941,W,0.233,0.00,261119,,,A*7D 2019-11-26T19:55:17.527Z,1574798117.527 [NAL9602](INFO): GPS fix at 20191126T195510: (36.802832, -121.787990) 2019-11-26T19:55:17.557Z,1574798117.557 [Default:CheckIn:Read_GPS] Stopped 2019-11-26T19:55:17.557Z,1574798117.557 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-11-26T19:55:26.320Z,1574798126.320 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20191126T185625/Courier0030.lzma 2019-11-26T19:55:28.326Z,1574798128.326 [DataOverHttps](INFO): Moved sent file to Logs/20191126T185625/Courier0030.lzma.bak 2019-11-26T19:55:28.326Z,1574798128.326 [DataOverHttps](INFO): SBD MOMSN=12107562 2019-11-26T19:55:46.128Z,1574798146.128 [DataOverHttps](INFO): Sending 192 bytes from file Logs/20191126T185625/Express0031.lzma 2019-11-26T19:55:48.134Z,1574798148.134 [DataOverHttps](INFO): Moved sent file to Logs/20191126T185625/Express0031.lzma.bak 2019-11-26T19:55:48.135Z,1574798148.135 [DataOverHttps](INFO): SBD MOMSN=12107565 2019-11-26T19:55:48.231Z,1574798148.231 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2019-11-26T19:55:48.305Z,1574798148.305 [NAL9602](FAULT): received: +CSQ:0 OK062, 2, 0, 0, 0 OK 2019-11-26T19:55:48.305Z,1574798148.305 [NAL9602] Data Fault, FailCount= 1 2019-11-26T19:55:48.305Z,1574798148.305 [NAL9602](ERROR): Data Fault 2019-11-26T19:55:48.364Z,1574798148.364 [CBIT](ERROR): Data Fault in component: NAL9602 2019-11-26T19:55:48.631Z,1574798148.631 [NAL9602](INFO): Powering down 2019-11-26T19:55:49.582Z,1574798149.582 [CBIT](INFO): Clearing failed state for component NAL9602 2019-11-26T19:55:49.582Z,1574798149.582 [NAL9602] No Fault, FailCount= 1 2019-11-26T19:55:50.296Z,1574798150.296 [Default:CheckIn:Read_Iridium] Stopped 2019-11-26T19:55:50.296Z,1574798150.296 [Default:CheckIn:C.Wait] Running Loop=1 2019-11-26T19:55:50.296Z,1574798150.296 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-11-26T19:56:18.951Z,1574798178.951 [NAL9602](INFO): Powering up NAL9602 2019-11-26T19:56:29.872Z,1574798189.872 [NAL9602](INFO): NAL9602 initialized 2019-11-26T19:57:00.967Z,1574798220.967 [NAL9602](INFO): Not Powering down - fast GPS 2019-11-26T20:00:50.889Z,1574798450.889 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-11-26T20:00:50.889Z,1574798450.889 [Default:CheckIn:C.Wait] Stopped 2019-11-26T20:00:50.889Z,1574798450.889 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-11-26T20:00:50.890Z,1574798450.890 [Default:CheckIn:D] Running Loop=1 2019-11-26T20:00:51.301Z,1574798451.301 [Default:CheckIn:D] Stopped 2019-11-26T20:00:51.301Z,1574798451.301 [Default:CheckIn:E] Running Loop=1 2019-11-26T20:00:51.720Z,1574798451.720 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 102.521639 min 2019-11-26T20:00:51.720Z,1574798451.720 [Default:CheckIn:E] Stopped 2019-11-26T20:00:51.720Z,1574798451.720 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-11-26T20:00:51.720Z,1574798451.720 [Default:CheckIn] Stopped 2019-11-26T20:00:51.720Z,1574798451.720 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-11-26T20:00:51.720Z,1574798451.720 [Default:CheckIn](INFO): Running loop #18 2019-11-26T20:00:51.720Z,1574798451.720 [Default:CheckIn] Running Loop=18 2019-11-26T20:00:51.725Z,1574798451.725 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-11-26T20:00:51.725Z,1574798451.725 [Default:CheckIn:Read_GPS] Running Loop=1 2019-11-26T20:00:53.684Z,1574798453.684 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200045.00,A,3648.16665,N,12147.27896,W,0.816,0.00,261119,,,A*74 2019-11-26T20:00:53.687Z,1574798453.687 [NAL9602](INFO): GPS fix at 20191126T200045: (36.802777, -121.787983) 2019-11-26T20:00:53.735Z,1574798453.735 [Default:CheckIn:Read_GPS] Stopped 2019-11-26T20:00:53.735Z,1574798453.735 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-11-26T20:00:56.107Z,1574798456.107 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-11-26T20:01:04.205Z,1574798464.205 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20191126T185625/Courier0033.lzma 2019-11-26T20:01:06.211Z,1574798466.211 [DataOverHttps](INFO): Moved sent file to Logs/20191126T185625/Courier0033.lzma.bak 2019-11-26T20:01:06.211Z,1574798466.211 [DataOverHttps](INFO): SBD MOMSN=12107568 2019-11-26T20:01:23.905Z,1574798483.905 [DataOverHttps](INFO): Sending 199 bytes from file Logs/20191126T185625/Express0034.lzma 2019-11-26T20:01:25.910Z,1574798485.910 [DataOverHttps](INFO): Moved sent file to Logs/20191126T185625/Express0034.lzma.bak 2019-11-26T20:01:25.910Z,1574798485.910 [DataOverHttps](INFO): SBD MOMSN=12107571 2019-11-26T20:01:26.805Z,1574798486.805 [NAL9602](INFO): Not Powering down - fast GPS 2019-11-26T20:01:28.075Z,1574798488.075 [Default:CheckIn:Read_Iridium] Stopped 2019-11-26T20:01:28.075Z,1574798488.075 [Default:CheckIn:C.Wait] Running Loop=1 2019-11-26T20:01:28.075Z,1574798488.075 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-11-26T20:06:28.664Z,1574798788.664 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-11-26T20:06:28.664Z,1574798788.664 [Default:CheckIn:C.Wait] Stopped 2019-11-26T20:06:28.664Z,1574798788.664 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-11-26T20:06:28.664Z,1574798788.664 [Default:CheckIn:D] Running Loop=1 2019-11-26T20:06:29.072Z,1574798789.072 [Default:CheckIn:D] Stopped 2019-11-26T20:06:29.072Z,1574798789.072 [Default:CheckIn:E] Running Loop=1 2019-11-26T20:06:29.548Z,1574798789.548 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 108.151156 min 2019-11-26T20:06:29.548Z,1574798789.548 [Default:CheckIn:E] Stopped 2019-11-26T20:06:29.548Z,1574798789.548 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-11-26T20:06:29.563Z,1574798789.563 [Default:CheckIn] Stopped 2019-11-26T20:06:29.563Z,1574798789.563 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-11-26T20:06:29.563Z,1574798789.563 [Default:CheckIn](INFO): Running loop #19 2019-11-26T20:06:29.563Z,1574798789.563 [Default:CheckIn] Running Loop=19 2019-11-26T20:06:29.563Z,1574798789.563 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-11-26T20:06:29.563Z,1574798789.563 [Default:CheckIn:Read_GPS] Running Loop=1 2019-11-26T20:06:31.467Z,1574798791.467 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200623.00,A,3648.16597,N,12147.27784,W,0.058,0.00,261119,,,A*72 2019-11-26T20:06:31.469Z,1574798791.469 [NAL9602](INFO): GPS fix at 20191126T200623: (36.802766, -121.787964) 2019-11-26T20:06:31.503Z,1574798791.503 [Default:CheckIn:Read_GPS] Stopped 2019-11-26T20:06:31.503Z,1574798791.503 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-11-26T20:06:39.564Z,1574798799.564 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20191126T185625/Courier0036.lzma 2019-11-26T20:06:41.570Z,1574798801.570 [DataOverHttps](INFO): Moved sent file to Logs/20191126T185625/Courier0036.lzma.bak 2019-11-26T20:06:41.571Z,1574798801.571 [DataOverHttps](INFO): SBD MOMSN=12107575 2019-11-26T20:06:59.021Z,1574798819.021 [DataOverHttps](INFO): Sending 221 bytes from file Logs/20191126T185625/Express0037.lzma 2019-11-26T20:07:01.026Z,1574798821.026 [DataOverHttps](INFO): Moved sent file to Logs/20191126T185625/Express0037.lzma.bak 2019-11-26T20:07:01.027Z,1574798821.027 [DataOverHttps](INFO): SBD MOMSN=12107578 2019-11-26T20:07:03.006Z,1574798823.006 [Default:CheckIn:Read_Iridium] Stopped 2019-11-26T20:07:03.006Z,1574798823.006 [Default:CheckIn:C.Wait] Running Loop=1 2019-11-26T20:07:03.006Z,1574798823.006 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-11-26T20:07:09.857Z,1574798829.857 [RDI_Pathfinder](ERROR): only read 1 of 4 data items 2019-11-26T20:07:09.857Z,1574798829.857 [RDI_Pathfinder](ERROR): Failed to parse: :BS,-32768-32768,V 2019-11-26T20:07:15.532Z,1574798835.532 [RDI_Pathfinder](ERROR): only read 2 of 4 data items 2019-11-26T20:07:15.534Z,1574798835.534 [RDI_Pathfinder](ERROR): Failed to parse: :BS,-32768,-3268,V 2019-11-26T20:07:36.092Z,1574798856.092 [NAL9602](INFO): SBD MO Status=2, MOMSN=10062, MT Status=2, MTMSN=0 2019-11-26T20:07:36.093Z,1574798856.093 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-11-26T20:11:33.260Z,1574799093.260 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-11-26T20:12:03.613Z,1574799123.613 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-11-26T20:12:03.613Z,1574799123.613 [Default:CheckIn:C.Wait] Stopped 2019-11-26T20:12:03.613Z,1574799123.613 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-11-26T20:12:03.614Z,1574799123.614 [Default:CheckIn:D] Running Loop=1 2019-11-26T20:12:03.967Z,1574799123.967 [NAL9602](INFO): Not Powering down - fast GPS 2019-11-26T20:12:04.023Z,1574799124.023 [Default:CheckIn:D] Stopped 2019-11-26T20:12:04.023Z,1574799124.023 [Default:CheckIn:E] Running Loop=1 2019-11-26T20:12:04.490Z,1574799124.490 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 113.733667 min 2019-11-26T20:12:04.490Z,1574799124.490 [Default:CheckIn:E] Stopped 2019-11-26T20:12:04.490Z,1574799124.490 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-11-26T20:12:04.490Z,1574799124.490 [Default:CheckIn] Stopped 2019-11-26T20:12:04.490Z,1574799124.490 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-11-26T20:12:04.490Z,1574799124.490 [Default:CheckIn](INFO): Running loop #20 2019-11-26T20:12:04.490Z,1574799124.490 [Default:CheckIn] Running Loop=20 2019-11-26T20:12:04.491Z,1574799124.491 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-11-26T20:12:04.491Z,1574799124.491 [Default:CheckIn:Read_GPS] Running Loop=1 2019-11-26T20:12:06.388Z,1574799126.388 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,201158.00,A,3648.16478,N,12147.28167,W,0.097,0.00,261119,,,A*7F 2019-11-26T20:12:06.391Z,1574799126.391 [NAL9602](INFO): GPS fix at 20191126T201158: (36.802746, -121.788028) 2019-11-26T20:12:06.468Z,1574799126.468 [Default:CheckIn:Read_GPS] Stopped 2019-11-26T20:12:06.468Z,1574799126.468 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-11-26T20:12:16.064Z,1574799136.064 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20191126T185625/Courier0039.lzma 2019-11-26T20:12:18.076Z,1574799138.076 [DataOverHttps](INFO): Moved sent file to Logs/20191126T185625/Courier0039.lzma.bak 2019-11-26T20:12:18.076Z,1574799138.076 [DataOverHttps](INFO): SBD MOMSN=12107582 2019-11-26T20:12:35.605Z,1574799155.605 [DataOverHttps](INFO): Sending 501 bytes from file Logs/20191126T185625/Express0040.lzma 2019-11-26T20:12:37.075Z,1574799157.075 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2019-11-26T20:12:37.153Z,1574799157.153 [NAL9602](FAULT): received: +CSQ:0 OK062, 2, 0, 0, 0 OK 2019-11-26T20:12:37.153Z,1574799157.153 [NAL9602] Data Fault, FailCount= 1 2019-11-26T20:12:37.153Z,1574799157.153 [NAL9602](ERROR): Data Fault 2019-11-26T20:12:37.193Z,1574799157.193 [CBIT](ERROR): Data Fault in component: NAL9602 2019-11-26T20:12:37.483Z,1574799157.483 [NAL9602](INFO): Powering down 2019-11-26T20:12:37.615Z,1574799157.615 [DataOverHttps](INFO): Moved sent file to Logs/20191126T185625/Express0040.lzma.bak 2019-11-26T20:12:37.615Z,1574799157.615 [DataOverHttps](INFO): SBD MOMSN=12107585 2019-11-26T20:12:38.334Z,1574799158.334 [CBIT](INFO): Clearing failed state for component NAL9602 2019-11-26T20:12:38.334Z,1574799158.334 [NAL9602] No Fault, FailCount= 1 2019-11-26T20:12:39.948Z,1574799159.948 [Default:CheckIn:Read_Iridium] Stopped 2019-11-26T20:12:39.948Z,1574799159.948 [Default:CheckIn:C.Wait] Running Loop=1 2019-11-26T20:12:39.948Z,1574799159.948 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-11-26T20:13:07.810Z,1574799187.810 [NAL9602](INFO): Powering up NAL9602 2019-11-26T20:13:18.687Z,1574799198.687 [NAL9602](INFO): NAL9602 initialized 2019-11-26T20:13:49.795Z,1574799229.795 [NAL9602](INFO): Not Powering down - fast GPS 2019-11-26T20:14:29.857Z,1574799269.857 [RDI_Pathfinder](ERROR): only read 2 of 4 data items 2019-11-26T20:14:29.857Z,1574799269.857 [RDI_Pathfinder](ERROR): Failed to parse: :BS,-3768,-32768,V 2019-11-26T20:16:10.457Z,1574799370.457 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude 2019-11-26T20:16:10.457Z,1574799370.457 [RDI_Pathfinder](ERROR): Failed to parse: :BD +0.00, +0.00, +0.00, 0.00,1890.85 2019-11-26T20:17:40.558Z,1574799460.558 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-11-26T20:17:40.559Z,1574799460.559 [Default:CheckIn:C.Wait] Stopped 2019-11-26T20:17:40.559Z,1574799460.559 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-11-26T20:17:40.559Z,1574799460.559 [Default:CheckIn:D] Running Loop=1 2019-11-26T20:17:40.966Z,1574799460.966 [Default:CheckIn:D] Stopped 2019-11-26T20:17:40.966Z,1574799460.966 [Default:CheckIn:E] Running Loop=1 2019-11-26T20:17:41.359Z,1574799461.359 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 119.349390 min 2019-11-26T20:17:41.359Z,1574799461.359 [Default:CheckIn:E] Stopped 2019-11-26T20:17:41.359Z,1574799461.359 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-11-26T20:17:41.359Z,1574799461.359 [Default:CheckIn] Stopped 2019-11-26T20:17:41.359Z,1574799461.359 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-11-26T20:17:41.360Z,1574799461.360 [Default:CheckIn](INFO): Running loop #21 2019-11-26T20:17:41.360Z,1574799461.360 [Default:CheckIn] Running Loop=21 2019-11-26T20:17:41.360Z,1574799461.360 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-11-26T20:17:41.360Z,1574799461.360 [Default:CheckIn:Read_GPS] Running Loop=1 2019-11-26T20:17:44.960Z,1574799464.960 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-11-26T20:17:55.523Z,1574799475.523 [RDI_Pathfinder](ERROR): only read 3 of 4 data items 2019-11-26T20:17:55.523Z,1574799475.523 [RDI_Pathfinder](ERROR): Failed to parse: :RA, 0.00, 0.00, 0.00, 0.00 2019-11-26T20:19:09.466Z,1574799549.466 [RDI_Pathfinder](ERROR): Failed to parse: :0, 0.00, 0.00, 0.00, 0.00 2019-11-26T20:21:52.481Z,1574799712.481 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2019-11-26T20:21:52.481Z,1574799712.481 [RDI_Pathfinder](ERROR): Failed to parse: :TS,19112613335284,35.0, -0.1, 0.0,1448:RA, 0.00, 0.00, 0.00, 0.00, 0.00 2019-11-26T20:21:54.490Z,1574799714.490 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2019-11-26T20:21:54.490Z,1574799714.490 [RDI_Pathfinder](ERROR): Failed to parse: :TS,19112613330, -0.1, 0.0,1448.9, 0 2019-11-26T20:22:41.676Z,1574799761.676 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-11-26T20:17:41.4Z 2019-11-26T20:22:41.676Z,1574799761.676 [Default:CheckIn:Read_GPS] Stopped 2019-11-26T20:22:41.685Z,1574799761.685 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-11-26T20:23:00.187Z,1574799780.187 [DataOverHttps](INFO): Sending 537 bytes from file Logs/20191126T185625/Express0043.lzma 2019-11-26T20:23:02.192Z,1574799782.192 [DataOverHttps](INFO): Moved sent file to Logs/20191126T185625/Express0043.lzma.bak 2019-11-26T20:23:02.192Z,1574799782.192 [DataOverHttps](INFO): SBD MOMSN=12107601 2019-11-26T20:23:08.047Z,1574799788.047 [Default:CheckIn:Read_Iridium] Stopped 2019-11-26T20:23:08.047Z,1574799788.047 [Default:CheckIn:C.Wait] Running Loop=1 2019-11-26T20:23:08.047Z,1574799788.047 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-11-26T20:23:14.681Z,1574799794.681 [NAL9602](INFO): Not Powering down - fast GPS 2019-11-26T20:25:38.163Z,1574799938.163 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2019-11-26T20:25:38.163Z,1574799938.163 [RDI_Pathfinder](ERROR): Failed to parse: :TS,19112613373784,35.0, -0.1, 0.0,1448.RA, 0.00, 0.00, 0.00, 0.00, 0.00 2019-11-26T20:25:59.174Z,1574799959.174 [RDI_Pathfinder](ERROR): Failed to parse: 68,-32768,-32768,V 2019-11-26T20:26:02.798Z,1574799962.798 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2019-11-26T20:26:02.799Z,1574799962.799 [RDI_Pathfinder](ERROR): Failed to parse: :TS,19112613380284,35.0, -0.1, 0.0,1448.RA, 0.00, 0.00, 0.00, 0.00, 0.00 2019-11-26T20:26:39.173Z,1574799999.173 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2019-11-26T20:26:39.173Z,1574799999.173 [RDI_Pathfinder](ERROR): Failed to parse: :TS,19112613383884,35.0, -00,1448.9, 0 2019-11-26T20:26:42.799Z,1574800002.799 [RDI_Pathfinder](ERROR): only read 3 of 4 data items 2019-11-26T20:26:42.800Z,1574800002.800 [RDI_Pathfinder](ERROR): Failed to parse: :RA, 0.00, 0.00, 0.00, 0.00 2019-11-26T20:27:05.550Z,1574800025.550 [RDI_Pathfinder](ERROR): only read 3 of 4 data items 2019-11-26T20:27:05.550Z,1574800025.550 [RDI_Pathfinder](ERROR): Failed to parse: :BS,-32768,-32768,-3:BE,-32768,-32768,-32768,V 2019-11-26T20:28:07.504Z,1574800087.504 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2019-11-26T20:28:08.598Z,1574800088.598 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-11-26T20:28:08.598Z,1574800088.598 [Default:CheckIn:C.Wait] Stopped 2019-11-26T20:28:08.598Z,1574800088.598 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-11-26T20:28:08.599Z,1574800088.599 [Default:CheckIn:D] Running Loop=1 2019-11-26T20:28:09.037Z,1574800089.037 [Default:CheckIn:D] Stopped 2019-11-26T20:28:09.037Z,1574800089.037 [Default:CheckIn:E] Running Loop=1 2019-11-26T20:28:09.596Z,1574800089.596 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 129.817244 min 2019-11-26T20:28:09.596Z,1574800089.596 [Default:CheckIn:E] Stopped 2019-11-26T20:28:09.596Z,1574800089.596 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-11-26T20:28:09.596Z,1574800089.596 [Default:CheckIn] Stopped 2019-11-26T20:28:09.596Z,1574800089.596 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-11-26T20:28:09.597Z,1574800089.597 [Default:CheckIn](INFO): Running loop #22 2019-11-26T20:28:09.597Z,1574800089.597 [Default:CheckIn] Running Loop=22 2019-11-26T20:28:09.597Z,1574800089.597 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-11-26T20:28:09.597Z,1574800089.597 [Default:CheckIn:Read_GPS] Running Loop=1 2019-11-26T20:28:10.976Z,1574800090.976 [NAL9602](FAULT): GPS failed to acquire within timeout. 2019-11-26T20:28:10.976Z,1574800090.976 [NAL9602] Data Fault, FailCount= 1 2019-11-26T20:28:10.976Z,1574800090.976 [NAL9602](ERROR): Data Fault 2019-11-26T20:28:11.090Z,1574800091.090 [CBIT](ERROR): Data Fault in component: NAL9602 2019-11-26T20:28:11.367Z,1574800091.367 [NAL9602](INFO): Powering down 2019-11-26T20:28:12.305Z,1574800092.305 [CBIT](INFO): Clearing failed state for component NAL9602 2019-11-26T20:28:12.305Z,1574800092.305 [NAL9602] No Fault, FailCount= 1 2019-11-26T20:28:13.521Z,1574800093.521 [RDI_Pathfinder](ERROR): DVL uart error: serial timeout 2019-11-26T20:28:13.521Z,1574800093.521 [RDI_Pathfinder] Communications Fault, FailCount= 1 2019-11-26T20:28:13.521Z,1574800093.521 [RDI_Pathfinder](ERROR): Communications Fault 2019-11-26T20:28:13.522Z,1574800093.522 [RDI_Pathfinder](ERROR): Failed to parse: 2019-11-26T20:28:13.639Z,1574800093.639 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder 2019-11-26T20:28:13.897Z,1574800093.897 [RDI_Pathfinder](INFO): Powering down 2019-11-26T20:28:14.724Z,1574800094.724 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder 2019-11-26T20:28:14.724Z,1574800094.724 [RDI_Pathfinder] No Fault, FailCount= 1 2019-11-26T20:28:22.406Z,1574800102.406 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2019-11-26T20:28:22.408Z,1574800102.408 [BPC1](INFO): Received data from all battery sticks. 2019-11-26T20:28:28.004Z,1574800108.004 [RDI_Pathfinder](ERROR): Failed to parse:Pathfinder 2019-11-26T20:28:41.707Z,1574800121.707 [NAL9602](INFO): Powering up NAL9602 2019-11-26T20:28:52.619Z,1574800132.619 [NAL9602](INFO): NAL9602 initialized 2019-11-26T20:28:55.470Z,1574800135.470 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2019-11-26T20:28:55.470Z,1574800135.470 [RDI_Pathfinder](ERROR): Failed to parse: :TS,19112613405532,35.0, -0.1, 0.0,1448.9,, 0.00, 0.00, 0.00, 0.00, 0.00 2019-11-26T20:30:24.347Z,1574800224.347 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2019-11-26T20:30:24.347Z,1574800224.347 [RDI_Pathfinder](ERROR): Failed to parse: :TS,19112613422432,35, 0.0,1448.9, 0 2019-11-26T20:33:09.622Z,1574800389.622 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-11-26T20:28:09.6Z 2019-11-26T20:33:09.622Z,1574800389.622 [Default:CheckIn:Read_GPS] Stopped 2019-11-26T20:33:09.623Z,1574800389.623 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-11-26T20:33:17.734Z,1574800397.734 [DataOverHttps](INFO): Sending 46 bytes from file Logs/20191126T185625/Courier0045.lzma 2019-11-26T20:33:19.739Z,1574800399.739 [DataOverHttps](INFO): Moved sent file to Logs/20191126T185625/Courier0045.lzma.bak 2019-11-26T20:33:19.739Z,1574800399.739 [DataOverHttps](INFO): SBD MOMSN=12107606 2019-11-26T20:33:40.169Z,1574800420.169 [DataOverHttps](INFO): Sending 181 bytes from file Logs/20191126T185625/Express0046.lzma 2019-11-26T20:33:42.175Z,1574800422.175 [DataOverHttps](INFO): Moved sent file to Logs/20191126T185625/Express0046.lzma.bak 2019-11-26T20:33:42.175Z,1574800422.175 [DataOverHttps](INFO): SBD MOMSN=12107608 2019-11-26T20:33:44.766Z,1574800424.766 [Default:CheckIn:Read_Iridium] Stopped 2019-11-26T20:33:44.766Z,1574800424.766 [Default:CheckIn:C.Wait] Running Loop=1 2019-11-26T20:33:44.766Z,1574800424.766 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-11-26T20:33:56.020Z,1574800436.020 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-11-26T20:34:26.735Z,1574800466.735 [NAL9602](INFO): Not Powering down - fast GPS 2019-11-26T20:34:41.300Z,1574800481.300 [RDI_Pathfinder](ERROR): only read 2 of 4 data items 2019-11-26T20:34:41.301Z,1574800481.301 [RDI_Pathfinder](ERROR): Failed to parse: :BS,-32768,-32768, 2019-11-26T20:36:11.943Z,1574800571.943 [RDI_Pathfinder](ERROR): only read 2 of 4 data items 2019-11-26T20:36:11.943Z,1574800571.943 [RDI_Pathfinder](ERROR): Failed to parse: :BS,-3268,-32768,V 2019-11-26T20:36:46.638Z,1574800606.638 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2019-11-26T20:36:46.638Z,1574800606.638 [RDI_Pathfinder](ERROR): Failed to parse: :TS,19112613484632,35. 0.0,1448.9, 0 2019-11-26T20:37:50.072Z,1574800670.072 [RDI_Pathfinder](ERROR): Failed to parse: :BI,-32768,-32768,-32768,-32768,V 2019-11-26T20:38:11.934Z,1574800691.934 [RDI_Pathfinder](ERROR): only read 3 of 4 data items 2019-11-26T20:38:11.935Z,1574800691.935 [RDI_Pathfinder](ERROR): Failed to parse: :RA, 0.00, 0.00, 0.00, 0.00, 2019-11-26T20:38:45.457Z,1574800725.457 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-11-26T20:38:45.457Z,1574800725.457 [Default:CheckIn:C.Wait] Stopped 2019-11-26T20:38:45.458Z,1574800725.458 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-11-26T20:38:45.458Z,1574800725.458 [Default:CheckIn:D] Running Loop=1 2019-11-26T20:38:45.850Z,1574800725.850 [Default:CheckIn:D] Stopped 2019-11-26T20:38:45.850Z,1574800725.850 [Default:CheckIn:E] Running Loop=1 2019-11-26T20:38:46.270Z,1574800726.270 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 140.430778 min 2019-11-26T20:38:46.270Z,1574800726.270 [Default:CheckIn:E] Stopped 2019-11-26T20:38:46.271Z,1574800726.271 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-11-26T20:38:46.271Z,1574800726.271 [Default:CheckIn] Stopped 2019-11-26T20:38:46.272Z,1574800726.272 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-11-26T20:38:46.272Z,1574800726.272 [Default:CheckIn](INFO): Running loop #23 2019-11-26T20:38:46.272Z,1574800726.272 [Default:CheckIn] Running Loop=23 2019-11-26T20:38:46.272Z,1574800726.272 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-11-26T20:38:46.272Z,1574800726.272 [Default:CheckIn:Read_GPS] Running Loop=1 2019-11-26T20:39:18.944Z,1574800758.944 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2019-11-26T20:39:19.021Z,1574800759.021 [NAL9602](FAULT): received: +CSQ:0 OK062, 2, 0, 0, 0 OK 2019-11-26T20:39:19.022Z,1574800759.022 [NAL9602] Data Fault, FailCount= 2 2019-11-26T20:39:19.022Z,1574800759.022 [NAL9602](ERROR): Data Fault 2019-11-26T20:39:19.117Z,1574800759.117 [CBIT](ERROR): Data Fault in component: NAL9602 2019-11-26T20:39:19.323Z,1574800759.323 [NAL9602](INFO): Powering down 2019-11-26T20:39:20.251Z,1574800760.251 [CBIT](INFO): Clearing failed state for component NAL9602 2019-11-26T20:39:20.251Z,1574800760.251 [NAL9602] No Fault, FailCount= 2 2019-11-26T20:39:32.273Z,1574800772.273 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2019-11-26T20:39:32.274Z,1574800772.274 [RDI_Pathfinder](ERROR): Failed to parse: :TS,191126135132 -0.1, 0.0,1448.9, 0 2019-11-26T20:39:49.664Z,1574800789.664 [NAL9602](INFO): Powering up NAL9602 2019-11-26T20:40:00.539Z,1574800800.539 [NAL9602](INFO): NAL9602 initialized 2019-11-26T20:40:01.355Z,1574800801.355 [NAL9602](FAULT): GPS failed to acquire within timeout. 2019-11-26T20:40:01.355Z,1574800801.355 [NAL9602] Data Fault, FailCount= 3 2019-11-26T20:40:01.355Z,1574800801.355 [NAL9602](ERROR): Data Fault 2019-11-26T20:40:01.425Z,1574800801.425 [CBIT](ERROR): Data Fault in component: NAL9602 2019-11-26T20:40:01.747Z,1574800801.747 [NAL9602](INFO): Powering down 2019-11-26T20:40:02.621Z,1574800802.621 [CBIT](INFO): Clearing failed state for component NAL9602 2019-11-26T20:40:02.621Z,1574800802.621 [NAL9602] No Fault, FailCount= 3 2019-11-26T20:40:32.053Z,1574800832.053 [NAL9602](INFO): Powering up NAL9602 2019-11-26T20:40:42.974Z,1574800842.974 [NAL9602](INFO): NAL9602 initialized 2019-11-26T20:42:27.624Z,1574800947.624 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2019-11-26T20:42:27.625Z,1574800947.625 [RDI_Pathfinder](ERROR): Failed to parse: :TS,19112613542732,35.0, -0.1, 0.0, 0 2019-11-26T20:43:46.446Z,1574801026.446 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-11-26T20:38:46.3Z 2019-11-26T20:43:46.446Z,1574801026.446 [Default:CheckIn:Read_GPS] Stopped 2019-11-26T20:43:46.448Z,1574801026.448 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-11-26T20:43:50.019Z,1574801030.019 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-11-26T20:43:56.218Z,1574801036.218 [DataOverHttps](INFO): Sending 280 bytes from file Logs/20191126T185625/Express0049.lzma 2019-11-26T20:43:58.219Z,1574801038.219 [DataOverHttps](INFO): Moved sent file to Logs/20191126T185625/Express0049.lzma.bak 2019-11-26T20:43:58.219Z,1574801038.219 [DataOverHttps](INFO): SBD MOMSN=12107612 2019-11-26T20:44:00.563Z,1574801040.563 [Default:CheckIn:Read_Iridium] Stopped 2019-11-26T20:44:00.563Z,1574801040.563 [Default:CheckIn:C.Wait] Running Loop=1 2019-11-26T20:44:00.563Z,1574801040.563 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-11-26T20:44:20.736Z,1574801060.736 [NAL9602](INFO): Not Powering down - fast GPS 2019-11-26T20:46:33.282Z,1574801193.282 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.107967 2019-11-26T20:47:22.470Z,1574801242.470 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.011825 2019-11-26T20:49:01.234Z,1574801341.234 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-11-26T20:49:01.234Z,1574801341.234 [Default:CheckIn:C.Wait] Stopped 2019-11-26T20:49:01.234Z,1574801341.234 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-11-26T20:49:01.234Z,1574801341.234 [Default:CheckIn:D] Running Loop=1 2019-11-26T20:49:01.575Z,1574801341.575 [Default:CheckIn:D] Stopped 2019-11-26T20:49:01.576Z,1574801341.576 [Default:CheckIn:E] Running Loop=1 2019-11-26T20:49:02.015Z,1574801342.015 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 150.692871 min 2019-11-26T20:49:02.015Z,1574801342.015 [Default:CheckIn:E] Stopped 2019-11-26T20:49:02.016Z,1574801342.016 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-11-26T20:49:02.016Z,1574801342.016 [Default:CheckIn] Stopped 2019-11-26T20:49:02.016Z,1574801342.016 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-11-26T20:49:02.016Z,1574801342.016 [Default:CheckIn](INFO): Running loop #24 2019-11-26T20:49:02.016Z,1574801342.016 [Default:CheckIn] Running Loop=24 2019-11-26T20:49:02.021Z,1574801342.021 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-11-26T20:49:02.021Z,1574801342.021 [Default:CheckIn:Read_GPS] Running Loop=1 2019-11-26T20:49:34.648Z,1574801374.648 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2019-11-26T20:49:34.722Z,1574801374.722 [NAL9602](FAULT): received: +CSQ:0 OK062, 2, 0, 0, 0 OK 2019-11-26T20:49:34.723Z,1574801374.723 [NAL9602] Data Fault, FailCount= 4 2019-11-26T20:49:34.723Z,1574801374.723 [NAL9602](ERROR): Data Fault 2019-11-26T20:49:34.820Z,1574801374.820 [CBIT](ERROR): Data Fault in component: NAL9602 2019-11-26T20:49:35.088Z,1574801375.088 [NAL9602](INFO): Powering down 2019-11-26T20:49:35.921Z,1574801375.921 [CBIT](INFO): Clearing failed state for component NAL9602 2019-11-26T20:49:35.922Z,1574801375.922 [NAL9602] No Fault, FailCount= 4 2019-11-26T20:50:05.386Z,1574801405.386 [NAL9602](INFO): Powering up NAL9602 2019-11-26T20:50:16.288Z,1574801416.288 [NAL9602](INFO): NAL9602 initialized 2019-11-26T20:53:18.928Z,1574801598.928 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude 2019-11-26T20:53:18.929Z,1574801598.929 [RDI_Pathfinder](ERROR): Failed to parse: :BD, +0.0 +0.00, +0.00, 0.00,1490.90 2019-11-26T20:54:02.167Z,1574801642.167 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-11-26T20:49:02.0Z 2019-11-26T20:54:02.168Z,1574801642.168 [Default:CheckIn:Read_GPS] Stopped 2019-11-26T20:54:02.168Z,1574801642.168 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-11-26T20:54:06.540Z,1574801646.540 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-11-26T20:54:13.983Z,1574801653.983 [DataOverHttps](INFO): Sending 256 bytes from file Logs/20191126T185625/Express0052.lzma 2019-11-26T20:54:15.988Z,1574801655.988 [DataOverHttps](INFO): Moved sent file to Logs/20191126T185625/Express0052.lzma.bak 2019-11-26T20:54:15.988Z,1574801655.988 [DataOverHttps](INFO): SBD MOMSN=12107618 2019-11-26T20:54:18.734Z,1574801658.734 [Default:CheckIn:Read_Iridium] Stopped 2019-11-26T20:54:18.734Z,1574801658.734 [Default:CheckIn:C.Wait] Running Loop=1 2019-11-26T20:54:18.734Z,1574801658.734 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-11-26T20:54:36.972Z,1574801676.972 [NAL9602](INFO): Not Powering down - fast GPS 2019-11-26T20:58:07.941Z,1574801887.941 [RDI_Pathfinder](ERROR): only read 2 of 4 data items 2019-11-26T20:58:07.941Z,1574801887.941 [RDI_Pathfinder](ERROR): Failed to parse: :BS,-32768,32768,V 2019-11-26T20:59:19.495Z,1574801959.495 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-11-26T20:59:19.496Z,1574801959.496 [Default:CheckIn:C.Wait] Stopped 2019-11-26T20:59:19.496Z,1574801959.496 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-11-26T20:59:19.496Z,1574801959.496 [Default:CheckIn:D] Running Loop=1 2019-11-26T20:59:19.913Z,1574801959.913 [Default:CheckIn:D] Stopped 2019-11-26T20:59:19.914Z,1574801959.914 [Default:CheckIn:E] Running Loop=1 2019-11-26T20:59:20.354Z,1574801960.354 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 160.998519 min 2019-11-26T20:59:20.354Z,1574801960.354 [Default:CheckIn:E] Stopped 2019-11-26T20:59:20.354Z,1574801960.354 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-11-26T20:59:20.354Z,1574801960.354 [Default:CheckIn] Stopped 2019-11-26T20:59:20.354Z,1574801960.354 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-11-26T20:59:20.355Z,1574801960.355 [Default:CheckIn](INFO): Running loop #25 2019-11-26T20:59:20.355Z,1574801960.355 [Default:CheckIn] Running Loop=25 2019-11-26T20:59:20.355Z,1574801960.355 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-11-26T20:59:20.355Z,1574801960.355 [Default:CheckIn:Read_GPS] Running Loop=1 2019-11-26T20:59:21.841Z,1574801961.841 [NAL9602](FAULT): GPS failed to acquire within timeout. 2019-11-26T20:59:21.841Z,1574801961.841 [NAL9602] Data Fault, FailCount= 5 2019-11-26T20:59:21.841Z,1574801961.841 [NAL9602](ERROR): Data Fault 2019-11-26T20:59:22.021Z,1574801962.021 [CBIT](ERROR): Data Fault in component: NAL9602 2019-11-26T20:59:22.022Z,1574801962.022 [CBIT](CRITICAL): Data Fault in component: NAL9602 2019-11-26T20:59:22.246Z,1574801962.246 [NAL9602](INFO): Powering down 2019-11-26T20:59:22.355Z,1574801962.355 [CBIT](INFO): Critical error at 20191126T205922 2019-11-26T20:59:22.355Z,1574801962.355 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals 2019-11-26T21:01:21.922Z,1574802081.922 [CBIT](INFO): Clearing failed state for component NAL9602 2019-11-26T21:01:21.922Z,1574802081.922 [NAL9602] No Fault, FailCount= 5 2019-11-26T21:01:22.242Z,1574802082.242 [NAL9602](INFO): Powering up NAL9602 2019-11-26T21:01:33.128Z,1574802093.128 [NAL9602](INFO): NAL9602 initialized 2019-11-26T21:04:20.435Z,1574802260.435 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-11-26T20:59:20.4Z 2019-11-26T21:04:20.435Z,1574802260.435 [Default:CheckIn:Read_GPS] Stopped 2019-11-26T21:04:20.435Z,1574802260.435 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-11-26T21:04:28.949Z,1574802268.949 [DataOverHttps](INFO): Sending 93 bytes from file Logs/20191126T185625/Courier0054.lzma 2019-11-26T21:04:30.955Z,1574802270.955 [DataOverHttps](INFO): Moved sent file to Logs/20191126T185625/Courier0054.lzma.bak 2019-11-26T21:04:30.955Z,1574802270.955 [DataOverHttps](INFO): SBD MOMSN=12107623 2019-11-26T21:04:52.717Z,1574802292.717 [DataOverHttps](INFO): Sending 240 bytes from file Logs/20191126T185625/Express0055.lzma 2019-11-26T21:04:54.723Z,1574802294.723 [DataOverHttps](INFO): Moved sent file to Logs/20191126T185625/Express0055.lzma.bak 2019-11-26T21:04:54.723Z,1574802294.723 [DataOverHttps](INFO): SBD MOMSN=12107626 2019-11-26T21:04:58.456Z,1574802298.456 [Default:CheckIn:Read_Iridium] Stopped 2019-11-26T21:04:58.456Z,1574802298.456 [Default:CheckIn:C.Wait] Running Loop=1 2019-11-26T21:04:58.456Z,1574802298.456 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-11-26T21:06:36.551Z,1574802396.551 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-11-26T21:07:07.266Z,1574802427.266 [NAL9602](INFO): Not Powering down - fast GPS 2019-11-26T21:09:49.306Z,1574802589.306 [RDI_Pathfinder](ERROR): Failed to parse: :BE,-32768,-32768,-32768,V 2019-11-26T21:09:58.995Z,1574802598.995 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-11-26T21:09:58.995Z,1574802598.995 [Default:CheckIn:C.Wait] Stopped 2019-11-26T21:09:58.995Z,1574802598.995 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-11-26T21:09:58.996Z,1574802598.996 [Default:CheckIn:D] Running Loop=1 2019-11-26T21:09:59.398Z,1574802599.398 [Default:CheckIn:D] Stopped 2019-11-26T21:09:59.398Z,1574802599.398 [Default:CheckIn:E] Running Loop=1 2019-11-26T21:09:59.793Z,1574802599.793 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 171.656592 min 2019-11-26T21:09:59.793Z,1574802599.793 [Default:CheckIn:E] Stopped 2019-11-26T21:09:59.793Z,1574802599.793 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-11-26T21:09:59.793Z,1574802599.793 [Default:CheckIn] Stopped 2019-11-26T21:09:59.794Z,1574802599.794 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-11-26T21:09:59.794Z,1574802599.794 [Default:CheckIn](INFO): Running loop #26 2019-11-26T21:09:59.794Z,1574802599.794 [Default:CheckIn] Running Loop=26 2019-11-26T21:09:59.794Z,1574802599.794 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-11-26T21:09:59.794Z,1574802599.794 [Default:CheckIn:Read_GPS] Running Loop=1 2019-11-26T21:10:32.485Z,1574802632.485 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2019-11-26T21:10:32.569Z,1574802632.569 [NAL9602](FAULT): received: +CSQ:0 OK062, 2, 0, 0, 0 OK 2019-11-26T21:10:32.569Z,1574802632.569 [NAL9602] Data Fault, FailCount= 1 2019-11-26T21:10:32.569Z,1574802632.569 [NAL9602](ERROR): Data Fault 2019-11-26T21:10:32.654Z,1574802632.654 [CBIT](ERROR): Data Fault in component: NAL9602 2019-11-26T21:10:32.903Z,1574802632.903 [NAL9602](INFO): Powering down 2019-11-26T21:10:33.733Z,1574802633.733 [CBIT](INFO): Clearing failed state for component NAL9602 2019-11-26T21:10:33.733Z,1574802633.733 [NAL9602] No Fault, FailCount= 1 2019-11-26T21:11:03.211Z,1574802663.211 [NAL9602](INFO): Powering up NAL9602 2019-11-26T21:11:14.113Z,1574802674.113 [NAL9602](INFO): NAL9602 initialized 2019-11-26T21:12:05.447Z,1574802725.447 [RDI_Pathfinder](ERROR): only read 3 of 4 data items 2019-11-26T21:12:05.448Z,1574802725.448 [RDI_Pathfinder](ERROR): Failed to parse: :RA, 0.00, 0.00, 0.00, 0.00 2019-11-26T21:12:32.928Z,1574802752.928 [RDI_Pathfinder](ERROR): only read 2 of 4 data items 2019-11-26T21:12:32.935Z,1574802752.935 [RDI_Pathfinder](ERROR): Failed to parse: :BS,-3768,-32768,V 2019-11-26T21:14:06.264Z,1574802846.264 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude 2019-11-26T21:14:06.273Z,1574802846.273 [RDI_Pathfinder](ERROR): Failed to parse: :BD, +0.00, +0.00, , 0.00,2737.67 2019-11-26T21:14:32.923Z,1574802872.923 [RDI_Pathfinder](ERROR): only read 1 of 4 data items 2019-11-26T21:14:32.923Z,1574802872.923 [RDI_Pathfinder](ERROR): Failed to parse: :BS,-3276,- 2019-11-26T21:14:59.996Z,1574802899.996 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-11-26T21:09:59.8Z 2019-11-26T21:14:59.996Z,1574802899.996 [Default:CheckIn:Read_GPS] Stopped 2019-11-26T21:15:00.001Z,1574802900.001 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-11-26T21:15:03.983Z,1574802903.983 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-11-26T21:15:07.215Z,1574802907.215 [DataOverHttps](INFO): Sending 262 bytes from file Logs/20191126T185625/Express0058.lzma 2019-11-26T21:15:09.218Z,1574802909.218 [DataOverHttps](INFO): Moved sent file to Logs/20191126T185625/Express0058.lzma.bak 2019-11-26T21:15:09.219Z,1574802909.219 [DataOverHttps](INFO): SBD MOMSN=12107631 2019-11-26T21:15:11.300Z,1574802911.300 [Default:CheckIn:Read_Iridium] Stopped 2019-11-26T21:15:11.305Z,1574802911.305 [Default:CheckIn:C.Wait] Running Loop=1 2019-11-26T21:15:11.305Z,1574802911.305 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-11-26T21:15:34.691Z,1574802934.691 [NAL9602](INFO): Not Powering down - fast GPS 2019-11-26T21:20:11.937Z,1574803211.937 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-11-26T21:20:11.937Z,1574803211.937 [Default:CheckIn:C.Wait] Stopped 2019-11-26T21:20:11.937Z,1574803211.937 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-11-26T21:20:11.937Z,1574803211.937 [Default:CheckIn:D] Running Loop=1 2019-11-26T21:20:12.297Z,1574803212.297 [Default:CheckIn:D] Stopped 2019-11-26T21:20:12.297Z,1574803212.297 [Default:CheckIn:E] Running Loop=1 2019-11-26T21:20:12.701Z,1574803212.701 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 181.871566 min 2019-11-26T21:20:12.701Z,1574803212.701 [Default:CheckIn:E] Stopped 2019-11-26T21:20:12.701Z,1574803212.701 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-11-26T21:20:12.701Z,1574803212.701 [Default:CheckIn] Stopped 2019-11-26T21:20:12.701Z,1574803212.701 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-11-26T21:20:12.702Z,1574803212.702 [Default:CheckIn](INFO): Running loop #27 2019-11-26T21:20:12.702Z,1574803212.702 [Default:CheckIn] Running Loop=27 2019-11-26T21:20:12.702Z,1574803212.702 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-11-26T21:20:12.702Z,1574803212.702 [Default:CheckIn:Read_GPS] Running Loop=1 2019-11-26T21:20:14.279Z,1574803214.279 [NAL9602](FAULT): GPS failed to acquire within timeout. 2019-11-26T21:20:14.279Z,1574803214.279 [NAL9602] Data Fault, FailCount= 2 2019-11-26T21:20:14.279Z,1574803214.279 [NAL9602](ERROR): Data Fault 2019-11-26T21:20:14.354Z,1574803214.354 [CBIT](ERROR): Data Fault in component: NAL9602 2019-11-26T21:20:14.687Z,1574803214.687 [NAL9602](INFO): Powering down 2019-11-26T21:20:15.537Z,1574803215.537 [CBIT](INFO): Clearing failed state for component NAL9602 2019-11-26T21:20:15.537Z,1574803215.537 [NAL9602] No Fault, FailCount= 2 2019-11-26T21:20:27.635Z,1574803227.635 [RDI_Pathfinder](ERROR): only read 3 of 4 data items 2019-11-26T21:20:27.636Z,1574803227.636 [RDI_Pathfinder](ERROR): Failed to parse: :RA, 0.00, 0.00, 0.00, 0.00 2019-11-26T21:20:44.979Z,1574803244.979 [NAL9602](INFO): Powering up NAL9602 2019-11-26T21:20:55.888Z,1574803255.888 [NAL9602](INFO): NAL9602 initialized 2019-11-26T21:22:06.630Z,1574803326.630 [RDI_Pathfinder](ERROR): Failed to parse:.00, 0.00, 0.00, 0.00 2019-11-26T21:22:11.909Z,1574803331.909 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude 2019-11-26T21:22:11.909Z,1574803331.909 [RDI_Pathfinder](ERROR): Failed to parse: :BD, +0 +0.00, +0.00, 0.00,3223.55 2019-11-26T21:23:51.270Z,1574803431.270 [RDI_Pathfinder](ERROR): only read 3 of 4 data items 2019-11-26T21:23:51.270Z,1574803431.270 [RDI_Pathfinder](ERROR): Failed to parse: :RA, 0.00, 0.00, 0.00, 0.00 2019-11-26T21:24:52.282Z,1574803492.282 [RDI_Pathfinder](ERROR): Failed to parse: :BE,-32768,-32768,-32768,V 2019-11-26T21:25:12.922Z,1574803512.922 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-11-26T21:20:12.7Z 2019-11-26T21:25:12.922Z,1574803512.922 [Default:CheckIn:Read_GPS] Stopped 2019-11-26T21:25:12.922Z,1574803512.922 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-11-26T21:25:20.875Z,1574803520.875 [DataOverHttps](INFO): Sending 234 bytes from file Logs/20191126T185625/Express0061.lzma 2019-11-26T21:25:22.878Z,1574803522.878 [DataOverHttps](INFO): Moved sent file to Logs/20191126T185625/Express0061.lzma.bak 2019-11-26T21:25:22.878Z,1574803522.878 [DataOverHttps](INFO): SBD MOMSN=12107636 2019-11-26T21:25:25.040Z,1574803525.040 [Default:CheckIn:Read_Iridium] Stopped 2019-11-26T21:25:25.040Z,1574803525.040 [Default:CheckIn:C.Wait] Running Loop=1 2019-11-26T21:25:25.045Z,1574803525.045 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-11-26T21:25:32.273Z,1574803532.273 [RDI_Pathfinder](ERROR): Failed to parse: 00, 0.00, 0.00, 0.00, 0.00 2019-11-26T21:25:59.315Z,1574803559.315 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-11-26T21:26:30.019Z,1574803590.019 [NAL9602](INFO): Not Powering down - fast GPS 2019-11-26T21:29:22.143Z,1574803762.143 [RDI_Pathfinder](ERROR): only read 2 of 4 data items 2019-11-26T21:29:22.144Z,1574803762.144 [RDI_Pathfinder](ERROR): Failed to parse: :BS,-32768,-3278,V 2019-11-26T21:30:25.605Z,1574803825.605 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-11-26T21:30:25.605Z,1574803825.605 [Default:CheckIn:C.Wait] Stopped 2019-11-26T21:30:25.605Z,1574803825.605 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-11-26T21:30:25.605Z,1574803825.605 [Default:CheckIn:D] Running Loop=1 2019-11-26T21:30:26.003Z,1574803826.003 [Default:CheckIn:D] Stopped 2019-11-26T21:30:26.003Z,1574803826.003 [Default:CheckIn:E] Running Loop=1 2019-11-26T21:30:26.400Z,1574803826.400 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 192.100000 min 2019-11-26T21:30:26.400Z,1574803826.400 [Default:CheckIn:E] Stopped 2019-11-26T21:30:26.400Z,1574803826.400 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-11-26T21:30:26.400Z,1574803826.400 [Default:CheckIn] Stopped 2019-11-26T21:30:26.400Z,1574803826.400 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-11-26T21:30:26.400Z,1574803826.400 [Default:CheckIn](INFO): Running loop #28 2019-11-26T21:30:26.401Z,1574803826.401 [Default:CheckIn] Running Loop=28 2019-11-26T21:30:26.401Z,1574803826.401 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-11-26T21:30:26.401Z,1574803826.401 [Default:CheckIn:Read_GPS] Running Loop=1 2019-11-26T21:30:51.042Z,1574803851.042 [BPC1](ERROR): BPC1B: No match for serial number 1717 in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file). 2019-11-26T21:30:59.087Z,1574803859.087 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2019-11-26T21:30:59.161Z,1574803859.161 [NAL9602](FAULT): received: +CSQ:0 OK062, 2, 0, 0, 0 OK 2019-11-26T21:30:59.161Z,1574803859.161 [NAL9602] Data Fault, FailCount= 3 2019-11-26T21:30:59.161Z,1574803859.161 [NAL9602](ERROR): Data Fault 2019-11-26T21:30:59.277Z,1574803859.277 [CBIT](ERROR): Data Fault in component: NAL9602 2019-11-26T21:30:59.495Z,1574803859.495 [NAL9602](INFO): Powering down 2019-11-26T21:31:00.345Z,1574803860.345 [CBIT](INFO): Clearing failed state for component NAL9602 2019-11-26T21:31:00.345Z,1574803860.345 [NAL9602] No Fault, FailCount= 3 2019-11-26T21:31:29.807Z,1574803889.807 [NAL9602](INFO): Powering up NAL9602 2019-11-26T21:31:40.703Z,1574803900.703 [NAL9602](INFO): NAL9602 initialized 2019-11-26T21:31:41.507Z,1574803901.507 [NAL9602](FAULT): GPS failed to acquire within timeout. 2019-11-26T21:31:41.507Z,1574803901.507 [NAL9602] Data Fault, FailCount= 4 2019-11-26T21:31:41.507Z,1574803901.507 [NAL9602](ERROR): Data Fault 2019-11-26T21:31:41.573Z,1574803901.573 [CBIT](ERROR): Data Fault in component: NAL9602 2019-11-26T21:31:41.912Z,1574803901.912 [NAL9602](INFO): Powering down 2019-11-26T21:31:42.777Z,1574803902.777 [CBIT](INFO): Clearing failed state for component NAL9602 2019-11-26T21:31:42.777Z,1574803902.777 [NAL9602] No Fault, FailCount= 4 2019-11-26T21:32:12.223Z,1574803932.223 [NAL9602](INFO): Powering up NAL9602 2019-11-26T21:32:23.135Z,1574803943.135 [NAL9602](INFO): NAL9602 initialized 2019-11-26T21:35:26.610Z,1574804126.610 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-11-26T21:30:26.4Z 2019-11-26T21:35:26.610Z,1574804126.610 [Default:CheckIn:Read_GPS] Stopped 2019-11-26T21:35:26.610Z,1574804126.610 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-11-26T21:35:30.195Z,1574804130.195 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-11-26T21:35:37.625Z,1574804137.625 [DataOverHttps](INFO): Sending 269 bytes from file Logs/20191126T185625/Express0064.lzma 2019-11-26T21:35:39.630Z,1574804139.630 [DataOverHttps](INFO): Moved sent file to Logs/20191126T185625/Express0064.lzma.bak 2019-11-26T21:35:39.631Z,1574804139.631 [DataOverHttps](INFO): SBD MOMSN=12107641 2019-11-26T21:35:42.095Z,1574804142.095 [Default:CheckIn:Read_Iridium] Stopped 2019-11-26T21:35:42.095Z,1574804142.095 [Default:CheckIn:C.Wait] Running Loop=1 2019-11-26T21:35:42.095Z,1574804142.095 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-11-26T21:35:47.679Z,1574804147.679 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2019-11-26T21:35:47.681Z,1574804147.681 [BPC1](INFO): Received data from all battery sticks. 2019-11-26T21:36:00.995Z,1574804160.995 [NAL9602](INFO): Not Powering down - fast GPS 2019-11-26T21:37:34.338Z,1574804254.338 [RDI_Pathfinder](ERROR): only read 3 of 4 data items 2019-11-26T21:37:34.338Z,1574804254.338 [RDI_Pathfinder](ERROR): Failed to parse: :RA, 0.00, 0.00, 0.00, 0.00 2019-11-26T21:37:48.969Z,1574804268.969 [RDI_Pathfinder](ERROR): DVL uart error: serial timeout 2019-11-26T21:37:48.969Z,1574804268.969 [RDI_Pathfinder] Communications Fault, FailCount= 1 2019-11-26T21:37:48.969Z,1574804268.969 [RDI_Pathfinder](ERROR): Communications Fault 2019-11-26T21:37:48.969Z,1574804268.969 [RDI_Pathfinder](ERROR): Failed to parse: 2019-11-26T21:37:48.996Z,1574804268.996 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder 2019-11-26T21:37:49.361Z,1574804269.361 [RDI_Pathfinder](INFO): Powering down 2019-11-26T21:37:50.106Z,1574804270.106 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder 2019-11-26T21:37:50.106Z,1574804270.106 [RDI_Pathfinder] No Fault, FailCount= 1 2019-11-26T21:38:03.429Z,1574804283.429 [RDI_Pathfinder](ERROR): Failed to parse:Pathfinder 2019-11-26T21:38:35.392Z,1574804315.392 [RDI_Pathfinder](ERROR): Failed to parse: :BE,-32768,-32768,-32768,V 2019-11-26T21:40:42.669Z,1574804442.669 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-11-26T21:40:42.669Z,1574804442.669 [Default:CheckIn:C.Wait] Stopped 2019-11-26T21:40:42.669Z,1574804442.669 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-11-26T21:40:42.670Z,1574804442.670 [Default:CheckIn:D] Running Loop=1 2019-11-26T21:40:43.051Z,1574804443.051 [Default:CheckIn:D] Stopped 2019-11-26T21:40:43.051Z,1574804443.051 [Default:CheckIn:E] Running Loop=1 2019-11-26T21:40:43.461Z,1574804443.461 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 202.384147 min 2019-11-26T21:40:43.461Z,1574804443.461 [Default:CheckIn:E] Stopped 2019-11-26T21:40:43.461Z,1574804443.461 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-11-26T21:40:43.461Z,1574804443.461 [Default:CheckIn] Stopped 2019-11-26T21:40:43.461Z,1574804443.461 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-11-26T21:40:43.461Z,1574804443.461 [Default:CheckIn](INFO): Running loop #29 2019-11-26T21:40:43.461Z,1574804443.461 [Default:CheckIn] Running Loop=29 2019-11-26T21:40:43.462Z,1574804443.462 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-11-26T21:40:43.462Z,1574804443.462 [Default:CheckIn:Read_GPS] Running Loop=1 2019-11-26T21:41:55.763Z,1574804515.763 [RDI_Pathfinder](ERROR): only read 0 of 4 data items 2019-11-26T21:41:55.764Z,1574804515.764 [RDI_Pathfinder](ERROR): Failed to parse: :BS-32768,-32768,V 2019-11-26T21:42:58.785Z,1574804578.785 [RDI_Pathfinder](ERROR): only read 2 of 4 data items 2019-11-26T21:42:58.785Z,1574804578.785 [RDI_Pathfinder](ERROR): Failed to parse: :BS,-32768,-2768,V 2019-11-26T21:44:13.545Z,1574804653.545 [RDI_Pathfinder](ERROR): Failed to parse: :SA, +0.00, +0.00, 0.00 2019-11-26T21:44:32.102Z,1574804672.102 [RDI_Pathfinder](ERROR): only read 3 of 4 data items 2019-11-26T21:44:32.103Z,1574804672.103 [RDI_Pathfinder](ERROR): Failed to parse: :RA, 0.00, 0.00, 0.00, 0.00 2019-11-26T21:45:17.742Z,1574804717.742 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2019-11-26T21:45:17.743Z,1574804717.743 [RDI_Pathfinder](ERROR): Failed to parse: :TS,19112614571781,35.0, 0.0,1448.9, 0 2019-11-26T21:45:33.110Z,1574804733.110 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2019-11-26T21:45:33.110Z,1574804733.110 [RDI_Pathfinder](ERROR): Failed to parse: :TS,191126145732810.1, 0.0,1448:RA, 0.00, 0.00, 0.00, 0.00, 0.00 2019-11-26T21:45:43.645Z,1574804743.645 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-11-26T21:40:43.5Z 2019-11-26T21:45:43.645Z,1574804743.645 [Default:CheckIn:Read_GPS] Stopped 2019-11-26T21:45:43.645Z,1574804743.645 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-11-26T21:45:48.027Z,1574804748.027 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-11-26T21:45:51.408Z,1574804751.408 [DataOverHttps](INFO): Sending 46 bytes from file Logs/20191126T185625/Courier0066.lzma 2019-11-26T21:45:53.414Z,1574804753.414 [DataOverHttps](INFO): Moved sent file to Logs/20191126T185625/Courier0066.lzma.bak 2019-11-26T21:45:53.415Z,1574804753.415 [DataOverHttps](INFO): SBD MOMSN=12107647 2019-11-26T21:46:11.113Z,1574804771.113 [DataOverHttps](INFO): Sending 219 bytes from file Logs/20191126T185625/Express0067.lzma 2019-11-26T21:46:13.119Z,1574804773.119 [DataOverHttps](INFO): Moved sent file to Logs/20191126T185625/Express0067.lzma.bak 2019-11-26T21:46:13.119Z,1574804773.119 [DataOverHttps](INFO): SBD MOMSN=12107649 2019-11-26T21:46:15.569Z,1574804775.569 [Default:CheckIn:Read_Iridium] Stopped 2019-11-26T21:46:15.569Z,1574804775.569 [Default:CheckIn:C.Wait] Running Loop=1 2019-11-26T21:46:15.569Z,1574804775.569 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-11-26T21:46:18.731Z,1574804778.731 [NAL9602](INFO): Not Powering down - fast GPS 2019-11-26T21:51:04.427Z,1574805064.427 [CBIT](IMPORTANT): Beginning ground fault scan 2019-11-26T21:51:15.400Z,1574805075.400 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.019641 CHAN A1 (24V): -0.026242 CHAN A2 (12V): -0.007597 CHAN A3 (5V): -0.002474 CHAN B0 (3.3V): 0.000390 CHAN B1 (3.15aV): 0.000063 CHAN B2 (3.15bV): 0.000392 CHAN B3 (GND): 0.001869 OPEN: 0.005262 Full Scale Calc: 4.765 mA, -1.589 mA 2019-11-26T21:51:16.115Z,1574805076.115 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-11-26T21:51:16.115Z,1574805076.115 [Default:CheckIn:C.Wait] Stopped 2019-11-26T21:51:16.115Z,1574805076.115 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-11-26T21:51:16.115Z,1574805076.115 [Default:CheckIn:D] Running Loop=1 2019-11-26T21:51:16.526Z,1574805076.526 [Default:CheckIn:D] Stopped 2019-11-26T21:51:16.526Z,1574805076.526 [Default:CheckIn:E] Running Loop=1 2019-11-26T21:51:16.923Z,1574805076.923 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 212.942041 min 2019-11-26T21:51:16.923Z,1574805076.923 [Default:CheckIn:E] Stopped 2019-11-26T21:51:16.923Z,1574805076.923 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-11-26T21:51:16.923Z,1574805076.923 [Default:CheckIn] Stopped 2019-11-26T21:51:16.923Z,1574805076.923 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-11-26T21:51:16.923Z,1574805076.923 [Default:CheckIn](INFO): Running loop #30 2019-11-26T21:51:16.923Z,1574805076.923 [Default:CheckIn] Running Loop=30 2019-11-26T21:51:16.923Z,1574805076.923 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-11-26T21:51:16.923Z,1574805076.923 [Default:CheckIn:Read_GPS] Running Loop=1 2019-11-26T21:51:18.503Z,1574805078.503 [NAL9602](FAULT): GPS failed to acquire within timeout. 2019-11-26T21:51:18.503Z,1574805078.503 [NAL9602] Data Fault, FailCount= 5 2019-11-26T21:51:18.503Z,1574805078.503 [NAL9602](ERROR): Data Fault 2019-11-26T21:51:18.585Z,1574805078.585 [CBIT](ERROR): Data Fault in component: NAL9602 2019-11-26T21:51:18.585Z,1574805078.585 [CBIT](CRITICAL): Data Fault in component: NAL9602 2019-11-26T21:51:18.907Z,1574805078.907 [NAL9602](INFO): Powering down 2019-11-26T21:51:18.958Z,1574805078.958 [CBIT](INFO): Critical error at 20191126T215118 2019-11-26T21:53:18.539Z,1574805198.539 [CBIT](INFO): Clearing failed state for component NAL9602 2019-11-26T21:53:18.539Z,1574805198.539 [NAL9602] No Fault, FailCount= 5 2019-11-26T21:53:18.895Z,1574805198.895 [NAL9602](INFO): Powering up NAL9602 2019-11-26T21:53:29.798Z,1574805209.798 [NAL9602](INFO): NAL9602 initialized 2019-11-26T21:55:29.447Z,1574805329.447 [RDI_Pathfinder](ERROR): Failed to parse: :BE,-32768,-32768,-32768,V 2019-11-26T21:56:17.111Z,1574805377.111 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-11-26T21:51:16.9Z 2019-11-26T21:56:17.111Z,1574805377.111 [Default:CheckIn:Read_GPS] Stopped 2019-11-26T21:56:17.111Z,1574805377.111 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-11-26T21:56:24.777Z,1574805384.777 [DataOverHttps](INFO): Sending 70 bytes from file Logs/20191126T185625/Courier0069.lzma 2019-11-26T21:56:26.783Z,1574805386.783 [DataOverHttps](INFO): Moved sent file to Logs/20191126T185625/Courier0069.lzma.bak 2019-11-26T21:56:26.783Z,1574805386.783 [DataOverHttps](INFO): SBD MOMSN=12107653 2019-11-26T21:56:45.599Z,1574805405.599 [DataOverHttps](INFO): Sending 437 bytes from file Logs/20191126T185625/Express0070.lzma 2019-11-26T21:56:47.615Z,1574805407.615 [DataOverHttps](INFO): Moved sent file to Logs/20191126T185625/Express0070.lzma.bak 2019-11-26T21:56:47.615Z,1574805407.615 [DataOverHttps](INFO): SBD MOMSN=12107656 2019-11-26T21:56:49.855Z,1574805409.855 [Default:CheckIn:Read_Iridium] Stopped 2019-11-26T21:56:49.856Z,1574805409.856 [Default:CheckIn:C.Wait] Running Loop=1 2019-11-26T21:56:49.856Z,1574805409.856 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-11-26T21:57:23.781Z,1574805443.781 [RDI_Pathfinder](ERROR): only read 2 of 4 data items 2019-11-26T21:57:23.781Z,1574805443.781 [RDI_Pathfinder](ERROR): Failed to parse: :BS,-32768,-3768,V 2019-11-26T21:57:29.454Z,1574805449.454 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude 2019-11-26T21:57:29.455Z,1574805449.455 [RDI_Pathfinder](ERROR): Failed to parse: :BD, +0.00, +0.00, , 0.00,1165.94 2019-11-26T21:58:33.232Z,1574805513.232 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-11-26T21:58:50.651Z,1574805530.651 [RDI_Pathfinder](ERROR): Failed to parse: :SA, +0.00, +0.00, 0.00 2019-11-26T21:59:03.935Z,1574805543.935 [NAL9602](INFO): Not Powering down - fast GPS 2019-11-26T22:00:00.550Z,1574805600.550 [RDI_Pathfinder](ERROR): Failed to parse: :8,-32768,-32768,V 2019-11-26T22:01:04.383Z,1574805664.383 [RDI_Pathfinder](ERROR): only read 2 of 4 data items 2019-11-26T22:01:04.383Z,1574805664.383 [RDI_Pathfinder](ERROR): Failed to parse: :BS,-32768,-3276,V 2019-11-26T22:01:50.428Z,1574805710.428 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-11-26T22:01:50.428Z,1574805710.428 [Default:CheckIn:C.Wait] Stopped 2019-11-26T22:01:50.428Z,1574805710.428 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-11-26T22:01:50.428Z,1574805710.428 [Default:CheckIn:D] Running Loop=1 2019-11-26T22:01:50.848Z,1574805710.848 [Default:CheckIn:D] Stopped 2019-11-26T22:01:50.848Z,1574805710.848 [Default:CheckIn:E] Running Loop=1 2019-11-26T22:01:51.246Z,1574805711.246 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 223.514095 min 2019-11-26T22:01:51.247Z,1574805711.247 [Default:CheckIn:E] Stopped 2019-11-26T22:01:51.247Z,1574805711.247 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-11-26T22:01:51.247Z,1574805711.247 [Default:CheckIn] Stopped 2019-11-26T22:01:51.247Z,1574805711.247 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-11-26T22:01:51.247Z,1574805711.247 [Default:CheckIn](INFO): Running loop #31 2019-11-26T22:01:51.247Z,1574805711.247 [Default:CheckIn] Running Loop=31 2019-11-26T22:01:51.247Z,1574805711.247 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-11-26T22:01:51.247Z,1574805711.247 [Default:CheckIn:Read_GPS] Running Loop=1 2019-11-26T22:02:23.923Z,1574805743.923 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2019-11-26T22:02:24.001Z,1574805744.001 [NAL9602](FAULT): received: +CSQ:0 OK062, 2, 0, 0, 0 OK 2019-11-26T22:02:24.001Z,1574805744.001 [NAL9602] Data Fault, FailCount= 1 2019-11-26T22:02:24.001Z,1574805744.001 [NAL9602](ERROR): Data Fault 2019-11-26T22:02:24.093Z,1574805744.093 [CBIT](ERROR): Data Fault in component: NAL9602 2019-11-26T22:02:24.335Z,1574805744.335 [NAL9602](INFO): Powering down 2019-11-26T22:02:25.188Z,1574805745.188 [CBIT](INFO): Clearing failed state for component NAL9602 2019-11-26T22:02:25.193Z,1574805745.193 [NAL9602] No Fault, FailCount= 1 2019-11-26T22:02:45.382Z,1574805765.382 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude 2019-11-26T22:02:45.382Z,1574805765.382 [RDI_Pathfinder](ERROR): Failed to parse: :BD, +0 +0.00, +0.00, 0.00,1481.90 2019-11-26T22:02:54.627Z,1574805774.627 [NAL9602](INFO): Powering up NAL9602 2019-11-26T22:03:05.529Z,1574805785.529 [NAL9602](INFO): NAL9602 initialized 2019-11-26T22:04:43.742Z,1574805883.742 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2019-11-26T22:04:43.742Z,1574805883.742 [RDI_Pathfinder](ERROR): Failed to parse: :TS,19112615164381,35.0 0.0,1448.9, 0 2019-11-26T22:06:05.737Z,1574805965.737 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2019-11-26T22:06:05.737Z,1574805965.737 [RDI_Pathfinder](ERROR): Failed to parse: :TS,19112615180581,35, 0.0,1448.9, 0 2019-11-26T22:06:42.101Z,1574806002.101 [RDI_Pathfinder](ERROR): Failed to parse: :8,-32768,-32768,V 2019-11-26T22:06:51.409Z,1574806011.409 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-11-26T22:01:51.2Z 2019-11-26T22:06:51.409Z,1574806011.409 [Default:CheckIn:Read_GPS] Stopped 2019-11-26T22:06:51.409Z,1574806011.409 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-11-26T22:06:55.411Z,1574806015.411 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-11-26T22:06:59.217Z,1574806019.217 [DataOverHttps](INFO): Sending 268 bytes from file Logs/20191126T185625/Express0073.lzma 2019-11-26T22:07:01.222Z,1574806021.222 [DataOverHttps](INFO): Moved sent file to Logs/20191126T185625/Express0073.lzma.bak 2019-11-26T22:07:01.223Z,1574806021.223 [DataOverHttps](INFO): SBD MOMSN=12107663 2019-11-26T22:07:03.570Z,1574806023.570 [Default:CheckIn:Read_Iridium] Stopped 2019-11-26T22:07:03.570Z,1574806023.570 [Default:CheckIn:C.Wait] Running Loop=1 2019-11-26T22:07:03.570Z,1574806023.570 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-11-26T22:07:26.111Z,1574806046.111 [NAL9602](INFO): Not Powering down - fast GPS 2019-11-26T22:08:47.739Z,1574806127.739 [RDI_Pathfinder](ERROR): only read 2 of 4 data items 2019-11-26T22:08:47.739Z,1574806127.739 [RDI_Pathfinder](ERROR): Failed to parse: :BS,-32768,-3268,V 2019-11-26T22:09:27.365Z,1574806167.365 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude 2019-11-26T22:09:27.365Z,1574806167.365 [RDI_Pathfinder](ERROR): Failed to parse: :BD +0.00, +0.00, +0.00, 0.00,1883.85 2019-11-26T22:11:49.546Z,1574806309.546 [RDI_Pathfinder](ERROR): Failed to parse: :RA, 0.00, 0.00, 0.00, 0.00, 0.00 2019-11-26T22:12:04.100Z,1574806324.100 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-11-26T22:12:04.100Z,1574806324.100 [Default:CheckIn:C.Wait] Stopped 2019-11-26T22:12:04.100Z,1574806324.100 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-11-26T22:12:04.100Z,1574806324.100 [Default:CheckIn:D] Running Loop=1 2019-11-26T22:12:04.513Z,1574806324.513 [Default:CheckIn:D] Stopped 2019-11-26T22:12:04.513Z,1574806324.513 [Default:CheckIn:E] Running Loop=1 2019-11-26T22:12:04.916Z,1574806324.916 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 233.741829 min 2019-11-26T22:12:04.916Z,1574806324.916 [Default:CheckIn:E] Stopped 2019-11-26T22:12:04.916Z,1574806324.916 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-11-26T22:12:04.916Z,1574806324.916 [Default:CheckIn] Stopped 2019-11-26T22:12:04.916Z,1574806324.916 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-11-26T22:12:04.916Z,1574806324.916 [Default:CheckIn](INFO): Running loop #32 2019-11-26T22:12:04.917Z,1574806324.917 [Default:CheckIn] Running Loop=32 2019-11-26T22:12:04.917Z,1574806324.917 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-11-26T22:12:04.917Z,1574806324.917 [Default:CheckIn:Read_GPS] Running Loop=1 2019-11-26T22:12:06.491Z,1574806326.491 [NAL9602](FAULT): GPS failed to acquire within timeout. 2019-11-26T22:12:06.491Z,1574806326.491 [NAL9602] Data Fault, FailCount= 2 2019-11-26T22:12:06.491Z,1574806326.491 [NAL9602](ERROR): Data Fault 2019-11-26T22:12:06.563Z,1574806326.563 [CBIT](ERROR): Data Fault in component: NAL9602 2019-11-26T22:12:06.890Z,1574806326.890 [NAL9602](INFO): Powering down 2019-11-26T22:12:07.748Z,1574806327.748 [CBIT](INFO): Clearing failed state for component NAL9602 2019-11-26T22:12:07.748Z,1574806327.748 [NAL9602] No Fault, FailCount= 2 2019-11-26T22:12:37.191Z,1574806357.191 [NAL9602](INFO): Powering up NAL9602 2019-11-26T22:12:48.103Z,1574806368.103 [NAL9602](INFO): NAL9602 initialized 2019-11-26T22:17:05.079Z,1574806625.079 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-11-26T22:12:04.9Z 2019-11-26T22:17:05.079Z,1574806625.079 [Default:CheckIn:Read_GPS] Stopped 2019-11-26T22:17:05.079Z,1574806625.079 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-11-26T22:17:13.933Z,1574806633.933 [DataOverHttps](INFO): Sending 233 bytes from file Logs/20191126T185625/Express0076.lzma 2019-11-26T22:17:15.939Z,1574806635.939 [DataOverHttps](INFO): Moved sent file to Logs/20191126T185625/Express0076.lzma.bak 2019-11-26T22:17:15.939Z,1574806635.939 [DataOverHttps](INFO): SBD MOMSN=12107668 2019-11-26T22:17:18.019Z,1574806638.019 [Default:CheckIn:Read_Iridium] Stopped 2019-11-26T22:17:18.020Z,1574806638.020 [Default:CheckIn:C.Wait] Running Loop=1 2019-11-26T22:17:18.020Z,1574806638.020 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-11-26T22:17:51.501Z,1574806671.501 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-11-26T22:18:13.763Z,1574806693.763 [RDI_Pathfinder](ERROR): only read 3 of 4 data items 2019-11-26T22:18:13.763Z,1574806693.763 [RDI_Pathfinder](ERROR): Failed to parse: :RA, 0.00, 0.00, 0.00, 0.00 2019-11-26T22:18:19.808Z,1574806699.808 [RDI_Pathfinder](ERROR): only read 2 of 4 data items 2019-11-26T22:18:19.808Z,1574806699.808 [RDI_Pathfinder](ERROR): Failed to parse: :BS,-3278,-32768,V 2019-11-26T22:18:22.207Z,1574806702.207 [NAL9602](INFO): Not Powering down - fast GPS 2019-11-26T22:20:50.910Z,1574806850.910 [RDI_Pathfinder](ERROR): Failed to parse: :BI,-32768,-32768,-32768,-32768,V 2019-11-26T22:21:07.442Z,1574806867.442 [CommandLine](IMPORTANT): got command quit 2019-11-26T22:21:08.449Z,1574806868.449 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2019-11-26T22:21:08.449Z,1574806868.449 [CommandLine ThreadHandler](INFO): Thread cancelled. 2019-11-26T22:21:08.649Z,1574806868.649 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2019-11-26T22:21:08.649Z,1574806868.649 [CommandLine ThreadHandler](INFO): Thread cancelled. 2019-11-26T22:21:08.650Z,1574806868.650 [CommandLine](INFO): Join timeout helper Thread ID is 2553 2019-11-26T22:21:08.653Z,1574806868.653 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2019-11-26T22:21:08.653Z,1574806868.653 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2019-11-26T22:21:08.654Z,1574806868.654 [NavChartDb](INFO): Join timeout helper Thread ID is 2554 2019-11-26T22:21:08.813Z,1574806868.813 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2019-11-26T22:21:08.813Z,1574806868.813 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2019-11-26T22:21:08.829Z,1574806868.829 [ComponentRegistry](INFO): Shutting down WetLabsSeaOWL_UV_A ThreadHandler 2019-11-26T22:21:08.829Z,1574806868.829 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled. 2019-11-26T22:21:08.829Z,1574806868.829 [WetLabsSeaOWL_UV_A](INFO): Join timeout helper Thread ID is 2555 2019-11-26T22:21:08.845Z,1574806868.845 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Uninitializing protected caller thread. 2019-11-26T22:21:08.845Z,1574806868.845 [WetLabsSeaOWL_UV_A](INFO): Powering down 2019-11-26T22:21:08.846Z,1574806868.846 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled. 2019-11-26T22:21:08.849Z,1574806868.849 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler 2019-11-26T22:21:08.849Z,1574806868.849 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled. 2019-11-26T22:21:08.849Z,1574806868.849 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 2556 2019-11-26T22:21:08.885Z,1574806868.885 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread. 2019-11-26T22:21:08.885Z,1574806868.885 [CTD_NeilBrown](INFO): Powering down 2019-11-26T22:21:08.897Z,1574806868.897 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled. 2019-11-26T22:21:08.913Z,1574806868.913 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2019-11-26T22:21:08.913Z,1574806868.913 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2019-11-26T22:21:08.913Z,1574806868.913 [Radio_Surface](INFO): Join timeout helper Thread ID is 2557 2019-11-26T22:21:09.225Z,1574806869.225 [Radio_Surface](INFO): Powering down 2019-11-26T22:21:09.226Z,1574806869.226 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2019-11-26T22:21:09.226Z,1574806869.226 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2019-11-26T22:21:09.249Z,1574806869.249 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2019-11-26T22:21:09.249Z,1574806869.249 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2019-11-26T22:21:09.250Z,1574806869.250 [DataOverHttps](INFO): Join timeout helper Thread ID is 2558 2019-11-26T22:21:09.313Z,1574806869.313 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2019-11-26T22:21:09.316Z,1574806869.316 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2019-11-26T22:21:09.329Z,1574806869.329 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2019-11-26T22:21:09.330Z,1574806869.330 [logger ThreadHandler](INFO): Thread cancelled. 2019-11-26T22:21:09.330Z,1574806869.330 [logger](INFO): Join timeout helper Thread ID is 2559 2019-11-26T22:21:09.345Z,1574806869.345 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2019-11-26T22:21:09.345Z,1574806869.345 [logger ThreadHandler](INFO): Thread cancelled. 2019-11-26T22:21:09.349Z,1574806869.349 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2019-11-26T22:21:09.350Z,1574806869.350 [CommandLine ThreadHandler](INFO): Thread cancelled. 2019-11-26T22:21:09.350Z,1574806869.350 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2019-11-26T22:21:09.350Z,1574806869.350 [controlThread ThreadHandler](INFO): Thread cancelled. 2019-11-26T22:21:09.350Z,1574806869.350 [controlThread](INFO): Join timeout helper Thread ID is 2560 2019-11-26T22:21:09.445Z,1574806869.445 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2019-11-26T22:21:09.445Z,1574806869.445 [controlThread](DEBUG): Uninitializing ControlThread 2019-11-26T22:21:09.446Z,1574806869.446 [AHRS_M2](INFO): Powering down 2019-11-26T22:21:09.517Z,1574806869.517 [DDM](INFO): Powering down 2019-11-26T22:21:09.609Z,1574806869.609 [DUSBL_Hydroid](INFO): Powering down 2019-11-26T22:21:09.681Z,1574806869.681 [Micromodem](INFO): Powering down 2019-11-26T22:21:09.777Z,1574806869.777 [NAL9602](INFO): Powering down 2019-11-26T22:21:09.849Z,1574806869.849 [RDI_Pathfinder](INFO): Powering down 2019-11-26T22:21:09.850Z,1574806869.850 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2019-11-26T22:21:09.851Z,1574806869.851 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2019-11-26T22:21:09.852Z,1574806869.852 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2019-11-26T22:21:09.852Z,1574806869.852 [MissionManager](INFO): Uninitializing Mission Default 2019-11-26T22:21:09.852Z,1574806869.852 [Default] Stopped 2019-11-26T22:21:09.852Z,1574806869.852 [Default](DEBUG): Aggregate::uninitialize Default 2019-11-26T22:21:09.852Z,1574806869.852 [Default:B.GoToSurface] Stopped 2019-11-26T22:21:09.853Z,1574806869.853 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2019-11-26T22:21:09.853Z,1574806869.853 [Default:CheckIn] Stopped 2019-11-26T22:21:09.853Z,1574806869.853 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-11-26T22:21:09.853Z,1574806869.853 [Default:CheckIn:C.Wait] Stopped 2019-11-26T22:21:09.853Z,1574806869.853 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-11-26T22:21:09.855Z,1574806869.855 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2019-11-26T22:21:09.856Z,1574806869.856 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2019-11-26T22:21:09.856Z,1574806869.856 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2019-11-26T22:21:09.856Z,1574806869.856 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2019-11-26T22:21:09.857Z,1574806869.857 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2019-11-26T22:21:09.857Z,1574806869.857 [BuoyancyServo](INFO): Powering down 2019-11-26T22:21:09.869Z,1574806869.869 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2019-11-26T22:21:09.869Z,1574806869.869 [ElevatorServo](INFO): Powering down 2019-11-26T22:21:09.870Z,1574806869.870 [MassServo](DEBUG): Uninitialize Mass Servo. 2019-11-26T22:21:09.870Z,1574806869.870 [MassServo](INFO): Powering down 2019-11-26T22:21:09.871Z,1574806869.871 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2019-11-26T22:21:09.871Z,1574806869.871 [RudderServo](INFO): Powering down 2019-11-26T22:21:09.872Z,1574806869.872 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2019-11-26T22:21:09.872Z,1574806869.872 [ThrusterServo](INFO): Powering down 2019-11-26T22:21:09.872Z,1574806869.872 [SBIT](DEBUG): Uninitialize SBIT Component. 2019-11-26T22:21:09.873Z,1574806869.873 [IBIT](DEBUG): Uninitialize IBIT Component. 2019-11-26T22:21:09.873Z,1574806869.873 [CBIT](DEBUG): Uninitialize CBIT Component. 2019-11-26T22:21:09.873Z,1574806869.873 [CBIT](DEBUG): Powering off loads. 2019-11-26T22:21:09.885Z,1574806869.885 [CBIT](DEBUG): Disabling WDT. 2019-11-26T22:21:09.897Z,1574806869.897 [CBIT](DEBUG): Opening all GF detection circuits. 2019-11-26T22:21:09.897Z,1574806869.897 [controlThread ThreadHandler](INFO): Thread cancelled. 2019-11-26T22:21:09.949Z,1574806869.949 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2019-11-26T22:21:09.959Z,1574806869.959 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2019-11-26T22:21:10.002Z,1574806870.002 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled. 2019-11-26T22:21:10.005Z,1574806870.005 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled. 2019-11-26T22:21:10.065Z,1574806870.065 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2019-11-26T22:21:10.139Z,1574806870.139 [logger ThreadHandler](INFO): Thread cancelled.