2019-11-20T23:01:12.839Z,1574290872.839 [Supervisor](DEBUG): Initializing supervisor.
2019-11-20T23:01:12.842Z,1574290872.842 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2019-11-20T23:01:12.843Z,1574290872.843 [SyncHandler](INFO): Protected caller Thread ID is 995
2019-11-20T23:01:12.843Z,1574290872.843 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2019-11-20T23:01:12.844Z,1574290872.844 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2019-11-20T23:01:12.845Z,1574290872.845 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 996
2019-11-20T23:01:12.848Z,1574290872.848 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2019-11-20T23:01:12.859Z,1574290872.859 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2019-11-20T23:01:12.860Z,1574290872.860 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2019-11-20T23:01:12.861Z,1574290872.861 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 997
2019-11-20T23:01:12.862Z,1574290872.862 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2019-11-20T23:01:12.863Z,1574290872.863 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2019-11-20T23:01:12.863Z,1574290872.863 [logger ThreadHandler](INFO): Protected caller Thread ID is 998
2019-11-20T23:01:12.865Z,1574290872.865 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2019-11-20T23:01:12.865Z,1574290872.865 [Supervisor](INFO): Looking for Config files in directory: Config/
2019-11-20T23:01:12.867Z,1574290872.867 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2019-11-20T23:01:13.278Z,1574290873.278 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2019-11-20T23:01:13.279Z,1574290873.279 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2019-11-20T23:01:13.374Z,1574290873.374 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2019-11-20T23:01:13.375Z,1574290873.375 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2019-11-20T23:01:13.676Z,1574290873.676 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2019-11-20T23:01:13.677Z,1574290873.677 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2019-11-20T23:01:13.815Z,1574290873.815 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2019-11-20T23:01:13.816Z,1574290873.816 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2019-11-20T23:01:13.998Z,1574290873.998 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2019-11-20T23:01:13.999Z,1574290873.999 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2019-11-20T23:01:14.431Z,1574290874.431 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2019-11-20T23:01:14.431Z,1574290874.431 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2019-11-20T23:01:14.631Z,1574290874.631 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2019-11-20T23:01:14.631Z,1574290874.631 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2019-11-20T23:01:14.771Z,1574290874.771 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2019-11-20T23:01:14.772Z,1574290874.772 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2019-11-20T23:01:14.953Z,1574290874.953 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2019-11-20T23:01:14.954Z,1574290874.954 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2019-11-20T23:01:15.057Z,1574290875.057 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2019-11-20T23:01:15.057Z,1574290875.057 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2019-11-20T23:01:15.836Z,1574290875.836 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2019-11-20T23:01:15.837Z,1574290875.837 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2019-11-20T23:01:15.918Z,1574290875.918 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2019-11-20T23:01:16.019Z,1574290876.019 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2019-11-20T23:01:16.019Z,1574290876.019 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2019-11-20T23:01:16.647Z,1574290876.647 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2019-11-20T23:01:16.647Z,1574290876.647 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2019-11-20T23:01:17.043Z,1574290877.043 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2019-11-20T23:01:17.045Z,1574290877.045 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/
2019-11-20T23:01:17.045Z,1574290877.045 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/vehicle.cfg
2019-11-20T23:01:17.243Z,1574290877.243 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Control.cfg
2019-11-20T23:01:17.340Z,1574290877.340 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/BIT.cfg
2019-11-20T23:01:17.435Z,1574290877.435 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Battery.cfg
2019-11-20T23:01:17.659Z,1574290877.659 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2019-11-20T23:01:17.659Z,1574290877.659 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Simulator.cfg
2019-11-20T23:01:17.742Z,1574290877.742 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Navigation.cfg
2019-11-20T23:01:17.833Z,1574290877.833 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/logger.cfg
2019-11-20T23:01:17.928Z,1574290877.928 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/secure.cfg
2019-11-20T23:01:18.009Z,1574290878.009 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Servo.cfg
2019-11-20T23:01:18.114Z,1574290878.114 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Sensor.cfg
2019-11-20T23:01:18.290Z,1574290878.290 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Science.cfg
2019-11-20T23:01:18.416Z,1574290878.416 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/root/
2019-11-20T23:01:18.417Z,1574290878.417 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2019-11-20T23:01:18.433Z,1574290878.433 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2019-11-20T23:01:18.732Z,1574290878.732 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_orientation
2019-11-20T23:01:18.737Z,1574290878.737 [AHRS_M2](INFO): created writer for : platform_orientation
2019-11-20T23:01:18.739Z,1574290878.739 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_magnetic_orientation
2019-11-20T23:01:18.744Z,1574290878.744 [AHRS_M2](INFO): created writer for : platform_magnetic_orientation
2019-11-20T23:01:18.745Z,1574290878.745 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_pitch_angle
2019-11-20T23:01:18.750Z,1574290878.750 [AHRS_M2](INFO): created writer for : platform_pitch_angle
2019-11-20T23:01:18.750Z,1574290878.750 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_roll_angle
2019-11-20T23:01:18.756Z,1574290878.756 [AHRS_M2](INFO): created writer for : platform_roll_angle
2019-11-20T23:01:18.825Z,1574290878.825 [AHRS_M2] Loaded
2019-11-20T23:01:18.825Z,1574290878.825 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2019-11-20T23:01:18.900Z,1574290878.900 [DataOverHttps] Loaded
2019-11-20T23:01:18.900Z,1574290878.900 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2019-11-20T23:01:18.901Z,1574290878.901 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 407694E0
2019-11-20T23:01:18.902Z,1574290878.902 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 1077
2019-11-20T23:01:18.925Z,1574290878.925 [DDM] Loaded
2019-11-20T23:01:18.925Z,1574290878.925 [ComponentRegistry](DEBUG): SyncComponent "DDM" handled in the control thread.
2019-11-20T23:01:18.939Z,1574290878.939 [Depth_Keller] Loaded
2019-11-20T23:01:18.939Z,1574290878.939 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2019-11-20T23:01:18.944Z,1574290878.944 [DropWeight] Loaded
2019-11-20T23:01:18.944Z,1574290878.944 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2019-11-20T23:01:19.005Z,1574290879.005 [DUSBL_Hydroid] Loaded
2019-11-20T23:01:19.005Z,1574290879.005 [ComponentRegistry](DEBUG): SyncComponent "DUSBL_Hydroid" handled in the control thread.
2019-11-20T23:01:19.050Z,1574290879.050 [Micromodem] Loaded
2019-11-20T23:01:19.051Z,1574290879.051 [ComponentRegistry](DEBUG): SyncComponent "Micromodem" handled in the control thread.
2019-11-20T23:01:19.145Z,1574290879.145 [NAL9602] Loaded
2019-11-20T23:01:19.146Z,1574290879.146 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2019-11-20T23:01:19.161Z,1574290879.161 [Onboard] Loaded
2019-11-20T23:01:19.161Z,1574290879.161 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2019-11-20T23:01:19.167Z,1574290879.167 [PowerOnly] Loaded
2019-11-20T23:01:19.167Z,1574290879.167 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread.
2019-11-20T23:01:19.173Z,1574290879.173 [Radio_Surface] Loaded
2019-11-20T23:01:19.174Z,1574290879.174 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2019-11-20T23:01:19.175Z,1574290879.175 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 407994E0
2019-11-20T23:01:19.175Z,1574290879.175 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 1078
2019-11-20T23:01:19.217Z,1574290879.217 [RDI_Pathfinder] Loaded
2019-11-20T23:01:19.217Z,1574290879.217 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2019-11-20T23:01:20.673Z,1574290880.673 [BPC1] Loaded
2019-11-20T23:01:20.674Z,1574290880.674 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2019-11-20T23:01:20.674Z,1574290880.674 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2019-11-20T23:01:20.675Z,1574290880.675 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2019-11-20T23:01:20.722Z,1574290880.722 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2019-11-20T23:01:20.723Z,1574290880.723 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2019-11-20T23:01:21.019Z,1574290881.019 [DeadReckonUsingMultipleVelocitySources] Loaded
2019-11-20T23:01:21.019Z,1574290881.019 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2019-11-20T23:01:21.102Z,1574290881.102 [NavChart] Loaded
2019-11-20T23:01:21.102Z,1574290881.102 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2019-11-20T23:01:21.106Z,1574290881.106 [UniversalFixResidualReporter] Loaded
2019-11-20T23:01:21.106Z,1574290881.106 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2019-11-20T23:01:21.107Z,1574290881.107 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2019-11-20T23:01:21.107Z,1574290881.107 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2019-11-20T23:01:21.267Z,1574290881.267 [BuoyancyServo] Loaded
2019-11-20T23:01:21.267Z,1574290881.267 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2019-11-20T23:01:21.329Z,1574290881.329 [ElevatorServo] Loaded
2019-11-20T23:01:21.329Z,1574290881.329 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2019-11-20T23:01:21.395Z,1574290881.395 [MassServo] Loaded
2019-11-20T23:01:21.396Z,1574290881.396 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2019-11-20T23:01:21.410Z,1574290881.410 [RudderServo] Loaded
2019-11-20T23:01:21.411Z,1574290881.411 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2019-11-20T23:01:21.425Z,1574290881.425 [ThrusterServo] Loaded
2019-11-20T23:01:21.425Z,1574290881.425 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2019-11-20T23:01:21.425Z,1574290881.425 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2019-11-20T23:01:21.426Z,1574290881.426 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2019-11-20T23:01:21.674Z,1574290881.674 [CTD_NeilBrown] Loaded
2019-11-20T23:01:21.674Z,1574290881.674 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2019-11-20T23:01:21.675Z,1574290881.675 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 408E34E0
2019-11-20T23:01:21.676Z,1574290881.676 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 1079
2019-11-20T23:01:21.690Z,1574290881.690 [PAR_Licor] Loaded
2019-11-20T23:01:21.690Z,1574290881.690 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2019-11-20T23:01:21.732Z,1574290881.732 [WetLabsSeaOWL_UV_A] Loaded
2019-11-20T23:01:21.733Z,1574290881.733 [ComponentRegistry](DEBUG): Component "WetLabsSeaOWL_UV_A" handled in its own thread.
2019-11-20T23:01:21.734Z,1574290881.734 [WetLabsSeaOWL_UV_A ThreadHandler](DEBUG): Created PCaller Thread at 409134E0
2019-11-20T23:01:21.734Z,1574290881.734 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Protected caller Thread ID is 1080
2019-11-20T23:01:21.735Z,1574290881.735 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2019-11-20T23:01:21.735Z,1574290881.735 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2019-11-20T23:01:22.032Z,1574290882.032 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2019-11-20T23:01:22.033Z,1574290882.033 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2019-11-20T23:01:22.071Z,1574290882.071 [DepthRateCalculator] Loaded
2019-11-20T23:01:22.072Z,1574290882.072 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2019-11-20T23:01:22.077Z,1574290882.077 [PitchRateCalculator] Loaded
2019-11-20T23:01:22.078Z,1574290882.078 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2019-11-20T23:01:22.089Z,1574290882.089 [SpeedCalculator] Loaded
2019-11-20T23:01:22.090Z,1574290882.090 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2019-11-20T23:01:22.110Z,1574290882.110 [TempGradientCalculator] Loaded
2019-11-20T23:01:22.110Z,1574290882.110 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2019-11-20T23:01:22.115Z,1574290882.115 [YawRateCalculator] Loaded
2019-11-20T23:01:22.116Z,1574290882.116 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2019-11-20T23:01:22.154Z,1574290882.154 [ElevatorOffsetCalculator] Loaded
2019-11-20T23:01:22.155Z,1574290882.155 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2019-11-20T23:01:22.155Z,1574290882.155 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2019-11-20T23:01:22.156Z,1574290882.156 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2019-11-20T23:01:22.286Z,1574290882.286 [SBIT](DEBUG): Construct Startup Built In Test.
2019-11-20T23:01:22.308Z,1574290882.308 [SBIT] Loaded
2019-11-20T23:01:22.308Z,1574290882.308 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2019-11-20T23:01:22.309Z,1574290882.309 [IBIT](DEBUG): Construct Initiated Built In Test.
2019-11-20T23:01:22.321Z,1574290882.321 [IBIT] Loaded
2019-11-20T23:01:22.321Z,1574290882.321 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2019-11-20T23:01:22.324Z,1574290882.324 [CBIT](DEBUG): Construct Continuous Built In Test.
2019-11-20T23:01:22.459Z,1574290882.459 [CBIT] Loaded
2019-11-20T23:01:22.459Z,1574290882.459 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2019-11-20T23:01:22.459Z,1574290882.459 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2019-11-20T23:01:22.460Z,1574290882.460 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2019-11-20T23:01:22.539Z,1574290882.539 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2019-11-20T23:01:22.539Z,1574290882.539 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2019-11-20T23:01:22.635Z,1574290882.635 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2019-11-20T23:01:22.635Z,1574290882.635 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2019-11-20T23:01:22.681Z,1574290882.681 [VerticalControl](DEBUG): Construct VerticalControl.
2019-11-20T23:01:22.761Z,1574290882.761 [VerticalControl] Loaded
2019-11-20T23:01:22.761Z,1574290882.761 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2019-11-20T23:01:22.762Z,1574290882.762 [HorizontalControl](DEBUG): Construct HorizontalControl.
2019-11-20T23:01:22.818Z,1574290882.818 [HorizontalControl] Loaded
2019-11-20T23:01:22.818Z,1574290882.818 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2019-11-20T23:01:22.819Z,1574290882.819 [SpeedControl](DEBUG): Construct SpeedControl.
2019-11-20T23:01:22.820Z,1574290882.820 [SpeedControl] Loaded
2019-11-20T23:01:22.821Z,1574290882.821 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2019-11-20T23:01:22.821Z,1574290882.821 [LoopControl](DEBUG): Construct LoopControl.
2019-11-20T23:01:22.822Z,1574290882.822 [LoopControl] Loaded
2019-11-20T23:01:22.822Z,1574290882.822 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2019-11-20T23:01:22.823Z,1574290882.823 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2019-11-20T23:01:22.823Z,1574290882.823 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2019-11-20T23:01:22.855Z,1574290882.855 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2019-11-20T23:01:22.859Z,1574290882.859 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2019-11-20T23:01:22.860Z,1574290882.860 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2019-11-20T23:01:22.866Z,1574290882.866 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2019-11-20T23:01:22.867Z,1574290882.867 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40AEF4E0
2019-11-20T23:01:22.867Z,1574290882.867 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 1081
2019-11-20T23:01:22.872Z,1574290882.872 [Supervisor](INFO): Main Thread ID is 802
2019-11-20T23:01:22.872Z,1574290882.872 [Supervisor](DEBUG): Running supervisor.
2019-11-20T23:01:22.873Z,1574290882.873 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1082
2019-11-20T23:01:22.875Z,1574290882.875 [controlThread ThreadHandler](INFO): Handler Thread ID is 1083
2019-11-20T23:01:22.875Z,1574290882.875 [controlThread](DEBUG): Initializing ControlThread
2019-11-20T23:01:22.885Z,1574290882.885 [NavChart](DEBUG): Initialize NavChart Navigation.
2019-11-20T23:01:22.885Z,1574290882.885 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2019-11-20T23:01:22.889Z,1574290882.889 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2019-11-20T23:01:22.889Z,1574290882.889 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2019-11-20T23:01:22.890Z,1574290882.890 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2019-11-20T23:01:22.890Z,1574290882.890 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2019-11-20T23:01:22.890Z,1574290882.890 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2019-11-20T23:01:22.891Z,1574290882.891 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2019-11-20T23:01:22.891Z,1574290882.891 [SBIT](INFO): Initialize SBIT Component.
2019-11-20T23:01:22.892Z,1574290882.892 [SBIT](IMPORTANT): git: 2019-11-13-4-g1952be0
2019-11-20T23:01:22.892Z,1574290882.892 [SBIT](INFO): git hash: 1952be029e6a0aa192ec2180874f0fa5b74dbe0e
2019-11-20T23:01:22.892Z,1574290882.892 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2019-11-20T23:01:22.894Z,1574290882.894 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #2 PREEMPT Wed May 15 08:34:03 PDT 2019
2019-11-20T23:01:22.895Z,1574290882.895 [SBIT](INFO): Beginning SBIT in 34.000000 seconds.
2019-11-20T23:01:22.895Z,1574290882.895 [IBIT](INFO): Initialize IBIT Component.
2019-11-20T23:01:22.896Z,1574290882.896 [CBIT](DEBUG): Initialize CBIT Component.
2019-11-20T23:01:22.897Z,1574290882.897 [logger ThreadHandler](INFO): Handler Thread ID is 1084
2019-11-20T23:01:22.909Z,1574290882.909 [CBIT](DEBUG): Initialized mux pins.
2019-11-20T23:01:22.909Z,1574290882.909 [CBIT](DEBUG): Initializing the watchdog timer.
2019-11-20T23:01:22.917Z,1574290882.917 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 1085
2019-11-20T23:01:22.918Z,1574290882.918 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2019-11-20T23:01:22.929Z,1574290882.929 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 1086
2019-11-20T23:01:22.933Z,1574290882.933 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2019-11-20T23:01:22.933Z,1574290882.933 [CBIT](DEBUG): Initializing heartbeat.
2019-11-20T23:01:22.941Z,1574290882.941 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 1087
2019-11-20T23:01:22.942Z,1574290882.942 [CTD_NeilBrown](INFO): Powering down
2019-11-20T23:01:22.969Z,1574290882.969 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Handler Thread ID is 1088
2019-11-20T23:01:22.970Z,1574290882.970 [WetLabsSeaOWL_UV_A](INFO): Powering down
2019-11-20T23:01:22.997Z,1574290882.997 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1089
2019-11-20T23:01:23.000Z,1574290883.000 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2019-11-20T23:01:23.000Z,1574290883.000 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2019-11-20T23:01:23.001Z,1574290883.001 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2019-11-20T23:01:23.001Z,1574290883.001 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2019-11-20T23:01:23.001Z,1574290883.001 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2019-11-20T23:01:23.001Z,1574290883.001 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2019-11-20T23:01:23.001Z,1574290883.001 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2019-11-20T23:01:23.002Z,1574290883.002 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2019-11-20T23:01:23.002Z,1574290883.002 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2019-11-20T23:01:23.002Z,1574290883.002 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2019-11-20T23:01:23.002Z,1574290883.002 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2019-11-20T23:01:23.002Z,1574290883.002 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2019-11-20T23:01:23.003Z,1574290883.003 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2019-11-20T23:01:23.003Z,1574290883.003 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2019-11-20T23:01:23.003Z,1574290883.003 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2019-11-20T23:01:23.003Z,1574290883.003 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2019-11-20T23:01:23.005Z,1574290883.005 [CBIT](DEBUG): Deactivating GF circuits.
2019-11-20T23:01:23.005Z,1574290883.005 [CBIT](DEBUG): Deactivating emergency mode.
2019-11-20T23:01:23.041Z,1574290883.041 [CBIT](DEBUG): Backplane powered.
2019-11-20T23:01:23.041Z,1574290883.041 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2019-11-20T23:01:23.043Z,1574290883.043 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2019-11-20T23:01:23.043Z,1574290883.043 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2019-11-20T23:01:23.044Z,1574290883.044 [LoopControl](DEBUG): Initialize LoopControlComponent.
2019-11-20T23:01:23.045Z,1574290883.045 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2019-11-20T23:01:23.055Z,1574290883.055 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2019-11-20T23:01:23.078Z,1574290883.078 [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-11-20T23:01:23.078Z,1574290883.078 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2019-11-20T23:01:23.157Z,1574290883.157 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2019-11-20T23:01:23.159Z,1574290883.159 [Default:A.Wait](DEBUG): Construct Wait.
2019-11-20T23:01:23.160Z,1574290883.160 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2019-11-20T23:01:23.199Z,1574290883.199 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2019-11-20T23:01:23.201Z,1574290883.201 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2019-11-20T23:01:23.224Z,1574290883.224 [Default:E.Execute](DEBUG): Construct Execute.
2019-11-20T23:01:23.231Z,1574290883.231 [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-11-20T23:01:23.243Z,1574290883.243 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,DDM,Depth_Keller,DropWeight,DUSBL_Hydroid,Micromodem,NAL9602,Onboard,PowerOnly,RDI_Pathfinder,BPC1,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2019-11-20T23:01:23.261Z,1574290883.261 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2019-11-20T23:01:23.294Z,1574290883.294 [DDM](INFO): Powering up
2019-11-20T23:01:23.294Z,1574290883.294 [DDM](DEBUG): Initializing DDM.
2019-11-20T23:01:23.326Z,1574290883.326 [Depth_Keller](ERROR): Pressure reading out of range: 957.962097 decibar
2019-11-20T23:01:23.326Z,1574290883.326 [DUSBL_Hydroid](INFO): Powering up
2019-11-20T23:01:23.327Z,1574290883.327 [DUSBL_Hydroid](DEBUG): Initializing DUSBL_Hydroid.
2019-11-20T23:01:23.333Z,1574290883.333 [Radio_Surface](INFO): Powering up
2019-11-20T23:01:23.533Z,1574290883.533 [DepthRateCalculator](ERROR): Depth measurement is not active
2019-11-20T23:01:23.555Z,1574290883.555 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2019-11-20T23:01:23.561Z,1574290883.561 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2019-11-20T23:01:23.562Z,1574290883.562 [ElevatorServo](DEBUG): Initializing EZServoServo.
2019-11-20T23:01:23.569Z,1574290883.569 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2019-11-20T23:01:23.570Z,1574290883.570 [MassServo](DEBUG): Initializing EZServoServo.
2019-11-20T23:01:23.577Z,1574290883.577 [MassServo](DEBUG): Initializing MassServo.
2019-11-20T23:01:23.578Z,1574290883.578 [RudderServo](DEBUG): Initializing EZServoServo.
2019-11-20T23:01:23.585Z,1574290883.585 [RudderServo](DEBUG): Initializing RudderServo.
2019-11-20T23:01:23.586Z,1574290883.586 [ThrusterServo](DEBUG): Initializing EZServoServo.
2019-11-20T23:01:23.593Z,1574290883.593 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2019-11-20T23:01:23.672Z,1574290883.672 [Micromodem](INFO): Powering up
2019-11-20T23:01:23.673Z,1574290883.673 [Micromodem](DEBUG): Initializing Micromodem.
2019-11-20T23:01:24.445Z,1574290884.445 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2019-11-20T23:01:24.445Z,1574290884.445 [RudderServo](FAULT): Rudder failed to initialize
2019-11-20T23:01:24.445Z,1574290884.445 [RudderServo] Communications Fault, FailCount= 1
2019-11-20T23:01:24.445Z,1574290884.445 [RudderServo](ERROR): Communications Fault
2019-11-20T23:01:24.556Z,1574290884.556 [CBIT](ERROR): Communications Fault in component: RudderServo
2019-11-20T23:01:24.742Z,1574290884.742 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-11-20T23:01:24.742Z,1574290884.742 [RudderServo](INFO): Powering down
2019-11-20T23:01:25.431Z,1574290885.431 [RudderServo](DEBUG): Initializing EZServoServo.
2019-11-20T23:01:25.550Z,1574290885.550 [RudderServo](DEBUG): Initializing RudderServo.
2019-11-20T23:01:25.554Z,1574290885.554 [CBIT](INFO): Clearing failed state for component RudderServo
2019-11-20T23:01:25.554Z,1574290885.554 [RudderServo] No Fault, FailCount= 1
2019-11-20T23:01:28.647Z,1574290888.647 [Micromodem](INFO): Nmea out: $CCCFG,ALL,0*33

2019-11-20T23:01:30.668Z,1574290890.668 [Micromodem](INFO): Nmea in: $CATMG,2019-11-20T23:01:29.802746Z,RTC,RTC*5C

2019-11-20T23:01:30.668Z,1574290890.668 [Micromodem](ERROR): CFG response from modem unexpected: $CATMG,2019-11-20T23:01:29.802746Z,RTC,RTC*5C

2019-11-20T23:01:31.071Z,1574290891.071 [Micromodem](INFO): Nmea in: $CACFG,ALL,0*31

2019-11-20T23:01:31.071Z,1574290891.071 [Micromodem](INFO): Nmea out: $CCCFG,SRC,1*31

2019-11-20T23:01:31.459Z,1574290891.459 [Micromodem](INFO): Nmea in: $CACFG,SRC,1*33

2019-11-20T23:01:31.459Z,1574290891.459 [Micromodem](INFO): Nmea out: $CCCFG,nav.dt.txtrig_gpio4,1*64

2019-11-20T23:01:31.891Z,1574290891.891 [Micromodem](INFO): Nmea in: $CACFG,nav.dt.txtrig_gpio4,1*66

2019-11-20T23:01:31.891Z,1574290891.891 [Micromodem](INFO): Nmea out: $CCCFG,pwramp.txlevel,0*2F

2019-11-20T23:01:32.255Z,1574290892.255 [Micromodem](INFO): Nmea in: $CACFG,pwramp.txlevel,0*2D

2019-11-20T23:01:32.255Z,1574290892.255 [Micromodem](INFO): Nmea out: $CCCFG,DTO,30*1E

2019-11-20T23:01:32.680Z,1574290892.680 [Micromodem](INFO): Nmea in: $CACFG,DTO,30*1C

2019-11-20T23:01:32.680Z,1574290892.680 [Micromodem](INFO): Nmea out: $CCCFG,FC0,10000*46

2019-11-20T23:01:33.059Z,1574290893.059 [Micromodem](INFO): Nmea in: $CACFG,FC0,10000*44

2019-11-20T23:01:33.059Z,1574290893.059 [Micromodem](INFO): Nmea out: $CCCFG,BW0,4000*63

2019-11-20T23:01:33.465Z,1574290893.465 [Micromodem](INFO): Nmea in: $CACFG,BW0,4000*61

2019-11-20T23:01:33.465Z,1574290893.465 [Micromodem](INFO): Nmea out: $CCCFG,BND,0*3A

2019-11-20T23:01:33.869Z,1574290893.869 [DDM](INFO): Dynamic Docking Module:!C REMUS Capture Rev 1.1
2019-11-20T23:01:33.971Z,1574290893.971 [Micromodem](INFO): Nmea in: $CACFG,BND,0*38

2019-11-20T23:01:33.972Z,1574290893.972 [Micromodem](INFO): Nmea out: $CCCLK,2019,11,20,23,01,34*4B

2019-11-20T23:01:34.267Z,1574290894.267 [Micromodem](INFO): Nmea in: $CACLK,2019,11,20,23,1,34*79

2019-11-20T23:01:34.665Z,1574290894.665 [DDM](INFO): Retracting whiskers, closing latch.
2019-11-20T23:01:34.677Z,1574290894.677 [DDM](FAULT): failed to deactivate IR emitter.
2019-11-20T23:01:34.677Z,1574290894.677 [DDM] Hardware Fault, FailCount= 1
2019-11-20T23:01:34.677Z,1574290894.677 [DDM](ERROR): Hardware Fault
2019-11-20T23:01:34.773Z,1574290894.773 [CBIT](ERROR): Hardware Fault in component: DDM
2019-11-20T23:01:35.069Z,1574290895.069 [DDM](INFO): Powering down
2019-11-20T23:01:35.168Z,1574290895.168 [Micromodem](INFO): Nmea in: $CATMS,0,2019-11-20T23:01:35Z*78

2019-11-20T23:01:35.199Z,1574290895.199 [Micromodem](INFO): Nmea in: $CATMG,2019-11-20T23:01:35.026089Z,USER_CMD,RTC*1A

2019-11-20T23:01:36.017Z,1574290896.017 [CBIT](INFO): Clearing failed state for component DDM
2019-11-20T23:01:36.017Z,1574290896.017 [DDM] No Fault, FailCount= 1
2019-11-20T23:01:36.717Z,1574290896.717 [RDI_Pathfinder](ERROR): Failed to parse:Pathfinder
2019-11-20T23:01:38.301Z,1574290898.301 [DDM](INFO): Powering up
2019-11-20T23:01:38.301Z,1574290898.301 [DDM](DEBUG): Initializing DDM.
2019-11-20T23:01:41.538Z,1574290901.538 [DUSBL_Hydroid](INFO): DUSBL Version:O
2019-11-20T23:01:48.805Z,1574290908.805 [DDM](INFO): Dynamic Docking Module:!C REMUS Capture Rev 1.1
2019-11-20T23:01:49.223Z,1574290909.223 [NAL9602](INFO): Powering up NAL9602
2019-11-20T23:01:49.619Z,1574290909.619 [DDM](INFO): Retracting whiskers, closing latch.
2019-11-20T23:01:57.336Z,1574290917.336 [SBIT](IMPORTANT): Beginning Startup BIT
2019-11-20T23:01:57.348Z,1574290917.348 [CBIT](IMPORTANT): Beginning ground fault scan
2019-11-20T23:02:00.239Z,1574290920.239 [NAL9602](INFO): NAL9602 initialized
2019-11-20T23:02:08.441Z,1574290928.441 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): 0.000714
CHAN A1 (24V): -0.028731
CHAN A2 (12V): -0.007233
CHAN A3 (5V): -0.002257
CHAN B0 (3.3V): -0.000199
CHAN B1 (3.15aV): -0.000067
CHAN B2 (3.15bV): 0.000072
CHAN B3 (GND): 0.002156
OPEN: 0.005261
Full Scale Calc: 4.765 mA, -1.589 mA
2019-11-20T23:02:51.069Z,1574290971.069 [SBIT](IMPORTANT): SBIT PASSED
2019-11-20T23:02:51.153Z,1574290971.153 [CommandLine](IMPORTANT): got command configSet list
2019-11-20T23:02:51.154Z,1574290971.154 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2019-11-20T23:02:51.154Z,1574290971.154 [CommandLine](IMPORTANT): DDM.loadAtStartup=1 bool;

2019-11-20T23:02:51.155Z,1574290971.155 [CommandLine](IMPORTANT): DDM.verbosity=3 count;

2019-11-20T23:02:51.155Z,1574290971.155 [CommandLine](IMPORTANT): DUSBL_Hydroid.detectionThreshold=75 count;

2019-11-20T23:02:51.155Z,1574290971.155 [CommandLine](IMPORTANT): DUSBL_Hydroid.transmitLockout=40 millisecond;

2019-11-20T23:02:51.155Z,1574290971.155 [CommandLine](IMPORTANT): Express linearApproximation DUSBL_Hydroid.acoustic_contact_range 1.000000 meter;

2019-11-20T23:02:51.155Z,1574290971.155 [CommandLine](IMPORTANT): Express linearApproximation DUSBL_Hydroid.xAngle 2.000000 degree;

2019-11-20T23:02:51.155Z,1574290971.155 [CommandLine](IMPORTANT): Express linearApproximation RDI_Pathfinder.height_above_sea_floor 2.000000 meter;

2019-11-20T23:02:51.155Z,1574290971.155 [CommandLine](IMPORTANT): Express linearApproximation platform_orientation 5.000000 degree;

2019-11-20T23:02:51.155Z,1574290971.155 [CommandLine](IMPORTANT): Express linearApproximation platform_x_velocity_wrt_ground 0.100000 meter_per_second;

2019-11-20T23:02:51.155Z,1574290971.155 [CommandLine](IMPORTANT): Express linearApproximation platform_y_velocity_wrt_ground 0.100000 meter_per_second;

2019-11-20T23:02:51.156Z,1574290971.156 [CommandLine](IMPORTANT): HorizontalControl.kiHeading=0.002 reciprocal_second;

2019-11-20T23:02:51.156Z,1574290971.156 [CommandLine](IMPORTANT): HorizontalControl.kpHeading=0.8 none;

2019-11-20T23:02:51.156Z,1574290971.156 [CommandLine](IMPORTANT): HorizontalControl.rudDeadband=0.05 degree;

2019-11-20T23:02:51.156Z,1574290971.156 [CommandLine](IMPORTANT): PowerOnly.sampleTime=90 second;

2019-11-20T23:02:51.156Z,1574290971.156 [CommandLine](IMPORTANT): RDI_Pathfinder.loadAtStartup=1 bool;

2019-11-20T23:02:51.156Z,1574290971.156 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=350 cubic_centimeter;

2019-11-20T23:02:51.156Z,1574290971.156 [CommandLine](IMPORTANT): VerticalControl.massDefault=3.6 millimeter;

2019-11-20T23:02:51.515Z,1574290971.515 [MissionManager](IMPORTANT): Started mission Startup
2019-11-20T23:02:51.515Z,1574290971.515 [Startup] Running Loop=1
2019-11-20T23:02:51.515Z,1574290971.515 [Startup](DEBUG): Aggregate::initialize Startup
2019-11-20T23:02:51.515Z,1574290971.515 [Startup:A.GoToSurface] Running Loop=1
2019-11-20T23:02:51.515Z,1574290971.515 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-11-20T23:02:51.516Z,1574290971.516 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-11-20T23:02:51.516Z,1574290971.516 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-11-20T23:02:51.516Z,1574290971.516 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-11-20T23:02:51.517Z,1574290971.517 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-11-20T23:02:51.517Z,1574290971.517 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-11-20T23:02:51.519Z,1574290971.519 [Startup:StartupSatComms] Running Loop=1
2019-11-20T23:02:51.519Z,1574290971.519 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2019-11-20T23:02:51.519Z,1574290971.519 [Startup:StartupSatComms:A] Running Loop=1
2019-11-20T23:02:51.878Z,1574290971.878 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2019-11-20T23:03:44.875Z,1574291024.875 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-11-20T23:03:51.640Z,1574291031.640 [Startup:StartupSatComms:A](INFO): Timed out from 2019-11-20T23:02:51.5Z
2019-11-20T23:03:51.657Z,1574291031.657 [Startup:StartupSatComms:A] Stopped
2019-11-20T23:03:51.657Z,1574291031.657 [Startup:StartupSatComms:B] Running Loop=1
2019-11-20T23:03:52.042Z,1574291032.042 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-11-20T23:03:52.154Z,1574291032.154 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004355
2019-11-20T23:04:00.629Z,1574291040.629 [DataOverHttps](INFO): Sending 97 bytes from file Logs/20191120T225844/Courier0000.lzma
2019-11-20T23:04:02.635Z,1574291042.635 [DataOverHttps](INFO): Moved sent file to Logs/20191120T225844/Courier0000.lzma.bak
2019-11-20T23:04:02.635Z,1574291042.635 [DataOverHttps](INFO): SBD MOMSN=12079520
2019-11-20T23:04:06.762Z,1574291046.762 [CommandLine](IMPORTANT): got command restart application
2019-11-20T23:04:07.777Z,1574291047.777 [Supervisor](INFO): Stop Mission called by Supervisor::terminate
2019-11-20T23:04:07.777Z,1574291047.777 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2019-11-20T23:04:07.777Z,1574291047.777 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-11-20T23:04:07.881Z,1574291047.881 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2019-11-20T23:04:07.881Z,1574291047.881 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-11-20T23:04:07.882Z,1574291047.882 [CommandLine](INFO): Join timeout helper Thread ID is 1118
2019-11-20T23:04:07.897Z,1574291047.897 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2019-11-20T23:04:07.897Z,1574291047.897 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-11-20T23:04:07.898Z,1574291047.898 [NavChartDb](INFO): Join timeout helper Thread ID is 1119
2019-11-20T23:04:08.201Z,1574291048.201 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2019-11-20T23:04:08.201Z,1574291048.201 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-11-20T23:04:08.217Z,1574291048.217 [ComponentRegistry](INFO): Shutting down WetLabsSeaOWL_UV_A ThreadHandler
2019-11-20T23:04:08.217Z,1574291048.217 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2019-11-20T23:04:08.217Z,1574291048.217 [WetLabsSeaOWL_UV_A](INFO): Join timeout helper Thread ID is 1120
2019-11-20T23:04:08.301Z,1574291048.301 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Uninitializing protected caller thread.
2019-11-20T23:04:08.301Z,1574291048.301 [WetLabsSeaOWL_UV_A](INFO): Powering down
2019-11-20T23:04:08.302Z,1574291048.302 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2019-11-20T23:04:08.305Z,1574291048.305 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2019-11-20T23:04:08.305Z,1574291048.305 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-11-20T23:04:08.305Z,1574291048.305 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 1121
2019-11-20T23:04:08.337Z,1574291048.337 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2019-11-20T23:04:08.337Z,1574291048.337 [CTD_NeilBrown](INFO): Powering down
2019-11-20T23:04:08.349Z,1574291048.349 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-11-20T23:04:08.367Z,1574291048.367 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2019-11-20T23:04:08.367Z,1574291048.367 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-11-20T23:04:08.368Z,1574291048.368 [Radio_Surface](INFO): Join timeout helper Thread ID is 1122
2019-11-20T23:04:08.605Z,1574291048.605 [Radio_Surface](INFO): Powering down
2019-11-20T23:04:08.606Z,1574291048.606 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2019-11-20T23:04:08.606Z,1574291048.606 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-11-20T23:04:08.610Z,1574291048.610 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2019-11-20T23:04:08.610Z,1574291048.610 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-11-20T23:04:08.610Z,1574291048.610 [DataOverHttps](INFO): Join timeout helper Thread ID is 1123
2019-11-20T23:04:10.528Z,1574291050.528 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2019-11-20T23:04:10.531Z,1574291050.531 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-11-20T23:04:10.534Z,1574291050.534 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2019-11-20T23:04:10.534Z,1574291050.534 [logger ThreadHandler](INFO): Thread cancelled.
2019-11-20T23:04:10.534Z,1574291050.534 [logger](INFO): Join timeout helper Thread ID is 1124
2019-11-20T23:04:10.549Z,1574291050.549 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2019-11-20T23:04:10.549Z,1574291050.549 [logger ThreadHandler](INFO): Thread cancelled.
2019-11-20T23:04:10.553Z,1574291050.553 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2019-11-20T23:04:10.554Z,1574291050.554 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-11-20T23:04:10.554Z,1574291050.554 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2019-11-20T23:04:10.554Z,1574291050.554 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-11-20T23:04:10.554Z,1574291050.554 [controlThread](INFO): Join timeout helper Thread ID is 1125
2019-11-20T23:04:10.593Z,1574291050.593 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2019-11-20T23:04:10.593Z,1574291050.593 [controlThread](DEBUG): Uninitializing ControlThread
2019-11-20T23:04:10.594Z,1574291050.594 [AHRS_M2](INFO): Powering down
2019-11-20T23:04:10.665Z,1574291050.665 [DDM](INFO): Powering down
2019-11-20T23:04:10.738Z,1574291050.738 [DUSBL_Hydroid](INFO): Powering down
2019-11-20T23:04:10.829Z,1574291050.829 [Micromodem](INFO): Powering down
2019-11-20T23:04:10.925Z,1574291050.925 [NAL9602](INFO): Powering down
2019-11-20T23:04:10.997Z,1574291050.997 [RDI_Pathfinder](INFO): Powering down
2019-11-20T23:04:10.999Z,1574291050.999 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2019-11-20T23:04:10.000Z,1574291051.000 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2019-11-20T23:04:11.000Z,1574291051.000 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2019-11-20T23:04:11.001Z,1574291051.001 [MissionManager](INFO): Uninitializing Mission Default
2019-11-20T23:04:11.003Z,1574291051.003 [MissionManager](INFO): Uninitializing Mission Startup
2019-11-20T23:04:11.003Z,1574291051.003 [Startup] Stopped
2019-11-20T23:04:11.003Z,1574291051.003 [Startup](DEBUG): Aggregate::uninitialize Startup
2019-11-20T23:04:11.003Z,1574291051.003 [Startup:A.GoToSurface] Stopped
2019-11-20T23:04:11.003Z,1574291051.003 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-11-20T23:04:11.003Z,1574291051.003 [Startup:StartupSatComms] Stopped
2019-11-20T23:04:11.004Z,1574291051.004 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2019-11-20T23:04:11.004Z,1574291051.004 [Startup:StartupSatComms:B] Stopped
2019-11-20T23:04:11.005Z,1574291051.005 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2019-11-20T23:04:11.005Z,1574291051.005 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2019-11-20T23:04:11.006Z,1574291051.006 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2019-11-20T23:04:11.006Z,1574291051.006 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2019-11-20T23:04:11.006Z,1574291051.006 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2019-11-20T23:04:11.006Z,1574291051.006 [BuoyancyServo](INFO): Powering down
2019-11-20T23:04:11.021Z,1574291051.021 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2019-11-20T23:04:11.021Z,1574291051.021 [ElevatorServo](INFO): Powering down
2019-11-20T23:04:11.022Z,1574291051.022 [MassServo](DEBUG): Uninitialize Mass Servo.
2019-11-20T23:04:11.022Z,1574291051.022 [MassServo](INFO): Powering down
2019-11-20T23:04:11.023Z,1574291051.023 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-11-20T23:04:11.023Z,1574291051.023 [RudderServo](INFO): Powering down
2019-11-20T23:04:11.023Z,1574291051.023 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2019-11-20T23:04:11.023Z,1574291051.023 [ThrusterServo](INFO): Powering down
2019-11-20T23:04:11.024Z,1574291051.024 [SBIT](DEBUG): Uninitialize SBIT Component.
2019-11-20T23:04:11.024Z,1574291051.024 [IBIT](DEBUG): Uninitialize IBIT Component.
2019-11-20T23:04:11.025Z,1574291051.025 [CBIT](DEBUG): Uninitialize CBIT Component.
2019-11-20T23:04:11.025Z,1574291051.025 [CBIT](DEBUG): Powering off loads.
2019-11-20T23:04:11.037Z,1574291051.037 [CBIT](DEBUG): Disabling WDT.
2019-11-20T23:04:11.049Z,1574291051.049 [CBIT](DEBUG): Opening all GF detection circuits.
2019-11-20T23:04:11.049Z,1574291051.049 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-11-20T23:04:11.092Z,1574291051.092 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-11-20T23:04:11.102Z,1574291051.102 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-11-20T23:04:11.149Z,1574291051.149 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2019-11-20T23:04:11.151Z,1574291051.151 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-11-20T23:04:11.212Z,1574291051.212 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-11-20T23:04:11.275Z,1574291051.275 [logger ThreadHandler](INFO): Thread cancelled.