2021-07-26T23:22:45.140Z,1627341765.140 [CommandLine](IMPORTANT): got command restart logs 2021-07-26T23:23:04.188Z,1627341784.188 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-26T23:23:34.889Z,1627341814.889 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-26T23:23:43.401Z,1627341823.401 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-26T23:23:43.401Z,1627341823.401 [Default:CheckIn:C.Wait] Stopped 2021-07-26T23:23:43.401Z,1627341823.401 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-26T23:23:43.401Z,1627341823.401 [Default:CheckIn:D] Running Loop=1 2021-07-26T23:23:43.839Z,1627341823.839 [Default:CheckIn:D] Stopped 2021-07-26T23:23:43.839Z,1627341823.839 [Default:CheckIn:E] Running Loop=1 2021-07-26T23:23:44.190Z,1627341824.190 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 39.208993 min 2021-07-26T23:23:44.191Z,1627341824.191 [Default:CheckIn:E] Stopped 2021-07-26T23:23:44.191Z,1627341824.191 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-26T23:23:44.191Z,1627341824.191 [Default:CheckIn] Stopped 2021-07-26T23:23:44.191Z,1627341824.191 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-26T23:23:44.191Z,1627341824.191 [Default:CheckIn](INFO): Running loop #6 2021-07-26T23:23:44.191Z,1627341824.191 [Default:CheckIn] Running Loop=6 2021-07-26T23:23:44.191Z,1627341824.191 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-26T23:23:44.192Z,1627341824.192 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-26T23:23:46.204Z,1627341826.204 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,232345.00,A,3648.16355,N,12147.29013,W,0.389,278.51,260721,,,A*73 2021-07-26T23:23:46.206Z,1627341826.206 [NAL9602](INFO): GPS fix at 20210726T232345: (36.802726, -121.788169) 2021-07-26T23:23:46.217Z,1627341826.217 [Default:CheckIn:Read_GPS] Stopped 2021-07-26T23:23:46.218Z,1627341826.218 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-26T23:23:55.435Z,1627341835.435 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20210726T221253/Courier0025.lzma 2021-07-26T23:23:56.437Z,1627341836.437 [DataOverHttps](INFO): Moved sent file to Logs/20210726T221253/Courier0025.lzma.bak 2021-07-26T23:23:56.437Z,1627341836.437 [DataOverHttps](INFO): SBD MOMSN=15762344 2021-07-26T23:24:13.795Z,1627341853.795 [DataOverHttps](INFO): Sending 267 bytes from file Logs/20210726T232245/Courier0000.lzma 2021-07-26T23:24:14.797Z,1627341854.797 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Courier0000.lzma.bak 2021-07-26T23:24:14.797Z,1627341854.797 [DataOverHttps](INFO): SBD MOMSN=15762346 2021-07-26T23:24:16.909Z,1627341856.909 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-07-26T23:24:16.992Z,1627341856.992 [NAL9602](ERROR): received: +CSQ:0 OK520, 2, 0, 0, 0 OK 2021-07-26T23:24:42.068Z,1627341882.068 [DataOverHttps](INFO): Sending 105 bytes from file Logs/20210726T221253/Express0026.lzma 2021-07-26T23:24:43.069Z,1627341883.069 [DataOverHttps](INFO): Moved sent file to Logs/20210726T221253/Express0026.lzma.bak 2021-07-26T23:24:43.069Z,1627341883.069 [DataOverHttps](INFO): SBD MOMSN=15762350 2021-07-26T23:25:14.068Z,1627341914.068 [DataOverHttps](INFO): Sending 466 bytes from file Logs/20210726T232245/Express0001.lzma 2021-07-26T23:25:15.069Z,1627341915.069 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Express0001.lzma.bak 2021-07-26T23:25:15.069Z,1627341915.069 [DataOverHttps](INFO): SBD MOMSN=15762353 2021-07-26T23:25:45.883Z,1627341945.883 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20210726T232245/Express0004.lzma 2021-07-26T23:25:46.885Z,1627341946.885 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Express0004.lzma.bak 2021-07-26T23:25:46.885Z,1627341946.885 [DataOverHttps](INFO): SBD MOMSN=15762358 2021-07-26T23:25:50.329Z,1627341950.329 [Default:CheckIn:Read_Iridium] Stopped 2021-07-26T23:25:50.329Z,1627341950.329 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-26T23:25:50.329Z,1627341950.329 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-26T23:26:17.768Z,1627341977.768 [BPC1](ERROR): BPC1A: No match for serial number 1717 in BPC1A's battery stick inventory (sticks 1-32 in onboard configuration file). 2021-07-26T23:27:53.122Z,1627342073.122 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2021-07-26T23:27:53.126Z,1627342073.126 [BPC1](INFO): Received data from all battery sticks. 2021-07-26T23:28:48.469Z,1627342128.469 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-26T23:29:19.167Z,1627342159.167 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-26T23:30:50.889Z,1627342250.889 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-26T23:30:50.889Z,1627342250.889 [Default:CheckIn:C.Wait] Stopped 2021-07-26T23:30:50.889Z,1627342250.889 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-26T23:30:50.889Z,1627342250.889 [Default:CheckIn:D] Running Loop=1 2021-07-26T23:30:51.287Z,1627342251.287 [Default:CheckIn:D] Stopped 2021-07-26T23:30:51.303Z,1627342251.303 [Default:CheckIn:E] Running Loop=1 2021-07-26T23:30:51.695Z,1627342251.695 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 46.333118 min 2021-07-26T23:30:51.695Z,1627342251.695 [Default:CheckIn:E] Stopped 2021-07-26T23:30:51.696Z,1627342251.696 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-26T23:30:51.696Z,1627342251.696 [Default:CheckIn] Stopped 2021-07-26T23:30:51.696Z,1627342251.696 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-26T23:30:51.696Z,1627342251.696 [Default:CheckIn](INFO): Running loop #7 2021-07-26T23:30:51.696Z,1627342251.696 [Default:CheckIn] Running Loop=7 2021-07-26T23:30:51.696Z,1627342251.696 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-26T23:30:51.696Z,1627342251.696 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-26T23:30:53.707Z,1627342253.707 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,233053.00,A,3648.16540,N,12147.27923,W,0.156,278.51,260721,,,A*70 2021-07-26T23:30:53.709Z,1627342253.709 [NAL9602](INFO): GPS fix at 20210726T233053: (36.802757, -121.787987) 2021-07-26T23:30:53.721Z,1627342253.721 [Default:CheckIn:Read_GPS] Stopped 2021-07-26T23:30:53.721Z,1627342253.721 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-26T23:31:02.235Z,1627342262.235 [DataOverHttps](INFO): Sending 202 bytes from file Logs/20210726T232245/Courier0006.lzma 2021-07-26T23:31:03.237Z,1627342263.237 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Courier0006.lzma.bak 2021-07-26T23:31:03.238Z,1627342263.238 [DataOverHttps](INFO): SBD MOMSN=15762360 2021-07-26T23:31:22.303Z,1627342282.303 [DataOverHttps](INFO): Sending 205 bytes from file Logs/20210726T232245/Express0007.lzma 2021-07-26T23:31:23.305Z,1627342283.305 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Express0007.lzma.bak 2021-07-26T23:31:23.305Z,1627342283.305 [DataOverHttps](INFO): SBD MOMSN=15762363 2021-07-26T23:31:24.406Z,1627342284.406 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-07-26T23:31:24.483Z,1627342284.483 [NAL9602](ERROR): received: +CSQ:0 OK520, 2, 0, 0, 0 OK 2021-07-26T23:31:26.844Z,1627342286.844 [Default:CheckIn:Read_Iridium] Stopped 2021-07-26T23:31:26.844Z,1627342286.844 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-26T23:31:26.844Z,1627342286.844 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-26T23:35:56.325Z,1627342556.325 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-26T23:36:27.036Z,1627342587.036 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-26T23:36:27.451Z,1627342587.451 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-26T23:36:27.451Z,1627342587.451 [Default:CheckIn:C.Wait] Stopped 2021-07-26T23:36:27.451Z,1627342587.451 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-26T23:36:27.456Z,1627342587.456 [Default:CheckIn:D] Running Loop=1 2021-07-26T23:36:27.866Z,1627342587.866 [Default:CheckIn:D] Stopped 2021-07-26T23:36:27.866Z,1627342587.866 [Default:CheckIn:E] Running Loop=1 2021-07-26T23:36:28.284Z,1627342588.284 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 51.942773 min 2021-07-26T23:36:28.284Z,1627342588.284 [Default:CheckIn:E] Stopped 2021-07-26T23:36:28.284Z,1627342588.284 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-26T23:36:28.284Z,1627342588.284 [Default:CheckIn] Stopped 2021-07-26T23:36:28.284Z,1627342588.284 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-26T23:36:28.284Z,1627342588.284 [Default:CheckIn](INFO): Running loop #8 2021-07-26T23:36:28.284Z,1627342588.284 [Default:CheckIn] Running Loop=8 2021-07-26T23:36:28.285Z,1627342588.285 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-26T23:36:28.285Z,1627342588.285 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-26T23:36:30.271Z,1627342590.271 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,233629.00,A,3648.16274,N,12147.28028,W,0.272,278.51,260721,,,D*76 2021-07-26T23:36:30.273Z,1627342590.273 [NAL9602](INFO): GPS fix at 20210726T233629: (36.802712, -121.788005) 2021-07-26T23:36:30.292Z,1627342590.292 [Default:CheckIn:Read_GPS] Stopped 2021-07-26T23:36:30.292Z,1627342590.292 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-26T23:36:41.283Z,1627342601.283 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210726T232245/Courier0009.lzma 2021-07-26T23:36:42.285Z,1627342602.285 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Courier0009.lzma.bak 2021-07-26T23:36:42.285Z,1627342602.285 [DataOverHttps](INFO): SBD MOMSN=15762367 2021-07-26T23:37:00.303Z,1627342620.303 [DataOverHttps](INFO): Sending 204 bytes from file Logs/20210726T232245/Express0010.lzma 2021-07-26T23:37:01.041Z,1627342621.041 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-07-26T23:37:01.115Z,1627342621.115 [NAL9602](ERROR): received: +CSQ:0 OK520, 2, 0, 0, 0 OK 2021-07-26T23:37:01.305Z,1627342621.305 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Express0010.lzma.bak 2021-07-26T23:37:01.305Z,1627342621.305 [DataOverHttps](INFO): SBD MOMSN=15762370 2021-07-26T23:37:04.704Z,1627342624.704 [Default:CheckIn:Read_Iridium] Stopped 2021-07-26T23:37:04.704Z,1627342624.704 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-26T23:37:04.704Z,1627342624.704 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-26T23:41:32.244Z,1627342892.244 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-26T23:42:02.944Z,1627342922.944 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-26T23:42:05.399Z,1627342925.399 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-26T23:42:05.399Z,1627342925.399 [Default:CheckIn:C.Wait] Stopped 2021-07-26T23:42:05.399Z,1627342925.399 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-26T23:42:05.399Z,1627342925.399 [Default:CheckIn:D] Running Loop=1 2021-07-26T23:42:05.787Z,1627342925.787 [Default:CheckIn:D] Stopped 2021-07-26T23:42:05.787Z,1627342925.787 [Default:CheckIn:E] Running Loop=1 2021-07-26T23:42:06.190Z,1627342926.190 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 57.574780 min 2021-07-26T23:42:06.190Z,1627342926.190 [Default:CheckIn:E] Stopped 2021-07-26T23:42:06.191Z,1627342926.191 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-26T23:42:06.191Z,1627342926.191 [Default:CheckIn] Stopped 2021-07-26T23:42:06.191Z,1627342926.191 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-26T23:42:06.191Z,1627342926.191 [Default:CheckIn](INFO): Running loop #9 2021-07-26T23:42:06.191Z,1627342926.191 [Default:CheckIn] Running Loop=9 2021-07-26T23:42:06.191Z,1627342926.191 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-26T23:42:06.191Z,1627342926.191 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-26T23:42:08.203Z,1627342928.203 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,234207.00,A,3648.16280,N,12147.27777,W,0.544,0.00,260721,,,D*7B 2021-07-26T23:42:08.205Z,1627342928.205 [NAL9602](INFO): GPS fix at 20210726T234207: (36.802713, -121.787963) 2021-07-26T23:42:08.217Z,1627342928.217 [Default:CheckIn:Read_GPS] Stopped 2021-07-26T23:42:08.217Z,1627342928.217 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-26T23:42:16.695Z,1627342936.695 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210726T232245/Courier0012.lzma 2021-07-26T23:42:17.697Z,1627342937.697 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Courier0012.lzma.bak 2021-07-26T23:42:17.697Z,1627342937.697 [DataOverHttps](INFO): SBD MOMSN=15762374 2021-07-26T23:42:38.620Z,1627342958.620 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-07-26T23:42:38.699Z,1627342958.699 [NAL9602](ERROR): received: +CSQ:1 OK520, 2, 0, 0, 0 OK 2021-07-26T23:42:44.291Z,1627342964.291 [DataOverHttps](INFO): Sending 205 bytes from file Logs/20210726T232245/Express0013.lzma 2021-07-26T23:42:45.293Z,1627342965.293 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Express0013.lzma.bak 2021-07-26T23:42:45.293Z,1627342965.293 [DataOverHttps](INFO): SBD MOMSN=15762377 2021-07-26T23:42:48.779Z,1627342968.779 [Default:CheckIn:Read_Iridium] Stopped 2021-07-26T23:42:48.779Z,1627342968.779 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-26T23:42:48.780Z,1627342968.780 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-26T23:47:10.510Z,1627343230.510 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-26T23:47:41.220Z,1627343261.220 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-26T23:47:49.306Z,1627343269.306 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-26T23:47:49.306Z,1627343269.306 [Default:CheckIn:C.Wait] Stopped 2021-07-26T23:47:49.307Z,1627343269.307 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-26T23:47:49.307Z,1627343269.307 [Default:CheckIn:D] Running Loop=1 2021-07-26T23:47:49.715Z,1627343269.715 [Default:CheckIn:D] Stopped 2021-07-26T23:47:49.715Z,1627343269.715 [Default:CheckIn:E] Running Loop=1 2021-07-26T23:47:50.123Z,1627343270.123 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 63.306913 min 2021-07-26T23:47:50.127Z,1627343270.127 [Default:CheckIn:E] Stopped 2021-07-26T23:47:50.127Z,1627343270.127 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-26T23:47:50.127Z,1627343270.127 [Default:CheckIn] Stopped 2021-07-26T23:47:50.128Z,1627343270.128 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-26T23:47:50.128Z,1627343270.128 [Default:CheckIn](INFO): Running loop #10 2021-07-26T23:47:50.128Z,1627343270.128 [Default:CheckIn] Running Loop=10 2021-07-26T23:47:50.128Z,1627343270.128 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-26T23:47:50.128Z,1627343270.128 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-26T23:47:52.127Z,1627343272.127 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,234751.00,A,3648.17270,N,12147.28671,W,1.322,177.36,260721,,,D*78 2021-07-26T23:47:52.129Z,1627343272.129 [NAL9602](INFO): GPS fix at 20210726T234751: (36.802878, -121.788112) 2021-07-26T23:47:52.140Z,1627343272.140 [Default:CheckIn:Read_GPS] Stopped 2021-07-26T23:47:52.140Z,1627343272.140 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-26T23:48:00.671Z,1627343280.671 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210726T232245/Courier0015.lzma 2021-07-26T23:48:01.673Z,1627343281.673 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Courier0015.lzma.bak 2021-07-26T23:48:01.673Z,1627343281.673 [DataOverHttps](INFO): SBD MOMSN=15762381 2021-07-26T23:48:22.889Z,1627343302.889 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-07-26T23:48:22.971Z,1627343302.971 [NAL9602](ERROR): received: +CSQ:0 OK520, 2, 0, 0, 0 OK 2021-07-26T23:48:23.347Z,1627343303.347 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20210726T232245/Express0016.lzma 2021-07-26T23:48:24.349Z,1627343304.349 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Express0016.lzma.bak 2021-07-26T23:48:24.350Z,1627343304.350 [DataOverHttps](INFO): SBD MOMSN=15762384 2021-07-26T23:48:29.905Z,1627343309.905 [Default:CheckIn:Read_Iridium] Stopped 2021-07-26T23:48:29.905Z,1627343309.905 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-26T23:48:29.905Z,1627343309.905 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-26T23:50:47.742Z,1627343447.742 [NAL9602](INFO): SBD MO Status=2, MOMSN=28520, MT Status=2, MTMSN=0 2021-07-26T23:50:47.742Z,1627343447.742 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-26T23:51:11.578Z,1627343471.578 [NAL9602](INFO): SBD MO Status=2, MOMSN=28520, MT Status=2, MTMSN=0 2021-07-26T23:51:11.578Z,1627343471.578 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-26T23:51:41.906Z,1627343501.906 [NAL9602](INFO): SBD MO Status=2, MOMSN=28520, MT Status=2, MTMSN=0 2021-07-26T23:51:41.906Z,1627343501.906 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-26T23:52:54.297Z,1627343574.297 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-26T23:53:24.991Z,1627343604.991 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-26T23:53:30.655Z,1627343610.655 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-26T23:53:30.655Z,1627343610.655 [Default:CheckIn:C.Wait] Stopped 2021-07-26T23:53:30.655Z,1627343610.655 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-26T23:53:30.655Z,1627343610.655 [Default:CheckIn:D] Running Loop=1 2021-07-26T23:53:31.057Z,1627343611.057 [Default:CheckIn:D] Stopped 2021-07-26T23:53:31.057Z,1627343611.057 [Default:CheckIn:E] Running Loop=1 2021-07-26T23:53:31.472Z,1627343611.473 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 68.995947 min 2021-07-26T23:53:31.473Z,1627343611.473 [Default:CheckIn:E] Stopped 2021-07-26T23:53:31.473Z,1627343611.473 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-26T23:53:31.473Z,1627343611.473 [Default:CheckIn] Stopped 2021-07-26T23:53:31.473Z,1627343611.473 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-26T23:53:31.473Z,1627343611.473 [Default:CheckIn](INFO): Running loop #11 2021-07-26T23:53:31.473Z,1627343611.473 [Default:CheckIn] Running Loop=11 2021-07-26T23:53:31.473Z,1627343611.473 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-26T23:53:31.474Z,1627343611.474 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-26T23:53:33.470Z,1627343613.470 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,235332.00,A,3648.16907,N,12147.27978,W,0.894,165.44,260721,,,A*7F 2021-07-26T23:53:33.473Z,1627343613.473 [NAL9602](INFO): GPS fix at 20210726T235332: (36.802818, -121.787996) 2021-07-26T23:53:33.485Z,1627343613.485 [Default:CheckIn:Read_GPS] Stopped 2021-07-26T23:53:33.485Z,1627343613.485 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-26T23:53:42.531Z,1627343622.531 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210726T232245/Courier0018.lzma 2021-07-26T23:53:43.533Z,1627343623.533 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Courier0018.lzma.bak 2021-07-26T23:53:43.533Z,1627343623.533 [DataOverHttps](INFO): SBD MOMSN=15762388 2021-07-26T23:54:01.607Z,1627343641.607 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20210726T232245/Express0019.lzma 2021-07-26T23:54:02.609Z,1627343642.609 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Express0019.lzma.bak 2021-07-26T23:54:02.609Z,1627343642.609 [DataOverHttps](INFO): SBD MOMSN=15762391 2021-07-26T23:54:04.173Z,1627343644.173 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-07-26T23:54:04.255Z,1627343644.255 [NAL9602](ERROR): received: +CSQ:0 OK520, 2, 0, 0, 0 OK 2021-07-26T23:54:05.815Z,1627343645.815 [Default:CheckIn:Read_Iridium] Stopped 2021-07-26T23:54:05.816Z,1627343645.816 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-26T23:54:05.816Z,1627343645.816 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-26T23:58:35.397Z,1627343915.397 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-26T23:59:06.080Z,1627343946.080 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-26T23:59:06.509Z,1627343946.509 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-26T23:59:06.509Z,1627343946.509 [Default:CheckIn:C.Wait] Stopped 2021-07-26T23:59:06.509Z,1627343946.509 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-26T23:59:06.509Z,1627343946.509 [Default:CheckIn:D] Running Loop=1 2021-07-26T23:59:06.911Z,1627343946.911 [Default:CheckIn:D] Stopped 2021-07-26T23:59:06.911Z,1627343946.911 [Default:CheckIn:E] Running Loop=1 2021-07-26T23:59:07.311Z,1627343947.311 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 74.593514 min 2021-07-26T23:59:07.311Z,1627343947.311 [Default:CheckIn:E] Stopped 2021-07-26T23:59:07.311Z,1627343947.311 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-26T23:59:07.311Z,1627343947.311 [Default:CheckIn] Stopped 2021-07-26T23:59:07.312Z,1627343947.312 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-26T23:59:07.312Z,1627343947.312 [Default:CheckIn](INFO): Running loop #12 2021-07-26T23:59:07.312Z,1627343947.312 [Default:CheckIn] Running Loop=12 2021-07-26T23:59:07.312Z,1627343947.312 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-26T23:59:07.312Z,1627343947.312 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-26T23:59:09.326Z,1627343949.326 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,235908.00,A,3648.16434,N,12147.28401,W,0.233,165.44,260721,,,D*7F 2021-07-26T23:59:09.329Z,1627343949.329 [NAL9602](INFO): GPS fix at 20210726T235908: (36.802739, -121.788067) 2021-07-26T23:59:09.340Z,1627343949.340 [Default:CheckIn:Read_GPS] Stopped 2021-07-26T23:59:09.340Z,1627343949.340 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-26T23:59:17.963Z,1627343957.963 [DataOverHttps](INFO): Sending 70 bytes from file Logs/20210726T232245/Courier0021.lzma 2021-07-26T23:59:18.965Z,1627343958.965 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Courier0021.lzma.bak 2021-07-26T23:59:18.965Z,1627343958.965 [DataOverHttps](INFO): SBD MOMSN=15762395 2021-07-26T23:59:37.139Z,1627343977.139 [DataOverHttps](INFO): Sending 204 bytes from file Logs/20210726T232245/Express0022.lzma 2021-07-26T23:59:38.141Z,1627343978.141 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Express0022.lzma.bak 2021-07-26T23:59:38.141Z,1627343978.141 [DataOverHttps](INFO): SBD MOMSN=15762398 2021-07-26T23:59:40.017Z,1627343980.017 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-07-26T23:59:40.095Z,1627343980.095 [NAL9602](ERROR): received: +CSQ:0 OK520, 2, 0, 0, 0 OK 2021-07-26T23:59:41.662Z,1627343981.662 [Default:CheckIn:Read_Iridium] Stopped 2021-07-26T23:59:41.662Z,1627343981.662 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-26T23:59:41.662Z,1627343981.662 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-26T23:59:58.781Z,1627343998.781 [DataOverHttps](IMPORTANT): SBD MTMSN=20210726T235957 2021-07-27T00:00:06.356Z,1627344006.356 [DataOverHttps](INFO): Received command:strobe off 2021-07-27T00:00:06.451Z,1627344006.451 [CommandLine](IMPORTANT): got command strobe off 2021-07-27T00:00:06.452Z,1627344006.452 [CommandLine](IMPORTANT): Deactivating strobe 2021-07-27T00:00:26.882Z,1627344026.882 [NAL9602](INFO): SBD MO Status=2, MOMSN=28520, MT Status=2, MTMSN=0 2021-07-27T00:00:26.882Z,1627344026.882 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-27T00:04:11.505Z,1627344251.505 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-27T00:04:42.212Z,1627344282.212 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-27T00:04:42.225Z,1627344282.225 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-27T00:04:42.225Z,1627344282.225 [Default:CheckIn:C.Wait] Stopped 2021-07-27T00:04:42.225Z,1627344282.225 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-27T00:04:42.225Z,1627344282.225 [Default:CheckIn:D] Running Loop=1 2021-07-27T00:04:42.625Z,1627344282.625 [Default:CheckIn:D] Stopped 2021-07-27T00:04:42.625Z,1627344282.625 [Default:CheckIn:E] Running Loop=1 2021-07-27T00:04:43.041Z,1627344283.041 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 80.188745 min 2021-07-27T00:04:43.041Z,1627344283.041 [Default:CheckIn:E] Stopped 2021-07-27T00:04:43.041Z,1627344283.041 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-27T00:04:43.041Z,1627344283.041 [Default:CheckIn] Stopped 2021-07-27T00:04:43.041Z,1627344283.041 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-27T00:04:43.041Z,1627344283.041 [Default:CheckIn](INFO): Running loop #13 2021-07-27T00:04:43.042Z,1627344283.042 [Default:CheckIn] Running Loop=13 2021-07-27T00:04:43.042Z,1627344283.042 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-27T00:04:43.042Z,1627344283.042 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-27T00:04:45.038Z,1627344285.038 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,000444.00,A,3648.16372,N,12147.28026,W,0.214,165.44,270721,,,D*7E 2021-07-27T00:04:45.041Z,1627344285.041 [NAL9602](INFO): GPS fix at 20210727T000444: (36.802729, -121.788004) 2021-07-27T00:04:45.052Z,1627344285.052 [Default:CheckIn:Read_GPS] Stopped 2021-07-27T00:04:45.052Z,1627344285.052 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-27T00:04:54.331Z,1627344294.331 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210726T232245/Courier0024.lzma 2021-07-27T00:04:55.333Z,1627344295.333 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Courier0024.lzma.bak 2021-07-27T00:04:55.333Z,1627344295.333 [DataOverHttps](INFO): SBD MOMSN=15762404 2021-07-27T00:05:13.420Z,1627344313.420 [DataOverHttps](INFO): Sending 306 bytes from file Logs/20210726T232245/Express0025.lzma 2021-07-27T00:05:14.421Z,1627344314.421 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Express0025.lzma.bak 2021-07-27T00:05:14.421Z,1627344314.421 [DataOverHttps](INFO): SBD MOMSN=15762407 2021-07-27T00:05:15.741Z,1627344315.741 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-07-27T00:05:15.823Z,1627344315.823 [NAL9602](ERROR): received: +CSQ:0 OK520, 2, 0, 0, 0 OK 2021-07-27T00:05:32.947Z,1627344332.947 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20210726T232245/Express0028.lzma 2021-07-27T00:05:33.449Z,1627344333.449 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Express0028.lzma.bak 2021-07-27T00:05:33.449Z,1627344333.449 [DataOverHttps](INFO): SBD MOMSN=15762414 2021-07-27T00:05:37.184Z,1627344337.184 [Default:CheckIn:Read_Iridium] Stopped 2021-07-27T00:05:37.184Z,1627344337.184 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-27T00:05:37.184Z,1627344337.184 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-27T00:07:24.714Z,1627344444.714 [NAL9602](INFO): SBD MO Status=2, MOMSN=28520, MT Status=2, MTMSN=0 2021-07-27T00:07:24.714Z,1627344444.714 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-27T00:07:57.814Z,1627344477.814 [NAL9602](INFO): SBD MO Status=2, MOMSN=28520, MT Status=2, MTMSN=0 2021-07-27T00:07:57.814Z,1627344477.814 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-27T00:08:28.170Z,1627344508.170 [NAL9602](INFO): SBD MO Status=2, MOMSN=28520, MT Status=2, MTMSN=0 2021-07-27T00:08:28.170Z,1627344508.170 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-27T00:08:51.202Z,1627344531.202 [NAL9602](INFO): SBD MO Status=0, MOMSN=28520, MT Status=0, MTMSN=0 2021-07-27T00:08:51.202Z,1627344531.202 [NAL9602](INFO): No messages in MT queue 2021-07-27T00:09:21.908Z,1627344561.908 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-27T00:10:37.946Z,1627344637.946 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-27T00:10:37.946Z,1627344637.946 [Default:CheckIn:C.Wait] Stopped 2021-07-27T00:10:37.947Z,1627344637.947 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-27T00:10:37.947Z,1627344637.947 [Default:CheckIn:D] Running Loop=1 2021-07-27T00:10:38.363Z,1627344638.363 [Default:CheckIn:D] Stopped 2021-07-27T00:10:38.363Z,1627344638.363 [Default:CheckIn:E] Running Loop=1 2021-07-27T00:10:38.769Z,1627344638.769 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 86.117716 min 2021-07-27T00:10:38.769Z,1627344638.769 [Default:CheckIn:E] Stopped 2021-07-27T00:10:38.770Z,1627344638.770 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-27T00:10:38.770Z,1627344638.770 [Default:CheckIn] Stopped 2021-07-27T00:10:38.770Z,1627344638.770 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-27T00:10:38.770Z,1627344638.770 [Default:CheckIn](INFO): Running loop #14 2021-07-27T00:10:38.770Z,1627344638.770 [Default:CheckIn] Running Loop=14 2021-07-27T00:10:38.770Z,1627344638.770 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-27T00:10:38.770Z,1627344638.770 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-27T00:10:40.762Z,1627344640.762 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,001040.00,A,3648.16177,N,12147.28306,W,0.117,0.00,270721,,,D*7B 2021-07-27T00:10:40.765Z,1627344640.765 [NAL9602](INFO): GPS fix at 20210727T001040: (36.802696, -121.788051) 2021-07-27T00:10:40.776Z,1627344640.776 [Default:CheckIn:Read_GPS] Stopped 2021-07-27T00:10:40.776Z,1627344640.776 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-27T00:10:49.363Z,1627344649.363 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210726T232245/Courier0030.lzma 2021-07-27T00:10:50.365Z,1627344650.365 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Courier0030.lzma.bak 2021-07-27T00:10:50.365Z,1627344650.365 [DataOverHttps](INFO): SBD MOMSN=15762416 2021-07-27T00:11:08.495Z,1627344668.495 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20210726T232245/Express0031.lzma 2021-07-27T00:11:09.497Z,1627344669.497 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Express0031.lzma.bak 2021-07-27T00:11:09.497Z,1627344669.497 [DataOverHttps](INFO): SBD MOMSN=15762419 2021-07-27T00:11:12.741Z,1627344672.741 [Default:CheckIn:Read_Iridium] Stopped 2021-07-27T00:11:12.741Z,1627344672.741 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-27T00:11:12.741Z,1627344672.741 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-27T00:15:43.490Z,1627344943.490 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-27T00:16:13.395Z,1627344973.395 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-27T00:16:13.395Z,1627344973.395 [Default:CheckIn:C.Wait] Stopped 2021-07-27T00:16:13.395Z,1627344973.395 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-27T00:16:13.395Z,1627344973.395 [Default:CheckIn:D] Running Loop=1 2021-07-27T00:16:13.821Z,1627344973.821 [Default:CheckIn:D] Stopped 2021-07-27T00:16:13.821Z,1627344973.821 [Default:CheckIn:E] Running Loop=1 2021-07-27T00:16:14.203Z,1627344974.203 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-27T00:16:14.216Z,1627344974.216 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 91.708683 min 2021-07-27T00:16:14.216Z,1627344974.216 [Default:CheckIn:E] Stopped 2021-07-27T00:16:14.216Z,1627344974.216 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-27T00:16:14.216Z,1627344974.216 [Default:CheckIn] Stopped 2021-07-27T00:16:14.216Z,1627344974.216 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-27T00:16:14.217Z,1627344974.217 [Default:CheckIn](INFO): Running loop #15 2021-07-27T00:16:14.217Z,1627344974.217 [Default:CheckIn] Running Loop=15 2021-07-27T00:16:14.217Z,1627344974.217 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-27T00:16:14.217Z,1627344974.217 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-27T00:16:16.218Z,1627344976.218 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,001615.00,A,3648.16256,N,12147.28505,W,0.680,164.35,270721,,,D*74 2021-07-27T00:16:16.221Z,1627344976.221 [NAL9602](INFO): GPS fix at 20210727T001615: (36.802709, -121.788084) 2021-07-27T00:16:16.232Z,1627344976.232 [Default:CheckIn:Read_GPS] Stopped 2021-07-27T00:16:16.232Z,1627344976.232 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-27T00:16:28.799Z,1627344988.799 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210726T232245/Courier0033.lzma 2021-07-27T00:16:29.801Z,1627344989.801 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Courier0033.lzma.bak 2021-07-27T00:16:29.802Z,1627344989.802 [DataOverHttps](INFO): SBD MOMSN=15762423 2021-07-27T00:16:46.664Z,1627345006.664 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-07-27T00:16:46.739Z,1627345006.739 [NAL9602](ERROR): received: +CSQ:0 OK520, 0, 0, 0, 0 OK 2021-07-27T00:16:53.479Z,1627345013.479 [DataOverHttps](INFO): Sending 205 bytes from file Logs/20210726T232245/Express0034.lzma 2021-07-27T00:16:54.482Z,1627345014.482 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Express0034.lzma.bak 2021-07-27T00:16:54.482Z,1627345014.482 [DataOverHttps](INFO): SBD MOMSN=15762426 2021-07-27T00:16:58.421Z,1627345018.421 [Default:CheckIn:Read_Iridium] Stopped 2021-07-27T00:16:58.421Z,1627345018.421 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-27T00:16:58.421Z,1627345018.421 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-27T00:17:28.278Z,1627345048.278 [NAL9602](INFO): SBD MO Status=2, MOMSN=28521, MT Status=2, MTMSN=0 2021-07-27T00:17:28.278Z,1627345048.278 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-27T00:17:38.386Z,1627345058.386 [NAL9602](INFO): SBD MO Status=0, MOMSN=28521, MT Status=0, MTMSN=0 2021-07-27T00:17:38.386Z,1627345058.386 [NAL9602](INFO): No messages in MT queue 2021-07-27T00:18:09.082Z,1627345089.082 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-27T00:21:58.986Z,1627345318.986 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-27T00:21:58.986Z,1627345318.986 [Default:CheckIn:C.Wait] Stopped 2021-07-27T00:21:58.987Z,1627345318.987 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-27T00:21:58.987Z,1627345318.987 [Default:CheckIn:D] Running Loop=1 2021-07-27T00:21:59.387Z,1627345319.387 [Default:CheckIn:D] Stopped 2021-07-27T00:21:59.387Z,1627345319.387 [Default:CheckIn:E] Running Loop=1 2021-07-27T00:21:59.797Z,1627345319.797 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 97.468115 min 2021-07-27T00:21:59.797Z,1627345319.797 [Default:CheckIn:E] Stopped 2021-07-27T00:21:59.798Z,1627345319.798 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-27T00:21:59.798Z,1627345319.798 [Default:CheckIn] Stopped 2021-07-27T00:21:59.798Z,1627345319.798 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-27T00:21:59.798Z,1627345319.798 [Default:CheckIn](INFO): Running loop #16 2021-07-27T00:21:59.798Z,1627345319.798 [Default:CheckIn] Running Loop=16 2021-07-27T00:21:59.798Z,1627345319.798 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-27T00:21:59.798Z,1627345319.798 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-27T00:22:01.802Z,1627345321.802 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,002201.00,A,3648.16196,N,12147.27714,W,0.428,164.35,270721,,,D*74 2021-07-27T00:22:01.805Z,1627345321.805 [NAL9602](INFO): GPS fix at 20210727T002201: (36.802699, -121.787952) 2021-07-27T00:22:01.840Z,1627345321.840 [Default:CheckIn:Read_GPS] Stopped 2021-07-27T00:22:01.840Z,1627345321.840 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-27T00:22:10.827Z,1627345330.827 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210726T232245/Courier0036.lzma 2021-07-27T00:22:12.593Z,1627345332.593 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Courier0036.lzma.bak 2021-07-27T00:22:12.593Z,1627345332.593 [DataOverHttps](INFO): SBD MOMSN=15762431 2021-07-27T00:22:36.439Z,1627345356.439 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20210726T232245/Express0037.lzma 2021-07-27T00:22:37.441Z,1627345357.441 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Express0037.lzma.bak 2021-07-27T00:22:37.442Z,1627345357.442 [DataOverHttps](INFO): SBD MOMSN=15762434 2021-07-27T00:22:43.164Z,1627345363.164 [Default:CheckIn:Read_Iridium] Stopped 2021-07-27T00:22:43.164Z,1627345363.164 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-27T00:22:43.164Z,1627345363.164 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-27T00:26:34.374Z,1627345594.374 [NAL9602](INFO): SBD MO Status=0, MOMSN=28522, MT Status=0, MTMSN=0 2021-07-27T00:26:34.375Z,1627345594.375 [NAL9602](INFO): No messages in MT queue 2021-07-27T00:27:05.072Z,1627345625.072 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-27T00:27:43.878Z,1627345663.878 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-27T00:27:43.878Z,1627345663.878 [Default:CheckIn:C.Wait] Stopped 2021-07-27T00:27:43.878Z,1627345663.878 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-27T00:27:43.878Z,1627345663.878 [Default:CheckIn:D] Running Loop=1 2021-07-27T00:27:44.285Z,1627345664.285 [Default:CheckIn:D] Stopped 2021-07-27T00:27:44.285Z,1627345664.285 [Default:CheckIn:E] Running Loop=1 2021-07-27T00:27:44.683Z,1627345664.683 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 103.216423 min 2021-07-27T00:27:44.683Z,1627345664.683 [Default:CheckIn:E] Stopped 2021-07-27T00:27:44.715Z,1627345664.715 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-27T00:27:44.716Z,1627345664.716 [Default:CheckIn] Stopped 2021-07-27T00:27:44.716Z,1627345664.716 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-27T00:27:44.716Z,1627345664.716 [Default:CheckIn](INFO): Running loop #17 2021-07-27T00:27:44.716Z,1627345664.716 [Default:CheckIn] Running Loop=17 2021-07-27T00:27:44.716Z,1627345664.716 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-27T00:27:44.716Z,1627345664.716 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-27T00:27:46.694Z,1627345666.694 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,002745.00,A,3648.17229,N,12147.28319,W,0.175,336.21,270721,,,A*79 2021-07-27T00:27:46.697Z,1627345666.697 [NAL9602](INFO): GPS fix at 20210727T002745: (36.802872, -121.788053) 2021-07-27T00:27:46.708Z,1627345666.708 [Default:CheckIn:Read_GPS] Stopped 2021-07-27T00:27:46.708Z,1627345666.708 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-27T00:27:56.815Z,1627345676.815 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210726T232245/Courier0039.lzma 2021-07-27T00:27:57.817Z,1627345677.817 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Courier0039.lzma.bak 2021-07-27T00:27:57.817Z,1627345677.817 [DataOverHttps](INFO): SBD MOMSN=15762437 2021-07-27T00:28:16.099Z,1627345696.099 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20210726T232245/Express0040.lzma 2021-07-27T00:28:17.102Z,1627345697.102 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Express0040.lzma.bak 2021-07-27T00:28:17.102Z,1627345697.102 [DataOverHttps](INFO): SBD MOMSN=15762440 2021-07-27T00:28:22.707Z,1627345702.707 [Default:CheckIn:Read_Iridium] Stopped 2021-07-27T00:28:22.707Z,1627345702.707 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-27T00:28:22.707Z,1627345702.707 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-27T00:29:02.809Z,1627345742.809 [NAL9602](INFO): SBD MO Status=2, MOMSN=28523, MT Status=2, MTMSN=0 2021-07-27T00:29:02.809Z,1627345742.809 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-27T00:29:20.178Z,1627345760.178 [NAL9602](INFO): SBD MO Status=2, MOMSN=28523, MT Status=2, MTMSN=0 2021-07-27T00:29:20.178Z,1627345760.178 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-27T00:32:49.481Z,1627345969.481 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-27T00:33:20.164Z,1627346000.164 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-27T00:33:23.421Z,1627346003.421 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-27T00:33:23.421Z,1627346003.421 [Default:CheckIn:C.Wait] Stopped 2021-07-27T00:33:23.421Z,1627346003.421 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-27T00:33:23.421Z,1627346003.421 [Default:CheckIn:D] Running Loop=1 2021-07-27T00:33:23.817Z,1627346003.817 [Default:CheckIn:D] Stopped 2021-07-27T00:33:23.817Z,1627346003.817 [Default:CheckIn:E] Running Loop=1 2021-07-27T00:33:24.215Z,1627346004.215 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 108.875277 min 2021-07-27T00:33:24.215Z,1627346004.215 [Default:CheckIn:E] Stopped 2021-07-27T00:33:24.216Z,1627346004.216 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-27T00:33:24.216Z,1627346004.216 [Default:CheckIn] Stopped 2021-07-27T00:33:24.216Z,1627346004.216 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-27T00:33:24.216Z,1627346004.216 [Default:CheckIn](INFO): Running loop #18 2021-07-27T00:33:24.216Z,1627346004.216 [Default:CheckIn] Running Loop=18 2021-07-27T00:33:24.216Z,1627346004.216 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-27T00:33:24.216Z,1627346004.216 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-27T00:33:56.929Z,1627346036.929 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-07-27T00:33:57.007Z,1627346037.007 [NAL9602](ERROR): received: +CSQ:0 OK523, 2, 0, 0, 0 OK 2021-07-27T00:34:08.241Z,1627346048.241 [BPC1](ERROR): BPC1A: No match for serial number 1717 in BPC1A's battery stick inventory (sticks 1-32 in onboard configuration file). 2021-07-27T00:34:34.173Z,1627346074.173 [BPC1](ERROR): BPC1B: No match for serial number 1717 in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file). 2021-07-27T00:35:20.613Z,1627346120.613 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2021-07-27T00:35:20.616Z,1627346120.616 [BPC1](INFO): Received data from all battery sticks. 2021-07-27T00:36:15.174Z,1627346175.174 [NAL9602](INFO): SBD MO Status=2, MOMSN=28523, MT Status=2, MTMSN=0 2021-07-27T00:36:15.174Z,1627346175.174 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-27T00:38:24.601Z,1627346304.601 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-07-27T00:33:24.2Z 2021-07-27T00:38:24.602Z,1627346304.602 [Default:CheckIn:Read_GPS] Stopped 2021-07-27T00:38:24.602Z,1627346304.602 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-27T00:38:28.585Z,1627346308.585 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-27T00:38:28.694Z,1627346308.694 [DataOverHttps](INFO): Sending 50 bytes from file Logs/20210726T232245/Courier0042.lzma 2021-07-27T00:38:29.717Z,1627346309.717 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Courier0042.lzma.bak 2021-07-27T00:38:29.718Z,1627346309.718 [DataOverHttps](INFO): SBD MOMSN=15762444 2021-07-27T00:38:52.752Z,1627346332.752 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20210726T232245/Express0043.lzma 2021-07-27T00:38:53.753Z,1627346333.753 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Express0043.lzma.bak 2021-07-27T00:38:53.753Z,1627346333.753 [DataOverHttps](INFO): SBD MOMSN=15762446 2021-07-27T00:38:56.947Z,1627346336.947 [Default:CheckIn:Read_Iridium] Stopped 2021-07-27T00:38:56.947Z,1627346336.947 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-27T00:38:56.947Z,1627346336.947 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-27T00:38:59.348Z,1627346339.348 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-27T00:43:57.522Z,1627346637.522 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-27T00:43:57.522Z,1627346637.522 [Default:CheckIn:C.Wait] Stopped 2021-07-27T00:43:57.523Z,1627346637.523 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-27T00:43:57.523Z,1627346637.523 [Default:CheckIn:D] Running Loop=1 2021-07-27T00:43:57.925Z,1627346637.925 [Default:CheckIn:D] Stopped 2021-07-27T00:43:57.925Z,1627346637.925 [Default:CheckIn:E] Running Loop=1 2021-07-27T00:43:58.340Z,1627346638.340 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 119.443758 min 2021-07-27T00:43:58.340Z,1627346638.340 [Default:CheckIn:E] Stopped 2021-07-27T00:43:58.341Z,1627346638.341 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-27T00:43:58.341Z,1627346638.341 [Default:CheckIn] Stopped 2021-07-27T00:43:58.341Z,1627346638.341 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-27T00:43:58.341Z,1627346638.341 [Default:CheckIn](INFO): Running loop #19 2021-07-27T00:43:58.341Z,1627346638.341 [Default:CheckIn] Running Loop=19 2021-07-27T00:43:58.341Z,1627346638.341 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-27T00:43:58.341Z,1627346638.341 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-27T00:43:59.933Z,1627346639.933 [NAL9602](FAULT): GPS failed to acquire within timeout. 2021-07-27T00:43:59.933Z,1627346639.933 [NAL9602] Data Fault, FailCount= 1 2021-07-27T00:43:59.933Z,1627346639.933 [NAL9602](ERROR): Data Fault 2021-07-27T00:43:59.981Z,1627346639.981 [CBIT](ERROR): Data Fault in component: NAL9602 2021-07-27T00:44:00.336Z,1627346640.336 [NAL9602](INFO): Powering down 2021-07-27T00:44:01.166Z,1627346641.166 [CBIT](INFO): Clearing failed state for component NAL9602 2021-07-27T00:44:01.166Z,1627346641.166 [NAL9602] No Fault, FailCount= 1 2021-07-27T00:44:30.657Z,1627346670.657 [NAL9602](INFO): Powering up NAL9602 2021-07-27T00:44:41.569Z,1627346681.569 [NAL9602](INFO): NAL9602 initialized 2021-07-27T00:47:55.142Z,1627346875.142 [NAL9602](INFO): SBD MO Status=2, MOMSN=28523, MT Status=2, MTMSN=0 2021-07-27T00:47:55.142Z,1627346875.142 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-27T00:48:46.110Z,1627346926.110 [NAL9602](INFO): SBD MO Status=2, MOMSN=28523, MT Status=2, MTMSN=0 2021-07-27T00:48:46.110Z,1627346926.110 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-27T00:48:58.635Z,1627346938.635 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-07-27T00:43:58.3Z 2021-07-27T00:48:58.635Z,1627346938.635 [Default:CheckIn:Read_GPS] Stopped 2021-07-27T00:48:58.636Z,1627346938.636 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-27T00:49:06.878Z,1627346946.878 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20210726T232245/Courier0045.lzma 2021-07-27T00:49:07.877Z,1627346947.877 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Courier0045.lzma.bak 2021-07-27T00:49:07.877Z,1627346947.877 [DataOverHttps](INFO): SBD MOMSN=15762450 2021-07-27T00:49:25.951Z,1627346965.951 [DataOverHttps](INFO): Sending 227 bytes from file Logs/20210726T232245/Express0046.lzma 2021-07-27T00:49:26.953Z,1627346966.953 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Express0046.lzma.bak 2021-07-27T00:49:26.953Z,1627346966.953 [DataOverHttps](INFO): SBD MOMSN=15762452 2021-07-27T00:49:30.168Z,1627346970.168 [Default:CheckIn:Read_Iridium] Stopped 2021-07-27T00:49:30.168Z,1627346970.168 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-27T00:49:30.168Z,1627346970.168 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-27T00:49:45.085Z,1627346985.085 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-27T00:50:15.784Z,1627347015.784 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-27T00:54:30.781Z,1627347270.781 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-27T00:54:30.781Z,1627347270.781 [Default:CheckIn:C.Wait] Stopped 2021-07-27T00:54:30.781Z,1627347270.781 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-27T00:54:30.782Z,1627347270.782 [Default:CheckIn:D] Running Loop=1 2021-07-27T00:54:31.207Z,1627347271.207 [Default:CheckIn:D] Stopped 2021-07-27T00:54:31.207Z,1627347271.207 [Default:CheckIn:E] Running Loop=1 2021-07-27T00:54:31.585Z,1627347271.585 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 129.998324 min 2021-07-27T00:54:31.586Z,1627347271.586 [Default:CheckIn:E] Stopped 2021-07-27T00:54:31.586Z,1627347271.586 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-27T00:54:31.586Z,1627347271.586 [Default:CheckIn] Stopped 2021-07-27T00:54:31.586Z,1627347271.586 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-27T00:54:31.586Z,1627347271.586 [Default:CheckIn](INFO): Running loop #20 2021-07-27T00:54:31.586Z,1627347271.586 [Default:CheckIn] Running Loop=20 2021-07-27T00:54:31.586Z,1627347271.586 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-27T00:54:31.587Z,1627347271.587 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-27T00:54:33.595Z,1627347273.595 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,005432.00,A,3648.16439,N,12147.28180,W,1.827,0.00,270721,,,A*73 2021-07-27T00:54:33.597Z,1627347273.597 [NAL9602](INFO): GPS fix at 20210727T005432: (36.802740, -121.788030) 2021-07-27T00:54:33.641Z,1627347273.641 [Default:CheckIn:Read_GPS] Stopped 2021-07-27T00:54:33.642Z,1627347273.642 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-27T00:54:43.511Z,1627347283.511 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210726T232245/Courier0048.lzma 2021-07-27T00:54:44.514Z,1627347284.514 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Courier0048.lzma.bak 2021-07-27T00:54:44.514Z,1627347284.514 [DataOverHttps](INFO): SBD MOMSN=15762457 2021-07-27T00:55:02.979Z,1627347302.979 [DataOverHttps](INFO): Sending 208 bytes from file Logs/20210726T232245/Express0049.lzma 2021-07-27T00:55:03.981Z,1627347303.981 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Express0049.lzma.bak 2021-07-27T00:55:03.981Z,1627347303.981 [DataOverHttps](INFO): SBD MOMSN=15762460 2021-07-27T00:55:04.181Z,1627347304.181 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-07-27T00:55:04.259Z,1627347304.259 [NAL9602](ERROR): received: +CSQ:0 OK523, 2, 0, 0, 0 OK 2021-07-27T00:55:07.445Z,1627347307.445 [Default:CheckIn:Read_Iridium] Stopped 2021-07-27T00:55:07.445Z,1627347307.445 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-27T00:55:07.445Z,1627347307.445 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-27T00:57:03.882Z,1627347423.882 [NAL9602](INFO): SBD MO Status=2, MOMSN=28523, MT Status=2, MTMSN=0 2021-07-27T00:57:03.882Z,1627347423.882 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-27T00:57:51.150Z,1627347471.150 [NAL9602](INFO): SBD MO Status=2, MOMSN=28523, MT Status=2, MTMSN=0 2021-07-27T00:57:51.150Z,1627347471.150 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-27T00:58:04.078Z,1627347484.078 [NAL9602](INFO): SBD MO Status=2, MOMSN=28523, MT Status=2, MTMSN=0 2021-07-27T00:58:04.078Z,1627347484.078 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-27T00:59:35.451Z,1627347575.451 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-27T01:00:06.156Z,1627347606.156 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-27T01:00:08.183Z,1627347608.183 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-27T01:00:08.183Z,1627347608.183 [Default:CheckIn:C.Wait] Stopped 2021-07-27T01:00:08.183Z,1627347608.183 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-27T01:00:08.183Z,1627347608.183 [Default:CheckIn:D] Running Loop=1 2021-07-27T01:00:08.601Z,1627347608.601 [Default:CheckIn:D] Stopped 2021-07-27T01:00:08.601Z,1627347608.601 [Default:CheckIn:E] Running Loop=1 2021-07-27T01:00:08.991Z,1627347608.991 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 135.621680 min 2021-07-27T01:00:09.015Z,1627347609.015 [Default:CheckIn:E] Stopped 2021-07-27T01:00:09.016Z,1627347609.016 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-27T01:00:09.016Z,1627347609.016 [Default:CheckIn] Stopped 2021-07-27T01:00:09.016Z,1627347609.016 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-27T01:00:09.017Z,1627347609.017 [Default:CheckIn](INFO): Running loop #21 2021-07-27T01:00:09.017Z,1627347609.017 [Default:CheckIn] Running Loop=21 2021-07-27T01:00:09.018Z,1627347609.018 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-27T01:00:09.018Z,1627347609.018 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-27T01:00:11.006Z,1627347611.006 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,010010.00,A,3648.16688,N,12147.28472,W,0.136,0.00,270721,,,A*7B 2021-07-27T01:00:11.009Z,1627347611.009 [NAL9602](INFO): GPS fix at 20210727T010010: (36.802781, -121.788079) 2021-07-27T01:00:11.049Z,1627347611.049 [Default:CheckIn:Read_GPS] Stopped 2021-07-27T01:00:11.049Z,1627347611.049 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-27T01:00:23.563Z,1627347623.563 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210726T232245/Courier0051.lzma 2021-07-27T01:00:24.565Z,1627347624.565 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Courier0051.lzma.bak 2021-07-27T01:00:24.565Z,1627347624.565 [DataOverHttps](INFO): SBD MOMSN=15762464 2021-07-27T01:00:41.469Z,1627347641.469 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-07-27T01:00:41.551Z,1627347641.551 [NAL9602](ERROR): received: +CSQ:0 OK523, 2, 0, 0, 0 OK 2021-07-27T01:00:47.947Z,1627347647.947 [DataOverHttps](INFO): Sending 205 bytes from file Logs/20210726T232245/Express0052.lzma 2021-07-27T01:00:48.949Z,1627347648.949 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Express0052.lzma.bak 2021-07-27T01:00:48.949Z,1627347648.949 [DataOverHttps](INFO): SBD MOMSN=15762467 2021-07-27T01:00:52.420Z,1627347652.420 [Default:CheckIn:Read_Iridium] Stopped 2021-07-27T01:00:52.420Z,1627347652.420 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-27T01:00:52.420Z,1627347652.420 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-27T01:05:13.361Z,1627347913.361 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-27T01:05:44.066Z,1627347944.066 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-27T01:05:52.966Z,1627347952.966 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-27T01:05:52.967Z,1627347952.967 [Default:CheckIn:C.Wait] Stopped 2021-07-27T01:05:52.967Z,1627347952.967 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-27T01:05:52.967Z,1627347952.967 [Default:CheckIn:D] Running Loop=1 2021-07-27T01:05:53.370Z,1627347953.370 [Default:CheckIn:D] Stopped 2021-07-27T01:05:53.370Z,1627347953.370 [Default:CheckIn:E] Running Loop=1 2021-07-27T01:05:53.783Z,1627347953.783 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 141.367839 min 2021-07-27T01:05:53.783Z,1627347953.783 [Default:CheckIn:E] Stopped 2021-07-27T01:05:53.784Z,1627347953.784 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-27T01:05:53.784Z,1627347953.784 [Default:CheckIn] Stopped 2021-07-27T01:05:53.784Z,1627347953.784 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-27T01:05:53.784Z,1627347953.784 [Default:CheckIn](INFO): Running loop #22 2021-07-27T01:05:53.784Z,1627347953.784 [Default:CheckIn] Running Loop=22 2021-07-27T01:05:53.784Z,1627347953.784 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-27T01:05:53.784Z,1627347953.784 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-27T01:05:55.782Z,1627347955.782 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,010555.00,A,3648.16150,N,12147.28330,W,0.350,0.00,270721,,,A*7E 2021-07-27T01:05:55.785Z,1627347955.785 [NAL9602](INFO): GPS fix at 20210727T010555: (36.802692, -121.788055) 2021-07-27T01:05:55.820Z,1627347955.820 [Default:CheckIn:Read_GPS] Stopped 2021-07-27T01:05:55.820Z,1627347955.820 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-27T01:06:04.703Z,1627347964.703 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210726T232245/Courier0054.lzma 2021-07-27T01:06:05.705Z,1627347965.705 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Courier0054.lzma.bak 2021-07-27T01:06:05.706Z,1627347965.706 [DataOverHttps](INFO): SBD MOMSN=15762471 2021-07-27T01:06:26.549Z,1627347986.549 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-07-27T01:06:26.631Z,1627347986.631 [NAL9602](ERROR): received: +CSQ:0 OK523, 2, 0, 0, 0 OK 2021-07-27T01:06:26.707Z,1627347986.707 [DataOverHttps](INFO): Sending 208 bytes from file Logs/20210726T232245/Express0055.lzma 2021-07-27T01:06:27.705Z,1627347987.705 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Express0055.lzma.bak 2021-07-27T01:06:27.706Z,1627347987.706 [DataOverHttps](INFO): SBD MOMSN=15762474 2021-07-27T01:06:33.105Z,1627347993.105 [Default:CheckIn:Read_Iridium] Stopped 2021-07-27T01:06:33.106Z,1627347993.106 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-27T01:06:33.106Z,1627347993.106 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-27T01:07:31.310Z,1627348051.310 [NAL9602](INFO): SBD MO Status=2, MOMSN=28523, MT Status=2, MTMSN=0 2021-07-27T01:07:31.310Z,1627348051.310 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-27T01:10:58.269Z,1627348258.269 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-27T01:11:28.972Z,1627348288.972 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-27T01:11:33.830Z,1627348293.830 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-27T01:11:33.830Z,1627348293.830 [Default:CheckIn:C.Wait] Stopped 2021-07-27T01:11:33.831Z,1627348293.831 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-27T01:11:33.831Z,1627348293.831 [Default:CheckIn:D] Running Loop=1 2021-07-27T01:11:34.239Z,1627348294.239 [Default:CheckIn:D] Stopped 2021-07-27T01:11:34.239Z,1627348294.239 [Default:CheckIn:E] Running Loop=1 2021-07-27T01:11:34.643Z,1627348294.643 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 147.048975 min 2021-07-27T01:11:34.643Z,1627348294.643 [Default:CheckIn:E] Stopped 2021-07-27T01:11:34.644Z,1627348294.644 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-27T01:11:34.644Z,1627348294.644 [Default:CheckIn] Stopped 2021-07-27T01:11:34.644Z,1627348294.644 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-27T01:11:34.644Z,1627348294.644 [Default:CheckIn](INFO): Running loop #23 2021-07-27T01:11:34.644Z,1627348294.644 [Default:CheckIn] Running Loop=23 2021-07-27T01:11:34.644Z,1627348294.644 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-27T01:11:34.644Z,1627348294.644 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-27T01:11:36.647Z,1627348296.647 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,011135.00,A,3648.16100,N,12147.28031,W,0.797,349.85,270721,,,D*73 2021-07-27T01:11:36.649Z,1627348296.649 [NAL9602](INFO): GPS fix at 20210727T011135: (36.802683, -121.788005) 2021-07-27T01:11:36.685Z,1627348296.685 [Default:CheckIn:Read_GPS] Stopped 2021-07-27T01:11:36.685Z,1627348296.685 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-27T01:11:45.131Z,1627348305.131 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210726T232245/Courier0057.lzma 2021-07-27T01:11:46.133Z,1627348306.133 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Courier0057.lzma.bak 2021-07-27T01:11:46.133Z,1627348306.133 [DataOverHttps](INFO): SBD MOMSN=15762478 2021-07-27T01:12:05.055Z,1627348325.055 [DataOverHttps](INFO): Sending 205 bytes from file Logs/20210726T232245/Express0058.lzma 2021-07-27T01:12:06.057Z,1627348326.057 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Express0058.lzma.bak 2021-07-27T01:12:06.058Z,1627348326.058 [DataOverHttps](INFO): SBD MOMSN=15762481 2021-07-27T01:12:07.349Z,1627348327.349 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-07-27T01:12:07.431Z,1627348327.431 [NAL9602](ERROR): received: +CSQ:0 OK523, 2, 0, 0, 0 OK 2021-07-27T01:12:09.385Z,1627348329.385 [Default:CheckIn:Read_Iridium] Stopped 2021-07-27T01:12:09.385Z,1627348329.385 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-27T01:12:09.385Z,1627348329.385 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-27T01:15:13.474Z,1627348513.474 [NAL9602](INFO): SBD MO Status=2, MOMSN=28523, MT Status=2, MTMSN=0 2021-07-27T01:15:13.475Z,1627348513.475 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-27T01:16:39.186Z,1627348599.186 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-27T01:17:09.885Z,1627348629.885 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-27T01:17:09.897Z,1627348629.897 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-27T01:17:09.897Z,1627348629.897 [Default:CheckIn:C.Wait] Stopped 2021-07-27T01:17:09.897Z,1627348629.897 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-27T01:17:09.898Z,1627348629.898 [Default:CheckIn:D] Running Loop=1 2021-07-27T01:17:10.301Z,1627348630.301 [Default:CheckIn:D] Stopped 2021-07-27T01:17:10.301Z,1627348630.301 [Default:CheckIn:E] Running Loop=1 2021-07-27T01:17:10.724Z,1627348630.724 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 152.650016 min 2021-07-27T01:17:10.724Z,1627348630.724 [Default:CheckIn:E] Stopped 2021-07-27T01:17:10.724Z,1627348630.724 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-27T01:17:10.724Z,1627348630.724 [Default:CheckIn] Stopped 2021-07-27T01:17:10.724Z,1627348630.724 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-27T01:17:10.724Z,1627348630.724 [Default:CheckIn](INFO): Running loop #24 2021-07-27T01:17:10.724Z,1627348630.724 [Default:CheckIn] Running Loop=24 2021-07-27T01:17:10.725Z,1627348630.725 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-27T01:17:10.725Z,1627348630.725 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-27T01:17:12.754Z,1627348632.754 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,011712.00,A,3648.16000,N,12147.27951,W,0.136,219.08,270721,,,D*7D 2021-07-27T01:17:12.756Z,1627348632.756 [NAL9602](INFO): GPS fix at 20210727T011712: (36.802667, -121.787992) 2021-07-27T01:17:12.772Z,1627348632.772 [Default:CheckIn:Read_GPS] Stopped 2021-07-27T01:17:12.772Z,1627348632.772 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-27T01:17:21.507Z,1627348641.507 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210726T232245/Courier0060.lzma 2021-07-27T01:17:22.509Z,1627348642.509 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Courier0060.lzma.bak 2021-07-27T01:17:22.509Z,1627348642.509 [DataOverHttps](INFO): SBD MOMSN=15762485 2021-07-27T01:17:40.559Z,1627348660.559 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20210726T232245/Express0061.lzma 2021-07-27T01:17:41.561Z,1627348661.561 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Express0061.lzma.bak 2021-07-27T01:17:41.561Z,1627348661.561 [DataOverHttps](INFO): SBD MOMSN=15762488 2021-07-27T01:17:43.431Z,1627348663.431 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-07-27T01:17:43.507Z,1627348663.507 [NAL9602](ERROR): received: +CSQ:0 OK523, 2, 0, 0, 0 OK 2021-07-27T01:17:45.085Z,1627348665.085 [Default:CheckIn:Read_Iridium] Stopped 2021-07-27T01:17:45.085Z,1627348665.085 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-27T01:17:45.085Z,1627348665.085 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-27T01:22:15.417Z,1627348935.417 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-27T01:22:45.789Z,1627348965.789 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-27T01:22:45.789Z,1627348965.789 [Default:CheckIn:C.Wait] Stopped 2021-07-27T01:22:45.789Z,1627348965.789 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-27T01:22:45.790Z,1627348965.790 [Default:CheckIn:D] Running Loop=1 2021-07-27T01:22:46.164Z,1627348966.164 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-27T01:22:46.177Z,1627348966.177 [Default:CheckIn:D] Stopped 2021-07-27T01:22:46.177Z,1627348966.177 [Default:CheckIn:E] Running Loop=1 2021-07-27T01:22:46.580Z,1627348966.580 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 158.247949 min 2021-07-27T01:22:46.580Z,1627348966.580 [Default:CheckIn:E] Stopped 2021-07-27T01:22:46.580Z,1627348966.580 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-27T01:22:46.580Z,1627348966.580 [Default:CheckIn] Stopped 2021-07-27T01:22:46.580Z,1627348966.580 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-27T01:22:46.581Z,1627348966.581 [Default:CheckIn](INFO): Running loop #25 2021-07-27T01:22:46.581Z,1627348966.581 [Default:CheckIn] Running Loop=25 2021-07-27T01:22:46.581Z,1627348966.581 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-27T01:22:46.581Z,1627348966.581 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-27T01:22:48.591Z,1627348968.591 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,012247.00,A,3648.16440,N,12147.28185,W,0.097,319.23,270721,,,D*77 2021-07-27T01:22:48.593Z,1627348968.593 [NAL9602](INFO): GPS fix at 20210727T012247: (36.802740, -121.788031) 2021-07-27T01:22:48.635Z,1627348968.635 [Default:CheckIn:Read_GPS] Stopped 2021-07-27T01:22:48.636Z,1627348968.636 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-27T01:22:57.199Z,1627348977.199 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210726T232245/Courier0063.lzma 2021-07-27T01:22:58.201Z,1627348978.201 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Courier0063.lzma.bak 2021-07-27T01:22:58.201Z,1627348978.201 [DataOverHttps](INFO): SBD MOMSN=15762492 2021-07-27T01:23:16.971Z,1627348996.971 [DataOverHttps](INFO): Sending 209 bytes from file Logs/20210726T232245/Express0064.lzma 2021-07-27T01:23:17.973Z,1627348997.973 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Express0064.lzma.bak 2021-07-27T01:23:17.973Z,1627348997.973 [DataOverHttps](INFO): SBD MOMSN=15762495 2021-07-27T01:23:19.293Z,1627348999.293 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-07-27T01:23:19.371Z,1627348999.371 [NAL9602](ERROR): received: +CSQ:0 OK523, 2, 0, 0, 0 OK 2021-07-27T01:23:21.322Z,1627349001.322 [Default:CheckIn:Read_Iridium] Stopped 2021-07-27T01:23:21.323Z,1627349001.323 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-27T01:23:21.323Z,1627349001.323 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-27T01:27:50.379Z,1627349270.379 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-27T01:28:21.080Z,1627349301.080 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-27T01:28:21.923Z,1627349301.923 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-27T01:28:21.923Z,1627349301.923 [Default:CheckIn:C.Wait] Stopped 2021-07-27T01:28:21.923Z,1627349301.923 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-27T01:28:21.924Z,1627349301.924 [Default:CheckIn:D] Running Loop=1 2021-07-27T01:28:22.308Z,1627349302.308 [Default:CheckIn:D] Stopped 2021-07-27T01:28:22.308Z,1627349302.308 [Default:CheckIn:E] Running Loop=1 2021-07-27T01:28:22.721Z,1627349302.721 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 163.850130 min 2021-07-27T01:28:22.722Z,1627349302.722 [Default:CheckIn:E] Stopped 2021-07-27T01:28:22.722Z,1627349302.722 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-27T01:28:22.722Z,1627349302.722 [Default:CheckIn] Stopped 2021-07-27T01:28:22.722Z,1627349302.722 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-27T01:28:22.722Z,1627349302.722 [Default:CheckIn](INFO): Running loop #26 2021-07-27T01:28:22.722Z,1627349302.722 [Default:CheckIn] Running Loop=26 2021-07-27T01:28:22.722Z,1627349302.722 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-27T01:28:22.723Z,1627349302.723 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-27T01:28:24.722Z,1627349304.722 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,012824.00,A,3648.16198,N,12147.28139,W,0.156,319.23,270721,,,A*76 2021-07-27T01:28:24.741Z,1627349304.741 [NAL9602](INFO): GPS fix at 20210727T012824: (36.802700, -121.788023) 2021-07-27T01:28:24.780Z,1627349304.780 [Default:CheckIn:Read_GPS] Stopped 2021-07-27T01:28:24.781Z,1627349304.781 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-27T01:28:37.199Z,1627349317.199 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210726T232245/Courier0066.lzma 2021-07-27T01:28:38.201Z,1627349318.201 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Courier0066.lzma.bak 2021-07-27T01:28:38.201Z,1627349318.201 [DataOverHttps](INFO): SBD MOMSN=15762499 2021-07-27T01:28:55.253Z,1627349335.253 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-07-27T01:28:55.335Z,1627349335.335 [NAL9602](ERROR): received: +CSQ:0 OK523, 2, 0, 0, 0 OK 2021-07-27T01:28:57.071Z,1627349337.071 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20210726T232245/Express0067.lzma 2021-07-27T01:28:58.073Z,1627349338.073 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Express0067.lzma.bak 2021-07-27T01:28:58.074Z,1627349338.074 [DataOverHttps](INFO): SBD MOMSN=15762502 2021-07-27T01:29:01.357Z,1627349341.357 [Default:CheckIn:Read_Iridium] Stopped 2021-07-27T01:29:01.358Z,1627349341.358 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-27T01:29:01.358Z,1627349341.358 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-27T01:33:27.620Z,1627349607.620 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-27T01:33:58.324Z,1627349638.324 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-27T01:34:01.971Z,1627349641.971 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-27T01:34:01.971Z,1627349641.971 [Default:CheckIn:C.Wait] Stopped 2021-07-27T01:34:01.971Z,1627349641.971 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-27T01:34:01.972Z,1627349641.972 [Default:CheckIn:D] Running Loop=1 2021-07-27T01:34:02.381Z,1627349642.381 [Default:CheckIn:D] Stopped 2021-07-27T01:34:02.381Z,1627349642.381 [Default:CheckIn:E] Running Loop=1 2021-07-27T01:34:02.789Z,1627349642.789 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 169.518018 min 2021-07-27T01:34:02.789Z,1627349642.789 [Default:CheckIn:E] Stopped 2021-07-27T01:34:02.790Z,1627349642.790 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-27T01:34:02.790Z,1627349642.790 [Default:CheckIn] Stopped 2021-07-27T01:34:02.790Z,1627349642.790 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-27T01:34:02.790Z,1627349642.790 [Default:CheckIn](INFO): Running loop #27 2021-07-27T01:34:02.790Z,1627349642.790 [Default:CheckIn] Running Loop=27 2021-07-27T01:34:02.790Z,1627349642.790 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-27T01:34:02.790Z,1627349642.790 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-27T01:34:04.791Z,1627349644.791 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,013404.00,A,3648.16174,N,12147.28201,W,0.097,248.66,270721,,,A*7B 2021-07-27T01:34:04.793Z,1627349644.793 [NAL9602](INFO): GPS fix at 20210727T013404: (36.802696, -121.788033) 2021-07-27T01:34:04.828Z,1627349644.828 [Default:CheckIn:Read_GPS] Stopped 2021-07-27T01:34:04.828Z,1627349644.828 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-27T01:34:13.723Z,1627349653.723 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210726T232245/Courier0069.lzma 2021-07-27T01:34:14.725Z,1627349654.725 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Courier0069.lzma.bak 2021-07-27T01:34:14.725Z,1627349654.725 [DataOverHttps](INFO): SBD MOMSN=15762506 2021-07-27T01:34:35.593Z,1627349675.593 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-07-27T01:34:35.667Z,1627349675.667 [NAL9602](ERROR): received: +CSQ:0 OK523, 2, 0, 0, 0 OK 2021-07-27T01:34:42.271Z,1627349682.271 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20210726T232245/Express0070.lzma 2021-07-27T01:34:43.273Z,1627349683.273 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Express0070.lzma.bak 2021-07-27T01:34:43.273Z,1627349683.273 [DataOverHttps](INFO): SBD MOMSN=15762510 2021-07-27T01:34:46.964Z,1627349686.964 [Default:CheckIn:Read_Iridium] Stopped 2021-07-27T01:34:46.964Z,1627349686.964 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-27T01:34:46.964Z,1627349686.964 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-27T01:39:07.564Z,1627349947.564 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-27T01:39:38.279Z,1627349978.279 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-27T01:39:47.570Z,1627349987.570 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-27T01:39:47.570Z,1627349987.570 [Default:CheckIn:C.Wait] Stopped 2021-07-27T01:39:47.570Z,1627349987.570 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-27T01:39:47.570Z,1627349987.570 [Default:CheckIn:D] Running Loop=1 2021-07-27T01:39:47.965Z,1627349987.965 [Default:CheckIn:D] Stopped 2021-07-27T01:39:47.965Z,1627349987.965 [Default:CheckIn:E] Running Loop=1 2021-07-27T01:39:48.363Z,1627349988.363 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 175.277751 min 2021-07-27T01:39:48.363Z,1627349988.363 [Default:CheckIn:E] Stopped 2021-07-27T01:39:48.364Z,1627349988.364 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-27T01:39:48.364Z,1627349988.364 [Default:CheckIn] Stopped 2021-07-27T01:39:48.364Z,1627349988.364 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-27T01:39:48.364Z,1627349988.364 [Default:CheckIn](INFO): Running loop #28 2021-07-27T01:39:48.364Z,1627349988.364 [Default:CheckIn] Running Loop=28 2021-07-27T01:39:48.364Z,1627349988.364 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-27T01:39:48.364Z,1627349988.364 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-27T01:39:50.382Z,1627349990.382 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,013949.00,A,3648.16602,N,12147.28626,W,0.117,248.66,270721,,,A*71 2021-07-27T01:39:50.385Z,1627349990.385 [NAL9602](INFO): GPS fix at 20210727T013949: (36.802767, -121.788104) 2021-07-27T01:39:50.396Z,1627349990.396 [Default:CheckIn:Read_GPS] Stopped 2021-07-27T01:39:50.396Z,1627349990.396 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-27T01:39:59.227Z,1627349999.227 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210726T232245/Courier0072.lzma 2021-07-27T01:40:00.229Z,1627350000.229 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Courier0072.lzma.bak 2021-07-27T01:40:00.229Z,1627350000.229 [DataOverHttps](INFO): SBD MOMSN=15762514 2021-07-27T01:40:20.055Z,1627350020.055 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20210726T232245/Express0073.lzma 2021-07-27T01:40:21.057Z,1627350021.057 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Express0073.lzma.bak 2021-07-27T01:40:21.058Z,1627350021.058 [DataOverHttps](INFO): SBD MOMSN=15762517 2021-07-27T01:40:21.169Z,1627350021.169 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-07-27T01:40:21.247Z,1627350021.247 [NAL9602](ERROR): received: +CSQ:0 OK523, 2, 0, 0, 0 OK 2021-07-27T01:40:26.651Z,1627350026.651 [Default:CheckIn:Read_Iridium] Stopped 2021-07-27T01:40:26.672Z,1627350026.672 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-27T01:40:26.672Z,1627350026.672 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-27T01:42:33.968Z,1627350153.968 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2021-07-27T01:42:45.194Z,1627350165.194 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2021-07-27T01:42:45.209Z,1627350165.209 [BPC1](INFO): Received data from all battery sticks. 2021-07-27T01:44:52.517Z,1627350292.517 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-27T01:45:23.224Z,1627350323.224 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-27T01:45:27.272Z,1627350327.272 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-27T01:45:27.272Z,1627350327.272 [Default:CheckIn:C.Wait] Stopped 2021-07-27T01:45:27.272Z,1627350327.272 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-27T01:45:27.273Z,1627350327.273 [Default:CheckIn:D] Running Loop=1 2021-07-27T01:45:27.688Z,1627350327.688 [Default:CheckIn:D] Stopped 2021-07-27T01:45:27.688Z,1627350327.688 [Default:CheckIn:E] Running Loop=1 2021-07-27T01:45:28.078Z,1627350328.078 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 180.939811 min 2021-07-27T01:45:28.078Z,1627350328.078 [Default:CheckIn:E] Stopped 2021-07-27T01:45:28.079Z,1627350328.079 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-27T01:45:28.079Z,1627350328.079 [Default:CheckIn] Stopped 2021-07-27T01:45:28.079Z,1627350328.079 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-27T01:45:28.079Z,1627350328.079 [Default:CheckIn](INFO): Running loop #29 2021-07-27T01:45:28.079Z,1627350328.079 [Default:CheckIn] Running Loop=29 2021-07-27T01:45:28.079Z,1627350328.079 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-27T01:45:28.080Z,1627350328.080 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-27T01:45:30.091Z,1627350330.091 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,014529.00,A,3648.15467,N,12147.29252,W,0.194,248.66,270721,,,A*73 2021-07-27T01:45:30.093Z,1627350330.093 [NAL9602](INFO): GPS fix at 20210727T014529: (36.802578, -121.788209) 2021-07-27T01:45:30.108Z,1627350330.108 [Default:CheckIn:Read_GPS] Stopped 2021-07-27T01:45:30.108Z,1627350330.108 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-27T01:45:38.975Z,1627350338.975 [DataOverHttps](INFO): Sending 85 bytes from file Logs/20210726T232245/Courier0075.lzma 2021-07-27T01:45:39.977Z,1627350339.977 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Courier0075.lzma.bak 2021-07-27T01:45:39.977Z,1627350339.977 [DataOverHttps](INFO): SBD MOMSN=15762521 2021-07-27T01:45:57.999Z,1627350357.999 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20210726T232245/Express0076.lzma 2021-07-27T01:45:59.001Z,1627350359.001 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Express0076.lzma.bak 2021-07-27T01:45:59.002Z,1627350359.002 [DataOverHttps](INFO): SBD MOMSN=15762524 2021-07-27T01:46:00.813Z,1627350360.813 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-07-27T01:46:00.887Z,1627350360.887 [NAL9602](ERROR): received: +CSQ:0 OK523, 2, 0, 0, 0 OK 2021-07-27T01:46:02.456Z,1627350362.456 [Default:CheckIn:Read_Iridium] Stopped 2021-07-27T01:46:02.456Z,1627350362.456 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-27T01:46:02.456Z,1627350362.456 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-27T01:50:32.513Z,1627350632.513 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-27T01:51:03.216Z,1627350663.216 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-27T01:51:03.229Z,1627350663.229 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-27T01:51:03.229Z,1627350663.229 [Default:CheckIn:C.Wait] Stopped 2021-07-27T01:51:03.229Z,1627350663.229 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-27T01:51:03.229Z,1627350663.229 [Default:CheckIn:D] Running Loop=1 2021-07-27T01:51:03.637Z,1627350663.637 [Default:CheckIn:D] Stopped 2021-07-27T01:51:03.637Z,1627350663.637 [Default:CheckIn:E] Running Loop=1 2021-07-27T01:51:04.038Z,1627350664.038 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 186.538949 min 2021-07-27T01:51:04.038Z,1627350664.038 [Default:CheckIn:E] Stopped 2021-07-27T01:51:04.038Z,1627350664.038 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-27T01:51:04.038Z,1627350664.038 [Default:CheckIn] Stopped 2021-07-27T01:51:04.038Z,1627350664.038 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-27T01:51:04.039Z,1627350664.039 [Default:CheckIn](INFO): Running loop #30 2021-07-27T01:51:04.039Z,1627350664.039 [Default:CheckIn] Running Loop=30 2021-07-27T01:51:04.039Z,1627350664.039 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-27T01:51:04.039Z,1627350664.039 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-27T01:51:06.046Z,1627350666.046 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,015105.00,A,3648.16464,N,12147.27671,W,0.194,0.00,270721,,,A*7D 2021-07-27T01:51:06.049Z,1627350666.049 [NAL9602](INFO): GPS fix at 20210727T015105: (36.802744, -121.787945) 2021-07-27T01:51:06.088Z,1627350666.088 [Default:CheckIn:Read_GPS] Stopped 2021-07-27T01:51:06.088Z,1627350666.088 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-27T01:51:14.635Z,1627350674.635 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210726T232245/Courier0078.lzma 2021-07-27T01:51:15.637Z,1627350675.637 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Courier0078.lzma.bak 2021-07-27T01:51:15.637Z,1627350675.637 [DataOverHttps](INFO): SBD MOMSN=15762528 2021-07-27T01:51:35.045Z,1627350695.045 [DataOverHttps](INFO): Sending 218 bytes from file Logs/20210726T232245/Express0079.lzma 2021-07-27T01:51:36.045Z,1627350696.045 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Express0079.lzma.bak 2021-07-27T01:51:36.046Z,1627350696.046 [DataOverHttps](INFO): SBD MOMSN=15762531 2021-07-27T01:51:36.756Z,1627350696.756 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-07-27T01:51:36.831Z,1627350696.831 [NAL9602](ERROR): received: +CSQ:0 OK523, 2, 0, 0, 0 OK 2021-07-27T01:51:39.216Z,1627350699.216 [Default:CheckIn:Read_Iridium] Stopped 2021-07-27T01:51:39.216Z,1627350699.216 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-27T01:51:39.216Z,1627350699.216 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-27T01:55:19.483Z,1627350919.483 [NAL9602](INFO): SBD MO Status=2, MOMSN=28523, MT Status=2, MTMSN=0 2021-07-27T01:55:19.484Z,1627350919.484 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-27T01:56:08.369Z,1627350968.369 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-27T01:56:39.128Z,1627350999.128 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-27T01:56:39.949Z,1627350999.949 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-27T01:56:39.949Z,1627350999.949 [Default:CheckIn:C.Wait] Stopped 2021-07-27T01:56:39.949Z,1627350999.949 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-27T01:56:39.950Z,1627350999.950 [Default:CheckIn:D] Running Loop=1 2021-07-27T01:56:40.387Z,1627351000.387 [Default:CheckIn:D] Stopped 2021-07-27T01:56:40.387Z,1627351000.387 [Default:CheckIn:E] Running Loop=1 2021-07-27T01:56:40.759Z,1627351000.759 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 192.151449 min 2021-07-27T01:56:40.759Z,1627351000.759 [Default:CheckIn:E] Stopped 2021-07-27T01:56:40.759Z,1627351000.759 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-27T01:56:40.759Z,1627351000.759 [Default:CheckIn] Stopped 2021-07-27T01:56:40.759Z,1627351000.759 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-27T01:56:40.760Z,1627351000.760 [Default:CheckIn](INFO): Running loop #31 2021-07-27T01:56:40.760Z,1627351000.760 [Default:CheckIn] Running Loop=31 2021-07-27T01:56:40.760Z,1627351000.760 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-27T01:56:40.760Z,1627351000.760 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-27T01:56:42.770Z,1627351002.770 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,015642.00,A,3648.16231,N,12147.28029,W,0.097,0.00,270721,,,A*79 2021-07-27T01:56:42.773Z,1627351002.773 [NAL9602](INFO): GPS fix at 20210727T015642: (36.802705, -121.788005) 2021-07-27T01:56:42.784Z,1627351002.784 [Default:CheckIn:Read_GPS] Stopped 2021-07-27T01:56:42.784Z,1627351002.784 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-27T01:56:51.883Z,1627351011.883 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210726T232245/Courier0081.lzma 2021-07-27T01:56:52.885Z,1627351012.885 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Courier0081.lzma.bak 2021-07-27T01:56:52.885Z,1627351012.885 [DataOverHttps](INFO): SBD MOMSN=15762535 2021-07-27T01:57:11.083Z,1627351031.083 [DataOverHttps](INFO): Sending 205 bytes from file Logs/20210726T232245/Express0082.lzma 2021-07-27T01:57:12.085Z,1627351032.085 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Express0082.lzma.bak 2021-07-27T01:57:12.086Z,1627351032.086 [DataOverHttps](INFO): SBD MOMSN=15762538 2021-07-27T01:57:13.469Z,1627351033.469 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-07-27T01:57:13.551Z,1627351033.551 [NAL9602](ERROR): received: +CSQ:0 OK523, 2, 0, 0, 0 OK 2021-07-27T01:57:15.512Z,1627351035.512 [Default:CheckIn:Read_Iridium] Stopped 2021-07-27T01:57:15.512Z,1627351035.512 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-27T01:57:15.512Z,1627351035.512 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-27T02:01:45.457Z,1627351305.457 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-27T02:02:16.160Z,1627351336.160 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-27T02:02:16.173Z,1627351336.173 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-27T02:02:16.173Z,1627351336.173 [Default:CheckIn:C.Wait] Stopped 2021-07-27T02:02:16.173Z,1627351336.173 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-27T02:02:16.173Z,1627351336.173 [Default:CheckIn:D] Running Loop=1 2021-07-27T02:02:16.584Z,1627351336.584 [Default:CheckIn:D] Stopped 2021-07-27T02:02:16.585Z,1627351336.585 [Default:CheckIn:E] Running Loop=1 2021-07-27T02:02:17.003Z,1627351337.003 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 197.754753 min 2021-07-27T02:02:17.003Z,1627351337.003 [Default:CheckIn:E] Stopped 2021-07-27T02:02:17.003Z,1627351337.003 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-27T02:02:17.003Z,1627351337.003 [Default:CheckIn] Stopped 2021-07-27T02:02:17.003Z,1627351337.003 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-27T02:02:17.004Z,1627351337.004 [Default:CheckIn](INFO): Running loop #32 2021-07-27T02:02:17.004Z,1627351337.004 [Default:CheckIn] Running Loop=32 2021-07-27T02:02:17.004Z,1627351337.004 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-27T02:02:17.004Z,1627351337.004 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-27T02:02:18.991Z,1627351338.991 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,020218.00,A,3648.16271,N,12147.27882,W,0.467,299.60,270721,,,A*79 2021-07-27T02:02:18.994Z,1627351338.994 [NAL9602](INFO): GPS fix at 20210727T020218: (36.802712, -121.787980) 2021-07-27T02:02:19.041Z,1627351339.041 [Default:CheckIn:Read_GPS] Stopped 2021-07-27T02:02:19.042Z,1627351339.042 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-27T02:02:32.131Z,1627351352.131 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210726T232245/Courier0084.lzma 2021-07-27T02:02:33.133Z,1627351353.133 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Courier0084.lzma.bak 2021-07-27T02:02:33.134Z,1627351353.134 [DataOverHttps](INFO): SBD MOMSN=15762542 2021-07-27T02:02:49.415Z,1627351369.415 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-07-27T02:02:49.495Z,1627351369.495 [NAL9602](ERROR): received: +CSQ:0 OK523, 2, 0, 0, 0 OK 2021-07-27T02:02:53.859Z,1627351373.859 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20210726T232245/Express0085.lzma 2021-07-27T02:02:54.861Z,1627351374.861 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Express0085.lzma.bak 2021-07-27T02:02:54.862Z,1627351374.862 [DataOverHttps](INFO): SBD MOMSN=15762545 2021-07-27T02:02:58.353Z,1627351378.353 [Default:CheckIn:Read_Iridium] Stopped 2021-07-27T02:02:58.354Z,1627351378.354 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-27T02:02:58.354Z,1627351378.354 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-27T02:07:21.320Z,1627351641.320 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-27T02:07:52.010Z,1627351672.010 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-27T02:07:58.894Z,1627351678.894 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-27T02:07:58.894Z,1627351678.894 [Default:CheckIn:C.Wait] Stopped 2021-07-27T02:07:58.895Z,1627351678.895 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-27T02:07:58.895Z,1627351678.895 [Default:CheckIn:D] Running Loop=1 2021-07-27T02:07:59.303Z,1627351679.303 [Default:CheckIn:D] Stopped 2021-07-27T02:07:59.307Z,1627351679.307 [Default:CheckIn:E] Running Loop=1 2021-07-27T02:07:59.699Z,1627351679.699 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 203.466715 min 2021-07-27T02:07:59.699Z,1627351679.699 [Default:CheckIn:E] Stopped 2021-07-27T02:07:59.699Z,1627351679.699 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-27T02:07:59.699Z,1627351679.699 [Default:CheckIn] Stopped 2021-07-27T02:07:59.699Z,1627351679.699 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-27T02:07:59.700Z,1627351679.700 [Default:CheckIn](INFO): Running loop #33 2021-07-27T02:07:59.700Z,1627351679.700 [Default:CheckIn] Running Loop=33 2021-07-27T02:07:59.700Z,1627351679.700 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-27T02:07:59.700Z,1627351679.700 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-27T02:08:01.710Z,1627351681.710 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,020800.00,A,3648.16268,N,12147.28298,W,0.505,286.13,270721,,,A*73 2021-07-27T02:08:01.713Z,1627351681.713 [NAL9602](INFO): GPS fix at 20210727T020800: (36.802711, -121.788050) 2021-07-27T02:08:01.724Z,1627351681.724 [Default:CheckIn:Read_GPS] Stopped 2021-07-27T02:08:01.724Z,1627351681.724 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-27T02:08:10.307Z,1627351690.307 [DataOverHttps](INFO): Sending 70 bytes from file Logs/20210726T232245/Courier0087.lzma 2021-07-27T02:08:11.309Z,1627351691.309 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Courier0087.lzma.bak 2021-07-27T02:08:11.309Z,1627351691.309 [DataOverHttps](INFO): SBD MOMSN=15762549 2021-07-27T02:08:32.506Z,1627351712.506 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-07-27T02:08:32.579Z,1627351712.579 [NAL9602](ERROR): received: +CSQ:0 OK523, 2, 0, 0, 0 OK 2021-07-27T02:08:36.883Z,1627351716.883 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20210726T232245/Express0088.lzma 2021-07-27T02:08:37.886Z,1627351717.886 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Express0088.lzma.bak 2021-07-27T02:08:37.886Z,1627351717.886 [DataOverHttps](INFO): SBD MOMSN=15762552 2021-07-27T02:08:43.072Z,1627351723.072 [Default:CheckIn:Read_Iridium] Stopped 2021-07-27T02:08:43.072Z,1627351723.072 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-27T02:08:43.072Z,1627351723.072 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-27T02:12:37.110Z,1627351957.110 [NAL9602](INFO): SBD MO Status=2, MOMSN=28523, MT Status=2, MTMSN=0 2021-07-27T02:12:37.110Z,1627351957.110 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-27T02:13:08.618Z,1627351988.618 [NAL9602](INFO): SBD MO Status=2, MOMSN=28523, MT Status=2, MTMSN=0 2021-07-27T02:13:08.618Z,1627351988.618 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-27T02:13:09.025Z,1627351989.025 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-27T02:13:39.727Z,1627352019.727 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-27T02:13:43.775Z,1627352023.775 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-27T02:13:43.775Z,1627352023.775 [Default:CheckIn:C.Wait] Stopped 2021-07-27T02:13:43.775Z,1627352023.775 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-27T02:13:43.776Z,1627352023.776 [Default:CheckIn:D] Running Loop=1 2021-07-27T02:13:44.185Z,1627352024.185 [Default:CheckIn:D] Stopped 2021-07-27T02:13:44.185Z,1627352024.185 [Default:CheckIn:E] Running Loop=1 2021-07-27T02:13:44.585Z,1627352024.585 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 209.214746 min 2021-07-27T02:13:44.586Z,1627352024.586 [Default:CheckIn:E] Stopped 2021-07-27T02:13:44.586Z,1627352024.586 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-27T02:13:44.586Z,1627352024.586 [Default:CheckIn] Stopped 2021-07-27T02:13:44.586Z,1627352024.586 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-27T02:13:44.586Z,1627352024.586 [Default:CheckIn](INFO): Running loop #34 2021-07-27T02:13:44.586Z,1627352024.586 [Default:CheckIn] Running Loop=34 2021-07-27T02:13:44.586Z,1627352024.586 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-27T02:13:44.586Z,1627352024.586 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-27T02:13:46.599Z,1627352026.599 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,021345.00,A,3648.16246,N,12147.28357,W,0.758,286.13,270721,,,A*7C 2021-07-27T02:13:46.601Z,1627352026.601 [NAL9602](INFO): GPS fix at 20210727T021345: (36.802708, -121.788060) 2021-07-27T02:13:46.632Z,1627352026.632 [Default:CheckIn:Read_GPS] Stopped 2021-07-27T02:13:46.633Z,1627352026.633 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-27T02:13:55.131Z,1627352035.131 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210726T232245/Courier0090.lzma 2021-07-27T02:13:56.133Z,1627352036.133 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Courier0090.lzma.bak 2021-07-27T02:13:56.133Z,1627352036.133 [DataOverHttps](INFO): SBD MOMSN=15762556 2021-07-27T02:14:14.403Z,1627352054.403 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20210726T232245/Express0091.lzma 2021-07-27T02:14:15.405Z,1627352055.405 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Express0091.lzma.bak 2021-07-27T02:14:15.406Z,1627352055.406 [DataOverHttps](INFO): SBD MOMSN=15762559 2021-07-27T02:14:18.550Z,1627352058.550 [NAL9602](INFO): SBD MO Status=2, MOMSN=28523, MT Status=2, MTMSN=0 2021-07-27T02:14:18.550Z,1627352058.550 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-27T02:14:21.452Z,1627352061.452 [Default:CheckIn:Read_Iridium] Stopped 2021-07-27T02:14:21.453Z,1627352061.453 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-27T02:14:21.453Z,1627352061.453 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-27T02:18:48.601Z,1627352328.601 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-27T02:19:19.308Z,1627352359.308 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-27T02:19:22.142Z,1627352362.142 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-27T02:19:22.143Z,1627352362.143 [Default:CheckIn:C.Wait] Stopped 2021-07-27T02:19:22.143Z,1627352362.143 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-27T02:19:22.143Z,1627352362.143 [Default:CheckIn:D] Running Loop=1 2021-07-27T02:19:22.561Z,1627352362.561 [Default:CheckIn:D] Stopped 2021-07-27T02:19:22.561Z,1627352362.561 [Default:CheckIn:E] Running Loop=1 2021-07-27T02:19:22.951Z,1627352362.951 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 214.854346 min 2021-07-27T02:19:22.951Z,1627352362.951 [Default:CheckIn:E] Stopped 2021-07-27T02:19:22.951Z,1627352362.951 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-27T02:19:22.951Z,1627352362.951 [Default:CheckIn] Stopped 2021-07-27T02:19:22.975Z,1627352362.975 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-27T02:19:22.975Z,1627352362.975 [Default:CheckIn](INFO): Running loop #35 2021-07-27T02:19:22.975Z,1627352362.975 [Default:CheckIn] Running Loop=35 2021-07-27T02:19:22.976Z,1627352362.976 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-27T02:19:22.976Z,1627352362.976 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-27T02:19:24.963Z,1627352364.963 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,021924.00,A,3648.16136,N,12147.27740,W,0.641,276.45,270721,,,A*7D 2021-07-27T02:19:24.965Z,1627352364.965 [NAL9602](INFO): GPS fix at 20210727T021924: (36.802689, -121.787957) 2021-07-27T02:19:24.976Z,1627352364.976 [Default:CheckIn:Read_GPS] Stopped 2021-07-27T02:19:24.976Z,1627352364.976 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-27T02:19:33.999Z,1627352373.999 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210726T232245/Courier0093.lzma 2021-07-27T02:19:35.001Z,1627352375.001 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Courier0093.lzma.bak 2021-07-27T02:19:35.001Z,1627352375.001 [DataOverHttps](INFO): SBD MOMSN=15762563 2021-07-27T02:19:54.432Z,1627352394.432 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20210726T232245/Express0094.lzma 2021-07-27T02:19:55.433Z,1627352395.433 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Express0094.lzma.bak 2021-07-27T02:19:55.434Z,1627352395.434 [DataOverHttps](INFO): SBD MOMSN=15762566 2021-07-27T02:19:55.664Z,1627352395.664 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-07-27T02:19:55.740Z,1627352395.740 [NAL9602](ERROR): received: +CSQ:0 OK523, 2, 0, 0, 0 OK 2021-07-27T02:19:58.949Z,1627352398.949 [Default:CheckIn:Read_Iridium] Stopped 2021-07-27T02:19:58.949Z,1627352398.949 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-27T02:19:58.949Z,1627352398.949 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-27T02:20:36.475Z,1627352436.475 [NAL9602](INFO): SBD MO Status=2, MOMSN=28523, MT Status=2, MTMSN=0 2021-07-27T02:20:36.475Z,1627352436.475 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-27T02:21:40.712Z,1627352500.712 [NAL9602](INFO): SBD MO Status=0, MOMSN=28523, MT Status=0, MTMSN=0 2021-07-27T02:21:40.712Z,1627352500.712 [NAL9602](INFO): No messages in MT queue 2021-07-27T02:22:11.418Z,1627352531.418 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-27T02:24:59.510Z,1627352699.510 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-27T02:24:59.510Z,1627352699.510 [Default:CheckIn:C.Wait] Stopped 2021-07-27T02:24:59.511Z,1627352699.511 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-27T02:24:59.511Z,1627352699.511 [Default:CheckIn:D] Running Loop=1 2021-07-27T02:24:59.911Z,1627352699.911 [Default:CheckIn:D] Stopped 2021-07-27T02:24:59.911Z,1627352699.911 [Default:CheckIn:E] Running Loop=1 2021-07-27T02:25:00.317Z,1627352700.317 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 220.476855 min 2021-07-27T02:25:00.317Z,1627352700.317 [Default:CheckIn:E] Stopped 2021-07-27T02:25:00.317Z,1627352700.317 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-27T02:25:00.317Z,1627352700.317 [Default:CheckIn] Stopped 2021-07-27T02:25:00.317Z,1627352700.317 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-27T02:25:00.318Z,1627352700.318 [Default:CheckIn](INFO): Running loop #36 2021-07-27T02:25:00.318Z,1627352700.318 [Default:CheckIn] Running Loop=36 2021-07-27T02:25:00.318Z,1627352700.318 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-27T02:25:00.318Z,1627352700.318 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-27T02:25:02.326Z,1627352702.326 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,022501.00,A,3648.17059,N,12147.27974,W,0.233,320.80,270721,,,A*7F 2021-07-27T02:25:02.329Z,1627352702.329 [NAL9602](INFO): GPS fix at 20210727T022501: (36.802843, -121.787996) 2021-07-27T02:25:02.376Z,1627352702.376 [Default:CheckIn:Read_GPS] Stopped 2021-07-27T02:25:02.377Z,1627352702.377 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-27T02:25:11.299Z,1627352711.299 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210726T232245/Courier0096.lzma 2021-07-27T02:25:12.302Z,1627352712.302 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Courier0096.lzma.bak 2021-07-27T02:25:12.302Z,1627352712.302 [DataOverHttps](INFO): SBD MOMSN=15762571 2021-07-27T02:25:30.311Z,1627352730.311 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20210726T232245/Express0097.lzma 2021-07-27T02:25:31.313Z,1627352731.313 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Express0097.lzma.bak 2021-07-27T02:25:31.314Z,1627352731.314 [DataOverHttps](INFO): SBD MOMSN=15762574 2021-07-27T02:25:34.673Z,1627352734.673 [Default:CheckIn:Read_Iridium] Stopped 2021-07-27T02:25:34.673Z,1627352734.673 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-27T02:25:34.673Z,1627352734.673 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-27T02:30:08.282Z,1627353008.282 [NAL9602](INFO): SBD MO Status=2, MOMSN=28524, MT Status=2, MTMSN=0 2021-07-27T02:30:08.282Z,1627353008.282 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-27T02:30:08.693Z,1627353008.693 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-27T02:30:35.453Z,1627353035.453 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-27T02:30:35.453Z,1627353035.453 [Default:CheckIn:C.Wait] Stopped 2021-07-27T02:30:35.453Z,1627353035.453 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-27T02:30:35.454Z,1627353035.454 [Default:CheckIn:D] Running Loop=1 2021-07-27T02:30:35.872Z,1627353035.872 [Default:CheckIn:D] Stopped 2021-07-27T02:30:35.872Z,1627353035.872 [Default:CheckIn:E] Running Loop=1 2021-07-27T02:30:36.238Z,1627353036.238 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 226.076204 min 2021-07-27T02:30:36.239Z,1627353036.239 [Default:CheckIn:E] Stopped 2021-07-27T02:30:36.239Z,1627353036.239 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-27T02:30:36.239Z,1627353036.239 [Default:CheckIn] Stopped 2021-07-27T02:30:36.243Z,1627353036.243 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-27T02:30:36.244Z,1627353036.244 [Default:CheckIn](INFO): Running loop #37 2021-07-27T02:30:36.244Z,1627353036.244 [Default:CheckIn] Running Loop=37 2021-07-27T02:30:36.244Z,1627353036.244 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-27T02:30:36.244Z,1627353036.244 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-27T02:30:38.231Z,1627353038.231 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,023037.00,A,3648.16561,N,12147.28281,W,0.311,329.91,270721,,,A*77 2021-07-27T02:30:38.251Z,1627353038.251 [NAL9602](INFO): GPS fix at 20210727T023037: (36.802760, -121.788047) 2021-07-27T02:30:38.261Z,1627353038.261 [Default:CheckIn:Read_GPS] Stopped 2021-07-27T02:30:38.261Z,1627353038.261 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-27T02:30:47.103Z,1627353047.103 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210726T232245/Courier0099.lzma 2021-07-27T02:30:48.105Z,1627353048.105 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Courier0099.lzma.bak 2021-07-27T02:30:48.106Z,1627353048.106 [DataOverHttps](INFO): SBD MOMSN=15762577 2021-07-27T02:31:06.051Z,1627353066.051 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20210726T232245/Express0100.lzma 2021-07-27T02:31:07.053Z,1627353067.053 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Express0100.lzma.bak 2021-07-27T02:31:07.054Z,1627353067.054 [DataOverHttps](INFO): SBD MOMSN=15762580 2021-07-27T02:31:10.179Z,1627353070.179 [Default:CheckIn:Read_Iridium] Stopped 2021-07-27T02:31:10.180Z,1627353070.180 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-27T02:31:10.180Z,1627353070.180 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-27T02:31:10.552Z,1627353070.552 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-27T02:36:10.875Z,1627353370.875 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-27T02:36:10.875Z,1627353370.875 [Default:CheckIn:C.Wait] Stopped 2021-07-27T02:36:10.875Z,1627353370.875 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-27T02:36:10.876Z,1627353370.876 [Default:CheckIn:D] Running Loop=1 2021-07-27T02:36:11.265Z,1627353371.265 [Default:CheckIn:D] Stopped 2021-07-27T02:36:11.265Z,1627353371.265 [Default:CheckIn:E] Running Loop=1 2021-07-27T02:36:11.681Z,1627353371.681 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 231.666097 min 2021-07-27T02:36:11.681Z,1627353371.681 [Default:CheckIn:E] Stopped 2021-07-27T02:36:11.681Z,1627353371.681 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-27T02:36:11.681Z,1627353371.681 [Default:CheckIn] Stopped 2021-07-27T02:36:11.681Z,1627353371.681 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-27T02:36:11.681Z,1627353371.681 [Default:CheckIn](INFO): Running loop #38 2021-07-27T02:36:11.681Z,1627353371.681 [Default:CheckIn] Running Loop=38 2021-07-27T02:36:11.682Z,1627353371.682 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-27T02:36:11.682Z,1627353371.682 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-27T02:36:13.687Z,1627353373.687 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,023612.00,A,3648.17285,N,12147.28052,W,0.330,329.91,270721,,,A*75 2021-07-27T02:36:13.689Z,1627353373.689 [NAL9602](INFO): GPS fix at 20210727T023612: (36.802881, -121.788009) 2021-07-27T02:36:13.700Z,1627353373.700 [Default:CheckIn:Read_GPS] Stopped 2021-07-27T02:36:13.700Z,1627353373.700 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-27T02:36:25.159Z,1627353385.159 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210726T232245/Courier0102.lzma 2021-07-27T02:36:26.158Z,1627353386.158 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Courier0102.lzma.bak 2021-07-27T02:36:26.158Z,1627353386.158 [DataOverHttps](INFO): SBD MOMSN=15762584 2021-07-27T02:36:51.095Z,1627353411.095 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20210726T232245/Express0103.lzma 2021-07-27T02:36:52.097Z,1627353412.097 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Express0103.lzma.bak 2021-07-27T02:36:52.098Z,1627353412.098 [DataOverHttps](INFO): SBD MOMSN=15762587 2021-07-27T02:36:55.548Z,1627353415.548 [Default:CheckIn:Read_Iridium] Stopped 2021-07-27T02:36:55.548Z,1627353415.548 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-27T02:36:55.548Z,1627353415.548 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-27T02:40:22.786Z,1627353622.786 [NAL9602](INFO): SBD MO Status=2, MOMSN=28524, MT Status=2, MTMSN=0 2021-07-27T02:40:22.786Z,1627353622.786 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-27T02:40:51.878Z,1627353651.878 [NAL9602](INFO): SBD MO Status=2, MOMSN=28524, MT Status=2, MTMSN=0 2021-07-27T02:40:51.878Z,1627353651.878 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-27T02:41:22.174Z,1627353682.174 [NAL9602](INFO): SBD MO Status=2, MOMSN=28524, MT Status=2, MTMSN=0 2021-07-27T02:41:22.174Z,1627353682.174 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-27T02:41:22.573Z,1627353682.573 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-27T02:41:53.280Z,1627353713.280 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-27T02:41:56.131Z,1627353716.131 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-27T02:41:56.131Z,1627353716.131 [Default:CheckIn:C.Wait] Stopped 2021-07-27T02:41:56.131Z,1627353716.131 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-27T02:41:56.132Z,1627353716.132 [Default:CheckIn:D] Running Loop=1 2021-07-27T02:41:56.519Z,1627353716.519 [Default:CheckIn:D] Stopped 2021-07-27T02:41:56.519Z,1627353716.519 [Default:CheckIn:E] Running Loop=1 2021-07-27T02:41:56.927Z,1627353716.927 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 237.420329 min 2021-07-27T02:41:56.927Z,1627353716.927 [Default:CheckIn:E] Stopped 2021-07-27T02:41:56.927Z,1627353716.927 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-27T02:41:56.927Z,1627353716.927 [Default:CheckIn] Stopped 2021-07-27T02:41:56.927Z,1627353716.927 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-27T02:41:56.928Z,1627353716.928 [Default:CheckIn](INFO): Running loop #39 2021-07-27T02:41:56.928Z,1627353716.928 [Default:CheckIn] Running Loop=39 2021-07-27T02:41:56.928Z,1627353716.928 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-27T02:41:56.928Z,1627353716.928 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-27T02:41:58.939Z,1627353718.939 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,024158.00,A,3648.16189,N,12147.28252,W,0.272,0.00,270721,,,A*70 2021-07-27T02:41:58.951Z,1627353718.951 [NAL9602](INFO): GPS fix at 20210727T024158: (36.802698, -121.788042) 2021-07-27T02:41:58.962Z,1627353718.962 [Default:CheckIn:Read_GPS] Stopped 2021-07-27T02:41:58.962Z,1627353718.962 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-27T02:42:07.371Z,1627353727.371 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210726T232245/Courier0105.lzma 2021-07-27T02:42:08.374Z,1627353728.374 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Courier0105.lzma.bak 2021-07-27T02:42:08.374Z,1627353728.374 [DataOverHttps](INFO): SBD MOMSN=15762590 2021-07-27T02:42:19.134Z,1627353739.134 [NAL9602](INFO): SBD MO Status=2, MOMSN=28524, MT Status=2, MTMSN=0 2021-07-27T02:42:19.134Z,1627353739.134 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-27T02:42:31.287Z,1627353751.287 [DataOverHttps](INFO): Sending 209 bytes from file Logs/20210726T232245/Express0106.lzma 2021-07-27T02:42:32.290Z,1627353752.290 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Express0106.lzma.bak 2021-07-27T02:42:32.290Z,1627353752.290 [DataOverHttps](INFO): SBD MOMSN=15762593 2021-07-27T02:42:37.915Z,1627353757.915 [Default:CheckIn:Read_Iridium] Stopped 2021-07-27T02:42:37.916Z,1627353757.916 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-27T02:42:37.916Z,1627353757.916 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-27T02:42:45.130Z,1627353765.130 [NAL9602](INFO): SBD MO Status=2, MOMSN=28524, MT Status=2, MTMSN=0 2021-07-27T02:42:45.131Z,1627353765.131 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-27T02:47:01.458Z,1627354021.458 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-27T02:47:32.120Z,1627354052.120 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-27T02:47:38.595Z,1627354058.595 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-27T02:47:38.595Z,1627354058.595 [Default:CheckIn:C.Wait] Stopped 2021-07-27T02:47:38.595Z,1627354058.595 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-27T02:47:38.596Z,1627354058.596 [Default:CheckIn:D] Running Loop=1 2021-07-27T02:47:39.007Z,1627354059.007 [Default:CheckIn:D] Stopped 2021-07-27T02:47:39.007Z,1627354059.007 [Default:CheckIn:E] Running Loop=1 2021-07-27T02:47:39.412Z,1627354059.412 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 243.128451 min 2021-07-27T02:47:39.412Z,1627354059.412 [Default:CheckIn:E] Stopped 2021-07-27T02:47:39.412Z,1627354059.412 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-27T02:47:39.412Z,1627354059.412 [Default:CheckIn] Stopped 2021-07-27T02:47:39.412Z,1627354059.412 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-27T02:47:39.412Z,1627354059.412 [Default:CheckIn](INFO): Running loop #40 2021-07-27T02:47:39.412Z,1627354059.412 [Default:CheckIn] Running Loop=40 2021-07-27T02:47:39.412Z,1627354059.412 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-27T02:47:39.413Z,1627354059.413 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-27T02:47:41.437Z,1627354061.437 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,024740.00,A,3648.17855,N,12147.29142,W,0.350,315.69,270721,,,A*7C 2021-07-27T02:47:41.440Z,1627354061.440 [NAL9602](INFO): GPS fix at 20210727T024740: (36.802976, -121.788190) 2021-07-27T02:47:41.451Z,1627354061.451 [Default:CheckIn:Read_GPS] Stopped 2021-07-27T02:47:41.451Z,1627354061.451 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-27T02:47:50.419Z,1627354070.419 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210726T232245/Courier0108.lzma 2021-07-27T02:47:51.421Z,1627354071.421 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Courier0108.lzma.bak 2021-07-27T02:47:51.422Z,1627354071.422 [DataOverHttps](INFO): SBD MOMSN=15762597 2021-07-27T02:48:10.883Z,1627354090.883 [DataOverHttps](INFO): Sending 215 bytes from file Logs/20210726T232245/Express0109.lzma 2021-07-27T02:48:11.885Z,1627354091.885 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Express0109.lzma.bak 2021-07-27T02:48:11.886Z,1627354091.886 [DataOverHttps](INFO): SBD MOMSN=15762600 2021-07-27T02:48:12.124Z,1627354092.124 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-07-27T02:48:12.207Z,1627354092.207 [NAL9602](ERROR): received: +CSQ:0 OK524, 2, 0, 0, 0 OK 2021-07-27T02:48:15.392Z,1627354095.392 [Default:CheckIn:Read_Iridium] Stopped 2021-07-27T02:48:15.392Z,1627354095.392 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-27T02:48:15.392Z,1627354095.392 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-27T02:49:56.898Z,1627354196.898 [NAL9602](INFO): SBD MO Status=2, MOMSN=28524, MT Status=2, MTMSN=0 2021-07-27T02:49:56.898Z,1627354196.898 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-27T02:50:15.078Z,1627354215.078 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2021-07-27T02:50:15.098Z,1627354215.098 [BPC1](INFO): Received data from all battery sticks. 2021-07-27T02:50:47.806Z,1627354247.806 [NAL9602](INFO): SBD MO Status=2, MOMSN=28524, MT Status=2, MTMSN=0 2021-07-27T02:50:47.806Z,1627354247.806 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-27T02:51:38.302Z,1627354298.302 [NAL9602](INFO): SBD MO Status=2, MOMSN=28524, MT Status=2, MTMSN=0 2021-07-27T02:51:38.302Z,1627354298.302 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-27T02:52:43.361Z,1627354363.361 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-27T02:53:14.055Z,1627354394.055 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-27T02:53:16.092Z,1627354396.092 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-27T02:53:16.092Z,1627354396.092 [Default:CheckIn:C.Wait] Stopped 2021-07-27T02:53:16.092Z,1627354396.092 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-27T02:53:16.093Z,1627354396.093 [Default:CheckIn:D] Running Loop=1 2021-07-27T02:53:16.482Z,1627354396.482 [Default:CheckIn:D] Stopped 2021-07-27T02:53:16.482Z,1627354396.482 [Default:CheckIn:E] Running Loop=1 2021-07-27T02:53:16.891Z,1627354396.891 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 248.753044 min 2021-07-27T02:53:16.891Z,1627354396.891 [Default:CheckIn:E] Stopped 2021-07-27T02:53:16.892Z,1627354396.892 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-27T02:53:16.892Z,1627354396.892 [Default:CheckIn] Stopped 2021-07-27T02:53:16.892Z,1627354396.892 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-27T02:53:16.892Z,1627354396.892 [Default:CheckIn](INFO): Running loop #41 2021-07-27T02:53:16.892Z,1627354396.892 [Default:CheckIn] Running Loop=41 2021-07-27T02:53:16.892Z,1627354396.892 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-27T02:53:16.892Z,1627354396.892 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-27T02:53:18.906Z,1627354398.906 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,025318.00,A,3648.16620,N,12147.28176,W,0.875,330.31,270721,,,A*79 2021-07-27T02:53:18.909Z,1627354398.909 [NAL9602](INFO): GPS fix at 20210727T025318: (36.802770, -121.788029) 2021-07-27T02:53:18.920Z,1627354398.920 [Default:CheckIn:Read_GPS] Stopped 2021-07-27T02:53:18.920Z,1627354398.920 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-27T02:53:27.911Z,1627354407.911 [DataOverHttps](INFO): Sending 85 bytes from file Logs/20210726T232245/Courier0111.lzma 2021-07-27T02:53:28.914Z,1627354408.914 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Courier0111.lzma.bak 2021-07-27T02:53:28.914Z,1627354408.914 [DataOverHttps](INFO): SBD MOMSN=15762604 2021-07-27T02:53:47.127Z,1627354427.127 [DataOverHttps](INFO): Sending 215 bytes from file Logs/20210726T232245/Express0112.lzma 2021-07-27T02:53:48.125Z,1627354428.125 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Express0112.lzma.bak 2021-07-27T02:53:48.126Z,1627354428.126 [DataOverHttps](INFO): SBD MOMSN=15762607 2021-07-27T02:53:49.613Z,1627354429.613 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-07-27T02:53:49.687Z,1627354429.687 [NAL9602](ERROR): received: +CSQ:0 OK524, 2, 0, 0, 0 OK 2021-07-27T02:53:51.649Z,1627354431.649 [Default:CheckIn:Read_Iridium] Stopped 2021-07-27T02:53:51.649Z,1627354431.649 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-27T02:53:51.649Z,1627354431.649 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-27T02:58:21.545Z,1627354701.545 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-27T02:58:52.346Z,1627354732.346 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-27T02:58:52.359Z,1627354732.359 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-27T02:58:52.359Z,1627354732.359 [Default:CheckIn:C.Wait] Stopped 2021-07-27T02:58:52.359Z,1627354732.359 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-27T02:58:52.359Z,1627354732.359 [Default:CheckIn:D] Running Loop=1 2021-07-27T02:58:52.763Z,1627354732.763 [Default:CheckIn:D] Stopped 2021-07-27T02:58:52.763Z,1627354732.763 [Default:CheckIn:E] Running Loop=1 2021-07-27T02:58:53.177Z,1627354733.177 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 254.357715 min 2021-07-27T02:58:53.177Z,1627354733.177 [Default:CheckIn:E] Stopped 2021-07-27T02:58:53.177Z,1627354733.177 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-27T02:58:53.177Z,1627354733.177 [Default:CheckIn] Stopped 2021-07-27T02:58:53.177Z,1627354733.177 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-27T02:58:53.177Z,1627354733.177 [Default:CheckIn](INFO): Running loop #42 2021-07-27T02:58:53.178Z,1627354733.178 [Default:CheckIn] Running Loop=42 2021-07-27T02:58:53.178Z,1627354733.178 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-27T02:58:53.178Z,1627354733.178 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-27T02:58:55.178Z,1627354735.178 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,025854.00,A,3648.16186,N,12147.28120,W,0.214,176.41,270721,,,D*7D 2021-07-27T02:58:55.181Z,1627354735.181 [NAL9602](INFO): GPS fix at 20210727T025854: (36.802698, -121.788020) 2021-07-27T02:58:55.212Z,1627354735.212 [Default:CheckIn:Read_GPS] Stopped 2021-07-27T02:58:55.212Z,1627354735.212 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-27T02:59:04.491Z,1627354744.491 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210726T232245/Courier0114.lzma 2021-07-27T02:59:05.493Z,1627354745.493 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Courier0114.lzma.bak 2021-07-27T02:59:05.494Z,1627354745.494 [DataOverHttps](INFO): SBD MOMSN=15762612 2021-07-27T02:59:23.787Z,1627354763.787 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20210726T232245/Express0115.lzma 2021-07-27T02:59:24.789Z,1627354764.789 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Express0115.lzma.bak 2021-07-27T02:59:24.790Z,1627354764.790 [DataOverHttps](INFO): SBD MOMSN=15762615 2021-07-27T02:59:25.877Z,1627354765.877 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-07-27T02:59:25.951Z,1627354765.951 [NAL9602](ERROR): received: +CSQ:0 OK524, 2, 0, 0, 0 OK 2021-07-27T02:59:28.315Z,1627354768.315 [Default:CheckIn:Read_Iridium] Stopped 2021-07-27T02:59:28.316Z,1627354768.316 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-27T02:59:28.316Z,1627354768.316 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-27T03:00:40.238Z,1627354840.238 [NAL9602](INFO): SBD MO Status=2, MOMSN=28524, MT Status=2, MTMSN=0 2021-07-27T03:00:40.238Z,1627354840.238 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-27T03:01:28.714Z,1627354888.714 [NAL9602](INFO): SBD MO Status=2, MOMSN=28524, MT Status=2, MTMSN=0 2021-07-27T03:01:28.714Z,1627354888.714 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-27T03:03:57.389Z,1627355037.389 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-27T03:04:28.124Z,1627355068.124 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-27T03:04:29.008Z,1627355069.008 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-27T03:04:29.008Z,1627355069.008 [Default:CheckIn:C.Wait] Stopped 2021-07-27T03:04:29.008Z,1627355069.008 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-27T03:04:29.009Z,1627355069.009 [Default:CheckIn:D] Running Loop=1 2021-07-27T03:04:29.359Z,1627355069.359 [Default:CheckIn:D] Stopped 2021-07-27T03:04:29.359Z,1627355069.359 [Default:CheckIn:E] Running Loop=1 2021-07-27T03:04:29.769Z,1627355069.769 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 259.967643 min 2021-07-27T03:04:29.769Z,1627355069.769 [Default:CheckIn:E] Stopped 2021-07-27T03:04:29.769Z,1627355069.769 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-27T03:04:29.769Z,1627355069.769 [Default:CheckIn] Stopped 2021-07-27T03:04:29.769Z,1627355069.769 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-27T03:04:29.769Z,1627355069.769 [Default:CheckIn](INFO): Running loop #43 2021-07-27T03:04:29.769Z,1627355069.769 [Default:CheckIn] Running Loop=43 2021-07-27T03:04:29.770Z,1627355069.770 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-27T03:04:29.770Z,1627355069.770 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-27T03:04:31.766Z,1627355071.766 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,030431.00,A,3648.16555,N,12147.28317,W,0.389,145.97,270721,,,D*74 2021-07-27T03:04:31.769Z,1627355071.769 [NAL9602](INFO): GPS fix at 20210727T030431: (36.802759, -121.788053) 2021-07-27T03:04:31.821Z,1627355071.821 [Default:CheckIn:Read_GPS] Stopped 2021-07-27T03:04:31.821Z,1627355071.821 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-27T03:04:41.811Z,1627355081.811 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210726T232245/Courier0117.lzma 2021-07-27T03:04:43.014Z,1627355083.014 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Courier0117.lzma.bak 2021-07-27T03:04:43.014Z,1627355083.014 [DataOverHttps](INFO): SBD MOMSN=15762619 2021-07-27T03:05:00.883Z,1627355100.883 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20210726T232245/Express0118.lzma 2021-07-27T03:05:01.886Z,1627355101.886 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Express0118.lzma.bak 2021-07-27T03:05:01.886Z,1627355101.886 [DataOverHttps](INFO): SBD MOMSN=15762622 2021-07-27T03:05:02.505Z,1627355102.505 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-07-27T03:05:02.579Z,1627355102.579 [NAL9602](ERROR): received: +CSQ:0 OK524, 2, 0, 0, 0 OK 2021-07-27T03:05:05.383Z,1627355105.383 [Default:CheckIn:Read_Iridium] Stopped 2021-07-27T03:05:05.384Z,1627355105.384 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-27T03:05:05.384Z,1627355105.384 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-27T03:09:34.551Z,1627355374.551 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-27T03:10:05.252Z,1627355405.252 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-27T03:10:06.080Z,1627355406.080 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-27T03:10:06.080Z,1627355406.080 [Default:CheckIn:C.Wait] Stopped 2021-07-27T03:10:06.081Z,1627355406.081 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-27T03:10:06.081Z,1627355406.081 [Default:CheckIn:D] Running Loop=1 2021-07-27T03:10:06.470Z,1627355406.470 [Default:CheckIn:D] Stopped 2021-07-27T03:10:06.470Z,1627355406.470 [Default:CheckIn:E] Running Loop=1 2021-07-27T03:10:06.876Z,1627355406.876 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 265.586182 min 2021-07-27T03:10:06.876Z,1627355406.876 [Default:CheckIn:E] Stopped 2021-07-27T03:10:06.876Z,1627355406.876 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-27T03:10:06.876Z,1627355406.876 [Default:CheckIn] Stopped 2021-07-27T03:10:06.876Z,1627355406.876 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-27T03:10:06.876Z,1627355406.876 [Default:CheckIn](INFO): Running loop #44 2021-07-27T03:10:06.876Z,1627355406.876 [Default:CheckIn] Running Loop=44 2021-07-27T03:10:06.877Z,1627355406.877 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-27T03:10:06.877Z,1627355406.877 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-27T03:10:08.886Z,1627355408.886 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,031008.00,A,3648.16517,N,12147.28323,W,0.330,192.68,270721,,,A*77 2021-07-27T03:10:08.889Z,1627355408.889 [NAL9602](INFO): GPS fix at 20210727T031008: (36.802753, -121.788054) 2021-07-27T03:10:08.929Z,1627355408.929 [Default:CheckIn:Read_GPS] Stopped 2021-07-27T03:10:08.929Z,1627355408.929 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-27T03:10:17.539Z,1627355417.539 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210726T232245/Courier0120.lzma 2021-07-27T03:10:18.542Z,1627355418.542 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Courier0120.lzma.bak 2021-07-27T03:10:18.542Z,1627355418.542 [DataOverHttps](INFO): SBD MOMSN=15762626 2021-07-27T03:10:39.401Z,1627355439.401 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-07-27T03:10:39.483Z,1627355439.483 [NAL9602](ERROR): received: +CSQ:0 OK524, 2, 0, 0, 0 OK 2021-07-27T03:10:42.871Z,1627355442.871 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20210726T232245/Express0121.lzma 2021-07-27T03:10:43.874Z,1627355443.874 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Express0121.lzma.bak 2021-07-27T03:10:43.874Z,1627355443.874 [DataOverHttps](INFO): SBD MOMSN=15762629 2021-07-27T03:10:47.120Z,1627355447.120 [Default:CheckIn:Read_Iridium] Stopped 2021-07-27T03:10:47.120Z,1627355447.120 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-27T03:10:47.120Z,1627355447.120 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-27T03:15:11.313Z,1627355711.313 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-27T03:15:42.020Z,1627355742.020 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-27T03:15:47.690Z,1627355747.690 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-27T03:15:47.690Z,1627355747.690 [Default:CheckIn:C.Wait] Stopped 2021-07-27T03:15:47.691Z,1627355747.691 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-27T03:15:47.691Z,1627355747.691 [Default:CheckIn:D] Running Loop=1 2021-07-27T03:15:48.102Z,1627355748.102 [Default:CheckIn:D] Stopped 2021-07-27T03:15:48.102Z,1627355748.102 [Default:CheckIn:E] Running Loop=1 2021-07-27T03:15:48.491Z,1627355748.491 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 271.280046 min 2021-07-27T03:15:48.491Z,1627355748.491 [Default:CheckIn:E] Stopped 2021-07-27T03:15:48.492Z,1627355748.492 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-27T03:15:48.492Z,1627355748.492 [Default:CheckIn] Stopped 2021-07-27T03:15:48.492Z,1627355748.492 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-27T03:15:48.492Z,1627355748.492 [Default:CheckIn](INFO): Running loop #45 2021-07-27T03:15:48.492Z,1627355748.492 [Default:CheckIn] Running Loop=45 2021-07-27T03:15:48.492Z,1627355748.492 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-27T03:15:48.492Z,1627355748.492 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-27T03:15:50.506Z,1627355750.506 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,031549.00,A,3648.16154,N,12147.28143,W,0.039,192.68,270721,,,A*7A 2021-07-27T03:15:50.509Z,1627355750.509 [NAL9602](INFO): GPS fix at 20210727T031549: (36.802692, -121.788024) 2021-07-27T03:15:50.519Z,1627355750.519 [Default:CheckIn:Read_GPS] Stopped 2021-07-27T03:15:50.520Z,1627355750.520 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-27T03:15:59.307Z,1627355759.307 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210726T232245/Courier0123.lzma 2021-07-27T03:16:00.309Z,1627355760.309 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Courier0123.lzma.bak 2021-07-27T03:16:00.310Z,1627355760.310 [DataOverHttps](INFO): SBD MOMSN=15762633 2021-07-27T03:16:20.172Z,1627355780.172 [DataOverHttps](INFO): Sending 210 bytes from file Logs/20210726T232245/Express0124.lzma 2021-07-27T03:16:21.174Z,1627355781.174 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Express0124.lzma.bak 2021-07-27T03:16:21.174Z,1627355781.174 [DataOverHttps](INFO): SBD MOMSN=15762636 2021-07-27T03:16:26.577Z,1627355786.577 [Default:CheckIn:Read_Iridium] Stopped 2021-07-27T03:16:26.578Z,1627355786.578 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-27T03:16:26.578Z,1627355786.578 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-27T03:20:52.157Z,1627356052.157 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-27T03:21:22.860Z,1627356082.860 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-27T03:21:27.321Z,1627356087.321 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-27T03:21:27.321Z,1627356087.321 [Default:CheckIn:C.Wait] Stopped 2021-07-27T03:21:27.321Z,1627356087.321 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-27T03:21:27.322Z,1627356087.322 [Default:CheckIn:D] Running Loop=1 2021-07-27T03:21:27.739Z,1627356087.739 [Default:CheckIn:D] Stopped 2021-07-27T03:21:27.739Z,1627356087.739 [Default:CheckIn:E] Running Loop=1 2021-07-27T03:21:28.123Z,1627356088.123 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 276.940658 min 2021-07-27T03:21:28.123Z,1627356088.123 [Default:CheckIn:E] Stopped 2021-07-27T03:21:28.123Z,1627356088.123 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-27T03:21:28.124Z,1627356088.124 [Default:CheckIn] Stopped 2021-07-27T03:21:28.124Z,1627356088.124 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-27T03:21:28.124Z,1627356088.124 [Default:CheckIn](INFO): Running loop #46 2021-07-27T03:21:28.124Z,1627356088.124 [Default:CheckIn] Running Loop=46 2021-07-27T03:21:28.124Z,1627356088.124 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-27T03:21:28.124Z,1627356088.124 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-27T03:21:30.139Z,1627356090.139 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,032129.00,A,3648.16646,N,12147.28089,W,0.389,167.17,270721,,,A*72 2021-07-27T03:21:30.141Z,1627356090.141 [NAL9602](INFO): GPS fix at 20210727T032129: (36.802774, -121.788015) 2021-07-27T03:21:30.152Z,1627356090.152 [Default:CheckIn:Read_GPS] Stopped 2021-07-27T03:21:30.152Z,1627356090.152 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-27T03:21:39.155Z,1627356099.155 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210726T232245/Courier0126.lzma 2021-07-27T03:21:40.157Z,1627356100.157 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Courier0126.lzma.bak 2021-07-27T03:21:40.158Z,1627356100.158 [DataOverHttps](INFO): SBD MOMSN=15762640 2021-07-27T03:21:58.151Z,1627356118.151 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20210726T232245/Express0127.lzma 2021-07-27T03:21:59.154Z,1627356119.154 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Express0127.lzma.bak 2021-07-27T03:21:59.154Z,1627356119.154 [DataOverHttps](INFO): SBD MOMSN=15762643 2021-07-27T03:22:00.849Z,1627356120.849 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-07-27T03:22:00.928Z,1627356120.928 [NAL9602](ERROR): received: +CSQ:0 OK524, 2, 0, 0, 0 OK 2021-07-27T03:22:02.515Z,1627356122.515 [Default:CheckIn:Read_Iridium] Stopped 2021-07-27T03:22:02.516Z,1627356122.516 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-27T03:22:02.516Z,1627356122.516 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-27T03:26:32.457Z,1627356392.457 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-27T03:27:03.160Z,1627356423.160 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-27T03:27:03.203Z,1627356423.203 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-27T03:27:03.203Z,1627356423.203 [Default:CheckIn:C.Wait] Stopped 2021-07-27T03:27:03.203Z,1627356423.203 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-27T03:27:03.204Z,1627356423.204 [Default:CheckIn:D] Running Loop=1 2021-07-27T03:27:03.579Z,1627356423.579 [Default:CheckIn:D] Stopped 2021-07-27T03:27:03.579Z,1627356423.579 [Default:CheckIn:E] Running Loop=1 2021-07-27T03:27:03.979Z,1627356423.979 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 282.537988 min 2021-07-27T03:27:03.979Z,1627356423.979 [Default:CheckIn:E] Stopped 2021-07-27T03:27:03.980Z,1627356423.980 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-27T03:27:03.980Z,1627356423.980 [Default:CheckIn] Stopped 2021-07-27T03:27:03.980Z,1627356423.980 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-27T03:27:03.980Z,1627356423.980 [Default:CheckIn](INFO): Running loop #47 2021-07-27T03:27:03.980Z,1627356423.980 [Default:CheckIn] Running Loop=47 2021-07-27T03:27:03.980Z,1627356423.980 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-27T03:27:03.980Z,1627356423.980 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-27T03:27:05.991Z,1627356425.991 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,032705.00,A,3648.16224,N,12147.28119,W,0.117,151.77,270721,,,A*74 2021-07-27T03:27:05.993Z,1627356425.993 [NAL9602](INFO): GPS fix at 20210727T032705: (36.802704, -121.788020) 2021-07-27T03:27:06.021Z,1627356426.021 [Default:CheckIn:Read_GPS] Stopped 2021-07-27T03:27:06.021Z,1627356426.021 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-27T03:27:14.815Z,1627356434.815 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210726T232245/Courier0129.lzma 2021-07-27T03:27:15.817Z,1627356435.817 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Courier0129.lzma.bak 2021-07-27T03:27:15.818Z,1627356435.818 [DataOverHttps](INFO): SBD MOMSN=15762647 2021-07-27T03:27:33.931Z,1627356453.931 [DataOverHttps](INFO): Sending 208 bytes from file Logs/20210726T232245/Express0130.lzma 2021-07-27T03:27:34.934Z,1627356454.934 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Express0130.lzma.bak 2021-07-27T03:27:34.934Z,1627356454.934 [DataOverHttps](INFO): SBD MOMSN=15762650 2021-07-27T03:27:38.348Z,1627356458.348 [Default:CheckIn:Read_Iridium] Stopped 2021-07-27T03:27:38.348Z,1627356458.348 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-27T03:27:38.348Z,1627356458.348 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-27T03:32:08.341Z,1627356728.341 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-27T03:32:39.116Z,1627356759.116 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-27T03:32:39.157Z,1627356759.157 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-27T03:32:39.157Z,1627356759.157 [Default:CheckIn:C.Wait] Stopped 2021-07-27T03:32:39.157Z,1627356759.157 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-27T03:32:39.157Z,1627356759.157 [Default:CheckIn:D] Running Loop=1 2021-07-27T03:32:39.523Z,1627356759.523 [Default:CheckIn:D] Stopped 2021-07-27T03:32:39.523Z,1627356759.523 [Default:CheckIn:E] Running Loop=1 2021-07-27T03:32:39.925Z,1627356759.925 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 288.137044 min 2021-07-27T03:32:39.925Z,1627356759.925 [Default:CheckIn:E] Stopped 2021-07-27T03:32:39.925Z,1627356759.925 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-27T03:32:39.925Z,1627356759.925 [Default:CheckIn] Stopped 2021-07-27T03:32:39.925Z,1627356759.925 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-27T03:32:39.926Z,1627356759.926 [Default:CheckIn](INFO): Running loop #48 2021-07-27T03:32:39.926Z,1627356759.926 [Default:CheckIn] Running Loop=48 2021-07-27T03:32:39.926Z,1627356759.926 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-27T03:32:39.926Z,1627356759.926 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-27T03:32:41.938Z,1627356761.938 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,033241.00,A,3648.16987,N,12147.29015,W,0.214,0.00,270721,,,A*7B 2021-07-27T03:32:41.941Z,1627356761.941 [NAL9602](INFO): GPS fix at 20210727T033241: (36.802831, -121.788169) 2021-07-27T03:32:41.977Z,1627356761.977 [Default:CheckIn:Read_GPS] Stopped 2021-07-27T03:32:41.977Z,1627356761.977 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-27T03:32:50.544Z,1627356770.544 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210726T232245/Courier0132.lzma 2021-07-27T03:32:51.545Z,1627356771.546 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Courier0132.lzma.bak 2021-07-27T03:32:51.546Z,1627356771.546 [DataOverHttps](INFO): SBD MOMSN=15762654 2021-07-27T03:33:10.515Z,1627356790.515 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20210726T232245/Express0133.lzma 2021-07-27T03:33:11.518Z,1627356791.518 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Express0133.lzma.bak 2021-07-27T03:33:11.518Z,1627356791.518 [DataOverHttps](INFO): SBD MOMSN=15762657 2021-07-27T03:33:12.725Z,1627356792.725 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-07-27T03:33:12.808Z,1627356792.808 [NAL9602](ERROR): received: +CSQ:0 OK524, 2, 0, 0, 0 OK 2021-07-27T03:33:14.768Z,1627356794.768 [Default:CheckIn:Read_Iridium] Stopped 2021-07-27T03:33:14.768Z,1627356794.768 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-27T03:33:14.768Z,1627356794.768 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-27T03:37:44.376Z,1627357064.376 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-27T03:38:15.080Z,1627357095.080 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-27T03:38:15.500Z,1627357095.500 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-27T03:38:15.501Z,1627357095.501 [Default:CheckIn:C.Wait] Stopped 2021-07-27T03:38:15.501Z,1627357095.501 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-27T03:38:15.501Z,1627357095.501 [Default:CheckIn:D] Running Loop=1 2021-07-27T03:38:15.901Z,1627357095.901 [Default:CheckIn:D] Stopped 2021-07-27T03:38:15.901Z,1627357095.901 [Default:CheckIn:E] Running Loop=1 2021-07-27T03:38:16.317Z,1627357096.317 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 293.743359 min 2021-07-27T03:38:16.317Z,1627357096.317 [Default:CheckIn:E] Stopped 2021-07-27T03:38:16.317Z,1627357096.317 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-27T03:38:16.317Z,1627357096.317 [Default:CheckIn] Stopped 2021-07-27T03:38:16.317Z,1627357096.317 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-27T03:38:16.318Z,1627357096.318 [Default:CheckIn](INFO): Running loop #49 2021-07-27T03:38:16.318Z,1627357096.318 [Default:CheckIn] Running Loop=49 2021-07-27T03:38:16.318Z,1627357096.318 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-27T03:38:16.318Z,1627357096.318 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-27T03:38:18.315Z,1627357098.315 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,033817.00,A,3648.16334,N,12147.28289,W,0.136,0.00,270721,,,A*75 2021-07-27T03:38:18.317Z,1627357098.317 [NAL9602](INFO): GPS fix at 20210727T033817: (36.802722, -121.788048) 2021-07-27T03:38:18.333Z,1627357098.333 [Default:CheckIn:Read_GPS] Stopped 2021-07-27T03:38:18.334Z,1627357098.334 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-27T03:38:30.987Z,1627357110.987 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210726T232245/Courier0135.lzma 2021-07-27T03:38:31.990Z,1627357111.990 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Courier0135.lzma.bak 2021-07-27T03:38:31.990Z,1627357111.990 [DataOverHttps](INFO): SBD MOMSN=15762661 2021-07-27T03:38:48.853Z,1627357128.853 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-07-27T03:38:48.927Z,1627357128.927 [NAL9602](ERROR): received: +CSQ:0 OK524, 2, 0, 0, 0 OK 2021-07-27T03:38:54.047Z,1627357134.047 [DataOverHttps](INFO): Sending 209 bytes from file Logs/20210726T232245/Express0136.lzma 2021-07-27T03:38:55.049Z,1627357135.049 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Express0136.lzma.bak 2021-07-27T03:38:55.050Z,1627357135.050 [DataOverHttps](INFO): SBD MOMSN=15762664 2021-07-27T03:38:58.585Z,1627357138.585 [Default:CheckIn:Read_Iridium] Stopped 2021-07-27T03:38:58.585Z,1627357138.585 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-27T03:38:58.585Z,1627357138.585 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-27T03:43:20.369Z,1627357400.369 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-27T03:43:51.076Z,1627357431.076 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-27T03:43:59.164Z,1627357439.164 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-27T03:43:59.164Z,1627357439.164 [Default:CheckIn:C.Wait] Stopped 2021-07-27T03:43:59.165Z,1627357439.165 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-27T03:43:59.165Z,1627357439.165 [Default:CheckIn:D] Running Loop=1 2021-07-27T03:43:59.580Z,1627357439.580 [Default:CheckIn:D] Stopped 2021-07-27T03:43:59.580Z,1627357439.580 [Default:CheckIn:E] Running Loop=1 2021-07-27T03:43:59.975Z,1627357439.975 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 299.471354 min 2021-07-27T03:43:59.975Z,1627357439.975 [Default:CheckIn:E] Stopped 2021-07-27T03:43:59.975Z,1627357439.975 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-27T03:43:59.975Z,1627357439.975 [Default:CheckIn] Stopped 2021-07-27T03:43:59.975Z,1627357439.975 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-27T03:43:59.976Z,1627357439.976 [Default:CheckIn](INFO): Running loop #50 2021-07-27T03:43:59.976Z,1627357439.976 [Default:CheckIn] Running Loop=50 2021-07-27T03:43:59.976Z,1627357439.976 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-27T03:43:59.976Z,1627357439.976 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-27T03:44:01.982Z,1627357441.982 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,034401.00,A,3648.16461,N,12147.28046,W,0.467,0.00,270721,,,A*7E 2021-07-27T03:44:01.985Z,1627357441.985 [NAL9602](INFO): GPS fix at 20210727T034401: (36.802743, -121.788008) 2021-07-27T03:44:01.995Z,1627357441.995 [Default:CheckIn:Read_GPS] Stopped 2021-07-27T03:44:01.996Z,1627357441.996 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-27T03:44:10.543Z,1627357450.543 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210726T232245/Courier0138.lzma 2021-07-27T03:44:11.546Z,1627357451.546 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Courier0138.lzma.bak 2021-07-27T03:44:11.546Z,1627357451.546 [DataOverHttps](INFO): SBD MOMSN=15762668 2021-07-27T03:44:32.797Z,1627357472.797 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-07-27T03:44:32.891Z,1627357472.891 [NAL9602](ERROR): received: +CSQ:0 OK524, 2, 0, 0, 0 OK 2021-07-27T03:44:37.280Z,1627357477.280 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20210726T232245/Express0139.lzma 2021-07-27T03:44:38.282Z,1627357478.282 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Express0139.lzma.bak 2021-07-27T03:44:38.282Z,1627357478.282 [DataOverHttps](INFO): SBD MOMSN=15762671 2021-07-27T03:44:43.739Z,1627357483.739 [Default:CheckIn:Read_Iridium] Stopped 2021-07-27T03:44:43.739Z,1627357483.739 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-27T03:44:43.739Z,1627357483.739 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-27T03:48:32.502Z,1627357712.502 [NAL9602](INFO): SBD MO Status=2, MOMSN=28524, MT Status=2, MTMSN=0 2021-07-27T03:48:32.502Z,1627357712.502 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-27T03:49:04.041Z,1627357744.041 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-27T03:49:34.744Z,1627357774.744 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-27T03:49:44.449Z,1627357784.449 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-27T03:49:44.449Z,1627357784.449 [Default:CheckIn:C.Wait] Stopped 2021-07-27T03:49:44.449Z,1627357784.449 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-27T03:49:44.450Z,1627357784.450 [Default:CheckIn:D] Running Loop=1 2021-07-27T03:49:44.862Z,1627357784.862 [Default:CheckIn:D] Stopped 2021-07-27T03:49:44.862Z,1627357784.862 [Default:CheckIn:E] Running Loop=1 2021-07-27T03:49:45.282Z,1627357785.282 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 305.226042 min 2021-07-27T03:49:45.282Z,1627357785.282 [Default:CheckIn:E] Stopped 2021-07-27T03:49:45.283Z,1627357785.283 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-27T03:49:45.283Z,1627357785.283 [Default:CheckIn] Stopped 2021-07-27T03:49:45.283Z,1627357785.283 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-27T03:49:45.283Z,1627357785.283 [Default:CheckIn](INFO): Running loop #51 2021-07-27T03:49:45.283Z,1627357785.283 [Default:CheckIn] Running Loop=51 2021-07-27T03:49:45.283Z,1627357785.283 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-27T03:49:45.283Z,1627357785.283 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-27T03:49:47.265Z,1627357787.265 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,034946.00,A,3648.16485,N,12147.28619,W,0.408,0.00,270721,,,A*7F 2021-07-27T03:49:47.267Z,1627357787.267 [NAL9602](INFO): GPS fix at 20210727T034946: (36.802748, -121.788103) 2021-07-27T03:49:47.298Z,1627357787.298 [Default:CheckIn:Read_GPS] Stopped 2021-07-27T03:49:47.299Z,1627357787.299 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-27T03:49:56.091Z,1627357796.091 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210726T232245/Courier0141.lzma 2021-07-27T03:49:57.094Z,1627357797.094 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Courier0141.lzma.bak 2021-07-27T03:49:57.094Z,1627357797.094 [DataOverHttps](INFO): SBD MOMSN=15762675 2021-07-27T03:50:15.091Z,1627357815.091 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20210726T232245/Express0142.lzma 2021-07-27T03:50:16.094Z,1627357816.094 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Express0142.lzma.bak 2021-07-27T03:50:16.094Z,1627357816.094 [DataOverHttps](INFO): SBD MOMSN=15762678 2021-07-27T03:50:17.977Z,1627357817.977 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-07-27T03:50:18.059Z,1627357818.059 [NAL9602](ERROR): received: +CSQ:0 OK524, 2, 0, 0, 0 OK 2021-07-27T03:50:21.655Z,1627357821.655 [Default:CheckIn:Read_Iridium] Stopped 2021-07-27T03:50:21.656Z,1627357821.656 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-27T03:50:21.656Z,1627357821.656 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-27T03:54:49.637Z,1627358089.637 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-27T03:55:20.343Z,1627358120.343 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-27T03:55:22.380Z,1627358122.380 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-27T03:55:22.380Z,1627358122.380 [Default:CheckIn:C.Wait] Stopped 2021-07-27T03:55:22.380Z,1627358122.380 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-27T03:55:22.381Z,1627358122.381 [Default:CheckIn:D] Running Loop=1 2021-07-27T03:55:22.804Z,1627358122.804 [Default:CheckIn:D] Stopped 2021-07-27T03:55:22.804Z,1627358122.804 [Default:CheckIn:E] Running Loop=1 2021-07-27T03:55:23.315Z,1627358123.315 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 310.857975 min 2021-07-27T03:55:23.315Z,1627358123.315 [Default:CheckIn:E] Stopped 2021-07-27T03:55:23.316Z,1627358123.316 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-27T03:55:23.316Z,1627358123.316 [Default:CheckIn] Stopped 2021-07-27T03:55:23.316Z,1627358123.316 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-27T03:55:23.316Z,1627358123.316 [Default:CheckIn](INFO): Running loop #52 2021-07-27T03:55:23.316Z,1627358123.316 [Default:CheckIn] Running Loop=52 2021-07-27T03:55:23.316Z,1627358123.316 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-27T03:55:23.316Z,1627358123.316 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-27T03:55:25.193Z,1627358125.193 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,035524.00,A,3648.16741,N,12147.28218,W,0.350,132.26,270721,,,A*76 2021-07-27T03:55:25.195Z,1627358125.195 [NAL9602](INFO): GPS fix at 20210727T035524: (36.802790, -121.788036) 2021-07-27T03:55:25.206Z,1627358125.206 [Default:CheckIn:Read_GPS] Stopped 2021-07-27T03:55:25.206Z,1627358125.206 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-27T03:55:33.827Z,1627358133.827 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210726T232245/Courier0144.lzma 2021-07-27T03:55:34.830Z,1627358134.830 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Courier0144.lzma.bak 2021-07-27T03:55:34.830Z,1627358134.830 [DataOverHttps](INFO): SBD MOMSN=15762682 2021-07-27T03:55:53.287Z,1627358153.287 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20210726T232245/Express0145.lzma 2021-07-27T03:55:54.290Z,1627358154.290 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Express0145.lzma.bak 2021-07-27T03:55:54.290Z,1627358154.290 [DataOverHttps](INFO): SBD MOMSN=15762686 2021-07-27T03:55:55.941Z,1627358155.941 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-07-27T03:55:56.019Z,1627358156.019 [NAL9602](ERROR): received: +CSQ:0 OK524, 2, 0, 0, 0 OK 2021-07-27T03:55:57.599Z,1627358157.599 [Default:CheckIn:Read_Iridium] Stopped 2021-07-27T03:55:57.600Z,1627358157.600 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-27T03:55:57.600Z,1627358157.600 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-27T03:57:43.195Z,1627358263.195 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2021-07-27T03:57:43.198Z,1627358263.198 [BPC1](INFO): Received data from all battery sticks. 2021-07-27T03:58:24.401Z,1627358304.401 [NAL9602](INFO): SBD MO Status=2, MOMSN=28524, MT Status=2, MTMSN=0 2021-07-27T03:58:24.401Z,1627358304.401 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-27T04:00:27.285Z,1627358427.285 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-27T04:00:57.992Z,1627358457.992 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-27T04:00:58.403Z,1627358458.403 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-27T04:00:58.403Z,1627358458.403 [Default:CheckIn:C.Wait] Stopped 2021-07-27T04:00:58.404Z,1627358458.404 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-27T04:00:58.404Z,1627358458.404 [Default:CheckIn:D] Running Loop=1 2021-07-27T04:00:58.815Z,1627358458.815 [Default:CheckIn:D] Stopped 2021-07-27T04:00:58.815Z,1627358458.815 [Default:CheckIn:E] Running Loop=1 2021-07-27T04:00:59.226Z,1627358459.226 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 316.458594 min 2021-07-27T04:00:59.226Z,1627358459.226 [Default:CheckIn:E] Stopped 2021-07-27T04:00:59.226Z,1627358459.226 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-27T04:00:59.226Z,1627358459.226 [Default:CheckIn] Stopped 2021-07-27T04:00:59.226Z,1627358459.226 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-27T04:00:59.226Z,1627358459.226 [Default:CheckIn](INFO): Running loop #53 2021-07-27T04:00:59.226Z,1627358459.226 [Default:CheckIn] Running Loop=53 2021-07-27T04:00:59.227Z,1627358459.227 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-27T04:00:59.227Z,1627358459.227 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-27T04:01:01.226Z,1627358461.226 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,040100.00,A,3648.16589,N,12147.28146,W,0.836,132.26,270721,,,A*73 2021-07-27T04:01:01.229Z,1627358461.229 [NAL9602](INFO): GPS fix at 20210727T040100: (36.802765, -121.788024) 2021-07-27T04:01:01.264Z,1627358461.264 [Default:CheckIn:Read_GPS] Stopped 2021-07-27T04:01:01.264Z,1627358461.264 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-27T04:01:10.227Z,1627358470.227 [DataOverHttps](INFO): Sending 84 bytes from file Logs/20210726T232245/Courier0147.lzma 2021-07-27T04:01:11.230Z,1627358471.230 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Courier0147.lzma.bak 2021-07-27T04:01:11.230Z,1627358471.230 [DataOverHttps](INFO): SBD MOMSN=15762690 2021-07-27T04:01:30.528Z,1627358490.528 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20210726T232245/Express0148.lzma 2021-07-27T04:01:31.530Z,1627358491.530 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Express0148.lzma.bak 2021-07-27T04:01:31.530Z,1627358491.530 [DataOverHttps](INFO): SBD MOMSN=15762693 2021-07-27T04:01:31.929Z,1627358491.929 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-07-27T04:01:32.003Z,1627358492.003 [NAL9602](ERROR): received: +CSQ:0 OK524, 2, 0, 0, 0 OK 2021-07-27T04:01:34.777Z,1627358494.777 [Default:CheckIn:Read_Iridium] Stopped 2021-07-27T04:01:34.778Z,1627358494.778 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-27T04:01:34.778Z,1627358494.778 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-27T04:06:03.532Z,1627358763.532 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-27T04:06:34.301Z,1627358794.301 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-27T04:06:35.580Z,1627358795.580 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-27T04:06:35.580Z,1627358795.580 [Default:CheckIn:C.Wait] Stopped 2021-07-27T04:06:35.581Z,1627358795.581 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-27T04:06:35.581Z,1627358795.581 [Default:CheckIn:D] Running Loop=1 2021-07-27T04:06:35.943Z,1627358795.943 [Default:CheckIn:D] Stopped 2021-07-27T04:06:35.943Z,1627358795.943 [Default:CheckIn:E] Running Loop=1 2021-07-27T04:06:36.333Z,1627358796.333 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 322.077376 min 2021-07-27T04:06:36.333Z,1627358796.333 [Default:CheckIn:E] Stopped 2021-07-27T04:06:36.333Z,1627358796.333 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-27T04:06:36.334Z,1627358796.334 [Default:CheckIn] Stopped 2021-07-27T04:06:36.334Z,1627358796.334 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-27T04:06:36.334Z,1627358796.334 [Default:CheckIn](INFO): Running loop #54 2021-07-27T04:06:36.334Z,1627358796.334 [Default:CheckIn] Running Loop=54 2021-07-27T04:06:36.334Z,1627358796.334 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-27T04:06:36.334Z,1627358796.334 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-27T04:06:38.350Z,1627358798.350 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,040637.00,A,3648.16842,N,12147.28326,W,0.525,146.36,270721,,,A*73 2021-07-27T04:06:38.353Z,1627358798.353 [NAL9602](INFO): GPS fix at 20210727T040637: (36.802807, -121.788054) 2021-07-27T04:06:38.364Z,1627358798.364 [Default:CheckIn:Read_GPS] Stopped 2021-07-27T04:06:38.364Z,1627358798.364 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-27T04:06:48.105Z,1627358808.105 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210726T232245/Courier0150.lzma 2021-07-27T04:06:48.386Z,1627358808.386 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Courier0150.lzma.bak 2021-07-27T04:06:48.386Z,1627358808.386 [DataOverHttps](INFO): SBD MOMSN=15762697 2021-07-27T04:07:06.363Z,1627358826.363 [DataOverHttps](INFO): Sending 205 bytes from file Logs/20210726T232245/Express0151.lzma 2021-07-27T04:07:07.366Z,1627358827.366 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Express0151.lzma.bak 2021-07-27T04:07:07.366Z,1627358827.366 [DataOverHttps](INFO): SBD MOMSN=15762700 2021-07-27T04:07:09.041Z,1627358829.041 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-07-27T04:07:09.115Z,1627358829.115 [NAL9602](ERROR): received: +CSQ:0 OK524, 2, 0, 0, 0 OK 2021-07-27T04:07:10.701Z,1627358830.701 [Default:CheckIn:Read_Iridium] Stopped 2021-07-27T04:07:10.701Z,1627358830.701 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-27T04:07:10.701Z,1627358830.701 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-27T04:07:28.446Z,1627358848.446 [NAL9602](INFO): SBD MO Status=2, MOMSN=28524, MT Status=2, MTMSN=0 2021-07-27T04:07:28.447Z,1627358848.447 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-27T04:07:52.275Z,1627358872.275 [NAL9602](INFO): SBD MO Status=2, MOMSN=28524, MT Status=2, MTMSN=0 2021-07-27T04:07:52.275Z,1627358872.275 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-27T04:11:40.661Z,1627359100.661 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-27T04:12:11.372Z,1627359131.372 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-27T04:12:11.408Z,1627359131.408 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-27T04:12:11.408Z,1627359131.408 [Default:CheckIn:C.Wait] Stopped 2021-07-27T04:12:11.408Z,1627359131.408 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-27T04:12:11.408Z,1627359131.408 [Default:CheckIn:D] Running Loop=1 2021-07-27T04:12:11.783Z,1627359131.783 [Default:CheckIn:D] Stopped 2021-07-27T04:12:11.783Z,1627359131.783 [Default:CheckIn:E] Running Loop=1 2021-07-27T04:12:12.185Z,1627359132.185 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 327.674707 min 2021-07-27T04:12:12.185Z,1627359132.185 [Default:CheckIn:E] Stopped 2021-07-27T04:12:12.185Z,1627359132.185 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-27T04:12:12.185Z,1627359132.185 [Default:CheckIn] Stopped 2021-07-27T04:12:12.185Z,1627359132.185 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-27T04:12:12.186Z,1627359132.186 [Default:CheckIn](INFO): Running loop #55 2021-07-27T04:12:12.186Z,1627359132.186 [Default:CheckIn] Running Loop=55 2021-07-27T04:12:12.186Z,1627359132.186 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-27T04:12:12.186Z,1627359132.186 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-27T04:12:14.199Z,1627359134.199 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,041213.00,A,3648.16538,N,12147.28179,W,0.739,142.51,270721,,,A*72 2021-07-27T04:12:14.201Z,1627359134.201 [NAL9602](INFO): GPS fix at 20210727T041213: (36.802756, -121.788030) 2021-07-27T04:12:14.212Z,1627359134.212 [Default:CheckIn:Read_GPS] Stopped 2021-07-27T04:12:14.212Z,1627359134.212 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-27T04:12:26.088Z,1627359146.088 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210726T232245/Courier0153.lzma 2021-07-27T04:12:27.090Z,1627359147.090 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Courier0153.lzma.bak 2021-07-27T04:12:27.090Z,1627359147.090 [DataOverHttps](INFO): SBD MOMSN=15762704 2021-07-27T04:12:44.632Z,1627359164.632 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-07-27T04:12:44.715Z,1627359164.715 [NAL9602](ERROR): received: +CSQ:0 OK524, 2, 0, 0, 0 OK 2021-07-27T04:12:50.512Z,1627359170.512 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20210726T232245/Express0154.lzma 2021-07-27T04:12:51.514Z,1627359171.514 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Express0154.lzma.bak 2021-07-27T04:12:51.514Z,1627359171.514 [DataOverHttps](INFO): SBD MOMSN=15762707 2021-07-27T04:12:54.768Z,1627359174.768 [Default:CheckIn:Read_Iridium] Stopped 2021-07-27T04:12:54.768Z,1627359174.768 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-27T04:12:54.768Z,1627359174.768 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-27T04:14:38.966Z,1627359278.966 [NAL9602](INFO): SBD MO Status=2, MOMSN=28524, MT Status=2, MTMSN=0 2021-07-27T04:14:38.966Z,1627359278.966 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-27T04:14:42.630Z,1627359282.630 [CBIT](IMPORTANT): Beginning ground fault scan 2021-07-27T04:14:53.540Z,1627359293.540 [CBIT](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): -0.002055 CHAN A1 (24V): -0.180911 CHAN A2 (12V): -0.002010 CHAN A3 (5V): -0.001625 CHAN B0 (3.3V): -0.000071 CHAN B1 (3.15aV): 0.000316 CHAN B2 (3.15bV): -0.000325 CHAN B3 (GND): -0.000119 OPEN: -0.000697 Full Scale Calc: 4.765 mA, -1.589 mA 2021-07-27T04:15:25.834Z,1627359325.834 [NAL9602](INFO): SBD MO Status=2, MOMSN=28524, MT Status=2, MTMSN=0 2021-07-27T04:15:25.834Z,1627359325.834 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-27T04:15:36.728Z,1627359336.728 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-07-27T04:16:31.722Z,1627359391.722 [NAL9602](INFO): SBD MO Status=2, MOMSN=28524, MT Status=2, MTMSN=0 2021-07-27T04:16:31.722Z,1627359391.722 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-27T04:17:03.214Z,1627359423.214 [NAL9602](INFO): SBD MO Status=2, MOMSN=28524, MT Status=2, MTMSN=0 2021-07-27T04:17:03.214Z,1627359423.214 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-27T04:17:08.732Z,1627359428.732 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-07-27T04:17:31.894Z,1627359451.894 [NAL9602](INFO): SBD MO Status=0, MOMSN=28524, MT Status=0, MTMSN=0 2021-07-27T04:17:31.895Z,1627359451.895 [NAL9602](INFO): No messages in MT queue 2021-07-27T04:17:55.338Z,1627359475.338 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-27T04:17:55.338Z,1627359475.338 [Default:CheckIn:C.Wait] Stopped 2021-07-27T04:17:55.338Z,1627359475.338 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-27T04:17:55.339Z,1627359475.339 [Default:CheckIn:D] Running Loop=1 2021-07-27T04:17:55.741Z,1627359475.741 [Default:CheckIn:D] Stopped 2021-07-27T04:17:55.741Z,1627359475.741 [Default:CheckIn:E] Running Loop=1 2021-07-27T04:17:56.153Z,1627359476.153 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 333.407357 min 2021-07-27T04:17:56.153Z,1627359476.153 [Default:CheckIn:E] Stopped 2021-07-27T04:17:56.154Z,1627359476.154 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-27T04:17:56.154Z,1627359476.154 [Default:CheckIn] Stopped 2021-07-27T04:17:56.154Z,1627359476.154 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-27T04:17:56.154Z,1627359476.154 [Default:CheckIn](INFO): Running loop #56 2021-07-27T04:17:56.154Z,1627359476.154 [Default:CheckIn] Running Loop=56 2021-07-27T04:17:56.154Z,1627359476.154 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-27T04:17:56.154Z,1627359476.154 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-27T04:17:58.153Z,1627359478.153 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,041757.00,A,3648.16543,N,12147.28290,W,0.914,142.51,270721,,,A*7E 2021-07-27T04:17:58.155Z,1627359478.155 [NAL9602](INFO): GPS fix at 20210727T041757: (36.802757, -121.788048) 2021-07-27T04:17:58.166Z,1627359478.166 [Default:CheckIn:Read_GPS] Stopped 2021-07-27T04:17:58.166Z,1627359478.166 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-27T04:18:06.743Z,1627359486.743 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210726T232245/Courier0156.lzma 2021-07-27T04:18:07.746Z,1627359487.746 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Courier0156.lzma.bak 2021-07-27T04:18:07.746Z,1627359487.746 [DataOverHttps](INFO): SBD MOMSN=15762711 2021-07-27T04:18:30.481Z,1627359510.481 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-27T04:18:40.948Z,1627359520.948 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-07-27T04:19:12.076Z,1627359552.076 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-07-27T04:19:43.200Z,1627359583.200 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-07-27T04:20:14.356Z,1627359614.356 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-07-27T04:20:36.620Z,1627359636.620 [DataOverHttps](INFO): Sending 340 bytes from file Logs/20210726T232245/Express0157.lzma 2021-07-27T04:20:37.622Z,1627359637.622 [DataOverHttps](INFO): Moved sent file to Logs/20210726T232245/Express0157.lzma.bak 2021-07-27T04:20:37.622Z,1627359637.622 [DataOverHttps](INFO): SBD MOMSN=15762714 2021-07-27T04:20:43.224Z,1627359643.224 [Default:CheckIn:Read_Iridium] Stopped 2021-07-27T04:20:43.224Z,1627359643.224 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-27T04:20:43.224Z,1627359643.224 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-27T04:21:57.823Z,1627359717.823 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-07-27T04:22:28.968Z,1627359748.968 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-07-27T04:23:00.091Z,1627359780.091 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-07-27T04:23:31.239Z,1627359811.239 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-07-27T04:23:42.089Z,1627359822.089 [DataOverHttps](IMPORTANT): SBD MTMSN=20210727T042341 2021-07-27T04:23:49.763Z,1627359829.763 [DataOverHttps](INFO): Received command:restart app 2021-07-27T04:23:49.829Z,1627359829.829 [CommandLine](IMPORTANT): got command restart application 2021-07-27T04:23:50.835Z,1627359830.835 [Supervisor](INFO): Stop Mission called by Supervisor::terminate 2021-07-27T04:23:50.836Z,1627359830.836 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2021-07-27T04:23:50.836Z,1627359830.836 [CommandLine ThreadHandler](INFO): Thread cancelled. 2021-07-27T04:23:50.943Z,1627359830.943 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2021-07-27T04:23:50.943Z,1627359830.943 [CommandLine ThreadHandler](INFO): Thread cancelled. 2021-07-27T04:23:50.944Z,1627359830.944 [CommandLine](INFO): Join timeout helper Thread ID is 7626 2021-07-27T04:23:50.944Z,1627359830.944 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2021-07-27T04:23:50.944Z,1627359830.944 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2021-07-27T04:23:50.945Z,1627359830.945 [NavChartDb](INFO): Join timeout helper Thread ID is 7627 2021-07-27T04:23:51.291Z,1627359831.291 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2021-07-27T04:23:51.292Z,1627359831.292 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2021-07-27T04:23:51.303Z,1627359831.303 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2021-07-27T04:23:51.303Z,1627359831.303 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2021-07-27T04:23:51.304Z,1627359831.304 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 7628 2021-07-27T04:23:51.323Z,1627359831.323 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2021-07-27T04:23:51.324Z,1627359831.324 [WetLabsBB2FL](INFO): Powering down 2021-07-27T04:23:51.324Z,1627359831.324 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2021-07-27T04:23:51.343Z,1627359831.343 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2021-07-27T04:23:51.343Z,1627359831.343 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2021-07-27T04:23:51.344Z,1627359831.344 [CTD_Seabird](INFO): Join timeout helper Thread ID is 7629 2021-07-27T04:23:51.595Z,1627359831.595 [CTD_Seabird](INFO): Powering down 2021-07-27T04:23:51.607Z,1627359831.607 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread. 2021-07-27T04:23:51.608Z,1627359831.608 [CTD_Seabird](INFO): Powering down 2021-07-27T04:23:51.619Z,1627359831.619 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2021-07-27T04:23:51.623Z,1627359831.623 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2021-07-27T04:23:51.623Z,1627359831.623 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2021-07-27T04:23:51.624Z,1627359831.624 [Radio_Surface](INFO): Join timeout helper Thread ID is 7630 2021-07-27T04:23:51.796Z,1627359831.796 [Radio_Surface](INFO): Powering down 2021-07-27T04:23:51.797Z,1627359831.797 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2021-07-27T04:23:51.797Z,1627359831.797 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2021-07-27T04:23:51.812Z,1627359831.812 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler 2021-07-27T04:23:51.812Z,1627359831.812 [Onboard ThreadHandler](INFO): Thread cancelled. 2021-07-27T04:23:51.813Z,1627359831.813 [Onboard](INFO): Join timeout helper Thread ID is 7631 2021-07-27T04:23:52.772Z,1627359832.772 [DataOverHttps](INFO): Radio surface powered OFF, will not connect. 2021-07-27T04:23:53.019Z,1627359833.019 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread. 2021-07-27T04:23:53.020Z,1627359833.020 [Onboard ThreadHandler](INFO): Thread cancelled. 2021-07-27T04:23:53.032Z,1627359833.032 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2021-07-27T04:23:53.032Z,1627359833.032 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2021-07-27T04:23:53.032Z,1627359833.032 [DataOverHttps](INFO): Join timeout helper Thread ID is 7632 2021-07-27T04:23:53.775Z,1627359833.775 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2021-07-27T04:23:53.776Z,1627359833.776 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2021-07-27T04:23:53.792Z,1627359833.792 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2021-07-27T04:23:53.792Z,1627359833.792 [logger ThreadHandler](INFO): Thread cancelled. 2021-07-27T04:23:53.793Z,1627359833.793 [logger](INFO): Join timeout helper Thread ID is 7633 2021-07-27T04:23:53.839Z,1627359833.839 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2021-07-27T04:23:53.840Z,1627359833.840 [logger ThreadHandler](INFO): Thread cancelled. 2021-07-27T04:23:53.852Z,1627359833.852 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2021-07-27T04:23:53.852Z,1627359833.852 [CommandLine ThreadHandler](INFO): Thread cancelled. 2021-07-27T04:23:53.852Z,1627359833.852 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2021-07-27T04:23:53.852Z,1627359833.852 [controlThread ThreadHandler](INFO): Thread cancelled. 2021-07-27T04:23:53.853Z,1627359833.853 [controlThread](INFO): Join timeout helper Thread ID is 7634 2021-07-27T04:23:53.971Z,1627359833.971 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2021-07-27T04:23:53.972Z,1627359833.972 [controlThread](DEBUG): Uninitializing ControlThread 2021-07-27T04:23:53.972Z,1627359833.972 [AHRS_M2](INFO): Powering down 2021-07-27T04:23:54.044Z,1627359834.044 [NAL9602](INFO): Powering down 2021-07-27T04:23:54.047Z,1627359834.047 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2021-07-27T04:23:54.048Z,1627359834.048 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2021-07-27T04:23:54.048Z,1627359834.048 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2021-07-27T04:23:54.049Z,1627359834.049 [MissionManager](INFO): Uninitializing Mission Default 2021-07-27T04:23:54.049Z,1627359834.049 [Default] Stopped 2021-07-27T04:23:54.049Z,1627359834.049 [Default](DEBUG): Aggregate::uninitialize Default 2021-07-27T04:23:54.049Z,1627359834.049 [Default:B.GoToSurface] Stopped 2021-07-27T04:23:54.049Z,1627359834.049 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2021-07-27T04:23:54.049Z,1627359834.049 [Default:CheckIn] Stopped 2021-07-27T04:23:54.050Z,1627359834.050 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-27T04:23:54.050Z,1627359834.050 [Default:CheckIn:C.Wait] Stopped 2021-07-27T04:23:54.050Z,1627359834.050 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-27T04:23:54.053Z,1627359834.053 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2021-07-27T04:23:54.054Z,1627359834.054 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2021-07-27T04:23:54.054Z,1627359834.054 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2021-07-27T04:23:54.054Z,1627359834.054 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2021-07-27T04:23:54.054Z,1627359834.054 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2021-07-27T04:23:54.055Z,1627359834.055 [BuoyancyServo](INFO): Powering down 2021-07-27T04:23:54.067Z,1627359834.067 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2021-07-27T04:23:54.068Z,1627359834.068 [ElevatorServo](INFO): Powering down 2021-07-27T04:23:54.068Z,1627359834.068 [MassServo](DEBUG): Uninitialize Mass Servo. 2021-07-27T04:23:54.069Z,1627359834.069 [MassServo](INFO): Powering down 2021-07-27T04:23:54.069Z,1627359834.069 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2021-07-27T04:23:54.070Z,1627359834.070 [RudderServo](INFO): Powering down 2021-07-27T04:23:54.070Z,1627359834.070 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2021-07-27T04:23:54.071Z,1627359834.071 [ThrusterServo](INFO): Powering down 2021-07-27T04:23:54.072Z,1627359834.072 [SBIT](DEBUG): Uninitialize SBIT Component. 2021-07-27T04:23:54.072Z,1627359834.072 [IBIT](DEBUG): Uninitialize IBIT Component. 2021-07-27T04:23:54.072Z,1627359834.072 [CBIT](DEBUG): Uninitialize CBIT Component. 2021-07-27T04:23:54.073Z,1627359834.073 [CBIT](DEBUG): Powering off loads. 2021-07-27T04:23:54.083Z,1627359834.083 [CBIT](DEBUG): Disabling WDT. 2021-07-27T04:23:54.095Z,1627359834.095 [CBIT](DEBUG): Opening all GF detection circuits. 2021-07-27T04:23:54.096Z,1627359834.096 [controlThread ThreadHandler](INFO): Thread cancelled. 2021-07-27T04:23:54.147Z,1627359834.147 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2021-07-27T04:23:54.150Z,1627359834.150 [Onboard ThreadHandler](INFO): Thread cancelled. 2021-07-27T04:23:54.157Z,1627359834.157 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2021-07-27T04:23:54.228Z,1627359834.228 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2021-07-27T04:23:54.232Z,1627359834.232 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2021-07-27T04:23:54.271Z,1627359834.271 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2021-07-27T04:23:54.348Z,1627359834.348 [logger ThreadHandler](INFO): Thread cancelled.