2018-11-06T00:01:36.044Z,1541462496.044 [Supervisor](DEBUG): Initializing supervisor.
2018-11-06T00:01:36.047Z,1541462496.047 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2018-11-06T00:01:36.047Z,1541462496.047 [SyncHandler](INFO): Protected caller Thread ID is 800
2018-11-06T00:01:36.048Z,1541462496.048 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2018-11-06T00:01:36.049Z,1541462496.049 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2018-11-06T00:01:36.049Z,1541462496.049 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 801
2018-11-06T00:01:36.052Z,1541462496.052 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2018-11-06T00:01:36.063Z,1541462496.063 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2018-11-06T00:01:36.064Z,1541462496.064 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2018-11-06T00:01:36.065Z,1541462496.065 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 802
2018-11-06T00:01:36.066Z,1541462496.066 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2018-11-06T00:01:36.066Z,1541462496.066 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2018-11-06T00:01:36.067Z,1541462496.067 [logger ThreadHandler](INFO): Protected caller Thread ID is 803
2018-11-06T00:01:36.069Z,1541462496.069 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2018-11-06T00:01:36.069Z,1541462496.069 [Supervisor](INFO): Looking for Config files in directory: Config/
2018-11-06T00:01:36.073Z,1541462496.073 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2018-11-06T00:01:36.453Z,1541462496.453 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2018-11-06T00:01:36.453Z,1541462496.453 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2018-11-06T00:01:36.653Z,1541462496.653 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2018-11-06T00:01:36.654Z,1541462496.654 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2018-11-06T00:01:36.954Z,1541462496.954 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2018-11-06T00:01:36.954Z,1541462496.954 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2018-11-06T00:01:37.101Z,1541462497.101 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2018-11-06T00:01:37.102Z,1541462497.102 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2018-11-06T00:01:37.202Z,1541462497.202 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2018-11-06T00:01:37.203Z,1541462497.203 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2018-11-06T00:01:37.669Z,1541462497.669 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2018-11-06T00:01:37.670Z,1541462497.670 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2018-11-06T00:01:38.136Z,1541462498.136 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2018-11-06T00:01:38.138Z,1541462498.138 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2018-11-06T00:01:38.699Z,1541462498.699 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2018-11-06T00:01:38.701Z,1541462498.701 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2018-11-06T00:01:38.806Z,1541462498.806 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2018-11-06T00:01:38.808Z,1541462498.808 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2018-11-06T00:01:38.905Z,1541462498.905 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2018-11-06T00:01:38.906Z,1541462498.906 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2018-11-06T00:01:39.125Z,1541462499.125 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2018-11-06T00:01:39.126Z,1541462499.126 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2018-11-06T00:01:39.332Z,1541462499.332 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2018-11-06T00:01:39.333Z,1541462499.333 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2018-11-06T00:01:39.687Z,1541462499.687 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2018-11-06T00:01:39.688Z,1541462499.688 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2018-11-06T00:01:40.176Z,1541462500.176 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2018-11-06T00:01:40.178Z,1541462500.178 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2018-11-06T00:01:40.261Z,1541462500.261 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2018-11-06T00:01:40.263Z,1541462500.263 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2018-11-06T00:01:40.368Z,1541462500.368 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2018-11-06T00:01:40.487Z,1541462500.487 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2018-11-06T00:01:40.583Z,1541462500.583 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2018-11-06T00:01:40.669Z,1541462500.669 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2018-11-06T00:01:40.834Z,1541462500.834 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2018-11-06T00:01:41.015Z,1541462501.015 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2018-11-06T00:01:41.092Z,1541462501.092 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg
2018-11-06T00:01:41.323Z,1541462501.323 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2018-11-06T00:01:41.324Z,1541462501.324 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2018-11-06T00:01:41.408Z,1541462501.408 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2018-11-06T00:01:41.502Z,1541462501.502 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2018-11-06T00:01:41.605Z,1541462501.605 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2018-11-06T00:01:41.733Z,1541462501.733 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/root/
2018-11-06T00:01:41.734Z,1541462501.734 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2018-11-06T00:01:41.748Z,1541462501.748 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2018-11-06T00:01:42.041Z,1541462502.041 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2018-11-06T00:01:42.043Z,1541462502.043 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2018-11-06T00:01:42.100Z,1541462502.100 [DepthRateCalculator] Loaded
2018-11-06T00:01:42.100Z,1541462502.100 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2018-11-06T00:01:42.106Z,1541462502.106 [PitchRateCalculator] Loaded
2018-11-06T00:01:42.107Z,1541462502.107 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2018-11-06T00:01:42.123Z,1541462502.123 [SpeedCalculator] Loaded
2018-11-06T00:01:42.123Z,1541462502.123 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2018-11-06T00:01:42.145Z,1541462502.145 [TempGradientCalculator] Loaded
2018-11-06T00:01:42.145Z,1541462502.145 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2018-11-06T00:01:42.151Z,1541462502.151 [YawRateCalculator] Loaded
2018-11-06T00:01:42.151Z,1541462502.151 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2018-11-06T00:01:42.191Z,1541462502.191 [ElevatorOffsetCalculator] Loaded
2018-11-06T00:01:42.192Z,1541462502.192 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2018-11-06T00:01:42.192Z,1541462502.192 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2018-11-06T00:01:42.193Z,1541462502.193 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2018-11-06T00:01:42.297Z,1541462502.297 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2018-11-06T00:01:42.299Z,1541462502.299 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2018-11-06T00:01:42.434Z,1541462502.434 [BuoyancyServo] Loaded
2018-11-06T00:01:42.434Z,1541462502.434 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2018-11-06T00:01:42.449Z,1541462502.449 [ElevatorServo] Loaded
2018-11-06T00:01:42.449Z,1541462502.449 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2018-11-06T00:01:42.464Z,1541462502.464 [MassServo] Loaded
2018-11-06T00:01:42.465Z,1541462502.465 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2018-11-06T00:01:42.480Z,1541462502.480 [RudderServo] Loaded
2018-11-06T00:01:42.480Z,1541462502.480 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2018-11-06T00:01:42.494Z,1541462502.494 [ThrusterServo] Loaded
2018-11-06T00:01:42.495Z,1541462502.495 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2018-11-06T00:01:42.495Z,1541462502.495 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2018-11-06T00:01:42.496Z,1541462502.496 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2018-11-06T00:01:42.520Z,1541462502.520 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2018-11-06T00:01:42.521Z,1541462502.521 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2018-11-06T00:01:42.653Z,1541462502.653 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2018-11-06T00:01:42.653Z,1541462502.653 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2018-11-06T00:01:43.566Z,1541462503.566 [DataOverHttps] Loaded
2018-11-06T00:01:43.566Z,1541462503.566 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2018-11-06T00:01:43.580Z,1541462503.580 [Depth_Keller] Loaded
2018-11-06T00:01:43.580Z,1541462503.580 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2018-11-06T00:01:43.586Z,1541462503.586 [DropWeight] Loaded
2018-11-06T00:01:43.586Z,1541462503.586 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2018-11-06T00:01:43.685Z,1541462503.685 [NAL9602] Loaded
2018-11-06T00:01:43.686Z,1541462503.686 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2018-11-06T00:01:43.702Z,1541462503.702 [Onboard] Loaded
2018-11-06T00:01:43.702Z,1541462503.702 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2018-11-06T00:01:43.713Z,1541462503.713 [Radio_Surface] Loaded
2018-11-06T00:01:43.713Z,1541462503.713 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2018-11-06T00:01:43.714Z,1541462503.714 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4088F4E0
2018-11-06T00:01:43.715Z,1541462503.715 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 886
2018-11-06T00:01:43.868Z,1541462503.868 [PNI_TCM] Loaded
2018-11-06T00:01:43.868Z,1541462503.868 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread.
2018-11-06T00:01:43.930Z,1541462503.930 [Rowe_600LCM] Loaded
2018-11-06T00:01:43.930Z,1541462503.930 [ComponentRegistry](DEBUG): Component "Rowe_600LCM" handled in its own thread.
2018-11-06T00:01:43.931Z,1541462503.931 [Rowe_600LCM ThreadHandler](DEBUG): Created PCaller Thread at 408BF4E0
2018-11-06T00:01:43.931Z,1541462503.931 [Rowe_600LCM ThreadHandler](INFO): Protected caller Thread ID is 887
2018-11-06T00:01:43.932Z,1541462503.932 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2018-11-06T00:01:43.933Z,1541462503.933 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2018-11-06T00:01:44.090Z,1541462504.090 [SBIT](DEBUG): Construct Startup Built In Test.
2018-11-06T00:01:44.112Z,1541462504.112 [SBIT] Loaded
2018-11-06T00:01:44.113Z,1541462504.113 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2018-11-06T00:01:44.113Z,1541462504.113 [IBIT](DEBUG): Construct Initiated Built In Test.
2018-11-06T00:01:44.126Z,1541462504.126 [IBIT] Loaded
2018-11-06T00:01:44.126Z,1541462504.126 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2018-11-06T00:01:44.129Z,1541462504.129 [CBIT](DEBUG): Construct Continuous Built In Test.
2018-11-06T00:01:44.279Z,1541462504.279 [CBIT] Loaded
2018-11-06T00:01:44.280Z,1541462504.280 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2018-11-06T00:01:44.280Z,1541462504.280 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2018-11-06T00:01:44.281Z,1541462504.281 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2018-11-06T00:01:44.492Z,1541462504.492 [Aanderaa_O2] Loaded
2018-11-06T00:01:44.493Z,1541462504.493 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2018-11-06T00:01:44.578Z,1541462504.578 [CTD_NeilBrown] Loaded
2018-11-06T00:01:44.579Z,1541462504.579 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2018-11-06T00:01:44.580Z,1541462504.580 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 4098B4E0
2018-11-06T00:01:44.580Z,1541462504.580 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 888
2018-11-06T00:01:44.594Z,1541462504.594 [PAR_Licor] Loaded
2018-11-06T00:01:44.595Z,1541462504.595 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2018-11-06T00:01:44.644Z,1541462504.644 [WetLabsBB2FL] Loaded
2018-11-06T00:01:44.644Z,1541462504.644 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2018-11-06T00:01:44.645Z,1541462504.645 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 409BB4E0
2018-11-06T00:01:44.645Z,1541462504.645 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 889
2018-11-06T00:01:44.646Z,1541462504.646 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2018-11-06T00:01:44.647Z,1541462504.647 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2018-11-06T00:01:44.737Z,1541462504.737 [VerticalControl](DEBUG): Construct VerticalControl.
2018-11-06T00:01:44.820Z,1541462504.820 [VerticalControl] Loaded
2018-11-06T00:01:44.821Z,1541462504.821 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2018-11-06T00:01:44.821Z,1541462504.821 [HorizontalControl](DEBUG): Construct HorizontalControl.
2018-11-06T00:01:44.879Z,1541462504.879 [HorizontalControl] Loaded
2018-11-06T00:01:44.879Z,1541462504.879 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2018-11-06T00:01:44.880Z,1541462504.880 [SpeedControl](DEBUG): Construct SpeedControl.
2018-11-06T00:01:44.881Z,1541462504.881 [SpeedControl] Loaded
2018-11-06T00:01:44.882Z,1541462504.882 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2018-11-06T00:01:44.883Z,1541462504.883 [LoopControl](DEBUG): Construct LoopControl.
2018-11-06T00:01:44.883Z,1541462504.883 [LoopControl] Loaded
2018-11-06T00:01:44.883Z,1541462504.883 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2018-11-06T00:01:44.884Z,1541462504.884 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2018-11-06T00:01:44.886Z,1541462504.886 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2018-11-06T00:01:45.826Z,1541462505.826 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2018-11-06T00:01:45.827Z,1541462505.827 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2018-11-06T00:01:46.036Z,1541462506.036 [DeadReckonUsingSpeedCalculator] Loaded
2018-11-06T00:01:46.036Z,1541462506.036 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2018-11-06T00:01:46.053Z,1541462506.053 [NavChart] Loaded
2018-11-06T00:01:46.053Z,1541462506.053 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2018-11-06T00:01:46.057Z,1541462506.057 [UniversalFixResidualReporter] Loaded
2018-11-06T00:01:46.058Z,1541462506.058 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2018-11-06T00:01:46.058Z,1541462506.058 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2018-11-06T00:01:46.062Z,1541462506.062 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2018-11-06T00:01:46.063Z,1541462506.063 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2018-11-06T00:01:46.069Z,1541462506.069 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2018-11-06T00:01:46.070Z,1541462506.070 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40A474E0
2018-11-06T00:01:46.071Z,1541462506.071 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 890
2018-11-06T00:01:46.075Z,1541462506.075 [Supervisor](INFO): Main Thread ID is 799
2018-11-06T00:01:46.075Z,1541462506.075 [Supervisor](DEBUG): Running supervisor.
2018-11-06T00:01:46.076Z,1541462506.076 [CommandLine ThreadHandler](INFO): Handler Thread ID is 891
2018-11-06T00:01:46.078Z,1541462506.078 [controlThread ThreadHandler](INFO): Handler Thread ID is 892
2018-11-06T00:01:46.079Z,1541462506.079 [controlThread](DEBUG): Initializing ControlThread
2018-11-06T00:01:46.080Z,1541462506.080 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2018-11-06T00:01:46.080Z,1541462506.080 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2018-11-06T00:01:46.080Z,1541462506.080 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2018-11-06T00:01:46.081Z,1541462506.081 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2018-11-06T00:01:46.081Z,1541462506.081 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2018-11-06T00:01:46.082Z,1541462506.082 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2018-11-06T00:01:46.087Z,1541462506.087 [SBIT](INFO): Initialize SBIT Component.
2018-11-06T00:01:46.087Z,1541462506.087 [SBIT](IMPORTANT): git: 2018-11-05
2018-11-06T00:01:46.088Z,1541462506.088 [SBIT](INFO): git hash: 17f8e4440ddc7f0910aa911cb821ed1a114d9cee
2018-11-06T00:01:46.088Z,1541462506.088 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2018-11-06T00:01:46.088Z,1541462506.088 [SBIT](IMPORTANT): Kernel Version:#2 PREEMPT Thu Jan 11 20:13:48 PST 2018
2018-11-06T00:01:46.089Z,1541462506.089 [SBIT](INFO): Beginning SBIT in 36.000000 seconds.
2018-11-06T00:01:46.090Z,1541462506.090 [IBIT](INFO): Initialize IBIT Component.
2018-11-06T00:01:46.091Z,1541462506.091 [CBIT](DEBUG): Initialize CBIT Component.
2018-11-06T00:01:46.091Z,1541462506.091 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2018-11-06T00:01:46.092Z,1541462506.092 [logger ThreadHandler](INFO): Handler Thread ID is 893
2018-11-06T00:01:46.109Z,1541462506.109 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 894
2018-11-06T00:01:46.115Z,1541462506.115 [Radio_Surface](INFO): Powering up
2018-11-06T00:01:46.121Z,1541462506.121 [Rowe_600LCM ThreadHandler](INFO): Handler Thread ID is 895
2018-11-06T00:01:46.122Z,1541462506.122 [Rowe_600LCM](INFO): Initializing
2018-11-06T00:01:46.122Z,1541462506.122 [Rowe_600LCM](INFO): Checking LCM
2018-11-06T00:01:46.238Z,1541462506.238 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 896
2018-11-06T00:01:46.238Z,1541462506.238 [CTD_NeilBrown](INFO): Powering down
2018-11-06T00:01:46.265Z,1541462506.265 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2018-11-06T00:01:46.267Z,1541462506.267 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2018-11-06T00:01:46.268Z,1541462506.268 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2018-11-06T00:01:46.268Z,1541462506.268 [LoopControl](DEBUG): Initialize LoopControlComponent.
2018-11-06T00:01:46.268Z,1541462506.268 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-11-06T00:01:46.269Z,1541462506.269 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-11-06T00:01:46.270Z,1541462506.270 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-11-06T00:01:46.270Z,1541462506.270 [NavChart](DEBUG): Initialize NavChart Navigation.
2018-11-06T00:01:46.271Z,1541462506.271 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2018-11-06T00:01:46.272Z,1541462506.272 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2018-11-06T00:01:46.376Z,1541462506.376 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 897
2018-11-06T00:01:46.377Z,1541462506.377 [WetLabsBB2FL](INFO): Powering down
2018-11-06T00:01:46.395Z,1541462506.395 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 898
2018-11-06T00:01:46.407Z,1541462506.407 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2018-11-06T00:01:46.408Z,1541462506.408 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2018-11-06T00:01:46.408Z,1541462506.408 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2018-11-06T00:01:46.408Z,1541462506.408 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2018-11-06T00:01:46.408Z,1541462506.408 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2018-11-06T00:01:46.409Z,1541462506.409 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2018-11-06T00:01:46.409Z,1541462506.409 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2018-11-06T00:01:46.409Z,1541462506.409 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2018-11-06T00:01:46.409Z,1541462506.409 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2018-11-06T00:01:46.409Z,1541462506.409 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2018-11-06T00:01:46.410Z,1541462506.410 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2018-11-06T00:01:46.410Z,1541462506.410 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2018-11-06T00:01:46.410Z,1541462506.410 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2018-11-06T00:01:46.410Z,1541462506.410 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2018-11-06T00:01:46.410Z,1541462506.410 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2018-11-06T00:01:46.410Z,1541462506.410 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2018-11-06T00:01:46.505Z,1541462506.505 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2018-11-06T00:01:46.592Z,1541462506.592 [MissionManager](DEBUG):
2018-11-06T00:01:46.598Z,1541462506.598 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2018-11-06T00:01:46.612Z,1541462506.612 [Rowe_600LCM](INFO): LCM OK
2018-11-06T00:01:46.625Z,1541462506.625 [Rowe_600LCM](INFO): Powering up
2018-11-06T00:01:46.682Z,1541462506.682 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2018-11-06T00:01:46.683Z,1541462506.683 [Default:A.Wait](DEBUG): Construct Wait.
2018-11-06T00:01:46.713Z,1541462506.713 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2018-11-06T00:01:46.748Z,1541462506.748 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2018-11-06T00:01:46.751Z,1541462506.751 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2018-11-06T00:01:46.773Z,1541462506.773 [Default:E.Execute](DEBUG): Construct Execute.
2018-11-06T00:01:46.777Z,1541462506.777 [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-06T00:01:46.782Z,1541462506.782 [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-06T00:01:46.816Z,1541462506.816 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2018-11-06T00:01:46.944Z,1541462506.944 [Depth_Keller](ERROR): Pressure reading out of range: 1831.023193 decibar
2018-11-06T00:01:47.217Z,1541462507.217 [DepthRateCalculator](ERROR): Depth measurement is not active
2018-11-06T00:01:47.513Z,1541462507.513 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2018-11-06T00:01:47.521Z,1541462507.521 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2018-11-06T00:01:47.535Z,1541462507.535 [ElevatorServo](DEBUG): Initializing EZServoServo.
2018-11-06T00:01:47.541Z,1541462507.541 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2018-11-06T00:01:47.547Z,1541462507.547 [MassServo](DEBUG): Initializing EZServoServo.
2018-11-06T00:01:47.553Z,1541462507.553 [MassServo](DEBUG): Initializing MassServo.
2018-11-06T00:01:47.559Z,1541462507.559 [RudderServo](DEBUG): Initializing EZServoServo.
2018-11-06T00:01:47.565Z,1541462507.565 [RudderServo](DEBUG): Initializing RudderServo.
2018-11-06T00:01:47.572Z,1541462507.572 [ThrusterServo](DEBUG): Initializing EZServoServo.
2018-11-06T00:01:47.577Z,1541462507.577 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2018-11-06T00:01:48.485Z,1541462508.485 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout
2018-11-06T00:01:48.485Z,1541462508.485 [BuoyancyServo](FAULT): Buoyancy failed to initialize
2018-11-06T00:01:48.485Z,1541462508.485 [BuoyancyServo] Communications Fault, FailCount= 1
2018-11-06T00:01:48.485Z,1541462508.485 [BuoyancyServo](ERROR): Communications Fault
2018-11-06T00:01:48.685Z,1541462508.685 [CBIT](ERROR): Communications Fault in component: BuoyancyServo
2018-11-06T00:01:50.352Z,1541462510.352 [Aanderaa_O2](INFO): Powering down
2018-11-06T00:01:50.706Z,1541462510.706 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-11-06T00:01:50.828Z,1541462510.828 [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-06T00:01:50.940Z,1541462510.940 [CBIT](INFO): Clearing failed state for component BuoyancyServo
2018-11-06T00:01:50.940Z,1541462510.940 [BuoyancyServo] No Fault, FailCount= 1
2018-11-06T00:01:50.987Z,1541462510.987 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-11-06T00:01:50.988Z,1541462510.988 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-11-06T00:01:51.001Z,1541462511.001 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-11-06T00:01:51.200Z,1541462511.200 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2018-11-06T00:01:51.200Z,1541462511.200 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2018-11-06T00:02:13.899Z,1541462533.899 [NAL9602](INFO): Powering up NAL9602
2018-11-06T00:02:14.782Z,1541462534.782 [CommandLine](IMPORTANT): got command failComponent
2018-11-06T00:02:14.783Z,1541462534.783 [CommandLine](IMPORTANT): Failed components:
2018-11-06T00:02:14.783Z,1541462534.783 [CommandLine](IMPORTANT): No failed Components.
2018-11-06T00:02:22.851Z,1541462542.851 [SBIT](IMPORTANT): Beginning Startup BIT
2018-11-06T00:02:22.867Z,1541462542.867 [CBIT](IMPORTANT): Beginning ground fault scan
2018-11-06T00:02:25.302Z,1541462545.302 [NAL9602](INFO): NAL9602 initialized
2018-11-06T00:02:27.101Z,1541462547.101 [CommandLine](IMPORTANT): got command quit
2018-11-06T00:02:28.106Z,1541462548.106 [Supervisor](INFO): Stop Mission called by Supervisor::terminate
2018-11-06T00:02:28.109Z,1541462548.109 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2018-11-06T00:02:28.109Z,1541462548.109 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-11-06T00:02:28.170Z,1541462548.170 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye!
2018-11-06T00:02:28.170Z,1541462548.170 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-11-06T00:02:28.225Z,1541462548.225 [CommandLine](INFO): Join timeout helper Thread ID is 913
2018-11-06T00:02:28.241Z,1541462548.241 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2018-11-06T00:02:28.241Z,1541462548.241 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-11-06T00:02:28.242Z,1541462548.242 [NavChartDb](INFO): Join timeout helper Thread ID is 914
2018-11-06T00:02:30.573Z,1541462550.573 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2018-11-06T00:02:30.574Z,1541462550.574 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-11-06T00:02:30.593Z,1541462550.593 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2018-11-06T00:02:30.593Z,1541462550.593 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-11-06T00:02:30.593Z,1541462550.593 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 915
2018-11-06T00:02:30.794Z,1541462550.794 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2018-11-06T00:02:30.794Z,1541462550.794 [WetLabsBB2FL](INFO): Powering down
2018-11-06T00:02:30.796Z,1541462550.796 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-11-06T00:02:30.813Z,1541462550.813 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2018-11-06T00:02:30.813Z,1541462550.813 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2018-11-06T00:02:30.813Z,1541462550.813 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 916
2018-11-06T00:02:30.993Z,1541462550.993 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2018-11-06T00:02:30.993Z,1541462550.993 [CTD_NeilBrown](INFO): Powering down
2018-11-06T00:02:31.005Z,1541462551.005 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2018-11-06T00:02:31.005Z,1541462551.005 [ComponentRegistry](INFO): Shutting down Rowe_600LCM ThreadHandler
2018-11-06T00:02:31.005Z,1541462551.005 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2018-11-06T00:02:31.006Z,1541462551.006 [Rowe_600LCM](INFO): Join timeout helper Thread ID is 917
2018-11-06T00:02:31.686Z,1541462551.686 [Rowe_600LCM ThreadHandler](INFO): Uninitializing protected caller thread.
2018-11-06T00:02:31.688Z,1541462551.688 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-11-06T00:02:31.977Z,1541462551.977 [Rowe_600LCM](INFO): Powering down
2018-11-06T00:02:31.978Z,1541462551.978 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2018-11-06T00:02:31.994Z,1541462551.994 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2018-11-06T00:02:31.994Z,1541462551.994 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-11-06T00:02:31.994Z,1541462551.994 [Radio_Surface](INFO): Join timeout helper Thread ID is 919
2018-11-06T00:02:32.241Z,1541462552.241 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2018-11-06T00:02:32.241Z,1541462552.241 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-11-06T00:02:32.248Z,1541462552.248 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2018-11-06T00:02:32.248Z,1541462552.248 [logger ThreadHandler](INFO): Thread cancelled.
2018-11-06T00:02:32.248Z,1541462552.248 [logger](INFO): Join timeout helper Thread ID is 920
2018-11-06T00:02:32.248Z,1541462552.248 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2018-11-06T00:02:32.249Z,1541462552.249 [logger ThreadHandler](INFO): Thread cancelled.
2018-11-06T00:02:32.250Z,1541462552.250 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2018-11-06T00:02:32.250Z,1541462552.250 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-11-06T00:02:32.250Z,1541462552.250 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2018-11-06T00:02:32.250Z,1541462552.250 [controlThread ThreadHandler](INFO): Thread cancelled.
2018-11-06T00:02:32.251Z,1541462552.251 [controlThread](INFO): Join timeout helper Thread ID is 921
2018-11-06T00:02:32.338Z,1541462552.338 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2018-11-06T00:02:32.338Z,1541462552.338 [controlThread](DEBUG): Uninitializing ControlThread
2018-11-06T00:02:32.340Z,1541462552.340 [NAL9602](INFO): Powering down
2018-11-06T00:02:32.341Z,1541462552.341 [PNI_TCM](INFO): Powering down
2018-11-06T00:02:32.429Z,1541462552.429 [Aanderaa_O2](INFO): Powering down
2018-11-06T00:02:32.431Z,1541462552.431 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2018-11-06T00:02:32.432Z,1541462552.432 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2018-11-06T00:02:32.432Z,1541462552.432 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2018-11-06T00:02:32.433Z,1541462552.433 [MissionManager](INFO): Uninitializing Mission Default
2018-11-06T00:02:32.435Z,1541462552.435 [MissionManager](INFO): Uninitializing Mission Startup
2018-11-06T00:02:32.437Z,1541462552.437 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2018-11-06T00:02:32.438Z,1541462552.438 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2018-11-06T00:02:32.438Z,1541462552.438 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2018-11-06T00:02:32.438Z,1541462552.438 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2018-11-06T00:02:32.438Z,1541462552.438 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2018-11-06T00:02:32.439Z,1541462552.439 [BuoyancyServo](INFO): Powering down
2018-11-06T00:02:32.453Z,1541462552.453 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2018-11-06T00:02:32.453Z,1541462552.453 [ElevatorServo](INFO): Powering down
2018-11-06T00:02:32.454Z,1541462552.454 [MassServo](DEBUG): Uninitialize Mass Servo.
2018-11-06T00:02:32.454Z,1541462552.454 [MassServo](INFO): Powering down
2018-11-06T00:02:32.455Z,1541462552.455 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2018-11-06T00:02:32.455Z,1541462552.455 [RudderServo](INFO): Powering down
2018-11-06T00:02:32.456Z,1541462552.456 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2018-11-06T00:02:32.456Z,1541462552.456 [ThrusterServo](INFO): Powering down
2018-11-06T00:02:32.457Z,1541462552.457 [SBIT](DEBUG): Uninitialize SBIT Component.
2018-11-06T00:02:32.457Z,1541462552.457 [IBIT](DEBUG): Uninitialize IBIT Component.
2018-11-06T00:02:32.458Z,1541462552.458 [CBIT](DEBUG): Uninitialize CBIT Component.
2018-11-06T00:02:32.459Z,1541462552.459 [controlThread ThreadHandler](INFO): Thread cancelled.
2018-11-06T00:02:32.526Z,1541462552.526 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2018-11-06T00:02:32.532Z,1541462552.532 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-11-06T00:02:32.569Z,1541462552.569 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-11-06T00:02:32.573Z,1541462552.573 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2018-11-06T00:02:32.600Z,1541462552.600 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-11-06T00:02:32.656Z,1541462552.656 [logger ThreadHandler](INFO): Thread cancelled.