2021-07-29T17:15:18.139Z,1627578918.139 [DataOverHttps](INFO): Received command:restart logs 2021-07-29T17:15:18.144Z,1627578918.144 [CommandLine](IMPORTANT): got command restart logs 2021-07-29T17:15:24.658Z,1627578924.658 [NAL9602](INFO): SBD MO Status=2, MOMSN=28605, MT Status=2, MTMSN=0 2021-07-29T17:15:24.658Z,1627578924.658 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-29T17:16:10.722Z,1627578970.722 [NAL9602](INFO): SBD MO Status=2, MOMSN=28605, MT Status=2, MTMSN=0 2021-07-29T17:16:10.722Z,1627578970.722 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-29T17:16:37.418Z,1627578997.418 [NAL9602](INFO): SBD MO Status=2, MOMSN=28605, MT Status=2, MTMSN=0 2021-07-29T17:16:37.418Z,1627578997.418 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-29T17:16:47.571Z,1627579007.571 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-07-29T17:11:47.4Z 2021-07-29T17:16:47.571Z,1627579007.571 [Default:CheckIn:Read_GPS] Stopped 2021-07-29T17:16:47.575Z,1627579007.575 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-29T17:16:50.364Z,1627579010.364 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20210729T161842/Courier0009.lzma 2021-07-29T17:16:51.369Z,1627579011.369 [DataOverHttps](INFO): Moved sent file to Logs/20210729T161842/Courier0009.lzma.bak 2021-07-29T17:16:51.369Z,1627579011.369 [DataOverHttps](INFO): SBD MOMSN=15774214 2021-07-29T17:16:53.242Z,1627579013.242 [NAL9602](INFO): SBD MO Status=2, MOMSN=28605, MT Status=2, MTMSN=0 2021-07-29T17:16:53.242Z,1627579013.242 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-29T17:17:08.687Z,1627579028.687 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20210729T171518/Courier0000.lzma 2021-07-29T17:17:09.690Z,1627579029.690 [DataOverHttps](INFO): Moved sent file to Logs/20210729T171518/Courier0000.lzma.bak 2021-07-29T17:17:09.690Z,1627579029.690 [DataOverHttps](INFO): SBD MOMSN=15774216 2021-07-29T17:17:29.335Z,1627579049.335 [DataOverHttps](INFO): Sending 315 bytes from file Logs/20210729T161842/Express0010.lzma 2021-07-29T17:17:30.197Z,1627579050.197 [DataOverHttps](INFO): Moved sent file to Logs/20210729T161842/Express0010.lzma.bak 2021-07-29T17:17:30.197Z,1627579050.197 [DataOverHttps](INFO): SBD MOMSN=15774219 2021-07-29T17:17:34.037Z,1627579054.037 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-29T17:17:48.511Z,1627579068.511 [DataOverHttps](INFO): Sending 312 bytes from file Logs/20210729T171518/Express0001.lzma 2021-07-29T17:17:49.513Z,1627579069.513 [DataOverHttps](INFO): Moved sent file to Logs/20210729T171518/Express0001.lzma.bak 2021-07-29T17:17:49.513Z,1627579069.513 [DataOverHttps](INFO): SBD MOMSN=15774226 2021-07-29T17:18:04.744Z,1627579084.744 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-29T17:18:09.065Z,1627579089.065 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20210729T171518/Express0004.lzma 2021-07-29T17:18:10.065Z,1627579090.065 [DataOverHttps](INFO): Moved sent file to Logs/20210729T171518/Express0004.lzma.bak 2021-07-29T17:18:10.065Z,1627579090.065 [DataOverHttps](INFO): SBD MOMSN=15774229 2021-07-29T17:18:13.675Z,1627579093.675 [Default:CheckIn:Read_Iridium] Stopped 2021-07-29T17:18:13.679Z,1627579093.679 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-29T17:18:13.679Z,1627579093.679 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-29T17:23:14.357Z,1627579394.357 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-29T17:23:14.357Z,1627579394.357 [Default:CheckIn:C.Wait] Stopped 2021-07-29T17:23:14.357Z,1627579394.357 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-29T17:23:14.358Z,1627579394.358 [Default:CheckIn:D] Running Loop=1 2021-07-29T17:23:14.768Z,1627579394.768 [Default:CheckIn:D] Stopped 2021-07-29T17:23:14.768Z,1627579394.768 [Default:CheckIn:E] Running Loop=1 2021-07-29T17:23:15.191Z,1627579395.191 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 22.706248 min 2021-07-29T17:23:15.191Z,1627579395.191 [Default:CheckIn:E] Stopped 2021-07-29T17:23:15.191Z,1627579395.191 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-29T17:23:15.191Z,1627579395.191 [Default:CheckIn] Stopped 2021-07-29T17:23:15.191Z,1627579395.191 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-29T17:23:15.191Z,1627579395.191 [Default:CheckIn](INFO): Running loop #3 2021-07-29T17:23:15.191Z,1627579395.191 [Default:CheckIn] Running Loop=3 2021-07-29T17:23:15.192Z,1627579395.192 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-29T17:23:15.192Z,1627579395.192 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-29T17:23:16.768Z,1627579396.768 [NAL9602](FAULT): GPS failed to acquire within timeout. 2021-07-29T17:23:16.768Z,1627579396.768 [NAL9602] Data Fault, FailCount= 2 2021-07-29T17:23:16.768Z,1627579396.768 [NAL9602](ERROR): Data Fault 2021-07-29T17:23:16.806Z,1627579396.806 [CBIT](ERROR): Data Fault in component: NAL9602 2021-07-29T17:23:17.173Z,1627579397.173 [NAL9602](INFO): Powering down 2021-07-29T17:23:18.026Z,1627579398.026 [CBIT](INFO): Clearing failed state for component NAL9602 2021-07-29T17:23:18.026Z,1627579398.026 [NAL9602] No Fault, FailCount= 2 2021-07-29T17:23:47.473Z,1627579427.473 [NAL9602](INFO): Powering up NAL9602 2021-07-29T17:23:58.385Z,1627579438.385 [NAL9602](INFO): NAL9602 initialized 2021-07-29T17:25:15.144Z,1627579515.144 [NAL9602](INFO): SBD MO Status=2, MOMSN=28605, MT Status=2, MTMSN=0 2021-07-29T17:25:15.145Z,1627579515.145 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-29T17:27:24.054Z,1627579644.054 [NAL9602](INFO): SBD MO Status=2, MOMSN=28605, MT Status=2, MTMSN=0 2021-07-29T17:27:24.054Z,1627579644.054 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-29T17:28:15.381Z,1627579695.381 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-07-29T17:23:15.2Z 2021-07-29T17:28:15.381Z,1627579695.381 [Default:CheckIn:Read_GPS] Stopped 2021-07-29T17:28:15.382Z,1627579695.382 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-29T17:28:27.575Z,1627579707.575 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20210729T171518/Courier0006.lzma 2021-07-29T17:28:28.577Z,1627579708.577 [DataOverHttps](INFO): Moved sent file to Logs/20210729T171518/Courier0006.lzma.bak 2021-07-29T17:28:28.578Z,1627579708.578 [DataOverHttps](INFO): SBD MOMSN=15774282 2021-07-29T17:28:52.687Z,1627579732.687 [DataOverHttps](INFO): Sending 268 bytes from file Logs/20210729T171518/Express0007.lzma 2021-07-29T17:28:53.691Z,1627579733.691 [DataOverHttps](INFO): Moved sent file to Logs/20210729T171518/Express0007.lzma.bak 2021-07-29T17:28:53.691Z,1627579733.691 [DataOverHttps](INFO): SBD MOMSN=15774284 2021-07-29T17:28:57.962Z,1627579737.962 [Default:CheckIn:Read_Iridium] Stopped 2021-07-29T17:28:57.962Z,1627579737.962 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-29T17:28:57.962Z,1627579737.962 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-29T17:29:01.977Z,1627579741.977 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-29T17:29:32.686Z,1627579772.686 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-29T17:33:58.563Z,1627580038.563 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-29T17:33:58.563Z,1627580038.563 [Default:CheckIn:C.Wait] Stopped 2021-07-29T17:33:58.564Z,1627580038.564 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-29T17:33:58.564Z,1627580038.564 [Default:CheckIn:D] Running Loop=1 2021-07-29T17:33:58.967Z,1627580038.967 [Default:CheckIn:D] Stopped 2021-07-29T17:33:58.968Z,1627580038.968 [Default:CheckIn:E] Running Loop=1 2021-07-29T17:33:59.380Z,1627580039.380 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 33.442906 min 2021-07-29T17:33:59.380Z,1627580039.380 [Default:CheckIn:E] Stopped 2021-07-29T17:33:59.380Z,1627580039.380 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-29T17:33:59.380Z,1627580039.380 [Default:CheckIn] Stopped 2021-07-29T17:33:59.381Z,1627580039.381 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-29T17:33:59.381Z,1627580039.381 [Default:CheckIn](INFO): Running loop #4 2021-07-29T17:33:59.381Z,1627580039.381 [Default:CheckIn] Running Loop=4 2021-07-29T17:33:59.381Z,1627580039.381 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-29T17:33:59.381Z,1627580039.381 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-29T17:34:00.978Z,1627580040.978 [NAL9602](FAULT): GPS failed to acquire within timeout. 2021-07-29T17:34:00.978Z,1627580040.978 [NAL9602] Data Fault, FailCount= 3 2021-07-29T17:34:00.978Z,1627580040.978 [NAL9602](ERROR): Data Fault 2021-07-29T17:34:01.003Z,1627580041.003 [CBIT](ERROR): Data Fault in component: NAL9602 2021-07-29T17:34:01.384Z,1627580041.384 [NAL9602](INFO): Powering down 2021-07-29T17:34:02.216Z,1627580042.216 [CBIT](INFO): Clearing failed state for component NAL9602 2021-07-29T17:34:02.216Z,1627580042.216 [NAL9602] No Fault, FailCount= 3 2021-07-29T17:34:31.680Z,1627580071.680 [NAL9602](INFO): Powering up NAL9602 2021-07-29T17:34:42.589Z,1627580082.589 [NAL9602](INFO): NAL9602 initialized 2021-07-29T17:36:03.794Z,1627580163.794 [NAL9602](INFO): SBD MO Status=2, MOMSN=28605, MT Status=2, MTMSN=0 2021-07-29T17:36:03.794Z,1627580163.794 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-29T17:38:59.716Z,1627580339.716 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-07-29T17:33:59.4Z 2021-07-29T17:38:59.716Z,1627580339.716 [Default:CheckIn:Read_GPS] Stopped 2021-07-29T17:38:59.717Z,1627580339.717 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-29T17:39:08.655Z,1627580348.655 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20210729T171518/Courier0009.lzma 2021-07-29T17:39:09.657Z,1627580349.657 [DataOverHttps](INFO): Moved sent file to Logs/20210729T171518/Courier0009.lzma.bak 2021-07-29T17:39:09.657Z,1627580349.657 [DataOverHttps](INFO): SBD MOMSN=15774326 2021-07-29T17:39:28.431Z,1627580368.431 [DataOverHttps](INFO): Sending 224 bytes from file Logs/20210729T171518/Express0010.lzma 2021-07-29T17:39:30.285Z,1627580370.285 [DataOverHttps](INFO): Moved sent file to Logs/20210729T171518/Express0010.lzma.bak 2021-07-29T17:39:30.286Z,1627580370.286 [DataOverHttps](INFO): SBD MOMSN=15774328 2021-07-29T17:39:33.229Z,1627580373.229 [Default:CheckIn:Read_Iridium] Stopped 2021-07-29T17:39:33.229Z,1627580373.229 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-29T17:39:33.229Z,1627580373.229 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-29T17:39:46.125Z,1627580386.125 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-29T17:40:16.828Z,1627580416.828 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-29T17:43:40.634Z,1627580620.634 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2021-07-29T17:43:40.661Z,1627580620.661 [BPC1](INFO): Received data from all battery sticks. 2021-07-29T17:44:33.643Z,1627580673.643 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-29T17:44:33.643Z,1627580673.643 [Default:CheckIn:C.Wait] Stopped 2021-07-29T17:44:33.643Z,1627580673.643 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-29T17:44:33.647Z,1627580673.647 [Default:CheckIn:D] Running Loop=1 2021-07-29T17:44:34.060Z,1627580674.060 [Default:CheckIn:D] Stopped 2021-07-29T17:44:34.060Z,1627580674.060 [Default:CheckIn:E] Running Loop=1 2021-07-29T17:44:34.453Z,1627580674.453 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 44.027787 min 2021-07-29T17:44:34.453Z,1627580674.453 [Default:CheckIn:E] Stopped 2021-07-29T17:44:34.453Z,1627580674.453 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-29T17:44:34.454Z,1627580674.454 [Default:CheckIn] Stopped 2021-07-29T17:44:34.454Z,1627580674.454 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-29T17:44:34.454Z,1627580674.454 [Default:CheckIn](INFO): Running loop #5 2021-07-29T17:44:34.454Z,1627580674.454 [Default:CheckIn] Running Loop=5 2021-07-29T17:44:34.454Z,1627580674.454 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-29T17:44:34.454Z,1627580674.454 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-29T17:44:36.455Z,1627580676.455 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174435.00,A,3648.15808,N,12147.28633,W,0.156,179.74,290721,,,A*7D 2021-07-29T17:44:36.457Z,1627580676.457 [NAL9602](INFO): GPS fix at 20210729T174435: (36.802635, -121.788106) 2021-07-29T17:44:36.469Z,1627580676.469 [Default:CheckIn:Read_GPS] Stopped 2021-07-29T17:44:36.469Z,1627580676.469 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-29T17:44:45.075Z,1627580685.075 [DataOverHttps](INFO): Sending 286 bytes from file Logs/20210729T171518/Courier0012.lzma 2021-07-29T17:44:46.077Z,1627580686.077 [DataOverHttps](INFO): Moved sent file to Logs/20210729T171518/Courier0012.lzma.bak 2021-07-29T17:44:46.078Z,1627580686.078 [DataOverHttps](INFO): SBD MOMSN=15774341 2021-07-29T17:45:04.340Z,1627580704.340 [DataOverHttps](INFO): Sending 215 bytes from file Logs/20210729T171518/Express0013.lzma 2021-07-29T17:45:05.341Z,1627580705.341 [DataOverHttps](INFO): Moved sent file to Logs/20210729T171518/Express0013.lzma.bak 2021-07-29T17:45:05.341Z,1627580705.341 [DataOverHttps](INFO): SBD MOMSN=15774344 2021-07-29T17:45:07.153Z,1627580707.153 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-07-29T17:45:07.227Z,1627580707.227 [NAL9602](ERROR): received: +CSQ:0 OK605, 2, 0, 0, 0 OK 2021-07-29T17:45:09.217Z,1627580709.217 [Default:CheckIn:Read_Iridium] Stopped 2021-07-29T17:45:09.217Z,1627580709.217 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-29T17:45:09.217Z,1627580709.217 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-29T17:45:35.438Z,1627580735.438 [NAL9602](INFO): SBD MO Status=2, MOMSN=28605, MT Status=2, MTMSN=0 2021-07-29T17:45:35.438Z,1627580735.438 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-29T17:49:38.361Z,1627580978.361 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-29T17:50:09.058Z,1627581009.058 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-29T17:50:09.880Z,1627581009.880 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-29T17:50:09.880Z,1627581009.880 [Default:CheckIn:C.Wait] Stopped 2021-07-29T17:50:09.880Z,1627581009.880 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-29T17:50:09.880Z,1627581009.880 [Default:CheckIn:D] Running Loop=1 2021-07-29T17:50:10.279Z,1627581010.279 [Default:CheckIn:D] Stopped 2021-07-29T17:50:10.280Z,1627581010.280 [Default:CheckIn:E] Running Loop=1 2021-07-29T17:50:10.686Z,1627581010.686 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 49.631437 min 2021-07-29T17:50:10.686Z,1627581010.686 [Default:CheckIn:E] Stopped 2021-07-29T17:50:10.686Z,1627581010.686 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-29T17:50:10.686Z,1627581010.686 [Default:CheckIn] Stopped 2021-07-29T17:50:10.686Z,1627581010.686 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-29T17:50:10.686Z,1627581010.686 [Default:CheckIn](INFO): Running loop #6 2021-07-29T17:50:10.686Z,1627581010.686 [Default:CheckIn] Running Loop=6 2021-07-29T17:50:10.687Z,1627581010.687 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-29T17:50:10.687Z,1627581010.687 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-29T17:50:12.695Z,1627581012.695 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175011.00,A,3648.16252,N,12147.27927,W,0.194,179.74,290721,,,A*73 2021-07-29T17:50:12.697Z,1627581012.697 [NAL9602](INFO): GPS fix at 20210729T175011: (36.802709, -121.787988) 2021-07-29T17:50:12.733Z,1627581012.733 [Default:CheckIn:Read_GPS] Stopped 2021-07-29T17:50:12.733Z,1627581012.733 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-29T17:50:24.575Z,1627581024.575 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210729T171518/Courier0015.lzma 2021-07-29T17:50:25.577Z,1627581025.577 [DataOverHttps](INFO): Moved sent file to Logs/20210729T171518/Courier0015.lzma.bak 2021-07-29T17:50:25.577Z,1627581025.577 [DataOverHttps](INFO): SBD MOMSN=15774389 2021-07-29T17:50:43.393Z,1627581043.393 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-07-29T17:50:43.467Z,1627581043.467 [NAL9602](ERROR): received: +CSQ:0 OK605, 2, 0, 0, 0 OK 2021-07-29T17:50:48.878Z,1627581048.878 [DataOverHttps](INFO): Sending 205 bytes from file Logs/20210729T171518/Express0016.lzma 2021-07-29T17:50:50.434Z,1627581050.434 [DataOverHttps](INFO): Moved sent file to Logs/20210729T171518/Express0016.lzma.bak 2021-07-29T17:50:50.434Z,1627581050.434 [DataOverHttps](INFO): SBD MOMSN=15774392 2021-07-29T17:50:53.514Z,1627581053.514 [Default:CheckIn:Read_Iridium] Stopped 2021-07-29T17:50:53.515Z,1627581053.515 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-29T17:50:53.515Z,1627581053.515 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-29T17:55:15.741Z,1627581315.741 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-29T17:55:46.440Z,1627581346.440 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-29T17:55:54.141Z,1627581354.141 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-29T17:55:54.141Z,1627581354.141 [Default:CheckIn:C.Wait] Stopped 2021-07-29T17:55:54.141Z,1627581354.141 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-29T17:55:54.141Z,1627581354.141 [Default:CheckIn:D] Running Loop=1 2021-07-29T17:55:54.532Z,1627581354.532 [Default:CheckIn:D] Stopped 2021-07-29T17:55:54.532Z,1627581354.532 [Default:CheckIn:E] Running Loop=1 2021-07-29T17:55:54.941Z,1627581354.941 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 55.368978 min 2021-07-29T17:55:54.941Z,1627581354.941 [Default:CheckIn:E] Stopped 2021-07-29T17:55:54.941Z,1627581354.941 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-29T17:55:54.941Z,1627581354.941 [Default:CheckIn] Stopped 2021-07-29T17:55:54.941Z,1627581354.941 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-29T17:55:54.941Z,1627581354.941 [Default:CheckIn](INFO): Running loop #7 2021-07-29T17:55:54.941Z,1627581354.941 [Default:CheckIn] Running Loop=7 2021-07-29T17:55:54.941Z,1627581354.941 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-29T17:55:54.942Z,1627581354.942 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-29T17:55:56.951Z,1627581356.951 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175556.00,A,3648.16220,N,12147.28324,W,0.117,179.74,290721,,,A*7D 2021-07-29T17:55:56.953Z,1627581356.953 [NAL9602](INFO): GPS fix at 20210729T175556: (36.802703, -121.788054) 2021-07-29T17:55:56.965Z,1627581356.965 [Default:CheckIn:Read_GPS] Stopped 2021-07-29T17:55:56.965Z,1627581356.965 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-29T17:56:05.423Z,1627581365.423 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210729T171518/Courier0018.lzma 2021-07-29T17:56:06.425Z,1627581366.425 [DataOverHttps](INFO): Moved sent file to Logs/20210729T171518/Courier0018.lzma.bak 2021-07-29T17:56:06.425Z,1627581366.425 [DataOverHttps](INFO): SBD MOMSN=15774404 2021-07-29T17:56:27.705Z,1627581387.705 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-07-29T17:56:27.768Z,1627581387.768 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20210729T171518/Express0019.lzma 2021-07-29T17:56:27.787Z,1627581387.787 [NAL9602](ERROR): received: +CSQ:0 OK605, 2, 0, 0, 0 OK 2021-07-29T17:56:28.769Z,1627581388.769 [DataOverHttps](INFO): Moved sent file to Logs/20210729T171518/Express0019.lzma.bak 2021-07-29T17:56:28.769Z,1627581388.769 [DataOverHttps](INFO): SBD MOMSN=15774407 2021-07-29T17:56:34.671Z,1627581394.671 [Default:CheckIn:Read_Iridium] Stopped 2021-07-29T17:56:34.671Z,1627581394.671 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-29T17:56:34.717Z,1627581394.717 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-29T18:00:59.504Z,1627581659.504 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-29T18:01:30.212Z,1627581690.212 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-29T18:01:35.474Z,1627581695.474 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-29T18:01:35.474Z,1627581695.474 [Default:CheckIn:C.Wait] Stopped 2021-07-29T18:01:35.474Z,1627581695.474 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-29T18:01:35.475Z,1627581695.475 [Default:CheckIn:D] Running Loop=1 2021-07-29T18:01:35.893Z,1627581695.893 [Default:CheckIn:D] Stopped 2021-07-29T18:01:35.893Z,1627581695.893 [Default:CheckIn:E] Running Loop=1 2021-07-29T18:01:36.284Z,1627581696.284 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 61.058325 min 2021-07-29T18:01:36.284Z,1627581696.284 [Default:CheckIn:E] Stopped 2021-07-29T18:01:36.284Z,1627581696.284 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-29T18:01:36.284Z,1627581696.284 [Default:CheckIn] Stopped 2021-07-29T18:01:36.285Z,1627581696.285 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-29T18:01:36.285Z,1627581696.285 [Default:CheckIn](INFO): Running loop #8 2021-07-29T18:01:36.285Z,1627581696.285 [Default:CheckIn] Running Loop=8 2021-07-29T18:01:36.285Z,1627581696.285 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-29T18:01:36.285Z,1627581696.285 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-29T18:01:38.294Z,1627581698.294 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180137.00,A,3648.16915,N,12147.28355,W,0.292,0.00,290721,,,A*7D 2021-07-29T18:01:38.297Z,1627581698.297 [NAL9602](INFO): GPS fix at 20210729T180137: (36.802819, -121.788059) 2021-07-29T18:01:38.309Z,1627581698.309 [Default:CheckIn:Read_GPS] Stopped 2021-07-29T18:01:38.310Z,1627581698.310 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-29T18:01:46.807Z,1627581706.807 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210729T171518/Courier0021.lzma 2021-07-29T18:01:47.809Z,1627581707.809 [DataOverHttps](INFO): Moved sent file to Logs/20210729T171518/Courier0021.lzma.bak 2021-07-29T18:01:47.809Z,1627581707.809 [DataOverHttps](INFO): SBD MOMSN=15774442 2021-07-29T18:02:06.151Z,1627581726.151 [DataOverHttps](INFO): Sending 205 bytes from file Logs/20210729T171518/Express0022.lzma 2021-07-29T18:02:07.153Z,1627581727.153 [DataOverHttps](INFO): Moved sent file to Logs/20210729T171518/Express0022.lzma.bak 2021-07-29T18:02:07.153Z,1627581727.153 [DataOverHttps](INFO): SBD MOMSN=15774445 2021-07-29T18:02:09.013Z,1627581729.013 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-07-29T18:02:09.095Z,1627581729.095 [NAL9602](ERROR): received: +CSQ:0 OK605, 2, 0, 0, 0 OK 2021-07-29T18:02:10.292Z,1627581730.292 [CBIT](IMPORTANT): Beginning ground fault scan 2021-07-29T18:02:11.061Z,1627581731.061 [Default:CheckIn:Read_Iridium] Stopped 2021-07-29T18:02:11.061Z,1627581731.061 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-29T18:02:11.061Z,1627581731.061 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-29T18:02:21.247Z,1627581741.247 [CBIT](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): -0.002296 CHAN A1 (24V): -0.181279 CHAN A2 (12V): -0.002124 CHAN A3 (5V): -0.001783 CHAN B0 (3.3V): 0.000217 CHAN B1 (3.15aV): 0.000230 CHAN B2 (3.15bV): -0.000190 CHAN B3 (GND): -0.000126 OPEN: -0.000376 Full Scale Calc: 4.765 mA, -1.589 mA 2021-07-29T18:06:40.322Z,1627582000.322 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-29T18:07:11.028Z,1627582031.028 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-29T18:07:11.853Z,1627582031.853 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-29T18:07:11.853Z,1627582031.853 [Default:CheckIn:C.Wait] Stopped 2021-07-29T18:07:11.853Z,1627582031.853 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-29T18:07:11.853Z,1627582031.853 [Default:CheckIn:D] Running Loop=1 2021-07-29T18:07:12.250Z,1627582032.250 [Default:CheckIn:D] Stopped 2021-07-29T18:07:12.250Z,1627582032.250 [Default:CheckIn:E] Running Loop=1 2021-07-29T18:07:12.652Z,1627582032.652 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 66.664274 min 2021-07-29T18:07:12.652Z,1627582032.652 [Default:CheckIn:E] Stopped 2021-07-29T18:07:12.652Z,1627582032.652 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-29T18:07:12.652Z,1627582032.652 [Default:CheckIn] Stopped 2021-07-29T18:07:12.652Z,1627582032.652 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-29T18:07:12.653Z,1627582032.653 [Default:CheckIn](INFO): Running loop #9 2021-07-29T18:07:12.653Z,1627582032.653 [Default:CheckIn] Running Loop=9 2021-07-29T18:07:12.653Z,1627582032.653 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-29T18:07:12.653Z,1627582032.653 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-29T18:07:14.664Z,1627582034.664 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180713.00,A,3648.15962,N,12147.27702,W,0.292,0.00,290721,,,A*77 2021-07-29T18:07:14.666Z,1627582034.666 [NAL9602](INFO): GPS fix at 20210729T180713: (36.802660, -121.787950) 2021-07-29T18:07:14.679Z,1627582034.679 [Default:CheckIn:Read_GPS] Stopped 2021-07-29T18:07:14.679Z,1627582034.679 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-29T18:07:23.139Z,1627582043.139 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210729T171518/Courier0024.lzma 2021-07-29T18:07:24.141Z,1627582044.141 [DataOverHttps](INFO): Moved sent file to Logs/20210729T171518/Courier0024.lzma.bak 2021-07-29T18:07:24.141Z,1627582044.141 [DataOverHttps](INFO): SBD MOMSN=15774478 2021-07-29T18:07:42.532Z,1627582062.532 [DataOverHttps](INFO): Sending 408 bytes from file Logs/20210729T171518/Express0025.lzma 2021-07-29T18:07:43.533Z,1627582063.533 [DataOverHttps](INFO): Moved sent file to Logs/20210729T171518/Express0025.lzma.bak 2021-07-29T18:07:43.533Z,1627582063.533 [DataOverHttps](INFO): SBD MOMSN=15774481 2021-07-29T18:07:48.244Z,1627582068.244 [Default:CheckIn:Read_Iridium] Stopped 2021-07-29T18:07:48.244Z,1627582068.244 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-29T18:07:48.244Z,1627582068.244 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-29T18:12:16.526Z,1627582336.526 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-29T18:12:47.236Z,1627582367.236 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-29T18:12:48.861Z,1627582368.861 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-29T18:12:48.861Z,1627582368.861 [Default:CheckIn:C.Wait] Stopped 2021-07-29T18:12:48.861Z,1627582368.861 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-29T18:12:48.861Z,1627582368.861 [Default:CheckIn:D] Running Loop=1 2021-07-29T18:12:49.272Z,1627582369.272 [Default:CheckIn:D] Stopped 2021-07-29T18:12:49.272Z,1627582369.272 [Default:CheckIn:E] Running Loop=1 2021-07-29T18:12:49.680Z,1627582369.680 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 72.281323 min 2021-07-29T18:12:49.680Z,1627582369.680 [Default:CheckIn:E] Stopped 2021-07-29T18:12:49.680Z,1627582369.680 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-29T18:12:49.680Z,1627582369.680 [Default:CheckIn] Stopped 2021-07-29T18:12:49.680Z,1627582369.680 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-29T18:12:49.681Z,1627582369.681 [Default:CheckIn](INFO): Running loop #10 2021-07-29T18:12:49.681Z,1627582369.681 [Default:CheckIn] Running Loop=10 2021-07-29T18:12:49.681Z,1627582369.681 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-29T18:12:49.681Z,1627582369.681 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-29T18:12:51.682Z,1627582371.682 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181250.00,A,3648.16565,N,12147.28389,W,0.330,0.00,290721,,,A*7D 2021-07-29T18:12:51.685Z,1627582371.685 [NAL9602](INFO): GPS fix at 20210729T181250: (36.802761, -121.788065) 2021-07-29T18:12:51.721Z,1627582371.721 [Default:CheckIn:Read_GPS] Stopped 2021-07-29T18:12:51.721Z,1627582371.721 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-29T18:13:00.363Z,1627582380.363 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210729T171518/Courier0027.lzma 2021-07-29T18:13:01.365Z,1627582381.365 [DataOverHttps](INFO): Moved sent file to Logs/20210729T171518/Courier0027.lzma.bak 2021-07-29T18:13:01.365Z,1627582381.365 [DataOverHttps](INFO): SBD MOMSN=15774494 2021-07-29T18:13:20.135Z,1627582400.135 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20210729T171518/Express0028.lzma 2021-07-29T18:13:21.137Z,1627582401.137 [DataOverHttps](INFO): Moved sent file to Logs/20210729T171518/Express0028.lzma.bak 2021-07-29T18:13:21.137Z,1627582401.137 [DataOverHttps](INFO): SBD MOMSN=15774497 2021-07-29T18:13:24.849Z,1627582404.849 [Default:CheckIn:Read_Iridium] Stopped 2021-07-29T18:13:24.850Z,1627582404.850 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-29T18:13:24.850Z,1627582404.850 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-29T18:17:54.285Z,1627582674.285 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-29T18:18:24.984Z,1627582704.984 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-29T18:18:25.428Z,1627582705.428 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-29T18:18:25.428Z,1627582705.428 [Default:CheckIn:C.Wait] Stopped 2021-07-29T18:18:25.428Z,1627582705.428 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-29T18:18:25.429Z,1627582705.429 [Default:CheckIn:D] Running Loop=1 2021-07-29T18:18:25.809Z,1627582705.809 [Default:CheckIn:D] Stopped 2021-07-29T18:18:25.809Z,1627582705.809 [Default:CheckIn:E] Running Loop=1 2021-07-29T18:18:26.214Z,1627582706.214 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 77.890259 min 2021-07-29T18:18:26.215Z,1627582706.215 [Default:CheckIn:E] Stopped 2021-07-29T18:18:26.215Z,1627582706.215 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-29T18:18:26.215Z,1627582706.215 [Default:CheckIn] Stopped 2021-07-29T18:18:26.219Z,1627582706.219 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-29T18:18:26.220Z,1627582706.220 [Default:CheckIn](INFO): Running loop #11 2021-07-29T18:18:26.220Z,1627582706.220 [Default:CheckIn] Running Loop=11 2021-07-29T18:18:26.220Z,1627582706.220 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-29T18:18:26.220Z,1627582706.220 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-29T18:18:28.218Z,1627582708.218 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181827.00,A,3648.16528,N,12147.28416,W,0.350,0.00,290721,,,A*79 2021-07-29T18:18:28.221Z,1627582708.221 [NAL9602](INFO): GPS fix at 20210729T181827: (36.802755, -121.788069) 2021-07-29T18:18:28.237Z,1627582708.237 [Default:CheckIn:Read_GPS] Stopped 2021-07-29T18:18:28.238Z,1627582708.238 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-29T18:18:38.375Z,1627582718.375 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210729T171518/Courier0030.lzma 2021-07-29T18:18:39.377Z,1627582719.377 [DataOverHttps](INFO): Moved sent file to Logs/20210729T171518/Courier0030.lzma.bak 2021-07-29T18:18:39.377Z,1627582719.377 [DataOverHttps](INFO): SBD MOMSN=15774531 2021-07-29T18:18:58.943Z,1627582738.943 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-07-29T18:18:59.015Z,1627582739.015 [NAL9602](ERROR): received: +CSQ:0 OK605, 2, 0, 0, 0 OK 2021-07-29T18:18:59.091Z,1627582739.091 [DataOverHttps](INFO): Sending 205 bytes from file Logs/20210729T171518/Express0031.lzma 2021-07-29T18:19:00.093Z,1627582740.093 [DataOverHttps](INFO): Moved sent file to Logs/20210729T171518/Express0031.lzma.bak 2021-07-29T18:19:00.093Z,1627582740.093 [DataOverHttps](INFO): SBD MOMSN=15774534 2021-07-29T18:19:03.829Z,1627582743.829 [Default:CheckIn:Read_Iridium] Stopped 2021-07-29T18:19:03.829Z,1627582743.829 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-29T18:19:03.829Z,1627582743.829 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-29T18:23:30.526Z,1627583010.526 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-29T18:24:01.235Z,1627583041.235 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-29T18:24:04.482Z,1627583044.482 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-29T18:24:04.482Z,1627583044.482 [Default:CheckIn:C.Wait] Stopped 2021-07-29T18:24:04.482Z,1627583044.482 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-29T18:24:04.482Z,1627583044.482 [Default:CheckIn:D] Running Loop=1 2021-07-29T18:24:04.876Z,1627583044.876 [Default:CheckIn:D] Stopped 2021-07-29T18:24:04.876Z,1627583044.876 [Default:CheckIn:E] Running Loop=1 2021-07-29T18:24:05.285Z,1627583045.285 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 83.541382 min 2021-07-29T18:24:05.285Z,1627583045.285 [Default:CheckIn:E] Stopped 2021-07-29T18:24:05.285Z,1627583045.285 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-29T18:24:05.285Z,1627583045.285 [Default:CheckIn] Stopped 2021-07-29T18:24:05.285Z,1627583045.285 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-29T18:24:05.285Z,1627583045.285 [Default:CheckIn](INFO): Running loop #12 2021-07-29T18:24:05.285Z,1627583045.285 [Default:CheckIn] Running Loop=12 2021-07-29T18:24:05.285Z,1627583045.285 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-29T18:24:05.286Z,1627583045.286 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-29T18:24:07.294Z,1627583047.294 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182406.00,A,3648.16525,N,12147.28372,W,0.680,0.00,290721,,,A*75 2021-07-29T18:24:07.307Z,1627583047.307 [NAL9602](INFO): GPS fix at 20210729T182406: (36.802754, -121.788062) 2021-07-29T18:24:07.319Z,1627583047.319 [Default:CheckIn:Read_GPS] Stopped 2021-07-29T18:24:07.319Z,1627583047.319 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-29T18:24:16.327Z,1627583056.327 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210729T171518/Courier0033.lzma 2021-07-29T18:24:17.329Z,1627583057.329 [DataOverHttps](INFO): Moved sent file to Logs/20210729T171518/Courier0033.lzma.bak 2021-07-29T18:24:17.329Z,1627583057.329 [DataOverHttps](INFO): SBD MOMSN=15774546 2021-07-29T18:24:43.915Z,1627583083.915 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20210729T171518/Express0034.lzma 2021-07-29T18:24:44.917Z,1627583084.917 [DataOverHttps](INFO): Moved sent file to Logs/20210729T171518/Express0034.lzma.bak 2021-07-29T18:24:44.917Z,1627583084.917 [DataOverHttps](INFO): SBD MOMSN=15774549 2021-07-29T18:24:48.747Z,1627583088.747 [Default:CheckIn:Read_Iridium] Stopped 2021-07-29T18:24:48.747Z,1627583088.747 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-29T18:24:48.747Z,1627583088.747 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-29T18:29:09.689Z,1627583349.689 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-29T18:29:40.392Z,1627583380.392 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-29T18:29:49.299Z,1627583389.299 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-29T18:29:49.299Z,1627583389.299 [Default:CheckIn:C.Wait] Stopped 2021-07-29T18:29:49.300Z,1627583389.300 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-29T18:29:49.300Z,1627583389.300 [Default:CheckIn:D] Running Loop=1 2021-07-29T18:29:49.696Z,1627583389.696 [Default:CheckIn:D] Stopped 2021-07-29T18:29:49.696Z,1627583389.696 [Default:CheckIn:E] Running Loop=1 2021-07-29T18:29:50.100Z,1627583390.100 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 89.288387 min 2021-07-29T18:29:50.100Z,1627583390.100 [Default:CheckIn:E] Stopped 2021-07-29T18:29:50.100Z,1627583390.100 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-29T18:29:50.100Z,1627583390.100 [Default:CheckIn] Stopped 2021-07-29T18:29:50.100Z,1627583390.100 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-29T18:29:50.101Z,1627583390.101 [Default:CheckIn](INFO): Running loop #13 2021-07-29T18:29:50.101Z,1627583390.101 [Default:CheckIn] Running Loop=13 2021-07-29T18:29:50.101Z,1627583390.101 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-29T18:29:50.101Z,1627583390.101 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-29T18:29:52.108Z,1627583392.108 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182951.00,A,3648.16888,N,12147.27356,W,0.389,0.00,290721,,,A*75 2021-07-29T18:29:52.110Z,1627583392.110 [NAL9602](INFO): GPS fix at 20210729T182951: (36.802815, -121.787893) 2021-07-29T18:29:52.123Z,1627583392.123 [Default:CheckIn:Read_GPS] Stopped 2021-07-29T18:29:52.123Z,1627583392.123 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-29T18:30:00.687Z,1627583400.687 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210729T171518/Courier0036.lzma 2021-07-29T18:30:01.689Z,1627583401.689 [DataOverHttps](INFO): Moved sent file to Logs/20210729T171518/Courier0036.lzma.bak 2021-07-29T18:30:01.689Z,1627583401.689 [DataOverHttps](INFO): SBD MOMSN=15774583 2021-07-29T18:30:21.779Z,1627583421.779 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20210729T171518/Express0037.lzma 2021-07-29T18:30:22.781Z,1627583422.781 [DataOverHttps](INFO): Moved sent file to Logs/20210729T171518/Express0037.lzma.bak 2021-07-29T18:30:22.782Z,1627583422.782 [DataOverHttps](INFO): SBD MOMSN=15774586 2021-07-29T18:30:22.877Z,1627583422.877 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-07-29T18:30:22.955Z,1627583422.955 [NAL9602](ERROR): received: +CSQ:0 OK605, 2, 0, 0, 0 OK 2021-07-29T18:30:30.242Z,1627583430.242 [Default:CheckIn:Read_Iridium] Stopped 2021-07-29T18:30:30.242Z,1627583430.242 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-29T18:30:30.243Z,1627583430.243 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-29T18:34:54.245Z,1627583694.245 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-29T18:35:24.948Z,1627583724.948 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-29T18:35:31.024Z,1627583731.024 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-29T18:35:31.024Z,1627583731.024 [Default:CheckIn:C.Wait] Stopped 2021-07-29T18:35:31.024Z,1627583731.024 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-29T18:35:31.024Z,1627583731.024 [Default:CheckIn:D] Running Loop=1 2021-07-29T18:35:31.429Z,1627583731.429 [Default:CheckIn:D] Stopped 2021-07-29T18:35:31.429Z,1627583731.429 [Default:CheckIn:E] Running Loop=1 2021-07-29T18:35:31.830Z,1627583731.830 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 94.983936 min 2021-07-29T18:35:31.830Z,1627583731.830 [Default:CheckIn:E] Stopped 2021-07-29T18:35:31.830Z,1627583731.830 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-29T18:35:31.830Z,1627583731.830 [Default:CheckIn] Stopped 2021-07-29T18:35:31.830Z,1627583731.830 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-29T18:35:31.831Z,1627583731.831 [Default:CheckIn](INFO): Running loop #14 2021-07-29T18:35:31.831Z,1627583731.831 [Default:CheckIn] Running Loop=14 2021-07-29T18:35:31.831Z,1627583731.831 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-29T18:35:31.831Z,1627583731.831 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-29T18:35:33.842Z,1627583733.842 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183533.00,A,3648.16477,N,12147.28595,W,0.428,0.00,290721,,,A*7A 2021-07-29T18:35:33.856Z,1627583733.856 [NAL9602](INFO): GPS fix at 20210729T183533: (36.802746, -121.788099) 2021-07-29T18:35:33.868Z,1627583733.868 [Default:CheckIn:Read_GPS] Stopped 2021-07-29T18:35:33.868Z,1627583733.868 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-29T18:35:42.703Z,1627583742.703 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210729T171518/Courier0039.lzma 2021-07-29T18:35:43.705Z,1627583743.705 [DataOverHttps](INFO): Moved sent file to Logs/20210729T171518/Courier0039.lzma.bak 2021-07-29T18:35:43.705Z,1627583743.705 [DataOverHttps](INFO): SBD MOMSN=15774597 2021-07-29T18:36:02.975Z,1627583762.975 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20210729T171518/Express0040.lzma 2021-07-29T18:36:03.977Z,1627583763.977 [DataOverHttps](INFO): Moved sent file to Logs/20210729T171518/Express0040.lzma.bak 2021-07-29T18:36:03.977Z,1627583763.977 [DataOverHttps](INFO): SBD MOMSN=15774600 2021-07-29T18:36:04.541Z,1627583764.541 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-07-29T18:36:04.616Z,1627583764.616 [NAL9602](ERROR): received: +CSQ:0 OK605, 2, 0, 0, 0 OK 2021-07-29T18:36:07.838Z,1627583767.838 [Default:CheckIn:Read_Iridium] Stopped 2021-07-29T18:36:07.838Z,1627583767.838 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-29T18:36:07.838Z,1627583767.838 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-29T18:40:36.605Z,1627584036.605 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-29T18:41:07.315Z,1627584067.315 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-29T18:41:08.535Z,1627584068.535 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-29T18:41:08.536Z,1627584068.536 [Default:CheckIn:C.Wait] Stopped 2021-07-29T18:41:08.536Z,1627584068.536 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-29T18:41:08.536Z,1627584068.536 [Default:CheckIn:D] Running Loop=1 2021-07-29T18:41:08.954Z,1627584068.954 [Default:CheckIn:D] Stopped 2021-07-29T18:41:08.954Z,1627584068.954 [Default:CheckIn:E] Running Loop=1 2021-07-29T18:41:09.362Z,1627584069.362 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 100.609342 min 2021-07-29T18:41:09.362Z,1627584069.362 [Default:CheckIn:E] Stopped 2021-07-29T18:41:09.362Z,1627584069.362 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-29T18:41:09.362Z,1627584069.362 [Default:CheckIn] Stopped 2021-07-29T18:41:09.362Z,1627584069.362 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-29T18:41:09.362Z,1627584069.362 [Default:CheckIn](INFO): Running loop #15 2021-07-29T18:41:09.363Z,1627584069.363 [Default:CheckIn] Running Loop=15 2021-07-29T18:41:09.363Z,1627584069.363 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-29T18:41:09.363Z,1627584069.363 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-29T18:41:11.358Z,1627584071.358 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184110.00,A,3648.16449,N,12147.28419,W,0.389,340.45,290721,,,A*7A 2021-07-29T18:41:11.361Z,1627584071.361 [NAL9602](INFO): GPS fix at 20210729T184110: (36.802742, -121.788070) 2021-07-29T18:41:11.374Z,1627584071.374 [Default:CheckIn:Read_GPS] Stopped 2021-07-29T18:41:11.374Z,1627584071.374 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-29T18:41:19.975Z,1627584079.975 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210729T171518/Courier0042.lzma 2021-07-29T18:41:20.977Z,1627584080.977 [DataOverHttps](INFO): Moved sent file to Logs/20210729T171518/Courier0042.lzma.bak 2021-07-29T18:41:20.977Z,1627584080.977 [DataOverHttps](INFO): SBD MOMSN=15774638 2021-07-29T18:41:39.217Z,1627584099.217 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20210729T171518/Express0043.lzma 2021-07-29T18:41:40.213Z,1627584100.213 [DataOverHttps](INFO): Moved sent file to Logs/20210729T171518/Express0043.lzma.bak 2021-07-29T18:41:40.213Z,1627584100.213 [DataOverHttps](INFO): SBD MOMSN=15774641 2021-07-29T18:41:42.109Z,1627584102.109 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-07-29T18:41:42.191Z,1627584102.191 [NAL9602](ERROR): received: +CSQ:0 OK605, 2, 0, 0, 0 OK 2021-07-29T18:41:44.113Z,1627584104.113 [Default:CheckIn:Read_Iridium] Stopped 2021-07-29T18:41:44.113Z,1627584104.113 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-29T18:41:44.113Z,1627584104.113 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-29T18:46:13.685Z,1627584373.685 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-29T18:46:44.405Z,1627584404.405 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-29T18:46:44.824Z,1627584404.824 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-29T18:46:44.824Z,1627584404.824 [Default:CheckIn:C.Wait] Stopped 2021-07-29T18:46:44.824Z,1627584404.824 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-29T18:46:44.825Z,1627584404.825 [Default:CheckIn:D] Running Loop=1 2021-07-29T18:46:45.230Z,1627584405.230 [Default:CheckIn:D] Stopped 2021-07-29T18:46:45.230Z,1627584405.230 [Default:CheckIn:E] Running Loop=1 2021-07-29T18:46:45.645Z,1627584405.645 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 106.213949 min 2021-07-29T18:46:45.645Z,1627584405.645 [Default:CheckIn:E] Stopped 2021-07-29T18:46:45.645Z,1627584405.645 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-29T18:46:45.645Z,1627584405.645 [Default:CheckIn] Stopped 2021-07-29T18:46:45.645Z,1627584405.645 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-29T18:46:45.645Z,1627584405.645 [Default:CheckIn](INFO): Running loop #16 2021-07-29T18:46:45.645Z,1627584405.645 [Default:CheckIn] Running Loop=16 2021-07-29T18:46:45.645Z,1627584405.645 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-29T18:46:45.646Z,1627584405.646 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-29T18:46:47.639Z,1627584407.639 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184646.00,A,3648.16723,N,12147.28569,W,0.350,154.45,290721,,,A*74 2021-07-29T18:46:47.641Z,1627584407.641 [NAL9602](INFO): GPS fix at 20210729T184646: (36.802787, -121.788095) 2021-07-29T18:46:47.654Z,1627584407.654 [Default:CheckIn:Read_GPS] Stopped 2021-07-29T18:46:47.654Z,1627584407.654 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-29T18:46:56.871Z,1627584416.871 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210729T171518/Courier0045.lzma 2021-07-29T18:46:57.873Z,1627584417.873 [DataOverHttps](INFO): Moved sent file to Logs/20210729T171518/Courier0045.lzma.bak 2021-07-29T18:46:57.873Z,1627584417.873 [DataOverHttps](INFO): SBD MOMSN=15774651 2021-07-29T18:47:16.504Z,1627584436.504 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20210729T171518/Express0046.lzma 2021-07-29T18:47:17.505Z,1627584437.505 [DataOverHttps](INFO): Moved sent file to Logs/20210729T171518/Express0046.lzma.bak 2021-07-29T18:47:17.505Z,1627584437.505 [DataOverHttps](INFO): SBD MOMSN=15774654 2021-07-29T18:47:18.345Z,1627584438.345 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-07-29T18:47:18.419Z,1627584438.419 [NAL9602](ERROR): received: +CSQ:0 OK605, 2, 0, 0, 0 OK 2021-07-29T18:47:21.219Z,1627584441.219 [Default:CheckIn:Read_Iridium] Stopped 2021-07-29T18:47:21.220Z,1627584441.220 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-29T18:47:21.220Z,1627584441.220 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-29T18:51:05.398Z,1627584665.398 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2021-07-29T18:51:05.401Z,1627584665.401 [BPC1](INFO): Received data from all battery sticks. 2021-07-29T18:51:50.241Z,1627584710.241 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-29T18:52:20.940Z,1627584740.940 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-29T18:52:21.766Z,1627584741.766 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-29T18:52:21.766Z,1627584741.766 [Default:CheckIn:C.Wait] Stopped 2021-07-29T18:52:21.767Z,1627584741.767 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-29T18:52:21.767Z,1627584741.767 [Default:CheckIn:D] Running Loop=1 2021-07-29T18:52:22.181Z,1627584742.181 [Default:CheckIn:D] Stopped 2021-07-29T18:52:22.181Z,1627584742.181 [Default:CheckIn:E] Running Loop=1 2021-07-29T18:52:22.596Z,1627584742.596 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 111.829801 min 2021-07-29T18:52:22.597Z,1627584742.597 [Default:CheckIn:E] Stopped 2021-07-29T18:52:22.597Z,1627584742.597 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-29T18:52:22.597Z,1627584742.597 [Default:CheckIn] Stopped 2021-07-29T18:52:22.597Z,1627584742.597 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-29T18:52:22.597Z,1627584742.597 [Default:CheckIn](INFO): Running loop #17 2021-07-29T18:52:22.597Z,1627584742.597 [Default:CheckIn] Running Loop=17 2021-07-29T18:52:22.597Z,1627584742.597 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-29T18:52:22.597Z,1627584742.597 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-29T18:52:24.578Z,1627584744.578 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185223.00,A,3648.16657,N,12147.28620,W,0.194,154.45,290721,,,A*74 2021-07-29T18:52:24.581Z,1627584744.581 [NAL9602](INFO): GPS fix at 20210729T185223: (36.802776, -121.788103) 2021-07-29T18:52:24.630Z,1627584744.630 [Default:CheckIn:Read_GPS] Stopped 2021-07-29T18:52:24.630Z,1627584744.630 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-29T18:52:37.012Z,1627584757.012 [DataOverHttps](INFO): Sending 85 bytes from file Logs/20210729T171518/Courier0048.lzma 2021-07-29T18:52:38.013Z,1627584758.013 [DataOverHttps](INFO): Moved sent file to Logs/20210729T171518/Courier0048.lzma.bak 2021-07-29T18:52:38.014Z,1627584758.014 [DataOverHttps](INFO): SBD MOMSN=15774685 2021-07-29T18:52:55.357Z,1627584775.357 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-07-29T18:52:55.435Z,1627584775.435 [NAL9602](ERROR): received: +CSQ:0 OK605, 2, 0, 0, 0 OK 2021-07-29T18:52:57.744Z,1627584777.744 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20210729T171518/Express0049.lzma 2021-07-29T18:52:58.745Z,1627584778.745 [DataOverHttps](INFO): Moved sent file to Logs/20210729T171518/Express0049.lzma.bak 2021-07-29T18:52:58.745Z,1627584778.745 [DataOverHttps](INFO): SBD MOMSN=15774688 2021-07-29T18:53:02.257Z,1627584782.257 [Default:CheckIn:Read_Iridium] Stopped 2021-07-29T18:53:02.257Z,1627584782.257 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-29T18:53:02.258Z,1627584782.258 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-29T18:53:44.646Z,1627584824.646 [NAL9602](INFO): SBD MO Status=2, MOMSN=28605, MT Status=2, MTMSN=0 2021-07-29T18:53:44.647Z,1627584824.647 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-29T18:54:49.334Z,1627584889.334 [NAL9602](INFO): SBD MO Status=2, MOMSN=28605, MT Status=2, MTMSN=0 2021-07-29T18:54:49.334Z,1627584889.334 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-29T18:55:19.634Z,1627584919.634 [NAL9602](INFO): SBD MO Status=2, MOMSN=28605, MT Status=2, MTMSN=0 2021-07-29T18:55:19.634Z,1627584919.634 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-29T18:55:41.046Z,1627584941.046 [NAL9602](INFO): SBD MO Status=2, MOMSN=28605, MT Status=2, MTMSN=0 2021-07-29T18:55:41.046Z,1627584941.046 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-29T18:56:51.406Z,1627585011.406 [NAL9602](INFO): SBD MO Status=2, MOMSN=28605, MT Status=2, MTMSN=0 2021-07-29T18:56:51.406Z,1627585011.406 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-29T18:57:26.559Z,1627585046.559 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-29T18:57:57.252Z,1627585077.252 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-29T18:58:02.951Z,1627585082.951 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-29T18:58:02.952Z,1627585082.952 [Default:CheckIn:C.Wait] Stopped 2021-07-29T18:58:02.952Z,1627585082.952 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-29T18:58:02.952Z,1627585082.952 [Default:CheckIn:D] Running Loop=1 2021-07-29T18:58:03.324Z,1627585083.324 [Default:CheckIn:D] Stopped 2021-07-29T18:58:03.324Z,1627585083.324 [Default:CheckIn:E] Running Loop=1 2021-07-29T18:58:03.728Z,1627585083.728 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 117.515511 min 2021-07-29T18:58:03.728Z,1627585083.728 [Default:CheckIn:E] Stopped 2021-07-29T18:58:03.728Z,1627585083.728 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-29T18:58:03.729Z,1627585083.729 [Default:CheckIn] Stopped 2021-07-29T18:58:03.729Z,1627585083.729 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-29T18:58:03.729Z,1627585083.729 [Default:CheckIn](INFO): Running loop #18 2021-07-29T18:58:03.729Z,1627585083.729 [Default:CheckIn] Running Loop=18 2021-07-29T18:58:03.729Z,1627585083.729 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-29T18:58:03.729Z,1627585083.729 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-29T18:58:05.747Z,1627585085.747 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185804.00,A,3648.16709,N,12147.28393,W,1.069,0.00,290721,,,A*7F 2021-07-29T18:58:05.749Z,1627585085.749 [NAL9602](INFO): GPS fix at 20210729T185804: (36.802785, -121.788066) 2021-07-29T18:58:05.761Z,1627585085.761 [Default:CheckIn:Read_GPS] Stopped 2021-07-29T18:58:05.761Z,1627585085.761 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-29T18:58:14.201Z,1627585094.201 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210729T171518/Courier0051.lzma 2021-07-29T18:58:15.114Z,1627585095.114 [DataOverHttps](INFO): Moved sent file to Logs/20210729T171518/Courier0051.lzma.bak 2021-07-29T18:58:15.114Z,1627585095.114 [DataOverHttps](INFO): SBD MOMSN=15774699 2021-07-29T18:58:36.181Z,1627585116.181 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-07-29T18:58:36.276Z,1627585116.276 [NAL9602](ERROR): received: +CSQ:0 OK605, 2, 0, 0, 0 OK 2021-07-29T18:58:42.063Z,1627585122.063 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20210729T171518/Express0052.lzma 2021-07-29T18:58:43.065Z,1627585123.065 [DataOverHttps](INFO): Moved sent file to Logs/20210729T171518/Express0052.lzma.bak 2021-07-29T18:58:43.065Z,1627585123.065 [DataOverHttps](INFO): SBD MOMSN=15774702 2021-07-29T18:58:47.941Z,1627585127.941 [Default:CheckIn:Read_Iridium] Stopped 2021-07-29T18:58:47.941Z,1627585127.941 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-29T18:58:47.941Z,1627585127.941 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-29T19:03:08.521Z,1627585388.521 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-29T19:03:39.220Z,1627585419.220 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-29T19:03:48.528Z,1627585428.528 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-29T19:03:48.528Z,1627585428.528 [Default:CheckIn:C.Wait] Stopped 2021-07-29T19:03:48.528Z,1627585428.528 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-29T19:03:48.529Z,1627585428.529 [Default:CheckIn:D] Running Loop=1 2021-07-29T19:03:48.930Z,1627585428.930 [Default:CheckIn:D] Stopped 2021-07-29T19:03:48.930Z,1627585428.930 [Default:CheckIn:E] Running Loop=1 2021-07-29T19:03:49.334Z,1627585429.334 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 123.275602 min 2021-07-29T19:03:49.334Z,1627585429.334 [Default:CheckIn:E] Stopped 2021-07-29T19:03:49.334Z,1627585429.334 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-29T19:03:49.334Z,1627585429.334 [Default:CheckIn] Stopped 2021-07-29T19:03:49.334Z,1627585429.334 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-29T19:03:49.335Z,1627585429.335 [Default:CheckIn](INFO): Running loop #19 2021-07-29T19:03:49.335Z,1627585429.335 [Default:CheckIn] Running Loop=19 2021-07-29T19:03:49.335Z,1627585429.335 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-29T19:03:49.335Z,1627585429.335 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-29T19:03:51.342Z,1627585431.342 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190350.00,A,3648.15589,N,12147.30020,W,2.333,169.78,290721,,,A*74 2021-07-29T19:03:51.345Z,1627585431.345 [NAL9602](INFO): GPS fix at 20210729T190350: (36.802598, -121.788337) 2021-07-29T19:03:51.377Z,1627585431.377 [Default:CheckIn:Read_GPS] Stopped 2021-07-29T19:03:51.377Z,1627585431.377 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-29T19:04:00.283Z,1627585440.283 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210729T171518/Courier0054.lzma 2021-07-29T19:04:01.285Z,1627585441.285 [DataOverHttps](INFO): Moved sent file to Logs/20210729T171518/Courier0054.lzma.bak 2021-07-29T19:04:01.285Z,1627585441.285 [DataOverHttps](INFO): SBD MOMSN=15774734 2021-07-29T19:04:16.421Z,1627585456.421 [CommandLine](IMPORTANT): got command quit 2021-07-29T19:04:17.431Z,1627585457.431 [Supervisor](INFO): Stop Mission called by Supervisor::terminate 2021-07-29T19:04:17.432Z,1627585457.432 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2021-07-29T19:04:17.432Z,1627585457.432 [CommandLine ThreadHandler](INFO): Thread cancelled. 2021-07-29T19:04:17.639Z,1627585457.639 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2021-07-29T19:04:17.639Z,1627585457.639 [CommandLine ThreadHandler](INFO): Thread cancelled. 2021-07-29T19:04:17.640Z,1627585457.640 [CommandLine](INFO): Join timeout helper Thread ID is 3496 2021-07-29T19:04:17.647Z,1627585457.647 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2021-07-29T19:04:17.647Z,1627585457.647 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2021-07-29T19:04:17.648Z,1627585457.648 [NavChartDb](INFO): Join timeout helper Thread ID is 3497 2021-07-29T19:04:17.768Z,1627585457.768 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2021-07-29T19:04:17.769Z,1627585457.769 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2021-07-29T19:04:17.771Z,1627585457.771 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2021-07-29T19:04:17.771Z,1627585457.771 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2021-07-29T19:04:17.772Z,1627585457.772 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 3498 2021-07-29T19:04:17.923Z,1627585457.923 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2021-07-29T19:04:17.924Z,1627585457.924 [WetLabsBB2FL](INFO): Powering down 2021-07-29T19:04:17.924Z,1627585457.924 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2021-07-29T19:04:17.939Z,1627585457.939 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2021-07-29T19:04:17.939Z,1627585457.939 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2021-07-29T19:04:17.940Z,1627585457.940 [CTD_Seabird](INFO): Join timeout helper Thread ID is 3499 2021-07-29T19:04:18.535Z,1627585458.535 [CTD_Seabird](INFO): Powering down 2021-07-29T19:04:18.547Z,1627585458.547 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread. 2021-07-29T19:04:18.548Z,1627585458.548 [CTD_Seabird](INFO): Powering down 2021-07-29T19:04:18.559Z,1627585458.559 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2021-07-29T19:04:18.563Z,1627585458.563 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2021-07-29T19:04:18.563Z,1627585458.563 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2021-07-29T19:04:18.564Z,1627585458.564 [Radio_Surface](INFO): Join timeout helper Thread ID is 3500 2021-07-29T19:04:18.663Z,1627585458.663 [Radio_Surface](INFO): Powering down 2021-07-29T19:04:18.664Z,1627585458.664 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2021-07-29T19:04:18.665Z,1627585458.665 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2021-07-29T19:04:18.668Z,1627585458.668 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler 2021-07-29T19:04:18.668Z,1627585458.668 [Onboard ThreadHandler](INFO): Thread cancelled. 2021-07-29T19:04:18.669Z,1627585458.669 [Onboard](INFO): Join timeout helper Thread ID is 3501 2021-07-29T19:04:19.651Z,1627585459.651 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20210729T171518/Express0055.lzma 2021-07-29T19:04:22.045Z,1627585462.045 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-07-29T19:04:22.124Z,1627585462.124 [NAL9602](ERROR): received: +CSQ:0 OK605, 2, 0, 0, 0 OK 2021-07-29T19:04:23.235Z,1627585463.235 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread. 2021-07-29T19:04:23.236Z,1627585463.236 [Onboard ThreadHandler](INFO): Thread cancelled. 2021-07-29T19:04:23.252Z,1627585463.252 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2021-07-29T19:04:23.252Z,1627585463.252 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2021-07-29T19:04:23.253Z,1627585463.253 [DataOverHttps](INFO): Join timeout helper Thread ID is 3502 2021-07-29T19:04:23.663Z,1627585463.663 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2021-07-29T19:04:23.667Z,1627585463.667 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2021-07-29T19:04:23.688Z,1627585463.688 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2021-07-29T19:04:23.688Z,1627585463.688 [logger ThreadHandler](INFO): Thread cancelled. 2021-07-29T19:04:23.689Z,1627585463.689 [logger](INFO): Join timeout helper Thread ID is 3503 2021-07-29T19:04:23.733Z,1627585463.733 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2021-07-29T19:04:23.733Z,1627585463.733 [logger ThreadHandler](INFO): Thread cancelled. 2021-07-29T19:04:23.752Z,1627585463.752 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2021-07-29T19:04:23.752Z,1627585463.752 [CommandLine ThreadHandler](INFO): Thread cancelled. 2021-07-29T19:04:23.752Z,1627585463.752 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2021-07-29T19:04:23.752Z,1627585463.752 [controlThread ThreadHandler](INFO): Thread cancelled. 2021-07-29T19:04:23.753Z,1627585463.753 [controlThread](INFO): Join timeout helper Thread ID is 3504 2021-07-29T19:04:24.047Z,1627585464.047 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2021-07-29T19:04:24.048Z,1627585464.048 [controlThread](DEBUG): Uninitializing ControlThread 2021-07-29T19:04:24.048Z,1627585464.048 [AHRS_M2](INFO): Powering down 2021-07-29T19:04:24.120Z,1627585464.120 [NAL9602](INFO): Powering down 2021-07-29T19:04:24.124Z,1627585464.124 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2021-07-29T19:04:24.125Z,1627585464.125 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2021-07-29T19:04:24.125Z,1627585464.125 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2021-07-29T19:04:24.126Z,1627585464.126 [MissionManager](INFO): Uninitializing Mission Default 2021-07-29T19:04:24.126Z,1627585464.126 [Default] Stopped 2021-07-29T19:04:24.126Z,1627585464.126 [Default](DEBUG): Aggregate::uninitialize Default 2021-07-29T19:04:24.126Z,1627585464.126 [Default:B.GoToSurface] Stopped 2021-07-29T19:04:24.126Z,1627585464.126 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2021-07-29T19:04:24.126Z,1627585464.126 [Default:CheckIn] Stopped 2021-07-29T19:04:24.126Z,1627585464.126 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-29T19:04:24.127Z,1627585464.127 [Default:CheckIn:Read_Iridium] Stopped 2021-07-29T19:04:24.130Z,1627585464.130 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2021-07-29T19:04:24.130Z,1627585464.130 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2021-07-29T19:04:24.131Z,1627585464.131 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2021-07-29T19:04:24.131Z,1627585464.131 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2021-07-29T19:04:24.131Z,1627585464.131 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2021-07-29T19:04:24.132Z,1627585464.132 [BuoyancyServo](INFO): Powering down 2021-07-29T19:04:24.144Z,1627585464.144 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2021-07-29T19:04:24.144Z,1627585464.144 [ElevatorServo](INFO): Powering down 2021-07-29T19:04:24.145Z,1627585464.145 [MassServo](DEBUG): Uninitialize Mass Servo. 2021-07-29T19:04:24.145Z,1627585464.145 [MassServo](INFO): Powering down 2021-07-29T19:04:24.146Z,1627585464.146 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2021-07-29T19:04:24.146Z,1627585464.146 [RudderServo](INFO): Powering down 2021-07-29T19:04:24.147Z,1627585464.147 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2021-07-29T19:04:24.147Z,1627585464.147 [ThrusterServo](INFO): Powering down 2021-07-29T19:04:24.148Z,1627585464.148 [SBIT](DEBUG): Uninitialize SBIT Component. 2021-07-29T19:04:24.149Z,1627585464.149 [IBIT](DEBUG): Uninitialize IBIT Component. 2021-07-29T19:04:24.149Z,1627585464.149 [CBIT](DEBUG): Uninitialize CBIT Component. 2021-07-29T19:04:24.149Z,1627585464.149 [CBIT](DEBUG): Powering off loads. 2021-07-29T19:04:24.163Z,1627585464.163 [CBIT](DEBUG): Disabling WDT. 2021-07-29T19:04:24.175Z,1627585464.175 [CBIT](DEBUG): Opening all GF detection circuits. 2021-07-29T19:04:24.176Z,1627585464.176 [controlThread ThreadHandler](INFO): Thread cancelled. 2021-07-29T19:04:24.254Z,1627585464.254 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2021-07-29T19:04:24.261Z,1627585464.261 [Onboard ThreadHandler](INFO): Thread cancelled. 2021-07-29T19:04:24.288Z,1627585464.288 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2021-07-29T19:04:24.564Z,1627585464.564 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2021-07-29T19:04:24.580Z,1627585464.580 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2021-07-29T19:04:24.704Z,1627585464.704 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2021-07-29T19:04:25.239Z,1627585465.239 [logger ThreadHandler](INFO): Thread cancelled.