2022-11-10T21:01:29.747Z,1668114089.747 [CommandExec](IMPORTANT): got command restart logs 2022-11-10T21:03:12.359Z,1668114192.359 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-11-10T21:03:12.359Z,1668114192.359 [Default:CheckIn:C.Wait] Stopped 2022-11-10T21:03:12.359Z,1668114192.359 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-11-10T21:03:12.359Z,1668114192.359 [Default:CheckIn:D] Running Loop=1 2022-11-10T21:03:12.779Z,1668114192.779 [Default:CheckIn:D] Stopped 2022-11-10T21:03:12.779Z,1668114192.779 [Default:CheckIn:E] Running Loop=1 2022-11-10T21:03:13.160Z,1668114193.160 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 46.969592 min 2022-11-10T21:03:13.161Z,1668114193.161 [Default:CheckIn:E] Stopped 2022-11-10T21:03:13.161Z,1668114193.161 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-11-10T21:03:13.161Z,1668114193.161 [Default:CheckIn] Stopped 2022-11-10T21:03:13.161Z,1668114193.161 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-11-10T21:03:13.161Z,1668114193.161 [Default:CheckIn](INFO): Running loop #8 2022-11-10T21:03:13.161Z,1668114193.161 [Default:CheckIn] Running Loop=8 2022-11-10T21:03:13.161Z,1668114193.161 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-11-10T21:03:13.161Z,1668114193.161 [Default:CheckIn:Read_GPS] Running Loop=1 2022-11-10T21:03:15.160Z,1668114195.160 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,210314.00,A,3647.54323,N,12151.39713,W,9.019,242.34,101122,,,A*76 2022-11-10T21:03:15.179Z,1668114195.179 [NAL9602](INFO): GPS fix at 20221110T210314: (36.792387, -121.856619) 2022-11-10T21:03:15.190Z,1668114195.190 [Default:CheckIn:Read_GPS] Stopped 2022-11-10T21:03:15.190Z,1668114195.190 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-11-10T21:03:24.802Z,1668114204.802 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-11-10T21:03:27.675Z,1668114207.675 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-11-10T21:03:39.799Z,1668114219.799 [NAL9602](INFO): SBD MO Status=2, MOMSN=37885, MT Status=2, MTMSN=0 2022-11-10T21:03:39.799Z,1668114219.799 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-11-10T21:03:43.836Z,1668114223.836 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-11-10T21:03:50.349Z,1668114230.349 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20221110T202315/Courier0021.lzma 2022-11-10T21:03:51.351Z,1668114231.351 [DataOverHttps](INFO): Moved sent file to Logs/20221110T202315/Courier0021.lzma.bak 2022-11-10T21:03:51.351Z,1668114231.351 [DataOverHttps](INFO): SBD MOMSN=17281298 2022-11-10T21:03:59.594Z,1668114239.594 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-11-10T21:04:02.834Z,1668114242.834 [NAL9602](INFO): SBD MO Status=1, MOMSN=37885, MT Status=0, MTMSN=0 2022-11-10T21:04:02.834Z,1668114242.834 [NAL9602](INFO): No messages in MT queue 2022-11-10T21:04:14.540Z,1668114254.540 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-11-10T21:04:25.803Z,1668114265.803 [DataOverHttps](INFO): Sending 269 bytes from file Logs/20221110T210129/Courier0000.lzma 2022-11-10T21:04:26.804Z,1668114266.804 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Courier0000.lzma.bak 2022-11-10T21:04:26.804Z,1668114266.804 [DataOverHttps](INFO): SBD MOMSN=17281300 2022-11-10T21:04:29.504Z,1668114269.504 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-11-10T21:04:33.548Z,1668114273.548 [NAL9602](INFO): Not Powering down - fast GPS 2022-11-10T21:04:44.452Z,1668114284.452 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-11-10T21:04:59.401Z,1668114299.401 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-11-10T21:05:14.349Z,1668114314.349 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-11-10T21:05:29.296Z,1668114329.296 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-11-10T21:05:33.737Z,1668114333.737 [DataOverHttps](INFO): Sending 166 bytes from file Logs/20221110T202315/Express0022.lzma 2022-11-10T21:05:34.739Z,1668114334.739 [DataOverHttps](INFO): Moved sent file to Logs/20221110T202315/Express0022.lzma.bak 2022-11-10T21:05:34.740Z,1668114334.740 [DataOverHttps](INFO): SBD MOMSN=17281304 2022-11-10T21:05:43.840Z,1668114343.840 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2022-11-10T21:05:50.830Z,1668114350.830 [DataOverHttps](INFO): Sending 395 bytes from file Logs/20221110T210129/Express0001.lzma 2022-11-10T21:05:51.831Z,1668114351.831 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Express0001.lzma.bak 2022-11-10T21:05:51.831Z,1668114351.831 [DataOverHttps](INFO): SBD MOMSN=17281307 2022-11-10T21:05:52.737Z,1668114352.737 [BPC1](INFO): Calculating totals. Valid battery stick count: 48. Valid reserve battery stick count: 5. 2022-11-10T21:05:52.740Z,1668114352.740 [BPC1](INFO): Received data from all battery sticks. 2022-11-10T21:06:07.589Z,1668114367.589 [DataOverHttps](INFO): Sending 52 bytes from file Logs/20221110T210129/Express0002.lzma 2022-11-10T21:06:08.591Z,1668114368.591 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Express0002.lzma.bak 2022-11-10T21:06:08.591Z,1668114368.591 [DataOverHttps](INFO): SBD MOMSN=17281311 2022-11-10T21:06:09.731Z,1668114369.731 [Default:CheckIn:Read_Iridium] Stopped 2022-11-10T21:06:09.731Z,1668114369.731 [Default:CheckIn:C.Wait] Running Loop=1 2022-11-10T21:06:09.731Z,1668114369.731 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-11-10T21:09:12.558Z,1668114552.558 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-11-10T21:09:43.682Z,1668114583.682 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-11-10T21:10:14.806Z,1668114614.806 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-11-10T21:10:45.930Z,1668114645.930 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-11-10T21:11:10.284Z,1668114670.284 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-11-10T21:11:10.285Z,1668114670.285 [Default:CheckIn:C.Wait] Stopped 2022-11-10T21:11:10.285Z,1668114670.285 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-11-10T21:11:10.285Z,1668114670.285 [Default:CheckIn:D] Running Loop=1 2022-11-10T21:11:10.697Z,1668114670.697 [Default:CheckIn:D] Stopped 2022-11-10T21:11:10.697Z,1668114670.697 [Default:CheckIn:E] Running Loop=1 2022-11-10T21:11:11.091Z,1668114671.091 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 54.934896 min 2022-11-10T21:11:11.091Z,1668114671.091 [Default:CheckIn:E] Stopped 2022-11-10T21:11:11.091Z,1668114671.091 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-11-10T21:11:11.091Z,1668114671.091 [Default:CheckIn] Stopped 2022-11-10T21:11:11.091Z,1668114671.091 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-11-10T21:11:11.091Z,1668114671.091 [Default:CheckIn](INFO): Running loop #9 2022-11-10T21:11:11.091Z,1668114671.091 [Default:CheckIn] Running Loop=9 2022-11-10T21:11:11.092Z,1668114671.092 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-11-10T21:11:11.092Z,1668114671.092 [Default:CheckIn:Read_GPS] Running Loop=1 2022-11-10T21:11:13.109Z,1668114673.109 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,211112.00,A,3647.39813,N,12151.74038,W,12.382,84.14,101122,,,D*73 2022-11-10T21:11:13.111Z,1668114673.111 [NAL9602](INFO): GPS fix at 20221110T211112: (36.789969, -121.862340) 2022-11-10T21:11:13.122Z,1668114673.122 [Default:CheckIn:Read_GPS] Stopped 2022-11-10T21:11:13.122Z,1668114673.122 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-11-10T21:11:17.054Z,1668114677.054 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-11-10T21:11:20.066Z,1668114680.066 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.719498 2022-11-10T21:11:32.091Z,1668114692.091 [NAL9602](INFO): SBD MO Status=1, MOMSN=37886, MT Status=0, MTMSN=0 2022-11-10T21:11:32.091Z,1668114692.091 [NAL9602](INFO): No messages in MT queue 2022-11-10T21:11:48.296Z,1668114708.296 [NAL9602](INFO): SBD MO Status=1, MOMSN=37887, MT Status=0, MTMSN=0 2022-11-10T21:11:48.350Z,1668114708.350 [NAL9602](INFO): Sent 202 bytes from file Logs/20221110T210129/Courier0005.lzma 2022-11-10T21:11:48.350Z,1668114708.350 [NAL9602](INFO): Packets left to send: 0 2022-11-10T21:11:51.190Z,1668114711.190 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-11-10T21:11:58.436Z,1668114718.436 [NAL9602](INFO): SBD MO Status=1, MOMSN=37888, MT Status=0, MTMSN=0 2022-11-10T21:11:58.490Z,1668114718.490 [NAL9602](INFO): Sent 271 bytes from file Logs/20221110T210129/Express0007.lzma 2022-11-10T21:11:58.490Z,1668114718.490 [NAL9602](INFO): Packets left to send: 0 2022-11-10T21:12:04.572Z,1668114724.572 [NAL9602](INFO): SBD MO Status=0, MOMSN=37889, MT Status=0, MTMSN=0 2022-11-10T21:12:04.655Z,1668114724.655 [Default:CheckIn:Read_Iridium] Stopped 2022-11-10T21:12:04.655Z,1668114724.655 [Default:CheckIn:C.Wait] Running Loop=1 2022-11-10T21:12:04.655Z,1668114724.655 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-11-10T21:12:22.314Z,1668114742.314 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-11-10T21:12:35.274Z,1668114755.274 [NAL9602](INFO): Not Powering down - fast GPS 2022-11-10T21:12:53.438Z,1668114773.438 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-11-10T21:13:24.598Z,1668114804.598 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-11-10T21:13:55.722Z,1668114835.722 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-11-10T21:14:26.851Z,1668114866.851 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-11-10T21:14:57.974Z,1668114897.974 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-11-10T21:15:29.098Z,1668114929.098 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-11-10T21:16:00.230Z,1668114960.230 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-11-10T21:16:31.382Z,1668114991.382 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-11-10T21:17:02.514Z,1668115022.514 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-11-10T21:17:05.160Z,1668115025.160 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-11-10T21:17:05.160Z,1668115025.160 [Default:CheckIn:C.Wait] Stopped 2022-11-10T21:17:05.160Z,1668115025.160 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-11-10T21:17:05.161Z,1668115025.161 [Default:CheckIn:D] Running Loop=1 2022-11-10T21:17:05.567Z,1668115025.567 [Default:CheckIn:D] Stopped 2022-11-10T21:17:05.567Z,1668115025.567 [Default:CheckIn:E] Running Loop=1 2022-11-10T21:17:05.987Z,1668115025.987 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 60.849394 min 2022-11-10T21:17:05.987Z,1668115025.987 [Default:CheckIn:E] Stopped 2022-11-10T21:17:05.987Z,1668115025.987 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-11-10T21:17:05.987Z,1668115025.987 [Default:CheckIn] Stopped 2022-11-10T21:17:05.987Z,1668115025.987 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-11-10T21:17:05.987Z,1668115025.987 [Default:CheckIn](INFO): Running loop #10 2022-11-10T21:17:05.988Z,1668115025.988 [Default:CheckIn] Running Loop=10 2022-11-10T21:17:05.988Z,1668115025.988 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-11-10T21:17:05.988Z,1668115025.988 [Default:CheckIn:Read_GPS] Running Loop=1 2022-11-10T21:17:07.977Z,1668115027.977 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,211707.00,A,3647.47492,N,12149.08633,W,8.650,101.27,101122,,,D*7F 2022-11-10T21:17:07.979Z,1668115027.979 [NAL9602](INFO): GPS fix at 20221110T211707: (36.791249, -121.818106) 2022-11-10T21:17:07.989Z,1668115027.989 [Default:CheckIn:Read_GPS] Stopped 2022-11-10T21:17:07.989Z,1668115027.989 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-11-10T21:17:28.219Z,1668115048.219 [NAL9602](INFO): SBD MO Status=1, MOMSN=37890, MT Status=0, MTMSN=0 2022-11-10T21:17:28.274Z,1668115048.274 [NAL9602](INFO): Sent 73 bytes from file Logs/20221110T210129/Courier0009.lzma 2022-11-10T21:17:28.274Z,1668115048.274 [NAL9602](INFO): Packets left to send: 0 2022-11-10T21:17:33.638Z,1668115053.638 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-11-10T21:17:39.979Z,1668115059.979 [NAL9602](INFO): SBD MO Status=1, MOMSN=37891, MT Status=0, MTMSN=0 2022-11-10T21:17:40.030Z,1668115060.030 [NAL9602](INFO): Sent 165 bytes from file Logs/20221110T210129/Express0010.lzma 2022-11-10T21:17:40.030Z,1668115060.030 [NAL9602](INFO): Packets left to send: 0 2022-11-10T21:17:50.892Z,1668115070.892 [NAL9602](INFO): SBD MO Status=0, MOMSN=37892, MT Status=0, MTMSN=0 2022-11-10T21:17:50.978Z,1668115070.978 [Default:CheckIn:Read_Iridium] Stopped 2022-11-10T21:17:50.978Z,1668115070.978 [Default:CheckIn:C.Wait] Running Loop=1 2022-11-10T21:17:50.978Z,1668115070.978 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-11-10T21:18:04.762Z,1668115084.762 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-11-10T21:18:21.589Z,1668115101.589 [NAL9602](INFO): Not Powering down - fast GPS 2022-11-10T21:18:35.890Z,1668115115.890 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-11-10T21:19:07.014Z,1668115147.014 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-11-10T21:19:38.142Z,1668115178.142 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-11-10T21:20:09.266Z,1668115209.266 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-11-10T21:20:40.418Z,1668115240.418 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-11-10T21:21:11.542Z,1668115271.542 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-11-10T21:21:42.666Z,1668115302.666 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-11-10T21:22:13.806Z,1668115333.806 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-11-10T21:22:44.930Z,1668115364.930 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-11-10T21:22:51.480Z,1668115371.480 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-11-10T21:22:51.480Z,1668115371.480 [Default:CheckIn:C.Wait] Stopped 2022-11-10T21:22:51.480Z,1668115371.480 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-11-10T21:22:51.481Z,1668115371.481 [Default:CheckIn:D] Running Loop=1 2022-11-10T21:22:51.893Z,1668115371.893 [Default:CheckIn:D] Stopped 2022-11-10T21:22:51.893Z,1668115371.893 [Default:CheckIn:E] Running Loop=1 2022-11-10T21:22:52.289Z,1668115372.289 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 66.621493 min 2022-11-10T21:22:52.289Z,1668115372.289 [Default:CheckIn:E] Stopped 2022-11-10T21:22:52.289Z,1668115372.289 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-11-10T21:22:52.289Z,1668115372.289 [Default:CheckIn] Stopped 2022-11-10T21:22:52.289Z,1668115372.289 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-11-10T21:22:52.290Z,1668115372.290 [Default:CheckIn](INFO): Running loop #11 2022-11-10T21:22:52.290Z,1668115372.290 [Default:CheckIn] Running Loop=11 2022-11-10T21:22:52.290Z,1668115372.290 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-11-10T21:22:52.290Z,1668115372.290 [Default:CheckIn:Read_GPS] Running Loop=1 2022-11-10T21:22:54.296Z,1668115374.296 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,212253.00,A,3647.53552,N,12148.81427,W,5.035,2.39,101122,,,D*72 2022-11-10T21:22:54.298Z,1668115374.298 [NAL9602](INFO): GPS fix at 20221110T212253: (36.792259, -121.813571) 2022-11-10T21:22:54.308Z,1668115374.308 [Default:CheckIn:Read_GPS] Stopped 2022-11-10T21:22:54.308Z,1668115374.308 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-11-10T21:23:11.314Z,1668115391.314 [NAL9602](INFO): SBD MO Status=1, MOMSN=37893, MT Status=0, MTMSN=0 2022-11-10T21:23:11.364Z,1668115391.364 [NAL9602](INFO): Sent 73 bytes from file Logs/20221110T210129/Courier0012.lzma 2022-11-10T21:23:11.364Z,1668115391.364 [NAL9602](INFO): Packets left to send: 0 2022-11-10T21:23:16.054Z,1668115396.054 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-11-10T21:23:28.408Z,1668115408.408 [NAL9602](INFO): SBD MO Status=1, MOMSN=37894, MT Status=0, MTMSN=0 2022-11-10T21:23:28.458Z,1668115408.458 [NAL9602](INFO): Sent 165 bytes from file Logs/20221110T210129/Express0013.lzma 2022-11-10T21:23:28.458Z,1668115408.458 [NAL9602](INFO): Packets left to send: 0 2022-11-10T21:23:40.123Z,1668115420.123 [NAL9602](INFO): SBD MO Status=0, MOMSN=37895, MT Status=0, MTMSN=0 2022-11-10T21:23:40.207Z,1668115420.207 [Default:CheckIn:Read_Iridium] Stopped 2022-11-10T21:23:40.207Z,1668115420.207 [Default:CheckIn:C.Wait] Running Loop=1 2022-11-10T21:23:40.208Z,1668115420.208 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-11-10T21:23:58.482Z,1668115438.482 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003542 2022-11-10T21:24:10.831Z,1668115450.831 [NAL9602](INFO): Not Powering down - fast GPS 2022-11-10T21:28:40.831Z,1668115720.831 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-11-10T21:28:40.831Z,1668115720.831 [Default:CheckIn:C.Wait] Stopped 2022-11-10T21:28:40.831Z,1668115720.831 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-11-10T21:28:40.831Z,1668115720.831 [Default:CheckIn:D] Running Loop=1 2022-11-10T21:28:41.229Z,1668115721.229 [Default:CheckIn:D] Stopped 2022-11-10T21:28:41.229Z,1668115721.229 [Default:CheckIn:E] Running Loop=1 2022-11-10T21:28:41.631Z,1668115721.631 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 72.443758 min 2022-11-10T21:28:41.631Z,1668115721.631 [Default:CheckIn:E] Stopped 2022-11-10T21:28:41.631Z,1668115721.631 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-11-10T21:28:41.631Z,1668115721.631 [Default:CheckIn] Stopped 2022-11-10T21:28:41.631Z,1668115721.631 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-11-10T21:28:41.631Z,1668115721.631 [Default:CheckIn](INFO): Running loop #12 2022-11-10T21:28:41.632Z,1668115721.632 [Default:CheckIn] Running Loop=12 2022-11-10T21:28:41.632Z,1668115721.632 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-11-10T21:28:41.632Z,1668115721.632 [Default:CheckIn:Read_GPS] Running Loop=1 2022-11-10T21:28:43.651Z,1668115723.651 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,212842.00,A,3648.19003,N,12147.74193,W,4.840,42.68,101122,,,D*4C 2022-11-10T21:28:43.653Z,1668115723.653 [NAL9602](INFO): GPS fix at 20221110T212842: (36.803167, -121.795699) 2022-11-10T21:28:43.664Z,1668115723.664 [Default:CheckIn:Read_GPS] Stopped 2022-11-10T21:28:43.664Z,1668115723.664 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-11-10T21:28:51.365Z,1668115731.365 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20221110T210129/Courier0015.lzma 2022-11-10T21:28:52.368Z,1668115732.368 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Courier0015.lzma.bak 2022-11-10T21:28:52.368Z,1668115732.368 [DataOverHttps](INFO): SBD MOMSN=17281449 2022-11-10T21:29:04.316Z,1668115744.316 [NAL9602](INFO): SBD MO Status=0, MOMSN=37896, MT Status=0, MTMSN=0 2022-11-10T21:29:04.317Z,1668115744.317 [NAL9602](INFO): No messages in MT queue 2022-11-10T21:29:10.697Z,1668115750.697 [DataOverHttps](INFO): Sending 165 bytes from file Logs/20221110T210129/Express0016.lzma 2022-11-10T21:29:11.699Z,1668115751.699 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Express0016.lzma.bak 2022-11-10T21:29:11.699Z,1668115751.699 [DataOverHttps](INFO): SBD MOMSN=17281452 2022-11-10T21:29:12.807Z,1668115752.807 [Default:CheckIn:Read_Iridium] Stopped 2022-11-10T21:29:12.807Z,1668115752.807 [Default:CheckIn:C.Wait] Running Loop=1 2022-11-10T21:29:12.807Z,1668115752.807 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-11-10T21:29:35.018Z,1668115775.018 [NAL9602](INFO): Not Powering down - fast GPS 2022-11-10T21:34:13.404Z,1668116053.404 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-11-10T21:34:13.405Z,1668116053.405 [Default:CheckIn:C.Wait] Stopped 2022-11-10T21:34:13.405Z,1668116053.405 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-11-10T21:34:13.405Z,1668116053.405 [Default:CheckIn:D] Running Loop=1 2022-11-10T21:34:13.824Z,1668116053.824 [Default:CheckIn:D] Stopped 2022-11-10T21:34:13.824Z,1668116053.824 [Default:CheckIn:E] Running Loop=1 2022-11-10T21:34:14.206Z,1668116054.206 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 77.987012 min 2022-11-10T21:34:14.207Z,1668116054.207 [Default:CheckIn:E] Stopped 2022-11-10T21:34:14.207Z,1668116054.207 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-11-10T21:34:14.207Z,1668116054.207 [Default:CheckIn] Stopped 2022-11-10T21:34:14.207Z,1668116054.207 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-11-10T21:34:14.207Z,1668116054.207 [Default:CheckIn](INFO): Running loop #13 2022-11-10T21:34:14.207Z,1668116054.207 [Default:CheckIn] Running Loop=13 2022-11-10T21:34:14.207Z,1668116054.207 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-11-10T21:34:14.207Z,1668116054.207 [Default:CheckIn:Read_GPS] Running Loop=1 2022-11-10T21:34:16.224Z,1668116056.224 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,213415.00,A,3648.31867,N,12147.56625,W,3.829,79.36,101122,,,D*42 2022-11-10T21:34:16.227Z,1668116056.227 [NAL9602](INFO): GPS fix at 20221110T213415: (36.805311, -121.792771) 2022-11-10T21:34:16.237Z,1668116056.237 [Default:CheckIn:Read_GPS] Stopped 2022-11-10T21:34:16.237Z,1668116056.237 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-11-10T21:34:25.197Z,1668116065.197 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20221110T210129/Courier0018.lzma 2022-11-10T21:34:26.200Z,1668116066.200 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Courier0018.lzma.bak 2022-11-10T21:34:26.200Z,1668116066.200 [DataOverHttps](INFO): SBD MOMSN=17281507 2022-11-10T21:34:43.653Z,1668116083.653 [DataOverHttps](INFO): Sending 164 bytes from file Logs/20221110T210129/Express0019.lzma 2022-11-10T21:34:44.128Z,1668116084.128 [NAL9602](INFO): SBD MO Status=0, MOMSN=37897, MT Status=0, MTMSN=0 2022-11-10T21:34:44.128Z,1668116084.128 [NAL9602](INFO): No messages in MT queue 2022-11-10T21:34:44.656Z,1668116084.656 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Express0019.lzma.bak 2022-11-10T21:34:44.657Z,1668116084.657 [DataOverHttps](INFO): SBD MOMSN=17281510 2022-11-10T21:34:45.752Z,1668116085.752 [Default:CheckIn:Read_Iridium] Stopped 2022-11-10T21:34:45.752Z,1668116085.752 [Default:CheckIn:C.Wait] Running Loop=1 2022-11-10T21:34:45.752Z,1668116085.752 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-11-10T21:35:14.831Z,1668116114.831 [NAL9602](INFO): Not Powering down - fast GPS 2022-11-10T21:39:46.329Z,1668116386.329 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-11-10T21:39:46.329Z,1668116386.329 [Default:CheckIn:C.Wait] Stopped 2022-11-10T21:39:46.329Z,1668116386.329 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-11-10T21:39:46.329Z,1668116386.329 [Default:CheckIn:D] Running Loop=1 2022-11-10T21:39:46.742Z,1668116386.742 [Default:CheckIn:D] Stopped 2022-11-10T21:39:46.742Z,1668116386.742 [Default:CheckIn:E] Running Loop=1 2022-11-10T21:39:47.164Z,1668116387.164 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 83.535636 min 2022-11-10T21:39:47.164Z,1668116387.164 [Default:CheckIn:E] Stopped 2022-11-10T21:39:47.164Z,1668116387.164 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-11-10T21:39:47.164Z,1668116387.164 [Default:CheckIn] Stopped 2022-11-10T21:39:47.164Z,1668116387.164 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-11-10T21:39:47.164Z,1668116387.164 [Default:CheckIn](INFO): Running loop #14 2022-11-10T21:39:47.165Z,1668116387.165 [Default:CheckIn] Running Loop=14 2022-11-10T21:39:47.165Z,1668116387.165 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-11-10T21:39:47.165Z,1668116387.165 [Default:CheckIn:Read_GPS] Running Loop=1 2022-11-10T21:39:49.152Z,1668116389.152 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,213948.00,A,3648.51095,N,12147.15744,W,5.540,73.49,101122,,,D*43 2022-11-10T21:39:49.155Z,1668116389.155 [NAL9602](INFO): GPS fix at 20221110T213948: (36.808516, -121.785957) 2022-11-10T21:39:49.166Z,1668116389.166 [Default:CheckIn:Read_GPS] Stopped 2022-11-10T21:39:49.166Z,1668116389.166 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-11-10T21:39:56.093Z,1668116396.093 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20221110T210129/Courier0021.lzma 2022-11-10T21:39:57.095Z,1668116397.095 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Courier0021.lzma.bak 2022-11-10T21:39:57.095Z,1668116397.095 [DataOverHttps](INFO): SBD MOMSN=17281514 2022-11-10T21:40:00.868Z,1668116400.868 [NAL9602](INFO): SBD MO Status=0, MOMSN=37898, MT Status=0, MTMSN=0 2022-11-10T21:40:00.868Z,1668116400.868 [NAL9602](INFO): No messages in MT queue 2022-11-10T21:40:13.314Z,1668116413.314 [DataOverHttps](INFO): Sending 163 bytes from file Logs/20221110T210129/Express0022.lzma 2022-11-10T21:40:14.315Z,1668116414.315 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Express0022.lzma.bak 2022-11-10T21:40:14.316Z,1668116414.316 [DataOverHttps](INFO): SBD MOMSN=17281517 2022-11-10T21:40:15.417Z,1668116415.417 [Default:CheckIn:Read_Iridium] Stopped 2022-11-10T21:40:15.418Z,1668116415.418 [Default:CheckIn:C.Wait] Running Loop=1 2022-11-10T21:40:15.418Z,1668116415.418 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-11-10T21:40:31.567Z,1668116431.567 [NAL9602](INFO): Not Powering down - fast GPS 2022-11-10T21:45:15.991Z,1668116715.991 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-11-10T21:45:15.992Z,1668116715.992 [Default:CheckIn:C.Wait] Stopped 2022-11-10T21:45:15.992Z,1668116715.992 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-11-10T21:45:15.992Z,1668116715.992 [Default:CheckIn:D] Running Loop=1 2022-11-10T21:45:16.397Z,1668116716.397 [Default:CheckIn:D] Stopped 2022-11-10T21:45:16.397Z,1668116716.397 [Default:CheckIn:E] Running Loop=1 2022-11-10T21:45:16.817Z,1668116716.817 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 89.029899 min 2022-11-10T21:45:16.817Z,1668116716.817 [Default:CheckIn:E] Stopped 2022-11-10T21:45:16.817Z,1668116716.817 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-11-10T21:45:16.817Z,1668116716.817 [Default:CheckIn] Stopped 2022-11-10T21:45:16.817Z,1668116716.817 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-11-10T21:45:16.817Z,1668116716.817 [Default:CheckIn](INFO): Running loop #15 2022-11-10T21:45:16.818Z,1668116716.818 [Default:CheckIn] Running Loop=15 2022-11-10T21:45:16.818Z,1668116716.818 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-11-10T21:45:16.818Z,1668116716.818 [Default:CheckIn:Read_GPS] Running Loop=1 2022-11-10T21:45:18.819Z,1668116718.819 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,214518.00,A,3648.16524,N,12147.20630,W,1.069,247.74,101122,,,D*74 2022-11-10T21:45:18.822Z,1668116718.822 [NAL9602](INFO): GPS fix at 20221110T214518: (36.802754, -121.786772) 2022-11-10T21:45:18.852Z,1668116718.852 [Default:CheckIn:Read_GPS] Stopped 2022-11-10T21:45:18.852Z,1668116718.852 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-11-10T21:45:26.781Z,1668116726.781 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20221110T210129/Courier0024.lzma 2022-11-10T21:45:27.783Z,1668116727.783 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Courier0024.lzma.bak 2022-11-10T21:45:27.784Z,1668116727.784 [DataOverHttps](INFO): SBD MOMSN=17281568 2022-11-10T21:45:29.316Z,1668116729.316 [NAL9602](INFO): SBD MO Status=0, MOMSN=37899, MT Status=0, MTMSN=0 2022-11-10T21:45:29.317Z,1668116729.317 [NAL9602](INFO): No messages in MT queue 2022-11-10T21:45:43.493Z,1668116743.493 [DataOverHttps](INFO): Sending 164 bytes from file Logs/20221110T210129/Express0025.lzma 2022-11-10T21:45:44.495Z,1668116744.495 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Express0025.lzma.bak 2022-11-10T21:45:44.496Z,1668116744.496 [DataOverHttps](INFO): SBD MOMSN=17281571 2022-11-10T21:45:45.898Z,1668116745.898 [Default:CheckIn:Read_Iridium] Stopped 2022-11-10T21:45:45.898Z,1668116745.898 [Default:CheckIn:C.Wait] Running Loop=1 2022-11-10T21:45:45.898Z,1668116745.898 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-11-10T21:46:00.023Z,1668116760.023 [NAL9602](INFO): Not Powering down - fast GPS 2022-11-10T21:50:46.598Z,1668117046.598 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-11-10T21:50:46.598Z,1668117046.598 [Default:CheckIn:C.Wait] Stopped 2022-11-10T21:50:46.598Z,1668117046.598 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-11-10T21:50:46.598Z,1668117046.598 [Default:CheckIn:D] Running Loop=1 2022-11-10T21:50:46.988Z,1668117046.988 [Default:CheckIn:D] Stopped 2022-11-10T21:50:46.988Z,1668117046.988 [Default:CheckIn:E] Running Loop=1 2022-11-10T21:50:47.397Z,1668117047.397 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 94.539746 min 2022-11-10T21:50:47.397Z,1668117047.397 [Default:CheckIn:E] Stopped 2022-11-10T21:50:47.397Z,1668117047.397 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-11-10T21:50:47.397Z,1668117047.397 [Default:CheckIn] Stopped 2022-11-10T21:50:47.398Z,1668117047.398 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-11-10T21:50:47.398Z,1668117047.398 [Default:CheckIn](INFO): Running loop #16 2022-11-10T21:50:47.398Z,1668117047.398 [Default:CheckIn] Running Loop=16 2022-11-10T21:50:47.398Z,1668117047.398 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-11-10T21:50:47.398Z,1668117047.398 [Default:CheckIn:Read_GPS] Running Loop=1 2022-11-10T21:50:49.415Z,1668117049.415 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,215048.00,A,3648.16661,N,12147.21458,W,0.039,238.41,101122,,,D*70 2022-11-10T21:50:49.417Z,1668117049.417 [NAL9602](INFO): GPS fix at 20221110T215048: (36.802777, -121.786910) 2022-11-10T21:50:49.428Z,1668117049.428 [Default:CheckIn:Read_GPS] Stopped 2022-11-10T21:50:49.428Z,1668117049.428 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-11-10T21:50:55.733Z,1668117055.733 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20221110T210129/Courier0027.lzma 2022-11-10T21:50:56.739Z,1668117056.739 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Courier0027.lzma.bak 2022-11-10T21:50:56.740Z,1668117056.740 [DataOverHttps](INFO): SBD MOMSN=17281575 2022-11-10T21:51:08.392Z,1668117068.392 [NAL9602](INFO): SBD MO Status=0, MOMSN=37900, MT Status=0, MTMSN=0 2022-11-10T21:51:08.392Z,1668117068.392 [NAL9602](INFO): No messages in MT queue 2022-11-10T21:51:12.401Z,1668117072.401 [DataOverHttps](INFO): Sending 146 bytes from file Logs/20221110T210129/Express0028.lzma 2022-11-10T21:51:13.404Z,1668117073.404 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Express0028.lzma.bak 2022-11-10T21:51:13.404Z,1668117073.404 [DataOverHttps](INFO): SBD MOMSN=17281578 2022-11-10T21:51:14.481Z,1668117074.481 [Default:CheckIn:Read_Iridium] Stopped 2022-11-10T21:51:14.481Z,1668117074.481 [Default:CheckIn:C.Wait] Running Loop=1 2022-11-10T21:51:14.481Z,1668117074.481 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-11-10T21:51:39.094Z,1668117099.094 [NAL9602](INFO): Not Powering down - fast GPS 2022-11-10T21:56:15.048Z,1668117375.048 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-11-10T21:56:15.049Z,1668117375.049 [Default:CheckIn:C.Wait] Stopped 2022-11-10T21:56:15.049Z,1668117375.049 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-11-10T21:56:15.049Z,1668117375.049 [Default:CheckIn:D] Running Loop=1 2022-11-10T21:56:15.456Z,1668117375.456 [Default:CheckIn:D] Stopped 2022-11-10T21:56:15.456Z,1668117375.456 [Default:CheckIn:E] Running Loop=1 2022-11-10T21:56:15.857Z,1668117375.857 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 100.014209 min 2022-11-10T21:56:15.857Z,1668117375.857 [Default:CheckIn:E] Stopped 2022-11-10T21:56:15.857Z,1668117375.857 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-11-10T21:56:15.857Z,1668117375.857 [Default:CheckIn] Stopped 2022-11-10T21:56:15.857Z,1668117375.857 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-11-10T21:56:15.858Z,1668117375.858 [Default:CheckIn](INFO): Running loop #17 2022-11-10T21:56:15.858Z,1668117375.858 [Default:CheckIn] Running Loop=17 2022-11-10T21:56:15.858Z,1668117375.858 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-11-10T21:56:15.858Z,1668117375.858 [Default:CheckIn:Read_GPS] Running Loop=1 2022-11-10T21:56:17.864Z,1668117377.864 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,215617.00,A,3648.16975,N,12147.28233,W,0.233,240.64,101122,,,D*74 2022-11-10T21:56:17.866Z,1668117377.866 [NAL9602](INFO): GPS fix at 20221110T215617: (36.802829, -121.788039) 2022-11-10T21:56:17.877Z,1668117377.877 [Default:CheckIn:Read_GPS] Stopped 2022-11-10T21:56:17.877Z,1668117377.877 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-11-10T21:56:26.941Z,1668117386.941 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20221110T210129/Courier0030.lzma 2022-11-10T21:56:27.944Z,1668117387.944 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Courier0030.lzma.bak 2022-11-10T21:56:27.944Z,1668117387.944 [DataOverHttps](INFO): SBD MOMSN=17281636 2022-11-10T21:56:45.717Z,1668117405.717 [DataOverHttps](INFO): Sending 161 bytes from file Logs/20221110T210129/Express0031.lzma 2022-11-10T21:56:46.720Z,1668117406.720 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Express0031.lzma.bak 2022-11-10T21:56:46.720Z,1668117406.720 [DataOverHttps](INFO): SBD MOMSN=17281639 2022-11-10T21:56:47.838Z,1668117407.838 [Default:CheckIn:Read_Iridium] Stopped 2022-11-10T21:56:47.838Z,1668117407.838 [Default:CheckIn:C.Wait] Running Loop=1 2022-11-10T21:56:47.839Z,1668117407.839 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-11-10T22:01:20.601Z,1668117680.601 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-11-10T22:01:48.490Z,1668117708.490 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-11-10T22:01:48.490Z,1668117708.490 [Default:CheckIn:C.Wait] Stopped 2022-11-10T22:01:48.490Z,1668117708.490 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-11-10T22:01:48.491Z,1668117708.491 [Default:CheckIn:D] Running Loop=1 2022-11-10T22:01:48.889Z,1668117708.889 [Default:CheckIn:D] Stopped 2022-11-10T22:01:48.889Z,1668117708.889 [Default:CheckIn:E] Running Loop=1 2022-11-10T22:01:49.293Z,1668117709.293 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 105.571427 min 2022-11-10T22:01:49.293Z,1668117709.293 [Default:CheckIn:E] Stopped 2022-11-10T22:01:49.293Z,1668117709.293 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-11-10T22:01:49.293Z,1668117709.293 [Default:CheckIn] Stopped 2022-11-10T22:01:49.293Z,1668117709.293 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-11-10T22:01:49.294Z,1668117709.294 [Default:CheckIn](INFO): Running loop #18 2022-11-10T22:01:49.294Z,1668117709.294 [Default:CheckIn] Running Loop=18 2022-11-10T22:01:49.294Z,1668117709.294 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-11-10T22:01:49.294Z,1668117709.294 [Default:CheckIn:Read_GPS] Running Loop=1 2022-11-10T22:01:51.304Z,1668117711.304 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,220150.00,A,3648.16613,N,12147.28014,W,0.467,256.53,101122,,,D*7A 2022-11-10T22:01:51.316Z,1668117711.316 [NAL9602](INFO): GPS fix at 20221110T220150: (36.802769, -121.788002) 2022-11-10T22:01:51.327Z,1668117711.327 [Default:CheckIn:Read_GPS] Stopped 2022-11-10T22:01:51.327Z,1668117711.327 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-11-10T22:01:58.969Z,1668117718.969 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20221110T210129/Courier0033.lzma 2022-11-10T22:01:59.972Z,1668117719.972 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Courier0033.lzma.bak 2022-11-10T22:01:59.972Z,1668117719.972 [DataOverHttps](INFO): SBD MOMSN=17281642 2022-11-10T22:02:15.917Z,1668117735.917 [DataOverHttps](INFO): Sending 239 bytes from file Logs/20221110T210129/Express0034.lzma 2022-11-10T22:02:16.920Z,1668117736.920 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Express0034.lzma.bak 2022-11-10T22:02:16.920Z,1668117736.920 [DataOverHttps](INFO): SBD MOMSN=17281645 2022-11-10T22:02:18.380Z,1668117738.380 [Default:CheckIn:Read_Iridium] Stopped 2022-11-10T22:02:18.380Z,1668117738.380 [Default:CheckIn:C.Wait] Running Loop=1 2022-11-10T22:02:18.381Z,1668117738.381 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-11-10T22:02:23.667Z,1668117743.667 [NAL9602](INFO): Not Powering down - fast GPS 2022-11-10T22:07:19.058Z,1668118039.058 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-11-10T22:07:19.059Z,1668118039.059 [Default:CheckIn:C.Wait] Stopped 2022-11-10T22:07:19.059Z,1668118039.059 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-11-10T22:07:19.059Z,1668118039.059 [Default:CheckIn:D] Running Loop=1 2022-11-10T22:07:19.452Z,1668118039.452 [Default:CheckIn:D] Stopped 2022-11-10T22:07:19.452Z,1668118039.452 [Default:CheckIn:E] Running Loop=1 2022-11-10T22:07:19.856Z,1668118039.856 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 111.080811 min 2022-11-10T22:07:19.856Z,1668118039.856 [Default:CheckIn:E] Stopped 2022-11-10T22:07:19.857Z,1668118039.857 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-11-10T22:07:19.857Z,1668118039.857 [Default:CheckIn] Stopped 2022-11-10T22:07:19.857Z,1668118039.857 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-11-10T22:07:19.857Z,1668118039.857 [Default:CheckIn](INFO): Running loop #19 2022-11-10T22:07:19.857Z,1668118039.857 [Default:CheckIn] Running Loop=19 2022-11-10T22:07:19.857Z,1668118039.857 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-11-10T22:07:19.857Z,1668118039.857 [Default:CheckIn:Read_GPS] Running Loop=1 2022-11-10T22:07:21.868Z,1668118041.868 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,220721.00,A,3648.16591,N,12147.27959,W,0.603,122.69,101122,,,D*75 2022-11-10T22:07:21.871Z,1668118041.871 [NAL9602](INFO): GPS fix at 20221110T220721: (36.802765, -121.787993) 2022-11-10T22:07:21.881Z,1668118041.881 [Default:CheckIn:Read_GPS] Stopped 2022-11-10T22:07:21.881Z,1668118041.881 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-11-10T22:07:28.561Z,1668118048.561 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20221110T210129/Courier0036.lzma 2022-11-10T22:07:29.563Z,1668118049.563 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Courier0036.lzma.bak 2022-11-10T22:07:29.564Z,1668118049.564 [DataOverHttps](INFO): SBD MOMSN=17281699 2022-11-10T22:07:45.389Z,1668118065.389 [DataOverHttps](INFO): Sending 138 bytes from file Logs/20221110T210129/Express0037.lzma 2022-11-10T22:07:46.391Z,1668118066.391 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Express0037.lzma.bak 2022-11-10T22:07:46.392Z,1668118066.392 [DataOverHttps](INFO): SBD MOMSN=17281702 2022-11-10T22:07:47.742Z,1668118067.742 [Default:CheckIn:Read_Iridium] Stopped 2022-11-10T22:07:47.742Z,1668118067.742 [Default:CheckIn:C.Wait] Running Loop=1 2022-11-10T22:07:47.743Z,1668118067.743 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-11-10T22:07:52.583Z,1668118072.583 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-11-10T22:07:52.666Z,1668118072.666 [NAL9602](ERROR): received: +CSQ:0 OK900, 0, 0, 0, 0 OK 2022-11-10T22:10:50.600Z,1668118250.600 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-11-10T22:10:57.468Z,1668118257.468 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-11-10T22:11:12.819Z,1668118272.819 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-11-10T22:11:27.768Z,1668118287.768 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-11-10T22:11:43.119Z,1668118303.119 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-11-10T22:11:58.071Z,1668118318.071 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-11-10T22:12:13.419Z,1668118333.419 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-11-10T22:12:24.351Z,1668118344.351 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-11-10T22:12:28.816Z,1668118348.816 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-11-10T22:12:44.588Z,1668118364.588 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-11-10T22:12:48.241Z,1668118368.241 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-11-10T22:12:48.241Z,1668118368.241 [Default:CheckIn:C.Wait] Stopped 2022-11-10T22:12:48.241Z,1668118368.241 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-11-10T22:12:48.242Z,1668118368.242 [Default:CheckIn:D] Running Loop=1 2022-11-10T22:12:48.644Z,1668118368.644 [Default:CheckIn:D] Stopped 2022-11-10T22:12:48.644Z,1668118368.644 [Default:CheckIn:E] Running Loop=1 2022-11-10T22:12:49.052Z,1668118369.052 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 116.567350 min 2022-11-10T22:12:49.052Z,1668118369.052 [Default:CheckIn:E] Stopped 2022-11-10T22:12:49.053Z,1668118369.053 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-11-10T22:12:49.053Z,1668118369.053 [Default:CheckIn] Stopped 2022-11-10T22:12:49.053Z,1668118369.053 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-11-10T22:12:49.053Z,1668118369.053 [Default:CheckIn](INFO): Running loop #20 2022-11-10T22:12:49.053Z,1668118369.053 [Default:CheckIn] Running Loop=20 2022-11-10T22:12:49.053Z,1668118369.053 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-11-10T22:12:49.053Z,1668118369.053 [Default:CheckIn:Read_GPS] Running Loop=1 2022-11-10T22:12:51.057Z,1668118371.057 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,221250.00,A,3648.16670,N,12147.28181,W,0.661,25.89,101122,,,D*45 2022-11-10T22:12:51.059Z,1668118371.059 [NAL9602](INFO): GPS fix at 20221110T221250: (36.802778, -121.788030) 2022-11-10T22:12:51.091Z,1668118371.091 [Default:CheckIn:Read_GPS] Stopped 2022-11-10T22:12:51.091Z,1668118371.091 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-11-10T22:12:59.033Z,1668118379.033 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20221110T210129/Courier0039.lzma 2022-11-10T22:13:00.035Z,1668118380.035 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Courier0039.lzma.bak 2022-11-10T22:13:00.036Z,1668118380.036 [DataOverHttps](INFO): SBD MOMSN=17281705 2022-11-10T22:13:00.345Z,1668118380.345 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-11-10T22:13:16.245Z,1668118396.245 [DataOverHttps](INFO): Sending 217 bytes from file Logs/20221110T210129/Express0040.lzma 2022-11-10T22:13:17.247Z,1668118397.247 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Express0040.lzma.bak 2022-11-10T22:13:17.248Z,1668118397.248 [DataOverHttps](INFO): SBD MOMSN=17281708 2022-11-10T22:13:18.140Z,1668118398.140 [BPC1](INFO): Calculating totals. Valid battery stick count: 48. Valid reserve battery stick count: 5. 2022-11-10T22:13:18.143Z,1668118398.143 [BPC1](INFO): Received data from all battery sticks. 2022-11-10T22:13:18.554Z,1668118398.554 [Default:CheckIn:Read_Iridium] Stopped 2022-11-10T22:13:18.554Z,1668118398.554 [Default:CheckIn:C.Wait] Running Loop=1 2022-11-10T22:13:18.554Z,1668118398.554 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-11-10T22:13:23.387Z,1668118403.387 [NAL9602](INFO): Not Powering down - fast GPS 2022-11-10T22:18:19.183Z,1668118699.183 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-11-10T22:18:19.183Z,1668118699.183 [Default:CheckIn:C.Wait] Stopped 2022-11-10T22:18:19.183Z,1668118699.183 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-11-10T22:18:19.183Z,1668118699.183 [Default:CheckIn:D] Running Loop=1 2022-11-10T22:18:19.588Z,1668118699.588 [Default:CheckIn:D] Stopped 2022-11-10T22:18:19.588Z,1668118699.588 [Default:CheckIn:E] Running Loop=1 2022-11-10T22:18:20.000Z,1668118700.000 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 122.083089 min 2022-11-10T22:18:20.000Z,1668118700.000 [Default:CheckIn:E] Stopped 2022-11-10T22:18:20.001Z,1668118700.001 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-11-10T22:18:20.001Z,1668118700.001 [Default:CheckIn] Stopped 2022-11-10T22:18:20.001Z,1668118700.001 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-11-10T22:18:20.001Z,1668118700.001 [Default:CheckIn](INFO): Running loop #21 2022-11-10T22:18:20.001Z,1668118700.001 [Default:CheckIn] Running Loop=21 2022-11-10T22:18:20.001Z,1668118700.001 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-11-10T22:18:20.001Z,1668118700.001 [Default:CheckIn:Read_GPS] Running Loop=1 2022-11-10T22:18:22.005Z,1668118702.005 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,221821.00,A,3648.16756,N,12147.27909,W,0.175,280.58,101122,,,D*78 2022-11-10T22:18:22.007Z,1668118702.007 [NAL9602](INFO): GPS fix at 20221110T221821: (36.802793, -121.787985) 2022-11-10T22:18:22.051Z,1668118702.051 [Default:CheckIn:Read_GPS] Stopped 2022-11-10T22:18:22.051Z,1668118702.051 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-11-10T22:18:31.901Z,1668118711.901 [DataOverHttps](INFO): Sending 85 bytes from file Logs/20221110T210129/Courier0042.lzma 2022-11-10T22:18:32.903Z,1668118712.903 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Courier0042.lzma.bak 2022-11-10T22:18:32.904Z,1668118712.904 [DataOverHttps](INFO): SBD MOMSN=17281761 2022-11-10T22:18:48.593Z,1668118728.593 [DataOverHttps](INFO): Sending 142 bytes from file Logs/20221110T210129/Express0043.lzma 2022-11-10T22:18:49.596Z,1668118729.596 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Express0043.lzma.bak 2022-11-10T22:18:49.596Z,1668118729.596 [DataOverHttps](INFO): SBD MOMSN=17281764 2022-11-10T22:18:50.809Z,1668118730.809 [Default:CheckIn:Read_Iridium] Stopped 2022-11-10T22:18:50.809Z,1668118730.809 [Default:CheckIn:C.Wait] Running Loop=1 2022-11-10T22:18:50.809Z,1668118730.809 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-11-10T22:18:52.823Z,1668118732.823 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-11-10T22:18:52.906Z,1668118732.906 [NAL9602](ERROR): received: +CSQ:0 OK900, 0, 0, 0, 0 OK 2022-11-10T22:23:24.407Z,1668119004.407 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-11-10T22:23:51.475Z,1668119031.475 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-11-10T22:23:51.475Z,1668119031.475 [Default:CheckIn:C.Wait] Stopped 2022-11-10T22:23:51.475Z,1668119031.475 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-11-10T22:23:51.475Z,1668119031.475 [Default:CheckIn:D] Running Loop=1 2022-11-10T22:23:51.884Z,1668119031.884 [Default:CheckIn:D] Stopped 2022-11-10T22:23:51.884Z,1668119031.884 [Default:CheckIn:E] Running Loop=1 2022-11-10T22:23:52.286Z,1668119032.286 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 127.621354 min 2022-11-10T22:23:52.286Z,1668119032.286 [Default:CheckIn:E] Stopped 2022-11-10T22:23:52.286Z,1668119032.286 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-11-10T22:23:52.286Z,1668119032.286 [Default:CheckIn] Stopped 2022-11-10T22:23:52.286Z,1668119032.286 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-11-10T22:23:52.287Z,1668119032.287 [Default:CheckIn](INFO): Running loop #22 2022-11-10T22:23:52.287Z,1668119032.287 [Default:CheckIn] Running Loop=22 2022-11-10T22:23:52.287Z,1668119032.287 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-11-10T22:23:52.287Z,1668119032.287 [Default:CheckIn:Read_GPS] Running Loop=1 2022-11-10T22:23:54.296Z,1668119034.296 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,222353.00,A,3648.17017,N,12147.27950,W,0.505,244.31,101122,,,D*7E 2022-11-10T22:23:54.309Z,1668119034.309 [NAL9602](INFO): GPS fix at 20221110T222353: (36.802836, -121.787992) 2022-11-10T22:23:54.319Z,1668119034.319 [Default:CheckIn:Read_GPS] Stopped 2022-11-10T22:23:54.319Z,1668119034.319 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-11-10T22:24:01.117Z,1668119041.117 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20221110T210129/Courier0045.lzma 2022-11-10T22:24:02.119Z,1668119042.119 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Courier0045.lzma.bak 2022-11-10T22:24:02.120Z,1668119042.120 [DataOverHttps](INFO): SBD MOMSN=17281767 2022-11-10T22:24:17.753Z,1668119057.753 [DataOverHttps](INFO): Sending 215 bytes from file Logs/20221110T210129/Express0046.lzma 2022-11-10T22:24:18.756Z,1668119058.756 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Express0046.lzma.bak 2022-11-10T22:24:18.756Z,1668119058.756 [DataOverHttps](INFO): SBD MOMSN=17281772 2022-11-10T22:24:20.166Z,1668119060.166 [Default:CheckIn:Read_Iridium] Stopped 2022-11-10T22:24:20.166Z,1668119060.166 [Default:CheckIn:C.Wait] Running Loop=1 2022-11-10T22:24:20.167Z,1668119060.167 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-11-10T22:24:26.635Z,1668119066.635 [NAL9602](INFO): Not Powering down - fast GPS 2022-11-10T22:29:20.934Z,1668119360.934 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-11-10T22:29:20.934Z,1668119360.934 [Default:CheckIn:C.Wait] Stopped 2022-11-10T22:29:20.934Z,1668119360.934 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-11-10T22:29:20.934Z,1668119360.934 [Default:CheckIn:D] Running Loop=1 2022-11-10T22:29:21.324Z,1668119361.324 [Default:CheckIn:D] Stopped 2022-11-10T22:29:21.324Z,1668119361.324 [Default:CheckIn:E] Running Loop=1 2022-11-10T22:29:21.733Z,1668119361.733 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 133.112012 min 2022-11-10T22:29:21.733Z,1668119361.733 [Default:CheckIn:E] Stopped 2022-11-10T22:29:21.734Z,1668119361.734 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-11-10T22:29:21.734Z,1668119361.734 [Default:CheckIn] Stopped 2022-11-10T22:29:21.734Z,1668119361.734 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-11-10T22:29:21.734Z,1668119361.734 [Default:CheckIn](INFO): Running loop #23 2022-11-10T22:29:21.734Z,1668119361.734 [Default:CheckIn] Running Loop=23 2022-11-10T22:29:21.734Z,1668119361.734 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-11-10T22:29:21.734Z,1668119361.734 [Default:CheckIn:Read_GPS] Running Loop=1 2022-11-10T22:29:23.740Z,1668119363.740 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,222923.00,A,3648.17072,N,12147.28102,W,0.330,244.09,101122,,,D*7B 2022-11-10T22:29:23.743Z,1668119363.743 [NAL9602](INFO): GPS fix at 20221110T222923: (36.802845, -121.788017) 2022-11-10T22:29:23.754Z,1668119363.754 [Default:CheckIn:Read_GPS] Stopped 2022-11-10T22:29:23.754Z,1668119363.754 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-11-10T22:29:31.005Z,1668119371.005 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20221110T210129/Courier0048.lzma 2022-11-10T22:29:32.007Z,1668119372.007 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Courier0048.lzma.bak 2022-11-10T22:29:32.008Z,1668119372.008 [DataOverHttps](INFO): SBD MOMSN=17281825 2022-11-10T22:29:47.889Z,1668119387.889 [DataOverHttps](INFO): Sending 142 bytes from file Logs/20221110T210129/Express0049.lzma 2022-11-10T22:29:48.892Z,1668119388.892 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Express0049.lzma.bak 2022-11-10T22:29:48.892Z,1668119388.892 [DataOverHttps](INFO): SBD MOMSN=17281828 2022-11-10T22:29:50.042Z,1668119390.042 [Default:CheckIn:Read_Iridium] Stopped 2022-11-10T22:29:50.042Z,1668119390.042 [Default:CheckIn:C.Wait] Running Loop=1 2022-11-10T22:29:50.042Z,1668119390.042 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-11-10T22:29:54.443Z,1668119394.443 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-11-10T22:29:54.518Z,1668119394.518 [NAL9602](ERROR): received: +CSQ:0 OK900, 0, 0, 0, 0 OK 2022-11-10T22:31:03.580Z,1668119463.580 [NAL9602](INFO): SBD MO Status=2, MOMSN=37901, MT Status=2, MTMSN=0 2022-11-10T22:31:03.580Z,1668119463.580 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-11-10T22:31:25.392Z,1668119485.392 [NAL9602](INFO): SBD MO Status=2, MOMSN=37901, MT Status=2, MTMSN=0 2022-11-10T22:31:25.392Z,1668119485.392 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-11-10T22:32:07.008Z,1668119527.008 [NAL9602](INFO): SBD MO Status=0, MOMSN=37901, MT Status=0, MTMSN=0 2022-11-10T22:32:07.008Z,1668119527.008 [NAL9602](INFO): No messages in MT queue 2022-11-10T22:32:37.765Z,1668119557.765 [NAL9602](INFO): Not Powering down - fast GPS 2022-11-10T22:34:50.734Z,1668119690.734 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-11-10T22:34:50.735Z,1668119690.735 [Default:CheckIn:C.Wait] Stopped 2022-11-10T22:34:50.735Z,1668119690.735 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-11-10T22:34:50.736Z,1668119690.736 [Default:CheckIn:D] Running Loop=1 2022-11-10T22:34:51.152Z,1668119691.152 [Default:CheckIn:D] Stopped 2022-11-10T22:34:51.152Z,1668119691.152 [Default:CheckIn:E] Running Loop=1 2022-11-10T22:34:51.540Z,1668119691.540 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 138.609147 min 2022-11-10T22:34:51.540Z,1668119691.540 [Default:CheckIn:E] Stopped 2022-11-10T22:34:51.541Z,1668119691.541 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-11-10T22:34:51.541Z,1668119691.541 [Default:CheckIn] Stopped 2022-11-10T22:34:51.541Z,1668119691.541 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-11-10T22:34:51.541Z,1668119691.541 [Default:CheckIn](INFO): Running loop #24 2022-11-10T22:34:51.541Z,1668119691.541 [Default:CheckIn] Running Loop=24 2022-11-10T22:34:51.541Z,1668119691.541 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-11-10T22:34:51.541Z,1668119691.541 [Default:CheckIn:Read_GPS] Running Loop=1 2022-11-10T22:34:53.547Z,1668119693.547 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,223452.00,A,3648.17200,N,12147.28156,W,0.641,244.09,101122,,,D*74 2022-11-10T22:34:53.550Z,1668119693.550 [NAL9602](INFO): GPS fix at 20221110T223452: (36.802867, -121.788026) 2022-11-10T22:34:53.560Z,1668119693.560 [Default:CheckIn:Read_GPS] Stopped 2022-11-10T22:34:53.560Z,1668119693.560 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-11-10T22:35:01.293Z,1668119701.293 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20221110T210129/Courier0051.lzma 2022-11-10T22:35:02.295Z,1668119702.295 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Courier0051.lzma.bak 2022-11-10T22:35:02.296Z,1668119702.296 [DataOverHttps](INFO): SBD MOMSN=17281834 2022-11-10T22:35:18.249Z,1668119718.249 [DataOverHttps](INFO): Sending 155 bytes from file Logs/20221110T210129/Express0052.lzma 2022-11-10T22:35:19.251Z,1668119719.251 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Express0052.lzma.bak 2022-11-10T22:35:19.252Z,1668119719.252 [DataOverHttps](INFO): SBD MOMSN=17281841 2022-11-10T22:35:20.645Z,1668119720.645 [Default:CheckIn:Read_Iridium] Stopped 2022-11-10T22:35:20.645Z,1668119720.645 [Default:CheckIn:C.Wait] Running Loop=1 2022-11-10T22:35:20.645Z,1668119720.645 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-11-10T22:35:38.005Z,1668119738.005 [CBIT](IMPORTANT): Beginning ground fault scan 2022-11-10T22:35:40.849Z,1668119740.849 [CBIT](ERROR): Error reading 24V bus power status. Assuming off for scan purposes. 2022-11-10T22:35:49.045Z,1668119749.045 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.002598 CHAN A1 (24V) N/A reporting off CHAN A2 (12V): -0.002173 CHAN A3 (5V): -0.001569 CHAN B0 (3.3V): -0.000024 CHAN B1 (3.15aV): -0.000125 CHAN B2 (3.15bV): 0.000051 CHAN B3 (GND): -0.000306 OPEN: -0.000510 Full Scale: +/- 1 mA 2022-11-10T22:39:55.387Z,1668119995.387 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-11-10T22:40:21.256Z,1668120021.256 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-11-10T22:40:21.256Z,1668120021.256 [Default:CheckIn:C.Wait] Stopped 2022-11-10T22:40:21.256Z,1668120021.256 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-11-10T22:40:21.257Z,1668120021.257 [Default:CheckIn:D] Running Loop=1 2022-11-10T22:40:21.663Z,1668120021.663 [Default:CheckIn:D] Stopped 2022-11-10T22:40:21.663Z,1668120021.663 [Default:CheckIn:E] Running Loop=1 2022-11-10T22:40:22.059Z,1668120022.059 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 144.117660 min 2022-11-10T22:40:22.059Z,1668120022.059 [Default:CheckIn:E] Stopped 2022-11-10T22:40:22.059Z,1668120022.059 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-11-10T22:40:22.059Z,1668120022.059 [Default:CheckIn] Stopped 2022-11-10T22:40:22.060Z,1668120022.060 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-11-10T22:40:22.060Z,1668120022.060 [Default:CheckIn](INFO): Running loop #25 2022-11-10T22:40:22.060Z,1668120022.060 [Default:CheckIn] Running Loop=25 2022-11-10T22:40:22.060Z,1668120022.060 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-11-10T22:40:22.060Z,1668120022.060 [Default:CheckIn:Read_GPS] Running Loop=1 2022-11-10T22:40:24.073Z,1668120024.073 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,224023.00,A,3648.17221,N,12147.28490,W,0.583,179.04,101122,,,D*70 2022-11-10T22:40:24.075Z,1668120024.075 [NAL9602](INFO): GPS fix at 20221110T224023: (36.802870, -121.788082) 2022-11-10T22:40:24.085Z,1668120024.085 [Default:CheckIn:Read_GPS] Stopped 2022-11-10T22:40:24.085Z,1668120024.085 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-11-10T22:40:34.281Z,1668120034.281 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20221110T210129/Courier0054.lzma 2022-11-10T22:40:35.284Z,1668120035.284 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Courier0054.lzma.bak 2022-11-10T22:40:35.284Z,1668120035.284 [DataOverHttps](INFO): SBD MOMSN=17281891 2022-11-10T22:40:51.038Z,1668120051.038 [DataOverHttps](INFO): Sending 416 bytes from file Logs/20221110T210129/Express0055.lzma 2022-11-10T22:40:52.040Z,1668120052.040 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Express0055.lzma.bak 2022-11-10T22:40:52.040Z,1668120052.040 [DataOverHttps](INFO): SBD MOMSN=17281894 2022-11-10T22:40:53.246Z,1668120053.246 [Default:CheckIn:Read_Iridium] Stopped 2022-11-10T22:40:53.246Z,1668120053.246 [Default:CheckIn:C.Wait] Running Loop=1 2022-11-10T22:40:53.246Z,1668120053.246 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-11-10T22:40:56.458Z,1668120056.458 [NAL9602](INFO): Not Powering down - fast GPS 2022-11-10T22:45:53.840Z,1668120353.840 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-11-10T22:45:53.840Z,1668120353.840 [Default:CheckIn:C.Wait] Stopped 2022-11-10T22:45:53.840Z,1668120353.840 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-11-10T22:45:53.841Z,1668120353.841 [Default:CheckIn:D] Running Loop=1 2022-11-10T22:45:54.241Z,1668120354.241 [Default:CheckIn:D] Stopped 2022-11-10T22:45:54.241Z,1668120354.241 [Default:CheckIn:E] Running Loop=1 2022-11-10T22:45:54.657Z,1668120354.657 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 149.660628 min 2022-11-10T22:45:54.657Z,1668120354.657 [Default:CheckIn:E] Stopped 2022-11-10T22:45:54.657Z,1668120354.657 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-11-10T22:45:54.657Z,1668120354.657 [Default:CheckIn] Stopped 2022-11-10T22:45:54.657Z,1668120354.657 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-11-10T22:45:54.658Z,1668120354.658 [Default:CheckIn](INFO): Running loop #26 2022-11-10T22:45:54.658Z,1668120354.658 [Default:CheckIn] Running Loop=26 2022-11-10T22:45:54.658Z,1668120354.658 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-11-10T22:45:54.658Z,1668120354.658 [Default:CheckIn:Read_GPS] Running Loop=1 2022-11-10T22:45:56.655Z,1668120356.655 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,224555.00,A,3648.16694,N,12147.27658,W,0.117,131.20,101122,,,D*75 2022-11-10T22:45:56.658Z,1668120356.658 [NAL9602](INFO): GPS fix at 20221110T224555: (36.802782, -121.787943) 2022-11-10T22:45:56.681Z,1668120356.681 [Default:CheckIn:Read_GPS] Stopped 2022-11-10T22:45:56.682Z,1668120356.682 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-11-10T22:46:03.682Z,1668120363.682 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20221110T210129/Courier0057.lzma 2022-11-10T22:46:04.683Z,1668120364.683 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Courier0057.lzma.bak 2022-11-10T22:46:04.684Z,1668120364.684 [DataOverHttps](INFO): SBD MOMSN=17281907 2022-11-10T22:46:20.509Z,1668120380.509 [DataOverHttps](INFO): Sending 141 bytes from file Logs/20221110T210129/Express0058.lzma 2022-11-10T22:46:21.512Z,1668120381.512 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Express0058.lzma.bak 2022-11-10T22:46:21.512Z,1668120381.512 [DataOverHttps](INFO): SBD MOMSN=17281910 2022-11-10T22:46:22.579Z,1668120382.579 [Default:CheckIn:Read_Iridium] Stopped 2022-11-10T22:46:22.579Z,1668120382.579 [Default:CheckIn:C.Wait] Running Loop=1 2022-11-10T22:46:22.579Z,1668120382.579 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-11-10T22:48:29.081Z,1668120509.081 [NAL9602](INFO): SBD MO Status=2, MOMSN=37902, MT Status=2, MTMSN=0 2022-11-10T22:48:29.082Z,1668120509.082 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-11-10T22:48:48.888Z,1668120528.888 [NAL9602](INFO): SBD MO Status=0, MOMSN=37902, MT Status=0, MTMSN=0 2022-11-10T22:48:48.888Z,1668120528.888 [NAL9602](INFO): No messages in MT queue 2022-11-10T22:49:19.594Z,1668120559.594 [NAL9602](INFO): Not Powering down - fast GPS 2022-11-10T22:51:23.261Z,1668120683.261 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-11-10T22:51:23.261Z,1668120683.261 [Default:CheckIn:C.Wait] Stopped 2022-11-10T22:51:23.261Z,1668120683.261 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-11-10T22:51:23.261Z,1668120683.261 [Default:CheckIn:D] Running Loop=1 2022-11-10T22:51:23.677Z,1668120683.677 [Default:CheckIn:D] Stopped 2022-11-10T22:51:23.677Z,1668120683.677 [Default:CheckIn:E] Running Loop=1 2022-11-10T22:51:24.082Z,1668120684.082 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 155.151237 min 2022-11-10T22:51:24.082Z,1668120684.082 [Default:CheckIn:E] Stopped 2022-11-10T22:51:24.082Z,1668120684.082 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-11-10T22:51:24.082Z,1668120684.082 [Default:CheckIn] Stopped 2022-11-10T22:51:24.082Z,1668120684.082 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-11-10T22:51:24.082Z,1668120684.082 [Default:CheckIn](INFO): Running loop #27 2022-11-10T22:51:24.082Z,1668120684.082 [Default:CheckIn] Running Loop=27 2022-11-10T22:51:24.082Z,1668120684.082 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-11-10T22:51:24.083Z,1668120684.083 [Default:CheckIn:Read_GPS] Running Loop=1 2022-11-10T22:51:26.084Z,1668120686.084 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,225125.00,A,3648.17247,N,12147.27903,W,0.233,86.70,101122,,,D*40 2022-11-10T22:51:26.087Z,1668120686.087 [NAL9602](INFO): GPS fix at 20221110T225125: (36.802875, -121.787984) 2022-11-10T22:51:26.120Z,1668120686.120 [Default:CheckIn:Read_GPS] Stopped 2022-11-10T22:51:26.120Z,1668120686.120 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-11-10T22:51:33.821Z,1668120693.821 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20221110T210129/Courier0060.lzma 2022-11-10T22:51:34.823Z,1668120694.823 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Courier0060.lzma.bak 2022-11-10T22:51:34.824Z,1668120694.824 [DataOverHttps](INFO): SBD MOMSN=17281955 2022-11-10T22:51:50.721Z,1668120710.721 [DataOverHttps](INFO): Sending 153 bytes from file Logs/20221110T210129/Express0061.lzma 2022-11-10T22:51:51.723Z,1668120711.723 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Express0061.lzma.bak 2022-11-10T22:51:51.724Z,1668120711.724 [DataOverHttps](INFO): SBD MOMSN=17281958 2022-11-10T22:51:52.822Z,1668120712.822 [Default:CheckIn:Read_Iridium] Stopped 2022-11-10T22:51:52.822Z,1668120712.822 [Default:CheckIn:C.Wait] Running Loop=1 2022-11-10T22:51:52.822Z,1668120712.822 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-11-10T22:56:28.442Z,1668120988.442 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-11-10T22:56:53.564Z,1668121013.564 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-11-10T22:56:53.564Z,1668121013.564 [Default:CheckIn:C.Wait] Stopped 2022-11-10T22:56:53.564Z,1668121013.564 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-11-10T22:56:53.565Z,1668121013.565 [Default:CheckIn:D] Running Loop=1 2022-11-10T22:56:53.963Z,1668121013.963 [Default:CheckIn:D] Stopped 2022-11-10T22:56:53.963Z,1668121013.963 [Default:CheckIn:E] Running Loop=1 2022-11-10T22:56:54.364Z,1668121014.364 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 160.656006 min 2022-11-10T22:56:54.364Z,1668121014.364 [Default:CheckIn:E] Stopped 2022-11-10T22:56:54.365Z,1668121014.365 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-11-10T22:56:54.365Z,1668121014.365 [Default:CheckIn] Stopped 2022-11-10T22:56:54.365Z,1668121014.365 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-11-10T22:56:54.365Z,1668121014.365 [Default:CheckIn](INFO): Running loop #28 2022-11-10T22:56:54.365Z,1668121014.365 [Default:CheckIn] Running Loop=28 2022-11-10T22:56:54.365Z,1668121014.365 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-11-10T22:56:54.365Z,1668121014.365 [Default:CheckIn:Read_GPS] Running Loop=1 2022-11-10T22:56:56.376Z,1668121016.376 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,225655.00,A,3648.18034,N,12147.27773,W,0.350,309.88,101122,,,D*77 2022-11-10T22:56:56.379Z,1668121016.379 [NAL9602](INFO): GPS fix at 20221110T225655: (36.803006, -121.787962) 2022-11-10T22:56:56.389Z,1668121016.389 [Default:CheckIn:Read_GPS] Stopped 2022-11-10T22:56:56.390Z,1668121016.390 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-11-10T22:57:03.333Z,1668121023.333 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20221110T210129/Courier0063.lzma 2022-11-10T22:57:04.335Z,1668121024.335 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Courier0063.lzma.bak 2022-11-10T22:57:04.336Z,1668121024.336 [DataOverHttps](INFO): SBD MOMSN=17281967 2022-11-10T22:57:20.109Z,1668121040.109 [DataOverHttps](INFO): Sending 214 bytes from file Logs/20221110T210129/Express0064.lzma 2022-11-10T22:57:21.112Z,1668121041.112 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Express0064.lzma.bak 2022-11-10T22:57:21.112Z,1668121041.112 [DataOverHttps](INFO): SBD MOMSN=17281974 2022-11-10T22:57:22.238Z,1668121042.238 [Default:CheckIn:Read_Iridium] Stopped 2022-11-10T22:57:22.238Z,1668121042.238 [Default:CheckIn:C.Wait] Running Loop=1 2022-11-10T22:57:22.238Z,1668121042.238 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-11-10T22:57:28.698Z,1668121048.698 [NAL9602](INFO): Not Powering down - fast GPS 2022-11-10T23:02:22.970Z,1668121342.970 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-11-10T23:02:22.970Z,1668121342.970 [Default:CheckIn:C.Wait] Stopped 2022-11-10T23:02:22.970Z,1668121342.970 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-11-10T23:02:22.970Z,1668121342.970 [Default:CheckIn:D] Running Loop=1 2022-11-10T23:02:23.360Z,1668121343.360 [Default:CheckIn:D] Stopped 2022-11-10T23:02:23.360Z,1668121343.360 [Default:CheckIn:E] Running Loop=1 2022-11-10T23:02:23.764Z,1668121343.764 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 166.145947 min 2022-11-10T23:02:23.764Z,1668121343.764 [Default:CheckIn:E] Stopped 2022-11-10T23:02:23.764Z,1668121343.764 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-11-10T23:02:23.764Z,1668121343.764 [Default:CheckIn] Stopped 2022-11-10T23:02:23.765Z,1668121343.765 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-11-10T23:02:23.765Z,1668121343.765 [Default:CheckIn](INFO): Running loop #29 2022-11-10T23:02:23.765Z,1668121343.765 [Default:CheckIn] Running Loop=29 2022-11-10T23:02:23.765Z,1668121343.765 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-11-10T23:02:23.765Z,1668121343.765 [Default:CheckIn:Read_GPS] Running Loop=1 2022-11-10T23:02:25.776Z,1668121345.776 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,230225.00,A,3648.17364,N,12147.27867,W,0.428,114.64,101122,,,D*77 2022-11-10T23:02:25.779Z,1668121345.779 [NAL9602](INFO): GPS fix at 20221110T230225: (36.802894, -121.787978) 2022-11-10T23:02:25.797Z,1668121345.797 [Default:CheckIn:Read_GPS] Stopped 2022-11-10T23:02:25.797Z,1668121345.797 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-11-10T23:02:33.605Z,1668121353.605 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20221110T210129/Courier0066.lzma 2022-11-10T23:02:34.607Z,1668121354.607 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Courier0066.lzma.bak 2022-11-10T23:02:34.608Z,1668121354.608 [DataOverHttps](INFO): SBD MOMSN=17282013 2022-11-10T23:02:50.361Z,1668121370.361 [DataOverHttps](INFO): Sending 142 bytes from file Logs/20221110T210129/Express0067.lzma 2022-11-10T23:02:51.364Z,1668121371.364 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Express0067.lzma.bak 2022-11-10T23:02:51.364Z,1668121371.364 [DataOverHttps](INFO): SBD MOMSN=17282016 2022-11-10T23:02:52.677Z,1668121372.677 [Default:CheckIn:Read_Iridium] Stopped 2022-11-10T23:02:52.677Z,1668121372.677 [Default:CheckIn:C.Wait] Running Loop=1 2022-11-10T23:02:52.678Z,1668121372.678 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-11-10T23:02:56.291Z,1668121376.291 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-11-10T23:02:56.366Z,1668121376.366 [NAL9602](ERROR): received: +CSQ:0 OK902, 0, 0, 0, 0 OK 2022-11-10T23:06:17.948Z,1668121577.948 [NAL9602](INFO): SBD MO Status=0, MOMSN=37903, MT Status=0, MTMSN=0 2022-11-10T23:06:17.948Z,1668121577.948 [NAL9602](INFO): No messages in MT queue 2022-11-10T23:06:48.676Z,1668121608.676 [NAL9602](INFO): Not Powering down - fast GPS 2022-11-10T23:07:53.329Z,1668121673.329 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-11-10T23:07:53.329Z,1668121673.329 [Default:CheckIn:C.Wait] Stopped 2022-11-10T23:07:53.329Z,1668121673.329 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-11-10T23:07:53.329Z,1668121673.329 [Default:CheckIn:D] Running Loop=1 2022-11-10T23:07:53.732Z,1668121673.732 [Default:CheckIn:D] Stopped 2022-11-10T23:07:53.732Z,1668121673.732 [Default:CheckIn:E] Running Loop=1 2022-11-10T23:07:54.140Z,1668121674.140 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 171.652148 min 2022-11-10T23:07:54.141Z,1668121674.141 [Default:CheckIn:E] Stopped 2022-11-10T23:07:54.141Z,1668121674.141 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-11-10T23:07:54.141Z,1668121674.141 [Default:CheckIn] Stopped 2022-11-10T23:07:54.141Z,1668121674.141 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-11-10T23:07:54.141Z,1668121674.141 [Default:CheckIn](INFO): Running loop #30 2022-11-10T23:07:54.141Z,1668121674.141 [Default:CheckIn] Running Loop=30 2022-11-10T23:07:54.141Z,1668121674.141 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-11-10T23:07:54.141Z,1668121674.141 [Default:CheckIn:Read_GPS] Running Loop=1 2022-11-10T23:07:56.148Z,1668121676.148 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,230755.00,A,3648.16987,N,12147.28166,W,0.505,216.50,101122,,,D*7C 2022-11-10T23:07:56.160Z,1668121676.160 [NAL9602](INFO): GPS fix at 20221110T230755: (36.802831, -121.788028) 2022-11-10T23:07:56.171Z,1668121676.171 [Default:CheckIn:Read_GPS] Stopped 2022-11-10T23:07:56.171Z,1668121676.171 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-11-10T23:08:03.229Z,1668121683.229 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20221110T210129/Courier0069.lzma 2022-11-10T23:08:04.232Z,1668121684.232 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Courier0069.lzma.bak 2022-11-10T23:08:04.232Z,1668121684.232 [DataOverHttps](INFO): SBD MOMSN=17282026 2022-11-10T23:08:19.977Z,1668121699.977 [DataOverHttps](INFO): Sending 145 bytes from file Logs/20221110T210129/Express0070.lzma 2022-11-10T23:08:20.980Z,1668121700.980 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Express0070.lzma.bak 2022-11-10T23:08:20.980Z,1668121700.980 [DataOverHttps](INFO): SBD MOMSN=17282029 2022-11-10T23:08:22.093Z,1668121702.093 [Default:CheckIn:Read_Iridium] Stopped 2022-11-10T23:08:22.093Z,1668121702.093 [Default:CheckIn:C.Wait] Running Loop=1 2022-11-10T23:08:22.093Z,1668121702.093 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-11-10T23:08:26.488Z,1668121706.488 [NAL9602](INFO): SBD MO Status=0, MOMSN=37904, MT Status=0, MTMSN=0 2022-11-10T23:08:26.488Z,1668121706.488 [NAL9602](INFO): No messages in MT queue 2022-11-10T23:08:57.238Z,1668121737.238 [NAL9602](INFO): Not Powering down - fast GPS 2022-11-10T23:13:22.779Z,1668122002.779 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-11-10T23:13:22.779Z,1668122002.779 [Default:CheckIn:C.Wait] Stopped 2022-11-10T23:13:22.779Z,1668122002.779 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-11-10T23:13:22.779Z,1668122002.779 [Default:CheckIn:D] Running Loop=1 2022-11-10T23:13:23.185Z,1668122003.185 [Default:CheckIn:D] Stopped 2022-11-10T23:13:23.185Z,1668122003.185 [Default:CheckIn:E] Running Loop=1 2022-11-10T23:13:23.608Z,1668122003.608 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 177.143034 min 2022-11-10T23:13:23.608Z,1668122003.608 [Default:CheckIn:E] Stopped 2022-11-10T23:13:23.608Z,1668122003.608 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-11-10T23:13:23.608Z,1668122003.608 [Default:CheckIn] Stopped 2022-11-10T23:13:23.608Z,1668122003.608 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-11-10T23:13:23.608Z,1668122003.608 [Default:CheckIn](INFO): Running loop #31 2022-11-10T23:13:23.608Z,1668122003.608 [Default:CheckIn] Running Loop=31 2022-11-10T23:13:23.608Z,1668122003.608 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-11-10T23:13:23.608Z,1668122003.608 [Default:CheckIn:Read_GPS] Running Loop=1 2022-11-10T23:13:25.608Z,1668122005.608 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,231324.00,A,3648.16840,N,12147.28239,W,0.156,122.47,101122,,,D*7C 2022-11-10T23:13:25.611Z,1668122005.611 [NAL9602](INFO): GPS fix at 20221110T231324: (36.802807, -121.788040) 2022-11-10T23:13:25.621Z,1668122005.621 [Default:CheckIn:Read_GPS] Stopped 2022-11-10T23:13:25.621Z,1668122005.621 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-11-10T23:13:33.621Z,1668122013.621 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20221110T210129/Courier0072.lzma 2022-11-10T23:13:34.623Z,1668122014.623 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Courier0072.lzma.bak 2022-11-10T23:13:34.624Z,1668122014.624 [DataOverHttps](INFO): SBD MOMSN=17282034 2022-11-10T23:13:50.521Z,1668122030.521 [DataOverHttps](INFO): Sending 147 bytes from file Logs/20221110T210129/Express0073.lzma 2022-11-10T23:13:51.523Z,1668122031.523 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Express0073.lzma.bak 2022-11-10T23:13:51.524Z,1668122031.524 [DataOverHttps](INFO): SBD MOMSN=17282037 2022-11-10T23:13:52.690Z,1668122032.690 [Default:CheckIn:Read_Iridium] Stopped 2022-11-10T23:13:52.690Z,1668122032.690 [Default:CheckIn:C.Wait] Running Loop=1 2022-11-10T23:13:52.690Z,1668122032.690 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-11-10T23:15:12.720Z,1668122112.720 [NAL9602](INFO): SBD MO Status=0, MOMSN=37905, MT Status=0, MTMSN=0 2022-11-10T23:15:12.720Z,1668122112.720 [NAL9602](INFO): No messages in MT queue 2022-11-10T23:15:43.423Z,1668122143.423 [NAL9602](INFO): Not Powering down - fast GPS 2022-11-10T23:18:14.551Z,1668122294.551 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-11-10T23:18:21.420Z,1668122301.420 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-11-10T23:18:36.810Z,1668122316.810 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-11-10T23:18:51.756Z,1668122331.756 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-11-10T23:18:53.403Z,1668122333.403 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-11-10T23:18:53.403Z,1668122333.403 [Default:CheckIn:C.Wait] Stopped 2022-11-10T23:18:53.403Z,1668122333.403 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-11-10T23:18:53.403Z,1668122333.403 [Default:CheckIn:D] Running Loop=1 2022-11-10T23:18:53.787Z,1668122333.787 [Default:CheckIn:D] Stopped 2022-11-10T23:18:53.787Z,1668122333.787 [Default:CheckIn:E] Running Loop=1 2022-11-10T23:18:54.197Z,1668122334.197 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 182.653060 min 2022-11-10T23:18:54.197Z,1668122334.197 [Default:CheckIn:E] Stopped 2022-11-10T23:18:54.197Z,1668122334.197 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-11-10T23:18:54.197Z,1668122334.197 [Default:CheckIn] Stopped 2022-11-10T23:18:54.198Z,1668122334.198 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-11-10T23:18:54.198Z,1668122334.198 [Default:CheckIn](INFO): Running loop #32 2022-11-10T23:18:54.198Z,1668122334.198 [Default:CheckIn] Running Loop=32 2022-11-10T23:18:54.198Z,1668122334.198 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-11-10T23:18:54.198Z,1668122334.198 [Default:CheckIn:Read_GPS] Running Loop=1 2022-11-10T23:18:56.212Z,1668122336.212 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,231855.00,A,3648.17744,N,12147.27903,W,0.292,244.96,101122,,,D*72 2022-11-10T23:18:56.215Z,1668122336.215 [NAL9602](INFO): GPS fix at 20221110T231855: (36.802957, -121.787984) 2022-11-10T23:18:56.226Z,1668122336.226 [Default:CheckIn:Read_GPS] Stopped 2022-11-10T23:18:56.226Z,1668122336.226 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-11-10T23:19:03.109Z,1668122343.109 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20221110T210129/Courier0075.lzma 2022-11-10T23:19:04.112Z,1668122344.112 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Courier0075.lzma.bak 2022-11-10T23:19:04.112Z,1668122344.112 [DataOverHttps](INFO): SBD MOMSN=17282047 2022-11-10T23:19:06.703Z,1668122346.703 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-11-10T23:19:20.181Z,1668122360.181 [DataOverHttps](INFO): Sending 149 bytes from file Logs/20221110T210129/Express0076.lzma 2022-11-10T23:19:21.184Z,1668122361.184 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Express0076.lzma.bak 2022-11-10T23:19:21.184Z,1668122361.184 [DataOverHttps](INFO): SBD MOMSN=17282050 2022-11-10T23:19:21.651Z,1668122361.651 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-11-10T23:19:22.488Z,1668122362.488 [Default:CheckIn:Read_Iridium] Stopped 2022-11-10T23:19:22.488Z,1668122362.488 [Default:CheckIn:C.Wait] Running Loop=1 2022-11-10T23:19:22.488Z,1668122362.488 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-11-10T23:19:36.600Z,1668122376.600 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-11-10T23:19:51.954Z,1668122391.954 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-11-10T23:20:07.303Z,1668122407.303 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-11-10T23:20:22.255Z,1668122422.255 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-11-10T23:20:43.323Z,1668122443.323 [BPC1](INFO): Calculating totals. Valid battery stick count: 47. Valid reserve battery stick count: 6. 2022-11-10T23:20:43.338Z,1668122443.338 [BPC1](INFO): Received data from all battery sticks. 2022-11-10T23:22:30.396Z,1668122550.396 [NAL9602](INFO): SBD MO Status=2, MOMSN=37906, MT Status=2, MTMSN=0 2022-11-10T23:22:30.396Z,1668122550.396 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-11-10T23:23:23.328Z,1668122603.328 [NAL9602](INFO): SBD MO Status=2, MOMSN=37906, MT Status=2, MTMSN=0 2022-11-10T23:23:23.328Z,1668122603.328 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-11-10T23:23:56.456Z,1668122636.456 [NAL9602](INFO): SBD MO Status=2, MOMSN=37906, MT Status=2, MTMSN=0 2022-11-10T23:23:56.456Z,1668122636.456 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-11-10T23:23:58.475Z,1668122638.475 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-11-10T23:24:23.124Z,1668122663.124 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-11-10T23:24:23.124Z,1668122663.124 [Default:CheckIn:C.Wait] Stopped 2022-11-10T23:24:23.124Z,1668122663.124 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-11-10T23:24:23.125Z,1668122663.125 [Default:CheckIn:D] Running Loop=1 2022-11-10T23:24:23.553Z,1668122663.553 [Default:CheckIn:D] Stopped 2022-11-10T23:24:23.553Z,1668122663.553 [Default:CheckIn:E] Running Loop=1 2022-11-10T23:24:23.940Z,1668122663.940 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 188.149170 min 2022-11-10T23:24:23.940Z,1668122663.940 [Default:CheckIn:E] Stopped 2022-11-10T23:24:23.940Z,1668122663.940 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-11-10T23:24:23.940Z,1668122663.940 [Default:CheckIn] Stopped 2022-11-10T23:24:23.940Z,1668122663.940 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-11-10T23:24:23.940Z,1668122663.940 [Default:CheckIn](INFO): Running loop #33 2022-11-10T23:24:23.940Z,1668122663.940 [Default:CheckIn] Running Loop=33 2022-11-10T23:24:23.940Z,1668122663.940 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-11-10T23:24:23.941Z,1668122663.941 [Default:CheckIn:Read_GPS] Running Loop=1 2022-11-10T23:24:25.943Z,1668122665.943 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,232425.00,A,3648.17060,N,12147.28089,W,0.136,259.02,101122,,,D*73 2022-11-10T23:24:25.945Z,1668122665.945 [NAL9602](INFO): GPS fix at 20221110T232425: (36.802843, -121.788015) 2022-11-10T23:24:25.964Z,1668122665.964 [Default:CheckIn:Read_GPS] Stopped 2022-11-10T23:24:25.964Z,1668122665.964 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-11-10T23:24:26.985Z,1668122666.985 [Default:CheckIn:Read_Iridium] Stopped 2022-11-10T23:24:26.985Z,1668122666.985 [Default:CheckIn:C.Wait] Running Loop=1 2022-11-10T23:24:26.985Z,1668122666.985 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-11-10T23:24:58.409Z,1668122698.409 [NAL9602](INFO): Not Powering down - fast GPS 2022-11-10T23:29:27.555Z,1668122967.555 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-11-10T23:29:27.555Z,1668122967.555 [Default:CheckIn:C.Wait] Stopped 2022-11-10T23:29:27.555Z,1668122967.555 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-11-10T23:29:27.556Z,1668122967.556 [Default:CheckIn:D] Running Loop=1 2022-11-10T23:29:27.967Z,1668122967.967 [Default:CheckIn:D] Stopped 2022-11-10T23:29:27.967Z,1668122967.967 [Default:CheckIn:E] Running Loop=1 2022-11-10T23:29:28.378Z,1668122968.378 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 193.222738 min 2022-11-10T23:29:28.378Z,1668122968.378 [Default:CheckIn:E] Stopped 2022-11-10T23:29:28.379Z,1668122968.379 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-11-10T23:29:28.379Z,1668122968.379 [Default:CheckIn] Stopped 2022-11-10T23:29:28.379Z,1668122968.379 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-11-10T23:29:28.379Z,1668122968.379 [Default:CheckIn](INFO): Running loop #34 2022-11-10T23:29:28.379Z,1668122968.379 [Default:CheckIn] Running Loop=34 2022-11-10T23:29:28.379Z,1668122968.379 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-11-10T23:29:28.379Z,1668122968.379 [Default:CheckIn:Read_GPS] Running Loop=1 2022-11-10T23:29:30.380Z,1668122970.380 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,232929.00,A,3648.17020,N,12147.27930,W,0.700,157.58,101122,,,D*73 2022-11-10T23:29:30.383Z,1668122970.383 [NAL9602](INFO): GPS fix at 20221110T232929: (36.802837, -121.787988) 2022-11-10T23:29:30.393Z,1668122970.393 [Default:CheckIn:Read_GPS] Stopped 2022-11-10T23:29:30.393Z,1668122970.393 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-11-10T23:29:37.937Z,1668122977.937 [DataOverHttps](INFO): Sending 84 bytes from file Logs/20221110T210129/Courier0078.lzma 2022-11-10T23:29:39.236Z,1668122979.236 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Courier0078.lzma.bak 2022-11-10T23:29:39.236Z,1668122979.236 [DataOverHttps](INFO): SBD MOMSN=17282079 2022-11-10T23:29:54.757Z,1668122994.757 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20221110T210129/Courier0081.lzma 2022-11-10T23:29:55.760Z,1668122995.760 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Courier0081.lzma.bak 2022-11-10T23:29:55.760Z,1668122995.760 [DataOverHttps](INFO): SBD MOMSN=17282082 2022-11-10T23:30:01.079Z,1668123001.079 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-11-10T23:30:01.162Z,1668123001.162 [NAL9602](ERROR): received: +SBDI: 2, 37906, 2, 0, 0, 0 OK 2022-11-10T23:30:11.622Z,1668123011.622 [DataOverHttps](INFO): Sending 232 bytes from file Logs/20221110T210129/Express0079.lzma 2022-11-10T23:30:12.624Z,1668123012.624 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Express0079.lzma.bak 2022-11-10T23:30:12.624Z,1668123012.624 [DataOverHttps](INFO): SBD MOMSN=17282085 2022-11-10T23:30:31.057Z,1668123031.057 [DataOverHttps](INFO): Sending 137 bytes from file Logs/20221110T210129/Express0082.lzma 2022-11-10T23:30:32.060Z,1668123032.060 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Express0082.lzma.bak 2022-11-10T23:30:32.060Z,1668123032.060 [DataOverHttps](INFO): SBD MOMSN=17282089 2022-11-10T23:30:33.449Z,1668123033.449 [Default:CheckIn:Read_Iridium] Stopped 2022-11-10T23:30:33.449Z,1668123033.449 [Default:CheckIn:C.Wait] Running Loop=1 2022-11-10T23:30:33.458Z,1668123033.458 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-11-10T23:30:55.661Z,1668123055.661 [NAL9602](INFO): SBD MO Status=2, MOMSN=37906, MT Status=2, MTMSN=0 2022-11-10T23:30:55.661Z,1668123055.661 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-11-10T23:31:23.540Z,1668123083.540 [NAL9602](INFO): SBD MO Status=0, MOMSN=37906, MT Status=0, MTMSN=0 2022-11-10T23:31:23.540Z,1668123083.540 [NAL9602](INFO): No messages in MT queue 2022-11-10T23:31:54.240Z,1668123114.240 [NAL9602](INFO): Not Powering down - fast GPS 2022-11-10T23:35:34.031Z,1668123334.031 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-11-10T23:35:34.032Z,1668123334.032 [Default:CheckIn:C.Wait] Stopped 2022-11-10T23:35:34.032Z,1668123334.032 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-11-10T23:35:34.032Z,1668123334.032 [Default:CheckIn:D] Running Loop=1 2022-11-10T23:35:34.453Z,1668123334.453 [Default:CheckIn:D] Stopped 2022-11-10T23:35:34.454Z,1668123334.454 [Default:CheckIn:E] Running Loop=1 2022-11-10T23:35:34.844Z,1668123334.844 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 199.330843 min 2022-11-10T23:35:34.844Z,1668123334.844 [Default:CheckIn:E] Stopped 2022-11-10T23:35:34.845Z,1668123334.845 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-11-10T23:35:34.845Z,1668123334.845 [Default:CheckIn] Stopped 2022-11-10T23:35:34.845Z,1668123334.845 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-11-10T23:35:34.845Z,1668123334.845 [Default:CheckIn](INFO): Running loop #35 2022-11-10T23:35:34.845Z,1668123334.845 [Default:CheckIn] Running Loop=35 2022-11-10T23:35:34.845Z,1668123334.845 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-11-10T23:35:34.845Z,1668123334.845 [Default:CheckIn:Read_GPS] Running Loop=1 2022-11-10T23:35:36.853Z,1668123336.853 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,233536.00,A,3648.17000,N,12147.27769,W,0.156,137.98,101122,,,D*7F 2022-11-10T23:35:36.855Z,1668123336.855 [NAL9602](INFO): GPS fix at 20221110T233536: (36.802833, -121.787961) 2022-11-10T23:35:36.865Z,1668123336.865 [Default:CheckIn:Read_GPS] Stopped 2022-11-10T23:35:36.866Z,1668123336.866 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-11-10T23:35:44.017Z,1668123344.017 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20221110T210129/Courier0084.lzma 2022-11-10T23:35:45.020Z,1668123345.020 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Courier0084.lzma.bak 2022-11-10T23:35:45.020Z,1668123345.020 [DataOverHttps](INFO): SBD MOMSN=17282093 2022-11-10T23:35:59.886Z,1668123359.886 [NAL9602](INFO): SBD MO Status=2, MOMSN=37907, MT Status=2, MTMSN=0 2022-11-10T23:35:59.886Z,1668123359.886 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-11-10T23:36:00.785Z,1668123360.785 [DataOverHttps](INFO): Sending 149 bytes from file Logs/20221110T210129/Express0085.lzma 2022-11-10T23:36:01.788Z,1668123361.788 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Express0085.lzma.bak 2022-11-10T23:36:01.788Z,1668123361.788 [DataOverHttps](INFO): SBD MOMSN=17282096 2022-11-10T23:36:03.127Z,1668123363.127 [Default:CheckIn:Read_Iridium] Stopped 2022-11-10T23:36:03.127Z,1668123363.127 [Default:CheckIn:C.Wait] Running Loop=1 2022-11-10T23:36:03.127Z,1668123363.127 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-11-10T23:36:34.224Z,1668123394.224 [NAL9602](INFO): SBD MO Status=2, MOMSN=37907, MT Status=2, MTMSN=0 2022-11-10T23:36:34.224Z,1668123394.224 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-11-10T23:40:39.499Z,1668123639.499 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-11-10T23:41:03.779Z,1668123663.779 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-11-10T23:41:03.779Z,1668123663.779 [Default:CheckIn:C.Wait] Stopped 2022-11-10T23:41:03.779Z,1668123663.779 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-11-10T23:41:03.780Z,1668123663.780 [Default:CheckIn:D] Running Loop=1 2022-11-10T23:41:04.168Z,1668123664.168 [Default:CheckIn:D] Stopped 2022-11-10T23:41:04.168Z,1668123664.168 [Default:CheckIn:E] Running Loop=1 2022-11-10T23:41:04.561Z,1668123664.561 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 204.826090 min 2022-11-10T23:41:04.561Z,1668123664.561 [Default:CheckIn:E] Stopped 2022-11-10T23:41:04.562Z,1668123664.562 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-11-10T23:41:04.562Z,1668123664.562 [Default:CheckIn] Stopped 2022-11-10T23:41:04.562Z,1668123664.562 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-11-10T23:41:04.562Z,1668123664.562 [Default:CheckIn](INFO): Running loop #36 2022-11-10T23:41:04.562Z,1668123664.562 [Default:CheckIn] Running Loop=36 2022-11-10T23:41:04.562Z,1668123664.562 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-11-10T23:41:04.562Z,1668123664.562 [Default:CheckIn:Read_GPS] Running Loop=1 2022-11-10T23:41:06.570Z,1668123666.570 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,234105.00,A,3648.17104,N,12147.28211,W,0.097,181.58,101122,,,D*71 2022-11-10T23:41:06.572Z,1668123666.572 [NAL9602](INFO): GPS fix at 20221110T234105: (36.802851, -121.788035) 2022-11-10T23:41:06.599Z,1668123666.599 [Default:CheckIn:Read_GPS] Stopped 2022-11-10T23:41:06.599Z,1668123666.599 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-11-10T23:41:13.785Z,1668123673.785 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20221110T210129/Courier0087.lzma 2022-11-10T23:41:14.788Z,1668123674.788 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Courier0087.lzma.bak 2022-11-10T23:41:14.788Z,1668123674.788 [DataOverHttps](INFO): SBD MOMSN=17282122 2022-11-10T23:41:30.730Z,1668123690.730 [DataOverHttps](INFO): Sending 228 bytes from file Logs/20221110T210129/Express0088.lzma 2022-11-10T23:41:31.732Z,1668123691.732 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Express0088.lzma.bak 2022-11-10T23:41:31.732Z,1668123691.732 [DataOverHttps](INFO): SBD MOMSN=17282125 2022-11-10T23:41:32.840Z,1668123692.840 [Default:CheckIn:Read_Iridium] Stopped 2022-11-10T23:41:32.841Z,1668123692.841 [Default:CheckIn:C.Wait] Running Loop=1 2022-11-10T23:41:32.841Z,1668123692.841 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-11-10T23:41:38.485Z,1668123698.485 [NAL9602](INFO): Not Powering down - fast GPS 2022-11-10T23:46:33.425Z,1668123993.425 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-11-10T23:46:33.425Z,1668123993.425 [Default:CheckIn:C.Wait] Stopped 2022-11-10T23:46:33.425Z,1668123993.425 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-11-10T23:46:33.426Z,1668123993.426 [Default:CheckIn:D] Running Loop=1 2022-11-10T23:46:33.841Z,1668123993.841 [Default:CheckIn:D] Stopped 2022-11-10T23:46:33.841Z,1668123993.841 [Default:CheckIn:E] Running Loop=1 2022-11-10T23:46:34.236Z,1668123994.236 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 210.320638 min 2022-11-10T23:46:34.236Z,1668123994.236 [Default:CheckIn:E] Stopped 2022-11-10T23:46:34.237Z,1668123994.237 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-11-10T23:46:34.237Z,1668123994.237 [Default:CheckIn] Stopped 2022-11-10T23:46:34.237Z,1668123994.237 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-11-10T23:46:34.237Z,1668123994.237 [Default:CheckIn](INFO): Running loop #37 2022-11-10T23:46:34.237Z,1668123994.237 [Default:CheckIn] Running Loop=37 2022-11-10T23:46:34.237Z,1668123994.237 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-11-10T23:46:34.238Z,1668123994.238 [Default:CheckIn:Read_GPS] Running Loop=1 2022-11-10T23:46:36.249Z,1668123996.249 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,234635.00,A,3648.17006,N,12147.28129,W,0.175,69.78,101122,,,D*46 2022-11-10T23:46:36.251Z,1668123996.251 [NAL9602](INFO): GPS fix at 20221110T234635: (36.802834, -121.788021) 2022-11-10T23:46:36.262Z,1668123996.262 [Default:CheckIn:Read_GPS] Stopped 2022-11-10T23:46:36.262Z,1668123996.262 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-11-10T23:46:43.677Z,1668124003.677 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20221110T210129/Courier0090.lzma 2022-11-10T23:46:44.680Z,1668124004.680 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Courier0090.lzma.bak 2022-11-10T23:46:44.680Z,1668124004.680 [DataOverHttps](INFO): SBD MOMSN=17282129 2022-11-10T23:47:00.565Z,1668124020.565 [DataOverHttps](INFO): Sending 140 bytes from file Logs/20221110T210129/Express0091.lzma 2022-11-10T23:47:01.568Z,1668124021.568 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Express0091.lzma.bak 2022-11-10T23:47:01.568Z,1668124021.568 [DataOverHttps](INFO): SBD MOMSN=17282132 2022-11-10T23:47:02.939Z,1668124022.939 [Default:CheckIn:Read_Iridium] Stopped 2022-11-10T23:47:02.939Z,1668124022.939 [Default:CheckIn:C.Wait] Running Loop=1 2022-11-10T23:47:02.939Z,1668124022.939 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-11-10T23:51:38.479Z,1668124298.479 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-11-10T23:52:03.540Z,1668124323.540 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-11-10T23:52:03.541Z,1668124323.541 [Default:CheckIn:C.Wait] Stopped 2022-11-10T23:52:03.541Z,1668124323.541 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-11-10T23:52:03.541Z,1668124323.541 [Default:CheckIn:D] Running Loop=1 2022-11-10T23:52:03.956Z,1668124323.956 [Default:CheckIn:D] Stopped 2022-11-10T23:52:03.957Z,1668124323.957 [Default:CheckIn:E] Running Loop=1 2022-11-10T23:52:04.343Z,1668124324.343 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 215.822559 min 2022-11-10T23:52:04.343Z,1668124324.343 [Default:CheckIn:E] Stopped 2022-11-10T23:52:04.344Z,1668124324.344 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-11-10T23:52:04.344Z,1668124324.344 [Default:CheckIn] Stopped 2022-11-10T23:52:04.344Z,1668124324.344 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-11-10T23:52:04.344Z,1668124324.344 [Default:CheckIn](INFO): Running loop #38 2022-11-10T23:52:04.344Z,1668124324.344 [Default:CheckIn] Running Loop=38 2022-11-10T23:52:04.344Z,1668124324.344 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-11-10T23:52:04.344Z,1668124324.344 [Default:CheckIn:Read_GPS] Running Loop=1 2022-11-10T23:52:06.360Z,1668124326.360 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,235205.00,A,3648.16972,N,12147.27744,W,0.253,6.97,101122,,,D*76 2022-11-10T23:52:06.363Z,1668124326.363 [NAL9602](INFO): GPS fix at 20221110T235205: (36.802829, -121.787957) 2022-11-10T23:52:06.373Z,1668124326.373 [Default:CheckIn:Read_GPS] Stopped 2022-11-10T23:52:06.373Z,1668124326.373 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-11-10T23:52:13.365Z,1668124333.365 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20221110T210129/Courier0093.lzma 2022-11-10T23:52:14.368Z,1668124334.368 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Courier0093.lzma.bak 2022-11-10T23:52:14.368Z,1668124334.368 [DataOverHttps](INFO): SBD MOMSN=17282195 2022-11-10T23:52:33.362Z,1668124353.362 [DataOverHttps](INFO): Sending 217 bytes from file Logs/20221110T210129/Express0094.lzma 2022-11-10T23:52:34.363Z,1668124354.363 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Express0094.lzma.bak 2022-11-10T23:52:34.364Z,1668124354.364 [DataOverHttps](INFO): SBD MOMSN=17282198 2022-11-10T23:52:35.515Z,1668124355.515 [Default:CheckIn:Read_Iridium] Stopped 2022-11-10T23:52:35.515Z,1668124355.515 [Default:CheckIn:C.Wait] Running Loop=1 2022-11-10T23:52:35.515Z,1668124355.515 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-11-10T23:52:38.327Z,1668124358.327 [NAL9602](INFO): Not Powering down - fast GPS 2022-11-10T23:57:36.088Z,1668124656.088 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-11-10T23:57:36.088Z,1668124656.088 [Default:CheckIn:C.Wait] Stopped 2022-11-10T23:57:36.088Z,1668124656.088 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-11-10T23:57:36.088Z,1668124656.088 [Default:CheckIn:D] Running Loop=1 2022-11-10T23:57:36.488Z,1668124656.488 [Default:CheckIn:D] Stopped 2022-11-10T23:57:36.488Z,1668124656.488 [Default:CheckIn:E] Running Loop=1 2022-11-10T23:57:36.902Z,1668124656.902 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 221.364746 min 2022-11-10T23:57:36.902Z,1668124656.902 [Default:CheckIn:E] Stopped 2022-11-10T23:57:36.903Z,1668124656.903 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-11-10T23:57:36.903Z,1668124656.903 [Default:CheckIn] Stopped 2022-11-10T23:57:36.903Z,1668124656.903 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-11-10T23:57:36.903Z,1668124656.903 [Default:CheckIn](INFO): Running loop #39 2022-11-10T23:57:36.903Z,1668124656.903 [Default:CheckIn] Running Loop=39 2022-11-10T23:57:36.903Z,1668124656.903 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-11-10T23:57:36.903Z,1668124656.903 [Default:CheckIn:Read_GPS] Running Loop=1 2022-11-10T23:57:38.909Z,1668124658.908 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,235738.00,A,3648.16711,N,12147.27505,W,0.486,126.13,101122,,,D*70 2022-11-10T23:57:38.911Z,1668124658.911 [NAL9602](INFO): GPS fix at 20221110T235738: (36.802785, -121.787918) 2022-11-10T23:57:38.942Z,1668124658.942 [Default:CheckIn:Read_GPS] Stopped 2022-11-10T23:57:38.942Z,1668124658.942 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-11-10T23:57:45.885Z,1668124665.885 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20221110T210129/Courier0096.lzma 2022-11-10T23:57:46.887Z,1668124666.887 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Courier0096.lzma.bak 2022-11-10T23:57:46.888Z,1668124666.888 [DataOverHttps](INFO): SBD MOMSN=17282202 2022-11-10T23:58:02.601Z,1668124682.601 [DataOverHttps](INFO): Sending 141 bytes from file Logs/20221110T210129/Express0097.lzma 2022-11-10T23:58:03.604Z,1668124683.604 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Express0097.lzma.bak 2022-11-10T23:58:03.604Z,1668124683.604 [DataOverHttps](INFO): SBD MOMSN=17282205 2022-11-10T23:58:04.780Z,1668124684.780 [Default:CheckIn:Read_Iridium] Stopped 2022-11-10T23:58:04.780Z,1668124684.780 [Default:CheckIn:C.Wait] Running Loop=1 2022-11-10T23:58:04.780Z,1668124684.780 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-11-10T23:58:09.607Z,1668124689.607 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-11-10T23:58:09.682Z,1668124689.682 [NAL9602](ERROR): received: +CSQ:0 OK907, 2, 0, 0, 0 OK 2022-11-11T00:02:22.511Z,1668124942.511 [NAL9602](INFO): SBD MO Status=2, MOMSN=37907, MT Status=2, MTMSN=0 2022-11-11T00:02:22.511Z,1668124942.511 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-11-11T00:02:41.499Z,1668124961.499 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-11-11T00:03:05.357Z,1668124985.357 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-11-11T00:03:05.357Z,1668124985.357 [Default:CheckIn:C.Wait] Stopped 2022-11-11T00:03:05.357Z,1668124985.357 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-11-11T00:03:05.357Z,1668124985.357 [Default:CheckIn:D] Running Loop=1 2022-11-11T00:03:05.747Z,1668124985.747 [Default:CheckIn:D] Stopped 2022-11-11T00:03:05.747Z,1668124985.747 [Default:CheckIn:E] Running Loop=1 2022-11-11T00:03:06.151Z,1668124986.151 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 226.852409 min 2022-11-11T00:03:06.152Z,1668124986.152 [Default:CheckIn:E] Stopped 2022-11-11T00:03:06.152Z,1668124986.152 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-11-11T00:03:06.152Z,1668124986.152 [Default:CheckIn] Stopped 2022-11-11T00:03:06.152Z,1668124986.152 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-11-11T00:03:06.152Z,1668124986.152 [Default:CheckIn](INFO): Running loop #40 2022-11-11T00:03:06.152Z,1668124986.152 [Default:CheckIn] Running Loop=40 2022-11-11T00:03:06.152Z,1668124986.152 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-11-11T00:03:06.152Z,1668124986.152 [Default:CheckIn:Read_GPS] Running Loop=1 2022-11-11T00:03:08.165Z,1668124988.165 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,000307.00,A,3648.17053,N,12147.28396,W,0.078,302.78,111122,,,D*72 2022-11-11T00:03:08.167Z,1668124988.167 [NAL9602](INFO): GPS fix at 20221111T000307: (36.802842, -121.788066) 2022-11-11T00:03:08.177Z,1668124988.177 [Default:CheckIn:Read_GPS] Stopped 2022-11-11T00:03:08.177Z,1668124988.177 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-11-11T00:03:15.837Z,1668124995.837 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20221110T210129/Courier0099.lzma 2022-11-11T00:03:16.840Z,1668124996.840 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Courier0099.lzma.bak 2022-11-11T00:03:16.840Z,1668124996.840 [DataOverHttps](INFO): SBD MOMSN=17282214 2022-11-11T00:03:32.720Z,1668125012.720 [DataOverHttps](INFO): Sending 228 bytes from file Logs/20221110T210129/Express0100.lzma 2022-11-11T00:03:33.720Z,1668125013.720 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Express0100.lzma.bak 2022-11-11T00:03:33.720Z,1668125013.720 [DataOverHttps](INFO): SBD MOMSN=17282217 2022-11-11T00:03:34.909Z,1668125014.909 [Default:CheckIn:Read_Iridium] Stopped 2022-11-11T00:03:34.909Z,1668125014.909 [Default:CheckIn:C.Wait] Running Loop=1 2022-11-11T00:03:34.910Z,1668125014.910 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-11-11T00:03:40.520Z,1668125020.520 [NAL9602](INFO): Not Powering down - fast GPS 2022-11-11T00:08:35.444Z,1668125315.444 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-11-11T00:08:35.444Z,1668125315.444 [Default:CheckIn:C.Wait] Stopped 2022-11-11T00:08:35.444Z,1668125315.444 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-11-11T00:08:35.445Z,1668125315.445 [Default:CheckIn:D] Running Loop=1 2022-11-11T00:08:35.845Z,1668125315.845 [Default:CheckIn:D] Stopped 2022-11-11T00:08:35.845Z,1668125315.845 [Default:CheckIn:E] Running Loop=1 2022-11-11T00:08:36.265Z,1668125316.265 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 232.354036 min 2022-11-11T00:08:36.265Z,1668125316.265 [Default:CheckIn:E] Stopped 2022-11-11T00:08:36.265Z,1668125316.265 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-11-11T00:08:36.265Z,1668125316.265 [Default:CheckIn] Stopped 2022-11-11T00:08:36.265Z,1668125316.265 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-11-11T00:08:36.266Z,1668125316.266 [Default:CheckIn](INFO): Running loop #41 2022-11-11T00:08:36.266Z,1668125316.266 [Default:CheckIn] Running Loop=41 2022-11-11T00:08:36.266Z,1668125316.266 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-11-11T00:08:36.266Z,1668125316.266 [Default:CheckIn:Read_GPS] Running Loop=1 2022-11-11T00:08:38.264Z,1668125318.264 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,000837.00,A,3648.16798,N,12147.28002,W,0.855,128.96,111122,,,D*78 2022-11-11T00:08:38.267Z,1668125318.267 [NAL9602](INFO): GPS fix at 20221111T000837: (36.802800, -121.788000) 2022-11-11T00:08:38.281Z,1668125318.281 [Default:CheckIn:Read_GPS] Stopped 2022-11-11T00:08:38.281Z,1668125318.281 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-11-11T00:08:46.233Z,1668125326.233 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20221110T210129/Courier0102.lzma 2022-11-11T00:08:47.236Z,1668125327.236 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Courier0102.lzma.bak 2022-11-11T00:08:47.236Z,1668125327.236 [DataOverHttps](INFO): SBD MOMSN=17282260 2022-11-11T00:09:02.965Z,1668125342.965 [DataOverHttps](INFO): Sending 140 bytes from file Logs/20221110T210129/Express0103.lzma 2022-11-11T00:09:03.968Z,1668125343.968 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Express0103.lzma.bak 2022-11-11T00:09:03.968Z,1668125343.968 [DataOverHttps](INFO): SBD MOMSN=17282263 2022-11-11T00:09:05.350Z,1668125345.350 [Default:CheckIn:Read_Iridium] Stopped 2022-11-11T00:09:05.350Z,1668125345.350 [Default:CheckIn:C.Wait] Running Loop=1 2022-11-11T00:09:05.350Z,1668125345.350 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-11-11T00:09:08.963Z,1668125348.963 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-11-11T00:09:09.038Z,1668125349.038 [NAL9602](ERROR): received: +CSQ:0 OK907, 2, 0, 0, 0 OK 2022-11-11T00:13:40.465Z,1668125620.465 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-11-11T00:14:05.925Z,1668125645.925 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-11-11T00:14:05.925Z,1668125645.925 [Default:CheckIn:C.Wait] Stopped 2022-11-11T00:14:05.925Z,1668125645.925 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-11-11T00:14:05.949Z,1668125645.949 [Default:CheckIn:D] Running Loop=1 2022-11-11T00:14:06.328Z,1668125646.328 [Default:CheckIn:D] Stopped 2022-11-11T00:14:06.328Z,1668125646.328 [Default:CheckIn:E] Running Loop=1 2022-11-11T00:14:06.728Z,1668125646.728 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 237.862093 min 2022-11-11T00:14:06.728Z,1668125646.728 [Default:CheckIn:E] Stopped 2022-11-11T00:14:06.728Z,1668125646.728 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-11-11T00:14:06.728Z,1668125646.728 [Default:CheckIn] Stopped 2022-11-11T00:14:06.729Z,1668125646.729 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-11-11T00:14:06.729Z,1668125646.729 [Default:CheckIn](INFO): Running loop #42 2022-11-11T00:14:06.729Z,1668125646.729 [Default:CheckIn] Running Loop=42 2022-11-11T00:14:06.729Z,1668125646.729 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-11-11T00:14:06.729Z,1668125646.729 [Default:CheckIn:Read_GPS] Running Loop=1 2022-11-11T00:14:08.741Z,1668125648.741 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,001408.00,A,3648.17062,N,12147.28335,W,0.369,13.72,111122,,,D*4A 2022-11-11T00:14:08.753Z,1668125648.753 [NAL9602](INFO): GPS fix at 20221111T001408: (36.802844, -121.788056) 2022-11-11T00:14:08.764Z,1668125648.764 [Default:CheckIn:Read_GPS] Stopped 2022-11-11T00:14:08.764Z,1668125648.764 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-11-11T00:14:16.345Z,1668125656.345 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20221110T210129/Courier0105.lzma 2022-11-11T00:14:17.348Z,1668125657.348 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Courier0105.lzma.bak 2022-11-11T00:14:17.349Z,1668125657.349 [DataOverHttps](INFO): SBD MOMSN=17282273 2022-11-11T00:14:35.869Z,1668125675.869 [DataOverHttps](INFO): Sending 215 bytes from file Logs/20221110T210129/Express0106.lzma 2022-11-11T00:14:36.872Z,1668125676.872 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Express0106.lzma.bak 2022-11-11T00:14:36.872Z,1668125676.872 [DataOverHttps](INFO): SBD MOMSN=17282276 2022-11-11T00:14:38.311Z,1668125678.311 [Default:CheckIn:Read_Iridium] Stopped 2022-11-11T00:14:38.311Z,1668125678.311 [Default:CheckIn:C.Wait] Running Loop=1 2022-11-11T00:14:38.311Z,1668125678.311 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-11-11T00:14:41.534Z,1668125681.534 [NAL9602](INFO): Not Powering down - fast GPS 2022-11-11T00:19:38.893Z,1668125978.893 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-11-11T00:19:38.893Z,1668125978.893 [Default:CheckIn:C.Wait] Stopped 2022-11-11T00:19:38.893Z,1668125978.893 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-11-11T00:19:38.893Z,1668125978.893 [Default:CheckIn:D] Running Loop=1 2022-11-11T00:19:39.309Z,1668125979.309 [Default:CheckIn:D] Stopped 2022-11-11T00:19:39.309Z,1668125979.309 [Default:CheckIn:E] Running Loop=1 2022-11-11T00:19:39.700Z,1668125979.700 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 243.411768 min 2022-11-11T00:19:39.700Z,1668125979.700 [Default:CheckIn:E] Stopped 2022-11-11T00:19:39.700Z,1668125979.700 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-11-11T00:19:39.700Z,1668125979.700 [Default:CheckIn] Stopped 2022-11-11T00:19:39.700Z,1668125979.700 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-11-11T00:19:39.700Z,1668125979.700 [Default:CheckIn](INFO): Running loop #43 2022-11-11T00:19:39.700Z,1668125979.700 [Default:CheckIn] Running Loop=43 2022-11-11T00:19:39.700Z,1668125979.700 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-11-11T00:19:39.700Z,1668125979.700 [Default:CheckIn:Read_GPS] Running Loop=1 2022-11-11T00:19:41.716Z,1668125981.716 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,001941.00,A,3648.16869,N,12147.27034,W,0.467,125.38,111122,,,D*76 2022-11-11T00:19:41.719Z,1668125981.719 [NAL9602](INFO): GPS fix at 20221111T001941: (36.802811, -121.787839) 2022-11-11T00:19:41.729Z,1668125981.729 [Default:CheckIn:Read_GPS] Stopped 2022-11-11T00:19:41.730Z,1668125981.730 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-11-11T00:19:48.734Z,1668125988.734 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20221110T210129/Courier0108.lzma 2022-11-11T00:19:49.736Z,1668125989.736 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Courier0108.lzma.bak 2022-11-11T00:19:49.736Z,1668125989.736 [DataOverHttps](INFO): SBD MOMSN=17282325 2022-11-11T00:20:05.461Z,1668126005.461 [DataOverHttps](INFO): Sending 155 bytes from file Logs/20221110T210129/Express0109.lzma 2022-11-11T00:20:06.464Z,1668126006.464 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Express0109.lzma.bak 2022-11-11T00:20:06.464Z,1668126006.464 [DataOverHttps](INFO): SBD MOMSN=17282330 2022-11-11T00:20:07.578Z,1668126007.578 [Default:CheckIn:Read_Iridium] Stopped 2022-11-11T00:20:07.578Z,1668126007.578 [Default:CheckIn:C.Wait] Running Loop=1 2022-11-11T00:20:07.578Z,1668126007.578 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-11-11T00:20:12.431Z,1668126012.431 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-11-11T00:20:12.505Z,1668126012.505 [NAL9602](ERROR): received: +CSQ:0 OK907, 2, 0, 0, 0 OK 2022-11-11T00:23:07.760Z,1668126187.760 [NAL9602](INFO): SBD MO Status=2, MOMSN=37907, MT Status=2, MTMSN=0 2022-11-11T00:23:07.760Z,1668126187.760 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-11-11T00:23:20.679Z,1668126200.679 [NAL9602](INFO): SBD MO Status=2, MOMSN=37907, MT Status=2, MTMSN=0 2022-11-11T00:23:20.680Z,1668126200.680 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-11-11T00:24:44.309Z,1668126284.309 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-11-11T00:25:08.174Z,1668126308.174 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-11-11T00:25:08.174Z,1668126308.174 [Default:CheckIn:C.Wait] Stopped 2022-11-11T00:25:08.174Z,1668126308.174 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-11-11T00:25:08.174Z,1668126308.174 [Default:CheckIn:D] Running Loop=1 2022-11-11T00:25:08.556Z,1668126308.556 [Default:CheckIn:D] Stopped 2022-11-11T00:25:08.556Z,1668126308.556 [Default:CheckIn:E] Running Loop=1 2022-11-11T00:25:08.965Z,1668126308.965 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 248.899219 min 2022-11-11T00:25:08.965Z,1668126308.965 [Default:CheckIn:E] Stopped 2022-11-11T00:25:08.966Z,1668126308.966 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-11-11T00:25:08.966Z,1668126308.966 [Default:CheckIn] Stopped 2022-11-11T00:25:08.966Z,1668126308.966 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-11-11T00:25:08.966Z,1668126308.966 [Default:CheckIn](INFO): Running loop #44 2022-11-11T00:25:08.966Z,1668126308.966 [Default:CheckIn] Running Loop=44 2022-11-11T00:25:08.966Z,1668126308.966 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-11-11T00:25:08.966Z,1668126308.966 [Default:CheckIn:Read_GPS] Running Loop=1 2022-11-11T00:25:10.973Z,1668126310.973 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,002510.00,A,3648.16961,N,12147.28067,W,0.078,130.12,111122,,,D*7B 2022-11-11T00:25:10.975Z,1668126310.975 [NAL9602](INFO): GPS fix at 20221111T002510: (36.802827, -121.788011) 2022-11-11T00:25:10.986Z,1668126310.986 [Default:CheckIn:Read_GPS] Stopped 2022-11-11T00:25:10.986Z,1668126310.986 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-11-11T00:25:18.937Z,1668126318.937 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20221110T210129/Courier0111.lzma 2022-11-11T00:25:19.940Z,1668126319.940 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Courier0111.lzma.bak 2022-11-11T00:25:19.940Z,1668126319.940 [DataOverHttps](INFO): SBD MOMSN=17282340 2022-11-11T00:25:35.677Z,1668126335.677 [DataOverHttps](INFO): Sending 236 bytes from file Logs/20221110T210129/Express0112.lzma 2022-11-11T00:25:36.680Z,1668126336.680 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Express0112.lzma.bak 2022-11-11T00:25:36.680Z,1668126336.680 [DataOverHttps](INFO): SBD MOMSN=17282343 2022-11-11T00:25:38.079Z,1668126338.079 [Default:CheckIn:Read_Iridium] Stopped 2022-11-11T00:25:38.079Z,1668126338.079 [Default:CheckIn:C.Wait] Running Loop=1 2022-11-11T00:25:38.079Z,1668126338.079 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-11-11T00:25:42.883Z,1668126342.883 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-11-11T00:25:43.299Z,1668126343.299 [NAL9602](INFO): Not Powering down - fast GPS 2022-11-11T00:25:57.832Z,1668126357.832 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-11-11T00:26:12.779Z,1668126372.779 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-11-11T00:26:28.132Z,1668126388.132 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-11-11T00:26:43.484Z,1668126403.484 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-11-11T00:26:59.241Z,1668126419.241 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-11-11T00:27:14.997Z,1668126434.997 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-11-11T00:27:29.947Z,1668126449.947 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-11-11T00:27:45.299Z,1668126465.299 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-11-11T00:28:11.971Z,1668126491.971 [BPC1](INFO): Calculating totals. Valid battery stick count: 48. Valid reserve battery stick count: 5. 2022-11-11T00:28:11.994Z,1668126491.994 [BPC1](INFO): Received data from all battery sticks. 2022-11-11T00:30:38.634Z,1668126638.634 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-11-11T00:30:38.634Z,1668126638.634 [Default:CheckIn:C.Wait] Stopped 2022-11-11T00:30:38.634Z,1668126638.634 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-11-11T00:30:38.634Z,1668126638.634 [Default:CheckIn:D] Running Loop=1 2022-11-11T00:30:39.031Z,1668126639.031 [Default:CheckIn:D] Stopped 2022-11-11T00:30:39.031Z,1668126639.031 [Default:CheckIn:E] Running Loop=1 2022-11-11T00:30:39.435Z,1668126639.435 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 254.407129 min 2022-11-11T00:30:39.435Z,1668126639.435 [Default:CheckIn:E] Stopped 2022-11-11T00:30:39.435Z,1668126639.435 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-11-11T00:30:39.435Z,1668126639.435 [Default:CheckIn] Stopped 2022-11-11T00:30:39.435Z,1668126639.435 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-11-11T00:30:39.436Z,1668126639.436 [Default:CheckIn](INFO): Running loop #45 2022-11-11T00:30:39.436Z,1668126639.436 [Default:CheckIn] Running Loop=45 2022-11-11T00:30:39.436Z,1668126639.436 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-11-11T00:30:39.436Z,1668126639.436 [Default:CheckIn:Read_GPS] Running Loop=1 2022-11-11T00:30:41.448Z,1668126641.448 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,003040.00,A,3648.16855,N,12147.27992,W,0.097,354.46,111122,,,D*70 2022-11-11T00:30:41.451Z,1668126641.451 [NAL9602](INFO): GPS fix at 20221111T003040: (36.802809, -121.787999) 2022-11-11T00:30:41.461Z,1668126641.461 [Default:CheckIn:Read_GPS] Stopped 2022-11-11T00:30:41.461Z,1668126641.461 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-11-11T00:30:49.173Z,1668126649.173 [DataOverHttps](INFO): Sending 82 bytes from file Logs/20221110T210129/Courier0114.lzma 2022-11-11T00:30:50.176Z,1668126650.176 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Courier0114.lzma.bak 2022-11-11T00:30:50.176Z,1668126650.176 [DataOverHttps](INFO): SBD MOMSN=17282354 2022-11-11T00:31:06.373Z,1668126666.373 [DataOverHttps](INFO): Sending 140 bytes from file Logs/20221110T210129/Express0115.lzma 2022-11-11T00:31:07.376Z,1668126667.376 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Express0115.lzma.bak 2022-11-11T00:31:07.376Z,1668126667.376 [DataOverHttps](INFO): SBD MOMSN=17282357 2022-11-11T00:31:08.538Z,1668126668.538 [Default:CheckIn:Read_Iridium] Stopped 2022-11-11T00:31:08.538Z,1668126668.538 [Default:CheckIn:C.Wait] Running Loop=1 2022-11-11T00:31:08.538Z,1668126668.538 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-11-11T00:31:55.792Z,1668126715.792 [NAL9602](INFO): SBD MO Status=2, MOMSN=37907, MT Status=2, MTMSN=0 2022-11-11T00:31:55.792Z,1668126715.792 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-11-11T00:32:34.977Z,1668126754.977 [NAL9602](INFO): SBD MO Status=2, MOMSN=37907, MT Status=2, MTMSN=0 2022-11-11T00:32:34.978Z,1668126754.978 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-11-11T00:33:04.867Z,1668126784.867 [NAL9602](INFO): SBD MO Status=2, MOMSN=37907, MT Status=2, MTMSN=0 2022-11-11T00:33:04.867Z,1668126784.867 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-11-11T00:35:43.249Z,1668126943.249 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-11-11T00:36:09.116Z,1668126969.116 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-11-11T00:36:09.116Z,1668126969.116 [Default:CheckIn:C.Wait] Stopped 2022-11-11T00:36:09.116Z,1668126969.116 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-11-11T00:36:09.117Z,1668126969.117 [Default:CheckIn:D] Running Loop=1 2022-11-11T00:36:09.533Z,1668126969.533 [Default:CheckIn:D] Stopped 2022-11-11T00:36:09.533Z,1668126969.533 [Default:CheckIn:E] Running Loop=1 2022-11-11T00:36:09.928Z,1668126969.928 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 259.915511 min 2022-11-11T00:36:09.928Z,1668126969.928 [Default:CheckIn:E] Stopped 2022-11-11T00:36:09.929Z,1668126969.929 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-11-11T00:36:09.929Z,1668126969.929 [Default:CheckIn] Stopped 2022-11-11T00:36:09.929Z,1668126969.929 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-11-11T00:36:09.929Z,1668126969.929 [Default:CheckIn](INFO): Running loop #46 2022-11-11T00:36:09.929Z,1668126969.929 [Default:CheckIn] Running Loop=46 2022-11-11T00:36:09.929Z,1668126969.929 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-11-11T00:36:09.929Z,1668126969.929 [Default:CheckIn:Read_GPS] Running Loop=1 2022-11-11T00:36:11.936Z,1668126971.936 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,003611.00,A,3648.16589,N,12147.27747,W,0.156,100.51,111122,,,D*71 2022-11-11T00:36:11.939Z,1668126971.939 [NAL9602](INFO): GPS fix at 20221111T003611: (36.802765, -121.787958) 2022-11-11T00:36:11.969Z,1668126971.969 [Default:CheckIn:Read_GPS] Stopped 2022-11-11T00:36:11.969Z,1668126971.969 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-11-11T00:36:18.827Z,1668126978.827 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20221110T210129/Courier0117.lzma 2022-11-11T00:36:19.828Z,1668126979.828 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Courier0117.lzma.bak 2022-11-11T00:36:19.828Z,1668126979.828 [DataOverHttps](INFO): SBD MOMSN=17282360 2022-11-11T00:36:38.701Z,1668126998.701 [DataOverHttps](INFO): Sending 230 bytes from file Logs/20221110T210129/Express0118.lzma 2022-11-11T00:36:39.704Z,1668126999.704 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Express0118.lzma.bak 2022-11-11T00:36:39.704Z,1668126999.704 [DataOverHttps](INFO): SBD MOMSN=17282363 2022-11-11T00:36:41.085Z,1668127001.085 [Default:CheckIn:Read_Iridium] Stopped 2022-11-11T00:36:41.085Z,1668127001.085 [Default:CheckIn:C.Wait] Running Loop=1 2022-11-11T00:36:41.085Z,1668127001.085 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-11-11T00:36:44.295Z,1668127004.295 [NAL9602](INFO): Not Powering down - fast GPS 2022-11-11T00:41:41.660Z,1668127301.660 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-11-11T00:41:41.660Z,1668127301.660 [Default:CheckIn:C.Wait] Stopped 2022-11-11T00:41:41.660Z,1668127301.660 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-11-11T00:41:41.661Z,1668127301.661 [Default:CheckIn:D] Running Loop=1 2022-11-11T00:41:42.069Z,1668127302.069 [Default:CheckIn:D] Stopped 2022-11-11T00:41:42.069Z,1668127302.069 [Default:CheckIn:E] Running Loop=1 2022-11-11T00:41:42.465Z,1668127302.465 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 265.457764 min 2022-11-11T00:41:42.465Z,1668127302.465 [Default:CheckIn:E] Stopped 2022-11-11T00:41:42.465Z,1668127302.465 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-11-11T00:41:42.465Z,1668127302.465 [Default:CheckIn] Stopped 2022-11-11T00:41:42.466Z,1668127302.466 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-11-11T00:41:42.466Z,1668127302.466 [Default:CheckIn](INFO): Running loop #47 2022-11-11T00:41:42.466Z,1668127302.466 [Default:CheckIn] Running Loop=47 2022-11-11T00:41:42.466Z,1668127302.466 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-11-11T00:41:42.466Z,1668127302.466 [Default:CheckIn:Read_GPS] Running Loop=1 2022-11-11T00:41:44.472Z,1668127304.472 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,004143.00,A,3648.16532,N,12147.28108,W,0.058,100.51,111122,,,A*7E 2022-11-11T00:41:44.475Z,1668127304.475 [NAL9602](INFO): GPS fix at 20221111T004143: (36.802755, -121.788018) 2022-11-11T00:41:44.485Z,1668127304.485 [Default:CheckIn:Read_GPS] Stopped 2022-11-11T00:41:44.485Z,1668127304.485 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-11-11T00:41:52.185Z,1668127312.185 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20221110T210129/Courier0120.lzma 2022-11-11T00:41:53.188Z,1668127313.188 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Courier0120.lzma.bak 2022-11-11T00:41:53.188Z,1668127313.188 [DataOverHttps](INFO): SBD MOMSN=17282892 2022-11-11T00:42:09.029Z,1668127329.029 [DataOverHttps](INFO): Sending 146 bytes from file Logs/20221110T210129/Express0121.lzma 2022-11-11T00:42:10.032Z,1668127330.032 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Express0121.lzma.bak 2022-11-11T00:42:10.032Z,1668127330.032 [DataOverHttps](INFO): SBD MOMSN=17282895 2022-11-11T00:42:11.146Z,1668127331.146 [Default:CheckIn:Read_Iridium] Stopped 2022-11-11T00:42:11.147Z,1668127331.147 [Default:CheckIn:C.Wait] Running Loop=1 2022-11-11T00:42:11.147Z,1668127331.147 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-11-11T00:42:15.175Z,1668127335.175 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-11-11T00:42:15.250Z,1668127335.250 [NAL9602](ERROR): received: +CSQ:0 OK907, 2, 0, 0, 0 OK 2022-11-11T00:46:46.275Z,1668127606.275 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-11-11T00:46:46.683Z,1668127606.683 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2022-11-11T00:46:46.683Z,1668127606.683 [DropWeight] Hardware Fault, FailCount= 1 2022-11-11T00:46:46.683Z,1668127606.683 [DropWeight](ERROR): Hardware Fault 2022-11-11T00:46:46.722Z,1668127606.722 [CommandExec](FAULT): Scheduling is paused 2022-11-11T00:46:46.722Z,1668127606.722 [CBIT](INFO): Critical error at 20221111T004646 2022-11-11T00:46:46.722Z,1668127606.722 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals 2022-11-11T00:46:46.725Z,1668127606.725 [CBIT](ERROR): Hardware Fault in component: DropWeight 2022-11-11T00:46:46.726Z,1668127606.726 [CBIT](CRITICAL): Hardware Fault in component: DropWeight 2022-11-11T00:46:47.119Z,1668127607.119 [CBIT](INFO): Critical error at 20221111T004646 2022-11-11T00:47:11.744Z,1668127631.744 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-11-11T00:47:11.744Z,1668127631.744 [Default:CheckIn:C.Wait] Stopped 2022-11-11T00:47:11.744Z,1668127631.744 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-11-11T00:47:11.745Z,1668127631.745 [Default:CheckIn:D] Running Loop=1 2022-11-11T00:47:12.141Z,1668127632.141 [Default:CheckIn:D] Stopped 2022-11-11T00:47:12.141Z,1668127632.141 [Default:CheckIn:E] Running Loop=1 2022-11-11T00:47:12.549Z,1668127632.549 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 270.958968 min 2022-11-11T00:47:12.549Z,1668127632.549 [Default:CheckIn:E] Stopped 2022-11-11T00:47:12.549Z,1668127632.549 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-11-11T00:47:12.549Z,1668127632.549 [Default:CheckIn] Stopped 2022-11-11T00:47:12.549Z,1668127632.549 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-11-11T00:47:12.549Z,1668127632.549 [Default:CheckIn](INFO): Running loop #48 2022-11-11T00:47:12.550Z,1668127632.550 [Default:CheckIn] Running Loop=48 2022-11-11T00:47:12.550Z,1668127632.550 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-11-11T00:47:12.550Z,1668127632.550 [Default:CheckIn:Read_GPS] Running Loop=1 2022-11-11T00:47:14.557Z,1668127634.557 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,004713.00,A,3648.16449,N,12147.28088,W,0.078,20.02,111122,,,A*4E 2022-11-11T00:47:14.559Z,1668127634.559 [NAL9602](INFO): GPS fix at 20221111T004713: (36.802742, -121.788015) 2022-11-11T00:47:14.570Z,1668127634.570 [Default:CheckIn:Read_GPS] Stopped 2022-11-11T00:47:14.570Z,1668127634.570 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-11-11T00:47:22.149Z,1668127642.149 [DataOverHttps](INFO): Sending 178 bytes from file Logs/20221110T210129/Courier0123.lzma 2022-11-11T00:47:23.152Z,1668127643.152 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Courier0123.lzma.bak 2022-11-11T00:47:23.152Z,1668127643.152 [DataOverHttps](INFO): SBD MOMSN=17283474 2022-11-11T00:47:38.917Z,1668127658.917 [DataOverHttps](INFO): Sending 237 bytes from file Logs/20221110T210129/Express0124.lzma 2022-11-11T00:47:39.920Z,1668127659.920 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Express0124.lzma.bak 2022-11-11T00:47:39.920Z,1668127659.920 [DataOverHttps](INFO): SBD MOMSN=17283522 2022-11-11T00:47:41.236Z,1668127661.236 [Default:CheckIn:Read_Iridium] Stopped 2022-11-11T00:47:41.236Z,1668127661.236 [Default:CheckIn:C.Wait] Running Loop=1 2022-11-11T00:47:41.236Z,1668127661.236 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-11-11T00:47:46.475Z,1668127666.475 [NAL9602](INFO): Not Powering down - fast GPS 2022-11-11T00:52:41.807Z,1668127961.807 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-11-11T00:52:41.807Z,1668127961.807 [Default:CheckIn:C.Wait] Stopped 2022-11-11T00:52:41.807Z,1668127961.807 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-11-11T00:52:41.807Z,1668127961.807 [Default:CheckIn:D] Running Loop=1 2022-11-11T00:52:42.216Z,1668127962.216 [Default:CheckIn:D] Stopped 2022-11-11T00:52:42.216Z,1668127962.216 [Default:CheckIn:E] Running Loop=1 2022-11-11T00:52:42.619Z,1668127962.619 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 276.460221 min 2022-11-11T00:52:42.619Z,1668127962.619 [Default:CheckIn:E] Stopped 2022-11-11T00:52:42.619Z,1668127962.619 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-11-11T00:52:42.619Z,1668127962.619 [Default:CheckIn] Stopped 2022-11-11T00:52:42.619Z,1668127962.619 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-11-11T00:52:42.619Z,1668127962.619 [Default:CheckIn](INFO): Running loop #49 2022-11-11T00:52:42.619Z,1668127962.619 [Default:CheckIn] Running Loop=49 2022-11-11T00:52:42.619Z,1668127962.619 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-11-11T00:52:42.620Z,1668127962.620 [Default:CheckIn:Read_GPS] Running Loop=1 2022-11-11T00:52:44.632Z,1668127964.632 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,005243.00,A,3648.16602,N,12147.27927,W,0.117,195.27,111122,,,A*71 2022-11-11T00:52:44.645Z,1668127964.645 [NAL9602](INFO): GPS fix at 20221111T005243: (36.802767, -121.787988) 2022-11-11T00:52:44.655Z,1668127964.655 [Default:CheckIn:Read_GPS] Stopped 2022-11-11T00:52:44.656Z,1668127964.656 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-11-11T00:52:52.837Z,1668127972.837 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20221110T210129/Courier0126.lzma 2022-11-11T00:52:53.840Z,1668127973.840 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Courier0126.lzma.bak 2022-11-11T00:52:53.840Z,1668127973.840 [DataOverHttps](INFO): SBD MOMSN=17283597 2022-11-11T00:53:09.705Z,1668127989.705 [DataOverHttps](INFO): Sending 141 bytes from file Logs/20221110T210129/Express0127.lzma 2022-11-11T00:53:10.708Z,1668127990.708 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Express0127.lzma.bak 2022-11-11T00:53:10.708Z,1668127990.708 [DataOverHttps](INFO): SBD MOMSN=17283600 2022-11-11T00:53:11.804Z,1668127991.804 [Default:CheckIn:Read_Iridium] Stopped 2022-11-11T00:53:11.804Z,1668127991.804 [Default:CheckIn:C.Wait] Running Loop=1 2022-11-11T00:53:11.804Z,1668127991.804 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-11-11T00:53:15.359Z,1668127995.359 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-11-11T00:53:15.442Z,1668127995.442 [NAL9602](ERROR): received: +CSQ:0 OK907, 2, 0, 0, 0 OK 2022-11-11T00:57:47.255Z,1668128267.255 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-11-11T00:58:12.325Z,1668128292.325 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-11-11T00:58:12.325Z,1668128292.325 [Default:CheckIn:C.Wait] Stopped 2022-11-11T00:58:12.325Z,1668128292.325 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-11-11T00:58:12.326Z,1668128292.326 [Default:CheckIn:D] Running Loop=1 2022-11-11T00:58:12.716Z,1668128292.716 [Default:CheckIn:D] Stopped 2022-11-11T00:58:12.716Z,1668128292.716 [Default:CheckIn:E] Running Loop=1 2022-11-11T00:58:13.125Z,1668128293.125 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 281.968555 min 2022-11-11T00:58:13.125Z,1668128293.125 [Default:CheckIn:E] Stopped 2022-11-11T00:58:13.125Z,1668128293.125 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-11-11T00:58:13.125Z,1668128293.125 [Default:CheckIn] Stopped 2022-11-11T00:58:13.125Z,1668128293.125 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-11-11T00:58:13.125Z,1668128293.125 [Default:CheckIn](INFO): Running loop #50 2022-11-11T00:58:13.126Z,1668128293.126 [Default:CheckIn] Running Loop=50 2022-11-11T00:58:13.126Z,1668128293.126 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-11-11T00:58:13.126Z,1668128293.126 [Default:CheckIn:Read_GPS] Running Loop=1 2022-11-11T00:58:15.133Z,1668128295.133 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,005814.00,A,3648.16230,N,12147.27592,W,1.730,186.98,111122,,,A*7A 2022-11-11T00:58:15.135Z,1668128295.135 [NAL9602](INFO): GPS fix at 20221111T005814: (36.802705, -121.787932) 2022-11-11T00:58:15.175Z,1668128295.175 [Default:CheckIn:Read_GPS] Stopped 2022-11-11T00:58:15.175Z,1668128295.175 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-11-11T00:58:24.425Z,1668128304.425 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20221110T210129/Courier0129.lzma 2022-11-11T00:58:25.428Z,1668128305.428 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Courier0129.lzma.bak 2022-11-11T00:58:25.428Z,1668128305.428 [DataOverHttps](INFO): SBD MOMSN=17283603 2022-11-11T00:58:42.465Z,1668128322.465 [DataOverHttps](INFO): Sending 216 bytes from file Logs/20221110T210129/Express0130.lzma 2022-11-11T00:58:43.468Z,1668128323.468 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Express0130.lzma.bak 2022-11-11T00:58:43.468Z,1668128323.468 [DataOverHttps](INFO): SBD MOMSN=17283606 2022-11-11T00:58:44.670Z,1668128324.670 [Default:CheckIn:Read_Iridium] Stopped 2022-11-11T00:58:44.670Z,1668128324.670 [Default:CheckIn:C.Wait] Running Loop=1 2022-11-11T00:58:44.670Z,1668128324.670 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-11-11T00:58:47.478Z,1668128327.478 [NAL9602](INFO): Not Powering down - fast GPS 2022-11-11T01:01:46.878Z,1668128506.878 [CBIT](INFO): Clearing failed state for component DropWeight 2022-11-11T01:01:46.878Z,1668128506.878 [DropWeight] No Fault, FailCount= 1 2022-11-11T01:03:45.250Z,1668128625.250 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-11-11T01:03:45.250Z,1668128625.250 [Default:CheckIn:C.Wait] Stopped 2022-11-11T01:03:45.250Z,1668128625.250 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-11-11T01:03:45.251Z,1668128625.251 [Default:CheckIn:D] Running Loop=1 2022-11-11T01:03:45.643Z,1668128625.643 [Default:CheckIn:D] Stopped 2022-11-11T01:03:45.643Z,1668128625.643 [Default:CheckIn:E] Running Loop=1 2022-11-11T01:03:46.051Z,1668128626.051 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 287.517318 min 2022-11-11T01:03:46.051Z,1668128626.051 [Default:CheckIn:E] Stopped 2022-11-11T01:03:46.051Z,1668128626.051 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-11-11T01:03:46.051Z,1668128626.051 [Default:CheckIn] Stopped 2022-11-11T01:03:46.051Z,1668128626.051 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-11-11T01:03:46.051Z,1668128626.051 [Default:CheckIn](INFO): Running loop #51 2022-11-11T01:03:46.052Z,1668128626.052 [Default:CheckIn] Running Loop=51 2022-11-11T01:03:46.052Z,1668128626.052 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-11-11T01:03:46.052Z,1668128626.052 [Default:CheckIn:Read_GPS] Running Loop=1 2022-11-11T01:03:48.088Z,1668128628.088 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,010347.00,A,3648.17108,N,12147.28289,W,1.089,185.39,111122,,,A*75 2022-11-11T01:03:48.090Z,1668128628.090 [NAL9602](INFO): GPS fix at 20221111T010347: (36.802851, -121.788048) 2022-11-11T01:03:48.101Z,1668128628.101 [Default:CheckIn:Read_GPS] Stopped 2022-11-11T01:03:48.101Z,1668128628.101 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-11-11T01:03:55.853Z,1668128635.853 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20221110T210129/Courier0132.lzma 2022-11-11T01:03:56.856Z,1668128636.856 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Courier0132.lzma.bak 2022-11-11T01:03:56.856Z,1668128636.856 [DataOverHttps](INFO): SBD MOMSN=17283670 2022-11-11T01:04:12.710Z,1668128652.710 [DataOverHttps](INFO): Sending 140 bytes from file Logs/20221110T210129/Express0133.lzma 2022-11-11T01:04:13.712Z,1668128653.712 [DataOverHttps](INFO): Moved sent file to Logs/20221110T210129/Express0133.lzma.bak 2022-11-11T01:04:13.712Z,1668128653.712 [DataOverHttps](INFO): SBD MOMSN=17283673 2022-11-11T01:04:15.137Z,1668128655.137 [Default:CheckIn:Read_Iridium] Stopped 2022-11-11T01:04:15.137Z,1668128655.137 [Default:CheckIn:C.Wait] Running Loop=1 2022-11-11T01:04:15.137Z,1668128655.137 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-11-11T01:04:18.763Z,1668128658.763 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-11-11T01:04:18.838Z,1668128658.838 [NAL9602](ERROR): received: +CSQ:0 OK907, 2, 0, 0, 0 OK 2022-11-11T01:05:11.095Z,1668128711.095 [CommandExec](IMPORTANT): got command quit 2022-11-11T01:05:12.098Z,1668128712.098 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread. 2022-11-11T01:05:12.098Z,1668128712.098 [CommandExec](INFO): Uninitializing the command executive. 2022-11-11T01:05:12.098Z,1668128712.098 [CommandExec](INFO): Uninitializing the command scheduler. 2022-11-11T01:05:12.098Z,1668128712.098 [CommandExec ThreadHandler](INFO): Thread cancelled. 2022-11-11T01:05:12.193Z,1668128712.193 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2022-11-11T01:05:12.194Z,1668128712.194 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2022-11-11T01:05:12.194Z,1668128712.194 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2022-11-11T01:05:12.194Z,1668128712.194 [NavChartDb](INFO): Join timeout helper Thread ID is 6270 2022-11-11T01:05:12.354Z,1668128712.354 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2022-11-11T01:05:12.354Z,1668128712.354 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2022-11-11T01:05:12.373Z,1668128712.373 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2022-11-11T01:05:12.374Z,1668128712.374 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2022-11-11T01:05:12.374Z,1668128712.374 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 6271 2022-11-11T01:05:12.646Z,1668128712.646 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2022-11-11T01:05:12.646Z,1668128712.646 [WetLabsBB2FL](INFO): Powering down 2022-11-11T01:05:12.647Z,1668128712.647 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2022-11-11T01:05:12.659Z,1668128712.659 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2022-11-11T01:05:12.659Z,1668128712.659 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2022-11-11T01:05:12.660Z,1668128712.659 [CTD_Seabird](INFO): Join timeout helper Thread ID is 6272 2022-11-11T01:05:12.910Z,1668128712.910 [CTD_Seabird](INFO): Powering down 2022-11-11T01:05:12.922Z,1668128712.922 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread. 2022-11-11T01:05:12.922Z,1668128712.922 [CTD_Seabird](INFO): Powering down 2022-11-11T01:05:12.934Z,1668128712.934 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2022-11-11T01:05:12.942Z,1668128712.942 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2022-11-11T01:05:12.942Z,1668128712.942 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2022-11-11T01:05:12.942Z,1668128712.942 [Radio_Surface](INFO): Join timeout helper Thread ID is 6273 2022-11-11T01:05:13.054Z,1668128713.054 [Radio_Surface](INFO): Powering down 2022-11-11T01:05:13.055Z,1668128713.055 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2022-11-11T01:05:13.055Z,1668128713.055 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2022-11-11T01:05:13.074Z,1668128713.074 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler 2022-11-11T01:05:13.074Z,1668128713.074 [Onboard ThreadHandler](INFO): Thread cancelled. 2022-11-11T01:05:13.074Z,1668128713.074 [Onboard](INFO): Join timeout helper Thread ID is 6274 2022-11-11T01:05:13.142Z,1668128713.142 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread. 2022-11-11T01:05:13.142Z,1668128713.142 [Onboard ThreadHandler](INFO): Thread cancelled. 2022-11-11T01:05:13.151Z,1668128713.151 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2022-11-11T01:05:13.151Z,1668128713.151 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2022-11-11T01:05:13.151Z,1668128713.151 [DataOverHttps](INFO): Join timeout helper Thread ID is 6275 2022-11-11T01:05:13.730Z,1668128713.730 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2022-11-11T01:05:13.730Z,1668128713.730 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2022-11-11T01:05:13.750Z,1668128713.750 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2022-11-11T01:05:13.750Z,1668128713.750 [logger ThreadHandler](INFO): Thread cancelled. 2022-11-11T01:05:13.751Z,1668128713.751 [logger](INFO): Join timeout helper Thread ID is 6276 2022-11-11T01:05:13.758Z,1668128713.758 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2022-11-11T01:05:13.758Z,1668128713.758 [logger ThreadHandler](INFO): Thread cancelled. 2022-11-11T01:05:13.770Z,1668128713.770 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2022-11-11T01:05:13.770Z,1668128713.770 [CommandLine ThreadHandler](INFO): Thread cancelled. 2022-11-11T01:05:13.771Z,1668128713.771 [CommandLine](INFO): Join timeout helper Thread ID is 6277 2022-11-11T01:05:13.838Z,1668128713.838 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2022-11-11T01:05:13.838Z,1668128713.838 [CommandLine ThreadHandler](INFO): Thread cancelled. 2022-11-11T01:05:13.850Z,1668128713.850 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler 2022-11-11T01:05:13.850Z,1668128713.850 [CommandExec ThreadHandler](INFO): Thread cancelled. 2022-11-11T01:05:13.851Z,1668128713.851 [CommandExec](INFO): Join timeout helper Thread ID is 6278 2022-11-11T01:05:13.852Z,1668128713.852 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2022-11-11T01:05:13.852Z,1668128713.852 [controlThread ThreadHandler](INFO): Thread cancelled. 2022-11-11T01:05:13.852Z,1668128713.852 [controlThread](INFO): Join timeout helper Thread ID is 6279 2022-11-11T01:05:14.094Z,1668128714.094 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2022-11-11T01:05:14.094Z,1668128714.094 [controlThread](DEBUG): Uninitializing ControlThread 2022-11-11T01:05:14.094Z,1668128714.094 [AHRS_M2](INFO): Powering down 2022-11-11T01:05:14.166Z,1668128714.166 [NAL9602](INFO): Powering down 2022-11-11T01:05:14.169Z,1668128714.169 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2022-11-11T01:05:14.170Z,1668128714.170 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2022-11-11T01:05:14.170Z,1668128714.170 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2022-11-11T01:05:14.171Z,1668128714.171 [MissionManager](INFO): Uninitializing Mission Default 2022-11-11T01:05:14.171Z,1668128714.171 [Default] Stopped 2022-11-11T01:05:14.171Z,1668128714.171 [Default](DEBUG): Aggregate::uninitialize Default 2022-11-11T01:05:14.171Z,1668128714.171 [Default:B.GoToSurface] Stopped 2022-11-11T01:05:14.171Z,1668128714.171 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2022-11-11T01:05:14.171Z,1668128714.171 [Default:CheckIn] Stopped 2022-11-11T01:05:14.171Z,1668128714.171 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-11-11T01:05:14.171Z,1668128714.171 [Default:CheckIn:C.Wait] Stopped 2022-11-11T01:05:14.172Z,1668128714.172 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-11-11T01:05:14.174Z,1668128714.174 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2022-11-11T01:05:14.175Z,1668128714.175 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2022-11-11T01:05:14.175Z,1668128714.175 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2022-11-11T01:05:14.175Z,1668128714.175 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2022-11-11T01:05:14.175Z,1668128714.175 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2022-11-11T01:05:14.176Z,1668128714.176 [BuoyancyServo](INFO): Powering down 2022-11-11T01:05:14.190Z,1668128714.190 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2022-11-11T01:05:14.190Z,1668128714.190 [ElevatorServo](INFO): Powering down 2022-11-11T01:05:14.191Z,1668128714.191 [MassServo](DEBUG): Uninitialize Mass Servo. 2022-11-11T01:05:14.191Z,1668128714.191 [MassServo](INFO): Powering down 2022-11-11T01:05:14.192Z,1668128714.192 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2022-11-11T01:05:14.192Z,1668128714.192 [RudderServo](INFO): Powering down 2022-11-11T01:05:14.193Z,1668128714.193 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2022-11-11T01:05:14.193Z,1668128714.193 [ThrusterServo](INFO): Powering down 2022-11-11T01:05:14.194Z,1668128714.194 [SBIT](DEBUG): Uninitialize SBIT Component. 2022-11-11T01:05:14.194Z,1668128714.194 [IBIT](DEBUG): Uninitialize IBIT Component. 2022-11-11T01:05:14.194Z,1668128714.194 [CBIT](DEBUG): Uninitialize CBIT Component. 2022-11-11T01:05:14.194Z,1668128714.194 [CBIT](DEBUG): Powering off loads. 2022-11-11T01:05:14.205Z,1668128714.205 [CBIT](DEBUG): Disabling WDT. 2022-11-11T01:05:14.217Z,1668128714.217 [CBIT](DEBUG): Opening all GF detection circuits. 2022-11-11T01:05:14.218Z,1668128714.218 [controlThread ThreadHandler](INFO): Thread cancelled. 2022-11-11T01:05:14.272Z,1668128714.272 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2022-11-11T01:05:14.275Z,1668128714.275 [Onboard ThreadHandler](INFO): Thread cancelled. 2022-11-11T01:05:14.282Z,1668128714.282 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2022-11-11T01:05:14.354Z,1668128714.354 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2022-11-11T01:05:14.357Z,1668128714.357 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2022-11-11T01:05:14.397Z,1668128714.397 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2022-11-11T01:05:14.499Z,1668128714.499 [logger ThreadHandler](INFO): Thread cancelled.