2020-12-04T19:41:32.908Z,1607110892.908 [CommandLine](IMPORTANT): got command restart logs 2020-12-04T19:41:36.169Z,1607110896.169 [NAL9602](INFO): Not Powering down - fast GPS 2020-12-04T19:46:27.126Z,1607111187.126 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-12-04T19:46:27.126Z,1607111187.126 [Default:CheckIn:C.Wait] Stopped 2020-12-04T19:46:27.126Z,1607111187.126 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-12-04T19:46:27.126Z,1607111187.126 [Default:CheckIn:D] Running Loop=1 2020-12-04T19:46:27.551Z,1607111187.551 [Default:CheckIn:D] Stopped 2020-12-04T19:46:27.551Z,1607111187.551 [Default:CheckIn:E] Running Loop=1 2020-12-04T19:46:27.955Z,1607111187.955 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 53.722831 min 2020-12-04T19:46:27.956Z,1607111187.956 [Default:CheckIn:E] Stopped 2020-12-04T19:46:27.956Z,1607111187.956 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-12-04T19:46:27.956Z,1607111187.956 [Default:CheckIn] Stopped 2020-12-04T19:46:27.956Z,1607111187.956 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-12-04T19:46:27.956Z,1607111187.956 [Default:CheckIn](INFO): Running loop #7 2020-12-04T19:46:27.956Z,1607111187.956 [Default:CheckIn] Running Loop=7 2020-12-04T19:46:27.956Z,1607111187.956 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-12-04T19:46:27.957Z,1607111187.957 [Default:CheckIn:Read_GPS] Running Loop=1 2020-12-04T19:46:29.939Z,1607111189.939 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194629.00,A,3642.92008,N,12154.89992,W,24.667,43.49,041220,,,D*76 2020-12-04T19:46:29.941Z,1607111189.941 [NAL9602](INFO): GPS fix at 20201204T194629: (36.715335, -121.914999) 2020-12-04T19:46:29.960Z,1607111189.960 [Default:CheckIn:Read_GPS] Stopped 2020-12-04T19:46:29.960Z,1607111189.960 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-12-04T19:46:41.686Z,1607111201.686 [NAL9602](INFO): SBD MO Status=0, MOMSN=11706, MT Status=0, MTMSN=0 2020-12-04T19:46:41.687Z,1607111201.687 [NAL9602](INFO): No messages in MT queue 2020-12-04T19:47:12.425Z,1607111232.425 [NAL9602](INFO): Not Powering down - fast GPS 2020-12-04T19:49:19.087Z,1607111359.087 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20201204T181312/Courier0033.lzma 2020-12-04T19:49:20.090Z,1607111360.090 [DataOverHttps](INFO): Moved sent file to Logs/20201204T181312/Courier0033.lzma.bak 2020-12-04T19:49:20.090Z,1607111360.090 [DataOverHttps](INFO): SBD MOMSN=13396778 2020-12-04T19:49:36.676Z,1607111376.676 [DataOverHttps](INFO): Sending 269 bytes from file Logs/20201204T194132/Courier0000.lzma 2020-12-04T19:49:37.678Z,1607111377.678 [DataOverHttps](INFO): Moved sent file to Logs/20201204T194132/Courier0000.lzma.bak 2020-12-04T19:49:37.678Z,1607111377.678 [DataOverHttps](INFO): SBD MOMSN=13396780 2020-12-04T19:49:54.344Z,1607111394.344 [DataOverHttps](INFO): Sending 115 bytes from file Logs/20201204T181312/Express0034.lzma 2020-12-04T19:49:55.349Z,1607111395.349 [DataOverHttps](INFO): Moved sent file to Logs/20201204T181312/Express0034.lzma.bak 2020-12-04T19:49:55.350Z,1607111395.350 [DataOverHttps](INFO): SBD MOMSN=13396784 2020-12-04T19:50:03.844Z,1607111403.844 [BPC1](ERROR): BPC1B: No match for serial number 1717 in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file). 2020-12-04T19:50:11.652Z,1607111411.652 [DataOverHttps](INFO): Sending 415 bytes from file Logs/20201204T194132/Express0001.lzma 2020-12-04T19:50:12.653Z,1607111412.653 [DataOverHttps](INFO): Moved sent file to Logs/20201204T194132/Express0001.lzma.bak 2020-12-04T19:50:12.654Z,1607111412.654 [DataOverHttps](INFO): SBD MOMSN=13396788 2020-12-04T19:50:13.960Z,1607111413.960 [Default:CheckIn:Read_Iridium] Stopped 2020-12-04T19:50:13.960Z,1607111413.960 [Default:CheckIn:C.Wait] Running Loop=1 2020-12-04T19:50:13.961Z,1607111413.961 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-12-04T19:53:39.704Z,1607111619.704 [BPC1](INFO): Calculating totals. Valid battery stick count: 53. Valid reserve battery stick count: 6. 2020-12-04T19:53:39.707Z,1607111619.707 [BPC1](INFO): Received data from all battery sticks. 2020-12-04T19:55:14.369Z,1607111714.369 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-12-04T19:55:14.369Z,1607111714.369 [Default:CheckIn:C.Wait] Stopped 2020-12-04T19:55:14.369Z,1607111714.369 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-12-04T19:55:14.370Z,1607111714.370 [Default:CheckIn:D] Running Loop=1 2020-12-04T19:55:14.747Z,1607111714.747 [Default:CheckIn:D] Stopped 2020-12-04T19:55:14.747Z,1607111714.747 [Default:CheckIn:E] Running Loop=1 2020-12-04T19:55:15.151Z,1607111715.151 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 62.509428 min 2020-12-04T19:55:15.151Z,1607111715.151 [Default:CheckIn:E] Stopped 2020-12-04T19:55:15.151Z,1607111715.151 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-12-04T19:55:15.152Z,1607111715.152 [Default:CheckIn] Stopped 2020-12-04T19:55:15.152Z,1607111715.152 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-12-04T19:55:15.152Z,1607111715.152 [Default:CheckIn](INFO): Running loop #8 2020-12-04T19:55:15.152Z,1607111715.152 [Default:CheckIn] Running Loop=8 2020-12-04T19:55:15.152Z,1607111715.152 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-12-04T19:55:15.152Z,1607111715.152 [Default:CheckIn:Read_GPS] Running Loop=1 2020-12-04T19:55:17.163Z,1607111717.163 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,195516.00,A,3645.49865,N,12151.35807,W,27.583,52.25,041220,,,D*75 2020-12-04T19:55:17.165Z,1607111717.165 [NAL9602](INFO): GPS fix at 20201204T195516: (36.758311, -121.855968) 2020-12-04T19:55:17.193Z,1607111717.193 [Default:CheckIn:Read_GPS] Stopped 2020-12-04T19:55:17.193Z,1607111717.193 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-12-04T19:55:26.068Z,1607111726.068 [DataOverHttps](INFO): Sending 201 bytes from file Logs/20201204T194132/Courier0003.lzma 2020-12-04T19:55:27.070Z,1607111727.070 [DataOverHttps](INFO): Moved sent file to Logs/20201204T194132/Courier0003.lzma.bak 2020-12-04T19:55:27.070Z,1607111727.070 [DataOverHttps](INFO): SBD MOMSN=13396793 2020-12-04T19:55:43.297Z,1607111743.297 [DataOverHttps](INFO): Sending 146 bytes from file Logs/20201204T194132/Express0005.lzma 2020-12-04T19:55:44.295Z,1607111744.295 [DataOverHttps](INFO): Moved sent file to Logs/20201204T194132/Express0005.lzma.bak 2020-12-04T19:55:44.295Z,1607111744.295 [DataOverHttps](INFO): SBD MOMSN=13396797 2020-12-04T19:55:45.465Z,1607111745.465 [Default:CheckIn:Read_Iridium] Stopped 2020-12-04T19:55:45.465Z,1607111745.465 [Default:CheckIn:C.Wait] Running Loop=1 2020-12-04T19:55:45.465Z,1607111745.465 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-12-04T19:55:47.483Z,1607111747.483 [NAL9602](INFO): SBD MO Status=0, MOMSN=11707, MT Status=0, MTMSN=0 2020-12-04T19:55:47.483Z,1607111747.483 [NAL9602](INFO): No messages in MT queue 2020-12-04T19:56:16.420Z,1607111776.420 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2020-12-04T19:56:18.161Z,1607111778.161 [NAL9602](INFO): Not Powering down - fast GPS 2020-12-04T19:56:44.532Z,1607111804.532 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.238045 2020-12-04T19:57:25.696Z,1607111845.696 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2020-12-04T19:57:38.364Z,1607111858.364 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003304 2020-12-04T19:58:36.600Z,1607111916.600 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2020-12-04T19:58:38.608Z,1607111918.608 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.247089 2020-12-04T19:59:11.740Z,1607111951.740 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2020-12-04T19:59:24.520Z,1607111964.520 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003290 2020-12-04T20:00:46.105Z,1607112046.105 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-12-04T20:00:46.106Z,1607112046.106 [Default:CheckIn:C.Wait] Stopped 2020-12-04T20:00:46.106Z,1607112046.106 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-12-04T20:00:46.107Z,1607112046.107 [Default:CheckIn:D] Running Loop=1 2020-12-04T20:00:46.480Z,1607112046.480 [Default:CheckIn:D] Stopped 2020-12-04T20:00:46.480Z,1607112046.480 [Default:CheckIn:E] Running Loop=1 2020-12-04T20:00:46.890Z,1607112046.890 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 68.038302 min 2020-12-04T20:00:46.890Z,1607112046.890 [Default:CheckIn:E] Stopped 2020-12-04T20:00:46.890Z,1607112046.890 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-12-04T20:00:46.890Z,1607112046.890 [Default:CheckIn] Stopped 2020-12-04T20:00:46.890Z,1607112046.890 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-12-04T20:00:46.890Z,1607112046.890 [Default:CheckIn](INFO): Running loop #9 2020-12-04T20:00:46.891Z,1607112046.891 [Default:CheckIn] Running Loop=9 2020-12-04T20:00:46.891Z,1607112046.891 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-12-04T20:00:46.891Z,1607112046.891 [Default:CheckIn:Read_GPS] Running Loop=1 2020-12-04T20:00:48.901Z,1607112048.901 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200048.00,A,3647.09831,N,12149.08577,W,27.700,51.44,041220,,,D*73 2020-12-04T20:00:48.903Z,1607112048.903 [NAL9602](INFO): GPS fix at 20201204T200048: (36.784972, -121.818096) 2020-12-04T20:00:48.914Z,1607112048.914 [Default:CheckIn:Read_GPS] Stopped 2020-12-04T20:00:48.914Z,1607112048.914 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-12-04T20:00:56.915Z,1607112056.915 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20201204T194132/Courier0009.lzma 2020-12-04T20:00:57.918Z,1607112057.918 [DataOverHttps](INFO): Moved sent file to Logs/20201204T194132/Courier0009.lzma.bak 2020-12-04T20:00:57.918Z,1607112057.918 [DataOverHttps](INFO): SBD MOMSN=13396820 2020-12-04T20:01:05.055Z,1607112065.055 [NAL9602](INFO): SBD MO Status=0, MOMSN=11708, MT Status=0, MTMSN=0 2020-12-04T20:01:05.055Z,1607112065.055 [NAL9602](INFO): No messages in MT queue 2020-12-04T20:01:35.757Z,1607112095.757 [NAL9602](INFO): Not Powering down - fast GPS 2020-12-04T20:03:59.061Z,1607112239.061 [DataOverHttps](INFO): Sending 145 bytes from file Logs/20201204T194132/Express0010.lzma 2020-12-04T20:04:00.062Z,1607112240.062 [DataOverHttps](INFO): Moved sent file to Logs/20201204T194132/Express0010.lzma.bak 2020-12-04T20:04:00.062Z,1607112240.062 [DataOverHttps](INFO): SBD MOMSN=13396868 2020-12-04T20:04:01.375Z,1607112241.375 [Default:CheckIn:Read_Iridium] Stopped 2020-12-04T20:04:01.375Z,1607112241.375 [Default:CheckIn:C.Wait] Running Loop=1 2020-12-04T20:04:01.375Z,1607112241.375 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-12-04T20:09:02.043Z,1607112542.043 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-12-04T20:09:02.043Z,1607112542.043 [Default:CheckIn:C.Wait] Stopped 2020-12-04T20:09:02.043Z,1607112542.043 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-12-04T20:09:02.043Z,1607112542.043 [Default:CheckIn:D] Running Loop=1 2020-12-04T20:09:02.457Z,1607112542.457 [Default:CheckIn:D] Stopped 2020-12-04T20:09:02.457Z,1607112542.457 [Default:CheckIn:E] Running Loop=1 2020-12-04T20:09:02.860Z,1607112542.860 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 76.304590 min 2020-12-04T20:09:02.860Z,1607112542.860 [Default:CheckIn:E] Stopped 2020-12-04T20:09:02.860Z,1607112542.860 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-12-04T20:09:02.860Z,1607112542.860 [Default:CheckIn] Stopped 2020-12-04T20:09:02.860Z,1607112542.860 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-12-04T20:09:02.860Z,1607112542.860 [Default:CheckIn](INFO): Running loop #10 2020-12-04T20:09:02.861Z,1607112542.861 [Default:CheckIn] Running Loop=10 2020-12-04T20:09:02.861Z,1607112542.861 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-12-04T20:09:02.861Z,1607112542.861 [Default:CheckIn:Read_GPS] Running Loop=1 2020-12-04T20:09:04.873Z,1607112544.873 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200904.00,A,3648.31243,N,12147.13136,W,4.140,188.98,041220,,,D*7B 2020-12-04T20:09:04.875Z,1607112544.875 [NAL9602](INFO): GPS fix at 20201204T200904: (36.805207, -121.785523) 2020-12-04T20:09:04.940Z,1607112544.940 [Default:CheckIn:Read_GPS] Stopped 2020-12-04T20:09:04.940Z,1607112544.940 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-12-04T20:09:12.877Z,1607112552.877 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20201204T194132/Courier0012.lzma 2020-12-04T20:09:13.878Z,1607112553.878 [DataOverHttps](INFO): Moved sent file to Logs/20201204T194132/Courier0012.lzma.bak 2020-12-04T20:09:13.878Z,1607112553.878 [DataOverHttps](INFO): SBD MOMSN=13396890 2020-12-04T20:09:24.652Z,1607112564.652 [NAL9602](INFO): SBD MO Status=2, MOMSN=11709, MT Status=2, MTMSN=0 2020-12-04T20:09:24.653Z,1607112564.653 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2020-12-04T20:09:30.207Z,1607112570.207 [DataOverHttps](INFO): Sending 146 bytes from file Logs/20201204T194132/Express0013.lzma 2020-12-04T20:09:31.210Z,1607112571.210 [DataOverHttps](INFO): Moved sent file to Logs/20201204T194132/Express0013.lzma.bak 2020-12-04T20:09:31.210Z,1607112571.210 [DataOverHttps](INFO): SBD MOMSN=13396893 2020-12-04T20:09:32.751Z,1607112572.751 [Default:CheckIn:Read_Iridium] Stopped 2020-12-04T20:09:32.751Z,1607112572.751 [Default:CheckIn:C.Wait] Running Loop=1 2020-12-04T20:09:32.751Z,1607112572.751 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-12-04T20:09:42.030Z,1607112582.030 [NAL9602](INFO): SBD MO Status=2, MOMSN=11709, MT Status=2, MTMSN=0 2020-12-04T20:09:42.030Z,1607112582.030 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2020-12-04T20:09:58.187Z,1607112598.187 [NAL9602](INFO): SBD MO Status=0, MOMSN=11709, MT Status=0, MTMSN=0 2020-12-04T20:09:58.187Z,1607112598.187 [NAL9602](INFO): No messages in MT queue 2020-12-04T20:10:28.887Z,1607112628.887 [NAL9602](INFO): Not Powering down - fast GPS 2020-12-04T20:14:33.486Z,1607112873.486 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-12-04T20:14:33.486Z,1607112873.486 [Default:CheckIn:C.Wait] Stopped 2020-12-04T20:14:33.486Z,1607112873.486 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-12-04T20:14:33.486Z,1607112873.486 [Default:CheckIn:D] Running Loop=1 2020-12-04T20:14:33.790Z,1607112873.790 [Default:CheckIn:D] Stopped 2020-12-04T20:14:33.790Z,1607112873.790 [Default:CheckIn:E] Running Loop=1 2020-12-04T20:14:34.202Z,1607112874.202 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 81.826815 min 2020-12-04T20:14:34.202Z,1607112874.202 [Default:CheckIn:E] Stopped 2020-12-04T20:14:34.202Z,1607112874.202 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-12-04T20:14:34.202Z,1607112874.202 [Default:CheckIn] Stopped 2020-12-04T20:14:34.203Z,1607112874.203 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-12-04T20:14:34.203Z,1607112874.203 [Default:CheckIn](INFO): Running loop #11 2020-12-04T20:14:34.203Z,1607112874.203 [Default:CheckIn] Running Loop=11 2020-12-04T20:14:34.203Z,1607112874.203 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-12-04T20:14:34.203Z,1607112874.203 [Default:CheckIn:Read_GPS] Running Loop=1 2020-12-04T20:14:36.207Z,1607112876.207 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,201435.00,A,3648.11884,N,12147.22803,W,0.117,269.59,041220,,,D*7C 2020-12-04T20:14:36.209Z,1607112876.209 [NAL9602](INFO): GPS fix at 20201204T201435: (36.801981, -121.787134) 2020-12-04T20:14:36.224Z,1607112876.224 [Default:CheckIn:Read_GPS] Stopped 2020-12-04T20:14:36.224Z,1607112876.224 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-12-04T20:15:00.362Z,1607112900.362 [NAL9602](INFO): SBD MO Status=2, MOMSN=11710, MT Status=2, MTMSN=0 2020-12-04T20:15:00.362Z,1607112900.362 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2020-12-04T20:15:09.319Z,1607112909.319 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2020-12-04T20:15:27.835Z,1607112927.835 [NAL9602](INFO): SBD MO Status=2, MOMSN=11710, MT Status=2, MTMSN=0 2020-12-04T20:15:27.835Z,1607112927.835 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2020-12-04T20:15:56.922Z,1607112956.922 [NAL9602](INFO): SBD MO Status=0, MOMSN=11710, MT Status=0, MTMSN=0 2020-12-04T20:15:56.922Z,1607112956.922 [NAL9602](INFO): No messages in MT queue 2020-12-04T20:16:27.661Z,1607112987.661 [NAL9602](INFO): Not Powering down - fast GPS 2020-12-04T20:17:18.671Z,1607113038.671 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20201204T194132/Courier0015.lzma 2020-12-04T20:17:19.674Z,1607113039.674 [DataOverHttps](INFO): Moved sent file to Logs/20201204T194132/Courier0015.lzma.bak 2020-12-04T20:17:19.674Z,1607113039.674 [DataOverHttps](INFO): SBD MOMSN=13396969 2020-12-04T20:17:36.099Z,1607113056.099 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20201204T194132/Express0016.lzma 2020-12-04T20:17:37.102Z,1607113057.102 [DataOverHttps](INFO): Moved sent file to Logs/20201204T194132/Express0016.lzma.bak 2020-12-04T20:17:37.102Z,1607113057.102 [DataOverHttps](INFO): SBD MOMSN=13396975 2020-12-04T20:17:38.439Z,1607113058.439 [Default:CheckIn:Read_Iridium] Stopped 2020-12-04T20:17:38.439Z,1607113058.439 [Default:CheckIn:C.Wait] Running Loop=1 2020-12-04T20:17:38.439Z,1607113058.439 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-12-04T20:22:39.108Z,1607113359.108 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-12-04T20:22:39.108Z,1607113359.108 [Default:CheckIn:C.Wait] Stopped 2020-12-04T20:22:39.108Z,1607113359.108 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-12-04T20:22:39.108Z,1607113359.108 [Default:CheckIn:D] Running Loop=1 2020-12-04T20:22:39.513Z,1607113359.513 [Default:CheckIn:D] Stopped 2020-12-04T20:22:39.513Z,1607113359.513 [Default:CheckIn:E] Running Loop=1 2020-12-04T20:22:39.919Z,1607113359.919 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 89.922192 min 2020-12-04T20:22:39.919Z,1607113359.919 [Default:CheckIn:E] Stopped 2020-12-04T20:22:39.920Z,1607113359.920 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-12-04T20:22:39.920Z,1607113359.920 [Default:CheckIn] Stopped 2020-12-04T20:22:39.920Z,1607113359.920 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-12-04T20:22:39.920Z,1607113359.920 [Default:CheckIn](INFO): Running loop #12 2020-12-04T20:22:39.920Z,1607113359.920 [Default:CheckIn] Running Loop=12 2020-12-04T20:22:39.920Z,1607113359.920 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-12-04T20:22:39.921Z,1607113359.921 [Default:CheckIn:Read_GPS] Running Loop=1 2020-12-04T20:22:41.923Z,1607113361.923 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,202241.00,A,3648.11889,N,12147.22851,W,0.019,269.59,041220,,,D*7F 2020-12-04T20:22:41.925Z,1607113361.925 [NAL9602](INFO): GPS fix at 20201204T202241: (36.801981, -121.787142) 2020-12-04T20:22:41.951Z,1607113361.951 [Default:CheckIn:Read_GPS] Stopped 2020-12-04T20:22:41.952Z,1607113361.952 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-12-04T20:22:49.345Z,1607113369.345 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20201204T194132/Courier0018.lzma 2020-12-04T20:22:50.338Z,1607113370.338 [DataOverHttps](INFO): Moved sent file to Logs/20201204T194132/Courier0018.lzma.bak 2020-12-04T20:22:50.338Z,1607113370.338 [DataOverHttps](INFO): SBD MOMSN=13397047 2020-12-04T20:22:50.807Z,1607113370.807 [NAL9602](INFO): SBD MO Status=0, MOMSN=11711, MT Status=0, MTMSN=0 2020-12-04T20:22:50.808Z,1607113370.807 [NAL9602](INFO): No messages in MT queue 2020-12-04T20:23:06.575Z,1607113386.575 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20201204T194132/Express0019.lzma 2020-12-04T20:23:07.578Z,1607113387.578 [DataOverHttps](INFO): Moved sent file to Logs/20201204T194132/Express0019.lzma.bak 2020-12-04T20:23:07.578Z,1607113387.578 [DataOverHttps](INFO): SBD MOMSN=13397050 2020-12-04T20:23:09.004Z,1607113389.004 [Default:CheckIn:Read_Iridium] Stopped 2020-12-04T20:23:09.004Z,1607113389.004 [Default:CheckIn:C.Wait] Running Loop=1 2020-12-04T20:23:09.005Z,1607113389.005 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-12-04T20:23:21.507Z,1607113401.507 [NAL9602](INFO): Not Powering down - fast GPS 2020-12-04T20:28:09.690Z,1607113689.690 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-12-04T20:28:09.691Z,1607113689.691 [Default:CheckIn:C.Wait] Stopped 2020-12-04T20:28:09.691Z,1607113689.691 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-12-04T20:28:09.691Z,1607113689.691 [Default:CheckIn:D] Running Loop=1 2020-12-04T20:28:10.063Z,1607113690.063 [Default:CheckIn:D] Stopped 2020-12-04T20:28:10.063Z,1607113690.063 [Default:CheckIn:E] Running Loop=1 2020-12-04T20:28:10.478Z,1607113690.478 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 95.431356 min 2020-12-04T20:28:10.478Z,1607113690.478 [Default:CheckIn:E] Stopped 2020-12-04T20:28:10.478Z,1607113690.478 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-12-04T20:28:10.478Z,1607113690.478 [Default:CheckIn] Stopped 2020-12-04T20:28:10.478Z,1607113690.478 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-12-04T20:28:10.478Z,1607113690.478 [Default:CheckIn](INFO): Running loop #13 2020-12-04T20:28:10.479Z,1607113690.479 [Default:CheckIn] Running Loop=13 2020-12-04T20:28:10.479Z,1607113690.479 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-12-04T20:28:10.479Z,1607113690.479 [Default:CheckIn:Read_GPS] Running Loop=1 2020-12-04T20:28:12.483Z,1607113692.483 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,202811.00,A,3648.11865,N,12147.22812,W,0.058,355.16,041220,,,A*70 2020-12-04T20:28:12.486Z,1607113692.486 [NAL9602](INFO): GPS fix at 20201204T202811: (36.801977, -121.787135) 2020-12-04T20:28:12.507Z,1607113692.507 [Default:CheckIn:Read_GPS] Stopped 2020-12-04T20:28:12.507Z,1607113692.507 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-12-04T20:28:20.183Z,1607113700.183 [NAL9602](INFO): SBD MO Status=0, MOMSN=11712, MT Status=0, MTMSN=0 2020-12-04T20:28:20.183Z,1607113700.183 [NAL9602](INFO): No messages in MT queue 2020-12-04T20:28:50.953Z,1607113730.953 [NAL9602](INFO): Not Powering down - fast GPS 2020-12-04T20:30:43.763Z,1607113843.763 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20201204T194132/Courier0021.lzma 2020-12-04T20:30:44.766Z,1607113844.766 [DataOverHttps](INFO): Moved sent file to Logs/20201204T194132/Courier0021.lzma.bak 2020-12-04T20:30:44.766Z,1607113844.766 [DataOverHttps](INFO): SBD MOMSN=13397118 2020-12-04T20:31:01.229Z,1607113861.229 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20201204T194132/Express0022.lzma 2020-12-04T20:31:02.230Z,1607113862.230 [DataOverHttps](INFO): Moved sent file to Logs/20201204T194132/Express0022.lzma.bak 2020-12-04T20:31:02.230Z,1607113862.230 [DataOverHttps](INFO): SBD MOMSN=13397124 2020-12-04T20:31:03.590Z,1607113863.590 [Default:CheckIn:Read_Iridium] Stopped 2020-12-04T20:31:03.591Z,1607113863.591 [Default:CheckIn:C.Wait] Running Loop=1 2020-12-04T20:31:03.591Z,1607113863.591 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-12-04T20:36:04.234Z,1607114164.234 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-12-04T20:36:04.234Z,1607114164.234 [Default:CheckIn:C.Wait] Stopped 2020-12-04T20:36:04.234Z,1607114164.234 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-12-04T20:36:04.235Z,1607114164.235 [Default:CheckIn:D] Running Loop=1 2020-12-04T20:36:04.631Z,1607114164.631 [Default:CheckIn:D] Stopped 2020-12-04T20:36:04.631Z,1607114164.631 [Default:CheckIn:E] Running Loop=1 2020-12-04T20:36:05.046Z,1607114165.046 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 103.340820 min 2020-12-04T20:36:05.046Z,1607114165.046 [Default:CheckIn:E] Stopped 2020-12-04T20:36:05.046Z,1607114165.046 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-12-04T20:36:05.046Z,1607114165.046 [Default:CheckIn] Stopped 2020-12-04T20:36:05.046Z,1607114165.046 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-12-04T20:36:05.046Z,1607114165.046 [Default:CheckIn](INFO): Running loop #14 2020-12-04T20:36:05.046Z,1607114165.046 [Default:CheckIn] Running Loop=14 2020-12-04T20:36:05.046Z,1607114165.046 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-12-04T20:36:05.047Z,1607114165.047 [Default:CheckIn:Read_GPS] Running Loop=1 2020-12-04T20:36:07.048Z,1607114167.048 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,203606.00,A,3648.11836,N,12147.22940,W,0.000,355.16,041220,,,D*71 2020-12-04T20:36:07.050Z,1607114167.050 [NAL9602](INFO): GPS fix at 20201204T203606: (36.801973, -121.787157) 2020-12-04T20:36:07.061Z,1607114167.061 [Default:CheckIn:Read_GPS] Stopped 2020-12-04T20:36:07.061Z,1607114167.061 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-12-04T20:36:15.067Z,1607114175.067 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20201204T194132/Courier0024.lzma 2020-12-04T20:36:16.070Z,1607114176.070 [DataOverHttps](INFO): Moved sent file to Logs/20201204T194132/Courier0024.lzma.bak 2020-12-04T20:36:16.070Z,1607114176.070 [DataOverHttps](INFO): SBD MOMSN=13397138 2020-12-04T20:36:22.447Z,1607114182.447 [NAL9602](INFO): SBD MO Status=0, MOMSN=11713, MT Status=0, MTMSN=0 2020-12-04T20:36:22.447Z,1607114182.447 [NAL9602](INFO): No messages in MT queue 2020-12-04T20:36:38.648Z,1607114198.648 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20201204T194132/Express0025.lzma 2020-12-04T20:36:39.650Z,1607114199.650 [DataOverHttps](INFO): Moved sent file to Logs/20201204T194132/Express0025.lzma.bak 2020-12-04T20:36:39.650Z,1607114199.650 [DataOverHttps](INFO): SBD MOMSN=13397532 2020-12-04T20:36:41.211Z,1607114201.211 [Default:CheckIn:Read_Iridium] Stopped 2020-12-04T20:36:41.211Z,1607114201.211 [Default:CheckIn:C.Wait] Running Loop=1 2020-12-04T20:36:41.211Z,1607114201.211 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-12-04T20:36:53.246Z,1607114213.246 [NAL9602](INFO): Not Powering down - fast GPS 2020-12-04T20:41:41.850Z,1607114501.850 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-12-04T20:41:41.851Z,1607114501.851 [Default:CheckIn:C.Wait] Stopped 2020-12-04T20:41:41.851Z,1607114501.851 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-12-04T20:41:41.851Z,1607114501.851 [Default:CheckIn:D] Running Loop=1 2020-12-04T20:41:42.244Z,1607114502.244 [Default:CheckIn:D] Stopped 2020-12-04T20:41:42.244Z,1607114502.244 [Default:CheckIn:E] Running Loop=1 2020-12-04T20:41:42.638Z,1607114502.638 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 108.967708 min 2020-12-04T20:41:42.638Z,1607114502.638 [Default:CheckIn:E] Stopped 2020-12-04T20:41:42.638Z,1607114502.638 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-12-04T20:41:42.638Z,1607114502.638 [Default:CheckIn] Stopped 2020-12-04T20:41:42.638Z,1607114502.638 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-12-04T20:41:42.638Z,1607114502.638 [Default:CheckIn](INFO): Running loop #15 2020-12-04T20:41:42.638Z,1607114502.638 [Default:CheckIn] Running Loop=15 2020-12-04T20:41:42.639Z,1607114502.639 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-12-04T20:41:42.639Z,1607114502.639 [Default:CheckIn:Read_GPS] Running Loop=1 2020-12-04T20:41:44.634Z,1607114504.634 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,204143.00,A,3648.12366,N,12147.24834,W,1.419,295.96,041220,,,D*71 2020-12-04T20:41:44.637Z,1607114504.637 [NAL9602](INFO): GPS fix at 20201204T204143: (36.802061, -121.787472) 2020-12-04T20:41:44.658Z,1607114504.658 [Default:CheckIn:Read_GPS] Stopped 2020-12-04T20:41:44.658Z,1607114504.658 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-12-04T20:42:11.310Z,1607114531.310 [NAL9602](INFO): SBD MO Status=2, MOMSN=11714, MT Status=2, MTMSN=0 2020-12-04T20:42:11.310Z,1607114531.310 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2020-12-04T20:42:29.948Z,1607114549.948 [NAL9602](INFO): SBD MO Status=0, MOMSN=11714, MT Status=0, MTMSN=0 2020-12-04T20:42:29.948Z,1607114549.948 [NAL9602](INFO): No messages in MT queue 2020-12-04T20:43:00.706Z,1607114580.706 [NAL9602](INFO): Not Powering down - fast GPS 2020-12-04T20:44:09.587Z,1607114649.587 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20201204T194132/Courier0027.lzma 2020-12-04T20:44:10.590Z,1607114650.590 [DataOverHttps](INFO): Moved sent file to Logs/20201204T194132/Courier0027.lzma.bak 2020-12-04T20:44:10.590Z,1607114650.590 [DataOverHttps](INFO): SBD MOMSN=13397634 2020-12-04T20:44:31.508Z,1607114671.508 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20201204T194132/Express0028.lzma 2020-12-04T20:44:32.510Z,1607114672.510 [DataOverHttps](INFO): Moved sent file to Logs/20201204T194132/Express0028.lzma.bak 2020-12-04T20:44:32.510Z,1607114672.510 [DataOverHttps](INFO): SBD MOMSN=13397637 2020-12-04T20:44:34.105Z,1607114674.105 [Default:CheckIn:Read_Iridium] Stopped 2020-12-04T20:44:34.106Z,1607114674.106 [Default:CheckIn:C.Wait] Running Loop=1 2020-12-04T20:44:34.106Z,1607114674.106 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-12-04T20:48:14.885Z,1607114894.885 [DataOverHttps](IMPORTANT): SBD MTMSN=20201204T204813 2020-12-04T20:48:26.052Z,1607114906.052 [DataOverHttps](INFO): Received command:strobe off 2020-12-04T20:48:26.081Z,1607114906.081 [CommandLine](IMPORTANT): got command strobe off 2020-12-04T20:48:26.081Z,1607114906.081 [CommandLine](IMPORTANT): Deactivating strobe 2020-12-04T20:49:34.850Z,1607114974.850 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-12-04T20:49:34.850Z,1607114974.850 [Default:CheckIn:C.Wait] Stopped 2020-12-04T20:49:34.850Z,1607114974.850 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-12-04T20:49:34.851Z,1607114974.851 [Default:CheckIn:D] Running Loop=1 2020-12-04T20:49:35.248Z,1607114975.248 [Default:CheckIn:D] Stopped 2020-12-04T20:49:35.248Z,1607114975.248 [Default:CheckIn:E] Running Loop=1 2020-12-04T20:49:35.656Z,1607114975.656 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 116.851099 min 2020-12-04T20:49:35.656Z,1607114975.656 [Default:CheckIn:E] Stopped 2020-12-04T20:49:35.656Z,1607114975.656 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-12-04T20:49:35.656Z,1607114975.656 [Default:CheckIn] Stopped 2020-12-04T20:49:35.656Z,1607114975.656 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-12-04T20:49:35.657Z,1607114975.657 [Default:CheckIn](INFO): Running loop #16 2020-12-04T20:49:35.657Z,1607114975.657 [Default:CheckIn] Running Loop=16 2020-12-04T20:49:35.657Z,1607114975.657 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-12-04T20:49:35.657Z,1607114975.657 [Default:CheckIn:Read_GPS] Running Loop=1 2020-12-04T20:49:37.667Z,1607114977.667 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,204936.00,A,3648.16595,N,12147.28398,W,0.680,256.75,041220,,,D*75 2020-12-04T20:49:37.669Z,1607114977.669 [NAL9602](INFO): GPS fix at 20201204T204936: (36.802766, -121.788066) 2020-12-04T20:49:37.680Z,1607114977.680 [Default:CheckIn:Read_GPS] Stopped 2020-12-04T20:49:37.680Z,1607114977.680 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-12-04T20:49:45.759Z,1607114985.759 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20201204T194132/Courier0030.lzma 2020-12-04T20:49:46.762Z,1607114986.762 [DataOverHttps](INFO): Moved sent file to Logs/20201204T194132/Courier0030.lzma.bak 2020-12-04T20:49:46.762Z,1607114986.762 [DataOverHttps](INFO): SBD MOMSN=13397648 2020-12-04T20:50:03.088Z,1607115003.088 [DataOverHttps](INFO): Sending 232 bytes from file Logs/20201204T194132/Express0031.lzma 2020-12-04T20:50:04.090Z,1607115004.090 [DataOverHttps](INFO): Moved sent file to Logs/20201204T194132/Express0031.lzma.bak 2020-12-04T20:50:04.090Z,1607115004.090 [DataOverHttps](INFO): SBD MOMSN=13397651 2020-12-04T20:50:14.854Z,1607115014.854 [NAL9602](INFO): SBD MO Status=2, MOMSN=11715, MT Status=2, MTMSN=0 2020-12-04T20:50:14.854Z,1607115014.854 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2020-12-04T20:50:23.440Z,1607115023.440 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20201204T194132/Express0034.lzma 2020-12-04T20:50:24.442Z,1607115024.442 [DataOverHttps](INFO): Moved sent file to Logs/20201204T194132/Express0034.lzma.bak 2020-12-04T20:50:24.442Z,1607115024.442 [DataOverHttps](INFO): SBD MOMSN=13397657 2020-12-04T20:50:25.787Z,1607115025.787 [Default:CheckIn:Read_Iridium] Stopped 2020-12-04T20:50:25.792Z,1607115025.792 [Default:CheckIn:C.Wait] Running Loop=1 2020-12-04T20:50:25.792Z,1607115025.792 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-12-04T20:54:40.353Z,1607115280.353 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2020-12-04T20:55:11.057Z,1607115311.057 [NAL9602](INFO): Not Powering down - fast GPS 2020-12-04T20:55:26.442Z,1607115326.442 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-12-04T20:55:26.442Z,1607115326.442 [Default:CheckIn:C.Wait] Stopped 2020-12-04T20:55:26.442Z,1607115326.442 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-12-04T20:55:26.443Z,1607115326.443 [Default:CheckIn:D] Running Loop=1 2020-12-04T20:55:26.819Z,1607115326.819 [Default:CheckIn:D] Stopped 2020-12-04T20:55:26.819Z,1607115326.819 [Default:CheckIn:E] Running Loop=1 2020-12-04T20:55:27.228Z,1607115327.228 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 122.710620 min 2020-12-04T20:55:27.228Z,1607115327.228 [Default:CheckIn:E] Stopped 2020-12-04T20:55:27.229Z,1607115327.229 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-12-04T20:55:27.229Z,1607115327.229 [Default:CheckIn] Stopped 2020-12-04T20:55:27.229Z,1607115327.229 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-12-04T20:55:27.229Z,1607115327.229 [Default:CheckIn](INFO): Running loop #17 2020-12-04T20:55:27.229Z,1607115327.229 [Default:CheckIn] Running Loop=17 2020-12-04T20:55:27.229Z,1607115327.229 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-12-04T20:55:27.229Z,1607115327.229 [Default:CheckIn:Read_GPS] Running Loop=1 2020-12-04T20:55:29.239Z,1607115329.239 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,205528.00,A,3648.16548,N,12147.27881,W,0.505,228.56,041220,,,A*78 2020-12-04T20:55:29.251Z,1607115329.251 [NAL9602](INFO): GPS fix at 20201204T205528: (36.802758, -121.787980) 2020-12-04T20:55:29.284Z,1607115329.284 [Default:CheckIn:Read_GPS] Stopped 2020-12-04T20:55:29.284Z,1607115329.284 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-12-04T20:55:41.776Z,1607115341.776 [BPC1](ERROR): BPC1A: No match for serial number 1717 in BPC1A's battery stick inventory (sticks 1-32 in onboard configuration file). 2020-12-04T20:55:59.946Z,1607115359.946 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2020-12-04T20:56:00.024Z,1607115360.024 [NAL9602](FAULT): received: +CSQ:0 OK715, 2, 0, 0, 0 OK 2020-12-04T20:56:00.024Z,1607115360.024 [NAL9602] Data Fault, FailCount= 1 2020-12-04T20:56:00.024Z,1607115360.024 [NAL9602](ERROR): Data Fault 2020-12-04T20:56:00.102Z,1607115360.102 [CBIT](ERROR): Data Fault in component: NAL9602 2020-12-04T20:56:00.345Z,1607115360.345 [NAL9602](INFO): Powering down 2020-12-04T20:56:01.185Z,1607115361.185 [CBIT](INFO): Clearing failed state for component NAL9602 2020-12-04T20:56:01.185Z,1607115361.185 [NAL9602] No Fault, FailCount= 1 2020-12-04T20:56:30.513Z,1607115390.513 [NAL9602](INFO): Powering up NAL9602 2020-12-04T20:56:41.447Z,1607115401.447 [NAL9602](INFO): NAL9602 initialized 2020-12-04T20:57:12.523Z,1607115432.523 [NAL9602](INFO): Not Powering down - fast GPS 2020-12-04T20:57:38.035Z,1607115458.035 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20201204T194132/Courier0036.lzma 2020-12-04T20:57:39.038Z,1607115459.038 [DataOverHttps](INFO): Moved sent file to Logs/20201204T194132/Courier0036.lzma.bak 2020-12-04T20:57:39.038Z,1607115459.038 [DataOverHttps](INFO): SBD MOMSN=13397713 2020-12-04T20:57:55.520Z,1607115475.520 [DataOverHttps](INFO): Sending 232 bytes from file Logs/20201204T194132/Express0037.lzma 2020-12-04T20:57:56.522Z,1607115476.522 [DataOverHttps](INFO): Moved sent file to Logs/20201204T194132/Express0037.lzma.bak 2020-12-04T20:57:56.522Z,1607115476.522 [DataOverHttps](INFO): SBD MOMSN=13397719 2020-12-04T20:57:57.788Z,1607115477.788 [Default:CheckIn:Read_Iridium] Stopped 2020-12-04T20:57:57.788Z,1607115477.788 [Default:CheckIn:C.Wait] Running Loop=1 2020-12-04T20:57:57.788Z,1607115477.788 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-12-04T21:01:05.737Z,1607115665.737 [BPC1](INFO): Calculating totals. Valid battery stick count: 54. Valid reserve battery stick count: 6. 2020-12-04T21:01:05.739Z,1607115665.739 [BPC1](INFO): Received data from all battery sticks. 2020-12-04T21:02:58.443Z,1607115778.443 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-12-04T21:02:58.443Z,1607115778.443 [Default:CheckIn:C.Wait] Stopped 2020-12-04T21:02:58.443Z,1607115778.443 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-12-04T21:02:58.443Z,1607115778.443 [Default:CheckIn:D] Running Loop=1 2020-12-04T21:02:58.857Z,1607115778.857 [Default:CheckIn:D] Stopped 2020-12-04T21:02:58.857Z,1607115778.857 [Default:CheckIn:E] Running Loop=1 2020-12-04T21:02:59.254Z,1607115779.254 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 130.244596 min 2020-12-04T21:02:59.254Z,1607115779.254 [Default:CheckIn:E] Stopped 2020-12-04T21:02:59.255Z,1607115779.255 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-12-04T21:02:59.255Z,1607115779.255 [Default:CheckIn] Stopped 2020-12-04T21:02:59.255Z,1607115779.255 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-12-04T21:02:59.255Z,1607115779.255 [Default:CheckIn](INFO): Running loop #18 2020-12-04T21:02:59.255Z,1607115779.255 [Default:CheckIn] Running Loop=18 2020-12-04T21:02:59.255Z,1607115779.255 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-12-04T21:02:59.255Z,1607115779.255 [Default:CheckIn:Read_GPS] Running Loop=1 2020-12-04T21:03:02.873Z,1607115782.873 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2020-12-04T21:07:59.557Z,1607116079.557 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-12-04T21:02:59.3Z 2020-12-04T21:07:59.557Z,1607116079.557 [Default:CheckIn:Read_GPS] Stopped 2020-12-04T21:07:59.557Z,1607116079.557 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-12-04T21:08:31.495Z,1607116111.495 [NAL9602](INFO): Not Powering down - fast GPS 2020-12-04T21:10:57.919Z,1607116257.919 [DataOverHttps](INFO): Sending 50 bytes from file Logs/20201204T194132/Courier0039.lzma 2020-12-04T21:10:58.922Z,1607116258.922 [DataOverHttps](INFO): Moved sent file to Logs/20201204T194132/Courier0039.lzma.bak 2020-12-04T21:10:58.922Z,1607116258.922 [DataOverHttps](INFO): SBD MOMSN=13397784 2020-12-04T21:11:15.028Z,1607116275.028 [DataOverHttps](INFO): Sending 247 bytes from file Logs/20201204T194132/Express0040.lzma 2020-12-04T21:11:16.030Z,1607116276.030 [DataOverHttps](INFO): Moved sent file to Logs/20201204T194132/Express0040.lzma.bak 2020-12-04T21:11:16.030Z,1607116276.030 [DataOverHttps](INFO): SBD MOMSN=13397791 2020-12-04T21:11:17.334Z,1607116277.334 [Default:CheckIn:Read_Iridium] Stopped 2020-12-04T21:11:17.335Z,1607116277.335 [Default:CheckIn:C.Wait] Running Loop=1 2020-12-04T21:11:17.335Z,1607116277.335 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-12-04T21:16:18.038Z,1607116578.038 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-12-04T21:16:18.038Z,1607116578.038 [Default:CheckIn:C.Wait] Stopped 2020-12-04T21:16:18.038Z,1607116578.038 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-12-04T21:16:18.038Z,1607116578.038 [Default:CheckIn:D] Running Loop=1 2020-12-04T21:16:18.454Z,1607116578.454 [Default:CheckIn:D] Stopped 2020-12-04T21:16:18.454Z,1607116578.454 [Default:CheckIn:E] Running Loop=1 2020-12-04T21:16:18.831Z,1607116578.831 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 143.571208 min 2020-12-04T21:16:18.831Z,1607116578.831 [Default:CheckIn:E] Stopped 2020-12-04T21:16:18.852Z,1607116578.852 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-12-04T21:16:18.852Z,1607116578.852 [Default:CheckIn] Stopped 2020-12-04T21:16:18.852Z,1607116578.852 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-12-04T21:16:18.852Z,1607116578.852 [Default:CheckIn](INFO): Running loop #19 2020-12-04T21:16:18.852Z,1607116578.852 [Default:CheckIn] Running Loop=19 2020-12-04T21:16:18.852Z,1607116578.852 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-12-04T21:16:18.853Z,1607116578.853 [Default:CheckIn:Read_GPS] Running Loop=1 2020-12-04T21:16:20.433Z,1607116580.433 [NAL9602](FAULT): GPS failed to acquire within timeout. 2020-12-04T21:16:20.433Z,1607116580.433 [NAL9602] Data Fault, FailCount= 1 2020-12-04T21:16:20.433Z,1607116580.433 [NAL9602](ERROR): Data Fault 2020-12-04T21:16:20.517Z,1607116580.517 [CBIT](ERROR): Data Fault in component: NAL9602 2020-12-04T21:16:20.849Z,1607116580.849 [NAL9602](INFO): Powering down 2020-12-04T21:16:21.722Z,1607116581.722 [CBIT](INFO): Clearing failed state for component NAL9602 2020-12-04T21:16:21.722Z,1607116581.722 [NAL9602] No Fault, FailCount= 1 2020-12-04T21:16:51.145Z,1607116611.145 [NAL9602](INFO): Powering up NAL9602 2020-12-04T21:17:02.049Z,1607116622.049 [NAL9602](INFO): NAL9602 initialized 2020-12-04T21:21:19.118Z,1607116879.118 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-12-04T21:16:18.9Z 2020-12-04T21:21:19.118Z,1607116879.118 [Default:CheckIn:Read_GPS] Stopped 2020-12-04T21:21:19.118Z,1607116879.118 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-12-04T21:22:05.163Z,1607116925.163 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2020-12-04T21:22:35.927Z,1607116955.927 [NAL9602](INFO): Not Powering down - fast GPS 2020-12-04T21:24:19.119Z,1607117059.119 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20201204T194132/Courier0042.lzma 2020-12-04T21:24:20.122Z,1607117060.122 [DataOverHttps](INFO): Moved sent file to Logs/20201204T194132/Courier0042.lzma.bak 2020-12-04T21:24:20.122Z,1607117060.122 [DataOverHttps](INFO): SBD MOMSN=13397858 2020-12-04T21:24:42.515Z,1607117082.515 [DataOverHttps](INFO): Sending 170 bytes from file Logs/20201204T194132/Express0043.lzma 2020-12-04T21:24:43.518Z,1607117083.518 [DataOverHttps](INFO): Moved sent file to Logs/20201204T194132/Express0043.lzma.bak 2020-12-04T21:24:43.518Z,1607117083.518 [DataOverHttps](INFO): SBD MOMSN=13397868 2020-12-04T21:24:44.980Z,1607117084.980 [Default:CheckIn:Read_Iridium] Stopped 2020-12-04T21:24:44.980Z,1607117084.980 [Default:CheckIn:C.Wait] Running Loop=1 2020-12-04T21:24:44.980Z,1607117084.980 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-12-04T21:29:45.615Z,1607117385.615 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-12-04T21:29:45.615Z,1607117385.615 [Default:CheckIn:C.Wait] Stopped 2020-12-04T21:29:45.615Z,1607117385.615 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-12-04T21:29:45.616Z,1607117385.616 [Default:CheckIn:D] Running Loop=1 2020-12-04T21:29:46.025Z,1607117386.025 [Default:CheckIn:D] Stopped 2020-12-04T21:29:46.025Z,1607117386.025 [Default:CheckIn:E] Running Loop=1 2020-12-04T21:29:46.439Z,1607117386.439 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 157.030729 min 2020-12-04T21:29:46.439Z,1607117386.439 [Default:CheckIn:E] Stopped 2020-12-04T21:29:46.439Z,1607117386.439 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-12-04T21:29:46.439Z,1607117386.439 [Default:CheckIn] Stopped 2020-12-04T21:29:46.439Z,1607117386.439 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-12-04T21:29:46.439Z,1607117386.439 [Default:CheckIn](INFO): Running loop #20 2020-12-04T21:29:46.439Z,1607117386.439 [Default:CheckIn] Running Loop=20 2020-12-04T21:29:46.439Z,1607117386.439 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-12-04T21:29:46.439Z,1607117386.439 [Default:CheckIn:Read_GPS] Running Loop=1 2020-12-04T21:29:48.025Z,1607117388.025 [NAL9602](FAULT): GPS failed to acquire within timeout. 2020-12-04T21:29:48.025Z,1607117388.025 [NAL9602] Data Fault, FailCount= 2 2020-12-04T21:29:48.025Z,1607117388.025 [NAL9602](ERROR): Data Fault 2020-12-04T21:29:48.079Z,1607117388.079 [CBIT](ERROR): Data Fault in component: NAL9602 2020-12-04T21:29:48.433Z,1607117388.433 [NAL9602](INFO): Powering down 2020-12-04T21:29:49.278Z,1607117389.278 [CBIT](INFO): Clearing failed state for component NAL9602 2020-12-04T21:29:49.278Z,1607117389.278 [NAL9602] No Fault, FailCount= 2 2020-12-04T21:30:18.727Z,1607117418.727 [NAL9602](INFO): Powering up NAL9602 2020-12-04T21:30:29.639Z,1607117429.639 [NAL9602](INFO): NAL9602 initialized 2020-12-04T21:34:46.736Z,1607117686.736 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-12-04T21:29:46.4Z 2020-12-04T21:34:46.736Z,1607117686.736 [Default:CheckIn:Read_GPS] Stopped 2020-12-04T21:34:46.737Z,1607117686.737 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-12-04T21:34:55.111Z,1607117695.111 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20201204T194132/Courier0045.lzma 2020-12-04T21:34:56.114Z,1607117696.114 [DataOverHttps](INFO): Moved sent file to Logs/20201204T194132/Courier0045.lzma.bak 2020-12-04T21:34:56.114Z,1607117696.114 [DataOverHttps](INFO): SBD MOMSN=13397891 2020-12-04T21:35:32.757Z,1607117732.757 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2020-12-04T21:36:03.457Z,1607117763.457 [NAL9602](INFO): Not Powering down - fast GPS 2020-12-04T21:37:46.148Z,1607117866.148 [DataOverHttps](INFO): Sending 224 bytes from file Logs/20201204T194132/Express0046.lzma 2020-12-04T21:37:47.150Z,1607117867.150 [DataOverHttps](INFO): Moved sent file to Logs/20201204T194132/Express0046.lzma.bak 2020-12-04T21:37:47.150Z,1607117867.150 [DataOverHttps](INFO): SBD MOMSN=13397930 2020-12-04T21:37:48.651Z,1607117868.651 [Default:CheckIn:Read_Iridium] Stopped 2020-12-04T21:37:48.652Z,1607117868.652 [Default:CheckIn:C.Wait] Running Loop=1 2020-12-04T21:37:48.653Z,1607117868.653 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-12-04T21:42:49.309Z,1607118169.309 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-12-04T21:42:49.310Z,1607118169.310 [Default:CheckIn:C.Wait] Stopped 2020-12-04T21:42:49.310Z,1607118169.310 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-12-04T21:42:49.310Z,1607118169.310 [Default:CheckIn:D] Running Loop=1 2020-12-04T21:42:49.686Z,1607118169.686 [Default:CheckIn:D] Stopped 2020-12-04T21:42:49.686Z,1607118169.686 [Default:CheckIn:E] Running Loop=1 2020-12-04T21:42:50.093Z,1607118170.093 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 170.091748 min 2020-12-04T21:42:50.093Z,1607118170.093 [Default:CheckIn:E] Stopped 2020-12-04T21:42:50.093Z,1607118170.093 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-12-04T21:42:50.093Z,1607118170.093 [Default:CheckIn] Stopped 2020-12-04T21:42:50.093Z,1607118170.093 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-12-04T21:42:50.093Z,1607118170.093 [Default:CheckIn](INFO): Running loop #21 2020-12-04T21:42:50.093Z,1607118170.093 [Default:CheckIn] Running Loop=21 2020-12-04T21:42:50.093Z,1607118170.093 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-12-04T21:42:50.093Z,1607118170.093 [Default:CheckIn:Read_GPS] Running Loop=1 2020-12-04T21:42:51.684Z,1607118171.684 [NAL9602](FAULT): GPS failed to acquire within timeout. 2020-12-04T21:42:51.684Z,1607118171.684 [NAL9602] Data Fault, FailCount= 3 2020-12-04T21:42:51.684Z,1607118171.684 [NAL9602](ERROR): Data Fault 2020-12-04T21:42:51.726Z,1607118171.726 [CBIT](ERROR): Data Fault in component: NAL9602 2020-12-04T21:42:52.087Z,1607118172.087 [NAL9602](INFO): Powering down 2020-12-04T21:42:52.501Z,1607118172.501 [NAL9602](FAULT): LCB fault: Software Overcurrent. 2020-12-04T21:42:52.501Z,1607118172.501 [NAL9602] Hardware Fault, FailCount= 3 2020-12-04T21:42:52.501Z,1607118172.501 [NAL9602](ERROR): Hardware Fault 2020-12-04T21:42:52.921Z,1607118172.921 [CBIT](INFO): Clearing failed state for component NAL9602 2020-12-04T21:42:52.921Z,1607118172.921 [NAL9602] No Fault, FailCount= 3 2020-12-04T21:43:22.389Z,1607118202.389 [NAL9602](INFO): Powering up NAL9602 2020-12-04T21:43:33.326Z,1607118213.326 [NAL9602](INFO): NAL9602 initialized 2020-12-04T21:47:50.349Z,1607118470.349 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-12-04T21:42:50.1Z 2020-12-04T21:47:50.349Z,1607118470.349 [Default:CheckIn:Read_GPS] Stopped 2020-12-04T21:47:50.349Z,1607118470.349 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-12-04T21:48:06.367Z,1607118486.367 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20201204T194132/Courier0048.lzma 2020-12-04T21:48:07.370Z,1607118487.370 [DataOverHttps](INFO): Moved sent file to Logs/20201204T194132/Courier0048.lzma.bak 2020-12-04T21:48:07.370Z,1607118487.370 [DataOverHttps](INFO): SBD MOMSN=13397948 2020-12-04T21:48:36.497Z,1607118516.497 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2020-12-04T21:49:07.217Z,1607118547.217 [NAL9602](INFO): Not Powering down - fast GPS 2020-12-04T21:50:14.326Z,1607118614.326 [RDI_Pathfinder](ERROR): only read 2 of 4 data items 2020-12-04T21:51:20.905Z,1607118680.905 [DataOverHttps](INFO): Sending 256 bytes from file Logs/20201204T194132/Express0049.lzma 2020-12-04T21:51:21.931Z,1607118681.931 [DataOverHttps](INFO): Moved sent file to Logs/20201204T194132/Express0049.lzma.bak 2020-12-04T21:51:21.931Z,1607118681.931 [DataOverHttps](INFO): SBD MOMSN=13397999 2020-12-04T21:51:23.097Z,1607118683.097 [Default:CheckIn:Read_Iridium] Stopped 2020-12-04T21:51:23.098Z,1607118683.098 [Default:CheckIn:C.Wait] Running Loop=1 2020-12-04T21:51:23.098Z,1607118683.098 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-12-04T21:56:23.735Z,1607118983.735 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-12-04T21:56:23.735Z,1607118983.735 [Default:CheckIn:C.Wait] Stopped 2020-12-04T21:56:23.735Z,1607118983.735 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-12-04T21:56:23.735Z,1607118983.735 [Default:CheckIn:D] Running Loop=1 2020-12-04T21:56:24.133Z,1607118984.133 [Default:CheckIn:D] Stopped 2020-12-04T21:56:24.133Z,1607118984.133 [Default:CheckIn:E] Running Loop=1 2020-12-04T21:56:24.559Z,1607118984.559 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 183.665869 min 2020-12-04T21:56:24.559Z,1607118984.559 [Default:CheckIn:E] Stopped 2020-12-04T21:56:24.559Z,1607118984.559 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-12-04T21:56:24.559Z,1607118984.559 [Default:CheckIn] Stopped 2020-12-04T21:56:24.559Z,1607118984.559 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-12-04T21:56:24.559Z,1607118984.559 [Default:CheckIn](INFO): Running loop #22 2020-12-04T21:56:24.559Z,1607118984.559 [Default:CheckIn] Running Loop=22 2020-12-04T21:56:24.559Z,1607118984.559 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-12-04T21:56:24.560Z,1607118984.560 [Default:CheckIn:Read_GPS] Running Loop=1 2020-12-04T21:56:26.149Z,1607118986.149 [NAL9602](FAULT): GPS failed to acquire within timeout. 2020-12-04T21:56:26.149Z,1607118986.149 [NAL9602] Data Fault, FailCount= 4 2020-12-04T21:56:26.149Z,1607118986.149 [NAL9602](ERROR): Data Fault 2020-12-04T21:56:26.169Z,1607118986.169 [CBIT](ERROR): Data Fault in component: NAL9602 2020-12-04T21:56:26.549Z,1607118986.549 [NAL9602](INFO): Powering down 2020-12-04T21:56:27.423Z,1607118987.423 [CBIT](INFO): Clearing failed state for component NAL9602 2020-12-04T21:56:27.423Z,1607118987.423 [NAL9602] No Fault, FailCount= 4 2020-12-04T21:56:56.847Z,1607119016.847 [NAL9602](INFO): Powering up NAL9602 2020-12-04T21:57:07.761Z,1607119027.761 [NAL9602](INFO): NAL9602 initialized 2020-12-04T21:58:26.659Z,1607119106.659 [CBIT](CRITICAL): run-time exception #7 2020-12-04T21:58:26.659Z,1607119106.659 [CBIT](CRITICAL): Bad address: 0x4041E008 2020-12-04T21:58:26.659Z,1607119106.659 [CBIT](CRITICAL): Backtrace: ./bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x17ddd4] ./bin/LRAUV(_ZN7PCaller10PThreadRunEPv+0xc8) [0x17d920] 2020-12-04T21:58:26.659Z,1607119106.659 [CBIT] Software Fault, FailCount= 1 2020-12-04T21:58:26.659Z,1607119106.659 [CBIT](ERROR): Software Fault 2020-12-04T21:58:26.677Z,1607119106.677 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2020-12-04T21:58:26.677Z,1607119106.677 [SyncHandler](INFO): Protected caller Thread ID is 5986 2020-12-04T21:58:27.009Z,1607119107.009 [CBIT](DEBUG): Uninitialize CBIT Component. 2020-12-04T21:58:27.009Z,1607119107.009 [CBIT](DEBUG): Powering off loads. 2020-12-04T21:58:27.020Z,1607119107.020 [CBIT](DEBUG): Disabling WDT. 2020-12-04T21:58:27.044Z,1607119107.044 [CBIT](DEBUG): Opening all GF detection circuits. 2020-12-04T21:58:37.084Z,1607119117.084 [AHRS_M2](FAULT): Failed to acquire valid data within timeout. 2020-12-04T21:58:37.084Z,1607119117.084 [AHRS_M2] Data Fault, FailCount= 1 2020-12-04T21:58:37.084Z,1607119117.084 [AHRS_M2](ERROR): Data Fault 2020-12-04T21:58:37.101Z,1607119117.101 [RDI_Pathfinder](ERROR): No DVL communication! Re-initializing 2020-12-04T21:58:37.101Z,1607119117.101 [RDI_Pathfinder] Communications Fault, FailCount= 1 2020-12-04T21:58:37.101Z,1607119117.101 [RDI_Pathfinder](ERROR): Communications Fault 2020-12-04T21:58:37.468Z,1607119117.468 [AHRS_M2](INFO): Powering down 2020-12-04T21:58:37.620Z,1607119117.620 [RDI_Pathfinder](INFO): Powering down 2020-12-04T21:58:39.091Z,1607119119.091 [DAT](INFO): commRate: 800 2020-12-04T21:58:55.249Z,1607119135.249 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2020-12-04T21:58:55.768Z,1607119135.768 [NAL9602](FAULT): received: 2020-12-04T21:58:55.768Z,1607119135.768 [NAL9602] Data Fault, FailCount= 5 2020-12-04T21:58:55.768Z,1607119135.768 [NAL9602](ERROR): Data Fault 2020-12-04T21:58:55.874Z,1607119135.874 [NAL9602](INFO): Powering down 2020-12-04T21:59:01.876Z,1607119141.876 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2020-12-04T21:59:03.884Z,1607119143.884 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.259109 2020-12-04T21:59:37.032Z,1607119177.032 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2020-12-04T22:00:12.172Z,1607119212.172 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2020-12-04T22:00:36.828Z,1607119236.828 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2020-12-04T22:00:36.828Z,1607119236.828 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2020-12-04T22:00:36.828Z,1607119236.828 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-12-04T22:00:47.312Z,1607119247.312 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2020-12-04T22:01:02.297Z,1607119262.297 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003858 2020-12-04T22:01:24.568Z,1607119284.568 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-12-04T21:56:24.6Z 2020-12-04T22:01:24.568Z,1607119284.568 [Default:CheckIn:Read_GPS] Stopped 2020-12-04T22:01:24.568Z,1607119284.568 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-12-04T22:02:12.469Z,1607119332.469 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2020-12-04T22:02:12.514Z,1607119332.514 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2020-12-04T22:02:23.572Z,1607119343.572 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2020-12-04T22:02:23.838Z,1607119343.838 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2020-12-04T22:02:33.792Z,1607119353.792 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2020-12-04T22:02:35.058Z,1607119355.058 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2020-12-04T22:02:44.690Z,1607119364.690 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2020-12-04T22:02:45.983Z,1607119365.983 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2020-12-04T22:02:55.669Z,1607119375.669 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2020-12-04T22:02:56.876Z,1607119376.876 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2020-12-04T22:03:07.082Z,1607119387.082 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2020-12-04T22:03:08.273Z,1607119388.273 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2020-12-04T22:03:18.432Z,1607119398.432 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2020-12-04T22:03:19.194Z,1607119399.194 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2020-12-04T22:03:29.723Z,1607119409.723 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2020-12-04T22:03:30.526Z,1607119410.526 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2020-12-04T22:03:40.639Z,1607119420.639 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2020-12-04T22:03:41.475Z,1607119421.475 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2020-12-04T22:03:51.507Z,1607119431.507 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2020-12-04T22:03:52.322Z,1607119432.322 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2020-12-04T22:04:02.442Z,1607119442.442 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2020-12-04T22:04:03.582Z,1607119443.582 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2020-12-04T22:04:13.320Z,1607119453.320 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2020-12-04T22:04:14.485Z,1607119454.485 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2020-12-04T22:04:24.276Z,1607119464.276 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2020-12-04T22:04:25.484Z,1607119465.484 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2020-12-04T22:04:41.738Z,1607119481.738 [CommandLine](IMPORTANT): got command quit 2020-12-04T22:04:42.744Z,1607119482.744 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2020-12-04T22:04:42.744Z,1607119482.744 [CommandLine ThreadHandler](INFO): Thread cancelled. 2020-12-04T22:04:42.884Z,1607119482.884 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2020-12-04T22:04:42.884Z,1607119482.884 [CommandLine ThreadHandler](INFO): Thread cancelled. 2020-12-04T22:04:42.885Z,1607119482.885 [CommandLine](INFO): Join timeout helper Thread ID is 8093 2020-12-04T22:04:42.892Z,1607119482.892 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2020-12-04T22:04:42.892Z,1607119482.892 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2020-12-04T22:04:42.892Z,1607119482.892 [NavChartDb](INFO): Join timeout helper Thread ID is 8094 2020-12-04T22:04:42.928Z,1607119482.928 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2020-12-04T22:04:42.928Z,1607119482.928 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2020-12-04T22:04:42.932Z,1607119482.932 [ComponentRegistry](INFO): Shutting down WetLabsUBAT ThreadHandler 2020-12-04T22:04:42.932Z,1607119482.932 [WetLabsUBAT ThreadHandler](INFO): Thread cancelled. 2020-12-04T22:04:42.932Z,1607119482.932 [WetLabsUBAT](INFO): Join timeout helper Thread ID is 8095 2020-12-04T22:04:43.156Z,1607119483.156 [WetLabsUBAT ThreadHandler](INFO): Uninitializing protected caller thread. 2020-12-04T22:04:43.156Z,1607119483.156 [WetLabsUBAT](INFO): Powering down 2020-12-04T22:04:43.157Z,1607119483.157 [WetLabsUBAT ThreadHandler](INFO): Thread cancelled. 2020-12-04T22:04:43.176Z,1607119483.176 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2020-12-04T22:04:43.176Z,1607119483.176 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2020-12-04T22:04:43.176Z,1607119483.176 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 8098 2020-12-04T22:04:43.653Z,1607119483.653 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2020-12-04T22:04:43.653Z,1607119483.653 [WetLabsBB2FL](INFO): Powering down 2020-12-04T22:04:43.654Z,1607119483.654 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2020-12-04T22:04:43.656Z,1607119483.656 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2020-12-04T22:04:43.656Z,1607119483.656 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2020-12-04T22:04:43.656Z,1607119483.656 [CTD_Seabird](INFO): Join timeout helper Thread ID is 8101 2020-12-04T22:04:44.156Z,1607119484.156 [CTD_Seabird](INFO): Powering down 2020-12-04T22:04:44.168Z,1607119484.168 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread. 2020-12-04T22:04:44.168Z,1607119484.168 [CTD_Seabird](INFO): Powering down 2020-12-04T22:04:44.180Z,1607119484.180 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2020-12-04T22:04:44.197Z,1607119484.197 [ComponentRegistry](INFO): Shutting down BackSeatDriver ThreadHandler 2020-12-04T22:04:44.197Z,1607119484.197 [BackSeatDriver ThreadHandler](INFO): Thread cancelled. 2020-12-04T22:04:44.197Z,1607119484.197 [BackSeatDriver](INFO): Join timeout helper Thread ID is 8106 2020-12-04T22:04:44.388Z,1607119484.388 [BackSeatDriver ThreadHandler](INFO): Uninitializing protected caller thread. 2020-12-04T22:04:44.388Z,1607119484.388 [BackSeatDriver ThreadHandler](INFO): Thread cancelled. 2020-12-04T22:04:44.401Z,1607119484.401 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2020-12-04T22:04:44.401Z,1607119484.401 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2020-12-04T22:04:44.401Z,1607119484.401 [Radio_Surface](INFO): Join timeout helper Thread ID is 8107 2020-12-04T22:04:44.401Z,1607119484.401 [Radio_Surface](INFO): Powering down 2020-12-04T22:04:44.402Z,1607119484.402 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2020-12-04T22:04:44.403Z,1607119484.403 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2020-12-04T22:04:44.404Z,1607119484.404 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler 2020-12-04T22:04:44.404Z,1607119484.404 [Onboard ThreadHandler](INFO): Thread cancelled. 2020-12-04T22:04:44.405Z,1607119484.405 [Onboard](INFO): Join timeout helper Thread ID is 8108 2020-12-04T22:04:45.064Z,1607119485.064 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread. 2020-12-04T22:04:45.064Z,1607119485.064 [Onboard ThreadHandler](INFO): Thread cancelled. 2020-12-04T22:04:45.085Z,1607119485.085 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2020-12-04T22:04:45.085Z,1607119485.085 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2020-12-04T22:04:45.085Z,1607119485.085 [DataOverHttps](INFO): Join timeout helper Thread ID is 8113 2020-12-04T22:04:48.286Z,1607119488.286 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2020-12-04T22:04:48.290Z,1607119488.290 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2020-12-04T22:04:48.293Z,1607119488.293 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2020-12-04T22:04:48.293Z,1607119488.293 [logger ThreadHandler](INFO): Thread cancelled. 2020-12-04T22:04:48.293Z,1607119488.293 [logger](INFO): Join timeout helper Thread ID is 8132 2020-12-04T22:04:48.328Z,1607119488.328 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2020-12-04T22:04:48.328Z,1607119488.328 [logger ThreadHandler](INFO): Thread cancelled. 2020-12-04T22:04:48.333Z,1607119488.333 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2020-12-04T22:04:48.333Z,1607119488.333 [CommandLine ThreadHandler](INFO): Thread cancelled. 2020-12-04T22:04:48.333Z,1607119488.333 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2020-12-04T22:04:48.333Z,1607119488.333 [controlThread ThreadHandler](INFO): Thread cancelled. 2020-12-04T22:04:48.333Z,1607119488.333 [controlThread](INFO): Join timeout helper Thread ID is 8133 2020-12-04T22:04:48.341Z,1607119488.341 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2020-12-04T22:04:48.341Z,1607119488.341 [controlThread](DEBUG): Uninitializing ControlThread 2020-12-04T22:04:48.341Z,1607119488.341 [AHRS_M2](INFO): Powering down 2020-12-04T22:04:48.342Z,1607119488.342 [NAL9602](INFO): Powering down 2020-12-04T22:04:48.343Z,1607119488.343 [RDI_Pathfinder](INFO): Powering down 2020-12-04T22:04:48.344Z,1607119488.344 [DAT](INFO): Powering down 2020-12-04T22:04:48.465Z,1607119488.465 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2020-12-04T22:04:48.466Z,1607119488.466 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2020-12-04T22:04:48.466Z,1607119488.466 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2020-12-04T22:04:48.467Z,1607119488.467 [MissionManager](INFO): Uninitializing Mission Default 2020-12-04T22:04:48.467Z,1607119488.467 [Default] Stopped 2020-12-04T22:04:48.467Z,1607119488.467 [Default](DEBUG): Aggregate::uninitialize Default 2020-12-04T22:04:48.467Z,1607119488.467 [Default:B.GoToSurface] Stopped 2020-12-04T22:04:48.467Z,1607119488.467 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2020-12-04T22:04:48.467Z,1607119488.467 [Default:CheckIn] Stopped 2020-12-04T22:04:48.467Z,1607119488.467 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-12-04T22:04:48.467Z,1607119488.467 [Default:CheckIn:Read_Iridium] Stopped 2020-12-04T22:04:48.498Z,1607119488.498 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2020-12-04T22:04:48.498Z,1607119488.498 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2020-12-04T22:04:48.498Z,1607119488.498 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2020-12-04T22:04:48.499Z,1607119488.499 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2020-12-04T22:04:48.499Z,1607119488.499 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2020-12-04T22:04:48.499Z,1607119488.499 [BuoyancyServo](INFO): Powering down 2020-12-04T22:04:48.512Z,1607119488.512 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2020-12-04T22:04:48.512Z,1607119488.512 [ElevatorServo](INFO): Powering down 2020-12-04T22:04:48.513Z,1607119488.513 [MassServo](DEBUG): Uninitialize Mass Servo. 2020-12-04T22:04:48.513Z,1607119488.513 [MassServo](INFO): Powering down 2020-12-04T22:04:48.514Z,1607119488.514 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2020-12-04T22:04:48.514Z,1607119488.514 [RudderServo](INFO): Powering down 2020-12-04T22:04:48.515Z,1607119488.515 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2020-12-04T22:04:48.515Z,1607119488.515 [ThrusterServo](INFO): Powering down 2020-12-04T22:04:48.515Z,1607119488.515 [SBIT](DEBUG): Uninitialize SBIT Component. 2020-12-04T22:04:48.516Z,1607119488.516 [IBIT](DEBUG): Uninitialize IBIT Component. 2020-12-04T22:04:48.516Z,1607119488.516 [CBIT](DEBUG): Uninitialize CBIT Component. 2020-12-04T22:04:48.516Z,1607119488.516 [CBIT](DEBUG): Powering off loads. 2020-12-04T22:04:48.528Z,1607119488.528 [CBIT](DEBUG): Disabling WDT. 2020-12-04T22:04:48.540Z,1607119488.540 [CBIT](DEBUG): Opening all GF detection circuits. 2020-12-04T22:04:48.541Z,1607119488.541 [controlThread ThreadHandler](INFO): Thread cancelled. 2020-12-04T22:04:48.632Z,1607119488.632 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2020-12-04T22:04:48.634Z,1607119488.634 [Onboard ThreadHandler](INFO): Thread cancelled. 2020-12-04T22:04:48.639Z,1607119488.639 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2020-12-04T22:04:48.699Z,1607119488.699 [WetLabsUBAT ThreadHandler](INFO): Thread cancelled. 2020-12-04T22:04:48.700Z,1607119488.700 [WetLabsUBAT](INFO): WetLabs destructor: dataLog is open - close it 2020-12-04T22:04:48.700Z,1607119488.700 [WetLabsUBAT](INFO): WetLabs destructor: done 2020-12-04T22:04:48.752Z,1607119488.752 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2020-12-04T22:04:48.755Z,1607119488.755 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2020-12-04T22:04:48.759Z,1607119488.759 [BackSeatDriver ThreadHandler](INFO): Thread cancelled. 2020-12-04T22:04:48.769Z,1607119488.769 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2020-12-04T22:04:48.914Z,1607119488.914 [logger ThreadHandler](INFO): Thread cancelled.