2017-09-12T20:19:03.904Z,1505247543.904 [Supervisor](DEBUG): Initializing supervisor. 2017-09-12T20:19:03.908Z,1505247543.908 [SyncHandler](DEBUG): Created PCaller Thread at 4051A4E0 2017-09-12T20:19:03.909Z,1505247543.909 [SyncHandler](INFO): Protected caller Thread ID is 5394 2017-09-12T20:19:03.909Z,1505247543.909 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2017-09-12T20:19:03.910Z,1505247543.910 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4054A4E0 2017-09-12T20:19:03.911Z,1505247543.911 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 5395 2017-09-12T20:19:03.916Z,1505247543.916 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2017-09-12T20:19:03.931Z,1505247543.931 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2017-09-12T20:19:03.932Z,1505247543.932 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 4057A4E0 2017-09-12T20:19:03.933Z,1505247543.933 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 5396 2017-09-12T20:19:03.934Z,1505247543.934 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2017-09-12T20:19:03.935Z,1505247543.935 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405AA4E0 2017-09-12T20:19:03.935Z,1505247543.935 [logger ThreadHandler](INFO): Protected caller Thread ID is 5397 2017-09-12T20:19:03.938Z,1505247543.938 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2017-09-12T20:19:03.938Z,1505247543.938 [Supervisor](INFO): Looking for Config files in directory: Config/ 2017-09-12T20:19:03.940Z,1505247543.940 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2017-09-12T20:19:04.145Z,1505247544.145 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2017-09-12T20:19:04.145Z,1505247544.145 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2017-09-12T20:19:04.287Z,1505247544.287 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2017-09-12T20:19:04.287Z,1505247544.287 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2017-09-12T20:19:04.673Z,1505247544.673 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2017-09-12T20:19:04.674Z,1505247544.674 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2017-09-12T20:19:04.825Z,1505247544.825 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2017-09-12T20:19:04.826Z,1505247544.826 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2017-09-12T20:19:04.909Z,1505247544.909 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2017-09-12T20:19:05.134Z,1505247545.134 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2017-09-12T20:19:05.135Z,1505247545.135 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2017-09-12T20:19:05.243Z,1505247545.243 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2017-09-12T20:19:05.243Z,1505247545.243 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2017-09-12T20:19:05.611Z,1505247545.611 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2017-09-12T20:19:05.612Z,1505247545.612 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2017-09-12T20:19:06.160Z,1505247546.160 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2017-09-12T20:19:06.160Z,1505247546.160 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2017-09-12T20:19:06.514Z,1505247546.514 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2017-09-12T20:19:06.515Z,1505247546.515 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2017-09-12T20:19:07.288Z,1505247547.288 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2017-09-12T20:19:07.289Z,1505247547.289 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2017-09-12T20:19:07.503Z,1505247547.503 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2017-09-12T20:19:07.503Z,1505247547.503 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2017-09-12T20:19:07.610Z,1505247547.610 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2017-09-12T20:19:07.610Z,1505247547.610 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2017-09-12T20:19:08.165Z,1505247548.165 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2017-09-12T20:19:08.165Z,1505247548.165 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2017-09-12T20:19:08.281Z,1505247548.281 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2017-09-12T20:19:08.283Z,1505247548.283 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/ 2017-09-12T20:19:08.284Z,1505247548.284 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg 2017-09-12T20:19:08.587Z,1505247548.587 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2017-09-12T20:19:08.588Z,1505247548.588 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg 2017-09-12T20:19:08.695Z,1505247548.695 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg 2017-09-12T20:19:08.790Z,1505247548.790 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg 2017-09-12T20:19:08.898Z,1505247548.898 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg 2017-09-12T20:19:08.989Z,1505247548.989 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg 2017-09-12T20:19:09.128Z,1505247549.128 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg 2017-09-12T20:19:09.297Z,1505247549.297 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg 2017-09-12T20:19:09.399Z,1505247549.399 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg 2017-09-12T20:19:09.497Z,1505247549.497 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg 2017-09-12T20:19:09.584Z,1505247549.584 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg 2017-09-12T20:19:09.782Z,1505247549.782 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg 2017-09-12T20:19:09.863Z,1505247549.863 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/root/ 2017-09-12T20:19:09.863Z,1505247549.863 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2017-09-12T20:19:09.872Z,1505247549.872 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2017-09-12T20:19:10.046Z,1505247550.046 [SBIT](DEBUG): Construct Startup Built In Test. 2017-09-12T20:19:10.084Z,1505247550.084 [SBIT] Loaded 2017-09-12T20:19:10.084Z,1505247550.084 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2017-09-12T20:19:10.085Z,1505247550.085 [IBIT](DEBUG): Construct Initiated Built In Test. 2017-09-12T20:19:10.121Z,1505247550.121 [IBIT] Loaded 2017-09-12T20:19:10.122Z,1505247550.122 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2017-09-12T20:19:10.127Z,1505247550.127 [CBIT](DEBUG): Construct Continuous Built In Test. 2017-09-12T20:19:10.330Z,1505247550.330 [CBIT] Loaded 2017-09-12T20:19:10.331Z,1505247550.331 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2017-09-12T20:19:10.331Z,1505247550.331 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2017-09-12T20:19:10.332Z,1505247550.332 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2017-09-12T20:19:10.434Z,1505247550.434 [VerticalControl](DEBUG): Construct VerticalControl. 2017-09-12T20:19:10.558Z,1505247550.558 [VerticalControl] Loaded 2017-09-12T20:19:10.559Z,1505247550.559 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2017-09-12T20:19:10.560Z,1505247550.560 [HorizontalControl](DEBUG): Construct HorizontalControl. 2017-09-12T20:19:10.642Z,1505247550.642 [HorizontalControl] Loaded 2017-09-12T20:19:10.642Z,1505247550.642 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2017-09-12T20:19:10.643Z,1505247550.643 [SpeedControl](DEBUG): Construct SpeedControl. 2017-09-12T20:19:10.650Z,1505247550.650 [SpeedControl] Loaded 2017-09-12T20:19:10.650Z,1505247550.650 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2017-09-12T20:19:10.651Z,1505247550.651 [LoopControl](DEBUG): Construct LoopControl. 2017-09-12T20:19:10.652Z,1505247550.652 [LoopControl] Loaded 2017-09-12T20:19:10.652Z,1505247550.652 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2017-09-12T20:19:10.653Z,1505247550.653 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2017-09-12T20:19:10.653Z,1505247550.653 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2017-09-12T20:19:12.195Z,1505247552.195 [DepthRateCalculator] Loaded 2017-09-12T20:19:12.195Z,1505247552.195 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2017-09-12T20:19:12.210Z,1505247552.210 [PitchRateCalculator] Loaded 2017-09-12T20:19:12.210Z,1505247552.210 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2017-09-12T20:19:12.232Z,1505247552.232 [SpeedCalculator] Loaded 2017-09-12T20:19:12.232Z,1505247552.232 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2017-09-12T20:19:12.259Z,1505247552.259 [TempGradientCalculator] Loaded 2017-09-12T20:19:12.259Z,1505247552.259 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2017-09-12T20:19:12.279Z,1505247552.279 [VerticalTemperatureHomogeneityIndexCalculator] Loaded 2017-09-12T20:19:12.279Z,1505247552.279 [ComponentRegistry](DEBUG): SyncComponent "VerticalTemperatureHomogeneityIndexCalculator" handled in the control thread. 2017-09-12T20:19:12.286Z,1505247552.286 [YawRateCalculator] Loaded 2017-09-12T20:19:12.286Z,1505247552.286 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2017-09-12T20:19:12.287Z,1505247552.287 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2017-09-12T20:19:12.287Z,1505247552.287 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2017-09-12T20:19:17.539Z,1505247557.539 [StratificationFrontDetector](INFO): threshold set to: 0.399988 degC 2017-09-12T20:19:17.539Z,1505247557.539 [StratificationFrontDetector](DEBUG): (re)initializing 2017-09-12T20:19:17.539Z,1505247557.539 [StratificationFrontDetector] Loaded 2017-09-12T20:19:17.539Z,1505247557.539 [ComponentRegistry](DEBUG): SyncComponent "StratificationFrontDetector" handled in the control thread. 2017-09-12T20:19:17.540Z,1505247557.540 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2017-09-12T20:19:17.541Z,1505247557.541 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2017-09-12T20:19:17.846Z,1505247557.846 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2017-09-12T20:19:17.847Z,1505247557.847 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2017-09-12T20:19:17.988Z,1505247557.988 [DeadReckonUsingMultipleVelocitySources] Loaded 2017-09-12T20:19:17.988Z,1505247557.988 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2017-09-12T20:19:18.060Z,1505247558.060 [DeadReckonUsingSpeedCalculator] Loaded 2017-09-12T20:19:18.060Z,1505247558.060 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread. 2017-09-12T20:19:18.082Z,1505247558.082 [NavChart] Loaded 2017-09-12T20:19:18.082Z,1505247558.082 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2017-09-12T20:19:18.088Z,1505247558.088 [UniversalFixResidualReporter] Loaded 2017-09-12T20:19:18.088Z,1505247558.088 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2017-09-12T20:19:18.089Z,1505247558.089 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2017-09-12T20:19:18.089Z,1505247558.089 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2017-09-12T20:19:18.119Z,1505247558.119 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2017-09-12T20:19:18.119Z,1505247558.119 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2017-09-12T20:19:18.347Z,1505247558.347 [Aanderaa_O2] Loaded 2017-09-12T20:19:18.348Z,1505247558.348 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread. 2017-09-12T20:19:18.367Z,1505247558.367 [PAR_Licor] Loaded 2017-09-12T20:19:18.367Z,1505247558.367 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2017-09-12T20:19:18.368Z,1505247558.368 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2017-09-12T20:19:18.369Z,1505247558.369 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2017-09-12T20:19:18.758Z,1505247558.758 [DataOverHttps] Loaded 2017-09-12T20:19:18.758Z,1505247558.758 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread. 2017-09-12T20:19:18.776Z,1505247558.776 [Depth_Keller] Loaded 2017-09-12T20:19:18.777Z,1505247558.777 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2017-09-12T20:19:18.783Z,1505247558.783 [DropWeight] Loaded 2017-09-12T20:19:18.783Z,1505247558.783 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2017-09-12T20:19:18.903Z,1505247558.903 [NAL9602] Loaded 2017-09-12T20:19:18.904Z,1505247558.904 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2017-09-12T20:19:18.915Z,1505247558.915 [Onboard] Loaded 2017-09-12T20:19:18.916Z,1505247558.916 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2017-09-12T20:19:18.925Z,1505247558.925 [Radio_Surface] Loaded 2017-09-12T20:19:18.925Z,1505247558.925 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2017-09-12T20:19:18.927Z,1505247558.927 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 40A674E0 2017-09-12T20:19:18.927Z,1505247558.927 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 5480 2017-09-12T20:19:19.105Z,1505247559.105 [DAT] Loaded 2017-09-12T20:19:19.106Z,1505247559.106 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread. 2017-09-12T20:19:19.166Z,1505247559.166 [PNI_TCM] Loaded 2017-09-12T20:19:19.167Z,1505247559.167 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread. 2017-09-12T20:19:21.693Z,1505247561.693 [BPC1] Loaded 2017-09-12T20:19:21.694Z,1505247561.694 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2017-09-12T20:19:21.694Z,1505247561.694 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2017-09-12T20:19:21.695Z,1505247561.695 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2017-09-12T20:19:21.832Z,1505247561.832 [BuoyancyServo] Loaded 2017-09-12T20:19:21.832Z,1505247561.832 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2017-09-12T20:19:21.848Z,1505247561.848 [ElevatorServo] Loaded 2017-09-12T20:19:21.848Z,1505247561.848 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2017-09-12T20:19:21.863Z,1505247561.863 [MassServo] Loaded 2017-09-12T20:19:21.863Z,1505247561.863 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2017-09-12T20:19:21.878Z,1505247561.878 [RudderServo] Loaded 2017-09-12T20:19:21.879Z,1505247561.879 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2017-09-12T20:19:21.893Z,1505247561.893 [ThrusterServo] Loaded 2017-09-12T20:19:21.894Z,1505247561.894 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2017-09-12T20:19:21.894Z,1505247561.894 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2017-09-12T20:19:21.895Z,1505247561.895 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2017-09-12T20:19:22.043Z,1505247562.043 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2017-09-12T20:19:22.044Z,1505247562.044 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2017-09-12T20:19:22.090Z,1505247562.090 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2017-09-12T20:19:22.095Z,1505247562.095 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2017-09-12T20:19:22.097Z,1505247562.097 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2017-09-12T20:19:22.107Z,1505247562.107 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2017-09-12T20:19:22.109Z,1505247562.109 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B3B4E0 2017-09-12T20:19:22.109Z,1505247562.109 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 5481 2017-09-12T20:19:22.116Z,1505247562.116 [Supervisor](INFO): Main Thread ID is 5393 2017-09-12T20:19:22.116Z,1505247562.116 [Supervisor](DEBUG): Running supervisor. 2017-09-12T20:19:22.117Z,1505247562.117 [CommandLine ThreadHandler](INFO): Handler Thread ID is 5482 2017-09-12T20:19:22.120Z,1505247562.120 [controlThread ThreadHandler](INFO): Handler Thread ID is 5483 2017-09-12T20:19:22.121Z,1505247562.121 [controlThread](DEBUG): Initializing ControlThread 2017-09-12T20:19:22.122Z,1505247562.122 [SBIT](INFO): Initialize SBIT Component. 2017-09-12T20:19:22.122Z,1505247562.122 [SBIT](IMPORTANT): git: 2017-08-02-103-g54acef0 2017-09-12T20:19:22.123Z,1505247562.123 [SBIT](INFO): git hash: 54acef0e8867e4ebce852e89742b80c54cea63d9 2017-09-12T20:19:22.125Z,1505247562.125 [SBIT](INFO): Kernel Reporting Different Release From Configuration. Kernel Expected: 2.6.27.8 Kernel Reported: 2.6.27.8-00011-g2bc81df-dirty 2017-09-12T20:19:22.125Z,1505247562.125 [SBIT](INFO): Kernel Reporting Different Version From Configuration. Kernel Expected: #639 PREEMPT Wed Mar 12 12:53:33 PDT 2014 Kernel Reported: #646 PREEMPT Thu Feb 11 17:01:12 PST 2016 2017-09-12T20:19:22.126Z,1505247562.126 [SBIT](INFO): Beginning SBIT in 71.000000 seconds. 2017-09-12T20:19:22.127Z,1505247562.127 [IBIT](INFO): Initialize IBIT Component. 2017-09-12T20:19:22.128Z,1505247562.128 [CBIT](DEBUG): Initialize CBIT Component. 2017-09-12T20:19:22.129Z,1505247562.129 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2017-09-12T20:19:22.129Z,1505247562.129 [logger ThreadHandler](INFO): Handler Thread ID is 5484 2017-09-12T20:19:22.156Z,1505247562.156 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 5485 2017-09-12T20:19:22.164Z,1505247562.164 [Radio_Surface](INFO): Powering up 2017-09-12T20:19:22.184Z,1505247562.184 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 5486 2017-09-12T20:19:22.189Z,1505247562.189 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2017-09-12T20:19:22.189Z,1505247562.189 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2017-09-12T20:19:22.189Z,1505247562.189 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2017-09-12T20:19:22.189Z,1505247562.189 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2017-09-12T20:19:22.190Z,1505247562.190 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2017-09-12T20:19:22.190Z,1505247562.190 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2017-09-12T20:19:22.190Z,1505247562.190 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000 2017-09-12T20:19:22.190Z,1505247562.190 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2017-09-12T20:19:22.190Z,1505247562.190 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2017-09-12T20:19:22.191Z,1505247562.191 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2017-09-12T20:19:22.191Z,1505247562.191 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000 2017-09-12T20:19:22.191Z,1505247562.191 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2017-09-12T20:19:22.191Z,1505247562.191 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000 2017-09-12T20:19:22.191Z,1505247562.191 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2017-09-12T20:19:22.192Z,1505247562.192 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000 2017-09-12T20:19:22.192Z,1505247562.192 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2017-09-12T20:19:22.212Z,1505247562.212 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2017-09-12T20:19:22.214Z,1505247562.214 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2017-09-12T20:19:22.215Z,1505247562.215 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2017-09-12T20:19:22.216Z,1505247562.216 [LoopControl](DEBUG): Initialize LoopControlComponent. 2017-09-12T20:19:22.217Z,1505247562.217 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2017-09-12T20:19:22.217Z,1505247562.217 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2017-09-12T20:19:22.217Z,1505247562.217 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2017-09-12T20:19:22.218Z,1505247562.218 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2017-09-12T20:19:22.219Z,1505247562.219 [VerticalTemperatureHomogeneityIndexCalculator](DEBUG): (re)initializing 2017-09-12T20:19:22.220Z,1505247562.220 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2017-09-12T20:19:22.220Z,1505247562.220 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component. 2017-09-12T20:19:22.221Z,1505247562.221 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s. 2017-09-12T20:19:22.222Z,1505247562.222 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s. 2017-09-12T20:19:22.222Z,1505247562.222 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2017-09-12T20:19:22.223Z,1505247562.223 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2017-09-12T20:19:22.223Z,1505247562.223 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2017-09-12T20:19:22.223Z,1505247562.223 [NavChart](DEBUG): Initialize NavChart Navigation. 2017-09-12T20:19:22.224Z,1505247562.224 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2017-09-12T20:19:22.255Z,1505247562.255 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2017-09-12T20:19:22.292Z,1505247562.292 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2017-09-12T20:19:22.334Z,1505247562.334 [MissionManager](DEBUG): 2017-09-12T20:19:22.334Z,1505247562.334 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2017-09-12T20:19:22.415Z,1505247562.415 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2017-09-12T20:19:22.432Z,1505247562.432 [Default:A.Wait](DEBUG): Construct Wait. 2017-09-12T20:19:22.434Z,1505247562.434 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2017-09-12T20:19:22.452Z,1505247562.452 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2017-09-12T20:19:22.479Z,1505247562.479 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2017-09-12T20:19:22.503Z,1505247562.503 [Default:E.Execute](DEBUG): Construct Execute. 2017-09-12T20:19:22.507Z,1505247562.507 [MissionManager](DEBUG): 0 Wait a moment to see if the scheduler starts a new mission before starting to actually run Default. 13 Burn 300 Dropped weight due to communications timeout. 5 Default mission has been running for Restarting logs and Default mission. restart logs 2017-09-12T20:19:22.518Z,1505247562.518 [controlThread](DEBUG): Component order: CycleStarter,Aanderaa_O2,PAR_Licor,DataOverHttps,Depth_Keller,DropWeight,NAL9602,Onboard,DAT,PNI_TCM,BPC1,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,VerticalTemperatureHomogeneityIndexCalculator,YawRateCalculator,StratificationFrontDetector,DeadReckonUsingMultipleVelocitySources,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2017-09-12T20:19:22.601Z,1505247562.601 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2017-09-12T20:19:22.658Z,1505247562.658 [Depth_Keller](ERROR): Pressure reading out of range: 1831.023193 decibar 2017-09-12T20:19:22.781Z,1505247562.781 [DAT](INFO): Powering up 2017-09-12T20:19:22.781Z,1505247562.781 [DAT](DEBUG): Initializing DAT. 2017-09-12T20:19:22.982Z,1505247562.982 [DepthRateCalculator](ERROR): Depth measurement is not active 2017-09-12T20:19:23.093Z,1505247563.093 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2017-09-12T20:19:23.130Z,1505247563.130 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2017-09-12T20:19:23.257Z,1505247563.257 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2017-09-12T20:19:23.266Z,1505247563.266 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2017-09-12T20:19:23.294Z,1505247563.294 [ElevatorServo](DEBUG): Initializing EZServoServo. 2017-09-12T20:19:23.306Z,1505247563.306 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2017-09-12T20:19:23.321Z,1505247563.321 [MassServo](DEBUG): Initializing EZServoServo. 2017-09-12T20:19:23.330Z,1505247563.330 [MassServo](DEBUG): Initializing MassServo. 2017-09-12T20:19:23.341Z,1505247563.341 [RudderServo](DEBUG): Initializing EZServoServo. 2017-09-12T20:19:23.346Z,1505247563.346 [RudderServo](DEBUG): Initializing RudderServo. 2017-09-12T20:19:23.365Z,1505247563.365 [ThrusterServo](DEBUG): Initializing EZServoServo. 2017-09-12T20:19:23.370Z,1505247563.370 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2017-09-12T20:19:23.826Z,1505247563.826 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2017-09-12T20:19:23.835Z,1505247563.835 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2017-09-12T20:19:24.167Z,1505247564.167 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout 2017-09-12T20:19:24.167Z,1505247564.167 [BuoyancyServo](FAULT): Buoyancy failed to initialize 2017-09-12T20:19:24.168Z,1505247564.168 [BuoyancyServo] Communications Fault, FailCount= 1 2017-09-12T20:19:24.168Z,1505247564.168 [BuoyancyServo](ERROR): Communications Fault 2017-09-12T20:19:24.380Z,1505247564.380 [CBIT](ERROR): Communications Fault in component: BuoyancyServo 2017-09-12T20:19:24.418Z,1505247564.418 [NAL9602](INFO): Powering up NAL9602 2017-09-12T20:19:24.487Z,1505247564.487 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2017-09-12T20:19:24.488Z,1505247564.488 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2017-09-12T20:19:24.512Z,1505247564.512 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2017-09-12T20:19:24.512Z,1505247564.512 [BuoyancyServo](INFO): Powering down 2017-09-12T20:19:24.842Z,1505247564.842 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2017-09-12T20:19:24.843Z,1505247564.843 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2017-09-12T20:19:25.257Z,1505247565.257 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2017-09-12T20:19:25.259Z,1505247565.259 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2017-09-12T20:19:25.710Z,1505247565.710 [Aanderaa_O2](INFO): Powering down 2017-09-12T20:19:25.870Z,1505247565.870 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2017-09-12T20:19:25.871Z,1505247565.871 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2017-09-12T20:19:26.110Z,1505247566.110 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2017-09-12T20:19:26.112Z,1505247566.112 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2017-09-12T20:19:26.612Z,1505247566.612 [CBIT](INFO): Clearing failed state for component BuoyancyServo 2017-09-12T20:19:26.612Z,1505247566.612 [BuoyancyServo] No Fault, FailCount= 1 2017-09-12T20:19:26.905Z,1505247566.905 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2017-09-12T20:19:27.025Z,1505247567.025 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2017-09-12T20:19:35.235Z,1505247575.235 [NAL9602](INFO): NAL9602 initialized 2017-09-12T20:20:07.687Z,1505247607.687 [BPC1](ERROR): Failed to receive battery data 2017-09-12T20:20:07.687Z,1505247607.687 [BPC1] Communications Fault, FailCount= 1 2017-09-12T20:20:07.687Z,1505247607.687 [BPC1](ERROR): Communications Fault 2017-09-12T20:20:07.792Z,1505247607.792 [CBIT](ERROR): Communications Fault in component: BPC1 2017-09-12T20:20:08.955Z,1505247608.955 [CBIT](INFO): Clearing failed state for component BPC1 2017-09-12T20:20:08.955Z,1505247608.955 [BPC1] No Fault, FailCount= 1 2017-09-12T20:20:12.488Z,1505247612.488 [DAT](DEBUG): Teledyne Benthos ATM-900 Series MF Frequency Band Directional Acoustic Transponder version 8.3.1 Jan 3 2000 06:13:19 Warning battery low CONNECT 2017-09-12T20:20:12.488Z,1505247612.488 [DAT](INFO): Got CONNECT 2017-09-12T20:20:12.500Z,1505247612.500 [DAT](INFO): entering command mode 2017-09-12T20:20:12.860Z,1505247612.860 [DAT](DEBUG): checking for command mode acknowledgment 2017-09-12T20:20:13.252Z,1505247613.252 [DAT](DEBUG): checking for command mode acknowledgment 2017-09-12T20:20:13.664Z,1505247613.664 [DAT](DEBUG): checking for command mode acknowledgment 2017-09-12T20:20:14.074Z,1505247614.074 [DAT](DEBUG): checking for command mode acknowledgment 2017-09-12T20:20:14.075Z,1505247614.075 [DAT](INFO): Found user prompt 2017-09-12T20:20:14.075Z,1505247614.075 [DAT](DEBUG): read user prompt 1: user:1> 2017-09-12T20:20:14.075Z,1505247614.075 [DAT](INFO): command mode acknowledged 2017-09-12T20:20:14.454Z,1505247614.454 [DAT](INFO): setting local address to 2 2017-09-12T20:20:14.861Z,1505247614.861 [DAT](DEBUG): checking for local address setting acknowledgment 2017-09-12T20:20:14.862Z,1505247614.862 [DAT](INFO): set local address to 2 2017-09-12T20:20:15.268Z,1505247615.268 [DAT](INFO): Found user prompt 2017-09-12T20:20:15.269Z,1505247615.269 [DAT](DEBUG): read user prompt 2: user:2> 2017-09-12T20:20:33.736Z,1505247633.736 [SBIT](IMPORTANT): Beginning Startup BIT 2017-09-12T20:20:33.757Z,1505247633.757 [CBIT](IMPORTANT): Beginning ground fault scan 2017-09-12T20:20:42.404Z,1505247642.404 [CommandLine](IMPORTANT): got command restart application 2017-09-12T20:20:43.408Z,1505247643.408 [Supervisor](INFO): Stop Mission called by Supervisor::terminate 2017-09-12T20:20:43.414Z,1505247643.414 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2017-09-12T20:20:43.414Z,1505247643.414 [CommandLine ThreadHandler](INFO): Thread cancelled. 2017-09-12T20:20:43.429Z,1505247643.429 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2017-09-12T20:20:43.429Z,1505247643.429 [CommandLine ThreadHandler](INFO): Thread cancelled. 2017-09-12T20:20:43.429Z,1505247643.429 [CommandLine](INFO): Join timeout helper Thread ID is 5498 2017-09-12T20:20:43.441Z,1505247643.441 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2017-09-12T20:20:43.441Z,1505247643.441 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2017-09-12T20:20:43.443Z,1505247643.443 [NavChartDb](INFO): Join timeout helper Thread ID is 5499 2017-09-12T20:20:44.468Z,1505247644.468 [CBIT](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): 4.657929 CHAN A1 (24V): 0.027559 CHAN A2 (12V): -0.001868 CHAN A3 (5V): 0.000279 CHAN B0 (3.3V): -0.000134 CHAN B1 (3.15aV): 4.767929 CHAN B2 (3.15bV): 0.002299 CHAN B3 (