2022-05-04T18:12:02.761Z,1651687922.761 [CommandExec](IMPORTANT): got command restart logs 2022-05-04T18:12:07.573Z,1651687927.573 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-04T18:12:37.806Z,1651687957.806 [DVL_micro](ERROR): only read 0 of 4 data items 2022-05-04T18:12:37.806Z,1651687957.806 [DVL_micro](ERROR): Failed to parse: :BI-00053,-00089,+00000,I 2022-05-04T18:12:38.712Z,1651687958.712 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-04T18:12:55.452Z,1651687975.452 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.002943 2022-05-04T18:13:33.533Z,1651688013.533 [ESPComponent](CRITICAL): [sample #1] ESP sampling sequence terminated with error: In state S_PREPARING_SHOW_STATUS got exception while awaiting result for cmd='showStatus' exception=<>. Elapsed time since command issued: 0.8082 2022-05-04T18:13:33.533Z,1651688013.533 [ESPComponent] Communications Fault, FailCount= 1 2022-05-04T18:13:33.533Z,1651688013.533 [ESPComponent](ERROR): Communications Fault 2022-05-04T18:13:33.610Z,1651688013.610 [CBIT](INFO): Critical error at 20220504T181333 2022-05-04T18:13:33.612Z,1651688013.612 [CBIT](ERROR): Communications Fault in component: ESPComponent 2022-05-04T18:13:33.937Z,1651688013.937 [ESPComponent](IMPORTANT): [sample #1] No ESP summary messages. 2022-05-04T18:13:33.938Z,1651688013.938 [ESPComponent](INFO): powering down ESP 2022-05-04T18:13:33.938Z,1651688013.938 [ESPComponent](INFO): powering down ESP secondary power supply 2022-05-04T18:13:34.852Z,1651688014.852 [CBIT](INFO): Clearing failed state for component ESPComponent 2022-05-04T18:13:34.852Z,1651688014.852 [ESPComponent] No Fault, FailCount= 1 2022-05-04T18:13:35.552Z,1651688015.552 [ESPComponent](INFO): powering down ESP 2022-05-04T18:13:35.553Z,1651688015.553 [ESPComponent](INFO): powering down ESP secondary power supply 2022-05-04T18:15:42.854Z,1651688142.854 [Default:CheckIn:Read_GPS](INFO): Timed out from 2022-05-04T18:10:42.7Z 2022-05-04T18:15:42.855Z,1651688142.855 [Default:CheckIn:Read_GPS] Stopped 2022-05-04T18:15:42.855Z,1651688142.855 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-04T18:15:50.611Z,1651688150.611 [DataOverHttps](INFO): Sending 193 bytes from file Logs/20220504T174528/Courier0013.lzma 2022-05-04T18:15:51.614Z,1651688151.614 [DataOverHttps](INFO): Moved sent file to Logs/20220504T174528/Courier0013.lzma.bak 2022-05-04T18:15:51.614Z,1651688151.614 [DataOverHttps](INFO): SBD MOMSN=16689200 2022-05-04T18:16:08.840Z,1651688168.840 [DataOverHttps](INFO): Sending 409 bytes from file Logs/20220504T181202/Courier0000.lzma 2022-05-04T18:16:09.842Z,1651688169.842 [DataOverHttps](INFO): Moved sent file to Logs/20220504T181202/Courier0000.lzma.bak 2022-05-04T18:16:09.842Z,1651688169.842 [DataOverHttps](INFO): SBD MOMSN=16689203 2022-05-04T18:16:14.823Z,1651688174.823 [DVL_micro](ERROR): only read 0 of 4 data items 2022-05-04T18:16:14.828Z,1651688174.828 [DVL_micro](ERROR): Failed to parse: :RD9,+9999..99,+9999.99 2022-05-04T18:16:26.475Z,1651688186.475 [DataOverHttps](INFO): Sending 2226 bytes from file Logs/20220504T174528/Express0014.lzma 2022-05-04T18:16:27.474Z,1651688187.474 [DataOverHttps](INFO): Moved sent file to Logs/20220504T174528/Express0014.lzma.bak 2022-05-04T18:16:27.474Z,1651688187.474 [DataOverHttps](INFO): SBD MOMSN=16689208 2022-05-04T18:16:29.714Z,1651688189.714 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-05-04T18:16:43.797Z,1651688203.797 [DataOverHttps](INFO): Sending 312 bytes from file Logs/20220504T181202/Express0001.lzma 2022-05-04T18:16:44.798Z,1651688204.798 [DataOverHttps](INFO): Moved sent file to Logs/20220504T181202/Express0001.lzma.bak 2022-05-04T18:16:44.798Z,1651688204.798 [DataOverHttps](INFO): SBD MOMSN=16689313 2022-05-04T18:16:46.317Z,1651688206.317 [Default:CheckIn:Read_Iridium] Stopped 2022-05-04T18:16:46.317Z,1651688206.317 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-04T18:16:46.317Z,1651688206.317 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-04T18:17:00.447Z,1651688220.447 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-04T18:20:57.697Z,1651688457.697 [DVL_micro](ERROR): Failed to parse: :SA,-03.09,+05.07,203.1 2022-05-04T18:21:46.941Z,1651688506.941 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-04T18:21:46.941Z,1651688506.941 [Default:CheckIn:C.Wait] Stopped 2022-05-04T18:21:46.941Z,1651688506.941 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-04T18:21:46.942Z,1651688506.942 [Default:CheckIn:D] Running Loop=1 2022-05-04T18:21:47.362Z,1651688507.362 [Default:CheckIn:D] Stopped 2022-05-04T18:21:47.362Z,1651688507.362 [Default:CheckIn:E] Running Loop=1 2022-05-04T18:21:47.752Z,1651688507.752 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 11.305919 min 2022-05-04T18:21:47.752Z,1651688507.752 [Default:CheckIn:E] Stopped 2022-05-04T18:21:47.753Z,1651688507.753 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-04T18:21:47.753Z,1651688507.753 [Default:CheckIn] Stopped 2022-05-04T18:21:47.753Z,1651688507.753 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-04T18:21:47.753Z,1651688507.753 [Default:CheckIn](INFO): Running loop #2 2022-05-04T18:21:47.753Z,1651688507.753 [Default:CheckIn] Running Loop=2 2022-05-04T18:21:47.753Z,1651688507.753 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-04T18:21:47.753Z,1651688507.753 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-04T18:21:49.347Z,1651688509.347 [NAL9602](FAULT): GPS failed to acquire within timeout. 2022-05-04T18:21:49.347Z,1651688509.347 [NAL9602] Data Fault, FailCount= 2 2022-05-04T18:21:49.347Z,1651688509.347 [NAL9602](ERROR): Data Fault 2022-05-04T18:21:49.383Z,1651688509.383 [CBIT](ERROR): Data Fault in component: NAL9602 2022-05-04T18:21:49.750Z,1651688509.750 [NAL9602](INFO): Powering down 2022-05-04T18:21:50.590Z,1651688510.590 [CBIT](INFO): Clearing failed state for component NAL9602 2022-05-04T18:21:50.590Z,1651688510.590 [NAL9602] No Fault, FailCount= 2 2022-05-04T18:22:20.051Z,1651688540.051 [NAL9602](INFO): Powering up NAL9602 2022-05-04T18:22:30.975Z,1651688550.975 [NAL9602](INFO): NAL9602 initialized 2022-05-04T18:25:48.139Z,1651688748.139 [DVL_micro](ERROR): Failed to parse: :R99,+9999.99,+9999.99,+9999.99 2022-05-04T18:26:47.915Z,1651688807.915 [Default:CheckIn:Read_GPS](INFO): Timed out from 2022-05-04T18:21:47.8Z 2022-05-04T18:26:47.915Z,1651688807.915 [Default:CheckIn:Read_GPS] Stopped 2022-05-04T18:26:47.916Z,1651688807.916 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-04T18:26:55.283Z,1651688815.283 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20220504T181202/Courier0003.lzma 2022-05-04T18:26:56.285Z,1651688816.285 [DataOverHttps](INFO): Moved sent file to Logs/20220504T181202/Courier0003.lzma.bak 2022-05-04T18:26:56.286Z,1651688816.286 [DataOverHttps](INFO): SBD MOMSN=16689316 2022-05-04T18:27:12.108Z,1651688832.108 [DataOverHttps](INFO): Sending 267 bytes from file Logs/20220504T181202/Express0004.lzma 2022-05-04T18:27:13.109Z,1651688833.109 [DataOverHttps](INFO): Moved sent file to Logs/20220504T181202/Express0004.lzma.bak 2022-05-04T18:27:13.110Z,1651688833.110 [DataOverHttps](INFO): SBD MOMSN=16689318 2022-05-04T18:27:14.625Z,1651688834.625 [Default:CheckIn:Read_Iridium] Stopped 2022-05-04T18:27:14.625Z,1651688834.625 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-04T18:27:14.625Z,1651688834.625 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-04T18:27:34.802Z,1651688854.802 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-05-04T18:28:05.500Z,1651688885.500 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-04T18:30:25.724Z,1651689025.724 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2022-05-04T18:30:25.724Z,1651689025.724 [DVL_micro](ERROR): Failed to parse: :TS,000,+22.5,0000.0,1489.0,000 2022-05-04T18:32:15.249Z,1651689135.249 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-04T18:32:15.249Z,1651689135.249 [Default:CheckIn:C.Wait] Stopped 2022-05-04T18:32:15.249Z,1651689135.249 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-04T18:32:15.249Z,1651689135.249 [Default:CheckIn:D] Running Loop=1 2022-05-04T18:32:15.643Z,1651689135.643 [Default:CheckIn:D] Stopped 2022-05-04T18:32:15.643Z,1651689135.643 [Default:CheckIn:E] Running Loop=1 2022-05-04T18:32:16.039Z,1651689136.039 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 21.777264 min 2022-05-04T18:32:16.039Z,1651689136.039 [Default:CheckIn:E] Stopped 2022-05-04T18:32:16.039Z,1651689136.039 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-04T18:32:16.039Z,1651689136.039 [Default:CheckIn] Stopped 2022-05-04T18:32:16.039Z,1651689136.039 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-04T18:32:16.039Z,1651689136.039 [Default:CheckIn](INFO): Running loop #3 2022-05-04T18:32:16.039Z,1651689136.039 [Default:CheckIn] Running Loop=3 2022-05-04T18:32:16.039Z,1651689136.039 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-04T18:32:16.039Z,1651689136.039 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-04T18:32:48.751Z,1651689168.751 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-05-04T18:32:48.824Z,1651689168.824 [NAL9602](ERROR): received: +CSQ:0 OK 2022-05-04T18:36:49.560Z,1651689409.560 [DVL_micro](ERROR): only read 3 of 4 data items 2022-05-04T18:36:49.560Z,1651689409.560 [DVL_micro](ERROR): Failed to parse: :RD,+99999.99,+9999.99,+9999.99 2022-05-04T18:37:16.210Z,1651689436.210 [Default:CheckIn:Read_GPS](INFO): Timed out from 2022-05-04T18:32:16.0Z 2022-05-04T18:37:16.210Z,1651689436.210 [Default:CheckIn:Read_GPS] Stopped 2022-05-04T18:37:16.210Z,1651689436.210 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-04T18:37:19.447Z,1651689439.447 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-05-04T18:37:23.527Z,1651689443.527 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20220504T181202/Courier0006.lzma 2022-05-04T18:37:24.530Z,1651689444.530 [DataOverHttps](INFO): Moved sent file to Logs/20220504T181202/Courier0006.lzma.bak 2022-05-04T18:37:24.530Z,1651689444.530 [DataOverHttps](INFO): SBD MOMSN=16689323 2022-05-04T18:37:40.144Z,1651689460.144 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20220504T181202/Express0007.lzma 2022-05-04T18:37:41.145Z,1651689461.145 [DataOverHttps](INFO): Moved sent file to Logs/20220504T181202/Express0007.lzma.bak 2022-05-04T18:37:41.146Z,1651689461.146 [DataOverHttps](INFO): SBD MOMSN=16689325 2022-05-04T18:37:42.490Z,1651689462.490 [Default:CheckIn:Read_Iridium] Stopped 2022-05-04T18:37:42.490Z,1651689462.490 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-04T18:37:42.490Z,1651689462.490 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-04T18:37:50.153Z,1651689470.153 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-04T18:40:13.566Z,1651689613.566 [DVL_micro](ERROR): Failed to parse: :SA,-03.18,+05.06,203.1 2022-05-04T18:42:43.049Z,1651689763.049 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-04T18:42:43.049Z,1651689763.049 [Default:CheckIn:C.Wait] Stopped 2022-05-04T18:42:43.049Z,1651689763.049 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-04T18:42:43.050Z,1651689763.050 [Default:CheckIn:D] Running Loop=1 2022-05-04T18:42:43.460Z,1651689763.460 [Default:CheckIn:D] Stopped 2022-05-04T18:42:43.460Z,1651689763.460 [Default:CheckIn:E] Running Loop=1 2022-05-04T18:42:43.877Z,1651689763.877 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 32.240873 min 2022-05-04T18:42:43.877Z,1651689763.877 [Default:CheckIn:E] Stopped 2022-05-04T18:42:43.877Z,1651689763.877 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-04T18:42:43.877Z,1651689763.877 [Default:CheckIn] Stopped 2022-05-04T18:42:43.878Z,1651689763.878 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-04T18:42:43.878Z,1651689763.878 [Default:CheckIn](INFO): Running loop #4 2022-05-04T18:42:43.878Z,1651689763.878 [Default:CheckIn] Running Loop=4 2022-05-04T18:42:43.878Z,1651689763.878 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-04T18:42:43.878Z,1651689763.878 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-04T18:42:45.460Z,1651689765.460 [NAL9602](FAULT): GPS failed to acquire within timeout. 2022-05-04T18:42:45.460Z,1651689765.460 [NAL9602] Data Fault, FailCount= 3 2022-05-04T18:42:45.460Z,1651689765.460 [NAL9602](ERROR): Data Fault 2022-05-04T18:42:45.502Z,1651689765.502 [CBIT](ERROR): Data Fault in component: NAL9602 2022-05-04T18:42:45.863Z,1651689765.863 [NAL9602](INFO): Powering down 2022-05-04T18:42:46.695Z,1651689766.695 [CBIT](INFO): Clearing failed state for component NAL9602 2022-05-04T18:42:46.695Z,1651689766.695 [NAL9602] No Fault, FailCount= 3 2022-05-04T18:43:16.189Z,1651689796.189 [NAL9602](INFO): Powering up NAL9602 2022-05-04T18:43:27.071Z,1651689807.071 [NAL9602](INFO): NAL9602 initialized 2022-05-04T18:47:44.026Z,1651690064.026 [Default:CheckIn:Read_GPS](INFO): Timed out from 2022-05-04T18:42:43.9Z 2022-05-04T18:47:44.026Z,1651690064.026 [Default:CheckIn:Read_GPS] Stopped 2022-05-04T18:47:44.026Z,1651690064.026 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-04T18:47:51.052Z,1651690071.052 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20220504T181202/Courier0009.lzma 2022-05-04T18:47:52.054Z,1651690072.054 [DataOverHttps](INFO): Moved sent file to Logs/20220504T181202/Courier0009.lzma.bak 2022-05-04T18:47:52.054Z,1651690072.054 [DataOverHttps](INFO): SBD MOMSN=16689329 2022-05-04T18:48:07.792Z,1651690087.792 [DataOverHttps](INFO): Sending 223 bytes from file Logs/20220504T181202/Express0010.lzma 2022-05-04T18:48:08.794Z,1651690088.794 [DataOverHttps](INFO): Moved sent file to Logs/20220504T181202/Express0010.lzma.bak 2022-05-04T18:48:08.794Z,1651690088.794 [DataOverHttps](INFO): SBD MOMSN=16689331 2022-05-04T18:48:10.291Z,1651690090.291 [Default:CheckIn:Read_Iridium] Stopped 2022-05-04T18:48:10.291Z,1651690090.291 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-04T18:48:10.291Z,1651690090.291 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-04T18:48:30.903Z,1651690110.903 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-05-04T18:49:01.583Z,1651690141.583 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-04T18:50:19.159Z,1651690219.159 [DVL_micro](ERROR): Failed to parse: :B,+00042,-00066,+00000,I 2022-05-04T18:53:10.901Z,1651690390.901 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-04T18:53:10.901Z,1651690390.901 [Default:CheckIn:C.Wait] Stopped 2022-05-04T18:53:10.901Z,1651690390.901 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-04T18:53:10.901Z,1651690390.901 [Default:CheckIn:D] Running Loop=1 2022-05-04T18:53:11.301Z,1651690391.301 [Default:CheckIn:D] Stopped 2022-05-04T18:53:11.301Z,1651690391.301 [Default:CheckIn:E] Running Loop=1 2022-05-04T18:53:11.717Z,1651690391.717 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 42.704903 min 2022-05-04T18:53:11.717Z,1651690391.717 [Default:CheckIn:E] Stopped 2022-05-04T18:53:11.717Z,1651690391.717 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-04T18:53:11.717Z,1651690391.717 [Default:CheckIn] Stopped 2022-05-04T18:53:11.717Z,1651690391.717 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-04T18:53:11.717Z,1651690391.717 [Default:CheckIn](INFO): Running loop #5 2022-05-04T18:53:11.717Z,1651690391.717 [Default:CheckIn] Running Loop=5 2022-05-04T18:53:11.718Z,1651690391.718 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-04T18:53:11.718Z,1651690391.718 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-04T18:53:44.424Z,1651690424.424 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-05-04T18:53:44.504Z,1651690424.504 [NAL9602](ERROR): received: +CSQ:0 OK 2022-05-04T18:53:48.466Z,1651690428.466 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2022-05-04T18:53:48.466Z,1651690428.466 [DVL_micro](ERROR): Failed to parse: :TS0000000,35.0,+22.5,0000.0,1489.0,000 2022-05-04T18:55:37.143Z,1651690537.143 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2022-05-04T18:55:37.143Z,1651690537.143 [DVL_micro](ERROR): Failed to parse: :TS,000000,35.0,+22.6,0000.0,148 2022-05-04T18:58:11.909Z,1651690691.909 [Default:CheckIn:Read_GPS](INFO): Timed out from 2022-05-04T18:53:11.7Z 2022-05-04T18:58:11.909Z,1651690691.909 [Default:CheckIn:Read_GPS] Stopped 2022-05-04T18:58:11.909Z,1651690691.909 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-04T18:58:15.929Z,1651690695.929 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-05-04T18:58:18.859Z,1651690698.859 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20220504T181202/Courier0012.lzma 2022-05-04T18:58:19.864Z,1651690699.864 [DataOverHttps](INFO): Moved sent file to Logs/20220504T181202/Courier0012.lzma.bak 2022-05-04T18:58:19.865Z,1651690699.865 [DataOverHttps](INFO): SBD MOMSN=16689336 2022-05-04T18:58:35.679Z,1651690715.679 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20220504T181202/Express0013.lzma 2022-05-04T18:58:36.683Z,1651690716.683 [DataOverHttps](INFO): Moved sent file to Logs/20220504T181202/Express0013.lzma.bak 2022-05-04T18:58:36.683Z,1651690716.683 [DataOverHttps](INFO): SBD MOMSN=16689338 2022-05-04T18:58:38.151Z,1651690718.151 [Default:CheckIn:Read_Iridium] Stopped 2022-05-04T18:58:38.152Z,1651690718.152 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-04T18:58:38.152Z,1651690718.152 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-04T18:58:46.611Z,1651690726.611 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-04T19:00:42.168Z,1651690842.168 [DVL_micro](ERROR): only read 3 of 4 data items 2022-05-04T19:00:42.168Z,1651690842.168 [DVL_micro](ERROR): Failed to parse: :BI,-00016,+00017,-00070,+00BD,+00000000.00,+00000000.0000.00,9999.99,000.00 2022-05-04T19:03:38.766Z,1651691018.766 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-04T19:03:38.766Z,1651691018.766 [Default:CheckIn:C.Wait] Stopped 2022-05-04T19:03:38.766Z,1651691018.766 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-04T19:03:38.766Z,1651691018.766 [Default:CheckIn:D] Running Loop=1 2022-05-04T19:03:39.166Z,1651691019.166 [Default:CheckIn:D] Stopped 2022-05-04T19:03:39.166Z,1651691019.166 [Default:CheckIn:E] Running Loop=1 2022-05-04T19:03:39.557Z,1651691019.557 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 53.169320 min 2022-05-04T19:03:39.557Z,1651691019.557 [Default:CheckIn:E] Stopped 2022-05-04T19:03:39.557Z,1651691019.557 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-04T19:03:39.558Z,1651691019.558 [Default:CheckIn] Stopped 2022-05-04T19:03:39.558Z,1651691019.558 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-04T19:03:39.558Z,1651691019.558 [Default:CheckIn](INFO): Running loop #6 2022-05-04T19:03:39.558Z,1651691019.558 [Default:CheckIn] Running Loop=6 2022-05-04T19:03:39.558Z,1651691019.558 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-04T19:03:39.558Z,1651691019.558 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-04T19:03:41.173Z,1651691021.173 [NAL9602](FAULT): GPS failed to acquire within timeout. 2022-05-04T19:03:41.173Z,1651691021.173 [NAL9602] Data Fault, FailCount= 4 2022-05-04T19:03:41.173Z,1651691021.173 [NAL9602](ERROR): Data Fault 2022-05-04T19:03:41.224Z,1651691021.224 [CBIT](ERROR): Data Fault in component: NAL9602 2022-05-04T19:03:41.565Z,1651691021.565 [NAL9602](INFO): Powering down 2022-05-04T19:03:42.398Z,1651691022.398 [CBIT](INFO): Clearing failed state for component NAL9602 2022-05-04T19:03:42.398Z,1651691022.398 [NAL9602] No Fault, FailCount= 4 2022-05-04T19:04:11.869Z,1651691051.869 [NAL9602](INFO): Powering up NAL9602 2022-05-04T19:04:22.775Z,1651691062.775 [NAL9602](INFO): NAL9602 initialized 2022-05-04T19:05:52.460Z,1651691152.460 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2022-05-04T19:05:52.461Z,1651691152.461 [DVL_micro](ERROR): Failed to parse: :TS0000000,35.0,+22.6,0000.0,1489.0,000 2022-05-04T19:08:39.727Z,1651691319.727 [Default:CheckIn:Read_GPS](INFO): Timed out from 2022-05-04T19:03:39.6Z 2022-05-04T19:08:39.727Z,1651691319.727 [Default:CheckIn:Read_GPS] Stopped 2022-05-04T19:08:39.727Z,1651691319.727 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-04T19:08:47.103Z,1651691327.103 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20220504T181202/Courier0015.lzma 2022-05-04T19:08:48.105Z,1651691328.105 [DataOverHttps](INFO): Moved sent file to Logs/20220504T181202/Courier0015.lzma.bak 2022-05-04T19:08:48.106Z,1651691328.106 [DataOverHttps](INFO): SBD MOMSN=16689342 2022-05-04T19:09:03.904Z,1651691343.904 [DataOverHttps](INFO): Sending 224 bytes from file Logs/20220504T181202/Express0016.lzma 2022-05-04T19:09:04.906Z,1651691344.906 [DataOverHttps](INFO): Moved sent file to Logs/20220504T181202/Express0016.lzma.bak 2022-05-04T19:09:04.906Z,1651691344.906 [DataOverHttps](INFO): SBD MOMSN=16689344 2022-05-04T19:09:06.398Z,1651691346.398 [Default:CheckIn:Read_Iridium] Stopped 2022-05-04T19:09:06.398Z,1651691346.398 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-04T19:09:06.398Z,1651691346.398 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-04T19:09:26.584Z,1651691366.584 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-05-04T19:09:57.289Z,1651691397.289 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-04T19:11:27.837Z,1651691487.837 [DVL_micro](ERROR): only read 1 of 4 data items 2022-05-04T19:11:27.837Z,1651691487.837 [DVL_micro](ERROR): Failed to parse: :RD,+9999..99,+99999.99 2022-05-04T19:11:32.687Z,1651691492.687 [DVL_micro](ERROR): only read 3 of 4 data items 2022-05-04T19:11:32.687Z,1651691492.687 [DVL_micro](ERROR): Failed to parse: :BI,+00032,+00022,-0000,I 2022-05-04T19:14:07.033Z,1651691647.033 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-04T19:14:07.033Z,1651691647.033 [Default:CheckIn:C.Wait] Stopped 2022-05-04T19:14:07.033Z,1651691647.033 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-04T19:14:07.033Z,1651691647.033 [Default:CheckIn:D] Running Loop=1 2022-05-04T19:14:07.421Z,1651691647.421 [Default:CheckIn:D] Stopped 2022-05-04T19:14:07.421Z,1651691647.421 [Default:CheckIn:E] Running Loop=1 2022-05-04T19:14:07.824Z,1651691647.824 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 63.640226 min 2022-05-04T19:14:07.825Z,1651691647.825 [Default:CheckIn:E] Stopped 2022-05-04T19:14:07.825Z,1651691647.825 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-04T19:14:07.825Z,1651691647.825 [Default:CheckIn] Stopped 2022-05-04T19:14:07.825Z,1651691647.825 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-04T19:14:07.825Z,1651691647.825 [Default:CheckIn](INFO): Running loop #7 2022-05-04T19:14:07.825Z,1651691647.825 [Default:CheckIn] Running Loop=7 2022-05-04T19:14:07.825Z,1651691647.825 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-04T19:14:07.825Z,1651691647.825 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-04T19:14:40.539Z,1651691680.539 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-05-04T19:14:40.624Z,1651691680.624 [NAL9602](ERROR): received: +CSQ:0 OK 2022-05-04T19:17:03.173Z,1651691823.173 [DVL_micro](ERROR): only read 3 of 4 data items 2022-05-04T19:17:03.173Z,1651691823.173 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+9999.99,+99999.99 2022-05-04T19:19:08.029Z,1651691948.029 [Default:CheckIn:Read_GPS](INFO): Timed out from 2022-05-04T19:14:07.8Z 2022-05-04T19:19:08.029Z,1651691948.029 [Default:CheckIn:Read_GPS] Stopped 2022-05-04T19:19:08.029Z,1651691948.029 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-04T19:19:11.669Z,1651691951.669 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-05-04T19:19:15.751Z,1651691955.751 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20220504T181202/Courier0018.lzma 2022-05-04T19:19:16.753Z,1651691956.753 [DataOverHttps](INFO): Moved sent file to Logs/20220504T181202/Courier0018.lzma.bak 2022-05-04T19:19:16.754Z,1651691956.754 [DataOverHttps](INFO): SBD MOMSN=16689349 2022-05-04T19:19:32.479Z,1651691972.479 [DataOverHttps](INFO): Sending 208 bytes from file Logs/20220504T181202/Express0019.lzma 2022-05-04T19:19:33.482Z,1651691973.482 [DataOverHttps](INFO): Moved sent file to Logs/20220504T181202/Express0019.lzma.bak 2022-05-04T19:19:33.482Z,1651691973.482 [DataOverHttps](INFO): SBD MOMSN=16689351 2022-05-04T19:19:35.065Z,1651691975.065 [Default:CheckIn:Read_Iridium] Stopped 2022-05-04T19:19:35.065Z,1651691975.065 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-04T19:19:35.065Z,1651691975.065 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-04T19:19:42.331Z,1651691982.331 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-04T19:23:08.444Z,1651692188.444 [DVL_micro](ERROR): DVL uart error: serial timeout 2022-05-04T19:23:08.444Z,1651692188.444 [DVL_micro] Communications Fault, FailCount= 1 2022-05-04T19:23:08.444Z,1651692188.444 [DVL_micro](ERROR): Communications Fault 2022-05-04T19:23:08.444Z,1651692188.444 [DVL_micro](ERROR): Failed to parse: 2022-05-04T19:23:08.493Z,1651692188.493 [CBIT](ERROR): Communications Fault in component: DVL_micro 2022-05-04T19:23:08.840Z,1651692188.840 [DVL_micro](INFO): Powering down 2022-05-04T19:23:09.644Z,1651692189.644 [CBIT](INFO): Clearing failed state for component DVL_micro 2022-05-04T19:23:09.644Z,1651692189.644 [DVL_micro] No Fault, FailCount= 1 2022-05-04T19:24:35.661Z,1651692275.661 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-04T19:24:35.661Z,1651692275.661 [Default:CheckIn:C.Wait] Stopped 2022-05-04T19:24:35.662Z,1651692275.662 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-04T19:24:35.662Z,1651692275.662 [Default:CheckIn:D] Running Loop=1 2022-05-04T19:24:36.068Z,1651692276.068 [Default:CheckIn:D] Stopped 2022-05-04T19:24:36.068Z,1651692276.068 [Default:CheckIn:E] Running Loop=1 2022-05-04T19:24:36.454Z,1651692276.454 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 74.117676 min 2022-05-04T19:24:36.454Z,1651692276.454 [Default:CheckIn:E] Stopped 2022-05-04T19:24:36.454Z,1651692276.454 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-04T19:24:36.454Z,1651692276.454 [Default:CheckIn] Stopped 2022-05-04T19:24:36.454Z,1651692276.454 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-04T19:24:36.454Z,1651692276.454 [Default:CheckIn](INFO): Running loop #8 2022-05-04T19:24:36.454Z,1651692276.454 [Default:CheckIn] Running Loop=8 2022-05-04T19:24:36.454Z,1651692276.454 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-04T19:24:36.455Z,1651692276.455 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-04T19:24:38.069Z,1651692278.069 [NAL9602](FAULT): GPS failed to acquire within timeout. 2022-05-04T19:24:38.069Z,1651692278.069 [NAL9602] Data Fault, FailCount= 5 2022-05-04T19:24:38.069Z,1651692278.069 [NAL9602](ERROR): Data Fault 2022-05-04T19:24:38.087Z,1651692278.087 [CBIT](ERROR): Data Fault in component: NAL9602 2022-05-04T19:24:38.088Z,1651692278.088 [CBIT](CRITICAL): Data Fault in component: NAL9602 2022-05-04T19:24:38.469Z,1651692278.469 [NAL9602](INFO): Powering down 2022-05-04T19:24:38.486Z,1651692278.486 [CBIT](INFO): Critical error at 20220504T192438 2022-05-04T19:24:55.914Z,1651692295.914 [CommandExec](IMPORTANT): got command show variable shortestDistance 2022-05-04T19:24:56.031Z,1651692296.031 [CommandExec](IMPORTANT): ShortestDistanceToPolygonSidesCalculator.loadAtStartup (bool) 2022-05-04T19:24:56.031Z,1651692296.031 [CommandExec](IMPORTANT): ShortestDistanceToPolygonSidesCalculator.verbosity (count) 2022-05-04T19:24:56.034Z,1651692296.034 [CommandExec](IMPORTANT): ShortestDistanceToPolygonSidesCalculator.latVertex1 (degree) 2022-05-04T19:24:56.034Z,1651692296.034 [CommandExec](IMPORTANT): ShortestDistanceToPolygonSidesCalculator.lonVertex1 (degree) 2022-05-04T19:24:56.035Z,1651692296.035 [CommandExec](IMPORTANT): ShortestDistanceToPolygonSidesCalculator.latVertex2 (degree) 2022-05-04T19:24:56.035Z,1651692296.035 [CommandExec](IMPORTANT): ShortestDistanceToPolygonSidesCalculator.lonVertex2 (degree) 2022-05-04T19:24:56.036Z,1651692296.036 [CommandExec](IMPORTANT): ShortestDistanceToPolygonSidesCalculator.latVertex3 (degree) 2022-05-04T19:24:56.036Z,1651692296.036 [CommandExec](IMPORTANT): ShortestDistanceToPolygonSidesCalculator.lonVertex3 (degree) 2022-05-04T19:24:56.037Z,1651692296.037 [CommandExec](IMPORTANT): ShortestDistanceToPolygonSidesCalculator.latVertex4 (degree) 2022-05-04T19:24:56.037Z,1651692296.037 [CommandExec](IMPORTANT): ShortestDistanceToPolygonSidesCalculator.lonVertex4 (degree) 2022-05-04T19:24:56.038Z,1651692296.038 [CommandExec](IMPORTANT): ShortestDistanceToPolygonSidesCalculator.latVertex5 (degree) 2022-05-04T19:24:56.038Z,1651692296.038 [CommandExec](IMPORTANT): ShortestDistanceToPolygonSidesCalculator.lonVertex5 (degree) 2022-05-04T19:24:56.038Z,1651692296.038 [CommandExec](IMPORTANT): ShortestDistanceToPolygonSidesCalculator.latVertex6 (degree) 2022-05-04T19:24:56.039Z,1651692296.039 [CommandExec](IMPORTANT): ShortestDistanceToPolygonSidesCalculator.lonVertex6 (degree) 2022-05-04T19:24:56.039Z,1651692296.039 [CommandExec](IMPORTANT): ShortestDistanceToPolygonSidesCalculator.latVertex7 (degree) 2022-05-04T19:24:56.040Z,1651692296.040 [CommandExec](IMPORTANT): ShortestDistanceToPolygonSidesCalculator.lonVertex7 (degree) 2022-05-04T19:24:56.040Z,1651692296.040 [CommandExec](IMPORTANT): ShortestDistanceToPolygonSidesCalculator.latVertex8 (degree) 2022-05-04T19:24:56.041Z,1651692296.041 [CommandExec](IMPORTANT): ShortestDistanceToPolygonSidesCalculator.lonVertex8 (degree) 2022-05-04T19:24:56.041Z,1651692296.041 [CommandExec](IMPORTANT): ShortestDistanceToPolygonSidesCalculator.latVertex9 (degree) 2022-05-04T19:24:56.041Z,1651692296.041 [CommandExec](IMPORTANT): ShortestDistanceToPolygonSidesCalculator.lonVertex9 (degree) 2022-05-04T19:24:56.042Z,1651692296.042 [CommandExec](IMPORTANT): ShortestDistanceToPolygonSidesCalculator.latVertex10 (degree) 2022-05-04T19:24:56.042Z,1651692296.042 [CommandExec](IMPORTANT): ShortestDistanceToPolygonSidesCalculator.lonVertex10 (degree) 2022-05-04T19:24:56.101Z,1651692296.101 [CommandExec](IMPORTANT): ShortestDistanceToPolygonSidesCalculator.enableBroadcast (bool) 2022-05-04T19:24:56.101Z,1651692296.101 [CommandExec](IMPORTANT): ShortestDistanceToPolygonSidesCalculator.shortest_distance_to_polygon_sides (meter) 2022-05-04T19:24:56.102Z,1651692296.102 [CommandExec](IMPORTANT): ShortestDistanceToPolygonSidesCalculator.side_shortest_distance (count) 2022-05-04T19:24:56.102Z,1651692296.102 [CommandExec](IMPORTANT): ShortestDistanceToPolygonSidesCalculator.inside_polygon (bool) 2022-05-04T19:25:14.483Z,1651692314.483 [CommandExec](IMPORTANT): got command get ShortestDistanceToPolygonSidesCalculator.verbosity 2022-05-04T19:25:14.483Z,1651692314.483 [CommandExec](IMPORTANT): ShortestDistanceToPolygonSidesCalculator.verbosity 0 count 2022-05-04T19:25:43.515Z,1651692343.515 [DVL_micro](ERROR): only read 3 of 4 data items 2022-05-04T19:25:43.515Z,1651692343.515 [DVL_micro](ERROR): Failed to parse: :BI,-00121,+00122,-00026, 2022-05-04T19:26:38.085Z,1651692398.085 [CBIT](INFO): Clearing failed state for component NAL9602 2022-05-04T19:26:38.085Z,1651692398.085 [NAL9602] No Fault, FailCount= 5 2022-05-04T19:26:38.451Z,1651692398.451 [NAL9602](INFO): Powering up NAL9602 2022-05-04T19:26:49.365Z,1651692409.365 [NAL9602](INFO): NAL9602 initialized 2022-05-04T19:29:36.668Z,1651692576.668 [Default:CheckIn:Read_GPS](INFO): Timed out from 2022-05-04T19:24:36.5Z 2022-05-04T19:29:36.669Z,1651692576.669 [Default:CheckIn:Read_GPS] Stopped 2022-05-04T19:29:36.669Z,1651692576.669 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-04T19:29:44.255Z,1651692584.255 [DataOverHttps](INFO): Sending 105 bytes from file Logs/20220504T181202/Courier0021.lzma 2022-05-04T19:29:45.258Z,1651692585.258 [DataOverHttps](INFO): Moved sent file to Logs/20220504T181202/Courier0021.lzma.bak 2022-05-04T19:29:45.258Z,1651692585.258 [DataOverHttps](INFO): SBD MOMSN=16689355 2022-05-04T19:30:01.252Z,1651692601.252 [DataOverHttps](INFO): Sending 535 bytes from file Logs/20220504T181202/Express0022.lzma 2022-05-04T19:30:02.254Z,1651692602.254 [DataOverHttps](INFO): Moved sent file to Logs/20220504T181202/Express0022.lzma.bak 2022-05-04T19:30:02.254Z,1651692602.254 [DataOverHttps](INFO): SBD MOMSN=16689358 2022-05-04T19:30:03.715Z,1651692603.715 [Default:CheckIn:Read_Iridium] Stopped 2022-05-04T19:30:03.715Z,1651692603.715 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-04T19:30:03.715Z,1651692603.715 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-04T19:31:53.191Z,1651692713.191 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-05-04T19:31:56.025Z,1651692716.025 [DVL_micro](ERROR): only read 3 of 4 data items 2022-05-04T19:31:56.025Z,1651692716.025 [DVL_micro](ERROR): Failed to parse: :BI,-00152,+00077,-0002,I 2022-05-04T19:32:18.689Z,1651692738.689 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2022-05-04T19:32:18.689Z,1651692738.689 [DVL_micro](ERROR): Failed to parse::TS,00000000000000,35.0,+22.7,0000.0,1489.0I,-00041,+0008,+00000,A 2022-05-04T19:32:23.926Z,1651692743.926 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-04T19:35:04.313Z,1651692904.313 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-04T19:35:04.314Z,1651692904.314 [Default:CheckIn:C.Wait] Stopped 2022-05-04T19:35:04.314Z,1651692904.314 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-04T19:35:04.314Z,1651692904.314 [Default:CheckIn:D] Running Loop=1 2022-05-04T19:35:04.697Z,1651692904.697 [Default:CheckIn:D] Stopped 2022-05-04T19:35:04.697Z,1651692904.697 [Default:CheckIn:E] Running Loop=1 2022-05-04T19:35:05.112Z,1651692905.112 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 84.594832 min 2022-05-04T19:35:05.112Z,1651692905.112 [Default:CheckIn:E] Stopped 2022-05-04T19:35:05.112Z,1651692905.112 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-04T19:35:05.112Z,1651692905.112 [Default:CheckIn] Stopped 2022-05-04T19:35:05.112Z,1651692905.112 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-04T19:35:05.113Z,1651692905.113 [Default:CheckIn](INFO): Running loop #9 2022-05-04T19:35:05.113Z,1651692905.113 [Default:CheckIn] Running Loop=9 2022-05-04T19:35:05.113Z,1651692905.113 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-04T19:35:05.113Z,1651692905.113 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-04T19:39:41.845Z,1651693181.845 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2022-05-04T19:39:41.845Z,1651693181.845 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+22.7,000.0,000 2022-05-04T19:40:05.283Z,1651693205.283 [Default:CheckIn:Read_GPS](INFO): Timed out from 2022-05-04T19:35:05.1Z 2022-05-04T19:40:05.283Z,1651693205.283 [Default:CheckIn:Read_GPS] Stopped 2022-05-04T19:40:05.284Z,1651693205.284 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-04T19:40:08.899Z,1651693208.899 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-05-04T19:40:12.292Z,1651693212.292 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20220504T181202/Courier0024.lzma 2022-05-04T19:40:13.289Z,1651693213.289 [DataOverHttps](INFO): Moved sent file to Logs/20220504T181202/Courier0024.lzma.bak 2022-05-04T19:40:13.290Z,1651693213.290 [DataOverHttps](INFO): SBD MOMSN=16689392 2022-05-04T19:40:29.256Z,1651693229.256 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20220504T181202/Express0025.lzma 2022-05-04T19:40:30.258Z,1651693230.258 [DataOverHttps](INFO): Moved sent file to Logs/20220504T181202/Express0025.lzma.bak 2022-05-04T19:40:30.258Z,1651693230.258 [DataOverHttps](INFO): SBD MOMSN=16689394 2022-05-04T19:40:31.535Z,1651693231.535 [Default:CheckIn:Read_Iridium] Stopped 2022-05-04T19:40:31.535Z,1651693231.535 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-04T19:40:31.535Z,1651693231.535 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-04T19:40:39.627Z,1651693239.627 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-04T19:45:32.121Z,1651693532.121 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-04T19:45:32.121Z,1651693532.121 [Default:CheckIn:C.Wait] Stopped 2022-05-04T19:45:32.121Z,1651693532.121 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-04T19:45:32.121Z,1651693532.121 [Default:CheckIn:D] Running Loop=1 2022-05-04T19:45:32.517Z,1651693532.517 [Default:CheckIn:D] Stopped 2022-05-04T19:45:32.517Z,1651693532.517 [Default:CheckIn:E] Running Loop=1 2022-05-04T19:45:32.921Z,1651693532.921 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 95.058496 min 2022-05-04T19:45:32.921Z,1651693532.921 [Default:CheckIn:E] Stopped 2022-05-04T19:45:32.921Z,1651693532.921 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-04T19:45:32.921Z,1651693532.921 [Default:CheckIn] Stopped 2022-05-04T19:45:32.921Z,1651693532.921 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-04T19:45:32.922Z,1651693532.922 [Default:CheckIn](INFO): Running loop #10 2022-05-04T19:45:32.922Z,1651693532.922 [Default:CheckIn] Running Loop=10 2022-05-04T19:45:32.922Z,1651693532.922 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-04T19:45:32.922Z,1651693532.922 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-04T19:45:34.533Z,1651693534.533 [NAL9602](FAULT): GPS failed to acquire within timeout. 2022-05-04T19:45:34.533Z,1651693534.533 [NAL9602] Data Fault, FailCount= 1 2022-05-04T19:45:34.533Z,1651693534.533 [NAL9602](ERROR): Data Fault 2022-05-04T19:45:34.551Z,1651693534.551 [CBIT](ERROR): Data Fault in component: NAL9602 2022-05-04T19:45:34.937Z,1651693534.937 [NAL9602](INFO): Powering down 2022-05-04T19:45:35.781Z,1651693535.781 [CBIT](INFO): Clearing failed state for component NAL9602 2022-05-04T19:45:35.781Z,1651693535.781 [NAL9602] No Fault, FailCount= 1 2022-05-04T19:46:05.239Z,1651693565.239 [NAL9602](INFO): Powering up NAL9602 2022-05-04T19:46:16.143Z,1651693576.143 [NAL9602](INFO): NAL9602 initialized 2022-05-04T19:46:29.477Z,1651693589.477 [DVL_micro](ERROR): only read 0 of 4 data items 2022-05-04T19:46:29.477Z,1651693589.477 [DVL_micro](ERROR): Failed to parse: :RD,,+9999.99,+9999.99,+9999.99 2022-05-04T19:46:34.729Z,1651693594.729 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2022-05-04T19:46:34.729Z,1651693594.729 [DVL_micro](ERROR): Failed to parse: :TS0000000,35.0,+22.7,0000.0,1489.0,000 2022-05-04T19:50:33.097Z,1651693833.097 [Default:CheckIn:Read_GPS](INFO): Timed out from 2022-05-04T19:45:32.9Z 2022-05-04T19:50:33.097Z,1651693833.097 [Default:CheckIn:Read_GPS] Stopped 2022-05-04T19:50:33.098Z,1651693833.098 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-04T19:50:42.471Z,1651693842.471 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20220504T181202/Courier0027.lzma 2022-05-04T19:50:43.474Z,1651693843.474 [DataOverHttps](INFO): Moved sent file to Logs/20220504T181202/Courier0027.lzma.bak 2022-05-04T19:50:43.474Z,1651693843.474 [DataOverHttps](INFO): SBD MOMSN=16689398 2022-05-04T19:51:00.238Z,1651693860.238 [DataOverHttps](INFO): Sending 225 bytes from file Logs/20220504T181202/Express0028.lzma 2022-05-04T19:51:01.238Z,1651693861.238 [DataOverHttps](INFO): Moved sent file to Logs/20220504T181202/Express0028.lzma.bak 2022-05-04T19:51:01.238Z,1651693861.238 [DataOverHttps](INFO): SBD MOMSN=16689400 2022-05-04T19:51:02.652Z,1651693862.652 [Default:CheckIn:Read_Iridium] Stopped 2022-05-04T19:51:02.652Z,1651693862.652 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-04T19:51:02.652Z,1651693862.652 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-04T19:51:19.989Z,1651693879.989 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-05-04T19:51:50.689Z,1651693910.689 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-04T19:53:30.081Z,1651694010.081 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+9999.99,+9999.99,+9999.99 2022-05-04T19:56:03.206Z,1651694163.206 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-04T19:56:03.206Z,1651694163.206 [Default:CheckIn:C.Wait] Stopped 2022-05-04T19:56:03.206Z,1651694163.206 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-04T19:56:03.207Z,1651694163.207 [Default:CheckIn:D] Running Loop=1 2022-05-04T19:56:03.635Z,1651694163.635 [Default:CheckIn:D] Stopped 2022-05-04T19:56:03.635Z,1651694163.635 [Default:CheckIn:E] Running Loop=1 2022-05-04T19:56:04.013Z,1651694164.013 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 105.577140 min 2022-05-04T19:56:04.013Z,1651694164.013 [Default:CheckIn:E] Stopped 2022-05-04T19:56:04.013Z,1651694164.013 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-04T19:56:04.013Z,1651694164.013 [Default:CheckIn] Stopped 2022-05-04T19:56:04.014Z,1651694164.014 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-04T19:56:04.014Z,1651694164.014 [Default:CheckIn](INFO): Running loop #11 2022-05-04T19:56:04.014Z,1651694164.014 [Default:CheckIn] Running Loop=11 2022-05-04T19:56:04.014Z,1651694164.014 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-04T19:56:04.014Z,1651694164.014 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-04T19:56:36.719Z,1651694196.719 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-05-04T19:56:36.804Z,1651694196.804 [NAL9602](ERROR): received: +CSQ:0 OK 2022-05-04T19:57:31.665Z,1651694251.665 [DVL_micro](ERROR): Failed to parse: :SA,-03.10,+05.08,203.2 2022-05-04T20:00:22.935Z,1651694422.935 [CommandExec](IMPORTANT): got command configSet ESPComponent.simulateHardware 1 bool persist 2022-05-04T20:00:22.936Z,1651694422.936 [CommandExec](IMPORTANT): configSet ESPComponent.simulateHardware requires a restart to take effect. 2022-05-04T20:00:57.723Z,1651694457.723 [DVL_micro](ERROR): only read 2 of 4 data items 2022-05-04T20:00:57.724Z,1651694457.724 [DVL_micro](ERROR): Failed to parse: :BI,-00036,+00112+00000,I 2022-05-04T20:01:04.190Z,1651694464.190 [Default:CheckIn:Read_GPS](INFO): Timed out from 2022-05-04T19:56:04.0Z 2022-05-04T20:01:04.190Z,1651694464.190 [Default:CheckIn:Read_GPS] Stopped 2022-05-04T20:01:04.190Z,1651694464.190 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-04T20:01:07.825Z,1651694467.825 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-05-04T20:01:10.703Z,1651694470.703 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20220504T181202/Courier0030.lzma 2022-05-04T20:01:11.698Z,1651694471.698 [DataOverHttps](INFO): Moved sent file to Logs/20220504T181202/Courier0030.lzma.bak 2022-05-04T20:01:11.698Z,1651694471.698 [DataOverHttps](INFO): SBD MOMSN=16689405 2022-05-04T20:01:27.660Z,1651694487.660 [DataOverHttps](INFO): Sending 299 bytes from file Logs/20220504T181202/Express0031.lzma 2022-05-04T20:01:28.662Z,1651694488.662 [DataOverHttps](INFO): Moved sent file to Logs/20220504T181202/Express0031.lzma.bak 2022-05-04T20:01:28.662Z,1651694488.662 [DataOverHttps](INFO): SBD MOMSN=16689407 2022-05-04T20:01:30.045Z,1651694490.045 [Default:CheckIn:Read_Iridium] Stopped 2022-05-04T20:01:30.045Z,1651694490.045 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-04T20:01:30.045Z,1651694490.045 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-04T20:01:38.519Z,1651694498.519 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-04T20:06:30.628Z,1651694790.628 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-04T20:06:30.628Z,1651694790.628 [Default:CheckIn:C.Wait] Stopped 2022-05-04T20:06:30.628Z,1651694790.628 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-04T20:06:30.628Z,1651694790.628 [Default:CheckIn:D] Running Loop=1 2022-05-04T20:06:31.043Z,1651694791.043 [Default:CheckIn:D] Stopped 2022-05-04T20:06:31.043Z,1651694791.043 [Default:CheckIn:E] Running Loop=1 2022-05-04T20:06:31.435Z,1651694791.435 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 116.033936 min 2022-05-04T20:06:31.435Z,1651694791.435 [Default:CheckIn:E] Stopped 2022-05-04T20:06:31.435Z,1651694791.435 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-04T20:06:31.435Z,1651694791.435 [Default:CheckIn] Stopped 2022-05-04T20:06:31.435Z,1651694791.435 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-04T20:06:31.435Z,1651694791.435 [Default:CheckIn](INFO): Running loop #12 2022-05-04T20:06:31.436Z,1651694791.436 [Default:CheckIn] Running Loop=12 2022-05-04T20:06:31.436Z,1651694791.436 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-04T20:06:31.436Z,1651694791.436 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-04T20:06:33.035Z,1651694793.035 [NAL9602](FAULT): GPS failed to acquire within timeout. 2022-05-04T20:06:33.035Z,1651694793.035 [NAL9602] Data Fault, FailCount= 2 2022-05-04T20:06:33.035Z,1651694793.035 [NAL9602](ERROR): Data Fault 2022-05-04T20:06:33.053Z,1651694793.053 [CBIT](ERROR): Data Fault in component: NAL9602 2022-05-04T20:06:33.453Z,1651694793.453 [NAL9602](INFO): Powering down 2022-05-04T20:06:34.285Z,1651694794.285 [CBIT](INFO): Clearing failed state for component NAL9602 2022-05-04T20:06:34.285Z,1651694794.285 [NAL9602] No Fault, FailCount= 2 2022-05-04T20:07:03.743Z,1651694823.743 [NAL9602](INFO): Powering up NAL9602 2022-05-04T20:07:14.649Z,1651694834.649 [NAL9602](INFO): NAL9602 initialized 2022-05-04T20:08:00.712Z,1651694880.712 [DVL_micro](ERROR): Failed to parse:074,+00125,-00030,+00000,I0000000.00,+00000000.00,+00000000.00,9999.99,000.00 2022-05-04T20:11:31.658Z,1651695091.658 [Default:CheckIn:Read_GPS](INFO): Timed out from 2022-05-04T20:06:31.4Z 2022-05-04T20:11:31.658Z,1651695091.658 [Default:CheckIn:Read_GPS] Stopped 2022-05-04T20:11:31.659Z,1651695091.659 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-04T20:11:37.735Z,1651695097.735 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20220504T181202/Courier0033.lzma 2022-05-04T20:11:38.738Z,1651695098.738 [DataOverHttps](INFO): Moved sent file to Logs/20220504T181202/Courier0033.lzma.bak 2022-05-04T20:11:38.738Z,1651695098.738 [DataOverHttps](INFO): SBD MOMSN=16689413 2022-05-04T20:11:54.656Z,1651695114.656 [DataOverHttps](INFO): Sending 226 bytes from file Logs/20220504T181202/Express0034.lzma 2022-05-04T20:11:55.654Z,1651695115.654 [DataOverHttps](INFO): Moved sent file to Logs/20220504T181202/Express0034.lzma.bak 2022-05-04T20:11:55.654Z,1651695115.654 [DataOverHttps](INFO): SBD MOMSN=16689415 2022-05-04T20:11:57.136Z,1651695117.136 [Default:CheckIn:Read_Iridium] Stopped 2022-05-04T20:11:57.136Z,1651695117.136 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-04T20:11:57.136Z,1651695117.136 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-04T20:12:18.508Z,1651695138.508 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-05-04T20:12:49.215Z,1651695169.215 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-04T20:16:57.699Z,1651695417.699 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-04T20:16:57.699Z,1651695417.699 [Default:CheckIn:C.Wait] Stopped 2022-05-04T20:16:57.699Z,1651695417.699 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-04T20:16:57.699Z,1651695417.699 [Default:CheckIn:D] Running Loop=1 2022-05-04T20:16:58.082Z,1651695418.082 [Default:CheckIn:D] Stopped 2022-05-04T20:16:58.082Z,1651695418.082 [Default:CheckIn:E] Running Loop=1 2022-05-04T20:16:58.490Z,1651695418.490 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 126.484578 min 2022-05-04T20:16:58.490Z,1651695418.490 [Default:CheckIn:E] Stopped 2022-05-04T20:16:58.491Z,1651695418.491 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-04T20:16:58.491Z,1651695418.491 [Default:CheckIn] Stopped 2022-05-04T20:16:58.491Z,1651695418.491 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-04T20:16:58.491Z,1651695418.491 [Default:CheckIn](INFO): Running loop #13 2022-05-04T20:16:58.491Z,1651695418.491 [Default:CheckIn] Running Loop=13 2022-05-04T20:16:58.491Z,1651695418.491 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-04T20:16:58.491Z,1651695418.491 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-04T20:21:58.677Z,1651695718.677 [Default:CheckIn:Read_GPS](INFO): Timed out from 2022-05-04T20:16:58.5Z 2022-05-04T20:21:58.677Z,1651695718.677 [Default:CheckIn:Read_GPS] Stopped 2022-05-04T20:21:58.677Z,1651695718.677 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-04T20:22:02.290Z,1651695722.290 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-05-04T20:22:06.091Z,1651695726.091 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20220504T181202/Courier0036.lzma 2022-05-04T20:22:07.093Z,1651695727.093 [DataOverHttps](INFO): Moved sent file to Logs/20220504T181202/Courier0036.lzma.bak 2022-05-04T20:22:07.094Z,1651695727.094 [DataOverHttps](INFO): SBD MOMSN=16689420 2022-05-04T20:22:22.839Z,1651695742.839 [DataOverHttps](INFO): Sending 209 bytes from file Logs/20220504T181202/Express0037.lzma 2022-05-04T20:22:23.842Z,1651695743.842 [DataOverHttps](INFO): Moved sent file to Logs/20220504T181202/Express0037.lzma.bak 2022-05-04T20:22:23.842Z,1651695743.842 [DataOverHttps](INFO): SBD MOMSN=16689422 2022-05-04T20:22:25.365Z,1651695745.365 [Default:CheckIn:Read_Iridium] Stopped 2022-05-04T20:22:25.365Z,1651695745.365 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-04T20:22:25.365Z,1651695745.365 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-04T20:22:33.015Z,1651695753.015 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-04T20:22:51.619Z,1651695771.619 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2022-05-04T20:22:51.619Z,1651695771.619 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+22.81489.0,000 2022-05-04T20:22:56.539Z,1651695776.539 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2022-05-04T20:22:56.539Z,1651695776.539 [DVL_micro](ERROR): Failed to parse: :TS,000000000000022.8,0000.0,1489.0,000 2022-05-04T20:27:25.947Z,1651696045.947 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-04T20:27:25.947Z,1651696045.947 [Default:CheckIn:C.Wait] Stopped 2022-05-04T20:27:25.952Z,1651696045.952 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-04T20:27:25.953Z,1651696045.953 [Default:CheckIn:D] Running Loop=1 2022-05-04T20:27:26.329Z,1651696046.329 [Default:CheckIn:D] Stopped 2022-05-04T20:27:26.329Z,1651696046.329 [Default:CheckIn:E] Running Loop=1 2022-05-04T20:27:26.747Z,1651696046.747 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 136.955355 min 2022-05-04T20:27:26.747Z,1651696046.747 [Default:CheckIn:E] Stopped 2022-05-04T20:27:26.747Z,1651696046.747 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-04T20:27:26.747Z,1651696046.747 [Default:CheckIn] Stopped 2022-05-04T20:27:26.747Z,1651696046.747 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-04T20:27:26.747Z,1651696046.747 [Default:CheckIn](INFO): Running loop #14 2022-05-04T20:27:26.747Z,1651696046.747 [Default:CheckIn] Running Loop=14 2022-05-04T20:27:26.748Z,1651696046.748 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-04T20:27:26.748Z,1651696046.748 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-04T20:27:28.351Z,1651696048.351 [NAL9602](FAULT): GPS failed to acquire within timeout. 2022-05-04T20:27:28.351Z,1651696048.351 [NAL9602] Data Fault, FailCount= 3 2022-05-04T20:27:28.351Z,1651696048.351 [NAL9602](ERROR): Data Fault 2022-05-04T20:27:28.369Z,1651696048.369 [CBIT](ERROR): Data Fault in component: NAL9602 2022-05-04T20:27:28.754Z,1651696048.754 [NAL9602](INFO): Powering down 2022-05-04T20:27:29.566Z,1651696049.566 [CBIT](INFO): Clearing failed state for component NAL9602 2022-05-04T20:27:29.566Z,1651696049.566 [NAL9602] No Fault, FailCount= 3 2022-05-04T20:27:59.045Z,1651696079.045 [NAL9602](INFO): Powering up NAL9602 2022-05-04T20:28:09.955Z,1651696089.955 [NAL9602](INFO): NAL9602 initialized 2022-05-04T20:30:31.759Z,1651696231.759 [DVL_micro](ERROR): Failed to parse: 0000000000,35.0,+22.8,0000.0,1489.0,000 2022-05-04T20:32:09.653Z,1651696329.653 [DataOverHttps](IMPORTANT): SBD MTMSN=20220504T203208 2022-05-04T20:32:16.996Z,1651696336.996 [DataOverHttps](INFO): Received command: restart sys 2022-05-04T20:32:17.057Z,1651696337.057 [CommandExec](IMPORTANT): got command restart system 2022-05-04T20:32:19.168Z,1651696339.168 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread. 2022-05-04T20:32:19.168Z,1651696339.168 [CommandExec](INFO): Uninitializing the command executive. 2022-05-04T20:32:19.169Z,1651696339.169 [CommandExec](INFO): Uninitializing the command scheduler. 2022-05-04T20:32:19.169Z,1651696339.169 [CommandExec ThreadHandler](INFO): Thread cancelled. 2022-05-04T20:32:19.364Z,1651696339.364 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2022-05-04T20:32:19.364Z,1651696339.364 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2022-05-04T20:32:19.365Z,1651696339.365 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2022-05-04T20:32:19.366Z,1651696339.366 [NavChartDb](INFO): Join timeout helper Thread ID is 1703 2022-05-04T20:32:19.512Z,1651696339.512 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2022-05-04T20:32:19.512Z,1651696339.512 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2022-05-04T20:32:19.524Z,1651696339.524 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2022-05-04T20:32:19.524Z,1651696339.524 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2022-05-04T20:32:19.525Z,1651696339.525 [Radio_Surface](INFO): Join timeout helper Thread ID is 1704 2022-05-04T20:32:19.812Z,1651696339.812 [Radio_Surface](INFO): Powering down 2022-05-04T20:32:19.814Z,1651696339.814 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2022-05-04T20:32:19.814Z,1651696339.814 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2022-05-04T20:32:19.824Z,1651696339.824 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler 2022-05-04T20:32:19.824Z,1651696339.824 [Onboard ThreadHandler](INFO): Thread cancelled. 2022-05-04T20:32:19.825Z,1651696339.825 [Onboard](INFO): Join timeout helper Thread ID is 1705 2022-05-04T20:32:20.004Z,1651696340.004 [DataOverHttps](INFO): Radio surface powered OFF, will not connect. 2022-05-04T20:32:23.408Z,1651696343.408 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread. 2022-05-04T20:32:23.408Z,1651696343.408 [Onboard ThreadHandler](INFO): Thread cancelled. 2022-05-04T20:32:23.416Z,1651696343.416 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2022-05-04T20:32:23.416Z,1651696343.416 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2022-05-04T20:32:23.417Z,1651696343.417 [DataOverHttps](INFO): Join timeout helper Thread ID is 1706 2022-05-04T20:32:24.020Z,1651696344.020 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2022-05-04T20:32:24.020Z,1651696344.020 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2022-05-04T20:32:24.036Z,1651696344.036 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2022-05-04T20:32:24.036Z,1651696344.036 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2022-05-04T20:32:24.036Z,1651696344.036 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 1707 2022-05-04T20:32:24.356Z,1651696344.356 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2022-05-04T20:32:24.356Z,1651696344.356 [WetLabsBB2FL](INFO): Powering down 2022-05-04T20:32:24.357Z,1651696344.357 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2022-05-04T20:32:24.369Z,1651696344.369 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2022-05-04T20:32:24.369Z,1651696344.369 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2022-05-04T20:32:24.370Z,1651696344.370 [CTD_Seabird](INFO): Join timeout helper Thread ID