2019-10-09T23:41:20.315Z,1570664480.315 [Supervisor](DEBUG): Initializing supervisor.
2019-10-09T23:41:20.317Z,1570664480.317 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2019-10-09T23:41:20.318Z,1570664480.318 [SyncHandler](INFO): Protected caller Thread ID is 4709
2019-10-09T23:41:20.318Z,1570664480.318 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2019-10-09T23:41:20.319Z,1570664480.319 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2019-10-09T23:41:20.320Z,1570664480.320 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 4710
2019-10-09T23:41:20.322Z,1570664480.322 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2019-10-09T23:41:20.333Z,1570664480.333 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2019-10-09T23:41:20.334Z,1570664480.334 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2019-10-09T23:41:20.334Z,1570664480.334 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 4711
2019-10-09T23:41:20.335Z,1570664480.335 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2019-10-09T23:41:20.336Z,1570664480.336 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2019-10-09T23:41:20.336Z,1570664480.336 [logger ThreadHandler](INFO): Protected caller Thread ID is 4712
2019-10-09T23:41:20.338Z,1570664480.338 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2019-10-09T23:41:20.339Z,1570664480.339 [Supervisor](INFO): Looking for Config files in directory: Config/
2019-10-09T23:41:20.340Z,1570664480.340 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2019-10-09T23:41:20.541Z,1570664480.541 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2019-10-09T23:41:20.542Z,1570664480.542 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2019-10-09T23:41:20.681Z,1570664480.681 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2019-10-09T23:41:21.190Z,1570664481.190 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2019-10-09T23:41:21.191Z,1570664481.191 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2019-10-09T23:41:21.572Z,1570664481.572 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2019-10-09T23:41:21.572Z,1570664481.572 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2019-10-09T23:41:21.670Z,1570664481.670 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2019-10-09T23:41:21.670Z,1570664481.670 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2019-10-09T23:41:22.027Z,1570664482.027 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2019-10-09T23:41:22.027Z,1570664482.027 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2019-10-09T23:41:22.284Z,1570664482.284 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2019-10-09T23:41:22.284Z,1570664482.284 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2019-10-09T23:41:22.801Z,1570664482.801 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2019-10-09T23:41:22.802Z,1570664482.802 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2019-10-09T23:41:22.909Z,1570664482.909 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2019-10-09T23:41:22.910Z,1570664482.910 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2019-10-09T23:41:23.091Z,1570664483.091 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2019-10-09T23:41:23.091Z,1570664483.091 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2019-10-09T23:41:23.784Z,1570664483.784 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2019-10-09T23:41:23.785Z,1570664483.785 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2019-10-09T23:41:24.323Z,1570664484.323 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2019-10-09T23:41:24.324Z,1570664484.324 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2019-10-09T23:41:24.870Z,1570664484.870 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2019-10-09T23:41:24.870Z,1570664484.870 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2019-10-09T23:41:25.018Z,1570664485.018 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2019-10-09T23:41:25.018Z,1570664485.018 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2019-10-09T23:41:25.218Z,1570664485.218 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2019-10-09T23:41:25.220Z,1570664485.220 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2019-10-09T23:41:25.222Z,1570664485.222 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2019-10-09T23:41:25.315Z,1570664485.315 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2019-10-09T23:41:25.400Z,1570664485.400 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2019-10-09T23:41:25.564Z,1570664485.564 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2019-10-09T23:41:25.648Z,1570664485.648 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2019-10-09T23:41:25.749Z,1570664485.749 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2019-10-09T23:41:25.908Z,1570664485.908 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2019-10-09T23:41:26.119Z,1570664486.119 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2019-10-09T23:41:26.196Z,1570664486.196 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2019-10-09T23:41:26.418Z,1570664486.418 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2019-10-09T23:41:26.553Z,1570664486.553 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2019-10-09T23:41:26.710Z,1570664486.710 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg
2019-10-09T23:41:26.971Z,1570664486.971 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2019-10-09T23:41:26.972Z,1570664486.972 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg
2019-10-09T23:41:26.973Z,1570664486.973 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2019-10-09T23:41:27.054Z,1570664487.054 [VerticalControl](DEBUG): Construct VerticalControl.
2019-10-09T23:41:27.224Z,1570664487.224 [VerticalControl] Loaded
2019-10-09T23:41:27.224Z,1570664487.224 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2019-10-09T23:41:27.225Z,1570664487.225 [HorizontalControl](DEBUG): Construct HorizontalControl.
2019-10-09T23:41:27.299Z,1570664487.299 [HorizontalControl] Loaded
2019-10-09T23:41:27.299Z,1570664487.299 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2019-10-09T23:41:27.300Z,1570664487.300 [SpeedControl](DEBUG): Construct SpeedControl.
2019-10-09T23:41:27.306Z,1570664487.306 [SpeedControl] Loaded
2019-10-09T23:41:27.306Z,1570664487.306 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2019-10-09T23:41:27.307Z,1570664487.307 [LoopControl](DEBUG): Construct LoopControl.
2019-10-09T23:41:27.307Z,1570664487.307 [LoopControl] Loaded
2019-10-09T23:41:27.308Z,1570664487.308 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2019-10-09T23:41:27.308Z,1570664487.308 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2019-10-09T23:41:27.309Z,1570664487.309 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2019-10-09T23:41:27.322Z,1570664487.322 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2019-10-09T23:41:27.322Z,1570664487.322 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2019-10-09T23:41:27.422Z,1570664487.422 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2019-10-09T23:41:27.423Z,1570664487.423 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2019-10-09T23:41:27.579Z,1570664487.579 [BuoyancyServo] Loaded
2019-10-09T23:41:27.579Z,1570664487.579 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2019-10-09T23:41:27.591Z,1570664487.591 [ElevatorServo] Loaded
2019-10-09T23:41:27.591Z,1570664487.591 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2019-10-09T23:41:27.602Z,1570664487.602 [MassServo] Loaded
2019-10-09T23:41:27.602Z,1570664487.602 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2019-10-09T23:41:27.614Z,1570664487.614 [RudderServo] Loaded
2019-10-09T23:41:27.615Z,1570664487.615 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2019-10-09T23:41:27.626Z,1570664487.626 [ThrusterServo] Loaded
2019-10-09T23:41:27.626Z,1570664487.626 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2019-10-09T23:41:27.626Z,1570664487.626 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2019-10-09T23:41:27.627Z,1570664487.627 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2019-10-09T23:41:27.742Z,1570664487.742 [DeadReckonUsingMultipleVelocitySources] Loaded
2019-10-09T23:41:27.742Z,1570664487.742 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2019-10-09T23:41:27.764Z,1570664487.764 [NavChart] Loaded
2019-10-09T23:41:27.764Z,1570664487.764 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2019-10-09T23:41:27.769Z,1570664487.769 [UniversalFixResidualReporter] Loaded
2019-10-09T23:41:27.769Z,1570664487.769 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2019-10-09T23:41:27.769Z,1570664487.769 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2019-10-09T23:41:27.770Z,1570664487.770 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2019-10-09T23:41:27.842Z,1570664487.842 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2019-10-09T23:41:27.842Z,1570664487.842 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2019-10-09T23:41:28.164Z,1570664488.164 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_orientation
2019-10-09T23:41:28.170Z,1570664488.170 [AHRS_M2](INFO): created writer for : platform_orientation
2019-10-09T23:41:28.172Z,1570664488.172 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_magnetic_orientation
2019-10-09T23:41:28.177Z,1570664488.177 [AHRS_M2](INFO): created writer for : platform_magnetic_orientation
2019-10-09T23:41:28.178Z,1570664488.178 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_pitch_angle
2019-10-09T23:41:28.184Z,1570664488.184 [AHRS_M2](INFO): created writer for : platform_pitch_angle
2019-10-09T23:41:28.184Z,1570664488.184 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_roll_angle
2019-10-09T23:41:28.190Z,1570664488.190 [AHRS_M2](INFO): created writer for : platform_roll_angle
2019-10-09T23:41:28.311Z,1570664488.311 [AHRS_M2] Loaded
2019-10-09T23:41:28.312Z,1570664488.312 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2019-10-09T23:41:28.411Z,1570664488.411 [DataOverHttps] Loaded
2019-10-09T23:41:28.412Z,1570664488.412 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2019-10-09T23:41:28.413Z,1570664488.413 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4087D4E0
2019-10-09T23:41:28.413Z,1570664488.413 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 4795
2019-10-09T23:41:28.427Z,1570664488.427 [Depth_Keller] Loaded
2019-10-09T23:41:28.427Z,1570664488.427 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2019-10-09T23:41:28.432Z,1570664488.432 [DropWeight] Loaded
2019-10-09T23:41:28.432Z,1570664488.432 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2019-10-09T23:41:28.568Z,1570664488.568 [DVL_micro] Loaded
2019-10-09T23:41:28.569Z,1570664488.569 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread.
2019-10-09T23:41:28.710Z,1570664488.710 [NAL9602] Loaded
2019-10-09T23:41:28.710Z,1570664488.710 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2019-10-09T23:41:28.738Z,1570664488.738 [Onboard] Loaded
2019-10-09T23:41:28.738Z,1570664488.738 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2019-10-09T23:41:28.742Z,1570664488.742 [Radio_Surface] Loaded
2019-10-09T23:41:28.742Z,1570664488.742 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2019-10-09T23:41:28.743Z,1570664488.743 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408AD4E0
2019-10-09T23:41:28.743Z,1570664488.743 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 4796
2019-10-09T23:41:28.892Z,1570664488.892 [DAT] Loaded
2019-10-09T23:41:28.892Z,1570664488.892 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread.
2019-10-09T23:41:31.426Z,1570664491.426 [BPC1] Loaded
2019-10-09T23:41:31.427Z,1570664491.427 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2019-10-09T23:41:31.427Z,1570664491.427 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2019-10-09T23:41:31.428Z,1570664491.428 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2019-10-09T23:41:31.470Z,1570664491.470 [DepthRateCalculator] Loaded
2019-10-09T23:41:31.470Z,1570664491.470 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2019-10-09T23:41:31.475Z,1570664491.475 [PitchRateCalculator] Loaded
2019-10-09T23:41:31.476Z,1570664491.476 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2019-10-09T23:41:31.487Z,1570664491.487 [SpeedCalculator] Loaded
2019-10-09T23:41:31.488Z,1570664491.488 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2019-10-09T23:41:31.548Z,1570664491.548 [TempGradientCalculator] Loaded
2019-10-09T23:41:31.548Z,1570664491.548 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2019-10-09T23:41:31.554Z,1570664491.554 [YawRateCalculator] Loaded
2019-10-09T23:41:31.554Z,1570664491.554 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2019-10-09T23:41:31.597Z,1570664491.597 [ElevatorOffsetCalculator] Loaded
2019-10-09T23:41:31.598Z,1570664491.598 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2019-10-09T23:41:31.598Z,1570664491.598 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2019-10-09T23:41:31.599Z,1570664491.599 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2019-10-09T23:41:31.793Z,1570664491.793 [Aanderaa_O2] Loaded
2019-10-09T23:41:31.793Z,1570664491.793 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2019-10-09T23:41:31.886Z,1570664491.886 [CTD_NeilBrown] Loaded
2019-10-09T23:41:31.886Z,1570664491.886 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2019-10-09T23:41:31.887Z,1570664491.887 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 409B04E0
2019-10-09T23:41:31.888Z,1570664491.888 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 4798
2019-10-09T23:41:31.944Z,1570664491.944 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density
2019-10-09T23:41:31.949Z,1570664491.949 [CTD_Seabird](INFO): created writer for : sea_water_density
2019-10-09T23:41:31.950Z,1570664491.950 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth
2019-10-09T23:41:31.959Z,1570664491.959 [CTD_Seabird](INFO): created writer for : depth
2019-10-09T23:41:31.959Z,1570664491.959 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure
2019-10-09T23:41:31.964Z,1570664491.964 [CTD_Seabird](INFO): created writer for : sea_water_pressure
2019-10-09T23:41:31.965Z,1570664491.965 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity
2019-10-09T23:41:31.994Z,1570664491.994 [CTD_Seabird](INFO): created writer for : sea_water_salinity
2019-10-09T23:41:31.994Z,1570664491.994 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature
2019-10-09T23:41:31.999Z,1570664491.999 [CTD_Seabird](INFO): created writer for : sea_water_temperature
2019-10-09T23:41:32.000Z,1570664492.000 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity
2019-10-09T23:41:32.005Z,1570664492.005 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity
2019-10-09T23:41:32.006Z,1570664492.006 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water
2019-10-09T23:41:32.011Z,1570664492.011 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water
2019-10-09T23:41:32.042Z,1570664492.042 [CTD_Seabird] Loaded
2019-10-09T23:41:32.042Z,1570664492.042 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2019-10-09T23:41:32.043Z,1570664492.043 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 409E04E0
2019-10-09T23:41:32.043Z,1570664492.043 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 4799
2019-10-09T23:41:32.058Z,1570664492.058 [PAR_Licor] Loaded
2019-10-09T23:41:32.059Z,1570664492.059 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2019-10-09T23:41:32.110Z,1570664492.110 [WetLabsBB2FL] Loaded
2019-10-09T23:41:32.110Z,1570664492.110 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2019-10-09T23:41:32.111Z,1570664492.111 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40A104E0
2019-10-09T23:41:32.111Z,1570664492.111 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 4800
2019-10-09T23:41:32.112Z,1570664492.112 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2019-10-09T23:41:32.113Z,1570664492.113 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2019-10-09T23:41:32.146Z,1570664492.146 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2019-10-09T23:41:32.147Z,1570664492.147 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2019-10-09T23:41:32.501Z,1570664492.501 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2019-10-09T23:41:32.501Z,1570664492.501 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2019-10-09T23:41:32.639Z,1570664492.639 [SBIT](DEBUG): Construct Startup Built In Test.
2019-10-09T23:41:32.651Z,1570664492.651 [SBIT] Loaded
2019-10-09T23:41:32.651Z,1570664492.651 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2019-10-09T23:41:32.652Z,1570664492.652 [IBIT](DEBUG): Construct Initiated Built In Test.
2019-10-09T23:41:32.664Z,1570664492.664 [IBIT] Loaded
2019-10-09T23:41:32.665Z,1570664492.665 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2019-10-09T23:41:32.668Z,1570664492.668 [CBIT](DEBUG): Construct Continuous Built In Test.
2019-10-09T23:41:32.878Z,1570664492.878 [CBIT] Loaded
2019-10-09T23:41:32.879Z,1570664492.879 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2019-10-09T23:41:32.879Z,1570664492.879 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2019-10-09T23:41:32.883Z,1570664492.883 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2019-10-09T23:41:32.884Z,1570664492.884 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2019-10-09T23:41:32.890Z,1570664492.890 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2019-10-09T23:41:32.892Z,1570664492.892 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B0F4E0
2019-10-09T23:41:32.892Z,1570664492.892 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 4801
2019-10-09T23:41:32.896Z,1570664492.896 [Supervisor](INFO): Main Thread ID is 4708
2019-10-09T23:41:32.897Z,1570664492.897 [Supervisor](DEBUG): Running supervisor.
2019-10-09T23:41:32.897Z,1570664492.897 [CommandLine ThreadHandler](INFO): Handler Thread ID is 4802
2019-10-09T23:41:32.899Z,1570664492.899 [controlThread ThreadHandler](INFO): Handler Thread ID is 4803
2019-10-09T23:41:32.900Z,1570664492.900 [controlThread](DEBUG): Initializing ControlThread
2019-10-09T23:41:32.901Z,1570664492.901 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2019-10-09T23:41:32.902Z,1570664492.902 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2019-10-09T23:41:32.903Z,1570664492.903 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2019-10-09T23:41:32.903Z,1570664492.903 [LoopControl](DEBUG): Initialize LoopControlComponent.
2019-10-09T23:41:32.905Z,1570664492.905 [NavChart](DEBUG): Initialize NavChart Navigation.
2019-10-09T23:41:32.906Z,1570664492.906 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2019-10-09T23:41:32.911Z,1570664492.911 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2019-10-09T23:41:32.912Z,1570664492.912 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2019-10-09T23:41:32.912Z,1570664492.912 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2019-10-09T23:41:32.912Z,1570664492.912 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2019-10-09T23:41:32.914Z,1570664492.914 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2019-10-09T23:41:32.914Z,1570664492.914 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2019-10-09T23:41:32.917Z,1570664492.917 [SBIT](INFO): Initialize SBIT Component.
2019-10-09T23:41:32.918Z,1570664492.918 [SBIT](IMPORTANT): git: 2019-09-10
2019-10-09T23:41:32.918Z,1570664492.918 [SBIT](INFO): git hash: e950883795b57abbf97d89589ea0268241928c93
2019-10-09T23:41:32.918Z,1570664492.918 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2019-10-09T23:41:32.919Z,1570664492.919 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #1 PREEMPT Tue Dec 18 21:19:28 PST 2018
2019-10-09T23:41:32.920Z,1570664492.920 [SBIT](INFO): Beginning SBIT in 23.000000 seconds.
2019-10-09T23:41:32.921Z,1570664492.921 [IBIT](INFO): Initialize IBIT Component.
2019-10-09T23:41:32.922Z,1570664492.922 [CBIT](DEBUG): Initialize CBIT Component.
2019-10-09T23:41:32.923Z,1570664492.923 [logger ThreadHandler](INFO): Handler Thread ID is 4804
2019-10-09T23:41:32.933Z,1570664492.933 [CBIT](DEBUG): Initialized mux pins.
2019-10-09T23:41:32.933Z,1570664492.933 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL.
2019-10-09T23:41:32.933Z,1570664492.933 [CBIT](DEBUG): Initializing the watchdog timer.
2019-10-09T23:41:32.941Z,1570664492.941 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 4805
2019-10-09T23:41:32.942Z,1570664492.942 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2019-10-09T23:41:32.953Z,1570664492.953 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 4806
2019-10-09T23:41:32.957Z,1570664492.957 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2019-10-09T23:41:32.957Z,1570664492.957 [CBIT](DEBUG): Initializing heartbeat.
2019-10-09T23:41:32.966Z,1570664492.966 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 4807
2019-10-09T23:41:32.967Z,1570664492.967 [CTD_NeilBrown](INFO): Powering down
2019-10-09T23:41:32.985Z,1570664492.985 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 4808
2019-10-09T23:41:32.986Z,1570664492.986 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2019-10-09T23:41:32.989Z,1570664492.989 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20
2019-10-09T23:41:33.002Z,1570664493.002 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 4810
2019-10-09T23:41:33.003Z,1570664493.003 [WetLabsBB2FL](INFO): Powering down
2019-10-09T23:41:33.029Z,1570664493.029 [CBIT](DEBUG): Deactivating GF circuits.
2019-10-09T23:41:33.029Z,1570664493.029 [CBIT](DEBUG): Deactivating emergency mode.
2019-10-09T23:41:33.030Z,1570664493.030 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 4811
2019-10-09T23:41:33.033Z,1570664493.033 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2019-10-09T23:41:33.033Z,1570664493.033 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2019-10-09T23:41:33.034Z,1570664493.034 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2019-10-09T23:41:33.034Z,1570664493.034 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2019-10-09T23:41:33.034Z,1570664493.034 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2019-10-09T23:41:33.034Z,1570664493.034 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2019-10-09T23:41:33.034Z,1570664493.034 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2019-10-09T23:41:33.034Z,1570664493.034 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2019-10-09T23:41:33.035Z,1570664493.035 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2019-10-09T23:41:33.035Z,1570664493.035 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2019-10-09T23:41:33.035Z,1570664493.035 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2019-10-09T23:41:33.035Z,1570664493.035 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2019-10-09T23:41:33.035Z,1570664493.035 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2019-10-09T23:41:33.036Z,1570664493.036 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2019-10-09T23:41:33.036Z,1570664493.036 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2019-10-09T23:41:33.036Z,1570664493.036 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2019-10-09T23:41:33.065Z,1570664493.065 [CBIT](DEBUG): Backplane powered.
2019-10-09T23:41:33.066Z,1570664493.066 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2019-10-09T23:41:33.076Z,1570664493.076 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2019-10-09T23:41:33.096Z,1570664493.096 [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>


2019-10-09T23:41:33.096Z,1570664493.096 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2019-10-09T23:41:33.241Z,1570664493.241 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2019-10-09T23:41:33.242Z,1570664493.242 [Default:A.Wait](DEBUG): Construct Wait.
2019-10-09T23:41:33.244Z,1570664493.244 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2019-10-09T23:41:33.275Z,1570664493.275 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2019-10-09T23:41:33.289Z,1570664493.289 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2019-10-09T23:41:33.295Z,1570664493.295 [Default:E.Execute](DEBUG): Construct Execute.
2019-10-09T23:41:33.314Z,1570664493.314 [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>


2019-10-09T23:41:33.319Z,1570664493.319 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,DVL_micro,NAL9602,Onboard,DAT,BPC1,Aanderaa_O2,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-10-09T23:41:33.337Z,1570664493.337 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2019-10-09T23:41:33.373Z,1570664493.373 [Radio_Surface](INFO): Powering up
2019-10-09T23:41:33.494Z,1570664493.494 [DVL_micro](INFO): Initializing
2019-10-09T23:41:33.553Z,1570664493.553 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2019-10-09T23:41:33.554Z,1570664493.554 [DAT](INFO): Powering up
2019-10-09T23:41:33.554Z,1570664493.554 [DAT](DEBUG): Initializing DAT.
2019-10-09T23:41:33.601Z,1570664493.601 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2019-10-09T23:41:33.719Z,1570664493.719 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2019-10-09T23:41:33.729Z,1570664493.729 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2019-10-09T23:41:33.730Z,1570664493.730 [ElevatorServo](DEBUG): Initializing EZServoServo.
2019-10-09T23:41:33.749Z,1570664493.749 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2019-10-09T23:41:33.750Z,1570664493.750 [MassServo](DEBUG): Initializing EZServoServo.
2019-10-09T23:41:33.765Z,1570664493.765 [MassServo](DEBUG): Initializing MassServo.
2019-10-09T23:41:33.766Z,1570664493.766 [RudderServo](DEBUG): Initializing EZServoServo.
2019-10-09T23:41:33.785Z,1570664493.785 [RudderServo](DEBUG): Initializing RudderServo.
2019-10-09T23:41:33.786Z,1570664493.786 [ThrusterServo](DEBUG): Initializing EZServoServo.
2019-10-09T23:41:33.813Z,1570664493.813 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2019-10-09T23:41:33.997Z,1570664493.997 [Depth_Keller](INFO): A/D timeout, 7 tries over 127 ms

2019-10-09T23:41:33.997Z,1570664493.997 [Depth_Keller] Data Fault, FailCount= 1
2019-10-09T23:41:33.997Z,1570664493.997 [Depth_Keller](ERROR): Data Fault
2019-10-09T23:41:33.998Z,1570664493.998 [DropWeight](CRITICAL): DROP WEIGHT MISSING.

2019-10-09T23:41:33.998Z,1570664493.998 [DropWeight] Hardware Fault, FailCount= 1
2019-10-09T23:41:33.998Z,1570664493.998 [DropWeight](ERROR): Hardware Fault
2019-10-09T23:41:34.123Z,1570664494.123 [CommandLine](FAULT): Scheduling is paused
2019-10-09T23:41:34.123Z,1570664494.123 [CBIT](INFO): Critical error at 20191009T234133
2019-10-09T23:41:34.124Z,1570664494.124 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2019-10-09T23:41:34.126Z,1570664494.126 [CBIT](ERROR): Data Fault in component: Depth_Keller
2019-10-09T23:41:34.126Z,1570664494.126 [CBIT](INFO): Clearing failed state for component Depth_Keller
2019-10-09T23:41:34.126Z,1570664494.126 [Depth_Keller] No Fault, FailCount= 1
2019-10-09T23:41:34.127Z,1570664494.127 [CBIT](ERROR): Hardware Fault in component: DropWeight
2019-10-09T23:41:34.127Z,1570664494.127 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2019-10-09T23:41:34.283Z,1570664494.283 [CBIT](INFO): Critical error at 20191009T234134
2019-10-09T23:41:36.309Z,1570664496.309 [MassServo](FAULT): Mass shifter EEPROM initialization uart error serial timeout
2019-10-09T23:41:36.309Z,1570664496.309 [MassServo] Communications Fault, FailCount= 1
2019-10-09T23:41:36.309Z,1570664496.309 [MassServo](ERROR): Communications Fault
2019-10-09T23:41:36.314Z,1570664496.314 [CBIT](ERROR): Communications Fault in component: MassServo
2019-10-09T23:41:36.799Z,1570664496.799 [ElevatorServo](FAULT): Elevator initialization uart error:serial timeout
2019-10-09T23:41:36.799Z,1570664496.799 [ElevatorServo] Communications Fault, FailCount= 1
2019-10-09T23:41:36.800Z,1570664496.800 [ElevatorServo](ERROR): Communications Fault
2019-10-09T23:41:36.804Z,1570664496.805 [MassServo](DEBUG): Uninitialize Mass Servo.
2019-10-09T23:41:36.809Z,1570664496.809 [MassServo](INFO): Powering down
2019-10-09T23:41:37.008Z,1570664497.008 [CBIT](ERROR): Communications Fault in component: ElevatorServo
2019-10-09T23:41:37.245Z,1570664497.245 [Aanderaa_O2](INFO): Powering down
2019-10-09T23:41:37.388Z,1570664497.388 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2019-10-09T23:41:37.388Z,1570664497.388 [ElevatorServo](INFO): Powering down
2019-10-09T23:41:37.831Z,1570664497.831 [MassServo](DEBUG): Initializing EZServoServo.
2019-10-09T23:41:37.951Z,1570664497.951 [MassServo](DEBUG): Initializing MassServo.
2019-10-09T23:41:38.046Z,1570664498.046 [CBIT](INFO): Clearing failed state for component MassServo
2019-10-09T23:41:38.046Z,1570664498.046 [MassServo] No Fault, FailCount= 1
2019-10-09T23:41:38.207Z,1570664498.207 [ElevatorServo](DEBUG): Initializing EZServoServo.
2019-10-09T23:41:38.322Z,1570664498.322 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2019-10-09T23:41:38.620Z,1570664498.620 [CBIT](INFO): Clearing failed state for component ElevatorServo
2019-10-09T23:41:38.621Z,1570664498.621 [ElevatorServo] No Fault, FailCount= 1
2019-10-09T23:41:40.018Z,1570664500.018 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit.
2019-10-09T23:41:43.213Z,1570664503.213 [CBIT](CRITICAL): Environmental Failure. Press:14.608959 PSI. Humidity:37%. Temp:24 C. ABORTING MISSION
2019-10-09T23:41:43.703Z,1570664503.703 [CBIT](INFO): Critical error at 20191009T234143
2019-10-09T23:41:44.290Z,1570664504.290 [DVL_micro](ERROR): No DVL communication! Re-initializing
2019-10-09T23:41:44.290Z,1570664504.290 [DVL_micro] Communications Fault, FailCount= 1
2019-10-09T23:41:44.290Z,1570664504.290 [DVL_micro](ERROR): Communications Fault
2019-10-09T23:41:44.415Z,1570664504.415 [CBIT](ERROR): Communications Fault in component: DVL_micro
2019-10-09T23:41:44.789Z,1570664504.789 [DVL_micro](INFO): uninitialize:Powering down
2019-10-09T23:41:45.610Z,1570664505.610 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-10-09T23:41:45.611Z,1570664505.611 [DVL_micro] No Fault, FailCount= 1
2019-10-09T23:41:45.916Z,1570664505.916 [DVL_micro](INFO): Initializing
2019-10-09T23:41:47.134Z,1570664507.134 [DAT](INFO): setting local address to 2
2019-10-09T23:41:47.540Z,1570664507.540 [DAT](INFO): set local address to 2
2019-10-09T23:41:53.431Z,1570664513.431 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.005053
2019-10-09T23:41:56.418Z,1570664516.418 [DVL_micro](ERROR): No DVL communication! Re-initializing
2019-10-09T23:41:56.418Z,1570664516.418 [DVL_micro] Communications Fault, FailCount= 2
2019-10-09T23:41:56.418Z,1570664516.418 [DVL_micro](ERROR): Communications Fault
2019-10-09T23:41:56.472Z,1570664516.472 [SBIT](IMPORTANT): Beginning Startup BIT
2019-10-09T23:41:56.484Z,1570664516.484 [CBIT](ERROR): Communications Fault in component: DVL_micro
2019-10-09T23:41:56.484Z,1570664516.484 [CBIT](IMPORTANT): Beginning ground fault scan
2019-10-09T23:41:56.885Z,1570664516.885 [DVL_micro](INFO): uninitialize:Powering down
2019-10-09T23:41:57.738Z,1570664517.738 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-10-09T23:41:57.738Z,1570664517.738 [DVL_micro] No Fault, FailCount= 2
2019-10-09T23:41:58.036Z,1570664518.036 [DVL_micro](INFO): Initializing
2019-10-09T23:41:58.951Z,1570664518.951 [NAL9602](INFO): Powering up NAL9602
2019-10-09T23:42:03.601Z,1570664523.601 [CBIT](INFO): A/D timeout, 3 tries over 128 ms

2019-10-09T23:42:07.613Z,1570664527.613 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.011267
CHAN A1 (24V): 0.047840
CHAN A2 (12V): -0.002292
CHAN A3 (5V): -0.001395
CHAN B0 (3.3V): nan
CHAN B1 (3.15aV): 0.001491
CHAN B2 (3.15bV): -0.000746
CHAN B3 (GND): -0.000316
OPEN: -0.000441
Full Scale Calc: 4.765 mA, -1.589 mA
2019-10-09T23:42:08.634Z,1570664528.634 [DVL_micro](ERROR): No DVL communication! Re-initializing
2019-10-09T23:42:08.634Z,1570664528.634 [DVL_micro] Communications Fault, FailCount= 3
2019-10-09T23:42:08.634Z,1570664528.634 [DVL_micro](ERROR): Communications Fault
2019-10-09T23:42:08.763Z,1570664528.763 [CBIT](ERROR): Communications Fault in component: DVL_micro
2019-10-09T23:42:09.118Z,1570664529.118 [DVL_micro](INFO): uninitialize:Powering down
2019-10-09T23:42:09.846Z,1570664529.846 [NAL9602](INFO): NAL9602 initialized
2019-10-09T23:42:09.971Z,1570664529.971 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-10-09T23:42:09.971Z,1570664529.971 [DVL_micro] No Fault, FailCount= 3
2019-10-09T23:42:10.252Z,1570664530.252 [DVL_micro](INFO): Initializing
2019-10-09T23:42:10.670Z,1570664530.670 [NAL9602](DEBUG): Fix Requested
2019-10-09T23:42:20.758Z,1570664540.758 [DVL_micro](ERROR): No DVL communication! Re-initializing
2019-10-09T23:42:20.758Z,1570664540.758 [DVL_micro] Communications Fault, FailCount= 4
2019-10-09T23:42:20.758Z,1570664540.758 [DVL_micro](ERROR): Communications Fault
2019-10-09T23:42:20.904Z,1570664540.904 [CBIT](ERROR): Communications Fault in component: DVL_micro
2019-10-09T23:42:21.229Z,1570664541.229 [DVL_micro](INFO): uninitialize:Powering down
2019-10-09T23:42:22.106Z,1570664542.106 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-10-09T23:42:22.107Z,1570664542.107 [DVL_micro] No Fault, FailCount= 4
2019-10-09T23:42:22.376Z,1570664542.376 [DVL_micro](INFO): Initializing
2019-10-09T23:42:32.874Z,1570664552.874 [DVL_micro](ERROR): No DVL communication! Re-initializing
2019-10-09T23:42:32.874Z,1570664552.874 [DVL_micro] Communications Fault, FailCount= 5
2019-10-09T23:42:32.874Z,1570664552.874 [DVL_micro](ERROR): Communications Fault
2019-10-09T23:42:33.035Z,1570664553.035 [CBIT](ERROR): Communications Fault in component: DVL_micro
2019-10-09T23:42:33.035Z,1570664553.035 [CBIT](CRITICAL): Communications Fault in component: DVL_micro
2019-10-09T23:42:33.357Z,1570664553.357 [DVL_micro](INFO): uninitialize:Powering down
2019-10-09T23:42:33.496Z,1570664553.496 [CBIT](INFO): Critical error at 20191009T234233
2019-10-09T23:42:50.260Z,1570664570.260 [SBIT](IMPORTANT): SBIT PASSED
2019-10-09T23:42:50.343Z,1570664570.343 [CommandLine](IMPORTANT): got command configSet list
2019-10-09T23:42:50.343Z,1570664570.343 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2019-10-09T23:42:50.344Z,1570664570.344 [CommandLine](IMPORTANT): CBIT.gf24Offset=154 microampere;

2019-10-09T23:42:50.344Z,1570664570.344 [CommandLine](IMPORTANT): CTD_NeilBrown.loadAtStartup=0 bool;

2019-10-09T23:42:50.344Z,1570664570.344 [CommandLine](IMPORTANT): DAT.loadAtStartup=0 bool;

2019-10-09T23:42:50.344Z,1570664570.344 [CommandLine](IMPORTANT): DVL_micro.loadAtStartup=0 bool;

2019-10-09T23:42:50.644Z,1570664570.644 [MissionManager](IMPORTANT): Started mission Startup
2019-10-09T23:42:50.644Z,1570664570.644 [Startup] Running Loop=1
2019-10-09T23:42:50.653Z,1570664570.653 [Startup](DEBUG): Aggregate::initialize Startup
2019-10-09T23:42:50.653Z,1570664570.653 [Startup:A.GoToSurface] Running Loop=1
2019-10-09T23:42:50.653Z,1570664570.653 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-10-09T23:42:50.654Z,1570664570.654 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-10-09T23:42:50.654Z,1570664570.654 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-10-09T23:42:50.654Z,1570664570.654 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-10-09T23:42:50.655Z,1570664570.655 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-10-09T23:42:50.655Z,1570664570.655 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-10-09T23:42:50.656Z,1570664570.656 [Startup:StartupSatComms] Running Loop=1
2019-10-09T23:42:50.666Z,1570664570.666 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2019-10-09T23:42:50.666Z,1570664570.666 [Startup:StartupSatComms:A] Running Loop=1
2019-10-09T23:42:51.047Z,1570664571.047 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2019-10-09T23:43:07.969Z,1570664587.969 [Depth_Keller](INFO): A/D timeout, 2 tries over 126 ms

2019-10-09T23:43:07.969Z,1570664587.969 [Depth_Keller] Data Fault, FailCount= 1
2019-10-09T23:43:07.969Z,1570664587.969 [Depth_Keller](ERROR): Data Fault
2019-10-09T23:43:08.108Z,1570664588.108 [CBIT](ERROR): Data Fault in component: Depth_Keller
2019-10-09T23:43:08.108Z,1570664588.108 [CBIT](INFO): Clearing failed state for component Depth_Keller
2019-10-09T23:43:08.108Z,1570664588.108 [Depth_Keller] No Fault, FailCount= 1
2019-10-09T23:43:50.965Z,1570664630.965 [Startup:StartupSatComms:A](INFO): Timed out from 2019-10-09T23:42:50.7Z
2019-10-09T23:43:50.965Z,1570664630.965 [Startup:StartupSatComms:A] Stopped
2019-10-09T23:43:50.965Z,1570664630.965 [Startup:StartupSatComms:B] Running Loop=1
2019-10-09T23:43:51.356Z,1570664631.356 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-10-09T23:43:59.556Z,1570664639.556 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20191009T232958/Courier0007.lzma
2019-10-09T23:44:01.563Z,1570664641.563 [DataOverHttps](INFO): Moved sent file to Logs/20191009T232958/Courier0007.lzma.bak
2019-10-09T23:44:01.563Z,1570664641.563 [DataOverHttps](INFO): SBD MOMSN=11868056
2019-10-09T23:44:20.813Z,1570664660.813 [DataOverHttps](INFO): Sending 239 bytes from file Logs/20191009T234120/Courier0000.lzma
2019-10-09T23:44:22.818Z,1570664662.818 [DataOverHttps](INFO): Moved sent file to Logs/20191009T234120/Courier0000.lzma.bak
2019-10-09T23:44:22.819Z,1570664662.819 [DataOverHttps](INFO): SBD MOMSN=11868062
2019-10-09T23:44:32.988Z,1570664672.988 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2019-10-09T23:44:32.988Z,1570664672.988 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-10-09T23:44:33.019Z,1570664673.019 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-10-09T23:44:33.392Z,1570664673.392 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-10-09T23:44:33.392Z,1570664673.392 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2019-10-09T23:44:41.920Z,1570664681.920 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20191009T232958/Express0008.lzma
2019-10-09T23:44:43.926Z,1570664683.926 [DataOverHttps](INFO): Moved sent file to Logs/20191009T232958/Express0008.lzma.bak
2019-10-09T23:44:43.927Z,1570664683.927 [DataOverHttps](INFO): SBD MOMSN=11868069
2019-10-09T23:44:51.181Z,1570664691.181 [Startup:StartupSatComms:B](INFO): Timed out from 2019-10-09T23:43:50.0Z
2019-10-09T23:44:51.181Z,1570664691.181 [Startup:StartupSatComms:B] Stopped
2019-10-09T23:44:51.181Z,1570664691.181 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2019-10-09T23:44:51.181Z,1570664691.181 [Startup:StartupSatComms] Stopped
2019-10-09T23:44:51.182Z,1570664691.182 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2019-10-09T23:44:51.182Z,1570664691.182 [Startup](INFO): Completed Startup
2019-10-09T23:44:51.183Z,1570664691.183 [MissionManager](INFO): Startup is completed.
2019-10-09T23:44:51.183Z,1570664691.183 [MissionManager](INFO): Uninitializing Mission Startup
2019-10-09T23:44:51.183Z,1570664691.183 [Startup] Stopped
2019-10-09T23:44:51.183Z,1570664691.183 [Startup](DEBUG): Aggregate::uninitialize Startup
2019-10-09T23:44:51.183Z,1570664691.183 [Startup:A.GoToSurface] Stopped
2019-10-09T23:44:51.183Z,1570664691.183 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-10-09T23:44:51.578Z,1570664691.578 [MissionManager](IMPORTANT): Started mission Default
2019-10-09T23:44:51.578Z,1570664691.578 [Default] Running Loop=1
2019-10-09T23:44:51.578Z,1570664691.578 [Default](DEBUG): Aggregate::initialize Default
2019-10-09T23:44:51.579Z,1570664691.579 [Default:B.GoToSurface] Running Loop=1
2019-10-09T23:44:51.579Z,1570664691.579 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-10-09T23:44:51.579Z,1570664691.579 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-10-09T23:44:51.579Z,1570664691.579 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-10-09T23:44:51.580Z,1570664691.580 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-10-09T23:44:51.580Z,1570664691.580 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-10-09T23:44:51.580Z,1570664691.580 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-10-09T23:44:51.580Z,1570664691.580 [Default:A.Wait] Running Loop=1
2019-10-09T23:44:51.580Z,1570664691.580 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-10-09T23:45:02.441Z,1570664702.441 [DataOverHttps](INFO): Sending 812 bytes from file Logs/20191009T234120/Express0001.lzma
2019-10-09T23:45:04.446Z,1570664704.446 [DataOverHttps](INFO): Moved sent file to Logs/20191009T234120/Express0001.lzma.bak
2019-10-09T23:45:04.447Z,1570664704.447 [DataOverHttps](INFO): SBD MOMSN=11868071
2019-10-09T23:45:04.901Z,1570664704.901 [Default:A.Wait](INFO): Done Waiting.
2019-10-09T23:45:04.901Z,1570664704.901 [Default:A.Wait] Stopped
2019-10-09T23:45:04.901Z,1570664704.901 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-10-09T23:45:05.293Z,1570664705.293 [Default:CheckIn] Running Loop=1
2019-10-09T23:45:05.293Z,1570664705.293 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-10-09T23:45:05.293Z,1570664705.293 [Default:CheckIn:Read_GPS] Running Loop=1
2019-10-09T23:45:05.736Z,1570664705.736 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2019-10-09T23:45:54.498Z,1570664754.498 [CommandLine](IMPORTANT): got command quit
2019-10-09T23:45:55.511Z,1570664755.511 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2019-10-09T23:45:55.519Z,1570664755.519 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-10-09T23:45:55.573Z,1570664755.573 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2019-10-09T23:45:55.573Z,1570664755.573 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-10-09T23:45:55.574Z,1570664755.574 [CommandLine](INFO): Join timeout helper Thread ID is 4858
2019-10-09T23:45:55.574Z,1570664755.574 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2019-10-09T23:45:55.575Z,1570664755.575 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-10-09T23:45:55.575Z,1570664755.575 [NavChartDb](INFO): Join timeout helper Thread ID is 4859
2019-10-09T23:45:55.609Z,1570664755.609 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2019-10-09T23:45:55.609Z,1570664755.609 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-10-09T23:45:55.613Z,1570664755.613 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2019-10-09T23:45:55.613Z,1570664755.613 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-10-09T23:45:55.614Z,1570664755.614 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 4860
2019-10-09T23:45:55.709Z,1570664755.709 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2019-10-09T23:45:55.710Z,1570664755.710 [WetLabsBB2FL](INFO): Powering down
2019-10-09T23:45:55.710Z,1570664755.710 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-10-09T23:45:55.717Z,1570664755.717 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2019-10-09T23:45:55.717Z,1570664755.717 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2019-10-09T23:45:55.717Z,1570664755.717 [CTD_Seabird](INFO): Join timeout helper Thread ID is 4861
2019-10-09T23:45:56.097Z,1570664756.097 [CTD_Seabird](INFO): Powering down
2019-10-09T23:45:56.109Z,1570664756.109 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2019-10-09T23:45:56.109Z,1570664756.109 [CTD_Seabird](INFO): Powering down
2019-10-09T23:45:56.121Z,1570664756.121 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2019-10-09T23:45:56.133Z,1570664756.133 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2019-10-09T23:45:56.133Z,1570664756.133 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-10-09T23:45:56.133Z,1570664756.133 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 4862
2019-10-09T23:45:56.285Z,1570664756.285 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2019-10-09T23:45:56.285Z,1570664756.285 [CTD_NeilBrown](INFO): Powering down
2019-10-09T23:45:56.297Z,1570664756.297 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-10-09T23:45:56.319Z,1570664756.319 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2019-10-09T23:45:56.320Z,1570664756.320 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-10-09T23:45:56.342Z,1570664756.342 [Radio_Surface](INFO): Join timeout helper Thread ID is 4863
2019-10-09T23:45:56.417Z,1570664756.417 [Radio_Surface](INFO): Powering down
2019-10-09T23:45:56.437Z,1570664756.437 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2019-10-09T23:45:56.437Z,1570664756.437 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-10-09T23:45:56.454Z,1570664756.454 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2019-10-09T23:45:56.454Z,1570664756.454 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-10-09T23:45:56.454Z,1570664756.454 [DataOverHttps](INFO): Join timeout helper Thread ID is 4864
2019-10-09T23:45:56.845Z,1570664756.845 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2019-10-09T23:45:56.845Z,1570664756.845 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-10-09T23:45:56.862Z,1570664756.862 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2019-10-09T23:45:56.862Z,1570664756.862 [logger ThreadHandler](INFO): Thread cancelled.
2019-10-09T23:45:56.862Z,1570664756.862 [logger](INFO): Join timeout helper Thread ID is 4865
2019-10-09T23:45:56.877Z,1570664756.877 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2019-10-09T23:45:56.877Z,1570664756.877 [logger ThreadHandler](INFO): Thread cancelled.
2019-10-09T23:45:56.882Z,1570664756.882 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2019-10-09T23:45:56.882Z,1570664756.882 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-10-09T23:45:56.882Z,1570664756.882 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2019-10-09T23:45:56.882Z,1570664756.882 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-10-09T23:45:56.882Z,1570664756.882 [controlThread](INFO): Join timeout helper Thread ID is 4866
2019-10-09T23:45:56.969Z,1570664756.969 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2019-10-09T23:45:56.969Z,1570664756.969 [controlThread](DEBUG): Uninitializing ControlThread
2019-10-09T23:45:56.970Z,1570664756.970 [AHRS_M2](INFO): Powering down
2019-10-09T23:45:57.042Z,1570664757.042 [DVL_micro](INFO): uninitialize:Powering down
2019-10-09T23:45:57.042Z,1570664757.042 [NAL9602](INFO): Powering down
2019-10-09T23:45:57.044Z,1570664757.044 [DAT](INFO): Powering down
2019-10-09T23:45:57.162Z,1570664757.162 [Aanderaa_O2](INFO): Powering down
2019-10-09T23:45:57.163Z,1570664757.163 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2019-10-09T23:45:57.164Z,1570664757.164 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2019-10-09T23:45:57.177Z,1570664757.177 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2019-10-09T23:45:57.178Z,1570664757.178 [MissionManager](INFO): Uninitializing Mission Default
2019-10-09T23:45:57.178Z,1570664757.178 [Default] Stopped
2019-10-09T23:45:57.178Z,1570664757.178 [Default](DEBUG): Aggregate::uninitialize Default
2019-10-09T23:45:57.178Z,1570664757.178 [Default:B.GoToSurface] Stopped
2019-10-09T23:45:57.178Z,1570664757.178 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-10-09T23:45:57.178Z,1570664757.178 [Default:CheckIn] Stopped
2019-10-09T23:45:57.178Z,1570664757.178 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-10-09T23:45:57.178Z,1570664757.178 [Default:CheckIn:Read_GPS] Stopped
2019-10-09T23:45:57.181Z,1570664757.181 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2019-10-09T23:45:57.181Z,1570664757.181 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2019-10-09T23:45:57.181Z,1570664757.181 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2019-10-09T23:45:57.182Z,1570664757.182 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2019-10-09T23:45:57.182Z,1570664757.182 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2019-10-09T23:45:57.182Z,1570664757.182 [BuoyancyServo](INFO): Powering down
2019-10-09T23:45:57.197Z,1570664757.197 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2019-10-09T23:45:57.197Z,1570664757.197 [ElevatorServo](INFO): Powering down
2019-10-09T23:45:57.198Z,1570664757.198 [MassServo](DEBUG): Uninitialize Mass Servo.
2019-10-09T23:45:57.198Z,1570664757.198 [MassServo](INFO): Powering down
2019-10-09T23:45:57.199Z,1570664757.199 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-10-09T23:45:57.199Z,1570664757.199 [RudderServo](INFO): Powering down
2019-10-09T23:45:57.199Z,1570664757.199 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2019-10-09T23:45:57.199Z,1570664757.199 [ThrusterServo](INFO): Powering down
2019-10-09T23:45:57.200Z,1570664757.200 [SBIT](DEBUG): Uninitialize SBIT Component.
2019-10-09T23:45:57.200Z,1570664757.200 [IBIT](DEBUG): Uninitialize IBIT Component.
2019-10-09T23:45:57.201Z,1570664757.201 [CBIT](DEBUG): Uninitialize CBIT Component.
2019-10-09T23:45:57.201Z,1570664757.201 [CBIT](DEBUG): Powering off loads.
2019-10-09T23:45:57.213Z,1570664757.213 [CBIT](DEBUG): Disabling WDT.
2019-10-09T23:45:57.225Z,1570664757.225 [CBIT](DEBUG): Opening all GF detection circuits.
2019-10-09T23:45:57.226Z,1570664757.226 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-10-09T23:45:57.318Z,1570664757.318 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-10-09T23:45:57.330Z,1570664757.330 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-10-09T23:45:57.363Z,1570664757.363 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-10-09T23:45:57.366Z,1570664757.366 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2019-10-09T23:45:57.370Z,1570664757.370 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-10-09T23:45:57.412Z,1570664757.412 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-10-09T23:45:57.475Z,1570664757.475 [logger ThreadHandler](INFO): Thread cancelled.