2021-07-27T16:55:52.496Z,1627404952.496 [CommandLine](IMPORTANT): got command restart logs 2021-07-27T16:56:03.520Z,1627404963.520 [DataOverHttps](INFO): Sending 874 bytes from file Logs/20210727T161405/Express0001.lzma 2021-07-27T16:56:04.521Z,1627404964.521 [DataOverHttps](INFO): Moved sent file to Logs/20210727T161405/Express0001.lzma.bak 2021-07-27T16:56:04.521Z,1627404964.521 [DataOverHttps](INFO): SBD MOMSN=15763881 2021-07-27T16:56:07.101Z,1627404967.101 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-27T16:56:25.107Z,1627404985.107 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20210727T161405/Courier0009.lzma 2021-07-27T16:56:26.109Z,1627404986.109 [DataOverHttps](INFO): Moved sent file to Logs/20210727T161405/Courier0009.lzma.bak 2021-07-27T16:56:26.109Z,1627404986.109 [DataOverHttps](INFO): SBD MOMSN=15763904 2021-07-27T16:56:54.843Z,1627405014.843 [DataOverHttps](INFO): Sending 1536 bytes from file Logs/20210727T161405/Express0005.lzma 2021-07-27T16:56:55.841Z,1627405015.841 [DataOverHttps](INFO): Moved sent file to Logs/20210727T161405/Express0005.lzma.bak 2021-07-27T16:56:55.841Z,1627405015.841 [DataOverHttps](INFO): SBD MOMSN=15763906 2021-07-27T16:57:25.335Z,1627405045.335 [DataOverHttps](INFO): Sending 52 bytes from file Logs/20210727T161405/Express0006.lzma 2021-07-27T16:57:26.338Z,1627405046.338 [DataOverHttps](INFO): Moved sent file to Logs/20210727T161405/Express0006.lzma.bak 2021-07-27T16:57:26.338Z,1627405046.338 [DataOverHttps](INFO): SBD MOMSN=15763947 2021-07-27T16:57:44.924Z,1627405064.924 [DataOverHttps](INFO): Sending 189 bytes from file Logs/20210727T161405/Express0010.lzma 2021-07-27T16:57:45.925Z,1627405065.925 [DataOverHttps](INFO): Moved sent file to Logs/20210727T161405/Express0010.lzma.bak 2021-07-27T16:57:45.925Z,1627405065.925 [DataOverHttps](INFO): SBD MOMSN=15763949 2021-07-27T16:57:49.588Z,1627405069.588 [Default:CheckIn:Read_Iridium] Stopped 2021-07-27T16:57:49.588Z,1627405069.588 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-27T16:57:49.588Z,1627405069.588 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-27T17:02:50.194Z,1627405370.194 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-27T17:02:50.194Z,1627405370.194 [Default:CheckIn:C.Wait] Stopped 2021-07-27T17:02:50.194Z,1627405370.194 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-27T17:02:50.195Z,1627405370.195 [Default:CheckIn:D] Running Loop=1 2021-07-27T17:02:50.583Z,1627405370.583 [Default:CheckIn:D] Stopped 2021-07-27T17:02:50.583Z,1627405370.583 [Default:CheckIn:E] Running Loop=1 2021-07-27T17:02:50.991Z,1627405370.991 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 12.543116 min 2021-07-27T17:02:50.991Z,1627405370.991 [Default:CheckIn:E] Stopped 2021-07-27T17:02:50.991Z,1627405370.991 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-27T17:02:50.991Z,1627405370.991 [Default:CheckIn] Stopped 2021-07-27T17:02:50.991Z,1627405370.991 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-27T17:02:50.991Z,1627405370.991 [Default:CheckIn](INFO): Running loop #2 2021-07-27T17:02:50.991Z,1627405370.991 [Default:CheckIn] Running Loop=2 2021-07-27T17:02:50.992Z,1627405370.992 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-27T17:02:50.992Z,1627405370.992 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-27T17:02:52.597Z,1627405372.597 [NAL9602](FAULT): GPS failed to acquire within timeout. 2021-07-27T17:02:52.597Z,1627405372.597 [NAL9602] Data Fault, FailCount= 1 2021-07-27T17:02:52.597Z,1627405372.597 [NAL9602](ERROR): Data Fault 2021-07-27T17:02:52.618Z,1627405372.618 [CBIT](ERROR): Data Fault in component: NAL9602 2021-07-27T17:02:53.012Z,1627405373.012 [NAL9602](INFO): Powering down 2021-07-27T17:02:53.824Z,1627405373.824 [CBIT](INFO): Clearing failed state for component NAL9602 2021-07-27T17:02:53.824Z,1627405373.824 [NAL9602] No Fault, FailCount= 1 2021-07-27T17:03:23.312Z,1627405403.312 [NAL9602](INFO): Powering up NAL9602 2021-07-27T17:03:34.214Z,1627405414.214 [NAL9602](INFO): NAL9602 initialized 2021-07-27T17:07:51.190Z,1627405671.190 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-07-27T17:02:50.0Z 2021-07-27T17:07:51.190Z,1627405671.190 [Default:CheckIn:Read_GPS] Stopped 2021-07-27T17:07:51.191Z,1627405671.191 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-27T17:07:59.363Z,1627405679.363 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20210727T165552/Courier0003.lzma 2021-07-27T17:08:00.365Z,1627405680.365 [DataOverHttps](INFO): Moved sent file to Logs/20210727T165552/Courier0003.lzma.bak 2021-07-27T17:08:00.365Z,1627405680.365 [DataOverHttps](INFO): SBD MOMSN=15763960 2021-07-27T17:08:19.912Z,1627405699.912 [DataOverHttps](INFO): Sending 434 bytes from file Logs/20210727T165552/Express0004.lzma 2021-07-27T17:08:20.889Z,1627405700.889 [DataOverHttps](INFO): Moved sent file to Logs/20210727T165552/Express0004.lzma.bak 2021-07-27T17:08:20.889Z,1627405700.889 [DataOverHttps](INFO): SBD MOMSN=15763963 2021-07-27T17:08:26.481Z,1627405706.481 [Default:CheckIn:Read_Iridium] Stopped 2021-07-27T17:08:26.481Z,1627405706.481 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-27T17:08:26.481Z,1627405706.481 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-27T17:08:37.813Z,1627405717.813 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-27T17:09:08.520Z,1627405748.520 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-27T17:13:27.220Z,1627406007.220 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-27T17:13:27.220Z,1627406007.220 [Default:CheckIn:C.Wait] Stopped 2021-07-27T17:13:27.220Z,1627406007.220 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-27T17:13:27.220Z,1627406007.220 [Default:CheckIn:D] Running Loop=1 2021-07-27T17:13:27.597Z,1627406007.597 [Default:CheckIn:D] Stopped 2021-07-27T17:13:27.597Z,1627406007.597 [Default:CheckIn:E] Running Loop=1 2021-07-27T17:13:28.003Z,1627406008.003 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 23.160010 min 2021-07-27T17:13:28.004Z,1627406008.004 [Default:CheckIn:E] Stopped 2021-07-27T17:13:28.004Z,1627406008.004 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-27T17:13:28.004Z,1627406008.004 [Default:CheckIn] Stopped 2021-07-27T17:13:28.004Z,1627406008.004 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-27T17:13:28.004Z,1627406008.004 [Default:CheckIn](INFO): Running loop #3 2021-07-27T17:13:28.004Z,1627406008.004 [Default:CheckIn] Running Loop=3 2021-07-27T17:13:28.004Z,1627406008.004 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-27T17:13:28.004Z,1627406008.004 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-27T17:13:30.014Z,1627406010.014 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171329.00,A,3648.17303,N,12147.27664,W,0.467,23.74,270721,,,A*4A 2021-07-27T17:13:30.027Z,1627406010.027 [NAL9602](INFO): GPS fix at 20210727T171329: (36.802884, -121.787944) 2021-07-27T17:13:30.038Z,1627406010.038 [Default:CheckIn:Read_GPS] Stopped 2021-07-27T17:13:30.038Z,1627406010.038 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-27T17:13:38.551Z,1627406018.551 [DataOverHttps](INFO): Sending 222 bytes from file Logs/20210727T165552/Courier0006.lzma 2021-07-27T17:13:39.553Z,1627406019.553 [DataOverHttps](INFO): Moved sent file to Logs/20210727T165552/Courier0006.lzma.bak 2021-07-27T17:13:39.553Z,1627406019.553 [DataOverHttps](INFO): SBD MOMSN=15763974 2021-07-27T17:13:57.687Z,1627406037.687 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20210727T165552/Express0007.lzma 2021-07-27T17:13:58.689Z,1627406038.689 [DataOverHttps](INFO): Moved sent file to Logs/20210727T165552/Express0007.lzma.bak 2021-07-27T17:13:58.689Z,1627406038.689 [DataOverHttps](INFO): SBD MOMSN=15763977 2021-07-27T17:14:00.761Z,1627406040.761 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-07-27T17:14:00.835Z,1627406040.835 [NAL9602](ERROR): received: +CSQ:0 OK551, 2, 0, 0, 0 OK 2021-07-27T17:14:02.041Z,1627406042.041 [Default:CheckIn:Read_Iridium] Stopped 2021-07-27T17:14:02.041Z,1627406042.041 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-27T17:14:02.041Z,1627406042.041 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-27T17:18:32.408Z,1627406312.408 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-27T17:19:02.718Z,1627406342.718 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-27T17:19:02.718Z,1627406342.718 [Default:CheckIn:C.Wait] Stopped 2021-07-27T17:19:02.718Z,1627406342.718 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-27T17:19:02.719Z,1627406342.719 [Default:CheckIn:D] Running Loop=1 2021-07-27T17:19:03.120Z,1627406343.120 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-27T17:19:03.133Z,1627406343.133 [Default:CheckIn:D] Stopped 2021-07-27T17:19:03.133Z,1627406343.133 [Default:CheckIn:E] Running Loop=1 2021-07-27T17:19:03.543Z,1627406343.543 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 28.752281 min 2021-07-27T17:19:03.543Z,1627406343.543 [Default:CheckIn:E] Stopped 2021-07-27T17:19:03.543Z,1627406343.543 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-27T17:19:03.543Z,1627406343.543 [Default:CheckIn] Stopped 2021-07-27T17:19:03.543Z,1627406343.543 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-27T17:19:03.543Z,1627406343.543 [Default:CheckIn](INFO): Running loop #4 2021-07-27T17:19:03.543Z,1627406343.543 [Default:CheckIn] Running Loop=4 2021-07-27T17:19:03.544Z,1627406343.544 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-27T17:19:03.544Z,1627406343.544 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-27T17:19:05.539Z,1627406345.539 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171904.00,A,3648.16061,N,12147.28971,W,0.233,219.65,270721,,,A*71 2021-07-27T17:19:05.541Z,1627406345.541 [NAL9602](INFO): GPS fix at 20210727T171904: (36.802677, -121.788162) 2021-07-27T17:19:05.552Z,1627406345.552 [Default:CheckIn:Read_GPS] Stopped 2021-07-27T17:19:05.552Z,1627406345.552 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-27T17:19:14.359Z,1627406354.359 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210727T165552/Courier0009.lzma 2021-07-27T17:19:15.361Z,1627406355.361 [DataOverHttps](INFO): Moved sent file to Logs/20210727T165552/Courier0009.lzma.bak 2021-07-27T17:19:15.361Z,1627406355.361 [DataOverHttps](INFO): SBD MOMSN=15763981 2021-07-27T17:19:33.969Z,1627406373.969 [DataOverHttps](INFO): Sending 220 bytes from file Logs/20210727T165552/Express0010.lzma 2021-07-27T17:19:34.969Z,1627406374.969 [DataOverHttps](INFO): Moved sent file to Logs/20210727T165552/Express0010.lzma.bak 2021-07-27T17:19:34.970Z,1627406374.970 [DataOverHttps](INFO): SBD MOMSN=15763984 2021-07-27T17:19:38.321Z,1627406378.321 [Default:CheckIn:Read_Iridium] Stopped 2021-07-27T17:19:38.321Z,1627406378.321 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-27T17:19:38.321Z,1627406378.321 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-27T17:21:33.967Z,1627406493.967 [NAL9602](INFO): SBD MO Status=2, MOMSN=28551, MT Status=2, MTMSN=0 2021-07-27T17:21:33.967Z,1627406493.967 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-27T17:22:00.202Z,1627406520.202 [NAL9602](INFO): SBD MO Status=2, MOMSN=28551, MT Status=2, MTMSN=0 2021-07-27T17:22:00.202Z,1627406520.202 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-27T17:22:44.302Z,1627406564.302 [NAL9602](INFO): SBD MO Status=2, MOMSN=28551, MT Status=2, MTMSN=0 2021-07-27T17:22:44.302Z,1627406564.302 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-27T17:23:58.230Z,1627406638.230 [NAL9602](INFO): SBD MO Status=2, MOMSN=28551, MT Status=2, MTMSN=0 2021-07-27T17:23:58.230Z,1627406638.230 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-27T17:24:20.050Z,1627406660.050 [NAL9602](INFO): SBD MO Status=2, MOMSN=28551, MT Status=2, MTMSN=0 2021-07-27T17:24:20.050Z,1627406660.050 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-27T17:24:20.548Z,1627406660.548 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-27T17:24:38.711Z,1627406678.711 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-27T17:24:38.711Z,1627406678.711 [Default:CheckIn:C.Wait] Stopped 2021-07-27T17:24:38.711Z,1627406678.711 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-27T17:24:38.712Z,1627406678.712 [Default:CheckIn:D] Running Loop=1 2021-07-27T17:24:39.135Z,1627406679.135 [Default:CheckIn:D] Stopped 2021-07-27T17:24:39.135Z,1627406679.135 [Default:CheckIn:E] Running Loop=1 2021-07-27T17:24:39.519Z,1627406679.519 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 34.352315 min 2021-07-27T17:24:39.519Z,1627406679.519 [Default:CheckIn:E] Stopped 2021-07-27T17:24:39.519Z,1627406679.519 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-27T17:24:39.519Z,1627406679.519 [Default:CheckIn] Stopped 2021-07-27T17:24:39.535Z,1627406679.535 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-27T17:24:39.536Z,1627406679.536 [Default:CheckIn](INFO): Running loop #5 2021-07-27T17:24:39.536Z,1627406679.536 [Default:CheckIn] Running Loop=5 2021-07-27T17:24:39.536Z,1627406679.536 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-27T17:24:39.536Z,1627406679.536 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-27T17:24:41.534Z,1627406681.534 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172440.00,A,3648.15964,N,12147.28975,W,0.525,39.96,270721,,,A*48 2021-07-27T17:24:41.537Z,1627406681.537 [NAL9602](INFO): GPS fix at 20210727T172440: (36.802661, -121.788162) 2021-07-27T17:24:41.548Z,1627406681.548 [Default:CheckIn:Read_GPS] Stopped 2021-07-27T17:24:41.548Z,1627406681.548 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-27T17:24:50.812Z,1627406690.812 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210727T165552/Courier0012.lzma 2021-07-27T17:24:51.805Z,1627406691.805 [DataOverHttps](INFO): Moved sent file to Logs/20210727T165552/Courier0012.lzma.bak 2021-07-27T17:24:51.805Z,1627406691.805 [DataOverHttps](INFO): SBD MOMSN=15763995 2021-07-27T17:25:10.028Z,1627406710.028 [DataOverHttps](INFO): Sending 204 bytes from file Logs/20210727T165552/Express0013.lzma 2021-07-27T17:25:11.029Z,1627406711.029 [DataOverHttps](INFO): Moved sent file to Logs/20210727T165552/Express0013.lzma.bak 2021-07-27T17:25:11.029Z,1627406711.029 [DataOverHttps](INFO): SBD MOMSN=15763998 2021-07-27T17:25:13.448Z,1627406713.448 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-27T17:25:14.709Z,1627406714.709 [Default:CheckIn:Read_Iridium] Stopped 2021-07-27T17:25:14.709Z,1627406714.709 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-27T17:25:14.709Z,1627406714.709 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-27T17:29:07.462Z,1627406947.462 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2021-07-27T17:29:07.465Z,1627406947.465 [BPC1](INFO): Received data from all battery sticks. 2021-07-27T17:30:15.354Z,1627407015.354 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-27T17:30:15.354Z,1627407015.354 [Default:CheckIn:C.Wait] Stopped 2021-07-27T17:30:15.354Z,1627407015.354 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-27T17:30:15.354Z,1627407015.354 [Default:CheckIn:D] Running Loop=1 2021-07-27T17:30:15.742Z,1627407015.742 [Default:CheckIn:D] Stopped 2021-07-27T17:30:15.743Z,1627407015.743 [Default:CheckIn:E] Running Loop=1 2021-07-27T17:30:16.147Z,1627407016.147 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 39.962443 min 2021-07-27T17:30:16.147Z,1627407016.147 [Default:CheckIn:E] Stopped 2021-07-27T17:30:16.147Z,1627407016.147 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-27T17:30:16.147Z,1627407016.147 [Default:CheckIn] Stopped 2021-07-27T17:30:16.147Z,1627407016.147 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-27T17:30:16.148Z,1627407016.148 [Default:CheckIn](INFO): Running loop #6 2021-07-27T17:30:16.148Z,1627407016.148 [Default:CheckIn] Running Loop=6 2021-07-27T17:30:16.148Z,1627407016.148 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-27T17:30:16.148Z,1627407016.148 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-27T17:30:18.162Z,1627407018.162 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173017.00,A,3648.16445,N,12147.28442,W,0.097,33.64,270721,,,A*40 2021-07-27T17:30:18.183Z,1627407018.183 [NAL9602](INFO): GPS fix at 20210727T173017: (36.802741, -121.788074) 2021-07-27T17:30:18.205Z,1627407018.205 [Default:CheckIn:Read_GPS] Stopped 2021-07-27T17:30:18.205Z,1627407018.205 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-27T17:30:31.183Z,1627407031.183 [DataOverHttps](INFO): Sending 202 bytes from file Logs/20210727T165552/Courier0015.lzma 2021-07-27T17:30:32.185Z,1627407032.185 [DataOverHttps](INFO): Moved sent file to Logs/20210727T165552/Courier0015.lzma.bak 2021-07-27T17:30:32.185Z,1627407032.185 [DataOverHttps](INFO): SBD MOMSN=15764005 2021-07-27T17:30:40.178Z,1627407040.178 [NAL9602](INFO): SBD MO Status=2, MOMSN=28551, MT Status=2, MTMSN=0 2021-07-27T17:30:40.178Z,1627407040.178 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-27T17:30:53.951Z,1627407053.951 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20210727T165552/Express0016.lzma 2021-07-27T17:30:54.953Z,1627407054.953 [DataOverHttps](INFO): Moved sent file to Logs/20210727T165552/Express0016.lzma.bak 2021-07-27T17:30:54.953Z,1627407054.953 [DataOverHttps](INFO): SBD MOMSN=15764012 2021-07-27T17:30:58.339Z,1627407058.339 [Default:CheckIn:Read_Iridium] Stopped 2021-07-27T17:30:58.340Z,1627407058.340 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-27T17:30:58.340Z,1627407058.340 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-27T17:31:05.190Z,1627407065.190 [NAL9602](INFO): SBD MO Status=2, MOMSN=28551, MT Status=2, MTMSN=0 2021-07-27T17:31:05.190Z,1627407065.190 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-27T17:33:11.254Z,1627407191.254 [NAL9602](INFO): SBD MO Status=2, MOMSN=28551, MT Status=2, MTMSN=0 2021-07-27T17:33:11.255Z,1627407191.255 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-27T17:35:20.529Z,1627407320.529 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-27T17:35:51.236Z,1627407351.236 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-27T17:35:58.923Z,1627407358.923 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-27T17:35:58.923Z,1627407358.923 [Default:CheckIn:C.Wait] Stopped 2021-07-27T17:35:58.923Z,1627407358.923 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-27T17:35:58.923Z,1627407358.923 [Default:CheckIn:D] Running Loop=1 2021-07-27T17:35:59.337Z,1627407359.337 [Default:CheckIn:D] Stopped 2021-07-27T17:35:59.337Z,1627407359.337 [Default:CheckIn:E] Running Loop=1 2021-07-27T17:35:59.740Z,1627407359.740 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 45.689010 min 2021-07-27T17:35:59.740Z,1627407359.740 [Default:CheckIn:E] Stopped 2021-07-27T17:35:59.740Z,1627407359.740 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-27T17:35:59.740Z,1627407359.740 [Default:CheckIn] Stopped 2021-07-27T17:35:59.741Z,1627407359.741 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-27T17:35:59.741Z,1627407359.741 [Default:CheckIn](INFO): Running loop #7 2021-07-27T17:35:59.741Z,1627407359.741 [Default:CheckIn] Running Loop=7 2021-07-27T17:35:59.741Z,1627407359.741 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-27T17:35:59.741Z,1627407359.741 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-27T17:36:01.743Z,1627407361.743 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173601.00,A,3648.16324,N,12147.28424,W,0.078,245.61,270721,,,A*76 2021-07-27T17:36:01.745Z,1627407361.745 [NAL9602](INFO): GPS fix at 20210727T173601: (36.802721, -121.788071) 2021-07-27T17:36:01.756Z,1627407361.756 [Default:CheckIn:Read_GPS] Stopped 2021-07-27T17:36:01.756Z,1627407361.756 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-27T17:36:10.391Z,1627407370.391 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210727T165552/Courier0018.lzma 2021-07-27T17:36:11.393Z,1627407371.393 [DataOverHttps](INFO): Moved sent file to Logs/20210727T165552/Courier0018.lzma.bak 2021-07-27T17:36:11.393Z,1627407371.393 [DataOverHttps](INFO): SBD MOMSN=15764015 2021-07-27T17:36:35.491Z,1627407395.491 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20210727T165552/Express0019.lzma 2021-07-27T17:36:36.493Z,1627407396.493 [DataOverHttps](INFO): Moved sent file to Logs/20210727T165552/Express0019.lzma.bak 2021-07-27T17:36:36.493Z,1627407396.493 [DataOverHttps](INFO): SBD MOMSN=15764018 2021-07-27T17:36:41.964Z,1627407401.964 [Default:CheckIn:Read_Iridium] Stopped 2021-07-27T17:36:41.964Z,1627407401.964 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-27T17:36:41.965Z,1627407401.965 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-27T17:38:05.131Z,1627407485.131 [NAL9602](INFO): SBD MO Status=0, MOMSN=28551, MT Status=0, MTMSN=0 2021-07-27T17:38:05.131Z,1627407485.131 [NAL9602](INFO): No messages in MT queue 2021-07-27T17:38:35.890Z,1627407515.890 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-27T17:41:42.602Z,1627407702.602 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-27T17:41:42.602Z,1627407702.602 [Default:CheckIn:C.Wait] Stopped 2021-07-27T17:41:42.602Z,1627407702.602 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-27T17:41:42.603Z,1627407702.603 [Default:CheckIn:D] Running Loop=1 2021-07-27T17:41:43.011Z,1627407703.011 [Default:CheckIn:D] Stopped 2021-07-27T17:41:43.011Z,1627407703.011 [Default:CheckIn:E] Running Loop=1 2021-07-27T17:41:43.407Z,1627407703.407 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 51.416907 min 2021-07-27T17:41:43.407Z,1627407703.407 [Default:CheckIn:E] Stopped 2021-07-27T17:41:43.408Z,1627407703.408 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-27T17:41:43.408Z,1627407703.408 [Default:CheckIn] Stopped 2021-07-27T17:41:43.408Z,1627407703.408 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-27T17:41:43.408Z,1627407703.408 [Default:CheckIn](INFO): Running loop #8 2021-07-27T17:41:43.408Z,1627407703.408 [Default:CheckIn] Running Loop=8 2021-07-27T17:41:43.408Z,1627407703.408 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-27T17:41:43.408Z,1627407703.408 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-27T17:41:45.415Z,1627407705.415 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174144.00,A,3648.16273,N,12147.28551,W,0.097,245.61,270721,,,A*76 2021-07-27T17:41:45.417Z,1627407705.417 [NAL9602](INFO): GPS fix at 20210727T174144: (36.802712, -121.788092) 2021-07-27T17:41:45.428Z,1627407705.428 [Default:CheckIn:Read_GPS] Stopped 2021-07-27T17:41:45.428Z,1627407705.428 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-27T17:41:54.055Z,1627407714.055 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210727T165552/Courier0021.lzma 2021-07-27T17:41:55.057Z,1627407715.057 [DataOverHttps](INFO): Moved sent file to Logs/20210727T165552/Courier0021.lzma.bak 2021-07-27T17:41:55.057Z,1627407715.057 [DataOverHttps](INFO): SBD MOMSN=15764023 2021-07-27T17:42:13.235Z,1627407733.235 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20210727T165552/Express0022.lzma 2021-07-27T17:42:14.928Z,1627407734.928 [DataOverHttps](INFO): Moved sent file to Logs/20210727T165552/Express0022.lzma.bak 2021-07-27T17:42:14.928Z,1627407734.928 [DataOverHttps](INFO): SBD MOMSN=15764026 2021-07-27T17:42:19.001Z,1627407739.001 [Default:CheckIn:Read_Iridium] Stopped 2021-07-27T17:42:19.002Z,1627407739.002 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-27T17:42:19.002Z,1627407739.002 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-27T17:46:59.082Z,1627408019.082 [NAL9602](INFO): SBD MO Status=2, MOMSN=28552, MT Status=2, MTMSN=0 2021-07-27T17:46:59.082Z,1627408019.082 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-27T17:46:59.484Z,1627408019.484 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-27T17:47:19.696Z,1627408039.696 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-27T17:47:19.696Z,1627408039.696 [Default:CheckIn:C.Wait] Stopped 2021-07-27T17:47:19.696Z,1627408039.696 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-27T17:47:19.697Z,1627408039.697 [Default:CheckIn:D] Running Loop=1 2021-07-27T17:47:20.095Z,1627408040.095 [Default:CheckIn:D] Stopped 2021-07-27T17:47:20.095Z,1627408040.095 [Default:CheckIn:E] Running Loop=1 2021-07-27T17:47:20.506Z,1627408040.506 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 57.034977 min 2021-07-27T17:47:20.506Z,1627408040.506 [Default:CheckIn:E] Stopped 2021-07-27T17:47:20.506Z,1627408040.506 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-27T17:47:20.506Z,1627408040.506 [Default:CheckIn] Stopped 2021-07-27T17:47:20.506Z,1627408040.506 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-27T17:47:20.507Z,1627408040.507 [Default:CheckIn](INFO): Running loop #9 2021-07-27T17:47:20.507Z,1627408040.507 [Default:CheckIn] Running Loop=9 2021-07-27T17:47:20.507Z,1627408040.507 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-27T17:47:20.507Z,1627408040.507 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-27T17:47:22.515Z,1627408042.515 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174721.00,A,3648.16404,N,12147.28377,W,0.214,245.61,270721,,,A*7E 2021-07-27T17:47:22.517Z,1627408042.517 [NAL9602](INFO): GPS fix at 20210727T174721: (36.802734, -121.788063) 2021-07-27T17:47:22.556Z,1627408042.556 [Default:CheckIn:Read_GPS] Stopped 2021-07-27T17:47:22.556Z,1627408042.556 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-27T17:47:31.167Z,1627408051.167 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210727T165552/Courier0024.lzma 2021-07-27T17:47:32.169Z,1627408052.169 [DataOverHttps](INFO): Moved sent file to Logs/20210727T165552/Courier0024.lzma.bak 2021-07-27T17:47:32.170Z,1627408052.170 [DataOverHttps](INFO): SBD MOMSN=15764033 2021-07-27T17:47:50.327Z,1627408070.327 [DataOverHttps](INFO): Sending 205 bytes from file Logs/20210727T165552/Express0025.lzma 2021-07-27T17:47:51.329Z,1627408071.329 [DataOverHttps](INFO): Moved sent file to Logs/20210727T165552/Express0025.lzma.bak 2021-07-27T17:47:51.329Z,1627408071.329 [DataOverHttps](INFO): SBD MOMSN=15764036 2021-07-27T17:47:54.424Z,1627408074.424 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-27T17:47:54.888Z,1627408074.888 [Default:CheckIn:Read_Iridium] Stopped 2021-07-27T17:47:54.889Z,1627408074.889 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-27T17:47:54.889Z,1627408074.889 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-27T17:52:55.430Z,1627408375.430 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-27T17:52:55.430Z,1627408375.430 [Default:CheckIn:C.Wait] Stopped 2021-07-27T17:52:55.431Z,1627408375.431 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-27T17:52:55.431Z,1627408375.431 [Default:CheckIn:D] Running Loop=1 2021-07-27T17:52:55.841Z,1627408375.841 [Default:CheckIn:D] Stopped 2021-07-27T17:52:55.841Z,1627408375.841 [Default:CheckIn:E] Running Loop=1 2021-07-27T17:52:56.231Z,1627408376.231 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 62.630754 min 2021-07-27T17:52:56.231Z,1627408376.231 [Default:CheckIn:E] Stopped 2021-07-27T17:52:56.231Z,1627408376.231 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-27T17:52:56.232Z,1627408376.232 [Default:CheckIn] Stopped 2021-07-27T17:52:56.232Z,1627408376.232 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-27T17:52:56.232Z,1627408376.232 [Default:CheckIn](INFO): Running loop #10 2021-07-27T17:52:56.232Z,1627408376.232 [Default:CheckIn] Running Loop=10 2021-07-27T17:52:56.232Z,1627408376.232 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-27T17:52:56.232Z,1627408376.232 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-27T17:52:58.246Z,1627408378.246 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175257.00,A,3648.16778,N,12147.27962,W,0.389,153.08,270721,,,A*7C 2021-07-27T17:52:58.249Z,1627408378.249 [NAL9602](INFO): GPS fix at 20210727T175257: (36.802796, -121.787994) 2021-07-27T17:52:58.259Z,1627408378.259 [Default:CheckIn:Read_GPS] Stopped 2021-07-27T17:52:58.260Z,1627408378.260 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-27T17:53:06.887Z,1627408386.887 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210727T165552/Courier0027.lzma 2021-07-27T17:53:07.889Z,1627408387.889 [DataOverHttps](INFO): Moved sent file to Logs/20210727T165552/Courier0027.lzma.bak 2021-07-27T17:53:07.889Z,1627408387.889 [DataOverHttps](INFO): SBD MOMSN=15764042 2021-07-27T17:53:26.071Z,1627408406.071 [DataOverHttps](INFO): Sending 132 bytes from file Logs/20210727T165552/Express0028.lzma 2021-07-27T17:53:27.073Z,1627408407.073 [DataOverHttps](INFO): Moved sent file to Logs/20210727T165552/Express0028.lzma.bak 2021-07-27T17:53:27.073Z,1627408407.073 [DataOverHttps](INFO): SBD MOMSN=15764047 2021-07-27T17:53:31.835Z,1627408411.835 [Default:CheckIn:Read_Iridium] Stopped 2021-07-27T17:53:31.836Z,1627408411.836 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-27T17:53:31.836Z,1627408411.836 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-27T17:55:23.694Z,1627408523.694 [NAL9602](INFO): SBD MO Status=2, MOMSN=28552, MT Status=2, MTMSN=0 2021-07-27T17:55:23.694Z,1627408523.694 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-27T17:56:13.382Z,1627408573.382 [NAL9602](INFO): SBD MO Status=2, MOMSN=28552, MT Status=2, MTMSN=0 2021-07-27T17:56:13.382Z,1627408573.382 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-27T17:56:13.752Z,1627408573.752 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-07-27T17:56:44.884Z,1627408604.884 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-07-27T17:57:16.028Z,1627408636.028 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-07-27T17:57:47.151Z,1627408667.151 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-07-27T17:58:00.441Z,1627408680.441 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-27T17:58:31.208Z,1627408711.208 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-27T17:58:32.430Z,1627408712.430 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-27T17:58:32.431Z,1627408712.431 [Default:CheckIn:C.Wait] Stopped 2021-07-27T17:58:32.431Z,1627408712.431 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-27T17:58:32.431Z,1627408712.431 [Default:CheckIn:D] Running Loop=1 2021-07-27T17:58:32.841Z,1627408712.841 [Default:CheckIn:D] Stopped 2021-07-27T17:58:32.841Z,1627408712.841 [Default:CheckIn:E] Running Loop=1 2021-07-27T17:58:33.264Z,1627408713.264 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 68.247424 min 2021-07-27T17:58:33.264Z,1627408713.264 [Default:CheckIn:E] Stopped 2021-07-27T17:58:33.264Z,1627408713.264 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-27T17:58:33.264Z,1627408713.264 [Default:CheckIn] Stopped 2021-07-27T17:58:33.264Z,1627408713.264 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-27T17:58:33.264Z,1627408713.264 [Default:CheckIn](INFO): Running loop #11 2021-07-27T17:58:33.265Z,1627408713.265 [Default:CheckIn] Running Loop=11 2021-07-27T17:58:33.265Z,1627408713.265 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-27T17:58:33.265Z,1627408713.265 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-27T17:58:35.250Z,1627408715.250 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175834.00,A,3648.16853,N,12147.28241,W,0.175,153.08,270721,,,A*71 2021-07-27T17:58:35.253Z,1627408715.253 [NAL9602](INFO): GPS fix at 20210727T175834: (36.802809, -121.788040) 2021-07-27T17:58:35.284Z,1627408715.284 [Default:CheckIn:Read_GPS] Stopped 2021-07-27T17:58:35.284Z,1627408715.284 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-27T17:58:44.739Z,1627408724.739 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210727T165552/Courier0030.lzma 2021-07-27T17:58:45.741Z,1627408725.741 [DataOverHttps](INFO): Moved sent file to Logs/20210727T165552/Courier0030.lzma.bak 2021-07-27T17:58:45.741Z,1627408725.741 [DataOverHttps](INFO): SBD MOMSN=15764105 2021-07-27T17:59:03.787Z,1627408743.787 [DataOverHttps](INFO): Sending 202 bytes from file Logs/20210727T165552/Express0031.lzma 2021-07-27T17:59:04.944Z,1627408744.944 [DataOverHttps](INFO): Moved sent file to Logs/20210727T165552/Express0031.lzma.bak 2021-07-27T17:59:04.944Z,1627408744.944 [DataOverHttps](INFO): SBD MOMSN=15764109 2021-07-27T17:59:06.077Z,1627408746.077 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-07-27T17:59:06.151Z,1627408746.151 [NAL9602](ERROR): received: +CSQ:0 OK552, 2, 0, 0, 0 OK 2021-07-27T17:59:08.504Z,1627408748.504 [Default:CheckIn:Read_Iridium] Stopped 2021-07-27T17:59:08.504Z,1627408748.504 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-27T17:59:08.504Z,1627408748.504 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-27T18:03:37.258Z,1627409017.258 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-27T18:04:07.960Z,1627409047.960 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-27T18:04:09.193Z,1627409049.193 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-27T18:04:09.193Z,1627409049.193 [Default:CheckIn:C.Wait] Stopped 2021-07-27T18:04:09.193Z,1627409049.193 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-27T18:04:09.193Z,1627409049.193 [Default:CheckIn:D] Running Loop=1 2021-07-27T18:04:09.614Z,1627409049.614 [Default:CheckIn:D] Stopped 2021-07-27T18:04:09.614Z,1627409049.614 [Default:CheckIn:E] Running Loop=1 2021-07-27T18:04:09.995Z,1627409049.995 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 73.860303 min 2021-07-27T18:04:09.995Z,1627409049.995 [Default:CheckIn:E] Stopped 2021-07-27T18:04:09.995Z,1627409049.995 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-27T18:04:09.995Z,1627409049.995 [Default:CheckIn] Stopped 2021-07-27T18:04:09.995Z,1627409049.995 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-27T18:04:09.996Z,1627409049.996 [Default:CheckIn](INFO): Running loop #12 2021-07-27T18:04:09.996Z,1627409049.996 [Default:CheckIn] Running Loop=12 2021-07-27T18:04:09.996Z,1627409049.996 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-27T18:04:09.996Z,1627409049.996 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-27T18:04:12.004Z,1627409052.004 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180411.00,A,3648.16673,N,12147.28113,W,0.194,153.08,270721,,,A*77 2021-07-27T18:04:12.006Z,1627409052.006 [NAL9602](INFO): GPS fix at 20210727T180411: (36.802779, -121.788019) 2021-07-27T18:04:12.017Z,1627409052.017 [Default:CheckIn:Read_GPS] Stopped 2021-07-27T18:04:12.017Z,1627409052.017 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-27T18:04:24.627Z,1627409064.627 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20210727T165552/Courier0033.lzma 2021-07-27T18:04:25.629Z,1627409065.629 [DataOverHttps](INFO): Moved sent file to Logs/20210727T165552/Courier0033.lzma.bak 2021-07-27T18:04:25.629Z,1627409065.629 [DataOverHttps](INFO): SBD MOMSN=15764115 2021-07-27T18:04:42.505Z,1627409082.505 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-07-27T18:04:42.587Z,1627409082.587 [NAL9602](ERROR): received: +CSQ:0 OK552, 2, 0, 0, 0 OK 2021-07-27T18:04:49.068Z,1627409089.068 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20210727T165552/Express0034.lzma 2021-07-27T18:04:50.069Z,1627409090.069 [DataOverHttps](INFO): Moved sent file to Logs/20210727T165552/Express0034.lzma.bak 2021-07-27T18:04:50.069Z,1627409090.069 [DataOverHttps](INFO): SBD MOMSN=15764172 2021-07-27T18:04:53.427Z,1627409093.427 [Default:CheckIn:Read_Iridium] Stopped 2021-07-27T18:04:53.427Z,1627409093.427 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-27T18:04:53.428Z,1627409093.428 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-27T18:06:04.917Z,1627409164.917 [NAL9602](INFO): SBD MO Status=2, MOMSN=28552, MT Status=2, MTMSN=0 2021-07-27T18:06:04.917Z,1627409164.917 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-27T18:07:24.514Z,1627409244.514 [NAL9602](INFO): SBD MO Status=2, MOMSN=28552, MT Status=2, MTMSN=0 2021-07-27T18:07:24.514Z,1627409244.514 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-27T18:08:06.928Z,1627409286.928 [NAL9602](INFO): SBD MO Status=2, MOMSN=28552, MT Status=2, MTMSN=0 2021-07-27T18:08:06.928Z,1627409286.928 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-27T18:08:36.018Z,1627409316.018 [NAL9602](INFO): SBD MO Status=2, MOMSN=28552, MT Status=2, MTMSN=0 2021-07-27T18:08:36.018Z,1627409316.018 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-27T18:09:14.400Z,1627409354.400 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-27T18:09:45.096Z,1627409385.096 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-27T18:09:54.006Z,1627409394.006 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-27T18:09:54.006Z,1627409394.006 [Default:CheckIn:C.Wait] Stopped 2021-07-27T18:09:54.007Z,1627409394.007 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-27T18:09:54.007Z,1627409394.007 [Default:CheckIn:D] Running Loop=1 2021-07-27T18:09:54.415Z,1627409394.415 [Default:CheckIn:D] Stopped 2021-07-27T18:09:54.415Z,1627409394.415 [Default:CheckIn:E] Running Loop=1 2021-07-27T18:09:54.806Z,1627409394.806 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 79.606974 min 2021-07-27T18:09:54.806Z,1627409394.806 [Default:CheckIn:E] Stopped 2021-07-27T18:09:54.806Z,1627409394.806 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-27T18:09:54.806Z,1627409394.806 [Default:CheckIn] Stopped 2021-07-27T18:09:54.807Z,1627409394.807 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-27T18:09:54.807Z,1627409394.807 [Default:CheckIn](INFO): Running loop #13 2021-07-27T18:09:54.807Z,1627409394.807 [Default:CheckIn] Running Loop=13 2021-07-27T18:09:54.807Z,1627409394.807 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-27T18:09:54.807Z,1627409394.807 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-27T18:09:56.814Z,1627409396.814 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180956.00,A,3648.16968,N,12147.27987,W,0.136,0.00,270721,,,A*71 2021-07-27T18:09:56.817Z,1627409396.817 [NAL9602](INFO): GPS fix at 20210727T180956: (36.802828, -121.787998) 2021-07-27T18:09:56.828Z,1627409396.828 [Default:CheckIn:Read_GPS] Stopped 2021-07-27T18:09:56.828Z,1627409396.828 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-27T18:10:05.387Z,1627409405.387 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210727T165552/Courier0036.lzma 2021-07-27T18:10:06.389Z,1627409406.389 [DataOverHttps](INFO): Moved sent file to Logs/20210727T165552/Courier0036.lzma.bak 2021-07-27T18:10:06.389Z,1627409406.389 [DataOverHttps](INFO): SBD MOMSN=15764176 2021-07-27T18:10:27.561Z,1627409427.561 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20210727T165552/Express0037.lzma 2021-07-27T18:10:27.585Z,1627409427.585 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-07-27T18:10:27.663Z,1627409427.663 [NAL9602](ERROR): received: +CSQ:0 OK552, 2, 0, 0, 0 OK 2021-07-27T18:10:28.557Z,1627409428.557 [DataOverHttps](INFO): Moved sent file to Logs/20210727T165552/Express0037.lzma.bak 2021-07-27T18:10:28.558Z,1627409428.558 [DataOverHttps](INFO): SBD MOMSN=15764180 2021-07-27T18:10:34.164Z,1627409434.164 [Default:CheckIn:Read_Iridium] Stopped 2021-07-27T18:10:34.165Z,1627409434.165 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-27T18:10:34.165Z,1627409434.165 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-27T18:14:22.446Z,1627409662.446 [NAL9602](INFO): SBD MO Status=2, MOMSN=28552, MT Status=2, MTMSN=0 2021-07-27T18:14:22.446Z,1627409662.446 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-27T18:14:44.734Z,1627409684.734 [NAL9602](INFO): SBD MO Status=2, MOMSN=28552, MT Status=2, MTMSN=0 2021-07-27T18:14:44.734Z,1627409684.734 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-27T18:15:01.302Z,1627409701.302 [NAL9602](INFO): SBD MO Status=2, MOMSN=28552, MT Status=2, MTMSN=0 2021-07-27T18:15:01.302Z,1627409701.302 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-07-27T18:15:01.714Z,1627409701.714 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-27T18:15:32.410Z,1627409732.410 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-27T18:15:34.844Z,1627409734.844 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-27T18:15:34.845Z,1627409734.845 [Default:CheckIn:C.Wait] Stopped 2021-07-27T18:15:34.845Z,1627409734.845 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-27T18:15:34.845Z,1627409734.845 [Default:CheckIn:D] Running Loop=1 2021-07-27T18:15:35.249Z,1627409735.249 [Default:CheckIn:D] Stopped 2021-07-27T18:15:35.249Z,1627409735.249 [Default:CheckIn:E] Running Loop=1 2021-07-27T18:15:35.655Z,1627409735.655 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 85.287549 min 2021-07-27T18:15:35.656Z,1627409735.656 [Default:CheckIn:E] Stopped 2021-07-27T18:15:35.656Z,1627409735.656 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-27T18:15:35.656Z,1627409735.656 [Default:CheckIn] Stopped 2021-07-27T18:15:35.656Z,1627409735.656 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-27T18:15:35.656Z,1627409735.656 [Default:CheckIn](INFO): Running loop #14 2021-07-27T18:15:35.656Z,1627409735.656 [Default:CheckIn] Running Loop=14 2021-07-27T18:15:35.656Z,1627409735.656 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-27T18:15:35.656Z,1627409735.656 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-27T18:15:37.658Z,1627409737.658 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181536.00,A,3648.16639,N,12147.28139,W,0.058,354.51,270721,,,A*7C 2021-07-27T18:15:37.661Z,1627409737.661 [NAL9602](INFO): GPS fix at 20210727T181536: (36.802773, -121.788023) 2021-07-27T18:15:37.684Z,1627409737.684 [Default:CheckIn:Read_GPS] Stopped 2021-07-27T18:15:37.684Z,1627409737.684 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-27T18:15:46.227Z,1627409746.227 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210727T165552/Courier0039.lzma 2021-07-27T18:15:47.229Z,1627409747.229 [DataOverHttps](INFO): Moved sent file to Logs/20210727T165552/Courier0039.lzma.bak 2021-07-27T18:15:47.229Z,1627409747.229 [DataOverHttps](INFO): SBD MOMSN=15764192 2021-07-27T18:16:05.495Z,1627409765.495 [DataOverHttps](INFO): Sending 205 bytes from file Logs/20210727T165552/Express0040.lzma 2021-07-27T18:16:06.497Z,1627409766.497 [DataOverHttps](INFO): Moved sent file to Logs/20210727T165552/Express0040.lzma.bak 2021-07-27T18:16:06.497Z,1627409766.497 [DataOverHttps](INFO): SBD MOMSN=15764195 2021-07-27T18:16:10.037Z,1627409770.037 [Default:CheckIn:Read_Iridium] Stopped 2021-07-27T18:16:10.037Z,1627409770.037 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-27T18:16:10.037Z,1627409770.037 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-27T18:20:40.479Z,1627410040.479 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-27T18:21:10.411Z,1627410070.411 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-27T18:21:10.411Z,1627410070.411 [Default:CheckIn:C.Wait] Stopped 2021-07-27T18:21:10.411Z,1627410070.411 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-27T18:21:10.412Z,1627410070.412 [Default:CheckIn:D] Running Loop=1 2021-07-27T18:21:10.789Z,1627410070.789 [Default:CheckIn:D] Stopped 2021-07-27T18:21:10.789Z,1627410070.789 [Default:CheckIn:E] Running Loop=1 2021-07-27T18:21:11.187Z,1627410071.187 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-27T18:21:11.199Z,1627410071.199 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 90.879875 min 2021-07-27T18:21:11.200Z,1627410071.200 [Default:CheckIn:E] Stopped 2021-07-27T18:21:11.200Z,1627410071.200 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-27T18:21:11.200Z,1627410071.200 [Default:CheckIn] Stopped 2021-07-27T18:21:11.200Z,1627410071.200 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-27T18:21:11.200Z,1627410071.200 [Default:CheckIn](INFO): Running loop #15 2021-07-27T18:21:11.200Z,1627410071.200 [Default:CheckIn] Running Loop=15 2021-07-27T18:21:11.200Z,1627410071.200 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-27T18:21:11.200Z,1627410071.200 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-27T18:21:13.199Z,1627410073.199 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182112.00,A,3648.16616,N,12147.27987,W,0.156,354.51,270721,,,A*7D 2021-07-27T18:21:13.201Z,1627410073.201 [NAL9602](INFO): GPS fix at 20210727T182112: (36.802769, -121.787998) 2021-07-27T18:21:13.231Z,1627410073.231 [Default:CheckIn:Read_GPS] Stopped 2021-07-27T18:21:13.231Z,1627410073.231 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-27T18:21:22.387Z,1627410082.387 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210727T165552/Courier0042.lzma 2021-07-27T18:21:23.389Z,1627410083.389 [DataOverHttps](INFO): Moved sent file to Logs/20210727T165552/Courier0042.lzma.bak 2021-07-27T18:21:23.389Z,1627410083.389 [DataOverHttps](INFO): SBD MOMSN=15764199 2021-07-27T18:21:42.815Z,1627410102.815 [DataOverHttps](INFO): Sending 205 bytes from file Logs/20210727T165552/Express0043.lzma 2021-07-27T18:21:43.817Z,1627410103.817 [DataOverHttps](INFO): Moved sent file to Logs/20210727T165552/Express0043.lzma.bak 2021-07-27T18:21:43.817Z,1627410103.817 [DataOverHttps](INFO): SBD MOMSN=15764202 2021-07-27T18:21:43.901Z,1627410103.901 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-07-27T18:21:43.979Z,1627410103.979 [NAL9602](ERROR): received: +CSQ:0 OK552, 2, 0, 0, 0 OK 2021-07-27T18:21:47.188Z,1627410107.188 [Default:CheckIn:Read_Iridium] Stopped 2021-07-27T18:21:47.188Z,1627410107.188 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-27T18:21:47.188Z,1627410107.188 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-27T18:26:15.473Z,1627410375.473 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-27T18:26:46.176Z,1627410406.176 [NAL9602](INFO): Not Powering down - fast GPS 2021-07-27T18:26:47.816Z,1627410407.816 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-07-27T18:26:47.816Z,1627410407.816 [Default:CheckIn:C.Wait] Stopped 2021-07-27T18:26:47.817Z,1627410407.817 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-27T18:26:47.817Z,1627410407.817 [Default:CheckIn:D] Running Loop=1 2021-07-27T18:26:48.223Z,1627410408.223 [Default:CheckIn:D] Stopped 2021-07-27T18:26:48.223Z,1627410408.223 [Default:CheckIn:E] Running Loop=1 2021-07-27T18:26:48.611Z,1627410408.611 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 96.503776 min 2021-07-27T18:26:48.611Z,1627410408.611 [Default:CheckIn:E] Stopped 2021-07-27T18:26:48.611Z,1627410408.611 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-07-27T18:26:48.611Z,1627410408.611 [Default:CheckIn] Stopped 2021-07-27T18:26:48.611Z,1627410408.611 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-27T18:26:48.612Z,1627410408.612 [Default:CheckIn](INFO): Running loop #16 2021-07-27T18:26:48.612Z,1627410408.612 [Default:CheckIn] Running Loop=16 2021-07-27T18:26:48.612Z,1627410408.612 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-07-27T18:26:48.612Z,1627410408.612 [Default:CheckIn:Read_GPS] Running Loop=1 2021-07-27T18:26:50.622Z,1627410410.622 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182649.00,A,3648.16451,N,12147.28112,W,0.019,354.51,270721,,,A*74 2021-07-27T18:26:50.625Z,1627410410.625 [NAL9602](INFO): GPS fix at 20210727T182649: (36.802742, -121.788019) 2021-07-27T18:26:50.636Z,1627410410.636 [Default:CheckIn:Read_GPS] Stopped 2021-07-27T18:26:50.636Z,1627410410.636 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-07-27T18:26:59.163Z,1627410419.163 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210727T165552/Courier0045.lzma 2021-07-27T18:27:00.165Z,1627410420.165 [DataOverHttps](INFO): Moved sent file to Logs/20210727T165552/Courier0045.lzma.bak 2021-07-27T18:27:00.165Z,1627410420.165 [DataOverHttps](INFO): SBD MOMSN=15764214 2021-07-27T18:27:18.515Z,1627410438.515 [DataOverHttps](INFO): Sending 205 bytes from file Logs/20210727T165552/Express0046.lzma 2021-07-27T18:27:19.517Z,1627410439.517 [DataOverHttps](INFO): Moved sent file to Logs/20210727T165552/Express0046.lzma.bak 2021-07-27T18:27:19.517Z,1627410439.517 [DataOverHttps](INFO): SBD MOMSN=15764217 2021-07-27T18:27:21.417Z,1627410441.417 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-07-27T18:27:21.499Z,1627410441.499 [NAL9602](ERROR): received: +CSQ:0 OK552, 2, 0, 0, 0 OK 2021-07-27T18:27:23.089Z,1627410443.089 [Default:CheckIn:Read_Iridium] Stopped 2021-07-27T18:27:23.089Z,1627410443.089 [Default:CheckIn:C.Wait] Running Loop=1 2021-07-27T18:27:23.089Z,1627410443.089 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-07-27T18:31:46.229Z,1627410706.229 [DataOverHttps](IMPORTANT): SBD MTMSN=20210727T183145 2021-07-27T18:31:49.297Z,1627410709.297 [BPC1](ERROR): BPC1B: No match for serial number 1717 in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file). 2021-07-27T18:31:52.497Z,1627410712.497 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-07-27T18:31:53.995Z,1627410713.995 [DataOverHttps](INFO): Received command:configSet VerticalControl.kiDepthOff 0.01 m/s persist;configSet VerticalControl.kiDepthBuoy 0.3 1/s persist;restart app 2021-07-27T18:31:54.475Z,1627410714.475 [CommandLine](IMPORTANT): got command configSet VerticalControl.kiDepthOff 0.010000 meter_per_second persist 2021-07-27T18:31:54.478Z,1627410714.478 [CommandLine](IMPORTANT): got command configSet VerticalControl.kiDepthBuoy 0.300000 reciprocal_second persist 2021-07-27T18:31:54.480Z,1627410714.480 [CommandLine](IMPORTANT): got command restart application 2021-07-27T18:31:55.483Z,1627410715.483 [Supervisor](INFO): Stop Mission called by Supervisor::terminate 2021-07-27T18:31:55.484Z,1627410715.484 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2021-07-27T18:31:55.484Z,1627410715.484 [CommandLine ThreadHandler](INFO): Thread cancelled. 2021-07-27T18:31:55.491Z,1627410715.491 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2021-07-27T18:31:55.491Z,1627410715.491 [CommandLine ThreadHandler](INFO): Thread cancelled. 2021-07-27T18:31:55.492Z,1627410715.492 [CommandLine](INFO): Join timeout helper Thread ID is 1051 2021-07-27T18:31:55.499Z,1627410715.499 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2021-07-27T18:31:55.499Z,1627410715.499 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2021-07-27T18:31:55.500Z,1627410715.500 [NavChartDb](INFO): Join timeout helper Thread ID is 1052 2021-07-27T18:31:55.839Z,1627410715.839 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2021-07-27T18:31:55.840Z,1627410715.840 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2021-07-27T18:31:55.855Z,1627410715.855 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2021-07-27T18:31:55.855Z,1627410715.855 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2021-07-27T18:31:55.856Z,1627410715.856 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 1053 2021-07-27T18:31:55.979Z,1627410715.979 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2021-07-27T18:31:55.980Z,1627410715.980 [WetLabsBB2FL](INFO): Powering down 2021-07-27T18:31:55.980Z,1627410715.980 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2021-07-27T18:31:55.995Z,1627410715.995 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2021-07-27T18:31:55.995Z,1627410715.995 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2021-07-27T18:31:55.996Z,1627410715.996 [CTD_Seabird](INFO): Join timeout helper Thread ID is 1054 2021-07-27T18:31:56.435Z,1627410716.435 [CTD_Seabird](INFO): Powering down 2021-07-27T18:31:56.447Z,1627410716.447 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread. 2021-07-27T18:31:56.447Z,1627410716.447 [CTD_Seabird](INFO): Powering down 2021-07-27T18:31:56.459Z,1627410716.459 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2021-07-27T18:31:56.486Z,1627410716.486 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2021-07-27T18:31:56.486Z,1627410716.486 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2021-07-27T18:31:56.486Z,1627410716.486 [Radio_Surface](INFO): Join timeout helper Thread ID is 1055 2021-07-27T18:31:56.675Z,1627410716.675 [Radio_Surface](INFO): Powering down 2021-07-27T18:31:56.676Z,1627410716.676 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2021-07-27T18:31:56.677Z,1627410716.677 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2021-07-27T18:31:56.696Z,1627410716.696 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler 2021-07-27T18:31:56.696Z,1627410716.696 [Onboard ThreadHandler](INFO): Thread cancelled. 2021-07-27T18:31:56.697Z,1627410716.697 [Onboard](INFO): Join timeout helper Thread ID is 1056 2021-07-27T18:31:57.026Z,1627410717.026 [DataOverHttps](INFO): Radio surface powered OFF, will not connect. 2021-07-27T18:31:57.595Z,1627410717.595 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread. 2021-07-27T18:31:57.596Z,1627410717.596 [Onboard ThreadHandler](INFO): Thread cancelled. 2021-07-27T18:31:57.604Z,1627410717.604 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2021-07-27T18:31:57.604Z,1627410717.604 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2021-07-27T18:31:57.604Z,1627410717.604 [DataOverHttps](INFO): Join timeout helper Thread ID is 1057 2021-07-27T18:31:58.027Z,1627410718.027 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2021-07-27T18:31:58.028Z,1627410718.028 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2021-07-27T18:31:58.048Z,1627410718.048 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2021-07-27T18:31:58.048Z,1627410718.048 [logger ThreadHandler](INFO): Thread cancelled. 2021-07-27T18:31:58.048Z,1627410718.048 [logger](INFO): Join timeout helper Thread ID is 1058 2021-07-27T18:31:58.095Z,1627410718.095 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2021-07-27T18:31:58.096Z,1627410718.096 [logger ThreadHandler](INFO): Thread cancelled. 2021-07-27T18:31:58.108Z,1627410718.108 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2021-07-27T18:31:58.108Z,1627410718.108 [CommandLine ThreadHandler](INFO): Thread cancelled. 2021-07-27T18:31:58.108Z,1627410718.108 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2021-07-27T18:31:58.108Z,1627410718.108 [controlThread ThreadHandler](INFO): Thread cancelled. 2021-07-27T18:31:58.109Z,1627410718.109 [controlThread](INFO): Join timeout helper Thread ID is 1059 2021-07-27T18:31:58.135Z,1627410718.135 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2021-07-27T18:31:58.136Z,1627410718.136 [controlThread](DEBUG): Uninitializing ControlThread 2021-07-27T18:31:58.136Z,1627410718.136 [AHRS_M2](INFO): Powering down 2021-07-27T18:31:58.208Z,1627410718.208 [NAL9602](INFO): Powering down 2021-07-27T18:31:58.211Z,1627410718.211 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2021-07-27T18:31:58.212Z,1627410718.212 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2021-07-27T18:31:58.213Z,1627410718.213 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2021-07-27T18:31:58.213Z,1627410718.213 [MissionManager](INFO): Uninitializing Mission Default 2021-07-27T18:31:58.213Z,1627410718.213 [Default] Stopped 2021-07-27T18:31:58.213Z,1627410718.213 [Default](DEBUG): Aggregate::uninitialize Default 2021-07-27T18:31:58.214Z,1627410718.214 [Default:B.GoToSurface] Stopped 2021-07-27T18:31:58.214Z,1627410718.214 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2021-07-27T18:31:58.214Z,1627410718.214 [Default:CheckIn] Stopped 2021-07-27T18:31:58.214Z,1627410718.214 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-07-27T18:31:58.214Z,1627410718.214 [Default:CheckIn:C.Wait] Stopped 2021-07-27T18:31:58.214Z,1627410718.214 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-07-27T18:31:58.217Z,1627410718.217 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2021-07-27T18:31:58.218Z,1627410718.218 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2021-07-27T18:31:58.218Z,1627410718.218 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2021-07-27T18:31:58.218Z,1627410718.218 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2021-07-27T18:31:58.219Z,1627410718.219 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2021-07-27T18:31:58.219Z,1627410718.219 [BuoyancyServo](INFO): Powering down 2021-07-27T18:31:58.231Z,1627410718.231 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2021-07-27T18:31:58.232Z,1627410718.232 [ElevatorServo](INFO): Powering down 2021-07-27T18:31:58.232Z,1627410718.232 [MassServo](DEBUG): Uninitialize Mass Servo. 2021-07-27T18:31:58.233Z,1627410718.233 [MassServo](INFO): Powering down 2021-07-27T18:31:58.233Z,1627410718.233 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2021-07-27T18:31:58.234Z,1627410718.234 [RudderServo](INFO): Powering down 2021-07-27T18:31:58.234Z,1627410718.234 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2021-07-27T18:31:58.235Z,1627410718.235 [ThrusterServo](INFO): Powering down 2021-07-27T18:31:58.236Z,1627410718.236 [SBIT](DEBUG): Uninitialize SBIT Component. 2021-07-27T18:31:58.236Z,1627410718.236 [IBIT](DEBUG): Uninitialize IBIT Component. 2021-07-27T18:31:58.236Z,1627410718.236 [CBIT](DEBUG): Uninitialize CBIT Component. 2021-07-27T18:31:58.236Z,1627410718.236 [CBIT](DEBUG): Powering off loads. 2021-07-27T18:31:58.247Z,1627410718.247 [CBIT](DEBUG): Disabling WDT. 2021-07-27T18:31:58.259Z,1627410718.259 [CBIT](DEBUG): Opening all GF detection circuits. 2021-07-27T18:31:58.260Z,1627410718.260 [controlThread ThreadHandler](INFO): Thread cancelled. 2021-07-27T18:31:58.302Z,1627410718.302 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2021-07-27T18:31:58.305Z,1627410718.305 [Onboard ThreadHandler](INFO): Thread cancelled. 2021-07-27T18:31:58.311Z,1627410718.311 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2021-07-27T18:31:58.383Z,1627410718.383 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2021-07-27T18:31:58.387Z,1627410718.387 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2021-07-27T18:31:58.426Z,1627410718.426 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2021-07-27T18:31:58.502Z,1627410718.502 [logger ThreadHandler](INFO): Thread cancelled.