2022-04-13T22:40:24.728Z,1649889624.728 [Supervisor](DEBUG): Initializing supervisor. 2022-04-13T22:40:24.734Z,1649889624.734 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2022-04-13T22:40:24.734Z,1649889624.734 [SyncHandler](INFO): Protected caller Thread ID is 5411 2022-04-13T22:40:24.735Z,1649889624.735 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2022-04-13T22:40:24.736Z,1649889624.736 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2022-04-13T22:40:24.736Z,1649889624.736 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 5412 2022-04-13T22:40:24.741Z,1649889624.741 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2022-04-13T22:40:24.759Z,1649889624.759 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread. 2022-04-13T22:40:24.760Z,1649889624.760 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2022-04-13T22:40:24.761Z,1649889624.761 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 5413 2022-04-13T22:40:24.765Z,1649889624.765 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2022-04-13T22:40:24.766Z,1649889624.766 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2022-04-13T22:40:24.766Z,1649889624.766 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 5414 2022-04-13T22:40:24.768Z,1649889624.768 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2022-04-13T22:40:24.769Z,1649889624.769 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0 2022-04-13T22:40:24.770Z,1649889624.770 [logger ThreadHandler](INFO): Protected caller Thread ID is 5415 2022-04-13T22:40:24.773Z,1649889624.773 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2022-04-13T22:40:24.774Z,1649889624.774 [Supervisor](INFO): Looking for Config files in directory: Config/ 2022-04-13T22:40:24.775Z,1649889624.775 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2022-04-13T22:40:24.933Z,1649889624.933 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2022-04-13T22:40:24.934Z,1649889624.934 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2022-04-13T22:40:25.549Z,1649889625.549 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2022-04-13T22:40:25.549Z,1649889625.549 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg 2022-04-13T22:40:25.761Z,1649889625.761 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock 2022-04-13T22:40:25.761Z,1649889625.761 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2022-04-13T22:40:25.838Z,1649889625.838 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2022-04-13T22:40:25.959Z,1649889625.959 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2022-04-13T22:40:25.959Z,1649889625.959 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2022-04-13T22:40:26.039Z,1649889626.039 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2022-04-13T22:40:26.144Z,1649889626.144 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2022-04-13T22:40:26.145Z,1649889626.145 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2022-04-13T22:40:26.501Z,1649889626.501 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2022-04-13T22:40:26.502Z,1649889626.502 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2022-04-13T22:40:27.922Z,1649889627.922 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2022-04-13T22:40:27.929Z,1649889627.929 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2022-04-13T22:40:28.427Z,1649889628.427 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2022-04-13T22:40:28.428Z,1649889628.428 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2022-04-13T22:40:28.619Z,1649889628.619 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2022-04-13T22:40:28.619Z,1649889628.619 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2022-04-13T22:40:29.796Z,1649889629.796 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2022-04-13T22:40:29.797Z,1649889629.797 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2022-04-13T22:40:30.069Z,1649889630.069 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2022-04-13T22:40:30.070Z,1649889630.070 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2022-04-13T22:40:30.284Z,1649889630.284 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2022-04-13T22:40:30.284Z,1649889630.284 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2022-04-13T22:40:30.639Z,1649889630.639 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2022-04-13T22:40:30.640Z,1649889630.640 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2022-04-13T22:40:30.987Z,1649889630.987 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2022-04-13T22:40:30.989Z,1649889630.989 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-pontus/ 2022-04-13T22:40:30.990Z,1649889630.990 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/secure.cfg 2022-04-13T22:40:31.073Z,1649889631.073 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Sensor.cfg 2022-04-13T22:40:31.230Z,1649889631.230 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Servo.cfg 2022-04-13T22:40:31.339Z,1649889631.339 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Simulator.cfg 2022-04-13T22:40:31.424Z,1649889631.424 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/logger.cfg 2022-04-13T22:40:31.518Z,1649889631.518 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/vehicle.cfg 2022-04-13T22:40:31.705Z,1649889631.705 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Battery.cfg 2022-04-13T22:40:31.967Z,1649889631.967 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2022-04-13T22:40:31.968Z,1649889631.968 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Navigation.cfg 2022-04-13T22:40:32.060Z,1649889632.060 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/BIT.cfg 2022-04-13T22:40:32.157Z,1649889632.157 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Science.cfg 2022-04-13T22:40:32.294Z,1649889632.294 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Control.cfg 2022-04-13T22:40:32.393Z,1649889632.393 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-pontus/root/ 2022-04-13T22:40:32.394Z,1649889632.394 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2022-04-13T22:40:32.406Z,1649889632.406 [Module Loader](DEBUG): Loading Module at Modules/Dock.so 2022-04-13T22:40:32.504Z,1649889632.504 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking) 2022-04-13T22:40:32.505Z,1649889632.505 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2022-04-13T22:40:32.557Z,1649889632.557 [VerticalControl](DEBUG): Construct VerticalControl. 2022-04-13T22:40:32.616Z,1649889632.616 [VerticalControl] Loaded 2022-04-13T22:40:32.617Z,1649889632.617 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2022-04-13T22:40:32.619Z,1649889632.619 [HorizontalControl](DEBUG): Construct HorizontalControl. 2022-04-13T22:40:32.658Z,1649889632.658 [HorizontalControl] Loaded 2022-04-13T22:40:32.658Z,1649889632.658 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2022-04-13T22:40:32.660Z,1649889632.660 [SpeedControl](DEBUG): Construct SpeedControl. 2022-04-13T22:40:32.663Z,1649889632.663 [SpeedControl] Loaded 2022-04-13T22:40:32.664Z,1649889632.664 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2022-04-13T22:40:32.666Z,1649889632.666 [LoopControl](DEBUG): Construct LoopControl. 2022-04-13T22:40:32.667Z,1649889632.667 [LoopControl] Loaded 2022-04-13T22:40:32.667Z,1649889632.667 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2022-04-13T22:40:32.667Z,1649889632.667 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2022-04-13T22:40:32.668Z,1649889632.668 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2022-04-13T22:40:32.722Z,1649889632.722 [DepthRateCalculator] Loaded 2022-04-13T22:40:32.722Z,1649889632.722 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2022-04-13T22:40:32.727Z,1649889632.727 [PitchRateCalculator] Loaded 2022-04-13T22:40:32.727Z,1649889632.727 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2022-04-13T22:40:32.737Z,1649889632.737 [SpeedCalculator] Loaded 2022-04-13T22:40:32.737Z,1649889632.737 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2022-04-13T22:40:32.742Z,1649889632.742 [YawRateCalculator] Loaded 2022-04-13T22:40:32.742Z,1649889632.742 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2022-04-13T22:40:32.759Z,1649889632.759 [ElevatorOffsetCalculator] Loaded 2022-04-13T22:40:32.759Z,1649889632.759 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2022-04-13T22:40:32.760Z,1649889632.760 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2022-04-13T22:40:32.760Z,1649889632.760 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2022-04-13T22:40:32.788Z,1649889632.788 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2022-04-13T22:40:32.789Z,1649889632.789 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2022-04-13T22:40:32.848Z,1649889632.848 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2022-04-13T22:40:32.849Z,1649889632.849 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2022-04-13T22:40:33.165Z,1649889633.165 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2022-04-13T22:40:33.166Z,1649889633.166 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2022-04-13T22:40:33.276Z,1649889633.276 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2022-04-13T22:40:33.277Z,1649889633.277 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2022-04-13T22:40:33.709Z,1649889633.709 [AHRS_M2] Loaded 2022-04-13T22:40:33.709Z,1649889633.709 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2022-04-13T22:40:33.745Z,1649889633.745 [BackseatComponent] Loaded 2022-04-13T22:40:33.745Z,1649889633.745 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread. 2022-04-13T22:40:33.746Z,1649889633.746 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 4096C4E0 2022-04-13T22:40:33.746Z,1649889633.746 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 5497 2022-04-13T22:40:33.749Z,1649889633.749 [LcmUniversalReporter] Loaded 2022-04-13T22:40:33.749Z,1649889633.749 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread. 2022-04-13T22:40:34.547Z,1649889634.547 [BPC1] Loaded 2022-04-13T22:40:34.547Z,1649889634.547 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2022-04-13T22:40:34.618Z,1649889634.618 [DataOverHttps] Loaded 2022-04-13T22:40:34.618Z,1649889634.618 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2022-04-13T22:40:34.619Z,1649889634.619 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4099C4E0 2022-04-13T22:40:34.620Z,1649889634.620 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 5498 2022-04-13T22:40:34.639Z,1649889634.639 [Depth_Keller] Loaded 2022-04-13T22:40:34.640Z,1649889634.640 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2022-04-13T22:40:34.645Z,1649889634.645 [DropWeight] Loaded 2022-04-13T22:40:34.645Z,1649889634.645 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2022-04-13T22:40:34.704Z,1649889634.704 [NAL9602] Loaded 2022-04-13T22:40:34.704Z,1649889634.704 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2022-04-13T22:40:34.733Z,1649889634.733 [Onboard] Loaded 2022-04-13T22:40:34.734Z,1649889634.734 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread. 2022-04-13T22:40:34.734Z,1649889634.734 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 409CC4E0 2022-04-13T22:40:34.735Z,1649889634.735 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 5499 2022-04-13T22:40:34.746Z,1649889634.746 [Power24vConverter] Loaded 2022-04-13T22:40:34.747Z,1649889634.747 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread. 2022-04-13T22:40:34.759Z,1649889634.759 [Radio_Surface] Loaded 2022-04-13T22:40:34.759Z,1649889634.759 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2022-04-13T22:40:34.760Z,1649889634.760 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409FC4E0 2022-04-13T22:40:34.761Z,1649889634.761 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 5500 2022-04-13T22:40:34.845Z,1649889634.845 [RDI_Pathfinder] Loaded 2022-04-13T22:40:34.846Z,1649889634.846 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread. 2022-04-13T22:40:35.243Z,1649889635.243 [DAT] Loaded 2022-04-13T22:40:35.243Z,1649889635.243 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread. 2022-04-13T22:40:35.251Z,1649889635.251 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 40A2C4E0 2022-04-13T22:40:35.251Z,1649889635.251 [DAT ThreadHandler](INFO): Protected caller Thread ID is 5501 2022-04-13T22:40:35.252Z,1649889635.252 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2022-04-13T22:40:35.252Z,1649889635.252 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2022-04-13T22:40:35.567Z,1649889635.567 [DeadReckonUsingMultipleVelocitySources] Loaded 2022-04-13T22:40:35.568Z,1649889635.568 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2022-04-13T22:40:35.581Z,1649889635.581 [NavChart] Loaded 2022-04-13T22:40:35.581Z,1649889635.581 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2022-04-13T22:40:35.587Z,1649889635.587 [UniversalFixResidualReporter] Loaded 2022-04-13T22:40:35.587Z,1649889635.587 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2022-04-13T22:40:35.588Z,1649889635.588 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2022-04-13T22:40:35.589Z,1649889635.589 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2022-04-13T22:40:35.925Z,1649889635.925 [SBIT](DEBUG): Construct Startup Built In Test. 2022-04-13T22:40:35.934Z,1649889635.934 [SBIT] Loaded 2022-04-13T22:40:35.934Z,1649889635.934 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2022-04-13T22:40:35.937Z,1649889635.937 [IBIT](DEBUG): Construct Initiated Built In Test. 2022-04-13T22:40:35.951Z,1649889635.951 [IBIT] Loaded 2022-04-13T22:40:35.952Z,1649889635.952 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2022-04-13T22:40:35.957Z,1649889635.957 [CBIT](DEBUG): Construct Continuous Built In Test. 2022-04-13T22:40:36.060Z,1649889636.060 [CBIT] Loaded 2022-04-13T22:40:36.060Z,1649889636.060 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2022-04-13T22:40:36.061Z,1649889636.061 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2022-04-13T22:40:36.061Z,1649889636.061 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2022-04-13T22:40:36.188Z,1649889636.188 [BuoyancyServo] Loaded 2022-04-13T22:40:36.189Z,1649889636.189 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2022-04-13T22:40:36.208Z,1649889636.208 [ElevatorServo] Loaded 2022-04-13T22:40:36.209Z,1649889636.209 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2022-04-13T22:40:36.228Z,1649889636.228 [MassServo] Loaded 2022-04-13T22:40:36.229Z,1649889636.229 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2022-04-13T22:40:36.246Z,1649889636.246 [RudderServo] Loaded 2022-04-13T22:40:36.247Z,1649889636.247 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2022-04-13T22:40:36.264Z,1649889636.264 [ThrusterServo] Loaded 2022-04-13T22:40:36.265Z,1649889636.265 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2022-04-13T22:40:36.265Z,1649889636.265 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2022-04-13T22:40:36.266Z,1649889636.266 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2022-04-13T22:40:36.276Z,1649889636.276 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2022-04-13T22:40:36.277Z,1649889636.277 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2022-04-13T22:40:36.452Z,1649889636.452 [CTD_Seabird] Loaded 2022-04-13T22:40:36.452Z,1649889636.452 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2022-04-13T22:40:36.453Z,1649889636.453 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40B764E0 2022-04-13T22:40:36.454Z,1649889636.454 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 5502 2022-04-13T22:40:36.473Z,1649889636.473 [PAR_Licor] Loaded 2022-04-13T22:40:36.473Z,1649889636.473 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2022-04-13T22:40:36.504Z,1649889636.504 [WetLabsBB2FL] Loaded 2022-04-13T22:40:36.505Z,1649889636.505 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2022-04-13T22:40:36.506Z,1649889636.506 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40BA64E0 2022-04-13T22:40:36.506Z,1649889636.506 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 5503 2022-04-13T22:40:36.526Z,1649889636.526 [WetLabsUBAT] Loaded 2022-04-13T22:40:36.526Z,1649889636.526 [ComponentRegistry](DEBUG): Component "WetLabsUBAT" handled in its own thread. 2022-04-13T22:40:36.527Z,1649889636.527 [WetLabsUBAT ThreadHandler](DEBUG): Created PCaller Thread at 40BD64E0 2022-04-13T22:40:36.528Z,1649889636.528 [WetLabsUBAT ThreadHandler](INFO): Protected caller Thread ID is 5504 2022-04-13T22:40:36.528Z,1649889636.528 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2022-04-13T22:40:36.534Z,1649889636.534 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2022-04-13T22:40:36.537Z,1649889636.537 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2022-04-13T22:40:36.548Z,1649889636.548 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2022-04-13T22:40:36.549Z,1649889636.549 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C064E0 2022-04-13T22:40:36.549Z,1649889636.549 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 5505 2022-04-13T22:40:36.554Z,1649889636.554 [Supervisor](INFO): Main Thread ID is 5237 2022-04-13T22:40:36.554Z,1649889636.554 [Supervisor](DEBUG): Running supervisor. 2022-04-13T22:40:36.555Z,1649889636.555 [CommandExec ThreadHandler](INFO): Handler Thread ID is 5506 2022-04-13T22:40:36.555Z,1649889636.555 [CommandExec](INFO): Initializing the command executive. 2022-04-13T22:40:36.557Z,1649889636.557 [CommandLine ThreadHandler](INFO): Handler Thread ID is 5507 2022-04-13T22:40:36.559Z,1649889636.559 [controlThread ThreadHandler](INFO): Handler Thread ID is 5508 2022-04-13T22:40:36.560Z,1649889636.560 [controlThread](DEBUG): Initializing ControlThread 2022-04-13T22:40:36.561Z,1649889636.561 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2022-04-13T22:40:36.562Z,1649889636.562 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2022-04-13T22:40:36.563Z,1649889636.563 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2022-04-13T22:40:36.563Z,1649889636.563 [LoopControl](DEBUG): Initialize LoopControlComponent. 2022-04-13T22:40:36.564Z,1649889636.564 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2022-04-13T22:40:36.564Z,1649889636.564 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2022-04-13T22:40:36.564Z,1649889636.564 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2022-04-13T22:40:36.565Z,1649889636.565 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2022-04-13T22:40:36.565Z,1649889636.565 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2022-04-13T22:40:36.570Z,1649889636.570 [NavChart](DEBUG): Initialize NavChart Navigation. 2022-04-13T22:40:36.571Z,1649889636.571 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2022-04-13T22:40:36.571Z,1649889636.571 [SBIT](INFO): Initialize SBIT Component. 2022-04-13T22:40:36.571Z,1649889636.571 [SBIT](IMPORTANT): git: 2022-04-13-2-g6a2310dff 2022-04-13T22:40:36.571Z,1649889636.571 [SBIT](INFO): git hash: 6a2310dff441a827ef861f8ed5d6284137a6a00f 2022-04-13T22:40:36.572Z,1649889636.572 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2022-04-13T22:40:36.573Z,1649889636.573 [SBIT](INFO): Kernel Reporting Different Version From Configuration. Kernel Expected: #1 PREEMPT Thu Feb 21 11:17:40 PST 2019 Kernel Reported: #1 PREEMPT Wed Mar 17 08:23:48 PDT 2021 2022-04-13T22:40:36.574Z,1649889636.574 [SBIT](INFO): Beginning SBIT in 42.000000 seconds. 2022-04-13T22:40:36.575Z,1649889636.575 [IBIT](INFO): Initialize IBIT Component. 2022-04-13T22:40:36.575Z,1649889636.575 [CBIT](DEBUG): Initialize CBIT Component. 2022-04-13T22:40:36.577Z,1649889636.577 [logger ThreadHandler](INFO): Handler Thread ID is 5509 2022-04-13T22:40:36.588Z,1649889636.588 [CBIT](DEBUG): Initialized mux pins. 2022-04-13T22:40:36.588Z,1649889636.588 [CBIT](DEBUG): Initializing the watchdog timer. 2022-04-13T22:40:36.596Z,1649889636.596 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 5510 2022-04-13T22:40:36.608Z,1649889636.608 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 5511 2022-04-13T22:40:36.609Z,1649889636.609 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2022-04-13T22:40:36.612Z,1649889636.612 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2022-04-13T22:40:36.612Z,1649889636.612 [CBIT](DEBUG): Initializing heartbeat. 2022-04-13T22:40:36.620Z,1649889636.620 [Onboard ThreadHandler](INFO): Handler Thread ID is 5512 2022-04-13T22:40:36.638Z,1649889636.638 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 5513 2022-04-13T22:40:36.661Z,1649889636.661 [DAT ThreadHandler](INFO): Handler Thread ID is 5514 2022-04-13T22:40:36.661Z,1649889636.661 [DAT](INFO): Powering up 2022-04-13T22:40:36.662Z,1649889636.662 [DAT](DEBUG): Initializing DAT. 2022-04-13T22:40:36.665Z,1649889636.665 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 5516 2022-04-13T22:40:36.666Z,1649889636.666 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2022-04-13T22:40:36.669Z,1649889636.669 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 5518 2022-04-13T22:40:36.672Z,1649889636.672 [WetLabsBB2FL](INFO): Powering up 2022-04-13T22:40:36.673Z,1649889636.673 [WetLabsUBAT ThreadHandler](INFO): Handler Thread ID is 5520 2022-04-13T22:40:36.677Z,1649889636.677 [WetLabsUBAT](INFO): Powering up 2022-04-13T22:40:36.678Z,1649889636.678 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 5522 2022-04-13T22:40:36.681Z,1649889636.681 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2022-04-13T22:40:36.682Z,1649889636.682 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2022-04-13T22:40:36.682Z,1649889636.682 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2022-04-13T22:40:36.682Z,1649889636.682 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2022-04-13T22:40:36.682Z,1649889636.682 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2022-04-13T22:40:36.682Z,1649889636.682 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2022-04-13T22:40:36.682Z,1649889636.682 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000 2022-04-13T22:40:36.683Z,1649889636.683 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2022-04-13T22:40:36.683Z,1649889636.683 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2022-04-13T22:40:36.683Z,1649889636.683 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2022-04-13T22:40:36.683Z,1649889636.683 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000 2022-04-13T22:40:36.683Z,1649889636.683 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2022-04-13T22:40:36.683Z,1649889636.683 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000 2022-04-13T22:40:36.684Z,1649889636.684 [CBIT](DEBUG): Deactivating GF circuits. 2022-04-13T22:40:36.684Z,1649889636.684 [CBIT](DEBUG): Deactivating emergency mode. 2022-04-13T22:40:36.683Z,1649889636.683 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2022-04-13T22:40:36.684Z,1649889636.684 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000 2022-04-13T22:40:36.685Z,1649889636.685 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2022-04-13T22:40:36.720Z,1649889636.720 [CBIT](DEBUG): Backplane powered. 2022-04-13T22:40:36.725Z,1649889636.725 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml 2022-04-13T22:40:36.751Z,1649889636.751 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2022-04-13T22:40:36.779Z,1649889636.779 [MissionManager](DEBUG): 2022-04-13T22:40:36.779Z,1649889636.779 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml 2022-04-13T22:40:36.861Z,1649889636.861 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2022-04-13T22:40:36.862Z,1649889636.862 [Default:A.Wait](DEBUG): Construct Wait. 2022-04-13T22:40:36.888Z,1649889636.888 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2022-04-13T22:40:36.932Z,1649889636.932 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2022-04-13T22:40:36.934Z,1649889636.934 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2022-04-13T22:40:36.974Z,1649889636.974 [Default:E.Execute](DEBUG): Construct Execute. 2022-04-13T22:40:36.978Z,1649889636.978 [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 2022-04-13T22:40:36.988Z,1649889636.988 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,RDI_Pathfinder,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter, 2022-04-13T22:40:36.000Z,1649889637.000 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2022-04-13T22:40:37.044Z,1649889637.044 [Radio_Surface](INFO): Powering up 2022-04-13T22:40:37.082Z,1649889637.082 [Power24vConverter](INFO): Powering up. 2022-04-13T22:40:37.126Z,1649889637.126 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2022-04-13T22:40:37.132Z,1649889637.132 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2022-04-13T22:40:37.133Z,1649889637.133 [ElevatorServo](DEBUG): Initializing EZServoServo. 2022-04-13T22:40:37.140Z,1649889637.140 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2022-04-13T22:40:37.141Z,1649889637.141 [MassServo](DEBUG): Initializing EZServoServo. 2022-04-13T22:40:37.148Z,1649889637.148 [MassServo](DEBUG): Initializing MassServo. 2022-04-13T22:40:37.149Z,1649889637.149 [RudderServo](DEBUG): Initializing EZServoServo. 2022-04-13T22:40:37.160Z,1649889637.160 [RudderServo](DEBUG): Initializing RudderServo. 2022-04-13T22:40:37.161Z,1649889637.161 [ThrusterServo](DEBUG): Initializing EZServoServo. 2022-04-13T22:40:37.168Z,1649889637.168 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2022-04-13T22:40:37.425Z,1649889637.425 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2022-04-13T22:40:37.425Z,1649889637.425 [DropWeight] Hardware Fault, FailCount= 1 2022-04-13T22:40:37.425Z,1649889637.425 [DropWeight](ERROR): Hardware Fault 2022-04-13T22:40:37.494Z,1649889637.494 [CommandExec](FAULT): Scheduling is paused 2022-04-13T22:40:37.495Z,1649889637.495 [CBIT](INFO): Critical error at 20220413T224037 2022-04-13T22:40:37.495Z,1649889637.495 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals 2022-04-13T22:40:37.505Z,1649889637.505 [CBIT](ERROR): Hardware Fault in component: DropWeight 2022-04-13T22:40:37.506Z,1649889637.506 [CBIT](CRITICAL): Hardware Fault in component: DropWeight 2022-04-13T22:40:38.148Z,1649889638.148 [RudderServo](ERROR): Rudder initialization uart error serial timeout 2022-04-13T22:40:38.148Z,1649889638.148 [RudderServo](FAULT): Rudder failed to initialize 2022-04-13T22:40:38.148Z,1649889638.148 [RudderServo] Communications Fault, FailCount= 1 2022-04-13T22:40:38.148Z,1649889638.148 [RudderServo](ERROR): Communications Fault 2022-04-13T22:40:38.246Z,1649889638.246 [CBIT](INFO): Critical error at 20220413T224037 2022-04-13T22:40:38.249Z,1649889638.249 [CBIT](ERROR): Communications Fault in component: RudderServo 2022-04-13T22:40:38.461Z,1649889638.461 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2022-04-13T22:40:38.461Z,1649889638.461 [RudderServo](INFO): Powering down 2022-04-13T22:40:39.083Z,1649889639.083 [RudderServo](DEBUG): Initializing EZServoServo. 2022-04-13T22:40:39.209Z,1649889639.209 [RudderServo](DEBUG): Initializing RudderServo. 2022-04-13T22:40:39.213Z,1649889639.213 [CBIT](INFO): Clearing failed state for component RudderServo 2022-04-13T22:40:39.214Z,1649889639.214 [RudderServo] No Fault, FailCount= 1 2022-04-13T22:40:39.284Z,1649889639.284 [WetLabsBB2FL](INFO): Powering down 2022-04-13T22:40:45.933Z,1649889645.933 [WetLabsUBAT](INFO): Powering down 2022-04-13T22:40:46.787Z,1649889646.787 [CBIT](FAULT): Could not open coulomb counter log file 2022-04-13T22:40:48.504Z,1649889648.504 [DAT](INFO): DAT read: 2022-04-13T22:40:48.506Z,1649889648.506 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series 2022-04-13T22:40:50.269Z,1649889650.269 [DAT](INFO): DAT read: MF Frequency Band 2022-04-13T22:40:50.270Z,1649889650.270 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0 2022-04-13T22:40:50.270Z,1649889650.270 [DAT](INFO): DAT read: Apr 13 2022 22:40:44 2022-04-13T22:40:51.277Z,1649889651.277 [DAT](INFO): DAT read: Features enabled [Bearing] 2022-04-13T22:40:51.278Z,1649889651.278 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP 2022-04-13T22:40:51.278Z,1649889651.278 [DAT](INFO): commRate: 800 2022-04-13T22:40:53.344Z,1649889653.344 [DAT](INFO): entering command mode 2022-04-13T22:40:53.544Z,1649889653.544 [DAT](INFO): DAT read: 2022-04-13T22:40:53.545Z,1649889653.545 [DAT](INFO): DAT read: user:1> 2022-04-13T22:40:53.545Z,1649889653.545 [DAT](INFO): setting verbose to 3 2022-04-13T22:40:53.797Z,1649889653.797 [DAT](INFO): DAT read: user:1> 2022-04-13T22:40:53.798Z,1649889653.798 [DAT](INFO): DAT read: Verbose | 3 2022-04-13T22:40:53.798Z,1649889653.798 [DAT](INFO): set verbose to 3 2022-04-13T22:40:53.798Z,1649889653.798 [DAT](INFO): setting DatVerbose to 27440 2022-04-13T22:40:54.049Z,1649889654.049 [DAT](INFO): DAT read: user:2> 2022-04-13T22:40:54.050Z,1649889654.050 [DAT](INFO): DAT read: DatVerbose | 27440 2022-04-13T22:40:54.050Z,1649889654.050 [DAT](INFO): set DatVerbose to 27440 2022-04-13T22:40:54.050Z,1649889654.050 [DAT](INFO): setting transmit power to 8 2022-04-13T22:40:54.300Z,1649889654.300 [DAT](INFO): DAT read: user:3> 2022-04-13T22:40:54.301Z,1649889654.301 [DAT](INFO): DAT read: TxPower | 8 (Max) 2022-04-13T22:40:54.302Z,1649889654.302 [DAT](INFO): set transmit power to 8 2022-04-13T22:40:54.302Z,1649889654.302 [DAT](INFO): setting local address to 9 2022-04-13T22:40:54.554Z,1649889654.554 [DAT](INFO): DAT read: user:4> 2022-04-13T22:40:54.556Z,1649889654.556 [DAT](INFO): DAT read: LocalAddr | 9 2022-04-13T22:40:54.556Z,1649889654.556 [DAT](INFO): set local address to 9 2022-04-13T22:40:54.558Z,1649889654.558 [DAT](INFO): Setting time to: 22:40:54 And date to:4/13/2022 2022-04-13T22:40:54.804Z,1649889654.804 [DAT](INFO): DAT read: user:5> 2022-04-13T22:40:54.805Z,1649889654.805 [DAT](INFO): DAT read: Wed Apr 13, 2022 22:40:54 2022-04-13T22:40:54.806Z,1649889654.806 [DAT](INFO): Local DAT time set to Wed Apr 13, 2022 22:40:54 2022-04-13T22:40:56.923Z,1649889656.923 [CBIT](FAULT): Could not open coulomb counter log file 2022-04-13T22:41:04.930Z,1649889664.930 [NAL9602](INFO): Powering up NAL9602 2022-04-13T22:41:07.031Z,1649889667.031 [CBIT](FAULT): Could not open coulomb counter log file 2022-04-13T22:41:15.833Z,1649889675.833 [NAL9602](INFO): NAL9602 initialized 2022-04-13T22:41:17.116Z,1649889677.116 [CBIT](FAULT): Could not open coulomb counter log file 2022-04-13T22:41:19.108Z,1649889679.108 [SBIT](IMPORTANT): Beginning Startup BIT 2022-04-13T22:41:19.117Z,1649889679.117 [CBIT](IMPORTANT): Beginning ground fault scan 2022-04-13T22:41:27.206Z,1649889687.206 [CBIT](FAULT): Could not open coulomb counter log file 2022-04-13T22:41:30.044Z,1649889690.044 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): 0.001868 CHAN A1 (24V): -0.000264 CHAN A2 (12V): -0.007545 CHAN A3 (5V): -0.001713 CHAN B0 (3.3V): 0.000543 CHAN B1 (3.15aV): -0.000092 CHAN B2 (3.15bV): -0.000464 CHAN B3 (GND): 0.001841 OPEN: 0.005302 Full Scale: +/- 1 mA 2022-04-13T22:41:37.351Z,1649889697.351 [CBIT](FAULT): Could not open coulomb counter log file 2022-04-13T22:41:47.411Z,1649889707.411 [CBIT](FAULT): Could not open coulomb counter log file 2022-04-13T22:41:57.557Z,1649889717.557 [CBIT](FAULT): Could not open coulomb counter log file 2022-04-13T22:42:07.566Z,1649889727.566 [CBIT](FAULT): Could not open coulomb counter log file 2022-04-13T22:42:12.838Z,1649889732.838 [SBIT](IMPORTANT): SBIT PASSED 2022-04-13T22:42:12.838Z,1649889732.838 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2022-04-13T22:42:12.839Z,1649889732.839 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=2 count; 2022-04-13T22:42:12.839Z,1649889732.839 [SBIT](IMPORTANT): CBIT.gf24Offset=143 microampere; 2022-04-13T22:42:12.839Z,1649889732.839 [SBIT](IMPORTANT): DAT.baud=115200 bit_per_second; 2022-04-13T22:42:12.839Z,1649889732.839 [SBIT](IMPORTANT): DAT.loadAtStartup=1 bool; 2022-04-13T22:42:12.839Z,1649889732.839 [SBIT](IMPORTANT): DAT.surfaceThreshold=0 meter; 2022-04-13T22:42:12.839Z,1649889732.839 [SBIT](IMPORTANT): DAT.verbosity=2 count; 2022-04-13T22:42:12.839Z,1649889732.839 [SBIT](IMPORTANT): Express linearApproximation WetLabsUBAT.flow_rate 0.300000 liter_per_second; 2022-04-13T22:42:12.840Z,1649889732.840 [SBIT](IMPORTANT): IBIT.batteryCapacityThreshold=24 ampere_hour; 2022-04-13T22:42:12.840Z,1649889732.840 [SBIT](IMPORTANT): IBIT.batteryVoltageThreshold=13 volt; 2022-04-13T22:42:12.840Z,1649889732.840 [SBIT](IMPORTANT): Power24vConverter.simulateHardware=0 bool; 2022-04-13T22:42:12.840Z,1649889732.840 [SBIT](IMPORTANT): RDI_Pathfinder.loadAtStartup=1 bool; 2022-04-13T22:42:12.840Z,1649889732.840 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=300.651033 cubic_centimeter; 2022-04-13T22:42:12.840Z,1649889732.840 [SBIT](IMPORTANT): VerticalControl.massDefault=5.530755 millimeter; 2022-04-13T22:42:13.233Z,1649889733.233 [MissionManager](IMPORTANT): Started mission Startup 2022-04-13T22:42:13.233Z,1649889733.233 [Startup] Running Loop=1 2022-04-13T22:42:13.233Z,1649889733.233 [Startup](DEBUG): Aggregate::initialize Startup 2022-04-13T22:42:13.233Z,1649889733.233 [Startup:A.GoToSurface] Running Loop=1 2022-04-13T22:42:13.233Z,1649889733.233 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2022-04-13T22:42:13.234Z,1649889733.234 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2022-04-13T22:42:13.234Z,1649889733.234 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2022-04-13T22:42:13.234Z,1649889733.234 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2022-04-13T22:42:13.235Z,1649889733.235 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2022-04-13T22:42:13.235Z,1649889733.235 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2022-04-13T22:42:13.237Z,1649889733.237 [Startup:StartupSatComms] Running Loop=1 2022-04-13T22:42:13.237Z,1649889733.237 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2022-04-13T22:42:13.237Z,1649889733.237 [Startup:StartupSatComms:A] Running Loop=1 2022-04-13T22:42:13.622Z,1649889733.622 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2022-04-13T22:42:17.669Z,1649889737.669 [CBIT](FAULT): Could not open coulomb counter log file 2022-04-13T22:42:25.205Z,1649889745.205 [CommandExec](IMPORTANT): got command show stack 2022-04-13T22:42:25.205Z,1649889745.205 [CommandExec](IMPORTANT): Behavior Stack: 2022-04-13T22:42:25.206Z,1649889745.206 [Startup](IMPORTANT): Priority 0: Startup:A.GoToSurface 2022-04-13T22:42:25.206Z,1649889745.206 [Startup:StartupSatComms](IMPORTANT): Priority 1: Startup:StartupSatComms:A 2022-04-13T22:42:27.815Z,1649889747.815 [CBIT](FAULT): Could not open coulomb counter log file 2022-04-13T22:42:35.786Z,1649889755.786 [CommandExec](IMPORTANT): got command set NAL9602.platform_communications 1 bool 2022-04-13T22:42:37.905Z,1649889757.905 [CBIT](FAULT): Could not open coulomb counter log file 2022-04-13T22:42:47.975Z,1649889767.975 [CBIT](FAULT): Could not open coulomb counter log file 2022-04-13T22:42:56.169Z,1649889776.169 [CommandExec](IMPORTANT): got command maintain sensor Depth_Keller.depth 0.1 meter 2022-04-13T22:42:56.172Z,1649889776.172 [ComponentRegistry](DEBUG): SyncComponent "Maintain_Depth_Keller.depth" handled in the control thread. 2022-04-13T22:42:56.470Z,1649889776.470 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,RDI_Pathfinder,PAR_Licor,Depth_Keller,PAR_Licor,Maintain_Depth_Keller.depth,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter, 2022-04-13T22:42:58.085Z,1649889778.085 [CBIT](FAULT): Could not open coulomb counter log file 2022-04-13T22:43:04.586Z,1649889784.586 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.010728 2022-04-13T22:43:08.185Z,1649889788.185 [CBIT](FAULT): Could not open coulomb counter log file 2022-04-13T22:43:13.410Z,1649889793.410 [Startup:StartupSatComms:A](INFO): Timed out from 2022-04-13T22:42:13.2Z 2022-04-13T22:43:13.410Z,1649889793.410 [Startup:StartupSatComms:A] Stopped 2022-04-13T22:43:13.410Z,1649889793.410 [Startup:StartupSatComms:B] Running Loop=1 2022-04-13T22:43:13.830Z,1649889793.830 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2022-04-13T22:43:18.305Z,1649889798.305 [CBIT](FAULT): Could not open coulomb counter log file 2022-04-13T22:43:21.219Z,1649889801.219 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20220413T222518/Courier0003.lzma 2022-04-13T22:43:22.222Z,1649889802.222 [DataOverHttps](INFO): Moved sent file to Logs/20220413T222518/Courier0003.lzma.bak 2022-04-13T22:43:22.222Z,1649889802.222 [DataOverHttps](INFO): SBD MOMSN=16644788 2022-04-13T22:43:27.857Z,1649889807.857 [CommandExec](IMPORTANT): got command show stack 2022-04-13T22:43:27.857Z,1649889807.857 [CommandExec](IMPORTANT): Behavior Stack: 2022-04-13T22:43:27.858Z,1649889807.858 [Startup](IMPORTANT): Priority 0: Startup:A.GoToSurface 2022-04-13T22:43:27.858Z,1649889807.858 [Startup:StartupSatComms](IMPORTANT): Priority 1: Startup:StartupSatComms:B 2022-04-13T22:43:28.398Z,1649889808.398 [CBIT](FAULT): Could not open coulomb counter log file 2022-04-13T22:43:36.958Z,1649889816.958 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2022-04-13T22:43:36.958Z,1649889816.958 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2022-04-13T22:43:37.079Z,1649889817.079 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2022-04-13T22:43:37.337Z,1649889817.337 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2022-04-13T22:43:37.337Z,1649889817.337 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2022-04-13T22:43:38.487Z,1649889818.487 [CBIT](FAULT): Could not open coulomb counter log file 2022-04-13T22:43:39.803Z,1649889819.803 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20220413T223323/Courier0000.lzma 2022-04-13T22:43:40.806Z,1649889820.806 [DataOverHttps](INFO): Moved sent file to Logs/20220413T223323/Courier0000.lzma.bak 2022-04-13T22:43:40.806Z,1649889820.806 [DataOverHttps](INFO): SBD MOMSN=16644790 2022-04-13T22:43:44.448Z,1649889824.448 [CommandExec](IMPORTANT): got command set NAL9602.platform_communications 1 bool 2022-04-13T22:43:44.566Z,1649889824.566 [Startup:StartupSatComms:B] Stopped 2022-04-13T22:43:44.567Z,1649889824.567 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2022-04-13T22:43:44.567Z,1649889824.567 [Startup:StartupSatComms] Stopped 2022-04-13T22:43:44.567Z,1649889824.567 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2022-04-13T22:43:44.580Z,1649889824.580 [Startup](INFO): Completed Startup 2022-04-13T22:43:44.581Z,1649889824.581 [MissionManager](INFO): Startup is completed. 2022-04-13T22:43:44.581Z,1649889824.581 [MissionManager](INFO): Uninitializing Mission Startup 2022-04-13T22:43:44.581Z,1649889824.581 [Startup] Stopped 2022-04-13T22:43:44.581Z,1649889824.581 [Startup](DEBUG): Aggregate::uninitialize Startup 2022-04-13T22:43:44.582Z,1649889824.582 [Startup:A.GoToSurface] Stopped 2022-04-13T22:43:44.582Z,1649889824.582 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2022-04-13T22:43:45.010Z,1649889825.010 [MissionManager](IMPORTANT): Started mission Default 2022-04-13T22:43:45.010Z,1649889825.010 [Default] Running Loop=1 2022-04-13T22:43:45.010Z,1649889825.010 [Default](DEBUG): Aggregate::initialize Default 2022-04-13T22:43:45.010Z,1649889825.010 [Default:B.GoToSurface] Running Loop=1 2022-04-13T22:43:45.010Z,1649889825.010 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2022-04-13T22:43:45.011Z,1649889825.011 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2022-04-13T22:43:45.011Z,1649889825.011 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2022-04-13T22:43:45.011Z,1649889825.011 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2022-04-13T22:43:45.040Z,1649889825.040 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2022-04-13T22:43:45.040Z,1649889825.040 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2022-04-13T22:43:45.040Z,1649889825.040 [Default:A.Wait] Running Loop=1 2022-04-13T22:43:45.040Z,1649889825.040 [Default:A.Wait](DEBUG): Initialize Wait Component. 2022-04-13T22:43:48.631Z,1649889828.631 [CBIT](FAULT): Could not open coulomb counter log file 2022-04-13T22:43:55.567Z,1649889835.567 [CommandExec](IMPORTANT): got command run ./Missions/Demo/senddata_direct_test.xml 2022-04-13T22:43:55.567Z,1649889835.567 [MissionManager](INFO): Loading Mission from file: ./Missions/Demo/senddata_direct_test.xml 2022-04-13T22:43:55.598Z,1649889835.598 [MissionManager](DEBUG): 2022-04-13T22:43:55.604Z,1649889835.604 [CommandExec](IMPORTANT): Running ./Missions/Demo/senddata_direct_test.xml 2022-04-13T22:43:55.854Z,1649889835.854 [Default] Stopped 2022-04-13T22:43:55.854Z,1649889835.854 [Default](DEBUG): Aggregate::uninitialize Default 2022-04-13T22:43:55.854Z,1649889835.854 [Default:A.Wait] Stopped 2022-04-13T22:43:55.854Z,1649889835.854 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2022-04-13T22:43:55.854Z,1649889835.854 [Default:B.GoToSurface] Stopped 2022-04-13T22:43:55.854Z,1649889835.854 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2022-04-13T22:43:55.855Z,1649889835.855 [MissionManager](IMPORTANT): Started mission senddata_direct_test 2022-04-13T22:43:55.855Z,1649889835.855 [senddata_direct_test] Running Loop=1 2022-04-13T22:43:55.855Z,1649889835.855 [senddata_direct_test](DEBUG): Aggregate::initialize senddata_direct_test 2022-04-13T22:43:55.855Z,1649889835.855 [senddata_direct_test:A] Running Loop=1 2022-04-13T22:43:55.860Z,1649889835.860 [senddata_direct_test:A](INFO): Queuing up send data for Onboard.Pressure with destination: modem:1:_.pressure 2022-04-13T22:43:55.860Z,1649889835.860 [senddata_direct_test:A] Stopped 2022-04-13T22:43:55.860Z,1649889835.860 [senddata_direct_test:B] Running Loop=1 2022-04-13T22:43:56.070Z,1649889836.070 [DAT](INFO): modem://1: set _.pressure 0.519420 atmosphere 2022-04-13T22:43:56.070Z,1649889836.070 [DAT](INFO): #Outgoing data=1 2022-04-13T22:43:56.070Z,1649889836.070 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-04-13T22:43:56.267Z,1649889836.267 [senddata_direct_test:B](INFO): Queuing up send data for Onboard.Temperature with destination: modem:1:_.temperature 2022-04-13T22:43:56.272Z,1649889836.272 [senddata_direct_test:B] Stopped 2022-04-13T22:43:56.272Z,1649889836.272 [senddata_direct_test:C] Running Loop=1 2022-04-13T22:43:56.321Z,1649889836.321 [DAT](INFO): setting remote address to 1 2022-04-13T22:43:56.574Z,1649889836.574 [DAT](INFO): DAT read: user:6> 2022-04-13T22:43:56.578Z,1649889836.578 [DAT](INFO): DAT read: RemoteAddr | 1 2022-04-13T22:43:56.579Z,1649889836.579 [DAT](INFO): set remote address to 1 2022-04-13T22:43:56.580Z,1649889836.580 [DAT](INFO): entering online mode 2022-04-13T22:43:56.748Z,1649889836.748 [senddata_direct_test:C](INFO): Queuing up send data for Onboard.Humidity with destination: modem:1:_.humidity 2022-04-13T22:43:56.749Z,1649889836.749 [senddata_direct_test:C] Stopped 2022-04-13T22:43:56.749Z,1649889836.749 [senddata_direct_test](INFO): Completed senddata_direct_test 2022-04-13T22:43:56.749Z,1649889836.749 [MissionManager](INFO): senddata_direct_test is completed. 2022-04-13T22:43:56.749Z,1649889836.749 [MissionManager](INFO): Uninitializing Mission senddata_direct_test 2022-04-13T22:43:56.749Z,1649889836.749 [senddata_direct_test] Stopped 2022-04-13T22:43:56.749Z,1649889836.749 [senddata_direct_test](DEBUG): Aggregate::uninitialize senddata_direct_test 2022-04-13T22:43:56.825Z,1649889836.825 [DAT](INFO): DAT read: user:7> 2022-04-13T22:43:56.825Z,1649889836.825 [DAT](INFO): DAT read: 2022-04-13T22:43:56.826Z,1649889836.826 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP 2022-04-13T22:43:56.827Z,1649889836.827 [DAT](INFO): commRate: 800 2022-04-13T22:43:56.827Z,1649889836.827 [DAT](INFO): online mode acknowledged 2022-04-13T22:43:56.827Z,1649889836.827 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-04-13T22:43:57.058Z,1649889837.058 [MissionManager](IMPORTANT): Started mission Default 2022-04-13T22:43:57.058Z,1649889837.058 [Default] Running Loop=1 2022-04-13T22:43:57.058Z,1649889837.058 [Default](DEBUG): Aggregate::initialize Default 2022-04-13T22:43:57.058Z,1649889837.058 [Default:B.GoToSurface] Running Loop=1 2022-04-13T22:43:57.058Z,1649889837.058 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2022-04-13T22:43:57.059Z,1649889837.059 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2022-04-13T22:43:57.059Z,1649889837.059 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2022-04-13T22:43:57.059Z,1649889837.059 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2022-04-13T22:43:57.064Z,1649889837.064 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2022-04-13T22:43:57.064Z,1649889837.064 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2022-04-13T22:43:57.064Z,1649889837.064 [Default:A.Wait] Running Loop=1 2022-04-13T22:43:57.065Z,1649889837.065 [Default:A.Wait](DEBUG): Initialize Wait Component. 2022-04-13T22:43:58.740Z,1649889838.740 [CBIT](FAULT): Could not open coulomb counter log file 2022-04-13T22:43:59.871Z,1649889839.871 [DataOverHttps](INFO): Sending 244 bytes from file Logs/20220413T224024/Courier0000.lzma 2022-04-13T22:44:00.101Z,1649889840.101 [DAT](INFO): DAT read: Forwarding Delay UpTx time:22:43:59.5147 2022-04-13T22:44:00.101Z,1649889840.101 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-04-13T22:44:00.873Z,1649889840.873 [DataOverHttps](INFO): Moved sent file to Logs/20220413T224024/Courier0000.lzma.bak 2022-04-13T22:44:00.874Z,1649889840.874 [DataOverHttps](INFO): SBD MOMSN=16644793 2022-04-13T22:44:08.787Z,1649889848.787 [CBIT](FAULT): Could not open coulomb counter log file 2022-04-13T22:44:10.188Z,1649889850.188 [DAT](FAULT): Ack receipt timeout failure. 2022-04-13T22:44:10.188Z,1649889850.188 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2022-04-13T22:44:10.374Z,1649889850.374 [Default:A.Wait](INFO): Done Waiting. 2022-04-13T22:44:10.374Z,1649889850.374 [Default:A.Wait] Stopped 2022-04-13T22:44:10.374Z,1649889850.374 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2022-04-13T22:44:10.442Z,1649889850.442 [DAT](INFO): modem://1: set _.temperature 24.138697 celsius 2022-04-13T22:44:10.443Z,1649889850.443 [DAT](INFO): #Outgoing data=1 2022-04-13T22:44:10.444Z,1649889850.444 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-04-13T22:44:10.692Z,1649889850.692 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-04-13T22:44:10.806Z,1649889850.806 [Default:CheckIn] Running Loop=1 2022-04-13T22:44:10.806Z,1649889850.806 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-04-13T22:44:10.806Z,1649889850.806 [Default:CheckIn:Read_GPS] Running Loop=1 2022-04-13T22:44:11.266Z,1649889851.266 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2022-04-13T22:44:13.977Z,1649889853.977 [DAT](INFO): DAT read: Forwarding Delay UpTx time:22:44:13.4146 2022-04-13T22:44:13.977Z,1649889853.977 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-04-13T22:44:18.889Z,1649889858.889 [CBIT](FAULT): Could not open coulomb counter log file 2022-04-13T22:44:24.072Z,1649889864.072 [DAT](FAULT): Ack receipt timeout failure. 2022-04-13T22:44:24.072Z,1649889864.072 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2022-04-13T22:44:24.325Z,1649889864.325 [DAT](INFO): modem://1: set _.humidity 22.201197 percent 2022-04-13T22:44:24.325Z,1649889864.325 [DAT](INFO): #Outgoing data=2 2022-04-13T22:44:24.325Z,1649889864.325 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-04-13T22:44:24.578Z,1649889864.578 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-04-13T22:44:27.853Z,1649889867.853 [DAT](INFO): DAT read: Forwarding Delay UpTx time:22:44:27.2645 2022-04-13T22:44:27.853Z,1649889867.853 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-04-13T22:44:28.990Z,1649889868.990 [CBIT](FAULT): Could not open coulomb counter log file 2022-04-13T22:44:37.936Z,1649889877.936 [DAT](FAULT): Ack receipt timeout failure. 2022-04-13T22:44:37.936Z,1649889877.936 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2022-04-13T22:44:38.188Z,1649889878.188 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-04-13T22:44:38.440Z,1649889878.440 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-04-13T22:44:39.079Z,1649889879.079 [CBIT](FAULT): Could not open coulomb counter log file 2022-04-13T22:44:41.721Z,1649889881.721 [DAT](INFO): DAT read: Forwarding Delay UpTx time:22:44:41.1145 2022-04-13T22:44:41.721Z,1649889881.721 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-04-13T22:44:49.189Z,1649889889.189 [CBIT](FAULT): Could not open coulomb counter log file 2022-04-13T22:44:51.804Z,1649889891.804 [DAT](FAULT): Ack receipt timeout failure. 2022-04-13T22:44:51.804Z,1649889891.804 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2022-04-13T22:44:52.056Z,1649889892.056 [DAT](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER 2022-04-13T22:44:52.309Z,1649889892.309 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-04-13T22:44:52.560Z,1649889892.560 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-04-13T22:44:55.837Z,1649889895.837 [DAT](INFO): DAT read: Forwarding Delay UpTx time:22:44:55.2644 2022-04-13T22:44:55.837Z,1649889895.837 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-04-13T22:44:59.275Z,1649889899.275 [CBIT](FAULT): Could not open coulomb counter log file 2022-04-13T22:45:05.932Z,1649889905.932 [DAT](FAULT): Ack receipt timeout failure. 2022-04-13T22:45:05.933Z,1649889905.933 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2022-04-13T22:45:06.184Z,1649889906.184 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-04-13T22:45:06.436Z,1649889906.436 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-04-13T22:45:09.395Z,1649889909.395 [CBIT](FAULT): Could not open coulomb counter log file 2022-04-13T22:45:09.713Z,1649889909.713 [DAT](INFO): DAT read: Forwarding Delay UpTx time:22:45:09.1144 2022-04-13T22:45:09.713Z,1649889909.713 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-04-13T22:45:19.513Z,1649889919.513 [CBIT](FAULT): Could not open coulomb counter log file 2022-04-13T22:45:19.792Z,1649889919.792 [DAT](FAULT): Ack receipt timeout failure. 2022-04-13T22:45:19.792Z,1649889919.792 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2022-04-13T22:45:20.044Z,1649889920.044 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-04-13T22:45:20.548Z,1649889920.548 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-04-13T22:45:23.825Z,1649889923.825 [DAT](INFO): DAT read: Forwarding Delay UpTx time:22:45:23.2643 2022-04-13T22:45:23.825Z,1649889923.825 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-04-13T22:45:29.589Z,1649889929.589 [CBIT](FAULT): Could not open coulomb counter log file 2022-04-13T22:45:33.916Z,1649889933.916 [DAT](FAULT): Ack receipt timeout failure. 2022-04-13T22:45:33.916Z,1649889933.916 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2022-04-13T22:45:34.169Z,1649889934.169 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-04-13T22:45:34.672Z,1649889934.672 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-04-13T22:45:37.957Z,1649889937.957 [DAT](INFO): DAT read: Forwarding Delay UpTx time:22:45:37.3642 2022-04-13T22:45:37.957Z,1649889937.957 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-04-13T22:45:39.693Z,1649889939.693 [CBIT](FAULT): Could not open coulomb counter log file 2022-04-13T22:45:48.048Z,1649889948.048 [DAT](FAULT): Ack receipt timeout failure. 2022-04-13T22:45:48.048Z,1649889948.048 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2022-04-13T22:45:48.300Z,1649889948.300 [DAT](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER 2022-04-13T22:45:48.554Z,1649889948.554 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-04-13T22:45:48.804Z,1649889948.804 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-04-13T22:45:49.789Z,1649889949.789 [CBIT](FAULT): Could not open coulomb counter log file 2022-04-13T22:45:52.081Z,1649889952.081 [DAT](INFO): DAT read: Forwarding Delay UpTx time:22:45:51.5142 2022-04-13T22:45:52.081Z,1649889952.081 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-04-13T22:45:59.950Z,1649889959.950 [CBIT](FAULT): Could not open coulomb counter log file 2022-04-13T22:46:02.179Z,1649889962.179 [DAT](FAULT): Ack receipt timeout failure. 2022-04-13T22:46:02.179Z,1649889962.179 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2022-04-13T22:46:02.428Z,1649889962.428 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-04-13T22:46:02.681Z,1649889962.681 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-04-13T22:46:05.961Z,1649889965.961 [DAT](INFO): DAT read: Forwarding Delay UpTx time:22:46:05.3641 2022-04-13T22:46:05.961Z,1649889965.961 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-04-13T22:46:09.997Z,1649889969.997 [CBIT](FAULT): Could not open coulomb counter log file 2022-04-13T22:46:16.044Z,1649889976.044 [DAT](FAULT): Ack receipt timeout failure. 2022-04-13T22:46:16.044Z,1649889976.044 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2022-04-13T22:46:16.296Z,1649889976.296 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-04-13T22:46:16.549Z,1649889976.549 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-04-13T22:46:18.849Z,1649889978.849 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-04-13T22:46:19.825Z,1649889979.825 [DAT](INFO): DAT read: Forwarding Delay UpTx time:22:46:19.2641 2022-04-13T22:46:19.826Z,1649889979.826 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-04-13T22:46:20.112Z,1649889980.112 [CBIT](FAULT): Could not open coulomb counter log file 2022-04-13T22:46:29.921Z,1649889989.921 [DAT](FAULT): Ack receipt timeout failure. 2022-04-13T22:46:29.921Z,1649889989.921 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2022-04-13T22:46:30.199Z,1649889990.199 [CBIT](FAULT): Could not open coulomb counter log file 2022-04-13T22:46:30.424Z,1649889990.424 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-04-13T22:46:30.676Z,1649889990.676 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-04-13T22:46:33.957Z,1649889993.957 [DAT](INFO): DAT read: Forwarding Delay UpTx time:22:46:33.3640 2022-04-13T22:46:33.957Z,1649889993.957 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-04-13T22:46:37.853Z,1649889997.853 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2 2022-04-13T22:46:37.853Z,1649889997.853 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2022-04-13T22:46:37.863Z,1649889997.863 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2022-04-13T22:46:38.285Z,1649889998.285 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2022-04-13T22:46:38.286Z,1649889998.286 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2 2022-04-13T22:46:40.355Z,1649890000.355 [CBIT](FAULT): Could not open coulomb counter log file 2022-04-13T22:46:44.044Z,1649890004.044 [DAT](FAULT): Ack receipt timeout failure. 2022-04-13T22:46:44.044Z,1649890004.044 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2022-04-13T22:46:44.305Z,1649890004.305 [DAT](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER 2022-04-13T22:46:50.412Z,1649890010.412 [CBIT](FAULT): Could not open coulomb counter log file 2022-04-13T22:47:00.480Z,1649890020.480 [CBIT](FAULT): Could not open coulomb counter log file 2022-04-13T22:47:10.634Z,1649890030.634 [CBIT](FAULT): Could not open coulomb counter log file 2022-04-13T22:47:20.731Z,1649890040.731 [CBIT](FAULT): Could not open coulomb counter log file 2022-04-13T22:47:30.859Z,1649890050.859 [CBIT](FAULT): Could not open coulomb counter log file 2022-04-13T22:47:40.929Z,1649890060.929 [CBIT](FAULT): Could not open coulomb counter log file 2022-04-13T22:47:50.999Z,1649890070.999 [CBIT](FAULT): Could not open coulomb counter log file 2022-04-13T22:47:59.102Z,1649890079.102 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2022-04-13T22:48:01.097Z,1649890081.097 [CBIT](FAULT): Could not open coulomb counter log file 2022-04-13T22:48:05.526Z,1649890085.526 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2022-04-13T22:48:05.533Z,1649890085.533 [BPC1](INFO): Received data from all battery sticks. 2022-04-13T22:48:11.189Z,1649890091.189 [CBIT](FAULT): Could not open coulomb counter log file 2022-04-13T22:48:21.310Z,1649890101.310 [CBIT](FAULT): Could not open coulomb counter log file