2021-11-17T21:18:16.762Z,1637183896.762 [Supervisor](DEBUG): Initializing supervisor. 2021-11-17T21:18:16.767Z,1637183896.767 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2021-11-17T21:18:16.767Z,1637183896.767 [SyncHandler](INFO): Protected caller Thread ID is 1243 2021-11-17T21:18:16.768Z,1637183896.768 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2021-11-17T21:18:16.769Z,1637183896.769 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2021-11-17T21:18:16.769Z,1637183896.769 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 1244 2021-11-17T21:18:16.774Z,1637183896.774 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2021-11-17T21:18:16.795Z,1637183896.795 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2021-11-17T21:18:16.796Z,1637183896.796 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2021-11-17T21:18:16.796Z,1637183896.796 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 1245 2021-11-17T21:18:16.799Z,1637183896.799 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2021-11-17T21:18:16.800Z,1637183896.800 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2021-11-17T21:18:16.800Z,1637183896.800 [logger ThreadHandler](INFO): Protected caller Thread ID is 1246 2021-11-17T21:18:16.804Z,1637183896.804 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2021-11-17T21:18:16.805Z,1637183896.805 [Supervisor](INFO): Looking for Config files in directory: Config/ 2021-11-17T21:18:16.806Z,1637183896.806 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2021-11-17T21:18:17.054Z,1637183897.054 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2021-11-17T21:18:17.054Z,1637183897.054 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2021-11-17T21:18:17.136Z,1637183897.136 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2021-11-17T21:18:17.681Z,1637183897.681 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2021-11-17T21:18:17.681Z,1637183897.681 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2021-11-17T21:18:18.047Z,1637183898.047 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2021-11-17T21:18:18.048Z,1637183898.048 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2021-11-17T21:18:18.148Z,1637183898.148 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2021-11-17T21:18:18.149Z,1637183898.149 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2021-11-17T21:18:18.558Z,1637183898.558 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2021-11-17T21:18:18.559Z,1637183898.559 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2021-11-17T21:18:18.774Z,1637183898.774 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2021-11-17T21:18:18.775Z,1637183898.775 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2021-11-17T21:18:19.288Z,1637183899.288 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2021-11-17T21:18:19.289Z,1637183899.289 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2021-11-17T21:18:19.422Z,1637183899.422 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2021-11-17T21:18:19.423Z,1637183899.423 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2021-11-17T21:18:19.504Z,1637183899.504 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2021-11-17T21:18:20.266Z,1637183900.266 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2021-11-17T21:18:20.266Z,1637183900.266 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2021-11-17T21:18:20.663Z,1637183900.663 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2021-11-17T21:18:20.664Z,1637183900.664 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2021-11-17T21:18:20.877Z,1637183900.877 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2021-11-17T21:18:20.878Z,1637183900.878 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2021-11-17T21:18:20.993Z,1637183900.993 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2021-11-17T21:18:20.994Z,1637183900.994 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2021-11-17T21:18:21.159Z,1637183901.159 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2021-11-17T21:18:21.160Z,1637183901.160 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg 2021-11-17T21:18:21.484Z,1637183901.484 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock 2021-11-17T21:18:21.487Z,1637183901.487 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/ 2021-11-17T21:18:21.488Z,1637183901.488 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg 2021-11-17T21:18:21.731Z,1637183901.731 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg 2021-11-17T21:18:21.886Z,1637183901.886 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg 2021-11-17T21:18:22.148Z,1637183902.148 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg 2021-11-17T21:18:22.236Z,1637183902.236 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg 2021-11-17T21:18:22.378Z,1637183902.378 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg 2021-11-17T21:18:22.506Z,1637183902.506 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg 2021-11-17T21:18:22.710Z,1637183902.710 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg 2021-11-17T21:18:22.787Z,1637183902.787 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg 2021-11-17T21:18:22.948Z,1637183902.948 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg 2021-11-17T21:18:23.097Z,1637183903.097 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg 2021-11-17T21:18:23.221Z,1637183903.221 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg 2021-11-17T21:18:23.497Z,1637183903.497 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2021-11-17T21:18:23.497Z,1637183903.497 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2021-11-17T21:18:23.511Z,1637183903.511 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2021-11-17T21:18:23.569Z,1637183903.569 [VerticalControl](DEBUG): Construct VerticalControl. 2021-11-17T21:18:23.635Z,1637183903.635 [VerticalControl] Loaded 2021-11-17T21:18:23.636Z,1637183903.636 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2021-11-17T21:18:23.639Z,1637183903.639 [HorizontalControl](DEBUG): Construct HorizontalControl. 2021-11-17T21:18:23.680Z,1637183903.680 [HorizontalControl] Loaded 2021-11-17T21:18:23.680Z,1637183903.680 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2021-11-17T21:18:23.683Z,1637183903.683 [SpeedControl](DEBUG): Construct SpeedControl. 2021-11-17T21:18:23.686Z,1637183903.686 [SpeedControl] Loaded 2021-11-17T21:18:23.686Z,1637183903.686 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2021-11-17T21:18:23.689Z,1637183903.689 [LoopControl](DEBUG): Construct LoopControl. 2021-11-17T21:18:23.689Z,1637183903.689 [LoopControl] Loaded 2021-11-17T21:18:23.690Z,1637183903.690 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2021-11-17T21:18:23.690Z,1637183903.690 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2021-11-17T21:18:23.691Z,1637183903.691 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2021-11-17T21:18:23.702Z,1637183903.702 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2021-11-17T21:18:23.703Z,1637183903.703 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2021-11-17T21:18:23.815Z,1637183903.815 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2021-11-17T21:18:23.816Z,1637183903.816 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2021-11-17T21:18:23.975Z,1637183903.975 [BuoyancyServo] Loaded 2021-11-17T21:18:23.975Z,1637183903.975 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2021-11-17T21:18:23.996Z,1637183903.996 [ElevatorServo] Loaded 2021-11-17T21:18:23.996Z,1637183903.996 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2021-11-17T21:18:24.015Z,1637183904.015 [MassServo] Loaded 2021-11-17T21:18:24.016Z,1637183904.016 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2021-11-17T21:18:24.034Z,1637183904.034 [RudderServo] Loaded 2021-11-17T21:18:24.035Z,1637183904.035 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2021-11-17T21:18:24.053Z,1637183904.053 [ThrusterServo] Loaded 2021-11-17T21:18:24.053Z,1637183904.053 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2021-11-17T21:18:24.054Z,1637183904.054 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2021-11-17T21:18:24.054Z,1637183904.054 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2021-11-17T21:18:24.140Z,1637183904.140 [DeadReckonUsingMultipleVelocitySources] Loaded 2021-11-17T21:18:24.141Z,1637183904.141 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2021-11-17T21:18:24.155Z,1637183904.155 [NavChart] Loaded 2021-11-17T21:18:24.155Z,1637183904.155 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2021-11-17T21:18:24.161Z,1637183904.161 [UniversalFixResidualReporter] Loaded 2021-11-17T21:18:24.161Z,1637183904.161 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2021-11-17T21:18:24.162Z,1637183904.162 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2021-11-17T21:18:24.162Z,1637183904.162 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2021-11-17T21:18:24.224Z,1637183904.224 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2021-11-17T21:18:24.225Z,1637183904.225 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2021-11-17T21:18:24.615Z,1637183904.615 [AHRS_M2] Loaded 2021-11-17T21:18:24.615Z,1637183904.615 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2021-11-17T21:18:25.453Z,1637183905.453 [BPC1] Loaded 2021-11-17T21:18:25.453Z,1637183905.453 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2021-11-17T21:18:25.473Z,1637183905.473 [Depth_Keller] Loaded 2021-11-17T21:18:25.474Z,1637183905.474 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2021-11-17T21:18:25.479Z,1637183905.479 [DropWeight] Loaded 2021-11-17T21:18:25.479Z,1637183905.479 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2021-11-17T21:18:25.541Z,1637183905.541 [NAL9602] Loaded 2021-11-17T21:18:25.541Z,1637183905.541 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2021-11-17T21:18:25.571Z,1637183905.571 [Onboard] Loaded 2021-11-17T21:18:25.571Z,1637183905.571 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread. 2021-11-17T21:18:25.572Z,1637183905.572 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 4088B4E0 2021-11-17T21:18:25.573Z,1637183905.573 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 1331 2021-11-17T21:18:25.586Z,1637183905.586 [Power24vConverter] Loaded 2021-11-17T21:18:25.587Z,1637183905.587 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread. 2021-11-17T21:18:25.602Z,1637183905.602 [Radio_Surface] Loaded 2021-11-17T21:18:25.602Z,1637183905.602 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2021-11-17T21:18:25.603Z,1637183905.603 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408BB4E0 2021-11-17T21:18:25.603Z,1637183905.603 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 1332 2021-11-17T21:18:25.690Z,1637183905.690 [DAT] Loaded 2021-11-17T21:18:25.690Z,1637183905.690 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread. 2021-11-17T21:18:25.690Z,1637183905.690 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2021-11-17T21:18:25.691Z,1637183905.691 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2021-11-17T21:18:25.738Z,1637183905.738 [DepthRateCalculator] Loaded 2021-11-17T21:18:25.738Z,1637183905.738 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2021-11-17T21:18:25.743Z,1637183905.743 [PitchRateCalculator] Loaded 2021-11-17T21:18:25.744Z,1637183905.744 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2021-11-17T21:18:25.753Z,1637183905.753 [SpeedCalculator] Loaded 2021-11-17T21:18:25.753Z,1637183905.753 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2021-11-17T21:18:25.768Z,1637183905.768 [TempGradientCalculator] Loaded 2021-11-17T21:18:25.768Z,1637183905.768 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2021-11-17T21:18:25.773Z,1637183905.773 [YawRateCalculator] Loaded 2021-11-17T21:18:25.773Z,1637183905.773 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2021-11-17T21:18:25.792Z,1637183905.792 [ElevatorOffsetCalculator] Loaded 2021-11-17T21:18:25.792Z,1637183905.792 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2021-11-17T21:18:25.793Z,1637183905.793 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2021-11-17T21:18:25.793Z,1637183905.793 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2021-11-17T21:18:25.941Z,1637183905.941 [CANONSampler] Loaded 2021-11-17T21:18:25.941Z,1637183905.941 [ComponentRegistry](DEBUG): SyncComponent "CANONSampler" handled in the control thread. 2021-11-17T21:18:26.003Z,1637183906.003 [CTD_Seabird] Loaded 2021-11-17T21:18:26.003Z,1637183906.003 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2021-11-17T21:18:26.004Z,1637183906.004 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 409704E0 2021-11-17T21:18:26.005Z,1637183906.005 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 1333 2021-11-17T21:18:26.026Z,1637183906.026 [PAR_Licor] Loaded 2021-11-17T21:18:26.026Z,1637183906.026 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2021-11-17T21:18:26.059Z,1637183906.059 [WetLabsBB2FL] Loaded 2021-11-17T21:18:26.060Z,1637183906.060 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2021-11-17T21:18:26.061Z,1637183906.061 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 409A04E0 2021-11-17T21:18:26.061Z,1637183906.061 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 1334 2021-11-17T21:18:26.062Z,1637183906.062 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2021-11-17T21:18:26.063Z,1637183906.063 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2021-11-17T21:18:26.093Z,1637183906.093 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2021-11-17T21:18:26.094Z,1637183906.094 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2021-11-17T21:18:26.447Z,1637183906.447 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2021-11-17T21:18:26.448Z,1637183906.448 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2021-11-17T21:18:26.609Z,1637183906.609 [SBIT](DEBUG): Construct Startup Built In Test. 2021-11-17T21:18:26.618Z,1637183906.618 [SBIT] Loaded 2021-11-17T21:18:26.619Z,1637183906.619 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2021-11-17T21:18:26.621Z,1637183906.621 [IBIT](DEBUG): Construct Initiated Built In Test. 2021-11-17T21:18:26.635Z,1637183906.635 [IBIT] Loaded 2021-11-17T21:18:26.635Z,1637183906.635 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2021-11-17T21:18:26.669Z,1637183906.669 [CBIT](DEBUG): Construct Continuous Built In Test. 2021-11-17T21:18:27.025Z,1637183907.025 [CBIT] Loaded 2021-11-17T21:18:27.025Z,1637183907.025 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2021-11-17T21:18:27.026Z,1637183907.026 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2021-11-17T21:18:27.026Z,1637183907.026 [Module Loader](DEBUG): Loading Module at Modules/Dock.so 2021-11-17T21:18:27.247Z,1637183907.247 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking) 2021-11-17T21:18:27.253Z,1637183907.253 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2021-11-17T21:18:27.256Z,1637183907.256 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2021-11-17T21:18:27.267Z,1637183907.267 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2021-11-17T21:18:27.268Z,1637183907.268 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40AD54E0 2021-11-17T21:18:27.269Z,1637183907.269 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 1335 2021-11-17T21:18:27.274Z,1637183907.274 [Supervisor](INFO): Main Thread ID is 829 2021-11-17T21:18:27.274Z,1637183907.274 [Supervisor](DEBUG): Running supervisor. 2021-11-17T21:18:27.275Z,1637183907.275 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1336 2021-11-17T21:18:27.277Z,1637183907.277 [controlThread ThreadHandler](INFO): Handler Thread ID is 1337 2021-11-17T21:18:27.277Z,1637183907.277 [controlThread](DEBUG): Initializing ControlThread 2021-11-17T21:18:27.278Z,1637183907.278 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2021-11-17T21:18:27.280Z,1637183907.280 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2021-11-17T21:18:27.281Z,1637183907.281 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2021-11-17T21:18:27.281Z,1637183907.281 [LoopControl](DEBUG): Initialize LoopControlComponent. 2021-11-17T21:18:27.283Z,1637183907.283 [NavChart](DEBUG): Initialize NavChart Navigation. 2021-11-17T21:18:27.284Z,1637183907.284 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2021-11-17T21:18:27.289Z,1637183907.289 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2021-11-17T21:18:27.289Z,1637183907.289 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2021-11-17T21:18:27.290Z,1637183907.290 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2021-11-17T21:18:27.290Z,1637183907.290 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2021-11-17T21:18:27.291Z,1637183907.291 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2021-11-17T21:18:27.291Z,1637183907.291 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2021-11-17T21:18:27.295Z,1637183907.295 [SBIT](INFO): Initialize SBIT Component. 2021-11-17T21:18:27.296Z,1637183907.296 [SBIT](IMPORTANT): git: 2021-09-29 2021-11-17T21:18:27.296Z,1637183907.296 [SBIT](INFO): git hash: d0bedea221735b48726a30f35f8acb1d414c6dbf 2021-11-17T21:18:27.296Z,1637183907.296 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2021-11-17T21:18:27.297Z,1637183907.297 [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:18:27.299Z,1637183907.299 [logger ThreadHandler](INFO): Handler Thread ID is 1338 2021-11-17T21:18:27.315Z,1637183907.315 [SBIT](INFO): Beginning SBIT in 84.000000 seconds. 2021-11-17T21:18:27.315Z,1637183907.315 [IBIT](INFO): Initialize IBIT Component. 2021-11-17T21:18:27.316Z,1637183907.316 [CBIT](DEBUG): Initialize CBIT Component. 2021-11-17T21:18:27.323Z,1637183907.323 [Onboard ThreadHandler](INFO): Handler Thread ID is 1339 2021-11-17T21:18:27.332Z,1637183907.332 [CBIT](DEBUG): Initialized mux pins. 2021-11-17T21:18:27.333Z,1637183907.333 [CBIT](DEBUG): Initializing the watchdog timer. 2021-11-17T21:18:27.355Z,1637183907.355 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 1340 2021-11-17T21:18:27.359Z,1637183907.359 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2021-11-17T21:18:27.359Z,1637183907.359 [CBIT](DEBUG): Initializing heartbeat. 2021-11-17T21:18:27.363Z,1637183907.363 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 1341 2021-11-17T21:18:27.364Z,1637183907.364 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2021-11-17T21:18:27.368Z,1637183907.368 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 1343 2021-11-17T21:18:27.371Z,1637183907.371 [WetLabsBB2FL](INFO): Powering up 2021-11-17T21:18:27.372Z,1637183907.372 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1345 2021-11-17T21:18:27.376Z,1637183907.376 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2021-11-17T21:18:27.376Z,1637183907.376 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2021-11-17T21:18:27.376Z,1637183907.376 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2021-11-17T21:18:27.377Z,1637183907.377 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2021-11-17T21:18:27.377Z,1637183907.377 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2021-11-17T21:18:27.377Z,1637183907.377 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2021-11-17T21:18:27.377Z,1637183907.377 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000 2021-11-17T21:18:27.377Z,1637183907.377 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2021-11-17T21:18:27.378Z,1637183907.378 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2021-11-17T21:18:27.378Z,1637183907.378 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2021-11-17T21:18:27.378Z,1637183907.378 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000 2021-11-17T21:18:27.378Z,1637183907.378 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2021-11-17T21:18:27.378Z,1637183907.378 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000 2021-11-17T21:18:27.379Z,1637183907.379 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2021-11-17T21:18:27.379Z,1637183907.379 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000 2021-11-17T21:18:27.379Z,1637183907.379 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2021-11-17T21:18:27.431Z,1637183907.431 [CBIT](DEBUG): Deactivating GF circuits. 2021-11-17T21:18:27.431Z,1637183907.431 [CBIT](DEBUG): Deactivating emergency mode. 2021-11-17T21:18:27.467Z,1637183907.467 [CBIT](DEBUG): Backplane powered. 2021-11-17T21:18:27.468Z,1637183907.468 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2021-11-17T21:18:27.481Z,1637183907.481 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2021-11-17T21:18:27.501Z,1637183907.501 [MissionManager](DEBUG): 2021-11-17T21:18:27.502Z,1637183907.502 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2021-11-17T21:18:27.591Z,1637183907.591 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2021-11-17T21:18:27.593Z,1637183907.593 [Default:A.Wait](DEBUG): Construct Wait. 2021-11-17T21:18:27.595Z,1637183907.595 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2021-11-17T21:18:27.640Z,1637183907.640 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2021-11-17T21:18:27.643Z,1637183907.643 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2021-11-17T21:18:27.663Z,1637183907.663 [Default:E.Execute](DEBUG): Construct Execute. 2021-11-17T21:18:27.666Z,1637183907.666 [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:18:27.695Z,1637183907.695 [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:18:27.702Z,1637183907.702 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2021-11-17T21:18:27.759Z,1637183907.759 [Radio_Surface](INFO): Powering up 2021-11-17T21:18:27.788Z,1637183907.788 [Depth_Keller](ERROR): Pressure reading out of range: 1831.023193 decibar 2021-11-17T21:18:27.789Z,1637183907.789 [Power24vConverter](INFO): Powering up. 2021-11-17T21:18:27.789Z,1637183907.789 [DAT](INFO): Powering up 2021-11-17T21:18:27.790Z,1637183907.790 [DAT](DEBUG): Initializing DAT. 2021-11-17T21:18:27.807Z,1637183907.807 [CANONSampler](INFO): Powering down 2021-11-17T21:18:27.819Z,1637183907.819 [DepthRateCalculator](ERROR): Depth measurement is not active 2021-11-17T21:18:27.845Z,1637183907.845 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2021-11-17T21:18:27.851Z,1637183907.851 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2021-11-17T21:18:27.852Z,1637183907.852 [ElevatorServo](DEBUG): Initializing EZServoServo. 2021-11-17T21:18:27.863Z,1637183907.863 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2021-11-17T21:18:27.864Z,1637183907.864 [MassServo](DEBUG): Initializing EZServoServo. 2021-11-17T21:18:27.871Z,1637183907.871 [MassServo](DEBUG): Initializing MassServo. 2021-11-17T21:18:27.872Z,1637183907.872 [RudderServo](DEBUG): Initializing EZServoServo. 2021-11-17T21:18:27.879Z,1637183907.879 [RudderServo](DEBUG): Initializing RudderServo. 2021-11-17T21:18:27.880Z,1637183907.880 [ThrusterServo](DEBUG): Initializing EZServoServo. 2021-11-17T21:18:27.887Z,1637183907.887 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2021-11-17T21:18:28.129Z,1637183908.129 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2021-11-17T21:18:28.129Z,1637183908.129 [DropWeight] Hardware Fault, FailCount= 1 2021-11-17T21:18:28.129Z,1637183908.129 [DropWeight](ERROR): Hardware Fault 2021-11-17T21:18:28.214Z,1637183908.214 [CommandLine](FAULT): Scheduling is paused 2021-11-17T21:18:28.215Z,1637183908.215 [CBIT](INFO): Critical error at 20211117T211828 2021-11-17T21:18:28.215Z,1637183908.215 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals 2021-11-17T21:18:28.218Z,1637183908.218 [CBIT](ERROR): Hardware Fault in component: DropWeight 2021-11-17T21:18:28.218Z,1637183908.218 [CBIT](CRITICAL): Hardware Fault in component: DropWeight 2021-11-17T21:18:28.863Z,1637183908.863 [RudderServo](ERROR): Rudder initialization uart error serial timeout 2021-11-17T21:18:28.863Z,1637183908.863 [RudderServo](FAULT): Rudder failed to initialize 2021-11-17T21:18:28.863Z,1637183908.863 [RudderServo] Communications Fault, FailCount= 1 2021-11-17T21:18:28.863Z,1637183908.863 [RudderServo](ERROR): Communications Fault 2021-11-17T21:18:28.965Z,1637183908.965 [CBIT](INFO): Critical error at 20211117T211828 2021-11-17T21:18:28.967Z,1637183908.967 [CBIT](ERROR): Communications Fault in component: RudderServo 2021-11-17T21:18:29.176Z,1637183909.176 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2021-11-17T21:18:29.176Z,1637183909.176 [RudderServo](INFO): Powering down 2021-11-17T21:18:29.479Z,1637183909.479 [WetLabsBB2FL](INFO): Powering down 2021-11-17T21:18:29.820Z,1637183909.820 [RudderServo](DEBUG): Initializing EZServoServo. 2021-11-17T21:18:29.940Z,1637183909.940 [RudderServo](DEBUG): Initializing RudderServo. 2021-11-17T21:18:29.944Z,1637183909.944 [CBIT](INFO): Clearing failed state for component RudderServo 2021-11-17T21:18:29.944Z,1637183909.944 [RudderServo] No Fault, FailCount= 1 2021-11-17T21:18:34.415Z,1637183914.415 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit. 2021-11-17T21:18:39.485Z,1637183919.485 [DAT](INFO): DAT read: 2021-11-17T21:18:39.486Z,1637183919.486 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series 2021-11-17T21:18:41.101Z,1637183921.101 [DAT](INFO): DAT read: MF Frequency Band 2021-11-17T21:18:41.102Z,1637183921.102 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.14.2 2021-11-17T21:18:41.103Z,1637183921.103 [DAT](INFO): DAT read: Nov 17 2021 21:18:01 2021-11-17T21:18:42.313Z,1637183922.313 [DAT](INFO): DAT read: Features enabled [Bearing] 2021-11-17T21:18:42.314Z,1637183922.314 [DAT](INFO): DAT read: CONNECT 01200 bits/sec 1 of 4, Rate 1/2 CC 2021-11-17T21:18:42.315Z,1637183922.315 [DAT](INFO): commRate: 1200 2021-11-17T21:18:44.333Z,1637183924.333 [DAT](INFO): entering command mode 2021-11-17T21:18:44.737Z,1637183924.737 [DAT](INFO): DAT read: 2021-11-17T21:18:44.737Z,1637183924.737 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-17T21:18:45.140Z,1637183925.140 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-17T21:18:45.545Z,1637183925.545 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-17T21:18:45.948Z,1637183925.948 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-17T21:18:46.352Z,1637183926.352 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-17T21:18:46.756Z,1637183926.756 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-17T21:18:47.160Z,1637183927.160 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-17T21:18:47.569Z,1637183927.569 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-17T21:18:47.969Z,1637183927.969 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-17T21:18:48.373Z,1637183928.373 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-17T21:18:48.777Z,1637183928.777 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-17T21:18:49.185Z,1637183929.185 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-17T21:18:49.585Z,1637183929.585 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-17T21:18:49.989Z,1637183929.989 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-17T21:18:50.393Z,1637183930.393 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-17T21:18:50.801Z,1637183930.801 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-17T21:18:51.201Z,1637183931.201 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-17T21:18:51.605Z,1637183931.605 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-17T21:18:52.009Z,1637183932.009 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-17T21:18:52.421Z,1637183932.421 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-17T21:18:52.817Z,1637183932.817 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-17T21:18:53.221Z,1637183933.221 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-17T21:18:53.625Z,1637183933.625 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-17T21:18:54.033Z,1637183934.033 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-17T21:18:54.433Z,1637183934.433 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-17T21:18:54.836Z,1637183934.836 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-17T21:18:55.241Z,1637183935.241 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-17T21:18:55.644Z,1637183935.644 [NAL9602](INFO): Powering up NAL9602 2021-11-17T21:18:55.646Z,1637183935.646 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-17T21:18:56.056Z,1637183936.056 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-17T21:18:56.453Z,1637183936.453 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-17T21:18:56.857Z,1637183936.857 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-17T21:18:57.260Z,1637183937.260 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-17T21:18:57.669Z,1637183937.669 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-17T21:18:58.069Z,1637183938.069 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-17T21:18:58.473Z,1637183938.473 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-17T21:18:58.877Z,1637183938.877 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-17T21:18:59.285Z,1637183939.285 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-17T21:18:59.685Z,1637183939.685 [DAT](DEBUG): checking for command mode acknowledgment 2021-11-17T21:18:59.685Z,1637183939.685 [DAT](FAULT): failed to enter command mode 2021-11-17T21:19:00.089Z,1637183940.089 [DAT](INFO): entering command mode 2021-11-17T21:19:00.493Z,1637183940.493 [DAT](INFO): DAT read: user:1> 2021-11-17T21:19:00.494Z,1637183940.494 [DAT](INFO): DAT read: Command '+++' not found 2021-11-17T21:19:00.494Z,1637183940.494 [DAT](INFO): DAT read: Error 2021-11-17T21:19:00.495Z,1637183940.495 [DAT](INFO): setting verbose to 3 2021-11-17T21:19:00.901Z,1637183940.901 [DAT](INFO): DAT read: user:2> 2021-11-17T21:19:00.902Z,1637183940.902 [DAT](INFO): DAT read: Verbose | 3 2021-11-17T21:19:00.902Z,1637183940.902 [DAT](INFO): set verbose to 3 2021-11-17T21:19:00.903Z,1637183940.903 [DAT](INFO): setting DatVerbose to 27440 2021-11-17T21:19:01.301Z,1637183941.301 [DAT](INFO): DAT read: user:3> 2021-11-17T21:19:01.302Z,1637183941.302 [DAT](INFO): DAT read: DatVerbose | 27440 2021-11-17T21:19:01.302Z,1637183941.302 [DAT](INFO): set DatVerbose to 27440 2021-11-17T21:19:01.303Z,1637183941.303 [DAT](INFO): setting transmit power to 8 2021-11-17T21:19:01.705Z,1637183941.705 [DAT](INFO): DAT read: user:4> 2021-11-17T21:19:01.706Z,1637183941.706 [DAT](INFO): DAT read: TxPower | 8 (Max) 2021-11-17T21:19:01.706Z,1637183941.706 [DAT](INFO): set transmit power to 8 2021-11-17T21:19:01.707Z,1637183941.707 [DAT](INFO): setting local address to 7 2021-11-17T21:19:02.109Z,1637183942.109 [DAT](INFO): DAT read: user:5> 2021-11-17T21:19:02.110Z,1637183942.110 [DAT](INFO): DAT read: LocalAddr | 7 2021-11-17T21:19:02.110Z,1637183942.110 [DAT](INFO): set local address to 7 2021-11-17T21:19:06.552Z,1637183946.552 [NAL9602](INFO): NAL9602 initialized 2021-11-17T21:19:51.833Z,1637183991.833 [SBIT](IMPORTANT): Beginning Startup BIT 2021-11-17T21:19:51.838Z,1637183991.838 [CBIT](IMPORTANT): Beginning ground fault scan 2021-11-17T21:20:02.806Z,1637184002.806 [CBIT](ERROR): Ground fault scan returned out of bounds value. Re-running scan. 2021-11-17T21:20:03.187Z,1637184003.187 [CBIT](IMPORTANT): Beginning ground fault scan 2021-11-17T21:20:14.094Z,1637184014.094 [CBIT](ERROR): Ground fault scan returned out of bounds value. Re-running scan. 2021-11-17T21:20:14.501Z,1637184014.501 [CBIT](IMPORTANT): Beginning ground fault scan 2021-11-17T21:20:25.368Z,1637184025.368 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.002391 CHAN A1 (24V): 0.000207 CHAN A2 (12V): -0.002165 CHAN A3 (5V): -0.001288 CHAN B0 (3.3V): -0.000045 CHAN B1 (3.15aV): -0.000011 CHAN B2 (3.15bV): -0.000760 CHAN B3 (GND): -0.000395 OPEN: -0.000662 Full Scale: +/- 1 mA 2021-11-17T21:20:45.964Z,1637184045.964 [SBIT](IMPORTANT): SBIT PASSED 2021-11-17T21:20:45.965Z,1637184045.965 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2021-11-17T21:20:45.966Z,1637184045.966 [SBIT](IMPORTANT): AMEcho.loadAtStartup=0 bool; 2021-11-17T21:20:45.966Z,1637184045.966 [SBIT](IMPORTANT): BuoyancyServo.fastPumpDepth=6 meter; 2021-11-17T21:20:45.966Z,1637184045.966 [SBIT](IMPORTANT): CANONSampler.loadAtStartup=1 bool; 2021-11-17T21:20:45.966Z,1637184045.966 [SBIT](IMPORTANT): DAT.baud=9600 bit_per_second; 2021-11-17T21:20:45.966Z,1637184045.966 [SBIT](IMPORTANT): DAT.loadAtStartup=1 bool; 2021-11-17T21:20:45.966Z,1637184045.966 [SBIT](IMPORTANT): DAT.sbdAddress=1 enum; 2021-11-17T21:20:45.966Z,1637184045.966 [SBIT](IMPORTANT): DAT.surfaceThreshold=0 meter; 2021-11-17T21:20:45.967Z,1637184045.967 [SBIT](IMPORTANT): DAT.verbosity=3 count; 2021-11-17T21:20:45.967Z,1637184045.967 [SBIT](IMPORTANT): DataOverHttps.loadAtStartup=0 bool; 2021-11-17T21:20:45.967Z,1637184045.967 [SBIT](IMPORTANT): ESPComponent.loadAtStartup=0 bool; 2021-11-17T21:20:45.967Z,1637184045.967 [SBIT](IMPORTANT): ESPComponent.simulateHardware=1 bool; 2021-11-17T21:20:45.967Z,1637184045.967 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=296 cubic_centimeter; 2021-11-17T21:20:45.967Z,1637184045.967 [SBIT](IMPORTANT): VerticalControl.massDefault=-16 millimeter; 2021-11-17T21:20:45.968Z,1637184045.968 [SBIT](IMPORTANT): VerticalControl.surfaceThreshold=2 meter; 2021-11-17T21:20:46.371Z,1637184046.371 [MissionManager](IMPORTANT): Started mission Startup 2021-11-17T21:20:46.372Z,1637184046.372 [Startup] Running Loop=1 2021-11-17T21:20:46.372Z,1637184046.372 [Startup](DEBUG): Aggregate::initialize Startup 2021-11-17T21:20:46.372Z,1637184046.372 [Startup:A.GoToSurface] Running Loop=1 2021-11-17T21:20:46.372Z,1637184046.372 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2021-11-17T21:20:46.372Z,1637184046.372 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2021-11-17T21:20:46.373Z,1637184046.373 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2021-11-17T21:20:46.373Z,1637184046.373 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2021-11-17T21:20:46.374Z,1637184046.374 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2021-11-17T21:20:46.374Z,1637184046.374 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2021-11-17T21:20:46.376Z,1637184046.376 [Startup:StartupSatComms] Running Loop=1 2021-11-17T21:20:46.376Z,1637184046.376 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2021-11-17T21:20:46.376Z,1637184046.376 [Startup:StartupSatComms:A] Running Loop=1 2021-11-17T21:20:46.761Z,1637184046.761 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2021-11-17T21:21:27.556Z,1637184087.556 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2021-11-17T21:21:27.556Z,1637184087.556 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-11-17T21:21:27.592Z,1637184087.592 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-11-17T21:21:27.975Z,1637184087.975 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-11-17T21:21:27.975Z,1637184087.975 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2021-11-17T21:21:46.573Z,1637184106.573 [Startup:StartupSatComms:A](INFO): Timed out from 2021-11-17T21:20:46.4Z 2021-11-17T21:21:46.573Z,1637184106.573 [Startup:StartupSatComms:A] Stopped 2021-11-17T21:21:46.574Z,1637184106.574 [Startup:StartupSatComms:B] Running Loop=1 2021-11-17T21:21:46.993Z,1637184106.993 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2021-11-17T21:21:47.881Z,1637184107.881 [DAT](INFO): #Outgoing data=1 2021-11-17T21:21:47.881Z,1637184107.881 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-11-17T21:21:47.984Z,1637184107.984 [DAT](INFO): setting remote address to 1 2021-11-17T21:21:48.329Z,1637184108.329 [DAT](INFO): DAT read: user:6> 2021-11-17T21:21:48.330Z,1637184108.330 [DAT](INFO): DAT read: RemoteAddr | 1 2021-11-17T21:21:48.330Z,1637184108.330 [DAT](INFO): set remote address to 1 2021-11-17T21:21:48.333Z,1637184108.333 [DAT](INFO): entering online mode 2021-11-17T21:21:48.725Z,1637184108.725 [DAT](INFO): DAT read: user:7> 2021-11-17T21:21:48.726Z,1637184108.726 [DAT](INFO): DAT read: 2021-11-17T21:21:48.728Z,1637184108.728 [DAT](INFO): DAT read: CONNECT 01200 bits/sec 1 of 4, Rate 1/2 CC 2021-11-17T21:21:48.728Z,1637184108.728 [DAT](INFO): commRate: 1200 2021-11-17T21:21:48.728Z,1637184108.728 [DAT](INFO): online mode acknowledged 2021-11-17T21:21:48.729Z,1637184108.729 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-11-17T21:21:51.988Z,1637184111.988 [DAT](INFO): DAT read: Forwarding Delay UpTx time:21:21:14.9253 2021-11-17T21:21:51.989Z,1637184111.989 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-11-17T21:21:53.878Z,1637184113.878 [CommandLine](IMPORTANT): got command maintain sensor NAL9602.latitude_fix 36.799999 degree 2021-11-17T21:21:53.882Z,1637184113.882 [ComponentRegistry](DEBUG): SyncComponent "Maintain_NAL9602.latitude_fix" handled in the control thread. 2021-11-17T21:21:53.882Z,1637184113.882 [CommandLine](IMPORTANT): got command maintain sensor NAL9602.longitude_fix -121.900002 degree 2021-11-17T21:21:53.886Z,1637184113.886 [ComponentRegistry](DEBUG): SyncComponent "Maintain_NAL9602.longitude_fix" handled in the control thread. 2021-11-17T21:21:54.025Z,1637184114.025 [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:21:54.416Z,1637184114.416 [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:21:54.416Z,1637184114.416 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2 2021-11-17T21:21:54.416Z,1637184114.416 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-11-17T21:21:54.427Z,1637184114.427 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-11-17T21:21:54.824Z,1637184114.824 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-11-17T21:21:54.824Z,1637184114.824 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2 2021-11-17T21:21:55.614Z,1637184115.614 [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:21:55.614Z,1637184115.614 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3 2021-11-17T21:21:55.614Z,1637184115.614 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-11-17T21:21:55.625Z,1637184115.625 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-11-17T21:21:56.059Z,1637184116.059 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-11-17T21:21:56.059Z,1637184116.059 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3 2021-11-17T21:21:56.837Z,1637184116.837 [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:21:56.838Z,1637184116.838 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4 2021-11-17T21:21:56.838Z,1637184116.838 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-11-17T21:21:56.897Z,1637184116.897 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-11-17T21:21:57.244Z,1637184117.244 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-11-17T21:21:57.244Z,1637184117.244 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4 2021-11-17T21:21:58.065Z,1637184118.065 [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:21:58.065Z,1637184118.065 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5 2021-11-17T21:21:58.065Z,1637184118.065 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-11-17T21:21:58.088Z,1637184118.088 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-11-17T21:21:58.572Z,1637184118.572 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-11-17T21:21:58.572Z,1637184118.572 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5 2021-11-17T21:21:58.832Z,1637184118.832 [DAT](FAULT): Ack receipt timeout failure. 2021-11-17T21:21:58.832Z,1637184118.832 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2021-11-17T21:21:59.226Z,1637184119.226 [DAT](INFO): DAT read: Rx Time:21:21:21.5354 2021-11-17T21:21:59.226Z,1637184119.226 [DAT](INFO): received an acoustic signal 2021-11-17T21:21:59.789Z,1637184119.789 [DAT](INFO): #Outgoing data=1 2021-11-17T21:21:59.790Z,1637184119.790 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-11-17T21:21:59.797Z,1637184119.797 [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:21:59.797Z,1637184119.797 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6 2021-11-17T21:21:59.797Z,1637184119.797 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-11-17T21:21:59.809Z,1637184119.809 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-11-17T21:21:59.887Z,1637184119.887 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-11-17T21:21:59.959Z,1637184119.959 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-11-17T21:21:59.959Z,1637184119.959 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6 2021-11-17T21:22:00.241Z,1637184120.241 [DAT](INFO): DAT read: 21:21:21.5354 LVL= 32752, 32753, 32754, 32755, AGC= 89, IDX= 232, 0.03, 2.845, 2.789, 2.750, 2.768, PHS= 0.073, 0.064,-0.033, RAW= 34.2, -19.8, CAL= 37.1, -22.9, ROT= 172.9, 22.9 2021-11-17T21:22:00.242Z,1637184120.242 [DAT](INFO): got valid direction response: 21:21:21.5354 LVL= 32752, 32753, 32754, 32755, AGC= 89, IDX= 232, 0.03, 2.845, 2.789, 2.750, 2.768, PHS= 0.073, 0.064,-0.033, RAW= 34.2, -19.8, CAL= 37.1, -22.9, ROT= 172.9, 22.9 2021-11-17T21:22:00.242Z,1637184120.242 [DAT](INFO): DAT read: 2021-11-17T21:22:00.243Z,1637184120.243 [DAT](INFO): DAT read: DATA(0002):~~ 2021-11-17T21:22:00.243Z,1637184120.243 [DAT](INFO): Got DATA 2 2021-11-17T21:22:00.244Z,1637184120.244 [DAT](INFO): DAT read: Source:001 Destination:007 2021-11-17T21:22:00.245Z,1637184120.245 [DAT](INFO): Got Src/Dest after DATA 2021-11-17T21:22:00.245Z,1637184120.245 [DAT](INFO): DATA Src=1, Dst=7 2021-11-17T21:22:00.246Z,1637184120.246 [DAT](INFO): DAT read: CRC:Pass MPD:03.6 PSNR:12.5 AGC:90 SPD:+0.0 CCERR:010 2021-11-17T21:22:00.247Z,1637184120.247 [DAT](INFO): Got CRC:Pass 2021-11-17T21:22:00.247Z,1637184120.247 [DAT](INFO): Got CRC:Pass 2021-11-17T21:22:00.247Z,1637184120.247 [DAT](INFO): Incoming data is intended for us 2021-11-17T21:22:00.247Z,1637184120.247 [DAT](DEBUG): In parseResponses, got ack so set commsState_ = SENDING_VERIFIED 2021-11-17T21:22:00.247Z,1637184120.247 [DAT](INFO): Got ack 2021-11-17T21:22:00.247Z,1637184120.247 [DAT](INFO): DAT read: 2021-11-17T21:22:00.248Z,1637184120.248 [DAT](INFO): DAT read: 2021-11-17T21:22:00.249Z,1637184120.249 [DAT](INFO): Sent 39 bytes from file Logs/20211117T185525/Courier0097.lzma.parts 2021-11-17T21:22:00.249Z,1637184120.249 [DAT](INFO): Packets left to send: 0 2021-11-17T21:22:00.253Z,1637184120.253 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2021-11-17T21:22:00.253Z,1637184120.253 [DAT](INFO): #Rx 1: Read direction message, but no range. 2021-11-17T21:22:00.254Z,1637184120.254 [DAT](INFO): direction in vehicle frame: [ -0.914122 forward, 0.113860 starboard, 0.389124 keelward ] 2021-11-17T21:22:01.198Z,1637184121.198 [DAT](INFO): #Outgoing data=2 2021-11-17T21:22:01.198Z,1637184121.198 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-11-17T21:22:01.211Z,1637184121.211 [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:22:01.211Z,1637184121.211 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7 2021-11-17T21:22:01.211Z,1637184121.211 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-11-17T21:22:01.222Z,1637184121.222 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-11-17T21:22:01.282Z,1637184121.282 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-11-17T21:22:01.365Z,1637184121.365 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-11-17T21:22:01.366Z,1637184121.366 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7 2021-11-17T21:22:02.057Z,1637184122.057 [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:22:02.057Z,1637184122.057 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8 2021-11-17T21:22:02.057Z,1637184122.057 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-11-17T21:22:02.069Z,1637184122.069 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-11-17T21:22:02.492Z,1637184122.492 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-11-17T21:22:02.492Z,1637184122.492 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8 2021-11-17T21:22:03.289Z,1637184123.289 [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:22:03.290Z,1637184123.290 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 9 2021-11-17T21:22:03.290Z,1637184123.290 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-11-17T21:22:03.301Z,1637184123.301 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-11-17T21:22:03.749Z,1637184123.749 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-11-17T21:22:03.749Z,1637184123.749 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 9 2021-11-17T21:22:04.510Z,1637184124.510 [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:22:04.510Z,1637184124.510 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 10 2021-11-17T21:22:04.510Z,1637184124.510 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-11-17T21:22:04.550Z,1637184124.550 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-11-17T21:22:04.898Z,1637184124.898 [DAT](INFO): DAT read: Forwarding Delay UpTx time:21:21:27.6751 2021-11-17T21:22:04.898Z,1637184124.898 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-11-17T21:22:04.956Z,1637184124.956 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-11-17T21:22:04.957Z,1637184124.957 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 10 2021-11-17T21:22:05.693Z,1637184125.693 [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:22:05.693Z,1637184125.693 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 11 2021-11-17T21:22:05.693Z,1637184125.693 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-11-17T21:22:05.721Z,1637184125.721 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-11-17T21:22:06.108Z,1637184126.108 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-11-17T21:22:06.108Z,1637184126.108 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 11 2021-11-17T21:22:06.465Z,1637184126.465 [CommandLine](IMPORTANT): got command set NAL9602.time_fix 1637184128.000000 second 2021-11-17T21:22:11.345Z,1637184131.345 [DAT](FAULT): Ack receipt timeout failure. 2021-11-17T21:22:11.345Z,1637184131.345 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2021-11-17T21:22:12.323Z,1637184132.323 [DAT](INFO): #Outgoing data=2 2021-11-17T21:22:12.324Z,1637184132.324 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-11-17T21:22:12.421Z,1637184132.421 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-11-17T21:22:14.024Z,1637184134.024 [DAT](INFO): DAT read: Rx Time:21:21:36.2357 2021-11-17T21:22:14.024Z,1637184134.024 [DAT](INFO): received an acoustic signal 2021-11-17T21:22:14.831Z,1637184134.831 [DAT](INFO): DAT read: 21:21:36.2357 LVL= 32752, 32753, 32754, 32755, AGC= 90, IDX= 189,-0.39, 1.502, 1.448, 1.427, 1.426, PHS= 0.072, 0.066,-0.014, RAW= 33.2, -27.9, CAL= 36.1, -29.7, ROT= 173.9, 29.7 2021-11-17T21:22:14.832Z,1637184134.832 [DAT](INFO): got valid direction response: 21:21:36.2357 LVL= 32752, 32753, 32754, 32755, AGC= 90, IDX= 189,-0.39, 1.502, 1.448, 1.427, 1.426, PHS= 0.072, 0.066,-0.014, RAW= 33.2, -27.9, CAL= 36.1, -29.7, ROT= 173.9, 29.7 2021-11-17T21:22:14.832Z,1637184134.832 [DAT](INFO): DAT read: 2021-11-17T21:22:14.833Z,1637184134.833 [DAT](INFO): #Rx 2: Read direction message, but no range. 2021-11-17T21:22:14.843Z,1637184134.843 [DAT](INFO): direction in vehicle frame: [ -0.863713 forward, 0.092304 starboard, 0.495459 keelward ] 2021-11-17T21:22:15.225Z,1637184135.225 [DAT](INFO): DAT read: DATA(0002):~~ 2021-11-17T21:22:15.226Z,1637184135.226 [DAT](INFO): Got DATA 2 2021-11-17T21:22:15.227Z,1637184135.227 [DAT](INFO): DAT read: Source:001 Destination:007 2021-11-17T21:22:15.227Z,1637184135.227 [DAT](INFO): Got Src/Dest after DATA 2021-11-17T21:22:15.227Z,1637184135.227 [DAT](INFO): DATA Src=1, Dst=7 2021-11-17T21:22:15.231Z,1637184135.231 [DAT](INFO): DAT read: CRC:Pass MPD:03.6 PSNR:12.1 AGC:89 SPD:+0.0 CCERR:010 2021-11-17T21:22:15.232Z,1637184135.232 [DAT](INFO): Got CRC:Pass 2021-11-17T21:22:15.232Z,1637184135.232 [DAT](INFO): Got CRC:Pass 2021-11-17T21:22:15.232Z,1637184135.232 [DAT](INFO): Incoming data is intended for us 2021-11-17T21:22:15.232Z,1637184135.232 [DAT](DEBUG): In parseResponses, got ack so set commsState_ = SENDING_VERIFIED 2021-11-17T21:22:15.232Z,1637184135.232 [DAT](INFO): Got ack 2021-11-17T21:22:15.233Z,1637184135.233 [DAT](INFO): DAT read: 2021-11-17T21:22:15.233Z,1637184135.233 [DAT](INFO): DAT read: 2021-11-17T21:22:15.234Z,1637184135.234 [DAT](INFO): Sent 240 bytes from file Logs/20211117T205316/Courier0000.lzma.parts 2021-11-17T21:22:15.234Z,1637184135.234 [DAT](INFO): Packets left to send: 0 2021-11-17T21:22:15.237Z,1637184135.237 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2021-11-17T21:22:16.109Z,1637184136.109 [DAT](INFO): #Outgoing data=3 2021-11-17T21:22:16.110Z,1637184136.110 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-11-17T21:22:16.194Z,1637184136.194 [DAT](INFO): DAT read: Forwarding Delay UpTx time:21:21:38.8250 2021-11-17T21:22:16.195Z,1637184136.195 [DAT](INFO): unknown deviceResponse_: Forwarding Delay UpTx time:21:21:38.8250 2021-11-17T21:22:16.196Z,1637184136.196 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-11-17T21:22:19.814Z,1637184139.814 [DAT](INFO): DAT read: Forwarding Delay UpTx time:21:21:42.5250 2021-11-17T21:22:19.814Z,1637184139.814 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-11-17T21:22:24.657Z,1637184144.657 [DAT](INFO): DAT read: Rx Time:21:21:47.0358 2021-11-17T21:22:24.658Z,1637184144.658 [DAT](INFO): received an acoustic signal 2021-11-17T21:22:25.889Z,1637184145.889 [DAT](INFO): DAT read: 21:21:47.0358 LVL= 32752, 32753, 32754, 32755, AGC= 90, IDX= 144,-0.21, 1.368, 1.313, 1.279, 1.288, PHS= 0.076, 0.069,-0.024, RAW= 33.5, -23.9, CAL= 36.4, -26.4, ROT= 173.6, 26.4 2021-11-17T21:22:25.890Z,1637184145.890 [DAT](INFO): got valid direction response: 21:21:47.0358 LVL= 32752, 32753, 32754, 32755, AGC= 90, IDX= 144,-0.21, 1.368, 1.313, 1.279, 1.288, PHS= 0.076, 0.069,-0.024, RAW= 33.5, -23.9, CAL= 36.4, -26.4, ROT= 173.6, 26.4 2021-11-17T21:22:25.890Z,1637184145.890 [DAT](INFO): DAT read: 2021-11-17T21:22:25.891Z,1637184145.891 [DAT](INFO): DAT read: DATA(0002):~~ 2021-11-17T21:22:25.891Z,1637184145.891 [DAT](INFO): Got DATA 2 2021-11-17T21:22:25.892Z,1637184145.892 [DAT](INFO): DAT read: Source:001 Destination:007 2021-11-17T21:22:25.892Z,1637184145.892 [DAT](INFO): Got Src/Dest after DATA 2021-11-17T21:22:25.893Z,1637184145.893 [DAT](INFO): DATA Src=1, Dst=7 2021-11-17T21:22:25.894Z,1637184145.894 [DAT](INFO): DAT read: CRC:Pass MPD:03.6 PSNR:12.3 AGC:91 SPD:-0.1 CCERR:011 2021-11-17T21:22:25.894Z,1637184145.894 [DAT](INFO): Got CRC:Pass 2021-11-17T21:22:25.895Z,1637184145.895 [DAT](INFO): Got CRC:Pass 2021-11-17T21:22:25.895Z,1637184145.895 [DAT](INFO): Incoming data is intended for us 2021-11-17T21:22:25.895Z,1637184145.895 [DAT](DEBUG): In parseResponses, got ack so set commsState_ = SENDING_VERIFIED 2021-11-17T21:22:25.895Z,1637184145.895 [DAT](INFO): Got ack 2021-11-17T21:22:25.895Z,1637184145.895 [DAT](INFO): DAT read: 2021-11-17T21:22:25.896Z,1637184145.896 [DAT](INFO): DAT read: 2021-11-17T21:22:25.896Z,1637184145.896 [DAT](INFO): Sent 168 bytes from file Logs/20211117T205316/Courier0004.lzma.parts 2021-11-17T21:22:25.897Z,1637184145.897 [DAT](INFO): Packets left to send: 0 2021-11-17T21:22:25.899Z,1637184145.899 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2021-11-17T21:22:25.900Z,1637184145.900 [DAT](INFO): #Rx 3: Read direction message, but no range. 2021-11-17T21:22:25.901Z,1637184145.901 [DAT](INFO): direction in vehicle frame: [ -0.890130 forward, 0.099844 starboard, 0.444635 keelward ] 2021-11-17T21:22:26.753Z,1637184146.753 [DAT](INFO): #Outgoing data=3 2021-11-17T21:22:26.753Z,1637184146.753 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-11-17T21:22:26.840Z,1637184146.840 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-11-17T21:22:30.446Z,1637184150.446 [DAT](INFO): DAT read: Forwarding Delay UpTx time:21:21:53.0748 2021-11-17T21:22:30.447Z,1637184150.447 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2021-11-17T21:22:36.910Z,1637184156.910 [DAT](FAULT): Ack receipt timeout failure. 2021-11-17T21:22:36.910Z,1637184156.910 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2021-11-17T21:22:37.828Z,1637184157.828 [DAT](INFO): #Outgoing data=3 2021-11-17T21:22:37.828Z,1637184157.828 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-11-17T21:22:37.914Z,1637184157.914 [DAT](INFO): DAT read: Rx Time:21:22:00.0860 2021-11-17T21:22:37.915Z,1637184157.915 [DAT](INFO): received an acoustic signal 2021-11-17T21:22:37.916Z,1637184157.916 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2021-11-17T21:22:38.698Z,1637184158.698 [DAT](INFO): DAT read: 21:22:00.0860 LVL= 32752, 32753, 32754, 32755, AGC= 89, IDX= 436,-0.22, 1.239, 1.183, 1.164, 1.164, PHS= 0.071, 0.062,-0.016, RAW= 35.1, -26.7, CAL= 38.0, -28.7, ROT= 172.0, 28.7 2021-11-17T21:22:38.707Z,1637184158.707 [DAT](INFO): got valid direction response: 21:22:00.0860 LVL= 32752, 32753, 32754, 32755, AGC= 89, IDX= 436,-0.22, 1.239, 1.183, 1.164, 1.164, PHS= 0.071, 0.062,-0.016, RAW= 35.1, -26.7, CAL= 38.0, -28.7, ROT= 172.0, 28.7 2021-11-17T21:22:38.708Z,1637184158.708 [DAT](INFO): DAT read: 2021-11-17T21:22:38.709Z,1637184158.709 [DAT](INFO): DAT read: DATA(0002):~~ 2021-11-17T21:22:38.709Z,1637184158.709 [DAT](INFO): Got DATA 2 2021-11-17T21:22:38.710Z,1637184158.710 [DAT](INFO): #Rx 4: Read direction message, but no range. 2021-11-17T21:22:38.711Z,1637184158.711 [DAT](INFO): direction in vehicle frame: [ -0.868610 forward, 0.122075 starboard, 0.480224 keelward ] 2021-11-17T21:22:39.100Z,1637184159.100 [DAT](INFO): DAT read: Source:001 Destination:007 2021-11-17T21:22:39.100Z,1637184159.100 [DAT](INFO): Got Src/Dest after DATA 2021-11-17T21:22:39.101Z,1637184159.101 [DAT](INFO): DATA Src=1, Dst=7 2021-11-17T21:22:39.102Z,1637184159.102 [DAT](INFO): DAT read: CRC:Pass MPD:03.6 PSNR:12.6 AGC:90 SPD:+0.0 CCERR:010 2021-11-17T21:22:39.103Z,1637184159.103 [DAT](INFO): Got CRC:Pass 2021-11-17T21:22:39.103Z,1637184159.103 [DAT](INFO): Got CRC:Pass 2021-11-17T21:22:39.103Z,1637184159.103 [DAT](INFO): Incoming data is intended for us 2021-11-17T21:22:39.103Z,1637184159.103 [DAT](DEBUG): In parseResponses, got ack so set commsState_ = SENDING_VERIFIED 2021-11-17T21:22:39.103Z,1637184159.103 [DAT](INFO): Got ack 2021-11-17T21:22:39.103Z,1637184159.103 [DAT](INFO): DAT read: 2021-11-17T21:22:39.104Z,1637184159.104 [DAT](INFO): DAT read: 2021-11-17T21:22:39.105Z,1637184159.105 [DAT](INFO): Sent 87 bytes from file Logs/20211117T205316/Courier0007.lzma.parts 2021-11-17T21:22:39.105Z,1637184159.105 [DAT](INFO): Packets left to send: 0 2021-11-17T21:22:39.107Z,1637184159.107 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2021-11-17T21:22:39.986Z,1637184159.986 [DAT](INFO): #Outgoing data=4 2021-11-17T21:22:39.987Z,1637184159.987 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2021-11-17T21:22:40.232Z,1637184160.232 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:22:40.232Z,1637184160.232 [DAT] Software Fault, FailCount= 1 2021-11-17T21:22:40.232Z,1637184160.232 [DAT](ERROR): Software Fault 2021-11-17T21:22:40.252Z,1637184160.252 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:22:40.601Z,1637184160.601 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:22:40.937Z,1637184160.937 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:22:41.274Z,1637184161.274 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:22:41.630Z,1637184161.630 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:22:41.965Z,1637184161.965 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:22:42.331Z,1637184162.331 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:22:42.663Z,1637184162.663 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:22:43.022Z,1637184163.022 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:22:43.419Z,1637184163.419 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:22:43.781Z,1637184163.781 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:22:44.113Z,1637184164.113 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:22:44.446Z,1637184164.446 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:22:44.780Z,1637184164.780 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:22:45.190Z,1637184165.190 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:22:45.564Z,1637184165.564 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:22:45.912Z,1637184165.912 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:22:46.241Z,1637184166.241 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:22:46.615Z,1637184166.615 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:22:46.994Z,1637184166.994 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:22:47.364Z,1637184167.364 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:22:47.763Z,1637184167.763 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:22:48.113Z,1637184168.113 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:22:48.489Z,1637184168.489 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:22:48.879Z,1637184168.879 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:22:49.267Z,1637184169.267 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:22:49.753Z,1637184169.753 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:22:50.403Z,1637184170.403 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:22:50.853Z,1637184170.853 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:22:51.182Z,1637184171.182 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:22:51.557Z,1637184171.557 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:22:51.935Z,1637184171.935 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:22:52.307Z,1637184172.307 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:22:52.745Z,1637184172.745 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:22:53.095Z,1637184173.095 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:22:53.459Z,1637184173.459 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:22:53.814Z,1637184173.814 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:22:54.203Z,1637184174.203 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:22:54.585Z,1637184174.585 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:22:54.965Z,1637184174.965 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:22:55.323Z,1637184175.323 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:22:55.935Z,1637184175.935 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:22:56.608Z,1637184176.608 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:22:57.222Z,1637184177.222 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:22:57.617Z,1637184177.617 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:22:58.035Z,1637184178.035 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:22:58.427Z,1637184178.427 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:22:58.809Z,1637184178.809 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:22:59.165Z,1637184179.165 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:22:59.552Z,1637184179.552 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:22:59.970Z,1637184179.970 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:23:00.354Z,1637184180.354 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:23:00.739Z,1637184180.739 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:23:01.088Z,1637184181.088 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:23:01.447Z,1637184181.447 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:23:01.845Z,1637184181.845 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:23:02.243Z,1637184182.243 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:23:02.640Z,1637184182.640 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:23:03.049Z,1637184183.049 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:23:03.401Z,1637184183.401 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:23:03.749Z,1637184183.749 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:23:04.187Z,1637184184.187 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:23:04.584Z,1637184184.584 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:23:04.949Z,1637184184.949 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:23:05.318Z,1637184185.318 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:23:05.769Z,1637184185.769 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:23:06.371Z,1637184186.371 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:23:07.113Z,1637184187.113 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:23:07.893Z,1637184187.893 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:23:08.481Z,1637184188.481 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:23:08.868Z,1637184188.868 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:23:09.305Z,1637184189.305 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:23:09.691Z,1637184189.691 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:23:10.077Z,1637184190.077 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:23:10.493Z,1637184190.493 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:23:10.879Z,1637184190.879 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:23:11.281Z,1637184191.281 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:23:11.667Z,1637184191.667 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:23:12.075Z,1637184192.075 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:23:12.466Z,1637184192.466 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:23:12.879Z,1637184192.879 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:23:13.269Z,1637184193.269 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:23:13.657Z,1637184193.657 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:23:14.051Z,1637184194.051 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:23:14.437Z,1637184194.437 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:23:14.823Z,1637184194.823 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:23:15.209Z,1637184195.209 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:23:15.595Z,1637184195.595 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:23:16.005Z,1637184196.005 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:23:16.415Z,1637184196.415 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:23:16.831Z,1637184196.831 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:23:17.219Z,1637184197.219 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:23:17.609Z,1637184197.609 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:23:18.042Z,1637184198.042 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:23:19.071Z,1637184199.071 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:23:19.549Z,1637184199.549 [DAT](CRITICAL): SIGSEGV: address not mapped to object 2021-11-17T21:23:20.036Z,1