2024-08-30T19:56:10.535Z,1725047770.535 [DataOverHttps](IMPORTANT): Could not stat file Logs/20240830T180641/Courier0064.lzma 2024-08-30T19:56:10.535Z,1725047770.535 [DataOverHttps](FAULT): Could not open file Logs/20240830T180641/Courier0064.lzma 2024-08-30T19:56:10.538Z,1725047770.538 [DataOverHttps](INFO): Received command: restart logs 2024-08-30T19:56:10.550Z,1725047770.550 [CommandExec](IMPORTANT): got command restart logs 2024-08-30T19:56:22.219Z,1725047782.219 [DataOverHttps](IMPORTANT): Could not stat file Logs/20240830T180641/Courier0064.lzma 2024-08-30T19:56:22.219Z,1725047782.219 [DataOverHttps](FAULT): Could not open file Logs/20240830T180641/Courier0064.lzma 2024-08-30T19:56:37.453Z,1725047797.453 [NAL9602](INFO): Not Powering down - fast GPS 2024-08-30T19:56:49.791Z,1725047809.791 [DataOverHttps](IMPORTANT): Could not stat file Logs/20240830T180641/Courier0064.lzma 2024-08-30T19:56:49.791Z,1725047809.791 [DataOverHttps](FAULT): Could not open file Logs/20240830T180641/Courier0064.lzma 2024-08-30T19:57:20.319Z,1725047840.319 [DataOverHttps](IMPORTANT): Could not stat file Logs/20240830T180641/Courier0064.lzma 2024-08-30T19:57:20.319Z,1725047840.319 [DataOverHttps](FAULT): Could not open file Logs/20240830T180641/Courier0064.lzma 2024-08-30T19:57:51.819Z,1725047871.819 [DataOverHttps](IMPORTANT): Could not stat file Logs/20240830T180641/Courier0064.lzma 2024-08-30T19:57:51.819Z,1725047871.819 [DataOverHttps](FAULT): Could not open file Logs/20240830T180641/Courier0064.lzma 2024-08-30T19:58:29.347Z,1725047909.347 [DataOverHttps](IMPORTANT): Could not stat file Logs/20240830T180641/Courier0064.lzma 2024-08-30T19:58:29.347Z,1725047909.347 [DataOverHttps](FAULT): Could not open file Logs/20240830T180641/Courier0064.lzma 2024-08-30T19:58:51.940Z,1725047931.940 [DataOverHttps](IMPORTANT): Could not stat file Logs/20240830T180641/Courier0064.lzma 2024-08-30T19:58:51.941Z,1725047931.941 [DataOverHttps](FAULT): Could not open file Logs/20240830T180641/Courier0064.lzma 2024-08-30T19:59:22.639Z,1725047962.639 [DataOverHttps](IMPORTANT): Could not stat file Logs/20240830T180641/Courier0064.lzma 2024-08-30T19:59:22.639Z,1725047962.639 [DataOverHttps](FAULT): Could not open file Logs/20240830T180641/Courier0064.lzma 2024-08-30T19:59:53.259Z,1725047993.259 [DataOverHttps](IMPORTANT): Could not stat file Logs/20240830T180641/Courier0064.lzma 2024-08-30T19:59:53.259Z,1725047993.259 [DataOverHttps](FAULT): Could not open file Logs/20240830T180641/Courier0064.lzma 2024-08-30T20:00:23.719Z,1725048023.719 [DataOverHttps](IMPORTANT): Could not stat file Logs/20240830T180641/Courier0064.lzma 2024-08-30T20:00:23.719Z,1725048023.719 [DataOverHttps](FAULT): Could not open file Logs/20240830T180641/Courier0064.lzma 2024-08-30T20:00:54.278Z,1725048054.278 [DataOverHttps](IMPORTANT): Could not stat file Logs/20240830T180641/Courier0064.lzma 2024-08-30T20:00:54.278Z,1725048054.278 [DataOverHttps](FAULT): Could not open file Logs/20240830T180641/Courier0064.lzma 2024-08-30T20:01:07.353Z,1725048067.353 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-08-30T20:01:07.353Z,1725048067.353 [Default:CheckIn:C.Wait] Stopped 2024-08-30T20:01:07.353Z,1725048067.353 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-08-30T20:01:07.353Z,1725048067.353 [Default:CheckIn:D] Running Loop=1 2024-08-30T20:01:07.763Z,1725048067.763 [Default:CheckIn:D] Stopped 2024-08-30T20:01:07.763Z,1725048067.763 [Default:CheckIn:E] Running Loop=1 2024-08-30T20:01:08.166Z,1725048068.166 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 32.482306 min 2024-08-30T20:01:08.166Z,1725048068.166 [Default:CheckIn:E] Stopped 2024-08-30T20:01:08.166Z,1725048068.166 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-08-30T20:01:08.166Z,1725048068.166 [Default:CheckIn] Stopped 2024-08-30T20:01:08.166Z,1725048068.166 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-08-30T20:01:08.167Z,1725048068.167 [Default:CheckIn](INFO): Running loop #6 2024-08-30T20:01:08.167Z,1725048068.167 [Default:CheckIn] Running Loop=6 2024-08-30T20:01:08.167Z,1725048068.167 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-08-30T20:01:08.167Z,1725048068.167 [Default:CheckIn:Read_GPS] Running Loop=1 2024-08-30T20:01:10.170Z,1725048070.170 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200109.00,A,3648.29329,N,12147.13419,W,4.879,187.52,300824,,,D*70 2024-08-30T20:01:10.173Z,1725048070.173 [NAL9602](INFO): GPS fix at 20240830T200109: (36.804888, -121.785570) 2024-08-30T20:01:10.182Z,1725048070.182 [Default:CheckIn:Read_GPS] Stopped 2024-08-30T20:01:10.182Z,1725048070.182 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-08-30T20:01:19.064Z,1725048079.064 [DataOverHttps](INFO): Sending 40 bytes from file Logs/20240830T180641/Courier0067.lzma 2024-08-30T20:01:20.067Z,1725048080.067 [DataOverHttps](INFO): Moved sent file to Logs/20240830T180641/Courier0067.lzma.bak 2024-08-30T20:01:20.067Z,1725048080.067 [DataOverHttps](INFO): SBD MOMSN=23103663 2024-08-30T20:01:38.884Z,1725048098.884 [DataOverHttps](INFO): Sending 272 bytes from file Logs/20240830T195610/Courier0000.lzma 2024-08-30T20:01:39.886Z,1725048099.886 [DataOverHttps](INFO): Moved sent file to Logs/20240830T195610/Courier0000.lzma.bak 2024-08-30T20:01:39.886Z,1725048099.886 [DataOverHttps](INFO): SBD MOMSN=23103665 2024-08-30T20:01:40.071Z,1725048100.071 [NAL9602](INFO): SBD MO Status=0, MOMSN=16377, MT Status=0, MTMSN=0 2024-08-30T20:01:40.072Z,1725048100.072 [NAL9602](INFO): No messages in MT queue 2024-08-30T20:01:57.600Z,1725048117.600 [DataOverHttps](INFO): Sending 179 bytes from file Logs/20240830T180641/Express0062.lzma 2024-08-30T20:01:58.603Z,1725048118.603 [DataOverHttps](INFO): Moved sent file to Logs/20240830T180641/Express0062.lzma.bak 2024-08-30T20:01:58.603Z,1725048118.603 [DataOverHttps](INFO): SBD MOMSN=23103717 2024-08-30T20:02:10.773Z,1725048130.773 [NAL9602](INFO): Not Powering down - fast GPS 2024-08-30T20:02:16.165Z,1725048136.165 [DataOverHttps](INFO): Sending 294 bytes from file Logs/20240830T180641/Express0065.lzma 2024-08-30T20:02:18.171Z,1725048138.171 [DataOverHttps](INFO): Moved sent file to Logs/20240830T180641/Express0065.lzma.bak 2024-08-30T20:02:18.171Z,1725048138.171 [DataOverHttps](INFO): SBD MOMSN=23103723 2024-08-30T20:02:38.640Z,1725048158.640 [DataOverHttps](INFO): Sending 109 bytes from file Logs/20240830T180641/Express0068.lzma 2024-08-30T20:02:39.643Z,1725048159.643 [DataOverHttps](INFO): Moved sent file to Logs/20240830T180641/Express0068.lzma.bak 2024-08-30T20:02:39.643Z,1725048159.643 [DataOverHttps](INFO): SBD MOMSN=23103785 2024-08-30T20:03:04.521Z,1725048184.521 [DataOverHttps](INFO): Sending 564 bytes from file Logs/20240830T195610/Express0001.lzma 2024-08-30T20:03:06.526Z,1725048186.526 [DataOverHttps](INFO): Moved sent file to Logs/20240830T195610/Express0001.lzma.bak 2024-08-30T20:03:06.526Z,1725048186.526 [DataOverHttps](INFO): SBD MOMSN=23103816 2024-08-30T20:04:10.433Z,1725048250.433 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-08-30T20:04:41.565Z,1725048281.565 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-08-30T20:05:12.709Z,1725048312.709 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-08-30T20:05:43.841Z,1725048343.841 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-08-30T20:06:06.941Z,1725048366.941 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.415390 2024-08-30T20:06:26.764Z,1725048386.764 [NAL9602](INFO): SBD MO Status=1, MOMSN=16378, MT Status=0, MTMSN=0 2024-08-30T20:06:26.821Z,1725048386.821 [NAL9602](INFO): Sent 63 bytes from file Logs/20240830T195610/Express0004.lzma 2024-08-30T20:06:26.821Z,1725048386.821 [NAL9602](INFO): Packets left to send: 0 2024-08-30T20:06:33.329Z,1725048393.329 [NAL9602](INFO): SBD MO Status=0, MOMSN=16379, MT Status=0, MTMSN=0 2024-08-30T20:06:33.412Z,1725048393.412 [Default:CheckIn:Read_Iridium] Stopped 2024-08-30T20:06:33.413Z,1725048393.413 [Default:CheckIn:C.Wait] Running Loop=1 2024-08-30T20:06:33.413Z,1725048393.413 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-08-30T20:06:38.065Z,1725048398.065 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-08-30T20:07:04.020Z,1725048424.020 [NAL9602](INFO): Not Powering down - fast GPS 2024-08-30T20:07:09.193Z,1725048429.193 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-08-30T20:07:40.317Z,1725048460.317 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-08-30T20:08:11.441Z,1725048491.441 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-08-30T20:08:42.565Z,1725048522.565 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-08-30T20:09:13.689Z,1725048553.689 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-08-30T20:09:44.813Z,1725048584.813 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-08-30T20:10:15.937Z,1725048615.937 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-08-30T20:10:47.065Z,1725048647.065 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-08-30T20:11:18.197Z,1725048678.197 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-08-30T20:11:33.909Z,1725048693.909 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-08-30T20:11:33.910Z,1725048693.910 [Default:CheckIn:C.Wait] Stopped 2024-08-30T20:11:33.910Z,1725048693.910 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-08-30T20:11:33.910Z,1725048693.910 [Default:CheckIn:D] Running Loop=1 2024-08-30T20:11:34.303Z,1725048694.303 [Default:CheckIn:D] Stopped 2024-08-30T20:11:34.303Z,1725048694.303 [Default:CheckIn:E] Running Loop=1 2024-08-30T20:11:34.711Z,1725048694.711 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 42.924630 min 2024-08-30T20:11:34.711Z,1725048694.711 [Default:CheckIn:E] Stopped 2024-08-30T20:11:34.711Z,1725048694.711 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-08-30T20:11:34.711Z,1725048694.711 [Default:CheckIn] Stopped 2024-08-30T20:11:34.711Z,1725048694.711 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-08-30T20:11:34.712Z,1725048694.712 [Default:CheckIn](INFO): Running loop #7 2024-08-30T20:11:34.712Z,1725048694.712 [Default:CheckIn] Running Loop=7 2024-08-30T20:11:34.712Z,1725048694.712 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-08-30T20:11:34.712Z,1725048694.712 [Default:CheckIn:Read_GPS] Running Loop=1 2024-08-30T20:11:36.728Z,1725048696.728 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,201136.00,A,3648.15089,N,12147.22295,W,0.000,316.50,300824,,,D*71 2024-08-30T20:11:36.746Z,1725048696.746 [NAL9602](INFO): GPS fix at 20240830T201136: (36.802515, -121.787049) 2024-08-30T20:11:36.764Z,1725048696.764 [Default:CheckIn:Read_GPS] Stopped 2024-08-30T20:11:36.764Z,1725048696.764 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-08-30T20:11:49.321Z,1725048709.321 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-08-30T20:12:20.445Z,1725048740.445 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-08-30T20:12:33.896Z,1725048753.896 [NAL9602](INFO): SBD MO Status=2, MOMSN=16380, MT Status=2, MTMSN=0 2024-08-30T20:12:33.896Z,1725048753.896 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2024-08-30T20:12:51.569Z,1725048771.569 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-08-30T20:12:59.932Z,1725048779.932 [NAL9602](INFO): SBD MO Status=1, MOMSN=16380, MT Status=0, MTMSN=0 2024-08-30T20:12:59.981Z,1725048779.981 [NAL9602](INFO): Sent 76 bytes from file Logs/20240830T195610/Courier0006.lzma 2024-08-30T20:12:59.981Z,1725048779.981 [NAL9602](INFO): Packets left to send: 0 2024-08-30T20:13:20.186Z,1725048800.186 [NAL9602](INFO): SBD MO Status=1, MOMSN=16381, MT Status=0, MTMSN=0 2024-08-30T20:13:20.241Z,1725048800.241 [NAL9602](INFO): Sent 149 bytes from file Logs/20240830T195610/Express0007.lzma 2024-08-30T20:13:20.241Z,1725048800.241 [NAL9602](INFO): Packets left to send: 0 2024-08-30T20:13:22.697Z,1725048802.697 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-08-30T20:13:35.707Z,1725048815.707 [NAL9602](INFO): SBD MO Status=2, MOMSN=16382, MT Status=2, MTMSN=0 2024-08-30T20:13:35.708Z,1725048815.708 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2024-08-30T20:13:51.155Z,1725048831.155 [BPC1](INFO): Calculating totals. Valid battery stick count: 27. Valid reserve battery stick count: 4. 2024-08-30T20:13:51.157Z,1725048831.157 [BPC1](INFO): Received data from all battery sticks. 2024-08-30T20:13:53.821Z,1725048833.821 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-08-30T20:13:53.980Z,1725048833.980 [NAL9602](INFO): SBD MO Status=2, MOMSN=16382, MT Status=2, MTMSN=0 2024-08-30T20:13:53.980Z,1725048833.980 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2024-08-30T20:14:17.082Z,1725048857.082 [NAL9602](INFO): SBD MO Status=2, MOMSN=16382, MT Status=2, MTMSN=0 2024-08-30T20:14:17.082Z,1725048857.082 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2024-08-30T20:14:23.563Z,1725048863.563 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2024-08-30T20:14:24.945Z,1725048864.945 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-08-30T20:14:26.894Z,1725048866.894 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2024-08-30T20:14:35.138Z,1725048875.138 [NAL9602](INFO): SBD MO Status=0, MOMSN=16382, MT Status=0, MTMSN=0 2024-08-30T20:14:35.218Z,1725048875.218 [Default:CheckIn:Read_Iridium] Stopped 2024-08-30T20:14:35.218Z,1725048875.218 [Default:CheckIn:C.Wait] Running Loop=1 2024-08-30T20:14:35.218Z,1725048875.218 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-08-30T20:14:56.081Z,1725048896.081 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-08-30T20:15:05.840Z,1725048905.840 [NAL9602](INFO): Not Powering down - fast GPS 2024-08-30T20:15:27.205Z,1725048927.205 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-08-30T20:15:58.329Z,1725048958.329 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-08-30T20:16:23.814Z,1725048983.814 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003345 2024-08-30T20:16:59.953Z,1725049019.953 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-08-30T20:17:31.089Z,1725049051.089 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-08-30T20:18:02.213Z,1725049082.213 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-08-30T20:18:33.349Z,1725049113.349 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-08-30T20:19:04.501Z,1725049144.501 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-08-30T20:19:35.723Z,1725049175.723 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-08-30T20:19:35.723Z,1725049175.723 [Default:CheckIn:C.Wait] Stopped 2024-08-30T20:19:35.723Z,1725049175.723 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-08-30T20:19:35.724Z,1725049175.724 [Default:CheckIn:D] Running Loop=1 2024-08-30T20:19:36.154Z,1725049176.154 [Default:CheckIn:D] Stopped 2024-08-30T20:19:36.154Z,1725049176.154 [Default:CheckIn:E] Running Loop=1 2024-08-30T20:19:36.535Z,1725049176.535 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 50.955489 min 2024-08-30T20:19:36.535Z,1725049176.535 [Default:CheckIn:E] Stopped 2024-08-30T20:19:36.535Z,1725049176.535 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-08-30T20:19:36.535Z,1725049176.535 [Default:CheckIn] Stopped 2024-08-30T20:19:36.535Z,1725049176.535 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-08-30T20:19:36.535Z,1725049176.535 [Default:CheckIn](INFO): Running loop #8 2024-08-30T20:19:36.535Z,1725049176.535 [Default:CheckIn] Running Loop=8 2024-08-30T20:19:36.535Z,1725049176.535 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-08-30T20:19:36.535Z,1725049176.535 [Default:CheckIn:Read_GPS] Running Loop=1 2024-08-30T20:19:38.544Z,1725049178.544 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,201938.00,A,3648.16772,N,12147.28356,W,0.156,348.99,300824,,,D*7F 2024-08-30T20:19:38.546Z,1725049178.546 [NAL9602](INFO): GPS fix at 20240830T201938: (36.802795, -121.788059) 2024-08-30T20:19:38.565Z,1725049178.565 [Default:CheckIn:Read_GPS] Stopped 2024-08-30T20:19:38.565Z,1725049178.565 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-08-30T20:19:42.609Z,1725049182.609 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20240830T195610/Courier0009.lzma 2024-08-30T20:19:42.746Z,1725049182.746 [DataOverHttps](INFO): Moved sent file to Logs/20240830T195610/Courier0009.lzma.bak 2024-08-30T20:19:42.746Z,1725049182.746 [DataOverHttps](INFO): SBD MOMSN=23103876 2024-08-30T20:20:00.874Z,1725049200.874 [DataOverHttps](INFO): Sending 147 bytes from file Logs/20240830T195610/Express0010.lzma 2024-08-30T20:20:03.680Z,1725049203.680 [DataOverHttps](INFO): Moved sent file to Logs/20240830T195610/Express0010.lzma.bak 2024-08-30T20:20:03.680Z,1725049203.680 [DataOverHttps](INFO): SBD MOMSN=23103879 2024-08-30T20:20:05.772Z,1725049205.772 [Default:CheckIn:Read_Iridium] Stopped 2024-08-30T20:20:05.777Z,1725049205.777 [Default:CheckIn:C.Wait] Running Loop=1 2024-08-30T20:20:05.777Z,1725049205.777 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-08-30T20:24:40.870Z,1725049480.870 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2024-08-30T20:25:06.326Z,1725049506.326 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-08-30T20:25:06.326Z,1725049506.326 [Default:CheckIn:C.Wait] Stopped 2024-08-30T20:25:06.326Z,1725049506.326 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-08-30T20:25:06.327Z,1725049506.327 [Default:CheckIn:D] Running Loop=1 2024-08-30T20:25:06.733Z,1725049506.733 [Default:CheckIn:D] Stopped 2024-08-30T20:25:06.733Z,1725049506.733 [Default:CheckIn:E] Running Loop=1 2024-08-30T20:25:07.146Z,1725049507.146 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 56.465125 min 2024-08-30T20:25:07.147Z,1725049507.147 [Default:CheckIn:E] Stopped 2024-08-30T20:25:07.147Z,1725049507.147 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-08-30T20:25:07.147Z,1725049507.147 [Default:CheckIn] Stopped 2024-08-30T20:25:07.147Z,1725049507.147 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-08-30T20:25:07.147Z,1725049507.147 [Default:CheckIn](INFO): Running loop #9 2024-08-30T20:25:07.147Z,1725049507.147 [Default:CheckIn] Running Loop=9 2024-08-30T20:25:07.147Z,1725049507.147 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-08-30T20:25:07.147Z,1725049507.147 [Default:CheckIn:Read_GPS] Running Loop=1 2024-08-30T20:25:09.150Z,1725049509.150 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,202508.00,A,3648.17032,N,12147.28502,W,0.311,203.93,300824,,,A*76 2024-08-30T20:25:09.153Z,1725049509.153 [NAL9602](INFO): GPS fix at 20240830T202508: (36.802839, -121.788084) 2024-08-30T20:25:09.183Z,1725049509.183 [Default:CheckIn:Read_GPS] Stopped 2024-08-30T20:25:09.183Z,1725049509.183 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-08-30T20:25:17.672Z,1725049517.672 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20240830T195610/Courier0012.lzma 2024-08-30T20:25:18.674Z,1725049518.674 [DataOverHttps](INFO): Moved sent file to Logs/20240830T195610/Courier0012.lzma.bak 2024-08-30T20:25:18.674Z,1725049518.674 [DataOverHttps](INFO): SBD MOMSN=23103960 2024-08-30T20:25:38.394Z,1725049538.394 [DataOverHttps](INFO): Sending 235 bytes from file Logs/20240830T195610/Express0013.lzma 2024-08-30T20:25:39.058Z,1725049539.058 [DataOverHttps](INFO): Moved sent file to Logs/20240830T195610/Express0013.lzma.bak 2024-08-30T20:25:39.059Z,1725049539.059 [DataOverHttps](INFO): SBD MOMSN=23103965 2024-08-30T20:25:41.879Z,1725049541.879 [NAL9602](INFO): Not Powering down - fast GPS 2024-08-30T20:25:42.323Z,1725049542.323 [Default:CheckIn:Read_Iridium] Stopped 2024-08-30T20:25:42.323Z,1725049542.323 [Default:CheckIn:C.Wait] Running Loop=1 2024-08-30T20:25:42.323Z,1725049542.323 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-08-30T20:30:42.867Z,1725049842.867 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-08-30T20:30:42.868Z,1725049842.868 [Default:CheckIn:C.Wait] Stopped 2024-08-30T20:30:42.868Z,1725049842.868 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-08-30T20:30:42.868Z,1725049842.868 [Default:CheckIn:D] Running Loop=1 2024-08-30T20:30:43.280Z,1725049843.280 [Default:CheckIn:D] Stopped 2024-08-30T20:30:43.281Z,1725049843.281 [Default:CheckIn:E] Running Loop=1 2024-08-30T20:30:43.674Z,1725049843.674 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 62.074255 min 2024-08-30T20:30:43.674Z,1725049843.674 [Default:CheckIn:E] Stopped 2024-08-30T20:30:43.674Z,1725049843.674 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-08-30T20:30:43.674Z,1725049843.674 [Default:CheckIn] Stopped 2024-08-30T20:30:43.675Z,1725049843.675 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-08-30T20:30:43.675Z,1725049843.675 [Default:CheckIn](INFO): Running loop #10 2024-08-30T20:30:43.675Z,1725049843.675 [Default:CheckIn] Running Loop=10 2024-08-30T20:30:43.675Z,1725049843.675 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-08-30T20:30:43.675Z,1725049843.675 [Default:CheckIn:Read_GPS] Running Loop=1 2024-08-30T20:30:45.691Z,1725049845.691 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,203045.00,A,3648.16616,N,12147.27571,W,0.875,203.93,300824,,,A*78 2024-08-30T20:30:45.693Z,1725049845.693 [NAL9602](INFO): GPS fix at 20240830T203045: (36.802769, -121.787929) 2024-08-30T20:30:45.702Z,1725049845.702 [Default:CheckIn:Read_GPS] Stopped 2024-08-30T20:30:45.702Z,1725049845.702 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-08-30T20:30:54.052Z,1725049854.052 [DataOverHttps](INFO): Sending 77 bytes from file Logs/20240830T195610/Courier0015.lzma 2024-08-30T20:30:55.054Z,1725049855.054 [DataOverHttps](INFO): Moved sent file to Logs/20240830T195610/Courier0015.lzma.bak 2024-08-30T20:30:55.055Z,1725049855.055 [DataOverHttps](INFO): SBD MOMSN=23104048 2024-08-30T20:31:13.655Z,1725049873.655 [DataOverHttps](INFO): Sending 134 bytes from file Logs/20240830T195610/Express0016.lzma 2024-08-30T20:31:14.218Z,1725049874.218 [DataOverHttps](INFO): Moved sent file to Logs/20240830T195610/Express0016.lzma.bak 2024-08-30T20:31:14.219Z,1725049874.219 [DataOverHttps](INFO): SBD MOMSN=23104051 2024-08-30T20:31:16.159Z,1725049876.159 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2024-08-30T20:31:16.237Z,1725049876.237 [NAL9602](ERROR): received: +CSQ:0 OK382, 0, 0, 0, 0 OK 2024-08-30T20:31:17.420Z,1725049877.420 [Default:CheckIn:Read_Iridium] Stopped 2024-08-30T20:31:17.420Z,1725049877.420 [Default:CheckIn:C.Wait] Running Loop=1 2024-08-30T20:31:17.420Z,1725049877.420 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-08-30T20:35:48.100Z,1725050148.100 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2024-08-30T20:36:18.001Z,1725050178.001 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-08-30T20:36:18.001Z,1725050178.001 [Default:CheckIn:C.Wait] Stopped 2024-08-30T20:36:18.001Z,1725050178.001 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-08-30T20:36:18.002Z,1725050178.002 [Default:CheckIn:D] Running Loop=1 2024-08-30T20:36:18.403Z,1725050178.403 [Default:CheckIn:D] Stopped 2024-08-30T20:36:18.403Z,1725050178.403 [Default:CheckIn:E] Running Loop=1 2024-08-30T20:36:18.806Z,1725050178.806 [NAL9602](INFO): Not Powering down - fast GPS 2024-08-30T20:36:18.823Z,1725050178.823 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 67.659631 min 2024-08-30T20:36:18.823Z,1725050178.823 [Default:CheckIn:E] Stopped 2024-08-30T20:36:18.823Z,1725050178.823 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-08-30T20:36:18.824Z,1725050178.824 [Default:CheckIn] Stopped 2024-08-30T20:36:18.824Z,1725050178.824 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-08-30T20:36:18.824Z,1725050178.824 [Default:CheckIn](INFO): Running loop #11 2024-08-30T20:36:18.824Z,1725050178.824 [Default:CheckIn] Running Loop=11 2024-08-30T20:36:18.824Z,1725050178.824 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-08-30T20:36:18.824Z,1725050178.824 [Default:CheckIn:Read_GPS] Running Loop=1 2024-08-30T20:36:20.823Z,1725050180.823 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,203620.00,A,3648.16792,N,12147.28254,W,0.233,210.70,300824,,,A*78 2024-08-30T20:36:20.826Z,1725050180.826 [NAL9602](INFO): GPS fix at 20240830T203620: (36.802799, -121.788042) 2024-08-30T20:36:20.852Z,1725050180.852 [Default:CheckIn:Read_GPS] Stopped 2024-08-30T20:36:20.852Z,1725050180.852 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-08-30T20:36:28.744Z,1725050188.744 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20240830T195610/Courier0018.lzma 2024-08-30T20:36:29.758Z,1725050189.758 [DataOverHttps](INFO): Moved sent file to Logs/20240830T195610/Courier0018.lzma.bak 2024-08-30T20:36:29.759Z,1725050189.759 [DataOverHttps](INFO): SBD MOMSN=23104092 2024-08-30T20:36:50.632Z,1725050210.632 [DataOverHttps](INFO): Sending 209 bytes from file Logs/20240830T195610/Express0019.lzma 2024-08-30T20:36:51.539Z,1725050211.539 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2024-08-30T20:36:51.613Z,1725050211.613 [NAL9602](ERROR): received: +CSQ:0 OK382, 0, 0, 0, 0 OK 2024-08-30T20:36:51.655Z,1725050211.655 [DataOverHttps](INFO): Moved sent file to Logs/20240830T195610/Express0019.lzma.bak 2024-08-30T20:36:51.655Z,1725050211.655 [DataOverHttps](INFO): SBD MOMSN=23104096 2024-08-30T20:36:54.797Z,1725050214.797 [Default:CheckIn:Read_Iridium] Stopped 2024-08-30T20:36:54.797Z,1725050214.797 [Default:CheckIn:C.Wait] Running Loop=1 2024-08-30T20:36:54.797Z,1725050214.797 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-08-30T20:37:01.643Z,1725050221.643 [Sonardyne_Nano](INFO): Battery below minimum, enabling charging 2024-08-30T20:41:23.029Z,1725050483.029 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2024-08-30T20:41:53.734Z,1725050513.734 [NAL9602](INFO): Not Powering down - fast GPS 2024-08-30T20:41:55.354Z,1725050515.354 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-08-30T20:41:55.354Z,1725050515.354 [Default:CheckIn:C.Wait] Stopped 2024-08-30T20:41:55.354Z,1725050515.354 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-08-30T20:41:55.355Z,1725050515.355 [Default:CheckIn:D] Running Loop=1 2024-08-30T20:41:55.760Z,1725050515.760 [Default:CheckIn:D] Stopped 2024-08-30T20:41:55.760Z,1725050515.760 [Default:CheckIn:E] Running Loop=1 2024-08-30T20:41:56.170Z,1725050516.170 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 73.282251 min 2024-08-30T20:41:56.170Z,1725050516.170 [Default:CheckIn:E] Stopped 2024-08-30T20:41:56.170Z,1725050516.170 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-08-30T20:41:56.170Z,1725050516.170 [Default:CheckIn] Stopped 2024-08-30T20:41:56.170Z,1725050516.170 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-08-30T20:41:56.171Z,1725050516.171 [Default:CheckIn](INFO): Running loop #12 2024-08-30T20:41:56.171Z,1725050516.171 [Default:CheckIn] Running Loop=12 2024-08-30T20:41:56.171Z,1725050516.171 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-08-30T20:41:56.171Z,1725050516.171 [Default:CheckIn:Read_GPS] Running Loop=1 2024-08-30T20:41:58.174Z,1725050518.174 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,204157.00,A,3648.16972,N,12147.28233,W,0.408,355.21,300824,,,A*73 2024-08-30T20:41:58.177Z,1725050518.177 [NAL9602](INFO): GPS fix at 20240830T204157: (36.802829, -121.788039) 2024-08-30T20:41:58.206Z,1725050518.206 [Default:CheckIn:Read_GPS] Stopped 2024-08-30T20:41:58.206Z,1725050518.206 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-08-30T20:42:06.476Z,1725050526.476 [DataOverHttps](INFO): Sending 77 bytes from file Logs/20240830T195610/Courier0021.lzma 2024-08-30T20:42:07.479Z,1725050527.479 [DataOverHttps](INFO): Moved sent file to Logs/20240830T195610/Courier0021.lzma.bak 2024-08-30T20:42:07.479Z,1725050527.479 [DataOverHttps](INFO): SBD MOMSN=23104165 2024-08-30T20:42:26.813Z,1725050546.813 [DataOverHttps](INFO): Sending 210 bytes from file Logs/20240830T195610/Express0022.lzma 2024-08-30T20:42:27.814Z,1725050547.814 [DataOverHttps](INFO): Moved sent file to Logs/20240830T195610/Express0022.lzma.bak 2024-08-30T20:42:27.815Z,1725050547.815 [DataOverHttps](INFO): SBD MOMSN=23104168 2024-08-30T20:42:28.886Z,1725050548.886 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2024-08-30T20:42:28.965Z,1725050548.965 [NAL9602](ERROR): received: +CSQ:0 OK382, 0, 0, 0, 0 OK 2024-08-30T20:42:30.948Z,1725050550.948 [Default:CheckIn:Read_Iridium] Stopped 2024-08-30T20:42:30.952Z,1725050550.952 [Default:CheckIn:C.Wait] Running Loop=1 2024-08-30T20:42:30.953Z,1725050550.953 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-08-30T20:47:00.809Z,1725050820.809 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2024-08-30T20:47:31.504Z,1725050851.504 [NAL9602](INFO): Not Powering down - fast GPS 2024-08-30T20:47:31.526Z,1725050851.526 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-08-30T20:47:31.526Z,1725050851.526 [Default:CheckIn:C.Wait] Stopped 2024-08-30T20:47:31.526Z,1725050851.526 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-08-30T20:47:31.526Z,1725050851.526 [Default:CheckIn:D] Running Loop=1 2024-08-30T20:47:31.997Z,1725050851.997 [Default:CheckIn:D] Stopped 2024-08-30T20:47:31.997Z,1725050851.997 [Default:CheckIn:E] Running Loop=1 2024-08-30T20:47:32.382Z,1725050852.382 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 78.886190 min 2024-08-30T20:47:32.382Z,1725050852.382 [Default:CheckIn:E] Stopped 2024-08-30T20:47:32.382Z,1725050852.382 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-08-30T20:47:32.382Z,1725050852.382 [Default:CheckIn] Stopped 2024-08-30T20:47:32.382Z,1725050852.382 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-08-30T20:47:32.383Z,1725050852.383 [Default:CheckIn](INFO): Running loop #13 2024-08-30T20:47:32.383Z,1725050852.383 [Default:CheckIn] Running Loop=13 2024-08-30T20:47:32.383Z,1725050852.383 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-08-30T20:47:32.383Z,1725050852.383 [Default:CheckIn:Read_GPS] Running Loop=1 2024-08-30T20:47:34.351Z,1725050854.351 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,204734.00,A,3648.16789,N,12147.28119,W,0.214,30.92,300824,,,A*42 2024-08-30T20:47:34.357Z,1725050854.357 [NAL9602](INFO): GPS fix at 20240830T204734: (36.802798, -121.788020) 2024-08-30T20:47:34.372Z,1725050854.372 [Default:CheckIn:Read_GPS] Stopped 2024-08-30T20:47:34.372Z,1725050854.372 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-08-30T20:47:41.748Z,1725050861.748 [DataOverHttps](INFO): Sending 77 bytes from file Logs/20240830T195610/Courier0024.lzma 2024-08-30T20:47:42.750Z,1725050862.750 [DataOverHttps](INFO): Moved sent file to Logs/20240830T195610/Courier0024.lzma.bak 2024-08-30T20:47:42.751Z,1725050862.751 [DataOverHttps](INFO): SBD MOMSN=23104259 2024-08-30T20:48:00.520Z,1725050880.520 [DataOverHttps](INFO): Sending 210 bytes from file Logs/20240830T195610/Express0025.lzma 2024-08-30T20:48:01.522Z,1725050881.522 [DataOverHttps](INFO): Moved sent file to Logs/20240830T195610/Express0025.lzma.bak 2024-08-30T20:48:01.523Z,1725050881.523 [DataOverHttps](INFO): SBD MOMSN=23104262 2024-08-30T20:48:04.657Z,1725050884.657 [Default:CheckIn:Read_Iridium] Stopped 2024-08-30T20:48:04.657Z,1725050884.657 [Default:CheckIn:C.Wait] Running Loop=1 2024-08-30T20:48:04.657Z,1725050884.657 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-08-30T20:48:05.039Z,1725050885.039 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2024-08-30T20:48:05.117Z,1725050885.117 [NAL9602](ERROR): received: +CSQ:0 OK382, 0, 0, 0, 0 OK 2024-08-30T20:52:21.176Z,1725051141.176 [NAL9602](INFO): SBD MO Status=2, MOMSN=16383, MT Status=2, MTMSN=0 2024-08-30T20:52:21.176Z,1725051141.176 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2024-08-30T20:52:36.934Z,1725051156.934 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2024-08-30T20:53:05.218Z,1725051185.218 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-08-30T20:53:05.218Z,1725051185.218 [Default:CheckIn:C.Wait] Stopped 2024-08-30T20:53:05.218Z,1725051185.218 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-08-30T20:53:05.218Z,1725051185.218 [Default:CheckIn:D] Running Loop=1 2024-08-30T20:53:05.626Z,1725051185.626 [Default:CheckIn:D] Stopped 2024-08-30T20:53:05.626Z,1725051185.626 [Default:CheckIn:E] Running Loop=1 2024-08-30T20:53:06.027Z,1725051186.027 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 84.446688 min 2024-08-30T20:53:06.027Z,1725051186.027 [Default:CheckIn:E] Stopped 2024-08-30T20:53:06.027Z,1725051186.027 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-08-30T20:53:06.027Z,1725051186.027 [Default:CheckIn] Stopped 2024-08-30T20:53:06.027Z,1725051186.027 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-08-30T20:53:06.027Z,1725051186.027 [Default:CheckIn](INFO): Running loop #14 2024-08-30T20:53:06.028Z,1725051186.028 [Default:CheckIn] Running Loop=14 2024-08-30T20:53:06.028Z,1725051186.028 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-08-30T20:53:06.028Z,1725051186.028 [Default:CheckIn:Read_GPS] Running Loop=1 2024-08-30T20:53:08.049Z,1725051188.049 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,205307.00,A,3648.16561,N,12147.28316,W,0.778,159.51,300824,,,A*70 2024-08-30T20:53:08.051Z,1725051188.051 [NAL9602](INFO): GPS fix at 20240830T205307: (36.802760, -121.788053) 2024-08-30T20:53:08.061Z,1725051188.061 [Default:CheckIn:Read_GPS] Stopped 2024-08-30T20:53:08.062Z,1725051188.062 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-08-30T20:53:15.612Z,1725051195.612 [DataOverHttps](INFO): Sending 77 bytes from file Logs/20240830T195610/Courier0027.lzma 2024-08-30T20:53:16.615Z,1725051196.615 [DataOverHttps](INFO): Moved sent file to Logs/20240830T195610/Courier0027.lzma.bak 2024-08-30T20:53:16.615Z,1725051196.615 [DataOverHttps](INFO): SBD MOMSN=23104302 2024-08-30T20:53:36.396Z,1725051216.396 [DataOverHttps](INFO): Sending 211 bytes from file Logs/20240830T195610/Express0028.lzma 2024-08-30T20:53:37.398Z,1725051217.398 [DataOverHttps](INFO): Moved sent file to Logs/20240830T195610/Express0028.lzma.bak 2024-08-30T20:53:37.398Z,1725051217.398 [DataOverHttps](INFO): SBD MOMSN=23104351 2024-08-30T20:53:39.986Z,1725051219.986 [NAL9602](INFO): Not Powering down - fast GPS 2024-08-30T20:53:40.422Z,1725051220.422 [Default:CheckIn:Read_Iridium] Stopped 2024-08-30T20:53:40.423Z,1725051220.423 [Default:CheckIn:C.Wait] Running Loop=1 2024-08-30T20:53:40.423Z,1725051220.423 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-08-30T20:58:40.994Z,1725051520.994 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-08-30T20:58:40.994Z,1725051520.994 [Default:CheckIn:C.Wait] Stopped 2024-08-30T20:58:40.994Z,1725051520.994 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-08-30T20:58:40.994Z,1725051520.994 [Default:CheckIn:D] Running Loop=1 2024-08-30T20:58:41.399Z,1725051521.399 [Default:CheckIn:D] Stopped 2024-08-30T20:58:41.399Z,1725051521.399 [Default:CheckIn:E] Running Loop=1 2024-08-30T20:58:41.817Z,1725051521.817 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 90.042904 min 2024-08-30T20:58:41.817Z,1725051521.817 [Default:CheckIn:E] Stopped 2024-08-30T20:58:41.817Z,1725051521.817 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-08-30T20:58:41.817Z,1725051521.817 [Default:CheckIn] Stopped 2024-08-30T20:58:41.817Z,1725051521.817 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-08-30T20:58:41.817Z,1725051521.817 [Default:CheckIn](INFO): Running loop #15 2024-08-30T20:58:41.817Z,1725051521.817 [Default:CheckIn] Running Loop=15 2024-08-30T20:58:41.817Z,1725051521.817 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-08-30T20:58:41.817Z,1725051521.817 [Default:CheckIn:Read_GPS] Running Loop=1 2024-08-30T20:58:43.814Z,1725051523.814 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,205843.00,A,3648.16177,N,12147.28514,W,0.272,41.33,300824,,,A*4F 2024-08-30T20:58:43.816Z,1725051523.816 [NAL9602](INFO): GPS fix at 20240830T205843: (36.802696, -121.788086) 2024-08-30T20:58:43.826Z,1725051523.826 [Default:CheckIn:Read_GPS] Stopped 2024-08-30T20:58:43.826Z,1725051523.826 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-08-30T20:58:52.090Z,1725051532.090 [DataOverHttps](INFO): Sending 77 bytes from file Logs/20240830T195610/Courier0030.lzma 2024-08-30T20:58:53.090Z,1725051533.090 [DataOverHttps](INFO): Moved sent file to Logs/20240830T195610/Courier0030.lzma.bak 2024-08-30T20:58:53.090Z,1725051533.090 [DataOverHttps](INFO): SBD MOMSN=23104439 2024-08-30T20:59:10.824Z,1725051550.824 [DataOverHttps](INFO): Sending 135 bytes from file Logs/20240830T195610/Express0031.lzma 2024-08-30T20:59:11.826Z,1725051551.826 [DataOverHttps](INFO): Moved sent file to Logs/20240830T195610/Express0031.lzma.bak 2024-08-30T20:59:11.827Z,1725051551.827 [DataOverHttps](INFO): SBD MOMSN=23104449 2024-08-30T20:59:14.515Z,1725051554.515 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2024-08-30T20:59:14.589Z,1725051554.589 [NAL9602](ERROR): received: +CSQ:0 OK383, 2, 0, 0, 0 OK 2024-08-30T20:59:14.981Z,1725051554.981 [Default:CheckIn:Read_Iridium] Stopped 2024-08-30T20:59:14.982Z,1725051554.982 [Default:CheckIn:C.Wait] Running Loop=1 2024-08-30T20:59:14.982Z,1725051554.982 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-08-30T21:00:32.082Z,1725051632.082 [NAL9602](INFO): SBD MO Status=2, MOMSN=16383, MT Status=2, MTMSN=0 2024-08-30T21:00:32.082Z,1725051632.082 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2024-08-30T21:00:49.050Z,1725051649.050 [NAL9602](INFO): SBD MO Status=2, MOMSN=16383, MT Status=2, MTMSN=0 2024-08-30T21:00:49.050Z,1725051649.050 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2024-08-30T21:01:04.012Z,1725051664.012 [NAL9602](INFO): SBD MO Status=2, MOMSN=16383, MT Status=2, MTMSN=0 2024-08-30T21:01:04.013Z,1725051664.013 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2024-08-30T21:03:37.498Z,1725051817.498 [DataOverHttps](IMPORTANT): SBD MTMSN=20240830T210336 2024-08-30T21:03:44.880Z,1725051824.880 [DataOverHttps](INFO): Received command: strobe off 2024-08-30T21:03:44.918Z,1725051824.918 [CommandExec](IMPORTANT): got command strobe off 2024-08-30T21:03:44.918Z,1725051824.918 [CommandExec](IMPORTANT): Deactivating strobe 2024-08-30T21:03:46.066Z,1725051826.066 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2024-08-30T21:04:15.563Z,1725051855.563 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-08-30T21:04:15.563Z,1725051855.563 [Default:CheckIn:C.Wait] Stopped 2024-08-30T21:04:15.563Z,1725051855.563 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-08-30T21:04:15.563Z,1725051855.563 [Default:CheckIn:D] Running Loop=1 2024-08-30T21:04:16.030Z,1725051856.030 [Default:CheckIn:D] Stopped 2024-08-30T21:04:16.031Z,1725051856.031 [Default:CheckIn:E] Running Loop=1 2024-08-30T21:04:16.370Z,1725051856.370 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 95.620093 min 2024-08-30T21:04:16.370Z,1725051856.370 [Default:CheckIn:E] Stopped 2024-08-30T21:04:16.371Z,1725051856.371 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-08-30T21:04:16.371Z,1725051856.371 [Default:CheckIn] Stopped 2024-08-30T21:04:16.371Z,1725051856.371 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-08-30T21:04:16.371Z,1725051856.371 [Default:CheckIn](INFO): Running loop #16 2024-08-30T21:04:16.371Z,1725051856.371 [Default:CheckIn] Running Loop=16 2024-08-30T21:04:16.371Z,1725051856.371 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-08-30T21:04:16.371Z,1725051856.371 [Default:CheckIn:Read_GPS] Running Loop=1 2024-08-30T21:04:16.765Z,1725051856.765 [NAL9602](INFO): Not Powering down - fast GPS 2024-08-30T21:04:18.388Z,1725051858.388 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,210418.00,A,3648.17391,N,12147.28403,W,0.428,34.89,300824,,,A*4F 2024-08-30T21:04:18.390Z,1725051858.390 [NAL9602](INFO): GPS fix at 20240830T210418: (36.802898, -121.788067) 2024-08-30T21:04:18.399Z,1725051858.399 [Default:CheckIn:Read_GPS] Stopped 2024-08-30T21:04:18.399Z,1725051858.399 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-08-30T21:04:27.012Z,1725051867.012 [DataOverHttps](INFO): Sending 77 bytes from file Logs/20240830T195610/Courier0033.lzma 2024-08-30T21:04:28.014Z,1725051868.014 [DataOverHttps](INFO): Moved sent file to Logs/20240830T195610/Courier0033.lzma.bak 2024-08-30T21:04:28.015Z,1725051868.015 [DataOverHttps](INFO): SBD MOMSN=23104572 2024-08-30T21:04:49.084Z,1725051889.084 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2024-08-30T21:04:49.157Z,1725051889.157 [NAL9602](ERROR): received: +CSQ:0 OK383, 2, 0, 0, 0 OK 2024-08-30T21:04:49.388Z,1725051889.388 [DataOverHttps](INFO): Sending 290 bytes from file Logs/20240830T195610/Express0034.lzma 2024-08-30T21:04:50.390Z,1725051890.390 [DataOverHttps](INFO): Moved sent file to Logs/20240830T195610/Express0034.lzma.bak 2024-08-30T21:04:50.391Z,1725051890.391 [DataOverHttps](INFO): SBD MOMSN=23104575 2024-08-30T21:05:09.656Z,1725051909.656 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20240830T195610/Express0037.lzma 2024-08-30T21:05:10.659Z,1725051910.659 [DataOverHttps](INFO): Moved sent file to Logs/20240830T195610/Express0037.lzma.bak 2024-08-30T21:05:10.659Z,1725051910.659 [DataOverHttps](INFO): SBD MOMSN=23104582 2024-08-30T21:05:13.778Z,1725051913.778 [Default:CheckIn:Read_Iridium] Stopped 2024-08-30T21:05:13.778Z,1725051913.778 [Default:CheckIn:C.Wait] Running Loop=1 2024-08-30T21:05:13.778Z,1725051913.778 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-08-30T21:08:20.796Z,1725052100.796 [NAL9602](INFO): SBD MO Status=2, MOMSN=16383, MT Status=2, MTMSN=0 2024-08-30T21:08:20.796Z,1725052100.796 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2024-08-30T21:09:18.564Z,1725052158.564 [NAL9602](INFO): SBD MO Status=0, MOMSN=16383, MT Status=0, MTMSN=0 2024-08-30T21:09:18.564Z,1725052158.564 [NAL9602](INFO): No messages in MT queue 2024-08-30T21:09:49.274Z,1725052189.274 [NAL9602](INFO): Not Powering down - fast GPS 2024-08-30T21:10:14.325Z,1725052214.325 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-08-30T21:10:14.325Z,1725052214.325 [Default:CheckIn:C.Wait] Stopped 2024-08-30T21:10:14.325Z,1725052214.325 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-08-30T21:10:14.326Z,1725052214.326 [Default:CheckIn:D] Running Loop=1 2024-08-30T21:10:14.735Z,1725052214.735 [Default:CheckIn:D] Stopped 2024-08-30T21:10:14.735Z,1725052214.735 [Default:CheckIn:E] Running Loop=1 2024-08-30T21:10:15.138Z,1725052215.138 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 101.598511 min 2024-08-30T21:10:15.138Z,1725052215.138 [Default:CheckIn:E] Stopped 2024-08-30T21:10:15.138Z,1725052215.138 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-08-30T21:10:15.138Z,1725052215.138 [Default:CheckIn] Stopped 2024-08-30T21:10:15.138Z,1725052215.138 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-08-30T21:10:15.139Z,1725052215.139 [Default:CheckIn](INFO): Running loop #17 2024-08-30T21:10:15.139Z,1725052215.139 [Default:CheckIn] Running Loop=17 2024-08-30T21:10:15.139Z,1725052215.139 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-08-30T21:10:15.139Z,1725052215.139 [Default:CheckIn:Read_GPS] Running Loop=1 2024-08-30T21:10:17.153Z,1725052217.153 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,211017.00,A,3648.17233,N,12147.27644,W,0.389,34.89,300824,,,A*4E 2024-08-30T21:10:17.155Z,1725052217.155 [NAL9602](INFO): GPS fix at 20240830T211017: (36.802872, -121.787941) 2024-08-30T21:10:17.165Z,1725052217.165 [Default:CheckIn:Read_GPS] Stopped 2024-08-30T21:10:17.165Z,1725052217.165 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-08-30T21:10:25.756Z,1725052225.756 [DataOverHttps](INFO): Sending 77 bytes from file Logs/20240830T195610/Courier0039.lzma 2024-08-30T21:10:26.759Z,1725052226.759 [DataOverHttps](INFO): Moved sent file to Logs/20240830T195610/Courier0039.lzma.bak 2024-08-30T21:10:26.759Z,1725052226.759 [DataOverHttps](INFO): SBD MOMSN=23104598 2024-08-30T21:10:49.156Z,1725052249.156 [DataOverHttps](INFO): Sending 134 bytes from file Logs/20240830T195610/Express0040.lzma 2024-08-30T21:10:50.158Z,1725052250.158 [DataOverHttps](INFO): Moved sent file to Logs/20240830T195610/Express0040.lzma.bak 2024-08-30T21:10:50.159Z,1725052250.159 [DataOverHttps](INFO): SBD MOMSN=23104601 2024-08-30T21:10:53.151Z,1725052253.151 [Default:CheckIn:Read_Iridium] Stopped 2024-08-30T21:10:53.151Z,1725052253.151 [Default:CheckIn:C.Wait] Running Loop=1 2024-08-30T21:10:53.151Z,1725052253.151 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-08-30T21:10:57.160Z,1725052257.160 [NAL9602](INFO): SBD MO Status=2, MOMSN=16384, MT Status=2, MTMSN=0 2024-08-30T21:10:57.160Z,1725052257.160 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2024-08-30T21:11:09.282Z,1725052269.282 [DVL_micro](ERROR): Failed to parse:9,+00000,I 2024-08-30T21:15:18.960Z,1725052518.960 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2024-08-30T21:15:49.661Z,1725052549.661 [NAL9602](INFO): Not Powering down - fast GPS 2024-08-30T21:15:53.731Z,1725052553.731 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-08-30T21:15:53.731Z,1725052553.731 [Default:CheckIn:C.Wait] Stopped 2024-08-30T21:15:53.731Z,1725052553.731 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-08-30T21:15:53.732Z,1725052553.732 [Default:CheckIn:D] Running Loop=1 2024-08-30T21:15:54.115Z,1725052554.115 [Default:CheckIn:D] Stopped 2024-08-30T21:15:54.115Z,1725052554.115 [Default:CheckIn:E] Running Loop=1 2024-08-30T21:15:54.551Z,1725052554.551 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 107.254842 min 2024-08-30T21:15:54.552Z,1725052554.552 [Default:CheckIn:E] Stopped 2024-08-30T21:15:54.552Z,1725052554.552 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-08-30T21:15:54.552Z,1725052554.552 [Default:CheckIn] Stopped 2024-08-30T21:15:54.552Z,1725052554.552 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-08-30T21:15:54.552Z,1725052554.552 [Default:CheckIn](INFO): Running loop #18 2024-08-30T21:15:54.552Z,1725052554.552 [Default:CheckIn] Running Loop=18 2024-08-30T21:15:54.552Z,1725052554.552 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-08-30T21:15:54.553Z,1725052554.553 [Default:CheckIn:Read_GPS] Running Loop=1 2024-08-30T21:15:56.533Z,1725052556.533 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,211556.00,A,3648.17202,N,12147.27848,W,0.097,34.89,300824,,,A*42 2024-08-30T21:15:56.535Z,1725052556.535 [NAL9602](INFO): GPS fix at 20240830T211556: (36.802867, -121.787975) 2024-08-30T21:15:56.545Z,1725052556.545 [Default:CheckIn:Read_GPS] Stopped 2024-08-30T21:15:56.545Z,1725052556.545 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-08-30T21:16:05.136Z,1725052565.136 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20240830T195610/Courier0042.lzma 2024-08-30T21:16:06.138Z,1725052566.138 [DataOverHttps](INFO): Moved sent file to Logs/20240830T195610/Courier0042.lzma.bak 2024-08-30T21:16:06.139Z,1725052566.139 [DataOverHttps](INFO): SBD MOMSN=23104629 2024-08-30T21:16:24.492Z,1725052584.492 [DataOverHttps](INFO): Sending 211 bytes from file Logs/20240830T195610/Express0043.lzma 2024-08-30T21:16:25.494Z,1725052585.494 [DataOverHttps](INFO): Moved sent file to Logs/20240830T195610/Express0043.lzma.bak 2024-08-30T21:16:25.495Z,1725052585.495 [DataOverHttps](INFO): SBD MOMSN=23104650 2024-08-30T21:16:27.246Z,1725052587.246 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2024-08-30T21:16:27.321Z,1725052587.321 [NAL9602](ERROR): received: +CSQ:0 OK384, 2, 0, 0, 0 OK 2024-08-30T21:16:28.481Z,1725052588.481 [Default:CheckIn:Read_Iridium] Stopped 2024-08-30T21:16:28.481Z,1725052588.481 [Default:CheckIn:C.Wait] Running Loop=1 2024-08-30T21:16:28.481Z,1725052588.481 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-08-30T21:16:35.020Z,1725052595.020 [BPC1](INFO): Calculating totals. Valid battery stick count: 27. Valid reserve battery stick count: 4. 2024-08-30T21:16:35.034Z,1725052595.034 [BPC1](INFO): Received data from all battery sticks. 2024-08-30T21:18:41.426Z,1725052721.426 [NAL9602](INFO): SBD MO Status=2, MOMSN=16384, MT Status=2, MTMSN=0 2024-08-30T21:18:41.427Z,1725052721.427 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2024-08-30T21:19:28.299Z,1725052768.299 [NAL9602](INFO): SBD MO Status=2, MOMSN=16384, MT Status=2, MTMSN=0 2024-08-30T21:19:28.299Z,1725052768.299 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2024-08-30T21:19:49.698Z,1725052789.698 [NAL9602](INFO): SBD MO Status=2, MOMSN=16384, MT Status=2, MTMSN=0 2024-08-30T21:19:49.698Z,1725052789.698 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2024-08-30T21:20:11.928Z,1725052811.928 [NAL9602](INFO): SBD MO Status=2, MOMSN=16384, MT Status=2, MTMSN=0 2024-08-30T21:20:11.928Z,1725052811.928 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2024-08-30T21:21:07.676Z,1725052867.676 [NAL9602](INFO): SBD MO Status=2, MOMSN=16384, MT Status=2, MTMSN=0 2024-08-30T21:21:07.676Z,1725052867.676 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2024-08-30T21:21:08.079Z,1725052868.079 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2024-08-30T21:21:29.100Z,1725052889.100 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-08-30T21:21:29.100Z,1725052889.100 [Default:CheckIn:C.Wait] Stopped 2024-08-30T21:21:29.112Z,1725052889.112 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-08-30T21:21:29.114Z,1725052889.114 [Default:CheckIn:D] Running Loop=1 2024-08-30T21:21:29.503Z,1725052889.503 [Default:CheckIn:D] Stopped 2024-08-30T21:21:29.503Z,1725052889.503 [Default:CheckIn:E] Running Loop=1 2024-08-30T21:21:29.904Z,1725052889.904 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 112.844637 min 2024-08-30T21:21:29.904Z,1725052889.904 [Default:CheckIn:E] Stopped 2024-08-30T21:21:29.905Z,1725052889.905 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-08-30T21:21:29.905Z,1725052889.905 [Default:CheckIn] Stopped 2024-08-30T21:21:29.905Z,1725052889.905 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-08-30T21:21:29.905Z,1725052889.905 [Default:CheckIn](INFO): Running loop #19 2024-08-30T21:21:29.905Z,1725052889.905 [Default:CheckIn] Running Loop=19 2024-08-30T21:21:29.905Z,1725052889.905 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-08-30T21:21:29.905Z,1725052889.905 [Default:CheckIn:Read_GPS] Running Loop=1 2024-08-30T21:21:31.953Z,1725052891.953 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,212131.00,A,3648.17104,N,12147.28139,W,0.525,189.35,300824,,,A*7D 2024-08-30T21:21:31.956Z,1725052891.956 [NAL9602](INFO): GPS fix at 20240830T212131: (36.802851, -121.788023) 2024-08-30T21:21:31.973Z,1725052891.973 [Default:CheckIn:Read_GPS] Stopped 2024-08-30T21:21:31.973Z,1725052891.973 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-08-30T21:21:40.900Z,1725052900.900 [DataOverHttps](INFO): Sending 90 bytes from file Logs/20240830T195610/Courier0045.lzma 2024-08-30T21:21:41.902Z,1725052901.902 [DataOverHttps](INFO): Moved sent file to Logs/20240830T195610/Courier0045.lzma.bak 2024-08-30T21:21:41.903Z,1725052901.903 [DataOverHttps](INFO): SBD MOMSN=23104855 2024-08-30T21:21:59.637Z,1725052919.637 [DataOverHttps](INFO): Sending 212 bytes from file Logs/20240830T195610/Express0046.lzma 2024-08-30T21:22:00.640Z,1725052920.640 [DataOverHttps](INFO): Moved sent file to Logs/20240830T195610/Express0046.lzma.bak 2024-08-30T21:22:00.640Z,1725052920.640 [DataOverHttps](INFO): SBD MOMSN=23104862 2024-08-30T21:22:03.673Z,1725052923.673 [Default:CheckIn:Read_Iridium] Stopped 2024-08-30T21:22:03.673Z,1725052923.673 [Default:CheckIn:C.Wait] Running Loop=1 2024-08-30T21:22:03.673Z,1725052923.673 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-08-30T21:22:04.022Z,1725052924.022 [NAL9602](INFO): Not Powering down - fast GPS 2024-08-30T21:27:04.215Z,1725053224.215 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-08-30T21:27:04.215Z,1725053224.215 [Default:CheckIn:C.Wait] Stopped 2024-08-30T21:27:04.215Z,1725053224.215 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-08-30T21:27:04.216Z,1725053224.216 [Default:CheckIn:D] Running Loop=1 2024-08-30T21:27:04.627Z,1725053224.627 [Default:CheckIn:D] Stopped 2024-08-30T21:27:04.627Z,1725053224.627 [Default:CheckIn:E] Running Loop=1 2024-08-30T21:27:05.023Z,1725053225.023 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 118.430037 min 2024-08-30T21:27:05.023Z,1725053225.023 [Default:CheckIn:E] Stopped 2024-08-30T21:27:05.023Z,1725053225.023 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-08-30T21:27:05.023Z,1725053225.023 [Default:CheckIn] Stopped 2024-08-30T21:27:05.024Z,1725053225.024 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-08-30T21:27:05.024Z,1725053225.024 [Default:CheckIn](INFO): Running loop #20 2024-08-30T21:27:05.024Z,1725053225.024 [Default:CheckIn] Running Loop=20 2024-08-30T21:27:05.024Z,1725053225.024 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-08-30T21:27:05.024Z,1725053225.024 [Default:CheckIn:Read_GPS] Running Loop=1 2024-08-30T21:27:07.035Z,1725053227.035 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,212706.00,A,3648.15769,N,12147.28312,W,0.641,226.17,300824,,,A*7C 2024-08-30T21:27:07.038Z,1725053227.038 [NAL9602](INFO): GPS fix at 20240830T212706: (36.802628, -121.788052) 2024-08-30T21:27:07.047Z,1725053227.047 [Default:CheckIn:Read_GPS] Stopped 2024-08-30T21:27:07.047Z,1725053227.047 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-08-30T21:27:15.348Z,1725053235.348 [DataOverHttps](INFO): Sending 77 bytes from file Logs/20240830T195610/Courier0048.lzma 2024-08-30T21:27:16.351Z,1725053236.351 [DataOverHttps](INFO): Moved sent file to Logs/20240830T195610/Courier0048.lzma.bak 2024-08-30T21:27:16.351Z,1725053236.351 [DataOverHttps](INFO): SBD MOMSN=23104934 2024-08-30T21:27:36.288Z,1725053256.288 [DataOverHttps](INFO): Sending 143 bytes from file Logs/20240830T195610/Express0049.lzma 2024-08-30T21:27:38.464Z,1725053258.464 [DataOverHttps](INFO): Moved sent file to Logs/20240830T195610/Express0049.lzma.bak 2024-08-30T21:27:38.467Z,1725053258.467 [DataOverHttps](INFO): SBD MOMSN=23104937 2024-08-30T21:27:40.620Z,1725053260.620 [Default:CheckIn:Read_Iridium] Stopped 2024-08-30T21:27:40.620Z,1725053260.620 [Default:CheckIn:C.Wait] Running Loop=1 2024-08-30T21:27:40.620Z,1725053260.620 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-08-30T21:32:08.857Z,1725053528.857 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2024-08-30T21:32:39.556Z,1725053559.556 [NAL9602](INFO): Not Powering down - fast GPS 2024-08-30T21:32:41.198Z,1725053561.198 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-08-30T21:32:41.198Z,1725053561.198 [Default:CheckIn:C.Wait] Stopped 2024-08-30T21:32:41.198Z,1725053561.198 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-08-30T21:32:41.198Z,1725053561.198 [Default:CheckIn:D] Running Loop=1 2024-08-30T21:32:41.591Z,1725053561.591 [Default:CheckIn:D] Stopped 2024-08-30T21:32:41.591Z,1725053561.591 [Default:CheckIn:E] Running Loop=1 2024-08-30T21:32:41.988Z,1725053561.988 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 124.046110 min 2024-08-30T21:32:41.988Z,1725053561.988 [Default:CheckIn:E] Stopped 2024-08-30T21:32:41.988Z,1725053561.988 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-08-30T21:32:41.988Z,1725053561.988 [Default:CheckIn] Stopped 2024-08-30T21:32:41.988Z,1725053561.988 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-08-30T21:32:41.989Z,1725053561.989 [Default:CheckIn](INFO): Running loop #21 2024-08-30T21:32:41.989Z,1725053561.989 [Default:CheckIn] Running Loop=21 2024-08-30T21:32:41.989Z,1725053561.989 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-08-30T21:32:41.989Z,1725053561.989 [Default:CheckIn:Read_GPS] Running Loop=1 2024-08-30T21:32:44.013Z,1725053564.013 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,213243.00,A,3648.17319,N,12147.25092,W,0.447,226.17,300824,,,A*7A 2024-08-30T21:32:44.015Z,1725053564.015 [NAL9602](INFO): GPS fix at 20240830T213243: (36.802886, -121.787515) 2024-08-30T21:32:44.025Z,1725053564.025 [Default:CheckIn:Read_GPS] Stopped 2024-08-30T21:32:44.025Z,1725053564.025 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-08-30T21:32:52.660Z,1725053572.660 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20240830T195610/Courier0051.lzma 2024-08-30T21:32:53.662Z,1725053573.662 [DataOverHttps](INFO): Moved sent file to Logs/20240830T195610/Courier0051.lzma.bak 2024-08-30T21:32:53.663Z,1725053573.663 [DataOverHttps](INFO): SBD MOMSN=23105069 2024-08-30T21:33:13.563Z,1725053593.563 [DataOverHttps](INFO): Sending 226 bytes from file Logs/20240830T195610/Express0052.lzma 2024-08-30T21:33:14.570Z,1725053594.570 [DataOverHttps](INFO): Moved sent file to Logs/20240830T195610/Express0052.lzma.bak 2024-08-30T21:33:14.571Z,1725053594.571 [DataOverHttps](INFO): SBD MOMSN=23105072 2024-08-30T21:33:14.711Z,1725053594.711 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2024-08-30T21:33:14.789Z,1725053594.789 [NAL9602](ERROR): received: +CSQ:0 OK384, 2, 0, 0, 0 OK 2024-08-30T21:33:17.567Z,1725053597.567 [Default:CheckIn:Read_Iridium] Stopped 2024-08-30T21:33:17.568Z,1725053597.568 [Default:CheckIn:C.Wait] Running Loop=1 2024-08-30T21:33:17.568Z,1725053597.568 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-08-30T21:37:04.630Z,1725053824.630 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2024-08-30T21:37:04.630Z,1725053824.630 [DropWeight] Hardware Fault, FailCount= 1 2024-08-30T21:37:04.630Z,1725053824.630 [DropWeight](ERROR): Hardware Fault 2024-08-30T21:37:04.687Z,1725053824.687 [CommandExec](FAULT): Scheduling is paused 2024-08-30T21:37:04.689Z,1725053824.689 [CBIT](INFO): Critical error at 20240830T213704 2024-08-30T21:37:04.691Z,1725053824.691 [CBIT](ERROR): Hardware Fault in component: DropWeight 2024-08-30T21:37:04.692Z,1725053824.692 [CBIT](CRITICAL): Hardware Fault in component: DropWeight 2024-08-30T21:37:05.075Z,1725053825.075 [CBIT](INFO): Critical error at 20240830T213704 2024-08-30T21:37:45.864Z,1725053865.864 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2024-08-30T21:38:16.547Z,1725053896.547 [NAL9602](INFO): Not Powering down - fast GPS 2024-08-30T21:38:18.174Z,1725053898.174 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-08-30T21:38:18.174Z,1725053898.174 [Default:CheckIn:C.Wait] Stopped 2024-08-30T21:38:18.174Z,1725053898.174 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-08-30T21:38:18.175Z,1725053898.175 [Default:CheckIn:D] Running Loop=1 2024-08-30T21:38:18.583Z,1725053898.583 [Default:CheckIn:D] Stopped 2024-08-30T21:38:18.583Z,1725053898.583 [Default:CheckIn:E] Running Loop=1 2024-08-30T21:38:18.972Z,1725053898.972 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 129.662638 min 2024-08-30T21:38:18.972Z,1725053898.972 [Default:CheckIn:E] Stopped 2024-08-30T21:38:18.972Z,1725053898.972 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-08-30T21:38:18.972Z,1725053898.972 [Default:CheckIn] Stopped 2024-08-30T21:38:18.972Z,1725053898.972 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-08-30T21:38:18.972Z,1725053898.972 [Default:CheckIn](INFO): Running loop #22 2024-08-30T21:38:18.972Z,1725053898.972 [Default:CheckIn] Running Loop=22 2024-08-30T21:38:18.973Z,1725053898.973 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-08-30T21:38:18.973Z,1725053898.973 [Default:CheckIn:Read_GPS] Running Loop=1 2024-08-30T21:38:20.986Z,1725053900.986 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,213820.00,A,3648.16464,N,12147.28588,W,0.972,0.00,300824,,,A*71 2024-08-30T21:38:20.989Z,1725053900.989 [NAL9602](INFO): GPS fix at 20240830T213820: (36.802744, -121.788098) 2024-08-30T21:38:20.998Z,1725053900.998 [Default:CheckIn:Read_GPS] Stopped 2024-08-30T21:38:20.998Z,1725053900.998 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-08-30T21:38:28.992Z,1725053908.992 [DataOverHttps](INFO): Sending 184 bytes from file Logs/20240830T195610/Courier0054.lzma 2024-08-30T21:38:29.994Z,1725053909.994 [DataOverHttps](INFO): Moved sent file to Logs/20240830T195610/Courier0054.lzma.bak 2024-08-30T21:38:29.995Z,1725053909.995 [DataOverHttps](INFO): SBD MOMSN=23105130 2024-08-30T21:38:50.836Z,1725053930.836 [DataOverHttps](INFO): Sending 242 bytes from file Logs/20240830T195610/Express0055.lzma 2024-08-30T21:38:51.762Z,1725053931.762 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2024-08-30T21:38:51.841Z,1725053931.841 [NAL9602](ERROR): received: +CSQ:0 OK384, 2, 0, 0, 0 OK 2024-08-30T21:38:53.663Z,1725053933.663 [DataOverHttps](INFO): Moved sent file to Logs/20240830T195610/Express0055.lzma.bak 2024-08-30T21:38:53.663Z,1725053933.663 [DataOverHttps](INFO): SBD MOMSN=23105135 2024-08-30T21:38:55.772Z,1725053935.772 [Default:CheckIn:Read_Iridium] Stopped 2024-08-30T21:38:55.772Z,1725053935.772 [Default:CheckIn:C.Wait] Running Loop=1 2024-08-30T21:38:55.772Z,1725053935.772 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-08-30T21:43:22.798Z,1725054202.798 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2024-08-30T21:43:53.496Z,1725054233.496 [NAL9602](INFO): Not Powering down - fast GPS 2024-08-30T21:43:56.341Z,1725054236.341 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-08-30T21:43:56.341Z,1725054236.341 [Default:CheckIn:C.Wait] Stopped 2024-08-30T21:43:56.341Z,1725054236.341 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-08-30T21:43:56.342Z,1725054236.342 [Default:CheckIn:D] Running Loop=1 2024-08-30T21:43:56.753Z,1725054236.753 [Default:CheckIn:D] Stopped 2024-08-30T21:43:56.753Z,1725054236.753 [Default:CheckIn:E] Running Loop=1 2024-08-30T21:43:57.141Z,1725054237.141 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 135.298804 min 2024-08-30T21:43:57.141Z,1725054237.141 [Default:CheckIn:E] Stopped 2024-08-30T21:43:57.142Z,1725054237.142 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-08-30T21:43:57.142Z,1725054237.142 [Default:CheckIn] Stopped 2024-08-30T21:43:57.142Z,1725054237.142 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-08-30T21:43:57.142Z,1725054237.142 [Default:CheckIn](INFO): Running loop #23 2024-08-30T21:43:57.142Z,1725054237.142 [Default:CheckIn] Running Loop=23 2024-08-30T21:43:57.142Z,1725054237.142 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-08-30T21:43:57.142Z,1725054237.142 [Default:CheckIn:Read_GPS] Running Loop=1 2024-08-30T21:43:59.165Z,1725054239.165 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,214358.00,A,3648.16060,N,12147.29351,W,0.292,0.00,300824,,,A*74 2024-08-30T21:43:59.169Z,1725054239.169 [NAL9602](INFO): GPS fix at 20240830T214358: (36.802677, -121.788225) 2024-08-30T21:43:59.201Z,1725054239.201 [Default:CheckIn:Read_GPS] Stopped 2024-08-30T21:43:59.201Z,1725054239.201 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-08-30T21:44:06.536Z,1725054246.536 [DataOverHttps](INFO): Sending 78 bytes from file Logs/20240830T195610/Courier0057.lzma 2024-08-30T21:44:07.538Z,1725054247.538 [DataOverHttps](INFO): Moved sent file to Logs/20240830T195610/Courier0057.lzma.bak 2024-08-30T21:44:07.539Z,1725054247.539 [DataOverHttps](INFO): SBD MOMSN=23105255 2024-08-30T21:44:25.300Z,1725054265.300 [DataOverHttps](INFO): Sending 211 bytes from file Logs/20240830T195610/Express0058.lzma 2024-08-30T21:44:26.303Z,1725054266.303 [DataOverHttps](INFO): Moved sent file to Logs/20240830T195610/Express0058.lzma.bak 2024-08-30T21:44:26.303Z,1725054266.303 [DataOverHttps](INFO): SBD MOMSN=23105258 2024-08-30T21:44:29.494Z,1725054269.494 [Default:CheckIn:Read_Iridium] Stopped 2024-08-30T21:44:29.495Z,1725054269.495 [Default:CheckIn:C.Wait] Running Loop=1 2024-08-30T21:44:29.496Z,1725054269.496 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-08-30T21:44:29.858Z,1725054269.858 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2024-08-30T21:44:29.941Z,1725054269.941 [NAL9602](ERROR): received: +CSQ:0 OK384, 2, 0, 0, 0 OK 2024-08-30T21:49:01.807Z,1725054541.807 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2024-08-30T21:49:30.066Z,1725054570.066 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-08-30T21:49:30.066Z,1725054570.066 [Default:CheckIn:C.Wait] Stopped 2024-08-30T21:49:30.066Z,1725054570.066 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-08-30T21:49:30.066Z,1725054570.066 [Default:CheckIn:D] Running Loop=1 2024-08-30T21:49:30.483Z,1725054570.483 [Default:CheckIn:D] Stopped 2024-08-30T21:49:30.483Z,1725054570.483 [Default:CheckIn:E] Running Loop=1 2024-08-30T21:49:30.889Z,1725054570.889 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 140.860970 min 2024-08-30T21:49:30.889Z,1725054570.889 [Default:CheckIn:E] Stopped 2024-08-30T21:49:30.889Z,1725054570.889 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-08-30T21:49:30.889Z,1725054570.889 [Default:CheckIn] Stopped 2024-08-30T21:49:30.889Z,1725054570.889 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-08-30T21:49:30.889Z,1725054570.889 [Default:CheckIn](INFO): Running loop #24 2024-08-30T21:49:30.889Z,1725054570.889 [Default:CheckIn] Running Loop=24 2024-08-30T21:49:30.890Z,1725054570.890 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-08-30T21:49:30.890Z,1725054570.890 [Default:CheckIn:Read_GPS] Running Loop=1 2024-08-30T21:49:32.904Z,1725054572.904 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,214932.00,A,3648.16412,N,12147.26871,W,0.156,0.00,300824,,,A*7E 2024-08-30T21:49:32.910Z,1725054572.910 [NAL9602](INFO): GPS fix at 20240830T214932: (36.802735, -121.787812) 2024-08-30T21:49:32.949Z,1725054572.949 [Default:CheckIn:Read_GPS] Stopped 2024-08-30T21:49:32.949Z,1725054572.949 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-08-30T21:49:41.864Z,1725054581.864 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20240830T195610/Courier0060.lzma 2024-08-30T21:49:42.867Z,1725054582.867 [DataOverHttps](INFO): Moved sent file to Logs/20240830T195610/Courier0060.lzma.bak 2024-08-30T21:49:42.867Z,1725054582.867 [DataOverHttps](INFO): SBD MOMSN=23105272 2024-08-30T21:50:00.401Z,1725054600.401 [DataOverHttps](INFO): Sending 222 bytes from file Logs/20240830T195610/Express0061.lzma 2024-08-30T21:50:01.402Z,1725054601.402 [DataOverHttps](INFO): Moved sent file to Logs/20240830T195610/Express0061.lzma.bak 2024-08-30T21:50:01.403Z,1725054601.403 [DataOverHttps](INFO): SBD MOMSN=23105275 2024-08-30T21:50:04.429Z,1725054604.429 [Default:CheckIn:Read_Iridium] Stopped 2024-08-30T21:50:04.429Z,1725054604.429 [Default:CheckIn:C.Wait] Running Loop=1 2024-08-30T21:50:04.429Z,1725054604.429 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-08-30T21:50:05.218Z,1725054605.218 [NAL9602](INFO): Not Powering down - fast GPS 2024-08-30T21:52:04.813Z,1725054724.813 [CBIT](INFO): Clearing failed state for component DropWeight 2024-08-30T21:52:04.813Z,1725054724.813 [DropWeight] No Fault, FailCount= 1 2024-08-30T21:55:04.987Z,1725054904.987 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-08-30T21:55:04.987Z,1725054904.987 [Default:CheckIn:C.Wait] Stopped 2024-08-30T21:55:04.987Z,1725054904.987 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-08-30T21:55:04.988Z,1725054904.988 [Default:CheckIn:D] Running Loop=1 2024-08-30T21:55:05.386Z,1725054905.386 [Default:CheckIn:D] Stopped 2024-08-30T21:55:05.386Z,1725054905.386 [Default:CheckIn:E] Running Loop=1 2024-08-30T21:55:05.790Z,1725054905.790 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 146.442676 min 2024-08-30T21:55:05.790Z,1725054905.790 [Default:CheckIn:E] Stopped 2024-08-30T21:55:05.790Z,1725054905.790 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-08-30T21:55:05.790Z,1725054905.790 [Default:CheckIn] Stopped 2024-08-30T21:55:05.790Z,1725054905.790 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-08-30T21:55:05.791Z,1725054905.791 [Default:CheckIn](INFO): Running loop #25 2024-08-30T21:55:05.791Z,1725054905.791 [Default:CheckIn] Running Loop=25 2024-08-30T21:55:05.791Z,1725054905.791 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-08-30T21:55:05.791Z,1725054905.791 [Default:CheckIn:Read_GPS] Running Loop=1 2024-08-30T21:55:07.813Z,1725054907.813 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,215507.00,A,3648.17695,N,12147.28940,W,0.136,0.00,300824,,,A*72 2024-08-30T21:55:07.816Z,1725054907.816 [NAL9602](INFO): GPS fix at 20240830T215507: (36.802949, -121.788157) 2024-08-30T21:55:07.825Z,1725054907.825 [Default:CheckIn:Read_GPS] Stopped 2024-08-30T21:55:07.825Z,1725054907.825 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-08-30T21:55:17.872Z,1725054917.872 [DataOverHttps](INFO): Sending 77 bytes from file Logs/20240830T195610/Courier0063.lzma 2024-08-30T21:55:18.875Z,1725054918.875 [DataOverHttps](INFO): Moved sent file to Logs/20240830T195610/Courier0063.lzma.bak 2024-08-30T21:55:18.875Z,1725054918.875 [DataOverHttps](INFO): SBD MOMSN=23105404 2024-08-30T21:55:38.488Z,1725054938.488 [DataOverHttps](INFO): Sending 148 bytes from file Logs/20240830T195610/Express0064.lzma 2024-08-30T21:55:38.523Z,1725054938.523 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2024-08-30T21:55:38.605Z,1725054938.605 [NAL9602](ERROR): received: +CSQ:0 OK384, 2, 0, 0, 0 OK 2024-08-30T21:55:39.491Z,1725054939.491 [DataOverHttps](INFO): Moved sent file to Logs/20240830T195610/Express0064.lzma.bak 2024-08-30T21:55:39.491Z,1725054939.491 [DataOverHttps](INFO): SBD MOMSN=23105407 2024-08-30T21:55:42.574Z,1725054942.574 [Default:CheckIn:Read_Iridium] Stopped 2024-08-30T21:55:42.575Z,1725054942.575 [Default:CheckIn:C.Wait] Running Loop=1 2024-08-30T21:55:42.575Z,1725054942.575 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-08-30T22:00:10.001Z,1725055210.001 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2024-08-30T22:00:40.743Z,1725055240.743 [NAL9602](INFO): Not Powering down - fast GPS 2024-08-30T22:00:43.163Z,1725055243.163 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-08-30T22:00:43.163Z,1725055243.163 [Default:CheckIn:C.Wait] Stopped 2024-08-30T22:00:43.163Z,1725055243.163 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-08-30T22:00:43.164Z,1725055243.164 [Default:CheckIn:D] Running Loop=1 2024-08-30T22:00:43.564Z,1725055243.564 [Default:CheckIn:D] Stopped 2024-08-30T22:00:43.564Z,1725055243.564 [Default:CheckIn:E] Running Loop=1 2024-08-30T22:00:43.976Z,1725055243.976 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 152.078988 min 2024-08-30T22:00:43.976Z,1725055243.976 [Default:CheckIn:E] Stopped 2024-08-30T22:00:43.976Z,1725055243.976 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-08-30T22:00:43.976Z,1725055243.976 [Default:CheckIn] Stopped 2024-08-30T22:00:43.976Z,1725055243.976 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-08-30T22:00:43.976Z,1725055243.976 [Default:CheckIn](INFO): Running loop #26 2024-08-30T22:00:43.977Z,1725055243.977 [Default:CheckIn] Running Loop=26 2024-08-30T22:00:43.977Z,1725055243.977 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-08-30T22:00:43.977Z,1725055243.977 [Default:CheckIn:Read_GPS] Running Loop=1 2024-08-30T22:00:45.979Z,1725055245.979 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,220045.00,A,3648.13214,N,12147.27857,W,1.108,0.00,300824,,,A*7A 2024-08-30T22:00:45.982Z,1725055245.982 [NAL9602](INFO): GPS fix at 20240830T220045: (36.802202, -121.787976) 2024-08-30T22:00:45.991Z,1725055245.991 [Default:CheckIn:Read_GPS] Stopped 2024-08-30T22:00:45.991Z,1725055245.991 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-08-30T22:00:53.764Z,1725055253.764 [DataOverHttps](INFO): Sending 77 bytes from file Logs/20240830T195610/Courier0066.lzma 2024-08-30T22:00:54.767Z,1725055254.767 [DataOverHttps](INFO): Moved sent file to Logs/20240830T195610/Courier0066.lzma.bak 2024-08-30T22:00:54.767Z,1725055254.767 [DataOverHttps](INFO): SBD MOMSN=23105421 2024-08-30T22:01:12.604Z,1725055272.604 [DataOverHttps](INFO): Sending 219 bytes from file Logs/20240830T195610/Express0067.lzma 2024-08-30T22:01:13.607Z,1725055273.607 [DataOverHttps](INFO): Moved sent file to Logs/20240830T195610/Express0067.lzma.bak 2024-08-30T22:01:13.607Z,1725055273.607 [DataOverHttps](INFO): SBD MOMSN=23105424 2024-08-30T22:01:16.674Z,1725055276.674 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2024-08-30T22:01:16.749Z,1725055276.749 [NAL9602](ERROR): received: +CSQ:0 OK384, 2, 0, 0, 0 OK 2024-08-30T22:01:16.780Z,1725055276.780 [Default:CheckIn:Read_Iridium] Stopped 2024-08-30T22:01:16.780Z,1725055276.780 [Default:CheckIn:C.Wait] Running Loop=1 2024-08-30T22:01:16.780Z,1725055276.780 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-08-30T22:05:47.793Z,1725055547.793 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2024-08-30T22:06:17.308Z,1725055577.308 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-08-30T22:06:17.308Z,1725055577.308 [Default:CheckIn:C.Wait] Stopped 2024-08-30T22:06:17.308Z,1725055577.308 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-08-30T22:06:17.308Z,1725055577.308 [Default:CheckIn:D] Running Loop=1 2024-08-30T22:06:17.693Z,1725055577.693 [Default:CheckIn:D] Stopped 2024-08-30T22:06:17.693Z,1725055577.693 [Default:CheckIn:E] Running Loop=1 2024-08-30T22:06:18.099Z,1725055578.099 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 157.647803 min 2024-08-30T22:06:18.099Z,1725055578.099 [Default:CheckIn:E] Stopped 2024-08-30T22:06:18.099Z,1725055578.099 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-08-30T22:06:18.100Z,1725055578.100 [Default:CheckIn] Stopped 2024-08-30T22:06:18.100Z,1725055578.100 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-08-30T22:06:18.100Z,1725055578.100 [Default:CheckIn](INFO): Running loop #27 2024-08-30T22:06:18.100Z,1725055578.100 [Default:CheckIn] Running Loop=27 2024-08-30T22:06:18.100Z,1725055578.100 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-08-30T22:06:18.100Z,1725055578.100 [Default:CheckIn:Read_GPS] Running Loop=1 2024-08-30T22:06:18.499Z,1725055578.499 [NAL9602](INFO): Not Powering down - fast GPS 2024-08-30T22:06:20.120Z,1725055580.120 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,220619.00,A,3648.16757,N,12147.28070,W,0.330,0.00,300824,,,A*78 2024-08-30T22:06:20.123Z,1725055580.123 [NAL9602](INFO): GPS fix at 20240830T220619: (36.802793, -121.788012) 2024-08-30T22:06:20.132Z,1725055580.132 [Default:CheckIn:Read_GPS] Stopped 2024-08-30T22:06:20.132Z,1725055580.132 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-08-30T22:06:28.304Z,1725055588.304 [DataOverHttps](INFO): Sending 78 bytes from file Logs/20240830T195610/Courier0069.lzma 2024-08-30T22:06:29.307Z,1725055589.307 [DataOverHttps](INFO): Moved sent file to Logs/20240830T195610/Courier0069.lzma.bak 2024-08-30T22:06:29.307Z,1725055589.307 [DataOverHttps](INFO): SBD MOMSN=23105486 2024-08-30T22:06:50.137Z,1725055610.137 [DataOverHttps](INFO): Sending 223 bytes from file Logs/20240830T195610/Express0070.lzma 2024-08-30T22:06:51.139Z,1725055611.139 [DataOverHttps](INFO): Moved sent file to Logs/20240830T195610/Express0070.lzma.bak 2024-08-30T22:06:51.139Z,1725055611.139 [DataOverHttps](INFO): SBD MOMSN=23105493 2024-08-30T22:06:55.365Z,1725055615.365 [Default:CheckIn:Read_Iridium] Stopped 2024-08-30T22:06:55.366Z,1725055615.366 [Default:CheckIn:C.Wait] Running Loop=1 2024-08-30T22:06:55.366Z,1725055615.366 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-08-30T22:11:21.982Z,1725055881.982 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2024-08-30T22:11:52.697Z,1725055912.697 [NAL9602](INFO): Not Powering down - fast GPS 2024-08-30T22:11:55.934Z,1725055915.934 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-08-30T22:11:55.935Z,1725055915.935 [Default:CheckIn:C.Wait] Stopped 2024-08-30T22:11:55.935Z,1725055915.935 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-08-30T22:11:55.935Z,1725055915.935 [Default:CheckIn:D] Running Loop=1 2024-08-30T22:11:56.330Z,1725055916.330 [Default:CheckIn:D] Stopped 2024-08-30T22:11:56.330Z,1725055916.330 [Default:CheckIn:E] Running Loop=1 2024-08-30T22:11:56.734Z,1725055916.734 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 163.291748 min 2024-08-30T22:11:56.734Z,1725055916.734 [Default:CheckIn:E] Stopped 2024-08-30T22:11:56.734Z,1725055916.734 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-08-30T22:11:56.735Z,1725055916.735 [Default:CheckIn] Stopped 2024-08-30T22:11:56.735Z,1725055916.735 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-08-30T22:11:56.735Z,1725055916.735 [Default:CheckIn](INFO): Running loop #28 2024-08-30T22:11:56.735Z,1725055916.735 [Default:CheckIn] Running Loop=28 2024-08-30T22:11:56.735Z,1725055916.735 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-08-30T22:11:56.735Z,1725055916.735 [Default:CheckIn:Read_GPS] Running Loop=1 2024-08-30T22:11:58.749Z,1725055918.749 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,221158.00,A,3648.17299,N,12147.27296,W,0.330,147.57,300824,,,A*78 2024-08-30T22:11:58.751Z,1725055918.751 [NAL9602](INFO): GPS fix at 20240830T221158: (36.802883, -121.787883) 2024-08-30T22:11:58.761Z,1725055918.761 [Default:CheckIn:Read_GPS] Stopped 2024-08-30T22:11:58.761Z,1725055918.761 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-08-30T22:12:06.924Z,1725055926.924 [DataOverHttps](INFO): Sending 77 bytes from file Logs/20240830T195610/Courier0072.lzma 2024-08-30T22:12:07.927Z,1725055927.927 [DataOverHttps](INFO): Moved sent file to Logs/20240830T195610/Courier0072.lzma.bak 2024-08-30T22:12:07.927Z,1725055927.927 [DataOverHttps](INFO): SBD MOMSN=23105504 2024-08-30T22:12:25.724Z,1725055945.724 [DataOverHttps](INFO): Sending 211 bytes from file Logs/20240830T195610/Express0073.lzma 2024-08-30T22:12:28.378Z,1725055948.378 [DataOverHttps](INFO): Moved sent file to Logs/20240830T195610/Express0073.lzma.bak 2024-08-30T22:12:28.378Z,1725055948.378 [DataOverHttps](INFO): SBD MOMSN=23105507 2024-08-30T22:12:29.503Z,1725055949.503 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2024-08-30T22:12:29.577Z,1725055949.577 [NAL9602](ERROR): received: +CSQ:0 OK384, 2, 0, 0, 0 OK 2024-08-30T22:12:30.712Z,1725055950.712 [Default:CheckIn:Read_Iridium] Stopped 2024-08-30T22:12:30.713Z,1725055950.713 [Default:CheckIn:C.Wait] Running Loop=1 2024-08-30T22:12:30.713Z,1725055950.713 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-08-30T22:17:00.978Z,1725056220.978 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2024-08-30T22:17:31.302Z,1725056251.302 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-08-30T22:17:31.302Z,1725056251.302 [Default:CheckIn:C.Wait] Stopped 2024-08-30T22:17:31.302Z,1725056251.302 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-08-30T22:17:31.302Z,1725056251.302 [Default:CheckIn:D] Running Loop=1 2024-08-30T22:17:31.710Z,1725056251.710 [NAL9602](INFO): Not Powering down - fast GPS 2024-08-30T22:17:31.734Z,1725056251.734 [Default:CheckIn:D] Stopped 2024-08-30T22:17:31.734Z,1725056251.734 [Default:CheckIn:E] Running Loop=1 2024-08-30T22:17:32.102Z,1725056252.102 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 168.881820 min 2024-08-30T22:17:32.102Z,1725056252.102 [Default:CheckIn:E] Stopped 2024-08-30T22:17:32.102Z,1725056252.102 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-08-30T22:17:32.103Z,1725056252.103 [Default:CheckIn] Stopped 2024-08-30T22:17:32.103Z,1725056252.103 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-08-30T22:17:32.103Z,1725056252.103 [Default:CheckIn](INFO): Running loop #29 2024-08-30T22:17:32.103Z,1725056252.103 [Default:CheckIn] Running Loop=29 2024-08-30T22:17:32.103Z,1725056252.103 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-08-30T22:17:32.103Z,1725056252.103 [Default:CheckIn:Read_GPS] Running Loop=1 2024-08-30T22:17:34.108Z,1725056254.108 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,221733.00,A,3648.16789,N,12147.27127,W,0.875,279.03,300824,,,A*7A 2024-08-30T22:17:34.111Z,1725056254.111 [NAL9602](INFO): GPS fix at 20240830T221733: (36.802798, -121.787854) 2024-08-30T22:17:34.146Z,1725056254.146 [Default:CheckIn:Read_GPS] Stopped 2024-08-30T22:17:34.146Z,1725056254.146 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-08-30T22:17:42.508Z,1725056262.508 [DataOverHttps](INFO): Sending 77 bytes from file Logs/20240830T195610/Courier0075.lzma 2024-08-30T22:17:43.510Z,1725056263.510 [DataOverHttps](INFO): Moved sent file to Logs/20240830T195610/Courier0075.lzma.bak 2024-08-30T22:17:43.511Z,1725056263.511 [DataOverHttps](INFO): SBD MOMSN=23105579 2024-08-30T22:18:01.177Z,1725056281.177 [DataOverHttps](INFO): Sending 211 bytes from file Logs/20240830T195610/Express0076.lzma 2024-08-30T22:18:02.179Z,1725056282.179 [DataOverHttps](INFO): Moved sent file to Logs/20240830T195610/Express0076.lzma.bak 2024-08-30T22:18:02.179Z,1725056282.179 [DataOverHttps](INFO): SBD MOMSN=23105582 2024-08-30T22:18:04.828Z,1725056284.828 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2024-08-30T22:18:04.901Z,1725056284.901 [NAL9602](ERROR): received: +CSQ:0 OK384, 2, 0, 0, 0 OK 2024-08-30T22:18:05.269Z,1725056285.269 [Default:CheckIn:Read_Iridium] Stopped 2024-08-30T22:18:05.269Z,1725056285.269 [Default:CheckIn:C.Wait] Running Loop=1 2024-08-30T22:18:05.270Z,1725056285.270 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-08-30T22:19:02.986Z,1725056342.986 [BPC1](ERROR): BPC1B: No match for serial number 1717 in BPC1B's battery stick inventory (sticks 32-62 in onboard configuration file). 2024-08-30T22:19:17.137Z,1725056357.137 [BPC1](INFO): Calculating totals. Valid battery stick count: 27. Valid reserve battery stick count: 4. 2024-08-30T22:19:17.140Z,1725056357.140 [BPC1](INFO): Received data from all battery sticks. 2024-08-30T22:22:05.999Z,1725056525.999 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2024-08-30T22:22:05.999Z,1725056525.999 [DropWeight] Hardware Fault, FailCount= 1 2024-08-30T22:22:05.999Z,1725056525.999 [DropWeight](ERROR): Hardware Fault 2024-08-30T22:22:06.046Z,1725056526.046 [CBIT](INFO): Critical error at 20240830T222205 2024-08-30T22:22:06.048Z,1725056526.048 [CBIT](ERROR): Hardware Fault in component: DropWeight 2024-08-30T22:22:06.053Z,1725056526.053 [CBIT](CRITICAL): Hardware Fault in component: DropWeight 2024-08-30T22:22:06.459Z,1725056526.459 [CBIT](INFO): Critical error at 20240830T222206 2024-08-30T22:22:35.897Z,1725056555.897 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2024-08-30T22:23:05.801Z,1725056585.801 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-08-30T22:23:05.801Z,1725056585.801 [Default:CheckIn:C.Wait] Stopped 2024-08-30T22:23:05.801Z,1725056585.801 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-08-30T22:23:05.801Z,1725056585.801 [Default:CheckIn:D] Running Loop=1 2024-08-30T22:23:06.206Z,1725056586.206 [Default:CheckIn:D] Stopped 2024-08-30T22:23:06.207Z,1725056586.207 [Default:CheckIn:E] Running Loop=1 2024-08-30T22:23:06.617Z,1725056586.617 [NAL9602](INFO): Not Powering down - fast GPS 2024-08-30T22:23:06.628Z,1725056586.628 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 174.456364 min 2024-08-30T22:23:06.628Z,1725056586.628 [Default:CheckIn:E] Stopped 2024-08-30T22:23:06.628Z,1725056586.628 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-08-30T22:23:06.628Z,1725056586.628 [Default:CheckIn] Stopped 2024-08-30T22:23:06.628Z,1725056586.628 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-08-30T22:23:06.629Z,1725056586.629 [Default:CheckIn](INFO): Running loop #30 2024-08-30T22:23:06.629Z,1725056586.629 [Default:CheckIn] Running Loop=30 2024-08-30T22:23:06.629Z,1725056586.629 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-08-30T22:23:06.629Z,1725056586.629 [Default:CheckIn:Read_GPS] Running Loop=1 2024-08-30T22:23:08.626Z,1725056588.626 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,222308.00,A,3648.16307,N,12147.29469,W,0.408,0.00,300824,,,A*7F 2024-08-30T22:23:08.628Z,1725056588.628 [NAL9602](INFO): GPS fix at 20240830T222308: (36.802718, -121.788245) 2024-08-30T22:23:08.656Z,1725056588.656 [Default:CheckIn:Read_GPS] Stopped 2024-08-30T22:23:08.656Z,1725056588.656 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-08-30T22:23:16.240Z,1725056596.240 [DataOverHttps](INFO): Sending 167 bytes from file Logs/20240830T195610/Courier0078.lzma 2024-08-30T22:23:17.242Z,1725056597.242 [DataOverHttps](INFO): Moved sent file to Logs/20240830T195610/Courier0078.lzma.bak 2024-08-30T22:23:17.243Z,1725056597.243 [DataOverHttps](INFO): SBD MOMSN=23105756 2024-08-30T22:23:37.452Z,1725056617.452 [DataOverHttps](INFO): Sending 220 bytes from file Logs/20240830T195610/Express0079.lzma 2024-08-30T22:23:38.455Z,1725056618.455 [DataOverHttps](INFO): Moved sent file to Logs/20240830T195610/Express0079.lzma.bak 2024-08-30T22:23:38.455Z,1725056618.455 [DataOverHttps](INFO): SBD MOMSN=23105763 2024-08-30T22:23:39.349Z,1725056619.349 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2024-08-30T22:23:39.433Z,1725056619.433 [NAL9602](ERROR): received: +CSQ:0 OK384, 2, 0, 0, 0 OK 2024-08-30T22:23:41.808Z,1725056621.808 [Default:CheckIn:Read_Iridium] Stopped 2024-08-30T22:23:41.808Z,1725056621.808 [Default:CheckIn:C.Wait] Running Loop=1 2024-08-30T22:23:41.808Z,1725056621.808 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-08-30T22:27:49.874Z,1725056869.874 [DVL_micro](ERROR): only read 3 of 4 data items for bottom velocity. Device response is::BI,+0201,-00838,+00000,I 2024-08-30T22:27:49.874Z,1725056869.874 [DVL_micro](ERROR): Failed to parse: :BI,+0201,-00838,+00000,I 2024-08-30T22:28:10.883Z,1725056890.883 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2024-08-30T22:28:41.584Z,1725056921.584 [NAL9602](INFO): Not Powering down - fast GPS 2024-08-30T22:28:42.397Z,1725056922.397 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-08-30T22:28:42.398Z,1725056922.398 [Default:CheckIn:C.Wait] Stopped 2024-08-30T22:28:42.398Z,1725056922.398 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-08-30T22:28:42.398Z,1725056922.398 [Default:CheckIn:D] Running Loop=1 2024-08-30T22:28:42.800Z,1725056922.800 [Default:CheckIn:D] Stopped 2024-08-30T22:28:42.800Z,1725056922.800 [Default:CheckIn:E] Running Loop=1 2024-08-30T22:28:43.217Z,1725056923.217 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 180.066243 min 2024-08-30T22:28:43.217Z,1725056923.217 [Default:CheckIn:E] Stopped 2024-08-30T22:28:43.217Z,1725056923.217 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-08-30T22:28:43.217Z,1725056923.217 [Default:CheckIn] Stopped 2024-08-30T22:28:43.217Z,1725056923.217 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-08-30T22:28:43.218Z,1725056923.218 [Default:CheckIn](INFO): Running loop #31 2024-08-30T22:28:43.218Z,1725056923.218 [Default:CheckIn] Running Loop=31 2024-08-30T22:28:43.218Z,1725056923.218 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-08-30T22:28:43.218Z,1725056923.218 [Default:CheckIn:Read_GPS] Running Loop=1 2024-08-30T22:28:45.215Z,1725056925.215 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,222844.00,A,3648.17774,N,12147.29061,W,1.263,316.80,300824,,,A*77 2024-08-30T22:28:45.218Z,1725056925.218 [NAL9602](INFO): GPS fix at 20240830T222844: (36.802962, -121.788177) 2024-08-30T22:28:45.227Z,1725056925.227 [Default:CheckIn:Read_GPS] Stopped 2024-08-30T22:28:45.227Z,1725056925.227 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-08-30T22:28:52.684Z,1725056932.684 [DataOverHttps](INFO): Sending 77 bytes from file Logs/20240830T195610/Courier0081.lzma 2024-08-30T22:28:53.687Z,1725056933.687 [DataOverHttps](INFO): Moved sent file to Logs/20240830T195610/Courier0081.lzma.bak 2024-08-30T22:28:53.687Z,1725056933.687 [DataOverHttps](INFO): SBD MOMSN=23105782 2024-08-30T22:29:11.276Z,1725056951.276 [DataOverHttps](INFO): Sending 221 bytes from file Logs/20240830T195610/Express0082.lzma 2024-08-30T22:29:13.749Z,1725056953.749 [DataOverHttps](INFO): Moved sent file to Logs/20240830T195610/Express0082.lzma.bak 2024-08-30T22:29:13.750Z,1725056953.750 [DataOverHttps](INFO): SBD MOMSN=23105788 2024-08-30T22:29:15.927Z,1725056955.927 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2024-08-30T22:29:16.001Z,1725056956.001 [NAL9602](ERROR): received: +CSQ:0 OK384, 2, 0, 0, 0 OK 2024-08-30T22:29:16.038Z,1725056956.038 [Default:CheckIn:Read_Iridium] Stopped 2024-08-30T22:29:16.038Z,1725056956.038 [Default:CheckIn:C.Wait] Running Loop=1 2024-08-30T22:29:16.038Z,1725056956.038 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-08-30T22:33:47.860Z,1725057227.860 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2024-08-30T22:34:16.555Z,1725057256.555 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-08-30T22:34:16.555Z,1725057256.555 [Default:CheckIn:C.Wait] Stopped 2024-08-30T22:34:16.555Z,1725057256.555 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-08-30T22:34:16.555Z,1725057256.555 [Default:CheckIn:D] Running Loop=1 2024-08-30T22:34:16.981Z,1725057256.981 [Default:CheckIn:D] Stopped 2024-08-30T22:34:16.981Z,1725057256.981 [Default:CheckIn:E] Running Loop=1 2024-08-30T22:34:17.363Z,1725057257.363 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 185.635938 min 2024-08-30T22:34:17.364Z,1725057257.364 [Default:CheckIn:E] Stopped 2024-08-30T22:34:17.364Z,1725057257.364 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-08-30T22:34:17.364Z,1725057257.364 [Default:CheckIn] Stopped 2024-08-30T22:34:17.364Z,1725057257.364 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-08-30T22:34:17.364Z,1725057257.364 [Default:CheckIn](INFO): Running loop #32 2024-08-30T22:34:17.364Z,1725057257.364 [Default:CheckIn] Running Loop=32 2024-08-30T22:34:17.364Z,1725057257.364 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-08-30T22:34:17.364Z,1725057257.364 [Default:CheckIn:Read_GPS] Running Loop=1 2024-08-30T22:34:19.389Z,1725057259.389 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,223419.00,A,3648.15974,N,12147.24471,W,0.758,313.89,300824,,,A*76 2024-08-30T22:34:19.391Z,1725057259.391 [NAL9602](INFO): GPS fix at 20240830T223419: (36.802662, -121.787412) 2024-08-30T22:34:19.400Z,1725057259.400 [Default:CheckIn:Read_GPS] Stopped 2024-08-30T22:34:19.401Z,1725057259.401 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-08-30T22:34:28.624Z,1725057268.624 [DataOverHttps](INFO): Sending 77 bytes from file Logs/20240830T195610/Courier0084.lzma 2024-08-30T22:34:29.635Z,1725057269.635 [DataOverHttps](INFO): Moved sent file to Logs/20240830T195610/Courier0084.lzma.bak 2024-08-30T22:34:29.635Z,1725057269.635 [DataOverHttps](INFO): SBD MOMSN=23105846 2024-08-30T22:34:50.408Z,1725057290.408 [DataOverHttps](INFO): Sending 226 bytes from file Logs/20240830T195610/Express0085.lzma 2024-08-30T22:34:51.411Z,1725057291.411 [DataOverHttps](INFO): Moved sent file to Logs/20240830T195610/Express0085.lzma.bak 2024-08-30T22:34:51.411Z,1725057291.411 [DataOverHttps](INFO): SBD MOMSN=23105849 2024-08-30T22:34:52.096Z,1725057292.096 [NAL9602](INFO): Not Powering down - fast GPS 2024-08-30T22:34:54.545Z,1725057294.545 [Default:CheckIn:Read_Iridium] Stopped 2024-08-30T22:34:54.545Z,1725057294.545 [Default:CheckIn:C.Wait] Running Loop=1 2024-08-30T22:34:54.545Z,1725057294.545 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-08-30T22:37:06.244Z,1725057426.244 [CBIT](INFO): Clearing failed state for component DropWeight 2024-08-30T22:37:06.244Z,1725057426.244 [DropWeight] No Fault, FailCount= 1 2024-08-30T22:37:20.905Z,1725057440.905 [CommandExec](IMPORTANT): got command failComponent 2024-08-30T22:37:20.905Z,1725057440.905 [CommandExec](IMPORTANT): Failed components: 2024-08-30T22:37:20.906Z,1725057440.906 [CommandExec](IMPORTANT): No failed Components. 2024-08-30T22:37:39.365Z,1725057459.365 [CommandExec](IMPORTANT): got command quit 2024-08-30T22:37:40.369Z,1725057460.369 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread. 2024-08-30T22:37:40.369Z,1725057460.369 [CommandExec](INFO): Uninitializing the command executive. 2024-08-30T22:37:40.369Z,1725057460.369 [CommandExec](INFO): Uninitializing the command scheduler. 2024-08-30T22:37:40.369Z,1725057460.369 [CommandExec ThreadHandler](INFO): Thread cancelled. 2024-08-30T22:37:40.537Z,1725057460.537 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2024-08-30T22:37:40.537Z,1725057460.537 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2024-08-30T22:37:40.537Z,1725057460.537 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2024-08-30T22:37:40.538Z,1725057460.538 [NavChartDb](INFO): Join timeout helper Thread ID is 2540 2024-08-30T22:37:40.785Z,1725057460.785 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2024-08-30T22:37:40.785Z,1725057460.785 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2024-08-30T22:37:40.801Z,1725057460.801 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2024-08-30T22:37:40.801Z,1725057460.801 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2024-08-30T22:37:40.801Z,1725057460.801 [Radio_Surface](INFO): Join timeout helper Thread ID is 2541 2024-08-30T22:37:41.141Z,1725057461.141 [Radio_Surface](INFO): Powering down 2024-08-30T22:37:41.142Z,1725057461.142 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2024-08-30T22:37:41.142Z,1725057461.142 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2024-08-30T22:37:41.161Z,1725057461.161 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler 2024-08-30T22:37:41.161Z,1725057461.161 [Onboard ThreadHandler](INFO): Thread cancelled. 2024-08-30T22:37:41.161Z,1725057461.161 [Onboard](INFO): Join timeout helper Thread ID is 2542 2024-08-30T22:37:42.405Z,1725057462.405 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread. 2024-08-30T22:37:42.405Z,1725057462.405 [Onboard ThreadHandler](INFO): Thread cancelled. 2024-08-30T22:37:42.421Z,1725057462.421 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2024-08-30T22:37:42.421Z,1725057462.421 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2024-08-30T22:37:42.421Z,1725057462.421 [DataOverHttps](INFO): Join timeout helper Thread ID is 2543 2024-08-30T22:37:42.709Z,1725057462.709 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2024-08-30T22:37:42.712Z,1725057462.712 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2024-08-30T22:37:42.717Z,1725057462.717 [ComponentRegistry](INFO): Shutting down DATMMP ThreadHandler 2024-08-30T22:37:42.717Z,1725057462.717 [DATMMP ThreadHandler](INFO): Thread cancelled. 2024-08-30T22:37:42.717Z,1725057462.717 [DATMMP](INFO): Join timeout helper Thread ID is 2544 2024-08-30T22:37:42.849Z,1725057462.849 [DATMMP](INFO): Stop 2024-08-30T22:37:42.849Z,1725057462.849 [DATMMP](INFO): uninitialize 2024-08-30T22:37:42.849Z,1725057462.849 [DATMMP](INFO): Powering down 2024-08-30T22:37:42.921Z,1725057462.921 [DATMMP ThreadHandler](INFO): Uninitializing protected caller thread. 2024-08-30T22:37:42.921Z,1725057462.921 [DATMMP](INFO): uninitialize 2024-08-30T22:37:42.922Z,1725057462.922 [DATMMP](INFO): Powering down 2024-08-30T22:37:42.922Z,1725057462.922 [DATMMP ThreadHandler](INFO): Thread cancelled. 2024-08-30T22:37:42.938Z,1725057462.938 [ComponentRegistry](INFO): Shutting down BackseatComponent ThreadHandler 2024-08-30T22:37:42.938Z,1725057462.938 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2024-08-30T22:37:42.938Z,1725057462.938 [BackseatComponent](INFO): Join timeout helper Thread ID is 2545 2024-08-30T22:37:43.097Z,1725057463.097 [BackseatComponent ThreadHandler](INFO): Uninitializing protected caller thread. 2024-08-30T22:37:43.098Z,1725057463.098 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2024-08-30T22:37:43.118Z,1725057463.118 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2024-08-30T22:37:43.118Z,1725057463.118 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2024-08-30T22:37:43.119Z,1725057463.119 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 2546 2024-08-30T22:37:43.609Z,1725057463.609 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2024-08-30T22:37:43.609Z,1725057463.609 [WetLabsBB2FL](INFO): Powering down 2024-08-30T22:37:43.610Z,1725057463.610 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2024-08-30T22:37:43.629Z,1725057463.629 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2024-08-30T22:37:43.629Z,1725057463.629 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2024-08-30T22:37:43.630Z,1725057463.630 [CTD_Seabird](INFO): Join timeout helper Thread ID is 2547 2024-08-30T22:37:44.533Z,1725057464.533 [CTD_Seabird](INFO): Powering down 2024-08-30T22:37:44.545Z,1725057464.545 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread. 2024-08-30T22:37:44.545Z,1725057464.545 [CTD_Seabird](INFO): Powering down 2024-08-30T22:37:44.557Z,1725057464.557 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2024-08-30T22:37:44.584Z,1725057464.584 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2024-08-30T22:37:44.593Z,1725057464.593 [logger ThreadHandler](INFO): Thread cancelled. 2024-08-30T22:37:44.593Z,1725057464.593 [logger](INFO): Join timeout helper Thread ID is 2548 2024-08-30T22:37:44.616Z,1725057464.616 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2024-08-30T22:37:44.617Z,1725057464.617 [logger ThreadHandler](INFO): Thread cancelled. 2024-08-30T22:37:44.633Z,1725057464.633 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2024-08-30T22:37:44.633Z,1725057464.633 [CommandLine ThreadHandler](INFO): Thread cancelled. 2024-08-30T22:37:44.634Z,1725057464.634 [CommandLine](INFO): Join timeout helper Thread ID is 2549 2024-08-30T22:37:44.697Z,1725057464.697 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2024-08-30T22:37:44.697Z,1725057464.697 [CommandLine ThreadHandler](INFO): Thread cancelled. 2024-08-30T22:37:44.717Z,1725057464.717 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler 2024-08-30T22:37:44.717Z,1725057464.717 [CommandExec ThreadHandler](INFO): Thread cancelled. 2024-08-30T22:37:44.718Z,1725057464.718 [CommandExec](INFO): Join timeout helper Thread ID is 2550 2024-08-30T22:37:44.719Z,1725057464.719 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2024-08-30T22:37:44.719Z,1725057464.719 [controlThread ThreadHandler](INFO): Thread cancelled. 2024-08-30T22:37:44.719Z,1725057464.719 [controlThread](INFO): Join timeout helper Thread ID is 2551 2024-08-30T22:37:44.989Z,1725057464.989 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2024-08-30T22:37:44.989Z,1725057464.989 [controlThread](DEBUG): Uninitializing ControlThread 2024-08-30T22:37:44.991Z,1725057464.991 [AHRS_M2](INFO): Powering down 2024-08-30T22:37:45.157Z,1725057465.157 [DVL_micro](INFO): Powering down 2024-08-30T22:37:45.158Z,1725057465.158 [NAL9602](INFO): Powering down 2024-08-30T22:37:45.159Z,1725057465.159 [Sonardyne_Nano](INFO): Powering down 2024-08-30T22:37:45.277Z,1725057465.277 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2024-08-30T22:37:45.278Z,1725057465.278 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2024-08-30T22:37:45.278Z,1725057465.278 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2024-08-30T22:37:45.279Z,1725057465.279 [MissionManager](INFO): Uninitializing Mission Default 2024-08-30T22:37:45.279Z,1725057465.279 [Default] Stopped 2024-08-30T22:37:45.279Z,1725057465.279 [Default](DEBUG): Aggregate::uninitialize Default 2024-08-30T22:37:45.279Z,1725057465.279 [Default:B.GoToSurface] Stopped 2024-08-30T22:37:45.279Z,1725057465.279 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2024-08-30T22:37:45.279Z,1725057465.279 [Default:CheckIn] Stopped 2024-08-30T22:37:45.279Z,1725057465.279 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-08-30T22:37:45.280Z,1725057465.280 [Default:CheckIn:C.Wait] Stopped 2024-08-30T22:37:45.280Z,1725057465.280 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-08-30T22:37:45.282Z,1725057465.282 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2024-08-30T22:37:45.283Z,1725057465.283 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2024-08-30T22:37:45.283Z,1725057465.283 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2024-08-30T22:37:45.283Z,1725057465.283 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2024-08-30T22:37:45.283Z,1725057465.283 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2024-08-30T22:37:45.284Z,1725057465.284 [BuoyancyServo](INFO): Powering down 2024-08-30T22:37:45.297Z,1725057465.297 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2024-08-30T22:37:45.297Z,1725057465.297 [ElevatorServo](INFO): Powering down 2024-08-30T22:37:45.298Z,1725057465.298 [MassServo](DEBUG): Uninitialize Mass Servo. 2024-08-30T22:37:45.298Z,1725057465.298 [MassServo](INFO): Powering down 2024-08-30T22:37:45.299Z,1725057465.299 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2024-08-30T22:37:45.299Z,1725057465.299 [RudderServo](INFO): Powering down 2024-08-30T22:37:45.300Z,1725057465.300 [ThrusterHE](DEBUG): Uninitialize Thruster Servo. 2024-08-30T22:37:45.300Z,1725057465.300 [ThrusterHE](INFO): Powering down 2024-08-30T22:37:45.301Z,1725057465.301 [SBIT](DEBUG): Uninitialize SBIT Component. 2024-08-30T22:37:45.301Z,1725057465.301 [IBIT](DEBUG): Uninitialize IBIT Component. 2024-08-30T22:37:45.301Z,1725057465.301 [CBIT](DEBUG): Uninitialize CBIT Component. 2024-08-30T22:37:45.301Z,1725057465.301 [CBIT](DEBUG): Powering off loads. 2024-08-30T22:37:45.312Z,1725057465.312 [CBIT](DEBUG): Disabling WDT. 2024-08-30T22:37:45.324Z,1725057465.324 [CBIT](DEBUG): Opening all GF detection circuits. 2024-08-30T22:37:45.325Z,1725057465.325 [controlThread ThreadHandler](INFO): Thread cancelled. 2024-08-30T22:37:45.369Z,1725057465.369 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2024-08-30T22:37:45.375Z,1725057465.375 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2024-08-30T22:37:45.406Z,1725057465.406 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2024-08-30T22:37:45.408Z,1725057465.408 [Onboard ThreadHandler](INFO): Thread cancelled. 2024-08-30T22:37:45.416Z,1725057465.416 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2024-08-30T22:37:45.422Z,1725057465.422 [DATMMP ThreadHandler](INFO): Thread cancelled. 2024-08-30T22:37:45.464Z,1725057465.464 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2024-08-30T22:37:45.517Z,1725057465.517 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2024-08-30T22:37:45.593Z,1725057465.593 [logger ThreadHandler](INFO): Thread cancelled.