2021-11-18T21:29:12.007Z,1637270952.007 [Supervisor](DEBUG): Initializing supervisor. 2021-11-18T21:29:12.011Z,1637270952.011 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2021-11-18T21:29:12.012Z,1637270952.012 [SyncHandler](INFO): Protected caller Thread ID is 834 2021-11-18T21:29:12.012Z,1637270952.012 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2021-11-18T21:29:12.013Z,1637270952.013 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2021-11-18T21:29:12.014Z,1637270952.014 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 835 2021-11-18T21:29:12.018Z,1637270952.018 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2021-11-18T21:29:12.036Z,1637270952.036 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread. 2021-11-18T21:29:12.037Z,1637270952.037 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2021-11-18T21:29:12.038Z,1637270952.038 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 836 2021-11-18T21:29:12.043Z,1637270952.043 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2021-11-18T21:29:12.044Z,1637270952.044 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2021-11-18T21:29:12.044Z,1637270952.044 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 837 2021-11-18T21:29:12.046Z,1637270952.046 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2021-11-18T21:29:12.047Z,1637270952.047 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0 2021-11-18T21:29:12.047Z,1637270952.047 [logger ThreadHandler](INFO): Protected caller Thread ID is 838 2021-11-18T21:29:12.051Z,1637270952.051 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2021-11-18T21:29:12.052Z,1637270952.052 [Supervisor](INFO): Looking for Config files in directory: Config/ 2021-11-18T21:29:12.056Z,1637270952.056 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2021-11-18T21:29:12.305Z,1637270952.305 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2021-11-18T21:29:12.307Z,1637270952.307 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2021-11-18T21:29:12.390Z,1637270952.390 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2021-11-18T21:29:12.945Z,1637270952.945 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2021-11-18T21:29:12.947Z,1637270952.947 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2021-11-18T21:29:13.322Z,1637270953.322 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2021-11-18T21:29:13.323Z,1637270953.323 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2021-11-18T21:29:13.422Z,1637270953.422 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2021-11-18T21:29:13.423Z,1637270953.423 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2021-11-18T21:29:13.823Z,1637270953.823 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2021-11-18T21:29:13.825Z,1637270953.825 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2021-11-18T21:29:14.037Z,1637270954.037 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2021-11-18T21:29:14.039Z,1637270954.039 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2021-11-18T21:29:14.537Z,1637270954.537 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2021-11-18T21:29:14.539Z,1637270954.539 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2021-11-18T21:29:14.673Z,1637270954.673 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2021-11-18T21:29:14.674Z,1637270954.674 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2021-11-18T21:29:14.754Z,1637270954.754 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2021-11-18T21:29:15.491Z,1637270955.491 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2021-11-18T21:29:15.492Z,1637270955.492 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2021-11-18T21:29:16.442Z,1637270956.442 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2021-11-18T21:29:16.444Z,1637270956.444 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2021-11-18T21:29:16.653Z,1637270956.653 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2021-11-18T21:29:16.655Z,1637270956.655 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2021-11-18T21:29:16.769Z,1637270956.769 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2021-11-18T21:29:16.771Z,1637270956.771 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2021-11-18T21:29:16.931Z,1637270956.931 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2021-11-18T21:29:16.932Z,1637270956.932 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg 2021-11-18T21:29:17.178Z,1637270957.178 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock 2021-11-18T21:29:17.179Z,1637270957.179 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/ 2021-11-18T21:29:17.183Z,1637270957.183 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg 2021-11-18T21:29:17.277Z,1637270957.277 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg 2021-11-18T21:29:17.365Z,1637270957.365 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg 2021-11-18T21:29:17.470Z,1637270957.470 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg 2021-11-18T21:29:17.555Z,1637270957.555 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg 2021-11-18T21:29:17.653Z,1637270957.653 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg 2021-11-18T21:29:17.759Z,1637270957.759 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg 2021-11-18T21:29:17.959Z,1637270957.959 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg 2021-11-18T21:29:18.038Z,1637270958.038 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg 2021-11-18T21:29:18.197Z,1637270958.197 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg 2021-11-18T21:29:18.343Z,1637270958.343 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg 2021-11-18T21:29:18.466Z,1637270958.466 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg 2021-11-18T21:29:18.738Z,1637270958.738 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2021-11-18T21:29:18.738Z,1637270958.738 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2021-11-18T21:29:18.758Z,1637270958.758 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2021-11-18T21:29:18.833Z,1637270958.833 [VerticalControl](DEBUG): Construct VerticalControl. 2021-11-18T21:29:18.898Z,1637270958.898 [VerticalControl] Loaded 2021-11-18T21:29:18.899Z,1637270958.899 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2021-11-18T21:29:18.901Z,1637270958.901 [HorizontalControl](DEBUG): Construct HorizontalControl. 2021-11-18T21:29:18.942Z,1637270958.942 [HorizontalControl] Loaded 2021-11-18T21:29:18.942Z,1637270958.942 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2021-11-18T21:29:18.944Z,1637270958.944 [SpeedControl](DEBUG): Construct SpeedControl. 2021-11-18T21:29:18.948Z,1637270958.948 [SpeedControl] Loaded 2021-11-18T21:29:18.948Z,1637270958.948 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2021-11-18T21:29:18.951Z,1637270958.951 [LoopControl](DEBUG): Construct LoopControl. 2021-11-18T21:29:18.951Z,1637270958.951 [LoopControl] Loaded 2021-11-18T21:29:18.951Z,1637270958.951 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2021-11-18T21:29:18.952Z,1637270958.952 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2021-11-18T21:29:18.953Z,1637270958.953 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2021-11-18T21:29:18.969Z,1637270958.969 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2021-11-18T21:29:18.970Z,1637270958.970 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2021-11-18T21:29:19.108Z,1637270959.108 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2021-11-18T21:29:19.109Z,1637270959.109 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2021-11-18T21:29:19.309Z,1637270959.309 [BuoyancyServo] Loaded 2021-11-18T21:29:19.310Z,1637270959.310 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2021-11-18T21:29:19.330Z,1637270959.330 [ElevatorServo] Loaded 2021-11-18T21:29:19.330Z,1637270959.330 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2021-11-18T21:29:19.349Z,1637270959.349 [MassServo] Loaded 2021-11-18T21:29:19.350Z,1637270959.350 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2021-11-18T21:29:19.369Z,1637270959.369 [RudderServo] Loaded 2021-11-18T21:29:19.369Z,1637270959.369 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2021-11-18T21:29:19.387Z,1637270959.387 [ThrusterServo] Loaded 2021-11-18T21:29:19.388Z,1637270959.388 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2021-11-18T21:29:19.388Z,1637270959.388 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2021-11-18T21:29:19.389Z,1637270959.389 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2021-11-18T21:29:19.492Z,1637270959.492 [DeadReckonUsingMultipleVelocitySources] Loaded 2021-11-18T21:29:19.493Z,1637270959.493 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2021-11-18T21:29:19.507Z,1637270959.507 [NavChart] Loaded 2021-11-18T21:29:19.507Z,1637270959.507 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2021-11-18T21:29:19.513Z,1637270959.513 [UniversalFixResidualReporter] Loaded 2021-11-18T21:29:19.513Z,1637270959.513 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2021-11-18T21:29:19.514Z,1637270959.514 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2021-11-18T21:29:19.514Z,1637270959.514 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2021-11-18T21:29:19.601Z,1637270959.601 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2021-11-18T21:29:19.603Z,1637270959.603 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2021-11-18T21:29:20.314Z,1637270960.314 [AHRS_M2] Loaded 2021-11-18T21:29:20.314Z,1637270960.314 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2021-11-18T21:29:21.136Z,1637270961.136 [BPC1] Loaded 2021-11-18T21:29:21.136Z,1637270961.136 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2021-11-18T21:29:21.157Z,1637270961.157 [Depth_Keller] Loaded 2021-11-18T21:29:21.157Z,1637270961.157 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2021-11-18T21:29:21.162Z,1637270961.162 [DropWeight] Loaded 2021-11-18T21:29:21.163Z,1637270961.163 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2021-11-18T21:29:21.333Z,1637270961.333 [NAL9602] Loaded 2021-11-18T21:29:21.333Z,1637270961.333 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2021-11-18T21:29:21.427Z,1637270961.427 [Onboard] Loaded 2021-11-18T21:29:21.427Z,1637270961.427 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread. 2021-11-18T21:29:21.458Z,1637270961.458 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 408C64E0 2021-11-18T21:29:21.458Z,1637270961.458 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 923 2021-11-18T21:29:21.493Z,1637270961.493 [Power24vConverter] Loaded 2021-11-18T21:29:21.493Z,1637270961.493 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread. 2021-11-18T21:29:21.539Z,1637270961.539 [Radio_Surface] Loaded 2021-11-18T21:29:21.539Z,1637270961.539 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2021-11-18T21:29:21.540Z,1637270961.540 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408F64E0 2021-11-18T21:29:21.543Z,1637270961.543 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 924 2021-11-18T21:29:21.772Z,1637270961.772 [DAT] Loaded 2021-11-18T21:29:21.805Z,1637270961.805 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread. 2021-11-18T21:29:21.805Z,1637270961.805 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2021-11-18T21:29:21.806Z,1637270961.806 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2021-11-18T21:29:22.058Z,1637270962.058 [DepthRateCalculator] Loaded 2021-11-18T21:29:22.059Z,1637270962.059 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2021-11-18T21:29:22.064Z,1637270962.064 [PitchRateCalculator] Loaded 2021-11-18T21:29:22.064Z,1637270962.064 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2021-11-18T21:29:22.073Z,1637270962.073 [SpeedCalculator] Loaded 2021-11-18T21:29:22.074Z,1637270962.074 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2021-11-18T21:29:22.088Z,1637270962.088 [TempGradientCalculator] Loaded 2021-11-18T21:29:22.089Z,1637270962.089 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2021-11-18T21:29:22.093Z,1637270962.093 [YawRateCalculator] Loaded 2021-11-18T21:29:22.094Z,1637270962.094 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2021-11-18T21:29:22.112Z,1637270962.112 [ElevatorOffsetCalculator] Loaded 2021-11-18T21:29:22.113Z,1637270962.113 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2021-11-18T21:29:22.113Z,1637270962.113 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2021-11-18T21:29:22.114Z,1637270962.114 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2021-11-18T21:29:22.301Z,1637270962.301 [CANONSampler] Loaded 2021-11-18T21:29:22.301Z,1637270962.301 [ComponentRegistry](DEBUG): SyncComponent "CANONSampler" handled in the control thread. 2021-11-18T21:29:22.362Z,1637270962.362 [CTD_Seabird] Loaded 2021-11-18T21:29:22.363Z,1637270962.363 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2021-11-18T21:29:22.364Z,1637270962.364 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 409AB4E0 2021-11-18T21:29:22.364Z,1637270962.364 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 925 2021-11-18T21:29:22.385Z,1637270962.385 [PAR_Licor] Loaded 2021-11-18T21:29:22.386Z,1637270962.386 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2021-11-18T21:29:22.420Z,1637270962.420 [WetLabsBB2FL] Loaded 2021-11-18T21:29:22.420Z,1637270962.420 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2021-11-18T21:29:22.421Z,1637270962.421 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 409DB4E0 2021-11-18T21:29:22.421Z,1637270962.421 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 926 2021-11-18T21:29:22.422Z,1637270962.422 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2021-11-18T21:29:22.423Z,1637270962.423 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2021-11-18T21:29:22.466Z,1637270962.466 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2021-11-18T21:29:22.467Z,1637270962.467 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2021-11-18T21:29:22.862Z,1637270962.862 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2021-11-18T21:29:22.864Z,1637270962.864 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2021-11-18T21:29:23.050Z,1637270963.050 [SBIT](DEBUG): Construct Startup Built In Test. 2021-11-18T21:29:23.060Z,1637270963.060 [SBIT] Loaded 2021-11-18T21:29:23.060Z,1637270963.060 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2021-11-18T21:29:23.063Z,1637270963.063 [IBIT](DEBUG): Construct Initiated Built In Test. 2021-11-18T21:29:23.078Z,1637270963.078 [IBIT] Loaded 2021-11-18T21:29:23.078Z,1637270963.078 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2021-11-18T21:29:23.084Z,1637270963.084 [CBIT](DEBUG): Construct Continuous Built In Test. 2021-11-18T21:29:23.192Z,1637270963.192 [CBIT] Loaded 2021-11-18T21:29:23.192Z,1637270963.192 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2021-11-18T21:29:23.193Z,1637270963.193 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2021-11-18T21:29:23.193Z,1637270963.193 [Module Loader](DEBUG): Loading Module at Modules/Dock.so 2021-11-18T21:29:23.317Z,1637270963.317 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking) 2021-11-18T21:29:23.323Z,1637270963.323 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2021-11-18T21:29:23.326Z,1637270963.326 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2021-11-18T21:29:23.337Z,1637270963.337 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2021-11-18T21:29:23.338Z,1637270963.338 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B104E0 2021-11-18T21:29:23.338Z,1637270963.338 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 927 2021-11-18T21:29:23.343Z,1637270963.343 [Supervisor](INFO): Main Thread ID is 830 2021-11-18T21:29:23.343Z,1637270963.343 [Supervisor](DEBUG): Running supervisor. 2021-11-18T21:29:23.344Z,1637270963.344 [CommandExec ThreadHandler](INFO): Handler Thread ID is 928 2021-11-18T21:29:23.344Z,1637270963.344 [CommandExec](INFO): Initializing the command executive. 2021-11-18T21:29:23.346Z,1637270963.346 [CommandLine ThreadHandler](INFO): Handler Thread ID is 929 2021-11-18T21:29:23.348Z,1637270963.348 [controlThread ThreadHandler](INFO): Handler Thread ID is 930 2021-11-18T21:29:23.348Z,1637270963.348 [controlThread](DEBUG): Initializing ControlThread 2021-11-18T21:29:23.349Z,1637270963.349 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2021-11-18T21:29:23.351Z,1637270963.351 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2021-11-18T21:29:23.352Z,1637270963.352 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2021-11-18T21:29:23.353Z,1637270963.353 [LoopControl](DEBUG): Initialize LoopControlComponent. 2021-11-18T21:29:23.355Z,1637270963.355 [NavChart](DEBUG): Initialize NavChart Navigation. 2021-11-18T21:29:23.355Z,1637270963.355 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2021-11-18T21:29:23.359Z,1637270963.359 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2021-11-18T21:29:23.359Z,1637270963.359 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2021-11-18T21:29:23.360Z,1637270963.360 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2021-11-18T21:29:23.360Z,1637270963.360 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2021-11-18T21:29:23.361Z,1637270963.361 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2021-11-18T21:29:23.361Z,1637270963.361 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2021-11-18T21:29:23.365Z,1637270963.365 [SBIT](INFO): Initialize SBIT Component. 2021-11-18T21:29:23.365Z,1637270963.365 [SBIT](IMPORTANT): git: 2021-11-01-22-gea1679f0f 2021-11-18T21:29:23.366Z,1637270963.366 [SBIT](INFO): git hash: ea1679f0fbc9f895a669b42c70dfc339166fc8a2 2021-11-18T21:29:23.366Z,1637270963.366 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2021-11-18T21:29:23.367Z,1637270963.367 [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-11-18T21:29:23.368Z,1637270963.368 [SBIT](INFO): Beginning SBIT in 84.000000 seconds. 2021-11-18T21:29:23.369Z,1637270963.369 [IBIT](INFO): Initialize IBIT Component. 2021-11-18T21:29:23.370Z,1637270963.370 [CBIT](DEBUG): Initialize CBIT Component. 2021-11-18T21:29:23.371Z,1637270963.371 [logger ThreadHandler](INFO): Handler Thread ID is 931 2021-11-18T21:29:23.381Z,1637270963.381 [CBIT](DEBUG): Initialized mux pins. 2021-11-18T21:29:23.381Z,1637270963.381 [CBIT](DEBUG): Initializing the watchdog timer. 2021-11-18T21:29:23.389Z,1637270963.389 [Onboard ThreadHandler](INFO): Handler Thread ID is 932 2021-11-18T21:29:23.405Z,1637270963.405 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2021-11-18T21:29:23.406Z,1637270963.406 [CBIT](DEBUG): Initializing heartbeat. 2021-11-18T21:29:23.410Z,1637270963.410 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 933 2021-11-18T21:29:23.421Z,1637270963.421 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 934 2021-11-18T21:29:23.422Z,1637270963.422 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2021-11-18T21:29:23.425Z,1637270963.425 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 936 2021-11-18T21:29:23.429Z,1637270963.429 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 938 2021-11-18T21:29:23.430Z,1637270963.430 [WetLabsBB2FL](INFO): Powering up 2021-11-18T21:29:23.439Z,1637270963.439 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2021-11-18T21:29:23.439Z,1637270963.439 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2021-11-18T21:29:23.439Z,1637270963.439 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2021-11-18T21:29:23.439Z,1637270963.439 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2021-11-18T21:29:23.439Z,1637270963.439 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2021-11-18T21:29:23.440Z,1637270963.440 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2021-11-18T21:29:23.440Z,1637270963.440 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000 2021-11-18T21:29:23.440Z,1637270963.440 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2021-11-18T21:29:23.440Z,1637270963.440 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2021-11-18T21:29:23.440Z,1637270963.440 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2021-11-18T21:29:23.441Z,1637270963.441 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000 2021-11-18T21:29:23.441Z,1637270963.441 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2021-11-18T21:29:23.441Z,1637270963.441 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000 2021-11-18T21:29:23.442Z,1637270963.442 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2021-11-18T21:29:23.442Z,1637270963.442 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000 2021-11-18T21:29:23.442Z,1637270963.442 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2021-11-18T21:29:23.477Z,1637270963.477 [CBIT](DEBUG): Deactivating GF circuits. 2021-11-18T21:29:23.477Z,1637270963.477 [CBIT](DEBUG): Deactivating emergency mode. 2021-11-18T21:29:23.513Z,1637270963.513 [CBIT](DEBUG): Backplane powered. 2021-11-18T21:29:23.514Z,1637270963.514 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2021-11-18T21:29:23.561Z,1637270963.561 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2021-11-18T21:29:23.588Z,1637270963.588 [MissionManager](DEBUG): 2021-11-18T21:29:23.589Z,1637270963.589 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2021-11-18T21:29:23.659Z,1637270963.659 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2021-11-18T21:29:23.660Z,1637270963.660 [Default:A.Wait](DEBUG): Construct Wait. 2021-11-18T21:29:23.663Z,1637270963.663 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2021-11-18T21:29:23.711Z,1637270963.711 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2021-11-18T21:29:23.714Z,1637270963.714 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2021-11-18T21:29:23.735Z,1637270963.735 [Default:E.Execute](DEBUG): Construct Execute. 2021-11-18T21:29:23.739Z,1637270963.739 [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. 5 Default mission has been running for Restarting logs and Default mission. restart logs 2021-11-18T21:29:23.749Z,1637270963.749 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,DAT,CANONSampler,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2021-11-18T21:29:23.761Z,1637270963.761 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2021-11-18T21:29:23.825Z,1637270963.825 [Radio_Surface](INFO): Powering up 2021-11-18T21:29:23.937Z,1637270963.937 [Depth_Keller](ERROR): Pressure reading out of range: 1831.023193 decibar 2021-11-18T21:29:23.939Z,1637270963.939 [Power24vConverter](INFO): Powering up. 2021-11-18T21:29:23.939Z,1637270963.939 [DAT](INFO): Powering up 2021-11-18T21:29:23.940Z,1637270963.940 [DAT](DEBUG): Initializing DAT. 2021-11-18T21:29:23.957Z,1637270963.957 [CANONSampler](INFO): Powering down 2021-11-18T21:29:23.977Z,1637270963.977 [DepthRateCalculator](ERROR): Depth measurement is not active 2021-11-18T21:29:24.003Z,1637270964.003 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2021-11-18T21:29:24.009Z,1637270964.009 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2021-11-18T21:29:24.010Z,1637270964.010 [ElevatorServo](DEBUG): Initializing EZServoServo. 2021-11-18T21:29:24.021Z,1637270964.021 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2021-11-18T21:29:24.022Z,1637270964.022 [MassServo](DEBUG): Initializing EZServoServo. 2021-11-18T21:29:24.029Z,1637270964.029 [MassServo](DEBUG): Initializing MassServo. 2021-11-18T21:29:24.030Z,1637270964.030 [RudderServo](DEBUG): Initializing EZServoServo. 2021-11-18T21:29:24.037Z,1637270964.037 [RudderServo](DEBUG): Initializing RudderServo. 2021-11-18T21:29:24.038Z,1637270964.038 [ThrusterServo](DEBUG): Initializing EZServoServo. 2021-11-18T21:29:24.045Z,1637270964.045 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2021-11-18T21:29:24.183Z,1637270964.183 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2021-11-18T21:29:24.183Z,1637270964.183 [DropWeight] Hardware Fault, FailCount= 1 2021-11-18T21:29:24.183Z,1637270964.183 [DropWeight](ERROR): Hardware Fault 2021-11-18T21:29:24.213Z,1637270964.213 [CommandExec](FAULT): Scheduling is paused 2021-11-18T21:29:24.213Z,1637270964.213 [CBIT](INFO): Critical error at 20211118T212924 2021-11-18T21:29:24.213Z,1637270964.213 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals 2021-11-18T21:29:24.216Z,1637270964.216 [CBIT](ERROR): Hardware Fault in component: DropWeight 2021-11-18T21:29:24.237Z,1637270964.237 [CBIT](CRITICAL): Hardware Fault in component: DropWeight 2021-11-18T21:29:24.921Z,1637270964.921 [RudderServo](ERROR): Rudder initialization uart error serial timeout 2021-11-18T21:29:24.921Z,1637270964.921 [RudderServo](FAULT): Rudder failed to initialize 2021-11-18T21:29:24.921Z,1637270964.921 [RudderServo] Communications Fault, FailCount= 1 2021-11-18T21:29:24.921Z,1637270964.921 [RudderServo](ERROR): Communications Fault 2021-11-18T21:29:25.022Z,1637270965.022 [CBIT](INFO): Critical error at 20211118T212924 2021-11-18T21:29:25.025Z,1637270965.025 [CBIT](ERROR): Communications Fault in component: RudderServo 2021-11-18T21:29:25.202Z,1637270965.202 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2021-11-18T21:29:25.202Z,1637270965.202 [RudderServo](INFO): Powering down 2021-11-18T21:29:25.537Z,1637270965.537 [WetLabsBB2FL](INFO): Powering down 2021-11-18T21:29:25.870Z,1637270965.870 [RudderServo](DEBUG): Initializing EZServoServo. 2021-11-18T21:29:25.990Z,1637270965.990 [RudderServo](DEBUG): Initializing RudderServo. 2021-11-18T21:29:25.994Z,1637270965.994 [CBIT](INFO): Clearing failed state for component RudderServo 2021-11-18T21:29:25.994Z,1637270965.994 [RudderServo] No Fault, FailCount= 1 2021-11-18T21:29:35.547Z,1637270975.547 [DAT](INFO): DAT read: 2021-11-18T21:29:35.548Z,1637270975.548 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series 2021-11-18T21:29:37.160Z,1637270977.160 [DAT](INFO): DAT read: MF Frequency Band 2021-11-18T21:29:37.162Z,1637270977.162 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.14.2 2021-11-18T21:29:37.563Z,1637270977.563 [DAT](INFO): DAT read: Nov 18 2021 21:28:49 2021-11-18T21:29:38.372Z,1637270978.372 [DAT](INFO): DAT read: Features enabled [Bearing] 2021-11-18T21:29:38.373Z,1637270978.373 [DAT](INFO): DAT read: CONNECT 01200 bits/sec 1 of 4, Rate 1/2 CC 2021-11-18T21:29:38.373Z,1637270978.373 [DAT](INFO): commRate: 1200 2021-11-18T21:29:40.391Z,1637270980.391 [DAT](INFO): entering command mode 2021-11-18T21:29:40.795Z,1637270980.795 [DAT](INFO): DAT read: 2021-11-18T21:29:40.795Z,1637270980.795 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-18T21:29:41.199Z,1637270981.199 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-18T21:29:41.622Z,1637270981.622 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-18T21:29:42.011Z,1637270982.011 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-18T21:29:42.411Z,1637270982.411 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-18T21:29:42.815Z,1637270982.815 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-18T21:29:43.219Z,1637270983.219 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-18T21:29:43.623Z,1637270983.623 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-18T21:29:44.027Z,1637270984.027 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-18T21:29:44.435Z,1637270984.435 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-18T21:29:44.835Z,1637270984.835 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-18T21:29:45.239Z,1637270985.239 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-18T21:29:45.643Z,1637270985.643 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-18T21:29:46.050Z,1637270986.050 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-18T21:29:46.451Z,1637270986.451 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-18T21:29:46.855Z,1637270986.855 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-18T21:29:47.259Z,1637270987.259 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-18T21:29:47.671Z,1637270987.671 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-18T21:29:48.067Z,1637270988.067 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-18T21:29:48.471Z,1637270988.471 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-18T21:29:48.875Z,1637270988.875 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-18T21:29:49.279Z,1637270989.279 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-18T21:29:49.683Z,1637270989.683 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-18T21:29:50.087Z,1637270990.087 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-18T21:29:50.491Z,1637270990.491 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-18T21:29:50.895Z,1637270990.895 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-18T21:29:51.307Z,1637270991.307 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-18T21:29:51.703Z,1637270991.703 [NAL9602](INFO): Powering up NAL9602 2021-11-18T21:29:51.705Z,1637270991.705 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-18T21:29:52.107Z,1637270992.107 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-18T21:29:52.511Z,1637270992.511 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-18T21:29:52.919Z,1637270992.919 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-18T21:29:53.323Z,1637270993.323 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-18T21:29:53.723Z,1637270993.723 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-18T21:29:54.127Z,1637270994.127 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-18T21:29:54.539Z,1637270994.539 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-18T21:29:54.935Z,1637270994.935 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-18T21:29:55.339Z,1637270995.339 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-18T21:29:55.743Z,1637270995.743 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-18T21:29:55.743Z,1637270995.743 [DAT](FAULT): failed to enter command mode 2021-11-18T21:29:56.155Z,1637270996.155 [DAT](INFO): entering command mode 2021-11-18T21:29:56.551Z,1637270996.551 [DAT](INFO): DAT read: user:1> 2021-11-18T21:29:56.552Z,1637270996.552 [DAT](INFO): DAT read: Command '+++' not found 2021-11-18T21:29:56.553Z,1637270996.553 [DAT](INFO): DAT read: Error 2021-11-18T21:29:56.553Z,1637270996.553 [DAT](INFO): setting verbose to 3 2021-11-18T21:29:56.955Z,1637270996.955 [DAT](INFO): DAT read: user:2> 2021-11-18T21:29:56.957Z,1637270996.957 [DAT](INFO): DAT read: Verbose | 3 2021-11-18T21:29:56.957Z,1637270996.957 [DAT](INFO): set verbose to 3 2021-11-18T21:29:56.957Z,1637270996.957 [DAT](INFO): setting DatVerbose to 27440 2021-11-18T21:29:57.367Z,1637270997.367 [DAT](INFO): DAT read: user:3> 2021-11-18T21:29:57.368Z,1637270997.368 [DAT](INFO): DAT read: DatVerbose | 27440 2021-11-18T21:29:57.368Z,1637270997.368 [DAT](INFO): set DatVerbose to 27440 2021-11-18T21:29:57.369Z,1637270997.369 [DAT](INFO): setting transmit power to 8 2021-11-18T21:29:57.764Z,1637270997.764 [DAT](INFO): DAT read: user:4> 2021-11-18T21:29:57.765Z,1637270997.765 [DAT](INFO): DAT read: TxPower | 8 (Max) 2021-11-18T21:29:57.765Z,1637270997.765 [DAT](INFO): set transmit power to 8 2021-11-18T21:29:57.766Z,1637270997.766 [DAT](INFO): setting local address to 7 2021-11-18T21:29:58.171Z,1637270998.171 [DAT](INFO): DAT read: user:5> 2021-11-18T21:29:58.172Z,1637270998.172 [DAT](INFO): DAT read: LocalAddr | 7 2021-11-18T21:29:58.172Z,1637270998.172 [DAT](INFO): set local address to 7 2021-11-18T21:30:02.611Z,1637271002.611 [NAL9602](INFO): NAL9602 initialized 2021-11-18T21:30:47.893Z,1637271047.893 [SBIT](IMPORTANT): Beginning Startup BIT 2021-11-18T21:30:47.898Z,1637271047.898 [CBIT](IMPORTANT): Beginning ground fault scan 2021-11-18T21:30:58.828Z,1637271058.828 [CBIT](ERROR): Ground fault scan returned out of bounds value. Re-running scan. 2021-11-18T21:30:59.236Z,1637271059.236 [CBIT](IMPORTANT): Beginning ground fault scan 2021-11-18T21:31:10.127Z,1637271070.127 [CBIT](ERROR): Ground fault scan returned out of bounds value. Re-running scan. 2021-11-18T21:31:10.534Z,1637271070.534 [CBIT](IMPORTANT): Beginning ground fault scan 2021-11-18T21:31:21.442Z,1637271081.442 [CBIT](ERROR): Ground fault scan returned out of bounds value. Re-running scan. 2021-11-18T21:31:21.443Z,1637271081.443 [CBIT](IMPORTANT): Ground fault scan returned out of bounds value in succession 3 times. Will re-run scan on normal schedule. 2021-11-18T21:31:42.021Z,1637271102.021 [SBIT](IMPORTANT): SBIT PASSED 2021-11-18T21:31:42.022Z,1637271102.022 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2021-11-18T21:31:42.023Z,1637271102.023 [SBIT](IMPORTANT): AMEcho.loadAtStartup=0 bool; 2021-11-18T21:31:42.023Z,1637271102.023 [SBIT](IMPORTANT): BuoyancyServo.fastPumpDepth=6 meter; 2021-11-18T21:31:42.029Z,1637271102.029 [SBIT](IMPORTANT): CANONSampler.loadAtStartup=1 bool; 2021-11-18T21:31:42.029Z,1637271102.029 [SBIT](IMPORTANT): DAT.baud=9600 bit_per_second; 2021-11-18T21:31:42.029Z,1637271102.029 [SBIT](IMPORTANT): DAT.loadAtStartup=1 bool; 2021-11-18T21:31:42.029Z,1637271102.029 [SBIT](IMPORTANT): DAT.sbdAddress=1 enum; 2021-11-18T21:31:42.029Z,1637271102.029 [SBIT](IMPORTANT): DAT.surfaceThreshold=0 meter; 2021-11-18T21:31:42.029Z,1637271102.029 [SBIT](IMPORTANT): DAT.verbosity=3 count; 2021-11-18T21:31:42.029Z,1637271102.029 [SBIT](IMPORTANT): DataOverHttps.loadAtStartup=0 bool; 2021-11-18T21:31:42.030Z,1637271102.030 [SBIT](IMPORTANT): ESPComponent.loadAtStartup=0 bool; 2021-11-18T21:31:42.030Z,1637271102.030 [SBIT](IMPORTANT): ESPComponent.simulateHardware=1 bool; 2021-11-18T21:31:42.030Z,1637271102.030 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=296 cubic_centimeter; 2021-11-18T21:31:42.030Z,1637271102.030 [SBIT](IMPORTANT): VerticalControl.massDefault=-16 millimeter; 2021-11-18T21:31:42.030Z,1637271102.030 [SBIT](IMPORTANT): VerticalControl.surfaceThreshold=2 meter; 2021-11-18T21:31:42.412Z,1637271102.412 [MissionManager](IMPORTANT): Started mission Startup 2021-11-18T21:31:42.413Z,1637271102.413 [Startup] Running Loop=1 2021-11-18T21:31:42.413Z,1637271102.413 [Startup](DEBUG): Aggregate::initialize Startup 2021-11-18T21:31:42.413Z,1637271102.413 [Startup:A.GoToSurface] Running Loop=1 2021-11-18T21:31:42.413Z,1637271102.413 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2021-11-18T21:31:42.414Z,1637271102.414 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2021-11-18T21:31:42.414Z,1637271102.414 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2021-11-18T21:31:42.415Z,1637271102.415 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2021-11-18T21:31:42.415Z,1637271102.415 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2021-11-18T21:31:42.415Z,1637271102.415 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2021-11-18T21:31:42.417Z,1637271102.417 [Startup:StartupSatComms] Running Loop=1 2021-11-18T21:31:42.418Z,1637271102.418 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2021-11-18T21:31:42.418Z,1637271102.418 [Startup:StartupSatComms:A] Running Loop=1 2021-11-18T21:31:42.824Z,1637271102.824 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2021-11-18T21:32:23.643Z,1637271143.643 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2021-11-18T21:32:23.643Z,1637271143.643 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-11-18T21:32:23.654Z,1637271143.654 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-11-18T21:32:24.062Z,1637271144.062 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-11-18T21:32:24.062Z,1637271144.062 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2021-11-18T21:32:42.620Z,1637271162.620 [Startup:StartupSatComms:A](INFO): Timed out from 2021-11-18T21:31:42.4Z 2021-11-18T21:32:42.620Z,1637271162.620 [Startup:StartupSatComms:A] Stopped 2021-11-18T21:32:42.621Z,1637271162.621 [Startup:StartupSatComms:B] Running Loop=1 2021-11-18T21:32:43.039Z,1637271163.039 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2021-11-18T21:32:44.167Z,1637271164.167 [DAT](INFO): #Outgoing data=1 2021-11-18T21:32:44.168Z,1637271164.168 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-11-18T21:32:44.260Z,1637271164.260 [DAT](INFO): setting remote address to 1 2021-11-18T21:32:44.608Z,1637271164.608 [DAT](INFO): DAT read: user:6> 2021-11-18T21:32:44.613Z,1637271164.613 [DAT](INFO): DAT read: RemoteAddr | 1 2021-11-18T21:32:44.614Z,1637271164.614 [DAT](INFO): set remote address to 1 2021-11-18T21:32:44.615Z,1637271164.615 [DAT](INFO): entering online mode 2021-11-18T21:32:45.011Z,1637271165.011 [DAT](INFO): DAT read: user:7> 2021-11-18T21:32:45.012Z,1637271165.012 [DAT](INFO): DAT read: 2021-11-18T21:32:45.013Z,1637271165.013 [DAT](INFO): DAT read: CONNECT 01200 bits/sec 1 of 4, Rate 1/2 CC 2021-11-18T21:32:45.014Z,1637271165.014 [DAT](INFO): commRate: 1200 2021-11-18T21:32:45.014Z,1637271165.014 [DAT](INFO): online mode acknowledged 2021-11-18T21:32:45.015Z,1637271165.015 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-11-18T21:32:48.292Z,1637271168.292 [DAT](INFO): DAT read: Forwarding Delay UpTx time:21:32:10.1786 2021-11-18T21:32:48.292Z,1637271168.292 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-11-18T21:32:58.344Z,1637271178.344 [DAT](FAULT): Ack receipt timeout failure. 2021-11-18T21:32:58.344Z,1637271178.344 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2021-11-18T21:32:59.274Z,1637271179.274 [DAT](INFO): #Outgoing data=1 2021-11-18T21:32:59.275Z,1637271179.275 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-11-18T21:32:59.365Z,1637271179.365 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-11-18T21:33:03.023Z,1637271183.023 [DAT](INFO): DAT read: Forwarding Delay UpTx time:21:32:24.5284 2021-11-18T21:33:03.023Z,1637271183.023 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-11-18T21:33:13.062Z,1637271193.062 [DAT](FAULT): Ack receipt timeout failure. 2021-11-18T21:33:13.062Z,1637271193.062 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2021-11-18T21:33:13.985Z,1637271193.985 [DAT](INFO): #Outgoing data=2 2021-11-18T21:33:13.985Z,1637271193.985 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-11-18T21:33:14.071Z,1637271194.071 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-11-18T21:33:17.686Z,1637271197.686 [DAT](INFO): DAT read: Forwarding Delay UpTx time:21:32:39.2281 2021-11-18T21:33:17.687Z,1637271197.687 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-11-18T21:33:27.778Z,1637271207.778 [DAT](FAULT): Ack receipt timeout failure. 2021-11-18T21:33:27.778Z,1637271207.778 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2021-11-18T21:33:28.962Z,1637271208.962 [DAT](INFO): #Outgoing data=3 2021-11-18T21:33:28.962Z,1637271208.962 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-11-18T21:33:29.074Z,1637271209.074 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-11-18T21:33:32.656Z,1637271212.656 [DAT](INFO): DAT read: Forwarding Delay UpTx time:21:32:54.2292 2021-11-18T21:33:32.656Z,1637271212.656 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-11-18T21:33:42.743Z,1637271222.743 [DAT](FAULT): Ack receipt timeout failure. 2021-11-18T21:33:42.743Z,1637271222.743 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2021-11-18T21:33:42.752Z,1637271222.752 [Startup:StartupSatComms:B](INFO): Timed out from 2021-11-18T21:32:42.6Z 2021-11-18T21:33:42.752Z,1637271222.752 [Startup:StartupSatComms:B] Stopped 2021-11-18T21:33:42.752Z,1637271222.752 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2021-11-18T21:33:42.752Z,1637271222.752 [Startup:StartupSatComms] Stopped 2021-11-18T21:33:42.752Z,1637271222.752 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2021-11-18T21:33:42.754Z,1637271222.754 [Startup](INFO): Completed Startup 2021-11-18T21:33:42.754Z,1637271222.754 [MissionManager](INFO): Startup is completed. 2021-11-18T21:33:42.754Z,1637271222.754 [MissionManager](INFO): Uninitializing Mission Startup 2021-11-18T21:33:42.754Z,1637271222.754 [Startup] Stopped 2021-11-18T21:33:42.754Z,1637271222.754 [Startup](DEBUG): Aggregate::uninitialize Startup 2021-11-18T21:33:42.754Z,1637271222.754 [Startup:A.GoToSurface] Stopped 2021-11-18T21:33:42.754Z,1637271222.754 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2021-11-18T21:33:43.148Z,1637271223.148 [DAT](INFO): Sent 39 bytes from file Logs/20211118T210305/Courier0007.lzma.parts 2021-11-18T21:33:43.149Z,1637271223.149 [DAT](INFO): Packets left to send: 0 2021-11-18T21:33:43.151Z,1637271223.151 [DAT](DEBUG): In sendingVerified, sbd done so set commsState_ = SENDING_FILL_BUFFER 2021-11-18T21:33:43.160Z,1637271223.160 [MissionManager](IMPORTANT): Started mission Default 2021-11-18T21:33:43.160Z,1637271223.160 [Default] Running Loop=1 2021-11-18T21:33:43.160Z,1637271223.160 [Default](DEBUG): Aggregate::initialize Default 2021-11-18T21:33:43.160Z,1637271223.160 [Default:B.GoToSurface] Running Loop=1 2021-11-18T21:33:43.160Z,1637271223.160 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2021-11-18T21:33:43.160Z,1637271223.160 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2021-11-18T21:33:43.161Z,1637271223.161 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2021-11-18T21:33:43.161Z,1637271223.161 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2021-11-18T21:33:43.162Z,1637271223.162 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2021-11-18T21:33:43.162Z,1637271223.162 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2021-11-18T21:33:43.162Z,1637271223.162 [Default:A.Wait] Running Loop=1 2021-11-18T21:33:43.162Z,1637271223.162 [Default:A.Wait](DEBUG): Initialize Wait Component. 2021-11-18T21:33:43.626Z,1637271223.626 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-11-18T21:33:43.971Z,1637271223.971 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-11-18T21:33:47.188Z,1637271227.188 [DAT](INFO): DAT read: Forwarding Delay UpTx time:21:33:09.1277 2021-11-18T21:33:47.188Z,1637271227.188 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-11-18T21:33:56.486Z,1637271236.486 [Default:A.Wait](INFO): Done Waiting. 2021-11-18T21:33:56.486Z,1637271236.486 [Default:A.Wait] Stopped 2021-11-18T21:33:56.486Z,1637271236.486 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2021-11-18T21:33:56.955Z,1637271236.955 [Default:CheckIn] Running Loop=1 2021-11-18T21:33:56.955Z,1637271236.955 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-11-18T21:33:56.955Z,1637271236.955 [Default:CheckIn:Read_GPS] Running Loop=1 2021-11-18T21:33:57.289Z,1637271237.289 [DAT](FAULT): Ack receipt timeout failure. 2021-11-18T21:33:57.289Z,1637271237.289 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2021-11-18T21:33:57.298Z,1637271237.298 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2021-11-18T21:33:57.703Z,1637271237.703 [DAT](DEBUG): In sendingVerified, sbd done so set commsState_ = SENDING_FILL_BUFFER 2021-11-18T21:33:58.171Z,1637271238.171 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-11-18T21:33:58.528Z,1637271238.528 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-11-18T21:34:02.136Z,1637271242.136 [DAT](INFO): DAT read: Forwarding Delay UpTx time:21:33:23.6775 2021-11-18T21:34:02.136Z,1637271242.136 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-11-18T21:34:12.251Z,1637271252.251 [DAT](FAULT): Ack receipt timeout failure. 2021-11-18T21:34:12.252Z,1637271252.252 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2021-11-18T21:34:12.642Z,1637271252.642 [DAT](DEBUG): In sendingVerified, sbd done so set commsState_ = SENDING_FILL_BUFFER 2021-11-18T21:34:13.044Z,1637271253.044 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-11-18T21:34:13.448Z,1637271253.448 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-11-18T21:34:17.084Z,1637271257.084 [DAT](INFO): DAT read: Forwarding Delay UpTx time:21:33:38.6273 2021-11-18T21:34:17.084Z,1637271257.084 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-11-18T21:34:27.183Z,1637271267.183 [DAT](FAULT): Ack receipt timeout failure. 2021-11-18T21:34:27.183Z,1637271267.183 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2021-11-18T21:34:27.588Z,1637271267.588 [DAT](DEBUG): In sendingVerified, sbd done so set commsState_ = SENDING_FILL_BUFFER 2021-11-18T21:35:05.993Z,1637271305.993 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-11-18T21:35:24.580Z,1637271324.580 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2 2021-11-18T21:35:24.581Z,1637271324.581 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-11-18T21:35:24.592Z,1637271324.592 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-11-18T21:35:25.007Z,1637271325.007 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-11-18T21:35:25.007Z,1637271325.007 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2 2021-11-18T21:35:31.418Z,1637271331.418 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2021-11-18T21:35:31.421Z,1637271331.421 [BPC1](INFO): Received data from all battery sticks. 2021-11-18T21:37:16.878Z,1637271436.878 [DAT](INFO): DAT read: Lowpower 2021-11-18T21:37:16.879Z,1637271436.879 [DAT](INFO): unknown deviceResponse_: Lowpower 2021-11-18T21:38:25.560Z,1637271505.560 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3 2021-11-18T21:38:25.561Z,1637271505.561 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-11-18T21:38:25.597Z,1637271505.597 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-11-18T21:38:26.001Z,1637271506.001 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-11-18T21:38:26.001Z,1637271506.001 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3 2021-11-18T21:38:57.064Z,1637271537.064 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-11-18T21:33:56.0Z 2021-11-18T21:38:57.064Z,1637271537.064 [Default:CheckIn:Read_GPS] Stopped 2021-11-18T21:38:57.064Z,1637271537.064 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-11-18T21:38:57.468Z,1637271537.468 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2021-11-18T21:38:58.367Z,1637271538.367 [DAT](INFO): #Outgoing data=1 2021-11-18T21:38:58.367Z,1637271538.367 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-11-18T21:38:58.455Z,1637271538.455 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-11-18T21:38:58.808Z,1637271538.808 [DAT](INFO): DAT read: UART Wakeup 2021-11-18T21:38:58.809Z,1637271538.809 [DAT](INFO): DAT read: CONNECT 01200 bits/sec 1 of 4, Rate 1/2 CC 2021-11-18T21:38:58.809Z,1637271538.809 [DAT](INFO): commRate: 1200 2021-11-18T21:39:02.041Z,1637271542.041 [DAT](INFO): DAT read: Forwarding Delay UpTx time:21:38:26.4793 2021-11-18T21:39:02.041Z,1637271542.041 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-11-18T21:39:12.139Z,1637271552.139 [DAT](FAULT): Ack receipt timeout failure. 2021-11-18T21:39:12.140Z,1637271552.140 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2021-11-18T21:39:12.540Z,1637271552.540 [DAT](INFO): Sent 184 bytes from file Logs/20211118T211551/Courier0000.lzma.parts 2021-11-18T21:39:12.540Z,1637271552.540 [DAT](INFO): Packets left to send: 1 2021-11-18T21:39:12.542Z,1637271552.542 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2021-11-18T21:39:13.436Z,1637271553.436 [DAT](INFO): #Outgoing data=1 2021-11-18T21:39:13.436Z,1637271553.436 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-11-18T21:39:13.532Z,1637271553.532 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-11-18T21:39:17.124Z,1637271557.124 [DAT](INFO): DAT read: Forwarding Delay UpTx time:21:38:41.4264 2021-11-18T21:39:17.124Z,1637271557.124 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-11-18T21:39:26.819Z,1637271566.819 [NAL9602](ERROR): Queried for signal strength and failed to receive proper response. 2021-11-18T21:39:26.893Z,1637271566.893 [NAL9602](ERROR): received: +CSQ:0 OK 2021-11-18T21:39:27.220Z,1637271567.220 [DAT](FAULT): Ack receipt timeout failure. 2021-11-18T21:39:27.220Z,1637271567.220 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2021-11-18T21:39:27.639Z,1637271567.639 [DAT](INFO): Sent 99 bytes from file Logs/20211118T211551/Courier0000.lzma.parts 2021-11-18T21:39:27.639Z,1637271567.639 [DAT](INFO): Packets left to send: 0 2021-11-18T21:39:27.641Z,1637271567.641 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2021-11-18T21:39:28.536Z,1637271568.536 [DAT](INFO): #Outgoing data=1 2021-11-18T21:39:28.536Z,1637271568.536 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-11-18T21:39:28.635Z,1637271568.635 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-11-18T21:39:32.359Z,1637271572.359 [DAT](INFO): DAT read: Forwarding Delay UpTx time:21:38:56.9371 2021-11-18T21:39:32.359Z,1637271572.359 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-11-18T21:39:42.754Z,1637271582.754 [DAT](FAULT): Ack receipt timeout failure. 2021-11-18T21:39:42.754Z,1637271582.754 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2021-11-18T21:39:43.642Z,1637271583.642 [DAT](INFO): Sent 168 bytes from file Logs/20211118T211551/Courier0004.lzma.parts 2021-11-18T21:39:43.642Z,1637271583.642 [DAT](INFO): Packets left to send: 0 2021-11-18T21:39:43.645Z,1637271583.645 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2021-11-18T21:39:44.224Z,1637271584.224 [DAT](INFO): #Outgoing data=1 2021-11-18T21:39:44.225Z,1637271584.225 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-11-18T21:39:44.331Z,1637271584.331 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-11-18T21:39:48.007Z,1637271588.007 [DAT](INFO): DAT read: Forwarding Delay UpTx time:21:39:12.4869 2021-11-18T21:39:48.008Z,1637271588.008 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-11-18T21:39:58.058Z,1637271598.058 [DAT](FAULT): Ack receipt timeout failure. 2021-11-18T21:39:58.058Z,1637271598.058 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2021-11-18T21:39:58.455Z,1637271598.455 [DAT](INFO): Sent 39 bytes from file Logs/20211118T211551/Courier0007.lzma.parts 2021-11-18T21:39:58.456Z,1637271598.456 [DAT](INFO): Packets left to send: 0 2021-11-18T21:39:58.458Z,1637271598.458 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2021-11-18T21:39:59.342Z,1637271599.342 [DAT](INFO): #Outgoing data=1 2021-11-18T21:39:59.342Z,1637271599.342 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-11-18T21:39:59.463Z,1637271599.463 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-11-18T21:40:03.195Z,1637271603.195 [DAT](INFO): DAT read: Forwarding Delay UpTx time:21:39:27.7869 2021-11-18T21:40:03.195Z,1637271603.195 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-11-18T21:40:05.866Z,1637271605.866 [NAL9602](FAULT): GPS failed to acquire within timeout. 2021-11-18T21:40:05.866Z,1637271605.866 [NAL9602] Data Fault, FailCount= 1 2021-11-18T21:40:05.867Z,1637271605.867 [NAL9602](ERROR): Data Fault 2021-11-18T21:40:05.919Z,1637271605.919 [CBIT](ERROR): Data Fault in component: NAL9602 2021-11-18T21:40:06.298Z,1637271606.298 [NAL9602](INFO): Powering down 2021-11-18T21:40:07.126Z,1637271607.126 [CBIT](INFO): Clearing failed state for component NAL9602 2021-11-18T21:40:07.126Z,1637271607.126 [NAL9602] No Fault, FailCount= 1 2021-11-18T21:40:13.548Z,1637271613.548 [DAT](FAULT): Ack receipt timeout failure. 2021-11-18T21:40:13.548Z,1637271613.548 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2021-11-18T21:40:13.947Z,1637271613.947 [DAT](INFO): Sent 184 bytes from file Logs/20211118T212911/Courier0000.lzma.parts 2021-11-18T21:40:13.947Z,1637271613.947 [DAT](INFO): Packets left to send: 1 2021-11-18T21:40:13.949Z,1637271613.949 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2021-11-18T21:40:15.578Z,1637271615.578 [DAT](INFO): #Outgoing data=1 2021-11-18T21:40:15.585Z,1637271615.585 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-11-18T21:40:15.746Z,1637271615.746 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-11-18T21:40:19.279Z,1637271619.279 [DAT](INFO): DAT read: Forwarding Delay UpTx time:21:39:43.8365 2021-11-18T21:40:19.280Z,1637271619.280 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-11-18T21:40:29.379Z,1637271629.379 [DAT](FAULT): Ack receipt timeout failure. 2021-11-18T21:40:29.379Z,1637271629.379 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2021-11-18T21:40:29.783Z,1637271629.783 [DAT](INFO): Sent 56 bytes from file Logs/20211118T212911/Courier0000.lzma.parts 2021-11-18T21:40:29.783Z,1637271629.783 [DAT](INFO): Packets left to send: 0 2021-11-18T21:40:29.785Z,1637271629.785 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2021-11-18T21:40:30.697Z,1637271630.697 [DAT](INFO): #Outgoing data=1 2021-11-18T21:40:30.697Z,1637271630.697 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-11-18T21:40:30.780Z,1637271630.780 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-11-18T21:40:34.387Z,1637271634.387 [DAT](INFO): DAT read: Forwarding Delay UpTx time:21:39:59.0863 2021-11-18T21:40:34.388Z,1637271634.388 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-11-18T21:40:36.407Z,1637271636.407 [NAL9602](INFO): Powering up NAL9602 2021-11-18T21:40:44.487Z,1637271644.487 [DAT](FAULT): Ack receipt timeout failure. 2021-11-18T21:40:44.487Z,1637271644.487 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2021-11-18T21:40:44.895Z,1637271644.895 [DAT](INFO): Sent 168 bytes from file Logs/20211118T212911/Courier0004.lzma.parts 2021-11-18T21:40:44.895Z,1637271644.895 [DAT](INFO): Packets left to send: 0 2021-11-18T21:40:44.898Z,1637271644.898 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2021-11-18T21:40:45.806Z,1637271645.806 [Default:CheckIn:Read_Iridium] Stopped 2021-11-18T21:40:45.806Z,1637271645.806 [Default:CheckIn:C.Wait] Running Loop=1 2021-11-18T21:40:45.806Z,1637271645.806 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-11-18T21:40:47.450Z,1637271647.450 [NAL9602](INFO): NAL9602 initialized 2021-11-18T21:41:26.642Z,1637271686.642 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4 2021-11-18T21:41:26.642Z,1637271686.642 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-11-18T21:41:26.654Z,1637271686.654 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-11-18T21:41:27.075Z,1637271687.075 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-11-18T21:41:27.075Z,1637271687.075 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4 2021-11-18T21:43:34.305Z,1637271814.305 [DAT](INFO): DAT read: Lowpower 2021-11-18T21:43:34.305Z,1637271814.305 [DAT](INFO): unknown deviceResponse_: Lowpower 2021-11-18T21:44:24.418Z,1637271864.418 [CBIT](INFO): Clearing failed state for component DropWeight 2021-11-18T21:44:24.418Z,1637271864.418 [DropWeight] No Fault, FailCount= 1 2021-11-18T21:44:27.639Z,1637271867.639 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5 2021-11-18T21:44:27.639Z,1637271867.639 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-11-18T21:44:27.650Z,1637271867.650 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-11-18T21:44:28.073Z,1637271868.073 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-11-18T21:44:28.073Z,1637271868.073 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5 2021-11-18T21:45:46.019Z,1637271946.019 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-11-18T21:45:46.019Z,1637271946.019 [Default:CheckIn:C.Wait] Stopped 2021-11-18T21:45:46.019Z,1637271946.019 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-11-18T21:45:46.019Z,1637271946.019 [Default:CheckIn:D] Running Loop=1 2021-11-18T21:45:46.432Z,1637271946.432 [Default:CheckIn:D] Stopped 2021-11-18T21:45:46.432Z,1637271946.432 [Default:CheckIn:E] Running Loop=1 2021-11-18T21:45:46.855Z,1637271946.855 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 12.054530 min 2021-11-18T21:45:46.855Z,1637271946.855 [Default:CheckIn:E] Stopped 2021-11-18T21:45:46.856Z,1637271946.856 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-11-18T21:45:46.856Z,1637271946.856 [Default:CheckIn] Stopped 2021-11-18T21:45:46.856Z,1637271946.856 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-11-18T21:45:46.856Z,1637271946.856 [Default:CheckIn](INFO): Running loop #2 2021-11-18T21:45:46.856Z,1637271946.856 [Default:CheckIn] Running Loop=2 2021-11-18T21:45:46.856Z,1637271946.856 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-11-18T21:45:46.856Z,1637271946.856 [Default:CheckIn:Read_GPS] Running Loop=1 2021-11-18T21:47:28.655Z,1637272048.655 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6 2021-11-18T21:47:28.655Z,1637272048.655 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-11-18T21:47:28.687Z,1637272048.687 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-11-18T21:47:29.050Z,1637272049.050 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-11-18T21:47:29.050Z,1637272049.050 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6 2021-11-18T21:50:29.635Z,1637272229.635 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7 2021-11-18T21:50:29.635Z,1637272229.635 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-11-18T21:50:29.646Z,1637272229.646 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-11-18T21:50:30.050Z,1637272230.050 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-11-18T21:50:30.050Z,1637272230.050 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7 2021-11-18T21:50:47.005Z,1637272247.005 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-11-18T21:45:46.9Z 2021-11-18T21:50:47.005Z,1637272247.005 [Default:CheckIn:Read_GPS] Stopped 2021-11-18T21:50:47.005Z,1637272247.005 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-11-18T21:50:49.024Z,1637272249.024 [DAT](INFO): #Outgoing data=1 2021-11-18T21:50:49.025Z,1637272249.025 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-11-18T21:50:49.139Z,1637272249.139 [NAL9602](FAULT): GPS failed to acquire within timeout. 2021-11-18T21:50:49.139Z,1637272249.139 [NAL9602] Data Fault, FailCount= 2 2021-11-18T21:50:49.139Z,1637272249.139 [NAL9602](ERROR): Data Fault 2021-11-18T21:50:49.141Z,1637272249.141 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-11-18T21:50:49.241Z,1637272249.241 [CBIT](ERROR): Data Fault in component: NAL9602 2021-11-18T21:50:49.518Z,1637272249.518 [NAL9602](INFO): Powering down 2021-11-18T21:50:49.520Z,1637272249.520 [DAT](INFO): DAT read: UART Wakeup 2021-11-18T21:50:49.522Z,1637272249.522 [DAT](INFO): DAT read: CONNECT 01200 bits/sec 1 of 4, Rate 1/2 CC 2021-11-18T21:50:49.522Z,1637272249.522 [DAT](INFO): commRate: 1200 2021-11-18T21:50:50.344Z,1637272250.344 [CBIT](INFO): Clearing failed state for component NAL9602 2021-11-18T21:50:50.344Z,1637272250.344 [NAL9602] No Fault, FailCount= 2 2021-11-18T21:50:52.752Z,1637272252.752 [DAT](INFO): DAT read: Forwarding Delay UpTx time:21:50:16.3318 2021-11-18T21:50:52.752Z,1637272252.752 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-11-18T21:51:02.848Z,1637272262.848 [DAT](FAULT): Ack receipt timeout failure. 2021-11-18T21:51:02.848Z,1637272262.848 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2021-11-18T21:51:03.255Z,1637272263.255 [DAT](INFO): Sent 39 bytes from file Logs/20211118T212911/Courier0007.lzma.parts 2021-11-18T21:51:03.256Z,1637272263.256 [DAT](INFO): Packets left to send: 0 2021-11-18T21:51:03.258Z,1637272263.258 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2021-11-18T21:51:04.157Z,1637272264.157 [Default:CheckIn:Read_Iridium] Stopped 2021-11-18T21:51:04.157Z,1637272264.157 [Default:CheckIn:C.Wait] Running Loop=1 2021-11-18T21:51:04.157Z,1637272264.157 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-11-18T21:51:19.534Z,1637272279.534 [NAL9602](INFO): Powering up NAL9602 2021-11-18T21:51:30.443Z,1637272290.443 [NAL9602](INFO): NAL9602 initialized 2021-11-18T21:53:30.451Z,1637272410.451 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8 2021-11-18T21:53:30.451Z,1637272410.451 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-11-18T21:53:30.462Z,1637272410.462 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-11-18T21:53:30.861Z,1637272410.861 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-11-18T21:53:30.861Z,1637272410.861 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8 2021-11-18T21:53:52.652Z,1637272432.652 [DAT](INFO): DAT read: Lowpower 2021-11-18T21:53:52.652Z,1637272432.652 [DAT](INFO): unknown deviceResponse_: Lowpower 2021-11-18T21:56:04.398Z,1637272564.398 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-11-18T21:56:04.398Z,1637272564.398 [Default:CheckIn:C.Wait] Stopped 2021-11-18T21:56:04.398Z,1637272564.398 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-11-18T21:56:04.398Z,1637272564.398 [Default:CheckIn:D] Running Loop=1 2021-11-18T21:56:04.788Z,1637272564.788 [Default:CheckIn:D] Stopped 2021-11-18T21:56:04.788Z,1637272564.788 [Default:CheckIn:E] Running Loop=1 2021-11-18T21:56:05.180Z,1637272565.180 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 22.360468 min 2021-11-18T21:56:05.180Z,1637272565.180 [Default:CheckIn:E] Stopped 2021-11-18T21:56:05.180Z,1637272565.180 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-11-18T21:56:05.180Z,1637272565.180 [Default:CheckIn] Stopped 2021-11-18T21:56:05.180Z,1637272565.180 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-11-18T21:56:05.185Z,1637272565.185 [Default:CheckIn](INFO): Running loop #3 2021-11-18T21:56:05.187Z,1637272565.187 [Default:CheckIn] Running Loop=3 2021-11-18T21:56:05.187Z,1637272565.187 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-11-18T21:56:05.187Z,1637272565.187 [Default:CheckIn:Read_GPS] Running Loop=1 2021-11-18T21:56:31.440Z,1637272591.440 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 9 2021-11-18T21:56:31.440Z,1637272591.440 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-11-18T21:56:31.451Z,1637272591.451 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-11-18T21:56:31.864Z,1637272591.864 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-11-18T21:56:31.864Z,1637272591.864 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 9 2021-11-18T21:59:32.426Z,1637272772.426 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 10 2021-11-18T21:59:32.426Z,1637272772.426 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-11-18T21:59:32.438Z,1637272772.438 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-11-18T21:59:32.852Z,1637272772.852 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-11-18T21:59:32.852Z,1637272772.852 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 10 2021-11-18T22:01:05.345Z,1637272865.345 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-11-18T21:56:05.2Z 2021-11-18T22:01:05.345Z,1637272865.345 [Default:CheckIn:Read_GPS] Stopped 2021-11-18T22:01:05.345Z,1637272865.345 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-11-18T22:01:06.776Z,1637272866.776 [DAT](INFO): #Outgoing data=1 2021-11-18T22:01:06.776Z,1637272866.776 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-11-18T22:01:06.899Z,1637272866.899 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-11-18T22:01:07.238Z,1637272867.238 [DAT](INFO): DAT read: UART Wakeup 2021-11-18T22:01:07.239Z,1637272867.239 [DAT](INFO): DAT read: CONNECT 01200 bits/sec 1 of 4, Rate 1/2 CC 2021-11-18T22:01:07.240Z,1637272867.240 [DAT](INFO): commRate: 1200 2021-11-18T22:01:10.217Z,1637272870.217 [DAT](INFO): DAT read: Forwarding Delay UpTx time:22:00:34.3319 2021-11-18T22:01:10.217Z,1637272870.217 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-11-18T22:01:20.390Z,1637272880.390 [DAT](FAULT): Ack receipt timeout failure. 2021-11-18T22:01:20.390Z,1637272880.390 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2021-11-18T22:01:20.472Z,1637272880.472 [DAT](INFO): Sent 39 bytes from file Logs/20211118T212911/Courier0010.lzma.parts 2021-11-18T22:01:20.472Z,1637272880.472 [DAT](INFO): Packets left to send: 0 2021-11-18T22:01:20.475Z,1637272880.475 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2021-11-18T22:01:21.385Z,1637272881.385 [DAT](INFO): #Outgoing data=1 2021-11-18T22:01:21.386Z,1637272881.386 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-11-18T22:01:21.483Z,1637272881.483 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-11-18T22:01:25.191Z,1637272885.191 [DAT](INFO): DAT read: Forwarding Delay UpTx time:22:00:49.0284 2021-11-18T22:01:25.191Z,1637272885.191 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-11-18T22:01:33.311Z,1637272893.311 [NAL9602](FAULT): GPS failed to acquire within timeout. 2021-11-18T22:01:33.311Z,1637272893.311 [NAL9602] Data Fault, FailCount= 3 2021-11-18T22:01:33.311Z,1637272893.311 [NAL9602](ERROR): Data Fault 2021-11-18T22:01:33.358Z,1637272893.358 [CBIT](ERROR): Data Fault in component: NAL9602 2021-11-18T22:01:33.718Z,1637272893.718 [NAL9602](INFO): Powering down 2021-11-18T22:01:34.550Z,1637272894.550 [CBIT](INFO): Clearing failed state for component NAL9602 2021-11-18T22:01:34.550Z,1637272894.550 [NAL9602] No Fault, FailCount= 3 2021-11-18T22:01:35.335Z,1637272895.335 [DAT](FAULT): Ack receipt timeout failure. 2021-11-18T22:01:35.335Z,1637272895.335 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2021-11-18T22:01:35.739Z,1637272895.739 [DAT](INFO): Sent 184 bytes from file Logs/20211118T212911/Courier9001.lzma.parts 2021-11-18T22:01:35.740Z,1637272895.740 [DAT](INFO): Packets left to send: 14 2021-11-18T22:01:35.812Z,1637272895.812 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2021-11-18T22:01:36.666Z,1637272896.666 [DAT](INFO): #Outgoing data=1 2021-11-18T22:01:36.666Z,1637272896.666 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-11-18T22:01:36.748Z,1637272896.748 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-11-18T22:01:40.340Z,1637272900.340 [DAT](INFO): DAT read: Forwarding Delay UpTx time:22:01:05.0322 2021-11-18T22:01:40.340Z,1637272900.340 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-11-18T22:01:50.440Z,1637272910.440 [DAT](FAULT): Ack receipt timeout failure. 2021-11-18T22:01:50.440Z,1637272910.440 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2021-11-18T22:01:50.843Z,1637272910.843 [DAT](INFO): Sent 184 bytes from file Logs/20211118T212911/Courier9001.lzma.parts 2021-11-18T22:01:50.843Z,1637272910.843 [DAT](INFO): Packets left to send: 13 2021-11-18T22:01:50.845Z,1637272910.845 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2021-11-18T22:01:51.757Z,1637272911.757 [DAT](INFO): #Outgoing data=1 2021-11-18T22:01:51.758Z,1637272911.758 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-11-18T22:01:51.844Z,1637272911.844 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-11-18T22:01:55.426Z,1637272915.426 [DAT](INFO): DAT read: Forwarding Delay UpTx time:22:01:20.1320 2021-11-18T22:01:55.426Z,1637272915.426 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-11-18T22:02:03.911Z,1637272923.911 [NAL9602](INFO): Powering up NAL9602 2021-11-18T22:02:05.525Z,1637272925.525 [DAT](FAULT): Ack receipt timeout failure. 2021-11-18T22:02:05.525Z,1637272925.525 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2021-11-18T22:02:05.932Z,1637272925.932 [DAT](INFO): Sent 184 bytes from file Logs/20211118T212911/Courier9001.lzma.parts 2021-11-18T22:02:05.932Z,1637272925.932 [DAT](INFO): Packets left to send: 12 2021-11-18T22:02:05.934Z,1637272925.934 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2021-11-18T22:02:06.863Z,1637272926.863 [DAT](INFO): #Outgoing data=1 2021-11-18T22:02:06.863Z,1637272926.863 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-11-18T22:02:06.956Z,1637272926.956 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-11-18T22:02:10.536Z,1637272930.536 [DAT](INFO): DAT read: Forwarding Delay UpTx time:22:01:35.2832 2021-11-18T22:02:10.536Z,1637272930.536 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-11-18T22:02:14.979Z,1637272934.979 [NAL9602](INFO): NAL9602 initialized 2021-11-18T22:02:20.554Z,1637272940.554 [DAT](FAULT): Ack receipt timeout failure. 2021-11-18T22:02:20.554Z,1637272940.554 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2021-11-18T22:02:20.963Z,1637272940.963 [DAT](INFO): Sent 184 bytes from file Logs/20211118T212911/Courier9001.lzma.parts 2021-11-18T22:02:20.963Z,1637272940.963 [DAT](INFO): Packets left to send: 11 2021-11-18T22:02:20.964Z,1637272940.964 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2021-11-18T22:02:21.871Z,1637272941.871 [DAT](INFO): #Outgoing data=1 2021-11-18T22:02:21.872Z,1637272941.872 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-11-18T22:02:21.958Z,1637272941.958 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-11-18T22:02:25.730Z,1637272945.730 [DAT](INFO): DAT read: Forwarding Delay UpTx time:22:01:50.2816 2021-11-18T22:02:25.730Z,1637272945.730 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-11-18T22:02:33.350Z,1637272953.350 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 11 2021-11-18T22:02:33.351Z,1637272953.351 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-11-18T22:02:33.378Z,1637272953.378 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-11-18T22:02:33.766Z,1637272953.766 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-11-18T22:02:33.766Z,1637272953.766 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 11 2021-11-18T22:02:35.953Z,1637272955.953 [DAT](FAULT): Ack receipt timeout failure. 2021-11-18T22:02:35.965Z,1637272955.965 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2021-11-18T22:02:36.355Z,1637272956.355 [DAT](INFO): Sent 184 bytes from file Logs/20211118T212911/Courier9001.lzma.parts 2021-11-18T22:02:36.355Z,1637272956.355 [DAT](INFO): Packets left to send: 10 2021-11-18T22:02:36.356Z,1637272956.356 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2021-11-18T22:02:37.280Z,1637272957.280 [DAT](INFO): #Outgoing data=1 2021-11-18T22:02:37.280Z,1637272957.280 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-11-18T22:02:37.366Z,1637272957.366 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-11-18T22:02:40.767Z,1637272960.767 [DAT](INFO): DAT read: Forwarding Delay UpTx time:22:02:05.6814 2021-11-18T22:02:40.767Z,1637272960.767 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-11-18T22:02:50.813Z,1637272970.813 [DAT](FAULT): Ack receipt timeout failure. 2021-11-18T22:02:50.813Z,1637272970.813 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2021-11-18T22:02:51.234Z,1637272971.234 [DAT](INFO): Sent 184 bytes from file Logs/20211118T212911/Courier9001.lzma.parts 2021-11-18T22:02:51.234Z,1637272971.234 [DAT](INFO): Packets left to send: 9 2021-11-18T22:02:51.236Z,1637272971.236 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2021-11-18T22:02:52.145Z,1637272972.145 [DAT](INFO): #Outgoing data=1 2021-11-18T22:02:52.146Z,1637272972.146 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-11-18T22:02:52.783Z,1637272972.783 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-11-18T22:02:56.230Z,1637272976.230 [DAT](INFO): DAT read: Forwarding Delay UpTx time:22:02:21.0812 2021-11-18T22:02:56.231Z,1637272976.231 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-11-18T22:03:06.382Z,1637272986.382 [DAT](FAULT): Ack receipt timeout failure. 2021-11-18T22:03:06.382Z,1637272986.382 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2021-11-18T22:03:06.790Z,1637272986.790 [DAT](INFO): Sent 184 bytes from file Logs/20211118T212911/Courier9001.lzma.parts 2021-11-18T22:03:06.790Z,1637272986.790 [DAT](INFO): Packets left to send: 8 2021-11-18T22:03:06.792Z,1637272986.792 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2021-11-18T22:03:07.723Z,1637272987.723 [DAT](INFO): #Outgoing data=1 2021-11-18T22:03:07.723Z,1637272987.723 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-11-18T22:03:07.813Z,1637272987.813 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-11-18T22:03:11.574Z,1637272991.574 [DAT](INFO): DAT read: Forwarding Delay UpTx time:22:02:36.1310 2021-11-18T22:03:11.575Z,1637272991.575 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-11-18T22:03:21.626Z,1637273001.626 [DAT](FAULT): Ack receipt timeout failure. 2021-11-18T22:03:21.626Z,1637273001.626 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2021-11-18T22:03:22.526Z,1637273002.526 [DAT](INFO): Sent 184 bytes from file Logs/20211118T212911/Courier9001.lzma.parts 2021-11-18T22:03:22.526Z,1637273002.526 [DAT](INFO): Packets left to send: 7 2021-11-18T22:03:22.528Z,1637273002.528 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2021-11-18T22:03:23.170Z,1637273003.170 [DAT](INFO): #Outgoing data=1 2021-11-18T22:03:23.171Z,1637273003.171 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-11-18T22:03:23.275Z,1637273003.275 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-11-18T22:03:26.959Z,1637273006.959 [DAT](INFO): DAT read: Forwarding Delay UpTx time:22:02:51.5808 2021-11-18T22:03:26.959Z,1637273006.959 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-11-18T22:03:37.042Z,1637273017.042 [DAT](FAULT): Ack receipt timeout failure. 2021-11-18T22:03:37.042Z,1637273017.042 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2021-11-18T22:03:37.438Z,1637273017.438 [DAT](INFO): Sent 184 bytes from file Logs/20211118T212911/Courier9001.lzma.parts 2021-11-18T22:03:37.438Z,1637273017.438 [DAT](INFO): Packets left to send: 6 2021-11-18T22:03:37.440Z,1637273017.440 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2021-11-18T22:03:38.335Z,1637273018.335 [DAT](INFO): #Outgoing data=1 2021-11-18T22:03:38.335Z,1637273018.335 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-11-18T22:03:38.443Z,1637273018.443 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-11-18T22:03:42.167Z,1637273022.167 [DAT](INFO): DAT read: Forwarding Delay UpTx time:22:03:06.7306 2021-11-18T22:03:42.167Z,1637273022.167 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-11-18T22:03:52.690Z,1637273032.690 [DAT](FAULT): Ack receipt timeout failure. 2021-11-18T22:03:52.690Z,1637273032.690 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2021-11-18T22:03:52.776Z,1637273032.776 [DAT](INFO): Sent 184 bytes from file Logs/20211118T212911/Courier9001.lzma.parts 2021-11-18T22:03:52.777Z,1637273032.777 [DAT](INFO): Packets left to send: 5 2021-11-18T22:03:52.779Z,1637273032.779 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2021-11-18T22:03:53.676Z,1637273033.676 [DAT](INFO): #Outgoing data=1 2021-11-18T22:03:53.677Z,1637273033.677 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-11-18T22:03:53.787Z,1637273033.787 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-11-18T22:03:57.487Z,1637273037.487 [DAT](INFO): DAT read: Forwarding Delay UpTx time:22:03:22.0804 2021-11-18T22:03:57.487Z,1637273037.487 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-11-18T22:04:07.533Z,1637273047.533 [DAT](FAULT): Ack receipt timeout failure. 2021-11-18T22:04:07.533Z,1637273047.533 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2021-11-18T22:04:07.959Z,1637273047.959 [DAT](INFO): Sent 184 bytes from file Logs/20211118T212911/Courier9001.lzma.parts 2021-11-18T22:04:07.959Z,1637273047.959 [DAT](INFO): Packets left to send: 4 2021-11-18T22:04:07.960Z,1637273047.960 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2021-11-18T22:04:08.848Z,1637273048.848 [DAT](INFO): #Outgoing data=1 2021-11-18T22:04:08.848Z,1637273048.848 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-11-18T22:04:08.947Z,1637273048.947 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-11-18T22:04:12.298Z,1637273052.298 [DAT](INFO): DAT read: Forwarding Delay UpTx time:22:03:37.2302 2021-11-18T22:04:12.299Z,1637273052.299 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-11-18T22:04:22.478Z,1637273062.478 [DAT](FAULT): Ack receipt timeout failure. 2021-11-18T22:04:22.479Z,1637273062.479 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2021-11-18T22:04:22.864Z,1637273062.864 [DAT](INFO): Sent 184 bytes from file Logs/20211118T212911/Courier9001.lzma.parts 2021-11-18T22:04:22.864Z,1637273062.864 [DAT](INFO): Packets left to send: 3 2021-11-18T22:04:22.866Z,1637273062.866 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2021-11-18T22:04:23.789Z,1637273063.789 [DAT](INFO): #Outgoing data=1 2021-11-18T22:04:23.789Z,1637273063.789 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-11-18T22:04:23.886Z,1637273063.886 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-11-18T22:04:27.641Z,1637273067.641 [DAT](INFO): DAT read: Forwarding Delay UpTx time:22:03:52.1799 2021-11-18T22:04:27.642Z,1637273067.642 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-11-18T22:04:37.862Z,1637273077.862 [DAT](FAULT): Ack receipt timeout failure. 2021-11-18T22:04:37.862Z,1637273077.862 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2021-11-18T22:04:38.266Z,1637273078.266 [DAT](INFO): Sent 184 bytes from file Logs/20211118T212911/Courier9001.lzma.parts 2021-11-18T22:04:38.266Z,1637273078.266 [DAT](INFO): Packets left to send: 2 2021-11-18T22:04:38.268Z,1637273078.268 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2021-11-18T22:04:39.176Z,1637273079.176 [DAT](INFO): #Outgoing data=1 2021-11-18T22:04:39.177Z,1637273079.177 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-11-18T22:04:39.260Z,1637273079.260 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-11-18T22:04:43.018Z,1637273083.018 [DAT](INFO): DAT read: Forwarding Delay UpTx time:22:04:07.5797 2021-11-18T22:04:43.019Z,1637273083.019 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-11-18T22:04:53.534Z,1637273093.534 [DAT](FAULT): Ack receipt timeout failure. 2021-11-18T22:04:53.534Z,1637273093.534 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2021-11-18T22:04:53.620Z,1637273093.620 [DAT](INFO): Sent 184 bytes from file Logs/20211118T212911/Courier9001.lzma.parts 2021-11-18T22:04:53.620Z,1637273093.620 [DAT](INFO): Packets left to send: 1 2021-11-18T22:04:53.630Z,1637273093.630 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2021-11-18T22:04:54.509Z,1637273094.509 [DAT](INFO): #Outgoing data=1 2021-11-18T22:04:54.509Z,1637273094.509 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-11-18T22:04:54.613Z,1637273094.613 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-11-18T22:04:57.939Z,1637273097.939 [DAT](INFO): DAT read: Forwarding Delay UpTx time:22:04:22.7295 2021-11-18T22:04:57.939Z,1637273097.939 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-11-18T22:05:08.049Z,1637273108.049 [DAT](FAULT): Ack receipt timeout failure. 2021-11-18T22:05:08.049Z,1637273108.049 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2021-11-18T22:05:08.436Z,1637273108.436 [DAT](INFO): Sent 7 bytes from file Logs/20211118T212911/Courier9001.lzma.parts 2021-11-18T22:05:08.436Z,1637273108.436 [DAT](INFO): Packets left to send: 0 2021-11-18T22:05:08.438Z,1637273108.438 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2021-11-18T22:05:09.369Z,1637273109.369 [Default:CheckIn:Read_Iridium] Stopped 2021-11-18T22:05:09.369Z,1637273109.369 [Default:CheckIn:C.Wait] Running Loop=1 2021-11-18T22:05:09.369Z,1637273109.369 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-11-18T22:05:34.318Z,1637273134.318 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 12 2021-11-18T22:05:34.318Z,1637273134.318 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-11-18T22:05:34.329Z,1637273134.329 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-11-18T22:05:34.736Z,1637273134.736 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-11-18T22:05:34.736Z,1637273134.736 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 12 2021-11-18T22:07:57.727Z,1637273277.727 [DAT](INFO): DAT read: Lowpower 2021-11-18T22:07:57.727Z,1637273277.727 [DAT](INFO): unknown deviceResponse_: Lowpower 2021-11-18T22:08:35.291Z,1637273315.291 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 13 2021-11-18T22:08:35.291Z,1637273315.291 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-11-18T22:08:35.302Z,1637273315.302 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-11-18T22:08:35.729Z,1637273315.729 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-11-18T22:08:35.729Z,1637273315.729 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 13 2021-11-18T22:10:09.819Z,1637273409.819 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-11-18T22:10:09.820Z,1637273409.820 [Default:CheckIn:C.Wait] Stopped 2021-11-18T22:10:09.820Z,1637273409.820 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-11-18T22:10:09.820Z,1637273409.820 [Default:CheckIn:D] Running Loop=1 2021-11-18T22:10:10.222Z,1637273410.222 [Default:CheckIn:D] Stopped 2021-11-18T22:10:10.222Z,1637273410.222 [Default:CheckIn:E] Running Loop=1 2021-11-18T22:10:10.648Z,1637273410.648 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 36.451038 min 2021-11-18T22:10:10.648Z,1637273410.648 [Default:CheckIn:E] Stopped 2021-11-18T22:10:10.648Z,1637273410.648 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-11-18T22:10:10.648Z,1637273410.648 [Default:CheckIn] Stopped 2021-11-18T22:10:10.648Z,1637273410.648 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-11-18T22:10:10.648Z,1637273410.648 [Default:CheckIn](INFO): Running loop #4 2021-11-18T22:10:10.649Z,1637273410.649 [Default:CheckIn] Running Loop=4 2021-11-18T22:10:10.649Z,1637273410.649 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-11-18T22:10:10.650Z,1637273410.650 [Default:CheckIn:Read_GPS] Running Loop=1 2021-11-18T22:11:36.297Z,1637273496.297 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 14 2021-11-18T22:11:36.297Z,1637273496.297 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-11-18T22:11:36.308Z,1637273496.308 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-11-18T22:11:36.709Z,1637273496.709 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-11-18T22:11:36.709Z,1637273496.709 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 14 2021-11-18T22:12:16.675Z,1637273536.675 [NAL9602](FAULT): GPS failed to acquire within timeout. 2021-11-18T22:12:16.675Z,1637273536.675 [NAL9602] Data Fault, FailCount= 4 2021-11-18T22:12:16.675Z,1637273536.675 [NAL9602](ERROR): Data Fault 2021-11-18T22:12:16.698Z,1637273536.698 [CBIT](ERROR): Data Fault in component: NAL9602 2021-11-18T22:12:17.070Z,1637273537.070 [NAL9602](INFO): Powering down 2021-11-18T22:12:17.906Z,1637273537.906 [CBIT](INFO): Clearing failed state for component NAL9602 2021-11-18T22:12:17.906Z,1637273537.906 [NAL9602] No Fault, FailCount= 4 2021-11-18T22:12:47.375Z,1637273567.375 [NAL9602](INFO): Powering up NAL9602 2021-11-18T22:12:58.283Z,1637273578.283 [NAL9602](INFO): NAL9602 initialized 2021-11-18T22:14:25.957Z,1637273665.957 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2021-11-18T22:14:25.957Z,1637273665.957 [DropWeight] Hardware Fault, FailCount= 1 2021-11-18T22:14:25.957Z,1637273665.957 [DropWeight](ERROR): Hardware Fault 2021-11-18T22:14:25.975Z,1637273665.975 [CBIT](INFO): Critical error at 20211118T221425 2021-11-18T22:14:25.978Z,1637273665.978 [CBIT](ERROR): Hardware Fault in component: DropWeight 2021-11-18T22:14:25.978Z,1637273665.978 [CBIT](CRITICAL): Hardware Fault in component: DropWeight 2021-11-18T22:14:26.390Z,1637273666.390 [CBIT](INFO): Critical error at 20211118T221425 2021-11-18T22:14:37.275Z,1637273677.275 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 15 2021-11-18T22:14:37.275Z,1637273677.275 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-11-18T22:14:37.286Z,1637273677.286 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-11-18T22:14:37.698Z,1637273677.698 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-11-18T22:14:37.698Z,1637273677.698 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 15 2021-11-18T22:15:10.804Z,1637273710.804 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-11-18T22:10:10.6Z 2021-11-18T22:15:10.804Z,1637273710.804 [Default:CheckIn:Read_GPS] Stopped 2021-11-18T22:15:10.804Z,1637273710.804 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-11-18T22:15:12.102Z,1637273712.102 [DAT](INFO): #Outgoing data=1 2021-11-18T22:15:12.102Z,1637273712.102 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-11-18T22:15:12.207Z,1637273712.207 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-11-18T22:15:12.562Z,1637273712.562 [DAT](INFO): DAT read: UART Wakeup 2021-11-18T22:15:12.563Z,1637273712.563 [DAT](INFO): DAT read: CONNECT 01200 bits/sec 1 of 4, Rate 1/2 CC 2021-11-18T22:15:12.563Z,1637273712.563 [DAT](INFO): commRate: 1200 2021-11-18T22:15:15.891Z,1637273715.891 [DAT](INFO): DAT read: Forwarding Delay UpTx time:22:14:40.3810 2021-11-18T22:15:15.891Z,1637273715.891 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-11-18T22:15:25.915Z,1637273725.915 [DAT](FAULT): Ack receipt timeout failure. 2021-11-18T22:15:25.915Z,1637273725.915 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2021-11-18T22:15:26.315Z,1637273726.315 [DAT](INFO): Sent 114 bytes from file Logs/20211118T212911/Courier0013.lzma.parts 2021-11-18T22:15:26.315Z,1637273726.315 [DAT](INFO): Packets left to send: 0 2021-11-18T22:15:26.318Z,1637273726.318 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2021-11-18T22:15:27.254Z,1637273727.254 [Default:CheckIn:Read_Iridium] Stopped 2021-11-18T22:15:27.254Z,1637273727.254 [Default:CheckIn:C.Wait] Running Loop=1 2021-11-18T22:15:27.254Z,1637273727.254 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-11-18T22:17:38.452Z,1637273858.452 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 16 2021-11-18T22:17:38.452Z,1637273858.452 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-11-18T22:17:38.464Z,1637273858.464 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-11-18T22:17:38.873Z,1637273858.873 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-11-18T22:17:38.873Z,1637273858.873 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 16 2021-11-18T22:18:15.619Z,1637273895.619 [DAT](INFO): DAT read: Lowpower 2021-11-18T22:18:15.620Z,1637273895.620 [DAT](INFO): unknown deviceResponse_: Lowpower 2021-11-18T22:20:27.742Z,1637274027.742 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-11-18T22:20:27.742Z,1637274027.742 [Default:CheckIn:C.Wait] Stopped 2021-11-18T22:20:27.742Z,1637274027.742 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-11-18T22:20:27.742Z,1637274027.742 [Default:CheckIn:D] Running Loop=1 2021-11-18T22:20:28.167Z,1637274028.167 [Default:CheckIn:D] Stopped 2021-11-18T22:20:28.167Z,1637274028.167 [Default:CheckIn:E] Running Loop=1 2021-11-18T22:20:28.576Z,1637274028.576 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 46.750118 min 2021-11-18T22:20:28.576Z,1637274028.576 [Default:CheckIn:E] Stopped 2021-11-18T22:20:28.576Z,1637274028.576 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-11-18T22:20:28.576Z,1637274028.576 [Default:CheckIn] Stopped 2021-11-18T22:20:28.576Z,1637274028.576 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-11-18T22:20:28.576Z,1637274028.576 [Default:CheckIn](INFO): Running loop #5 2021-11-18T22:20:28.576Z,1637274028.576 [Default:CheckIn] Running Loop=5 2021-11-18T22:20:28.576Z,1637274028.576 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-11-18T22:20:28.577Z,1637274028.577 [Default:CheckIn:Read_GPS] Running Loop=1 2021-11-18T22:20:39.460Z,1637274039.460 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 17 2021-11-18T22:20:39.460Z,1637274039.460 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-11-18T22:20:39.472Z,1637274039.472 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-11-18T22:20:39.890Z,1637274039.890 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-11-18T22:20:39.890Z,1637274039.890 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 17 2021-11-18T22:23:00.038Z,1637274180.038 [NAL9602](FAULT): GPS failed to acquire within timeout. 2021-11-18T22:23:00.038Z,1637274180.038 [NAL9602] Data Fault, FailCount= 5 2021-11-18T22:23:00.038Z,1637274180.038 [NAL9602](ERROR): Data Fault 2021-11-18T22:23:00.076Z,1637274180.076 [CBIT](ERROR): Data Fault in component: NAL9602 2021-11-18T22:23:00.077Z,1637274180.077 [CBIT](CRITICAL): Data Fault in component: NAL9602 2021-11-18T22:23:00.438Z,1637274180.438 [NAL9602](INFO): Powering down 2021-11-18T22:23:00.487Z,1637274180.487 [CBIT](INFO): Critical error at 20211118T222300 2021-11-18T22:23:40.454Z,1637274220.454 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 18 2021-11-18T22:23:40.454Z,1637274220.454 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-11-18T22:23:40.466Z,1637274220.466 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-11-18T22:23:40.862Z,1637274220.862 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-11-18T22:23:40.862Z,1637274220.862 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 18 2021-11-18T22:25:00.053Z,1637274300.053 [CBIT](INFO): Clearing failed state for component NAL9602 2021-11-18T22:25:00.054Z,1637274300.054 [NAL9602] No Fault, FailCount= 5 2021-11-18T22:25:00.426Z,1637274300.426 [NAL9602](INFO): Powering up NAL9602 2021-11-18T22:25:11.338Z,1637274311.338 [NAL9602](INFO): NAL9602 initialized 2021-11-18T22:25:28.723Z,1637274328.723 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-11-18T22:20:28.6Z 2021-11-18T22:25:28.724Z,1637274328.724 [Default:CheckIn:Read_GPS] Stopped 2021-11-18T22:25:28.724Z,1637274328.724 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-11-18T22:25:30.038Z,1637274330.038 [DAT](INFO): #Outgoing data=1 2021-11-18T22:25:30.038Z,1637274330.038 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-11-18T22:25:30.135Z,1637274330.135 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-11-18T22:25:30.480Z,1637274330.480 [DAT](INFO): DAT read: UART Wakeup 2021-11-18T22:25:30.481Z,1637274330.481 [DAT](INFO): DAT read: CONNECT 01200 bits/sec 1 of 4, Rate 1/2 CC 2021-11-18T22:25:30.481Z,1637274330.481 [DAT](INFO): commRate: 1200 2021-11-18T22:25:33.466Z,1637274333.466 [DAT](INFO): DAT read: Forwarding Delay UpTx time:22:24:57.3336 2021-11-18T22:25:33.466Z,1637274333.466 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-11-18T22:25:43.563Z,1637274343.563 [DAT](FAULT): Ack receipt timeout failure. 2021-11-18T22:25:43.563Z,1637274343.563 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2021-11-18T22:25:43.944Z,1637274343.944 [DAT](INFO): Sent 81 bytes from file Logs/20211118T212911/Courier0016.lzma.parts 2021-11-18T22:25:43.944Z,1637274343.944 [DAT](INFO): Packets left to send: 0 2021-11-18T22:25:43.947Z,1637274343.947 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2021-11-18T22:25:44.868Z,1637274344.868 [Default:CheckIn:Read_Iridium] Stopped 2021-11-18T22:25:44.868Z,1637274344.868 [Default:CheckIn:C.Wait] Running Loop=1 2021-11-18T22:25:44.869Z,1637274344.869 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-11-18T22:26:41.336Z,1637274401.336 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 19 2021-11-18T22:26:41.336Z,1637274401.336 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-11-18T22:26:41.347Z,1637274401.347 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-11-18T22:26:41.746Z,1637274401.746 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-11-18T22:26:41.746Z,1637274401.746 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 19 2021-11-18T22:28:33.640Z,1637274513.640 [DAT](INFO): DAT read: Lowpower 2021-11-18T22:28:33.640Z,1637274513.640 [DAT](INFO): unknown deviceResponse_: Lowpower 2021-11-18T22:29:26.196Z,1637274566.196 [CBIT](INFO): Clearing failed state for component DropWeight 2021-11-18T22:29:26.197Z,1637274566.197 [DropWeight] No Fault, FailCount= 1 2021-11-18T22:29:42.334Z,1637274582.334 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 20 2021-11-18T22:29:42.334Z,1637274582.334 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-11-18T22:29:42.357Z,1637274582.357 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-11-18T22:29:42.358Z,1637274582.358 [CBIT](FAULT): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-11-18T22:30:46.154Z,1637274646.154 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-11-18T22:30:46.155Z,1637274646.155 [Default:CheckIn:C.Wait] Stopped 2021-11-18T22:30:46.155Z,1637274646.155 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-11-18T22:30:46.155Z,1637274646.155 [Default:CheckIn:D] Running Loop=1 2021-11-18T22:30:46.567Z,1637274646.567 [Default:CheckIn:D] Stopped 2021-11-18T22:30:46.567Z,1637274646.567 [Default:CheckIn:E] Running Loop=1 2021-11-18T22:30:46.981Z,1637274646.981 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 57.056787 min 2021-11-18T22:30:46.981Z,1637274646.981 [Default:CheckIn:E] Stopped 2021-11-18T22:30:46.981Z,1637274646.981 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-11-18T22:30:46.981Z,1637274646.981 [Default:CheckIn] Stopped 2021-11-18T22:30:46.981Z,1637274646.981 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-11-18T22:30:46.981Z,1637274646.981 [Default:CheckIn](INFO): Running loop #6 2021-11-18T22:30:46.982Z,1637274646.982 [Default:CheckIn] Running Loop=6 2021-11-18T22:30:46.982Z,1637274646.982 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-11-18T22:30:46.982Z,1637274646.982 [Default:CheckIn:Read_GPS] Running Loop=1 2021-11-18T22:35:14.002Z,1637274914.002 [NAL9602](FAULT): GPS failed to acquire within timeout. 2021-11-18T22:35:14.003Z,1637274914.003 [NAL9602] Data Fault, FailCount= 1 2021-11-18T22:35:14.003Z,1637274914.003 [NAL9602](ERROR): Data Fault 2021-11-18T22:35:14.020Z,1637274914.020 [CBIT](ERROR): Data Fault in component: NAL9602 2021-11-18T22:35:14.408Z,1637274914.408 [NAL9602](INFO): Powering down 2021-11-18T22:35:15.231Z,1637274915.231 [CBIT](INFO): Clearing failed state for component NAL9602 2021-11-18T22:35:15.232Z,1637274915.232 [NAL9602] No Fault, FailCount= 1 2021-11-18T22:35:44.700Z,1637274944.700 [NAL9602](INFO): Powering up NAL9602 2021-11-18T22:35:47.138Z,1637274947.138 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-11-18T22:30:46.0Z 2021-11-18T22:35:47.138Z,1637274947.138 [Default:CheckIn:Read_GPS] Stopped 2021-11-18T22:35:47.139Z,1637274947.139 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-11-18T22:35:48.422Z,1637274948.422 [DAT](INFO): #Outgoing data=1 2021-11-18T22:35:48.422Z,1637274948.422 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-11-18T22:35:48.508Z,1637274948.508 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-11-18T22:35:48.864Z,1637274948.864 [DAT](INFO): DAT read: UART Wakeup 2021-11-18T22:35:48.865Z,1637274948.865 [DAT](INFO): DAT read: CONNECT 01200 bits/sec 1 of 4, Rate 1/2 CC 2021-11-18T22:35:48.866Z,1637274948.866 [DAT](INFO): commRate: 1200 2021-11-18T22:35:52.086Z,1637274952.086 [DAT](INFO): DAT read: Forwarding Delay UpTx time:22:35:16.2858 2021-11-18T22:35:52.086Z,1637274952.086 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-11-18T22:35:55.727Z,1637274955.727 [NAL9602](INFO): NAL9602 initialized 2021-11-18T22:36:02.340Z,1637274962.340 [DAT](FAULT): Ack receipt timeout failure. 2021-11-18T22:36:02.340Z,1637274962.340 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2021-11-18T22:36:02.766Z,1637274962.766 [DAT](INFO): Sent 39 bytes from file Logs/20211118T212911/Courier0019.lzma.parts 2021-11-18T22:36:02.766Z,1637274962.766 [DAT](INFO): Packets left to send: 0 2021-11-18T22:36:02.806Z,1637274962.806 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2021-11-18T22:36:03.648Z,1637274963.648 [Default:CheckIn:Read_Iridium] Stopped 2021-11-18T22:36:03.648Z,1637274963.648 [Default:CheckIn:C.Wait] Running Loop=1 2021-11-18T22:36:03.649Z,1637274963.649 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-11-18T22:38:52.044Z,1637275132.044 [DAT](INFO): DAT read: Lowpower 2021-11-18T22:38:52.044Z,1637275132.044 [DAT](INFO): unknown deviceResponse_: Lowpower 2021-11-18T22:41:04.117Z,1637275264.117 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-11-18T22:41:04.117Z,1637275264.117 [Default:CheckIn:C.Wait] Stopped 2021-11-18T22:41:04.117Z,1637275264.117 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-11-18T22:41:04.117Z,1637275264.117 [Default:CheckIn:D] Running Loop=1 2021-11-18T22:41:04.522Z,1637275264.522 [Default:CheckIn:D] Stopped 2021-11-18T22:41:04.523Z,1637275264.523 [Default:CheckIn:E] Running Loop=1 2021-11-18T22:41:04.975Z,1637275264.975 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 67.356042 min 2021-11-18T22:41:04.976Z,1637275264.976 [Default:CheckIn:E] Stopped 2021-11-18T22:41:04.976Z,1637275264.976 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-11-18T22:41:04.976Z,1637275264.976 [Default:CheckIn] Stopped 2021-11-18T22:41:04.976Z,1637275264.976 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-11-18T22:41:04.976Z,1637275264.976 [Default:CheckIn](INFO): Running loop #7 2021-11-18T22:41:04.976Z,1637275264.976 [Default:CheckIn] Running Loop=7 2021-11-18T22:41:04.976Z,1637275264.976 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-11-18T22:41:04.976Z,1637275264.976 [Default:CheckIn:Read_GPS] Running Loop=1 2021-11-18T22:42:57.623Z,1637275377.623 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2021-11-18T22:42:57.626Z,1637275377.626 [BPC1](INFO): Received data from all battery sticks. 2021-11-18T22:44:42.712Z,1637275482.712 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-11-18T22:44:42.712Z,1637275482.712 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 20 2021-11-18T22:45:57.405Z,1637275557.405 [NAL9602](FAULT): GPS failed to acquire within timeout. 2021-11-18T22:45:57.405Z,1637275557.405 [NAL9602] Data Fault, FailCount= 2 2021-11-18T22:45:57.405Z,1637275557.405 [NAL9602](ERROR): Data Fault 2021-11-18T22:45:57.424Z,1637275557.424 [CBIT](ERROR): Data Fault in component: NAL9602 2021-11-18T22:45:57.798Z,1637275557.798 [NAL9602](INFO): Powering down 2021-11-18T22:45:58.628Z,1637275558.628 [CBIT](INFO): Clearing failed state for component NAL9602 2021-11-18T22:45:58.628Z,1637275558.628 [NAL9602] No Fault, FailCount= 2 2021-11-18T22:46:05.078Z,1637275565.078 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-11-18T22:41:04.0Z 2021-11-18T22:46:05.078Z,1637275565.078 [Default:CheckIn:Read_GPS] Stopped 2021-11-18T22:46:05.078Z,1637275565.078 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-11-18T22:46:06.379Z,1637275566.379 [DAT](INFO): #Outgoing data=1 2021-11-18T22:46:06.380Z,1637275566.380 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-11-18T22:46:06.468Z,1637275566.468 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-11-18T22:46:06.820Z,1637275566.820 [DAT](INFO): DAT read: UART Wakeup 2021-11-18T22:46:06.821Z,1637275566.821 [DAT](INFO): DAT read: CONNECT 01200 bits/sec 1 of 4, Rate 1/2 CC 2021-11-18T22:46:06.821Z,1637275566.821 [DAT](INFO): commRate: 1200 2021-11-18T22:46:10.057Z,1637275570.057 [DAT](INFO): DAT read: Forwarding Delay UpTx time:22:45:34.3290 2021-11-18T22:46:10.057Z,1637275570.057 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-11-18T22:46:20.161Z,1637275580.161 [DAT](FAULT): Ack receipt timeout failure. 2021-11-18T22:46:20.161Z,1637275580.161 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2021-11-18T22:46:20.556Z,1637275580.556 [DAT](INFO): Sent 50 bytes from file Logs/20211118T212911/Courier0022.lzma.parts 2021-11-18T22:46:20.556Z,1637275580.556 [DAT](INFO): Packets left to send: 0 2021-11-18T22:46:20.558Z,1637275580.558 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2021-11-18T22:46:21.467Z,1637275581.467 [Default:CheckIn:Read_Iridium] Stopped 2021-11-18T22:46:21.467Z,1637275581.467 [Default:CheckIn:C.Wait] Running Loop=1 2021-11-18T22:46:21.467Z,1637275581.467 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-11-18T22:46:27.955Z,1637275587.955 [NAL9602](INFO): Powering up NAL9602 2021-11-18T22:46:38.867Z,1637275598.867 [NAL9602](INFO): NAL9602 initialized 2021-11-18T22:47:43.111Z,1637275663.111 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2021-11-18T22:47:43.111Z,1637275663.111 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-11-18T22:47:43.122Z,1637275663.122 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-11-18T22:47:43.539Z,1637275663.539 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-11-18T22:47:43.539Z,1637275663.539 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2021-11-18T22:49:09.978Z,1637275749.978 [DAT](INFO): DAT read: Lowpower 2021-11-18T22:49:09.978Z,1637275749.978 [DAT](INFO): unknown deviceResponse_: Lowpower 2021-11-18T22:50:44.116Z,1637275844.116 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2 2021-11-18T22:50:44.116Z,1637275844.116 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-11-18T22:50:44.137Z,1637275844.137 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-11-18T22:50:44.542Z,1637275844.542 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-11-18T22:50:44.542Z,1637275844.542 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2 2021-11-18T22:51:21.680Z,1637275881.680 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-11-18T22:51:21.680Z,1637275881.681 [Default:CheckIn:C.Wait] Stopped 2021-11-18T22:51:21.681Z,1637275881.681 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-11-18T22:51:21.681Z,1637275881.681 [Default:CheckIn:D] Running Loop=1 2021-11-18T22:51:22.084Z,1637275882.084 [Default:CheckIn:D] Stopped 2021-11-18T22:51:22.084Z,1637275882.084 [Default:CheckIn:E] Running Loop=1 2021-11-18T22:51:22.504Z,1637275882.504 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 77.648739 min 2021-11-18T22:51:22.504Z,1637275882.504 [Default:CheckIn:E] Stopped 2021-11-18T22:51:22.504Z,1637275882.504 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-11-18T22:51:22.504Z,1637275882.504 [Default:CheckIn] Stopped 2021-11-18T22:51:22.505Z,1637275882.505 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-11-18T22:51:22.505Z,1637275882.505 [Default:CheckIn](INFO): Running loop #8 2021-11-18T22:51:22.505Z,1637275882.505 [Default:CheckIn] Running Loop=8 2021-11-18T22:51:22.505Z,1637275882.505 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-11-18T22:51:22.505Z,1637275882.505 [Default:CheckIn:Read_GPS] Running Loop=1 2021-11-18T22:53:45.110Z,1637276025.110 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3 2021-11-18T22:53:45.110Z,1637276025.110 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-11-18T22:53:45.122Z,1637276025.122 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-11-18T22:53:45.525Z,1637276025.525 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-11-18T22:53:45.525Z,1637276025.525 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3 2021-11-18T22:56:22.689Z,1637276182.689 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-11-18T22:51:22.5Z 2021-11-18T22:56:22.689Z,1637276182.689 [Default:CheckIn:Read_GPS] Stopped 2021-11-18T22:56:22.689Z,1637276182.689 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-11-18T22:56:23.973Z,1637276183.973 [DAT](INFO): #Outgoing data=1 2021-11-18T22:56:23.973Z,1637276183.973 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-11-18T22:56:24.060Z,1637276184.060 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-11-18T22:56:24.412Z,1637276184.412 [DAT](INFO): DAT read: UART Wakeup 2021-11-18T22:56:24.413Z,1637276184.413 [DAT](INFO): DAT read: CONNECT 01200 bits/sec 1 of 4, Rate 1/2 CC 2021-11-18T22:56:24.413Z,1637276184.413 [DAT](INFO): commRate: 1200 2021-11-18T22:56:27.394Z,1637276187.394 [DAT](INFO): DAT read: Forwarding Delay UpTx time:22:55:51.3291 2021-11-18T22:56:27.395Z,1637276187.395 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-11-18T22:56:37.402Z,1637276197.402 [DAT](FAULT): Ack receipt timeout failure. 2021-11-18T22:56:37.402Z,1637276197.402 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2021-11-18T22:56:37.814Z,1637276197.814 [DAT](INFO): Sent 39 bytes from file Logs/20211118T212911/Courier0025.lzma.parts 2021-11-18T22:56:37.814Z,1637276197.814 [DAT](INFO): Packets left to send: 0 2021-11-18T22:56:37.817Z,1637276197.817 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2021-11-18T22:56:39.684Z,1637276199.684 [Default:CheckIn:Read_Iridium] Stopped 2021-11-18T22:56:39.684Z,1637276199.684 [Default:CheckIn:C.Wait] Running Loop=1 2021-11-18T22:56:39.684Z,1637276199.684 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-11-18T22:56:40.115Z,1637276200.115 [NAL9602](FAULT): GPS failed to acquire within timeout. 2021-11-18T22:56:40.115Z,1637276200.115 [NAL9602] Data Fault, FailCount= 3 2021-11-18T22:56:40.115Z,1637276200.115 [NAL9602](ERROR): Data Fault 2021-11-18T22:56:40.135Z,1637276200.135 [CBIT](ERROR): Data Fault in component: NAL9602 2021-11-18T22:56:40.521Z,1637276200.521 [NAL9602](INFO): Powering down 2021-11-18T22:56:41.368Z,1637276201.368 [CBIT](INFO): Clearing failed state for component NAL9602 2021-11-18T22:56:41.368Z,1637276201.368 [NAL9602] No Fault, FailCount= 3 2021-11-18T22:56:46.182Z,1637276206.182 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4 2021-11-18T22:56:46.182Z,1637276206.182 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-11-18T22:56:46.225Z,1637276206.225 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-11-18T22:56:46.595Z,1637276206.595 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-11-18T22:56:46.596Z,1637276206.596 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4 2021-11-18T22:57:10.818Z,1637276230.818 [NAL9602](INFO): Powering up NAL9602 2021-11-18T22:57:21.727Z,1637276241.727 [NAL9602](INFO): NAL9602 initialized 2021-11-18T22:59:27.371Z,1637276367.371 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2021-11-18T22:59:27.371Z,1637276367.371 [DropWeight] Hardware Fault, FailCount= 1 2021-11-18T22:59:27.371Z,1637276367.371 [DropWeight](ERROR): Hardware Fault 2021-11-18T22:59:27.386Z,1637276367.386 [DAT](INFO): DAT read: Lowpower 2021-11-18T22:59:27.387Z,1637276367.387 [DAT](INFO): unknown deviceResponse_: Lowpower 2021-11-18T22:59:27.450Z,1637276367.450 [CBIT](INFO): Critical error at 20211118T225927 2021-11-18T22:59:27.453Z,1637276367.453 [CBIT](ERROR): Hardware Fault in component: DropWeight 2021-11-18T22:59:27.461Z,1637276367.461 [CBIT](CRITICAL): Hardware Fault in component: DropWeight 2021-11-18T22:59:27.815Z,1637276367.815 [CBIT](INFO): Critical error at 20211118T225927 2021-11-18T22:59:47.172Z,1637276387.172 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5 2021-11-18T22:59:47.172Z,1637276387.172 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-11-18T22:59:47.184Z,1637276387.184 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-11-18T22:59:47.601Z,1637276387.601 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-11-18T22:59:47.601Z,1637276387.601 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5 2021-11-18T23:01:39.896Z,1637276499.896 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-11-18T23:01:39.896Z,1637276499.896 [Default:CheckIn:C.Wait] Stopped 2021-11-18T23:01:39.896Z,1637276499.896 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-11-18T23:01:39.896Z,1637276499.896 [Default:CheckIn:D] Running Loop=1 2021-11-18T23:01:40.320Z,1637276500.320 [Default:CheckIn:D] Stopped 2021-11-18T23:01:40.320Z,1637276500.320 [Default:CheckIn:E] Running Loop=1 2021-11-18T23:01:40.721Z,1637276500.721 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 87.952669 min 2021-11-18T23:01:40.721Z,1637276500.721 [Default:CheckIn:E] Stopped 2021-11-18T23:01:40.721Z,1637276500.721 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-11-18T23:01:40.721Z,1637276500.721 [Default:CheckIn] Stopped 2021-11-18T23:01:40.721Z,1637276500.721 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-11-18T23:01:40.722Z,1637276500.722 [Default:CheckIn](INFO): Running loop #9 2021-11-18T23:01:40.722Z,1637276500.722 [Default:CheckIn] Running Loop=9 2021-11-18T23:01:40.722Z,1637276500.722 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-11-18T23:01:40.722Z,1637276500.722 [Default:CheckIn:Read_GPS] Running Loop=1 2021-11-18T23:02:48.194Z,1637276568.194 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6 2021-11-18T23:02:48.194Z,1637276568.194 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-11-18T23:02:48.205Z,1637276568.205 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-11-18T23:02:48.585Z,1637276568.585 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-11-18T23:02:48.585Z,1637276568.585 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6 2021-11-18T23:05:49.162Z,1637276749.162 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7 2021-11-18T23:05:49.162Z,1637276749.162 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-11-18T23:05:49.196Z,1637276749.196 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-11-18T23:05:49.608Z,1637276749.608 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-11-18T23:05:49.608Z,1637276749.608 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7 2021-11-18T23:06:40.897Z,1637276800.897 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-11-18T23:01:40.7Z 2021-11-18T23:06:40.897Z,1637276800.897 [Default:CheckIn:Read_GPS] Stopped 2021-11-18T23:06:40.897Z,1637276800.897 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-11-18T23:06:42.175Z,1637276802.175 [DAT](INFO): #Outgoing data=1 2021-11-18T23:06:42.176Z,1637276802.176 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-11-18T23:06:42.260Z,1637276802.260 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-11-18T23:06:42.629Z,1637276802.629 [DAT](INFO): DAT read: UART Wakeup 2021-11-18T23:06:42.630Z,1637276802.630 [DAT](INFO): DAT read: CONNECT 01200 bits/sec 1 of 4, Rate 1/2 CC 2021-11-18T23:06:42.631Z,1637276802.631 [DAT](INFO): commRate: 1200 2021-11-18T23:06:45.747Z,1637276805.747 [DAT](INFO): DAT read: Forwarding Delay UpTx time:23:06:10.3833 2021-11-18T23:06:45.747Z,1637276805.747 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-11-18T23:06:55.782Z,1637276815.782 [DAT](FAULT): Ack receipt timeout failure. 2021-11-18T23:06:55.782Z,1637276815.782 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2021-11-18T23:06:56.670Z,1637276816.670 [DAT](INFO): Sent 114 bytes from file Logs/20211118T212911/Courier0028.lzma.parts 2021-11-18T23:06:56.670Z,1637276816.670 [DAT](INFO): Packets left to send: 0 2021-11-18T23:06:56.673Z,1637276816.673 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2021-11-18T23:06:57.259Z,1637276817.259 [Default:CheckIn:Read_Iridium] Stopped 2021-11-18T23:06:57.259Z,1637276817.259 [Default:CheckIn:C.Wait] Running Loop=1 2021-11-18T23:06:57.259Z,1637276817.259 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-11-18T23:07:24.370Z,1637276844.370 [NAL9602](FAULT): GPS failed to acquire within timeout. 2021-11-18T23:07:24.370Z,1637276844.370 [NAL9602] Data Fault, FailCount= 4 2021-11-18T23:07:24.371Z,1637276844.371 [NAL9602](ERROR): Data Fault 2021-11-18T23:07:24.423Z,1637276844.423 [CBIT](ERROR): Data Fault in component: NAL9602 2021-11-18T23:07:24.774Z,1637276844.774 [NAL9602](INFO): Powering down 2021-11-18T23:07:25.172Z,1637276845.172 [NAL9602](FAULT): LCB fault: Software Overcurrent. 2021-11-18T23:07:25.172Z,1637276845.172 [NAL9602] Hardware Fault, FailCount= 4 2021-11-18T23:07:25.172Z,1637276845.172 [NAL9602](ERROR): Hardware Fault 2021-11-18T23:07:25.610Z,1637276845.610 [CBIT](INFO): Clearing failed state for component NAL9602 2021-11-18T23:07:25.610Z,1637276845.610 [NAL9602] No Fault, FailCount= 4 2021-11-18T23:07:55.075Z,1637276875.075 [NAL9602](INFO): Powering up NAL9602 2021-11-18T23:08:05.983Z,1637276885.983 [NAL9602](INFO): NAL9602 initialized 2021-11-18T23:08:50.040Z,1637276930.040 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8 2021-11-18T23:08:50.040Z,1637276930.040 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-11-18T23:08:50.051Z,1637276930.051 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-11-18T23:08:50.440Z,1637276930.440 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-11-18T23:08:50.440Z,1637276930.440 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8 2021-11-18T23:09:45.766Z,1637276985.766 [DAT](INFO): DAT read: Lowpower 2021-11-18T23:09:45.767Z,1637276985.767 [DAT](INFO): unknown deviceResponse_: Lowpower 2021-11-18T23:11:51.042Z,1637277111.042 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 9 2021-11-18T23:11:51.042Z,1637277111.042 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-11-18T23:11:51.054Z,1637277111.054 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-11-18T23:11:51.459Z,1637277111.459 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-11-18T23:11:51.459Z,1637277111.459 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 9 2021-11-18T23:11:57.494Z,1637277117.494 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-11-18T23:11:57.494Z,1637277117.494 [Default:CheckIn:C.Wait] Stopped 2021-11-18T23:11:57.494Z,1637277117.494 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-11-18T23:11:57.494Z,1637277117.494 [Default:CheckIn:D] Running Loop=1 2021-11-18T23:11:57.888Z,1637277117.888 [Default:CheckIn:D] Stopped 2021-11-18T23:11:57.888Z,1637277117.888 [Default:CheckIn:E] Running Loop=1 2021-11-18T23:11:58.288Z,1637277118.288 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 98.245467 min 2021-11-18T23:11:58.288Z,1637277118.288 [Default:CheckIn:E] Stopped 2021-11-18T23:11:58.288Z,1637277118.288 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-11-18T23:11:58.288Z,1637277118.288 [Default:CheckIn] Stopped 2021-11-18T23:11:58.289Z,1637277118.289 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-11-18T23:11:58.289Z,1637277118.289 [Default:CheckIn](INFO): Running loop #10 2021-11-18T23:11:58.289Z,1637277118.289 [Default:CheckIn] Running Loop=10 2021-11-18T23:11:58.289Z,1637277118.289 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-11-18T23:11:58.289Z,1637277118.289 [Default:CheckIn:Read_GPS] Running Loop=1 2021-11-18T23:14:27.402Z,1637277267.402 [CBIT](INFO): Clearing failed state for component DropWeight 2021-11-18T23:14:27.402Z,1637277267.402 [DropWeight] No Fault, FailCount= 1 2021-11-18T23:14:52.011Z,1637277292.011 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 10 2021-11-18T23:14:52.011Z,1637277292.011 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-11-18T23:14:52.046Z,1637277292.046 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-11-18T23:14:52.420Z,1637277292.420 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-11-18T23:14:52.421Z,1637277292.421 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 10 2021-11-18T23:16:58.466Z,1637277418.466 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-11-18T23:11:58.3Z 2021-11-18T23:16:58.466Z,1637277418.466 [Default:CheckIn:Read_GPS] Stopped 2021-11-18T23:16:58.466Z,1637277418.466 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-11-18T23:16:59.766Z,1637277419.766 [DAT](INFO): #Outgoing data=1 2021-11-18T23:16:59.767Z,1637277419.767 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-11-18T23:16:59.875Z,1637277419.875 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-11-18T23:17:00.222Z,1637277420.222 [DAT](INFO): DAT read: UART Wakeup 2021-11-18T23:17:00.223Z,1637277420.223 [DAT](INFO): DAT read: CONNECT 01200 bits/sec 1 of 4, Rate 1/2 CC 2021-11-18T23:17:00.224Z,1637277420.224 [DAT](INFO): commRate: 1200 2021-11-18T23:17:03.775Z,1637277423.775 [DAT](INFO): DAT read: Forwarding Delay UpTx time:23:16:27.2853 2021-11-18T23:17:03.775Z,1637277423.775 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-11-18T23:17:13.833Z,1637277433.833 [DAT](FAULT): Ack receipt timeout failure. 2021-11-18T23:17:13.833Z,1637277433.833 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2021-11-18T23:17:14.258Z,1637277434.258 [DAT](INFO): Sent 39 bytes from file Logs/20211118T212911/Courier0031.lzma.parts 2021-11-18T23:17:14.258Z,1637277434.258 [DAT](INFO): Packets left to send: 0 2021-11-18T23:17:14.261Z,1637277434.261 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2021-11-18T23:17:15.166Z,1637277435.166 [Default:CheckIn:Read_Iridium] Stopped 2021-11-18T23:17:15.166Z,1637277435.166 [Default:CheckIn:C.Wait] Running Loop=1 2021-11-18T23:17:15.166Z,1637277435.166 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-11-18T23:17:53.089Z,1637277473.089 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 11 2021-11-18T23:17:53.089Z,1637277473.089 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-11-18T23:17:53.101Z,1637277473.101 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-11-18T23:17:53.513Z,1637277473.513 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-11-18T23:17:53.514Z,1637277473.514 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 11 2021-11-18T23:18:07.610Z,1637277487.610 [NAL9602](FAULT): GPS failed to acquire within timeout. 2021-11-18T23:18:07.611Z,1637277487.611 [NAL9602] Data Fault, FailCount= 5 2021-11-18T23:18:07.611Z,1637277487.611 [NAL9602](ERROR): Data Fault 2021-11-18T23:18:07.663Z,1637277487.663 [CBIT](ERROR): Data Fault in component: NAL9602 2021-11-18T23:18:07.663Z,1637277487.663 [CBIT](CRITICAL): Data Fault in component: NAL9602 2021-11-18T23:18:08.014Z,1637277488.014 [NAL9602](INFO): Powering down 2021-11-18T23:18:08.032Z,1637277488.032 [CBIT](INFO): Critical error at 20211118T231807 2021-11-18T23:20:03.165Z,1637277603.165 [DAT](INFO): DAT read: Lowpower 2021-11-18T23:20:03.166Z,1637277603.166 [DAT](INFO): unknown deviceResponse_: Lowpower 2021-11-18T23:20:07.636Z,1637277607.636 [CBIT](INFO): Clearing failed state for component NAL9602 2021-11-18T23:20:07.636Z,1637277607.636 [NAL9602] No Fault, FailCount= 5 2021-11-18T23:20:07.999Z,1637277607.999 [NAL9602](INFO): Powering up NAL9602 2021-11-18T23:20:18.921Z,1637277618.921 [NAL9602](INFO): NAL9602 initialized 2021-11-18T23:20:54.067Z,1637277654.067 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 12 2021-11-18T23:20:54.067Z,1637277654.067 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-11-18T23:20:54.103Z,1637277654.103 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-11-18T23:20:54.510Z,1637277654.510 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-11-18T23:20:54.510Z,1637277654.510 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 12 2021-11-18T23:22:15.271Z,1637277735.271 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-11-18T23:22:15.271Z,1637277735.271 [Default:CheckIn:C.Wait] Stopped 2021-11-18T23:22:15.271Z,1637277735.271 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-11-18T23:22:15.272Z,1637277735.272 [Default:CheckIn:D] Running Loop=1 2021-11-18T23:22:15.690Z,1637277735.690 [Default:CheckIn:D] Stopped 2021-11-18T23:22:15.690Z,1637277735.690 [Default:CheckIn:E] Running Loop=1 2021-11-18T23:22:16.096Z,1637277736.096 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 108.542171 min 2021-11-18T23:22:16.096Z,1637277736.096 [Default:CheckIn:E] Stopped 2021-11-18T23:22:16.096Z,1637277736.096 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-11-18T23:22:16.097Z,1637277736.097 [Default:CheckIn] Stopped 2021-11-18T23:22:16.097Z,1637277736.097 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-11-18T23:22:16.097Z,1637277736.097 [Default:CheckIn](INFO): Running loop #11 2021-11-18T23:22:16.097Z,1637277736.097 [Default:CheckIn] Running Loop=11 2021-11-18T23:22:16.097Z,1637277736.097 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-11-18T23:22:16.097Z,1637277736.097 [Default:CheckIn:Read_GPS] Running Loop=1 2021-11-18T23:23:55.059Z,1637277835.059 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 13 2021-11-18T23:23:55.059Z,1637277835.059 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-11-18T23:23:55.070Z,1637277835.070 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-11-18T23:23:55.487Z,1637277835.487 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-11-18T23:23:55.487Z,1637277835.487 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 13 2021-11-18T23:26:56.064Z,1637278016.064 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 14 2021-11-18T23:26:56.064Z,1637278016.065 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-11-18T23:26:56.076Z,1637278016.076 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-11-18T23:26:56.489Z,1637278016.489 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-11-18T23:26:56.489Z,1637278016.489 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 14 2021-11-18T23:27:16.252Z,1637278036.252 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-11-18T23:22:16.1Z 2021-11-18T23:27:16.253Z,1637278036.253 [Default:CheckIn:Read_GPS] Stopped 2021-11-18T23:27:16.253Z,1637278036.253 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-11-18T23:27:17.579Z,1637278037.579 [DAT](INFO): #Outgoing data=1 2021-11-18T23:27:17.579Z,1637278037.579 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-11-18T23:27:17.683Z,1637278037.683 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-11-18T23:27:18.028Z,1637278038.028 [DAT](INFO): DAT read: UART Wakeup 2021-11-18T23:27:18.029Z,1637278038.029 [DAT](INFO): DAT read: CONNECT 01200 bits/sec 1 of 4, Rate 1/2 CC 2021-11-18T23:27:18.029Z,1637278038.029 [DAT](INFO): commRate: 1200 2021-11-18T23:27:21.035Z,1637278041.035 [DAT](INFO): DAT read: Forwarding Delay UpTx time:23:26:45.3302 2021-11-18T23:27:21.035Z,1637278041.035 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-11-18T23:27:31.090Z,1637278051.090 [DAT](FAULT): Ack receipt timeout failure. 2021-11-18T23:27:31.090Z,1637278051.090 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2021-11-18T23:27:31.464Z,1637278051.464 [DAT](INFO): Sent 82 bytes from file Logs/20211118T212911/Courier0034.lzma.parts 2021-11-18T23:27:31.464Z,1637278051.464 [DAT](INFO): Packets left to send: 0 2021-11-18T23:27:31.467Z,1637278051.467 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2021-11-18T23:27:32.384Z,1637278052.384 [Default:CheckIn:Read_Iridium] Stopped 2021-11-18T23:27:32.384Z,1637278052.384 [Default:CheckIn:C.Wait] Running Loop=1 2021-11-18T23:27:32.384Z,1637278052.384 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-11-18T23:29:56.955Z,1637278196.955 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 15 2021-11-18T23:29:56.955Z,1637278196.955 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-11-18T23:29:56.982Z,1637278196.982 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-11-18T23:29:57.368Z,1637278197.368 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-11-18T23:29:57.368Z,1637278197.368 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 15 2021-11-18T23:30:20.394Z,1637278220.394 [NAL9602](FAULT): GPS failed to acquire within timeout. 2021-11-18T23:30:20.395Z,1637278220.395 [NAL9602] Data Fault, FailCount= 1 2021-11-18T23:30:20.395Z,1637278220.395 [NAL9602](ERROR): Data Fault 2021-11-18T23:30:20.465Z,1637278220.465 [CBIT](ERROR): Data Fault in component: NAL9602 2021-11-18T23:30:20.811Z,1637278220.811 [NAL9602](INFO): Powering down 2021-11-18T23:30:21.203Z,1637278221.203 [DAT](INFO): DAT read: Lowpower 2021-11-18T23:30:21.204Z,1637278221.204 [DAT](INFO): unknown deviceResponse_: Lowpower 2021-11-18T23:30:21.705Z,1637278221.705 [CBIT](INFO): Clearing failed state for component NAL9602 2021-11-18T23:30:21.705Z,1637278221.705 [NAL9602] No Fault, FailCount= 1 2021-11-18T23:30:51.098Z,1637278251.098 [NAL9602](INFO): Powering up NAL9602 2021-11-18T23:31:02.011Z,1637278262.011 [NAL9602](INFO): NAL9602 initialized 2021-11-18T23:32:33.732Z,1637278353.732 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-11-18T23:32:33.732Z,1637278353.732 [Default:CheckIn:C.Wait] Stopped 2021-11-18T23:32:33.732Z,1637278353.732 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-11-18T23:32:33.732Z,1637278353.732 [Default:CheckIn:D] Running Loop=1 2021-11-18T23:32:34.130Z,1637278354.130 [Default:CheckIn:D] Stopped 2021-11-18T23:32:34.130Z,1637278354.130 [Default:CheckIn:E] Running Loop=1 2021-11-18T23:32:34.532Z,1637278354.532 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 118.849495 min 2021-11-18T23:32:34.532Z,1637278354.532 [Default:CheckIn:E] Stopped 2021-11-18T23:32:34.532Z,1637278354.532 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-11-18T23:32:34.532Z,1637278354.532 [Default:CheckIn] Stopped 2021-11-18T23:32:34.532Z,1637278354.532 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-11-18T23:32:34.532Z,1637278354.532 [Default:CheckIn](INFO): Running loop #12 2021-11-18T23:32:34.533Z,1637278354.533 [Default:CheckIn] Running Loop=12 2021-11-18T23:32:34.533Z,1637278354.533 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-11-18T23:32:34.533Z,1637278354.533 [Default:CheckIn:Read_GPS] Running Loop=1 2021-11-18T23:32:57.963Z,1637278377.963 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 16 2021-11-18T23:32:57.963Z,1637278377.963 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-11-18T23:32:57.994Z,1637278377.994 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-11-18T23:32:58.377Z,1637278378.377 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-11-18T23:32:58.377Z,1637278378.377 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 16 2021-11-18T23:35:58.955Z,1637278558.955 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 17 2021-11-18T23:35:58.955Z,1637278558.955 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-11-18T23:35:58.990Z,1637278558.990 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-11-18T23:35:59.365Z,1637278559.365 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-11-18T23:35:59.365Z,1637278559.365 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 17 2021-11-18T23:37:34.709Z,1637278654.709 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-11-18T23:32:34.5Z 2021-11-18T23:37:34.710Z,1637278654.710 [Default:CheckIn:Read_GPS] Stopped 2021-11-18T23:37:34.710Z,1637278654.710 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-11-18T23:37:36.018Z,1637278656.018 [DAT](INFO): #Outgoing data=1 2021-11-18T23:37:36.018Z,1637278656.018 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-11-18T23:37:36.127Z,1637278656.127 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-11-18T23:37:36.494Z,1637278656.494 [DAT](INFO): DAT read: UART Wakeup 2021-11-18T23:37:36.495Z,1637278656.495 [DAT](INFO): DAT read: CONNECT 01200 bits/sec 1 of 4, Rate 1/2 CC 2021-11-18T23:37:36.496Z,1637278656.496 [DAT](INFO): commRate: 1200 2021-11-18T23:37:39.419Z,1637278659.419 [DAT](INFO): DAT read: Forwarding Delay UpTx time:23:37:03.3305 2021-11-18T23:37:39.419Z,1637278659.419 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-11-18T23:37:49.492Z,1637278669.492 [DAT](FAULT): Ack receipt timeout failure. 2021-11-18T23:37:49.492Z,1637278669.492 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2021-11-18T23:37:49.901Z,1637278669.901 [DAT](INFO): Sent 39 bytes from file Logs/20211118T212911/Courier0037.lzma.parts 2021-11-18T23:37:49.902Z,1637278669.902 [DAT](INFO): Packets left to send: 0 2021-11-18T23:37:49.904Z,1637278669.904 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2021-11-18T23:37:50.831Z,1637278670.831 [Default:CheckIn:Read_Iridium] Stopped 2021-11-18T23:37:50.831Z,1637278670.831 [Default:CheckIn:C.Wait] Running Loop=1 2021-11-18T23:37:50.832Z,1637278670.832 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-11-18T23:38:59.824Z,1637278739.824 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 18 2021-11-18T23:38:59.824Z,1637278739.824 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-11-18T23:38:59.836Z,1637278739.836 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-11-18T23:39:00.250Z,1637278740.250 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-11-18T23:39:00.251Z,1637278740.251 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 18 2021-11-18T23:40:39.634Z,1637278839.634 [DAT](INFO): DAT read: Lowpower 2021-11-18T23:40:39.634Z,1637278839.634 [DAT](INFO): unknown deviceResponse_: Lowpower 2021-11-18T23:41:03.863Z,1637278863.863 [NAL9602](FAULT): GPS failed to acquire within timeout. 2021-11-18T23:41:03.863Z,1637278863.863 [NAL9602] Data Fault, FailCount= 2 2021-11-18T23:41:03.863Z,1637278863.863 [NAL9602](ERROR): Data Fault 2021-11-18T23:41:03.882Z,1637278863.882 [CBIT](ERROR): Data Fault in component: NAL9602 2021-11-18T23:41:04.258Z,1637278864.258 [NAL9602](INFO): Powering down 2021-11-18T23:41:04.666Z,1637278864.666 [NAL9602](FAULT): LCB fault: Software Overcurrent. 2021-11-18T23:41:04.667Z,1637278864.667 [NAL9602] Hardware Fault, FailCount= 2 2021-11-18T23:41:04.667Z,1637278864.667 [NAL9602](ERROR): Hardware Fault 2021-11-18T23:41:05.089Z,1637278865.089 [CBIT](INFO): Clearing failed state for component NAL9602 2021-11-18T23:41:05.089Z,1637278865.089 [NAL9602] No Fault, FailCount= 2 2021-11-18T23:41:34.563Z,1637278894.563 [NAL9602](INFO): Powering up NAL9602 2021-11-18T23:41:45.471Z,1637278905.471 [NAL9602](INFO): NAL9602 initialized 2021-11-18T23:42:00.841Z,1637278920.841 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 19 2021-11-18T23:42:00.841Z,1637278920.841 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-11-18T23:42:00.868Z,1637278920.868 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-11-18T23:42:01.248Z,1637278921.248 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-11-18T23:42:01.248Z,1637278921.248 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 19 2021-11-18T23:42:51.348Z,1637278971.348 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-11-18T23:42:51.348Z,1637278971.348 [Default:CheckIn:C.Wait] Stopped 2021-11-18T23:42:51.348Z,1637278971.348 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-11-18T23:42:51.348Z,1637278971.348 [Default:CheckIn:D] Running Loop=1 2021-11-18T23:42:51.754Z,1637278971.754 [Default:CheckIn:D] Stopped 2021-11-18T23:42:51.754Z,1637278971.754 [Default:CheckIn:E] Running Loop=1 2021-11-18T23:42:52.155Z,1637278972.155 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 129.143229 min 2021-11-18T23:42:52.155Z,1637278972.155 [Default:CheckIn:E] Stopped 2021-11-18T23:42:52.155Z,1637278972.155 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-11-18T23:42:52.155Z,1637278972.155 [Default:CheckIn] Stopped 2021-11-18T23:42:52.155Z,1637278972.155 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-11-18T23:42:52.155Z,1637278972.155 [Default:CheckIn](INFO): Running loop #13 2021-11-18T23:42:52.155Z,1637278972.155 [Default:CheckIn] Running Loop=13 2021-11-18T23:42:52.155Z,1637278972.155 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-11-18T23:42:52.156Z,1637278972.156 [Default:CheckIn:Read_GPS] Running Loop=1 2021-11-18T23:44:28.686Z,1637279068.686 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2021-11-18T23:44:28.686Z,1637279068.686 [DropWeight] Hardware Fault, FailCount= 1 2021-11-18T23:44:28.686Z,1637279068.686 [DropWeight](ERROR): Hardware Fault 2021-11-18T23:44:28.704Z,1637279068.704 [CBIT](INFO): Critical error at 20211118T234428 2021-11-18T23:44:28.707Z,1637279068.707 [CBIT](ERROR): Hardware Fault in component: DropWeight 2021-11-18T23:44:28.707Z,1637279068.707 [CBIT](CRITICAL): Hardware Fault in component: DropWeight 2021-11-18T23:44:29.124Z,1637279069.124 [CBIT](INFO): Critical error at 20211118T234428 2021-11-18T23:45:01.823Z,1637279101.823 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 20 2021-11-18T23:45:01.823Z,1637279101.823 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-11-18T23:45:01.858Z,1637279101.858 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-11-18T23:45:01.859Z,1637279101.859 [CBIT](FAULT): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-11-18T23:47:52.379Z,1637279272.379 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-11-18T23:42:52.2Z 2021-11-18T23:47:52.379Z,1637279272.379 [Default:CheckIn:Read_GPS] Stopped 2021-11-18T23:47:52.379Z,1637279272.379 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-11-18T23:47:53.662Z,1637279273.662 [DAT](INFO): #Outgoing data=1 2021-11-18T23:47:53.662Z,1637279273.662 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-11-18T23:47:53.814Z,1637279273.814 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-11-18T23:47:54.162Z,1637279274.162 [DAT](INFO): DAT read: URTWup 2021-11-18T23:47:54.162Z,1637279274.162 [DAT](INFO): unknown deviceResponse_: URTWup 2021-11-18T23:47:54.163Z,1637279274.163 [DAT](INFO): DAT read: CECT12 ts 1o 4 Rte 1/2C 2021-11-18T23:47:54.163Z,1637279274.163 [DAT](INFO): unknown deviceResponse_: CECT12 ts 1o 4 Rte 1/2C 2021-11-18T23:47:57.116Z,1637279277.116 [DAT](INFO): DAT read: Forwarding Delay UpTx time:23:47:21.3827 2021-11-18T23:47:57.116Z,1637279277.116 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-11-18T23:48:07.162Z,1637279287.162 [DAT](FAULT): Ack receipt timeout failure. 2021-11-18T23:48:07.162Z,1637279287.162 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2021-11-18T23:48:08.086Z,1637279288.086 [DAT](INFO): Sent 114 bytes from file Logs/20211118T212911/Courier0040.lzma.parts 2021-11-18T23:48:08.086Z,1637279288.086 [DAT](INFO): Packets left to send: 0 2021-11-18T23:48:08.089Z,1637279288.089 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2021-11-18T23:48:08.668Z,1637279288.668 [Default:CheckIn:Read_Iridium] Stopped 2021-11-18T23:48:08.668Z,1637279288.668 [Default:CheckIn:C.Wait] Running Loop=1 2021-11-18T23:48:08.668Z,1637279288.668 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-11-18T23:50:25.325Z,1637279425.325 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2021-11-18T23:50:25.328Z,1637279425.328 [BPC1](INFO): Received data from all battery sticks. 2021-11-18T23:50:57.169Z,1637279457.169 [DAT](INFO): DAT read: Lowpower 2021-11-18T23:50:57.170Z,1637279457.170 [DAT](INFO): unknown deviceResponse_: Lowpower 2021-11-18T23:51:47.264Z,1637279507.264 [NAL9602](FAULT): GPS failed to acquire within timeout. 2021-11-18T23:51:47.265Z,1637279507.265 [NAL9602] Data Fault, FailCount= 3 2021-11-18T23:51:47.265Z,1637279507.265 [NAL9602](ERROR): Data Fault 2021-11-18T23:51:47.284Z,1637279507.284 [CBIT](ERROR): Data Fault in component: NAL9602 2021-11-18T23:51:47.662Z,1637279507.662 [NAL9602](INFO): Powering down 2021-11-18T23:51:48.070Z,1637279508.070 [NAL9602](FAULT): LCB fault: Software Overcurrent. 2021-11-18T23:51:48.070Z,1637279508.070 [NAL9602] Hardware Fault, FailCount= 3 2021-11-18T23:51:48.070Z,1637279508.070 [NAL9602](ERROR): Hardware Fault 2021-11-18T23:51:48.492Z,1637279508.492 [CBIT](INFO): Clearing failed state for component NAL9602 2021-11-18T23:51:48.492Z,1637279508.492 [NAL9602] No Fault, FailCount= 3 2021-11-18T23:52:17.985Z,1637279537.985 [NAL9602](INFO): Powering up NAL9602 2021-11-18T23:52:28.871Z,1637279548.871 [NAL9602](INFO): NAL9602 initialized 2021-11-18T23:53:08.889Z,1637279588.889 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-11-18T23:53:08.889Z,1637279588.889 [Default:CheckIn:C.Wait] Stopped 2021-11-18T23:53:08.889Z,1637279588.889 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-11-18T23:53:08.889Z,1637279588.889 [Default:CheckIn:D] Running Loop=1 2021-11-18T23:53:09.292Z,1637279589.292 [Default:CheckIn:D] Stopped 2021-11-18T23:53:09.292Z,1637279589.292 [Default:CheckIn:E] Running Loop=1 2021-11-18T23:53:09.711Z,1637279589.711 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 139.435531 min 2021-11-18T23:53:09.711Z,1637279589.711 [Default:CheckIn:E] Stopped 2021-11-18T23:53:09.711Z,1637279589.711 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-11-18T23:53:09.711Z,1637279589.711 [Default:CheckIn] Stopped 2021-11-18T23:53:09.711Z,1637279589.711 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-11-18T23:53:09.711Z,1637279589.711 [Default:CheckIn](INFO): Running loop #14 2021-11-18T23:53:09.712Z,1637279589.712 [Default:CheckIn] Running Loop=14 2021-11-18T23:53:09.712Z,1637279589.712 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-11-18T23:53:09.712Z,1637279589.712 [Default:CheckIn:Read_GPS] Running Loop=1 2021-11-18T23:58:09.903Z,1637279889.903 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-11-18T23:53:09.7Z 2021-11-18T23:58:09.903Z,1637279889.903 [Default:CheckIn:Read_GPS] Stopped 2021-11-18T23:58:09.903Z,1637279889.903 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-11-18T23:58:11.182Z,1637279891.182 [DAT](INFO): #Outgoing data=1 2021-11-18T23:58:11.183Z,1637279891.183 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-11-18T23:58:11.264Z,1637279891.264 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-11-18T23:58:11.625Z,1637279891.625 [DAT](INFO): DAT read: UART Wakeup 2021-11-18T23:58:11.626Z,1637279891.626 [DAT](INFO): DAT read: CONNECT 01200 bits/sec 1 of 4, Rate 1/2 CC 2021-11-18T23:58:11.627Z,1637279891.627 [DAT](INFO): commRate: 1200 2021-11-18T23:58:14.750Z,1637279894.750 [DAT](INFO): DAT read: Forwarding Delay UpTx time:23:57:39.3334 2021-11-18T23:58:14.751Z,1637279894.751 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-11-18T23:58:20.242Z,1637279900.242 [CommandExec](IMPORTANT): got command restart application 2021-11-18T23:58:21.245Z,1637279901.245 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread. 2021-11-18T23:58:21.245Z,1637279901.245 [CommandExec](INFO): Uninitializing the command executive. 2021-11-18T23:58:21.245Z,1637279901.245 [CommandExec](INFO): Uninitializing the command scheduler. 2021-11-18T23:58:21.246Z,1637279901.246 [CommandExec ThreadHandler](INFO): Thread cancelled. 2021-11-18T23:58:21.285Z,1637279901.285 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2021-11-18T23:58:21.285Z,1637279901.285 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2021-11-18T23:58:21.285Z,1637279901.285 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2021-11-18T23:58:21.286Z,1637279901.286 [NavChartDb](INFO): Join timeout helper Thread ID is 1067 2021-11-18T23:58:21.457Z,1637279901.457 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2021-11-18T23:58:21.457Z,1637279901.457 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2021-11-18T23:58:21.458Z,1637279901.458 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2021-11-18T23:58:21.458Z,1637279901.458 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2021-11-18T23:58:21.459Z,1637279901.459 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 1068 2021-11-18T23:58:21.821Z,1637279901.821 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2021-11-18T23:58:21.821Z,1637279901.821 [WetLabsBB2FL](INFO): Powering down 2021-11-18T23:58:21.822Z,1637279901.822 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2021-11-18T23:58:21.837Z,1637279901.837 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2021-11-18T23:58:21.837Z,1637279901.837 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2021-11-18T23:58:21.837Z,1637279901.837 [CTD_Seabird](INFO): Join timeout helper Thread ID is 1069 2021-11-18T23:58:21.933Z,1637279901.933 [CTD_Seabird](INFO): Powering down 2021-11-18T23:58:21.950Z,1637279901.950 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread. 2021-11-18T23:58:21.950Z,1637279901.950 [CTD_Seabird](INFO): Powering down 2021-11-18T23:58:21.965Z,1637279901.965 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2021-11-18T23:58:21.969Z,1637279901.969 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2021-11-18T23:58:21.969Z,1637279901.969 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2021-11-18T23:58:21.969Z,1637279901.969 [Radio_Surface](INFO): Join timeout helper Thread ID is 1070 2021-11-18T23:58:22.265Z,1637279902.265 [Radio_Surface](INFO): Powering down 2021-11-18T23:58:22.266Z,1637279902.266 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2021-11-18T23:58:22.266Z,1637279902.266 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2021-11-18T23:58:22.269Z,1637279902.269 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler 2021-11-18T23:58:22.269Z,1637279902.269 [Onboard ThreadHandler](INFO): Thread cancelled. 2021-11-18T23:58:22.269Z,1637279902.269 [Onboard](INFO): Join timeout helper Thread ID is 1071 2021-11-18T23:58:23.257Z,1637279903.257 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread. 2021-11-18T23:58:23.257Z,1637279903.257 [Onboard ThreadHandler](INFO): Thread cancelled. 2021-11-18T23:58:23.280Z,1637279903.280 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2021-11-18T23:58:23.280Z,1637279903.280 [logger ThreadHandler](INFO): Thread cancelled. 2021-11-18T23:58:23.281Z,1637279903.281 [logger](INFO): Join timeout helper Thread ID is 1072 2021-11-18T23:58:23.304Z,1637279903.304 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2021-11-18T23:58:23.304Z,1637279903.304 [logger ThreadHandler](INFO): Thread cancelled. 2021-11-18T23:58:23.306Z,1637279903.306 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2021-11-18T23:58:23.306Z,1637279903.306 [CommandLine ThreadHandler](INFO): Thread cancelled. 2021-11-18T23:58:23.307Z,1637279903.307 [CommandLine](INFO): Join timeout helper Thread ID is 1073 2021-11-18T23:58:23.397Z,1637279903.397 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2021-11-18T23:58:23.397Z,1637279903.397 [CommandLine ThreadHandler](INFO): Thread cancelled. 2021-11-18T23:58:23.406Z,1637279903.406 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler 2021-11-18T23:58:23.406Z,1637279903.406 [CommandExec ThreadHandler](INFO): Thread cancelled. 2021-11-18T23:58:23.406Z,1637279903.406 [CommandExec](INFO): Join timeout helper Thread ID is 1074 2021-11-18T23:58:23.407Z,1637279903.407 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2021-11-18T23:58:23.407Z,1637279903.407 [controlThread ThreadHandler](INFO): Thread cancelled. 2021-11-18T23:58:23.408Z,1637279903.408 [controlThread](INFO): Join timeout helper Thread ID is 1075 2021-11-18T23:58:23.585Z,1637279903.585 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2021-11-18T23:58:23.585Z,1637279903.585 [controlThread](DEBUG): Uninitializing ControlThread 2021-11-18T23:58:23.586Z,1637279903.586 [AHRS_M2](INFO): Powering down 2021-11-18T23:58:23.658Z,1637279903.658 [NAL9602](INFO): Powering down 2021-11-18T23:58:23.659Z,1637279903.659 [DAT](INFO): Powering down 2021-11-18T23:58:23.779Z,1637279903.779 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2021-11-18T23:58:23.780Z,1637279903.780 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2021-11-18T23:58:23.780Z,1637279903.780 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2021-11-18T23:58:23.781Z,1637279903.781 [MissionManager](INFO): Uninitializing Mission Default 2021-11-18T23:58:23.781Z,1637279903.781 [Default] Stopped 2021-11-18T23:58:23.781Z,1637279903.781 [Default](DEBUG): Aggregate::uninitialize Default 2021-11-18T23:58:23.781Z,1637279903.781 [Default:B.GoToSurface] Stopped 2021-11-18T23:58:23.781Z,1637279903.781 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2021-11-18T23:58:23.781Z,1637279903.781 [Default:CheckIn] Stopped 2021-11-18T23:58:23.781Z,1637279903.781 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-11-18T23:58:23.781Z,1637279903.781 [Default:CheckIn:Read_Iridium] Stopped 2021-11-18T23:58:23.785Z,1637279903.785 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2021-11-18T23:58:23.785Z,1637279903.785 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2021-11-18T23:58:23.785Z,1637279903.785 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2021-11-18T23:58:23.786Z,1637279903.786 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2021-11-18T23:58:23.786Z,1637279903.786 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2021-11-18T23:58:23.786Z,1637279903.786 [BuoyancyServo](INFO): Powering down 2021-11-18T23:58:23.801Z,1637279903.801 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2021-11-18T23:58:23.801Z,1637279903.801 [ElevatorServo](INFO): Powering down 2021-11-18T23:58:23.802Z,1637279903.802 [MassServo](DEBUG): Uninitialize Mass Servo. 2021-11-18T23:58:23.802Z,1637279903.802 [MassServo](INFO): Powering down 2021-11-18T23:58:23.803Z,1637279903.803 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2021-11-18T23:58:23.803Z,1637279903.803 [RudderServo](INFO): Powering down 2021-11-18T23:58:23.804Z,1637279903.804 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2021-11-18T23:58:23.804Z,1637279903.804 [ThrusterServo](INFO): Powering down 2021-11-18T23:58:23.805Z,1637279903.805 [SBIT](DEBUG): Uninitialize SBIT Component. 2021-11-18T23:58:23.806Z,1637279903.806 [IBIT](DEBUG): Uninitialize IBIT Component. 2021-11-18T23:58:23.806Z,1637279903.806 [CBIT](DEBUG): Uninitialize CBIT Component. 2021-11-18T23:58:23.806Z,1637279903.806 [CBIT](DEBUG): Powering off loads. 2021-11-18T23:58:23.817Z,1637279903.817 [CBIT](DEBUG): Disabling WDT. 2021-11-18T23:58:23.829Z,1637279903.829 [CBIT](DEBUG): Opening all GF detection circuits. 2021-11-18T23:58:23.830Z,1637279903.830 [controlThread ThreadHandler](INFO): Thread cancelled. 2021-11-18T23:58:23.884Z,1637279903.884 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2021-11-18T23:58:23.887Z,1637279903.887 [Onboard ThreadHandler](INFO): Thread cancelled. 2021-11-18T23:58:23.960Z,1637279903.960 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2021-11-18T23:58:23.964Z,1637279903.964 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2021-11-18T23:58:24.004Z,1637279904.004 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2021-11-18T23:58:24.068Z,1637279904.068 [logger ThreadHandler](INFO): Thread cancelled.