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.