2021-04-18T18:38:51.762Z,1618771131.762 [CommandLine](IMPORTANT): got command restart logs 2021-04-18T18:38:52.104Z,1618771132.104 [MissionManager](IMPORTANT): Started mission Default 2021-04-18T18:38:52.104Z,1618771132.104 [Default] Running Loop=1 2021-04-18T18:38:52.104Z,1618771132.104 [Default](DEBUG): Aggregate::initialize Default 2021-04-18T18:38:52.104Z,1618771132.104 [Default:B.GoToSurface] Running Loop=1 2021-04-18T18:38:52.104Z,1618771132.104 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2021-04-18T18:38:52.104Z,1618771132.104 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2021-04-18T18:38:52.105Z,1618771132.105 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2021-04-18T18:38:52.105Z,1618771132.105 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2021-04-18T18:38:52.106Z,1618771132.106 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2021-04-18T18:38:52.106Z,1618771132.106 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2021-04-18T18:38:52.106Z,1618771132.106 [Default:A.Wait] Running Loop=1 2021-04-18T18:38:52.106Z,1618771132.106 [Default:A.Wait](DEBUG): Initialize Wait Component. 2021-04-18T18:39:05.440Z,1618771145.440 [Default:A.Wait](INFO): Done Waiting. 2021-04-18T18:39:05.440Z,1618771145.440 [Default:A.Wait] Stopped 2021-04-18T18:39:05.440Z,1618771145.440 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2021-04-18T18:39:05.858Z,1618771145.858 [Default:CheckIn] Running Loop=1 2021-04-18T18:39:05.858Z,1618771145.858 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-18T18:39:05.858Z,1618771145.858 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-18T18:39:07.446Z,1618771147.446 [NAL9602](FAULT): GPS failed to acquire within timeout. 2021-04-18T18:39:07.447Z,1618771147.447 [NAL9602] Data Fault, FailCount= 3 2021-04-18T18:39:07.447Z,1618771147.447 [NAL9602](ERROR): Data Fault 2021-04-18T18:39:07.504Z,1618771147.504 [CBIT](ERROR): Data Fault in component: NAL9602 2021-04-18T18:39:07.854Z,1618771147.854 [NAL9602](INFO): Powering down 2021-04-18T18:39:08.685Z,1618771148.685 [CBIT](INFO): Clearing failed state for component NAL9602 2021-04-18T18:39:08.685Z,1618771148.685 [NAL9602] No Fault, FailCount= 3 2021-04-18T18:39:38.159Z,1618771178.159 [NAL9602](INFO): Powering up NAL9602 2021-04-18T18:39:49.063Z,1618771189.063 [NAL9602](INFO): NAL9602 initialized 2021-04-18T18:44:06.098Z,1618771446.098 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-18T18:39:05.9Z 2021-04-18T18:44:06.098Z,1618771446.098 [Default:CheckIn:Read_GPS] Stopped 2021-04-18T18:44:06.099Z,1618771446.099 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-18T18:44:14.533Z,1618771454.533 [DataOverHttps](INFO): Sending 38 bytes from file Logs/20210416T143818/Courier0892.lzma 2021-04-18T18:44:15.536Z,1618771455.536 [DataOverHttps](INFO): Moved sent file to Logs/20210416T143818/Courier0892.lzma.bak 2021-04-18T18:44:15.536Z,1618771455.536 [DataOverHttps](INFO): SBD MOMSN=15581910 2021-04-18T18:44:32.053Z,1618771472.053 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20210418T183851/Courier0000.lzma 2021-04-18T18:44:33.055Z,1618771473.055 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Courier0000.lzma.bak 2021-04-18T18:44:33.055Z,1618771473.055 [DataOverHttps](INFO): SBD MOMSN=15581912 2021-04-18T18:44:48.826Z,1618771488.826 [DataOverHttps](INFO): Sending 258 bytes from file Logs/20210416T143818/Express0893.lzma 2021-04-18T18:44:49.828Z,1618771489.828 [DataOverHttps](INFO): Moved sent file to Logs/20210416T143818/Express0893.lzma.bak 2021-04-18T18:44:49.828Z,1618771489.828 [DataOverHttps](INFO): SBD MOMSN=15581915 2021-04-18T18:44:52.135Z,1618771492.135 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-18T18:45:04.873Z,1618771504.873 [DataOverHttps](INFO): Sending 412 bytes from file Logs/20210418T183851/Express0001.lzma 2021-04-18T18:45:05.883Z,1618771505.883 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Express0001.lzma.bak 2021-04-18T18:45:05.883Z,1618771505.883 [DataOverHttps](INFO): SBD MOMSN=15581920 2021-04-18T18:45:07.506Z,1618771507.506 [Default:CheckIn:Read_Iridium] Stopped 2021-04-18T18:45:07.506Z,1618771507.506 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-18T18:45:07.506Z,1618771507.506 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-18T18:45:22.838Z,1618771522.838 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-18T18:50:08.079Z,1618771808.079 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-18T18:50:08.079Z,1618771808.079 [Default:CheckIn:C.Wait] Stopped 2021-04-18T18:50:08.079Z,1618771808.079 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-18T18:50:08.079Z,1618771808.079 [Default:CheckIn:D] Running Loop=1 2021-04-18T18:50:08.503Z,1618771808.503 [Default:CheckIn:D] Stopped 2021-04-18T18:50:08.503Z,1618771808.503 [Default:CheckIn:E] Running Loop=1 2021-04-18T18:50:08.882Z,1618771808.882 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 11.273314 min 2021-04-18T18:50:08.882Z,1618771808.882 [Default:CheckIn:E] Stopped 2021-04-18T18:50:08.882Z,1618771808.882 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-18T18:50:08.882Z,1618771808.882 [Default:CheckIn] Stopped 2021-04-18T18:50:08.882Z,1618771808.882 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-18T18:50:08.882Z,1618771808.882 [Default:CheckIn](INFO): Running loop #2 2021-04-18T18:50:08.882Z,1618771808.882 [Default:CheckIn] Running Loop=2 2021-04-18T18:50:08.883Z,1618771808.883 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-18T18:50:08.883Z,1618771808.883 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-18T18:50:10.480Z,1618771810.480 [NAL9602](FAULT): GPS failed to acquire within timeout. 2021-04-18T18:50:10.480Z,1618771810.480 [NAL9602] Data Fault, FailCount= 4 2021-04-18T18:50:10.480Z,1618771810.480 [NAL9602](ERROR): Data Fault 2021-04-18T18:50:10.500Z,1618771810.500 [CBIT](ERROR): Data Fault in component: NAL9602 2021-04-18T18:50:10.892Z,1618771810.892 [NAL9602](INFO): Powering down 2021-04-18T18:50:11.759Z,1618771811.759 [CBIT](INFO): Clearing failed state for component NAL9602 2021-04-18T18:50:11.760Z,1618771811.760 [NAL9602] No Fault, FailCount= 4 2021-04-18T18:50:41.262Z,1618771841.262 [NAL9602](INFO): Powering up NAL9602 2021-04-18T18:50:52.171Z,1618771852.171 [NAL9602](INFO): NAL9602 initialized 2021-04-18T18:55:09.124Z,1618772109.124 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-18T18:50:08.9Z 2021-04-18T18:55:09.124Z,1618772109.124 [Default:CheckIn:Read_GPS] Stopped 2021-04-18T18:55:09.125Z,1618772109.125 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-18T18:55:16.734Z,1618772116.734 [DataOverHttps](INFO): Sending 38 bytes from file Logs/20210418T183851/Courier0003.lzma 2021-04-18T18:55:17.735Z,1618772117.735 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Courier0003.lzma.bak 2021-04-18T18:55:17.735Z,1618772117.735 [DataOverHttps](INFO): SBD MOMSN=15581934 2021-04-18T18:55:32.617Z,1618772132.617 [DataOverHttps](INFO): Sending 254 bytes from file Logs/20210418T183851/Express0004.lzma 2021-04-18T18:55:33.619Z,1618772133.619 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Express0004.lzma.bak 2021-04-18T18:55:33.619Z,1618772133.619 [DataOverHttps](INFO): SBD MOMSN=15581936 2021-04-18T18:55:34.978Z,1618772134.978 [Default:CheckIn:Read_Iridium] Stopped 2021-04-18T18:55:34.978Z,1618772134.978 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-18T18:55:34.978Z,1618772134.978 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-18T18:55:55.176Z,1618772155.176 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-18T18:56:25.870Z,1618772185.870 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-18T18:59:37.825Z,1618772377.825 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2021-04-18T19:00:35.578Z,1618772435.578 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-18T19:00:35.578Z,1618772435.578 [Default:CheckIn:C.Wait] Stopped 2021-04-18T19:00:35.578Z,1618772435.578 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-18T19:00:35.580Z,1618772435.580 [Default:CheckIn:D] Running Loop=1 2021-04-18T19:00:36.041Z,1618772436.041 [Default:CheckIn:D] Stopped 2021-04-18T19:00:36.041Z,1618772436.041 [Default:CheckIn:E] Running Loop=1 2021-04-18T19:00:36.378Z,1618772436.378 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 21.732284 min 2021-04-18T19:00:36.378Z,1618772436.378 [Default:CheckIn:E] Stopped 2021-04-18T19:00:36.379Z,1618772436.379 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-18T19:00:36.379Z,1618772436.379 [Default:CheckIn] Stopped 2021-04-18T19:00:36.379Z,1618772436.379 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-18T19:00:36.379Z,1618772436.379 [Default:CheckIn](INFO): Running loop #3 2021-04-18T19:00:36.379Z,1618772436.379 [Default:CheckIn] Running Loop=3 2021-04-18T19:00:36.379Z,1618772436.379 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-18T19:00:36.379Z,1618772436.379 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-18T19:01:09.107Z,1618772469.107 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-04-18T19:01:09.189Z,1618772469.189 [NAL9602](FAULT): received: +CSQ:0 OK576, 2, 0, 0, 0 OK 2021-04-18T19:01:09.189Z,1618772469.189 [NAL9602] Data Fault, FailCount= 5 2021-04-18T19:01:09.189Z,1618772469.189 [NAL9602](ERROR): Data Fault 2021-04-18T19:01:09.269Z,1618772469.269 [CBIT](ERROR): Data Fault in component: NAL9602 2021-04-18T19:01:09.278Z,1618772469.278 [CBIT](CRITICAL): Data Fault in component: NAL9602 2021-04-18T19:01:09.490Z,1618772469.490 [NAL9602](INFO): Powering down 2021-04-18T19:01:09.527Z,1618772469.527 [CBIT](INFO): Critical error at 20210418T190109 2021-04-18T19:01:23.689Z,1618772483.689 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2021-04-18T19:02:52.568Z,1618772572.568 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2021-04-18T19:03:09.511Z,1618772589.511 [CBIT](INFO): Clearing failed state for component NAL9602 2021-04-18T19:03:09.511Z,1618772589.511 [NAL9602] No Fault, FailCount= 5 2021-04-18T19:03:09.880Z,1618772589.880 [NAL9602](INFO): Powering up NAL9602 2021-04-18T19:03:20.789Z,1618772600.789 [NAL9602](INFO): NAL9602 initialized 2021-04-18T19:03:21.661Z,1618772601.661 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2021-04-18T19:03:21.663Z,1618772601.663 [NAL9602](FAULT): GPS failed to acquire within timeout. 2021-04-18T19:03:21.663Z,1618772601.663 [NAL9602] Data Fault, FailCount= 1 2021-04-18T19:03:21.663Z,1618772601.663 [NAL9602](ERROR): Data Fault 2021-04-18T19:03:21.682Z,1618772601.682 [CBIT](ERROR): Data Fault in component: NAL9602 2021-04-18T19:03:22.021Z,1618772602.021 [NAL9602](INFO): Powering down 2021-04-18T19:03:22.865Z,1618772602.865 [CBIT](INFO): Clearing failed state for component NAL9602 2021-04-18T19:03:22.865Z,1618772602.865 [NAL9602] No Fault, FailCount= 1 2021-04-18T19:03:52.310Z,1618772632.310 [NAL9602](INFO): Powering up NAL9602 2021-04-18T19:04:03.214Z,1618772643.214 [NAL9602](INFO): NAL9602 initialized 2021-04-18T19:04:21.037Z,1618772661.037 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2021-04-18T19:04:33.565Z,1618772673.565 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2021-04-18T19:05:36.561Z,1618772736.561 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-18T19:00:36.4Z 2021-04-18T19:05:36.561Z,1618772736.561 [Default:CheckIn:Read_GPS] Stopped 2021-04-18T19:05:36.562Z,1618772736.562 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-18T19:05:40.171Z,1618772740.171 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-18T19:05:44.349Z,1618772744.349 [DataOverHttps](INFO): Sending 104 bytes from file Logs/20210418T183851/Courier0006.lzma 2021-04-18T19:05:45.351Z,1618772745.351 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Courier0006.lzma.bak 2021-04-18T19:05:45.351Z,1618772745.351 [DataOverHttps](INFO): SBD MOMSN=15581981 2021-04-18T19:05:47.095Z,1618772747.095 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2021-04-18T19:05:58.870Z,1618772758.870 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2021-04-18T19:06:01.266Z,1618772761.266 [DataOverHttps](INFO): Sending 265 bytes from file Logs/20210418T183851/Express0007.lzma 2021-04-18T19:06:02.267Z,1618772762.267 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Express0007.lzma.bak 2021-04-18T19:06:02.267Z,1618772762.267 [DataOverHttps](INFO): SBD MOMSN=15581986 2021-04-18T19:06:03.626Z,1618772763.626 [Default:CheckIn:Read_Iridium] Stopped 2021-04-18T19:06:03.627Z,1618772763.627 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-18T19:06:03.627Z,1618772763.627 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-18T19:06:10.878Z,1618772770.878 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-18T19:06:44.562Z,1618772804.562 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2021-04-18T19:06:44.565Z,1618772804.565 [BPC1](INFO): Received data from all battery sticks. 2021-04-18T19:11:04.378Z,1618773064.378 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-18T19:11:04.378Z,1618773064.378 [Default:CheckIn:C.Wait] Stopped 2021-04-18T19:11:04.378Z,1618773064.378 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-18T19:11:04.379Z,1618773064.379 [Default:CheckIn:D] Running Loop=1 2021-04-18T19:11:04.778Z,1618773064.778 [Default:CheckIn:D] Stopped 2021-04-18T19:11:04.778Z,1618773064.778 [Default:CheckIn:E] Running Loop=1 2021-04-18T19:11:05.181Z,1618773065.181 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 32.211226 min 2021-04-18T19:11:05.181Z,1618773065.181 [Default:CheckIn:E] Stopped 2021-04-18T19:11:05.181Z,1618773065.181 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-18T19:11:05.181Z,1618773065.181 [Default:CheckIn] Stopped 2021-04-18T19:11:05.181Z,1618773065.181 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-18T19:11:05.181Z,1618773065.181 [Default:CheckIn](INFO): Running loop #4 2021-04-18T19:11:05.182Z,1618773065.182 [Default:CheckIn] Running Loop=4 2021-04-18T19:11:05.182Z,1618773065.182 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-18T19:11:05.182Z,1618773065.182 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-18T19:11:37.898Z,1618773097.898 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-04-18T19:11:37.973Z,1618773097.973 [NAL9602](FAULT): received: +CSQ:0 OK576, 2, 0, 0, 0 OK 2021-04-18T19:11:37.973Z,1618773097.973 [NAL9602] Data Fault, FailCount= 2 2021-04-18T19:11:37.973Z,1618773097.973 [NAL9602](ERROR): Data Fault 2021-04-18T19:11:38.013Z,1618773098.013 [CBIT](ERROR): Data Fault in component: NAL9602 2021-04-18T19:11:38.298Z,1618773098.298 [NAL9602](INFO): Powering down 2021-04-18T19:11:39.121Z,1618773099.121 [CBIT](INFO): Clearing failed state for component NAL9602 2021-04-18T19:11:39.122Z,1618773099.122 [NAL9602] No Fault, FailCount= 2 2021-04-18T19:12:08.598Z,1618773128.598 [NAL9602](INFO): Powering up NAL9602 2021-04-18T19:12:19.507Z,1618773139.507 [NAL9602](INFO): NAL9602 initialized 2021-04-18T19:16:05.361Z,1618773365.361 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-18T19:11:05.2Z 2021-04-18T19:16:05.361Z,1618773365.361 [Default:CheckIn:Read_GPS] Stopped 2021-04-18T19:16:05.361Z,1618773365.361 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-18T19:16:09.387Z,1618773369.387 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-18T19:16:12.217Z,1618773372.217 [DataOverHttps](INFO): Sending 169 bytes from file Logs/20210418T183851/Courier0009.lzma 2021-04-18T19:16:13.219Z,1618773373.219 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Courier0009.lzma.bak 2021-04-18T19:16:13.219Z,1618773373.219 [DataOverHttps](INFO): SBD MOMSN=15582009 2021-04-18T19:16:29.217Z,1618773389.217 [DataOverHttps](INFO): Sending 245 bytes from file Logs/20210418T183851/Express0010.lzma 2021-04-18T19:16:30.219Z,1618773390.219 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Express0010.lzma.bak 2021-04-18T19:16:30.219Z,1618773390.219 [DataOverHttps](INFO): SBD MOMSN=15582011 2021-04-18T19:16:31.625Z,1618773391.625 [Default:CheckIn:Read_Iridium] Stopped 2021-04-18T19:16:31.625Z,1618773391.625 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-18T19:16:31.625Z,1618773391.625 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-18T19:16:40.094Z,1618773400.094 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-18T19:21:32.207Z,1618773692.207 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-18T19:21:32.207Z,1618773692.207 [Default:CheckIn:C.Wait] Stopped 2021-04-18T19:21:32.207Z,1618773692.207 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-18T19:21:32.207Z,1618773692.207 [Default:CheckIn:D] Running Loop=1 2021-04-18T19:21:32.619Z,1618773692.619 [Default:CheckIn:D] Stopped 2021-04-18T19:21:32.619Z,1618773692.619 [Default:CheckIn:E] Running Loop=1 2021-04-18T19:21:33.009Z,1618773693.009 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 42.675248 min 2021-04-18T19:21:33.009Z,1618773693.009 [Default:CheckIn:E] Stopped 2021-04-18T19:21:33.009Z,1618773693.009 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-18T19:21:33.010Z,1618773693.010 [Default:CheckIn] Stopped 2021-04-18T19:21:33.010Z,1618773693.010 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-18T19:21:33.010Z,1618773693.010 [Default:CheckIn](INFO): Running loop #5 2021-04-18T19:21:33.010Z,1618773693.010 [Default:CheckIn] Running Loop=5 2021-04-18T19:21:33.010Z,1618773693.010 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-18T19:21:33.010Z,1618773693.010 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-18T19:21:34.612Z,1618773694.612 [NAL9602](FAULT): GPS failed to acquire within timeout. 2021-04-18T19:21:34.612Z,1618773694.612 [NAL9602] Data Fault, FailCount= 3 2021-04-18T19:21:34.612Z,1618773694.612 [NAL9602](ERROR): Data Fault 2021-04-18T19:21:34.632Z,1618773694.632 [CBIT](ERROR): Data Fault in component: NAL9602 2021-04-18T19:21:35.018Z,1618773695.018 [NAL9602](INFO): Powering down 2021-04-18T19:21:35.857Z,1618773695.857 [CBIT](INFO): Clearing failed state for component NAL9602 2021-04-18T19:21:35.857Z,1618773695.857 [NAL9602] No Fault, FailCount= 3 2021-04-18T19:22:05.322Z,1618773725.322 [NAL9602](INFO): Powering up NAL9602 2021-04-18T19:22:16.227Z,1618773736.227 [NAL9602](INFO): NAL9602 initialized 2021-04-18T19:23:31.782Z,1618773811.782 [NAL9602](INFO): SBD MO Status=2, MOMSN=25576, MT Status=2, MTMSN=0 2021-04-18T19:23:31.783Z,1618773811.783 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-04-18T19:26:33.182Z,1618773993.182 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-18T19:21:33.0Z 2021-04-18T19:26:33.182Z,1618773993.182 [Default:CheckIn:Read_GPS] Stopped 2021-04-18T19:26:33.182Z,1618773993.182 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-18T19:26:40.853Z,1618774000.853 [DataOverHttps](INFO): Sending 38 bytes from file Logs/20210418T183851/Courier0012.lzma 2021-04-18T19:26:41.855Z,1618774001.855 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Courier0012.lzma.bak 2021-04-18T19:26:41.855Z,1618774001.855 [DataOverHttps](INFO): SBD MOMSN=15582027 2021-04-18T19:26:57.809Z,1618774017.809 [DataOverHttps](INFO): Sending 224 bytes from file Logs/20210418T183851/Express0013.lzma 2021-04-18T19:26:58.811Z,1618774018.811 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Express0013.lzma.bak 2021-04-18T19:26:58.811Z,1618774018.811 [DataOverHttps](INFO): SBD MOMSN=15582029 2021-04-18T19:27:00.258Z,1618774020.258 [Default:CheckIn:Read_Iridium] Stopped 2021-04-18T19:27:00.258Z,1618774020.258 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-18T19:27:00.258Z,1618774020.258 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-18T19:27:19.231Z,1618774039.231 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-18T19:27:49.934Z,1618774069.934 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-18T19:32:00.838Z,1618774320.838 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-18T19:32:00.838Z,1618774320.838 [Default:CheckIn:C.Wait] Stopped 2021-04-18T19:32:00.838Z,1618774320.838 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-18T19:32:00.838Z,1618774320.838 [Default:CheckIn:D] Running Loop=1 2021-04-18T19:32:01.240Z,1618774321.240 [Default:CheckIn:D] Stopped 2021-04-18T19:32:01.241Z,1618774321.241 [Default:CheckIn:E] Running Loop=1 2021-04-18T19:32:01.633Z,1618774321.633 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 53.152275 min 2021-04-18T19:32:01.633Z,1618774321.633 [Default:CheckIn:E] Stopped 2021-04-18T19:32:01.633Z,1618774321.633 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-18T19:32:01.634Z,1618774321.634 [Default:CheckIn] Stopped 2021-04-18T19:32:01.634Z,1618774321.634 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-18T19:32:01.634Z,1618774321.634 [Default:CheckIn](INFO): Running loop #6 2021-04-18T19:32:01.634Z,1618774321.634 [Default:CheckIn] Running Loop=6 2021-04-18T19:32:01.634Z,1618774321.634 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-18T19:32:01.634Z,1618774321.634 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-18T19:32:34.347Z,1618774354.347 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-04-18T19:32:34.429Z,1618774354.429 [NAL9602](FAULT): received: +CSQ:0 OK576, 2, 0, 0, 0 OK 2021-04-18T19:32:34.429Z,1618774354.429 [NAL9602] Data Fault, FailCount= 4 2021-04-18T19:32:34.429Z,1618774354.429 [NAL9602](ERROR): Data Fault 2021-04-18T19:32:34.474Z,1618774354.474 [CBIT](ERROR): Data Fault in component: NAL9602 2021-04-18T19:32:34.757Z,1618774354.757 [NAL9602](INFO): Powering down 2021-04-18T19:32:35.610Z,1618774355.610 [CBIT](INFO): Clearing failed state for component NAL9602 2021-04-18T19:32:35.610Z,1618774355.610 [NAL9602] No Fault, FailCount= 4 2021-04-18T19:33:05.050Z,1618774385.050 [NAL9602](INFO): Powering up NAL9602 2021-04-18T19:33:15.963Z,1618774395.963 [NAL9602](INFO): NAL9602 initialized 2021-04-18T19:33:16.771Z,1618774396.771 [NAL9602](FAULT): GPS failed to acquire within timeout. 2021-04-18T19:33:16.771Z,1618774396.771 [NAL9602] Data Fault, FailCount= 5 2021-04-18T19:33:16.771Z,1618774396.771 [NAL9602](ERROR): Data Fault 2021-04-18T19:33:16.790Z,1618774396.790 [CBIT](ERROR): Data Fault in component: NAL9602 2021-04-18T19:33:16.790Z,1618774396.790 [CBIT](CRITICAL): Data Fault in component: NAL9602 2021-04-18T19:33:17.177Z,1618774397.177 [NAL9602](INFO): Powering down 2021-04-18T19:33:17.201Z,1618774397.201 [CBIT](INFO): Critical error at 20210418T193316 2021-04-18T19:35:16.775Z,1618774516.775 [CBIT](INFO): Clearing failed state for component NAL9602 2021-04-18T19:35:16.775Z,1618774516.775 [NAL9602] No Fault, FailCount= 5 2021-04-18T19:35:17.166Z,1618774517.166 [NAL9602](INFO): Powering up NAL9602 2021-04-18T19:35:28.070Z,1618774528.070 [NAL9602](INFO): NAL9602 initialized 2021-04-18T19:37:01.802Z,1618774621.802 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-18T19:32:01.6Z 2021-04-18T19:37:01.803Z,1618774621.803 [Default:CheckIn:Read_GPS] Stopped 2021-04-18T19:37:01.803Z,1618774621.803 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-18T19:37:05.431Z,1618774625.431 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-18T19:37:08.633Z,1618774628.633 [DataOverHttps](INFO): Sending 81 bytes from file Logs/20210418T183851/Courier0015.lzma 2021-04-18T19:37:09.635Z,1618774629.635 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Courier0015.lzma.bak 2021-04-18T19:37:09.635Z,1618774629.635 [DataOverHttps](INFO): SBD MOMSN=15582044 2021-04-18T19:37:25.617Z,1618774645.617 [DataOverHttps](INFO): Sending 264 bytes from file Logs/20210418T183851/Express0016.lzma 2021-04-18T19:37:26.615Z,1618774646.615 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Express0016.lzma.bak 2021-04-18T19:37:26.615Z,1618774646.615 [DataOverHttps](INFO): SBD MOMSN=15582047 2021-04-18T19:37:28.472Z,1618774648.472 [Default:CheckIn:Read_Iridium] Stopped 2021-04-18T19:37:28.472Z,1618774648.472 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-18T19:37:28.472Z,1618774648.472 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-18T19:37:36.134Z,1618774656.134 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-18T19:42:29.048Z,1618774949.048 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-18T19:42:29.048Z,1618774949.048 [Default:CheckIn:C.Wait] Stopped 2021-04-18T19:42:29.049Z,1618774949.049 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-18T19:42:29.049Z,1618774949.049 [Default:CheckIn:D] Running Loop=1 2021-04-18T19:42:29.454Z,1618774949.454 [Default:CheckIn:D] Stopped 2021-04-18T19:42:29.454Z,1618774949.454 [Default:CheckIn:E] Running Loop=1 2021-04-18T19:42:29.861Z,1618774949.861 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 63.622498 min 2021-04-18T19:42:29.861Z,1618774949.861 [Default:CheckIn:E] Stopped 2021-04-18T19:42:29.861Z,1618774949.861 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-18T19:42:29.861Z,1618774949.861 [Default:CheckIn] Stopped 2021-04-18T19:42:29.861Z,1618774949.861 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-18T19:42:29.862Z,1618774949.862 [Default:CheckIn](INFO): Running loop #7 2021-04-18T19:42:29.862Z,1618774949.862 [Default:CheckIn] Running Loop=7 2021-04-18T19:42:29.862Z,1618774949.862 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-18T19:42:29.862Z,1618774949.862 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-18T19:47:30.034Z,1618775250.034 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-18T19:42:29.9Z 2021-04-18T19:47:30.034Z,1618775250.034 [Default:CheckIn:Read_GPS] Stopped 2021-04-18T19:47:30.035Z,1618775250.035 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-18T19:47:34.099Z,1618775254.099 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-18T19:47:36.849Z,1618775256.849 [DataOverHttps](INFO): Sending 38 bytes from file Logs/20210418T183851/Courier0018.lzma 2021-04-18T19:47:37.852Z,1618775257.852 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Courier0018.lzma.bak 2021-04-18T19:47:37.852Z,1618775257.852 [DataOverHttps](INFO): SBD MOMSN=15582066 2021-04-18T19:47:53.694Z,1618775273.694 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20210418T183851/Express0019.lzma 2021-04-18T19:47:54.695Z,1618775274.695 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Express0019.lzma.bak 2021-04-18T19:47:54.695Z,1618775274.695 [DataOverHttps](INFO): SBD MOMSN=15582068 2021-04-18T19:47:56.362Z,1618775276.362 [Default:CheckIn:Read_Iridium] Stopped 2021-04-18T19:47:56.362Z,1618775276.362 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-18T19:47:56.362Z,1618775276.362 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-18T19:48:04.830Z,1618775284.830 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-18T19:52:57.052Z,1618775577.052 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-18T19:52:57.052Z,1618775577.052 [Default:CheckIn:C.Wait] Stopped 2021-04-18T19:52:57.052Z,1618775577.052 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-18T19:52:57.053Z,1618775577.053 [Default:CheckIn:D] Running Loop=1 2021-04-18T19:52:57.466Z,1618775577.466 [Default:CheckIn:D] Stopped 2021-04-18T19:52:57.466Z,1618775577.466 [Default:CheckIn:E] Running Loop=1 2021-04-18T19:52:57.869Z,1618775577.869 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 74.089364 min 2021-04-18T19:52:57.869Z,1618775577.869 [Default:CheckIn:E] Stopped 2021-04-18T19:52:57.870Z,1618775577.870 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-18T19:52:57.870Z,1618775577.870 [Default:CheckIn] Stopped 2021-04-18T19:52:57.870Z,1618775577.870 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-18T19:52:57.870Z,1618775577.870 [Default:CheckIn](INFO): Running loop #8 2021-04-18T19:52:57.870Z,1618775577.870 [Default:CheckIn] Running Loop=8 2021-04-18T19:52:57.870Z,1618775577.870 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-18T19:52:57.870Z,1618775577.870 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-18T19:52:59.466Z,1618775579.466 [NAL9602](FAULT): GPS failed to acquire within timeout. 2021-04-18T19:52:59.467Z,1618775579.467 [NAL9602] Data Fault, FailCount= 1 2021-04-18T19:52:59.467Z,1618775579.467 [NAL9602](ERROR): Data Fault 2021-04-18T19:52:59.514Z,1618775579.514 [CBIT](ERROR): Data Fault in component: NAL9602 2021-04-18T19:52:59.866Z,1618775579.866 [NAL9602](INFO): Powering down 2021-04-18T19:53:00.714Z,1618775580.714 [CBIT](INFO): Clearing failed state for component NAL9602 2021-04-18T19:53:00.714Z,1618775580.714 [NAL9602] No Fault, FailCount= 1 2021-04-18T19:53:30.174Z,1618775610.174 [NAL9602](INFO): Powering up NAL9602 2021-04-18T19:53:41.075Z,1618775621.075 [NAL9602](INFO): NAL9602 initialized 2021-04-18T19:57:58.043Z,1618775878.043 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-18T19:52:57.9Z 2021-04-18T19:57:58.043Z,1618775878.043 [Default:CheckIn:Read_GPS] Stopped 2021-04-18T19:57:58.044Z,1618775878.044 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-18T19:58:05.157Z,1618775885.157 [DataOverHttps](INFO): Sending 38 bytes from file Logs/20210418T183851/Courier0021.lzma 2021-04-18T19:58:06.167Z,1618775886.167 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Courier0021.lzma.bak 2021-04-18T19:58:06.167Z,1618775886.167 [DataOverHttps](INFO): SBD MOMSN=15582082 2021-04-18T19:58:21.938Z,1618775901.938 [DataOverHttps](INFO): Sending 225 bytes from file Logs/20210418T183851/Express0022.lzma 2021-04-18T19:58:22.939Z,1618775902.939 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Express0022.lzma.bak 2021-04-18T19:58:22.939Z,1618775902.939 [DataOverHttps](INFO): SBD MOMSN=15582084 2021-04-18T19:58:24.694Z,1618775904.694 [Default:CheckIn:Read_Iridium] Stopped 2021-04-18T19:58:24.694Z,1618775904.694 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-18T19:58:24.694Z,1618775904.694 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-18T19:58:44.083Z,1618775924.083 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-18T19:59:14.790Z,1618775954.790 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-18T20:03:25.282Z,1618776205.282 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-18T20:03:25.282Z,1618776205.282 [Default:CheckIn:C.Wait] Stopped 2021-04-18T20:03:25.282Z,1618776205.282 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-18T20:03:25.282Z,1618776205.282 [Default:CheckIn:D] Running Loop=1 2021-04-18T20:03:25.684Z,1618776205.684 [Default:CheckIn:D] Stopped 2021-04-18T20:03:25.684Z,1618776205.684 [Default:CheckIn:E] Running Loop=1 2021-04-18T20:03:26.091Z,1618776206.091 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 84.559676 min 2021-04-18T20:03:26.091Z,1618776206.091 [Default:CheckIn:E] Stopped 2021-04-18T20:03:26.091Z,1618776206.091 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-18T20:03:26.091Z,1618776206.091 [Default:CheckIn] Stopped 2021-04-18T20:03:26.091Z,1618776206.091 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-18T20:03:26.091Z,1618776206.091 [Default:CheckIn](INFO): Running loop #9 2021-04-18T20:03:26.092Z,1618776206.092 [Default:CheckIn] Running Loop=9 2021-04-18T20:03:26.092Z,1618776206.092 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-18T20:03:26.092Z,1618776206.092 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-18T20:08:26.261Z,1618776506.261 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-18T20:03:26.1Z 2021-04-18T20:08:26.261Z,1618776506.261 [Default:CheckIn:Read_GPS] Stopped 2021-04-18T20:08:26.262Z,1618776506.262 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-18T20:08:30.429Z,1618776510.429 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-18T20:08:34.245Z,1618776514.245 [DataOverHttps](INFO): Sending 38 bytes from file Logs/20210418T183851/Courier0024.lzma 2021-04-18T20:08:35.247Z,1618776515.247 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Courier0024.lzma.bak 2021-04-18T20:08:35.247Z,1618776515.247 [DataOverHttps](INFO): SBD MOMSN=15582115 2021-04-18T20:08:49.766Z,1618776529.766 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2021-04-18T20:08:51.289Z,1618776531.289 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20210418T183851/Express0025.lzma 2021-04-18T20:08:52.291Z,1618776532.291 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Express0025.lzma.bak 2021-04-18T20:08:52.291Z,1618776532.291 [DataOverHttps](INFO): SBD MOMSN=15582117 2021-04-18T20:08:53.731Z,1618776533.731 [Default:CheckIn:Read_Iridium] Stopped 2021-04-18T20:08:53.731Z,1618776533.731 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-18T20:08:53.731Z,1618776533.731 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-18T20:09:01.011Z,1618776541.011 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-18T20:09:31.015Z,1618776571.015 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2021-04-18T20:09:41.439Z,1618776581.439 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2021-04-18T20:10:00.433Z,1618776600.433 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2021-04-18T20:10:08.102Z,1618776608.102 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2021-04-18T20:10:59.514Z,1618776659.514 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2021-04-18T20:11:11.539Z,1618776671.539 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2021-04-18T20:12:13.813Z,1618776733.813 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2021-04-18T20:12:26.275Z,1618776746.275 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2021-04-18T20:12:58.596Z,1618776778.596 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2021-04-18T20:13:41.423Z,1618776821.423 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2021-04-18T20:13:54.308Z,1618776834.308 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-18T20:13:54.308Z,1618776834.308 [Default:CheckIn:C.Wait] Stopped 2021-04-18T20:13:54.308Z,1618776834.308 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-18T20:13:54.309Z,1618776834.309 [Default:CheckIn:D] Running Loop=1 2021-04-18T20:13:54.707Z,1618776834.707 [Default:CheckIn:D] Stopped 2021-04-18T20:13:54.707Z,1618776834.707 [Default:CheckIn:E] Running Loop=1 2021-04-18T20:13:55.117Z,1618776835.117 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 95.043376 min 2021-04-18T20:13:55.118Z,1618776835.118 [Default:CheckIn:E] Stopped 2021-04-18T20:13:55.118Z,1618776835.118 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-18T20:13:55.118Z,1618776835.118 [Default:CheckIn] Stopped 2021-04-18T20:13:55.118Z,1618776835.118 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-18T20:13:55.118Z,1618776835.118 [Default:CheckIn](INFO): Running loop #10 2021-04-18T20:13:55.118Z,1618776835.118 [Default:CheckIn] Running Loop=10 2021-04-18T20:13:55.118Z,1618776835.118 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-18T20:13:55.118Z,1618776835.118 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-18T20:13:56.729Z,1618776836.729 [NAL9602](FAULT): GPS failed to acquire within timeout. 2021-04-18T20:13:56.729Z,1618776836.729 [NAL9602] Data Fault, FailCount= 2 2021-04-18T20:13:56.729Z,1618776836.729 [NAL9602](ERROR): Data Fault 2021-04-18T20:13:56.750Z,1618776836.750 [CBIT](ERROR): Data Fault in component: NAL9602 2021-04-18T20:13:57.142Z,1618776837.142 [NAL9602](INFO): Powering down 2021-04-18T20:13:57.993Z,1618776837.993 [CBIT](INFO): Clearing failed state for component NAL9602 2021-04-18T20:13:57.993Z,1618776837.993 [NAL9602] No Fault, FailCount= 2 2021-04-18T20:14:10.104Z,1618776850.104 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2021-04-18T20:14:27.420Z,1618776867.420 [NAL9602](INFO): Powering up NAL9602 2021-04-18T20:14:38.339Z,1618776878.339 [NAL9602](INFO): NAL9602 initialized 2021-04-18T20:15:01.447Z,1618776901.447 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2021-04-18T20:15:09.496Z,1618776909.496 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2021-04-18T20:15:13.125Z,1618776913.125 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2021-04-18T20:15:27.628Z,1618776927.628 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2021-04-18T20:15:27.630Z,1618776927.630 [BPC1](INFO): Received data from all battery sticks. 2021-04-18T20:18:55.314Z,1618777135.314 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-18T20:13:55.1Z 2021-04-18T20:18:55.314Z,1618777135.314 [Default:CheckIn:Read_GPS] Stopped 2021-04-18T20:18:55.314Z,1618777135.314 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-18T20:19:02.629Z,1618777142.629 [DataOverHttps](INFO): Sending 51 bytes from file Logs/20210418T183851/Courier0027.lzma 2021-04-18T20:19:03.631Z,1618777143.631 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Courier0027.lzma.bak 2021-04-18T20:19:03.631Z,1618777143.631 [DataOverHttps](INFO): SBD MOMSN=15582149 2021-04-18T20:19:19.986Z,1618777159.986 [DataOverHttps](INFO): Sending 225 bytes from file Logs/20210418T183851/Express0028.lzma 2021-04-18T20:19:20.987Z,1618777160.987 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Express0028.lzma.bak 2021-04-18T20:19:20.987Z,1618777160.987 [DataOverHttps](INFO): SBD MOMSN=15582151 2021-04-18T20:19:22.379Z,1618777162.379 [Default:CheckIn:Read_Iridium] Stopped 2021-04-18T20:19:22.379Z,1618777162.379 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-18T20:19:22.379Z,1618777162.379 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-18T20:19:41.355Z,1618777181.355 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-18T20:20:12.062Z,1618777212.062 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-18T20:24:22.951Z,1618777462.951 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-18T20:24:22.952Z,1618777462.952 [Default:CheckIn:C.Wait] Stopped 2021-04-18T20:24:22.952Z,1618777462.952 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-18T20:24:22.952Z,1618777462.952 [Default:CheckIn:D] Running Loop=1 2021-04-18T20:24:23.357Z,1618777463.357 [Default:CheckIn:D] Stopped 2021-04-18T20:24:23.357Z,1618777463.357 [Default:CheckIn:E] Running Loop=1 2021-04-18T20:24:23.765Z,1618777463.765 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 105.520882 min 2021-04-18T20:24:23.765Z,1618777463.765 [Default:CheckIn:E] Stopped 2021-04-18T20:24:23.765Z,1618777463.765 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-18T20:24:23.765Z,1618777463.765 [Default:CheckIn] Stopped 2021-04-18T20:24:23.765Z,1618777463.765 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-18T20:24:23.766Z,1618777463.766 [Default:CheckIn](INFO): Running loop #11 2021-04-18T20:24:23.766Z,1618777463.766 [Default:CheckIn] Running Loop=11 2021-04-18T20:24:23.766Z,1618777463.766 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-18T20:24:23.766Z,1618777463.766 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-18T20:29:23.941Z,1618777763.941 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-18T20:24:23.8Z 2021-04-18T20:29:23.941Z,1618777763.941 [Default:CheckIn:Read_GPS] Stopped 2021-04-18T20:29:23.942Z,1618777763.942 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-18T20:29:27.995Z,1618777767.995 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-18T20:29:30.817Z,1618777770.817 [DataOverHttps](INFO): Sending 38 bytes from file Logs/20210418T183851/Courier0030.lzma 2021-04-18T20:29:31.819Z,1618777771.819 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Courier0030.lzma.bak 2021-04-18T20:29:31.819Z,1618777771.819 [DataOverHttps](INFO): SBD MOMSN=15582166 2021-04-18T20:29:46.633Z,1618777786.633 [DataOverHttps](INFO): Sending 208 bytes from file Logs/20210418T183851/Express0031.lzma 2021-04-18T20:29:47.627Z,1618777787.627 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Express0031.lzma.bak 2021-04-18T20:29:47.627Z,1618777787.627 [DataOverHttps](INFO): SBD MOMSN=15582168 2021-04-18T20:29:49.032Z,1618777789.032 [Default:CheckIn:Read_Iridium] Stopped 2021-04-18T20:29:49.032Z,1618777789.032 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-18T20:29:49.033Z,1618777789.033 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-18T20:29:58.716Z,1618777798.716 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-18T20:34:49.610Z,1618778089.610 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-18T20:34:49.610Z,1618778089.610 [Default:CheckIn:C.Wait] Stopped 2021-04-18T20:34:49.610Z,1618778089.610 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-18T20:34:49.610Z,1618778089.610 [Default:CheckIn:D] Running Loop=1 2021-04-18T20:34:50.022Z,1618778090.022 [Default:CheckIn:D] Stopped 2021-04-18T20:34:50.022Z,1618778090.022 [Default:CheckIn:E] Running Loop=1 2021-04-18T20:34:50.438Z,1618778090.438 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 115.965308 min 2021-04-18T20:34:50.438Z,1618778090.438 [Default:CheckIn:E] Stopped 2021-04-18T20:34:50.439Z,1618778090.439 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-18T20:34:50.439Z,1618778090.439 [Default:CheckIn] Stopped 2021-04-18T20:34:50.439Z,1618778090.439 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-18T20:34:50.439Z,1618778090.439 [Default:CheckIn](INFO): Running loop #12 2021-04-18T20:34:50.439Z,1618778090.439 [Default:CheckIn] Running Loop=12 2021-04-18T20:34:50.439Z,1618778090.439 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-18T20:34:50.439Z,1618778090.439 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-18T20:34:52.030Z,1618778092.030 [NAL9602](FAULT): GPS failed to acquire within timeout. 2021-04-18T20:34:52.031Z,1618778092.031 [NAL9602] Data Fault, FailCount= 3 2021-04-18T20:34:52.031Z,1618778092.031 [NAL9602](ERROR): Data Fault 2021-04-18T20:34:52.050Z,1618778092.050 [CBIT](ERROR): Data Fault in component: NAL9602 2021-04-18T20:34:52.436Z,1618778092.436 [NAL9602](INFO): Powering down 2021-04-18T20:34:53.257Z,1618778093.257 [CBIT](INFO): Clearing failed state for component NAL9602 2021-04-18T20:34:53.258Z,1618778093.258 [NAL9602] No Fault, FailCount= 3 2021-04-18T20:35:22.730Z,1618778122.730 [NAL9602](INFO): Powering up NAL9602 2021-04-18T20:35:33.639Z,1618778133.639 [NAL9602](INFO): NAL9602 initialized 2021-04-18T20:39:50.607Z,1618778390.607 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-18T20:34:50.4Z 2021-04-18T20:39:50.607Z,1618778390.607 [Default:CheckIn:Read_GPS] Stopped 2021-04-18T20:39:50.607Z,1618778390.607 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-18T20:39:57.090Z,1618778397.090 [DataOverHttps](INFO): Sending 38 bytes from file Logs/20210418T183851/Courier0033.lzma 2021-04-18T20:39:58.031Z,1618778398.031 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Courier0033.lzma.bak 2021-04-18T20:39:58.031Z,1618778398.031 [DataOverHttps](INFO): SBD MOMSN=15582182 2021-04-18T20:40:15.826Z,1618778415.826 [DataOverHttps](INFO): Sending 225 bytes from file Logs/20210418T183851/Express0034.lzma 2021-04-18T20:40:16.827Z,1618778416.827 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Express0034.lzma.bak 2021-04-18T20:40:16.827Z,1618778416.827 [DataOverHttps](INFO): SBD MOMSN=15582184 2021-04-18T20:40:18.510Z,1618778418.510 [Default:CheckIn:Read_Iridium] Stopped 2021-04-18T20:40:18.510Z,1618778418.510 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-18T20:40:18.510Z,1618778418.510 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-18T20:40:36.683Z,1618778436.683 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-18T20:41:07.390Z,1618778467.390 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-18T20:45:19.092Z,1618778719.092 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-18T20:45:19.092Z,1618778719.092 [Default:CheckIn:C.Wait] Stopped 2021-04-18T20:45:19.092Z,1618778719.092 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-18T20:45:19.093Z,1618778719.093 [Default:CheckIn:D] Running Loop=1 2021-04-18T20:45:19.496Z,1618778719.496 [Default:CheckIn:D] Stopped 2021-04-18T20:45:19.496Z,1618778719.496 [Default:CheckIn:E] Running Loop=1 2021-04-18T20:45:19.909Z,1618778719.909 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 126.456543 min 2021-04-18T20:45:19.909Z,1618778719.909 [Default:CheckIn:E] Stopped 2021-04-18T20:45:19.909Z,1618778719.909 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-18T20:45:19.909Z,1618778719.909 [Default:CheckIn] Stopped 2021-04-18T20:45:19.909Z,1618778719.909 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-18T20:45:19.909Z,1618778719.909 [Default:CheckIn](INFO): Running loop #13 2021-04-18T20:45:19.909Z,1618778719.909 [Default:CheckIn] Running Loop=13 2021-04-18T20:45:19.910Z,1618778719.910 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-18T20:45:19.910Z,1618778719.910 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-18T20:50:20.117Z,1618779020.117 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-18T20:45:19.9Z 2021-04-18T20:50:20.118Z,1618779020.118 [Default:CheckIn:Read_GPS] Stopped 2021-04-18T20:50:20.118Z,1618779020.118 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-18T20:50:24.131Z,1618779024.131 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-18T20:50:31.305Z,1618779031.305 [DataOverHttps](INFO): Sending 38 bytes from file Logs/20210418T183851/Courier0036.lzma 2021-04-18T20:50:32.307Z,1618779032.307 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Courier0036.lzma.bak 2021-04-18T20:50:32.307Z,1618779032.307 [DataOverHttps](INFO): SBD MOMSN=15582199 2021-04-18T20:50:48.070Z,1618779048.070 [DataOverHttps](INFO): Sending 212 bytes from file Logs/20210418T183851/Express0037.lzma 2021-04-18T20:50:49.071Z,1618779049.071 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Express0037.lzma.bak 2021-04-18T20:50:49.071Z,1618779049.071 [DataOverHttps](INFO): SBD MOMSN=15582201 2021-04-18T20:50:50.806Z,1618779050.806 [Default:CheckIn:Read_Iridium] Stopped 2021-04-18T20:50:50.806Z,1618779050.806 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-18T20:50:50.806Z,1618779050.806 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-18T20:50:54.834Z,1618779054.834 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-18T20:55:51.380Z,1618779351.380 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-18T20:55:51.380Z,1618779351.380 [Default:CheckIn:C.Wait] Stopped 2021-04-18T20:55:51.380Z,1618779351.380 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-18T20:55:51.381Z,1618779351.381 [Default:CheckIn:D] Running Loop=1 2021-04-18T20:55:51.788Z,1618779351.788 [Default:CheckIn:D] Stopped 2021-04-18T20:55:51.788Z,1618779351.788 [Default:CheckIn:E] Running Loop=1 2021-04-18T20:55:52.198Z,1618779352.198 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 136.994743 min 2021-04-18T20:55:52.198Z,1618779352.198 [Default:CheckIn:E] Stopped 2021-04-18T20:55:52.198Z,1618779352.198 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-18T20:55:52.198Z,1618779352.198 [Default:CheckIn] Stopped 2021-04-18T20:55:52.198Z,1618779352.198 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-18T20:55:52.199Z,1618779352.199 [Default:CheckIn](INFO): Running loop #14 2021-04-18T20:55:52.199Z,1618779352.199 [Default:CheckIn] Running Loop=14 2021-04-18T20:55:52.199Z,1618779352.199 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-18T20:55:52.199Z,1618779352.199 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-18T20:55:53.791Z,1618779353.791 [NAL9602](FAULT): GPS failed to acquire within timeout. 2021-04-18T20:55:53.791Z,1618779353.791 [NAL9602] Data Fault, FailCount= 4 2021-04-18T20:55:53.791Z,1618779353.791 [NAL9602](ERROR): Data Fault 2021-04-18T20:55:53.838Z,1618779353.838 [CBIT](ERROR): Data Fault in component: NAL9602 2021-04-18T20:55:54.195Z,1618779354.195 [NAL9602](INFO): Powering down 2021-04-18T20:55:55.023Z,1618779355.023 [CBIT](INFO): Clearing failed state for component NAL9602 2021-04-18T20:55:55.023Z,1618779355.023 [NAL9602] No Fault, FailCount= 4 2021-04-18T20:56:24.498Z,1618779384.498 [NAL9602](INFO): Powering up NAL9602 2021-04-18T20:56:35.407Z,1618779395.407 [NAL9602](INFO): NAL9602 initialized 2021-04-18T21:00:52.458Z,1618779652.458 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-18T20:55:52.2Z 2021-04-18T21:00:52.458Z,1618779652.458 [Default:CheckIn:Read_GPS] Stopped 2021-04-18T21:00:52.459Z,1618779652.459 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-18T21:01:00.229Z,1618779660.229 [DataOverHttps](INFO): Sending 38 bytes from file Logs/20210418T183851/Courier0039.lzma 2021-04-18T21:01:01.231Z,1618779661.231 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Courier0039.lzma.bak 2021-04-18T21:01:01.231Z,1618779661.231 [DataOverHttps](INFO): SBD MOMSN=15582216 2021-04-18T21:01:17.013Z,1618779677.013 [DataOverHttps](INFO): Sending 227 bytes from file Logs/20210418T183851/Express0040.lzma 2021-04-18T21:01:18.016Z,1618779678.016 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Express0040.lzma.bak 2021-04-18T21:01:18.016Z,1618779678.016 [DataOverHttps](INFO): SBD MOMSN=15582218 2021-04-18T21:01:19.525Z,1618779679.525 [Default:CheckIn:Read_Iridium] Stopped 2021-04-18T21:01:19.525Z,1618779679.525 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-18T21:01:19.525Z,1618779679.525 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-18T21:01:38.487Z,1618779698.487 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-18T21:02:09.190Z,1618779729.190 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-18T21:06:20.096Z,1618779980.096 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-18T21:06:20.096Z,1618779980.096 [Default:CheckIn:C.Wait] Stopped 2021-04-18T21:06:20.096Z,1618779980.096 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-18T21:06:20.097Z,1618779980.097 [Default:CheckIn:D] Running Loop=1 2021-04-18T21:06:20.503Z,1618779980.503 [Default:CheckIn:D] Stopped 2021-04-18T21:06:20.503Z,1618779980.503 [Default:CheckIn:E] Running Loop=1 2021-04-18T21:06:20.901Z,1618779980.901 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 147.473307 min 2021-04-18T21:06:20.930Z,1618779980.930 [Default:CheckIn:E] Stopped 2021-04-18T21:06:20.930Z,1618779980.930 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-18T21:06:20.930Z,1618779980.930 [Default:CheckIn] Stopped 2021-04-18T21:06:20.930Z,1618779980.930 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-18T21:06:20.930Z,1618779980.930 [Default:CheckIn](INFO): Running loop #15 2021-04-18T21:06:20.930Z,1618779980.930 [Default:CheckIn] Running Loop=15 2021-04-18T21:06:20.930Z,1618779980.930 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-18T21:06:20.931Z,1618779980.931 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-18T21:06:53.607Z,1618780013.607 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-04-18T21:06:53.681Z,1618780013.681 [NAL9602](FAULT): received: +CSQ:0 OK576, 2, 0, 0, 0 OK 2021-04-18T21:06:53.681Z,1618780013.681 [NAL9602] Data Fault, FailCount= 5 2021-04-18T21:06:53.681Z,1618780013.681 [NAL9602](ERROR): Data Fault 2021-04-18T21:06:53.702Z,1618780013.702 [CBIT](ERROR): Data Fault in component: NAL9602 2021-04-18T21:06:53.702Z,1618780013.702 [CBIT](CRITICAL): Data Fault in component: NAL9602 2021-04-18T21:06:54.011Z,1618780014.011 [NAL9602](INFO): Powering down 2021-04-18T21:06:54.049Z,1618780014.049 [CBIT](INFO): Critical error at 20210418T210653 2021-04-18T21:08:54.021Z,1618780134.021 [CBIT](INFO): Clearing failed state for component NAL9602 2021-04-18T21:08:54.021Z,1618780134.021 [NAL9602] No Fault, FailCount= 5 2021-04-18T21:08:54.410Z,1618780134.410 [NAL9602](INFO): Powering up NAL9602 2021-04-18T21:09:05.319Z,1618780145.319 [NAL9602](INFO): NAL9602 initialized 2021-04-18T21:09:06.123Z,1618780146.123 [NAL9602](FAULT): GPS failed to acquire within timeout. 2021-04-18T21:09:06.123Z,1618780146.123 [NAL9602] Data Fault, FailCount= 1 2021-04-18T21:09:06.123Z,1618780146.123 [NAL9602](ERROR): Data Fault 2021-04-18T21:09:06.172Z,1618780146.172 [CBIT](ERROR): Data Fault in component: NAL9602 2021-04-18T21:09:06.522Z,1618780146.522 [NAL9602](INFO): Powering down 2021-04-18T21:09:07.357Z,1618780147.357 [CBIT](INFO): Clearing failed state for component NAL9602 2021-04-18T21:09:07.358Z,1618780147.358 [NAL9602] No Fault, FailCount= 1 2021-04-18T21:09:36.820Z,1618780176.820 [NAL9602](INFO): Powering up NAL9602 2021-04-18T21:09:47.735Z,1618780187.735 [NAL9602](INFO): NAL9602 initialized 2021-04-18T21:11:21.071Z,1618780281.071 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-18T21:06:20.9Z 2021-04-18T21:11:21.071Z,1618780281.071 [Default:CheckIn:Read_GPS] Stopped 2021-04-18T21:11:21.071Z,1618780281.071 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-18T21:11:24.699Z,1618780284.699 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-18T21:11:28.481Z,1618780288.481 [DataOverHttps](INFO): Sending 82 bytes from file Logs/20210418T183851/Courier0042.lzma 2021-04-18T21:11:29.483Z,1618780289.483 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Courier0042.lzma.bak 2021-04-18T21:11:29.483Z,1618780289.483 [DataOverHttps](INFO): SBD MOMSN=15582232 2021-04-18T21:11:45.410Z,1618780305.410 [DataOverHttps](INFO): Sending 267 bytes from file Logs/20210418T183851/Express0043.lzma 2021-04-18T21:11:46.411Z,1618780306.411 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Express0043.lzma.bak 2021-04-18T21:11:46.411Z,1618780306.411 [DataOverHttps](INFO): SBD MOMSN=15582235 2021-04-18T21:11:47.763Z,1618780307.763 [Default:CheckIn:Read_Iridium] Stopped 2021-04-18T21:11:47.763Z,1618780307.763 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-18T21:11:47.763Z,1618780307.763 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-18T21:11:55.406Z,1618780315.406 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-18T21:12:48.355Z,1618780368.355 [CBIT](IMPORTANT): Beginning ground fault scan 2021-04-18T21:12:59.258Z,1618780379.258 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): 0.001923 CHAN A1 (24V): 0.000112 CHAN A2 (12V): -0.002335 CHAN A3 (5V): -0.001530 CHAN B0 (3.3V): 0.000084 CHAN B1 (3.15aV): -0.000185 CHAN B2 (3.15bV): -0.000184 CHAN B3 (GND): 0.000059 OPEN: -0.000509 Full Scale Calc: 4.765 mA, -1.589 mA 2021-04-18T21:16:48.315Z,1618780608.315 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-18T21:16:48.315Z,1618780608.315 [Default:CheckIn:C.Wait] Stopped 2021-04-18T21:16:48.315Z,1618780608.315 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-18T21:16:48.316Z,1618780608.316 [Default:CheckIn:D] Running Loop=1 2021-04-18T21:16:48.758Z,1618780608.758 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2021-04-18T21:16:48.783Z,1618780608.783 [Default:CheckIn:D] Stopped 2021-04-18T21:16:48.783Z,1618780608.783 [Default:CheckIn:E] Running Loop=1 2021-04-18T21:16:49.146Z,1618780609.146 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 157.944645 min 2021-04-18T21:16:49.146Z,1618780609.146 [Default:CheckIn:E] Stopped 2021-04-18T21:16:49.146Z,1618780609.146 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-18T21:16:49.146Z,1618780609.146 [Default:CheckIn] Stopped 2021-04-18T21:16:49.146Z,1618780609.146 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-18T21:16:49.147Z,1618780609.147 [Default:CheckIn](INFO): Running loop #16 2021-04-18T21:16:49.147Z,1618780609.147 [Default:CheckIn] Running Loop=16 2021-04-18T21:16:49.147Z,1618780609.147 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-18T21:16:49.147Z,1618780609.147 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-18T21:17:21.833Z,1618780641.833 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-04-18T21:17:21.913Z,1618780641.913 [NAL9602](FAULT): received: +CSQ:0 OK576, 2, 0, 0, 0 OK 2021-04-18T21:17:21.913Z,1618780641.913 [NAL9602] Data Fault, FailCount= 2 2021-04-18T21:17:21.913Z,1618780641.913 [NAL9602](ERROR): Data Fault 2021-04-18T21:17:21.939Z,1618780641.939 [CBIT](ERROR): Data Fault in component: NAL9602 2021-04-18T21:17:22.239Z,1618780642.239 [NAL9602](INFO): Powering down 2021-04-18T21:17:23.086Z,1618780643.086 [CBIT](INFO): Clearing failed state for component NAL9602 2021-04-18T21:17:23.086Z,1618780643.086 [NAL9602] No Fault, FailCount= 2 2021-04-18T21:17:29.167Z,1618780649.167 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2021-04-18T21:17:52.543Z,1618780672.543 [NAL9602](INFO): Powering up NAL9602 2021-04-18T21:18:03.451Z,1618780683.451 [NAL9602](INFO): NAL9602 initialized 2021-04-18T21:18:14.414Z,1618780694.414 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2021-04-18T21:18:57.268Z,1618780737.268 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2021-04-18T21:19:11.780Z,1618780751.780 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2021-04-18T21:19:26.264Z,1618780766.264 [BPC1](ERROR): BPC1B: No match for serial number 0000 in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file). 2021-04-18T21:20:21.258Z,1618780821.258 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2021-04-18T21:20:34.193Z,1618780834.193 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2021-04-18T21:20:48.803Z,1618780848.803 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2021-04-18T21:21:49.323Z,1618780909.323 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-18T21:16:49.1Z 2021-04-18T21:21:49.324Z,1618780909.324 [Default:CheckIn:Read_GPS] Stopped 2021-04-18T21:21:49.324Z,1618780909.324 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-18T21:21:52.923Z,1618780912.923 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-18T21:21:55.900Z,1618780915.900 [DataOverHttps](INFO): Sending 38 bytes from file Logs/20210418T183851/Courier0045.lzma 2021-04-18T21:21:56.895Z,1618780916.895 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Courier0045.lzma.bak 2021-04-18T21:21:56.895Z,1618780916.895 [DataOverHttps](INFO): SBD MOMSN=15582272 2021-04-18T21:22:12.786Z,1618780932.786 [DataOverHttps](INFO): Sending 449 bytes from file Logs/20210418T183851/Express0046.lzma 2021-04-18T21:22:13.787Z,1618780933.787 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Express0046.lzma.bak 2021-04-18T21:22:13.787Z,1618780933.787 [DataOverHttps](INFO): SBD MOMSN=15582274 2021-04-18T21:22:15.154Z,1618780935.154 [Default:CheckIn:Read_Iridium] Stopped 2021-04-18T21:22:15.154Z,1618780935.154 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-18T21:22:15.154Z,1618780935.154 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-18T21:22:16.001Z,1618780936.001 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2021-04-18T21:22:23.628Z,1618780943.628 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-18T21:23:22.267Z,1618781002.267 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2021-04-18T21:23:33.117Z,1618781013.117 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2021-04-18T21:23:33.120Z,1618781013.120 [BPC1](INFO): Received data from all battery sticks. 2021-04-18T21:27:15.764Z,1618781235.764 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-18T21:27:15.764Z,1618781235.764 [Default:CheckIn:C.Wait] Stopped 2021-04-18T21:27:15.764Z,1618781235.764 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-18T21:27:15.765Z,1618781235.765 [Default:CheckIn:D] Running Loop=1 2021-04-18T21:27:16.168Z,1618781236.168 [Default:CheckIn:D] Stopped 2021-04-18T21:27:16.168Z,1618781236.168 [Default:CheckIn:E] Running Loop=1 2021-04-18T21:27:16.574Z,1618781236.574 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 168.401074 min 2021-04-18T21:27:16.574Z,1618781236.574 [Default:CheckIn:E] Stopped 2021-04-18T21:27:16.574Z,1618781236.574 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-18T21:27:16.574Z,1618781236.574 [Default:CheckIn] Stopped 2021-04-18T21:27:16.574Z,1618781236.574 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-18T21:27:16.574Z,1618781236.574 [Default:CheckIn](INFO): Running loop #17 2021-04-18T21:27:16.574Z,1618781236.574 [Default:CheckIn] Running Loop=17 2021-04-18T21:27:16.574Z,1618781236.574 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-18T21:27:16.575Z,1618781236.575 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-18T21:27:18.177Z,1618781238.177 [NAL9602](FAULT): GPS failed to acquire within timeout. 2021-04-18T21:27:18.177Z,1618781238.177 [NAL9602] Data Fault, FailCount= 3 2021-04-18T21:27:18.177Z,1618781238.177 [NAL9602](ERROR): Data Fault 2021-04-18T21:27:18.197Z,1618781238.197 [CBIT](ERROR): Data Fault in component: NAL9602 2021-04-18T21:27:18.574Z,1618781238.574 [NAL9602](INFO): Powering down 2021-04-18T21:27:19.409Z,1618781239.409 [CBIT](INFO): Clearing failed state for component NAL9602 2021-04-18T21:27:19.410Z,1618781239.410 [NAL9602] No Fault, FailCount= 3 2021-04-18T21:27:48.877Z,1618781268.877 [NAL9602](INFO): Powering up NAL9602 2021-04-18T21:27:59.799Z,1618781279.799 [NAL9602](INFO): NAL9602 initialized 2021-04-18T21:32:16.762Z,1618781536.762 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-18T21:27:16.6Z 2021-04-18T21:32:16.762Z,1618781536.762 [Default:CheckIn:Read_GPS] Stopped 2021-04-18T21:32:16.763Z,1618781536.763 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-18T21:32:23.605Z,1618781543.605 [DataOverHttps](INFO): Sending 50 bytes from file Logs/20210418T183851/Courier0048.lzma 2021-04-18T21:32:24.607Z,1618781544.607 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Courier0048.lzma.bak 2021-04-18T21:32:24.607Z,1618781544.607 [DataOverHttps](INFO): SBD MOMSN=15582329 2021-04-18T21:32:40.498Z,1618781560.498 [DataOverHttps](INFO): Sending 226 bytes from file Logs/20210418T183851/Express0049.lzma 2021-04-18T21:32:41.499Z,1618781561.499 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Express0049.lzma.bak 2021-04-18T21:32:41.500Z,1618781561.500 [DataOverHttps](INFO): SBD MOMSN=15582331 2021-04-18T21:32:43.050Z,1618781563.050 [Default:CheckIn:Read_Iridium] Stopped 2021-04-18T21:32:43.050Z,1618781563.050 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-18T21:32:43.050Z,1618781563.050 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-18T21:33:02.825Z,1618781582.825 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-18T21:33:33.523Z,1618781613.523 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-18T21:37:43.612Z,1618781863.612 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-18T21:37:43.612Z,1618781863.612 [Default:CheckIn:C.Wait] Stopped 2021-04-18T21:37:43.612Z,1618781863.612 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-18T21:37:43.613Z,1618781863.613 [Default:CheckIn:D] Running Loop=1 2021-04-18T21:37:44.015Z,1618781864.015 [Default:CheckIn:D] Stopped 2021-04-18T21:37:44.015Z,1618781864.015 [Default:CheckIn:E] Running Loop=1 2021-04-18T21:37:44.430Z,1618781864.430 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 178.865186 min 2021-04-18T21:37:44.430Z,1618781864.430 [Default:CheckIn:E] Stopped 2021-04-18T21:37:44.430Z,1618781864.430 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-18T21:37:44.431Z,1618781864.431 [Default:CheckIn] Stopped 2021-04-18T21:37:44.431Z,1618781864.431 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-18T21:37:44.431Z,1618781864.431 [Default:CheckIn](INFO): Running loop #18 2021-04-18T21:37:44.431Z,1618781864.431 [Default:CheckIn] Running Loop=18 2021-04-18T21:37:44.431Z,1618781864.431 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-18T21:37:44.431Z,1618781864.431 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-18T21:38:17.134Z,1618781897.134 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-04-18T21:38:17.209Z,1618781897.209 [NAL9602](FAULT): received: +CSQ:0 OK576, 2, 0, 0, 0 OK 2021-04-18T21:38:17.209Z,1618781897.209 [NAL9602] Data Fault, FailCount= 4 2021-04-18T21:38:17.209Z,1618781897.209 [NAL9602](ERROR): Data Fault 2021-04-18T21:38:17.229Z,1618781897.229 [CBIT](ERROR): Data Fault in component: NAL9602 2021-04-18T21:38:17.534Z,1618781897.534 [NAL9602](INFO): Powering down 2021-04-18T21:38:18.374Z,1618781898.374 [CBIT](INFO): Clearing failed state for component NAL9602 2021-04-18T21:38:18.374Z,1618781898.374 [NAL9602] No Fault, FailCount= 4 2021-04-18T21:38:47.832Z,1618781927.832 [NAL9602](INFO): Powering up NAL9602 2021-04-18T21:38:58.755Z,1618781938.755 [NAL9602](INFO): NAL9602 initialized 2021-04-18T21:38:59.555Z,1618781939.555 [NAL9602](FAULT): GPS failed to acquire within timeout. 2021-04-18T21:38:59.555Z,1618781939.555 [NAL9602] Data Fault, FailCount= 5 2021-04-18T21:38:59.555Z,1618781939.555 [NAL9602](ERROR): Data Fault 2021-04-18T21:38:59.606Z,1618781939.606 [CBIT](ERROR): Data Fault in component: NAL9602 2021-04-18T21:38:59.606Z,1618781939.606 [CBIT](CRITICAL): Data Fault in component: NAL9602 2021-04-18T21:38:59.954Z,1618781939.954 [NAL9602](INFO): Powering down 2021-04-18T21:39:00.022Z,1618781940.022 [CBIT](INFO): Critical error at 20210418T213859 2021-04-18T21:40:59.573Z,1618782059.573 [CBIT](INFO): Clearing failed state for component NAL9602 2021-04-18T21:40:59.573Z,1618782059.573 [NAL9602] No Fault, FailCount= 5 2021-04-18T21:40:59.954Z,1618782059.954 [NAL9602](INFO): Powering up NAL9602 2021-04-18T21:41:10.856Z,1618782070.856 [NAL9602](INFO): NAL9602 initialized 2021-04-18T21:42:44.607Z,1618782164.607 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-18T21:37:44.4Z 2021-04-18T21:42:44.607Z,1618782164.607 [Default:CheckIn:Read_GPS] Stopped 2021-04-18T21:42:44.608Z,1618782164.608 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-18T21:42:49.031Z,1618782169.031 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-18T21:42:51.977Z,1618782171.977 [DataOverHttps](INFO): Sending 81 bytes from file Logs/20210418T183851/Courier0051.lzma 2021-04-18T21:42:52.979Z,1618782172.979 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Courier0051.lzma.bak 2021-04-18T21:42:52.979Z,1618782172.979 [DataOverHttps](INFO): SBD MOMSN=15582346 2021-04-18T21:43:08.726Z,1618782188.726 [DataOverHttps](INFO): Sending 266 bytes from file Logs/20210418T183851/Express0052.lzma 2021-04-18T21:43:09.728Z,1618782189.728 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Express0052.lzma.bak 2021-04-18T21:43:09.728Z,1618782189.728 [DataOverHttps](INFO): SBD MOMSN=15582349 2021-04-18T21:43:11.260Z,1618782191.260 [Default:CheckIn:Read_Iridium] Stopped 2021-04-18T21:43:11.261Z,1618782191.261 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-18T21:43:11.261Z,1618782191.261 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-18T21:43:19.738Z,1618782199.738 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-18T21:48:11.843Z,1618782491.843 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-18T21:48:11.843Z,1618782491.843 [Default:CheckIn:C.Wait] Stopped 2021-04-18T21:48:11.843Z,1618782491.843 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-18T21:48:11.844Z,1618782491.844 [Default:CheckIn:D] Running Loop=1 2021-04-18T21:48:12.252Z,1618782492.252 [Default:CheckIn:D] Stopped 2021-04-18T21:48:12.252Z,1618782492.252 [Default:CheckIn:E] Running Loop=1 2021-04-18T21:48:12.659Z,1618782492.659 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 189.335807 min 2021-04-18T21:48:12.660Z,1618782492.660 [Default:CheckIn:E] Stopped 2021-04-18T21:48:12.660Z,1618782492.660 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-18T21:48:12.660Z,1618782492.660 [Default:CheckIn] Stopped 2021-04-18T21:48:12.660Z,1618782492.660 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-18T21:48:12.660Z,1618782492.660 [Default:CheckIn](INFO): Running loop #19 2021-04-18T21:48:12.660Z,1618782492.660 [Default:CheckIn] Running Loop=19 2021-04-18T21:48:12.660Z,1618782492.660 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-18T21:48:12.660Z,1618782492.660 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-18T21:53:12.835Z,1618782792.835 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-18T21:48:12.7Z 2021-04-18T21:53:12.835Z,1618782792.835 [Default:CheckIn:Read_GPS] Stopped 2021-04-18T21:53:12.835Z,1618782792.835 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-18T21:53:16.850Z,1618782796.850 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-18T21:53:19.853Z,1618782799.853 [DataOverHttps](INFO): Sending 38 bytes from file Logs/20210418T183851/Courier0054.lzma 2021-04-18T21:53:20.855Z,1618782800.855 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Courier0054.lzma.bak 2021-04-18T21:53:20.855Z,1618782800.855 [DataOverHttps](INFO): SBD MOMSN=15582366 2021-04-18T21:53:36.693Z,1618782816.693 [DataOverHttps](INFO): Sending 209 bytes from file Logs/20210418T183851/Express0055.lzma 2021-04-18T21:53:37.695Z,1618782817.695 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Express0055.lzma.bak 2021-04-18T21:53:37.695Z,1618782817.695 [DataOverHttps](INFO): SBD MOMSN=15582368 2021-04-18T21:53:39.087Z,1618782819.087 [Default:CheckIn:Read_Iridium] Stopped 2021-04-18T21:53:39.087Z,1618782819.087 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-18T21:53:39.087Z,1618782819.087 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-18T21:53:47.562Z,1618782827.562 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-18T21:58:39.671Z,1618783119.671 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-18T21:58:39.671Z,1618783119.671 [Default:CheckIn:C.Wait] Stopped 2021-04-18T21:58:39.671Z,1618783119.671 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-18T21:58:39.671Z,1618783119.671 [Default:CheckIn:D] Running Loop=1 2021-04-18T21:58:40.064Z,1618783120.064 [Default:CheckIn:D] Stopped 2021-04-18T21:58:40.064Z,1618783120.064 [Default:CheckIn:E] Running Loop=1 2021-04-18T21:58:40.462Z,1618783120.462 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 199.799333 min 2021-04-18T21:58:40.462Z,1618783120.462 [Default:CheckIn:E] Stopped 2021-04-18T21:58:40.463Z,1618783120.463 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-18T21:58:40.463Z,1618783120.463 [Default:CheckIn] Stopped 2021-04-18T21:58:40.463Z,1618783120.463 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-18T21:58:40.463Z,1618783120.463 [Default:CheckIn](INFO): Running loop #20 2021-04-18T21:58:40.463Z,1618783120.463 [Default:CheckIn] Running Loop=20 2021-04-18T21:58:40.463Z,1618783120.463 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-18T21:58:40.463Z,1618783120.463 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-18T21:58:42.068Z,1618783122.068 [NAL9602](FAULT): GPS failed to acquire within timeout. 2021-04-18T21:58:42.068Z,1618783122.068 [NAL9602] Data Fault, FailCount= 1 2021-04-18T21:58:42.068Z,1618783122.068 [NAL9602](ERROR): Data Fault 2021-04-18T21:58:42.088Z,1618783122.088 [CBIT](ERROR): Data Fault in component: NAL9602 2021-04-18T21:58:42.480Z,1618783122.480 [NAL9602](INFO): Powering down 2021-04-18T21:58:43.306Z,1618783123.306 [CBIT](INFO): Clearing failed state for component NAL9602 2021-04-18T21:58:43.306Z,1618783123.306 [NAL9602] No Fault, FailCount= 1 2021-04-18T21:59:12.782Z,1618783152.782 [NAL9602](INFO): Powering up NAL9602 2021-04-18T21:59:23.691Z,1618783163.691 [NAL9602](INFO): NAL9602 initialized 2021-04-18T22:03:40.681Z,1618783420.681 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-18T21:58:40.5Z 2021-04-18T22:03:40.681Z,1618783420.681 [Default:CheckIn:Read_GPS] Stopped 2021-04-18T22:03:40.682Z,1618783420.682 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-18T22:03:47.509Z,1618783427.509 [DataOverHttps](INFO): Sending 38 bytes from file Logs/20210418T183851/Courier0057.lzma 2021-04-18T22:03:48.511Z,1618783428.511 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Courier0057.lzma.bak 2021-04-18T22:03:48.511Z,1618783428.511 [DataOverHttps](INFO): SBD MOMSN=15582382 2021-04-18T22:04:04.578Z,1618783444.578 [DataOverHttps](INFO): Sending 225 bytes from file Logs/20210418T183851/Express0058.lzma 2021-04-18T22:04:05.579Z,1618783445.579 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Express0058.lzma.bak 2021-04-18T22:04:05.579Z,1618783445.579 [DataOverHttps](INFO): SBD MOMSN=15582384 2021-04-18T22:04:07.398Z,1618783447.398 [Default:CheckIn:Read_Iridium] Stopped 2021-04-18T22:04:07.398Z,1618783447.398 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-18T22:04:07.398Z,1618783447.398 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-18T22:04:26.776Z,1618783466.776 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-18T22:04:57.477Z,1618783497.477 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-18T22:09:07.968Z,1618783747.968 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-18T22:09:07.968Z,1618783747.968 [Default:CheckIn:C.Wait] Stopped 2021-04-18T22:09:07.968Z,1618783747.968 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-18T22:09:07.969Z,1618783747.969 [Default:CheckIn:D] Running Loop=1 2021-04-18T22:09:08.378Z,1618783748.378 [Default:CheckIn:D] Stopped 2021-04-18T22:09:08.378Z,1618783748.378 [Default:CheckIn:E] Running Loop=1 2021-04-18T22:09:08.773Z,1618783748.773 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 210.271224 min 2021-04-18T22:09:08.773Z,1618783748.773 [Default:CheckIn:E] Stopped 2021-04-18T22:09:08.773Z,1618783748.773 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-18T22:09:08.773Z,1618783748.773 [Default:CheckIn] Stopped 2021-04-18T22:09:08.773Z,1618783748.773 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-18T22:09:08.773Z,1618783748.773 [Default:CheckIn](INFO): Running loop #21 2021-04-18T22:09:08.774Z,1618783748.774 [Default:CheckIn] Running Loop=21 2021-04-18T22:09:08.774Z,1618783748.774 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-18T22:09:08.774Z,1618783748.774 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-18T22:09:41.487Z,1618783781.487 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-04-18T22:09:41.561Z,1618783781.561 [NAL9602](FAULT): received: +CSQ:0 OK576, 2, 0, 0, 0 OK 2021-04-18T22:09:41.561Z,1618783781.561 [NAL9602] Data Fault, FailCount= 2 2021-04-18T22:09:41.561Z,1618783781.561 [NAL9602](ERROR): Data Fault 2021-04-18T22:09:41.677Z,1618783781.677 [CBIT](ERROR): Data Fault in component: NAL9602 2021-04-18T22:09:41.886Z,1618783781.886 [NAL9602](INFO): Powering down 2021-04-18T22:09:42.720Z,1618783782.720 [CBIT](INFO): Clearing failed state for component NAL9602 2021-04-18T22:09:42.720Z,1618783782.720 [NAL9602] No Fault, FailCount= 2 2021-04-18T22:10:12.202Z,1618783812.202 [NAL9602](INFO): Powering up NAL9602 2021-04-18T22:10:23.209Z,1618783823.209 [NAL9602](INFO): NAL9602 initialized 2021-04-18T22:10:24.031Z,1618783824.031 [NAL9602](FAULT): GPS failed to acquire within timeout. 2021-04-18T22:10:24.031Z,1618783824.031 [NAL9602] Data Fault, FailCount= 3 2021-04-18T22:10:24.031Z,1618783824.031 [NAL9602](ERROR): Data Fault 2021-04-18T22:10:24.189Z,1618783824.189 [CBIT](ERROR): Data Fault in component: NAL9602 2021-04-18T22:10:24.436Z,1618783824.436 [NAL9602](INFO): Powering down 2021-04-18T22:10:25.367Z,1618783825.367 [CBIT](INFO): Clearing failed state for component NAL9602 2021-04-18T22:10:25.368Z,1618783825.368 [NAL9602] No Fault, FailCount= 3 2021-04-18T22:10:54.743Z,1618783854.743 [NAL9602](INFO): Powering up NAL9602 2021-04-18T22:11:05.650Z,1618783865.650 [NAL9602](INFO): NAL9602 initialized 2021-04-18T22:14:09.074Z,1618784049.074 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-18T22:09:08.8Z 2021-04-18T22:14:09.074Z,1618784049.074 [Default:CheckIn:Read_GPS] Stopped 2021-04-18T22:14:09.074Z,1618784049.074 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-18T22:14:13.112Z,1618784053.112 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-18T22:14:16.437Z,1618784056.437 [DataOverHttps](INFO): Sending 38 bytes from file Logs/20210418T183851/Courier0060.lzma 2021-04-18T22:14:17.440Z,1618784057.440 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Courier0060.lzma.bak 2021-04-18T22:14:17.440Z,1618784057.440 [DataOverHttps](INFO): SBD MOMSN=15582414 2021-04-18T22:14:33.838Z,1618784073.838 [DataOverHttps](INFO): Sending 264 bytes from file Logs/20210418T183851/Express0061.lzma 2021-04-18T22:14:34.839Z,1618784074.839 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Express0061.lzma.bak 2021-04-18T22:14:34.839Z,1618784074.839 [DataOverHttps](INFO): SBD MOMSN=15582416 2021-04-18T22:14:36.550Z,1618784076.550 [Default:CheckIn:Read_Iridium] Stopped 2021-04-18T22:14:36.550Z,1618784076.550 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-18T22:14:36.550Z,1618784076.550 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-18T22:14:43.806Z,1618784083.806 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-18T22:19:37.126Z,1618784377.126 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-18T22:19:37.126Z,1618784377.126 [Default:CheckIn:C.Wait] Stopped 2021-04-18T22:19:37.126Z,1618784377.126 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-18T22:19:37.127Z,1618784377.127 [Default:CheckIn:D] Running Loop=1 2021-04-18T22:19:37.543Z,1618784377.543 [Default:CheckIn:D] Stopped 2021-04-18T22:19:37.543Z,1618784377.543 [Default:CheckIn:E] Running Loop=1 2021-04-18T22:19:37.930Z,1618784377.930 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 220.757324 min 2021-04-18T22:19:37.931Z,1618784377.931 [Default:CheckIn:E] Stopped 2021-04-18T22:19:37.931Z,1618784377.931 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-18T22:19:37.931Z,1618784377.931 [Default:CheckIn] Stopped 2021-04-18T22:19:37.931Z,1618784377.931 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-18T22:19:37.931Z,1618784377.931 [Default:CheckIn](INFO): Running loop #22 2021-04-18T22:19:37.931Z,1618784377.931 [Default:CheckIn] Running Loop=22 2021-04-18T22:19:37.931Z,1618784377.931 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-18T22:19:37.931Z,1618784377.931 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-18T22:24:38.176Z,1618784678.176 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-18T22:19:37.9Z 2021-04-18T22:24:38.176Z,1618784678.176 [Default:CheckIn:Read_GPS] Stopped 2021-04-18T22:24:38.176Z,1618784678.176 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-18T22:24:42.203Z,1618784682.203 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-18T22:24:46.117Z,1618784686.117 [DataOverHttps](INFO): Sending 38 bytes from file Logs/20210418T183851/Courier0063.lzma 2021-04-18T22:24:47.119Z,1618784687.119 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Courier0063.lzma.bak 2021-04-18T22:24:47.119Z,1618784687.119 [DataOverHttps](INFO): SBD MOMSN=15582439 2021-04-18T22:25:01.287Z,1618784701.287 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2021-04-18T22:25:03.081Z,1618784703.081 [DataOverHttps](INFO): Sending 208 bytes from file Logs/20210418T183851/Express0064.lzma 2021-04-18T22:25:04.083Z,1618784704.083 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Express0064.lzma.bak 2021-04-18T22:25:04.083Z,1618784704.083 [DataOverHttps](INFO): SBD MOMSN=15582473 2021-04-18T22:25:05.651Z,1618784705.651 [Default:CheckIn:Read_Iridium] Stopped 2021-04-18T22:25:05.651Z,1618784705.651 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-18T22:25:05.651Z,1618784705.651 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-18T22:25:12.904Z,1618784712.904 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-18T22:25:25.474Z,1618784725.474 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2021-04-18T22:25:30.736Z,1618784730.736 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2021-04-18T22:27:08.089Z,1618784828.089 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2021-04-18T22:27:20.209Z,1618784840.209 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2021-04-18T22:28:58.326Z,1618784938.326 [BPC1](ERROR): BPC1B got IPBS message with 5 sticks (min is 7). 2021-04-18T22:28:58.330Z,1618784938.330 [BPC1](ERROR): BPC1B failed to parse battery stick message. 2021-04-18T22:29:05.256Z,1618784945.256 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2021-04-18T22:30:06.220Z,1618785006.220 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-18T22:30:06.220Z,1618785006.220 [Default:CheckIn:C.Wait] Stopped 2021-04-18T22:30:06.221Z,1618785006.221 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-18T22:30:06.221Z,1618785006.221 [Default:CheckIn:D] Running Loop=1 2021-04-18T22:30:06.630Z,1618785006.630 [Default:CheckIn:D] Stopped 2021-04-18T22:30:06.630Z,1618785006.630 [Default:CheckIn:E] Running Loop=1 2021-04-18T22:30:07.018Z,1618785007.018 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 231.242090 min 2021-04-18T22:30:07.019Z,1618785007.019 [Default:CheckIn:E] Stopped 2021-04-18T22:30:07.019Z,1618785007.019 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-18T22:30:07.019Z,1618785007.019 [Default:CheckIn] Stopped 2021-04-18T22:30:07.019Z,1618785007.019 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-18T22:30:07.019Z,1618785007.019 [Default:CheckIn](INFO): Running loop #23 2021-04-18T22:30:07.019Z,1618785007.019 [Default:CheckIn] Running Loop=23 2021-04-18T22:30:07.019Z,1618785007.019 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-18T22:30:07.019Z,1618785007.019 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-18T22:30:08.627Z,1618785008.627 [NAL9602](FAULT): GPS failed to acquire within timeout. 2021-04-18T22:30:08.627Z,1618785008.627 [NAL9602] Data Fault, FailCount= 4 2021-04-18T22:30:08.627Z,1618785008.627 [NAL9602](ERROR): Data Fault 2021-04-18T22:30:08.647Z,1618785008.647 [CBIT](ERROR): Data Fault in component: NAL9602 2021-04-18T22:30:09.031Z,1618785009.031 [NAL9602](INFO): Powering down 2021-04-18T22:30:09.876Z,1618785009.876 [CBIT](INFO): Clearing failed state for component NAL9602 2021-04-18T22:30:09.876Z,1618785009.876 [NAL9602] No Fault, FailCount= 4 2021-04-18T22:30:39.421Z,1618785039.421 [NAL9602](INFO): Powering up NAL9602 2021-04-18T22:30:50.327Z,1618785050.327 [NAL9602](INFO): NAL9602 initialized 2021-04-18T22:31:14.275Z,1618785074.275 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2021-04-18T22:31:31.129Z,1618785091.129 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2021-04-18T22:31:31.132Z,1618785091.132 [BPC1](INFO): Received data from all battery sticks. 2021-04-18T22:35:07.285Z,1618785307.285 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-18T22:30:07.0Z 2021-04-18T22:35:07.285Z,1618785307.285 [Default:CheckIn:Read_GPS] Stopped 2021-04-18T22:35:07.286Z,1618785307.286 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-18T22:35:15.009Z,1618785315.009 [DataOverHttps](INFO): Sending 50 bytes from file Logs/20210418T183851/Courier0066.lzma 2021-04-18T22:35:16.011Z,1618785316.011 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Courier0066.lzma.bak 2021-04-18T22:35:16.012Z,1618785316.012 [DataOverHttps](INFO): SBD MOMSN=15582515 2021-04-18T22:35:31.837Z,1618785331.837 [DataOverHttps](INFO): Sending 226 bytes from file Logs/20210418T183851/Express0067.lzma 2021-04-18T22:35:32.841Z,1618785332.841 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Express0067.lzma.bak 2021-04-18T22:35:32.841Z,1618785332.841 [DataOverHttps](INFO): SBD MOMSN=15582525 2021-04-18T22:35:34.345Z,1618785334.345 [Default:CheckIn:Read_Iridium] Stopped 2021-04-18T22:35:34.345Z,1618785334.345 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-18T22:35:34.345Z,1618785334.345 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-18T22:35:53.326Z,1618785353.326 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-18T22:36:24.036Z,1618785384.036 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-18T22:40:34.940Z,1618785634.940 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-18T22:40:34.940Z,1618785634.940 [Default:CheckIn:C.Wait] Stopped 2021-04-18T22:40:34.941Z,1618785634.941 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-18T22:40:34.941Z,1618785634.941 [Default:CheckIn:D] Running Loop=1 2021-04-18T22:40:35.338Z,1618785635.338 [Default:CheckIn:D] Stopped 2021-04-18T22:40:35.338Z,1618785635.338 [Default:CheckIn:E] Running Loop=1 2021-04-18T22:40:35.737Z,1618785635.737 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 241.720557 min 2021-04-18T22:40:35.738Z,1618785635.738 [Default:CheckIn:E] Stopped 2021-04-18T22:40:35.738Z,1618785635.738 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-18T22:40:35.738Z,1618785635.738 [Default:CheckIn] Stopped 2021-04-18T22:40:35.738Z,1618785635.738 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-18T22:40:35.738Z,1618785635.738 [Default:CheckIn](INFO): Running loop #24 2021-04-18T22:40:35.738Z,1618785635.738 [Default:CheckIn] Running Loop=24 2021-04-18T22:40:35.738Z,1618785635.738 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-18T22:40:35.738Z,1618785635.738 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-18T22:45:35.938Z,1618785935.938 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-18T22:40:35.7Z 2021-04-18T22:45:35.938Z,1618785935.938 [Default:CheckIn:Read_GPS] Stopped 2021-04-18T22:45:35.939Z,1618785935.939 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-18T22:45:39.539Z,1618785939.539 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-18T22:45:42.145Z,1618785942.145 [DataOverHttps](INFO): Sending 38 bytes from file Logs/20210418T183851/Courier0069.lzma 2021-04-18T22:45:43.139Z,1618785943.139 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Courier0069.lzma.bak 2021-04-18T22:45:43.140Z,1618785943.140 [DataOverHttps](INFO): SBD MOMSN=15582591 2021-04-18T22:45:58.769Z,1618785958.769 [DataOverHttps](INFO): Sending 208 bytes from file Logs/20210418T183851/Express0070.lzma 2021-04-18T22:45:59.771Z,1618785959.771 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Express0070.lzma.bak 2021-04-18T22:45:59.772Z,1618785959.772 [DataOverHttps](INFO): SBD MOMSN=15582595 2021-04-18T22:46:01.364Z,1618785961.364 [Default:CheckIn:Read_Iridium] Stopped 2021-04-18T22:46:01.364Z,1618785961.364 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-18T22:46:01.365Z,1618785961.365 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-18T22:46:10.239Z,1618785970.239 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-18T22:51:01.954Z,1618786261.954 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-18T22:51:01.954Z,1618786261.954 [Default:CheckIn:C.Wait] Stopped 2021-04-18T22:51:01.954Z,1618786261.954 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-18T22:51:01.954Z,1618786261.954 [Default:CheckIn:D] Running Loop=1 2021-04-18T22:51:02.372Z,1618786262.372 [Default:CheckIn:D] Stopped 2021-04-18T22:51:02.372Z,1618786262.372 [Default:CheckIn:E] Running Loop=1 2021-04-18T22:51:02.761Z,1618786262.761 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 252.171126 min 2021-04-18T22:51:02.761Z,1618786262.761 [Default:CheckIn:E] Stopped 2021-04-18T22:51:02.761Z,1618786262.761 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-18T22:51:02.761Z,1618786262.761 [Default:CheckIn] Stopped 2021-04-18T22:51:02.761Z,1618786262.761 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-18T22:51:02.761Z,1618786262.761 [Default:CheckIn](INFO): Running loop #25 2021-04-18T22:51:02.761Z,1618786262.761 [Default:CheckIn] Running Loop=25 2021-04-18T22:51:02.762Z,1618786262.762 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-18T22:51:02.762Z,1618786262.762 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-18T22:51:04.367Z,1618786264.367 [NAL9602](FAULT): GPS failed to acquire within timeout. 2021-04-18T22:51:04.367Z,1618786264.367 [NAL9602] Data Fault, FailCount= 5 2021-04-18T22:51:04.367Z,1618786264.367 [NAL9602](ERROR): Data Fault 2021-04-18T22:51:04.403Z,1618786264.403 [CBIT](ERROR): Data Fault in component: NAL9602 2021-04-18T22:51:04.404Z,1618786264.404 [CBIT](CRITICAL): Data Fault in component: NAL9602 2021-04-18T22:51:04.766Z,1618786264.766 [NAL9602](INFO): Powering down 2021-04-18T22:51:04.792Z,1618786264.792 [CBIT](INFO): Critical error at 20210418T225104 2021-04-18T22:53:04.406Z,1618786384.406 [CBIT](INFO): Clearing failed state for component NAL9602 2021-04-18T22:53:04.406Z,1618786384.406 [NAL9602] No Fault, FailCount= 5 2021-04-18T22:53:04.758Z,1618786384.758 [NAL9602](INFO): Powering up NAL9602 2021-04-18T22:53:15.663Z,1618786395.663 [NAL9602](INFO): NAL9602 initialized 2021-04-18T22:56:02.942Z,1618786562.942 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-18T22:51:02.8Z 2021-04-18T22:56:02.942Z,1618786562.942 [Default:CheckIn:Read_GPS] Stopped 2021-04-18T22:56:02.943Z,1618786562.943 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-18T22:56:09.753Z,1618786569.753 [DataOverHttps](INFO): Sending 81 bytes from file Logs/20210418T183851/Courier0072.lzma 2021-04-18T22:56:10.755Z,1618786570.755 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Courier0072.lzma.bak 2021-04-18T22:56:10.755Z,1618786570.755 [DataOverHttps](INFO): SBD MOMSN=15582617 2021-04-18T22:56:26.693Z,1618786586.693 [DataOverHttps](INFO): Sending 227 bytes from file Logs/20210418T183851/Express0073.lzma 2021-04-18T22:56:27.695Z,1618786587.695 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Express0073.lzma.bak 2021-04-18T22:56:27.696Z,1618786587.696 [DataOverHttps](INFO): SBD MOMSN=15582624 2021-04-18T22:56:29.209Z,1618786589.209 [Default:CheckIn:Read_Iridium] Stopped 2021-04-18T22:56:29.209Z,1618786589.209 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-18T22:56:29.209Z,1618786589.209 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-18T22:58:18.671Z,1618786698.671 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-18T22:58:49.380Z,1618786729.380 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-18T23:01:29.813Z,1618786889.813 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-18T23:01:29.813Z,1618786889.813 [Default:CheckIn:C.Wait] Stopped 2021-04-18T23:01:29.814Z,1618786889.814 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-18T23:01:29.814Z,1618786889.814 [Default:CheckIn:D] Running Loop=1 2021-04-18T23:01:30.209Z,1618786890.209 [Default:CheckIn:D] Stopped 2021-04-18T23:01:30.209Z,1618786890.209 [Default:CheckIn:E] Running Loop=1 2021-04-18T23:01:30.606Z,1618786890.606 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 262.635075 min 2021-04-18T23:01:30.606Z,1618786890.606 [Default:CheckIn:E] Stopped 2021-04-18T23:01:30.607Z,1618786890.607 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-18T23:01:30.607Z,1618786890.607 [Default:CheckIn] Stopped 2021-04-18T23:01:30.607Z,1618786890.607 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-18T23:01:30.607Z,1618786890.607 [Default:CheckIn](INFO): Running loop #26 2021-04-18T23:01:30.607Z,1618786890.607 [Default:CheckIn] Running Loop=26 2021-04-18T23:01:30.607Z,1618786890.607 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-18T23:01:30.607Z,1618786890.607 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-18T23:02:03.333Z,1618786923.333 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-04-18T23:02:03.409Z,1618786923.409 [NAL9602](FAULT): received: +CSQ:0 OK576, 2, 0, 0, 0 OK 2021-04-18T23:02:03.409Z,1618786923.409 [NAL9602] Data Fault, FailCount= 1 2021-04-18T23:02:03.409Z,1618786923.409 [NAL9602](ERROR): Data Fault 2021-04-18T23:02:03.466Z,1618786923.466 [CBIT](ERROR): Data Fault in component: NAL9602 2021-04-18T23:02:03.727Z,1618786923.727 [NAL9602](INFO): Powering down 2021-04-18T23:02:04.555Z,1618786924.555 [CBIT](INFO): Clearing failed state for component NAL9602 2021-04-18T23:02:04.555Z,1618786924.555 [NAL9602] No Fault, FailCount= 1 2021-04-18T23:02:34.034Z,1618786954.034 [NAL9602](INFO): Powering up NAL9602 2021-04-18T23:02:44.935Z,1618786964.935 [NAL9602](INFO): NAL9602 initialized 2021-04-18T23:06:30.796Z,1618787190.796 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-18T23:01:30.6Z 2021-04-18T23:06:30.796Z,1618787190.796 [Default:CheckIn:Read_GPS] Stopped 2021-04-18T23:06:30.796Z,1618787190.796 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-18T23:06:35.215Z,1618787195.215 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-18T23:06:38.515Z,1618787198.515 [DataOverHttps](INFO): Sending 38 bytes from file Logs/20210418T183851/Courier0075.lzma 2021-04-18T23:06:39.379Z,1618787199.379 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Courier0075.lzma.bak 2021-04-18T23:06:39.379Z,1618787199.379 [DataOverHttps](INFO): SBD MOMSN=15582662 2021-04-18T23:06:55.333Z,1618787215.333 [DataOverHttps](INFO): Sending 248 bytes from file Logs/20210418T183851/Express0076.lzma 2021-04-18T23:06:56.335Z,1618787216.335 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Express0076.lzma.bak 2021-04-18T23:06:56.336Z,1618787216.336 [DataOverHttps](INFO): SBD MOMSN=15582666 2021-04-18T23:06:57.857Z,1618787217.857 [Default:CheckIn:Read_Iridium] Stopped 2021-04-18T23:06:57.857Z,1618787217.857 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-18T23:06:57.857Z,1618787217.857 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-18T23:07:05.922Z,1618787225.922 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-18T23:11:58.439Z,1618787518.439 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-18T23:11:58.439Z,1618787518.439 [Default:CheckIn:C.Wait] Stopped 2021-04-18T23:11:58.439Z,1618787518.439 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-18T23:11:58.439Z,1618787518.439 [Default:CheckIn:D] Running Loop=1 2021-04-18T23:11:58.853Z,1618787518.853 [Default:CheckIn:D] Stopped 2021-04-18T23:11:58.854Z,1618787518.854 [Default:CheckIn:E] Running Loop=1 2021-04-18T23:11:59.246Z,1618787519.246 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 273.112500 min 2021-04-18T23:11:59.246Z,1618787519.246 [Default:CheckIn:E] Stopped 2021-04-18T23:11:59.247Z,1618787519.247 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-18T23:11:59.247Z,1618787519.247 [Default:CheckIn] Stopped 2021-04-18T23:11:59.247Z,1618787519.247 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-18T23:11:59.247Z,1618787519.247 [Default:CheckIn](INFO): Running loop #27 2021-04-18T23:11:59.247Z,1618787519.247 [Default:CheckIn] Running Loop=27 2021-04-18T23:11:59.247Z,1618787519.247 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-18T23:11:59.247Z,1618787519.247 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-18T23:12:00.854Z,1618787520.854 [NAL9602](FAULT): GPS failed to acquire within timeout. 2021-04-18T23:12:00.855Z,1618787520.855 [NAL9602] Data Fault, FailCount= 2 2021-04-18T23:12:00.855Z,1618787520.855 [NAL9602](ERROR): Data Fault 2021-04-18T23:12:00.899Z,1618787520.899 [CBIT](ERROR): Data Fault in component: NAL9602 2021-04-18T23:12:01.258Z,1618787521.258 [NAL9602](INFO): Powering down 2021-04-18T23:12:02.092Z,1618787522.092 [CBIT](INFO): Clearing failed state for component NAL9602 2021-04-18T23:12:02.092Z,1618787522.092 [NAL9602] No Fault, FailCount= 2 2021-04-18T23:12:31.554Z,1618787551.554 [NAL9602](INFO): Powering up NAL9602 2021-04-18T23:12:42.463Z,1618787562.463 [NAL9602](INFO): NAL9602 initialized 2021-04-18T23:16:59.421Z,1618787819.421 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-18T23:11:59.2Z 2021-04-18T23:16:59.421Z,1618787819.421 [Default:CheckIn:Read_GPS] Stopped 2021-04-18T23:16:59.421Z,1618787819.421 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-18T23:17:06.757Z,1618787826.757 [DataOverHttps](INFO): Sending 38 bytes from file Logs/20210418T183851/Courier0078.lzma 2021-04-18T23:17:07.775Z,1618787827.775 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Courier0078.lzma.bak 2021-04-18T23:17:07.775Z,1618787827.775 [DataOverHttps](INFO): SBD MOMSN=15582751 2021-04-18T23:17:23.685Z,1618787843.685 [DataOverHttps](INFO): Sending 225 bytes from file Logs/20210418T183851/Express0079.lzma 2021-04-18T23:17:24.687Z,1618787844.687 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Express0079.lzma.bak 2021-04-18T23:17:24.688Z,1618787844.688 [DataOverHttps](INFO): SBD MOMSN=15582786 2021-04-18T23:17:26.094Z,1618787846.094 [Default:CheckIn:Read_Iridium] Stopped 2021-04-18T23:17:26.094Z,1618787846.094 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-18T23:17:26.094Z,1618787846.094 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-18T23:17:45.476Z,1618787865.476 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-18T23:18:16.170Z,1618787896.170 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-18T23:22:26.742Z,1618788146.742 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-18T23:22:26.742Z,1618788146.742 [Default:CheckIn:C.Wait] Stopped 2021-04-18T23:22:26.742Z,1618788146.742 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-18T23:22:26.742Z,1618788146.742 [Default:CheckIn:D] Running Loop=1 2021-04-18T23:22:27.136Z,1618788147.136 [Default:CheckIn:D] Stopped 2021-04-18T23:22:27.136Z,1618788147.136 [Default:CheckIn:E] Running Loop=1 2021-04-18T23:22:27.534Z,1618788147.534 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 283.583887 min 2021-04-18T23:22:27.534Z,1618788147.534 [Default:CheckIn:E] Stopped 2021-04-18T23:22:27.535Z,1618788147.535 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-18T23:22:27.535Z,1618788147.535 [Default:CheckIn] Stopped 2021-04-18T23:22:27.535Z,1618788147.535 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-18T23:22:27.535Z,1618788147.535 [Default:CheckIn](INFO): Running loop #28 2021-04-18T23:22:27.535Z,1618788147.535 [Default:CheckIn] Running Loop=28 2021-04-18T23:22:27.535Z,1618788147.535 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-18T23:22:27.535Z,1618788147.535 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-18T23:23:00.257Z,1618788180.257 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-04-18T23:23:00.329Z,1618788180.329 [NAL9602](FAULT): received: +CSQ:0 OK576, 2, 0, 0, 0 OK 2021-04-18T23:23:00.329Z,1618788180.329 [NAL9602] Data Fault, FailCount= 3 2021-04-18T23:23:00.329Z,1618788180.329 [NAL9602](ERROR): Data Fault 2021-04-18T23:23:00.410Z,1618788180.410 [CBIT](ERROR): Data Fault in component: NAL9602 2021-04-18T23:23:00.654Z,1618788180.654 [NAL9602](INFO): Powering down 2021-04-18T23:23:01.059Z,1618788181.059 [NAL9602](FAULT): LCB fault: Software Overcurrent. 2021-04-18T23:23:01.059Z,1618788181.059 [NAL9602] Hardware Fault, FailCount= 3 2021-04-18T23:23:01.059Z,1618788181.059 [NAL9602](ERROR): Hardware Fault 2021-04-18T23:23:01.495Z,1618788181.495 [CBIT](INFO): Clearing failed state for component NAL9602 2021-04-18T23:23:01.495Z,1618788181.495 [NAL9602] No Fault, FailCount= 3 2021-04-18T23:23:30.958Z,1618788210.958 [NAL9602](INFO): Powering up NAL9602 2021-04-18T23:23:41.863Z,1618788221.863 [NAL9602](INFO): NAL9602 initialized 2021-04-18T23:23:42.675Z,1618788222.675 [NAL9602](FAULT): GPS failed to acquire within timeout. 2021-04-18T23:23:42.675Z,1618788222.675 [NAL9602] Data Fault, FailCount= 4 2021-04-18T23:23:42.675Z,1618788222.675 [NAL9602](ERROR): Data Fault 2021-04-18T23:23:42.731Z,1618788222.731 [CBIT](ERROR): Data Fault in component: NAL9602 2021-04-18T23:23:43.078Z,1618788223.078 [NAL9602](INFO): Powering down 2021-04-18T23:23:43.904Z,1618788223.904 [CBIT](INFO): Clearing failed state for component NAL9602 2021-04-18T23:23:43.904Z,1618788223.904 [NAL9602] No Fault, FailCount= 4 2021-04-18T23:24:13.379Z,1618788253.379 [NAL9602](INFO): Powering up NAL9602 2021-04-18T23:24:24.287Z,1618788264.287 [NAL9602](INFO): NAL9602 initialized 2021-04-18T23:27:27.713Z,1618788447.713 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-18T23:22:27.5Z 2021-04-18T23:27:27.714Z,1618788447.714 [Default:CheckIn:Read_GPS] Stopped 2021-04-18T23:27:27.714Z,1618788447.714 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-18T23:27:31.739Z,1618788451.739 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-18T23:27:35.277Z,1618788455.277 [DataOverHttps](INFO): Sending 38 bytes from file Logs/20210418T183851/Courier0081.lzma 2021-04-18T23:27:36.279Z,1618788456.279 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Courier0081.lzma.bak 2021-04-18T23:27:36.279Z,1618788456.279 [DataOverHttps](INFO): SBD MOMSN=15582854 2021-04-18T23:27:52.094Z,1618788472.094 [DataOverHttps](INFO): Sending 299 bytes from file Logs/20210418T183851/Express0082.lzma 2021-04-18T23:27:53.095Z,1618788473.095 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Express0082.lzma.bak 2021-04-18T23:27:53.096Z,1618788473.096 [DataOverHttps](INFO): SBD MOMSN=15582856 2021-04-18T23:27:54.789Z,1618788474.789 [Default:CheckIn:Read_Iridium] Stopped 2021-04-18T23:27:54.789Z,1618788474.789 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-18T23:27:54.789Z,1618788474.789 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-18T23:28:02.442Z,1618788482.442 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-18T23:32:55.360Z,1618788775.360 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-18T23:32:55.360Z,1618788775.360 [Default:CheckIn:C.Wait] Stopped 2021-04-18T23:32:55.360Z,1618788775.360 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-18T23:32:55.361Z,1618788775.361 [Default:CheckIn:D] Running Loop=1 2021-04-18T23:32:55.766Z,1618788775.766 [Default:CheckIn:D] Stopped 2021-04-18T23:32:55.766Z,1618788775.766 [Default:CheckIn:E] Running Loop=1 2021-04-18T23:32:56.185Z,1618788776.185 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 294.061035 min 2021-04-18T23:32:56.185Z,1618788776.185 [Default:CheckIn:E] Stopped 2021-04-18T23:32:56.185Z,1618788776.185 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-18T23:32:56.185Z,1618788776.185 [Default:CheckIn] Stopped 2021-04-18T23:32:56.185Z,1618788776.185 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-18T23:32:56.185Z,1618788776.185 [Default:CheckIn](INFO): Running loop #29 2021-04-18T23:32:56.185Z,1618788776.185 [Default:CheckIn] Running Loop=29 2021-04-18T23:32:56.186Z,1618788776.186 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-18T23:32:56.186Z,1618788776.186 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-18T23:33:00.258Z,1618788780.258 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2021-04-18T23:33:47.521Z,1618788827.521 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2021-04-18T23:34:16.611Z,1618788856.611 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2021-04-18T23:34:48.147Z,1618788888.147 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2021-04-18T23:35:53.163Z,1618788953.163 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2021-04-18T23:35:56.792Z,1618788956.792 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2021-04-18T23:36:11.346Z,1618788971.346 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2021-04-18T23:36:21.437Z,1618788981.437 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2021-04-18T23:36:56.592Z,1618789016.592 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2021-04-18T23:37:10.735Z,1618789030.735 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2021-04-18T23:37:46.276Z,1618789066.276 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2021-04-18T23:37:56.353Z,1618789076.353 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-18T23:32:56.2Z 2021-04-18T23:37:56.353Z,1618789076.353 [Default:CheckIn:Read_GPS] Stopped 2021-04-18T23:37:56.353Z,1618789076.353 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-18T23:37:57.994Z,1618789077.994 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2021-04-18T23:37:59.963Z,1618789079.963 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-18T23:38:04.085Z,1618789084.085 [DataOverHttps](INFO): Sending 38 bytes from file Logs/20210418T183851/Courier0084.lzma 2021-04-18T23:38:05.088Z,1618789085.088 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Courier0084.lzma.bak 2021-04-18T23:38:05.088Z,1618789085.088 [DataOverHttps](INFO): SBD MOMSN=15582941 2021-04-18T23:38:20.861Z,1618789100.861 [DataOverHttps](INFO): Sending 208 bytes from file Logs/20210418T183851/Express0085.lzma 2021-04-18T23:38:21.863Z,1618789101.863 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Express0085.lzma.bak 2021-04-18T23:38:21.863Z,1618789101.863 [DataOverHttps](INFO): SBD MOMSN=15582943 2021-04-18T23:38:23.831Z,1618789103.831 [Default:CheckIn:Read_Iridium] Stopped 2021-04-18T23:38:23.831Z,1618789103.831 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-18T23:38:23.832Z,1618789103.832 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-18T23:38:26.227Z,1618789106.227 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2021-04-18T23:38:26.229Z,1618789106.229 [BPC1](INFO): Received data from all battery sticks. 2021-04-18T23:38:30.663Z,1618789110.663 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-18T23:43:24.388Z,1618789404.388 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-18T23:43:24.388Z,1618789404.388 [Default:CheckIn:C.Wait] Stopped 2021-04-18T23:43:24.388Z,1618789404.388 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-18T23:43:24.390Z,1618789404.390 [Default:CheckIn:D] Running Loop=1 2021-04-18T23:43:24.798Z,1618789404.798 [Default:CheckIn:D] Stopped 2021-04-18T23:43:24.798Z,1618789404.798 [Default:CheckIn:E] Running Loop=1 2021-04-18T23:43:25.197Z,1618789405.197 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 304.544889 min 2021-04-18T23:43:25.197Z,1618789405.197 [Default:CheckIn:E] Stopped 2021-04-18T23:43:25.197Z,1618789405.197 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-18T23:43:25.197Z,1618789405.197 [Default:CheckIn] Stopped 2021-04-18T23:43:25.213Z,1618789405.213 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-18T23:43:25.213Z,1618789405.213 [Default:CheckIn](INFO): Running loop #30 2021-04-18T23:43:25.214Z,1618789405.214 [Default:CheckIn] Running Loop=30 2021-04-18T23:43:25.214Z,1618789405.214 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-18T23:43:25.214Z,1618789405.214 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-18T23:43:26.796Z,1618789406.796 [NAL9602](FAULT): GPS failed to acquire within timeout. 2021-04-18T23:43:26.796Z,1618789406.796 [NAL9602] Data Fault, FailCount= 5 2021-04-18T23:43:26.796Z,1618789406.796 [NAL9602](ERROR): Data Fault 2021-04-18T23:43:26.817Z,1618789406.817 [CBIT](ERROR): Data Fault in component: NAL9602 2021-04-18T23:43:26.817Z,1618789406.817 [CBIT](CRITICAL): Data Fault in component: NAL9602 2021-04-18T23:43:27.208Z,1618789407.208 [NAL9602](INFO): Powering down 2021-04-18T23:43:27.232Z,1618789407.232 [CBIT](INFO): Critical error at 20210418T234326 2021-04-18T23:45:26.818Z,1618789526.818 [CBIT](INFO): Clearing failed state for component NAL9602 2021-04-18T23:45:26.818Z,1618789526.818 [NAL9602] No Fault, FailCount= 5 2021-04-18T23:45:27.191Z,1618789527.191 [NAL9602](INFO): Powering up NAL9602 2021-04-18T23:45:38.099Z,1618789538.099 [NAL9602](INFO): NAL9602 initialized 2021-04-18T23:48:25.370Z,1618789705.370 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-18T23:43:25.2Z 2021-04-18T23:48:25.370Z,1618789705.370 [Default:CheckIn:Read_GPS] Stopped 2021-04-18T23:48:25.370Z,1618789705.370 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-18T23:48:32.369Z,1618789712.369 [DataOverHttps](INFO): Sending 93 bytes from file Logs/20210418T183851/Courier0087.lzma 2021-04-18T23:48:33.371Z,1618789713.371 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Courier0087.lzma.bak 2021-04-18T23:48:33.371Z,1618789713.371 [DataOverHttps](INFO): SBD MOMSN=15582964 2021-04-18T23:48:49.294Z,1618789729.294 [DataOverHttps](INFO): Sending 226 bytes from file Logs/20210418T183851/Express0088.lzma 2021-04-18T23:48:50.295Z,1618789730.295 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Express0088.lzma.bak 2021-04-18T23:48:50.295Z,1618789730.295 [DataOverHttps](INFO): SBD MOMSN=15582967 2021-04-18T23:48:52.037Z,1618789732.037 [Default:CheckIn:Read_Iridium] Stopped 2021-04-18T23:48:52.037Z,1618789732.037 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-18T23:48:52.037Z,1618789732.037 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-18T23:50:41.101Z,1618789841.101 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-18T23:51:11.829Z,1618789871.829 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-18T23:53:52.617Z,1618790032.617 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-18T23:53:52.617Z,1618790032.617 [Default:CheckIn:C.Wait] Stopped 2021-04-18T23:53:52.617Z,1618790032.617 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-18T23:53:52.618Z,1618790032.618 [Default:CheckIn:D] Running Loop=1 2021-04-18T23:53:53.012Z,1618790033.012 [Default:CheckIn:D] Stopped 2021-04-18T23:53:53.012Z,1618790033.012 [Default:CheckIn:E] Running Loop=1 2021-04-18T23:53:53.410Z,1618790033.410 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 315.015137 min 2021-04-18T23:53:53.410Z,1618790033.410 [Default:CheckIn:E] Stopped 2021-04-18T23:53:53.410Z,1618790033.410 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-18T23:53:53.410Z,1618790033.410 [Default:CheckIn] Stopped 2021-04-18T23:53:53.410Z,1618790033.410 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-18T23:53:53.411Z,1618790033.411 [Default:CheckIn](INFO): Running loop #31 2021-04-18T23:53:53.411Z,1618790033.411 [Default:CheckIn] Running Loop=31 2021-04-18T23:53:53.411Z,1618790033.411 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-18T23:53:53.411Z,1618790033.411 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-18T23:54:26.129Z,1618790066.129 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-04-18T23:54:26.205Z,1618790066.205 [NAL9602](FAULT): received: +CSQ:0 OK576, 2, 0, 0, 0 OK 2021-04-18T23:54:26.205Z,1618790066.205 [NAL9602] Data Fault, FailCount= 1 2021-04-18T23:54:26.205Z,1618790066.205 [NAL9602](ERROR): Data Fault 2021-04-18T23:54:26.240Z,1618790066.240 [CBIT](ERROR): Data Fault in component: NAL9602 2021-04-18T23:54:26.530Z,1618790066.530 [NAL9602](INFO): Powering down 2021-04-18T23:54:27.361Z,1618790067.361 [CBIT](INFO): Clearing failed state for component NAL9602 2021-04-18T23:54:27.361Z,1618790067.361 [NAL9602] No Fault, FailCount= 1 2021-04-18T23:54:56.834Z,1618790096.834 [NAL9602](INFO): Powering up NAL9602 2021-04-18T23:55:07.767Z,1618790107.767 [NAL9602](INFO): NAL9602 initialized 2021-04-18T23:58:53.613Z,1618790333.613 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-18T23:53:53.4Z 2021-04-18T23:58:53.613Z,1618790333.613 [Default:CheckIn:Read_GPS] Stopped 2021-04-18T23:58:53.614Z,1618790333.614 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-18T23:58:57.250Z,1618790337.250 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-18T23:59:00.513Z,1618790340.513 [DataOverHttps](INFO): Sending 38 bytes from file Logs/20210418T183851/Courier0090.lzma 2021-04-18T23:59:01.515Z,1618790341.515 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Courier0090.lzma.bak 2021-04-18T23:59:01.515Z,1618790341.515 [DataOverHttps](INFO): SBD MOMSN=15582981 2021-04-18T23:59:17.270Z,1618790357.270 [DataOverHttps](INFO): Sending 249 bytes from file Logs/20210418T183851/Express0091.lzma 2021-04-18T23:59:18.272Z,1618790358.272 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Express0091.lzma.bak 2021-04-18T23:59:18.272Z,1618790358.272 [DataOverHttps](INFO): SBD MOMSN=15582983 2021-04-18T23:59:19.885Z,1618790359.885 [Default:CheckIn:Read_Iridium] Stopped 2021-04-18T23:59:19.885Z,1618790359.885 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-18T23:59:19.885Z,1618790359.885 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-18T23:59:27.958Z,1618790367.958 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-19T00:04:20.464Z,1618790660.464 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-19T00:04:20.464Z,1618790660.464 [Default:CheckIn:C.Wait] Stopped 2021-04-19T00:04:20.464Z,1618790660.464 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-19T00:04:20.465Z,1618790660.465 [Default:CheckIn:D] Running Loop=1 2021-04-19T00:04:20.868Z,1618790660.868 [Default:CheckIn:D] Stopped 2021-04-19T00:04:20.868Z,1618790660.868 [Default:CheckIn:E] Running Loop=1 2021-04-19T00:04:21.275Z,1618790661.275 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 325.479395 min 2021-04-19T00:04:21.275Z,1618790661.275 [Default:CheckIn:E] Stopped 2021-04-19T00:04:21.275Z,1618790661.275 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-19T00:04:21.275Z,1618790661.275 [Default:CheckIn] Stopped 2021-04-19T00:04:21.275Z,1618790661.275 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-19T00:04:21.275Z,1618790661.275 [Default:CheckIn](INFO): Running loop #32 2021-04-19T00:04:21.275Z,1618790661.275 [Default:CheckIn] Running Loop=32 2021-04-19T00:04:21.276Z,1618790661.276 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-19T00:04:21.276Z,1618790661.276 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-19T00:04:22.880Z,1618790662.880 [NAL9602](FAULT): GPS failed to acquire within timeout. 2021-04-19T00:04:22.880Z,1618790662.880 [NAL9602] Data Fault, FailCount= 2 2021-04-19T00:04:22.880Z,1618790662.880 [NAL9602](ERROR): Data Fault 2021-04-19T00:04:22.907Z,1618790662.907 [CBIT](ERROR): Data Fault in component: NAL9602 2021-04-19T00:04:23.278Z,1618790663.278 [NAL9602](INFO): Powering down 2021-04-19T00:04:24.109Z,1618790664.109 [CBIT](INFO): Clearing failed state for component NAL9602 2021-04-19T00:04:24.109Z,1618790664.109 [NAL9602] No Fault, FailCount= 2 2021-04-19T00:04:53.582Z,1618790693.582 [NAL9602](INFO): Powering up NAL9602 2021-04-19T00:05:04.490Z,1618790704.490 [NAL9602](INFO): NAL9602 initialized 2021-04-19T00:09:21.446Z,1618790961.446 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-19T00:04:21.3Z 2021-04-19T00:09:21.446Z,1618790961.446 [Default:CheckIn:Read_GPS] Stopped 2021-04-19T00:09:21.447Z,1618790961.447 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-19T00:09:29.121Z,1618790969.121 [DataOverHttps](INFO): Sending 38 bytes from file Logs/20210418T183851/Courier0093.lzma 2021-04-19T00:09:30.123Z,1618790970.123 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Courier0093.lzma.bak 2021-04-19T00:09:30.123Z,1618790970.123 [DataOverHttps](INFO): SBD MOMSN=15583008 2021-04-19T00:09:45.942Z,1618790985.942 [DataOverHttps](INFO): Sending 225 bytes from file Logs/20210418T183851/Express0094.lzma 2021-04-19T00:09:46.943Z,1618790986.943 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Express0094.lzma.bak 2021-04-19T00:09:46.944Z,1618790986.944 [DataOverHttps](INFO): SBD MOMSN=15583010 2021-04-19T00:09:48.515Z,1618790988.515 [Default:CheckIn:Read_Iridium] Stopped 2021-04-19T00:09:48.515Z,1618790988.515 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-19T00:09:48.515Z,1618790988.515 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-19T00:10:07.494Z,1618791007.494 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-19T00:10:38.190Z,1618791038.190 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-19T00:14:49.081Z,1618791289.081 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-19T00:14:49.082Z,1618791289.082 [Default:CheckIn:C.Wait] Stopped 2021-04-19T00:14:49.082Z,1618791289.082 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-19T00:14:49.082Z,1618791289.082 [Default:CheckIn:D] Running Loop=1 2021-04-19T00:14:49.498Z,1618791289.498 [Default:CheckIn:D] Stopped 2021-04-19T00:14:49.498Z,1618791289.498 [Default:CheckIn:E] Running Loop=1 2021-04-19T00:14:49.901Z,1618791289.901 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 335.956576 min 2021-04-19T00:14:49.901Z,1618791289.901 [Default:CheckIn:E] Stopped 2021-04-19T00:14:49.901Z,1618791289.901 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-19T00:14:49.901Z,1618791289.901 [Default:CheckIn] Stopped 2021-04-19T00:14:49.902Z,1618791289.902 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-19T00:14:49.902Z,1618791289.902 [Default:CheckIn](INFO): Running loop #33 2021-04-19T00:14:49.902Z,1618791289.902 [Default:CheckIn] Running Loop=33 2021-04-19T00:14:49.902Z,1618791289.902 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-19T00:14:49.902Z,1618791289.902 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-19T00:19:50.073Z,1618791590.073 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-19T00:14:49.9Z 2021-04-19T00:19:50.073Z,1618791590.073 [Default:CheckIn:Read_GPS] Stopped 2021-04-19T00:19:50.074Z,1618791590.074 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-19T00:19:54.095Z,1618791594.095 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-19T00:19:58.022Z,1618791598.022 [DataOverHttps](INFO): Sending 38 bytes from file Logs/20210418T183851/Courier0096.lzma 2021-04-19T00:19:59.019Z,1618791599.019 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Courier0096.lzma.bak 2021-04-19T00:19:59.020Z,1618791599.020 [DataOverHttps](INFO): SBD MOMSN=15583029 2021-04-19T00:20:17.557Z,1618791617.557 [DataOverHttps](INFO): Sending 209 bytes from file Logs/20210418T183851/Express0097.lzma 2021-04-19T00:20:18.560Z,1618791618.560 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Express0097.lzma.bak 2021-04-19T00:20:18.560Z,1618791618.560 [DataOverHttps](INFO): SBD MOMSN=15583032 2021-04-19T00:20:20.438Z,1618791620.438 [Default:CheckIn:Read_Iridium] Stopped 2021-04-19T00:20:20.438Z,1618791620.438 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-19T00:20:20.438Z,1618791620.438 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-19T00:20:24.854Z,1618791624.854 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-19T00:25:21.008Z,1618791921.008 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-19T00:25:21.008Z,1618791921.008 [Default:CheckIn:C.Wait] Stopped 2021-04-19T00:25:21.008Z,1618791921.008 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-19T00:25:21.009Z,1618791921.009 [Default:CheckIn:D] Running Loop=1 2021-04-19T00:25:21.418Z,1618791921.418 [Default:CheckIn:D] Stopped 2021-04-19T00:25:21.418Z,1618791921.418 [Default:CheckIn:E] Running Loop=1 2021-04-19T00:25:21.813Z,1618791921.813 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 346.488574 min 2021-04-19T00:25:21.813Z,1618791921.813 [Default:CheckIn:E] Stopped 2021-04-19T00:25:21.813Z,1618791921.813 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-19T00:25:21.813Z,1618791921.813 [Default:CheckIn] Stopped 2021-04-19T00:25:21.813Z,1618791921.813 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-19T00:25:21.813Z,1618791921.813 [Default:CheckIn](INFO): Running loop #34 2021-04-19T00:25:21.814Z,1618791921.814 [Default:CheckIn] Running Loop=34 2021-04-19T00:25:21.814Z,1618791921.814 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-19T00:25:21.814Z,1618791921.814 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-19T00:25:23.418Z,1618791923.418 [NAL9602](FAULT): GPS failed to acquire within timeout. 2021-04-19T00:25:23.418Z,1618791923.418 [NAL9602] Data Fault, FailCount= 3 2021-04-19T00:25:23.419Z,1618791923.419 [NAL9602](ERROR): Data Fault 2021-04-19T00:25:23.438Z,1618791923.438 [CBIT](ERROR): Data Fault in component: NAL9602 2021-04-19T00:25:23.819Z,1618791923.819 [NAL9602](INFO): Powering down 2021-04-19T00:25:24.649Z,1618791924.649 [CBIT](INFO): Clearing failed state for component NAL9602 2021-04-19T00:25:24.649Z,1618791924.649 [NAL9602] No Fault, FailCount= 3 2021-04-19T00:25:54.122Z,1618791954.122 [NAL9602](INFO): Powering up NAL9602 2021-04-19T00:26:05.031Z,1618791965.031 [NAL9602](INFO): NAL9602 initialized 2021-04-19T00:30:22.029Z,1618792222.029 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-19T00:25:21.8Z 2021-04-19T00:30:22.029Z,1618792222.029 [Default:CheckIn:Read_GPS] Stopped 2021-04-19T00:30:22.033Z,1618792222.033 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-19T00:30:33.217Z,1618792233.217 [DataOverHttps](INFO): Sending 38 bytes from file Logs/20210418T183851/Courier0099.lzma 2021-04-19T00:30:34.220Z,1618792234.220 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Courier0099.lzma.bak 2021-04-19T00:30:34.220Z,1618792234.220 [DataOverHttps](INFO): SBD MOMSN=15583048 2021-04-19T00:30:49.969Z,1618792249.969 [DataOverHttps](INFO): Sending 226 bytes from file Logs/20210418T183851/Express0100.lzma 2021-04-19T00:30:50.971Z,1618792250.971 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Express0100.lzma.bak 2021-04-19T00:30:50.972Z,1618792250.972 [DataOverHttps](INFO): SBD MOMSN=15583050 2021-04-19T00:30:52.706Z,1618792252.706 [Default:CheckIn:Read_Iridium] Stopped 2021-04-19T00:30:52.706Z,1618792252.706 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-19T00:30:52.706Z,1618792252.706 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-19T00:31:08.047Z,1618792268.047 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-19T00:31:38.756Z,1618792298.756 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-19T00:35:53.286Z,1618792553.286 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-19T00:35:53.286Z,1618792553.286 [Default:CheckIn:C.Wait] Stopped 2021-04-19T00:35:53.286Z,1618792553.286 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-19T00:35:53.287Z,1618792553.287 [Default:CheckIn:D] Running Loop=1 2021-04-19T00:35:53.681Z,1618792553.681 [Default:CheckIn:D] Stopped 2021-04-19T00:35:53.681Z,1618792553.681 [Default:CheckIn:E] Running Loop=1 2021-04-19T00:35:54.089Z,1618792554.089 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 357.026270 min 2021-04-19T00:35:54.089Z,1618792554.089 [Default:CheckIn:E] Stopped 2021-04-19T00:35:54.089Z,1618792554.089 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-19T00:35:54.089Z,1618792554.089 [Default:CheckIn] Stopped 2021-04-19T00:35:54.089Z,1618792554.089 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-19T00:35:54.089Z,1618792554.089 [Default:CheckIn](INFO): Running loop #35 2021-04-19T00:35:54.090Z,1618792554.090 [Default:CheckIn] Running Loop=35 2021-04-19T00:35:54.090Z,1618792554.090 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-19T00:35:54.090Z,1618792554.090 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-19T00:40:54.269Z,1618792854.269 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-19T00:35:54.1Z 2021-04-19T00:40:54.269Z,1618792854.269 [Default:CheckIn:Read_GPS] Stopped 2021-04-19T00:40:54.270Z,1618792854.270 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-19T00:40:55.170Z,1618792855.170 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2021-04-19T00:40:58.299Z,1618792858.299 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-19T00:41:01.445Z,1618792861.445 [DataOverHttps](INFO): Sending 38 bytes from file Logs/20210418T183851/Courier0102.lzma 2021-04-19T00:41:02.448Z,1618792862.448 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Courier0102.lzma.bak 2021-04-19T00:41:02.448Z,1618792862.448 [DataOverHttps](INFO): SBD MOMSN=15583095 2021-04-19T00:41:17.421Z,1618792877.421 [DataOverHttps](INFO): Sending 209 bytes from file Logs/20210418T183851/Express0103.lzma 2021-04-19T00:41:18.420Z,1618792878.420 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Express0103.lzma.bak 2021-04-19T00:41:18.420Z,1618792878.420 [DataOverHttps](INFO): SBD MOMSN=15583097 2021-04-19T00:41:20.128Z,1618792880.128 [Default:CheckIn:Read_Iridium] Stopped 2021-04-19T00:41:20.129Z,1618792880.129 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-19T00:41:20.129Z,1618792880.129 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-19T00:41:29.010Z,1618792889.010 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-19T00:41:43.184Z,1618792903.184 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2021-04-19T00:42:53.520Z,1618792973.520 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2021-04-19T00:43:07.631Z,1618792987.631 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2021-04-19T00:43:37.529Z,1618793017.529 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2021-04-19T00:43:47.619Z,1618793027.619 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2021-04-19T00:44:00.146Z,1618793040.146 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2021-04-19T00:45:21.361Z,1618793121.361 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2021-04-19T00:46:20.716Z,1618793180.716 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-19T00:46:20.716Z,1618793180.716 [Default:CheckIn:C.Wait] Stopped 2021-04-19T00:46:20.716Z,1618793180.716 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-19T00:46:20.716Z,1618793180.716 [Default:CheckIn:D] Running Loop=1 2021-04-19T00:46:21.165Z,1618793181.165 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2021-04-19T00:46:21.177Z,1618793181.177 [Default:CheckIn:D] Stopped 2021-04-19T00:46:21.177Z,1618793181.177 [Default:CheckIn:E] Running Loop=1 2021-04-19T00:46:21.546Z,1618793181.546 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 367.484538 min 2021-04-19T00:46:21.546Z,1618793181.546 [Default:CheckIn:E] Stopped 2021-04-19T00:46:21.546Z,1618793181.546 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-19T00:46:21.547Z,1618793181.547 [Default:CheckIn] Stopped 2021-04-19T00:46:21.547Z,1618793181.547 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-19T00:46:21.547Z,1618793181.547 [Default:CheckIn](INFO): Running loop #36 2021-04-19T00:46:21.547Z,1618793181.547 [Default:CheckIn] Running Loop=36 2021-04-19T00:46:21.547Z,1618793181.547 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-19T00:46:21.547Z,1618793181.547 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-19T00:46:23.127Z,1618793183.127 [NAL9602](FAULT): GPS failed to acquire within timeout. 2021-04-19T00:46:23.127Z,1618793183.127 [NAL9602] Data Fault, FailCount= 4 2021-04-19T00:46:23.127Z,1618793183.127 [NAL9602](ERROR): Data Fault 2021-04-19T00:46:23.175Z,1618793183.175 [CBIT](ERROR): Data Fault in component: NAL9602 2021-04-19T00:46:23.531Z,1618793183.531 [NAL9602](INFO): Powering down 2021-04-19T00:46:24.371Z,1618793184.371 [CBIT](INFO): Clearing failed state for component NAL9602 2021-04-19T00:46:24.371Z,1618793184.371 [NAL9602] No Fault, FailCount= 4 2021-04-19T00:46:32.829Z,1618793192.829 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2021-04-19T00:46:32.831Z,1618793192.831 [BPC1](INFO): Received data from all battery sticks. 2021-04-19T00:46:53.828Z,1618793213.828 [NAL9602](INFO): Powering up NAL9602 2021-04-19T00:47:04.736Z,1618793224.736 [NAL9602](INFO): NAL9602 initialized 2021-04-19T00:51:21.691Z,1618793481.691 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-19T00:46:21.5Z 2021-04-19T00:51:21.691Z,1618793481.691 [Default:CheckIn:Read_GPS] Stopped 2021-04-19T00:51:21.691Z,1618793481.691 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-19T00:51:29.317Z,1618793489.317 [DataOverHttps](INFO): Sending 50 bytes from file Logs/20210418T183851/Courier0105.lzma 2021-04-19T00:51:30.322Z,1618793490.322 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Courier0105.lzma.bak 2021-04-19T00:51:30.322Z,1618793490.322 [DataOverHttps](INFO): SBD MOMSN=15583143 2021-04-19T00:51:46.837Z,1618793506.837 [DataOverHttps](INFO): Sending 225 bytes from file Logs/20210418T183851/Express0106.lzma 2021-04-19T00:51:47.839Z,1618793507.839 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Express0106.lzma.bak 2021-04-19T00:51:47.840Z,1618793507.840 [DataOverHttps](INFO): SBD MOMSN=15583147 2021-04-19T00:51:49.572Z,1618793509.572 [Default:CheckIn:Read_Iridium] Stopped 2021-04-19T00:51:49.573Z,1618793509.573 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-19T00:51:49.573Z,1618793509.573 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-19T00:52:07.748Z,1618793527.748 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-19T00:52:38.446Z,1618793558.446 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-19T00:56:50.142Z,1618793810.142 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-19T00:56:50.142Z,1618793810.142 [Default:CheckIn:C.Wait] Stopped 2021-04-19T00:56:50.142Z,1618793810.142 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-19T00:56:50.143Z,1618793810.143 [Default:CheckIn:D] Running Loop=1 2021-04-19T00:56:50.562Z,1618793810.562 [Default:CheckIn:D] Stopped 2021-04-19T00:56:50.562Z,1618793810.562 [Default:CheckIn:E] Running Loop=1 2021-04-19T00:56:50.971Z,1618793810.971 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 377.974284 min 2021-04-19T00:56:50.971Z,1618793810.971 [Default:CheckIn:E] Stopped 2021-04-19T00:56:50.972Z,1618793810.972 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-19T00:56:50.972Z,1618793810.972 [Default:CheckIn] Stopped 2021-04-19T00:56:50.972Z,1618793810.972 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-19T00:56:50.972Z,1618793810.972 [Default:CheckIn](INFO): Running loop #37 2021-04-19T00:56:50.972Z,1618793810.972 [Default:CheckIn] Running Loop=37 2021-04-19T00:56:50.972Z,1618793810.972 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-19T00:56:50.972Z,1618793810.972 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-19T01:01:51.138Z,1618794111.138 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-19T00:56:50.0Z 2021-04-19T01:01:51.138Z,1618794111.138 [Default:CheckIn:Read_GPS] Stopped 2021-04-19T01:01:51.139Z,1618794111.139 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-19T01:01:54.751Z,1618794114.751 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-19T01:01:58.709Z,1618794118.709 [DataOverHttps](INFO): Sending 38 bytes from file Logs/20210418T183851/Courier0108.lzma 2021-04-19T01:01:59.712Z,1618794119.712 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Courier0108.lzma.bak 2021-04-19T01:01:59.712Z,1618794119.712 [DataOverHttps](INFO): SBD MOMSN=15583162 2021-04-19T01:02:15.485Z,1618794135.485 [DataOverHttps](INFO): Sending 208 bytes from file Logs/20210418T183851/Express0109.lzma 2021-04-19T01:02:16.487Z,1618794136.487 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Express0109.lzma.bak 2021-04-19T01:02:16.488Z,1618794136.488 [DataOverHttps](INFO): SBD MOMSN=15583164 2021-04-19T01:02:18.208Z,1618794138.208 [Default:CheckIn:Read_Iridium] Stopped 2021-04-19T01:02:18.209Z,1618794138.209 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-19T01:02:18.209Z,1618794138.209 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-19T01:02:25.465Z,1618794145.465 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-19T01:07:18.772Z,1618794438.772 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-19T01:07:18.772Z,1618794438.772 [Default:CheckIn:C.Wait] Stopped 2021-04-19T01:07:18.773Z,1618794438.773 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-19T01:07:18.773Z,1618794438.773 [Default:CheckIn:D] Running Loop=1 2021-04-19T01:07:19.179Z,1618794439.179 [Default:CheckIn:D] Stopped 2021-04-19T01:07:19.179Z,1618794439.179 [Default:CheckIn:E] Running Loop=1 2021-04-19T01:07:19.593Z,1618794439.593 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 388.451237 min 2021-04-19T01:07:19.594Z,1618794439.594 [Default:CheckIn:E] Stopped 2021-04-19T01:07:19.594Z,1618794439.594 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-19T01:07:19.594Z,1618794439.594 [Default:CheckIn] Stopped 2021-04-19T01:07:19.594Z,1618794439.594 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-19T01:07:19.594Z,1618794439.594 [Default:CheckIn](INFO): Running loop #38 2021-04-19T01:07:19.594Z,1618794439.594 [Default:CheckIn] Running Loop=38 2021-04-19T01:07:19.594Z,1618794439.594 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-19T01:07:19.594Z,1618794439.594 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-19T01:07:21.191Z,1618794441.191 [NAL9602](FAULT): GPS failed to acquire within timeout. 2021-04-19T01:07:21.191Z,1618794441.191 [NAL9602] Data Fault, FailCount= 5 2021-04-19T01:07:21.191Z,1618794441.191 [NAL9602](ERROR): Data Fault 2021-04-19T01:07:21.250Z,1618794441.250 [CBIT](ERROR): Data Fault in component: NAL9602 2021-04-19T01:07:21.251Z,1618794441.251 [CBIT](CRITICAL): Data Fault in component: NAL9602 2021-04-19T01:07:21.591Z,1618794441.591 [NAL9602](INFO): Powering down 2021-04-19T01:07:21.609Z,1618794441.609 [CBIT](INFO): Critical error at 20210419T010721 2021-04-19T01:09:21.196Z,1618794561.196 [CBIT](INFO): Clearing failed state for component NAL9602 2021-04-19T01:09:21.196Z,1618794561.196 [NAL9602] No Fault, FailCount= 5 2021-04-19T01:09:21.576Z,1618794561.576 [NAL9602](INFO): Powering up NAL9602 2021-04-19T01:09:32.486Z,1618794572.486 [NAL9602](INFO): NAL9602 initialized 2021-04-19T01:12:19.757Z,1618794739.757 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-19T01:07:19.6Z 2021-04-19T01:12:19.757Z,1618794739.757 [Default:CheckIn:Read_GPS] Stopped 2021-04-19T01:12:19.758Z,1618794739.758 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-19T01:12:27.157Z,1618794747.157 [DataOverHttps](INFO): Sending 81 bytes from file Logs/20210418T183851/Courier0111.lzma 2021-04-19T01:12:28.159Z,1618794748.159 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Courier0111.lzma.bak 2021-04-19T01:12:28.160Z,1618794748.160 [DataOverHttps](INFO): SBD MOMSN=15583178 2021-04-19T01:12:43.913Z,1618794763.913 [DataOverHttps](INFO): Sending 227 bytes from file Logs/20210418T183851/Express0112.lzma 2021-04-19T01:12:44.915Z,1618794764.915 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Express0112.lzma.bak 2021-04-19T01:12:44.916Z,1618794764.916 [DataOverHttps](INFO): SBD MOMSN=15583181 2021-04-19T01:12:46.417Z,1618794766.417 [Default:CheckIn:Read_Iridium] Stopped 2021-04-19T01:12:46.418Z,1618794766.418 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-19T01:12:46.418Z,1618794766.418 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-19T01:14:35.491Z,1618794875.491 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-19T01:15:06.194Z,1618794906.194 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-19T01:17:46.994Z,1618795066.994 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-19T01:17:46.994Z,1618795066.994 [Default:CheckIn:C.Wait] Stopped 2021-04-19T01:17:46.994Z,1618795066.994 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-19T01:17:46.996Z,1618795066.996 [Default:CheckIn:D] Running Loop=1 2021-04-19T01:17:47.404Z,1618795067.404 [Default:CheckIn:D] Stopped 2021-04-19T01:17:47.404Z,1618795067.404 [Default:CheckIn:E] Running Loop=1 2021-04-19T01:17:47.857Z,1618795067.857 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 398.921680 min 2021-04-19T01:17:47.857Z,1618795067.857 [Default:CheckIn:E] Stopped 2021-04-19T01:17:47.857Z,1618795067.857 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-19T01:17:47.857Z,1618795067.857 [Default:CheckIn] Stopped 2021-04-19T01:17:47.858Z,1618795067.858 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-19T01:17:47.858Z,1618795067.858 [Default:CheckIn](INFO): Running loop #39 2021-04-19T01:17:47.858Z,1618795067.858 [Default:CheckIn] Running Loop=39 2021-04-19T01:17:47.858Z,1618795067.858 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-19T01:17:47.858Z,1618795067.858 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-19T01:18:20.517Z,1618795100.517 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-04-19T01:18:20.593Z,1618795100.593 [NAL9602](FAULT): received: +CSQ:0 OK576, 2, 0, 0, 0 OK 2021-04-19T01:18:20.593Z,1618795100.593 [NAL9602] Data Fault, FailCount= 1 2021-04-19T01:18:20.593Z,1618795100.593 [NAL9602](ERROR): Data Fault 2021-04-19T01:18:20.618Z,1618795100.618 [CBIT](ERROR): Data Fault in component: NAL9602 2021-04-19T01:18:20.920Z,1618795100.920 [NAL9602](INFO): Powering down 2021-04-19T01:18:21.775Z,1618795101.775 [CBIT](INFO): Clearing failed state for component NAL9602 2021-04-19T01:18:21.776Z,1618795101.776 [NAL9602] No Fault, FailCount= 1 2021-04-19T01:18:51.224Z,1618795131.224 [NAL9602](INFO): Powering up NAL9602 2021-04-19T01:19:02.139Z,1618795142.139 [NAL9602](INFO): NAL9602 initialized 2021-04-19T01:22:47.985Z,1618795367.985 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-19T01:17:47.9Z 2021-04-19T01:22:48.001Z,1618795368.001 [Default:CheckIn:Read_GPS] Stopped 2021-04-19T01:22:48.001Z,1618795368.001 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-19T01:22:51.606Z,1618795371.606 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-19T01:22:55.241Z,1618795375.241 [DataOverHttps](INFO): Sending 38 bytes from file Logs/20210418T183851/Courier0114.lzma 2021-04-19T01:22:56.243Z,1618795376.243 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Courier0114.lzma.bak 2021-04-19T01:22:56.243Z,1618795376.243 [DataOverHttps](INFO): SBD MOMSN=15583196 2021-04-19T01:23:12.025Z,1618795392.025 [DataOverHttps](INFO): Sending 249 bytes from file Logs/20210418T183851/Express0115.lzma 2021-04-19T01:23:13.036Z,1618795393.036 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Express0115.lzma.bak 2021-04-19T01:23:13.036Z,1618795393.036 [DataOverHttps](INFO): SBD MOMSN=15583198 2021-04-19T01:23:14.653Z,1618795394.653 [Default:CheckIn:Read_Iridium] Stopped 2021-04-19T01:23:14.653Z,1618795394.653 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-19T01:23:14.653Z,1618795394.653 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-19T01:23:22.310Z,1618795402.310 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-19T01:28:15.229Z,1618795695.229 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-19T01:28:15.229Z,1618795695.229 [Default:CheckIn:C.Wait] Stopped 2021-04-19T01:28:15.230Z,1618795695.230 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-19T01:28:15.230Z,1618795695.230 [Default:CheckIn:D] Running Loop=1 2021-04-19T01:28:15.644Z,1618795695.644 [Default:CheckIn:D] Stopped 2021-04-19T01:28:15.644Z,1618795695.644 [Default:CheckIn:E] Running Loop=1 2021-04-19T01:28:16.060Z,1618795696.060 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 409.392318 min 2021-04-19T01:28:16.061Z,1618795696.061 [Default:CheckIn:E] Stopped 2021-04-19T01:28:16.061Z,1618795696.061 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-19T01:28:16.061Z,1618795696.061 [Default:CheckIn] Stopped 2021-04-19T01:28:16.061Z,1618795696.061 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-19T01:28:16.085Z,1618795696.085 [Default:CheckIn](INFO): Running loop #40 2021-04-19T01:28:16.085Z,1618795696.085 [Default:CheckIn] Running Loop=40 2021-04-19T01:28:16.085Z,1618795696.085 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-19T01:28:16.086Z,1618795696.086 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-19T01:28:17.643Z,1618795697.643 [NAL9602](FAULT): GPS failed to acquire within timeout. 2021-04-19T01:28:17.643Z,1618795697.643 [NAL9602] Data Fault, FailCount= 2 2021-04-19T01:28:17.643Z,1618795697.643 [NAL9602](ERROR): Data Fault 2021-04-19T01:28:17.662Z,1618795697.662 [CBIT](ERROR): Data Fault in component: NAL9602 2021-04-19T01:28:18.039Z,1618795698.039 [NAL9602](INFO): Powering down 2021-04-19T01:28:18.869Z,1618795698.869 [CBIT](INFO): Clearing failed state for component NAL9602 2021-04-19T01:28:18.869Z,1618795698.869 [NAL9602] No Fault, FailCount= 2 2021-04-19T01:28:48.345Z,1618795728.345 [NAL9602](INFO): Powering up NAL9602 2021-04-19T01:28:59.253Z,1618795739.253 [NAL9602](INFO): NAL9602 initialized 2021-04-19T01:33:16.215Z,1618795996.215 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-19T01:28:16.1Z 2021-04-19T01:33:16.215Z,1618795996.215 [Default:CheckIn:Read_GPS] Stopped 2021-04-19T01:33:16.215Z,1618795996.215 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-19T01:33:23.205Z,1618796003.205 [DataOverHttps](INFO): Sending 38 bytes from file Logs/20210418T183851/Courier0117.lzma 2021-04-19T01:33:24.207Z,1618796004.207 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Courier0117.lzma.bak 2021-04-19T01:33:24.208Z,1618796004.208 [DataOverHttps](INFO): SBD MOMSN=15583214 2021-04-19T01:33:40.013Z,1618796020.013 [DataOverHttps](INFO): Sending 226 bytes from file Logs/20210418T183851/Express0118.lzma 2021-04-19T01:33:41.015Z,1618796021.015 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Express0118.lzma.bak 2021-04-19T01:33:41.016Z,1618796021.016 [DataOverHttps](INFO): SBD MOMSN=15583216 2021-04-19T01:33:42.493Z,1618796022.493 [Default:CheckIn:Read_Iridium] Stopped 2021-04-19T01:33:42.493Z,1618796022.493 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-19T01:33:42.493Z,1618796022.493 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-19T01:34:02.251Z,1618796042.251 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-19T01:34:32.968Z,1618796072.968 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-19T01:38:43.046Z,1618796323.046 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-19T01:38:43.046Z,1618796323.046 [Default:CheckIn:C.Wait] Stopped 2021-04-19T01:38:43.046Z,1618796323.046 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-19T01:38:43.046Z,1618796323.046 [Default:CheckIn:D] Running Loop=1 2021-04-19T01:38:43.451Z,1618796323.451 [Default:CheckIn:D] Stopped 2021-04-19T01:38:43.451Z,1618796323.451 [Default:CheckIn:E] Running Loop=1 2021-04-19T01:38:43.847Z,1618796323.847 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 419.855794 min 2021-04-19T01:38:43.847Z,1618796323.847 [Default:CheckIn:E] Stopped 2021-04-19T01:38:43.847Z,1618796323.847 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-19T01:38:43.847Z,1618796323.847 [Default:CheckIn] Stopped 2021-04-19T01:38:43.847Z,1618796323.847 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-19T01:38:43.847Z,1618796323.847 [Default:CheckIn](INFO): Running loop #41 2021-04-19T01:38:43.847Z,1618796323.847 [Default:CheckIn] Running Loop=41 2021-04-19T01:38:43.848Z,1618796323.848 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-19T01:38:43.848Z,1618796323.848 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-19T01:39:16.567Z,1618796356.567 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-04-19T01:39:16.649Z,1618796356.649 [NAL9602](FAULT): received: +CSQ:0 OK576, 2, 0, 0, 0 OK 2021-04-19T01:39:16.649Z,1618796356.649 [NAL9602] Data Fault, FailCount= 3 2021-04-19T01:39:16.649Z,1618796356.649 [NAL9602](ERROR): Data Fault 2021-04-19T01:39:16.714Z,1618796356.714 [CBIT](ERROR): Data Fault in component: NAL9602 2021-04-19T01:39:16.976Z,1618796356.976 [NAL9602](INFO): Powering down 2021-04-19T01:39:17.791Z,1618796357.791 [CBIT](INFO): Clearing failed state for component NAL9602 2021-04-19T01:39:17.791Z,1618796357.791 [NAL9602] No Fault, FailCount= 3 2021-04-19T01:39:47.270Z,1618796387.270 [NAL9602](INFO): Powering up NAL9602 2021-04-19T01:39:58.177Z,1618796398.177 [NAL9602](INFO): NAL9602 initialized 2021-04-19T01:39:58.987Z,1618796398.987 [NAL9602](FAULT): GPS failed to acquire within timeout. 2021-04-19T01:39:58.987Z,1618796398.987 [NAL9602] Data Fault, FailCount= 4 2021-04-19T01:39:58.987Z,1618796398.987 [NAL9602](ERROR): Data Fault 2021-04-19T01:39:59.047Z,1618796399.047 [CBIT](ERROR): Data Fault in component: NAL9602 2021-04-19T01:39:59.390Z,1618796399.390 [NAL9602](INFO): Powering down 2021-04-19T01:40:00.216Z,1618796400.216 [CBIT](INFO): Clearing failed state for component NAL9602 2021-04-19T01:40:00.216Z,1618796400.216 [NAL9602] No Fault, FailCount= 4 2021-04-19T01:40:29.427Z,1618796429.427 [NAL9602](INFO): Powering up NAL9602 2021-04-19T01:40:40.343Z,1618796440.343 [NAL9602](INFO): NAL9602 initialized 2021-04-19T01:43:44.177Z,1618796624.177 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-19T01:38:43.8Z 2021-04-19T01:43:44.177Z,1618796624.177 [Default:CheckIn:Read_GPS] Stopped 2021-04-19T01:43:44.193Z,1618796624.193 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-19T01:43:45.776Z,1618796625.776 [NAL9602](INFO): SBD MO Status=2, MOMSN=25576, MT Status=2, MTMSN=0 2021-04-19T01:43:45.776Z,1618796625.776 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-04-19T01:43:48.199Z,1618796628.199 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-19T01:43:51.833Z,1618796631.833 [DataOverHttps](INFO): Sending 38 bytes from file Logs/20210418T183851/Courier0120.lzma 2021-04-19T01:43:52.835Z,1618796632.835 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Courier0120.lzma.bak 2021-04-19T01:43:52.835Z,1618796632.835 [DataOverHttps](INFO): SBD MOMSN=15583233 2021-04-19T01:44:10.202Z,1618796650.202 [DataOverHttps](INFO): Sending 265 bytes from file Logs/20210418T183851/Express0121.lzma 2021-04-19T01:44:11.203Z,1618796651.203 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Express0121.lzma.bak 2021-04-19T01:44:11.204Z,1618796651.204 [DataOverHttps](INFO): SBD MOMSN=15583235 2021-04-19T01:44:12.890Z,1618796652.890 [Default:CheckIn:Read_Iridium] Stopped 2021-04-19T01:44:12.890Z,1618796652.890 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-19T01:44:12.890Z,1618796652.890 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-19T01:44:18.930Z,1618796658.930 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-19T01:47:51.878Z,1618796871.878 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2021-04-19T01:49:13.457Z,1618796953.457 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-19T01:49:13.457Z,1618796953.457 [Default:CheckIn:C.Wait] Stopped 2021-04-19T01:49:13.457Z,1618796953.457 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-19T01:49:13.458Z,1618796953.458 [Default:CheckIn:D] Running Loop=1 2021-04-19T01:49:13.856Z,1618796953.856 [Default:CheckIn:D] Stopped 2021-04-19T01:49:13.857Z,1618796953.857 [Default:CheckIn:E] Running Loop=1 2021-04-19T01:49:14.267Z,1618796954.267 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 430.362533 min 2021-04-19T01:49:14.267Z,1618796954.267 [Default:CheckIn:E] Stopped 2021-04-19T01:49:14.267Z,1618796954.267 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-19T01:49:14.268Z,1618796954.268 [Default:CheckIn] Stopped 2021-04-19T01:49:14.268Z,1618796954.268 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-19T01:49:14.268Z,1618796954.268 [Default:CheckIn](INFO): Running loop #42 2021-04-19T01:49:14.268Z,1618796954.268 [Default:CheckIn] Running Loop=42 2021-04-19T01:49:14.268Z,1618796954.268 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-19T01:49:14.268Z,1618796954.268 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-19T01:49:46.979Z,1618796986.979 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-04-19T01:49:47.061Z,1618796987.061 [NAL9602](FAULT): received: +SBDI: 2, 25576, 2, 0, 0, 0 OK 2021-04-19T01:49:47.061Z,1618796987.061 [NAL9602] Data Fault, FailCount= 5 2021-04-19T01:49:47.061Z,1618796987.061 [NAL9602](ERROR): Data Fault 2021-04-19T01:49:47.107Z,1618796987.107 [CBIT](ERROR): Data Fault in component: NAL9602 2021-04-19T01:49:47.107Z,1618796987.107 [CBIT](CRITICAL): Data Fault in component: NAL9602 2021-04-19T01:49:47.378Z,1618796987.378 [NAL9602](INFO): Powering down 2021-04-19T01:49:47.404Z,1618796987.404 [CBIT](INFO): Critical error at 20210419T014947 2021-04-19T01:51:47.419Z,1618797107.419 [CBIT](INFO): Clearing failed state for component NAL9602 2021-04-19T01:51:47.419Z,1618797107.419 [NAL9602] No Fault, FailCount= 5 2021-04-19T01:51:47.778Z,1618797107.778 [NAL9602](INFO): Powering up NAL9602 2021-04-19T01:51:58.683Z,1618797118.683 [NAL9602](INFO): NAL9602 initialized 2021-04-19T01:51:59.491Z,1618797119.491 [NAL9602](FAULT): GPS failed to acquire within timeout. 2021-04-19T01:51:59.491Z,1618797119.491 [NAL9602] Data Fault, FailCount= 1 2021-04-19T01:51:59.491Z,1618797119.491 [NAL9602](ERROR): Data Fault 2021-04-19T01:51:59.537Z,1618797119.537 [CBIT](ERROR): Data Fault in component: NAL9602 2021-04-19T01:51:59.898Z,1618797119.898 [NAL9602](INFO): Powering down 2021-04-19T01:52:00.730Z,1618797120.730 [CBIT](INFO): Clearing failed state for component NAL9602 2021-04-19T01:52:00.730Z,1618797120.730 [NAL9602] No Fault, FailCount= 1 2021-04-19T01:52:30.198Z,1618797150.198 [NAL9602](INFO): Powering up NAL9602 2021-04-19T01:52:41.119Z,1618797161.119 [NAL9602](INFO): NAL9602 initialized 2021-04-19T01:53:25.950Z,1618797205.950 [BPC1](ERROR): BPC1A: No match for serial number 0000 in BPC1A's battery stick inventory (sticks 1-32 in onboard configuration file). 2021-04-19T01:53:53.476Z,1618797233.476 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2021-04-19T01:54:12.474Z,1618797252.474 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2021-04-19T01:54:14.449Z,1618797254.449 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-19T01:49:14.3Z 2021-04-19T01:54:14.449Z,1618797254.449 [Default:CheckIn:Read_GPS] Stopped 2021-04-19T01:54:14.450Z,1618797254.450 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-19T01:54:18.071Z,1618797258.071 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-19T01:54:22.225Z,1618797262.225 [DataOverHttps](INFO): Sending 81 bytes from file Logs/20210418T183851/Courier0123.lzma 2021-04-19T01:54:23.231Z,1618797263.231 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Courier0123.lzma.bak 2021-04-19T01:54:23.231Z,1618797263.231 [DataOverHttps](INFO): SBD MOMSN=15583264 2021-04-19T01:54:39.222Z,1618797279.222 [DataOverHttps](INFO): Sending 268 bytes from file Logs/20210418T183851/Express0124.lzma 2021-04-19T01:54:40.223Z,1618797280.223 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Express0124.lzma.bak 2021-04-19T01:54:40.224Z,1618797280.224 [DataOverHttps](INFO): SBD MOMSN=15583267 2021-04-19T01:54:41.973Z,1618797281.973 [Default:CheckIn:Read_Iridium] Stopped 2021-04-19T01:54:41.973Z,1618797281.973 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-19T01:54:41.973Z,1618797281.973 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-19T01:54:48.768Z,1618797288.768 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-19T01:54:50.845Z,1618797290.845 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2021-04-19T01:55:06.146Z,1618797306.146 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2021-04-19T01:55:06.153Z,1618797306.153 [BPC1](INFO): Received data from all battery sticks. 2021-04-19T01:59:42.498Z,1618797582.498 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-19T01:59:42.499Z,1618797582.499 [Default:CheckIn:C.Wait] Stopped 2021-04-19T01:59:42.499Z,1618797582.499 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-19T01:59:42.499Z,1618797582.499 [Default:CheckIn:D] Running Loop=1 2021-04-19T01:59:42.895Z,1618797582.895 [Default:CheckIn:D] Stopped 2021-04-19T01:59:42.895Z,1618797582.895 [Default:CheckIn:E] Running Loop=1 2021-04-19T01:59:43.309Z,1618797583.309 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 440.846517 min 2021-04-19T01:59:43.309Z,1618797583.309 [Default:CheckIn:E] Stopped 2021-04-19T01:59:43.310Z,1618797583.310 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-19T01:59:43.310Z,1618797583.310 [Default:CheckIn] Stopped 2021-04-19T01:59:43.310Z,1618797583.310 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-19T01:59:43.310Z,1618797583.310 [Default:CheckIn](INFO): Running loop #43 2021-04-19T01:59:43.310Z,1618797583.310 [Default:CheckIn] Running Loop=43 2021-04-19T01:59:43.310Z,1618797583.310 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-19T01:59:43.310Z,1618797583.310 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-19T02:00:16.021Z,1618797616.021 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-04-19T02:00:16.097Z,1618797616.097 [NAL9602](FAULT): received: +CSQ:1 OK576, 2, 0, 0, 0 OK 2021-04-19T02:00:16.097Z,1618797616.097 [NAL9602] Data Fault, FailCount= 2 2021-04-19T02:00:16.098Z,1618797616.098 [NAL9602](ERROR): Data Fault 2021-04-19T02:00:16.181Z,1618797616.181 [CBIT](ERROR): Data Fault in component: NAL9602 2021-04-19T02:00:16.418Z,1618797616.418 [NAL9602](INFO): Powering down 2021-04-19T02:00:17.245Z,1618797617.245 [CBIT](INFO): Clearing failed state for component NAL9602 2021-04-19T02:00:17.245Z,1618797617.245 [NAL9602] No Fault, FailCount= 2 2021-04-19T02:00:46.727Z,1618797646.727 [NAL9602](INFO): Powering up NAL9602 2021-04-19T02:00:57.634Z,1618797657.634 [NAL9602](INFO): NAL9602 initialized 2021-04-19T02:04:43.477Z,1618797883.477 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-19T01:59:43.3Z 2021-04-19T02:04:43.477Z,1618797883.477 [Default:CheckIn:Read_GPS] Stopped 2021-04-19T02:04:43.477Z,1618797883.477 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-19T02:04:47.099Z,1618797887.099 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-19T02:04:51.141Z,1618797891.141 [DataOverHttps](INFO): Sending 50 bytes from file Logs/20210418T183851/Courier0126.lzma 2021-04-19T02:04:52.143Z,1618797892.143 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Courier0126.lzma.bak 2021-04-19T02:04:52.143Z,1618797892.143 [DataOverHttps](INFO): SBD MOMSN=15583310 2021-04-19T02:05:08.445Z,1618797908.445 [DataOverHttps](INFO): Sending 248 bytes from file Logs/20210418T183851/Express0127.lzma 2021-04-19T02:05:09.448Z,1618797909.448 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Express0127.lzma.bak 2021-04-19T02:05:09.448Z,1618797909.448 [DataOverHttps](INFO): SBD MOMSN=15583312 2021-04-19T02:05:10.962Z,1618797910.962 [Default:CheckIn:Read_Iridium] Stopped 2021-04-19T02:05:10.962Z,1618797910.962 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-19T02:05:10.962Z,1618797910.962 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-19T02:05:17.803Z,1618797917.803 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-19T02:10:11.532Z,1618798211.532 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-19T02:10:11.532Z,1618798211.532 [Default:CheckIn:C.Wait] Stopped 2021-04-19T02:10:11.532Z,1618798211.532 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-19T02:10:11.533Z,1618798211.533 [Default:CheckIn:D] Running Loop=1 2021-04-19T02:10:11.943Z,1618798211.943 [Default:CheckIn:D] Stopped 2021-04-19T02:10:11.943Z,1618798211.943 [Default:CheckIn:E] Running Loop=1 2021-04-19T02:10:12.331Z,1618798212.331 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 451.330632 min 2021-04-19T02:10:12.331Z,1618798212.331 [Default:CheckIn:E] Stopped 2021-04-19T02:10:12.331Z,1618798212.331 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-19T02:10:12.331Z,1618798212.331 [Default:CheckIn] Stopped 2021-04-19T02:10:12.331Z,1618798212.331 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-19T02:10:12.332Z,1618798212.332 [Default:CheckIn](INFO): Running loop #44 2021-04-19T02:10:12.332Z,1618798212.332 [Default:CheckIn] Running Loop=44 2021-04-19T02:10:12.332Z,1618798212.332 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-19T02:10:12.332Z,1618798212.332 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-19T02:10:13.939Z,1618798213.939 [NAL9602](FAULT): GPS failed to acquire within timeout. 2021-04-19T02:10:13.939Z,1618798213.939 [NAL9602] Data Fault, FailCount= 3 2021-04-19T02:10:13.939Z,1618798213.939 [NAL9602](ERROR): Data Fault 2021-04-19T02:10:14.012Z,1618798214.012 [CBIT](ERROR): Data Fault in component: NAL9602 2021-04-19T02:10:14.342Z,1618798214.342 [NAL9602](INFO): Powering down 2021-04-19T02:10:15.246Z,1618798215.246 [CBIT](INFO): Clearing failed state for component NAL9602 2021-04-19T02:10:15.246Z,1618798215.246 [NAL9602] No Fault, FailCount= 3 2021-04-19T02:10:44.698Z,1618798244.698 [NAL9602](INFO): Powering up NAL9602 2021-04-19T02:10:55.603Z,1618798255.603 [NAL9602](INFO): NAL9602 initialized 2021-04-19T02:15:12.575Z,1618798512.575 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-19T02:10:12.3Z 2021-04-19T02:15:12.575Z,1618798512.575 [Default:CheckIn:Read_GPS] Stopped 2021-04-19T02:15:12.576Z,1618798512.576 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-19T02:15:19.481Z,1618798519.481 [DataOverHttps](INFO): Sending 38 bytes from file Logs/20210418T183851/Courier0129.lzma 2021-04-19T02:15:20.483Z,1618798520.483 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Courier0129.lzma.bak 2021-04-19T02:15:20.484Z,1618798520.484 [DataOverHttps](INFO): SBD MOMSN=15583346 2021-04-19T02:15:36.298Z,1618798536.298 [DataOverHttps](INFO): Sending 226 bytes from file Logs/20210418T183851/Express0130.lzma 2021-04-19T02:15:37.299Z,1618798537.299 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Express0130.lzma.bak 2021-04-19T02:15:37.300Z,1618798537.300 [DataOverHttps](INFO): SBD MOMSN=15583348 2021-04-19T02:15:38.838Z,1618798538.838 [Default:CheckIn:Read_Iridium] Stopped 2021-04-19T02:15:38.838Z,1618798538.838 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-19T02:15:38.838Z,1618798538.838 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-19T02:15:58.606Z,1618798558.606 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-19T02:16:29.304Z,1618798589.304 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-19T02:20:39.462Z,1618798839.462 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-19T02:20:39.462Z,1618798839.462 [Default:CheckIn:C.Wait] Stopped 2021-04-19T02:20:39.462Z,1618798839.462 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-19T02:20:39.463Z,1618798839.463 [Default:CheckIn:D] Running Loop=1 2021-04-19T02:20:39.883Z,1618798839.883 [Default:CheckIn:D] Stopped 2021-04-19T02:20:39.883Z,1618798839.883 [Default:CheckIn:E] Running Loop=1 2021-04-19T02:20:40.258Z,1618798840.258 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 461.796322 min 2021-04-19T02:20:40.259Z,1618798840.259 [Default:CheckIn:E] Stopped 2021-04-19T02:20:40.259Z,1618798840.259 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-19T02:20:40.259Z,1618798840.259 [Default:CheckIn] Stopped 2021-04-19T02:20:40.259Z,1618798840.259 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-19T02:20:40.259Z,1618798840.259 [Default:CheckIn](INFO): Running loop #45 2021-04-19T02:20:40.259Z,1618798840.259 [Default:CheckIn] Running Loop=45 2021-04-19T02:20:40.259Z,1618798840.259 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-19T02:20:40.259Z,1618798840.259 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-19T02:21:12.979Z,1618798872.979 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-04-19T02:21:13.053Z,1618798873.053 [NAL9602](FAULT): received: +CSQ:0 OK576, 2, 0, 0, 0 OK 2021-04-19T02:21:13.053Z,1618798873.053 [NAL9602] Data Fault, FailCount= 4 2021-04-19T02:21:13.053Z,1618798873.053 [NAL9602](ERROR): Data Fault 2021-04-19T02:21:13.119Z,1618798873.119 [CBIT](ERROR): Data Fault in component: NAL9602 2021-04-19T02:21:13.388Z,1618798873.388 [NAL9602](INFO): Powering down 2021-04-19T02:21:14.203Z,1618798874.203 [CBIT](INFO): Clearing failed state for component NAL9602 2021-04-19T02:21:14.203Z,1618798874.203 [NAL9602] No Fault, FailCount= 4 2021-04-19T02:21:43.679Z,1618798903.679 [NAL9602](INFO): Powering up NAL9602 2021-04-19T02:21:54.587Z,1618798914.587 [NAL9602](INFO): NAL9602 initialized 2021-04-19T02:21:55.394Z,1618798915.394 [NAL9602](FAULT): GPS failed to acquire within timeout. 2021-04-19T02:21:55.394Z,1618798915.394 [NAL9602] Data Fault, FailCount= 5 2021-04-19T02:21:55.394Z,1618798915.394 [NAL9602](ERROR): Data Fault 2021-04-19T02:21:55.414Z,1618798915.414 [CBIT](ERROR): Data Fault in component: NAL9602 2021-04-19T02:21:55.414Z,1618798915.414 [CBIT](CRITICAL): Data Fault in component: NAL9602 2021-04-19T02:21:55.798Z,1618798915.798 [NAL9602](INFO): Powering down 2021-04-19T02:21:55.844Z,1618798915.844 [CBIT](INFO): Critical error at 20210419T022155 2021-04-19T02:23:55.406Z,1618799035.406 [CBIT](INFO): Clearing failed state for component NAL9602 2021-04-19T02:23:55.406Z,1618799035.406 [NAL9602] No Fault, FailCount= 5 2021-04-19T02:23:55.786Z,1618799035.786 [NAL9602](INFO): Powering up NAL9602 2021-04-19T02:24:06.695Z,1618799046.695 [NAL9602](INFO): NAL9602 initialized 2021-04-19T02:25:40.437Z,1618799140.437 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-19T02:20:40.3Z 2021-04-19T02:25:40.437Z,1618799140.437 [Default:CheckIn:Read_GPS] Stopped 2021-04-19T02:25:40.461Z,1618799140.461 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-19T02:25:44.087Z,1618799144.087 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-19T02:25:47.329Z,1618799147.329 [DataOverHttps](INFO): Sending 81 bytes from file Logs/20210418T183851/Courier0132.lzma 2021-04-19T02:25:48.331Z,1618799148.331 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Courier0132.lzma.bak 2021-04-19T02:25:48.332Z,1618799148.332 [DataOverHttps](INFO): SBD MOMSN=15583398 2021-04-19T02:26:03.488Z,1618799163.488 [DataOverHttps](INFO): Sending 267 bytes from file Logs/20210418T183851/Express0133.lzma 2021-04-19T02:26:04.427Z,1618799164.427 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Express0133.lzma.bak 2021-04-19T02:26:04.428Z,1618799164.428 [DataOverHttps](INFO): SBD MOMSN=15583402 2021-04-19T02:26:05.932Z,1618799165.932 [Default:CheckIn:Read_Iridium] Stopped 2021-04-19T02:26:05.932Z,1618799165.932 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-19T02:26:05.932Z,1618799165.932 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-19T02:26:14.794Z,1618799174.794 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-19T02:31:06.536Z,1618799466.536 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-19T02:31:06.536Z,1618799466.536 [Default:CheckIn:C.Wait] Stopped 2021-04-19T02:31:06.536Z,1618799466.536 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-19T02:31:06.545Z,1618799466.545 [Default:CheckIn:D] Running Loop=1 2021-04-19T02:31:06.941Z,1618799466.941 [Default:CheckIn:D] Stopped 2021-04-19T02:31:06.941Z,1618799466.941 [Default:CheckIn:E] Running Loop=1 2021-04-19T02:31:07.344Z,1618799467.344 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 472.247266 min 2021-04-19T02:31:07.345Z,1618799467.345 [Default:CheckIn:E] Stopped 2021-04-19T02:31:07.345Z,1618799467.345 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-19T02:31:07.345Z,1618799467.345 [Default:CheckIn] Stopped 2021-04-19T02:31:07.345Z,1618799467.345 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-19T02:31:07.345Z,1618799467.345 [Default:CheckIn](INFO): Running loop #46 2021-04-19T02:31:07.345Z,1618799467.345 [Default:CheckIn] Running Loop=46 2021-04-19T02:31:07.345Z,1618799467.345 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-19T02:31:07.346Z,1618799467.346 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-19T02:36:07.512Z,1618799767.512 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-19T02:31:07.3Z 2021-04-19T02:36:07.512Z,1618799767.512 [Default:CheckIn:Read_GPS] Stopped 2021-04-19T02:36:07.512Z,1618799767.512 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-19T02:36:11.947Z,1618799771.947 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-19T02:36:14.705Z,1618799774.705 [DataOverHttps](INFO): Sending 38 bytes from file Logs/20210418T183851/Courier0135.lzma 2021-04-19T02:36:15.708Z,1618799775.708 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Courier0135.lzma.bak 2021-04-19T02:36:15.708Z,1618799775.708 [DataOverHttps](INFO): SBD MOMSN=15583440 2021-04-19T02:36:32.209Z,1618799792.209 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20210418T183851/Express0136.lzma 2021-04-19T02:36:33.212Z,1618799793.212 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Express0136.lzma.bak 2021-04-19T02:36:33.212Z,1618799793.212 [DataOverHttps](INFO): SBD MOMSN=15583442 2021-04-19T02:36:34.591Z,1618799794.591 [Default:CheckIn:Read_Iridium] Stopped 2021-04-19T02:36:34.591Z,1618799794.591 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-19T02:36:34.591Z,1618799794.591 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-19T02:36:42.652Z,1618799802.652 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-19T02:41:35.198Z,1618800095.198 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-19T02:41:35.199Z,1618800095.199 [Default:CheckIn:C.Wait] Stopped 2021-04-19T02:41:35.199Z,1618800095.199 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-19T02:41:35.199Z,1618800095.199 [Default:CheckIn:D] Running Loop=1 2021-04-19T02:41:35.615Z,1618800095.615 [Default:CheckIn:D] Stopped 2021-04-19T02:41:35.615Z,1618800095.615 [Default:CheckIn:E] Running Loop=1 2021-04-19T02:41:35.999Z,1618800095.999 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 482.725195 min 2021-04-19T02:41:35.999Z,1618800095.999 [Default:CheckIn:E] Stopped 2021-04-19T02:41:35.999Z,1618800095.999 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-19T02:41:35.999Z,1618800095.999 [Default:CheckIn] Stopped 2021-04-19T02:41:35.999Z,1618800095.999 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-19T02:41:35.999Z,1618800095.999 [Default:CheckIn](INFO): Running loop #47 2021-04-19T02:41:35.999Z,1618800095.999 [Default:CheckIn] Running Loop=47 2021-04-19T02:41:35.999Z,1618800095.999 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-19T02:41:35.999Z,1618800095.999 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-19T02:41:37.611Z,1618800097.611 [NAL9602](FAULT): GPS failed to acquire within timeout. 2021-04-19T02:41:37.611Z,1618800097.611 [NAL9602] Data Fault, FailCount= 1 2021-04-19T02:41:37.611Z,1618800097.611 [NAL9602](ERROR): Data Fault 2021-04-19T02:41:37.647Z,1618800097.647 [CBIT](ERROR): Data Fault in component: NAL9602 2021-04-19T02:41:38.014Z,1618800098.014 [NAL9602](INFO): Powering down 2021-04-19T02:41:38.862Z,1618800098.862 [CBIT](INFO): Clearing failed state for component NAL9602 2021-04-19T02:41:38.862Z,1618800098.862 [NAL9602] No Fault, FailCount= 1 2021-04-19T02:42:08.310Z,1618800128.310 [NAL9602](INFO): Powering up NAL9602 2021-04-19T02:42:19.219Z,1618800139.219 [NAL9602](INFO): NAL9602 initialized 2021-04-19T02:46:36.198Z,1618800396.198 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-19T02:41:35.0Z 2021-04-19T02:46:36.198Z,1618800396.198 [Default:CheckIn:Read_GPS] Stopped 2021-04-19T02:46:36.199Z,1618800396.199 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-19T02:46:43.817Z,1618800403.817 [DataOverHttps](INFO): Sending 38 bytes from file Logs/20210418T183851/Courier0138.lzma 2021-04-19T02:46:44.820Z,1618800404.820 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Courier0138.lzma.bak 2021-04-19T02:46:44.820Z,1618800404.820 [DataOverHttps](INFO): SBD MOMSN=15583509 2021-04-19T02:47:00.745Z,1618800420.745 [DataOverHttps](INFO): Sending 225 bytes from file Logs/20210418T183851/Express0139.lzma 2021-04-19T02:47:01.748Z,1618800421.748 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Express0139.lzma.bak 2021-04-19T02:47:01.748Z,1618800421.748 [DataOverHttps](INFO): SBD MOMSN=15583511 2021-04-19T02:47:03.261Z,1618800423.261 [Default:CheckIn:Read_Iridium] Stopped 2021-04-19T02:47:03.261Z,1618800423.261 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-19T02:47:03.261Z,1618800423.261 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-19T02:47:22.243Z,1618800442.243 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-19T02:47:52.972Z,1618800472.972 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-19T02:52:03.839Z,1618800723.839 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-19T02:52:03.839Z,1618800723.839 [Default:CheckIn:C.Wait] Stopped 2021-04-19T02:52:03.839Z,1618800723.839 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-19T02:52:03.839Z,1618800723.839 [Default:CheckIn:D] Running Loop=1 2021-04-19T02:52:04.253Z,1618800724.253 [Default:CheckIn:D] Stopped 2021-04-19T02:52:04.253Z,1618800724.253 [Default:CheckIn:E] Running Loop=1 2021-04-19T02:52:04.642Z,1618800724.642 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 493.202474 min 2021-04-19T02:52:04.642Z,1618800724.642 [Default:CheckIn:E] Stopped 2021-04-19T02:52:04.642Z,1618800724.642 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-19T02:52:04.642Z,1618800724.642 [Default:CheckIn] Stopped 2021-04-19T02:52:04.643Z,1618800724.643 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-19T02:52:04.643Z,1618800724.643 [Default:CheckIn](INFO): Running loop #48 2021-04-19T02:52:04.643Z,1618800724.643 [Default:CheckIn] Running Loop=48 2021-04-19T02:52:04.643Z,1618800724.643 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-19T02:52:04.643Z,1618800724.643 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-19T02:52:37.363Z,1618800757.363 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-04-19T02:52:37.437Z,1618800757.437 [NAL9602](FAULT): received: +CSQ:0 OK576, 2, 0, 0, 0 OK 2021-04-19T02:52:37.437Z,1618800757.437 [NAL9602] Data Fault, FailCount= 2 2021-04-19T02:52:37.437Z,1618800757.437 [NAL9602](ERROR): Data Fault 2021-04-19T02:52:37.493Z,1618800757.493 [CBIT](ERROR): Data Fault in component: NAL9602 2021-04-19T02:52:37.763Z,1618800757.763 [NAL9602](INFO): Powering down 2021-04-19T02:52:38.620Z,1618800758.620 [CBIT](INFO): Clearing failed state for component NAL9602 2021-04-19T02:52:38.620Z,1618800758.620 [NAL9602] No Fault, FailCount= 2 2021-04-19T02:53:08.066Z,1618800788.066 [NAL9602](INFO): Powering up NAL9602 2021-04-19T02:53:18.973Z,1618800798.973 [NAL9602](INFO): NAL9602 initialized 2021-04-19T02:53:19.783Z,1618800799.783 [NAL9602](FAULT): GPS failed to acquire within timeout. 2021-04-19T02:53:19.783Z,1618800799.783 [NAL9602] Data Fault, FailCount= 3 2021-04-19T02:53:19.783Z,1618800799.783 [NAL9602](ERROR): Data Fault 2021-04-19T02:53:19.830Z,1618800799.830 [CBIT](ERROR): Data Fault in component: NAL9602 2021-04-19T02:53:20.180Z,1618800800.180 [NAL9602](INFO): Powering down 2021-04-19T02:53:21.028Z,1618800801.028 [CBIT](INFO): Clearing failed state for component NAL9602 2021-04-19T02:53:21.028Z,1618800801.028 [NAL9602] No Fault, FailCount= 3 2021-04-19T02:53:50.480Z,1618800830.480 [NAL9602](INFO): Powering up NAL9602 2021-04-19T02:54:01.395Z,1618800841.395 [NAL9602](INFO): NAL9602 initialized 2021-04-19T02:57:04.820Z,1618801024.820 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-19T02:52:04.6Z 2021-04-19T02:57:04.820Z,1618801024.820 [Default:CheckIn:Read_GPS] Stopped 2021-04-19T02:57:04.821Z,1618801024.821 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-19T02:57:09.387Z,1618801029.387 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-19T02:57:11.837Z,1618801031.837 [DataOverHttps](INFO): Sending 37 bytes from file Logs/20210418T183851/Courier0141.lzma 2021-04-19T02:57:12.839Z,1618801032.839 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Courier0141.lzma.bak 2021-04-19T02:57:12.840Z,1618801032.840 [DataOverHttps](INFO): SBD MOMSN=15583545 2021-04-19T02:57:28.747Z,1618801048.747 [DataOverHttps](INFO): Sending 267 bytes from file Logs/20210418T183851/Express0142.lzma 2021-04-19T02:57:29.747Z,1618801049.747 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Express0142.lzma.bak 2021-04-19T02:57:29.748Z,1618801049.748 [DataOverHttps](INFO): SBD MOMSN=15583547 2021-04-19T02:57:31.222Z,1618801051.222 [Default:CheckIn:Read_Iridium] Stopped 2021-04-19T02:57:31.222Z,1618801051.222 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-19T02:57:31.222Z,1618801051.222 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-19T02:57:40.089Z,1618801060.089 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-19T02:58:18.138Z,1618801098.138 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2021-04-19T02:58:53.275Z,1618801133.275 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2021-04-19T02:59:16.295Z,1618801156.295 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2021-04-19T03:00:06.841Z,1618801206.841 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2021-04-19T03:00:51.244Z,1618801251.244 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2021-04-19T03:01:52.252Z,1618801312.252 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2021-04-19T03:02:31.788Z,1618801351.788 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-19T03:02:31.788Z,1618801351.788 [Default:CheckIn:C.Wait] Stopped 2021-04-19T03:02:31.788Z,1618801351.788 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-19T03:02:31.788Z,1618801351.788 [Default:CheckIn:D] Running Loop=1 2021-04-19T03:02:32.200Z,1618801352.200 [Default:CheckIn:D] Stopped 2021-04-19T03:02:32.200Z,1618801352.200 [Default:CheckIn:E] Running Loop=1 2021-04-19T03:02:32.614Z,1618801352.614 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 503.668262 min 2021-04-19T03:02:32.614Z,1618801352.614 [Default:CheckIn:E] Stopped 2021-04-19T03:02:32.614Z,1618801352.614 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-19T03:02:32.614Z,1618801352.614 [Default:CheckIn] Stopped 2021-04-19T03:02:32.614Z,1618801352.614 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-19T03:02:32.615Z,1618801352.615 [Default:CheckIn](INFO): Running loop #49 2021-04-19T03:02:32.615Z,1618801352.615 [Default:CheckIn] Running Loop=49 2021-04-19T03:02:32.615Z,1618801352.615 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-19T03:02:32.615Z,1618801352.615 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-19T03:03:02.543Z,1618801382.543 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2021-04-19T03:03:05.315Z,1618801385.315 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-04-19T03:03:05.397Z,1618801385.397 [NAL9602](FAULT): received: +CSQ:0 OK576, 2, 0, 0, 0 OK 2021-04-19T03:03:05.397Z,1618801385.397 [NAL9602] Data Fault, FailCount= 4 2021-04-19T03:03:05.397Z,1618801385.397 [NAL9602](ERROR): Data Fault 2021-04-19T03:03:05.423Z,1618801385.423 [CBIT](ERROR): Data Fault in component: NAL9602 2021-04-19T03:03:05.719Z,1618801385.719 [NAL9602](INFO): Powering down 2021-04-19T03:03:06.554Z,1618801386.554 [CBIT](INFO): Clearing failed state for component NAL9602 2021-04-19T03:03:06.554Z,1618801386.554 [NAL9602] No Fault, FailCount= 4 2021-04-19T03:03:09.356Z,1618801389.356 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2021-04-19T03:03:09.363Z,1618801389.363 [BPC1](INFO): Received data from all battery sticks. 2021-04-19T03:03:36.012Z,1618801416.012 [NAL9602](INFO): Powering up NAL9602 2021-04-19T03:03:46.927Z,1618801426.927 [NAL9602](INFO): NAL9602 initialized 2021-04-19T03:07:32.797Z,1618801652.797 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-19T03:02:32.6Z 2021-04-19T03:07:32.797Z,1618801652.797 [Default:CheckIn:Read_GPS] Stopped 2021-04-19T03:07:32.798Z,1618801652.798 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-19T03:07:36.418Z,1618801656.418 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-19T03:07:40.365Z,1618801660.365 [DataOverHttps](INFO): Sending 50 bytes from file Logs/20210418T183851/Courier0144.lzma 2021-04-19T03:07:41.368Z,1618801661.368 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Courier0144.lzma.bak 2021-04-19T03:07:41.368Z,1618801661.368 [DataOverHttps](INFO): SBD MOMSN=15583563 2021-04-19T03:07:57.121Z,1618801677.121 [DataOverHttps](INFO): Sending 248 bytes from file Logs/20210418T183851/Express0145.lzma 2021-04-19T03:07:58.124Z,1618801678.124 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Express0145.lzma.bak 2021-04-19T03:07:58.124Z,1618801678.124 [DataOverHttps](INFO): SBD MOMSN=15583565 2021-04-19T03:07:59.864Z,1618801679.864 [Default:CheckIn:Read_Iridium] Stopped 2021-04-19T03:07:59.864Z,1618801679.864 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-19T03:07:59.864Z,1618801679.864 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-19T03:08:07.122Z,1618801687.122 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-19T03:12:59.648Z,1618801979.648 [CBIT](IMPORTANT): Beginning ground fault scan 2021-04-19T03:13:00.445Z,1618801980.445 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-19T03:13:00.446Z,1618801980.446 [Default:CheckIn:C.Wait] Stopped 2021-04-19T03:13:00.446Z,1618801980.446 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-19T03:13:00.446Z,1618801980.446 [Default:CheckIn:D] Running Loop=1 2021-04-19T03:13:00.848Z,1618801980.848 [Default:CheckIn:D] Stopped 2021-04-19T03:13:00.848Z,1618801980.848 [Default:CheckIn:E] Running Loop=1 2021-04-19T03:13:01.261Z,1618801981.261 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 514.145736 min 2021-04-19T03:13:01.261Z,1618801981.261 [Default:CheckIn:E] Stopped 2021-04-19T03:13:01.262Z,1618801981.262 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-19T03:13:01.262Z,1618801981.262 [Default:CheckIn] Stopped 2021-04-19T03:13:01.262Z,1618801981.262 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-19T03:13:01.262Z,1618801981.262 [Default:CheckIn](INFO): Running loop #50 2021-04-19T03:13:01.262Z,1618801981.262 [Default:CheckIn] Running Loop=50 2021-04-19T03:13:01.262Z,1618801981.262 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-19T03:13:01.262Z,1618801981.262 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-19T03:13:02.859Z,1618801982.859 [NAL9602](FAULT): GPS failed to acquire within timeout. 2021-04-19T03:13:02.859Z,1618801982.859 [NAL9602] Data Fault, FailCount= 5 2021-04-19T03:13:02.859Z,1618801982.859 [NAL9602](ERROR): Data Fault 2021-04-19T03:13:02.907Z,1618801982.907 [CBIT](ERROR): Data Fault in component: NAL9602 2021-04-19T03:13:02.908Z,1618801982.908 [CBIT](CRITICAL): Data Fault in component: NAL9602 2021-04-19T03:13:03.262Z,1618801983.262 [NAL9602](INFO): Powering down 2021-04-19T03:13:03.297Z,1618801983.297 [CBIT](INFO): Critical error at 20210419T031302 2021-04-19T03:13:10.550Z,1618801990.550 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): 0.001868 CHAN A1 (24V): 0.000278 CHAN A2 (12V): -0.002268 CHAN A3 (5V): -0.001331 CHAN B0 (3.3V): -0.000190 CHAN B1 (3.15aV): -0.000646 CHAN B2 (3.15bV): -0.000055 CHAN B3 (GND): -0.000191 OPEN: -0.000344 Full Scale Calc: 4.765 mA, -1.589 mA 2021-04-19T03:15:02.868Z,1618802102.868 [CBIT](INFO): Clearing failed state for component NAL9602 2021-04-19T03:15:02.868Z,1618802102.868 [NAL9602] No Fault, FailCount= 5 2021-04-19T03:15:03.257Z,1618802103.257 [NAL9602](INFO): Powering up NAL9602 2021-04-19T03:15:14.160Z,1618802114.160 [NAL9602](INFO): NAL9602 initialized 2021-04-19T03:18:01.435Z,1618802281.435 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-19T03:13:01.3Z 2021-04-19T03:18:01.435Z,1618802281.435 [Default:CheckIn:Read_GPS] Stopped 2021-04-19T03:18:01.435Z,1618802281.435 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-19T03:18:08.593Z,1618802288.593 [DataOverHttps](INFO): Sending 81 bytes from file Logs/20210418T183851/Courier0147.lzma 2021-04-19T03:18:09.595Z,1618802289.595 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Courier0147.lzma.bak 2021-04-19T03:18:09.596Z,1618802289.596 [DataOverHttps](INFO): SBD MOMSN=15583579 2021-04-19T03:18:25.653Z,1618802305.653 [DataOverHttps](INFO): Sending 403 bytes from file Logs/20210418T183851/Express0148.lzma 2021-04-19T03:18:26.655Z,1618802306.655 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Express0148.lzma.bak 2021-04-19T03:18:26.656Z,1618802306.656 [DataOverHttps](INFO): SBD MOMSN=15583582 2021-04-19T03:18:28.125Z,1618802308.125 [Default:CheckIn:Read_Iridium] Stopped 2021-04-19T03:18:28.125Z,1618802308.125 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-19T03:18:28.125Z,1618802308.125 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-19T03:20:17.182Z,1618802417.182 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-19T03:20:47.882Z,1618802447.882 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-19T03:23:28.683Z,1618802608.683 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-19T03:23:28.683Z,1618802608.683 [Default:CheckIn:C.Wait] Stopped 2021-04-19T03:23:28.683Z,1618802608.683 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-19T03:23:28.683Z,1618802608.683 [Default:CheckIn:D] Running Loop=1 2021-04-19T03:23:29.094Z,1618802609.094 [Default:CheckIn:D] Stopped 2021-04-19T03:23:29.094Z,1618802609.094 [Default:CheckIn:E] Running Loop=1 2021-04-19T03:23:29.498Z,1618802609.498 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 524.616504 min 2021-04-19T03:23:29.498Z,1618802609.498 [Default:CheckIn:E] Stopped 2021-04-19T03:23:29.498Z,1618802609.498 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-19T03:23:29.498Z,1618802609.498 [Default:CheckIn] Stopped 2021-04-19T03:23:29.498Z,1618802609.498 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-19T03:23:29.498Z,1618802609.498 [Default:CheckIn](INFO): Running loop #51 2021-04-19T03:23:29.499Z,1618802609.499 [Default:CheckIn] Running Loop=51 2021-04-19T03:23:29.499Z,1618802609.499 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-19T03:23:29.499Z,1618802609.499 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-19T03:24:02.211Z,1618802642.211 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-04-19T03:24:02.285Z,1618802642.285 [NAL9602](FAULT): received: +CSQ:0 OK576, 2, 0, 0, 0 OK 2021-04-19T03:24:02.285Z,1618802642.285 [NAL9602] Data Fault, FailCount= 1 2021-04-19T03:24:02.285Z,1618802642.285 [NAL9602](ERROR): Data Fault 2021-04-19T03:24:02.327Z,1618802642.327 [CBIT](ERROR): Data Fault in component: NAL9602 2021-04-19T03:24:02.610Z,1618802642.610 [NAL9602](INFO): Powering down 2021-04-19T03:24:03.437Z,1618802643.437 [CBIT](INFO): Clearing failed state for component NAL9602 2021-04-19T03:24:03.437Z,1618802643.437 [NAL9602] No Fault, FailCount= 1 2021-04-19T03:24:32.910Z,1618802672.910 [NAL9602](INFO): Powering up NAL9602 2021-04-19T03:24:43.823Z,1618802683.823 [NAL9602](INFO): NAL9602 initialized 2021-04-19T03:28:29.684Z,1618802909.684 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-19T03:23:29.5Z 2021-04-19T03:28:29.684Z,1618802909.684 [Default:CheckIn:Read_GPS] Stopped 2021-04-19T03:28:29.684Z,1618802909.684 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-19T03:28:32.887Z,1618802912.887 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-19T03:28:37.169Z,1618802917.169 [DataOverHttps](INFO): Sending 38 bytes from file Logs/20210418T183851/Courier0150.lzma 2021-04-19T03:28:38.172Z,1618802918.172 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Courier0150.lzma.bak 2021-04-19T03:28:38.172Z,1618802918.172 [DataOverHttps](INFO): SBD MOMSN=15583600 2021-04-19T03:28:53.886Z,1618802933.886 [DataOverHttps](INFO): Sending 248 bytes from file Logs/20210418T183851/Express0151.lzma 2021-04-19T03:28:54.888Z,1618802934.888 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Express0151.lzma.bak 2021-04-19T03:28:54.888Z,1618802934.888 [DataOverHttps](INFO): SBD MOMSN=15583602 2021-04-19T03:28:56.328Z,1618802936.328 [Default:CheckIn:Read_Iridium] Stopped 2021-04-19T03:28:56.329Z,1618802936.329 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-19T03:28:56.329Z,1618802936.329 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-19T03:29:03.594Z,1618802943.594 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-19T03:33:56.912Z,1618803236.912 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-19T03:33:56.913Z,1618803236.913 [Default:CheckIn:C.Wait] Stopped 2021-04-19T03:33:56.913Z,1618803236.913 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-19T03:33:56.929Z,1618803236.929 [Default:CheckIn:D] Running Loop=1 2021-04-19T03:33:57.316Z,1618803237.316 [Default:CheckIn:D] Stopped 2021-04-19T03:33:57.316Z,1618803237.316 [Default:CheckIn:E] Running Loop=1 2021-04-19T03:33:57.716Z,1618803237.716 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 535.086882 min 2021-04-19T03:33:57.716Z,1618803237.716 [Default:CheckIn:E] Stopped 2021-04-19T03:33:57.716Z,1618803237.716 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-19T03:33:57.716Z,1618803237.716 [Default:CheckIn] Stopped 2021-04-19T03:33:57.717Z,1618803237.717 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-19T03:33:57.717Z,1618803237.717 [Default:CheckIn](INFO): Running loop #52 2021-04-19T03:33:57.717Z,1618803237.717 [Default:CheckIn] Running Loop=52 2021-04-19T03:33:57.717Z,1618803237.717 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-19T03:33:57.717Z,1618803237.717 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-19T03:33:59.328Z,1618803239.328 [NAL9602](FAULT): GPS failed to acquire within timeout. 2021-04-19T03:33:59.328Z,1618803239.328 [NAL9602] Data Fault, FailCount= 2 2021-04-19T03:33:59.328Z,1618803239.328 [NAL9602](ERROR): Data Fault 2021-04-19T03:33:59.348Z,1618803239.348 [CBIT](ERROR): Data Fault in component: NAL9602 2021-04-19T03:33:59.727Z,1618803239.727 [NAL9602](INFO): Powering down 2021-04-19T03:34:00.557Z,1618803240.557 [CBIT](INFO): Clearing failed state for component NAL9602 2021-04-19T03:34:00.557Z,1618803240.557 [NAL9602] No Fault, FailCount= 2 2021-04-19T03:34:30.030Z,1618803270.030 [NAL9602](INFO): Powering up NAL9602 2021-04-19T03:34:40.939Z,1618803280.939 [NAL9602](INFO): NAL9602 initialized 2021-04-19T03:38:57.913Z,1618803537.913 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-19T03:33:57.7Z 2021-04-19T03:38:57.913Z,1618803537.913 [Default:CheckIn:Read_GPS] Stopped 2021-04-19T03:38:57.913Z,1618803537.913 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-19T03:39:05.549Z,1618803545.549 [DataOverHttps](INFO): Sending 38 bytes from file Logs/20210418T183851/Courier0153.lzma 2021-04-19T03:39:06.551Z,1618803546.551 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Courier0153.lzma.bak 2021-04-19T03:39:06.552Z,1618803546.552 [DataOverHttps](INFO): SBD MOMSN=15583617 2021-04-19T03:39:22.521Z,1618803562.521 [DataOverHttps](INFO): Sending 225 bytes from file Logs/20210418T183851/Express0154.lzma 2021-04-19T03:39:23.520Z,1618803563.520 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Express0154.lzma.bak 2021-04-19T03:39:23.520Z,1618803563.520 [DataOverHttps](INFO): SBD MOMSN=15583619 2021-04-19T03:39:24.977Z,1618803564.977 [Default:CheckIn:Read_Iridium] Stopped 2021-04-19T03:39:24.977Z,1618803564.977 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-19T03:39:24.977Z,1618803564.977 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-19T03:39:43.952Z,1618803583.952 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-19T03:40:14.660Z,1618803614.660 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-19T03:44:25.554Z,1618803865.554 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-19T03:44:25.554Z,1618803865.554 [Default:CheckIn:C.Wait] Stopped 2021-04-19T03:44:25.554Z,1618803865.554 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-19T03:44:25.555Z,1618803865.555 [Default:CheckIn:D] Running Loop=1 2021-04-19T03:44:25.966Z,1618803865.966 [Default:CheckIn:D] Stopped 2021-04-19T03:44:25.967Z,1618803865.967 [Default:CheckIn:E] Running Loop=1 2021-04-19T03:44:26.384Z,1618803866.384 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 545.564388 min 2021-04-19T03:44:26.384Z,1618803866.384 [Default:CheckIn:E] Stopped 2021-04-19T03:44:26.384Z,1618803866.384 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-19T03:44:26.384Z,1618803866.384 [Default:CheckIn] Stopped 2021-04-19T03:44:26.384Z,1618803866.384 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-19T03:44:26.384Z,1618803866.384 [Default:CheckIn](INFO): Running loop #53 2021-04-19T03:44:26.384Z,1618803866.384 [Default:CheckIn] Running Loop=53 2021-04-19T03:44:26.384Z,1618803866.384 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-19T03:44:26.385Z,1618803866.385 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-19T03:44:59.079Z,1618803899.079 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-04-19T03:44:59.161Z,1618803899.161 [NAL9602](FAULT): received: +CSQ:0 OK576, 2, 0, 0, 0 OK 2021-04-19T03:44:59.161Z,1618803899.161 [NAL9602] Data Fault, FailCount= 3 2021-04-19T03:44:59.161Z,1618803899.161 [NAL9602](ERROR): Data Fault 2021-04-19T03:44:59.186Z,1618803899.186 [CBIT](ERROR): Data Fault in component: NAL9602 2021-04-19T03:44:59.486Z,1618803899.486 [NAL9602](INFO): Powering down 2021-04-19T03:45:00.329Z,1618803900.329 [CBIT](INFO): Clearing failed state for component NAL9602 2021-04-19T03:45:00.329Z,1618803900.329 [NAL9602] No Fault, FailCount= 3 2021-04-19T03:45:29.780Z,1618803929.780 [NAL9602](INFO): Powering up NAL9602 2021-04-19T03:45:40.695Z,1618803940.695 [NAL9602](INFO): NAL9602 initialized 2021-04-19T03:45:41.503Z,1618803941.503 [NAL9602](FAULT): GPS failed to acquire within timeout. 2021-04-19T03:45:41.503Z,1618803941.503 [NAL9602] Data Fault, FailCount= 4 2021-04-19T03:45:41.503Z,1618803941.503 [NAL9602](ERROR): Data Fault 2021-04-19T03:45:41.527Z,1618803941.527 [CBIT](ERROR): Data Fault in component: NAL9602 2021-04-19T03:45:41.910Z,1618803941.910 [NAL9602](INFO): Powering down 2021-04-19T03:45:42.732Z,1618803942.732 [CBIT](INFO): Clearing failed state for component NAL9602 2021-04-19T03:45:42.732Z,1618803942.732 [NAL9602] No Fault, FailCount= 4 2021-04-19T03:46:12.202Z,1618803972.202 [NAL9602](INFO): Powering up NAL9602 2021-04-19T03:46:23.113Z,1618803983.113 [NAL9602](INFO): NAL9602 initialized 2021-04-19T03:47:14.424Z,1618804034.424 [NAL9602](INFO): SBD MO Status=2, MOMSN=25576, MT Status=2, MTMSN=0 2021-04-19T03:47:14.424Z,1618804034.424 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-04-19T03:49:26.542Z,1618804166.542 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-19T03:44:26.4Z 2021-04-19T03:49:26.542Z,1618804166.542 [Default:CheckIn:Read_GPS] Stopped 2021-04-19T03:49:26.543Z,1618804166.543 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-19T03:49:30.163Z,1618804170.163 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-19T03:49:34.201Z,1618804174.201 [DataOverHttps](INFO): Sending 38 bytes from file Logs/20210418T183851/Courier0156.lzma 2021-04-19T03:49:35.204Z,1618804175.204 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Courier0156.lzma.bak 2021-04-19T03:49:35.204Z,1618804175.204 [DataOverHttps](INFO): SBD MOMSN=15583637 2021-04-19T03:49:51.106Z,1618804191.106 [DataOverHttps](INFO): Sending 266 bytes from file Logs/20210418T183851/Express0157.lzma 2021-04-19T03:49:52.108Z,1618804192.108 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Express0157.lzma.bak 2021-04-19T03:49:52.108Z,1618804192.108 [DataOverHttps](INFO): SBD MOMSN=15583639 2021-04-19T03:49:53.653Z,1618804193.653 [Default:CheckIn:Read_Iridium] Stopped 2021-04-19T03:49:53.653Z,1618804193.653 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-19T03:49:53.653Z,1618804193.653 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-19T03:50:00.903Z,1618804200.903 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-19T03:54:54.255Z,1618804494.255 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-19T03:54:54.255Z,1618804494.255 [Default:CheckIn:C.Wait] Stopped 2021-04-19T03:54:54.255Z,1618804494.255 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-19T03:54:54.255Z,1618804494.255 [Default:CheckIn:D] Running Loop=1 2021-04-19T03:54:54.650Z,1618804494.650 [Default:CheckIn:D] Stopped 2021-04-19T03:54:54.650Z,1618804494.650 [Default:CheckIn:E] Running Loop=1 2021-04-19T03:54:55.061Z,1618804495.061 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 556.042448 min 2021-04-19T03:54:55.061Z,1618804495.061 [Default:CheckIn:E] Stopped 2021-04-19T03:54:55.061Z,1618804495.061 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-19T03:54:55.061Z,1618804495.061 [Default:CheckIn] Stopped 2021-04-19T03:54:55.061Z,1618804495.061 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-19T03:54:55.061Z,1618804495.061 [Default:CheckIn](INFO): Running loop #54 2021-04-19T03:54:55.062Z,1618804495.062 [Default:CheckIn] Running Loop=54 2021-04-19T03:54:55.062Z,1618804495.062 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-19T03:54:55.062Z,1618804495.062 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-19T03:55:27.775Z,1618804527.775 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-04-19T03:55:27.849Z,1618804527.849 [NAL9602](FAULT): received: +CSQ:0 OK576, 2, 0, 0, 0 OK 2021-04-19T03:55:27.849Z,1618804527.849 [NAL9602] Data Fault, FailCount= 5 2021-04-19T03:55:27.849Z,1618804527.849 [NAL9602](ERROR): Data Fault 2021-04-19T03:55:27.895Z,1618804527.895 [CBIT](ERROR): Data Fault in component: NAL9602 2021-04-19T03:55:27.896Z,1618804527.896 [CBIT](CRITICAL): Data Fault in component: NAL9602 2021-04-19T03:55:28.183Z,1618804528.183 [NAL9602](INFO): Powering down 2021-04-19T03:55:28.201Z,1618804528.201 [CBIT](INFO): Critical error at 20210419T035527 2021-04-19T03:57:28.188Z,1618804648.188 [CBIT](INFO): Clearing failed state for component NAL9602 2021-04-19T03:57:28.188Z,1618804648.188 [NAL9602] No Fault, FailCount= 5 2021-04-19T03:57:28.574Z,1618804648.574 [NAL9602](INFO): Powering up NAL9602 2021-04-19T03:57:39.494Z,1618804659.494 [NAL9602](INFO): NAL9602 initialized 2021-04-19T03:57:40.290Z,1618804660.290 [NAL9602](FAULT): GPS failed to acquire within timeout. 2021-04-19T03:57:40.290Z,1618804660.290 [NAL9602] Data Fault, FailCount= 1 2021-04-19T03:57:40.290Z,1618804660.290 [NAL9602](ERROR): Data Fault 2021-04-19T03:57:40.310Z,1618804660.310 [CBIT](ERROR): Data Fault in component: NAL9602 2021-04-19T03:57:40.686Z,1618804660.686 [NAL9602](INFO): Powering down 2021-04-19T03:57:41.518Z,1618804661.518 [CBIT](INFO): Clearing failed state for component NAL9602 2021-04-19T03:57:41.518Z,1618804661.518 [NAL9602] No Fault, FailCount= 1 2021-04-19T03:58:10.984Z,1618804690.984 [NAL9602](INFO): Powering up NAL9602 2021-04-19T03:58:21.905Z,1618804701.905 [NAL9602](INFO): NAL9602 initialized 2021-04-19T03:59:55.264Z,1618804795.264 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-19T03:54:55.1Z 2021-04-19T03:59:55.264Z,1618804795.264 [Default:CheckIn:Read_GPS] Stopped 2021-04-19T03:59:55.264Z,1618804795.264 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-19T03:59:59.290Z,1618804799.290 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-19T04:00:02.649Z,1618804802.649 [DataOverHttps](INFO): Sending 81 bytes from file Logs/20210418T183851/Courier0159.lzma 2021-04-19T04:00:03.651Z,1618804803.651 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Courier0159.lzma.bak 2021-04-19T04:00:03.652Z,1618804803.652 [DataOverHttps](INFO): SBD MOMSN=15583678 2021-04-19T04:00:22.926Z,1618804822.926 [DataOverHttps](INFO): Sending 266 bytes from file Logs/20210418T183851/Express0160.lzma 2021-04-19T04:00:23.928Z,1618804823.928 [DataOverHttps](INFO): Moved sent file to Logs/20210418T183851/Express0160.lzma.bak 2021-04-19T04:00:23.928Z,1618804823.928 [DataOverHttps](INFO): SBD MOMSN=15583691 2021-04-19T04:00:26.034Z,1618804826.034 [Default:CheckIn:Read_Iridium] Stopped 2021-04-19T04:00:26.034Z,1618804826.034 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-19T04:00:26.034Z,1618804826.034 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-19T04:00:30.050Z,1618804830.050 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-19T04:04:17.580Z,1618805057.580 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2021-04-19T04:05:02.483Z,1618805102.483 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2021-04-19T04:05:26.682Z,1618805126.682 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-19T04:05:26.682Z,1618805126.682 [Default:CheckIn:C.Wait] Stopped 2021-04-19T04:05:26.682Z,1618805126.682 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-19T04:05:26.683Z,1618805126.683 [Default:CheckIn:D] Running Loop=1 2021-04-19T04:05:27.061Z,1618805127.061 [Default:CheckIn:D] Stopped 2021-04-19T04:05:27.061Z,1618805127.061 [Default:CheckIn:E] Running Loop=1 2021-04-19T04:05:27.491Z,1618805127.491 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 566.582617 min 2021-04-19T04:05:27.491Z,1618805127.491 [Default:CheckIn:E] Stopped 2021-04-19T04:05:27.492Z,1618805127.492 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-19T04:05:27.492Z,1618805127.492 [Default:CheckIn] Stopped 2021-04-19T04:05:27.492Z,1618805127.492 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-19T04:05:27.492Z,1618805127.492 [Default:CheckIn](INFO): Running loop #55 2021-04-19T04:05:27.492Z,1618805127.492 [Default:CheckIn] Running Loop=55 2021-04-19T04:05:27.492Z,1618805127.492 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-19T04:05:27.492Z,1618805127.492 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-19T04:05:40.971Z,1618805140.971 [CommandLine](IMPORTANT): got command restart system 2021-04-19T04:05:41.397Z,1618805141.397 [PAR_Licor](INFO): A/D timeout, 4 tries over 131 ms 2021-04-19T04:05:41.397Z,1618805141.397 [PAR_Licor] Data Fault, FailCount= 1 2021-04-19T04:05:41.397Z,1618805141.397 [PAR_Licor](ERROR): Data Fault 2021-04-19T04:05:41.508Z,1618805141.508 [CBIT](ERROR): Data Fault in component: PAR_Licor 2021-04-19T04:05:41.508Z,1618805141.508 [CBIT](INFO): Clearing failed state for component PAR_Licor 2021-04-19T04:05:41.509Z,1618805141.509 [PAR_Licor] No Fault, FailCount= 1 2021-04-19T04:05:41.961Z,1618805141.961 [CBIT](CRITICAL): Run-time exception #7 2021-04-19T04:05:41.961Z,1618805141.961 [CBIT] Software Fault, FailCount= 1 2021-04-19T04:05:41.961Z,1618805141.961 [CBIT](ERROR): Software Fault 2021-04-19T04:05:41.971Z,1618805141.971 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2021-04-19T04:05:41.972Z,1618805141.972 [SyncHandler](INFO): Protected caller Thread ID is 8389 2021-04-19T04:05:42.417Z,1618805142.417 [CBIT](DEBUG): Uninitialize CBIT Component. 2021-04-19T04:05:42.417Z,1618805142.417 [CBIT](DEBUG): Powering off loads. 2021-04-19T04:05:42.462Z,1618805142.462 [CBIT](DEBUG): Disabling WDT. 2021-04-19T04:05:42.473Z,1618805142.473 [CBIT](DEBUG): Opening all GF detection circuits. 2021-04-19T04:05:43.278Z,1618805143.278 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2021-04-19T04:05:43.278Z,1618805143.278 [CommandLine ThreadHandler](INFO): Thread cancelled. 2021-04-19T04:05:43.378Z,1618805143.378 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2021-04-19T04:05:43.378Z,1618805143.378 [CommandLine ThreadHandler](INFO): Thread cancelled. 2021-04-19T04:05:43.379Z,1618805143.379 [CommandLine](INFO): Join timeout helper Thread ID is 8393 2021-04-19T04:05:43.380Z,1618805143.380 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2021-04-19T04:05:43.381Z,1618805143.381 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2021-04-19T04:05:43.406Z,1618805143.406 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2021-04-19T04:05:43.406Z,1618805143.406 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2021-04-19T04:05:43.430Z,1618805143.430 [NavChartDb](INFO): Join timeout helper Thread ID is 8394 2021-04-19T04:05:43.430Z,1618805143.430 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2021-04-19T04:05:43.430Z,1618805143.430 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2021-04-19T04:05:43.430Z,1618805143.430 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 8395 2021-04-19T04:05:43.878Z,1618805143.878 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2021-04-19T04:05:43.878Z,1618805143.878 [WetLabsBB2FL](INFO): Powering down 2021-04-19T04:05:43.879Z,1618805143.879 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2021-04-19T04:05:43.893Z,1618805143.893 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2021-04-19T04:05:43.894Z,1618805143.894 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2021-04-19T04:05:43.894Z,1618805143.894 [CTD_Seabird](INFO): Join timeout helper Thread ID is 8396 2021-04-19T04:05:44.230Z,1618805144.230 [CTD_Seabird](INFO): Powering down 2021-04-19T04:05:44.242Z,1618805144.242 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread. 2021-04-19T04:05:44.242Z,1618805144.242 [CTD_Seabird](INFO): Powering down 2021-04-19T04:05:44.254Z,1618805144.254 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2021-04-19T04:05:44.296Z,1618805144.296 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2021-04-19T04:05:44.296Z,1618805144.296 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2021-04-19T04:05:44.297Z,1618805144.297 [Radio_Surface](INFO): Join timeout helper Thread ID is 8397 2021-04-19T04:05:44.534Z,1618805144.534 [Radio_Surface](INFO): Powering down 2021-04-19T04:05:44.535Z,1618805144.535 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2021-04-19T04:05:44.535Z,1618805144.535 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2021-04-19T04:05:44.538Z,1618805144.538 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler 2021-04-19T04:05:44.539Z,1618805144.539 [Onboard ThreadHandler](INFO): Thread cancelled. 2021-04-19T04:05:44.539Z,1618805144.539 [Onboard](INFO): Join timeout helper Thread ID is 8399 2021-04-19T04:05:44.862Z,1618805144.862 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread. 2021-04-19T04:05:44.863Z,1618805144.863 [Onboard ThreadHandler](INFO): Thread cancelled. 2021-04-19T04:05:44.882Z,1618805144.882 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2021-04-19T04:05:44.882Z,1618805144.882 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2021-04-19T04:05:44.883Z,1618805144.883 [DataOverHttps](INFO): Join timeout helper Thread ID is 8401 2021-04-19T04:05:45.494Z,1618805145.494 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2021-04-19T04:05:45.494Z,1618805145.494 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2021-04-19T04:05:45.514Z,1618805145.514 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2021-04-19T04:05:45.514Z,1618805145.514 [logger ThreadHandler](INFO): Thread cancelled. 2021-04-19T04:05:45.515Z,1618805145.515 [logger](INFO): Join timeout helper Thread ID is 8402 2021-04-19T04:05:45.538Z,1618805145.538 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2021-04-19T04:05:45.538Z,1618805145.538 [logger ThreadHandler](INFO): Thread cancelled. 2021-04-19T04:05:45.554Z,1618805145.554 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2021-04-19T04:05:45.554Z,1618805145.554 [CommandLine ThreadHandler](INFO): Thread cancelled. 2021-04-19T04:05:45.554Z,1618805145.554 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2021-04-19T04:05:45.555Z,1618805145.555 [controlThread ThreadHandler](INFO): Thread cancelled. 2021-04-19T04:05:45.555Z,1618805145.555 [controlThread](INFO): Join timeout helper Thread ID is 8403 2021-04-19T04:05:45.710Z,1618805145.710 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2021-04-19T04:05:45.710Z,1618805145.710 [controlThread](DEBUG): Uninitializing ControlThread 2021-04-19T04:05:45.710Z,1618805145.710 [AHRS_M2](INFO): Powering down 2021-04-19T04:05:45.711Z,1618805145.711 [NAL9602](INFO): Powering down 2021-04-19T04:05:45.712Z,1618805145.712 [AMEcho](INFO): Powering down 2021-04-19T04:05:45.714Z,1618805145.714 [DAT](INFO): Powering down 2021-04-19T04:05:45.715Z,1618805145.715 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2021-04-19T04:05:45.716Z,1618805145.716 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2021-04-19T04:05:45.716Z,1618805145.716 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2021-04-19T04:05:45.717Z,1618805145.717 [MissionManager](INFO): Uninitializing Mission Default 2021-04-19T04:05:45.717Z,1618805145.717 [Default] Stopped 2021-04-19T04:05:45.717Z,1618805145.717 [Default](DEBUG): Aggregate::uninitialize Default 2021-04-19T04:05:45.717Z,1618805145.717 [Default:B