2021-12-17T20:19:53.081Z,1639772393.081 [DataOverHttps](INFO): Received command: restart logs 2021-12-17T20:19:53.084Z,1639772393.084 [CommandExec](IMPORTANT): got command restart logs 2021-12-17T20:21:06.255Z,1639772466.255 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-17T20:21:06.255Z,1639772466.255 [Default:CheckIn:C.Wait] Stopped 2021-12-17T20:21:06.256Z,1639772466.256 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-17T20:21:06.256Z,1639772466.256 [Default:CheckIn:D] Running Loop=1 2021-12-17T20:21:06.738Z,1639772466.738 [Default:CheckIn:D] Stopped 2021-12-17T20:21:06.739Z,1639772466.739 [Default:CheckIn:E] Running Loop=1 2021-12-17T20:21:07.097Z,1639772467.097 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 84.337394 min 2021-12-17T20:21:07.097Z,1639772467.097 [Default:CheckIn:E] Stopped 2021-12-17T20:21:07.097Z,1639772467.097 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-17T20:21:07.141Z,1639772467.141 [Default:CheckIn] Stopped 2021-12-17T20:21:07.142Z,1639772467.142 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-17T20:21:07.142Z,1639772467.142 [Default:CheckIn](INFO): Running loop #15 2021-12-17T20:21:07.142Z,1639772467.142 [Default:CheckIn] Running Loop=15 2021-12-17T20:21:07.142Z,1639772467.142 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-17T20:21:07.142Z,1639772467.142 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-17T20:21:09.076Z,1639772469.076 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,202108.00,A,3648.38993,N,12149.63598,W,7.756,95.81,171221,,,D*4F 2021-12-17T20:21:09.079Z,1639772469.079 [NAL9602](INFO): GPS fix at 20211217T202108: (36.806499, -121.827266) 2021-12-17T20:21:09.099Z,1639772469.099 [Default:CheckIn:Read_GPS] Stopped 2021-12-17T20:21:09.100Z,1639772469.100 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-17T20:21:10.569Z,1639772470.569 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20211217T142912/Courier0103.lzma 2021-12-17T20:21:10.867Z,1639772470.867 [DataOverHttps](INFO): Moved sent file to Logs/20211217T142912/Courier0103.lzma.bak 2021-12-17T20:21:10.868Z,1639772470.868 [DataOverHttps](INFO): SBD MOMSN=16397930 2021-12-17T20:21:25.322Z,1639772485.322 [NAL9602](INFO): SBD MO Status=0, MOMSN=7626, MT Status=0, MTMSN=0 2021-12-17T20:21:25.322Z,1639772485.322 [NAL9602](INFO): No messages in MT queue 2021-12-17T20:21:56.019Z,1639772516.019 [NAL9602](INFO): Not Powering down - fast GPS 2021-12-17T20:22:05.178Z,1639772525.178 [DataOverHttps](INFO): Sending 268 bytes from file Logs/20211217T201953/Courier0000.lzma 2021-12-17T20:22:09.191Z,1639772529.191 [DataOverHttps](INFO): Moved sent file to Logs/20211217T201953/Courier0000.lzma.bak 2021-12-17T20:22:09.191Z,1639772529.191 [DataOverHttps](INFO): SBD MOMSN=16397932 2021-12-17T20:22:56.142Z,1639772576.142 [DataOverHttps](INFO): Sending 402 bytes from file Logs/20211217T142912/Express0104.lzma 2021-12-17T20:22:57.143Z,1639772577.143 [DataOverHttps](INFO): Moved sent file to Logs/20211217T142912/Express0104.lzma.bak 2021-12-17T20:22:57.144Z,1639772577.144 [DataOverHttps](INFO): SBD MOMSN=16397937 2021-12-17T20:23:22.123Z,1639772602.123 [DataOverHttps](INFO): Sending 437 bytes from file Logs/20211217T201953/Express0001.lzma 2021-12-17T20:23:23.123Z,1639772603.123 [DataOverHttps](INFO): Moved sent file to Logs/20211217T201953/Express0001.lzma.bak 2021-12-17T20:23:23.123Z,1639772603.123 [DataOverHttps](INFO): SBD MOMSN=16397940 2021-12-17T20:23:24.542Z,1639772604.542 [Default:CheckIn:Read_Iridium] Stopped 2021-12-17T20:23:24.542Z,1639772604.542 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-17T20:23:24.542Z,1639772604.542 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-17T20:28:25.174Z,1639772905.174 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-17T20:28:25.174Z,1639772905.174 [Default:CheckIn:C.Wait] Stopped 2021-12-17T20:28:25.174Z,1639772905.174 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-17T20:28:25.175Z,1639772905.175 [Default:CheckIn:D] Running Loop=1 2021-12-17T20:28:25.575Z,1639772905.575 [Default:CheckIn:D] Stopped 2021-12-17T20:28:25.575Z,1639772905.575 [Default:CheckIn:E] Running Loop=1 2021-12-17T20:28:25.983Z,1639772905.983 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 91.651335 min 2021-12-17T20:28:25.983Z,1639772905.983 [Default:CheckIn:E] Stopped 2021-12-17T20:28:25.983Z,1639772905.983 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-17T20:28:25.983Z,1639772905.983 [Default:CheckIn] Stopped 2021-12-17T20:28:25.983Z,1639772905.983 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-17T20:28:25.983Z,1639772905.983 [Default:CheckIn](INFO): Running loop #16 2021-12-17T20:28:25.984Z,1639772905.984 [Default:CheckIn] Running Loop=16 2021-12-17T20:28:25.984Z,1639772905.984 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-17T20:28:25.984Z,1639772905.984 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-17T20:28:27.988Z,1639772907.988 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,202827.00,A,3648.21328,N,12147.79503,W,8.456,64.23,171221,,,D*44 2021-12-17T20:28:27.991Z,1639772907.991 [NAL9602](INFO): GPS fix at 20211217T202827: (36.803555, -121.796584) 2021-12-17T20:28:28.003Z,1639772908.003 [Default:CheckIn:Read_GPS] Stopped 2021-12-17T20:28:28.003Z,1639772908.003 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-17T20:28:35.553Z,1639772915.553 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211217T201953/Courier0005.lzma 2021-12-17T20:28:36.555Z,1639772916.555 [DataOverHttps](INFO): Moved sent file to Logs/20211217T201953/Courier0005.lzma.bak 2021-12-17T20:28:36.555Z,1639772916.555 [DataOverHttps](INFO): SBD MOMSN=16397951 2021-12-17T20:28:51.824Z,1639772931.824 [NAL9602](INFO): SBD MO Status=0, MOMSN=7627, MT Status=0, MTMSN=0 2021-12-17T20:28:51.824Z,1639772931.824 [NAL9602](INFO): No messages in MT queue 2021-12-17T20:28:52.334Z,1639772932.334 [DataOverHttps](INFO): Sending 155 bytes from file Logs/20211217T201953/Express0007.lzma 2021-12-17T20:28:53.335Z,1639772933.335 [DataOverHttps](INFO): Moved sent file to Logs/20211217T201953/Express0007.lzma.bak 2021-12-17T20:28:53.335Z,1639772933.335 [DataOverHttps](INFO): SBD MOMSN=16397956 2021-12-17T20:28:54.653Z,1639772934.653 [Default:CheckIn:Read_Iridium] Stopped 2021-12-17T20:28:54.653Z,1639772934.653 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-17T20:28:54.653Z,1639772934.653 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-17T20:29:22.522Z,1639772962.522 [NAL9602](INFO): Not Powering down - fast GPS 2021-12-17T20:30:26.785Z,1639773026.785 [CBIT](IMPORTANT): Beginning ground fault scan 2021-12-17T20:30:37.714Z,1639773037.714 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.005819 CHAN A1 (24V): -0.008455 CHAN A2 (12V): -0.004778 CHAN A3 (5V): -0.002739 CHAN B0 (3.3V): -0.000967 CHAN B1 (3.15aV): -0.000805 CHAN B2 (3.15bV): -0.001697 CHAN B3 (GND): -0.000163 OPEN: 0.004535 Full Scale: +/- 1 mA 2021-12-17T20:33:55.298Z,1639773235.298 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-17T20:33:55.298Z,1639773235.298 [Default:CheckIn:C.Wait] Stopped 2021-12-17T20:33:55.298Z,1639773235.298 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-17T20:33:55.298Z,1639773235.298 [Default:CheckIn:D] Running Loop=1 2021-12-17T20:33:55.693Z,1639773235.693 [Default:CheckIn:D] Stopped 2021-12-17T20:33:55.693Z,1639773235.693 [Default:CheckIn:E] Running Loop=1 2021-12-17T20:33:56.115Z,1639773236.115 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 97.153304 min 2021-12-17T20:33:56.115Z,1639773236.115 [Default:CheckIn:E] Stopped 2021-12-17T20:33:56.116Z,1639773236.116 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-17T20:33:56.116Z,1639773236.116 [Default:CheckIn] Stopped 2021-12-17T20:33:56.116Z,1639773236.116 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-17T20:33:56.116Z,1639773236.116 [Default:CheckIn](INFO): Running loop #17 2021-12-17T20:33:56.116Z,1639773236.116 [Default:CheckIn] Running Loop=17 2021-12-17T20:33:56.116Z,1639773236.116 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-17T20:33:56.116Z,1639773236.116 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-17T20:33:58.110Z,1639773238.110 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,203357.00,A,3648.18444,N,12147.84779,W,3.013,309.59,171221,,,D*78 2021-12-17T20:33:58.113Z,1639773238.113 [NAL9602](INFO): GPS fix at 20211217T203357: (36.803074, -121.797463) 2021-12-17T20:33:58.128Z,1639773238.128 [Default:CheckIn:Read_GPS] Stopped 2021-12-17T20:33:58.128Z,1639773238.128 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-17T20:34:05.117Z,1639773245.117 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211217T201953/Courier0009.lzma 2021-12-17T20:34:06.119Z,1639773246.119 [DataOverHttps](INFO): Moved sent file to Logs/20211217T201953/Courier0009.lzma.bak 2021-12-17T20:34:06.119Z,1639773246.119 [DataOverHttps](INFO): SBD MOMSN=16397964 2021-12-17T20:34:13.460Z,1639773253.460 [NAL9602](INFO): SBD MO Status=0, MOMSN=7628, MT Status=0, MTMSN=0 2021-12-17T20:34:13.460Z,1639773253.460 [NAL9602](INFO): No messages in MT queue 2021-12-17T20:34:24.786Z,1639773264.786 [DataOverHttps](INFO): Sending 454 bytes from file Logs/20211217T201953/Express0010.lzma 2021-12-17T20:34:25.787Z,1639773265.787 [DataOverHttps](INFO): Moved sent file to Logs/20211217T201953/Express0010.lzma.bak 2021-12-17T20:34:25.787Z,1639773265.787 [DataOverHttps](INFO): SBD MOMSN=16397967 2021-12-17T20:34:27.275Z,1639773267.275 [Default:CheckIn:Read_Iridium] Stopped 2021-12-17T20:34:27.275Z,1639773267.275 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-17T20:34:27.275Z,1639773267.275 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-17T20:34:44.218Z,1639773284.218 [NAL9602](INFO): Not Powering down - fast GPS 2021-12-17T20:39:27.942Z,1639773567.942 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-17T20:39:27.942Z,1639773567.942 [Default:CheckIn:C.Wait] Stopped 2021-12-17T20:39:27.942Z,1639773567.942 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-17T20:39:27.943Z,1639773567.943 [Default:CheckIn:D] Running Loop=1 2021-12-17T20:39:28.347Z,1639773568.347 [Default:CheckIn:D] Stopped 2021-12-17T20:39:28.347Z,1639773568.347 [Default:CheckIn:E] Running Loop=1 2021-12-17T20:39:28.755Z,1639773568.755 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 102.697534 min 2021-12-17T20:39:28.755Z,1639773568.755 [Default:CheckIn:E] Stopped 2021-12-17T20:39:28.755Z,1639773568.755 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-17T20:39:28.755Z,1639773568.755 [Default:CheckIn] Stopped 2021-12-17T20:39:28.755Z,1639773568.755 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-17T20:39:28.756Z,1639773568.756 [Default:CheckIn](INFO): Running loop #18 2021-12-17T20:39:28.756Z,1639773568.756 [Default:CheckIn] Running Loop=18 2021-12-17T20:39:28.756Z,1639773568.756 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-17T20:39:28.756Z,1639773568.756 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-17T20:39:30.756Z,1639773570.756 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,203929.00,A,3648.18311,N,12147.77726,W,1.924,222.25,171221,,,D*76 2021-12-17T20:39:30.759Z,1639773570.759 [NAL9602](INFO): GPS fix at 20211217T203929: (36.803052, -121.796288) 2021-12-17T20:39:30.771Z,1639773570.771 [Default:CheckIn:Read_GPS] Stopped 2021-12-17T20:39:30.771Z,1639773570.771 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-17T20:39:38.964Z,1639773578.964 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211217T201953/Courier0012.lzma 2021-12-17T20:39:39.599Z,1639773579.599 [DataOverHttps](INFO): Moved sent file to Logs/20211217T201953/Courier0012.lzma.bak 2021-12-17T20:39:39.600Z,1639773579.600 [DataOverHttps](INFO): SBD MOMSN=16397978 2021-12-17T20:39:46.108Z,1639773586.108 [NAL9602](INFO): SBD MO Status=0, MOMSN=7629, MT Status=0, MTMSN=0 2021-12-17T20:39:46.109Z,1639773586.109 [NAL9602](INFO): No messages in MT queue 2021-12-17T20:39:55.434Z,1639773595.434 [DataOverHttps](INFO): Sending 259 bytes from file Logs/20211217T201953/Express0013.lzma 2021-12-17T20:39:56.435Z,1639773596.435 [DataOverHttps](INFO): Moved sent file to Logs/20211217T201953/Express0013.lzma.bak 2021-12-17T20:39:56.435Z,1639773596.435 [DataOverHttps](INFO): SBD MOMSN=16397983 2021-12-17T20:39:57.846Z,1639773597.846 [Default:CheckIn:Read_Iridium] Stopped 2021-12-17T20:39:57.847Z,1639773597.847 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-17T20:39:57.847Z,1639773597.847 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-17T20:40:16.810Z,1639773616.810 [NAL9602](INFO): Not Powering down - fast GPS 2021-12-17T20:44:58.531Z,1639773898.531 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-17T20:44:58.532Z,1639773898.532 [Default:CheckIn:C.Wait] Stopped 2021-12-17T20:44:58.532Z,1639773898.532 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-17T20:44:58.532Z,1639773898.532 [Default:CheckIn:D] Running Loop=1 2021-12-17T20:44:58.971Z,1639773898.971 [Default:CheckIn:D] Stopped 2021-12-17T20:44:58.971Z,1639773898.971 [Default:CheckIn:E] Running Loop=1 2021-12-17T20:44:59.295Z,1639773899.295 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 108.207926 min 2021-12-17T20:44:59.295Z,1639773899.295 [Default:CheckIn:E] Stopped 2021-12-17T20:44:59.295Z,1639773899.295 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-17T20:44:59.295Z,1639773899.295 [Default:CheckIn] Stopped 2021-12-17T20:44:59.295Z,1639773899.295 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-17T20:44:59.295Z,1639773899.295 [Default:CheckIn](INFO): Running loop #19 2021-12-17T20:44:59.296Z,1639773899.296 [Default:CheckIn] Running Loop=19 2021-12-17T20:44:59.296Z,1639773899.296 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-17T20:44:59.296Z,1639773899.296 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-17T20:45:01.315Z,1639773901.315 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,204500.00,A,3648.33323,N,12148.17639,W,1.205,261.21,171221,,,D*73 2021-12-17T20:45:01.319Z,1639773901.319 [NAL9602](INFO): GPS fix at 20211217T204500: (36.805554, -121.802940) 2021-12-17T20:45:01.330Z,1639773901.330 [Default:CheckIn:Read_GPS] Stopped 2021-12-17T20:45:01.330Z,1639773901.330 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-17T20:45:11.809Z,1639773911.809 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211217T201953/Courier0015.lzma 2021-12-17T20:45:12.812Z,1639773912.812 [DataOverHttps](INFO): Moved sent file to Logs/20211217T201953/Courier0015.lzma.bak 2021-12-17T20:45:12.812Z,1639773912.812 [DataOverHttps](INFO): SBD MOMSN=16397992 2021-12-17T20:45:28.590Z,1639773928.590 [DataOverHttps](INFO): Sending 222 bytes from file Logs/20211217T201953/Express0016.lzma 2021-12-17T20:45:33.607Z,1639773933.607 [DataOverHttps](INFO): Moved sent file to Logs/20211217T201953/Express0016.lzma.bak 2021-12-17T20:45:33.607Z,1639773933.607 [DataOverHttps](INFO): SBD MOMSN=16397995 2021-12-17T20:45:34.903Z,1639773934.903 [Default:CheckIn:Read_Iridium] Stopped 2021-12-17T20:45:34.903Z,1639773934.903 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-17T20:45:34.903Z,1639773934.903 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-17T20:45:35.692Z,1639773935.692 [NAL9602](INFO): SBD MO Status=0, MOMSN=7630, MT Status=0, MTMSN=0 2021-12-17T20:45:35.692Z,1639773935.692 [NAL9602](INFO): No messages in MT queue 2021-12-17T20:46:06.398Z,1639773966.398 [NAL9602](INFO): Not Powering down - fast GPS 2021-12-17T20:50:35.544Z,1639774235.544 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-17T20:50:35.544Z,1639774235.544 [Default:CheckIn:C.Wait] Stopped 2021-12-17T20:50:35.544Z,1639774235.544 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-17T20:50:35.545Z,1639774235.545 [Default:CheckIn:D] Running Loop=1 2021-12-17T20:50:35.930Z,1639774235.930 [Default:CheckIn:D] Stopped 2021-12-17T20:50:35.930Z,1639774235.930 [Default:CheckIn:E] Running Loop=1 2021-12-17T20:50:36.334Z,1639774236.334 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 113.823926 min 2021-12-17T20:50:36.334Z,1639774236.334 [Default:CheckIn:E] Stopped 2021-12-17T20:50:36.334Z,1639774236.334 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-17T20:50:36.334Z,1639774236.334 [Default:CheckIn] Stopped 2021-12-17T20:50:36.334Z,1639774236.334 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-17T20:50:36.334Z,1639774236.334 [Default:CheckIn](INFO): Running loop #20 2021-12-17T20:50:36.334Z,1639774236.334 [Default:CheckIn] Running Loop=20 2021-12-17T20:50:36.334Z,1639774236.334 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-17T20:50:36.335Z,1639774236.335 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-17T20:50:38.341Z,1639774238.341 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,205037.00,A,3648.28288,N,12148.01125,W,14.035,103.74,171221,,,A*43 2021-12-17T20:50:38.343Z,1639774238.343 [NAL9602](INFO): GPS fix at 20211217T205037: (36.804715, -121.800188) 2021-12-17T20:50:38.378Z,1639774238.378 [Default:CheckIn:Read_GPS] Stopped 2021-12-17T20:50:38.378Z,1639774238.378 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-17T20:50:46.253Z,1639774246.253 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20211217T201953/Courier0018.lzma 2021-12-17T20:50:47.255Z,1639774247.255 [DataOverHttps](INFO): Moved sent file to Logs/20211217T201953/Courier0018.lzma.bak 2021-12-17T20:50:47.255Z,1639774247.255 [DataOverHttps](INFO): SBD MOMSN=16398003 2021-12-17T20:50:53.292Z,1639774253.292 [NAL9602](INFO): SBD MO Status=0, MOMSN=7631, MT Status=0, MTMSN=0 2021-12-17T20:50:53.292Z,1639774253.292 [NAL9602](INFO): No messages in MT queue 2021-12-17T20:51:03.050Z,1639774263.050 [DataOverHttps](INFO): Sending 317 bytes from file Logs/20211217T201953/Express0019.lzma 2021-12-17T20:51:04.052Z,1639774264.052 [DataOverHttps](INFO): Moved sent file to Logs/20211217T201953/Express0019.lzma.bak 2021-12-17T20:51:04.052Z,1639774264.052 [DataOverHttps](INFO): SBD MOMSN=16398008 2021-12-17T20:51:05.431Z,1639774265.431 [Default:CheckIn:Read_Iridium] Stopped 2021-12-17T20:51:05.431Z,1639774265.431 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-17T20:51:05.431Z,1639774265.431 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-17T20:51:24.035Z,1639774284.035 [NAL9602](INFO): Not Powering down - fast GPS 2021-12-17T20:56:06.106Z,1639774566.106 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-17T20:56:06.106Z,1639774566.106 [Default:CheckIn:C.Wait] Stopped 2021-12-17T20:56:06.106Z,1639774566.106 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-17T20:56:06.106Z,1639774566.106 [Default:CheckIn:D] Running Loop=1 2021-12-17T20:56:06.522Z,1639774566.522 [Default:CheckIn:D] Stopped 2021-12-17T20:56:06.522Z,1639774566.522 [Default:CheckIn:E] Running Loop=1 2021-12-17T20:56:06.941Z,1639774566.941 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 119.333781 min 2021-12-17T20:56:06.942Z,1639774566.942 [Default:CheckIn:E] Stopped 2021-12-17T20:56:06.942Z,1639774566.942 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-17T20:56:06.942Z,1639774566.942 [Default:CheckIn] Stopped 2021-12-17T20:56:06.942Z,1639774566.942 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-17T20:56:06.942Z,1639774566.942 [Default:CheckIn](INFO): Running loop #21 2021-12-17T20:56:06.942Z,1639774566.942 [Default:CheckIn] Running Loop=21 2021-12-17T20:56:06.942Z,1639774566.942 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-17T20:56:06.942Z,1639774566.942 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-17T20:56:08.928Z,1639774568.928 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,205608.00,A,3648.48419,N,12147.12316,W,5.268,178.81,171221,,,A*72 2021-12-17T20:56:08.931Z,1639774568.931 [NAL9602](INFO): GPS fix at 20211217T205608: (36.808070, -121.785386) 2021-12-17T20:56:08.971Z,1639774568.971 [Default:CheckIn:Read_GPS] Stopped 2021-12-17T20:56:08.971Z,1639774568.971 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-17T20:56:16.917Z,1639774576.917 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20211217T201953/Courier0021.lzma 2021-12-17T20:56:17.919Z,1639774577.919 [DataOverHttps](INFO): Moved sent file to Logs/20211217T201953/Courier0021.lzma.bak 2021-12-17T20:56:17.919Z,1639774577.919 [DataOverHttps](INFO): SBD MOMSN=16398017 2021-12-17T20:56:22.715Z,1639774582.715 [NAL9602](INFO): SBD MO Status=0, MOMSN=7632, MT Status=0, MTMSN=0 2021-12-17T20:56:22.715Z,1639774582.715 [NAL9602](INFO): No messages in MT queue 2021-12-17T20:56:36.449Z,1639774596.449 [DataOverHttps](INFO): Sending 166 bytes from file Logs/20211217T201953/Express0022.lzma 2021-12-17T20:56:37.451Z,1639774597.451 [DataOverHttps](INFO): Moved sent file to Logs/20211217T201953/Express0022.lzma.bak 2021-12-17T20:56:37.451Z,1639774597.451 [DataOverHttps](INFO): SBD MOMSN=16398020 2021-12-17T20:56:38.914Z,1639774598.914 [Default:CheckIn:Read_Iridium] Stopped 2021-12-17T20:56:38.915Z,1639774598.915 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-17T20:56:38.915Z,1639774598.915 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-17T20:56:53.435Z,1639774613.435 [NAL9602](INFO): Not Powering down - fast GPS 2021-12-17T21:01:34.361Z,1639774894.361 [BPC1](ERROR): BPC1B: No match for serial number 0C29 in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file). 2021-12-17T21:01:39.597Z,1639774899.597 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-17T21:01:39.598Z,1639774899.598 [Default:CheckIn:C.Wait] Stopped 2021-12-17T21:01:39.598Z,1639774899.598 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-17T21:01:39.598Z,1639774899.598 [Default:CheckIn:D] Running Loop=1 2021-12-17T21:01:40.001Z,1639774900.001 [Default:CheckIn:D] Stopped 2021-12-17T21:01:40.002Z,1639774900.002 [Default:CheckIn:E] Running Loop=1 2021-12-17T21:01:40.404Z,1639774900.404 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 124.891781 min 2021-12-17T21:01:40.404Z,1639774900.404 [Default:CheckIn:E] Stopped 2021-12-17T21:01:40.404Z,1639774900.404 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-17T21:01:40.404Z,1639774900.404 [Default:CheckIn] Stopped 2021-12-17T21:01:40.404Z,1639774900.404 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-17T21:01:40.404Z,1639774900.404 [Default:CheckIn](INFO): Running loop #22 2021-12-17T21:01:40.404Z,1639774900.404 [Default:CheckIn] Running Loop=22 2021-12-17T21:01:40.404Z,1639774900.404 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-17T21:01:40.405Z,1639774900.405 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-17T21:01:42.426Z,1639774902.426 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,210141.00,A,3648.13012,N,12147.22652,W,0.078,309.10,171221,,,D*74 2021-12-17T21:01:42.428Z,1639774902.428 [NAL9602](INFO): GPS fix at 20211217T210141: (36.802169, -121.787109) 2021-12-17T21:01:42.439Z,1639774902.439 [Default:CheckIn:Read_GPS] Stopped 2021-12-17T21:01:42.439Z,1639774902.439 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-17T21:01:47.665Z,1639774907.665 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file). 2021-12-17T21:01:49.853Z,1639774909.853 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211217T201953/Courier0024.lzma 2021-12-17T21:01:50.855Z,1639774910.855 [DataOverHttps](INFO): Moved sent file to Logs/20211217T201953/Courier0024.lzma.bak 2021-12-17T21:01:50.855Z,1639774910.855 [DataOverHttps](INFO): SBD MOMSN=16398031 2021-12-17T21:02:01.008Z,1639774921.008 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file). 2021-12-17T21:02:06.721Z,1639774926.721 [DataOverHttps](INFO): Sending 154 bytes from file Logs/20211217T201953/Express0025.lzma 2021-12-17T21:02:07.723Z,1639774927.723 [DataOverHttps](INFO): Moved sent file to Logs/20211217T201953/Express0025.lzma.bak 2021-12-17T21:02:07.723Z,1639774927.723 [DataOverHttps](INFO): SBD MOMSN=16398034 2021-12-17T21:02:09.095Z,1639774929.095 [Default:CheckIn:Read_Iridium] Stopped 2021-12-17T21:02:09.096Z,1639774929.096 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-17T21:02:09.096Z,1639774929.096 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-17T21:02:14.340Z,1639774934.340 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file). 2021-12-17T21:02:28.067Z,1639774948.067 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file). 2021-12-17T21:02:42.209Z,1639774962.209 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file). 2021-12-17T21:02:55.943Z,1639774975.943 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file). 2021-12-17T21:03:09.680Z,1639774989.680 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file). 2021-12-17T21:03:23.010Z,1639775003.010 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file). 2021-12-17T21:03:35.938Z,1639775015.938 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file). 2021-12-17T21:03:42.002Z,1639775022.002 [NAL9602](INFO): SBD MO Status=2, MOMSN=7633, MT Status=2, MTMSN=0 2021-12-17T21:03:42.002Z,1639775022.002 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-12-17T21:03:49.675Z,1639775029.675 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file). 2021-12-17T21:04:03.449Z,1639775043.449 [BPC1](INFO): Calculating totals. Valid battery stick count: 31. Valid reserve battery stick count: 5. 2021-12-17T21:04:03.452Z,1639775043.452 [BPC1](INFO): Received data from all battery sticks. 2021-12-17T21:04:11.904Z,1639775051.904 [NAL9602](INFO): SBD MO Status=0, MOMSN=7633, MT Status=0, MTMSN=0 2021-12-17T21:04:11.905Z,1639775051.905 [NAL9602](INFO): No messages in MT queue 2021-12-17T21:04:42.614Z,1639775082.614 [NAL9602](INFO): Not Powering down - fast GPS 2021-12-17T21:07:09.821Z,1639775229.821 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-17T21:07:09.821Z,1639775229.821 [Default:CheckIn:C.Wait] Stopped 2021-12-17T21:07:09.822Z,1639775229.822 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-17T21:07:09.822Z,1639775229.822 [Default:CheckIn:D] Running Loop=1 2021-12-17T21:07:10.213Z,1639775230.213 [Default:CheckIn:D] Stopped 2021-12-17T21:07:10.213Z,1639775230.213 [Default:CheckIn:E] Running Loop=1 2021-12-17T21:07:10.622Z,1639775230.622 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 130.395304 min 2021-12-17T21:07:10.623Z,1639775230.623 [Default:CheckIn:E] Stopped 2021-12-17T21:07:10.623Z,1639775230.623 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-17T21:07:10.623Z,1639775230.623 [Default:CheckIn] Stopped 2021-12-17T21:07:10.623Z,1639775230.623 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-17T21:07:10.623Z,1639775230.623 [Default:CheckIn](INFO): Running loop #23 2021-12-17T21:07:10.623Z,1639775230.623 [Default:CheckIn] Running Loop=23 2021-12-17T21:07:10.623Z,1639775230.623 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-17T21:07:10.623Z,1639775230.623 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-17T21:07:12.629Z,1639775232.629 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,210711.00,A,3648.12934,N,12147.22611,W,0.019,309.10,171221,,,A*7E 2021-12-17T21:07:12.640Z,1639775232.640 [NAL9602](INFO): GPS fix at 20211217T210711: (36.802156, -121.787102) 2021-12-17T21:07:12.652Z,1639775232.652 [Default:CheckIn:Read_GPS] Stopped 2021-12-17T21:07:12.652Z,1639775232.652 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-17T21:07:20.149Z,1639775240.149 [DataOverHttps](INFO): Sending 202 bytes from file Logs/20211217T201953/Courier0027.lzma 2021-12-17T21:07:21.151Z,1639775241.151 [DataOverHttps](INFO): Moved sent file to Logs/20211217T201953/Courier0027.lzma.bak 2021-12-17T21:07:21.152Z,1639775241.152 [DataOverHttps](INFO): SBD MOMSN=16398038 2021-12-17T21:07:27.573Z,1639775247.573 [NAL9602](INFO): SBD MO Status=0, MOMSN=7634, MT Status=0, MTMSN=0 2021-12-17T21:07:27.573Z,1639775247.573 [NAL9602](INFO): No messages in MT queue 2021-12-17T21:07:37.009Z,1639775257.009 [DataOverHttps](INFO): Sending 142 bytes from file Logs/20211217T201953/Express0028.lzma 2021-12-17T21:07:38.013Z,1639775258.013 [DataOverHttps](INFO): Moved sent file to Logs/20211217T201953/Express0028.lzma.bak 2021-12-17T21:07:38.013Z,1639775258.013 [DataOverHttps](INFO): SBD MOMSN=16398042 2021-12-17T21:07:39.708Z,1639775259.708 [Default:CheckIn:Read_Iridium] Stopped 2021-12-17T21:07:39.708Z,1639775259.708 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-17T21:07:39.708Z,1639775259.708 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-17T21:07:58.274Z,1639775278.274 [NAL9602](INFO): Not Powering down - fast GPS 2021-12-17T21:12:40.325Z,1639775560.325 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-17T21:12:40.325Z,1639775560.325 [Default:CheckIn:C.Wait] Stopped 2021-12-17T21:12:40.325Z,1639775560.325 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-17T21:12:40.326Z,1639775560.326 [Default:CheckIn:D] Running Loop=1 2021-12-17T21:12:40.742Z,1639775560.742 [Default:CheckIn:D] Stopped 2021-12-17T21:12:40.742Z,1639775560.742 [Default:CheckIn:E] Running Loop=1 2021-12-17T21:12:41.145Z,1639775561.145 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 135.904110 min 2021-12-17T21:12:41.145Z,1639775561.145 [Default:CheckIn:E] Stopped 2021-12-17T21:12:41.145Z,1639775561.145 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-17T21:12:41.145Z,1639775561.145 [Default:CheckIn] Stopped 2021-12-17T21:12:41.145Z,1639775561.145 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-17T21:12:41.146Z,1639775561.146 [Default:CheckIn](INFO): Running loop #24 2021-12-17T21:12:41.146Z,1639775561.146 [Default:CheckIn] Running Loop=24 2021-12-17T21:12:41.146Z,1639775561.146 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-17T21:12:41.146Z,1639775561.146 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-17T21:12:43.145Z,1639775563.145 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,211242.00,A,3648.12898,N,12147.22463,W,0.078,309.10,171221,,,A*7B 2021-12-17T21:12:43.147Z,1639775563.147 [NAL9602](INFO): GPS fix at 20211217T211242: (36.802150, -121.787077) 2021-12-17T21:12:43.185Z,1639775563.185 [Default:CheckIn:Read_GPS] Stopped 2021-12-17T21:12:43.185Z,1639775563.185 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-17T21:12:50.377Z,1639775570.377 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211217T201953/Courier0030.lzma 2021-12-17T21:12:51.379Z,1639775571.379 [DataOverHttps](INFO): Moved sent file to Logs/20211217T201953/Courier0030.lzma.bak 2021-12-17T21:12:51.379Z,1639775571.379 [DataOverHttps](INFO): SBD MOMSN=16398052 2021-12-17T21:12:59.708Z,1639775579.708 [NAL9602](INFO): SBD MO Status=0, MOMSN=7635, MT Status=0, MTMSN=0 2021-12-17T21:12:59.708Z,1639775579.708 [NAL9602](INFO): No messages in MT queue 2021-12-17T21:13:09.889Z,1639775589.889 [DataOverHttps](INFO): Sending 139 bytes from file Logs/20211217T201953/Express0031.lzma 2021-12-17T21:13:10.891Z,1639775590.891 [DataOverHttps](INFO): Moved sent file to Logs/20211217T201953/Express0031.lzma.bak 2021-12-17T21:13:10.892Z,1639775590.892 [DataOverHttps](INFO): SBD MOMSN=16398055 2021-12-17T21:13:12.314Z,1639775592.314 [Default:CheckIn:Read_Iridium] Stopped 2021-12-17T21:13:12.314Z,1639775592.314 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-17T21:13:12.314Z,1639775592.314 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-17T21:13:30.467Z,1639775610.467 [NAL9602](INFO): Not Powering down - fast GPS 2021-12-17T21:18:12.921Z,1639775892.921 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-17T21:18:12.921Z,1639775892.921 [Default:CheckIn:C.Wait] Stopped 2021-12-17T21:18:12.922Z,1639775892.922 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-17T21:18:12.922Z,1639775892.922 [Default:CheckIn:D] Running Loop=1 2021-12-17T21:18:13.313Z,1639775893.313 [Default:CheckIn:D] Stopped 2021-12-17T21:18:13.313Z,1639775893.313 [Default:CheckIn:E] Running Loop=1 2021-12-17T21:18:13.718Z,1639775893.718 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 141.446973 min 2021-12-17T21:18:13.718Z,1639775893.718 [Default:CheckIn:E] Stopped 2021-12-17T21:18:13.718Z,1639775893.718 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-17T21:18:13.719Z,1639775893.719 [Default:CheckIn] Stopped 2021-12-17T21:18:13.719Z,1639775893.719 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-17T21:18:13.719Z,1639775893.719 [Default:CheckIn](INFO): Running loop #25 2021-12-17T21:18:13.719Z,1639775893.719 [Default:CheckIn] Running Loop=25 2021-12-17T21:18:13.719Z,1639775893.719 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-17T21:18:13.719Z,1639775893.719 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-17T21:18:15.736Z,1639775895.736 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,211814.00,A,3648.16494,N,12147.21305,W,0.058,257.63,171221,,,A*7E 2021-12-17T21:18:15.738Z,1639775895.738 [NAL9602](INFO): GPS fix at 20211217T211814: (36.802749, -121.786884) 2021-12-17T21:18:15.750Z,1639775895.750 [Default:CheckIn:Read_GPS] Stopped 2021-12-17T21:18:15.750Z,1639775895.750 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-17T21:18:26.054Z,1639775906.054 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211217T201953/Courier0033.lzma 2021-12-17T21:18:27.055Z,1639775907.055 [DataOverHttps](INFO): Moved sent file to Logs/20211217T201953/Courier0033.lzma.bak 2021-12-17T21:18:27.056Z,1639775907.056 [DataOverHttps](INFO): SBD MOMSN=16398059 2021-12-17T21:18:39.220Z,1639775919.220 [NAL9602](INFO): SBD MO Status=2, MOMSN=7636, MT Status=2, MTMSN=0 2021-12-17T21:18:39.220Z,1639775919.220 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-12-17T21:18:43.221Z,1639775923.221 [DataOverHttps](INFO): Sending 149 bytes from file Logs/20211217T201953/Express0034.lzma 2021-12-17T21:18:44.223Z,1639775924.223 [DataOverHttps](INFO): Moved sent file to Logs/20211217T201953/Express0034.lzma.bak 2021-12-17T21:18:44.223Z,1639775924.223 [DataOverHttps](INFO): SBD MOMSN=16398062 2021-12-17T21:18:45.696Z,1639775925.696 [Default:CheckIn:Read_Iridium] Stopped 2021-12-17T21:18:45.697Z,1639775925.697 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-17T21:18:45.701Z,1639775925.701 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-17T21:19:04.270Z,1639775944.270 [NAL9602](INFO): SBD MO Status=2, MOMSN=7636, MT Status=2, MTMSN=0 2021-12-17T21:19:04.270Z,1639775944.270 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-12-17T21:19:23.656Z,1639775963.656 [NAL9602](INFO): SBD MO Status=2, MOMSN=7636, MT Status=2, MTMSN=0 2021-12-17T21:19:23.656Z,1639775963.656 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-12-17T21:19:44.261Z,1639775984.261 [NAL9602](INFO): SBD MO Status=0, MOMSN=7636, MT Status=0, MTMSN=0 2021-12-17T21:19:44.261Z,1639775984.261 [NAL9602](INFO): No messages in MT queue 2021-12-17T21:20:14.963Z,1639776014.963 [NAL9602](INFO): Not Powering down - fast GPS 2021-12-17T21:23:46.339Z,1639776226.339 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-17T21:23:46.340Z,1639776226.340 [Default:CheckIn:C.Wait] Stopped 2021-12-17T21:23:46.340Z,1639776226.340 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-17T21:23:46.340Z,1639776226.340 [Default:CheckIn:D] Running Loop=1 2021-12-17T21:23:46.754Z,1639776226.754 [Default:CheckIn:D] Stopped 2021-12-17T21:23:46.754Z,1639776226.754 [Default:CheckIn:E] Running Loop=1 2021-12-17T21:23:47.139Z,1639776227.139 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 147.004297 min 2021-12-17T21:23:47.139Z,1639776227.139 [Default:CheckIn:E] Stopped 2021-12-17T21:23:47.140Z,1639776227.140 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-17T21:23:47.140Z,1639776227.140 [Default:CheckIn] Stopped 2021-12-17T21:23:47.140Z,1639776227.140 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-17T21:23:47.140Z,1639776227.140 [Default:CheckIn](INFO): Running loop #26 2021-12-17T21:23:47.140Z,1639776227.140 [Default:CheckIn] Running Loop=26 2021-12-17T21:23:47.140Z,1639776227.140 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-17T21:23:47.141Z,1639776227.141 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-17T21:23:49.156Z,1639776229.156 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,212348.00,A,3648.14086,N,12147.22784,W,0.097,198.55,171221,,,D*77 2021-12-17T21:23:49.159Z,1639776229.159 [NAL9602](INFO): GPS fix at 20211217T212348: (36.802348, -121.787131) 2021-12-17T21:23:49.188Z,1639776229.188 [Default:CheckIn:Read_GPS] Stopped 2021-12-17T21:23:49.188Z,1639776229.188 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-17T21:23:56.961Z,1639776236.961 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20211217T201953/Courier0036.lzma 2021-12-17T21:23:57.963Z,1639776237.963 [DataOverHttps](INFO): Moved sent file to Logs/20211217T201953/Courier0036.lzma.bak 2021-12-17T21:23:57.964Z,1639776237.964 [DataOverHttps](INFO): SBD MOMSN=16398073 2021-12-17T21:24:13.814Z,1639776253.814 [DataOverHttps](INFO): Sending 210 bytes from file Logs/20211217T201953/Express0037.lzma 2021-12-17T21:24:14.815Z,1639776254.815 [DataOverHttps](INFO): Moved sent file to Logs/20211217T201953/Express0037.lzma.bak 2021-12-17T21:24:14.815Z,1639776254.815 [DataOverHttps](INFO): SBD MOMSN=16398076 2021-12-17T21:24:16.241Z,1639776256.241 [Default:CheckIn:Read_Iridium] Stopped 2021-12-17T21:24:16.241Z,1639776256.241 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-17T21:24:16.241Z,1639776256.241 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-17T21:26:50.602Z,1639776410.602 [NAL9602](INFO): SBD MO Status=2, MOMSN=7637, MT Status=2, MTMSN=0 2021-12-17T21:26:50.602Z,1639776410.602 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-12-17T21:27:20.092Z,1639776440.092 [NAL9602](INFO): SBD MO Status=0, MOMSN=7637, MT Status=0, MTMSN=0 2021-12-17T21:27:20.093Z,1639776440.093 [NAL9602](INFO): No messages in MT queue 2021-12-17T21:27:50.787Z,1639776470.787 [NAL9602](INFO): Not Powering down - fast GPS 2021-12-17T21:29:16.983Z,1639776556.983 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-17T21:29:16.983Z,1639776556.983 [Default:CheckIn:C.Wait] Stopped 2021-12-17T21:29:16.983Z,1639776556.983 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-17T21:29:16.983Z,1639776556.983 [Default:CheckIn:D] Running Loop=1 2021-12-17T21:29:17.394Z,1639776557.394 [Default:CheckIn:D] Stopped 2021-12-17T21:29:17.395Z,1639776557.395 [Default:CheckIn:E] Running Loop=1 2021-12-17T21:29:17.786Z,1639776557.786 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 152.514990 min 2021-12-17T21:29:17.786Z,1639776557.786 [Default:CheckIn:E] Stopped 2021-12-17T21:29:17.786Z,1639776557.786 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-17T21:29:17.786Z,1639776557.786 [Default:CheckIn] Stopped 2021-12-17T21:29:17.786Z,1639776557.786 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-17T21:29:17.786Z,1639776557.786 [Default:CheckIn](INFO): Running loop #27 2021-12-17T21:29:17.786Z,1639776557.786 [Default:CheckIn] Running Loop=27 2021-12-17T21:29:17.787Z,1639776557.787 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-17T21:29:17.787Z,1639776557.787 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-17T21:29:19.793Z,1639776559.793 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,212919.00,A,3648.14334,N,12147.22827,W,0.058,198.55,171221,,,D*76 2021-12-17T21:29:19.795Z,1639776559.795 [NAL9602](INFO): GPS fix at 20211217T212919: (36.802389, -121.787138) 2021-12-17T21:29:19.806Z,1639776559.806 [Default:CheckIn:Read_GPS] Stopped 2021-12-17T21:29:19.806Z,1639776559.806 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-17T21:29:27.041Z,1639776567.041 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211217T201953/Courier0039.lzma 2021-12-17T21:29:28.043Z,1639776568.043 [DataOverHttps](INFO): Moved sent file to Logs/20211217T201953/Courier0039.lzma.bak 2021-12-17T21:29:28.043Z,1639776568.043 [DataOverHttps](INFO): SBD MOMSN=16398079 2021-12-17T21:29:37.172Z,1639776577.172 [NAL9602](INFO): SBD MO Status=0, MOMSN=7638, MT Status=0, MTMSN=0 2021-12-17T21:29:37.172Z,1639776577.172 [NAL9602](INFO): No messages in MT queue 2021-12-17T21:29:44.489Z,1639776584.489 [DataOverHttps](INFO): Sending 141 bytes from file Logs/20211217T201953/Express0040.lzma 2021-12-17T21:29:45.491Z,1639776585.491 [DataOverHttps](INFO): Moved sent file to Logs/20211217T201953/Express0040.lzma.bak 2021-12-17T21:29:45.491Z,1639776585.491 [DataOverHttps](INFO): SBD MOMSN=16398082 2021-12-17T21:29:46.887Z,1639776586.887 [Default:CheckIn:Read_Iridium] Stopped 2021-12-17T21:29:46.887Z,1639776586.887 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-17T21:29:46.887Z,1639776586.887 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-17T21:30:07.866Z,1639776607.866 [NAL9602](INFO): Not Powering down - fast GPS 2021-12-17T21:34:47.555Z,1639776887.555 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-17T21:34:47.555Z,1639776887.555 [Default:CheckIn:C.Wait] Stopped 2021-12-17T21:34:47.555Z,1639776887.555 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-17T21:34:47.555Z,1639776887.555 [Default:CheckIn:D] Running Loop=1 2021-12-17T21:34:47.942Z,1639776887.942 [Default:CheckIn:D] Stopped 2021-12-17T21:34:47.942Z,1639776887.942 [Default:CheckIn:E] Running Loop=1 2021-12-17T21:34:48.349Z,1639776888.349 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 158.024105 min 2021-12-17T21:34:48.350Z,1639776888.350 [Default:CheckIn:E] Stopped 2021-12-17T21:34:48.350Z,1639776888.350 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-17T21:34:48.350Z,1639776888.350 [Default:CheckIn] Stopped 2021-12-17T21:34:48.350Z,1639776888.350 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-17T21:34:48.350Z,1639776888.350 [Default:CheckIn](INFO): Running loop #28 2021-12-17T21:34:48.350Z,1639776888.350 [Default:CheckIn] Running Loop=28 2021-12-17T21:34:48.350Z,1639776888.350 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-17T21:34:48.351Z,1639776888.351 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-17T21:34:50.358Z,1639776890.358 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,213449.00,A,3648.14224,N,12147.22853,W,0.039,198.55,171221,,,D*7B 2021-12-17T21:34:50.360Z,1639776890.360 [NAL9602](INFO): GPS fix at 20211217T213449: (36.802371, -121.787142) 2021-12-17T21:34:50.372Z,1639776890.372 [Default:CheckIn:Read_GPS] Stopped 2021-12-17T21:34:50.372Z,1639776890.372 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-17T21:34:57.569Z,1639776897.569 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211217T201953/Courier0042.lzma 2021-12-17T21:34:58.572Z,1639776898.572 [DataOverHttps](INFO): Moved sent file to Logs/20211217T201953/Courier0042.lzma.bak 2021-12-17T21:34:58.572Z,1639776898.572 [DataOverHttps](INFO): SBD MOMSN=16398093 2021-12-17T21:35:16.668Z,1639776916.668 [NAL9602](INFO): SBD MO Status=0, MOMSN=7639, MT Status=0, MTMSN=0 2021-12-17T21:35:16.668Z,1639776916.668 [NAL9602](INFO): No messages in MT queue 2021-12-17T21:35:17.643Z,1639776917.643 [DataOverHttps](INFO): Sending 141 bytes from file Logs/20211217T201953/Express0043.lzma 2021-12-17T21:35:18.643Z,1639776918.643 [DataOverHttps](INFO): Moved sent file to Logs/20211217T201953/Express0043.lzma.bak 2021-12-17T21:35:18.643Z,1639776918.643 [DataOverHttps](INFO): SBD MOMSN=16398096 2021-12-17T21:35:19.910Z,1639776919.910 [Default:CheckIn:Read_Iridium] Stopped 2021-12-17T21:35:19.911Z,1639776919.911 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-17T21:35:19.911Z,1639776919.911 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-17T21:35:47.368Z,1639776947.368 [NAL9602](INFO): Not Powering down - fast GPS 2021-12-17T21:40:20.690Z,1639777220.690 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-17T21:40:20.690Z,1639777220.690 [Default:CheckIn:C.Wait] Stopped 2021-12-17T21:40:20.690Z,1639777220.690 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-17T21:40:20.690Z,1639777220.690 [Default:CheckIn:D] Running Loop=1 2021-12-17T21:40:21.107Z,1639777221.107 [Default:CheckIn:D] Stopped 2021-12-17T21:40:21.107Z,1639777221.107 [Default:CheckIn:E] Running Loop=1 2021-12-17T21:40:21.484Z,1639777221.484 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 163.576872 min 2021-12-17T21:40:21.484Z,1639777221.484 [Default:CheckIn:E] Stopped 2021-12-17T21:40:21.484Z,1639777221.484 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-17T21:40:21.484Z,1639777221.484 [Default:CheckIn] Stopped 2021-12-17T21:40:21.484Z,1639777221.484 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-17T21:40:21.484Z,1639777221.484 [Default:CheckIn](INFO): Running loop #29 2021-12-17T21:40:21.485Z,1639777221.485 [Default:CheckIn] Running Loop=29 2021-12-17T21:40:21.485Z,1639777221.485 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-17T21:40:21.485Z,1639777221.485 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-17T21:40:23.492Z,1639777223.492 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,214022.00,A,3648.14143,N,12147.22779,W,0.058,199.41,171221,,,D*73 2021-12-17T21:40:23.495Z,1639777223.495 [NAL9602](INFO): GPS fix at 20211217T214022: (36.802357, -121.787130) 2021-12-17T21:40:23.538Z,1639777223.538 [Default:CheckIn:Read_GPS] Stopped 2021-12-17T21:40:23.538Z,1639777223.538 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-17T21:40:31.137Z,1639777231.137 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211217T201953/Courier0045.lzma 2021-12-17T21:40:32.139Z,1639777232.139 [DataOverHttps](INFO): Moved sent file to Logs/20211217T201953/Courier0045.lzma.bak 2021-12-17T21:40:32.139Z,1639777232.139 [DataOverHttps](INFO): SBD MOMSN=16398100 2021-12-17T21:40:36.426Z,1639777236.426 [NAL9602](INFO): SBD MO Status=0, MOMSN=7640, MT Status=0, MTMSN=0 2021-12-17T21:40:36.426Z,1639777236.426 [NAL9602](INFO): No messages in MT queue 2021-12-17T21:40:48.161Z,1639777248.161 [DataOverHttps](INFO): Sending 140 bytes from file Logs/20211217T201953/Express0046.lzma 2021-12-17T21:40:49.163Z,1639777249.163 [DataOverHttps](INFO): Moved sent file to Logs/20211217T201953/Express0046.lzma.bak 2021-12-17T21:40:49.164Z,1639777249.164 [DataOverHttps](INFO): SBD MOMSN=16398103 2021-12-17T21:40:50.578Z,1639777250.578 [Default:CheckIn:Read_Iridium] Stopped 2021-12-17T21:40:50.578Z,1639777250.578 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-17T21:40:50.578Z,1639777250.578 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-17T21:41:07.122Z,1639777267.122 [NAL9602](INFO): Not Powering down - fast GPS 2021-12-17T21:45:51.219Z,1639777551.219 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-17T21:45:51.219Z,1639777551.219 [Default:CheckIn:C.Wait] Stopped 2021-12-17T21:45:51.219Z,1639777551.219 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-17T21:45:51.220Z,1639777551.220 [Default:CheckIn:D] Running Loop=1 2021-12-17T21:45:51.594Z,1639777551.594 [Default:CheckIn:D] Stopped 2021-12-17T21:45:51.594Z,1639777551.594 [Default:CheckIn:E] Running Loop=1 2021-12-17T21:45:52.013Z,1639777552.013 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 169.084993 min 2021-12-17T21:45:52.013Z,1639777552.013 [Default:CheckIn:E] Stopped 2021-12-17T21:45:52.013Z,1639777552.013 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-17T21:45:52.013Z,1639777552.013 [Default:CheckIn] Stopped 2021-12-17T21:45:52.013Z,1639777552.013 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-17T21:45:52.013Z,1639777552.013 [Default:CheckIn](INFO): Running loop #30 2021-12-17T21:45:52.013Z,1639777552.013 [Default:CheckIn] Running Loop=30 2021-12-17T21:45:52.014Z,1639777552.014 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-17T21:45:52.014Z,1639777552.014 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-17T21:45:54.005Z,1639777554.005 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,214553.00,A,3648.14238,N,12147.22757,W,0.058,199.41,171221,,,D*73 2021-12-17T21:45:54.007Z,1639777554.007 [NAL9602](INFO): GPS fix at 20211217T214553: (36.802373, -121.787126) 2021-12-17T21:45:54.018Z,1639777554.018 [Default:CheckIn:Read_GPS] Stopped 2021-12-17T21:45:54.019Z,1639777554.019 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-17T21:46:00.941Z,1639777560.941 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211217T201953/Courier0048.lzma 2021-12-17T21:46:01.943Z,1639777561.943 [DataOverHttps](INFO): Moved sent file to Logs/20211217T201953/Courier0048.lzma.bak 2021-12-17T21:46:01.943Z,1639777561.943 [DataOverHttps](INFO): SBD MOMSN=16398115 2021-12-17T21:46:10.972Z,1639777570.972 [NAL9602](INFO): SBD MO Status=0, MOMSN=7641, MT Status=0, MTMSN=0 2021-12-17T21:46:10.972Z,1639777570.972 [NAL9602](INFO): No messages in MT queue 2021-12-17T21:46:17.829Z,1639777577.829 [DataOverHttps](INFO): Sending 140 bytes from file Logs/20211217T201953/Express0049.lzma 2021-12-17T21:46:18.831Z,1639777578.831 [DataOverHttps](INFO): Moved sent file to Logs/20211217T201953/Express0049.lzma.bak 2021-12-17T21:46:18.832Z,1639777578.832 [DataOverHttps](INFO): SBD MOMSN=16398118 2021-12-17T21:46:20.280Z,1639777580.280 [Default:CheckIn:Read_Iridium] Stopped 2021-12-17T21:46:20.280Z,1639777580.280 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-17T21:46:20.280Z,1639777580.280 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-17T21:46:41.722Z,1639777601.722 [NAL9602](INFO): Not Powering down - fast GPS 2021-12-17T21:51:21.001Z,1639777881.001 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-17T21:51:21.002Z,1639777881.002 [Default:CheckIn:C.Wait] Stopped 2021-12-17T21:51:21.002Z,1639777881.002 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-17T21:51:21.002Z,1639777881.002 [Default:CheckIn:D] Running Loop=1 2021-12-17T21:51:21.408Z,1639777881.408 [Default:CheckIn:D] Stopped 2021-12-17T21:51:21.408Z,1639777881.408 [Default:CheckIn:E] Running Loop=1 2021-12-17T21:51:21.822Z,1639777881.822 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 174.581885 min 2021-12-17T21:51:21.822Z,1639777881.822 [Default:CheckIn:E] Stopped 2021-12-17T21:51:21.822Z,1639777881.822 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-17T21:51:21.822Z,1639777881.822 [Default:CheckIn] Stopped 2021-12-17T21:51:21.822Z,1639777881.822 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-17T21:51:21.822Z,1639777881.822 [Default:CheckIn](INFO): Running loop #31 2021-12-17T21:51:21.823Z,1639777881.823 [Default:CheckIn] Running Loop=31 2021-12-17T21:51:21.823Z,1639777881.823 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-17T21:51:21.823Z,1639777881.823 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-17T21:51:23.824Z,1639777883.824 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,215123.00,A,3648.14003,N,12147.22973,W,0.019,199.41,171221,,,D*76 2021-12-17T21:51:23.827Z,1639777883.827 [NAL9602](INFO): GPS fix at 20211217T215123: (36.802334, -121.787162) 2021-12-17T21:51:23.856Z,1639777883.856 [Default:CheckIn:Read_GPS] Stopped 2021-12-17T21:51:23.856Z,1639777883.856 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-17T21:51:32.037Z,1639777892.037 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211217T201953/Courier0051.lzma 2021-12-17T21:51:33.041Z,1639777893.041 [DataOverHttps](INFO): Moved sent file to Logs/20211217T201953/Courier0051.lzma.bak 2021-12-17T21:51:33.042Z,1639777893.042 [DataOverHttps](INFO): SBD MOMSN=16398122 2021-12-17T21:51:48.929Z,1639777908.929 [DataOverHttps](INFO): Sending 142 bytes from file Logs/20211217T201953/Express0052.lzma 2021-12-17T21:51:49.931Z,1639777909.931 [DataOverHttps](INFO): Moved sent file to Logs/20211217T201953/Express0052.lzma.bak 2021-12-17T21:51:49.931Z,1639777909.931 [DataOverHttps](INFO): SBD MOMSN=16398125 2021-12-17T21:51:51.314Z,1639777911.314 [Default:CheckIn:Read_Iridium] Stopped 2021-12-17T21:51:51.314Z,1639777911.314 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-17T21:51:51.315Z,1639777911.315 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-17T21:51:58.164Z,1639777918.164 [NAL9602](INFO): SBD MO Status=0, MOMSN=7642, MT Status=0, MTMSN=0 2021-12-17T21:51:58.164Z,1639777918.164 [NAL9602](INFO): No messages in MT queue 2021-12-17T21:52:28.863Z,1639777948.863 [NAL9602](INFO): Not Powering down - fast GPS 2021-12-17T21:56:51.939Z,1639778211.939 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-17T21:56:51.939Z,1639778211.939 [Default:CheckIn:C.Wait] Stopped 2021-12-17T21:56:51.939Z,1639778211.939 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-17T21:56:51.940Z,1639778211.940 [Default:CheckIn:D] Running Loop=1 2021-12-17T21:56:52.354Z,1639778212.354 [Default:CheckIn:D] Stopped 2021-12-17T21:56:52.354Z,1639778212.354 [Default:CheckIn:E] Running Loop=1 2021-12-17T21:56:52.749Z,1639778212.749 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 180.097656 min 2021-12-17T21:56:52.749Z,1639778212.749 [Default:CheckIn:E] Stopped 2021-12-17T21:56:52.750Z,1639778212.750 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-17T21:56:52.750Z,1639778212.750 [Default:CheckIn] Stopped 2021-12-17T21:56:52.750Z,1639778212.750 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-17T21:56:52.750Z,1639778212.750 [Default:CheckIn](INFO): Running loop #32 2021-12-17T21:56:52.750Z,1639778212.750 [Default:CheckIn] Running Loop=32 2021-12-17T21:56:52.750Z,1639778212.750 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-17T21:56:52.750Z,1639778212.750 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-17T21:56:54.756Z,1639778214.756 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,215653.00,A,3648.14087,N,12147.22812,W,0.058,199.41,171221,,,D*79 2021-12-17T21:56:54.759Z,1639778214.759 [NAL9602](INFO): GPS fix at 20211217T215653: (36.802348, -121.787135) 2021-12-17T21:56:54.787Z,1639778214.787 [Default:CheckIn:Read_GPS] Stopped 2021-12-17T21:56:54.787Z,1639778214.787 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-17T21:57:02.645Z,1639778222.645 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211217T201953/Courier0054.lzma 2021-12-17T21:57:03.647Z,1639778223.647 [DataOverHttps](INFO): Moved sent file to Logs/20211217T201953/Courier0054.lzma.bak 2021-12-17T21:57:03.647Z,1639778223.647 [DataOverHttps](INFO): SBD MOMSN=16398154 2021-12-17T21:57:08.936Z,1639778228.936 [NAL9602](INFO): SBD MO Status=0, MOMSN=7643, MT Status=0, MTMSN=0 2021-12-17T21:57:08.936Z,1639778228.936 [NAL9602](INFO): No messages in MT queue 2021-12-17T21:57:22.221Z,1639778242.221 [DataOverHttps](INFO): Sending 142 bytes from file Logs/20211217T201953/Express0055.lzma 2021-12-17T21:57:23.223Z,1639778243.223 [DataOverHttps](INFO): Moved sent file to Logs/20211217T201953/Express0055.lzma.bak 2021-12-17T21:57:23.223Z,1639778243.223 [DataOverHttps](INFO): SBD MOMSN=16398157 2021-12-17T21:57:24.721Z,1639778244.721 [Default:CheckIn:Read_Iridium] Stopped 2021-12-17T21:57:24.722Z,1639778244.722 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-17T21:57:24.722Z,1639778244.722 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-17T21:57:39.658Z,1639778259.658 [NAL9602](INFO): Not Powering down - fast GPS 2021-12-17T22:02:25.386Z,1639778545.386 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-17T22:02:25.386Z,1639778545.386 [Default:CheckIn:C.Wait] Stopped 2021-12-17T22:02:25.386Z,1639778545.386 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-17T22:02:25.386Z,1639778545.386 [Default:CheckIn:D] Running Loop=1 2021-12-17T22:02:25.823Z,1639778545.823 [Default:CheckIn:D] Stopped 2021-12-17T22:02:25.823Z,1639778545.823 [Default:CheckIn:E] Running Loop=1 2021-12-17T22:02:26.208Z,1639778546.208 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 185.655469 min 2021-12-17T22:02:26.208Z,1639778546.208 [Default:CheckIn:E] Stopped 2021-12-17T22:02:26.208Z,1639778546.208 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-17T22:02:26.208Z,1639778546.208 [Default:CheckIn] Stopped 2021-12-17T22:02:26.208Z,1639778546.208 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-17T22:02:26.208Z,1639778546.208 [Default:CheckIn](INFO): Running loop #33 2021-12-17T22:02:26.208Z,1639778546.208 [Default:CheckIn] Running Loop=33 2021-12-17T22:02:26.209Z,1639778546.209 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-17T22:02:26.209Z,1639778546.209 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-17T22:02:28.205Z,1639778548.205 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,220227.00,A,3648.13983,N,12147.22805,W,0.330,199.41,171221,,,D*79 2021-12-17T22:02:28.207Z,1639778548.207 [NAL9602](INFO): GPS fix at 20211217T220227: (36.802330, -121.787134) 2021-12-17T22:02:28.218Z,1639778548.218 [Default:CheckIn:Read_GPS] Stopped 2021-12-17T22:02:28.218Z,1639778548.218 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-17T22:02:35.969Z,1639778555.969 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20211217T201953/Courier0057.lzma 2021-12-17T22:02:36.971Z,1639778556.971 [DataOverHttps](INFO): Moved sent file to Logs/20211217T201953/Courier0057.lzma.bak 2021-12-17T22:02:36.971Z,1639778556.971 [DataOverHttps](INFO): SBD MOMSN=16398161 2021-12-17T22:02:52.835Z,1639778572.835 [DataOverHttps](INFO): Sending 140 bytes from file Logs/20211217T201953/Express0058.lzma 2021-12-17T22:02:53.831Z,1639778573.831 [DataOverHttps](INFO): Moved sent file to Logs/20211217T201953/Express0058.lzma.bak 2021-12-17T22:02:53.832Z,1639778573.832 [DataOverHttps](INFO): SBD MOMSN=16398164 2021-12-17T22:02:55.299Z,1639778575.299 [Default:CheckIn:Read_Iridium] Stopped 2021-12-17T22:02:55.299Z,1639778575.299 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-17T22:02:55.299Z,1639778575.299 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-17T22:02:55.680Z,1639778575.680 [NAL9602](INFO): SBD MO Status=0, MOMSN=7644, MT Status=0, MTMSN=0 2021-12-17T22:02:55.680Z,1639778575.680 [NAL9602](INFO): No messages in MT queue 2021-12-17T22:03:26.391Z,1639778606.391 [NAL9602](INFO): Not Powering down - fast GPS 2021-12-17T22:06:32.241Z,1639778792.241 [BPC1](ERROR): BPC1B: No match for serial number 0C29 in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file). 2021-12-17T22:06:46.362Z,1639778806.362 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file). 2021-12-17T22:06:59.694Z,1639778819.694 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file). 2021-12-17T22:07:13.078Z,1639778833.078 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file). 2021-12-17T22:07:27.219Z,1639778847.219 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file). 2021-12-17T22:07:40.551Z,1639778860.551 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file). 2021-12-17T22:07:54.286Z,1639778874.286 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file). 2021-12-17T22:07:55.918Z,1639778875.918 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-17T22:07:55.918Z,1639778875.918 [Default:CheckIn:C.Wait] Stopped 2021-12-17T22:07:55.918Z,1639778875.918 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-17T22:07:55.918Z,1639778875.918 [Default:CheckIn:D] Running Loop=1 2021-12-17T22:07:56.319Z,1639778876.319 [Default:CheckIn:D] Stopped 2021-12-17T22:07:56.319Z,1639778876.319 [Default:CheckIn:E] Running Loop=1 2021-12-17T22:07:56.728Z,1639778876.728 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 191.163737 min 2021-12-17T22:07:56.728Z,1639778876.728 [Default:CheckIn:E] Stopped 2021-12-17T22:07:56.729Z,1639778876.729 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-17T22:07:56.729Z,1639778876.729 [Default:CheckIn] Stopped 2021-12-17T22:07:56.729Z,1639778876.729 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-17T22:07:56.729Z,1639778876.729 [Default:CheckIn](INFO): Running loop #34 2021-12-17T22:07:56.729Z,1639778876.729 [Default:CheckIn] Running Loop=34 2021-12-17T22:07:56.729Z,1639778876.729 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-17T22:07:56.729Z,1639778876.729 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-17T22:07:58.733Z,1639778878.733 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,220757.00,A,3648.15092,N,12147.26184,W,0.253,328.67,171221,,,D*78 2021-12-17T22:07:58.736Z,1639778878.736 [NAL9602](INFO): GPS fix at 20211217T220757: (36.802515, -121.787697) 2021-12-17T22:07:58.747Z,1639778878.747 [Default:CheckIn:Read_GPS] Stopped 2021-12-17T22:07:58.747Z,1639778878.747 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-17T22:08:05.673Z,1639778885.673 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211217T201953/Courier0060.lzma 2021-12-17T22:08:06.675Z,1639778886.675 [DataOverHttps](INFO): Moved sent file to Logs/20211217T201953/Courier0060.lzma.bak 2021-12-17T22:08:06.675Z,1639778886.675 [DataOverHttps](INFO): SBD MOMSN=16398175 2021-12-17T22:08:07.644Z,1639778887.644 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file). 2021-12-17T22:08:20.604Z,1639778900.604 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file). 2021-12-17T22:08:21.445Z,1639778901.445 [NAL9602](INFO): SBD MO Status=2, MOMSN=7645, MT Status=2, MTMSN=0 2021-12-17T22:08:21.445Z,1639778901.445 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-12-17T22:08:25.626Z,1639778905.626 [DataOverHttps](INFO): Sending 149 bytes from file Logs/20211217T201953/Express0061.lzma 2021-12-17T22:08:26.628Z,1639778906.628 [DataOverHttps](INFO): Moved sent file to Logs/20211217T201953/Express0061.lzma.bak 2021-12-17T22:08:26.628Z,1639778906.628 [DataOverHttps](INFO): SBD MOMSN=16398178 2021-12-17T22:08:27.947Z,1639778907.947 [Default:CheckIn:Read_Iridium] Stopped 2021-12-17T22:08:27.947Z,1639778907.947 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-17T22:08:27.947Z,1639778907.947 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-17T22:08:34.371Z,1639778914.371 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file). 2021-12-17T22:08:48.108Z,1639778928.108 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file). 2021-12-17T22:08:56.196Z,1639778936.196 [NAL9602](INFO): SBD MO Status=2, MOMSN=7645, MT Status=2, MTMSN=0 2021-12-17T22:08:56.196Z,1639778936.196 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-12-17T22:08:58.617Z,1639778938.617 [BPC1](INFO): Calculating totals. Valid battery stick count: 27. Valid reserve battery stick count: 4. 2021-12-17T22:08:58.632Z,1639778938.632 [BPC1](INFO): Received data from all battery sticks. 2021-12-17T22:09:13.230Z,1639778953.230 [NAL9602](INFO): SBD MO Status=2, MOMSN=7645, MT Status=2, MTMSN=0 2021-12-17T22:09:13.231Z,1639778953.231 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-12-17T22:13:01.527Z,1639779181.527 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-12-17T22:13:28.605Z,1639779208.605 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-17T22:13:28.606Z,1639779208.606 [Default:CheckIn:C.Wait] Stopped 2021-12-17T22:13:28.606Z,1639779208.606 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-17T22:13:28.606Z,1639779208.606 [Default:CheckIn:D] Running Loop=1 2021-12-17T22:13:29.012Z,1639779209.012 [Default:CheckIn:D] Stopped 2021-12-17T22:13:29.012Z,1639779209.012 [Default:CheckIn:E] Running Loop=1 2021-12-17T22:13:29.422Z,1639779209.422 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 196.708610 min 2021-12-17T22:13:29.422Z,1639779209.422 [Default:CheckIn:E] Stopped 2021-12-17T22:13:29.422Z,1639779209.422 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-17T22:13:29.422Z,1639779209.422 [Default:CheckIn] Stopped 2021-12-17T22:13:29.422Z,1639779209.422 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-17T22:13:29.422Z,1639779209.422 [Default:CheckIn](INFO): Running loop #35 2021-12-17T22:13:29.422Z,1639779209.422 [Default:CheckIn] Running Loop=35 2021-12-17T22:13:29.422Z,1639779209.422 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-17T22:13:29.423Z,1639779209.423 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-17T22:13:31.424Z,1639779211.424 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,221330.00,A,3648.14145,N,12147.26290,W,0.175,199.16,171221,,,A*7C 2021-12-17T22:13:31.435Z,1639779211.435 [NAL9602](INFO): GPS fix at 20211217T221330: (36.802357, -121.787715) 2021-12-17T22:13:31.446Z,1639779211.446 [Default:CheckIn:Read_GPS] Stopped 2021-12-17T22:13:31.446Z,1639779211.446 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-17T22:13:38.281Z,1639779218.281 [DataOverHttps](INFO): Sending 85 bytes from file Logs/20211217T201953/Courier0063.lzma 2021-12-17T22:13:39.283Z,1639779219.283 [DataOverHttps](INFO): Moved sent file to Logs/20211217T201953/Courier0063.lzma.bak 2021-12-17T22:13:39.283Z,1639779219.283 [DataOverHttps](INFO): SBD MOMSN=16398181 2021-12-17T22:13:54.946Z,1639779234.946 [DataOverHttps](INFO): Sending 243 bytes from file Logs/20211217T201953/Express0064.lzma 2021-12-17T22:13:55.947Z,1639779235.947 [DataOverHttps](INFO): Moved sent file to Logs/20211217T201953/Express0064.lzma.bak 2021-12-17T22:13:55.948Z,1639779235.948 [DataOverHttps](INFO): SBD MOMSN=16398184 2021-12-17T22:13:57.310Z,1639779237.310 [Default:CheckIn:Read_Iridium] Stopped 2021-12-17T22:13:57.311Z,1639779237.311 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-17T22:13:57.311Z,1639779237.311 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-17T22:14:03.350Z,1639779243.350 [NAL9602](INFO): Not Powering down - fast GPS 2021-12-17T22:18:57.955Z,1639779537.955 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-17T22:18:57.955Z,1639779537.955 [Default:CheckIn:C.Wait] Stopped 2021-12-17T22:18:57.955Z,1639779537.955 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-17T22:18:57.956Z,1639779537.956 [Default:CheckIn:D] Running Loop=1 2021-12-17T22:18:58.326Z,1639779538.326 [Default:CheckIn:D] Stopped 2021-12-17T22:18:58.326Z,1639779538.326 [Default:CheckIn:E] Running Loop=1 2021-12-17T22:18:58.733Z,1639779538.733 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 202.197184 min 2021-12-17T22:18:58.733Z,1639779538.733 [Default:CheckIn:E] Stopped 2021-12-17T22:18:58.734Z,1639779538.734 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-17T22:18:58.734Z,1639779538.734 [Default:CheckIn] Stopped 2021-12-17T22:18:58.734Z,1639779538.734 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-17T22:18:58.734Z,1639779538.734 [Default:CheckIn](INFO): Running loop #36 2021-12-17T22:18:58.734Z,1639779538.734 [Default:CheckIn] Running Loop=36 2021-12-17T22:18:58.734Z,1639779538.734 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-17T22:18:58.734Z,1639779538.734 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-17T22:19:00.738Z,1639779540.738 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,221859.00,A,3648.14291,N,12147.26638,W,0.525,211.70,171221,,,A*76 2021-12-17T22:19:00.740Z,1639779540.740 [NAL9602](INFO): GPS fix at 20211217T221859: (36.802382, -121.787773) 2021-12-17T22:19:00.752Z,1639779540.752 [Default:CheckIn:Read_GPS] Stopped 2021-12-17T22:19:00.752Z,1639779540.752 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-17T22:19:10.589Z,1639779550.589 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211217T201953/Courier0066.lzma 2021-12-17T22:19:11.591Z,1639779551.591 [DataOverHttps](INFO): Moved sent file to Logs/20211217T201953/Courier0066.lzma.bak 2021-12-17T22:19:11.592Z,1639779551.592 [DataOverHttps](INFO): SBD MOMSN=16398201 2021-12-17T22:19:27.361Z,1639779567.361 [DataOverHttps](INFO): Sending 141 bytes from file Logs/20211217T201953/Express0067.lzma 2021-12-17T22:19:28.363Z,1639779568.363 [DataOverHttps](INFO): Moved sent file to Logs/20211217T201953/Express0067.lzma.bak 2021-12-17T22:19:28.364Z,1639779568.364 [DataOverHttps](INFO): SBD MOMSN=16398204 2021-12-17T22:19:29.902Z,1639779569.902 [Default:CheckIn:Read_Iridium] Stopped 2021-12-17T22:19:29.902Z,1639779569.902 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-17T22:19:29.902Z,1639779569.902 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-17T22:19:31.503Z,1639779571.503 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-12-17T22:19:31.585Z,1639779571.585 [NAL9602](ERROR): received: +CSQ:0 OK45, 2, 0, 0, 0 OK 2021-12-17T22:24:03.447Z,1639779843.447 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-12-17T22:24:30.557Z,1639779870.557 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-17T22:24:30.557Z,1639779870.557 [Default:CheckIn:C.Wait] Stopped 2021-12-17T22:24:30.557Z,1639779870.557 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-17T22:24:30.557Z,1639779870.557 [Default:CheckIn:D] Running Loop=1 2021-12-17T22:24:30.961Z,1639779870.961 [Default:CheckIn:D] Stopped 2021-12-17T22:24:30.961Z,1639779870.961 [Default:CheckIn:E] Running Loop=1 2021-12-17T22:24:31.376Z,1639779871.376 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 207.741113 min 2021-12-17T22:24:31.376Z,1639779871.376 [Default:CheckIn:E] Stopped 2021-12-17T22:24:31.376Z,1639779871.376 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-17T22:24:31.376Z,1639779871.376 [Default:CheckIn] Stopped 2021-12-17T22:24:31.376Z,1639779871.376 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-17T22:24:31.376Z,1639779871.376 [Default:CheckIn](INFO): Running loop #37 2021-12-17T22:24:31.377Z,1639779871.377 [Default:CheckIn] Running Loop=37 2021-12-17T22:24:31.377Z,1639779871.377 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-17T22:24:31.377Z,1639779871.377 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-17T22:24:33.372Z,1639779873.372 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,222432.00,A,3648.15497,N,12147.26157,W,0.214,196.13,171221,,,A*77 2021-12-17T22:24:33.374Z,1639779873.374 [NAL9602](INFO): GPS fix at 20211217T222432: (36.802583, -121.787693) 2021-12-17T22:24:33.408Z,1639779873.408 [Default:CheckIn:Read_GPS] Stopped 2021-12-17T22:24:33.408Z,1639779873.408 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-17T22:24:41.013Z,1639779881.013 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20211217T201953/Courier0069.lzma 2021-12-17T22:24:42.015Z,1639779882.015 [DataOverHttps](INFO): Moved sent file to Logs/20211217T201953/Courier0069.lzma.bak 2021-12-17T22:24:42.015Z,1639779882.015 [DataOverHttps](INFO): SBD MOMSN=16398207 2021-12-17T22:24:57.942Z,1639779897.942 [DataOverHttps](INFO): Sending 232 bytes from file Logs/20211217T201953/Express0070.lzma 2021-12-17T22:24:58.943Z,1639779898.943 [DataOverHttps](INFO): Moved sent file to Logs/20211217T201953/Express0070.lzma.bak 2021-12-17T22:24:58.944Z,1639779898.944 [DataOverHttps](INFO): SBD MOMSN=16398210 2021-12-17T22:25:00.472Z,1639779900.472 [Default:CheckIn:Read_Iridium] Stopped 2021-12-17T22:25:00.472Z,1639779900.472 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-17T22:25:00.472Z,1639779900.472 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-17T22:25:05.739Z,1639779905.739 [NAL9602](INFO): Not Powering down - fast GPS 2021-12-17T22:30:01.114Z,1639780201.114 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-17T22:30:01.114Z,1639780201.114 [Default:CheckIn:C.Wait] Stopped 2021-12-17T22:30:01.114Z,1639780201.114 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-17T22:30:01.115Z,1639780201.115 [Default:CheckIn:D] Running Loop=1 2021-12-17T22:30:01.503Z,1639780201.503 [Default:CheckIn:D] Stopped 2021-12-17T22:30:01.503Z,1639780201.503 [Default:CheckIn:E] Running Loop=1 2021-12-17T22:30:01.914Z,1639780201.914 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 213.250130 min 2021-12-17T22:30:01.914Z,1639780201.914 [Default:CheckIn:E] Stopped 2021-12-17T22:30:01.914Z,1639780201.914 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-17T22:30:01.914Z,1639780201.914 [Default:CheckIn] Stopped 2021-12-17T22:30:01.914Z,1639780201.914 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-17T22:30:01.914Z,1639780201.914 [Default:CheckIn](INFO): Running loop #38 2021-12-17T22:30:01.915Z,1639780201.915 [Default:CheckIn] Running Loop=38 2021-12-17T22:30:01.915Z,1639780201.915 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-17T22:30:01.915Z,1639780201.915 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-17T22:30:03.916Z,1639780203.916 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,223003.00,A,3648.13420,N,12147.27651,W,0.661,204.22,171221,,,A*76 2021-12-17T22:30:03.919Z,1639780203.919 [NAL9602](INFO): GPS fix at 20211217T223003: (36.802237, -121.787942) 2021-12-17T22:30:03.931Z,1639780203.931 [Default:CheckIn:Read_GPS] Stopped 2021-12-17T22:30:03.931Z,1639780203.931 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-17T22:30:11.405Z,1639780211.405 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211217T201953/Courier0072.lzma 2021-12-17T22:30:12.407Z,1639780212.407 [DataOverHttps](INFO): Moved sent file to Logs/20211217T201953/Courier0072.lzma.bak 2021-12-17T22:30:12.407Z,1639780212.407 [DataOverHttps](INFO): SBD MOMSN=16398231 2021-12-17T22:30:31.505Z,1639780231.505 [DataOverHttps](INFO): Sending 154 bytes from file Logs/20211217T201953/Express0073.lzma 2021-12-17T22:30:32.507Z,1639780232.507 [DataOverHttps](INFO): Moved sent file to Logs/20211217T201953/Express0073.lzma.bak 2021-12-17T22:30:32.508Z,1639780232.508 [DataOverHttps](INFO): SBD MOMSN=16398234 2021-12-17T22:30:33.895Z,1639780233.895 [Default:CheckIn:Read_Iridium] Stopped 2021-12-17T22:30:33.895Z,1639780233.895 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-17T22:30:33.895Z,1639780233.895 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-17T22:30:34.679Z,1639780234.679 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-12-17T22:30:34.761Z,1639780234.761 [NAL9602](ERROR): received: +CSQ:0 OK45, 2, 0, 0, 0 OK 2021-12-17T22:31:17.897Z,1639780277.897 [NAL9602](INFO): SBD MO Status=2, MOMSN=7645, MT Status=2, MTMSN=0 2021-12-17T22:31:17.897Z,1639780277.897 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-12-17T22:31:47.792Z,1639780307.792 [NAL9602](INFO): SBD MO Status=2, MOMSN=7645, MT Status=2, MTMSN=0 2021-12-17T22:31:47.792Z,1639780307.792 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-12-17T22:32:09.612Z,1639780329.612 [NAL9602](INFO): SBD MO Status=2, MOMSN=7645, MT Status=2, MTMSN=0 2021-12-17T22:32:09.612Z,1639780329.612 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-12-17T22:32:58.532Z,1639780378.532 [NAL9602](INFO): SBD MO Status=2, MOMSN=7645, MT Status=2, MTMSN=0 2021-12-17T22:32:58.532Z,1639780378.532 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-12-17T22:33:15.908Z,1639780395.908 [NAL9602](INFO): SBD MO Status=2, MOMSN=7645, MT Status=2, MTMSN=0 2021-12-17T22:33:15.908Z,1639780395.908 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-12-17T22:33:30.452Z,1639780410.452 [NAL9602](INFO): SBD MO Status=2, MOMSN=7645, MT Status=2, MTMSN=0 2021-12-17T22:33:30.452Z,1639780410.452 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-12-17T22:35:09.837Z,1639780509.837 [NAL9602](INFO): SBD MO Status=2, MOMSN=7645, MT Status=2, MTMSN=0 2021-12-17T22:35:09.837Z,1639780509.837 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-12-17T22:35:10.235Z,1639780510.235 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-12-17T22:35:34.489Z,1639780534.489 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-17T22:35:34.489Z,1639780534.489 [Default:CheckIn:C.Wait] Stopped 2021-12-17T22:35:34.489Z,1639780534.489 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-17T22:35:34.489Z,1639780534.489 [Default:CheckIn:D] Running Loop=1 2021-12-17T22:35:34.891Z,1639780534.891 [Default:CheckIn:D] Stopped 2021-12-17T22:35:34.891Z,1639780534.891 [Default:CheckIn:E] Running Loop=1 2021-12-17T22:35:35.306Z,1639780535.306 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 218.806608 min 2021-12-17T22:35:35.306Z,1639780535.306 [Default:CheckIn:E] Stopped 2021-12-17T22:35:35.306Z,1639780535.306 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-17T22:35:35.307Z,1639780535.307 [Default:CheckIn] Stopped 2021-12-17T22:35:35.307Z,1639780535.307 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-17T22:35:35.307Z,1639780535.307 [Default:CheckIn](INFO): Running loop #39 2021-12-17T22:35:35.307Z,1639780535.307 [Default:CheckIn] Running Loop=39 2021-12-17T22:35:35.307Z,1639780535.307 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-17T22:35:35.307Z,1639780535.307 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-17T22:35:37.304Z,1639780537.304 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,223536.00,A,3648.14873,N,12147.26291,W,0.156,204.22,171221,,,A*72 2021-12-17T22:35:37.307Z,1639780537.307 [NAL9602](INFO): GPS fix at 20211217T223536: (36.802479, -121.787715) 2021-12-17T22:35:37.318Z,1639780537.318 [Default:CheckIn:Read_GPS] Stopped 2021-12-17T22:35:37.318Z,1639780537.318 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-17T22:35:44.469Z,1639780544.469 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20211217T201953/Courier0075.lzma 2021-12-17T22:35:45.471Z,1639780545.471 [DataOverHttps](INFO): Moved sent file to Logs/20211217T201953/Courier0075.lzma.bak 2021-12-17T22:35:45.471Z,1639780545.471 [DataOverHttps](INFO): SBD MOMSN=16398237 2021-12-17T22:36:01.578Z,1639780561.578 [DataOverHttps](INFO): Sending 230 bytes from file Logs/20211217T201953/Express0076.lzma 2021-12-17T22:36:02.580Z,1639780562.580 [DataOverHttps](INFO): Moved sent file to Logs/20211217T201953/Express0076.lzma.bak 2021-12-17T22:36:02.580Z,1639780562.580 [DataOverHttps](INFO): SBD MOMSN=16398240 2021-12-17T22:36:03.983Z,1639780563.983 [Default:CheckIn:Read_Iridium] Stopped 2021-12-17T22:36:03.983Z,1639780563.983 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-17T22:36:03.983Z,1639780563.983 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-17T22:36:09.626Z,1639780569.626 [NAL9602](INFO): Not Powering down - fast GPS 2021-12-17T22:41:04.667Z,1639780864.667 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-17T22:41:04.667Z,1639780864.667 [Default:CheckIn:C.Wait] Stopped 2021-12-17T22:41:04.667Z,1639780864.667 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-17T22:41:04.668Z,1639780864.668 [Default:CheckIn:D] Running Loop=1 2021-12-17T22:41:05.091Z,1639780865.091 [Default:CheckIn:D] Stopped 2021-12-17T22:41:05.091Z,1639780865.091 [Default:CheckIn:E] Running Loop=1 2021-12-17T22:41:05.468Z,1639780865.468 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 224.309945 min 2021-12-17T22:41:05.468Z,1639780865.468 [Default:CheckIn:E] Stopped 2021-12-17T22:41:05.468Z,1639780865.468 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-17T22:41:05.468Z,1639780865.468 [Default:CheckIn] Stopped 2021-12-17T22:41:05.468Z,1639780865.468 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-17T22:41:05.468Z,1639780865.468 [Default:CheckIn](INFO): Running loop #40 2021-12-17T22:41:05.468Z,1639780865.468 [Default:CheckIn] Running Loop=40 2021-12-17T22:41:05.468Z,1639780865.468 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-17T22:41:05.469Z,1639780865.469 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-17T22:41:07.472Z,1639780867.472 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,224106.00,A,3648.14851,N,12147.26301,W,0.097,0.00,171221,,,A*70 2021-12-17T22:41:07.491Z,1639780867.491 [NAL9602](INFO): GPS fix at 20211217T224106: (36.802475, -121.787717) 2021-12-17T22:41:07.503Z,1639780867.503 [Default:CheckIn:Read_GPS] Stopped 2021-12-17T22:41:07.503Z,1639780867.503 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-17T22:41:15.333Z,1639780875.333 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211217T201953/Courier0078.lzma 2021-12-17T22:41:16.335Z,1639780876.335 [DataOverHttps](INFO): Moved sent file to Logs/20211217T201953/Courier0078.lzma.bak 2021-12-17T22:41:16.336Z,1639780876.336 [DataOverHttps](INFO): SBD MOMSN=16398261 2021-12-17T22:41:32.285Z,1639780892.285 [DataOverHttps](INFO): Sending 140 bytes from file Logs/20211217T201953/Express0079.lzma 2021-12-17T22:41:33.287Z,1639780893.287 [DataOverHttps](INFO): Moved sent file to Logs/20211217T201953/Express0079.lzma.bak 2021-12-17T22:41:33.288Z,1639780893.288 [DataOverHttps](INFO): SBD MOMSN=16398264 2021-12-17T22:41:34.676Z,1639780894.676 [Default:CheckIn:Read_Iridium] Stopped 2021-12-17T22:41:34.676Z,1639780894.676 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-17T22:41:34.677Z,1639780894.677 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-17T22:42:32.444Z,1639780952.444 [NAL9602](INFO): SBD MO Status=2, MOMSN=7645, MT Status=2, MTMSN=0 2021-12-17T22:42:32.444Z,1639780952.444 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-12-17T22:42:51.844Z,1639780971.844 [NAL9602](INFO): SBD MO Status=2, MOMSN=7645, MT Status=2, MTMSN=0 2021-12-17T22:42:51.844Z,1639780971.844 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-12-17T22:43:09.216Z,1639780989.216 [NAL9602](INFO): SBD MO Status=2, MOMSN=7645, MT Status=2, MTMSN=0 2021-12-17T22:43:09.216Z,1639780989.216 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-12-17T22:46:09.437Z,1639781169.437 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-12-17T22:46:35.357Z,1639781195.357 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-17T22:46:35.357Z,1639781195.357 [Default:CheckIn:C.Wait] Stopped 2021-12-17T22:46:35.358Z,1639781195.358 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-17T22:46:35.358Z,1639781195.358 [Default:CheckIn:D] Running Loop=1 2021-12-17T22:46:35.766Z,1639781195.766 [Default:CheckIn:D] Stopped 2021-12-17T22:46:35.766Z,1639781195.766 [Default:CheckIn:E] Running Loop=1 2021-12-17T22:46:36.163Z,1639781196.163 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 229.821175 min 2021-12-17T22:46:36.163Z,1639781196.163 [Default:CheckIn:E] Stopped 2021-12-17T22:46:36.164Z,1639781196.164 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-17T22:46:36.164Z,1639781196.164 [Default:CheckIn] Stopped 2021-12-17T22:46:36.164Z,1639781196.164 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-17T22:46:36.164Z,1639781196.164 [Default:CheckIn](INFO): Running loop #41 2021-12-17T22:46:36.164Z,1639781196.164 [Default:CheckIn] Running Loop=41 2021-12-17T22:46:36.164Z,1639781196.164 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-17T22:46:36.164Z,1639781196.164 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-17T22:46:38.172Z,1639781198.172 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,224637.00,A,3648.14780,N,12147.25411,W,0.214,0.00,171221,,,A*7A 2021-12-17T22:46:38.175Z,1639781198.175 [NAL9602](INFO): GPS fix at 20211217T224637: (36.802463, -121.787569) 2021-12-17T22:46:38.186Z,1639781198.186 [Default:CheckIn:Read_GPS] Stopped 2021-12-17T22:46:38.187Z,1639781198.187 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-17T22:46:45.785Z,1639781205.785 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211217T201953/Courier0081.lzma 2021-12-17T22:46:46.787Z,1639781206.787 [DataOverHttps](INFO): Moved sent file to Logs/20211217T201953/Courier0081.lzma.bak 2021-12-17T22:46:46.788Z,1639781206.788 [DataOverHttps](INFO): SBD MOMSN=16398267 2021-12-17T22:47:02.778Z,1639781222.778 [DataOverHttps](INFO): Sending 217 bytes from file Logs/20211217T201953/Express0082.lzma 2021-12-17T22:47:03.780Z,1639781223.780 [DataOverHttps](INFO): Moved sent file to Logs/20211217T201953/Express0082.lzma.bak 2021-12-17T22:47:03.780Z,1639781223.780 [DataOverHttps](INFO): SBD MOMSN=16398270 2021-12-17T22:47:05.264Z,1639781225.264 [Default:CheckIn:Read_Iridium] Stopped 2021-12-17T22:47:05.264Z,1639781225.264 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-17T22:47:05.264Z,1639781225.264 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-17T22:47:10.530Z,1639781230.530 [NAL9602](INFO): Not Powering down - fast GPS 2021-12-17T22:52:05.925Z,1639781525.925 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-17T22:52:05.925Z,1639781525.925 [Default:CheckIn:C.Wait] Stopped 2021-12-17T22:52:05.925Z,1639781525.925 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-17T22:52:05.925Z,1639781525.925 [Default:CheckIn:D] Running Loop=1 2021-12-17T22:52:06.329Z,1639781526.329 [Default:CheckIn:D] Stopped 2021-12-17T22:52:06.330Z,1639781526.330 [Default:CheckIn:E] Running Loop=1 2021-12-17T22:52:06.725Z,1639781526.725 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 235.330583 min 2021-12-17T22:52:06.726Z,1639781526.726 [Default:CheckIn:E] Stopped 2021-12-17T22:52:06.726Z,1639781526.726 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-17T22:52:06.726Z,1639781526.726 [Default:CheckIn] Stopped 2021-12-17T22:52:06.726Z,1639781526.726 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-17T22:52:06.726Z,1639781526.726 [Default:CheckIn](INFO): Running loop #42 2021-12-17T22:52:06.726Z,1639781526.726 [Default:CheckIn] Running Loop=42 2021-12-17T22:52:06.726Z,1639781526.726 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-17T22:52:06.727Z,1639781526.727 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-17T22:52:08.736Z,1639781528.736 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,225207.00,A,3648.14825,N,12147.26181,W,0.117,0.00,171221,,,A*73 2021-12-17T22:52:08.739Z,1639781528.739 [NAL9602](INFO): GPS fix at 20211217T225207: (36.802471, -121.787697) 2021-12-17T22:52:08.754Z,1639781528.754 [Default:CheckIn:Read_GPS] Stopped 2021-12-17T22:52:08.754Z,1639781528.754 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-17T22:52:16.969Z,1639781536.969 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211217T201953/Courier0084.lzma 2021-12-17T22:52:17.971Z,1639781537.971 [DataOverHttps](INFO): Moved sent file to Logs/20211217T201953/Courier0084.lzma.bak 2021-12-17T22:52:17.972Z,1639781537.972 [DataOverHttps](INFO): SBD MOMSN=16398292 2021-12-17T22:52:36.585Z,1639781556.585 [DataOverHttps](INFO): Sending 138 bytes from file Logs/20211217T201953/Express0085.lzma 2021-12-17T22:52:37.588Z,1639781557.588 [DataOverHttps](INFO): Moved sent file to Logs/20211217T201953/Express0085.lzma.bak 2021-12-17T22:52:37.588Z,1639781557.588 [DataOverHttps](INFO): SBD MOMSN=16398295 2021-12-17T22:52:39.098Z,1639781559.098 [Default:CheckIn:Read_Iridium] Stopped 2021-12-17T22:52:39.098Z,1639781559.098 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-17T22:52:39.098Z,1639781559.098 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-17T22:52:39.487Z,1639781559.487 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-12-17T22:52:39.570Z,1639781559.570 [NAL9602](ERROR): received: +CSQ:0 OK45, 2, 0, 0, 0 OK 2021-12-17T22:57:11.439Z,1639781831.439 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-12-17T22:57:39.731Z,1639781859.731 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-17T22:57:39.731Z,1639781859.731 [Default:CheckIn:C.Wait] Stopped 2021-12-17T22:57:39.731Z,1639781859.731 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-17T22:57:39.731Z,1639781859.731 [Default:CheckIn:D] Running Loop=1 2021-12-17T22:57:40.146Z,1639781860.146 [Default:CheckIn:D] Stopped 2021-12-17T22:57:40.147Z,1639781860.147 [Default:CheckIn:E] Running Loop=1 2021-12-17T22:57:40.544Z,1639781860.544 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 240.894189 min 2021-12-17T22:57:40.544Z,1639781860.544 [Default:CheckIn:E] Stopped 2021-12-17T22:57:40.544Z,1639781860.544 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-17T22:57:40.544Z,1639781860.544 [Default:CheckIn] Stopped 2021-12-17T22:57:40.544Z,1639781860.544 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-17T22:57:40.545Z,1639781860.545 [Default:CheckIn](INFO): Running loop #43 2021-12-17T22:57:40.545Z,1639781860.545 [Default:CheckIn] Running Loop=43 2021-12-17T22:57:40.545Z,1639781860.545 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-17T22:57:40.545Z,1639781860.545 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-17T22:57:42.557Z,1639781862.557 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,225741.00,A,3648.15135,N,12147.25781,W,0.350,0.00,171221,,,A*79 2021-12-17T22:57:42.559Z,1639781862.559 [NAL9602](INFO): GPS fix at 20211217T225741: (36.802523, -121.787630) 2021-12-17T22:57:42.571Z,1639781862.571 [Default:CheckIn:Read_GPS] Stopped 2021-12-17T22:57:42.571Z,1639781862.571 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-17T22:57:50.313Z,1639781870.313 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211217T201953/Courier0087.lzma 2021-12-17T22:57:51.315Z,1639781871.315 [DataOverHttps](INFO): Moved sent file to Logs/20211217T201953/Courier0087.lzma.bak 2021-12-17T22:57:51.315Z,1639781871.315 [DataOverHttps](INFO): SBD MOMSN=16398298 2021-12-17T22:58:07.125Z,1639781887.125 [DataOverHttps](INFO): Sending 216 bytes from file Logs/20211217T201953/Express0088.lzma 2021-12-17T22:58:08.128Z,1639781888.128 [DataOverHttps](INFO): Moved sent file to Logs/20211217T201953/Express0088.lzma.bak 2021-12-17T22:58:08.128Z,1639781888.128 [DataOverHttps](INFO): SBD MOMSN=16398301 2021-12-17T22:58:09.641Z,1639781889.641 [Default:CheckIn:Read_Iridium] Stopped 2021-12-17T22:58:09.641Z,1639781889.641 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-17T22:58:09.641Z,1639781889.641 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-17T22:58:14.462Z,1639781894.462 [NAL9602](INFO): Not Powering down - fast GPS 2021-12-17T23:03:10.271Z,1639782190.271 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-17T23:03:10.272Z,1639782190.272 [Default:CheckIn:C.Wait] Stopped 2021-12-17T23:03:10.272Z,1639782190.272 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-17T23:03:10.272Z,1639782190.272 [Default:CheckIn:D] Running Loop=1 2021-12-17T23:03:10.681Z,1639782190.681 [Default:CheckIn:D] Stopped 2021-12-17T23:03:10.681Z,1639782190.681 [Default:CheckIn:E] Running Loop=1 2021-12-17T23:03:11.047Z,1639782191.047 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 246.403092 min 2021-12-17T23:03:11.047Z,1639782191.047 [Default:CheckIn:E] Stopped 2021-12-17T23:03:11.047Z,1639782191.047 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-17T23:03:11.047Z,1639782191.047 [Default:CheckIn] Stopped 2021-12-17T23:03:11.047Z,1639782191.047 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-17T23:03:11.048Z,1639782191.048 [Default:CheckIn](INFO): Running loop #44 2021-12-17T23:03:11.048Z,1639782191.048 [Default:CheckIn] Running Loop=44 2021-12-17T23:03:11.048Z,1639782191.048 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-17T23:03:11.048Z,1639782191.048 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-17T23:03:13.061Z,1639782193.061 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,230312.00,A,3648.17312,N,12147.28124,W,0.272,292.98,171221,,,A*77 2021-12-17T23:03:13.063Z,1639782193.063 [NAL9602](INFO): GPS fix at 20211217T230312: (36.802885, -121.788021) 2021-12-17T23:03:13.075Z,1639782193.075 [Default:CheckIn:Read_GPS] Stopped 2021-12-17T23:03:13.075Z,1639782193.075 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-17T23:03:20.317Z,1639782200.317 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20211217T201953/Courier0090.lzma 2021-12-17T23:03:21.320Z,1639782201.320 [DataOverHttps](INFO): Moved sent file to Logs/20211217T201953/Courier0090.lzma.bak 2021-12-17T23:03:21.320Z,1639782201.320 [DataOverHttps](INFO): SBD MOMSN=16398320 2021-12-17T23:03:37.185Z,1639782217.185 [DataOverHttps](INFO): Sending 156 bytes from file Logs/20211217T201953/Express0091.lzma 2021-12-17T23:03:38.187Z,1639782218.187 [DataOverHttps](INFO): Moved sent file to Logs/20211217T201953/Express0091.lzma.bak 2021-12-17T23:03:38.188Z,1639782218.188 [DataOverHttps](INFO): SBD MOMSN=16398323 2021-12-17T23:03:39.753Z,1639782219.753 [Default:CheckIn:Read_Iridium] Stopped 2021-12-17T23:03:39.753Z,1639782219.753 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-17T23:03:39.754Z,1639782219.754 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-17T23:03:43.767Z,1639782223.767 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-12-17T23:03:43.841Z,1639782223.841 [NAL9602](ERROR): received: +CSQ:0 OK45, 2, 0, 0, 0 OK 2021-12-17T23:07:56.308Z,1639782476.308 [NAL9602](INFO): SBD MO Status=2, MOMSN=7645, MT Status=2, MTMSN=0 2021-12-17T23:07:56.308Z,1639782476.308 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-12-17T23:08:11.666Z,1639782491.666 [NAL9602](INFO): SBD MO Status=0, MOMSN=7645, MT Status=0, MTMSN=0 2021-12-17T23:08:11.666Z,1639782491.666 [NAL9602](INFO): No messages in MT queue 2021-12-17T23:08:40.361Z,1639782520.361 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-17T23:08:40.361Z,1639782520.361 [Default:CheckIn:C.Wait] Stopped 2021-12-17T23:08:40.361Z,1639782520.361 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-17T23:08:40.362Z,1639782520.362 [Default:CheckIn:D] Running Loop=1 2021-12-17T23:08:40.769Z,1639782520.769 [Default:CheckIn:D] Stopped 2021-12-17T23:08:40.770Z,1639782520.770 [Default:CheckIn:E] Running Loop=1 2021-12-17T23:08:41.175Z,1639782521.175 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 251.904574 min 2021-12-17T23:08:41.175Z,1639782521.175 [Default:CheckIn:E] Stopped 2021-12-17T23:08:41.175Z,1639782521.175 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-17T23:08:41.175Z,1639782521.175 [Default:CheckIn] Stopped 2021-12-17T23:08:41.175Z,1639782521.175 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-17T23:08:41.176Z,1639782521.176 [Default:CheckIn](INFO): Running loop #45 2021-12-17T23:08:41.176Z,1639782521.176 [Default:CheckIn] Running Loop=45 2021-12-17T23:08:41.176Z,1639782521.176 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-17T23:08:41.176Z,1639782521.176 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-17T23:08:43.184Z,1639782523.184 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,230842.00,A,3648.16924,N,12147.28084,W,0.428,292.98,171221,,,A*75 2021-12-17T23:08:43.187Z,1639782523.187 [NAL9602](INFO): GPS fix at 20211217T230842: (36.802821, -121.788014) 2021-12-17T23:08:43.219Z,1639782523.219 [Default:CheckIn:Read_GPS] Stopped 2021-12-17T23:08:43.219Z,1639782523.219 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-17T23:08:51.005Z,1639782531.005 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211217T201953/Courier0093.lzma 2021-12-17T23:08:52.007Z,1639782532.007 [DataOverHttps](INFO): Moved sent file to Logs/20211217T201953/Courier0093.lzma.bak 2021-12-17T23:08:52.008Z,1639782532.008 [DataOverHttps](INFO): SBD MOMSN=16398333 2021-12-17T23:09:10.414Z,1639782550.414 [DataOverHttps](INFO): Sending 203 bytes from file Logs/20211217T201953/Express0094.lzma 2021-12-17T23:09:11.416Z,1639782551.416 [DataOverHttps](INFO): Moved sent file to Logs/20211217T201953/Express0094.lzma.bak 2021-12-17T23:09:11.416Z,1639782551.416 [DataOverHttps](INFO): SBD MOMSN=16398336 2021-12-17T23:09:12.753Z,1639782552.753 [Default:CheckIn:Read_Iridium] Stopped 2021-12-17T23:09:12.753Z,1639782552.753 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-17T23:09:12.754Z,1639782552.754 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-17T23:09:15.555Z,1639782555.555 [NAL9602](INFO): Not Powering down - fast GPS 2021-12-17T23:11:28.109Z,1639782688.109 [BPC1](ERROR): BPC1B: No match for serial number 0C29 in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file). 2021-12-17T23:11:41.088Z,1639782701.088 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file). 2021-12-17T23:11:54.420Z,1639782714.420 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file). 2021-12-17T23:12:08.091Z,1639782728.091 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file). 2021-12-17T23:12:21.924Z,1639782741.924 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file). 2021-12-17T23:12:35.223Z,1639782755.223 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file). 2021-12-17T23:12:48.595Z,1639782768.595 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file). 2021-12-17T23:13:01.823Z,1639782781.823 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file). 2021-12-17T23:13:15.624Z,1639782795.624 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file). 2021-12-17T23:13:29.361Z,1639782809.361 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file). 2021-12-17T23:13:42.633Z,1639782822.633 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file). 2021-12-17T23:13:55.562Z,1639782835.562 [BPC1](INFO): Calculating totals. Valid battery stick count: 33. Valid reserve battery stick count: 4. 2021-12-17T23:13:55.565Z,1639782835.565 [BPC1](INFO): Received data from all battery sticks. 2021-12-17T23:14:13.354Z,1639782853.354 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-17T23:14:13.354Z,1639782853.354 [Default:CheckIn:C.Wait] Stopped 2021-12-17T23:14:13.354Z,1639782853.354 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-17T23:14:13.354Z,1639782853.354 [Default:CheckIn:D] Running Loop=1 2021-12-17T23:14:13.750Z,1639782853.750 [Default:CheckIn:D] Stopped 2021-12-17T23:14:13.750Z,1639782853.750 [Default:CheckIn:E] Running Loop=1 2021-12-17T23:14:14.150Z,1639782854.150 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 257.454248 min 2021-12-17T23:14:14.150Z,1639782854.150 [Default:CheckIn:E] Stopped 2021-12-17T23:14:14.150Z,1639782854.150 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-17T23:14:14.150Z,1639782854.150 [Default:CheckIn] Stopped 2021-12-17T23:14:14.150Z,1639782854.150 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-17T23:14:14.150Z,1639782854.150 [Default:CheckIn](INFO): Running loop #46 2021-12-17T23:14:14.151Z,1639782854.151 [Default:CheckIn] Running Loop=46 2021-12-17T23:14:14.151Z,1639782854.151 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-17T23:14:14.151Z,1639782854.151 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-17T23:14:16.165Z,1639782856.165 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,231415.00,A,3648.16744,N,12147.28624,W,0.175,292.98,171221,,,A*73 2021-12-17T23:14:16.176Z,1639782856.176 [NAL9602](INFO): GPS fix at 20211217T231415: (36.802791, -121.788104) 2021-12-17T23:14:16.188Z,1639782856.188 [Default:CheckIn:Read_GPS] Stopped 2021-12-17T23:14:16.188Z,1639782856.188 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-17T23:14:26.477Z,1639782866.477 [DataOverHttps](INFO): Sending 83 bytes from file Logs/20211217T201953/Courier0096.lzma 2021-12-17T23:14:27.479Z,1639782867.479 [DataOverHttps](INFO): Moved sent file to Logs/20211217T201953/Courier0096.lzma.bak 2021-12-17T23:14:27.480Z,1639782867.480 [DataOverHttps](INFO): SBD MOMSN=16398347 2021-12-17T23:14:43.234Z,1639782883.234 [DataOverHttps](INFO): Sending 141 bytes from file Logs/20211217T201953/Express0097.lzma 2021-12-17T23:14:44.235Z,1639782884.235 [DataOverHttps](INFO): Moved sent file to Logs/20211217T201953/Express0097.lzma.bak 2021-12-17T23:14:44.236Z,1639782884.236 [DataOverHttps](INFO): SBD MOMSN=16398350 2021-12-17T23:14:45.718Z,1639782885.718 [Default:CheckIn:Read_Iridium] Stopped 2021-12-17T23:14:45.718Z,1639782885.718 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-17T23:14:45.718Z,1639782885.718 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-17T23:17:37.012Z,1639783057.012 [NAL9602](INFO): SBD MO Status=2, MOMSN=7646, MT Status=2, MTMSN=0 2021-12-17T23:17:37.012Z,1639783057.012 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-12-17T23:18:08.532Z,1639783088.532 [NAL9602](INFO): SBD MO Status=2, MOMSN=7646, MT Status=2, MTMSN=0 2021-12-17T23:18:08.533Z,1639783088.533 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-12-17T23:18:23.520Z,1639783103.520 [NAL9602](INFO): SBD MO Status=2, MOMSN=7646, MT Status=2, MTMSN=0 2021-12-17T23:18:23.520Z,1639783103.520 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-12-17T23:19:13.636Z,1639783153.636 [NAL9602](INFO): SBD MO Status=2, MOMSN=7646, MT Status=2, MTMSN=0 2021-12-17T23:19:13.636Z,1639783153.636 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-12-17T23:19:18.483Z,1639783158.483 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-12-17T23:19:46.399Z,1639783186.399 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-17T23:19:46.400Z,1639783186.400 [Default:CheckIn:C.Wait] Stopped 2021-12-17T23:19:46.400Z,1639783186.400 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-17T23:19:46.400Z,1639783186.400 [Default:CheckIn:D] Running Loop=1 2021-12-17T23:19:46.818Z,1639783186.818 [Default:CheckIn:D] Stopped 2021-12-17T23:19:46.818Z,1639783186.818 [Default:CheckIn:E] Running Loop=1 2021-12-17T23:19:47.195Z,1639783187.195 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 263.005387 min 2021-12-17T23:19:47.195Z,1639783187.195 [Default:CheckIn:E] Stopped 2021-12-17T23:19:47.195Z,1639783187.195 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-17T23:19:47.195Z,1639783187.195 [Default:CheckIn] Stopped 2021-12-17T23:19:47.195Z,1639783187.195 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-17T23:19:47.196Z,1639783187.196 [Default:CheckIn](INFO): Running loop #47 2021-12-17T23:19:47.196Z,1639783187.196 [Default:CheckIn] Running Loop=47 2021-12-17T23:19:47.196Z,1639783187.196 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-17T23:19:47.196Z,1639783187.196 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-17T23:19:49.188Z,1639783189.188 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,231948.00,A,3648.16552,N,12147.28082,W,0.428,0.00,171221,,,A*7C 2021-12-17T23:19:49.191Z,1639783189.191 [NAL9602](INFO): GPS fix at 20211217T231948: (36.802759, -121.788014) 2021-12-17T23:19:49.210Z,1639783189.210 [Default:CheckIn:Read_GPS] Stopped 2021-12-17T23:19:49.210Z,1639783189.210 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-17T23:19:57.001Z,1639783197.001 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20211217T201953/Courier0099.lzma 2021-12-17T23:19:58.004Z,1639783198.004 [DataOverHttps](INFO): Moved sent file to Logs/20211217T201953/Courier0099.lzma.bak 2021-12-17T23:19:58.004Z,1639783198.004 [DataOverHttps](INFO): SBD MOMSN=16398360 2021-12-17T23:20:13.802Z,1639783213.802 [DataOverHttps](INFO): Sending 226 bytes from file Logs/20211217T201953/Express0100.lzma 2021-12-17T23:20:14.807Z,1639783214.807 [DataOverHttps](INFO): Moved sent file to Logs/20211217T201953/Express0100.lzma.bak 2021-12-17T23:20:14.807Z,1639783214.807 [DataOverHttps](INFO): SBD MOMSN=16398363 2021-12-17T23:20:16.278Z,1639783216.278 [Default:CheckIn:Read_Iridium] Stopped 2021-12-17T23:20:16.278Z,1639783216.278 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-17T23:20:16.279Z,1639783216.279 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-17T23:20:21.554Z,1639783221.554 [NAL9602](INFO): Not Powering down - fast GPS 2021-12-17T23:25:16.893Z,1639783516.893 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-17T23:25:16.893Z,1639783516.893 [Default:CheckIn:C.Wait] Stopped 2021-12-17T23:25:16.893Z,1639783516.893 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-17T23:25:16.894Z,1639783516.894 [Default:CheckIn:D] Running Loop=1 2021-12-17T23:25:17.298Z,1639783517.298 [Default:CheckIn:D] Stopped 2021-12-17T23:25:17.298Z,1639783517.298 [Default:CheckIn:E] Running Loop=1 2021-12-17T23:25:17.710Z,1639783517.710 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 268.513379 min 2021-12-17T23:25:17.710Z,1639783517.710 [Default:CheckIn:E] Stopped 2021-12-17T23:25:17.710Z,1639783517.710 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-17T23:25:17.710Z,1639783517.710 [Default:CheckIn] Stopped 2021-12-17T23:25:17.710Z,1639783517.710 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-17T23:25:17.710Z,1639783517.710 [Default:CheckIn](INFO): Running loop #48 2021-12-17T23:25:17.710Z,1639783517.710 [Default:CheckIn] Running Loop=48 2021-12-17T23:25:17.711Z,1639783517.711 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-17T23:25:17.711Z,1639783517.711 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-17T23:25:50.423Z,1639783550.423 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-12-17T23:25:50.497Z,1639783550.497 [NAL9602](ERROR): received: +CSQ:0 OK46, 2, 0, 0, 0 OK 2021-12-17T23:26:11.806Z,1639783571.806 [CommandExec](IMPORTANT): got command quit 2021-12-17T23:26:12.809Z,1639783572.809 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread. 2021-12-17T23:26:12.810Z,1639783572.810 [CommandExec](INFO): Uninitializing the command executive. 2021-12-17T23:26:12.810Z,1639783572.810 [CommandExec](INFO): Uninitializing the command scheduler. 2021-12-17T23:26:12.810Z,1639783572.810 [CommandExec ThreadHandler](INFO): Thread cancelled. 2021-12-17T23:26:12.913Z,1639783572.913 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2021-12-17T23:26:12.913Z,1639783572.913 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2021-12-17T23:26:12.914Z,1639783572.914 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2021-12-17T23:26:12.914Z,1639783572.914 [NavChartDb](INFO): Join timeout helper Thread ID is 6523 2021-12-17T23:26:13.005Z,1639783573.005 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2021-12-17T23:26:13.006Z,1639783573.006 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2021-12-17T23:26:13.017Z,1639783573.017 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2021-12-17T23:26:13.017Z,1639783573.017 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2021-12-17T23:26:13.017Z,1639783573.017 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 6524 2021-12-17T23:26:13.490Z,1639783573.490 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2021-12-17T23:26:13.490Z,1639783573.490 [WetLabsBB2FL](INFO): Powering down 2021-12-17T23:26:13.491Z,1639783573.491 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2021-12-17T23:26:13.493Z,1639783573.493 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2021-12-17T23:26:13.494Z,1639783573.494 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2021-12-17T23:26:13.494Z,1639783573.494 [CTD_Seabird](INFO): Join timeout helper Thread ID is 6525 2021-12-17T23:26:13.822Z,1639783573.822 [CTD_Seabird](INFO): Powering down 2021-12-17T23:26:13.846Z,1639783573.846 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread. 2021-12-17T23:26:13.846Z,1639783573.846 [CTD_Seabird](INFO): Powering down 2021-12-17T23:26:13.857Z,1639783573.857 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2021-12-17T23:26:13.861Z,1639783573.861 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2021-12-17T23:26:13.862Z,1639783573.862 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2021-12-17T23:26:13.862Z,1639783573.862 [Radio_Surface](INFO): Join timeout helper Thread ID is 6526 2021-12-17T23:26:14.157Z,1639783574.157 [Radio_Surface](INFO): Powering down 2021-12-17T23:26:14.158Z,1639783574.158 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2021-12-17T23:26:14.159Z,1639783574.159 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2021-12-17T23:26:14.173Z,1639783574.173 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler 2021-12-17T23:26:14.173Z,1639783574.173 [Onboard ThreadHandler](INFO): Thread cancelled. 2021-12-17T23:26:14.174Z,1639783574.174 [Onboard](INFO): Join timeout helper Thread ID is 6527 2021-12-17T23:26:16.450Z,1639783576.450 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread. 2021-12-17T23:26:16.450Z,1639783576.450 [Onboard ThreadHandler](INFO): Thread cancelled. 2021-12-17T23:26:16.466Z,1639783576.466 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2021-12-17T23:26:16.466Z,1639783576.466 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2021-12-17T23:26:16.467Z,1639783576.467 [DataOverHttps](INFO): Join timeout helper Thread ID is 6528 2021-12-17T23:26:16.577Z,1639783576.577 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2021-12-17T23:26:16.580Z,1639783576.580 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2021-12-17T23:26:16.598Z,1639783576.598 [ComponentRegistry](INFO): Shutting down BackseatComponent ThreadHandler 2021-12-17T23:26:16.598Z,1639783576.598 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2021-12-17T23:26:16.599Z,1639783576.599 [BackseatComponent](INFO): Join timeout helper Thread ID is 6529 2021-12-17T23:26:16.702Z,1639783576.702 [BackseatComponent ThreadHandler](INFO): Uninitializing protected caller thread. 2021-12-17T23:26:16.702Z,1639783576.702 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2021-12-17T23:26:16.703Z,1639783576.703 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2021-12-17T23:26:16.704Z,1639783576.704 [logger ThreadHandler](INFO): Thread cancelled. 2021-12-17T23:26:16.704Z,1639783576.704 [logger](INFO): Join timeout helper Thread ID is 6530 2021-12-17T23:26:16.730Z,1639783576.730 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2021-12-17T23:26:16.730Z,1639783576.730 [logger ThreadHandler](INFO): Thread cancelled. 2021-12-17T23:26:16.734Z,1639783576.734 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2021-12-17T23:26:16.734Z,1639783576.734 [CommandLine ThreadHandler](INFO): Thread cancelled. 2021-12-17T23:26:16.735Z,1639783576.735 [CommandLine](INFO): Join timeout helper Thread ID is 6531 2021-12-17T23:26:16.786Z,1639783576.786 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2021-12-17T23:26:16.786Z,1639783576.786 [CommandLine ThreadHandler](INFO): Thread cancelled. 2021-12-17T23:26:16.798Z,1639783576.798 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler 2021-12-17T23:26:16.798Z,1639783576.798 [CommandExec ThreadHandler](INFO): Thread cancelled. 2021-12-17T23:26:16.799Z,1639783576.799 [CommandExec](INFO): Join timeout helper Thread ID is 6532 2021-12-17T23:26:16.800Z,1639783576.800 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2021-12-17T23:26:16.800Z,1639783576.800 [controlThread ThreadHandler](INFO): Thread cancelled. 2021-12-17T23:26:16.800Z,1639783576.800 [controlThread](INFO): Join timeout helper Thread ID is 6533 2021-12-17T23:26:17.061Z,1639783577.061 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2021-12-17T23:26:17.062Z,1639783577.062 [controlThread](DEBUG): Uninitializing ControlThread 2021-12-17T23:26:17.062Z,1639783577.062 [AHRS_M2](INFO): Powering down 2021-12-17T23:26:17.134Z,1639783577.134 [NAL9602](INFO): Powering down 2021-12-17T23:26:17.136Z,1639783577.136 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2021-12-17T23:26:17.137Z,1639783577.137 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2021-12-17T23:26:17.138Z,1639783577.138 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2021-12-17T23:26:17.139Z,1639783577.139 [MissionManager](INFO): Uninitializing Mission Default 2021-12-17T23:26:17.139Z,1639783577.139 [Default] Stopped 2021-12-17T23:26:17.139Z,1639783577.139 [Default](DEBUG): Aggregate::uninitialize Default 2021-12-17T23:26:17.139Z,1639783577.139 [Default:B.GoToSurface] Stopped 2021-12-17T23:26:17.139Z,1639783577.139 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2021-12-17T23:26:17.139Z,1639783577.139 [Default:CheckIn] Stopped 2021-12-17T23:26:17.139Z,1639783577.139 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-17T23:26:17.139Z,1639783577.139 [Default:CheckIn:Read_GPS] Stopped 2021-12-17T23:26:17.143Z,1639783577.143 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2021-12-17T23:26:17.143Z,1639783577.143 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2021-12-17T23:26:17.143Z,1639783577.143 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2021-12-17T23:26:17.143Z,1639783577.143 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2021-12-17T23:26:17.144Z,1639783577.144 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2021-12-17T23:26:17.144Z,1639783577.144 [BuoyancyServo](INFO): Powering down 2021-12-17T23:26:17.157Z,1639783577.157 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2021-12-17T23:26:17.158Z,1639783577.158 [ElevatorServo](INFO): Powering down 2021-12-17T23:26:17.159Z,1639783577.159 [MassServo](DEBUG): Uninitialize Mass Servo. 2021-12-17T23:26:17.159Z,1639783577.159 [MassServo](INFO): Powering down 2021-12-17T23:26:17.160Z,1639783577.160 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2021-12-17T23:26:17.160Z,1639783577.160 [RudderServo](INFO): Powering down 2021-12-17T23:26:17.161Z,1639783577.161 [ThrusterHE](DEBUG): Uninitialize Thruster Servo. 2021-12-17T23:26:17.161Z,1639783577.161 [ThrusterHE](INFO): Powering down 2021-12-17T23:26:17.162Z,1639783577.162 [SBIT](DEBUG): Uninitialize SBIT Component. 2021-12-17T23:26:17.162Z,1639783577.162 [IBIT](DEBUG): Uninitialize IBIT Component. 2021-12-17T23:26:17.162Z,1639783577.162 [CBIT](DEBUG): Uninitialize CBIT Component. 2021-12-17T23:26:17.162Z,1639783577.162 [CBIT](DEBUG): Powering off loads. 2021-12-17T23:26:17.173Z,1639783577.173 [CBIT](DEBUG): Disabling WDT. 2021-12-17T23:26:17.185Z,1639783577.185 [CBIT](DEBUG): Opening all GF detection circuits. 2021-12-17T23:26:17.186Z,1639783577.186 [controlThread ThreadHandler](INFO): Thread cancelled. 2021-12-17T23:26:17.245Z,1639783577.245 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2021-12-17T23:26:17.248Z,1639783577.248 [Onboard ThreadHandler](INFO): Thread cancelled. 2021-12-17T23:26:17.254Z,1639783577.254 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2021-12-17T23:26:17.300Z,1639783577.300 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2021-12-17T23:26:17.334Z,1639783577.334 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2021-12-17T23:26:17.338Z,1639783577.338 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2021-12-17T23:26:17.369Z,1639783577.369 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2021-12-17T23:26:17.443Z,1639783577.443 [logger ThreadHandler](INFO): Thread cancelled.