2022-05-31T16:17:56.472Z,1654013876.472 [DataOverHttps](INFO): Received command: restart logs 2022-05-31T16:17:56.485Z,1654013876.485 [CommandExec](IMPORTANT): got command restart logs 2022-05-31T16:17:57.905Z,1654013877.905 [DataOverHttps](INFO): Moved sent file to Logs/20220531T014417/Courier0085.lzma.bak 2022-05-31T16:17:57.905Z,1654013877.905 [DataOverHttps](INFO): SBD MOMSN=16845411 2022-05-31T16:18:40.273Z,1654013920.273 [NAL9602](INFO): SBD MO Status=2, MOMSN=7842, MT Status=2, MTMSN=0 2022-05-31T16:18:40.273Z,1654013920.273 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-05-31T16:18:44.679Z,1654013924.679 [DataOverHttps](INFO): Sending 161 bytes from file Logs/20220531T014417/Express0086.lzma 2022-05-31T16:18:45.682Z,1654013925.682 [DataOverHttps](INFO): Moved sent file to Logs/20220531T014417/Express0086.lzma.bak 2022-05-31T16:18:45.682Z,1654013925.682 [DataOverHttps](INFO): SBD MOMSN=16845415 2022-05-31T16:18:59.246Z,1654013939.246 [NAL9602](INFO): SBD MO Status=0, MOMSN=7842, MT Status=0, MTMSN=0 2022-05-31T16:18:59.246Z,1654013939.246 [NAL9602](INFO): No messages in MT queue 2022-05-31T16:19:01.711Z,1654013941.711 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20220531T014417/Express0089.lzma 2022-05-31T16:19:02.714Z,1654013942.714 [DataOverHttps](INFO): Moved sent file to Logs/20220531T014417/Express0089.lzma.bak 2022-05-31T16:19:02.714Z,1654013942.714 [DataOverHttps](INFO): SBD MOMSN=16845419 2022-05-31T16:19:04.101Z,1654013944.101 [Default:CheckIn:Read_Iridium] Stopped 2022-05-31T16:19:04.101Z,1654013944.101 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-31T16:19:04.101Z,1654013944.101 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-31T16:19:29.943Z,1654013969.943 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-31T16:24:04.696Z,1654014244.696 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-31T16:24:04.696Z,1654014244.696 [Default:CheckIn:C.Wait] Stopped 2022-05-31T16:24:04.696Z,1654014244.696 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-31T16:24:04.696Z,1654014244.696 [Default:CheckIn:D] Running Loop=1 2022-05-31T16:24:05.114Z,1654014245.114 [Default:CheckIn:D] Stopped 2022-05-31T16:24:05.114Z,1654014245.114 [Default:CheckIn:E] Running Loop=1 2022-05-31T16:24:05.498Z,1654014245.498 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 17.510665 min 2022-05-31T16:24:05.498Z,1654014245.498 [Default:CheckIn:E] Stopped 2022-05-31T16:24:05.498Z,1654014245.498 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-31T16:24:05.498Z,1654014245.498 [Default:CheckIn] Stopped 2022-05-31T16:24:05.498Z,1654014245.498 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-31T16:24:05.499Z,1654014245.499 [Default:CheckIn](INFO): Running loop #4 2022-05-31T16:24:05.499Z,1654014245.499 [Default:CheckIn] Running Loop=4 2022-05-31T16:24:05.499Z,1654014245.499 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-31T16:24:05.499Z,1654014245.499 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-31T16:24:07.507Z,1654014247.507 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162404.00,A,3648.49229,N,12147.23427,W,6.084,42.60,310522,,,D*4D 2022-05-31T16:24:07.509Z,1654014247.509 [NAL9602](INFO): GPS fix at 20220531T162404: (36.808205, -121.787238) 2022-05-31T16:24:07.524Z,1654014247.524 [Default:CheckIn:Read_GPS] Stopped 2022-05-31T16:24:07.524Z,1654014247.524 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-31T16:24:15.135Z,1654014255.135 [DataOverHttps](INFO): Sending 269 bytes from file Logs/20220531T161756/Courier0003.lzma 2022-05-31T16:24:16.138Z,1654014256.138 [DataOverHttps](INFO): Moved sent file to Logs/20220531T161756/Courier0003.lzma.bak 2022-05-31T16:24:16.138Z,1654014256.138 [DataOverHttps](INFO): SBD MOMSN=16845426 2022-05-31T16:24:32.240Z,1654014272.240 [DataOverHttps](INFO): Sending 393 bytes from file Logs/20220531T161756/Express0004.lzma 2022-05-31T16:24:33.241Z,1654014273.241 [DataOverHttps](INFO): Moved sent file to Logs/20220531T161756/Express0004.lzma.bak 2022-05-31T16:24:33.241Z,1654014273.241 [DataOverHttps](INFO): SBD MOMSN=16845430 2022-05-31T16:24:34.668Z,1654014274.668 [Default:CheckIn:Read_Iridium] Stopped 2022-05-31T16:24:34.668Z,1654014274.668 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-31T16:24:34.668Z,1654014274.668 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-31T16:24:52.058Z,1654014292.058 [NAL9602](INFO): SBD MO Status=0, MOMSN=7843, MT Status=0, MTMSN=0 2022-05-31T16:24:52.058Z,1654014292.058 [NAL9602](INFO): No messages in MT queue 2022-05-31T16:25:22.764Z,1654014322.764 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-31T16:27:27.259Z,1654014447.259 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2022-05-31T16:27:27.262Z,1654014447.262 [BPC1](INFO): Received data from all battery sticks. 2022-05-31T16:29:35.317Z,1654014575.317 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-31T16:29:35.318Z,1654014575.318 [Default:CheckIn:C.Wait] Stopped 2022-05-31T16:29:35.318Z,1654014575.318 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-31T16:29:35.318Z,1654014575.318 [Default:CheckIn:D] Running Loop=1 2022-05-31T16:29:35.727Z,1654014575.727 [Default:CheckIn:D] Stopped 2022-05-31T16:29:35.727Z,1654014575.727 [Default:CheckIn:E] Running Loop=1 2022-05-31T16:29:36.145Z,1654014576.145 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 23.020882 min 2022-05-31T16:29:36.145Z,1654014576.145 [Default:CheckIn:E] Stopped 2022-05-31T16:29:36.146Z,1654014576.146 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-31T16:29:36.146Z,1654014576.146 [Default:CheckIn] Stopped 2022-05-31T16:29:36.146Z,1654014576.146 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-31T16:29:36.146Z,1654014576.146 [Default:CheckIn](INFO): Running loop #5 2022-05-31T16:29:36.146Z,1654014576.146 [Default:CheckIn] Running Loop=5 2022-05-31T16:29:36.146Z,1654014576.146 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-31T16:29:36.146Z,1654014576.146 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-31T16:29:38.146Z,1654014578.146 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162934.00,A,3648.33386,N,12147.10665,W,1.322,33.68,310522,,,D*48 2022-05-31T16:29:38.148Z,1654014578.148 [NAL9602](INFO): GPS fix at 20220531T162934: (36.805564, -121.785111) 2022-05-31T16:29:38.178Z,1654014578.178 [Default:CheckIn:Read_GPS] Stopped 2022-05-31T16:29:38.178Z,1654014578.178 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-31T16:29:46.467Z,1654014586.467 [DataOverHttps](INFO): Sending 204 bytes from file Logs/20220531T161756/Courier0006.lzma 2022-05-31T16:29:47.469Z,1654014587.469 [DataOverHttps](INFO): Moved sent file to Logs/20220531T161756/Courier0006.lzma.bak 2022-05-31T16:29:47.470Z,1654014587.470 [DataOverHttps](INFO): SBD MOMSN=16845436 2022-05-31T16:30:02.022Z,1654014602.022 [NAL9602](INFO): SBD MO Status=0, MOMSN=7844, MT Status=0, MTMSN=0 2022-05-31T16:30:02.022Z,1654014602.022 [NAL9602](INFO): No messages in MT queue 2022-05-31T16:30:06.027Z,1654014606.027 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20220531T161756/Express0007.lzma 2022-05-31T16:30:07.029Z,1654014607.029 [DataOverHttps](INFO): Moved sent file to Logs/20220531T161756/Express0007.lzma.bak 2022-05-31T16:30:07.030Z,1654014607.030 [DataOverHttps](INFO): SBD MOMSN=16845439 2022-05-31T16:30:08.513Z,1654014608.513 [Default:CheckIn:Read_Iridium] Stopped 2022-05-31T16:30:08.513Z,1654014608.513 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-31T16:30:08.514Z,1654014608.514 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-31T16:30:32.726Z,1654014632.726 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-31T16:35:09.132Z,1654014909.132 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-31T16:35:09.132Z,1654014909.132 [Default:CheckIn:C.Wait] Stopped 2022-05-31T16:35:09.133Z,1654014909.133 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-31T16:35:09.133Z,1654014909.133 [Default:CheckIn:D] Running Loop=1 2022-05-31T16:35:09.545Z,1654014909.545 [Default:CheckIn:D] Stopped 2022-05-31T16:35:09.545Z,1654014909.545 [Default:CheckIn:E] Running Loop=1 2022-05-31T16:35:09.942Z,1654014909.942 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 28.584513 min 2022-05-31T16:35:09.942Z,1654014909.942 [Default:CheckIn:E] Stopped 2022-05-31T16:35:09.942Z,1654014909.942 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-31T16:35:09.942Z,1654014909.942 [Default:CheckIn] Stopped 2022-05-31T16:35:09.942Z,1654014909.942 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-31T16:35:09.942Z,1654014909.942 [Default:CheckIn](INFO): Running loop #6 2022-05-31T16:35:09.943Z,1654014909.943 [Default:CheckIn] Running Loop=6 2022-05-31T16:35:09.943Z,1654014909.943 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-31T16:35:09.943Z,1654014909.943 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-31T16:35:11.958Z,1654014911.958 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163508.00,A,3648.31587,N,12147.14378,W,0.058,219.76,310522,,,A*7D 2022-05-31T16:35:11.960Z,1654014911.960 [NAL9602](INFO): GPS fix at 20220531T163508: (36.805264, -121.785730) 2022-05-31T16:35:11.971Z,1654014911.971 [Default:CheckIn:Read_GPS] Stopped 2022-05-31T16:35:11.971Z,1654014911.971 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-31T16:35:19.507Z,1654014919.507 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220531T161756/Courier0009.lzma 2022-05-31T16:35:20.509Z,1654014920.509 [DataOverHttps](INFO): Moved sent file to Logs/20220531T161756/Courier0009.lzma.bak 2022-05-31T16:35:20.510Z,1654014920.510 [DataOverHttps](INFO): SBD MOMSN=16845449 2022-05-31T16:35:33.776Z,1654014933.776 [NAL9602](INFO): SBD MO Status=2, MOMSN=7845, MT Status=2, MTMSN=0 2022-05-31T16:35:33.776Z,1654014933.776 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-05-31T16:35:36.447Z,1654014936.447 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20220531T161756/Express0010.lzma 2022-05-31T16:35:37.449Z,1654014937.449 [DataOverHttps](INFO): Moved sent file to Logs/20220531T161756/Express0010.lzma.bak 2022-05-31T16:35:37.450Z,1654014937.450 [DataOverHttps](INFO): SBD MOMSN=16845452 2022-05-31T16:35:38.649Z,1654014938.649 [Default:CheckIn:Read_Iridium] Stopped 2022-05-31T16:35:38.649Z,1654014938.649 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-31T16:35:38.649Z,1654014938.649 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-31T16:35:49.533Z,1654014949.533 [NAL9602](INFO): SBD MO Status=0, MOMSN=7845, MT Status=0, MTMSN=0 2022-05-31T16:35:49.533Z,1654014949.533 [NAL9602](INFO): No messages in MT queue 2022-05-31T16:36:20.236Z,1654014980.236 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-31T16:40:39.258Z,1654015239.258 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-31T16:40:39.258Z,1654015239.258 [Default:CheckIn:C.Wait] Stopped 2022-05-31T16:40:39.258Z,1654015239.258 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-31T16:40:39.258Z,1654015239.258 [Default:CheckIn:D] Running Loop=1 2022-05-31T16:40:39.635Z,1654015239.635 [Default:CheckIn:D] Stopped 2022-05-31T16:40:39.635Z,1654015239.635 [Default:CheckIn:E] Running Loop=1 2022-05-31T16:40:40.047Z,1654015240.047 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 34.086015 min 2022-05-31T16:40:40.047Z,1654015240.047 [Default:CheckIn:E] Stopped 2022-05-31T16:40:40.047Z,1654015240.047 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-31T16:40:40.047Z,1654015240.047 [Default:CheckIn] Stopped 2022-05-31T16:40:40.047Z,1654015240.047 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-31T16:40:40.048Z,1654015240.048 [Default:CheckIn](INFO): Running loop #7 2022-05-31T16:40:40.048Z,1654015240.048 [Default:CheckIn] Running Loop=7 2022-05-31T16:40:40.048Z,1654015240.048 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-31T16:40:40.048Z,1654015240.048 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-31T16:40:42.056Z,1654015242.056 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164038.00,A,3648.31460,N,12147.14562,W,0.078,112.85,310522,,,A*7F 2022-05-31T16:40:42.058Z,1654015242.058 [NAL9602](INFO): GPS fix at 20220531T164038: (36.805243, -121.785760) 2022-05-31T16:40:42.069Z,1654015242.069 [Default:CheckIn:Read_GPS] Stopped 2022-05-31T16:40:42.069Z,1654015242.069 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-31T16:40:49.775Z,1654015249.775 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20220531T161756/Courier0012.lzma 2022-05-31T16:40:50.777Z,1654015250.777 [DataOverHttps](INFO): Moved sent file to Logs/20220531T161756/Courier0012.lzma.bak 2022-05-31T16:40:50.777Z,1654015250.777 [DataOverHttps](INFO): SBD MOMSN=16845457 2022-05-31T16:40:56.998Z,1654015256.998 [NAL9602](INFO): SBD MO Status=0, MOMSN=7846, MT Status=0, MTMSN=0 2022-05-31T16:40:56.998Z,1654015256.998 [NAL9602](INFO): No messages in MT queue 2022-05-31T16:41:06.767Z,1654015266.767 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20220531T161756/Express0013.lzma 2022-05-31T16:41:07.769Z,1654015267.769 [DataOverHttps](INFO): Moved sent file to Logs/20220531T161756/Express0013.lzma.bak 2022-05-31T16:41:07.769Z,1654015267.769 [DataOverHttps](INFO): SBD MOMSN=16845460 2022-05-31T16:41:09.126Z,1654015269.126 [Default:CheckIn:Read_Iridium] Stopped 2022-05-31T16:41:09.127Z,1654015269.127 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-31T16:41:09.127Z,1654015269.127 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-31T16:41:27.699Z,1654015287.699 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-31T16:46:09.779Z,1654015569.779 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-31T16:46:09.779Z,1654015569.779 [Default:CheckIn:C.Wait] Stopped 2022-05-31T16:46:09.780Z,1654015569.780 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-31T16:46:09.780Z,1654015569.780 [Default:CheckIn:D] Running Loop=1 2022-05-31T16:46:10.166Z,1654015570.166 [Default:CheckIn:D] Stopped 2022-05-31T16:46:10.166Z,1654015570.166 [Default:CheckIn:E] Running Loop=1 2022-05-31T16:46:10.570Z,1654015570.570 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 39.594877 min 2022-05-31T16:46:10.571Z,1654015570.571 [Default:CheckIn:E] Stopped 2022-05-31T16:46:10.571Z,1654015570.571 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-31T16:46:10.571Z,1654015570.571 [Default:CheckIn] Stopped 2022-05-31T16:46:10.571Z,1654015570.571 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-31T16:46:10.571Z,1654015570.571 [Default:CheckIn](INFO): Running loop #8 2022-05-31T16:46:10.571Z,1654015570.571 [Default:CheckIn] Running Loop=8 2022-05-31T16:46:10.571Z,1654015570.571 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-31T16:46:10.572Z,1654015570.572 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-31T16:46:12.582Z,1654015572.582 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164609.00,A,3648.31439,N,12147.14187,W,0.719,64.13,310522,,,A*47 2022-05-31T16:46:12.584Z,1654015572.584 [NAL9602](INFO): GPS fix at 20220531T164609: (36.805240, -121.785698) 2022-05-31T16:46:12.614Z,1654015572.614 [Default:CheckIn:Read_GPS] Stopped 2022-05-31T16:46:12.615Z,1654015572.615 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-31T16:46:19.743Z,1654015579.743 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20220531T161756/Courier0015.lzma 2022-05-31T16:46:20.745Z,1654015580.745 [DataOverHttps](INFO): Moved sent file to Logs/20220531T161756/Courier0015.lzma.bak 2022-05-31T16:46:20.745Z,1654015580.745 [DataOverHttps](INFO): SBD MOMSN=16845471 2022-05-31T16:46:36.587Z,1654015596.587 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20220531T161756/Express0016.lzma 2022-05-31T16:46:37.589Z,1654015597.589 [DataOverHttps](INFO): Moved sent file to Logs/20220531T161756/Express0016.lzma.bak 2022-05-31T16:46:37.589Z,1654015597.589 [DataOverHttps](INFO): SBD MOMSN=16845474 2022-05-31T16:46:38.873Z,1654015598.873 [Default:CheckIn:Read_Iridium] Stopped 2022-05-31T16:46:38.873Z,1654015598.873 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-31T16:46:38.873Z,1654015598.873 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-31T16:46:53.784Z,1654015613.784 [NAL9602](INFO): SBD MO Status=0, MOMSN=7847, MT Status=0, MTMSN=0 2022-05-31T16:46:53.784Z,1654015613.784 [NAL9602](INFO): No messages in MT queue 2022-05-31T16:47:24.487Z,1654015644.487 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-31T16:51:39.438Z,1654015899.438 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-31T16:51:39.438Z,1654015899.438 [Default:CheckIn:C.Wait] Stopped 2022-05-31T16:51:39.438Z,1654015899.438 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-31T16:51:39.439Z,1654015899.439 [Default:CheckIn:D] Running Loop=1 2022-05-31T16:51:39.853Z,1654015899.853 [Default:CheckIn:D] Stopped 2022-05-31T16:51:39.853Z,1654015899.853 [Default:CheckIn:E] Running Loop=1 2022-05-31T16:51:40.238Z,1654015900.238 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 45.089657 min 2022-05-31T16:51:40.238Z,1654015900.238 [Default:CheckIn:E] Stopped 2022-05-31T16:51:40.238Z,1654015900.238 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-31T16:51:40.238Z,1654015900.238 [Default:CheckIn] Stopped 2022-05-31T16:51:40.238Z,1654015900.238 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-31T16:51:40.238Z,1654015900.238 [Default:CheckIn](INFO): Running loop #9 2022-05-31T16:51:40.239Z,1654015900.239 [Default:CheckIn] Running Loop=9 2022-05-31T16:51:40.239Z,1654015900.239 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-31T16:51:40.239Z,1654015900.239 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-31T16:51:42.258Z,1654015902.258 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165139.00,A,3648.11911,N,12147.22552,W,0.428,263.82,310522,,,D*77 2022-05-31T16:51:42.260Z,1654015902.260 [NAL9602](INFO): GPS fix at 20220531T165139: (36.801985, -121.787092) 2022-05-31T16:51:42.271Z,1654015902.271 [Default:CheckIn:Read_GPS] Stopped 2022-05-31T16:51:42.305Z,1654015902.305 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-31T16:51:53.227Z,1654015913.227 [DataOverHttps](INFO): Sending 75 bytes from file Logs/20220531T161756/Courier0018.lzma 2022-05-31T16:51:54.230Z,1654015914.230 [DataOverHttps](INFO): Moved sent file to Logs/20220531T161756/Courier0018.lzma.bak 2022-05-31T16:51:54.230Z,1654015914.230 [DataOverHttps](INFO): SBD MOMSN=16845486 2022-05-31T16:52:00.089Z,1654015920.089 [NAL9602](INFO): SBD MO Status=0, MOMSN=7848, MT Status=0, MTMSN=0 2022-05-31T16:52:00.089Z,1654015920.089 [NAL9602](INFO): No messages in MT queue 2022-05-31T16:52:10.511Z,1654015930.511 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20220531T161756/Express0019.lzma 2022-05-31T16:52:11.513Z,1654015931.513 [DataOverHttps](INFO): Moved sent file to Logs/20220531T161756/Express0019.lzma.bak 2022-05-31T16:52:11.513Z,1654015931.513 [DataOverHttps](INFO): SBD MOMSN=16845490 2022-05-31T16:52:13.020Z,1654015933.020 [Default:CheckIn:Read_Iridium] Stopped 2022-05-31T16:52:13.020Z,1654015933.020 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-31T16:52:13.021Z,1654015933.021 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-31T16:52:30.787Z,1654015950.787 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-31T16:57:13.652Z,1654016233.652 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-31T16:57:13.652Z,1654016233.652 [Default:CheckIn:C.Wait] Stopped 2022-05-31T16:57:13.652Z,1654016233.652 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-31T16:57:13.652Z,1654016233.652 [Default:CheckIn:D] Running Loop=1 2022-05-31T16:57:14.054Z,1654016234.054 [Default:CheckIn:D] Stopped 2022-05-31T16:57:14.055Z,1654016234.055 [Default:CheckIn:E] Running Loop=1 2022-05-31T16:57:14.457Z,1654016234.457 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 50.659676 min 2022-05-31T16:57:14.458Z,1654016234.458 [Default:CheckIn:E] Stopped 2022-05-31T16:57:14.458Z,1654016234.458 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-31T16:57:14.458Z,1654016234.458 [Default:CheckIn] Stopped 2022-05-31T16:57:14.458Z,1654016234.458 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-31T16:57:14.458Z,1654016234.458 [Default:CheckIn](INFO): Running loop #10 2022-05-31T16:57:14.458Z,1654016234.458 [Default:CheckIn] Running Loop=10 2022-05-31T16:57:14.458Z,1654016234.458 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-31T16:57:14.458Z,1654016234.458 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-31T16:57:16.471Z,1654016236.471 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165713.00,A,3648.12286,N,12147.22939,W,0.097,263.82,310522,,,D*7E 2022-05-31T16:57:16.473Z,1654016236.473 [NAL9602](INFO): GPS fix at 20220531T165713: (36.802048, -121.787156) 2022-05-31T16:57:16.484Z,1654016236.484 [Default:CheckIn:Read_GPS] Stopped 2022-05-31T16:57:16.484Z,1654016236.484 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-31T16:57:23.867Z,1654016243.867 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20220531T161756/Courier0021.lzma 2022-05-31T16:57:24.869Z,1654016244.869 [DataOverHttps](INFO): Moved sent file to Logs/20220531T161756/Courier0021.lzma.bak 2022-05-31T16:57:24.869Z,1654016244.869 [DataOverHttps](INFO): SBD MOMSN=16845525 2022-05-31T16:57:40.767Z,1654016260.767 [DataOverHttps](INFO): Sending 127 bytes from file Logs/20220531T161756/Express0022.lzma 2022-05-31T16:57:41.769Z,1654016261.769 [DataOverHttps](INFO): Moved sent file to Logs/20220531T161756/Express0022.lzma.bak 2022-05-31T16:57:41.769Z,1654016261.769 [DataOverHttps](INFO): SBD MOMSN=16845528 2022-05-31T16:57:43.177Z,1654016263.177 [Default:CheckIn:Read_Iridium] Stopped 2022-05-31T16:57:43.177Z,1654016263.177 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-31T16:57:43.177Z,1654016263.177 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-31T16:57:47.254Z,1654016267.254 [NAL9602](INFO): SBD MO Status=0, MOMSN=7849, MT Status=0, MTMSN=0 2022-05-31T16:57:47.254Z,1654016267.254 [NAL9602](INFO): No messages in MT queue 2022-05-31T16:58:17.952Z,1654016297.952 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-31T17:02:43.824Z,1654016563.824 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-31T17:02:43.824Z,1654016563.824 [Default:CheckIn:C.Wait] Stopped 2022-05-31T17:02:43.824Z,1654016563.824 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-31T17:02:43.825Z,1654016563.825 [Default:CheckIn:D] Running Loop=1 2022-05-31T17:02:44.205Z,1654016564.205 [Default:CheckIn:D] Stopped 2022-05-31T17:02:44.205Z,1654016564.205 [Default:CheckIn:E] Running Loop=1 2022-05-31T17:02:44.610Z,1654016564.610 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 56.162187 min 2022-05-31T17:02:44.610Z,1654016564.610 [Default:CheckIn:E] Stopped 2022-05-31T17:02:44.610Z,1654016564.610 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-31T17:02:44.611Z,1654016564.611 [Default:CheckIn] Stopped 2022-05-31T17:02:44.611Z,1654016564.611 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-31T17:02:44.611Z,1654016564.611 [Default:CheckIn](INFO): Running loop #11 2022-05-31T17:02:44.611Z,1654016564.611 [Default:CheckIn] Running Loop=11 2022-05-31T17:02:44.611Z,1654016564.611 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-31T17:02:44.611Z,1654016564.611 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-31T17:02:46.626Z,1654016566.626 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170243.00,A,3648.15267,N,12147.25220,W,2.683,15.70,310522,,,D*49 2022-05-31T17:02:46.628Z,1654016566.628 [NAL9602](INFO): GPS fix at 20220531T170243: (36.802545, -121.787537) 2022-05-31T17:02:46.639Z,1654016566.639 [Default:CheckIn:Read_GPS] Stopped 2022-05-31T17:02:46.639Z,1654016566.639 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-31T17:02:54.653Z,1654016574.653 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20220531T161756/Courier0024.lzma 2022-05-31T17:02:55.654Z,1654016575.654 [DataOverHttps](INFO): Moved sent file to Logs/20220531T161756/Courier0024.lzma.bak 2022-05-31T17:02:55.654Z,1654016575.654 [DataOverHttps](INFO): SBD MOMSN=16845532 2022-05-31T17:03:11.687Z,1654016591.687 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20220531T161756/Express0025.lzma 2022-05-31T17:03:12.689Z,1654016592.689 [DataOverHttps](INFO): Moved sent file to Logs/20220531T161756/Express0025.lzma.bak 2022-05-31T17:03:12.690Z,1654016592.690 [DataOverHttps](INFO): SBD MOMSN=16845535 2022-05-31T17:03:14.122Z,1654016594.122 [Default:CheckIn:Read_Iridium] Stopped 2022-05-31T17:03:14.122Z,1654016594.122 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-31T17:03:14.122Z,1654016594.122 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-31T17:03:25.010Z,1654016605.010 [NAL9602](INFO): SBD MO Status=0, MOMSN=7850, MT Status=0, MTMSN=0 2022-05-31T17:03:25.010Z,1654016605.010 [NAL9602](INFO): No messages in MT queue 2022-05-31T17:03:55.707Z,1654016635.707 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-31T17:08:14.694Z,1654016894.694 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-31T17:08:14.694Z,1654016894.694 [Default:CheckIn:C.Wait] Stopped 2022-05-31T17:08:14.695Z,1654016894.695 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-31T17:08:14.695Z,1654016894.695 [Default:CheckIn:D] Running Loop=1 2022-05-31T17:08:15.098Z,1654016895.098 [Default:CheckIn:D] Stopped 2022-05-31T17:08:15.098Z,1654016895.098 [Default:CheckIn:E] Running Loop=1 2022-05-31T17:08:15.505Z,1654016895.505 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 61.677075 min 2022-05-31T17:08:15.505Z,1654016895.505 [Default:CheckIn:E] Stopped 2022-05-31T17:08:15.505Z,1654016895.505 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-31T17:08:15.505Z,1654016895.505 [Default:CheckIn] Stopped 2022-05-31T17:08:15.506Z,1654016895.506 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-31T17:08:15.506Z,1654016895.506 [Default:CheckIn](INFO): Running loop #12 2022-05-31T17:08:15.506Z,1654016895.506 [Default:CheckIn] Running Loop=12 2022-05-31T17:08:15.506Z,1654016895.506 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-31T17:08:15.506Z,1654016895.506 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-31T17:08:17.514Z,1654016897.514 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170814.00,A,3648.16394,N,12147.28541,W,1.108,230.52,310522,,,A*75 2022-05-31T17:08:17.516Z,1654016897.516 [NAL9602](INFO): GPS fix at 20220531T170814: (36.802732, -121.788090) 2022-05-31T17:08:17.546Z,1654016897.546 [Default:CheckIn:Read_GPS] Stopped 2022-05-31T17:08:17.546Z,1654016897.546 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-31T17:08:25.403Z,1654016905.403 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20220531T161756/Courier0027.lzma 2022-05-31T17:08:26.405Z,1654016906.405 [DataOverHttps](INFO): Moved sent file to Logs/20220531T161756/Courier0027.lzma.bak 2022-05-31T17:08:26.406Z,1654016906.406 [DataOverHttps](INFO): SBD MOMSN=16845539 2022-05-31T17:08:42.583Z,1654016922.583 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20220531T161756/Express0028.lzma 2022-05-31T17:08:43.585Z,1654016923.585 [DataOverHttps](INFO): Moved sent file to Logs/20220531T161756/Express0028.lzma.bak 2022-05-31T17:08:43.586Z,1654016923.586 [DataOverHttps](INFO): SBD MOMSN=16845543 2022-05-31T17:08:45.017Z,1654016925.017 [Default:CheckIn:Read_Iridium] Stopped 2022-05-31T17:08:45.017Z,1654016925.017 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-31T17:08:45.017Z,1654016925.017 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-31T17:13:19.697Z,1654017199.697 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-05-31T17:13:45.588Z,1654017225.588 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-31T17:13:45.588Z,1654017225.588 [Default:CheckIn:C.Wait] Stopped 2022-05-31T17:13:45.588Z,1654017225.588 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-31T17:13:45.589Z,1654017225.589 [Default:CheckIn:D] Running Loop=1 2022-05-31T17:13:45.973Z,1654017225.973 [Default:CheckIn:D] Stopped 2022-05-31T17:13:45.973Z,1654017225.973 [Default:CheckIn:E] Running Loop=1 2022-05-31T17:13:46.374Z,1654017226.374 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 67.191659 min 2022-05-31T17:13:46.374Z,1654017226.374 [Default:CheckIn:E] Stopped 2022-05-31T17:13:46.374Z,1654017226.374 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-31T17:13:46.374Z,1654017226.374 [Default:CheckIn] Stopped 2022-05-31T17:13:46.374Z,1654017226.374 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-31T17:13:46.375Z,1654017226.375 [Default:CheckIn](INFO): Running loop #13 2022-05-31T17:13:46.375Z,1654017226.375 [Default:CheckIn] Running Loop=13 2022-05-31T17:13:46.375Z,1654017226.375 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-31T17:13:46.375Z,1654017226.375 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-31T17:13:48.386Z,1654017228.386 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171345.00,A,3648.16230,N,12147.28407,W,0.253,230.52,310522,,,A*7B 2022-05-31T17:13:48.400Z,1654017228.400 [NAL9602](INFO): GPS fix at 20220531T171345: (36.802705, -121.788068) 2022-05-31T17:13:48.417Z,1654017228.417 [Default:CheckIn:Read_GPS] Stopped 2022-05-31T17:13:48.417Z,1654017228.417 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-31T17:13:55.347Z,1654017235.347 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20220531T161756/Courier0030.lzma 2022-05-31T17:13:56.349Z,1654017236.349 [DataOverHttps](INFO): Moved sent file to Logs/20220531T161756/Courier0030.lzma.bak 2022-05-31T17:13:56.349Z,1654017236.349 [DataOverHttps](INFO): SBD MOMSN=16845546 2022-05-31T17:14:12.520Z,1654017252.520 [DataOverHttps](INFO): Sending 229 bytes from file Logs/20220531T161756/Express0031.lzma 2022-05-31T17:14:13.521Z,1654017253.521 [DataOverHttps](INFO): Moved sent file to Logs/20220531T161756/Express0031.lzma.bak 2022-05-31T17:14:13.522Z,1654017253.522 [DataOverHttps](INFO): SBD MOMSN=16845549 2022-05-31T17:14:14.722Z,1654017254.722 [Default:CheckIn:Read_Iridium] Stopped 2022-05-31T17:14:14.722Z,1654017254.722 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-31T17:14:14.722Z,1654017254.722 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-31T17:14:20.753Z,1654017260.753 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-31T17:19:15.375Z,1654017555.375 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-31T17:19:15.375Z,1654017555.375 [Default:CheckIn:C.Wait] Stopped 2022-05-31T17:19:15.376Z,1654017555.376 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-31T17:19:15.376Z,1654017555.376 [Default:CheckIn:D] Running Loop=1 2022-05-31T17:19:15.794Z,1654017555.794 [Default:CheckIn:D] Stopped 2022-05-31T17:19:15.795Z,1654017555.795 [Default:CheckIn:E] Running Loop=1 2022-05-31T17:19:16.190Z,1654017556.190 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 72.688680 min 2022-05-31T17:19:16.190Z,1654017556.190 [Default:CheckIn:E] Stopped 2022-05-31T17:19:16.190Z,1654017556.190 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-31T17:19:16.190Z,1654017556.190 [Default:CheckIn] Stopped 2022-05-31T17:19:16.190Z,1654017556.190 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-31T17:19:16.190Z,1654017556.190 [Default:CheckIn](INFO): Running loop #14 2022-05-31T17:19:16.191Z,1654017556.191 [Default:CheckIn] Running Loop=14 2022-05-31T17:19:16.191Z,1654017556.191 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-31T17:19:16.191Z,1654017556.191 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-31T17:19:18.194Z,1654017558.194 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171915.00,A,3648.16736,N,12147.27911,W,0.525,284.01,310522,,,A*7D 2022-05-31T17:19:18.197Z,1654017558.197 [NAL9602](INFO): GPS fix at 20220531T171915: (36.802789, -121.787985) 2022-05-31T17:19:18.207Z,1654017558.207 [Default:CheckIn:Read_GPS] Stopped 2022-05-31T17:19:18.208Z,1654017558.208 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-31T17:19:25.487Z,1654017565.487 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20220531T161756/Courier0033.lzma 2022-05-31T17:19:26.911Z,1654017566.911 [DataOverHttps](INFO): Moved sent file to Logs/20220531T161756/Courier0033.lzma.bak 2022-05-31T17:19:26.911Z,1654017566.911 [DataOverHttps](INFO): SBD MOMSN=16845554 2022-05-31T17:19:42.491Z,1654017582.491 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20220531T161756/Express0034.lzma 2022-05-31T17:19:43.494Z,1654017583.494 [DataOverHttps](INFO): Moved sent file to Logs/20220531T161756/Express0034.lzma.bak 2022-05-31T17:19:43.494Z,1654017583.494 [DataOverHttps](INFO): SBD MOMSN=16845557 2022-05-31T17:19:44.898Z,1654017584.898 [Default:CheckIn:Read_Iridium] Stopped 2022-05-31T17:19:44.898Z,1654017584.898 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-31T17:19:44.898Z,1654017584.898 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-31T17:24:20.857Z,1654017860.857 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-05-31T17:24:45.526Z,1654017885.526 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-31T17:24:45.526Z,1654017885.526 [Default:CheckIn:C.Wait] Stopped 2022-05-31T17:24:45.526Z,1654017885.526 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-31T17:24:45.526Z,1654017885.526 [Default:CheckIn:D] Running Loop=1 2022-05-31T17:24:45.906Z,1654017885.906 [Default:CheckIn:D] Stopped 2022-05-31T17:24:45.906Z,1654017885.906 [Default:CheckIn:E] Running Loop=1 2022-05-31T17:24:46.319Z,1654017886.319 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 78.190535 min 2022-05-31T17:24:46.319Z,1654017886.319 [Default:CheckIn:E] Stopped 2022-05-31T17:24:46.319Z,1654017886.319 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-31T17:24:46.319Z,1654017886.319 [Default:CheckIn] Stopped 2022-05-31T17:24:46.319Z,1654017886.319 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-31T17:24:46.320Z,1654017886.320 [Default:CheckIn](INFO): Running loop #15 2022-05-31T17:24:46.320Z,1654017886.320 [Default:CheckIn] Running Loop=15 2022-05-31T17:24:46.320Z,1654017886.320 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-31T17:24:46.320Z,1654017886.320 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-31T17:24:48.331Z,1654017888.331 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172445.00,A,3648.16814,N,12147.28254,W,0.350,328.39,310522,,,A*74 2022-05-31T17:24:48.333Z,1654017888.333 [NAL9602](INFO): GPS fix at 20220531T172445: (36.802802, -121.788042) 2022-05-31T17:24:48.345Z,1654017888.345 [Default:CheckIn:Read_GPS] Stopped 2022-05-31T17:24:48.345Z,1654017888.345 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-31T17:24:56.803Z,1654017896.803 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20220531T161756/Courier0036.lzma 2022-05-31T17:24:57.805Z,1654017897.805 [DataOverHttps](INFO): Moved sent file to Logs/20220531T161756/Courier0036.lzma.bak 2022-05-31T17:24:57.805Z,1654017897.806 [DataOverHttps](INFO): SBD MOMSN=16845560 2022-05-31T17:25:13.788Z,1654017913.788 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20220531T161756/Express0037.lzma 2022-05-31T17:25:14.785Z,1654017914.785 [DataOverHttps](INFO): Moved sent file to Logs/20220531T161756/Express0037.lzma.bak 2022-05-31T17:25:14.786Z,1654017914.786 [DataOverHttps](INFO): SBD MOMSN=16845563 2022-05-31T17:25:16.239Z,1654017916.239 [Default:CheckIn:Read_Iridium] Stopped 2022-05-31T17:25:16.239Z,1654017916.239 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-31T17:25:16.239Z,1654017916.239 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-31T17:25:21.080Z,1654017921.080 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-31T17:30:16.826Z,1654018216.826 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-31T17:30:16.826Z,1654018216.826 [Default:CheckIn:C.Wait] Stopped 2022-05-31T17:30:16.826Z,1654018216.826 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-31T17:30:16.827Z,1654018216.827 [Default:CheckIn:D] Running Loop=1 2022-05-31T17:30:17.223Z,1654018217.223 [Default:CheckIn:D] Stopped 2022-05-31T17:30:17.223Z,1654018217.223 [Default:CheckIn:E] Running Loop=1 2022-05-31T17:30:17.623Z,1654018217.623 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 83.712476 min 2022-05-31T17:30:17.623Z,1654018217.623 [Default:CheckIn:E] Stopped 2022-05-31T17:30:17.623Z,1654018217.623 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-31T17:30:17.623Z,1654018217.623 [Default:CheckIn] Stopped 2022-05-31T17:30:17.623Z,1654018217.623 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-31T17:30:17.624Z,1654018217.624 [Default:CheckIn](INFO): Running loop #16 2022-05-31T17:30:17.624Z,1654018217.624 [Default:CheckIn] Running Loop=16 2022-05-31T17:30:17.624Z,1654018217.624 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-31T17:30:17.624Z,1654018217.624 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-31T17:30:19.638Z,1654018219.638 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173016.00,A,3648.16694,N,12147.28146,W,0.505,328.39,310522,,,A*77 2022-05-31T17:30:19.641Z,1654018219.641 [NAL9602](INFO): GPS fix at 20220531T173016: (36.802782, -121.788024) 2022-05-31T17:30:19.670Z,1654018219.670 [Default:CheckIn:Read_GPS] Stopped 2022-05-31T17:30:19.670Z,1654018219.670 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-31T17:30:26.798Z,1654018226.798 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220531T161756/Courier0039.lzma 2022-05-31T17:30:27.769Z,1654018227.769 [DataOverHttps](INFO): Moved sent file to Logs/20220531T161756/Courier0039.lzma.bak 2022-05-31T17:30:27.770Z,1654018227.770 [DataOverHttps](INFO): SBD MOMSN=16845567 2022-05-31T17:30:43.811Z,1654018243.811 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20220531T161756/Express0040.lzma 2022-05-31T17:30:44.813Z,1654018244.813 [DataOverHttps](INFO): Moved sent file to Logs/20220531T161756/Express0040.lzma.bak 2022-05-31T17:30:44.814Z,1654018244.814 [DataOverHttps](INFO): SBD MOMSN=16845570 2022-05-31T17:30:46.393Z,1654018246.393 [Default:CheckIn:Read_Iridium] Stopped 2022-05-31T17:30:46.393Z,1654018246.393 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-31T17:30:46.394Z,1654018246.394 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-31T17:31:07.721Z,1654018267.721 [NAL9602](INFO): SBD MO Status=2, MOMSN=7851, MT Status=2, MTMSN=0 2022-05-31T17:31:07.721Z,1654018267.721 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-05-31T17:32:03.463Z,1654018323.463 [NAL9602](INFO): SBD MO Status=2, MOMSN=7851, MT Status=2, MTMSN=0 2022-05-31T17:32:03.463Z,1654018323.463 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-05-31T17:34:52.811Z,1654018492.811 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2022-05-31T17:34:52.813Z,1654018492.813 [BPC1](INFO): Received data from all battery sticks. 2022-05-31T17:34:56.034Z,1654018496.034 [NAL9602](INFO): SBD MO Status=0, MOMSN=7851, MT Status=0, MTMSN=0 2022-05-31T17:34:56.034Z,1654018496.034 [NAL9602](INFO): No messages in MT queue 2022-05-31T17:35:26.738Z,1654018526.738 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-31T17:35:46.955Z,1654018546.955 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-31T17:35:46.955Z,1654018546.955 [Default:CheckIn:C.Wait] Stopped 2022-05-31T17:35:46.955Z,1654018546.955 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-31T17:35:46.955Z,1654018546.955 [Default:CheckIn:D] Running Loop=1 2022-05-31T17:35:47.366Z,1654018547.366 [Default:CheckIn:D] Stopped 2022-05-31T17:35:47.366Z,1654018547.366 [Default:CheckIn:E] Running Loop=1 2022-05-31T17:35:47.806Z,1654018547.806 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 89.214868 min 2022-05-31T17:35:47.806Z,1654018547.806 [Default:CheckIn:E] Stopped 2022-05-31T17:35:47.807Z,1654018547.807 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-31T17:35:47.807Z,1654018547.807 [Default:CheckIn] Stopped 2022-05-31T17:35:47.807Z,1654018547.807 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-31T17:35:47.807Z,1654018547.807 [Default:CheckIn](INFO): Running loop #17 2022-05-31T17:35:47.807Z,1654018547.807 [Default:CheckIn] Running Loop=17 2022-05-31T17:35:47.807Z,1654018547.807 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-31T17:35:47.807Z,1654018547.807 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-31T17:35:49.781Z,1654018549.781 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173546.00,A,3648.17413,N,12147.27884,W,0.078,328.39,310522,,,D*79 2022-05-31T17:35:49.783Z,1654018549.783 [NAL9602](INFO): GPS fix at 20220531T173546: (36.802902, -121.787981) 2022-05-31T17:35:49.794Z,1654018549.794 [Default:CheckIn:Read_GPS] Stopped 2022-05-31T17:35:49.794Z,1654018549.794 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-31T17:35:57.815Z,1654018557.815 [DataOverHttps](INFO): Sending 86 bytes from file Logs/20220531T161756/Courier0042.lzma 2022-05-31T17:35:58.817Z,1654018558.817 [DataOverHttps](INFO): Moved sent file to Logs/20220531T161756/Courier0042.lzma.bak 2022-05-31T17:35:58.818Z,1654018558.818 [DataOverHttps](INFO): SBD MOMSN=16845573 2022-05-31T17:36:04.320Z,1654018564.320 [NAL9602](INFO): SBD MO Status=0, MOMSN=7852, MT Status=0, MTMSN=0 2022-05-31T17:36:04.320Z,1654018564.320 [NAL9602](INFO): No messages in MT queue 2022-05-31T17:36:14.839Z,1654018574.839 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20220531T161756/Express0043.lzma 2022-05-31T17:36:15.841Z,1654018575.841 [DataOverHttps](INFO): Moved sent file to Logs/20220531T161756/Express0043.lzma.bak 2022-05-31T17:36:15.842Z,1654018575.842 [DataOverHttps](INFO): SBD MOMSN=16845576 2022-05-31T17:36:17.268Z,1654018577.268 [Default:CheckIn:Read_Iridium] Stopped 2022-05-31T17:36:17.268Z,1654018577.268 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-31T17:36:17.268Z,1654018577.268 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-31T17:36:35.019Z,1654018595.019 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-31T17:41:17.853Z,1654018877.853 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-31T17:41:17.853Z,1654018877.853 [Default:CheckIn:C.Wait] Stopped 2022-05-31T17:41:17.853Z,1654018877.853 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-31T17:41:17.853Z,1654018877.853 [Default:CheckIn:D] Running Loop=1 2022-05-31T17:41:18.270Z,1654018878.270 [Default:CheckIn:D] Stopped 2022-05-31T17:41:18.270Z,1654018878.270 [Default:CheckIn:E] Running Loop=1 2022-05-31T17:41:18.654Z,1654018878.654 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 94.729932 min 2022-05-31T17:41:18.654Z,1654018878.654 [Default:CheckIn:E] Stopped 2022-05-31T17:41:18.654Z,1654018878.654 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-31T17:41:18.654Z,1654018878.654 [Default:CheckIn] Stopped 2022-05-31T17:41:18.654Z,1654018878.654 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-31T17:41:18.654Z,1654018878.654 [Default:CheckIn](INFO): Running loop #18 2022-05-31T17:41:18.654Z,1654018878.654 [Default:CheckIn] Running Loop=18 2022-05-31T17:41:18.654Z,1654018878.654 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-31T17:41:18.655Z,1654018878.655 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-31T17:41:20.661Z,1654018880.661 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174117.00,A,3648.17414,N,12147.27963,W,0.019,0.00,310522,,,D*75 2022-05-31T17:41:20.663Z,1654018880.663 [NAL9602](INFO): GPS fix at 20220531T174117: (36.802902, -121.787994) 2022-05-31T17:41:20.674Z,1654018880.674 [Default:CheckIn:Read_GPS] Stopped 2022-05-31T17:41:20.674Z,1654018880.674 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-31T17:41:28.703Z,1654018888.703 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20220531T161756/Courier0045.lzma 2022-05-31T17:41:29.706Z,1654018889.706 [DataOverHttps](INFO): Moved sent file to Logs/20220531T161756/Courier0045.lzma.bak 2022-05-31T17:41:29.706Z,1654018889.706 [DataOverHttps](INFO): SBD MOMSN=16845583 2022-05-31T17:41:42.074Z,1654018902.074 [NAL9602](INFO): SBD MO Status=2, MOMSN=7853, MT Status=2, MTMSN=0 2022-05-31T17:41:42.074Z,1654018902.074 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-05-31T17:41:45.919Z,1654018905.919 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20220531T161756/Express0046.lzma 2022-05-31T17:41:46.921Z,1654018906.921 [DataOverHttps](INFO): Moved sent file to Logs/20220531T161756/Express0046.lzma.bak 2022-05-31T17:41:46.922Z,1654018906.922 [DataOverHttps](INFO): SBD MOMSN=16845586 2022-05-31T17:41:48.143Z,1654018908.143 [Default:CheckIn:Read_Iridium] Stopped 2022-05-31T17:41:48.143Z,1654018908.143 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-31T17:41:48.143Z,1654018908.143 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-31T17:42:10.764Z,1654018930.764 [NAL9602](INFO): SBD MO Status=2, MOMSN=7853, MT Status=2, MTMSN=0 2022-05-31T17:42:10.764Z,1654018930.764 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-05-31T17:43:10.954Z,1654018990.954 [NAL9602](INFO): SBD MO Status=0, MOMSN=7853, MT Status=0, MTMSN=0 2022-05-31T17:43:10.954Z,1654018990.954 [NAL9602](INFO): No messages in MT queue 2022-05-31T17:43:41.655Z,1654019021.655 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-31T17:46:48.726Z,1654019208.726 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-31T17:46:48.727Z,1654019208.727 [Default:CheckIn:C.Wait] Stopped 2022-05-31T17:46:48.727Z,1654019208.727 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-31T17:46:48.727Z,1654019208.727 [Default:CheckIn:D] Running Loop=1 2022-05-31T17:46:49.139Z,1654019209.139 [Default:CheckIn:D] Stopped 2022-05-31T17:46:49.139Z,1654019209.139 [Default:CheckIn:E] Running Loop=1 2022-05-31T17:46:49.534Z,1654019209.534 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 100.244409 min 2022-05-31T17:46:49.534Z,1654019209.534 [Default:CheckIn:E] Stopped 2022-05-31T17:46:49.534Z,1654019209.534 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-31T17:46:49.534Z,1654019209.534 [Default:CheckIn] Stopped 2022-05-31T17:46:49.534Z,1654019209.534 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-31T17:46:49.535Z,1654019209.535 [Default:CheckIn](INFO): Running loop #19 2022-05-31T17:46:49.535Z,1654019209.535 [Default:CheckIn] Running Loop=19 2022-05-31T17:46:49.535Z,1654019209.535 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-31T17:46:49.535Z,1654019209.535 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-31T17:46:51.550Z,1654019211.550 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174648.00,A,3648.17649,N,12147.27728,W,0.058,0.00,310522,,,D*76 2022-05-31T17:46:51.553Z,1654019211.553 [NAL9602](INFO): GPS fix at 20220531T174648: (36.802942, -121.787955) 2022-05-31T17:46:51.598Z,1654019211.598 [Default:CheckIn:Read_GPS] Stopped 2022-05-31T17:46:51.598Z,1654019211.598 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-31T17:46:58.635Z,1654019218.635 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220531T161756/Courier0048.lzma 2022-05-31T17:46:59.638Z,1654019219.638 [DataOverHttps](INFO): Moved sent file to Logs/20220531T161756/Courier0048.lzma.bak 2022-05-31T17:46:59.638Z,1654019219.638 [DataOverHttps](INFO): SBD MOMSN=16845590 2022-05-31T17:47:04.076Z,1654019224.076 [NAL9602](INFO): SBD MO Status=0, MOMSN=7854, MT Status=0, MTMSN=0 2022-05-31T17:47:04.076Z,1654019224.076 [NAL9602](INFO): No messages in MT queue 2022-05-31T17:47:15.443Z,1654019235.443 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20220531T161756/Express0049.lzma 2022-05-31T17:47:16.447Z,1654019236.447 [DataOverHttps](INFO): Moved sent file to Logs/20220531T161756/Express0049.lzma.bak 2022-05-31T17:47:16.447Z,1654019236.447 [DataOverHttps](INFO): SBD MOMSN=16845593 2022-05-31T17:47:17.837Z,1654019237.837 [Default:CheckIn:Read_Iridium] Stopped 2022-05-31T17:47:17.837Z,1654019237.837 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-31T17:47:17.837Z,1654019237.837 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-31T17:47:34.777Z,1654019254.777 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-31T17:52:18.400Z,1654019538.400 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-31T17:52:18.400Z,1654019538.400 [Default:CheckIn:C.Wait] Stopped 2022-05-31T17:52:18.401Z,1654019538.401 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-31T17:52:18.401Z,1654019538.401 [Default:CheckIn:D] Running Loop=1 2022-05-31T17:52:18.799Z,1654019538.799 [Default:CheckIn:D] Stopped 2022-05-31T17:52:18.799Z,1654019538.799 [Default:CheckIn:E] Running Loop=1 2022-05-31T17:52:19.200Z,1654019539.200 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 105.738753 min 2022-05-31T17:52:19.201Z,1654019539.201 [Default:CheckIn:E] Stopped 2022-05-31T17:52:19.201Z,1654019539.201 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-31T17:52:19.201Z,1654019539.201 [Default:CheckIn] Stopped 2022-05-31T17:52:19.201Z,1654019539.201 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-31T17:52:19.201Z,1654019539.201 [Default:CheckIn](INFO): Running loop #20 2022-05-31T17:52:19.201Z,1654019539.201 [Default:CheckIn] Running Loop=20 2022-05-31T17:52:19.201Z,1654019539.201 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-31T17:52:19.201Z,1654019539.201 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-31T17:52:21.209Z,1654019541.209 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175218.00,A,3648.17548,N,12147.28130,W,0.000,0.00,310522,,,D*79 2022-05-31T17:52:21.211Z,1654019541.211 [NAL9602](INFO): GPS fix at 20220531T175218: (36.802925, -121.788022) 2022-05-31T17:52:21.238Z,1654019541.238 [Default:CheckIn:Read_GPS] Stopped 2022-05-31T17:52:21.239Z,1654019541.239 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-31T17:52:28.621Z,1654019548.621 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20220531T161756/Courier0051.lzma 2022-05-31T17:52:29.621Z,1654019549.621 [DataOverHttps](INFO): Moved sent file to Logs/20220531T161756/Courier0051.lzma.bak 2022-05-31T17:52:29.622Z,1654019549.622 [DataOverHttps](INFO): SBD MOMSN=16845597 2022-05-31T17:52:45.543Z,1654019565.543 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20220531T161756/Express0052.lzma 2022-05-31T17:52:46.545Z,1654019566.545 [DataOverHttps](INFO): Moved sent file to Logs/20220531T161756/Express0052.lzma.bak 2022-05-31T17:52:46.546Z,1654019566.546 [DataOverHttps](INFO): SBD MOMSN=16845600 2022-05-31T17:52:47.896Z,1654019567.896 [Default:CheckIn:Read_Iridium] Stopped 2022-05-31T17:52:47.896Z,1654019567.896 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-31T17:52:47.896Z,1654019567.896 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-31T17:54:13.929Z,1654019653.929 [NAL9602](INFO): SBD MO Status=2, MOMSN=7855, MT Status=2, MTMSN=0 2022-05-31T17:54:13.929Z,1654019653.929 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-05-31T17:54:37.371Z,1654019677.371 [NAL9602](INFO): SBD MO Status=2, MOMSN=7855, MT Status=2, MTMSN=0 2022-05-31T17:54:37.371Z,1654019677.371 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-05-31T17:54:44.651Z,1654019684.651 [CBIT](IMPORTANT): Beginning ground fault scan 2022-05-31T17:54:47.509Z,1654019687.509 [CBIT](ERROR): Error reading 24V bus power status. Assuming off for scan purposes. 2022-05-31T17:54:55.544Z,1654019695.544 [NAL9602](INFO): SBD MO Status=2, MOMSN=7855, MT Status=2, MTMSN=0 2022-05-31T17:54:55.544Z,1654019695.544 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-05-31T17:54:55.600Z,1654019695.600 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.005562 CHAN A1 (24V) N/A reporting off CHAN A2 (12V): -0.005458 CHAN A3 (5V): -0.003360 CHAN B0 (3.3V): -0.001825 CHAN B1 (3.15aV): -0.001780 CHAN B2 (3.15bV): -0.001212 CHAN B3 (GND): 0.000202 OPEN: 0.003894 Full Scale: +/- 1 mA 2022-05-31T17:55:06.451Z,1654019706.451 [NAL9602](INFO): SBD MO Status=0, MOMSN=7855, MT Status=0, MTMSN=0 2022-05-31T17:55:06.451Z,1654019706.451 [NAL9602](INFO): No messages in MT queue 2022-05-31T17:55:37.156Z,1654019737.156 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-31T17:57:48.472Z,1654019868.472 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-31T17:57:48.472Z,1654019868.472 [Default:CheckIn:C.Wait] Stopped 2022-05-31T17:57:48.472Z,1654019868.472 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-31T17:57:48.472Z,1654019868.472 [Default:CheckIn:D] Running Loop=1 2022-05-31T17:57:48.881Z,1654019868.881 [Default:CheckIn:D] Stopped 2022-05-31T17:57:48.881Z,1654019868.881 [Default:CheckIn:E] Running Loop=1 2022-05-31T17:57:49.302Z,1654019869.302 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 111.240120 min 2022-05-31T17:57:49.302Z,1654019869.302 [Default:CheckIn:E] Stopped 2022-05-31T17:57:49.302Z,1654019869.302 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-31T17:57:49.302Z,1654019869.302 [Default:CheckIn] Stopped 2022-05-31T17:57:49.302Z,1654019869.302 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-31T17:57:49.302Z,1654019869.302 [Default:CheckIn](INFO): Running loop #21 2022-05-31T17:57:49.302Z,1654019869.302 [Default:CheckIn] Running Loop=21 2022-05-31T17:57:49.302Z,1654019869.302 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-31T17:57:49.303Z,1654019869.303 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-31T17:57:51.287Z,1654019871.287 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175748.00,A,3648.17554,N,12147.28146,W,0.117,296.68,310522,,,D*71 2022-05-31T17:57:51.289Z,1654019871.289 [NAL9602](INFO): GPS fix at 20220531T175748: (36.802926, -121.788024) 2022-05-31T17:57:51.300Z,1654019871.300 [Default:CheckIn:Read_GPS] Stopped 2022-05-31T17:57:51.300Z,1654019871.300 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-31T17:57:59.051Z,1654019879.051 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220531T161756/Courier0054.lzma 2022-05-31T17:58:00.055Z,1654019880.055 [DataOverHttps](INFO): Moved sent file to Logs/20220531T161756/Courier0054.lzma.bak 2022-05-31T17:58:00.055Z,1654019880.055 [DataOverHttps](INFO): SBD MOMSN=16845604 2022-05-31T17:58:11.513Z,1654019891.513 [NAL9602](INFO): SBD MO Status=0, MOMSN=7856, MT Status=0, MTMSN=0 2022-05-31T17:58:11.514Z,1654019891.514 [NAL9602](INFO): No messages in MT queue 2022-05-31T17:58:16.364Z,1654019896.364 [DataOverHttps](INFO): Sending 342 bytes from file Logs/20220531T161756/Express0055.lzma 2022-05-31T17:58:17.365Z,1654019897.365 [DataOverHttps](INFO): Moved sent file to Logs/20220531T161756/Express0055.lzma.bak 2022-05-31T17:58:17.366Z,1654019897.366 [DataOverHttps](INFO): SBD MOMSN=16845607 2022-05-31T17:58:18.794Z,1654019898.794 [Default:CheckIn:Read_Iridium] Stopped 2022-05-31T17:58:18.794Z,1654019898.794 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-31T17:58:18.795Z,1654019898.795 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-31T17:58:42.206Z,1654019922.206 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-31T18:03:19.377Z,1654020199.377 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-31T18:03:19.377Z,1654020199.377 [Default:CheckIn:C.Wait] Stopped 2022-05-31T18:03:19.377Z,1654020199.377 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-31T18:03:19.378Z,1654020199.378 [Default:CheckIn:D] Running Loop=1 2022-05-31T18:03:19.770Z,1654020199.770 [Default:CheckIn:D] Stopped 2022-05-31T18:03:19.770Z,1654020199.770 [Default:CheckIn:E] Running Loop=1 2022-05-31T18:03:20.175Z,1654020200.175 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 116.754940 min 2022-05-31T18:03:20.175Z,1654020200.175 [Default:CheckIn:E] Stopped 2022-05-31T18:03:20.176Z,1654020200.176 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-31T18:03:20.176Z,1654020200.176 [Default:CheckIn] Stopped 2022-05-31T18:03:20.176Z,1654020200.176 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-31T18:03:20.176Z,1654020200.176 [Default:CheckIn](INFO): Running loop #22 2022-05-31T18:03:20.176Z,1654020200.176 [Default:CheckIn] Running Loop=22 2022-05-31T18:03:20.176Z,1654020200.176 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-31T18:03:20.176Z,1654020200.176 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-31T18:03:22.190Z,1654020202.190 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180319.00,A,3648.17437,N,12147.28055,W,0.039,296.68,310522,,,D*71 2022-05-31T18:03:22.193Z,1654020202.193 [NAL9602](INFO): GPS fix at 20220531T180319: (36.802906, -121.788009) 2022-05-31T18:03:22.204Z,1654020202.204 [Default:CheckIn:Read_GPS] Stopped 2022-05-31T18:03:22.204Z,1654020202.204 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-31T18:03:29.935Z,1654020209.935 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20220531T161756/Courier0057.lzma 2022-05-31T18:03:30.937Z,1654020210.937 [DataOverHttps](INFO): Moved sent file to Logs/20220531T161756/Courier0057.lzma.bak 2022-05-31T18:03:30.938Z,1654020210.938 [DataOverHttps](INFO): SBD MOMSN=16845637 2022-05-31T18:03:46.871Z,1654020226.871 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20220531T161756/Express0058.lzma 2022-05-31T18:03:47.874Z,1654020227.874 [DataOverHttps](INFO): Moved sent file to Logs/20220531T161756/Express0058.lzma.bak 2022-05-31T18:03:47.874Z,1654020227.874 [DataOverHttps](INFO): SBD MOMSN=16845643 2022-05-31T18:03:49.265Z,1654020229.265 [Default:CheckIn:Read_Iridium] Stopped 2022-05-31T18:03:49.265Z,1654020229.265 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-31T18:03:49.265Z,1654020229.265 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-31T18:03:53.696Z,1654020233.696 [NAL9602](INFO): SBD MO Status=0, MOMSN=7857, MT Status=0, MTMSN=0 2022-05-31T18:03:53.696Z,1654020233.696 [NAL9602](INFO): No messages in MT queue 2022-05-31T18:04:24.400Z,1654020264.400 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-31T18:08:49.835Z,1654020529.835 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-31T18:08:49.835Z,1654020529.835 [Default:CheckIn:C.Wait] Stopped 2022-05-31T18:08:49.835Z,1654020529.835 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-31T18:08:49.836Z,1654020529.836 [Default:CheckIn:D] Running Loop=1 2022-05-31T18:08:50.245Z,1654020530.245 [Default:CheckIn:D] Stopped 2022-05-31T18:08:50.245Z,1654020530.245 [Default:CheckIn:E] Running Loop=1 2022-05-31T18:08:50.642Z,1654020530.642 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 122.262858 min 2022-05-31T18:08:50.642Z,1654020530.642 [Default:CheckIn:E] Stopped 2022-05-31T18:08:50.642Z,1654020530.642 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-31T18:08:50.643Z,1654020530.643 [Default:CheckIn] Stopped 2022-05-31T18:08:50.643Z,1654020530.643 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-31T18:08:50.643Z,1654020530.643 [Default:CheckIn](INFO): Running loop #23 2022-05-31T18:08:50.643Z,1654020530.643 [Default:CheckIn] Running Loop=23 2022-05-31T18:08:50.643Z,1654020530.643 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-31T18:08:50.643Z,1654020530.643 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-31T18:08:52.655Z,1654020532.655 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180849.00,A,3648.17433,N,12147.28010,W,0.039,296.68,310522,,,D*7A 2022-05-31T18:08:52.657Z,1654020532.657 [NAL9602](INFO): GPS fix at 20220531T180849: (36.802906, -121.788002) 2022-05-31T18:08:52.668Z,1654020532.668 [Default:CheckIn:Read_GPS] Stopped 2022-05-31T18:08:52.668Z,1654020532.668 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-31T18:09:00.423Z,1654020540.423 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20220531T161756/Courier0060.lzma 2022-05-31T18:09:01.425Z,1654020541.425 [DataOverHttps](INFO): Moved sent file to Logs/20220531T161756/Courier0060.lzma.bak 2022-05-31T18:09:01.426Z,1654020541.426 [DataOverHttps](INFO): SBD MOMSN=16845678 2022-05-31T18:09:17.411Z,1654020557.411 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20220531T161756/Express0061.lzma 2022-05-31T18:09:18.413Z,1654020558.413 [DataOverHttps](INFO): Moved sent file to Logs/20220531T161756/Express0061.lzma.bak 2022-05-31T18:09:18.414Z,1654020558.414 [DataOverHttps](INFO): SBD MOMSN=16845682 2022-05-31T18:09:19.753Z,1654020559.753 [Default:CheckIn:Read_Iridium] Stopped 2022-05-31T18:09:19.753Z,1654020559.753 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-31T18:09:19.754Z,1654020559.754 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-31T18:11:20.940Z,1654020680.940 [NAL9602](INFO): SBD MO Status=2, MOMSN=7858, MT Status=2, MTMSN=0 2022-05-31T18:11:20.941Z,1654020680.941 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-05-31T18:11:39.118Z,1654020699.118 [NAL9602](INFO): SBD MO Status=2, MOMSN=7858, MT Status=2, MTMSN=0 2022-05-31T18:11:39.118Z,1654020699.118 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-05-31T18:12:29.286Z,1654020749.286 [NAL9602](INFO): SBD MO Status=0, MOMSN=7858, MT Status=0, MTMSN=0 2022-05-31T18:12:29.286Z,1654020749.286 [NAL9602](INFO): No messages in MT queue 2022-05-31T18:12:59.986Z,1654020779.986 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-31T18:14:20.410Z,1654020860.410 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-31T18:14:20.410Z,1654020860.410 [Default:CheckIn:C.Wait] Stopped 2022-05-31T18:14:20.410Z,1654020860.410 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-31T18:14:20.410Z,1654020860.410 [Default:CheckIn:D] Running Loop=1 2022-05-31T18:14:20.819Z,1654020860.819 [Default:CheckIn:D] Stopped 2022-05-31T18:14:20.820Z,1654020860.820 [Default:CheckIn:E] Running Loop=1 2022-05-31T18:14:21.227Z,1654020861.227 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 127.772428 min 2022-05-31T18:14:21.227Z,1654020861.227 [Default:CheckIn:E] Stopped 2022-05-31T18:14:21.227Z,1654020861.227 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-31T18:14:21.227Z,1654020861.227 [Default:CheckIn] Stopped 2022-05-31T18:14:21.227Z,1654020861.227 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-31T18:14:21.227Z,1654020861.227 [Default:CheckIn](INFO): Running loop #24 2022-05-31T18:14:21.227Z,1654020861.227 [Default:CheckIn] Running Loop=24 2022-05-31T18:14:21.228Z,1654020861.228 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-31T18:14:21.228Z,1654020861.228 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-31T18:14:23.238Z,1654020863.238 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181420.00,A,3648.17350,N,12147.28364,W,0.097,296.68,310522,,,D*7E 2022-05-31T18:14:23.241Z,1654020863.241 [NAL9602](INFO): GPS fix at 20220531T181420: (36.802892, -121.788061) 2022-05-31T18:14:23.252Z,1654020863.252 [Default:CheckIn:Read_GPS] Stopped 2022-05-31T18:14:23.252Z,1654020863.252 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-31T18:14:30.255Z,1654020870.255 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220531T161756/Courier0063.lzma 2022-05-31T18:14:31.258Z,1654020871.258 [DataOverHttps](INFO): Moved sent file to Logs/20220531T161756/Courier0063.lzma.bak 2022-05-31T18:14:31.258Z,1654020871.258 [DataOverHttps](INFO): SBD MOMSN=16845720 2022-05-31T18:14:39.396Z,1654020879.396 [NAL9602](INFO): SBD MO Status=0, MOMSN=7859, MT Status=0, MTMSN=0 2022-05-31T18:14:39.396Z,1654020879.396 [NAL9602](INFO): No messages in MT queue 2022-05-31T18:14:47.159Z,1654020887.159 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20220531T161756/Express0064.lzma 2022-05-31T18:14:48.161Z,1654020888.161 [DataOverHttps](INFO): Moved sent file to Logs/20220531T161756/Express0064.lzma.bak 2022-05-31T18:14:48.162Z,1654020888.162 [DataOverHttps](INFO): SBD MOMSN=16845723 2022-05-31T18:14:49.499Z,1654020889.499 [Default:CheckIn:Read_Iridium] Stopped 2022-05-31T18:14:49.500Z,1654020889.500 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-31T18:14:49.500Z,1654020889.500 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-31T18:15:10.091Z,1654020910.091 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-31T18:19:50.169Z,1654021190.169 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-31T18:19:50.169Z,1654021190.169 [Default:CheckIn:C.Wait] Stopped 2022-05-31T18:19:50.169Z,1654021190.169 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-31T18:19:50.170Z,1654021190.170 [Default:CheckIn:D] Running Loop=1 2022-05-31T18:19:50.561Z,1654021190.561 [Default:CheckIn:D] Stopped 2022-05-31T18:19:50.561Z,1654021190.561 [Default:CheckIn:E] Running Loop=1 2022-05-31T18:19:50.964Z,1654021190.964 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 133.268123 min 2022-05-31T18:19:50.964Z,1654021190.964 [Default:CheckIn:E] Stopped 2022-05-31T18:19:50.964Z,1654021190.964 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-31T18:19:50.964Z,1654021190.964 [Default:CheckIn] Stopped 2022-05-31T18:19:50.964Z,1654021190.964 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-31T18:19:50.964Z,1654021190.964 [Default:CheckIn](INFO): Running loop #25 2022-05-31T18:19:50.964Z,1654021190.964 [Default:CheckIn] Running Loop=25 2022-05-31T18:19:50.964Z,1654021190.964 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-31T18:19:50.965Z,1654021190.965 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-31T18:19:52.974Z,1654021192.974 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181949.00,A,3648.17339,N,12147.27846,W,0.058,0.00,310522,,,D*77 2022-05-31T18:19:52.977Z,1654021192.977 [NAL9602](INFO): GPS fix at 20220531T181949: (36.802890, -121.787974) 2022-05-31T18:19:52.994Z,1654021192.994 [Default:CheckIn:Read_GPS] Stopped 2022-05-31T18:19:52.994Z,1654021192.994 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-31T18:20:00.711Z,1654021200.711 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220531T161756/Courier0066.lzma 2022-05-31T18:20:01.714Z,1654021201.714 [DataOverHttps](INFO): Moved sent file to Logs/20220531T161756/Courier0066.lzma.bak 2022-05-31T18:20:01.714Z,1654021201.714 [DataOverHttps](INFO): SBD MOMSN=16845728 2022-05-31T18:20:17.559Z,1654021217.559 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20220531T161756/Express0067.lzma 2022-05-31T18:20:18.562Z,1654021218.562 [DataOverHttps](INFO): Moved sent file to Logs/20220531T161756/Express0067.lzma.bak 2022-05-31T18:20:18.562Z,1654021218.562 [DataOverHttps](INFO): SBD MOMSN=16845731 2022-05-31T18:20:19.846Z,1654021219.846 [Default:CheckIn:Read_Iridium] Stopped 2022-05-31T18:20:19.846Z,1654021219.846 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-31T18:20:19.846Z,1654021219.846 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-31T18:20:20.234Z,1654021220.234 [NAL9602](INFO): SBD MO Status=0, MOMSN=7860, MT Status=0, MTMSN=0 2022-05-31T18:20:20.234Z,1654021220.234 [NAL9602](INFO): No messages in MT queue 2022-05-31T18:20:50.935Z,1654021250.935 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-31T18:25:20.433Z,1654021520.433 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-31T18:25:20.433Z,1654021520.433 [Default:CheckIn:C.Wait] Stopped 2022-05-31T18:25:20.433Z,1654021520.433 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-31T18:25:20.433Z,1654021520.433 [Default:CheckIn:D] Running Loop=1 2022-05-31T18:25:20.822Z,1654021520.822 [Default:CheckIn:D] Stopped 2022-05-31T18:25:20.822Z,1654021520.822 [Default:CheckIn:E] Running Loop=1 2022-05-31T18:25:21.225Z,1654021521.225 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 138.772461 min 2022-05-31T18:25:21.225Z,1654021521.225 [Default:CheckIn:E] Stopped 2022-05-31T18:25:21.225Z,1654021521.225 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-31T18:25:21.225Z,1654021521.225 [Default:CheckIn] Stopped 2022-05-31T18:25:21.225Z,1654021521.225 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-31T18:25:21.226Z,1654021521.226 [Default:CheckIn](INFO): Running loop #26 2022-05-31T18:25:21.226Z,1654021521.226 [Default:CheckIn] Running Loop=26 2022-05-31T18:25:21.226Z,1654021521.226 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-31T18:25:21.226Z,1654021521.226 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-31T18:25:23.238Z,1654021523.238 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182520.00,A,3648.17066,N,12147.28055,W,0.117,186.74,310522,,,D*7D 2022-05-31T18:25:23.252Z,1654021523.252 [NAL9602](INFO): GPS fix at 20220531T182520: (36.802844, -121.788009) 2022-05-31T18:25:23.264Z,1654021523.264 [Default:CheckIn:Read_GPS] Stopped 2022-05-31T18:25:23.264Z,1654021523.264 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-31T18:25:30.159Z,1654021530.159 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220531T161756/Courier0069.lzma 2022-05-31T18:25:31.161Z,1654021531.161 [DataOverHttps](INFO): Moved sent file to Logs/20220531T161756/Courier0069.lzma.bak 2022-05-31T18:25:31.162Z,1654021531.162 [DataOverHttps](INFO): SBD MOMSN=16845735 2022-05-31T18:25:49.243Z,1654021549.243 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20220531T161756/Express0070.lzma 2022-05-31T18:25:50.246Z,1654021550.246 [DataOverHttps](INFO): Moved sent file to Logs/20220531T161756/Express0070.lzma.bak 2022-05-31T18:25:50.246Z,1654021550.246 [DataOverHttps](INFO): SBD MOMSN=16845739 2022-05-31T18:25:51.651Z,1654021551.651 [Default:CheckIn:Read_Iridium] Stopped 2022-05-31T18:25:51.652Z,1654021551.652 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-31T18:25:51.652Z,1654021551.652 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-31T18:28:22.306Z,1654021702.306 [NAL9602](INFO): SBD MO Status=2, MOMSN=7861, MT Status=2, MTMSN=0 2022-05-31T18:28:22.307Z,1654021702.307 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-05-31T18:30:25.929Z,1654021825.929 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-05-31T18:30:52.209Z,1654021852.209 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-31T18:30:52.210Z,1654021852.210 [Default:CheckIn:C.Wait] Stopped 2022-05-31T18:30:52.210Z,1654021852.210 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-31T18:30:52.210Z,1654021852.210 [Default:CheckIn:D] Running Loop=1 2022-05-31T18:30:52.602Z,1654021852.602 [Default:CheckIn:D] Stopped 2022-05-31T18:30:52.603Z,1654021852.603 [Default:CheckIn:E] Running Loop=1 2022-05-31T18:30:53.005Z,1654021853.005 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 144.302148 min 2022-05-31T18:30:53.005Z,1654021853.005 [Default:CheckIn:E] Stopped 2022-05-31T18:30:53.005Z,1654021853.005 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-31T18:30:53.005Z,1654021853.005 [Default:CheckIn] Stopped 2022-05-31T18:30:53.005Z,1654021853.005 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-31T18:30:53.006Z,1654021853.006 [Default:CheckIn](INFO): Running loop #27 2022-05-31T18:30:53.006Z,1654021853.006 [Default:CheckIn] Running Loop=27 2022-05-31T18:30:53.006Z,1654021853.006 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-31T18:30:53.006Z,1654021853.006 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-31T18:30:55.022Z,1654021855.022 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183052.00,A,3648.16572,N,12147.28406,W,0.214,186.74,310522,,,D*7F 2022-05-31T18:30:55.024Z,1654021855.024 [NAL9602](INFO): GPS fix at 20220531T183052: (36.802762, -121.788068) 2022-05-31T18:30:55.036Z,1654021855.036 [Default:CheckIn:Read_GPS] Stopped 2022-05-31T18:30:55.036Z,1654021855.036 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-31T18:31:03.011Z,1654021863.011 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220531T161756/Courier0072.lzma 2022-05-31T18:31:04.013Z,1654021864.013 [DataOverHttps](INFO): Moved sent file to Logs/20220531T161756/Courier0072.lzma.bak 2022-05-31T18:31:04.014Z,1654021864.014 [DataOverHttps](INFO): SBD MOMSN=16845742 2022-05-31T18:31:19.827Z,1654021879.827 [DataOverHttps](INFO): Sending 208 bytes from file Logs/20220531T161756/Express0073.lzma 2022-05-31T18:31:20.830Z,1654021880.830 [DataOverHttps](INFO): Moved sent file to Logs/20220531T161756/Express0073.lzma.bak 2022-05-31T18:31:20.830Z,1654021880.830 [DataOverHttps](INFO): SBD MOMSN=16845745 2022-05-31T18:31:22.104Z,1654021882.104 [Default:CheckIn:Read_Iridium] Stopped 2022-05-31T18:31:22.105Z,1654021882.105 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-31T18:31:22.105Z,1654021882.105 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-31T18:31:27.744Z,1654021887.744 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-31T18:36:22.753Z,1654022182.753 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-31T18:36:22.753Z,1654022182.753 [Default:CheckIn:C.Wait] Stopped 2022-05-31T18:36:22.753Z,1654022182.753 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-31T18:36:22.753Z,1654022182.753 [Default:CheckIn:D] Running Loop=1 2022-05-31T18:36:23.147Z,1654022183.147 [Default:CheckIn:D] Stopped 2022-05-31T18:36:23.147Z,1654022183.147 [Default:CheckIn:E] Running Loop=1 2022-05-31T18:36:23.546Z,1654022183.546 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 149.811214 min 2022-05-31T18:36:23.546Z,1654022183.546 [Default:CheckIn:E] Stopped 2022-05-31T18:36:23.547Z,1654022183.547 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-31T18:36:23.547Z,1654022183.547 [Default:CheckIn] Stopped 2022-05-31T18:36:23.547Z,1654022183.547 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-31T18:36:23.547Z,1654022183.547 [Default:CheckIn](INFO): Running loop #28 2022-05-31T18:36:23.547Z,1654022183.547 [Default:CheckIn] Running Loop=28 2022-05-31T18:36:23.547Z,1654022183.547 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-31T18:36:23.547Z,1654022183.547 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-31T18:36:56.264Z,1654022216.264 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-05-31T18:36:56.339Z,1654022216.339 [NAL9602](ERROR): received: +CSQ:0 OK61, 2, 0, 0, 0 OK 2022-05-31T18:41:23.740Z,1654022483.740 [Default:CheckIn:Read_GPS](INFO): Timed out from 2022-05-31T18:36:23.5Z 2022-05-31T18:41:23.740Z,1654022483.740 [Default:CheckIn:Read_GPS] Stopped 2022-05-31T18:41:23.740Z,1654022483.740 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-31T18:41:27.769Z,1654022487.769 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-05-31T18:41:31.415Z,1654022491.415 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20220531T161756/Courier0075.lzma 2022-05-31T18:41:32.417Z,1654022492.417 [DataOverHttps](INFO): Moved sent file to Logs/20220531T161756/Courier0075.lzma.bak 2022-05-31T18:41:32.418Z,1654022492.418 [DataOverHttps](INFO): SBD MOMSN=16845749 2022-05-31T18:41:52.043Z,1654022512.043 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20220531T161756/Express0076.lzma 2022-05-31T18:41:53.046Z,1654022513.046 [DataOverHttps](INFO): Moved sent file to Logs/20220531T161756/Express0076.lzma.bak 2022-05-31T18:41:53.046Z,1654022513.046 [DataOverHttps](INFO): SBD MOMSN=16845751 2022-05-31T18:41:54.520Z,1654022514.520 [Default:CheckIn:Read_Iridium] Stopped 2022-05-31T18:41:54.520Z,1654022514.520 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-31T18:41:54.520Z,1654022514.520 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-31T18:41:58.551Z,1654022518.551 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-31T18:42:21.973Z,1654022541.973 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2022-05-31T18:42:21.975Z,1654022541.975 [BPC1](INFO): Received data from all battery sticks. 2022-05-31T18:46:55.127Z,1654022815.127 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-31T18:46:55.127Z,1654022815.127 [Default:CheckIn:C.Wait] Stopped 2022-05-31T18:46:55.127Z,1654022815.127 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-31T18:46:55.128Z,1654022815.128 [Default:CheckIn:D] Running Loop=1 2022-05-31T18:46:55.549Z,1654022815.549 [Default:CheckIn:D] Stopped 2022-05-31T18:46:55.549Z,1654022815.549 [Default:CheckIn:E] Running Loop=1 2022-05-31T18:46:55.932Z,1654022815.932 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 160.351253 min 2022-05-31T18:46:55.932Z,1654022815.932 [Default:CheckIn:E] Stopped 2022-05-31T18:46:55.932Z,1654022815.932 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-31T18:46:55.932Z,1654022815.932 [Default:CheckIn] Stopped 2022-05-31T18:46:55.932Z,1654022815.932 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-31T18:46:55.932Z,1654022815.932 [Default:CheckIn](INFO): Running loop #29 2022-05-31T18:46:55.932Z,1654022815.932 [Default:CheckIn] Running Loop=29 2022-05-31T18:46:55.933Z,1654022815.933 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-31T18:46:55.933Z,1654022815.933 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-31T18:46:57.535Z,1654022817.535 [NAL9602](FAULT): GPS failed to acquire within timeout. 2022-05-31T18:46:57.535Z,1654022817.535 [NAL9602] Data Fault, FailCount= 1 2022-05-31T18:46:57.535Z,1654022817.535 [NAL9602](ERROR): Data Fault 2022-05-31T18:46:57.568Z,1654022817.568 [CBIT](ERROR): Data Fault in component: NAL9602 2022-05-31T18:46:57.943Z,1654022817.943 [NAL9602](INFO): Powering down 2022-05-31T18:46:58.777Z,1654022818.777 [CBIT](INFO): Clearing failed state for component NAL9602 2022-05-31T18:46:58.777Z,1654022818.777 [NAL9602] No Fault, FailCount= 1 2022-05-31T18:47:28.239Z,1654022848.239 [NAL9602](INFO): Powering up NAL9602 2022-05-31T18:47:39.151Z,1654022859.151 [NAL9602](INFO): NAL9602 initialized 2022-05-31T18:50:57.488Z,1654023057.488 [CommandExec](IMPORTANT): got command quit 2022-05-31T18:50:58.492Z,1654023058.492 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread. 2022-05-31T18:50:58.492Z,1654023058.492 [CommandExec](INFO): Uninitializing the command executive. 2022-05-31T18:50:58.492Z,1654023058.492 [CommandExec](INFO): Uninitializing the command scheduler. 2022-05-31T18:50:58.492Z,1654023058.492 [CommandExec ThreadHandler](INFO): Thread cancelled. 2022-05-31T18:50:58.680Z,1654023058.680 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2022-05-31T18:50:58.680Z,1654023058.680 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2022-05-31T18:50:58.680Z,1654023058.680 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2022-05-31T18:50:58.681Z,1654023058.681 [NavChartDb](INFO): Join timeout helper Thread ID is 5908 2022-05-31T18:50:58.868Z,1654023058.868 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2022-05-31T18:50:58.868Z,1654023058.868 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2022-05-31T18:50:58.880Z,1654023058.880 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2022-05-31T18:50:58.880Z,1654023058.880 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2022-05-31T18:50:58.880Z,1654023058.880 [Radio_Surface](INFO): Join timeout helper Thread ID is 5909 2022-05-31T18:50:58.948Z,1654023058.948 [Radio_Surface](INFO): Powering down 2022-05-31T18:50:58.949Z,1654023058.949 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2022-05-31T18:50:58.949Z,1654023058.949 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2022-05-31T18:50:58.956Z,1654023058.956 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler 2022-05-31T18:50:58.956Z,1654023058.956 [Onboard ThreadHandler](INFO): Thread cancelled. 2022-05-31T18:50:58.956Z,1654023058.956 [Onboard](INFO): Join timeout helper Thread ID is 5910 2022-05-31T18:50:59.664Z,1654023059.664 [DataOverHttps](INFO): Radio surface powered OFF, will not connect. 2022-05-31T18:51:01.088Z,1654023061.088 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread. 2022-05-31T18:51:01.088Z,1654023061.088 [Onboard ThreadHandler](INFO): Thread cancelled. 2022-05-31T18:51:01.100Z,1654023061.100 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2022-05-31T18:51:01.100Z,1654023061.100 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2022-05-31T18:51:01.100Z,1654023061.100 [DataOverHttps](INFO): Join timeout helper Thread ID is 5911 2022-05-31T18:51:01.672Z,1654023061.672 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2022-05-31T18:51:01.672Z,1654023061.672 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2022-05-31T18:51:01.676Z,1654023061.676 [ComponentRegistry](INFO): Shutting down BackseatComponent ThreadHandler 2022-05-31T18:51:01.676Z,1654023061.676 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2022-05-31T18:51:01.676Z,1654023061.676 [BackseatComponent](INFO): Join timeout helper Thread ID is 5912 2022-05-31T18:51:01.824Z,1654023061.824 [BackseatComponent ThreadHandler](INFO): Uninitializing protected caller thread. 2022-05-31T18:51:01.824Z,1654023061.824 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2022-05-31T18:51:01.845Z,1654023061.845 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2022-05-31T18:51:01.845Z,1654023061.845 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2022-05-31T18:51:01.845Z,1654023061.845 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 5913 2022-05-31T18:51:02.264Z,1654023062.264 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2022-05-31T18:51:02.264Z,1654023062.264 [WetLabsBB2FL](INFO): Powering down 2022-05-31T18:51:02.265Z,1654023062.265 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2022-05-31T18:51:02.284Z,1654023062.284 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2022-05-31T18:51:02.284Z,1654023062.284 [logger ThreadHandler](INFO): Thread cancelled. 2022-05-31T18:51:02.285Z,1654023062.285 [logger](INFO): Join timeout helper Thread ID is 5914 2022-05-31T18:51:02.308Z,1654023062.308 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2022-05-31T18:51:02.308Z,1654023062.308 [logger ThreadHandler](INFO): Thread cancelled. 2022-05-31T18:51:02.312Z,1654023062.312 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2022-05-31T18:51:02.313Z,1654023062.313 [CommandLine ThreadHandler](INFO): Thread cancelled. 2022-05-31T18:51:02.313Z,1654023062.313 [CommandLine](INFO): Join timeout helper Thread ID is 5915 2022-05-31T18:51:02.360Z,1654023062.360 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2022-05-31T18:51:02.360Z,1654023062.360 [CommandLine ThreadHandler](INFO): Thread cancelled. 2022-05-31T18:51:02.363Z,1654023062.363 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler 2022-05-31T18:51:02.363Z,1654023062.363 [CommandExec ThreadHandler](INFO): Thread cancelled. 2022-05-31T18:51:02.363Z,1654023062.363 [CommandExec](INFO): Join timeout helper Thread ID is 5916 2022-05-31T18:51:02.384Z,1654023062.384 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2022-05-31T18:51:02.384Z,1654023062.384 [controlThread ThreadHandler](INFO): Thread cancelled. 2022-05-31T18:51:02.385Z,1654023062.385 [controlThread](INFO): Join timeout helper Thread ID is 5917 2022-05-31T18:51:02.422Z,1654023062.422 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2022-05-31T18:51:02.422Z,1654023062.422 [controlThread](DEBUG): Uninitializing ControlThread 2022-05-31T18:51:02.423Z,1654023062.423 [AHRS_M2](INFO): Powering down 2022-05-31T18:51:02.500Z,1654023062.500 [NAL9602](INFO): Powering down 2022-05-31T18:51:02.502Z,1654023062.502 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2022-05-31T18:51:02.503Z,1654023062.503 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2022-05-31T18:51:02.504Z,1654023062.504 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2022-05-31T18:51:02.504Z,1654023062.504 [MissionManager](INFO): Uninitializing Mission Default 2022-05-31T18:51:02.504Z,1654023062.504 [Default] Stopped 2022-05-31T18:51:02.504Z,1654023062.504 [Default](DEBUG): Aggregate::uninitialize Default 2022-05-31T18:51:02.505Z,1654023062.505 [Default:B.GoToSurface] Stopped 2022-05-31T18:51:02.505Z,1654023062.505 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2022-05-31T18:51:02.505Z,1654023062.505 [Default:CheckIn] Stopped 2022-05-31T18:51:02.505Z,1654023062.505 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-31T18:51:02.505Z,1654023062.505 [Default:CheckIn:Read_GPS] Stopped 2022-05-31T18:51:02.508Z,1654023062.508 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2022-05-31T18:51:02.508Z,1654023062.508 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2022-05-31T18:51:02.508Z,1654023062.508 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2022-05-31T18:51:02.509Z,1654023062.509 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2022-05-31T18:51:02.509Z,1654023062.509 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2022-05-31T18:51:02.509Z,1654023062.509 [BuoyancyServo](INFO): Powering down 2022-05-31T18:51:02.524Z,1654023062.524 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2022-05-31T18:51:02.524Z,1654023062.524 [ElevatorServo](INFO): Powering down 2022-05-31T18:51:02.525Z,1654023062.525 [MassServo](DEBUG): Uninitialize Mass Servo. 2022-05-31T18:51:02.525Z,1654023062.525 [MassServo](INFO): Powering down 2022-05-31T18:51:02.526Z,1654023062.526 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2022-05-31T18:51:02.526Z,1654023062.526 [RudderServo](INFO): Powering down 2022-05-31T18:51:02.527Z,1654023062.527 [ThrusterHE](DEBUG): Uninitialize Thruster Servo. 2022-05-31T18:51:02.527Z,1654023062.527 [ThrusterHE](INFO): Powering down 2022-05-31T18:51:02.528Z,1654023062.528 [SBIT](DEBUG): Uninitialize SBIT Component. 2022-05-31T18:51:02.528Z,1654023062.528 [IBIT](DEBUG): Uninitialize IBIT Component. 2022-05-31T18:51:02.529Z,1654023062.529 [CBIT](DEBUG): Uninitialize CBIT Component. 2022-05-31T18:51:02.529Z,1654023062.529 [CBIT](DEBUG): Powering off loads. 2022-05-31T18:51:02.540Z,1654023062.540 [CBIT](DEBUG): Disabling WDT. 2022-05-31T18:51:02.552Z,1654023062.552 [CBIT](DEBUG): Opening all GF detection circuits. 2022-05-31T18:51:02.553Z,1654023062.553 [controlThread ThreadHandler](INFO): Thread cancelled. 2022-05-31T18:51:02.637Z,1654023062.637 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2022-05-31T18:51:02.728Z,1654023062.728 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2022-05-31T18:51:02.746Z,1654023062.746 [Onboard ThreadHandler](INFO): Thread cancelled. 2022-05-31T18:51:02.752Z,1654023062.752 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2022-05-31T18:51:02.832Z,1654023062.832 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2022-05-31T18:51:02.922Z,1654023062.922 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2022-05-31T18:51:03.085Z,1654023063.085 [logger ThreadHandler](INFO): Thread cancelled.