2022-04-14T18:49:27.375Z,1649962167.375 [CommandExec](IMPORTANT): got command restart logs 2022-04-14T18:49:28.328Z,1649962168.328 [DataOverHttps](IMPORTANT): SBD MTMSN=20220414T184927 2022-04-14T18:49:40.402Z,1649962180.402 [DataOverHttps](INFO): Received command: strobe off 2022-04-14T18:49:42.681Z,1649962182.681 [CommandExec](IMPORTANT): got command strobe off 2022-04-14T18:49:42.681Z,1649962182.681 [CommandExec](IMPORTANT): Deactivating strobe 2022-04-14T18:50:04.011Z,1649962204.011 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-04-14T18:50:04.011Z,1649962204.011 [Default:CheckIn:C.Wait] Stopped 2022-04-14T18:50:04.011Z,1649962204.011 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-04-14T18:50:04.013Z,1649962204.013 [Default:CheckIn:D] Running Loop=1 2022-04-14T18:50:04.540Z,1649962204.540 [Default:CheckIn:D] Stopped 2022-04-14T18:50:04.540Z,1649962204.540 [Default:CheckIn:E] Running Loop=1 2022-04-14T18:50:04.851Z,1649962204.851 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 22.313208 min 2022-04-14T18:50:04.851Z,1649962204.851 [Default:CheckIn:E] Stopped 2022-04-14T18:50:04.851Z,1649962204.851 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-04-14T18:50:04.851Z,1649962204.851 [Default:CheckIn] Stopped 2022-04-14T18:50:04.851Z,1649962204.851 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-04-14T18:50:04.851Z,1649962204.851 [Default:CheckIn](INFO): Running loop #5 2022-04-14T18:50:04.851Z,1649962204.851 [Default:CheckIn] Running Loop=5 2022-04-14T18:50:04.851Z,1649962204.851 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-04-14T18:50:04.851Z,1649962204.851 [Default:CheckIn:Read_GPS] Running Loop=1 2022-04-14T18:50:06.821Z,1649962206.821 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185006.00,A,3648.33220,N,12149.09447,W,28.788,99.21,140422,,,D*74 2022-04-14T18:50:06.823Z,1649962206.823 [NAL9602](INFO): GPS fix at 20220414T185006: (36.805537, -121.818241) 2022-04-14T18:50:06.834Z,1649962206.834 [Default:CheckIn:Read_GPS] Stopped 2022-04-14T18:50:06.834Z,1649962206.834 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-04-14T18:50:14.793Z,1649962214.793 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20220414T150143/Courier0039.lzma 2022-04-14T18:50:15.796Z,1649962215.796 [DataOverHttps](INFO): Moved sent file to Logs/20220414T150143/Courier0039.lzma.bak 2022-04-14T18:50:15.796Z,1649962215.796 [DataOverHttps](INFO): SBD MOMSN=16646301 2022-04-14T18:50:21.764Z,1649962221.764 [NAL9602](INFO): SBD MO Status=0, MOMSN=32711, MT Status=0, MTMSN=0 2022-04-14T18:50:21.764Z,1649962221.764 [NAL9602](INFO): No messages in MT queue 2022-04-14T18:50:34.423Z,1649962234.423 [DataOverHttps](INFO): Sending 268 bytes from file Logs/20220414T184927/Courier0000.lzma 2022-04-14T18:50:35.424Z,1649962235.424 [DataOverHttps](INFO): Moved sent file to Logs/20220414T184927/Courier0000.lzma.bak 2022-04-14T18:50:35.424Z,1649962235.424 [DataOverHttps](INFO): SBD MOMSN=16646304 2022-04-14T18:50:52.590Z,1649962252.590 [NAL9602](INFO): Not Powering down - fast GPS 2022-04-14T18:50:53.398Z,1649962253.398 [DataOverHttps](INFO): Sending 104 bytes from file Logs/20220414T150143/Express0040.lzma 2022-04-14T18:50:54.400Z,1649962254.400 [DataOverHttps](INFO): Moved sent file to Logs/20220414T150143/Express0040.lzma.bak 2022-04-14T18:50:54.400Z,1649962254.400 [DataOverHttps](INFO): SBD MOMSN=16646308 2022-04-14T18:51:04.653Z,1649962264.653 [BPC1](ERROR): BPC1A: No match for serial number 1717 in BPC1A's battery stick inventory (sticks 1-32 in onboard configuration file). 2022-04-14T18:51:11.294Z,1649962271.294 [DataOverHttps](INFO): Sending 411 bytes from file Logs/20220414T184927/Express0001.lzma 2022-04-14T18:51:12.296Z,1649962272.296 [DataOverHttps](INFO): Moved sent file to Logs/20220414T184927/Express0001.lzma.bak 2022-04-14T18:51:12.296Z,1649962272.296 [DataOverHttps](INFO): SBD MOMSN=16646311 2022-04-14T18:51:28.162Z,1649962288.162 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20220414T184927/Express0004.lzma 2022-04-14T18:51:29.164Z,1649962289.164 [DataOverHttps](INFO): Moved sent file to Logs/20220414T184927/Express0004.lzma.bak 2022-04-14T18:51:29.164Z,1649962289.164 [DataOverHttps](INFO): SBD MOMSN=16646318 2022-04-14T18:51:30.526Z,1649962290.526 [Default:CheckIn:Read_Iridium] Stopped 2022-04-14T18:51:30.527Z,1649962290.527 [Default:CheckIn:C.Wait] Running Loop=1 2022-04-14T18:51:30.527Z,1649962290.527 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-04-14T18:53:29.296Z,1649962409.296 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2022-04-14T18:53:29.298Z,1649962409.298 [BPC1](ERROR): Failed to receive data from all sticks prior to timeout. Will not retry this scan cycle. 2022-04-14T18:56:31.108Z,1649962591.108 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-04-14T18:56:31.108Z,1649962591.108 [Default:CheckIn:C.Wait] Stopped 2022-04-14T18:56:31.108Z,1649962591.108 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-04-14T18:56:31.109Z,1649962591.109 [Default:CheckIn:D] Running Loop=1 2022-04-14T18:56:31.513Z,1649962591.513 [Default:CheckIn:D] Stopped 2022-04-14T18:56:31.513Z,1649962591.513 [Default:CheckIn:E] Running Loop=1 2022-04-14T18:56:31.931Z,1649962591.931 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 28.762764 min 2022-04-14T18:56:31.931Z,1649962591.931 [Default:CheckIn:E] Stopped 2022-04-14T18:56:31.931Z,1649962591.931 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-04-14T18:56:31.931Z,1649962591.931 [Default:CheckIn] Stopped 2022-04-14T18:56:31.931Z,1649962591.931 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-04-14T18:56:31.932Z,1649962591.932 [Default:CheckIn](INFO): Running loop #6 2022-04-14T18:56:31.932Z,1649962591.932 [Default:CheckIn] Running Loop=6 2022-04-14T18:56:31.932Z,1649962591.932 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-04-14T18:56:31.932Z,1649962591.932 [Default:CheckIn:Read_GPS] Running Loop=1 2022-04-14T18:56:33.935Z,1649962593.935 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185633.00,A,3648.42451,N,12147.11412,W,4.957,180.10,140422,,,D*7C 2022-04-14T18:56:33.937Z,1649962593.937 [NAL9602](INFO): GPS fix at 20220414T185633: (36.807075, -121.785235) 2022-04-14T18:56:34.017Z,1649962594.017 [Default:CheckIn:Read_GPS] Stopped 2022-04-14T18:56:34.017Z,1649962594.017 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-04-14T18:56:35.542Z,1649962595.542 [NAL9602](FAULT): LCB fault: Invalid Command. Hardware Overcurrent Shutdown. Current Limiter Activated. 2022-04-14T18:56:35.542Z,1649962595.542 [NAL9602] Hardware Fault, FailCount= 1 2022-04-14T18:56:35.542Z,1649962595.542 [NAL9602](ERROR): Hardware Fault 2022-04-14T18:56:35.589Z,1649962595.589 [CBIT](ERROR): Hardware Fault in component: NAL9602 2022-04-14T18:56:35.947Z,1649962595.947 [NAL9602](INFO): Powering down 2022-04-14T18:56:36.802Z,1649962596.802 [CBIT](INFO): Clearing failed state for component NAL9602 2022-04-14T18:56:36.803Z,1649962596.803 [NAL9602] No Fault, FailCount= 1 2022-04-14T18:56:41.098Z,1649962601.098 [DataOverHttps](INFO): Sending 203 bytes from file Logs/20220414T184927/Courier0006.lzma 2022-04-14T18:56:42.100Z,1649962602.100 [DataOverHttps](INFO): Moved sent file to Logs/20220414T184927/Courier0006.lzma.bak 2022-04-14T18:56:42.100Z,1649962602.100 [DataOverHttps](INFO): SBD MOMSN=16646351 2022-04-14T18:56:57.810Z,1649962617.810 [DataOverHttps](INFO): Sending 252 bytes from file Logs/20220414T184927/Express0007.lzma 2022-04-14T18:56:58.812Z,1649962618.812 [DataOverHttps](INFO): Moved sent file to Logs/20220414T184927/Express0007.lzma.bak 2022-04-14T18:56:58.812Z,1649962618.812 [DataOverHttps](INFO): SBD MOMSN=16646354 2022-04-14T18:57:00.206Z,1649962620.206 [Default:CheckIn:Read_Iridium] Stopped 2022-04-14T18:57:00.206Z,1649962620.206 [Default:CheckIn:C.Wait] Running Loop=1 2022-04-14T18:57:00.206Z,1649962620.206 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-04-14T18:57:06.251Z,1649962626.251 [NAL9602](INFO): Powering up NAL9602 2022-04-14T18:57:17.159Z,1649962637.159 [NAL9602](INFO): NAL9602 initialized 2022-04-14T18:57:48.267Z,1649962668.267 [NAL9602](INFO): Not Powering down - fast GPS 2022-04-14T19:02:00.849Z,1649962920.849 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-04-14T19:02:00.849Z,1649962920.849 [Default:CheckIn:C.Wait] Stopped 2022-04-14T19:02:00.849Z,1649962920.849 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-04-14T19:02:00.850Z,1649962920.850 [Default:CheckIn:D] Running Loop=1 2022-04-14T19:02:01.238Z,1649962921.238 [Default:CheckIn:D] Stopped 2022-04-14T19:02:01.238Z,1649962921.238 [Default:CheckIn:E] Running Loop=1 2022-04-14T19:02:01.649Z,1649962921.649 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 34.258187 min 2022-04-14T19:02:01.649Z,1649962921.649 [Default:CheckIn:E] Stopped 2022-04-14T19:02:01.650Z,1649962921.650 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-04-14T19:02:01.650Z,1649962921.650 [Default:CheckIn] Stopped 2022-04-14T19:02:01.650Z,1649962921.650 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-04-14T19:02:01.650Z,1649962921.650 [Default:CheckIn](INFO): Running loop #7 2022-04-14T19:02:01.650Z,1649962921.650 [Default:CheckIn] Running Loop=7 2022-04-14T19:02:01.650Z,1649962921.650 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-04-14T19:02:01.651Z,1649962921.651 [Default:CheckIn:Read_GPS] Running Loop=1 2022-04-14T19:02:03.665Z,1649962923.665 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190201.00,A,3648.12116,N,12147.23058,W,0.097,271.95,140422,,,D*74 2022-04-14T19:02:03.667Z,1649962923.667 [NAL9602](INFO): GPS fix at 20220414T190201: (36.802019, -121.787176) 2022-04-14T19:02:03.677Z,1649962923.677 [Default:CheckIn:Read_GPS] Stopped 2022-04-14T19:02:03.677Z,1649962923.677 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-04-14T19:02:04.122Z,1649962924.122 [NAL9602](ERROR): parseGSV uart error: serial timeout 2022-04-14T19:02:10.830Z,1649962930.830 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220414T184927/Courier0009.lzma 2022-04-14T19:02:11.832Z,1649962931.832 [DataOverHttps](INFO): Moved sent file to Logs/20220414T184927/Courier0009.lzma.bak 2022-04-14T19:02:11.832Z,1649962931.832 [DataOverHttps](INFO): SBD MOMSN=16646374 2022-04-14T19:02:18.603Z,1649962938.603 [NAL9602](INFO): SBD MO Status=0, MOMSN=32712, MT Status=0, MTMSN=0 2022-04-14T19:02:18.603Z,1649962938.603 [NAL9602](INFO): No messages in MT queue 2022-04-14T19:02:30.357Z,1649962950.357 [DataOverHttps](INFO): Sending 249 bytes from file Logs/20220414T184927/Express0010.lzma 2022-04-14T19:02:31.352Z,1649962951.352 [DataOverHttps](INFO): Moved sent file to Logs/20220414T184927/Express0010.lzma.bak 2022-04-14T19:02:31.352Z,1649962951.352 [DataOverHttps](INFO): SBD MOMSN=16646380 2022-04-14T19:02:32.803Z,1649962952.803 [Default:CheckIn:Read_Iridium] Stopped 2022-04-14T19:02:32.803Z,1649962952.803 [Default:CheckIn:C.Wait] Running Loop=1 2022-04-14T19:02:32.803Z,1649962952.803 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-04-14T19:02:49.356Z,1649962969.356 [NAL9602](INFO): Not Powering down - fast GPS 2022-04-14T19:07:33.375Z,1649963253.375 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-04-14T19:07:33.375Z,1649963253.375 [Default:CheckIn:C.Wait] Stopped 2022-04-14T19:07:33.375Z,1649963253.375 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-04-14T19:07:33.376Z,1649963253.376 [Default:CheckIn:D] Running Loop=1 2022-04-14T19:07:33.785Z,1649963253.785 [Default:CheckIn:D] Stopped 2022-04-14T19:07:33.785Z,1649963253.785 [Default:CheckIn:E] Running Loop=1 2022-04-14T19:07:34.189Z,1649963254.189 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 39.800635 min 2022-04-14T19:07:34.189Z,1649963254.189 [Default:CheckIn:E] Stopped 2022-04-14T19:07:34.189Z,1649963254.189 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-04-14T19:07:34.189Z,1649963254.189 [Default:CheckIn] Stopped 2022-04-14T19:07:34.189Z,1649963254.189 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-04-14T19:07:34.189Z,1649963254.189 [Default:CheckIn](INFO): Running loop #8 2022-04-14T19:07:34.189Z,1649963254.189 [Default:CheckIn] Running Loop=8 2022-04-14T19:07:34.189Z,1649963254.189 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-04-14T19:07:34.189Z,1649963254.189 [Default:CheckIn:Read_GPS] Running Loop=1 2022-04-14T19:07:36.205Z,1649963256.205 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190734.00,A,3648.12267,N,12147.23652,W,0.058,315.89,140422,,,A*76 2022-04-14T19:07:36.207Z,1649963256.207 [NAL9602](INFO): GPS fix at 20220414T190734: (36.802045, -121.787275) 2022-04-14T19:07:36.218Z,1649963256.218 [Default:CheckIn:Read_GPS] Stopped 2022-04-14T19:07:36.219Z,1649963256.219 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-04-14T19:07:43.790Z,1649963263.790 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220414T184927/Courier0012.lzma 2022-04-14T19:07:44.792Z,1649963264.792 [DataOverHttps](INFO): Moved sent file to Logs/20220414T184927/Courier0012.lzma.bak 2022-04-14T19:07:44.792Z,1649963264.792 [DataOverHttps](INFO): SBD MOMSN=16646424 2022-04-14T19:07:56.809Z,1649963276.809 [NAL9602](INFO): SBD MO Status=2, MOMSN=32713, MT Status=2, MTMSN=0 2022-04-14T19:07:56.809Z,1649963276.809 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-04-14T19:08:00.578Z,1649963280.578 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20220414T184927/Express0013.lzma 2022-04-14T19:08:01.580Z,1649963281.580 [DataOverHttps](INFO): Moved sent file to Logs/20220414T184927/Express0013.lzma.bak 2022-04-14T19:08:01.580Z,1649963281.580 [DataOverHttps](INFO): SBD MOMSN=16646427 2022-04-14T19:08:02.875Z,1649963282.875 [Default:CheckIn:Read_Iridium] Stopped 2022-04-14T19:08:02.875Z,1649963282.875 [Default:CheckIn:C.Wait] Running Loop=1 2022-04-14T19:08:02.875Z,1649963282.875 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-04-14T19:08:14.179Z,1649963294.179 [NAL9602](INFO): SBD MO Status=2, MOMSN=32713, MT Status=2, MTMSN=0 2022-04-14T19:08:14.179Z,1649963294.179 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-04-14T19:09:22.456Z,1649963362.456 [NAL9602](INFO): SBD MO Status=2, MOMSN=32713, MT Status=2, MTMSN=0 2022-04-14T19:09:22.457Z,1649963362.457 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-04-14T19:09:39.420Z,1649963379.420 [NAL9602](INFO): SBD MO Status=2, MOMSN=32713, MT Status=2, MTMSN=0 2022-04-14T19:09:39.421Z,1649963379.421 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-04-14T19:10:40.829Z,1649963440.829 [NAL9602](INFO): SBD MO Status=0, MOMSN=32713, MT Status=0, MTMSN=0 2022-04-14T19:10:40.829Z,1649963440.829 [NAL9602](INFO): No messages in MT queue 2022-04-14T19:11:11.528Z,1649963471.528 [NAL9602](INFO): Not Powering down - fast GPS 2022-04-14T19:13:03.453Z,1649963583.453 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-04-14T19:13:03.453Z,1649963583.453 [Default:CheckIn:C.Wait] Stopped 2022-04-14T19:13:03.453Z,1649963583.453 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-04-14T19:13:03.453Z,1649963583.453 [Default:CheckIn:D] Running Loop=1 2022-04-14T19:13:03.866Z,1649963583.866 [Default:CheckIn:D] Stopped 2022-04-14T19:13:03.866Z,1649963583.866 [Default:CheckIn:E] Running Loop=1 2022-04-14T19:13:04.254Z,1649963584.254 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 45.301990 min 2022-04-14T19:13:04.254Z,1649963584.254 [Default:CheckIn:E] Stopped 2022-04-14T19:13:04.255Z,1649963584.255 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-04-14T19:13:04.255Z,1649963584.255 [Default:CheckIn] Stopped 2022-04-14T19:13:04.255Z,1649963584.255 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-04-14T19:13:04.255Z,1649963584.255 [Default:CheckIn](INFO): Running loop #9 2022-04-14T19:13:04.255Z,1649963584.255 [Default:CheckIn] Running Loop=9 2022-04-14T19:13:04.255Z,1649963584.255 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-04-14T19:13:04.255Z,1649963584.255 [Default:CheckIn:Read_GPS] Running Loop=1 2022-04-14T19:13:06.269Z,1649963586.269 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191305.00,A,3648.12054,N,12147.23526,W,0.039,315.89,140422,,,D*71 2022-04-14T19:13:06.271Z,1649963586.271 [NAL9602](INFO): GPS fix at 20220414T191305: (36.802009, -121.787254) 2022-04-14T19:13:06.315Z,1649963586.315 [Default:CheckIn:Read_GPS] Stopped 2022-04-14T19:13:06.315Z,1649963586.315 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-04-14T19:13:14.061Z,1649963594.061 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220414T184927/Courier0015.lzma 2022-04-14T19:13:15.064Z,1649963595.064 [DataOverHttps](INFO): Moved sent file to Logs/20220414T184927/Courier0015.lzma.bak 2022-04-14T19:13:15.064Z,1649963595.064 [DataOverHttps](INFO): SBD MOMSN=16646447 2022-04-14T19:13:21.621Z,1649963601.621 [NAL9602](INFO): SBD MO Status=0, MOMSN=32714, MT Status=0, MTMSN=0 2022-04-14T19:13:21.621Z,1649963601.621 [NAL9602](INFO): No messages in MT queue 2022-04-14T19:13:31.166Z,1649963611.166 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20220414T184927/Express0016.lzma 2022-04-14T19:13:32.168Z,1649963612.168 [DataOverHttps](INFO): Moved sent file to Logs/20220414T184927/Express0016.lzma.bak 2022-04-14T19:13:32.168Z,1649963612.168 [DataOverHttps](INFO): SBD MOMSN=16646453 2022-04-14T19:13:33.753Z,1649963613.753 [Default:CheckIn:Read_Iridium] Stopped 2022-04-14T19:13:33.753Z,1649963613.753 [Default:CheckIn:C.Wait] Running Loop=1 2022-04-14T19:13:33.753Z,1649963613.753 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-04-14T19:13:52.321Z,1649963632.321 [NAL9602](INFO): Not Powering down - fast GPS 2022-04-14T19:18:34.372Z,1649963914.372 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-04-14T19:18:34.372Z,1649963914.372 [Default:CheckIn:C.Wait] Stopped 2022-04-14T19:18:34.372Z,1649963914.372 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-04-14T19:18:34.373Z,1649963914.373 [Default:CheckIn:D] Running Loop=1 2022-04-14T19:18:34.744Z,1649963914.744 [Default:CheckIn:D] Stopped 2022-04-14T19:18:34.745Z,1649963914.745 [Default:CheckIn:E] Running Loop=1 2022-04-14T19:18:35.150Z,1649963915.150 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 50.816622 min 2022-04-14T19:18:35.151Z,1649963915.151 [Default:CheckIn:E] Stopped 2022-04-14T19:18:35.151Z,1649963915.151 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-04-14T19:18:35.151Z,1649963915.151 [Default:CheckIn] Stopped 2022-04-14T19:18:35.151Z,1649963915.151 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-04-14T19:18:35.151Z,1649963915.151 [Default:CheckIn](INFO): Running loop #10 2022-04-14T19:18:35.151Z,1649963915.151 [Default:CheckIn] Running Loop=10 2022-04-14T19:18:35.151Z,1649963915.151 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-04-14T19:18:35.151Z,1649963915.151 [Default:CheckIn:Read_GPS] Running Loop=1 2022-04-14T19:18:37.177Z,1649963917.177 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191836.00,A,3648.12072,N,12147.23474,W,0.272,315.89,140422,,,D*75 2022-04-14T19:18:37.179Z,1649963917.179 [NAL9602](INFO): GPS fix at 20220414T191836: (36.802012, -121.787246) 2022-04-14T19:18:37.239Z,1649963917.239 [Default:CheckIn:Read_GPS] Stopped 2022-04-14T19:18:37.239Z,1649963917.239 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-04-14T19:18:44.774Z,1649963924.774 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220414T184927/Courier0018.lzma 2022-04-14T19:18:45.776Z,1649963925.776 [DataOverHttps](INFO): Moved sent file to Logs/20220414T184927/Courier0018.lzma.bak 2022-04-14T19:18:45.776Z,1649963925.776 [DataOverHttps](INFO): SBD MOMSN=16646467 2022-04-14T19:19:01.570Z,1649963941.570 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20220414T184927/Express0019.lzma 2022-04-14T19:19:02.213Z,1649963942.213 [NAL9602](INFO): SBD MO Status=0, MOMSN=32715, MT Status=0, MTMSN=0 2022-04-14T19:19:02.213Z,1649963942.213 [NAL9602](INFO): No messages in MT queue 2022-04-14T19:19:02.572Z,1649963942.572 [DataOverHttps](INFO): Moved sent file to Logs/20220414T184927/Express0019.lzma.bak 2022-04-14T19:19:02.572Z,1649963942.572 [DataOverHttps](INFO): SBD MOMSN=16646470 2022-04-14T19:19:03.842Z,1649963943.842 [Default:CheckIn:Read_Iridium] Stopped 2022-04-14T19:19:03.843Z,1649963943.843 [Default:CheckIn:C.Wait] Running Loop=1 2022-04-14T19:19:03.843Z,1649963943.843 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-04-14T19:19:32.911Z,1649963972.911 [NAL9602](INFO): Not Powering down - fast GPS 2022-04-14T19:24:04.420Z,1649964244.420 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-04-14T19:24:04.420Z,1649964244.420 [Default:CheckIn:C.Wait] Stopped 2022-04-14T19:24:04.420Z,1649964244.420 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-04-14T19:24:04.421Z,1649964244.421 [Default:CheckIn:D] Running Loop=1 2022-04-14T19:24:04.823Z,1649964244.823 [Default:CheckIn:D] Stopped 2022-04-14T19:24:04.823Z,1649964244.823 [Default:CheckIn:E] Running Loop=1 2022-04-14T19:24:05.239Z,1649964245.239 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 56.317924 min 2022-04-14T19:24:05.239Z,1649964245.239 [Default:CheckIn:E] Stopped 2022-04-14T19:24:05.239Z,1649964245.239 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-04-14T19:24:05.239Z,1649964245.239 [Default:CheckIn] Stopped 2022-04-14T19:24:05.239Z,1649964245.239 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-04-14T19:24:05.239Z,1649964245.239 [Default:CheckIn](INFO): Running loop #11 2022-04-14T19:24:05.239Z,1649964245.239 [Default:CheckIn] Running Loop=11 2022-04-14T19:24:05.239Z,1649964245.239 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-04-14T19:24:05.240Z,1649964245.240 [Default:CheckIn:Read_GPS] Running Loop=1 2022-04-14T19:24:07.237Z,1649964247.237 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,192406.00,A,3648.17478,N,12147.27253,W,2.799,294.36,140422,,,D*7B 2022-04-14T19:24:07.239Z,1649964247.239 [NAL9602](INFO): GPS fix at 20220414T192406: (36.802913, -121.787875) 2022-04-14T19:24:07.250Z,1649964247.250 [Default:CheckIn:Read_GPS] Stopped 2022-04-14T19:24:07.251Z,1649964247.251 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-04-14T19:24:15.258Z,1649964255.258 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220414T184927/Courier0021.lzma 2022-04-14T19:24:16.260Z,1649964256.260 [DataOverHttps](INFO): Moved sent file to Logs/20220414T184927/Courier0021.lzma.bak 2022-04-14T19:24:16.260Z,1649964256.260 [DataOverHttps](INFO): SBD MOMSN=16646494 2022-04-14T19:24:32.030Z,1649964272.030 [DataOverHttps](INFO): Sending 142 bytes from file Logs/20220414T184927/Express0022.lzma 2022-04-14T19:24:33.032Z,1649964273.032 [DataOverHttps](INFO): Moved sent file to Logs/20220414T184927/Express0022.lzma.bak 2022-04-14T19:24:33.032Z,1649964273.032 [DataOverHttps](INFO): SBD MOMSN=16646497 2022-04-14T19:24:34.339Z,1649964274.339 [Default:CheckIn:Read_Iridium] Stopped 2022-04-14T19:24:34.339Z,1649964274.339 [Default:CheckIn:C.Wait] Running Loop=1 2022-04-14T19:24:34.339Z,1649964274.339 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-04-14T19:25:10.332Z,1649964310.332 [NAL9602](INFO): SBD MO Status=2, MOMSN=32716, MT Status=2, MTMSN=0 2022-04-14T19:25:10.333Z,1649964310.333 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-04-14T19:29:09.507Z,1649964549.507 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-04-14T19:29:34.963Z,1649964574.963 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-04-14T19:29:34.963Z,1649964574.963 [Default:CheckIn:C.Wait] Stopped 2022-04-14T19:29:34.963Z,1649964574.963 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-04-14T19:29:34.963Z,1649964574.963 [Default:CheckIn:D] Running Loop=1 2022-04-14T19:29:35.375Z,1649964575.375 [Default:CheckIn:D] Stopped 2022-04-14T19:29:35.375Z,1649964575.375 [Default:CheckIn:E] Running Loop=1 2022-04-14T19:29:35.793Z,1649964575.793 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 61.827132 min 2022-04-14T19:29:35.793Z,1649964575.793 [Default:CheckIn:E] Stopped 2022-04-14T19:29:35.793Z,1649964575.793 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-04-14T19:29:35.793Z,1649964575.793 [Default:CheckIn] Stopped 2022-04-14T19:29:35.793Z,1649964575.793 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-04-14T19:29:35.794Z,1649964575.794 [Default:CheckIn](INFO): Running loop #12 2022-04-14T19:29:35.794Z,1649964575.794 [Default:CheckIn] Running Loop=12 2022-04-14T19:29:35.794Z,1649964575.794 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-04-14T19:29:35.794Z,1649964575.794 [Default:CheckIn:Read_GPS] Running Loop=1 2022-04-14T19:29:37.789Z,1649964577.789 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,192936.00,A,3648.16983,N,12147.28482,W,0.544,234.39,140422,,,A*78 2022-04-14T19:29:37.791Z,1649964577.791 [NAL9602](INFO): GPS fix at 20220414T192936: (36.802830, -121.788080) 2022-04-14T19:29:37.801Z,1649964577.801 [Default:CheckIn:Read_GPS] Stopped 2022-04-14T19:29:37.802Z,1649964577.802 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-04-14T19:29:45.678Z,1649964585.678 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220414T184927/Courier0024.lzma 2022-04-14T19:29:46.680Z,1649964586.680 [DataOverHttps](INFO): Moved sent file to Logs/20220414T184927/Courier0024.lzma.bak 2022-04-14T19:29:46.680Z,1649964586.680 [DataOverHttps](INFO): SBD MOMSN=16646504 2022-04-14T19:30:02.466Z,1649964602.466 [DataOverHttps](INFO): Sending 217 bytes from file Logs/20220414T184927/Express0025.lzma 2022-04-14T19:30:03.468Z,1649964603.468 [DataOverHttps](INFO): Moved sent file to Logs/20220414T184927/Express0025.lzma.bak 2022-04-14T19:30:03.468Z,1649964603.468 [DataOverHttps](INFO): SBD MOMSN=16646510 2022-04-14T19:30:04.858Z,1649964604.858 [Default:CheckIn:Read_Iridium] Stopped 2022-04-14T19:30:04.858Z,1649964604.858 [Default:CheckIn:C.Wait] Running Loop=1 2022-04-14T19:30:04.858Z,1649964604.858 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-04-14T19:30:10.515Z,1649964610.515 [NAL9602](INFO): Not Powering down - fast GPS 2022-04-14T19:35:05.450Z,1649964905.450 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-04-14T19:35:05.450Z,1649964905.450 [Default:CheckIn:C.Wait] Stopped 2022-04-14T19:35:05.450Z,1649964905.450 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-04-14T19:35:05.451Z,1649964905.451 [Default:CheckIn:D] Running Loop=1 2022-04-14T19:35:05.857Z,1649964905.857 [Default:CheckIn:D] Stopped 2022-04-14T19:35:05.857Z,1649964905.857 [Default:CheckIn:E] Running Loop=1 2022-04-14T19:35:06.265Z,1649964906.265 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 67.335168 min 2022-04-14T19:35:06.265Z,1649964906.265 [Default:CheckIn:E] Stopped 2022-04-14T19:35:06.265Z,1649964906.265 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-04-14T19:35:06.265Z,1649964906.265 [Default:CheckIn] Stopped 2022-04-14T19:35:06.265Z,1649964906.265 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-04-14T19:35:06.265Z,1649964906.265 [Default:CheckIn](INFO): Running loop #13 2022-04-14T19:35:06.265Z,1649964906.265 [Default:CheckIn] Running Loop=13 2022-04-14T19:35:06.265Z,1649964906.265 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-04-14T19:35:06.265Z,1649964906.265 [Default:CheckIn:Read_GPS] Running Loop=1 2022-04-14T19:35:08.273Z,1649964908.273 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,193507.00,A,3648.16354,N,12147.28024,W,0.058,234.39,140422,,,A*77 2022-04-14T19:35:08.276Z,1649964908.276 [NAL9602](INFO): GPS fix at 20220414T193507: (36.802726, -121.788004) 2022-04-14T19:35:08.322Z,1649964908.322 [Default:CheckIn:Read_GPS] Stopped 2022-04-14T19:35:08.322Z,1649964908.322 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-04-14T19:35:15.782Z,1649964915.782 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220414T184927/Courier0027.lzma 2022-04-14T19:35:16.784Z,1649964916.784 [DataOverHttps](INFO): Moved sent file to Logs/20220414T184927/Courier0027.lzma.bak 2022-04-14T19:35:16.784Z,1649964916.784 [DataOverHttps](INFO): SBD MOMSN=16646527 2022-04-14T19:35:32.582Z,1649964932.582 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20220414T184927/Express0028.lzma 2022-04-14T19:35:33.584Z,1649964933.584 [DataOverHttps](INFO): Moved sent file to Logs/20220414T184927/Express0028.lzma.bak 2022-04-14T19:35:33.584Z,1649964933.584 [DataOverHttps](INFO): SBD MOMSN=16646534 2022-04-14T19:35:34.961Z,1649964934.961 [Default:CheckIn:Read_Iridium] Stopped 2022-04-14T19:35:34.961Z,1649964934.961 [Default:CheckIn:C.Wait] Running Loop=1 2022-04-14T19:35:34.961Z,1649964934.961 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-04-14T19:35:38.975Z,1649964938.975 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-04-14T19:35:39.058Z,1649964939.058 [NAL9602](ERROR): received: +CSQ:0 OK716, 2, 0, 0, 0 OK 2022-04-14T19:37:16.743Z,1649965036.743 [NAL9602](INFO): SBD MO Status=2, MOMSN=32716, MT Status=2, MTMSN=0 2022-04-14T19:37:16.743Z,1649965036.743 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-04-14T19:37:52.301Z,1649965072.301 [NAL9602](INFO): SBD MO Status=0, MOMSN=32716, MT Status=0, MTMSN=0 2022-04-14T19:37:52.301Z,1649965072.301 [NAL9602](INFO): No messages in MT queue 2022-04-14T19:38:22.000Z,1649965103.000 [NAL9602](INFO): Not Powering down - fast GPS 2022-04-14T19:40:35.537Z,1649965235.537 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-04-14T19:40:35.537Z,1649965235.537 [Default:CheckIn:C.Wait] Stopped 2022-04-14T19:40:35.537Z,1649965235.537 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-04-14T19:40:35.538Z,1649965235.538 [Default:CheckIn:D] Running Loop=1 2022-04-14T19:40:35.946Z,1649965235.946 [Default:CheckIn:D] Stopped 2022-04-14T19:40:35.946Z,1649965235.946 [Default:CheckIn:E] Running Loop=1 2022-04-14T19:40:36.342Z,1649965236.342 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 72.836646 min 2022-04-14T19:40:36.342Z,1649965236.342 [Default:CheckIn:E] Stopped 2022-04-14T19:40:36.342Z,1649965236.342 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-04-14T19:40:36.342Z,1649965236.342 [Default:CheckIn] Stopped 2022-04-14T19:40:36.343Z,1649965236.343 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-04-14T19:40:36.343Z,1649965236.343 [Default:CheckIn](INFO): Running loop #14 2022-04-14T19:40:36.343Z,1649965236.343 [Default:CheckIn] Running Loop=14 2022-04-14T19:40:36.343Z,1649965236.343 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-04-14T19:40:36.343Z,1649965236.343 [Default:CheckIn:Read_GPS] Running Loop=1 2022-04-14T19:40:38.357Z,1649965238.357 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194037.00,A,3648.16826,N,12147.28220,W,0.292,0.00,140422,,,A*75 2022-04-14T19:40:38.360Z,1649965238.360 [NAL9602](INFO): GPS fix at 20220414T194037: (36.802804, -121.788037) 2022-04-14T19:40:38.370Z,1649965238.370 [Default:CheckIn:Read_GPS] Stopped 2022-04-14T19:40:38.370Z,1649965238.370 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-04-14T19:40:46.006Z,1649965246.006 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220414T184927/Courier0030.lzma 2022-04-14T19:40:47.008Z,1649965247.008 [DataOverHttps](INFO): Moved sent file to Logs/20220414T184927/Courier0030.lzma.bak 2022-04-14T19:40:47.008Z,1649965247.008 [DataOverHttps](INFO): SBD MOMSN=16646539 2022-04-14T19:41:02.798Z,1649965262.798 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20220414T184927/Express0031.lzma 2022-04-14T19:41:03.800Z,1649965263.800 [DataOverHttps](INFO): Moved sent file to Logs/20220414T184927/Express0031.lzma.bak 2022-04-14T19:41:03.800Z,1649965263.800 [DataOverHttps](INFO): SBD MOMSN=16646544 2022-04-14T19:41:05.034Z,1649965265.034 [Default:CheckIn:Read_Iridium] Stopped 2022-04-14T19:41:05.034Z,1649965265.034 [Default:CheckIn:C.Wait] Running Loop=1 2022-04-14T19:41:05.035Z,1649965265.035 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-04-14T19:45:40.551Z,1649965540.551 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-04-14T19:46:05.606Z,1649965565.606 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-04-14T19:46:05.606Z,1649965565.606 [Default:CheckIn:C.Wait] Stopped 2022-04-14T19:46:05.606Z,1649965565.606 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-04-14T19:46:05.607Z,1649965565.607 [Default:CheckIn:D] Running Loop=1 2022-04-14T19:46:06.002Z,1649965566.002 [Default:CheckIn:D] Stopped 2022-04-14T19:46:06.003Z,1649965566.003 [Default:CheckIn:E] Running Loop=1 2022-04-14T19:46:06.409Z,1649965566.409 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 78.337590 min 2022-04-14T19:46:06.409Z,1649965566.409 [Default:CheckIn:E] Stopped 2022-04-14T19:46:06.409Z,1649965566.409 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-04-14T19:46:06.409Z,1649965566.409 [Default:CheckIn] Stopped 2022-04-14T19:46:06.410Z,1649965566.410 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-04-14T19:46:06.410Z,1649965566.410 [Default:CheckIn](INFO): Running loop #15 2022-04-14T19:46:06.410Z,1649965566.410 [Default:CheckIn] Running Loop=15 2022-04-14T19:46:06.410Z,1649965566.410 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-04-14T19:46:06.410Z,1649965566.410 [Default:CheckIn:Read_GPS] Running Loop=1 2022-04-14T19:46:08.425Z,1649965568.425 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194607.00,A,3648.16332,N,12147.28012,W,0.078,0.00,140422,,,A*7B 2022-04-14T19:46:08.427Z,1649965568.427 [NAL9602](INFO): GPS fix at 20220414T194607: (36.802722, -121.788002) 2022-04-14T19:46:08.437Z,1649965568.437 [Default:CheckIn:Read_GPS] Stopped 2022-04-14T19:46:08.437Z,1649965568.437 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-04-14T19:46:15.250Z,1649965575.250 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220414T184927/Courier0033.lzma 2022-04-14T19:46:16.252Z,1649965576.252 [DataOverHttps](INFO): Moved sent file to Logs/20220414T184927/Courier0033.lzma.bak 2022-04-14T19:46:16.252Z,1649965576.252 [DataOverHttps](INFO): SBD MOMSN=16646580 2022-04-14T19:46:34.902Z,1649965594.902 [DataOverHttps](INFO): Sending 205 bytes from file Logs/20220414T184927/Express0034.lzma 2022-04-14T19:46:35.904Z,1649965595.904 [DataOverHttps](INFO): Moved sent file to Logs/20220414T184927/Express0034.lzma.bak 2022-04-14T19:46:35.904Z,1649965595.904 [DataOverHttps](INFO): SBD MOMSN=16646583 2022-04-14T19:46:37.223Z,1649965597.223 [Default:CheckIn:Read_Iridium] Stopped 2022-04-14T19:46:37.223Z,1649965597.223 [Default:CheckIn:C.Wait] Running Loop=1 2022-04-14T19:46:37.223Z,1649965597.223 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-04-14T19:46:40.819Z,1649965600.819 [NAL9602](INFO): Not Powering down - fast GPS 2022-04-14T19:51:37.786Z,1649965897.786 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-04-14T19:51:37.786Z,1649965897.786 [Default:CheckIn:C.Wait] Stopped 2022-04-14T19:51:37.786Z,1649965897.786 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-04-14T19:51:37.787Z,1649965897.787 [Default:CheckIn:D] Running Loop=1 2022-04-14T19:51:38.183Z,1649965898.183 [Default:CheckIn:D] Stopped 2022-04-14T19:51:38.183Z,1649965898.183 [Default:CheckIn:E] Running Loop=1 2022-04-14T19:51:38.599Z,1649965898.599 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 83.873926 min 2022-04-14T19:51:38.599Z,1649965898.599 [Default:CheckIn:E] Stopped 2022-04-14T19:51:38.599Z,1649965898.599 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-04-14T19:51:38.599Z,1649965898.599 [Default:CheckIn] Stopped 2022-04-14T19:51:38.599Z,1649965898.599 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-04-14T19:51:38.600Z,1649965898.600 [Default:CheckIn](INFO): Running loop #16 2022-04-14T19:51:38.600Z,1649965898.600 [Default:CheckIn] Running Loop=16 2022-04-14T19:51:38.600Z,1649965898.600 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-04-14T19:51:38.600Z,1649965898.600 [Default:CheckIn:Read_GPS] Running Loop=1 2022-04-14T19:51:40.609Z,1649965900.609 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,195139.00,A,3648.16541,N,12147.27972,W,0.097,0.00,140422,,,A*73 2022-04-14T19:51:40.611Z,1649965900.611 [NAL9602](INFO): GPS fix at 20220414T195139: (36.802757, -121.787995) 2022-04-14T19:51:40.621Z,1649965900.621 [Default:CheckIn:Read_GPS] Stopped 2022-04-14T19:51:40.621Z,1649965900.621 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-04-14T19:51:47.634Z,1649965907.634 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220414T184927/Courier0036.lzma 2022-04-14T19:51:48.636Z,1649965908.636 [DataOverHttps](INFO): Moved sent file to Logs/20220414T184927/Courier0036.lzma.bak 2022-04-14T19:51:48.636Z,1649965908.636 [DataOverHttps](INFO): SBD MOMSN=16646598 2022-04-14T19:52:04.422Z,1649965924.422 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20220414T184927/Express0037.lzma 2022-04-14T19:52:05.420Z,1649965925.420 [DataOverHttps](INFO): Moved sent file to Logs/20220414T184927/Express0037.lzma.bak 2022-04-14T19:52:05.420Z,1649965925.420 [DataOverHttps](INFO): SBD MOMSN=16646601 2022-04-14T19:52:06.878Z,1649965926.878 [Default:CheckIn:Read_Iridium] Stopped 2022-04-14T19:52:06.878Z,1649965926.878 [Default:CheckIn:C.Wait] Running Loop=1 2022-04-14T19:52:06.878Z,1649965926.878 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-04-14T19:52:11.304Z,1649965931.304 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-04-14T19:52:11.382Z,1649965931.382 [NAL9602](ERROR): received: +CSQ:0 OK716, 0, 0, 0, 0 OK 2022-04-14T19:56:19.368Z,1649966179.368 [NAL9602](INFO): SBD MO Status=2, MOMSN=32717, MT Status=2, MTMSN=0 2022-04-14T19:56:19.369Z,1649966179.369 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-04-14T19:56:42.399Z,1649966202.399 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-04-14T19:57:07.457Z,1649966227.457 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-04-14T19:57:07.457Z,1649966227.457 [Default:CheckIn:C.Wait] Stopped 2022-04-14T19:57:07.458Z,1649966227.458 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-04-14T19:57:07.458Z,1649966227.458 [Default:CheckIn:D] Running Loop=1 2022-04-14T19:57:07.853Z,1649966227.853 [Default:CheckIn:D] Stopped 2022-04-14T19:57:07.854Z,1649966227.854 [Default:CheckIn:E] Running Loop=1 2022-04-14T19:57:08.274Z,1649966228.274 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 89.368441 min 2022-04-14T19:57:08.274Z,1649966228.274 [Default:CheckIn:E] Stopped 2022-04-14T19:57:08.274Z,1649966228.274 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-04-14T19:57:08.274Z,1649966228.274 [Default:CheckIn] Stopped 2022-04-14T19:57:08.274Z,1649966228.274 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-04-14T19:57:08.275Z,1649966228.275 [Default:CheckIn](INFO): Running loop #17 2022-04-14T19:57:08.275Z,1649966228.275 [Default:CheckIn] Running Loop=17 2022-04-14T19:57:08.275Z,1649966228.275 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-04-14T19:57:08.275Z,1649966228.275 [Default:CheckIn:Read_GPS] Running Loop=1 2022-04-14T19:57:10.269Z,1649966230.269 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,195709.00,A,3648.16601,N,12147.28361,W,0.661,0.00,140422,,,A*79 2022-04-14T19:57:10.271Z,1649966230.271 [NAL9602](INFO): GPS fix at 20220414T195709: (36.802767, -121.788060) 2022-04-14T19:57:10.326Z,1649966230.326 [Default:CheckIn:Read_GPS] Stopped 2022-04-14T19:57:10.326Z,1649966230.326 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-04-14T19:57:17.566Z,1649966237.566 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220414T184927/Courier0039.lzma 2022-04-14T19:57:18.568Z,1649966238.568 [DataOverHttps](INFO): Moved sent file to Logs/20220414T184927/Courier0039.lzma.bak 2022-04-14T19:57:18.568Z,1649966238.568 [DataOverHttps](INFO): SBD MOMSN=16646613 2022-04-14T19:57:34.610Z,1649966254.610 [DataOverHttps](INFO): Sending 203 bytes from file Logs/20220414T184927/Express0040.lzma 2022-04-14T19:57:35.612Z,1649966255.612 [DataOverHttps](INFO): Moved sent file to Logs/20220414T184927/Express0040.lzma.bak 2022-04-14T19:57:35.612Z,1649966255.612 [DataOverHttps](INFO): SBD MOMSN=16646616 2022-04-14T19:57:36.949Z,1649966256.949 [Default:CheckIn:Read_Iridium] Stopped 2022-04-14T19:57:36.949Z,1649966256.949 [Default:CheckIn:C.Wait] Running Loop=1 2022-04-14T19:57:36.949Z,1649966256.949 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-04-14T19:57:42.588Z,1649966262.588 [NAL9602](INFO): Not Powering down - fast GPS 2022-04-14T19:57:49.870Z,1649966269.870 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2022-04-14T19:57:49.870Z,1649966269.870 [DropWeight] Hardware Fault, FailCount= 1 2022-04-14T19:57:49.870Z,1649966269.870 [DropWeight](ERROR): Hardware Fault 2022-04-14T19:57:49.887Z,1649966269.887 [CommandExec](FAULT): Scheduling is paused 2022-04-14T19:57:49.887Z,1649966269.887 [CBIT](INFO): Critical error at 20220414T195749 2022-04-14T19:57:49.890Z,1649966269.890 [CBIT](ERROR): Hardware Fault in component: DropWeight 2022-04-14T19:57:49.890Z,1649966269.890 [CBIT](CRITICAL): Hardware Fault in component: DropWeight 2022-04-14T19:57:50.307Z,1649966270.307 [CBIT](INFO): Critical error at 20220414T195749 2022-04-14T20:00:54.110Z,1649966454.110 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2022-04-14T20:00:54.112Z,1649966454.112 [BPC1](INFO): Received data from all battery sticks. 2022-04-14T20:02:37.538Z,1649966557.538 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-04-14T20:02:37.539Z,1649966557.539 [Default:CheckIn:C.Wait] Stopped 2022-04-14T20:02:37.539Z,1649966557.539 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-04-14T20:02:37.539Z,1649966557.539 [Default:CheckIn:D] Running Loop=1 2022-04-14T20:02:37.944Z,1649966557.944 [Default:CheckIn:D] Stopped 2022-04-14T20:02:37.944Z,1649966557.944 [Default:CheckIn:E] Running Loop=1 2022-04-14T20:02:38.359Z,1649966558.359 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 94.869954 min 2022-04-14T20:02:38.359Z,1649966558.359 [Default:CheckIn:E] Stopped 2022-04-14T20:02:38.360Z,1649966558.360 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-04-14T20:02:38.360Z,1649966558.360 [Default:CheckIn] Stopped 2022-04-14T20:02:38.360Z,1649966558.360 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-04-14T20:02:38.360Z,1649966558.360 [Default:CheckIn](INFO): Running loop #18 2022-04-14T20:02:38.360Z,1649966558.360 [Default:CheckIn] Running Loop=18 2022-04-14T20:02:38.360Z,1649966558.360 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-04-14T20:02:38.360Z,1649966558.360 [Default:CheckIn:Read_GPS] Running Loop=1 2022-04-14T20:02:40.361Z,1649966560.361 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200239.00,A,3648.16481,N,12147.28485,W,0.019,0.00,140422,,,A*7E 2022-04-14T20:02:40.363Z,1649966560.363 [NAL9602](INFO): GPS fix at 20220414T200239: (36.802747, -121.788081) 2022-04-14T20:02:40.428Z,1649966560.428 [Default:CheckIn:Read_GPS] Stopped 2022-04-14T20:02:40.428Z,1649966560.428 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-04-14T20:02:47.962Z,1649966567.962 [DataOverHttps](INFO): Sending 190 bytes from file Logs/20220414T184927/Courier0042.lzma 2022-04-14T20:02:48.964Z,1649966568.964 [DataOverHttps](INFO): Moved sent file to Logs/20220414T184927/Courier0042.lzma.bak 2022-04-14T20:02:48.964Z,1649966568.964 [DataOverHttps](INFO): SBD MOMSN=16646632 2022-04-14T20:03:04.746Z,1649966584.746 [DataOverHttps](INFO): Sending 157 bytes from file Logs/20220414T184927/Express0043.lzma 2022-04-14T20:03:05.748Z,1649966585.748 [DataOverHttps](INFO): Moved sent file to Logs/20220414T184927/Express0043.lzma.bak 2022-04-14T20:03:05.748Z,1649966585.748 [DataOverHttps](INFO): SBD MOMSN=16646637 2022-04-14T20:03:07.039Z,1649966587.039 [Default:CheckIn:Read_Iridium] Stopped 2022-04-14T20:03:07.039Z,1649966587.039 [Default:CheckIn:C.Wait] Running Loop=1 2022-04-14T20:03:07.039Z,1649966587.039 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-04-14T20:03:11.063Z,1649966591.063 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-04-14T20:03:11.146Z,1649966591.146 [NAL9602](ERROR): received: +CSQ:0 OK717, 2, 0, 0, 0 OK 2022-04-14T20:07:42.555Z,1649966862.555 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-04-14T20:08:07.615Z,1649966887.615 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-04-14T20:08:07.615Z,1649966887.615 [Default:CheckIn:C.Wait] Stopped 2022-04-14T20:08:07.615Z,1649966887.615 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-04-14T20:08:07.615Z,1649966887.615 [Default:CheckIn:D] Running Loop=1 2022-04-14T20:08:08.031Z,1649966888.031 [Default:CheckIn:D] Stopped 2022-04-14T20:08:08.031Z,1649966888.031 [Default:CheckIn:E] Running Loop=1 2022-04-14T20:08:08.414Z,1649966888.414 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 100.371403 min 2022-04-14T20:08:08.414Z,1649966888.414 [Default:CheckIn:E] Stopped 2022-04-14T20:08:08.414Z,1649966888.414 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-04-14T20:08:08.415Z,1649966888.415 [Default:CheckIn] Stopped 2022-04-14T20:08:08.415Z,1649966888.415 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-04-14T20:08:08.415Z,1649966888.415 [Default:CheckIn](INFO): Running loop #19 2022-04-14T20:08:08.415Z,1649966888.415 [Default:CheckIn] Running Loop=19 2022-04-14T20:08:08.415Z,1649966888.415 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-04-14T20:08:08.415Z,1649966888.415 [Default:CheckIn:Read_GPS] Running Loop=1 2022-04-14T20:08:10.433Z,1649966890.433 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200809.00,A,3648.16771,N,12147.28142,W,0.078,0.00,140422,,,A*72 2022-04-14T20:08:10.435Z,1649966890.435 [NAL9602](INFO): GPS fix at 20220414T200809: (36.802795, -121.788024) 2022-04-14T20:08:10.445Z,1649966890.445 [Default:CheckIn:Read_GPS] Stopped 2022-04-14T20:08:10.445Z,1649966890.445 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-04-14T20:08:18.370Z,1649966898.370 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220414T184927/Courier0045.lzma 2022-04-14T20:08:19.372Z,1649966899.372 [DataOverHttps](INFO): Moved sent file to Logs/20220414T184927/Courier0045.lzma.bak 2022-04-14T20:08:19.372Z,1649966899.372 [DataOverHttps](INFO): SBD MOMSN=16646653 2022-04-14T20:08:37.927Z,1649966917.927 [DataOverHttps](INFO): Sending 208 bytes from file Logs/20220414T184927/Express0046.lzma 2022-04-14T20:08:38.928Z,1649966918.928 [DataOverHttps](INFO): Moved sent file to Logs/20220414T184927/Express0046.lzma.bak 2022-04-14T20:08:38.928Z,1649966918.928 [DataOverHttps](INFO): SBD MOMSN=16646657 2022-04-14T20:08:40.022Z,1649966920.022 [Default:CheckIn:Read_Iridium] Stopped 2022-04-14T20:08:40.049Z,1649966920.049 [Default:CheckIn:C.Wait] Running Loop=1 2022-04-14T20:08:40.049Z,1649966920.049 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-04-14T20:08:42.803Z,1649966922.803 [NAL9602](INFO): Not Powering down - fast GPS 2022-04-14T20:12:50.091Z,1649967170.091 [CBIT](INFO): Clearing failed state for component DropWeight 2022-04-14T20:12:50.091Z,1649967170.091 [DropWeight] No Fault, FailCount= 1 2022-04-14T20:13:40.584Z,1649967220.584 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-04-14T20:13:40.585Z,1649967220.585 [Default:CheckIn:C.Wait] Stopped 2022-04-14T20:13:40.585Z,1649967220.585 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-04-14T20:13:40.585Z,1649967220.585 [Default:CheckIn:D] Running Loop=1 2022-04-14T20:13:40.999Z,1649967220.999 [Default:CheckIn:D] Stopped 2022-04-14T20:13:40.999Z,1649967220.999 [Default:CheckIn:E] Running Loop=1 2022-04-14T20:13:41.405Z,1649967221.405 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 105.920866 min 2022-04-14T20:13:41.406Z,1649967221.406 [Default:CheckIn:E] Stopped 2022-04-14T20:13:41.406Z,1649967221.406 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-04-14T20:13:41.406Z,1649967221.406 [Default:CheckIn] Stopped 2022-04-14T20:13:41.406Z,1649967221.406 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-04-14T20:13:41.406Z,1649967221.406 [Default:CheckIn](INFO): Running loop #20 2022-04-14T20:13:41.406Z,1649967221.406 [Default:CheckIn] Running Loop=20 2022-04-14T20:13:41.406Z,1649967221.406 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-04-14T20:13:41.406Z,1649967221.406 [Default:CheckIn:Read_GPS] Running Loop=1 2022-04-14T20:13:43.409Z,1649967223.409 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,201342.00,A,3648.16259,N,12147.28227,W,0.039,0.00,140422,,,A*7D 2022-04-14T20:13:43.412Z,1649967223.412 [NAL9602](INFO): GPS fix at 20220414T201342: (36.802710, -121.788038) 2022-04-14T20:13:43.422Z,1649967223.422 [Default:CheckIn:Read_GPS] Stopped 2022-04-14T20:13:43.422Z,1649967223.422 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-04-14T20:13:50.790Z,1649967230.790 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220414T184927/Courier0048.lzma 2022-04-14T20:13:51.792Z,1649967231.792 [DataOverHttps](INFO): Moved sent file to Logs/20220414T184927/Courier0048.lzma.bak 2022-04-14T20:13:51.792Z,1649967231.792 [DataOverHttps](INFO): SBD MOMSN=16646668 2022-04-14T20:14:07.979Z,1649967247.979 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20220414T184927/Express0049.lzma 2022-04-14T20:14:08.980Z,1649967248.980 [DataOverHttps](INFO): Moved sent file to Logs/20220414T184927/Express0049.lzma.bak 2022-04-14T20:14:08.980Z,1649967248.980 [DataOverHttps](INFO): SBD MOMSN=16646671 2022-04-14T20:14:10.081Z,1649967250.081 [Default:CheckIn:Read_Iridium] Stopped 2022-04-14T20:14:10.081Z,1649967250.081 [Default:CheckIn:C.Wait] Running Loop=1 2022-04-14T20:14:10.081Z,1649967250.081 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-04-14T20:18:45.647Z,1649967525.647 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-04-14T20:19:10.715Z,1649967550.715 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-04-14T20:19:10.715Z,1649967550.715 [Default:CheckIn:C.Wait] Stopped 2022-04-14T20:19:10.715Z,1649967550.715 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-04-14T20:19:10.715Z,1649967550.715 [Default:CheckIn:D] Running Loop=1 2022-04-14T20:19:11.165Z,1649967551.165 [Default:CheckIn:D] Stopped 2022-04-14T20:19:11.165Z,1649967551.165 [Default:CheckIn:E] Running Loop=1 2022-04-14T20:19:11.519Z,1649967551.519 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 111.423633 min 2022-04-14T20:19:11.519Z,1649967551.519 [Default:CheckIn:E] Stopped 2022-04-14T20:19:11.519Z,1649967551.519 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-04-14T20:19:11.519Z,1649967551.519 [Default:CheckIn] Stopped 2022-04-14T20:19:11.519Z,1649967551.519 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-04-14T20:19:11.520Z,1649967551.520 [Default:CheckIn](INFO): Running loop #21 2022-04-14T20:19:11.520Z,1649967551.520 [Default:CheckIn] Running Loop=21 2022-04-14T20:19:11.520Z,1649967551.520 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-04-14T20:19:11.520Z,1649967551.520 [Default:CheckIn:Read_GPS] Running Loop=1 2022-04-14T20:19:13.529Z,1649967553.529 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,201912.00,A,3648.16885,N,12147.28181,W,0.097,0.00,140422,,,A*72 2022-04-14T20:19:13.541Z,1649967553.541 [NAL9602](INFO): GPS fix at 20220414T201912: (36.802814, -121.788030) 2022-04-14T20:19:13.551Z,1649967553.551 [Default:CheckIn:Read_GPS] Stopped 2022-04-14T20:19:13.551Z,1649967553.551 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-04-14T20:19:20.802Z,1649967560.802 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220414T184927/Courier0051.lzma 2022-04-14T20:19:21.804Z,1649967561.804 [DataOverHttps](INFO): Moved sent file to Logs/20220414T184927/Courier0051.lzma.bak 2022-04-14T20:19:21.804Z,1649967561.804 [DataOverHttps](INFO): SBD MOMSN=16646683 2022-04-14T20:19:37.682Z,1649967577.682 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20220414T184927/Express0052.lzma 2022-04-14T20:19:38.684Z,1649967578.684 [DataOverHttps](INFO): Moved sent file to Logs/20220414T184927/Express0052.lzma.bak 2022-04-14T20:19:38.684Z,1649967578.684 [DataOverHttps](INFO): SBD MOMSN=16646686 2022-04-14T20:19:40.197Z,1649967580.197 [Default:CheckIn:Read_Iridium] Stopped 2022-04-14T20:19:40.197Z,1649967580.197 [Default:CheckIn:C.Wait] Running Loop=1 2022-04-14T20:19:40.198Z,1649967580.198 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-04-14T20:19:45.438Z,1649967585.438 [NAL9602](INFO): Not Powering down - fast GPS 2022-04-14T20:24:40.892Z,1649967880.892 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-04-14T20:24:40.892Z,1649967880.892 [Default:CheckIn:C.Wait] Stopped 2022-04-14T20:24:40.892Z,1649967880.892 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-04-14T20:24:40.893Z,1649967880.893 [Default:CheckIn:D] Running Loop=1 2022-04-14T20:24:41.304Z,1649967881.304 [Default:CheckIn:D] Stopped 2022-04-14T20:24:41.304Z,1649967881.304 [Default:CheckIn:E] Running Loop=1 2022-04-14T20:24:41.714Z,1649967881.714 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 116.925952 min 2022-04-14T20:24:41.714Z,1649967881.714 [Default:CheckIn:E] Stopped 2022-04-14T20:24:41.715Z,1649967881.715 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-04-14T20:24:41.715Z,1649967881.715 [Default:CheckIn] Stopped 2022-04-14T20:24:41.715Z,1649967881.715 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-04-14T20:24:41.715Z,1649967881.715 [Default:CheckIn](INFO): Running loop #22 2022-04-14T20:24:41.715Z,1649967881.715 [Default:CheckIn] Running Loop=22 2022-04-14T20:24:41.715Z,1649967881.715 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-04-14T20:24:41.715Z,1649967881.715 [Default:CheckIn:Read_GPS] Running Loop=1 2022-04-14T20:24:43.713Z,1649967883.713 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,202442.00,A,3648.16625,N,12147.28115,W,0.058,0.00,140422,,,A*73 2022-04-14T20:24:43.715Z,1649967883.715 [NAL9602](INFO): GPS fix at 20220414T202442: (36.802771, -121.788019) 2022-04-14T20:24:43.725Z,1649967883.725 [Default:CheckIn:Read_GPS] Stopped 2022-04-14T20:24:43.725Z,1649967883.725 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-04-14T20:24:51.511Z,1649967891.511 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220414T184927/Courier0054.lzma 2022-04-14T20:24:52.512Z,1649967892.512 [DataOverHttps](INFO): Moved sent file to Logs/20220414T184927/Courier0054.lzma.bak 2022-04-14T20:24:52.512Z,1649967892.512 [DataOverHttps](INFO): SBD MOMSN=16646701 2022-04-14T20:25:08.346Z,1649967908.346 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20220414T184927/Express0055.lzma 2022-04-14T20:25:09.350Z,1649967909.350 [DataOverHttps](INFO): Moved sent file to Logs/20220414T184927/Express0055.lzma.bak 2022-04-14T20:25:09.351Z,1649967909.351 [DataOverHttps](INFO): SBD MOMSN=16646704 2022-04-14T20:25:10.789Z,1649967910.789 [Default:CheckIn:Read_Iridium] Stopped 2022-04-14T20:25:10.789Z,1649967910.789 [Default:CheckIn:C.Wait] Running Loop=1 2022-04-14T20:25:10.789Z,1649967910.789 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-04-14T20:25:14.411Z,1649967914.411 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-04-14T20:25:14.494Z,1649967914.494 [NAL9602](ERROR): received: +CSQ:0 OK717, 2, 0, 0, 0 OK 2022-04-14T20:29:46.393Z,1649968186.393 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-04-14T20:30:11.459Z,1649968211.459 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-04-14T20:30:11.459Z,1649968211.459 [Default:CheckIn:C.Wait] Stopped 2022-04-14T20:30:11.459Z,1649968211.459 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-04-14T20:30:11.459Z,1649968211.459 [Default:CheckIn:D] Running Loop=1 2022-04-14T20:30:11.856Z,1649968211.856 [Default:CheckIn:D] Stopped 2022-04-14T20:30:11.857Z,1649968211.857 [Default:CheckIn:E] Running Loop=1 2022-04-14T20:30:12.259Z,1649968212.259 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 122.435156 min 2022-04-14T20:30:12.259Z,1649968212.259 [Default:CheckIn:E] Stopped 2022-04-14T20:30:12.259Z,1649968212.259 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-04-14T20:30:12.259Z,1649968212.259 [Default:CheckIn] Stopped 2022-04-14T20:30:12.259Z,1649968212.259 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-04-14T20:30:12.260Z,1649968212.260 [Default:CheckIn](INFO): Running loop #23 2022-04-14T20:30:12.260Z,1649968212.260 [Default:CheckIn] Running Loop=23 2022-04-14T20:30:12.260Z,1649968212.260 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-04-14T20:30:12.260Z,1649968212.260 [Default:CheckIn:Read_GPS] Running Loop=1 2022-04-14T20:30:14.279Z,1649968214.279 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,203013.00,A,3648.16749,N,12147.27973,W,0.428,0.00,140422,,,A*7D 2022-04-14T20:30:14.281Z,1649968214.281 [NAL9602](INFO): GPS fix at 20220414T203013: (36.802791, -121.787995) 2022-04-14T20:30:14.291Z,1649968214.291 [Default:CheckIn:Read_GPS] Stopped 2022-04-14T20:30:14.291Z,1649968214.291 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-04-14T20:30:24.424Z,1649968224.424 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220414T184927/Courier0057.lzma 2022-04-14T20:30:25.420Z,1649968225.420 [DataOverHttps](INFO): Moved sent file to Logs/20220414T184927/Courier0057.lzma.bak 2022-04-14T20:30:25.421Z,1649968225.421 [DataOverHttps](INFO): SBD MOMSN=16646714 2022-04-14T20:30:45.110Z,1649968245.110 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20220414T184927/Express0058.lzma 2022-04-14T20:30:46.108Z,1649968246.108 [DataOverHttps](INFO): Moved sent file to Logs/20220414T184927/Express0058.lzma.bak 2022-04-14T20:30:46.108Z,1649968246.108 [DataOverHttps](INFO): SBD MOMSN=16646717 2022-04-14T20:30:46.333Z,1649968246.333 [NAL9602](INFO): Not Powering down - fast GPS 2022-04-14T20:30:47.560Z,1649968247.560 [Default:CheckIn:Read_Iridium] Stopped 2022-04-14T20:30:47.561Z,1649968247.561 [Default:CheckIn:C.Wait] Running Loop=1 2022-04-14T20:30:47.561Z,1649968247.561 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-04-14T20:35:48.276Z,1649968548.276 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-04-14T20:35:48.276Z,1649968548.276 [Default:CheckIn:C.Wait] Stopped 2022-04-14T20:35:48.276Z,1649968548.276 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-04-14T20:35:48.277Z,1649968548.277 [Default:CheckIn:D] Running Loop=1 2022-04-14T20:35:48.681Z,1649968548.681 [Default:CheckIn:D] Stopped 2022-04-14T20:35:48.681Z,1649968548.681 [Default:CheckIn:E] Running Loop=1 2022-04-14T20:35:49.095Z,1649968549.095 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 128.048901 min 2022-04-14T20:35:49.095Z,1649968549.095 [Default:CheckIn:E] Stopped 2022-04-14T20:35:49.095Z,1649968549.095 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-04-14T20:35:49.095Z,1649968549.095 [Default:CheckIn] Stopped 2022-04-14T20:35:49.095Z,1649968549.095 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-04-14T20:35:49.096Z,1649968549.096 [Default:CheckIn](INFO): Running loop #24 2022-04-14T20:35:49.096Z,1649968549.096 [Default:CheckIn] Running Loop=24 2022-04-14T20:35:49.096Z,1649968549.096 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-04-14T20:35:49.096Z,1649968549.096 [Default:CheckIn:Read_GPS] Running Loop=1 2022-04-14T20:35:51.097Z,1649968551.097 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,203550.00,A,3648.16561,N,12147.28793,W,0.194,0.00,140422,,,A*7A 2022-04-14T20:35:51.099Z,1649968551.099 [NAL9602](INFO): GPS fix at 20220414T203550: (36.802760, -121.788132) 2022-04-14T20:35:51.111Z,1649968551.111 [Default:CheckIn:Read_GPS] Stopped 2022-04-14T20:35:51.111Z,1649968551.111 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-04-14T20:35:57.793Z,1649968557.793 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220414T184927/Courier0060.lzma 2022-04-14T20:35:58.792Z,1649968558.792 [DataOverHttps](INFO): Moved sent file to Logs/20220414T184927/Courier0060.lzma.bak 2022-04-14T20:35:58.792Z,1649968558.792 [DataOverHttps](INFO): SBD MOMSN=16646731 2022-04-14T20:36:14.522Z,1649968574.522 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20220414T184927/Express0061.lzma 2022-04-14T20:36:15.524Z,1649968575.524 [DataOverHttps](INFO): Moved sent file to Logs/20220414T184927/Express0061.lzma.bak 2022-04-14T20:36:15.524Z,1649968575.524 [DataOverHttps](INFO): SBD MOMSN=16646734 2022-04-14T20:36:17.027Z,1649968577.027 [Default:CheckIn:Read_Iridium] Stopped 2022-04-14T20:36:17.027Z,1649968577.027 [Default:CheckIn:C.Wait] Running Loop=1 2022-04-14T20:36:17.027Z,1649968577.027 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-04-14T20:36:21.857Z,1649968581.857 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-04-14T20:36:21.938Z,1649968581.938 [NAL9602](ERROR): received: +CSQ:0 OK717, 2, 0, 0, 0 OK 2022-04-14T20:38:04.495Z,1649968684.495 [NAL9602](INFO): SBD MO Status=2, MOMSN=32717, MT Status=2, MTMSN=0 2022-04-14T20:38:04.495Z,1649968684.495 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-04-14T20:38:17.431Z,1649968697.431 [NAL9602](INFO): SBD MO Status=2, MOMSN=32717, MT Status=2, MTMSN=0 2022-04-14T20:38:17.431Z,1649968697.431 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-04-14T20:39:39.116Z,1649968779.116 [NAL9602](INFO): SBD MO Status=2, MOMSN=32717, MT Status=2, MTMSN=0 2022-04-14T20:39:39.117Z,1649968779.117 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-04-14T20:40:03.351Z,1649968803.351 [NAL9602](INFO): SBD MO Status=2, MOMSN=32717, MT Status=2, MTMSN=0 2022-04-14T20:40:03.351Z,1649968803.351 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-04-14T20:40:53.919Z,1649968853.919 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-04-14T20:41:17.769Z,1649968877.769 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-04-14T20:41:17.770Z,1649968877.770 [Default:CheckIn:C.Wait] Stopped 2022-04-14T20:41:17.770Z,1649968877.770 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-04-14T20:41:17.770Z,1649968877.770 [Default:CheckIn:D] Running Loop=1 2022-04-14T20:41:18.162Z,1649968878.162 [Default:CheckIn:D] Stopped 2022-04-14T20:41:18.162Z,1649968878.162 [Default:CheckIn:E] Running Loop=1 2022-04-14T20:41:18.573Z,1649968878.573 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 133.540251 min 2022-04-14T20:41:18.573Z,1649968878.573 [Default:CheckIn:E] Stopped 2022-04-14T20:41:18.573Z,1649968878.573 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-04-14T20:41:18.573Z,1649968878.573 [Default:CheckIn] Stopped 2022-04-14T20:41:18.574Z,1649968878.574 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-04-14T20:41:18.574Z,1649968878.574 [Default:CheckIn](INFO): Running loop #25 2022-04-14T20:41:18.574Z,1649968878.574 [Default:CheckIn] Running Loop=25 2022-04-14T20:41:18.574Z,1649968878.574 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-04-14T20:41:18.574Z,1649968878.574 [Default:CheckIn:Read_GPS] Running Loop=1 2022-04-14T20:41:20.581Z,1649968880.581 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,204119.00,A,3648.16997,N,12147.27532,W,0.428,0.00,140422,,,A*75 2022-04-14T20:41:20.583Z,1649968880.583 [NAL9602](INFO): GPS fix at 20220414T204119: (36.802833, -121.787922) 2022-04-14T20:41:20.593Z,1649968880.593 [Default:CheckIn:Read_GPS] Stopped 2022-04-14T20:41:20.593Z,1649968880.593 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-04-14T20:41:27.930Z,1649968887.930 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220414T184927/Courier0063.lzma 2022-04-14T20:41:28.932Z,1649968888.932 [DataOverHttps](INFO): Moved sent file to Logs/20220414T184927/Courier0063.lzma.bak 2022-04-14T20:41:28.932Z,1649968888.932 [DataOverHttps](INFO): SBD MOMSN=16646744 2022-04-14T20:41:44.782Z,1649968904.782 [DataOverHttps](INFO): Sending 219 bytes from file Logs/20220414T184927/Express0064.lzma 2022-04-14T20:41:45.784Z,1649968905.784 [DataOverHttps](INFO): Moved sent file to Logs/20220414T184927/Express0064.lzma.bak 2022-04-14T20:41:45.784Z,1649968905.784 [DataOverHttps](INFO): SBD MOMSN=16646747 2022-04-14T20:41:47.254Z,1649968907.254 [Default:CheckIn:Read_Iridium] Stopped 2022-04-14T20:41:47.254Z,1649968907.254 [Default:CheckIn:C.Wait] Running Loop=1 2022-04-14T20:41:47.254Z,1649968907.254 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-04-14T20:41:52.492Z,1649968912.492 [NAL9602](INFO): Not Powering down - fast GPS 2022-04-14T20:42:51.559Z,1649968971.559 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2022-04-14T20:42:51.559Z,1649968971.559 [DropWeight] Hardware Fault, FailCount= 1 2022-04-14T20:42:51.559Z,1649968971.559 [DropWeight](ERROR): Hardware Fault 2022-04-14T20:42:51.663Z,1649968971.663 [CBIT](INFO): Critical error at 20220414T204251 2022-04-14T20:42:51.665Z,1649968971.665 [CBIT](ERROR): Hardware Fault in component: DropWeight 2022-04-14T20:42:51.665Z,1649968971.665 [CBIT](CRITICAL): Hardware Fault in component: DropWeight 2022-04-14T20:42:52.018Z,1649968972.018 [CBIT](INFO): Critical error at 20220414T204251 2022-04-14T20:46:47.996Z,1649969207.996 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-04-14T20:46:47.997Z,1649969207.997 [Default:CheckIn:C.Wait] Stopped 2022-04-14T20:46:47.997Z,1649969207.997 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-04-14T20:46:47.997Z,1649969207.997 [Default:CheckIn:D] Running Loop=1 2022-04-14T20:46:48.399Z,1649969208.399 [Default:CheckIn:D] Stopped 2022-04-14T20:46:48.399Z,1649969208.399 [Default:CheckIn:E] Running Loop=1 2022-04-14T20:46:48.803Z,1649969208.803 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 139.044189 min 2022-04-14T20:46:48.803Z,1649969208.803 [Default:CheckIn:E] Stopped 2022-04-14T20:46:48.803Z,1649969208.803 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-04-14T20:46:48.803Z,1649969208.803 [Default:CheckIn] Stopped 2022-04-14T20:46:48.803Z,1649969208.803 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-04-14T20:46:48.803Z,1649969208.803 [Default:CheckIn](INFO): Running loop #26 2022-04-14T20:46:48.803Z,1649969208.803 [Default:CheckIn] Running Loop=26 2022-04-14T20:46:48.803Z,1649969208.803 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-04-14T20:46:48.804Z,1649969208.804 [Default:CheckIn:Read_GPS] Running Loop=1 2022-04-14T20:46:50.815Z,1649969210.815 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,204650.00,A,3648.16994,N,12147.28617,W,0.233,0.00,140422,,,A*7B 2022-04-14T20:46:50.817Z,1649969210.817 [NAL9602](INFO): GPS fix at 20220414T204650: (36.802832, -121.788103) 2022-04-14T20:46:50.828Z,1649969210.828 [Default:CheckIn:Read_GPS] Stopped 2022-04-14T20:46:50.828Z,1649969210.828 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-04-14T20:46:57.695Z,1649969217.695 [DataOverHttps](INFO): Sending 148 bytes from file Logs/20220414T184927/Courier0066.lzma 2022-04-14T20:46:58.696Z,1649969218.696 [DataOverHttps](INFO): Moved sent file to Logs/20220414T184927/Courier0066.lzma.bak 2022-04-14T20:46:58.696Z,1649969218.696 [DataOverHttps](INFO): SBD MOMSN=16646762 2022-04-14T20:47:14.562Z,1649969234.562 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20220414T184927/Express0067.lzma 2022-04-14T20:47:15.564Z,1649969235.564 [DataOverHttps](INFO): Moved sent file to Logs/20220414T184927/Express0067.lzma.bak 2022-04-14T20:47:15.564Z,1649969235.564 [DataOverHttps](INFO): SBD MOMSN=16646767 2022-04-14T20:47:16.681Z,1649969236.681 [Default:CheckIn:Read_Iridium] Stopped 2022-04-14T20:47:16.681Z,1649969236.681 [Default:CheckIn:C.Wait] Running Loop=1 2022-04-14T20:47:16.681Z,1649969236.681 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-04-14T20:47:21.511Z,1649969241.511 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-04-14T20:47:21.594Z,1649969241.594 [NAL9602](ERROR): received: +CSQ:0 OK717, 2, 0, 0, 0 OK 2022-04-14T20:48:05.950Z,1649969285.950 [NAL9602](INFO): SBD MO Status=2, MOMSN=32717, MT Status=2, MTMSN=0 2022-04-14T20:48:05.951Z,1649969285.951 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-04-14T20:48:34.328Z,1649969314.328 [NAL9602](INFO): SBD MO Status=2, MOMSN=32717, MT Status=2, MTMSN=0 2022-04-14T20:48:34.328Z,1649969314.328 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-04-14T20:48:51.296Z,1649969331.296 [NAL9602](INFO): SBD MO Status=2, MOMSN=32717, MT Status=2, MTMSN=0 2022-04-14T20:48:51.296Z,1649969331.296 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-04-14T20:51:53.589Z,1649969513.589 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-04-14T20:52:17.481Z,1649969537.481 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-04-14T20:52:17.481Z,1649969537.481 [Default:CheckIn:C.Wait] Stopped 2022-04-14T20:52:17.481Z,1649969537.481 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-04-14T20:52:17.482Z,1649969537.482 [Default:CheckIn:D] Running Loop=1 2022-04-14T20:52:17.838Z,1649969537.838 [Default:CheckIn:D] Stopped 2022-04-14T20:52:17.839Z,1649969537.839 [Default:CheckIn:E] Running Loop=1 2022-04-14T20:52:18.237Z,1649969538.237 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 144.534863 min 2022-04-14T20:52:18.237Z,1649969538.237 [Default:CheckIn:E] Stopped 2022-04-14T20:52:18.237Z,1649969538.237 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-04-14T20:52:18.237Z,1649969538.237 [Default:CheckIn] Stopped 2022-04-14T20:52:18.237Z,1649969538.237 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-04-14T20:52:18.237Z,1649969538.237 [Default:CheckIn](INFO): Running loop #27 2022-04-14T20:52:18.237Z,1649969538.237 [Default:CheckIn] Running Loop=27 2022-04-14T20:52:18.237Z,1649969538.237 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-04-14T20:52:18.238Z,1649969538.238 [Default:CheckIn:Read_GPS] Running Loop=1 2022-04-14T20:52:20.253Z,1649969540.253 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,205219.00,A,3648.17294,N,12147.28063,W,0.136,346.98,140422,,,A*7A 2022-04-14T20:52:20.255Z,1649969540.255 [NAL9602](INFO): GPS fix at 20220414T205219: (36.802882, -121.788010) 2022-04-14T20:52:20.265Z,1649969540.265 [Default:CheckIn:Read_GPS] Stopped 2022-04-14T20:52:20.265Z,1649969540.265 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-04-14T20:52:30.274Z,1649969550.274 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220414T184927/Courier0069.lzma 2022-04-14T20:52:31.276Z,1649969551.276 [DataOverHttps](INFO): Moved sent file to Logs/20220414T184927/Courier0069.lzma.bak 2022-04-14T20:52:31.276Z,1649969551.276 [DataOverHttps](INFO): SBD MOMSN=16646778 2022-04-14T20:52:49.834Z,1649969569.834 [DataOverHttps](INFO): Sending 205 bytes from file Logs/20220414T184927/Express0070.lzma 2022-04-14T20:52:50.836Z,1649969570.836 [DataOverHttps](INFO): Moved sent file to Logs/20220414T184927/Express0070.lzma.bak 2022-04-14T20:52:50.836Z,1649969570.836 [DataOverHttps](INFO): SBD MOMSN=16646781 2022-04-14T20:52:51.940Z,1649969571.940 [Default:CheckIn:Read_Iridium] Stopped 2022-04-14T20:52:51.941Z,1649969571.941 [Default:CheckIn:C.Wait] Running Loop=1 2022-04-14T20:52:51.941Z,1649969571.941 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-04-14T20:52:52.308Z,1649969572.308 [NAL9602](INFO): Not Powering down - fast GPS 2022-04-14T20:57:51.823Z,1649969871.823 [CBIT](INFO): Clearing failed state for component DropWeight 2022-04-14T20:57:51.823Z,1649969871.823 [DropWeight] No Fault, FailCount= 1 2022-04-14T20:57:52.624Z,1649969872.624 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-04-14T20:57:52.625Z,1649969872.625 [Default:CheckIn:C.Wait] Stopped 2022-04-14T20:57:52.625Z,1649969872.625 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-04-14T20:57:52.625Z,1649969872.625 [Default:CheckIn:D] Running Loop=1 2022-04-14T20:57:53.035Z,1649969873.035 [Default:CheckIn:D] Stopped 2022-04-14T20:57:53.035Z,1649969873.035 [Default:CheckIn:E] Running Loop=1 2022-04-14T20:57:53.439Z,1649969873.439 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 150.121468 min 2022-04-14T20:57:53.439Z,1649969873.439 [Default:CheckIn:E] Stopped 2022-04-14T20:57:53.439Z,1649969873.439 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-04-14T20:57:53.439Z,1649969873.439 [Default:CheckIn] Stopped 2022-04-14T20:57:53.439Z,1649969873.439 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-04-14T20:57:53.439Z,1649969873.439 [Default:CheckIn](INFO): Running loop #28 2022-04-14T20:57:53.439Z,1649969873.439 [Default:CheckIn] Running Loop=28 2022-04-14T20:57:53.439Z,1649969873.439 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-04-14T20:57:53.440Z,1649969873.440 [Default:CheckIn:Read_GPS] Running Loop=1 2022-04-14T20:57:55.449Z,1649969875.449 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,205754.00,A,3648.16924,N,12147.28271,W,0.194,346.98,140422,,,A*7E 2022-04-14T20:57:55.451Z,1649969875.451 [NAL9602](INFO): GPS fix at 20220414T205754: (36.802821, -121.788045) 2022-04-14T20:57:55.461Z,1649969875.461 [Default:CheckIn:Read_GPS] Stopped 2022-04-14T20:57:55.462Z,1649969875.462 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-04-14T20:58:03.198Z,1649969883.198 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220414T184927/Courier0072.lzma 2022-04-14T20:58:04.200Z,1649969884.200 [DataOverHttps](INFO): Moved sent file to Logs/20220414T184927/Courier0072.lzma.bak 2022-04-14T20:58:04.200Z,1649969884.200 [DataOverHttps](INFO): SBD MOMSN=16646789 2022-04-14T20:58:21.815Z,1649969901.815 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20220414T184927/Express0073.lzma 2022-04-14T20:58:22.816Z,1649969902.816 [DataOverHttps](INFO): Moved sent file to Logs/20220414T184927/Express0073.lzma.bak 2022-04-14T20:58:22.816Z,1649969902.816 [DataOverHttps](INFO): SBD MOMSN=16646795 2022-04-14T20:58:24.171Z,1649969904.171 [Default:CheckIn:Read_Iridium] Stopped 2022-04-14T20:58:24.171Z,1649969904.171 [Default:CheckIn:C.Wait] Running Loop=1 2022-04-14T20:58:24.171Z,1649969904.171 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-04-14T20:58:26.191Z,1649969906.191 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-04-14T20:58:26.274Z,1649969906.274 [NAL9602](ERROR): received: +CSQ:0 OK717, 2, 0, 0, 0 OK 2022-04-14T21:02:28.605Z,1649970148.605 [BPC1](ERROR): BPC1A: No match for serial number 1717 in BPC1A's battery stick inventory (sticks 1-32 in onboard configuration file). 2022-04-14T21:02:57.699Z,1649970177.699 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-04-14T21:03:24.794Z,1649970204.794 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-04-14T21:03:24.794Z,1649970204.794 [Default:CheckIn:C.Wait] Stopped 2022-04-14T21:03:24.794Z,1649970204.794 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-04-14T21:03:24.795Z,1649970204.795 [Default:CheckIn:D] Running Loop=1 2022-04-14T21:03:25.171Z,1649970205.171 [Default:CheckIn:D] Stopped 2022-04-14T21:03:25.171Z,1649970205.171 [Default:CheckIn:E] Running Loop=1 2022-04-14T21:03:25.585Z,1649970205.585 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 155.657064 min 2022-04-14T21:03:25.585Z,1649970205.585 [Default:CheckIn:E] Stopped 2022-04-14T21:03:25.585Z,1649970205.585 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-04-14T21:03:25.585Z,1649970205.585 [Default:CheckIn] Stopped 2022-04-14T21:03:25.585Z,1649970205.585 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-04-14T21:03:25.585Z,1649970205.585 [Default:CheckIn](INFO): Running loop #29 2022-04-14T21:03:25.585Z,1649970205.585 [Default:CheckIn] Running Loop=29 2022-04-14T21:03:25.586Z,1649970205.586 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-04-14T21:03:25.586Z,1649970205.586 [Default:CheckIn:Read_GPS] Running Loop=1 2022-04-14T21:03:27.603Z,1649970207.603 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,210326.00,A,3648.16984,N,12147.27006,W,0.097,346.98,140422,,,A*7E 2022-04-14T21:03:27.605Z,1649970207.605 [NAL9602](INFO): GPS fix at 20220414T210326: (36.802831, -121.787834) 2022-04-14T21:03:27.616Z,1649970207.616 [Default:CheckIn:Read_GPS] Stopped 2022-04-14T21:03:27.616Z,1649970207.616 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-04-14T21:03:35.334Z,1649970215.334 [DataOverHttps](INFO): Sending 75 bytes from file Logs/20220414T184927/Courier0075.lzma 2022-04-14T21:03:36.336Z,1649970216.336 [DataOverHttps](INFO): Moved sent file to Logs/20220414T184927/Courier0075.lzma.bak 2022-04-14T21:03:36.337Z,1649970216.337 [DataOverHttps](INFO): SBD MOMSN=16646798 2022-04-14T21:03:59.503Z,1649970239.503 [NAL9602](INFO): Not Powering down - fast GPS 2022-04-14T21:04:13.530Z,1649970253.530 [DataOverHttps](INFO): Sending 219 bytes from file Logs/20220414T184927/Express0076.lzma 2022-04-14T21:04:14.532Z,1649970254.532 [DataOverHttps](INFO): Moved sent file to Logs/20220414T184927/Express0076.lzma.bak 2022-04-14T21:04:14.532Z,1649970254.532 [DataOverHttps](INFO): SBD MOMSN=16646801 2022-04-14T21:04:15.690Z,1649970255.690 [Default:CheckIn:Read_Iridium] Stopped 2022-04-14T21:04:15.691Z,1649970255.691 [Default:CheckIn:C.Wait] Running Loop=1 2022-04-14T21:04:15.691Z,1649970255.691 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-04-14T21:04:41.573Z,1649970281.573 [BPC1](ERROR): BPC1A: No match for serial number 1717 in BPC1A's battery stick inventory (sticks 1-32 in onboard configuration file). 2022-04-14T21:08:19.328Z,1649970499.328 [BPC1](ERROR): BPC1B: No match for serial number 1717 in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file). 2022-04-14T21:08:31.452Z,1649970511.452 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2022-04-14T21:08:31.454Z,1649970511.454 [BPC1](INFO): Received data from all battery sticks. 2022-04-14T21:09:08.427Z,1649970548.427 [CommandExec](IMPORTANT): got command quit 2022-04-14T21:09:09.430Z,1649970549.430 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread. 2022-04-14T21:09:09.430Z,1649970549.430 [CommandExec](INFO): Uninitializing the command executive. 2022-04-14T21:09:09.430Z,1649970549.430 [CommandExec](INFO): Uninitializing the command scheduler. 2022-04-14T21:09:09.431Z,1649970549.431 [CommandExec ThreadHandler](INFO): Thread cancelled. 2022-04-14T21:09:09.514Z,1649970549.514 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2022-04-14T21:09:09.514Z,1649970549.514 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2022-04-14T21:09:09.514Z,1649970549.514 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2022-04-14T21:09:09.515Z,1649970549.515 [NavChartDb](INFO): Join timeout helper Thread ID is 5974 2022-04-14T21:09:09.558Z,1649970549.558 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2022-04-14T21:09:09.559Z,1649970549.559 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2022-04-14T21:09:09.578Z,1649970549.578 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2022-04-14T21:09:09.578Z,1649970549.578 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2022-04-14T21:09:09.579Z,1649970549.579 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 5975 2022-04-14T21:09:09.882Z,1649970549.882 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2022-04-14T21:09:09.882Z,1649970549.882 [WetLabsBB2FL](INFO): Powering down 2022-04-14T21:09:09.883Z,1649970549.883 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2022-04-14T21:09:09.890Z,1649970549.890 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2022-04-14T21:09:09.890Z,1649970549.890 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2022-04-14T21:09:09.891Z,1649970549.891 [CTD_Seabird](INFO): Join timeout helper Thread ID is 5976 2022-04-14T21:09:10.114Z,1649970550.114 [CTD_Seabird](INFO): Powering down 2022-04-14T21:09:10.126Z,1649970550.126 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread. 2022-04-14T21:09:10.126Z,1649970550.126 [CTD_Seabird](INFO): Powering down 2022-04-14T21:09:10.138Z,1649970550.138 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2022-04-14T21:09:10.138Z,1649970550.138 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2022-04-14T21:09:10.138Z,1649970550.138 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2022-04-14T21:09:10.139Z,1649970550.139 [Radio_Surface](INFO): Join timeout helper Thread ID is 5977 2022-04-14T21:09:10.434Z,1649970550.434 [Radio_Surface](INFO): Powering down 2022-04-14T21:09:10.435Z,1649970550.435 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2022-04-14T21:09:10.435Z,1649970550.435 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2022-04-14T21:09:10.460Z,1649970550.460 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler 2022-04-14T21:09:10.460Z,1649970550.460 [Onboard ThreadHandler](INFO): Thread cancelled. 2022-04-14T21:09:10.461Z,1649970550.461 [Onboard](INFO): Join timeout helper Thread ID is 5978 2022-04-14T21:09:11.270Z,1649970551.270 [DataOverHttps](INFO): Radio surface powered OFF, will not connect. 2022-04-14T21:09:13.846Z,1649970553.846 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread. 2022-04-14T21:09:13.847Z,1649970553.847 [Onboard ThreadHandler](INFO): Thread cancelled. 2022-04-14T21:09:13.851Z,1649970553.851 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2022-04-14T21:09:13.851Z,1649970553.851 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2022-04-14T21:09:13.851Z,1649970553.851 [DataOverHttps](INFO): Join timeout helper Thread ID is 5979 2022-04-14T21:09:14.282Z,1649970554.282 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2022-04-14T21:09:14.283Z,1649970554.283 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2022-04-14T21:09:14.295Z,1649970554.295 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2022-04-14T21:09:14.295Z,1649970554.295 [logger ThreadHandler](INFO): Thread cancelled. 2022-04-14T21:09:14.295Z,1649970554.295 [logger](INFO): Join timeout helper Thread ID is 5980 2022-04-14T21:09:14.322Z,1649970554.322 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2022-04-14T21:09:14.322Z,1649970554.322 [logger ThreadHandler](INFO): Thread cancelled. 2022-04-14T21:09:14.339Z,1649970554.339 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2022-04-14T21:09:14.339Z,1649970554.339 [CommandLine ThreadHandler](INFO): Thread cancelled. 2022-04-14T21:09:14.339Z,1649970554.339 [CommandLine](INFO): Join timeout helper Thread ID is 5981 2022-04-14T21:09:14.342Z,1649970554.342 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2022-04-14T21:09:14.343Z,1649970554.342 [CommandLine ThreadHandler](INFO): Thread cancelled. 2022-04-14T21:09:14.359Z,1649970554.359 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler 2022-04-14T21:09:14.359Z,1649970554.359 [CommandExec ThreadHandler](INFO): Thread cancelled. 2022-04-14T21:09:14.359Z,1649970554.359 [CommandExec](INFO): Join timeout helper Thread ID is 5982 2022-04-14T21:09:14.360Z,1649970554.360 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2022-04-14T21:09:14.361Z,1649970554.361 [controlThread ThreadHandler](INFO): Thread cancelled. 2022-04-14T21:09:14.361Z,1649970554.361 [controlThread](INFO): Join timeout helper Thread ID is 5983 2022-04-14T21:09:14.658Z,1649970554.658 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2022-04-14T21:09:14.658Z,1649970554.658 [controlThread](DEBUG): Uninitializing ControlThread 2022-04-14T21:09:14.659Z,1649970554.659 [AHRS_M2](INFO): Powering down 2022-04-14T21:09:14.731Z,1649970554.731 [NAL9602](INFO): Powering down 2022-04-14T21:09:14.733Z,1649970554.733 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2022-04-14T21:09:14.734Z,1649970554.734 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2022-04-14T21:09:14.735Z,1649970554.735 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2022-04-14T21:09:14.735Z,1649970554.735 [MissionManager](INFO): Uninitializing Mission Default 2022-04-14T21:09:14.735Z,1649970554.735 [Default] Stopped 2022-04-14T21:09:14.735Z,1649970554.735 [Default](DEBUG): Aggregate::uninitialize Default 2022-04-14T21:09:14.735Z,1649970554.735 [Default:B.GoToSurface] Stopped 2022-04-14T21:09:14.736Z,1649970554.736 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2022-04-14T21:09:14.736Z,1649970554.736 [Default:CheckIn] Stopped 2022-04-14T21:09:14.736Z,1649970554.736 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-04-14T21:09:14.736Z,1649970554.736 [Default:CheckIn:C.Wait] Stopped 2022-04-14T21:09:14.736Z,1649970554.736 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-04-14T21:09:14.739Z,1649970554.739 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2022-04-14T21:09:14.739Z,1649970554.739 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2022-04-14T21:09:14.739Z,1649970554.739 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2022-04-14T21:09:14.740Z,1649970554.740 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2022-04-14T21:09:14.740Z,1649970554.740 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2022-04-14T21:09:14.740Z,1649970554.740 [BuoyancyServo](INFO): Powering down 2022-04-14T21:09:14.754Z,1649970554.754 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2022-04-14T21:09:14.754Z,1649970554.754 [ElevatorServo](INFO): Powering down 2022-04-14T21:09:14.755Z,1649970554.755 [MassServo](DEBUG): Uninitialize Mass Servo. 2022-04-14T21:09:14.755Z,1649970554.755 [MassServo](INFO): Powering down 2022-04-14T21:09:14.756Z,1649970554.756 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2022-04-14T21:09:14.756Z,1649970554.756 [RudderServo](INFO): Powering down 2022-04-14T21:09:14.757Z,1649970554.757 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2022-04-14T21:09:14.757Z,1649970554.757 [ThrusterServo](INFO): Powering down 2022-04-14T21:09:14.758Z,1649970554.758 [SBIT](DEBUG): Uninitialize SBIT Component. 2022-04-14T21:09:14.758Z,1649970554.758 [IBIT](DEBUG): Uninitialize IBIT Component. 2022-04-14T21:09:14.759Z,1649970554.759 [CBIT](DEBUG): Uninitialize CBIT Component. 2022-04-14T21:09:14.759Z,1649970554.759 [CBIT](DEBUG): Powering off loads. 2022-04-14T21:09:14.770Z,1649970554.770 [CBIT](DEBUG): Disabling WDT. 2022-04-14T21:09:14.782Z,1649970554.782 [CBIT](DEBUG): Opening all GF detection circuits. 2022-04-14T21:09:14.783Z,1649970554.783 [controlThread ThreadHandler](INFO): Thread cancelled. 2022-04-14T21:09:14.839Z,1649970554.839 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2022-04-14T21:09:14.842Z,1649970554.842 [Onboard ThreadHandler](INFO): Thread cancelled. 2022-04-14T21:09:14.848Z,1649970554.848 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2022-04-14T21:09:14.917Z,1649970554.917 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2022-04-14T21:09:14.921Z,1649970554.921 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2022-04-14T21:09:14.960Z,1649970554.960 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2022-04-14T21:09:15.060Z,1649970555.060 [logger ThreadHandler](INFO): Thread cancelled.