2024-04-11T17:13:38.144Z,1712855618.144 [Supervisor](DEBUG): Initializing supervisor. 2024-04-11T17:13:38.148Z,1712855618.148 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2024-04-11T17:13:38.149Z,1712855618.149 [SyncHandler](INFO): Protected caller Thread ID is 5115 2024-04-11T17:13:38.149Z,1712855618.149 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2024-04-11T17:13:38.150Z,1712855618.150 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2024-04-11T17:13:38.151Z,1712855618.151 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 5116 2024-04-11T17:13:38.154Z,1712855618.154 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2024-04-11T17:13:38.172Z,1712855618.172 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread. 2024-04-11T17:13:38.173Z,1712855618.173 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2024-04-11T17:13:38.173Z,1712855618.173 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 5117 2024-04-11T17:13:38.178Z,1712855618.178 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2024-04-11T17:13:38.178Z,1712855618.178 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2024-04-11T17:13:38.179Z,1712855618.179 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 5118 2024-04-11T17:13:38.181Z,1712855618.181 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2024-04-11T17:13:38.182Z,1712855618.182 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0 2024-04-11T17:13:38.182Z,1712855618.182 [logger ThreadHandler](INFO): Protected caller Thread ID is 5119 2024-04-11T17:13:38.186Z,1712855618.186 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2024-04-11T17:13:38.186Z,1712855618.186 [Supervisor](INFO): Looking for Config files in directory: Config/ 2024-04-11T17:13:38.188Z,1712855618.188 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2024-04-11T17:13:38.467Z,1712855618.467 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2024-04-11T17:13:38.467Z,1712855618.467 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2024-04-11T17:13:38.561Z,1712855618.561 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2024-04-11T17:13:39.112Z,1712855619.112 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2024-04-11T17:13:39.113Z,1712855619.113 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2024-04-11T17:13:39.475Z,1712855619.475 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2024-04-11T17:13:39.475Z,1712855619.475 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2024-04-11T17:13:39.584Z,1712855619.584 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2024-04-11T17:13:39.585Z,1712855619.585 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2024-04-11T17:13:40.008Z,1712855620.008 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2024-04-11T17:13:40.008Z,1712855620.008 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2024-04-11T17:13:40.237Z,1712855620.237 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2024-04-11T17:13:40.237Z,1712855620.237 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2024-04-11T17:13:40.772Z,1712855620.772 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2024-04-11T17:13:40.772Z,1712855620.772 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2024-04-11T17:13:40.925Z,1712855620.925 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2024-04-11T17:13:40.925Z,1712855620.925 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2024-04-11T17:13:41.017Z,1712855621.017 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2024-04-11T17:13:41.864Z,1712855621.864 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2024-04-11T17:13:41.865Z,1712855621.865 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2024-04-11T17:13:42.278Z,1712855622.278 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2024-04-11T17:13:42.278Z,1712855622.278 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2024-04-11T17:13:42.486Z,1712855622.486 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2024-04-11T17:13:42.487Z,1712855622.487 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2024-04-11T17:13:42.611Z,1712855622.611 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2024-04-11T17:13:42.612Z,1712855622.612 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2024-04-11T17:13:42.869Z,1712855622.869 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2024-04-11T17:13:42.870Z,1712855622.870 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg 2024-04-11T17:13:43.615Z,1712855623.615 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock 2024-04-11T17:13:43.617Z,1712855623.617 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/ 2024-04-11T17:13:43.618Z,1712855623.618 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg 2024-04-11T17:13:43.865Z,1712855623.865 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg 2024-04-11T17:13:44.009Z,1712855624.009 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg 2024-04-11T17:13:44.127Z,1712855624.127 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg 2024-04-11T17:13:44.223Z,1712855624.223 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg 2024-04-11T17:13:44.338Z,1712855624.338 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg 2024-04-11T17:13:44.444Z,1712855624.444 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg 2024-04-11T17:13:44.570Z,1712855624.570 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg 2024-04-11T17:13:44.731Z,1712855624.731 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg 2024-04-11T17:13:44.884Z,1712855624.884 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg 2024-04-11T17:13:45.007Z,1712855625.007 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg 2024-04-11T17:13:45.281Z,1712855625.281 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2024-04-11T17:13:45.283Z,1712855625.283 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/root/ 2024-04-11T17:13:45.283Z,1712855625.283 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2024-04-11T17:13:45.288Z,1712855625.288 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2024-04-11T17:13:45.341Z,1712855625.341 [VerticalControl](DEBUG): Construct VerticalControl. 2024-04-11T17:13:45.401Z,1712855625.401 [VerticalControl] Loaded 2024-04-11T17:13:45.401Z,1712855625.401 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2024-04-11T17:13:45.404Z,1712855625.404 [HorizontalControl](DEBUG): Construct HorizontalControl. 2024-04-11T17:13:45.446Z,1712855625.446 [HorizontalControl] Loaded 2024-04-11T17:13:45.446Z,1712855625.446 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2024-04-11T17:13:45.448Z,1712855625.448 [SpeedControl](DEBUG): Construct SpeedControl. 2024-04-11T17:13:45.451Z,1712855625.451 [SpeedControl] Loaded 2024-04-11T17:13:45.451Z,1712855625.451 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2024-04-11T17:13:45.454Z,1712855625.454 [LoopControl](DEBUG): Construct LoopControl. 2024-04-11T17:13:45.455Z,1712855625.455 [LoopControl] Loaded 2024-04-11T17:13:45.455Z,1712855625.455 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2024-04-11T17:13:45.455Z,1712855625.455 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2024-04-11T17:13:45.456Z,1712855625.456 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2024-04-11T17:13:45.466Z,1712855625.466 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2024-04-11T17:13:45.466Z,1712855625.466 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2024-04-11T17:13:45.637Z,1712855625.637 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2024-04-11T17:13:45.638Z,1712855625.638 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2024-04-11T17:13:45.768Z,1712855625.768 [BuoyancyServo] Loaded 2024-04-11T17:13:45.769Z,1712855625.769 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2024-04-11T17:13:45.788Z,1712855625.788 [ElevatorServo] Loaded 2024-04-11T17:13:45.788Z,1712855625.788 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2024-04-11T17:13:45.807Z,1712855625.807 [MassServo] Loaded 2024-04-11T17:13:45.808Z,1712855625.808 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2024-04-11T17:13:45.825Z,1712855625.825 [RudderServo] Loaded 2024-04-11T17:13:45.826Z,1712855625.826 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2024-04-11T17:13:45.840Z,1712855625.840 [ThrusterHE] Loaded 2024-04-11T17:13:45.840Z,1712855625.840 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread. 2024-04-11T17:13:45.841Z,1712855625.841 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2024-04-11T17:13:45.841Z,1712855625.841 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2024-04-11T17:13:45.953Z,1712855625.953 [DeadReckonUsingMultipleVelocitySources] Loaded 2024-04-11T17:13:45.953Z,1712855625.953 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2024-04-11T17:13:45.967Z,1712855625.967 [NavChart] Loaded 2024-04-11T17:13:45.967Z,1712855625.967 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2024-04-11T17:13:45.973Z,1712855625.973 [UniversalFixResidualReporter] Loaded 2024-04-11T17:13:45.973Z,1712855625.973 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2024-04-11T17:13:45.974Z,1712855625.974 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2024-04-11T17:13:45.974Z,1712855625.974 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2024-04-11T17:13:46.029Z,1712855626.029 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2024-04-11T17:13:46.030Z,1712855626.030 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2024-04-11T17:13:46.457Z,1712855626.457 [AHRS_M2] Loaded 2024-04-11T17:13:46.457Z,1712855626.457 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2024-04-11T17:13:47.264Z,1712855627.264 [BPC1] Loaded 2024-04-11T17:13:47.264Z,1712855627.264 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2024-04-11T17:13:47.340Z,1712855627.340 [DataOverHttps] Loaded 2024-04-11T17:13:47.340Z,1712855627.340 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2024-04-11T17:13:47.341Z,1712855627.341 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 409304E0 2024-04-11T17:13:47.342Z,1712855627.342 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 5202 2024-04-11T17:13:47.362Z,1712855627.362 [Depth_Keller] Loaded 2024-04-11T17:13:47.362Z,1712855627.362 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2024-04-11T17:13:47.367Z,1712855627.367 [DropWeight] Loaded 2024-04-11T17:13:47.368Z,1712855627.368 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2024-04-11T17:13:47.429Z,1712855627.429 [NAL9602] Loaded 2024-04-11T17:13:47.430Z,1712855627.430 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2024-04-11T17:13:47.459Z,1712855627.459 [Onboard] Loaded 2024-04-11T17:13:47.459Z,1712855627.459 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread. 2024-04-11T17:13:47.460Z,1712855627.460 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 409604E0 2024-04-11T17:13:47.460Z,1712855627.460 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 5203 2024-04-11T17:13:47.474Z,1712855627.474 [Power24vConverter] Loaded 2024-04-11T17:13:47.474Z,1712855627.474 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread. 2024-04-11T17:13:47.487Z,1712855627.487 [Radio_Surface] Loaded 2024-04-11T17:13:47.487Z,1712855627.487 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2024-04-11T17:13:47.488Z,1712855627.488 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409904E0 2024-04-11T17:13:47.488Z,1712855627.488 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 5204 2024-04-11T17:13:47.502Z,1712855627.502 [Sonardyne_Nano] Loaded 2024-04-11T17:13:47.502Z,1712855627.502 [ComponentRegistry](DEBUG): SyncComponent "Sonardyne_Nano" handled in the control thread. 2024-04-11T17:13:47.594Z,1712855627.594 [DAT] Loaded 2024-04-11T17:13:47.594Z,1712855627.594 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread. 2024-04-11T17:13:47.595Z,1712855627.595 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 409C04E0 2024-04-11T17:13:47.596Z,1712855627.596 [DAT ThreadHandler](INFO): Protected caller Thread ID is 5205 2024-04-11T17:13:47.596Z,1712855627.596 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2024-04-11T17:13:47.597Z,1712855627.597 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2024-04-11T17:13:47.647Z,1712855627.647 [DepthRateCalculator] Loaded 2024-04-11T17:13:47.647Z,1712855627.647 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2024-04-11T17:13:47.652Z,1712855627.652 [PitchRateCalculator] Loaded 2024-04-11T17:13:47.652Z,1712855627.652 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2024-04-11T17:13:47.661Z,1712855627.661 [SpeedCalculator] Loaded 2024-04-11T17:13:47.661Z,1712855627.661 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2024-04-11T17:13:47.665Z,1712855627.665 [YawRateCalculator] Loaded 2024-04-11T17:13:47.666Z,1712855627.666 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2024-04-11T17:13:47.684Z,1712855627.684 [ElevatorOffsetCalculator] Loaded 2024-04-11T17:13:47.685Z,1712855627.685 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2024-04-11T17:13:47.685Z,1712855627.685 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2024-04-11T17:13:47.686Z,1712855627.686 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2024-04-11T17:13:47.819Z,1712855627.819 [CANONSampler] Loaded 2024-04-11T17:13:47.819Z,1712855627.819 [ComponentRegistry](DEBUG): SyncComponent "CANONSampler" handled in the control thread. 2024-04-11T17:13:47.879Z,1712855627.879 [CTD_Seabird] Loaded 2024-04-11T17:13:47.880Z,1712855627.880 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2024-04-11T17:13:47.881Z,1712855627.881 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40A7C4E0 2024-04-11T17:13:47.881Z,1712855627.881 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 5206 2024-04-11T17:13:47.901Z,1712855627.901 [PAR_Licor] Loaded 2024-04-11T17:13:47.901Z,1712855627.901 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2024-04-11T17:13:47.945Z,1712855627.945 [WetLabsBB2FL] Loaded 2024-04-11T17:13:47.945Z,1712855627.945 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2024-04-11T17:13:47.946Z,1712855627.946 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40AAC4E0 2024-04-11T17:13:47.947Z,1712855627.947 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 5207 2024-04-11T17:13:47.947Z,1712855627.947 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2024-04-11T17:13:47.948Z,1712855627.948 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2024-04-11T17:13:48.070Z,1712855628.070 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2024-04-11T17:13:48.071Z,1712855628.071 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2024-04-11T17:13:48.600Z,1712855628.600 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2024-04-11T17:13:48.600Z,1712855628.600 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2024-04-11T17:13:48.745Z,1712855628.745 [SBIT](DEBUG): Construct Startup Built In Test. 2024-04-11T17:13:48.754Z,1712855628.754 [SBIT] Loaded 2024-04-11T17:13:48.754Z,1712855628.754 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2024-04-11T17:13:48.757Z,1712855628.757 [IBIT](DEBUG): Construct Initiated Built In Test. 2024-04-11T17:13:48.770Z,1712855628.770 [IBIT] Loaded 2024-04-11T17:13:48.770Z,1712855628.770 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2024-04-11T17:13:48.776Z,1712855628.776 [CBIT](DEBUG): Construct Continuous Built In Test. 2024-04-11T17:13:48.881Z,1712855628.881 [CBIT] Loaded 2024-04-11T17:13:48.881Z,1712855628.881 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2024-04-11T17:13:48.881Z,1712855628.881 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2024-04-11T17:13:48.882Z,1712855628.882 [Module Loader](DEBUG): Loading Module at Modules/Dock.so 2024-04-11T17:13:48.996Z,1712855628.996 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking) 2024-04-11T17:13:49.003Z,1712855629.003 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2024-04-11T17:13:49.006Z,1712855629.006 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2024-04-11T17:13:49.017Z,1712855629.017 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2024-04-11T17:13:49.018Z,1712855629.018 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C054E0 2024-04-11T17:13:49.018Z,1712855629.018 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 5208 2024-04-11T17:13:49.023Z,1712855629.023 [Supervisor](INFO): Main Thread ID is 5114 2024-04-11T17:13:49.023Z,1712855629.023 [Supervisor](DEBUG): Running supervisor. 2024-04-11T17:13:49.023Z,1712855629.023 [CommandExec ThreadHandler](INFO): Handler Thread ID is 5209 2024-04-11T17:13:49.024Z,1712855629.024 [CommandExec](INFO): Initializing the command executive. 2024-04-11T17:13:49.026Z,1712855629.026 [CommandLine ThreadHandler](INFO): Handler Thread ID is 5210 2024-04-11T17:13:49.029Z,1712855629.029 [controlThread ThreadHandler](INFO): Handler Thread ID is 5211 2024-04-11T17:13:49.030Z,1712855629.030 [controlThread](DEBUG): Initializing ControlThread 2024-04-11T17:13:49.030Z,1712855629.030 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2024-04-11T17:13:49.032Z,1712855629.032 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2024-04-11T17:13:49.033Z,1712855629.033 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2024-04-11T17:13:49.033Z,1712855629.033 [LoopControl](DEBUG): Initialize LoopControlComponent. 2024-04-11T17:13:49.035Z,1712855629.035 [NavChart](DEBUG): Initialize NavChart Navigation. 2024-04-11T17:13:49.036Z,1712855629.036 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2024-04-11T17:13:49.041Z,1712855629.041 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2024-04-11T17:13:49.041Z,1712855629.041 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2024-04-11T17:13:49.042Z,1712855629.042 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2024-04-11T17:13:49.042Z,1712855629.042 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2024-04-11T17:13:49.042Z,1712855629.042 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2024-04-11T17:13:49.048Z,1712855629.048 [SBIT](INFO): Initialize SBIT Component. 2024-04-11T17:13:49.048Z,1712855629.048 [SBIT](IMPORTANT): git: 2024-03-26-44-g1514cc2c4 2024-04-11T17:13:49.048Z,1712855629.048 [SBIT](INFO): git hash: 1514cc2c4a99aff7d2a01b01e5397a9c6de228ef 2024-04-11T17:13:49.048Z,1712855629.048 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2024-04-11T17:13:49.049Z,1712855629.049 [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 2024-04-11T17:13:49.051Z,1712855629.051 [SBIT](INFO): Beginning SBIT in 49.000000 seconds. 2024-04-11T17:13:49.051Z,1712855629.051 [IBIT](INFO): Initialize IBIT Component. 2024-04-11T17:13:49.052Z,1712855629.052 [CBIT](DEBUG): Initialize CBIT Component. 2024-04-11T17:13:49.053Z,1712855629.053 [logger ThreadHandler](INFO): Handler Thread ID is 5212 2024-04-11T17:13:49.063Z,1712855629.063 [CBIT](DEBUG): Initialized mux pins. 2024-04-11T17:13:49.063Z,1712855629.063 [CBIT](DEBUG): Initializing the watchdog timer. 2024-04-11T17:13:49.072Z,1712855629.072 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 5213 2024-04-11T17:13:49.073Z,1712855629.073 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2024-04-11T17:13:49.084Z,1712855629.084 [Onboard ThreadHandler](INFO): Handler Thread ID is 5214 2024-04-11T17:13:49.088Z,1712855629.088 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2024-04-11T17:13:49.088Z,1712855629.088 [CBIT](DEBUG): Initializing heartbeat. 2024-04-11T17:13:49.104Z,1712855629.104 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 5215 2024-04-11T17:13:49.120Z,1712855629.120 [DAT ThreadHandler](INFO): Handler Thread ID is 5216 2024-04-11T17:13:49.120Z,1712855629.120 [DAT](INFO): Powering up 2024-04-11T17:13:49.121Z,1712855629.121 [DAT](DEBUG): Initializing DAT. 2024-04-11T17:13:49.125Z,1712855629.125 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 5218 2024-04-11T17:13:49.125Z,1712855629.125 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2024-04-11T17:13:49.129Z,1712855629.129 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 5220 2024-04-11T17:13:49.132Z,1712855629.132 [WetLabsBB2FL](INFO): Powering up 2024-04-11T17:13:49.133Z,1712855629.133 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 5222 2024-04-11T17:13:49.136Z,1712855629.136 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2024-04-11T17:13:49.137Z,1712855629.137 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2024-04-11T17:13:49.137Z,1712855629.137 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2024-04-11T17:13:49.137Z,1712855629.137 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2024-04-11T17:13:49.137Z,1712855629.137 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2024-04-11T17:13:49.137Z,1712855629.137 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2024-04-11T17:13:49.137Z,1712855629.137 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2024-04-11T17:13:49.138Z,1712855629.138 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2024-04-11T17:13:49.159Z,1712855629.159 [CBIT](DEBUG): Deactivating GF circuits. 2024-04-11T17:13:49.159Z,1712855629.159 [CBIT](DEBUG): Deactivating emergency mode. 2024-04-11T17:13:49.199Z,1712855629.199 [CBIT](DEBUG): Backplane powered. 2024-04-11T17:13:49.200Z,1712855629.200 [MissionManager](IMPORTANT): Using TethysL tl-to-tx parser 2024-04-11T17:13:49.201Z,1712855629.201 [MissionManager](INFO): Loading Mission from file: Missions/Startup.tl 2024-04-11T17:13:49.201Z,1712855629.201 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Startup.tl 2024-04-11T17:13:49.202Z,1712855629.202 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Startup.tl 2024-04-11T17:13:49.243Z,1712855629.243 [MissionManager](DEBUG): TethyslAPI: Missions/Startup.tl translated into: 2024-04-11T17:13:49.267Z,1712855629.267 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2024-04-11T17:13:49.295Z,1712855629.295 [MissionManager](DEBUG): # Copyright (c) 2024 MBARI # MBARI Proprietary Information. Confidential. All Rights Reserved # Unauthorized copying or distribution of this file via any medium is strictly # prohibited. # # WARNING - This file contains information whose export is restricted by the # Export Administration Act of 1979 (Title 50, U.S.C., App. 2401 et seq.), as # amended. Violations of these export laws are subject to severe civil and/or # criminal penalties. mission Startup { behavior Guidance:GoToSurface { run in progression } aggregate StartupSatComms { run in sequence readDatum { timeout duration=P1M Universal:latitude_fix } readDatum { timeout duration=P1M Universal:platform_communications } } } 2024-04-11T17:13:49.296Z,1712855629.296 [MissionManager](INFO): Loading Mission from file: Missions/Default.tl 2024-04-11T17:13:49.296Z,1712855629.296 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Default.tl 2024-04-11T17:13:49.297Z,1712855629.297 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Default.tl 2024-04-11T17:13:49.507Z,1712855629.507 [Radio_Surface](INFO): Powering up 2024-04-11T17:13:49.620Z,1712855629.620 [MissionManager](DEBUG): TethyslAPI: Missions/Default.tl translated into: 0 13 Burn on Dropped weight due to communications timeout. 5 Default mission has been running for Restarting logs and Default mission. restart logs 2024-04-11T17:13:49.635Z,1712855629.635 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2024-04-11T17:13:49.644Z,1712855629.644 [Default:A.Wait](DEBUG): Construct Wait. 2024-04-11T17:13:49.646Z,1712855629.646 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2024-04-11T17:13:49.703Z,1712855629.703 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2024-04-11T17:13:49.706Z,1712855629.706 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2024-04-11T17:13:49.728Z,1712855629.728 [Default:E.Execute](DEBUG): Construct Execute. 2024-04-11T17:13:49.731Z,1712855629.731 [MissionManager](DEBUG): # Copyright (c) 2024 MBARI # MBARI Proprietary Information. Confidential. All Rights Reserved # Unauthorized copying or distribution of this file via any medium is strictly # prohibited. # # WARNING - This file contains information whose export is restricted by the # Export Administration Act of 1979 (Title 50, U.S.C., App. 2401 et seq.), as # amended. Violations of these export laws are subject to severe civil and/or # criminal penalties. mission Default { arguments { ElapsedSinceDefaultStarted = 0 minute } behavior Guidance:Wait { """ Wait a moment to see if the scheduler starts a new mission before starting to actually run Default. """ run in sequence set duration = 13 second } behavior Guidance:GoToSurface { run in progression } aggregate CheckIn { run in sequence repeat=288 readDatum id="Read_GPS" { timeout duration=P5M Universal:time_fix } readDatum id="Read_Iridium" { timeout duration=P4H { behavior Guidance:Execute { run in sequence set command = "Burn on" } syslog critical "Dropped weight due to communications timeout." } Universal:platform_communications } behavior Guidance:Wait { run in sequence set duration = 5 minute } assign in sequence ElapsedSinceDefaultStarted = elapsed ( Universal:mission_started ) syslog important "Default mission has been running for " + ElapsedSinceDefaultStarted~minute } syslog important "Restarting logs and Default mission." behavior Guidance:Execute { run in sequence set command = "restart logs" } } 2024-04-11T17:13:49.739Z,1712855629.739 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,Sonardyne_Nano,CANONSampler,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2024-04-11T17:13:49.752Z,1712855629.752 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2024-04-11T17:13:49.820Z,1712855629.820 [Depth_Keller](ERROR): Pressure or depth reading out of range: 1831.023193 decibar, 0.000000 m 2024-04-11T17:13:49.821Z,1712855629.821 [Power24vConverter](INFO): Powering up. 2024-04-11T17:13:49.822Z,1712855629.822 [Sonardyne_Nano](INFO): Initializing. 2024-04-11T17:13:49.836Z,1712855629.836 [CANONSampler](INFO): Powering down 2024-04-11T17:13:49.883Z,1712855629.883 [DepthRateCalculator](ERROR): Depth measurement is not active 2024-04-11T17:13:49.909Z,1712855629.909 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2024-04-11T17:13:49.915Z,1712855629.915 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2024-04-11T17:13:49.917Z,1712855629.917 [ElevatorServo](DEBUG): Initializing EZServoServo. 2024-04-11T17:13:49.923Z,1712855629.923 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2024-04-11T17:13:49.924Z,1712855629.924 [MassServo](DEBUG): Initializing EZServoServo. 2024-04-11T17:13:49.931Z,1712855629.931 [MassServo](DEBUG): Initializing MassServo. 2024-04-11T17:13:49.932Z,1712855629.932 [RudderServo](DEBUG): Initializing EZServoServo. 2024-04-11T17:13:49.939Z,1712855629.939 [RudderServo](DEBUG): Initializing RudderServo. 2024-04-11T17:13:49.940Z,1712855629.940 [ThrusterHE](DEBUG): Initializing EZServoServo. 2024-04-11T17:13:49.947Z,1712855629.947 [ThrusterHE](DEBUG): Initializing ThrusterHE. 2024-04-11T17:13:51.239Z,1712855631.239 [WetLabsBB2FL](INFO): Powering down 2024-04-11T17:13:51.770Z,1712855631.770 [Sonardyne_Nano](ERROR): Failed to get valid response or reached max queue size, flushing UART 2024-04-11T17:13:53.416Z,1712855633.416 [Sonardyne_Nano](IMPORTANT): Found beacon with acoustic ID 2109 2024-04-11T17:13:55.664Z,1712855635.664 [ThrusterHE](ERROR): Zero Speed Commanded. 2024-04-11T17:14:01.720Z,1712855641.720 [DAT](INFO): DAT read: 2024-04-11T17:14:01.721Z,1712855641.721 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series 2024-04-11T17:14:01.966Z,1712855641.966 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.005214 2024-04-11T17:14:03.484Z,1712855643.484 [DAT](INFO): DAT read: MF Frequency Band 2024-04-11T17:14:03.485Z,1712855643.485 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0 2024-04-11T17:14:03.486Z,1712855643.486 [DAT](INFO): DAT read: Apr 11 2024 00:49:43 2024-04-11T17:14:04.745Z,1712855644.745 [DAT](INFO): DAT read: Features enabled [Bearing] 2024-04-11T17:14:04.746Z,1712855644.746 [DAT](INFO): DAT read: CONNECT 01200 bits/sec 1 of 4, Rate 1/2 CC 2024-04-11T17:14:04.746Z,1712855644.746 [DAT](INFO): commRate: 1200 2024-04-11T17:14:06.811Z,1712855646.811 [DAT](INFO): entering command mode 2024-04-11T17:14:07.012Z,1712855647.012 [DAT](INFO): DAT read: 2024-04-11T17:14:07.012Z,1712855647.012 [DAT](INFO): DAT read: user:1> 2024-04-11T17:14:07.013Z,1712855647.013 [DAT](INFO): setting verbose to 3 2024-04-11T17:14:07.264Z,1712855647.264 [DAT](INFO): DAT read: user:1> 2024-04-11T17:14:07.265Z,1712855647.265 [DAT](INFO): DAT read: Verbose | 3 2024-04-11T17:14:07.265Z,1712855647.265 [DAT](INFO): set verbose to 3 2024-04-11T17:14:07.266Z,1712855647.266 [DAT](INFO): setting DatVerbose to 27440 2024-04-11T17:14:07.516Z,1712855647.516 [DAT](INFO): DAT read: user:2> 2024-04-11T17:14:07.517Z,1712855647.517 [DAT](INFO): DAT read: DatVerbose | 27440 2024-04-11T17:14:07.517Z,1712855647.517 [DAT](INFO): set DatVerbose to 27440 2024-04-11T17:14:07.517Z,1712855647.517 [DAT](INFO): setting transmit power to 8 2024-04-11T17:14:07.768Z,1712855647.768 [DAT](INFO): DAT read: user:3> 2024-04-11T17:14:07.769Z,1712855647.769 [DAT](INFO): DAT read: TxPower | 8 (Max) 2024-04-11T17:14:07.769Z,1712855647.769 [DAT](INFO): set transmit power to 8 2024-04-11T17:14:07.770Z,1712855647.770 [DAT](INFO): setting local address to 8 2024-04-11T17:14:08.020Z,1712855648.020 [DAT](INFO): DAT read: user:4> 2024-04-11T17:14:08.021Z,1712855648.021 [DAT](INFO): DAT read: LocalAddr | 8 2024-04-11T17:14:08.021Z,1712855648.021 [DAT](INFO): set local address to 8 2024-04-11T17:14:08.022Z,1712855648.022 [DAT](INFO): Setting time to: 17:14:8 And date to:4/11/2024 2024-04-11T17:14:08.274Z,1712855648.274 [DAT](INFO): DAT read: user:5> 2024-04-11T17:14:08.276Z,1712855648.276 [DAT](INFO): DAT read: Thu Apr 11, 2024 17:14:08 2024-04-11T17:14:08.276Z,1712855648.276 [DAT](INFO): Local DAT time set to Thu Apr 11, 2024 17:14:08 2024-04-11T17:14:17.629Z,1712855657.629 [NAL9602](INFO): Powering up NAL9602 2024-04-11T17:14:28.549Z,1712855668.549 [NAL9602](INFO): NAL9602 initialized 2024-04-11T17:14:38.666Z,1712855678.666 [SBIT](IMPORTANT): Beginning Startup BIT 2024-04-11T17:14:38.675Z,1712855678.675 [CBIT](IMPORTANT): Beginning ground fault scan 2024-04-11T17:14:49.974Z,1712855689.974 [CBIT](ERROR): Ground fault scan returned out of bounds value. Re-running scan. 2024-04-11T17:14:50.400Z,1712855690.400 [CBIT](IMPORTANT): Beginning ground fault scan 2024-04-11T17:14:58.026Z,1712855698.026 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-04-11T17:15:01.721Z,1712855701.721 [CBIT](ERROR): Ground fault scan returned out of bounds value. Re-running scan. 2024-04-11T17:15:02.121Z,1712855702.121 [CBIT](IMPORTANT): Beginning ground fault scan 2024-04-11T17:15:13.042Z,1712855713.042 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.002042 CHAN A1 (24V): 0.000718 CHAN A2 (12V): -0.002345 CHAN A3 (5V): -0.001448 CHAN B0 (3.3V): 0.000235 CHAN B1 (3.15aV): 0.000075 CHAN B2 (3.15bV): 0.000239 CHAN B3 (GND): 0.000017 OPEN: -0.000370 Full Scale: +/- 1 mA 2024-04-11T17:15:14.993Z,1712855714.993 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-04-11T17:15:32.841Z,1712855732.841 [SBIT](IMPORTANT): SBIT PASSED 2024-04-11T17:15:32.841Z,1712855732.841 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2024-04-11T17:15:32.842Z,1712855732.842 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=20 count; 2024-04-11T17:15:32.842Z,1712855732.842 [SBIT](IMPORTANT): Vehicle.useTlLoader=1 bool; 2024-04-11T17:15:32.842Z,1712855732.842 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=186 cubic_centimeter; 2024-04-11T17:15:32.842Z,1712855732.842 [SBIT](IMPORTANT): VerticalControl.massDefault=7.5 millimeter; 2024-04-11T17:15:33.213Z,1712855733.213 [MissionManager](IMPORTANT): Started mission Startup 2024-04-11T17:15:33.214Z,1712855733.214 [Startup] Running Loop=1 2024-04-11T17:15:33.214Z,1712855733.214 [Startup](DEBUG): Aggregate::initialize Startup 2024-04-11T17:15:33.214Z,1712855733.214 [Startup:A.GoToSurface] Running Loop=1 2024-04-11T17:15:33.214Z,1712855733.214 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2024-04-11T17:15:33.214Z,1712855733.214 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2024-04-11T17:15:33.219Z,1712855733.219 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2024-04-11T17:15:33.219Z,1712855733.219 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2024-04-11T17:15:33.220Z,1712855733.220 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2024-04-11T17:15:33.220Z,1712855733.220 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2024-04-11T17:15:33.222Z,1712855733.222 [Startup:StartupSatComms] Running Loop=1 2024-04-11T17:15:33.222Z,1712855733.222 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2024-04-11T17:15:33.222Z,1712855733.222 [Startup:StartupSatComms:A] Running Loop=1 2024-04-11T17:15:33.630Z,1712855733.630 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2024-04-11T17:16:33.395Z,1712855793.395 [Startup:StartupSatComms:A](INFO): Timed out from 2024-04-11T17:15:33.2Z 2024-04-11T17:16:33.396Z,1712855793.396 [Startup:StartupSatComms:A] Stopped 2024-04-11T17:16:33.396Z,1712855793.396 [Startup:StartupSatComms:B] Running Loop=1 2024-04-11T17:16:33.790Z,1712855793.790 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2024-04-11T17:16:35.443Z,1712855795.443 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2024-04-11T17:16:40.707Z,1712855800.707 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20240411T003326/Courier0007.lzma 2024-04-11T17:16:41.709Z,1712855801.709 [DataOverHttps](INFO): Moved sent file to Logs/20240411T003326/Courier0007.lzma.bak 2024-04-11T17:16:41.709Z,1712855801.709 [DataOverHttps](INFO): SBD MOMSN=19399743 2024-04-11T17:16:49.176Z,1712855809.176 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2024-04-11T17:16:49.176Z,1712855809.176 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2024-04-11T17:16:49.186Z,1712855809.186 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2024-04-11T17:16:49.557Z,1712855809.557 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2024-04-11T17:16:49.557Z,1712855809.557 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2024-04-11T17:16:57.271Z,1712855817.271 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20240411T171338/Courier0000.lzma 2024-04-11T17:16:58.273Z,1712855818.273 [DataOverHttps](INFO): Moved sent file to Logs/20240411T171338/Courier0000.lzma.bak 2024-04-11T17:16:58.273Z,1712855818.273 [DataOverHttps](INFO): SBD MOMSN=19399745 2024-04-11T17:17:09.841Z,1712855829.841 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2024-04-11T17:17:14.155Z,1712855834.155 [DataOverHttps](INFO): Sending 142 bytes from file Logs/20240411T003326/Express0008.lzma 2024-04-11T17:17:15.157Z,1712855835.157 [DataOverHttps](INFO): Moved sent file to Logs/20240411T003326/Express0008.lzma.bak 2024-04-11T17:17:15.157Z,1712855835.157 [DataOverHttps](INFO): SBD MOMSN=19399750 2024-04-11T17:17:30.784Z,1712855850.784 [DataOverHttps](INFO): Sending 788 bytes from file Logs/20240411T171338/Express0001.lzma 2024-04-11T17:17:31.785Z,1712855851.785 [DataOverHttps](INFO): Moved sent file to Logs/20240411T171338/Express0001.lzma.bak 2024-04-11T17:17:31.785Z,1712855851.785 [DataOverHttps](INFO): SBD MOMSN=19399757 2024-04-11T17:17:33.180Z,1712855853.180 [Startup:StartupSatComms:B] Stopped 2024-04-11T17:17:33.181Z,1712855853.181 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2024-04-11T17:17:33.181Z,1712855853.181 [Startup:StartupSatComms] Stopped 2024-04-11T17:17:33.181Z,1712855853.181 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2024-04-11T17:17:33.182Z,1712855853.182 [Startup](INFO): Completed Startup 2024-04-11T17:17:33.182Z,1712855853.182 [MissionManager](INFO): Startup is completed. 2024-04-11T17:17:33.182Z,1712855853.182 [MissionManager](INFO): Uninitializing Mission Startup 2024-04-11T17:17:33.182Z,1712855853.182 [Startup] Stopped 2024-04-11T17:17:33.182Z,1712855853.182 [Startup](DEBUG): Aggregate::uninitialize Startup 2024-04-11T17:17:33.182Z,1712855853.182 [Startup:A.GoToSurface] Stopped 2024-04-11T17:17:33.182Z,1712855853.182 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2024-04-11T17:17:33.586Z,1712855853.586 [MissionManager](IMPORTANT): Started mission Default 2024-04-11T17:17:33.586Z,1712855853.586 [Default] Running Loop=1 2024-04-11T17:17:33.586Z,1712855853.586 [Default](DEBUG): Aggregate::initialize Default 2024-04-11T17:17:33.586Z,1712855853.586 [Default:B.GoToSurface] Running Loop=1 2024-04-11T17:17:33.586Z,1712855853.586 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2024-04-11T17:17:33.587Z,1712855853.587 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2024-04-11T17:17:33.587Z,1712855853.587 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2024-04-11T17:17:33.588Z,1712855853.588 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2024-04-11T17:17:33.588Z,1712855853.588 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2024-04-11T17:17:33.588Z,1712855853.588 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2024-04-11T17:17:33.588Z,1712855853.588 [Default:A.Wait] Running Loop=1 2024-04-11T17:17:33.589Z,1712855853.589 [Default:A.Wait](DEBUG): Initialize Wait Component. 2024-04-11T17:17:46.924Z,1712855866.924 [Default:A.Wait](INFO): Done Waiting. 2024-04-11T17:17:46.924Z,1712855866.924 [Default:A.Wait] Stopped 2024-04-11T17:17:46.924Z,1712855866.924 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2024-04-11T17:17:47.314Z,1712855867.314 [Default:CheckIn] Running Loop=1 2024-04-11T17:17:47.314Z,1712855867.314 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-04-11T17:17:47.314Z,1712855867.314 [Default:CheckIn:Read_GPS] Running Loop=1 2024-04-11T17:17:47.721Z,1712855867.721 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2024-04-11T17:19:04.474Z,1712855944.474 [BPC1](INFO): Calculating totals. Valid battery stick count: 38. Valid reserve battery stick count: 5. 2024-04-11T17:19:04.477Z,1712855944.477 [BPC1](INFO): Received data from all battery sticks. 2024-04-11T17:19:31.949Z,1712855971.949 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2024-04-11T17:19:50.152Z,1712855990.152 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2 2024-04-11T17:19:50.152Z,1712855990.152 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2024-04-11T17:19:50.163Z,1712855990.163 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2024-04-11T17:19:50.559Z,1712855990.559 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2024-04-11T17:19:50.559Z,1712855990.559 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2 2024-04-11T17:22:47.500Z,1712856167.500 [Default:CheckIn:Read_GPS](INFO): Timed out from 2024-04-11T17:17:47.3Z 2024-04-11T17:22:47.500Z,1712856167.500 [Default:CheckIn:Read_GPS] Stopped 2024-04-11T17:22:47.500Z,1712856167.500 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-04-11T17:22:47.893Z,1712856167.893 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2024-04-11T17:22:51.149Z,1712856171.149 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3 2024-04-11T17:22:51.149Z,1712856171.149 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2024-04-11T17:22:51.172Z,1712856171.172 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2024-04-11T17:22:51.578Z,1712856171.578 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2024-04-11T17:22:51.578Z,1712856171.578 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3 2024-04-11T17:22:55.107Z,1712856175.107 [DataOverHttps](INFO): Sending 168 bytes from file Logs/20240411T171338/Courier0004.lzma 2024-04-11T17:22:56.130Z,1712856176.130 [DataOverHttps](INFO): Moved sent file to Logs/20240411T171338/Courier0004.lzma.bak 2024-04-11T17:22:56.130Z,1712856176.130 [DataOverHttps](INFO): SBD MOMSN=19399824 2024-04-11T17:23:11.640Z,1712856191.640 [DataOverHttps](INFO): Sending 187 bytes from file Logs/20240411T171338/Express0005.lzma 2024-04-11T17:23:12.642Z,1712856192.642 [DataOverHttps](INFO): Moved sent file to Logs/20240411T171338/Express0005.lzma.bak 2024-04-11T17:23:12.642Z,1712856192.642 [DataOverHttps](INFO): SBD MOMSN=19399826 2024-04-11T17:23:14.173Z,1712856194.173 [Default:CheckIn:Read_Iridium] Stopped 2024-04-11T17:23:14.173Z,1712856194.173 [Default:CheckIn:C.Wait] Running Loop=1 2024-04-11T17:23:14.173Z,1712856194.173 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-04-11T17:24:31.309Z,1712856271.309 [NAL9602](FAULT): GPS failed to acquire within timeout. 2024-04-11T17:24:31.309Z,1712856271.309 [NAL9602] Data Fault, FailCount= 1 2024-04-11T17:24:31.309Z,1712856271.309 [NAL9602](ERROR): Data Fault 2024-04-11T17:24:31.355Z,1712856271.355 [CBIT](ERROR): Data Fault in component: NAL9602 2024-04-11T17:24:31.708Z,1712856271.708 [NAL9602](INFO): Powering down 2024-04-11T17:24:32.541Z,1712856272.541 [CBIT](INFO): Clearing failed state for component NAL9602 2024-04-11T17:24:32.541Z,1712856272.541 [NAL9602] No Fault, FailCount= 1 2024-04-11T17:25:02.012Z,1712856302.012 [NAL9602](INFO): Powering up NAL9602 2024-04-11T17:25:12.921Z,1712856312.921 [NAL9602](INFO): NAL9602 initialized 2024-04-11T17:25:52.116Z,1712856352.116 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4 2024-04-11T17:25:52.116Z,1712856352.116 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2024-04-11T17:25:52.127Z,1712856352.127 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2024-04-11T17:25:52.529Z,1712856352.529 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2024-04-11T17:25:52.529Z,1712856352.529 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4 2024-04-11T17:28:14.740Z,1712856494.740 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-04-11T17:28:14.740Z,1712856494.740 [Default:CheckIn:C.Wait] Stopped 2024-04-11T17:28:14.740Z,1712856494.740 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-04-11T17:28:14.740Z,1712856494.740 [Default:CheckIn:D] Running Loop=1 2024-04-11T17:28:15.156Z,1712856495.156 [Default:CheckIn:D] Stopped 2024-04-11T17:28:15.156Z,1712856495.156 [Default:CheckIn:E] Running Loop=1 2024-04-11T17:28:15.558Z,1712856495.558 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.692827 min 2024-04-11T17:28:15.558Z,1712856495.558 [Default:CheckIn:E] Stopped 2024-04-11T17:28:15.558Z,1712856495.558 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-04-11T17:28:15.558Z,1712856495.558 [Default:CheckIn] Stopped 2024-04-11T17:28:15.558Z,1712856495.558 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-04-11T17:28:15.558Z,1712856495.558 [Default:CheckIn](INFO): Running loop #2 2024-04-11T17:28:15.558Z,1712856495.558 [Default:CheckIn] Running Loop=2 2024-04-11T17:28:15.558Z,1712856495.558 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-04-11T17:28:15.558Z,1712856495.558 [Default:CheckIn:Read_GPS] Running Loop=1 2024-04-11T17:28:53.116Z,1712856533.116 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5 2024-04-11T17:28:53.116Z,1712856533.116 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2024-04-11T17:28:53.127Z,1712856533.127 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2024-04-11T17:28:53.537Z,1712856533.537 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2024-04-11T17:28:53.537Z,1712856533.537 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5 2024-04-11T17:31:54.122Z,1712856714.122 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6 2024-04-11T17:31:54.122Z,1712856714.122 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2024-04-11T17:31:54.137Z,1712856714.137 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2024-04-11T17:31:54.549Z,1712856714.549 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2024-04-11T17:31:54.549Z,1712856714.549 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6 2024-04-11T17:33:15.742Z,1712856795.742 [Default:CheckIn:Read_GPS](INFO): Timed out from 2024-04-11T17:28:15.6Z 2024-04-11T17:33:15.742Z,1712856795.742 [Default:CheckIn:Read_GPS] Stopped 2024-04-11T17:33:15.742Z,1712856795.742 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-04-11T17:33:23.331Z,1712856803.331 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20240411T171338/Courier0007.lzma 2024-04-11T17:33:24.333Z,1712856804.333 [DataOverHttps](INFO): Moved sent file to Logs/20240411T171338/Courier0007.lzma.bak 2024-04-11T17:33:24.333Z,1712856804.333 [DataOverHttps](INFO): SBD MOMSN=19400035 2024-04-11T17:33:39.847Z,1712856819.847 [DataOverHttps](INFO): Sending 184 bytes from file Logs/20240411T171338/Express0008.lzma 2024-04-11T17:33:40.849Z,1712856820.849 [DataOverHttps](INFO): Moved sent file to Logs/20240411T171338/Express0008.lzma.bak 2024-04-11T17:33:40.849Z,1712856820.849 [DataOverHttps](INFO): SBD MOMSN=19400037 2024-04-11T17:33:42.405Z,1712856822.405 [Default:CheckIn:Read_Iridium] Stopped 2024-04-11T17:33:42.405Z,1712856822.405 [Default:CheckIn:C.Wait] Running Loop=1 2024-04-11T17:33:42.405Z,1712856822.405 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-04-11T17:34:55.092Z,1712856895.092 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7 2024-04-11T17:34:55.092Z,1712856895.092 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2024-04-11T17:34:55.156Z,1712856895.156 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2024-04-11T17:34:55.506Z,1712856895.506 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2024-04-11T17:34:55.506Z,1712856895.506 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7 2024-04-11T17:35:14.073Z,1712856914.073 [NAL9602](FAULT): GPS failed to acquire within timeout. 2024-04-11T17:35:14.073Z,1712856914.073 [NAL9602] Data Fault, FailCount= 2 2024-04-11T17:35:14.073Z,1712856914.073 [NAL9602](ERROR): Data Fault 2024-04-11T17:35:14.127Z,1712856914.127 [CBIT](ERROR): Data Fault in component: NAL9602 2024-04-11T17:35:14.473Z,1712856914.473 [NAL9602](INFO): Powering down 2024-04-11T17:35:15.327Z,1712856915.327 [CBIT](INFO): Clearing failed state for component NAL9602 2024-04-11T17:35:15.327Z,1712856915.327 [NAL9602] No Fault, FailCount= 2 2024-04-11T17:35:44.781Z,1712856944.781 [NAL9602](INFO): Powering up NAL9602 2024-04-11T17:35:55.679Z,1712856955.679 [NAL9602](INFO): NAL9602 initialized 2024-04-11T17:37:56.082Z,1712857076.082 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8 2024-04-11T17:37:56.082Z,1712857076.082 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2024-04-11T17:37:56.120Z,1712857076.120 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2024-04-11T17:37:56.529Z,1712857076.529 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2024-04-11T17:37:56.529Z,1712857076.529 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8 2024-04-11T17:38:42.969Z,1712857122.969 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-04-11T17:38:42.969Z,1712857122.969 [Default:CheckIn:C.Wait] Stopped 2024-04-11T17:38:42.969Z,1712857122.969 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-04-11T17:38:42.969Z,1712857122.969 [Default:CheckIn:D] Running Loop=1 2024-04-11T17:38:43.377Z,1712857123.377 [Default:CheckIn:D] Stopped 2024-04-11T17:38:43.377Z,1712857123.377 [Default:CheckIn:E] Running Loop=1 2024-04-11T17:38:43.757Z,1712857123.757 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 21.163184 min 2024-04-11T17:38:43.757Z,1712857123.757 [Default:CheckIn:E] Stopped 2024-04-11T17:38:43.757Z,1712857123.757 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-04-11T17:38:43.757Z,1712857123.757 [Default:CheckIn] Stopped 2024-04-11T17:38:43.757Z,1712857123.757 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-04-11T17:38:43.758Z,1712857123.758 [Default:CheckIn](INFO): Running loop #3 2024-04-11T17:38:43.758Z,1712857123.758 [Default:CheckIn] Running Loop=3 2024-04-11T17:38:43.758Z,1712857123.758 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-04-11T17:38:43.758Z,1712857123.758 [Default:CheckIn:Read_GPS] Running Loop=1 2024-04-11T17:40:57.096Z,1712857257.096 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 9 2024-04-11T17:40:57.096Z,1712857257.096 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2024-04-11T17:40:57.107Z,1712857257.107 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2024-04-11T17:40:57.513Z,1712857257.513 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2024-04-11T17:40:57.513Z,1712857257.513 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 9 2024-04-11T17:43:20.317Z,1712857400.317 [CommandExec](IMPORTANT): got command show variable thrusterHE 2024-04-11T17:43:20.380Z,1712857400.380 [CommandExec](IMPORTANT): ThrusterHE.loadAtStartup (bool) 2024-04-11T17:43:20.380Z,1712857400.380 [CommandExec](IMPORTANT): ThrusterHE.simulateHardware (bool) 2024-04-11T17:43:20.381Z,1712857400.381 [CommandExec](IMPORTANT): ThrusterHE.deviation (count) 2024-04-11T17:43:20.381Z,1712857400.381 [CommandExec](IMPORTANT): ThrusterHE.allowableBadVelocity (count) 2024-04-11T17:43:20.381Z,1712857400.381 [CommandExec](IMPORTANT): ThrusterHE.ratedSpeed (count) 2024-04-11T17:43:20.382Z,1712857400.382 [CommandExec](IMPORTANT): ThrusterHE.powerOnTimeout (second) 2024-04-11T17:43:20.397Z,1712857400.397 [CommandExec](IMPORTANT): ThrusterHE.loadControl (none) 2024-04-11T17:43:20.397Z,1712857400.397 [CommandExec](IMPORTANT): ThrusterHE.uart (none) 2024-04-11T17:43:20.398Z,1712857400.398 [CommandExec](IMPORTANT): ThrusterHE.baud (bit_per_second) 2024-04-11T17:43:20.646Z,1712857400.646 [CommandExec](IMPORTANT): ThrusterHE.enableBroadcast (bool) 2024-04-11T17:43:20.647Z,1712857400.647 [CommandExec](IMPORTANT): ThrusterHE.component_voltage (volt) 2024-04-11T17:43:20.647Z,1712857400.647 [CommandExec](IMPORTANT): ThrusterHE.component_avgVoltage (volt) 2024-04-11T17:43:20.648Z,1712857400.648 [CommandExec](IMPORTANT): ThrusterHE.component_current (milliampere) 2024-04-11T17:43:20.648Z,1712857400.648 [CommandExec](IMPORTANT): ThrusterHE.component_avgCurrent (milliampere) 2024-04-11T17:43:20.648Z,1712857400.648 [CommandExec](IMPORTANT): ThrusterHE.platform_propeller_rotation_rate (radian_per_second) 2024-04-11T17:43:39.758Z,1712857419.758 [CommandExec](IMPORTANT): got command report mod ThrusterHE.component_current 2024-04-11T17:43:39.759Z,1712857419.759 [CommandExec](IMPORTANT): got command report mod ThrusterHE.component_avgCurrent 2024-04-11T17:43:39.903Z,1712857419.903 [Reporter](INFO): ThrusterHE.component_current 0.000000 mA 2024-04-11T17:43:39.904Z,1712857419.904 [Reporter](INFO): ThrusterHE.component_avgCurrent 0.000000 mA 2024-04-11T17:43:43.939Z,1712857423.939 [Default:CheckIn:Read_GPS](INFO): Timed out from 2024-04-11T17:38:43.8Z 2024-04-11T17:43:43.939Z,1712857423.939 [Default:CheckIn:Read_GPS] Stopped 2024-04-11T17:43:43.939Z,1712857423.939 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-04-11T17:43:51.828Z,1712857431.828 [CommandExec](IMPORTANT): got command maintain control SpeedControl.propOmegaAction 400 revolution_per_minute 2024-04-11T17:43:51.836Z,1712857431.836 [ComponentRegistry](DEBUG): SyncComponent "Maintain_SpeedControl.propOmegaAction" handled in the control thread. 2024-04-11T17:43:52.067Z,1712857432.067 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,Sonardyne_Nano,CANONSampler,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,Maintain_SpeedControl.propOmegaAction,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2024-04-11T17:43:53.259Z,1712857433.259 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20240411T171338/Courier0010.lzma 2024-04-11T17:43:54.261Z,1712857434.261 [DataOverHttps](INFO): Moved sent file to Logs/20240411T171338/Courier0010.lzma.bak 2024-04-11T17:43:54.261Z,1712857434.261 [DataOverHttps](INFO): SBD MOMSN=19400048 2024-04-11T17:43:56.100Z,1712857436.100 [Reporter](INFO): ThrusterHE.component_current 11.010000 mA 2024-04-11T17:43:56.100Z,1712857436.100 [Reporter](INFO): ThrusterHE.component_avgCurrent 18.350000 mA 2024-04-11T17:43:58.083Z,1712857438.083 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 10 2024-04-11T17:43:58.083Z,1712857438.083 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2024-04-11T17:43:58.143Z,1712857438.143 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2024-04-11T17:43:58.526Z,1712857438.526 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2024-04-11T17:43:58.527Z,1712857438.527 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 10 2024-04-11T17:43:58.536Z,1712857438.536 [Reporter](INFO): ThrusterHE.component_current 135.790009 mA 2024-04-11T17:43:58.537Z,1712857438.537 [Reporter](INFO): ThrusterHE.component_avgCurrent 297.270020 mA 2024-04-11T17:44:00.988Z,1712857440.988 [Reporter](INFO): ThrusterHE.component_current 143.130005 mA 2024-04-11T17:44:00.989Z,1712857440.989 [Reporter](INFO): ThrusterHE.component_avgCurrent 150.470001 mA 2024-04-11T17:44:03.424Z,1712857443.424 [Reporter](INFO): ThrusterHE.component_avgCurrent 146.800003 mA 2024-04-11T17:44:05.844Z,1712857445.844 [Reporter](INFO): ThrusterHE.component_current 172.490005 mA 2024-04-11T17:44:05.845Z,1712857445.845 [Reporter](INFO): ThrusterHE.component_avgCurrent 161.480011 mA 2024-04-11T17:44:08.288Z,1712857448.288 [Reporter](INFO): ThrusterHE.component_current 190.839996 mA 2024-04-11T17:44:08.289Z,1712857448.289 [Reporter](INFO): ThrusterHE.component_avgCurrent 150.470001 mA 2024-04-11T17:44:10.228Z,1712857450.228 [DataOverHttps](INFO): Sending 503 bytes from file Logs/20240411T171338/Express0011.lzma 2024-04-11T17:44:10.728Z,1712857450.728 [Reporter](INFO): ThrusterHE.component_current 121.110001 mA 2024-04-11T17:44:10.729Z,1712857450.729 [Reporter](INFO): ThrusterHE.component_avgCurrent 146.800003 mA 2024-04-11T17:44:11.229Z,1712857451.229 [DataOverHttps](INFO): Moved sent file to Logs/20240411T171338/Express0011.lzma.bak 2024-04-11T17:44:11.229Z,1712857451.229 [DataOverHttps](INFO): SBD MOMSN=19400050 2024-04-11T17:44:12.630Z,1712857452.630 [Default:CheckIn:Read_Iridium] Stopped 2024-04-11T17:44:12.630Z,1712857452.630 [Default:CheckIn:C.Wait] Running Loop=1 2024-04-11T17:44:12.630Z,1712857452.630 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-04-11T17:44:13.124Z,1712857453.124 [Reporter](INFO): ThrusterHE.component_current 143.130005 mA 2024-04-11T17:44:13.125Z,1712857453.125 [Reporter](INFO): ThrusterHE.component_avgCurrent 165.150009 mA 2024-04-11T17:44:15.560Z,1712857455.560 [Reporter](INFO): ThrusterHE.component_current 121.110001 mA 2024-04-11T17:44:15.561Z,1712857455.561 [Reporter](INFO): ThrusterHE.component_avgCurrent 143.130005 mA 2024-04-11T17:44:17.976Z,1712857457.976 [Reporter](INFO): ThrusterHE.component_current 187.169998 mA 2024-04-11T17:44:17.977Z,1712857457.977 [Reporter](INFO): ThrusterHE.component_avgCurrent 154.139999 mA 2024-04-11T17:44:22.833Z,1712857462.833 [Reporter](INFO): ThrusterHE.component_current 157.809998 mA 2024-04-11T17:44:22.834Z,1712857462.834 [Reporter](INFO): ThrusterHE.component_avgCurrent 143.130005 mA 2024-04-11T17:44:25.229Z,1712857465.229 [Reporter](INFO): ThrusterHE.component_current 187.169998 mA 2024-04-11T17:44:25.230Z,1712857465.230 [Reporter](INFO): ThrusterHE.component_avgCurrent 157.809998 mA 2024-04-11T17:44:34.948Z,1712857474.948 [Reporter](INFO): ThrusterHE.component_current 172.490005 mA 2024-04-11T17:44:34.949Z,1712857474.949 [Reporter](INFO): ThrusterHE.component_avgCurrent 146.800003 mA 2024-04-11T17:44:37.372Z,1712857477.372 [Reporter](INFO): ThrusterHE.component_avgCurrent 161.480011 mA 2024-04-11T17:44:39.776Z,1712857479.776 [Reporter](INFO): ThrusterHE.component_current 150.470001 mA 2024-04-11T17:44:39.777Z,1712857479.777 [Reporter](INFO): ThrusterHE.component_avgCurrent 150.470001 mA 2024-04-11T17:44:44.620Z,1712857484.620 [Reporter](INFO): ThrusterHE.component_current 157.809998 mA 2024-04-11T17:44:44.621Z,1712857484.621 [Reporter](INFO): ThrusterHE.component_avgCurrent 165.150009 mA 2024-04-11T17:44:47.021Z,1712857487.021 [Reporter](INFO): ThrusterHE.component_avgCurrent 146.800003 mA 2024-04-11T17:44:49.496Z,1712857489.496 [Reporter](INFO): ThrusterHE.component_current 150.470001 mA 2024-04-11T17:44:49.497Z,1712857489.497 [Reporter](INFO): ThrusterHE.component_avgCurrent 157.809998 mA 2024-04-11T17:44:56.740Z,1712857496.740 [Reporter](INFO): ThrusterHE.component_current 172.490005 mA 2024-04-11T17:44:56.741Z,1712857496.741 [Reporter](INFO): ThrusterHE.component_avgCurrent 165.150009 mA 2024-04-11T17:44:58.429Z,1712857498.429 [CommandExec](IMPORTANT): got command maintain clear 2024-04-11T17:44:58.782Z,1712857498.782 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,Sonardyne_Nano,CANONSampler,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2024-04-11T17:44:59.610Z,1712857499.610 [Reporter](INFO): ThrusterHE.component_current 0.000000 mA 2024-04-11T17:44:59.610Z,1712857499.610 [Reporter](INFO): ThrusterHE.component_avgCurrent 0.000000 mA 2024-04-11T17:45:58.457Z,1712857558.457 [NAL9602](FAULT): GPS failed to acquire within timeout. 2024-04-11T17:45:58.457Z,1712857558.457 [NAL9602] Data Fault, FailCount= 3 2024-04-11T17:45:58.457Z,1712857558.457 [NAL9602](ERROR): Data Fault 2024-04-11T17:45:58.474Z,1712857558.474 [CBIT](ERROR): Data Fault in component: NAL9602 2024-04-11T17:45:58.857Z,1712857558.857 [NAL9602](INFO): Powering down 2024-04-11T17:45:59.681Z,1712857559.681 [CBIT](INFO): Clearing failed state for component NAL9602 2024-04-11T17:45:59.681Z,1712857559.681 [NAL9602] No Fault, FailCount= 3 2024-04-11T17:46:29.155Z,1712857589.155 [NAL9602](INFO): Powering up NAL9602 2024-04-11T17:46:30.259Z,1712857590.259 [CommandExec](IMPORTANT): got command maintain control SpeedControl.propOmegaAction 400 revolution_per_minute 2024-04-11T17:46:30.260Z,1712857590.260 [ComponentRegistry](DEBUG): SyncComponent "Maintain_SpeedControl.propOmegaAction" handled in the control thread. 2024-04-11T17:46:30.413Z,1712857590.413 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,Sonardyne_Nano,CANONSampler,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,Maintain_SpeedControl.propOmegaAction,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2024-04-11T17:46:35.330Z,1712857595.330 [Reporter](INFO): ThrusterHE.component_current 29.360001 mA 2024-04-11T17:46:35.331Z,1712857595.331 [Reporter](INFO): ThrusterHE.component_avgCurrent 29.360001 mA 2024-04-11T17:46:37.736Z,1712857597.736 [Reporter](INFO): ThrusterHE.component_current 139.460007 mA 2024-04-11T17:46:37.737Z,1712857597.737 [Reporter](INFO): ThrusterHE.component_avgCurrent 311.950012 mA 2024-04-11T17:46:40.069Z,1712857600.069 [NAL9602](INFO): NAL9602 initialized 2024-04-11T17:46:40.172Z,1712857600.172 [Reporter](INFO): ThrusterHE.component_current 143.130005 mA 2024-04-11T17:46:40.173Z,1712857600.173 [Reporter](INFO): ThrusterHE.component_avgCurrent 143.130005 mA 2024-04-11T17:46:42.620Z,1712857602.620 [Reporter](INFO): ThrusterHE.component_avgCurrent 146.800003 mA 2024-04-11T17:46:44.948Z,1712857604.948 [Reporter](INFO): ThrusterHE.component_avgCurrent 150.470001 mA 2024-04-11T17:46:47.516Z,1712857607.516 [Reporter](INFO): ThrusterHE.component_current 132.119995 mA 2024-04-11T17:46:47.517Z,1712857607.517 [Reporter](INFO): ThrusterHE.component_avgCurrent 143.130005 mA 2024-04-11T17:46:49.020Z,1712857609.020 [CommandExec](IMPORTANT): got command maintain control SpeedControl.propOmegaAction 600 revolution_per_minute 2024-04-11T17:46:49.916Z,1712857609.916 [Reporter](INFO): ThrusterHE.component_current 150.470001 mA 2024-04-11T17:46:49.917Z,1712857609.917 [Reporter](INFO): ThrusterHE.component_avgCurrent 157.809998 mA 2024-04-11T17:46:52.332Z,1712857612.332 [Reporter](INFO): ThrusterHE.component_current 139.460007 mA 2024-04-11T17:46:52.333Z,1712857612.333 [Reporter](INFO): ThrusterHE.component_avgCurrent 154.139999 mA 2024-04-11T17:46:54.680Z,1712857614.680 [Reporter](INFO): ThrusterHE.component_current 135.790009 mA 2024-04-11T17:46:54.680Z,1712857614.680 [Reporter](INFO): ThrusterHE.component_avgCurrent 143.130005 mA 2024-04-11T17:46:57.169Z,1712857617.169 [Reporter](INFO): ThrusterHE.component_current 201.850006 mA 2024-04-11T17:46:57.170Z,1712857617.170 [Reporter](INFO): ThrusterHE.component_avgCurrent 179.830002 mA 2024-04-11T17:46:59.093Z,1712857619.093 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 11 2024-04-11T17:46:59.093Z,1712857619.093 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2024-04-11T17:46:59.162Z,1712857619.162 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2024-04-11T17:46:59.530Z,1712857619.530 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2024-04-11T17:46:59.530Z,1712857619.530 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 11 2024-04-11T17:46:59.532Z,1712857619.532 [Reporter](INFO): ThrusterHE.component_current 176.160004 mA 2024-04-11T17:46:59.533Z,1712857619.533 [Reporter](INFO): ThrusterHE.component_avgCurrent 209.190002 mA 2024-04-11T17:47:01.960Z,1712857621.960 [Reporter](INFO): ThrusterHE.component_current 209.190002 mA 2024-04-11T17:47:01.960Z,1712857621.960 [Reporter](INFO): ThrusterHE.component_avgCurrent 220.200012 mA 2024-04-11T17:47:06.650Z,1712857626.650 [CommandExec](IMPORTANT): got command maintain control SpeedControl.propOmegaAction 800 revolution_per_minute 2024-04-11T17:47:06.784Z,1712857626.784 [ThrusterHE](FAULT): Commanded speed of:799 rpm exceeds configured ratedSpeed value. 2024-04-11T17:47:06.784Z,1712857626.784 [ThrusterHE] Hardware Fault, FailCount= 1 2024-04-11T17:47:06.784Z,1712857626.784 [ThrusterHE](ERROR): Hardware Fault 2024-04-11T17:47:06.788Z,1712857626.788 [CBIT](ERROR): Hardware Fault in component: ThrusterHE 2024-04-11T17:47:06.789Z,1712857626.789 [Reporter](INFO): ThrusterHE.component_current 209.190002 mA 2024-04-11T17:47:06.789Z,1712857626.789 [Reporter](INFO): ThrusterHE.component_avgCurrent 220.200012 mA 2024-04-11T17:47:07.177Z,1712857627.177 [ThrusterHE](DEBUG): Uninitialize Thruster Servo. 2024-04-11T17:47:07.177Z,1712857627.177 [ThrusterHE](INFO): Powering down 2024-04-11T17:47:08.008Z,1712857628.008 [ThrusterHE](DEBUG): Initializing EZServoServo. 2024-04-11T17:47:08.128Z,1712857628.128 [ThrusterHE](DEBUG): Initializing ThrusterHE. 2024-04-11T17:47:08.132Z,1712857628.132 [CBIT](INFO): Clearing failed state for component ThrusterHE 2024-04-11T17:47:08.132Z,1712857628.132 [ThrusterHE] No Fault, FailCount= 1 2024-04-11T17:47:13.263Z,1712857633.263 [Reporter](INFO): ThrusterHE.component_current 0.000000 mA 2024-04-11T17:47:13.264Z,1712857633.264 [Reporter](INFO): ThrusterHE.component_avgCurrent 0.000000 mA 2024-04-11T17:47:13.655Z,1712857633.655 [ThrusterHE](ERROR): Zero Speed Commanded. 2024-04-11T17:47:13.655Z,1712857633.655 [ThrusterHE](FAULT): Commanded speed of:799 rpm exceeds configured ratedSpeed value. 2024-04-11T17:47:13.655Z,1712857633.655 [ThrusterHE] Hardware Fault, FailCount= 2 2024-04-11T17:47:13.655Z,1712857633.655 [ThrusterHE](ERROR): Hardware Fault 2024-04-11T17:47:13.659Z,1712857633.659 [CBIT](ERROR): Hardware Fault in component: ThrusterHE 2024-04-11T17:47:13.660Z,1712857633.660 [Reporter](INFO): ThrusterHE.component_current 0.000000 mA 2024-04-11T17:47:13.661Z,1712857633.661 [Reporter](INFO): ThrusterHE.component_avgCurrent 0.000000 mA 2024-04-11T17:47:14.077Z,1712857634.077 [ThrusterHE](DEBUG): Uninitialize Thruster Servo. 2024-04-11T17:47:14.077Z,1712857634.077 [ThrusterHE](INFO): Powering down 2024-04-11T17:47:14.864Z,1712857634.864 [ThrusterHE](DEBUG): Initializing EZServoServo. 2024-04-11T17:47:14.984Z,1712857634.984 [ThrusterHE](DEBUG): Initializing ThrusterHE. 2024-04-11T17:47:14.988Z,1712857634.988 [CBIT](INFO): Clearing failed state for component ThrusterHE 2024-04-11T17:47:14.988Z,1712857634.988 [ThrusterHE] No Fault, FailCount= 2 2024-04-11T17:47:17.689Z,1712857637.689 [CommandExec](IMPORTANT): got command maintain control SpeedControl.propOmegaAction 700 revolution_per_minute 2024-04-11T17:47:20.560Z,1712857640.560 [Reporter](INFO): ThrusterHE.component_current 0.000000 mA 2024-04-11T17:47:20.561Z,1712857640.561 [Reporter](INFO): ThrusterHE.component_avgCurrent 0.000000 mA 2024-04-11T17:47:20.937Z,1712857640.937 [ThrusterHE](FAULT): Commanded speed of:699 rpm exceeds configured ratedSpeed value. 2024-04-11T17:47:20.937Z,1712857640.937 [ThrusterHE] Hardware Fault, FailCount= 3 2024-04-11T17:47:20.937Z,1712857640.937 [ThrusterHE](ERROR): Hardware Fault 2024-04-11T17:47:20.940Z,1712857640.940 [CBIT](ERROR): Hardware Fault in component: ThrusterHE 2024-04-11T17:47:20.941Z,1712857640.941 [Reporter](INFO): ThrusterHE.component_current 0.000000 mA 2024-04-11T17:47:20.942Z,1712857640.942 [Reporter](INFO): ThrusterHE.component_avgCurrent 0.000000 mA 2024-04-11T17:47:21.316Z,1712857641.316 [ThrusterHE](DEBUG): Uninitialize Thruster Servo. 2024-04-11T17:47:21.316Z,1712857641.316 [ThrusterHE](INFO): Powering down 2024-04-11T17:47:22.124Z,1712857642.124 [ThrusterHE](DEBUG): Initializing EZServoServo. 2024-04-11T17:47:22.240Z,1712857642.240 [ThrusterHE](DEBUG): Initializing ThrusterHE. 2024-04-11T17:47:22.244Z,1712857642.244 [CBIT](INFO): Clearing failed state for component ThrusterHE 2024-04-11T17:47:22.244Z,1712857642.244 [ThrusterHE] No Fault, FailCount= 3 2024-04-11T17:47:27.400Z,1712857647.400 [Reporter](INFO): ThrusterHE.component_current 0.000000 mA 2024-04-11T17:47:27.400Z,1712857647.400 [Reporter](INFO): ThrusterHE.component_avgCurrent 0.000000 mA 2024-04-11T17:47:27.777Z,1712857647.777 [ThrusterHE](FAULT): Commanded speed of:699 rpm exceeds configured ratedSpeed value. 2024-04-11T17:47:27.777Z,1712857647.777 [ThrusterHE] Hardware Fault, FailCount= 4 2024-04-11T17:47:27.777Z,1712857647.777 [ThrusterHE](ERROR): Hardware Fault 2024-04-11T17:47:27.798Z,1712857647.798 [CBIT](ERROR): Hardware Fault in component: ThrusterHE 2024-04-11T17:47:27.819Z,1712857647.819 [Reporter](INFO): ThrusterHE.component_current 0.000000 mA 2024-04-11T17:47:27.820Z,1712857647.820 [Reporter](INFO): ThrusterHE.component_avgCurrent 0.000000 mA 2024-04-11T17:47:28.196Z,1712857648.196 [ThrusterHE](DEBUG): Uninitialize Thruster Servo. 2024-04-11T17:47:28.196Z,1712857648.196 [ThrusterHE](INFO): Powering down 2024-04-11T17:47:29.019Z,1712857649.019 [ThrusterHE](DEBUG): Initializing EZServoServo. 2024-04-11T17:47:29.140Z,1712857649.140 [ThrusterHE](DEBUG): Initializing ThrusterHE. 2024-04-11T17:47:29.144Z,1712857649.144 [CBIT](INFO): Clearing failed state for component ThrusterHE 2024-04-11T17:47:29.144Z,1712857649.144 [ThrusterHE] No Fault, FailCount= 4 2024-04-11T17:47:30.472Z,1712857650.472 [CommandExec](IMPORTANT): got command maintain control SpeedControl.propOmegaAction 600 revolution_per_minute 2024-04-11T17:47:34.260Z,1712857654.260 [Reporter](INFO): ThrusterHE.component_current 0.000000 mA 2024-04-11T17:47:34.260Z,1712857654.260 [Reporter](INFO): ThrusterHE.component_avgCurrent 0.000000 mA 2024-04-11T17:47:39.586Z,1712857659.586 [Reporter](INFO): ThrusterHE.component_current 172.490005 mA 2024-04-11T17:47:39.587Z,1712857659.587 [Reporter](INFO): ThrusterHE.component_avgCurrent 176.160004 mA 2024-04-11T17:47:42.038Z,1712857662.038 [Reporter](INFO): ThrusterHE.component_current 201.850006 mA 2024-04-11T17:47:42.038Z,1712857662.038 [Reporter](INFO): ThrusterHE.component_avgCurrent 216.529999 mA 2024-04-11T17:47:44.400Z,1712857664.400 [Reporter](INFO): ThrusterHE.component_current 205.520004 mA 2024-04-11T17:47:44.401Z,1712857664.401 [Reporter](INFO): ThrusterHE.component_avgCurrent 201.850006 mA 2024-04-11T17:47:45.905Z,1712857665.905 [CommandExec](IMPORTANT): got command maintain clear 2024-04-11T17:47:46.061Z,1712857666.061 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,Sonardyne_Nano,CANONSampler,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2024-04-11T17:47:46.916Z,1712857666.916 [Reporter](INFO): ThrusterHE.component_current 0.000000 mA 2024-04-11T17:47:46.917Z,1712857666.917 [Reporter](INFO): ThrusterHE.component_avgCurrent 0.000000 mA 2024-04-11T17:49:13.233Z,1712857753.233 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-04-11T17:49:13.233Z,1712857753.233 [Default:CheckIn:C.Wait] Stopped 2024-04-11T17:49:13.233Z,1712857753.233 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-04-11T17:49:13.233Z,1712857753.233 [Default:CheckIn:D] Running Loop=1 2024-04-11T17:49:13.642Z,1712857753.642 [Default:CheckIn:D] Stopped 2024-04-11T17:49:13.642Z,1712857753.642 [Default:CheckIn:E] Running Loop=1 2024-04-11T17:49:14.038Z,1712857754.038 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 31.667596 min 2024-04-11T17:49:14.038Z,1712857754.038 [Default:CheckIn:E] Stopped 2024-04-11T17:49:14.038Z,1712857754.038 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-04-11T17:49:14.038Z,1712857754.038 [Default:CheckIn] Stopped 2024-04-11T17:49:14.038Z,1712857754.038 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-04-11T17:49:14.038Z,1712857754.038 [Default:CheckIn](INFO): Running loop #4 2024-04-11T17:49:14.038Z,1712857754.038 [Default:CheckIn] Running Loop=4 2024-04-11T17:49:14.038Z,1712857754.038 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-04-11T17:49:14.038Z,1712857754.038 [Default:CheckIn:Read_GPS] Running Loop=1 2024-04-11T17:50:00.080Z,1712857800.080 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 12 2024-04-11T17:50:00.080Z,1712857800.080 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2024-04-11T17:50:00.090Z,1712857800.090 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2024-04-11T17:50:00.496Z,1712857800.496 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2024-04-11T17:50:00.496Z,1712857800.496 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 12 2024-04-11T17:53:01.104Z,1712857981.104 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 13 2024-04-11T17:53:01.104Z,1712857981.104 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2024-04-11T17:53:01.115Z,1712857981.115 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2024-04-11T17:53:01.543Z,1712857981.543 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2024-04-11T17:53:01.543Z,1712857981.543 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 13 2024-04-11T17:53:25.174Z,1712858005.174 [CommandExec](IMPORTANT): got command maintain control SpeedControl.propOmegaAction 600 revolution_per_minute 2024-04-11T17:53:25.198Z,1712858005.198 [ComponentRegistry](DEBUG): SyncComponent "Maintain_SpeedControl.propOmegaAction" handled in the control thread. 2024-04-11T17:53:25.380Z,1712858005.380 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,Sonardyne_Nano,CANONSampler,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,Maintain_SpeedControl.propOmegaAction,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2024-04-11T17:53:31.096Z,1712858011.096 [Reporter](INFO): ThrusterHE.component_current 69.730003 mA 2024-04-11T17:53:31.097Z,1712858011.097 [Reporter](INFO): ThrusterHE.component_avgCurrent 25.690001 mA 2024-04-11T17:53:33.500Z,1712858013.500 [Reporter](INFO): ThrusterHE.component_current 157.809998 mA 2024-04-11T17:53:33.501Z,1712858013.501 [Reporter](INFO): ThrusterHE.component_avgCurrent 528.479980 mA 2024-04-11T17:53:35.884Z,1712858015.884 [Reporter](INFO): ThrusterHE.component_current 234.880005 mA 2024-04-11T17:53:35.884Z,1712858015.884 [Reporter](INFO): ThrusterHE.component_avgCurrent 201.850006 mA 2024-04-11T17:53:38.384Z,1712858018.384 [Reporter](INFO): ThrusterHE.component_current 245.889999 mA 2024-04-11T17:53:38.385Z,1712858018.385 [Reporter](INFO): ThrusterHE.component_avgCurrent 212.860001 mA 2024-04-11T17:53:40.788Z,1712858020.788 [Reporter](INFO): ThrusterHE.component_current 220.200012 mA 2024-04-11T17:53:40.789Z,1712858020.789 [Reporter](INFO): ThrusterHE.component_avgCurrent 234.880005 mA 2024-04-11T17:53:43.192Z,1712858023.192 [Reporter](INFO): ThrusterHE.component_current 242.220001 mA 2024-04-11T17:53:43.193Z,1712858023.193 [Reporter](INFO): ThrusterHE.component_avgCurrent 209.190002 mA 2024-04-11T17:53:45.568Z,1712858025.568 [Reporter](INFO): ThrusterHE.component_current 234.880005 mA 2024-04-11T17:53:45.568Z,1712858025.568 [Reporter](INFO): ThrusterHE.component_avgCurrent 212.860001 mA 2024-04-11T17:53:50.181Z,1712858030.181 [CommandExec](IMPORTANT): got command maintain clear 2024-04-11T17:53:50.488Z,1712858030.488 [Reporter](INFO): ThrusterHE.component_current 220.200012 mA 2024-04-11T17:53:50.489Z,1712858030.489 [Reporter](INFO): ThrusterHE.component_avgCurrent 205.520004 mA 2024-04-11T17:53:50.495Z,1712858030.495 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,Sonardyne_Nano,CANONSampler,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2024-04-11T17:53:51.320Z,1712858031.320 [Reporter](INFO): ThrusterHE.component_current 0.000000 mA 2024-04-11T17:53:51.321Z,1712858031.321 [Reporter](INFO): ThrusterHE.component_avgCurrent 0.000000 mA 2024-04-11T17:54:14.242Z,1712858054.242 [Default:CheckIn:Read_GPS](INFO): Timed out from 2024-04-11T17:49:14.0Z 2024-04-11T17:54:14.242Z,1712858054.242 [Default:CheckIn:Read_GPS] Stopped 2024-04-11T17:54:14.242Z,1712858054.242 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-04-11T17:54:21.527Z,1712858061.527 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20240411T171338/Courier0013.lzma 2024-04-11T17:54:22.530Z,1712858062.530 [DataOverHttps](INFO): Moved sent file to Logs/20240411T171338/Courier0013.lzma.bak 2024-04-11T17:54:22.530Z,1712858062.530 [DataOverHttps](INFO): SBD MOMSN=19400101 2024-04-11T17:54:38.152Z,1712858078.152 [DataOverHttps](INFO): Sending 394 bytes from file Logs/20240411T171338/Express0014.lzma 2024-04-11T17:54:39.153Z,1712858079.153 [DataOverHttps](INFO): Moved sent file to Logs/20240411T171338/Express0014.lzma.bak 2024-04-11T17:54:39.153Z,1712858079.153 [DataOverHttps](INFO): SBD MOMSN=19400103 2024-04-11T17:54:40.501Z,1712858080.501 [Default:CheckIn:Read_Iridium] Stopped 2024-04-11T17:54:40.501Z,1712858080.501 [Default:CheckIn:C.Wait] Running Loop=1 2024-04-11T17:54:40.501Z,1712858080.501 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-04-11T17:54:51.172Z,1712858091.172 [CommandExec](IMPORTANT): got command quit 2024-04-11T17:54:52.547Z,1712858092.547 [Supervisor](INFO): Stop Mission called by Supervisor::terminate 2024-04-11T17:54:52.548Z,1712858092.548 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread. 2024-04-11T17:54:52.548Z,1712858092.548 [CommandExec](INFO): Uninitializing the command executive. 2024-04-11T17:54:52.548Z,1712858092.548 [CommandExec](INFO): Uninitializing the command scheduler. 2024-04-11T17:54:52.548Z,1712858092.548 [CommandExec ThreadHandler](INFO): Thread cancelled. 2024-04-11T17:54:52.587Z,1712858092.587 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2024-04-11T17:54:52.588Z,1712858092.588 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2024-04-11T17:54:52.588Z,1712858092.588 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2024-04-11T17:54:52.588Z,1712858092.588 [NavChartDb](INFO): Join timeout helper Thread ID is 5279 2024-04-11T17:54:52.708Z,1712858092.708 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2024-04-11T17:54:52.709Z,1712858092.709 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2024-04-11T17:54:52.715Z,1712858092.715 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2024-04-11T17:54:52.715Z,1712858092.715 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2024-04-11T17:54:52.716Z,1712858092.716 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 5280 2024-04-11T17:54:53.184Z,1712858093.184 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2024-04-11T17:54:53.186Z,1712858093.186 [WetLabsBB2FL](INFO): Powering down 2024-04-11T17:54:53.187Z,1712858093.187 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2024-04-11T17:54:53.187Z,1712858093.187 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2024-04-11T17:54:53.188Z,1712858093.188 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2024-04-11T17:54:53.188Z,1712858093.188 [CTD_Seabird](INFO): Join timeout helper Thread ID is 5281 2024-04-11T17:54:53.379Z,1712858093.379 [CTD_Seabird](INFO): Powering down 2024-04-11T17:54:53.399Z,1712858093.399 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread. 2024-04-11T17:54:53.400Z,1712858093.400 [CTD_Seabird](INFO): Powering down 2024-04-11T17:54:53.411Z,1712858093.411 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2024-04-11T17:54:53.419Z,1712858093.419 [ComponentRegistry](INFO): Shutting down DAT ThreadHandler 2024-04-11T17:54:53.419Z,1712858093.419 [DAT ThreadHandler](INFO): Thread cancelled. 2024-04-11T17:54:53.420Z,1712858093.420 [DAT](INFO): Join timeout helper Thread ID is 5282 2024-04-11T17:54:53.463Z,1712858093.463 [DAT](INFO): Powering down 2024-04-11T17:54:53.536Z,1712858093.536 [DAT ThreadHandler](INFO): Uninitializing protected caller thread. 2024-04-11T17:54:53.536Z,1712858093.536 [DAT](INFO): Powering down 2024-04-11T17:54:53.537Z,1712858093.537 [DAT ThreadHandler](INFO): Thread cancelled. 2024-04-11T17:54:53.539Z,1712858093.539 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2024-04-11T17:54:53.539Z,1712858093.539 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2024-04-11T17:54:53.540Z,1712858093.540 [Radio_Surface](INFO): Join timeout helper Thread ID is 5283 2024-04-11T17:54:53.595Z,1712858093.595 [Radio_Surface](INFO): Powering down 2024-04-11T17:54:53.596Z,1712858093.596 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2024-04-11T17:54:53.597Z,1712858093.597 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2024-04-11T17:54:53.600Z,1712858093.600 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler 2024-04-11T17:54:53.600Z,1712858093.600 [Onboard ThreadHandler](INFO): Thread cancelled. 2024-04-11T17:54:53.601Z,1712858093.601 [Onboard](INFO): Join timeout helper Thread ID is 5284 2024-04-11T17:54:54.455Z,1712858094.455 [DataOverHttps](INFO): Radio surface powered OFF, will not connect. 2024-04-11T17:54:56.123Z,1712858096.123 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread. 2024-04-11T17:54:56.124Z,1712858096.124 [Onboard ThreadHandler](INFO): Thread cancelled. 2024-04-11T17:54:56.128Z,1712858096.128 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2024-04-11T17:54:56.128Z,1712858096.128 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2024-04-11T17:54:56.128Z,1712858096.128 [DataOverHttps](INFO): Join timeout helper Thread ID is 5285 2024-04-11T17:54:56.463Z,1712858096.463 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2024-04-11T17:54:56.464Z,1712858096.464 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2024-04-11T17:54:56.472Z,1712858096.472 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2024-04-11T17:54:56.472Z,1712858096.472 [logger ThreadHandler](INFO): Thread cancelled. 2024-04-11T17:54:56.472Z,1712858096.472 [logger](INFO): Join timeout helper Thread ID is 5286 2024-04-11T17:54:56.511Z,1712858096.511 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2024-04-11T17:54:56.512Z,1712858096.512 [logger ThreadHandler](INFO): Thread cancelled. 2024-04-11T17:54:56.532Z,1712858096.532 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2024-04-11T17:54:56.532Z,1712858096.532 [CommandLine ThreadHandler](INFO): Thread cancelled. 2024-04-11T17:54:56.532Z,1712858096.532 [CommandLine](INFO): Join timeout helper Thread ID is 5287 2024-04-11T17:54:56.607Z,1712858096.607 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2024-04-11T17:54:56.608Z,1712858096.608 [CommandLine ThreadHandler](INFO): Thread cancelled. 2024-04-11T17:54:56.612Z,1712858096.612 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler 2024-04-11T17:54:56.612Z,1712858096.612 [CommandExec ThreadHandler](INFO): Thread cancelled. 2024-04-11T17:54:56.612Z,1712858096.612 [CommandExec](INFO): Join timeout helper Thread ID is 5288 2024-04-11T17:54:56.614Z,1712858096.614 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2024-04-11T17:54:56.614Z,1712858096.614 [controlThread ThreadHandler](INFO): Thread cancelled. 2024-04-11T17:54:56.614Z,1712858096.614 [controlThread](INFO): Join timeout helper Thread ID is 5289 2024-04-11T17:54:56.615Z,1712858096.615 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2024-04-11T17:54:56.616Z,1712858096.616 [controlThread](DEBUG): Uninitializing ControlThread 2024-04-11T17:54:56.616Z,1712858096.616 [AHRS_M2](INFO): Powering down 2024-04-11T17:54:56.688Z,1712858096.688 [NAL9602](INFO): Powering down 2024-04-11T17:54:56.689Z,1712858096.689 [Sonardyne_Nano](INFO): Powering down 2024-04-11T17:54:56.809Z,1712858096.809 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2024-04-11T17:54:56.810Z,1712858096.810 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2024-04-11T17:54:56.810Z,1712858096.810 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2024-04-11T17:54:56.810Z,1712858096.810 [MissionManager](INFO): Uninitializing Mission Default 2024-04-11T17:54:56.811Z,1712858096.811 [Default] Stopped 2024-04-11T17:54:56.811Z,1712858096.811 [Default](DEBUG): Aggregate::uninitialize Default 2024-04-11T17:54:56.811Z,1712858096.811 [Default:B.GoToSurface] Stopped 2024-04-11T17:54:56.811Z,1712858096.811 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2024-04-11T17:54:56.811Z,1712858096.811 [Default:CheckIn] Stopped 2024-04-11T17:54:56.811Z,1712858096.811 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-04-11T17:54:56.811Z,1712858096.811 [Default:CheckIn:C.Wait] Stopped 2024-04-11T17:54:56.811Z,1712858096.811 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-04-11T17:54:56.814Z,1712858096.814 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2024-04-11T17:54:56.814Z,1712858096.814 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2024-04-11T17:54:56.815Z,1712858096.815 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2024-04-11T17:54:56.815Z,1712858096.815 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2024-04-11T17:54:56.815Z,1712858096.815 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2024-04-11T17:54:56.816Z,1712858096.816 [BuoyancyServo](INFO): Powering down 2024-04-11T17:54:56.827Z,1712858096.827 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2024-04-11T17:54:56.827Z,1712858096.827 [ElevatorServo](INFO): Powering down 2024-04-11T17:54:56.828Z,1712858096.828 [MassServo](DEBUG): Uninitialize Mass Servo. 2024-04-11T17:54:56.828Z,1712858096.828 [MassServo](INFO): Powering down 2024-04-11T17:54:56.829Z,1712858096.829 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2024-04-11T17:54:56.829Z,1712858096.829 [RudderServo](INFO): Powering down 2024-04-11T17:54:56.830Z,1712858096.830 [ThrusterHE](DEBUG): Uninitialize Thruster Servo. 2024-04-11T17:54:56.830Z,1712858096.830 [ThrusterHE](INFO): Powering down 2024-04-11T17:54:56.831Z,1712858096.831 [SBIT](DEBUG): Uninitialize SBIT Component. 2024-04-11T17:54:56.831Z,1712858096.831 [IBIT](DEBUG): Uninitialize IBIT Component. 2024-04-11T17:54:56.832Z,1712858096.832 [CBIT](DEBUG): Uninitialize CBIT Component. 2024-04-11T17:54:56.832Z,1712858096.832 [CBIT](DEBUG): Powering off loads. 2024-04-11T17:54:56.843Z,1712858096.843 [CBIT](DEBUG): Disabling WDT. 2024-04-11T17:54:56.855Z,1712858096.855 [CBIT](DEBUG): Opening all GF detection circuits. 2024-04-11T17:54:56.856Z,1712858096.856 [controlThread ThreadHandler](INFO): Thread cancelled. 2024-04-11T17:54:56.909Z,1712858096.909 [DAT ThreadHandler](INFO): Thread cancelled. 2024-04-11T17:54:56.914Z,1712858096.914 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2024-04-11T17:54:56.916Z,1712858096.916 [Onboard ThreadHandler](INFO): Thread cancelled. 2024-04-11T17:54:56.921Z,1712858096.921 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2024-04-11T17:54:56.993Z,1712858096.993 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2024-04-11T17:54:56.997Z,1712858096.997 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2024-04-11T17:54:57.038Z,1712858097.038 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2024-04-11T17:54:57.104Z,1712858097.104 [logger ThreadHandler](INFO): Thread cancelled.