2020-11-05T19:16:48.788Z,1604603808.788 [Supervisor](DEBUG): Initializing supervisor.
2020-11-05T19:16:48.791Z,1604603808.791 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2020-11-05T19:16:48.791Z,1604603808.791 [SyncHandler](INFO): Protected caller Thread ID is 7374
2020-11-05T19:16:48.792Z,1604603808.792 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2020-11-05T19:16:48.793Z,1604603808.793 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2020-11-05T19:16:48.793Z,1604603808.793 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 7375
2020-11-05T19:16:48.796Z,1604603808.796 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2020-11-05T19:16:48.813Z,1604603808.813 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2020-11-05T19:16:48.813Z,1604603808.813 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2020-11-05T19:16:48.814Z,1604603808.814 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 7376
2020-11-05T19:16:48.814Z,1604603808.814 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2020-11-05T19:16:48.815Z,1604603808.815 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2020-11-05T19:16:48.816Z,1604603808.816 [logger ThreadHandler](INFO): Protected caller Thread ID is 7377
2020-11-05T19:16:48.818Z,1604603808.818 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2020-11-05T19:16:48.818Z,1604603808.818 [Supervisor](INFO): Looking for Config files in directory: Config/
2020-11-05T19:16:48.822Z,1604603808.822 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2020-11-05T19:16:48.979Z,1604603808.979 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2020-11-05T19:16:48.981Z,1604603808.981 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2020-11-05T19:16:49.546Z,1604603809.546 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2020-11-05T19:16:49.547Z,1604603809.547 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2020-11-05T19:16:49.740Z,1604603809.740 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2020-11-05T19:16:49.741Z,1604603809.741 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2020-11-05T19:16:49.837Z,1604603809.837 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2020-11-05T19:16:49.839Z,1604603809.839 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2020-11-05T19:16:49.941Z,1604603809.941 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2020-11-05T19:16:49.943Z,1604603809.943 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2020-11-05T19:16:50.022Z,1604603810.022 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2020-11-05T19:16:50.159Z,1604603810.159 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2020-11-05T19:16:50.159Z,1604603810.159 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2020-11-05T19:16:50.438Z,1604603810.438 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2020-11-05T19:16:50.438Z,1604603810.438 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2020-11-05T19:16:50.922Z,1604603810.922 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2020-11-05T19:16:50.923Z,1604603810.923 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2020-11-05T19:16:51.063Z,1604603811.063 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2020-11-05T19:16:51.065Z,1604603811.065 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2020-11-05T19:16:51.245Z,1604603811.245 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2020-11-05T19:16:51.246Z,1604603811.246 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2020-11-05T19:16:51.851Z,1604603811.851 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2020-11-05T19:16:51.853Z,1604603811.853 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2020-11-05T19:16:52.062Z,1604603812.062 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2020-11-05T19:16:52.063Z,1604603812.063 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2020-11-05T19:16:52.255Z,1604603812.255 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2020-11-05T19:16:52.256Z,1604603812.256 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2020-11-05T19:16:52.651Z,1604603812.651 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2020-11-05T19:16:52.653Z,1604603812.653 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2020-11-05T19:16:52.965Z,1604603812.965 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2020-11-05T19:16:52.967Z,1604603812.967 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-pontus/
2020-11-05T19:16:52.969Z,1604603812.969 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/secure.cfg
2020-11-05T19:16:53.051Z,1604603813.051 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Sensor.cfg
2020-11-05T19:16:53.200Z,1604603813.200 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Servo.cfg
2020-11-05T19:16:53.304Z,1604603813.304 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Simulator.cfg
2020-11-05T19:16:53.388Z,1604603813.388 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/logger.cfg
2020-11-05T19:16:53.481Z,1604603813.481 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/vehicle.cfg
2020-11-05T19:16:53.742Z,1604603813.742 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Battery.cfg
2020-11-05T19:16:54.396Z,1604603814.396 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2020-11-05T19:16:54.397Z,1604603814.397 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Navigation.cfg
2020-11-05T19:16:54.489Z,1604603814.489 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/BIT.cfg
2020-11-05T19:16:54.584Z,1604603814.584 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Science.cfg
2020-11-05T19:16:54.709Z,1604603814.709 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Control.cfg
2020-11-05T19:16:54.806Z,1604603814.806 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2020-11-05T19:16:54.823Z,1604603814.823 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2020-11-05T19:16:54.901Z,1604603814.901 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2020-11-05T19:16:54.902Z,1604603814.902 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2020-11-05T19:16:54.947Z,1604603814.947 [VerticalControl](DEBUG): Construct VerticalControl.
2020-11-05T19:16:55.004Z,1604603815.004 [VerticalControl] Loaded
2020-11-05T19:16:55.005Z,1604603815.005 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2020-11-05T19:16:55.005Z,1604603815.005 [HorizontalControl](DEBUG): Construct HorizontalControl.
2020-11-05T19:16:55.041Z,1604603815.041 [HorizontalControl] Loaded
2020-11-05T19:16:55.041Z,1604603815.041 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2020-11-05T19:16:55.042Z,1604603815.042 [SpeedControl](DEBUG): Construct SpeedControl.
2020-11-05T19:16:55.045Z,1604603815.045 [SpeedControl] Loaded
2020-11-05T19:16:55.045Z,1604603815.045 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2020-11-05T19:16:55.046Z,1604603815.046 [LoopControl](DEBUG): Construct LoopControl.
2020-11-05T19:16:55.046Z,1604603815.046 [LoopControl] Loaded
2020-11-05T19:16:55.046Z,1604603815.046 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2020-11-05T19:16:55.047Z,1604603815.047 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2020-11-05T19:16:55.047Z,1604603815.047 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2020-11-05T19:16:55.085Z,1604603815.085 [DepthRateCalculator] Loaded
2020-11-05T19:16:55.085Z,1604603815.085 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2020-11-05T19:16:55.088Z,1604603815.088 [PitchRateCalculator] Loaded
2020-11-05T19:16:55.088Z,1604603815.088 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2020-11-05T19:16:55.096Z,1604603815.096 [SpeedCalculator] Loaded
2020-11-05T19:16:55.096Z,1604603815.096 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2020-11-05T19:16:55.107Z,1604603815.107 [TempGradientCalculator] Loaded
2020-11-05T19:16:55.107Z,1604603815.107 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2020-11-05T19:16:55.110Z,1604603815.110 [YawRateCalculator] Loaded
2020-11-05T19:16:55.110Z,1604603815.110 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2020-11-05T19:16:55.124Z,1604603815.124 [ElevatorOffsetCalculator] Loaded
2020-11-05T19:16:55.124Z,1604603815.124 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2020-11-05T19:16:55.124Z,1604603815.124 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2020-11-05T19:16:55.125Z,1604603815.125 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2020-11-05T19:16:55.152Z,1604603815.152 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2020-11-05T19:16:55.153Z,1604603815.153 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2020-11-05T19:16:55.235Z,1604603815.235 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2020-11-05T19:16:55.235Z,1604603815.235 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2020-11-05T19:16:55.512Z,1604603815.512 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2020-11-05T19:16:55.512Z,1604603815.512 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2020-11-05T19:16:55.607Z,1604603815.607 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2020-11-05T19:16:55.607Z,1604603815.607 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2020-11-05T19:16:55.899Z,1604603815.899 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_orientation
2020-11-05T19:16:55.902Z,1604603815.902 [AHRS_M2](INFO): created writer for : platform_orientation
2020-11-05T19:16:55.903Z,1604603815.903 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_magnetic_orientation
2020-11-05T19:16:55.906Z,1604603815.906 [AHRS_M2](INFO): created writer for : platform_magnetic_orientation
2020-11-05T19:16:55.907Z,1604603815.907 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_pitch_angle
2020-11-05T19:16:55.909Z,1604603815.909 [AHRS_M2](INFO): created writer for : platform_pitch_angle
2020-11-05T19:16:55.910Z,1604603815.910 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_roll_angle
2020-11-05T19:16:55.912Z,1604603815.912 [AHRS_M2](INFO): created writer for : platform_roll_angle
2020-11-05T19:16:55.948Z,1604603815.948 [AHRS_M2] Loaded
2020-11-05T19:16:55.948Z,1604603815.948 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2020-11-05T19:16:56.018Z,1604603816.018 [DataOverHttps] Loaded
2020-11-05T19:16:56.019Z,1604603816.019 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2020-11-05T19:16:56.020Z,1604603816.020 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4090F4E0
2020-11-05T19:16:56.020Z,1604603816.020 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 7461
2020-11-05T19:16:56.036Z,1604603816.036 [Depth_Keller] Loaded
2020-11-05T19:16:56.037Z,1604603816.037 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2020-11-05T19:16:56.039Z,1604603816.039 [DropWeight] Loaded
2020-11-05T19:16:56.039Z,1604603816.039 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2020-11-05T19:16:56.092Z,1604603816.092 [NAL9602] Loaded
2020-11-05T19:16:56.093Z,1604603816.093 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2020-11-05T19:16:56.118Z,1604603816.118 [Onboard] Loaded
2020-11-05T19:16:56.118Z,1604603816.118 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2020-11-05T19:16:56.119Z,1604603816.119 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 4093F4E0
2020-11-05T19:16:56.119Z,1604603816.119 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 7462
2020-11-05T19:16:56.129Z,1604603816.129 [Radio_Surface] Loaded
2020-11-05T19:16:56.130Z,1604603816.130 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2020-11-05T19:16:56.130Z,1604603816.130 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4096F4E0
2020-11-05T19:16:56.131Z,1604603816.131 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 7463
2020-11-05T19:16:56.200Z,1604603816.200 [DAT] Loaded
2020-11-05T19:16:56.201Z,1604603816.201 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread.
2020-11-05T19:16:56.967Z,1604603816.967 [BPC1] Loaded
2020-11-05T19:16:56.967Z,1604603816.967 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2020-11-05T19:16:56.968Z,1604603816.968 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2020-11-05T19:16:56.968Z,1604603816.968 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2020-11-05T19:16:57.044Z,1604603817.044 [DeadReckonUsingMultipleVelocitySources] Loaded
2020-11-05T19:16:57.044Z,1604603817.044 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2020-11-05T19:16:57.055Z,1604603817.055 [NavChart] Loaded
2020-11-05T19:16:57.055Z,1604603817.055 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2020-11-05T19:16:57.059Z,1604603817.059 [UniversalFixResidualReporter] Loaded
2020-11-05T19:16:57.059Z,1604603817.059 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2020-11-05T19:16:57.060Z,1604603817.060 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2020-11-05T19:16:57.061Z,1604603817.061 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2020-11-05T19:16:57.187Z,1604603817.187 [SBIT](DEBUG): Construct Startup Built In Test.
2020-11-05T19:16:57.196Z,1604603817.196 [SBIT] Loaded
2020-11-05T19:16:57.196Z,1604603817.196 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2020-11-05T19:16:57.197Z,1604603817.197 [IBIT](DEBUG): Construct Initiated Built In Test.
2020-11-05T19:16:57.209Z,1604603817.209 [IBIT] Loaded
2020-11-05T19:16:57.209Z,1604603817.209 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2020-11-05T19:16:57.212Z,1604603817.212 [CBIT](DEBUG): Construct Continuous Built In Test.
2020-11-05T19:16:57.305Z,1604603817.305 [CBIT] Loaded
2020-11-05T19:16:57.305Z,1604603817.305 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2020-11-05T19:16:57.306Z,1604603817.306 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2020-11-05T19:16:57.306Z,1604603817.306 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2020-11-05T19:16:57.416Z,1604603817.416 [BuoyancyServo] Loaded
2020-11-05T19:16:57.416Z,1604603817.416 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2020-11-05T19:16:57.433Z,1604603817.433 [ElevatorServo] Loaded
2020-11-05T19:16:57.433Z,1604603817.433 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2020-11-05T19:16:57.448Z,1604603817.448 [MassServo] Loaded
2020-11-05T19:16:57.448Z,1604603817.448 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2020-11-05T19:16:57.463Z,1604603817.463 [RudderServo] Loaded
2020-11-05T19:16:57.463Z,1604603817.463 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2020-11-05T19:16:57.478Z,1604603817.478 [ThrusterServo] Loaded
2020-11-05T19:16:57.478Z,1604603817.478 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2020-11-05T19:16:57.479Z,1604603817.479 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2020-11-05T19:16:57.479Z,1604603817.479 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2020-11-05T19:16:57.499Z,1604603817.499 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2020-11-05T19:16:57.499Z,1604603817.499 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2020-11-05T19:16:57.701Z,1604603817.701 [BackSeatDriver] Loaded
2020-11-05T19:16:57.701Z,1604603817.701 [ComponentRegistry](DEBUG): Component "BackSeatDriver" handled in its own thread.
2020-11-05T19:16:57.702Z,1604603817.702 [BackSeatDriver ThreadHandler](DEBUG): Created PCaller Thread at 40B074E0
2020-11-05T19:16:57.702Z,1604603817.702 [BackSeatDriver ThreadHandler](INFO): Protected caller Thread ID is 7464
2020-11-05T19:16:57.721Z,1604603817.721 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density
2020-11-05T19:16:57.723Z,1604603817.723 [CTD_Seabird](INFO): created writer for : sea_water_density
2020-11-05T19:16:57.724Z,1604603817.724 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth
2020-11-05T19:16:57.726Z,1604603817.726 [CTD_Seabird](INFO): created writer for : depth
2020-11-05T19:16:57.727Z,1604603817.727 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure
2020-11-05T19:16:57.729Z,1604603817.729 [CTD_Seabird](INFO): created writer for : sea_water_pressure
2020-11-05T19:16:57.730Z,1604603817.730 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity
2020-11-05T19:16:57.733Z,1604603817.733 [CTD_Seabird](INFO): created writer for : sea_water_salinity
2020-11-05T19:16:57.733Z,1604603817.733 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature
2020-11-05T19:16:57.736Z,1604603817.736 [CTD_Seabird](INFO): created writer for : sea_water_temperature
2020-11-05T19:16:57.737Z,1604603817.737 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity
2020-11-05T19:16:57.740Z,1604603817.740 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity
2020-11-05T19:16:57.740Z,1604603817.740 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water
2020-11-05T19:16:57.743Z,1604603817.743 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water
2020-11-05T19:16:57.757Z,1604603817.757 [CTD_Seabird] Loaded
2020-11-05T19:16:57.757Z,1604603817.757 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2020-11-05T19:16:57.758Z,1604603817.758 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40B374E0
2020-11-05T19:16:57.758Z,1604603817.758 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 7465
2020-11-05T19:16:57.775Z,1604603817.775 [PAR_Licor] Loaded
2020-11-05T19:16:57.775Z,1604603817.775 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2020-11-05T19:16:57.787Z,1604603817.787 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output470
2020-11-05T19:16:57.788Z,1604603817.788 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output470
2020-11-05T19:16:57.789Z,1604603817.789 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output650
2020-11-05T19:16:57.790Z,1604603817.790 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output650
2020-11-05T19:16:57.791Z,1604603817.791 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.OutputChl
2020-11-05T19:16:57.792Z,1604603817.792 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: OutputChl
2020-11-05T19:16:57.794Z,1604603817.794 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg470nm
2020-11-05T19:16:57.794Z,1604603817.794 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg470nm
2020-11-05T19:16:57.796Z,1604603817.796 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg650nm
2020-11-05T19:16:57.796Z,1604603817.796 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg650nm
2020-11-05T19:16:57.798Z,1604603817.798 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff470nm
2020-11-05T19:16:57.798Z,1604603817.798 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff470nm
2020-11-05T19:16:57.800Z,1604603817.800 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff650nm
2020-11-05T19:16:57.800Z,1604603817.800 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff650nm
2020-11-05T19:16:57.802Z,1604603817.802 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): mass_concentration_of_chlorophyll_in_sea_water
2020-11-05T19:16:57.804Z,1604603817.804 [WetLabsBB2FL](INFO): created writer for : mass_concentration_of_chlorophyll_in_sea_water
2020-11-05T19:16:57.805Z,1604603817.805 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_median_mass_concentration_of_chlorophyll_in_sea_water
2020-11-05T19:16:57.805Z,1604603817.805 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_median_mass_concentration_of_chlorophyll_in_sea_water
2020-11-05T19:16:57.807Z,1604603817.807 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water
2020-11-05T19:16:57.807Z,1604603817.807 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_mean_mass_concentration_of_chlorophyll_in_sea_water
2020-11-05T19:16:57.809Z,1604603817.809 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_variance_mass_concentration_of_chlorophyll_in_sea_water
2020-11-05T19:16:57.809Z,1604603817.809 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_variance_mass_concentration_of_chlorophyll_in_sea_water
2020-11-05T19:16:57.811Z,1604603817.811 [WetLabsBB2FL] Loaded
2020-11-05T19:16:57.811Z,1604603817.811 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2020-11-05T19:16:57.812Z,1604603817.812 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40B674E0
2020-11-05T19:16:57.812Z,1604603817.812 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 7466
2020-11-05T19:16:57.832Z,1604603817.832 [WetLabsUBAT..SerialDriver](INFO): Created logger
2020-11-05T19:16:57.833Z,1604603817.833 [WetLabsUBAT..SerialDriver](INFO): publishing on LCM channel WetLabsUBAT
2020-11-05T19:16:57.833Z,1604603817.833 [WetLabsUBAT..StreamSerialDriver](INFO): Created logger
2020-11-05T19:16:57.835Z,1604603817.835 [WetLabsUBAT](CRITICAL): No configuration setting for: WetLabsUBAT.optionalArgs
2020-11-05T19:16:57.838Z,1604603817.838 [WetLabsUBAT](CRITICAL): No configuration setting for: WetLabsUBAT.emulateHardware
2020-11-05T19:16:57.839Z,1604603817.839 [WetLabsUBAT](INFO): readConfig(): serialNo_: UBAT0051, uartName_: /dev/ttyC1, optionalArgs_: UBAT0051
2020-11-05T19:16:57.839Z,1604603817.839 [WetLabsUBAT](CRITICAL): Error loading configuration parameters during WetLabsUBAT::start()
2020-11-05T19:16:57.839Z,1604603817.839 [WetLabsUBAT] Data Fault, FailCount= 1
2020-11-05T19:16:57.840Z,1604603817.840 [WetLabsUBAT](ERROR): Data Fault
2020-11-05T19:16:57.840Z,1604603817.840 [WetLabsUBAT](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsUBAT.biolum_potential
2020-11-05T19:16:57.840Z,1604603817.840 [WetLabsUBAT](DEBUG): LcmSlateWriter::add(): dataName: biolum_potential
2020-11-05T19:16:57.842Z,1604603817.842 [WetLabsUBAT](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsUBAT.flow_rate
2020-11-05T19:16:57.842Z,1604603817.842 [WetLabsUBAT](DEBUG): LcmSlateWriter::add(): dataName: flow_rate
2020-11-05T19:16:57.845Z,1604603817.845 [WetLabsUBAT] Loaded
2020-11-05T19:16:57.845Z,1604603817.845 [ComponentRegistry](DEBUG): Component "WetLabsUBAT" handled in its own thread.
2020-11-05T19:16:57.846Z,1604603817.846 [WetLabsUBAT ThreadHandler](DEBUG): Created PCaller Thread at 40B974E0
2020-11-05T19:16:57.846Z,1604603817.846 [WetLabsUBAT ThreadHandler](INFO): Protected caller Thread ID is 7467
2020-11-05T19:16:57.847Z,1604603817.847 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2020-11-05T19:16:57.851Z,1604603817.851 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2020-11-05T19:16:57.852Z,1604603817.852 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2020-11-05T19:16:57.860Z,1604603817.860 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2020-11-05T19:16:57.861Z,1604603817.861 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40BC74E0
2020-11-05T19:16:57.861Z,1604603817.861 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 7468
2020-11-05T19:16:57.866Z,1604603817.866 [Supervisor](INFO): Main Thread ID is 7373
2020-11-05T19:16:57.866Z,1604603817.866 [Supervisor](DEBUG): Running supervisor.
2020-11-05T19:16:57.866Z,1604603817.866 [CommandLine ThreadHandler](INFO): Handler Thread ID is 7469
2020-11-05T19:16:57.869Z,1604603817.869 [controlThread ThreadHandler](INFO): Handler Thread ID is 7470
2020-11-05T19:16:57.869Z,1604603817.869 [controlThread](DEBUG): Initializing ControlThread
2020-11-05T19:16:57.870Z,1604603817.870 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2020-11-05T19:16:57.872Z,1604603817.872 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2020-11-05T19:16:57.873Z,1604603817.873 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2020-11-05T19:16:57.873Z,1604603817.873 [LoopControl](DEBUG): Initialize LoopControlComponent.
2020-11-05T19:16:57.873Z,1604603817.873 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2020-11-05T19:16:57.874Z,1604603817.874 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2020-11-05T19:16:57.874Z,1604603817.874 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2020-11-05T19:16:57.874Z,1604603817.874 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2020-11-05T19:16:57.875Z,1604603817.875 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2020-11-05T19:16:57.875Z,1604603817.875 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2020-11-05T19:16:57.879Z,1604603817.879 [NavChart](DEBUG): Initialize NavChart Navigation.
2020-11-05T19:16:57.880Z,1604603817.880 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2020-11-05T19:16:57.880Z,1604603817.880 [SBIT](INFO): Initialize SBIT Component.
2020-11-05T19:16:57.880Z,1604603817.880 [SBIT](IMPORTANT): git: 2020-10-07_A-23-gb592a2cb2
2020-11-05T19:16:57.881Z,1604603817.881 [SBIT](INFO): git hash: b592a2cb22003dea79cadb74c1e16be2caad515f
2020-11-05T19:16:57.881Z,1604603817.881 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2020-11-05T19:16:57.882Z,1604603817.882 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #1 PREEMPT Thu Feb 21 11:17:40 PST 2019
Kernel Reported: #1 PREEMPT Thu Aug 6 12:04:53 PDT 2020
2020-11-05T19:16:57.883Z,1604603817.883 [SBIT](INFO): Beginning SBIT in 26.000000 seconds.
2020-11-05T19:16:57.884Z,1604603817.884 [IBIT](INFO): Initialize IBIT Component.
2020-11-05T19:16:57.884Z,1604603817.884 [CBIT](DEBUG): Initialize CBIT Component.
2020-11-05T19:16:57.885Z,1604603817.885 [logger ThreadHandler](INFO): Handler Thread ID is 7471
2020-11-05T19:16:57.897Z,1604603817.897 [CBIT](DEBUG): Initialized mux pins.
2020-11-05T19:16:57.897Z,1604603817.897 [CBIT](DEBUG): Initializing the watchdog timer.
2020-11-05T19:16:57.905Z,1604603817.905 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 7472
2020-11-05T19:16:57.906Z,1604603817.906 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2020-11-05T19:16:57.917Z,1604603817.917 [Onboard ThreadHandler](INFO): Handler Thread ID is 7473
2020-11-05T19:16:57.921Z,1604603817.921 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2020-11-05T19:16:57.921Z,1604603817.921 [CBIT](DEBUG): Initializing heartbeat.
2020-11-05T19:16:57.935Z,1604603817.935 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 7474
2020-11-05T19:16:57.957Z,1604603817.957 [BackSeatDriver ThreadHandler](INFO): Handler Thread ID is 7475
2020-11-05T19:16:57.977Z,1604603817.977 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 7476
2020-11-05T19:16:57.978Z,1604603817.978 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2020-11-05T19:16:57.982Z,1604603817.982 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 7478
2020-11-05T19:16:57.983Z,1604603817.983 [WetLabsBB2FL](INFO): Powering down
2020-11-05T19:16:57.993Z,1604603817.993 [CBIT](DEBUG): Deactivating GF circuits.
2020-11-05T19:16:57.993Z,1604603817.993 [CBIT](DEBUG): Deactivating emergency mode.
2020-11-05T19:16:57.994Z,1604603817.994 [WetLabsUBAT ThreadHandler](INFO): Handler Thread ID is 7479
2020-11-05T19:16:58.001Z,1604603818.001 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 7480
2020-11-05T19:16:58.008Z,1604603818.008 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2020-11-05T19:16:58.009Z,1604603818.009 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2020-11-05T19:16:58.009Z,1604603818.009 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2020-11-05T19:16:58.009Z,1604603818.009 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2020-11-05T19:16:58.009Z,1604603818.009 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2020-11-05T19:16:58.009Z,1604603818.009 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2020-11-05T19:16:58.009Z,1604603818.009 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2020-11-05T19:16:58.010Z,1604603818.010 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2020-11-05T19:16:58.010Z,1604603818.010 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2020-11-05T19:16:58.010Z,1604603818.010 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2020-11-05T19:16:58.010Z,1604603818.010 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2020-11-05T19:16:58.010Z,1604603818.010 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2020-11-05T19:16:58.010Z,1604603818.010 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2020-11-05T19:16:58.010Z,1604603818.010 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2020-11-05T19:16:58.011Z,1604603818.011 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2020-11-05T19:16:58.011Z,1604603818.011 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2020-11-05T19:16:58.029Z,1604603818.029 [CBIT](DEBUG): Backplane powered.
2020-11-05T19:16:58.034Z,1604603818.034 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2020-11-05T19:16:58.050Z,1604603818.050 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2020-11-05T19:16:58.061Z,1604603818.061 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
       Id="Startup">

    <Guidance:GoToSurface>
        <Progression/>
    </Guidance:GoToSurface>

    <Aggregate Id="StartupSatComms">

        <Sequence/>

        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:latitude_fix/>
        </ReadDatum>

        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:platform_communications/>
        </ReadDatum>

    </Aggregate>

</Mission>


2020-11-05T19:16:58.061Z,1604603818.061 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2020-11-05T19:16:58.122Z,1604603818.122 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2020-11-05T19:16:58.123Z,1604603818.123 [Default:A.Wait](DEBUG): Construct Wait.
2020-11-05T19:16:58.125Z,1604603818.125 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2020-11-05T19:16:58.151Z,1604603818.151 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2020-11-05T19:16:58.173Z,1604603818.173 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2020-11-05T19:16:58.179Z,1604603818.179 [Default:E.Execute](DEBUG): Construct Execute.
2020-11-05T19:16:58.195Z,1604603818.195 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Universal="Tethys/Universal"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
         Id="Default">

    <DefineArg Name="ElapsedSinceDefaultStarted"><Units:minute/><Value>0</Value></DefineArg>

    <Guidance:Wait>
        <Description>
            Wait a moment to see if the scheduler starts a new mission before
            starting to actually run Default.
        </Description>
        <Sequence/>
        <Setting><Guidance:Wait.duration/><Units:second/><Value>13</Value></Setting>
    </Guidance:Wait>

    <Guidance:GoToSurface>
        <Progression/>
    </Guidance:GoToSurface>

    <Aggregate Id="CheckIn">

        <Sequence Repeat="288"/>

        <ReadDatum Id="Read_GPS">
            <Timeout Duration="P5M"/>
            <Universal:time_fix/>
        </ReadDatum>

        <ReadDatum Id="Read_Iridium">
            <Timeout Duration="P2H">
                <Guidance:Execute>
                    <Sequence/>
                    <Setting><Guidance:Execute.command/><String>Burn on</String></Setting>
                </Guidance:Execute>
                <Syslog Severity="Critical">Dropped weight due to communications timeout.</Syslog>
            </Timeout>
            <Universal:platform_communications/>
        </ReadDatum>

        <Guidance:Wait>
            <Sequence/>
            <Setting><Guidance:Wait.duration/><Units:minute/><Value>5</Value></Setting>
        </Guidance:Wait>

        <Assign><Sequence/><Arg Name="ElapsedSinceDefaultStarted"/><Elapsed><Universal:mission_started/></Elapsed></Assign>

        <Syslog Severity="Important">Default mission has been running for <Arg Name="ElapsedSinceDefaultStarted"/><Units:minute/></Syslog>

    </Aggregate>

    <Syslog Severity="Important">Restarting logs and Default mission.</Syslog>

    <Guidance:Execute>
        <Sequence/>
        <Setting><Guidance:Execute.command/><String>restart logs</String></Setting>
    </Guidance:Execute>

</Mission>


2020-11-05T19:16:58.199Z,1604603818.199 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,NAL9602,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,
2020-11-05T19:16:58.215Z,1604603818.215 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2020-11-05T19:16:58.285Z,1604603818.285 [Depth_Keller](ERROR): Pressure reading out of range: 1650.297119 decibar
2020-11-05T19:16:58.288Z,1604603818.288 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2020-11-05T19:16:58.289Z,1604603818.289 [DAT](INFO): Powering up
2020-11-05T19:16:58.289Z,1604603818.289 [DAT](DEBUG): Initializing DAT.
2020-11-05T19:16:58.341Z,1604603818.341 [Radio_Surface](INFO): Powering up
2020-11-05T19:16:58.355Z,1604603818.355 [DepthRateCalculator](ERROR): Depth measurement is not active
2020-11-05T19:16:58.365Z,1604603818.365 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2020-11-05T19:16:58.405Z,1604603818.405 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2020-11-05T19:16:58.417Z,1604603818.417 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2020-11-05T19:16:58.418Z,1604603818.418 [ElevatorServo](DEBUG): Initializing EZServoServo.
2020-11-05T19:16:58.429Z,1604603818.429 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2020-11-05T19:16:58.430Z,1604603818.430 [MassServo](DEBUG): Initializing EZServoServo.
2020-11-05T19:16:58.441Z,1604603818.441 [MassServo](DEBUG): Initializing MassServo.
2020-11-05T19:16:58.442Z,1604603818.442 [RudderServo](DEBUG): Initializing EZServoServo.
2020-11-05T19:16:58.453Z,1604603818.453 [RudderServo](DEBUG): Initializing RudderServo.
2020-11-05T19:16:58.454Z,1604603818.454 [ThrusterServo](DEBUG): Initializing EZServoServo.
2020-11-05T19:16:58.465Z,1604603818.465 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2020-11-05T19:16:58.467Z,1604603818.467 [CommandLine](FAULT): Scheduling is paused
2020-11-05T19:16:58.468Z,1604603818.468 [CBIT](INFO): Critical error at 20201105T191657
2020-11-05T19:16:58.468Z,1604603818.468 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2020-11-05T19:16:58.472Z,1604603818.472 [CBIT](ERROR): Data Fault in component: WetLabsUBAT
2020-11-05T19:16:58.472Z,1604603818.472 [CBIT](INFO): Clearing failed state for component WetLabsUBAT
2020-11-05T19:16:58.472Z,1604603818.472 [WetLabsUBAT] No Fault, FailCount= 1
2020-11-05T19:16:58.645Z,1604603818.645 [DropWeight](CRITICAL): DROP WEIGHT MISSING.

2020-11-05T19:16:58.645Z,1604603818.645 [DropWeight] Hardware Fault, FailCount= 1
2020-11-05T19:16:58.645Z,1604603818.645 [DropWeight](ERROR): Hardware Fault
2020-11-05T19:16:58.705Z,1604603818.705 [DepthRateCalculator](ERROR): Depth measurement is not active
2020-11-05T19:16:58.730Z,1604603818.730 [CBIT](INFO): Critical error at 20201105T191658
2020-11-05T19:16:58.732Z,1604603818.732 [CBIT](ERROR): Hardware Fault in component: DropWeight
2020-11-05T19:16:58.732Z,1604603818.732 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2020-11-05T19:16:58.801Z,1604603818.801 [WetLabsUBAT](INFO): Initializing
2020-11-05T19:16:58.803Z,1604603818.803 [WetLabsUBAT](INFO): readConfig(): serialNo_: UBAT0051, uartName_: /dev/ttyC1, optionalArgs_: nan n/a
2020-11-05T19:16:58.803Z,1604603818.803 [WetLabsUBAT](INFO): Powering up
2020-11-05T19:16:58.803Z,1604603818.803 [WetLabsUBAT](INFO): Checking LCM
2020-11-05T19:16:58.803Z,1604603818.803 [WetLabsUBAT](INFO): LCM OK
2020-11-05T19:16:58.805Z,1604603818.805 [WetLabsUBAT](ERROR): Error configuring driver
2020-11-05T19:16:58.805Z,1604603818.805 [WetLabsUBAT] Software Fault, FailCount= 2
2020-11-05T19:16:58.805Z,1604603818.805 [WetLabsUBAT](ERROR): Software Fault
2020-11-05T19:16:59.209Z,1604603819.209 [WetLabsUBAT](INFO): Powering down
2020-11-05T19:16:59.345Z,1604603819.345 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2020-11-05T19:16:59.345Z,1604603819.345 [RudderServo](FAULT): Rudder failed to initialize
2020-11-05T19:16:59.345Z,1604603819.345 [RudderServo] Communications Fault, FailCount= 1
2020-11-05T19:16:59.345Z,1604603819.345 [RudderServo](ERROR): Communications Fault
2020-11-05T19:16:59.443Z,1604603819.443 [CBIT](INFO): Critical error at 20201105T191658
2020-11-05T19:16:59.445Z,1604603819.445 [CBIT](ERROR): Communications Fault in component: RudderServo
2020-11-05T19:16:59.446Z,1604603819.446 [CBIT](ERROR): Software Fault in component: WetLabsUBAT
2020-11-05T19:16:59.654Z,1604603819.654 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2020-11-05T19:16:59.654Z,1604603819.654 [RudderServo](INFO): Powering down
2020-11-05T19:17:00.315Z,1604603820.315 [RudderServo](DEBUG): Initializing EZServoServo.
2020-11-05T19:17:00.434Z,1604603820.434 [RudderServo](DEBUG): Initializing RudderServo.
2020-11-05T19:17:00.438Z,1604603820.438 [CBIT](INFO): Clearing failed state for component RudderServo
2020-11-05T19:17:00.438Z,1604603820.438 [RudderServo] No Fault, FailCount= 1
2020-11-05T19:17:00.438Z,1604603820.438 [CBIT](INFO): Clearing failed state for component WetLabsUBAT
2020-11-05T19:17:00.438Z,1604603820.438 [WetLabsUBAT] No Fault, FailCount= 2
2020-11-05T19:17:00.825Z,1604603820.825 [WetLabsUBAT](INFO): Initializing
2020-11-05T19:17:00.827Z,1604603820.827 [WetLabsUBAT](INFO): readConfig(): serialNo_: UBAT0051, uartName_: /dev/ttyC1, optionalArgs_: nan n/a
2020-11-05T19:17:00.827Z,1604603820.827 [WetLabsUBAT](INFO): Powering up
2020-11-05T19:17:00.827Z,1604603820.827 [WetLabsUBAT](INFO): Checking LCM
2020-11-05T19:17:00.827Z,1604603820.827 [WetLabsUBAT](INFO): LCM OK
2020-11-05T19:17:00.828Z,1604603820.828 [WetLabsUBAT](ERROR): Error configuring driver
2020-11-05T19:17:00.829Z,1604603820.829 [WetLabsUBAT] Software Fault, FailCount= 3
2020-11-05T19:17:00.829Z,1604603820.829 [WetLabsUBAT](ERROR): Software Fault
2020-11-05T19:17:01.234Z,1604603821.234 [WetLabsUBAT](INFO): Powering down
2020-11-05T19:17:01.288Z,1604603821.288 [CBIT](ERROR): Software Fault in component: WetLabsUBAT
2020-11-05T19:17:02.080Z,1604603822.080 [CBIT](INFO): Clearing failed state for component WetLabsUBAT
2020-11-05T19:17:02.080Z,1604603822.080 [WetLabsUBAT] No Fault, FailCount= 3
2020-11-05T19:17:02.445Z,1604603822.445 [WetLabsUBAT](INFO): Initializing
2020-11-05T19:17:02.447Z,1604603822.447 [WetLabsUBAT](INFO): readConfig(): serialNo_: UBAT0051, uartName_: /dev/ttyC1, optionalArgs_: nan n/a
2020-11-05T19:17:02.447Z,1604603822.447 [WetLabsUBAT](INFO): Powering up
2020-11-05T19:17:02.447Z,1604603822.447 [WetLabsUBAT](INFO): Checking LCM
2020-11-05T19:17:02.447Z,1604603822.447 [WetLabsUBAT](INFO): LCM OK
2020-11-05T19:17:02.449Z,1604603822.449 [WetLabsUBAT](ERROR): Error configuring driver
2020-11-05T19:17:02.449Z,1604603822.449 [WetLabsUBAT] Software Fault, FailCount= 4
2020-11-05T19:17:02.449Z,1604603822.449 [WetLabsUBAT](ERROR): Software Fault
2020-11-05T19:17:02.529Z,1604603822.529 [CBIT](ERROR): Software Fault in component: WetLabsUBAT
2020-11-05T19:17:02.853Z,1604603822.853 [WetLabsUBAT](INFO): Powering down
2020-11-05T19:17:03.685Z,1604603823.685 [CBIT](INFO): Clearing failed state for component WetLabsUBAT
2020-11-05T19:17:03.685Z,1604603823.685 [WetLabsUBAT] No Fault, FailCount= 4
2020-11-05T19:17:04.065Z,1604603824.065 [WetLabsUBAT](INFO): Initializing
2020-11-05T19:17:04.067Z,1604603824.067 [WetLabsUBAT](INFO): readConfig(): serialNo_: UBAT0051, uartName_: /dev/ttyC1, optionalArgs_: nan n/a
2020-11-05T19:17:04.067Z,1604603824.067 [WetLabsUBAT](INFO): Powering up
2020-11-05T19:17:04.067Z,1604603824.067 [WetLabsUBAT](INFO): Checking LCM
2020-11-05T19:17:04.067Z,1604603824.067 [WetLabsUBAT](INFO): LCM OK
2020-11-05T19:17:04.068Z,1604603824.068 [WetLabsUBAT](ERROR): Error configuring driver
2020-11-05T19:17:04.068Z,1604603824.068 [WetLabsUBAT] Software Fault, FailCount= 5
2020-11-05T19:17:04.068Z,1604603824.068 [WetLabsUBAT](ERROR): Software Fault
2020-11-05T19:17:04.468Z,1604603824.468 [CBIT](ERROR): Software Fault in component: WetLabsUBAT
2020-11-05T19:17:04.469Z,1604603824.469 [CBIT](CRITICAL): Software Fault in component: WetLabsUBAT
2020-11-05T19:17:04.473Z,1604603824.473 [WetLabsUBAT](INFO): Powering down
2020-11-05T19:17:04.842Z,1604603824.842 [CBIT](INFO): Critical error at 20201105T191704
2020-11-05T19:17:05.033Z,1604603825.033 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit.
2020-11-05T19:17:08.141Z,1604603828.141 [CBIT](CRITICAL): Environmental Failure. Press:14.465972 PSI. Humidity:43%. Temp:23 C. ABORTING MISSION
2020-11-05T19:17:08.423Z,1604603828.423 [CBIT](INFO): Critical error at 20201105T191708
2020-11-05T19:17:11.731Z,1604603831.731 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004857
2020-11-05T19:17:12.388Z,1604603832.388 [DAT](INFO): commRate: 800
2020-11-05T19:17:14.406Z,1604603834.406 [DAT](INFO): entering command mode
2020-11-05T19:17:14.810Z,1604603834.810 [DAT](DEBUG): checking for command mode acknowledgment
2020-11-05T19:17:15.214Z,1604603835.214 [DAT](DEBUG): checking for command mode acknowledgment
2020-11-05T19:17:15.618Z,1604603835.618 [DAT](DEBUG): checking for command mode acknowledgment
2020-11-05T19:17:16.022Z,1604603836.022 [DAT](DEBUG): checking for command mode acknowledgment
2020-11-05T19:17:16.426Z,1604603836.426 [DAT](DEBUG): checking for command mode acknowledgment
2020-11-05T19:17:16.830Z,1604603836.830 [DAT](DEBUG): checking for command mode acknowledgment
2020-11-05T19:17:17.234Z,1604603837.234 [DAT](DEBUG): checking for command mode acknowledgment
2020-11-05T19:17:17.688Z,1604603837.688 [DAT](DEBUG): checking for command mode acknowledgment
2020-11-05T19:17:18.042Z,1604603838.042 [DAT](DEBUG): checking for command mode acknowledgment
2020-11-05T19:17:18.446Z,1604603838.446 [DAT](DEBUG): checking for command mode acknowledgment
2020-11-05T19:17:18.850Z,1604603838.850 [DAT](DEBUG): checking for command mode acknowledgment
2020-11-05T19:17:19.254Z,1604603839.254 [DAT](DEBUG): checking for command mode acknowledgment
2020-11-05T19:17:19.658Z,1604603839.658 [DAT](DEBUG): checking for command mode acknowledgment
2020-11-05T19:17:20.067Z,1604603840.067 [DAT](DEBUG): checking for command mode acknowledgment
2020-11-05T19:17:20.462Z,1604603840.462 [DAT](DEBUG): checking for command mode acknowledgment
2020-11-05T19:17:20.866Z,1604603840.866 [DAT](DEBUG): checking for command mode acknowledgment
2020-11-05T19:17:21.270Z,1604603841.270 [DAT](DEBUG): checking for command mode acknowledgment
2020-11-05T19:17:21.680Z,1604603841.680 [DAT](DEBUG): checking for command mode acknowledgment
2020-11-05T19:17:22.079Z,1604603842.079 [DAT](DEBUG): checking for command mode acknowledgment
2020-11-05T19:17:22.482Z,1604603842.482 [DAT](DEBUG): checking for command mode acknowledgment
2020-11-05T19:17:22.886Z,1604603842.886 [DAT](DEBUG): checking for command mode acknowledgment
2020-11-05T19:17:23.296Z,1604603843.296 [DAT](DEBUG): checking for command mode acknowledgment
2020-11-05T19:17:23.695Z,1604603843.695 [DAT](DEBUG): checking for command mode acknowledgment
2020-11-05T19:17:24.105Z,1604603844.105 [DAT](DEBUG): checking for command mode acknowledgment
2020-11-05T19:17:24.510Z,1604603844.510 [DAT](DEBUG): checking for command mode acknowledgment
2020-11-05T19:17:24.570Z,1604603844.570 [SBIT](IMPORTANT): Beginning Startup BIT
2020-11-05T19:17:24.575Z,1604603844.575 [CBIT](IMPORTANT): Beginning ground fault scan
2020-11-05T19:17:24.906Z,1604603844.906 [DAT](DEBUG): checking for command mode acknowledgment
2020-11-05T19:17:25.314Z,1604603845.314 [DAT](DEBUG): checking for command mode acknowledgment
2020-11-05T19:17:25.718Z,1604603845.718 [DAT](DEBUG): checking for command mode acknowledgment
2020-11-05T19:17:26.122Z,1604603846.122 [NAL9602](INFO): Powering up NAL9602
2020-11-05T19:17:26.123Z,1604603846.123 [DAT](DEBUG): checking for command mode acknowledgment
2020-11-05T19:17:26.534Z,1604603846.534 [DAT](DEBUG): checking for command mode acknowledgment
2020-11-05T19:17:26.930Z,1604603846.930 [DAT](DEBUG): checking for command mode acknowledgment
2020-11-05T19:17:27.330Z,1604603847.330 [DAT](DEBUG): checking for command mode acknowledgment
2020-11-05T19:17:27.751Z,1604603847.751 [DAT](DEBUG): checking for command mode acknowledgment
2020-11-05T19:17:28.146Z,1604603848.146 [DAT](DEBUG): checking for command mode acknowledgment
2020-11-05T19:17:28.542Z,1604603848.542 [DAT](DEBUG): checking for command mode acknowledgment
2020-11-05T19:17:28.950Z,1604603848.950 [DAT](DEBUG): checking for command mode acknowledgment
2020-11-05T19:17:29.354Z,1604603849.354 [DAT](DEBUG): checking for command mode acknowledgment
2020-11-05T19:17:29.754Z,1604603849.754 [DAT](DEBUG): checking for command mode acknowledgment
2020-11-05T19:17:29.754Z,1604603849.754 [DAT](FAULT): failed to enter command mode
2020-11-05T19:17:30.158Z,1604603850.158 [DAT](INFO): entering command mode
2020-11-05T19:17:30.563Z,1604603850.563 [DAT](INFO): setting verbose to 3
2020-11-05T19:17:30.976Z,1604603850.976 [DAT](INFO): set verbose to 3
2020-11-05T19:17:30.977Z,1604603850.977 [DAT](INFO): setting DatVerbose to 27440
2020-11-05T19:17:31.371Z,1604603851.371 [DAT](INFO): set DatVerbose to 27440
2020-11-05T19:17:31.372Z,1604603851.372 [DAT](INFO): setting transmit power to 8
2020-11-05T19:17:31.775Z,1604603851.775 [DAT](INFO): set transmit power to 8
2020-11-05T19:17:31.776Z,1604603851.776 [DAT](INFO): setting local address to 9
2020-11-05T19:17:32.179Z,1604603852.179 [DAT](INFO): set local address to 9
2020-11-05T19:17:35.521Z,1604603855.521 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): 0.003499
CHAN A1 (24V): -0.001679
CHAN A2 (12V): -0.006806
CHAN A3 (5V): -0.001937
CHAN B0 (3.3V): -0.000233
CHAN B1 (3.15aV): -0.000579
CHAN B2 (3.15bV): -0.000166
CHAN B3 (GND): 0.002440
OPEN: 0.005211
Full Scale Calc: 4.765 mA, -1.589 mA
2020-11-05T19:17:37.030Z,1604603857.030 [NAL9602](INFO): NAL9602 initialized
2020-11-05T19:18:18.655Z,1604603898.655 [SBIT](IMPORTANT): SBIT PASSED
2020-11-05T19:18:18.656Z,1604603898.656 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2020-11-05T19:18:18.657Z,1604603898.657 [SBIT](IMPORTANT): AMEcho.loadAtStartup=0 bool;

2020-11-05T19:18:18.657Z,1604603898.657 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=6 count;

2020-11-05T19:18:18.657Z,1604603898.657 [SBIT](IMPORTANT): CBIT.gf24Offset=145 microampere;

2020-11-05T19:18:18.657Z,1604603898.657 [SBIT](IMPORTANT): DAT.loadAtStartup=1 bool;

2020-11-05T19:18:18.657Z,1604603898.657 [SBIT](IMPORTANT): DAT.sbdAddress=-1 enum;

2020-11-05T19:18:18.657Z,1604603898.657 [SBIT](IMPORTANT): DAT.surfaceThreshold=100 meter;

2020-11-05T19:18:18.657Z,1604603898.657 [SBIT](IMPORTANT): DAT.verbosity=0 count;

2020-11-05T19:18:18.658Z,1604603898.658 [SBIT](IMPORTANT): Express linearApproximation WetLabsUBAT.flow_rate 1.000000 liter_per_second;

2020-11-05T19:18:18.658Z,1604603898.658 [SBIT](IMPORTANT): Express linearApproximation height_above_sea_floor 5.000000 meter;

2020-11-05T19:18:18.658Z,1604603898.658 [SBIT](IMPORTANT): PAR_Licor.loadAtStartup=1 bool;

2020-11-05T19:18:18.658Z,1604603898.658 [SBIT](IMPORTANT): PAR_Licor.parCal=1.01146 none;

2020-11-05T19:18:18.658Z,1604603898.658 [SBIT](IMPORTANT): RDI_Pathfinder.loadAtStartup=0 bool;

2020-11-05T19:18:18.658Z,1604603898.658 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=256.318046 cubic_centimeter;

2020-11-05T19:18:18.658Z,1604603898.658 [SBIT](IMPORTANT): VerticalControl.massDefault=1.572083 millimeter;

2020-11-05T19:18:18.658Z,1604603898.658 [SBIT](IMPORTANT): WetLabsUBAT.loadAtStartup=1 bool;

2020-11-05T19:18:19.183Z,1604603899.183 [MissionManager](IMPORTANT): Started mission Startup
2020-11-05T19:18:19.183Z,1604603899.183 [Startup] Running Loop=1
2020-11-05T19:18:19.183Z,1604603899.183 [Startup](DEBUG): Aggregate::initialize Startup
2020-11-05T19:18:19.183Z,1604603899.183 [Startup:A.GoToSurface] Running Loop=1
2020-11-05T19:18:19.183Z,1604603899.183 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-11-05T19:18:19.184Z,1604603899.184 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-11-05T19:18:1