2022-01-07T18:23:28.192Z,1641579808.192 [NAL9602](INFO): Received command: restart logs 2022-01-07T18:23:28.205Z,1641579808.205 [CommandExec](IMPORTANT): got command restart logs 2022-01-07T18:23:58.805Z,1641579838.805 [NAL9602](INFO): Not Powering down - fast GPS 2022-01-07T18:24:11.976Z,1641579851.976 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-01-07T18:24:43.100Z,1641579883.100 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-01-07T18:25:14.224Z,1641579914.224 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-01-07T18:25:45.360Z,1641579945.360 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-01-07T18:26:09.456Z,1641579969.456 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.250732 2022-01-07T18:26:40.596Z,1641580000.596 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-01-07T18:26:52.175Z,1641580012.175 [NAL9602](INFO): SBD MO Status=2, MOMSN=31425, MT Status=2, MTMSN=0 2022-01-07T18:26:52.175Z,1641580012.175 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-01-07T18:27:11.728Z,1641580031.728 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-01-07T18:27:42.861Z,1641580062.861 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-01-07T18:28:14.005Z,1641580094.005 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-01-07T18:28:20.307Z,1641580100.307 [NAL9602](INFO): SBD MO Status=2, MOMSN=31425, MT Status=2, MTMSN=0 2022-01-07T18:28:20.307Z,1641580100.307 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-01-07T18:28:38.539Z,1641580118.539 [NAL9602](INFO): SBD MO Status=1, MOMSN=31425, MT Status=0, MTMSN=0 2022-01-07T18:28:38.584Z,1641580118.584 [NAL9602](INFO): Sent 39 bytes from file Logs/20220106T213029/Courier0099.lzma 2022-01-07T18:28:38.585Z,1641580118.585 [NAL9602](INFO): Packets left to send: 0 2022-01-07T18:28:45.128Z,1641580125.128 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-01-07T18:28:55.967Z,1641580135.967 [NAL9602](INFO): SBD MO Status=1, MOMSN=31426, MT Status=0, MTMSN=0 2022-01-07T18:28:56.016Z,1641580136.016 [NAL9602](INFO): Sent 147 bytes from file Logs/20220106T213029/Express0097.lzma 2022-01-07T18:28:56.016Z,1641580136.016 [NAL9602](INFO): Packets left to send: 0 2022-01-07T18:29:10.155Z,1641580150.155 [NAL9602](INFO): SBD MO Status=2, MOMSN=31427, MT Status=2, MTMSN=0 2022-01-07T18:29:10.155Z,1641580150.155 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-01-07T18:29:16.252Z,1641580156.252 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-01-07T18:29:29.599Z,1641580169.599 [NAL9602](INFO): SBD MO Status=1, MOMSN=31427, MT Status=0, MTMSN=0 2022-01-07T18:29:29.648Z,1641580169.648 [NAL9602](INFO): Sent 121 bytes from file Logs/20220106T213029/Express0100.lzma 2022-01-07T18:29:29.648Z,1641580169.648 [NAL9602](INFO): Packets left to send: 0 2022-01-07T18:29:38.891Z,1641580178.891 [NAL9602](INFO): SBD MO Status=0, MOMSN=31428, MT Status=0, MTMSN=0 2022-01-07T18:29:38.977Z,1641580178.977 [Default:CheckIn:Read_Iridium] Stopped 2022-01-07T18:29:38.977Z,1641580178.977 [Default:CheckIn:C.Wait] Running Loop=1 2022-01-07T18:29:38.978Z,1641580178.978 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-01-07T18:29:47.376Z,1641580187.376 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-01-07T18:30:09.589Z,1641580209.589 [NAL9602](INFO): Not Powering down - fast GPS 2022-01-07T18:30:18.528Z,1641580218.528 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-01-07T18:30:49.652Z,1641580249.652 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-01-07T18:31:20.796Z,1641580280.796 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-01-07T18:31:51.952Z,1641580311.952 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-01-07T18:32:23.088Z,1641580343.088 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-01-07T18:32:54.212Z,1641580374.212 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-01-07T18:33:25.364Z,1641580405.364 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-01-07T18:33:56.500Z,1641580436.500 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-01-07T18:34:27.630Z,1641580467.630 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-01-07T18:34:39.479Z,1641580479.479 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-01-07T18:34:39.479Z,1641580479.479 [Default:CheckIn:C.Wait] Stopped 2022-01-07T18:34:39.480Z,1641580479.480 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-01-07T18:34:39.480Z,1641580479.480 [Default:CheckIn:D] Running Loop=1 2022-01-07T18:34:39.887Z,1641580479.887 [Default:CheckIn:D] Stopped 2022-01-07T18:34:39.887Z,1641580479.887 [Default:CheckIn:E] Running Loop=1 2022-01-07T18:34:40.284Z,1641580480.284 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 31.377311 min 2022-01-07T18:34:40.284Z,1641580480.284 [Default:CheckIn:E] Stopped 2022-01-07T18:34:40.284Z,1641580480.284 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-01-07T18:34:40.284Z,1641580480.284 [Default:CheckIn] Stopped 2022-01-07T18:34:40.285Z,1641580480.285 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-01-07T18:34:40.285Z,1641580480.285 [Default:CheckIn](INFO): Running loop #5 2022-01-07T18:34:40.285Z,1641580480.285 [Default:CheckIn] Running Loop=5 2022-01-07T18:34:40.285Z,1641580480.285 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-01-07T18:34:40.285Z,1641580480.285 [Default:CheckIn:Read_GPS] Running Loop=1 2022-01-07T18:34:42.295Z,1641580482.295 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183441.00,A,3648.59130,N,12149.21918,W,4.937,105.99,070122,,,D*72 2022-01-07T18:34:42.298Z,1641580482.298 [NAL9602](INFO): GPS fix at 20220107T183441: (36.809855, -121.820320) 2022-01-07T18:34:42.309Z,1641580482.309 [Default:CheckIn:Read_GPS] Stopped 2022-01-07T18:34:42.309Z,1641580482.309 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-01-07T18:34:58.752Z,1641580498.752 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-01-07T18:35:07.799Z,1641580507.799 [NAL9602](INFO): SBD MO Status=1, MOMSN=31429, MT Status=0, MTMSN=0 2022-01-07T18:35:07.860Z,1641580507.860 [NAL9602](INFO): Sent 268 bytes from file Logs/20220107T182328/Courier0000.lzma 2022-01-07T18:35:07.860Z,1641580507.860 [NAL9602](INFO): Packets left to send: 0 2022-01-07T18:35:23.203Z,1641580523.203 [NAL9602](INFO): SBD MO Status=2, MOMSN=31430, MT Status=2, MTMSN=0 2022-01-07T18:35:23.203Z,1641580523.203 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-01-07T18:35:29.908Z,1641580529.908 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-01-07T18:35:58.481Z,1641580558.481 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003244 2022-01-07T18:36:06.088Z,1641580566.088 [DataOverHttps](INFO): Sending 397 bytes from file Logs/20220107T182328/Express0001.lzma 2022-01-07T18:36:07.090Z,1641580567.090 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Express0001.lzma.bak 2022-01-07T18:36:07.090Z,1641580567.090 [DataOverHttps](INFO): SBD MOMSN=16416484 2022-01-07T18:36:08.172Z,1641580568.172 [Default:CheckIn:Read_Iridium] Stopped 2022-01-07T18:36:08.172Z,1641580568.172 [Default:CheckIn:C.Wait] Running Loop=1 2022-01-07T18:36:08.172Z,1641580568.172 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-01-07T18:36:10.159Z,1641580570.159 [NAL9602](INFO): SBD MO Status=2, MOMSN=31430, MT Status=2, MTMSN=0 2022-01-07T18:36:10.160Z,1641580570.160 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-01-07T18:36:40.825Z,1641580600.825 [NAL9602](INFO): Not Powering down - fast GPS 2022-01-07T18:41:08.761Z,1641580868.761 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-01-07T18:41:08.761Z,1641580868.761 [Default:CheckIn:C.Wait] Stopped 2022-01-07T18:41:08.761Z,1641580868.761 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-01-07T18:41:08.762Z,1641580868.762 [Default:CheckIn:D] Running Loop=1 2022-01-07T18:41:09.113Z,1641580869.113 [Default:CheckIn:D] Stopped 2022-01-07T18:41:09.113Z,1641580869.113 [Default:CheckIn:E] Running Loop=1 2022-01-07T18:41:09.531Z,1641580869.531 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 37.864408 min 2022-01-07T18:41:09.531Z,1641580869.531 [Default:CheckIn:E] Stopped 2022-01-07T18:41:09.531Z,1641580869.531 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-01-07T18:41:09.531Z,1641580869.531 [Default:CheckIn] Stopped 2022-01-07T18:41:09.531Z,1641580869.531 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-01-07T18:41:09.532Z,1641580869.532 [Default:CheckIn](INFO): Running loop #6 2022-01-07T18:41:09.532Z,1641580869.532 [Default:CheckIn] Running Loop=6 2022-01-07T18:41:09.532Z,1641580869.532 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-01-07T18:41:09.532Z,1641580869.532 [Default:CheckIn:Read_GPS] Running Loop=1 2022-01-07T18:41:11.531Z,1641580871.531 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184110.00,A,3648.39739,N,12148.59881,W,5.559,105.98,070122,,,D*76 2022-01-07T18:41:11.534Z,1641580871.534 [NAL9602](INFO): GPS fix at 20220107T184110: (36.806623, -121.809980) 2022-01-07T18:41:11.545Z,1641580871.545 [Default:CheckIn:Read_GPS] Stopped 2022-01-07T18:41:11.546Z,1641580871.546 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-01-07T18:41:18.647Z,1641580878.647 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220107T182328/Courier0003.lzma 2022-01-07T18:41:19.650Z,1641580879.650 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Courier0003.lzma.bak 2022-01-07T18:41:19.650Z,1641580879.650 [DataOverHttps](INFO): SBD MOMSN=16416493 2022-01-07T18:41:35.564Z,1641580895.564 [DataOverHttps](INFO): Sending 144 bytes from file Logs/20220107T182328/Express0004.lzma 2022-01-07T18:41:36.566Z,1641580896.566 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Express0004.lzma.bak 2022-01-07T18:41:36.566Z,1641580896.566 [DataOverHttps](INFO): SBD MOMSN=16416497 2022-01-07T18:41:37.796Z,1641580897.796 [Default:CheckIn:Read_Iridium] Stopped 2022-01-07T18:41:37.796Z,1641580897.796 [Default:CheckIn:C.Wait] Running Loop=1 2022-01-07T18:41:37.796Z,1641580897.796 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-01-07T18:41:38.192Z,1641580898.192 [NAL9602](INFO): SBD MO Status=1, MOMSN=31430, MT Status=0, MTMSN=0 2022-01-07T18:41:38.192Z,1641580898.192 [NAL9602](INFO): No messages in MT queue 2022-01-07T18:42:08.893Z,1641580928.893 [NAL9602](INFO): Not Powering down - fast GPS 2022-01-07T18:46:38.283Z,1641581198.283 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-01-07T18:46:38.283Z,1641581198.283 [Default:CheckIn:C.Wait] Stopped 2022-01-07T18:46:38.283Z,1641581198.283 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-01-07T18:46:38.283Z,1641581198.283 [Default:CheckIn:D] Running Loop=1 2022-01-07T18:46:38.699Z,1641581198.699 [Default:CheckIn:D] Stopped 2022-01-07T18:46:38.699Z,1641581198.699 [Default:CheckIn:E] Running Loop=1 2022-01-07T18:46:39.096Z,1641581199.096 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 43.357511 min 2022-01-07T18:46:39.096Z,1641581199.096 [Default:CheckIn:E] Stopped 2022-01-07T18:46:39.096Z,1641581199.096 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-01-07T18:46:39.096Z,1641581199.096 [Default:CheckIn] Stopped 2022-01-07T18:46:39.096Z,1641581199.096 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-01-07T18:46:39.097Z,1641581199.097 [Default:CheckIn](INFO): Running loop #7 2022-01-07T18:46:39.097Z,1641581199.097 [Default:CheckIn] Running Loop=7 2022-01-07T18:46:39.097Z,1641581199.097 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-01-07T18:46:39.097Z,1641581199.097 [Default:CheckIn:Read_GPS] Running Loop=1 2022-01-07T18:46:41.106Z,1641581201.106 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184640.00,A,3648.27929,N,12148.04394,W,4.937,109.95,070122,,,D*77 2022-01-07T18:46:41.108Z,1641581201.108 [NAL9602](INFO): GPS fix at 20220107T184640: (36.804655, -121.800732) 2022-01-07T18:46:41.119Z,1641581201.119 [Default:CheckIn:Read_GPS] Stopped 2022-01-07T18:46:41.120Z,1641581201.120 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-01-07T18:46:49.198Z,1641581209.198 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20220107T182328/Courier0006.lzma 2022-01-07T18:46:50.200Z,1641581210.200 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Courier0006.lzma.bak 2022-01-07T18:46:50.200Z,1641581210.200 [DataOverHttps](INFO): SBD MOMSN=16416501 2022-01-07T18:46:59.330Z,1641581219.330 [NAL9602](INFO): SBD MO Status=1, MOMSN=31431, MT Status=0, MTMSN=0 2022-01-07T18:46:59.330Z,1641581219.330 [NAL9602](INFO): No messages in MT queue 2022-01-07T18:47:08.703Z,1641581228.703 [DataOverHttps](INFO): Sending 145 bytes from file Logs/20220107T182328/Express0007.lzma 2022-01-07T18:47:09.704Z,1641581229.704 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Express0007.lzma.bak 2022-01-07T18:47:09.704Z,1641581229.704 [DataOverHttps](INFO): SBD MOMSN=16416504 2022-01-07T18:47:11.059Z,1641581231.059 [Default:CheckIn:Read_Iridium] Stopped 2022-01-07T18:47:11.059Z,1641581231.059 [Default:CheckIn:C.Wait] Running Loop=1 2022-01-07T18:47:11.059Z,1641581231.059 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-01-07T18:47:30.033Z,1641581250.033 [NAL9602](INFO): Not Powering down - fast GPS 2022-01-07T18:49:49.460Z,1641581389.460 [CBIT](IMPORTANT): Beginning ground fault scan 2022-01-07T18:50:00.411Z,1641581400.411 [CBIT](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): -0.002161 CHAN A1 (24V): -0.180438 CHAN A2 (12V): -0.002123 CHAN A3 (5V): -0.001377 CHAN B0 (3.3V): -0.000286 CHAN B1 (3.15aV): 0.000016 CHAN B2 (3.15bV): -0.000416 CHAN B3 (GND): -0.000032 OPEN: -0.000470 Full Scale: +/- 1 mA 2022-01-07T18:52:11.697Z,1641581531.697 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-01-07T18:52:11.697Z,1641581531.697 [Default:CheckIn:C.Wait] Stopped 2022-01-07T18:52:11.697Z,1641581531.697 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-01-07T18:52:11.698Z,1641581531.698 [Default:CheckIn:D] Running Loop=1 2022-01-07T18:52:12.105Z,1641581532.105 [Default:CheckIn:D] Stopped 2022-01-07T18:52:12.105Z,1641581532.105 [Default:CheckIn:E] Running Loop=1 2022-01-07T18:52:12.512Z,1641581532.512 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 48.914266 min 2022-01-07T18:52:12.512Z,1641581532.512 [Default:CheckIn:E] Stopped 2022-01-07T18:52:12.512Z,1641581532.512 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-01-07T18:52:12.513Z,1641581532.513 [Default:CheckIn] Stopped 2022-01-07T18:52:12.513Z,1641581532.513 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-01-07T18:52:12.513Z,1641581532.513 [Default:CheckIn](INFO): Running loop #8 2022-01-07T18:52:12.513Z,1641581532.513 [Default:CheckIn] Running Loop=8 2022-01-07T18:52:12.513Z,1641581532.513 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-01-07T18:52:12.513Z,1641581532.513 [Default:CheckIn:Read_GPS] Running Loop=1 2022-01-07T18:52:14.513Z,1641581534.513 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185213.00,A,3648.33703,N,12147.47390,W,5.695,53.20,070122,,,D*4D 2022-01-07T18:52:14.516Z,1641581534.516 [NAL9602](INFO): GPS fix at 20220107T185213: (36.805617, -121.791232) 2022-01-07T18:52:14.528Z,1641581534.528 [Default:CheckIn:Read_GPS] Stopped 2022-01-07T18:52:14.528Z,1641581534.528 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-01-07T18:52:22.306Z,1641581542.306 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220107T182328/Courier0009.lzma 2022-01-07T18:52:23.308Z,1641581543.308 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Courier0009.lzma.bak 2022-01-07T18:52:23.308Z,1641581543.308 [DataOverHttps](INFO): SBD MOMSN=16416508 2022-01-07T18:52:39.251Z,1641581559.251 [DataOverHttps](INFO): Sending 341 bytes from file Logs/20220107T182328/Express0010.lzma 2022-01-07T18:52:40.252Z,1641581560.252 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Express0010.lzma.bak 2022-01-07T18:52:40.252Z,1641581560.252 [DataOverHttps](INFO): SBD MOMSN=16416511 2022-01-07T18:52:41.599Z,1641581561.599 [Default:CheckIn:Read_Iridium] Stopped 2022-01-07T18:52:41.600Z,1641581561.600 [Default:CheckIn:C.Wait] Running Loop=1 2022-01-07T18:52:41.600Z,1641581561.600 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-01-07T18:52:47.241Z,1641581567.241 [NAL9602](INFO): SBD MO Status=1, MOMSN=31432, MT Status=0, MTMSN=0 2022-01-07T18:52:47.241Z,1641581567.241 [NAL9602](INFO): No messages in MT queue 2022-01-07T18:53:17.946Z,1641581597.946 [NAL9602](INFO): Not Powering down - fast GPS 2022-01-07T18:57:42.295Z,1641581862.295 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-01-07T18:57:42.295Z,1641581862.295 [Default:CheckIn:C.Wait] Stopped 2022-01-07T18:57:42.295Z,1641581862.295 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-01-07T18:57:42.295Z,1641581862.295 [Default:CheckIn:D] Running Loop=1 2022-01-07T18:57:42.689Z,1641581862.689 [Default:CheckIn:D] Stopped 2022-01-07T18:57:42.689Z,1641581862.689 [Default:CheckIn:E] Running Loop=1 2022-01-07T18:57:43.098Z,1641581863.098 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 54.423999 min 2022-01-07T18:57:43.098Z,1641581863.098 [Default:CheckIn:E] Stopped 2022-01-07T18:57:43.098Z,1641581863.098 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-01-07T18:57:43.099Z,1641581863.099 [Default:CheckIn] Stopped 2022-01-07T18:57:43.099Z,1641581863.099 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-01-07T18:57:43.099Z,1641581863.099 [Default:CheckIn](INFO): Running loop #9 2022-01-07T18:57:43.099Z,1641581863.099 [Default:CheckIn] Running Loop=9 2022-01-07T18:57:43.099Z,1641581863.099 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-01-07T18:57:43.099Z,1641581863.099 [Default:CheckIn:Read_GPS] Running Loop=1 2022-01-07T18:57:45.105Z,1641581865.105 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185744.00,A,3648.50614,N,12147.12894,W,2.741,134.59,070122,,,D*76 2022-01-07T18:57:45.108Z,1641581865.108 [NAL9602](INFO): GPS fix at 20220107T185744: (36.808436, -121.785482) 2022-01-07T18:57:45.119Z,1641581865.119 [Default:CheckIn:Read_GPS] Stopped 2022-01-07T18:57:45.119Z,1641581865.119 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-01-07T18:57:52.366Z,1641581872.366 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20220107T182328/Courier0012.lzma 2022-01-07T18:57:53.368Z,1641581873.368 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Courier0012.lzma.bak 2022-01-07T18:57:53.368Z,1641581873.368 [DataOverHttps](INFO): SBD MOMSN=16416517 2022-01-07T18:58:00.054Z,1641581880.054 [NAL9602](INFO): SBD MO Status=1, MOMSN=31433, MT Status=0, MTMSN=0 2022-01-07T18:58:00.054Z,1641581880.054 [NAL9602](INFO): No messages in MT queue 2022-01-07T18:58:09.370Z,1641581889.370 [DataOverHttps](INFO): Sending 144 bytes from file Logs/20220107T182328/Express0013.lzma 2022-01-07T18:58:10.372Z,1641581890.372 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Express0013.lzma.bak 2022-01-07T18:58:10.372Z,1641581890.372 [DataOverHttps](INFO): SBD MOMSN=16416520 2022-01-07T18:58:11.784Z,1641581891.784 [Default:CheckIn:Read_Iridium] Stopped 2022-01-07T18:58:11.784Z,1641581891.784 [Default:CheckIn:C.Wait] Running Loop=1 2022-01-07T18:58:11.784Z,1641581891.784 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-01-07T18:58:30.759Z,1641581910.759 [NAL9602](INFO): Not Powering down - fast GPS 2022-01-07T19:03:12.425Z,1641582192.425 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-01-07T19:03:12.425Z,1641582192.425 [Default:CheckIn:C.Wait] Stopped 2022-01-07T19:03:12.426Z,1641582192.426 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-01-07T19:03:12.426Z,1641582192.426 [Default:CheckIn:D] Running Loop=1 2022-01-07T19:03:12.832Z,1641582192.832 [Default:CheckIn:D] Stopped 2022-01-07T19:03:12.832Z,1641582192.832 [Default:CheckIn:E] Running Loop=1 2022-01-07T19:03:13.252Z,1641582193.252 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 59.926392 min 2022-01-07T19:03:13.252Z,1641582193.252 [Default:CheckIn:E] Stopped 2022-01-07T19:03:13.252Z,1641582193.252 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-01-07T19:03:13.253Z,1641582193.253 [Default:CheckIn] Stopped 2022-01-07T19:03:13.253Z,1641582193.253 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-01-07T19:03:13.253Z,1641582193.253 [Default:CheckIn](INFO): Running loop #10 2022-01-07T19:03:13.253Z,1641582193.253 [Default:CheckIn] Running Loop=10 2022-01-07T19:03:13.253Z,1641582193.253 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-01-07T19:03:13.253Z,1641582193.253 [Default:CheckIn:Read_GPS] Running Loop=1 2022-01-07T19:03:15.246Z,1641582195.246 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190314.00,A,3648.23683,N,12147.14424,W,3.441,192.12,070122,,,D*79 2022-01-07T19:03:15.248Z,1641582195.248 [NAL9602](INFO): GPS fix at 20220107T190314: (36.803947, -121.785737) 2022-01-07T19:03:15.260Z,1641582195.260 [Default:CheckIn:Read_GPS] Stopped 2022-01-07T19:03:15.260Z,1641582195.260 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-01-07T19:03:22.422Z,1641582202.422 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220107T182328/Courier0015.lzma 2022-01-07T19:03:23.424Z,1641582203.424 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Courier0015.lzma.bak 2022-01-07T19:03:23.424Z,1641582203.424 [DataOverHttps](INFO): SBD MOMSN=16416524 2022-01-07T19:03:39.442Z,1641582219.442 [DataOverHttps](INFO): Sending 143 bytes from file Logs/20220107T182328/Express0016.lzma 2022-01-07T19:03:40.444Z,1641582220.444 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Express0016.lzma.bak 2022-01-07T19:03:40.444Z,1641582220.444 [DataOverHttps](INFO): SBD MOMSN=16416527 2022-01-07T19:03:41.540Z,1641582221.540 [Default:CheckIn:Read_Iridium] Stopped 2022-01-07T19:03:41.540Z,1641582221.540 [Default:CheckIn:C.Wait] Running Loop=1 2022-01-07T19:03:41.540Z,1641582221.540 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-01-07T19:04:56.689Z,1641582296.689 [NAL9602](INFO): SBD MO Status=2, MOMSN=31434, MT Status=2, MTMSN=0 2022-01-07T19:04:56.689Z,1641582296.689 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-01-07T19:05:13.661Z,1641582313.661 [NAL9602](INFO): SBD MO Status=1, MOMSN=31434, MT Status=0, MTMSN=0 2022-01-07T19:05:13.661Z,1641582313.661 [NAL9602](INFO): No messages in MT queue 2022-01-07T19:05:44.363Z,1641582344.363 [NAL9602](INFO): Not Powering down - fast GPS 2022-01-07T19:08:42.197Z,1641582522.197 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-01-07T19:08:42.197Z,1641582522.197 [Default:CheckIn:C.Wait] Stopped 2022-01-07T19:08:42.197Z,1641582522.197 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-01-07T19:08:42.197Z,1641582522.197 [Default:CheckIn:D] Running Loop=1 2022-01-07T19:08:42.590Z,1641582522.590 [Default:CheckIn:D] Stopped 2022-01-07T19:08:42.590Z,1641582522.590 [Default:CheckIn:E] Running Loop=1 2022-01-07T19:08:42.996Z,1641582522.996 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 65.422355 min 2022-01-07T19:08:42.996Z,1641582522.996 [Default:CheckIn:E] Stopped 2022-01-07T19:08:42.996Z,1641582522.996 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-01-07T19:08:42.996Z,1641582522.996 [Default:CheckIn] Stopped 2022-01-07T19:08:42.996Z,1641582522.996 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-01-07T19:08:42.996Z,1641582522.996 [Default:CheckIn](INFO): Running loop #11 2022-01-07T19:08:42.996Z,1641582522.996 [Default:CheckIn] Running Loop=11 2022-01-07T19:08:42.997Z,1641582522.997 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-01-07T19:08:42.997Z,1641582522.997 [Default:CheckIn:Read_GPS] Running Loop=1 2022-01-07T19:08:45.007Z,1641582525.007 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190844.00,A,3648.13176,N,12147.20903,W,0.058,262.36,070122,,,D*73 2022-01-07T19:08:45.010Z,1641582525.010 [NAL9602](INFO): GPS fix at 20220107T190844: (36.802196, -121.786817) 2022-01-07T19:08:45.021Z,1641582525.021 [Default:CheckIn:Read_GPS] Stopped 2022-01-07T19:08:45.021Z,1641582525.021 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-01-07T19:08:55.606Z,1641582535.606 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20220107T182328/Courier0018.lzma 2022-01-07T19:08:56.608Z,1641582536.608 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Courier0018.lzma.bak 2022-01-07T19:08:56.608Z,1641582536.608 [DataOverHttps](INFO): SBD MOMSN=16416531 2022-01-07T19:09:12.602Z,1641582552.602 [DataOverHttps](INFO): Sending 146 bytes from file Logs/20220107T182328/Express0019.lzma 2022-01-07T19:09:13.604Z,1641582553.604 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Express0019.lzma.bak 2022-01-07T19:09:13.604Z,1641582553.604 [DataOverHttps](INFO): SBD MOMSN=16416534 2022-01-07T19:09:14.975Z,1641582554.975 [Default:CheckIn:Read_Iridium] Stopped 2022-01-07T19:09:14.975Z,1641582554.975 [Default:CheckIn:C.Wait] Running Loop=1 2022-01-07T19:09:14.975Z,1641582554.975 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-01-07T19:09:57.377Z,1641582597.377 [NAL9602](INFO): SBD MO Status=2, MOMSN=31435, MT Status=2, MTMSN=0 2022-01-07T19:09:57.377Z,1641582597.377 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-01-07T19:10:38.981Z,1641582638.981 [NAL9602](INFO): SBD MO Status=1, MOMSN=31435, MT Status=0, MTMSN=0 2022-01-07T19:10:38.981Z,1641582638.981 [NAL9602](INFO): No messages in MT queue 2022-01-07T19:11:09.739Z,1641582669.739 [NAL9602](INFO): Not Powering down - fast GPS 2022-01-07T19:14:15.628Z,1641582855.628 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-01-07T19:14:15.628Z,1641582855.628 [Default:CheckIn:C.Wait] Stopped 2022-01-07T19:14:15.628Z,1641582855.628 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-01-07T19:14:15.628Z,1641582855.628 [Default:CheckIn:D] Running Loop=1 2022-01-07T19:14:16.014Z,1641582856.014 [Default:CheckIn:D] Stopped 2022-01-07T19:14:16.014Z,1641582856.014 [Default:CheckIn:E] Running Loop=1 2022-01-07T19:14:16.411Z,1641582856.411 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 70.979419 min 2022-01-07T19:14:16.411Z,1641582856.411 [Default:CheckIn:E] Stopped 2022-01-07T19:14:16.411Z,1641582856.411 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-01-07T19:14:16.411Z,1641582856.411 [Default:CheckIn] Stopped 2022-01-07T19:14:16.411Z,1641582856.411 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-01-07T19:14:16.411Z,1641582856.411 [Default:CheckIn](INFO): Running loop #12 2022-01-07T19:14:16.412Z,1641582856.412 [Default:CheckIn] Running Loop=12 2022-01-07T19:14:16.412Z,1641582856.412 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-01-07T19:14:16.412Z,1641582856.412 [Default:CheckIn:Read_GPS] Running Loop=1 2022-01-07T19:14:18.424Z,1641582858.424 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191417.00,A,3648.13216,N,12147.20940,W,0.097,322.13,070122,,,D*7B 2022-01-07T19:14:18.426Z,1641582858.426 [NAL9602](INFO): GPS fix at 20220107T191417: (36.802203, -121.786823) 2022-01-07T19:14:18.437Z,1641582858.437 [Default:CheckIn:Read_GPS] Stopped 2022-01-07T19:14:18.437Z,1641582858.437 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-01-07T19:14:25.358Z,1641582865.358 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220107T182328/Courier0021.lzma 2022-01-07T19:14:26.360Z,1641582866.360 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Courier0021.lzma.bak 2022-01-07T19:14:26.360Z,1641582866.360 [DataOverHttps](INFO): SBD MOMSN=16416538 2022-01-07T19:14:35.392Z,1641582875.392 [NAL9602](INFO): SBD MO Status=1, MOMSN=31436, MT Status=0, MTMSN=0 2022-01-07T19:14:35.392Z,1641582875.392 [NAL9602](INFO): No messages in MT queue 2022-01-07T19:14:42.634Z,1641582882.634 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20220107T182328/Express0022.lzma 2022-01-07T19:14:43.636Z,1641582883.636 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Express0022.lzma.bak 2022-01-07T19:14:43.637Z,1641582883.637 [DataOverHttps](INFO): SBD MOMSN=16416541 2022-01-07T19:14:45.112Z,1641582885.112 [Default:CheckIn:Read_Iridium] Stopped 2022-01-07T19:14:45.112Z,1641582885.112 [Default:CheckIn:C.Wait] Running Loop=1 2022-01-07T19:14:45.112Z,1641582885.112 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-01-07T19:15:06.137Z,1641582906.137 [NAL9602](INFO): Not Powering down - fast GPS 2022-01-07T19:19:23.590Z,1641583163.590 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2022-01-07T19:19:23.593Z,1641583163.593 [BPC1](INFO): Received data from all battery sticks. 2022-01-07T19:19:45.835Z,1641583185.835 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-01-07T19:19:45.835Z,1641583185.835 [Default:CheckIn:C.Wait] Stopped 2022-01-07T19:19:45.835Z,1641583185.835 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-01-07T19:19:45.835Z,1641583185.835 [Default:CheckIn:D] Running Loop=1 2022-01-07T19:19:46.223Z,1641583186.223 [Default:CheckIn:D] Stopped 2022-01-07T19:19:46.223Z,1641583186.223 [Default:CheckIn:E] Running Loop=1 2022-01-07T19:19:46.621Z,1641583186.621 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 76.482910 min 2022-01-07T19:19:46.622Z,1641583186.622 [Default:CheckIn:E] Stopped 2022-01-07T19:19:46.622Z,1641583186.622 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-01-07T19:19:46.622Z,1641583186.622 [Default:CheckIn] Stopped 2022-01-07T19:19:46.623Z,1641583186.623 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-01-07T19:19:46.623Z,1641583186.623 [Default:CheckIn](INFO): Running loop #13 2022-01-07T19:19:46.623Z,1641583186.623 [Default:CheckIn] Running Loop=13 2022-01-07T19:19:46.623Z,1641583186.623 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-01-07T19:19:46.623Z,1641583186.623 [Default:CheckIn:Read_GPS] Running Loop=1 2022-01-07T19:19:48.635Z,1641583188.635 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191947.00,A,3648.13751,N,12147.20423,W,0.117,322.13,070122,,,A*71 2022-01-07T19:19:48.638Z,1641583188.638 [NAL9602](INFO): GPS fix at 20220107T191947: (36.802292, -121.786737) 2022-01-07T19:19:48.649Z,1641583188.649 [Default:CheckIn:Read_GPS] Stopped 2022-01-07T19:19:48.649Z,1641583188.649 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-01-07T19:19:56.418Z,1641583196.418 [DataOverHttps](INFO): Sending 201 bytes from file Logs/20220107T182328/Courier0024.lzma 2022-01-07T19:19:57.420Z,1641583197.420 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Courier0024.lzma.bak 2022-01-07T19:19:57.420Z,1641583197.420 [DataOverHttps](INFO): SBD MOMSN=16416545 2022-01-07T19:20:04.793Z,1641583204.793 [NAL9602](INFO): SBD MO Status=1, MOMSN=31437, MT Status=0, MTMSN=0 2022-01-07T19:20:04.793Z,1641583204.793 [NAL9602](INFO): No messages in MT queue 2022-01-07T19:20:13.382Z,1641583213.382 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20220107T182328/Express0025.lzma 2022-01-07T19:20:14.384Z,1641583214.384 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Express0025.lzma.bak 2022-01-07T19:20:14.384Z,1641583214.384 [DataOverHttps](INFO): SBD MOMSN=16416548 2022-01-07T19:20:15.709Z,1641583215.709 [Default:CheckIn:Read_Iridium] Stopped 2022-01-07T19:20:15.709Z,1641583215.709 [Default:CheckIn:C.Wait] Running Loop=1 2022-01-07T19:20:15.709Z,1641583215.709 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-01-07T19:20:35.501Z,1641583235.501 [NAL9602](INFO): Not Powering down - fast GPS 2022-01-07T19:25:16.463Z,1641583516.463 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-01-07T19:25:16.463Z,1641583516.463 [Default:CheckIn:C.Wait] Stopped 2022-01-07T19:25:16.463Z,1641583516.463 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-01-07T19:25:16.463Z,1641583516.463 [Default:CheckIn:D] Running Loop=1 2022-01-07T19:25:16.858Z,1641583516.858 [Default:CheckIn:D] Stopped 2022-01-07T19:25:16.858Z,1641583516.858 [Default:CheckIn:E] Running Loop=1 2022-01-07T19:25:17.266Z,1641583517.266 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 81.993481 min 2022-01-07T19:25:17.266Z,1641583517.266 [Default:CheckIn:E] Stopped 2022-01-07T19:25:17.267Z,1641583517.267 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-01-07T19:25:17.267Z,1641583517.267 [Default:CheckIn] Stopped 2022-01-07T19:25:17.267Z,1641583517.267 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-01-07T19:25:17.267Z,1641583517.267 [Default:CheckIn](INFO): Running loop #14 2022-01-07T19:25:17.267Z,1641583517.267 [Default:CheckIn] Running Loop=14 2022-01-07T19:25:17.267Z,1641583517.267 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-01-07T19:25:17.267Z,1641583517.267 [Default:CheckIn:Read_GPS] Running Loop=1 2022-01-07T19:25:19.274Z,1641583519.274 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,192518.00,A,3648.17192,N,12147.27743,W,0.117,292.15,070122,,,D*72 2022-01-07T19:25:19.277Z,1641583519.277 [NAL9602](INFO): GPS fix at 20220107T192518: (36.802865, -121.787957) 2022-01-07T19:25:19.288Z,1641583519.288 [Default:CheckIn:Read_GPS] Stopped 2022-01-07T19:25:19.288Z,1641583519.288 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-01-07T19:25:26.850Z,1641583526.850 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220107T182328/Courier0027.lzma 2022-01-07T19:25:27.852Z,1641583527.852 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Courier0027.lzma.bak 2022-01-07T19:25:27.852Z,1641583527.852 [DataOverHttps](INFO): SBD MOMSN=16416552 2022-01-07T19:25:33.413Z,1641583533.413 [NAL9602](INFO): SBD MO Status=1, MOMSN=31438, MT Status=0, MTMSN=0 2022-01-07T19:25:33.413Z,1641583533.413 [NAL9602](INFO): No messages in MT queue 2022-01-07T19:25:43.950Z,1641583543.950 [DataOverHttps](INFO): Sending 145 bytes from file Logs/20220107T182328/Express0028.lzma 2022-01-07T19:25:44.952Z,1641583544.952 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Express0028.lzma.bak 2022-01-07T19:25:44.952Z,1641583544.952 [DataOverHttps](INFO): SBD MOMSN=16416555 2022-01-07T19:25:46.355Z,1641583546.355 [Default:CheckIn:Read_Iridium] Stopped 2022-01-07T19:25:46.355Z,1641583546.355 [Default:CheckIn:C.Wait] Running Loop=1 2022-01-07T19:25:46.355Z,1641583546.355 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-01-07T19:26:04.115Z,1641583564.115 [NAL9602](INFO): Not Powering down - fast GPS 2022-01-07T19:30:47.124Z,1641583847.124 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-01-07T19:30:47.124Z,1641583847.124 [Default:CheckIn:C.Wait] Stopped 2022-01-07T19:30:47.124Z,1641583847.124 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-01-07T19:30:47.124Z,1641583847.124 [Default:CheckIn:D] Running Loop=1 2022-01-07T19:30:47.546Z,1641583847.546 [Default:CheckIn:D] Stopped 2022-01-07T19:30:47.546Z,1641583847.546 [Default:CheckIn:E] Running Loop=1 2022-01-07T19:30:47.989Z,1641583847.989 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 87.504948 min 2022-01-07T19:30:47.989Z,1641583847.989 [Default:CheckIn:E] Stopped 2022-01-07T19:30:47.989Z,1641583847.989 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-01-07T19:30:47.989Z,1641583847.989 [Default:CheckIn] Stopped 2022-01-07T19:30:47.989Z,1641583847.989 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-01-07T19:30:47.989Z,1641583847.989 [Default:CheckIn](INFO): Running loop #15 2022-01-07T19:30:47.989Z,1641583847.989 [Default:CheckIn] Running Loop=15 2022-01-07T19:30:47.989Z,1641583847.989 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-01-07T19:30:47.990Z,1641583847.990 [Default:CheckIn:Read_GPS] Running Loop=1 2022-01-07T19:30:49.930Z,1641583849.930 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,193049.00,A,3648.17007,N,12147.27905,W,0.330,79.35,070122,,,A*44 2022-01-07T19:30:49.933Z,1641583849.933 [NAL9602](INFO): GPS fix at 20220107T193049: (36.802835, -121.787984) 2022-01-07T19:30:49.980Z,1641583849.980 [Default:CheckIn:Read_GPS] Stopped 2022-01-07T19:30:49.980Z,1641583849.980 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-01-07T19:31:00.771Z,1641583860.771 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220107T182328/Courier0030.lzma 2022-01-07T19:31:01.772Z,1641583861.772 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Courier0030.lzma.bak 2022-01-07T19:31:01.772Z,1641583861.772 [DataOverHttps](INFO): SBD MOMSN=16416559 2022-01-07T19:31:17.838Z,1641583877.838 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20220107T182328/Express0031.lzma 2022-01-07T19:31:18.840Z,1641583878.840 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Express0031.lzma.bak 2022-01-07T19:31:18.840Z,1641583878.840 [DataOverHttps](INFO): SBD MOMSN=16416562 2022-01-07T19:31:20.312Z,1641583880.312 [Default:CheckIn:Read_Iridium] Stopped 2022-01-07T19:31:20.312Z,1641583880.312 [Default:CheckIn:C.Wait] Running Loop=1 2022-01-07T19:31:20.312Z,1641583880.312 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-01-07T19:32:14.829Z,1641583934.829 [NAL9602](INFO): SBD MO Status=2, MOMSN=31439, MT Status=2, MTMSN=0 2022-01-07T19:32:14.829Z,1641583934.829 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-01-07T19:33:19.885Z,1641583999.885 [NAL9602](INFO): SBD MO Status=2, MOMSN=31439, MT Status=2, MTMSN=0 2022-01-07T19:33:19.885Z,1641583999.885 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-01-07T19:33:50.182Z,1641584030.182 [NAL9602](INFO): SBD MO Status=2, MOMSN=31439, MT Status=2, MTMSN=0 2022-01-07T19:33:50.182Z,1641584030.182 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-01-07T19:34:07.157Z,1641584047.157 [NAL9602](INFO): SBD MO Status=2, MOMSN=31439, MT Status=2, MTMSN=0 2022-01-07T19:34:07.157Z,1641584047.157 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-01-07T19:34:39.875Z,1641584079.875 [NAL9602](INFO): SBD MO Status=2, MOMSN=31439, MT Status=2, MTMSN=0 2022-01-07T19:34:39.875Z,1641584079.875 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-01-07T19:35:19.061Z,1641584119.061 [NAL9602](INFO): SBD MO Status=2, MOMSN=31439, MT Status=2, MTMSN=0 2022-01-07T19:35:19.062Z,1641584119.062 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-01-07T19:35:52.596Z,1641584152.596 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-01-07T19:36:20.889Z,1641584180.889 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-01-07T19:36:20.889Z,1641584180.889 [Default:CheckIn:C.Wait] Stopped 2022-01-07T19:36:20.889Z,1641584180.889 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-01-07T19:36:20.890Z,1641584180.890 [Default:CheckIn:D] Running Loop=1 2022-01-07T19:36:21.288Z,1641584181.288 [Default:CheckIn:D] Stopped 2022-01-07T19:36:21.288Z,1641584181.288 [Default:CheckIn:E] Running Loop=1 2022-01-07T19:36:21.704Z,1641584181.704 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 93.067318 min 2022-01-07T19:36:21.704Z,1641584181.704 [Default:CheckIn:E] Stopped 2022-01-07T19:36:21.704Z,1641584181.704 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-01-07T19:36:21.704Z,1641584181.704 [Default:CheckIn] Stopped 2022-01-07T19:36:21.705Z,1641584181.705 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-01-07T19:36:21.705Z,1641584181.705 [Default:CheckIn](INFO): Running loop #16 2022-01-07T19:36:21.705Z,1641584181.705 [Default:CheckIn] Running Loop=16 2022-01-07T19:36:21.705Z,1641584181.705 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-01-07T19:36:21.705Z,1641584181.705 [Default:CheckIn:Read_GPS] Running Loop=1 2022-01-07T19:36:23.706Z,1641584183.706 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,193622.00,A,3648.16895,N,12147.28449,W,0.447,41.21,070122,,,A*4E 2022-01-07T19:36:23.708Z,1641584183.708 [NAL9602](INFO): GPS fix at 20220107T193622: (36.802816, -121.788075) 2022-01-07T19:36:23.736Z,1641584183.736 [Default:CheckIn:Read_GPS] Stopped 2022-01-07T19:36:23.736Z,1641584183.736 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-01-07T19:36:31.326Z,1641584191.326 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220107T182328/Courier0033.lzma 2022-01-07T19:36:32.328Z,1641584192.328 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Courier0033.lzma.bak 2022-01-07T19:36:32.328Z,1641584192.328 [DataOverHttps](INFO): SBD MOMSN=16416567 2022-01-07T19:36:48.798Z,1641584208.798 [DataOverHttps](INFO): Sending 231 bytes from file Logs/20220107T182328/Express0034.lzma 2022-01-07T19:36:49.800Z,1641584209.800 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Express0034.lzma.bak 2022-01-07T19:36:49.800Z,1641584209.800 [DataOverHttps](INFO): SBD MOMSN=16416570 2022-01-07T19:36:51.196Z,1641584211.196 [Default:CheckIn:Read_Iridium] Stopped 2022-01-07T19:36:51.196Z,1641584211.196 [Default:CheckIn:C.Wait] Running Loop=1 2022-01-07T19:36:51.196Z,1641584211.196 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-01-07T19:36:56.467Z,1641584216.467 [NAL9602](INFO): Not Powering down - fast GPS 2022-01-07T19:41:51.806Z,1641584511.806 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-01-07T19:41:51.807Z,1641584511.807 [Default:CheckIn:C.Wait] Stopped 2022-01-07T19:41:51.807Z,1641584511.807 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-01-07T19:41:51.807Z,1641584511.807 [Default:CheckIn:D] Running Loop=1 2022-01-07T19:41:52.206Z,1641584512.206 [Default:CheckIn:D] Stopped 2022-01-07T19:41:52.206Z,1641584512.206 [Default:CheckIn:E] Running Loop=1 2022-01-07T19:41:52.612Z,1641584512.612 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 98.582617 min 2022-01-07T19:41:52.612Z,1641584512.612 [Default:CheckIn:E] Stopped 2022-01-07T19:41:52.613Z,1641584512.613 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-01-07T19:41:52.613Z,1641584512.613 [Default:CheckIn] Stopped 2022-01-07T19:41:52.613Z,1641584512.613 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-01-07T19:41:52.613Z,1641584512.613 [Default:CheckIn](INFO): Running loop #17 2022-01-07T19:41:52.613Z,1641584512.613 [Default:CheckIn] Running Loop=17 2022-01-07T19:41:52.613Z,1641584512.613 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-01-07T19:41:52.613Z,1641584512.613 [Default:CheckIn:Read_GPS] Running Loop=1 2022-01-07T19:41:54.622Z,1641584514.622 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194153.00,A,3648.15344,N,12147.28501,W,0.486,155.17,070122,,,A*7D 2022-01-07T19:41:54.624Z,1641584514.624 [NAL9602](INFO): GPS fix at 20220107T194153: (36.802557, -121.788083) 2022-01-07T19:41:54.656Z,1641584514.656 [Default:CheckIn:Read_GPS] Stopped 2022-01-07T19:41:54.656Z,1641584514.656 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-01-07T19:42:02.410Z,1641584522.410 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220107T182328/Courier0036.lzma 2022-01-07T19:42:03.412Z,1641584523.412 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Courier0036.lzma.bak 2022-01-07T19:42:03.412Z,1641584523.412 [DataOverHttps](INFO): SBD MOMSN=16416575 2022-01-07T19:42:19.614Z,1641584539.614 [DataOverHttps](INFO): Sending 140 bytes from file Logs/20220107T182328/Express0037.lzma 2022-01-07T19:42:20.616Z,1641584540.616 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Express0037.lzma.bak 2022-01-07T19:42:20.616Z,1641584540.616 [DataOverHttps](INFO): SBD MOMSN=16416578 2022-01-07T19:42:21.705Z,1641584541.705 [Default:CheckIn:Read_Iridium] Stopped 2022-01-07T19:42:21.705Z,1641584541.705 [Default:CheckIn:C.Wait] Running Loop=1 2022-01-07T19:42:21.706Z,1641584541.706 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-01-07T19:43:21.097Z,1641584601.097 [NAL9602](INFO): SBD MO Status=2, MOMSN=31439, MT Status=2, MTMSN=0 2022-01-07T19:43:21.098Z,1641584601.098 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-01-07T19:46:57.252Z,1641584817.252 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-01-07T19:47:22.310Z,1641584842.310 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-01-07T19:47:22.310Z,1641584842.310 [Default:CheckIn:C.Wait] Stopped 2022-01-07T19:47:22.310Z,1641584842.310 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-01-07T19:47:22.310Z,1641584842.310 [Default:CheckIn:D] Running Loop=1 2022-01-07T19:47:22.716Z,1641584842.716 [Default:CheckIn:D] Stopped 2022-01-07T19:47:22.716Z,1641584842.716 [Default:CheckIn:E] Running Loop=1 2022-01-07T19:47:23.134Z,1641584843.134 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 104.091130 min 2022-01-07T19:47:23.134Z,1641584843.134 [Default:CheckIn:E] Stopped 2022-01-07T19:47:23.135Z,1641584843.135 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-01-07T19:47:23.135Z,1641584843.135 [Default:CheckIn] Stopped 2022-01-07T19:47:23.135Z,1641584843.135 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-01-07T19:47:23.135Z,1641584843.135 [Default:CheckIn](INFO): Running loop #18 2022-01-07T19:47:23.135Z,1641584843.135 [Default:CheckIn] Running Loop=18 2022-01-07T19:47:23.135Z,1641584843.135 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-01-07T19:47:23.135Z,1641584843.135 [Default:CheckIn:Read_GPS] Running Loop=1 2022-01-07T19:47:25.125Z,1641584845.125 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194724.00,A,3648.16315,N,12147.28985,W,0.622,19.38,070122,,,A*44 2022-01-07T19:47:25.128Z,1641584845.128 [NAL9602](INFO): GPS fix at 20220107T194724: (36.802719, -121.788164) 2022-01-07T19:47:25.168Z,1641584845.168 [Default:CheckIn:Read_GPS] Stopped 2022-01-07T19:47:25.168Z,1641584845.168 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-01-07T19:47:32.898Z,1641584852.898 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20220107T182328/Courier0039.lzma 2022-01-07T19:47:33.900Z,1641584853.900 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Courier0039.lzma.bak 2022-01-07T19:47:33.900Z,1641584853.900 [DataOverHttps](INFO): SBD MOMSN=16416581 2022-01-07T19:47:49.890Z,1641584869.890 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20220107T182328/Express0040.lzma 2022-01-07T19:47:50.892Z,1641584870.892 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Express0040.lzma.bak 2022-01-07T19:47:50.892Z,1641584870.892 [DataOverHttps](INFO): SBD MOMSN=16416584 2022-01-07T19:47:52.208Z,1641584872.208 [Default:CheckIn:Read_Iridium] Stopped 2022-01-07T19:47:52.208Z,1641584872.208 [Default:CheckIn:C.Wait] Running Loop=1 2022-01-07T19:47:52.208Z,1641584872.208 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-01-07T19:47:57.450Z,1641584877.450 [NAL9602](INFO): Not Powering down - fast GPS 2022-01-07T19:52:52.788Z,1641585172.788 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-01-07T19:52:52.788Z,1641585172.788 [Default:CheckIn:C.Wait] Stopped 2022-01-07T19:52:52.788Z,1641585172.788 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-01-07T19:52:52.789Z,1641585172.789 [Default:CheckIn:D] Running Loop=1 2022-01-07T19:52:53.207Z,1641585173.207 [Default:CheckIn:D] Stopped 2022-01-07T19:52:53.207Z,1641585173.207 [Default:CheckIn:E] Running Loop=1 2022-01-07T19:52:53.661Z,1641585173.661 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 109.599300 min 2022-01-07T19:52:53.661Z,1641585173.661 [Default:CheckIn:E] Stopped 2022-01-07T19:52:53.661Z,1641585173.661 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-01-07T19:52:53.661Z,1641585173.661 [Default:CheckIn] Stopped 2022-01-07T19:52:53.661Z,1641585173.661 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-01-07T19:52:53.661Z,1641585173.661 [Default:CheckIn](INFO): Running loop #19 2022-01-07T19:52:53.661Z,1641585173.661 [Default:CheckIn] Running Loop=19 2022-01-07T19:52:53.662Z,1641585173.662 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-01-07T19:52:53.662Z,1641585173.662 [Default:CheckIn:Read_GPS] Running Loop=1 2022-01-07T19:52:55.610Z,1641585175.610 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,195254.00,A,3648.16615,N,12147.28641,W,2.080,177.74,070122,,,A*78 2022-01-07T19:52:55.628Z,1641585175.628 [NAL9602](INFO): GPS fix at 20220107T195254: (36.802769, -121.788107) 2022-01-07T19:52:55.655Z,1641585175.655 [Default:CheckIn:Read_GPS] Stopped 2022-01-07T19:52:55.655Z,1641585175.655 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-01-07T19:53:02.630Z,1641585182.630 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220107T182328/Courier0042.lzma 2022-01-07T19:53:03.633Z,1641585183.633 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Courier0042.lzma.bak 2022-01-07T19:53:03.633Z,1641585183.633 [DataOverHttps](INFO): SBD MOMSN=16416588 2022-01-07T19:53:19.466Z,1641585199.466 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20220107T182328/Express0043.lzma 2022-01-07T19:53:20.468Z,1641585200.468 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Express0043.lzma.bak 2022-01-07T19:53:20.468Z,1641585200.468 [DataOverHttps](INFO): SBD MOMSN=16416591 2022-01-07T19:53:21.876Z,1641585201.876 [Default:CheckIn:Read_Iridium] Stopped 2022-01-07T19:53:21.876Z,1641585201.876 [Default:CheckIn:C.Wait] Running Loop=1 2022-01-07T19:53:21.876Z,1641585201.876 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-01-07T19:53:26.308Z,1641585206.308 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-01-07T19:53:26.386Z,1641585206.386 [NAL9602](ERROR): received: +CSQ:0 OK439, 2, 0, 0, 0 OK 2022-01-07T19:57:35.982Z,1641585455.982 [NAL9602](INFO): SBD MO Status=2, MOMSN=31439, MT Status=2, MTMSN=0 2022-01-07T19:57:35.982Z,1641585455.982 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-01-07T19:57:57.396Z,1641585477.396 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-01-07T19:58:22.452Z,1641585502.452 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-01-07T19:58:22.452Z,1641585502.452 [Default:CheckIn:C.Wait] Stopped 2022-01-07T19:58:22.452Z,1641585502.452 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-01-07T19:58:22.453Z,1641585502.453 [Default:CheckIn:D] Running Loop=1 2022-01-07T19:58:22.861Z,1641585502.861 [Default:CheckIn:D] Stopped 2022-01-07T19:58:22.861Z,1641585502.861 [Default:CheckIn:E] Running Loop=1 2022-01-07T19:58:23.281Z,1641585503.281 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 115.093538 min 2022-01-07T19:58:23.281Z,1641585503.281 [Default:CheckIn:E] Stopped 2022-01-07T19:58:23.282Z,1641585503.282 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-01-07T19:58:23.282Z,1641585503.282 [Default:CheckIn] Stopped 2022-01-07T19:58:23.282Z,1641585503.282 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-01-07T19:58:23.285Z,1641585503.285 [Default:CheckIn](INFO): Running loop #20 2022-01-07T19:58:23.285Z,1641585503.285 [Default:CheckIn] Running Loop=20 2022-01-07T19:58:23.285Z,1641585503.285 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-01-07T19:58:23.285Z,1641585503.285 [Default:CheckIn:Read_GPS] Running Loop=1 2022-01-07T19:58:25.271Z,1641585505.271 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,195824.00,A,3648.16493,N,12147.28571,W,0.311,165.45,070122,,,A*71 2022-01-07T19:58:25.276Z,1641585505.276 [NAL9602](INFO): GPS fix at 20220107T195824: (36.802749, -121.788095) 2022-01-07T19:58:25.288Z,1641585505.288 [Default:CheckIn:Read_GPS] Stopped 2022-01-07T19:58:25.288Z,1641585505.288 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-01-07T19:58:32.858Z,1641585512.858 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20220107T182328/Courier0045.lzma 2022-01-07T19:58:33.860Z,1641585513.860 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Courier0045.lzma.bak 2022-01-07T19:58:33.860Z,1641585513.860 [DataOverHttps](INFO): SBD MOMSN=16416594 2022-01-07T19:58:51.946Z,1641585531.946 [DataOverHttps](INFO): Sending 208 bytes from file Logs/20220107T182328/Express0046.lzma 2022-01-07T19:58:52.948Z,1641585532.948 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Express0046.lzma.bak 2022-01-07T19:58:52.949Z,1641585532.949 [DataOverHttps](INFO): SBD MOMSN=16416597 2022-01-07T19:58:54.400Z,1641585534.400 [Default:CheckIn:Read_Iridium] Stopped 2022-01-07T19:58:54.400Z,1641585534.400 [Default:CheckIn:C.Wait] Running Loop=1 2022-01-07T19:58:54.401Z,1641585534.401 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-01-07T19:58:57.623Z,1641585537.623 [NAL9602](INFO): Not Powering down - fast GPS 2022-01-07T20:03:55.004Z,1641585835.004 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-01-07T20:03:55.004Z,1641585835.004 [Default:CheckIn:C.Wait] Stopped 2022-01-07T20:03:55.004Z,1641585835.004 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-01-07T20:03:55.004Z,1641585835.004 [Default:CheckIn:D] Running Loop=1 2022-01-07T20:03:55.402Z,1641585835.402 [Default:CheckIn:D] Stopped 2022-01-07T20:03:55.402Z,1641585835.402 [Default:CheckIn:E] Running Loop=1 2022-01-07T20:03:55.809Z,1641585835.809 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 120.635889 min 2022-01-07T20:03:55.809Z,1641585835.809 [Default:CheckIn:E] Stopped 2022-01-07T20:03:55.809Z,1641585835.809 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-01-07T20:03:55.809Z,1641585835.809 [Default:CheckIn] Stopped 2022-01-07T20:03:55.809Z,1641585835.809 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-01-07T20:03:55.809Z,1641585835.809 [Default:CheckIn](INFO): Running loop #21 2022-01-07T20:03:55.809Z,1641585835.809 [Default:CheckIn] Running Loop=21 2022-01-07T20:03:55.810Z,1641585835.810 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-01-07T20:03:55.810Z,1641585835.810 [Default:CheckIn:Read_GPS] Running Loop=1 2022-01-07T20:03:57.821Z,1641585837.821 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200357.00,A,3648.16216,N,12147.28466,W,0.952,358.22,070122,,,A*7D 2022-01-07T20:03:57.833Z,1641585837.833 [NAL9602](INFO): GPS fix at 20220107T200357: (36.802703, -121.788078) 2022-01-07T20:03:57.845Z,1641585837.845 [Default:CheckIn:Read_GPS] Stopped 2022-01-07T20:03:57.845Z,1641585837.845 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-01-07T20:04:05.570Z,1641585845.570 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220107T182328/Courier0048.lzma 2022-01-07T20:04:06.572Z,1641585846.572 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Courier0048.lzma.bak 2022-01-07T20:04:06.572Z,1641585846.572 [DataOverHttps](INFO): SBD MOMSN=16416601 2022-01-07T20:04:22.530Z,1641585862.530 [DataOverHttps](INFO): Sending 132 bytes from file Logs/20220107T182328/Express0049.lzma 2022-01-07T20:04:23.532Z,1641585863.532 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Express0049.lzma.bak 2022-01-07T20:04:23.532Z,1641585863.532 [DataOverHttps](INFO): SBD MOMSN=16416604 2022-01-07T20:04:24.901Z,1641585864.901 [Default:CheckIn:Read_Iridium] Stopped 2022-01-07T20:04:24.901Z,1641585864.901 [Default:CheckIn:C.Wait] Running Loop=1 2022-01-07T20:04:24.901Z,1641585864.901 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-01-07T20:04:28.528Z,1641585868.528 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-01-07T20:04:28.610Z,1641585868.610 [NAL9602](ERROR): received: +CSQ:1 OK439, 2, 0, 0, 0 OK 2022-01-07T20:07:51.741Z,1641586071.741 [NAL9602](INFO): SBD MO Status=1, MOMSN=31439, MT Status=0, MTMSN=0 2022-01-07T20:07:51.741Z,1641586071.741 [NAL9602](INFO): No messages in MT queue 2022-01-07T20:08:22.439Z,1641586102.439 [NAL9602](INFO): Not Powering down - fast GPS 2022-01-07T20:09:25.476Z,1641586165.476 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-01-07T20:09:25.476Z,1641586165.476 [Default:CheckIn:C.Wait] Stopped 2022-01-07T20:09:25.476Z,1641586165.476 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-01-07T20:09:25.476Z,1641586165.476 [Default:CheckIn:D] Running Loop=1 2022-01-07T20:09:25.892Z,1641586165.892 [Default:CheckIn:D] Stopped 2022-01-07T20:09:25.892Z,1641586165.892 [Default:CheckIn:E] Running Loop=1 2022-01-07T20:09:26.287Z,1641586166.287 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 126.144051 min 2022-01-07T20:09:26.288Z,1641586166.288 [Default:CheckIn:E] Stopped 2022-01-07T20:09:26.288Z,1641586166.288 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-01-07T20:09:26.288Z,1641586166.288 [Default:CheckIn] Stopped 2022-01-07T20:09:26.288Z,1641586166.288 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-01-07T20:09:26.288Z,1641586166.288 [Default:CheckIn](INFO): Running loop #22 2022-01-07T20:09:26.288Z,1641586166.288 [Default:CheckIn] Running Loop=22 2022-01-07T20:09:26.288Z,1641586166.288 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-01-07T20:09:26.289Z,1641586166.289 [Default:CheckIn:Read_GPS] Running Loop=1 2022-01-07T20:09:28.295Z,1641586168.295 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200927.00,A,3648.18023,N,12147.28180,W,1.322,29.30,070122,,,A*4D 2022-01-07T20:09:28.297Z,1641586168.297 [NAL9602](INFO): GPS fix at 20220107T200927: (36.803004, -121.788030) 2022-01-07T20:09:28.309Z,1641586168.309 [Default:CheckIn:Read_GPS] Stopped 2022-01-07T20:09:28.309Z,1641586168.309 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-01-07T20:09:36.282Z,1641586176.282 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220107T182328/Courier0051.lzma 2022-01-07T20:09:37.284Z,1641586177.284 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Courier0051.lzma.bak 2022-01-07T20:09:37.284Z,1641586177.284 [DataOverHttps](INFO): SBD MOMSN=16416607 2022-01-07T20:09:42.437Z,1641586182.437 [NAL9602](INFO): SBD MO Status=1, MOMSN=31440, MT Status=0, MTMSN=0 2022-01-07T20:09:42.437Z,1641586182.437 [NAL9602](INFO): No messages in MT queue 2022-01-07T20:09:53.318Z,1641586193.318 [DataOverHttps](INFO): Sending 139 bytes from file Logs/20220107T182328/Express0052.lzma 2022-01-07T20:09:54.320Z,1641586194.320 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Express0052.lzma.bak 2022-01-07T20:09:54.320Z,1641586194.320 [DataOverHttps](INFO): SBD MOMSN=16416610 2022-01-07T20:09:55.404Z,1641586195.404 [Default:CheckIn:Read_Iridium] Stopped 2022-01-07T20:09:55.404Z,1641586195.404 [Default:CheckIn:C.Wait] Running Loop=1 2022-01-07T20:09:55.404Z,1641586195.404 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-01-07T20:10:13.137Z,1641586213.137 [NAL9602](INFO): Not Powering down - fast GPS 2022-01-07T20:14:55.960Z,1641586495.960 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-01-07T20:14:55.961Z,1641586495.961 [Default:CheckIn:C.Wait] Stopped 2022-01-07T20:14:55.961Z,1641586495.961 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-01-07T20:14:55.961Z,1641586495.961 [Default:CheckIn:D] Running Loop=1 2022-01-07T20:14:56.364Z,1641586496.364 [Default:CheckIn:D] Stopped 2022-01-07T20:14:56.364Z,1641586496.364 [Default:CheckIn:E] Running Loop=1 2022-01-07T20:14:56.774Z,1641586496.774 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 131.651929 min 2022-01-07T20:14:56.774Z,1641586496.774 [Default:CheckIn:E] Stopped 2022-01-07T20:14:56.775Z,1641586496.775 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-01-07T20:14:56.775Z,1641586496.775 [Default:CheckIn] Stopped 2022-01-07T20:14:56.775Z,1641586496.775 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-01-07T20:14:56.775Z,1641586496.775 [Default:CheckIn](INFO): Running loop #23 2022-01-07T20:14:56.775Z,1641586496.775 [Default:CheckIn] Running Loop=23 2022-01-07T20:14:56.775Z,1641586496.775 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-01-07T20:14:56.775Z,1641586496.775 [Default:CheckIn:Read_GPS] Running Loop=1 2022-01-07T20:14:58.781Z,1641586498.781 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,201458.00,A,3648.17852,N,12147.28610,W,4.238,349.26,070122,,,A*7B 2022-01-07T20:14:58.784Z,1641586498.784 [NAL9602](INFO): GPS fix at 20220107T201458: (36.802975, -121.788102) 2022-01-07T20:14:58.823Z,1641586498.823 [Default:CheckIn:Read_GPS] Stopped 2022-01-07T20:14:58.823Z,1641586498.823 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-01-07T20:15:06.746Z,1641586506.746 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220107T182328/Courier0054.lzma 2022-01-07T20:15:07.749Z,1641586507.749 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Courier0054.lzma.bak 2022-01-07T20:15:07.749Z,1641586507.749 [DataOverHttps](INFO): SBD MOMSN=16416615 2022-01-07T20:15:23.770Z,1641586523.770 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20220107T182328/Express0055.lzma 2022-01-07T20:15:24.772Z,1641586524.772 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Express0055.lzma.bak 2022-01-07T20:15:24.772Z,1641586524.772 [DataOverHttps](INFO): SBD MOMSN=16416618 2022-01-07T20:15:25.869Z,1641586525.869 [Default:CheckIn:Read_Iridium] Stopped 2022-01-07T20:15:25.869Z,1641586525.869 [Default:CheckIn:C.Wait] Running Loop=1 2022-01-07T20:15:25.869Z,1641586525.869 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-01-07T20:17:54.926Z,1641586674.926 [NAL9602](INFO): SBD MO Status=2, MOMSN=31441, MT Status=2, MTMSN=0 2022-01-07T20:17:54.930Z,1641586674.930 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-01-07T20:18:23.601Z,1641586703.601 [NAL9602](INFO): SBD MO Status=2, MOMSN=31441, MT Status=2, MTMSN=0 2022-01-07T20:18:23.602Z,1641586703.602 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-01-07T20:18:38.145Z,1641586718.145 [NAL9602](INFO): SBD MO Status=2, MOMSN=31441, MT Status=2, MTMSN=0 2022-01-07T20:18:38.145Z,1641586718.145 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-01-07T20:20:01.382Z,1641586801.382 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-01-07T20:20:26.427Z,1641586826.427 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-01-07T20:20:26.427Z,1641586826.427 [Default:CheckIn:C.Wait] Stopped 2022-01-07T20:20:26.427Z,1641586826.427 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-01-07T20:20:26.427Z,1641586826.427 [Default:CheckIn:D] Running Loop=1 2022-01-07T20:20:26.838Z,1641586826.838 [Default:CheckIn:D] Stopped 2022-01-07T20:20:26.838Z,1641586826.838 [Default:CheckIn:E] Running Loop=1 2022-01-07T20:20:27.249Z,1641586827.249 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 137.159814 min 2022-01-07T20:20:27.249Z,1641586827.249 [Default:CheckIn:E] Stopped 2022-01-07T20:20:27.249Z,1641586827.249 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-01-07T20:20:27.249Z,1641586827.249 [Default:CheckIn] Stopped 2022-01-07T20:20:27.249Z,1641586827.249 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-01-07T20:20:27.250Z,1641586827.250 [Default:CheckIn](INFO): Running loop #24 2022-01-07T20:20:27.250Z,1641586827.250 [Default:CheckIn] Running Loop=24 2022-01-07T20:20:27.250Z,1641586827.250 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-01-07T20:20:27.250Z,1641586827.250 [Default:CheckIn:Read_GPS] Running Loop=1 2022-01-07T20:20:29.253Z,1641586829.253 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,202028.00,A,3648.15501,N,12147.28667,W,0.389,184.65,070122,,,A*79 2022-01-07T20:20:29.256Z,1641586829.256 [NAL9602](INFO): GPS fix at 20220107T202028: (36.802583, -121.788111) 2022-01-07T20:20:29.299Z,1641586829.299 [Default:CheckIn:Read_GPS] Stopped 2022-01-07T20:20:29.299Z,1641586829.299 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-01-07T20:20:36.434Z,1641586836.434 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20220107T182328/Courier0057.lzma 2022-01-07T20:20:37.436Z,1641586837.436 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Courier0057.lzma.bak 2022-01-07T20:20:37.436Z,1641586837.436 [DataOverHttps](INFO): SBD MOMSN=16416621 2022-01-07T20:20:56.450Z,1641586856.450 [DataOverHttps](INFO): Sending 216 bytes from file Logs/20220107T182328/Express0058.lzma 2022-01-07T20:20:57.452Z,1641586857.452 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Express0058.lzma.bak 2022-01-07T20:20:57.453Z,1641586857.453 [DataOverHttps](INFO): SBD MOMSN=16416624 2022-01-07T20:20:58.860Z,1641586858.860 [Default:CheckIn:Read_Iridium] Stopped 2022-01-07T20:20:58.860Z,1641586858.860 [Default:CheckIn:C.Wait] Running Loop=1 2022-01-07T20:20:58.860Z,1641586858.860 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-01-07T20:21:01.631Z,1641586861.631 [NAL9602](INFO): Not Powering down - fast GPS 2022-01-07T20:25:59.390Z,1641587159.390 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-01-07T20:25:59.390Z,1641587159.390 [Default:CheckIn:C.Wait] Stopped 2022-01-07T20:25:59.390Z,1641587159.390 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-01-07T20:25:59.390Z,1641587159.390 [Default:CheckIn:D] Running Loop=1 2022-01-07T20:25:59.800Z,1641587159.800 [Default:CheckIn:D] Stopped 2022-01-07T20:25:59.800Z,1641587159.800 [Default:CheckIn:E] Running Loop=1 2022-01-07T20:26:00.205Z,1641587160.205 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 142.709180 min 2022-01-07T20:26:00.205Z,1641587160.205 [Default:CheckIn:E] Stopped 2022-01-07T20:26:00.205Z,1641587160.205 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-01-07T20:26:00.205Z,1641587160.205 [Default:CheckIn] Stopped 2022-01-07T20:26:00.205Z,1641587160.205 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-01-07T20:26:00.206Z,1641587160.206 [Default:CheckIn](INFO): Running loop #25 2022-01-07T20:26:00.206Z,1641587160.206 [Default:CheckIn] Running Loop=25 2022-01-07T20:26:00.206Z,1641587160.206 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-01-07T20:26:00.206Z,1641587160.206 [Default:CheckIn:Read_GPS] Running Loop=1 2022-01-07T20:26:02.213Z,1641587162.213 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,202601.00,A,3648.16772,N,12147.28283,W,0.525,188.24,070122,,,A*76 2022-01-07T20:26:02.226Z,1641587162.226 [NAL9602](INFO): GPS fix at 20220107T202601: (36.802795, -121.788047) 2022-01-07T20:26:02.237Z,1641587162.237 [Default:CheckIn:Read_GPS] Stopped 2022-01-07T20:26:02.237Z,1641587162.237 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-01-07T20:26:09.578Z,1641587169.578 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220107T182328/Courier0060.lzma 2022-01-07T20:26:10.580Z,1641587170.580 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Courier0060.lzma.bak 2022-01-07T20:26:10.580Z,1641587170.580 [DataOverHttps](INFO): SBD MOMSN=16416628 2022-01-07T20:26:26.806Z,1641587186.806 [DataOverHttps](INFO): Sending 139 bytes from file Logs/20220107T182328/Express0061.lzma 2022-01-07T20:26:27.808Z,1641587187.808 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Express0061.lzma.bak 2022-01-07T20:26:27.808Z,1641587187.808 [DataOverHttps](INFO): SBD MOMSN=16416631 2022-01-07T20:26:28.908Z,1641587188.908 [Default:CheckIn:Read_Iridium] Stopped 2022-01-07T20:26:28.908Z,1641587188.908 [Default:CheckIn:C.Wait] Running Loop=1 2022-01-07T20:26:28.908Z,1641587188.908 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-01-07T20:26:32.916Z,1641587192.916 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-01-07T20:26:32.990Z,1641587192.990 [NAL9602](ERROR): received: +CSQ:0 OK441, 2, 0, 0, 0 OK 2022-01-07T20:26:48.270Z,1641587208.270 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2022-01-07T20:26:48.273Z,1641587208.273 [BPC1](INFO): Received data from all battery sticks. 2022-01-07T20:27:04.844Z,1641587224.844 [NAL9602](INFO): SBD MO Status=2, MOMSN=31441, MT Status=2, MTMSN=0 2022-01-07T20:27:04.844Z,1641587224.844 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-01-07T20:31:04.424Z,1641587464.424 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-01-07T20:31:29.489Z,1641587489.489 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-01-07T20:31:29.489Z,1641587489.489 [Default:CheckIn:C.Wait] Stopped 2022-01-07T20:31:29.489Z,1641587489.489 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-01-07T20:31:29.490Z,1641587489.490 [Default:CheckIn:D] Running Loop=1 2022-01-07T20:31:29.883Z,1641587489.883 [Default:CheckIn:D] Stopped 2022-01-07T20:31:29.883Z,1641587489.883 [Default:CheckIn:E] Running Loop=1 2022-01-07T20:31:30.282Z,1641587490.282 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 148.210563 min 2022-01-07T20:31:30.282Z,1641587490.282 [Default:CheckIn:E] Stopped 2022-01-07T20:31:30.282Z,1641587490.282 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-01-07T20:31:30.282Z,1641587490.282 [Default:CheckIn] Stopped 2022-01-07T20:31:30.283Z,1641587490.283 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-01-07T20:31:30.283Z,1641587490.283 [Default:CheckIn](INFO): Running loop #26 2022-01-07T20:31:30.283Z,1641587490.283 [Default:CheckIn] Running Loop=26 2022-01-07T20:31:30.283Z,1641587490.283 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-01-07T20:31:30.283Z,1641587490.283 [Default:CheckIn:Read_GPS] Running Loop=1 2022-01-07T20:31:32.301Z,1641587492.301 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,203131.00,A,3648.17399,N,12147.28505,W,0.292,205.47,070122,,,A*72 2022-01-07T20:31:32.304Z,1641587492.304 [NAL9602](INFO): GPS fix at 20220107T203131: (36.802900, -121.788084) 2022-01-07T20:31:32.318Z,1641587492.318 [Default:CheckIn:Read_GPS] Stopped 2022-01-07T20:31:32.318Z,1641587492.318 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-01-07T20:31:39.362Z,1641587499.362 [DataOverHttps](INFO): Sending 85 bytes from file Logs/20220107T182328/Courier0063.lzma 2022-01-07T20:31:40.364Z,1641587500.364 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Courier0063.lzma.bak 2022-01-07T20:31:40.364Z,1641587500.364 [DataOverHttps](INFO): SBD MOMSN=16416634 2022-01-07T20:31:56.210Z,1641587516.210 [DataOverHttps](INFO): Sending 209 bytes from file Logs/20220107T182328/Express0064.lzma 2022-01-07T20:31:57.212Z,1641587517.212 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Express0064.lzma.bak 2022-01-07T20:31:57.212Z,1641587517.212 [DataOverHttps](INFO): SBD MOMSN=16416637 2022-01-07T20:31:58.567Z,1641587518.567 [Default:CheckIn:Read_Iridium] Stopped 2022-01-07T20:31:58.567Z,1641587518.567 [Default:CheckIn:C.Wait] Running Loop=1 2022-01-07T20:31:58.567Z,1641587518.567 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-01-07T20:32:04.611Z,1641587524.611 [NAL9602](INFO): Not Powering down - fast GPS 2022-01-07T20:36:59.175Z,1641587819.175 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-01-07T20:36:59.175Z,1641587819.175 [Default:CheckIn:C.Wait] Stopped 2022-01-07T20:36:59.175Z,1641587819.175 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-01-07T20:36:59.175Z,1641587819.175 [Default:CheckIn:D] Running Loop=1 2022-01-07T20:36:59.549Z,1641587819.549 [Default:CheckIn:D] Stopped 2022-01-07T20:36:59.549Z,1641587819.549 [Default:CheckIn:E] Running Loop=1 2022-01-07T20:36:59.957Z,1641587819.957 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 153.705013 min 2022-01-07T20:36:59.957Z,1641587819.957 [Default:CheckIn:E] Stopped 2022-01-07T20:36:59.957Z,1641587819.957 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-01-07T20:36:59.957Z,1641587819.957 [Default:CheckIn] Stopped 2022-01-07T20:36:59.957Z,1641587819.957 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-01-07T20:36:59.957Z,1641587819.957 [Default:CheckIn](INFO): Running loop #27 2022-01-07T20:36:59.957Z,1641587819.957 [Default:CheckIn] Running Loop=27 2022-01-07T20:36:59.958Z,1641587819.958 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-01-07T20:36:59.958Z,1641587819.958 [Default:CheckIn:Read_GPS] Running Loop=1 2022-01-07T20:37:01.969Z,1641587821.969 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,203701.00,A,3648.16164,N,12147.27990,W,0.350,326.50,070122,,,A*70 2022-01-07T20:37:01.972Z,1641587821.972 [NAL9602](INFO): GPS fix at 20220107T203701: (36.802694, -121.787998) 2022-01-07T20:37:02.003Z,1641587822.003 [Default:CheckIn:Read_GPS] Stopped 2022-01-07T20:37:02.003Z,1641587822.003 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-01-07T20:37:09.578Z,1641587829.578 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220107T182328/Courier0066.lzma 2022-01-07T20:37:10.580Z,1641587830.580 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Courier0066.lzma.bak 2022-01-07T20:37:10.580Z,1641587830.580 [DataOverHttps](INFO): SBD MOMSN=16416641 2022-01-07T20:37:26.702Z,1641587846.702 [DataOverHttps](INFO): Sending 140 bytes from file Logs/20220107T182328/Express0067.lzma 2022-01-07T20:37:27.704Z,1641587847.704 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Express0067.lzma.bak 2022-01-07T20:37:27.704Z,1641587847.704 [DataOverHttps](INFO): SBD MOMSN=16416644 2022-01-07T20:37:29.050Z,1641587849.050 [Default:CheckIn:Read_Iridium] Stopped 2022-01-07T20:37:29.050Z,1641587849.050 [Default:CheckIn:C.Wait] Running Loop=1 2022-01-07T20:37:29.050Z,1641587849.050 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-01-07T20:37:32.664Z,1641587852.664 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-01-07T20:37:32.738Z,1641587852.738 [NAL9602](ERROR): received: +CSQ:0 OK441, 2, 0, 0, 0 OK 2022-01-07T20:42:04.561Z,1641588124.561 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-01-07T20:42:29.618Z,1641588149.618 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-01-07T20:42:29.618Z,1641588149.618 [Default:CheckIn:C.Wait] Stopped 2022-01-07T20:42:29.619Z,1641588149.619 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-01-07T20:42:29.619Z,1641588149.619 [Default:CheckIn:D] Running Loop=1 2022-01-07T20:42:30.025Z,1641588150.025 [Default:CheckIn:D] Stopped 2022-01-07T20:42:30.025Z,1641588150.025 [Default:CheckIn:E] Running Loop=1 2022-01-07T20:42:30.434Z,1641588150.434 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 159.212939 min 2022-01-07T20:42:30.434Z,1641588150.434 [Default:CheckIn:E] Stopped 2022-01-07T20:42:30.434Z,1641588150.434 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-01-07T20:42:30.434Z,1641588150.434 [Default:CheckIn] Stopped 2022-01-07T20:42:30.434Z,1641588150.434 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-01-07T20:42:30.434Z,1641588150.434 [Default:CheckIn](INFO): Running loop #28 2022-01-07T20:42:30.434Z,1641588150.434 [Default:CheckIn] Running Loop=28 2022-01-07T20:42:30.435Z,1641588150.435 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-01-07T20:42:30.435Z,1641588150.435 [Default:CheckIn:Read_GPS] Running Loop=1 2022-01-07T20:42:32.438Z,1641588152.438 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,204231.00,A,3648.15647,N,12147.28009,W,1.225,18.83,070122,,,A*40 2022-01-07T20:42:32.440Z,1641588152.440 [NAL9602](INFO): GPS fix at 20220107T204231: (36.802608, -121.788002) 2022-01-07T20:42:32.476Z,1641588152.476 [Default:CheckIn:Read_GPS] Stopped 2022-01-07T20:42:32.476Z,1641588152.476 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-01-07T20:42:40.254Z,1641588160.254 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220107T182328/Courier0069.lzma 2022-01-07T20:42:41.256Z,1641588161.256 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Courier0069.lzma.bak 2022-01-07T20:42:41.256Z,1641588161.256 [DataOverHttps](INFO): SBD MOMSN=16416647 2022-01-07T20:43:00.434Z,1641588180.434 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20220107T182328/Express0070.lzma 2022-01-07T20:43:01.436Z,1641588181.436 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Express0070.lzma.bak 2022-01-07T20:43:01.436Z,1641588181.436 [DataOverHttps](INFO): SBD MOMSN=16416650 2022-01-07T20:43:02.799Z,1641588182.799 [Default:CheckIn:Read_Iridium] Stopped 2022-01-07T20:43:02.799Z,1641588182.799 [Default:CheckIn:C.Wait] Running Loop=1 2022-01-07T20:43:02.799Z,1641588182.799 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-01-07T20:43:04.391Z,1641588184.391 [NAL9602](INFO): Not Powering down - fast GPS 2022-01-07T20:48:03.376Z,1641588483.376 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-01-07T20:48:03.376Z,1641588483.376 [Default:CheckIn:C.Wait] Stopped 2022-01-07T20:48:03.376Z,1641588483.376 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-01-07T20:48:03.376Z,1641588483.376 [Default:CheckIn:D] Running Loop=1 2022-01-07T20:48:03.766Z,1641588483.766 [Default:CheckIn:D] Stopped 2022-01-07T20:48:03.766Z,1641588483.766 [Default:CheckIn:E] Running Loop=1 2022-01-07T20:48:04.170Z,1641588484.170 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 164.775277 min 2022-01-07T20:48:04.171Z,1641588484.171 [Default:CheckIn:E] Stopped 2022-01-07T20:48:04.171Z,1641588484.171 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-01-07T20:48:04.171Z,1641588484.171 [Default:CheckIn] Stopped 2022-01-07T20:48:04.171Z,1641588484.171 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-01-07T20:48:04.171Z,1641588484.171 [Default:CheckIn](INFO): Running loop #29 2022-01-07T20:48:04.171Z,1641588484.171 [Default:CheckIn] Running Loop=29 2022-01-07T20:48:04.171Z,1641588484.171 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-01-07T20:48:04.171Z,1641588484.171 [Default:CheckIn:Read_GPS] Running Loop=1 2022-01-07T20:48:06.189Z,1641588486.189 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,204805.00,A,3648.15925,N,12147.27987,W,0.292,274.16,070122,,,A*7F 2022-01-07T20:48:06.192Z,1641588486.192 [NAL9602](INFO): GPS fix at 20220107T204805: (36.802654, -121.787998) 2022-01-07T20:48:06.214Z,1641588486.214 [Default:CheckIn:Read_GPS] Stopped 2022-01-07T20:48:06.214Z,1641588486.214 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-01-07T20:48:13.990Z,1641588493.990 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220107T182328/Courier0072.lzma 2022-01-07T20:48:14.992Z,1641588494.992 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Courier0072.lzma.bak 2022-01-07T20:48:14.992Z,1641588494.992 [DataOverHttps](INFO): SBD MOMSN=16416654 2022-01-07T20:48:30.962Z,1641588510.962 [DataOverHttps](INFO): Sending 132 bytes from file Logs/20220107T182328/Express0073.lzma 2022-01-07T20:48:31.965Z,1641588511.965 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Express0073.lzma.bak 2022-01-07T20:48:31.965Z,1641588511.965 [DataOverHttps](INFO): SBD MOMSN=16416657 2022-01-07T20:48:33.263Z,1641588513.263 [Default:CheckIn:Read_Iridium] Stopped 2022-01-07T20:48:33.264Z,1641588513.264 [Default:CheckIn:C.Wait] Running Loop=1 2022-01-07T20:48:33.264Z,1641588513.264 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-01-07T20:53:08.380Z,1641588788.380 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-01-07T20:53:33.870Z,1641588813.870 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-01-07T20:53:33.870Z,1641588813.870 [Default:CheckIn:C.Wait] Stopped 2022-01-07T20:53:33.870Z,1641588813.870 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-01-07T20:53:33.871Z,1641588813.871 [Default:CheckIn:D] Running Loop=1 2022-01-07T20:53:34.264Z,1641588814.264 [Default:CheckIn:D] Stopped 2022-01-07T20:53:34.264Z,1641588814.264 [Default:CheckIn:E] Running Loop=1 2022-01-07T20:53:34.666Z,1641588814.666 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 170.283577 min 2022-01-07T20:53:34.666Z,1641588814.666 [Default:CheckIn:E] Stopped 2022-01-07T20:53:34.666Z,1641588814.666 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-01-07T20:53:34.667Z,1641588814.667 [Default:CheckIn] Stopped 2022-01-07T20:53:34.667Z,1641588814.667 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-01-07T20:53:34.667Z,1641588814.667 [Default:CheckIn](INFO): Running loop #30 2022-01-07T20:53:34.667Z,1641588814.667 [Default:CheckIn] Running Loop=30 2022-01-07T20:53:34.667Z,1641588814.667 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-01-07T20:53:34.667Z,1641588814.667 [Default:CheckIn:Read_GPS] Running Loop=1 2022-01-07T20:53:36.680Z,1641588816.680 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,205335.00,A,3648.19379,N,12147.26612,W,3.052,30.84,070122,,,A*4F 2022-01-07T20:53:36.683Z,1641588816.683 [NAL9602](INFO): GPS fix at 20220107T205335: (36.803230, -121.787769) 2022-01-07T20:53:36.694Z,1641588816.694 [Default:CheckIn:Read_GPS] Stopped 2022-01-07T20:53:36.694Z,1641588816.694 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-01-07T20:53:44.510Z,1641588824.510 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20220107T182328/Courier0075.lzma 2022-01-07T20:53:45.512Z,1641588825.512 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Courier0075.lzma.bak 2022-01-07T20:53:45.512Z,1641588825.512 [DataOverHttps](INFO): SBD MOMSN=16416660 2022-01-07T20:54:01.398Z,1641588841.398 [DataOverHttps](INFO): Sending 222 bytes from file Logs/20220107T182328/Express0076.lzma 2022-01-07T20:54:02.400Z,1641588842.400 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Express0076.lzma.bak 2022-01-07T20:54:02.400Z,1641588842.400 [DataOverHttps](INFO): SBD MOMSN=16416663 2022-01-07T20:54:03.760Z,1641588843.760 [Default:CheckIn:Read_Iridium] Stopped 2022-01-07T20:54:03.760Z,1641588843.760 [Default:CheckIn:C.Wait] Running Loop=1 2022-01-07T20:54:03.760Z,1641588843.760 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-01-07T20:54:09.396Z,1641588849.396 [NAL9602](INFO): Not Powering down - fast GPS 2022-01-07T20:59:04.329Z,1641589144.329 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-01-07T20:59:04.329Z,1641589144.329 [Default:CheckIn:C.Wait] Stopped 2022-01-07T20:59:04.329Z,1641589144.329 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-01-07T20:59:04.330Z,1641589144.330 [Default:CheckIn:D] Running Loop=1 2022-01-07T20:59:04.732Z,1641589144.732 [Default:CheckIn:D] Stopped 2022-01-07T20:59:04.732Z,1641589144.732 [Default:CheckIn:E] Running Loop=1 2022-01-07T20:59:05.148Z,1641589145.148 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 175.791390 min 2022-01-07T20:59:05.149Z,1641589145.149 [Default:CheckIn:E] Stopped 2022-01-07T20:59:05.149Z,1641589145.149 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-01-07T20:59:05.149Z,1641589145.149 [Default:CheckIn] Stopped 2022-01-07T20:59:05.149Z,1641589145.149 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-01-07T20:59:05.149Z,1641589145.149 [Default:CheckIn](INFO): Running loop #31 2022-01-07T20:59:05.149Z,1641589145.149 [Default:CheckIn] Running Loop=31 2022-01-07T20:59:05.149Z,1641589145.149 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-01-07T20:59:05.149Z,1641589145.149 [Default:CheckIn:Read_GPS] Running Loop=1 2022-01-07T20:59:07.146Z,1641589147.146 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,205906.00,A,3648.15730,N,12147.28322,W,0.719,40.65,070122,,,A*4B 2022-01-07T20:59:07.148Z,1641589147.148 [NAL9602](INFO): GPS fix at 20220107T205906: (36.802622, -121.788054) 2022-01-07T20:59:07.160Z,1641589147.160 [Default:CheckIn:Read_GPS] Stopped 2022-01-07T20:59:07.160Z,1641589147.160 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-01-07T20:59:14.825Z,1641589154.825 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220107T182328/Courier0078.lzma 2022-01-07T20:59:15.828Z,1641589155.828 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Courier0078.lzma.bak 2022-01-07T20:59:15.828Z,1641589155.828 [DataOverHttps](INFO): SBD MOMSN=16416667 2022-01-07T20:59:31.882Z,1641589171.882 [DataOverHttps](INFO): Sending 146 bytes from file Logs/20220107T182328/Express0079.lzma 2022-01-07T20:59:32.884Z,1641589172.884 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Express0079.lzma.bak 2022-01-07T20:59:32.884Z,1641589172.884 [DataOverHttps](INFO): SBD MOMSN=16416670 2022-01-07T20:59:34.224Z,1641589174.224 [Default:CheckIn:Read_Iridium] Stopped 2022-01-07T20:59:34.224Z,1641589174.224 [Default:CheckIn:C.Wait] Running Loop=1 2022-01-07T20:59:34.224Z,1641589174.224 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-01-07T20:59:37.847Z,1641589177.847 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-01-07T20:59:37.922Z,1641589177.922 [NAL9602](ERROR): received: +CSQ:0 OK441, 2, 0, 0, 0 OK 2022-01-07T21:04:09.336Z,1641589449.336 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-01-07T21:04:34.805Z,1641589474.805 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-01-07T21:04:34.805Z,1641589474.805 [Default:CheckIn:C.Wait] Stopped 2022-01-07T21:04:34.805Z,1641589474.805 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-01-07T21:04:34.805Z,1641589474.805 [Default:CheckIn:D] Running Loop=1 2022-01-07T21:04:35.201Z,1641589475.201 [Default:CheckIn:D] Stopped 2022-01-07T21:04:35.202Z,1641589475.202 [Default:CheckIn:E] Running Loop=1 2022-01-07T21:04:35.607Z,1641589475.607 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 181.299219 min 2022-01-07T21:04:35.607Z,1641589475.607 [Default:CheckIn:E] Stopped 2022-01-07T21:04:35.607Z,1641589475.607 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-01-07T21:04:35.607Z,1641589475.607 [Default:CheckIn] Stopped 2022-01-07T21:04:35.607Z,1641589475.607 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-01-07T21:04:35.607Z,1641589475.607 [Default:CheckIn](INFO): Running loop #32 2022-01-07T21:04:35.607Z,1641589475.607 [Default:CheckIn] Running Loop=32 2022-01-07T21:04:35.608Z,1641589475.608 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-01-07T21:04:35.608Z,1641589475.608 [Default:CheckIn:Read_GPS] Running Loop=1 2022-01-07T21:04:37.618Z,1641589477.618 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,210436.00,A,3648.16171,N,12147.28488,W,1.030,40.65,070122,,,A*4B 2022-01-07T21:04:37.620Z,1641589477.620 [NAL9602](INFO): GPS fix at 20220107T210436: (36.802695, -121.788081) 2022-01-07T21:04:37.636Z,1641589477.636 [Default:CheckIn:Read_GPS] Stopped 2022-01-07T21:04:37.636Z,1641589477.636 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-01-07T21:04:45.446Z,1641589485.446 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20220107T182328/Courier0081.lzma 2022-01-07T21:04:46.448Z,1641589486.448 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Courier0081.lzma.bak 2022-01-07T21:04:46.448Z,1641589486.448 [DataOverHttps](INFO): SBD MOMSN=16416673 2022-01-07T21:05:05.483Z,1641589505.483 [DataOverHttps](INFO): Sending 208 bytes from file Logs/20220107T182328/Express0082.lzma 2022-01-07T21:05:06.484Z,1641589506.484 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Express0082.lzma.bak 2022-01-07T21:05:06.484Z,1641589506.484 [DataOverHttps](INFO): SBD MOMSN=16416676 2022-01-07T21:05:07.583Z,1641589507.583 [Default:CheckIn:Read_Iridium] Stopped 2022-01-07T21:05:07.583Z,1641589507.583 [Default:CheckIn:C.Wait] Running Loop=1 2022-01-07T21:05:07.583Z,1641589507.583 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-01-07T21:05:10.387Z,1641589510.387 [NAL9602](INFO): Not Powering down - fast GPS 2022-01-07T21:10:08.163Z,1641589808.163 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-01-07T21:10:08.163Z,1641589808.163 [Default:CheckIn:C.Wait] Stopped 2022-01-07T21:10:08.163Z,1641589808.163 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-01-07T21:10:08.164Z,1641589808.164 [Default:CheckIn:D] Running Loop=1 2022-01-07T21:10:08.558Z,1641589808.558 [Default:CheckIn:D] Stopped 2022-01-07T21:10:08.558Z,1641589808.558 [Default:CheckIn:E] Running Loop=1 2022-01-07T21:10:08.958Z,1641589808.958 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 186.855160 min 2022-01-07T21:10:08.958Z,1641589808.958 [Default:CheckIn:E] Stopped 2022-01-07T21:10:08.959Z,1641589808.959 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-01-07T21:10:08.959Z,1641589808.959 [Default:CheckIn] Stopped 2022-01-07T21:10:08.959Z,1641589808.959 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-01-07T21:10:08.959Z,1641589808.959 [Default:CheckIn](INFO): Running loop #33 2022-01-07T21:10:08.959Z,1641589808.959 [Default:CheckIn] Running Loop=33 2022-01-07T21:10:08.959Z,1641589808.959 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-01-07T21:10:08.959Z,1641589808.959 [Default:CheckIn:Read_GPS] Running Loop=1 2022-01-07T21:10:10.976Z,1641589810.976 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,211010.00,A,3648.16858,N,12147.28642,W,0.408,0.00,070122,,,A*75 2022-01-07T21:10:10.979Z,1641589810.979 [NAL9602](INFO): GPS fix at 20220107T211010: (36.802810, -121.788107) 2022-01-07T21:10:10.990Z,1641589810.990 [Default:CheckIn:Read_GPS] Stopped 2022-01-07T21:10:10.990Z,1641589810.990 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-01-07T21:10:18.222Z,1641589818.222 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220107T182328/Courier0084.lzma 2022-01-07T21:10:19.224Z,1641589819.224 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Courier0084.lzma.bak 2022-01-07T21:10:19.225Z,1641589819.225 [DataOverHttps](INFO): SBD MOMSN=16416680 2022-01-07T21:10:35.354Z,1641589835.354 [DataOverHttps](INFO): Sending 132 bytes from file Logs/20220107T182328/Express0085.lzma 2022-01-07T21:10:36.356Z,1641589836.356 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Express0085.lzma.bak 2022-01-07T21:10:36.356Z,1641589836.356 [DataOverHttps](INFO): SBD MOMSN=16416683 2022-01-07T21:10:37.647Z,1641589837.647 [Default:CheckIn:Read_Iridium] Stopped 2022-01-07T21:10:37.647Z,1641589837.647 [Default:CheckIn:C.Wait] Running Loop=1 2022-01-07T21:10:37.647Z,1641589837.647 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-01-07T21:10:41.672Z,1641589841.672 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-01-07T21:10:41.754Z,1641589841.754 [NAL9602](ERROR): received: +CSQ:0 OK441, 2, 0, 0, 0 OK 2022-01-07T21:15:13.208Z,1641590113.208 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-01-07T21:15:38.277Z,1641590138.277 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-01-07T21:15:38.277Z,1641590138.277 [Default:CheckIn:C.Wait] Stopped 2022-01-07T21:15:38.277Z,1641590138.277 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-01-07T21:15:38.277Z,1641590138.277 [Default:CheckIn:D] Running Loop=1 2022-01-07T21:15:38.690Z,1641590138.690 [Default:CheckIn:D] Stopped 2022-01-07T21:15:38.690Z,1641590138.690 [Default:CheckIn:E] Running Loop=1 2022-01-07T21:15:39.082Z,1641590139.082 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 192.357080 min 2022-01-07T21:15:39.082Z,1641590139.082 [Default:CheckIn:E] Stopped 2022-01-07T21:15:39.082Z,1641590139.082 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-01-07T21:15:39.082Z,1641590139.082 [Default:CheckIn] Stopped 2022-01-07T21:15:39.082Z,1641590139.082 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-01-07T21:15:39.082Z,1641590139.082 [Default:CheckIn](INFO): Running loop #34 2022-01-07T21:15:39.083Z,1641590139.083 [Default:CheckIn] Running Loop=34 2022-01-07T21:15:39.083Z,1641590139.083 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-01-07T21:15:39.083Z,1641590139.083 [Default:CheckIn:Read_GPS] Running Loop=1 2022-01-07T21:15:41.088Z,1641590141.088 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,211540.00,A,3648.16189,N,12147.28392,W,1.108,115.25,070122,,,A*7E 2022-01-07T21:15:41.090Z,1641590141.090 [NAL9602](INFO): GPS fix at 20220107T211540: (36.802698, -121.788065) 2022-01-07T21:15:41.101Z,1641590141.101 [Default:CheckIn:Read_GPS] Stopped 2022-01-07T21:15:41.101Z,1641590141.101 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-01-07T21:15:48.478Z,1641590148.478 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20220107T182328/Courier0087.lzma 2022-01-07T21:15:49.480Z,1641590149.480 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Courier0087.lzma.bak 2022-01-07T21:15:49.480Z,1641590149.480 [DataOverHttps](INFO): SBD MOMSN=16416686 2022-01-07T21:16:05.607Z,1641590165.607 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20220107T182328/Express0088.lzma 2022-01-07T21:16:06.608Z,1641590166.608 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Express0088.lzma.bak 2022-01-07T21:16:06.608Z,1641590166.608 [DataOverHttps](INFO): SBD MOMSN=16416689 2022-01-07T21:16:07.765Z,1641590167.765 [Default:CheckIn:Read_Iridium] Stopped 2022-01-07T21:16:07.765Z,1641590167.765 [Default:CheckIn:C.Wait] Running Loop=1 2022-01-07T21:16:07.765Z,1641590167.765 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-01-07T21:16:13.403Z,1641590173.403 [NAL9602](INFO): Not Powering down - fast GPS 2022-01-07T21:21:08.351Z,1641590468.351 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-01-07T21:21:08.351Z,1641590468.351 [Default:CheckIn:C.Wait] Stopped 2022-01-07T21:21:08.351Z,1641590468.351 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-01-07T21:21:08.351Z,1641590468.351 [Default:CheckIn:D] Running Loop=1 2022-01-07T21:21:08.764Z,1641590468.764 [Default:CheckIn:D] Stopped 2022-01-07T21:21:08.764Z,1641590468.764 [Default:CheckIn:E] Running Loop=1 2022-01-07T21:21:09.171Z,1641590469.171 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 197.858577 min 2022-01-07T21:21:09.171Z,1641590469.171 [Default:CheckIn:E] Stopped 2022-01-07T21:21:09.171Z,1641590469.171 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-01-07T21:21:09.171Z,1641590469.171 [Default:CheckIn] Stopped 2022-01-07T21:21:09.171Z,1641590469.171 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-01-07T21:21:09.171Z,1641590469.171 [Default:CheckIn](INFO): Running loop #35 2022-01-07T21:21:09.172Z,1641590469.172 [Default:CheckIn] Running Loop=35 2022-01-07T21:21:09.172Z,1641590469.172 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-01-07T21:21:09.172Z,1641590469.172 [Default:CheckIn:Read_GPS] Running Loop=1 2022-01-07T21:21:11.169Z,1641590471.169 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,212110.00,A,3648.15905,N,12147.27891,W,0.272,115.25,070122,,,A*7B 2022-01-07T21:21:11.172Z,1641590471.172 [NAL9602](INFO): GPS fix at 20220107T212110: (36.802651, -121.787982) 2022-01-07T21:21:11.183Z,1641590471.183 [Default:CheckIn:Read_GPS] Stopped 2022-01-07T21:21:11.183Z,1641590471.183 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-01-07T21:21:18.322Z,1641590478.322 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220107T182328/Courier0090.lzma 2022-01-07T21:21:19.324Z,1641590479.324 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Courier0090.lzma.bak 2022-01-07T21:21:19.324Z,1641590479.324 [DataOverHttps](INFO): SBD MOMSN=16416693 2022-01-07T21:21:35.366Z,1641590495.366 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20220107T182328/Express0091.lzma 2022-01-07T21:21:36.368Z,1641590496.368 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Express0091.lzma.bak 2022-01-07T21:21:36.368Z,1641590496.368 [DataOverHttps](INFO): SBD MOMSN=16416696 2022-01-07T21:21:37.459Z,1641590497.459 [Default:CheckIn:Read_Iridium] Stopped 2022-01-07T21:21:37.459Z,1641590497.459 [Default:CheckIn:C.Wait] Running Loop=1 2022-01-07T21:21:37.459Z,1641590497.459 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-01-07T21:21:41.868Z,1641590501.868 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-01-07T21:21:41.946Z,1641590501.946 [NAL9602](ERROR): received: +CSQ:0 OK441, 2, 0, 0, 0 OK 2022-01-07T21:26:13.374Z,1641590773.374 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-01-07T21:26:38.023Z,1641590798.023 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-01-07T21:26:38.024Z,1641590798.024 [Default:CheckIn:C.Wait] Stopped 2022-01-07T21:26:38.024Z,1641590798.024 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-01-07T21:26:38.024Z,1641590798.024 [Default:CheckIn:D] Running Loop=1 2022-01-07T21:26:38.414Z,1641590798.414 [Default:CheckIn:D] Stopped 2022-01-07T21:26:38.414Z,1641590798.414 [Default:CheckIn:E] Running Loop=1 2022-01-07T21:26:38.827Z,1641590798.827 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 203.352751 min 2022-01-07T21:26:38.827Z,1641590798.827 [Default:CheckIn:E] Stopped 2022-01-07T21:26:38.827Z,1641590798.827 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-01-07T21:26:38.827Z,1641590798.827 [Default:CheckIn] Stopped 2022-01-07T21:26:38.827Z,1641590798.827 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-01-07T21:26:38.827Z,1641590798.827 [Default:CheckIn](INFO): Running loop #36 2022-01-07T21:26:38.828Z,1641590798.828 [Default:CheckIn] Running Loop=36 2022-01-07T21:26:38.828Z,1641590798.828 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-01-07T21:26:38.828Z,1641590798.828 [Default:CheckIn:Read_GPS] Running Loop=1 2022-01-07T21:26:40.836Z,1641590800.836 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,212640.00,A,3648.16092,N,12147.28023,W,0.778,0.00,070122,,,A*7E 2022-01-07T21:26:40.839Z,1641590800.839 [NAL9602](INFO): GPS fix at 20220107T212640: (36.802682, -121.788004) 2022-01-07T21:26:40.849Z,1641590800.849 [Default:CheckIn:Read_GPS] Stopped 2022-01-07T21:26:40.849Z,1641590800.849 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-01-07T21:26:48.418Z,1641590808.418 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20220107T182328/Courier0093.lzma 2022-01-07T21:26:49.420Z,1641590809.420 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Courier0093.lzma.bak 2022-01-07T21:26:49.421Z,1641590809.421 [DataOverHttps](INFO): SBD MOMSN=16416699 2022-01-07T21:27:08.314Z,1641590828.314 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20220107T182328/Express0094.lzma 2022-01-07T21:27:09.316Z,1641590829.316 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Express0094.lzma.bak 2022-01-07T21:27:09.316Z,1641590829.316 [DataOverHttps](INFO): SBD MOMSN=16416702 2022-01-07T21:27:10.774Z,1641590830.774 [Default:CheckIn:Read_Iridium] Stopped 2022-01-07T21:27:10.774Z,1641590830.774 [Default:CheckIn:C.Wait] Running Loop=1 2022-01-07T21:27:10.774Z,1641590830.774 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-01-07T21:27:13.587Z,1641590833.587 [NAL9602](INFO): Not Powering down - fast GPS 2022-01-07T21:32:11.480Z,1641591131.480 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-01-07T21:32:11.480Z,1641591131.480 [Default:CheckIn:C.Wait] Stopped 2022-01-07T21:32:11.480Z,1641591131.480 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-01-07T21:32:11.481Z,1641591131.481 [Default:CheckIn:D] Running Loop=1 2022-01-07T21:32:11.878Z,1641591131.878 [Default:CheckIn:D] Stopped 2022-01-07T21:32:11.878Z,1641591131.878 [Default:CheckIn:E] Running Loop=1 2022-01-07T21:32:12.280Z,1641591132.280 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 208.910498 min 2022-01-07T21:32:12.280Z,1641591132.280 [Default:CheckIn:E] Stopped 2022-01-07T21:32:12.280Z,1641591132.280 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-01-07T21:32:12.280Z,1641591132.280 [Default:CheckIn] Stopped 2022-01-07T21:32:12.280Z,1641591132.280 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-01-07T21:32:12.281Z,1641591132.281 [Default:CheckIn](INFO): Running loop #37 2022-01-07T21:32:12.281Z,1641591132.281 [Default:CheckIn] Running Loop=37 2022-01-07T21:32:12.281Z,1641591132.281 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-01-07T21:32:12.281Z,1641591132.281 [Default:CheckIn:Read_GPS] Running Loop=1 2022-01-07T21:32:14.289Z,1641591134.289 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,213213.00,A,3648.16862,N,12147.27981,W,0.330,135.35,070122,,,A*7D 2022-01-07T21:32:14.292Z,1641591134.292 [NAL9602](INFO): GPS fix at 20220107T213213: (36.802810, -121.787997) 2022-01-07T21:32:14.327Z,1641591134.327 [Default:CheckIn:Read_GPS] Stopped 2022-01-07T21:32:14.327Z,1641591134.327 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-01-07T21:32:22.338Z,1641591142.338 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220107T182328/Courier0096.lzma 2022-01-07T21:32:23.340Z,1641591143.340 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Courier0096.lzma.bak 2022-01-07T21:32:23.341Z,1641591143.341 [DataOverHttps](INFO): SBD MOMSN=16416706 2022-01-07T21:32:39.687Z,1641591159.687 [DataOverHttps](INFO): Sending 132 bytes from file Logs/20220107T182328/Express0097.lzma 2022-01-07T21:32:40.688Z,1641591160.688 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Express0097.lzma.bak 2022-01-07T21:32:40.689Z,1641591160.689 [DataOverHttps](INFO): SBD MOMSN=16416709 2022-01-07T21:32:41.774Z,1641591161.774 [Default:CheckIn:Read_Iridium] Stopped 2022-01-07T21:32:41.775Z,1641591161.775 [Default:CheckIn:C.Wait] Running Loop=1 2022-01-07T21:32:41.775Z,1641591161.775 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-01-07T21:32:44.996Z,1641591164.996 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-01-07T21:32:45.070Z,1641591165.070 [NAL9602](ERROR): received: +CSQ:0 OK441, 2, 0, 0, 0 OK 2022-01-07T21:34:15.921Z,1641591255.921 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2022-01-07T21:34:15.927Z,1641591255.927 [BPC1](INFO): Received data from all battery sticks. 2022-01-07T21:37:16.599Z,1641591436.599 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-01-07T21:37:42.473Z,1641591462.473 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-01-07T21:37:42.474Z,1641591462.474 [Default:CheckIn:C.Wait] Stopped 2022-01-07T21:37:42.474Z,1641591462.474 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-01-07T21:37:42.475Z,1641591462.475 [Default:CheckIn:D] Running Loop=1 2022-01-07T21:37:42.889Z,1641591462.889 [Default:CheckIn:D] Stopped 2022-01-07T21:37:42.889Z,1641591462.889 [Default:CheckIn:E] Running Loop=1 2022-01-07T21:37:43.274Z,1641591463.274 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 214.427344 min 2022-01-07T21:37:43.275Z,1641591463.275 [Default:CheckIn:E] Stopped 2022-01-07T21:37:43.275Z,1641591463.275 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-01-07T21:37:43.275Z,1641591463.275 [Default:CheckIn] Stopped 2022-01-07T21:37:43.275Z,1641591463.275 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-01-07T21:37:43.275Z,1641591463.275 [Default:CheckIn](INFO): Running loop #38 2022-01-07T21:37:43.275Z,1641591463.275 [Default:CheckIn] Running Loop=38 2022-01-07T21:37:43.275Z,1641591463.275 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-01-07T21:37:43.275Z,1641591463.275 [Default:CheckIn:Read_GPS] Running Loop=1 2022-01-07T21:37:45.290Z,1641591465.290 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,213744.00,A,3648.16760,N,12147.28098,W,1.458,59.88,070122,,,A*4C 2022-01-07T21:37:45.293Z,1641591465.293 [NAL9602](INFO): GPS fix at 20220107T213744: (36.802793, -121.788016) 2022-01-07T21:37:45.304Z,1641591465.304 [Default:CheckIn:Read_GPS] Stopped 2022-01-07T21:37:45.304Z,1641591465.304 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-01-07T21:37:52.914Z,1641591472.914 [DataOverHttps](INFO): Sending 84 bytes from file Logs/20220107T182328/Courier0099.lzma 2022-01-07T21:37:53.916Z,1641591473.916 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Courier0099.lzma.bak 2022-01-07T21:37:53.916Z,1641591473.916 [DataOverHttps](INFO): SBD MOMSN=16416712 2022-01-07T21:38:09.886Z,1641591489.886 [DataOverHttps](INFO): Sending 212 bytes from file Logs/20220107T182328/Express0100.lzma 2022-01-07T21:38:10.892Z,1641591490.892 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Express0100.lzma.bak 2022-01-07T21:38:10.892Z,1641591490.892 [DataOverHttps](INFO): SBD MOMSN=16416715 2022-01-07T21:38:12.375Z,1641591492.375 [Default:CheckIn:Read_Iridium] Stopped 2022-01-07T21:38:12.375Z,1641591492.375 [Default:CheckIn:C.Wait] Running Loop=1 2022-01-07T21:38:12.375Z,1641591492.375 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-01-07T21:38:17.603Z,1641591497.603 [NAL9602](INFO): Not Powering down - fast GPS 2022-01-07T21:43:13.079Z,1641591793.079 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-01-07T21:43:13.079Z,1641591793.079 [Default:CheckIn:C.Wait] Stopped 2022-01-07T21:43:13.079Z,1641591793.079 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-01-07T21:43:13.079Z,1641591793.079 [Default:CheckIn:D] Running Loop=1 2022-01-07T21:43:13.458Z,1641591793.458 [Default:CheckIn:D] Stopped 2022-01-07T21:43:13.458Z,1641591793.458 [Default:CheckIn:E] Running Loop=1 2022-01-07T21:43:13.876Z,1641591793.876 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 219.936816 min 2022-01-07T21:43:13.876Z,1641591793.876 [Default:CheckIn:E] Stopped 2022-01-07T21:43:13.876Z,1641591793.876 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-01-07T21:43:13.876Z,1641591793.876 [Default:CheckIn] Stopped 2022-01-07T21:43:13.876Z,1641591793.876 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-01-07T21:43:13.876Z,1641591793.876 [Default:CheckIn](INFO): Running loop #39 2022-01-07T21:43:13.876Z,1641591793.876 [Default:CheckIn] Running Loop=39 2022-01-07T21:43:13.876Z,1641591793.876 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-01-07T21:43:13.877Z,1641591793.877 [Default:CheckIn:Read_GPS] Running Loop=1 2022-01-07T21:43:15.873Z,1641591795.873 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,214315.00,A,3648.16453,N,12147.28538,W,0.233,161.84,070122,,,A*7B 2022-01-07T21:43:15.876Z,1641591795.876 [NAL9602](INFO): GPS fix at 20220107T214315: (36.802742, -121.788090) 2022-01-07T21:43:15.887Z,1641591795.887 [Default:CheckIn:Read_GPS] Stopped 2022-01-07T21:43:15.887Z,1641591795.887 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-01-07T21:43:23.802Z,1641591803.802 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220107T182328/Courier0102.lzma 2022-01-07T21:43:24.805Z,1641591804.805 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Courier0102.lzma.bak 2022-01-07T21:43:24.805Z,1641591804.805 [DataOverHttps](INFO): SBD MOMSN=16416719 2022-01-07T21:43:40.000Z,1641591821.000 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20220107T182328/Express0103.lzma 2022-01-07T21:43:42.000Z,1641591822.000 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Express0103.lzma.bak 2022-01-07T21:43:42.001Z,1641591822.001 [DataOverHttps](INFO): SBD MOMSN=16416722 2022-01-07T21:43:43.366Z,1641591823.366 [Default:CheckIn:Read_Iridium] Stopped 2022-01-07T21:43:43.366Z,1641591823.366 [Default:CheckIn:C.Wait] Running Loop=1 2022-01-07T21:43:43.366Z,1641591823.366 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-01-07T21:43:46.576Z,1641591826.576 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-01-07T21:43:46.650Z,1641591826.650 [NAL9602](ERROR): received: +CSQ:0 OK441, 2, 0, 0, 0 OK 2022-01-07T21:48:18.556Z,1641592098.556 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-01-07T21:48:44.018Z,1641592124.018 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-01-07T21:48:44.018Z,1641592124.018 [Default:CheckIn:C.Wait] Stopped 2022-01-07T21:48:44.018Z,1641592124.018 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-01-07T21:48:44.019Z,1641592124.019 [Default:CheckIn:D] Running Loop=1 2022-01-07T21:48:44.426Z,1641592124.426 [Default:CheckIn:D] Stopped 2022-01-07T21:48:44.426Z,1641592124.426 [Default:CheckIn:E] Running Loop=1 2022-01-07T21:48:44.839Z,1641592124.839 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 225.452946 min 2022-01-07T21:48:44.840Z,1641592124.840 [Default:CheckIn:E] Stopped 2022-01-07T21:48:44.840Z,1641592124.840 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-01-07T21:48:44.840Z,1641592124.840 [Default:CheckIn] Stopped 2022-01-07T21:48:44.840Z,1641592124.840 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-01-07T21:48:44.840Z,1641592124.840 [Default:CheckIn](INFO): Running loop #40 2022-01-07T21:48:44.840Z,1641592124.840 [Default:CheckIn] Running Loop=40 2022-01-07T21:48:44.840Z,1641592124.840 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-01-07T21:48:44.841Z,1641592124.841 [Default:CheckIn:Read_GPS] Running Loop=1 2022-01-07T21:48:46.837Z,1641592126.837 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,214846.00,A,3648.16286,N,12147.28015,W,0.311,161.77,070122,,,A*7F 2022-01-07T21:48:46.840Z,1641592126.840 [NAL9602](INFO): GPS fix at 20220107T214846: (36.802714, -121.788003) 2022-01-07T21:48:46.875Z,1641592126.875 [Default:CheckIn:Read_GPS] Stopped 2022-01-07T21:48:46.876Z,1641592126.876 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-01-07T21:48:56.926Z,1641592136.926 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220107T182328/Courier0105.lzma 2022-01-07T21:48:57.928Z,1641592137.928 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Courier0105.lzma.bak 2022-01-07T21:48:57.929Z,1641592137.929 [DataOverHttps](INFO): SBD MOMSN=16416725 2022-01-07T21:49:13.794Z,1641592153.794 [DataOverHttps](INFO): Sending 212 bytes from file Logs/20220107T182328/Express0106.lzma 2022-01-07T21:49:14.796Z,1641592154.796 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Express0106.lzma.bak 2022-01-07T21:49:14.797Z,1641592154.797 [DataOverHttps](INFO): SBD MOMSN=16416728 2022-01-07T21:49:15.898Z,1641592155.898 [Default:CheckIn:Read_Iridium] Stopped 2022-01-07T21:49:15.898Z,1641592155.898 [Default:CheckIn:C.Wait] Running Loop=1 2022-01-07T21:49:15.898Z,1641592155.898 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-01-07T21:49:19.483Z,1641592159.483 [NAL9602](INFO): Not Powering down - fast GPS 2022-01-07T21:54:16.566Z,1641592456.566 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-01-07T21:54:16.566Z,1641592456.566 [Default:CheckIn:C.Wait] Stopped 2022-01-07T21:54:16.566Z,1641592456.566 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-01-07T21:54:16.599Z,1641592456.599 [Default:CheckIn:D] Running Loop=1 2022-01-07T21:54:16.966Z,1641592456.966 [Default:CheckIn:D] Stopped 2022-01-07T21:54:16.966Z,1641592456.966 [Default:CheckIn:E] Running Loop=1 2022-01-07T21:54:17.380Z,1641592457.380 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 230.995296 min 2022-01-07T21:54:17.380Z,1641592457.380 [Default:CheckIn:E] Stopped 2022-01-07T21:54:17.381Z,1641592457.381 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-01-07T21:54:17.381Z,1641592457.381 [Default:CheckIn] Stopped 2022-01-07T21:54:17.381Z,1641592457.381 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-01-07T21:54:17.381Z,1641592457.381 [Default:CheckIn](INFO): Running loop #41 2022-01-07T21:54:17.381Z,1641592457.381 [Default:CheckIn] Running Loop=41 2022-01-07T21:54:17.381Z,1641592457.381 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-01-07T21:54:17.381Z,1641592457.381 [Default:CheckIn:Read_GPS] Running Loop=1 2022-01-07T21:54:19.385Z,1641592459.385 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,215418.00,A,3648.16057,N,12147.28271,W,0.952,134.00,070122,,,A*7A 2022-01-07T21:54:19.398Z,1641592459.398 [NAL9602](INFO): GPS fix at 20220107T215418: (36.802676, -121.788045) 2022-01-07T21:54:19.410Z,1641592459.410 [Default:CheckIn:Read_GPS] Stopped 2022-01-07T21:54:19.410Z,1641592459.410 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-01-07T21:54:27.274Z,1641592467.274 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220107T182328/Courier0108.lzma 2022-01-07T21:54:28.276Z,1641592468.276 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Courier0108.lzma.bak 2022-01-07T21:54:28.277Z,1641592468.277 [DataOverHttps](INFO): SBD MOMSN=16416732 2022-01-07T21:54:44.150Z,1641592484.150 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20220107T182328/Express0109.lzma 2022-01-07T21:54:45.152Z,1641592485.152 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Express0109.lzma.bak 2022-01-07T21:54:45.153Z,1641592485.153 [DataOverHttps](INFO): SBD MOMSN=16416735 2022-01-07T21:54:46.482Z,1641592486.482 [Default:CheckIn:Read_Iridium] Stopped 2022-01-07T21:54:46.494Z,1641592486.494 [Default:CheckIn:C.Wait] Running Loop=1 2022-01-07T21:54:46.494Z,1641592486.494 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-01-07T21:54:50.122Z,1641592490.122 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-01-07T21:54:50.203Z,1641592490.203 [NAL9602](ERROR): received: +CSQ:0 OK441, 2, 0, 0, 0 OK 2022-01-07T21:58:08.981Z,1641592688.981 [NAL9602](INFO): SBD MO Status=2, MOMSN=31441, MT Status=2, MTMSN=0 2022-01-07T21:58:08.981Z,1641592688.981 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-01-07T21:59:21.720Z,1641592761.720 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-01-07T21:59:47.186Z,1641592787.186 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-01-07T21:59:47.186Z,1641592787.186 [Default:CheckIn:C.Wait] Stopped 2022-01-07T21:59:47.186Z,1641592787.186 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-01-07T21:59:47.186Z,1641592787.186 [Default:CheckIn:D] Running Loop=1 2022-01-07T21:59:47.594Z,1641592787.594 [Default:CheckIn:D] Stopped 2022-01-07T21:59:47.594Z,1641592787.594 [Default:CheckIn:E] Running Loop=1 2022-01-07T21:59:48.020Z,1641592788.020 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 236.505745 min 2022-01-07T21:59:48.020Z,1641592788.020 [Default:CheckIn:E] Stopped 2022-01-07T21:59:48.020Z,1641592788.020 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-01-07T21:59:48.020Z,1641592788.020 [Default:CheckIn] Stopped 2022-01-07T21:59:48.020Z,1641592788.020 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-01-07T21:59:48.021Z,1641592788.021 [Default:CheckIn](INFO): Running loop #42 2022-01-07T21:59:48.021Z,1641592788.021 [Default:CheckIn] Running Loop=42 2022-01-07T21:59:48.021Z,1641592788.021 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-01-07T21:59:48.021Z,1641592788.021 [Default:CheckIn:Read_GPS] Running Loop=1 2022-01-07T21:59:50.006Z,1641592790.006 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,215949.00,A,3648.16742,N,12147.29157,W,0.816,134.00,070122,,,A*77 2022-01-07T21:59:50.008Z,1641592790.008 [NAL9602](INFO): GPS fix at 20220107T215949: (36.802790, -121.788193) 2022-01-07T21:59:50.019Z,1641592790.019 [Default:CheckIn:Read_GPS] Stopped 2022-01-07T21:59:50.019Z,1641592790.019 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-01-07T21:59:57.038Z,1641592797.038 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20220107T182328/Courier0111.lzma 2022-01-07T21:59:58.040Z,1641592798.040 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Courier0111.lzma.bak 2022-01-07T21:59:58.040Z,1641592798.040 [DataOverHttps](INFO): SBD MOMSN=16416738 2022-01-07T22:00:13.921Z,1641592813.921 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20220107T182328/Express0112.lzma 2022-01-07T22:00:14.920Z,1641592814.920 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Express0112.lzma.bak 2022-01-07T22:00:14.920Z,1641592814.920 [DataOverHttps](INFO): SBD MOMSN=16416741 2022-01-07T22:00:16.303Z,1641592816.303 [Default:CheckIn:Read_Iridium] Stopped 2022-01-07T22:00:16.303Z,1641592816.303 [Default:CheckIn:C.Wait] Running Loop=1 2022-01-07T22:00:16.303Z,1641592816.303 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-01-07T22:00:22.371Z,1641592822.371 [NAL9602](INFO): Not Powering down - fast GPS 2022-01-07T22:05:17.095Z,1641593117.095 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-01-07T22:05:17.095Z,1641593117.095 [Default:CheckIn:C.Wait] Stopped 2022-01-07T22:05:17.095Z,1641593117.095 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-01-07T22:05:17.096Z,1641593117.096 [Default:CheckIn:D] Running Loop=1 2022-01-07T22:05:17.505Z,1641593117.505 [Default:CheckIn:D] Stopped 2022-01-07T22:05:17.505Z,1641593117.505 [Default:CheckIn:E] Running Loop=1 2022-01-07T22:05:17.891Z,1641593117.891 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 242.004281 min 2022-01-07T22:05:17.891Z,1641593117.891 [Default:CheckIn:E] Stopped 2022-01-07T22:05:17.891Z,1641593117.891 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-01-07T22:05:17.891Z,1641593117.891 [Default:CheckIn] Stopped 2022-01-07T22:05:17.891Z,1641593117.891 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-01-07T22:05:17.891Z,1641593117.891 [Default:CheckIn](INFO): Running loop #43 2022-01-07T22:05:17.891Z,1641593117.891 [Default:CheckIn] Running Loop=43 2022-01-07T22:05:17.892Z,1641593117.892 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-01-07T22:05:17.892Z,1641593117.892 [Default:CheckIn:Read_GPS] Running Loop=1 2022-01-07T22:05:19.910Z,1641593119.910 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,220519.00,A,3648.16792,N,12147.28552,W,1.147,0.00,070122,,,A*7F 2022-01-07T22:05:19.912Z,1641593119.912 [NAL9602](INFO): GPS fix at 20220107T220519: (36.802799, -121.788092) 2022-01-07T22:05:19.923Z,1641593119.923 [Default:CheckIn:Read_GPS] Stopped 2022-01-07T22:05:19.923Z,1641593119.923 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-01-07T22:05:27.294Z,1641593127.294 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220107T182328/Courier0114.lzma 2022-01-07T22:05:28.296Z,1641593128.296 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Courier0114.lzma.bak 2022-01-07T22:05:28.297Z,1641593128.297 [DataOverHttps](INFO): SBD MOMSN=16416745 2022-01-07T22:05:44.262Z,1641593144.262 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20220107T182328/Express0115.lzma 2022-01-07T22:05:45.264Z,1641593145.264 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Express0115.lzma.bak 2022-01-07T22:05:45.265Z,1641593145.265 [DataOverHttps](INFO): SBD MOMSN=16416748 2022-01-07T22:05:46.587Z,1641593146.587 [Default:CheckIn:Read_Iridium] Stopped 2022-01-07T22:05:46.587Z,1641593146.587 [Default:CheckIn:C.Wait] Running Loop=1 2022-01-07T22:05:46.587Z,1641593146.587 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-01-07T22:05:50.604Z,1641593150.604 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-01-07T22:05:50.686Z,1641593150.686 [NAL9602](ERROR): received: +CSQ:0 OK441, 2, 0, 0, 0 OK 2022-01-07T22:06:31.409Z,1641593191.409 [NAL9602](INFO): SBD MO Status=2, MOMSN=31441, MT Status=2, MTMSN=0 2022-01-07T22:06:31.409Z,1641593191.409 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-01-07T22:07:36.113Z,1641593256.113 [NAL9602](INFO): SBD MO Status=2, MOMSN=31441, MT Status=2, MTMSN=0 2022-01-07T22:07:36.113Z,1641593256.113 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-01-07T22:10:22.630Z,1641593422.630 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-01-07T22:10:47.326Z,1641593447.326 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-01-07T22:10:47.327Z,1641593447.327 [Default:CheckIn:C.Wait] Stopped 2022-01-07T22:10:47.327Z,1641593447.327 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-01-07T22:10:47.327Z,1641593447.327 [Default:CheckIn:D] Running Loop=1 2022-01-07T22:10:47.687Z,1641593447.687 [Default:CheckIn:D] Stopped 2022-01-07T22:10:47.687Z,1641593447.687 [Default:CheckIn:E] Running Loop=1 2022-01-07T22:10:48.102Z,1641593448.102 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 247.507292 min 2022-01-07T22:10:48.102Z,1641593448.102 [Default:CheckIn:E] Stopped 2022-01-07T22:10:48.102Z,1641593448.102 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-01-07T22:10:48.102Z,1641593448.102 [Default:CheckIn] Stopped 2022-01-07T22:10:48.102Z,1641593448.102 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-01-07T22:10:48.102Z,1641593448.102 [Default:CheckIn](INFO): Running loop #44 2022-01-07T22:10:48.103Z,1641593448.103 [Default:CheckIn] Running Loop=44 2022-01-07T22:10:48.103Z,1641593448.103 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-01-07T22:10:48.103Z,1641593448.103 [Default:CheckIn:Read_GPS] Running Loop=1 2022-01-07T22:10:50.102Z,1641593450.102 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,221049.00,A,3648.16632,N,12147.27938,W,0.680,155.13,070122,,,A*74 2022-01-07T22:10:50.104Z,1641593450.104 [NAL9602](INFO): GPS fix at 20220107T221049: (36.802772, -121.787990) 2022-01-07T22:10:50.151Z,1641593450.151 [Default:CheckIn:Read_GPS] Stopped 2022-01-07T22:10:50.151Z,1641593450.151 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-01-07T22:11:00.250Z,1641593460.250 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20220107T182328/Courier0117.lzma 2022-01-07T22:11:01.252Z,1641593461.252 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Courier0117.lzma.bak 2022-01-07T22:11:01.252Z,1641593461.252 [DataOverHttps](INFO): SBD MOMSN=16416751 2022-01-07T22:11:17.194Z,1641593477.194 [DataOverHttps](INFO): Sending 209 bytes from file Logs/20220107T182328/Express0118.lzma 2022-01-07T22:11:18.196Z,1641593478.196 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Express0118.lzma.bak 2022-01-07T22:11:18.197Z,1641593478.197 [DataOverHttps](INFO): SBD MOMSN=16416754 2022-01-07T22:11:19.291Z,1641593479.291 [Default:CheckIn:Read_Iridium] Stopped 2022-01-07T22:11:19.291Z,1641593479.291 [Default:CheckIn:C.Wait] Running Loop=1 2022-01-07T22:11:19.291Z,1641593479.291 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-01-07T22:11:22.503Z,1641593482.503 [NAL9602](INFO): Not Powering down - fast GPS 2022-01-07T22:16:19.900Z,1641593779.900 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-01-07T22:16:19.900Z,1641593779.900 [Default:CheckIn:C.Wait] Stopped 2022-01-07T22:16:19.900Z,1641593779.900 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-01-07T22:16:19.901Z,1641593779.901 [Default:CheckIn:D] Running Loop=1 2022-01-07T22:16:20.317Z,1641593780.317 [Default:CheckIn:D] Stopped 2022-01-07T22:16:20.317Z,1641593780.317 [Default:CheckIn:E] Running Loop=1 2022-01-07T22:16:20.706Z,1641593780.706 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 253.051139 min 2022-01-07T22:16:20.706Z,1641593780.706 [Default:CheckIn:E] Stopped 2022-01-07T22:16:20.706Z,1641593780.706 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-01-07T22:16:20.706Z,1641593780.706 [Default:CheckIn] Stopped 2022-01-07T22:16:20.706Z,1641593780.706 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-01-07T22:16:20.707Z,1641593780.707 [Default:CheckIn](INFO): Running loop #45 2022-01-07T22:16:20.707Z,1641593780.707 [Default:CheckIn] Running Loop=45 2022-01-07T22:16:20.707Z,1641593780.707 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-01-07T22:16:20.707Z,1641593780.707 [Default:CheckIn:Read_GPS] Running Loop=1 2022-01-07T22:16:22.726Z,1641593782.726 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,221622.00,A,3648.03674,N,12147.26833,W,21.596,181.31,070122,,,A*4C 2022-01-07T22:16:22.728Z,1641593782.728 [NAL9602](INFO): GPS fix at 20220107T221622: (36.800612, -121.787806) 2022-01-07T22:16:22.739Z,1641593782.739 [Default:CheckIn:Read_GPS] Stopped 2022-01-07T22:16:22.739Z,1641593782.739 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-01-07T22:16:29.962Z,1641593789.962 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220107T182328/Courier0120.lzma 2022-01-07T22:16:30.964Z,1641593790.964 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Courier0120.lzma.bak 2022-01-07T22:16:30.965Z,1641593790.965 [DataOverHttps](INFO): SBD MOMSN=16416758 2022-01-07T22:16:53.428Z,1641593813.428 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-01-07T22:16:53.506Z,1641593813.506 [NAL9602](ERROR): received: +CSQ:0 OK441, 2, 0, 0, 0 OK 2022-01-07T22:17:18.102Z,1641593838.102 [DataOverHttps](INFO): Sending 138 bytes from file Logs/20220107T182328/Express0121.lzma 2022-01-07T22:17:19.104Z,1641593839.104 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Express0121.lzma.bak 2022-01-07T22:17:19.105Z,1641593839.105 [DataOverHttps](INFO): SBD MOMSN=16416761 2022-01-07T22:17:20.515Z,1641593840.515 [Default:CheckIn:Read_Iridium] Stopped 2022-01-07T22:17:20.516Z,1641593840.516 [Default:CheckIn:C.Wait] Running Loop=1 2022-01-07T22:17:20.516Z,1641593840.516 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-01-07T22:21:25.392Z,1641594085.392 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-01-07T22:21:56.087Z,1641594116.087 [NAL9602](INFO): Not Powering down - fast GPS 2022-01-07T22:22:21.172Z,1641594141.172 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-01-07T22:22:21.172Z,1641594141.172 [Default:CheckIn:C.Wait] Stopped 2022-01-07T22:22:21.172Z,1641594141.172 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-01-07T22:22:21.172Z,1641594141.172 [Default:CheckIn:D] Running Loop=1 2022-01-07T22:22:21.607Z,1641594141.607 [Default:CheckIn:D] Stopped 2022-01-07T22:22:21.607Z,1641594141.607 [Default:CheckIn:E] Running Loop=1 2022-01-07T22:22:21.967Z,1641594141.967 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 259.072624 min 2022-01-07T22:22:21.967Z,1641594141.967 [Default:CheckIn:E] Stopped 2022-01-07T22:22:21.968Z,1641594141.968 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-01-07T22:22:21.968Z,1641594141.968 [Default:CheckIn] Stopped 2022-01-07T22:22:21.968Z,1641594141.968 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-01-07T22:22:21.968Z,1641594141.968 [Default:CheckIn](INFO): Running loop #46 2022-01-07T22:22:21.968Z,1641594141.968 [Default:CheckIn] Running Loop=46 2022-01-07T22:22:21.968Z,1641594141.968 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-01-07T22:22:21.968Z,1641594141.968 [Default:CheckIn:Read_GPS] Running Loop=1 2022-01-07T22:22:23.961Z,1641594143.961 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,222223.00,A,3648.17184,N,12147.27435,W,0.622,88.56,070122,,,A*4A 2022-01-07T22:22:23.964Z,1641594143.964 [NAL9602](INFO): GPS fix at 20220107T222223: (36.802864, -121.787906) 2022-01-07T22:22:24.040Z,1641594144.040 [Default:CheckIn:Read_GPS] Stopped 2022-01-07T22:22:24.040Z,1641594144.040 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-01-07T22:22:36.062Z,1641594156.062 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220107T182328/Courier0123.lzma 2022-01-07T22:22:37.065Z,1641594157.065 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Courier0123.lzma.bak 2022-01-07T22:22:37.065Z,1641594157.065 [DataOverHttps](INFO): SBD MOMSN=16416764 2022-01-07T22:22:54.400Z,1641594174.400 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-01-07T22:22:54.474Z,1641594174.474 [NAL9602](ERROR): received: +CSQ:0 OK441, 2, 0, 0, 0 OK 2022-01-07T22:23:02.311Z,1641594182.311 [DataOverHttps](INFO): Sending 216 bytes from file Logs/20220107T182328/Express0124.lzma 2022-01-07T22:23:03.313Z,1641594183.313 [DataOverHttps](INFO): Moved sent file to Logs/20220107T182328/Express0124.lzma.bak 2022-01-07T22:23:03.313Z,1641594183.313 [DataOverHttps](INFO): SBD MOMSN=16416767 2022-01-07T22:23:04.530Z,1641594184.530 [Default:CheckIn:Read_Iridium] Stopped 2022-01-07T22:23:04.530Z,1641594184.530 [Default:CheckIn:C.Wait] Running Loop=1 2022-01-07T22:23:04.530Z,1641594184.530 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-01-07T22:23:11.251Z,1641594191.251 [CommandExec](IMPORTANT): got command quit 2022-01-07T22:23:12.258Z,1641594192.258 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread. 2022-01-07T22:23:12.259Z,1641594192.259 [CommandExec](INFO): Uninitializing the command executive. 2022-01-07T22:23:12.259Z,1641594192.259 [CommandExec](INFO): Uninitializing the command scheduler. 2022-01-07T22:23:12.259Z,1641594192.259 [CommandExec ThreadHandler](INFO): Thread cancelled. 2022-01-07T22:23:12.370Z,1641594192.370 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2022-01-07T22:23:12.370Z,1641594192.370 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2022-01-07T22:23:12.371Z,1641594192.371 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2022-01-07T22:23:12.371Z,1641594192.371 [NavChartDb](INFO): Join timeout helper Thread ID is 5893 2022-01-07T22:23:12.675Z,1641594192.675 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2022-01-07T22:23:12.675Z,1641594192.675 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2022-01-07T22:23:12.690Z,1641594192.690 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2022-01-07T22:23:12.691Z,1641594192.691 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2022-01-07T22:23:12.691Z,1641594192.691 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 5894 2022-01-07T22:23:13.066Z,1641594193.066 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2022-01-07T22:23:13.067Z,1641594193.067 [WetLabsBB2FL](INFO): Powering down 2022-01-07T22:23:13.067Z,1641594193.067 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2022-01-07T22:23:13.086Z,1641594193.086 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2022-01-07T22:23:13.086Z,1641594193.086 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2022-01-07T22:23:13.087Z,1641594193.087 [CTD_Seabird](INFO): Join timeout helper Thread ID is 5895 2022-01-07T22:23:13.874Z,1641594193.874 [CTD_Seabird](INFO): Powering down 2022-01-07T22:23:13.886Z,1641594193.886 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread. 2022-01-07T22:23:13.887Z,1641594193.887 [CTD_Seabird](INFO): Powering down 2022-01-07T22:23:13.898Z,1641594193.898 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2022-01-07T22:23:13.907Z,1641594193.907 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2022-01-07T22:23:13.907Z,1641594193.907 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2022-01-07T22:23:13.907Z,1641594193.907 [Radio_Surface](INFO): Join timeout helper Thread ID is 5896 2022-01-07T22:23:14.194Z,1641594194.194 [Radio_Surface](INFO): Powering down 2022-01-07T22:23:14.195Z,1641594194.195 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2022-01-07T22:23:14.195Z,1641594194.195 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2022-01-07T22:23:14.196Z,1641594194.196 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler 2022-01-07T22:23:14.196Z,1641594194.196 [Onboard ThreadHandler](INFO): Thread cancelled. 2022-01-07T22:23:14.197Z,1641594194.197 [Onboard](INFO): Join timeout helper Thread ID is 5897 2022-01-07T22:23:16.227Z,1641594196.227 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread. 2022-01-07T22:23:16.227Z,1641594196.227 [Onboard ThreadHandler](INFO): Thread cancelled. 2022-01-07T22:23:16.247Z,1641594196.247 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2022-01-07T22:23:16.247Z,1641594196.247 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2022-01-07T22:23:16.248Z,1641594196.248 [DataOverHttps](INFO): Join timeout helper Thread ID is 5898 2022-01-07T22:23:16.554Z,1641594196.554 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2022-01-07T22:23:16.557Z,1641594196.557 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2022-01-07T22:23:16.567Z,1641594196.567 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2022-01-07T22:23:16.567Z,1641594196.567 [logger ThreadHandler](INFO): Thread cancelled. 2022-01-07T22:23:16.567Z,1641594196.567 [logger](INFO): Join timeout helper Thread ID is 5899 2022-01-07T22:23:16.574Z,1641594196.574 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2022-01-07T22:23:16.575Z,1641594196.575 [logger ThreadHandler](INFO): Thread cancelled. 2022-01-07T22:23:16.587Z,1641594196.587 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2022-01-07T22:23:16.587Z,1641594196.587 [CommandLine ThreadHandler](INFO): Thread cancelled. 2022-01-07T22:23:16.587Z,1641594196.587 [CommandLine](INFO): Join timeout helper Thread ID is 5900 2022-01-07T22:23:16.622Z,1641594196.622 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2022-01-07T22:23:16.623Z,1641594196.623 [CommandLine ThreadHandler](INFO): Thread cancelled. 2022-01-07T22:23:16.639Z,1641594196.639 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler 2022-01-07T22:23:16.639Z,1641594196.639 [CommandExec ThreadHandler](INFO): Thread cancelled. 2022-01-07T22:23:16.639Z,1641594196.639 [CommandExec](INFO): Join timeout helper Thread ID is 5901 2022-01-07T22:23:16.644Z,1641594196.644 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2022-01-07T22:23:16.644Z,1641594196.644 [controlThread ThreadHandler](INFO): Thread cancelled. 2022-01-07T22:23:16.645Z,1641594196.645 [controlThread](INFO): Join timeout helper Thread ID is 5902 2022-01-07T22:23:17.002Z,1641594197.002 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2022-01-07T22:23:17.003Z,1641594197.003 [controlThread](DEBUG): Uninitializing ControlThread 2022-01-07T22:23:17.003Z,1641594197.003 [AHRS_M2](INFO): Powering down 2022-01-07T22:23:17.075Z,1641594197.075 [NAL9602](INFO): Powering down 2022-01-07T22:23:17.078Z,1641594197.078 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2022-01-07T22:23:17.079Z,1641594197.079 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2022-01-07T22:23:17.079Z,1641594197.079 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2022-01-07T22:23:17.080Z,1641594197.080 [MissionManager](INFO): Uninitializing Mission Default 2022-01-07T22:23:17.080Z,1641594197.080 [Default] Stopped 2022-01-07T22:23:17.080Z,1641594197.080 [Default](DEBUG): Aggregate::uninitialize Default 2022-01-07T22:23:17.080Z,1641594197.080 [Default:B.GoToSurface] Stopped 2022-01-07T22:23:17.080Z,1641594197.080 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2022-01-07T22:23:17.080Z,1641594197.080 [Default:CheckIn] Stopped 2022-01-07T22:23:17.081Z,1641594197.081 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-01-07T22:23:17.081Z,1641594197.081 [Default:CheckIn:C.Wait] Stopped 2022-01-07T22:23:17.081Z,1641594197.081 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-01-07T22:23:17.084Z,1641594197.084 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2022-01-07T22:23:17.084Z,1641594197.084 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2022-01-07T22:23:17.085Z,1641594197.085 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2022-01-07T22:23:17.085Z,1641594197.085 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2022-01-07T22:23:17.085Z,1641594197.085 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2022-01-07T22:23:17.085Z,1641594197.085 [BuoyancyServo](INFO): Powering down 2022-01-07T22:23:17.098Z,1641594197.098 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2022-01-07T22:23:17.098Z,1641594197.098 [ElevatorServo](INFO): Powering down 2022-01-07T22:23:17.099Z,1641594197.099 [MassServo](DEBUG): Uninitialize Mass Servo. 2022-01-07T22:23:17.099Z,1641594197.099 [MassServo](INFO): Powering down 2022-01-07T22:23:17.100Z,1641594197.100 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2022-01-07T22:23:17.100Z,1641594197.100 [RudderServo](INFO): Powering down 2022-01-07T22:23:17.101Z,1641594197.101 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2022-01-07T22:23:17.101Z,1641594197.101 [ThrusterServo](INFO): Powering down 2022-01-07T22:23:17.103Z,1641594197.103 [SBIT](DEBUG): Uninitialize SBIT Component. 2022-01-07T22:23:17.103Z,1641594197.103 [IBIT](DEBUG): Uninitialize IBIT Component. 2022-01-07T22:23:17.103Z,1641594197.103 [CBIT](DEBUG): Uninitialize CBIT Component. 2022-01-07T22:23:17.103Z,1641594197.103 [CBIT](DEBUG): Powering off loads. 2022-01-07T22:23:17.114Z,1641594197.114 [CBIT](DEBUG): Disabling WDT. 2022-01-07T22:23:17.126Z,1641594197.126 [CBIT](DEBUG): Opening all GF detection circuits. 2022-01-07T22:23:17.127Z,1641594197.127 [controlThread ThreadHandler](INFO): Thread cancelled. 2022-01-07T22:23:17.180Z,1641594197.180 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2022-01-07T22:23:17.184Z,1641594197.184 [Onboard ThreadHandler](INFO): Thread cancelled. 2022-01-07T22:23:17.190Z,1641594197.190 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2022-01-07T22:23:17.263Z,1641594197.263 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2022-01-07T22:23:17.267Z,1641594197.267 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2022-01-07T22:23:17.311Z,1641594197.311 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2022-01-07T22:23:17.408Z,1641594197.408 [logger ThreadHandler](INFO): Thread cancelled.