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.