2019-09-18T21:27:18.161Z,1568842038.161 [Supervisor](DEBUG): Initializing supervisor. 2019-09-18T21:27:18.164Z,1568842038.164 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2019-09-18T21:27:18.164Z,1568842038.164 [SyncHandler](INFO): Protected caller Thread ID is 2730 2019-09-18T21:27:18.165Z,1568842038.165 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2019-09-18T21:27:18.166Z,1568842038.166 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2019-09-18T21:27:18.166Z,1568842038.166 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 2731 2019-09-18T21:27:18.169Z,1568842038.169 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2019-09-18T21:27:18.180Z,1568842038.180 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2019-09-18T21:27:18.181Z,1568842038.181 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2019-09-18T21:27:18.181Z,1568842038.181 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 2732 2019-09-18T21:27:18.182Z,1568842038.182 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2019-09-18T21:27:18.183Z,1568842038.183 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2019-09-18T21:27:18.183Z,1568842038.183 [logger ThreadHandler](INFO): Protected caller Thread ID is 2733 2019-09-18T21:27:18.185Z,1568842038.185 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2019-09-18T21:27:18.186Z,1568842038.186 [Supervisor](INFO): Looking for Config files in directory: Config/ 2019-09-18T21:27:18.187Z,1568842038.187 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2019-09-18T21:27:18.593Z,1568842038.593 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2019-09-18T21:27:18.594Z,1568842038.594 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2019-09-18T21:27:18.736Z,1568842038.736 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2019-09-18T21:27:18.736Z,1568842038.736 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2019-09-18T21:27:18.818Z,1568842038.818 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2019-09-18T21:27:18.918Z,1568842038.918 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2019-09-18T21:27:18.918Z,1568842038.918 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2019-09-18T21:27:19.014Z,1568842039.014 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2019-09-18T21:27:19.015Z,1568842039.015 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2019-09-18T21:27:19.387Z,1568842039.387 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2019-09-18T21:27:19.388Z,1568842039.388 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2019-09-18T21:27:19.493Z,1568842039.493 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2019-09-18T21:27:19.494Z,1568842039.494 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2019-09-18T21:27:19.940Z,1568842039.940 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2019-09-18T21:27:19.941Z,1568842039.941 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2019-09-18T21:27:20.136Z,1568842040.136 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2019-09-18T21:27:20.136Z,1568842040.136 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2019-09-18T21:27:20.431Z,1568842040.431 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2019-09-18T21:27:20.432Z,1568842040.432 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2019-09-18T21:27:20.639Z,1568842040.639 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2019-09-18T21:27:20.640Z,1568842040.640 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2019-09-18T21:27:20.781Z,1568842040.781 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2019-09-18T21:27:20.781Z,1568842040.781 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2019-09-18T21:27:21.381Z,1568842041.381 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2019-09-18T21:27:21.382Z,1568842041.382 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2019-09-18T21:27:21.722Z,1568842041.722 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2019-09-18T21:27:21.723Z,1568842041.723 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2019-09-18T21:27:21.926Z,1568842041.926 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2019-09-18T21:27:21.928Z,1568842041.928 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-triton/ 2019-09-18T21:27:21.929Z,1568842041.929 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/vehicle.cfg 2019-09-18T21:27:22.117Z,1568842042.117 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/secure.cfg 2019-09-18T21:27:22.202Z,1568842042.202 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Science.cfg 2019-09-18T21:27:22.334Z,1568842042.334 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Simulator.cfg 2019-09-18T21:27:22.421Z,1568842042.421 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Battery.cfg 2019-09-18T21:27:22.649Z,1568842042.649 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2019-09-18T21:27:22.650Z,1568842042.650 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/logger.cfg 2019-09-18T21:27:22.747Z,1568842042.747 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Servo.cfg 2019-09-18T21:27:22.858Z,1568842042.858 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Navigation.cfg 2019-09-18T21:27:22.994Z,1568842042.994 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Sensor.cfg 2019-09-18T21:27:23.175Z,1568842043.175 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Control.cfg 2019-09-18T21:27:23.327Z,1568842043.327 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/BIT.cfg 2019-09-18T21:27:23.610Z,1568842043.610 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2019-09-18T21:27:23.615Z,1568842043.615 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2019-09-18T21:27:23.629Z,1568842043.629 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2019-09-18T21:27:23.630Z,1568842043.630 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2019-09-18T21:27:23.695Z,1568842043.695 [VerticalControl](DEBUG): Construct VerticalControl. 2019-09-18T21:27:23.895Z,1568842043.895 [VerticalControl] Loaded 2019-09-18T21:27:23.895Z,1568842043.895 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2019-09-18T21:27:23.896Z,1568842043.896 [HorizontalControl](DEBUG): Construct HorizontalControl. 2019-09-18T21:27:23.964Z,1568842043.964 [HorizontalControl] Loaded 2019-09-18T21:27:23.964Z,1568842043.964 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2019-09-18T21:27:23.965Z,1568842043.965 [SpeedControl](DEBUG): Construct SpeedControl. 2019-09-18T21:27:23.972Z,1568842043.972 [SpeedControl] Loaded 2019-09-18T21:27:24.005Z,1568842044.005 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2019-09-18T21:27:24.006Z,1568842044.006 [LoopControl](DEBUG): Construct LoopControl. 2019-09-18T21:27:24.006Z,1568842044.006 [LoopControl] Loaded 2019-09-18T21:27:24.006Z,1568842044.006 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2019-09-18T21:27:24.007Z,1568842044.007 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2019-09-18T21:27:24.007Z,1568842044.007 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2019-09-18T21:27:24.128Z,1568842044.128 [BuoyancyServo] Loaded 2019-09-18T21:27:24.128Z,1568842044.128 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2019-09-18T21:27:24.139Z,1568842044.139 [ElevatorServo] Loaded 2019-09-18T21:27:24.139Z,1568842044.139 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2019-09-18T21:27:24.158Z,1568842044.158 [MassServo] Loaded 2019-09-18T21:27:24.158Z,1568842044.158 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2019-09-18T21:27:24.180Z,1568842044.180 [RudderServo] Loaded 2019-09-18T21:27:24.181Z,1568842044.181 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2019-09-18T21:27:24.244Z,1568842044.244 [ThrusterServo] Loaded 2019-09-18T21:27:24.244Z,1568842044.244 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2019-09-18T21:27:24.244Z,1568842044.244 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2019-09-18T21:27:24.253Z,1568842044.253 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2019-09-18T21:27:24.419Z,1568842044.419 [DepthRateCalculator] Loaded 2019-09-18T21:27:24.420Z,1568842044.420 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2019-09-18T21:27:24.425Z,1568842044.425 [PitchRateCalculator] Loaded 2019-09-18T21:27:24.425Z,1568842044.425 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2019-09-18T21:27:24.440Z,1568842044.440 [SpeedCalculator] Loaded 2019-09-18T21:27:24.441Z,1568842044.441 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2019-09-18T21:27:24.461Z,1568842044.461 [TempGradientCalculator] Loaded 2019-09-18T21:27:24.462Z,1568842044.462 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2019-09-18T21:27:24.467Z,1568842044.467 [YawRateCalculator] Loaded 2019-09-18T21:27:24.467Z,1568842044.467 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2019-09-18T21:27:24.496Z,1568842044.496 [ElevatorOffsetCalculator] Loaded 2019-09-18T21:27:24.496Z,1568842044.496 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2019-09-18T21:27:24.497Z,1568842044.497 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2019-09-18T21:27:24.497Z,1568842044.497 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2019-09-18T21:27:24.602Z,1568842044.602 [DeadReckonUsingMultipleVelocitySources] Loaded 2019-09-18T21:27:24.602Z,1568842044.602 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2019-09-18T21:27:24.622Z,1568842044.622 [NavChart] Loaded 2019-09-18T21:27:24.623Z,1568842044.623 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2019-09-18T21:27:24.627Z,1568842044.627 [UniversalFixResidualReporter] Loaded 2019-09-18T21:27:24.627Z,1568842044.627 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2019-09-18T21:27:24.627Z,1568842044.627 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2019-09-18T21:27:24.628Z,1568842044.628 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2019-09-18T21:27:24.862Z,1568842044.862 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_orientation 2019-09-18T21:27:24.867Z,1568842044.867 [AHRS_M2](INFO): created writer for : platform_orientation 2019-09-18T21:27:24.868Z,1568842044.868 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_magnetic_orientation 2019-09-18T21:27:24.874Z,1568842044.874 [AHRS_M2](INFO): created writer for : platform_magnetic_orientation 2019-09-18T21:27:24.874Z,1568842044.874 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_pitch_angle 2019-09-18T21:27:24.879Z,1568842044.879 [AHRS_M2](INFO): created writer for : platform_pitch_angle 2019-09-18T21:27:24.880Z,1568842044.880 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_roll_angle 2019-09-18T21:27:24.885Z,1568842044.885 [AHRS_M2](INFO): created writer for : platform_roll_angle 2019-09-18T21:27:24.955Z,1568842044.955 [AHRS_M2] Loaded 2019-09-18T21:27:24.955Z,1568842044.955 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2019-09-18T21:27:25.034Z,1568842045.034 [DataOverHttps] Loaded 2019-09-18T21:27:25.035Z,1568842045.035 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2019-09-18T21:27:25.036Z,1568842045.036 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 407F84E0 2019-09-18T21:27:25.036Z,1568842045.036 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 2812 2019-09-18T21:27:25.049Z,1568842045.049 [Depth_Keller] Loaded 2019-09-18T21:27:25.050Z,1568842045.050 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2019-09-18T21:27:25.054Z,1568842045.054 [DropWeight] Loaded 2019-09-18T21:27:25.055Z,1568842045.055 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2019-09-18T21:27:25.100Z,1568842045.100 [DVL_micro] Loaded 2019-09-18T21:27:25.100Z,1568842045.100 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread. 2019-09-18T21:27:25.196Z,1568842045.196 [NAL9602] Loaded 2019-09-18T21:27:25.196Z,1568842045.196 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2019-09-18T21:27:25.212Z,1568842045.212 [Onboard] Loaded 2019-09-18T21:27:25.212Z,1568842045.212 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2019-09-18T21:27:25.216Z,1568842045.216 [Radio_Surface] Loaded 2019-09-18T21:27:25.216Z,1568842045.216 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2019-09-18T21:27:25.217Z,1568842045.217 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408284E0 2019-09-18T21:27:25.217Z,1568842045.217 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 2813 2019-09-18T21:27:25.345Z,1568842045.345 [DAT] Loaded 2019-09-18T21:27:25.346Z,1568842045.346 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread. 2019-09-18T21:27:26.828Z,1568842046.828 [BPC1] Loaded 2019-09-18T21:27:26.828Z,1568842046.828 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2019-09-18T21:27:26.828Z,1568842046.828 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2019-09-18T21:27:26.829Z,1568842046.829 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2019-09-18T21:27:26.897Z,1568842046.897 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2019-09-18T21:27:26.897Z,1568842046.897 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2019-09-18T21:27:27.062Z,1568842047.062 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2019-09-18T21:27:27.062Z,1568842047.062 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2019-09-18T21:27:27.100Z,1568842047.100 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2019-09-18T21:27:27.100Z,1568842047.100 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2019-09-18T21:27:27.271Z,1568842047.271 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density 2019-09-18T21:27:27.277Z,1568842047.277 [CTD_Seabird](INFO): created writer for : sea_water_density 2019-09-18T21:27:27.277Z,1568842047.277 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth 2019-09-18T21:27:27.282Z,1568842047.282 [CTD_Seabird](INFO): created writer for : depth 2019-09-18T21:27:27.283Z,1568842047.283 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure 2019-09-18T21:27:27.288Z,1568842047.288 [CTD_Seabird](INFO): created writer for : sea_water_pressure 2019-09-18T21:27:27.288Z,1568842047.288 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity 2019-09-18T21:27:27.293Z,1568842047.293 [CTD_Seabird](INFO): created writer for : sea_water_salinity 2019-09-18T21:27:27.294Z,1568842047.294 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature 2019-09-18T21:27:27.299Z,1568842047.299 [CTD_Seabird](INFO): created writer for : sea_water_temperature 2019-09-18T21:27:27.300Z,1568842047.300 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity 2019-09-18T21:27:27.305Z,1568842047.305 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity 2019-09-18T21:27:27.306Z,1568842047.306 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water 2019-09-18T21:27:27.311Z,1568842047.311 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water 2019-09-18T21:27:27.311Z,1568842047.311 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): mass_concentration_of_oxygen_in_sea_water 2019-09-18T21:27:27.316Z,1568842047.316 [CTD_Seabird](INFO): created writer for : mass_concentration_of_oxygen_in_sea_water 2019-09-18T21:27:27.317Z,1568842047.317 [CTD_Seabird](DEBUG): LcmSlateWriter::add(DAtaURI): CTD_Seabird.sea_water_dissolved_oxygen_freq 2019-09-18T21:27:27.317Z,1568842047.317 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): dataName: sea_water_dissolved_oxygen_freq 2019-09-18T21:27:27.350Z,1568842047.350 [CTD_Seabird] Loaded 2019-09-18T21:27:27.351Z,1568842047.351 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2019-09-18T21:27:27.352Z,1568842047.352 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 409BF4E0 2019-09-18T21:27:27.352Z,1568842047.352 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 2815 2019-09-18T21:27:27.367Z,1568842047.367 [PAR_Licor] Loaded 2019-09-18T21:27:27.367Z,1568842047.367 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2019-09-18T21:27:27.414Z,1568842047.414 [WetLabsBB2FL] Loaded 2019-09-18T21:27:27.414Z,1568842047.414 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2019-09-18T21:27:27.415Z,1568842047.415 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 409EF4E0 2019-09-18T21:27:27.416Z,1568842047.416 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 2816 2019-09-18T21:27:27.416Z,1568842047.416 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2019-09-18T21:27:27.417Z,1568842047.417 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2019-09-18T21:27:27.706Z,1568842047.706 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2019-09-18T21:27:27.707Z,1568842047.707 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2019-09-18T21:27:27.835Z,1568842047.835 [SBIT](DEBUG): Construct Startup Built In Test. 2019-09-18T21:27:27.846Z,1568842047.846 [SBIT] Loaded 2019-09-18T21:27:27.846Z,1568842047.846 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2019-09-18T21:27:27.847Z,1568842047.847 [IBIT](DEBUG): Construct Initiated Built In Test. 2019-09-18T21:27:27.858Z,1568842047.858 [IBIT] Loaded 2019-09-18T21:27:27.858Z,1568842047.858 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2019-09-18T21:27:27.862Z,1568842047.862 [CBIT](DEBUG): Construct Continuous Built In Test. 2019-09-18T21:27:28.002Z,1568842048.002 [CBIT] Loaded 2019-09-18T21:27:28.002Z,1568842048.002 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2019-09-18T21:27:28.002Z,1568842048.002 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2019-09-18T21:27:28.018Z,1568842048.018 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2019-09-18T21:27:28.019Z,1568842048.019 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2019-09-18T21:27:28.031Z,1568842048.031 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2019-09-18T21:27:28.032Z,1568842048.032 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40ACE4E0 2019-09-18T21:27:28.032Z,1568842048.032 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 2817 2019-09-18T21:27:28.037Z,1568842048.037 [Supervisor](INFO): Main Thread ID is 2729 2019-09-18T21:27:28.037Z,1568842048.037 [Supervisor](DEBUG): Running supervisor. 2019-09-18T21:27:28.037Z,1568842048.037 [CommandLine ThreadHandler](INFO): Handler Thread ID is 2818 2019-09-18T21:27:28.040Z,1568842048.040 [controlThread ThreadHandler](INFO): Handler Thread ID is 2819 2019-09-18T21:27:28.040Z,1568842048.040 [controlThread](DEBUG): Initializing ControlThread 2019-09-18T21:27:28.041Z,1568842048.041 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2019-09-18T21:27:28.043Z,1568842048.043 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2019-09-18T21:27:28.043Z,1568842048.043 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2019-09-18T21:27:28.044Z,1568842048.044 [LoopControl](DEBUG): Initialize LoopControlComponent. 2019-09-18T21:27:28.045Z,1568842048.045 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2019-09-18T21:27:28.046Z,1568842048.046 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2019-09-18T21:27:28.046Z,1568842048.046 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2019-09-18T21:27:28.046Z,1568842048.046 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2019-09-18T21:27:28.047Z,1568842048.047 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2019-09-18T21:27:28.047Z,1568842048.047 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2019-09-18T21:27:28.048Z,1568842048.048 [NavChart](DEBUG): Initialize NavChart Navigation. 2019-09-18T21:27:28.049Z,1568842048.049 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2019-09-18T21:27:28.057Z,1568842048.057 [SBIT](INFO): Initialize SBIT Component. 2019-09-18T21:27:28.058Z,1568842048.058 [SBIT](IMPORTANT): git: 2019-09-12-A 2019-09-18T21:27:28.058Z,1568842048.058 [SBIT](INFO): git hash: eb701a7227645e802542eb6676257ee77fc4e0fc 2019-09-18T21:27:28.058Z,1568842048.058 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2019-09-18T21:27:28.059Z,1568842048.059 [SBIT](INFO): Kernel Reporting Different Version From Configuration. Kernel Expected: #1 PREEMPT Tue Dec 18 21:19:28 PST 2018 Kernel Reported: #1 PREEMPT Thu Feb 21 11:17:40 PST 2019 2019-09-18T21:27:28.060Z,1568842048.060 [SBIT](INFO): Beginning SBIT in 37.000000 seconds. 2019-09-18T21:27:28.061Z,1568842048.061 [IBIT](INFO): Initialize IBIT Component. 2019-09-18T21:27:28.062Z,1568842048.062 [CBIT](DEBUG): Initialize CBIT Component. 2019-09-18T21:27:28.063Z,1568842048.063 [logger ThreadHandler](INFO): Handler Thread ID is 2820 2019-09-18T21:27:28.073Z,1568842048.073 [CBIT](DEBUG): Initialized mux pins. 2019-09-18T21:27:28.073Z,1568842048.073 [CBIT](DEBUG): Initializing the watchdog timer. 2019-09-18T21:27:28.081Z,1568842048.081 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 2821 2019-09-18T21:27:28.082Z,1568842048.082 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2019-09-18T21:27:28.093Z,1568842048.093 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 2822 2019-09-18T21:27:28.097Z,1568842048.097 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2019-09-18T21:27:28.097Z,1568842048.097 [CBIT](DEBUG): Initializing heartbeat. 2019-09-18T21:27:28.105Z,1568842048.105 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 2823 2019-09-18T21:27:28.106Z,1568842048.106 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2019-09-18T21:27:28.109Z,1568842048.109 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20 2019-09-18T21:27:28.111Z,1568842048.111 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 2825 2019-09-18T21:27:28.112Z,1568842048.112 [WetLabsBB2FL](INFO): Powering down 2019-09-18T21:27:28.139Z,1568842048.139 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 2826 2019-09-18T21:27:28.142Z,1568842048.142 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2019-09-18T21:27:28.142Z,1568842048.142 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2019-09-18T21:27:28.142Z,1568842048.142 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2019-09-18T21:27:28.142Z,1568842048.142 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2019-09-18T21:27:28.142Z,1568842048.142 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2019-09-18T21:27:28.143Z,1568842048.143 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2019-09-18T21:27:28.143Z,1568842048.143 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000 2019-09-18T21:27:28.143Z,1568842048.143 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2019-09-18T21:27:28.143Z,1568842048.143 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2019-09-18T21:27:28.143Z,1568842048.143 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2019-09-18T21:27:28.143Z,1568842048.143 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000 2019-09-18T21:27:28.144Z,1568842048.144 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2019-09-18T21:27:28.144Z,1568842048.144 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000 2019-09-18T21:27:28.144Z,1568842048.144 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2019-09-18T21:27:28.144Z,1568842048.144 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000 2019-09-18T21:27:28.144Z,1568842048.144 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2019-09-18T21:27:28.169Z,1568842048.169 [CBIT](DEBUG): Deactivating GF circuits. 2019-09-18T21:27:28.170Z,1568842048.170 [CBIT](DEBUG): Deactivating emergency mode. 2019-09-18T21:27:28.205Z,1568842048.205 [CBIT](DEBUG): Backplane powered. 2019-09-18T21:27:28.206Z,1568842048.206 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2019-09-18T21:27:28.215Z,1568842048.215 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2019-09-18T21:27:28.226Z,1568842048.226 [MissionManager](DEBUG): 2019-09-18T21:27:28.226Z,1568842048.226 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2019-09-18T21:27:28.301Z,1568842048.301 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2019-09-18T21:27:28.302Z,1568842048.302 [Default:A.Wait](DEBUG): Construct Wait. 2019-09-18T21:27:28.304Z,1568842048.304 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2019-09-18T21:27:28.339Z,1568842048.339 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2019-09-18T21:27:28.341Z,1568842048.341 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2019-09-18T21:27:28.371Z,1568842048.371 [Default:E.Execute](DEBUG): Construct Execute. 2019-09-18T21:27:28.374Z,1568842048.374 [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-09-18T21:27:28.397Z,1568842048.397 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,DVL_micro,NAL9602,Onboard,DAT,BPC1,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, 2019-09-18T21:27:28.403Z,1568842048.403 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2019-09-18T21:27:28.497Z,1568842048.497 [Radio_Surface](INFO): Powering up 2019-09-18T21:27:28.559Z,1568842048.559 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2 2019-09-18T21:27:28.559Z,1568842048.559 [DAT](INFO): Powering up 2019-09-18T21:27:28.559Z,1568842048.559 [DAT](DEBUG): Initializing DAT. 2019-09-18T21:27:28.641Z,1568842048.641 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2 2019-09-18T21:27:28.679Z,1568842048.679 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2019-09-18T21:27:28.681Z,1568842048.681 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2019-09-18T21:27:28.682Z,1568842048.682 [ElevatorServo](DEBUG): Initializing EZServoServo. 2019-09-18T21:27:28.693Z,1568842048.693 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2019-09-18T21:27:28.694Z,1568842048.694 [MassServo](DEBUG): Initializing EZServoServo. 2019-09-18T21:27:28.705Z,1568842048.705 [MassServo](DEBUG): Initializing MassServo. 2019-09-18T21:27:28.706Z,1568842048.706 [RudderServo](DEBUG): Initializing EZServoServo. 2019-09-18T21:27:28.717Z,1568842048.717 [RudderServo](DEBUG): Initializing RudderServo. 2019-09-18T21:27:28.718Z,1568842048.718 [ThrusterServo](DEBUG): Initializing EZServoServo. 2019-09-18T21:27:28.729Z,1568842048.729 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2019-09-18T21:27:28.830Z,1568842048.830 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2019-09-18T21:27:28.830Z,1568842048.830 [DropWeight] Hardware Fault, FailCount= 1 2019-09-18T21:27:28.830Z,1568842048.830 [DropWeight](ERROR): Hardware Fault 2019-09-18T21:27:28.935Z,1568842048.935 [CommandLine](FAULT): Scheduling is paused 2019-09-18T21:27:28.935Z,1568842048.935 [CBIT](INFO): Critical error at 20190918T212728 2019-09-18T21:27:28.936Z,1568842048.936 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals 2019-09-18T21:27:28.938Z,1568842048.938 [CBIT](ERROR): Hardware Fault in component: DropWeight 2019-09-18T21:27:28.939Z,1568842048.939 [CBIT](CRITICAL): Hardware Fault in component: DropWeight 2019-09-18T21:27:29.569Z,1568842049.569 [RudderServo](ERROR): Rudder initialization uart error serial timeout 2019-09-18T21:27:29.569Z,1568842049.569 [RudderServo](FAULT): Rudder failed to initialize 2019-09-18T21:27:29.569Z,1568842049.569 [RudderServo] Communications Fault, FailCount= 1 2019-09-18T21:27:29.569Z,1568842049.569 [RudderServo](ERROR): Communications Fault 2019-09-18T21:27:29.738Z,1568842049.738 [CBIT](INFO): Critical error at 20190918T212728 2019-09-18T21:27:29.741Z,1568842049.741 [CBIT](ERROR): Communications Fault in component: RudderServo 2019-09-18T21:27:29.942Z,1568842049.942 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2019-09-18T21:27:29.942Z,1568842049.942 [RudderServo](INFO): Powering down 2019-09-18T21:27:30.609Z,1568842050.609 [RudderServo](DEBUG): Initializing EZServoServo. 2019-09-18T21:27:30.730Z,1568842050.730 [RudderServo](DEBUG): Initializing RudderServo. 2019-09-18T21:27:30.734Z,1568842050.734 [CBIT](INFO): Clearing failed state for component RudderServo 2019-09-18T21:27:30.734Z,1568842050.734 [RudderServo] No Fault, FailCount= 1 2019-09-18T21:27:32.089Z,1568842052.089 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-18T21:27:32.517Z,1568842052.517 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-18T21:27:33.049Z,1568842053.049 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-18T21:27:33.705Z,1568842053.705 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-18T21:27:34.165Z,1568842054.165 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-18T21:27:34.625Z,1568842054.625 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-18T21:27:35.101Z,1568842055.101 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-18T21:27:35.629Z,1568842055.629 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-18T21:27:36.041Z,1568842056.041 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-18T21:27:36.625Z,1568842056.625 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-18T21:27:37.097Z,1568842057.097 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-18T21:27:37.529Z,1568842057.529 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-18T21:27:38.045Z,1568842058.045 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-18T21:27:38.213Z,1568842058.213 [CBIT](CRITICAL): Environmental Failure. Press:14.872351 PSI. Humidity:49%. Temp:24 C. ABORTING MISSION 2019-09-18T21:27:38.545Z,1568842058.545 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-18T21:27:38.663Z,1568842058.663 [CBIT](INFO): Critical error at 20190918T212738 2019-09-18T21:27:38.997Z,1568842058.997 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-18T21:27:39.441Z,1568842059.441 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-18T21:27:39.901Z,1568842059.901 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-18T21:27:40.337Z,1568842060.337 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-18T21:27:40.773Z,1568842060.773 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-18T21:27:41.157Z,1568842061.157 [CTD_Seabird](FAULT): Failed to initialize within timeout. 2019-09-18T21:27:41.157Z,1568842061.157 [CTD_Seabird] Communications Fault, FailCount= 1 2019-09-18T21:27:41.157Z,1568842061.157 [CTD_Seabird](ERROR): Communications Fault 2019-09-18T21:27:41.233Z,1568842061.233 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-18T21:27:41.386Z,1568842061.386 [CBIT](ERROR): Communications Fault in component: CTD_Seabird 2019-09-18T21:27:41.561Z,1568842061.561 [CTD_Seabird](INFO): Powering down 2019-09-18T21:27:41.717Z,1568842061.717 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-18T21:27:41.717Z,1568842061.717 [AHRS_M2](FAULT): Failed to initialize within timeout. 2019-09-18T21:27:41.717Z,1568842061.717 [AHRS_M2] Communications Fault, FailCount= 1 2019-09-18T21:27:41.717Z,1568842061.717 [AHRS_M2](ERROR): Communications Fault 2019-09-18T21:27:41.822Z,1568842061.822 [CBIT](ERROR): Communications Fault in component: AHRS_M2 2019-09-18T21:27:41.827Z,1568842061.827 [AHRS_M2](INFO): Powering down 2019-09-18T21:27:41.980Z,1568842061.980 [DAT](INFO): setting local address to 5 2019-09-18T21:27:42.254Z,1568842062.254 [DAT](INFO): set local address to 5 2019-09-18T21:27:42.750Z,1568842062.750 [CBIT](INFO): Clearing failed state for component AHRS_M2 2019-09-18T21:27:42.750Z,1568842062.750 [AHRS_M2] No Fault, FailCount= 1 2019-09-18T21:27:42.750Z,1568842062.750 [CBIT](INFO): Clearing failed state for component CTD_Seabird 2019-09-18T21:27:42.750Z,1568842062.750 [CTD_Seabird] No Fault, FailCount= 1 2019-09-18T21:27:42.933Z,1568842062.933 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2019-09-18T21:27:42.935Z,1568842062.935 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20 2019-09-18T21:27:43.011Z,1568842063.011 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004793 2019-09-18T21:27:43.036Z,1568842063.036 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2019-09-18T21:27:45.874Z,1568842065.874 [DVL_micro](ERROR): No DVL communication! Re-initializing 2019-09-18T21:27:45.874Z,1568842065.874 [DVL_micro] Communications Fault, FailCount= 1 2019-09-18T21:27:45.874Z,1568842065.874 [DVL_micro](ERROR): Communications Fault 2019-09-18T21:27:45.953Z,1568842065.953 [CBIT](ERROR): Communications Fault in component: DVL_micro 2019-09-18T21:27:46.593Z,1568842066.593 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-18T21:27:46.669Z,1568842066.669 [DVL_micro](INFO): Powering down 2019-09-18T21:27:47.085Z,1568842067.085 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-18T21:27:47.505Z,1568842067.505 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-18T21:27:47.569Z,1568842067.569 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-09-18T21:27:47.570Z,1568842067.570 [DVL_micro] No Fault, FailCount= 1 2019-09-18T21:27:47.913Z,1568842067.913 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-18T21:27:48.337Z,1568842068.337 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-18T21:27:48.557Z,1568842068.557 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout 2019-09-18T21:27:55.391Z,1568842075.391 [NAL9602](INFO): Powering up NAL9602 2019-09-18T21:27:55.985Z,1568842075.985 [CTD_Seabird](FAULT): Failed to initialize within timeout. 2019-09-18T21:27:55.985Z,1568842075.985 [CTD_Seabird] Communications Fault, FailCount= 2 2019-09-18T21:27:55.985Z,1568842075.985 [CTD_Seabird](ERROR): Communications Fault 2019-09-18T21:27:56.181Z,1568842076.181 [CBIT](ERROR): Communications Fault in component: CTD_Seabird 2019-09-18T21:27:56.389Z,1568842076.389 [CTD_Seabird](INFO): Powering down 2019-09-18T21:27:57.384Z,1568842077.384 [CBIT](INFO): Clearing failed state for component CTD_Seabird 2019-09-18T21:27:57.384Z,1568842077.384 [CTD_Seabird] No Fault, FailCount= 2 2019-09-18T21:27:57.733Z,1568842077.733 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2019-09-18T21:27:57.735Z,1568842077.735 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20 2019-09-18T21:28:03.797Z,1568842083.797 [AHRS_M2](FAULT): Failed to acquire valid data within timeout. 2019-09-18T21:28:03.797Z,1568842083.797 [AHRS_M2] Data Fault, FailCount= 2 2019-09-18T21:28:03.797Z,1568842083.797 [AHRS_M2](ERROR): Data Fault 2019-09-18T21:28:03.874Z,1568842083.874 [CBIT](ERROR): Data Fault in component: AHRS_M2 2019-09-18T21:28:04.188Z,1568842084.188 [AHRS_M2](INFO): Powering down 2019-09-18T21:28:05.080Z,1568842085.080 [CBIT](INFO): Clearing failed state for component AHRS_M2 2019-09-18T21:28:05.080Z,1568842085.080 [AHRS_M2] No Fault, FailCount= 2 2019-09-18T21:28:05.400Z,1568842085.400 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2019-09-18T21:28:05.410Z,1568842085.410 [DVL_micro](ERROR): No DVL communication! Re-initializing 2019-09-18T21:28:05.410Z,1568842085.410 [DVL_micro] Communications Fault, FailCount= 2 2019-09-18T21:28:05.411Z,1568842085.411 [DVL_micro](ERROR): Communications Fault 2019-09-18T21:28:05.510Z,1568842085.510 [SBIT](IMPORTANT): Beginning Startup BIT 2019-09-18T21:28:05.514Z,1568842085.514 [CBIT](ERROR): Communications Fault in component: DVL_micro 2019-09-18T21:28:05.514Z,1568842085.514 [CBIT](IMPORTANT): Beginning ground fault scan 2019-09-18T21:28:05.885Z,1568842085.885 [DVL_micro](INFO): Powering down 2019-09-18T21:28:06.214Z,1568842086.214 [NAL9602](INFO): NAL9602 initialized 2019-09-18T21:28:06.758Z,1568842086.758 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-09-18T21:28:06.758Z,1568842086.758 [DVL_micro] No Fault, FailCount= 2 2019-09-18T21:28:07.053Z,1568842087.053 [NAL9602](DEBUG): Fix Requested 2019-09-18T21:28:09.089Z,1568842089.089 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-09-18T21:28:09.617Z,1568842089.617 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-09-18T21:28:10.301Z,1568842090.301 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-09-18T21:28:10.785Z,1568842090.785 [CTD_Seabird](FAULT): Failed to initialize within timeout. 2019-09-18T21:28:10.785Z,1568842090.785 [CTD_Seabird] Communications Fault, FailCount= 3 2019-09-18T21:28:10.785Z,1568842090.785 [CTD_Seabird](ERROR): Communications Fault 2019-09-18T21:28:10.801Z,1568842090.801 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-09-18T21:28:11.078Z,1568842091.078 [CBIT](ERROR): Communications Fault in component: CTD_Seabird 2019-09-18T21:28:11.078Z,1568842091.078 [CBIT](FAULT): Communications Fault in component: CTD_Seabird 2019-09-18T21:28:11.191Z,1568842091.191 [CTD_Seabird](INFO): Powering down 2019-09-18T21:28:11.517Z,1568842091.517 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-09-18T21:28:11.989Z,1568842091.989 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-09-18T21:28:12.425Z,1568842092.425 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-09-18T21:28:12.861Z,1568842092.861 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-09-18T21:28:13.409Z,1568842093.409 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-09-18T21:28:13.849Z,1568842093.849 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-09-18T21:28:14.281Z,1568842094.281 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-09-18T21:28:14.805Z,1568842094.805 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-09-18T21:28:15.241Z,1568842095.241 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-09-18T21:28:15.685Z,1568842095.685 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-09-18T21:28:16.209Z,1568842096.209 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-09-18T21:28:16.729Z,1568842096.729 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-09-18T21:28:17.133Z,1568842097.133 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-09-18T21:28:17.609Z,1568842097.609 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-09-18T21:28:17.677Z,1568842097.677 [CBIT](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): 0.006117 CHAN A1 (24V): -0.030220 CHAN A2 (12V): -0.005255 CHAN A3 (5V): -0.002687 CHAN B0 (3.3V): -0.000911 CHAN B1 (3.15aV): -0.001093 CHAN B2 (3.15bV): -0.000457 CHAN B3 (GND): -0.000488 OPEN: -0.001245 Full Scale Calc: 4.765 mA, -1.589 mA 2019-09-18T21:28:18.045Z,1568842098.045 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-09-18T21:28:18.465Z,1568842098.465 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-09-18T21:28:18.465Z,1568842098.465 [AHRS_M2](FAULT): Failed to initialize within timeout. 2019-09-18T21:28:18.465Z,1568842098.465 [AHRS_M2] Communications Fault, FailCount= 3 2019-09-18T21:28:18.465Z,1568842098.465 [AHRS_M2](ERROR): Communications Fault 2019-09-18T21:28:18.552Z,1568842098.552 [CBIT](ERROR): Communications Fault in component: AHRS_M2 2019-09-18T21:28:18.561Z,1568842098.561 [AHRS_M2](INFO): Powering down 2019-09-18T21:28:19.453Z,1568842099.453 [CBIT](INFO): Clearing failed state for component AHRS_M2 2019-09-18T21:28:19.454Z,1568842099.454 [AHRS_M2] No Fault, FailCount= 3 2019-09-18T21:28:19.768Z,1568842099.768 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2019-09-18T21:28:23.501Z,1568842103.501 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-09-18T21:28:23.989Z,1568842103.989 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-09-18T21:28:24.493Z,1568842104.493 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-09-18T21:28:24.498Z,1568842104.498 [DVL_micro](ERROR): No DVL communication! Re-initializing 2019-09-18T21:28:24.498Z,1568842104.498 [DVL_micro] Communications Fault, FailCount= 3 2019-09-18T21:28:24.498Z,1568842104.498 [DVL_micro](ERROR): Communications Fault 2019-09-18T21:28:24.698Z,1568842104.698 [CBIT](ERROR): Communications Fault in component: DVL_micro 2019-09-18T21:28:24.698Z,1568842104.698 [CBIT](CRITICAL): Communications Fault in component: DVL_micro 2019-09-18T21:28:25.025Z,1568842105.025 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-09-18T21:28:25.101Z,1568842105.101 [DVL_micro](INFO): Powering down 2019-09-18T21:28:25.260Z,1568842105.260 [CBIT](INFO): Critical error at 20190918T212824 2019-09-18T21:28:25.593Z,1568842105.593 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-09-18T21:28:26.205Z,1568842106.205 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-09-18T21:28:26.781Z,1568842106.781 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-09-18T21:28:27.229Z,1568842107.229 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-09-18T21:28:27.685Z,1568842107.685 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-09-18T21:28:28.125Z,1568842108.125 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-09-18T21:28:28.557Z,1568842108.557 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-09-18T21:28:29.001Z,1568842109.001 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-09-18T21:28:29.429Z,1568842109.429 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-09-18T21:28:29.897Z,1568842109.897 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-09-18T21:28:30.381Z,1568842110.381 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-09-18T21:28:30.841Z,1568842110.841 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-09-18T21:28:31.305Z,1568842111.305 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-09-18T21:28:31.753Z,1568842111.753 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-09-18T21:28:32.197Z,1568842112.197 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-09-18T21:28:32.641Z,1568842112.641 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-09-18T21:28:33.093Z,1568842113.093 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-09-18T21:28:33.093Z,1568842113.093 [AHRS_M2](FAULT): Failed to initialize within timeout. 2019-09-18T21:28:33.093Z,1568842113.093 [AHRS_M2] Communications Fault, FailCount= 4 2019-09-18T21:28:33.093Z,1568842113.093 [AHRS_M2](ERROR): Communications Fault 2019-09-18T21:28:33.238Z,1568842113.238 [CBIT](ERROR): Communications Fault in component: AHRS_M2 2019-09-18T21:28:33.243Z,1568842113.243 [AHRS_M2](INFO): Powering down 2019-09-18T21:28:34.150Z,1568842114.150 [CBIT](INFO): Clearing failed state for component AHRS_M2 2019-09-18T21:28:34.150Z,1568842114.150 [AHRS_M2] No Fault, FailCount= 4 2019-09-18T21:28:34.452Z,1568842114.452 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2019-09-18T21:28:38.009Z,1568842118.009 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-09-18T21:28:38.425Z,1568842118.425 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-09-18T21:28:38.817Z,1568842118.817 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-09-18T21:28:39.221Z,1568842119.221 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-09-18T21:28:39.629Z,1568842119.629 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-09-18T21:28:40.029Z,1568842120.029 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-09-18T21:28:40.429Z,1568842120.429 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-09-18T21:28:40.837Z,1568842120.837 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-09-18T21:28:41.237Z,1568842121.237 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-09-18T21:28:41.665Z,1568842121.665 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-09-18T21:28:42.085Z,1568842122.085 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-09-18T21:28:42.509Z,1568842122.509 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-09-18T21:28:42.957Z,1568842122.957 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-09-18T21:28:43.381Z,1568842123.381 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-09-18T21:28:43.793Z,1568842123.793 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-09-18T21:28:44.209Z,1568842124.209 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-09-18T21:28:44.645Z,1568842124.645 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-09-18T21:28:45.049Z,1568842125.049 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-09-18T21:28:45.465Z,1568842125.465 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-09-18T21:28:45.861Z,1568842125.861 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-09-18T21:28:46.257Z,1568842126.257 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-09-18T21:28:46.669Z,1568842126.669 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-09-18T21:28:47.221Z,1568842127.221 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-09-18T21:28:48.049Z,1568842128.049 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout 2019-09-18T21:28:48.049Z,1568842128.049 [AHRS_M2](FAULT): Failed to initialize within timeout. 2019-09-18T21:28:48.049Z,1568842128.049 [AHRS_M2] Communications Fault, FailCount= 5 2019-09-18T21:28:48.049Z,1568842128.049 [AHRS_M2](ERROR): Communications Fault 2019-09-18T21:28:48.186Z,1568842128.186 [CBIT](ERROR): Communications Fault in component: AHRS_M2 2019-09-18T21:28:48.186Z,1568842128.186 [CBIT](CRITICAL): Communications Fault in component: AHRS_M2 2019-09-18T21:28:48.192Z,1568842128.192 [AHRS_M2](INFO): Powering down 2019-09-18T21:28:48.408Z,1568842128.408 [CBIT](INFO): Critical error at 20190918T212848 2019-09-18T21:28:58.720Z,1568842138.720 [SBIT](IMPORTANT): SBIT PASSED 2019-09-18T21:28:58.761Z,1568842138.761 [CommandLine](IMPORTANT): got command configSet list 2019-09-18T21:28:58.761Z,1568842138.761 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2019-09-18T21:28:58.762Z,1568842138.762 [CommandLine](IMPORTANT): CBIT.gf24Offset=180 microampere; 2019-09-18T21:28:58.762Z,1568842138.762 [CommandLine](IMPORTANT): Express linearApproximation Tracking.range_to_contact 10.000000 meter; 2019-09-18T21:28:58.762Z,1568842138.762 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=270 cubic_centimeter; 2019-09-18T21:28:58.762Z,1568842138.762 [CommandLine](IMPORTANT): VerticalControl.massDefault=-4.25 millimeter; 2019-09-18T21:28:59.126Z,1568842139.126 [MissionManager](IMPORTANT): Started mission Startup 2019-09-18T21:28:59.127Z,1568842139.127 [Startup] Running Loop=1 2019-09-18T21:28:59.127Z,1568842139.127 [Startup](DEBUG): Aggregate::initialize Startup 2019-09-18T21:28:59.127Z,1568842139.127 [Startup:A.GoToSurface] Running Loop=1 2019-09-18T21:28:59.127Z,1568842139.127 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2019-09-18T21:28:59.128Z,1568842139.128 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2019-09-18T21:28:59.128Z,1568842139.128 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2019-09-18T21:28:59.128Z,1568842139.128 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2019-09-18T21:28:59.129Z,1568842139.129 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2019-09-18T21:28:59.129Z,1568842139.129 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2019-09-18T21:28:59.131Z,1568842139.131 [Startup:StartupSatComms] Running Loop=1 2019-09-18T21:28:59.131Z,1568842139.131 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2019-09-18T21:28:59.131Z,1568842139.131 [Startup:StartupSatComms:A] Running Loop=1 2019-09-18T21:28:59.535Z,1568842139.535 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2019-09-18T21:29:28.237Z,1568842168.237 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds. 2019-09-18T21:29:28.238Z,1568842168.238 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2019-09-18T21:29:28.238Z,1568842168.238 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-09-18T21:29:28.248Z,1568842168.248 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-09-18T21:29:28.646Z,1568842168.646 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-09-18T21:29:28.646Z,1568842168.646 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2019-09-18T21:29:59.334Z,1568842199.334 [Startup:StartupSatComms:A](INFO): Timed out from 2019-09-18T21:28:59.1Z 2019-09-18T21:29:59.334Z,1568842199.334 [Startup:StartupSatComms:A] Stopped 2019-09-18T21:29:59.334Z,1568842199.334 [Startup:StartupSatComms:B] Running Loop=1 2019-09-18T21:29:59.743Z,1568842199.743 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2019-09-18T21:30:06.284Z,1568842206.284 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190918T173034/Courier0007.lzma 2019-09-18T21:30:08.290Z,1568842208.290 [DataOverHttps](INFO): Moved sent file to Logs/20190918T173034/Courier0007.lzma.bak 2019-09-18T21:30:08.291Z,1568842208.291 [DataOverHttps](INFO): SBD MOMSN=11787722 2019-09-18T21:30:24.826Z,1568842224.826 [DataOverHttps](INFO): Sending 255 bytes from file Logs/20190918T212718/Courier0000.lzma 2019-09-18T21:30:26.830Z,1568842226.830 [DataOverHttps](INFO): Moved sent file to Logs/20