2018-07-29T18:10:32.766Z,1532887832.766 [Supervisor](DEBUG): Initializing supervisor.
2018-07-29T18:10:32.769Z,1532887832.769 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2018-07-29T18:10:32.770Z,1532887832.770 [SyncHandler](INFO): Protected caller Thread ID is 5251
2018-07-29T18:10:32.771Z,1532887832.771 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2018-07-29T18:10:32.772Z,1532887832.772 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2018-07-29T18:10:32.772Z,1532887832.772 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 5252
2018-07-29T18:10:32.775Z,1532887832.775 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2018-07-29T18:10:32.788Z,1532887832.788 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2018-07-29T18:10:32.789Z,1532887832.789 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2018-07-29T18:10:32.789Z,1532887832.789 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 5253
2018-07-29T18:10:32.790Z,1532887832.790 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2018-07-29T18:10:32.791Z,1532887832.791 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2018-07-29T18:10:32.791Z,1532887832.791 [logger ThreadHandler](INFO): Protected caller Thread ID is 5254
2018-07-29T18:10:32.793Z,1532887832.793 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2018-07-29T18:10:32.794Z,1532887832.794 [Supervisor](INFO): Looking for Config files in directory: Config/
2018-07-29T18:10:32.795Z,1532887832.795 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2018-07-29T18:10:32.991Z,1532887832.991 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2018-07-29T18:10:32.992Z,1532887832.992 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2018-07-29T18:10:33.134Z,1532887833.134 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2018-07-29T18:10:33.135Z,1532887833.135 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2018-07-29T18:10:33.482Z,1532887833.482 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2018-07-29T18:10:33.483Z,1532887833.483 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2018-07-29T18:10:33.621Z,1532887833.621 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2018-07-29T18:10:33.622Z,1532887833.622 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2018-07-29T18:10:33.701Z,1532887833.701 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2018-07-29T18:10:33.904Z,1532887833.904 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2018-07-29T18:10:33.904Z,1532887833.904 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2018-07-29T18:10:34.002Z,1532887834.002 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2018-07-29T18:10:34.003Z,1532887834.003 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2018-07-29T18:10:34.344Z,1532887834.344 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2018-07-29T18:10:34.345Z,1532887834.345 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2018-07-29T18:10:34.781Z,1532887834.781 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2018-07-29T18:10:34.782Z,1532887834.782 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2018-07-29T18:10:35.089Z,1532887835.089 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2018-07-29T18:10:35.089Z,1532887835.089 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2018-07-29T18:10:35.594Z,1532887835.594 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2018-07-29T18:10:35.595Z,1532887835.595 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2018-07-29T18:10:35.802Z,1532887835.802 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2018-07-29T18:10:35.803Z,1532887835.803 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2018-07-29T18:10:35.900Z,1532887835.900 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2018-07-29T18:10:35.900Z,1532887835.900 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2018-07-29T18:10:36.387Z,1532887836.387 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2018-07-29T18:10:36.388Z,1532887836.388 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2018-07-29T18:10:36.494Z,1532887836.494 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2018-07-29T18:10:36.495Z,1532887836.495 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/
2018-07-29T18:10:36.496Z,1532887836.496 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Battery.cfg
2018-07-29T18:10:36.728Z,1532887836.728 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2018-07-29T18:10:36.728Z,1532887836.728 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/BIT.cfg
2018-07-29T18:10:36.826Z,1532887836.826 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Navigation.cfg
2018-07-29T18:10:36.919Z,1532887836.919 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Control.cfg
2018-07-29T18:10:37.022Z,1532887837.022 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Simulator.cfg
2018-07-29T18:10:37.107Z,1532887837.107 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Science.cfg
2018-07-29T18:10:37.239Z,1532887837.239 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Sensor.cfg
2018-07-29T18:10:37.405Z,1532887837.405 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Servo.cfg
2018-07-29T18:10:37.515Z,1532887837.515 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/logger.cfg
2018-07-29T18:10:37.599Z,1532887837.599 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/secure.cfg
2018-07-29T18:10:37.682Z,1532887837.682 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/vehicle.cfg
2018-07-29T18:10:37.882Z,1532887837.882 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/root/
2018-07-29T18:10:37.883Z,1532887837.883 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2018-07-29T18:10:37.895Z,1532887837.895 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2018-07-29T18:10:38.072Z,1532887838.072 [SBIT](DEBUG): Construct Startup Built In Test.
2018-07-29T18:10:38.103Z,1532887838.103 [SBIT] Loaded
2018-07-29T18:10:38.103Z,1532887838.103 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2018-07-29T18:10:38.104Z,1532887838.104 [IBIT](DEBUG): Construct Initiated Built In Test.
2018-07-29T18:10:38.132Z,1532887838.132 [IBIT] Loaded
2018-07-29T18:10:38.132Z,1532887838.132 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2018-07-29T18:10:38.135Z,1532887838.135 [CBIT](DEBUG): Construct Continuous Built In Test.
2018-07-29T18:10:38.295Z,1532887838.295 [CBIT] Loaded
2018-07-29T18:10:38.295Z,1532887838.295 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2018-07-29T18:10:38.295Z,1532887838.295 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2018-07-29T18:10:38.296Z,1532887838.296 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2018-07-29T18:10:38.365Z,1532887838.365 [VerticalControl](DEBUG): Construct VerticalControl.
2018-07-29T18:10:38.467Z,1532887838.467 [VerticalControl] Loaded
2018-07-29T18:10:38.467Z,1532887838.467 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2018-07-29T18:10:38.468Z,1532887838.468 [HorizontalControl](DEBUG): Construct HorizontalControl.
2018-07-29T18:10:38.531Z,1532887838.531 [HorizontalControl] Loaded
2018-07-29T18:10:38.531Z,1532887838.531 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2018-07-29T18:10:38.532Z,1532887838.532 [SpeedControl](DEBUG): Construct SpeedControl.
2018-07-29T18:10:38.537Z,1532887838.537 [SpeedControl] Loaded
2018-07-29T18:10:38.538Z,1532887838.538 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2018-07-29T18:10:38.538Z,1532887838.538 [LoopControl](DEBUG): Construct LoopControl.
2018-07-29T18:10:38.539Z,1532887838.539 [LoopControl] Loaded
2018-07-29T18:10:38.539Z,1532887838.539 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2018-07-29T18:10:38.540Z,1532887838.540 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2018-07-29T18:10:38.540Z,1532887838.540 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2018-07-29T18:10:38.582Z,1532887838.582 [DepthRateCalculator] Loaded
2018-07-29T18:10:38.582Z,1532887838.582 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2018-07-29T18:10:38.588Z,1532887838.588 [PitchRateCalculator] Loaded
2018-07-29T18:10:38.588Z,1532887838.588 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2018-07-29T18:10:38.605Z,1532887838.605 [SpeedCalculator] Loaded
2018-07-29T18:10:38.605Z,1532887838.605 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2018-07-29T18:10:38.626Z,1532887838.626 [TempGradientCalculator] Loaded
2018-07-29T18:10:38.627Z,1532887838.627 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2018-07-29T18:10:38.643Z,1532887838.643 [VerticalTemperatureHomogeneityIndexCalculator] Loaded
2018-07-29T18:10:38.643Z,1532887838.643 [ComponentRegistry](DEBUG): SyncComponent "VerticalTemperatureHomogeneityIndexCalculator" handled in the control thread.
2018-07-29T18:10:38.648Z,1532887838.648 [YawRateCalculator] Loaded
2018-07-29T18:10:38.649Z,1532887838.649 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2018-07-29T18:10:38.679Z,1532887838.679 [ElevatorOffsetCalculator] Loaded
2018-07-29T18:10:38.679Z,1532887838.679 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2018-07-29T18:10:38.679Z,1532887838.679 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2018-07-29T18:10:38.680Z,1532887838.680 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2018-07-29T18:10:38.764Z,1532887838.764 [StratificationFrontDetector](INFO): threshold set to: 0.399988 degC
2018-07-29T18:10:38.765Z,1532887838.765 [StratificationFrontDetector](DEBUG): (re)initializing
2018-07-29T18:10:38.765Z,1532887838.765 [StratificationFrontDetector] Loaded
2018-07-29T18:10:38.765Z,1532887838.765 [ComponentRegistry](DEBUG): SyncComponent "StratificationFrontDetector" handled in the control thread.
2018-07-29T18:10:38.766Z,1532887838.766 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2018-07-29T18:10:38.766Z,1532887838.766 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2018-07-29T18:10:39.014Z,1532887839.014 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2018-07-29T18:10:39.014Z,1532887839.014 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2018-07-29T18:10:39.112Z,1532887839.112 [DeadReckonUsingMultipleVelocitySources] Loaded
2018-07-29T18:10:39.112Z,1532887839.112 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2018-07-29T18:10:39.168Z,1532887839.168 [DeadReckonUsingSpeedCalculator] Loaded
2018-07-29T18:10:39.168Z,1532887839.168 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2018-07-29T18:10:39.185Z,1532887839.185 [NavChart] Loaded
2018-07-29T18:10:39.186Z,1532887839.186 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2018-07-29T18:10:39.190Z,1532887839.190 [UniversalFixResidualReporter] Loaded
2018-07-29T18:10:39.190Z,1532887839.190 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2018-07-29T18:10:39.190Z,1532887839.190 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2018-07-29T18:10:39.191Z,1532887839.191 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2018-07-29T18:10:39.204Z,1532887839.204 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2018-07-29T18:10:39.205Z,1532887839.205 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2018-07-29T18:10:39.360Z,1532887839.360 [Aanderaa_O2] Loaded
2018-07-29T18:10:39.361Z,1532887839.361 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2018-07-29T18:10:39.412Z,1532887839.412 [WetLabsBB2FL] Loaded
2018-07-29T18:10:39.412Z,1532887839.412 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2018-07-29T18:10:39.413Z,1532887839.413 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 406D24E0
2018-07-29T18:10:39.414Z,1532887839.414 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 5333
2018-07-29T18:10:39.414Z,1532887839.414 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2018-07-29T18:10:39.415Z,1532887839.415 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2018-07-29T18:10:39.703Z,1532887839.703 [AHRS_M2] Loaded
2018-07-29T18:10:39.703Z,1532887839.703 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2018-07-29T18:10:39.775Z,1532887839.775 [DataOverHttps] Loaded
2018-07-29T18:10:39.775Z,1532887839.775 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2018-07-29T18:10:39.789Z,1532887839.789 [Depth_Keller] Loaded
2018-07-29T18:10:39.789Z,1532887839.789 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2018-07-29T18:10:39.794Z,1532887839.794 [DropWeight] Loaded
2018-07-29T18:10:39.795Z,1532887839.795 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2018-07-29T18:10:39.887Z,1532887839.887 [NAL9602] Loaded
2018-07-29T18:10:39.887Z,1532887839.887 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2018-07-29T18:10:39.892Z,1532887839.892 [Onboard] Loaded
2018-07-29T18:10:39.893Z,1532887839.893 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2018-07-29T18:10:39.900Z,1532887839.900 [Radio_Surface] Loaded
2018-07-29T18:10:39.900Z,1532887839.900 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2018-07-29T18:10:39.901Z,1532887839.901 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409284E0
2018-07-29T18:10:39.902Z,1532887839.902 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 5334
2018-07-29T18:10:39.931Z,1532887839.931 [RDI_Pathfinder] Loaded
2018-07-29T18:10:39.931Z,1532887839.931 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2018-07-29T18:10:39.938Z,1532887839.938 [SCPI] Loaded
2018-07-29T18:10:39.938Z,1532887839.938 [ComponentRegistry](DEBUG): SyncComponent "SCPI" handled in the control thread.
2018-07-29T18:10:41.772Z,1532887841.772 [BPC1] Loaded
2018-07-29T18:10:41.773Z,1532887841.773 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2018-07-29T18:10:41.773Z,1532887841.773 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2018-07-29T18:10:41.774Z,1532887841.774 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2018-07-29T18:10:41.874Z,1532887841.874 [BuoyancyServo] Loaded
2018-07-29T18:10:41.874Z,1532887841.874 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2018-07-29T18:10:41.886Z,1532887841.886 [ElevatorServo] Loaded
2018-07-29T18:10:41.887Z,1532887841.887 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2018-07-29T18:10:41.898Z,1532887841.898 [MassServo] Loaded
2018-07-29T18:10:41.898Z,1532887841.898 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2018-07-29T18:10:41.910Z,1532887841.910 [RudderServo] Loaded
2018-07-29T18:10:41.910Z,1532887841.910 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2018-07-29T18:10:41.921Z,1532887841.921 [ThrusterServo] Loaded
2018-07-29T18:10:41.921Z,1532887841.921 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2018-07-29T18:10:41.922Z,1532887841.922 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2018-07-29T18:10:41.922Z,1532887841.922 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2018-07-29T18:10:42.025Z,1532887842.025 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2018-07-29T18:10:42.026Z,1532887842.026 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2018-07-29T18:10:42.050Z,1532887842.050 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2018-07-29T18:10:42.054Z,1532887842.054 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2018-07-29T18:10:42.055Z,1532887842.055 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2018-07-29T18:10:42.062Z,1532887842.062 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2018-07-29T18:10:42.063Z,1532887842.063 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 409D14E0
2018-07-29T18:10:42.063Z,1532887842.063 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 5335
2018-07-29T18:10:42.068Z,1532887842.068 [Supervisor](INFO): Main Thread ID is 5114
2018-07-29T18:10:42.068Z,1532887842.068 [Supervisor](DEBUG): Running supervisor.
2018-07-29T18:10:42.069Z,1532887842.069 [CommandLine ThreadHandler](INFO): Handler Thread ID is 5336
2018-07-29T18:10:42.071Z,1532887842.071 [controlThread ThreadHandler](INFO): Handler Thread ID is 5337
2018-07-29T18:10:42.071Z,1532887842.071 [controlThread](DEBUG): Initializing ControlThread
2018-07-29T18:10:42.072Z,1532887842.072 [SBIT](INFO): Initialize SBIT Component.
2018-07-29T18:10:42.073Z,1532887842.073 [SBIT](IMPORTANT): git: 2018-07-27
2018-07-29T18:10:42.073Z,1532887842.073 [SBIT](INFO): git hash: 70248c5183d51ba6f068484fc78a5bddbcaafe8c
2018-07-29T18:10:42.074Z,1532887842.074 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2018-07-29T18:10:42.075Z,1532887842.075 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #639 PREEMPT Wed Mar 12 12:53:33 PDT 2014
Kernel Reported: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
2018-07-29T18:10:42.076Z,1532887842.076 [SBIT](INFO): Beginning SBIT in 39.000000 seconds.
2018-07-29T18:10:42.077Z,1532887842.077 [IBIT](INFO): Initialize IBIT Component.
2018-07-29T18:10:42.078Z,1532887842.078 [CBIT](DEBUG): Initialize CBIT Component.
2018-07-29T18:10:42.078Z,1532887842.078 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2018-07-29T18:10:42.079Z,1532887842.079 [logger ThreadHandler](INFO): Handler Thread ID is 5338
2018-07-29T18:10:42.105Z,1532887842.105 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 5339
2018-07-29T18:10:42.125Z,1532887842.125 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 5340
2018-07-29T18:10:42.131Z,1532887842.131 [Radio_Surface](INFO): Powering up
2018-07-29T18:10:42.150Z,1532887842.150 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 5341
2018-07-29T18:10:42.153Z,1532887842.153 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2018-07-29T18:10:42.153Z,1532887842.153 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2018-07-29T18:10:42.153Z,1532887842.153 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2018-07-29T18:10:42.153Z,1532887842.153 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2018-07-29T18:10:42.154Z,1532887842.154 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2018-07-29T18:10:42.154Z,1532887842.154 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2018-07-29T18:10:42.154Z,1532887842.154 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2018-07-29T18:10:42.154Z,1532887842.154 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2018-07-29T18:10:42.154Z,1532887842.154 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2018-07-29T18:10:42.155Z,1532887842.155 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2018-07-29T18:10:42.155Z,1532887842.155 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2018-07-29T18:10:42.155Z,1532887842.155 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2018-07-29T18:10:42.155Z,1532887842.155 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2018-07-29T18:10:42.155Z,1532887842.155 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2018-07-29T18:10:42.156Z,1532887842.156 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2018-07-29T18:10:42.156Z,1532887842.156 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2018-07-29T18:10:42.185Z,1532887842.185 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2018-07-29T18:10:42.187Z,1532887842.187 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2018-07-29T18:10:42.187Z,1532887842.187 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2018-07-29T18:10:42.188Z,1532887842.188 [LoopControl](DEBUG): Initialize LoopControlComponent.
2018-07-29T18:10:42.188Z,1532887842.188 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2018-07-29T18:10:42.189Z,1532887842.189 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2018-07-29T18:10:42.189Z,1532887842.189 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2018-07-29T18:10:42.189Z,1532887842.189 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2018-07-29T18:10:42.190Z,1532887842.190 [VerticalTemperatureHomogeneityIndexCalculator](DEBUG): (re)initializing
2018-07-29T18:10:42.191Z,1532887842.191 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2018-07-29T18:10:42.191Z,1532887842.191 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2018-07-29T18:10:42.192Z,1532887842.192 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2018-07-29T18:10:42.193Z,1532887842.193 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s.
2018-07-29T18:10:42.193Z,1532887842.193 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s.
2018-07-29T18:10:42.194Z,1532887842.194 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-07-29T18:10:42.194Z,1532887842.194 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-07-29T18:10:42.194Z,1532887842.194 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-07-29T18:10:42.195Z,1532887842.195 [NavChart](DEBUG): Initialize NavChart Navigation.
2018-07-29T18:10:42.195Z,1532887842.195 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2018-07-29T18:10:42.202Z,1532887842.202 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2018-07-29T18:10:42.238Z,1532887842.238 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2018-07-29T18:10:42.285Z,1532887842.285 [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>


2018-07-29T18:10:42.286Z,1532887842.286 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2018-07-29T18:10:42.367Z,1532887842.367 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2018-07-29T18:10:42.368Z,1532887842.368 [Default:A.Wait](DEBUG): Construct Wait.
2018-07-29T18:10:42.386Z,1532887842.386 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2018-07-29T18:10:42.418Z,1532887842.418 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2018-07-29T18:10:42.420Z,1532887842.420 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2018-07-29T18:10:42.450Z,1532887842.450 [Default:E.Execute](DEBUG): Construct Execute.
2018-07-29T18:10:42.470Z,1532887842.470 [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 300</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>


2018-07-29T18:10:42.475Z,1532887842.475 [controlThread](DEBUG): Component order: CycleStarter,Aanderaa_O2,AHRS_M2,DataOverHttps,Depth_Keller,DropWeight,NAL9602,Onboard,RDI_Pathfinder,SCPI,BPC1,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,VerticalTemperatureHomogeneityIndexCalculator,YawRateCalculator,ElevatorOffsetCalculator,StratificationFrontDetector,DeadReckonUsingMultipleVelocitySources,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2018-07-29T18:10:42.548Z,1532887842.548 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2018-07-29T18:10:42.590Z,1532887842.590 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2018-07-29T18:10:42.615Z,1532887842.615 [Depth_Keller](ERROR): Pressure reading out of range: 1913.424561 decibar
2018-07-29T18:10:42.866Z,1532887842.866 [DepthRateCalculator](ERROR): Depth measurement is not active
2018-07-29T18:10:43.005Z,1532887843.005 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-07-29T18:10:43.026Z,1532887843.026 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-07-29T18:10:43.169Z,1532887843.169 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2018-07-29T18:10:43.177Z,1532887843.177 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2018-07-29T18:10:43.191Z,1532887843.191 [ElevatorServo](DEBUG): Initializing EZServoServo.
2018-07-29T18:10:43.197Z,1532887843.197 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2018-07-29T18:10:43.211Z,1532887843.211 [MassServo](DEBUG): Initializing EZServoServo.
2018-07-29T18:10:43.217Z,1532887843.217 [MassServo](DEBUG): Initializing MassServo.
2018-07-29T18:10:43.241Z,1532887843.241 [RudderServo](DEBUG): Initializing EZServoServo.
2018-07-29T18:10:43.253Z,1532887843.253 [RudderServo](DEBUG): Initializing RudderServo.
2018-07-29T18:10:43.281Z,1532887843.281 [ThrusterServo](DEBUG): Initializing EZServoServo.
2018-07-29T18:10:43.289Z,1532887843.289 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2018-07-29T18:10:43.494Z,1532887843.494 [DropWeight](CRITICAL): DROP WEIGHT MISSING.

2018-07-29T18:10:43.494Z,1532887843.494 [DropWeight] Hardware Fault, FailCount= 1
2018-07-29T18:10:43.494Z,1532887843.494 [DropWeight](ERROR): Hardware Fault
2018-07-29T18:10:43.541Z,1532887843.541 [DepthRateCalculator](ERROR): Depth measurement is not active
2018-07-29T18:10:43.561Z,1532887843.561 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-07-29T18:10:43.562Z,1532887843.562 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-07-29T18:10:43.588Z,1532887843.588 [CommandLine](FAULT): Scheduling is paused
2018-07-29T18:10:43.589Z,1532887843.589 [CBIT](INFO): Critical error at 20180729T181043
2018-07-29T18:10:43.589Z,1532887843.589 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2018-07-29T18:10:43.591Z,1532887843.591 [CBIT](ERROR): Hardware Fault in component: DropWeight
2018-07-29T18:10:43.592Z,1532887843.592 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2018-07-29T18:10:43.841Z,1532887843.841 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-07-29T18:10:43.842Z,1532887843.842 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-07-29T18:10:44.165Z,1532887844.165 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout
2018-07-29T18:10:44.165Z,1532887844.165 [BuoyancyServo](FAULT): Buoyancy failed to initialize
2018-07-29T18:10:44.165Z,1532887844.165 [BuoyancyServo] Communications Fault, FailCount= 1
2018-07-29T18:10:44.165Z,1532887844.165 [BuoyancyServo](ERROR): Communications Fault
2018-07-29T18:10:44.375Z,1532887844.375 [CBIT](INFO): Critical error at 20180729T181043
2018-07-29T18:10:44.377Z,1532887844.377 [CBIT](ERROR): Communications Fault in component: BuoyancyServo
2018-07-29T18:10:44.433Z,1532887844.433 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-07-29T18:10:44.435Z,1532887844.435 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-07-29T18:10:44.443Z,1532887844.443 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2018-07-29T18:10:44.444Z,1532887844.444 [BuoyancyServo](INFO): Powering down
2018-07-29T18:10:44.817Z,1532887844.817 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-07-29T18:10:44.818Z,1532887844.818 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-07-29T18:10:45.213Z,1532887845.213 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-07-29T18:10:45.214Z,1532887845.214 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-07-29T18:10:45.705Z,1532887845.705 [Aanderaa_O2](INFO): Powering down
2018-07-29T18:10:45.841Z,1532887845.841 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-07-29T18:10:45.842Z,1532887845.842 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-07-29T18:10:46.094Z,1532887846.094 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-07-29T18:10:46.096Z,1532887846.096 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-07-29T18:10:46.441Z,1532887846.441 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-07-29T18:10:46.442Z,1532887846.442 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-07-29T18:10:46.494Z,1532887846.494 [CBIT](INFO): Clearing failed state for component BuoyancyServo
2018-07-29T18:10:46.494Z,1532887846.494 [BuoyancyServo] No Fault, FailCount= 1
2018-07-29T18:10:46.841Z,1532887846.841 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-07-29T18:10:46.842Z,1532887846.842 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-07-29T18:10:46.855Z,1532887846.855 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2018-07-29T18:10:46.974Z,1532887846.974 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2018-07-29T18:10:47.281Z,1532887847.281 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-07-29T18:10:47.283Z,1532887847.283 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-07-29T18:10:47.679Z,1532887847.679 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-07-29T18:10:47.680Z,1532887847.680 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-07-29T18:10:48.098Z,1532887848.098 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-07-29T18:10:48.099Z,1532887848.099 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-07-29T18:10:48.478Z,1532887848.478 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-07-29T18:10:48.479Z,1532887848.479 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-07-29T18:10:48.850Z,1532887848.850 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-07-29T18:10:48.851Z,1532887848.851 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-07-29T18:10:49.250Z,1532887849.250 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-07-29T18:10:49.251Z,1532887849.251 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-07-29T18:10:49.679Z,1532887849.679 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-07-29T18:10:49.680Z,1532887849.680 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-07-29T18:10:56.449Z,1532887856.449 [RDI_Pathfinder](ERROR): Failed to parse:Pathfinder
2018-07-29T18:11:10.043Z,1532887870.043 [NAL9602](INFO): Powering up NAL9602
2018-07-29T18:11:21.230Z,1532887881.230 [NAL9602](INFO): NAL9602 initialized
2018-07-29T18:11:21.745Z,1532887881.745 [SBIT](IMPORTANT): Beginning Startup BIT
2018-07-29T18:11:21.759Z,1532887881.759 [CBIT](IMPORTANT): Beginning ground fault scan
2018-07-29T18:11:32.726Z,1532887892.726 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.009304
CHAN A1 (24V): -0.013697
CHAN A2 (12V): -0.007315
CHAN A3 (5V): -0.002396
CHAN B0 (3.3V): 0.000553
CHAN B1 (3.15aV): -0.000142
CHAN B2 (3.15bV): -0.000058
CHAN B3 (GND): 0.002316
OPEN: 0.004605
Full Scale Calc: 4.765 mA, -1.589 mA
2018-07-29T18:11:36.660Z,1532887896.660 [CommandLine](IMPORTANT): got command configSet AHRS_M2.verbosity 2.000000 count
2018-07-29T18:11:36.980Z,1532887896.980 [AHRS_M2](INFO): CRC match. PITCH: -2.262855 deg, ROLL: -1.725913 deg, YAW: 316.234644 deg, TEMP: 27.512239 C.
2018-07-29T18:11:37.590Z,1532887897.590 [AHRS_M2](INFO): CRC match. PITCH: -2.257979 deg, ROLL: -1.728944 deg, YAW: 316.240108 deg, TEMP: 27.487761 C.
2018-07-29T18:11:37.990Z,1532887897.990 [AHRS_M2](INFO): CRC match. PITCH: -2.251875 deg, ROLL: -1.732475 deg, YAW: 316.239261 deg, TEMP: 27.506121 C.
2018-07-29T18:11:38.390Z,1532887898.390 [AHRS_M2](INFO): CRC match. PITCH: -2.254870 deg, ROLL: -1.732407 deg, YAW: 316.233141 deg, TEMP: 27.506121 C.
2018-07-29T18:11:38.790Z,1532887898.790 [AHRS_M2](INFO): CRC match. PITCH: -2.259304 deg, ROLL: -1.734160 deg, YAW: 316.222951 deg, TEMP: 27.484699 C.
2018-07-29T18:11:39.191Z,1532887899.191 [AHRS_M2](INFO): CRC match. PITCH: -2.258233 deg, ROLL: -1.735786 deg, YAW: 316.220328 deg, TEMP: 27.484699 C.
2018-07-29T18:11:39.224Z,1532887899.224 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude
2018-07-29T18:11:39.225Z,1532887899.225 [RDI_Pathfinder](ERROR): Failed to parse:
:BD,  , 65.535
2018-07-29T18:11:39.590Z,1532887899.590 [AHRS_M2](INFO): CRC match. PITCH: -2.261181 deg, ROLL: -1.727153 deg, YAW: 316.233660 deg, TEMP: 27.503059 C.
2018-07-29T18:11:39.990Z,1532887899.990 [AHRS_M2](INFO): CRC match. PITCH: -2.261963 deg, ROLL: -1.733437 deg, YAW: 316.222076 deg, TEMP: 27.509180 C.
2018-07-29T18:11:40.390Z,1532887900.390 [AHRS_M2](INFO): CRC match. PITCH: -2.260009 deg, ROLL: -1.728035 deg, YAW: 316.237048 deg, TEMP: 27.512239 C.
2018-07-29T18:11:40.790Z,1532887900.790 [AHRS_M2](INFO): CRC match. PITCH: -2.265320 deg, ROLL: -1.728734 deg, YAW: 316.228032 deg, TEMP: 27.503059 C.
2018-07-29T18:11:41.192Z,1532887901.192 [AHRS_M2](INFO): CRC match. PITCH: -2.262542 deg, ROLL: -1.729993 deg, YAW: 316.229999 deg, TEMP: 27.503059 C.
2018-07-29T18:11:41.589Z,1532887901.589 [AHRS_M2](INFO): CRC match. PITCH: -2.263535 deg, ROLL: -1.728755 deg, YAW: 316.227295 deg, TEMP: 27.506121 C.
2018-07-29T18:11:41.989Z,1532887901.989 [AHRS_M2](INFO): CRC match. PITCH: -2.258197 deg, ROLL: -1.729272 deg, YAW: 316.239179 deg, TEMP: 27.490820 C.
2018-07-29T18:11:42.388Z,1532887902.388 [AHRS_M2](INFO): CRC match. PITCH: -2.253780 deg, ROLL: -1.730048 deg, YAW: 316.246173 deg, TEMP: 27.509180 C.
2018-07-29T18:11:42.788Z,1532887902.788 [AHRS_M2](INFO): CRC match. PITCH: -2.257122 deg, ROLL: -1.726797 deg, YAW: 316.238360 deg, TEMP: 27.506121 C.
2018-07-29T18:11:43.188Z,1532887903.188 [AHRS_M2](INFO): CRC match. PITCH: -2.256988 deg, ROLL: -1.730625 deg, YAW: 316.233469 deg, TEMP: 27.506121 C.
2018-07-29T18:11:43.588Z,1532887903.588 [AHRS_M2](INFO): CRC match. PITCH: -2.263599 deg, ROLL: -1.737134 deg, YAW: 316.213634 deg, TEMP: 27.503059 C.
2018-07-29T18:11:43.989Z,1532887903.989 [AHRS_M2](INFO): CRC match. PITCH: -2.263200 deg, ROLL: -1.736823 deg, YAW: 316.215465 deg, TEMP: 27.490820 C.
2018-07-29T18:11:44.388Z,1532887904.388 [AHRS_M2](INFO): CRC match. PITCH: -2.261544 deg, ROLL: -1.731853 deg, YAW: 316.228169 deg, TEMP: 27.509180 C.
2018-07-29T18:11:44.788Z,1532887904.788 [AHRS_M2](INFO): CRC match. PITCH: -2.260100 deg, ROLL: -1.736600 deg, YAW: 316.227076 deg, TEMP: 27.503059 C.
2018-07-29T18:11:45.188Z,1532887905.188 [AHRS_M2](INFO): CRC match. PITCH: -2.262811 deg, ROLL: -1.738956 deg, YAW: 316.214345 deg, TEMP: 27.509180 C.
2018-07-29T18:11:45.588Z,1532887905.588 [AHRS_M2](INFO): CRC match. PITCH: -2.257799 deg, ROLL: -1.732228 deg, YAW: 316.234945 deg, TEMP: 27.509180 C.
2018-07-29T18:11:45.988Z,1532887905.988 [AHRS_M2](INFO): CRC match. PITCH: -2.254836 deg, ROLL: -1.731815 deg, YAW: 316.239452 deg, TEMP: 27.512239 C.
2018-07-29T18:11:46.388Z,1532887906.388 [AHRS_M2](INFO): CRC match. PITCH: -2.263431 deg, ROLL: -1.735318 deg, YAW: 316.220164 deg, TEMP: 27.524479 C.
2018-07-29T18:11:46.712Z,1532887906.712 [CommandLine](IMPORTANT): got command configSet AHRS_M2.verbosity 0.000000 count
2018-07-29T18:12:15.784Z,1532887935.784 [SBIT](IMPORTANT): SBIT PASSED
2018-07-29T18:12:15.833Z,1532887935.833 [CommandLine](IMPORTANT): got command configSet list
2018-07-29T18:12:15.833Z,1532887935.833 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2018-07-29T18:12:15.834Z,1532887935.834 [CommandLine](IMPORTANT): AHRS_M2.readAccelerations=0 bool;

2018-07-29T18:12:15.834Z,1532887935.834 [CommandLine](IMPORTANT): AHRS_M2.readMagnetics=0 bool;

2018-07-29T18:12:15.834Z,1532887935.834 [CommandLine](IMPORTANT): Express linearApproximation height_above_sea_floor 5.000000 meter;

2018-07-29T18:12:15.835Z,1532887935.835 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=160 cubic_centimeter;

2018-07-29T18:12:15.835Z,1532887935.835 [CommandLine](IMPORTANT): VerticalControl.massDefault=-5 millimeter;

2018-07-29T18:12:16.195Z,1532887936.195 [MissionManager](IMPORTANT): Started mission Startup
2018-07-29T18:12:16.195Z,1532887936.195 [Startup] Running Loop=1
2018-07-29T18:12:16.195Z,1532887936.195 [Startup](DEBUG): Aggregate::initialize Startup
2018-07-29T18:12:16.195Z,1532887936.195 [Startup:A.GoToSurface] Running Loop=1
2018-07-29T18:12:16.195Z,1532887936.195 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-07-29T18:12:16.196Z,1532887936.196 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2018-07-29T18:12:16.196Z,1532887936.196 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2018-07-29T18:12:16.197Z,1532887936.197 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2018-07-29T18:12:16.197Z,1532887936.197 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-07-29T18:12:16.198Z,1532887936.198 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2018-07-29T18:12:16.204Z,1532887936.204 [Startup:StartupSatComms] Running Loop=1
2018-07-29T18:12:16.204Z,1532887936.204 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2018-07-29T18:12:16.204Z,1532887936.204 [Startup:StartupSatComms:A] Running Loop=1
2018-07-29T18:12:16.569Z,1532887936.569 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2018-07-29T18:12:41.199Z,1532887961.199 [CommandLine](IMPORTANT): got command configSet AHRS_M2.readMagnetics 1.000000 bool persist
2018-07-29T18:12:41.199Z,1532887961.199 [CommandLine](IMPORTANT): configSet AHRS_M2.readMagnetics requires a restart to take effect.
2018-07-29T18:12:46.390Z,1532887966.390 [CommandLine](IMPORTANT): got command restart application
2018-07-29T18:12:47.400Z,1532887967.400 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2018-07-29T18:12:47.400Z,1532887967.400 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-07-29T18:12:47.561Z,1532887967.561 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2018-07-29T18:12:47.561Z,1532887967.561 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-07-29T18:12:47.562Z,1532887967.562 [CommandLine](INFO): Join timeout helper Thread ID is 5359
2018-07-29T18:12:47.562Z,1532887967.562 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2018-07-29T18:12:47.562Z,1532887967.562 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-07-29T18:12:47.563Z,1532887967.563 [NavChartDb](INFO): Join timeout helper Thread ID is 5360
2018-07-29T18:12:47.897Z,1532887967.897 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2018-07-29T18:12:47.899Z,1532887967.899 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-07-29T18:12:47.901Z,1532887967.901 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2018-07-29T18:12:47.901Z,1532887967.901 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-07-29T18:12:47.901Z,1532887967.901 [Radio_Surface](INFO): Join timeout helper Thread ID is 5361
2018-07-29T18:12:47.909Z,1532887967.909 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2018-07-29T18:12:47.909Z,1532887967.909 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-07-29T18:12:47.925Z,1532887967.925 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2018-07-29T18:12:47.925Z,1532887967.925 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-07-29T18:12:47.925Z,1532887967.925 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 5362
2018-07-29T18:12:48.061Z,1532887968.061 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2018-07-29T18:12:48.061Z,1532887968.061 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-07-29T18:12:48.077Z,1532887968.077 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2018-07-29T18:12:48.077Z,1532887968.077 [logger ThreadHandler](INFO): Thread cancelled.
2018-07-29T18:12:48.078Z,1532887968.078 [logger](INFO): Join timeout helper Thread ID is 5363
2018-07-29T18:12:48.085Z,1532887968.085 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2018-07-29T18:12:48.086Z,1532887968.086 [logger ThreadHandler](INFO): Thread cancelled.
2018-07-29T18:12:48.099Z,1532887968.099 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2018-07-29T18:12:48.099Z,1532887968.099 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-07-29T18:12:48.099Z,1532887968.099 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2018-07-29T18:12:48.099Z,1532887968.099 [controlThread ThreadHandler](INFO): Thread cancelled.
2018-07-29T18:12:48.100Z,1532887968.100 [controlThread](INFO): Join timeout helper Thread ID is 5364
2018-07-29T18:12:48.101Z,1532887968.101 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2018-07-29T18:12:48.102Z,1532887968.102 [controlThread](DEBUG): Uninitializing ControlThread
2018-07-29T18:12:48.103Z,1532887968.103 [Aanderaa_O2](INFO): Powering down
2018-07-29T18:12:48.105Z,1532887968.105 [AHRS_M2](INFO): Powering down
2018-07-29T18:12:48.178Z,1532887968.178 [NAL9602](INFO): Powering down
2018-07-29T18:12:48.249Z,1532887968.249 [RDI_Pathfinder](INFO): Powering down
2018-07-29T18:12:48.251Z,1532887968.251 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2018-07-29T18:12:48.252Z,1532887968.252 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2018-07-29T18:12:48.253Z,1532887968.253 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2018-07-29T18:12:48.254Z,1532887968.254 [MissionManager](INFO): Uninitializing Mission Default
2018-07-29T18:12:48.256Z,1532887968.256 [MissionManager](INFO): Uninitializing Mission Startup
2018-07-29T18:12:48.256Z,1532887968.256 [Startup] Stopped
2018-07-29T18:12:48.257Z,1532887968.257 [Startup](DEBUG): Aggregate::uninitialize Startup
2018-07-29T18:12:48.257Z,1532887968.257 [Startup:A.GoToSurface] Stopped
2018-07-29T18:12:48.257Z,1532887968.257 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2018-07-29T18:12:48.257Z,1532887968.257 [Startup:StartupSatComms] Stopped
2018-07-29T18:12:48.257Z,1532887968.257 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2018-07-29T18:12:48.257Z,1532887968.257 [Startup:StartupSatComms:A] Stopped
2018-07-29T18:12:48.259Z,1532887968.259 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2018-07-29T18:12:48.259Z,1532887968.259 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2018-07-29T18:12:48.259Z,1532887968.259 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2018-07-29T18:12:48.260Z,1532887968.260 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2018-07-29T18:12:48.260Z,1532887968.260 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2018-07-29T18:12:48.260Z,1532887968.260 [BuoyancyServo](INFO): Powering down
2018-07-29T18:12:48.273Z,1532887968.273 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2018-07-29T18:12:48.273Z,1532887968.273 [ElevatorServo](INFO): Powering down
2018-07-29T18:12:48.274Z,1532887968.274 [MassServo](DEBUG): Uninitialize Mass Servo.
2018-07-29T18:12:48.274Z,1532887968.274 [MassServo](INFO): Powering down
2018-07-29T18:12:48.275Z,1532887968.275 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2018-07-29T18:12:48.275Z,1532887968.275 [RudderServo](INFO): Powering down
2018-07-29T18:12:48.276Z,1532887968.276 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2018-07-29T18:12:48.276Z,1532887968.276 [ThrusterServo](INFO): Powering down
2018-07-29T18:12:48.277Z,1532887968.277 [SBIT](DEBUG): Uninitialize SBIT Component.
2018-07-29T18:12:48.277Z,1532887968.277 [IBIT](DEBUG): Uninitialize IBIT Component.
2018-07-29T18:12:48.278Z,1532887968.278 [CBIT](DEBUG): Uninitialize CBIT Component.
2018-07-29T18:12:48.279Z,1532887968.279 [controlThread ThreadHandler](INFO): Thread cancelled.
2018-07-29T18:12:48.329Z,1532887968.329 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-07-29T18:12:48.387Z,1532887968.387 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-07-29T18:12:48.428Z,1532887968.428 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-07-29T18:12:48.483Z,1532887968.483 [logger ThreadHandler](INFO): Thread cancelled.