2025-06-19T18:04:20.203Z,1750356260.203 [CommandExec](IMPORTANT): got command restart logs 2025-06-19T18:04:28.716Z,1750356268.716 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-06-19T18:04:28.716Z,1750356268.716 [Default:CheckIn:C.Wait] Stopped 2025-06-19T18:04:28.716Z,1750356268.716 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-06-19T18:04:28.717Z,1750356268.717 [Default:CheckIn:D] Running Loop=1 2025-06-19T18:04:29.150Z,1750356269.150 [Default:CheckIn:D] Stopped 2025-06-19T18:04:29.150Z,1750356269.150 [Default:CheckIn:E] Running Loop=1 2025-06-19T18:04:29.541Z,1750356269.541 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 11.943113 min 2025-06-19T18:04:29.541Z,1750356269.541 [Default:CheckIn:E] Stopped 2025-06-19T18:04:29.541Z,1750356269.541 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-06-19T18:04:29.541Z,1750356269.541 [Default:CheckIn] Stopped 2025-06-19T18:04:29.541Z,1750356269.541 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-06-19T18:04:29.542Z,1750356269.542 [Default:CheckIn](INFO): Running loop #3 2025-06-19T18:04:29.542Z,1750356269.542 [Default:CheckIn] Running Loop=3 2025-06-19T18:04:29.542Z,1750356269.542 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-06-19T18:04:29.542Z,1750356269.542 [Default:CheckIn:Read_GPS] Running Loop=1 2025-06-19T18:04:31.584Z,1750356271.584 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180430.00,A,3648.49544,N,12149.39992,W,2.041,72.73,190625,,,D*4E 2025-06-19T18:04:31.626Z,1750356271.626 [NAL9602](INFO): GPS fix at 20250619T180430: (36.808257, -121.823332) 2025-06-19T18:04:31.691Z,1750356271.691 [Default:CheckIn:Read_GPS] Stopped 2025-06-19T18:04:31.691Z,1750356271.691 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-06-19T18:04:40.056Z,1750356280.056 [DataOverHttps](INFO): Sending 40 bytes from file Logs/20250619T160839/Courier0021.lzma 2025-06-19T18:04:41.058Z,1750356281.058 [DataOverHttps](INFO): Moved sent file to Logs/20250619T160839/Courier0021.lzma.bak 2025-06-19T18:04:41.058Z,1750356281.058 [DataOverHttps](INFO): SBD MOMSN=25229559 2025-06-19T18:04:45.739Z,1750356285.739 [NAL9602](INFO): SBD MO Status=1, MOMSN=21811, MT Status=0, MTMSN=0 2025-06-19T18:04:45.739Z,1750356285.739 [NAL9602](INFO): No messages in MT queue 2025-06-19T18:04:58.390Z,1750356298.390 [DataOverHttps](INFO): Sending 270 bytes from file Logs/20250619T180420/Courier0000.lzma 2025-06-19T18:04:59.390Z,1750356299.390 [DataOverHttps](INFO): Moved sent file to Logs/20250619T180420/Courier0000.lzma.bak 2025-06-19T18:04:59.390Z,1750356299.390 [DataOverHttps](INFO): SBD MOMSN=25229561 2025-06-19T18:05:16.440Z,1750356316.440 [NAL9602](INFO): Not Powering down - fast GPS 2025-06-19T18:05:16.508Z,1750356316.508 [DataOverHttps](INFO): Sending 108 bytes from file Logs/20250619T160839/Express0022.lzma 2025-06-19T18:05:17.510Z,1750356317.510 [DataOverHttps](INFO): Moved sent file to Logs/20250619T160839/Express0022.lzma.bak 2025-06-19T18:05:17.510Z,1750356317.510 [DataOverHttps](INFO): SBD MOMSN=25229565 2025-06-19T18:05:35.429Z,1750356335.429 [DataOverHttps](INFO): Sending 442 bytes from file Logs/20250619T180420/Express0001.lzma 2025-06-19T18:05:37.434Z,1750356337.434 [DataOverHttps](INFO): Moved sent file to Logs/20250619T180420/Express0001.lzma.bak 2025-06-19T18:05:37.434Z,1750356337.434 [DataOverHttps](INFO): SBD MOMSN=25229568 2025-06-19T18:05:39.091Z,1750356339.091 [Default:CheckIn:Read_Iridium] Stopped 2025-06-19T18:05:39.092Z,1750356339.092 [Default:CheckIn:C.Wait] Running Loop=1 2025-06-19T18:05:39.092Z,1750356339.092 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-06-19T18:08:02.487Z,1750356482.487 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error. Device response is::TS,0000000000000157,+00000,I 2025-06-19T18:08:02.487Z,1750356482.487 [DVL_micro](ERROR): Failed to parse: :TS,0000000000000157,+00000,I 2025-06-19T18:10:39.661Z,1750356639.661 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-06-19T18:10:39.661Z,1750356639.661 [Default:CheckIn:C.Wait] Stopped 2025-06-19T18:10:39.661Z,1750356639.661 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-06-19T18:10:39.661Z,1750356639.661 [Default:CheckIn:D] Running Loop=1 2025-06-19T18:10:40.067Z,1750356640.067 [Default:CheckIn:D] Stopped 2025-06-19T18:10:40.067Z,1750356640.067 [Default:CheckIn:E] Running Loop=1 2025-06-19T18:10:40.463Z,1750356640.463 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 18.125071 min 2025-06-19T18:10:40.463Z,1750356640.463 [Default:CheckIn:E] Stopped 2025-06-19T18:10:40.464Z,1750356640.464 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-06-19T18:10:40.464Z,1750356640.464 [Default:CheckIn] Stopped 2025-06-19T18:10:40.464Z,1750356640.464 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-06-19T18:10:40.464Z,1750356640.464 [Default:CheckIn](INFO): Running loop #4 2025-06-19T18:10:40.464Z,1750356640.464 [Default:CheckIn] Running Loop=4 2025-06-19T18:10:40.464Z,1750356640.464 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-06-19T18:10:40.465Z,1750356640.465 [Default:CheckIn:Read_GPS] Running Loop=1 2025-06-19T18:10:42.478Z,1750356642.478 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181041.00,A,3648.43677,N,12147.32484,W,4.762,55.21,190625,,,A*4C 2025-06-19T18:10:42.481Z,1750356642.481 [NAL9602](INFO): GPS fix at 20250619T181041: (36.807279, -121.788747) 2025-06-19T18:10:42.491Z,1750356642.491 [Default:CheckIn:Read_GPS] Stopped 2025-06-19T18:10:42.491Z,1750356642.491 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-06-19T18:10:49.988Z,1750356649.988 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20250619T180420/Courier0003.lzma 2025-06-19T18:10:50.990Z,1750356650.990 [DataOverHttps](INFO): Moved sent file to Logs/20250619T180420/Courier0003.lzma.bak 2025-06-19T18:10:50.990Z,1750356650.990 [DataOverHttps](INFO): SBD MOMSN=25229583 2025-06-19T18:11:05.931Z,1750356665.931 [NAL9602](INFO): SBD MO Status=1, MOMSN=21812, MT Status=0, MTMSN=0 2025-06-19T18:11:05.932Z,1750356665.932 [NAL9602](INFO): No messages in MT queue 2025-06-19T18:11:07.117Z,1750356667.117 [DataOverHttps](INFO): Sending 289 bytes from file Logs/20250619T180420/Express0005.lzma 2025-06-19T18:11:08.118Z,1750356668.118 [DataOverHttps](INFO): Moved sent file to Logs/20250619T180420/Express0005.lzma.bak 2025-06-19T18:11:08.118Z,1750356668.118 [DataOverHttps](INFO): SBD MOMSN=25229586 2025-06-19T18:11:09.955Z,1750356669.955 [Default:CheckIn:Read_Iridium] Stopped 2025-06-19T18:11:09.955Z,1750356669.955 [Default:CheckIn:C.Wait] Running Loop=1 2025-06-19T18:11:09.955Z,1750356669.955 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-06-19T18:11:36.620Z,1750356696.620 [NAL9602](INFO): Not Powering down - fast GPS 2025-06-19T18:12:25.909Z,1750356745.909 [DVL_micro](ERROR): Failed to parse: :SA,+00.78,+01.17,091.9 2025-06-19T18:16:10.545Z,1750356970.545 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-06-19T18:16:10.545Z,1750356970.545 [Default:CheckIn:C.Wait] Stopped 2025-06-19T18:16:10.545Z,1750356970.545 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-06-19T18:16:10.545Z,1750356970.545 [Default:CheckIn:D] Running Loop=1 2025-06-19T18:16:11.032Z,1750356971.032 [Default:CheckIn:D] Stopped 2025-06-19T18:16:11.032Z,1750356971.032 [Default:CheckIn:E] Running Loop=1 2025-06-19T18:16:11.352Z,1750356971.352 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 23.641152 min 2025-06-19T18:16:11.352Z,1750356971.352 [Default:CheckIn:E] Stopped 2025-06-19T18:16:11.352Z,1750356971.352 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-06-19T18:16:11.352Z,1750356971.352 [Default:CheckIn] Stopped 2025-06-19T18:16:11.352Z,1750356971.352 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-06-19T18:16:11.352Z,1750356971.352 [Default:CheckIn](INFO): Running loop #5 2025-06-19T18:16:11.352Z,1750356971.352 [Default:CheckIn] Running Loop=5 2025-06-19T18:16:11.353Z,1750356971.353 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-06-19T18:16:11.353Z,1750356971.353 [Default:CheckIn:Read_GPS] Running Loop=1 2025-06-19T18:16:13.358Z,1750356973.358 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181612.00,A,3648.27238,N,12147.13609,W,3.635,184.13,190625,,,D*78 2025-06-19T18:16:13.360Z,1750356973.360 [NAL9602](INFO): GPS fix at 20250619T181612: (36.804540, -121.785601) 2025-06-19T18:16:13.371Z,1750356973.371 [Default:CheckIn:Read_GPS] Stopped 2025-06-19T18:16:13.371Z,1750356973.371 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-06-19T18:16:21.668Z,1750356981.668 [DataOverHttps](INFO): Sending 75 bytes from file Logs/20250619T180420/Courier0009.lzma 2025-06-19T18:16:22.678Z,1750356982.678 [DataOverHttps](INFO): Moved sent file to Logs/20250619T180420/Courier0009.lzma.bak 2025-06-19T18:16:22.678Z,1750356982.678 [DataOverHttps](INFO): SBD MOMSN=25229596 2025-06-19T18:16:31.165Z,1750356991.165 [NAL9602](INFO): SBD MO Status=1, MOMSN=21813, MT Status=0, MTMSN=0 2025-06-19T18:16:31.165Z,1750356991.165 [NAL9602](INFO): No messages in MT queue 2025-06-19T18:16:41.972Z,1750357001.972 [DataOverHttps](INFO): Sending 176 bytes from file Logs/20250619T180420/Express0010.lzma 2025-06-19T18:16:42.974Z,1750357002.974 [DataOverHttps](INFO): Moved sent file to Logs/20250619T180420/Express0010.lzma.bak 2025-06-19T18:16:42.974Z,1750357002.974 [DataOverHttps](INFO): SBD MOMSN=25229599 2025-06-19T18:16:44.895Z,1750357004.895 [Default:CheckIn:Read_Iridium] Stopped 2025-06-19T18:16:44.895Z,1750357004.895 [Default:CheckIn:C.Wait] Running Loop=1 2025-06-19T18:16:44.895Z,1750357004.895 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-06-19T18:17:01.845Z,1750357021.845 [NAL9602](INFO): Not Powering down - fast GPS 2025-06-19T18:21:45.526Z,1750357305.526 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-06-19T18:21:45.526Z,1750357305.526 [Default:CheckIn:C.Wait] Stopped 2025-06-19T18:21:45.526Z,1750357305.526 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-06-19T18:21:45.526Z,1750357305.526 [Default:CheckIn:D] Running Loop=1 2025-06-19T18:21:45.924Z,1750357305.924 [Default:CheckIn:D] Stopped 2025-06-19T18:21:45.924Z,1750357305.924 [Default:CheckIn:E] Running Loop=1 2025-06-19T18:21:46.319Z,1750357306.319 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 29.222687 min 2025-06-19T18:21:46.319Z,1750357306.319 [Default:CheckIn:E] Stopped 2025-06-19T18:21:46.336Z,1750357306.336 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-06-19T18:21:46.336Z,1750357306.336 [Default:CheckIn] Stopped 2025-06-19T18:21:46.336Z,1750357306.336 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-06-19T18:21:46.336Z,1750357306.336 [Default:CheckIn](INFO): Running loop #6 2025-06-19T18:21:46.336Z,1750357306.336 [Default:CheckIn] Running Loop=6 2025-06-19T18:21:46.337Z,1750357306.337 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-06-19T18:21:46.337Z,1750357306.337 [Default:CheckIn:Read_GPS] Running Loop=1 2025-06-19T18:21:48.335Z,1750357308.335 [BPC1](ERROR): Battery stick #2 (s/n: 0124) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0. 2025-06-19T18:21:48.336Z,1750357308.336 [BPC1](ERROR): Battery stick #4 (s/n: 017A) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4AD0. 2025-06-19T18:21:48.337Z,1750357308.337 [BPC1](INFO): Calculating totals. Valid battery stick count: 54. Valid reserve battery stick count: 6. 2025-06-19T18:21:48.339Z,1750357308.339 [BPC1](INFO): Received data from all battery sticks. 2025-06-19T18:21:48.344Z,1750357308.344 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182147.00,A,3648.15049,N,12147.21245,W,0.019,209.16,190625,,,D*7C 2025-06-19T18:21:48.346Z,1750357308.346 [NAL9602](INFO): GPS fix at 20250619T182147: (36.802508, -121.786874) 2025-06-19T18:21:48.382Z,1750357308.382 [Default:CheckIn:Read_GPS] Stopped 2025-06-19T18:21:48.382Z,1750357308.382 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-06-19T18:21:56.028Z,1750357316.028 [DataOverHttps](INFO): Sending 204 bytes from file Logs/20250619T180420/Courier0012.lzma 2025-06-19T18:21:57.030Z,1750357317.030 [DataOverHttps](INFO): Moved sent file to Logs/20250619T180420/Courier0012.lzma.bak 2025-06-19T18:21:57.030Z,1750357317.030 [DataOverHttps](INFO): SBD MOMSN=25229608 2025-06-19T18:22:12.171Z,1750357332.171 [NAL9602](INFO): SBD MO Status=1, MOMSN=21814, MT Status=0, MTMSN=0 2025-06-19T18:22:12.171Z,1750357332.171 [NAL9602](INFO): No messages in MT queue 2025-06-19T18:22:13.060Z,1750357333.060 [DataOverHttps](INFO): Sending 177 bytes from file Logs/20250619T180420/Express0013.lzma 2025-06-19T18:22:14.062Z,1750357334.062 [DataOverHttps](INFO): Moved sent file to Logs/20250619T180420/Express0013.lzma.bak 2025-06-19T18:22:14.062Z,1750357334.062 [DataOverHttps](INFO): SBD MOMSN=25229611 2025-06-19T18:22:15.819Z,1750357335.819 [Default:CheckIn:Read_Iridium] Stopped 2025-06-19T18:22:15.819Z,1750357335.819 [Default:CheckIn:C.Wait] Running Loop=1 2025-06-19T18:22:15.819Z,1750357335.819 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-06-19T18:22:42.871Z,1750357362.871 [NAL9602](INFO): Not Powering down - fast GPS 2025-06-19T18:27:16.392Z,1750357636.392 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-06-19T18:27:16.392Z,1750357636.392 [Default:CheckIn:C.Wait] Stopped 2025-06-19T18:27:16.392Z,1750357636.392 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-06-19T18:27:16.392Z,1750357636.392 [Default:CheckIn:D] Running Loop=1 2025-06-19T18:27:16.787Z,1750357636.787 [Default:CheckIn:D] Stopped 2025-06-19T18:27:16.787Z,1750357636.787 [Default:CheckIn:E] Running Loop=1 2025-06-19T18:27:17.192Z,1750357637.192 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 34.737061 min 2025-06-19T18:27:17.192Z,1750357637.192 [Default:CheckIn:E] Stopped 2025-06-19T18:27:17.192Z,1750357637.192 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-06-19T18:27:17.192Z,1750357637.192 [Default:CheckIn] Stopped 2025-06-19T18:27:17.193Z,1750357637.193 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-06-19T18:27:17.193Z,1750357637.193 [Default:CheckIn](INFO): Running loop #7 2025-06-19T18:27:17.193Z,1750357637.193 [Default:CheckIn] Running Loop=7 2025-06-19T18:27:17.193Z,1750357637.193 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-06-19T18:27:17.193Z,1750357637.193 [Default:CheckIn:Read_GPS] Running Loop=1 2025-06-19T18:27:19.207Z,1750357639.207 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182718.00,A,3648.15328,N,12147.21887,W,0.408,345.17,190625,,,D*7C 2025-06-19T18:27:19.210Z,1750357639.210 [NAL9602](INFO): GPS fix at 20250619T182718: (36.802555, -121.786981) 2025-06-19T18:27:19.220Z,1750357639.220 [Default:CheckIn:Read_GPS] Stopped 2025-06-19T18:27:19.220Z,1750357639.220 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-06-19T18:27:27.112Z,1750357647.112 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20250619T180420/Courier0015.lzma 2025-06-19T18:27:28.116Z,1750357648.116 [DataOverHttps](INFO): Moved sent file to Logs/20250619T180420/Courier0015.lzma.bak 2025-06-19T18:27:28.116Z,1750357648.116 [DataOverHttps](INFO): SBD MOMSN=25229620 2025-06-19T18:27:46.792Z,1750357666.792 [DataOverHttps](INFO): Sending 155 bytes from file Logs/20250619T180420/Express0016.lzma 2025-06-19T18:27:47.794Z,1750357667.794 [DataOverHttps](INFO): Moved sent file to Logs/20250619T180420/Express0016.lzma.bak 2025-06-19T18:27:47.794Z,1750357667.794 [DataOverHttps](INFO): SBD MOMSN=25229623 2025-06-19T18:27:50.393Z,1750357670.393 [Default:CheckIn:Read_Iridium] Stopped 2025-06-19T18:27:50.394Z,1750357670.394 [Default:CheckIn:C.Wait] Running Loop=1 2025-06-19T18:27:50.394Z,1750357670.394 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-06-19T18:27:51.958Z,1750357671.958 [NAL9602](INFO): SBD MO Status=1, MOMSN=21815, MT Status=0, MTMSN=0 2025-06-19T18:27:51.958Z,1750357671.958 [NAL9602](INFO): No messages in MT queue 2025-06-19T18:28:22.654Z,1750357702.654 [NAL9602](INFO): Not Powering down - fast GPS 2025-06-19T18:32:06.504Z,1750357926.504 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error. Device response is::TS,00000000000000.0,1489.0,000 2025-06-19T18:32:06.504Z,1750357926.504 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000.0,1489.0,000 2025-06-19T18:32:50.955Z,1750357970.955 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-06-19T18:32:50.955Z,1750357970.955 [Default:CheckIn:C.Wait] Stopped 2025-06-19T18:32:50.955Z,1750357970.955 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-06-19T18:32:50.956Z,1750357970.956 [Default:CheckIn:D] Running Loop=1 2025-06-19T18:32:51.342Z,1750357971.342 [Default:CheckIn:D] Stopped 2025-06-19T18:32:51.342Z,1750357971.342 [Default:CheckIn:E] Running Loop=1 2025-06-19T18:32:51.762Z,1750357971.762 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 40.312976 min 2025-06-19T18:32:51.762Z,1750357971.762 [Default:CheckIn:E] Stopped 2025-06-19T18:32:51.762Z,1750357971.762 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-06-19T18:32:51.762Z,1750357971.762 [Default:CheckIn] Stopped 2025-06-19T18:32:51.762Z,1750357971.762 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-06-19T18:32:51.762Z,1750357971.762 [Default:CheckIn](INFO): Running loop #8 2025-06-19T18:32:51.762Z,1750357971.762 [Default:CheckIn] Running Loop=8 2025-06-19T18:32:51.762Z,1750357971.762 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-06-19T18:32:51.762Z,1750357971.762 [Default:CheckIn:Read_GPS] Running Loop=1 2025-06-19T18:32:53.764Z,1750357973.764 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183252.00,A,3648.14594,N,12147.22338,W,1.769,203.15,190625,,,D*7E 2025-06-19T18:32:53.766Z,1750357973.766 [NAL9602](INFO): GPS fix at 20250619T183252: (36.802432, -121.787056) 2025-06-19T18:32:53.776Z,1750357973.776 [Default:CheckIn:Read_GPS] Stopped 2025-06-19T18:32:53.776Z,1750357973.776 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-06-19T18:33:01.676Z,1750357981.676 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20250619T180420/Courier0018.lzma 2025-06-19T18:33:02.678Z,1750357982.678 [DataOverHttps](INFO): Moved sent file to Logs/20250619T180420/Courier0018.lzma.bak 2025-06-19T18:33:02.678Z,1750357982.678 [DataOverHttps](INFO): SBD MOMSN=25229632 2025-06-19T18:33:19.237Z,1750357999.237 [DataOverHttps](INFO): Sending 156 bytes from file Logs/20250619T180420/Express0019.lzma 2025-06-19T18:33:20.238Z,1750358000.238 [DataOverHttps](INFO): Moved sent file to Logs/20250619T180420/Express0019.lzma.bak 2025-06-19T18:33:20.238Z,1750358000.238 [DataOverHttps](INFO): SBD MOMSN=25229635 2025-06-19T18:33:22.075Z,1750358002.075 [Default:CheckIn:Read_Iridium] Stopped 2025-06-19T18:33:22.075Z,1750358002.075 [Default:CheckIn:C.Wait] Running Loop=1 2025-06-19T18:33:22.075Z,1750358002.075 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-06-19T18:33:55.613Z,1750358035.613 [NAL9602](INFO): SBD MO Status=2, MOMSN=21816, MT Status=2, MTMSN=0 2025-06-19T18:33:55.613Z,1750358035.613 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-06-19T18:35:13.171Z,1750358113.171 [NAL9602](INFO): SBD MO Status=2, MOMSN=21816, MT Status=2, MTMSN=0 2025-06-19T18:35:13.171Z,1750358113.171 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-06-19T18:36:34.759Z,1750358194.759 [NAL9602](INFO): SBD MO Status=2, MOMSN=21816, MT Status=2, MTMSN=0 2025-06-19T18:36:34.759Z,1750358194.759 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-06-19T18:36:44.448Z,1750358204.448 [NAL9602](INFO): SBD MO Status=1, MOMSN=21816, MT Status=0, MTMSN=0 2025-06-19T18:36:44.448Z,1750358204.448 [NAL9602](INFO): No messages in MT queue 2025-06-19T18:37:15.148Z,1750358235.148 [NAL9602](INFO): Not Powering down - fast GPS 2025-06-19T18:38:22.630Z,1750358302.630 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-06-19T18:38:22.630Z,1750358302.630 [Default:CheckIn:C.Wait] Stopped 2025-06-19T18:38:22.630Z,1750358302.630 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-06-19T18:38:22.631Z,1750358302.631 [Default:CheckIn:D] Running Loop=1 2025-06-19T18:38:23.037Z,1750358303.037 [Default:CheckIn:D] Stopped 2025-06-19T18:38:23.037Z,1750358303.037 [Default:CheckIn:E] Running Loop=1 2025-06-19T18:38:23.448Z,1750358303.448 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 45.841231 min 2025-06-19T18:38:23.448Z,1750358303.448 [Default:CheckIn:E] Stopped 2025-06-19T18:38:23.448Z,1750358303.448 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-06-19T18:38:23.448Z,1750358303.448 [Default:CheckIn] Stopped 2025-06-19T18:38:23.448Z,1750358303.448 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-06-19T18:38:23.448Z,1750358303.448 [Default:CheckIn](INFO): Running loop #9 2025-06-19T18:38:23.449Z,1750358303.449 [Default:CheckIn] Running Loop=9 2025-06-19T18:38:23.449Z,1750358303.449 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-06-19T18:38:23.449Z,1750358303.449 [Default:CheckIn:Read_GPS] Running Loop=1 2025-06-19T18:38:25.450Z,1750358305.450 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183824.00,A,3648.17507,N,12147.27234,W,0.058,277.81,190625,,,A*7B 2025-06-19T18:38:25.453Z,1750358305.453 [NAL9602](INFO): GPS fix at 20250619T183824: (36.802918, -121.787872) 2025-06-19T18:38:25.479Z,1750358305.479 [Default:CheckIn:Read_GPS] Stopped 2025-06-19T18:38:25.479Z,1750358305.479 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-06-19T18:38:34.696Z,1750358314.696 [DataOverHttps](INFO): Sending 75 bytes from file Logs/20250619T180420/Courier0021.lzma 2025-06-19T18:38:35.698Z,1750358315.698 [DataOverHttps](INFO): Moved sent file to Logs/20250619T180420/Courier0021.lzma.bak 2025-06-19T18:38:35.698Z,1750358315.698 [DataOverHttps](INFO): SBD MOMSN=25229645 2025-06-19T18:38:51.768Z,1750358331.768 [DataOverHttps](INFO): Sending 176 bytes from file Logs/20250619T180420/Express0022.lzma 2025-06-19T18:38:52.762Z,1750358332.762 [DataOverHttps](INFO): Moved sent file to Logs/20250619T180420/Express0022.lzma.bak 2025-06-19T18:38:52.762Z,1750358332.762 [DataOverHttps](INFO): SBD MOMSN=25229648 2025-06-19T18:38:54.569Z,1750358334.569 [Default:CheckIn:Read_Iridium] Stopped 2025-06-19T18:38:54.570Z,1750358334.570 [Default:CheckIn:C.Wait] Running Loop=1 2025-06-19T18:38:54.570Z,1750358334.570 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-06-19T18:38:58.987Z,1750358338.987 [NAL9602](INFO): SBD MO Status=2, MOMSN=21817, MT Status=2, MTMSN=0 2025-06-19T18:38:58.987Z,1750358338.987 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-06-19T18:39:12.732Z,1750358352.732 [NAL9602](INFO): SBD MO Status=1, MOMSN=21817, MT Status=0, MTMSN=0 2025-06-19T18:39:12.732Z,1750358352.732 [NAL9602](INFO): No messages in MT queue 2025-06-19T18:39:43.422Z,1750358383.422 [NAL9602](INFO): Not Powering down - fast GPS 2025-06-19T18:43:55.184Z,1750358635.184 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-06-19T18:43:55.184Z,1750358635.184 [Default:CheckIn:C.Wait] Stopped 2025-06-19T18:43:55.184Z,1750358635.184 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-06-19T18:43:55.184Z,1750358635.184 [Default:CheckIn:D] Running Loop=1 2025-06-19T18:43:55.588Z,1750358635.588 [Default:CheckIn:D] Stopped 2025-06-19T18:43:55.588Z,1750358635.588 [Default:CheckIn:E] Running Loop=1 2025-06-19T18:43:55.999Z,1750358635.999 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 51.383752 min 2025-06-19T18:43:55.999Z,1750358635.999 [Default:CheckIn:E] Stopped 2025-06-19T18:43:55.999Z,1750358635.999 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-06-19T18:43:55.999Z,1750358635.999 [Default:CheckIn] Stopped 2025-06-19T18:43:55.999Z,1750358635.999 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-06-19T18:43:55.999Z,1750358635.999 [Default:CheckIn](INFO): Running loop #10 2025-06-19T18:43:55.999Z,1750358635.999 [Default:CheckIn] Running Loop=10 2025-06-19T18:43:55.999Z,1750358635.999 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-06-19T18:43:55.999Z,1750358636.000 [Default:CheckIn:Read_GPS] Running Loop=1 2025-06-19T18:43:58.002Z,1750358638.002 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184357.00,A,3648.17575,N,12147.28004,W,0.019,277.81,190625,,,D*78 2025-06-19T18:43:58.005Z,1750358638.005 [NAL9602](INFO): GPS fix at 20250619T184357: (36.802929, -121.788001) 2025-06-19T18:43:58.036Z,1750358638.036 [Default:CheckIn:Read_GPS] Stopped 2025-06-19T18:43:58.036Z,1750358638.036 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-06-19T18:44:05.652Z,1750358645.652 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20250619T180420/Courier0024.lzma 2025-06-19T18:44:06.654Z,1750358646.654 [DataOverHttps](INFO): Moved sent file to Logs/20250619T180420/Courier0024.lzma.bak 2025-06-19T18:44:06.654Z,1750358646.654 [DataOverHttps](INFO): SBD MOMSN=25229729 2025-06-19T18:44:22.764Z,1750358662.764 [DataOverHttps](INFO): Sending 155 bytes from file Logs/20250619T180420/Express0025.lzma 2025-06-19T18:44:23.766Z,1750358663.766 [DataOverHttps](INFO): Moved sent file to Logs/20250619T180420/Express0025.lzma.bak 2025-06-19T18:44:23.766Z,1750358663.766 [DataOverHttps](INFO): SBD MOMSN=25229733 2025-06-19T18:44:25.493Z,1750358665.493 [Default:CheckIn:Read_Iridium] Stopped 2025-06-19T18:44:25.493Z,1750358665.493 [Default:CheckIn:C.Wait] Running Loop=1 2025-06-19T18:44:25.493Z,1750358665.493 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-06-19T18:45:22.441Z,1750358722.441 [NAL9602](INFO): SBD MO Status=1, MOMSN=21818, MT Status=0, MTMSN=0 2025-06-19T18:45:22.441Z,1750358722.441 [NAL9602](INFO): No messages in MT queue 2025-06-19T18:45:53.190Z,1750358753.190 [NAL9602](INFO): Not Powering down - fast GPS 2025-06-19T18:49:26.102Z,1750358966.102 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-06-19T18:49:26.102Z,1750358966.102 [Default:CheckIn:C.Wait] Stopped 2025-06-19T18:49:26.102Z,1750358966.102 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-06-19T18:49:26.103Z,1750358966.103 [Default:CheckIn:D] Running Loop=1 2025-06-19T18:49:26.499Z,1750358966.499 [Default:CheckIn:D] Stopped 2025-06-19T18:49:26.499Z,1750358966.499 [Default:CheckIn:E] Running Loop=1 2025-06-19T18:49:26.905Z,1750358966.905 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 56.898938 min 2025-06-19T18:49:26.905Z,1750358966.905 [Default:CheckIn:E] Stopped 2025-06-19T18:49:26.905Z,1750358966.905 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-06-19T18:49:26.905Z,1750358966.905 [Default:CheckIn] Stopped 2025-06-19T18:49:26.905Z,1750358966.905 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-06-19T18:49:26.906Z,1750358966.906 [Default:CheckIn](INFO): Running loop #11 2025-06-19T18:49:26.906Z,1750358966.906 [Default:CheckIn] Running Loop=11 2025-06-19T18:49:26.906Z,1750358966.906 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-06-19T18:49:26.906Z,1750358966.906 [Default:CheckIn:Read_GPS] Running Loop=1 2025-06-19T18:49:28.926Z,1750358968.926 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184928.00,A,3648.17513,N,12147.27903,W,0.019,277.81,190625,,,D*7B 2025-06-19T18:49:28.928Z,1750358968.928 [NAL9602](INFO): GPS fix at 20250619T184928: (36.802919, -121.787984) 2025-06-19T18:49:28.939Z,1750358968.939 [Default:CheckIn:Read_GPS] Stopped 2025-06-19T18:49:28.939Z,1750358968.939 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-06-19T18:49:38.896Z,1750358978.896 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20250619T180420/Courier0027.lzma 2025-06-19T18:49:39.898Z,1750358979.898 [DataOverHttps](INFO): Moved sent file to Logs/20250619T180420/Courier0027.lzma.bak 2025-06-19T18:49:39.898Z,1750358979.898 [DataOverHttps](INFO): SBD MOMSN=25229807 2025-06-19T18:49:56.112Z,1750358996.112 [DataOverHttps](INFO): Sending 156 bytes from file Logs/20250619T180420/Express0028.lzma 2025-06-19T18:49:57.114Z,1750358997.114 [DataOverHttps](INFO): Moved sent file to Logs/20250619T180420/Express0028.lzma.bak 2025-06-19T18:49:57.114Z,1750358997.114 [DataOverHttps](INFO): SBD MOMSN=25229815 2025-06-19T18:49:58.836Z,1750358998.836 [Default:CheckIn:Read_Iridium] Stopped 2025-06-19T18:49:58.836Z,1750358998.836 [Default:CheckIn:C.Wait] Running Loop=1 2025-06-19T18:49:58.836Z,1750358998.836 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-06-19T18:50:15.800Z,1750359015.800 [DVL_micro](ERROR): Failed to parse: :SA,-01.00,-06.24,199.2 2025-06-19T18:51:30.143Z,1750359090.143 [NAL9602](INFO): SBD MO Status=1, MOMSN=21819, MT Status=0, MTMSN=0 2025-06-19T18:51:30.143Z,1750359090.143 [NAL9602](INFO): No messages in MT queue 2025-06-19T18:52:00.860Z,1750359120.860 [NAL9602](INFO): Not Powering down - fast GPS 2025-06-19T18:53:54.389Z,1750359234.389 [DVL_micro](ERROR): Failed to parse: :9,+00029,+00153,+00000,I 2025-06-19T18:54:59.482Z,1750359299.482 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-06-19T18:54:59.482Z,1750359299.482 [Default:CheckIn:C.Wait] Stopped 2025-06-19T18:54:59.482Z,1750359299.482 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-06-19T18:54:59.482Z,1750359299.482 [Default:CheckIn:D] Running Loop=1 2025-06-19T18:54:59.975Z,1750359299.975 [Default:CheckIn:D] Stopped 2025-06-19T18:54:59.975Z,1750359299.975 [Default:CheckIn:E] Running Loop=1 2025-06-19T18:55:00.318Z,1750359300.318 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 62.456860 min 2025-06-19T18:55:00.318Z,1750359300.318 [Default:CheckIn:E] Stopped 2025-06-19T18:55:00.318Z,1750359300.318 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-06-19T18:55:00.318Z,1750359300.318 [Default:CheckIn] Stopped 2025-06-19T18:55:00.318Z,1750359300.318 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-06-19T18:55:00.319Z,1750359300.319 [Default:CheckIn](INFO): Running loop #12 2025-06-19T18:55:00.319Z,1750359300.319 [Default:CheckIn] Running Loop=12 2025-06-19T18:55:00.319Z,1750359300.319 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-06-19T18:55:00.319Z,1750359300.319 [Default:CheckIn:Read_GPS] Running Loop=1 2025-06-19T18:55:02.258Z,1750359302.258 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185501.00,A,3648.17280,N,12147.27822,W,0.175,277.81,190625,,,D*79 2025-06-19T18:55:02.260Z,1750359302.260 [NAL9602](INFO): GPS fix at 20250619T185501: (36.802880, -121.787970) 2025-06-19T18:55:02.289Z,1750359302.289 [Default:CheckIn:Read_GPS] Stopped 2025-06-19T18:55:02.289Z,1750359302.289 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-06-19T18:55:10.356Z,1750359310.356 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20250619T180420/Courier0030.lzma 2025-06-19T18:55:11.358Z,1750359311.358 [DataOverHttps](INFO): Moved sent file to Logs/20250619T180420/Courier0030.lzma.bak 2025-06-19T18:55:11.358Z,1750359311.358 [DataOverHttps](INFO): SBD MOMSN=25229844 2025-06-19T18:55:27.365Z,1750359327.365 [DataOverHttps](INFO): Sending 156 bytes from file Logs/20250619T180420/Express0031.lzma 2025-06-19T18:55:28.366Z,1750359328.366 [DataOverHttps](INFO): Moved sent file to Logs/20250619T180420/Express0031.lzma.bak 2025-06-19T18:55:28.366Z,1750359328.366 [DataOverHttps](INFO): SBD MOMSN=25229847 2025-06-19T18:55:30.175Z,1750359330.175 [Default:CheckIn:Read_Iridium] Stopped 2025-06-19T18:55:30.175Z,1750359330.175 [Default:CheckIn:C.Wait] Running Loop=1 2025-06-19T18:55:30.175Z,1750359330.175 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-06-19T19:00:04.476Z,1750359604.476 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2025-06-19T19:00:30.724Z,1750359630.724 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-06-19T19:00:30.724Z,1750359630.724 [Default:CheckIn:C.Wait] Stopped 2025-06-19T19:00:30.724Z,1750359630.724 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-06-19T19:00:30.724Z,1750359630.724 [Default:CheckIn:D] Running Loop=1 2025-06-19T19:00:31.132Z,1750359631.132 [Default:CheckIn:D] Stopped 2025-06-19T19:00:31.132Z,1750359631.132 [Default:CheckIn:E] Running Loop=1 2025-06-19T19:00:31.531Z,1750359631.531 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 67.976152 min 2025-06-19T19:00:31.531Z,1750359631.531 [Default:CheckIn:E] Stopped 2025-06-19T19:00:31.532Z,1750359631.532 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-06-19T19:00:31.532Z,1750359631.532 [Default:CheckIn] Stopped 2025-06-19T19:00:31.548Z,1750359631.548 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-06-19T19:00:31.548Z,1750359631.548 [Default:CheckIn](INFO): Running loop #13 2025-06-19T19:00:31.548Z,1750359631.548 [Default:CheckIn] Running Loop=13 2025-06-19T19:00:31.548Z,1750359631.548 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-06-19T19:00:31.548Z,1750359631.548 [Default:CheckIn:Read_GPS] Running Loop=1 2025-06-19T19:00:33.559Z,1750359633.559 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190032.00,A,3648.19165,N,12147.27456,W,0.194,320.04,190625,,,D*70 2025-06-19T19:00:33.565Z,1750359633.565 [NAL9602](INFO): GPS fix at 20250619T190032: (36.803194, -121.787909) 2025-06-19T19:00:33.609Z,1750359633.609 [Default:CheckIn:Read_GPS] Stopped 2025-06-19T19:00:33.609Z,1750359633.609 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-06-19T19:00:41.304Z,1750359641.304 [DataOverHttps](INFO): Sending 75 bytes from file Logs/20250619T180420/Courier0033.lzma 2025-06-19T19:00:42.306Z,1750359642.306 [DataOverHttps](INFO): Moved sent file to Logs/20250619T180420/Courier0033.lzma.bak 2025-06-19T19:00:42.306Z,1750359642.306 [DataOverHttps](INFO): SBD MOMSN=25229872 2025-06-19T19:00:58.472Z,1750359658.472 [DataOverHttps](INFO): Sending 269 bytes from file Logs/20250619T180420/Express0034.lzma 2025-06-19T19:01:00.042Z,1750359660.042 [DataOverHttps](INFO): Moved sent file to Logs/20250619T180420/Express0034.lzma.bak 2025-06-19T19:01:00.043Z,1750359660.043 [DataOverHttps](INFO): SBD MOMSN=25229875 2025-06-19T19:01:01.431Z,1750359661.431 [Default:CheckIn:Read_Iridium] Stopped 2025-06-19T19:01:01.431Z,1750359661.431 [Default:CheckIn:C.Wait] Running Loop=1 2025-06-19T19:01:01.431Z,1750359661.431 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-06-19T19:01:05.457Z,1750359665.457 [NAL9602](INFO): Not Powering down - fast GPS 2025-06-19T19:06:02.017Z,1750359962.017 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-06-19T19:06:02.017Z,1750359962.017 [Default:CheckIn:C.Wait] Stopped 2025-06-19T19:06:02.017Z,1750359962.017 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-06-19T19:06:02.018Z,1750359962.018 [Default:CheckIn:D] Running Loop=1 2025-06-19T19:06:02.435Z,1750359962.435 [Default:CheckIn:D] Stopped 2025-06-19T19:06:02.435Z,1750359962.435 [Default:CheckIn:E] Running Loop=1 2025-06-19T19:06:02.814Z,1750359962.814 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 73.497868 min 2025-06-19T19:06:02.815Z,1750359962.815 [Default:CheckIn:E] Stopped 2025-06-19T19:06:02.815Z,1750359962.815 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-06-19T19:06:02.815Z,1750359962.815 [Default:CheckIn] Stopped 2025-06-19T19:06:02.815Z,1750359962.815 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-06-19T19:06:02.815Z,1750359962.815 [Default:CheckIn](INFO): Running loop #14 2025-06-19T19:06:02.815Z,1750359962.815 [Default:CheckIn] Running Loop=14 2025-06-19T19:06:02.815Z,1750359962.815 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-06-19T19:06:02.815Z,1750359962.815 [Default:CheckIn:Read_GPS] Running Loop=1 2025-06-19T19:06:04.837Z,1750359964.837 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190604.00,A,3648.17995,N,12147.27449,W,0.078,43.25,190625,,,A*47 2025-06-19T19:06:04.840Z,1750359964.840 [NAL9602](INFO): GPS fix at 20250619T190604: (36.802999, -121.787908) 2025-06-19T19:06:04.857Z,1750359964.857 [Default:CheckIn:Read_GPS] Stopped 2025-06-19T19:06:04.857Z,1750359964.857 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-06-19T19:06:12.208Z,1750359972.208 [DataOverHttps](INFO): Sending 75 bytes from file Logs/20250619T180420/Courier0036.lzma 2025-06-19T19:06:13.211Z,1750359973.211 [DataOverHttps](INFO): Moved sent file to Logs/20250619T180420/Courier0036.lzma.bak 2025-06-19T19:06:13.211Z,1750359973.211 [DataOverHttps](INFO): SBD MOMSN=25229885 2025-06-19T19:06:30.434Z,1750359990.434 [DataOverHttps](INFO): Sending 157 bytes from file Logs/20250619T180420/Express0037.lzma 2025-06-19T19:06:31.439Z,1750359991.439 [DataOverHttps](INFO): Moved sent file to Logs/20250619T180420/Express0037.lzma.bak 2025-06-19T19:06:31.439Z,1750359991.439 [DataOverHttps](INFO): SBD MOMSN=25229888 2025-06-19T19:06:33.610Z,1750359993.610 [Default:CheckIn:Read_Iridium] Stopped 2025-06-19T19:06:33.610Z,1750359993.610 [Default:CheckIn:C.Wait] Running Loop=1 2025-06-19T19:06:33.611Z,1750359993.611 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-06-19T19:06:35.568Z,1750359995.568 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2025-06-19T19:06:35.652Z,1750359995.652 [NAL9602](ERROR): received: +CSQ:0 OK819, 0, 0, 0, 0 OK 2025-06-19T19:11:07.440Z,1750360267.440 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2025-06-19T19:11:34.170Z,1750360294.170 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-06-19T19:11:34.171Z,1750360294.171 [Default:CheckIn:C.Wait] Stopped 2025-06-19T19:11:34.171Z,1750360294.171 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-06-19T19:11:34.171Z,1750360294.171 [Default:CheckIn:D] Running Loop=1 2025-06-19T19:11:34.589Z,1750360294.589 [Default:CheckIn:D] Stopped 2025-06-19T19:11:34.589Z,1750360294.589 [Default:CheckIn:E] Running Loop=1 2025-06-19T19:11:34.933Z,1750360294.933 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 79.033683 min 2025-06-19T19:11:34.933Z,1750360294.933 [Default:CheckIn:E] Stopped 2025-06-19T19:11:34.933Z,1750360294.933 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-06-19T19:11:34.933Z,1750360294.933 [Default:CheckIn] Stopped 2025-06-19T19:11:34.933Z,1750360294.933 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-06-19T19:11:34.933Z,1750360294.933 [Default:CheckIn](INFO): Running loop #15 2025-06-19T19:11:34.933Z,1750360294.933 [Default:CheckIn] Running Loop=15 2025-06-19T19:11:34.934Z,1750360294.934 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-06-19T19:11:34.934Z,1750360294.934 [Default:CheckIn:Read_GPS] Running Loop=1 2025-06-19T19:11:36.961Z,1750360296.961 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191136.00,A,3648.16703,N,12147.28441,W,1.594,115.10,190625,,,A*75 2025-06-19T19:11:36.963Z,1750360296.963 [NAL9602](INFO): GPS fix at 20250619T191136: (36.802784, -121.788073) 2025-06-19T19:11:36.974Z,1750360296.974 [Default:CheckIn:Read_GPS] Stopped 2025-06-19T19:11:36.974Z,1750360296.974 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-06-19T19:11:44.774Z,1750360304.774 [DataOverHttps](INFO): Sending 75 bytes from file Logs/20250619T180420/Courier0039.lzma 2025-06-19T19:11:45.774Z,1750360305.774 [DataOverHttps](INFO): Moved sent file to Logs/20250619T180420/Courier0039.lzma.bak 2025-06-19T19:11:45.774Z,1750360305.774 [DataOverHttps](INFO): SBD MOMSN=25229900 2025-06-19T19:12:03.052Z,1750360323.052 [DataOverHttps](INFO): Sending 244 bytes from file Logs/20250619T180420/Express0040.lzma 2025-06-19T19:12:04.066Z,1750360324.066 [DataOverHttps](INFO): Moved sent file to Logs/20250619T180420/Express0040.lzma.bak 2025-06-19T19:12:04.066Z,1750360324.066 [DataOverHttps](INFO): SBD MOMSN=25229903 2025-06-19T19:12:06.054Z,1750360326.054 [Default:CheckIn:Read_Iridium] Stopped 2025-06-19T19:12:06.055Z,1750360326.055 [Default:CheckIn:C.Wait] Running Loop=1 2025-06-19T19:12:06.055Z,1750360326.055 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-06-19T19:12:09.661Z,1750360329.661 [NAL9602](INFO): Not Powering down - fast GPS 2025-06-19T19:16:47.365Z,1750360607.365 [CommandExec](IMPORTANT): got command failComponent 2025-06-19T19:16:47.365Z,1750360607.365 [CommandExec](IMPORTANT): Failed components: 2025-06-19T19:16:47.366Z,1750360607.366 [CommandExec](IMPORTANT): No failed Components. 2025-06-19T19:16:52.573Z,1750360612.573 [CommandExec](IMPORTANT): got command quit 2025-06-19T19:16:53.576Z,1750360613.576 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread. 2025-06-19T19:16:53.576Z,1750360613.576 [CommandExec](INFO): Uninitializing the command executive. 2025-06-19T19:16:53.576Z,1750360613.576 [CommandExec](INFO): Uninitializing the command scheduler. 2025-06-19T19:16:53.577Z,1750360613.577 [CommandExec ThreadHandler](INFO): Thread cancelled. 2025-06-19T19:16:53.593Z,1750360613.593 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2025-06-19T19:16:53.593Z,1750360613.593 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2025-06-19T19:16:53.594Z,1750360613.594 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2025-06-19T19:16:53.594Z,1750360613.594 [NavChartDb](INFO): Join timeout helper Thread ID is 8992 2025-06-19T19:16:53.844Z,1750360613.844 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2025-06-19T19:16:53.845Z,1750360613.845 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2025-06-19T19:16:53.860Z,1750360613.860 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2025-06-19T19:16:53.860Z,1750360613.860 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2025-06-19T19:16:53.861Z,1750360613.861 [Radio_Surface](INFO): Join timeout helper Thread ID is 8993 2025-06-19T19:16:53.920Z,1750360613.920 [Radio_Surface](INFO): Powering down 2025-06-19T19:16:53.921Z,1750360613.921 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2025-06-19T19:16:53.921Z,1750360613.921 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2025-06-19T19:16:53.940Z,1750360613.940 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler 2025-06-19T19:16:53.940Z,1750360613.940 [Onboard ThreadHandler](INFO): Thread cancelled. 2025-06-19T19:16:53.940Z,1750360613.940 [Onboard](INFO): Join timeout helper Thread ID is 8994 2025-06-19T19:16:54.056Z,1750360614.056 [DataOverHttps](INFO): Radio surface powered OFF, will not connect. 2025-06-19T19:16:55.245Z,1750360615.245 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread. 2025-06-19T19:16:55.247Z,1750360615.247 [Onboard ThreadHandler](INFO): Thread cancelled. 2025-06-19T19:16:55.261Z,1750360615.261 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2025-06-19T19:16:55.261Z,1750360615.261 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2025-06-19T19:16:55.262Z,1750360615.262 [DataOverHttps](INFO): Join timeout helper Thread ID is 8995 2025-06-19T19:16:56.064Z,1750360616.064 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2025-06-19T19:16:56.064Z,1750360616.065 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2025-06-19T19:16:56.084Z,1750360616.084 [ComponentRegistry](INFO): Shutting down DAT ThreadHandler 2025-06-19T19:16:56.084Z,1750360616.084 [DAT ThreadHandler](INFO): Thread cancelled. 2025-06-19T19:16:56.084Z,1750360616.084 [DAT](INFO): Join timeout helper Thread ID is 8996 2025-06-19T19:16:56.208Z,1750360616.208 [DAT](INFO): Powering down 2025-06-19T19:16:56.285Z,1750360616.285 [DAT ThreadHandler](INFO): Uninitializing protected caller thread. 2025-06-19T19:16:56.285Z,1750360616.285 [DAT](INFO): Powering down 2025-06-19T19:16:56.286Z,1750360616.286 [DAT ThreadHandler](INFO): Thread cancelled. 2025-06-19T19:16:56.293Z,1750360616.293 [ComponentRegistry](INFO): Shutting down BackseatComponent ThreadHandler 2025-06-19T19:16:56.293Z,1750360616.293 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2025-06-19T19:16:56.293Z,1750360616.293 [BackseatComponent](INFO): Join timeout helper Thread ID is 8997 2025-06-19T19:16:56.397Z,1750360616.397 [BackseatComponent ThreadHandler](INFO): Uninitializing protected caller thread. 2025-06-19T19:16:56.397Z,1750360616.397 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2025-06-19T19:16:56.417Z,1750360616.417 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2025-06-19T19:16:56.417Z,1750360616.417 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2025-06-19T19:16:56.417Z,1750360616.417 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 8998 2025-06-19T19:16:56.888Z,1750360616.888 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2025-06-19T19:16:56.888Z,1750360616.888 [WetLabsBB2FL](INFO): Powering down 2025-06-19T19:16:56.889Z,1750360616.889 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2025-06-19T19:16:56.891Z,1750360616.891 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2025-06-19T19:16:56.891Z,1750360616.891 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2025-06-19T19:16:56.891Z,1750360616.891 [CTD_Seabird](INFO): Join timeout helper Thread ID is 8999 2025-06-19T19:16:57.656Z,1750360617.656 [CTD_Seabird](INFO): Powering down 2025-06-19T19:16:57.672Z,1750360617.672 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread. 2025-06-19T19:16:57.673Z,1750360617.673 [CTD_Seabird](INFO): Powering down 2025-06-19T19:16:57.684Z,1750360617.684 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2025-06-19T19:16:57.697Z,1750360617.697 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2025-06-19T19:16:57.697Z,1750360617.697 [logger ThreadHandler](INFO): Thread cancelled. 2025-06-19T19:16:57.697Z,1750360617.697 [logger](INFO): Join timeout helper Thread ID is 9000 2025-06-19T19:16:57.716Z,1750360617.716 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2025-06-19T19:16:57.717Z,1750360617.717 [logger ThreadHandler](INFO): Thread cancelled. 2025-06-19T19:16:57.725Z,1750360617.725 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2025-06-19T19:16:57.725Z,1750360617.725 [CommandLine ThreadHandler](INFO): Thread cancelled. 2025-06-19T19:16:57.725Z,1750360617.725 [CommandLine](INFO): Join timeout helper Thread ID is 9001 2025-06-19T19:16:57.796Z,1750360617.796 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2025-06-19T19:16:57.797Z,1750360617.797 [CommandLine ThreadHandler](INFO): Thread cancelled. 2025-06-19T19:16:57.813Z,1750360617.813 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler 2025-06-19T19:16:57.813Z,1750360617.813 [CommandExec ThreadHandler](INFO): Thread cancelled. 2025-06-19T19:16:57.813Z,1750360617.813 [CommandExec](INFO): Join timeout helper Thread ID is 9002 2025-06-19T19:16:57.814Z,1750360617.814 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2025-06-19T19:16:57.814Z,1750360617.814 [controlThread ThreadHandler](INFO): Thread cancelled. 2025-06-19T19:16:57.815Z,1750360617.815 [controlThread](INFO): Join timeout helper Thread ID is 9003 2025-06-19T19:16:58.092Z,1750360618.092 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2025-06-19T19:16:58.093Z,1750360618.093 [controlThread](DEBUG): Uninitializing ControlThread 2025-06-19T19:16:58.093Z,1750360618.093 [AHRS_M2](INFO): Powering down 2025-06-19T19:16:58.268Z,1750360618.268 [DVL_micro](INFO): Powering down 2025-06-19T19:16:58.269Z,1750360618.269 [NAL9602](INFO): Powering down 2025-06-19T19:16:58.270Z,1750360618.270 [Sonardyne_Nano](INFO): Powering down 2025-06-19T19:16:58.476Z,1750360618.476 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2025-06-19T19:16:58.477Z,1750360618.477 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2025-06-19T19:16:58.477Z,1750360618.477 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2025-06-19T19:16:58.478Z,1750360618.478 [MissionManager](INFO): Uninitializing Mission Default 2025-06-19T19:16:58.478Z,1750360618.478 [Default] Stopped 2025-06-19T19:16:58.478Z,1750360618.478 [Default](DEBUG): Aggregate::uninitialize Default 2025-06-19T19:16:58.478Z,1750360618.478 [Default:B.GoToSurface] Stopped 2025-06-19T19:16:58.478Z,1750360618.478 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2025-06-19T19:16:58.478Z,1750360618.478 [Default:CheckIn] Stopped 2025-06-19T19:16:58.478Z,1750360618.478 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-06-19T19:16:58.479Z,1750360618.479 [Default:CheckIn:C.Wait] Stopped 2025-06-19T19:16:58.479Z,1750360618.479 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-06-19T19:16:58.482Z,1750360618.482 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2025-06-19T19:16:58.482Z,1750360618.482 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2025-06-19T19:16:58.482Z,1750360618.482 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2025-06-19T19:16:58.482Z,1750360618.482 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2025-06-19T19:16:58.483Z,1750360618.483 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2025-06-19T19:16:58.483Z,1750360618.483 [BuoyancyServo](INFO): Powering down 2025-06-19T19:16:58.496Z,1750360618.496 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2025-06-19T19:16:58.496Z,1750360618.496 [ElevatorServo](INFO): Powering down 2025-06-19T19:16:58.497Z,1750360618.497 [MassServo](DEBUG): Uninitialize Mass Servo. 2025-06-19T19:16:58.497Z,1750360618.497 [MassServo](INFO): Powering down 2025-06-19T19:16:58.498Z,1750360618.498 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2025-06-19T19:16:58.498Z,1750360618.498 [RudderServo](INFO): Powering down 2025-06-19T19:16:58.499Z,1750360618.499 [ThrusterHE](DEBUG): Uninitialize Thruster Servo. 2025-06-19T19:16:58.499Z,1750360618.499 [ThrusterHE](INFO): Powering down 2025-06-19T19:16:58.500Z,1750360618.500 [SBIT](DEBUG): Uninitialize SBIT Component. 2025-06-19T19:16:58.500Z,1750360618.500 [IBIT](DEBUG): Uninitialize IBIT Component. 2025-06-19T19:16:58.501Z,1750360618.501 [CBIT](DEBUG): Uninitialize CBIT Component. 2025-06-19T19:16:58.501Z,1750360618.501 [CBIT](DEBUG): Powering off loads. 2025-06-19T19:16:58.512Z,1750360618.512 [CBIT](DEBUG): Disabling WDT. 2025-06-19T19:16:58.524Z,1750360618.524 [GFScanner](DEBUG): Uninitialize GFScanner component. 2025-06-19T19:16:58.524Z,1750360618.524 [GFScanner](DEBUG): Opening all GF detection circuits. 2025-06-19T19:16:58.525Z,1750360618.525 [controlThread ThreadHandler](INFO): Thread cancelled. 2025-06-19T19:16:58.554Z,1750360618.554 [GFScanner](DEBUG): Uninitialize GFScanner component. 2025-06-19T19:16:58.554Z,1750360618.554 [GFScanner](DEBUG): Opening all GF detection circuits. 2025-06-19T19:16:58.568Z,1750360618.568 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2025-06-19T19:16:58.575Z,1750360618.575 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2025-06-19T19:16:58.606Z,1750360618.606 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2025-06-19T19:16:58.609Z,1750360618.609 [Onboard ThreadHandler](INFO): Thread cancelled. 2025-06-19T19:16:58.616Z,1750360618.616 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2025-06-19T19:16:58.622Z,1750360618.622 [DAT ThreadHandler](INFO): Thread cancelled. 2025-06-19T19:16:58.664Z,1750360618.664 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2025-06-19T19:16:58.717Z,1750360618.717 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2025-06-19T19:16:58.796Z,1750360618.796 [logger ThreadHandler](INFO): Thread cancelled.