2022-05-19T14:49:34.238Z,1652971774.238 [CommandExec](IMPORTANT): got command restart logs 2022-05-19T14:49:41.763Z,1652971781.763 [NAL9602](INFO): SBD MO Status=0, MOMSN=33025, MT Status=0, MTMSN=0 2022-05-19T14:49:41.763Z,1652971781.763 [NAL9602](INFO): No messages in MT queue 2022-05-19T14:50:12.463Z,1652971812.463 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-19T14:52:25.828Z,1652971945.828 [CBIT](IMPORTANT): Beginning ground fault scan 2022-05-19T14:52:28.680Z,1652971948.680 [CBIT](ERROR): Error reading 24V bus power status. Assuming off for scan purposes. 2022-05-19T14:52:36.767Z,1652971956.767 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.002080 CHAN A1 (24V) N/A reporting off CHAN A2 (12V): -0.002244 CHAN A3 (5V): -0.001032 CHAN B0 (3.3V): 0.000120 CHAN B1 (3.15aV): -0.000160 CHAN B2 (3.15bV): -0.000670 CHAN B3 (GND): 0.000097 OPEN: -0.000444 Full Scale: +/- 1 mA 2022-05-19T14:53:49.864Z,1652972029.864 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-19T14:53:49.864Z,1652972029.864 [Default:CheckIn:C.Wait] Stopped 2022-05-19T14:53:49.864Z,1652972029.864 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-19T14:53:49.865Z,1652972029.865 [Default:CheckIn:D] Running Loop=1 2022-05-19T14:53:50.261Z,1652972030.261 [Default:CheckIn:D] Stopped 2022-05-19T14:53:50.261Z,1652972030.261 [Default:CheckIn:E] Running Loop=1 2022-05-19T14:53:50.658Z,1652972030.658 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 13.712155 min 2022-05-19T14:53:50.658Z,1652972030.658 [Default:CheckIn:E] Stopped 2022-05-19T14:53:50.658Z,1652972030.658 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-19T14:53:50.658Z,1652972030.658 [Default:CheckIn] Stopped 2022-05-19T14:53:50.658Z,1652972030.658 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-19T14:53:50.658Z,1652972030.658 [Default:CheckIn](INFO): Running loop #3 2022-05-19T14:53:50.659Z,1652972030.659 [Default:CheckIn] Running Loop=3 2022-05-19T14:53:50.659Z,1652972030.659 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-19T14:53:50.659Z,1652972030.659 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-19T14:53:52.678Z,1652972032.678 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,145351.00,A,3648.05810,N,12150.57171,W,10.827,42.77,190522,,,D*7E 2022-05-19T14:53:52.681Z,1652972032.681 [NAL9602](INFO): GPS fix at 20220519T145351: (36.800968, -121.842862) 2022-05-19T14:53:52.691Z,1652972032.691 [Default:CheckIn:Read_GPS] Stopped 2022-05-19T14:53:52.691Z,1652972032.691 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-19T14:54:00.500Z,1652972040.500 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20220519T084911/Courier0079.lzma 2022-05-19T14:54:01.502Z,1652972041.502 [DataOverHttps](INFO): Moved sent file to Logs/20220519T084911/Courier0079.lzma.bak 2022-05-19T14:54:01.503Z,1652972041.503 [DataOverHttps](INFO): SBD MOMSN=16808609 2022-05-19T14:54:17.421Z,1652972057.421 [DataOverHttps](INFO): Sending 267 bytes from file Logs/20220519T144934/Courier0000.lzma 2022-05-19T14:54:18.422Z,1652972058.422 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Courier0000.lzma.bak 2022-05-19T14:54:18.422Z,1652972058.422 [DataOverHttps](INFO): SBD MOMSN=16808613 2022-05-19T14:54:30.288Z,1652972070.288 [NAL9602](INFO): SBD MO Status=0, MOMSN=33026, MT Status=0, MTMSN=0 2022-05-19T14:54:30.288Z,1652972070.288 [NAL9602](INFO): No messages in MT queue 2022-05-19T14:55:00.986Z,1652972100.986 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-19T14:55:14.524Z,1652972114.524 [DataOverHttps](INFO): Sending 105 bytes from file Logs/20220519T084911/Express0080.lzma 2022-05-19T14:55:15.527Z,1652972115.527 [DataOverHttps](INFO): Moved sent file to Logs/20220519T084911/Express0080.lzma.bak 2022-05-19T14:55:15.527Z,1652972115.527 [DataOverHttps](INFO): SBD MOMSN=16808619 2022-05-19T14:55:34.389Z,1652972134.389 [DataOverHttps](INFO): Sending 581 bytes from file Logs/20220519T144934/Express0001.lzma 2022-05-19T14:55:35.390Z,1652972135.390 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Express0001.lzma.bak 2022-05-19T14:55:35.391Z,1652972135.391 [DataOverHttps](INFO): SBD MOMSN=16808622 2022-05-19T14:55:51.520Z,1652972151.520 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20220519T144934/Express0004.lzma 2022-05-19T14:55:52.522Z,1652972152.522 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Express0004.lzma.bak 2022-05-19T14:55:52.522Z,1652972152.522 [DataOverHttps](INFO): SBD MOMSN=16808629 2022-05-19T14:55:53.992Z,1652972153.992 [Default:CheckIn:Read_Iridium] Stopped 2022-05-19T14:55:53.992Z,1652972153.992 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-19T14:55:53.992Z,1652972153.992 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-19T14:58:26.409Z,1652972306.409 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-19T14:58:57.533Z,1652972337.533 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-19T14:59:28.661Z,1652972368.661 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-19T14:59:59.809Z,1652972399.809 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-19T15:00:30.933Z,1652972430.933 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-19T15:00:48.001Z,1652972448.001 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.775314 2022-05-19T15:00:54.569Z,1652972454.569 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-19T15:00:54.569Z,1652972454.569 [Default:CheckIn:C.Wait] Stopped 2022-05-19T15:00:54.569Z,1652972454.569 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-19T15:00:54.569Z,1652972454.569 [Default:CheckIn:D] Running Loop=1 2022-05-19T15:00:54.971Z,1652972454.971 [Default:CheckIn:D] Stopped 2022-05-19T15:00:54.971Z,1652972454.971 [Default:CheckIn:E] Running Loop=1 2022-05-19T15:00:55.379Z,1652972455.379 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 20.790651 min 2022-05-19T15:00:55.379Z,1652972455.379 [Default:CheckIn:E] Stopped 2022-05-19T15:00:55.380Z,1652972455.380 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-19T15:00:55.380Z,1652972455.380 [Default:CheckIn] Stopped 2022-05-19T15:00:55.380Z,1652972455.380 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-19T15:00:55.380Z,1652972455.380 [Default:CheckIn](INFO): Running loop #4 2022-05-19T15:00:55.380Z,1652972455.380 [Default:CheckIn] Running Loop=4 2022-05-19T15:00:55.380Z,1652972455.380 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-19T15:00:55.380Z,1652972455.380 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-19T15:00:57.383Z,1652972457.383 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,150056.00,A,3648.43696,N,12149.55480,W,8.086,260.70,190522,,,D*72 2022-05-19T15:00:57.385Z,1652972457.385 [NAL9602](INFO): GPS fix at 20220519T150056: (36.807283, -121.825913) 2022-05-19T15:00:57.418Z,1652972457.418 [Default:CheckIn:Read_GPS] Stopped 2022-05-19T15:00:57.418Z,1652972457.418 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-19T15:01:09.401Z,1652972469.401 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.002947 2022-05-19T15:01:20.052Z,1652972480.052 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20220519T144934/Courier0006.lzma 2022-05-19T15:01:21.054Z,1652972481.054 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Courier0006.lzma.bak 2022-05-19T15:01:21.054Z,1652972481.054 [DataOverHttps](INFO): SBD MOMSN=16808649 2022-05-19T15:01:42.265Z,1652972502.265 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-19T15:01:49.600Z,1652972509.600 [DataOverHttps](INFO): Sending 146 bytes from file Logs/20220519T144934/Express0007.lzma 2022-05-19T15:01:50.602Z,1652972510.602 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Express0007.lzma.bak 2022-05-19T15:01:50.602Z,1652972510.602 [DataOverHttps](INFO): SBD MOMSN=16808652 2022-05-19T15:01:51.985Z,1652972511.985 [Default:CheckIn:Read_Iridium] Stopped 2022-05-19T15:01:51.986Z,1652972511.986 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-19T15:01:51.986Z,1652972511.986 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-19T15:06:52.597Z,1652972812.597 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-19T15:06:52.597Z,1652972812.597 [Default:CheckIn:C.Wait] Stopped 2022-05-19T15:06:52.597Z,1652972812.597 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-19T15:06:52.598Z,1652972812.598 [Default:CheckIn:D] Running Loop=1 2022-05-19T15:06:53.004Z,1652972813.004 [Default:CheckIn:D] Stopped 2022-05-19T15:06:53.004Z,1652972813.004 [Default:CheckIn:E] Running Loop=1 2022-05-19T15:06:53.414Z,1652972813.414 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 26.757865 min 2022-05-19T15:06:53.414Z,1652972813.414 [Default:CheckIn:E] Stopped 2022-05-19T15:06:53.414Z,1652972813.414 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-19T15:06:53.414Z,1652972813.414 [Default:CheckIn] Stopped 2022-05-19T15:06:53.414Z,1652972813.414 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-19T15:06:53.414Z,1652972813.414 [Default:CheckIn](INFO): Running loop #5 2022-05-19T15:06:53.414Z,1652972813.414 [Default:CheckIn] Running Loop=5 2022-05-19T15:06:53.414Z,1652972813.414 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-19T15:06:53.415Z,1652972813.415 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-19T15:06:55.423Z,1652972815.423 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,150654.00,A,3648.42244,N,12150.12787,W,0.486,40.01,190522,,,D*49 2022-05-19T15:06:55.426Z,1652972815.426 [NAL9602](INFO): GPS fix at 20220519T150654: (36.807041, -121.835465) 2022-05-19T15:06:55.436Z,1652972815.436 [Default:CheckIn:Read_GPS] Stopped 2022-05-19T15:06:55.436Z,1652972815.436 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-19T15:07:11.983Z,1652972831.983 [NAL9602](INFO): SBD MO Status=0, MOMSN=33027, MT Status=0, MTMSN=0 2022-05-19T15:07:11.983Z,1652972831.983 [NAL9602](INFO): No messages in MT queue 2022-05-19T15:07:13.516Z,1652972833.516 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220519T144934/Courier0009.lzma 2022-05-19T15:07:14.518Z,1652972834.518 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Courier0009.lzma.bak 2022-05-19T15:07:14.518Z,1652972834.518 [DataOverHttps](INFO): SBD MOMSN=16808662 2022-05-19T15:07:42.689Z,1652972862.689 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-19T15:07:51.676Z,1652972871.676 [DataOverHttps](INFO): Sending 142 bytes from file Logs/20220519T144934/Express0010.lzma 2022-05-19T15:07:52.678Z,1652972872.678 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Express0010.lzma.bak 2022-05-19T15:07:52.678Z,1652972872.678 [DataOverHttps](INFO): SBD MOMSN=16808665 2022-05-19T15:07:54.016Z,1652972874.016 [Default:CheckIn:Read_Iridium] Stopped 2022-05-19T15:07:54.016Z,1652972874.016 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-19T15:07:54.016Z,1652972874.016 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-19T15:08:54.225Z,1652972934.225 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-19T15:12:54.666Z,1652973174.666 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-19T15:12:54.666Z,1652973174.666 [Default:CheckIn:C.Wait] Stopped 2022-05-19T15:12:54.666Z,1652973174.666 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-19T15:12:54.667Z,1652973174.667 [Default:CheckIn:D] Running Loop=1 2022-05-19T15:12:55.029Z,1652973175.029 [Default:CheckIn:D] Stopped 2022-05-19T15:12:55.029Z,1652973175.029 [Default:CheckIn:E] Running Loop=1 2022-05-19T15:12:55.416Z,1652973175.416 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 32.791626 min 2022-05-19T15:12:55.416Z,1652973175.416 [Default:CheckIn:E] Stopped 2022-05-19T15:12:55.416Z,1652973175.416 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-19T15:12:55.417Z,1652973175.417 [Default:CheckIn] Stopped 2022-05-19T15:12:55.417Z,1652973175.417 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-19T15:12:55.417Z,1652973175.417 [Default:CheckIn](INFO): Running loop #6 2022-05-19T15:12:55.417Z,1652973175.417 [Default:CheckIn] Running Loop=6 2022-05-19T15:12:55.417Z,1652973175.417 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-19T15:12:55.417Z,1652973175.417 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-19T15:12:57.427Z,1652973177.427 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,151256.00,A,3648.47607,N,12150.12600,W,1.788,36.49,190522,,,D*47 2022-05-19T15:12:57.429Z,1652973177.429 [NAL9602](INFO): GPS fix at 20220519T151256: (36.807935, -121.835433) 2022-05-19T15:12:57.461Z,1652973177.461 [Default:CheckIn:Read_GPS] Stopped 2022-05-19T15:12:57.461Z,1652973177.461 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-19T15:13:06.488Z,1652973186.488 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20220519T144934/Courier0012.lzma 2022-05-19T15:13:07.490Z,1652973187.490 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Courier0012.lzma.bak 2022-05-19T15:13:07.491Z,1652973187.491 [DataOverHttps](INFO): SBD MOMSN=16808671 2022-05-19T15:13:12.379Z,1652973192.379 [NAL9602](INFO): SBD MO Status=0, MOMSN=33028, MT Status=0, MTMSN=0 2022-05-19T15:13:12.379Z,1652973192.379 [NAL9602](INFO): No messages in MT queue 2022-05-19T15:13:25.220Z,1652973205.220 [DataOverHttps](INFO): Sending 137 bytes from file Logs/20220519T144934/Express0013.lzma 2022-05-19T15:13:26.222Z,1652973206.222 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Express0013.lzma.bak 2022-05-19T15:13:26.222Z,1652973206.222 [DataOverHttps](INFO): SBD MOMSN=16808674 2022-05-19T15:13:27.748Z,1652973207.748 [Default:CheckIn:Read_Iridium] Stopped 2022-05-19T15:13:27.749Z,1652973207.749 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-19T15:13:27.749Z,1652973207.749 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-19T15:13:43.081Z,1652973223.081 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-19T15:18:28.384Z,1652973508.384 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-19T15:18:28.384Z,1652973508.384 [Default:CheckIn:C.Wait] Stopped 2022-05-19T15:18:28.384Z,1652973508.384 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-19T15:18:28.385Z,1652973508.385 [Default:CheckIn:D] Running Loop=1 2022-05-19T15:18:28.795Z,1652973508.795 [Default:CheckIn:D] Stopped 2022-05-19T15:18:28.795Z,1652973508.795 [Default:CheckIn:E] Running Loop=1 2022-05-19T15:18:29.204Z,1652973509.204 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 38.354390 min 2022-05-19T15:18:29.204Z,1652973509.204 [Default:CheckIn:E] Stopped 2022-05-19T15:18:29.205Z,1652973509.205 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-19T15:18:29.205Z,1652973509.205 [Default:CheckIn] Stopped 2022-05-19T15:18:29.205Z,1652973509.205 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-19T15:18:29.205Z,1652973509.205 [Default:CheckIn](INFO): Running loop #7 2022-05-19T15:18:29.205Z,1652973509.205 [Default:CheckIn] Running Loop=7 2022-05-19T15:18:29.205Z,1652973509.205 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-19T15:18:29.205Z,1652973509.205 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-19T15:18:31.211Z,1652973511.211 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,151830.00,A,3648.50540,N,12149.94225,W,2.274,88.56,190522,,,D*40 2022-05-19T15:18:31.225Z,1652973511.225 [NAL9602](INFO): GPS fix at 20220519T151830: (36.808423, -121.832371) 2022-05-19T15:18:31.236Z,1652973511.236 [Default:CheckIn:Read_GPS] Stopped 2022-05-19T15:18:31.236Z,1652973511.236 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-19T15:18:38.980Z,1652973518.980 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220519T144934/Courier0015.lzma 2022-05-19T15:18:39.982Z,1652973519.982 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Courier0015.lzma.bak 2022-05-19T15:18:39.982Z,1652973519.982 [DataOverHttps](INFO): SBD MOMSN=16808739 2022-05-19T15:19:01.244Z,1652973541.244 [DataOverHttps](INFO): Sending 144 bytes from file Logs/20220519T144934/Express0016.lzma 2022-05-19T15:19:02.246Z,1652973542.246 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Express0016.lzma.bak 2022-05-19T15:19:02.247Z,1652973542.247 [DataOverHttps](INFO): SBD MOMSN=16808742 2022-05-19T15:19:03.582Z,1652973543.582 [Default:CheckIn:Read_Iridium] Stopped 2022-05-19T15:19:03.582Z,1652973543.582 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-19T15:19:03.582Z,1652973543.582 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-19T15:19:03.975Z,1652973543.975 [NAL9602](INFO): SBD MO Status=2, MOMSN=33029, MT Status=2, MTMSN=0 2022-05-19T15:19:03.975Z,1652973543.975 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-05-19T15:19:17.311Z,1652973557.311 [NAL9602](INFO): SBD MO Status=2, MOMSN=33029, MT Status=2, MTMSN=0 2022-05-19T15:19:17.311Z,1652973557.311 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-05-19T15:20:25.180Z,1652973625.180 [NAL9602](INFO): SBD MO Status=0, MOMSN=33029, MT Status=0, MTMSN=0 2022-05-19T15:20:25.180Z,1652973625.180 [NAL9602](INFO): No messages in MT queue 2022-05-19T15:20:55.885Z,1652973655.885 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-19T15:24:04.178Z,1652973844.178 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-19T15:24:04.178Z,1652973844.178 [Default:CheckIn:C.Wait] Stopped 2022-05-19T15:24:04.178Z,1652973844.178 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-19T15:24:04.179Z,1652973844.179 [Default:CheckIn:D] Running Loop=1 2022-05-19T15:24:04.557Z,1652973844.557 [Default:CheckIn:D] Stopped 2022-05-19T15:24:04.557Z,1652973844.557 [Default:CheckIn:E] Running Loop=1 2022-05-19T15:24:04.969Z,1652973844.969 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 43.950427 min 2022-05-19T15:24:04.969Z,1652973844.969 [Default:CheckIn:E] Stopped 2022-05-19T15:24:04.969Z,1652973844.969 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-19T15:24:04.969Z,1652973844.969 [Default:CheckIn] Stopped 2022-05-19T15:24:04.970Z,1652973844.970 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-19T15:24:04.970Z,1652973844.970 [Default:CheckIn](INFO): Running loop #8 2022-05-19T15:24:04.970Z,1652973844.970 [Default:CheckIn] Running Loop=8 2022-05-19T15:24:04.970Z,1652973844.970 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-19T15:24:04.970Z,1652973844.970 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-19T15:24:06.976Z,1652973846.976 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,152406.00,A,3648.43397,N,12149.44339,W,5.909,63.12,190522,,,D*46 2022-05-19T15:24:06.978Z,1652973846.978 [NAL9602](INFO): GPS fix at 20220519T152406: (36.807233, -121.824056) 2022-05-19T15:24:06.989Z,1652973846.989 [Default:CheckIn:Read_GPS] Stopped 2022-05-19T15:24:06.989Z,1652973846.989 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-19T15:24:15.004Z,1652973855.004 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220519T144934/Courier0018.lzma 2022-05-19T15:24:16.007Z,1652973856.007 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Courier0018.lzma.bak 2022-05-19T15:24:16.007Z,1652973856.007 [DataOverHttps](INFO): SBD MOMSN=16808778 2022-05-19T15:24:28.835Z,1652973868.835 [NAL9602](INFO): SBD MO Status=0, MOMSN=33030, MT Status=0, MTMSN=0 2022-05-19T15:24:28.835Z,1652973868.835 [NAL9602](INFO): No messages in MT queue 2022-05-19T15:24:59.585Z,1652973899.585 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-19T15:25:51.181Z,1652973951.181 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-19T15:26:22.333Z,1652973982.333 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-19T15:26:53.489Z,1652974013.489 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-19T15:27:16.581Z,1652974036.581 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.574768 2022-05-19T15:27:46.881Z,1652974066.881 [NAL9602](INFO): SBD MO Status=2, MOMSN=33031, MT Status=2, MTMSN=0 2022-05-19T15:27:46.881Z,1652974066.881 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-05-19T15:27:47.741Z,1652974067.741 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-19T15:28:18.866Z,1652974098.866 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-19T15:28:20.455Z,1652974100.455 [NAL9602](INFO): SBD MO Status=1, MOMSN=33031, MT Status=0, MTMSN=0 2022-05-19T15:28:20.509Z,1652974100.509 [NAL9602](INFO): Sent 142 bytes from file Logs/20220519T144934/Express0019.lzma 2022-05-19T15:28:20.509Z,1652974100.509 [NAL9602](INFO): Packets left to send: 0 2022-05-19T15:28:39.035Z,1652974119.035 [NAL9602](INFO): SBD MO Status=0, MOMSN=33032, MT Status=0, MTMSN=0 2022-05-19T15:28:39.116Z,1652974119.116 [Default:CheckIn:Read_Iridium] Stopped 2022-05-19T15:28:39.117Z,1652974119.117 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-19T15:28:39.117Z,1652974119.117 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-19T15:28:49.989Z,1652974129.989 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-19T15:29:09.741Z,1652974149.741 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-19T15:29:21.130Z,1652974161.130 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-19T15:29:52.257Z,1652974192.257 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-19T15:30:23.381Z,1652974223.381 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-19T15:30:54.585Z,1652974254.585 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-19T15:31:25.273Z,1652974285.273 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.002926 2022-05-19T15:32:57.849Z,1652974377.849 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-19T15:33:28.973Z,1652974408.973 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-19T15:33:39.665Z,1652974419.665 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-19T15:33:39.665Z,1652974419.665 [Default:CheckIn:C.Wait] Stopped 2022-05-19T15:33:39.665Z,1652974419.665 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-19T15:33:39.666Z,1652974419.666 [Default:CheckIn:D] Running Loop=1 2022-05-19T15:33:40.081Z,1652974420.081 [Default:CheckIn:D] Stopped 2022-05-19T15:33:40.081Z,1652974420.081 [Default:CheckIn:E] Running Loop=1 2022-05-19T15:33:40.467Z,1652974420.467 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 53.542497 min 2022-05-19T15:33:40.467Z,1652974420.467 [Default:CheckIn:E] Stopped 2022-05-19T15:33:40.467Z,1652974420.467 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-19T15:33:40.467Z,1652974420.467 [Default:CheckIn] Stopped 2022-05-19T15:33:40.467Z,1652974420.467 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-19T15:33:40.467Z,1652974420.467 [Default:CheckIn](INFO): Running loop #9 2022-05-19T15:33:40.468Z,1652974420.468 [Default:CheckIn] Running Loop=9 2022-05-19T15:33:40.468Z,1652974420.468 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-19T15:33:40.468Z,1652974420.468 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-19T15:33:42.478Z,1652974422.478 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,153341.00,A,3648.29396,N,12148.60524,W,3.596,88.56,190522,,,D*4A 2022-05-19T15:33:42.480Z,1652974422.480 [NAL9602](INFO): GPS fix at 20220519T153341: (36.804899, -121.810087) 2022-05-19T15:33:42.490Z,1652974422.490 [Default:CheckIn:Read_GPS] Stopped 2022-05-19T15:33:42.490Z,1652974422.490 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-19T15:33:57.083Z,1652974437.083 [NAL9602](INFO): SBD MO Status=0, MOMSN=33033, MT Status=0, MTMSN=0 2022-05-19T15:33:57.083Z,1652974437.083 [NAL9602](INFO): No messages in MT queue 2022-05-19T15:34:00.097Z,1652974440.097 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-19T15:34:27.753Z,1652974467.753 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-19T15:34:31.229Z,1652974471.229 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-19T15:34:35.245Z,1652974475.245 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.727875 2022-05-19T15:35:04.619Z,1652974504.619 [NAL9602](INFO): SBD MO Status=2, MOMSN=33034, MT Status=2, MTMSN=0 2022-05-19T15:35:04.619Z,1652974504.619 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-05-19T15:35:06.389Z,1652974506.389 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-19T15:35:22.375Z,1652974522.375 [NAL9602](INFO): SBD MO Status=2, MOMSN=33034, MT Status=2, MTMSN=0 2022-05-19T15:35:22.375Z,1652974522.375 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-05-19T15:35:37.521Z,1652974537.521 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-19T15:35:47.863Z,1652974547.863 [NAL9602](INFO): SBD MO Status=2, MOMSN=33034, MT Status=2, MTMSN=0 2022-05-19T15:35:47.863Z,1652974547.863 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-05-19T15:36:06.123Z,1652974566.123 [NAL9602](INFO): SBD MO Status=1, MOMSN=33034, MT Status=0, MTMSN=0 2022-05-19T15:36:06.181Z,1652974566.181 [NAL9602](INFO): Sent 72 bytes from file Logs/20220519T144934/Courier0021.lzma 2022-05-19T15:36:06.181Z,1652974566.181 [NAL9602](INFO): Packets left to send: 0 2022-05-19T15:36:08.649Z,1652974568.649 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-19T15:36:26.387Z,1652974586.387 [NAL9602](INFO): SBD MO Status=1, MOMSN=33035, MT Status=0, MTMSN=0 2022-05-19T15:36:26.437Z,1652974586.437 [NAL9602](INFO): Sent 142 bytes from file Logs/20220519T144934/Express0022.lzma 2022-05-19T15:36:26.437Z,1652974586.437 [NAL9602](INFO): Packets left to send: 0 2022-05-19T15:36:36.048Z,1652974596.048 [NAL9602](INFO): SBD MO Status=0, MOMSN=33036, MT Status=0, MTMSN=0 2022-05-19T15:36:36.125Z,1652974596.125 [Default:CheckIn:Read_Iridium] Stopped 2022-05-19T15:36:36.125Z,1652974596.125 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-19T15:36:36.126Z,1652974596.126 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-19T15:36:39.773Z,1652974599.773 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-19T15:37:06.786Z,1652974626.786 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-19T15:37:10.917Z,1652974630.917 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-19T15:37:19.449Z,1652974639.449 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.002938 2022-05-19T15:38:57.498Z,1652974737.498 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-05-19T15:39:13.259Z,1652974753.259 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-05-19T15:39:28.202Z,1652974768.202 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-05-19T15:39:43.558Z,1652974783.558 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-05-19T15:39:58.503Z,1652974798.503 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-05-19T15:40:13.453Z,1652974813.453 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-05-19T15:40:29.250Z,1652974829.250 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-05-19T15:40:45.006Z,1652974845.006 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-05-19T15:41:00.410Z,1652974860.410 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-05-19T15:41:20.631Z,1652974880.631 [BPC1](INFO): Calculating totals. Valid battery stick count: 54. Valid reserve battery stick count: 6. 2022-05-19T15:41:20.633Z,1652974880.633 [BPC1](INFO): Received data from all battery sticks. 2022-05-19T15:41:36.782Z,1652974896.782 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-19T15:41:36.782Z,1652974896.782 [Default:CheckIn:C.Wait] Stopped 2022-05-19T15:41:36.783Z,1652974896.783 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-19T15:41:36.783Z,1652974896.783 [Default:CheckIn:D] Running Loop=1 2022-05-19T15:41:37.200Z,1652974897.200 [Default:CheckIn:D] Stopped 2022-05-19T15:41:37.200Z,1652974897.200 [Default:CheckIn:E] Running Loop=1 2022-05-19T15:41:37.589Z,1652974897.589 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 61.494470 min 2022-05-19T15:41:37.589Z,1652974897.589 [Default:CheckIn:E] Stopped 2022-05-19T15:41:37.589Z,1652974897.589 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-19T15:41:37.589Z,1652974897.589 [Default:CheckIn] Stopped 2022-05-19T15:41:37.589Z,1652974897.589 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-19T15:41:37.590Z,1652974897.590 [Default:CheckIn](INFO): Running loop #10 2022-05-19T15:41:37.590Z,1652974897.590 [Default:CheckIn] Running Loop=10 2022-05-19T15:41:37.590Z,1652974897.590 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-19T15:41:37.590Z,1652974897.590 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-19T15:41:39.604Z,1652974899.604 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,154138.00,A,3648.20779,N,12147.96353,W,3.849,94.43,190522,,,D*4B 2022-05-19T15:41:39.607Z,1652974899.607 [NAL9602](INFO): GPS fix at 20220519T154138: (36.803463, -121.799392) 2022-05-19T15:41:39.617Z,1652974899.617 [Default:CheckIn:Read_GPS] Stopped 2022-05-19T15:41:39.617Z,1652974899.617 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-19T15:41:46.489Z,1652974906.489 [DataOverHttps](INFO): Sending 200 bytes from file Logs/20220519T144934/Courier0024.lzma 2022-05-19T15:41:47.490Z,1652974907.490 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Courier0024.lzma.bak 2022-05-19T15:41:47.490Z,1652974907.490 [DataOverHttps](INFO): SBD MOMSN=16808886 2022-05-19T15:42:03.249Z,1652974923.249 [DataOverHttps](INFO): Sending 143 bytes from file Logs/20220519T144934/Express0025.lzma 2022-05-19T15:42:03.915Z,1652974923.915 [NAL9602](INFO): SBD MO Status=0, MOMSN=33037, MT Status=0, MTMSN=0 2022-05-19T15:42:03.915Z,1652974923.915 [NAL9602](INFO): No messages in MT queue 2022-05-19T15:42:04.250Z,1652974924.250 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Express0025.lzma.bak 2022-05-19T15:42:04.251Z,1652974924.251 [DataOverHttps](INFO): SBD MOMSN=16808890 2022-05-19T15:42:05.546Z,1652974925.546 [Default:CheckIn:Read_Iridium] Stopped 2022-05-19T15:42:05.546Z,1652974925.546 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-19T15:42:05.546Z,1652974925.546 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-19T15:42:34.617Z,1652974954.617 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-19T15:47:06.169Z,1652975226.169 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-19T15:47:06.169Z,1652975226.169 [Default:CheckIn:C.Wait] Stopped 2022-05-19T15:47:06.169Z,1652975226.169 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-19T15:47:06.169Z,1652975226.169 [Default:CheckIn:D] Running Loop=1 2022-05-19T15:47:06.576Z,1652975226.576 [Default:CheckIn:D] Stopped 2022-05-19T15:47:06.576Z,1652975226.576 [Default:CheckIn:E] Running Loop=1 2022-05-19T15:47:06.990Z,1652975226.990 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 66.984066 min 2022-05-19T15:47:06.990Z,1652975226.990 [Default:CheckIn:E] Stopped 2022-05-19T15:47:06.990Z,1652975226.990 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-19T15:47:06.990Z,1652975226.990 [Default:CheckIn] Stopped 2022-05-19T15:47:06.990Z,1652975226.990 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-19T15:47:06.990Z,1652975226.990 [Default:CheckIn](INFO): Running loop #11 2022-05-19T15:47:06.990Z,1652975226.990 [Default:CheckIn] Running Loop=11 2022-05-19T15:47:06.990Z,1652975226.990 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-19T15:47:06.990Z,1652975226.990 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-19T15:47:08.995Z,1652975228.995 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,154708.00,A,3648.31174,N,12147.52458,W,3.965,11.72,190522,,,D*41 2022-05-19T15:47:08.998Z,1652975228.998 [NAL9602](INFO): GPS fix at 20220519T154708: (36.805196, -121.792076) 2022-05-19T15:47:09.028Z,1652975229.028 [Default:CheckIn:Read_GPS] Stopped 2022-05-19T15:47:09.028Z,1652975229.028 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-19T15:47:17.072Z,1652975237.072 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20220519T144934/Courier0027.lzma 2022-05-19T15:47:18.074Z,1652975238.074 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Courier0027.lzma.bak 2022-05-19T15:47:18.074Z,1652975238.074 [DataOverHttps](INFO): SBD MOMSN=16808924 2022-05-19T15:47:30.407Z,1652975250.407 [NAL9602](INFO): SBD MO Status=0, MOMSN=33038, MT Status=0, MTMSN=0 2022-05-19T15:47:30.407Z,1652975250.407 [NAL9602](INFO): No messages in MT queue 2022-05-19T15:47:33.920Z,1652975253.920 [DataOverHttps](INFO): Sending 142 bytes from file Logs/20220519T144934/Express0028.lzma 2022-05-19T15:47:34.923Z,1652975254.923 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Express0028.lzma.bak 2022-05-19T15:47:34.923Z,1652975254.923 [DataOverHttps](INFO): SBD MOMSN=16808928 2022-05-19T15:47:36.082Z,1652975256.082 [Default:CheckIn:Read_Iridium] Stopped 2022-05-19T15:47:36.082Z,1652975256.082 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-19T15:47:36.082Z,1652975256.082 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-19T15:48:01.109Z,1652975281.109 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-19T15:52:36.647Z,1652975556.647 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-19T15:52:36.647Z,1652975556.647 [Default:CheckIn:C.Wait] Stopped 2022-05-19T15:52:36.647Z,1652975556.647 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-19T15:52:36.647Z,1652975556.647 [Default:CheckIn:D] Running Loop=1 2022-05-19T15:52:37.051Z,1652975557.051 [Default:CheckIn:D] Stopped 2022-05-19T15:52:37.051Z,1652975557.051 [Default:CheckIn:E] Running Loop=1 2022-05-19T15:52:37.459Z,1652975557.459 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 72.491984 min 2022-05-19T15:52:37.459Z,1652975557.459 [Default:CheckIn:E] Stopped 2022-05-19T15:52:37.460Z,1652975557.460 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-19T15:52:37.460Z,1652975557.460 [Default:CheckIn] Stopped 2022-05-19T15:52:37.460Z,1652975557.460 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-19T15:52:37.460Z,1652975557.460 [Default:CheckIn](INFO): Running loop #12 2022-05-19T15:52:37.460Z,1652975557.460 [Default:CheckIn] Running Loop=12 2022-05-19T15:52:37.460Z,1652975557.460 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-19T15:52:37.460Z,1652975557.460 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-19T15:52:39.467Z,1652975559.467 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155238.00,A,3648.52736,N,12147.15018,W,3.130,105.66,190522,,,D*79 2022-05-19T15:52:39.469Z,1652975559.469 [NAL9602](INFO): GPS fix at 20220519T155238: (36.808789, -121.785836) 2022-05-19T15:52:39.499Z,1652975559.499 [Default:CheckIn:Read_GPS] Stopped 2022-05-19T15:52:39.499Z,1652975559.499 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-19T15:52:47.286Z,1652975567.286 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220519T144934/Courier0030.lzma 2022-05-19T15:52:48.282Z,1652975568.282 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Courier0030.lzma.bak 2022-05-19T15:52:48.283Z,1652975568.283 [DataOverHttps](INFO): SBD MOMSN=16808935 2022-05-19T15:53:06.720Z,1652975586.720 [DataOverHttps](INFO): Sending 143 bytes from file Logs/20220519T144934/Express0031.lzma 2022-05-19T15:53:06.991Z,1652975586.991 [NAL9602](INFO): SBD MO Status=0, MOMSN=33039, MT Status=0, MTMSN=0 2022-05-19T15:53:06.991Z,1652975586.991 [NAL9602](INFO): No messages in MT queue 2022-05-19T15:53:07.722Z,1652975587.722 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Express0031.lzma.bak 2022-05-19T15:53:07.722Z,1652975587.722 [DataOverHttps](INFO): SBD MOMSN=16808942 2022-05-19T15:53:09.013Z,1652975589.013 [Default:CheckIn:Read_Iridium] Stopped 2022-05-19T15:53:09.013Z,1652975589.013 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-19T15:53:09.013Z,1652975589.013 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-19T15:53:37.693Z,1652975617.693 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-19T15:58:09.614Z,1652975889.614 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-19T15:58:09.614Z,1652975889.614 [Default:CheckIn:C.Wait] Stopped 2022-05-19T15:58:09.614Z,1652975889.614 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-19T15:58:09.614Z,1652975889.614 [Default:CheckIn:D] Running Loop=1 2022-05-19T15:58:10.022Z,1652975890.022 [Default:CheckIn:D] Stopped 2022-05-19T15:58:10.022Z,1652975890.022 [Default:CheckIn:E] Running Loop=1 2022-05-19T15:58:10.435Z,1652975890.435 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 78.041504 min 2022-05-19T15:58:10.435Z,1652975890.435 [Default:CheckIn:E] Stopped 2022-05-19T15:58:10.435Z,1652975890.435 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-19T15:58:10.435Z,1652975890.435 [Default:CheckIn] Stopped 2022-05-19T15:58:10.435Z,1652975890.435 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-19T15:58:10.435Z,1652975890.435 [Default:CheckIn](INFO): Running loop #13 2022-05-19T15:58:10.435Z,1652975890.435 [Default:CheckIn] Running Loop=13 2022-05-19T15:58:10.435Z,1652975890.435 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-19T15:58:10.435Z,1652975890.435 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-19T15:58:12.439Z,1652975892.439 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155811.00,A,3648.27578,N,12147.13035,W,3.324,189.18,190522,,,A*74 2022-05-19T15:58:12.442Z,1652975892.442 [NAL9602](INFO): GPS fix at 20220519T155811: (36.804596, -121.785506) 2022-05-19T15:58:12.452Z,1652975892.452 [Default:CheckIn:Read_GPS] Stopped 2022-05-19T15:58:12.452Z,1652975892.452 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-19T15:58:20.532Z,1652975900.532 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220519T144934/Courier0033.lzma 2022-05-19T15:58:21.534Z,1652975901.534 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Courier0033.lzma.bak 2022-05-19T15:58:21.535Z,1652975901.535 [DataOverHttps](INFO): SBD MOMSN=16808953 2022-05-19T15:58:26.199Z,1652975906.199 [NAL9602](INFO): SBD MO Status=0, MOMSN=33040, MT Status=0, MTMSN=0 2022-05-19T15:58:26.199Z,1652975906.199 [NAL9602](INFO): No messages in MT queue 2022-05-19T15:58:39.401Z,1652975919.401 [DataOverHttps](INFO): Sending 142 bytes from file Logs/20220519T144934/Express0034.lzma 2022-05-19T15:58:40.402Z,1652975920.402 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Express0034.lzma.bak 2022-05-19T15:58:40.402Z,1652975920.402 [DataOverHttps](INFO): SBD MOMSN=16808956 2022-05-19T15:58:41.932Z,1652975921.932 [Default:CheckIn:Read_Iridium] Stopped 2022-05-19T15:58:41.933Z,1652975921.932 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-19T15:58:41.933Z,1652975921.933 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-19T15:58:56.877Z,1652975936.877 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-19T16:03:42.656Z,1652976222.656 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-19T16:03:42.656Z,1652976222.656 [Default:CheckIn:C.Wait] Stopped 2022-05-19T16:03:42.656Z,1652976222.656 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-19T16:03:42.657Z,1652976222.657 [Default:CheckIn:D] Running Loop=1 2022-05-19T16:03:43.067Z,1652976223.067 [Default:CheckIn:D] Stopped 2022-05-19T16:03:43.067Z,1652976223.067 [Default:CheckIn:E] Running Loop=1 2022-05-19T16:03:43.471Z,1652976223.471 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 83.592253 min 2022-05-19T16:03:43.471Z,1652976223.471 [Default:CheckIn:E] Stopped 2022-05-19T16:03:43.472Z,1652976223.472 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-19T16:03:43.472Z,1652976223.472 [Default:CheckIn] Stopped 2022-05-19T16:03:43.472Z,1652976223.472 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-19T16:03:43.472Z,1652976223.472 [Default:CheckIn](INFO): Running loop #14 2022-05-19T16:03:43.472Z,1652976223.472 [Default:CheckIn] Running Loop=14 2022-05-19T16:03:43.472Z,1652976223.472 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-19T16:03:43.472Z,1652976223.472 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-19T16:03:45.480Z,1652976225.480 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160344.00,A,3648.13426,N,12147.20777,W,0.447,231.76,190522,,,A*7C 2022-05-19T16:03:45.482Z,1652976225.482 [NAL9602](INFO): GPS fix at 20220519T160344: (36.802238, -121.786796) 2022-05-19T16:03:45.493Z,1652976225.493 [Default:CheckIn:Read_GPS] Stopped 2022-05-19T16:03:45.493Z,1652976225.493 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-19T16:03:53.548Z,1652976233.548 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20220519T144934/Courier0036.lzma 2022-05-19T16:03:54.550Z,1652976234.550 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Courier0036.lzma.bak 2022-05-19T16:03:54.550Z,1652976234.550 [DataOverHttps](INFO): SBD MOMSN=16808966 2022-05-19T16:04:10.452Z,1652976250.452 [DataOverHttps](INFO): Sending 144 bytes from file Logs/20220519T144934/Express0037.lzma 2022-05-19T16:04:10.531Z,1652976250.531 [NAL9602](INFO): SBD MO Status=2, MOMSN=33041, MT Status=2, MTMSN=0 2022-05-19T16:04:10.531Z,1652976250.531 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-05-19T16:04:11.455Z,1652976251.455 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Express0037.lzma.bak 2022-05-19T16:04:11.455Z,1652976251.455 [DataOverHttps](INFO): SBD MOMSN=16808969 2022-05-19T16:04:12.959Z,1652976252.959 [Default:CheckIn:Read_Iridium] Stopped 2022-05-19T16:04:12.959Z,1652976252.959 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-19T16:04:12.960Z,1652976252.960 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-19T16:04:36.405Z,1652976276.405 [NAL9602](INFO): SBD MO Status=2, MOMSN=33041, MT Status=2, MTMSN=0 2022-05-19T16:04:36.405Z,1652976276.405 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-05-19T16:04:46.499Z,1652976286.499 [NAL9602](INFO): SBD MO Status=0, MOMSN=33041, MT Status=0, MTMSN=0 2022-05-19T16:04:46.499Z,1652976286.499 [NAL9602](INFO): No messages in MT queue 2022-05-19T16:05:17.220Z,1652976317.220 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-19T16:09:13.395Z,1652976553.395 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-19T16:09:13.395Z,1652976553.395 [Default:CheckIn:C.Wait] Stopped 2022-05-19T16:09:13.395Z,1652976553.395 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-19T16:09:13.396Z,1652976553.396 [Default:CheckIn:D] Running Loop=1 2022-05-19T16:09:13.798Z,1652976553.798 [Default:CheckIn:D] Stopped 2022-05-19T16:09:13.798Z,1652976553.798 [Default:CheckIn:E] Running Loop=1 2022-05-19T16:09:14.199Z,1652976554.199 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 89.104435 min 2022-05-19T16:09:14.200Z,1652976554.200 [Default:CheckIn:E] Stopped 2022-05-19T16:09:14.200Z,1652976554.200 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-19T16:09:14.200Z,1652976554.200 [Default:CheckIn] Stopped 2022-05-19T16:09:14.200Z,1652976554.200 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-19T16:09:14.200Z,1652976554.200 [Default:CheckIn](INFO): Running loop #15 2022-05-19T16:09:14.200Z,1652976554.200 [Default:CheckIn] Running Loop=15 2022-05-19T16:09:14.200Z,1652976554.200 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-19T16:09:14.201Z,1652976554.201 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-19T16:09:16.212Z,1652976556.212 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160915.00,A,3648.13255,N,12147.20606,W,0.156,292.57,190522,,,A*78 2022-05-19T16:09:16.217Z,1652976556.217 [NAL9602](INFO): GPS fix at 20220519T160915: (36.802209, -121.786768) 2022-05-19T16:09:16.227Z,1652976556.227 [Default:CheckIn:Read_GPS] Stopped 2022-05-19T16:09:16.227Z,1652976556.227 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-19T16:09:23.388Z,1652976563.388 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220519T144934/Courier0039.lzma 2022-05-19T16:09:24.390Z,1652976564.390 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Courier0039.lzma.bak 2022-05-19T16:09:24.390Z,1652976564.390 [DataOverHttps](INFO): SBD MOMSN=16808979 2022-05-19T16:09:38.835Z,1652976578.835 [NAL9602](INFO): SBD MO Status=2, MOMSN=33042, MT Status=2, MTMSN=0 2022-05-19T16:09:38.835Z,1652976578.835 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-05-19T16:09:40.144Z,1652976580.144 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20220519T144934/Express0040.lzma 2022-05-19T16:09:41.146Z,1652976581.146 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Express0040.lzma.bak 2022-05-19T16:09:41.147Z,1652976581.147 [DataOverHttps](INFO): SBD MOMSN=16808982 2022-05-19T16:09:42.489Z,1652976582.489 [Default:CheckIn:Read_Iridium] Stopped 2022-05-19T16:09:42.489Z,1652976582.489 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-19T16:09:42.489Z,1652976582.489 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-19T16:10:43.495Z,1652976643.495 [NAL9602](INFO): SBD MO Status=0, MOMSN=33042, MT Status=0, MTMSN=0 2022-05-19T16:10:43.495Z,1652976643.495 [NAL9602](INFO): No messages in MT queue 2022-05-19T16:11:14.233Z,1652976674.233 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-19T16:14:42.887Z,1652976882.887 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-19T16:14:42.887Z,1652976882.887 [Default:CheckIn:C.Wait] Stopped 2022-05-19T16:14:42.887Z,1652976882.887 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-19T16:14:42.888Z,1652976882.888 [Default:CheckIn:D] Running Loop=1 2022-05-19T16:14:43.301Z,1652976883.301 [Default:CheckIn:D] Stopped 2022-05-19T16:14:43.302Z,1652976883.302 [Default:CheckIn:E] Running Loop=1 2022-05-19T16:14:43.699Z,1652976883.699 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 94.596167 min 2022-05-19T16:14:43.699Z,1652976883.699 [Default:CheckIn:E] Stopped 2022-05-19T16:14:43.699Z,1652976883.699 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-19T16:14:43.700Z,1652976883.700 [Default:CheckIn] Stopped 2022-05-19T16:14:43.700Z,1652976883.700 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-19T16:14:43.700Z,1652976883.700 [Default:CheckIn](INFO): Running loop #16 2022-05-19T16:14:43.700Z,1652976883.700 [Default:CheckIn] Running Loop=16 2022-05-19T16:14:43.700Z,1652976883.700 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-19T16:14:43.700Z,1652976883.700 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-19T16:14:45.717Z,1652976885.717 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,161445.00,A,3648.13669,N,12147.20604,W,0.311,292.57,190522,,,A*79 2022-05-19T16:14:45.719Z,1652976885.719 [NAL9602](INFO): GPS fix at 20220519T161445: (36.802278, -121.786767) 2022-05-19T16:14:45.730Z,1652976885.730 [Default:CheckIn:Read_GPS] Stopped 2022-05-19T16:14:45.730Z,1652976885.730 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-19T16:14:55.409Z,1652976895.409 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220519T144934/Courier0042.lzma 2022-05-19T16:14:56.410Z,1652976896.410 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Courier0042.lzma.bak 2022-05-19T16:14:56.411Z,1652976896.411 [DataOverHttps](INFO): SBD MOMSN=16808997 2022-05-19T16:15:08.395Z,1652976908.395 [NAL9602](INFO): SBD MO Status=0, MOMSN=33043, MT Status=0, MTMSN=0 2022-05-19T16:15:08.395Z,1652976908.395 [NAL9602](INFO): No messages in MT queue 2022-05-19T16:15:12.322Z,1652976912.322 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20220519T144934/Express0043.lzma 2022-05-19T16:15:13.322Z,1652976913.322 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Express0043.lzma.bak 2022-05-19T16:15:13.323Z,1652976913.323 [DataOverHttps](INFO): SBD MOMSN=16809000 2022-05-19T16:15:14.467Z,1652976914.467 [Default:CheckIn:Read_Iridium] Stopped 2022-05-19T16:15:14.467Z,1652976914.467 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-19T16:15:14.467Z,1652976914.467 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-19T16:15:39.097Z,1652976939.097 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-19T16:20:14.890Z,1652977214.890 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-19T16:20:14.890Z,1652977214.890 [Default:CheckIn:C.Wait] Stopped 2022-05-19T16:20:14.890Z,1652977214.890 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-19T16:20:14.890Z,1652977214.890 [Default:CheckIn:D] Running Loop=1 2022-05-19T16:20:15.270Z,1652977215.270 [Default:CheckIn:D] Stopped 2022-05-19T16:20:15.270Z,1652977215.270 [Default:CheckIn:E] Running Loop=1 2022-05-19T16:20:15.681Z,1652977215.681 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 100.128963 min 2022-05-19T16:20:15.681Z,1652977215.681 [Default:CheckIn:E] Stopped 2022-05-19T16:20:15.681Z,1652977215.681 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-19T16:20:15.681Z,1652977215.681 [Default:CheckIn] Stopped 2022-05-19T16:20:15.681Z,1652977215.681 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-19T16:20:15.681Z,1652977215.681 [Default:CheckIn](INFO): Running loop #17 2022-05-19T16:20:15.681Z,1652977215.681 [Default:CheckIn] Running Loop=17 2022-05-19T16:20:15.682Z,1652977215.682 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-19T16:20:15.682Z,1652977215.682 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-19T16:20:17.686Z,1652977217.686 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162016.00,A,3648.13338,N,12147.21133,W,0.019,186.34,190522,,,A*73 2022-05-19T16:20:17.688Z,1652977217.688 [NAL9602](INFO): GPS fix at 20220519T162016: (36.802223, -121.786856) 2022-05-19T16:20:17.718Z,1652977217.718 [Default:CheckIn:Read_GPS] Stopped 2022-05-19T16:20:17.719Z,1652977217.719 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-19T16:20:28.360Z,1652977228.360 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20220519T144934/Courier0045.lzma 2022-05-19T16:20:29.362Z,1652977229.362 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Courier0045.lzma.bak 2022-05-19T16:20:29.363Z,1652977229.363 [DataOverHttps](INFO): SBD MOMSN=16809011 2022-05-19T16:20:45.144Z,1652977245.144 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20220519T144934/Express0046.lzma 2022-05-19T16:20:46.146Z,1652977246.146 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Express0046.lzma.bak 2022-05-19T16:20:46.147Z,1652977246.147 [DataOverHttps](INFO): SBD MOMSN=16809014 2022-05-19T16:20:47.649Z,1652977247.649 [Default:CheckIn:Read_Iridium] Stopped 2022-05-19T16:20:47.649Z,1652977247.649 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-19T16:20:47.649Z,1652977247.649 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-19T16:22:52.615Z,1652977372.615 [NAL9602](INFO): SBD MO Status=2, MOMSN=33044, MT Status=2, MTMSN=0 2022-05-19T16:22:52.615Z,1652977372.615 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-05-19T16:23:05.571Z,1652977385.571 [NAL9602](INFO): SBD MO Status=2, MOMSN=33044, MT Status=2, MTMSN=0 2022-05-19T16:23:05.571Z,1652977385.571 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-05-19T16:23:29.811Z,1652977409.811 [NAL9602](INFO): SBD MO Status=0, MOMSN=33044, MT Status=0, MTMSN=0 2022-05-19T16:23:29.811Z,1652977409.811 [NAL9602](INFO): No messages in MT queue 2022-05-19T16:24:00.511Z,1652977440.511 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-19T16:25:48.424Z,1652977548.424 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-19T16:25:48.424Z,1652977548.424 [Default:CheckIn:C.Wait] Stopped 2022-05-19T16:25:48.424Z,1652977548.424 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-19T16:25:48.425Z,1652977548.425 [Default:CheckIn:D] Running Loop=1 2022-05-19T16:25:48.830Z,1652977548.830 [Default:CheckIn:D] Stopped 2022-05-19T16:25:48.830Z,1652977548.830 [Default:CheckIn:E] Running Loop=1 2022-05-19T16:25:49.248Z,1652977549.248 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 105.688306 min 2022-05-19T16:25:49.248Z,1652977549.248 [Default:CheckIn:E] Stopped 2022-05-19T16:25:49.249Z,1652977549.249 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-19T16:25:49.249Z,1652977549.249 [Default:CheckIn] Stopped 2022-05-19T16:25:49.249Z,1652977549.249 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-19T16:25:49.249Z,1652977549.249 [Default:CheckIn](INFO): Running loop #18 2022-05-19T16:25:49.249Z,1652977549.249 [Default:CheckIn] Running Loop=18 2022-05-19T16:25:49.249Z,1652977549.249 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-19T16:25:49.249Z,1652977549.249 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-19T16:25:51.248Z,1652977551.248 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162550.00,A,3648.13513,N,12147.22160,W,2.410,277.41,190522,,,D*7B 2022-05-19T16:25:51.251Z,1652977551.251 [NAL9602](INFO): GPS fix at 20220519T162550: (36.802252, -121.787027) 2022-05-19T16:25:51.261Z,1652977551.261 [Default:CheckIn:Read_GPS] Stopped 2022-05-19T16:25:51.261Z,1652977551.261 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-19T16:25:57.804Z,1652977557.804 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220519T144934/Courier0048.lzma 2022-05-19T16:25:58.806Z,1652977558.806 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Courier0048.lzma.bak 2022-05-19T16:25:58.807Z,1652977558.807 [DataOverHttps](INFO): SBD MOMSN=16809024 2022-05-19T16:26:05.387Z,1652977565.387 [NAL9602](INFO): SBD MO Status=0, MOMSN=33045, MT Status=0, MTMSN=0 2022-05-19T16:26:05.387Z,1652977565.387 [NAL9602](INFO): No messages in MT queue 2022-05-19T16:26:14.604Z,1652977574.604 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20220519T144934/Express0049.lzma 2022-05-19T16:26:15.606Z,1652977575.606 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Express0049.lzma.bak 2022-05-19T16:26:15.607Z,1652977575.607 [DataOverHttps](INFO): SBD MOMSN=16809028 2022-05-19T16:26:17.141Z,1652977577.141 [Default:CheckIn:Read_Iridium] Stopped 2022-05-19T16:26:17.141Z,1652977577.141 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-19T16:26:17.141Z,1652977577.141 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-19T16:26:36.143Z,1652977596.143 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-19T16:31:17.529Z,1652977877.529 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-19T16:31:17.529Z,1652977877.529 [Default:CheckIn:C.Wait] Stopped 2022-05-19T16:31:17.529Z,1652977877.529 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-19T16:31:17.529Z,1652977877.529 [Default:CheckIn:D] Running Loop=1 2022-05-19T16:31:17.941Z,1652977877.941 [Default:CheckIn:D] Stopped 2022-05-19T16:31:17.941Z,1652977877.941 [Default:CheckIn:E] Running Loop=1 2022-05-19T16:31:18.347Z,1652977878.347 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 111.173486 min 2022-05-19T16:31:18.347Z,1652977878.347 [Default:CheckIn:E] Stopped 2022-05-19T16:31:18.347Z,1652977878.347 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-19T16:31:18.347Z,1652977878.347 [Default:CheckIn] Stopped 2022-05-19T16:31:18.347Z,1652977878.347 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-19T16:31:18.347Z,1652977878.347 [Default:CheckIn](INFO): Running loop #19 2022-05-19T16:31:18.347Z,1652977878.347 [Default:CheckIn] Running Loop=19 2022-05-19T16:31:18.347Z,1652977878.347 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-19T16:31:18.347Z,1652977878.347 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-19T16:31:20.355Z,1652977880.355 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163119.00,A,3648.19504,N,12147.28127,W,0.505,273.71,190522,,,D*76 2022-05-19T16:31:20.369Z,1652977880.369 [NAL9602](INFO): GPS fix at 20220519T163119: (36.803251, -121.788021) 2022-05-19T16:31:20.379Z,1652977880.379 [Default:CheckIn:Read_GPS] Stopped 2022-05-19T16:31:20.379Z,1652977880.379 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-19T16:31:27.592Z,1652977887.592 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220519T144934/Courier0051.lzma 2022-05-19T16:31:28.594Z,1652977888.594 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Courier0051.lzma.bak 2022-05-19T16:31:28.595Z,1652977888.595 [DataOverHttps](INFO): SBD MOMSN=16809040 2022-05-19T16:31:44.476Z,1652977904.476 [DataOverHttps](INFO): Sending 144 bytes from file Logs/20220519T144934/Express0052.lzma 2022-05-19T16:31:45.478Z,1652977905.478 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Express0052.lzma.bak 2022-05-19T16:31:45.479Z,1652977905.479 [DataOverHttps](INFO): SBD MOMSN=16809043 2022-05-19T16:31:46.649Z,1652977906.649 [Default:CheckIn:Read_Iridium] Stopped 2022-05-19T16:31:46.649Z,1652977906.649 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-19T16:31:46.649Z,1652977906.649 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-19T16:35:57.311Z,1652978157.311 [NAL9602](INFO): SBD MO Status=2, MOMSN=33046, MT Status=2, MTMSN=0 2022-05-19T16:35:57.311Z,1652978157.311 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-05-19T16:36:22.790Z,1652978182.790 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-05-19T16:36:47.074Z,1652978207.074 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-19T16:36:47.074Z,1652978207.074 [Default:CheckIn:C.Wait] Stopped 2022-05-19T16:36:47.074Z,1652978207.074 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-19T16:36:47.074Z,1652978207.074 [Default:CheckIn:D] Running Loop=1 2022-05-19T16:36:47.498Z,1652978207.498 [Default:CheckIn:D] Stopped 2022-05-19T16:36:47.498Z,1652978207.498 [Default:CheckIn:E] Running Loop=1 2022-05-19T16:36:47.900Z,1652978207.900 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 116.666105 min 2022-05-19T16:36:47.900Z,1652978207.900 [Default:CheckIn:E] Stopped 2022-05-19T16:36:47.900Z,1652978207.900 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-19T16:36:47.900Z,1652978207.900 [Default:CheckIn] Stopped 2022-05-19T16:36:47.900Z,1652978207.900 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-19T16:36:47.900Z,1652978207.900 [Default:CheckIn](INFO): Running loop #20 2022-05-19T16:36:47.901Z,1652978207.901 [Default:CheckIn] Running Loop=20 2022-05-19T16:36:47.901Z,1652978207.901 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-19T16:36:47.901Z,1652978207.901 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-19T16:36:49.895Z,1652978209.895 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163649.00,A,3648.18176,N,12147.27743,W,0.233,222.33,190522,,,A*7A 2022-05-19T16:36:49.898Z,1652978209.898 [NAL9602](INFO): GPS fix at 20220519T163649: (36.803029, -121.787957) 2022-05-19T16:36:49.933Z,1652978209.933 [Default:CheckIn:Read_GPS] Stopped 2022-05-19T16:36:49.933Z,1652978209.933 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-19T16:36:59.468Z,1652978219.468 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220519T144934/Courier0054.lzma 2022-05-19T16:37:00.470Z,1652978220.470 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Courier0054.lzma.bak 2022-05-19T16:37:00.471Z,1652978220.471 [DataOverHttps](INFO): SBD MOMSN=16809054 2022-05-19T16:37:16.165Z,1652978236.165 [DataOverHttps](INFO): Sending 240 bytes from file Logs/20220519T144934/Express0055.lzma 2022-05-19T16:37:17.166Z,1652978237.166 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Express0055.lzma.bak 2022-05-19T16:37:17.167Z,1652978237.167 [DataOverHttps](INFO): SBD MOMSN=16809057 2022-05-19T16:37:18.661Z,1652978238.661 [Default:CheckIn:Read_Iridium] Stopped 2022-05-19T16:37:18.661Z,1652978238.661 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-19T16:37:18.661Z,1652978238.661 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-19T16:37:22.681Z,1652978242.681 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-19T16:42:19.334Z,1652978539.334 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-19T16:42:19.334Z,1652978539.334 [Default:CheckIn:C.Wait] Stopped 2022-05-19T16:42:19.334Z,1652978539.334 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-19T16:42:19.334Z,1652978539.334 [Default:CheckIn:D] Running Loop=1 2022-05-19T16:42:19.754Z,1652978539.754 [Default:CheckIn:D] Stopped 2022-05-19T16:42:19.754Z,1652978539.754 [Default:CheckIn:E] Running Loop=1 2022-05-19T16:42:20.175Z,1652978540.175 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 122.203703 min 2022-05-19T16:42:20.175Z,1652978540.175 [Default:CheckIn:E] Stopped 2022-05-19T16:42:20.175Z,1652978540.175 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-19T16:42:20.175Z,1652978540.175 [Default:CheckIn] Stopped 2022-05-19T16:42:20.175Z,1652978540.175 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-19T16:42:20.175Z,1652978540.175 [Default:CheckIn](INFO): Running loop #21 2022-05-19T16:42:20.175Z,1652978540.175 [Default:CheckIn] Running Loop=21 2022-05-19T16:42:20.175Z,1652978540.175 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-19T16:42:20.175Z,1652978540.175 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-19T16:42:22.183Z,1652978542.183 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164221.00,A,3648.18088,N,12147.27591,W,0.505,222.33,190522,,,A*78 2022-05-19T16:42:22.186Z,1652978542.186 [NAL9602](INFO): GPS fix at 20220519T164221: (36.803015, -121.787932) 2022-05-19T16:42:22.196Z,1652978542.196 [Default:CheckIn:Read_GPS] Stopped 2022-05-19T16:42:22.196Z,1652978542.196 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-19T16:42:31.060Z,1652978551.060 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220519T144934/Courier0057.lzma 2022-05-19T16:42:32.062Z,1652978552.062 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Courier0057.lzma.bak 2022-05-19T16:42:32.062Z,1652978552.062 [DataOverHttps](INFO): SBD MOMSN=16809070 2022-05-19T16:42:47.869Z,1652978567.869 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20220519T144934/Express0058.lzma 2022-05-19T16:42:48.870Z,1652978568.870 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Express0058.lzma.bak 2022-05-19T16:42:48.871Z,1652978568.871 [DataOverHttps](INFO): SBD MOMSN=16809074 2022-05-19T16:42:50.385Z,1652978570.385 [Default:CheckIn:Read_Iridium] Stopped 2022-05-19T16:42:50.386Z,1652978570.386 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-19T16:42:50.386Z,1652978570.386 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-19T16:44:50.232Z,1652978690.232 [NAL9602](INFO): SBD MO Status=2, MOMSN=33046, MT Status=2, MTMSN=0 2022-05-19T16:44:50.232Z,1652978690.232 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-05-19T16:46:19.107Z,1652978779.107 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-05-19T16:46:34.461Z,1652978794.461 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-05-19T16:46:49.407Z,1652978809.407 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-05-19T16:46:52.643Z,1652978812.643 [NAL9602](INFO): SBD MO Status=2, MOMSN=33046, MT Status=2, MTMSN=0 2022-05-19T16:46:52.643Z,1652978812.643 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-05-19T16:47:04.758Z,1652978824.758 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-05-19T16:47:20.110Z,1652978840.110 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-05-19T16:47:25.029Z,1652978845.029 [NAL9602](INFO): SBD MO Status=0, MOMSN=33046, MT Status=0, MTMSN=0 2022-05-19T16:47:25.029Z,1652978845.029 [NAL9602](INFO): No messages in MT queue 2022-05-19T16:47:35.867Z,1652978855.867 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-05-19T16:47:50.874Z,1652978870.874 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-19T16:47:50.874Z,1652978870.874 [Default:CheckIn:C.Wait] Stopped 2022-05-19T16:47:50.874Z,1652978870.874 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-19T16:47:50.875Z,1652978870.875 [Default:CheckIn:D] Running Loop=1 2022-05-19T16:47:51.218Z,1652978871.218 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-05-19T16:47:51.251Z,1652978871.251 [Default:CheckIn:D] Stopped 2022-05-19T16:47:51.251Z,1652978871.251 [Default:CheckIn:E] Running Loop=1 2022-05-19T16:47:51.657Z,1652978871.657 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 127.728654 min 2022-05-19T16:47:51.658Z,1652978871.658 [Default:CheckIn:E] Stopped 2022-05-19T16:47:51.658Z,1652978871.658 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-19T16:47:51.658Z,1652978871.658 [Default:CheckIn] Stopped 2022-05-19T16:47:51.658Z,1652978871.658 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-19T16:47:51.658Z,1652978871.658 [Default:CheckIn](INFO): Running loop #22 2022-05-19T16:47:51.658Z,1652978871.658 [Default:CheckIn] Running Loop=22 2022-05-19T16:47:51.658Z,1652978871.658 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-19T16:47:51.658Z,1652978871.658 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-19T16:47:53.655Z,1652978873.655 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164752.00,A,3648.18828,N,12147.27251,W,0.136,359.02,190522,,,A*7B 2022-05-19T16:47:53.657Z,1652978873.657 [NAL9602](INFO): GPS fix at 20220519T164752: (36.803138, -121.787875) 2022-05-19T16:47:53.668Z,1652978873.668 [Default:CheckIn:Read_GPS] Stopped 2022-05-19T16:47:53.668Z,1652978873.668 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-19T16:48:00.816Z,1652978880.816 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20220519T144934/Courier0060.lzma 2022-05-19T16:48:01.818Z,1652978881.818 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Courier0060.lzma.bak 2022-05-19T16:48:01.819Z,1652978881.819 [DataOverHttps](INFO): SBD MOMSN=16809108 2022-05-19T16:48:07.378Z,1652978887.378 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-05-19T16:48:19.069Z,1652978899.069 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20220519T144934/Express0061.lzma 2022-05-19T16:48:20.071Z,1652978900.071 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Express0061.lzma.bak 2022-05-19T16:48:20.071Z,1652978900.071 [DataOverHttps](INFO): SBD MOMSN=16809111 2022-05-19T16:48:21.545Z,1652978901.545 [Default:CheckIn:Read_Iridium] Stopped 2022-05-19T16:48:21.545Z,1652978901.545 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-19T16:48:21.545Z,1652978901.545 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-19T16:48:22.326Z,1652978902.326 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-05-19T16:48:26.409Z,1652978906.409 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-19T16:48:45.404Z,1652978925.404 [BPC1](INFO): Calculating totals. Valid battery stick count: 54. Valid reserve battery stick count: 6. 2022-05-19T16:48:45.406Z,1652978925.406 [BPC1](INFO): Received data from all battery sticks. 2022-05-19T16:53:22.177Z,1652979202.177 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-19T16:53:22.177Z,1652979202.177 [Default:CheckIn:C.Wait] Stopped 2022-05-19T16:53:22.177Z,1652979202.177 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-19T16:53:22.178Z,1652979202.178 [Default:CheckIn:D] Running Loop=1 2022-05-19T16:53:22.583Z,1652979202.583 [Default:CheckIn:D] Stopped 2022-05-19T16:53:22.583Z,1652979202.583 [Default:CheckIn:E] Running Loop=1 2022-05-19T16:53:22.993Z,1652979202.993 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 133.250863 min 2022-05-19T16:53:22.993Z,1652979202.993 [Default:CheckIn:E] Stopped 2022-05-19T16:53:22.993Z,1652979202.993 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-19T16:53:22.993Z,1652979202.993 [Default:CheckIn] Stopped 2022-05-19T16:53:22.993Z,1652979202.993 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-19T16:53:22.993Z,1652979202.993 [Default:CheckIn](INFO): Running loop #23 2022-05-19T16:53:22.993Z,1652979202.993 [Default:CheckIn] Running Loop=23 2022-05-19T16:53:22.993Z,1652979202.993 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-19T16:53:22.993Z,1652979202.993 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-19T16:53:24.995Z,1652979204.995 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165324.00,A,3648.17939,N,12147.27694,W,0.078,359.02,190522,,,A*77 2022-05-19T16:53:24.998Z,1652979204.998 [NAL9602](INFO): GPS fix at 20220519T165324: (36.802990, -121.787949) 2022-05-19T16:53:25.007Z,1652979205.007 [Default:CheckIn:Read_GPS] Stopped 2022-05-19T16:53:25.008Z,1652979205.008 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-19T16:53:32.228Z,1652979212.228 [DataOverHttps](INFO): Sending 84 bytes from file Logs/20220519T144934/Courier0063.lzma 2022-05-19T16:53:33.230Z,1652979213.230 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Courier0063.lzma.bak 2022-05-19T16:53:33.231Z,1652979213.231 [DataOverHttps](INFO): SBD MOMSN=16809131 2022-05-19T16:53:49.176Z,1652979229.176 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20220519T144934/Express0064.lzma 2022-05-19T16:53:50.178Z,1652979230.178 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Express0064.lzma.bak 2022-05-19T16:53:50.179Z,1652979230.179 [DataOverHttps](INFO): SBD MOMSN=16809134 2022-05-19T16:53:51.680Z,1652979231.680 [Default:CheckIn:Read_Iridium] Stopped 2022-05-19T16:53:51.680Z,1652979231.680 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-19T16:53:51.680Z,1652979231.680 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-19T16:54:05.795Z,1652979245.795 [NAL9602](INFO): SBD MO Status=2, MOMSN=33047, MT Status=2, MTMSN=0 2022-05-19T16:54:05.795Z,1652979245.795 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-05-19T16:56:27.635Z,1652979387.635 [NAL9602](INFO): SBD MO Status=0, MOMSN=33047, MT Status=0, MTMSN=0 2022-05-19T16:56:27.635Z,1652979387.635 [NAL9602](INFO): No messages in MT queue 2022-05-19T16:56:58.337Z,1652979418.337 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-19T16:58:52.294Z,1652979532.294 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-19T16:58:52.294Z,1652979532.294 [Default:CheckIn:C.Wait] Stopped 2022-05-19T16:58:52.294Z,1652979532.294 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-19T16:58:52.294Z,1652979532.294 [Default:CheckIn:D] Running Loop=1 2022-05-19T16:58:52.712Z,1652979532.712 [Default:CheckIn:D] Stopped 2022-05-19T16:58:52.712Z,1652979532.712 [Default:CheckIn:E] Running Loop=1 2022-05-19T16:58:53.090Z,1652979533.090 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 138.753011 min 2022-05-19T16:58:53.090Z,1652979533.090 [Default:CheckIn:E] Stopped 2022-05-19T16:58:53.090Z,1652979533.090 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-19T16:58:53.090Z,1652979533.090 [Default:CheckIn] Stopped 2022-05-19T16:58:53.091Z,1652979533.091 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-19T16:58:53.091Z,1652979533.091 [Default:CheckIn](INFO): Running loop #24 2022-05-19T16:58:53.091Z,1652979533.091 [Default:CheckIn] Running Loop=24 2022-05-19T16:58:53.091Z,1652979533.091 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-19T16:58:53.091Z,1652979533.091 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-19T16:58:55.095Z,1652979535.095 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165854.00,A,3648.18655,N,12147.27623,W,0.253,359.02,190522,,,A*76 2022-05-19T16:58:55.098Z,1652979535.098 [NAL9602](INFO): GPS fix at 20220519T165854: (36.803109, -121.787937) 2022-05-19T16:58:55.116Z,1652979535.116 [Default:CheckIn:Read_GPS] Stopped 2022-05-19T16:58:55.116Z,1652979535.116 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-19T16:59:02.372Z,1652979542.372 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220519T144934/Courier0066.lzma 2022-05-19T16:59:03.375Z,1652979543.375 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Courier0066.lzma.bak 2022-05-19T16:59:03.375Z,1652979543.375 [DataOverHttps](INFO): SBD MOMSN=16809161 2022-05-19T16:59:19.644Z,1652979559.644 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20220519T144934/Express0067.lzma 2022-05-19T16:59:20.647Z,1652979560.647 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Express0067.lzma.bak 2022-05-19T16:59:20.647Z,1652979560.647 [DataOverHttps](INFO): SBD MOMSN=16809165 2022-05-19T16:59:21.893Z,1652979561.893 [Default:CheckIn:Read_Iridium] Stopped 2022-05-19T16:59:21.893Z,1652979561.893 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-19T16:59:21.893Z,1652979561.893 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-19T17:03:57.389Z,1652979837.389 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-05-19T17:04:22.441Z,1652979862.441 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-19T17:04:22.441Z,1652979862.441 [Default:CheckIn:C.Wait] Stopped 2022-05-19T17:04:22.441Z,1652979862.441 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-19T17:04:22.441Z,1652979862.441 [Default:CheckIn:D] Running Loop=1 2022-05-19T17:04:22.854Z,1652979862.854 [Default:CheckIn:D] Stopped 2022-05-19T17:04:22.854Z,1652979862.854 [Default:CheckIn:E] Running Loop=1 2022-05-19T17:04:23.273Z,1652979863.273 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 144.255371 min 2022-05-19T17:04:23.273Z,1652979863.273 [Default:CheckIn:E] Stopped 2022-05-19T17:04:23.273Z,1652979863.273 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-19T17:04:23.273Z,1652979863.273 [Default:CheckIn] Stopped 2022-05-19T17:04:23.273Z,1652979863.273 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-19T17:04:23.274Z,1652979863.274 [Default:CheckIn](INFO): Running loop #25 2022-05-19T17:04:23.274Z,1652979863.274 [Default:CheckIn] Running Loop=25 2022-05-19T17:04:23.274Z,1652979863.274 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-19T17:04:23.274Z,1652979863.274 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-19T17:04:25.276Z,1652979865.276 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170424.00,A,3648.17918,N,12147.26712,W,0.603,138.69,190522,,,A*7B 2022-05-19T17:04:25.278Z,1652979865.278 [NAL9602](INFO): GPS fix at 20220519T170424: (36.802986, -121.787785) 2022-05-19T17:04:25.344Z,1652979865.344 [Default:CheckIn:Read_GPS] Stopped 2022-05-19T17:04:25.344Z,1652979865.344 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-19T17:04:32.197Z,1652979872.197 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20220519T144934/Courier0069.lzma 2022-05-19T17:04:33.198Z,1652979873.198 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Courier0069.lzma.bak 2022-05-19T17:04:33.198Z,1652979873.198 [DataOverHttps](INFO): SBD MOMSN=16809192 2022-05-19T17:04:49.809Z,1652979889.809 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20220519T144934/Express0070.lzma 2022-05-19T17:04:50.810Z,1652979890.810 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Express0070.lzma.bak 2022-05-19T17:04:50.811Z,1652979890.811 [DataOverHttps](INFO): SBD MOMSN=16809195 2022-05-19T17:04:52.367Z,1652979892.367 [Default:CheckIn:Read_Iridium] Stopped 2022-05-19T17:04:52.367Z,1652979892.367 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-19T17:04:52.367Z,1652979892.367 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-19T17:04:57.621Z,1652979897.621 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-19T17:09:52.949Z,1652980192.949 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-19T17:09:52.949Z,1652980192.949 [Default:CheckIn:C.Wait] Stopped 2022-05-19T17:09:52.949Z,1652980192.949 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-19T17:09:52.949Z,1652980192.949 [Default:CheckIn:D] Running Loop=1 2022-05-19T17:09:53.353Z,1652980193.353 [Default:CheckIn:D] Stopped 2022-05-19T17:09:53.353Z,1652980193.353 [Default:CheckIn:E] Running Loop=1 2022-05-19T17:09:53.768Z,1652980193.768 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 149.763688 min 2022-05-19T17:09:53.768Z,1652980193.768 [Default:CheckIn:E] Stopped 2022-05-19T17:09:53.768Z,1652980193.768 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-19T17:09:53.769Z,1652980193.769 [Default:CheckIn] Stopped 2022-05-19T17:09:53.769Z,1652980193.769 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-19T17:09:53.769Z,1652980193.769 [Default:CheckIn](INFO): Running loop #26 2022-05-19T17:09:53.769Z,1652980193.769 [Default:CheckIn] Running Loop=26 2022-05-19T17:09:53.769Z,1652980193.769 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-19T17:09:53.769Z,1652980193.769 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-19T17:09:55.781Z,1652980195.781 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170955.00,A,3648.17682,N,12147.27577,W,0.428,119.66,190522,,,A*7B 2022-05-19T17:09:55.783Z,1652980195.783 [NAL9602](INFO): GPS fix at 20220519T170955: (36.802947, -121.787930) 2022-05-19T17:09:55.794Z,1652980195.794 [Default:CheckIn:Read_GPS] Stopped 2022-05-19T17:09:55.794Z,1652980195.794 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-19T17:10:03.596Z,1652980203.596 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220519T144934/Courier0072.lzma 2022-05-19T17:10:04.598Z,1652980204.598 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Courier0072.lzma.bak 2022-05-19T17:10:04.599Z,1652980204.599 [DataOverHttps](INFO): SBD MOMSN=16809247 2022-05-19T17:10:23.352Z,1652980223.352 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20220519T144934/Express0073.lzma 2022-05-19T17:10:24.355Z,1652980224.355 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Express0073.lzma.bak 2022-05-19T17:10:24.355Z,1652980224.355 [DataOverHttps](INFO): SBD MOMSN=16809250 2022-05-19T17:10:25.725Z,1652980225.725 [Default:CheckIn:Read_Iridium] Stopped 2022-05-19T17:10:25.725Z,1652980225.725 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-19T17:10:25.726Z,1652980225.726 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-19T17:10:26.507Z,1652980226.507 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-05-19T17:10:26.581Z,1652980226.581 [NAL9602](ERROR): received: +CSQ:0 OK047, 0, 0, 0, 0 OK 2022-05-19T17:14:43.863Z,1652980483.863 [NAL9602](INFO): SBD MO Status=0, MOMSN=33048, MT Status=0, MTMSN=0 2022-05-19T17:14:43.863Z,1652980483.863 [NAL9602](INFO): No messages in MT queue 2022-05-19T17:15:14.560Z,1652980514.560 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-19T17:15:26.292Z,1652980526.292 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-19T17:15:26.292Z,1652980526.292 [Default:CheckIn:C.Wait] Stopped 2022-05-19T17:15:26.292Z,1652980526.292 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-19T17:15:26.293Z,1652980526.293 [Default:CheckIn:D] Running Loop=1 2022-05-19T17:15:26.717Z,1652980526.717 [Default:CheckIn:D] Stopped 2022-05-19T17:15:26.717Z,1652980526.717 [Default:CheckIn:E] Running Loop=1 2022-05-19T17:15:27.093Z,1652980527.093 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 155.319743 min 2022-05-19T17:15:27.093Z,1652980527.093 [Default:CheckIn:E] Stopped 2022-05-19T17:15:27.093Z,1652980527.093 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-19T17:15:27.093Z,1652980527.093 [Default:CheckIn] Stopped 2022-05-19T17:15:27.093Z,1652980527.093 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-19T17:15:27.094Z,1652980527.094 [Default:CheckIn](INFO): Running loop #27 2022-05-19T17:15:27.094Z,1652980527.094 [Default:CheckIn] Running Loop=27 2022-05-19T17:15:27.094Z,1652980527.094 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-19T17:15:27.094Z,1652980527.094 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-19T17:15:29.108Z,1652980529.108 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171528.00,A,3648.18791,N,12147.27165,W,0.272,119.66,190522,,,A*7E 2022-05-19T17:15:29.110Z,1652980529.110 [NAL9602](INFO): GPS fix at 20220519T171528: (36.803132, -121.787861) 2022-05-19T17:15:29.121Z,1652980529.121 [Default:CheckIn:Read_GPS] Stopped 2022-05-19T17:15:29.121Z,1652980529.121 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-19T17:15:37.036Z,1652980537.036 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20220519T144934/Courier0075.lzma 2022-05-19T17:15:38.038Z,1652980538.038 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Courier0075.lzma.bak 2022-05-19T17:15:38.039Z,1652980538.039 [DataOverHttps](INFO): SBD MOMSN=16809356 2022-05-19T17:15:53.848Z,1652980553.848 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20220519T144934/Express0076.lzma 2022-05-19T17:15:54.851Z,1652980554.851 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Express0076.lzma.bak 2022-05-19T17:15:54.851Z,1652980554.851 [DataOverHttps](INFO): SBD MOMSN=16809359 2022-05-19T17:15:56.206Z,1652980556.206 [Default:CheckIn:Read_Iridium] Stopped 2022-05-19T17:15:56.206Z,1652980556.206 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-19T17:15:56.206Z,1652980556.206 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-19T17:20:31.326Z,1652980831.326 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-05-19T17:20:56.793Z,1652980856.793 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-19T17:20:56.793Z,1652980856.793 [Default:CheckIn:C.Wait] Stopped 2022-05-19T17:20:56.793Z,1652980856.793 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-19T17:20:56.793Z,1652980856.793 [Default:CheckIn:D] Running Loop=1 2022-05-19T17:20:57.207Z,1652980857.207 [Default:CheckIn:D] Stopped 2022-05-19T17:20:57.207Z,1652980857.207 [Default:CheckIn:E] Running Loop=1 2022-05-19T17:20:57.589Z,1652980857.589 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 160.827539 min 2022-05-19T17:20:57.589Z,1652980857.589 [Default:CheckIn:E] Stopped 2022-05-19T17:20:57.590Z,1652980857.590 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-19T17:20:57.590Z,1652980857.590 [Default:CheckIn] Stopped 2022-05-19T17:20:57.590Z,1652980857.590 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-19T17:20:57.590Z,1652980857.590 [Default:CheckIn](INFO): Running loop #28 2022-05-19T17:20:57.590Z,1652980857.590 [Default:CheckIn] Running Loop=28 2022-05-19T17:20:57.590Z,1652980857.590 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-19T17:20:57.590Z,1652980857.590 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-19T17:20:59.603Z,1652980859.603 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172058.00,A,3648.17756,N,12147.27693,W,0.039,86.68,190522,,,A*41 2022-05-19T17:20:59.606Z,1652980859.606 [NAL9602](INFO): GPS fix at 20220519T172058: (36.802959, -121.787949) 2022-05-19T17:20:59.638Z,1652980859.638 [Default:CheckIn:Read_GPS] Stopped 2022-05-19T17:20:59.638Z,1652980859.638 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-19T17:21:06.520Z,1652980866.520 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220519T144934/Courier0078.lzma 2022-05-19T17:21:07.522Z,1652980867.522 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Courier0078.lzma.bak 2022-05-19T17:21:07.523Z,1652980867.523 [DataOverHttps](INFO): SBD MOMSN=16809427 2022-05-19T17:21:23.305Z,1652980883.305 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20220519T144934/Express0079.lzma 2022-05-19T17:21:24.307Z,1652980884.307 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Express0079.lzma.bak 2022-05-19T17:21:24.307Z,1652980884.307 [DataOverHttps](INFO): SBD MOMSN=16809434 2022-05-19T17:21:25.953Z,1652980885.953 [Default:CheckIn:Read_Iridium] Stopped 2022-05-19T17:21:25.953Z,1652980885.953 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-19T17:21:25.953Z,1652980885.953 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-19T17:21:31.584Z,1652980891.584 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-19T17:26:26.532Z,1652981186.532 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-19T17:26:26.532Z,1652981186.532 [Default:CheckIn:C.Wait] Stopped 2022-05-19T17:26:26.532Z,1652981186.532 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-19T17:26:26.532Z,1652981186.532 [Default:CheckIn:D] Running Loop=1 2022-05-19T17:26:26.927Z,1652981186.927 [Default:CheckIn:D] Stopped 2022-05-19T17:26:26.927Z,1652981186.927 [Default:CheckIn:E] Running Loop=1 2022-05-19T17:26:27.325Z,1652981187.325 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 166.323242 min 2022-05-19T17:26:27.325Z,1652981187.325 [Default:CheckIn:E] Stopped 2022-05-19T17:26:27.326Z,1652981187.326 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-19T17:26:27.326Z,1652981187.326 [Default:CheckIn] Stopped 2022-05-19T17:26:27.326Z,1652981187.326 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-19T17:26:27.326Z,1652981187.326 [Default:CheckIn](INFO): Running loop #29 2022-05-19T17:26:27.326Z,1652981187.326 [Default:CheckIn] Running Loop=29 2022-05-19T17:26:27.326Z,1652981187.326 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-19T17:26:27.326Z,1652981187.326 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-19T17:26:29.339Z,1652981189.339 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172628.00,A,3648.18115,N,12147.27561,W,0.292,208.46,190522,,,A*7B 2022-05-19T17:26:29.341Z,1652981189.341 [NAL9602](INFO): GPS fix at 20220519T172628: (36.803019, -121.787927) 2022-05-19T17:26:29.373Z,1652981189.373 [Default:CheckIn:Read_GPS] Stopped 2022-05-19T17:26:29.373Z,1652981189.373 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-19T17:26:37.036Z,1652981197.036 [DataOverHttps](INFO): Sending 70 bytes from file Logs/20220519T144934/Courier0081.lzma 2022-05-19T17:26:38.038Z,1652981198.038 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Courier0081.lzma.bak 2022-05-19T17:26:38.039Z,1652981198.039 [DataOverHttps](INFO): SBD MOMSN=16809470 2022-05-19T17:26:57.164Z,1652981217.164 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20220519T144934/Express0082.lzma 2022-05-19T17:26:58.167Z,1652981218.167 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Express0082.lzma.bak 2022-05-19T17:26:58.167Z,1652981218.167 [DataOverHttps](INFO): SBD MOMSN=16809473 2022-05-19T17:26:59.705Z,1652981219.705 [Default:CheckIn:Read_Iridium] Stopped 2022-05-19T17:26:59.705Z,1652981219.705 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-19T17:26:59.705Z,1652981219.705 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-19T17:27:00.101Z,1652981220.101 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-05-19T17:27:00.184Z,1652981220.184 [NAL9602](ERROR): received: +CSQ:0 OK048, 0, 0, 0, 0 OK 2022-05-19T17:28:11.611Z,1652981291.611 [NAL9602](INFO): SBD MO Status=2, MOMSN=33049, MT Status=2, MTMSN=0 2022-05-19T17:28:11.611Z,1652981291.611 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-05-19T17:28:54.435Z,1652981334.435 [NAL9602](INFO): SBD MO Status=2, MOMSN=33049, MT Status=2, MTMSN=0 2022-05-19T17:28:54.435Z,1652981334.435 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-05-19T17:30:53.207Z,1652981453.207 [NAL9602](INFO): SBD MO Status=2, MOMSN=33049, MT Status=2, MTMSN=0 2022-05-19T17:30:53.207Z,1652981453.207 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-05-19T17:31:27.547Z,1652981487.547 [NAL9602](INFO): SBD MO Status=2, MOMSN=33049, MT Status=2, MTMSN=0 2022-05-19T17:31:27.547Z,1652981487.547 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-05-19T17:31:31.583Z,1652981491.583 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-05-19T17:32:00.278Z,1652981520.278 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-19T17:32:00.278Z,1652981520.278 [Default:CheckIn:C.Wait] Stopped 2022-05-19T17:32:00.278Z,1652981520.278 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-19T17:32:00.279Z,1652981520.279 [Default:CheckIn:D] Running Loop=1 2022-05-19T17:32:00.689Z,1652981520.689 [Default:CheckIn:D] Stopped 2022-05-19T17:32:00.689Z,1652981520.689 [Default:CheckIn:E] Running Loop=1 2022-05-19T17:32:01.106Z,1652981521.106 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 171.885954 min 2022-05-19T17:32:01.106Z,1652981521.106 [Default:CheckIn:E] Stopped 2022-05-19T17:32:01.106Z,1652981521.106 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-19T17:32:01.106Z,1652981521.106 [Default:CheckIn] Stopped 2022-05-19T17:32:01.106Z,1652981521.106 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-19T17:32:01.107Z,1652981521.107 [Default:CheckIn](INFO): Running loop #30 2022-05-19T17:32:01.107Z,1652981521.107 [Default:CheckIn] Running Loop=30 2022-05-19T17:32:01.107Z,1652981521.107 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-19T17:32:01.107Z,1652981521.107 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-19T17:32:03.098Z,1652981523.098 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173202.00,A,3648.18016,N,12147.27826,W,0.039,256.27,190522,,,A*75 2022-05-19T17:32:03.100Z,1652981523.100 [NAL9602](INFO): GPS fix at 20220519T173202: (36.803003, -121.787971) 2022-05-19T17:32:03.111Z,1652981523.111 [Default:CheckIn:Read_GPS] Stopped 2022-05-19T17:32:03.111Z,1652981523.111 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-19T17:32:09.932Z,1652981529.932 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220519T144934/Courier0084.lzma 2022-05-19T17:32:10.934Z,1652981530.934 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Courier0084.lzma.bak 2022-05-19T17:32:10.935Z,1652981530.935 [DataOverHttps](INFO): SBD MOMSN=16809485 2022-05-19T17:32:29.797Z,1652981549.797 [DataOverHttps](INFO): Sending 205 bytes from file Logs/20220519T144934/Express0085.lzma 2022-05-19T17:32:30.798Z,1652981550.798 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Express0085.lzma.bak 2022-05-19T17:32:30.799Z,1652981550.799 [DataOverHttps](INFO): SBD MOMSN=16809488 2022-05-19T17:32:32.249Z,1652981552.249 [Default:CheckIn:Read_Iridium] Stopped 2022-05-19T17:32:32.250Z,1652981552.250 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-19T17:32:32.250Z,1652981552.250 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-19T17:32:35.473Z,1652981555.473 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-19T17:37:32.825Z,1652981852.825 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-19T17:37:32.825Z,1652981852.825 [Default:CheckIn:C.Wait] Stopped 2022-05-19T17:37:32.825Z,1652981852.825 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-19T17:37:32.826Z,1652981852.826 [Default:CheckIn:D] Running Loop=1 2022-05-19T17:37:33.237Z,1652981853.237 [Default:CheckIn:D] Stopped 2022-05-19T17:37:33.238Z,1652981853.238 [Default:CheckIn:E] Running Loop=1 2022-05-19T17:37:33.633Z,1652981853.633 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 177.428434 min 2022-05-19T17:37:33.633Z,1652981853.633 [Default:CheckIn:E] Stopped 2022-05-19T17:37:33.633Z,1652981853.633 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-19T17:37:33.633Z,1652981853.633 [Default:CheckIn] Stopped 2022-05-19T17:37:33.633Z,1652981853.633 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-19T17:37:33.633Z,1652981853.633 [Default:CheckIn](INFO): Running loop #31 2022-05-19T17:37:33.633Z,1652981853.633 [Default:CheckIn] Running Loop=31 2022-05-19T17:37:33.633Z,1652981853.633 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-19T17:37:33.633Z,1652981853.633 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-19T17:37:35.647Z,1652981855.647 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173734.00,A,3648.17833,N,12147.27726,W,0.156,9.43,190522,,,A*78 2022-05-19T17:37:35.650Z,1652981855.650 [NAL9602](INFO): GPS fix at 20220519T173734: (36.802972, -121.787954) 2022-05-19T17:37:35.697Z,1652981855.697 [Default:CheckIn:Read_GPS] Stopped 2022-05-19T17:37:35.698Z,1652981855.698 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-19T17:37:42.636Z,1652981862.636 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220519T144934/Courier0087.lzma 2022-05-19T17:37:43.638Z,1652981863.638 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Courier0087.lzma.bak 2022-05-19T17:37:43.639Z,1652981863.639 [DataOverHttps](INFO): SBD MOMSN=16809550 2022-05-19T17:37:59.445Z,1652981879.445 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20220519T144934/Express0088.lzma 2022-05-19T17:38:00.446Z,1652981880.446 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Express0088.lzma.bak 2022-05-19T17:38:00.447Z,1652981880.447 [DataOverHttps](INFO): SBD MOMSN=16809554 2022-05-19T17:38:01.915Z,1652981881.915 [Default:CheckIn:Read_Iridium] Stopped 2022-05-19T17:38:01.915Z,1652981881.915 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-19T17:38:01.916Z,1652981881.916 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-19T17:38:06.352Z,1652981886.352 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-05-19T17:38:06.429Z,1652981886.429 [NAL9602](ERROR): received: +SBDI: 2, 33049, 2, 0, 0, 0 OK 2022-05-19T17:39:38.059Z,1652981978.059 [NAL9602](INFO): SBD MO Status=2, MOMSN=33049, MT Status=2, MTMSN=0 2022-05-19T17:39:38.059Z,1652981978.059 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-05-19T17:40:03.923Z,1652982003.923 [NAL9602](INFO): SBD MO Status=2, MOMSN=33049, MT Status=2, MTMSN=0 2022-05-19T17:40:03.923Z,1652982003.923 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-05-19T17:42:38.258Z,1652982158.258 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-05-19T17:43:02.522Z,1652982182.522 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-19T17:43:02.522Z,1652982182.522 [Default:CheckIn:C.Wait] Stopped 2022-05-19T17:43:02.523Z,1652982182.523 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-19T17:43:02.523Z,1652982182.523 [Default:CheckIn:D] Running Loop=1 2022-05-19T17:43:02.920Z,1652982182.920 [Default:CheckIn:D] Stopped 2022-05-19T17:43:02.920Z,1652982182.920 [Default:CheckIn:E] Running Loop=1 2022-05-19T17:43:03.313Z,1652982183.313 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 182.923128 min 2022-05-19T17:43:03.313Z,1652982183.313 [Default:CheckIn:E] Stopped 2022-05-19T17:43:03.313Z,1652982183.313 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-19T17:43:03.313Z,1652982183.313 [Default:CheckIn] Stopped 2022-05-19T17:43:03.314Z,1652982183.314 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-19T17:43:03.314Z,1652982183.314 [Default:CheckIn](INFO): Running loop #32 2022-05-19T17:43:03.314Z,1652982183.314 [Default:CheckIn] Running Loop=32 2022-05-19T17:43:03.314Z,1652982183.314 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-19T17:43:03.314Z,1652982183.314 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-19T17:43:05.331Z,1652982185.331 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174304.00,A,3648.18302,N,12147.27471,W,0.000,9.43,190522,,,A*7D 2022-05-19T17:43:05.334Z,1652982185.334 [NAL9602](INFO): GPS fix at 20220519T174304: (36.803050, -121.787912) 2022-05-19T17:43:05.344Z,1652982185.344 [Default:CheckIn:Read_GPS] Stopped 2022-05-19T17:43:05.344Z,1652982185.344 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-19T17:43:13.000Z,1652982193.000 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20220519T144934/Courier0090.lzma 2022-05-19T17:43:14.004Z,1652982194.004 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Courier0090.lzma.bak 2022-05-19T17:43:14.005Z,1652982194.005 [DataOverHttps](INFO): SBD MOMSN=16809580 2022-05-19T17:43:29.849Z,1652982209.849 [DataOverHttps](INFO): Sending 208 bytes from file Logs/20220519T144934/Express0091.lzma 2022-05-19T17:43:30.874Z,1652982210.874 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Express0091.lzma.bak 2022-05-19T17:43:30.875Z,1652982210.875 [DataOverHttps](INFO): SBD MOMSN=16809583 2022-05-19T17:43:32.025Z,1652982212.025 [Default:CheckIn:Read_Iridium] Stopped 2022-05-19T17:43:32.025Z,1652982212.025 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-19T17:43:32.025Z,1652982212.025 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-19T17:43:37.670Z,1652982217.670 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-19T17:48:32.606Z,1652982512.606 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-19T17:48:32.607Z,1652982512.607 [Default:CheckIn:C.Wait] Stopped 2022-05-19T17:48:32.607Z,1652982512.607 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-19T17:48:32.607Z,1652982512.607 [Default:CheckIn:D] Running Loop=1 2022-05-19T17:48:33.005Z,1652982513.005 [Default:CheckIn:D] Stopped 2022-05-19T17:48:33.005Z,1652982513.005 [Default:CheckIn:E] Running Loop=1 2022-05-19T17:48:33.419Z,1652982513.419 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 188.424544 min 2022-05-19T17:48:33.419Z,1652982513.419 [Default:CheckIn:E] Stopped 2022-05-19T17:48:33.420Z,1652982513.420 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-19T17:48:33.420Z,1652982513.420 [Default:CheckIn] Stopped 2022-05-19T17:48:33.420Z,1652982513.420 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-19T17:48:33.420Z,1652982513.420 [Default:CheckIn](INFO): Running loop #33 2022-05-19T17:48:33.420Z,1652982513.420 [Default:CheckIn] Running Loop=33 2022-05-19T17:48:33.420Z,1652982513.420 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-19T17:48:33.420Z,1652982513.420 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-19T17:48:35.423Z,1652982515.423 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174834.00,A,3648.18338,N,12147.27784,W,0.078,9.43,190522,,,A*7A 2022-05-19T17:48:35.425Z,1652982515.425 [NAL9602](INFO): GPS fix at 20220519T174834: (36.803056, -121.787964) 2022-05-19T17:48:35.454Z,1652982515.454 [Default:CheckIn:Read_GPS] Stopped 2022-05-19T17:48:35.454Z,1652982515.454 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-19T17:48:43.136Z,1652982523.136 [DataOverHttps](INFO): Sending 70 bytes from file Logs/20220519T144934/Courier0093.lzma 2022-05-19T17:48:44.138Z,1652982524.138 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Courier0093.lzma.bak 2022-05-19T17:48:44.139Z,1652982524.139 [DataOverHttps](INFO): SBD MOMSN=16809600 2022-05-19T17:49:03.188Z,1652982543.188 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20220519T144934/Express0094.lzma 2022-05-19T17:49:04.199Z,1652982544.199 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Express0094.lzma.bak 2022-05-19T17:49:04.199Z,1652982544.199 [DataOverHttps](INFO): SBD MOMSN=16809609 2022-05-19T17:49:05.379Z,1652982545.379 [Default:CheckIn:Read_Iridium] Stopped 2022-05-19T17:49:05.380Z,1652982545.380 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-19T17:49:05.380Z,1652982545.380 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-19T17:49:06.178Z,1652982546.178 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-05-19T17:49:06.252Z,1652982546.252 [NAL9602](ERROR): received: +CSQ:0 OK049, 2, 0, 0, 0 OK 2022-05-19T17:49:23.959Z,1652982563.959 [NAL9602](INFO): SBD MO Status=2, MOMSN=33049, MT Status=2, MTMSN=0 2022-05-19T17:49:23.959Z,1652982563.959 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-05-19T17:49:42.135Z,1652982582.135 [NAL9602](INFO): SBD MO Status=0, MOMSN=33049, MT Status=0, MTMSN=0 2022-05-19T17:49:42.135Z,1652982582.135 [NAL9602](INFO): No messages in MT queue 2022-05-19T17:50:12.837Z,1652982612.837 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-19T17:53:43.722Z,1652982823.722 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-05-19T17:53:58.673Z,1652982838.673 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-05-19T17:54:05.959Z,1652982845.959 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-19T17:54:05.960Z,1652982845.960 [Default:CheckIn:C.Wait] Stopped 2022-05-19T17:54:05.960Z,1652982845.960 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-19T17:54:05.960Z,1652982845.960 [Default:CheckIn:D] Running Loop=1 2022-05-19T17:54:06.373Z,1652982846.373 [Default:CheckIn:D] Stopped 2022-05-19T17:54:06.373Z,1652982846.373 [Default:CheckIn:E] Running Loop=1 2022-05-19T17:54:06.767Z,1652982846.767 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 193.980697 min 2022-05-19T17:54:06.767Z,1652982846.767 [Default:CheckIn:E] Stopped 2022-05-19T17:54:06.768Z,1652982846.768 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-19T17:54:06.768Z,1652982846.768 [Default:CheckIn] Stopped 2022-05-19T17:54:06.768Z,1652982846.768 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-19T17:54:06.768Z,1652982846.768 [Default:CheckIn](INFO): Running loop #34 2022-05-19T17:54:06.768Z,1652982846.768 [Default:CheckIn] Running Loop=34 2022-05-19T17:54:06.768Z,1652982846.768 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-19T17:54:06.768Z,1652982846.768 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-19T17:54:08.783Z,1652982848.783 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175408.00,A,3648.17606,N,12147.27645,W,0.156,9.43,190522,,,A*7E 2022-05-19T17:54:08.786Z,1652982848.786 [NAL9602](INFO): GPS fix at 20220519T175408: (36.802934, -121.787941) 2022-05-19T17:54:08.796Z,1652982848.796 [Default:CheckIn:Read_GPS] Stopped 2022-05-19T17:54:08.796Z,1652982848.796 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-19T17:54:13.621Z,1652982853.621 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-05-19T17:54:16.596Z,1652982856.596 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20220519T144934/Courier0096.lzma 2022-05-19T17:54:17.599Z,1652982857.599 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Courier0096.lzma.bak 2022-05-19T17:54:17.599Z,1652982857.599 [DataOverHttps](INFO): SBD MOMSN=16809625 2022-05-19T17:54:24.983Z,1652982864.983 [NAL9602](INFO): SBD MO Status=0, MOMSN=33050, MT Status=0, MTMSN=0 2022-05-19T17:54:24.983Z,1652982864.983 [NAL9602](INFO): No messages in MT queue 2022-05-19T17:54:28.618Z,1652982868.618 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-05-19T17:54:36.448Z,1652982876.448 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20220519T144934/Express0097.lzma 2022-05-19T17:54:37.451Z,1652982877.451 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Express0097.lzma.bak 2022-05-19T17:54:37.451Z,1652982877.451 [DataOverHttps](INFO): SBD MOMSN=16809633 2022-05-19T17:54:38.738Z,1652982878.738 [Default:CheckIn:Read_Iridium] Stopped 2022-05-19T17:54:38.738Z,1652982878.738 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-19T17:54:38.738Z,1652982878.738 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-19T17:54:43.973Z,1652982883.973 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-05-19T17:54:55.690Z,1652982895.690 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-19T17:54:59.727Z,1652982899.727 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-05-19T17:55:14.674Z,1652982914.674 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-05-19T17:55:30.026Z,1652982930.026 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-05-19T17:55:44.974Z,1652982944.974 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-05-19T17:55:59.518Z,1652982959.518 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2022-05-19T17:56:09.221Z,1652982969.221 [BPC1](INFO): Calculating totals. Valid battery stick count: 54. Valid reserve battery stick count: 6. 2022-05-19T17:56:09.223Z,1652982969.223 [BPC1](INFO): Received data from all battery sticks. 2022-05-19T17:59:39.347Z,1652983179.347 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-19T17:59:39.347Z,1652983179.347 [Default:CheckIn:C.Wait] Stopped 2022-05-19T17:59:39.347Z,1652983179.347 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-19T17:59:39.347Z,1652983179.347 [Default:CheckIn:D] Running Loop=1 2022-05-19T17:59:39.759Z,1652983179.759 [Default:CheckIn:D] Stopped 2022-05-19T17:59:39.759Z,1652983179.759 [Default:CheckIn:E] Running Loop=1 2022-05-19T17:59:40.147Z,1652983180.147 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 199.537126 min 2022-05-19T17:59:40.148Z,1652983180.148 [Default:CheckIn:E] Stopped 2022-05-19T17:59:40.148Z,1652983180.148 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-19T17:59:40.148Z,1652983180.148 [Default:CheckIn] Stopped 2022-05-19T17:59:40.148Z,1652983180.148 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-19T17:59:40.148Z,1652983180.148 [Default:CheckIn](INFO): Running loop #35 2022-05-19T17:59:40.148Z,1652983180.148 [Default:CheckIn] Running Loop=35 2022-05-19T17:59:40.148Z,1652983180.148 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-19T17:59:40.149Z,1652983180.149 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-19T17:59:42.166Z,1652983182.166 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175941.00,A,3648.17115,N,12147.27915,W,0.194,307.61,190522,,,A*72 2022-05-19T17:59:42.168Z,1652983182.168 [NAL9602](INFO): GPS fix at 20220519T175941: (36.802853, -121.787986) 2022-05-19T17:59:42.178Z,1652983182.178 [Default:CheckIn:Read_GPS] Stopped 2022-05-19T17:59:42.178Z,1652983182.178 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-19T17:59:50.148Z,1652983190.148 [DataOverHttps](INFO): Sending 85 bytes from file Logs/20220519T144934/Courier0099.lzma 2022-05-19T17:59:51.151Z,1652983191.151 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Courier0099.lzma.bak 2022-05-19T17:59:51.151Z,1652983191.151 [DataOverHttps](INFO): SBD MOMSN=16809653 2022-05-19T18:00:06.916Z,1652983206.916 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20220519T144934/Express0100.lzma 2022-05-19T18:00:07.919Z,1652983207.919 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Express0100.lzma.bak 2022-05-19T18:00:07.919Z,1652983207.919 [DataOverHttps](INFO): SBD MOMSN=16809656 2022-05-19T18:00:09.235Z,1652983209.235 [Default:CheckIn:Read_Iridium] Stopped 2022-05-19T18:00:09.235Z,1652983209.235 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-19T18:00:09.236Z,1652983209.236 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-19T18:01:49.023Z,1652983309.023 [NAL9602](INFO): SBD MO Status=0, MOMSN=33051, MT Status=0, MTMSN=0 2022-05-19T18:01:49.023Z,1652983309.023 [NAL9602](INFO): No messages in MT queue 2022-05-19T18:02:19.717Z,1652983339.717 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-19T18:05:09.872Z,1652983509.872 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-19T18:05:09.872Z,1652983509.872 [Default:CheckIn:C.Wait] Stopped 2022-05-19T18:05:09.872Z,1652983509.872 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-19T18:05:09.873Z,1652983509.873 [Default:CheckIn:D] Running Loop=1 2022-05-19T18:05:10.281Z,1652983510.281 [Default:CheckIn:D] Stopped 2022-05-19T18:05:10.281Z,1652983510.281 [Default:CheckIn:E] Running Loop=1 2022-05-19T18:05:10.698Z,1652983510.698 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 205.045833 min 2022-05-19T18:05:10.698Z,1652983510.698 [Default:CheckIn:E] Stopped 2022-05-19T18:05:10.698Z,1652983510.698 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-19T18:05:10.698Z,1652983510.698 [Default:CheckIn] Stopped 2022-05-19T18:05:10.698Z,1652983510.698 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-19T18:05:10.699Z,1652983510.699 [Default:CheckIn](INFO): Running loop #36 2022-05-19T18:05:10.699Z,1652983510.699 [Default:CheckIn] Running Loop=36 2022-05-19T18:05:10.699Z,1652983510.699 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-19T18:05:10.699Z,1652983510.699 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-19T18:05:12.687Z,1652983512.687 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180512.00,A,3648.16850,N,12147.28217,W,0.233,307.61,190522,,,A*73 2022-05-19T18:05:12.689Z,1652983512.689 [NAL9602](INFO): GPS fix at 20220519T180512: (36.802808, -121.788036) 2022-05-19T18:05:12.705Z,1652983512.705 [Default:CheckIn:Read_GPS] Stopped 2022-05-19T18:05:12.705Z,1652983512.705 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-19T18:05:20.657Z,1652983520.657 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20220519T144934/Courier0102.lzma 2022-05-19T18:05:21.659Z,1652983521.659 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Courier0102.lzma.bak 2022-05-19T18:05:21.659Z,1652983521.659 [DataOverHttps](INFO): SBD MOMSN=16809686 2022-05-19T18:05:35.311Z,1652983535.311 [NAL9602](INFO): SBD MO Status=2, MOMSN=33052, MT Status=2, MTMSN=0 2022-05-19T18:05:35.311Z,1652983535.311 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-05-19T18:05:37.506Z,1652983537.506 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20220519T144934/Express0103.lzma 2022-05-19T18:05:38.506Z,1652983538.506 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Express0103.lzma.bak 2022-05-19T18:05:38.507Z,1652983538.507 [DataOverHttps](INFO): SBD MOMSN=16809693 2022-05-19T18:05:39.782Z,1652983539.782 [Default:CheckIn:Read_Iridium] Stopped 2022-05-19T18:05:39.782Z,1652983539.782 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-19T18:05:39.782Z,1652983539.782 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-19T18:05:43.795Z,1652983543.795 [NAL9602](INFO): SBD MO Status=0, MOMSN=33052, MT Status=0, MTMSN=0 2022-05-19T18:05:43.795Z,1652983543.795 [NAL9602](INFO): No messages in MT queue 2022-05-19T18:06:14.497Z,1652983574.497 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-19T18:10:40.402Z,1652983840.402 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-19T18:10:40.403Z,1652983840.403 [Default:CheckIn:C.Wait] Stopped 2022-05-19T18:10:40.403Z,1652983840.403 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-19T18:10:40.403Z,1652983840.403 [Default:CheckIn:D] Running Loop=1 2022-05-19T18:10:40.795Z,1652983840.795 [Default:CheckIn:D] Stopped 2022-05-19T18:10:40.795Z,1652983840.795 [Default:CheckIn:E] Running Loop=1 2022-05-19T18:10:41.204Z,1652983841.204 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 210.554395 min 2022-05-19T18:10:41.204Z,1652983841.204 [Default:CheckIn:E] Stopped 2022-05-19T18:10:41.204Z,1652983841.204 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-19T18:10:41.204Z,1652983841.204 [Default:CheckIn] Stopped 2022-05-19T18:10:41.204Z,1652983841.204 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-19T18:10:41.205Z,1652983841.205 [Default:CheckIn](INFO): Running loop #37 2022-05-19T18:10:41.205Z,1652983841.205 [Default:CheckIn] Running Loop=37 2022-05-19T18:10:41.205Z,1652983841.205 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-19T18:10:41.205Z,1652983841.205 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-19T18:10:43.209Z,1652983843.209 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181042.00,A,3648.17359,N,12147.27872,W,0.350,307.61,190522,,,A*73 2022-05-19T18:10:43.211Z,1652983843.211 [NAL9602](INFO): GPS fix at 20220519T181042: (36.802893, -121.787979) 2022-05-19T18:10:43.222Z,1652983843.222 [Default:CheckIn:Read_GPS] Stopped 2022-05-19T18:10:43.222Z,1652983843.222 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-19T18:10:53.520Z,1652983853.520 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220519T144934/Courier0105.lzma 2022-05-19T18:10:53.759Z,1652983853.759 [NAL9602](INFO): SBD MO Status=0, MOMSN=33053, MT Status=0, MTMSN=0 2022-05-19T18:10:53.759Z,1652983853.759 [NAL9602](INFO): No messages in MT queue 2022-05-19T18:10:54.523Z,1652983854.523 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Courier0105.lzma.bak 2022-05-19T18:10:54.523Z,1652983854.523 [DataOverHttps](INFO): SBD MOMSN=16809712 2022-05-19T18:11:11.132Z,1652983871.132 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20220519T144934/Express0106.lzma 2022-05-19T18:11:12.135Z,1652983872.135 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Express0106.lzma.bak 2022-05-19T18:11:12.135Z,1652983872.135 [DataOverHttps](INFO): SBD MOMSN=16809716 2022-05-19T18:11:13.563Z,1652983873.563 [Default:CheckIn:Read_Iridium] Stopped 2022-05-19T18:11:13.563Z,1652983873.563 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-19T18:11:13.564Z,1652983873.564 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-19T18:11:24.461Z,1652983884.461 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-19T18:16:14.349Z,1652984174.349 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-19T18:16:14.350Z,1652984174.350 [Default:CheckIn:C.Wait] Stopped 2022-05-19T18:16:14.350Z,1652984174.350 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-19T18:16:14.350Z,1652984174.350 [Default:CheckIn:D] Running Loop=1 2022-05-19T18:16:14.762Z,1652984174.762 [Default:CheckIn:D] Stopped 2022-05-19T18:16:14.762Z,1652984174.762 [Default:CheckIn:E] Running Loop=1 2022-05-19T18:16:15.166Z,1652984175.166 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 216.120508 min 2022-05-19T18:16:15.166Z,1652984175.166 [Default:CheckIn:E] Stopped 2022-05-19T18:16:15.166Z,1652984175.166 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-19T18:16:15.166Z,1652984175.166 [Default:CheckIn] Stopped 2022-05-19T18:16:15.166Z,1652984175.166 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-19T18:16:15.166Z,1652984175.166 [Default:CheckIn](INFO): Running loop #38 2022-05-19T18:16:15.166Z,1652984175.166 [Default:CheckIn] Running Loop=38 2022-05-19T18:16:15.166Z,1652984175.166 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-19T18:16:15.167Z,1652984175.167 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-19T18:16:17.171Z,1652984177.171 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181616.00,A,3648.17257,N,12147.27744,W,0.214,0.00,190522,,,A*73 2022-05-19T18:16:17.174Z,1652984177.174 [NAL9602](INFO): GPS fix at 20220519T181616: (36.802876, -121.787957) 2022-05-19T18:16:17.249Z,1652984177.249 [Default:CheckIn:Read_GPS] Stopped 2022-05-19T18:16:17.249Z,1652984177.249 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-19T18:16:27.044Z,1652984187.044 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20220519T144934/Courier0108.lzma 2022-05-19T18:16:28.047Z,1652984188.047 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Courier0108.lzma.bak 2022-05-19T18:16:28.047Z,1652984188.047 [DataOverHttps](INFO): SBD MOMSN=16809749 2022-05-19T18:16:39.927Z,1652984199.927 [NAL9602](INFO): SBD MO Status=0, MOMSN=33054, MT Status=0, MTMSN=0 2022-05-19T18:16:39.927Z,1652984199.927 [NAL9602](INFO): No messages in MT queue 2022-05-19T18:16:43.872Z,1652984203.872 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20220519T144934/Express0109.lzma 2022-05-19T18:16:44.875Z,1652984204.875 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Express0109.lzma.bak 2022-05-19T18:16:44.875Z,1652984204.875 [DataOverHttps](INFO): SBD MOMSN=16809754 2022-05-19T18:16:46.405Z,1652984206.405 [Default:CheckIn:Read_Iridium] Stopped 2022-05-19T18:16:46.405Z,1652984206.405 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-19T18:16:46.405Z,1652984206.405 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-19T18:17:10.691Z,1652984230.691 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-19T18:21:47.219Z,1652984507.219 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-19T18:21:47.219Z,1652984507.219 [Default:CheckIn:C.Wait] Stopped 2022-05-19T18:21:47.219Z,1652984507.219 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-19T18:21:47.219Z,1652984507.219 [Default:CheckIn:D] Running Loop=1 2022-05-19T18:21:47.617Z,1652984507.617 [Default:CheckIn:D] Stopped 2022-05-19T18:21:47.617Z,1652984507.617 [Default:CheckIn:E] Running Loop=1 2022-05-19T18:21:48.024Z,1652984508.024 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 221.668083 min 2022-05-19T18:21:48.024Z,1652984508.024 [Default:CheckIn:E] Stopped 2022-05-19T18:21:48.024Z,1652984508.024 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-19T18:21:48.025Z,1652984508.025 [Default:CheckIn] Stopped 2022-05-19T18:21:48.025Z,1652984508.025 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-19T18:21:48.025Z,1652984508.025 [Default:CheckIn](INFO): Running loop #39 2022-05-19T18:21:48.025Z,1652984508.025 [Default:CheckIn] Running Loop=39 2022-05-19T18:21:48.025Z,1652984508.025 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-19T18:21:48.025Z,1652984508.025 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-19T18:21:50.035Z,1652984510.035 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182149.00,A,3648.17786,N,12147.27746,W,0.058,339.76,190522,,,A*74 2022-05-19T18:21:50.038Z,1652984510.038 [NAL9602](INFO): GPS fix at 20220519T182149: (36.802964, -121.787958) 2022-05-19T18:21:50.068Z,1652984510.068 [Default:CheckIn:Read_GPS] Stopped 2022-05-19T18:21:50.069Z,1652984510.069 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-19T18:21:57.732Z,1652984517.732 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220519T144934/Courier0111.lzma 2022-05-19T18:21:58.735Z,1652984518.735 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Courier0111.lzma.bak 2022-05-19T18:21:58.735Z,1652984518.735 [DataOverHttps](INFO): SBD MOMSN=16809808 2022-05-19T18:22:08.215Z,1652984528.215 [NAL9602](INFO): SBD MO Status=0, MOMSN=33055, MT Status=0, MTMSN=0 2022-05-19T18:22:08.215Z,1652984528.215 [NAL9602](INFO): No messages in MT queue 2022-05-19T18:22:14.664Z,1652984534.664 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20220519T144934/Express0112.lzma 2022-05-19T18:22:15.667Z,1652984535.667 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Express0112.lzma.bak 2022-05-19T18:22:15.667Z,1652984535.667 [DataOverHttps](INFO): SBD MOMSN=16809811 2022-05-19T18:22:17.134Z,1652984537.134 [Default:CheckIn:Read_Iridium] Stopped 2022-05-19T18:22:17.135Z,1652984537.135 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-19T18:22:17.135Z,1652984537.135 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-19T18:22:38.983Z,1652984558.983 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-19T18:27:17.625Z,1652984837.625 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-19T18:27:17.625Z,1652984837.625 [Default:CheckIn:C.Wait] Stopped 2022-05-19T18:27:17.625Z,1652984837.625 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-19T18:27:17.626Z,1652984837.626 [Default:CheckIn:D] Running Loop=1 2022-05-19T18:27:17.970Z,1652984837.970 [Default:CheckIn:D] Stopped 2022-05-19T18:27:17.970Z,1652984837.970 [Default:CheckIn:E] Running Loop=1 2022-05-19T18:27:18.383Z,1652984838.383 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 227.173975 min 2022-05-19T18:27:18.383Z,1652984838.383 [Default:CheckIn:E] Stopped 2022-05-19T18:27:18.383Z,1652984838.383 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-19T18:27:18.383Z,1652984838.383 [Default:CheckIn] Stopped 2022-05-19T18:27:18.383Z,1652984838.383 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-19T18:27:18.383Z,1652984838.383 [Default:CheckIn](INFO): Running loop #40 2022-05-19T18:27:18.384Z,1652984838.384 [Default:CheckIn] Running Loop=40 2022-05-19T18:27:18.384Z,1652984838.384 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-19T18:27:18.384Z,1652984838.384 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-19T18:27:20.389Z,1652984840.389 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182719.00,A,3648.17239,N,12147.27948,W,0.544,339.76,190522,,,A*7E 2022-05-19T18:27:20.391Z,1652984840.391 [NAL9602](INFO): GPS fix at 20220519T182719: (36.802873, -121.787991) 2022-05-19T18:27:20.402Z,1652984840.402 [Default:CheckIn:Read_GPS] Stopped 2022-05-19T18:27:20.402Z,1652984840.402 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-19T18:27:27.672Z,1652984847.672 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220519T144934/Courier0114.lzma 2022-05-19T18:27:28.674Z,1652984848.674 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Courier0114.lzma.bak 2022-05-19T18:27:28.675Z,1652984848.675 [DataOverHttps](INFO): SBD MOMSN=16809870 2022-05-19T18:27:44.580Z,1652984864.580 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20220519T144934/Express0115.lzma 2022-05-19T18:27:45.583Z,1652984865.583 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Express0115.lzma.bak 2022-05-19T18:27:45.583Z,1652984865.583 [DataOverHttps](INFO): SBD MOMSN=16809899 2022-05-19T18:27:47.089Z,1652984867.089 [Default:CheckIn:Read_Iridium] Stopped 2022-05-19T18:27:47.089Z,1652984867.089 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-19T18:27:47.089Z,1652984867.089 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-19T18:29:35.839Z,1652984975.839 [NAL9602](INFO): SBD MO Status=2, MOMSN=33056, MT Status=2, MTMSN=0 2022-05-19T18:29:35.839Z,1652984975.839 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-05-19T18:29:47.551Z,1652984987.551 [NAL9602](INFO): SBD MO Status=0, MOMSN=33056, MT Status=0, MTMSN=0 2022-05-19T18:29:47.551Z,1652984987.551 [NAL9602](INFO): No messages in MT queue 2022-05-19T18:30:18.257Z,1652985018.257 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-19T18:32:47.882Z,1652985167.882 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-19T18:32:47.882Z,1652985167.882 [Default:CheckIn:C.Wait] Stopped 2022-05-19T18:32:47.882Z,1652985167.882 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-19T18:32:47.882Z,1652985167.882 [Default:CheckIn:D] Running Loop=1 2022-05-19T18:32:48.292Z,1652985168.292 [Default:CheckIn:D] Stopped 2022-05-19T18:32:48.292Z,1652985168.292 [Default:CheckIn:E] Running Loop=1 2022-05-19T18:32:48.697Z,1652985168.697 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 232.679329 min 2022-05-19T18:32:48.697Z,1652985168.697 [Default:CheckIn:E] Stopped 2022-05-19T18:32:48.697Z,1652985168.697 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-19T18:32:48.697Z,1652985168.697 [Default:CheckIn] Stopped 2022-05-19T18:32:48.697Z,1652985168.697 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-19T18:32:48.698Z,1652985168.698 [Default:CheckIn](INFO): Running loop #41 2022-05-19T18:32:48.698Z,1652985168.698 [Default:CheckIn] Running Loop=41 2022-05-19T18:32:48.698Z,1652985168.698 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-19T18:32:48.698Z,1652985168.698 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-19T18:32:50.718Z,1652985170.718 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183250.00,A,3648.18104,N,12147.27447,W,0.117,339.76,190522,,,A*75 2022-05-19T18:32:50.720Z,1652985170.720 [NAL9602](INFO): GPS fix at 20220519T183250: (36.803017, -121.787908) 2022-05-19T18:32:50.731Z,1652985170.731 [Default:CheckIn:Read_GPS] Stopped 2022-05-19T18:32:50.731Z,1652985170.731 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-19T18:32:59.872Z,1652985179.872 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220519T144934/Courier0117.lzma 2022-05-19T18:33:00.875Z,1652985180.875 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Courier0117.lzma.bak 2022-05-19T18:33:00.875Z,1652985180.875 [DataOverHttps](INFO): SBD MOMSN=16809955 2022-05-19T18:33:15.861Z,1652985195.861 [NAL9602](INFO): SBD MO Status=0, MOMSN=33057, MT Status=0, MTMSN=0 2022-05-19T18:33:15.861Z,1652985195.861 [NAL9602](INFO): No messages in MT queue 2022-05-19T18:33:16.700Z,1652985196.700 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20220519T144934/Express0118.lzma 2022-05-19T18:33:17.703Z,1652985197.703 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Express0118.lzma.bak 2022-05-19T18:33:17.703Z,1652985197.703 [DataOverHttps](INFO): SBD MOMSN=16809959 2022-05-19T18:33:19.105Z,1652985199.105 [Default:CheckIn:Read_Iridium] Stopped 2022-05-19T18:33:19.105Z,1652985199.105 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-19T18:33:19.105Z,1652985199.105 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-19T18:33:46.563Z,1652985226.563 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-19T18:38:19.777Z,1652985499.777 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-19T18:38:19.777Z,1652985499.777 [Default:CheckIn:C.Wait] Stopped 2022-05-19T18:38:19.777Z,1652985499.777 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-19T18:38:19.778Z,1652985499.778 [Default:CheckIn:D] Running Loop=1 2022-05-19T18:38:20.149Z,1652985500.149 [Default:CheckIn:D] Stopped 2022-05-19T18:38:20.149Z,1652985500.149 [Default:CheckIn:E] Running Loop=1 2022-05-19T18:38:20.566Z,1652985500.566 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 238.210303 min 2022-05-19T18:38:20.566Z,1652985500.566 [Default:CheckIn:E] Stopped 2022-05-19T18:38:20.566Z,1652985500.566 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-19T18:38:20.566Z,1652985500.566 [Default:CheckIn] Stopped 2022-05-19T18:38:20.566Z,1652985500.566 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-19T18:38:20.566Z,1652985500.566 [Default:CheckIn](INFO): Running loop #42 2022-05-19T18:38:20.566Z,1652985500.566 [Default:CheckIn] Running Loop=42 2022-05-19T18:38:20.567Z,1652985500.567 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-19T18:38:20.567Z,1652985500.567 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-19T18:38:22.565Z,1652985502.565 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183821.00,A,3648.17846,N,12147.27490,W,0.156,0.00,190522,,,A*7E 2022-05-19T18:38:22.567Z,1652985502.567 [NAL9602](INFO): GPS fix at 20220519T183821: (36.802974, -121.787915) 2022-05-19T18:38:22.578Z,1652985502.578 [Default:CheckIn:Read_GPS] Stopped 2022-05-19T18:38:22.578Z,1652985502.578 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-19T18:38:30.412Z,1652985510.412 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220519T144934/Courier0120.lzma 2022-05-19T18:38:31.415Z,1652985511.415 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Courier0120.lzma.bak 2022-05-19T18:38:31.415Z,1652985511.415 [DataOverHttps](INFO): SBD MOMSN=16809991 2022-05-19T18:38:47.518Z,1652985527.518 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20220519T144934/Express0121.lzma 2022-05-19T18:38:48.519Z,1652985528.519 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Express0121.lzma.bak 2022-05-19T18:38:48.519Z,1652985528.519 [DataOverHttps](INFO): SBD MOMSN=16809994 2022-05-19T18:38:50.079Z,1652985530.079 [Default:CheckIn:Read_Iridium] Stopped 2022-05-19T18:38:50.079Z,1652985530.079 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-19T18:38:50.079Z,1652985530.079 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-19T18:39:22.819Z,1652985562.819 [NAL9602](INFO): SBD MO Status=2, MOMSN=33058, MT Status=2, MTMSN=0 2022-05-19T18:39:22.819Z,1652985562.819 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-05-19T18:39:33.731Z,1652985573.731 [NAL9602](INFO): SBD MO Status=0, MOMSN=33058, MT Status=0, MTMSN=0 2022-05-19T18:39:33.731Z,1652985573.731 [NAL9602](INFO): No messages in MT queue 2022-05-19T18:40:04.427Z,1652985604.427 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-19T18:43:50.735Z,1652985830.735 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-19T18:43:50.735Z,1652985830.735 [Default:CheckIn:C.Wait] Stopped 2022-05-19T18:43:50.735Z,1652985830.735 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-19T18:43:50.736Z,1652985830.736 [Default:CheckIn:D] Running Loop=1 2022-05-19T18:43:51.137Z,1652985831.137 [Default:CheckIn:D] Stopped 2022-05-19T18:43:51.137Z,1652985831.137 [Default:CheckIn:E] Running Loop=1 2022-05-19T18:43:51.547Z,1652985831.547 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 243.726758 min 2022-05-19T18:43:51.547Z,1652985831.547 [Default:CheckIn:E] Stopped 2022-05-19T18:43:51.547Z,1652985831.547 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-19T18:43:51.547Z,1652985831.547 [Default:CheckIn] Stopped 2022-05-19T18:43:51.547Z,1652985831.547 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-19T18:43:51.548Z,1652985831.548 [Default:CheckIn](INFO): Running loop #43 2022-05-19T18:43:51.548Z,1652985831.548 [Default:CheckIn] Running Loop=43 2022-05-19T18:43:51.548Z,1652985831.548 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-19T18:43:51.548Z,1652985831.548 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-19T18:43:53.551Z,1652985833.551 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184352.00,A,3648.17644,N,12147.27543,W,0.447,0.00,190522,,,A*70 2022-05-19T18:43:53.554Z,1652985833.554 [NAL9602](INFO): GPS fix at 20220519T184352: (36.802941, -121.787924) 2022-05-19T18:43:53.580Z,1652985833.580 [Default:CheckIn:Read_GPS] Stopped 2022-05-19T18:43:53.580Z,1652985833.580 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-19T18:44:00.944Z,1652985840.944 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20220519T144934/Courier0123.lzma 2022-05-19T18:44:01.947Z,1652985841.947 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Courier0123.lzma.bak 2022-05-19T18:44:01.947Z,1652985841.947 [DataOverHttps](INFO): SBD MOMSN=16810015 2022-05-19T18:44:18.611Z,1652985858.611 [NAL9602](INFO): SBD MO Status=2, MOMSN=33059, MT Status=2, MTMSN=0 2022-05-19T18:44:18.611Z,1652985858.611 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-05-19T18:44:18.928Z,1652985858.928 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20220519T144934/Express0124.lzma 2022-05-19T18:44:19.931Z,1652985859.931 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Express0124.lzma.bak 2022-05-19T18:44:19.931Z,1652985859.931 [DataOverHttps](INFO): SBD MOMSN=16810018 2022-05-19T18:44:21.457Z,1652985861.457 [Default:CheckIn:Read_Iridium] Stopped 2022-05-19T18:44:21.457Z,1652985861.457 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-19T18:44:21.457Z,1652985861.457 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-19T18:47:10.855Z,1652986030.855 [NAL9602](INFO): SBD MO Status=2, MOMSN=33059, MT Status=2, MTMSN=0 2022-05-19T18:47:10.855Z,1652986030.855 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-05-19T18:48:33.275Z,1652986113.275 [NAL9602](INFO): SBD MO Status=2, MOMSN=33059, MT Status=2, MTMSN=0 2022-05-19T18:48:33.275Z,1652986113.275 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-05-19T18:48:55.491Z,1652986135.491 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-05-19T18:49:22.169Z,1652986162.169 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-19T18:49:22.169Z,1652986162.169 [Default:CheckIn:C.Wait] Stopped 2022-05-19T18:49:22.169Z,1652986162.169 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-19T18:49:22.170Z,1652986162.170 [Default:CheckIn:D] Running Loop=1 2022-05-19T18:49:22.567Z,1652986162.567 [Default:CheckIn:D] Stopped 2022-05-19T18:49:22.567Z,1652986162.567 [Default:CheckIn:E] Running Loop=1 2022-05-19T18:49:22.975Z,1652986162.975 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 249.250602 min 2022-05-19T18:49:22.975Z,1652986162.975 [Default:CheckIn:E] Stopped 2022-05-19T18:49:22.975Z,1652986162.975 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-19T18:49:22.975Z,1652986162.975 [Default:CheckIn] Stopped 2022-05-19T18:49:22.975Z,1652986162.975 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-19T18:49:22.975Z,1652986162.975 [Default:CheckIn](INFO): Running loop #44 2022-05-19T18:49:22.976Z,1652986162.976 [Default:CheckIn] Running Loop=44 2022-05-19T18:49:22.976Z,1652986162.976 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-19T18:49:22.976Z,1652986162.976 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-19T18:49:24.993Z,1652986164.993 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184924.00,A,3648.17708,N,12147.27577,W,0.194,357.73,190522,,,A*7B 2022-05-19T18:49:24.995Z,1652986164.995 [NAL9602](INFO): GPS fix at 20220519T184924: (36.802951, -121.787930) 2022-05-19T18:49:25.013Z,1652986165.013 [Default:CheckIn:Read_GPS] Stopped 2022-05-19T18:49:25.013Z,1652986165.013 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-19T18:49:31.965Z,1652986171.965 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20220519T144934/Courier0126.lzma 2022-05-19T18:49:32.967Z,1652986172.967 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Courier0126.lzma.bak 2022-05-19T18:49:32.967Z,1652986172.967 [DataOverHttps](INFO): SBD MOMSN=16810041 2022-05-19T18:49:48.776Z,1652986188.776 [DataOverHttps](INFO): Sending 208 bytes from file Logs/20220519T144934/Express0127.lzma 2022-05-19T18:49:49.779Z,1652986189.779 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Express0127.lzma.bak 2022-05-19T18:49:49.779Z,1652986189.779 [DataOverHttps](INFO): SBD MOMSN=16810047 2022-05-19T18:49:51.251Z,1652986191.251 [Default:CheckIn:Read_Iridium] Stopped 2022-05-19T18:49:51.251Z,1652986191.251 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-19T18:49:51.251Z,1652986191.251 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-19T18:49:57.299Z,1652986197.299 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-19T18:54:51.881Z,1652986491.881 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-19T18:54:51.881Z,1652986491.881 [Default:CheckIn:C.Wait] Stopped 2022-05-19T18:54:51.881Z,1652986491.881 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-19T18:54:51.882Z,1652986491.882 [Default:CheckIn:D] Running Loop=1 2022-05-19T18:54:52.274Z,1652986492.274 [Default:CheckIn:D] Stopped 2022-05-19T18:54:52.274Z,1652986492.274 [Default:CheckIn:E] Running Loop=1 2022-05-19T18:54:52.672Z,1652986492.672 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 254.745703 min 2022-05-19T18:54:52.672Z,1652986492.672 [Default:CheckIn:E] Stopped 2022-05-19T18:54:52.672Z,1652986492.672 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-19T18:54:52.672Z,1652986492.672 [Default:CheckIn] Stopped 2022-05-19T18:54:52.672Z,1652986492.672 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-19T18:54:52.672Z,1652986492.672 [Default:CheckIn](INFO): Running loop #45 2022-05-19T18:54:52.673Z,1652986492.673 [Default:CheckIn] Running Loop=45 2022-05-19T18:54:52.673Z,1652986492.673 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-19T18:54:52.673Z,1652986492.673 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-19T18:54:54.683Z,1652986494.683 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185453.00,A,3648.16166,N,12147.27549,W,0.972,323.12,190522,,,A*71 2022-05-19T18:54:54.686Z,1652986494.686 [NAL9602](INFO): GPS fix at 20220519T185453: (36.802694, -121.787925) 2022-05-19T18:54:54.708Z,1652986494.708 [Default:CheckIn:Read_GPS] Stopped 2022-05-19T18:54:54.708Z,1652986494.708 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-19T18:55:02.076Z,1652986502.076 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220519T144934/Courier0129.lzma 2022-05-19T18:55:03.079Z,1652986503.079 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Courier0129.lzma.bak 2022-05-19T18:55:03.079Z,1652986503.079 [DataOverHttps](INFO): SBD MOMSN=16810088 2022-05-19T18:55:18.952Z,1652986518.952 [DataOverHttps](INFO): Sending 137 bytes from file Logs/20220519T144934/Express0130.lzma 2022-05-19T18:55:19.955Z,1652986519.955 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Express0130.lzma.bak 2022-05-19T18:55:19.955Z,1652986519.955 [DataOverHttps](INFO): SBD MOMSN=16810092 2022-05-19T18:55:21.365Z,1652986521.365 [Default:CheckIn:Read_Iridium] Stopped 2022-05-19T18:55:21.365Z,1652986521.365 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-19T18:55:21.365Z,1652986521.365 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-19T18:55:25.385Z,1652986525.385 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-05-19T18:55:25.468Z,1652986525.468 [NAL9602](ERROR): received: +CSQ:0 OK059, 2, 0, 0, 0 OK 2022-05-19T18:59:57.350Z,1652986797.350 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-05-19T19:00:22.019Z,1652986822.019 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-19T19:00:22.019Z,1652986822.019 [Default:CheckIn:C.Wait] Stopped 2022-05-19T19:00:22.019Z,1652986822.019 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-19T19:00:22.020Z,1652986822.020 [Default:CheckIn:D] Running Loop=1 2022-05-19T19:00:22.391Z,1652986822.391 [Default:CheckIn:D] Stopped 2022-05-19T19:00:22.391Z,1652986822.391 [Default:CheckIn:E] Running Loop=1 2022-05-19T19:00:22.902Z,1652986822.902 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 260.247656 min 2022-05-19T19:00:22.902Z,1652986822.902 [Default:CheckIn:E] Stopped 2022-05-19T19:00:22.902Z,1652986822.902 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-19T19:00:22.902Z,1652986822.902 [Default:CheckIn] Stopped 2022-05-19T19:00:22.902Z,1652986822.902 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-19T19:00:22.902Z,1652986822.902 [Default:CheckIn](INFO): Running loop #46 2022-05-19T19:00:22.903Z,1652986822.903 [Default:CheckIn] Running Loop=46 2022-05-19T19:00:22.903Z,1652986822.903 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-19T19:00:22.903Z,1652986822.903 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-19T19:00:24.805Z,1652986824.805 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190024.00,A,3648.17536,N,12147.29094,W,1.147,323.12,190522,,,A*75 2022-05-19T19:00:24.808Z,1652986824.808 [NAL9602](INFO): GPS fix at 20220519T190024: (36.802923, -121.788182) 2022-05-19T19:00:24.818Z,1652986824.818 [Default:CheckIn:Read_GPS] Stopped 2022-05-19T19:00:24.818Z,1652986824.818 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-19T19:00:33.024Z,1652986833.024 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20220519T144934/Courier0132.lzma 2022-05-19T19:00:34.027Z,1652986834.027 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Courier0132.lzma.bak 2022-05-19T19:00:34.027Z,1652986834.027 [DataOverHttps](INFO): SBD MOMSN=16810144 2022-05-19T19:00:51.593Z,1652986851.593 [DataOverHttps](INFO): Sending 219 bytes from file Logs/20220519T144934/Express0133.lzma 2022-05-19T19:00:52.595Z,1652986852.595 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Express0133.lzma.bak 2022-05-19T19:00:52.595Z,1652986852.595 [DataOverHttps](INFO): SBD MOMSN=16810151 2022-05-19T19:00:54.094Z,1652986854.094 [Default:CheckIn:Read_Iridium] Stopped 2022-05-19T19:00:54.094Z,1652986854.094 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-19T19:00:54.094Z,1652986854.094 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-19T19:00:57.341Z,1652986857.341 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-19T19:01:08.238Z,1652986868.238 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-05-19T19:01:23.186Z,1652986883.186 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-05-19T19:01:38.134Z,1652986898.134 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-05-19T19:01:53.487Z,1652986913.487 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-05-19T19:02:08.838Z,1652986928.838 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-05-19T19:02:23.789Z,1652986943.789 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-05-19T19:02:39.145Z,1652986959.145 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-05-19T19:02:54.115Z,1652986974.115 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-05-19T19:03:09.449Z,1652986989.449 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-05-19T19:03:24.387Z,1652987004.387 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2022-05-19T19:03:36.517Z,1652987016.517 [BPC1](INFO): Calculating totals. Valid battery stick count: 54. Valid reserve battery stick count: 6. 2022-05-19T19:03:36.519Z,1652987016.519 [BPC1](INFO): Received data from all battery sticks. 2022-05-19T19:05:54.702Z,1652987154.702 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-19T19:05:54.702Z,1652987154.702 [Default:CheckIn:C.Wait] Stopped 2022-05-19T19:05:54.702Z,1652987154.702 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-19T19:05:54.702Z,1652987154.702 [Default:CheckIn:D] Running Loop=1 2022-05-19T19:05:55.117Z,1652987155.117 [Default:CheckIn:D] Stopped 2022-05-19T19:05:55.117Z,1652987155.117 [Default:CheckIn:E] Running Loop=1 2022-05-19T19:05:55.519Z,1652987155.519 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 265.793099 min 2022-05-19T19:05:55.519Z,1652987155.519 [Default:CheckIn:E] Stopped 2022-05-19T19:05:55.519Z,1652987155.519 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-19T19:05:55.519Z,1652987155.519 [Default:CheckIn] Stopped 2022-05-19T19:05:55.520Z,1652987155.520 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-19T19:05:55.520Z,1652987155.520 [Default:CheckIn](INFO): Running loop #47 2022-05-19T19:05:55.520Z,1652987155.520 [Default:CheckIn] Running Loop=47 2022-05-19T19:05:55.520Z,1652987155.520 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-19T19:05:55.520Z,1652987155.520 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-19T19:05:57.533Z,1652987157.533 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190556.00,A,3648.17363,N,12147.28028,W,2.838,325.27,190522,,,A*77 2022-05-19T19:05:57.535Z,1652987157.535 [NAL9602](INFO): GPS fix at 20220519T190556: (36.802894, -121.788005) 2022-05-19T19:05:57.545Z,1652987157.545 [Default:CheckIn:Read_GPS] Stopped 2022-05-19T19:05:57.545Z,1652987157.545 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-19T19:06:05.364Z,1652987165.364 [DataOverHttps](INFO): Sending 83 bytes from file Logs/20220519T144934/Courier0135.lzma 2022-05-19T19:06:06.367Z,1652987166.367 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Courier0135.lzma.bak 2022-05-19T19:06:06.367Z,1652987166.367 [DataOverHttps](INFO): SBD MOMSN=16810216 2022-05-19T19:06:24.913Z,1652987184.913 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20220519T144934/Express0136.lzma 2022-05-19T19:06:25.915Z,1652987185.915 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Express0136.lzma.bak 2022-05-19T19:06:25.915Z,1652987185.915 [DataOverHttps](INFO): SBD MOMSN=16810225 2022-05-19T19:06:27.497Z,1652987187.497 [Default:CheckIn:Read_Iridium] Stopped 2022-05-19T19:06:27.498Z,1652987187.498 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-19T19:06:27.498Z,1652987187.498 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-19T19:06:28.309Z,1652987188.309 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-05-19T19:06:28.388Z,1652987188.388 [NAL9602](ERROR): received: +CSQ:0 OK059, 2, 0, 0, 0 OK 2022-05-19T19:10:53.327Z,1652987453.327 [NAL9602](INFO): SBD MO Status=2, MOMSN=33059, MT Status=2, MTMSN=0 2022-05-19T19:10:53.327Z,1652987453.327 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-05-19T19:10:59.386Z,1652987459.386 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-05-19T19:11:28.080Z,1652987488.080 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-19T19:11:28.080Z,1652987488.080 [Default:CheckIn:C.Wait] Stopped 2022-05-19T19:11:28.080Z,1652987488.080 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-19T19:11:28.081Z,1652987488.081 [Default:CheckIn:D] Running Loop=1 2022-05-19T19:11:28.493Z,1652987488.493 [Default:CheckIn:D] Stopped 2022-05-19T19:11:28.493Z,1652987488.493 [Default:CheckIn:E] Running Loop=1 2022-05-19T19:11:28.905Z,1652987488.905 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 271.349349 min 2022-05-19T19:11:28.905Z,1652987488.905 [Default:CheckIn:E] Stopped 2022-05-19T19:11:28.906Z,1652987488.906 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-19T19:11:28.906Z,1652987488.906 [Default:CheckIn] Stopped 2022-05-19T19:11:28.906Z,1652987488.906 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-19T19:11:28.906Z,1652987488.906 [Default:CheckIn](INFO): Running loop #48 2022-05-19T19:11:28.906Z,1652987488.906 [Default:CheckIn] Running Loop=48 2022-05-19T19:11:28.906Z,1652987488.906 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-19T19:11:28.906Z,1652987488.906 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-19T19:11:30.903Z,1652987490.903 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191130.00,A,3648.15707,N,12147.26521,W,0.816,327.17,190522,,,A*7B 2022-05-19T19:11:30.905Z,1652987490.905 [NAL9602](INFO): GPS fix at 20220519T191130: (36.802618, -121.787753) 2022-05-19T19:11:30.915Z,1652987490.915 [Default:CheckIn:Read_GPS] Stopped 2022-05-19T19:11:30.915Z,1652987490.915 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-19T19:11:37.792Z,1652987497.792 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220519T144934/Courier0138.lzma 2022-05-19T19:11:38.795Z,1652987498.795 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Courier0138.lzma.bak 2022-05-19T19:11:38.795Z,1652987498.795 [DataOverHttps](INFO): SBD MOMSN=16810272 2022-05-19T19:11:54.493Z,1652987514.493 [DataOverHttps](INFO): Sending 220 bytes from file Logs/20220519T144934/Express0139.lzma 2022-05-19T19:11:55.738Z,1652987515.738 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Express0139.lzma.bak 2022-05-19T19:11:55.738Z,1652987515.738 [DataOverHttps](INFO): SBD MOMSN=16810275 2022-05-19T19:11:56.793Z,1652987516.793 [Default:CheckIn:Read_Iridium] Stopped 2022-05-19T19:11:56.793Z,1652987516.793 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-19T19:11:56.793Z,1652987516.793 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-19T19:12:03.641Z,1652987523.641 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-19T19:16:57.379Z,1652987817.379 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-19T19:16:57.379Z,1652987817.379 [Default:CheckIn:C.Wait] Stopped 2022-05-19T19:16:57.379Z,1652987817.379 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-19T19:16:57.380Z,1652987817.380 [Default:CheckIn:D] Running Loop=1 2022-05-19T19:16:57.766Z,1652987817.766 [Default:CheckIn:D] Stopped 2022-05-19T19:16:57.766Z,1652987817.766 [Default:CheckIn:E] Running Loop=1 2022-05-19T19:16:58.175Z,1652987818.175 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 276.837240 min 2022-05-19T19:16:58.175Z,1652987818.175 [Default:CheckIn:E] Stopped 2022-05-19T19:16:58.175Z,1652987818.175 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-19T19:16:58.175Z,1652987818.175 [Default:CheckIn] Stopped 2022-05-19T19:16:58.175Z,1652987818.175 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-19T19:16:58.176Z,1652987818.176 [Default:CheckIn](INFO): Running loop #49 2022-05-19T19:16:58.176Z,1652987818.176 [Default:CheckIn] Running Loop=49 2022-05-19T19:16:58.176Z,1652987818.176 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-19T19:16:58.176Z,1652987818.176 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-19T19:17:00.179Z,1652987820.179 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191659.00,A,3648.17435,N,12147.28866,W,1.050,0.00,190522,,,A*78 2022-05-19T19:17:00.181Z,1652987820.181 [NAL9602](INFO): GPS fix at 20220519T191659: (36.802906, -121.788144) 2022-05-19T19:17:00.192Z,1652987820.192 [Default:CheckIn:Read_GPS] Stopped 2022-05-19T19:17:00.192Z,1652987820.192 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-19T19:17:07.808Z,1652987827.808 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220519T144934/Courier0141.lzma 2022-05-19T19:17:08.811Z,1652987828.811 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Courier0141.lzma.bak 2022-05-19T19:17:08.811Z,1652987828.811 [DataOverHttps](INFO): SBD MOMSN=16810285 2022-05-19T19:17:24.704Z,1652987844.704 [DataOverHttps](INFO): Sending 143 bytes from file Logs/20220519T144934/Express0142.lzma 2022-05-19T19:17:25.731Z,1652987845.731 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Express0142.lzma.bak 2022-05-19T19:17:25.732Z,1652987845.732 [DataOverHttps](INFO): SBD MOMSN=16810288 2022-05-19T19:17:26.862Z,1652987846.862 [Default:CheckIn:Read_Iridium] Stopped 2022-05-19T19:17:26.862Z,1652987846.862 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-19T19:17:26.862Z,1652987846.862 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-19T19:17:30.882Z,1652987850.882 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-05-19T19:17:30.957Z,1652987850.957 [NAL9602](ERROR): received: +CSQ:0 OK059, 2, 0, 0, 0 OK 2022-05-19T19:22:02.377Z,1652988122.377 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-05-19T19:22:27.436Z,1652988147.436 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-19T19:22:27.436Z,1652988147.436 [Default:CheckIn:C.Wait] Stopped 2022-05-19T19:22:27.436Z,1652988147.436 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-19T19:22:27.436Z,1652988147.436 [Default:CheckIn:D] Running Loop=1 2022-05-19T19:22:27.849Z,1652988147.849 [Default:CheckIn:D] Stopped 2022-05-19T19:22:27.849Z,1652988147.849 [Default:CheckIn:E] Running Loop=1 2022-05-19T19:22:28.266Z,1652988148.266 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 282.338607 min 2022-05-19T19:22:28.266Z,1652988148.266 [Default:CheckIn:E] Stopped 2022-05-19T19:22:28.266Z,1652988148.266 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-19T19:22:28.266Z,1652988148.266 [Default:CheckIn] Stopped 2022-05-19T19:22:28.266Z,1652988148.266 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-19T19:22:28.266Z,1652988148.266 [Default:CheckIn](INFO): Running loop #50 2022-05-19T19:22:28.266Z,1652988148.266 [Default:CheckIn] Running Loop=50 2022-05-19T19:22:28.267Z,1652988148.267 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-19T19:22:28.267Z,1652988148.267 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-19T19:22:30.271Z,1652988150.271 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,192229.00,A,3648.17278,N,12147.28364,W,0.330,78.53,190522,,,A*43 2022-05-19T19:22:30.273Z,1652988150.273 [NAL9602](INFO): GPS fix at 20220519T192229: (36.802880, -121.788061) 2022-05-19T19:22:30.305Z,1652988150.305 [Default:CheckIn:Read_GPS] Stopped 2022-05-19T19:22:30.305Z,1652988150.305 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-19T19:22:37.544Z,1652988157.544 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220519T144934/Courier0144.lzma 2022-05-19T19:22:38.547Z,1652988158.547 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Courier0144.lzma.bak 2022-05-19T19:22:38.547Z,1652988158.547 [DataOverHttps](INFO): SBD MOMSN=16810329 2022-05-19T19:22:57.645Z,1652988177.645 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20220519T144934/Express0145.lzma 2022-05-19T19:22:58.647Z,1652988178.647 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Express0145.lzma.bak 2022-05-19T19:22:58.647Z,1652988178.647 [DataOverHttps](INFO): SBD MOMSN=16810334 2022-05-19T19:22:59.841Z,1652988179.841 [Default:CheckIn:Read_Iridium] Stopped 2022-05-19T19:22:59.841Z,1652988179.841 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-19T19:22:59.841Z,1652988179.841 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-19T19:23:02.661Z,1652988182.661 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-19T19:28:00.415Z,1652988480.415 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-19T19:28:00.415Z,1652988480.415 [Default:CheckIn:C.Wait] Stopped 2022-05-19T19:28:00.415Z,1652988480.415 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-19T19:28:00.415Z,1652988480.415 [Default:CheckIn:D] Running Loop=1 2022-05-19T19:28:00.823Z,1652988480.823 [Default:CheckIn:D] Stopped 2022-05-19T19:28:00.823Z,1652988480.823 [Default:CheckIn:E] Running Loop=1 2022-05-19T19:28:01.233Z,1652988481.233 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 287.888184 min 2022-05-19T19:28:01.233Z,1652988481.233 [Default:CheckIn:E] Stopped 2022-05-19T19:28:01.233Z,1652988481.233 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-19T19:28:01.233Z,1652988481.233 [Default:CheckIn] Stopped 2022-05-19T19:28:01.233Z,1652988481.233 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-19T19:28:01.233Z,1652988481.233 [Default:CheckIn](INFO): Running loop #51 2022-05-19T19:28:01.233Z,1652988481.233 [Default:CheckIn] Running Loop=51 2022-05-19T19:28:01.233Z,1652988481.233 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-19T19:28:01.233Z,1652988481.233 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-19T19:28:03.239Z,1652988483.239 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,192802.00,A,3648.16907,N,12147.28259,W,1.030,78.53,190522,,,A*4F 2022-05-19T19:28:03.256Z,1652988483.256 [NAL9602](INFO): GPS fix at 20220519T192802: (36.802818, -121.788043) 2022-05-19T19:28:03.267Z,1652988483.267 [Default:CheckIn:Read_GPS] Stopped 2022-05-19T19:28:03.267Z,1652988483.267 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-19T19:28:10.256Z,1652988490.256 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220519T144934/Courier0147.lzma 2022-05-19T19:28:11.259Z,1652988491.259 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Courier0147.lzma.bak 2022-05-19T19:28:11.259Z,1652988491.259 [DataOverHttps](INFO): SBD MOMSN=16810344 2022-05-19T19:28:30.716Z,1652988510.716 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20220519T144934/Express0148.lzma 2022-05-19T19:28:31.719Z,1652988511.719 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Express0148.lzma.bak 2022-05-19T19:28:31.719Z,1652988511.719 [DataOverHttps](INFO): SBD MOMSN=16810347 2022-05-19T19:28:33.229Z,1652988513.229 [Default:CheckIn:Read_Iridium] Stopped 2022-05-19T19:28:33.229Z,1652988513.229 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-19T19:28:33.230Z,1652988513.230 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-19T19:28:34.018Z,1652988514.018 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-05-19T19:28:34.092Z,1652988514.092 [NAL9602](ERROR): received: +CSQ:0 OK059, 2, 0, 0, 0 OK 2022-05-19T19:33:05.552Z,1652988785.552 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-05-19T19:33:33.857Z,1652988813.857 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-19T19:33:33.857Z,1652988813.857 [Default:CheckIn:C.Wait] Stopped 2022-05-19T19:33:33.857Z,1652988813.857 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-19T19:33:33.857Z,1652988813.857 [Default:CheckIn:D] Running Loop=1 2022-05-19T19:33:34.248Z,1652988814.248 [Default:CheckIn:D] Stopped 2022-05-19T19:33:34.248Z,1652988814.248 [Default:CheckIn:E] Running Loop=1 2022-05-19T19:33:34.664Z,1652988814.664 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 293.445280 min 2022-05-19T19:33:34.664Z,1652988814.664 [Default:CheckIn:E] Stopped 2022-05-19T19:33:34.664Z,1652988814.664 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-19T19:33:34.664Z,1652988814.664 [Default:CheckIn] Stopped 2022-05-19T19:33:34.664Z,1652988814.664 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-19T19:33:34.665Z,1652988814.665 [Default:CheckIn](INFO): Running loop #52 2022-05-19T19:33:34.665Z,1652988814.665 [Default:CheckIn] Running Loop=52 2022-05-19T19:33:34.665Z,1652988814.665 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-19T19:33:34.665Z,1652988814.665 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-19T19:33:36.667Z,1652988816.667 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,193335.00,A,3648.16520,N,12147.28157,W,1.769,0.00,190522,,,A*77 2022-05-19T19:33:36.669Z,1652988816.669 [NAL9602](INFO): GPS fix at 20220519T193335: (36.802753, -121.788026) 2022-05-19T19:33:36.680Z,1652988816.680 [Default:CheckIn:Read_GPS] Stopped 2022-05-19T19:33:36.680Z,1652988816.680 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-19T19:33:43.932Z,1652988823.932 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220519T144934/Courier0150.lzma 2022-05-19T19:33:44.935Z,1652988824.935 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Courier0150.lzma.bak 2022-05-19T19:33:44.935Z,1652988824.935 [DataOverHttps](INFO): SBD MOMSN=16810371 2022-05-19T19:34:00.809Z,1652988840.809 [DataOverHttps](INFO): Sending 205 bytes from file Logs/20220519T144934/Express0151.lzma 2022-05-19T19:34:01.811Z,1652988841.811 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Express0151.lzma.bak 2022-05-19T19:34:01.811Z,1652988841.811 [DataOverHttps](INFO): SBD MOMSN=16810377 2022-05-19T19:34:03.365Z,1652988843.365 [Default:CheckIn:Read_Iridium] Stopped 2022-05-19T19:34:03.366Z,1652988843.366 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-19T19:34:03.366Z,1652988843.366 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-19T19:34:09.411Z,1652988849.411 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-19T19:39:03.959Z,1652989143.959 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-19T19:39:03.959Z,1652989143.959 [Default:CheckIn:C.Wait] Stopped 2022-05-19T19:39:03.959Z,1652989143.959 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-19T19:39:03.960Z,1652989143.960 [Default:CheckIn:D] Running Loop=1 2022-05-19T19:39:04.371Z,1652989144.371 [Default:CheckIn:D] Stopped 2022-05-19T19:39:04.371Z,1652989144.371 [Default:CheckIn:E] Running Loop=1 2022-05-19T19:39:04.781Z,1652989144.781 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 298.947331 min 2022-05-19T19:39:04.781Z,1652989144.781 [Default:CheckIn:E] Stopped 2022-05-19T19:39:04.781Z,1652989144.781 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-19T19:39:04.781Z,1652989144.781 [Default:CheckIn] Stopped 2022-05-19T19:39:04.781Z,1652989144.781 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-19T19:39:04.781Z,1652989144.781 [Default:CheckIn](INFO): Running loop #53 2022-05-19T19:39:04.781Z,1652989144.781 [Default:CheckIn] Running Loop=53 2022-05-19T19:39:04.782Z,1652989144.782 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-19T19:39:04.782Z,1652989144.782 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-19T19:39:06.783Z,1652989146.783 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,193906.00,A,3648.16534,N,12147.27765,W,0.680,0.00,190522,,,A*77 2022-05-19T19:39:06.785Z,1652989146.785 [NAL9602](INFO): GPS fix at 20220519T193906: (36.802756, -121.787961) 2022-05-19T19:39:06.795Z,1652989146.795 [Default:CheckIn:Read_GPS] Stopped 2022-05-19T19:39:06.795Z,1652989146.795 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-19T19:39:13.800Z,1652989153.800 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220519T144934/Courier0153.lzma 2022-05-19T19:39:14.803Z,1652989154.803 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Courier0153.lzma.bak 2022-05-19T19:39:14.803Z,1652989154.803 [DataOverHttps](INFO): SBD MOMSN=16810462 2022-05-19T19:39:30.625Z,1652989170.625 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20220519T144934/Express0154.lzma 2022-05-19T19:39:31.627Z,1652989171.627 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Express0154.lzma.bak 2022-05-19T19:39:31.627Z,1652989171.627 [DataOverHttps](INFO): SBD MOMSN=16810465 2022-05-19T19:39:33.057Z,1652989173.057 [Default:CheckIn:Read_Iridium] Stopped 2022-05-19T19:39:33.057Z,1652989173.057 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-19T19:39:33.057Z,1652989173.057 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-19T19:39:37.482Z,1652989177.482 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-05-19T19:39:37.556Z,1652989177.556 [NAL9602](ERROR): received: +CSQ:0 OK059, 2, 0, 0, 0 OK 2022-05-19T19:44:09.374Z,1652989449.374 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-05-19T19:44:33.639Z,1652989473.639 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-19T19:44:33.639Z,1652989473.639 [Default:CheckIn:C.Wait] Stopped 2022-05-19T19:44:33.639Z,1652989473.639 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-19T19:44:33.640Z,1652989473.640 [Default:CheckIn:D] Running Loop=1 2022-05-19T19:44:34.033Z,1652989474.033 [Default:CheckIn:D] Stopped 2022-05-19T19:44:34.033Z,1652989474.033 [Default:CheckIn:E] Running Loop=1 2022-05-19T19:44:34.435Z,1652989474.435 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 304.441699 min 2022-05-19T19:44:34.435Z,1652989474.435 [Default:CheckIn:E] Stopped 2022-05-19T19:44:34.435Z,1652989474.435 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-19T19:44:34.435Z,1652989474.435 [Default:CheckIn] Stopped 2022-05-19T19:44:34.435Z,1652989474.435 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-19T19:44:34.435Z,1652989474.435 [Default:CheckIn](INFO): Running loop #54 2022-05-19T19:44:34.436Z,1652989474.436 [Default:CheckIn] Running Loop=54 2022-05-19T19:44:34.436Z,1652989474.436 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-19T19:44:34.436Z,1652989474.436 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-19T19:44:36.449Z,1652989476.449 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194435.00,A,3648.17117,N,12147.28638,W,0.408,0.00,190522,,,A*7D 2022-05-19T19:44:36.451Z,1652989476.451 [NAL9602](INFO): GPS fix at 20220519T194435: (36.802853, -121.788106) 2022-05-19T19:44:36.461Z,1652989476.461 [Default:CheckIn:Read_GPS] Stopped 2022-05-19T19:44:36.461Z,1652989476.461 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-19T19:44:44.256Z,1652989484.256 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220519T144934/Courier0156.lzma 2022-05-19T19:44:45.259Z,1652989485.259 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Courier0156.lzma.bak 2022-05-19T19:44:45.259Z,1652989485.259 [DataOverHttps](INFO): SBD MOMSN=16810487 2022-05-19T19:45:04.177Z,1652989504.177 [DataOverHttps](INFO): Sending 208 bytes from file Logs/20220519T144934/Express0157.lzma 2022-05-19T19:45:05.179Z,1652989505.179 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Express0157.lzma.bak 2022-05-19T19:45:05.179Z,1652989505.179 [DataOverHttps](INFO): SBD MOMSN=16810490 2022-05-19T19:45:06.407Z,1652989506.407 [Default:CheckIn:Read_Iridium] Stopped 2022-05-19T19:45:06.407Z,1652989506.407 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-19T19:45:06.408Z,1652989506.408 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-19T19:45:08.413Z,1652989508.413 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-19T19:50:07.024Z,1652989807.024 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-19T19:50:07.024Z,1652989807.024 [Default:CheckIn:C.Wait] Stopped 2022-05-19T19:50:07.024Z,1652989807.024 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-19T19:50:07.024Z,1652989807.024 [Default:CheckIn:D] Running Loop=1 2022-05-19T19:50:07.446Z,1652989807.446 [Default:CheckIn:D] Stopped 2022-05-19T19:50:07.446Z,1652989807.446 [Default:CheckIn:E] Running Loop=1 2022-05-19T19:50:07.840Z,1652989807.840 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 309.998568 min 2022-05-19T19:50:07.841Z,1652989807.841 [Default:CheckIn:E] Stopped 2022-05-19T19:50:07.841Z,1652989807.841 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-19T19:50:07.841Z,1652989807.841 [Default:CheckIn] Stopped 2022-05-19T19:50:07.841Z,1652989807.841 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-19T19:50:07.841Z,1652989807.841 [Default:CheckIn](INFO): Running loop #55 2022-05-19T19:50:07.841Z,1652989807.841 [Default:CheckIn] Running Loop=55 2022-05-19T19:50:07.841Z,1652989807.841 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-19T19:50:07.841Z,1652989807.841 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-19T19:50:09.843Z,1652989809.843 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,195009.00,A,3648.16661,N,12147.28124,W,0.408,67.90,190522,,,A*42 2022-05-19T19:50:09.846Z,1652989809.846 [NAL9602](INFO): GPS fix at 20220519T195009: (36.802777, -121.788021) 2022-05-19T19:50:09.861Z,1652989809.861 [Default:CheckIn:Read_GPS] Stopped 2022-05-19T19:50:09.861Z,1652989809.861 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-19T19:50:17.592Z,1652989817.592 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220519T144934/Courier0159.lzma 2022-05-19T19:50:18.595Z,1652989818.595 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Courier0159.lzma.bak 2022-05-19T19:50:18.596Z,1652989818.596 [DataOverHttps](INFO): SBD MOMSN=16810500 2022-05-19T19:50:37.444Z,1652989837.444 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20220519T144934/Express0160.lzma 2022-05-19T19:50:38.447Z,1652989838.447 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Express0160.lzma.bak 2022-05-19T19:50:38.447Z,1652989838.447 [DataOverHttps](INFO): SBD MOMSN=16810503 2022-05-19T19:50:39.784Z,1652989839.784 [Default:CheckIn:Read_Iridium] Stopped 2022-05-19T19:50:39.784Z,1652989839.784 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-19T19:50:39.784Z,1652989839.784 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-19T19:50:40.585Z,1652989840.585 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-05-19T19:50:40.664Z,1652989840.664 [NAL9602](ERROR): received: +CSQ:0 OK059, 2, 0, 0, 0 OK 2022-05-19T19:55:12.566Z,1652990112.566 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-05-19T19:55:40.455Z,1652990140.455 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-19T19:55:40.455Z,1652990140.455 [Default:CheckIn:C.Wait] Stopped 2022-05-19T19:55:40.455Z,1652990140.455 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-19T19:55:40.455Z,1652990140.455 [Default:CheckIn:D] Running Loop=1 2022-05-19T19:55:40.861Z,1652990140.861 [Default:CheckIn:D] Stopped 2022-05-19T19:55:40.861Z,1652990140.861 [Default:CheckIn:E] Running Loop=1 2022-05-19T19:55:41.263Z,1652990141.263 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 315.555501 min 2022-05-19T19:55:41.263Z,1652990141.263 [Default:CheckIn:E] Stopped 2022-05-19T19:55:41.263Z,1652990141.263 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-19T19:55:41.263Z,1652990141.263 [Default:CheckIn] Stopped 2022-05-19T19:55:41.263Z,1652990141.263 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-19T19:55:41.264Z,1652990141.264 [Default:CheckIn](INFO): Running loop #56 2022-05-19T19:55:41.264Z,1652990141.264 [Default:CheckIn] Running Loop=56 2022-05-19T19:55:41.264Z,1652990141.264 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-19T19:55:41.264Z,1652990141.264 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-19T19:55:43.271Z,1652990143.271 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,195542.00,A,3648.16486,N,12147.27783,W,0.408,10.19,190522,,,A*46 2022-05-19T19:55:43.273Z,1652990143.273 [NAL9602](INFO): GPS fix at 20220519T195542: (36.802748, -121.787964) 2022-05-19T19:55:43.302Z,1652990143.302 [Default:CheckIn:Read_GPS] Stopped 2022-05-19T19:55:43.302Z,1652990143.302 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-19T19:55:50.960Z,1652990150.960 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220519T144934/Courier0162.lzma 2022-05-19T19:55:51.963Z,1652990151.963 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Courier0162.lzma.bak 2022-05-19T19:55:51.963Z,1652990151.963 [DataOverHttps](INFO): SBD MOMSN=16810521 2022-05-19T19:56:07.757Z,1652990167.757 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20220519T144934/Express0163.lzma 2022-05-19T19:56:08.759Z,1652990168.759 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Express0163.lzma.bak 2022-05-19T19:56:08.759Z,1652990168.759 [DataOverHttps](INFO): SBD MOMSN=16810524 2022-05-19T19:56:09.945Z,1652990169.945 [Default:CheckIn:Read_Iridium] Stopped 2022-05-19T19:56:09.945Z,1652990169.945 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-19T19:56:09.945Z,1652990169.945 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-19T19:56:15.587Z,1652990175.587 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-19T20:01:10.639Z,1652990470.639 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-19T20:01:10.639Z,1652990470.639 [Default:CheckIn:C.Wait] Stopped 2022-05-19T20:01:10.639Z,1652990470.639 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-19T20:01:10.639Z,1652990470.639 [Default:CheckIn:D] Running Loop=1 2022-05-19T20:01:11.043Z,1652990471.043 [Default:CheckIn:D] Stopped 2022-05-19T20:01:11.043Z,1652990471.043 [Default:CheckIn:E] Running Loop=1 2022-05-19T20:01:11.444Z,1652990471.444 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 321.058529 min 2022-05-19T20:01:11.444Z,1652990471.444 [Default:CheckIn:E] Stopped 2022-05-19T20:01:11.444Z,1652990471.444 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-19T20:01:11.444Z,1652990471.444 [Default:CheckIn] Stopped 2022-05-19T20:01:11.444Z,1652990471.444 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-19T20:01:11.444Z,1652990471.444 [Default:CheckIn](INFO): Running loop #57 2022-05-19T20:01:11.445Z,1652990471.445 [Default:CheckIn] Running Loop=57 2022-05-19T20:01:11.445Z,1652990471.445 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-19T20:01:11.445Z,1652990471.445 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-19T20:01:13.459Z,1652990473.459 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200112.00,A,3648.16920,N,12147.28387,W,0.194,132.17,190522,,,A*79 2022-05-19T20:01:13.461Z,1652990473.461 [NAL9602](INFO): GPS fix at 20220519T200112: (36.802820, -121.788065) 2022-05-19T20:01:13.496Z,1652990473.496 [Default:CheckIn:Read_GPS] Stopped 2022-05-19T20:01:13.496Z,1652990473.496 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-19T20:01:21.028Z,1652990481.028 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20220519T144934/Courier0165.lzma 2022-05-19T20:01:22.031Z,1652990482.031 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Courier0165.lzma.bak 2022-05-19T20:01:22.032Z,1652990482.032 [DataOverHttps](INFO): SBD MOMSN=16810609 2022-05-19T20:01:37.771Z,1652990497.771 [DataOverHttps](INFO): Sending 132 bytes from file Logs/20220519T144934/Express0166.lzma 2022-05-19T20:01:38.771Z,1652990498.771 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Express0166.lzma.bak 2022-05-19T20:01:38.771Z,1652990498.771 [DataOverHttps](INFO): SBD MOMSN=16810612 2022-05-19T20:01:40.137Z,1652990500.137 [Default:CheckIn:Read_Iridium] Stopped 2022-05-19T20:01:40.137Z,1652990500.137 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-19T20:01:40.137Z,1652990500.137 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-19T20:01:44.158Z,1652990504.158 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-05-19T20:01:44.236Z,1652990504.236 [NAL9602](ERROR): received: +CSQ:0 OK059, 2, 0, 0, 0 OK 2022-05-19T20:06:15.293Z,1652990775.293 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-05-19T20:06:40.789Z,1652990800.789 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-19T20:06:40.789Z,1652990800.789 [Default:CheckIn:C.Wait] Stopped 2022-05-19T20:06:40.789Z,1652990800.789 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-19T20:06:40.789Z,1652990800.789 [Default:CheckIn:D] Running Loop=1 2022-05-19T20:06:41.186Z,1652990801.186 [Default:CheckIn:D] Stopped 2022-05-19T20:06:41.186Z,1652990801.186 [Default:CheckIn:E] Running Loop=1 2022-05-19T20:06:41.601Z,1652990801.601 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 326.560905 min 2022-05-19T20:06:41.601Z,1652990801.601 [Default:CheckIn:E] Stopped 2022-05-19T20:06:41.602Z,1652990801.602 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-19T20:06:41.602Z,1652990801.602 [Default:CheckIn] Stopped 2022-05-19T20:06:41.602Z,1652990801.602 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-19T20:06:41.602Z,1652990801.602 [Default:CheckIn](INFO): Running loop #58 2022-05-19T20:06:41.602Z,1652990801.602 [Default:CheckIn] Running Loop=58 2022-05-19T20:06:41.602Z,1652990801.602 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-19T20:06:41.602Z,1652990801.602 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-19T20:06:43.608Z,1652990803.608 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200642.00,A,3648.16771,N,12147.28275,W,0.525,291.26,190522,,,A*7B 2022-05-19T20:06:43.620Z,1652990803.620 [NAL9602](INFO): GPS fix at 20220519T200642: (36.802795, -121.788046) 2022-05-19T20:06:43.631Z,1652990803.631 [Default:CheckIn:Read_GPS] Stopped 2022-05-19T20:06:43.631Z,1652990803.631 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-19T20:06:53.080Z,1652990813.080 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20220519T144934/Courier0168.lzma 2022-05-19T20:06:54.083Z,1652990814.083 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Courier0168.lzma.bak 2022-05-19T20:06:54.083Z,1652990814.083 [DataOverHttps](INFO): SBD MOMSN=16810647 2022-05-19T20:07:11.021Z,1652990831.021 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20220519T144934/Express0169.lzma 2022-05-19T20:07:12.023Z,1652990832.023 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Express0169.lzma.bak 2022-05-19T20:07:12.023Z,1652990832.023 [DataOverHttps](INFO): SBD MOMSN=16810650 2022-05-19T20:07:13.198Z,1652990833.198 [Default:CheckIn:Read_Iridium] Stopped 2022-05-19T20:07:13.198Z,1652990833.198 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-19T20:07:13.199Z,1652990833.199 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-19T20:07:16.405Z,1652990836.405 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-19T20:08:31.202Z,1652990911.202 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-05-19T20:08:46.153Z,1652990926.153 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-05-19T20:09:01.975Z,1652990941.975 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-05-19T20:09:17.732Z,1652990957.732 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-05-19T20:09:33.082Z,1652990973.082 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-05-19T20:09:48.032Z,1652990988.032 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-05-19T20:10:02.978Z,1652991002.978 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-05-19T20:10:17.937Z,1652991017.937 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-05-19T20:10:33.342Z,1652991033.342 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-05-19T20:10:48.731Z,1652991048.731 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2022-05-19T20:11:03.311Z,1652991063.311 [BPC1](INFO): Calculating totals. Valid battery stick count: 54. Valid reserve battery stick count: 6. 2022-05-19T20:11:03.313Z,1652991063.313 [BPC1](INFO): Received data from all battery sticks. 2022-05-19T20:12:13.612Z,1652991133.612 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-19T20:12:13.612Z,1652991133.612 [Default:CheckIn:C.Wait] Stopped 2022-05-19T20:12:13.612Z,1652991133.612 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-19T20:12:13.612Z,1652991133.612 [Default:CheckIn:D] Running Loop=1 2022-05-19T20:12:14.029Z,1652991134.029 [Default:CheckIn:D] Stopped 2022-05-19T20:12:14.029Z,1652991134.029 [Default:CheckIn:E] Running Loop=1 2022-05-19T20:12:14.423Z,1652991134.423 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 332.108301 min 2022-05-19T20:12:14.424Z,1652991134.424 [Default:CheckIn:E] Stopped 2022-05-19T20:12:14.424Z,1652991134.424 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-19T20:12:14.424Z,1652991134.424 [Default:CheckIn] Stopped 2022-05-19T20:12:14.424Z,1652991134.424 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-19T20:12:14.424Z,1652991134.424 [Default:CheckIn](INFO): Running loop #59 2022-05-19T20:12:14.424Z,1652991134.424 [Default:CheckIn] Running Loop=59 2022-05-19T20:12:14.424Z,1652991134.424 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-19T20:12:14.424Z,1652991134.424 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-19T20:12:16.432Z,1652991136.432 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,201215.00,A,3648.17038,N,12147.27749,W,0.408,302.71,190522,,,A*75 2022-05-19T20:12:16.434Z,1652991136.434 [NAL9602](INFO): GPS fix at 20220519T201215: (36.802840, -121.787958) 2022-05-19T20:12:16.444Z,1652991136.444 [Default:CheckIn:Read_GPS] Stopped 2022-05-19T20:12:16.444Z,1652991136.444 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-19T20:12:26.928Z,1652991146.928 [DataOverHttps](INFO): Sending 85 bytes from file Logs/20220519T144934/Courier0171.lzma 2022-05-19T20:12:27.931Z,1652991147.931 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Courier0171.lzma.bak 2022-05-19T20:12:27.931Z,1652991147.931 [DataOverHttps](INFO): SBD MOMSN=16810687 2022-05-19T20:12:43.844Z,1652991163.844 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20220519T144934/Express0172.lzma 2022-05-19T20:12:44.847Z,1652991164.847 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Express0172.lzma.bak 2022-05-19T20:12:44.847Z,1652991164.847 [DataOverHttps](INFO): SBD MOMSN=16810690 2022-05-19T20:12:46.032Z,1652991166.032 [Default:CheckIn:Read_Iridium] Stopped 2022-05-19T20:12:46.032Z,1652991166.032 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-19T20:12:46.032Z,1652991166.032 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-19T20:12:47.230Z,1652991167.230 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-05-19T20:12:47.308Z,1652991167.308 [NAL9602](ERROR): received: +CSQ:0 OK059, 2, 0, 0, 0 OK 2022-05-19T20:17:18.159Z,1652991438.159 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-05-19T20:17:46.466Z,1652991466.466 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-19T20:17:46.466Z,1652991466.466 [Default:CheckIn:C.Wait] Stopped 2022-05-19T20:17:46.466Z,1652991466.466 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-19T20:17:46.466Z,1652991466.466 [Default:CheckIn:D] Running Loop=1 2022-05-19T20:17:46.859Z,1652991466.859 [Default:CheckIn:D] Stopped 2022-05-19T20:17:46.859Z,1652991466.859 [Default:CheckIn:E] Running Loop=1 2022-05-19T20:17:47.258Z,1652991467.258 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 337.655436 min 2022-05-19T20:17:47.258Z,1652991467.258 [Default:CheckIn:E] Stopped 2022-05-19T20:17:47.258Z,1652991467.258 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-19T20:17:47.258Z,1652991467.258 [Default:CheckIn] Stopped 2022-05-19T20:17:47.258Z,1652991467.258 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-19T20:17:47.258Z,1652991467.258 [Default:CheckIn](INFO): Running loop #60 2022-05-19T20:17:47.258Z,1652991467.258 [Default:CheckIn] Running Loop=60 2022-05-19T20:17:47.259Z,1652991467.259 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-19T20:17:47.259Z,1652991467.259 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-19T20:17:49.275Z,1652991469.275 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,201748.00,A,3648.16874,N,12147.28165,W,1.147,302.71,190522,,,A*71 2022-05-19T20:17:49.277Z,1652991469.277 [NAL9602](INFO): GPS fix at 20220519T201748: (36.802812, -121.788027) 2022-05-19T20:17:49.302Z,1652991469.302 [Default:CheckIn:Read_GPS] Stopped 2022-05-19T20:17:49.302Z,1652991469.302 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-19T20:17:56.160Z,1652991476.160 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20220519T144934/Courier0174.lzma 2022-05-19T20:17:57.163Z,1652991477.163 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Courier0174.lzma.bak 2022-05-19T20:17:57.163Z,1652991477.163 [DataOverHttps](INFO): SBD MOMSN=16810709 2022-05-19T20:18:13.109Z,1652991493.109 [DataOverHttps](INFO): Sending 208 bytes from file Logs/20220519T144934/Express0175.lzma 2022-05-19T20:18:14.111Z,1652991494.111 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Express0175.lzma.bak 2022-05-19T20:18:14.111Z,1652991494.111 [DataOverHttps](INFO): SBD MOMSN=16810712 2022-05-19T20:18:15.608Z,1652991495.608 [Default:CheckIn:Read_Iridium] Stopped 2022-05-19T20:18:15.608Z,1652991495.608 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-19T20:18:15.608Z,1652991495.608 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-19T20:18:21.681Z,1652991501.681 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-19T20:23:16.088Z,1652991796.088 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-19T20:23:16.089Z,1652991796.089 [Default:CheckIn:C.Wait] Stopped 2022-05-19T20:23:16.089Z,1652991796.089 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-19T20:23:16.089Z,1652991796.089 [Default:CheckIn:D] Running Loop=1 2022-05-19T20:23:16.505Z,1652991796.505 [Default:CheckIn:D] Stopped 2022-05-19T20:23:16.505Z,1652991796.505 [Default:CheckIn:E] Running Loop=1 2022-05-19T20:23:16.893Z,1652991796.893 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 343.149544 min 2022-05-19T20:23:16.893Z,1652991796.893 [Default:CheckIn:E] Stopped 2022-05-19T20:23:16.893Z,1652991796.893 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-19T20:23:16.894Z,1652991796.894 [Default:CheckIn] Stopped 2022-05-19T20:23:16.894Z,1652991796.894 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-19T20:23:16.894Z,1652991796.894 [Default:CheckIn](INFO): Running loop #61 2022-05-19T20:23:16.894Z,1652991796.894 [Default:CheckIn] Running Loop=61 2022-05-19T20:23:16.894Z,1652991796.894 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-19T20:23:16.894Z,1652991796.894 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-19T20:23:18.907Z,1652991798.907 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,202318.00,A,3648.16871,N,12147.27983,W,0.428,0.00,190522,,,A*73 2022-05-19T20:23:18.909Z,1652991798.909 [NAL9602](INFO): GPS fix at 20220519T202318: (36.802812, -121.787997) 2022-05-19T20:23:18.920Z,1652991798.920 [Default:CheckIn:Read_GPS] Stopped 2022-05-19T20:23:18.920Z,1652991798.920 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-19T20:23:25.904Z,1652991805.904 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220519T144934/Courier0177.lzma 2022-05-19T20:23:26.907Z,1652991806.907 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Courier0177.lzma.bak 2022-05-19T20:23:26.907Z,1652991806.907 [DataOverHttps](INFO): SBD MOMSN=16810747 2022-05-19T20:23:42.908Z,1652991822.908 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20220519T144934/Express0178.lzma 2022-05-19T20:23:43.911Z,1652991823.911 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Express0178.lzma.bak 2022-05-19T20:23:43.911Z,1652991823.911 [DataOverHttps](INFO): SBD MOMSN=16810751 2022-05-19T20:23:45.171Z,1652991825.171 [Default:CheckIn:Read_Iridium] Stopped 2022-05-19T20:23:45.171Z,1652991825.171 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-19T20:23:45.172Z,1652991825.172 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-19T20:23:49.606Z,1652991829.606 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-05-19T20:23:49.688Z,1652991829.688 [NAL9602](ERROR): received: +CSQ:0 OK059, 2, 0, 0, 0 OK 2022-05-19T20:28:02.735Z,1652992082.735 [NAL9602](INFO): SBD MO Status=2, MOMSN=33059, MT Status=2, MTMSN=0 2022-05-19T20:28:02.735Z,1652992082.735 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-05-19T20:28:21.326Z,1652992101.326 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-05-19T20:28:45.636Z,1652992125.636 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-19T20:28:45.636Z,1652992125.636 [Default:CheckIn:C.Wait] Stopped 2022-05-19T20:28:45.637Z,1652992125.637 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-19T20:28:45.637Z,1652992125.637 [Default:CheckIn:D] Running Loop=1 2022-05-19T20:28:46.050Z,1652992126.050 [Default:CheckIn:D] Stopped 2022-05-19T20:28:46.050Z,1652992126.050 [Default:CheckIn:E] Running Loop=1 2022-05-19T20:28:46.419Z,1652992126.419 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 348.641960 min 2022-05-19T20:28:46.419Z,1652992126.419 [Default:CheckIn:E] Stopped 2022-05-19T20:28:46.419Z,1652992126.419 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-19T20:28:46.419Z,1652992126.419 [Default:CheckIn] Stopped 2022-05-19T20:28:46.419Z,1652992126.419 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-19T20:28:46.419Z,1652992126.419 [Default:CheckIn](INFO): Running loop #62 2022-05-19T20:28:46.420Z,1652992126.420 [Default:CheckIn] Running Loop=62 2022-05-19T20:28:46.420Z,1652992126.420 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-19T20:28:46.420Z,1652992126.420 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-19T20:28:48.426Z,1652992128.426 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,202847.00,A,3648.16187,N,12147.28179,W,0.136,0.00,190522,,,A*7A 2022-05-19T20:28:48.429Z,1652992128.429 [NAL9602](INFO): GPS fix at 20220519T202847: (36.802698, -121.788030) 2022-05-19T20:28:48.447Z,1652992128.447 [Default:CheckIn:Read_GPS] Stopped 2022-05-19T20:28:48.447Z,1652992128.447 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-19T20:28:58.128Z,1652992138.128 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220519T144934/Courier0180.lzma 2022-05-19T20:28:59.131Z,1652992139.131 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Courier0180.lzma.bak 2022-05-19T20:28:59.131Z,1652992139.131 [DataOverHttps](INFO): SBD MOMSN=16810758 2022-05-19T20:29:14.893Z,1652992154.893 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20220519T144934/Express0181.lzma 2022-05-19T20:29:15.895Z,1652992155.895 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Express0181.lzma.bak 2022-05-19T20:29:15.895Z,1652992155.895 [DataOverHttps](INFO): SBD MOMSN=16810761 2022-05-19T20:29:17.429Z,1652992157.429 [Default:CheckIn:Read_Iridium] Stopped 2022-05-19T20:29:17.429Z,1652992157.429 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-19T20:29:17.429Z,1652992157.429 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-19T20:29:20.637Z,1652992160.637 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-19T20:34:17.858Z,1652992457.858 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-19T20:34:17.858Z,1652992457.858 [Default:CheckIn:C.Wait] Stopped 2022-05-19T20:34:17.858Z,1652992457.858 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-19T20:34:17.858Z,1652992457.858 [Default:CheckIn:D] Running Loop=1 2022-05-19T20:34:18.220Z,1652992458.220 [Default:CheckIn:D] Stopped 2022-05-19T20:34:18.220Z,1652992458.220 [Default:CheckIn:E] Running Loop=1 2022-05-19T20:34:18.630Z,1652992458.630 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 354.178125 min 2022-05-19T20:34:18.630Z,1652992458.630 [Default:CheckIn:E] Stopped 2022-05-19T20:34:18.630Z,1652992458.630 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-19T20:34:18.630Z,1652992458.630 [Default:CheckIn] Stopped 2022-05-19T20:34:18.630Z,1652992458.630 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-19T20:34:18.630Z,1652992458.630 [Default:CheckIn](INFO): Running loop #63 2022-05-19T20:34:18.630Z,1652992458.630 [Default:CheckIn] Running Loop=63 2022-05-19T20:34:18.631Z,1652992458.631 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-19T20:34:18.631Z,1652992458.631 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-19T20:34:20.635Z,1652992460.635 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,203419.00,A,3648.16487,N,12147.28175,W,0.564,0.00,190522,,,A*76 2022-05-19T20:34:20.638Z,1652992460.638 [NAL9602](INFO): GPS fix at 20220519T203419: (36.802748, -121.788029) 2022-05-19T20:34:20.654Z,1652992460.654 [Default:CheckIn:Read_GPS] Stopped 2022-05-19T20:34:20.654Z,1652992460.654 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-19T20:34:30.008Z,1652992470.008 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220519T144934/Courier0183.lzma 2022-05-19T20:34:31.011Z,1652992471.011 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Courier0183.lzma.bak 2022-05-19T20:34:31.011Z,1652992471.011 [DataOverHttps](INFO): SBD MOMSN=16810773 2022-05-19T20:34:46.757Z,1652992486.757 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20220519T144934/Express0184.lzma 2022-05-19T20:34:47.759Z,1652992487.759 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Express0184.lzma.bak 2022-05-19T20:34:47.759Z,1652992487.759 [DataOverHttps](INFO): SBD MOMSN=16810776 2022-05-19T20:34:49.040Z,1652992489.040 [Default:CheckIn:Read_Iridium] Stopped 2022-05-19T20:34:49.040Z,1652992489.040 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-19T20:34:49.040Z,1652992489.040 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-19T20:34:51.446Z,1652992491.446 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-05-19T20:34:51.529Z,1652992491.529 [NAL9602](ERROR): received: +CSQ:0 OK059, 2, 0, 0, 0 OK 2022-05-19T20:36:47.946Z,1652992607.946 [NAL9602](INFO): SBD MO Status=2, MOMSN=33059, MT Status=2, MTMSN=0 2022-05-19T20:36:47.947Z,1652992607.947 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-05-19T20:38:21.703Z,1652992701.703 [NAL9602](INFO): SBD MO Status=2, MOMSN=33059, MT Status=2, MTMSN=0 2022-05-19T20:38:21.703Z,1652992701.703 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-05-19T20:39:23.113Z,1652992763.113 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-05-19T20:39:49.787Z,1652992789.787 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-19T20:39:49.787Z,1652992789.787 [Default:CheckIn:C.Wait] Stopped 2022-05-19T20:39:49.787Z,1652992789.787 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-19T20:39:49.787Z,1652992789.787 [Default:CheckIn:D] Running Loop=1 2022-05-19T20:39:50.191Z,1652992790.191 [Default:CheckIn:D] Stopped 2022-05-19T20:39:50.191Z,1652992790.191 [Default:CheckIn:E] Running Loop=1 2022-05-19T20:39:50.607Z,1652992790.607 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 359.711003 min 2022-05-19T20:39:50.607Z,1652992790.607 [Default:CheckIn:E] Stopped 2022-05-19T20:39:50.607Z,1652992790.607 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-19T20:39:50.607Z,1652992790.607 [Default:CheckIn] Stopped 2022-05-19T20:39:50.607Z,1652992790.607 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-19T20:39:50.607Z,1652992790.607 [Default:CheckIn](INFO): Running loop #64 2022-05-19T20:39:50.607Z,1652992790.607 [Default:CheckIn] Running Loop=64 2022-05-19T20:39:50.608Z,1652992790.608 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-19T20:39:50.608Z,1652992790.608 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-19T20:39:52.607Z,1652992792.607 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,203951.00,A,3648.16889,N,12147.28070,W,0.117,6.45,190522,,,A*76 2022-05-19T20:39:52.609Z,1652992792.609 [NAL9602](INFO): GPS fix at 20220519T203951: (36.802815, -121.788012) 2022-05-19T20:39:52.638Z,1652992792.638 [Default:CheckIn:Read_GPS] Stopped 2022-05-19T20:39:52.638Z,1652992792.638 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-19T20:40:00.296Z,1652992800.296 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220519T144934/Courier0186.lzma 2022-05-19T20:40:01.299Z,1652992801.299 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Courier0186.lzma.bak 2022-05-19T20:40:01.299Z,1652992801.299 [DataOverHttps](INFO): SBD MOMSN=16810779 2022-05-19T20:40:17.009Z,1652992817.009 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20220519T144934/Express0187.lzma 2022-05-19T20:40:18.011Z,1652992818.011 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Express0187.lzma.bak 2022-05-19T20:40:18.011Z,1652992818.011 [DataOverHttps](INFO): SBD MOMSN=16810782 2022-05-19T20:40:19.341Z,1652992819.341 [Default:CheckIn:Read_Iridium] Stopped 2022-05-19T20:40:19.341Z,1652992819.341 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-19T20:40:19.342Z,1652992819.342 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-19T20:40:25.429Z,1652992825.429 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-19T20:45:20.011Z,1652993120.011 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-19T20:45:20.011Z,1652993120.011 [Default:CheckIn:C.Wait] Stopped 2022-05-19T20:45:20.012Z,1652993120.012 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-19T20:45:20.012Z,1652993120.012 [Default:CheckIn:D] Running Loop=1 2022-05-19T20:45:20.404Z,1652993120.404 [Default:CheckIn:D] Stopped 2022-05-19T20:45:20.404Z,1652993120.404 [Default:CheckIn:E] Running Loop=1 2022-05-19T20:45:20.798Z,1652993120.798 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 365.214551 min 2022-05-19T20:45:20.798Z,1652993120.798 [Default:CheckIn:E] Stopped 2022-05-19T20:45:20.798Z,1652993120.798 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-19T20:45:20.798Z,1652993120.798 [Default:CheckIn] Stopped 2022-05-19T20:45:20.798Z,1652993120.798 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-19T20:45:20.798Z,1652993120.798 [Default:CheckIn](INFO): Running loop #65 2022-05-19T20:45:20.798Z,1652993120.798 [Default:CheckIn] Running Loop=65 2022-05-19T20:45:20.798Z,1652993120.798 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-19T20:45:20.799Z,1652993120.799 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-19T20:45:22.811Z,1652993122.811 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,204522.00,A,3648.15700,N,12147.29258,W,0.855,108.16,190522,,,A*7B 2022-05-19T20:45:22.813Z,1652993122.813 [NAL9602](INFO): GPS fix at 20220519T204522: (36.802617, -121.788210) 2022-05-19T20:45:22.824Z,1652993122.824 [Default:CheckIn:Read_GPS] Stopped 2022-05-19T20:45:22.824Z,1652993122.824 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-19T20:45:30.220Z,1652993130.220 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220519T144934/Courier0189.lzma 2022-05-19T20:45:31.223Z,1652993131.223 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Courier0189.lzma.bak 2022-05-19T20:45:31.223Z,1652993131.223 [DataOverHttps](INFO): SBD MOMSN=16810792 2022-05-19T20:45:47.129Z,1652993147.129 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20220519T144934/Express0190.lzma 2022-05-19T20:45:48.131Z,1652993148.131 [DataOverHttps](INFO): Moved sent file to Logs/20220519T144934/Express0190.lzma.bak 2022-05-19T20:45:48.131Z,1652993148.131 [DataOverHttps](INFO): SBD MOMSN=16810795 2022-05-19T20:45:49.517Z,1652993149.517 [Default:CheckIn:Read_Iridium] Stopped 2022-05-19T20:45:49.517Z,1652993149.517 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-19T20:45:49.517Z,1652993149.517 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-19T20:45:53.510Z,1652993153.510 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-05-19T20:45:53.584Z,1652993153.584 [NAL9602](ERROR): received: +CSQ:0 OK059, 2, 0, 0, 0 OK 2022-05-19T20:48:59.441Z,1652993339.441 [CommandExec](IMPORTANT): got command quit 2022-05-19T20:49:00.445Z,1652993340.445 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread. 2022-05-19T20:49:00.445Z,1652993340.445 [CommandExec](INFO): Uninitializing the command executive. 2022-05-19T20:49:00.445Z,1652993340.445 [CommandExec](INFO): Uninitializing the command scheduler. 2022-05-19T20:49:00.445Z,1652993340.445 [CommandExec ThreadHandler](INFO): Thread cancelled. 2022-05-19T20:49:00.544Z,1652993340.544 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2022-05-19T20:49:00.545Z,1652993340.545 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2022-05-19T20:49:00.545Z,1652993340.545 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2022-05-19T20:49:00.545Z,1652993340.545 [NavChartDb](INFO): Join timeout helper Thread ID is 5300 2022-05-19T20:49:00.913Z,1652993340.913 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2022-05-19T20:49:00.913Z,1652993340.913 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2022-05-19T20:49:00.929Z,1652993340.929 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2022-05-19T20:49:00.929Z,1652993340.929 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2022-05-19T20:49:00.929Z,1652993340.929 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 5301 2022-05-19T20:49:00.981Z,1652993340.981 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2022-05-19T20:49:00.981Z,1652993340.981 [WetLabsBB2FL](INFO): Powering down 2022-05-19T20:49:00.982Z,1652993340.982 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2022-05-19T20:49:00.989Z,1652993340.989 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2022-05-19T20:49:00.989Z,1652993340.989 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2022-05-19T20:49:00.989Z,1652993340.989 [CTD_Seabird](INFO): Join timeout helper Thread ID is 5302 2022-05-19T20:49:01.473Z,1652993341.473 [CTD_Seabird](INFO): Powering down 2022-05-19T20:49:01.490Z,1652993341.490 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread. 2022-05-19T20:49:01.491Z,1652993341.491 [CTD_Seabird](INFO): Powering down 2022-05-19T20:49:01.505Z,1652993341.505 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2022-05-19T20:49:01.510Z,1652993341.510 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2022-05-19T20:49:01.510Z,1652993341.510 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2022-05-19T20:49:01.510Z,1652993341.510 [Radio_Surface](INFO): Join timeout helper Thread ID is 5303 2022-05-19T20:49:01.617Z,1652993341.617 [Radio_Surface](INFO): Powering down 2022-05-19T20:49:01.618Z,1652993341.618 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2022-05-19T20:49:01.618Z,1652993341.618 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2022-05-19T20:49:01.621Z,1652993341.621 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler 2022-05-19T20:49:01.621Z,1652993341.621 [Onboard ThreadHandler](INFO): Thread cancelled. 2022-05-19T20:49:01.621Z,1652993341.621 [Onboard](INFO): Join timeout helper Thread ID is 5304 2022-05-19T20:49:02.545Z,1652993342.545 [DataOverHttps](INFO): Radio surface powered OFF, will not connect. 2022-05-19T20:49:04.637Z,1652993344.637 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread. 2022-05-19T20:49:04.637Z,1652993344.637 [Onboard ThreadHandler](INFO): Thread cancelled. 2022-05-19T20:49:04.657Z,1652993344.657 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2022-05-19T20:49:04.657Z,1652993344.657 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2022-05-19T20:49:04.658Z,1652993344.658 [DataOverHttps](INFO): Join timeout helper Thread ID is 5305 2022-05-19T20:49:05.557Z,1652993345.557 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2022-05-19T20:49:05.557Z,1652993345.557 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2022-05-19T20:49:05.577Z,1652993345.577 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2022-05-19T20:49:05.577Z,1652993345.577 [logger ThreadHandler](INFO): Thread cancelled. 2022-05-19T20:49:05.578Z,1652993345.578 [logger](INFO): Join timeout helper Thread ID is 5306 2022-05-19T20:49:05.601Z,1652993345.601 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2022-05-19T20:49:05.601Z,1652993345.601 [logger ThreadHandler](INFO): Thread cancelled. 2022-05-19T20:49:05.617Z,1652993345.617 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2022-05-19T20:49:05.617Z,1652993345.617 [CommandLine ThreadHandler](INFO): Thread cancelled. 2022-05-19T20:49:05.618Z,1652993345.618 [CommandLine](INFO): Join timeout helper Thread ID is 5307 2022-05-19T20:49:05.629Z,1652993345.629 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2022-05-19T20:49:05.629Z,1652993345.629 [CommandLine ThreadHandler](INFO): Thread cancelled. 2022-05-19T20:49:05.637Z,1652993345.637 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler 2022-05-19T20:49:05.637Z,1652993345.637 [CommandExec ThreadHandler](INFO): Thread cancelled. 2022-05-19T20:49:05.638Z,1652993345.638 [CommandExec](INFO): Join timeout helper Thread ID is 5308 2022-05-19T20:49:05.639Z,1652993345.639 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2022-05-19T20:49:05.639Z,1652993345.639 [controlThread ThreadHandler](INFO): Thread cancelled. 2022-05-19T20:49:05.639Z,1652993345.639 [controlThread](INFO): Join timeout helper Thread ID is 5309 2022-05-19T20:49:05.809Z,1652993345.809 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2022-05-19T20:49:05.809Z,1652993345.809 [controlThread](DEBUG): Uninitializing ControlThread 2022-05-19T20:49:05.809Z,1652993345.809 [AHRS_M2](INFO): Powering down 2022-05-19T20:49:05.881Z,1652993345.881 [NAL9602](INFO): Powering down 2022-05-19T20:49:05.884Z,1652993345.884 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2022-05-19T20:49:05.885Z,1652993345.885 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2022-05-19T20:49:05.885Z,1652993345.885 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2022-05-19T20:49:05.886Z,1652993345.886 [MissionManager](INFO): Uninitializing Mission Default 2022-05-19T20:49:05.886Z,1652993345.886 [Default] Stopped 2022-05-19T20:49:05.886Z,1652993345.886 [Default](DEBUG): Aggregate::uninitialize Default 2022-05-19T20:49:05.886Z,1652993345.886 [Default:B.GoToSurface] Stopped 2022-05-19T20:49:05.886Z,1652993345.886 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2022-05-19T20:49:05.886Z,1652993345.886 [Default:CheckIn] Stopped 2022-05-19T20:49:05.886Z,1652993345.886 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-19T20:49:05.886Z,1652993345.886 [Default:CheckIn:C.Wait] Stopped 2022-05-19T20:49:05.886Z,1652993345.886 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-19T20:49:05.889Z,1652993345.889 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2022-05-19T20:49:05.889Z,1652993345.889 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2022-05-19T20:49:05.890Z,1652993345.890 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2022-05-19T20:49:05.890Z,1652993345.890 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2022-05-19T20:49:05.890Z,1652993345.890 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2022-05-19T20:49:05.890Z,1652993345.890 [BuoyancyServo](INFO): Powering down 2022-05-19T20:49:05.905Z,1652993345.905 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2022-05-19T20:49:05.905Z,1652993345.905 [ElevatorServo](INFO): Powering down 2022-05-19T20:49:05.906Z,1652993345.906 [MassServo](DEBUG): Uninitialize Mass Servo. 2022-05-19T20:49:05.906Z,1652993345.906 [MassServo](INFO): Powering down 2022-05-19T20:49:05.906Z,1652993345.906 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2022-05-19T20:49:05.907Z,1652993345.907 [RudderServo](INFO): Powering down 2022-05-19T20:49:05.907Z,1652993345.907 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2022-05-19T20:49:05.907Z,1652993345.907 [ThrusterServo](INFO): Powering down 2022-05-19T20:49:05.908Z,1652993345.908 [SBIT](DEBUG): Uninitialize SBIT Component. 2022-05-19T20:49:05.909Z,1652993345.909 [IBIT](DEBUG): Uninitialize IBIT Component. 2022-05-19T20:49:05.909Z,1652993345.909 [CBIT](DEBUG): Uninitialize CBIT Component. 2022-05-19T20:49:05.909Z,1652993345.909 [CBIT](DEBUG): Powering off loads. 2022-05-19T20:49:05.920Z,1652993345.920 [CBIT](DEBUG): Disabling WDT. 2022-05-19T20:49:05.932Z,1652993345.932 [CBIT](DEBUG): Opening all GF detection circuits. 2022-05-19T20:49:05.933Z,1652993345.933 [controlThread ThreadHandler](INFO): Thread cancelled. 2022-05-19T20:49:05.973Z,1652993345.973 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2022-05-19T20:49:05.976Z,1652993345.976 [Onboard ThreadHandler](INFO): Thread cancelled. 2022-05-19T20:49:05.982Z,1652993345.982 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2022-05-19T20:49:06.051Z,1652993346.051 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2022-05-19T20:49:06.054Z,1652993346.054 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2022-05-19T20:49:06.093Z,1652993346.093 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2022-05-19T20:49:06.172Z,1652993346.172 [logger ThreadHandler](INFO): Thread cancelled.