2022-05-16T16:49:53.865Z,1652719793.865 [CommandExec](IMPORTANT): got command restart logs 2022-05-16T16:49:54.212Z,1652719794.212 [MissionManager](IMPORTANT): Started mission Default 2022-05-16T16:49:54.213Z,1652719794.213 [Default] Running Loop=1 2022-05-16T16:49:54.213Z,1652719794.213 [Default](DEBUG): Aggregate::initialize Default 2022-05-16T16:49:54.213Z,1652719794.213 [Default:B.GoToSurface] Running Loop=1 2022-05-16T16:49:54.213Z,1652719794.213 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2022-05-16T16:49:54.213Z,1652719794.213 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2022-05-16T16:49:54.213Z,1652719794.213 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2022-05-16T16:49:54.214Z,1652719794.214 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2022-05-16T16:49:54.214Z,1652719794.214 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2022-05-16T16:49:54.214Z,1652719794.214 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2022-05-16T16:49:54.215Z,1652719794.215 [Default:A.Wait] Running Loop=1 2022-05-16T16:49:54.215Z,1652719794.215 [Default:A.Wait](DEBUG): Initialize Wait Component. 2022-05-16T16:50:07.539Z,1652719807.539 [Default:A.Wait](INFO): Done Waiting. 2022-05-16T16:50:07.539Z,1652719807.539 [Default:A.Wait] Stopped 2022-05-16T16:50:07.539Z,1652719807.539 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2022-05-16T16:50:07.929Z,1652719807.929 [Default:CheckIn] Running Loop=1 2022-05-16T16:50:07.930Z,1652719807.930 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-16T16:50:07.930Z,1652719807.930 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-16T16:50:09.541Z,1652719809.541 [NAL9602](FAULT): GPS failed to acquire within timeout. 2022-05-16T16:50:09.541Z,1652719809.541 [NAL9602] Data Fault, FailCount= 1 2022-05-16T16:50:09.541Z,1652719809.541 [NAL9602](ERROR): Data Fault 2022-05-16T16:50:09.589Z,1652719809.589 [CBIT](ERROR): Data Fault in component: NAL9602 2022-05-16T16:50:09.939Z,1652719809.939 [NAL9602](INFO): Powering down 2022-05-16T16:50:10.798Z,1652719810.798 [CBIT](INFO): Clearing failed state for component NAL9602 2022-05-16T16:50:10.798Z,1652719810.798 [NAL9602] No Fault, FailCount= 1 2022-05-16T16:50:40.245Z,1652719840.245 [NAL9602](INFO): Powering up NAL9602 2022-05-16T16:50:51.153Z,1652719851.153 [NAL9602](INFO): NAL9602 initialized 2022-05-16T16:54:26.593Z,1652720066.593 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude 2022-05-16T16:55:08.154Z,1652720108.154 [Default:CheckIn:Read_GPS](INFO): Timed out from 2022-05-16T16:50:07.9Z 2022-05-16T16:55:08.154Z,1652720108.154 [Default:CheckIn:Read_GPS] Stopped 2022-05-16T16:55:08.155Z,1652720108.155 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-16T16:55:15.743Z,1652720115.743 [DataOverHttps](INFO): Sending 50 bytes from file Logs/20220514T141718/Courier0864.lzma 2022-05-16T16:55:16.746Z,1652720116.746 [DataOverHttps](INFO): Moved sent file to Logs/20220514T141718/Courier0864.lzma.bak 2022-05-16T16:55:16.746Z,1652720116.746 [DataOverHttps](INFO): SBD MOMSN=16790273 2022-05-16T16:55:33.040Z,1652720133.040 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20220516T164953/Courier0000.lzma 2022-05-16T16:55:34.042Z,1652720134.042 [DataOverHttps](INFO): Moved sent file to Logs/20220516T164953/Courier0000.lzma.bak 2022-05-16T16:55:34.042Z,1652720134.042 [DataOverHttps](INFO): SBD MOMSN=16790275 2022-05-16T16:55:51.588Z,1652720151.588 [DataOverHttps](INFO): Sending 257 bytes from file Logs/20220514T141718/Express0865.lzma 2022-05-16T16:55:52.590Z,1652720152.590 [DataOverHttps](INFO): Moved sent file to Logs/20220514T141718/Express0865.lzma.bak 2022-05-16T16:55:52.590Z,1652720152.590 [DataOverHttps](INFO): SBD MOMSN=16790278 2022-05-16T16:55:54.201Z,1652720154.201 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-05-16T16:56:10.024Z,1652720170.024 [DataOverHttps](INFO): Sending 409 bytes from file Logs/20220516T164953/Express0001.lzma 2022-05-16T16:56:11.026Z,1652720171.026 [DataOverHttps](INFO): Moved sent file to Logs/20220516T164953/Express0001.lzma.bak 2022-05-16T16:56:11.026Z,1652720171.026 [DataOverHttps](INFO): SBD MOMSN=16790283 2022-05-16T16:56:13.615Z,1652720173.615 [Default:CheckIn:Read_Iridium] Stopped 2022-05-16T16:56:13.620Z,1652720173.620 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-16T16:56:13.620Z,1652720173.620 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-16T16:56:24.901Z,1652720184.901 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-16T17:01:14.218Z,1652720474.218 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-16T17:01:14.218Z,1652720474.218 [Default:CheckIn:C.Wait] Stopped 2022-05-16T17:01:14.218Z,1652720474.218 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-16T17:01:14.218Z,1652720474.218 [Default:CheckIn:D] Running Loop=1 2022-05-16T17:01:14.613Z,1652720474.613 [Default:CheckIn:D] Stopped 2022-05-16T17:01:14.614Z,1652720474.614 [Default:CheckIn:E] Running Loop=1 2022-05-16T17:01:15.003Z,1652720475.003 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 11.340014 min 2022-05-16T17:01:15.008Z,1652720475.008 [Default:CheckIn:E] Stopped 2022-05-16T17:01:15.008Z,1652720475.008 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-16T17:01:15.008Z,1652720475.008 [Default:CheckIn] Stopped 2022-05-16T17:01:15.008Z,1652720475.008 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-16T17:01:15.008Z,1652720475.008 [Default:CheckIn](INFO): Running loop #2 2022-05-16T17:01:15.009Z,1652720475.009 [Default:CheckIn] Running Loop=2 2022-05-16T17:01:15.009Z,1652720475.009 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-16T17:01:15.009Z,1652720475.009 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-16T17:01:16.589Z,1652720476.589 [NAL9602](FAULT): GPS failed to acquire within timeout. 2022-05-16T17:01:16.589Z,1652720476.589 [NAL9602] Data Fault, FailCount= 2 2022-05-16T17:01:16.589Z,1652720476.589 [NAL9602](ERROR): Data Fault 2022-05-16T17:01:16.689Z,1652720476.689 [CBIT](ERROR): Data Fault in component: NAL9602 2022-05-16T17:01:17.032Z,1652720477.032 [NAL9602](INFO): Powering down 2022-05-16T17:01:17.891Z,1652720477.891 [CBIT](INFO): Clearing failed state for component NAL9602 2022-05-16T17:01:17.891Z,1652720477.891 [NAL9602] No Fault, FailCount= 2 2022-05-16T17:01:47.293Z,1652720507.293 [NAL9602](INFO): Powering up NAL9602 2022-05-16T17:01:58.199Z,1652720518.199 [NAL9602](INFO): NAL9602 initialized 2022-05-16T17:06:15.161Z,1652720775.161 [Default:CheckIn:Read_GPS](INFO): Timed out from 2022-05-16T17:01:15.0Z 2022-05-16T17:06:15.161Z,1652720775.161 [Default:CheckIn:Read_GPS] Stopped 2022-05-16T17:06:15.161Z,1652720775.161 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-16T17:06:24.903Z,1652720784.903 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20220516T164953/Courier0003.lzma 2022-05-16T17:06:25.906Z,1652720785.906 [DataOverHttps](INFO): Moved sent file to Logs/20220516T164953/Courier0003.lzma.bak 2022-05-16T17:06:25.906Z,1652720785.906 [DataOverHttps](INFO): SBD MOMSN=16790313 2022-05-16T17:06:44.436Z,1652720804.436 [DataOverHttps](INFO): Sending 253 bytes from file Logs/20220516T164953/Express0004.lzma 2022-05-16T17:06:45.437Z,1652720805.437 [DataOverHttps](INFO): Moved sent file to Logs/20220516T164953/Express0004.lzma.bak 2022-05-16T17:06:45.438Z,1652720805.438 [DataOverHttps](INFO): SBD MOMSN=16790315 2022-05-16T17:06:47.924Z,1652720807.924 [Default:CheckIn:Read_Iridium] Stopped 2022-05-16T17:06:47.924Z,1652720807.924 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-16T17:06:47.924Z,1652720807.924 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-16T17:07:02.417Z,1652720822.417 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-05-16T17:07:33.117Z,1652720853.117 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-16T17:11:48.482Z,1652721108.482 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-16T17:11:48.483Z,1652721108.483 [Default:CheckIn:C.Wait] Stopped 2022-05-16T17:11:48.483Z,1652721108.483 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-16T17:11:48.492Z,1652721108.492 [Default:CheckIn:D] Running Loop=1 2022-05-16T17:11:48.911Z,1652721108.911 [Default:CheckIn:D] Stopped 2022-05-16T17:11:48.911Z,1652721108.911 [Default:CheckIn:E] Running Loop=1 2022-05-16T17:11:49.273Z,1652721109.273 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 21.911639 min 2022-05-16T17:11:49.274Z,1652721109.274 [Default:CheckIn:E] Stopped 2022-05-16T17:11:49.274Z,1652721109.274 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-16T17:11:49.274Z,1652721109.274 [Default:CheckIn] Stopped 2022-05-16T17:11:49.274Z,1652721109.274 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-16T17:11:49.274Z,1652721109.274 [Default:CheckIn](INFO): Running loop #3 2022-05-16T17:11:49.274Z,1652721109.274 [Default:CheckIn] Running Loop=3 2022-05-16T17:11:49.274Z,1652721109.274 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-16T17:11:49.274Z,1652721109.274 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-16T17:12:21.977Z,1652721141.977 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-05-16T17:12:22.052Z,1652721142.052 [NAL9602](ERROR): received: +CSQ:0 OK847, 2, 0, 0, 0 OK 2022-05-16T17:16:49.457Z,1652721409.457 [Default:CheckIn:Read_GPS](INFO): Timed out from 2022-05-16T17:11:49.3Z 2022-05-16T17:16:49.457Z,1652721409.457 [Default:CheckIn:Read_GPS] Stopped 2022-05-16T17:16:49.458Z,1652721409.458 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-16T17:16:53.469Z,1652721413.469 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-05-16T17:16:57.123Z,1652721417.123 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20220516T164953/Courier0006.lzma 2022-05-16T17:16:58.126Z,1652721418.126 [DataOverHttps](INFO): Moved sent file to Logs/20220516T164953/Courier0006.lzma.bak 2022-05-16T17:16:58.126Z,1652721418.126 [DataOverHttps](INFO): SBD MOMSN=16790373 2022-05-16T17:17:15.451Z,1652721435.451 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20220516T164953/Express0007.lzma 2022-05-16T17:17:16.454Z,1652721436.454 [DataOverHttps](INFO): Moved sent file to Logs/20220516T164953/Express0007.lzma.bak 2022-05-16T17:17:16.454Z,1652721436.454 [DataOverHttps](INFO): SBD MOMSN=16790375 2022-05-16T17:17:18.949Z,1652721438.949 [Default:CheckIn:Read_Iridium] Stopped 2022-05-16T17:17:18.949Z,1652721438.949 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-16T17:17:18.949Z,1652721438.949 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-16T17:17:24.173Z,1652721444.173 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-16T17:22:19.512Z,1652721739.512 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-16T17:22:19.513Z,1652721739.513 [Default:CheckIn:C.Wait] Stopped 2022-05-16T17:22:19.513Z,1652721739.513 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-16T17:22:19.513Z,1652721739.513 [Default:CheckIn:D] Running Loop=1 2022-05-16T17:22:19.923Z,1652721739.923 [Default:CheckIn:D] Stopped 2022-05-16T17:22:19.923Z,1652721739.923 [Default:CheckIn:E] Running Loop=1 2022-05-16T17:22:20.328Z,1652721740.328 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 32.428505 min 2022-05-16T17:22:20.328Z,1652721740.328 [Default:CheckIn:E] Stopped 2022-05-16T17:22:20.328Z,1652721740.328 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-16T17:22:20.328Z,1652721740.328 [Default:CheckIn] Stopped 2022-05-16T17:22:20.328Z,1652721740.328 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-16T17:22:20.328Z,1652721740.328 [Default:CheckIn](INFO): Running loop #4 2022-05-16T17:22:20.328Z,1652721740.328 [Default:CheckIn] Running Loop=4 2022-05-16T17:22:20.329Z,1652721740.329 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-16T17:22:20.329Z,1652721740.329 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-16T17:22:21.933Z,1652721741.933 [NAL9602](FAULT): GPS failed to acquire within timeout. 2022-05-16T17:22:21.933Z,1652721741.933 [NAL9602] Data Fault, FailCount= 3 2022-05-16T17:22:21.933Z,1652721741.933 [NAL9602](ERROR): Data Fault 2022-05-16T17:22:21.952Z,1652721741.952 [CBIT](ERROR): Data Fault in component: NAL9602 2022-05-16T17:22:22.338Z,1652721742.338 [NAL9602](INFO): Powering down 2022-05-16T17:22:23.194Z,1652721743.194 [CBIT](INFO): Clearing failed state for component NAL9602 2022-05-16T17:22:23.194Z,1652721743.194 [NAL9602] No Fault, FailCount= 3 2022-05-16T17:22:52.633Z,1652721772.633 [NAL9602](INFO): Powering up NAL9602 2022-05-16T17:23:03.539Z,1652721783.539 [NAL9602](INFO): NAL9602 initialized 2022-05-16T17:27:20.547Z,1652722040.547 [Default:CheckIn:Read_GPS](INFO): Timed out from 2022-05-16T17:22:20.3Z 2022-05-16T17:27:20.547Z,1652722040.547 [Default:CheckIn:Read_GPS] Stopped 2022-05-16T17:27:20.547Z,1652722040.547 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-16T17:27:28.079Z,1652722048.079 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20220516T164953/Courier0009.lzma 2022-05-16T17:27:29.082Z,1652722049.082 [DataOverHttps](INFO): Moved sent file to Logs/20220516T164953/Courier0009.lzma.bak 2022-05-16T17:27:29.082Z,1652722049.082 [DataOverHttps](INFO): SBD MOMSN=16790406 2022-05-16T17:27:47.312Z,1652722067.312 [DataOverHttps](INFO): Sending 225 bytes from file Logs/20220516T164953/Express0010.lzma 2022-05-16T17:27:48.314Z,1652722068.314 [DataOverHttps](INFO): Moved sent file to Logs/20220516T164953/Express0010.lzma.bak 2022-05-16T17:27:48.314Z,1652722068.314 [DataOverHttps](INFO): SBD MOMSN=16790408 2022-05-16T17:27:50.850Z,1652722070.850 [Default:CheckIn:Read_Iridium] Stopped 2022-05-16T17:27:50.850Z,1652722070.850 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-16T17:27:50.851Z,1652722070.851 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-16T17:28:06.546Z,1652722086.546 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-05-16T17:28:37.253Z,1652722117.253 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-16T17:32:51.472Z,1652722371.472 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-16T17:32:51.472Z,1652722371.472 [Default:CheckIn:C.Wait] Stopped 2022-05-16T17:32:51.472Z,1652722371.472 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-16T17:32:51.473Z,1652722371.473 [Default:CheckIn:D] Running Loop=1 2022-05-16T17:32:51.847Z,1652722371.847 [Default:CheckIn:D] Stopped 2022-05-16T17:32:51.876Z,1652722371.876 [Default:CheckIn:E] Running Loop=1 2022-05-16T17:32:52.264Z,1652722372.264 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 42.960579 min 2022-05-16T17:32:52.264Z,1652722372.264 [Default:CheckIn:E] Stopped 2022-05-16T17:32:52.264Z,1652722372.264 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-16T17:32:52.265Z,1652722372.265 [Default:CheckIn] Stopped 2022-05-16T17:32:52.265Z,1652722372.265 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-16T17:32:52.265Z,1652722372.265 [Default:CheckIn](INFO): Running loop #5 2022-05-16T17:32:52.265Z,1652722372.265 [Default:CheckIn] Running Loop=5 2022-05-16T17:32:52.265Z,1652722372.265 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-16T17:32:52.265Z,1652722372.265 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-16T17:33:58.577Z,1652722438.577 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude 2022-05-16T17:37:52.402Z,1652722672.402 [Default:CheckIn:Read_GPS](INFO): Timed out from 2022-05-16T17:32:52.3Z 2022-05-16T17:37:52.402Z,1652722672.402 [Default:CheckIn:Read_GPS] Stopped 2022-05-16T17:37:52.402Z,1652722672.402 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-16T17:37:56.837Z,1652722676.837 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-05-16T17:38:00.327Z,1652722680.327 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20220516T164953/Courier0012.lzma 2022-05-16T17:38:01.342Z,1652722681.342 [DataOverHttps](INFO): Moved sent file to Logs/20220516T164953/Courier0012.lzma.bak 2022-05-16T17:38:01.342Z,1652722681.342 [DataOverHttps](INFO): SBD MOMSN=16790448 2022-05-16T17:38:18.804Z,1652722698.804 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20220516T164953/Express0013.lzma 2022-05-16T17:38:19.806Z,1652722699.806 [DataOverHttps](INFO): Moved sent file to Logs/20220516T164953/Express0013.lzma.bak 2022-05-16T17:38:19.806Z,1652722699.806 [DataOverHttps](INFO): SBD MOMSN=16790450 2022-05-16T17:38:22.318Z,1652722702.318 [Default:CheckIn:Read_Iridium] Stopped 2022-05-16T17:38:22.318Z,1652722702.318 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-16T17:38:22.318Z,1652722702.318 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-16T17:38:27.541Z,1652722707.541 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-16T17:43:22.910Z,1652723002.910 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-16T17:43:22.910Z,1652723002.910 [Default:CheckIn:C.Wait] Stopped 2022-05-16T17:43:22.910Z,1652723002.910 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-16T17:43:22.911Z,1652723002.911 [Default:CheckIn:D] Running Loop=1 2022-05-16T17:43:23.280Z,1652723003.280 [Default:CheckIn:D] Stopped 2022-05-16T17:43:23.280Z,1652723003.280 [Default:CheckIn:E] Running Loop=1 2022-05-16T17:43:23.688Z,1652723003.688 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 53.484448 min 2022-05-16T17:43:23.688Z,1652723003.688 [Default:CheckIn:E] Stopped 2022-05-16T17:43:23.688Z,1652723003.688 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-16T17:43:23.688Z,1652723003.688 [Default:CheckIn] Stopped 2022-05-16T17:43:23.689Z,1652723003.689 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-16T17:43:23.689Z,1652723003.689 [Default:CheckIn](INFO): Running loop #6 2022-05-16T17:43:23.689Z,1652723003.689 [Default:CheckIn] Running Loop=6 2022-05-16T17:43:23.689Z,1652723003.689 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-16T17:43:23.689Z,1652723003.689 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-16T17:43:25.294Z,1652723005.294 [NAL9602](FAULT): GPS failed to acquire within timeout. 2022-05-16T17:43:25.294Z,1652723005.294 [NAL9602] Data Fault, FailCount= 4 2022-05-16T17:43:25.294Z,1652723005.294 [NAL9602](ERROR): Data Fault 2022-05-16T17:43:25.313Z,1652723005.313 [CBIT](ERROR): Data Fault in component: NAL9602 2022-05-16T17:43:25.693Z,1652723005.693 [NAL9602](INFO): Powering down 2022-05-16T17:43:26.577Z,1652723006.577 [CBIT](INFO): Clearing failed state for component NAL9602 2022-05-16T17:43:26.577Z,1652723006.577 [NAL9602] No Fault, FailCount= 4 2022-05-16T17:43:56.009Z,1652723036.009 [NAL9602](INFO): Powering up NAL9602 2022-05-16T17:44:06.902Z,1652723046.902 [NAL9602](INFO): NAL9602 initialized 2022-05-16T17:48:23.872Z,1652723303.872 [Default:CheckIn:Read_GPS](INFO): Timed out from 2022-05-16T17:43:23.7Z 2022-05-16T17:48:23.872Z,1652723303.872 [Default:CheckIn:Read_GPS] Stopped 2022-05-16T17:48:23.872Z,1652723303.872 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-16T17:48:56.264Z,1652723336.264 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T17:49:09.902Z,1652723349.902 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-05-16T17:49:11.328Z,1652723351.328 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.275486 2022-05-16T17:49:14.552Z,1652723354.552 [RDI_Pathfinder](ERROR): only read 3 of 4 data items 2022-05-16T17:49:42.452Z,1652723382.452 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T17:50:17.592Z,1652723417.592 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T17:50:52.732Z,1652723452.732 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T17:51:27.888Z,1652723487.888 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T17:52:03.032Z,1652723523.032 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T17:52:38.172Z,1652723558.172 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T17:53:13.316Z,1652723593.316 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T17:53:48.473Z,1652723628.473 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T17:54:23.636Z,1652723663.636 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T17:54:58.776Z,1652723698.776 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T17:55:21.742Z,1652723721.742 [BPC1](ERROR): BPC1B: No match for serial number 1717 in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file). 2022-05-16T17:55:33.916Z,1652723733.916 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T17:56:01.841Z,1652723761.841 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2022-05-16T17:56:01.843Z,1652723761.843 [BPC1](INFO): Received data from all battery sticks. 2022-05-16T17:56:09.056Z,1652723769.056 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T17:56:33.109Z,1652723793.109 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for water mass range. 2022-05-16T17:56:44.216Z,1652723804.216 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T17:57:19.364Z,1652723839.364 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T17:57:54.505Z,1652723874.505 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T17:58:29.644Z,1652723909.644 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T17:59:04.800Z,1652723944.800 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T17:59:39.950Z,1652723979.950 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:00:15.112Z,1652724015.112 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:00:50.268Z,1652724050.268 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:01:25.424Z,1652724085.424 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:02:00.588Z,1652724120.588 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:02:35.728Z,1652724155.728 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:03:10.868Z,1652724190.868 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:03:46.008Z,1652724226.008 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:04:21.164Z,1652724261.164 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:04:56.312Z,1652724296.312 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:05:31.461Z,1652724331.461 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:06:06.605Z,1652724366.605 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:06:41.744Z,1652724401.744 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:07:16.884Z,1652724436.884 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:07:52.024Z,1652724472.024 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:08:27.192Z,1652724507.192 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:09:02.340Z,1652724542.340 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:09:37.492Z,1652724577.492 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:10:12.644Z,1652724612.644 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:10:47.784Z,1652724647.784 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:11:22.924Z,1652724682.924 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:11:58.064Z,1652724718.064 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:12:33.204Z,1652724753.204 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:13:08.348Z,1652724788.348 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:13:43.512Z,1652724823.512 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:14:18.680Z,1652724858.680 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:14:53.828Z,1652724893.828 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:15:28.968Z,1652724928.968 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:16:04.108Z,1652724964.108 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:16:39.248Z,1652724999.248 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:17:14.388Z,1652725034.388 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:17:49.528Z,1652725069.528 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:18:24.668Z,1652725104.668 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:18:59.808Z,1652725139.808 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:19:34.948Z,1652725174.948 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:20:10.088Z,1652725210.088 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:20:45.232Z,1652725245.232 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:21:20.388Z,1652725280.388 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:21:55.544Z,1652725315.544 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:22:30.692Z,1652725350.692 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:23:05.832Z,1652725385.832 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:23:40.972Z,1652725420.972 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:24:16.112Z,1652725456.112 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:24:51.264Z,1652725491.264 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:25:26.408Z,1652725526.408 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:26:01.548Z,1652725561.548 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:26:36.688Z,1652725596.688 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:27:11.832Z,1652725631.832 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:27:46.988Z,1652725666.988 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:28:22.128Z,1652725702.128 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:28:57.268Z,1652725737.268 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:29:32.428Z,1652725772.428 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:30:07.568Z,1652725807.568 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:30:42.728Z,1652725842.728 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:31:17.868Z,1652725877.868 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:31:53.008Z,1652725913.008 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:32:28.176Z,1652725948.176 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:33:03.316Z,1652725983.316 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:33:38.464Z,1652726018.464 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:34:13.612Z,1652726053.612 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:34:48.772Z,1652726088.772 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:35:23.912Z,1652726123.912 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:35:59.052Z,1652726159.052 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:36:34.196Z,1652726194.196 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:37:09.360Z,1652726229.360 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:37:44.505Z,1652726264.505 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:38:19.656Z,1652726299.656 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:38:54.812Z,1652726334.812 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:39:29.952Z,1652726369.952 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:40:05.100Z,1652726405.100 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:40:40.240Z,1652726440.240 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:41:15.392Z,1652726475.392 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:41:50.533Z,1652726510.533 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:42:25.680Z,1652726545.680 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:43:00.820Z,1652726580.820 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:43:35.960Z,1652726615.960 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:44:11.100Z,1652726651.100 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:44:46.240Z,1652726686.240 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:45:21.380Z,1652726721.380 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:45:56.533Z,1652726756.533 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:46:31.672Z,1652726791.672 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:47:06.812Z,1652726826.812 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:47:41.952Z,1652726861.952 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:48:17.108Z,1652726897.108 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:48:52.248Z,1652726932.248 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:49:27.401Z,1652726967.401 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-16T18:49:39.956Z,1652726979.956 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003349 2022-05-16T18:49:47.467Z,1652726987.467 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20220516T164953/Courier0015.lzma 2022-05-16T18:49:48.473Z,1652726988.473 [DataOverHttps](INFO): Moved sent file to Logs/20220516T164953/Courier0015.lzma.bak 2022-05-16T18:49:48.473Z,1652726988.473 [DataOverHttps](INFO): SBD MOMSN=16790562 2022-05-16T18:50:05.903Z,1652727005.903 [DataOverHttps](INFO): Sending 224 bytes from file Logs/20220516T164953/Express0016.lzma 2022-05-16T18:50:06.906Z,1652727006.906 [DataOverHttps](INFO): Moved sent file to Logs/20220516T164953/Express0016.lzma.bak 2022-05-16T18:50:06.906Z,1652727006.906 [DataOverHttps](INFO): SBD MOMSN=16790564 2022-05-16T18:50:09.647Z,1652727009.647 [Default:CheckIn:Read_Iridium] Stopped 2022-05-16T18:50:09.647Z,1652727009.647 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-16T18:50:09.647Z,1652727009.647 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-16T18:50:11.205Z,1652727011.205 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-16T18:55:10.196Z,1652727310.196 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-16T18:55:10.196Z,1652727310.196 [Default:CheckIn:C.Wait] Stopped 2022-05-16T18:55:10.196Z,1652727310.196 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-16T18:55:10.197Z,1652727310.197 [Default:CheckIn:D] Running Loop=1 2022-05-16T18:55:10.617Z,1652727310.617 [Default:CheckIn:D] Stopped 2022-05-16T18:55:10.617Z,1652727310.617 [Default:CheckIn:E] Running Loop=1 2022-05-16T18:55:11.005Z,1652727311.005 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 125.273413 min 2022-05-16T18:55:11.005Z,1652727311.005 [Default:CheckIn:E] Stopped 2022-05-16T18:55:11.005Z,1652727311.005 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-16T18:55:11.005Z,1652727311.005 [Default:CheckIn] Stopped 2022-05-16T18:55:11.005Z,1652727311.005 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-16T18:55:11.005Z,1652727311.005 [Default:CheckIn](INFO): Running loop #7 2022-05-16T18:55:11.005Z,1652727311.005 [Default:CheckIn] Running Loop=7 2022-05-16T18:55:11.005Z,1652727311.005 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-16T18:55:11.006Z,1652727311.006 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-16T18:55:12.614Z,1652727312.614 [NAL9602](FAULT): GPS failed to acquire within timeout. 2022-05-16T18:55:12.614Z,1652727312.614 [NAL9602] Data Fault, FailCount= 5 2022-05-16T18:55:12.614Z,1652727312.614 [NAL9602](ERROR): Data Fault 2022-05-16T18:55:12.653Z,1652727312.653 [CBIT](ERROR): Data Fault in component: NAL9602 2022-05-16T18:55:12.653Z,1652727312.653 [CBIT](CRITICAL): Data Fault in component: NAL9602 2022-05-16T18:55:13.014Z,1652727313.014 [NAL9602](INFO): Powering down 2022-05-16T18:55:13.056Z,1652727313.056 [CBIT](INFO): Critical error at 20220516T185512 2022-05-16T18:57:12.642Z,1652727432.642 [CBIT](INFO): Clearing failed state for component NAL9602 2022-05-16T18:57:12.642Z,1652727432.642 [NAL9602] No Fault, FailCount= 5 2022-05-16T18:57:13.001Z,1652727433.001 [NAL9602](INFO): Powering up NAL9602 2022-05-16T18:57:23.937Z,1652727443.937 [NAL9602](INFO): NAL9602 initialized 2022-05-16T19:00:11.188Z,1652727611.188 [Default:CheckIn:Read_GPS](INFO): Timed out from 2022-05-16T18:55:11.0Z 2022-05-16T19:00:11.188Z,1652727611.188 [Default:CheckIn:Read_GPS] Stopped 2022-05-16T19:00:11.189Z,1652727611.189 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-16T19:00:18.531Z,1652727618.531 [DataOverHttps](INFO): Sending 221 bytes from file Logs/20220516T164953/Courier0018.lzma 2022-05-16T19:00:19.526Z,1652727619.526 [DataOverHttps](INFO): Moved sent file to Logs/20220516T164953/Courier0018.lzma.bak 2022-05-16T19:00:19.526Z,1652727619.526 [DataOverHttps](INFO): SBD MOMSN=16790619 2022-05-16T19:00:42.616Z,1652727642.616 [DataOverHttps](INFO): Sending 226 bytes from file Logs/20220516T164953/Express0019.lzma 2022-05-16T19:00:43.618Z,1652727643.618 [DataOverHttps](INFO): Moved sent file to Logs/20220516T164953/Express0019.lzma.bak 2022-05-16T19:00:43.618Z,1652727643.618 [DataOverHttps](INFO): SBD MOMSN=16790622 2022-05-16T19:00:46.371Z,1652727646.371 [Default:CheckIn:Read_Iridium] Stopped 2022-05-16T19:00:46.396Z,1652727646.396 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-16T19:00:46.396Z,1652727646.396 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-16T19:02:26.949Z,1652727746.949 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-05-16T19:02:57.653Z,1652727777.653 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-16T19:03:31.184Z,1652727811.184 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2022-05-16T19:03:31.186Z,1652727811.186 [BPC1](INFO): Received data from all battery sticks. 2022-05-16T19:05:46.977Z,1652727946.977 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-16T19:05:46.977Z,1652727946.977 [Default:CheckIn:C.Wait] Stopped 2022-05-16T19:05:46.977Z,1652727946.977 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-16T19:05:46.977Z,1652727946.977 [Default:CheckIn:D] Running Loop=1 2022-05-16T19:05:47.392Z,1652727947.392 [Default:CheckIn:D] Stopped 2022-05-16T19:05:47.392Z,1652727947.392 [Default:CheckIn:E] Running Loop=1 2022-05-16T19:05:47.805Z,1652727947.805 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 135.886247 min 2022-05-16T19:05:47.805Z,1652727947.805 [Default:CheckIn:E] Stopped 2022-05-16T19:05:47.805Z,1652727947.805 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-16T19:05:47.805Z,1652727947.805 [Default:CheckIn] Stopped 2022-05-16T19:05:47.805Z,1652727947.805 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-16T19:05:47.806Z,1652727947.806 [Default:CheckIn](INFO): Running loop #8 2022-05-16T19:05:47.806Z,1652727947.806 [Default:CheckIn] Running Loop=8 2022-05-16T19:05:47.806Z,1652727947.806 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-16T19:05:47.806Z,1652727947.806 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-16T19:06:20.507Z,1652727980.507 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-05-16T19:06:20.584Z,1652727980.584 [NAL9602](ERROR): received: +CSQ:0 OK847, 2, 0, 0, 0 OK 2022-05-16T19:08:18.866Z,1652728098.866 [RDI_Pathfinder](ERROR): only read 2 of 4 data items 2022-05-16T19:10:47.958Z,1652728247.958 [Default:CheckIn:Read_GPS](INFO): Timed out from 2022-05-16T19:05:47.8Z 2022-05-16T19:10:47.958Z,1652728247.958 [Default:CheckIn:Read_GPS] Stopped 2022-05-16T19:10:47.958Z,1652728247.958 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-16T19:10:52.029Z,1652728252.029 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-05-16T19:10:55.255Z,1652728255.255 [DataOverHttps](INFO): Sending 50 bytes from file Logs/20220516T164953/Courier0021.lzma 2022-05-16T19:10:56.258Z,1652728256.258 [DataOverHttps](INFO): Moved sent file to Logs/20220516T164953/Courier0021.lzma.bak 2022-05-16T19:10:56.258Z,1652728256.258 [DataOverHttps](INFO): SBD MOMSN=16790654 2022-05-16T19:11:17.673Z,1652728277.673 [DataOverHttps](INFO): Sending 209 bytes from file Logs/20220516T164953/Express0022.lzma 2022-05-16T19:11:18.674Z,1652728278.674 [DataOverHttps](INFO): Moved sent file to Logs/20220516T164953/Express0022.lzma.bak 2022-05-16T19:11:18.674Z,1652728278.674 [DataOverHttps](INFO): SBD MOMSN=16790658 2022-05-16T19:11:22.447Z,1652728282.447 [Default:CheckIn:Read_Iridium] Stopped 2022-05-16T19:11:22.456Z,1652728282.456 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-16T19:11:22.457Z,1652728282.457 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-16T19:11:22.813Z,1652728282.813 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-16T19:16:23.015Z,1652728583.015 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-16T19:16:23.015Z,1652728583.015 [Default:CheckIn:C.Wait] Stopped 2022-05-16T19:16:23.016Z,1652728583.016 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-16T19:16:23.017Z,1652728583.017 [Default:CheckIn:D] Running Loop=1 2022-05-16T19:16:23.415Z,1652728583.415 [Default:CheckIn:D] Stopped 2022-05-16T19:16:23.415Z,1652728583.415 [Default:CheckIn:E] Running Loop=1 2022-05-16T19:16:23.821Z,1652728583.821 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 146.486702 min 2022-05-16T19:16:23.821Z,1652728583.821 [Default:CheckIn:E] Stopped 2022-05-16T19:16:23.821Z,1652728583.821 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-16T19:16:23.821Z,1652728583.821 [Default:CheckIn] Stopped 2022-05-16T19:16:23.821Z,1652728583.821 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-16T19:16:23.821Z,1652728583.821 [Default:CheckIn](INFO): Running loop #9 2022-05-16T19:16:23.822Z,1652728583.822 [Default:CheckIn] Running Loop=9 2022-05-16T19:16:23.822Z,1652728583.822 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-16T19:16:23.822Z,1652728583.822 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-16T19:16:25.417Z,1652728585.417 [NAL9602](FAULT): GPS failed to acquire within timeout. 2022-05-16T19:16:25.417Z,1652728585.417 [NAL9602] Data Fault, FailCount= 1 2022-05-16T19:16:25.417Z,1652728585.417 [NAL9602](ERROR): Data Fault 2022-05-16T19:16:25.453Z,1652728585.453 [CBIT](ERROR): Data Fault in component: NAL9602 2022-05-16T19:16:25.813Z,1652728585.813 [NAL9602](INFO): Powering down 2022-05-16T19:16:26.715Z,1652728586.715 [CBIT](INFO): Clearing failed state for component NAL9602 2022-05-16T19:16:26.715Z,1652728586.715 [NAL9602] No Fault, FailCount= 1 2022-05-16T19:16:56.111Z,1652728616.111 [NAL9602](INFO): Powering up NAL9602 2022-05-16T19:17:07.021Z,1652728627.021 [NAL9602](INFO): NAL9602 initialized 2022-05-16T19:21:23.991Z,1652728883.991 [Default:CheckIn:Read_GPS](INFO): Timed out from 2022-05-16T19:16:23.8Z 2022-05-16T19:21:23.991Z,1652728883.991 [Default:CheckIn:Read_GPS] Stopped 2022-05-16T19:21:23.991Z,1652728883.991 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-16T19:21:31.787Z,1652728891.787 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20220516T164953/Courier0024.lzma 2022-05-16T19:21:32.790Z,1652728892.790 [DataOverHttps](INFO): Moved sent file to Logs/20220516T164953/Courier0024.lzma.bak 2022-05-16T19:21:32.790Z,1652728892.790 [DataOverHttps](INFO): SBD MOMSN=16790689 2022-05-16T19:21:50.537Z,1652728910.537 [DataOverHttps](INFO): Sending 226 bytes from file Logs/20220516T164953/Express0025.lzma 2022-05-16T19:21:51.526Z,1652728911.526 [DataOverHttps](INFO): Moved sent file to Logs/20220516T164953/Express0025.lzma.bak 2022-05-16T19:21:51.526Z,1652728911.526 [DataOverHttps](INFO): SBD MOMSN=16790691 2022-05-16T19:21:53.919Z,1652728913.919 [Default:CheckIn:Read_Iridium] Stopped 2022-05-16T19:21:53.919Z,1652728913.919 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-16T19:21:53.919Z,1652728913.919 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-16T19:22:10.030Z,1652728930.030 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-05-16T19:22:40.733Z,1652728960.733 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-16T19:23:38.933Z,1652729018.933 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude 2022-05-16T19:26:54.533Z,1652729214.533 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-16T19:26:54.534Z,1652729214.534 [Default:CheckIn:C.Wait] Stopped 2022-05-16T19:26:54.534Z,1652729214.534 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-16T19:26:54.535Z,1652729214.535 [Default:CheckIn:D] Running Loop=1 2022-05-16T19:26:54.897Z,1652729214.897 [Default:CheckIn:D] Stopped 2022-05-16T19:26:54.897Z,1652729214.897 [Default:CheckIn:E] Running Loop=1 2022-05-16T19:26:55.267Z,1652729215.267 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 157.011393 min 2022-05-16T19:26:55.267Z,1652729215.267 [Default:CheckIn:E] Stopped 2022-05-16T19:26:55.267Z,1652729215.267 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-16T19:26:55.268Z,1652729215.268 [Default:CheckIn] Stopped 2022-05-16T19:26:55.268Z,1652729215.268 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-16T19:26:55.268Z,1652729215.268 [Default:CheckIn](INFO): Running loop #10 2022-05-16T19:26:55.268Z,1652729215.268 [Default:CheckIn] Running Loop=10 2022-05-16T19:26:55.269Z,1652729215.269 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-16T19:26:55.269Z,1652729215.269 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-16T19:31:55.442Z,1652729515.442 [Default:CheckIn:Read_GPS](INFO): Timed out from 2022-05-16T19:26:55.3Z 2022-05-16T19:31:55.442Z,1652729515.442 [Default:CheckIn:Read_GPS] Stopped 2022-05-16T19:31:55.442Z,1652729515.442 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-16T19:31:59.085Z,1652729519.085 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-05-16T19:32:02.599Z,1652729522.599 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20220516T164953/Courier0027.lzma 2022-05-16T19:32:03.602Z,1652729523.602 [DataOverHttps](INFO): Moved sent file to Logs/20220516T164953/Courier0027.lzma.bak 2022-05-16T19:32:03.602Z,1652729523.602 [DataOverHttps](INFO): SBD MOMSN=16790724 2022-05-16T19:32:21.064Z,1652729541.064 [DataOverHttps](INFO): Sending 208 bytes from file Logs/20220516T164953/Express0028.lzma 2022-05-16T19:32:22.218Z,1652729542.218 [DataOverHttps](INFO): Moved sent file to Logs/20220516T164953/Express0028.lzma.bak 2022-05-16T19:32:22.218Z,1652729542.218 [DataOverHttps](INFO): SBD MOMSN=16790726 2022-05-16T19:32:24.620Z,1652729544.620 [Default:CheckIn:Read_Iridium] Stopped 2022-05-16T19:32:24.620Z,1652729544.620 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-16T19:32:24.620Z,1652729544.620 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-16T19:32:29.789Z,1652729549.789 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-16T19:37:25.135Z,1652729845.135 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-16T19:37:25.135Z,1652729845.135 [Default:CheckIn:C.Wait] Stopped 2022-05-16T19:37:25.135Z,1652729845.135 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-16T19:37:25.135Z,1652729845.135 [Default:CheckIn:D] Running Loop=1 2022-05-16T19:37:25.526Z,1652729845.526 [Default:CheckIn:D] Stopped 2022-05-16T19:37:25.526Z,1652729845.526 [Default:CheckIn:E] Running Loop=1 2022-05-16T19:37:25.933Z,1652729845.933 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 167.521875 min 2022-05-16T19:37:25.933Z,1652729845.933 [Default:CheckIn:E] Stopped 2022-05-16T19:37:25.934Z,1652729845.934 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-16T19:37:25.934Z,1652729845.934 [Default:CheckIn] Stopped 2022-05-16T19:37:25.934Z,1652729845.934 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-16T19:37:25.934Z,1652729845.934 [Default:CheckIn](INFO): Running loop #11 2022-05-16T19:37:25.934Z,1652729845.934 [Default:CheckIn] Running Loop=11 2022-05-16T19:37:25.934Z,1652729845.934 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-16T19:37:25.934Z,1652729845.934 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-16T19:37:27.535Z,1652729847.535 [NAL9602](FAULT): GPS failed to acquire within timeout. 2022-05-16T19:37:27.535Z,1652729847.535 [NAL9602] Data Fault, FailCount= 2 2022-05-16T19:37:27.535Z,1652729847.535 [NAL9602](ERROR): Data Fault 2022-05-16T19:37:27.554Z,1652729847.554 [CBIT](ERROR): Data Fault in component: NAL9602 2022-05-16T19:37:27.946Z,1652729847.946 [NAL9602](INFO): Powering down 2022-05-16T19:37:28.815Z,1652729848.815 [CBIT](INFO): Clearing failed state for component NAL9602 2022-05-16T19:37:28.815Z,1652729848.815 [NAL9602] No Fault, FailCount= 2 2022-05-16T19:37:58.241Z,1652729878.241 [NAL9602](INFO): Powering up NAL9602 2022-05-16T19:38:09.153Z,1652729889.153 [NAL9602](INFO): NAL9602 initialized 2022-05-16T19:42:26.177Z,1652730146.177 [Default:CheckIn:Read_GPS](INFO): Timed out from 2022-05-16T19:37:25.9Z 2022-05-16T19:42:26.177Z,1652730146.177 [Default:CheckIn:Read_GPS] Stopped 2022-05-16T19:42:26.177Z,1652730146.177 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-16T19:42:33.551Z,1652730153.551 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20220516T164953/Courier0030.lzma 2022-05-16T19:42:34.554Z,1652730154.554 [DataOverHttps](INFO): Moved sent file to Logs/20220516T164953/Courier0030.lzma.bak 2022-05-16T19:42:34.554Z,1652730154.554 [DataOverHttps](INFO): SBD MOMSN=16790750 2022-05-16T19:42:52.072Z,1652730172.072 [DataOverHttps](INFO): Sending 228 bytes from file Logs/20220516T164953/Express0031.lzma 2022-05-16T19:42:53.074Z,1652730173.074 [DataOverHttps](INFO): Moved sent file to Logs/20220516T164953/Express0031.lzma.bak 2022-05-16T19:42:53.074Z,1652730173.074 [DataOverHttps](INFO): SBD MOMSN=16790752 2022-05-16T19:42:55.701Z,1652730175.701 [Default:CheckIn:Read_Iridium] Stopped 2022-05-16T19:42:55.701Z,1652730175.701 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-16T19:42:55.701Z,1652730175.701 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-16T19:43:12.222Z,1652730192.222 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-05-16T19:43:42.917Z,1652730222.917 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-16T19:47:56.256Z,1652730476.256 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-16T19:47:56.256Z,1652730476.256 [Default:CheckIn:C.Wait] Stopped 2022-05-16T19:47:56.256Z,1652730476.256 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-16T19:47:56.256Z,1652730476.256 [Default:CheckIn:D] Running Loop=1 2022-05-16T19:47:56.681Z,1652730476.681 [Default:CheckIn:D] Stopped 2022-05-16T19:47:56.681Z,1652730476.681 [Default:CheckIn:E] Running Loop=1 2022-05-16T19:47:57.043Z,1652730477.043 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 178.041130 min 2022-05-16T19:47:57.044Z,1652730477.044 [Default:CheckIn:E] Stopped 2022-05-16T19:47:57.044Z,1652730477.044 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-16T19:47:57.044Z,1652730477.044 [Default:CheckIn] Stopped 2022-05-16T19:47:57.044Z,1652730477.044 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-16T19:47:57.044Z,1652730477.044 [Default:CheckIn](INFO): Running loop #12 2022-05-16T19:47:57.044Z,1652730477.044 [Default:CheckIn] Running Loop=12 2022-05-16T19:47:57.044Z,1652730477.044 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-16T19:47:57.045Z,1652730477.045 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-16T19:52:57.220Z,1652730777.220 [Default:CheckIn:Read_GPS](INFO): Timed out from 2022-05-16T19:47:57.0Z 2022-05-16T19:52:57.220Z,1652730777.220 [Default:CheckIn:Read_GPS] Stopped 2022-05-16T19:52:57.220Z,1652730777.220 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-16T19:53:01.245Z,1652730781.245 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-05-16T19:53:04.847Z,1652730784.847 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20220516T164953/Courier0033.lzma 2022-05-16T19:53:05.850Z,1652730785.850 [DataOverHttps](INFO): Moved sent file to Logs/20220516T164953/Courier0033.lzma.bak 2022-05-16T19:53:05.850Z,1652730785.850 [DataOverHttps](INFO): SBD MOMSN=16790770 2022-05-16T19:53:23.424Z,1652730803.424 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20220516T164953/Express0034.lzma 2022-05-16T19:53:24.426Z,1652730804.426 [DataOverHttps](INFO): Moved sent file to Logs/20220516T164953/Express0034.lzma.bak 2022-05-16T19:53:24.426Z,1652730804.426 [DataOverHttps](INFO): SBD MOMSN=16790775 2022-05-16T19:53:26.765Z,1652730806.765 [Default:CheckIn:Read_Iridium] Stopped 2022-05-16T19:53:26.765Z,1652730806.765 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-16T19:53:26.766Z,1652730806.766 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-16T19:53:31.949Z,1652730811.949 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-16T19:58:27.283Z,1652731107.283 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-16T19:58:27.283Z,1652731107.283 [Default:CheckIn:C.Wait] Stopped 2022-05-16T19:58:27.283Z,1652731107.283 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-16T19:58:27.284Z,1652731107.284 [Default:CheckIn:D] Running Loop=1 2022-05-16T19:58:27.699Z,1652731107.699 [Default:CheckIn:D] Stopped 2022-05-16T19:58:27.699Z,1652731107.699 [Default:CheckIn:E] Running Loop=1 2022-05-16T19:58:28.095Z,1652731108.095 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 188.558105 min 2022-05-16T19:58:28.095Z,1652731108.095 [Default:CheckIn:E] Stopped 2022-05-16T19:58:28.095Z,1652731108.095 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-16T19:58:28.095Z,1652731108.095 [Default:CheckIn] Stopped 2022-05-16T19:58:28.095Z,1652731108.095 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-16T19:58:28.095Z,1652731108.095 [Default:CheckIn](INFO): Running loop #13 2022-05-16T19:58:28.095Z,1652731108.095 [Default:CheckIn] Running Loop=13 2022-05-16T19:58:28.096Z,1652731108.096 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-16T19:58:28.096Z,1652731108.096 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-16T19:58:29.695Z,1652731109.695 [NAL9602](FAULT): GPS failed to acquire within timeout. 2022-05-16T19:58:29.695Z,1652731109.695 [NAL9602] Data Fault, FailCount= 3 2022-05-16T19:58:29.695Z,1652731109.695 [NAL9602](ERROR): Data Fault 2022-05-16T19:58:29.715Z,1652731109.715 [CBIT](ERROR): Data Fault in component: NAL9602 2022-05-16T19:58:30.105Z,1652731110.105 [NAL9602](INFO): Powering down 2022-05-16T19:58:30.961Z,1652731110.961 [CBIT](INFO): Clearing failed state for component NAL9602 2022-05-16T19:58:30.961Z,1652731110.961 [NAL9602] No Fault, FailCount= 3 2022-05-16T19:59:00.405Z,1652731140.405 [NAL9602](INFO): Powering up NAL9602 2022-05-16T19:59:11.317Z,1652731151.317 [NAL9602](INFO): NAL9602 initialized 2022-05-16T20:03:00.628Z,1652731380.628 [CommandExec](IMPORTANT): got command failComponent 2022-05-16T20:03:00.629Z,1652731380.629 [CommandExec](IMPORTANT): Failed components: 2022-05-16T20:03:00.629Z,1652731380.629 [CommandExec](IMPORTANT): No failed Components. 2022-05-16T20:03:28.346Z,1652731408.346 [Default:CheckIn:Read_GPS](INFO): Timed out from 2022-05-16T19:58:28.1Z 2022-05-16T20:03:28.347Z,1652731408.347 [Default:CheckIn:Read_GPS] Stopped 2022-05-16T20:03:28.347Z,1652731408.347 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-16T20:03:36.103Z,1652731416.103 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20220516T164953/Courier0036.lzma 2022-05-16T20:03:37.106Z,1652731417.106 [DataOverHttps](INFO): Moved sent file to Logs/20220516T164953/Courier0036.lzma.bak 2022-05-16T20:03:37.106Z,1652731417.106 [DataOverHttps](INFO): SBD MOMSN=16790798 2022-05-16T20:03:54.684Z,1652731434.684 [DataOverHttps](INFO): Sending 272 bytes from file Logs/20220516T164953/Express0037.lzma 2022-05-16T20:03:55.686Z,1652731435.686 [DataOverHttps](INFO): Moved sent file to Logs/20220516T164953/Express0037.lzma.bak 2022-05-16T20:03:55.686Z,1652731435.686 [DataOverHttps](INFO): SBD MOMSN=16790800 2022-05-16T20:03:58.731Z,1652731438.731 [Default:CheckIn:Read_Iridium] Stopped 2022-05-16T20:03:58.731Z,1652731438.731 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-16T20:03:58.731Z,1652731438.731 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-16T20:04:14.389Z,1652731454.389 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-05-16T20:04:45.097Z,1652731485.097 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-16T20:08:59.231Z,1652731739.231 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-16T20:08:59.236Z,1652731739.236 [Default:CheckIn:C.Wait] Stopped 2022-05-16T20:08:59.236Z,1652731739.236 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-16T20:08:59.237Z,1652731739.237 [Default:CheckIn:D] Running Loop=1 2022-05-16T20:08:59.635Z,1652731739.635 [Default:CheckIn:D] Stopped 2022-05-16T20:08:59.636Z,1652731739.636 [Default:CheckIn:E] Running Loop=1 2022-05-16T20:09:00.031Z,1652731740.031 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 199.090381 min 2022-05-16T20:09:00.031Z,1652731740.031 [Default:CheckIn:E] Stopped 2022-05-16T20:09:00.031Z,1652731740.031 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-16T20:09:00.031Z,1652731740.031 [Default:CheckIn] Stopped 2022-05-16T20:09:00.032Z,1652731740.032 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-16T20:09:00.032Z,1652731740.032 [Default:CheckIn](INFO): Running loop #14 2022-05-16T20:09:00.032Z,1652731740.032 [Default:CheckIn] Running Loop=14 2022-05-16T20:09:00.032Z,1652731740.032 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-16T20:09:00.032Z,1652731740.032 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-16T20:11:00.415Z,1652731860.415 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2022-05-16T20:11:00.417Z,1652731860.417 [BPC1](INFO): Received data from all battery sticks. 2022-05-16T20:14:00.203Z,1652732040.203 [Default:CheckIn:Read_GPS](INFO): Timed out from 2022-05-16T20:09:00.0Z 2022-05-16T20:14:00.203Z,1652732040.203 [Default:CheckIn:Read_GPS] Stopped 2022-05-16T20:14:00.204Z,1652732040.204 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-16T20:14:04.229Z,1652732044.229 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-05-16T20:14:07.999Z,1652732047.999 [DataOverHttps](INFO): Sending 51 bytes from file Logs/20220516T164953/Courier0039.lzma 2022-05-16T20:14:09.002Z,1652732049.002 [DataOverHttps](INFO): Moved sent file to Logs/20220516T164953/Courier0039.lzma.bak 2022-05-16T20:14:09.002Z,1652732049.002 [DataOverHttps](INFO): SBD MOMSN=16790822 2022-05-16T20:14:27.195Z,1652732067.195 [DataOverHttps](INFO): Sending 208 bytes from file Logs/20220516T164953/Express0040.lzma 2022-05-16T20:14:27.590Z,1652732067.590 [DataOverHttps](INFO): Moved sent file to Logs/20220516T164953/Express0040.lzma.bak 2022-05-16T20:14:27.590Z,1652732067.590 [DataOverHttps](INFO): SBD MOMSN=16790824 2022-05-16T20:14:30.111Z,1652732070.111 [Default:CheckIn:Read_Iridium] Stopped 2022-05-16T20:14:30.116Z,1652732070.116 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-16T20:14:30.116Z,1652732070.116 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-16T20:14:34.933Z,1652732074.933 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-16T20:19:30.694Z,1652732370.694 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-16T20:19:30.694Z,1652732370.694 [Default:CheckIn:C.Wait] Stopped 2022-05-16T20:19:30.694Z,1652732370.694 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-16T20:19:30.694Z,1652732370.694 [Default:CheckIn:D] Running Loop=1 2022-05-16T20:19:31.085Z,1652732371.085 [Default:CheckIn:D] Stopped 2022-05-16T20:19:31.085Z,1652732371.085 [Default:CheckIn:E] Running Loop=1 2022-05-16T20:19:31.499Z,1652732371.499 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 209.614535 min 2022-05-16T20:19:31.499Z,1652732371.499 [Default:CheckIn:E] Stopped 2022-05-16T20:19:31.499Z,1652732371.499 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-16T20:19:31.500Z,1652732371.500 [Default:CheckIn] Stopped 2022-05-16T20:19:31.500Z,1652732371.500 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-16T20:19:31.500Z,1652732371.500 [Default:CheckIn](INFO): Running loop #15 2022-05-16T20:19:31.500Z,1652732371.500 [Default:CheckIn] Running Loop=15 2022-05-16T20:19:31.500Z,1652732371.500 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-16T20:19:31.500Z,1652732371.500 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-16T20:19:33.093Z,1652732373.093 [NAL9602](FAULT): GPS failed to acquire within timeout. 2022-05-16T20:19:33.093Z,1652732373.093 [NAL9602] Data Fault, FailCount= 4 2022-05-16T20:19:33.093Z,1652732373.093 [NAL9602](ERROR): Data Fault 2022-05-16T20:19:33.140Z,1652732373.140 [CBIT](ERROR): Data Fault in component: NAL9602 2022-05-16T20:19:33.497Z,1652732373.497 [NAL9602](INFO): Powering down 2022-05-16T20:19:34.323Z,1652732374.323 [CBIT](INFO): Clearing failed state for component NAL9602 2022-05-16T20:19:34.324Z,1652732374.324 [NAL9602] No Fault, FailCount= 4 2022-05-16T20:20:03.805Z,1652732403.805 [NAL9602](INFO): Powering up NAL9602 2022-05-16T20:20:14.705Z,1652732414.705 [NAL9602](INFO): NAL9602 initialized 2022-05-16T20:24:31.672Z,1652732671.672 [Default:CheckIn:Read_GPS](INFO): Timed out from 2022-05-16T20:19:31.5Z 2022-05-16T20:24:31.672Z,1652732671.672 [Default:CheckIn:Read_GPS] Stopped 2022-05-16T20:24:31.672Z,1652732671.672 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-16T20:24:39.795Z,1652732679.795 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20220516T164953/Courier0042.lzma 2022-05-16T20:24:40.798Z,1652732680.798 [DataOverHttps](INFO): Moved sent file to Logs/20220516T164953/Courier0042.lzma.bak 2022-05-16T20:24:40.798Z,1652732680.798 [DataOverHttps](INFO): SBD MOMSN=16790843 2022-05-16T20:24:58.712Z,1652732698.712 [DataOverHttps](INFO): Sending 226 bytes from file Logs/20220516T164953/Express0043.lzma 2022-05-16T20:24:59.714Z,1652732699.714 [DataOverHttps](INFO): Moved sent file to Logs/20220516T164953/Express0043.lzma.bak 2022-05-16T20:24:59.714Z,1652732699.714 [DataOverHttps](INFO): SBD MOMSN=16790845 2022-05-16T20:25:03.625Z,1652732703.625 [Default:CheckIn:Read_Iridium] Stopped 2022-05-16T20:25:03.625Z,1652732703.625 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-16T20:25:03.625Z,1652732703.625 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-16T20:25:17.722Z,1652732717.722 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-05-16T20:25:48.425Z,1652732748.425 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-16T20:26:28.049Z,1652732788.049 [CommandExec](IMPORTANT): got command restart application 2022-05-16T20:26:29.052Z,1652732789.052 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread. 2022-05-16T20:26:29.052Z,1652732789.052 [CommandExec](INFO): Uninitializing the command executive. 2022-05-16T20:26:29.052Z,1652732789.052 [CommandExec](INFO): Uninitializing the command scheduler. 2022-05-16T20:26:29.053Z,1652732789.053 [CommandExec ThreadHandler](INFO): Thread cancelled. 2022-05-16T20:26:29.208Z,1652732789.208 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2022-05-16T20:26:29.208Z,1652732789.208 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2022-05-16T20:26:29.208Z,1652732789.208 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2022-05-16T20:26:29.208Z,1652732789.208 [NavChartDb](INFO): Join timeout helper Thread ID is 8260 2022-05-16T20:26:29.588Z,1652732789.588 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2022-05-16T20:26:29.588Z,1652732789.588 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2022-05-16T20:26:29.592Z,1652732789.592 [ComponentRegistry](INFO): Shutting down WetLabsUBAT ThreadHandler 2022-05-16T20:26:29.592Z,1652732789.592 [WetLabsUBAT ThreadHandler](INFO): Thread cancelled. 2022-05-16T20:26:29.592Z,1652732789.592 [WetLabsUBAT](INFO): Join timeout helper Thread ID is 8261 2022-05-16T20:26:29.856Z,1652732789.856 [WetLabsUBAT ThreadHandler](INFO): Uninitializing protected caller thread. 2022-05-16T20:26:29.856Z,1652732789.856 [WetLabsUBAT](INFO): Powering down 2022-05-16T20:26:29.857Z,1652732789.857 [WetLabsUBAT ThreadHandler](INFO): Thread cancelled. 2022-05-16T20:26:29.872Z,1652732789.872 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2022-05-16T20:26:29.872Z,1652732789.872 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2022-05-16T20:26:29.872Z,1652732789.872 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 8262 2022-05-16T20:26:29.892Z,1652732789.892 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2022-05-16T20:26:29.892Z,1652732789.892 [WetLabsBB2FL](INFO): Powering down 2022-05-16T20:26:29.893Z,1652732789.893 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2022-05-16T20:26:29.914Z,1652732789.914 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2022-05-16T20:26:29.914Z,1652732789.914 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2022-05-16T20:26:29.914Z,1652732789.914 [CTD_Seabird](INFO): Join timeout helper Thread ID is 8263 2022-05-16T20:26:30.728Z,1652732790.728 [CTD_Seabird](INFO): Powering down 2022-05-16T20:26:30.740Z,1652732790.740 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread. 2022-05-16T20:26:30.740Z,1652732790.740 [CTD_Seabird](INFO): Powering down 2022-05-16T20:26:30.752Z,1652732790.752 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2022-05-16T20:26:30.760Z,1652732790.760 [ComponentRegistry](INFO): Shutting down DAT ThreadHandler 2022-05-16T20:26:30.760Z,1652732790.760 [DAT ThreadHandler](INFO): Thread cancelled. 2022-05-16T20:26:30.764Z,1652732790.764 [DAT](INFO): Join timeout helper Thread ID is 8264 2022-05-16T20:26:30.836Z,1652732790.836 [DAT](INFO): Powering down 2022-05-16T20:26:30.909Z,1652732790.909 [DAT ThreadHandler](INFO): Uninitializing protected caller thread. 2022-05-16T20:26:30.909Z,1652732790.909 [DAT](INFO): Powering down 2022-05-16T20:26:30.910Z,1652732790.910 [DAT ThreadHandler](INFO): Thread cancelled. 2022-05-16T20:26:30.913Z,1652732790.913 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2022-05-16T20:26:30.913Z,1652732790.913 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2022-05-16T20:26:30.914Z,1652732790.914 [Radio_Surface](INFO): Join timeout helper Thread ID is 8265 2022-05-16T20:26:31.016Z,1652732791.016 [Radio_Surface](INFO): Powering down 2022-05-16T20:26:31.017Z,1652732791.017 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2022-05-16T20:26:31.017Z,1652732791.017 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2022-05-16T20:26:31.024Z,1652732791.024 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler 2022-05-16T20:26:31.025Z,1652732791.025 [Onboard ThreadHandler](INFO): Thread cancelled. 2022-05-16T20:26:31.025Z,1652732791.025 [Onboard](INFO): Join timeout helper Thread ID is 8266 2022-05-16T20:26:31.284Z,1652732791.284 [DataOverHttps](INFO): Radio surface powered OFF, will not connect. 2022-05-16T20:26:32.472Z,1652732792.472 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread. 2022-05-16T20:26:32.472Z,1652732792.472 [Onboard ThreadHandler](INFO): Thread cancelled. 2022-05-16T20:26:32.477Z,1652732792.477 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2022-05-16T20:26:32.478Z,1652732792.478 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2022-05-16T20:26:32.478Z,1652732792.478 [DataOverHttps](INFO): Join timeout helper Thread ID is 8267 2022-05-16T20:26:33.292Z,1652732793.292 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2022-05-16T20:26:33.292Z,1652732793.292 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2022-05-16T20:26:33.305Z,1652732793.305 [ComponentRegistry](INFO): Shutting down BackseatComponent ThreadHandler 2022-05-16T20:26:33.305Z,1652732793.305 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2022-05-16T20:26:33.305Z,1652732793.305 [BackseatComponent](INFO): Join timeout helper Thread ID is 8268 2022-05-16T20:26:33.400Z,1652732793.400 [BackseatComponent ThreadHandler](INFO): Uninitializing protected caller thread. 2022-05-16T20:26:33.400Z,1652732793.400 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2022-05-16T20:26:33.405Z,1652732793.405 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2022-05-16T20:26:33.405Z,1652732793.405 [logger ThreadHandler](INFO): Thread cancelled. 2022-05-16T20:26:33.405Z,1652732793.405 [logger](INFO): Join timeout helper Thread ID is 8269 2022-05-16T20:26:33.432Z,1652732793.432 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2022-05-16T20:26:33.432Z,1652732793.432 [logger ThreadHandler](INFO): Thread cancelled. 2022-05-16T20:26:33.444Z,1652732793.444 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2022-05-16T20:26:33.445Z,1652732793.445 [CommandLine ThreadHandler](INFO): Thread cancelled. 2022-05-16T20:26:33.445Z,1652732793.445 [CommandLine](INFO): Join timeout helper Thread ID is 8270 2022-05-16T20:26:33.480Z,1652732793.480 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2022-05-16T20:26:33.480Z,1652732793.480 [CommandLine ThreadHandler](INFO): Thread cancelled. 2022-05-16T20:26:33.484Z,1652732793.484 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler 2022-05-16T20:26:33.485Z,1652732793.485 [CommandExec ThreadHandler](INFO): Thread cancelled. 2022-05-16T20:26:33.485Z,1652732793.485 [CommandExec](INFO): Join timeout helper Thread ID is 8271 2022-05-16T20:26:33.486Z,1652732793.486 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2022-05-16T20:26:33.486Z,1652732793.486 [controlThread ThreadHandler](INFO): Thread cancelled. 2022-05-16T20:26:33.487Z,1652732793.487 [controlThread](INFO): Join timeout helper Thread ID is 8272 2022-05-16T20:26:33.656Z,1652732793.656 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2022-05-16T20:26:33.656Z,1652732793.656 [controlThread](DEBUG): Uninitializing ControlThread 2022-05-16T20:26:33.657Z,1652732793.657 [AHRS_M2](INFO): Powering down 2022-05-16T20:26:33.729Z,1652732793.729 [NAL9602](INFO): Powering down 2022-05-16T20:26:33.800Z,1652732793.800 [RDI_Pathfinder](INFO): Powering down 2022-05-16T20:26:33.803Z,1652732793.803 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2022-05-16T20:26:33.804Z,1652732793.804 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2022-05-16T20:26:33.805Z,1652732793.805 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2022-05-16T20:26:33.805Z,1652732793.805 [MissionManager](INFO): Uninitializing Mission Default 2022-05-16T20:26:33.805Z,1652732793.805 [Default] Stopped 2022-05-16T20:26:33.805Z,1652732793.805 [Default](DEBUG): Aggregate::uninitialize Default 2022-05-16T20:26:33.805Z,1652732793.805 [Default:B.GoToSurface] Stopped 2022-05-16T20:26:33.806Z,1652732793.806 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2022-05-16T20:26:33.806Z,1652732793.806 [Default:CheckIn] Stopped 2022-05-16T20:26:33.806Z,1652732793.806 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-16T20:26:33.806Z,1652732793.806 [Default:CheckIn:C.Wait] Stopped 2022-05-16T20:26:33.806Z,1652732793.806 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-16T20:26:33.809Z,1652732793.809 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2022-05-16T20:26:33.811Z,1652732793.811 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2022-05-16T20:26:33.811Z,1652732793.811 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2022-05-16T20:26:33.811Z,1652732793.811 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2022-05-16T20:26:33.812Z,1652732793.812 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2022-05-16T20:26:33.812Z,1652732793.812 [BuoyancyServo](INFO): Powering down 2022-05-16T20:26:33.824Z,1652732793.824 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2022-05-16T20:26:33.824Z,1652732793.824 [ElevatorServo](INFO): Powering down 2022-05-16T20:26:33.825Z,1652732793.825 [MassServo](DEBUG): Uninitialize Mass Servo. 2022-05-16T20:26:33.825Z,1652732793.825 [MassServo](INFO): Powering down 2022-05-16T20:26:33.826Z,1652732793.826 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2022-05-16T20:26:33.826Z,1652732793.826 [RudderServo](INFO): Powering down 2022-05-16T20:26:33.827Z,1652732793.827 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2022-05-16T20:26:33.827Z,1652732793.827 [ThrusterServo](INFO): Powering down 2022-05-16T20:26:33.828Z,1652732793.828 [SBIT](DEBUG): Uninitialize SBIT Component. 2022-05-16T20:26:33.828Z,1652732793.828 [IBIT](DEBUG): Uninitialize IBIT Component. 2022-05-16T20:26:33.828Z,1652732793.828 [CBIT](DEBUG): Uninitialize CBIT Component. 2022-05-16T20:26:33.829Z,1652732793.829 [CBIT](DEBUG): Powering off loads. 2022-05-16T20:26:33.840Z,1652732793.840 [CBIT](DEBUG): Disabling WDT. 2022-05-16T20:26:33.852Z,1652732793.852 [CBIT](DEBUG): Opening all GF detection circuits. 2022-05-16T20:26:33.853Z,1652732793.853 [controlThread ThreadHandler](INFO): Thread cancelled. 2022-05-16T20:26:33.923Z,1652732793.923 [DAT ThreadHandler](INFO): Thread cancelled. 2022-05-16T20:26:33.930Z,1652732793.930 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2022-05-16T20:26:33.932Z,1652732793.932 [Onboard ThreadHandler](INFO): Thread cancelled. 2022-05-16T20:26:33.938Z,1652732793.938 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2022-05-16T20:26:33.981Z,1652732793.981 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2022-05-16T20:26:34.046Z,1652732794.046 [WetLabsUBAT ThreadHandler](INFO): Thread cancelled. 2022-05-16T20:26:34.048Z,1652732794.048 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2022-05-16T20:26:34.051Z,1652732794.051 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2022-05-16T20:26:34.060Z,1652732794.060 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2022-05-16T20:26:34.134Z,1652732794.134 [logger ThreadHandler](INFO): Thread cancelled.