2019-06-24T23:37:15.597Z,1561419435.597 [Supervisor](DEBUG): Initializing supervisor.
2019-06-24T23:37:15.600Z,1561419435.600 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2019-06-24T23:37:15.600Z,1561419435.600 [SyncHandler](INFO): Protected caller Thread ID is 806
2019-06-24T23:37:15.601Z,1561419435.601 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2019-06-24T23:37:15.602Z,1561419435.602 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2019-06-24T23:37:15.602Z,1561419435.602 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 807
2019-06-24T23:37:15.604Z,1561419435.604 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2019-06-24T23:37:15.616Z,1561419435.616 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2019-06-24T23:37:15.617Z,1561419435.617 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2019-06-24T23:37:15.617Z,1561419435.617 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 808
2019-06-24T23:37:15.618Z,1561419435.618 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2019-06-24T23:37:15.619Z,1561419435.619 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2019-06-24T23:37:15.619Z,1561419435.619 [logger ThreadHandler](INFO): Protected caller Thread ID is 809
2019-06-24T23:37:15.621Z,1561419435.621 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2019-06-24T23:37:15.622Z,1561419435.622 [Supervisor](INFO): Looking for Config files in directory: Config/
2019-06-24T23:37:15.626Z,1561419435.626 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2019-06-24T23:37:16.039Z,1561419436.039 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2019-06-24T23:37:16.041Z,1561419436.041 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2019-06-24T23:37:16.137Z,1561419436.137 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2019-06-24T23:37:16.139Z,1561419436.139 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2019-06-24T23:37:16.449Z,1561419436.449 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2019-06-24T23:37:16.451Z,1561419436.451 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2019-06-24T23:37:16.589Z,1561419436.589 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2019-06-24T23:37:16.590Z,1561419436.590 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2019-06-24T23:37:16.779Z,1561419436.779 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2019-06-24T23:37:16.781Z,1561419436.781 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2019-06-24T23:37:17.239Z,1561419437.239 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2019-06-24T23:37:17.240Z,1561419437.240 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2019-06-24T23:37:17.442Z,1561419437.442 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2019-06-24T23:37:17.444Z,1561419437.444 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2019-06-24T23:37:17.586Z,1561419437.586 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2019-06-24T23:37:17.588Z,1561419437.588 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2019-06-24T23:37:17.777Z,1561419437.777 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2019-06-24T23:37:17.779Z,1561419437.779 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2019-06-24T23:37:17.876Z,1561419437.876 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2019-06-24T23:37:17.877Z,1561419437.877 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2019-06-24T23:37:18.171Z,1561419438.171 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2019-06-24T23:37:18.171Z,1561419438.171 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2019-06-24T23:37:18.253Z,1561419438.253 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2019-06-24T23:37:18.354Z,1561419438.354 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2019-06-24T23:37:18.356Z,1561419438.356 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2019-06-24T23:37:18.916Z,1561419438.916 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2019-06-24T23:37:18.917Z,1561419438.917 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2019-06-24T23:37:19.889Z,1561419439.889 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2019-06-24T23:37:19.891Z,1561419439.891 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/
2019-06-24T23:37:19.893Z,1561419439.893 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/vehicle.cfg
2019-06-24T23:37:20.098Z,1561419440.098 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Control.cfg
2019-06-24T23:37:20.197Z,1561419440.197 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/BIT.cfg
2019-06-24T23:37:20.295Z,1561419440.295 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Battery.cfg
2019-06-24T23:37:20.518Z,1561419440.518 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2019-06-24T23:37:20.519Z,1561419440.519 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Simulator.cfg
2019-06-24T23:37:20.603Z,1561419440.603 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Navigation.cfg
2019-06-24T23:37:20.695Z,1561419440.695 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/logger.cfg
2019-06-24T23:37:20.792Z,1561419440.792 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/secure.cfg
2019-06-24T23:37:20.874Z,1561419440.874 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Servo.cfg
2019-06-24T23:37:20.982Z,1561419440.982 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Sensor.cfg
2019-06-24T23:37:21.145Z,1561419441.145 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Science.cfg
2019-06-24T23:37:21.273Z,1561419441.273 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2019-06-24T23:37:21.281Z,1561419441.281 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2019-06-24T23:37:22.008Z,1561419442.008 [AHRS_M2] Loaded
2019-06-24T23:37:22.008Z,1561419442.008 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2019-06-24T23:37:22.156Z,1561419442.156 [DataOverHttps] Loaded
2019-06-24T23:37:22.156Z,1561419442.156 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2019-06-24T23:37:22.157Z,1561419442.157 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 407654E0
2019-06-24T23:37:22.158Z,1561419442.158 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 888
2019-06-24T23:37:22.171Z,1561419442.171 [Depth_Keller] Loaded
2019-06-24T23:37:22.171Z,1561419442.171 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2019-06-24T23:37:22.175Z,1561419442.175 [DropWeight] Loaded
2019-06-24T23:37:22.176Z,1561419442.176 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2019-06-24T23:37:22.232Z,1561419442.232 [DUSBL_Hydroid] Loaded
2019-06-24T23:37:22.233Z,1561419442.233 [ComponentRegistry](DEBUG): SyncComponent "DUSBL_Hydroid" handled in the control thread.
2019-06-24T23:37:22.330Z,1561419442.330 [NAL9602](CRITICAL): No configuration setting for: NAL9602.maxDownlinkMsgSize
2019-06-24T23:37:22.331Z,1561419442.331 [NAL9602] Loaded
2019-06-24T23:37:22.331Z,1561419442.331 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2019-06-24T23:37:22.347Z,1561419442.347 [Onboard] Loaded
2019-06-24T23:37:22.347Z,1561419442.347 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2019-06-24T23:37:22.353Z,1561419442.353 [PowerOnly] Loaded
2019-06-24T23:37:22.353Z,1561419442.353 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread.
2019-06-24T23:37:22.360Z,1561419442.360 [Radio_Surface] Loaded
2019-06-24T23:37:22.360Z,1561419442.360 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2019-06-24T23:37:22.361Z,1561419442.361 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 407954E0
2019-06-24T23:37:22.361Z,1561419442.361 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 889
2019-06-24T23:37:22.405Z,1561419442.405 [RDI_Pathfinder] Loaded
2019-06-24T23:37:22.405Z,1561419442.405 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2019-06-24T23:37:23.957Z,1561419443.957 [BPC1] Loaded
2019-06-24T23:37:23.958Z,1561419443.958 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2019-06-24T23:37:23.958Z,1561419443.958 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2019-06-24T23:37:23.960Z,1561419443.960 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2019-06-24T23:37:24.629Z,1561419444.629 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2019-06-24T23:37:24.629Z,1561419444.629 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2019-06-24T23:37:24.858Z,1561419444.858 [DeadReckonUsingMultipleVelocitySources] Loaded
2019-06-24T23:37:24.858Z,1561419444.858 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2019-06-24T23:37:24.878Z,1561419444.878 [NavChart] Loaded
2019-06-24T23:37:24.878Z,1561419444.878 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2019-06-24T23:37:24.882Z,1561419444.882 [UniversalFixResidualReporter] Loaded
2019-06-24T23:37:24.883Z,1561419444.883 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2019-06-24T23:37:24.883Z,1561419444.883 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2019-06-24T23:37:24.884Z,1561419444.884 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2019-06-24T23:37:25.013Z,1561419445.013 [BuoyancyServo] Loaded
2019-06-24T23:37:25.013Z,1561419445.013 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2019-06-24T23:37:25.028Z,1561419445.028 [ElevatorServo] Loaded
2019-06-24T23:37:25.029Z,1561419445.029 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2019-06-24T23:37:25.043Z,1561419445.043 [MassServo] Loaded
2019-06-24T23:37:25.043Z,1561419445.043 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2019-06-24T23:37:25.058Z,1561419445.058 [RudderServo] Loaded
2019-06-24T23:37:25.059Z,1561419445.059 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2019-06-24T23:37:25.073Z,1561419445.073 [ThrusterServo] Loaded
2019-06-24T23:37:25.073Z,1561419445.073 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2019-06-24T23:37:25.074Z,1561419445.074 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2019-06-24T23:37:25.074Z,1561419445.074 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2019-06-24T23:37:25.393Z,1561419445.393 [CTD_NeilBrown] Loaded
2019-06-24T23:37:25.393Z,1561419445.393 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2019-06-24T23:37:25.394Z,1561419445.394 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 408DF4E0
2019-06-24T23:37:25.395Z,1561419445.395 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 891
2019-06-24T23:37:25.438Z,1561419445.438 [WetLabsSeaOWL_UV_A] Loaded
2019-06-24T23:37:25.439Z,1561419445.439 [ComponentRegistry](DEBUG): Component "WetLabsSeaOWL_UV_A" handled in its own thread.
2019-06-24T23:37:25.440Z,1561419445.440 [WetLabsSeaOWL_UV_A ThreadHandler](DEBUG): Created PCaller Thread at 4090F4E0
2019-06-24T23:37:25.440Z,1561419445.440 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Protected caller Thread ID is 892
2019-06-24T23:37:25.441Z,1561419445.441 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2019-06-24T23:37:25.441Z,1561419445.441 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2019-06-24T23:37:25.785Z,1561419445.785 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2019-06-24T23:37:25.786Z,1561419445.786 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2019-06-24T23:37:25.840Z,1561419445.840 [DepthRateCalculator] Loaded
2019-06-24T23:37:25.840Z,1561419445.840 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2019-06-24T23:37:25.846Z,1561419445.846 [PitchRateCalculator] Loaded
2019-06-24T23:37:25.846Z,1561419445.846 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2019-06-24T23:37:25.858Z,1561419445.858 [SpeedCalculator] Loaded
2019-06-24T23:37:25.859Z,1561419445.859 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2019-06-24T23:37:25.879Z,1561419445.879 [TempGradientCalculator] Loaded
2019-06-24T23:37:25.879Z,1561419445.879 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2019-06-24T23:37:25.885Z,1561419445.885 [YawRateCalculator] Loaded
2019-06-24T23:37:25.885Z,1561419445.885 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2019-06-24T23:37:25.925Z,1561419445.925 [ElevatorOffsetCalculator] Loaded
2019-06-24T23:37:25.925Z,1561419445.925 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2019-06-24T23:37:25.925Z,1561419445.925 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2019-06-24T23:37:25.926Z,1561419445.926 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2019-06-24T23:37:26.086Z,1561419446.086 [SBIT](DEBUG): Construct Startup Built In Test.
2019-06-24T23:37:26.108Z,1561419446.108 [SBIT] Loaded
2019-06-24T23:37:26.108Z,1561419446.108 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2019-06-24T23:37:26.109Z,1561419446.109 [IBIT](DEBUG): Construct Initiated Built In Test.
2019-06-24T23:37:26.121Z,1561419446.121 [IBIT] Loaded
2019-06-24T23:37:26.121Z,1561419446.121 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2019-06-24T23:37:26.124Z,1561419446.124 [CBIT](DEBUG): Construct Continuous Built In Test.
2019-06-24T23:37:26.261Z,1561419446.261 [CBIT] Loaded
2019-06-24T23:37:26.262Z,1561419446.262 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2019-06-24T23:37:26.262Z,1561419446.262 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2019-06-24T23:37:26.263Z,1561419446.263 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2019-06-24T23:37:26.382Z,1561419446.382 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2019-06-24T23:37:26.383Z,1561419446.383 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2019-06-24T23:37:26.507Z,1561419446.507 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2019-06-24T23:37:26.508Z,1561419446.508 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2019-06-24T23:37:26.594Z,1561419446.594 [VerticalControl](DEBUG): Construct VerticalControl.
2019-06-24T23:37:26.677Z,1561419446.677 [VerticalControl] Loaded
2019-06-24T23:37:26.677Z,1561419446.677 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2019-06-24T23:37:26.678Z,1561419446.678 [HorizontalControl](DEBUG): Construct HorizontalControl.
2019-06-24T23:37:26.734Z,1561419446.734 [HorizontalControl] Loaded
2019-06-24T23:37:26.735Z,1561419446.735 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2019-06-24T23:37:26.735Z,1561419446.735 [SpeedControl](DEBUG): Construct SpeedControl.
2019-06-24T23:37:26.737Z,1561419446.737 [SpeedControl] Loaded
2019-06-24T23:37:26.737Z,1561419446.737 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2019-06-24T23:37:26.738Z,1561419446.738 [LoopControl](DEBUG): Construct LoopControl.
2019-06-24T23:37:26.738Z,1561419446.738 [LoopControl] Loaded
2019-06-24T23:37:26.739Z,1561419446.739 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2019-06-24T23:37:26.739Z,1561419446.739 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2019-06-24T23:37:26.740Z,1561419446.740 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2019-06-24T23:37:26.780Z,1561419446.780 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2019-06-24T23:37:26.784Z,1561419446.784 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2019-06-24T23:37:26.785Z,1561419446.785 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2019-06-24T23:37:26.791Z,1561419446.791 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2019-06-24T23:37:26.792Z,1561419446.792 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40AE94E0
2019-06-24T23:37:26.793Z,1561419446.793 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 893
2019-06-24T23:37:26.797Z,1561419446.797 [Supervisor](INFO): Main Thread ID is 802
2019-06-24T23:37:26.798Z,1561419446.798 [Supervisor](DEBUG): Running supervisor.
2019-06-24T23:37:26.798Z,1561419446.798 [CommandLine ThreadHandler](INFO): Handler Thread ID is 894
2019-06-24T23:37:26.806Z,1561419446.806 [CommandLine](IMPORTANT): got command quit
2019-06-24T23:37:26.811Z,1561419446.810 [controlThread ThreadHandler](INFO): Handler Thread ID is 895
2019-06-24T23:37:26.811Z,1561419446.811 [controlThread](DEBUG): Initializing ControlThread
2019-06-24T23:37:26.816Z,1561419446.816 [NavChart](DEBUG): Initialize NavChart Navigation.
2019-06-24T23:37:26.816Z,1561419446.816 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2019-06-24T23:37:26.817Z,1561419446.817 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2019-06-24T23:37:26.818Z,1561419446.818 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2019-06-24T23:37:26.818Z,1561419446.818 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2019-06-24T23:37:26.818Z,1561419446.818 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2019-06-24T23:37:26.819Z,1561419446.819 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2019-06-24T23:37:26.819Z,1561419446.819 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2019-06-24T23:37:26.820Z,1561419446.820 [SBIT](INFO): Initialize SBIT Component.
2019-06-24T23:37:26.820Z,1561419446.820 [SBIT](IMPORTANT): git: 2019-06-10-2-g709c054
2019-06-24T23:37:26.820Z,1561419446.820 [SBIT](INFO): git hash: 709c0545d45ae3977146e0060076f9aec254ba96
2019-06-24T23:37:26.821Z,1561419446.821 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2019-06-24T23:37:26.822Z,1561419446.822 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #1 PREEMPT Thu Feb 21 11:17:40 PST 2019
2019-06-24T23:37:26.823Z,1561419446.823 [SBIT](INFO): Beginning SBIT in 28.000000 seconds.
2019-06-24T23:37:26.824Z,1561419446.824 [IBIT](INFO): Initialize IBIT Component.
2019-06-24T23:37:26.824Z,1561419446.824 [CBIT](DEBUG): Initialize CBIT Component.
2019-06-24T23:37:26.825Z,1561419446.825 [logger ThreadHandler](INFO): Handler Thread ID is 896
2019-06-24T23:37:26.837Z,1561419446.837 [CBIT](DEBUG): Initialized mux pins.
2019-06-24T23:37:26.837Z,1561419446.837 [CBIT](DEBUG): Initializing the watchdog timer.
2019-06-24T23:37:26.845Z,1561419446.845 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 897
2019-06-24T23:37:26.846Z,1561419446.846 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2019-06-24T23:37:26.857Z,1561419446.857 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 898
2019-06-24T23:37:26.861Z,1561419446.861 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2019-06-24T23:37:26.861Z,1561419446.861 [CBIT](DEBUG): Initializing heartbeat.
2019-06-24T23:37:26.869Z,1561419446.869 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 899
2019-06-24T23:37:26.870Z,1561419446.870 [CTD_NeilBrown](INFO): Powering down
2019-06-24T23:37:26.897Z,1561419446.897 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Handler Thread ID is 900
2019-06-24T23:37:26.898Z,1561419446.898 [WetLabsSeaOWL_UV_A](INFO): Powering down
2019-06-24T23:37:26.930Z,1561419446.930 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 901
2019-06-24T23:37:26.933Z,1561419446.933 [CBIT](DEBUG): Deactivating GF circuits.
2019-06-24T23:37:26.933Z,1561419446.933 [CBIT](DEBUG): Deactivating emergency mode.
2019-06-24T23:37:26.938Z,1561419446.938 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2019-06-24T23:37:26.938Z,1561419446.938 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2019-06-24T23:37:26.939Z,1561419446.939 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2019-06-24T23:37:26.939Z,1561419446.939 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2019-06-24T23:37:26.939Z,1561419446.939 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2019-06-24T23:37:26.939Z,1561419446.939 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2019-06-24T23:37:26.939Z,1561419446.939 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2019-06-24T23:37:26.939Z,1561419446.939 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2019-06-24T23:37:26.940Z,1561419446.940 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2019-06-24T23:37:26.940Z,1561419446.940 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2019-06-24T23:37:26.940Z,1561419446.940 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2019-06-24T23:37:26.940Z,1561419446.940 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2019-06-24T23:37:26.940Z,1561419446.940 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2019-06-24T23:37:26.941Z,1561419446.941 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2019-06-24T23:37:26.941Z,1561419446.941 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2019-06-24T23:37:26.941Z,1561419446.941 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2019-06-24T23:37:26.969Z,1561419446.969 [CBIT](DEBUG): Backplane powered.
2019-06-24T23:37:26.969Z,1561419446.969 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2019-06-24T23:37:26.971Z,1561419446.971 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2019-06-24T23:37:26.972Z,1561419446.972 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2019-06-24T23:37:26.972Z,1561419446.972 [LoopControl](DEBUG): Initialize LoopControlComponent.
2019-06-24T23:37:26.973Z,1561419446.973 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2019-06-24T23:37:26.999Z,1561419446.999 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2019-06-24T23:37:27.027Z,1561419447.027 [MissionManager](DEBUG):
2019-06-24T23:37:27.028Z,1561419447.028 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2019-06-24T23:37:27.105Z,1561419447.105 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2019-06-24T23:37:27.106Z,1561419447.106 [Default:A.Wait](DEBUG): Construct Wait.
2019-06-24T23:37:27.108Z,1561419447.108 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2019-06-24T23:37:27.126Z,1561419447.126 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2019-06-24T23:37:27.153Z,1561419447.153 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2019-06-24T23:37:27.158Z,1561419447.158 [Default:E.Execute](DEBUG): Construct Execute.
2019-06-24T23:37:27.170Z,1561419447.170 [MissionManager](DEBUG):
0
Wait a moment to see if the scheduler starts a new mission before
starting to actually run Default.
13
Burn on
Dropped weight due to communications timeout.
5
Default mission has been running for
Restarting logs and Default mission.
restart logs
2019-06-24T23:37:27.179Z,1561419447.179 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,DUSBL_Hydroid,NAL9602,Onboard,PowerOnly,RDI_Pathfinder,BPC1,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2019-06-24T23:37:27.209Z,1561419447.209 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2019-06-24T23:37:27.261Z,1561419447.261 [Radio_Surface](INFO): Powering up
2019-06-24T23:37:27.322Z,1561419447.322 [Depth_Keller](ERROR): Pressure reading out of range: 1913.424561 decibar
2019-06-24T23:37:27.323Z,1561419447.323 [DUSBL_Hydroid](INFO): Powering up
2019-06-24T23:37:27.323Z,1561419447.323 [DUSBL_Hydroid](DEBUG): Initializing DUSBL_Hydroid.
2019-06-24T23:37:27.393Z,1561419447.393 [DepthRateCalculator](ERROR): Depth measurement is not active
2019-06-24T23:37:27.439Z,1561419447.439 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2019-06-24T23:37:27.445Z,1561419447.445 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2019-06-24T23:37:27.446Z,1561419447.446 [ElevatorServo](DEBUG): Initializing EZServoServo.
2019-06-24T23:37:27.453Z,1561419447.453 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2019-06-24T23:37:27.454Z,1561419447.454 [MassServo](DEBUG): Initializing EZServoServo.
2019-06-24T23:37:27.461Z,1561419447.461 [MassServo](DEBUG): Initializing MassServo.
2019-06-24T23:37:27.462Z,1561419447.462 [RudderServo](DEBUG): Initializing EZServoServo.
2019-06-24T23:37:27.469Z,1561419447.469 [RudderServo](DEBUG): Initializing RudderServo.
2019-06-24T23:37:27.470Z,1561419447.470 [ThrusterServo](DEBUG): Initializing EZServoServo.
2019-06-24T23:37:27.477Z,1561419447.477 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2019-06-24T23:37:27.479Z,1561419447.479 [CommandLine](FAULT): Scheduling is paused
2019-06-24T23:37:27.479Z,1561419447.479 [CBIT](INFO): Critical error at 20190624T233722
2019-06-24T23:37:27.480Z,1561419447.480 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2019-06-24T23:37:27.715Z,1561419447.715 [DropWeight](CRITICAL): DROP WEIGHT MISSING.
2019-06-24T23:37:27.715Z,1561419447.715 [DropWeight] Hardware Fault, FailCount= 1
2019-06-24T23:37:27.715Z,1561419447.715 [DropWeight](ERROR): Hardware Fault
2019-06-24T23:37:27.748Z,1561419447.748 [CBIT](INFO): Critical error at 20190624T233727
2019-06-24T23:37:27.759Z,1561419447.759 [CBIT](ERROR): Hardware Fault in component: DropWeight
2019-06-24T23:37:27.759Z,1561419447.759 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2019-06-24T23:37:27.809Z,1561419447.809 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2019-06-24T23:37:27.809Z,1561419447.809 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-06-24T23:37:27.953Z,1561419447.953 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye!
2019-06-24T23:37:27.953Z,1561419447.953 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-06-24T23:37:27.954Z,1561419447.954 [CommandLine](INFO): Join timeout helper Thread ID is 910
2019-06-24T23:37:27.969Z,1561419447.969 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2019-06-24T23:37:27.969Z,1561419447.969 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-06-24T23:37:27.969Z,1561419447.969 [NavChartDb](INFO): Join timeout helper Thread ID is 911
2019-06-24T23:37:28.345Z,1561419448.345 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2019-06-24T23:37:28.345Z,1561419448.345 [RudderServo](FAULT): Rudder failed to initialize
2019-06-24T23:37:28.345Z,1561419448.345 [RudderServo] Communications Fault, FailCount= 1
2019-06-24T23:37:28.345Z,1561419448.345 [RudderServo](ERROR): Communications Fault
2019-06-24T23:37:28.466Z,1561419448.466 [CBIT](INFO): Critical error at 20190624T233727
2019-06-24T23:37:28.469Z,1561419448.469 [CBIT](ERROR): Communications Fault in component: RudderServo
2019-06-24T23:37:28.634Z,1561419448.634 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-06-24T23:37:28.634Z,1561419448.634 [RudderServo](INFO): Powering down
2019-06-24T23:37:29.312Z,1561419449.312 [RudderServo](DEBUG): Initializing EZServoServo.
2019-06-24T23:37:29.434Z,1561419449.434 [RudderServo](DEBUG): Initializing RudderServo.
2019-06-24T23:37:29.438Z,1561419449.438 [CBIT](INFO): Clearing failed state for component RudderServo
2019-06-24T23:37:29.438Z,1561419449.438 [RudderServo] No Fault, FailCount= 1
2019-06-24T23:37:32.887Z,1561419452.887 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2019-06-24T23:37:32.888Z,1561419452.888 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-06-24T23:37:32.893Z,1561419452.893 [ComponentRegistry](INFO): Shutting down WetLabsSeaOWL_UV_A ThreadHandler
2019-06-24T23:37:32.893Z,1561419452.893 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2019-06-24T23:37:32.893Z,1561419452.893 [WetLabsSeaOWL_UV_A](INFO): Join timeout helper Thread ID is 913
2019-06-24T23:37:32.977Z,1561419452.977 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Uninitializing protected caller thread.
2019-06-24T23:37:32.977Z,1561419452.977 [WetLabsSeaOWL_UV_A](INFO): Powering down
2019-06-24T23:37:32.978Z,1561419452.978 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2019-06-24T23:37:32.985Z,1561419452.985 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2019-06-24T23:37:32.985Z,1561419452.985 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-06-24T23:37:32.985Z,1561419452.985 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 914
2019-06-24T23:37:32.989Z,1561419452.989 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2019-06-24T23:37:32.989Z,1561419452.989 [CTD_NeilBrown](INFO): Powering down
2019-06-24T23:37:33.001Z,1561419453.001 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-06-24T23:37:33.017Z,1561419453.017 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2019-06-24T23:37:33.017Z,1561419453.017 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-06-24T23:37:33.017Z,1561419453.017 [Radio_Surface](INFO): Join timeout helper Thread ID is 915
2019-06-24T23:37:33.321Z,1561419453.321 [Radio_Surface](INFO): Powering down
2019-06-24T23:37:33.344Z,1561419453.344 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2019-06-24T23:37:33.344Z,1561419453.344 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-06-24T23:37:33.350Z,1561419453.350 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2019-06-24T23:37:33.350Z,1561419453.350 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-06-24T23:37:33.350Z,1561419453.350 [DataOverHttps](INFO): Join timeout helper Thread ID is 916
2019-06-24T23:37:33.713Z,1561419453.713 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2019-06-24T23:37:33.713Z,1561419453.713 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-06-24T23:37:33.726Z,1561419453.726 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2019-06-24T23:37:33.726Z,1561419453.726 [logger ThreadHandler](INFO): Thread cancelled.
2019-06-24T23:37:33.726Z,1561419453.726 [logger](INFO): Join timeout helper Thread ID is 917
2019-06-24T23:37:33.779Z,1561419453.779 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2019-06-24T23:37:33.780Z,1561419453.780 [logger ThreadHandler](INFO): Thread cancelled.
2019-06-24T23:37:33.798Z,1561419453.798 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2019-06-24T23:37:33.798Z,1561419453.798 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-06-24T23:37:33.798Z,1561419453.798 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2019-06-24T23:37:33.798Z,1561419453.798 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-06-24T23:37:33.798Z,1561419453.798 [controlThread](INFO): Join timeout helper Thread ID is 918
2019-06-24T23:37:33.890Z,1561419453.890 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2019-06-24T23:37:33.890Z,1561419453.890 [controlThread](DEBUG): Uninitializing ControlThread
2019-06-24T23:37:33.890Z,1561419453.890 [AHRS_M2](INFO): Powering down
2019-06-24T23:37:33.986Z,1561419453.986 [DUSBL_Hydroid](INFO): Powering down
2019-06-24T23:37:34.077Z,1561419454.077 [NAL9602](INFO): Powering down
2019-06-24T23:37:34.165Z,1561419454.165 [RDI_Pathfinder](INFO): Powering down
2019-06-24T23:37:34.184Z,1561419454.184 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2019-06-24T23:37:34.185Z,1561419454.185 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2019-06-24T23:37:34.186Z,1561419454.186 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2019-06-24T23:37:34.186Z,1561419454.186 [MissionManager](INFO): Uninitializing Mission Default
2019-06-24T23:37:34.188Z,1561419454.188 [MissionManager](INFO): Uninitializing Mission Startup
2019-06-24T23:37:34.190Z,1561419454.190 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2019-06-24T23:37:34.190Z,1561419454.190 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2019-06-24T23:37:34.190Z,1561419454.190 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2019-06-24T23:37:34.191Z,1561419454.191 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2019-06-24T23:37:34.191Z,1561419454.191 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2019-06-24T23:37:34.191Z,1561419454.191 [BuoyancyServo](INFO): Powering down
2019-06-24T23:37:34.205Z,1561419454.205 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2019-06-24T23:37:34.205Z,1561419454.205 [ElevatorServo](INFO): Powering down
2019-06-24T23:37:34.224Z,1561419454.224 [MassServo](DEBUG): Uninitialize Mass Servo.
2019-06-24T23:37:34.224Z,1561419454.224 [MassServo](INFO): Powering down
2019-06-24T23:37:34.234Z,1561419454.234 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-06-24T23:37:34.234Z,1561419454.234 [RudderServo](INFO): Powering down
2019-06-24T23:37:34.235Z,1561419454.235 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2019-06-24T23:37:34.235Z,1561419454.235 [ThrusterServo](INFO): Powering down
2019-06-24T23:37:34.236Z,1561419454.236 [SBIT](DEBUG): Uninitialize SBIT Component.
2019-06-24T23:37:34.236Z,1561419454.236 [IBIT](DEBUG): Uninitialize IBIT Component.
2019-06-24T23:37:34.236Z,1561419454.236 [CBIT](DEBUG): Uninitialize CBIT Component.
2019-06-24T23:37:34.236Z,1561419454.236 [CBIT](DEBUG): Powering off loads.
2019-06-24T23:37:34.249Z,1561419454.249 [CBIT](DEBUG): Disabling WDT.
2019-06-24T23:37:34.261Z,1561419454.261 [CBIT](DEBUG): Opening all GF detection circuits.
2019-06-24T23:37:34.262Z,1561419454.262 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-06-24T23:37:34.316Z,1561419454.316 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-06-24T23:37:34.323Z,1561419454.323 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-06-24T23:37:34.598Z,1561419454.598 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2019-06-24T23:37:34.601Z,1561419454.601 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-06-24T23:37:34.657Z,1561419454.657 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-06-24T23:37:34.713Z,1561419454.713 [logger ThreadHandler](INFO): Thread cancelled.