2018-11-05T23:47:57.742Z,1541461677.742 [Supervisor](DEBUG): Initializing supervisor.
2018-11-05T23:47:57.745Z,1541461677.745 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2018-11-05T23:47:57.746Z,1541461677.746 [SyncHandler](INFO): Protected caller Thread ID is 797
2018-11-05T23:47:57.746Z,1541461677.746 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2018-11-05T23:47:57.747Z,1541461677.747 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2018-11-05T23:47:57.747Z,1541461677.747 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 798
2018-11-05T23:47:57.750Z,1541461677.750 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2018-11-05T23:47:57.762Z,1541461677.762 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2018-11-05T23:47:57.763Z,1541461677.763 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2018-11-05T23:47:57.763Z,1541461677.763 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 799
2018-11-05T23:47:57.764Z,1541461677.764 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2018-11-05T23:47:57.765Z,1541461677.765 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2018-11-05T23:47:57.766Z,1541461677.766 [logger ThreadHandler](INFO): Protected caller Thread ID is 800
2018-11-05T23:47:57.767Z,1541461677.767 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2018-11-05T23:47:57.768Z,1541461677.768 [Supervisor](INFO): Looking for Config files in directory: Config/
2018-11-05T23:47:57.772Z,1541461677.772 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2018-11-05T23:47:58.102Z,1541461678.102 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2018-11-05T23:47:58.102Z,1541461678.102 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2018-11-05T23:47:58.301Z,1541461678.301 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2018-11-05T23:47:58.302Z,1541461678.302 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2018-11-05T23:47:58.601Z,1541461678.601 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2018-11-05T23:47:58.601Z,1541461678.601 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2018-11-05T23:47:58.748Z,1541461678.748 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2018-11-05T23:47:58.748Z,1541461678.748 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2018-11-05T23:47:58.849Z,1541461678.849 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2018-11-05T23:47:58.851Z,1541461678.851 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2018-11-05T23:47:59.400Z,1541461679.400 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2018-11-05T23:47:59.401Z,1541461679.401 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2018-11-05T23:47:59.864Z,1541461679.864 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2018-11-05T23:47:59.866Z,1541461679.866 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2018-11-05T23:48:00.331Z,1541461680.331 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2018-11-05T23:48:00.333Z,1541461680.333 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2018-11-05T23:48:00.438Z,1541461680.438 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2018-11-05T23:48:00.439Z,1541461680.439 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2018-11-05T23:48:00.537Z,1541461680.537 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2018-11-05T23:48:00.537Z,1541461680.537 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2018-11-05T23:48:00.755Z,1541461680.755 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2018-11-05T23:48:00.756Z,1541461680.756 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2018-11-05T23:48:00.960Z,1541461680.960 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2018-11-05T23:48:00.961Z,1541461680.961 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2018-11-05T23:48:01.311Z,1541461681.311 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2018-11-05T23:48:01.312Z,1541461681.312 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2018-11-05T23:48:01.468Z,1541461681.468 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2018-11-05T23:48:01.810Z,1541461681.810 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2018-11-05T23:48:02.007Z,1541461682.007 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2018-11-05T23:48:02.009Z,1541461682.009 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2018-11-05T23:48:02.113Z,1541461682.113 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2018-11-05T23:48:02.232Z,1541461682.232 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2018-11-05T23:48:02.328Z,1541461682.328 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2018-11-05T23:48:02.413Z,1541461682.413 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2018-11-05T23:48:02.578Z,1541461682.578 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2018-11-05T23:48:02.758Z,1541461682.758 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2018-11-05T23:48:02.835Z,1541461682.835 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg
2018-11-05T23:48:03.064Z,1541461683.064 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2018-11-05T23:48:03.065Z,1541461683.065 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2018-11-05T23:48:03.149Z,1541461683.149 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2018-11-05T23:48:03.242Z,1541461683.242 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2018-11-05T23:48:03.344Z,1541461683.344 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2018-11-05T23:48:03.472Z,1541461683.472 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/root/
2018-11-05T23:48:03.473Z,1541461683.473 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2018-11-05T23:48:03.487Z,1541461683.487 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2018-11-05T23:48:03.773Z,1541461683.773 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2018-11-05T23:48:03.775Z,1541461683.775 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2018-11-05T23:48:03.832Z,1541461683.832 [DepthRateCalculator] Loaded
2018-11-05T23:48:03.832Z,1541461683.832 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2018-11-05T23:48:03.838Z,1541461683.838 [PitchRateCalculator] Loaded
2018-11-05T23:48:03.839Z,1541461683.839 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2018-11-05T23:48:03.855Z,1541461683.855 [SpeedCalculator] Loaded
2018-11-05T23:48:03.855Z,1541461683.855 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2018-11-05T23:48:03.876Z,1541461683.876 [TempGradientCalculator] Loaded
2018-11-05T23:48:03.877Z,1541461683.877 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2018-11-05T23:48:03.882Z,1541461683.882 [YawRateCalculator] Loaded
2018-11-05T23:48:03.883Z,1541461683.883 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2018-11-05T23:48:03.923Z,1541461683.923 [ElevatorOffsetCalculator] Loaded
2018-11-05T23:48:03.923Z,1541461683.923 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2018-11-05T23:48:03.924Z,1541461683.924 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2018-11-05T23:48:03.924Z,1541461683.924 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2018-11-05T23:48:04.027Z,1541461684.027 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2018-11-05T23:48:04.029Z,1541461684.029 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2018-11-05T23:48:04.164Z,1541461684.164 [BuoyancyServo] Loaded
2018-11-05T23:48:04.164Z,1541461684.164 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2018-11-05T23:48:04.179Z,1541461684.179 [ElevatorServo] Loaded
2018-11-05T23:48:04.179Z,1541461684.179 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2018-11-05T23:48:04.194Z,1541461684.194 [MassServo] Loaded
2018-11-05T23:48:04.194Z,1541461684.194 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2018-11-05T23:48:04.210Z,1541461684.210 [RudderServo] Loaded
2018-11-05T23:48:04.210Z,1541461684.210 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2018-11-05T23:48:04.224Z,1541461684.224 [ThrusterServo] Loaded
2018-11-05T23:48:04.224Z,1541461684.224 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2018-11-05T23:48:04.225Z,1541461684.225 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2018-11-05T23:48:04.226Z,1541461684.226 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2018-11-05T23:48:04.250Z,1541461684.250 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2018-11-05T23:48:04.250Z,1541461684.250 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2018-11-05T23:48:04.379Z,1541461684.379 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2018-11-05T23:48:04.380Z,1541461684.380 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2018-11-05T23:48:04.955Z,1541461684.955 [DataOverHttps] Loaded
2018-11-05T23:48:04.956Z,1541461684.956 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2018-11-05T23:48:04.970Z,1541461684.970 [Depth_Keller] Loaded
2018-11-05T23:48:04.970Z,1541461684.970 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2018-11-05T23:48:04.975Z,1541461684.975 [DropWeight] Loaded
2018-11-05T23:48:04.975Z,1541461684.975 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2018-11-05T23:48:05.074Z,1541461685.074 [NAL9602] Loaded
2018-11-05T23:48:05.075Z,1541461685.075 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2018-11-05T23:48:05.091Z,1541461685.091 [Onboard] Loaded
2018-11-05T23:48:05.091Z,1541461685.091 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2018-11-05T23:48:05.102Z,1541461685.102 [Radio_Surface] Loaded
2018-11-05T23:48:05.102Z,1541461685.102 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2018-11-05T23:48:05.103Z,1541461685.103 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4088F4E0
2018-11-05T23:48:05.103Z,1541461685.103 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 883
2018-11-05T23:48:05.256Z,1541461685.256 [PNI_TCM] Loaded
2018-11-05T23:48:05.256Z,1541461685.256 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread.
2018-11-05T23:48:05.317Z,1541461685.317 [Rowe_600LCM] Loaded
2018-11-05T23:48:05.317Z,1541461685.317 [ComponentRegistry](DEBUG): Component "Rowe_600LCM" handled in its own thread.
2018-11-05T23:48:05.318Z,1541461685.318 [Rowe_600LCM ThreadHandler](DEBUG): Created PCaller Thread at 408BF4E0
2018-11-05T23:48:05.319Z,1541461685.319 [Rowe_600LCM ThreadHandler](INFO): Protected caller Thread ID is 884
2018-11-05T23:48:05.319Z,1541461685.319 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2018-11-05T23:48:05.320Z,1541461685.320 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2018-11-05T23:48:05.475Z,1541461685.475 [SBIT](DEBUG): Construct Startup Built In Test.
2018-11-05T23:48:05.497Z,1541461685.497 [SBIT] Loaded
2018-11-05T23:48:05.498Z,1541461685.498 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2018-11-05T23:48:05.499Z,1541461685.499 [IBIT](DEBUG): Construct Initiated Built In Test.
2018-11-05T23:48:05.511Z,1541461685.511 [IBIT] Loaded
2018-11-05T23:48:05.511Z,1541461685.511 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2018-11-05T23:48:05.515Z,1541461685.515 [CBIT](DEBUG): Construct Continuous Built In Test.
2018-11-05T23:48:05.664Z,1541461685.664 [CBIT] Loaded
2018-11-05T23:48:05.664Z,1541461685.664 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2018-11-05T23:48:05.664Z,1541461685.664 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2018-11-05T23:48:05.665Z,1541461685.665 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2018-11-05T23:48:05.874Z,1541461685.874 [Aanderaa_O2] Loaded
2018-11-05T23:48:05.874Z,1541461685.874 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2018-11-05T23:48:05.957Z,1541461685.957 [CTD_NeilBrown] Loaded
2018-11-05T23:48:05.957Z,1541461685.957 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2018-11-05T23:48:05.958Z,1541461685.958 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 4098B4E0
2018-11-05T23:48:05.959Z,1541461685.959 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 885
2018-11-05T23:48:05.973Z,1541461685.973 [PAR_Licor] Loaded
2018-11-05T23:48:05.973Z,1541461685.973 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2018-11-05T23:48:06.022Z,1541461686.022 [WetLabsBB2FL] Loaded
2018-11-05T23:48:06.022Z,1541461686.022 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2018-11-05T23:48:06.023Z,1541461686.023 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 409BB4E0
2018-11-05T23:48:06.024Z,1541461686.024 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 886
2018-11-05T23:48:06.024Z,1541461686.024 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2018-11-05T23:48:06.025Z,1541461686.025 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2018-11-05T23:48:06.113Z,1541461686.113 [VerticalControl](DEBUG): Construct VerticalControl.
2018-11-05T23:48:06.197Z,1541461686.197 [VerticalControl] Loaded
2018-11-05T23:48:06.197Z,1541461686.197 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2018-11-05T23:48:06.198Z,1541461686.198 [HorizontalControl](DEBUG): Construct HorizontalControl.
2018-11-05T23:48:06.255Z,1541461686.255 [HorizontalControl] Loaded
2018-11-05T23:48:06.255Z,1541461686.255 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2018-11-05T23:48:06.256Z,1541461686.256 [SpeedControl](DEBUG): Construct SpeedControl.
2018-11-05T23:48:06.257Z,1541461686.257 [SpeedControl] Loaded
2018-11-05T23:48:06.258Z,1541461686.258 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2018-11-05T23:48:06.258Z,1541461686.258 [LoopControl](DEBUG): Construct LoopControl.
2018-11-05T23:48:06.259Z,1541461686.259 [LoopControl] Loaded
2018-11-05T23:48:06.259Z,1541461686.259 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2018-11-05T23:48:06.260Z,1541461686.260 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2018-11-05T23:48:06.262Z,1541461686.262 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2018-11-05T23:48:06.300Z,1541461686.300 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2018-11-05T23:48:06.301Z,1541461686.301 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2018-11-05T23:48:06.407Z,1541461686.407 [DeadReckonUsingSpeedCalculator] Loaded
2018-11-05T23:48:06.407Z,1541461686.407 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2018-11-05T23:48:06.423Z,1541461686.423 [NavChart] Loaded
2018-11-05T23:48:06.424Z,1541461686.424 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2018-11-05T23:48:06.428Z,1541461686.428 [UniversalFixResidualReporter] Loaded
2018-11-05T23:48:06.428Z,1541461686.428 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2018-11-05T23:48:06.428Z,1541461686.428 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2018-11-05T23:48:06.432Z,1541461686.432 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2018-11-05T23:48:06.433Z,1541461686.433 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2018-11-05T23:48:06.439Z,1541461686.439 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2018-11-05T23:48:06.440Z,1541461686.440 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40A474E0
2018-11-05T23:48:06.441Z,1541461686.441 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 887
2018-11-05T23:48:06.445Z,1541461686.445 [Supervisor](INFO): Main Thread ID is 796
2018-11-05T23:48:06.446Z,1541461686.446 [Supervisor](DEBUG): Running supervisor.
2018-11-05T23:48:06.446Z,1541461686.446 [CommandLine ThreadHandler](INFO): Handler Thread ID is 888
2018-11-05T23:48:06.449Z,1541461686.449 [controlThread ThreadHandler](INFO): Handler Thread ID is 889
2018-11-05T23:48:06.449Z,1541461686.449 [controlThread](DEBUG): Initializing ControlThread
2018-11-05T23:48:06.450Z,1541461686.450 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2018-11-05T23:48:06.450Z,1541461686.450 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2018-11-05T23:48:06.451Z,1541461686.451 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2018-11-05T23:48:06.451Z,1541461686.451 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2018-11-05T23:48:06.452Z,1541461686.452 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2018-11-05T23:48:06.452Z,1541461686.452 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2018-11-05T23:48:06.457Z,1541461686.457 [SBIT](INFO): Initialize SBIT Component.
2018-11-05T23:48:06.457Z,1541461686.457 [SBIT](IMPORTANT): git: 2018-11-05
2018-11-05T23:48:06.458Z,1541461686.458 [SBIT](INFO): git hash: 17f8e4440ddc7f0910aa911cb821ed1a114d9cee
2018-11-05T23:48:06.458Z,1541461686.458 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2018-11-05T23:48:06.458Z,1541461686.458 [SBIT](IMPORTANT): Kernel Version:#2 PREEMPT Thu Jan 11 20:13:48 PST 2018
2018-11-05T23:48:06.460Z,1541461686.460 [SBIT](INFO): Beginning SBIT in 36.000000 seconds.
2018-11-05T23:48:06.460Z,1541461686.460 [IBIT](INFO): Initialize IBIT Component.
2018-11-05T23:48:06.461Z,1541461686.461 [CBIT](DEBUG): Initialize CBIT Component.
2018-11-05T23:48:06.461Z,1541461686.461 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2018-11-05T23:48:06.462Z,1541461686.462 [logger ThreadHandler](INFO): Handler Thread ID is 890
2018-11-05T23:48:06.507Z,1541461686.507 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 891
2018-11-05T23:48:06.513Z,1541461686.513 [Radio_Surface](INFO): Powering up
2018-11-05T23:48:06.515Z,1541461686.515 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 893
2018-11-05T23:48:06.516Z,1541461686.516 [CTD_NeilBrown](INFO): Powering down
2018-11-05T23:48:06.536Z,1541461686.536 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 894
2018-11-05T23:48:06.537Z,1541461686.537 [WetLabsBB2FL](INFO): Powering down
2018-11-05T23:48:06.571Z,1541461686.571 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 895
2018-11-05T23:48:06.579Z,1541461686.579 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2018-11-05T23:48:06.581Z,1541461686.581 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2018-11-05T23:48:06.581Z,1541461686.581 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2018-11-05T23:48:06.582Z,1541461686.582 [LoopControl](DEBUG): Initialize LoopControlComponent.
2018-11-05T23:48:06.582Z,1541461686.582 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-11-05T23:48:06.583Z,1541461686.583 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-11-05T23:48:06.583Z,1541461686.583 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-11-05T23:48:06.584Z,1541461686.584 [NavChart](DEBUG): Initialize NavChart Navigation.
2018-11-05T23:48:06.584Z,1541461686.584 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2018-11-05T23:48:06.585Z,1541461686.585 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2018-11-05T23:48:06.596Z,1541461686.596 [Rowe_600LCM ThreadHandler](INFO): Handler Thread ID is 892
2018-11-05T23:48:06.597Z,1541461686.597 [Rowe_600LCM](INFO): Initializing
2018-11-05T23:48:06.598Z,1541461686.598 [Rowe_600LCM](INFO): Checking LCM
2018-11-05T23:48:07.317Z,1541461687.317 [Rowe_600LCM](INFO): LCM OK
2018-11-05T23:48:07.317Z,1541461687.317 [Rowe_600LCM](INFO): Powering up
2018-11-05T23:48:07.322Z,1541461687.322 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2018-11-05T23:48:07.322Z,1541461687.322 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2018-11-05T23:48:07.323Z,1541461687.323 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2018-11-05T23:48:07.323Z,1541461687.323 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2018-11-05T23:48:07.323Z,1541461687.323 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2018-11-05T23:48:07.323Z,1541461687.323 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2018-11-05T23:48:07.323Z,1541461687.323 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2018-11-05T23:48:07.324Z,1541461687.324 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2018-11-05T23:48:07.324Z,1541461687.324 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2018-11-05T23:48:07.324Z,1541461687.324 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2018-11-05T23:48:07.324Z,1541461687.324 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2018-11-05T23:48:07.324Z,1541461687.324 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2018-11-05T23:48:07.325Z,1541461687.325 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2018-11-05T23:48:07.325Z,1541461687.325 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2018-11-05T23:48:07.325Z,1541461687.325 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2018-11-05T23:48:07.325Z,1541461687.325 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2018-11-05T23:48:07.452Z,1541461687.452 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2018-11-05T23:48:07.463Z,1541461687.463 [MissionManager](DEBUG):
2018-11-05T23:48:07.464Z,1541461687.464 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2018-11-05T23:48:07.558Z,1541461687.558 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2018-11-05T23:48:07.559Z,1541461687.559 [Default:A.Wait](DEBUG): Construct Wait.
2018-11-05T23:48:07.561Z,1541461687.561 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2018-11-05T23:48:07.604Z,1541461687.604 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2018-11-05T23:48:07.607Z,1541461687.607 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2018-11-05T23:48:07.624Z,1541461687.624 [Default:E.Execute](DEBUG): Construct Execute.
2018-11-05T23:48:07.628Z,1541461687.628 [MissionManager](DEBUG):
0
Wait a moment to see if the scheduler starts a new mission before
starting to actually run Default.
13
Burn on
Dropped weight due to communications timeout.
5
Default mission has been running for
Restarting logs and Default mission.
restart logs
2018-11-05T23:48:07.641Z,1541461687.641 [controlThread](DEBUG): Component order: CycleStarter,DataOverHttps,Depth_Keller,DropWeight,NAL9602,Onboard,PNI_TCM,Aanderaa_O2,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2018-11-05T23:48:07.666Z,1541461687.666 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2018-11-05T23:48:07.689Z,1541461687.689 [Depth_Keller](ERROR): Pressure reading out of range: 1831.023193 decibar
2018-11-05T23:48:07.816Z,1541461687.816 [DepthRateCalculator](ERROR): Depth measurement is not active
2018-11-05T23:48:08.099Z,1541461688.099 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2018-11-05T23:48:08.107Z,1541461688.107 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2018-11-05T23:48:08.122Z,1541461688.122 [ElevatorServo](DEBUG): Initializing EZServoServo.
2018-11-05T23:48:08.128Z,1541461688.128 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2018-11-05T23:48:08.142Z,1541461688.142 [MassServo](DEBUG): Initializing EZServoServo.
2018-11-05T23:48:08.147Z,1541461688.147 [MassServo](DEBUG): Initializing MassServo.
2018-11-05T23:48:08.153Z,1541461688.153 [RudderServo](DEBUG): Initializing EZServoServo.
2018-11-05T23:48:08.159Z,1541461688.159 [RudderServo](DEBUG): Initializing RudderServo.
2018-11-05T23:48:08.166Z,1541461688.166 [ThrusterServo](DEBUG): Initializing EZServoServo.
2018-11-05T23:48:08.171Z,1541461688.171 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2018-11-05T23:48:08.417Z,1541461688.417 [DropWeight](CRITICAL): DROP WEIGHT MISSING.
2018-11-05T23:48:08.417Z,1541461688.417 [DropWeight] Hardware Fault, FailCount= 1
2018-11-05T23:48:08.417Z,1541461688.417 [DropWeight](ERROR): Hardware Fault
2018-11-05T23:48:08.499Z,1541461688.499 [CommandLine](FAULT): Scheduling is paused
2018-11-05T23:48:08.499Z,1541461688.499 [CBIT](INFO): Critical error at 20181105T234808
2018-11-05T23:48:08.500Z,1541461688.500 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2018-11-05T23:48:08.502Z,1541461688.502 [CBIT](ERROR): Hardware Fault in component: DropWeight
2018-11-05T23:48:08.515Z,1541461688.515 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2018-11-05T23:48:09.083Z,1541461689.083 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout
2018-11-05T23:48:09.083Z,1541461689.083 [BuoyancyServo](FAULT): Buoyancy failed to initialize
2018-11-05T23:48:09.083Z,1541461689.083 [BuoyancyServo] Communications Fault, FailCount= 1
2018-11-05T23:48:09.083Z,1541461689.083 [BuoyancyServo](ERROR): Communications Fault
2018-11-05T23:48:09.288Z,1541461689.288 [CBIT](INFO): Critical error at 20181105T234808
2018-11-05T23:48:09.291Z,1541461689.291 [CBIT](ERROR): Communications Fault in component: BuoyancyServo
2018-11-05T23:48:11.051Z,1541461691.051 [Aanderaa_O2](INFO): Powering down
2018-11-05T23:48:11.257Z,1541461691.257 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-11-05T23:48:11.370Z,1541461691.370 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2018-11-05T23:48:11.489Z,1541461691.489 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-11-05T23:48:11.490Z,1541461691.490 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-11-05T23:48:11.494Z,1541461691.494 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-11-05T23:48:11.524Z,1541461691.524 [CBIT](INFO): Clearing failed state for component BuoyancyServo
2018-11-05T23:48:11.524Z,1541461691.524 [BuoyancyServo] No Fault, FailCount= 1
2018-11-05T23:48:11.820Z,1541461691.820 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2018-11-05T23:48:11.820Z,1541461691.820 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2018-11-05T23:48:35.308Z,1541461715.308 [NAL9602](INFO): Powering up NAL9602
2018-11-05T23:48:36.012Z,1541461716.012 [CommandLine](IMPORTANT): got command failComponent
2018-11-05T23:48:36.013Z,1541461716.013 [CommandLine](IMPORTANT): Failed components:
2018-11-05T23:48:36.013Z,1541461716.013 [CommandLine](IMPORTANT): DropWeight: Hardware Fault
2018-11-05T23:48:43.016Z,1541461723.016 [SBIT](IMPORTANT): Beginning Startup BIT
2018-11-05T23:48:43.021Z,1541461723.021 [CBIT](IMPORTANT): Beginning ground fault scan
2018-11-05T23:48:46.253Z,1541461726.253 [NAL9602](INFO): NAL9602 initialized
2018-11-05T23:48:48.748Z,1541461728.748 [CommandLine](IMPORTANT): got command quit
2018-11-05T23:48:49.765Z,1541461729.765 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2018-11-05T23:48:49.766Z,1541461729.766 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-11-05T23:48:49.868Z,1541461729.868 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye!
2018-11-05T23:48:49.868Z,1541461729.868 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-11-05T23:48:49.869Z,1541461729.869 [CommandLine](INFO): Join timeout helper Thread ID is 910
2018-11-05T23:48:49.871Z,1541461729.871 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2018-11-05T23:48:49.872Z,1541461729.872 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-11-05T23:48:49.872Z,1541461729.872 [NavChartDb](INFO): Join timeout helper Thread ID is 911
2018-11-05T23:48:50.665Z,1541461730.665 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2018-11-05T23:48:50.667Z,1541461730.667 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-11-05T23:48:50.679Z,1541461730.679 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2018-11-05T23:48:50.679Z,1541461730.679 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-11-05T23:48:50.679Z,1541461730.679 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 912
2018-11-05T23:48:50.959Z,1541461730.959 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2018-11-05T23:48:50.959Z,1541461730.959 [WetLabsBB2FL](INFO): Powering down
2018-11-05T23:48:50.960Z,1541461730.960 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-11-05T23:48:50.963Z,1541461730.963 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2018-11-05T23:48:50.963Z,1541461730.963 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2018-11-05T23:48:50.963Z,1541461730.963 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 913
2018-11-05T23:48:50.964Z,1541461730.964 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2018-11-05T23:48:50.964Z,1541461730.964 [CTD_NeilBrown](INFO): Powering down
2018-11-05T23:48:50.979Z,1541461730.979 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2018-11-05T23:48:50.983Z,1541461730.983 [ComponentRegistry](INFO): Shutting down Rowe_600LCM ThreadHandler
2018-11-05T23:48:50.983Z,1541461730.983 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2018-11-05T23:48:50.983Z,1541461730.983 [Rowe_600LCM](INFO): Join timeout helper Thread ID is 914
2018-11-05T23:48:51.731Z,1541461731.731 [Rowe_600LCM ThreadHandler](INFO): Uninitializing protected caller thread.
2018-11-05T23:48:51.731Z,1541461731.731 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-11-05T23:48:51.987Z,1541461731.987 [Rowe_600LCM](INFO): Powering down
2018-11-05T23:48:51.988Z,1541461731.988 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2018-11-05T23:48:52.004Z,1541461732.004 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2018-11-05T23:48:52.004Z,1541461732.004 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-11-05T23:48:52.004Z,1541461732.004 [Radio_Surface](INFO): Join timeout helper Thread ID is 916
2018-11-05T23:48:52.299Z,1541461732.299 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2018-11-05T23:48:52.299Z,1541461732.299 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-11-05T23:48:52.315Z,1541461732.315 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2018-11-05T23:48:52.316Z,1541461732.316 [logger ThreadHandler](INFO): Thread cancelled.
2018-11-05T23:48:52.316Z,1541461732.316 [logger](INFO): Join timeout helper Thread ID is 917
2018-11-05T23:48:52.320Z,1541461732.320 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2018-11-05T23:48:52.320Z,1541461732.320 [logger ThreadHandler](INFO): Thread cancelled.
2018-11-05T23:48:52.336Z,1541461732.336 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2018-11-05T23:48:52.336Z,1541461732.336 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-11-05T23:48:52.336Z,1541461732.336 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2018-11-05T23:48:52.336Z,1541461732.336 [controlThread ThreadHandler](INFO): Thread cancelled.
2018-11-05T23:48:52.337Z,1541461732.337 [controlThread](INFO): Join timeout helper Thread ID is 918
2018-11-05T23:48:52.440Z,1541461732.440 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2018-11-05T23:48:52.440Z,1541461732.440 [controlThread](DEBUG): Uninitializing ControlThread
2018-11-05T23:48:52.441Z,1541461732.441 [NAL9602](INFO): Powering down
2018-11-05T23:48:52.443Z,1541461732.443 [PNI_TCM](INFO): Powering down
2018-11-05T23:48:52.531Z,1541461732.531 [Aanderaa_O2](INFO): Powering down
2018-11-05T23:48:52.532Z,1541461732.532 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2018-11-05T23:48:52.533Z,1541461732.533 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2018-11-05T23:48:52.534Z,1541461732.534 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2018-11-05T23:48:52.534Z,1541461732.534 [MissionManager](INFO): Uninitializing Mission Default
2018-11-05T23:48:52.537Z,1541461732.537 [MissionManager](INFO): Uninitializing Mission Startup
2018-11-05T23:48:52.539Z,1541461732.539 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2018-11-05T23:48:52.539Z,1541461732.539 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2018-11-05T23:48:52.539Z,1541461732.539 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2018-11-05T23:48:52.540Z,1541461732.540 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2018-11-05T23:48:52.540Z,1541461732.540 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2018-11-05T23:48:52.540Z,1541461732.540 [BuoyancyServo](INFO): Powering down
2018-11-05T23:48:52.555Z,1541461732.555 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2018-11-05T23:48:52.555Z,1541461732.555 [ElevatorServo](INFO): Powering down
2018-11-05T23:48:52.556Z,1541461732.556 [MassServo](DEBUG): Uninitialize Mass Servo.
2018-11-05T23:48:52.556Z,1541461732.556 [MassServo](INFO): Powering down
2018-11-05T23:48:52.557Z,1541461732.557 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2018-11-05T23:48:52.557Z,1541461732.557 [RudderServo](INFO): Powering down
2018-11-05T23:48:52.558Z,1541461732.558 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2018-11-05T23:48:52.558Z,1541461732.558 [ThrusterServo](INFO): Powering down
2018-11-05T23:48:52.559Z,1541461732.559 [SBIT](DEBUG): Uninitialize SBIT Component.
2018-11-05T23:48:52.559Z,1541461732.559 [IBIT](DEBUG): Uninitialize IBIT Component.
2018-11-05T23:48:52.560Z,1541461732.560 [CBIT](DEBUG): Uninitialize CBIT Component.
2018-11-05T23:48:52.561Z,1541461732.561 [controlThread ThreadHandler](INFO): Thread cancelled.
2018-11-05T23:48:52.749Z,1541461732.749 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2018-11-05T23:48:52.756Z,1541461732.756 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-11-05T23:48:52.793Z,1541461732.793 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-11-05T23:48:52.797Z,1541461732.797 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2018-11-05T23:48:52.823Z,1541461732.823 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-11-05T23:48:52.880Z,1541461732.880 [logger ThreadHandler](INFO): Thread cancelled.