2021-07-26T18:51:44.428Z,1627325504.428 [CommandLine](IMPORTANT): got command restart logs 2021-07-26T18:55:45.500Z,1627325745.500 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-07-26T18:50:45.3Z 2021-07-26T18:55:45.500Z,1627325745.500 [Default:CheckIn:Read_GPS] Stopped 2021-07-26T18:55:45.500Z,1627325745.500 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-26T18:55:49.876Z,1627325749.876 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20210726T180946/Courier0015.lzma 2021-07-26T18:55:50.881Z,1627325750.881 [DataOverHttps](INFO): Moved sent file to Logs/20210726T180946/Courier0015.lzma.bak 2021-07-26T18:55:50.881Z,1627325750.881 [DataOverHttps](INFO): SBD MOMSN=15761940 2021-07-26T18:56:07.791Z,1627325767.791 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20210726T185144/Courier0000.lzma 2021-07-26T18:56:08.793Z,1627325768.793 [DataOverHttps](INFO): Moved sent file to Logs/20210726T185144/Courier0000.lzma.bak 2021-07-26T18:56:08.793Z,1627325768.793 [DataOverHttps](INFO): SBD MOMSN=15761942 2021-07-26T18:56:31.753Z,1627325791.753 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-26T18:56:35.532Z,1627325795.532 [DataOverHttps](INFO): Sending 254 bytes from file Logs/20210726T180946/Express0016.lzma 2021-07-26T18:56:36.533Z,1627325796.533 [DataOverHttps](INFO): Moved sent file to Logs/20210726T180946/Express0016.lzma.bak 2021-07-26T18:56:36.533Z,1627325796.533 [DataOverHttps](INFO): SBD MOMSN=15761945 2021-07-26T18:56:54.739Z,1627325814.739 [DataOverHttps](INFO): Sending 312 bytes from file Logs/20210726T185144/Express0001.lzma 2021-07-26T18:56:55.741Z,1627325815.741 [DataOverHttps](INFO): Moved sent file to Logs/20210726T185144/Express0001.lzma.bak 2021-07-26T18:56:55.741Z,1627325815.741 [DataOverHttps](INFO): SBD MOMSN=15761951 2021-07-26T18:57:02.476Z,1627325822.476 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-26T18:57:18.407Z,1627325838.407 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20210726T185144/Express0004.lzma 2021-07-26T18:57:19.410Z,1627325839.410 [DataOverHttps](INFO): Moved sent file to Logs/20210726T185144/Express0004.lzma.bak 2021-07-26T18:57:19.410Z,1627325839.410 [DataOverHttps](INFO): SBD MOMSN=15761954 2021-07-26T18:57:22.695Z,1627325842.695 [Default:CheckIn:Read_Iridium] Stopped 2021-07-26T18:57:22.695Z,1627325842.695 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-26T18:57:22.696Z,1627325842.696 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-26T19:02:23.287Z,1627326143.287 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-26T19:02:23.287Z,1627326143.287 [Default:CheckIn:C.Wait] Stopped 2021-07-26T19:02:23.287Z,1627326143.287 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-26T19:02:23.288Z,1627326143.288 [Default:CheckIn:D] Running Loop=1 2021-07-26T19:02:23.693Z,1627326143.693 [Default:CheckIn:D] Stopped 2021-07-26T19:02:23.693Z,1627326143.693 [Default:CheckIn:E] Running Loop=1 2021-07-26T19:02:24.125Z,1627326144.125 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 23.091522 min 2021-07-26T19:02:24.126Z,1627326144.126 [Default:CheckIn:E] Stopped 2021-07-26T19:02:24.126Z,1627326144.126 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-26T19:02:24.126Z,1627326144.126 [Default:CheckIn] Stopped 2021-07-26T19:02:24.126Z,1627326144.126 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-26T19:02:24.126Z,1627326144.126 [Default:CheckIn](INFO): Running loop #3 2021-07-26T19:02:24.126Z,1627326144.126 [Default:CheckIn] Running Loop=3 2021-07-26T19:02:24.126Z,1627326144.126 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-26T19:02:24.127Z,1627326144.127 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-26T19:02:25.701Z,1627326145.701 [NAL9602](FAULT): GPS failed to acquire within timeout. 2021-07-26T19:02:25.701Z,1627326145.701 [NAL9602] Data Fault, FailCount= 2 2021-07-26T19:02:25.701Z,1627326145.701 [NAL9602](ERROR): Data Fault 2021-07-26T19:02:25.766Z,1627326145.766 [CBIT](ERROR): Data Fault in component: NAL9602 2021-07-26T19:02:26.104Z,1627326146.104 [NAL9602](INFO): Powering down 2021-07-26T19:02:26.985Z,1627326146.985 [CBIT](INFO): Clearing failed state for component NAL9602 2021-07-26T19:02:26.985Z,1627326146.985 [NAL9602] No Fault, FailCount= 2 2021-07-26T19:02:56.413Z,1627326176.413 [NAL9602](INFO): Powering up NAL9602 2021-07-26T19:03:07.317Z,1627326187.317 [NAL9602](INFO): NAL9602 initialized 2021-07-26T19:07:24.302Z,1627326444.302 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-07-26T19:02:24.1Z 2021-07-26T19:07:24.302Z,1627326444.302 [Default:CheckIn:Read_GPS] Stopped 2021-07-26T19:07:24.302Z,1627326444.302 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-26T19:07:33.087Z,1627326453.087 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20210726T185144/Courier0006.lzma 2021-07-26T19:07:35.093Z,1627326455.093 [DataOverHttps](INFO): Moved sent file to Logs/20210726T185144/Courier0006.lzma.bak 2021-07-26T19:07:35.093Z,1627326455.093 [DataOverHttps](INFO): SBD MOMSN=15761956 2021-07-26T19:07:56.575Z,1627326476.575 [DataOverHttps](INFO): Sending 267 bytes from file Logs/20210726T185144/Express0007.lzma 2021-07-26T19:07:57.577Z,1627326477.577 [DataOverHttps](INFO): Moved sent file to Logs/20210726T185144/Express0007.lzma.bak 2021-07-26T19:07:57.577Z,1627326477.577 [DataOverHttps](INFO): SBD MOMSN=15761958 2021-07-26T19:08:01.497Z,1627326481.497 [Default:CheckIn:Read_Iridium] Stopped 2021-07-26T19:08:01.497Z,1627326481.497 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-26T19:08:01.497Z,1627326481.497 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-26T19:08:10.747Z,1627326490.747 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-26T19:08:41.455Z,1627326521.455 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-26T19:13:02.203Z,1627326782.203 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-26T19:13:02.203Z,1627326782.203 [Default:CheckIn:C.Wait] Stopped 2021-07-26T19:13:02.203Z,1627326782.203 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-26T19:13:02.203Z,1627326782.203 [Default:CheckIn:D] Running Loop=1 2021-07-26T19:13:02.588Z,1627326782.588 [Default:CheckIn:D] Stopped 2021-07-26T19:13:02.588Z,1627326782.588 [Default:CheckIn:E] Running Loop=1 2021-07-26T19:13:02.987Z,1627326782.987 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 33.739783 min 2021-07-26T19:13:02.987Z,1627326782.987 [Default:CheckIn:E] Stopped 2021-07-26T19:13:02.987Z,1627326782.987 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-26T19:13:02.988Z,1627326782.988 [Default:CheckIn] Stopped 2021-07-26T19:13:02.988Z,1627326782.988 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-26T19:13:02.988Z,1627326782.988 [Default:CheckIn](INFO): Running loop #4 2021-07-26T19:13:02.988Z,1627326782.988 [Default:CheckIn] Running Loop=4 2021-07-26T19:13:02.988Z,1627326782.988 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-26T19:13:02.988Z,1627326782.988 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-26T19:13:05.014Z,1627326785.014 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191303.00,A,3648.16305,N,12147.27791,W,1.205,171.03,260721,,,A*74 2021-07-26T19:13:05.017Z,1627326785.017 [NAL9602](INFO): GPS fix at 20210726T191303: (36.802717, -121.787965) 2021-07-26T19:13:05.030Z,1627326785.030 [Default:CheckIn:Read_GPS] Stopped 2021-07-26T19:13:05.030Z,1627326785.030 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-26T19:13:14.280Z,1627326794.280 [DataOverHttps](INFO): Sending 221 bytes from file Logs/20210726T185144/Courier0009.lzma 2021-07-26T19:13:15.281Z,1627326795.281 [DataOverHttps](INFO): Moved sent file to Logs/20210726T185144/Courier0009.lzma.bak 2021-07-26T19:13:15.281Z,1627326795.281 [DataOverHttps](INFO): SBD MOMSN=15761963 2021-07-26T19:13:34.755Z,1627326814.755 [DataOverHttps](INFO): Sending 217 bytes from file Logs/20210726T185144/Express0010.lzma 2021-07-26T19:13:35.709Z,1627326815.709 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-07-26T19:13:35.753Z,1627326815.753 [DataOverHttps](INFO): Moved sent file to Logs/20210726T185144/Express0010.lzma.bak 2021-07-26T19:13:35.753Z,1627326815.753 [DataOverHttps](INFO): SBD MOMSN=15761966 2021-07-26T19:13:35.791Z,1627326815.791 [NAL9602](ERROR): received: +CSQ:0 OK517, 2, 0, 0, 0 OK 2021-07-26T19:13:39.080Z,1627326819.080 [Default:CheckIn:Read_Iridium] Stopped 2021-07-26T19:13:39.080Z,1627326819.080 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-26T19:13:39.080Z,1627326819.080 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-26T19:15:14.395Z,1627326914.395 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2021-07-26T19:15:14.398Z,1627326914.398 [BPC1](INFO): Received data from all battery sticks. 2021-07-26T19:18:07.353Z,1627327087.353 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-26T19:18:38.100Z,1627327118.100 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-26T19:18:39.726Z,1627327119.726 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-26T19:18:39.727Z,1627327119.727 [Default:CheckIn:C.Wait] Stopped 2021-07-26T19:18:39.727Z,1627327119.727 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-26T19:18:39.727Z,1627327119.727 [Default:CheckIn:D] Running Loop=1 2021-07-26T19:18:40.129Z,1627327120.129 [Default:CheckIn:D] Stopped 2021-07-26T19:18:40.129Z,1627327120.129 [Default:CheckIn:E] Running Loop=1 2021-07-26T19:18:40.558Z,1627327120.558 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 39.365458 min 2021-07-26T19:18:40.558Z,1627327120.558 [Default:CheckIn:E] Stopped 2021-07-26T19:18:40.558Z,1627327120.558 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-26T19:18:40.558Z,1627327120.558 [Default:CheckIn] Stopped 2021-07-26T19:18:40.558Z,1627327120.558 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-26T19:18:40.559Z,1627327120.559 [Default:CheckIn](INFO): Running loop #5 2021-07-26T19:18:40.559Z,1627327120.559 [Default:CheckIn] Running Loop=5 2021-07-26T19:18:40.559Z,1627327120.559 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-26T19:18:40.559Z,1627327120.559 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-26T19:18:42.542Z,1627327122.542 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191841.00,A,3648.16506,N,12147.28327,W,0.272,171.03,260721,,,A*7B 2021-07-26T19:18:42.544Z,1627327122.544 [NAL9602](INFO): GPS fix at 20210726T191841: (36.802751, -121.788055) 2021-07-26T19:18:42.555Z,1627327122.555 [Default:CheckIn:Read_GPS] Stopped 2021-07-26T19:18:42.555Z,1627327122.555 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-26T19:18:53.331Z,1627327133.331 [DataOverHttps](INFO): Sending 203 bytes from file Logs/20210726T185144/Courier0012.lzma 2021-07-26T19:18:54.333Z,1627327134.333 [DataOverHttps](INFO): Moved sent file to Logs/20210726T185144/Courier0012.lzma.bak 2021-07-26T19:18:54.333Z,1627327134.333 [DataOverHttps](INFO): SBD MOMSN=15761970 2021-07-26T19:19:12.583Z,1627327152.583 [DataOverHttps](INFO): Sending 204 bytes from file Logs/20210726T185144/Express0013.lzma 2021-07-26T19:19:13.252Z,1627327153.252 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-07-26T19:19:13.335Z,1627327153.335 [NAL9602](ERROR): received: +CSQ:0 OK517, 2, 0, 0, 0 OK 2021-07-26T19:19:13.585Z,1627327153.585 [DataOverHttps](INFO): Moved sent file to Logs/20210726T185144/Express0013.lzma.bak 2021-07-26T19:19:13.585Z,1627327153.585 [DataOverHttps](INFO): SBD MOMSN=15761973 2021-07-26T19:19:17.345Z,1627327157.345 [Default:CheckIn:Read_Iridium] Stopped 2021-07-26T19:19:17.346Z,1627327157.346 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-26T19:19:17.346Z,1627327157.346 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-26T19:21:28.278Z,1627327288.278 [NAL9602](INFO): SBD MO Status=2, MOMSN=28517, MT Status=2, MTMSN=0 2021-07-26T19:21:28.278Z,1627327288.278 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-26T19:23:30.714Z,1627327410.714 [NAL9602](INFO): SBD MO Status=2, MOMSN=28517, MT Status=2, MTMSN=0 2021-07-26T19:23:30.714Z,1627327410.714 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-26T19:23:44.449Z,1627327424.449 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-26T19:24:15.153Z,1627327455.153 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-26T19:24:17.995Z,1627327457.995 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-26T19:24:17.995Z,1627327457.995 [Default:CheckIn:C.Wait] Stopped 2021-07-26T19:24:17.995Z,1627327457.995 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-26T19:24:17.995Z,1627327457.995 [Default:CheckIn:D] Running Loop=1 2021-07-26T19:24:18.399Z,1627327458.399 [Default:CheckIn:D] Stopped 2021-07-26T19:24:18.399Z,1627327458.399 [Default:CheckIn:E] Running Loop=1 2021-07-26T19:24:18.811Z,1627327458.811 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 45.003296 min 2021-07-26T19:24:18.811Z,1627327458.811 [Default:CheckIn:E] Stopped 2021-07-26T19:24:18.811Z,1627327458.811 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-26T19:24:18.815Z,1627327458.815 [Default:CheckIn] Stopped 2021-07-26T19:24:18.815Z,1627327458.815 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-26T19:24:18.816Z,1627327458.816 [Default:CheckIn](INFO): Running loop #6 2021-07-26T19:24:18.816Z,1627327458.816 [Default:CheckIn] Running Loop=6 2021-07-26T19:24:18.816Z,1627327458.816 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-26T19:24:18.816Z,1627327458.816 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-26T19:24:20.875Z,1627327460.875 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,192420.00,A,3648.17125,N,12147.28125,W,0.389,171.03,260721,,,A*72 2021-07-26T19:24:20.877Z,1627327460.877 [NAL9602](INFO): GPS fix at 20210726T192420: (36.802854, -121.788021) 2021-07-26T19:24:20.922Z,1627327460.922 [Default:CheckIn:Read_GPS] Stopped 2021-07-26T19:24:20.923Z,1627327460.923 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-26T19:24:33.503Z,1627327473.503 [DataOverHttps](INFO): Sending 70 bytes from file Logs/20210726T185144/Courier0015.lzma 2021-07-26T19:24:34.507Z,1627327474.507 [DataOverHttps](INFO): Moved sent file to Logs/20210726T185144/Courier0015.lzma.bak 2021-07-26T19:24:34.507Z,1627327474.507 [DataOverHttps](INFO): SBD MOMSN=15761977 2021-07-26T19:24:51.617Z,1627327491.617 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-07-26T19:24:51.691Z,1627327491.691 [NAL9602](ERROR): received: +CSQ:0 OK517, 2, 0, 0, 0 OK 2021-07-26T19:24:55.291Z,1627327495.291 [DataOverHttps](INFO): Sending 202 bytes from file Logs/20210726T185144/Express0016.lzma 2021-07-26T19:24:56.293Z,1627327496.293 [DataOverHttps](INFO): Moved sent file to Logs/20210726T185144/Express0016.lzma.bak 2021-07-26T19:24:56.293Z,1627327496.293 [DataOverHttps](INFO): SBD MOMSN=15761980 2021-07-26T19:24:59.732Z,1627327499.732 [Default:CheckIn:Read_Iridium] Stopped 2021-07-26T19:24:59.732Z,1627327499.732 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-26T19:24:59.732Z,1627327499.732 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-26T19:29:23.553Z,1627327763.553 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-26T19:29:54.256Z,1627327794.256 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-26T19:30:00.338Z,1627327800.338 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-26T19:30:00.338Z,1627327800.338 [Default:CheckIn:C.Wait] Stopped 2021-07-26T19:30:00.338Z,1627327800.338 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-26T19:30:00.339Z,1627327800.339 [Default:CheckIn:D] Running Loop=1 2021-07-26T19:30:00.735Z,1627327800.735 [Default:CheckIn:D] Stopped 2021-07-26T19:30:00.735Z,1627327800.735 [Default:CheckIn:E] Running Loop=1 2021-07-26T19:30:01.149Z,1627327801.149 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 50.708891 min 2021-07-26T19:30:01.149Z,1627327801.149 [Default:CheckIn:E] Stopped 2021-07-26T19:30:01.149Z,1627327801.149 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-26T19:30:01.149Z,1627327801.149 [Default:CheckIn] Stopped 2021-07-26T19:30:01.149Z,1627327801.149 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-26T19:30:01.149Z,1627327801.149 [Default:CheckIn](INFO): Running loop #7 2021-07-26T19:30:01.149Z,1627327801.149 [Default:CheckIn] Running Loop=7 2021-07-26T19:30:01.149Z,1627327801.149 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-26T19:30:01.150Z,1627327801.150 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-26T19:30:03.148Z,1627327803.148 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,193002.00,A,3648.16660,N,12147.28512,W,0.389,0.00,260721,,,A*74 2021-07-26T19:30:03.150Z,1627327803.150 [NAL9602](INFO): GPS fix at 20210726T193002: (36.802777, -121.788085) 2021-07-26T19:30:03.162Z,1627327803.162 [Default:CheckIn:Read_GPS] Stopped 2021-07-26T19:30:03.162Z,1627327803.162 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-26T19:30:11.663Z,1627327811.663 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210726T185144/Courier0018.lzma 2021-07-26T19:30:12.665Z,1627327812.665 [DataOverHttps](INFO): Moved sent file to Logs/20210726T185144/Courier0018.lzma.bak 2021-07-26T19:30:12.665Z,1627327812.665 [DataOverHttps](INFO): SBD MOMSN=15761984 2021-07-26T19:30:33.573Z,1627327833.573 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-07-26T19:30:33.651Z,1627327833.651 [NAL9602](ERROR): received: +CSQ:0 OK517, 2, 0, 0, 0 OK 2021-07-26T19:30:37.317Z,1627327837.317 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20210726T185144/Express0019.lzma 2021-07-26T19:30:37.701Z,1627327837.701 [DataOverHttps](INFO): Moved sent file to Logs/20210726T185144/Express0019.lzma.bak 2021-07-26T19:30:37.701Z,1627327837.701 [DataOverHttps](INFO): SBD MOMSN=15761987 2021-07-26T19:30:43.741Z,1627327843.741 [Default:CheckIn:Read_Iridium] Stopped 2021-07-26T19:30:43.742Z,1627327843.742 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-26T19:30:43.742Z,1627327843.742 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-26T19:31:49.978Z,1627327909.978 [NAL9602](INFO): SBD MO Status=2, MOMSN=28517, MT Status=2, MTMSN=0 2021-07-26T19:31:49.978Z,1627327909.978 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-26T19:33:22.166Z,1627328002.166 [NAL9602](INFO): SBD MO Status=2, MOMSN=28517, MT Status=2, MTMSN=0 2021-07-26T19:33:22.166Z,1627328002.166 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-26T19:35:05.250Z,1627328105.250 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-26T19:35:35.958Z,1627328135.958 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-26T19:35:44.460Z,1627328144.460 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-26T19:35:44.460Z,1627328144.460 [Default:CheckIn:C.Wait] Stopped 2021-07-26T19:35:44.460Z,1627328144.460 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-26T19:35:44.460Z,1627328144.460 [Default:CheckIn:D] Running Loop=1 2021-07-26T19:35:44.855Z,1627328144.855 [Default:CheckIn:D] Stopped 2021-07-26T19:35:44.855Z,1627328144.855 [Default:CheckIn:E] Running Loop=1 2021-07-26T19:35:45.259Z,1627328145.259 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 56.444226 min 2021-07-26T19:35:45.259Z,1627328145.259 [Default:CheckIn:E] Stopped 2021-07-26T19:35:45.260Z,1627328145.260 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-26T19:35:45.260Z,1627328145.260 [Default:CheckIn] Stopped 2021-07-26T19:35:45.260Z,1627328145.260 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-26T19:35:45.260Z,1627328145.260 [Default:CheckIn](INFO): Running loop #8 2021-07-26T19:35:45.260Z,1627328145.260 [Default:CheckIn] Running Loop=8 2021-07-26T19:35:45.260Z,1627328145.260 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-26T19:35:45.260Z,1627328145.260 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-26T19:35:47.274Z,1627328147.274 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,193546.00,A,3648.16631,N,12147.28353,W,0.603,0.00,260721,,,A*71 2021-07-26T19:35:47.276Z,1627328147.276 [NAL9602](INFO): GPS fix at 20210726T193546: (36.802772, -121.788059) 2021-07-26T19:35:47.287Z,1627328147.287 [Default:CheckIn:Read_GPS] Stopped 2021-07-26T19:35:47.287Z,1627328147.287 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-26T19:35:55.835Z,1627328155.835 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210726T185144/Courier0021.lzma 2021-07-26T19:35:56.837Z,1627328156.837 [DataOverHttps](INFO): Moved sent file to Logs/20210726T185144/Courier0021.lzma.bak 2021-07-26T19:35:56.837Z,1627328156.837 [DataOverHttps](INFO): SBD MOMSN=15761991 2021-07-26T19:36:16.127Z,1627328176.127 [DataOverHttps](INFO): Sending 204 bytes from file Logs/20210726T185144/Express0022.lzma 2021-07-26T19:36:17.129Z,1627328177.129 [DataOverHttps](INFO): Moved sent file to Logs/20210726T185144/Express0022.lzma.bak 2021-07-26T19:36:17.129Z,1627328177.129 [DataOverHttps](INFO): SBD MOMSN=15761994 2021-07-26T19:36:17.997Z,1627328177.997 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-07-26T19:36:18.072Z,1627328178.072 [NAL9602](ERROR): received: +CSQ:0 OK517, 2, 0, 0, 0 OK 2021-07-26T19:36:22.984Z,1627328182.984 [Default:CheckIn:Read_Iridium] Stopped 2021-07-26T19:36:22.984Z,1627328182.984 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-26T19:36:22.985Z,1627328182.985 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-26T19:38:17.718Z,1627328297.718 [NAL9602](INFO): SBD MO Status=2, MOMSN=28517, MT Status=2, MTMSN=0 2021-07-26T19:38:17.718Z,1627328297.718 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-26T19:39:52.666Z,1627328392.666 [NAL9602](INFO): SBD MO Status=2, MOMSN=28517, MT Status=2, MTMSN=0 2021-07-26T19:39:52.666Z,1627328392.666 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-26T19:40:11.654Z,1627328411.654 [NAL9602](INFO): SBD MO Status=2, MOMSN=28517, MT Status=2, MTMSN=0 2021-07-26T19:40:11.654Z,1627328411.654 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-26T19:40:54.878Z,1627328454.878 [NAL9602](INFO): SBD MO Status=2, MOMSN=28517, MT Status=2, MTMSN=0 2021-07-26T19:40:54.878Z,1627328454.878 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-26T19:40:55.289Z,1627328455.289 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-26T19:41:23.571Z,1627328483.571 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-26T19:41:23.571Z,1627328483.571 [Default:CheckIn:C.Wait] Stopped 2021-07-26T19:41:23.571Z,1627328483.571 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-26T19:41:23.572Z,1627328483.572 [Default:CheckIn:D] Running Loop=1 2021-07-26T19:41:23.980Z,1627328483.980 [Default:CheckIn:D] Stopped 2021-07-26T19:41:23.980Z,1627328483.980 [Default:CheckIn:E] Running Loop=1 2021-07-26T19:41:24.393Z,1627328484.393 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 62.096318 min 2021-07-26T19:41:24.393Z,1627328484.393 [Default:CheckIn:E] Stopped 2021-07-26T19:41:24.393Z,1627328484.393 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-26T19:41:24.393Z,1627328484.393 [Default:CheckIn] Stopped 2021-07-26T19:41:24.393Z,1627328484.393 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-26T19:41:24.394Z,1627328484.394 [Default:CheckIn](INFO): Running loop #9 2021-07-26T19:41:24.394Z,1627328484.394 [Default:CheckIn] Running Loop=9 2021-07-26T19:41:24.394Z,1627328484.394 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-26T19:41:24.394Z,1627328484.394 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-26T19:41:26.393Z,1627328486.393 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194125.00,A,3648.16768,N,12147.28293,W,0.603,0.00,260721,,,A*77 2021-07-26T19:41:26.408Z,1627328486.408 [NAL9602](INFO): GPS fix at 20210726T194125: (36.802795, -121.788049) 2021-07-26T19:41:26.418Z,1627328486.418 [Default:CheckIn:Read_GPS] Stopped 2021-07-26T19:41:26.419Z,1627328486.419 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-26T19:41:35.183Z,1627328495.183 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210726T185144/Courier0024.lzma 2021-07-26T19:41:36.185Z,1627328496.185 [DataOverHttps](INFO): Moved sent file to Logs/20210726T185144/Courier0024.lzma.bak 2021-07-26T19:41:36.185Z,1627328496.185 [DataOverHttps](INFO): SBD MOMSN=15761998 2021-07-26T19:41:55.475Z,1627328515.475 [DataOverHttps](INFO): Sending 205 bytes from file Logs/20210726T185144/Express0025.lzma 2021-07-26T19:41:56.477Z,1627328516.477 [DataOverHttps](INFO): Moved sent file to Logs/20210726T185144/Express0025.lzma.bak 2021-07-26T19:41:56.477Z,1627328516.477 [DataOverHttps](INFO): SBD MOMSN=15762001 2021-07-26T19:41:58.336Z,1627328518.336 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-26T19:41:59.589Z,1627328519.589 [Default:CheckIn:Read_Iridium] Stopped 2021-07-26T19:41:59.589Z,1627328519.589 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-26T19:41:59.589Z,1627328519.589 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-26T19:47:00.190Z,1627328820.190 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-26T19:47:00.190Z,1627328820.190 [Default:CheckIn:C.Wait] Stopped 2021-07-26T19:47:00.190Z,1627328820.190 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-26T19:47:00.191Z,1627328820.191 [Default:CheckIn:D] Running Loop=1 2021-07-26T19:47:00.592Z,1627328820.592 [Default:CheckIn:D] Stopped 2021-07-26T19:47:00.592Z,1627328820.592 [Default:CheckIn:E] Running Loop=1 2021-07-26T19:47:01.008Z,1627328821.008 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 67.706514 min 2021-07-26T19:47:01.008Z,1627328821.008 [Default:CheckIn:E] Stopped 2021-07-26T19:47:01.009Z,1627328821.009 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-26T19:47:01.009Z,1627328821.009 [Default:CheckIn] Stopped 2021-07-26T19:47:01.009Z,1627328821.009 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-26T19:47:01.009Z,1627328821.009 [Default:CheckIn](INFO): Running loop #10 2021-07-26T19:47:01.009Z,1627328821.009 [Default:CheckIn] Running Loop=10 2021-07-26T19:47:01.009Z,1627328821.009 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-26T19:47:01.009Z,1627328821.009 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-26T19:47:03.010Z,1627328823.010 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194702.00,A,3648.16743,N,12147.28553,W,0.117,0.00,260721,,,A*74 2021-07-26T19:47:03.013Z,1627328823.013 [NAL9602](INFO): GPS fix at 20210726T194702: (36.802791, -121.788092) 2021-07-26T19:47:03.024Z,1627328823.024 [Default:CheckIn:Read_GPS] Stopped 2021-07-26T19:47:03.024Z,1627328823.024 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-26T19:47:11.468Z,1627328831.468 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210726T185144/Courier0027.lzma 2021-07-26T19:47:12.469Z,1627328832.469 [DataOverHttps](INFO): Moved sent file to Logs/20210726T185144/Courier0027.lzma.bak 2021-07-26T19:47:12.469Z,1627328832.469 [DataOverHttps](INFO): SBD MOMSN=15762005 2021-07-26T19:47:30.503Z,1627328850.503 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20210726T185144/Express0028.lzma 2021-07-26T19:47:32.571Z,1627328852.571 [DataOverHttps](INFO): Moved sent file to Logs/20210726T185144/Express0028.lzma.bak 2021-07-26T19:47:32.572Z,1627328852.572 [DataOverHttps](INFO): SBD MOMSN=15762008 2021-07-26T19:47:34.981Z,1627328854.981 [Default:CheckIn:Read_Iridium] Stopped 2021-07-26T19:47:34.981Z,1627328854.981 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-26T19:47:34.981Z,1627328854.981 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-26T19:48:19.794Z,1627328899.794 [NAL9602](INFO): SBD MO Status=2, MOMSN=28517, MT Status=2, MTMSN=0 2021-07-26T19:48:19.794Z,1627328899.794 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-26T19:49:07.902Z,1627328947.902 [NAL9602](INFO): SBD MO Status=2, MOMSN=28517, MT Status=2, MTMSN=0 2021-07-26T19:49:07.902Z,1627328947.902 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-26T19:49:18.009Z,1627328958.009 [NAL9602](INFO): SBD MO Status=0, MOMSN=28517, MT Status=0, MTMSN=0 2021-07-26T19:49:18.009Z,1627328958.009 [NAL9602](INFO): No messages in MT queue 2021-07-26T19:49:48.704Z,1627328988.704 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-26T19:52:35.695Z,1627329155.695 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-26T19:52:35.696Z,1627329155.696 [Default:CheckIn:C.Wait] Stopped 2021-07-26T19:52:35.696Z,1627329155.696 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-26T19:52:35.696Z,1627329155.696 [Default:CheckIn:D] Running Loop=1 2021-07-26T19:52:36.093Z,1627329156.093 [Default:CheckIn:D] Stopped 2021-07-26T19:52:36.093Z,1627329156.093 [Default:CheckIn:E] Running Loop=1 2021-07-26T19:52:36.508Z,1627329156.508 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 73.298201 min 2021-07-26T19:52:36.508Z,1627329156.508 [Default:CheckIn:E] Stopped 2021-07-26T19:52:36.508Z,1627329156.508 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-26T19:52:36.508Z,1627329156.508 [Default:CheckIn] Stopped 2021-07-26T19:52:36.508Z,1627329156.508 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-26T19:52:36.508Z,1627329156.508 [Default:CheckIn](INFO): Running loop #11 2021-07-26T19:52:36.509Z,1627329156.509 [Default:CheckIn] Running Loop=11 2021-07-26T19:52:36.509Z,1627329156.509 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-26T19:52:36.509Z,1627329156.509 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-26T19:52:38.507Z,1627329158.507 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,195237.00,A,3648.16618,N,12147.28242,W,0.253,165.89,260721,,,D*7B 2021-07-26T19:52:38.509Z,1627329158.509 [NAL9602](INFO): GPS fix at 20210726T195237: (36.802770, -121.788040) 2021-07-26T19:52:38.584Z,1627329158.584 [Default:CheckIn:Read_GPS] Stopped 2021-07-26T19:52:38.584Z,1627329158.584 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-26T19:52:47.483Z,1627329167.483 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210726T185144/Courier0030.lzma 2021-07-26T19:52:48.485Z,1627329168.485 [DataOverHttps](INFO): Moved sent file to Logs/20210726T185144/Courier0030.lzma.bak 2021-07-26T19:52:48.485Z,1627329168.485 [DataOverHttps](INFO): SBD MOMSN=15762012 2021-07-26T19:53:06.615Z,1627329186.615 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20210726T185144/Express0031.lzma 2021-07-26T19:53:07.617Z,1627329187.617 [DataOverHttps](INFO): Moved sent file to Logs/20210726T185144/Express0031.lzma.bak 2021-07-26T19:53:07.617Z,1627329187.617 [DataOverHttps](INFO): SBD MOMSN=15762015 2021-07-26T19:53:10.819Z,1627329190.819 [Default:CheckIn:Read_Iridium] Stopped 2021-07-26T19:53:10.819Z,1627329190.819 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-26T19:53:10.820Z,1627329190.820 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-26T19:55:50.806Z,1627329350.806 [NAL9602](INFO): SBD MO Status=2, MOMSN=28518, MT Status=2, MTMSN=0 2021-07-26T19:55:50.807Z,1627329350.807 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-26T19:56:49.045Z,1627329409.045 [NAL9602](INFO): SBD MO Status=2, MOMSN=28518, MT Status=2, MTMSN=0 2021-07-26T19:56:49.045Z,1627329409.045 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-26T19:57:02.370Z,1627329422.370 [NAL9602](INFO): SBD MO Status=2, MOMSN=28518, MT Status=2, MTMSN=0 2021-07-26T19:57:02.370Z,1627329422.370 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-26T19:57:40.352Z,1627329460.352 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-26T19:58:11.055Z,1627329491.055 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-26T19:58:11.481Z,1627329491.481 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-26T19:58:11.481Z,1627329491.481 [Default:CheckIn:C.Wait] Stopped 2021-07-26T19:58:11.481Z,1627329491.481 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-26T19:58:11.481Z,1627329491.481 [Default:CheckIn:D] Running Loop=1 2021-07-26T19:58:11.870Z,1627329491.870 [Default:CheckIn:D] Stopped 2021-07-26T19:58:11.870Z,1627329491.870 [Default:CheckIn:E] Running Loop=1 2021-07-26T19:58:12.278Z,1627329492.278 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 78.894482 min 2021-07-26T19:58:12.278Z,1627329492.278 [Default:CheckIn:E] Stopped 2021-07-26T19:58:12.278Z,1627329492.278 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-26T19:58:12.278Z,1627329492.278 [Default:CheckIn] Stopped 2021-07-26T19:58:12.278Z,1627329492.278 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-26T19:58:12.279Z,1627329492.279 [Default:CheckIn](INFO): Running loop #12 2021-07-26T19:58:12.279Z,1627329492.279 [Default:CheckIn] Running Loop=12 2021-07-26T19:58:12.279Z,1627329492.279 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-26T19:58:12.279Z,1627329492.279 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-26T19:58:14.288Z,1627329494.288 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,195813.00,A,3648.16639,N,12147.28168,W,0.272,303.63,260721,,,D*7A 2021-07-26T19:58:14.290Z,1627329494.290 [NAL9602](INFO): GPS fix at 20210726T195813: (36.802773, -121.788028) 2021-07-26T19:58:14.301Z,1627329494.301 [Default:CheckIn:Read_GPS] Stopped 2021-07-26T19:58:14.301Z,1627329494.301 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-26T19:58:28.012Z,1627329508.012 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210726T185144/Courier0033.lzma 2021-07-26T19:58:29.013Z,1627329509.013 [DataOverHttps](INFO): Moved sent file to Logs/20210726T185144/Courier0033.lzma.bak 2021-07-26T19:58:29.013Z,1627329509.013 [DataOverHttps](INFO): SBD MOMSN=15762018 2021-07-26T19:58:44.725Z,1627329524.725 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-07-26T19:58:44.799Z,1627329524.799 [NAL9602](ERROR): received: +CSQ:0 OK518, 2, 0, 0, 0 OK 2021-07-26T19:58:52.552Z,1627329532.552 [DataOverHttps](INFO): Sending 205 bytes from file Logs/20210726T185144/Express0034.lzma 2021-07-26T19:58:53.545Z,1627329533.545 [DataOverHttps](INFO): Moved sent file to Logs/20210726T185144/Express0034.lzma.bak 2021-07-26T19:58:53.545Z,1627329533.545 [DataOverHttps](INFO): SBD MOMSN=15762021 2021-07-26T19:58:56.913Z,1627329536.913 [Default:CheckIn:Read_Iridium] Stopped 2021-07-26T19:58:56.914Z,1627329536.914 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-26T19:58:56.914Z,1627329536.914 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-26T20:03:16.631Z,1627329796.631 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-26T20:03:47.331Z,1627329827.331 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-26T20:03:57.449Z,1627329837.449 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-26T20:03:57.449Z,1627329837.449 [Default:CheckIn:C.Wait] Stopped 2021-07-26T20:03:57.449Z,1627329837.449 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-26T20:03:57.450Z,1627329837.450 [Default:CheckIn:D] Running Loop=1 2021-07-26T20:03:57.843Z,1627329837.843 [Default:CheckIn:D] Stopped 2021-07-26T20:03:57.843Z,1627329837.843 [Default:CheckIn:E] Running Loop=1 2021-07-26T20:03:58.247Z,1627329838.247 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 84.660693 min 2021-07-26T20:03:58.247Z,1627329838.247 [Default:CheckIn:E] Stopped 2021-07-26T20:03:58.247Z,1627329838.247 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-26T20:03:58.247Z,1627329838.247 [Default:CheckIn] Stopped 2021-07-26T20:03:58.247Z,1627329838.247 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-26T20:03:58.247Z,1627329838.247 [Default:CheckIn](INFO): Running loop #13 2021-07-26T20:03:58.248Z,1627329838.248 [Default:CheckIn] Running Loop=13 2021-07-26T20:03:58.248Z,1627329838.248 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-26T20:03:58.248Z,1627329838.248 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-26T20:04:00.263Z,1627329840.263 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200359.00,A,3648.16457,N,12147.28857,W,0.408,303.63,260721,,,A*71 2021-07-26T20:04:00.265Z,1627329840.265 [NAL9602](INFO): GPS fix at 20210726T200359: (36.802743, -121.788143) 2021-07-26T20:04:00.277Z,1627329840.277 [Default:CheckIn:Read_GPS] Stopped 2021-07-26T20:04:00.277Z,1627329840.277 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-26T20:04:08.935Z,1627329848.935 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210726T185144/Courier0036.lzma 2021-07-26T20:04:09.937Z,1627329849.937 [DataOverHttps](INFO): Moved sent file to Logs/20210726T185144/Courier0036.lzma.bak 2021-07-26T20:04:09.937Z,1627329849.937 [DataOverHttps](INFO): SBD MOMSN=15762025 2021-07-26T20:04:30.677Z,1627329870.677 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-07-26T20:04:30.760Z,1627329870.760 [NAL9602](ERROR): received: +CSQ:0 OK518, 2, 0, 0, 0 OK 2021-07-26T20:04:33.267Z,1627329873.267 [DataOverHttps](INFO): Sending 208 bytes from file Logs/20210726T185144/Express0037.lzma 2021-07-26T20:04:34.269Z,1627329874.269 [DataOverHttps](INFO): Moved sent file to Logs/20210726T185144/Express0037.lzma.bak 2021-07-26T20:04:34.270Z,1627329874.270 [DataOverHttps](INFO): SBD MOMSN=15762028 2021-07-26T20:04:39.686Z,1627329879.686 [Default:CheckIn:Read_Iridium] Stopped 2021-07-26T20:04:39.687Z,1627329879.687 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-26T20:04:39.687Z,1627329879.687 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-26T20:05:31.912Z,1627329931.912 [DataOverHttps](IMPORTANT): SBD MTMSN=20210726T200530 2021-07-26T20:05:39.351Z,1627329939.351 [DataOverHttps](INFO): Received command:restart app 2021-07-26T20:05:39.440Z,1627329939.440 [CommandLine](IMPORTANT): got command restart application 2021-07-26T20:05:40.443Z,1627329940.443 [Supervisor](INFO): Stop Mission called by Supervisor::terminate 2021-07-26T20:05:40.444Z,1627329940.444 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2021-07-26T20:05:40.444Z,1627329940.444 [CommandLine ThreadHandler](INFO): Thread cancelled. 2021-07-26T20:05:40.483Z,1627329940.483 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2021-07-26T20:05:40.483Z,1627329940.483 [CommandLine ThreadHandler](INFO): Thread cancelled. 2021-07-26T20:05:40.484Z,1627329940.484 [CommandLine](INFO): Join timeout helper Thread ID is 5419 2021-07-26T20:05:40.495Z,1627329940.495 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2021-07-26T20:05:40.495Z,1627329940.495 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2021-07-26T20:05:40.496Z,1627329940.496 [NavChartDb](INFO): Join timeout helper Thread ID is 5420 2021-07-26T20:05:40.695Z,1627329940.695 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2021-07-26T20:05:40.696Z,1627329940.696 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2021-07-26T20:05:40.699Z,1627329940.699 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2021-07-26T20:05:40.699Z,1627329940.699 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2021-07-26T20:05:40.700Z,1627329940.700 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 5421 2021-07-26T20:05:41.019Z,1627329941.019 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2021-07-26T20:05:41.020Z,1627329941.020 [WetLabsBB2FL](INFO): Powering down 2021-07-26T20:05:41.020Z,1627329941.020 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2021-07-26T20:05:41.021Z,1627329941.021 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2021-07-26T20:05:41.021Z,1627329941.021 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2021-07-26T20:05:41.021Z,1627329941.021 [CTD_Seabird](INFO): Join timeout helper Thread ID is 5422 2021-07-26T20:05:41.999Z,1627329941.999 [CTD_Seabird](INFO): Powering down 2021-07-26T20:05:42.011Z,1627329942.011 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread. 2021-07-26T20:05:42.011Z,1627329942.011 [CTD_Seabird](INFO): Powering down 2021-07-26T20:05:42.023Z,1627329942.023 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2021-07-26T20:05:42.027Z,1627329942.027 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2021-07-26T20:05:42.027Z,1627329942.027 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2021-07-26T20:05:42.028Z,1627329942.028 [Radio_Surface](INFO): Join timeout helper Thread ID is 5423 2021-07-26T20:05:42.071Z,1627329942.071 [Radio_Surface](INFO): Powering down 2021-07-26T20:05:42.072Z,1627329942.072 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2021-07-26T20:05:42.073Z,1627329942.073 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2021-07-26T20:05:42.088Z,1627329942.088 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler 2021-07-26T20:05:42.088Z,1627329942.088 [Onboard ThreadHandler](INFO): Thread cancelled. 2021-07-26T20:05:42.089Z,1627329942.089 [Onboard](INFO): Join timeout helper Thread ID is 5424 2021-07-26T20:05:42.360Z,1627329942.360 [DataOverHttps](INFO): Radio surface powered OFF, will not connect. 2021-07-26T20:05:42.967Z,1627329942.967 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread. 2021-07-26T20:05:42.968Z,1627329942.968 [Onboard ThreadHandler](INFO): Thread cancelled. 2021-07-26T20:05:42.980Z,1627329942.980 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2021-07-26T20:05:42.980Z,1627329942.980 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2021-07-26T20:05:42.980Z,1627329942.980 [DataOverHttps](INFO): Join timeout helper Thread ID is 5425 2021-07-26T20:05:43.363Z,1627329943.363 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2021-07-26T20:05:43.364Z,1627329943.364 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2021-07-26T20:05:43.376Z,1627329943.376 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2021-07-26T20:05:43.376Z,1627329943.376 [logger ThreadHandler](INFO): Thread cancelled. 2021-07-26T20:05:43.377Z,1627329943.377 [logger](INFO): Join timeout helper Thread ID is 5426 2021-07-26T20:05:43.407Z,1627329943.407 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2021-07-26T20:05:43.408Z,1627329943.408 [logger ThreadHandler](INFO): Thread cancelled. 2021-07-26T20:05:43.416Z,1627329943.416 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2021-07-26T20:05:43.416Z,1627329943.416 [CommandLine ThreadHandler](INFO): Thread cancelled. 2021-07-26T20:05:43.416Z,1627329943.416 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2021-07-26T20:05:43.416Z,1627329943.416 [controlThread ThreadHandler](INFO): Thread cancelled. 2021-07-26T20:05:43.417Z,1627329943.417 [controlThread](INFO): Join timeout helper Thread ID is 5427 2021-07-26T20:05:43.431Z,1627329943.431 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2021-07-26T20:05:43.432Z,1627329943.432 [controlThread](DEBUG): Uninitializing ControlThread 2021-07-26T20:05:43.432Z,1627329943.432 [AHRS_M2](INFO): Powering down 2021-07-26T20:05:43.504Z,1627329943.504 [NAL9602](INFO): Powering down 2021-07-26T20:05:43.507Z,1627329943.507 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2021-07-26T20:05:43.508Z,1627329943.508 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2021-07-26T20:05:43.508Z,1627329943.508 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2021-07-26T20:05:43.509Z,1627329943.509 [MissionManager](INFO): Uninitializing Mission Default 2021-07-26T20:05:43.509Z,1627329943.509 [Default] Stopped 2021-07-26T20:05:43.509Z,1627329943.509 [Default](DEBUG): Aggregate::uninitialize Default 2021-07-26T20:05:43.509Z,1627329943.509 [Default:B.GoToSurface] Stopped 2021-07-26T20:05:43.509Z,1627329943.509 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2021-07-26T20:05:43.509Z,1627329943.509 [Default:CheckIn] Stopped 2021-07-26T20:05:43.510Z,1627329943.510 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-26T20:05:43.510Z,1627329943.510 [Default:CheckIn:C.Wait] Stopped 2021-07-26T20:05:43.510Z,1627329943.510 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-26T20:05:43.513Z,1627329943.513 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2021-07-26T20:05:43.513Z,1627329943.513 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2021-07-26T20:05:43.514Z,1627329943.514 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2021-07-26T20:05:43.514Z,1627329943.514 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2021-07-26T20:05:43.514Z,1627329943.514 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2021-07-26T20:05:43.514Z,1627329943.514 [BuoyancyServo](INFO): Powering down 2021-07-26T20:05:43.527Z,1627329943.527 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2021-07-26T20:05:43.528Z,1627329943.528 [ElevatorServo](INFO): Powering down 2021-07-26T20:05:43.528Z,1627329943.528 [MassServo](DEBUG): Uninitialize Mass Servo. 2021-07-26T20:05:43.529Z,1627329943.529 [MassServo](INFO): Powering down 2021-07-26T20:05:43.529Z,1627329943.529 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2021-07-26T20:05:43.530Z,1627329943.530 [RudderServo](INFO): Powering down 2021-07-26T20:05:43.530Z,1627329943.530 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2021-07-26T20:05:43.531Z,1627329943.531 [ThrusterServo](INFO): Powering down 2021-07-26T20:05:43.532Z,1627329943.532 [SBIT](DEBUG): Uninitialize SBIT Component. 2021-07-26T20:05:43.532Z,1627329943.532 [IBIT](DEBUG): Uninitialize IBIT Component. 2021-07-26T20:05:43.532Z,1627329943.532 [CBIT](DEBUG): Uninitialize CBIT Component. 2021-07-26T20:05:43.532Z,1627329943.532 [CBIT](DEBUG): Powering off loads. 2021-07-26T20:05:43.543Z,1627329943.543 [CBIT](DEBUG): Disabling WDT. 2021-07-26T20:05:43.555Z,1627329943.555 [CBIT](DEBUG): Opening all GF detection circuits. 2021-07-26T20:05:43.556Z,1627329943.556 [controlThread ThreadHandler](INFO): Thread cancelled. 2021-07-26T20:05:43.611Z,1627329943.611 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2021-07-26T20:05:43.614Z,1627329943.614 [Onboard ThreadHandler](INFO): Thread cancelled. 2021-07-26T20:05:43.621Z,1627329943.621 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2021-07-26T20:05:43.692Z,1627329943.692 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2021-07-26T20:05:43.696Z,1627329943.696 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2021-07-26T20:05:43.735Z,1627329943.735 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2021-07-26T20:05:43.809Z,1627329943.809 [logger ThreadHandler](INFO): Thread cancelled.