2017-12-12T22:07:44.796Z,1513116464.796 [Supervisor](DEBUG): Initializing supervisor. 2017-12-12T22:07:44.798Z,1513116464.798 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2017-12-12T22:07:44.799Z,1513116464.799 [SyncHandler](INFO): Protected caller Thread ID is 1222 2017-12-12T22:07:44.799Z,1513116464.799 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2017-12-12T22:07:44.800Z,1513116464.800 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2017-12-12T22:07:44.801Z,1513116464.801 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 1223 2017-12-12T22:07:44.803Z,1513116464.803 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2017-12-12T22:07:44.814Z,1513116464.814 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2017-12-12T22:07:44.815Z,1513116464.815 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2017-12-12T22:07:44.816Z,1513116464.816 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 1224 2017-12-12T22:07:44.816Z,1513116464.816 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2017-12-12T22:07:44.817Z,1513116464.817 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2017-12-12T22:07:44.818Z,1513116464.818 [logger ThreadHandler](INFO): Protected caller Thread ID is 1225 2017-12-12T22:07:44.820Z,1513116464.820 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2017-12-12T22:07:44.820Z,1513116464.820 [Supervisor](INFO): Looking for Config files in directory: Config/ 2017-12-12T22:07:44.821Z,1513116464.821 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2017-12-12T22:07:44.990Z,1513116464.990 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2017-12-12T22:07:44.990Z,1513116464.990 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2017-12-12T22:07:45.124Z,1513116465.124 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2017-12-12T22:07:45.124Z,1513116465.124 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2017-12-12T22:07:45.420Z,1513116465.420 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2017-12-12T22:07:45.421Z,1513116465.421 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2017-12-12T22:07:45.548Z,1513116465.548 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2017-12-12T22:07:45.548Z,1513116465.548 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2017-12-12T22:07:45.627Z,1513116465.627 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2017-12-12T22:07:45.809Z,1513116465.809 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2017-12-12T22:07:45.810Z,1513116465.810 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2017-12-12T22:07:45.904Z,1513116465.904 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2017-12-12T22:07:45.905Z,1513116465.905 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2017-12-12T22:07:46.204Z,1513116466.204 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2017-12-12T22:07:46.205Z,1513116466.205 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2017-12-12T22:07:46.524Z,1513116466.524 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2017-12-12T22:07:46.525Z,1513116466.525 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2017-12-12T22:07:46.797Z,1513116466.797 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2017-12-12T22:07:46.797Z,1513116466.797 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2017-12-12T22:07:47.258Z,1513116467.258 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2017-12-12T22:07:47.259Z,1513116467.259 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2017-12-12T22:07:47.436Z,1513116467.436 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2017-12-12T22:07:47.437Z,1513116467.437 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2017-12-12T22:07:47.531Z,1513116467.531 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2017-12-12T22:07:47.532Z,1513116467.532 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2017-12-12T22:07:47.960Z,1513116467.960 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2017-12-12T22:07:47.961Z,1513116467.961 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2017-12-12T22:07:48.062Z,1513116468.062 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2017-12-12T22:07:48.064Z,1513116468.064 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/ 2017-12-12T22:07:48.065Z,1513116468.065 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg 2017-12-12T22:07:48.287Z,1513116468.287 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2017-12-12T22:07:48.288Z,1513116468.288 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg 2017-12-12T22:07:48.384Z,1513116468.384 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg 2017-12-12T22:07:48.471Z,1513116468.471 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg 2017-12-12T22:07:48.568Z,1513116468.568 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg 2017-12-12T22:07:48.651Z,1513116468.651 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg 2017-12-12T22:07:48.769Z,1513116468.769 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg 2017-12-12T22:07:48.910Z,1513116468.910 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg 2017-12-12T22:07:49.012Z,1513116469.012 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg 2017-12-12T22:07:49.109Z,1513116469.109 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg 2017-12-12T22:07:49.190Z,1513116469.190 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg 2017-12-12T22:07:49.354Z,1513116469.354 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg 2017-12-12T22:07:49.429Z,1513116469.429 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2017-12-12T22:07:49.441Z,1513116469.441 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2017-12-12T22:07:49.563Z,1513116469.563 [SBIT](DEBUG): Construct Startup Built In Test. 2017-12-12T22:07:49.592Z,1513116469.592 [SBIT] Loaded 2017-12-12T22:07:49.592Z,1513116469.592 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2017-12-12T22:07:49.593Z,1513116469.593 [IBIT](DEBUG): Construct Initiated Built In Test. 2017-12-12T22:07:49.619Z,1513116469.619 [IBIT] Loaded 2017-12-12T22:07:49.619Z,1513116469.619 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2017-12-12T22:07:49.623Z,1513116469.623 [CBIT](DEBUG): Construct Continuous Built In Test. 2017-12-12T22:07:49.769Z,1513116469.769 [CBIT] Loaded 2017-12-12T22:07:49.769Z,1513116469.769 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2017-12-12T22:07:49.770Z,1513116469.770 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2017-12-12T22:07:49.770Z,1513116469.770 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2017-12-12T22:07:49.856Z,1513116469.856 [VerticalControl](DEBUG): Construct VerticalControl. 2017-12-12T22:07:49.951Z,1513116469.951 [VerticalControl] Loaded 2017-12-12T22:07:49.951Z,1513116469.951 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2017-12-12T22:07:49.952Z,1513116469.952 [HorizontalControl](DEBUG): Construct HorizontalControl. 2017-12-12T22:07:50.010Z,1513116470.010 [HorizontalControl] Loaded 2017-12-12T22:07:50.010Z,1513116470.010 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2017-12-12T22:07:50.011Z,1513116470.011 [SpeedControl](DEBUG): Construct SpeedControl. 2017-12-12T22:07:50.016Z,1513116470.016 [SpeedControl] Loaded 2017-12-12T22:07:50.016Z,1513116470.016 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2017-12-12T22:07:50.017Z,1513116470.017 [LoopControl](DEBUG): Construct LoopControl. 2017-12-12T22:07:50.017Z,1513116470.017 [LoopControl] Loaded 2017-12-12T22:07:50.018Z,1513116470.018 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2017-12-12T22:07:50.018Z,1513116470.018 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2017-12-12T22:07:50.019Z,1513116470.019 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2017-12-12T22:07:50.058Z,1513116470.058 [DepthRateCalculator] Loaded 2017-12-12T22:07:50.059Z,1513116470.059 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2017-12-12T22:07:50.064Z,1513116470.064 [PitchRateCalculator] Loaded 2017-12-12T22:07:50.064Z,1513116470.064 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2017-12-12T22:07:50.079Z,1513116470.079 [SpeedCalculator] Loaded 2017-12-12T22:07:50.079Z,1513116470.079 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2017-12-12T22:07:50.100Z,1513116470.100 [TempGradientCalculator] Loaded 2017-12-12T22:07:50.101Z,1513116470.101 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2017-12-12T22:07:50.116Z,1513116470.116 [VerticalTemperatureHomogeneityIndexCalculator] Loaded 2017-12-12T22:07:50.116Z,1513116470.116 [ComponentRegistry](DEBUG): SyncComponent "VerticalTemperatureHomogeneityIndexCalculator" handled in the control thread. 2017-12-12T22:07:50.121Z,1513116470.121 [YawRateCalculator] Loaded 2017-12-12T22:07:50.121Z,1513116470.121 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2017-12-12T22:07:50.121Z,1513116470.121 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2017-12-12T22:07:50.122Z,1513116470.122 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2017-12-12T22:07:50.200Z,1513116470.200 [StratificationFrontDetector](INFO): threshold set to: 0.399988 degC 2017-12-12T22:07:50.200Z,1513116470.200 [StratificationFrontDetector](DEBUG): (re)initializing 2017-12-12T22:07:50.201Z,1513116470.201 [StratificationFrontDetector] Loaded 2017-12-12T22:07:50.201Z,1513116470.201 [ComponentRegistry](DEBUG): SyncComponent "StratificationFrontDetector" handled in the control thread. 2017-12-12T22:07:50.201Z,1513116470.201 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2017-12-12T22:07:50.202Z,1513116470.202 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2017-12-12T22:07:50.428Z,1513116470.428 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2017-12-12T22:07:50.429Z,1513116470.429 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2017-12-12T22:07:50.516Z,1513116470.516 [DeadReckonUsingSpeedCalculator] Loaded 2017-12-12T22:07:50.516Z,1513116470.516 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread. 2017-12-12T22:07:50.568Z,1513116470.568 [DeadReckonWithRespectToSeafloor] Loaded 2017-12-12T22:07:50.569Z,1513116470.569 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonWithRespectToSeafloor" handled in the control thread. 2017-12-12T22:07:50.584Z,1513116470.584 [NavChart] Loaded 2017-12-12T22:07:50.584Z,1513116470.584 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2017-12-12T22:07:50.588Z,1513116470.588 [UniversalFixResidualReporter] Loaded 2017-12-12T22:07:50.589Z,1513116470.589 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2017-12-12T22:07:50.589Z,1513116470.589 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2017-12-12T22:07:50.590Z,1513116470.590 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2017-12-12T22:07:50.602Z,1513116470.602 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2017-12-12T22:07:50.603Z,1513116470.603 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2017-12-12T22:07:50.777Z,1513116470.777 [Aanderaa_O2] Loaded 2017-12-12T22:07:50.777Z,1513116470.777 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread. 2017-12-12T22:07:50.789Z,1513116470.789 [CANONSampler] Loaded 2017-12-12T22:07:50.789Z,1513116470.789 [ComponentRegistry](DEBUG): SyncComponent "CANONSampler" handled in the control thread. 2017-12-12T22:07:50.864Z,1513116470.864 [CTD_NeilBrown] Loaded 2017-12-12T22:07:50.864Z,1513116470.864 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread. 2017-12-12T22:07:50.865Z,1513116470.865 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 406D14E0 2017-12-12T22:07:50.865Z,1513116470.865 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 1307 2017-12-12T22:07:50.897Z,1513116470.897 [CTD_Seabird] Loaded 2017-12-12T22:07:50.897Z,1513116470.897 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2017-12-12T22:07:50.898Z,1513116470.898 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 407014E0 2017-12-12T22:07:50.899Z,1513116470.899 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 1308 2017-12-12T22:07:50.912Z,1513116470.912 [PAR_Licor] Loaded 2017-12-12T22:07:50.913Z,1513116470.913 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2017-12-12T22:07:50.960Z,1513116470.960 [WetLabsBB2FL] Loaded 2017-12-12T22:07:50.961Z,1513116470.961 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2017-12-12T22:07:50.962Z,1513116470.962 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 407314E0 2017-12-12T22:07:50.962Z,1513116470.962 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 1309 2017-12-12T22:07:51.004Z,1513116471.004 [WetLabsSeaOWL_UV_A] Loaded 2017-12-12T22:07:51.004Z,1513116471.004 [ComponentRegistry](DEBUG): Component "WetLabsSeaOWL_UV_A" handled in its own thread. 2017-12-12T22:07:51.005Z,1513116471.005 [WetLabsSeaOWL_UV_A ThreadHandler](DEBUG): Created PCaller Thread at 407614E0 2017-12-12T22:07:51.005Z,1513116471.005 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Protected caller Thread ID is 1310 2017-12-12T22:07:51.006Z,1513116471.006 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2017-12-12T22:07:51.006Z,1513116471.006 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2017-12-12T22:07:51.258Z,1513116471.258 [DataOverHttps] Loaded 2017-12-12T22:07:51.259Z,1513116471.259 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread. 2017-12-12T22:07:51.271Z,1513116471.271 [Depth_Keller] Loaded 2017-12-12T22:07:51.272Z,1513116471.272 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2017-12-12T22:07:51.276Z,1513116471.276 [DropWeight] Loaded 2017-12-12T22:07:51.277Z,1513116471.277 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2017-12-12T22:07:51.364Z,1513116471.364 [NAL9602] Loaded 2017-12-12T22:07:51.364Z,1513116471.364 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2017-12-12T22:07:51.369Z,1513116471.369 [Onboard] Loaded 2017-12-12T22:07:51.370Z,1513116471.370 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2017-12-12T22:07:51.376Z,1513116471.376 [Radio_Surface] Loaded 2017-12-12T22:07:51.377Z,1513116471.377 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2017-12-12T22:07:51.378Z,1513116471.378 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409A54E0 2017-12-12T22:07:51.378Z,1513116471.378 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 1311 2017-12-12T22:07:51.423Z,1513116471.423 [PNI_TCM] Loaded 2017-12-12T22:07:51.423Z,1513116471.423 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread. 2017-12-12T22:07:53.288Z,1513116473.288 [BPC1] Loaded 2017-12-12T22:07:53.289Z,1513116473.289 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2017-12-12T22:07:53.289Z,1513116473.289 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2017-12-12T22:07:53.290Z,1513116473.290 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2017-12-12T22:07:53.382Z,1513116473.382 [BuoyancyServo] Loaded 2017-12-12T22:07:53.382Z,1513116473.382 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2017-12-12T22:07:53.393Z,1513116473.393 [ElevatorServo] Loaded 2017-12-12T22:07:53.394Z,1513116473.394 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2017-12-12T22:07:53.404Z,1513116473.404 [MassServo] Loaded 2017-12-12T22:07:53.405Z,1513116473.405 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2017-12-12T22:07:53.415Z,1513116473.415 [RudderServo] Loaded 2017-12-12T22:07:53.416Z,1513116473.416 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2017-12-12T22:07:53.426Z,1513116473.426 [ThrusterServo] Loaded 2017-12-12T22:07:53.426Z,1513116473.426 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2017-12-12T22:07:53.427Z,1513116473.427 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2017-12-12T22:07:53.427Z,1513116473.427 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2017-12-12T22:07:53.568Z,1513116473.568 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2017-12-12T22:07:53.569Z,1513116473.569 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2017-12-12T22:07:53.593Z,1513116473.593 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2017-12-12T22:07:53.596Z,1513116473.596 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2017-12-12T22:07:53.597Z,1513116473.597 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2017-12-12T22:07:53.604Z,1513116473.604 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2017-12-12T22:07:53.605Z,1513116473.605 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40A4C4E0 2017-12-12T22:07:53.605Z,1513116473.605 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 1312 2017-12-12T22:07:53.610Z,1513116473.610 [Supervisor](INFO): Main Thread ID is 795 2017-12-12T22:07:53.610Z,1513116473.610 [Supervisor](DEBUG): Running supervisor. 2017-12-12T22:07:53.610Z,1513116473.610 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1313 2017-12-12T22:07:53.613Z,1513116473.613 [controlThread ThreadHandler](INFO): Handler Thread ID is 1314 2017-12-12T22:07:53.613Z,1513116473.613 [controlThread](DEBUG): Initializing ControlThread 2017-12-12T22:07:53.614Z,1513116473.614 [SBIT](INFO): Initialize SBIT Component. 2017-12-12T22:07:53.615Z,1513116473.615 [SBIT](IMPORTANT): git: 2017-12-11 2017-12-12T22:07:53.615Z,1513116473.615 [SBIT](INFO): git hash: 8651b6fcf04aad5c066f1d23bee794430771ed42 2017-12-12T22:07:53.615Z,1513116473.615 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2017-12-12T22:07:53.617Z,1513116473.617 [SBIT](INFO): Kernel Reporting Different Version From Configuration. Kernel Expected: #639 PREEMPT Wed Mar 12 12:53:33 PDT 2014 Kernel Reported: #1 PREEMPT Wed Nov 29 17:23:09 PST 2017 2017-12-12T22:07:53.618Z,1513116473.618 [SBIT](INFO): Beginning SBIT in 44.000000 seconds. 2017-12-12T22:07:53.618Z,1513116473.618 [IBIT](INFO): Initialize IBIT Component. 2017-12-12T22:07:53.619Z,1513116473.619 [CBIT](DEBUG): Initialize CBIT Component. 2017-12-12T22:07:53.619Z,1513116473.619 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2017-12-12T22:07:53.620Z,1513116473.620 [logger ThreadHandler](INFO): Handler Thread ID is 1315 2017-12-12T22:07:53.647Z,1513116473.647 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 1316 2017-12-12T22:07:53.648Z,1513116473.648 [CTD_NeilBrown](INFO): Powering down 2017-12-12T22:07:53.683Z,1513116473.683 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 1317 2017-12-12T22:07:53.683Z,1513116473.683 [CTD_Seabird](INFO): Initializing 2017-12-12T22:07:53.719Z,1513116473.719 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2017-12-12T22:07:53.721Z,1513116473.721 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2017-12-12T22:07:53.722Z,1513116473.722 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2017-12-12T22:07:53.722Z,1513116473.722 [LoopControl](DEBUG): Initialize LoopControlComponent. 2017-12-12T22:07:53.723Z,1513116473.723 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2017-12-12T22:07:53.723Z,1513116473.723 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2017-12-12T22:07:53.723Z,1513116473.723 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2017-12-12T22:07:53.724Z,1513116473.724 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2017-12-12T22:07:53.724Z,1513116473.724 [VerticalTemperatureHomogeneityIndexCalculator](DEBUG): (re)initializing 2017-12-12T22:07:53.725Z,1513116473.725 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2017-12-12T22:07:53.726Z,1513116473.726 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2017-12-12T22:07:53.727Z,1513116473.727 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2017-12-12T22:07:53.727Z,1513116473.727 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2017-12-12T22:07:53.727Z,1513116473.727 [DeadReckonWithRespectToSeafloor](DEBUG): Initializing DeadReckonWithRespectToSeafloor component. 2017-12-12T22:07:53.728Z,1513116473.728 [DeadReckonWithRespectToSeafloor](INFO): Will consider orientation measurement stale after 120s. 2017-12-12T22:07:53.728Z,1513116473.728 [DeadReckonWithRespectToSeafloor](INFO): Will consider velocity measurement stale after 20s. 2017-12-12T22:07:53.729Z,1513116473.729 [NavChart](DEBUG): Initialize NavChart Navigation. 2017-12-12T22:07:53.729Z,1513116473.729 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2017-12-12T22:07:53.740Z,1513116473.740 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2017-12-12T22:07:53.747Z,1513116473.747 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 1319 2017-12-12T22:07:53.749Z,1513116473.749 [WetLabsBB2FL](INFO): Powering down 2017-12-12T22:07:53.783Z,1513116473.783 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Handler Thread ID is 1320 2017-12-12T22:07:53.792Z,1513116473.792 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2017-12-12T22:07:53.799Z,1513116473.799 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 1321 2017-12-12T22:07:53.805Z,1513116473.805 [Radio_Surface](INFO): Powering up 2017-12-12T22:07:53.823Z,1513116473.823 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1322 2017-12-12T22:07:53.827Z,1513116473.827 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2017-12-12T22:07:53.827Z,1513116473.827 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2017-12-12T22:07:53.827Z,1513116473.827 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2017-12-12T22:07:53.827Z,1513116473.827 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2017-12-12T22:07:53.827Z,1513116473.827 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2017-12-12T22:07:53.828Z,1513116473.828 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2017-12-12T22:07:53.828Z,1513116473.828 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000 2017-12-12T22:07:53.828Z,1513116473.828 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2017-12-12T22:07:53.828Z,1513116473.828 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2017-12-12T22:07:53.828Z,1513116473.828 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2017-12-12T22:07:53.829Z,1513116473.829 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000 2017-12-12T22:07:53.829Z,1513116473.829 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2017-12-12T22:07:53.829Z,1513116473.829 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000 2017-12-12T22:07:53.829Z,1513116473.829 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2017-12-12T22:07:53.830Z,1513116473.830 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000 2017-12-12T22:07:53.830Z,1513116473.830 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2017-12-12T22:07:53.855Z,1513116473.855 [MissionManager](DEBUG): 2017-12-12T22:07:53.856Z,1513116473.856 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2017-12-12T22:07:53.955Z,1513116473.955 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2017-12-12T22:07:53.956Z,1513116473.956 [Default:A.Wait](DEBUG): Construct Wait. 2017-12-12T22:07:53.980Z,1513116473.980 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2017-12-12T22:07:53.988Z,1513116473.988 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface 2017-12-12T22:07:53.988Z,1513116473.988 [CTD_Seabird](INFO): Powering down 2017-12-12T22:07:54.029Z,1513116474.029 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2017-12-12T22:07:54.032Z,1513116474.032 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2017-12-12T22:07:54.046Z,1513116474.046 [Default:E.Execute](DEBUG): Construct Execute. 2017-12-12T22:07:54.049Z,1513116474.049 [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-12-12T22:07:54.059Z,1513116474.059 [controlThread](DEBUG): Component order: CycleStarter,Aanderaa_O2,CANONSampler,PAR_Licor,DataOverHttps,Depth_Keller,DropWeight,NAL9602,Onboard,PNI_TCM,BPC1,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,VerticalTemperatureHomogeneityIndexCalculator,YawRateCalculator,StratificationFrontDetector,DeadReckonUsingSpeedCalculator,DeadReckonWithRespectToSeafloor,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2017-12-12T22:07:54.102Z,1513116474.102 [CANONSampler](INFO): Powering down 2017-12-12T22:07:54.208Z,1513116474.208 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2017-12-12T22:07:54.247Z,1513116474.247 [Depth_Keller](ERROR): Pressure reading out of range: 1831.023193 decibar 2017-12-12T22:07:54.425Z,1513116474.425 [DepthRateCalculator](ERROR): Depth measurement is not active 2017-12-12T22:07:54.508Z,1513116474.508 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2017-12-12T22:07:54.539Z,1513116474.539 [DeadReckonWithRespectToSeafloor](DEBUG): Starting up and don't have orientation data yet. 2017-12-12T22:07:54.631Z,1513116474.631 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2017-12-12T22:07:54.639Z,1513116474.639 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2017-12-12T22:07:54.653Z,1513116474.653 [ElevatorServo](DEBUG): Initializing EZServoServo. 2017-12-12T22:07:54.659Z,1513116474.659 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2017-12-12T22:07:54.664Z,1513116474.664 [MassServo](DEBUG): Initializing EZServoServo. 2017-12-12T22:07:54.671Z,1513116474.671 [MassServo](DEBUG): Initializing MassServo. 2017-12-12T22:07:54.683Z,1513116474.683 [RudderServo](DEBUG): Initializing EZServoServo. 2017-12-12T22:07:54.691Z,1513116474.691 [RudderServo](DEBUG): Initializing RudderServo. 2017-12-12T22:07:54.704Z,1513116474.704 [ThrusterServo](DEBUG): Initializing EZServoServo. 2017-12-12T22:07:54.711Z,1513116474.711 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2017-12-12T22:07:55.167Z,1513116475.167 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2017-12-12T22:07:55.168Z,1513116475.168 [DeadReckonWithRespectToSeafloor](DEBUG): Starting up and don't have orientation data yet. 2017-12-12T22:07:55.507Z,1513116475.507 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout 2017-12-12T22:07:55.507Z,1513116475.507 [BuoyancyServo](FAULT): Buoyancy failed to initialize 2017-12-12T22:07:55.507Z,1513116475.507 [BuoyancyServo] Communications Fault, FailCount= 1 2017-12-12T22:07:55.507Z,1513116475.507 [BuoyancyServo](ERROR): Communications Fault 2017-12-12T22:07:55.714Z,1513116475.714 [CBIT](ERROR): Communications Fault in component: BuoyancyServo 2017-12-12T22:07:55.792Z,1513116475.792 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2017-12-12T22:07:55.793Z,1513116475.793 [DeadReckonWithRespectToSeafloor](DEBUG): Starting up and don't have orientation data yet. 2017-12-12T22:07:55.815Z,1513116475.815 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2017-12-12T22:07:55.815Z,1513116475.815 [BuoyancyServo](INFO): Powering down 2017-12-12T22:07:56.174Z,1513116476.174 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2017-12-12T22:07:56.175Z,1513116476.175 [DeadReckonWithRespectToSeafloor](DEBUG): Starting up and don't have orientation data yet. 2017-12-12T22:07:56.568Z,1513116476.568 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2017-12-12T22:07:56.569Z,1513116476.569 [DeadReckonWithRespectToSeafloor](DEBUG): Starting up and don't have orientation data yet. 2017-12-12T22:07:56.958Z,1513116476.958 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2017-12-12T22:07:56.958Z,1513116476.958 [DeadReckonWithRespectToSeafloor](DEBUG): Starting up and don't have orientation data yet. 2017-12-12T22:07:57.443Z,1513116477.443 [Aanderaa_O2](INFO): Powering down 2017-12-12T22:07:57.518Z,1513116477.518 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2017-12-12T22:07:57.535Z,1513116477.535 [DeadReckonWithRespectToSeafloor](DEBUG): Starting up and don't have orientation data yet. 2017-12-12T22:07:57.803Z,1513116477.803 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2017-12-12T22:07:57.804Z,1513116477.804 [DeadReckonWithRespectToSeafloor](DEBUG): Starting up and don't have orientation data yet. 2017-12-12T22:07:57.980Z,1513116477.980 [CBIT](INFO): Clearing failed state for component BuoyancyServo 2017-12-12T22:07:57.980Z,1513116477.980 [BuoyancyServo] No Fault, FailCount= 1 2017-12-12T22:07:58.236Z,1513116478.236 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2017-12-12T22:07:58.355Z,1513116478.355 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2017-12-12T22:08:21.732Z,1513116501.732 [NAL9602](INFO): Powering up NAL9602 2017-12-12T22:08:38.296Z,1513116518.296 [SBIT](IMPORTANT): Beginning Startup BIT 2017-12-12T22:08:38.306Z,1513116518.306 [CBIT](IMPORTANT): Beginning ground fault scan 2017-12-12T22:08:42.280Z,1513116522.280 [NAL9602](ERROR): NAL9602 initialization error. 2017-12-12T22:08:42.280Z,1513116522.280 [NAL9602] Communications Fault, FailCount= 1 2017-12-12T22:08:42.280Z,1513116522.280 [NAL9602](ERROR): Communications Fault 2017-12-12T22:08:42.408Z,1513116522.408 [CBIT](ERROR): Communications Fault in component: NAL9602 2017-12-12T22:08:42.684Z,1513116522.684 [NAL9602](INFO): Powering down 2017-12-12T22:08:43.592Z,1513116523.592 [CBIT](INFO): Clearing failed state for component NAL9602 2017-12-12T22:08:43.592Z,1513116523.592 [NAL9602] No Fault, FailCount= 1 2017-12-12T22:08:46.319Z,1513116526.319 [BPC1](ERROR): Failed to receive battery data 2017-12-12T22:08:46.319Z,1513116526.319 [BPC1] Communications Fault, FailCount= 1 2017-12-12T22:08:46.319Z,1513116526.319 [BPC1](ERROR): Communications Fault 2017-12-12T22:08:46.451Z,1513116526.451 [CBIT](ERROR): Communications Fault in component: BPC1 2017-12-12T22:08:47.608Z,1513116527.608 [CBIT](INFO): Clearing failed state for component BPC1 2017-12-12T22:08:47.608Z,1513116527.608 [BPC1] No Fault, FailCount= 1 2017-12-12T22:08:49.205Z,1513116529.205 [CBIT](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): -0.011704 CHAN A1 (24V): -0.014451 CHAN A2 (12V): -0.002380 CHAN A3 (5V): 4.753929 CHAN B0 (3.3V): 0.001349 CHAN B1 (3.15aV): -0.000361 CHAN B2 (3.15bV): 0.000143 CHAN B3 (GND): 0.000162 OPEN: -0.000494 Full Scale Calc: 4.765 mA, -1.589 mA 2017-12-12T22:08:49.505Z,1513116529.505 [PNI_TCM](ERROR): CRC does not match. Expected:0x64639 got:0x41 2017-12-12T22:09:12.888Z,1513116552.888 [NAL9602](INFO): Powering up NAL9602 2017-12-12T22:09:32.276Z,1513116572.276 [SBIT](IMPORTANT): SBIT PASSED 2017-12-12T22:09:32.666Z,1513116572.666 [MissionManager](IMPORTANT): Started mission Startup 2017-12-12T22:09:32.666Z,1513116572.666 [Startup] Running Loop=1 2017-12-12T22:09:32.666Z,1513116572.666 [Startup](DEBUG): Aggregate::initialize Startup 2017-12-12T22:09:32.667Z,1513116572.667 [Startup:A.GoToSurface] Running Loop=1 2017-12-12T22:09:32.667Z,1513116572.667 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2017-12-12T22:09:32.667Z,1513116572.667 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2017-12-12T22:09:32.668Z,1513116572.668 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2017-12-12T22:09:32.668Z,1513116572.668 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2017-12-12T22:09:32.668Z,1513116572.668 [Startup:A.GoToSurface](DEBUG): No pitch timeout specified. Using default value of 20.000000 seconds. 2017-12-12T22:09:32.669Z,1513116572.669 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2017-12-12T22:09:32.674Z,1513116572.674 [Startup:StartupSatComms] Running Loop=1 2017-12-12T22:09:32.674Z,1513116572.674 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2017-12-12T22:09:32.674Z,1513116572.674 [Startup:StartupSatComms:A] Running Loop=1 2017-12-12T22:09:33.079Z,1513116573.079 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2017-12-12T22:09:33.812Z,1513116573.812 [NAL9602](ERROR): NAL9602 initialization error. 2017-12-12T22:09:33.812Z,1513116573.812 [NAL9602] Communications Fault, FailCount= 2 2017-12-12T22:09:33.812Z,1513116573.812 [NAL9602](ERROR): Communications Fault 2017-12-12T22:09:33.898Z,1513116573.898 [CBIT](ERROR): Communications Fault in component: NAL9602 2017-12-12T22:09:34.220Z,1513116574.220 [NAL9602](INFO): Powering down 2017-12-12T22:09:35.068Z,1513116575.068 [CBIT](INFO): Clearing failed state for component NAL9602 2017-12-12T22:09:35.068Z,1513116575.068 [NAL9602] No Fault, FailCount= 2 2017-12-12T22:09:45.059Z,1513116585.059 [BPC1](ERROR): Failed to receive battery data 2017-12-12T22:09:45.059Z,1513116585.059 [BPC1] Communications Fault, FailCount= 1 2017-12-12T22:09:45.059Z,1513116585.059 [BPC1](ERROR): Communications Fault 2017-12-12T22:09:45.078Z,1513116585.078 [CBIT](ERROR): Communications Fault in component: BPC1 2017-12-12T22:09:46.287Z,1513116586.287 [CBIT](INFO): Clearing failed state for component BPC1 2017-12-12T22:09:46.287Z,1513116586.287 [BPC1] No Fault, FailCount= 1 2017-12-12T22:10:04.224Z,1513116604.224 [NAL9602](INFO): Powering up NAL9602 2017-12-12T22:10:25.423Z,1513116625.423 [NAL9602](ERROR): NAL9602 initialization error. 2017-12-12T22:10:25.423Z,1513116625.423 [NAL9602] Communications Fault, FailCount= 3 2017-12-12T22:10:25.423Z,1513116625.423 [NAL9602](ERROR): Communications Fault 2017-12-12T22:10:25.493Z,1513116625.493 [CBIT](ERROR): Communications Fault in component: NAL9602 2017-12-12T22:10:25.813Z,1513116625.813 [NAL9602](INFO): Powering down 2017-12-12T22:10:26.668Z,1513116626.668 [CBIT](INFO): Clearing failed state for component NAL9602 2017-12-12T22:10:26.668Z,1513116626.668 [NAL9602] No Fault, FailCount= 3 2017-12-12T22:10:33.064Z,1513116633.064 [Startup:StartupSatComms:A](INFO): Timed out from 2017-12-12T22:09:32.7Z 2017-12-12T22:10:33.064Z,1513116633.064 [Startup:StartupSatComms:A] Stopped 2017-12-12T22:10:33.064Z,1513116633.064 [Startup:StartupSatComms:B] Running Loop=1 2017-12-12T22:10:33.464Z,1513116633.464 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2017-12-12T22:10:43.454Z,1513116643.454 [BPC1](ERROR): Failed to receive battery data 2017-12-12T22:10:43.454Z,1513116643.454 [BPC1] Communications Fault, FailCount= 1 2017-12-12T22:10:43.454Z,1513116643.454 [BPC1](ERROR): Communications Fault 2017-12-12T22:10:43.500Z,1513116643.500 [CBIT](ERROR): Communications Fault in component: BPC1 2017-12-12T22:10:44.670Z,1513116644.670 [CBIT](INFO): Clearing failed state for component BPC1 2017-12-12T22:10:44.670Z,1513116644.670 [BPC1] No Fault, FailCount= 1 2017-12-12T22:10:53.859Z,1513116653.859 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2017-12-12T22:10:53.860Z,1513116653.860 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1 2017-12-12T22:10:53.860Z,1513116653.860 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2017-12-12T22:10:53.861Z,1513116653.861 [DeadReckonWithRespectToSeafloor](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2017-12-12T22:10:53.861Z,1513116653.861 [DeadReckonWithRespectToSeafloor] Software Fault, FailCount= 1 2017-12-12T22:10:53.861Z,1513116653.861 [DeadReckonWithRespectToSeafloor](ERROR): Software Fault 2017-12-12T22:10:53.889Z,1513116653.889 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2017-12-12T22:10:53.889Z,1513116653.889 [CBIT](ERROR): Software Fault in component: DeadReckonWithRespectToSeafloor 2017-12-12T22:10:54.270Z,1513116654.270 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2017-12-12T22:10:54.270Z,1513116654.270 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1 2017-12-12T22:10:54.275Z,1513116654.275 [CBIT](INFO): Clearing failed state for component DeadReckonWithRespectToSeafloor 2017-12-12T22:10:54.275Z,1513116654.275 [DeadReckonWithRespectToSeafloor] No Fault, FailCount= 1 2017-12-12T22:10:54.651Z,1513116654.651 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2017-12-12T22:10:54.652Z,1513116654.652 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2017-12-12T22:10:54.652Z,1513116654.652 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2017-12-12T22:10:54.652Z,1513116654.652 [DeadReckonWithRespectToSeafloor](DEBUG): Initializing DeadReckonWithRespectToSeafloor component. 2017-12-12T22:10:54.653Z,1513116654.653 [DeadReckonWithRespectToSeafloor](INFO): Will consider orientation measurement stale after 120s. 2017-12-12T22:10:54.653Z,1513116654.653 [DeadReckonWithRespectToSeafloor](INFO): Will consider velocity measurement stale after 20s. 2017-12-12T22:10:55.820Z,1513116655.820 [NAL9602](INFO): Powering up NAL9602 2017-12-12T22:11:19.420Z,1513116679.420 [NAL9602](ERROR): NAL9602 initialization error. 2017-12-12T22:11:19.420Z,1513116679.420 [NAL9602] Communications Fault, FailCount= 4 2017-12-12T22:11:19.420Z,1513116679.420 [NAL9602](ERROR): Communications Fault 2017-12-12T22:11:19.543Z,1513116679.543 [CBIT](ERROR): Communications Fault in component: NAL9602 2017-12-12T22:11:19.599Z,1513116679.599 [NAL9602](INFO): Powering down 2017-12-12T22:11:20.360Z,1513116680.360 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003601 2017-12-12T22:11:20.454Z,1513116680.454 [CBIT](INFO): Clearing failed state for component NAL9602 2017-12-12T22:11:20.455Z,1513116680.455 [NAL9602] No Fault, FailCount= 4 2017-12-12T22:11:24.452Z,1513116684.452 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20171212T195033/Courier0056.lzma 2017-12-12T22:11:25.193Z,1513116685.193 [DataOverHttps](INFO): Moved sent file to Logs/20171212T195033/Courier0056.lzma.bak 2017-12-12T22:11:25.193Z,1513116685.193 [DataOverHttps](INFO): SBD MOMSN=5432047 2017-12-12T22:11:34.069Z,1513116694.069 [Startup:StartupSatComms:B](INFO): Timed out from 2017-12-12T22:10:33.1Z 2017-12-12T22:11:34.069Z,1513116694.069 [Startup:StartupSatComms:B] Stopped 2017-12-12T22:11:34.069Z,1513116694.069 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2017-12-12T22:11:34.070Z,1513116694.070 [Startup:StartupSatComms] Stopped 2017-12-12T22:11:34.070Z,1513116694.070 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2017-12-12T22:11:34.071Z,1513116694.071 [Startup](INFO): Completed Startup 2017-12-12T22:11:34.071Z,1513116694.071 [MissionManager](INFO): Startup is completed. 2017-12-12T22:11:34.071Z,1513116694.071 [MissionManager](INFO): Uninitializing Mission Startup 2017-12-12T22:11:34.071Z,1513116694.071 [Startup] Stopped 2017-12-12T22:11:34.071Z,1513116694.071 [Startup](DEBUG): Aggregate::uninitialize Startup 2017-12-12T22:11:34.071Z,1513116694.071 [Startup:A.GoToSurface] Stopped 2017-12-12T22:11:34.071Z,1513116694.071 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2017-12-12T22:11:34.208Z,1513116694.208 [MissionManager](IMPORTANT): Started mission Default 2017-12-12T22:11:34.208Z,1513116694.208 [Default] Running Loop=1 2017-12-12T22:11:34.208Z,1513116694.208 [Default](DEBUG): Aggregate::initialize Default 2017-12-12T22:11:34.208Z,1513116694.208 [Default:B.GoToSurface] Running Loop=1 2017-12-12T22:11:34.208Z,1513116694.208 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2017-12-12T22:11:34.209Z,1513116694.209 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2017-12-12T22:11:34.209Z,1513116694.209 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2017-12-12T22:11:34.209Z,1513116694.209 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2017-12-12T22:11:34.210Z,1513116694.210 [Default:B.GoToSurface](DEBUG): No pitch timeout specified. Using default value of 20.000000 seconds. 2017-12-12T22:11:34.210Z,1513116694.210 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2017-12-12T22:11:34.210Z,1513116694.210 [Default:A.Wait] Running Loop=1 2017-12-12T22:11:34.210Z,1513116694.210 [Default:A.Wait](DEBUG): Initialize Wait Component. 2017-12-12T22:11:34.542Z,1513116694.542 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20171212T195033/Courier0060.lzma 2017-12-12T22:11:35.342Z,1513116695.342 [DataOverHttps](INFO): Moved sent file to Logs/20171212T195033/Courier0060.lzma.bak 2017-12-12T22:11:35.342Z,1513116695.342 [DataOverHttps](INFO): SBD MOMSN=5432049 2017-12-12T22:11:44.236Z,1513116704.236 [BPC1](ERROR): Failed to receive battery data 2017-12-12T22:11:44.236Z,1513116704.236 [BPC1] Communications Fault, FailCount= 1 2017-12-12T22:11:44.236Z,1513116704.236 [BPC1](ERROR): Communications Fault 2017-12-12T22:11:44.279Z,1513116704.279 [CBIT](ERROR): Communications Fault in component: BPC1 2017-12-12T22:11:45.490Z,1513116705.490 [CBIT](INFO): Clearing failed state for component BPC1 2017-12-12T22:11:45.490Z,1513116705.490 [BPC1] No Fault, FailCount= 1 2017-12-12T22:11:47.453Z,1513116707.453 [Default:A.Wait](INFO): Done Waiting. 2017-12-12T22:11:47.453Z,1513116707.453 [Default:A.Wait] Stopped 2017-12-12T22:11:47.453Z,1513116707.453 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2017-12-12T22:11:47.860Z,1513116707.860 [Default:CheckIn] Running Loop=1 2017-12-12T22:11:47.860Z,1513116707.860 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2017-12-12T22:11:47.860Z,1513116707.860 [Default:CheckIn:Read_GPS] Running Loop=1 2017-12-12T22:11:48.254Z,1513116708.254 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2017-12-12T22:11:49.809Z,1513116709.809 [NAL9602](INFO): Powering up NAL9602 2017-12-12T22:12:10.617Z,1513116730.617 [NAL9602](ERROR): NAL9602 initialization error. 2017-12-12T22:12:10.617Z,1513116730.617 [NAL9602] Communications Fault, FailCount= 5 2017-12-12T22:12:10.617Z,1513116730.617 [NAL9602](ERROR): Communications Fault 2017-12-12T22:12:10.703Z,1513116730.703 [CBIT](ERROR): Communications Fault in component: NAL9602 2017-12-12T22:12:10.703Z,1513116730.703 [CBIT](CRITICAL): Communications Fault in component: NAL9602 2017-12-12T22:12:11.012Z,1513116731.012 [NAL9602](INFO): Powering down 2017-12-12T22:12:11.091Z,1513116731.091 [CommandLine](FAULT): Scheduling is paused 2017-12-12T22:12:11.091Z,1513116731.091 [CBIT](INFO): Critical error at 20171212T221210 2017-12-12T22:12:11.091Z,1513116731.091 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals 2017-12-12T22:12:24.247Z,1513116744.247 [PNI_TCM](ERROR): CRC does not match. Expected:0x25900 got:0x1347 2017-12-12T22:12:25.847Z,1513116745.847 [PNI_TCM](ERROR): CRC does not match. Expected:0x43793 got:0x34311 2017-12-12T22:12:27.449Z,1513116747.449 [PNI_TCM](ERROR): CRC does not match. Expected:0x4763 got:0x7490 2017-12-12T22:12:44.322Z,1513116764.322 [BPC1](ERROR): Failed to receive battery data 2017-12-12T22:12:44.322Z,1513116764.322 [BPC1] Communications Fault, FailCount= 1 2017-12-12T22:12:44.322Z,1513116764.322 [BPC1](ERROR): Communications Fault 2017-12-12T22:12:44.342Z,1513116764.342 [CBIT](ERROR): Communications Fault in component: BPC1 2017-12-12T22:12:45.556Z,1513116765.556 [CBIT](INFO): Clearing failed state for component BPC1 2017-12-12T22:12:45.556Z,1513116765.556 [BPC1] No Fault, FailCount= 1 2017-12-12T22:13:09.119Z,1513116789.119 [PNI_TCM](ERROR): CRC does not match. Expected:0x7106 got:0x35097 2017-12-12T22:13:10.719Z,1513116790.719 [PNI_TCM](ERROR): CRC does not match. Expected:0x397 got:0x7490 2017-12-12T22:13:12.321Z,1513116792.321 [PNI_TCM](ERROR): CRC does not match. Expected:0x12246 got:0x1857 2017-12-12T22:13:16.323Z,1513116796.323 [PNI_TCM](ERROR): CRC does not match. Expected:0x36808 got:0x53752 2017-12-12T22:13:39.529Z,1513116819.529 [BPC1](ERROR): Failed to receive battery data 2017-12-12T22:13:39.529Z,1513116819.529 [BPC1] Communications Fault, FailCount= 1 2017-12-12T22:13:39.529Z,1513116819.529 [BPC1](ERROR): Communications Fault 2017-12-12T22:13:39.584Z,1513116819.584 [CBIT](ERROR): Communications Fault in component: BPC1 2017-12-12T22:13:40.472Z,1513116820.472 [CBIT](INFO): Clearing failed state for component BPC1 2017-12-12T22:13:40.472Z,1513116820.472 [BPC1] No Fault, FailCount= 1 2017-12-12T22:13:40.792Z,1513116820.792 [DataOverHttps](IMPORTANT): SBD MTMSN=20171212T221327 2017-12-12T22:13:44.881Z,1513116824.881 [DataOverHttps](INFO): Received command:run Maintenance/new_tank_ballast_and_trim.xml 2017-12-12T22:13:44.942Z,1513116824.942 [CommandLine](IMPORTANT): got command run ./Missions/Maintenance/new_tank_ballast_and_trim.xml 2017-12-12T22:13:44.943Z,1513116824.943 [MissionManager](INFO): Loading Mission: ./Missions/Maintenance/new_tank_ballast_and_trim.xml 2017-12-12T22:13:45.091Z,1513116825.091 [MissionManager](INFO): DefineArg ballast_and_trim.MissionTimeout = 120.000000 min 2017-12-12T22:13:45.093Z,1513116825.093 [MissionManager](INFO): DefineArg ballast_and_trim.SkipComms = 0 bool 2017-12-12T22:13:45.096Z,1513116825.096 [MissionManager](INFO): DefineArg ballast_and_trim.Depth1 = 7.000000 m 2017-12-12T22:13:45.099Z,1513116825.099 [MissionManager](INFO): DefineArg ballast_and_trim.DepthDeadband1 = 0.100000 m 2017-12-12T22:13:45.102Z,1513116825.102 [MissionManager](INFO): DefineArg ballast_and_trim.Depth2 = nan m 2017-12-12T22:13:45.104Z,1513116825.104 [MissionManager](INFO): DefineArg ballast_and_trim.DepthDeadband2 = nan m 2017-12-12T22:13:45.108Z,1513116825.108 [MissionManager](INFO): DefineArg ballast_and_trim.SettleTime = 10.000000 min 2017-12-12T22:13:45.111Z,1513116825.111 [MissionManager](INFO): DefineArg ballast_and_trim.EstimationTimeout = 45.000000 min 2017-12-12T22:13:45.134Z,1513116825.134 [MissionManager](INFO): DefineArg ballast_and_trim.MinEstimationTime = 10.000000 min 2017-12-12T22:13:45.138Z,1513116825.138 [MissionManager](INFO): DefineArg ballast_and_trim.MassEstimationErrorBound = 0.250000 mm 2017-12-12T22:13:45.151Z,1513116825.151 [MissionManager](INFO): DefineArg ballast_and_trim.BuoyEstimationErrorBound = 15.000000 cc 2017-12-12T22:13:45.154Z,1513116825.154 [MissionManager](INFO): DefineArg ballast_and_trim.EstimationConfidence = 99.900000 % 2017-12-12T22:13:45.161Z,1513116825.161 [MissionManager](INFO): DefineArg ballast_and_trim.WaitToFloat = 5.000000 min 2017-12-12T22:13:45.161Z,1513116825.161 [MissionManager](INFO): Inserting Stack: Missions/Insert/Science.xml 2017-12-12T22:13:45.498Z,1513116825.498 [MissionManager](INFO): DefineArg ballast_and_trim:Science.SampleISUS = 0 bool 2017-12-12T22:13:45.501Z,1513116825.501 [MissionManager](INFO): DefineArg ballast_and_trim:Science.SampleISUSmaxPitch = 60.000000 arcdeg 2017-12-12T22:13:45.504Z,1513116825.504 [MissionManager](INFO): DefineArg ballast_and_trim:Science.SampleISUSminPitch = -60.000000 arcdeg 2017-12-12T22:13:45.511Z,1513116825.511 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectChlActive = 0 bool 2017-12-12T22:13:45.514Z,1513116825.514 [MissionManager](INFO): DefineArg ballast_and_trim:Science.HighestChlPeakReportActive = 0 bool 2017-12-12T22:13:45.516Z,1513116825.516 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PatchTracking = 0 bool 2017-12-12T22:13:45.519Z,1513116825.519 [MissionManager](INFO): DefineArg ballast_and_trim:Science.FilterWidthHorizontal = 3.000000 count 2017-12-12T22:13:45.522Z,1513116825.522 [MissionManager](INFO): DefineArg ballast_and_trim:Science.NumProfilesSlidingwindow = 100.000000 count 2017-12-12T22:13:45.536Z,1513116825.536 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectNO3Active = 0 bool 2017-12-12T22:13:45.542Z,1513116825.542 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectOilActive = 0 bool 2017-12-12T22:13:45.545Z,1513116825.545 [MissionManager](INFO): DefineArg ballast_and_trim:Science.UpwardDerivativeOfTemperatureActive = 0 bool 2017-12-12T22:13:45.548Z,1513116825.548 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledAanderaaO2 = 1.000000 bool 2017-12-12T22:13:45.574Z,1513116825.574 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledNeilBrown = 1.000000 bool 2017-12-12T22:13:45.578Z,1513116825.578 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledSeabird = 1.000000 bool 2017-12-12T22:13:45.581Z,1513116825.581 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledTurbulence_NPS = 0.000000 bool 2017-12-12T22:13:45.605Z,1513116825.605 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledWetLabsBB2FL = 1.000000 bool 2017-12-12T22:13:45.608Z,1513116825.608 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledWetLabsSeaOWL_UV_A = 1.000000 bool 2017-12-12T22:13:45.622Z,1513116825.622 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledISUS = 0.000000 bool 2017-12-12T22:13:45.625Z,1513116825.625 [MissionManager](INFO): DefineArg ballast_and_trim:Science.LowPassWindowLength = 20.000000 count 2017-12-12T22:13:45.628Z,1513116825.628 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakChlShallowBound = nan m 2017-12-12T22:13:45.674Z,1513116825.674 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakChlDeepBound = nan m 2017-12-12T22:13:45.700Z,1513116825.700 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChl = 0.000000 ug/l 2017-12-12T22:13:45.722Z,1513116825.722 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChlDepth = 0.000000 m 2017-12-12T22:13:45.725Z,1513116825.725 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChlTemperature = 0.000000 degC 2017-12-12T22:13:45.741Z,1513116825.741 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChlLatitude = nan arcdeg 2017-12-12T22:13:45.745Z,1513116825.745 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChlLongitude = nan arcdeg 2017-12-12T22:13:45.748Z,1513116825.748 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakNO3 = 0.000000 umol/l 2017-12-12T22:13:45.752Z,1513116825.752 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakNO3Depth = 0.000000 m 2017-12-12T22:13:45.768Z,1513116825.768 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakNO3Latitude = nan arcdeg 2017-12-12T22:13:45.771Z,1513116825.771 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakNO3Longitude = nan arcdeg 2017-12-12T22:13:45.774Z,1513116825.774 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChl = 0.000000 m 2017-12-12T22:13:45.777Z,1513116825.777 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChlDepth = 0.000000 m 2017-12-12T22:13:45.797Z,1513116825.797 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChlLatitude = nan arcdeg 2017-12-12T22:13:45.800Z,1513116825.800 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChlLongitude = nan arcdeg 2017-12-12T22:13:45.803Z,1513116825.803 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChlDistance = nan arcdeg 2017-12-12T22:13:45.806Z,1513116825.806 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakOil = 0.000000 kg/m3 2017-12-12T22:13:45.821Z,1513116825.821 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakOilDepth = 0.000000 m 2017-12-12T22:13:45.824Z,1513116825.824 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakOilLatitude = nan arcdeg 2017-12-12T22:13:45.827Z,1513116825.827 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakOilLongitude = nan arcdeg 2017-12-12T22:13:45.870Z,1513116825.870 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth. 2017-12-12T22:13:45.901Z,1513116825.901 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal](DEBUG): Construct PeakDetectHorizontal. 2017-12-12T22:13:45.927Z,1513116825.927 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth. 2017-12-12T22:13:45.946Z,1513116825.946 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth. 2017-12-12T22:13:45.968Z,1513116825.968 [MissionManager](INFO): Inserting Stack: Missions/Insert/newBallastAndTrim.xml 2017-12-12T22:13:46.087Z,1513116826.087 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:Depth1:BallastAndTrim.InsertDepth = 25.000000 m 2017-12-12T22:13:46.095Z,1513116826.095 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:Depth1:BallastAndTrim.InsertDepthDeadband = 1.000000 m 2017-12-12T22:13:46.098Z,1513116826.098 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:Depth1:BallastAndTrim.InsertSettleTime = 10.000000 min 2017-12-12T22:13:46.117Z,1513116826.117 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:Depth1:BallastAndTrim.EstTimeout = 45.000000 min 2017-12-12T22:13:46.120Z,1513116826.120 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:Depth1:BallastAndTrim.MinEstTime = 10.000000 min 2017-12-12T22:13:46.131Z,1513116826.131 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:Depth1:BallastAndTrim.MassEstErrorBound = 0.250000 mm 2017-12-12T22:13:46.147Z,1513116826.147 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:Depth1:BallastAndTrim.BuoyEstErrorBound = 15.000000 cc 2017-12-12T22:13:46.150Z,1513116826.150 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:Depth1:BallastAndTrim.EstConfidence = 99.900000 % 2017-12-12T22:13:46.177Z,1513116826.177 [ballast_and_trim:RunBallastAndTrim:Depth1:BallastAndTrim:E.SetSpeed](DEBUG): Construct. 2017-12-12T22:13:46.192Z,1513116826.192 [ballast_and_trim:RunBallastAndTrim:Depth1:BallastAndTrim:F.Pitch](DEBUG): Construct. 2017-12-12T22:13:46.209Z,1513116826.209 [ballast_and_trim:RunBallastAndTrim:Depth1:BallastAndTrim:G.Wait](DEBUG): Construct Wait. 2017-12-12T22:13:46.215Z,1513116826.215 [ballast_and_trim:RunBallastAndTrim:Depth1:BallastAndTrim:H.](DEBUG): Construct BallastAndTrim. 2017-12-12T22:13:46.280Z,1513116826.280 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:Depth1:BallastAndTrim.InsertDepth = reader:ballast_and_trim.Depth1 2017-12-12T22:13:46.282Z,1513116826.282 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:Depth1:BallastAndTrim.InsertDepthDeadband = reader:ballast_and_trim.DepthDeadband1 2017-12-12T22:13:46.296Z,1513116826.296 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:Depth1:BallastAndTrim.InsertSettleTime = reader:ballast_and_trim.SettleTime 2017-12-12T22:13:46.297Z,1513116826.297 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:Depth1:BallastAndTrim.EstTimeout = reader:ballast_and_trim.EstimationTimeout 2017-12-12T22:13:46.299Z,1513116826.299 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:Depth1:BallastAndTrim.MinEstTime = reader:ballast_and_trim.MinEstimationTime 2017-12-12T22:13:46.301Z,1513116826.301 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:Depth1:BallastAndTrim.MassEstErrorBound = reader:ballast_and_trim.MassEstimationErrorBound 2017-12-12T22:13:46.303Z,1513116826.303 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:Depth1:BallastAndTrim.BuoyEstErrorBound = reader:ballast_and_trim.BuoyEstimationErrorBound 2017-12-12T22:13:46.304Z,1513116826.304 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:Depth1:BallastAndTrim.EstConfidence = reader:ballast_and_trim.EstimationConfidence 2017-12-12T22:13:46.306Z,1513116826.306 [MissionManager](INFO): Inserting Stack: Missions/Insert/newBallastAndTrim.xml 2017-12-12T22:13:46.404Z,1513116826.404 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:Depth2:BallastAndTrim.InsertDepth = 25.000000 m 2017-12-12T22:13:46.407Z,1513116826.407 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:Depth2:BallastAndTrim.InsertDepthDeadband = 1.000000 m 2017-12-12T22:13:46.410Z,1513116826.410 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:Depth2:BallastAndTrim.InsertSettleTime = 10.000000 min 2017-12-12T22:13:46.417Z,1513116826.417 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:Depth2:BallastAndTrim.EstTimeout = 45.000000 min 2017-12-12T22:13:46.420Z,1513116826.420 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:Depth2:BallastAndTrim.MinEstTime = 10.000000 min 2017-12-12T22:13:46.432Z,1513116826.432 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:Depth2:BallastAndTrim.MassEstErrorBound = 0.250000 mm 2017-12-12T22:13:46.439Z,1513116826.439 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:Depth2:BallastAndTrim.BuoyEstErrorBound = 15.000000 cc 2017-12-12T22:13:46.442Z,1513116826.442 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:Depth2:BallastAndTrim.EstConfidence = 99.900000 % 2017-12-12T22:13:46.502Z,1513116826.502 [ballast_and_trim:RunBallastAndTrim:Depth2:BallastAndTrim:E.SetSpeed](DEBUG): Construct. 2017-12-12T22:13:46.505Z,1513116826.505 [ballast_and_trim:RunBallastAndTrim:Depth2:BallastAndTrim:F.Pitch](DEBUG): Construct. 2017-12-12T22:13:46.538Z,1513116826.538 [ballast_and_trim:RunBallastAndTrim:Depth2:BallastAndTrim:G.Wait](DEBUG): Construct Wait. 2017-12-12T22:13:46.540Z,1513116826.540 [ballast_and_trim:RunBallastAndTrim:Depth2:BallastAndTrim:H.](DEBUG): Construct BallastAndTrim. 2017-12-12T22:13:46.546Z,1513116826.546 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:Depth2:BallastAndTrim.InsertDepth = reader:ballast_and_trim.Depth2 2017-12-12T22:13:46.557Z,1513116826.557 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:Depth2:BallastAndTrim.InsertDepthDeadband = reader:ballast_and_trim.DepthDeadband2 2017-12-12T22:13:46.559Z,1513116826.559 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:Depth2:BallastAndTrim.InsertSettleTime = reader:ballast_and_trim.SettleTime 2017-12-12T22:13:46.560Z,1513116826.560 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:Depth2:BallastAndTrim.EstTimeout = reader:ballast_and_trim.EstimationTimeout 2017-12-12T22:13:46.562Z,1513116826.562 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:Depth2:BallastAndTrim.MinEstTime = reader:ballast_and_trim.MinEstimationTime 2017-12-12T22:13:46.564Z,1513116826.564 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:Depth2:BallastAndTrim.MassEstErrorBound = reader:ballast_and_trim.MassEstimationErrorBound 2017-12-12T22:13:46.565Z,1513116826.565 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:Depth2:BallastAndTrim.BuoyEstErrorBound = reader:ballast_and_trim.BuoyEstimationErrorBound 2017-12-12T22:13:46.583Z,1513116826.583 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:Depth2:BallastAndTrim.EstConfidence = reader:ballast_and_trim.EstimationConfidence 2017-12-12T22:13:46.588Z,1513116826.588 [ballast_and_trim:Float_Up:A.Buoyancy](DEBUG): Construct Buoyancy. 2017-12-12T22:13:46.591Z,1513116826.591 [ballast_and_trim:Float_Up:B.Wait](DEBUG): Construct Wait. 2017-12-12T22:13:46.636Z,1513116826.636 [MissionManager](DEBUG): Maximum duration of mission 120 Skip communications at start of mission. 7 0.1 NaN NaN How long to wait after reaching target depth before starting ballast and trim. 10 Timeout for ballast and trim estimation. 45 Minimum time to run ballast and trim estimation before determining convergence (must be shorter than timeout). 10 Desired range of the estimated sample mean from the true mean statistic (smaller values take longer to converge). 0.25 Desired range of the estimated sample mean from the true mean statistic (smaller values take longer to converge). 15 Confidence level that the estimator has reached the desired error range (larger values take longer to converge). 99.9 5 Float to surface instead of driving. 2017-12-12T22:13:46.639Z,1513116826.639 [CommandLine](IMPORTANT): Running ./Missions/Maintenance/new_tank_ballast_and_trim.xml 2017-12-12T22:13:46.901Z,1513116826.901 [Default] Stopped 2017-12-12T22:13:46.901Z,1513116826.901 [Default](DEBUG): Aggregate::uninitialize Default 2017-12-12T22:13:46.901Z,1513116826.901 [Default:B.GoToSurface] Stopped 2017-12-12T22:13:46.901Z,1513116826.901 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2017-12-12T22:13:46.902Z,1513116826.902 [Default:CheckIn] Stopped 2017-12-12T22:13:46.902Z,1513116826.902 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2017-12-12T22:13:46.902Z,1513116826.902 [Default:CheckIn:Read_GPS] Stopped 2017-12-12T22:13:46.902Z,1513116826.902 [MissionManager](IMPORTANT): Started mission ballast_and_trim 2017-12-12T22:13:46.902Z,1513116826.902 [ballast_and_trim] Running Loop=1 2017-12-12T22:13:46.902Z,1513116826.902 [ballast_and_trim](DEBUG): Aggregate::initialize ballast_and_trim 2017-12-12T22:13:46.902Z,1513116826.902 [ballast_and_trim:Science] Running Loop=1 2017-12-12T22:13:46.903Z,1513116826.903 [ballast_and_trim:Science](DEBUG): Aggregate::initialize ballast_and_trim:Science 2017-12-12T22:13:46.903Z,1513116826.903 [ballast_and_trim:Science:A] Running Loop=1 2017-12-12T22:13:46.903Z,1513116826.903 [ballast_and_trim:Science:B] Running Loop=1 2017-12-12T22:13:46.903Z,1513116826.903 [ballast_and_trim:Science:C] Running Loop=1 2017-12-12T22:13:46.903Z,1513116826.903 [ballast_and_trim:Science:D] Running Loop=1 2017-12-12T22:13:46.903Z,1513116826.903 [ballast_and_trim:Science:E] Running Loop=1 2017-12-12T22:13:46.903Z,1513116826.903 [ballast_and_trim:Science:F] Running Loop=1 2017-12-12T22:13:46.903Z,1513116826.903 [ballast_and_trim:Science:G] Running Loop=1 2017-12-12T22:13:46.903Z,1513116826.903 [ballast_and_trim:Science:H] Running Loop=1 2017-12-12T22:13:46.903Z,1513116826.903 [ballast_and_trim:Science:PeakDetectChl] Running Loop=1 2017-12-12T22:13:46.903Z,1513116826.903 [ballast_and_trim:Science:PeakDetectChl](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectChl 2017-12-12T22:13:46.903Z,1513116826.903 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth] Running Loop=1 2017-12-12T22:13:46.903Z,1513116826.903 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Initialize. 2017-12-12T22:13:46.905Z,1513116826.905 [ballast_and_trim:Science:HighestChlPeakReport] Running Loop=1 2017-12-12T22:13:46.905Z,1513116826.905 [ballast_and_trim:Science:HighestChlPeakReport](DEBUG): Aggregate::initialize ballast_and_trim:Science:HighestChlPeakReport 2017-12-12T22:13:46.906Z,1513116826.906 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal] Running Loop=1 2017-12-12T22:13:46.906Z,1513116826.906 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal](INFO): Initialize. 2017-12-12T22:13:46.906Z,1513116826.906 [ballast_and_trim:Science:PeakDetectNO3] Running Loop=1 2017-12-12T22:13:46.906Z,1513116826.906 [ballast_and_trim:Science:PeakDetectNO3](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectNO3 2017-12-12T22:13:46.908Z,1513116826.908 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth] Running Loop=1 2017-12-12T22:13:46.908Z,1513116826.908 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Initialize. 2017-12-12T22:13:46.910Z,1513116826.910 [ballast_and_trim:Science:PeakDetectOil] Running Loop=1 2017-12-12T22:13:46.910Z,1513116826.910 [ballast_and_trim:Science:PeakDetectOil](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectOil 2017-12-12T22:13:46.910Z,1513116826.910 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth] Running Loop=1 2017-12-12T22:13:46.910Z,1513116826.910 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Initialize. 2017-12-12T22:13:46.912Z,1513116826.912 [ballast_and_trim:RunBallastAndTrim] Running Loop=1 2017-12-12T22:13:46.912Z,1513116826.912 [ballast_and_trim:RunBallastAndTrim](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim 2017-12-12T22:13:46.912Z,1513116826.912 [ballast_and_trim:RunBallastAndTrim:Depth1] Running Loop=1 2017-12-12T22:13:46.912Z,1513116826.912 [ballast_and_trim:RunBallastAndTrim:Depth1](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:Depth1 2017-12-12T22:13:46.912Z,1513116826.912 [ballast_and_trim:RunBallastAndTrim:Depth1:BallastAndTrim] Running Loop=1 2017-12-12T22:13:46.912Z,1513116826.912 [ballast_and_trim:RunBallastAndTrim:Depth1:BallastAndTrim](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:Depth1:BallastAndTrim 2017-12-12T22:13:46.912Z,1513116826.912 [ballast_and_trim:RunBallastAndTrim:Depth1:BallastAndTrim:A] Running Loop=1 2017-12-12T22:13:46.912Z,1513116826.912 [ballast_and_trim:RunBallastAndTrim:Depth1:BallastAndTrim:B] Running Loop=1 2017-12-12T22:13:46.912Z,1513116826.912 [ballast_and_trim:RunBallastAndTrim:Depth1:BallastAndTrim:C] Running Loop=1 2017-12-12T22:13:46.912Z,1513116826.912 [ballast_and_trim:RunBallastAndTrim:Depth1:BallastAndTrim:D] Running Loop=1 2017-12-12T22:13:46.912Z,1513116826.912 [ballast_and_trim:RunBallastAndTrim:Depth1:BallastAndTrim:E.SetSpeed] Running Loop=1 2017-12-12T22:13:46.913Z,1513116826.913 [ballast_and_trim:RunBallastAndTrim:Depth1:BallastAndTrim:E.SetSpeed](DEBUG): Initialize. 2017-12-12T22:13:46.913Z,1513116826.913 [ballast_and_trim:RunBallastAndTrim:Depth1:BallastAndTrim:F.Pitch] Running Loop=1 2017-12-12T22:13:46.913Z,1513116826.913 [ballast_and_trim:RunBallastAndTrim:Depth1:BallastAndTrim:F.Pitch](DEBUG): Initialize. 2017-12-12T22:13:46.943Z,1513116826.943 [ballast_and_trim:RunBallastAndTrim:Depth1:BallastAndTrim:E.SetSpeed] Running Loop=1 2017-12-12T22:13:46.947Z,1513116826.947 [ballast_and_trim:RunBallastAndTrim:Depth1:BallastAndTrim:D] Running Loop=1 2017-12-12T22:13:46.949Z,1513116826.949 [ballast_and_trim:RunBallastAndTrim:Depth1:BallastAndTrim:C] Running Loop=1 2017-12-12T22:13:46.950Z,1513116826.950 [ballast_and_trim:RunBallastAndTrim:Depth1:BallastAndTrim:B] Running Loop=1 2017-12-12T22:13:46.988Z,1513116826.988 [ballast_and_trim:RunBallastAndTrim:Depth1:BallastAndTrim:A] Running Loop=1 2017-12-12T22:13:46.990Z,1513116826.990 [ballast_and_trim:Science] Running Loop=1 2017-12-12T22:13:46.991Z,1513116826.991 [ballast_and_trim:Science:PeakDetectOil] Stopped 2017-12-12T22:13:46.991Z,1513116826.991 [ballast_and_trim:Science:PeakDetectOil](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectOil 2017-12-12T22:13:46.991Z,1513116826.991 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth] Stopped 2017-12-12T22:13:46.991Z,1513116826.991 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Uninitialize. 2017-12-12T22:13:46.991Z,1513116826.991 [ballast_and_trim:Science:PeakDetectNO3] Stopped 2017-12-12T22:13:46.991Z,1513116826.991 [ballast_and_trim:Science:PeakDetectNO3](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectNO3 2017-12-12T22:13:46.991Z,1513116826.991 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth] Stopped 2017-12-12T22:13:46.991Z,1513116826.991 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Uninitialize. 2017-12-12T22:13:46.991Z,1513116826.991 [ballast_and_trim:Science:HighestChlPeakReport] Stopped 2017-12-12T22:13:46.991Z,1513116826.991 [ballast_and_trim:Science:HighestChlPeakReport](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:HighestChlPeakReport 2017-12-12T22:13:46.992Z,1513116826.992 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal] Stopped 2017-12-12T22:13:46.992Z,1513116826.992 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal](DEBUG): Uninitialize. 2017-12-12T22:13:46.992Z,1513116826.992 [ballast_and_trim:Science:PeakDetectChl] Stopped 2017-12-12T22:13:46.992Z,1513116826.992 [ballast_and_trim:Science:PeakDetectChl](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectChl 2017-12-12T22:13:46.992Z,1513116826.992 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth] Stopped 2017-12-12T22:13:46.992Z,1513116826.992 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Uninitialize. 2017-12-12T22:13:46.992Z,1513116826.992 [ballast_and_trim:Science:H] Running Loop=1 2017-12-12T22:13:46.993Z,1513116826.993 [ballast_and_trim:Science:H](DEBUG): Initialize ReadDataComponent to sense mass_concentration_of_petroleum_hydrocarbons_in_sea_water 2017-12-12T22:13:46.994Z,1513116826.994 [ballast_and_trim:Science:G] Running Loop=1 2017-12-12T22:13:46.995Z,1513116826.995 [ballast_and_trim:Science:G](DEBUG): Initialize ReadDataComponent to sense mass_concentration_of_chlorophyll_in_sea_water 2017-12-12T22:13:46.996Z,1513116826.996 [ballast_and_trim:Science:F] Stopped 2017-12-12T22:13:46.996Z,1513116826.996 [ballast_and_trim:Science:E] Stopped 2017-12-12T22:13:46.996Z,1513116826.996 [ballast_and_trim:Science:D] Running Loop=1 2017-12-12T22:13:46.997Z,1513116826.997 [ballast_and_trim:Science:D](DEBUG): Initialize ReadDataComponent to sense CTD_Seabird.sea_water_temperature 2017-12-12T22:13:46.997Z,1513116826.997 [ballast_and_trim:Science:D](DEBUG): Initialize ReadDataComponent to sense CTD_Seabird.sea_water_salinity 2017-12-12T22:13:47.024Z,1513116827.024 [ballast_and_trim:Science:C] Running Loop=1 2017-12-12T22:13:47.025Z,1513116827.025 [ballast_and_trim:Science:C](DEBUG): Initialize ReadDataComponent to sense sea_water_temperature 2017-12-12T22:13:47.025Z,1513116827.025 [ballast_and_trim:Science:C](DEBUG): Initialize ReadDataComponent to sense sea_water_salinity 2017-12-12T22:13:47.027Z,1513116827.027 [ballast_and_trim:Science:B] Stopped 2017-12-12T22:13:47.027Z,1513116827.027 [ballast_and_trim:Science:A] Running Loop=1 2017-12-12T22:13:47.027Z,1513116827.027 [ballast_and_trim:Science:A](DEBUG): Initialize ReadDataComponent to sense mass_concentration_of_oxygen_in_sea_water 2017-12-12T22:13:47.052Z,1513116827.052 [WetLabsBB2FL](INFO): Opening uart, block timeout 10ths=4 2017-12-12T22:13:47.053Z,1513116827.053 [WetLabsBB2FL](INFO): Powering up 2017-12-12T22:13:47.279Z,1513116827.279 [CTD_Seabird](INFO): Initializing 2017-12-12T22:13:47.280Z,1513116827.280 [CTD_Seabird](INFO): Checking LCM 2017-12-12T22:13:47.289Z,1513116827.289 [CTD_Seabird](INFO): LCM OK 2017-12-12T22:13:47.289Z,1513116827.289 [CTD_Seabird](INFO): Powering up 2017-12-12T22:13:47.359Z,1513116827.359 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown. 2017-12-12T22:13:47.371Z,1513116827.371 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4 2017-12-12T22:13:47.783Z,1513116827.783 [CTD_NeilBrown](DEBUG): serial timeout 2017-12-12T22:13:48.199Z,1513116828.199 [CTD_NeilBrown](DEBUG): serial timeout 2017-12-12T22:13:48.606Z,1513116828.606 [CTD_NeilBrown](DEBUG): serial timeout 2017-12-12T22:13:49.695Z,1513116829.695 [CTD_NeilBrown](DEBUG): serial timeout 2017-12-12T22:13:52.103Z,1513116832.103 [CTD_NeilBrown](DEBUG): serial timeout 2017-12-12T22:13:52.712Z,1513116832.712 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface 2017-12-12T22:13:52.782Z,1513116832.782 [CTD_Seabird](INFO): Started Seabird LCM interface with command:nohup ./lrauv-framework/onboard/bin/gpctd -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyC6 -b 9600 >& /dev/null & 2017-12-12T22:13:52.823Z,1513116832.823 [CTD_Seabird](INFO): LCM subscribed to channel:ctd_t.seabird-gpctd 2017-12-12T22:13:54.511Z,1513116834.511 [CTD_NeilBrown](DEBUG): serial timeout 2017-12-12T22:13:54.934Z,1513116834.934 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2017-12-12T22:13:54.934Z,1513116834.934 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 2 2017-12-12T22:13:54.934Z,1513116834.934 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2017-12-12T22:13:54.939Z,1513116834.939 [CTD_NeilBrown](DEBUG): serial timeout 2017-12-12T22:13:54.941Z,1513116834.941 [DeadReckonWithRespectToSeafloor](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2017-12-12T22:13:54.942Z,1513116834.942 [DeadReckonWithRespectToSeafloor] Software Fault, FailCount= 2 2017-12-12T22:13:54.942Z,1513116834.942 [DeadReckonWithRespectToSeafloor](ERROR): Software Fault 2017-12-12T22:13:55.032Z,1513116835.032 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2017-12-12T22:13:55.033Z,1513116835.033 [CBIT](ERROR): Software Fault in component: DeadReckonWithRespectToSeafloor 2017-12-12T22:13:55.388Z,1513116835.388 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2017-12-12T22:13:55.388Z,1513116835.388 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 2 2017-12-12T22:13:55.389Z,1513116835.389 [CBIT](INFO): Clearing failed state for component DeadReckonWithRespectToSeafloor 2017-12-12T22:13:55.389Z,1513116835.389 [DeadReckonWithRespectToSeafloor] No Fault, FailCount= 2 2017-12-12T22:13:55.777Z,1513116835.777 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2017-12-12T22:13:55.778Z,1513116835.778 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2017-12-12T22:13:55.778Z,1513116835.778 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2017-12-12T22:13:55.779Z,1513116835.779 [DeadReckonWithRespectToSeafloor](DEBUG): Initializing DeadReckonWithRespectToSeafloor component. 2017-12-12T22:13:55.780Z,1513116835.780 [DeadReckonWithRespectToSeafloor](INFO): Will consider orientation measurement stale after 120s. 2017-12-12T22:13:55.780Z,1513116835.780 [DeadReckonWithRespectToSeafloor](INFO): Will consider velocity measurement stale after 20s. 2017-12-12T22:13:56.046Z,1513116836.046 [Aanderaa_O2](DEBUG): Error parsing data: 4831F 241 239.117 82.304 18.851 30.845 30.845 39.557 8.712 245.9 518.7 135.3 2017-12-12T22:13:56.046Z,1513116836.046 [Aanderaa_O2](DEBUG): Error parsing device response 2017-12-12T22:13:57.247Z,1513116837.247 [Aanderaa_O2](DEBUG): Error parsing data: 4831F 241 239.695 82.403 18.792 30.843 30.843 39.553 8.711 246.0 518.1 137.3 2017-12-12T22:13:57.248Z,1513116837.248 [Aanderaa_O2](DEBUG): Error parsing device response 2017-12-12T22:14:01.247Z,1513116841.247 [Aanderaa_O2](DEBUG): Error parsing data: 4831F 241 237.998 81.652 18.691 30.971 30.971 39.671 8.700 247.0 516.3 140.6 2017-12-12T22:14:01.248Z,1513116841.248 [Aanderaa_O2](DEBUG): Error parsing device response 2017-12-12T22:14:01.538Z,1513116841.538 [CTD_NeilBrown](DEBUG): serial timeout 2017-12-12T22:14:03.538Z,1513116843.538 [CTD_NeilBrown](DEBUG): serial timeout 2017-12-12T22:14:06.566Z,1513116846.566 [CTD_NeilBrown](DEBUG): serial timeout 2017-12-12T22:14:09.191Z,1513116849.191 [CommandLine](IMPORTANT): got command show stack 2017-12-12T22:14:09.191Z,1513116849.191 [CommandLine](IMPORTANT): Behavior Stack: 2017-12-12T22:14:09.193Z,1513116849.193 [ballast_and_trim:Science](IMPORTANT): Priority 0: ballast_and_trim:Science:A 2017-12-12T22:14:09.193Z,1513116849.193 [ballast_and_trim:Science](IMPORTANT): Priority 1: ballast_and_trim:Science:C 2017-12-12T22:14:09.193Z,1513116849.193 [ballast_and_trim:Science](IMPORTANT): Priority 2: ballast_and_trim:Science:D 2017-12-12T22:14:09.194Z,1513116849.194 [ballast_and_trim:Science](IMPORTANT): Priority 3: ballast_and_trim:Science:G 2017-12-12T22:14:09.194Z,1513116849.194 [ballast_and_trim:Science](IMPORTANT): Priority 4: ballast_and_trim:Science:H 2017-12-12T22:14:09.197Z,1513116849.197 [ballast_and_trim:RunBallastAndTrim:Depth1:BallastAndTrim](IMPORTANT): Priority 5: ballast_and_trim:RunBallastAndTrim:Depth1:BallastAndTrim:A 2017-12-12T22:14:09.197Z,1513116849.197 [ballast_and_trim:RunBallastAndTrim:Depth1:BallastAndTrim](IMPORTANT): Priority 6: ballast_and_trim:RunBallastAndTrim:Depth1:BallastAndTrim:B 2017-12-12T22:14:09.198Z,1513116849.198 [ballast_and_trim:RunBallastAndTrim:Depth1:BallastAndTrim](IMPORTANT): Priority 7: ballast_and_trim:RunBallastAndTrim:Depth1:BallastAndTrim:C 2017-12-12T22:14:09.198Z,1513116849.198 [ballast_and_trim:RunBallastAndTrim:Depth1:BallastAndTrim](IMPORTANT): Priority 8: ballast_and_trim:RunBallastAndTrim:Depth1:BallastAndTrim:D 2017-12-12T22:14:09.198Z,1513116849.198 [ballast_and_trim:RunBallastAndTrim:Depth1:BallastAndTrim](IMPORTANT): Priority 9: ballast_and_trim:RunBallastAndTrim:Depth1:BallastAndTrim:E.SetSpeed 2017-12-12T22:14:09.199Z,1513116849.199 [ballast_and_trim:RunBallastAndTrim:Depth1:BallastAndTrim](IMPORTANT): Priority 10: ballast_and_trim:RunBallastAndTrim:Depth1:BallastAndTrim:F.Pitch 2017-12-12T22:14:09.918Z,1513116849.918 [CTD_NeilBrown](DEBUG): serial timeout 2017-12-12T22:14:10.338Z,1513116850.339 [CTD_NeilBrown](DEBUG): serial timeout 2017-12-12T22:14:10.736Z,1513116850.736 [CBIT](INFO): Clearing failed state for component NAL9602 2017-12-12T22:14:10.736Z,1513116850.736 [NAL9602] No Fault, FailCount= 5 2017-12-12T22:14:10.771Z,1513116850.771 [CTD_NeilBrown](DEBUG): serial timeout 2017-12-12T22:14:11.002Z,1513116851.002 [NAL9602](INFO): Powering up NAL9602 2017-12-12T22:14:15.166Z,1513116855.166 [CTD_NeilBrown](DEBUG): serial timeout 2017-12-12T22:14:19.787Z,1513116859.787 [CTD_NeilBrown](DEBUG): serial timeout 2017-12-12T22:14:21.978Z,1513116861.978 [CTD_NeilBrown](DEBUG): serial timeout 2017-