2025-08-13T18:07:59.459Z,1755108479.459 [CommandExec](IMPORTANT): got command restart logs 2025-08-13T18:10:18.686Z,1755108618.686 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-08-13T18:10:18.687Z,1755108618.687 [Default:CheckIn:C.Wait] Stopped 2025-08-13T18:10:18.687Z,1755108618.687 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-08-13T18:10:18.687Z,1755108618.687 [Default:CheckIn:D] Running Loop=1 2025-08-13T18:10:19.102Z,1755108619.102 [Default:CheckIn:D] Stopped 2025-08-13T18:10:19.102Z,1755108619.102 [Default:CheckIn:E] Running Loop=1 2025-08-13T18:10:19.499Z,1755108619.499 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 27.973344 min 2025-08-13T18:10:19.500Z,1755108619.500 [Default:CheckIn:E] Stopped 2025-08-13T18:10:19.500Z,1755108619.500 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-08-13T18:10:19.500Z,1755108619.500 [Default:CheckIn] Stopped 2025-08-13T18:10:19.500Z,1755108619.500 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-08-13T18:10:19.500Z,1755108619.500 [Default:CheckIn](INFO): Running loop #5 2025-08-13T18:10:19.500Z,1755108619.500 [Default:CheckIn] Running Loop=5 2025-08-13T18:10:19.500Z,1755108619.500 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-08-13T18:10:19.500Z,1755108619.500 [Default:CheckIn:Read_GPS] Running Loop=1 2025-08-13T18:10:21.110Z,1755108621.110 [BPC1](INFO): Calculating totals. Valid battery stick count: 46. Valid reserve battery stick count: 4. 2025-08-13T18:10:21.114Z,1755108621.114 [BPC1](FAULT): Failed to receive data from 6 sticks prior to timeout. Will not retry this scan cycle. Missing stick IDs are: 32, 33, 36, 37, 51, 54. 2025-08-13T18:10:21.504Z,1755108621.504 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181020.00,A,3648.04738,N,12148.39555,W,26.883,73.75,130825,,,D*7F 2025-08-13T18:10:21.507Z,1755108621.507 [NAL9602](INFO): GPS fix at 20250813T181020: (36.800790, -121.806592) 2025-08-13T18:10:21.551Z,1755108621.551 [Default:CheckIn:Read_GPS] Stopped 2025-08-13T18:10:21.551Z,1755108621.551 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-08-13T18:10:31.809Z,1755108631.809 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250812T185144/Courier0096.lzma 2025-08-13T18:10:32.812Z,1755108632.812 [DataOverHttps](INFO): Moved sent file to Logs/20250812T185144/Courier0096.lzma.bak 2025-08-13T18:10:32.812Z,1755108632.812 [DataOverHttps](INFO): SBD MOMSN=25847456 2025-08-13T18:10:34.128Z,1755108634.128 [NAL9602](INFO): SBD MO Status=0, MOMSN=64405, MT Status=0, MTMSN=0 2025-08-13T18:10:34.128Z,1755108634.128 [NAL9602](INFO): No messages in MT queue 2025-08-13T18:10:48.707Z,1755108648.707 [DataOverHttps](INFO): Sending 307 bytes from file Logs/20250813T180759/Courier0000.lzma 2025-08-13T18:10:49.707Z,1755108649.707 [DataOverHttps](INFO): Moved sent file to Logs/20250813T180759/Courier0000.lzma.bak 2025-08-13T18:10:49.707Z,1755108649.707 [DataOverHttps](INFO): SBD MOMSN=25847458 2025-08-13T18:11:04.826Z,1755108664.826 [NAL9602](INFO): Not Powering down - fast GPS 2025-08-13T18:11:05.713Z,1755108665.713 [DataOverHttps](INFO): Sending 104 bytes from file Logs/20250812T185144/Express0097.lzma 2025-08-13T18:11:06.716Z,1755108666.716 [DataOverHttps](INFO): Moved sent file to Logs/20250812T185144/Express0097.lzma.bak 2025-08-13T18:11:06.716Z,1755108666.716 [DataOverHttps](INFO): SBD MOMSN=25847466 2025-08-13T18:11:22.655Z,1755108682.655 [DataOverHttps](INFO): Sending 612 bytes from file Logs/20250813T180759/Express0001.lzma 2025-08-13T18:11:23.655Z,1755108683.655 [DataOverHttps](INFO): Moved sent file to Logs/20250813T180759/Express0001.lzma.bak 2025-08-13T18:11:23.655Z,1755108683.655 [DataOverHttps](INFO): SBD MOMSN=25847470 2025-08-13T18:11:25.044Z,1755108685.044 [Default:CheckIn:Read_Iridium] Stopped 2025-08-13T18:11:25.045Z,1755108685.045 [Default:CheckIn:C.Wait] Running Loop=1 2025-08-13T18:11:25.045Z,1755108685.045 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-08-13T18:16:25.613Z,1755108985.613 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-08-13T18:16:25.632Z,1755108985.632 [Default:CheckIn:C.Wait] Stopped 2025-08-13T18:16:25.632Z,1755108985.632 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-08-13T18:16:25.632Z,1755108985.632 [Default:CheckIn:D] Running Loop=1 2025-08-13T18:16:26.019Z,1755108986.019 [Default:CheckIn:D] Stopped 2025-08-13T18:16:26.019Z,1755108986.019 [Default:CheckIn:E] Running Loop=1 2025-08-13T18:16:26.427Z,1755108986.427 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 34.088633 min 2025-08-13T18:16:26.428Z,1755108986.428 [Default:CheckIn:E] Stopped 2025-08-13T18:16:26.428Z,1755108986.428 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-08-13T18:16:26.428Z,1755108986.428 [Default:CheckIn] Stopped 2025-08-13T18:16:26.428Z,1755108986.428 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-08-13T18:16:26.428Z,1755108986.428 [Default:CheckIn](INFO): Running loop #6 2025-08-13T18:16:26.428Z,1755108986.428 [Default:CheckIn] Running Loop=6 2025-08-13T18:16:26.428Z,1755108986.428 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-08-13T18:16:26.428Z,1755108986.428 [Default:CheckIn:Read_GPS] Running Loop=1 2025-08-13T18:16:28.429Z,1755108988.429 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181627.00,A,3648.41119,N,12147.12294,W,3.149,180.23,130825,,,D*70 2025-08-13T18:16:28.431Z,1755108988.431 [NAL9602](INFO): GPS fix at 20250813T181627: (36.806853, -121.785382) 2025-08-13T18:16:28.443Z,1755108988.443 [Default:CheckIn:Read_GPS] Stopped 2025-08-13T18:16:28.443Z,1755108988.443 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-08-13T18:16:36.465Z,1755108996.465 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250813T180759/Courier0006.lzma 2025-08-13T18:16:37.467Z,1755108997.467 [DataOverHttps](INFO): Moved sent file to Logs/20250813T180759/Courier0006.lzma.bak 2025-08-13T18:16:37.468Z,1755108997.468 [DataOverHttps](INFO): SBD MOMSN=25847478 2025-08-13T18:16:50.648Z,1755109010.648 [NAL9602](INFO): SBD MO Status=0, MOMSN=64406, MT Status=0, MTMSN=0 2025-08-13T18:16:50.648Z,1755109010.648 [NAL9602](INFO): No messages in MT queue 2025-08-13T18:16:53.545Z,1755109013.545 [DataOverHttps](INFO): Sending 169 bytes from file Logs/20250813T180759/Express0007.lzma 2025-08-13T18:16:54.547Z,1755109014.547 [DataOverHttps](INFO): Moved sent file to Logs/20250813T180759/Express0007.lzma.bak 2025-08-13T18:16:54.547Z,1755109014.547 [DataOverHttps](INFO): SBD MOMSN=25847481 2025-08-13T18:16:55.928Z,1755109015.928 [Default:CheckIn:Read_Iridium] Stopped 2025-08-13T18:16:55.928Z,1755109015.928 [Default:CheckIn:C.Wait] Running Loop=1 2025-08-13T18:16:55.928Z,1755109015.928 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-08-13T18:17:21.350Z,1755109041.350 [NAL9602](INFO): Not Powering down - fast GPS 2025-08-13T18:21:56.524Z,1755109316.524 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-08-13T18:21:56.524Z,1755109316.524 [Default:CheckIn:C.Wait] Stopped 2025-08-13T18:21:56.525Z,1755109316.525 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-08-13T18:21:56.526Z,1755109316.526 [Default:CheckIn:D] Running Loop=1 2025-08-13T18:21:56.913Z,1755109316.913 [Default:CheckIn:D] Stopped 2025-08-13T18:21:56.913Z,1755109316.913 [Default:CheckIn:E] Running Loop=1 2025-08-13T18:21:57.322Z,1755109317.322 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 39.603532 min 2025-08-13T18:21:57.323Z,1755109317.323 [Default:CheckIn:E] Stopped 2025-08-13T18:21:57.323Z,1755109317.323 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-08-13T18:21:57.323Z,1755109317.323 [Default:CheckIn] Stopped 2025-08-13T18:21:57.323Z,1755109317.323 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-08-13T18:21:57.323Z,1755109317.323 [Default:CheckIn](INFO): Running loop #7 2025-08-13T18:21:57.323Z,1755109317.323 [Default:CheckIn] Running Loop=7 2025-08-13T18:21:57.323Z,1755109317.323 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-08-13T18:21:57.323Z,1755109317.323 [Default:CheckIn:Read_GPS] Running Loop=1 2025-08-13T18:21:59.316Z,1755109319.316 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182158.00,A,3648.15764,N,12147.21261,W,1.672,218.68,130825,,,D*7B 2025-08-13T18:21:59.319Z,1755109319.319 [NAL9602](INFO): GPS fix at 20250813T182158: (36.802627, -121.786877) 2025-08-13T18:21:59.329Z,1755109319.329 [Default:CheckIn:Read_GPS] Stopped 2025-08-13T18:21:59.330Z,1755109319.330 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-08-13T18:22:06.665Z,1755109326.665 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20250813T180759/Courier0009.lzma 2025-08-13T18:22:07.667Z,1755109327.667 [DataOverHttps](INFO): Moved sent file to Logs/20250813T180759/Courier0009.lzma.bak 2025-08-13T18:22:07.667Z,1755109327.667 [DataOverHttps](INFO): SBD MOMSN=25847491 2025-08-13T18:22:26.778Z,1755109346.778 [DataOverHttps](INFO): Sending 168 bytes from file Logs/20250813T180759/Express0010.lzma 2025-08-13T18:22:27.779Z,1755109347.779 [DataOverHttps](INFO): Moved sent file to Logs/20250813T180759/Express0010.lzma.bak 2025-08-13T18:22:27.779Z,1755109347.779 [DataOverHttps](INFO): SBD MOMSN=25847494 2025-08-13T18:22:29.275Z,1755109349.275 [Default:CheckIn:Read_Iridium] Stopped 2025-08-13T18:22:29.275Z,1755109349.275 [Default:CheckIn:C.Wait] Running Loop=1 2025-08-13T18:22:29.275Z,1755109349.275 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-08-13T18:22:41.373Z,1755109361.373 [NAL9602](INFO): SBD MO Status=0, MOMSN=64407, MT Status=0, MTMSN=0 2025-08-13T18:22:41.373Z,1755109361.373 [NAL9602](INFO): No messages in MT queue 2025-08-13T18:22:49.087Z,1755109369.087 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2025-08-13T18:23:12.075Z,1755109392.075 [NAL9602](INFO): Not Powering down - fast GPS 2025-08-13T18:25:19.746Z,1755109519.746 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-08-13T18:25:33.090Z,1755109533.090 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-08-13T18:25:46.795Z,1755109546.795 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-08-13T18:26:00.127Z,1755109560.127 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-08-13T18:26:13.863Z,1755109573.863 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-08-13T18:26:27.201Z,1755109587.201 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-08-13T18:26:40.930Z,1755109600.930 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-08-13T18:26:54.261Z,1755109614.261 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-08-13T18:27:07.594Z,1755109627.594 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-08-13T18:27:21.331Z,1755109641.331 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-08-13T18:27:29.835Z,1755109649.835 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-08-13T18:27:29.835Z,1755109649.835 [Default:CheckIn:C.Wait] Stopped 2025-08-13T18:27:29.835Z,1755109649.835 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-08-13T18:27:29.835Z,1755109649.835 [Default:CheckIn:D] Running Loop=1 2025-08-13T18:27:30.233Z,1755109650.233 [Default:CheckIn:D] Stopped 2025-08-13T18:27:30.233Z,1755109650.233 [Default:CheckIn:E] Running Loop=1 2025-08-13T18:27:30.636Z,1755109650.636 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 45.158870 min 2025-08-13T18:27:30.636Z,1755109650.636 [Default:CheckIn:E] Stopped 2025-08-13T18:27:30.636Z,1755109650.636 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-08-13T18:27:30.636Z,1755109650.636 [Default:CheckIn] Stopped 2025-08-13T18:27:30.636Z,1755109650.636 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-08-13T18:27:30.637Z,1755109650.637 [Default:CheckIn](INFO): Running loop #8 2025-08-13T18:27:30.637Z,1755109650.637 [Default:CheckIn] Running Loop=8 2025-08-13T18:27:30.637Z,1755109650.637 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-08-13T18:27:30.637Z,1755109650.637 [Default:CheckIn:Read_GPS] Running Loop=1 2025-08-13T18:27:32.665Z,1755109652.665 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182731.00,A,3648.15122,N,12147.21618,W,0.214,203.81,130825,,,D*74 2025-08-13T18:27:32.667Z,1755109652.667 [NAL9602](INFO): GPS fix at 20250813T182731: (36.802520, -121.786936) 2025-08-13T18:27:32.679Z,1755109652.679 [Default:CheckIn:Read_GPS] Stopped 2025-08-13T18:27:32.679Z,1755109652.679 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-08-13T18:27:34.662Z,1755109654.662 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-08-13T18:27:40.042Z,1755109660.042 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20250813T180759/Courier0012.lzma 2025-08-13T18:27:48.426Z,1755109668.426 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20250813T180759/Courier0012.lzma 2025-08-13T18:27:49.428Z,1755109669.428 [DataOverHttps](INFO): Moved sent file to Logs/20250813T180759/Courier0012.lzma.bak 2025-08-13T18:27:49.428Z,1755109669.428 [DataOverHttps](INFO): SBD MOMSN=25847502 2025-08-13T18:27:56.081Z,1755109676.081 [NAL9602](INFO): SBD MO Status=0, MOMSN=64408, MT Status=0, MTMSN=0 2025-08-13T18:27:56.081Z,1755109676.081 [NAL9602](INFO): No messages in MT queue 2025-08-13T18:28:05.750Z,1755109685.750 [DataOverHttps](INFO): Sending 153 bytes from file Logs/20250813T180759/Express0013.lzma 2025-08-13T18:28:06.752Z,1755109686.752 [DataOverHttps](INFO): Moved sent file to Logs/20250813T180759/Express0013.lzma.bak 2025-08-13T18:28:06.752Z,1755109686.752 [DataOverHttps](INFO): SBD MOMSN=25847506 2025-08-13T18:28:08.217Z,1755109688.217 [Default:CheckIn:Read_Iridium] Stopped 2025-08-13T18:28:08.217Z,1755109688.217 [Default:CheckIn:C.Wait] Running Loop=1 2025-08-13T18:28:08.217Z,1755109688.217 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-08-13T18:28:26.783Z,1755109706.783 [NAL9602](INFO): Not Powering down - fast GPS 2025-08-13T18:28:54.255Z,1755109734.255 [BPC1](ERROR): BPC1B: No match for serial number 1717 in BPC1B's battery stick inventory (sticks 32-62 in onboard configuration file). 2025-08-13T18:33:08.865Z,1755109988.865 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-08-13T18:33:08.865Z,1755109988.865 [Default:CheckIn:C.Wait] Stopped 2025-08-13T18:33:08.865Z,1755109988.865 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-08-13T18:33:08.865Z,1755109988.865 [Default:CheckIn:D] Running Loop=1 2025-08-13T18:33:09.211Z,1755109989.211 [Default:CheckIn:D] Stopped 2025-08-13T18:33:09.211Z,1755109989.211 [Default:CheckIn:E] Running Loop=1 2025-08-13T18:33:09.626Z,1755109989.626 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 50.808496 min 2025-08-13T18:33:09.626Z,1755109989.626 [Default:CheckIn:E] Stopped 2025-08-13T18:33:09.627Z,1755109989.627 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-08-13T18:33:09.627Z,1755109989.627 [Default:CheckIn] Stopped 2025-08-13T18:33:09.627Z,1755109989.627 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-08-13T18:33:09.627Z,1755109989.627 [Default:CheckIn](INFO): Running loop #9 2025-08-13T18:33:09.627Z,1755109989.627 [Default:CheckIn] Running Loop=9 2025-08-13T18:33:09.627Z,1755109989.627 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-08-13T18:33:09.627Z,1755109989.627 [Default:CheckIn:Read_GPS] Running Loop=1 2025-08-13T18:33:11.626Z,1755109991.626 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183310.00,A,3648.16417,N,12147.24839,W,2.002,332.13,130825,,,D*75 2025-08-13T18:33:11.628Z,1755109991.628 [NAL9602](INFO): GPS fix at 20250813T183310: (36.802736, -121.787473) 2025-08-13T18:33:11.656Z,1755109991.656 [Default:CheckIn:Read_GPS] Stopped 2025-08-13T18:33:11.656Z,1755109991.656 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-08-13T18:33:18.638Z,1755109998.638 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20250813T180759/Courier0015.lzma 2025-08-13T18:33:19.640Z,1755109999.640 [DataOverHttps](INFO): Moved sent file to Logs/20250813T180759/Courier0015.lzma.bak 2025-08-13T18:33:19.640Z,1755109999.640 [DataOverHttps](INFO): SBD MOMSN=25847548 2025-08-13T18:33:35.947Z,1755110015.947 [DataOverHttps](INFO): Sending 168 bytes from file Logs/20250813T180759/Express0016.lzma 2025-08-13T18:33:36.948Z,1755110016.948 [DataOverHttps](INFO): Moved sent file to Logs/20250813T180759/Express0016.lzma.bak 2025-08-13T18:33:36.948Z,1755110016.948 [DataOverHttps](INFO): SBD MOMSN=25847552 2025-08-13T18:33:38.331Z,1755110018.331 [Default:CheckIn:Read_Iridium] Stopped 2025-08-13T18:33:38.331Z,1755110018.331 [Default:CheckIn:C.Wait] Running Loop=1 2025-08-13T18:33:38.331Z,1755110018.331 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-08-13T18:33:47.597Z,1755110027.597 [NAL9602](INFO): SBD MO Status=2, MOMSN=64409, MT Status=2, MTMSN=0 2025-08-13T18:33:47.598Z,1755110027.598 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-08-13T18:34:06.986Z,1755110046.986 [NAL9602](INFO): SBD MO Status=0, MOMSN=64409, MT Status=0, MTMSN=0 2025-08-13T18:34:06.986Z,1755110046.986 [NAL9602](INFO): No messages in MT queue 2025-08-13T18:34:37.687Z,1755110077.687 [NAL9602](INFO): Not Powering down - fast GPS 2025-08-13T18:34:59.507Z,1755110099.507 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-13T18:35:12.434Z,1755110112.434 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-13T18:35:25.363Z,1755110125.363 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-13T18:35:37.478Z,1755110137.478 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-13T18:35:50.867Z,1755110150.867 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-13T18:36:03.326Z,1755110163.326 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-13T18:36:16.254Z,1755110176.254 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-13T18:36:29.190Z,1755110189.190 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-13T18:36:42.519Z,1755110202.519 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-13T18:36:55.447Z,1755110215.447 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-13T18:37:08.779Z,1755110228.779 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-13T18:38:38.911Z,1755110318.911 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-08-13T18:38:38.911Z,1755110318.911 [Default:CheckIn:C.Wait] Stopped 2025-08-13T18:38:38.911Z,1755110318.911 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-08-13T18:38:38.911Z,1755110318.911 [Default:CheckIn:D] Running Loop=1 2025-08-13T18:38:39.322Z,1755110319.322 [Default:CheckIn:D] Stopped 2025-08-13T18:38:39.322Z,1755110319.322 [Default:CheckIn:E] Running Loop=1 2025-08-13T18:38:39.774Z,1755110319.774 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 56.310343 min 2025-08-13T18:38:39.774Z,1755110319.774 [Default:CheckIn:E] Stopped 2025-08-13T18:38:39.774Z,1755110319.774 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-08-13T18:38:39.775Z,1755110319.775 [Default:CheckIn] Stopped 2025-08-13T18:38:39.775Z,1755110319.775 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-08-13T18:38:39.775Z,1755110319.775 [Default:CheckIn](INFO): Running loop #10 2025-08-13T18:38:39.775Z,1755110319.775 [Default:CheckIn] Running Loop=10 2025-08-13T18:38:39.775Z,1755110319.775 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-08-13T18:38:39.775Z,1755110319.775 [Default:CheckIn:Read_GPS] Running Loop=1 2025-08-13T18:38:41.745Z,1755110321.745 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183841.00,A,3648.16710,N,12147.28238,W,0.039,279.56,130825,,,A*79 2025-08-13T18:38:41.748Z,1755110321.748 [NAL9602](INFO): GPS fix at 20250813T183841: (36.802785, -121.788040) 2025-08-13T18:38:41.767Z,1755110321.767 [Default:CheckIn:Read_GPS] Stopped 2025-08-13T18:38:41.767Z,1755110321.767 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-08-13T18:38:49.138Z,1755110329.138 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20250813T180759/Courier0018.lzma 2025-08-13T18:38:50.141Z,1755110330.141 [DataOverHttps](INFO): Moved sent file to Logs/20250813T180759/Courier0018.lzma.bak 2025-08-13T18:38:50.141Z,1755110330.141 [DataOverHttps](INFO): SBD MOMSN=25847590 2025-08-13T18:38:57.493Z,1755110337.493 [NAL9602](INFO): SBD MO Status=0, MOMSN=64410, MT Status=0, MTMSN=0 2025-08-13T18:38:57.493Z,1755110337.493 [NAL9602](INFO): No messages in MT queue 2025-08-13T18:39:06.326Z,1755110346.326 [DataOverHttps](INFO): Sending 162 bytes from file Logs/20250813T180759/Express0019.lzma 2025-08-13T18:39:07.328Z,1755110347.328 [DataOverHttps](INFO): Moved sent file to Logs/20250813T180759/Express0019.lzma.bak 2025-08-13T18:39:07.328Z,1755110347.328 [DataOverHttps](INFO): SBD MOMSN=25847593 2025-08-13T18:39:08.814Z,1755110348.814 [Default:CheckIn:Read_Iridium] Stopped 2025-08-13T18:39:08.814Z,1755110348.814 [Default:CheckIn:C.Wait] Running Loop=1 2025-08-13T18:39:08.814Z,1755110348.814 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-08-13T18:39:28.187Z,1755110368.187 [NAL9602](INFO): Not Powering down - fast GPS 2025-08-13T18:44:09.391Z,1755110649.391 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-08-13T18:44:09.391Z,1755110649.391 [Default:CheckIn:C.Wait] Stopped 2025-08-13T18:44:09.391Z,1755110649.391 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-08-13T18:44:09.392Z,1755110649.392 [Default:CheckIn:D] Running Loop=1 2025-08-13T18:44:09.805Z,1755110649.805 [Default:CheckIn:D] Stopped 2025-08-13T18:44:09.805Z,1755110649.805 [Default:CheckIn:E] Running Loop=1 2025-08-13T18:44:10.199Z,1755110650.199 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 61.818396 min 2025-08-13T18:44:10.199Z,1755110650.199 [Default:CheckIn:E] Stopped 2025-08-13T18:44:10.199Z,1755110650.199 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-08-13T18:44:10.199Z,1755110650.199 [Default:CheckIn] Stopped 2025-08-13T18:44:10.199Z,1755110650.199 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-08-13T18:44:10.199Z,1755110650.199 [Default:CheckIn](INFO): Running loop #11 2025-08-13T18:44:10.199Z,1755110650.199 [Default:CheckIn] Running Loop=11 2025-08-13T18:44:10.199Z,1755110650.199 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-08-13T18:44:10.199Z,1755110650.199 [Default:CheckIn:Read_GPS] Running Loop=1 2025-08-13T18:44:12.217Z,1755110652.217 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184411.00,A,3648.17105,N,12147.28273,W,0.272,279.56,130825,,,A*76 2025-08-13T18:44:12.219Z,1755110652.219 [NAL9602](INFO): GPS fix at 20250813T184411: (36.802851, -121.788045) 2025-08-13T18:44:12.231Z,1755110652.231 [Default:CheckIn:Read_GPS] Stopped 2025-08-13T18:44:12.231Z,1755110652.231 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-08-13T18:44:22.753Z,1755110662.753 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20250813T180759/Courier0021.lzma 2025-08-13T18:44:23.758Z,1755110663.758 [DataOverHttps](INFO): Moved sent file to Logs/20250813T180759/Courier0021.lzma.bak 2025-08-13T18:44:23.759Z,1755110663.759 [DataOverHttps](INFO): SBD MOMSN=25847674 2025-08-13T18:44:26.805Z,1755110666.805 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-13T18:44:27.217Z,1755110667.217 [NAL9602](INFO): SBD MO Status=0, MOMSN=64411, MT Status=0, MTMSN=0 2025-08-13T18:44:27.217Z,1755110667.217 [NAL9602](INFO): No messages in MT queue 2025-08-13T18:44:39.318Z,1755110679.318 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-13T18:44:41.102Z,1755110681.102 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20250813T180759/Express0022.lzma 2025-08-13T18:44:42.104Z,1755110682.104 [DataOverHttps](INFO): Moved sent file to Logs/20250813T180759/Express0022.lzma.bak 2025-08-13T18:44:42.104Z,1755110682.104 [DataOverHttps](INFO): SBD MOMSN=25847677 2025-08-13T18:44:43.379Z,1755110683.379 [Default:CheckIn:Read_Iridium] Stopped 2025-08-13T18:44:43.379Z,1755110683.379 [Default:CheckIn:C.Wait] Running Loop=1 2025-08-13T18:44:43.379Z,1755110683.379 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-08-13T18:44:52.651Z,1755110692.651 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-13T18:44:57.903Z,1755110697.903 [NAL9602](INFO): Not Powering down - fast GPS 2025-08-13T18:45:05.579Z,1755110705.579 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-13T18:45:18.506Z,1755110718.506 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-13T18:45:31.436Z,1755110731.436 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-13T18:45:44.765Z,1755110744.765 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-13T18:45:57.693Z,1755110757.693 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-13T18:46:10.623Z,1755110770.623 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-13T18:46:23.552Z,1755110783.552 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-13T18:46:36.487Z,1755110796.487 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-13T18:46:49.415Z,1755110809.415 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-13T18:49:44.001Z,1755110984.001 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-08-13T18:49:44.002Z,1755110984.002 [Default:CheckIn:C.Wait] Stopped 2025-08-13T18:49:44.002Z,1755110984.002 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-08-13T18:49:44.003Z,1755110984.003 [Default:CheckIn:D] Running Loop=1 2025-08-13T18:49:44.414Z,1755110984.414 [Default:CheckIn:D] Stopped 2025-08-13T18:49:44.414Z,1755110984.414 [Default:CheckIn:E] Running Loop=1 2025-08-13T18:49:44.818Z,1755110984.818 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 67.395211 min 2025-08-13T18:49:44.818Z,1755110984.818 [Default:CheckIn:E] Stopped 2025-08-13T18:49:44.818Z,1755110984.818 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-08-13T18:49:44.818Z,1755110984.818 [Default:CheckIn] Stopped 2025-08-13T18:49:44.818Z,1755110984.818 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-08-13T18:49:44.818Z,1755110984.818 [Default:CheckIn](INFO): Running loop #12 2025-08-13T18:49:44.819Z,1755110984.819 [Default:CheckIn] Running Loop=12 2025-08-13T18:49:44.819Z,1755110984.819 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-08-13T18:49:44.819Z,1755110984.819 [Default:CheckIn:Read_GPS] Running Loop=1 2025-08-13T18:49:46.821Z,1755110986.821 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184946.00,A,3648.17060,N,12147.28191,W,0.058,2.62,130825,,,A*77 2025-08-13T18:49:46.824Z,1755110986.824 [NAL9602](INFO): GPS fix at 20250813T184946: (36.802843, -121.788032) 2025-08-13T18:49:46.855Z,1755110986.855 [Default:CheckIn:Read_GPS] Stopped 2025-08-13T18:49:46.856Z,1755110986.856 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-08-13T18:49:54.758Z,1755110994.758 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20250813T180759/Courier0024.lzma 2025-08-13T18:49:55.760Z,1755110995.760 [DataOverHttps](INFO): Moved sent file to Logs/20250813T180759/Courier0024.lzma.bak 2025-08-13T18:49:55.760Z,1755110995.760 [DataOverHttps](INFO): SBD MOMSN=25847689 2025-08-13T18:50:12.822Z,1755111012.822 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20250813T180759/Express0025.lzma 2025-08-13T18:50:13.824Z,1755111013.824 [DataOverHttps](INFO): Moved sent file to Logs/20250813T180759/Express0025.lzma.bak 2025-08-13T18:50:13.824Z,1755111013.824 [DataOverHttps](INFO): SBD MOMSN=25847692 2025-08-13T18:50:15.170Z,1755111015.170 [Default:CheckIn:Read_Iridium] Stopped 2025-08-13T18:50:15.170Z,1755111015.170 [Default:CheckIn:C.Wait] Running Loop=1 2025-08-13T18:50:15.170Z,1755111015.170 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-08-13T18:50:23.646Z,1755111023.646 [Sonardyne_Nano](INFO): Battery below minimum, enabling charging 2025-08-13T18:51:22.623Z,1755111082.623 [BPC1](INFO): Calculating totals. Valid battery stick count: 48. Valid reserve battery stick count: 4. 2025-08-13T18:51:22.626Z,1755111082.626 [BPC1](FAULT): Failed to receive data from 5 sticks prior to timeout. Will not retry this scan cycle. Missing stick IDs are: 32, 33, 36, 37, 54. 2025-08-13T18:52:23.265Z,1755111143.265 [NAL9602](INFO): SBD MO Status=0, MOMSN=64412, MT Status=0, MTMSN=0 2025-08-13T18:52:23.265Z,1755111143.265 [NAL9602](INFO): No messages in MT queue 2025-08-13T18:52:53.983Z,1755111173.983 [NAL9602](INFO): Not Powering down - fast GPS 2025-08-13T18:55:15.845Z,1755111315.845 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-08-13T18:55:15.845Z,1755111315.845 [Default:CheckIn:C.Wait] Stopped 2025-08-13T18:55:15.845Z,1755111315.845 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-08-13T18:55:15.845Z,1755111315.845 [Default:CheckIn:D] Running Loop=1 2025-08-13T18:55:16.251Z,1755111316.251 [Default:CheckIn:D] Stopped 2025-08-13T18:55:16.251Z,1755111316.251 [Default:CheckIn:E] Running Loop=1 2025-08-13T18:55:16.665Z,1755111316.665 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 72.925830 min 2025-08-13T18:55:16.665Z,1755111316.665 [Default:CheckIn:E] Stopped 2025-08-13T18:55:16.665Z,1755111316.665 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-08-13T18:55:16.665Z,1755111316.665 [Default:CheckIn] Stopped 2025-08-13T18:55:16.665Z,1755111316.665 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-08-13T18:55:16.666Z,1755111316.666 [Default:CheckIn](INFO): Running loop #13 2025-08-13T18:55:16.666Z,1755111316.666 [Default:CheckIn] Running Loop=13 2025-08-13T18:55:16.666Z,1755111316.666 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-08-13T18:55:16.666Z,1755111316.666 [Default:CheckIn:Read_GPS] Running Loop=1 2025-08-13T18:55:18.665Z,1755111318.665 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185517.00,A,3648.17180,N,12147.28116,W,0.058,25.98,130825,,,A*4E 2025-08-13T18:55:18.668Z,1755111318.668 [NAL9602](INFO): GPS fix at 20250813T185517: (36.802863, -121.788019) 2025-08-13T18:55:18.679Z,1755111318.679 [Default:CheckIn:Read_GPS] Stopped 2025-08-13T18:55:18.679Z,1755111318.679 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-08-13T18:55:26.690Z,1755111326.690 [DataOverHttps](INFO): Sending 86 bytes from file Logs/20250813T180759/Courier0027.lzma 2025-08-13T18:55:27.692Z,1755111327.692 [DataOverHttps](INFO): Moved sent file to Logs/20250813T180759/Courier0027.lzma.bak 2025-08-13T18:55:27.692Z,1755111327.692 [DataOverHttps](INFO): SBD MOMSN=25847700 2025-08-13T18:55:32.001Z,1755111332.001 [NAL9602](INFO): SBD MO Status=0, MOMSN=64413, MT Status=0, MTMSN=0 2025-08-13T18:55:32.001Z,1755111332.001 [NAL9602](INFO): No messages in MT queue 2025-08-13T18:55:43.722Z,1755111343.722 [DataOverHttps](INFO): Sending 263 bytes from file Logs/20250813T180759/Express0028.lzma 2025-08-13T18:55:44.724Z,1755111344.724 [DataOverHttps](INFO): Moved sent file to Logs/20250813T180759/Express0028.lzma.bak 2025-08-13T18:55:44.724Z,1755111344.724 [DataOverHttps](INFO): SBD MOMSN=25847703 2025-08-13T18:55:46.145Z,1755111346.145 [Default:CheckIn:Read_Iridium] Stopped 2025-08-13T18:55:46.145Z,1755111346.145 [Default:CheckIn:C.Wait] Running Loop=1 2025-08-13T18:55:46.145Z,1755111346.145 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-08-13T18:56:02.727Z,1755111362.727 [NAL9602](INFO): Not Powering down - fast GPS 2025-08-13T19:00:23.861Z,1755111623.861 [Sonardyne_Nano](INFO): Battery below minimum, enabling charging 2025-08-13T19:00:46.897Z,1755111646.897 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-08-13T19:00:46.897Z,1755111646.897 [Default:CheckIn:C.Wait] Stopped 2025-08-13T19:00:46.897Z,1755111646.897 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-08-13T19:00:46.897Z,1755111646.897 [Default:CheckIn:D] Running Loop=1 2025-08-13T19:00:47.306Z,1755111647.306 [Default:CheckIn:D] Stopped 2025-08-13T19:00:47.306Z,1755111647.306 [Default:CheckIn:E] Running Loop=1 2025-08-13T19:00:47.698Z,1755111647.698 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 78.443416 min 2025-08-13T19:00:47.699Z,1755111647.699 [Default:CheckIn:E] Stopped 2025-08-13T19:00:47.699Z,1755111647.699 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-08-13T19:00:47.699Z,1755111647.699 [Default:CheckIn] Stopped 2025-08-13T19:00:47.699Z,1755111647.699 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-08-13T19:00:47.699Z,1755111647.699 [Default:CheckIn](INFO): Running loop #14 2025-08-13T19:00:47.699Z,1755111647.699 [Default:CheckIn] Running Loop=14 2025-08-13T19:00:47.699Z,1755111647.699 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-08-13T19:00:47.699Z,1755111647.699 [Default:CheckIn:Read_GPS] Running Loop=1 2025-08-13T19:00:49.718Z,1755111649.718 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190049.00,A,3648.17524,N,12147.27959,W,0.039,107.35,130825,,,A*73 2025-08-13T19:00:49.720Z,1755111649.720 [NAL9602](INFO): GPS fix at 20250813T190049: (36.802921, -121.787993) 2025-08-13T19:00:49.739Z,1755111649.739 [Default:CheckIn:Read_GPS] Stopped 2025-08-13T19:00:49.739Z,1755111649.739 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-08-13T19:00:57.242Z,1755111657.242 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20250813T180759/Courier0030.lzma 2025-08-13T19:00:58.244Z,1755111658.244 [DataOverHttps](INFO): Moved sent file to Logs/20250813T180759/Courier0030.lzma.bak 2025-08-13T19:00:58.244Z,1755111658.244 [DataOverHttps](INFO): SBD MOMSN=25847715 2025-08-13T19:01:14.199Z,1755111674.199 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20250813T180759/Express0031.lzma 2025-08-13T19:01:15.200Z,1755111675.200 [DataOverHttps](INFO): Moved sent file to Logs/20250813T180759/Express0031.lzma.bak 2025-08-13T19:01:15.200Z,1755111675.200 [DataOverHttps](INFO): SBD MOMSN=25847718 2025-08-13T19:01:16.391Z,1755111676.391 [Default:CheckIn:Read_Iridium] Stopped 2025-08-13T19:01:16.391Z,1755111676.391 [Default:CheckIn:C.Wait] Running Loop=1 2025-08-13T19:01:16.391Z,1755111676.391 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-08-13T19:01:40.208Z,1755111700.208 [NAL9602](INFO): SBD MO Status=2, MOMSN=64414, MT Status=2, MTMSN=0 2025-08-13T19:01:40.209Z,1755111700.209 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-08-13T19:02:29.538Z,1755111749.538 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-08-13T19:02:41.658Z,1755111761.658 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-08-13T19:02:53.383Z,1755111773.383 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-08-13T19:03:05.094Z,1755111785.094 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-08-13T19:03:15.204Z,1755111795.204 [NAL9602](INFO): SBD MO Status=2, MOMSN=64414, MT Status=2, MTMSN=0 2025-08-13T19:03:15.205Z,1755111795.205 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-08-13T19:03:16.405Z,1755111796.405 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-08-13T19:03:27.718Z,1755111807.718 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-08-13T19:03:39.850Z,1755111819.850 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-08-13T19:03:51.555Z,1755111831.555 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2025-08-13T19:05:52.408Z,1755111952.408 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2025-08-13T19:06:17.063Z,1755111977.063 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-08-13T19:06:17.063Z,1755111977.063 [Default:CheckIn:C.Wait] Stopped 2025-08-13T19:06:17.063Z,1755111977.063 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-08-13T19:06:17.063Z,1755111977.063 [Default:CheckIn:D] Running Loop=1 2025-08-13T19:06:17.471Z,1755111977.471 [Default:CheckIn:D] Stopped 2025-08-13T19:06:17.472Z,1755111977.472 [Default:CheckIn:E] Running Loop=1 2025-08-13T19:06:17.886Z,1755111977.886 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 83.946175 min 2025-08-13T19:06:17.886Z,1755111977.886 [Default:CheckIn:E] Stopped 2025-08-13T19:06:17.886Z,1755111977.886 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-08-13T19:06:17.886Z,1755111977.886 [Default:CheckIn] Stopped 2025-08-13T19:06:17.886Z,1755111977.886 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-08-13T19:06:17.887Z,1755111977.887 [Default:CheckIn](INFO): Running loop #15 2025-08-13T19:06:17.887Z,1755111977.887 [Default:CheckIn] Running Loop=15 2025-08-13T19:06:17.887Z,1755111977.887 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-08-13T19:06:17.887Z,1755111977.887 [Default:CheckIn:Read_GPS] Running Loop=1 2025-08-13T19:06:19.893Z,1755111979.893 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190619.00,A,3648.16979,N,12147.28264,W,3.149,150.61,130825,,,A*79 2025-08-13T19:06:19.895Z,1755111979.895 [NAL9602](INFO): GPS fix at 20250813T190619: (36.802830, -121.788044) 2025-08-13T19:06:19.951Z,1755111979.951 [Default:CheckIn:Read_GPS] Stopped 2025-08-13T19:06:19.951Z,1755111979.951 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-08-13T19:06:26.841Z,1755111986.841 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-13T19:06:30.834Z,1755111990.834 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20250813T180759/Courier0033.lzma 2025-08-13T19:06:31.836Z,1755111991.836 [DataOverHttps](INFO): Moved sent file to Logs/20250813T180759/Courier0033.lzma.bak 2025-08-13T19:06:31.836Z,1755111991.836 [DataOverHttps](INFO): SBD MOMSN=25847730 2025-08-13T19:06:39.799Z,1755111999.799 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-13T19:06:48.142Z,1755112008.142 [DataOverHttps](INFO): Sending 255 bytes from file Logs/20250813T180759/Express0034.lzma 2025-08-13T19:06:49.144Z,1755112009.144 [DataOverHttps](INFO): Moved sent file to Logs/20250813T180759/Express0034.lzma.bak 2025-08-13T19:06:49.144Z,1755112009.144 [DataOverHttps](INFO): SBD MOMSN=25847733 2025-08-13T19:06:50.341Z,1755112010.341 [Default:CheckIn:Read_Iridium] Stopped 2025-08-13T19:06:50.341Z,1755112010.341 [Default:CheckIn:C.Wait] Running Loop=1 2025-08-13T19:06:50.341Z,1755112010.341 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-08-13T19:06:52.398Z,1755112012.398 [NAL9602](INFO): Not Powering down - fast GPS 2025-08-13T19:06:52.727Z,1755112012.727 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-13T19:07:06.062Z,1755112026.062 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-13T19:07:14.954Z,1755112034.954 [BPC1](ERROR): BPC1A: No match for serial number 1717 in BPC1A's battery stick inventory (sticks 1-31 in onboard configuration file). 2025-08-13T19:07:19.390Z,1755112039.390 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-13T19:07:31.509Z,1755112051.509 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-13T19:07:44.437Z,1755112064.437 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-13T19:07:57.365Z,1755112077.365 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-13T19:08:10.297Z,1755112090.297 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-13T19:08:23.267Z,1755112103.267 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-13T19:08:35.768Z,1755112115.768 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-13T19:10:24.045Z,1755112224.045 [Sonardyne_Nano](INFO): Battery below minimum, enabling charging 2025-08-13T19:11:50.913Z,1755112310.913 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-08-13T19:11:50.913Z,1755112310.913 [Default:CheckIn:C.Wait] Stopped 2025-08-13T19:11:50.913Z,1755112310.913 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-08-13T19:11:50.913Z,1755112310.913 [Default:CheckIn:D] Running Loop=1 2025-08-13T19:11:51.326Z,1755112311.326 [Default:CheckIn:D] Stopped 2025-08-13T19:11:51.326Z,1755112311.326 [Default:CheckIn:E] Running Loop=1 2025-08-13T19:11:51.730Z,1755112311.730 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 89.510409 min 2025-08-13T19:11:51.730Z,1755112311.730 [Default:CheckIn:E] Stopped 2025-08-13T19:11:51.730Z,1755112311.730 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-08-13T19:11:51.730Z,1755112311.730 [Default:CheckIn] Stopped 2025-08-13T19:11:51.730Z,1755112311.730 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-08-13T19:11:51.730Z,1755112311.730 [Default:CheckIn](INFO): Running loop #16 2025-08-13T19:11:51.730Z,1755112311.730 [Default:CheckIn] Running Loop=16 2025-08-13T19:11:51.731Z,1755112311.731 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-08-13T19:11:51.731Z,1755112311.731 [Default:CheckIn:Read_GPS] Running Loop=1 2025-08-13T19:11:53.741Z,1755112313.741 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191153.00,A,3648.16470,N,12147.27895,W,0.233,163.60,130825,,,A*72 2025-08-13T19:11:53.743Z,1755112313.743 [NAL9602](INFO): GPS fix at 20250813T191153: (36.802745, -121.787982) 2025-08-13T19:11:53.754Z,1755112313.754 [Default:CheckIn:Read_GPS] Stopped 2025-08-13T19:11:53.754Z,1755112313.754 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-08-13T19:12:00.886Z,1755112320.886 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20250813T180759/Courier0036.lzma 2025-08-13T19:12:01.888Z,1755112321.888 [DataOverHttps](INFO): Moved sent file to Logs/20250813T180759/Courier0036.lzma.bak 2025-08-13T19:12:01.888Z,1755112321.888 [DataOverHttps](INFO): SBD MOMSN=25847759 2025-08-13T19:12:18.046Z,1755112338.046 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20250813T180759/Express0037.lzma 2025-08-13T19:12:19.049Z,1755112339.049 [DataOverHttps](INFO): Moved sent file to Logs/20250813T180759/Express0037.lzma.bak 2025-08-13T19:12:19.049Z,1755112339.049 [DataOverHttps](INFO): SBD MOMSN=25847762 2025-08-13T19:12:20.415Z,1755112340.415 [Default:CheckIn:Read_Iridium] Stopped 2025-08-13T19:12:20.415Z,1755112340.415 [Default:CheckIn:C.Wait] Running Loop=1 2025-08-13T19:12:20.415Z,1755112340.415 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-08-13T19:12:24.227Z,1755112344.227 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2025-08-13T19:12:24.302Z,1755112344.302 [NAL9602](ERROR): received: +CSQ:0 OK414, 2, 0, 0, 0 OK 2025-08-13T19:14:25.737Z,1755112465.737 [BPC1](ERROR): BPC1B: No match for serial number 1717 in BPC1B's battery stick inventory (sticks 32-62 in onboard configuration file). 2025-08-13T19:15:54.718Z,1755112554.718 [DataOverHttps](INFO): Exceeded connection timeout, disconnecting. 2025-08-13T19:15:59.494Z,1755112559.494 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-13T19:16:11.962Z,1755112571.962 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-13T19:16:25.295Z,1755112585.295 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-13T19:16:38.222Z,1755112598.222 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-13T19:16:51.958Z,1755112611.958 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-08-13T19:16:55.207Z,1755112615.207 [CommandExec](IMPORTANT): got command quit 2025-08-13T19:16:56.210Z,1755112616.210 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread. 2025-08-13T19:16:56.210Z,1755112616.210 [CommandExec](INFO): Uninitializing the command executive. 2025-08-13T19:16:56.210Z,1755112616.210 [CommandExec](INFO): Uninitializing the command scheduler. 2025-08-13T19:16:56.211Z,1755112616.211 [CommandExec ThreadHandler](INFO): Thread cancelled. 2025-08-13T19:16:56.370Z,1755112616.370 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2025-08-13T19:16:56.370Z,1755112616.370 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2025-08-13T19:16:56.370Z,1755112616.370 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2025-08-13T19:16:56.371Z,1755112616.371 [NavChartDb](INFO): Join timeout helper Thread ID is 7450 2025-08-13T19:16:56.411Z,1755112616.411 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2025-08-13T19:16:56.690Z,1755112616.690 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2025-08-13T19:16:56.690Z,1755112616.690 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2025-08-13T19:16:56.698Z,1755112616.698 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2025-08-13T19:16:56.698Z,1755112616.698 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2025-08-13T19:16:56.699Z,1755112616.699 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 7451 2025-08-13T19:16:57.103Z,1755112617.103 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2025-08-13T19:16:57.103Z,1755112617.103 [WetLabsBB2FL](INFO): Powering down 2025-08-13T19:16:57.103Z,1755112617.103 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2025-08-13T19:16:57.106Z,1755112617.106 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2025-08-13T19:16:57.106Z,1755112617.106 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2025-08-13T19:16:57.106Z,1755112617.106 [CTD_Seabird](INFO): Join timeout helper Thread ID is 7452 2025-08-13T19:16:57.502Z,1755112617.502 [CTD_Seabird](INFO): Powering down 2025-08-13T19:16:57.514Z,1755112617.514 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread. 2025-08-13T19:16:57.514Z,1755112617.514 [CTD_Seabird](INFO): Powering down 2025-08-13T19:16:57.526Z,1755112617.526 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2025-08-13T19:16:57.532Z,1755112617.532 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2025-08-13T19:16:57.532Z,1755112617.532 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2025-08-13T19:16:57.532Z,1755112617.532 [Radio_Surface](INFO): Join timeout helper Thread ID is 7453 2025-08-13T19:16:57.770Z,1755112617.770 [Radio_Surface](INFO): Powering down 2025-08-13T19:16:57.771Z,1755112617.771 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2025-08-13T19:16:57.771Z,1755112617.771 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2025-08-13T19:16:57.794Z,1755112617.794 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler 2025-08-13T19:16:57.794Z,1755112617.794 [Onboard ThreadHandler](INFO): Thread cancelled. 2025-08-13T19:16:57.794Z,1755112617.794 [Onboard](INFO): Join timeout helper Thread ID is 7454 2025-08-13T19:17:01.450Z,1755112621.450 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread. 2025-08-13T19:17:01.450Z,1755112621.450 [Onboard ThreadHandler](INFO): Thread cancelled. 2025-08-13T19:17:01.455Z,1755112621.455 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2025-08-13T19:17:01.455Z,1755112621.455 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2025-08-13T19:17:01.456Z,1755112621.456 [DataOverHttps](INFO): Join timeout helper Thread ID is 7455 2025-08-13T19:17:01.486Z,1755112621.486 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2025-08-13T19:17:01.487Z,1755112621.487 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2025-08-13T19:17:01.507Z,1755112621.507 [ComponentRegistry](INFO): Shutting down DAT ThreadHandler 2025-08-13T19:17:01.507Z,1755112621.507 [DAT ThreadHandler](INFO): Thread cancelled. 2025-08-13T19:17:01.507Z,1755112621.507 [DAT](INFO): Join timeout helper Thread ID is 7456 2025-08-13T19:17:01.754Z,1755112621.754 [DAT](INFO): Powering down 2025-08-13T19:17:01.823Z,1755112621.823 [DAT ThreadHandler](INFO): Uninitializing protected caller thread. 2025-08-13T19:17:01.823Z,1755112621.823 [DAT](INFO): Powering down 2025-08-13T19:17:01.824Z,1755112621.824 [DAT ThreadHandler](INFO): Thread cancelled. 2025-08-13T19:17:01.831Z,1755112621.831 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2025-08-13T19:17:01.831Z,1755112621.831 [logger ThreadHandler](INFO): Thread cancelled. 2025-08-13T19:17:01.831Z,1755112621.831 [logger](INFO): Join timeout helper Thread ID is 7457 2025-08-13T19:17:01.838Z,1755112621.838 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2025-08-13T19:17:01.838Z,1755112621.838 [logger ThreadHandler](INFO): Thread cancelled. 2025-08-13T19:17:01.851Z,1755112621.851 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2025-08-13T19:17:01.851Z,1755112621.851 [CommandLine ThreadHandler](INFO): Thread cancelled. 2025-08-13T19:17:01.851Z,1755112621.851 [CommandLine](INFO): Join timeout helper Thread ID is 7458 2025-08-13T19:17:01.862Z,1755112621.862 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2025-08-13T19:17:01.863Z,1755112621.863 [CommandLine ThreadHandler](INFO): Thread cancelled. 2025-08-13T19:17:01.871Z,1755112621.871 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler 2025-08-13T19:17:01.871Z,1755112621.871 [CommandExec ThreadHandler](INFO): Thread cancelled. 2025-08-13T19:17:01.871Z,1755112621.871 [CommandExec](INFO): Join timeout helper Thread ID is 7459 2025-08-13T19:17:01.872Z,1755112621.872 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2025-08-13T19:17:01.872Z,1755112621.872 [controlThread ThreadHandler](INFO): Thread cancelled. 2025-08-13T19:17:01.873Z,1755112621.873 [controlThread](INFO): Join timeout helper Thread ID is 7460 2025-08-13T19:17:02.042Z,1755112622.042 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2025-08-13T19:17:02.042Z,1755112622.042 [controlThread](DEBUG): Uninitializing ControlThread 2025-08-13T19:17:02.043Z,1755112622.043 [AHRS_M2](INFO): Powering down 2025-08-13T19:17:02.122Z,1755112622.122 [NAL9602](INFO): Powering down 2025-08-13T19:17:02.124Z,1755112622.124 [Sonardyne_Nano](INFO): Powering down 2025-08-13T19:17:02.330Z,1755112622.330 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2025-08-13T19:17:02.331Z,1755112622.331 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2025-08-13T19:17:02.332Z,1755112622.332 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2025-08-13T19:17:02.332Z,1755112622.332 [MissionManager](INFO): Uninitializing Mission Default 2025-08-13T19:17:02.332Z,1755112622.332 [Default] Stopped 2025-08-13T19:17:02.332Z,1755112622.332 [Default](DEBUG): Aggregate::uninitialize Default 2025-08-13T19:17:02.332Z,1755112622.332 [Default:B.GoToSurface] Stopped 2025-08-13T19:17:02.332Z,1755112622.332 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2025-08-13T19:17:02.332Z,1755112622.332 [Default:CheckIn] Stopped 2025-08-13T19:17:02.333Z,1755112622.333 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-08-13T19:17:02.333Z,1755112622.333 [Default:CheckIn:C.Wait] Stopped 2025-08-13T19:17:02.333Z,1755112622.333 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-08-13T19:17:02.336Z,1755112622.336 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2025-08-13T19:17:02.336Z,1755112622.336 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2025-08-13T19:17:02.336Z,1755112622.336 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2025-08-13T19:17:02.337Z,1755112622.337 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2025-08-13T19:17:02.337Z,1755112622.337 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2025-08-13T19:17:02.337Z,1755112622.337 [BuoyancyServo](INFO): Powering down 2025-08-13T19:17:02.350Z,1755112622.350 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2025-08-13T19:17:02.350Z,1755112622.350 [ElevatorServo](INFO): Powering down 2025-08-13T19:17:02.351Z,1755112622.351 [MassServo](DEBUG): Uninitialize Mass Servo. 2025-08-13T19:17:02.351Z,1755112622.351 [MassServo](INFO): Powering down 2025-08-13T19:17:02.352Z,1755112622.352 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2025-08-13T19:17:02.352Z,1755112622.352 [RudderServo](INFO): Powering down 2025-08-13T19:17:02.353Z,1755112622.353 [ThrusterHE](DEBUG): Uninitialize Thruster Servo. 2025-08-13T19:17:02.353Z,1755112622.353 [ThrusterHE](INFO): Powering down 2025-08-13T19:17:02.354Z,1755112622.354 [SBIT](DEBUG): Uninitialize SBIT Component. 2025-08-13T19:17:02.354Z,1755112622.354 [IBIT](DEBUG): Uninitialize IBIT Component. 2025-08-13T19:17:02.355Z,1755112622.355 [CBIT](DEBUG): Uninitialize CBIT Component. 2025-08-13T19:17:02.355Z,1755112622.355 [CBIT](DEBUG): Powering off loads. 2025-08-13T19:17:02.366Z,1755112622.366 [CBIT](DEBUG): Disabling WDT. 2025-08-13T19:17:02.378Z,1755112622.378 [GFScanner](DEBUG): Uninitialize GFScanner component. 2025-08-13T19:17:02.378Z,1755112622.378 [GFScanner](DEBUG): Opening all GF detection circuits. 2025-08-13T19:17:02.379Z,1755112622.379 [controlThread ThreadHandler](INFO): Thread cancelled. 2025-08-13T19:17:02.437Z,1755112622.437 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2025-08-13T19:17:02.440Z,1755112622.440 [Onboard ThreadHandler](INFO): Thread cancelled. 2025-08-13T19:17:02.446Z,1755112622.446 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2025-08-13T19:17:02.453Z,1755112622.453 [DAT ThreadHandler](INFO): Thread cancelled. 2025-08-13T19:17:02.526Z,1755112622.526 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2025-08-13T19:17:02.530Z,1755112622.530 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2025-08-13T19:17:02.554Z,1755112622.554 [GFScanner](DEBUG): Uninitialize GFScanner component. 2025-08-13T19:17:02.554Z,1755112622.554 [GFScanner](DEBUG): Opening all GF detection circuits. 2025-08-13T19:17:02.575Z,1755112622.575 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2025-08-13T19:17:02.689Z,1755112622.689 [logger ThreadHandler](INFO): Thread cancelled.