2021-11-17T21:51:20.445Z,1637185880.445 [Supervisor](DEBUG): Initializing supervisor.
2021-11-17T21:51:20.450Z,1637185880.450 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2021-11-17T21:51:20.450Z,1637185880.450 [SyncHandler](INFO): Protected caller Thread ID is 833
2021-11-17T21:51:20.451Z,1637185880.451 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2021-11-17T21:51:20.452Z,1637185880.452 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2021-11-17T21:51:20.452Z,1637185880.452 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 834
2021-11-17T21:51:20.456Z,1637185880.456 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2021-11-17T21:51:20.474Z,1637185880.474 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2021-11-17T21:51:20.475Z,1637185880.475 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2021-11-17T21:51:20.475Z,1637185880.475 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 835
2021-11-17T21:51:20.480Z,1637185880.480 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2021-11-17T21:51:20.481Z,1637185880.481 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2021-11-17T21:51:20.481Z,1637185880.481 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 836
2021-11-17T21:51:20.483Z,1637185880.483 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2021-11-17T21:51:20.484Z,1637185880.484 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2021-11-17T21:51:20.485Z,1637185880.485 [logger ThreadHandler](INFO): Protected caller Thread ID is 837
2021-11-17T21:51:20.488Z,1637185880.488 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2021-11-17T21:51:20.489Z,1637185880.489 [Supervisor](INFO): Looking for Config files in directory: Config/
2021-11-17T21:51:20.493Z,1637185880.493 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2021-11-17T21:51:20.717Z,1637185880.717 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2021-11-17T21:51:20.719Z,1637185880.719 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2021-11-17T21:51:20.800Z,1637185880.800 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2021-11-17T21:51:21.311Z,1637185881.311 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2021-11-17T21:51:21.313Z,1637185881.313 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2021-11-17T21:51:21.629Z,1637185881.629 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2021-11-17T21:51:21.631Z,1637185881.631 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2021-11-17T21:51:21.727Z,1637185881.727 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2021-11-17T21:51:21.727Z,1637185881.727 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2021-11-17T21:51:22.082Z,1637185882.082 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2021-11-17T21:51:22.083Z,1637185882.083 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2021-11-17T21:51:22.277Z,1637185882.277 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2021-11-17T21:51:22.279Z,1637185882.279 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2021-11-17T21:51:22.723Z,1637185882.723 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2021-11-17T21:51:22.724Z,1637185882.724 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2021-11-17T21:51:22.849Z,1637185882.849 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2021-11-17T21:51:22.850Z,1637185882.850 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2021-11-17T21:51:22.931Z,1637185882.931 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2021-11-17T21:51:24.301Z,1637185884.301 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2021-11-17T21:51:24.301Z,1637185884.301 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2021-11-17T21:51:24.652Z,1637185884.652 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2021-11-17T21:51:24.652Z,1637185884.652 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2021-11-17T21:51:24.838Z,1637185884.838 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2021-11-17T21:51:24.840Z,1637185884.840 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2021-11-17T21:51:24.949Z,1637185884.949 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2021-11-17T21:51:24.949Z,1637185884.949 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2021-11-17T21:51:25.097Z,1637185885.097 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2021-11-17T21:51:25.099Z,1637185885.099 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2021-11-17T21:51:25.334Z,1637185885.334 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2021-11-17T21:51:25.336Z,1637185885.336 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2021-11-17T21:51:25.338Z,1637185885.338 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2021-11-17T21:51:25.428Z,1637185885.428 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2021-11-17T21:51:25.513Z,1637185885.513 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2021-11-17T21:51:25.612Z,1637185885.612 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2021-11-17T21:51:25.695Z,1637185885.695 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2021-11-17T21:51:25.789Z,1637185885.789 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2021-11-17T21:51:25.889Z,1637185885.889 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2021-11-17T21:51:26.070Z,1637185886.070 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2021-11-17T21:51:26.147Z,1637185886.147 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2021-11-17T21:51:26.292Z,1637185886.292 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2021-11-17T21:51:26.426Z,1637185886.426 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2021-11-17T21:51:26.539Z,1637185886.539 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg
2021-11-17T21:51:26.795Z,1637185886.795 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2021-11-17T21:51:26.795Z,1637185886.795 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2021-11-17T21:51:26.814Z,1637185886.814 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2021-11-17T21:51:26.886Z,1637185886.886 [VerticalControl](DEBUG): Construct VerticalControl.
2021-11-17T21:51:26.947Z,1637185886.947 [VerticalControl] Loaded
2021-11-17T21:51:26.947Z,1637185886.947 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2021-11-17T21:51:26.950Z,1637185886.950 [HorizontalControl](DEBUG): Construct HorizontalControl.
2021-11-17T21:51:26.988Z,1637185886.988 [HorizontalControl] Loaded
2021-11-17T21:51:26.988Z,1637185886.988 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2021-11-17T21:51:26.991Z,1637185886.991 [SpeedControl](DEBUG): Construct SpeedControl.
2021-11-17T21:51:26.994Z,1637185886.994 [SpeedControl] Loaded
2021-11-17T21:51:26.994Z,1637185886.994 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2021-11-17T21:51:26.997Z,1637185886.997 [LoopControl](DEBUG): Construct LoopControl.
2021-11-17T21:51:26.997Z,1637185886.997 [LoopControl] Loaded
2021-11-17T21:51:26.997Z,1637185886.997 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2021-11-17T21:51:26.998Z,1637185886.998 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2021-11-17T21:51:26.998Z,1637185886.998 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2021-11-17T21:51:27.014Z,1637185887.014 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2021-11-17T21:51:27.016Z,1637185887.016 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2021-11-17T21:51:27.148Z,1637185887.148 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2021-11-17T21:51:27.149Z,1637185887.149 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2021-11-17T21:51:27.325Z,1637185887.325 [BuoyancyServo] Loaded
2021-11-17T21:51:27.326Z,1637185887.326 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2021-11-17T21:51:27.344Z,1637185887.344 [ElevatorServo] Loaded
2021-11-17T21:51:27.345Z,1637185887.345 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2021-11-17T21:51:27.363Z,1637185887.363 [MassServo] Loaded
2021-11-17T21:51:27.363Z,1637185887.363 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2021-11-17T21:51:27.381Z,1637185887.381 [RudderServo] Loaded
2021-11-17T21:51:27.381Z,1637185887.381 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2021-11-17T21:51:27.398Z,1637185887.398 [ThrusterServo] Loaded
2021-11-17T21:51:27.399Z,1637185887.399 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2021-11-17T21:51:27.399Z,1637185887.399 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2021-11-17T21:51:27.400Z,1637185887.400 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2021-11-17T21:51:27.498Z,1637185887.498 [DeadReckonUsingMultipleVelocitySources] Loaded
2021-11-17T21:51:27.499Z,1637185887.499 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2021-11-17T21:51:27.512Z,1637185887.512 [NavChart] Loaded
2021-11-17T21:51:27.512Z,1637185887.512 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2021-11-17T21:51:27.518Z,1637185887.518 [UniversalFixResidualReporter] Loaded
2021-11-17T21:51:27.518Z,1637185887.518 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2021-11-17T21:51:27.518Z,1637185887.518 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2021-11-17T21:51:27.519Z,1637185887.519 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2021-11-17T21:51:27.602Z,1637185887.602 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2021-11-17T21:51:27.602Z,1637185887.602 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2021-11-17T21:51:28.290Z,1637185888.290 [AHRS_M2] Loaded
2021-11-17T21:51:28.290Z,1637185888.290 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2021-11-17T21:51:29.072Z,1637185889.072 [BPC1] Loaded
2021-11-17T21:51:29.072Z,1637185889.072 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2021-11-17T21:51:29.092Z,1637185889.092 [Depth_Keller] Loaded
2021-11-17T21:51:29.092Z,1637185889.092 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2021-11-17T21:51:29.097Z,1637185889.097 [DropWeight] Loaded
2021-11-17T21:51:29.097Z,1637185889.097 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2021-11-17T21:51:29.155Z,1637185889.155 [NAL9602] Loaded
2021-11-17T21:51:29.156Z,1637185889.156 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2021-11-17T21:51:29.185Z,1637185889.185 [Onboard] Loaded
2021-11-17T21:51:29.185Z,1637185889.185 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2021-11-17T21:51:29.186Z,1637185889.186 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 408C64E0
2021-11-17T21:51:29.186Z,1637185889.186 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 922
2021-11-17T21:51:29.199Z,1637185889.199 [Power24vConverter] Loaded
2021-11-17T21:51:29.199Z,1637185889.199 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2021-11-17T21:51:29.213Z,1637185889.213 [Radio_Surface] Loaded
2021-11-17T21:51:29.214Z,1637185889.214 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2021-11-17T21:51:29.214Z,1637185889.214 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408F64E0
2021-11-17T21:51:29.215Z,1637185889.215 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 923
2021-11-17T21:51:29.295Z,1637185889.295 [DAT] Loaded
2021-11-17T21:51:29.296Z,1637185889.296 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread.
2021-11-17T21:51:29.296Z,1637185889.296 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2021-11-17T21:51:29.297Z,1637185889.297 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2021-11-17T21:51:29.370Z,1637185889.370 [DepthRateCalculator] Loaded
2021-11-17T21:51:29.370Z,1637185889.370 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2021-11-17T21:51:29.375Z,1637185889.375 [PitchRateCalculator] Loaded
2021-11-17T21:51:29.375Z,1637185889.375 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2021-11-17T21:51:29.384Z,1637185889.384 [SpeedCalculator] Loaded
2021-11-17T21:51:29.385Z,1637185889.385 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2021-11-17T21:51:29.398Z,1637185889.398 [TempGradientCalculator] Loaded
2021-11-17T21:51:29.398Z,1637185889.398 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2021-11-17T21:51:29.403Z,1637185889.403 [YawRateCalculator] Loaded
2021-11-17T21:51:29.403Z,1637185889.403 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2021-11-17T21:51:29.443Z,1637185889.443 [ElevatorOffsetCalculator] Loaded
2021-11-17T21:51:29.443Z,1637185889.443 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2021-11-17T21:51:29.444Z,1637185889.444 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2021-11-17T21:51:29.444Z,1637185889.444 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2021-11-17T21:51:30.118Z,1637185890.118 [CANONSampler] Loaded
2021-11-17T21:51:30.118Z,1637185890.118 [ComponentRegistry](DEBUG): SyncComponent "CANONSampler" handled in the control thread.
2021-11-17T21:51:30.176Z,1637185890.176 [CTD_Seabird] Loaded
2021-11-17T21:51:30.177Z,1637185890.177 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2021-11-17T21:51:30.178Z,1637185890.178 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 409AB4E0
2021-11-17T21:51:30.178Z,1637185890.178 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 924
2021-11-17T21:51:30.198Z,1637185890.198 [PAR_Licor] Loaded
2021-11-17T21:51:30.198Z,1637185890.198 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2021-11-17T21:51:30.230Z,1637185890.230 [WetLabsBB2FL] Loaded
2021-11-17T21:51:30.230Z,1637185890.230 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2021-11-17T21:51:30.231Z,1637185890.231 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 409DB4E0
2021-11-17T21:51:30.232Z,1637185890.232 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 925
2021-11-17T21:51:30.232Z,1637185890.232 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2021-11-17T21:51:30.233Z,1637185890.233 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2021-11-17T21:51:30.275Z,1637185890.275 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2021-11-17T21:51:30.276Z,1637185890.276 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2021-11-17T21:51:30.648Z,1637185890.648 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2021-11-17T21:51:30.650Z,1637185890.650 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2021-11-17T21:51:30.825Z,1637185890.825 [SBIT](DEBUG): Construct Startup Built In Test.
2021-11-17T21:51:30.834Z,1637185890.834 [SBIT] Loaded
2021-11-17T21:51:30.835Z,1637185890.835 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2021-11-17T21:51:30.837Z,1637185890.837 [IBIT](DEBUG): Construct Initiated Built In Test.
2021-11-17T21:51:30.851Z,1637185890.851 [IBIT] Loaded
2021-11-17T21:51:30.851Z,1637185890.851 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2021-11-17T21:51:30.857Z,1637185890.857 [CBIT](DEBUG): Construct Continuous Built In Test.
2021-11-17T21:51:30.958Z,1637185890.958 [CBIT] Loaded
2021-11-17T21:51:30.959Z,1637185890.959 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2021-11-17T21:51:30.959Z,1637185890.959 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2021-11-17T21:51:30.960Z,1637185890.960 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2021-11-17T21:51:31.076Z,1637185891.076 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2021-11-17T21:51:31.083Z,1637185891.083 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2021-11-17T21:51:31.086Z,1637185891.086 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2021-11-17T21:51:31.096Z,1637185891.096 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2021-11-17T21:51:31.097Z,1637185891.097 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B104E0
2021-11-17T21:51:31.097Z,1637185891.097 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 926
2021-11-17T21:51:31.102Z,1637185891.102 [Supervisor](INFO): Main Thread ID is 829
2021-11-17T21:51:31.102Z,1637185891.102 [Supervisor](DEBUG): Running supervisor.
2021-11-17T21:51:31.103Z,1637185891.103 [CommandExec ThreadHandler](INFO): Handler Thread ID is 927
2021-11-17T21:51:31.103Z,1637185891.103 [CommandExec](INFO): Initializing the command executive.
2021-11-17T21:51:31.105Z,1637185891.105 [CommandLine ThreadHandler](INFO): Handler Thread ID is 928
2021-11-17T21:51:31.107Z,1637185891.107 [controlThread ThreadHandler](INFO): Handler Thread ID is 929
2021-11-17T21:51:31.107Z,1637185891.107 [controlThread](DEBUG): Initializing ControlThread
2021-11-17T21:51:31.108Z,1637185891.108 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2021-11-17T21:51:31.111Z,1637185891.111 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2021-11-17T21:51:31.112Z,1637185891.112 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2021-11-17T21:51:31.112Z,1637185891.112 [LoopControl](DEBUG): Initialize LoopControlComponent.
2021-11-17T21:51:31.114Z,1637185891.114 [NavChart](DEBUG): Initialize NavChart Navigation.
2021-11-17T21:51:31.115Z,1637185891.115 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2021-11-17T21:51:31.119Z,1637185891.119 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2021-11-17T21:51:31.119Z,1637185891.119 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2021-11-17T21:51:31.120Z,1637185891.120 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2021-11-17T21:51:31.120Z,1637185891.120 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2021-11-17T21:51:31.120Z,1637185891.120 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2021-11-17T21:51:31.121Z,1637185891.121 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2021-11-17T21:51:31.125Z,1637185891.125 [SBIT](INFO): Initialize SBIT Component.
2021-11-17T21:51:31.126Z,1637185891.126 [SBIT](IMPORTANT): git: 2021-10-11a
2021-11-17T21:51:31.126Z,1637185891.126 [SBIT](INFO): git hash: 36f3a97de7a122c995f034a375e3cefac6406048
2021-11-17T21:51:31.126Z,1637185891.126 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2021-11-17T21:51:31.127Z,1637185891.127 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #1 PREEMPT Wed Mar 17 08:23:48 PDT 2021
2021-11-17T21:51:31.129Z,1637185891.129 [SBIT](INFO): Beginning SBIT in 84.000000 seconds.
2021-11-17T21:51:31.129Z,1637185891.129 [IBIT](INFO): Initialize IBIT Component.
2021-11-17T21:51:31.130Z,1637185891.130 [CBIT](DEBUG): Initialize CBIT Component.
2021-11-17T21:51:31.131Z,1637185891.131 [logger ThreadHandler](INFO): Handler Thread ID is 930
2021-11-17T21:51:31.141Z,1637185891.141 [CBIT](DEBUG): Initialized mux pins.
2021-11-17T21:51:31.141Z,1637185891.141 [CBIT](DEBUG): Initializing the watchdog timer.
2021-11-17T21:51:31.149Z,1637185891.149 [Onboard ThreadHandler](INFO): Handler Thread ID is 931
2021-11-17T21:51:31.165Z,1637185891.165 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2021-11-17T21:51:31.166Z,1637185891.166 [CBIT](DEBUG): Initializing heartbeat.
2021-11-17T21:51:31.171Z,1637185891.171 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 932
2021-11-17T21:51:31.181Z,1637185891.181 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 933
2021-11-17T21:51:31.183Z,1637185891.183 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2021-11-17T21:51:31.186Z,1637185891.186 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 935
2021-11-17T21:51:31.190Z,1637185891.190 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 937
2021-11-17T21:51:31.190Z,1637185891.190 [WetLabsBB2FL](INFO): Powering up
2021-11-17T21:51:31.199Z,1637185891.199 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2021-11-17T21:51:31.199Z,1637185891.199 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2021-11-17T21:51:31.199Z,1637185891.199 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2021-11-17T21:51:31.200Z,1637185891.200 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2021-11-17T21:51:31.200Z,1637185891.200 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2021-11-17T21:51:31.200Z,1637185891.200 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2021-11-17T21:51:31.200Z,1637185891.200 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2021-11-17T21:51:31.200Z,1637185891.200 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2021-11-17T21:51:31.201Z,1637185891.201 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2021-11-17T21:51:31.201Z,1637185891.201 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2021-11-17T21:51:31.201Z,1637185891.201 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2021-11-17T21:51:31.202Z,1637185891.202 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2021-11-17T21:51:31.202Z,1637185891.202 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2021-11-17T21:51:31.202Z,1637185891.202 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2021-11-17T21:51:31.202Z,1637185891.202 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2021-11-17T21:51:31.202Z,1637185891.202 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2021-11-17T21:51:31.237Z,1637185891.237 [CBIT](DEBUG): Deactivating GF circuits.
2021-11-17T21:51:31.237Z,1637185891.237 [CBIT](DEBUG): Deactivating emergency mode.
2021-11-17T21:51:31.273Z,1637185891.273 [CBIT](DEBUG): Backplane powered.
2021-11-17T21:51:31.274Z,1637185891.274 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2021-11-17T21:51:31.300Z,1637185891.300 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2021-11-17T21:51:31.356Z,1637185891.356 [MissionManager](DEBUG):
2021-11-17T21:51:31.357Z,1637185891.357 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2021-11-17T21:51:31.432Z,1637185891.432 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2021-11-17T21:51:31.445Z,1637185891.445 [Default:A.Wait](DEBUG): Construct Wait.
2021-11-17T21:51:31.447Z,1637185891.447 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2021-11-17T21:51:31.467Z,1637185891.467 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2021-11-17T21:51:31.494Z,1637185891.494 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2021-11-17T21:51:31.499Z,1637185891.499 [Default:E.Execute](DEBUG): Construct Execute.
2021-11-17T21:51:31.515Z,1637185891.515 [MissionManager](DEBUG):
0
Wait a moment to see if the scheduler starts a new mission before
starting to actually run Default.
13
Burn on
Dropped weight due to communications timeout.
1
Default mission has been running for
Restarting logs and Default mission.
restart logs
2021-11-17T21:51:31.520Z,1637185891.520 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,DAT,CANONSampler,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2021-11-17T21:51:31.539Z,1637185891.539 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2021-11-17T21:51:31.585Z,1637185891.585 [Radio_Surface](INFO): Powering up
2021-11-17T21:51:31.723Z,1637185891.723 [Power24vConverter](INFO): Powering up.
2021-11-17T21:51:31.724Z,1637185891.724 [DAT](INFO): Powering up
2021-11-17T21:51:31.724Z,1637185891.724 [DAT](DEBUG): Initializing DAT.
2021-11-17T21:51:31.741Z,1637185891.741 [CANONSampler](INFO): Powering down
2021-11-17T21:51:31.807Z,1637185891.807 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2021-11-17T21:51:31.813Z,1637185891.813 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2021-11-17T21:51:31.814Z,1637185891.814 [ElevatorServo](DEBUG): Initializing EZServoServo.
2021-11-17T21:51:31.821Z,1637185891.821 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2021-11-17T21:51:31.822Z,1637185891.822 [MassServo](DEBUG): Initializing EZServoServo.
2021-11-17T21:51:31.829Z,1637185891.829 [MassServo](DEBUG): Initializing MassServo.
2021-11-17T21:51:31.830Z,1637185891.830 [RudderServo](DEBUG): Initializing EZServoServo.
2021-11-17T21:51:31.837Z,1637185891.837 [RudderServo](DEBUG): Initializing RudderServo.
2021-11-17T21:51:31.838Z,1637185891.838 [ThrusterServo](DEBUG): Initializing EZServoServo.
2021-11-17T21:51:31.845Z,1637185891.845 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2021-11-17T21:51:31.962Z,1637185891.962 [DropWeight](CRITICAL): DROP WEIGHT MISSING.
2021-11-17T21:51:31.962Z,1637185891.962 [DropWeight] Hardware Fault, FailCount= 1
2021-11-17T21:51:31.962Z,1637185891.962 [DropWeight](ERROR): Hardware Fault
2021-11-17T21:51:32.048Z,1637185892.048 [CommandExec](FAULT): Scheduling is paused
2021-11-17T21:51:32.048Z,1637185892.048 [CBIT](INFO): Critical error at 20211117T215131
2021-11-17T21:51:32.048Z,1637185892.048 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2021-11-17T21:51:32.059Z,1637185892.059 [CBIT](ERROR): Hardware Fault in component: DropWeight
2021-11-17T21:51:32.060Z,1637185892.060 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2021-11-17T21:51:32.661Z,1637185892.661 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2021-11-17T21:51:32.661Z,1637185892.661 [RudderServo](FAULT): Rudder failed to initialize
2021-11-17T21:51:32.661Z,1637185892.661 [RudderServo] Communications Fault, FailCount= 1
2021-11-17T21:51:32.661Z,1637185892.661 [RudderServo](ERROR): Communications Fault
2021-11-17T21:51:32.766Z,1637185892.766 [CBIT](INFO): Critical error at 20211117T215132
2021-11-17T21:51:32.769Z,1637185892.769 [CBIT](ERROR): Communications Fault in component: RudderServo
2021-11-17T21:51:32.942Z,1637185892.942 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2021-11-17T21:51:32.942Z,1637185892.942 [RudderServo](INFO): Powering down
2021-11-17T21:51:33.297Z,1637185893.297 [WetLabsBB2FL](INFO): Powering down
2021-11-17T21:51:33.606Z,1637185893.606 [RudderServo](DEBUG): Initializing EZServoServo.
2021-11-17T21:51:33.726Z,1637185893.726 [RudderServo](DEBUG): Initializing RudderServo.
2021-11-17T21:51:33.731Z,1637185893.731 [CBIT](INFO): Clearing failed state for component RudderServo
2021-11-17T21:51:33.731Z,1637185893.731 [RudderServo] No Fault, FailCount= 1
2021-11-17T21:51:43.291Z,1637185903.291 [DAT](INFO): DAT read:
2021-11-17T21:51:43.292Z,1637185903.292 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series
2021-11-17T21:51:44.904Z,1637185904.904 [DAT](INFO): DAT read: MF Frequency Band
2021-11-17T21:51:45.308Z,1637185905.308 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.14.2
2021-11-17T21:51:45.308Z,1637185905.308 [DAT](INFO): DAT read: Nov 17 2021 21:50:58
2021-11-17T21:51:46.115Z,1637185906.115 [DAT](INFO): DAT read: Features enabled [Bearing]
2021-11-17T21:51:46.117Z,1637185906.117 [DAT](INFO): DAT read: CONNECT 01200 bits/sec 1 of 4, Rate 1/2 CC
2021-11-17T21:51:46.117Z,1637185906.117 [DAT](INFO): commRate: 1200
2021-11-17T21:51:48.135Z,1637185908.135 [DAT](INFO): entering command mode
2021-11-17T21:51:48.539Z,1637185908.539 [DAT](INFO): DAT read:
2021-11-17T21:51:48.539Z,1637185908.539 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-17T21:51:48.943Z,1637185908.943 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-17T21:51:49.347Z,1637185909.347 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-17T21:51:49.759Z,1637185909.759 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-17T21:51:50.155Z,1637185910.155 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-17T21:51:50.559Z,1637185910.559 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-17T21:51:50.963Z,1637185910.963 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-17T21:51:51.367Z,1637185911.367 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-17T21:51:51.771Z,1637185911.771 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-17T21:51:52.175Z,1637185912.175 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-17T21:51:52.583Z,1637185912.583 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-17T21:51:52.983Z,1637185912.983 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-17T21:51:53.387Z,1637185913.387 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-17T21:51:53.791Z,1637185913.791 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-17T21:51:54.195Z,1637185914.195 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-17T21:51:54.611Z,1637185914.611 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-17T21:51:55.003Z,1637185915.003 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-17T21:51:55.423Z,1637185915.423 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-17T21:51:55.811Z,1637185915.811 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-17T21:51:56.225Z,1637185916.225 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-17T21:51:56.619Z,1637185916.619 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-17T21:51:57.023Z,1637185917.023 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-17T21:51:57.427Z,1637185917.427 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-17T21:51:57.838Z,1637185917.838 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-17T21:51:58.235Z,1637185918.235 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-17T21:51:58.643Z,1637185918.643 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-17T21:51:59.043Z,1637185919.043 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-17T21:51:59.451Z,1637185919.451 [NAL9602](INFO): Powering up NAL9602
2021-11-17T21:51:59.452Z,1637185919.452 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-17T21:51:59.851Z,1637185919.851 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-17T21:52:00.255Z,1637185920.255 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-17T21:52:00.659Z,1637185920.659 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-17T21:52:01.063Z,1637185921.063 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-17T21:52:01.467Z,1637185921.467 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-17T21:52:01.871Z,1637185921.871 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-17T21:52:02.275Z,1637185922.275 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-17T21:52:02.679Z,1637185922.679 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-17T21:52:03.089Z,1637185923.089 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-17T21:52:03.487Z,1637185923.487 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-17T21:52:03.487Z,1637185923.487 [DAT](FAULT): failed to enter command mode
2021-11-17T21:52:03.891Z,1637185923.891 [DAT](INFO): entering command mode
2021-11-17T21:52:04.295Z,1637185924.295 [DAT](INFO): DAT read: user:1>
2021-11-17T21:52:04.296Z,1637185924.296 [DAT](INFO): DAT read: Command '+++' not found
2021-11-17T21:52:04.296Z,1637185924.296 [DAT](INFO): DAT read: Error
2021-11-17T21:52:04.297Z,1637185924.297 [DAT](INFO): setting verbose to 3
2021-11-17T21:52:04.705Z,1637185924.705 [DAT](INFO): DAT read: user:2>
2021-11-17T21:52:04.706Z,1637185924.706 [DAT](INFO): DAT read: Verbose | 3
2021-11-17T21:52:04.706Z,1637185924.706 [DAT](INFO): set verbose to 3
2021-11-17T21:52:04.707Z,1637185924.707 [DAT](INFO): setting DatVerbose to 27440
2021-11-17T21:52:05.103Z,1637185925.103 [DAT](INFO): DAT read: user:3>
2021-11-17T21:52:05.104Z,1637185925.104 [DAT](INFO): DAT read: DatVerbose | 27440
2021-11-17T21:52:05.104Z,1637185925.104 [DAT](INFO): set DatVerbose to 27440
2021-11-17T21:52:05.105Z,1637185925.105 [DAT](INFO): setting transmit power to 8
2021-11-17T21:52:05.507Z,1637185925.507 [DAT](INFO): DAT read: user:4>
2021-11-17T21:52:05.508Z,1637185925.508 [DAT](INFO): DAT read: TxPower | 8 (Max)
2021-11-17T21:52:05.509Z,1637185925.509 [DAT](INFO): set transmit power to 8
2021-11-17T21:52:05.509Z,1637185925.509 [DAT](INFO): setting local address to 7
2021-11-17T21:52:05.911Z,1637185925.911 [DAT](INFO): DAT read: user:5>
2021-11-17T21:52:05.912Z,1637185925.912 [DAT](INFO): DAT read: LocalAddr | 7
2021-11-17T21:52:05.912Z,1637185925.912 [DAT](INFO): set local address to 7
2021-11-17T21:52:10.355Z,1637185930.355 [NAL9602](INFO): NAL9602 initialized
2021-11-17T21:52:36.590Z,1637185956.590 [CommandExec](IMPORTANT): got command failComponent
2021-11-17T21:52:36.590Z,1637185956.590 [CommandExec](IMPORTANT): Failed components:
2021-11-17T21:52:36.590Z,1637185956.590 [CommandExec](IMPORTANT): DropWeight: Hardware Fault
2021-11-17T21:52:40.972Z,1637185960.972 [CommandExec](IMPORTANT): got command show stack
2021-11-17T21:52:40.972Z,1637185960.972 [CommandExec](IMPORTANT): Behavior Stack:
2021-11-17T21:52:40.972Z,1637185960.972 [MissionManager](IMPORTANT): Mission loaded, but not running.
2021-11-17T21:52:55.632Z,1637185975.632 [SBIT](IMPORTANT): Beginning Startup BIT
2021-11-17T21:52:55.636Z,1637185975.636 [CBIT](IMPORTANT): Beginning ground fault scan
2021-11-17T21:53:03.192Z,1637185983.192 [CommandExec](IMPORTANT): got command maintain sensor NAL9602.latitude_fix 36.799999 degree
2021-11-17T21:53:03.195Z,1637185983.195 [ComponentRegistry](DEBUG): SyncComponent "Maintain_NAL9602.latitude_fix" handled in the control thread.
2021-11-17T21:53:03.196Z,1637185983.196 [CommandExec](IMPORTANT): got command maintain sensor NAL9602.longitude_fix -121.900002 degree
2021-11-17T21:53:03.199Z,1637185983.199 [ComponentRegistry](DEBUG): SyncComponent "Maintain_NAL9602.longitude_fix" handled in the control thread.
2021-11-17T21:53:03.336Z,1637185983.336 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,DAT,CANONSampler,PAR_Licor,Depth_Keller,PAR_Licor,Maintain_NAL9602.latitude_fix,Maintain_NAL9602.longitude_fix,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2021-11-17T21:53:03.708Z,1637185983.708 [DeadReckonUsingMultipleVelocitySources](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2021-11-17T21:53:03.708Z,1637185983.708 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2021-11-17T21:53:03.708Z,1637185983.708 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-11-17T21:53:03.750Z,1637185983.750 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-11-17T21:53:04.158Z,1637185984.158 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-11-17T21:53:04.158Z,1637185984.158 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2021-11-17T21:53:04.912Z,1637185984.912 [DeadReckonUsingMultipleVelocitySources](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2021-11-17T21:53:04.912Z,1637185984.912 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2021-11-17T21:53:04.912Z,1637185984.912 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-11-17T21:53:05.038Z,1637185985.038 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-11-17T21:53:05.479Z,1637185985.479 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-11-17T21:53:05.479Z,1637185985.479 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2021-11-17T21:53:06.142Z,1637185986.142 [DeadReckonUsingMultipleVelocitySources](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2021-11-17T21:53:06.142Z,1637185986.142 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2021-11-17T21:53:06.142Z,1637185986.142 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-11-17T21:53:06.153Z,1637185986.153 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-11-17T21:53:06.585Z,1637185986.585 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-11-17T21:53:06.586Z,1637185986.586 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2021-11-17T21:53:06.587Z,1637185986.587 [CBIT](ERROR): Ground fault scan returned out of bounds value. Re-running scan.
2021-11-17T21:53:06.956Z,1637185986.956 [CBIT](IMPORTANT): Beginning ground fault scan
2021-11-17T21:53:07.332Z,1637185987.332 [DeadReckonUsingMultipleVelocitySources](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2021-11-17T21:53:07.332Z,1637185987.332 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2021-11-17T21:53:07.332Z,1637185987.332 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-11-17T21:53:07.343Z,1637185987.343 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-11-17T21:53:07.798Z,1637185987.798 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-11-17T21:53:07.798Z,1637185987.798 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2021-11-17T21:53:08.543Z,1637185988.543 [DeadReckonUsingMultipleVelocitySources](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2021-11-17T21:53:08.544Z,1637185988.544 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2021-11-17T21:53:08.544Z,1637185988.544 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-11-17T21:53:08.555Z,1637185988.555 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-11-17T21:53:08.970Z,1637185988.970 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-11-17T21:53:08.970Z,1637185988.970 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2021-11-17T21:53:09.752Z,1637185989.752 [DeadReckonUsingMultipleVelocitySources](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2021-11-17T21:53:09.752Z,1637185989.752 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6
2021-11-17T21:53:09.752Z,1637185989.752 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-11-17T21:53:09.794Z,1637185989.794 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-11-17T21:53:10.171Z,1637185990.171 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-11-17T21:53:10.171Z,1637185990.171 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6
2021-11-17T21:53:10.992Z,1637185990.992 [DeadReckonUsingMultipleVelocitySources](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2021-11-17T21:53:10.992Z,1637185990.992 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7
2021-11-17T21:53:10.992Z,1637185990.992 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-11-17T21:53:11.210Z,1637185991.210 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-11-17T21:53:11.488Z,1637185991.488 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-11-17T21:53:11.488Z,1637185991.488 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7
2021-11-17T21:53:12.184Z,1637185992.184 [DeadReckonUsingMultipleVelocitySources](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2021-11-17T21:53:12.184Z,1637185992.184 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8
2021-11-17T21:53:12.184Z,1637185992.184 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-11-17T21:53:12.287Z,1637185992.287 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-11-17T21:53:12.706Z,1637185992.706 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-11-17T21:53:12.706Z,1637185992.706 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8
2021-11-17T21:53:13.387Z,1637185993.387 [DeadReckonUsingMultipleVelocitySources](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2021-11-17T21:53:13.387Z,1637185993.387 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 9
2021-11-17T21:53:13.387Z,1637185993.387 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-11-17T21:53:13.494Z,1637185993.494 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-11-17T21:53:13.958Z,1637185993.958 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-11-17T21:53:13.958Z,1637185993.958 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 9
2021-11-17T21:53:14.604Z,1637185994.604 [DeadReckonUsingMultipleVelocitySources](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2021-11-17T21:53:14.604Z,1637185994.604 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 10
2021-11-17T21:53:14.604Z,1637185994.604 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-11-17T21:53:14.702Z,1637185994.702 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-11-17T21:53:15.102Z,1637185995.102 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-11-17T21:53:15.102Z,1637185995.102 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 10
2021-11-17T21:53:15.838Z,1637185995.838 [DeadReckonUsingMultipleVelocitySources](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2021-11-17T21:53:15.838Z,1637185995.838 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 11
2021-11-17T21:53:15.838Z,1637185995.838 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-11-17T21:53:15.958Z,1637185995.958 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-11-17T21:53:16.446Z,1637185996.446 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-11-17T21:53:16.446Z,1637185996.446 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 11
2021-11-17T21:53:16.930Z,1637185996.930 [CommandExec](IMPORTANT): got command set NAL9602.time_fix 1637186048.000000 second
2021-11-17T21:53:18.798Z,1637185998.798 [CBIT](ERROR): Ground fault scan returned out of bounds value. Re-running scan.
2021-11-17T21:53:19.142Z,1637185999.142 [CBIT](IMPORTANT): Beginning ground fault scan
2021-11-17T21:53:30.002Z,1637186010.002 [CBIT](ERROR): Ground fault scan returned out of bounds value. Re-running scan.
2021-11-17T21:53:30.002Z,1637186010.002 [CBIT](IMPORTANT): Ground fault scan returned out of bounds value in succession 3 times. Will re-run scan on normal schedule.
2021-11-17T21:53:37.220Z,1637186017.220 [CommandExec](IMPORTANT): got command ! echo 1 > /dev/loadB6
2021-11-17T21:53:49.812Z,1637186029.812 [SBIT](IMPORTANT): SBIT PASSED
2021-11-17T21:53:49.812Z,1637186029.812 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2021-11-17T21:53:49.817Z,1637186029.817 [SBIT](IMPORTANT): AMEcho.loadAtStartup=0 bool;
2021-11-17T21:53:49.817Z,1637186029.817 [SBIT](IMPORTANT): BuoyancyServo.fastPumpDepth=6 meter;
2021-11-17T21:53:49.818Z,1637186029.818 [SBIT](IMPORTANT): CANONSampler.loadAtStartup=1 bool;
2021-11-17T21:53:49.818Z,1637186029.818 [SBIT](IMPORTANT): DAT.baud=9600 bit_per_second;
2021-11-17T21:53:49.818Z,1637186029.818 [SBIT](IMPORTANT): DAT.loadAtStartup=1 bool;
2021-11-17T21:53:49.818Z,1637186029.818 [SBIT](IMPORTANT): DAT.sbdAddress=1 enum;
2021-11-17T21:53:49.818Z,1637186029.818 [SBIT](IMPORTANT): DAT.surfaceThreshold=0 meter;
2021-11-17T21:53:49.818Z,1637186029.818 [SBIT](IMPORTANT): DAT.verbosity=3 count;
2021-11-17T21:53:49.818Z,1637186029.818 [SBIT](IMPORTANT): DataOverHttps.loadAtStartup=0 bool;
2021-11-17T21:53:49.818Z,1637186029.818 [SBIT](IMPORTANT): ESPComponent.loadAtStartup=0 bool;
2021-11-17T21:53:49.819Z,1637186029.819 [SBIT](IMPORTANT): ESPComponent.simulateHardware=1 bool;
2021-11-17T21:53:49.819Z,1637186029.819 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=296 cubic_centimeter;
2021-11-17T21:53:49.819Z,1637186029.819 [SBIT](IMPORTANT): VerticalControl.massDefault=-16 millimeter;
2021-11-17T21:53:49.819Z,1637186029.819 [SBIT](IMPORTANT): VerticalControl.surfaceThreshold=2 meter;
2021-11-17T21:53:50.203Z,1637186030.203 [MissionManager](IMPORTANT): Started mission Startup
2021-11-17T21:53:50.203Z,1637186030.203 [Startup] Running Loop=1
2021-11-17T21:53:50.203Z,1637186030.203 [Startup](DEBUG): Aggregate::initialize Startup
2021-11-17T21:53:50.203Z,1637186030.203 [Startup:A.GoToSurface] Running Loop=1
2021-11-17T21:53:50.203Z,1637186030.203 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2021-11-17T21:53:50.204Z,1637186030.204 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2021-11-17T21:53:50.205Z,1637186030.205 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2021-11-17T21:53:50.205Z,1637186030.205 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2021-11-17T21:53:50.206Z,1637186030.206 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2021-11-17T21:53:50.206Z,1637186030.206 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2021-11-17T21:53:50.207Z,1637186030.207 [Startup:StartupSatComms] Running Loop=1
2021-11-17T21:53:50.208Z,1637186030.208 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2021-11-17T21:53:50.208Z,1637186030.208 [Startup:StartupSatComms:A] Running Loop=1
2021-11-17T21:53:50.604Z,1637186030.604 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2021-11-17T21:53:50.604Z,1637186030.604 [Startup:StartupSatComms:A] Stopped
2021-11-17T21:53:50.604Z,1637186030.604 [Startup:StartupSatComms:B] Running Loop=1
2021-11-17T21:53:51.010Z,1637186031.010 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2021-11-17T21:53:52.252Z,1637186032.252 [DAT](INFO): #Outgoing data=1
2021-11-17T21:53:52.253Z,1637186032.253 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2021-11-17T21:53:52.410Z,1637186032.410 [DAT](INFO): setting remote address to 1
2021-11-17T21:53:52.727Z,1637186032.727 [DAT](INFO): DAT read: user:6>
2021-11-17T21:53:52.728Z,1637186032.728 [DAT](INFO): DAT read: RemoteAddr | 1
2021-11-17T21:53:52.728Z,1637186032.728 [DAT](INFO): set remote address to 1
2021-11-17T21:53:52.729Z,1637186032.729 [DAT](INFO): entering online mode
2021-11-17T21:53:53.139Z,1637186033.139 [DAT](INFO): DAT read: user:7>
2021-11-17T21:53:53.140Z,1637186033.140 [DAT](INFO): DAT read:
2021-11-17T21:53:53.142Z,1637186033.142 [DAT](INFO): DAT read: CONNECT 01200 bits/sec 1 of 4, Rate 1/2 CC
2021-11-17T21:53:53.143Z,1637186033.143 [DAT](INFO): commRate: 1200
2021-11-17T21:53:53.143Z,1637186033.143 [DAT](INFO): online mode acknowledged
2021-11-17T21:53:53.143Z,1637186033.143 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2021-11-17T21:53:56.808Z,1637186036.808 [DAT](INFO): DAT read: Forwarding Delay UpTx time:21:53:12.6391
2021-11-17T21:53:56.809Z,1637186036.809 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2021-11-17T21:54:06.524Z,1637186046.524 [DAT](INFO): DAT read: Rx Time:21:53:21.5694
2021-11-17T21:54:06.524Z,1637186046.524 [DAT](INFO): received an acoustic signal
2021-11-17T21:54:06.927Z,1637186046.927 [DAT](FAULT): Ack receipt timeout failure.
2021-11-17T21:54:06.927Z,1637186046.927 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER
2021-11-17T21:54:00.296Z,1637186040.296 [DAT](INFO): DAT read: 21:53:21.5694 LVL= 32752, 32753, 32754, 32755, AGC= 89, IDX= 440,-0.07, 1.739, 1.687, 1.671, 1.667, PHS= 0.068, 0.064,-0.011, RAW= 32.0, -29.3, CAL= 34.8, -30.8, ROT= 175.2, 30.8
2021-11-17T21:54:00.299Z,1637186040.299 [DAT](INFO): got valid direction response:
21:53:21.5694 LVL= 32752, 32753, 32754, 32755, AGC= 89, IDX= 440,-0.07, 1.739, 1.687, 1.671, 1.667, PHS= 0.068, 0.064,-0.011, RAW= 32.0, -29.3, CAL= 34.8, -30.8, ROT= 175.2, 30.8
2021-11-17T21:54:00.300Z,1637186040.300 [DAT](INFO): DAT read:
2021-11-17T21:54:00.301Z,1637186040.301 [DAT](INFO): DAT read: DATA(0002):~~
2021-11-17T21:54:00.301Z,1637186040.301 [DAT](INFO): Got DATA 2
2021-11-17T21:54:00.302Z,1637186040.302 [DAT](INFO): DAT read: Source:001 Destination:007
2021-11-17T21:54:00.302Z,1637186040.302 [DAT](INFO): Got Src/Dest after DATA
2021-11-17T21:54:00.302Z,1637186040.302 [DAT](INFO): DATA Src=1, Dst=7
2021-11-17T21:54:00.336Z,1637186040.336 [DAT](INFO): DAT read: CRC:Pass MPD:03.6 PSNR:12.3 AGC:88 SPD:+0.0 CCERR:011
2021-11-17T21:54:00.336Z,1637186040.336 [DAT](INFO): Got CRC:Pass
2021-11-17T21:54:00.336Z,1637186040.336 [DAT](INFO): Got CRC:Pass
2021-11-17T21:54:00.336Z,1637186040.336 [DAT](INFO): Incoming data is intended for us
2021-11-17T21:54:00.336Z,1637186040.336 [DAT](INFO): Got ack
2021-11-17T21:54:00.337Z,1637186040.337 [DAT](INFO): DAT read:
2021-11-17T21:54:00.337Z,1637186040.337 [DAT](INFO): DAT read:
2021-11-17T21:54:00.961Z,1637186040.961 [DAT](INFO): #Outgoing data=1
2021-11-17T21:54:00.962Z,1637186040.962 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2021-11-17T21:54:00.962Z,1637186040.962 [DAT](INFO): #Rx 1: Read direction message, but no range.
2021-11-17T21:54:00.964Z,1637186040.964 [DAT](INFO): direction in vehicle frame: [ -0.855947 forward, 0.071876 starboard, 0.512043 keelward ]
2021-11-17T21:54:01.072Z,1637186041.072 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2021-11-17T21:54:04.854Z,1637186044.854 [DAT](INFO): DAT read: Forwarding Delay UpTx time:21:53:27.5888
2021-11-17T21:54:04.854Z,1637186044.854 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2021-11-17T21:54:14.078Z,1637186054.078 [DAT](INFO): DAT read: Rx Time:21:53:36.5197
2021-11-17T21:54:14.079Z,1637186054.079 [DAT](INFO): received an acoustic signal
2021-11-17T21:54:14.888Z,1637186054.888 [DAT](FAULT): Ack receipt timeout failure.
2021-11-17T21:54:14.888Z,1637186054.888 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER
2021-11-17T21:54:15.308Z,1637186055.308 [DAT](INFO): DAT read: 21:53:36.5197 LVL= 32752, 32753, 32754, 32755, AGC= 90, IDX= 188, 0.43,-3.136, 3.098, 3.076, 3.074, PHS= 0.069, 0.068,-0.013, RAW= 30.7, -28.4, CAL= 33.4, -30.1, ROT= 176.6, 30.1
2021-11-17T21:54:15.309Z,1637186055.309 [DAT](INFO): got valid direction response:
21:53:36.5197 LVL= 32752, 32753, 32754, 32755, AGC= 90, IDX= 188, 0.43,-3.136, 3.098, 3.076, 3.074, PHS= 0.069, 0.068,-0.013, RAW= 30.7, -28.4, CAL= 33.4, -30.1, ROT= 176.6, 30.1
2021-11-17T21:54:15.309Z,1637186055.309 [DAT](INFO): DAT read:
2021-11-17T21:54:15.310Z,1637186055.310 [DAT](INFO): DAT read: DATA(0002):~~
2021-11-17T21:54:15.310Z,1637186055.310 [DAT](INFO): Got DATA 2
2021-11-17T21:54:15.312Z,1637186055.312 [DAT](INFO): DAT read: Source:001 Destination:007
2021-11-17T21:54:15.312Z,1637186055.312 [DAT](INFO): Got Src/Dest after DATA
2021-11-17T21:54:15.312Z,1637186055.312 [DAT](INFO): DATA Src=1, Dst=7
2021-11-17T21:54:15.313Z,1637186055.313 [DAT](INFO): DAT read: CRC:Pass MPD:03.5 PSNR:12.3 AGC:91 SPD:+0.0 CCERR:010
2021-11-17T21:54:15.314Z,1637186055.314 [DAT](INFO): Got CRC:Pass
2021-11-17T21:54:15.314Z,1637186055.314 [DAT](INFO): Got CRC:Pass
2021-11-17T21:54:15.314Z,1637186055.314 [DAT](INFO): Incoming data is intended for us
2021-11-17T21:54:15.314Z,1637186055.314 [DAT](INFO): Got ack
2021-11-17T21:54:15.314Z,1637186055.314 [DAT](INFO): DAT read:
2021-11-17T21:54:15.315Z,1637186055.315 [DAT](INFO): DAT read:
2021-11-17T21:54:15.948Z,1637186055.948 [DAT](INFO): #Outgoing data=2
2021-11-17T21:54:15.948Z,1637186055.948 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2021-11-17T21:54:15.948Z,1637186055.948 [DAT](INFO): #Rx 2: Read direction message, but no range.
2021-11-17T21:54:15.949Z,1637186055.949 [DAT](INFO): direction in vehicle frame: [ -0.863629 forward, 0.051309 starboard, 0.501511 keelward ]
2021-11-17T21:54:16.076Z,1637186056.076 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2021-11-17T21:54:19.739Z,1637186059.739 [DAT](INFO): DAT read: Forwarding Delay UpTx time:21:53:42.5886
2021-11-17T21:54:19.739Z,1637186059.739 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2021-11-17T21:54:29.429Z,1637186069.429 [DAT](INFO): DAT read: Rx Time:21:53:51.5199
2021-11-17T21:54:29.430Z,1637186069.430 [DAT](INFO): received an acoustic signal
2021-11-17T21:54:29.830Z,1637186069.830 [DAT](FAULT): Ack receipt timeout failure.
2021-11-17T21:54:29.830Z,1637186069.830 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER
2021-11-17T21:54:30.252Z,1637186070.252 [DAT](INFO): DAT read: 21:53:51.5198 LVL= 32752, 32753, 32754, 32755, AGC= 90, IDX= 177, 0.09, 2.708, 2.659, 2.637, 2.631, PHS= 0.073, 0.072,-0.009, RAW= 30.7, -30.5, CAL= 33.4, -31.9, ROT= 176.6, 31.9
2021-11-17T21:54:30.253Z,1637186070.253 [DAT](INFO): got valid direction response:
21:53:51.5198 LVL= 32752, 32753, 32754, 32755, AGC= 90, IDX= 177, 0.09, 2.708, 2.659, 2.637, 2.631, PHS= 0.073, 0.072,-0.009, RAW= 30.7, -30.5, CAL= 33.4, -31.9, ROT= 176.6, 31.9
2021-11-17T21:54:30.253Z,1637186070.253 [DAT](INFO): DAT read:
2021-11-17T21:54:30.254Z,1637186070.254 [DAT](INFO): DAT read: DATA(0002):~~
2021-11-17T21:54:30.254Z,1637186070.254 [DAT](INFO): Got DATA 2
2021-11-17T21:54:30.255Z,1637186070.255 [DAT](INFO): DAT read: Source:001 Destination:007
2021-11-17T21:54:30.304Z,1637186070.304 [DAT](INFO): Got Src/Dest after DATA
2021-11-17T21:54:30.304Z,1637186070.304 [DAT](INFO): DATA Src=1, Dst=7
2021-11-17T21:54:30.305Z,1637186070.305 [DAT](INFO): DAT read: CRC:Pass MPD:03.6 PSNR:12.6 AGC:90 SPD:+0.0 CCERR:010
2021-11-17T21:54:30.306Z,1637186070.306 [DAT](INFO): Got CRC:Pass
2021-11-17T21:54:30.306Z,1637186070.306 [DAT](INFO): Got CRC:Pass
2021-11-17T21:54:30.306Z,1637186070.306 [DAT](INFO): Incoming data is intended for us
2021-11-17T21:54:30.306Z,1637186070.306 [DAT](INFO): Got ack
2021-11-17T21:54:30.306Z,1637186070.306 [DAT](INFO): DAT read:
2021-11-17T21:54:30.307Z,1637186070.307 [DAT](INFO): DAT read:
2021-11-17T21:54:31.266Z,1637186071.266 [DAT](INFO): #Outgoing data=3
2021-11-17T21:54:31.267Z,1637186071.267 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2021-11-17T21:54:31.282Z,1637186071.282 [DAT](INFO): #Rx 3: Read direction message, but no range.
2021-11-17T21:54:31.283Z,1637186071.283 [DAT](INFO): direction in vehicle frame: [ -0.847477 forward, 0.050349 starboard, 0.528438 keelward ]
2021-11-17T21:54:31.546Z,1637186071.546 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2021-11-17T21:54:35.215Z,1637186075.215 [DAT](INFO): DAT read: Forwarding Delay UpTx time:21:53:58.0384
2021-11-17T21:54:35.215Z,1637186075.215 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2021-11-17T21:54:45.055Z,1637186085.055 [DAT](INFO): DAT read: Rx Time:21:54:07.0201
2021-11-17T21:54:45.055Z,1637186085.055 [DAT](INFO): received an acoustic signal
2021-11-17T21:54:45.318Z,1637186085.318 [DAT](FAULT): Ack receipt timeout failure.
2021-11-17T21:54:45.318Z,1637186085.318 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED
2021-11-17T21:54:45.732Z,1637186085.732 [DAT](INFO): DAT read: 21:54:07.0201 LVL= 32752, 32753, 32754, 32755, AGC= 90, IDX= 182,-0.04, 1.577, 1.530, 1.511, 1.507, PHS= 0.066, 0.067,-0.011, RAW= 29.5, -29.2, CAL= 32.1, -30.8, ROT= 177.9, 30.8
2021-11-17T21:54:45.733Z,1637186085.733 [DAT](INFO): got valid direction response:
21:54:07.0201 LVL= 32752, 32753, 32754, 32755, AGC= 90, IDX= 182,-0.04, 1.577, 1.530, 1.511, 1.507, PHS= 0.066, 0.067,-0.011, RAW= 29.5, -29.2, CAL= 32.1, -30.8, ROT= 177.9, 30.8
2021-11-17T21:54:45.734Z,1637186085.734 [DAT](INFO): DAT read:
2021-11-17T21:54:45.734Z,1637186085.734 [DAT](INFO): DAT read: DATA(0002):~~
2021-11-17T21:54:45.735Z,1637186085.735 [DAT](INFO): Got DATA 2
2021-11-17T21:54:45.736Z,1637186085.736 [DAT](INFO): DAT read: Source:001 Destination:007
2021-11-17T21:54:45.736Z,1637186085.736 [DAT](INFO): Got Src/Dest after DATA
2021-11-17T21:54:45.736Z,1637186085.736 [DAT](INFO): DATA Src=1, Dst=7
2021-11-17T21:54:45.738Z,1637186085.738 [DAT](INFO): DAT read: CRC:Pass MPD:03.6 PSNR:12.5 AGC:91 SPD:+0.0 CCERR:010
2021-11-17T21:54:45.738Z,1637186085.738 [DAT](INFO): Got CRC:Pass
2021-11-17T21:54:45.738Z,1637186085.738 [DAT](INFO): Got CRC:Pass
2021-11-17T21:54:45.738Z,1637186085.738 [DAT](INFO): Incoming data is intended for us
2021-11-17T21:54:45.738Z,1637186085.738 [DAT](INFO): Got ack
2021-11-17T21:54:45.738Z,1637186085.738 [DAT](INFO): DAT read:
2021-11-17T21:54:45.739Z,1637186085.739 [DAT](INFO): DAT read:
2021-11-17T21:54:45.740Z,1637186085.740 [DAT](INFO): Sent 335 bytes from file Logs/20211117T213937/Courier0010.lzma.parts
2021-11-17T21:54:45.740Z,1637186085.740 [DAT](INFO): Packets left to send: 0
2021-11-17T21:54:45.743Z,1637186085.743 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER
2021-11-17T21:54:45.743Z,1637186085.743 [DAT](INFO): #Rx 4: Read direction message, but no range.
2021-11-17T21:54:45.777Z,1637186085.777 [DAT](INFO): direction in vehicle frame: [ -0.858383 forward, 0.031476 starboard, 0.512043 keelward ]
2021-11-17T21:54:47.173Z,1637186087.173 [DAT](INFO): #Outgoing data=4
2021-11-17T21:54:47.174Z,1637186087.174 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2021-11-17T21:54:47.508Z,1637186087.508 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:54:47.508Z,1637186087.508 [DAT] Software Fault, FailCount= 1
2021-11-17T21:54:47.509Z,1637186087.509 [DAT](ERROR): Software Fault
2021-11-17T21:54:47.544Z,1637186087.544 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:54:48.066Z,1637186088.066 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:54:48.604Z,1637186088.604 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:54:49.155Z,1637186089.155 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:54:49.696Z,1637186089.696 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:54:50.455Z,1637186090.455 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:54:51.117Z,1637186091.117 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:54:51.450Z,1637186091.450 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:54:51.780Z,1637186091.780 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:54:52.103Z,1637186092.103 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:54:52.509Z,1637186092.509 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:54:52.880Z,1637186092.880 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:54:53.222Z,1637186093.222 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:54:53.590Z,1637186093.590 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:54:53.976Z,1637186093.976 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:54:54.375Z,1637186094.375 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:54:54.768Z,1637186094.768 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:54:55.133Z,1637186095.133 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:54:55.518Z,1637186095.518 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:54:55.914Z,1637186095.914 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:54:56.292Z,1637186096.292 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:54:56.665Z,1637186096.665 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:54:57.330Z,1637186097.330 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:54:57.963Z,1637186097.963 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:54:58.360Z,1637186098.360 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:54:58.755Z,1637186098.755 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:54:59.158Z,1637186099.158 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:54:59.581Z,1637186099.581 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:54:59.947Z,1637186099.947 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:00.360Z,1637186100.360 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:00.779Z,1637186100.779 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:01.179Z,1637186101.179 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:01.577Z,1637186101.577 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:01.958Z,1637186101.958 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:02.383Z,1637186102.383 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:03.107Z,1637186103.107 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:03.832Z,1637186103.832 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:04.416Z,1637186104.416 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:04.832Z,1637186104.832 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:05.246Z,1637186105.246 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:05.666Z,1637186105.666 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:06.073Z,1637186106.073 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:06.449Z,1637186106.449 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:06.890Z,1637186106.890 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:07.309Z,1637186107.309 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:07.734Z,1637186107.734 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:08.133Z,1637186108.133 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:08.516Z,1637186108.516 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:08.926Z,1637186108.926 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:09.367Z,1637186109.367 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:09.777Z,1637186109.777 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:10.189Z,1637186110.189 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:10.557Z,1637186110.557 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:10.928Z,1637186110.928 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:11.378Z,1637186111.378 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:11.798Z,1637186111.798 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:12.190Z,1637186112.190 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:12.574Z,1637186112.574 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:13.116Z,1637186113.116 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:13.900Z,1637186113.900 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:14.708Z,1637186114.708 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:15.488Z,1637186115.488 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:15.896Z,1637186115.896 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:16.328Z,1637186116.328 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:16.760Z,1637186116.760 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:17.167Z,1637186117.167 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:17.603Z,1637186117.603 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:18.007Z,1637186118.007 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:18.434Z,1637186118.434 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:18.837Z,1637186118.837 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:19.268Z,1637186119.268 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:19.712Z,1637186119.712 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:20.117Z,1637186120.117 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:20.522Z,1637186120.522 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:21.047Z,1637186121.047 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:21.476Z,1637186121.476 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:21.880Z,1637186121.880 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:22.283Z,1637186122.283 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:22.687Z,1637186122.687 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:23.093Z,1637186123.093 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:23.529Z,1637186123.529 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:23.992Z,1637186123.992 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:24.427Z,1637186124.427 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:24.849Z,1637186124.849 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:25.255Z,1637186125.255 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:25.663Z,1637186125.663 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:26.549Z,1637186126.549 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:26.952Z,1637186126.952 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:27.364Z,1637186127.364 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:27.779Z,1637186127.779 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:28.224Z,1637186128.224 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:28.629Z,1637186128.629 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:29.042Z,1637186129.042 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:29.491Z,1637186129.491 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:29.945Z,1637186129.945 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:30.360Z,1637186130.360 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:30.762Z,1637186130.762 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:31.177Z,1637186131.177 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:31.581Z,1637186131.581 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:31.994Z,1637186131.994 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:32.400Z,1637186132.400 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:32.812Z,1637186132.812 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:33.217Z,1637186133.217 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:33.697Z,1637186133.697 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:34.102Z,1637186134.102 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:34.533Z,1637186134.533 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:34.957Z,1637186134.957 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:35.365Z,1637186135.365 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:35.768Z,1637186135.768 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:36.172Z,1637186136.172 [DAT](CRITICAL): SIGSEGV: address not mapped to object
2021-11-17T21:55:36.577Z,1637186136.577 [DAT](CRITICAL): SIGSEGV: address