2021-12-06T23:56:08.158Z,1638834968.158 [Supervisor](DEBUG): Initializing supervisor. 2021-12-06T23:56:08.164Z,1638834968.164 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2021-12-06T23:56:08.165Z,1638834968.165 [SyncHandler](INFO): Protected caller Thread ID is 1686 2021-12-06T23:56:08.165Z,1638834968.165 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2021-12-06T23:56:08.166Z,1638834968.166 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2021-12-06T23:56:08.166Z,1638834968.166 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 1687 2021-12-06T23:56:08.171Z,1638834968.171 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2021-12-06T23:56:08.190Z,1638834968.190 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread. 2021-12-06T23:56:08.191Z,1638834968.191 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2021-12-06T23:56:08.191Z,1638834968.191 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 1688 2021-12-06T23:56:08.195Z,1638834968.195 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2021-12-06T23:56:08.196Z,1638834968.196 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2021-12-06T23:56:08.197Z,1638834968.197 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 1689 2021-12-06T23:56:08.199Z,1638834968.199 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2021-12-06T23:56:08.200Z,1638834968.200 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0 2021-12-06T23:56:08.200Z,1638834968.200 [logger ThreadHandler](INFO): Protected caller Thread ID is 1690 2021-12-06T23:56:08.204Z,1638834968.204 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2021-12-06T23:56:08.205Z,1638834968.205 [Supervisor](INFO): Looking for Config files in directory: Config/ 2021-12-06T23:56:08.206Z,1638834968.206 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2021-12-06T23:56:08.370Z,1638834968.370 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2021-12-06T23:56:08.370Z,1638834968.370 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg 2021-12-06T23:56:08.577Z,1638834968.577 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock 2021-12-06T23:56:08.577Z,1638834968.577 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2021-12-06T23:56:08.799Z,1638834968.799 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2021-12-06T23:56:08.800Z,1638834968.800 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2021-12-06T23:56:08.908Z,1638834968.908 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2021-12-06T23:56:08.908Z,1638834968.908 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2021-12-06T23:56:09.546Z,1638834969.546 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2021-12-06T23:56:09.546Z,1638834969.546 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2021-12-06T23:56:09.985Z,1638834969.985 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2021-12-06T23:56:09.985Z,1638834969.985 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2021-12-06T23:56:10.513Z,1638834970.513 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2021-12-06T23:56:10.513Z,1638834970.513 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2021-12-06T23:56:10.877Z,1638834970.877 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2021-12-06T23:56:10.878Z,1638834970.878 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2021-12-06T23:56:11.200Z,1638834971.200 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2021-12-06T23:56:11.201Z,1638834971.201 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2021-12-06T23:56:11.557Z,1638834971.557 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2021-12-06T23:56:11.558Z,1638834971.558 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2021-12-06T23:56:11.707Z,1638834971.707 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2021-12-06T23:56:11.708Z,1638834971.708 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2021-12-06T23:56:11.837Z,1638834971.837 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2021-12-06T23:56:11.838Z,1638834971.838 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2021-12-06T23:56:11.920Z,1638834971.920 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2021-12-06T23:56:12.002Z,1638834972.001 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2021-12-06T23:56:12.188Z,1638834972.188 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2021-12-06T23:56:12.189Z,1638834972.189 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2021-12-06T23:56:12.471Z,1638834972.471 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2021-12-06T23:56:12.473Z,1638834972.473 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/ 2021-12-06T23:56:12.559Z,1638834972.559 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg 2021-12-06T23:56:12.644Z,1638834972.644 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg 2021-12-06T23:56:12.901Z,1638834972.901 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2021-12-06T23:56:12.901Z,1638834972.901 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg 2021-12-06T23:56:12.999Z,1638834972.999 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg 2021-12-06T23:56:13.167Z,1638834973.167 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg 2021-12-06T23:56:13.713Z,1638834973.713 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg 2021-12-06T23:56:14.202Z,1638834974.202 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg 2021-12-06T23:56:14.358Z,1638834974.358 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg 2021-12-06T23:56:14.459Z,1638834974.459 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg 2021-12-06T23:56:14.616Z,1638834974.616 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg 2021-12-06T23:56:14.719Z,1638834974.719 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg 2021-12-06T23:56:14.820Z,1638834974.820 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/root/ 2021-12-06T23:56:14.820Z,1638834974.820 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2021-12-06T23:56:14.828Z,1638834974.828 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2021-12-06T23:56:14.955Z,1638834974.955 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2021-12-06T23:56:14.956Z,1638834974.956 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2021-12-06T23:56:15.126Z,1638834975.126 [BuoyancyServo] Loaded 2021-12-06T23:56:15.126Z,1638834975.126 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2021-12-06T23:56:15.146Z,1638834975.146 [MassServo] Loaded 2021-12-06T23:56:15.146Z,1638834975.146 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2021-12-06T23:56:15.147Z,1638834975.147 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2021-12-06T23:56:15.147Z,1638834975.147 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2021-12-06T23:56:15.313Z,1638834975.313 [SBIT](DEBUG): Construct Startup Built In Test. 2021-12-06T23:56:15.328Z,1638834975.328 [SBIT] Loaded 2021-12-06T23:56:15.328Z,1638834975.328 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2021-12-06T23:56:15.331Z,1638834975.331 [IBIT](DEBUG): Construct Initiated Built In Test. 2021-12-06T23:56:15.352Z,1638834975.352 [IBIT] Loaded 2021-12-06T23:56:15.352Z,1638834975.352 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2021-12-06T23:56:15.358Z,1638834975.358 [CBIT](DEBUG): Construct Continuous Built In Test. 2021-12-06T23:56:15.562Z,1638834975.562 [CBIT] Loaded 2021-12-06T23:56:15.562Z,1638834975.562 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2021-12-06T23:56:15.563Z,1638834975.563 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2021-12-06T23:56:15.563Z,1638834975.563 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2021-12-06T23:56:15.742Z,1638834975.742 [ESPComponent] Loaded 2021-12-06T23:56:15.742Z,1638834975.742 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread. 2021-12-06T23:56:15.761Z,1638834975.761 [PAR_Licor] Loaded 2021-12-06T23:56:15.761Z,1638834975.761 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2021-12-06T23:56:15.762Z,1638834975.762 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2021-12-06T23:56:15.762Z,1638834975.762 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2021-12-06T23:56:15.818Z,1638834975.818 [DepthRateCalculator] Loaded 2021-12-06T23:56:15.818Z,1638834975.818 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2021-12-06T23:56:15.823Z,1638834975.823 [PitchRateCalculator] Loaded 2021-12-06T23:56:15.823Z,1638834975.823 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2021-12-06T23:56:15.834Z,1638834975.834 [SpeedCalculator] Loaded 2021-12-06T23:56:15.834Z,1638834975.834 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2021-12-06T23:56:15.847Z,1638834975.847 [TempGradientCalculator] Loaded 2021-12-06T23:56:15.848Z,1638834975.848 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2021-12-06T23:56:15.852Z,1638834975.852 [YawRateCalculator] Loaded 2021-12-06T23:56:15.853Z,1638834975.853 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2021-12-06T23:56:15.870Z,1638834975.870 [ElevatorOffsetCalculator] Loaded 2021-12-06T23:56:15.871Z,1638834975.871 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2021-12-06T23:56:15.871Z,1638834975.871 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2021-12-06T23:56:15.872Z,1638834975.872 [Module Loader](DEBUG): Loading Module at Modules/Dock.so 2021-12-06T23:56:15.982Z,1638834975.982 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking) 2021-12-06T23:56:15.983Z,1638834975.983 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2021-12-06T23:56:16.020Z,1638834976.020 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2021-12-06T23:56:16.020Z,1638834976.020 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2021-12-06T23:56:16.110Z,1638834976.110 [DeadReckonUsingMultipleVelocitySources] Loaded 2021-12-06T23:56:16.111Z,1638834976.111 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2021-12-06T23:56:16.124Z,1638834976.124 [NavChart] Loaded 2021-12-06T23:56:16.124Z,1638834976.124 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2021-12-06T23:56:16.130Z,1638834976.130 [UniversalFixResidualReporter] Loaded 2021-12-06T23:56:16.130Z,1638834976.130 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2021-12-06T23:56:16.130Z,1638834976.130 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2021-12-06T23:56:16.131Z,1638834976.131 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2021-12-06T23:56:17.221Z,1638834977.221 [BPC1] Loaded 2021-12-06T23:56:17.221Z,1638834977.221 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2021-12-06T23:56:17.241Z,1638834977.241 [Depth_Keller] Loaded 2021-12-06T23:56:17.241Z,1638834977.241 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2021-12-06T23:56:17.246Z,1638834977.246 [DropWeight] Loaded 2021-12-06T23:56:17.246Z,1638834977.246 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2021-12-06T23:56:17.303Z,1638834977.303 [NAL9602] Loaded 2021-12-06T23:56:17.303Z,1638834977.303 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2021-12-06T23:56:17.328Z,1638834977.328 [Onboard] Loaded 2021-12-06T23:56:17.329Z,1638834977.329 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread. 2021-12-06T23:56:17.330Z,1638834977.330 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 4097C4E0 2021-12-06T23:56:17.330Z,1638834977.330 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 1772 2021-12-06T23:56:17.343Z,1638834977.343 [Power24vConverter] Loaded 2021-12-06T23:56:17.343Z,1638834977.343 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread. 2021-12-06T23:56:17.358Z,1638834977.358 [Radio_Surface] Loaded 2021-12-06T23:56:17.358Z,1638834977.358 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2021-12-06T23:56:17.359Z,1638834977.359 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409AC4E0 2021-12-06T23:56:17.359Z,1638834977.359 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 1773 2021-12-06T23:56:17.440Z,1638834977.440 [DAT] Loaded 2021-12-06T23:56:17.440Z,1638834977.440 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread. 2021-12-06T23:56:17.440Z,1638834977.440 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2021-12-06T23:56:17.441Z,1638834977.441 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2021-12-06T23:56:17.508Z,1638834977.508 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2021-12-06T23:56:17.509Z,1638834977.509 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2021-12-06T23:56:17.570Z,1638834977.570 [VerticalControl](DEBUG): Construct VerticalControl. 2021-12-06T23:56:17.623Z,1638834977.623 [VerticalControl] Loaded 2021-12-06T23:56:17.623Z,1638834977.623 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2021-12-06T23:56:17.626Z,1638834977.626 [HorizontalControl](DEBUG): Construct HorizontalControl. 2021-12-06T23:56:17.662Z,1638834977.662 [HorizontalControl] Loaded 2021-12-06T23:56:17.662Z,1638834977.662 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2021-12-06T23:56:17.665Z,1638834977.665 [SpeedControl](DEBUG): Construct SpeedControl. 2021-12-06T23:56:17.667Z,1638834977.667 [SpeedControl] Loaded 2021-12-06T23:56:17.668Z,1638834977.668 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2021-12-06T23:56:17.670Z,1638834977.670 [LoopControl](DEBUG): Construct LoopControl. 2021-12-06T23:56:17.671Z,1638834977.671 [LoopControl] Loaded 2021-12-06T23:56:17.671Z,1638834977.671 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2021-12-06T23:56:17.672Z,1638834977.672 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2021-12-06T23:56:17.672Z,1638834977.672 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2021-12-06T23:56:17.686Z,1638834977.686 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2021-12-06T23:56:17.686Z,1638834977.686 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2021-12-06T23:56:18.027Z,1638834978.027 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2021-12-06T23:56:18.033Z,1638834978.033 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2021-12-06T23:56:18.036Z,1638834978.036 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2021-12-06T23:56:18.047Z,1638834978.047 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2021-12-06T23:56:18.048Z,1638834978.048 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40AB14E0 2021-12-06T23:56:18.048Z,1638834978.048 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 1774 2021-12-06T23:56:18.053Z,1638834978.053 [Supervisor](INFO): Main Thread ID is 2933 2021-12-06T23:56:18.054Z,1638834978.054 [Supervisor](DEBUG): Running supervisor. 2021-12-06T23:56:18.054Z,1638834978.054 [CommandExec ThreadHandler](INFO): Handler Thread ID is 1775 2021-12-06T23:56:18.055Z,1638834978.055 [CommandExec](INFO): Initializing the command executive. 2021-12-06T23:56:18.057Z,1638834978.057 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1776 2021-12-06T23:56:18.059Z,1638834978.059 [controlThread ThreadHandler](INFO): Handler Thread ID is 1777 2021-12-06T23:56:18.059Z,1638834978.059 [controlThread](DEBUG): Initializing ControlThread 2021-12-06T23:56:18.061Z,1638834978.061 [SBIT](INFO): Initialize SBIT Component. 2021-12-06T23:56:18.061Z,1638834978.061 [SBIT](IMPORTANT): git: 2021-11-29_Tethys-17-gf3efab6f0 2021-12-06T23:56:18.062Z,1638834978.062 [SBIT](INFO): git hash: f3efab6f0c987c9256f0f0444cf2c47d9a7dd597 2021-12-06T23:56:18.062Z,1638834978.062 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2021-12-06T23:56:18.063Z,1638834978.063 [SBIT](INFO): Kernel Reporting Different Version From Configuration. Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018 Kernel Reported: #1 PREEMPT Wed Mar 17 08:23:48 PDT 2021 2021-12-06T23:56:18.065Z,1638834978.065 [SBIT](INFO): Beginning SBIT in 59.000000 seconds. 2021-12-06T23:56:18.065Z,1638834978.065 [IBIT](INFO): Initialize IBIT Component. 2021-12-06T23:56:18.066Z,1638834978.066 [CBIT](DEBUG): Initialize CBIT Component. 2021-12-06T23:56:18.067Z,1638834978.067 [logger ThreadHandler](INFO): Handler Thread ID is 1778 2021-12-06T23:56:18.080Z,1638834978.080 [CBIT](DEBUG): Initialized mux pins. 2021-12-06T23:56:18.080Z,1638834978.080 [CBIT](DEBUG): Initializing the watchdog timer. 2021-12-06T23:56:18.088Z,1638834978.088 [Onboard ThreadHandler](INFO): Handler Thread ID is 1779 2021-12-06T23:56:18.104Z,1638834978.104 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2021-12-06T23:56:18.104Z,1638834978.104 [CBIT](DEBUG): Initializing heartbeat. 2021-12-06T23:56:18.107Z,1638834978.107 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 1780 2021-12-06T23:56:18.132Z,1638834978.132 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1781 2021-12-06T23:56:18.142Z,1638834978.142 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2MI01M.000 2021-12-06T23:56:18.142Z,1638834978.142 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2MI01M.000 2021-12-06T23:56:18.143Z,1638834978.143 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4MI89M.000 2021-12-06T23:56:18.143Z,1638834978.143 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4MI89M.000 2021-12-06T23:56:18.143Z,1638834978.143 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4MI11M.000 2021-12-06T23:56:18.143Z,1638834978.143 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4MI11M.000 2021-12-06T23:56:18.143Z,1638834978.143 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5MI07M.000 2021-12-06T23:56:18.144Z,1638834978.144 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5MI07M.000 2021-12-06T23:56:18.144Z,1638834978.144 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5OH07M.000 2021-12-06T23:56:18.144Z,1638834978.144 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5OH07M.000 2021-12-06T23:56:18.144Z,1638834978.144 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5OH31M.000 2021-12-06T23:56:18.144Z,1638834978.144 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5OH31M.000 2021-12-06T23:56:18.176Z,1638834978.176 [CBIT](DEBUG): Deactivating GF circuits. 2021-12-06T23:56:18.176Z,1638834978.176 [CBIT](DEBUG): Deactivating emergency mode. 2021-12-06T23:56:18.212Z,1638834978.212 [CBIT](DEBUG): Backplane powered. 2021-12-06T23:56:18.220Z,1638834978.220 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2021-12-06T23:56:18.221Z,1638834978.221 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2021-12-06T23:56:18.221Z,1638834978.221 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2021-12-06T23:56:18.221Z,1638834978.221 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2021-12-06T23:56:18.222Z,1638834978.222 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2021-12-06T23:56:18.222Z,1638834978.222 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2021-12-06T23:56:18.224Z,1638834978.224 [NavChart](DEBUG): Initialize NavChart Navigation. 2021-12-06T23:56:18.224Z,1638834978.224 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2021-12-06T23:56:18.230Z,1638834978.230 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2021-12-06T23:56:18.232Z,1638834978.232 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2021-12-06T23:56:18.233Z,1638834978.233 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2021-12-06T23:56:18.234Z,1638834978.234 [LoopControl](DEBUG): Initialize LoopControlComponent. 2021-12-06T23:56:18.235Z,1638834978.235 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2021-12-06T23:56:18.461Z,1638834978.461 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2021-12-06T23:56:18.489Z,1638834978.489 [MissionManager](DEBUG): 2021-12-06T23:56:18.490Z,1638834978.490 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2021-12-06T23:56:18.512Z,1638834978.512 [Radio_Surface](INFO): Powering up 2021-12-06T23:56:18.653Z,1638834978.653 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2021-12-06T23:56:18.654Z,1638834978.654 [Default:A.Wait](DEBUG): Construct Wait. 2021-12-06T23:56:18.668Z,1638834978.668 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2021-12-06T23:56:18.696Z,1638834978.696 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2021-12-06T23:56:18.698Z,1638834978.698 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2021-12-06T23:56:18.729Z,1638834978.729 [Default:E.Execute](DEBUG): Construct Execute. 2021-12-06T23:56:18.748Z,1638834978.748 [MissionManager](DEBUG): 0 Wait a moment to see if the scheduler starts a new mission before starting to actually run Default. 13 Burn on Dropped weight due to communications timeout. 1 Default mission has been running for Restarting logs and Default mission. restart logs 2021-12-06T23:56:18.753Z,1638834978.753 [controlThread](DEBUG): Component order: CycleStarter,ESPComponent,PAR_Licor,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,DAT,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,MassServo,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2021-12-06T23:56:18.833Z,1638834978.833 [Depth_Keller](ERROR): Pressure reading out of range: 1896.040405 decibar 2021-12-06T23:56:18.834Z,1638834978.834 [Power24vConverter](INFO): Powering up. 2021-12-06T23:56:18.834Z,1638834978.834 [DAT](INFO): Powering up 2021-12-06T23:56:18.835Z,1638834978.835 [DAT](DEBUG): Initializing DAT. 2021-12-06T23:56:18.876Z,1638834978.876 [DepthRateCalculator](ERROR): Depth measurement is not active 2021-12-06T23:56:18.914Z,1638834978.914 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2021-12-06T23:56:18.920Z,1638834978.920 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2021-12-06T23:56:18.921Z,1638834978.921 [MassServo](DEBUG): Initializing EZServoServo. 2021-12-06T23:56:18.928Z,1638834978.928 [MassServo](DEBUG): Initializing MassServo. 2021-12-06T23:56:19.185Z,1638834979.185 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2021-12-06T23:56:19.185Z,1638834979.185 [DropWeight] Hardware Fault, FailCount= 1 2021-12-06T23:56:19.185Z,1638834979.185 [DropWeight](ERROR): Hardware Fault 2021-12-06T23:56:19.225Z,1638834979.225 [CommandExec](FAULT): Scheduling is paused 2021-12-06T23:56:19.225Z,1638834979.225 [CBIT](INFO): Critical error at 20211206T235619 2021-12-06T23:56:19.226Z,1638834979.226 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals 2021-12-06T23:56:19.228Z,1638834979.228 [CBIT](ERROR): Hardware Fault in component: DropWeight 2021-12-06T23:56:19.229Z,1638834979.229 [CBIT](CRITICAL): Hardware Fault in component: DropWeight 2021-12-06T23:56:19.589Z,1638834979.589 [CBIT](INFO): Critical error at 20211206T235619 2021-12-06T23:56:28.123Z,1638834988.123 [CBIT](CRITICAL): Environmental Failure. Press:14.774860 PSI. Humidity:42%. Temp:23 C. ABORTING MISSION 2021-12-06T23:56:28.541Z,1638834988.541 [CBIT](INFO): Critical error at 20211206T235628 2021-12-06T23:56:30.078Z,1638834990.078 [DAT](INFO): DAT read: 2021-12-06T23:56:30.482Z,1638834990.482 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series 2021-12-06T23:56:31.694Z,1638834991.694 [DAT](INFO): DAT read: MF Frequency Band 2021-12-06T23:56:31.695Z,1638834991.695 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.14.0 2021-12-06T23:56:31.696Z,1638834991.696 [DAT](INFO): DAT read: Dec 6 2021 23:54:37 2021-12-06T23:56:32.907Z,1638834992.907 [DAT](INFO): DAT read: Features enabled [Bearing] 2021-12-06T23:56:32.908Z,1638834992.908 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP 2021-12-06T23:56:32.908Z,1638834992.908 [DAT](INFO): commRate: 800 2021-12-06T23:56:34.926Z,1638834994.926 [DAT](INFO): entering command mode 2021-12-06T23:56:35.330Z,1638834995.330 [DAT](INFO): DAT read: 2021-12-06T23:56:35.330Z,1638834995.330 [DAT](DEBUG): checking for command mode acknowledgment 2021-12-06T23:56:35.734Z,1638834995.734 [DAT](DEBUG): checking for command mode acknowledgment 2021-12-06T23:56:36.134Z,1638834996.134 [DAT](DEBUG): checking for command mode acknowledgment 2021-12-06T23:56:36.541Z,1638834996.541 [DAT](DEBUG): checking for command mode acknowledgment 2021-12-06T23:56:36.946Z,1638834996.946 [DAT](DEBUG): checking for command mode acknowledgment 2021-12-06T23:56:37.346Z,1638834997.346 [DAT](DEBUG): checking for command mode acknowledgment 2021-12-06T23:56:37.754Z,1638834997.754 [DAT](DEBUG): checking for command mode acknowledgment 2021-12-06T23:56:38.158Z,1638834998.158 [DAT](DEBUG): checking for command mode acknowledgment 2021-12-06T23:56:38.561Z,1638834998.561 [DAT](DEBUG): checking for command mode acknowledgment 2021-12-06T23:56:38.965Z,1638834998.965 [DAT](DEBUG): checking for command mode acknowledgment 2021-12-06T23:56:39.369Z,1638834999.369 [DAT](DEBUG): checking for command mode acknowledgment 2021-12-06T23:56:39.774Z,1638834999.774 [DAT](DEBUG): checking for command mode acknowledgment 2021-12-06T23:56:40.178Z,1638835000.178 [DAT](DEBUG): checking for command mode acknowledgment 2021-12-06T23:56:40.582Z,1638835000.582 [DAT](DEBUG): checking for command mode acknowledgment 2021-12-06T23:56:40.986Z,1638835000.986 [DAT](DEBUG): checking for command mode acknowledgment 2021-12-06T23:56:41.386Z,1638835001.386 [DAT](DEBUG): checking for command mode acknowledgment 2021-12-06T23:56:41.794Z,1638835001.794 [DAT](DEBUG): checking for command mode acknowledgment 2021-12-06T23:56:42.198Z,1638835002.198 [DAT](DEBUG): checking for command mode acknowledgment 2021-12-06T23:56:42.602Z,1638835002.602 [DAT](DEBUG): checking for command mode acknowledgment 2021-12-06T23:56:43.006Z,1638835003.006 [DAT](DEBUG): checking for command mode acknowledgment 2021-12-06T23:56:43.410Z,1638835003.410 [DAT](DEBUG): checking for command mode acknowledgment 2021-12-06T23:56:43.814Z,1638835003.814 [DAT](DEBUG): checking for command mode acknowledgment 2021-12-06T23:56:44.217Z,1638835004.217 [DAT](DEBUG): checking for command mode acknowledgment 2021-12-06T23:56:44.621Z,1638835004.621 [DAT](DEBUG): checking for command mode acknowledgment 2021-12-06T23:56:45.026Z,1638835005.026 [DAT](DEBUG): checking for command mode acknowledgment 2021-12-06T23:56:45.430Z,1638835005.430 [DAT](DEBUG): checking for command mode acknowledgment 2021-12-06T23:56:45.834Z,1638835005.834 [DAT](DEBUG): checking for command mode acknowledgment 2021-12-06T23:56:46.237Z,1638835006.237 [DAT](DEBUG): checking for command mode acknowledgment 2021-12-06T23:56:46.642Z,1638835006.642 [DAT](DEBUG): checking for command mode acknowledgment 2021-12-06T23:56:47.046Z,1638835007.046 [DAT](DEBUG): checking for command mode acknowledgment 2021-12-06T23:56:47.449Z,1638835007.449 [NAL9602](INFO): Powering up NAL9602 2021-12-06T23:56:47.451Z,1638835007.451 [DAT](DEBUG): checking for command mode acknowledgment 2021-12-06T23:56:47.851Z,1638835007.851 [DAT](DEBUG): checking for command mode acknowledgment 2021-12-06T23:56:48.259Z,1638835008.259 [DAT](DEBUG): checking for command mode acknowledgment 2021-12-06T23:56:48.663Z,1638835008.663 [DAT](DEBUG): checking for command mode acknowledgment 2021-12-06T23:56:49.061Z,1638835009.061 [DAT](DEBUG): checking for command mode acknowledgment 2021-12-06T23:56:49.465Z,1638835009.465 [DAT](DEBUG): checking for command mode acknowledgment 2021-12-06T23:56:49.875Z,1638835009.875 [DAT](DEBUG): checking for command mode acknowledgment 2021-12-06T23:56:50.279Z,1638835010.279 [DAT](DEBUG): checking for command mode acknowledgment 2021-12-06T23:56:50.279Z,1638835010.279 [DAT](FAULT): failed to enter command mode 2021-12-06T23:56:50.681Z,1638835010.681 [DAT](INFO): entering command mode 2021-12-06T23:56:51.087Z,1638835011.087 [DAT](INFO): DAT read: user:1> 2021-12-06T23:56:51.088Z,1638835011.088 [DAT](INFO): DAT read: Command '+++' not found 2021-12-06T23:56:51.088Z,1638835011.088 [DAT](INFO): DAT read: Error 2021-12-06T23:56:51.089Z,1638835011.089 [DAT](INFO): setting verbose to 3 2021-12-06T23:56:51.491Z,1638835011.491 [DAT](INFO): DAT read: user:2> 2021-12-06T23:56:51.492Z,1638835011.492 [DAT](INFO): DAT read: Verbose | 3 2021-12-06T23:56:51.493Z,1638835011.493 [DAT](INFO): set verbose to 3 2021-12-06T23:56:51.493Z,1638835011.493 [DAT](INFO): setting DatVerbose to 27440 2021-12-06T23:56:51.894Z,1638835011.894 [DAT](INFO): DAT read: user:3> 2021-12-06T23:56:51.895Z,1638835011.895 [DAT](INFO): DAT read: DatVerbose | 27440 2021-12-06T23:56:51.896Z,1638835011.896 [DAT](INFO): set DatVerbose to 27440 2021-12-06T23:56:51.896Z,1638835011.896 [DAT](INFO): setting transmit power to 8 2021-12-06T23:56:52.304Z,1638835012.304 [DAT](INFO): DAT read: user:4> 2021-12-06T23:56:52.305Z,1638835012.305 [DAT](INFO): DAT read: TxPower | 8 (Max) 2021-12-06T23:56:52.306Z,1638835012.306 [DAT](INFO): set transmit power to 8 2021-12-06T23:56:52.306Z,1638835012.306 [DAT](INFO): setting local address to 4 2021-12-06T23:56:52.706Z,1638835012.706 [DAT](INFO): DAT read: user:5> 2021-12-06T23:56:52.707Z,1638835012.707 [DAT](INFO): DAT read: LocalAddr | 4 2021-12-06T23:56:52.707Z,1638835012.707 [DAT](INFO): set local address to 4 2021-12-06T23:56:58.359Z,1638835018.359 [NAL9602](INFO): NAL9602 initialized 2021-12-06T23:57:17.789Z,1638835037.789 [SBIT](IMPORTANT): Beginning Startup BIT 2021-12-06T23:57:17.794Z,1638835037.794 [CBIT](IMPORTANT): Beginning ground fault scan 2021-12-06T23:57:25.022Z,1638835045.022 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-12-06T23:57:28.724Z,1638835048.724 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.007208 CHAN A1 (24V): 0.000491 CHAN A2 (12V): -0.005147 CHAN A3 (5V): -0.002522 CHAN B0 (3.3V): -0.001190 CHAN B1 (3.15aV): -0.001179 CHAN B2 (3.15bV): -0.001099 CHAN B3 (GND): -0.000154 OPEN: 0.006963 Full Scale: +/- 1 mA 2021-12-06T23:57:30.813Z,1638835050.813 [SBIT](ERROR): Could not read elevatorAngleReader_. 2021-12-06T23:57:30.813Z,1638835050.813 [SBIT](ERROR): Could not read rudderAngleReader_. 2021-12-06T23:57:36.737Z,1638835056.737 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-12-06T23:57:48.449Z,1638835068.449 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-12-06T23:57:57.357Z,1638835077.357 [SBIT](ERROR): Could not read elevatorAngleReader_. 2021-12-06T23:57:57.357Z,1638835077.357 [SBIT](ERROR): Could not read rudderAngleReader_. 2021-12-06T23:57:57.357Z,1638835077.357 [SBIT](FAULT): Control surface position failure. 2021-12-06T23:57:59.765Z,1638835079.765 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-12-06T23:58:11.077Z,1638835091.077 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-12-06T23:58:11.125Z,1638835091.125 [SBIT](ERROR): Could not read elevatorAngleReader_. 2021-12-06T23:58:11.125Z,1638835091.125 [SBIT](ERROR): Could not read rudderAngleReader_. 2021-12-06T23:58:11.125Z,1638835091.125 [SBIT](FAULT): Control surface position failure. 2021-12-06T23:58:11.501Z,1638835091.501 [SBIT](CRITICAL): SBIT FAILED 2021-12-06T23:58:11.501Z,1638835091.501 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2021-12-06T23:58:11.502Z,1638835091.502 [SBIT](IMPORTANT): AHRS_M2.loadAtStartup=0 bool; 2021-12-06T23:58:11.502Z,1638835091.502 [SBIT](IMPORTANT): CTD_Seabird.loadAtStartup=0 bool; 2021-12-06T23:58:11.503Z,1638835091.503 [SBIT](IMPORTANT): DVL_micro.loadAtStartup=0 bool; 2021-12-06T23:58:11.503Z,1638835091.503 [SBIT](IMPORTANT): ElevatorServo.loadAtStartup=0 bool; 2021-12-06T23:58:11.503Z,1638835091.503 [SBIT](IMPORTANT): RudderServo.loadAtStartup=0 bool; 2021-12-06T23:58:11.503Z,1638835091.503 [SBIT](IMPORTANT): ThrusterServo.loadAtStartup=0 bool; 2021-12-06T23:58:11.503Z,1638835091.503 [SBIT](IMPORTANT): WetLabsBB2FL.loadAtStartup=0 bool; 2021-12-06T23:58:11.505Z,1638835091.505 [CBIT](INFO): Critical error at 20211206T235811 2021-12-06T23:58:11.908Z,1638835091.908 [MissionManager](IMPORTANT): Started mission Startup 2021-12-06T23:58:11.909Z,1638835091.909 [Startup] Running Loop=1 2021-12-06T23:58:11.909Z,1638835091.909 [Startup](DEBUG): Aggregate::initialize Startup 2021-12-06T23:58:11.909Z,1638835091.909 [Startup:A.GoToSurface] Running Loop=1 2021-12-06T23:58:11.909Z,1638835091.909 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2021-12-06T23:58:11.909Z,1638835091.909 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2021-12-06T23:58:11.910Z,1638835091.910 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2021-12-06T23:58:11.910Z,1638835091.910 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2021-12-06T23:58:11.911Z,1638835091.911 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2021-12-06T23:58:11.911Z,1638835091.911 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2021-12-06T23:58:11.913Z,1638835091.913 [Startup:StartupSatComms] Running Loop=1 2021-12-06T23:58:11.913Z,1638835091.913 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2021-12-06T23:58:11.913Z,1638835091.913 [Startup:StartupSatComms:A] Running Loop=1 2021-12-06T23:58:12.306Z,1638835092.306 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2021-12-06T23:58:18.418Z,1638835098.418 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2021-12-06T23:58:18.418Z,1638835098.418 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2021-12-06T23:58:18.418Z,1638835098.418 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-12-06T23:58:18.429Z,1638835098.429 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-12-06T23:58:18.517Z,1638835098.517 [CommandExec](IMPORTANT): got command failComponent 2021-12-06T23:58:18.517Z,1638835098.517 [CommandExec](IMPORTANT): Failed components: 2021-12-06T23:58:18.517Z,1638835098.517 [CommandExec](IMPORTANT): DeadReckonUsingMultipleVelocitySources: Software Fault 2021-12-06T23:58:18.518Z,1638835098.518 [CommandExec](IMPORTANT): DropWeight: Hardware Fault 2021-12-06T23:58:18.779Z,1638835098.779 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-12-06T23:58:18.779Z,1638835098.779 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2021-12-06T23:58:22.383Z,1638835102.383 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-12-06T23:58:34.105Z,1638835114.105 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-12-06T23:58:45.041Z,1638835125.041 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-12-06T23:59:12.126Z,1638835152.126 [Startup:StartupSatComms:A](INFO): Timed out from 2021-12-06T23:58:11.9Z 2021-12-06T23:59:12.126Z,1638835152.126 [Startup:StartupSatComms:A] Stopped 2021-12-06T23:59:12.126Z,1638835152.126 [Startup:StartupSatComms:B] Running Loop=1 2021-12-06T23:59:12.536Z,1638835152.536 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2021-12-06T23:59:14.526Z,1638835154.526 [DAT](INFO): #Outgoing data=1 2021-12-06T23:59:14.527Z,1638835154.527 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-12-06T23:59:14.633Z,1638835154.633 [DAT](INFO): setting remote address to 1 2021-12-06T23:59:14.960Z,1638835154.960 [DAT](INFO): DAT read: user:6> 2021-12-06T23:59:14.961Z,1638835154.961 [DAT](INFO): DAT read: RemoteAddr | 1 2021-12-06T23:59:14.962Z,1638835154.962 [DAT](INFO): set remote address to 1 2021-12-06T23:59:14.963Z,1638835154.963 [DAT](INFO): entering online mode 2021-12-06T23:59:15.366Z,1638835155.366 [DAT](INFO): DAT read: user:7> 2021-12-06T23:59:15.367Z,1638835155.367 [DAT](INFO): DAT read: 2021-12-06T23:59:15.368Z,1638835155.368 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP 2021-12-06T23:59:15.369Z,1638835155.369 [DAT](INFO): commRate: 800 2021-12-06T23:59:15.369Z,1638835155.369 [DAT](INFO): online mode acknowledged 2021-12-06T23:59:15.370Z,1638835155.370 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-12-06T23:59:19.001Z,1638835159.001 [DAT](INFO): DAT read: Forwarding Delay UpTx time:23:57:28.2405 2021-12-06T23:59:19.001Z,1638835159.001 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-12-06T23:59:27.087Z,1638835167.087 [DAT](INFO): DAT read: Rx Time:23:57:36.0289 2021-12-06T23:59:27.087Z,1638835167.087 [DAT](INFO): received an acoustic signal 2021-12-06T23:59:28.305Z,1638835168.305 [DAT](INFO): DAT read: 2021-12-06T23:59:28.306Z,1638835168.306 [DAT](INFO): DAT read: DATA(0002):~~ 2021-12-06T23:59:28.306Z,1638835168.306 [DAT](INFO): Got DATA 2 2021-12-06T23:59:28.307Z,1638835168.307 [DAT](INFO): DAT read: Source:001 Destination:004 2021-12-06T23:59:28.307Z,1638835168.307 [DAT](INFO): Got Src/Dest after DATA 2021-12-06T23:59:28.307Z,1638835168.307 [DAT](INFO): DATA Src=1, Dst=4 2021-12-06T23:59:28.309Z,1638835168.309 [DAT](INFO): DAT read: CRC:Pass MPD:03.5 PSNR:12.5 AGC:61 SPD:+0.0 CCERR:011 2021-12-06T23:59:28.309Z,1638835168.309 [DAT](INFO): Got CRC:Pass 2021-12-06T23:59:28.309Z,1638835168.309 [DAT](INFO): Got CRC:Pass 2021-12-06T23:59:28.309Z,1638835168.309 [DAT](INFO): Incoming data is intended for us 2021-12-06T23:59:28.309Z,1638835168.309 [DAT](DEBUG): In parseResponses, got ack so set commsState_ = SENDING_VERIFIED 2021-12-06T23:59:28.309Z,1638835168.309 [DAT](INFO): Got ack 2021-12-06T23:59:28.310Z,1638835168.310 [DAT](INFO): DAT read: 2021-12-06T23:59:28.310Z,1638835168.310 [DAT](INFO): DAT read: 2021-12-06T23:59:28.311Z,1638835168.311 [DAT](INFO): Sent 130 bytes from file Logs/20211206T232409/Courier0036.lzma.parts 2021-12-06T23:59:28.311Z,1638835168.311 [DAT](INFO): Packets left to send: 0 2021-12-06T23:59:28.314Z,1638835168.314 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2021-12-06T23:59:30.347Z,1638835170.347 [DAT](INFO): #Outgoing data=1 2021-12-06T23:59:30.347Z,1638835170.347 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-12-06T23:59:30.442Z,1638835170.442 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-12-06T23:59:34.041Z,1638835174.041 [DAT](INFO): DAT read: Forwarding Delay UpTx time:23:57:43.5404 2021-12-06T23:59:34.042Z,1638835174.042 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-12-06T23:59:44.937Z,1638835184.937 [DAT](INFO): DAT read: Rx Time:23:57:53.7292 2021-12-06T23:59:44.937Z,1638835184.937 [DAT](INFO): received an acoustic signal 2021-12-06T23:59:45.744Z,1638835185.744 [DAT](INFO): DAT read: 2021-12-06T23:59:45.745Z,1638835185.745 [DAT](INFO): DAT read: DATA(0002):~~ 2021-12-06T23:59:45.745Z,1638835185.745 [DAT](INFO): Got DATA 2 2021-12-06T23:59:45.746Z,1638835185.746 [DAT](INFO): DAT read: Source:001 Destination:004 2021-12-06T23:59:45.746Z,1638835185.746 [DAT](INFO): Got Src/Dest after DATA 2021-12-06T23:59:45.747Z,1638835185.747 [DAT](INFO): DATA Src=1, Dst=4 2021-12-06T23:59:45.748Z,1638835185.748 [DAT](INFO): DAT read: CRC:Pass MPD:03.4 PSNR:12.5 AGC:63 SPD:+0.0 CCERR:011 2021-12-06T23:59:45.748Z,1638835185.748 [DAT](INFO): Got CRC:Pass 2021-12-06T23:59:45.748Z,1638835185.748 [DAT](INFO): Got CRC:Pass 2021-12-06T23:59:45.749Z,1638835185.749 [DAT](INFO): Incoming data is intended for us 2021-12-06T23:59:45.749Z,1638835185.749 [DAT](DEBUG): In parseResponses, got ack so set commsState_ = SENDING_VERIFIED 2021-12-06T23:59:45.749Z,1638835185.749 [DAT](INFO): Got ack 2021-12-06T23:59:45.749Z,1638835185.749 [DAT](INFO): DAT read: 2021-12-06T23:59:45.750Z,1638835185.750 [DAT](INFO): DAT read: 2021-12-06T23:59:45.750Z,1638835185.750 [DAT](INFO): Sent 336 bytes from file Logs/20211206T235608/Courier0000.lzma.parts 2021-12-06T23:59:45.750Z,1638835185.750 [DAT](INFO): Packets left to send: 0 2021-12-06T23:59:45.753Z,1638835185.753 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2021-12-06T23:59:47.737Z,1638835187.737 [DAT](INFO): #Outgoing data=1 2021-12-06T23:59:47.738Z,1638835187.738 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-12-06T23:59:47.821Z,1638835187.821 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-12-06T23:59:52.153Z,1638835192.153 [DAT](INFO): DAT read: Forwarding Delay UpTx time:23:58:01.6416 2021-12-06T23:59:52.153Z,1638835192.153 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-12-07T00:00:10.741Z,1638835210.741 [DAT](INFO): DAT read: Rx Time:23:58:19.4796 2021-12-07T00:00:10.741Z,1638835210.741 [DAT](INFO): received an acoustic signal 2021-12-07T00:00:11.532Z,1638835211.532 [DAT](INFO): DAT read: 2021-12-07T00:00:11.533Z,1638835211.533 [DAT](INFO): DAT read: DATA(0002):~~ 2021-12-07T00:00:11.533Z,1638835211.533 [DAT](INFO): Got DATA 2 2021-12-07T00:00:11.534Z,1638835211.534 [DAT](INFO): DAT read: Source:001 Destination:004 2021-12-07T00:00:11.534Z,1638835211.534 [DAT](INFO): Got Src/Dest after DATA 2021-12-07T00:00:11.535Z,1638835211.535 [DAT](INFO): DATA Src=1, Dst=4 2021-12-07T00:00:11.536Z,1638835211.536 [DAT](INFO): DAT read: CRC:Pass MPD:03.3 PSNR:12.5 AGC:64 SPD:+0.0 CCERR:011 2021-12-07T00:00:11.536Z,1638835211.536 [DAT](INFO): Got CRC:Pass 2021-12-07T00:00:11.536Z,1638835211.536 [DAT](INFO): Got CRC:Pass 2021-12-07T00:00:11.537Z,1638835211.537 [DAT](INFO): Incoming data is intended for us 2021-12-07T00:00:11.537Z,1638835211.537 [DAT](DEBUG): In parseResponses, got ack so set commsState_ = SENDING_VERIFIED 2021-12-07T00:00:11.537Z,1638835211.537 [DAT](INFO): Got ack 2021-12-07T00:00:11.537Z,1638835211.537 [DAT](INFO): DAT read: 2021-12-07T00:00:11.538Z,1638835211.538 [DAT](INFO): DAT read: 2021-12-07T00:00:11.538Z,1638835211.538 [DAT](INFO): Sent 1016 bytes from file Logs/20211206T235608/Courier9001.lzma.parts 2021-12-07T00:00:11.538Z,1638835211.538 [DAT](INFO): Packets left to send: 2 2021-12-07T00:00:11.541Z,1638835211.541 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2021-12-07T00:00:13.516Z,1638835213.516 [DAT](INFO): #Outgoing data=1 2021-12-07T00:00:13.516Z,1638835213.516 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-12-07T00:00:13.522Z,1638835213.522 [Startup:StartupSatComms:B](INFO): Timed out from 2021-12-06T23:59:12.1Z 2021-12-07T00:00:13.522Z,1638835213.522 [Startup:StartupSatComms:B] Stopped 2021-12-07T00:00:13.522Z,1638835213.522 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2021-12-07T00:00:13.522Z,1638835213.522 [Startup:StartupSatComms] Stopped 2021-12-07T00:00:13.522Z,1638835213.522 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2021-12-07T00:00:13.523Z,1638835213.523 [Startup](INFO): Completed Startup 2021-12-07T00:00:13.523Z,1638835213.523 [MissionManager](INFO): Startup is completed. 2021-12-07T00:00:13.523Z,1638835213.523 [MissionManager](INFO): Uninitializing Mission Startup 2021-12-07T00:00:13.524Z,1638835213.524 [Startup] Stopped 2021-12-07T00:00:13.524Z,1638835213.524 [Startup](DEBUG): Aggregate::uninitialize Startup 2021-12-07T00:00:13.524Z,1638835213.524 [Startup:A.GoToSurface] Stopped 2021-12-07T00:00:13.524Z,1638835213.524 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2021-12-07T00:00:13.607Z,1638835213.607 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-12-07T00:00:13.626Z,1638835213.626 [MissionManager](IMPORTANT): Started mission Default 2021-12-07T00:00:13.627Z,1638835213.627 [Default] Running Loop=1 2021-12-07T00:00:13.627Z,1638835213.627 [Default](DEBUG): Aggregate::initialize Default 2021-12-07T00:00:13.628Z,1638835213.628 [Default:B.GoToSurface] Running Loop=1 2021-12-07T00:00:13.628Z,1638835213.628 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2021-12-07T00:00:13.629Z,1638835213.629 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2021-12-07T00:00:13.631Z,1638835213.631 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2021-12-07T00:00:13.648Z,1638835213.648 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2021-12-07T00:00:13.650Z,1638835213.650 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2021-12-07T00:00:13.651Z,1638835213.651 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2021-12-07T00:00:13.656Z,1638835213.656 [Default:A.Wait] Running Loop=1 2021-12-07T00:00:13.657Z,1638835213.657 [Default:A.Wait](DEBUG): Initialize Wait Component. 2021-12-07T00:00:18.021Z,1638835218.021 [DAT](INFO): DAT read: Forwarding Delay UpTx time:23:58:27.4414 2021-12-07T00:00:18.021Z,1638835218.021 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-12-07T00:00:19.275Z,1638835219.275 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2021-12-07T00:00:19.275Z,1638835219.275 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2 2021-12-07T00:00:19.275Z,1638835219.275 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-12-07T00:00:19.295Z,1638835219.295 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-12-07T00:00:19.705Z,1638835219.705 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-12-07T00:00:19.705Z,1638835219.705 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2 2021-12-07T00:00:26.931Z,1638835226.931 [Default:A.Wait](INFO): Done Waiting. 2021-12-07T00:00:26.931Z,1638835226.931 [Default:A.Wait] Stopped 2021-12-07T00:00:26.931Z,1638835226.931 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2021-12-07T00:00:27.323Z,1638835227.323 [Default:CheckIn] Running Loop=1 2021-12-07T00:00:27.323Z,1638835227.323 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-07T00:00:27.323Z,1638835227.323 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-07T00:00:27.724Z,1638835227.724 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2021-12-07T00:00:36.213Z,1638835236.213 [DAT](INFO): DAT read: Rx Time:23:58:45.2799 2021-12-07T00:00:36.213Z,1638835236.213 [DAT](INFO): received an acoustic signal 2021-12-07T00:00:37.453Z,1638835237.453 [DAT](INFO): DAT read: 2021-12-07T00:00:37.454Z,1638835237.454 [DAT](INFO): DAT read: DATA(0002):~~ 2021-12-07T00:00:37.454Z,1638835237.454 [DAT](INFO): Got DATA 2 2021-12-07T00:00:37.455Z,1638835237.455 [DAT](INFO): DAT read: Source:001 Destination:004 2021-12-07T00:00:37.455Z,1638835237.455 [DAT](INFO): Got Src/Dest after DATA 2021-12-07T00:00:37.456Z,1638835237.456 [DAT](INFO): DATA Src=1, Dst=4 2021-12-07T00:00:37.457Z,1638835237.457 [DAT](INFO): DAT read: CRC:Pass MPD:03.5 PSNR:12.7 AGC:60 SPD:+0.0 CCERR:011 2021-12-07T00:00:37.457Z,1638835237.457 [DAT](INFO): Got CRC:Pass 2021-12-07T00:00:37.457Z,1638835237.457 [DAT](INFO): Got CRC:Pass 2021-12-07T00:00:37.458Z,1638835237.458 [DAT](INFO): Incoming data is intended for us 2021-12-07T00:00:37.458Z,1638835237.458 [DAT](DEBUG): In parseResponses, got ack so set commsState_ = SENDING_VERIFIED 2021-12-07T00:00:37.458Z,1638835237.458 [DAT](INFO): Got ack 2021-12-07T00:00:37.458Z,1638835237.458 [DAT](INFO): DAT read: 2021-12-07T00:00:37.459Z,1638835237.459 [DAT](INFO): DAT read: 2021-12-07T00:00:37.459Z,1638835237.459 [DAT](INFO): Sent 1016 bytes from file Logs/20211206T235608/Courier9001.lzma.parts 2021-12-07T00:00:37.459Z,1638835237.459 [DAT](INFO): Packets left to send: 1 2021-12-07T00:00:37.470Z,1638835237.470 [DAT](DEBUG): In sendingVerified, sbd done so set commsState_ = SENDING_FILL_BUFFER 2021-12-07T00:01:27.513Z,1638835287.513 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-12-07T00:00:27.3Z 2021-12-07T00:01:27.513Z,1638835287.513 [Default:CheckIn:Read_GPS] Stopped 2021-12-07T00:01:27.513Z,1638835287.513 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-07T00:01:27.918Z,1638835287.918 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2021-12-07T00:01:29.918Z,1638835289.918 [DAT](INFO): #Outgoing data=1 2021-12-07T00:01:29.918Z,1638835289.918 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-12-07T00:01:30.022Z,1638835290.022 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-12-07T00:01:33.585Z,1638835293.585 [DAT](INFO): DAT read: Forwarding Delay UpTx time:23:59:42.7907 2021-12-07T00:01:33.585Z,1638835293.585 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-12-07T00:01:40.869Z,1638835300.869 [DAT](INFO): DAT read: Rx Time:23:59:49.6311 2021-12-07T00:01:40.869Z,1638835300.869 [DAT](INFO): received an acoustic signal 2021-12-07T00:01:41.677Z,1638835301.677 [DAT](INFO): DAT read: 2021-12-07T00:01:41.678Z,1638835301.678 [DAT](INFO): DAT read: DATA(0002):~~ 2021-12-07T00:01:41.678Z,1638835301.678 [DAT](INFO): Got DATA 2 2021-12-07T00:01:41.679Z,1638835301.679 [DAT](INFO): DAT read: Source:001 Destination:004 2021-12-07T00:01:41.679Z,1638835301.679 [DAT](INFO): Got Src/Dest after DATA 2021-12-07T00:01:41.679Z,1638835301.679 [DAT](INFO): DATA Src=1, Dst=4 2021-12-07T00:01:41.681Z,1638835301.681 [DAT](INFO): DAT read: CRC:Pass MPD:03.5 PSNR:12.5 AGC:62 SPD:+0.0 CCERR:011 2021-12-07T00:01:41.681Z,1638835301.681 [DAT](INFO): Got CRC:Pass 2021-12-07T00:01:41.681Z,1638835301.681 [DAT](INFO): Got CRC:Pass 2021-12-07T00:01:41.681Z,1638835301.681 [DAT](INFO): Incoming data is intended for us 2021-12-07T00:01:41.681Z,1638835301.681 [DAT](DEBUG): In parseResponses, got ack so set commsState_ = SENDING_VERIFIED 2021-12-07T00:01:41.681Z,1638835301.681 [DAT](INFO): Got ack 2021-12-07T00:01:41.682Z,1638835301.682 [DAT](INFO): DAT read: 2021-12-07T00:01:41.682Z,1638835301.682 [DAT](INFO): DAT read: 2021-12-07T00:01:41.683Z,1638835301.683 [DAT](INFO): Sent 38 bytes from file Logs/20211206T235608/Courier0004.lzma.parts 2021-12-07T00:01:41.683Z,1638835301.683 [DAT](INFO): Packets left to send: 0 2021-12-07T00:01:41.734Z,1638835301.734 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2021-12-07T00:01:43.641Z,1638835303.641 [DAT](INFO): #Outgoing data=1 2021-12-07T00:01:43.641Z,1638835303.641 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-12-07T00:01:43.737Z,1638835303.737 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-12-07T00:01:47.567Z,1638835307.567 [DAT](INFO): DAT read: Forwarding Delay UpTx time:23:59:57.0892 2021-12-07T00:01:47.567Z,1638835307.567 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-12-07T00:02:00.894Z,1638835320.894 [DAT](INFO): DAT read: Rx Time:00:00:09.6815 2021-12-07T00:02:00.894Z,1638835320.894 [DAT](INFO): received an acoustic signal 2021-12-07T00:02:01.701Z,1638835321.701 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-12-07T00:02:01.702Z,1638835321.702 [DAT](INFO): DAT read: 2021-12-07T00:02:01.703Z,1638835321.703 [DAT](INFO): DAT read: DATA(0002):~~ 2021-12-07T00:02:01.703Z,1638835321.703 [DAT](INFO): Got DATA 2 2021-12-07T00:02:01.705Z,1638835321.705 [DAT](INFO): DAT read: Source:001 Destination:004 2021-12-07T00:02:01.705Z,1638835321.705 [DAT](INFO): Got Src/Dest after DATA 2021-12-07T00:02:01.706Z,1638835321.706 [DAT](INFO): DATA Src=1, Dst=4 2021-12-07T00:02:01.707Z,1638835321.707 [DAT](INFO): DAT read: CRC:Pass MPD:03.4 PSNR:12.1 AGC:62 SPD:+0.1 CCERR:011 2021-12-07T00:02:01.707Z,1638835321.707 [DAT](INFO): Got CRC:Pass 2021-12-07T00:02:01.707Z,1638835321.707 [DAT](INFO): Got CRC:Pass 2021-12-07T00:02:01.707Z,1638835321.707 [DAT](INFO): Incoming data is intended for us 2021-12-07T00:02:01.707Z,1638835321.707 [DAT](DEBUG): In parseResponses, got ack so set commsState_ = SENDING_VERIFIED 2021-12-07T00:02:01.708Z,1638835321.708 [DAT](INFO): Got ack 2021-12-07T00:02:01.708Z,1638835321.708 [DAT](INFO): DAT read: 2021-12-07T00:02:01.709Z,1638835321.709 [DAT](INFO): DAT read: 2021-12-07T00:02:01.709Z,1638835321.709 [DAT](INFO): Sent 551 bytes from file Logs/20211206T235608/Courier9001.lzma.parts 2021-12-07T00:02:01.709Z,1638835321.709 [DAT](INFO): Packets left to send: 0 2021-12-07T00:02:01.713Z,1638835321.713 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2021-12-07T00:02:06.587Z,1638835326.587 [Default:CheckIn:Read_Iridium] Stopped 2021-12-07T00:02:06.587Z,1638835326.587 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-07T00:02:06.587Z,1638835326.587 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-07T00:02:20.096Z,1638835340.096 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2021-12-07T00:02:20.096Z,1638835340.096 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3 2021-12-07T00:02:20.096Z,1638835340.096 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-12-07T00:02:20.107Z,1638835340.107 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-12-07T00:02:20.429Z,1638835340.429 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-12-07T00:02:20.429Z,1638835340.429 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3 2021-12-07T00:03:07.241Z,1638835387.241 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-07T00:03:07.242Z,1638835387.242 [Default:CheckIn:C.Wait] Stopped 2021-12-07T00:03:07.242Z,1638835387.242 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-07T00:03:07.242Z,1638835387.242 [Default:CheckIn:D] Running Loop=1 2021-12-07T00:03:07.647Z,1638835387.647 [Default:CheckIn:D] Stopped 2021-12-07T00:03:07.647Z,1638835387.647 [Default:CheckIn:E] Running Loop=1 2021-12-07T00:03:08.052Z,1638835388.052 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 2.900351 min 2021-12-07T00:03:08.052Z,1638835388.052 [Default:CheckIn:E] Stopped 2021-12-07T00:03:08.052Z,1638835388.052 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-07T00:03:08.052Z,1638835388.052 [Default:CheckIn] Stopped 2021-12-07T00:03:08.052Z,1638835388.052 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-07T00:03:08.053Z,1638835388.053 [Default:CheckIn](INFO): Running loop #2 2021-12-07T00:03:08.053Z,1638835388.053 [Default:CheckIn] Running Loop=2 2021-12-07T00:03:08.053Z,1638835388.053 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-07T00:03:08.053Z,1638835388.053 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-07T00:04:08.251Z,1638835448.251 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-12-07T00:03:08.1Z 2021-12-07T00:04:08.251Z,1638835448.251 [Default:CheckIn:Read_GPS] Stopped 2021-12-07T00:04:08.251Z,1638835448.251 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-07T00:04:10.678Z,1638835450.678 [DAT](INFO): #Outgoing data=1 2021-12-07T00:04:10.679Z,1638835450.679 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-12-07T00:04:10.830Z,1638835450.830 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-12-07T00:04:15.278Z,1638835455.278 [DAT](INFO): DAT read: Forwarding Delay UpTx time:00:02:23.6378 2021-12-07T00:04:15.278Z,1638835455.278 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-12-07T00:04:21.076Z,1638835461.076 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2021-12-07T00:04:21.077Z,1638835461.077 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4 2021-12-07T00:04:21.077Z,1638835461.077 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-12-07T00:04:21.087Z,1638835461.087 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-12-07T00:04:21.477Z,1638835461.477 [DAT](INFO): DAT read: Rx Time:00:02:30.4339 2021-12-07T00:04:21.477Z,1638835461.477 [DAT](INFO): received an acoustic signal 2021-12-07T00:04:21.492Z,1638835461.492 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-12-07T00:04:21.492Z,1638835461.492 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4 2021-12-07T00:04:22.701Z,1638835462.701 [DAT](INFO): DAT read: 2021-12-07T00:04:22.702Z,1638835462.702 [DAT](INFO): DAT read: DATA(0002):~~ 2021-12-07T00:04:22.702Z,1638835462.702 [DAT](INFO): Got DATA 2 2021-12-07T00:04:22.703Z,1638835462.703 [DAT](INFO): DAT read: Source:001 Destination:004 2021-12-07T00:04:22.703Z,1638835462.703 [DAT](INFO): Got Src/Dest after DATA 2021-12-07T00:04:22.703Z,1638835462.703 [DAT](INFO): DATA Src=1, Dst=4 2021-12-07T00:04:22.705Z,1638835462.705 [DAT](INFO): DAT read: CRC:Pass MPD:02.6 PSNR:09.5 AGC:67 SPD:+0.0 CCERR:009 2021-12-07T00:04:22.705Z,1638835462.705 [DAT](INFO): Got CRC:Pass 2021-12-07T00:04:22.705Z,1638835462.705 [DAT](INFO): Got CRC:Pass 2021-12-07T00:04:22.706Z,1638835462.706 [DAT](INFO): Incoming data is intended for us 2021-12-07T00:04:22.706Z,1638835462.706 [DAT](DEBUG): In parseResponses, got ack so set commsState_ = SENDING_VERIFIED 2021-12-07T00:04:22.706Z,1638835462.706 [DAT](INFO): Got ack 2021-12-07T00:04:22.706Z,1638835462.706 [DAT](INFO): DAT read: 2021-12-07T00:04:22.707Z,1638835462.707 [DAT](INFO): DAT read: 2021-12-07T00:04:22.707Z,1638835462.707 [DAT](INFO): Sent 39 bytes from file Logs/20211206T235608/Courier0007.lzma.parts 2021-12-07T00:04:22.707Z,1638835462.707 [DAT](INFO): Packets left to send: 0 2021-12-07T00:04:22.742Z,1638835462.742 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2021-12-07T00:04:24.788Z,1638835464.788 [Default:CheckIn:Read_Iridium] Stopped 2021-12-07T00:04:24.788Z,1638835464.788 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-07T00:04:24.788Z,1638835464.788 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-07T00:05:27.452Z,1638835527.452 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-07T00:05:27.452Z,1638835527.452 [Default:CheckIn:C.Wait] Stopped 2021-12-07T00:05:27.452Z,1638835527.452 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-07T00:05:27.452Z,1638835527.452 [Default:CheckIn:D] Running Loop=1 2021-12-07T00:05:27.918Z,1638835527.918 [Default:CheckIn:D] Stopped 2021-12-07T00:05:27.918Z,1638835527.918 [Default:CheckIn:E] Running Loop=1 2021-12-07T00:05:28.281Z,1638835528.281 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 5.238193 min 2021-12-07T00:05:28.281Z,1638835528.281 [Default:CheckIn:E] Stopped 2021-12-07T00:05:28.281Z,1638835528.281 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-07T00:05:28.282Z,1638835528.282 [Default:CheckIn] Stopped 2021-12-07T00:05:28.282Z,1638835528.282 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-07T00:05:28.282Z,1638835528.282 [Default:CheckIn](INFO): Running loop #3 2021-12-07T00:05:28.282Z,1638835528.282 [Default:CheckIn] Running Loop=3 2021-12-07T00:05:28.282Z,1638835528.282 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-07T00:05:28.282Z,1638835528.282 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-07T00:06:21.996Z,1638835581.996 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2021-12-07T00:06:21.997Z,1638835581.997 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5 2021-12-07T00:06:21.997Z,1638835581.997 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-12-07T00:06:22.007Z,1638835582.007 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-12-07T00:06:22.494Z,1638835582.494 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-12-07T00:06:22.494Z,1638835582.494 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5 2021-12-07T00:06:28.455Z,1638835588.455 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-12-07T00:05:28.3Z 2021-12-07T00:06:28.455Z,1638835588.455 [Default:CheckIn:Read_GPS] Stopped 2021-12-07T00:06:28.455Z,1638835588.455 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-07T00:06:31.035Z,1638835591.035 [DAT](INFO): #Outgoing data=1 2021-12-07T00:06:31.035Z,1638835591.035 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-12-07T00:06:31.194Z,1638835591.194 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-12-07T00:06:36.362Z,1638835596.362 [DAT](INFO): DAT read: Forwarding Delay UpTx time:00:04:43.9866 2021-12-07T00:06:36.362Z,1638835596.362 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-12-07T00:06:41.829Z,1638835601.829 [DAT](INFO): DAT read: Rx Time:00:04:50.8366 2021-12-07T00:06:41.830Z,1638835601.830 [DAT](INFO): received an acoustic signal 2021-12-07T00:06:43.082Z,1638835603.082 [DAT](INFO): DAT read: 2021-12-07T00:06:43.083Z,1638835603.083 [DAT](INFO): DAT read: DATA(0002):~~ 2021-12-07T00:06:43.083Z,1638835603.083 [DAT](INFO): Got DATA 2 2021-12-07T00:06:43.085Z,1638835603.085 [DAT](INFO): DAT read: Source:001 Destination:004 2021-12-07T00:06:43.085Z,1638835603.085 [DAT](INFO): Got Src/Dest after DATA 2021-12-07T00:06:43.085Z,1638835603.085 [DAT](INFO): DATA Src=1, Dst=4 2021-12-07T00:06:43.087Z,1638835603.087 [DAT](INFO): DAT read: CRC:Pass MPD:02.7 PSNR:09.6 AGC:66 SPD:-0.1 CCERR:009 2021-12-07T00:06:43.087Z,1638835603.087 [DAT](INFO): Got CRC:Pass 2021-12-07T00:06:43.087Z,1638835603.087 [DAT](INFO): Got CRC:Pass 2021-12-07T00:06:43.087Z,1638835603.087 [DAT](INFO): Incoming data is intended for us 2021-12-07T00:06:43.087Z,1638835603.087 [DAT](DEBUG): In parseResponses, got ack so set commsState_ = SENDING_VERIFIED 2021-12-07T00:06:43.087Z,1638835603.087 [DAT](INFO): Got ack 2021-12-07T00:06:43.087Z,1638835603.087 [DAT](INFO): DAT read: 2021-12-07T00:06:43.088Z,1638835603.088 [DAT](INFO): DAT read: 2021-12-07T00:06:43.089Z,1638835603.089 [DAT](INFO): Sent 39 bytes from file Logs/20211206T235608/Courier0010.lzma.parts 2021-12-07T00:06:43.089Z,1638835603.089 [DAT](INFO): Packets left to send: 0 2021-12-07T00:06:43.092Z,1638835603.092 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2021-12-07T00:06:45.147Z,1638835605.147 [DAT](INFO): #Outgoing data=1 2021-12-07T00:06:45.154Z,1638835605.154 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-12-07T00:06:45.325Z,1638835605.325 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-12-07T00:06:49.924Z,1638835609.924 [DAT](INFO): DAT read: Forwarding Delay UpTx time:00:04:59.1364 2021-12-07T00:06:49.925Z,1638835609.925 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-12-07T00:07:03.479Z,1638835623.479 [NAL9602](FAULT): GPS failed to acquire within timeout. 2021-12-07T00:07:03.479Z,1638835623.479 [NAL9602] Data Fault, FailCount= 1 2021-12-07T00:07:03.479Z,1638835623.479 [NAL9602](ERROR): Data Fault 2021-12-07T00:07:03.515Z,1638835623.515 [CBIT](ERROR): Data Fault in component: NAL9602 2021-12-07T00:07:03.879Z,1638835623.879 [NAL9602](INFO): Powering down 2021-12-07T00:07:04.705Z,1638835624.705 [CBIT](INFO): Clearing failed state for component NAL9602 2021-12-07T00:07:04.705Z,1638835624.705 [NAL9602] No Fault, FailCount= 1 2021-12-07T00:07:08.345Z,1638835628.345 [DAT](INFO): DAT read: Rx Time:00:05:16.9881 2021-12-07T00:07:08.345Z,1638835628.345 [DAT](INFO): received an acoustic signal 2021-12-07T00:07:09.138Z,1638835629.138 [DAT](INFO): DAT read: 2021-12-07T00:07:09.139Z,1638835629.139 [DAT](INFO): DAT read: DATA(0002):~~ 2021-12-07T00:07:09.139Z,1638835629.139 [DAT](INFO): Got DATA 2 2021-12-07T00:07:09.140Z,1638835629.140 [DAT](INFO): DAT read: Source:001 Destination:004 2021-12-07T00:07:09.140Z,1638835629.140 [DAT](INFO): Got Src/Dest after DATA 2021-12-07T00:07:09.141Z,1638835629.141 [DAT](INFO): DATA Src=1, Dst=4 2021-12-07T00:07:09.142Z,1638835629.142 [DAT](INFO): DAT read: CRC:Pass MPD:03.5 PSNR:09.7 AGC:67 SPD:+0.0 CCERR:009 2021-12-07T00:07:09.142Z,1638835629.142 [DAT](INFO): Got CRC:Pass 2021-12-07T00:07:09.142Z,1638835629.142 [DAT](INFO): Got CRC:Pass 2021-12-07T00:07:09.143Z,1638835629.143 [DAT](INFO): Incoming data is intended for us 2021-12-07T00:07:09.143Z,1638835629.143 [DAT](DEBUG): In parseResponses, got ack so set commsState_ = SENDING_VERIFIED 2021-12-07T00:07:09.143Z,1638835629.143 [DAT](INFO): Got ack 2021-12-07T00:07:09.143Z,1638835629.143 [DAT](INFO): DAT read: 2021-12-07T00:07:09.145Z,1638835629.145 [DAT](INFO): DAT read: 2021-12-07T00:07:09.148Z,1638835629.148 [DAT](INFO): Sent 1016 bytes from file Logs/20211206T235608/Courier9002.lzma.parts 2021-12-07T00:07:09.148Z,1638835629.148 [DAT](INFO): Packets left to send: 5 2021-12-07T00:07:09.261Z,1638835629.261 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2021-12-07T00:07:11.123Z,1638835631.123 [DAT](INFO): #Outgoing data=1 2021-12-07T00:07:11.123Z,1638835631.123 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-12-07T00:07:11.270Z,1638835631.270 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-12-07T00:07:15.644Z,1638835635.644 [DAT](INFO): DAT read: Forwarding Delay UpTx time:00:05:25.0862 2021-12-07T00:07:15.644Z,1638835635.644 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-12-07T00:07:34.197Z,1638835654.197 [NAL9602](INFO): Powering up NAL9602 2021-12-07T00:07:34.199Z,1638835654.199 [DAT](INFO): DAT read: Rx Time:00:05:42.9374 2021-12-07T00:07:34.199Z,1638835654.200 [DAT](INFO): received an acoustic signal 2021-12-07T00:07:35.003Z,1638835655.003 [DAT](INFO): DAT read: 2021-12-07T00:07:35.004Z,1638835655.004 [DAT](INFO): DAT read: DATA(0002):~~ 2021-12-07T00:07:35.004Z,1638835655.004 [DAT](INFO): Got DATA 2 2021-12-07T00:07:35.005Z,1638835655.005 [DAT](INFO): DAT read: Source:001 Destination:004 2021-12-07T00:07:35.006Z,1638835655.006 [DAT](INFO): Got Src/Dest after DATA 2021-12-07T00:07:35.006Z,1638835655.006 [DAT](INFO): DATA Src=1, Dst=4 2021-12-07T00:07:35.007Z,1638835655.007 [DAT](INFO): DAT read: CRC:Pass MPD:03.5 PSNR:09.9 AGC:65 SPD:+0.0 CCERR:009 2021-12-07T00:07:35.007Z,1638835655.007 [DAT](INFO): Got CRC:Pass 2021-12-07T00:07:35.008Z,1638835655.008 [DAT](INFO): Got CRC:Pass 2021-12-07T00:07:35.008Z,1638835655.008 [DAT](INFO): Incoming data is intended for us 2021-12-07T00:07:35.008Z,1638835655.008 [DAT](DEBUG): In parseResponses, got ack so set commsState_ = SENDING_VERIFIED 2021-12-07T00:07:35.008Z,1638835655.008 [DAT](INFO): Got ack 2021-12-07T00:07:35.008Z,1638835655.008 [DAT](INFO): DAT read: 2021-12-07T00:07:35.009Z,1638835655.009 [DAT](INFO): DAT read: 2021-12-07T00:07:35.009Z,1638835655.009 [DAT](INFO): Sent 1016 bytes from file Logs/20211206T235608/Courier9002.lzma.parts 2021-12-07T00:07:35.010Z,1638835655.010 [DAT](INFO): Packets left to send: 4 2021-12-07T00:07:35.011Z,1638835655.011 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2021-12-07T00:07:36.996Z,1638835656.996 [DAT](INFO): #Outgoing data=1 2021-12-07T00:07:36.996Z,1638835656.996 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-12-07T00:07:37.142Z,1638835657.142 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-12-07T00:07:41.472Z,1638835661.472 [DAT](INFO): DAT read: Forwarding Delay UpTx time:00:05:50.9359 2021-12-07T00:07:41.472Z,1638835661.472 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-12-07T00:07:45.111Z,1638835665.111 [NAL9602](INFO): NAL9602 initialized 2021-12-07T00:08:01.009Z,1638835681.009 [DAT](INFO): DAT read: Rx Time:00:06:08.7878 2021-12-07T00:08:01.010Z,1638835681.010 [DAT](INFO): received an acoustic signal 2021-12-07T00:08:01.010Z,1638835681.010 [DAT](INFO): DAT read: 2021-12-07T00:08:01.011Z,1638835681.011 [DAT](INFO): DAT read: DATA(0002):~~ 2021-12-07T00:08:01.011Z,1638835681.011 [DAT](INFO): Got DATA 2 2021-12-07T00:08:01.012Z,1638835681.012 [DAT](INFO): DAT read: Source:001 Destination:004 2021-12-07T00:08:01.012Z,1638835681.012 [DAT](INFO): Got Src/Dest after DATA 2021-12-07T00:08:01.013Z,1638835681.013 [DAT](INFO): DATA Src=1, Dst=4 2021-12-07T00:08:01.014Z,1638835681.014 [DAT](INFO): DAT read: CRC:Pass MPD:03.4 PSNR:10.0 AGC:66 SPD:+0.0 CCERR:009 2021-12-07T00:08:01.014Z,1638835681.014 [DAT](INFO): Got CRC:Pass 2021-12-07T00:08:01.014Z,1638835681.014 [DAT](INFO): Got CRC:Pass 2021-12-07T00:08:01.014Z,1638835681.014 [DAT](INFO): Incoming data is intended for us 2021-12-07T00:08:01.014Z,1638835681.014 [DAT](DEBUG): In parseResponses, got ack so set commsState_ = SENDING_VERIFIED 2021-12-07T00:08:01.015Z,1638835681.015 [DAT](INFO): Got ack 2021-12-07T00:08:01.015Z,1638835681.015 [DAT](INFO): DAT read: 2021-12-07T00:08:01.015Z,1638835681.015 [DAT](INFO): DAT read: 2021-12-07T00:08:01.016Z,1638835681.016 [DAT](INFO): Sent 1016 bytes from file Logs/20211206T235608/Courier9002.lzma.parts 2021-12-07T00:08:01.016Z,1638835681.016 [DAT](INFO): Packets left to send: 3 2021-12-07T00:08:01.018Z,1638835681.018 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2021-12-07T00:08:02.790Z,1638835682.790 [DAT](INFO): #Outgoing data=1 2021-12-07T00:08:02.791Z,1638835682.791 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-12-07T00:08:02.890Z,1638835682.890 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-12-07T00:08:07.590Z,1638835687.590 [DAT](INFO): DAT read: Forwarding Delay UpTx time:00:06:16.6857 2021-12-07T00:08:07.590Z,1638835687.590 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-12-07T00:08:22.817Z,1638835702.817 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2021-12-07T00:08:22.817Z,1638835702.817 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6 2021-12-07T00:08:22.817Z,1638835702.817 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-12-07T00:08:22.828Z,1638835702.828 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-12-07T00:08:22.977Z,1638835702.977 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-12-07T00:08:22.977Z,1638835702.977 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6 2021-12-07T00:08:25.685Z,1638835705.685 [DAT](INFO): DAT read: Rx Time:00:06:34.5382 2021-12-07T00:08:25.686Z,1638835705.686 [DAT](INFO): received an acoustic signal 2021-12-07T00:08:27.969Z,1638835707.969 [DAT](INFO): DAT read: 2021-12-07T00:08:27.970Z,1638835707.970 [DAT](INFO): DAT read: DATA(0002):~~ 2021-12-07T00:08:27.970Z,1638835707.970 [DAT](INFO): Got DATA 2 2021-12-07T00:08:27.971Z,1638835707.971 [DAT](INFO): DAT read: Source:001 Destination:004 2021-12-07T00:08:27.971Z,1638835707.971 [DAT](INFO): Got Src/Dest after DATA 2021-12-07T00:08:27.971Z,1638835707.971 [DAT](INFO): DATA Src=1, Dst=4 2021-12-07T00:08:27.973Z,1638835707.973 [DAT](INFO): DAT read: CRC:Pass MPD:03.4 PSNR:10.2 AGC:65 SPD:+0.0 CCERR:010 2021-12-07T00:08:27.973Z,1638835707.973 [DAT](INFO): Got CRC:Pass 2021-12-07T00:08:27.973Z,1638835707.973 [DAT](INFO): Got CRC:Pass 2021-12-07T00:08:27.974Z,1638835707.974 [DAT](INFO): Incoming data is intended for us 2021-12-07T00:08:27.974Z,1638835707.974 [DAT](DEBUG): In parseResponses, got ack so set commsState_ = SENDING_VERIFIED 2021-12-07T00:08:27.974Z,1638835707.974 [DAT](INFO): Got ack 2021-12-07T00:08:27.974Z,1638835707.974 [DAT](INFO): DAT read: 2021-12-07T00:08:27.975Z,1638835707.975 [DAT](INFO): DAT read: 2021-12-07T00:08:27.975Z,1638835707.975 [DAT](INFO): Sent 1016 bytes from file Logs/20211206T235608/Courier9002.lzma.parts 2021-12-07T00:08:27.975Z,1638835707.975 [DAT](INFO): Packets left to send: 2 2021-12-07T00:08:27.977Z,1638835707.977 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2021-12-07T00:08:29.716Z,1638835709.716 [DAT](INFO): #Outgoing data=1 2021-12-07T00:08:29.717Z,1638835709.717 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-12-07T00:08:29.869Z,1638835709.869 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-12-07T00:08:34.622Z,1638835714.622 [DAT](INFO): DAT read: Forwarding Delay UpTx time:00:06:43.6854 2021-12-07T00:08:34.622Z,1638835714.622 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-12-07T00:08:52.665Z,1638835732.665 [DAT](INFO): DAT read: Rx Time:00:07:01.5387 2021-12-07T00:08:52.665Z,1638835732.665 [DAT](INFO): received an acoustic signal 2021-12-07T00:08:54.721Z,1638835734.721 [DAT](INFO): DAT read: 2021-12-07T00:08:54.722Z,1638835734.722 [DAT](INFO): DAT read: DATA(0002):~~ 2021-12-07T00:08:54.722Z,1638835734.722 [DAT](INFO): Got DATA 2 2021-12-07T00:08:54.723Z,1638835734.723 [DAT](INFO): DAT read: Source:001 Destination:004 2021-12-07T00:08:54.723Z,1638835734.723 [DAT](INFO): Got Src/Dest after DATA 2021-12-07T00:08:54.723Z,1638835734.723 [DAT](INFO): DATA Src=1, Dst=4 2021-12-07T00:08:54.725Z,1638835734.725 [DAT](INFO): DAT read: CRC:Pass MPD:03.4 PSNR:10.4 AGC:67 SPD:+0.0 CCERR:009 2021-12-07T00:08:54.725Z,1638835734.725 [DAT](INFO): Got CRC:Pass 2021-12-07T00:08:54.725Z,1638835734.725 [DAT](INFO): Got CRC:Pass 2021-12-07T00:08:54.725Z,1638835734.725 [DAT](INFO): Incoming data is intended for us 2021-12-07T00:08:54.725Z,1638835734.725 [DAT](DEBUG): In parseResponses, got ack so set commsState_ = SENDING_VERIFIED 2021-12-07T00:08:54.725Z,1638835734.725 [DAT](INFO): Got ack 2021-12-07T00:08:54.726Z,1638835734.726 [DAT](INFO): DAT read: 2021-12-07T00:08:54.726Z,1638835734.726 [DAT](INFO): DAT read: 2021-12-07T00:08:54.727Z,1638835734.727 [DAT](INFO): Sent 1016 bytes from file Logs/20211206T235608/Courier9002.lzma.parts 2021-12-07T00:08:54.727Z,1638835734.727 [DAT](INFO): Packets left to send: 1 2021-12-07T00:08:54.770Z,1638835734.770 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2021-12-07T00:08:56.520Z,1638835736.520 [DAT](INFO): #Outgoing data=1 2021-12-07T00:08:56.520Z,1638835736.520 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-12-07T00:08:56.622Z,1638835736.622 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-12-07T00:09:00.642Z,1638835740.642 [DAT](INFO): DAT read: Forwarding Delay UpTx time:00:07:09.6352 2021-12-07T00:09:00.642Z,1638835740.642 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-12-07T00:09:11.025Z,1638835751.025 [DAT](INFO): DAT read: Rx Time:00:07:18.6389 2021-12-07T00:09:11.026Z,1638835751.026 [DAT](INFO): received an acoustic signal 2021-12-07T00:09:11.026Z,1638835751.026 [DAT](INFO): DAT read: 2021-12-07T00:09:11.027Z,1638835751.027 [DAT](INFO): DAT read: DATA(0002):~~ 2021-12-07T00:09:11.027Z,1638835751.027 [DAT](INFO): Got DATA 2 2021-12-07T00:09:11.029Z,1638835751.029 [DAT](INFO): DAT read: Source:001 Destination:004 2021-12-07T00:09:11.029Z,1638835751.029 [DAT](INFO): Got Src/Dest after DATA 2021-12-07T00:09:11.029Z,1638835751.029 [DAT](INFO): DATA Src=1, Dst=4 2021-12-07T00:09:11.031Z,1638835751.031 [DAT](INFO): DAT read: CRC:Pass MPD:03.5 PSNR:10.4 AGC:66 SPD:+0.0 CCERR:010 2021-12-07T00:09:11.031Z,1638835751.031 [DAT](INFO): Got CRC:Pass 2021-12-07T00:09:11.031Z,1638835751.031 [DAT](INFO): Got CRC:Pass 2021-12-07T00:09:11.031Z,1638835751.031 [DAT](INFO): Incoming data is intended for us 2021-12-07T00:09:11.031Z,1638835751.031 [DAT](DEBUG): In parseResponses, got ack so set commsState_ = SENDING_VERIFIED 2021-12-07T00:09:11.031Z,1638835751.031 [DAT](INFO): Got ack 2021-12-07T00:09:11.031Z,1638835751.031 [DAT](INFO): DAT read: 2021-12-07T00:09:11.085Z,1638835751.085 [DAT](INFO): DAT read: 2021-12-07T00:09:11.086Z,1638835751.086 [DAT](INFO): Sent 233 bytes from file Logs/20211206T235608/Courier9002.lzma.parts 2021-12-07T00:09:11.086Z,1638835751.086 [DAT](INFO): Packets left to send: 0 2021-12-07T00:09:11.088Z,1638835751.088 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2021-12-07T00:09:12.887Z,1638835752.887 [Default:CheckIn:Read_Iridium] Stopped 2021-12-07T00:09:12.887Z,1638835752.887 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-07T00:09:12.888Z,1638835752.888 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-07T00:10:13.115Z,1638835813.115 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-07T00:10:13.115Z,1638835813.115 [Default:CheckIn:C.Wait] Stopped 2021-12-07T00:10:13.115Z,1638835813.115 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-07T00:10:13.115Z,1638835813.115 [Default:CheckIn:D] Running Loop=1 2021-12-07T00:10:13.517Z,1638835813.517 [Default:CheckIn:D] Stopped 2021-12-07T00:10:13.517Z,1638835813.517 [Default:CheckIn:E] Running Loop=1 2021-12-07T00:10:13.934Z,1638835813.934 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 9.998178 min 2021-12-07T00:10:13.934Z,1638835813.934 [Default:CheckIn:E] Stopped 2021-12-07T00:10:13.934Z,1638835813.934 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-07T00:10:13.934Z,1638835813.934 [Default:CheckIn] Stopped 2021-12-07T00:10:13.934Z,1638835813.934 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-07T00:10:13.935Z,1638835813.935 [Default:CheckIn](INFO): Running loop #4 2021-12-07T00:10:13.935Z,1638835813.935 [Default:CheckIn] Running Loop=4 2021-12-07T00:10:13.935Z,1638835813.935 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-07T00:10:13.935Z,1638835813.935 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-07T00:10:23.688Z,1638835823.688 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2021-12-07T00:10:23.689Z,1638835823.689 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7 2021-12-07T00:10:23.689Z,1638835823.689 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-12-07T00:10:23.700Z,1638835823.700 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-12-07T00:10:24.068Z,1638835824.068 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-12-07T00:10:24.068Z,1638835824.068 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7 2021-12-07T00:11:14.137Z,1638835874.137 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-12-07T00:10:13.9Z 2021-12-07T00:11:14.137Z,1638835874.137 [Default:CheckIn:Read_GPS] Stopped 2021-12-07T00:11:14.137Z,1638835874.137 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-07T00:11:16.561Z,1638835876.561 [DAT](INFO): #Outgoing data=1 2021-12-07T00:11:16.561Z,1638835876.561 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-12-07T00:11:16.658Z,1638835876.658 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-12-07T00:11:20.638Z,1638835880.638 [DAT](INFO): DAT read: Forwarding Delay UpTx time:00:09:29.4339 2021-12-07T00:11:20.638Z,1638835880.638 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-12-07T00:11:20.652Z,1638835880.652 [CBIT](INFO): Clearing failed state for component DropWeight 2021-12-07T00:11:20.653Z,1638835880.653 [DropWeight] No Fault, FailCount= 1 2021-12-07T00:11:31.685Z,1638835891.685 [DAT](FAULT): Ack receipt timeout failure. 2021-12-07T00:11:31.685Z,1638835891.685 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2021-12-07T00:11:33.647Z,1638835893.647 [DAT](INFO): #Outgoing data=1 2021-12-07T00:11:33.647Z,1638835893.647 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-12-07T00:11:33.736Z,1638835893.736 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-12-07T00:11:36.990Z,1638835896.990 [DAT](INFO): DAT read: Forwarding Delay UpTx time:00:09:46.5337 2021-12-07T00:11:36.990Z,1638835896.990 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-12-07T00:11:48.093Z,1638835908.093 [DAT](FAULT): Ack receipt timeout failure. 2021-12-07T00:11:48.093Z,1638835908.093 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2021-12-07T00:11:50.053Z,1638835910.053 [DAT](INFO): #Outgoing data=2 2021-12-07T00:11:50.053Z,1638835910.053 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-12-07T00:11:50.146Z,1638835910.146 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-12-07T00:11:53.646Z,1638835913.646 [DAT](INFO): DAT read: Forwarding Delay UpTx time:00:10:02.9335 2021-12-07T00:11:53.646Z,1638835913.646 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-12-07T00:12:06.773Z,1638835926.773 [DAT](FAULT): Ack receipt timeout failure. 2021-12-07T00:12:06.773Z,1638835926.773 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2021-12-07T00:12:11.002Z,1638835931.002 [DAT](INFO): #Outgoing data=3 2021-12-07T00:12:11.002Z,1638835931.002 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-12-07T00:12:11.297Z,1638835931.297 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-12-07T00:12:17.870Z,1638835937.870 [DAT](INFO): DAT read: Forwarding Delay UpTx time:00:10:24.0833 2021-12-07T00:12:17.871Z,1638835937.871 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-12-07T00:12:24.634Z,1638835944.634 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2021-12-07T00:12:24.634Z,1638835944.634 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8 2021-12-07T00:12:24.634Z,1638835944.634 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-12-07T00:12:24.668Z,1638835944.668 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-12-07T00:12:24.991Z,1638835944.991 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-12-07T00:12:24.991Z,1638835944.991 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8 2021-12-07T00:12:28.997Z,1638835948.997 [DAT](FAULT): Ack receipt timeout failure. 2021-12-07T00:12:28.997Z,1638835948.997 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2021-12-07T00:12:29.405Z,1638835949.405 [DAT](INFO): Sent 39 bytes from file Logs/20211206T235608/Courier0013.lzma.parts 2021-12-07T00:12:29.405Z,1638835949.405 [DAT](INFO): Packets left to send: 0 2021-12-07T00:12:29.407Z,1638835949.407 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2021-12-07T00:12:31.719Z,1638835951.719 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-12-07T00:12:31.724Z,1638835951.724 [Default:CheckIn:Read_Iridium] Stopped 2021-12-07T00:12:31.724Z,1638835951.724 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-07T00:12:31.724Z,1638835951.724 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-07T00:12:31.825Z,1638835951.825 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-12-07T00:12:35.398Z,1638835955.398 [DAT](INFO): DAT read: Forwarding Delay UpTx time:00:10:44.6332 2021-12-07T00:12:35.398Z,1638835955.398 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-12-07T00:12:46.762Z,1638835966.762 [DAT](FAULT): Ack receipt timeout failure. 2021-12-07T00:12:46.763Z,1638835966.763 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2021-12-07T00:12:47.167Z,1638835967.167 [DAT](DEBUG): In sendingVerified, sbd done so set commsState_ = SENDING_FILL_BUFFER 2021-12-07T00:12:47.569Z,1638835967.569 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-12-07T00:12:47.986Z,1638835967.986 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-12-07T00:12:51.284Z,1638835971.284 [DAT](INFO): DAT read: Forwarding Delay UpTx time:00:11:00.7830 2021-12-07T00:12:51.285Z,1638835971.285 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-12-07T00:13:02.517Z,1638835982.517 [DAT](FAULT): Ack receipt timeout failure. 2021-12-07T00:13:02.517Z,1638835982.517 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2021-12-07T00:13:02.933Z,1638835982.933 [DAT](DEBUG): In sendingVerified, sbd done so set commsState_ = SENDING_FILL_BUFFER 2021-12-07T00:13:03.341Z,1638835983.341 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-12-07T00:13:03.741Z,1638835983.741 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-12-07T00:13:06.963Z,1638835986.963 [DAT](INFO): DAT read: Forwarding Delay UpTx time:00:11:16.5329 2021-12-07T00:13:06.963Z,1638835986.963 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-12-07T00:13:18.293Z,1638835998.293 [DAT](FAULT): Ack receipt timeout failure. 2021-12-07T00:13:18.293Z,1638835998.293 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2021-12-07T00:13:18.705Z,1638835998.705 [DAT](DEBUG): In sendingVerified, sbd done so set commsState_ = SENDING_FILL_BUFFER 2021-12-07T00:13:32.014Z,1638836012.014 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-07T00:13:32.014Z,1638836012.014 [Default:CheckIn:C.Wait] Stopped 2021-12-07T00:13:32.014Z,1638836012.014 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-07T00:13:32.014Z,1638836012.014 [Default:CheckIn:D] Running Loop=1 2021-12-07T00:13:32.420Z,1638836012.420 [Default:CheckIn:D] Stopped 2021-12-07T00:13:32.420Z,1638836012.420 [Default:CheckIn:E] Running Loop=1 2021-12-07T00:13:32.844Z,1638836012.844 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 13.313221 min 2021-12-07T00:13:32.845Z,1638836012.845 [Default:CheckIn:E] Stopped 2021-12-07T00:13:32.845Z,1638836012.845 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-07T00:13:32.845Z,1638836012.845 [Default:CheckIn] Stopped 2021-12-07T00:13:32.845Z,1638836012.845 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-07T00:13:32.845Z,1638836012.845 [Default:CheckIn](INFO): Running loop #5 2021-12-07T00:13:32.845Z,1638836012.845 [Default:CheckIn] Running Loop=5 2021-12-07T00:13:32.845Z,1638836012.845 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-07T00:13:32.846Z,1638836012.846 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-07T00:14:25.791Z,1638836065.791 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2021-12-07T00:14:25.791Z,1638836065.791 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 9 2021-12-07T00:14:25.791Z,1638836065.791 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-12-07T00:14:25.802Z,1638836065.802 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-12-07T00:14:26.191Z,1638836066.191 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-12-07T00:14:26.191Z,1638836066.191 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 9 2021-12-07T00:14:33.019Z,1638836073.019 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-12-07T00:13:32.8Z 2021-12-07T00:14:33.019Z,1638836073.019 [Default:CheckIn:Read_GPS] Stopped 2021-12-07T00:14:33.020Z,1638836073.020 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-07T00:14:35.409Z,1638836075.409 [DAT](INFO): #Outgoing data=1 2021-12-07T00:14:35.410Z,1638836075.410 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-12-07T00:14:35.522Z,1638836075.522 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-12-07T00:14:38.866Z,1638836078.866 [DAT](INFO): DAT read: Forwarding Delay UpTx time:00:12:48.3320 2021-12-07T00:14:38.866Z,1638836078.866 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-12-07T00:14:49.923Z,1638836089.923 [DAT](FAULT): Ack receipt timeout failure. 2021-12-07T00:14:49.924Z,1638836089.924 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2021-12-07T00:14:50.309Z,1638836090.309 [DAT](INFO): Sent 39 bytes from file Logs/20211206T235608/Courier0016.lzma.parts 2021-12-07T00:14:50.309Z,1638836090.309 [DAT](INFO): Packets left to send: 0 2021-12-07T00:14:50.312Z,1638836090.312 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2021-12-07T00:14:52.347Z,1638836092.347 [Default:CheckIn:Read_Iridium] Stopped 2021-12-07T00:14:52.347Z,1638836092.347 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-07T00:14:52.347Z,1638836092.347 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-07T00:15:54.954Z,1638836154.954 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-07T00:15:54.954Z,1638836154.954 [Default:CheckIn:C.Wait] Stopped 2021-12-07T00:15:54.954Z,1638836154.954 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-07T00:15:54.954Z,1638836154.954 [Default:CheckIn:D] Running Loop=1 2021-12-07T00:15:55.359Z,1638836155.359 [Default:CheckIn:D] Stopped 2021-12-07T00:15:55.359Z,1638836155.359 [Default:CheckIn:E] Running Loop=1 2021-12-07T00:15:55.762Z,1638836155.762 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 15.695549 min 2021-12-07T00:15:55.762Z,1638836155.762 [Default:CheckIn:E] Stopped 2021-12-07T00:15:55.762Z,1638836155.762 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-07T00:15:55.762Z,1638836155.762 [Default:CheckIn] Stopped 2021-12-07T00:15:55.762Z,1638836155.762 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-07T00:15:55.763Z,1638836155.763 [Default:CheckIn](INFO): Running loop #6 2021-12-07T00:15:55.763Z,1638836155.763 [Default:CheckIn] Running Loop=6 2021-12-07T00:15:55.763Z,1638836155.763 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-07T00:15:55.763Z,1638836155.763 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-07T00:16:26.877Z,1638836186.877 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2021-12-07T00:16:26.877Z,1638836186.877 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 10 2021-12-07T00:16:26.877Z,1638836186.877 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-12-07T00:16:26.888Z,1638836186.888 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-12-07T00:16:27.304Z,1638836187.304 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-12-07T00:16:27.304Z,1638836187.304 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 10 2021-12-07T00:16:55.982Z,1638836215.982 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-12-07T00:15:55.8Z 2021-12-07T00:16:55.982Z,1638836215.982 [Default:CheckIn:Read_GPS] Stopped 2021-12-07T00:16:55.982Z,1638836215.982 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-07T00:16:58.339Z,1638836218.339 [DAT](INFO): #Outgoing data=1 2021-12-07T00:16:58.340Z,1638836218.340 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-12-07T00:16:58.422Z,1638836218.422 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-12-07T00:17:02.046Z,1638836222.046 [DAT](INFO): DAT read: Forwarding Delay UpTx time:00:15:11.2305 2021-12-07T00:17:02.046Z,1638836222.046 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-12-07T00:17:13.098Z,1638836233.098 [DAT](FAULT): Ack receipt timeout failure. 2021-12-07T00:17:13.098Z,1638836233.098 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2021-12-07T00:17:13.489Z,1638836233.489 [DAT](INFO): Sent 39 bytes from file Logs/20211206T235608/Courier0019.lzma.parts 2021-12-07T00:17:13.489Z,1638836233.489 [DAT](INFO): Packets left to send: 0 2021-12-07T00:17:13.492Z,1638836233.492 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2021-12-07T00:17:15.473Z,1638836235.473 [Default:CheckIn:Read_Iridium] Stopped 2021-12-07T00:17:15.473Z,1638836235.473 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-07T00:17:15.474Z,1638836235.474 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-07T00:17:46.155Z,1638836266.155 [NAL9602](FAULT): GPS failed to acquire within timeout. 2021-12-07T00:17:46.155Z,1638836266.155 [NAL9602] Data Fault, FailCount= 2 2021-12-07T00:17:46.155Z,1638836266.155 [NAL9602](ERROR): Data Fault 2021-12-07T00:17:46.197Z,1638836266.197 [CBIT](ERROR): Data Fault in component: NAL9602 2021-12-07T00:17:46.559Z,1638836266.559 [NAL9602](INFO): Powering down 2021-12-07T00:17:47.383Z,1638836267.383 [CBIT](INFO): Clearing failed state for component NAL9602 2021-12-07T00:17:47.383Z,1638836267.383 [NAL9602] No Fault, FailCount= 2 2021-12-07T00:18:15.715Z,1638836295.715 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-07T00:18:15.715Z,1638836295.715 [Default:CheckIn:C.Wait] Stopped 2021-12-07T00:18:15.715Z,1638836295.715 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-07T00:18:15.715Z,1638836295.715 [Default:CheckIn:D] Running Loop=1 2021-12-07T00:18:16.061Z,1638836296.061 [Default:CheckIn:D] Stopped 2021-12-07T00:18:16.061Z,1638836296.061 [Default:CheckIn:E] Running Loop=1 2021-12-07T00:18:16.481Z,1638836296.481 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 18.040576 min 2021-12-07T00:18:16.482Z,1638836296.482 [Default:CheckIn:E] Stopped 2021-12-07T00:18:16.482Z,1638836296.482 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-07T00:18:16.482Z,1638836296.482 [Default:CheckIn] Stopped 2021-12-07T00:18:16.482Z,1638836296.482 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-07T00:18:16.482Z,1638836296.482 [Default:CheckIn](INFO): Running loop #7 2021-12-07T00:18:16.482Z,1638836296.482 [Default:CheckIn] Running Loop=7 2021-12-07T00:18:16.482Z,1638836296.482 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-07T00:18:16.482Z,1638836296.482 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-07T00:18:16.877Z,1638836296.877 [NAL9602](INFO): Powering up NAL9602 2021-12-07T00:18:27.767Z,1638836307.767 [NAL9602](INFO): NAL9602 initialized 2021-12-07T00:18:27.772Z,1638836307.772 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2021-12-07T00:18:27.772Z,1638836307.772 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 11 2021-12-07T00:18:27.772Z,1638836307.772 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-12-07T00:18:27.783Z,1638836307.783 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-12-07T00:18:28.187Z,1638836308.187 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-12-07T00:18:28.187Z,1638836308.187 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 11 2021-12-07T00:19:16.677Z,1638836356.677 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-12-07T00:18:16.5Z 2021-12-07T00:19:16.677Z,1638836356.677 [Default:CheckIn:Read_GPS] Stopped 2021-12-07T00:19:16.677Z,1638836356.677 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-07T00:19:19.054Z,1638836359.054 [DAT](INFO): #Outgoing data=1 2021-12-07T00:19:19.055Z,1638836359.055 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-12-07T00:19:19.166Z,1638836359.166 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-12-07T00:19:22.786Z,1638836362.786 [DAT](INFO): DAT read: Forwarding Delay UpTx time:00:17:31.9792 2021-12-07T00:19:22.786Z,1638836362.786 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-12-07T00:19:33.885Z,1638836373.885 [DAT](FAULT): Ack receipt timeout failure. 2021-12-07T00:19:33.885Z,1638836373.885 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2021-12-07T00:19:34.281Z,1638836374.281 [DAT](INFO): Sent 39 bytes from file Logs/20211206T235608/Courier0022.lzma.parts 2021-12-07T00:19:34.281Z,1638836374.281 [DAT](INFO): Packets left to send: 0 2021-12-07T00:19:34.284Z,1638836374.284 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2021-12-07T00:19:38.593Z,1638836378.593 [Default:CheckIn:Read_Iridium] Stopped 2021-12-07T00:19:38.593Z,1638836378.593 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-07T00:19:38.593Z,1638836378.593 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-07T00:20:05.680Z,1638836405.680 [BPC1](ERROR): BPC1A: No match for serial number 1717 in BPC1A's battery stick inventory (sticks 1-32 in onboard configuration file). 2021-12-07T00:20:28.733Z,1638836428.733 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2021-12-07T00:20:28.733Z,1638836428.733 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 12 2021-12-07T00:20:28.733Z,1638836428.733 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-12-07T00:20:28.744Z,1638836428.744 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-12-07T00:20:29.164Z,1638836429.164 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-12-07T00:20:29.164Z,1638836429.164 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 12 2021-12-07T00:20:38.817Z,1638836438.817 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-07T00:20:38.817Z,1638836438.817 [Default:CheckIn:C.Wait] Stopped 2021-12-07T00:20:38.817Z,1638836438.817 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-07T00:20:38.818Z,1638836438.818 [Default:CheckIn:D] Running Loop=1 2021-12-07T00:20:39.222Z,1638836439.222 [Default:CheckIn:D] Stopped 2021-12-07T00:20:39.222Z,1638836439.222 [Default:CheckIn:E] Running Loop=1 2021-12-07T00:20:39.629Z,1638836439.629 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 20.426593 min 2021-12-07T00:20:39.629Z,1638836439.629 [Default:CheckIn:E] Stopped 2021-12-07T00:20:39.629Z,1638836439.629 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-07T00:20:39.630Z,1638836439.630 [Default:CheckIn] Stopped 2021-12-07T00:20:39.630Z,1638836439.630 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-07T00:20:39.630Z,1638836439.630 [Default:CheckIn](INFO): Running loop #8 2021-12-07T00:20:39.630Z,1638836439.630 [Default:CheckIn] Running Loop=8 2021-12-07T00:20:39.630Z,1638836439.630 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-07T00:20:39.630Z,1638836439.630 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-07T00:21:39.826Z,1638836499.826 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-12-07T00:20:39.6Z 2021-12-07T00:21:39.826Z,1638836499.826 [Default:CheckIn:Read_GPS] Stopped 2021-12-07T00:21:39.826Z,1638836499.826 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-07T00:21:42.258Z,1638836502.258 [DAT](INFO): #Outgoing data=1 2021-12-07T00:21:42.258Z,1638836502.258 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-12-07T00:21:42.366Z,1638836502.366 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-12-07T00:21:45.963Z,1638836505.963 [DAT](INFO): DAT read: Forwarding Delay UpTx time:00:19:55.1779 2021-12-07T00:21:45.963Z,1638836505.963 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-12-07T00:21:57.421Z,1638836517.421 [DAT](FAULT): Ack receipt timeout failure. 2021-12-07T00:21:57.421Z,1638836517.421 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2021-12-07T00:22:00.246Z,1638836520.246 [DAT](INFO): Sent 39 bytes from file Logs/20211206T235608/Courier0025.lzma.parts 2021-12-07T00:22:00.246Z,1638836520.246 [DAT](INFO): Packets left to send: 0 2021-12-07T00:22:00.249Z,1638836520.249 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2021-12-07T00:22:02.821Z,1638836522.821 [Default:CheckIn:Read_Iridium] Stopped 2021-12-07T00:22:02.821Z,1638836522.821 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-07T00:22:02.822Z,1638836522.822 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-07T00:22:29.526Z,1638836549.526 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2021-12-07T00:22:29.526Z,1638836549.526 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 13 2021-12-07T00:22:29.526Z,1638836549.526 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-12-07T00:22:29.566Z,1638836549.566 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-12-07T00:22:29.928Z,1638836549.928 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-12-07T00:22:29.928Z,1638836549.928 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 13 2021-12-07T00:23:03.069Z,1638836583.069 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-07T00:23:03.069Z,1638836583.069 [Default:CheckIn:C.Wait] Stopped 2021-12-07T00:23:03.069Z,1638836583.069 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-07T00:23:03.069Z,1638836583.069 [Default:CheckIn:D] Running Loop=1 2021-12-07T00:23:03.473Z,1638836583.473 [Default:CheckIn:D] Stopped 2021-12-07T00:23:03.473Z,1638836583.473 [Default:CheckIn:E] Running Loop=1 2021-12-07T00:23:03.865Z,1638836583.865 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 22.830772 min 2021-12-07T00:23:03.865Z,1638836583.865 [Default:CheckIn:E] Stopped 2021-12-07T00:23:03.865Z,1638836583.865 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-07T00:23:03.865Z,1638836583.865 [Default:CheckIn] Stopped 2021-12-07T00:23:03.865Z,1638836583.865 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-07T00:23:03.865Z,1638836583.865 [Default:CheckIn](INFO): Running loop #9 2021-12-07T00:23:03.866Z,1638836583.866 [Default:CheckIn] Running Loop=9 2021-12-07T00:23:03.866Z,1638836583.866 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-07T00:23:03.866Z,1638836583.866 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-07T00:24:04.054Z,1638836644.054 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-12-07T00:23:03.9Z 2021-12-07T00:24:04.054Z,1638836644.054 [Default:CheckIn:Read_GPS] Stopped 2021-12-07T00:24:04.054Z,1638836644.054 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-07T00:24:06.448Z,1638836646.448 [DAT](INFO): #Outgoing data=1 2021-12-07T00:24:06.448Z,1638836646.448 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-12-07T00:24:06.598Z,1638836646.598 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-12-07T00:24:11.330Z,1638836651.330 [DAT](INFO): DAT read: Forwarding Delay UpTx time:00:22:19.3766 2021-12-07T00:24:11.330Z,1638836651.330 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-12-07T00:24:22.461Z,1638836662.461 [DAT](FAULT): Ack receipt timeout failure. 2021-12-07T00:24:22.461Z,1638836662.461 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2021-12-07T00:24:22.861Z,1638836662.861 [DAT](INFO): Sent 39 bytes from file Logs/20211206T235608/Courier0028.lzma.parts 2021-12-07T00:24:22.861Z,1638836662.861 [DAT](INFO): Packets left to send: 0 2021-12-07T00:24:22.864Z,1638836662.864 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2021-12-07T00:24:24.853Z,1638836664.853 [Default:CheckIn:Read_Iridium] Stopped 2021-12-07T00:24:24.853Z,1638836664.853 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-07T00:24:24.853Z,1638836664.853 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-07T00:24:30.538Z,1638836670.538 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2021-12-07T00:24:30.538Z,1638836670.538 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 14 2021-12-07T00:24:30.538Z,1638836670.538 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-12-07T00:24:30.549Z,1638836670.549 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-12-07T00:24:31.009Z,1638836671.009 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-12-07T00:24:31.009Z,1638836671.009 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 14 2021-12-07T00:25:25.097Z,1638836725.097 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-07T00:25:25.097Z,1638836725.097 [Default:CheckIn:C.Wait] Stopped 2021-12-07T00:25:25.097Z,1638836725.097 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-07T00:25:25.097Z,1638836725.097 [Default:CheckIn:D] Running Loop=1 2021-12-07T00:25:25.484Z,1638836725.484 [Default:CheckIn:D] Stopped 2021-12-07T00:25:25.484Z,1638836725.484 [Default:CheckIn:E] Running Loop=1 2021-12-07T00:25:25.934Z,1638836725.934 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 25.197630 min 2021-12-07T00:25:25.935Z,1638836725.935 [Default:CheckIn:E] Stopped 2021-12-07T00:25:25.935Z,1638836725.935 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-07T00:25:25.935Z,1638836725.935 [Default:CheckIn] Stopped 2021-12-07T00:25:25.935Z,1638836725.935 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-07T00:25:25.935Z,1638836725.935 [Default:CheckIn](INFO): Running loop #10 2021-12-07T00:25:25.935Z,1638836725.935 [Default:CheckIn] Running Loop=10 2021-12-07T00:25:25.935Z,1638836725.935 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-07T00:25:25.935Z,1638836725.935 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-07T00:26:26.105Z,1638836786.105 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-12-07T00:25:25.9Z 2021-12-07T00:26:26.105Z,1638836786.105 [Default:CheckIn:Read_GPS] Stopped 2021-12-07T00:26:26.105Z,1638836786.105 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-07T00:26:28.475Z,1638836788.475 [DAT](INFO): #Outgoing data=1 2021-12-07T00:26:28.475Z,1638836788.475 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-12-07T00:26:28.621Z,1638836788.621 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-12-07T00:26:33.762Z,1638836793.762 [DAT](INFO): DAT read: Forwarding Delay UpTx time:00:24:41.4254 2021-12-07T00:26:33.762Z,1638836793.762 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-12-07T00:26:33.766Z,1638836793.766 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2021-12-07T00:26:33.766Z,1638836793.766 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 15 2021-12-07T00:26:33.766Z,1638836793.766 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-12-07T00:26:33.777Z,1638836793.777 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-12-07T00:26:33.870Z,1638836793.870 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-12-07T00:26:33.870Z,1638836793.870 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 15 2021-12-07T00:26:44.861Z,1638836804.861 [DAT](FAULT): Ack receipt timeout failure. 2021-12-07T00:26:44.861Z,1638836804.861 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2021-12-07T00:26:45.252Z,1638836805.252 [DAT](INFO): Sent 39 bytes from file Logs/20211206T235608/Courier0031.lzma.parts 2021-12-07T00:26:45.253Z,1638836805.253 [DAT](INFO): Packets left to send: 0 2021-12-07T00:26:45.255Z,1638836805.255 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2021-12-07T00:26:47.343Z,1638836807.343 [Default:CheckIn:Read_Iridium] Stopped 2021-12-07T00:26:47.343Z,1638836807.343 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-07T00:26:47.344Z,1638836807.344 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-07T00:27:19.145Z,1638836839.145 [BPC1](ERROR): Battery stick #38 (s/n: 0139) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4AD0. 2021-12-07T00:27:19.146Z,1638836839.146 [BPC1](INFO): Calculating totals. Valid battery stick count: 55. Valid reserve battery stick count: 5. 2021-12-07T00:27:19.149Z,1638836839.149 [BPC1](ERROR): Failed to receive data from all sticks prior to timeout. Will not retry this scan cycle. 2021-12-07T00:27:47.839Z,1638836867.839 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-07T00:27:47.839Z,1638836867.839 [Default:CheckIn:C.Wait] Stopped 2021-12-07T00:27:47.839Z,1638836867.839 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-07T00:27:47.839Z,1638836867.839 [Default:CheckIn:D] Running Loop=1 2021-12-07T00:27:48.249Z,1638836868.249 [Default:CheckIn:D] Stopped 2021-12-07T00:27:48.249Z,1638836868.249 [Default:CheckIn:E] Running Loop=1 2021-12-07T00:27:48.633Z,1638836868.633 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 27.577037 min 2021-12-07T00:27:48.633Z,1638836868.633 [Default:CheckIn:E] Stopped 2021-12-07T00:27:48.634Z,1638836868.634 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-07T00:27:48.634Z,1638836868.634 [Default:CheckIn] Stopped 2021-12-07T00:27:48.634Z,1638836868.634 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-07T00:27:48.634Z,1638836868.634 [Default:CheckIn](INFO): Running loop #11 2021-12-07T00:27:48.634Z,1638836868.634 [Default:CheckIn] Running Loop=11 2021-12-07T00:27:48.634Z,1638836868.634 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-07T00:27:48.634Z,1638836868.634 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-07T00:28:29.431Z,1638836909.431 [NAL9602](FAULT): GPS failed to acquire within timeout. 2021-12-07T00:28:29.431Z,1638836909.431 [NAL9602] Data Fault, FailCount= 3 2021-12-07T00:28:29.431Z,1638836909.431 [NAL9602](ERROR): Data Fault 2021-12-07T00:28:29.468Z,1638836909.468 [CBIT](ERROR): Data Fault in component: NAL9602 2021-12-07T00:28:29.828Z,1638836909.828 [NAL9602](INFO): Powering down 2021-12-07T00:28:30.657Z,1638836910.657 [CBIT](INFO): Clearing failed state for component NAL9602 2021-12-07T00:28:30.657Z,1638836910.657 [NAL9602] No Fault, FailCount= 3 2021-12-07T00:28:34.284Z,1638836914.284 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2021-12-07T00:28:34.284Z,1638836914.284 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 16 2021-12-07T00:28:34.285Z,1638836914.285 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-12-07T00:28:34.296Z,1638836914.296 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-12-07T00:28:34.700Z,1638836914.700 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-12-07T00:28:34.700Z,1638836914.700 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 16 2021-12-07T00:28:48.829Z,1638836928.829 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-12-07T00:27:48.6Z 2021-12-07T00:28:48.829Z,1638836928.829 [Default:CheckIn:Read_GPS] Stopped 2021-12-07T00:28:48.829Z,1638836928.829 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-07T00:28:51.206Z,1638836931.206 [DAT](INFO): #Outgoing data=1 2021-12-07T00:28:51.206Z,1638836931.206 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-12-07T00:28:51.288Z,1638836931.288 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-12-07T00:28:54.874Z,1638836934.874 [DAT](INFO): DAT read: Forwarding Delay UpTx time:00:27:04.2242 2021-12-07T00:28:54.874Z,1638836934.874 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-12-07T00:29:00.122Z,1638836940.122 [NAL9602](INFO): Powering up NAL9602 2021-12-07T00:29:10.217Z,1638836950.217 [DAT](FAULT): Ack receipt timeout failure. 2021-12-07T00:29:10.217Z,1638836950.217 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2021-12-07T00:29:10.641Z,1638836950.641 [DAT](INFO): Sent 169 bytes from file Logs/20211206T235608/Courier0034.lzma.parts 2021-12-07T00:29:10.641Z,1638836950.641 [DAT](INFO): Packets left to send: 0 2021-12-07T00:29:10.644Z,1638836950.644 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2021-12-07T00:29:11.034Z,1638836951.034 [NAL9602](INFO): NAL9602 initialized 2021-12-07T00:29:12.643Z,1638836952.643 [Default:CheckIn:Read_Iridium] Stopped 2021-12-07T00:29:12.643Z,1638836952.643 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-07T00:29:12.643Z,1638836952.643 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-07T00:30:12.870Z,1638837012.870 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-07T00:30:12.870Z,1638837012.870 [Default:CheckIn:C.Wait] Stopped 2021-12-07T00:30:12.870Z,1638837012.870 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-07T00:30:12.870Z,1638837012.870 [Default:CheckIn:D] Running Loop=1 2021-12-07T00:30:13.276Z,1638837013.276 [Default:CheckIn:D] Stopped 2021-12-07T00:30:13.276Z,1638837013.276 [Default:CheckIn:E] Running Loop=1 2021-12-07T00:30:13.694Z,1638837013.694 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 29.994167 min 2021-12-07T00:30:13.694Z,1638837013.694 [Default:CheckIn:E] Stopped 2021-12-07T00:30:13.694Z,1638837013.694 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-07T00:30:13.694Z,1638837013.694 [Default:CheckIn] Stopped 2021-12-07T00:30:13.694Z,1638837013.694 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-07T00:30:13.695Z,1638837013.695 [Default:CheckIn](INFO): Running loop #12 2021-12-07T00:30:13.695Z,1638837013.695 [Default:CheckIn] Running Loop=12 2021-12-07T00:30:13.695Z,1638837013.695 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-07T00:30:13.695Z,1638837013.695 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-07T00:30:35.494Z,1638837035.494 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2021-12-07T00:30:35.494Z,1638837035.494 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 17 2021-12-07T00:30:35.494Z,1638837035.494 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-12-07T00:30:35.505Z,1638837035.505 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-12-07T00:30:35.921Z,1638837035.921 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-12-07T00:30:35.921Z,1638837035.921 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 17 2021-12-07T00:31:13.874Z,1638837073.874 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-12-07T00:30:13.7Z 2021-12-07T00:31:13.874Z,1638837073.874 [Default:CheckIn:Read_GPS] Stopped 2021-12-07T00:31:13.875Z,1638837073.875 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-07T00:31:16.258Z,1638837076.258 [DAT](INFO): #Outgoing data=1 2021-12-07T00:31:16.258Z,1638837076.258 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-12-07T00:31:16.358Z,1638837076.358 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-12-07T00:31:20.766Z,1638837080.766 [DAT](INFO): DAT read: Forwarding Delay UpTx time:00:29:29.1229 2021-12-07T00:31:20.766Z,1638837080.766 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-12-07T00:31:31.845Z,1638837091.845 [DAT](FAULT): Ack receipt timeout failure. 2021-12-07T00:31:31.845Z,1638837091.845 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2021-12-07T00:31:32.247Z,1638837092.247 [DAT](INFO): Sent 39 bytes from file Logs/20211206T235608/Courier0037.lzma.parts 2021-12-07T00:31:32.247Z,1638837092.247 [DAT](INFO): Packets left to send: 0 2021-12-07T00:31:32.250Z,1638837092.250 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2021-12-07T00:31:34.229Z,1638837094.229 [Default:CheckIn:Read_Iridium] Stopped 2021-12-07T00:31:34.229Z,1638837094.229 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-07T00:31:34.229Z,1638837094.229 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-07T00:32:34.453Z,1638837154.453 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-07T00:32:34.453Z,1638837154.453 [Default:CheckIn:C.Wait] Stopped 2021-12-07T00:32:34.454Z,1638837154.454 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-07T00:32:34.454Z,1638837154.454 [Default:CheckIn:D] Running Loop=1 2021-12-07T00:32:34.865Z,1638837154.865 [Default:CheckIn:D] Stopped 2021-12-07T00:32:34.865Z,1638837154.865 [Default:CheckIn:E] Running Loop=1 2021-12-07T00:32:35.261Z,1638837155.261 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 32.353977 min 2021-12-07T00:32:35.262Z,1638837155.262 [Default:CheckIn:E] Stopped 2021-12-07T00:32:35.262Z,1638837155.262 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-07T00:32:35.262Z,1638837155.262 [Default:CheckIn] Stopped 2021-12-07T00:32:35.262Z,1638837155.262 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-07T00:32:35.262Z,1638837155.262 [Default:CheckIn](INFO): Running loop #13 2021-12-07T00:32:35.262Z,1638837155.262 [Default:CheckIn] Running Loop=13 2021-12-07T00:32:35.262Z,1638837155.262 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-07T00:32:35.262Z,1638837155.262 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-07T00:32:36.491Z,1638837156.491 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2021-12-07T00:32:36.491Z,1638837156.491 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 18 2021-12-07T00:32:36.491Z,1638837156.491 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-12-07T00:32:36.502Z,1638837156.502 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-12-07T00:32:36.894Z,1638837156.894 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-12-07T00:32:36.894Z,1638837156.894 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 18 2021-12-07T00:33:35.457Z,1638837215.457 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-12-07T00:32:35.3Z 2021-12-07T00:33:35.457Z,1638837215.457 [Default:CheckIn:Read_GPS] Stopped 2021-12-07T00:33:35.458Z,1638837215.458 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-07T00:33:37.863Z,1638837217.863 [DAT](INFO): #Outgoing data=1 2021-12-07T00:33:37.863Z,1638837217.863 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-12-07T00:33:37.962Z,1638837217.962 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-12-07T00:33:42.726Z,1638837222.726 [DAT](INFO): DAT read: Forwarding Delay UpTx time:00:31:50.7716 2021-12-07T00:33:42.726Z,1638837222.726 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-12-07T00:33:53.969Z,1638837233.969 [DAT](FAULT): Ack receipt timeout failure. 2021-12-07T00:33:53.969Z,1638837233.969 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2021-12-07T00:33:54.371Z,1638837234.371 [DAT](INFO): Sent 39 bytes from file Logs/20211206T235608/Courier0040.lzma.parts 2021-12-07T00:33:54.371Z,1638837234.371 [DAT](INFO): Packets left to send: 0 2021-12-07T00:33:54.374Z,1638837234.374 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2021-12-07T00:33:56.407Z,1638837236.407 [Default:CheckIn:Read_Iridium] Stopped 2021-12-07T00:33:56.407Z,1638837236.407 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-07T00:33:56.407Z,1638837236.407 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-07T00:34:37.519Z,1638837277.519 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2021-12-07T00:34:37.519Z,1638837277.519 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 19 2021-12-07T00:34:37.520Z,1638837277.520 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-12-07T00:34:37.531Z,1638837277.531 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-12-07T00:34:37.936Z,1638837277.936 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-12-07T00:34:37.936Z,1638837277.936 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 19 2021-12-07T00:34:56.933Z,1638837296.933 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-07T00:34:56.933Z,1638837296.933 [Default:CheckIn:C.Wait] Stopped 2021-12-07T00:34:56.933Z,1638837296.933 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-07T00:34:56.933Z,1638837296.933 [Default:CheckIn:D] Running Loop=1 2021-12-07T00:34:57.330Z,1638837297.330 [Default:CheckIn:D] Stopped 2021-12-07T00:34:57.330Z,1638837297.330 [Default:CheckIn:E] Running Loop=1 2021-12-07T00:34:57.716Z,1638837297.716 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 34.728398 min 2021-12-07T00:34:57.716Z,1638837297.716 [Default:CheckIn:E] Stopped 2021-12-07T00:34:57.717Z,1638837297.717 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-07T00:34:57.717Z,1638837297.717 [Default:CheckIn] Stopped 2021-12-07T00:34:57.717Z,1638837297.717 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-07T00:34:57.717Z,1638837297.717 [Default:CheckIn](INFO): Running loop #14 2021-12-07T00:34:57.717Z,1638837297.717 [Default:CheckIn] Running Loop=14 2021-12-07T00:34:57.717Z,1638837297.717 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-07T00:34:57.717Z,1638837297.717 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-07T00:35:57.918Z,1638837357.918 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-12-07T00:34:57.7Z 2021-12-07T00:35:57.918Z,1638837357.918 [Default:CheckIn:Read_GPS] Stopped 2021-12-07T00:35:57.919Z,1638837357.919 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-07T00:36:00.306Z,1638837360.306 [DAT](INFO): #Outgoing data=1 2021-12-07T00:36:00.306Z,1638837360.306 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-12-07T00:36:00.410Z,1638837360.410 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-12-07T00:36:04.806Z,1638837364.806 [DAT](INFO): DAT read: Forwarding Delay UpTx time:00:34:13.2204 2021-12-07T00:36:04.806Z,1638837364.806 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-12-07T00:36:15.877Z,1638837375.877 [DAT](FAULT): Ack receipt timeout failure. 2021-12-07T00:36:15.877Z,1638837375.877 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2021-12-07T00:36:16.268Z,1638837376.268 [DAT](INFO): Sent 39 bytes from file Logs/20211206T235608/Courier0043.lzma.parts 2021-12-07T00:36:16.268Z,1638837376.268 [DAT](INFO): Packets left to send: 0 2021-12-07T00:36:16.271Z,1638837376.271 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2021-12-07T00:36:18.261Z,1638837378.261 [Default:CheckIn:Read_Iridium] Stopped 2021-12-07T00:36:18.261Z,1638837378.261 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-07T00:36:18.261Z,1638837378.261 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-07T00:36:38.503Z,1638837398.503 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2021-12-07T00:36:38.503Z,1638837398.503 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 20 2021-12-07T00:36:38.503Z,1638837398.503 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-12-07T00:36:38.514Z,1638837398.514 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-12-07T00:36:38.911Z,1638837398.911 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-12-07T00:36:38.911Z,1638837398.911 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 20 2021-12-07T00:37:18.511Z,1638837438.511 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-07T00:37:18.511Z,1638837438.511 [Default:CheckIn:C.Wait] Stopped 2021-12-07T00:37:18.511Z,1638837438.511 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-07T00:37:18.511Z,1638837438.511 [Default:CheckIn:D] Running Loop=1 2021-12-07T00:37:18.892Z,1638837438.892 [Default:CheckIn:D] Stopped 2021-12-07T00:37:18.892Z,1638837438.892 [Default:CheckIn:E] Running Loop=1 2021-12-07T00:37:19.294Z,1638837439.294 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 37.087756 min 2021-12-07T00:37:19.295Z,1638837439.295 [Default:CheckIn:E] Stopped 2021-12-07T00:37:19.295Z,1638837439.295 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-07T00:37:19.295Z,1638837439.295 [Default:CheckIn] Stopped 2021-12-07T00:37:19.295Z,1638837439.295 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-07T00:37:19.295Z,1638837439.295 [Default:CheckIn](INFO): Running loop #15 2021-12-07T00:37:19.295Z,1638837439.295 [Default:CheckIn] Running Loop=15 2021-12-07T00:37:19.295Z,1638837439.295 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-07T00:37:19.296Z,1638837439.296 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-07T00:38:19.509Z,1638837499.509 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-12-07T00:37:19.3Z 2021-12-07T00:38:19.509Z,1638837499.509 [Default:CheckIn:Read_GPS] Stopped 2021-12-07T00:38:19.509Z,1638837499.509 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-07T00:38:21.867Z,1638837501.867 [DAT](INFO): #Outgoing data=1 2021-12-07T00:38:21.868Z,1638837501.868 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-12-07T00:38:21.955Z,1638837501.955 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-12-07T00:38:25.225Z,1638837505.225 [DAT](INFO): DAT read: Forwarding Delay UpTx time:00:36:34.7692 2021-12-07T00:38:25.226Z,1638837505.226 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-12-07T00:38:36.572Z,1638837516.572 [DAT](FAULT): Ack receipt timeout failure. 2021-12-07T00:38:36.572Z,1638837516.572 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2021-12-07T00:38:36.977Z,1638837516.977 [DAT](INFO): Sent 39 bytes from file Logs/20211206T235608/Courier0046.lzma.parts 2021-12-07T00:38:36.978Z,1638837516.978 [DAT](INFO): Packets left to send: 0 2021-12-07T00:38:36.980Z,1638837516.980 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2021-12-07T00:38:39.090Z,1638837519.090 [Default:CheckIn:Read_Iridium] Stopped 2021-12-07T00:38:39.090Z,1638837519.090 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-07T00:38:39.090Z,1638837519.090 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-07T00:38:41.794Z,1638837521.794 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2021-12-07T00:38:41.794Z,1638837521.794 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 21 2021-12-07T00:38:41.794Z,1638837521.794 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-12-07T00:38:41.805Z,1638837521.805 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-12-07T00:38:41.895Z,1638837521.895 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-12-07T00:38:41.895Z,1638837521.895 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 21 2021-12-07T00:39:13.735Z,1638837553.735 [NAL9602](FAULT): GPS failed to acquire within timeout. 2021-12-07T00:39:13.735Z,1638837553.735 [NAL9602] Data Fault, FailCount= 4 2021-12-07T00:39:13.735Z,1638837553.735 [NAL9602](ERROR): Data Fault 2021-12-07T00:39:13.750Z,1638837553.750 [CBIT](ERROR): Data Fault in component: NAL9602 2021-12-07T00:39:14.138Z,1638837554.138 [NAL9602](INFO): Powering down 2021-12-07T00:39:14.971Z,1638837554.971 [CBIT](INFO): Clearing failed state for component NAL9602 2021-12-07T00:39:14.971Z,1638837554.971 [NAL9602] No Fault, FailCount= 4 2021-12-07T00:39:39.192Z,1638837579.192 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-07T00:39:39.192Z,1638837579.192 [Default:CheckIn:C.Wait] Stopped 2021-12-07T00:39:39.192Z,1638837579.192 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-07T00:39:39.192Z,1638837579.192 [Default:CheckIn:D] Running Loop=1 2021-12-07T00:39:39.597Z,1638837579.597 [Default:CheckIn:D] Stopped 2021-12-07T00:39:39.597Z,1638837579.597 [Default:CheckIn:E] Running Loop=1 2021-12-07T00:39:39.995Z,1638837579.995 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 39.432845 min 2021-12-07T00:39:39.995Z,1638837579.995 [Default:CheckIn:E] Stopped 2021-12-07T00:39:39.995Z,1638837579.995 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-07T00:39:39.995Z,1638837579.995 [Default:CheckIn] Stopped 2021-12-07T00:39:39.995Z,1638837579.995 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-07T00:39:39.995Z,1638837579.995 [Default:CheckIn](INFO): Running loop #16 2021-12-07T00:39:40.004Z,1638837580.004 [Default:CheckIn] Running Loop=16 2021-12-07T00:39:40.004Z,1638837580.004 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-07T00:39:40.004Z,1638837580.004 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-07T00:39:44.435Z,1638837584.435 [NAL9602](INFO): Powering up NAL9602 2021-12-07T00:39:55.347Z,1638837595.347 [NAL9602](INFO): NAL9602 initialized 2021-12-07T00:40:40.198Z,1638837640.198 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-12-07T00:39:40.0Z 2021-12-07T00:40:40.198Z,1638837640.198 [Default:CheckIn:Read_GPS] Stopped 2021-12-07T00:40:40.198Z,1638837640.198 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-07T00:40:42.601Z,1638837642.601 [DAT](INFO): #Outgoing data=1 2021-12-07T00:40:42.601Z,1638837642.601 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-12-07T00:40:42.605Z,1638837642.605 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2021-12-07T00:40:42.606Z,1638837642.606 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 22 2021-12-07T00:40:42.606Z,1638837642.606 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-12-07T00:40:42.617Z,1638837642.617 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-12-07T00:40:42.685Z,1638837642.685 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-12-07T00:40:42.748Z,1638837642.748 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-12-07T00:40:42.749Z,1638837642.749 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 22 2021-12-07T00:40:46.398Z,1638837646.398 [DAT](INFO): DAT read: Forwarding Delay UpTx time:00:38:55.4680 2021-12-07T00:40:46.398Z,1638837646.398 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-12-07T00:40:57.409Z,1638837657.409 [DAT](FAULT): Ack receipt timeout failure. 2021-12-07T00:40:57.409Z,1638837657.409 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2021-12-07T00:40:57.799Z,1638837657.799 [DAT](INFO): Sent 39 bytes from file Logs/20211206T235608/Courier0049.lzma.parts 2021-12-07T00:40:57.799Z,1638837657.799 [DAT](INFO): Packets left to send: 0 2021-12-07T00:40:57.802Z,1638837657.802 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2021-12-07T00:40:59.867Z,1638837659.867 [Default:CheckIn:Read_Iridium] Stopped 2021-12-07T00:40:59.867Z,1638837659.867 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-07T00:40:59.868Z,1638837659.868 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-07T00:41:21.608Z,1638837681.608 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2021-12-07T00:41:21.608Z,1638837681.608 [DropWeight] Hardware Fault, FailCount= 1 2021-12-07T00:41:21.608Z,1638837681.608 [DropWeight](ERROR): Hardware Fault 2021-12-07T00:41:21.622Z,1638837681.622 [CBIT](INFO): Critical error at 20211207T004121 2021-12-07T00:41:21.624Z,1638837681.624 [CBIT](ERROR): Hardware Fault in component: DropWeight 2021-12-07T00:41:21.625Z,1638837681.625 [CBIT](CRITICAL): Hardware Fault in component: DropWeight 2021-12-07T00:41:22.032Z,1638837682.032 [CBIT](INFO): Critical error at 20211207T004121 2021-12-07T00:41:59.998Z,1638837719.998 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-07T00:41:59.998Z,1638837719.998 [Default:CheckIn:C.Wait] Stopped 2021-12-07T00:41:59.998Z,1638837719.998 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-07T00:41:59.999Z,1638837719.999 [Default:CheckIn:D] Running Loop=1 2021-12-07T00:42:00.413Z,1638837720.413 [Default:CheckIn:D] Stopped 2021-12-07T00:42:00.413Z,1638837720.413 [Default:CheckIn:E] Running Loop=1 2021-12-07T00:42:00.816Z,1638837720.816 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 41.779773 min 2021-12-07T00:42:00.816Z,1638837720.816 [Default:CheckIn:E] Stopped 2021-12-07T00:42:00.816Z,1638837720.816 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-07T00:42:00.817Z,1638837720.817 [Default:CheckIn] Stopped 2021-12-07T00:42:00.817Z,1638837720.817 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-07T00:42:00.817Z,1638837720.817 [Default:CheckIn](INFO): Running loop #17 2021-12-07T00:42:00.817Z,1638837720.817 [Default:CheckIn] Running Loop=17 2021-12-07T00:42:00.817Z,1638837720.817 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-07T00:42:00.817Z,1638837720.817 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-07T00:42:43.247Z,1638837763.247 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2021-12-07T00:42:43.247Z,1638837763.247 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 23 2021-12-07T00:42:43.247Z,1638837763.247 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-12-07T00:42:43.289Z,1638837763.289 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-12-07T00:42:43.650Z,1638837763.650 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-12-07T00:42:43.650Z,1638837763.650 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 23 2021-12-07T00:43:01.010Z,1638837781.010 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-12-07T00:42:00.8Z 2021-12-07T00:43:01.010Z,1638837781.010 [Default:CheckIn:Read_GPS] Stopped 2021-12-07T00:43:01.010Z,1638837781.010 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-07T00:43:03.576Z,1638837783.576 [DAT](INFO): #Outgoing data=1 2021-12-07T00:43:03.576Z,1638837783.576 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-12-07T00:43:03.666Z,1638837783.666 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-12-07T00:43:07.253Z,1638837787.253 [DAT](INFO): DAT read: Forwarding Delay UpTx time:00:41:16.5169 2021-12-07T00:43:07.254Z,1638837787.254 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-12-07T00:43:20.965Z,1638837800.965 [DAT](FAULT): Ack receipt timeout failure. 2021-12-07T00:43:20.965Z,1638837800.965 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2021-12-07T00:43:21.048Z,1638837801.048 [DAT](INFO): Sent 114 bytes from file Logs/20211206T235608/Courier0052.lzma.parts 2021-12-07T00:43:21.048Z,1638837801.048 [DAT](INFO): Packets left to send: 0 2021-12-07T00:43:21.051Z,1638837801.051 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2021-12-07T00:43:23.007Z,1638837803.007 [Default:CheckIn:Read_Iridium] Stopped 2021-12-07T00:43:23.007Z,1638837803.007 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-07T00:43:23.007Z,1638837803.007 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-07T00:44:23.234Z,1638837863.234 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-07T00:44:23.234Z,1638837863.234 [Default:CheckIn:C.Wait] Stopped 2021-12-07T00:44:23.234Z,1638837863.234 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-07T00:44:23.234Z,1638837863.234 [Default:CheckIn:D] Running Loop=1 2021-12-07T00:44:23.639Z,1638837863.639 [Default:CheckIn:D] Stopped 2021-12-07T00:44:23.639Z,1638837863.639 [Default:CheckIn:E] Running Loop=1 2021-12-07T00:44:24.054Z,1638837864.054 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 44.166882 min 2021-12-07T00:44:24.054Z,1638837864.054 [Default:CheckIn:E] Stopped 2021-12-07T00:44:24.054Z,1638837864.054 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-07T00:44:24.054Z,1638837864.054 [Default:CheckIn] Stopped 2021-12-07T00:44:24.055Z,1638837864.055 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-07T00:44:24.055Z,1638837864.055 [Default:CheckIn](INFO): Running loop #18 2021-12-07T00:44:24.055Z,1638837864.055 [Default:CheckIn] Running Loop=18 2021-12-07T00:44:24.055Z,1638837864.055 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-07T00:44:24.055Z,1638837864.055 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-07T00:44:44.240Z,1638837884.240 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2021-12-07T00:44:44.240Z,1638837884.240 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 24 2021-12-07T00:44:44.240Z,1638837884.240 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-12-07T00:44:44.252Z,1638837884.252 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-12-07T00:44:44.655Z,1638837884.655 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-12-07T00:44:44.655Z,1638837884.655 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 24 2021-12-07T00:45:24.238Z,1638837924.238 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-12-07T00:44:24.1Z 2021-12-07T00:45:24.238Z,1638837924.238 [Default:CheckIn:Read_GPS] Stopped 2021-12-07T00:45:24.239Z,1638837924.239 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-07T00:45:26.639Z,1638837926.639 [DAT](INFO): #Outgoing data=1 2021-12-07T00:45:26.639Z,1638837926.639 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-12-07T00:45:26.738Z,1638837926.738 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-12-07T00:45:31.218Z,1638837931.218 [DAT](INFO): DAT read: Forwarding Delay UpTx time:00:43:39.5159 2021-12-07T00:45:31.218Z,1638837931.218 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-12-07T00:45:42.337Z,1638837942.337 [DAT](FAULT): Ack receipt timeout failure. 2021-12-07T00:45:42.337Z,1638837942.337 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2021-12-07T00:45:42.730Z,1638837942.730 [DAT](INFO): Sent 39 bytes from file Logs/20211206T235608/Courier0055.lzma.parts 2021-12-07T00:45:42.731Z,1638837942.731 [DAT](INFO): Packets left to send: 0 2021-12-07T00:45:42.734Z,1638837942.734 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2021-12-07T00:45:45.303Z,1638837945.303 [Default:CheckIn:Read_Iridium] Stopped 2021-12-07T00:45:45.303Z,1638837945.303 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-07T00:45:45.303Z,1638837945.303 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-07T00:46:45.453Z,1638838005.453 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2021-12-07T00:46:45.453Z,1638838005.453 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 25 2021-12-07T00:46:45.453Z,1638838005.453 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-12-07T00:46:45.455Z,1638838005.455 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-07T00:46:45.455Z,1638838005.455 [Default:CheckIn:C.Wait] Stopped 2021-12-07T00:46:45.455Z,1638838005.455 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-07T00:46:45.455Z,1638838005.455 [Default:CheckIn:D] Running Loop=1 2021-12-07T00:46:45.465Z,1638838005.465 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-12-07T00:46:45.867Z,1638838005.867 [Default:CheckIn:D] Stopped 2021-12-07T00:46:45.867Z,1638838005.867 [Default:CheckIn:E] Running Loop=1 2021-12-07T00:46:45.876Z,1638838005.876 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-12-07T00:46:45.876Z,1638838005.876 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 25 2021-12-07T00:46:46.249Z,1638838006.249 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 46.537341 min 2021-12-07T00:46:46.249Z,1638838006.249 [Default:CheckIn:E] Stopped 2021-12-07T00:46:46.249Z,1638838006.249 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-07T00:46:46.250Z,1638838006.250 [Default:CheckIn] Stopped 2021-12-07T00:46:46.250Z,1638838006.250 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-07T00:46:46.250Z,1638838006.250 [Default:CheckIn](INFO): Running loop #19 2021-12-07T00:46:46.250Z,1638838006.250 [Default:CheckIn] Running Loop=19 2021-12-07T00:46:46.250Z,1638838006.250 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-07T00:46:46.250Z,1638838006.250 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-07T00:47:46.458Z,1638838066.458 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-12-07T00:46:46.3Z 2021-12-07T00:47:46.458Z,1638838066.458 [Default:CheckIn:Read_GPS] Stopped 2021-12-07T00:47:46.458Z,1638838066.458 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-07T00:47:48.881Z,1638838068.881 [DAT](INFO): #Outgoing data=1 2021-12-07T00:47:48.882Z,1638838068.882 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-12-07T00:47:48.966Z,1638838068.966 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-12-07T00:47:52.573Z,1638838072.573 [DAT](INFO): DAT read: Forwarding Delay UpTx time:00:46:01.7648 2021-12-07T00:47:52.574Z,1638838072.574 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-12-07T00:48:03.928Z,1638838083.928 [DAT](FAULT): Ack receipt timeout failure. 2021-12-07T00:48:03.928Z,1638838083.928 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2021-12-07T00:48:04.334Z,1638838084.334 [DAT](INFO): Sent 39 bytes from file Logs/20211206T235608/Courier0058.lzma.parts 2021-12-07T00:48:04.334Z,1638838084.334 [DAT](INFO): Packets left to send: 0 2021-12-07T00:48:04.337Z,1638838084.337 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2021-12-07T00:48:06.396Z,1638838086.396 [Default:CheckIn:Read_Iridium] Stopped 2021-12-07T00:48:06.396Z,1638838086.396 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-07T00:48:06.397Z,1638838086.397 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-07T00:48:46.328Z,1638838126.328 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2021-12-07T00:48:46.328Z,1638838126.328 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 26 2021-12-07T00:48:46.328Z,1638838126.328 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-12-07T00:48:46.338Z,1638838126.338 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-12-07T00:48:46.735Z,1638838126.735 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-12-07T00:48:46.735Z,1638838126.735 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 26 2021-12-07T00:49:06.529Z,1638838146.529 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-07T00:49:06.529Z,1638838146.529 [Default:CheckIn:C.Wait] Stopped 2021-12-07T00:49:06.529Z,1638838146.529 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-07T00:49:06.529Z,1638838146.529 [Default:CheckIn:D] Running Loop=1 2021-12-07T00:49:06.946Z,1638838146.946 [Default:CheckIn:D] Stopped 2021-12-07T00:49:06.946Z,1638838146.946 [Default:CheckIn:E] Running Loop=1 2021-12-07T00:49:07.347Z,1638838147.347 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 48.888656 min 2021-12-07T00:49:07.347Z,1638838147.347 [Default:CheckIn:E] Stopped 2021-12-07T00:49:07.347Z,1638838147.347 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-07T00:49:07.347Z,1638838147.347 [Default:CheckIn] Stopped 2021-12-07T00:49:07.347Z,1638838147.347 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-07T00:49:07.347Z,1638838147.347 [Default:CheckIn](INFO): Running loop #20 2021-12-07T00:49:07.347Z,1638838147.347 [Default:CheckIn] Running Loop=20 2021-12-07T00:49:07.348Z,1638838147.348 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-07T00:49:07.348Z,1638838147.348 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-07T00:49:56.215Z,1638838196.215 [NAL9602](FAULT): GPS failed to acquire within timeout. 2021-12-07T00:49:56.215Z,1638838196.215 [NAL9602] Data Fault, FailCount= 5 2021-12-07T00:49:56.215Z,1638838196.215 [NAL9602](ERROR): Data Fault 2021-12-07T00:49:56.230Z,1638838196.230 [CBIT](ERROR): Data Fault in component: NAL9602 2021-12-07T00:49:56.230Z,1638838196.230 [CBIT](CRITICAL): Data Fault in component: NAL9602 2021-12-07T00:49:56.621Z,1638838196.621 [NAL9602](INFO): Powering down 2021-12-07T00:49:56.635Z,1638838196.635 [CBIT](INFO): Critical error at 20211207T004956 2021-12-07T00:50:07.542Z,1638838207.542 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-12-07T00:49:07.3Z 2021-12-07T00:50:07.542Z,1638838207.542 [Default:CheckIn:Read_GPS] Stopped 2021-12-07T00:50:07.542Z,1638838207.542 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-07T00:50:09.909Z,1638838209.909 [DAT](INFO): #Outgoing data=1 2021-12-07T00:50:09.910Z,1638838209.910 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-12-07T00:50:09.996Z,1638838209.996 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-12-07T00:50:13.588Z,1638838213.588 [DAT](INFO): DAT read: Forwarding Delay UpTx time:00:48:22.8137 2021-12-07T00:50:13.588Z,1638838213.588 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-12-07T00:50:25.707Z,1638838225.707 [DAT](FAULT): Ack receipt timeout failure. 2021-12-07T00:50:25.707Z,1638838225.707 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2021-12-07T00:50:26.111Z,1638838226.111 [DAT](INFO): Sent 80 bytes from file Logs/20211206T235608/Courier0061.lzma.parts 2021-12-07T00:50:26.111Z,1638838226.111 [DAT](INFO): Packets left to send: 0 2021-12-07T00:50:26.114Z,1638838226.114 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2021-12-07T00:50:28.125Z,1638838228.125 [Default:CheckIn:Read_Iridium] Stopped 2021-12-07T00:50:28.125Z,1638838228.125 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-07T00:50:28.126Z,1638838228.126 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-07T00:50:47.143Z,1638838247.143 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2021-12-07T00:50:47.143Z,1638838247.143 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 27 2021-12-07T00:50:47.143Z,1638838247.143 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-12-07T00:50:47.183Z,1638838247.183 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-12-07T00:50:47.557Z,1638838247.557 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-12-07T00:50:47.557Z,1638838247.557 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 27 2021-12-07T00:51:28.348Z,1638838288.348 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-07T00:51:28.349Z,1638838288.349 [Default:CheckIn:C.Wait] Stopped 2021-12-07T00:51:28.349Z,1638838288.349 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-07T00:51:28.349Z,1638838288.349 [Default:CheckIn:D] Running Loop=1 2021-12-07T00:51:28.764Z,1638838288.764 [Default:CheckIn:D] Stopped 2021-12-07T00:51:28.764Z,1638838288.764 [Default:CheckIn:E] Running Loop=1 2021-12-07T00:51:29.161Z,1638838289.161 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 51.252291 min 2021-12-07T00:51:29.161Z,1638838289.161 [Default:CheckIn:E] Stopped 2021-12-07T00:51:29.161Z,1638838289.161 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-07T00:51:29.161Z,1638838289.161 [Default:CheckIn] Stopped 2021-12-07T00:51:29.161Z,1638838289.161 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-07T00:51:29.161Z,1638838289.161 [Default:CheckIn](INFO): Running loop #21 2021-12-07T00:51:29.161Z,1638838289.161 [Default:CheckIn] Running Loop=21 2021-12-07T00:51:29.161Z,1638838289.161 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-07T00:51:29.162Z,1638838289.162 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-07T00:51:56.231Z,1638838316.231 [CBIT](INFO): Clearing failed state for component NAL9602 2021-12-07T00:51:56.231Z,1638838316.231 [NAL9602] No Fault, FailCount= 5 2021-12-07T00:51:56.625Z,1638838316.625 [NAL9602](INFO): Powering up NAL9602 2021-12-07T00:52:07.541Z,1638838327.541 [NAL9602](INFO): NAL9602 initialized 2021-12-07T00:52:29.366Z,1638838349.366 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-12-07T00:51:29.2Z 2021-12-07T00:52:29.366Z,1638838349.366 [Default:CheckIn:Read_GPS] Stopped 2021-12-07T00:52:29.366Z,1638838349.366 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-07T00:52:31.861Z,1638838351.861 [DAT](INFO): #Outgoing data=1 2021-12-07T00:52:31.862Z,1638838351.862 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-12-07T00:52:31.962Z,1638838351.962 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-12-07T00:52:36.334Z,1638838356.334 [DAT](INFO): DAT read: Forwarding Delay UpTx time:00:50:44.7627 2021-12-07T00:52:36.334Z,1638838356.334 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-12-07T00:52:47.345Z,1638838367.345 [DAT](FAULT): Ack receipt timeout failure. 2021-12-07T00:52:47.345Z,1638838367.345 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2021-12-07T00:52:47.737Z,1638838367.737 [DAT](INFO): Sent 39 bytes from file Logs/20211206T235608/Courier0064.lzma.parts 2021-12-07T00:52:47.737Z,1638838367.737 [DAT](INFO): Packets left to send: 0 2021-12-07T00:52:47.740Z,1638838367.740 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2021-12-07T00:52:49.831Z,1638838369.831 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2021-12-07T00:52:49.831Z,1638838369.831 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 28 2021-12-07T00:52:49.831Z,1638838369.831 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-12-07T00:52:49.833Z,1638838369.833 [Default:CheckIn:Read_Iridium] Stopped 2021-12-07T00:52:49.833Z,1638838369.833 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-07T00:52:49.834Z,1638838369.834 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-07T00:52:49.843Z,1638838369.843 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-12-07T00:52:49.930Z,1638838369.930 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-12-07T00:52:49.930Z,1638838369.930 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 28 2021-12-07T00:53:50.102Z,1638838430.102 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-07T00:53:50.102Z,1638838430.102 [Default:CheckIn:C.Wait] Stopped 2021-12-07T00:53:50.102Z,1638838430.102 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-07T00:53:50.102Z,1638838430.102 [Default:CheckIn:D] Running Loop=1 2021-12-07T00:53:50.494Z,1638838430.494 [Default:CheckIn:D] Stopped 2021-12-07T00:53:50.494Z,1638838430.494 [Default:CheckIn:E] Running Loop=1 2021-12-07T00:53:50.902Z,1638838430.902 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 53.614457 min 2021-12-07T00:53:50.902Z,1638838430.902 [Default:CheckIn:E] Stopped 2021-12-07T00:53:50.902Z,1638838430.902 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-07T00:53:50.903Z,1638838430.903 [Default:CheckIn] Stopped 2021-12-07T00:53:50.903Z,1638838430.903 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-07T00:53:50.903Z,1638838430.903 [Default:CheckIn](INFO): Running loop #22 2021-12-07T00:53:50.903Z,1638838430.903 [Default:CheckIn] Running Loop=22 2021-12-07T00:53:50.903Z,1638838430.903 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-07T00:53:50.903Z,1638838430.903 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-07T00:54:50.707Z,1638838490.707 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2021-12-07T00:54:50.707Z,1638838490.707 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 29 2021-12-07T00:54:50.707Z,1638838490.707 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-12-07T00:54:50.748Z,1638838490.748 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-12-07T00:54:51.112Z,1638838491.112 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-12-07T00:53:50.9Z 2021-12-07T00:54:51.113Z,1638838491.113 [Default:CheckIn:Read_GPS] Stopped 2021-12-07T00:54:51.113Z,1638838491.113 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-07T00:54:51.121Z,1638838491.121 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-12-07T00:54:51.122Z,1638838491.122 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 29 2021-12-07T00:54:53.503Z,1638838493.503 [DAT](INFO): #Outgoing data=1 2021-12-07T00:54:53.503Z,1638838493.503 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-12-07T00:54:53.590Z,1638838493.590 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-12-07T00:54:56.786Z,1638838496.786 [DAT](INFO): DAT read: Forwarding Delay UpTx time:00:53:06.3618 2021-12-07T00:54:56.786Z,1638838496.786 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-12-07T00:55:08.102Z,1638838508.102 [DAT](FAULT): Ack receipt timeout failure. 2021-12-07T00:55:08.102Z,1638838508.102 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2021-12-07T00:55:08.501Z,1638838508.501 [DAT](INFO): Sent 39 bytes from file Logs/20211206T235608/Courier0067.lzma.parts 2021-12-07T00:55:08.501Z,1638838508.501 [DAT](INFO): Packets left to send: 0 2021-12-07T00:55:08.504Z,1638838508.504 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2021-12-07T00:55:10.522Z,1638838510.522 [Default:CheckIn:Read_Iridium] Stopped 2021-12-07T00:55:10.522Z,1638838510.522 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-07T00:55:10.522Z,1638838510.522 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-07T00:56:11.036Z,1638838571.036 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-07T00:56:11.037Z,1638838571.037 [Default:CheckIn:C.Wait] Stopped 2021-12-07T00:56:11.037Z,1638838571.037 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-07T00:56:11.037Z,1638838571.037 [Default:CheckIn:D] Running Loop=1 2021-12-07T00:56:11.434Z,1638838571.434 [Default:CheckIn:D] Stopped 2021-12-07T00:56:11.434Z,1638838571.434 [Default:CheckIn:E] Running Loop=1 2021-12-07T00:56:11.841Z,1638838571.841 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 55.963460 min 2021-12-07T00:56:11.841Z,1638838571.841 [Default:CheckIn:E] Stopped 2021-12-07T00:56:11.842Z,1638838571.842 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-07T00:56:11.842Z,1638838571.842 [Default:CheckIn] Stopped 2021-12-07T00:56:11.842Z,1638838571.842 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-07T00:56:11.842Z,1638838571.842 [Default:CheckIn](INFO): Running loop #23 2021-12-07T00:56:11.842Z,1638838571.842 [Default:CheckIn] Running Loop=23 2021-12-07T00:56:11.842Z,1638838571.842 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-07T00:56:11.842Z,1638838571.842 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-07T00:56:21.950Z,1638838581.950 [CBIT](INFO): Clearing failed state for component DropWeight 2021-12-07T00:56:21.950Z,1638838581.950 [DropWeight] No Fault, FailCount= 1 2021-12-07T00:56:51.828Z,1638838611.828 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2021-12-07T00:56:51.828Z,1638838611.828 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 30 2021-12-07T00:56:51.829Z,1638838611.829 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-12-07T00:56:51.839Z,1638838611.839 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-12-07T00:56:52.239Z,1638838612.239 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-12-07T00:56:52.239Z,1638838612.239 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 30 2021-12-07T00:57:12.019Z,1638838632.019 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-12-07T00:56:11.8Z 2021-12-07T00:57:12.019Z,1638838632.019 [Default:CheckIn:Read_GPS] Stopped 2021-12-07T00:57:12.019Z,1638838632.019 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-07T00:57:14.437Z,1638838634.437 [DAT](INFO): #Outgoing data=1 2021-12-07T00:57:14.437Z,1638838634.437 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-12-07T00:57:14.534Z,1638838634.534 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-12-07T00:57:20.702Z,1638838640.702 [DAT](INFO): DAT read: Forwarding Delay UpTx time:00:55:27.3108 2021-12-07T00:57:20.702Z,1638838640.702 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-12-07T00:57:32.041Z,1638838652.041 [DAT](FAULT): Ack receipt timeout failure. 2021-12-07T00:57:32.041Z,1638838652.041 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2021-12-07T00:57:32.445Z,1638838652.445 [DAT](INFO): Sent 39 bytes from file Logs/20211206T235608/Courier0070.lzma.parts 2021-12-07T00:57:32.445Z,1638838652.445 [DAT](INFO): Packets left to send: 0 2021-12-07T00:57:32.448Z,1638838652.448 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2021-12-07T00:57:34.418Z,1638838654.418 [Default:CheckIn:Read_Iridium] Stopped 2021-12-07T00:57:34.418Z,1638838654.418 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-07T00:57:34.419Z,1638838654.419 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-07T00:58:34.664Z,1638838714.664 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-07T00:58:34.664Z,1638838714.664 [Default:CheckIn:C.Wait] Stopped 2021-12-07T00:58:34.665Z,1638838714.665 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-07T00:58:34.665Z,1638838714.665 [Default:CheckIn:D] Running Loop=1 2021-12-07T00:58:35.069Z,1638838715.069 [Default:CheckIn:D] Stopped 2021-12-07T00:58:35.069Z,1638838715.069 [Default:CheckIn:E] Running Loop=1 2021-12-07T00:58:35.453Z,1638838715.453 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 58.357377 min 2021-12-07T00:58:35.453Z,1638838715.453 [Default:CheckIn:E] Stopped 2021-12-07T00:58:35.454Z,1638838715.454 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-07T00:58:35.454Z,1638838715.454 [Default:CheckIn] Stopped 2021-12-07T00:58:35.454Z,1638838715.454 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-07T00:58:35.454Z,1638838715.454 [Default:CheckIn](INFO): Running loop #24 2021-12-07T00:58:35.454Z,1638838715.454 [Default:CheckIn] Running Loop=24 2021-12-07T00:58:35.454Z,1638838715.454 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-07T00:58:35.454Z,1638838715.454 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-07T00:58:52.835Z,1638838732.835 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2021-12-07T00:58:52.835Z,1638838732.835 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 31 2021-12-07T00:58:52.835Z,1638838732.835 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-12-07T00:58:52.846Z,1638838732.846 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-12-07T00:58:53.240Z,1638838733.240 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-12-07T00:58:53.240Z,1638838733.240 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 31 2021-12-07T00:59:35.647Z,1638838775.647 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-12-07T00:58:35.5Z 2021-12-07T00:59:35.647Z,1638838775.647 [Default:CheckIn:Read_GPS] Stopped 2021-12-07T00:59:35.647Z,1638838775.647 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-07T00:59:38.043Z,1638838778.043 [DAT](INFO): #Outgoing data=1 2021-12-07T00:59:38.043Z,1638838778.043 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-12-07T00:59:38.138Z,1638838778.138 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-12-07T00:59:41.709Z,1638838781.709 [DAT](INFO): DAT read: Forwarding Delay UpTx time:00:57:50.9096 2021-12-07T00:59:41.709Z,1638838781.709 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-12-07T00:59:54.437Z,1638838794.437 [DAT](FAULT): Ack receipt timeout failure. 2021-12-07T00:59:54.437Z,1638838794.437 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2021-12-07T00:59:54.535Z,1638838794.535 [DAT](INFO): Sent 39 bytes from file Logs/20211206T235608/Courier0073.lzma.parts 2021-12-07T00:59:54.535Z,1638838794.535 [DAT](INFO): Packets left to send: 0 2021-12-07T00:59:54.538Z,1638838794.538 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2021-12-07T00:59:56.465Z,1638838796.465 [Default:CheckIn:Read_Iridium] Stopped 2021-12-07T00:59:56.465Z,1638838796.465 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-07T00:59:56.465Z,1638838796.465 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-07T01:00:53.872Z,1638838853.872 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2021-12-07T01:00:53.873Z,1638838853.873 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 32 2021-12-07T01:00:53.873Z,1638838853.873 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-12-07T01:00:53.884Z,1638838853.884 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-12-07T01:00:54.267Z,1638838854.267 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-12-07T01:00:54.267Z,1638838854.267 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 32 2021-12-07T01:00:56.708Z,1638838856.708 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-07T01:00:56.708Z,1638838856.708 [Default:CheckIn:C.Wait] Stopped 2021-12-07T01:00:56.708Z,1638838856.708 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-07T01:00:56.709Z,1638838856.709 [Default:CheckIn:D] Running Loop=1 2021-12-07T01:00:57.113Z,1638838857.113 [Default:CheckIn:D] Stopped 2021-12-07T01:00:57.113Z,1638838857.113 [Default:CheckIn:E] Running Loop=1 2021-12-07T01:00:57.504Z,1638838857.504 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 60.724772 min 2021-12-07T01:00:57.504Z,1638838857.504 [Default:CheckIn:E] Stopped 2021-12-07T01:00:57.504Z,1638838857.504 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-07T01:00:57.504Z,1638838857.504 [Default:CheckIn] Stopped 2021-12-07T01:00:57.504Z,1638838857.504 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-07T01:00:57.504Z,1638838857.504 [Default:CheckIn](INFO): Running loop #25 2021-12-07T01:00:57.505Z,1638838857.505 [Default:CheckIn] Running Loop=25 2021-12-07T01:00:57.505Z,1638838857.505 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-07T01:00:57.505Z,1638838857.505 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-07T01:01:57.705Z,1638838917.705 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-12-07T01:00:57.5Z 2021-12-07T01:01:57.705Z,1638838917.705 [Default:CheckIn:Read_GPS] Stopped 2021-12-07T01:01:57.705Z,1638838917.705 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-07T01:02:00.969Z,1638838920.969 [DAT](INFO): #Outgoing data=1 2021-12-07T01:02:00.969Z,1638838920.969 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-12-07T01:02:01.058Z,1638838921.058 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-12-07T01:02:05.146Z,1638838925.146 [DAT](INFO): DAT read: Forwarding Delay UpTx time:01:00:13.8585 2021-12-07T01:02:05.147Z,1638838925.147 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-12-07T01:02:12.737Z,1638838932.737 [NAL9602](FAULT): GPS failed to acquire within timeout. 2021-12-07T01:02:12.738Z,1638838932.738 [NAL9602] Data Fault, FailCount= 1 2021-12-07T01:02:12.738Z,1638838932.738 [NAL9602](ERROR): Data Fault 2021-12-07T01:02:12.765Z,1638838932.765 [CBIT](ERROR): Data Fault in component: NAL9602 2021-12-07T01:02:13.144Z,1638838933.144 [NAL9602](INFO): Powering down 2021-12-07T01:02:13.964Z,1638838933.964 [CBIT](INFO): Clearing failed state for component NAL9602 2021-12-07T01:02:13.964Z,1638838933.964 [NAL9602] No Fault, FailCount= 1 2021-12-07T01:02:16.374Z,1638838936.374 [DAT](FAULT): Ack receipt timeout failure. 2021-12-07T01:02:16.374Z,1638838936.374 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2021-12-07T01:02:16.778Z,1638838936.778 [DAT](INFO): Sent 39 bytes from file Logs/20211206T235608/Courier0076.lzma.parts 2021-12-07T01:02:16.778Z,1638838936.778 [DAT](INFO): Packets left to send: 0 2021-12-07T01:02:16.781Z,1638838936.781 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2021-12-07T01:02:21.133Z,1638838941.133 [Default:CheckIn:Read_Iridium] Stopped 2021-12-07T01:02:21.133Z,1638838941.133 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-07T01:02:21.133Z,1638838941.133 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-07T01:02:43.383Z,1638838963.383 [NAL9602](INFO): Powering up NAL9602 2021-12-07T01:02:54.290Z,1638838974.290 [NAL9602](INFO): NAL9602 initialized 2021-12-07T01:02:54.703Z,1638838974.703 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2021-12-07T01:02:54.704Z,1638838974.704 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 33 2021-12-07T01:02:54.704Z,1638838974.704 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-12-07T01:02:54.746Z,1638838974.746 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-12-07T01:02:55.122Z,1638838975.122 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-12-07T01:02:55.122Z,1638838975.122 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 33 2021-12-07T01:03:21.369Z,1638839001.369 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-07T01:03:21.369Z,1638839001.369 [Default:CheckIn:C.Wait] Stopped 2021-12-07T01:03:21.369Z,1638839001.369 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-07T01:03:21.369Z,1638839001.369 [Default:CheckIn:D] Running Loop=1 2021-12-07T01:03:21.796Z,1638839001.796 [Default:CheckIn:D] Stopped 2021-12-07T01:03:21.796Z,1638839001.796 [Default:CheckIn:E] Running Loop=1 2021-12-07T01:03:22.197Z,1638839002.197 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 63.136161 min 2021-12-07T01:03:22.197Z,1638839002.197 [Default:CheckIn:E] Stopped 2021-12-07T01:03:22.197Z,1638839002.197 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-07T01:03:22.197Z,1638839002.197 [Default:CheckIn] Stopped 2021-12-07T01:03:22.197Z,1638839002.197 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-07T01:03:22.197Z,1638839002.197 [Default:CheckIn](INFO): Running loop #26 2021-12-07T01:03:22.197Z,1638839002.197 [Default:CheckIn] Running Loop=26 2021-12-07T01:03:22.198Z,1638839002.198 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-07T01:03:22.198Z,1638839002.198 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-07T01:04:22.374Z,1638839062.374 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-12-07T01:03:22.2Z 2021-12-07T01:04:22.374Z,1638839062.374 [Default:CheckIn:Read_GPS] Stopped 2021-12-07T01:04:22.374Z,1638839062.374 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-07T01:04:24.782Z,1638839064.782 [DAT](INFO): #Outgoing data=1 2021-12-07T01:04:24.783Z,1638839064.783 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-12-07T01:04:24.905Z,1638839064.905 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-12-07T01:04:28.486Z,1638839068.486 [DAT](INFO): DAT read: Forwarding Delay UpTx time:01:02:37.7075 2021-12-07T01:04:28.486Z,1638839068.486 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-12-07T01:04:39.841Z,1638839079.841 [DAT](FAULT): Ack receipt timeout failure. 2021-12-07T01:04:39.841Z,1638839079.841 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2021-12-07T01:04:41.869Z,1638839081.869 [DAT](INFO): Sent 39 bytes from file Logs/20211206T235608/Courier0079.lzma.parts 2021-12-07T01:04:41.869Z,1638839081.869 [DAT](INFO): Packets left to send: 0 2021-12-07T01:04:41.872Z,1638839081.872 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2021-12-07T01:04:43.510Z,1638839083.510 [Default:CheckIn:Read_Iridium] Stopped 2021-12-07T01:04:43.511Z,1638839083.511 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-07T01:04:43.511Z,1638839083.511 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-07T01:04:55.695Z,1638839095.695 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2021-12-07T01:04:55.695Z,1638839095.695 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 34 2021-12-07T01:04:55.695Z,1638839095.695 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-12-07T01:04:55.738Z,1638839095.738 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-12-07T01:04:56.089Z,1638839096.089 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-12-07T01:04:56.089Z,1638839096.089 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 34 2021-12-07T01:05:43.755Z,1638839143.755 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-07T01:05:43.755Z,1638839143.755 [Default:CheckIn:C.Wait] Stopped 2021-12-07T01:05:43.755Z,1638839143.755 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-07T01:05:43.755Z,1638839143.755 [Default:CheckIn:D] Running Loop=1 2021-12-07T01:05:44.162Z,1638839144.162 [Default:CheckIn:D] Stopped 2021-12-07T01:05:44.162Z,1638839144.162 [Default:CheckIn:E] Running Loop=1 2021-12-07T01:05:44.585Z,1638839144.585 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 65.508931 min 2021-12-07T01:05:44.585Z,1638839144.585 [Default:CheckIn:E] Stopped 2021-12-07T01:05:44.585Z,1638839144.585 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-07T01:05:44.585Z,1638839144.585 [Default:CheckIn] Stopped 2021-12-07T01:05:44.585Z,1638839144.585 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-07T01:05:44.585Z,1638839144.585 [Default:CheckIn](INFO): Running loop #27 2021-12-07T01:05:44.585Z,1638839144.585 [Default:CheckIn] Running Loop=27 2021-12-07T01:05:44.586Z,1638839144.586 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-07T01:05:44.586Z,1638839144.586 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-07T01:06:44.764Z,1638839204.764 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-12-07T01:05:44.6Z 2021-12-07T01:06:44.764Z,1638839204.764 [Default:CheckIn:Read_GPS] Stopped 2021-12-07T01:06:44.764Z,1638839204.764 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-07T01:06:47.158Z,1638839207.158 [DAT](INFO): #Outgoing data=1 2021-12-07T01:06:47.159Z,1638839207.159 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-12-07T01:06:47.258Z,1638839207.258 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-12-07T01:06:50.802Z,1638839210.802 [DAT](INFO): DAT read: Forwarding Delay UpTx time:01:05:00.0564 2021-12-07T01:06:50.802Z,1638839210.802 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-12-07T01:06:56.605Z,1638839216.605 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2021-12-07T01:06:56.605Z,1638839216.605 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 35 2021-12-07T01:06:56.605Z,1638839216.605 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-12-07T01:06:56.641Z,1638839216.641 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-12-07T01:06:57.044Z,1638839217.044 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-12-07T01:06:57.044Z,1638839217.044 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 35 2021-12-07T01:07:01.922Z,1638839221.922 [DAT](FAULT): Ack receipt timeout failure. 2021-12-07T01:07:01.922Z,1638839221.922 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2021-12-07T01:07:02.321Z,1638839222.321 [DAT](INFO): Sent 39 bytes from file Logs/20211206T235608/Courier0082.lzma.parts 2021-12-07T01:07:02.321Z,1638839222.321 [DAT](INFO): Packets left to send: 0 2021-12-07T01:07:02.324Z,1638839222.324 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2021-12-07T01:07:04.315Z,1638839224.315 [Default:CheckIn:Read_Iridium] Stopped 2021-12-07T01:07:04.315Z,1638839224.315 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-07T01:07:04.316Z,1638839224.316 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-07T01:08:04.543Z,1638839284.543 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-07T01:08:04.543Z,1638839284.543 [Default:CheckIn:C.Wait] Stopped 2021-12-07T01:08:04.543Z,1638839284.543 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-07T01:08:04.543Z,1638839284.543 [Default:CheckIn:D] Running Loop=1 2021-12-07T01:08:04.965Z,1638839284.965 [Default:CheckIn:D] Stopped 2021-12-07T01:08:04.965Z,1638839284.965 [Default:CheckIn:E] Running Loop=1 2021-12-07T01:08:05.377Z,1638839285.377 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 67.855644 min 2021-12-07T01:08:05.377Z,1638839285.377 [Default:CheckIn:E] Stopped 2021-12-07T01:08:05.377Z,1638839285.377 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-07T01:08:05.377Z,1638839285.377 [Default:CheckIn] Stopped 2021-12-07T01:08:05.377Z,1638839285.377 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-07T01:08:05.377Z,1638839285.377 [Default:CheckIn](INFO): Running loop #28 2021-12-07T01:08:05.378Z,1638839285.378 [Default:CheckIn] Running Loop=28 2021-12-07T01:08:05.378Z,1638839285.378 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-07T01:08:05.378Z,1638839285.378 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-07T01:08:57.465Z,1638839337.465 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2021-12-07T01:08:57.465Z,1638839337.465 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 36 2021-12-07T01:08:57.465Z,1638839337.465 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-12-07T01:08:57.476Z,1638839337.476 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-12-07T01:08:57.896Z,1638839337.896 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-12-07T01:08:57.896Z,1638839337.896 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 36 2021-12-07T01:09:05.545Z,1638839345.545 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-12-07T01:08:05.4Z 2021-12-07T01:09:05.545Z,1638839345.545 [Default:CheckIn:Read_GPS] Stopped 2021-12-07T01:09:05.546Z,1638839345.546 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-07T01:09:07.929Z,1638839347.929 [DAT](INFO): #Outgoing data=1 2021-12-07T01:09:07.929Z,1638839347.929 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-12-07T01:09:08.050Z,1638839348.050 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-12-07T01:09:11.642Z,1638839351.642 [DAT](INFO): DAT read: Forwarding Delay UpTx time:01:07:20.8553 2021-12-07T01:09:11.642Z,1638839351.642 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-12-07T01:09:22.701Z,1638839362.701 [DAT](FAULT): Ack receipt timeout failure. 2021-12-07T01:09:22.701Z,1638839362.701 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2021-12-07T01:09:23.107Z,1638839363.107 [DAT](INFO): Sent 39 bytes from file Logs/20211206T235608/Courier0085.lzma.parts 2021-12-07T01:09:23.107Z,1638839363.107 [DAT](INFO): Packets left to send: 0 2021-12-07T01:09:23.110Z,1638839363.110 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2021-12-07T01:09:25.215Z,1638839365.215 [Default:CheckIn:Read_Iridium] Stopped 2021-12-07T01:09:25.215Z,1638839365.215 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-07T01:09:25.215Z,1638839365.215 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-07T01:10:25.721Z,1638839425.721 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-07T01:10:25.721Z,1638839425.721 [Default:CheckIn:C.Wait] Stopped 2021-12-07T01:10:25.721Z,1638839425.721 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-07T01:10:25.721Z,1638839425.721 [Default:CheckIn:D] Running Loop=1 2021-12-07T01:10:26.127Z,1638839426.127 [Default:CheckIn:D] Stopped 2021-12-07T01:10:26.128Z,1638839426.128 [Default:CheckIn:E] Running Loop=1 2021-12-07T01:10:26.538Z,1638839426.538 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 70.208350 min 2021-12-07T01:10:26.538Z,1638839426.538 [Default:CheckIn:E] Stopped 2021-12-07T01:10:26.538Z,1638839426.538 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-07T01:10:26.538Z,1638839426.538 [Default:CheckIn] Stopped 2021-12-07T01:10:26.539Z,1638839426.539 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-07T01:10:26.539Z,1638839426.539 [Default:CheckIn](INFO): Running loop #29 2021-12-07T01:10:26.539Z,1638839426.539 [Default:CheckIn] Running Loop=29 2021-12-07T01:10:26.539Z,1638839426.539 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-07T01:10:26.539Z,1638839426.539 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-07T01:10:58.457Z,1638839458.457 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2021-12-07T01:10:58.457Z,1638839458.457 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 37 2021-12-07T01:10:58.457Z,1638839458.457 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-12-07T01:10:58.467Z,1638839458.467 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-12-07T01:10:58.874Z,1638839458.874 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-12-07T01:10:58.874Z,1638839458.874 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 37 2021-12-07T01:11:26.725Z,1638839486.725 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-12-07T01:10:26.5Z 2021-12-07T01:11:26.725Z,1638839486.725 [Default:CheckIn:Read_GPS] Stopped 2021-12-07T01:11:26.726Z,1638839486.726 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-07T01:11:29.130Z,1638839489.130 [DAT](INFO): #Outgoing data=1 2021-12-07T01:11:29.131Z,1638839489.131 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-12-07T01:11:29.230Z,1638839489.230 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-12-07T01:11:34.066Z,1638839494.066 [DAT](INFO): DAT read: Forwarding Delay UpTx time:01:09:42.0043 2021-12-07T01:11:34.066Z,1638839494.066 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-12-07T01:11:45.149Z,1638839505.149 [DAT](FAULT): Ack receipt timeout failure. 2021-12-07T01:11:45.149Z,1638839505.149 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2021-12-07T01:11:45.543Z,1638839505.543 [DAT](INFO): Sent 39 bytes from file Logs/20211206T235608/Courier0088.lzma.parts 2021-12-07T01:11:45.543Z,1638839505.543 [DAT](INFO): Packets left to send: 0 2021-12-07T01:11:45.546Z,1638839505.546 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2021-12-07T01:11:47.564Z,1638839507.564 [Default:CheckIn:Read_Iridium] Stopped 2021-12-07T01:11:47.564Z,1638839507.564 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-07T01:11:47.564Z,1638839507.564 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-07T01:12:47.808Z,1638839567.808 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-07T01:12:47.809Z,1638839567.809 [Default:CheckIn:C.Wait] Stopped 2021-12-07T01:12:47.809Z,1638839567.809 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-07T01:12:47.809Z,1638839567.809 [Default:CheckIn:D] Running Loop=1 2021-12-07T01:12:48.215Z,1638839568.215 [Default:CheckIn:D] Stopped 2021-12-07T01:12:48.215Z,1638839568.215 [Default:CheckIn:E] Running Loop=1 2021-12-07T01:12:48.632Z,1638839568.632 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 72.576473 min 2021-12-07T01:12:48.632Z,1638839568.632 [Default:CheckIn:E] Stopped 2021-12-07T01:12:48.632Z,1638839568.632 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-07T01:12:48.632Z,1638839568.632 [Default:CheckIn] Stopped 2021-12-07T01:12:48.633Z,1638839568.633 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-07T01:12:48.633Z,1638839568.633 [Default:CheckIn](INFO): Running loop #30 2021-12-07T01:12:48.633Z,1638839568.633 [Default:CheckIn] Running Loop=30 2021-12-07T01:12:48.633Z,1638839568.633 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-07T01:12:48.633Z,1638839568.633 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-07T01:12:55.866Z,1638839575.866 [NAL9602](FAULT): GPS failed to acquire within timeout. 2021-12-07T01:12:55.866Z,1638839575.866 [NAL9602] Data Fault, FailCount= 2 2021-12-07T01:12:55.866Z,1638839575.866 [NAL9602](ERROR): Data Fault 2021-12-07T01:12:55.882Z,1638839575.882 [CBIT](ERROR): Data Fault in component: NAL9602 2021-12-07T01:12:56.263Z,1638839576.263 [NAL9602](INFO): Powering down 2021-12-07T01:12:57.089Z,1638839577.089 [CBIT](INFO): Clearing failed state for component NAL9602 2021-12-07T01:12:57.089Z,1638839577.089 [NAL9602] No Fault, FailCount= 2 2021-12-07T01:12:59.505Z,1638839579.505 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2021-12-07T01:12:59.505Z,1638839579.505 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 38 2021-12-07T01:12:59.505Z,1638839579.505 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-12-07T01:12:59.516Z,1638839579.516 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-12-07T01:12:59.926Z,1638839579.926 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-12-07T01:12:59.926Z,1638839579.926 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 38 2021-12-07T01:13:26.567Z,1638839606.567 [NAL9602](INFO): Powering up NAL9602 2021-12-07T01:13:37.475Z,1638839617.475 [NAL9602](INFO): NAL9602 initialized 2021-12-07T01:13:48.794Z,1638839628.794 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-12-07T01:12:48.6Z 2021-12-07T01:13:48.794Z,1638839628.794 [Default:CheckIn:Read_GPS] Stopped 2021-12-07T01:13:48.794Z,1638839628.794 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-07T01:13:51.185Z,1638839631.185 [DAT](INFO): #Outgoing data=1 2021-12-07T01:13:51.186Z,1638839631.186 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-12-07T01:13:51.281Z,1638839631.281 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-12-07T01:13:56.042Z,1638839636.042 [DAT](INFO): DAT read: Forwarding Delay UpTx time:01:12:04.0532 2021-12-07T01:13:56.042Z,1638839636.042 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-12-07T01:14:07.101Z,1638839647.101 [DAT](FAULT): Ack receipt timeout failure. 2021-12-07T01:14:07.101Z,1638839647.101 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2021-12-07T01:14:07.509Z,1638839647.509 [DAT](INFO): Sent 39 bytes from file Logs/20211206T235608/Courier0091.lzma.parts 2021-12-07T01:14:07.509Z,1638839647.509 [DAT](INFO): Packets left to send: 0 2021-12-07T01:14:07.513Z,1638839647.513 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2021-12-07T01:14:09.487Z,1638839649.487 [Default:CheckIn:Read_Iridium] Stopped 2021-12-07T01:14:09.487Z,1638839649.487 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-07T01:14:09.487Z,1638839649.487 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-07T01:14:16.268Z,1638839656.268 [CommandExec](IMPORTANT): got command quit 2021-12-07T01:14:17.272Z,1638839657.272 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread. 2021-12-07T01:14:17.272Z,1638839657.272 [CommandExec](INFO): Uninitializing the command executive. 2021-12-07T01:14:17.272Z,1638839657.272 [CommandExec](INFO): Uninitializing the command scheduler. 2021-12-07T01:14:17.273Z,1638839657.273 [CommandExec ThreadHandler](INFO): Thread cancelled. 2021-12-07T01:14:17.352Z,1638839657.352 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2021-12-07T01:14:17.352Z,1638839657.352 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2021-12-07T01:14:17.352Z,1638839657.352 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2021-12-07T01:14:17.353Z,1638839657.353 [NavChartDb](INFO): Join timeout helper Thread ID is 1850 2021-12-07T01:14:17.356Z,1638839657.356 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2021-12-07T01:14:17.356Z,1638839657.356 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2021-12-07T01:14:17.372Z,1638839657.372 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2021-12-07T01:14:17.372Z,1638839657.372 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2021-12-07T01:14:17.372Z,1638839657.372 [Radio_Surface](INFO): Join timeout helper Thread ID is 1851 2021-12-07T01:14:17.752Z,1638839657.752 [Radio_Surface](INFO): Powering down 2021-12-07T01:14:17.753Z,1638839657.753 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2021-12-07T01:14:17.753Z,1638839657.753 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2021-12-07T01:14:17.760Z,1638839657.760 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler 2021-12-07T01:14:17.760Z,1638839657.760 [Onboard ThreadHandler](INFO): Thread cancelled. 2021-12-07T01:14:17.760Z,1638839657.760 [Onboard](INFO): Join timeout helper Thread ID is 1852 2021-12-07T01:14:19.232Z,1638839659.232 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread. 2021-12-07T01:14:19.232Z,1638839659.232 [Onboard ThreadHandler](INFO): Thread cancelled. 2021-12-07T01:14:19.245Z,1638839659.245 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2021-12-07T01:14:19.245Z,1638839659.245 [logger ThreadHandler](INFO): Thread cancelled. 2021-12-07T01:14:19.245Z,1638839659.245 [logger](INFO): Join timeout helper Thread ID is 1853 2021-12-07T01:14:19.277Z,1638839659.277 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2021-12-07T01:14:19.277Z,1638839659.277 [logger ThreadHandler](INFO): Thread cancelled. 2021-12-07T01:14:19.284Z,1638839659.284 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2021-12-07T01:14:19.284Z,1638839659.284 [CommandLine ThreadHandler](INFO): Thread cancelled. 2021-12-07T01:14:19.284Z,1638839659.284 [CommandLine](INFO): Join timeout helper Thread ID is 1854 2021-12-07T01:14:19.360Z,1638839659.360 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2021-12-07T01:14:19.360Z,1638839659.360 [CommandLine ThreadHandler](INFO): Thread cancelled. 2021-12-07T01:14:19.365Z,1638839659.365 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler 2021-12-07T01:14:19.365Z,1638839659.365 [CommandExec ThreadHandler](INFO): Thread cancelled. 2021-12-07T01:14:19.365Z,1638839659.365 [CommandExec](INFO): Join timeout helper Thread ID is 1855 2021-12-07T01:14:19.366Z,1638839659.366 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2021-12-07T01:14:19.366Z,1638839659.366 [controlThread ThreadHandler](INFO): Thread cancelled. 2021-12-07T01:14:19.367Z,1638839659.367 [controlThread](INFO): Join timeout helper Thread ID is 1856 2021-12-07T01:14:19.596Z,1638839659.596 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2021-12-07T01:14:19.596Z,1638839659.596 [controlThread](DEBUG): Uninitializing ControlThread 2021-12-07T01:14:19.599Z,1638839659.599 [NAL9602](INFO): Powering down 2021-12-07T01:14:19.600Z,1638839659.600 [DAT](INFO): Powering down 2021-12-07T01:14:19.720Z,1638839659.720 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2021-12-07T01:14:19.721Z,1638839659.721 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2021-12-07T01:14:19.722Z,1638839659.722 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2021-12-07T01:14:19.722Z,1638839659.722 [MissionManager](INFO): Uninitializing Mission Default 2021-12-07T01:14:19.723Z,1638839659.723 [Default] Stopped 2021-12-07T01:14:19.723Z,1638839659.723 [Default](DEBUG): Aggregate::uninitialize Default 2021-12-07T01:14:19.723Z,1638839659.723 [Default:B.GoToSurface] Stopped 2021-12-07T01:14:19.723Z,1638839659.723 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2021-12-07T01:14:19.723Z,1638839659.723 [Default:CheckIn] Stopped 2021-12-07T01:14:19.723Z,1638839659.723 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-07T01:14:19.723Z,1638839659.723 [Default:CheckIn:C.Wait] Stopped 2021-12-07T01:14:19.723Z,1638839659.723 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-07T01:14:19.727Z,1638839659.727 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2021-12-07T01:14:19.727Z,1638839659.727 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2021-12-07T01:14:19.727Z,1638839659.727 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2021-12-07T01:14:19.727Z,1638839659.727 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2021-12-07T01:14:19.728Z,1638839659.728 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2021-12-07T01:14:19.728Z,1638839659.728 [BuoyancyServo](INFO): Powering down 2021-12-07T01:14:19.740Z,1638839659.740 [MassServo](DEBUG): Uninitialize Mass Servo. 2021-12-07T01:14:19.740Z,1638839659.740 [MassServo](INFO): Powering down 2021-12-07T01:14:19.741Z,1638839659.741 [SBIT](DEBUG): Uninitialize SBIT Component. 2021-12-07T01:14:19.741Z,1638839659.741 [IBIT](DEBUG): Uninitialize IBIT Component. 2021-12-07T01:14:19.742Z,1638839659.742 [CBIT](DEBUG): Uninitialize CBIT Component. 2021-12-07T01:14:19.742Z,1638839659.742 [CBIT](DEBUG): Powering off loads. 2021-12-07T01:14:19.756Z,1638839659.756 [CBIT](DEBUG): Disabling WDT. 2021-12-07T01:14:19.768Z,1638839659.768 [CBIT](DEBUG): Opening all GF detection circuits. 2021-12-07T01:14:19.769Z,1638839659.769 [controlThread ThreadHandler](INFO): Thread cancelled. 2021-12-07T01:14:19.840Z,1638839659.840 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2021-12-07T01:14:19.843Z,1638839659.843 [Onboard ThreadHandler](INFO): Thread cancelled. 2021-12-07T01:14:19.927Z,1638839659.927 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2021-12-07T01:14:19.985Z,1638839659.985 [logger ThreadHandler](INFO): Thread cancelled.