2023-01-27T19:59:34.437Z,1674849574.437 [DataOverHttps](INFO): Received command: restart logs 2023-01-27T19:59:34.470Z,1674849574.470 [CommandExec](IMPORTANT): got command restart logs 2023-01-27T20:00:47.405Z,1674849647.405 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-01-27T20:00:47.405Z,1674849647.405 [Default:CheckIn:C.Wait] Stopped 2023-01-27T20:00:47.405Z,1674849647.405 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-01-27T20:00:47.406Z,1674849647.406 [Default:CheckIn:D] Running Loop=1 2023-01-27T20:00:47.815Z,1674849647.815 [Default:CheckIn:D] Stopped 2023-01-27T20:00:47.815Z,1674849647.815 [Default:CheckIn:E] Running Loop=1 2023-01-27T20:00:48.216Z,1674849648.216 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 5.938990 min 2023-01-27T20:00:48.216Z,1674849648.216 [Default:CheckIn:E] Stopped 2023-01-27T20:00:48.216Z,1674849648.216 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-01-27T20:00:48.216Z,1674849648.216 [Default:CheckIn] Stopped 2023-01-27T20:00:48.217Z,1674849648.217 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-01-27T20:00:48.217Z,1674849648.217 [Default:CheckIn](INFO): Running loop #2 2023-01-27T20:00:48.217Z,1674849648.217 [Default:CheckIn] Running Loop=2 2023-01-27T20:00:48.217Z,1674849648.217 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-01-27T20:00:48.217Z,1674849648.217 [Default:CheckIn:Read_GPS] Running Loop=1 2023-01-27T20:00:50.228Z,1674849650.228 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200049.00,A,3648.35938,N,12147.31693,W,0.194,76.55,270123,,,D*4C 2023-01-27T20:00:50.239Z,1674849650.239 [NAL9602](INFO): GPS fix at 20230127T200049: (36.805990, -121.788616) 2023-01-27T20:00:50.251Z,1674849650.251 [Default:CheckIn:Read_GPS] Stopped 2023-01-27T20:00:50.251Z,1674849650.251 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-01-27T20:00:57.997Z,1674849657.997 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20230127T191449/Courier0024.lzma 2023-01-27T20:00:58.999Z,1674849658.999 [DataOverHttps](INFO): Moved sent file to Logs/20230127T191449/Courier0024.lzma.bak 2023-01-27T20:00:58.999Z,1674849658.999 [DataOverHttps](INFO): SBD MOMSN=17414171 2023-01-27T20:01:15.161Z,1674849675.161 [DataOverHttps](INFO): Sending 266 bytes from file Logs/20230127T195934/Courier0000.lzma 2023-01-27T20:01:16.163Z,1674849676.163 [DataOverHttps](INFO): Moved sent file to Logs/20230127T195934/Courier0000.lzma.bak 2023-01-27T20:01:16.163Z,1674849676.163 [DataOverHttps](INFO): SBD MOMSN=17414173 2023-01-27T20:01:22.954Z,1674849682.954 [NAL9602](INFO): SBD MO Status=0, MOMSN=11268, MT Status=0, MTMSN=0 2023-01-27T20:01:22.954Z,1674849682.954 [NAL9602](INFO): No messages in MT queue 2023-01-27T20:01:31.877Z,1674849691.877 [DataOverHttps](INFO): Sending 105 bytes from file Logs/20230127T191449/Express0025.lzma 2023-01-27T20:01:32.879Z,1674849692.879 [DataOverHttps](INFO): Moved sent file to Logs/20230127T191449/Express0025.lzma.bak 2023-01-27T20:01:32.879Z,1674849692.879 [DataOverHttps](INFO): SBD MOMSN=17414177 2023-01-27T20:01:51.693Z,1674849711.693 [DataOverHttps](INFO): Sending 382 bytes from file Logs/20230127T195934/Express0001.lzma 2023-01-27T20:01:52.695Z,1674849712.695 [DataOverHttps](INFO): Moved sent file to Logs/20230127T195934/Express0001.lzma.bak 2023-01-27T20:01:52.695Z,1674849712.695 [DataOverHttps](INFO): SBD MOMSN=17414180 2023-01-27T20:01:53.743Z,1674849713.743 [NAL9602](INFO): Not Powering down - fast GPS 2023-01-27T20:02:10.329Z,1674849730.329 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20230127T195934/Express0004.lzma 2023-01-27T20:02:11.331Z,1674849731.331 [DataOverHttps](INFO): Moved sent file to Logs/20230127T195934/Express0004.lzma.bak 2023-01-27T20:02:11.331Z,1674849731.331 [DataOverHttps](INFO): SBD MOMSN=17414184 2023-01-27T20:02:12.745Z,1674849732.745 [Default:CheckIn:Read_Iridium] Stopped 2023-01-27T20:02:12.745Z,1674849732.745 [Default:CheckIn:C.Wait] Running Loop=1 2023-01-27T20:02:12.745Z,1674849732.745 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-01-27T20:03:00.018Z,1674849780.018 [CBIT](FAULT): Could not open coulomb counter log file 2023-01-27T20:04:59.183Z,1674849899.183 [Power24vConverter](INFO): Powering down. 2023-01-27T20:07:13.378Z,1674850033.378 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-01-27T20:07:13.378Z,1674850033.378 [Default:CheckIn:C.Wait] Stopped 2023-01-27T20:07:13.378Z,1674850033.378 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-01-27T20:07:13.378Z,1674850033.378 [Default:CheckIn:D] Running Loop=1 2023-01-27T20:07:13.789Z,1674850033.789 [Default:CheckIn:D] Stopped 2023-01-27T20:07:13.789Z,1674850033.789 [Default:CheckIn:E] Running Loop=1 2023-01-27T20:07:14.181Z,1674850034.181 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 12.371886 min 2023-01-27T20:07:14.181Z,1674850034.181 [Default:CheckIn:E] Stopped 2023-01-27T20:07:14.181Z,1674850034.181 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-01-27T20:07:14.181Z,1674850034.181 [Default:CheckIn] Stopped 2023-01-27T20:07:14.181Z,1674850034.181 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-01-27T20:07:14.182Z,1674850034.182 [Default:CheckIn](INFO): Running loop #3 2023-01-27T20:07:14.182Z,1674850034.182 [Default:CheckIn] Running Loop=3 2023-01-27T20:07:14.182Z,1674850034.182 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-01-27T20:07:14.182Z,1674850034.182 [Default:CheckIn:Read_GPS] Running Loop=1 2023-01-27T20:07:16.197Z,1674850036.197 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200715.00,A,3648.15991,N,12147.23884,W,2.430,195.33,270123,,,D*7D 2023-01-27T20:07:16.200Z,1674850036.200 [NAL9602](INFO): GPS fix at 20230127T200715: (36.802665, -121.787314) 2023-01-27T20:07:16.212Z,1674850036.212 [Default:CheckIn:Read_GPS] Stopped 2023-01-27T20:07:16.212Z,1674850036.212 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-01-27T20:07:23.529Z,1674850043.529 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230127T195934/Courier0006.lzma 2023-01-27T20:07:24.531Z,1674850044.531 [DataOverHttps](INFO): Moved sent file to Logs/20230127T195934/Courier0006.lzma.bak 2023-01-27T20:07:24.531Z,1674850044.531 [DataOverHttps](INFO): SBD MOMSN=17414187 2023-01-27T20:07:33.164Z,1674850053.164 [NAL9602](INFO): SBD MO Status=0, MOMSN=11269, MT Status=0, MTMSN=0 2023-01-27T20:07:33.164Z,1674850053.164 [NAL9602](INFO): No messages in MT queue 2023-01-27T20:07:40.401Z,1674850060.401 [DataOverHttps](INFO): Sending 192 bytes from file Logs/20230127T195934/Express0007.lzma 2023-01-27T20:07:41.403Z,1674850061.403 [DataOverHttps](INFO): Moved sent file to Logs/20230127T195934/Express0007.lzma.bak 2023-01-27T20:07:41.403Z,1674850061.403 [DataOverHttps](INFO): SBD MOMSN=17414190 2023-01-27T20:07:42.872Z,1674850062.872 [Default:CheckIn:Read_Iridium] Stopped 2023-01-27T20:07:42.872Z,1674850062.872 [Default:CheckIn:C.Wait] Running Loop=1 2023-01-27T20:07:42.872Z,1674850062.872 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-01-27T20:08:03.913Z,1674850083.913 [NAL9602](INFO): Not Powering down - fast GPS 2023-01-27T20:12:43.493Z,1674850363.493 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-01-27T20:12:43.494Z,1674850363.494 [Default:CheckIn:C.Wait] Stopped 2023-01-27T20:12:43.494Z,1674850363.494 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-01-27T20:12:43.494Z,1674850363.494 [Default:CheckIn:D] Running Loop=1 2023-01-27T20:12:43.899Z,1674850363.899 [Default:CheckIn:D] Stopped 2023-01-27T20:12:43.899Z,1674850363.899 [Default:CheckIn:E] Running Loop=1 2023-01-27T20:12:44.314Z,1674850364.314 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 17.873722 min 2023-01-27T20:12:44.314Z,1674850364.314 [Default:CheckIn:E] Stopped 2023-01-27T20:12:44.314Z,1674850364.314 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-01-27T20:12:44.314Z,1674850364.314 [Default:CheckIn] Stopped 2023-01-27T20:12:44.314Z,1674850364.314 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-01-27T20:12:44.315Z,1674850364.315 [Default:CheckIn](INFO): Running loop #4 2023-01-27T20:12:44.315Z,1674850364.315 [Default:CheckIn] Running Loop=4 2023-01-27T20:12:44.315Z,1674850364.315 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-01-27T20:12:44.315Z,1674850364.315 [Default:CheckIn:Read_GPS] Running Loop=1 2023-01-27T20:12:46.316Z,1674850366.316 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,201245.00,A,3648.17543,N,12147.28028,W,0.000,227.75,270123,,,D*75 2023-01-27T20:12:46.319Z,1674850366.319 [NAL9602](INFO): GPS fix at 20230127T201245: (36.802924, -121.788005) 2023-01-27T20:12:46.331Z,1674850366.331 [Default:CheckIn:Read_GPS] Stopped 2023-01-27T20:12:46.331Z,1674850366.331 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-01-27T20:12:54.005Z,1674850374.005 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230127T195934/Courier0009.lzma 2023-01-27T20:12:55.007Z,1674850375.007 [DataOverHttps](INFO): Moved sent file to Logs/20230127T195934/Courier0009.lzma.bak 2023-01-27T20:12:55.007Z,1674850375.007 [DataOverHttps](INFO): SBD MOMSN=17414195 2023-01-27T20:13:00.119Z,1674850380.119 [CBIT](FAULT): Could not open coulomb counter log file 2023-01-27T20:13:11.126Z,1674850391.126 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20230127T195934/Express0010.lzma 2023-01-27T20:13:12.127Z,1674850392.127 [DataOverHttps](INFO): Moved sent file to Logs/20230127T195934/Express0010.lzma.bak 2023-01-27T20:13:12.127Z,1674850392.127 [DataOverHttps](INFO): SBD MOMSN=17414198 2023-01-27T20:13:13.808Z,1674850393.808 [Default:CheckIn:Read_Iridium] Stopped 2023-01-27T20:13:13.808Z,1674850393.808 [Default:CheckIn:C.Wait] Running Loop=1 2023-01-27T20:13:13.808Z,1674850393.808 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-01-27T20:15:07.314Z,1674850507.314 [BPC1](ERROR): BPC1B: No match for serial number 1717 in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file). 2023-01-27T20:16:15.995Z,1674850575.995 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2023-01-27T20:16:16.006Z,1674850576.006 [BPC1](INFO): Received data from all battery sticks. 2023-01-27T20:17:48.507Z,1674850668.507 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2023-01-27T20:18:14.375Z,1674850694.375 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-01-27T20:18:14.375Z,1674850694.375 [Default:CheckIn:C.Wait] Stopped 2023-01-27T20:18:14.375Z,1674850694.375 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-01-27T20:18:14.376Z,1674850694.376 [Default:CheckIn:D] Running Loop=1 2023-01-27T20:18:14.787Z,1674850694.787 [Default:CheckIn:D] Stopped 2023-01-27T20:18:14.788Z,1674850694.788 [Default:CheckIn:E] Running Loop=1 2023-01-27T20:18:15.314Z,1674850695.314 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 23.388529 min 2023-01-27T20:18:15.314Z,1674850695.314 [Default:CheckIn:E] Stopped 2023-01-27T20:18:15.315Z,1674850695.315 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-01-27T20:18:15.316Z,1674850695.316 [Default:CheckIn] Stopped 2023-01-27T20:18:15.316Z,1674850695.316 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-01-27T20:18:15.317Z,1674850695.317 [Default:CheckIn](INFO): Running loop #5 2023-01-27T20:18:15.317Z,1674850695.317 [Default:CheckIn] Running Loop=5 2023-01-27T20:18:15.317Z,1674850695.317 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-01-27T20:18:15.317Z,1674850695.317 [Default:CheckIn:Read_GPS] Running Loop=1 2023-01-27T20:18:17.196Z,1674850697.196 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,201816.00,A,3648.16872,N,12147.28400,W,0.428,133.64,270123,,,D*71 2023-01-27T20:18:17.199Z,1674850697.199 [NAL9602](INFO): GPS fix at 20230127T201816: (36.802812, -121.788067) 2023-01-27T20:18:17.211Z,1674850697.211 [Default:CheckIn:Read_GPS] Stopped 2023-01-27T20:18:17.211Z,1674850697.211 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-01-27T20:18:24.841Z,1674850704.841 [DataOverHttps](INFO): Sending 202 bytes from file Logs/20230127T195934/Courier0012.lzma 2023-01-27T20:18:25.843Z,1674850705.843 [DataOverHttps](INFO): Moved sent file to Logs/20230127T195934/Courier0012.lzma.bak 2023-01-27T20:18:25.843Z,1674850705.843 [DataOverHttps](INFO): SBD MOMSN=17414201 2023-01-27T20:18:41.649Z,1674850721.649 [DataOverHttps](INFO): Sending 264 bytes from file Logs/20230127T195934/Express0013.lzma 2023-01-27T20:18:42.651Z,1674850722.651 [DataOverHttps](INFO): Moved sent file to Logs/20230127T195934/Express0013.lzma.bak 2023-01-27T20:18:42.651Z,1674850722.651 [DataOverHttps](INFO): SBD MOMSN=17414205 2023-01-27T20:18:44.277Z,1674850724.277 [Default:CheckIn:Read_Iridium] Stopped 2023-01-27T20:18:44.278Z,1674850724.278 [Default:CheckIn:C.Wait] Running Loop=1 2023-01-27T20:18:44.278Z,1674850724.278 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-01-27T20:18:49.511Z,1674850729.511 [NAL9602](INFO): Not Powering down - fast GPS 2023-01-27T20:23:00.467Z,1674850980.467 [CBIT](FAULT): Could not open coulomb counter log file 2023-01-27T20:23:44.885Z,1674851024.885 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-01-27T20:23:44.885Z,1674851024.885 [Default:CheckIn:C.Wait] Stopped 2023-01-27T20:23:44.886Z,1674851024.886 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-01-27T20:23:44.886Z,1674851024.886 [Default:CheckIn:D] Running Loop=1 2023-01-27T20:23:45.298Z,1674851025.298 [Default:CheckIn:D] Stopped 2023-01-27T20:23:45.298Z,1674851025.298 [Default:CheckIn:E] Running Loop=1 2023-01-27T20:23:45.711Z,1674851025.711 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 28.897034 min 2023-01-27T20:23:45.711Z,1674851025.711 [Default:CheckIn:E] Stopped 2023-01-27T20:23:45.711Z,1674851025.711 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-01-27T20:23:45.711Z,1674851025.711 [Default:CheckIn] Stopped 2023-01-27T20:23:45.712Z,1674851025.712 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-01-27T20:23:45.712Z,1674851025.712 [Default:CheckIn](INFO): Running loop #6 2023-01-27T20:23:45.712Z,1674851025.712 [Default:CheckIn] Running Loop=6 2023-01-27T20:23:45.712Z,1674851025.712 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-01-27T20:23:45.712Z,1674851025.712 [Default:CheckIn:Read_GPS] Running Loop=1 2023-01-27T20:23:47.724Z,1674851027.724 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,202347.00,A,3648.16645,N,12147.28496,W,0.739,117.13,270123,,,D*7D 2023-01-27T20:23:47.727Z,1674851027.727 [NAL9602](INFO): GPS fix at 20230127T202347: (36.802774, -121.788083) 2023-01-27T20:23:47.747Z,1674851027.747 [Default:CheckIn:Read_GPS] Stopped 2023-01-27T20:23:47.747Z,1674851027.747 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-01-27T20:23:57.185Z,1674851037.185 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230127T195934/Courier0015.lzma 2023-01-27T20:23:58.187Z,1674851038.187 [DataOverHttps](INFO): Moved sent file to Logs/20230127T195934/Courier0015.lzma.bak 2023-01-27T20:23:58.187Z,1674851038.187 [DataOverHttps](INFO): SBD MOMSN=17414210 2023-01-27T20:24:13.945Z,1674851053.945 [DataOverHttps](INFO): Sending 169 bytes from file Logs/20230127T195934/Express0016.lzma 2023-01-27T20:24:14.947Z,1674851054.947 [DataOverHttps](INFO): Moved sent file to Logs/20230127T195934/Express0016.lzma.bak 2023-01-27T20:24:14.947Z,1674851054.947 [DataOverHttps](INFO): SBD MOMSN=17414213 2023-01-27T20:24:16.630Z,1674851056.630 [Default:CheckIn:Read_Iridium] Stopped 2023-01-27T20:24:16.630Z,1674851056.630 [Default:CheckIn:C.Wait] Running Loop=1 2023-01-27T20:24:16.630Z,1674851056.630 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-01-27T20:24:18.219Z,1674851058.219 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2023-01-27T20:24:18.297Z,1674851058.297 [NAL9602](ERROR): received: +CSQ:0 OK269, 0, 0, 0, 0 OK 2023-01-27T20:28:50.514Z,1674851330.514 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2023-01-27T20:29:17.202Z,1674851357.202 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-01-27T20:29:17.202Z,1674851357.202 [Default:CheckIn:C.Wait] Stopped 2023-01-27T20:29:17.202Z,1674851357.202 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-01-27T20:29:17.202Z,1674851357.202 [Default:CheckIn:D] Running Loop=1 2023-01-27T20:29:17.592Z,1674851357.592 [Default:CheckIn:D] Stopped 2023-01-27T20:29:17.593Z,1674851357.593 [Default:CheckIn:E] Running Loop=1 2023-01-27T20:29:18.002Z,1674851358.002 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 34.435278 min 2023-01-27T20:29:18.002Z,1674851358.002 [Default:CheckIn:E] Stopped 2023-01-27T20:29:18.002Z,1674851358.002 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-01-27T20:29:18.002Z,1674851358.002 [Default:CheckIn] Stopped 2023-01-27T20:29:18.002Z,1674851358.002 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-01-27T20:29:18.002Z,1674851358.002 [Default:CheckIn](INFO): Running loop #7 2023-01-27T20:29:18.002Z,1674851358.002 [Default:CheckIn] Running Loop=7 2023-01-27T20:29:18.002Z,1674851358.002 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-01-27T20:29:18.003Z,1674851358.003 [Default:CheckIn:Read_GPS] Running Loop=1 2023-01-27T20:29:20.009Z,1674851360.009 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,202919.00,A,3648.16660,N,12147.28177,W,0.194,117.13,270123,,,D*70 2023-01-27T20:29:20.011Z,1674851360.011 [NAL9602](INFO): GPS fix at 20230127T202919: (36.802777, -121.788029) 2023-01-27T20:29:20.024Z,1674851360.024 [Default:CheckIn:Read_GPS] Stopped 2023-01-27T20:29:20.024Z,1674851360.024 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-01-27T20:29:27.437Z,1674851367.437 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230127T195934/Courier0018.lzma 2023-01-27T20:29:28.439Z,1674851368.439 [DataOverHttps](INFO): Moved sent file to Logs/20230127T195934/Courier0018.lzma.bak 2023-01-27T20:29:28.439Z,1674851368.439 [DataOverHttps](INFO): SBD MOMSN=17414217 2023-01-27T20:29:44.257Z,1674851384.257 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20230127T195934/Express0019.lzma 2023-01-27T20:29:45.650Z,1674851385.650 [DataOverHttps](INFO): Moved sent file to Logs/20230127T195934/Express0019.lzma.bak 2023-01-27T20:29:45.651Z,1674851385.651 [DataOverHttps](INFO): SBD MOMSN=17414220 2023-01-27T20:29:47.096Z,1674851387.096 [Default:CheckIn:Read_Iridium] Stopped 2023-01-27T20:29:47.096Z,1674851387.096 [Default:CheckIn:C.Wait] Running Loop=1 2023-01-27T20:29:47.096Z,1674851387.096 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-01-27T20:29:52.385Z,1674851392.385 [NAL9602](INFO): Not Powering down - fast GPS 2023-01-27T20:33:00.708Z,1674851580.708 [CBIT](FAULT): Could not open coulomb counter log file 2023-01-27T20:34:47.750Z,1674851687.750 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-01-27T20:34:47.750Z,1674851687.750 [Default:CheckIn:C.Wait] Stopped 2023-01-27T20:34:47.750Z,1674851687.750 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-01-27T20:34:47.750Z,1674851687.750 [Default:CheckIn:D] Running Loop=1 2023-01-27T20:34:48.146Z,1674851688.146 [Default:CheckIn:D] Stopped 2023-01-27T20:34:48.146Z,1674851688.146 [Default:CheckIn:E] Running Loop=1 2023-01-27T20:34:48.550Z,1674851688.550 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 39.944503 min 2023-01-27T20:34:48.550Z,1674851688.550 [Default:CheckIn:E] Stopped 2023-01-27T20:34:48.550Z,1674851688.550 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-01-27T20:34:48.550Z,1674851688.550 [Default:CheckIn] Stopped 2023-01-27T20:34:48.551Z,1674851688.551 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-01-27T20:34:48.551Z,1674851688.551 [Default:CheckIn](INFO): Running loop #8 2023-01-27T20:34:48.551Z,1674851688.551 [Default:CheckIn] Running Loop=8 2023-01-27T20:34:48.551Z,1674851688.551 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-01-27T20:34:48.551Z,1674851688.551 [Default:CheckIn:Read_GPS] Running Loop=1 2023-01-27T20:34:50.557Z,1674851690.557 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,203449.00,A,3648.16811,N,12147.28043,W,0.175,216.86,270123,,,D*76 2023-01-27T20:34:50.559Z,1674851690.559 [NAL9602](INFO): GPS fix at 20230127T203449: (36.802802, -121.788007) 2023-01-27T20:34:50.571Z,1674851690.571 [Default:CheckIn:Read_GPS] Stopped 2023-01-27T20:34:50.571Z,1674851690.571 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-01-27T20:34:58.165Z,1674851698.165 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230127T195934/Courier0021.lzma 2023-01-27T20:34:59.167Z,1674851699.167 [DataOverHttps](INFO): Moved sent file to Logs/20230127T195934/Courier0021.lzma.bak 2023-01-27T20:34:59.167Z,1674851699.167 [DataOverHttps](INFO): SBD MOMSN=17414224 2023-01-27T20:35:15.153Z,1674851715.153 [DataOverHttps](INFO): Sending 171 bytes from file Logs/20230127T195934/Express0022.lzma 2023-01-27T20:35:16.155Z,1674851716.155 [DataOverHttps](INFO): Moved sent file to Logs/20230127T195934/Express0022.lzma.bak 2023-01-27T20:35:16.155Z,1674851716.155 [DataOverHttps](INFO): SBD MOMSN=17414227 2023-01-27T20:35:17.635Z,1674851717.635 [Default:CheckIn:Read_Iridium] Stopped 2023-01-27T20:35:17.635Z,1674851717.635 [Default:CheckIn:C.Wait] Running Loop=1 2023-01-27T20:35:17.635Z,1674851717.635 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-01-27T20:35:21.259Z,1674851721.259 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2023-01-27T20:35:21.333Z,1674851721.333 [NAL9602](ERROR): received: +CSQ:0 OK269, 0, 0, 0, 0 OK 2023-01-27T20:39:52.375Z,1674851992.375 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2023-01-27T20:40:18.236Z,1674852018.236 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-01-27T20:40:18.236Z,1674852018.236 [Default:CheckIn:C.Wait] Stopped 2023-01-27T20:40:18.236Z,1674852018.236 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-01-27T20:40:18.237Z,1674852018.237 [Default:CheckIn:D] Running Loop=1 2023-01-27T20:40:18.646Z,1674852018.646 [Default:CheckIn:D] Stopped 2023-01-27T20:40:18.646Z,1674852018.646 [Default:CheckIn:E] Running Loop=1 2023-01-27T20:40:19.045Z,1674852019.045 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 45.452840 min 2023-01-27T20:40:19.045Z,1674852019.045 [Default:CheckIn:E] Stopped 2023-01-27T20:40:19.045Z,1674852019.045 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-01-27T20:40:19.045Z,1674852019.045 [Default:CheckIn] Stopped 2023-01-27T20:40:19.045Z,1674852019.045 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-01-27T20:40:19.046Z,1674852019.046 [Default:CheckIn](INFO): Running loop #9 2023-01-27T20:40:19.046Z,1674852019.046 [Default:CheckIn] Running Loop=9 2023-01-27T20:40:19.046Z,1674852019.046 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-01-27T20:40:19.046Z,1674852019.046 [Default:CheckIn:Read_GPS] Running Loop=1 2023-01-27T20:40:21.067Z,1674852021.067 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,204020.00,A,3648.16558,N,12147.28532,W,0.350,216.86,270123,,,A*79 2023-01-27T20:40:21.069Z,1674852021.069 [NAL9602](INFO): GPS fix at 20230127T204020: (36.802760, -121.788089) 2023-01-27T20:40:21.081Z,1674852021.081 [Default:CheckIn:Read_GPS] Stopped 2023-01-27T20:40:21.081Z,1674852021.081 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-01-27T20:40:28.049Z,1674852028.049 [DataOverHttps](INFO): Sending 70 bytes from file Logs/20230127T195934/Courier0024.lzma 2023-01-27T20:40:29.051Z,1674852029.051 [DataOverHttps](INFO): Moved sent file to Logs/20230127T195934/Courier0024.lzma.bak 2023-01-27T20:40:29.051Z,1674852029.051 [DataOverHttps](INFO): SBD MOMSN=17414231 2023-01-27T20:40:44.717Z,1674852044.717 [DataOverHttps](INFO): Sending 205 bytes from file Logs/20230127T195934/Express0025.lzma 2023-01-27T20:40:45.719Z,1674852045.719 [DataOverHttps](INFO): Moved sent file to Logs/20230127T195934/Express0025.lzma.bak 2023-01-27T20:40:45.719Z,1674852045.719 [DataOverHttps](INFO): SBD MOMSN=17414234 2023-01-27T20:40:47.338Z,1674852047.338 [Default:CheckIn:Read_Iridium] Stopped 2023-01-27T20:40:47.338Z,1674852047.338 [Default:CheckIn:C.Wait] Running Loop=1 2023-01-27T20:40:47.338Z,1674852047.338 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-01-27T20:40:53.373Z,1674852053.373 [NAL9602](INFO): Not Powering down - fast GPS 2023-01-27T20:43:01.061Z,1674852181.061 [CBIT](FAULT): Could not open coulomb counter log file 2023-01-27T20:45:47.966Z,1674852347.966 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-01-27T20:45:47.966Z,1674852347.966 [Default:CheckIn:C.Wait] Stopped 2023-01-27T20:45:47.966Z,1674852347.966 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-01-27T20:45:47.966Z,1674852347.966 [Default:CheckIn:D] Running Loop=1 2023-01-27T20:45:48.361Z,1674852348.361 [Default:CheckIn:D] Stopped 2023-01-27T20:45:48.361Z,1674852348.361 [Default:CheckIn:E] Running Loop=1 2023-01-27T20:45:48.762Z,1674852348.762 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 50.948096 min 2023-01-27T20:45:48.762Z,1674852348.762 [Default:CheckIn:E] Stopped 2023-01-27T20:45:48.762Z,1674852348.762 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-01-27T20:45:48.762Z,1674852348.762 [Default:CheckIn] Stopped 2023-01-27T20:45:48.762Z,1674852348.762 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-01-27T20:45:48.763Z,1674852348.763 [Default:CheckIn](INFO): Running loop #10 2023-01-27T20:45:48.763Z,1674852348.763 [Default:CheckIn] Running Loop=10 2023-01-27T20:45:48.763Z,1674852348.763 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-01-27T20:45:48.763Z,1674852348.763 [Default:CheckIn:Read_GPS] Running Loop=1 2023-01-27T20:46:21.483Z,1674852381.483 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2023-01-27T20:46:21.565Z,1674852381.565 [NAL9602](ERROR): received: +CSQ:0 OK269, 0, 0, 0, 0 OK 2023-01-27T20:47:25.314Z,1674852445.314 [CommandExec](IMPORTANT): got command quit 2023-01-27T20:47:26.317Z,1674852446.317 [Supervisor](INFO): Stop Mission called by Supervisor::terminate 2023-01-27T20:47:26.318Z,1674852446.318 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread. 2023-01-27T20:47:26.318Z,1674852446.318 [CommandExec](INFO): Uninitializing the command executive. 2023-01-27T20:47:26.318Z,1674852446.318 [CommandExec](INFO): Uninitializing the command scheduler. 2023-01-27T20:47:26.318Z,1674852446.318 [CommandExec ThreadHandler](INFO): Thread cancelled. 2023-01-27T20:47:26.385Z,1674852446.385 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2023-01-27T20:47:26.385Z,1674852446.385 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2023-01-27T20:47:26.387Z,1674852446.387 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2023-01-27T20:47:26.387Z,1674852446.387 [NavChartDb](INFO): Join timeout helper Thread ID is 3294 2023-01-27T20:47:26.689Z,1674852446.689 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2023-01-27T20:47:26.690Z,1674852446.690 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2023-01-27T20:47:26.701Z,1674852446.701 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2023-01-27T20:47:26.701Z,1674852446.701 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2023-01-27T20:47:26.702Z,1674852446.702 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 3295 2023-01-27T20:47:27.053Z,1674852447.053 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2023-01-27T20:47:27.054Z,1674852447.054 [WetLabsBB2FL](INFO): Powering down 2023-01-27T20:47:27.054Z,1674852447.054 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2023-01-27T20:47:27.065Z,1674852447.065 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2023-01-27T20:47:27.065Z,1674852447.065 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2023-01-27T20:47:27.066Z,1674852447.066 [CTD_Seabird](INFO): Join timeout helper Thread ID is 3296 2023-01-27T20:47:27.342Z,1674852447.342 [CTD_Seabird](INFO): Powering down 2023-01-27T20:47:27.353Z,1674852447.353 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread. 2023-01-27T20:47:27.354Z,1674852447.354 [CTD_Seabird](INFO): Powering down 2023-01-27T20:47:27.365Z,1674852447.365 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2023-01-27T20:47:27.369Z,1674852447.369 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2023-01-27T20:47:27.370Z,1674852447.370 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2023-01-27T20:47:27.370Z,1674852447.370 [Radio_Surface](INFO): Join timeout helper Thread ID is 3297 2023-01-27T20:47:27.482Z,1674852447.482 [Radio_Surface](INFO): Powering down 2023-01-27T20:47:27.482Z,1674852447.482 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2023-01-27T20:47:27.483Z,1674852447.483 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2023-01-27T20:47:27.498Z,1674852447.498 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler 2023-01-27T20:47:27.498Z,1674852447.498 [Onboard ThreadHandler](INFO): Thread cancelled. 2023-01-27T20:47:27.498Z,1674852447.498 [Onboard](INFO): Join timeout helper Thread ID is 3298 2023-01-27T20:47:27.578Z,1674852447.578 [DataOverHttps](INFO): Radio surface powered OFF, will not connect. 2023-01-27T20:47:31.361Z,1674852451.361 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread. 2023-01-27T20:47:31.362Z,1674852451.362 [Onboard ThreadHandler](INFO): Thread cancelled. 2023-01-27T20:47:31.366Z,1674852451.366 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2023-01-27T20:47:31.366Z,1674852451.366 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2023-01-27T20:47:31.367Z,1674852451.367 [DataOverHttps](INFO): Join timeout helper Thread ID is 3299 2023-01-27T20:47:31.601Z,1674852451.601 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2023-01-27T20:47:31.602Z,1674852451.602 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2023-01-27T20:47:31.614Z,1674852451.614 [ComponentRegistry](INFO): Shutting down BackseatComponent ThreadHandler 2023-01-27T20:47:31.614Z,1674852451.614 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2023-01-27T20:47:31.615Z,1674852451.615 [BackseatComponent](INFO): Join timeout helper Thread ID is 3300 2023-01-27T20:47:31.770Z,1674852451.770 [BackseatComponent ThreadHandler](INFO): Uninitializing protected caller thread. 2023-01-27T20:47:31.770Z,1674852451.770 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2023-01-27T20:47:31.790Z,1674852451.790 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2023-01-27T20:47:31.790Z,1674852451.790 [logger ThreadHandler](INFO): Thread cancelled. 2023-01-27T20:47:31.791Z,1674852451.791 [logger](INFO): Join timeout helper Thread ID is 3301 2023-01-27T20:47:31.793Z,1674852451.793 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2023-01-27T20:47:31.794Z,1674852451.794 [logger ThreadHandler](INFO): Thread cancelled. 2023-01-27T20:47:31.810Z,1674852451.810 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2023-01-27T20:47:31.810Z,1674852451.810 [CommandLine ThreadHandler](INFO): Thread cancelled. 2023-01-27T20:47:31.811Z,1674852451.811 [CommandLine](INFO): Join timeout helper Thread ID is 3302 2023-01-27T20:47:31.897Z,1674852451.897 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2023-01-27T20:47:31.898Z,1674852451.898 [CommandLine ThreadHandler](INFO): Thread cancelled. 2023-01-27T20:47:31.910Z,1674852451.910 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler 2023-01-27T20:47:31.910Z,1674852451.910 [CommandExec ThreadHandler](INFO): Thread cancelled. 2023-01-27T20:47:31.911Z,1674852451.911 [CommandExec](INFO): Join timeout helper Thread ID is 3303 2023-01-27T20:47:31.912Z,1674852451.912 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2023-01-27T20:47:31.912Z,1674852451.912 [controlThread ThreadHandler](INFO): Thread cancelled. 2023-01-27T20:47:31.912Z,1674852451.912 [controlThread](INFO): Join timeout helper Thread ID is 3304 2023-01-27T20:47:32.157Z,1674852452.157 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2023-01-27T20:47:32.158Z,1674852452.158 [controlThread](DEBUG): Uninitializing ControlThread 2023-01-27T20:47:32.158Z,1674852452.158 [AHRS_M2](INFO): Powering down 2023-01-27T20:47:32.230Z,1674852452.230 [NAL9602](INFO): Powering down 2023-01-27T20:47:32.232Z,1674852452.232 [Waterlinked](INFO): Powering down 2023-01-27T20:47:32.233Z,1674852452.233 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2023-01-27T20:47:32.234Z,1674852452.234 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2023-01-27T20:47:32.235Z,1674852452.235 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2023-01-27T20:47:32.235Z,1674852452.235 [MissionManager](INFO): Uninitializing Mission Default 2023-01-27T20:47:32.235Z,1674852452.235 [Default] Stopped 2023-01-27T20:47:32.235Z,1674852452.235 [Default](DEBUG): Aggregate::uninitialize Default 2023-01-27T20:47:32.235Z,1674852452.235 [Default:B.GoToSurface] Stopped 2023-01-27T20:47:32.235Z,1674852452.235 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2023-01-27T20:47:32.235Z,1674852452.235 [Default:CheckIn] Stopped 2023-01-27T20:47:32.236Z,1674852452.236 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-01-27T20:47:32.236Z,1674852452.236 [Default:CheckIn:Read_GPS] Stopped 2023-01-27T20:47:32.238Z,1674852452.238 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2023-01-27T20:47:32.239Z,1674852452.239 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2023-01-27T20:47:32.239Z,1674852452.239 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2023-01-27T20:47:32.239Z,1674852452.239 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2023-01-27T20:47:32.240Z,1674852452.240 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2023-01-27T20:47:32.240Z,1674852452.240 [BuoyancyServo](INFO): Powering down 2023-01-27T20:47:32.253Z,1674852452.253 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2023-01-27T20:47:32.254Z,1674852452.254 [ElevatorServo](INFO): Powering down 2023-01-27T20:47:32.254Z,1674852452.254 [MassServo](DEBUG): Uninitialize Mass Servo. 2023-01-27T20:47:32.255Z,1674852452.255 [MassServo](INFO): Powering down 2023-01-27T20:47:32.255Z,1674852452.255 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2023-01-27T20:47:32.255Z,1674852452.255 [RudderServo](INFO): Powering down 2023-01-27T20:47:32.256Z,1674852452.256 [ThrusterHE](DEBUG): Uninitialize Thruster Servo. 2023-01-27T20:47:32.256Z,1674852452.256 [ThrusterHE](INFO): Powering down 2023-01-27T20:47:32.257Z,1674852452.257 [SBIT](DEBUG): Uninitialize SBIT Component. 2023-01-27T20:47:32.258Z,1674852452.258 [IBIT](DEBUG): Uninitialize IBIT Component. 2023-01-27T20:47:32.258Z,1674852452.258 [CBIT](DEBUG): Uninitialize CBIT Component. 2023-01-27T20:47:32.258Z,1674852452.258 [CBIT](DEBUG): Powering off loads. 2023-01-27T20:47:32.269Z,1674852452.269 [CBIT](DEBUG): Disabling WDT. 2023-01-27T20:47:32.281Z,1674852452.281 [CBIT](DEBUG): Opening all GF detection circuits. 2023-01-27T20:47:32.282Z,1674852452.282 [controlThread ThreadHandler](INFO): Thread cancelled. 2023-01-27T20:47:32.312Z,1674852452.312 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2023-01-27T20:47:32.316Z,1674852452.316 [Onboard ThreadHandler](INFO): Thread cancelled. 2023-01-27T20:47:32.323Z,1674852452.323 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2023-01-27T20:47:32.368Z,1674852452.368 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2023-01-27T20:47:32.421Z,1674852452.421 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2023-01-27T20:47:32.424Z,1674852452.424 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2023-01-27T20:47:32.475Z,1674852452.475 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2023-01-27T20:47:32.522Z,1674852452.522 [logger ThreadHandler](INFO): Thread cancelled.