2017-09-11T22:58:52.259Z,1505170732.259 [Supervisor](DEBUG): Initializing supervisor. 2017-09-11T22:58:52.263Z,1505170732.263 [SyncHandler](DEBUG): Created PCaller Thread at 4051A4E0 2017-09-11T22:58:52.263Z,1505170732.263 [SyncHandler](INFO): Protected caller Thread ID is 1206 2017-09-11T22:58:52.264Z,1505170732.264 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2017-09-11T22:58:52.265Z,1505170732.265 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4054A4E0 2017-09-11T22:58:52.265Z,1505170732.265 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 1207 2017-09-11T22:58:52.270Z,1505170732.270 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2017-09-11T22:58:52.285Z,1505170732.285 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2017-09-11T22:58:52.287Z,1505170732.287 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 4057A4E0 2017-09-11T22:58:52.287Z,1505170732.287 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 1208 2017-09-11T22:58:52.288Z,1505170732.288 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2017-09-11T22:58:52.289Z,1505170732.289 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405AA4E0 2017-09-11T22:58:52.290Z,1505170732.290 [logger ThreadHandler](INFO): Protected caller Thread ID is 1209 2017-09-11T22:58:52.292Z,1505170732.292 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2017-09-11T22:58:52.293Z,1505170732.293 [Supervisor](INFO): Looking for Config files in directory: Config/ 2017-09-11T22:58:52.295Z,1505170732.295 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2017-09-11T22:58:52.498Z,1505170732.498 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2017-09-11T22:58:52.499Z,1505170732.499 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2017-09-11T22:58:52.640Z,1505170732.640 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2017-09-11T22:58:52.641Z,1505170732.641 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2017-09-11T22:58:53.024Z,1505170733.024 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2017-09-11T22:58:53.025Z,1505170733.025 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2017-09-11T22:58:53.177Z,1505170733.177 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2017-09-11T22:58:53.178Z,1505170733.178 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2017-09-11T22:58:53.263Z,1505170733.263 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2017-09-11T22:58:53.487Z,1505170733.487 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2017-09-11T22:58:53.488Z,1505170733.488 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2017-09-11T22:58:53.597Z,1505170733.597 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2017-09-11T22:58:53.598Z,1505170733.598 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2017-09-11T22:58:53.933Z,1505170733.933 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2017-09-11T22:58:53.934Z,1505170733.934 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2017-09-11T22:58:54.452Z,1505170734.452 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2017-09-11T22:58:54.453Z,1505170734.453 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2017-09-11T22:58:54.806Z,1505170734.806 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2017-09-11T22:58:54.807Z,1505170734.807 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2017-09-11T22:58:55.423Z,1505170735.423 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2017-09-11T22:58:55.424Z,1505170735.424 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2017-09-11T22:58:55.637Z,1505170735.637 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2017-09-11T22:58:55.637Z,1505170735.637 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2017-09-11T22:58:55.744Z,1505170735.744 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2017-09-11T22:58:55.745Z,1505170735.745 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2017-09-11T22:58:56.297Z,1505170736.297 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2017-09-11T22:58:56.298Z,1505170736.298 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2017-09-11T22:58:56.415Z,1505170736.415 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2017-09-11T22:58:56.418Z,1505170736.418 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/ 2017-09-11T22:58:56.418Z,1505170736.418 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg 2017-09-11T22:58:56.718Z,1505170736.718 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2017-09-11T22:58:56.719Z,1505170736.719 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg 2017-09-11T22:58:56.826Z,1505170736.826 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg 2017-09-11T22:58:56.923Z,1505170736.923 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg 2017-09-11T22:58:57.032Z,1505170737.032 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg 2017-09-11T22:58:57.123Z,1505170737.123 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg 2017-09-11T22:58:57.261Z,1505170737.261 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg 2017-09-11T22:58:57.432Z,1505170737.432 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg 2017-09-11T22:58:57.552Z,1505170737.552 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg 2017-09-11T22:58:57.650Z,1505170737.650 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg 2017-09-11T22:58:57.738Z,1505170737.738 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg 2017-09-11T22:58:57.937Z,1505170737.937 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg 2017-09-11T22:58:58.018Z,1505170738.018 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/root/ 2017-09-11T22:58:58.018Z,1505170738.018 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2017-09-11T22:58:58.026Z,1505170738.026 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2017-09-11T22:58:58.153Z,1505170738.153 [SBIT](DEBUG): Construct Startup Built In Test. 2017-09-11T22:58:58.190Z,1505170738.190 [SBIT] Loaded 2017-09-11T22:58:58.190Z,1505170738.190 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2017-09-11T22:58:58.191Z,1505170738.191 [IBIT](DEBUG): Construct Initiated Built In Test. 2017-09-11T22:58:58.226Z,1505170738.226 [IBIT] Loaded 2017-09-11T22:58:58.226Z,1505170738.226 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2017-09-11T22:58:58.231Z,1505170738.231 [CBIT](DEBUG): Construct Continuous Built In Test. 2017-09-11T22:58:58.468Z,1505170738.468 [CBIT] Loaded 2017-09-11T22:58:58.468Z,1505170738.468 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2017-09-11T22:58:58.468Z,1505170738.468 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2017-09-11T22:58:58.469Z,1505170738.469 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2017-09-11T22:58:58.540Z,1505170738.540 [VerticalControl](DEBUG): Construct VerticalControl. 2017-09-11T22:58:58.661Z,1505170738.661 [VerticalControl] Loaded 2017-09-11T22:58:58.661Z,1505170738.661 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2017-09-11T22:58:58.662Z,1505170738.662 [HorizontalControl](DEBUG): Construct HorizontalControl. 2017-09-11T22:58:58.740Z,1505170738.740 [HorizontalControl] Loaded 2017-09-11T22:58:58.740Z,1505170738.740 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2017-09-11T22:58:58.741Z,1505170738.741 [SpeedControl](DEBUG): Construct SpeedControl. 2017-09-11T22:58:58.748Z,1505170738.748 [SpeedControl] Loaded 2017-09-11T22:58:58.748Z,1505170738.748 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2017-09-11T22:58:58.749Z,1505170738.749 [LoopControl](DEBUG): Construct LoopControl. 2017-09-11T22:58:58.750Z,1505170738.750 [LoopControl] Loaded 2017-09-11T22:58:58.750Z,1505170738.750 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2017-09-11T22:58:58.751Z,1505170738.751 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2017-09-11T22:58:58.751Z,1505170738.751 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2017-09-11T22:58:58.778Z,1505170738.778 [DepthRateCalculator] Loaded 2017-09-11T22:58:58.778Z,1505170738.778 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2017-09-11T22:58:58.785Z,1505170738.785 [PitchRateCalculator] Loaded 2017-09-11T22:58:58.785Z,1505170738.785 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2017-09-11T22:58:58.804Z,1505170738.804 [SpeedCalculator] Loaded 2017-09-11T22:58:58.804Z,1505170738.804 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2017-09-11T22:58:58.830Z,1505170738.830 [TempGradientCalculator] Loaded 2017-09-11T22:58:58.831Z,1505170738.831 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2017-09-11T22:58:58.850Z,1505170738.850 [VerticalTemperatureHomogeneityIndexCalculator] Loaded 2017-09-11T22:58:58.850Z,1505170738.850 [ComponentRegistry](DEBUG): SyncComponent "VerticalTemperatureHomogeneityIndexCalculator" handled in the control thread. 2017-09-11T22:58:58.856Z,1505170738.856 [YawRateCalculator] Loaded 2017-09-11T22:58:58.857Z,1505170738.857 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2017-09-11T22:58:58.857Z,1505170738.857 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2017-09-11T22:58:58.858Z,1505170738.858 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2017-09-11T22:58:58.944Z,1505170738.944 [StratificationFrontDetector](INFO): threshold set to: 0.399988 degC 2017-09-11T22:58:58.944Z,1505170738.944 [StratificationFrontDetector](DEBUG): (re)initializing 2017-09-11T22:58:58.944Z,1505170738.944 [StratificationFrontDetector] Loaded 2017-09-11T22:58:58.944Z,1505170738.944 [ComponentRegistry](DEBUG): SyncComponent "StratificationFrontDetector" handled in the control thread. 2017-09-11T22:58:58.945Z,1505170738.945 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2017-09-11T22:58:58.946Z,1505170738.946 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2017-09-11T22:58:59.180Z,1505170739.180 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2017-09-11T22:58:59.181Z,1505170739.181 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2017-09-11T22:58:59.295Z,1505170739.295 [DeadReckonUsingMultipleVelocitySources] Loaded 2017-09-11T22:58:59.295Z,1505170739.295 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2017-09-11T22:58:59.364Z,1505170739.364 [DeadReckonUsingSpeedCalculator] Loaded 2017-09-11T22:58:59.364Z,1505170739.364 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread. 2017-09-11T22:58:59.385Z,1505170739.385 [NavChart] Loaded 2017-09-11T22:58:59.385Z,1505170739.385 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2017-09-11T22:58:59.391Z,1505170739.391 [UniversalFixResidualReporter] Loaded 2017-09-11T22:58:59.391Z,1505170739.391 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2017-09-11T22:58:59.392Z,1505170739.392 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2017-09-11T22:58:59.392Z,1505170739.392 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2017-09-11T22:58:59.407Z,1505170739.407 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2017-09-11T22:58:59.408Z,1505170739.408 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2017-09-11T22:58:59.745Z,1505170739.745 [Aanderaa_O2] Loaded 2017-09-11T22:58:59.745Z,1505170739.745 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread. 2017-09-11T22:58:59.931Z,1505170739.931 [CTD_NeilBrown] Loaded 2017-09-11T22:58:59.931Z,1505170739.931 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread. 2017-09-11T22:58:59.932Z,1505170739.932 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 408154E0 2017-09-11T22:58:59.933Z,1505170739.933 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 1292 2017-09-11T22:58:59.951Z,1505170739.951 [PAR_Licor] Loaded 2017-09-11T22:58:59.952Z,1505170739.952 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2017-09-11T22:59:00.011Z,1505170740.011 [WetLabsBB2FL] Loaded 2017-09-11T22:59:00.011Z,1505170740.011 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2017-09-11T22:59:00.012Z,1505170740.012 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 408454E0 2017-09-11T22:59:00.012Z,1505170740.012 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 1293 2017-09-11T22:59:00.013Z,1505170740.013 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2017-09-11T22:59:00.014Z,1505170740.014 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2017-09-11T22:59:00.295Z,1505170740.295 [DataOverHttps] Loaded 2017-09-11T22:59:00.295Z,1505170740.295 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread. 2017-09-11T22:59:00.312Z,1505170740.312 [Depth_Keller] Loaded 2017-09-11T22:59:00.313Z,1505170740.313 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2017-09-11T22:59:00.319Z,1505170740.319 [DropWeight] Loaded 2017-09-11T22:59:00.319Z,1505170740.319 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2017-09-11T22:59:00.432Z,1505170740.432 [NAL9602] Loaded 2017-09-11T22:59:00.433Z,1505170740.433 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2017-09-11T22:59:00.444Z,1505170740.444 [Onboard] Loaded 2017-09-11T22:59:00.445Z,1505170740.445 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2017-09-11T22:59:00.453Z,1505170740.453 [Radio_Surface] Loaded 2017-09-11T22:59:00.454Z,1505170740.454 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2017-09-11T22:59:00.455Z,1505170740.455 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 40ACB4E0 2017-09-11T22:59:00.456Z,1505170740.456 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 1294 2017-09-11T22:59:00.630Z,1505170740.630 [DAT] Loaded 2017-09-11T22:59:00.630Z,1505170740.630 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread. 2017-09-11T22:59:00.689Z,1505170740.689 [PNI_TCM] Loaded 2017-09-11T22:59:00.689Z,1505170740.689 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread. 2017-09-11T22:59:03.321Z,1505170743.321 [BPC1] Loaded 2017-09-11T22:59:03.322Z,1505170743.322 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2017-09-11T22:59:03.322Z,1505170743.322 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2017-09-11T22:59:03.323Z,1505170743.323 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2017-09-11T22:59:03.425Z,1505170743.425 [BuoyancyServo] Loaded 2017-09-11T22:59:03.425Z,1505170743.425 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2017-09-11T22:59:03.441Z,1505170743.441 [ElevatorServo] Loaded 2017-09-11T22:59:03.441Z,1505170743.441 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2017-09-11T22:59:03.456Z,1505170743.456 [MassServo] Loaded 2017-09-11T22:59:03.456Z,1505170743.456 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2017-09-11T22:59:03.471Z,1505170743.471 [RudderServo] Loaded 2017-09-11T22:59:03.472Z,1505170743.472 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2017-09-11T22:59:03.486Z,1505170743.486 [ThrusterServo] Loaded 2017-09-11T22:59:03.486Z,1505170743.486 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2017-09-11T22:59:03.487Z,1505170743.487 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2017-09-11T22:59:03.487Z,1505170743.487 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2017-09-11T22:59:03.584Z,1505170743.584 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2017-09-11T22:59:03.585Z,1505170743.585 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2017-09-11T22:59:03.610Z,1505170743.610 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2017-09-11T22:59:03.615Z,1505170743.615 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2017-09-11T22:59:03.616Z,1505170743.616 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2017-09-11T22:59:03.627Z,1505170743.627 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2017-09-11T22:59:03.628Z,1505170743.628 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B9F4E0 2017-09-11T22:59:03.629Z,1505170743.629 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 1295 2017-09-11T22:59:03.635Z,1505170743.635 [Supervisor](INFO): Main Thread ID is 1205 2017-09-11T22:59:03.636Z,1505170743.636 [Supervisor](DEBUG): Running supervisor. 2017-09-11T22:59:03.636Z,1505170743.636 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1296 2017-09-11T22:59:03.640Z,1505170743.640 [controlThread ThreadHandler](INFO): Handler Thread ID is 1297 2017-09-11T22:59:03.640Z,1505170743.640 [controlThread](DEBUG): Initializing ControlThread 2017-09-11T22:59:03.641Z,1505170743.641 [SBIT](INFO): Initialize SBIT Component. 2017-09-11T22:59:03.642Z,1505170743.642 [SBIT](IMPORTANT): git: 2017-08-02-81-g2dedf71 2017-09-11T22:59:03.642Z,1505170743.642 [SBIT](INFO): git hash: 2dedf719d304b5c3f7e3acd061a0c8109ea4feed 2017-09-11T22:59:03.644Z,1505170743.644 [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-11T22:59:03.645Z,1505170743.645 [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-11T22:59:03.646Z,1505170743.646 [SBIT](INFO): Beginning SBIT in 71.000000 seconds. 2017-09-11T22:59:03.646Z,1505170743.646 [IBIT](INFO): Initialize IBIT Component. 2017-09-11T22:59:03.647Z,1505170743.647 [CBIT](DEBUG): Initialize CBIT Component. 2017-09-11T22:59:03.648Z,1505170743.648 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2017-09-11T22:59:03.649Z,1505170743.649 [logger ThreadHandler](INFO): Handler Thread ID is 1298 2017-09-11T22:59:03.677Z,1505170743.677 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 1299 2017-09-11T22:59:03.678Z,1505170743.678 [CTD_NeilBrown](INFO): Powering down 2017-09-11T22:59:03.717Z,1505170743.717 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 1300 2017-09-11T22:59:03.718Z,1505170743.718 [WetLabsBB2FL](INFO): Powering down 2017-09-11T22:59:03.728Z,1505170743.728 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2017-09-11T22:59:03.731Z,1505170743.731 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2017-09-11T22:59:03.731Z,1505170743.731 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2017-09-11T22:59:03.732Z,1505170743.732 [LoopControl](DEBUG): Initialize LoopControlComponent. 2017-09-11T22:59:03.733Z,1505170743.733 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2017-09-11T22:59:03.733Z,1505170743.733 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2017-09-11T22:59:03.733Z,1505170743.733 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2017-09-11T22:59:03.734Z,1505170743.734 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2017-09-11T22:59:03.735Z,1505170743.735 [VerticalTemperatureHomogeneityIndexCalculator](DEBUG): (re)initializing 2017-09-11T22:59:03.735Z,1505170743.735 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2017-09-11T22:59:03.740Z,1505170743.740 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component. 2017-09-11T22:59:03.741Z,1505170743.741 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s. 2017-09-11T22:59:03.742Z,1505170743.742 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s. 2017-09-11T22:59:03.742Z,1505170743.742 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2017-09-11T22:59:03.743Z,1505170743.743 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2017-09-11T22:59:03.743Z,1505170743.743 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2017-09-11T22:59:03.744Z,1505170743.744 [NavChart](DEBUG): Initialize NavChart Navigation. 2017-09-11T22:59:03.744Z,1505170743.744 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2017-09-11T22:59:03.777Z,1505170743.777 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 1301 2017-09-11T22:59:03.788Z,1505170743.788 [Radio_Surface](INFO): Powering up 2017-09-11T22:59:03.788Z,1505170743.788 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2017-09-11T22:59:03.797Z,1505170743.797 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1302 2017-09-11T22:59:03.801Z,1505170743.801 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2017-09-11T22:59:03.802Z,1505170743.802 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2017-09-11T22:59:03.802Z,1505170743.802 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2017-09-11T22:59:03.802Z,1505170743.802 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2017-09-11T22:59:03.802Z,1505170743.802 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2017-09-11T22:59:03.803Z,1505170743.803 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2017-09-11T22:59:03.803Z,1505170743.803 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000 2017-09-11T22:59:03.803Z,1505170743.803 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2017-09-11T22:59:03.803Z,1505170743.803 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2017-09-11T22:59:03.803Z,1505170743.803 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2017-09-11T22:59:03.804Z,1505170743.804 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000 2017-09-11T22:59:03.804Z,1505170743.804 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2017-09-11T22:59:03.804Z,1505170743.804 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000 2017-09-11T22:59:03.804Z,1505170743.804 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2017-09-11T22:59:03.805Z,1505170743.805 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000 2017-09-11T22:59:03.805Z,1505170743.805 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2017-09-11T22:59:03.845Z,1505170743.845 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2017-09-11T22:59:03.895Z,1505170743.895 [MissionManager](DEBUG): 2017-09-11T22:59:03.895Z,1505170743.895 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2017-09-11T22:59:03.963Z,1505170743.963 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2017-09-11T22:59:03.964Z,1505170743.964 [Default:A.Wait](DEBUG): Construct Wait. 2017-09-11T22:59:03.967Z,1505170743.967 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2017-09-11T22:59:04.016Z,1505170744.016 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2017-09-11T22:59:04.019Z,1505170744.019 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2017-09-11T22:59:04.051Z,1505170744.051 [Default:E.Execute](DEBUG): Construct Execute. 2017-09-11T22:59:04.055Z,1505170744.055 [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-11T22:59:04.066Z,1505170744.066 [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-11T22:59:04.273Z,1505170744.273 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2017-09-11T22:59:04.338Z,1505170744.338 [Depth_Keller](ERROR): Pressure reading out of range: 1831.023193 decibar 2017-09-11T22:59:04.436Z,1505170744.436 [DAT](INFO): Powering up 2017-09-11T22:59:04.436Z,1505170744.436 [DAT](DEBUG): Initializing DAT. 2017-09-11T22:59:04.666Z,1505170744.666 [DepthRateCalculator](ERROR): Depth measurement is not active 2017-09-11T22:59:04.791Z,1505170744.791 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2017-09-11T22:59:04.818Z,1505170744.818 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2017-09-11T22:59:04.963Z,1505170744.963 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2017-09-11T22:59:04.971Z,1505170744.971 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2017-09-11T22:59:05.003Z,1505170745.003 [ElevatorServo](DEBUG): Initializing EZServoServo. 2017-09-11T22:59:05.007Z,1505170745.007 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2017-09-11T22:59:05.043Z,1505170745.043 [MassServo](DEBUG): Initializing EZServoServo. 2017-09-11T22:59:05.051Z,1505170745.051 [MassServo](DEBUG): Initializing MassServo. 2017-09-11T22:59:05.080Z,1505170745.080 [RudderServo](DEBUG): Initializing EZServoServo. 2017-09-11T22:59:05.087Z,1505170745.087 [RudderServo](DEBUG): Initializing RudderServo. 2017-09-11T22:59:05.093Z,1505170745.093 [ThrusterServo](DEBUG): Initializing EZServoServo. 2017-09-11T22:59:05.099Z,1505170745.099 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2017-09-11T22:59:05.448Z,1505170745.448 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2017-09-11T22:59:05.449Z,1505170745.449 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2017-09-11T22:59:05.610Z,1505170745.610 [NAL9602](INFO): Powering up NAL9602 2017-09-11T22:59:05.657Z,1505170745.657 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2017-09-11T22:59:05.658Z,1505170745.658 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2017-09-11T22:59:06.168Z,1505170746.168 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2017-09-11T22:59:06.170Z,1505170746.170 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2017-09-11T22:59:06.537Z,1505170746.537 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2017-09-11T22:59:06.538Z,1505170746.538 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2017-09-11T22:59:06.939Z,1505170746.939 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2017-09-11T22:59:06.940Z,1505170746.940 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2017-09-11T22:59:07.390Z,1505170747.390 [Aanderaa_O2](INFO): Powering down 2017-09-11T22:59:07.568Z,1505170747.568 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2017-09-11T22:59:07.569Z,1505170747.569 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2017-09-11T22:59:07.815Z,1505170747.815 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2017-09-11T22:59:07.817Z,1505170747.817 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2017-09-11T22:59:16.643Z,1505170756.643 [NAL9602](INFO): NAL9602 initialized 2017-09-11T22:59:53.873Z,1505170793.873 [DAT](DEBUG): 2017-09-11T22:59:53.874Z,1505170793.874 [DAT](DEBUG): Teledyne Benthos ATM-900 Series 2017-09-11T22:59:53.875Z,1505170793.875 [DAT](DEBUG): MF Frequency Band 2017-09-11T22:59:53.877Z,1505170793.877 [DAT](DEBUG): Directional Acoustic Transponder version 8.3.1 2017-09-11T22:59:53.877Z,1505170793.877 [DAT](DEBUG): Jan 3 2000 01:41:21 2017-09-11T22:59:54.281Z,1505170794.281 [DAT](DEBUG): Warning battery low 2017-09-11T23:00:04.685Z,1505170804.685 [DAT](FAULT): failed to initialize; deviceResponse_ loaded: Warning battery low , available: CONNECT 02400 bits/sec 1 of 4 @전 2017-09-11T23:00:04.685Z,1505170804.685 [DAT] Communications Fault, FailCount= 1 2017-09-11T23:00:04.685Z,1505170804.685 [DAT](ERROR): Communications Fault 2017-09-11T23:00:04.800Z,1505170804.800 [CBIT](ERROR): Communications Fault in component: DAT 2017-09-11T23:00:05.074Z,1505170805.074 [DAT](INFO): Powering down 2017-09-11T23:00:05.953Z,1505170805.953 [CBIT](INFO): Clearing failed state for component DAT 2017-09-11T23:00:05.953Z,1505170805.953 [DAT] No Fault, FailCount= 1 2017-09-11T23:00:08.275Z,1505170808.275 [DAT](INFO): Powering up 2017-09-11T23:00:08.275Z,1505170808.275 [DAT](DEBUG): Initializing DAT. 2017-09-11T23:00:15.180Z,1505170815.180 [SBIT](IMPORTANT): Beginning Startup BIT 2017-09-11T23:00:15.185Z,1505170815.185 [CBIT](IMPORTANT): Beginning ground fault scan 2017-09-11T23:00:25.777Z,1505170825.777 [CBIT](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): 4.657929 CHAN A1 (24V): 0.027783 CHAN A2 (12V): -0.002082 CHAN A3 (5V): 0.000389 CHAN B0 (3.3V): 0.000296 CHAN B1 (3.15aV): 0.000057 CHAN B2 (3.15bV): -0.000182 CHAN B3 (GND): -0.000412 OPEN: -0.000215 Full Scale Calc: 4.765 mA, -1.589 mA 2017-09-11T23:00:57.129Z,1505170857.129 [DAT](DEBUG): 2017-09-11T23:00:57.131Z,1505170857.131 [DAT](DEBUG): Teledyne Benthos ATM-900 Series 2017-09-11T23:00:57.132Z,1505170857.132 [DAT](DEBUG): MF Frequency Band 2017-09-11T23:00:57.714Z,1505170857.714 [DAT](DEBUG): Directional Acoustic Transponder version 8.3.1 2017-09-11T23:00:57.715Z,1505170857.715 [DAT](DEBUG): Jan 3 2000 01:42:24 2017-09-11T23:00:57.716Z,1505170857.716 [DAT](DEBUG): Warning battery low 2017-09-11T23:01:08.657Z,1505170868.657 [DAT](FAULT): failed to initialize; deviceResponse_ loaded: Warning battery low , available: CONNECT 02400 bits/sec 1 of 4 @전 2017-09-11T23:01:08.658Z,1505170868.658 [DAT] Communications Fault, FailCount= 2 2017-09-11T23:01:08.658Z,1505170868.658 [DAT](ERROR): Communications Fault 2017-09-11T23:01:08.805Z,1505170868.805 [CBIT](ERROR): Communications Fault in component: DAT 2017-09-11T23:01:08.868Z,1505170868.868 [DAT](INFO): Powering down 2017-09-11T23:01:09.177Z,1505170869.177 [SBIT](IMPORTANT): SBIT PASSED 2017-09-11T23:01:09.296Z,1505170869.296 [MissionManager](IMPORTANT): Started mission Startup 2017-09-11T23:01:09.297Z,1505170869.297 [Startup] Running Loop=1 2017-09-11T23:01:09.297Z,1505170869.297 [Startup](DEBUG): Aggregate::initialize Startup 2017-09-11T23:01:09.297Z,1505170869.297 [Startup:A.GoToSurface] Running Loop=1 2017-09-11T23:01:09.297Z,1505170869.297 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2017-09-11T23:01:09.298Z,1505170869.298 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2017-09-11T23:01:09.299Z,1505170869.299 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2017-09-11T23:01:09.299Z,1505170869.299 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2017-09-11T23:01:09.299Z,1505170869.299 [Startup:A.GoToSurface](DEBUG): No pitch timeout specified. Using default value of 20.000000 seconds. 2017-09-11T23:01:09.300Z,1505170869.300 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2017-09-11T23:01:09.315Z,1505170869.315 [Startup:StartupSatComms] Running Loop=1 2017-09-11T23:01:09.315Z,1505170869.315 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2017-09-11T23:01:09.315Z,1505170869.315 [Startup:StartupSatComms:A] Running Loop=1 2017-09-11T23:01:09.625Z,1505170869.625 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003806 2017-09-11T23:01:09.708Z,1505170869.708 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2017-09-11T23:01:09.739Z,1505170869.739 [CBIT](INFO): Clearing failed state for component DAT 2017-09-11T23:01:09.739Z,1505170869.739 [DAT] No Fault, FailCount= 2 2017-09-11T23:01:12.054Z,1505170872.054 [DAT](INFO): Powering up 2017-09-11T23:01:12.055Z,1505170872.055 [DAT](DEBUG): Initializing DAT. 2017-09-11T23:02:00.854Z,1505170920.854 [DAT](DEBUG): 2017-09-11T23:02:01.256Z,1505170921.256 [DAT](DEBUG): Teledyne Benthos ATM-900 Series 2017-09-11T23:02:01.257Z,1505170921.257 [DAT](DEBUG): MF Frequency Band 2017-09-11T23:02:01.258Z,1505170921.258 [DAT](DEBUG): Directional Acoustic Transponder version 8.3.1 2017-09-11T23:02:01.259Z,1505170921.259 [DAT](DEBUG): Jan 3 2000 01:43:28 2017-09-11T23:02:01.651Z,1505170921.651 [DAT](DEBUG): Warning battery low 2017-09-11T23:02:04.118Z,1505170924.118 [DeadReckonUsingMultipleVelocitySources](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2017-09-11T23:02:04.118Z,1505170924.118 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2017-09-11T23:02:04.118Z,1505170924.118 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2017-09-11T23:02:04.121Z,1505170924.121 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2017-09-11T23:02:04.121Z,1505170924.121 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1 2017-09-11T23:02:04.121Z,1505170924.121 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2017-09-11T23:02:04.174Z,1505170924.174 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2017-09-11T23:02:04.174Z,1505170924.174 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2017-09-11T23:02:04.569Z,1505170924.569 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2017-09-11T23:02:04.569Z,1505170924.569 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2017-09-11T23:02:04.569Z,1505170924.569 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2017-09-11T23:02:04.569Z,1505170924.569 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1 2017-09-11T23:02:04.914Z,1505170924.914 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component. 2017-09-11T23:02:04.914Z,1505170924.914 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s. 2017-09-11T23:02:04.914Z,1505170924.914 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s. 2017-09-11T23:02:04.919Z,1505170924.919 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2017-09-11T23:02:04.920Z,1505170924.920 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2017-09-11T23:02:04.920Z,1505170924.920 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2017-09-11T23:02:05.300Z,1505170925.300 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 1.2 s old, using for 20.0 s. 2017-09-11T23:02:05.692Z,1505170925.692 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 1.6 s old, using for 20.0 s. 2017-09-11T23:02:09.695Z,1505170929.695 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 5.6 s old, using for 20.0 s. 2017-09-11T23:02:09.702Z,1505170929.702 [Startup:StartupSatComms:A](INFO): Timed out from 2017-09-11T23:01:09.3Z 2017-09-11T23:02:09.702Z,1505170929.702 [Startup:StartupSatComms:A] Stopped 2017-09-11T23:02:09.702Z,1505170929.702 [Startup:StartupSatComms:B] Running Loop=1 2017-09-11T23:02:09.855Z,1505170929.855 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 5.8 s old, using for 20.0 s. 2017-09-11T23:02:09.860Z,1505170929.860 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2017-09-11T23:02:10.826Z,1505170930.826 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.7 s old, using for 20.0 s. 2017-09-11T23:02:11.032Z,1505170931.032 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.9 s old, using for 20.0 s. 2017-09-11T23:02:11.429Z,1505170931.429 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 7.3 s old, using for 20.0 s. 2017-09-11T23:02:11.853Z,1505170931.853 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 7.8 s old, using for 20.0 s. 2017-09-11T23:02:15.737Z,1505170935.737 [DAT](FAULT): failed to initialize; deviceResponse_ loaded: Warning battery low , available: CONNECT 02400 bits/sec 1 of 4 @전 2017-09-11T23:02:15.738Z,1505170935.738 [DAT] Communications Fault, FailCount= 3 2017-09-11T23:02:15.738Z,1505170935.738 [DAT](ERROR): Communications Fault 2017-09-11T23:02:15.757Z,1505170935.757 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 11.7 s old, using for 20.0 s. 2017-09-11T23:02:15.818Z,1505170935.818 [CBIT](ERROR): Communications Fault in component: DAT 2017-09-11T23:02:15.848Z,1505170935.848 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20170911T225148/Courier0008.lzma 2017-09-11T23:02:15.890Z,1505170935.890 [DAT](INFO): Powering down 2017-09-11T23:02:16.057Z,1505170936.057 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 12.0 s old, using for 20.0 s. 2017-09-11T23:02:16.307Z,1505170936.307 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 12.2 s old, using for 20.0 s. 2017-09-11T23:02:16.644Z,1505170936.644 [DataOverHttps](INFO): Moved sent file to Logs/20170911T225148/Courier0008.lzma.bak 2017-09-11T23:02:16.644Z,1505170936.644 [DataOverHttps](INFO): SBD MOMSN=5085961 2017-09-11T23:02:16.732Z,1505170936.732 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 12.6 s old, using for 20.0 s. 2017-09-11T23:02:16.774Z,1505170936.774 [CBIT](INFO): Clearing failed state for component DAT 2017-09-11T23:02:16.774Z,1505170936.774 [DAT] No Fault, FailCount= 3 2017-09-11T23:02:17.330Z,1505170937.330 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 13.2 s old, using for 20.0 s. 2017-09-11T23:02:17.499Z,1505170937.499 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 13.4 s old, using for 20.0 s. 2017-09-11T23:02:20.776Z,1505170940.776 [DAT](INFO): Powering up 2017-09-11T23:02:20.777Z,1505170940.777 [DAT](DEBUG): Initializing DAT. 2017-09-11T23:02:20.835Z,1505170940.835 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 16.7 s old, using for 20.0 s. 2017-09-11T23:02:21.043Z,1505170941.043 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 16.9 s old, using for 20.0 s. 2017-09-11T23:02:21.355Z,1505170941.355 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 17.3 s old, using for 20.0 s. 2017-09-11T23:02:21.771Z,1505170941.771 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 17.7 s old, using for 20.0 s. 2017-09-11T23:02:22.147Z,1505170942.147 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 18.1 s old, using for 20.0 s. 2017-09-11T23:02:22.533Z,1505170942.533 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 18.4 s old, using for 20.0 s. 2017-09-11T23:02:25.993Z,1505170945.993 [DataOverHttps](INFO): Sending 221 bytes from file Logs/20170911T225148/Express0009.lzma 2017-09-11T23:02:26.768Z,1505170946.768 [DataOverHttps](INFO): Moved sent file to Logs/20170911T225148/Express0009.lzma.bak 2017-09-11T23:02:26.768Z,1505170946.768 [DataOverHttps](INFO): SBD MOMSN=5085963 2017-09-11T23:02:36.077Z,1505170956.077 [DataOverHttps](INFO): Sending 623 bytes from file Logs/20170911T225852/Express0001.lzma 2017-09-11T23:02:41.806Z,1505170961.806 [DataOverHttps](INFO): Moved sent file to Logs/20170911T225852/Express0001.lzma.bak 2017-09-11T23:02:41.806Z,1505170961.806 [DataOverHttps](INFO): SBD MOMSN=5085967 2017-09-11T23:02:42.382Z,1505170962.382 [Startup:StartupSatComms:B] Stopped 2017-09-11T23:02:42.382Z,1505170962.382 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2017-09-11T23:02:42.382Z,1505170962.382 [Startup:StartupSatComms] Stopped 2017-09-11T23:02:42.382Z,1505170962.382 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2017-09-11T23:02:42.383Z,1505170962.383 [Startup](INFO): Completed Startup 2017-09-11T23:02:42.384Z,1505170962.384 [MissionManager](INFO): Startup is completed. 2017-09-11T23:02:42.384Z,1505170962.384 [MissionManager](INFO): Uninitializing Mission Startup 2017-09-11T23:02:42.384Z,1505170962.384 [Startup] Stopped 2017-09-11T23:02:42.384Z,1505170962.384 [Startup](DEBUG): Aggregate::uninitialize Startup 2017-09-11T23:02:42.384Z,1505170962.384 [Startup:A.GoToSurface] Stopped 2017-09-11T23:02:42.384Z,1505170962.384 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2017-09-11T23:02:42.589Z,1505170962.589 [MissionManager](IMPORTANT): Started mission Default 2017-09-11T23:02:42.589Z,1505170962.589 [Default] Running Loop=1 2017-09-11T23:02:42.589Z,1505170962.589 [Default](DEBUG): Aggregate::initialize Default 2017-09-11T23:02:42.589Z,1505170962.589 [Default:B.GoToSurface] Running Loop=1 2017-09-11T23:02:42.589Z,1505170962.589 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2017-09-11T23:02:42.590Z,1505170962.590 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2017-09-11T23:02:42.590Z,1505170962.590 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2017-09-11T23:02:42.595Z,1505170962.595 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2017-09-11T23:02:42.595Z,1505170962.595 [Default:B.GoToSurface](DEBUG): No pitch timeout specified. Using default value of 20.000000 seconds. 2017-09-11T23:02:42.596Z,1505170962.596 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2017-09-11T23:02:42.596Z,1505170962.596 [Default:A.Wait] Running Loop=1 2017-09-11T23:02:42.596Z,1505170962.596 [Default:A.Wait](DEBUG): Initialize Wait Component. 2017-09-11T23:02:55.986Z,1505170975.986 [Default:A.Wait](INFO): Done Waiting. 2017-09-11T23:02:55.986Z,1505170975.986 [Default:A.Wait] Stopped 2017-09-11T23:02:55.986Z,1505170975.986 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2017-09-11T23:02:56.380Z,1505170976.380 [Default:CheckIn] Running Loop=1 2017-09-11T23:02:56.380Z,1505170976.380 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2017-09-11T23:02:56.380Z,1505170976.380 [Default:CheckIn:Read_GPS] Running Loop=1 2017-09-11T23:02:56.782Z,1505170976.782 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2017-09-11T23:03:09.939Z,1505170989.939 [DAT](DEBUG): 2017-09-11T23:03:09.940Z,1505170989.940 [DAT](DEBUG): Teledyne Benthos ATM-900 Series 2017-09-11T23:03:09.940Z,1505170989.940 [DAT](DEBUG): MF Frequency Band 2017-09-11T23:03:10.343Z,1505170990.343 [DAT](DEBUG): Directional Acoustic Transponder version 8.3.1 2017-09-11T23:03:10.343Z,1505170990.343 [DAT](DEBUG): Jan 3 2000 01:44:37 2017-09-11T23:03:10.742Z,1505170990.742 [DAT](DEBUG): Warning battery low 2017-09-11T23:03:21.145Z,1505171001.145 [DAT](FAULT): failed to initialize; deviceResponse_ loaded: Warning battery low , available: CONNECT 02400 bits/sec 1 of 4 @전 2017-09-11T23:03:21.145Z,1505171001.145 [DAT] Communications Fault, FailCount= 4 2017-09-11T23:03:21.145Z,1505171001.145 [DAT](ERROR): Communications Fault 2017-09-11T23:03:21.324Z,1505171001.324 [CBIT](ERROR): Communications Fault in component: DAT 2017-09-11T23:03:21.530Z,1505171001.530 [DAT](INFO): Powering down 2017-09-11T23:03:22.423Z,1505171002.423 [CBIT](INFO): Clearing failed state for component DAT 2017-09-11T23:03:22.423Z,1505171002.423 [DAT] No Fault, FailCount= 4 2017-09-11T23:03:24.739Z,1505171004.739 [DAT](INFO): Powering up 2017-09-11T23:03:24.740Z,1505171004.740 [DAT](DEBUG): Initializing DAT. 2017-09-11T23:04:13.744Z,1505171053.744 [DAT](DEBUG): 2017-09-11T23:04:13.746Z,1505171053.746 [DAT](DEBUG): Teledyne Benthos ATM-900 Series 2017-09-11T23:04:13.747Z,1505171053.747 [DAT](DEBUG): MF Frequency Band 2017-09-11T23:04:13.748Z,1505171053.748 [DAT](DEBUG): Directional Acoustic Transponder version 8.3.1 2017-09-11T23:04:13.749Z,1505171053.749 [DAT](DEBUG): Jan 3 2000 01:45:41 2017-09-11T23:04:14.149Z,1505171054.149 [DAT](DEBUG): Warning battery low 2017-09-11T23:04:19.718Z,1505171059.718 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2017-09-11T23:04:24.953Z,1505171064.953 [DAT](FAULT): failed to initialize; deviceResponse_ loaded: Warning battery low , available: CONNECT 02400 bits/sec 1 of 4 @전 2017-09-11T23:04:24.953Z,1505171064.953 [DAT] Communications Fault, FailCount= 5 2017-09-11T23:04:24.953Z,1505171064.953 [DAT](ERROR): Communications Fault 2017-09-11T23:04:25.042Z,1505171065.042 [CBIT](ERROR): Communications Fault in component: DAT 2017-09-11T23:04:25.345Z,1505171065.345 [DAT](INFO): Powering down 2017-09-11T23:04:26.214Z,1505171066.214 [CBIT](INFO): Clearing failed state for component DAT 2017-09-11T23:04:26.214Z,1505171066.214 [DAT] No Fault, FailCount= 5 2017-09-11T23:04:28.561Z,1505171068.561 [DAT](INFO): Powering up 2017-09-11T23:04:28.561Z,1505171068.561 [DAT](DEBUG): Initializing DAT. 2017-09-11T23:05:05.208Z,1505171105.208 [DeadReckonUsingMultipleVelocitySources](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2017-09-11T23:05:05.209Z,1505171105.209 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2 2017-09-11T23:05:05.209Z,1505171105.209 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2017-09-11T23:05:05.249Z,1505171105.249 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2017-09-11T23:05:05.249Z,1505171105.249 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 2 2017-09-11T23:05:05.249Z,1505171105.249 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2017-09-11T23:05:05.304Z,1505171105.304 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2017-09-11T23:05:05.304Z,1505171105.304 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2017-09-11T23:05:05.695Z,1505171105.695 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2017-09-11T23:05:05.695Z,1505171105.695 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2 2017-09-11T23:05:05.696Z,1505171105.696 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2017-09-11T23:05:05.696Z,1505171105.696 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 2 2017-09-11T23:05:05.994Z,1505171105.994 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component. 2017-09-11T23:05:05.994Z,1505171105.994 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s. 2017-09-11T23:05:05.995Z,1505171105.995 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s. 2017-09-11T23:05:05.995Z,1505171105.995 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2017-09-11T23:05:05.996Z,1505171105.996 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2017-09-11T23:05:05.996Z,1505171105.996 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2017-09-11T23:05:06.444Z,1505171106.444 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 1.2 s old, using for 20.0 s. 2017-09-11T23:05:06.826Z,1505171106.826 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 1.6 s old, using for 20.0 s. 2017-09-11T23:05:07.326Z,1505171107.326 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 2.1 s old, using for 20.0 s. 2017-09-11T23:05:07.726Z,1505171107.726 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 2.5 s old, using for 20.0 s. 2017-09-11T23:05:08.009Z,1505171108.009 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 2.8 s old, using for 20.0 s. 2017-09-11T23:05:08.401Z,1505171108.401 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 3.2 s old, using for 20.0 s. 2017-09-11T23:05:08.823Z,1505171108.823 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 3.6 s old, using for 20.0 s. 2017-09-11T23:05:09.244Z,1505171109.244 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.0 s old, using for 20.0 s. 2017-09-11T23:05:09.644Z,1505171109.644 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.4 s old, using for 20.0 s. 2017-09-11T23:05:10.069Z,1505171110.069 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.9 s old, using for 20.0 s. 2017-09-11T23:05:10.461Z,1505171110.461 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 5.2 s old, using for 20.0 s. 2017-09-11T23:05:10.829Z,1505171110.829 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 5.6 s old, using for 20.0 s. 2017-09-11T23:05:11.247Z,1505171111.247 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.0 s old, using for 20.0 s. 2017-09-11T23:05:11.604Z,1505171111.604 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.4 s old, using for 20.0 s. 2017-09-11T23:05:12.025Z,1505171112.025 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.8 s old, using for 20.0 s. 2017-09-11T23:05:12.420Z,1505171112.420 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 7.2 s old, using for 20.0 s. 2017-09-11T23:05:12.850Z,1505171112.850 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 7.6 s old, using for 20.0 s. 2017-09-11T23:05:13.230Z,1505171113.230 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 8.0 s old, using for 20.0 s. 2017-09-11T23:05:13.639Z,1505171113.639 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 8.4 s old, using for 20.0 s. 2017-09-11T23:05:14.040Z,1505171114.040 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 8.8 s old, using for 20.0 s. 2017-09-11T23:05:14.409Z,1505171114.409 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 9.2 s old, using for 20.0 s. 2017-09-11T23:05:14.872Z,1505171114.872 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom t