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.