2022-07-22T21:29:00.040Z,1658525340.040 [CommandExec](IMPORTANT): got command restart logs 2022-07-22T21:29:05.910Z,1658525345.910 [NAL9602](INFO): Not Powering down - fast GPS 2022-07-22T21:33:35.792Z,1658525615.792 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-07-22T21:33:35.792Z,1658525615.792 [Default:CheckIn:C.Wait] Stopped 2022-07-22T21:33:35.792Z,1658525615.792 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-07-22T21:33:35.793Z,1658525615.793 [Default:CheckIn:D] Running Loop=1 2022-07-22T21:33:36.227Z,1658525616.227 [Default:CheckIn:D] Stopped 2022-07-22T21:33:36.227Z,1658525616.227 [Default:CheckIn:E] Running Loop=1 2022-07-22T21:33:36.605Z,1658525616.605 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 28.863271 min 2022-07-22T21:33:36.605Z,1658525616.605 [Default:CheckIn:E] Stopped 2022-07-22T21:33:36.605Z,1658525616.605 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-07-22T21:33:36.605Z,1658525616.605 [Default:CheckIn] Stopped 2022-07-22T21:33:36.605Z,1658525616.605 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-07-22T21:33:36.605Z,1658525616.605 [Default:CheckIn](INFO): Running loop #6 2022-07-22T21:33:36.605Z,1658525616.605 [Default:CheckIn] Running Loop=6 2022-07-22T21:33:36.606Z,1658525616.606 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-07-22T21:33:36.606Z,1658525616.606 [Default:CheckIn:Read_GPS] Running Loop=1 2022-07-22T21:33:38.612Z,1658525618.612 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,213338.00,A,3648.04625,N,12148.09987,W,20.080,73.58,220722,,,D*78 2022-07-22T21:33:38.614Z,1658525618.614 [NAL9602](INFO): GPS fix at 20220722T213338: (36.800771, -121.801665) 2022-07-22T21:33:38.669Z,1658525618.669 [Default:CheckIn:Read_GPS] Stopped 2022-07-22T21:33:38.669Z,1658525618.669 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-07-22T21:33:44.812Z,1658525624.812 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20220721T181230/Courier0250.lzma 2022-07-22T21:33:45.815Z,1658525625.815 [DataOverHttps](INFO): Moved sent file to Logs/20220721T181230/Courier0250.lzma.bak 2022-07-22T21:33:45.815Z,1658525625.815 [DataOverHttps](INFO): SBD MOMSN=17075125 2022-07-22T21:33:57.295Z,1658525637.295 [NAL9602](INFO): SBD MO Status=0, MOMSN=20446, MT Status=0, MTMSN=0 2022-07-22T21:33:57.295Z,1658525637.295 [NAL9602](INFO): No messages in MT queue 2022-07-22T21:34:02.153Z,1658525642.153 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20220722T212847/Courier0000.lzma 2022-07-22T21:34:03.155Z,1658525643.155 [DataOverHttps](INFO): Moved sent file to Logs/20220722T212847/Courier0000.lzma.bak 2022-07-22T21:34:03.155Z,1658525643.155 [DataOverHttps](INFO): SBD MOMSN=17075127 2022-07-22T21:34:19.649Z,1658525659.649 [DataOverHttps](INFO): Sending 267 bytes from file Logs/20220722T212900/Courier0000.lzma 2022-07-22T21:34:20.651Z,1658525660.651 [DataOverHttps](INFO): Moved sent file to Logs/20220722T212900/Courier0000.lzma.bak 2022-07-22T21:34:20.651Z,1658525660.651 [DataOverHttps](INFO): SBD MOMSN=17075131 2022-07-22T21:34:27.995Z,1658525667.995 [NAL9602](INFO): Not Powering down - fast GPS 2022-07-22T21:34:36.876Z,1658525676.876 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20220722T212900/Courier0003.lzma 2022-07-22T21:34:37.879Z,1658525677.879 [DataOverHttps](INFO): Moved sent file to Logs/20220722T212900/Courier0003.lzma.bak 2022-07-22T21:34:37.879Z,1658525677.879 [DataOverHttps](INFO): SBD MOMSN=17075135 2022-07-22T21:34:54.260Z,1658525694.260 [DataOverHttps](INFO): Sending 95 bytes from file Logs/20220721T181230/Express0251.lzma 2022-07-22T21:34:55.263Z,1658525695.263 [DataOverHttps](INFO): Moved sent file to Logs/20220721T181230/Express0251.lzma.bak 2022-07-22T21:34:55.263Z,1658525695.263 [DataOverHttps](INFO): SBD MOMSN=17075137 2022-07-22T21:35:11.534Z,1658525711.534 [DataOverHttps](INFO): Sending 357 bytes from file Logs/20220722T212847/Express0001.lzma 2022-07-22T21:35:12.535Z,1658525712.535 [DataOverHttps](INFO): Moved sent file to Logs/20220722T212847/Express0001.lzma.bak 2022-07-22T21:35:12.535Z,1658525712.535 [DataOverHttps](INFO): SBD MOMSN=17075141 2022-07-22T21:35:28.721Z,1658525728.721 [DataOverHttps](INFO): Sending 392 bytes from file Logs/20220722T212900/Express0001.lzma 2022-07-22T21:35:29.723Z,1658525729.723 [DataOverHttps](INFO): Moved sent file to Logs/20220722T212900/Express0001.lzma.bak 2022-07-22T21:35:29.723Z,1658525729.723 [DataOverHttps](INFO): SBD MOMSN=17075145 2022-07-22T21:35:46.092Z,1658525746.092 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20220722T212900/Express0004.lzma 2022-07-22T21:35:47.095Z,1658525747.095 [DataOverHttps](INFO): Moved sent file to Logs/20220722T212900/Express0004.lzma.bak 2022-07-22T21:35:47.095Z,1658525747.095 [DataOverHttps](INFO): SBD MOMSN=17075149 2022-07-22T21:35:48.423Z,1658525748.423 [Default:CheckIn:Read_Iridium] Stopped 2022-07-22T21:35:48.424Z,1658525748.424 [Default:CheckIn:C.Wait] Running Loop=1 2022-07-22T21:35:48.424Z,1658525748.424 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-07-22T21:40:48.978Z,1658526048.978 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-07-22T21:40:48.978Z,1658526048.978 [Default:CheckIn:C.Wait] Stopped 2022-07-22T21:40:48.978Z,1658526048.978 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-07-22T21:40:48.979Z,1658526048.979 [Default:CheckIn:D] Running Loop=1 2022-07-22T21:40:49.392Z,1658526049.392 [Default:CheckIn:D] Stopped 2022-07-22T21:40:49.392Z,1658526049.392 [Default:CheckIn:E] Running Loop=1 2022-07-22T21:40:49.801Z,1658526049.801 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 36.082694 min 2022-07-22T21:40:49.801Z,1658526049.801 [Default:CheckIn:E] Stopped 2022-07-22T21:40:49.801Z,1658526049.801 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-07-22T21:40:49.801Z,1658526049.801 [Default:CheckIn] Stopped 2022-07-22T21:40:49.801Z,1658526049.801 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-07-22T21:40:49.801Z,1658526049.801 [Default:CheckIn](INFO): Running loop #7 2022-07-22T21:40:49.801Z,1658526049.801 [Default:CheckIn] Running Loop=7 2022-07-22T21:40:49.802Z,1658526049.802 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-07-22T21:40:49.802Z,1658526049.802 [Default:CheckIn:Read_GPS] Running Loop=1 2022-07-22T21:40:51.804Z,1658526051.804 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,214051.00,A,3648.29906,N,12147.12560,W,3.596,191.82,220722,,,D*7B 2022-07-22T21:40:51.806Z,1658526051.806 [NAL9602](INFO): GPS fix at 20220722T214051: (36.804984, -121.785427) 2022-07-22T21:40:51.817Z,1658526051.817 [Default:CheckIn:Read_GPS] Stopped 2022-07-22T21:40:51.817Z,1658526051.817 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-07-22T21:40:59.860Z,1658526059.860 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220722T212900/Courier0006.lzma 2022-07-22T21:41:00.863Z,1658526060.863 [DataOverHttps](INFO): Moved sent file to Logs/20220722T212900/Courier0006.lzma.bak 2022-07-22T21:41:00.863Z,1658526060.863 [DataOverHttps](INFO): SBD MOMSN=17075158 2022-07-22T21:41:17.216Z,1658526077.216 [DataOverHttps](INFO): Sending 138 bytes from file Logs/20220722T212900/Express0007.lzma 2022-07-22T21:41:18.219Z,1658526078.219 [DataOverHttps](INFO): Moved sent file to Logs/20220722T212900/Express0007.lzma.bak 2022-07-22T21:41:18.219Z,1658526078.219 [DataOverHttps](INFO): SBD MOMSN=17075161 2022-07-22T21:41:19.698Z,1658526079.698 [Default:CheckIn:Read_Iridium] Stopped 2022-07-22T21:41:19.698Z,1658526079.698 [Default:CheckIn:C.Wait] Running Loop=1 2022-07-22T21:41:19.698Z,1658526079.698 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-07-22T21:41:28.968Z,1658526088.968 [NAL9602](INFO): SBD MO Status=2, MOMSN=20447, MT Status=2, MTMSN=0 2022-07-22T21:41:28.968Z,1658526088.968 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-07-22T21:41:36.238Z,1658526096.238 [NAL9602](INFO): SBD MO Status=0, MOMSN=20447, MT Status=0, MTMSN=0 2022-07-22T21:41:36.239Z,1658526096.239 [NAL9602](INFO): No messages in MT queue 2022-07-22T21:42:06.950Z,1658526126.950 [NAL9602](INFO): Not Powering down - fast GPS 2022-07-22T21:46:20.304Z,1658526380.304 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-07-22T21:46:20.304Z,1658526380.304 [Default:CheckIn:C.Wait] Stopped 2022-07-22T21:46:20.304Z,1658526380.304 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-07-22T21:46:20.304Z,1658526380.304 [Default:CheckIn:D] Running Loop=1 2022-07-22T21:46:20.674Z,1658526380.674 [Default:CheckIn:D] Stopped 2022-07-22T21:46:20.674Z,1658526380.674 [Default:CheckIn:E] Running Loop=1 2022-07-22T21:46:21.084Z,1658526381.084 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 41.604057 min 2022-07-22T21:46:21.084Z,1658526381.084 [Default:CheckIn:E] Stopped 2022-07-22T21:46:21.085Z,1658526381.085 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-07-22T21:46:21.085Z,1658526381.085 [Default:CheckIn] Stopped 2022-07-22T21:46:21.085Z,1658526381.085 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-07-22T21:46:21.085Z,1658526381.085 [Default:CheckIn](INFO): Running loop #8 2022-07-22T21:46:21.085Z,1658526381.085 [Default:CheckIn] Running Loop=8 2022-07-22T21:46:21.085Z,1658526381.085 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-07-22T21:46:21.085Z,1658526381.085 [Default:CheckIn:Read_GPS] Running Loop=1 2022-07-22T21:46:23.085Z,1658526383.085 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,214622.00,A,3648.16442,N,12147.21333,W,0.039,245.36,220722,,,A*7B 2022-07-22T21:46:23.087Z,1658526383.087 [NAL9602](INFO): GPS fix at 20220722T214622: (36.802740, -121.786889) 2022-07-22T21:46:23.098Z,1658526383.098 [Default:CheckIn:Read_GPS] Stopped 2022-07-22T21:46:23.098Z,1658526383.098 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-07-22T21:46:30.887Z,1658526390.887 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220722T212900/Courier0009.lzma 2022-07-22T21:46:31.889Z,1658526391.889 [DataOverHttps](INFO): Moved sent file to Logs/20220722T212900/Courier0009.lzma.bak 2022-07-22T21:46:31.889Z,1658526391.889 [DataOverHttps](INFO): SBD MOMSN=17075196 2022-07-22T21:46:48.149Z,1658526408.149 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20220722T212900/Express0010.lzma 2022-07-22T21:46:49.145Z,1658526409.145 [DataOverHttps](INFO): Moved sent file to Logs/20220722T212900/Express0010.lzma.bak 2022-07-22T21:46:49.145Z,1658526409.145 [DataOverHttps](INFO): SBD MOMSN=17075199 2022-07-22T21:46:50.575Z,1658526410.575 [Default:CheckIn:Read_Iridium] Stopped 2022-07-22T21:46:50.575Z,1658526410.575 [Default:CheckIn:C.Wait] Running Loop=1 2022-07-22T21:46:50.575Z,1658526410.575 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-07-22T21:47:44.322Z,1658526464.322 [NAL9602](INFO): SBD MO Status=2, MOMSN=20448, MT Status=2, MTMSN=0 2022-07-22T21:47:44.322Z,1658526464.322 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-07-22T21:48:14.222Z,1658526494.222 [NAL9602](INFO): SBD MO Status=0, MOMSN=20448, MT Status=0, MTMSN=0 2022-07-22T21:48:14.222Z,1658526494.222 [NAL9602](INFO): No messages in MT queue 2022-07-22T21:48:44.929Z,1658526524.929 [NAL9602](INFO): Not Powering down - fast GPS 2022-07-22T21:51:51.190Z,1658526711.190 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-07-22T21:51:51.190Z,1658526711.190 [Default:CheckIn:C.Wait] Stopped 2022-07-22T21:51:51.191Z,1658526711.191 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-07-22T21:51:51.191Z,1658526711.191 [Default:CheckIn:D] Running Loop=1 2022-07-22T21:51:51.584Z,1658526711.584 [Default:CheckIn:D] Stopped 2022-07-22T21:51:51.585Z,1658526711.585 [Default:CheckIn:E] Running Loop=1 2022-07-22T21:51:51.994Z,1658526711.994 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 47.119230 min 2022-07-22T21:51:51.994Z,1658526711.994 [Default:CheckIn:E] Stopped 2022-07-22T21:51:51.995Z,1658526711.995 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-07-22T21:51:51.995Z,1658526711.995 [Default:CheckIn] Stopped 2022-07-22T21:51:51.995Z,1658526711.995 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-07-22T21:51:51.995Z,1658526711.995 [Default:CheckIn](INFO): Running loop #9 2022-07-22T21:51:51.995Z,1658526711.995 [Default:CheckIn] Running Loop=9 2022-07-22T21:51:51.995Z,1658526711.995 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-07-22T21:51:51.995Z,1658526711.995 [Default:CheckIn:Read_GPS] Running Loop=1 2022-07-22T21:51:53.998Z,1658526713.998 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,215153.00,A,3648.16500,N,12147.21587,W,0.778,228.08,220722,,,A*71 2022-07-22T21:51:54.000Z,1658526714.000 [NAL9602](INFO): GPS fix at 20220722T215153: (36.802750, -121.786931) 2022-07-22T21:51:54.011Z,1658526714.011 [Default:CheckIn:Read_GPS] Stopped 2022-07-22T21:51:54.031Z,1658526714.031 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-07-22T21:52:02.183Z,1658526722.183 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220722T212900/Courier0012.lzma 2022-07-22T21:52:03.185Z,1658526723.185 [DataOverHttps](INFO): Moved sent file to Logs/20220722T212900/Courier0012.lzma.bak 2022-07-22T21:52:03.185Z,1658526723.185 [DataOverHttps](INFO): SBD MOMSN=17075210 2022-07-22T21:52:15.810Z,1658526735.810 [NAL9602](INFO): SBD MO Status=0, MOMSN=20449, MT Status=0, MTMSN=0 2022-07-22T21:52:15.810Z,1658526735.810 [NAL9602](INFO): No messages in MT queue 2022-07-22T21:52:16.236Z,1658526736.236 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude 2022-07-22T21:52:21.103Z,1658526741.103 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20220722T212900/Express0013.lzma 2022-07-22T21:52:22.109Z,1658526742.109 [DataOverHttps](INFO): Moved sent file to Logs/20220722T212900/Express0013.lzma.bak 2022-07-22T21:52:22.109Z,1658526742.109 [DataOverHttps](INFO): SBD MOMSN=17075214 2022-07-22T21:52:23.528Z,1658526743.528 [Default:CheckIn:Read_Iridium] Stopped 2022-07-22T21:52:23.528Z,1658526743.528 [Default:CheckIn:C.Wait] Running Loop=1 2022-07-22T21:52:23.528Z,1658526743.528 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-07-22T21:52:46.544Z,1658526766.544 [NAL9602](INFO): Not Powering down - fast GPS 2022-07-22T21:57:24.169Z,1658527044.169 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-07-22T21:57:24.169Z,1658527044.169 [Default:CheckIn:C.Wait] Stopped 2022-07-22T21:57:24.169Z,1658527044.169 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-07-22T21:57:24.170Z,1658527044.170 [Default:CheckIn:D] Running Loop=1 2022-07-22T21:57:24.532Z,1658527044.532 [Default:CheckIn:D] Stopped 2022-07-22T21:57:24.533Z,1658527044.533 [Default:CheckIn:E] Running Loop=1 2022-07-22T21:57:24.926Z,1658527044.926 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 52.668363 min 2022-07-22T21:57:24.926Z,1658527044.926 [Default:CheckIn:E] Stopped 2022-07-22T21:57:24.927Z,1658527044.927 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-07-22T21:57:24.927Z,1658527044.927 [Default:CheckIn] Stopped 2022-07-22T21:57:24.927Z,1658527044.927 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-07-22T21:57:24.927Z,1658527044.927 [Default:CheckIn](INFO): Running loop #10 2022-07-22T21:57:24.927Z,1658527044.927 [Default:CheckIn] Running Loop=10 2022-07-22T21:57:24.927Z,1658527044.927 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-07-22T21:57:24.928Z,1658527044.928 [Default:CheckIn:Read_GPS] Running Loop=1 2022-07-22T21:57:26.938Z,1658527046.938 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,215726.00,A,3648.16082,N,12147.22000,W,2.566,202.68,220722,,,A*72 2022-07-22T21:57:26.940Z,1658527046.940 [NAL9602](INFO): GPS fix at 20220722T215726: (36.802680, -121.787000) 2022-07-22T21:57:26.951Z,1658527046.951 [Default:CheckIn:Read_GPS] Stopped 2022-07-22T21:57:26.951Z,1658527046.951 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-07-22T21:57:34.331Z,1658527054.331 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220722T212900/Courier0015.lzma 2022-07-22T21:57:35.333Z,1658527055.333 [DataOverHttps](INFO): Moved sent file to Logs/20220722T212900/Courier0015.lzma.bak 2022-07-22T21:57:35.333Z,1658527055.333 [DataOverHttps](INFO): SBD MOMSN=17075225 2022-07-22T21:57:51.531Z,1658527071.531 [DataOverHttps](INFO): Sending 127 bytes from file Logs/20220722T212900/Express0016.lzma 2022-07-22T21:57:52.533Z,1658527072.533 [DataOverHttps](INFO): Moved sent file to Logs/20220722T212900/Express0016.lzma.bak 2022-07-22T21:57:52.533Z,1658527072.533 [DataOverHttps](INFO): SBD MOMSN=17075228 2022-07-22T21:57:54.032Z,1658527074.032 [Default:CheckIn:Read_Iridium] Stopped 2022-07-22T21:57:54.032Z,1658527074.032 [Default:CheckIn:C.Wait] Running Loop=1 2022-07-22T21:57:54.032Z,1658527074.032 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-07-22T21:57:55.618Z,1658527075.618 [NAL9602](INFO): SBD MO Status=0, MOMSN=20450, MT Status=0, MTMSN=0 2022-07-22T21:57:55.618Z,1658527075.618 [NAL9602](INFO): No messages in MT queue 2022-07-22T21:58:26.351Z,1658527106.351 [NAL9602](INFO): Not Powering down - fast GPS 2022-07-22T22:02:54.671Z,1658527374.671 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-07-22T22:02:54.672Z,1658527374.672 [Default:CheckIn:C.Wait] Stopped 2022-07-22T22:02:54.672Z,1658527374.672 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-07-22T22:02:54.672Z,1658527374.672 [Default:CheckIn:D] Running Loop=1 2022-07-22T22:02:55.092Z,1658527375.092 [Default:CheckIn:D] Stopped 2022-07-22T22:02:55.092Z,1658527375.092 [Default:CheckIn:E] Running Loop=1 2022-07-22T22:02:55.481Z,1658527375.481 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 58.177690 min 2022-07-22T22:02:55.481Z,1658527375.481 [Default:CheckIn:E] Stopped 2022-07-22T22:02:55.481Z,1658527375.481 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-07-22T22:02:55.481Z,1658527375.481 [Default:CheckIn] Stopped 2022-07-22T22:02:55.481Z,1658527375.481 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-07-22T22:02:55.481Z,1658527375.481 [Default:CheckIn](INFO): Running loop #11 2022-07-22T22:02:55.481Z,1658527375.481 [Default:CheckIn] Running Loop=11 2022-07-22T22:02:55.481Z,1658527375.481 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-07-22T22:02:55.481Z,1658527375.481 [Default:CheckIn:Read_GPS] Running Loop=1 2022-07-22T22:02:57.490Z,1658527377.490 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,220256.00,A,3648.14042,N,12147.22873,W,0.019,234.74,220722,,,D*76 2022-07-22T22:02:57.493Z,1658527377.493 [NAL9602](INFO): GPS fix at 20220722T220256: (36.802340, -121.787145) 2022-07-22T22:02:57.503Z,1658527377.503 [Default:CheckIn:Read_GPS] Stopped 2022-07-22T22:02:57.503Z,1658527377.503 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-07-22T22:03:05.515Z,1658527385.515 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220722T212900/Courier0018.lzma 2022-07-22T22:03:06.517Z,1658527386.517 [DataOverHttps](INFO): Moved sent file to Logs/20220722T212900/Courier0018.lzma.bak 2022-07-22T22:03:06.517Z,1658527386.517 [DataOverHttps](INFO): SBD MOMSN=17075238 2022-07-22T22:03:12.090Z,1658527392.090 [NAL9602](INFO): SBD MO Status=0, MOMSN=20451, MT Status=0, MTMSN=0 2022-07-22T22:03:12.090Z,1658527392.090 [NAL9602](INFO): No messages in MT queue 2022-07-22T22:03:22.831Z,1658527402.831 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20220722T212900/Express0019.lzma 2022-07-22T22:03:23.833Z,1658527403.833 [DataOverHttps](INFO): Moved sent file to Logs/20220722T212900/Express0019.lzma.bak 2022-07-22T22:03:23.833Z,1658527403.833 [DataOverHttps](INFO): SBD MOMSN=17075241 2022-07-22T22:03:24.972Z,1658527404.972 [Default:CheckIn:Read_Iridium] Stopped 2022-07-22T22:03:24.972Z,1658527404.972 [Default:CheckIn:C.Wait] Running Loop=1 2022-07-22T22:03:24.972Z,1658527404.972 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-07-22T22:03:42.740Z,1658527422.740 [NAL9602](INFO): Not Powering down - fast GPS 2022-07-22T22:08:25.405Z,1658527705.405 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-07-22T22:08:25.406Z,1658527705.406 [Default:CheckIn:C.Wait] Stopped 2022-07-22T22:08:25.406Z,1658527705.406 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-07-22T22:08:25.407Z,1658527705.407 [Default:CheckIn:D] Running Loop=1 2022-07-22T22:08:25.784Z,1658527705.784 [Default:CheckIn:D] Stopped 2022-07-22T22:08:25.784Z,1658527705.784 [Default:CheckIn:E] Running Loop=1 2022-07-22T22:08:26.239Z,1658527706.239 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 63.689221 min 2022-07-22T22:08:26.239Z,1658527706.239 [Default:CheckIn:E] Stopped 2022-07-22T22:08:26.239Z,1658527706.239 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-07-22T22:08:26.239Z,1658527706.239 [Default:CheckIn] Stopped 2022-07-22T22:08:26.239Z,1658527706.239 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-07-22T22:08:26.239Z,1658527706.239 [Default:CheckIn](INFO): Running loop #12 2022-07-22T22:08:26.239Z,1658527706.239 [Default:CheckIn] Running Loop=12 2022-07-22T22:08:26.239Z,1658527706.239 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-07-22T22:08:26.240Z,1658527706.240 [Default:CheckIn:Read_GPS] Running Loop=1 2022-07-22T22:08:28.229Z,1658527708.229 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,220827.00,A,3648.16873,N,12147.26396,W,2.177,297.34,220722,,,D*70 2022-07-22T22:08:28.236Z,1658527708.236 [NAL9602](INFO): GPS fix at 20220722T220827: (36.802812, -121.787733) 2022-07-22T22:08:28.282Z,1658527708.282 [Default:CheckIn:Read_GPS] Stopped 2022-07-22T22:08:28.282Z,1658527708.282 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-07-22T22:08:35.761Z,1658527715.761 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20220722T212900/Courier0021.lzma 2022-07-22T22:08:36.764Z,1658527716.764 [DataOverHttps](INFO): Moved sent file to Logs/20220722T212900/Courier0021.lzma.bak 2022-07-22T22:08:36.764Z,1658527716.764 [DataOverHttps](INFO): SBD MOMSN=17075254 2022-07-22T22:08:47.993Z,1658527727.993 [NAL9602](INFO): SBD MO Status=2, MOMSN=20452, MT Status=2, MTMSN=0 2022-07-22T22:08:47.993Z,1658527727.993 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-07-22T22:08:53.101Z,1658527733.101 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20220722T212900/Express0022.lzma 2022-07-22T22:08:54.104Z,1658527734.104 [DataOverHttps](INFO): Moved sent file to Logs/20220722T212900/Express0022.lzma.bak 2022-07-22T22:08:54.104Z,1658527734.104 [DataOverHttps](INFO): SBD MOMSN=17075257 2022-07-22T22:08:55.315Z,1658527735.315 [Default:CheckIn:Read_Iridium] Stopped 2022-07-22T22:08:55.315Z,1658527735.315 [Default:CheckIn:C.Wait] Running Loop=1 2022-07-22T22:08:55.315Z,1658527735.315 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-07-22T22:09:13.877Z,1658527753.877 [NAL9602](INFO): SBD MO Status=2, MOMSN=20452, MT Status=2, MTMSN=0 2022-07-22T22:09:13.877Z,1658527753.877 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-07-22T22:09:41.753Z,1658527781.753 [NAL9602](INFO): SBD MO Status=2, MOMSN=20452, MT Status=2, MTMSN=0 2022-07-22T22:09:41.753Z,1658527781.753 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-07-22T22:13:12.233Z,1658527992.233 [NAL9602](INFO): SBD MO Status=2, MOMSN=20452, MT Status=2, MTMSN=0 2022-07-22T22:13:12.233Z,1658527992.233 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-07-22T22:13:31.623Z,1658528011.623 [NAL9602](INFO): SBD MO Status=0, MOMSN=20452, MT Status=0, MTMSN=0 2022-07-22T22:13:31.623Z,1658528011.623 [NAL9602](INFO): No messages in MT queue 2022-07-22T22:13:55.882Z,1658528035.882 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-07-22T22:13:55.882Z,1658528035.882 [Default:CheckIn:C.Wait] Stopped 2022-07-22T22:13:55.882Z,1658528035.882 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-07-22T22:13:55.882Z,1658528035.882 [Default:CheckIn:D] Running Loop=1 2022-07-22T22:13:56.309Z,1658528036.309 [Default:CheckIn:D] Stopped 2022-07-22T22:13:56.309Z,1658528036.309 [Default:CheckIn:E] Running Loop=1 2022-07-22T22:13:56.685Z,1658528036.685 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 69.197982 min 2022-07-22T22:13:56.685Z,1658528036.685 [Default:CheckIn:E] Stopped 2022-07-22T22:13:56.685Z,1658528036.685 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-07-22T22:13:56.685Z,1658528036.685 [Default:CheckIn] Stopped 2022-07-22T22:13:56.686Z,1658528036.686 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-07-22T22:13:56.686Z,1658528036.686 [Default:CheckIn](INFO): Running loop #13 2022-07-22T22:13:56.686Z,1658528036.686 [Default:CheckIn] Running Loop=13 2022-07-22T22:13:56.686Z,1658528036.686 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-07-22T22:13:56.686Z,1658528036.686 [Default:CheckIn:Read_GPS] Running Loop=1 2022-07-22T22:13:58.693Z,1658528038.693 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,221358.00,A,3648.17962,N,12147.28073,W,0.078,338.96,220722,,,D*74 2022-07-22T22:13:58.696Z,1658528038.696 [NAL9602](INFO): GPS fix at 20220722T221358: (36.802994, -121.788012) 2022-07-22T22:13:58.706Z,1658528038.706 [Default:CheckIn:Read_GPS] Stopped 2022-07-22T22:13:58.706Z,1658528038.706 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-07-22T22:14:06.489Z,1658528046.489 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220722T212900/Courier0024.lzma 2022-07-22T22:14:07.492Z,1658528047.492 [DataOverHttps](INFO): Moved sent file to Logs/20220722T212900/Courier0024.lzma.bak 2022-07-22T22:14:07.492Z,1658528047.492 [DataOverHttps](INFO): SBD MOMSN=17075267 2022-07-22T22:14:23.797Z,1658528063.797 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20220722T212900/Express0025.lzma 2022-07-22T22:14:24.800Z,1658528064.800 [DataOverHttps](INFO): Moved sent file to Logs/20220722T212900/Express0025.lzma.bak 2022-07-22T22:14:24.800Z,1658528064.800 [DataOverHttps](INFO): SBD MOMSN=17075270 2022-07-22T22:14:26.243Z,1658528066.243 [Default:CheckIn:Read_Iridium] Stopped 2022-07-22T22:14:26.243Z,1658528066.243 [Default:CheckIn:C.Wait] Running Loop=1 2022-07-22T22:14:26.243Z,1658528066.243 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-07-22T22:14:31.415Z,1658528071.415 [NAL9602](INFO): Not Powering down - fast GPS 2022-07-22T22:16:03.152Z,1658528163.152 [CBIT](IMPORTANT): Beginning ground fault scan 2022-07-22T22:16:14.076Z,1658528174.076 [CBIT](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): 0.025662 CHAN A1 (24V): 0.055286 CHAN A2 (12V): 0.018755 CHAN A3 (5V): 0.007599 CHAN B0 (3.3V): 0.006050 CHAN B1 (3.15aV): 0.005315 CHAN B2 (3.15bV): 0.005849 CHAN B3 (GND): 0.000542 OPEN: 0.007563 Full Scale: +/- 1 mA 2022-07-22T22:19:26.769Z,1658528366.769 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-07-22T22:19:26.769Z,1658528366.769 [Default:CheckIn:C.Wait] Stopped 2022-07-22T22:19:26.769Z,1658528366.769 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-07-22T22:19:26.769Z,1658528366.769 [Default:CheckIn:D] Running Loop=1 2022-07-22T22:19:27.174Z,1658528367.174 [Default:CheckIn:D] Stopped 2022-07-22T22:19:27.174Z,1658528367.174 [Default:CheckIn:E] Running Loop=1 2022-07-22T22:19:27.589Z,1658528367.589 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 74.712394 min 2022-07-22T22:19:27.589Z,1658528367.589 [Default:CheckIn:E] Stopped 2022-07-22T22:19:27.589Z,1658528367.589 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-07-22T22:19:27.589Z,1658528367.589 [Default:CheckIn] Stopped 2022-07-22T22:19:27.590Z,1658528367.590 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-07-22T22:19:27.590Z,1658528367.590 [Default:CheckIn](INFO): Running loop #14 2022-07-22T22:19:27.590Z,1658528367.590 [Default:CheckIn] Running Loop=14 2022-07-22T22:19:27.590Z,1658528367.590 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-07-22T22:19:27.590Z,1658528367.590 [Default:CheckIn:Read_GPS] Running Loop=1 2022-07-22T22:19:29.587Z,1658528369.587 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,221928.00,A,3648.17075,N,12147.28037,W,0.525,338.96,220722,,,A*7E 2022-07-22T22:19:29.589Z,1658528369.589 [NAL9602](INFO): GPS fix at 20220722T221928: (36.802846, -121.788006) 2022-07-22T22:19:29.601Z,1658528369.601 [Default:CheckIn:Read_GPS] Stopped 2022-07-22T22:19:29.601Z,1658528369.601 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-07-22T22:19:37.281Z,1658528377.281 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220722T212900/Courier0027.lzma 2022-07-22T22:19:38.284Z,1658528378.284 [DataOverHttps](INFO): Moved sent file to Logs/20220722T212900/Courier0027.lzma.bak 2022-07-22T22:19:38.284Z,1658528378.284 [DataOverHttps](INFO): SBD MOMSN=17075280 2022-07-22T22:19:54.810Z,1658528394.810 [DataOverHttps](INFO): Sending 326 bytes from file Logs/20220722T212900/Express0028.lzma 2022-07-22T22:19:55.812Z,1658528395.812 [DataOverHttps](INFO): Moved sent file to Logs/20220722T212900/Express0028.lzma.bak 2022-07-22T22:19:55.812Z,1658528395.812 [DataOverHttps](INFO): SBD MOMSN=17075283 2022-07-22T22:19:57.078Z,1658528397.078 [Default:CheckIn:Read_Iridium] Stopped 2022-07-22T22:19:57.079Z,1658528397.079 [Default:CheckIn:C.Wait] Running Loop=1 2022-07-22T22:19:57.079Z,1658528397.079 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-07-22T22:24:32.211Z,1658528672.211 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-07-22T22:24:57.679Z,1658528697.679 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-07-22T22:24:57.679Z,1658528697.679 [Default:CheckIn:C.Wait] Stopped 2022-07-22T22:24:57.679Z,1658528697.679 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-07-22T22:24:57.680Z,1658528697.680 [Default:CheckIn:D] Running Loop=1 2022-07-22T22:24:58.152Z,1658528698.152 [Default:CheckIn:D] Stopped 2022-07-22T22:24:58.152Z,1658528698.152 [Default:CheckIn:E] Running Loop=1 2022-07-22T22:24:58.482Z,1658528698.482 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 80.228687 min 2022-07-22T22:24:58.482Z,1658528698.482 [Default:CheckIn:E] Stopped 2022-07-22T22:24:58.482Z,1658528698.482 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-07-22T22:24:58.482Z,1658528698.482 [Default:CheckIn] Stopped 2022-07-22T22:24:58.482Z,1658528698.482 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-07-22T22:24:58.482Z,1658528698.482 [Default:CheckIn](INFO): Running loop #15 2022-07-22T22:24:58.482Z,1658528698.482 [Default:CheckIn] Running Loop=15 2022-07-22T22:24:58.483Z,1658528698.483 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-07-22T22:24:58.483Z,1658528698.483 [Default:CheckIn:Read_GPS] Running Loop=1 2022-07-22T22:25:00.495Z,1658528700.495 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,222459.00,A,3648.16644,N,12147.28663,W,0.350,69.76,220722,,,A*49 2022-07-22T22:25:00.497Z,1658528700.497 [NAL9602](INFO): GPS fix at 20220722T222459: (36.802774, -121.788111) 2022-07-22T22:25:00.515Z,1658528700.515 [Default:CheckIn:Read_GPS] Stopped 2022-07-22T22:25:00.515Z,1658528700.515 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-07-22T22:25:08.641Z,1658528708.641 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220722T212900/Courier0030.lzma 2022-07-22T22:25:09.644Z,1658528709.644 [DataOverHttps](INFO): Moved sent file to Logs/20220722T212900/Courier0030.lzma.bak 2022-07-22T22:25:09.644Z,1658528709.644 [DataOverHttps](INFO): SBD MOMSN=17075295 2022-07-22T22:25:25.926Z,1658528725.926 [DataOverHttps](INFO): Sending 229 bytes from file Logs/20220722T212900/Express0031.lzma 2022-07-22T22:25:26.928Z,1658528726.928 [DataOverHttps](INFO): Moved sent file to Logs/20220722T212900/Express0031.lzma.bak 2022-07-22T22:25:26.928Z,1658528726.928 [DataOverHttps](INFO): SBD MOMSN=17075298 2022-07-22T22:25:28.404Z,1658528728.404 [Default:CheckIn:Read_Iridium] Stopped 2022-07-22T22:25:28.404Z,1658528728.404 [Default:CheckIn:C.Wait] Running Loop=1 2022-07-22T22:25:28.404Z,1658528728.404 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-07-22T22:25:33.215Z,1658528733.215 [NAL9602](INFO): Not Powering down - fast GPS 2022-07-22T22:27:37.249Z,1658528857.249 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2022-07-22T22:27:37.251Z,1658528857.251 [BPC1](INFO): Received data from all battery sticks. 2022-07-22T22:30:28.965Z,1658529028.965 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-07-22T22:30:28.965Z,1658529028.965 [Default:CheckIn:C.Wait] Stopped 2022-07-22T22:30:28.965Z,1658529028.965 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-07-22T22:30:28.965Z,1658529028.965 [Default:CheckIn:D] Running Loop=1 2022-07-22T22:30:29.372Z,1658529029.372 [Default:CheckIn:D] Stopped 2022-07-22T22:30:29.372Z,1658529029.372 [Default:CheckIn:E] Running Loop=1 2022-07-22T22:30:29.765Z,1658529029.765 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 85.749032 min 2022-07-22T22:30:29.765Z,1658529029.765 [Default:CheckIn:E] Stopped 2022-07-22T22:30:29.765Z,1658529029.765 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-07-22T22:30:29.765Z,1658529029.765 [Default:CheckIn] Stopped 2022-07-22T22:30:29.766Z,1658529029.766 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-07-22T22:30:29.766Z,1658529029.766 [Default:CheckIn](INFO): Running loop #16 2022-07-22T22:30:29.766Z,1658529029.766 [Default:CheckIn] Running Loop=16 2022-07-22T22:30:29.766Z,1658529029.766 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-07-22T22:30:29.766Z,1658529029.766 [Default:CheckIn:Read_GPS] Running Loop=1 2022-07-22T22:30:31.781Z,1658529031.781 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,223031.00,A,3648.16918,N,12147.28006,W,0.369,69.76,220722,,,A*4B 2022-07-22T22:30:31.783Z,1658529031.783 [NAL9602](INFO): GPS fix at 20220722T223031: (36.802820, -121.788001) 2022-07-22T22:30:31.794Z,1658529031.794 [Default:CheckIn:Read_GPS] Stopped 2022-07-22T22:30:31.794Z,1658529031.794 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-07-22T22:30:39.182Z,1658529039.182 [DataOverHttps](INFO): Sending 202 bytes from file Logs/20220722T212900/Courier0033.lzma 2022-07-22T22:30:40.184Z,1658529040.184 [DataOverHttps](INFO): Moved sent file to Logs/20220722T212900/Courier0033.lzma.bak 2022-07-22T22:30:40.184Z,1658529040.184 [DataOverHttps](INFO): SBD MOMSN=17075308 2022-07-22T22:30:56.477Z,1658529056.477 [DataOverHttps](INFO): Sending 127 bytes from file Logs/20220722T212900/Express0034.lzma 2022-07-22T22:30:57.480Z,1658529057.480 [DataOverHttps](INFO): Moved sent file to Logs/20220722T212900/Express0034.lzma.bak 2022-07-22T22:30:57.480Z,1658529057.480 [DataOverHttps](INFO): SBD MOMSN=17075311 2022-07-22T22:30:58.937Z,1658529058.937 [Default:CheckIn:Read_Iridium] Stopped 2022-07-22T22:30:58.937Z,1658529058.937 [Default:CheckIn:C.Wait] Running Loop=1 2022-07-22T22:30:58.937Z,1658529058.937 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-07-22T22:31:02.555Z,1658529062.555 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-07-22T22:31:02.638Z,1658529062.638 [NAL9602](ERROR): received: +CSQ:0 OK452, 0, 0, 0, 0 OK 2022-07-22T22:35:34.243Z,1658529334.243 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-07-22T22:35:59.702Z,1658529359.702 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-07-22T22:35:59.702Z,1658529359.702 [Default:CheckIn:C.Wait] Stopped 2022-07-22T22:35:59.702Z,1658529359.702 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-07-22T22:35:59.702Z,1658529359.702 [Default:CheckIn:D] Running Loop=1 2022-07-22T22:36:00.115Z,1658529360.115 [Default:CheckIn:D] Stopped 2022-07-22T22:36:00.115Z,1658529360.115 [Default:CheckIn:E] Running Loop=1 2022-07-22T22:36:00.539Z,1658529360.539 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 91.261410 min 2022-07-22T22:36:00.540Z,1658529360.540 [Default:CheckIn:E] Stopped 2022-07-22T22:36:00.540Z,1658529360.540 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-07-22T22:36:00.540Z,1658529360.540 [Default:CheckIn] Stopped 2022-07-22T22:36:00.540Z,1658529360.540 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-07-22T22:36:00.544Z,1658529360.544 [Default:CheckIn](INFO): Running loop #17 2022-07-22T22:36:00.544Z,1658529360.544 [Default:CheckIn] Running Loop=17 2022-07-22T22:36:00.545Z,1658529360.545 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-07-22T22:36:00.545Z,1658529360.545 [Default:CheckIn:Read_GPS] Running Loop=1 2022-07-22T22:36:02.551Z,1658529362.551 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,223601.00,A,3648.16747,N,12147.28381,W,0.117,278.90,220722,,,A*77 2022-07-22T22:36:02.564Z,1658529362.564 [NAL9602](INFO): GPS fix at 20220722T223601: (36.802791, -121.788064) 2022-07-22T22:36:02.595Z,1658529362.595 [Default:CheckIn:Read_GPS] Stopped 2022-07-22T22:36:02.595Z,1658529362.595 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-07-22T22:36:11.672Z,1658529371.672 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220722T212900/Courier0036.lzma 2022-07-22T22:36:12.674Z,1658529372.674 [DataOverHttps](INFO): Moved sent file to Logs/20220722T212900/Courier0036.lzma.bak 2022-07-22T22:36:12.674Z,1658529372.674 [DataOverHttps](INFO): SBD MOMSN=17075321 2022-07-22T22:36:28.900Z,1658529388.900 [DataOverHttps](INFO): Sending 204 bytes from file Logs/20220722T212900/Express0037.lzma 2022-07-22T22:36:29.902Z,1658529389.902 [DataOverHttps](INFO): Moved sent file to Logs/20220722T212900/Express0037.lzma.bak 2022-07-22T22:36:29.902Z,1658529389.902 [DataOverHttps](INFO): SBD MOMSN=17075324 2022-07-22T22:36:31.221Z,1658529391.221 [Default:CheckIn:Read_Iridium] Stopped 2022-07-22T22:36:31.221Z,1658529391.221 [Default:CheckIn:C.Wait] Running Loop=1 2022-07-22T22:36:31.221Z,1658529391.221 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-07-22T22:36:34.425Z,1658529394.425 [NAL9602](INFO): Not Powering down - fast GPS 2022-07-22T22:41:31.811Z,1658529691.811 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-07-22T22:41:31.811Z,1658529691.811 [Default:CheckIn:C.Wait] Stopped 2022-07-22T22:41:31.811Z,1658529691.811 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-07-22T22:41:31.812Z,1658529691.812 [Default:CheckIn:D] Running Loop=1 2022-07-22T22:41:32.232Z,1658529692.232 [Default:CheckIn:D] Stopped 2022-07-22T22:41:32.232Z,1658529692.232 [Default:CheckIn:E] Running Loop=1 2022-07-22T22:41:32.633Z,1658529692.633 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 96.796696 min 2022-07-22T22:41:32.633Z,1658529692.633 [Default:CheckIn:E] Stopped 2022-07-22T22:41:32.634Z,1658529692.634 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-07-22T22:41:32.634Z,1658529692.634 [Default:CheckIn] Stopped 2022-07-22T22:41:32.634Z,1658529692.634 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-07-22T22:41:32.634Z,1658529692.634 [Default:CheckIn](INFO): Running loop #18 2022-07-22T22:41:32.634Z,1658529692.634 [Default:CheckIn] Running Loop=18 2022-07-22T22:41:32.634Z,1658529692.634 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-07-22T22:41:32.634Z,1658529692.634 [Default:CheckIn:Read_GPS] Running Loop=1 2022-07-22T22:41:34.631Z,1658529694.631 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,224133.00,A,3648.16934,N,12147.28348,W,0.369,278.90,220722,,,A*72 2022-07-22T22:41:34.634Z,1658529694.634 [NAL9602](INFO): GPS fix at 20220722T224133: (36.802822, -121.788058) 2022-07-22T22:41:34.645Z,1658529694.645 [Default:CheckIn:Read_GPS] Stopped 2022-07-22T22:41:34.645Z,1658529694.645 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-07-22T22:41:42.696Z,1658529702.696 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220722T212900/Courier0039.lzma 2022-07-22T22:41:43.698Z,1658529703.698 [DataOverHttps](INFO): Moved sent file to Logs/20220722T212900/Courier0039.lzma.bak 2022-07-22T22:41:43.699Z,1658529703.699 [DataOverHttps](INFO): SBD MOMSN=17075334 2022-07-22T22:42:00.068Z,1658529720.068 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20220722T212900/Express0040.lzma 2022-07-22T22:42:01.070Z,1658529721.070 [DataOverHttps](INFO): Moved sent file to Logs/20220722T212900/Express0040.lzma.bak 2022-07-22T22:42:01.070Z,1658529721.070 [DataOverHttps](INFO): SBD MOMSN=17075337 2022-07-22T22:42:02.555Z,1658529722.555 [Default:CheckIn:Read_Iridium] Stopped 2022-07-22T22:42:02.556Z,1658529722.556 [Default:CheckIn:C.Wait] Running Loop=1 2022-07-22T22:42:02.556Z,1658529722.556 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-07-22T22:42:05.338Z,1658529725.338 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-07-22T22:42:05.412Z,1658529725.412 [NAL9602](ERROR): received: +CSQ:0 OK452, 0, 0, 0, 0 OK 2022-07-22T22:46:37.238Z,1658529997.238 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-07-22T22:47:03.103Z,1658530023.103 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-07-22T22:47:03.104Z,1658530023.104 [Default:CheckIn:C.Wait] Stopped 2022-07-22T22:47:03.104Z,1658530023.104 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-07-22T22:47:03.104Z,1658530023.104 [Default:CheckIn:D] Running Loop=1 2022-07-22T22:47:03.513Z,1658530023.513 [Default:CheckIn:D] Stopped 2022-07-22T22:47:03.513Z,1658530023.513 [Default:CheckIn:E] Running Loop=1 2022-07-22T22:47:03.912Z,1658530023.912 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 102.318042 min 2022-07-22T22:47:03.912Z,1658530023.912 [Default:CheckIn:E] Stopped 2022-07-22T22:47:03.912Z,1658530023.912 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-07-22T22:47:03.928Z,1658530023.928 [Default:CheckIn] Stopped 2022-07-22T22:47:03.928Z,1658530023.928 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-07-22T22:47:03.929Z,1658530023.929 [Default:CheckIn](INFO): Running loop #19 2022-07-22T22:47:03.929Z,1658530023.929 [Default:CheckIn] Running Loop=19 2022-07-22T22:47:03.929Z,1658530023.929 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-07-22T22:47:03.929Z,1658530023.929 [Default:CheckIn:Read_GPS] Running Loop=1 2022-07-22T22:47:05.927Z,1658530025.927 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,224705.00,A,3648.16557,N,12147.27586,W,0.097,278.90,220722,,,A*71 2022-07-22T22:47:05.930Z,1658530025.930 [NAL9602](INFO): GPS fix at 20220722T224705: (36.802760, -121.787931) 2022-07-22T22:47:05.940Z,1658530025.940 [Default:CheckIn:Read_GPS] Stopped 2022-07-22T22:47:05.940Z,1658530025.940 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-07-22T22:47:13.272Z,1658530033.272 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220722T212900/Courier0042.lzma 2022-07-22T22:47:14.274Z,1658530034.274 [DataOverHttps](INFO): Moved sent file to Logs/20220722T212900/Courier0042.lzma.bak 2022-07-22T22:47:14.274Z,1658530034.274 [DataOverHttps](INFO): SBD MOMSN=17075367 2022-07-22T22:47:30.600Z,1658530050.600 [DataOverHttps](INFO): Sending 209 bytes from file Logs/20220722T212900/Express0043.lzma 2022-07-22T22:47:31.602Z,1658530051.602 [DataOverHttps](INFO): Moved sent file to Logs/20220722T212900/Express0043.lzma.bak 2022-07-22T22:47:31.602Z,1658530051.602 [DataOverHttps](INFO): SBD MOMSN=17075370 2022-07-22T22:47:33.005Z,1658530053.005 [Default:CheckIn:Read_Iridium] Stopped 2022-07-22T22:47:33.005Z,1658530053.005 [Default:CheckIn:C.Wait] Running Loop=1 2022-07-22T22:47:33.005Z,1658530053.005 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-07-22T22:47:38.241Z,1658530058.241 [NAL9602](INFO): Not Powering down - fast GPS 2022-07-22T22:52:33.588Z,1658530353.588 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-07-22T22:52:33.588Z,1658530353.588 [Default:CheckIn:C.Wait] Stopped 2022-07-22T22:52:33.588Z,1658530353.588 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-07-22T22:52:33.588Z,1658530353.588 [Default:CheckIn:D] Running Loop=1 2022-07-22T22:52:33.996Z,1658530353.996 [Default:CheckIn:D] Stopped 2022-07-22T22:52:33.996Z,1658530353.996 [Default:CheckIn:E] Running Loop=1 2022-07-22T22:52:34.419Z,1658530354.419 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 107.826090 min 2022-07-22T22:52:34.419Z,1658530354.419 [Default:CheckIn:E] Stopped 2022-07-22T22:52:34.419Z,1658530354.419 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-07-22T22:52:34.419Z,1658530354.419 [Default:CheckIn] Stopped 2022-07-22T22:52:34.420Z,1658530354.420 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-07-22T22:52:34.420Z,1658530354.420 [Default:CheckIn](INFO): Running loop #20 2022-07-22T22:52:34.420Z,1658530354.420 [Default:CheckIn] Running Loop=20 2022-07-22T22:52:34.420Z,1658530354.420 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-07-22T22:52:34.420Z,1658530354.420 [Default:CheckIn:Read_GPS] Running Loop=1 2022-07-22T22:52:36.407Z,1658530356.407 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,225235.00,A,3648.16582,N,12147.28500,W,0.156,0.00,220722,,,A*77 2022-07-22T22:52:36.410Z,1658530356.410 [NAL9602](INFO): GPS fix at 20220722T225235: (36.802764, -121.788083) 2022-07-22T22:52:36.461Z,1658530356.461 [Default:CheckIn:Read_GPS] Stopped 2022-07-22T22:52:36.461Z,1658530356.461 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-07-22T22:52:43.728Z,1658530363.728 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220722T212900/Courier0045.lzma 2022-07-22T22:52:44.730Z,1658530364.730 [DataOverHttps](INFO): Moved sent file to Logs/20220722T212900/Courier0045.lzma.bak 2022-07-22T22:52:44.730Z,1658530364.730 [DataOverHttps](INFO): SBD MOMSN=17075384 2022-07-22T22:53:01.176Z,1658530381.176 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20220722T212900/Express0046.lzma 2022-07-22T22:53:02.178Z,1658530382.178 [DataOverHttps](INFO): Moved sent file to Logs/20220722T212900/Express0046.lzma.bak 2022-07-22T22:53:02.178Z,1658530382.178 [DataOverHttps](INFO): SBD MOMSN=17075387 2022-07-22T22:53:03.489Z,1658530383.489 [Default:CheckIn:Read_Iridium] Stopped 2022-07-22T22:53:03.489Z,1658530383.489 [Default:CheckIn:C.Wait] Running Loop=1 2022-07-22T22:53:03.489Z,1658530383.489 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-07-22T22:57:38.194Z,1658530658.194 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-07-22T22:58:04.094Z,1658530684.094 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-07-22T22:58:04.094Z,1658530684.094 [Default:CheckIn:C.Wait] Stopped 2022-07-22T22:58:04.094Z,1658530684.094 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-07-22T22:58:04.094Z,1658530684.094 [Default:CheckIn:D] Running Loop=1 2022-07-22T22:58:04.460Z,1658530684.460 [Default:CheckIn:D] Stopped 2022-07-22T22:58:04.460Z,1658530684.460 [Default:CheckIn:E] Running Loop=1 2022-07-22T22:58:04.864Z,1658530684.864 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 113.333813 min 2022-07-22T22:58:04.864Z,1658530684.864 [Default:CheckIn:E] Stopped 2022-07-22T22:58:04.864Z,1658530684.864 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-07-22T22:58:04.865Z,1658530684.865 [Default:CheckIn] Stopped 2022-07-22T22:58:04.865Z,1658530684.865 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-07-22T22:58:04.865Z,1658530684.865 [Default:CheckIn](INFO): Running loop #21 2022-07-22T22:58:04.865Z,1658530684.865 [Default:CheckIn] Running Loop=21 2022-07-22T22:58:04.865Z,1658530684.865 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-07-22T22:58:04.866Z,1658530684.866 [Default:CheckIn:Read_GPS] Running Loop=1 2022-07-22T22:58:06.876Z,1658530686.876 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,225806.00,A,3648.16627,N,12147.28206,W,0.058,311.13,220722,,,A*7E 2022-07-22T22:58:06.878Z,1658530686.878 [NAL9602](INFO): GPS fix at 20220722T225806: (36.802771, -121.788034) 2022-07-22T22:58:06.889Z,1658530686.889 [Default:CheckIn:Read_GPS] Stopped 2022-07-22T22:58:06.889Z,1658530686.889 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-07-22T22:58:14.568Z,1658530694.568 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220722T212900/Courier0048.lzma 2022-07-22T22:58:15.570Z,1658530695.570 [DataOverHttps](INFO): Moved sent file to Logs/20220722T212900/Courier0048.lzma.bak 2022-07-22T22:58:15.570Z,1658530695.570 [DataOverHttps](INFO): SBD MOMSN=17075397 2022-07-22T22:58:31.852Z,1658530711.852 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20220722T212900/Express0049.lzma 2022-07-22T22:58:32.854Z,1658530712.854 [DataOverHttps](INFO): Moved sent file to Logs/20220722T212900/Express0049.lzma.bak 2022-07-22T22:58:32.854Z,1658530712.854 [DataOverHttps](INFO): SBD MOMSN=17075400 2022-07-22T22:58:34.386Z,1658530714.386 [Default:CheckIn:Read_Iridium] Stopped 2022-07-22T22:58:34.387Z,1658530714.387 [Default:CheckIn:C.Wait] Running Loop=1 2022-07-22T22:58:34.387Z,1658530714.387 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-07-22T22:58:39.193Z,1658530719.193 [NAL9602](INFO): Not Powering down - fast GPS 2022-07-22T23:03:35.135Z,1658531015.135 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-07-22T23:03:35.135Z,1658531015.135 [Default:CheckIn:C.Wait] Stopped 2022-07-22T23:03:35.135Z,1658531015.135 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-07-22T23:03:35.135Z,1658531015.135 [Default:CheckIn:D] Running Loop=1 2022-07-22T23:03:35.544Z,1658531015.544 [Default:CheckIn:D] Stopped 2022-07-22T23:03:35.545Z,1658531015.545 [Default:CheckIn:E] Running Loop=1 2022-07-22T23:03:35.946Z,1658531015.946 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 118.851896 min 2022-07-22T23:03:35.946Z,1658531015.946 [Default:CheckIn:E] Stopped 2022-07-22T23:03:35.946Z,1658531015.946 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-07-22T23:03:35.946Z,1658531015.946 [Default:CheckIn] Stopped 2022-07-22T23:03:35.946Z,1658531015.946 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-07-22T23:03:35.947Z,1658531015.947 [Default:CheckIn](INFO): Running loop #22 2022-07-22T23:03:35.947Z,1658531015.947 [Default:CheckIn] Running Loop=22 2022-07-22T23:03:35.947Z,1658531015.947 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-07-22T23:03:35.947Z,1658531015.947 [Default:CheckIn:Read_GPS] Running Loop=1 2022-07-22T23:03:37.961Z,1658531017.961 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,230337.00,A,3648.16474,N,12147.28302,W,0.175,47.09,220722,,,A*47 2022-07-22T23:03:37.963Z,1658531017.963 [NAL9602](INFO): GPS fix at 20220722T230337: (36.802746, -121.788050) 2022-07-22T23:03:37.998Z,1658531017.998 [Default:CheckIn:Read_GPS] Stopped 2022-07-22T23:03:37.998Z,1658531017.998 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-07-22T23:03:45.625Z,1658531025.625 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220722T212900/Courier0051.lzma 2022-07-22T23:03:46.627Z,1658531026.627 [DataOverHttps](INFO): Moved sent file to Logs/20220722T212900/Courier0051.lzma.bak 2022-07-22T23:03:46.628Z,1658531026.628 [DataOverHttps](INFO): SBD MOMSN=17075410 2022-07-22T23:04:02.917Z,1658531042.917 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20220722T212900/Express0052.lzma 2022-07-22T23:04:03.920Z,1658531043.920 [DataOverHttps](INFO): Moved sent file to Logs/20220722T212900/Express0052.lzma.bak 2022-07-22T23:04:03.920Z,1658531043.920 [DataOverHttps](INFO): SBD MOMSN=17075413 2022-07-22T23:04:05.446Z,1658531045.446 [Default:CheckIn:Read_Iridium] Stopped 2022-07-22T23:04:05.446Z,1658531045.446 [Default:CheckIn:C.Wait] Running Loop=1 2022-07-22T23:04:05.446Z,1658531045.446 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-07-22T23:04:08.671Z,1658531048.671 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-07-22T23:04:08.746Z,1658531048.746 [NAL9602](ERROR): received: +CSQ:0 OK452, 0, 0, 0, 0 OK 2022-07-22T23:05:33.104Z,1658531133.104 [NAL9602](INFO): SBD MO Status=2, MOMSN=20453, MT Status=2, MTMSN=0 2022-07-22T23:05:33.104Z,1658531133.104 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-07-22T23:06:49.460Z,1658531209.460 [NAL9602](INFO): SBD MO Status=2, MOMSN=20453, MT Status=2, MTMSN=0 2022-07-22T23:06:49.461Z,1658531209.461 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-07-22T23:07:22.588Z,1658531242.588 [NAL9602](INFO): SBD MO Status=2, MOMSN=20453, MT Status=2, MTMSN=0 2022-07-22T23:07:22.588Z,1658531242.588 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-07-22T23:08:40.165Z,1658531320.165 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-07-22T23:09:06.016Z,1658531346.016 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-07-22T23:09:06.016Z,1658531346.016 [Default:CheckIn:C.Wait] Stopped 2022-07-22T23:09:06.016Z,1658531346.016 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-07-22T23:09:06.016Z,1658531346.016 [Default:CheckIn:D] Running Loop=1 2022-07-22T23:09:06.463Z,1658531346.463 [Default:CheckIn:D] Stopped 2022-07-22T23:09:06.463Z,1658531346.463 [Default:CheckIn:E] Running Loop=1 2022-07-22T23:09:06.834Z,1658531346.834 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 124.367204 min 2022-07-22T23:09:06.834Z,1658531346.834 [Default:CheckIn:E] Stopped 2022-07-22T23:09:06.835Z,1658531346.835 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-07-22T23:09:06.835Z,1658531346.835 [Default:CheckIn] Stopped 2022-07-22T23:09:06.835Z,1658531346.835 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-07-22T23:09:06.835Z,1658531346.835 [Default:CheckIn](INFO): Running loop #23 2022-07-22T23:09:06.835Z,1658531346.835 [Default:CheckIn] Running Loop=23 2022-07-22T23:09:06.835Z,1658531346.835 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-07-22T23:09:06.835Z,1658531346.835 [Default:CheckIn:Read_GPS] Running Loop=1 2022-07-22T23:09:08.840Z,1658531348.840 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,230908.00,A,3648.16592,N,12147.27703,W,0.428,47.09,220722,,,D*4A 2022-07-22T23:09:08.852Z,1658531348.852 [NAL9602](INFO): GPS fix at 20220722T230908: (36.802765, -121.787950) 2022-07-22T23:09:08.862Z,1658531348.862 [Default:CheckIn:Read_GPS] Stopped 2022-07-22T23:09:08.862Z,1658531348.862 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-07-22T23:09:16.845Z,1658531356.845 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220722T212900/Courier0054.lzma 2022-07-22T23:09:17.848Z,1658531357.848 [DataOverHttps](INFO): Moved sent file to Logs/20220722T212900/Courier0054.lzma.bak 2022-07-22T23:09:17.849Z,1658531357.849 [DataOverHttps](INFO): SBD MOMSN=17075422 2022-07-22T23:09:34.214Z,1658531374.214 [DataOverHttps](INFO): Sending 205 bytes from file Logs/20220722T212900/Express0055.lzma 2022-07-22T23:09:35.216Z,1658531375.216 [DataOverHttps](INFO): Moved sent file to Logs/20220722T212900/Express0055.lzma.bak 2022-07-22T23:09:35.216Z,1658531375.216 [DataOverHttps](INFO): SBD MOMSN=17075430 2022-07-22T23:09:36.376Z,1658531376.376 [Default:CheckIn:Read_Iridium] Stopped 2022-07-22T23:09:36.376Z,1658531376.376 [Default:CheckIn:C.Wait] Running Loop=1 2022-07-22T23:09:36.376Z,1658531376.376 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-07-22T23:09:41.155Z,1658531381.155 [NAL9602](INFO): Not Powering down - fast GPS 2022-07-22T23:14:05.775Z,1658531645.775 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2022-07-22T23:14:05.775Z,1658531645.775 [DropWeight] Hardware Fault, FailCount= 1 2022-07-22T23:14:05.775Z,1658531645.775 [DropWeight](ERROR): Hardware Fault 2022-07-22T23:14:05.792Z,1658531645.792 [CommandExec](FAULT): Scheduling is paused 2022-07-22T23:14:05.792Z,1658531645.792 [CBIT](INFO): Critical error at 20220722T231405 2022-07-22T23:14:05.795Z,1658531645.795 [CBIT](ERROR): Hardware Fault in component: DropWeight 2022-07-22T23:14:05.795Z,1658531645.795 [CBIT](CRITICAL): Hardware Fault in component: DropWeight 2022-07-22T23:14:06.235Z,1658531646.235 [CBIT](INFO): Critical error at 20220722T231405 2022-07-22T23:14:36.893Z,1658531676.893 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-07-22T23:14:36.893Z,1658531676.893 [Default:CheckIn:C.Wait] Stopped 2022-07-22T23:14:36.893Z,1658531676.893 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-07-22T23:14:36.894Z,1658531676.894 [Default:CheckIn:D] Running Loop=1 2022-07-22T23:14:37.309Z,1658531677.309 [Default:CheckIn:D] Stopped 2022-07-22T23:14:37.309Z,1658531677.309 [Default:CheckIn:E] Running Loop=1 2022-07-22T23:14:37.705Z,1658531677.705 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 129.881299 min 2022-07-22T23:14:37.705Z,1658531677.705 [Default:CheckIn:E] Stopped 2022-07-22T23:14:37.706Z,1658531677.706 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-07-22T23:14:37.706Z,1658531677.706 [Default:CheckIn] Stopped 2022-07-22T23:14:37.706Z,1658531677.706 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-07-22T23:14:37.706Z,1658531677.706 [Default:CheckIn](INFO): Running loop #24 2022-07-22T23:14:37.706Z,1658531677.706 [Default:CheckIn] Running Loop=24 2022-07-22T23:14:37.706Z,1658531677.706 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-07-22T23:14:37.706Z,1658531677.706 [Default:CheckIn:Read_GPS] Running Loop=1 2022-07-22T23:14:39.716Z,1658531679.716 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,231439.00,A,3648.16346,N,12147.29083,W,0.447,192.64,220722,,,D*71 2022-07-22T23:14:39.719Z,1658531679.719 [NAL9602](INFO): GPS fix at 20220722T231439: (36.802724, -121.788180) 2022-07-22T23:14:39.729Z,1658531679.729 [Default:CheckIn:Read_GPS] Stopped 2022-07-22T23:14:39.729Z,1658531679.729 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-07-22T23:14:47.741Z,1658531687.741 [DataOverHttps](INFO): Sending 183 bytes from file Logs/20220722T212900/Courier0057.lzma 2022-07-22T23:14:48.743Z,1658531688.743 [DataOverHttps](INFO): Moved sent file to Logs/20220722T212900/Courier0057.lzma.bak 2022-07-22T23:14:48.744Z,1658531688.744 [DataOverHttps](INFO): SBD MOMSN=17075438 2022-07-22T23:15:05.053Z,1658531705.053 [DataOverHttps](INFO): Sending 157 bytes from file Logs/20220722T212900/Express0058.lzma 2022-07-22T23:15:06.055Z,1658531706.055 [DataOverHttps](INFO): Moved sent file to Logs/20220722T212900/Express0058.lzma.bak 2022-07-22T23:15:06.056Z,1658531706.056 [DataOverHttps](INFO): SBD MOMSN=17075446 2022-07-22T23:15:07.193Z,1658531707.193 [Default:CheckIn:Read_Iridium] Stopped 2022-07-22T23:15:07.193Z,1658531707.193 [Default:CheckIn:C.Wait] Running Loop=1 2022-07-22T23:15:07.193Z,1658531707.193 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-07-22T23:15:10.415Z,1658531710.415 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-07-22T23:15:10.490Z,1658531710.490 [NAL9602](ERROR): received: +CSQ:0 OK453, 2, 0, 0, 0 OK 2022-07-22T23:19:42.305Z,1658531982.305 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-07-22T23:19:49.835Z,1658531989.835 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.247665 2022-07-22T23:20:00.547Z,1658532000.547 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003793 2022-07-22T23:20:07.766Z,1658532007.766 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-07-22T23:20:07.766Z,1658532007.766 [Default:CheckIn:C.Wait] Stopped 2022-07-22T23:20:07.766Z,1658532007.766 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-07-22T23:20:07.767Z,1658532007.767 [Default:CheckIn:D] Running Loop=1 2022-07-22T23:20:08.196Z,1658532008.196 [Default:CheckIn:D] Stopped 2022-07-22T23:20:08.197Z,1658532008.197 [Default:CheckIn:E] Running Loop=1 2022-07-22T23:20:08.588Z,1658532008.588 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 135.396102 min 2022-07-22T23:20:08.588Z,1658532008.588 [Default:CheckIn:E] Stopped 2022-07-22T23:20:08.588Z,1658532008.588 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-07-22T23:20:08.588Z,1658532008.588 [Default:CheckIn] Stopped 2022-07-22T23:20:08.588Z,1658532008.588 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-07-22T23:20:08.589Z,1658532008.589 [Default:CheckIn](INFO): Running loop #25 2022-07-22T23:20:08.589Z,1658532008.589 [Default:CheckIn] Running Loop=25 2022-07-22T23:20:08.589Z,1658532008.589 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-07-22T23:20:08.589Z,1658532008.589 [Default:CheckIn:Read_GPS] Running Loop=1 2022-07-22T23:20:10.588Z,1658532010.588 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,232010.00,A,3648.15957,N,12147.30540,W,1.749,53.75,220722,,,A*43 2022-07-22T23:20:10.591Z,1658532010.591 [NAL9602](INFO): GPS fix at 20220722T232010: (36.802659, -121.788423) 2022-07-22T23:20:10.623Z,1658532010.623 [Default:CheckIn:Read_GPS] Stopped 2022-07-22T23:20:10.623Z,1658532010.623 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-07-22T23:20:18.325Z,1658532018.325 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220722T212900/Courier0060.lzma 2022-07-22T23:20:19.328Z,1658532019.328 [DataOverHttps](INFO): Moved sent file to Logs/20220722T212900/Courier0060.lzma.bak 2022-07-22T23:20:19.328Z,1658532019.328 [DataOverHttps](INFO): SBD MOMSN=17075528 2022-07-22T23:20:35.745Z,1658532035.745 [DataOverHttps](INFO): Sending 208 bytes from file Logs/20220722T212900/Express0061.lzma 2022-07-22T23:20:36.746Z,1658532036.746 [DataOverHttps](INFO): Moved sent file to Logs/20220722T212900/Express0061.lzma.bak 2022-07-22T23:20:36.747Z,1658532036.747 [DataOverHttps](INFO): SBD MOMSN=17075531 2022-07-22T23:20:38.490Z,1658532038.490 [Default:CheckIn:Read_Iridium] Stopped 2022-07-22T23:20:38.490Z,1658532038.490 [Default:CheckIn:C.Wait] Running Loop=1 2022-07-22T23:20:38.490Z,1658532038.490 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-07-22T23:20:43.309Z,1658532043.309 [NAL9602](INFO): Not Powering down - fast GPS 2022-07-22T23:23:36.285Z,1658532216.285 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude 2022-07-22T23:25:39.059Z,1658532339.059 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-07-22T23:25:39.059Z,1658532339.059 [Default:CheckIn:C.Wait] Stopped 2022-07-22T23:25:39.059Z,1658532339.059 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-07-22T23:25:39.059Z,1658532339.059 [Default:CheckIn:D] Running Loop=1 2022-07-22T23:25:39.472Z,1658532339.472 [Default:CheckIn:D] Stopped 2022-07-22T23:25:39.472Z,1658532339.472 [Default:CheckIn:E] Running Loop=1 2022-07-22T23:25:39.884Z,1658532339.884 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 140.917350 min 2022-07-22T23:25:39.884Z,1658532339.884 [Default:CheckIn:E] Stopped 2022-07-22T23:25:39.884Z,1658532339.884 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-07-22T23:25:39.884Z,1658532339.884 [Default:CheckIn] Stopped 2022-07-22T23:25:39.884Z,1658532339.884 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-07-22T23:25:39.884Z,1658532339.884 [Default:CheckIn](INFO): Running loop #26 2022-07-22T23:25:39.884Z,1658532339.884 [Default:CheckIn] Running Loop=26 2022-07-22T23:25:39.885Z,1658532339.885 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-07-22T23:25:39.885Z,1658532339.885 [Default:CheckIn:Read_GPS] Running Loop=1 2022-07-22T23:25:41.872Z,1658532341.872 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,232541.00,A,3648.16513,N,12147.28689,W,1.555,40.27,220722,,,A*48 2022-07-22T23:25:41.874Z,1658532341.874 [NAL9602](INFO): GPS fix at 20220722T232541: (36.802752, -121.788115) 2022-07-22T23:25:41.885Z,1658532341.885 [Default:CheckIn:Read_GPS] Stopped 2022-07-22T23:25:41.885Z,1658532341.885 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-07-22T23:25:49.664Z,1658532349.664 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220722T212900/Courier0063.lzma 2022-07-22T23:25:50.667Z,1658532350.667 [DataOverHttps](INFO): Moved sent file to Logs/20220722T212900/Courier0063.lzma.bak 2022-07-22T23:25:50.667Z,1658532350.667 [DataOverHttps](INFO): SBD MOMSN=17075536 2022-07-22T23:26:06.044Z,1658532366.044 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20220722T212900/Express0064.lzma 2022-07-22T23:26:07.047Z,1658532367.047 [DataOverHttps](INFO): Moved sent file to Logs/20220722T212900/Express0064.lzma.bak 2022-07-22T23:26:07.047Z,1658532367.047 [DataOverHttps](INFO): SBD MOMSN=17075539 2022-07-22T23:26:08.591Z,1658532368.591 [Default:CheckIn:Read_Iridium] Stopped 2022-07-22T23:26:08.591Z,1658532368.591 [Default:CheckIn:C.Wait] Running Loop=1 2022-07-22T23:26:08.591Z,1658532368.591 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-07-22T23:26:12.574Z,1658532372.574 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-07-22T23:26:12.653Z,1658532372.653 [NAL9602](ERROR): received: +CSQ:0 OK453, 2, 0, 0, 0 OK 2022-07-22T23:28:19.553Z,1658532499.553 [CommandExec](IMPORTANT): got command quit 2022-07-22T23:28:20.557Z,1658532500.557 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread. 2022-07-22T23:28:20.557Z,1658532500.557 [CommandExec](INFO): Uninitializing the command executive. 2022-07-22T23:28:20.557Z,1658532500.557 [CommandExec](INFO): Uninitializing the command scheduler. 2022-07-22T23:28:20.557Z,1658532500.557 [CommandExec ThreadHandler](INFO): Thread cancelled. 2022-07-22T23:28:20.577Z,1658532500.577 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2022-07-22T23:28:20.577Z,1658532500.577 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2022-07-22T23:28:20.577Z,1658532500.577 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2022-07-22T23:28:20.578Z,1658532500.578 [NavChartDb](INFO): Join timeout helper Thread ID is 2383 2022-07-22T23:28:20.929Z,1658532500.929 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2022-07-22T23:28:20.929Z,1658532500.929 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2022-07-22T23:28:20.945Z,1658532500.945 [ComponentRegistry](INFO): Shutting down WetLabsUBAT ThreadHandler 2022-07-22T23:28:20.945Z,1658532500.945 [WetLabsUBAT ThreadHandler](INFO): Thread cancelled. 2022-07-22T23:28:20.945Z,1658532500.945 [WetLabsUBAT](INFO): Join timeout helper Thread ID is 2384 2022-07-22T23:28:20.949Z,1658532500.949 [WetLabsUBAT ThreadHandler](INFO): Uninitializing protected caller thread. 2022-07-22T23:28:20.949Z,1658532500.949 [WetLabsUBAT](INFO): Powering down 2022-07-22T23:28:20.950Z,1658532500.950 [WetLabsUBAT ThreadHandler](INFO): Thread cancelled. 2022-07-22T23:28:20.969Z,1658532500.969 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2022-07-22T23:28:20.969Z,1658532500.969 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2022-07-22T23:28:20.970Z,1658532500.970 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 2385 2022-07-22T23:28:21.341Z,1658532501.341 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2022-07-22T23:28:21.341Z,1658532501.341 [WetLabsBB2FL](INFO): Powering down 2022-07-22T23:28:21.342Z,1658532501.342 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2022-07-22T23:28:21.349Z,1658532501.349 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2022-07-22T23:28:21.349Z,1658532501.349 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2022-07-22T23:28:21.349Z,1658532501.349 [CTD_Seabird](INFO): Join timeout helper Thread ID is 2386 2022-07-22T23:28:22.121Z,1658532502.121 [CTD_Seabird](INFO): Powering down 2022-07-22T23:28:22.137Z,1658532502.137 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread. 2022-07-22T23:28:22.138Z,1658532502.138 [CTD_Seabird](INFO): Powering down 2022-07-22T23:28:22.153Z,1658532502.153 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2022-07-22T23:28:22.170Z,1658532502.170 [ComponentRegistry](INFO): Shutting down DAT ThreadHandler 2022-07-22T23:28:22.171Z,1658532502.171 [DAT ThreadHandler](INFO): Thread cancelled. 2022-07-22T23:28:22.172Z,1658532502.172 [DAT](INFO): Join timeout helper Thread ID is 2387 2022-07-22T23:28:22.297Z,1658532502.297 [DAT](INFO): Powering down 2022-07-22T23:28:22.369Z,1658532502.369 [DAT ThreadHandler](INFO): Uninitializing protected caller thread. 2022-07-22T23:28:22.370Z,1658532502.370 [DAT](INFO): Powering down 2022-07-22T23:28:22.370Z,1658532502.370 [DAT ThreadHandler](INFO): Thread cancelled. 2022-07-22T23:28:22.382Z,1658532502.382 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2022-07-22T23:28:22.382Z,1658532502.382 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2022-07-22T23:28:22.382Z,1658532502.382 [Radio_Surface](INFO): Join timeout helper Thread ID is 2388 2022-07-22T23:28:22.597Z,1658532502.597 [Radio_Surface](INFO): Powering down 2022-07-22T23:28:22.598Z,1658532502.598 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2022-07-22T23:28:22.598Z,1658532502.598 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2022-07-22T23:28:22.605Z,1658532502.605 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler 2022-07-22T23:28:22.605Z,1658532502.605 [Onboard ThreadHandler](INFO): Thread cancelled. 2022-07-22T23:28:22.606Z,1658532502.606 [Onboard](INFO): Join timeout helper Thread ID is 2389 2022-07-22T23:28:22.793Z,1658532502.793 [DataOverHttps](INFO): Radio surface powered OFF, will not connect. 2022-07-22T23:28:26.449Z,1658532506.449 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread. 2022-07-22T23:28:26.449Z,1658532506.449 [Onboard ThreadHandler](INFO): Thread cancelled. 2022-07-22T23:28:26.465Z,1658532506.465 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2022-07-22T23:28:26.465Z,1658532506.465 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2022-07-22T23:28:26.466Z,1658532506.466 [DataOverHttps](INFO): Join timeout helper Thread ID is 2390 2022-07-22T23:28:26.809Z,1658532506.809 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2022-07-22T23:28:26.809Z,1658532506.809 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2022-07-22T23:28:26.825Z,1658532506.825 [ComponentRegistry](INFO): Shutting down BackseatComponent ThreadHandler 2022-07-22T23:28:26.825Z,1658532506.825 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2022-07-22T23:28:26.826Z,1658532506.826 [BackseatComponent](INFO): Join timeout helper Thread ID is 2391 2022-07-22T23:28:26.885Z,1658532506.885 [BackseatComponent ThreadHandler](INFO): Uninitializing protected caller thread. 2022-07-22T23:28:26.885Z,1658532506.885 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2022-07-22T23:28:26.894Z,1658532506.894 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2022-07-22T23:28:26.894Z,1658532506.894 [logger ThreadHandler](INFO): Thread cancelled. 2022-07-22T23:28:26.894Z,1658532506.894 [logger](INFO): Join timeout helper Thread ID is 2392 2022-07-22T23:28:26.911Z,1658532506.911 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2022-07-22T23:28:26.911Z,1658532506.911 [logger ThreadHandler](INFO): Thread cancelled. 2022-07-22T23:28:26.929Z,1658532506.929 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2022-07-22T23:28:26.929Z,1658532506.929 [CommandLine ThreadHandler](INFO): Thread cancelled. 2022-07-22T23:28:26.930Z,1658532506.930 [CommandLine](INFO): Join timeout helper Thread ID is 2393 2022-07-22T23:28:26.941Z,1658532506.941 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2022-07-22T23:28:26.941Z,1658532506.941 [CommandLine ThreadHandler](INFO): Thread cancelled. 2022-07-22T23:28:26.949Z,1658532506.949 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler 2022-07-22T23:28:26.949Z,1658532506.949 [CommandExec ThreadHandler](INFO): Thread cancelled. 2022-07-22T23:28:26.950Z,1658532506.950 [CommandExec](INFO): Join timeout helper Thread ID is 2394 2022-07-22T23:28:26.951Z,1658532506.951 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2022-07-22T23:28:26.951Z,1658532506.951 [controlThread ThreadHandler](INFO): Thread cancelled. 2022-07-22T23:28:26.952Z,1658532506.952 [controlThread](INFO): Join timeout helper Thread ID is 2395 2022-07-22T23:28:27.089Z,1658532507.089 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2022-07-22T23:28:27.089Z,1658532507.089 [controlThread](DEBUG): Uninitializing ControlThread 2022-07-22T23:28:27.090Z,1658532507.090 [AHRS_M2](INFO): Powering down 2022-07-22T23:28:27.162Z,1658532507.162 [NAL9602](INFO): Powering down 2022-07-22T23:28:27.233Z,1658532507.233 [RDI_Pathfinder](INFO): Powering down 2022-07-22T23:28:27.234Z,1658532507.234 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2022-07-22T23:28:27.235Z,1658532507.235 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2022-07-22T23:28:27.235Z,1658532507.235 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2022-07-22T23:28:27.236Z,1658532507.236 [MissionManager](INFO): Uninitializing Mission Default 2022-07-22T23:28:27.236Z,1658532507.236 [Default] Stopped 2022-07-22T23:28:27.236Z,1658532507.236 [Default](DEBUG): Aggregate::uninitialize Default 2022-07-22T23:28:27.236Z,1658532507.236 [Default:B.GoToSurface] Stopped 2022-07-22T23:28:27.236Z,1658532507.236 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2022-07-22T23:28:27.236Z,1658532507.236 [Default:CheckIn] Stopped 2022-07-22T23:28:27.236Z,1658532507.236 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-07-22T23:28:27.237Z,1658532507.237 [Default:CheckIn:C.Wait] Stopped 2022-07-22T23:28:27.237Z,1658532507.237 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-07-22T23:28:27.239Z,1658532507.239 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2022-07-22T23:28:27.240Z,1658532507.240 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2022-07-22T23:28:27.240Z,1658532507.240 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2022-07-22T23:28:27.240Z,1658532507.240 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2022-07-22T23:28:27.241Z,1658532507.241 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2022-07-22T23:28:27.241Z,1658532507.241 [BuoyancyServo](INFO): Powering down 2022-07-22T23:28:27.253Z,1658532507.253 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2022-07-22T23:28:27.253Z,1658532507.253 [ElevatorServo](INFO): Powering down 2022-07-22T23:28:27.254Z,1658532507.254 [MassServo](DEBUG): Uninitialize Mass Servo. 2022-07-22T23:28:27.254Z,1658532507.254 [MassServo](INFO): Powering down 2022-07-22T23:28:27.255Z,1658532507.255 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2022-07-22T23:28:27.255Z,1658532507.255 [RudderServo](INFO): Powering down 2022-07-22T23:28:27.256Z,1658532507.256 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2022-07-22T23:28:27.256Z,1658532507.256 [ThrusterServo](INFO): Powering down 2022-07-22T23:28:27.257Z,1658532507.257 [SBIT](DEBUG): Uninitialize SBIT Component. 2022-07-22T23:28:27.257Z,1658532507.257 [IBIT](DEBUG): Uninitialize IBIT Component. 2022-07-22T23:28:27.257Z,1658532507.257 [CBIT](DEBUG): Uninitialize CBIT Component. 2022-07-22T23:28:27.257Z,1658532507.257 [CBIT](DEBUG): Powering off loads. 2022-07-22T23:28:27.268Z,1658532507.268 [CBIT](DEBUG): Disabling WDT. 2022-07-22T23:28:27.280Z,1658532507.280 [CBIT](DEBUG): Opening all GF detection circuits. 2022-07-22T23:28:27.281Z,1658532507.281 [controlThread ThreadHandler](INFO): Thread cancelled. 2022-07-22T23:28:27.329Z,1658532507.329 [DAT ThreadHandler](INFO): Thread cancelled. 2022-07-22T23:28:27.337Z,1658532507.337 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2022-07-22T23:28:27.338Z,1658532507.338 [Onboard ThreadHandler](INFO): Thread cancelled. 2022-07-22T23:28:27.344Z,1658532507.344 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2022-07-22T23:28:27.386Z,1658532507.386 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2022-07-22T23:28:27.449Z,1658532507.449 [WetLabsUBAT ThreadHandler](INFO): Thread cancelled. 2022-07-22T23:28:27.451Z,1658532507.451 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2022-07-22T23:28:27.454Z,1658532507.454 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2022-07-22T23:28:27.461Z,1658532507.461 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2022-07-22T23:28:27.539Z,1658532507.539 [logger ThreadHandler](INFO): Thread cancelled.