2019-05-14T16:15:10.046Z,1557850510.046 [Supervisor](DEBUG): Initializing supervisor.
2019-05-14T16:15:10.049Z,1557850510.049 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2019-05-14T16:15:10.050Z,1557850510.050 [SyncHandler](INFO): Protected caller Thread ID is 7215
2019-05-14T16:15:10.050Z,1557850510.050 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2019-05-14T16:15:10.051Z,1557850510.051 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2019-05-14T16:15:10.052Z,1557850510.052 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 7216
2019-05-14T16:15:10.055Z,1557850510.055 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2019-05-14T16:15:10.067Z,1557850510.067 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2019-05-14T16:15:10.068Z,1557850510.068 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2019-05-14T16:15:10.068Z,1557850510.068 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 7217
2019-05-14T16:15:10.069Z,1557850510.069 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2019-05-14T16:15:10.070Z,1557850510.070 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2019-05-14T16:15:10.071Z,1557850510.071 [logger ThreadHandler](INFO): Protected caller Thread ID is 7218
2019-05-14T16:15:10.073Z,1557850510.073 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2019-05-14T16:15:10.073Z,1557850510.073 [Supervisor](INFO): Looking for Config files in directory: Config/
2019-05-14T16:15:10.075Z,1557850510.075 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2019-05-14T16:15:10.346Z,1557850510.346 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2019-05-14T16:15:10.346Z,1557850510.346 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2019-05-14T16:15:10.428Z,1557850510.428 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2019-05-14T16:15:10.867Z,1557850510.867 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2019-05-14T16:15:10.868Z,1557850510.868 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2019-05-14T16:15:11.205Z,1557850511.205 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2019-05-14T16:15:11.206Z,1557850511.206 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2019-05-14T16:15:11.304Z,1557850511.304 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2019-05-14T16:15:11.304Z,1557850511.304 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2019-05-14T16:15:11.604Z,1557850511.604 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2019-05-14T16:15:11.605Z,1557850511.605 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2019-05-14T16:15:11.801Z,1557850511.801 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2019-05-14T16:15:11.802Z,1557850511.802 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2019-05-14T16:15:12.259Z,1557850512.259 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2019-05-14T16:15:12.260Z,1557850512.260 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2019-05-14T16:15:12.367Z,1557850512.367 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2019-05-14T16:15:12.368Z,1557850512.368 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2019-05-14T16:15:12.470Z,1557850512.470 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2019-05-14T16:15:12.471Z,1557850512.471 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2019-05-14T16:15:13.045Z,1557850513.045 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2019-05-14T16:15:13.046Z,1557850513.046 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2019-05-14T16:15:13.446Z,1557850513.446 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2019-05-14T16:15:13.446Z,1557850513.446 [Supervisor](INFO): Opening Config file at: Config/._workSite.cfg
2019-05-14T16:15:13.704Z,1557850513.704 [Config/._workSite](ERROR): Could not parse value: resource
2019-05-14T16:15:13.996Z,1557850513.996 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2019-05-14T16:15:14.196Z,1557850514.196 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2019-05-14T16:15:14.197Z,1557850514.197 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2019-05-14T16:15:14.343Z,1557850514.343 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2019-05-14T16:15:14.344Z,1557850514.344 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2019-05-14T16:15:14.495Z,1557850514.495 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2019-05-14T16:15:14.497Z,1557850514.497 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2019-05-14T16:15:14.498Z,1557850514.498 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2019-05-14T16:15:14.590Z,1557850514.590 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2019-05-14T16:15:14.677Z,1557850514.677 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2019-05-14T16:15:14.781Z,1557850514.781 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2019-05-14T16:15:14.866Z,1557850514.866 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2019-05-14T16:15:14.963Z,1557850514.963 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2019-05-14T16:15:15.065Z,1557850515.065 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2019-05-14T16:15:15.275Z,1557850515.275 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2019-05-14T16:15:15.354Z,1557850515.354 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2019-05-14T16:15:15.525Z,1557850515.525 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2019-05-14T16:15:15.662Z,1557850515.662 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2019-05-14T16:15:15.784Z,1557850515.784 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg
2019-05-14T16:15:16.016Z,1557850516.016 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2019-05-14T16:15:16.018Z,1557850516.018 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/root/
2019-05-14T16:15:16.018Z,1557850516.018 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2019-05-14T16:15:16.028Z,1557850516.028 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2019-05-14T16:15:16.098Z,1557850516.098 [VerticalControl](DEBUG): Construct VerticalControl.
2019-05-14T16:15:16.212Z,1557850516.212 [VerticalControl] Loaded
2019-05-14T16:15:16.212Z,1557850516.212 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2019-05-14T16:15:16.213Z,1557850516.213 [HorizontalControl](DEBUG): Construct HorizontalControl.
2019-05-14T16:15:16.282Z,1557850516.282 [HorizontalControl] Loaded
2019-05-14T16:15:16.282Z,1557850516.282 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2019-05-14T16:15:16.283Z,1557850516.283 [SpeedControl](DEBUG): Construct SpeedControl.
2019-05-14T16:15:16.288Z,1557850516.288 [SpeedControl] Loaded
2019-05-14T16:15:16.288Z,1557850516.288 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2019-05-14T16:15:16.289Z,1557850516.289 [LoopControl](DEBUG): Construct LoopControl.
2019-05-14T16:15:16.290Z,1557850516.290 [LoopControl] Loaded
2019-05-14T16:15:16.290Z,1557850516.290 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2019-05-14T16:15:16.290Z,1557850516.290 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2019-05-14T16:15:16.291Z,1557850516.291 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2019-05-14T16:15:16.305Z,1557850516.305 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2019-05-14T16:15:16.305Z,1557850516.305 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2019-05-14T16:15:16.410Z,1557850516.410 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2019-05-14T16:15:16.410Z,1557850516.410 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2019-05-14T16:15:16.543Z,1557850516.543 [BuoyancyServo] Loaded
2019-05-14T16:15:16.543Z,1557850516.543 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2019-05-14T16:15:16.554Z,1557850516.554 [ElevatorServo] Loaded
2019-05-14T16:15:16.554Z,1557850516.554 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2019-05-14T16:15:16.565Z,1557850516.565 [MassServo] Loaded
2019-05-14T16:15:16.565Z,1557850516.565 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2019-05-14T16:15:16.576Z,1557850516.576 [RudderServo] Loaded
2019-05-14T16:15:16.577Z,1557850516.577 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2019-05-14T16:15:16.587Z,1557850516.587 [ThrusterServo] Loaded
2019-05-14T16:15:16.588Z,1557850516.588 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2019-05-14T16:15:16.588Z,1557850516.588 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2019-05-14T16:15:16.589Z,1557850516.589 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2019-05-14T16:15:16.700Z,1557850516.700 [DeadReckonUsingMultipleVelocitySources] Loaded
2019-05-14T16:15:16.700Z,1557850516.700 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2019-05-14T16:15:16.720Z,1557850516.720 [NavChart] Loaded
2019-05-14T16:15:16.721Z,1557850516.721 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2019-05-14T16:15:16.725Z,1557850516.725 [UniversalFixResidualReporter] Loaded
2019-05-14T16:15:16.725Z,1557850516.725 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2019-05-14T16:15:16.725Z,1557850516.725 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2019-05-14T16:15:16.726Z,1557850516.726 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2019-05-14T16:15:16.803Z,1557850516.803 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2019-05-14T16:15:16.804Z,1557850516.804 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2019-05-14T16:15:17.211Z,1557850517.211 [AHRS_M2] Loaded
2019-05-14T16:15:17.211Z,1557850517.211 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2019-05-14T16:15:17.286Z,1557850517.286 [DataOverHttps] Loaded
2019-05-14T16:15:17.286Z,1557850517.286 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2019-05-14T16:15:17.287Z,1557850517.287 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4087B4E0
2019-05-14T16:15:17.287Z,1557850517.287 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 7303
2019-05-14T16:15:17.301Z,1557850517.301 [Depth_Keller] Loaded
2019-05-14T16:15:17.301Z,1557850517.301 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2019-05-14T16:15:17.434Z,1557850517.434 [DVL_micro] Loaded
2019-05-14T16:15:17.434Z,1557850517.434 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread.
2019-05-14T16:15:17.533Z,1557850517.533 [NAL9602] Loaded
2019-05-14T16:15:17.534Z,1557850517.534 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2019-05-14T16:15:17.550Z,1557850517.550 [Onboard] Loaded
2019-05-14T16:15:17.550Z,1557850517.550 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2019-05-14T16:15:17.554Z,1557850517.554 [Radio_Surface] Loaded
2019-05-14T16:15:17.554Z,1557850517.554 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2019-05-14T16:15:17.555Z,1557850517.555 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408AB4E0
2019-05-14T16:15:17.555Z,1557850517.555 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 7304
2019-05-14T16:15:17.688Z,1557850517.688 [DAT] Loaded
2019-05-14T16:15:17.688Z,1557850517.688 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread.
2019-05-14T16:15:17.689Z,1557850517.689 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2019-05-14T16:15:17.690Z,1557850517.690 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2019-05-14T16:15:17.732Z,1557850517.732 [DepthRateCalculator] Loaded
2019-05-14T16:15:17.732Z,1557850517.732 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2019-05-14T16:15:17.738Z,1557850517.738 [PitchRateCalculator] Loaded
2019-05-14T16:15:17.738Z,1557850517.738 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2019-05-14T16:15:17.749Z,1557850517.749 [SpeedCalculator] Loaded
2019-05-14T16:15:17.750Z,1557850517.750 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2019-05-14T16:15:17.771Z,1557850517.771 [TempGradientCalculator] Loaded
2019-05-14T16:15:17.771Z,1557850517.771 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2019-05-14T16:15:17.776Z,1557850517.776 [YawRateCalculator] Loaded
2019-05-14T16:15:17.777Z,1557850517.777 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2019-05-14T16:15:17.806Z,1557850517.806 [ElevatorOffsetCalculator] Loaded
2019-05-14T16:15:17.806Z,1557850517.806 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2019-05-14T16:15:17.807Z,1557850517.807 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2019-05-14T16:15:17.807Z,1557850517.807 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2019-05-14T16:15:18.005Z,1557850518.005 [Aanderaa_O2] Loaded
2019-05-14T16:15:18.006Z,1557850518.006 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2019-05-14T16:15:18.093Z,1557850518.093 [CTD_NeilBrown] Loaded
2019-05-14T16:15:18.094Z,1557850518.094 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2019-05-14T16:15:18.095Z,1557850518.095 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 409A54E0
2019-05-14T16:15:18.095Z,1557850518.095 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 7305
2019-05-14T16:15:18.104Z,1557850518.104 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density
2019-05-14T16:15:18.109Z,1557850518.109 [CTD_Seabird](INFO): created writer for : sea_water_density
2019-05-14T16:15:18.111Z,1557850518.111 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth
2019-05-14T16:15:18.116Z,1557850518.116 [CTD_Seabird](INFO): created writer for : depth
2019-05-14T16:15:18.117Z,1557850518.117 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure
2019-05-14T16:15:18.122Z,1557850518.122 [CTD_Seabird](INFO): created writer for : sea_water_pressure
2019-05-14T16:15:18.123Z,1557850518.123 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity
2019-05-14T16:15:18.128Z,1557850518.128 [CTD_Seabird](INFO): created writer for : sea_water_salinity
2019-05-14T16:15:18.128Z,1557850518.128 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature
2019-05-14T16:15:18.133Z,1557850518.133 [CTD_Seabird](INFO): created writer for : sea_water_temperature
2019-05-14T16:15:18.134Z,1557850518.134 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity
2019-05-14T16:15:18.139Z,1557850518.139 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity
2019-05-14T16:15:18.140Z,1557850518.140 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water
2019-05-14T16:15:18.145Z,1557850518.145 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water
2019-05-14T16:15:18.173Z,1557850518.173 [CTD_Seabird] Loaded
2019-05-14T16:15:18.173Z,1557850518.173 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2019-05-14T16:15:18.175Z,1557850518.175 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 409D54E0
2019-05-14T16:15:18.175Z,1557850518.175 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 7306
2019-05-14T16:15:18.189Z,1557850518.189 [PAR_Licor] Loaded
2019-05-14T16:15:18.190Z,1557850518.190 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2019-05-14T16:15:18.239Z,1557850518.239 [WetLabsBB2FL] Loaded
2019-05-14T16:15:18.239Z,1557850518.239 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2019-05-14T16:15:18.240Z,1557850518.240 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40A054E0
2019-05-14T16:15:18.240Z,1557850518.240 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 7307
2019-05-14T16:15:18.241Z,1557850518.241 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2019-05-14T16:15:18.241Z,1557850518.241 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2019-05-14T16:15:18.270Z,1557850518.270 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2019-05-14T16:15:18.270Z,1557850518.270 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2019-05-14T16:15:18.577Z,1557850518.577 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2019-05-14T16:15:18.578Z,1557850518.578 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2019-05-14T16:15:18.860Z,1557850518.860 [SBIT](DEBUG): Construct Startup Built In Test.
2019-05-14T16:15:18.910Z,1557850518.910 [SBIT] Loaded
2019-05-14T16:15:18.910Z,1557850518.910 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2019-05-14T16:15:18.911Z,1557850518.911 [IBIT](DEBUG): Construct Initiated Built In Test.
2019-05-14T16:15:18.923Z,1557850518.923 [IBIT] Loaded
2019-05-14T16:15:18.923Z,1557850518.923 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2019-05-14T16:15:18.927Z,1557850518.927 [CBIT](DEBUG): Construct Continuous Built In Test.
2019-05-14T16:15:19.483Z,1557850519.483 [CBIT] Loaded
2019-05-14T16:15:19.483Z,1557850519.483 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2019-05-14T16:15:19.484Z,1557850519.484 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2019-05-14T16:15:19.487Z,1557850519.487 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2019-05-14T16:15:19.488Z,1557850519.488 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2019-05-14T16:15:19.495Z,1557850519.495 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2019-05-14T16:15:19.496Z,1557850519.496 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B034E0
2019-05-14T16:15:19.497Z,1557850519.497 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 7308
2019-05-14T16:15:19.502Z,1557850519.502 [Supervisor](INFO): Main Thread ID is 6074
2019-05-14T16:15:19.502Z,1557850519.502 [Supervisor](DEBUG): Running supervisor.
2019-05-14T16:15:19.502Z,1557850519.502 [CommandLine ThreadHandler](INFO): Handler Thread ID is 7309
2019-05-14T16:15:19.505Z,1557850519.505 [controlThread ThreadHandler](INFO): Handler Thread ID is 7310
2019-05-14T16:15:19.505Z,1557850519.505 [controlThread](DEBUG): Initializing ControlThread
2019-05-14T16:15:19.506Z,1557850519.506 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2019-05-14T16:15:19.508Z,1557850519.508 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2019-05-14T16:15:19.508Z,1557850519.508 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2019-05-14T16:15:19.509Z,1557850519.509 [LoopControl](DEBUG): Initialize LoopControlComponent.
2019-05-14T16:15:19.511Z,1557850519.511 [NavChart](DEBUG): Initialize NavChart Navigation.
2019-05-14T16:15:19.511Z,1557850519.511 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2019-05-14T16:15:19.514Z,1557850519.514 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2019-05-14T16:15:19.515Z,1557850519.515 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2019-05-14T16:15:19.515Z,1557850519.515 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2019-05-14T16:15:19.515Z,1557850519.515 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2019-05-14T16:15:19.516Z,1557850519.516 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2019-05-14T16:15:19.516Z,1557850519.516 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2019-05-14T16:15:19.521Z,1557850519.521 [SBIT](INFO): Initialize SBIT Component.
2019-05-14T16:15:19.522Z,1557850519.522 [SBIT](IMPORTANT): git: 2019-04-10-19-gda15b3b
2019-05-14T16:15:19.522Z,1557850519.522 [SBIT](INFO): git hash: da15b3bc615cce9b5cb8428ed44ec3695b388448
2019-05-14T16:15:19.522Z,1557850519.522 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2019-05-14T16:15:19.523Z,1557850519.523 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #1 PREEMPT Tue Dec 18 21:19:28 PST 2018
2019-05-14T16:15:19.524Z,1557850519.524 [SBIT](INFO): Beginning SBIT in 59.000000 seconds.
2019-05-14T16:15:19.525Z,1557850519.525 [IBIT](INFO): Initialize IBIT Component.
2019-05-14T16:15:19.526Z,1557850519.526 [CBIT](DEBUG): Initialize CBIT Component.
2019-05-14T16:15:19.527Z,1557850519.527 [logger ThreadHandler](INFO): Handler Thread ID is 7311
2019-05-14T16:15:19.537Z,1557850519.537 [CBIT](DEBUG): Initialized mux pins.
2019-05-14T16:15:19.537Z,1557850519.537 [CBIT](DEBUG): Initializing the watchdog timer.
2019-05-14T16:15:19.545Z,1557850519.545 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 7312
2019-05-14T16:15:19.546Z,1557850519.546 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2019-05-14T16:15:19.557Z,1557850519.557 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 7313
2019-05-14T16:15:19.561Z,1557850519.561 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2019-05-14T16:15:19.561Z,1557850519.561 [CBIT](DEBUG): Initializing heartbeat.
2019-05-14T16:15:19.569Z,1557850519.569 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 7314
2019-05-14T16:15:19.570Z,1557850519.570 [CTD_NeilBrown](INFO): Powering down
2019-05-14T16:15:19.597Z,1557850519.597 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 7315
2019-05-14T16:15:19.598Z,1557850519.598 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2019-05-14T16:15:19.605Z,1557850519.605 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 7317
2019-05-14T16:15:19.606Z,1557850519.606 [WetLabsBB2FL](INFO): Powering down
2019-05-14T16:15:19.625Z,1557850519.625 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20
2019-05-14T16:15:19.633Z,1557850519.633 [CBIT](DEBUG): Deactivating GF circuits.
2019-05-14T16:15:19.633Z,1557850519.633 [CBIT](DEBUG): Deactivating emergency mode.
2019-05-14T16:15:19.634Z,1557850519.634 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 7318
2019-05-14T16:15:19.643Z,1557850519.643 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2019-05-14T16:15:19.643Z,1557850519.643 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2019-05-14T16:15:19.643Z,1557850519.643 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2019-05-14T16:15:19.644Z,1557850519.644 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2019-05-14T16:15:19.644Z,1557850519.644 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2019-05-14T16:15:19.644Z,1557850519.644 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2019-05-14T16:15:19.644Z,1557850519.644 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2019-05-14T16:15:19.644Z,1557850519.644 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2019-05-14T16:15:19.644Z,1557850519.644 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2019-05-14T16:15:19.645Z,1557850519.645 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2019-05-14T16:15:19.645Z,1557850519.645 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2019-05-14T16:15:19.645Z,1557850519.645 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2019-05-14T16:15:19.646Z,1557850519.646 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2019-05-14T16:15:19.646Z,1557850519.646 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2019-05-14T16:15:19.646Z,1557850519.646 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2019-05-14T16:15:19.646Z,1557850519.646 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2019-05-14T16:15:19.669Z,1557850519.669 [CBIT](DEBUG): Backplane powered.
2019-05-14T16:15:19.670Z,1557850519.670 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2019-05-14T16:15:19.683Z,1557850519.683 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2019-05-14T16:15:19.719Z,1557850519.719 [MissionManager](DEBUG):
2019-05-14T16:15:19.719Z,1557850519.719 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2019-05-14T16:15:19.792Z,1557850519.792 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2019-05-14T16:15:19.793Z,1557850519.793 [Default:A.Wait](DEBUG): Construct Wait.
2019-05-14T16:15:19.795Z,1557850519.795 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2019-05-14T16:15:19.833Z,1557850519.833 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2019-05-14T16:15:19.836Z,1557850519.836 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2019-05-14T16:15:19.862Z,1557850519.862 [Default:E.Execute](DEBUG): Construct Execute.
2019-05-14T16:15:19.870Z,1557850519.870 [MissionManager](DEBUG):
0
Wait a moment to see if the scheduler starts a new mission before
starting to actually run Default.
13
Burn on
Dropped weight due to communications timeout.
5
Default mission has been running for
Restarting logs and Default mission.
restart logs
2019-05-14T16:15:19.885Z,1557850519.885 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DVL_micro,NAL9602,Onboard,DAT,Aanderaa_O2,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2019-05-14T16:15:19.903Z,1557850519.903 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2019-05-14T16:15:19.961Z,1557850519.961 [Radio_Surface](INFO): Powering up
2019-05-14T16:15:20.074Z,1557850520.074 [DVL_micro](INFO): Initializing
2019-05-14T16:15:20.099Z,1557850520.099 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2019-05-14T16:15:20.099Z,1557850520.099 [DAT](INFO): Powering up
2019-05-14T16:15:20.099Z,1557850520.099 [DAT](DEBUG): Initializing DAT.
2019-05-14T16:15:20.101Z,1557850520.101 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2019-05-14T16:15:20.275Z,1557850520.275 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2019-05-14T16:15:20.281Z,1557850520.281 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2019-05-14T16:15:20.282Z,1557850520.282 [ElevatorServo](DEBUG): Initializing EZServoServo.
2019-05-14T16:15:20.289Z,1557850520.289 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2019-05-14T16:15:20.290Z,1557850520.290 [MassServo](DEBUG): Initializing EZServoServo.
2019-05-14T16:15:20.297Z,1557850520.297 [MassServo](DEBUG): Initializing MassServo.
2019-05-14T16:15:20.298Z,1557850520.298 [RudderServo](DEBUG): Initializing EZServoServo.
2019-05-14T16:15:20.305Z,1557850520.305 [RudderServo](DEBUG): Initializing RudderServo.
2019-05-14T16:15:20.306Z,1557850520.306 [ThrusterServo](DEBUG): Initializing EZServoServo.
2019-05-14T16:15:20.313Z,1557850520.313 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2019-05-14T16:15:23.433Z,1557850523.433 [Aanderaa_O2](INFO): Powering down
2019-05-14T16:15:27.633Z,1557850527.633 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit.
2019-05-14T16:15:33.335Z,1557850533.335 [DAT](INFO): setting local address to 2
2019-05-14T16:15:33.759Z,1557850533.759 [DAT](INFO): set local address to 2
2019-05-14T16:15:47.872Z,1557850547.872 [NAL9602](INFO): Powering up NAL9602
2019-05-14T16:15:58.784Z,1557850558.784 [NAL9602](INFO): NAL9602 initialized
2019-05-14T16:15:59.621Z,1557850559.621 [NAL9602](DEBUG): Fix Requested
2019-05-14T16:16:19.052Z,1557850579.052 [SBIT](IMPORTANT): Beginning Startup BIT
2019-05-14T16:16:19.060Z,1557850579.060 [CBIT](IMPORTANT): Beginning ground fault scan
2019-05-14T16:16:30.023Z,1557850590.023 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 4.657929
CHAN A1 (24V): -0.017305
CHAN A2 (12V): -0.002283
CHAN A3 (5V): -0.000954
CHAN B0 (3.3V): 4.766929
CHAN B1 (3.15aV): -0.000279
CHAN B2 (3.15bV): -0.000261
CHAN B3 (GND): -0.000129
OPEN: -0.000138
Full Scale Calc: 4.765 mA, -1.589 mA
2019-05-14T16:17:12.690Z,1557850632.690 [SBIT](IMPORTANT): SBIT PASSED
2019-05-14T16:17:12.762Z,1557850632.762 [CommandLine](IMPORTANT): got command configSet list
2019-05-14T16:17:12.762Z,1557850632.762 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2019-05-14T16:17:12.763Z,1557850632.763 [CommandLine](IMPORTANT): Aanderaa_O2.loadAtStartup=1 bool;
2019-05-14T16:17:12.763Z,1557850632.763 [CommandLine](IMPORTANT): BPC1.batteryMissingStickThreshold=8 count;
2019-05-14T16:17:12.763Z,1557850632.763 [CommandLine](IMPORTANT): BPC1.batterySamplingInterval=3 hour;
2019-05-14T16:17:12.763Z,1557850632.763 [CommandLine](IMPORTANT): BPC1.loadAtStartup=0 bool;
2019-05-14T16:17:12.763Z,1557850632.763 [CommandLine](IMPORTANT): CBIT.gf24Offset=172 microampere;
2019-05-14T16:17:12.764Z,1557850632.764 [CommandLine](IMPORTANT): DropWeight.loadAtStartup=0 bool;
2019-05-14T16:17:12.764Z,1557850632.764 [CommandLine](IMPORTANT): Express none DVL_micro.height_above_sea_floor;
2019-05-14T16:17:12.764Z,1557850632.764 [CommandLine](IMPORTANT): NAL9602.fastGPSFix=1 bool;
2019-05-14T16:17:12.764Z,1557850632.764 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=90 cubic_centimeter;
2019-05-14T16:17:12.764Z,1557850632.764 [CommandLine](IMPORTANT): VerticalControl.massDefault=-1 centimeter;
2019-05-14T16:17:13.083Z,1557850633.083 [MissionManager](IMPORTANT): Started mission Startup
2019-05-14T16:17:13.083Z,1557850633.083 [Startup] Running Loop=1
2019-05-14T16:17:13.084Z,1557850633.084 [Startup](DEBUG): Aggregate::initialize Startup
2019-05-14T16:17:13.084Z,1557850633.084 [Startup:A.GoToSurface] Running Loop=1
2019-05-14T16:17:13.084Z,1557850633.084 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-05-14T16:17:13.084Z,1557850633.084 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-05-14T16:17:13.086Z,1557850633.086 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-05-14T16:17:13.086Z,1557850633.086 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-05-14T16:17:13.086Z,1557850633.086 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-05-14T16:17:13.087Z,1557850633.087 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-05-14T16:17:13.088Z,1557850633.088 [Startup:StartupSatComms] Running Loop=1
2019-05-14T16:17:13.088Z,1557850633.088 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2019-05-14T16:17:13.088Z,1557850633.088 [Startup:StartupSatComms:A] Running Loop=1
2019-05-14T16:17:13.496Z,1557850633.496 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2019-05-14T16:17:21.942Z,1557850641.942 [NAL9602](INFO): SBD MO Status=2, MOMSN=12096, MT Status=2, MTMSN=0
2019-05-14T16:17:21.943Z,1557850641.943 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-05-14T16:17:44.190Z,1557850664.190 [NAL9602](INFO): SBD MO Status=2, MOMSN=12096, MT Status=2, MTMSN=0
2019-05-14T16:17:44.192Z,1557850664.192 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-05-14T16:18:04.067Z,1557850684.067 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004874
2019-05-14T16:18:13.288Z,1557850693.288 [Startup:StartupSatComms:A](INFO): Timed out from 2019-05-14T16:17:13.1Z
2019-05-14T16:18:13.288Z,1557850693.288 [Startup:StartupSatComms:A] Stopped
2019-05-14T16:18:13.288Z,1557850693.288 [Startup:StartupSatComms:B] Running Loop=1
2019-05-14T16:18:13.680Z,1557850693.680 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-05-14T16:18:19.745Z,1557850699.745 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2019-05-14T16:18:19.745Z,1557850699.745 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-05-14T16:18:19.775Z,1557850699.775 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-05-14T16:18:19.885Z,1557850699.885 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190514T002117/Courier0499.lzma
2019-05-14T16:18:20.158Z,1557850700.158 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-05-14T16:18:20.158Z,1557850700.158 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2019-05-14T16:18:20.691Z,1557850700.691 [DataOverHttps](INFO): Moved sent file to Logs/20190514T002117/Courier0499.lzma.bak
2019-05-14T16:18:20.691Z,1557850700.691 [DataOverHttps](INFO): SBD MOMSN=11053028
2019-05-14T16:19:13.494Z,1557850753.494 [Startup:StartupSatComms:B](INFO): Timed out from 2019-05-14T16:18:13.3Z
2019-05-14T16:19:13.494Z,1557850753.494 [Startup:StartupSatComms:B] Stopped
2019-05-14T16:19:13.494Z,1557850753.494 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2019-05-14T16:19:13.494Z,1557850753.494 [Startup:StartupSatComms] Stopped
2019-05-14T16:19:13.495Z,1557850753.495 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2019-05-14T16:19:13.495Z,1557850753.495 [Startup](INFO): Completed Startup
2019-05-14T16:19:13.495Z,1557850753.495 [MissionManager](INFO): Startup is completed.
2019-05-14T16:19:13.496Z,1557850753.496 [MissionManager](INFO): Uninitializing Mission Startup
2019-05-14T16:19:13.496Z,1557850753.496 [Startup] Stopped
2019-05-14T16:19:13.496Z,1557850753.496 [Startup](DEBUG): Aggregate::uninitialize Startup
2019-05-14T16:19:13.496Z,1557850753.496 [Startup:A.GoToSurface] Stopped
2019-05-14T16:19:13.496Z,1557850753.496 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-05-14T16:19:13.898Z,1557850753.898 [MissionManager](IMPORTANT): Started mission Default
2019-05-14T16:19:13.898Z,1557850753.898 [Default] Running Loop=1
2019-05-14T16:19:13.899Z,1557850753.899 [Default](DEBUG): Aggregate::initialize Default
2019-05-14T16:19:13.899Z,1557850753.899 [Default:B.GoToSurface] Running Loop=1
2019-05-14T16:19:13.899Z,1557850753.899 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-05-14T16:19:13.899Z,1557850753.899 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-05-14T16:19:13.899Z,1557850753.899 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-05-14T16:19:13.900Z,1557850753.900 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-05-14T16:19:13.900Z,1557850753.900 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-05-14T16:19:13.900Z,1557850753.900 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-05-14T16:19:13.905Z,1557850753.905 [Default:A.Wait] Running Loop=1
2019-05-14T16:19:13.905Z,1557850753.905 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-05-14T16:19:22.153Z,1557850762.153 [DataOverHttps](INFO): Sending 465 bytes from file Logs/20190514T002117/Express0500.lzma
2019-05-14T16:19:22.959Z,1557850762.959 [DataOverHttps](INFO): Moved sent file to Logs/20190514T002117/Express0500.lzma.bak
2019-05-14T16:19:22.959Z,1557850762.959 [DataOverHttps](INFO): SBD MOMSN=11053032
2019-05-14T16:19:27.220Z,1557850767.220 [Default:A.Wait](INFO): Done Waiting.
2019-05-14T16:19:27.220Z,1557850767.220 [Default:A.Wait] Stopped
2019-05-14T16:19:27.220Z,1557850767.220 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-05-14T16:19:27.643Z,1557850767.643 [Default:CheckIn] Running Loop=1
2019-05-14T16:19:27.643Z,1557850767.643 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-05-14T16:19:27.643Z,1557850767.643 [Default:CheckIn:Read_GPS] Running Loop=1
2019-05-14T16:19:28.019Z,1557850768.019 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2019-05-14T16:20:19.846Z,1557850819.846 [CommandLine](IMPORTANT): got command report touch acoustic_contact_range
2019-05-14T16:21:01.715Z,1557850861.715 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-05-14T16:21:02.537Z,1557850862.537 [NAL9602](DEBUG): Fix Requested
2019-05-14T16:21:04.691Z,1557850864.691 [CommandLine](IMPORTANT): got command get time_fix
2019-05-14T16:21:04.691Z,1557850864.691 [CommandLine](FAULT): Element has no value
2019-05-14T16:21:06.577Z,1557850866.577 [NAL9602](DEBUG): Fix Requested
2019-05-14T16:21:06.980Z,1557850866.980 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160838.00,A,3648.16136,N,12147.28061,W,2.022,187.09,140519,,,A*73
2019-05-14T16:21:06.984Z,1557850866.984 [NAL9602](INFO): GPS fix at 20190514T160838: (36.802689, -121.788010)
2019-05-14T16:21:07.014Z,1557850867.014 [Default:CheckIn:Read_GPS] Stopped
2019-05-14T16:21:07.014Z,1557850867.014 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-05-14T16:21:07.421Z,1557850867.421 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-05-14T16:21:16.669Z,1557850876.669 [DataOverHttps](INFO): Sending 212 bytes from file Logs/20190514T161510/Courier0004.lzma
2019-05-14T16:21:17.475Z,1557850877.475 [DataOverHttps](INFO): Moved sent file to Logs/20190514T161510/Courier0004.lzma.bak
2019-05-14T16:21:17.475Z,1557850877.475 [DataOverHttps](INFO): SBD MOMSN=11053052
2019-05-14T16:21:32.934Z,1557850892.934 [DataOverHttps](INFO): Sending 840 bytes from file Logs/20190514T161510/Express0001.lzma
2019-05-14T16:21:33.738Z,1557850893.738 [DataOverHttps](INFO): Moved sent file to Logs/20190514T161510/Express0001.lzma.bak
2019-05-14T16:21:33.738Z,1557850893.738 [DataOverHttps](INFO): SBD MOMSN=11053058
2019-05-14T16:21:39.468Z,1557850899.468 [NAL9602](INFO): Not Powering down - fast GPS
2019-05-14T16:21:48.157Z,1557850908.157 [DataOverHttps](INFO): Sending 378 bytes from file Logs/20190514T161510/Express0005.lzma
2019-05-14T16:21:48.967Z,1557850908.967 [DataOverHttps](INFO): Moved sent file to Logs/20190514T161510/Express0005.lzma.bak
2019-05-14T16:21:48.967Z,1557850908.967 [DataOverHttps](INFO): SBD MOMSN=11053104
2019-05-14T16:21:51.985Z,1557850911.985 [Default:CheckIn:Read_Iridium] Stopped
2019-05-14T16:21:51.985Z,1557850911.985 [Default:CheckIn:C.Wait] Running Loop=1
2019-05-14T16:21:51.985Z,1557850911.985 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-05-14T16:26:52.553Z,1557851212.553 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-05-14T16:26:52.553Z,1557851212.553 [Default:CheckIn:C.Wait] Stopped
2019-05-14T16:26:52.553Z,1557851212.553 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-14T16:26:52.553Z,1557851212.553 [Default:CheckIn:D] Running Loop=1
2019-05-14T16:26:52.968Z,1557851212.968 [Default:CheckIn:D] Stopped
2019-05-14T16:26:52.968Z,1557851212.968 [Default:CheckIn:E] Running Loop=1
2019-05-14T16:26:53.361Z,1557851213.361 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 7.651164 min
2019-05-14T16:26:53.362Z,1557851213.362 [Default:CheckIn:E] Stopped
2019-05-14T16:26:53.362Z,1557851213.362 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-05-14T16:26:53.362Z,1557851213.362 [Default:CheckIn] Stopped
2019-05-14T16:26:53.362Z,1557851213.362 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-05-14T16:26:53.362Z,1557851213.362 [Default:CheckIn](INFO): Running loop #2
2019-05-14T16:26:53.362Z,1557851213.362 [Default:CheckIn] Running Loop=2
2019-05-14T16:26:53.362Z,1557851213.362 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-05-14T16:26:53.362Z,1557851213.362 [Default:CheckIn:Read_GPS] Running Loop=1
2019-05-14T16:26:54.965Z,1557851214.965 [NAL9602](DEBUG): Fix Requested
2019-05-14T16:26:55.370Z,1557851215.370 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,161426.00,A,3648.16222,N,12147.28190,W,0.350,193.26,140519,,,A*74
2019-05-14T16:26:55.372Z,1557851215.372 [NAL9602](INFO): GPS fix at 20190514T161426: (36.802704, -121.788032)
2019-05-14T16:26:55.438Z,1557851215.438 [Default:CheckIn:Read_GPS] Stopped
2019-05-14T16:26:55.438Z,1557851215.438 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-05-14T16:27:02.880Z,1557851222.880 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20190514T161510/Courier0007.lzma
2019-05-14T16:27:03.686Z,1557851223.686 [DataOverHttps](INFO): Moved sent file to Logs/20190514T161510/Courier0007.lzma.bak
2019-05-14T16:27:03.686Z,1557851223.686 [DataOverHttps](INFO): SBD MOMSN=11053148
2019-05-14T16:27:17.884Z,1557851237.884 [DataOverHttps](INFO): Sending 165 bytes from file Logs/20190514T161510/Express0008.lzma
2019-05-14T16:27:18.690Z,1557851238.690 [DataOverHttps](INFO): Moved sent file to Logs/20190514T161510/Express0008.lzma.bak
2019-05-14T16:27:18.691Z,1557851238.691 [DataOverHttps](INFO): SBD MOMSN=11053151
2019-05-14T16:27:21.658Z,1557851241.658 [Default:CheckIn:Read_Iridium] Stopped
2019-05-14T16:27:21.658Z,1557851241.658 [Default:CheckIn:C.Wait] Running Loop=1
2019-05-14T16:27:21.658Z,1557851241.658 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-05-14T16:27:26.081Z,1557851246.081 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2019-05-14T16:27:26.165Z,1557851246.165 [NAL9602](FAULT): received:
+CSQ:0
OK096, 2, 0, 0, 0
OK
2019-05-14T16:27:26.165Z,1557851246.165 [NAL9602] Data Fault, FailCount= 1
2019-05-14T16:27:26.165Z,1557851246.165 [NAL9602](ERROR): Data Fault
2019-05-14T16:27:26.256Z,1557851246.256 [CBIT](ERROR): Data Fault in component: NAL9602
2019-05-14T16:27:26.460Z,1557851246.460 [NAL9602](INFO): Powering down
2019-05-14T16:27:27.343Z,1557851247.343 [CBIT](INFO): Clearing failed state for component NAL9602
2019-05-14T16:27:27.343Z,1557851247.343 [NAL9602] No Fault, FailCount= 1
2019-05-14T16:27:56.783Z,1557851276.783 [NAL9602](INFO): Powering up NAL9602
2019-05-14T16:28:07.676Z,1557851287.676 [NAL9602](INFO): NAL9602 initialized
2019-05-14T16:28:38.801Z,1557851318.801 [NAL9602](INFO): Not Powering down - fast GPS
2019-05-14T16:29:03.024Z,1557851343.024 [DVL_micro](ERROR): only read 4 of 46 data items
2019-05-14T16:29:03.029Z,1557851343.029 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 01 1 0 0.2 9.8 10.2 0 121.3 -22.8 -234.8 0 0 -581 11 505 0 1 2 2 475.3 90.6 -61.2 1 -35.9 -482.7 -59.7 1 101 -1449 -41 2 -1424 287 -41 2 2.85 0.38 254.6 0.2 18.6 0.005 35.0 1489 124
2019-05-14T16:31:52.666Z,1557851512.666 [CommandLine](IMPORTANT): got command load ./Missions/Science/circle_acoustic_contact.xml
2019-05-14T16:31:52.667Z,1557851512.667 [MissionManager](INFO): Loading Mission: ./Missions/Science/circle_acoustic_contact.xml
2019-05-14T16:31:52.918Z,1557851512.918 [MissionManager](INFO): DefineArg circle_acoustic_contact.MissionTimeout = 2.000000 h
2019-05-14T16:31:52.921Z,1557851512.921 [MissionManager](INFO): DefineArg circle_acoustic_contact.NeedCommsTime = 60.000000 min
2019-05-14T16:31:52.924Z,1557851512.924 [MissionManager](INFO): DefineArg circle_acoustic_contact.AcousticContactTimeout = 15.000000 min
2019-05-14T16:31:52.927Z,1557851512.927 [MissionManager](INFO): DefineArg circle_acoustic_contact.ContactLabel = 0.000000 count
2019-05-14T16:31:52.934Z,1557851512.934 [MissionManager](INFO): DefineArg circle_acoustic_contact.CenterLatitude = 36.815440 arcdeg
2019-05-14T16:31:52.938Z,1557851512.938 [MissionManager](INFO): DefineArg circle_acoustic_contact.CenterLongitude = -121.825060 arcdeg
2019-05-14T16:31:52.940Z,1557851512.940 [MissionManager](INFO): DefineArg circle_acoustic_contact.OuterCircleRadius = 300.000000 m
2019-05-14T16:31:52.944Z,1557851512.944 [MissionManager](INFO): DefineArg circle_acoustic_contact.InnerCircleRadius = 50.000000 m
2019-05-14T16:31:52.947Z,1557851512.947 [MissionManager](INFO): DefineArg circle_acoustic_contact.TrackingUpdatePeriod = 60.000000 s
2019-05-14T16:31:52.950Z,1557851512.950 [MissionManager](INFO): DefineArg circle_acoustic_contact.NumberOfPings = 1.000000 count
2019-05-14T16:31:52.953Z,1557851512.953 [MissionManager](INFO): DefineArg circle_acoustic_contact.InnerCircleTime = 0.000000 min
2019-05-14T16:31:52.956Z,1557851512.956 [MissionManager](INFO): DefineArg circle_acoustic_contact.CircleMaxError = 100.000000 m
2019-05-14T16:31:52.959Z,1557851512.959 [MissionManager](INFO): DefineArg circle_acoustic_contact.CircleTurnToPort = 0 bool
2019-05-14T16:31:52.962Z,1557851512.962 [MissionManager](INFO): DefineArg circle_acoustic_contact.YoYoMinDepth = 3.000000 m
2019-05-14T16:31:52.985Z,1557851512.985 [MissionManager](INFO): DefineArg circle_acoustic_contact.YoYoMaxDepth = 33.000000 m
2019-05-14T16:31:52.988Z,1557851512.988 [MissionManager](INFO): DefineArg circle_acoustic_contact.YoYoMinAltitude = 10.000000 m
2019-05-14T16:31:52.996Z,1557851512.996 [MissionManager](INFO): DefineArg circle_acoustic_contact.YoYoPitch = 20.000000 arcdeg
2019-05-14T16:31:53.012Z,1557851513.012 [MissionManager](INFO): DefineArg circle_acoustic_contact.Speed = 1.000000 m/s
2019-05-14T16:31:53.020Z,1557851513.020 [MissionManager](INFO): DefineArg circle_acoustic_contact.KwpHeading = 0.010000 rad/m
2019-05-14T16:31:53.027Z,1557851513.027 [MissionManager](INFO): DefineArg circle_acoustic_contact.MinAltitude = 7.000000 m
2019-05-14T16:31:53.030Z,1557851513.030 [MissionManager](INFO): DefineArg circle_acoustic_contact.MaxDepth = 105.000000 m
2019-05-14T16:31:53.046Z,1557851513.046 [MissionManager](INFO): DefineArg circle_acoustic_contact.MinOffshore = 1.500000 km
2019-05-14T16:31:53.305Z,1557851513.305 [MissionManager](INFO): Inserting Stack: Missions/Insert/NeedComms.xml
2019-05-14T16:31:53.442Z,1557851513.442 [MissionManager](INFO): DefineArg circle_acoustic_contact:NeedComms.DiveInterval = 3.000000 h
2019-05-14T16:31:53.446Z,1557851513.446 [MissionManager](INFO): DefineArg circle_acoustic_contact:NeedComms.WaitForPitchUp = 10.000000 min
2019-05-14T16:31:53.450Z,1557851513.450 [MissionManager](INFO): DefineArg circle_acoustic_contact:NeedComms.SurfacePitch = 20.000000 arcdeg
2019-05-14T16:31:53.475Z,1557851513.475 [MissionManager](INFO): DefineArg circle_acoustic_contact:NeedComms.SurfaceDepthRate = nan m/s
2019-05-14T16:31:53.478Z,1557851513.478 [MissionManager](INFO): DefineArg circle_acoustic_contact:NeedComms.SurfaceSpeed = 1.000000 m/s
2019-05-14T16:31:53.481Z,1557851513.481 [MissionManager](INFO): DefineArg circle_acoustic_contact:NeedComms.GPSTimeout = 7.000000 min
2019-05-14T16:31:53.484Z,1557851513.484 [MissionManager](INFO): DefineArg circle_acoustic_contact:NeedComms.CommsTimeout = 30.000000 min
2019-05-14T16:31:53.538Z,1557851513.538 [circle_acoustic_contact:NeedComms:B.GoToSurface](DEBUG): Construct GoToSurface.
2019-05-14T16:31:53.595Z,1557851513.595 [MissionManager](INFO): Inserting Stack: Missions/Insert/StandardEnvelopes.xml
2019-05-14T16:31:53.654Z,1557851513.654 [MissionManager](INFO): DefineArg circle_acoustic_contact:StandardEnvelopes.MinAltitude = 5.000000 m
2019-05-14T16:31:53.662Z,1557851513.662 [MissionManager](INFO): DefineArg circle_acoustic_contact:StandardEnvelopes.MaxDepth = 200.000000 m
2019-05-14T16:31:53.669Z,1557851513.669 [MissionManager](INFO): DefineArg circle_acoustic_contact:StandardEnvelopes.MinOffshore = 2000.000000 m
2019-05-14T16:31:53.670Z,1557851513.670 [circle_acoustic_contact:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope.
2019-05-14T16:31:53.686Z,1557851513.686 [circle_acoustic_contact:StandardEnvelopes:B.DepthEnvelope](DEBUG): Construct DepthEnvelope.
2019-05-14T16:31:53.710Z,1557851513.710 [circle_acoustic_contact:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Construct OffshoreEnvelope.
2019-05-14T16:31:53.735Z,1557851513.735 [circle_acoustic_contact:I.Pitch](DEBUG): Construct.
2019-05-14T16:31:53.752Z,1557851513.752 [circle_acoustic_contact:J.Buoyancy](DEBUG): Construct Buoyancy.
2019-05-14T16:31:53.756Z,1557851513.756 [MissionManager](INFO): Inserting Stack: Missions/Insert/Science.xml
2019-05-14T16:31:54.181Z,1557851514.181 [MissionManager](INFO): DefineArg circle_acoustic_contact:Science.SampleISUS = 0 bool
2019-05-14T16:31:54.184Z,1557851514.184 [MissionManager](INFO): DefineArg circle_acoustic_contact:Science.SampleISUSmaxPitch = 60.000000 arcdeg
2019-05-14T16:31:54.187Z,1557851514.187 [MissionManager](INFO): DefineArg circle_acoustic_contact:Science.SampleISUSminPitch = -60.000000 arcdeg
2019-05-14T16:31:54.199Z,1557851514.199 [MissionManager](INFO): DefineArg circle_acoustic_contact:Science.PeakDetectChlActive = 0 bool
2019-05-14T16:31:54.207Z,1557851514.207 [MissionManager](INFO): DefineArg circle_acoustic_contact:Science.TimeWindowPeakReport = nan min
2019-05-14T16:31:54.210Z,1557851514.210 [MissionManager](INFO): DefineArg circle_acoustic_contact:Science.HighestChlPeakReportActive = 0 bool
2019-05-14T16:31:54.221Z,1557851514.221 [MissionManager](INFO): DefineArg circle_acoustic_contact:Science.PatchTracking = 0 bool
2019-05-14T16:31:54.224Z,1557851514.224 [MissionManager](INFO): DefineArg circle_acoustic_contact:Science.FilterWidthHorizontal = 3.000000 count
2019-05-14T16:31:54.243Z,1557851514.243 [MissionManager](INFO): DefineArg circle_acoustic_contact:Science.NumProfilesSlidingwindow = 100.000000 count
2019-05-14T16:31:54.247Z,1557851514.247 [MissionManager](INFO): DefineArg circle_acoustic_contact:Science.OffPeakFractionHorizontal = 80.000000 %
2019-05-14T16:31:54.252Z,1557851514.252 [MissionManager](INFO): DefineArg circle_acoustic_contact:Science.PeakDetectNO3Active = 0 bool
2019-05-14T16:31:54.255Z,1557851514.255 [MissionManager](INFO): DefineArg circle_acoustic_contact:Science.PeakDetectOilActive = 0 bool
2019-05-14T16:31:54.266Z,1557851514.266 [MissionManager](INFO): DefineArg circle_acoustic_contact:Science.PeakDetectFDOMActive = 0 bool
2019-05-14T16:31:54.273Z,1557851514.273 [MissionManager](INFO): DefineArg circle_acoustic_contact:Science.UpwardDerivativeOfTemperatureActive = 0 bool
2019-05-14T16:31:54.281Z,1557851514.281 [MissionManager](INFO): DefineArg circle_acoustic_contact:Science.EnabledAanderaaO2 = 1.000000 bool
2019-05-14T16:31:54.284Z,1557851514.284 [MissionManager](INFO): DefineArg circle_acoustic_contact:Science.EnabledNeilBrown = 1.000000 bool
2019-05-14T16:31:54.293Z,1557851514.293 [MissionManager](INFO): DefineArg circle_acoustic_contact:Science.EnabledSeabird = 1.000000 bool
2019-05-14T16:31:54.296Z,1557851514.296 [MissionManager](INFO): DefineArg circle_acoustic_contact:Science.EnabledTurbulence_NPS = 0.000000 bool
2019-05-14T16:31:54.375Z,1557851514.375 [MissionManager](INFO): DefineArg circle_acoustic_contact:Science.EnabledWetLabsBB2FL = 1.000000 bool
2019-05-14T16:31:54.387Z,1557851514.387 [MissionManager](INFO): DefineArg circle_acoustic_contact:Science.EnabledWetLabsSeaOWL_UV_A = 0.000000 bool
2019-05-14T16:31:54.392Z,1557851514.392 [MissionManager](INFO): DefineArg circle_acoustic_contact:Science.EnabledWetLabsUBAT = 0.000000 bool
2019-05-14T16:31:54.403Z,1557851514.403 [MissionManager](INFO): DefineArg circle_acoustic_contact:Science.EnabledISUS = 0.000000 bool
2019-05-14T16:31:54.408Z,1557851514.408 [MissionManager](INFO): DefineArg circle_acoustic_contact:Science.LowPassWindowLength = 20.000000 count
2019-05-14T16:31:54.419Z,1557851514.419 [MissionManager](INFO): DefineArg circle_acoustic_contact:Science.MedianFilterLen = 5.000000 count
2019-05-14T16:31:54.426Z,1557851514.426 [MissionManager](INFO): DefineArg circle_acoustic_contact:Science.PeakChlShallowBound = nan m
2019-05-14T16:31:54.433Z,1557851514.433 [MissionManager](INFO): DefineArg circle_acoustic_contact:Science.PeakChlDeepBound = nan m
2019-05-14T16:31:54.438Z,1557851514.438 [MissionManager](INFO): DefineArg circle_acoustic_contact:Science.PeakShallowBound = nan m
2019-05-14T16:31:54.441Z,1557851514.441 [MissionManager](INFO): DefineArg circle_acoustic_contact:Science.PeakDeepBound = nan m
2019-05-14T16:31:54.445Z,1557851514.445 [MissionManager](INFO): DefineOutput circle_acoustic_contact:Science.PeakChl = 0.000000 ug/l
2019-05-14T16:31:54.452Z,1557851514.452 [MissionManager](INFO): DefineOutput circle_acoustic_contact:Science.PeakChlDepth = 0.000000 m
2019-05-14T16:31:54.459Z,1557851514.459 [MissionManager](INFO): DefineOutput circle_acoustic_contact:Science.PeakChlTemperature = 0.000000 degC
2019-05-14T16:31:54.464Z,1557851514.464 [MissionManager](INFO): DefineOutput circle_acoustic_contact:Science.PeakChlLatitude = nan arcdeg
2019-05-14T16:31:54.479Z,1557851514.479 [MissionManager](INFO): DefineOutput circle_acoustic_contact:Science.PeakChlLongitude = nan arcdeg
2019-05-14T16:31:54.483Z,1557851514.483 [MissionManager](INFO): DefineOutput circle_acoustic_contact:Science.PeakNO3 = 0.000000 umol/l
2019-05-14T16:31:54.494Z,1557851514.494 [MissionManager](INFO): DefineOutput circle_acoustic_contact:Science.PeakNO3Depth = 0.000000 m
2019-05-14T16:31:54.501Z,1557851514.501 [MissionManager](INFO): DefineOutput circle_acoustic_contact:Science.PeakNO3Latitude = nan arcdeg
2019-05-14T16:31:54.504Z,1557851514.504 [MissionManager](INFO): DefineOutput circle_acoustic_contact:Science.PeakNO3Longitude = nan arcdeg
2019-05-14T16:31:54.512Z,1557851514.512 [MissionManager](INFO): DefineOutput circle_acoustic_contact:Science.PatchChl = 0.000000 m
2019-05-14T16:31:54.519Z,1557851514.519 [MissionManager](INFO): DefineOutput circle_acoustic_contact:Science.PatchChlDepth = 0.000000 m
2019-05-14T16:31:54.522Z,1557851514.522 [MissionManager](INFO): DefineOutput circle_acoustic_contact:Science.PatchChlLatitude = nan arcdeg
2019-05-14T16:31:54.538Z,1557851514.538 [MissionManager](INFO): DefineOutput circle_acoustic_contact:Science.PatchChlLongitude = nan arcdeg
2019-05-14T16:31:54.554Z,1557851514.554 [MissionManager](INFO): DefineOutput circle_acoustic_contact:Science.PatchChlDistance = nan m
2019-05-14T16:31:54.557Z,1557851514.557 [MissionManager](INFO): DefineOutput circle_acoustic_contact:Science.PeakOil = 0.000000 kg/m3
2019-05-14T16:31:54.560Z,1557851514.560 [MissionManager](INFO): DefineOutput circle_acoustic_contact:Science.PeakOilDepth = 0.000000 m
2019-05-14T16:31:54.564Z,1557851514.564 [MissionManager](INFO): DefineOutput circle_acoustic_contact:Science.PeakOilLatitude = nan arcdeg
2019-05-14T16:31:54.595Z,1557851514.595 [MissionManager](INFO): DefineOutput circle_acoustic_contact:Science.PeakOilLongitude = nan arcdeg
2019-05-14T16:31:54.600Z,1557851514.600 [MissionManager](INFO): DefineOutput circle_acoustic_contact:Science.PeakFDOM = 0.000000 ppb
2019-05-14T16:31:54.617Z,1557851514.617 [MissionManager](INFO): DefineOutput circle_acoustic_contact:Science.PeakFDOMDepth = 0.000000 m
2019-05-14T16:31:54.621Z,1557851514.621 [MissionManager](INFO): DefineOutput circle_acoustic_contact:Science.PeakFDOMLatitude = nan arcdeg
2019-05-14T16:31:54.624Z,1557851514.624 [MissionManager](INFO): DefineOutput circle_acoustic_contact:Science.PeakFDOMLongitude = nan arcdeg
2019-05-14T16:31:54.627Z,1557851514.627 [MissionManager](INFO): DefineOutput circle_acoustic_contact:Science.PatchFDOMDistance = nan m
2019-05-14T16:31:54.661Z,1557851514.661 [circle_acoustic_contact:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2019-05-14T16:31:54.690Z,1557851514.690 [circle_acoustic_contact:Science:HighestChlPeakReport:A.PeakDetectHorizontal](DEBUG): Construct PeakDetectHorizontal.
2019-05-14T16:31:54.773Z,1557851514.773 [circle_acoustic_contact:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2019-05-14T16:31:54.799Z,1557851514.799 [circle_acoustic_contact:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2019-05-14T16:31:54.826Z,1557851514.826 [circle_acoustic_contact:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2019-05-14T16:31:54.849Z,1557851514.849 [MissionManager](INFO): RedefineArg circle_acoustic_contact:Science.PeakDetectChlActive = value:1 bool
2019-05-14T16:31:54.851Z,1557851514.851 [MissionManager](INFO): RedefineArg circle_acoustic_contact:Science.SampleISUS = value:1 bool
2019-05-14T16:31:54.865Z,1557851514.865 [MissionManager](INFO): RedefineArg circle_acoustic_contact:Science.SampleISUSmaxPitch = value:30.000000 arcdeg
2019-05-14T16:31:54.867Z,1557851514.867 [MissionManager](INFO): RedefineArg circle_acoustic_contact:Science.SampleISUSminPitch = value:10.000000 arcdeg
2019-05-14T16:31:54.868Z,1557851514.868 [circle_acoustic_contact:L.SetSpeed](DEBUG): Construct.
2019-05-14T16:31:54.877Z,1557851514.877 [circle_acoustic_contact:YoYos:A.DepthEnvelope](DEBUG): Construct DepthEnvelope.
2019-05-14T16:31:54.895Z,1557851514.895 [circle_acoustic_contact:YoYos:B.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope.
2019-05-14T16:31:54.916Z,1557851514.916 [circle_acoustic_contact:YoYos:C.YoYo](DEBUG): Construct YoYo.
2019-05-14T16:31:54.941Z,1557851514.941 [circle_acoustic_contact:CircleWrapper:CircleContact:B.Circle](DEBUG): Construct.
2019-05-14T16:31:54.984Z,1557851514.984 [circle_acoustic_contact:CircleWrapper:CircleContactClose:B.Circle](DEBUG): Construct.
2019-05-14T16:31:55.075Z,1557851515.075 [MissionManager](DEBUG):
This mission runs a circle around a specified acoustic contact. The
tracking behavior periodically queries the DAT for range and direction
to the contact, and the DAT acoustically interrogates the contact. The
tracking component then calculates the position of the contact to update
the center of the circle. When the vehicle surfaces and updates its own
position with GPS, it queries the contact again, then sends the contact
position to shore.
Maximum duration of mission
2
Elapsed time after previous surface communications when vehicle will
begin to ascend for additional surface communications
60
If the vehicle does not receive an acoustic signal for more than this
length of time, it will surface for communications with shore.
15
The acoustic address of the asset to be tracked
0
The latitude of the center of the circle. Fill this in to specify a
start position, it will be overwritten once the vehicle receives an
acoustic signal from the contact.
36.81544
The longitude of the center of the circle. Fill this in to specify a
start position, it will be overwritten once the vehicle receives an
acoustic signal from the contact.
-121.82506
Radius of circle around acoustic contact during wait time
300
Radius of circle around acoustic contact during wait time
50
How long to wait between acoustic queries
60
Number of return pings to request with each acoustic query (more than 1
will activate oneway mode)
1
Time before each normal communication cycle to move to the inner circle.
Default value of 0 means vehicle will stay at OuterCircleRadius the
whole time.
0
If this distance away from the circle, drive straight towards (or away
from the center). Otherwise, try to reduce distance from the ideal
circle.
100
If true, vehicle turns to the left around the center point. If false,
vehicle turns to the right.
Minimum depth during yo-yo's.
3
Maximum depth during yo-yo's.
33
Min altitude while in yo-yo mode.
10
Pitch (plus and minus) for yo-yo behavior.
20
Vehicle speed.
1
Used to relax waypoint cross-track error constant that is adjusted for
docking. (You can override this setting by passing an argument.)
0.010
Minimum height above the sea floor for the entire mission.
7
Maximum depth for the entire mission.
105
Minimum offshore distance for the entire mission.
1.5
Get science data, including PeakDetectChl
30.0
10.0
Circle the contact while updating its position using the
tracking behavior.
Circle the contact closely while updating its position using the
tracking behavior.
2019-05-14T16:31:55.076Z,1557851515.076 [CommandLine](IMPORTANT): Loaded ./Missions/Science/circle_acoustic_contact.xml
2019-05-14T16:32:22.221Z,1557851542.221 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-05-14T16:32:22.221Z,1557851542.221 [Default:CheckIn:C.Wait] Stopped
2019-05-14T16:32:22.221Z,1557851542.221 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-14T16:32:22.221Z,1557851542.221 [Default:CheckIn:D] Running Loop=1
2019-05-14T16:32:22.668Z,1557851542.668 [Default:CheckIn:D] Stopped
2019-05-14T16:32:22.668Z,1557851542.668 [Default:CheckIn:E] Running Loop=1
2019-05-14T16:32:23.030Z,1557851543.030 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 13.146156 min
2019-05-14T16:32:23.030Z,1557851543.030 [Default:CheckIn:E] Stopped
2019-05-14T16:32:23.030Z,1557851543.030 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-05-14T16:32:23.030Z,1557851543.030 [Default:CheckIn] Stopped
2019-05-14T16:32:23.031Z,1557851543.031 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-05-14T16:32:23.031Z,1557851543.031 [Default:CheckIn](INFO): Running loop #3
2019-05-14T16:32:23.031Z,1557851543.031 [Default:CheckIn] Running Loop=3
2019-05-14T16:32:23.031Z,1557851543.031 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-05-14T16:32:23.031Z,1557851543.031 [Default:CheckIn:Read_GPS] Running Loop=1
2019-05-14T16:32:24.629Z,1557851544.629 [NAL9602](DEBUG): Fix Requested
2019-05-14T16:32:24.938Z,1557851544.938 [CommandLine](IMPORTANT): got command set circle_acoustic_contact.Speed 0.000000 meter_per_second
2019-05-14T16:32:27.040Z,1557851547.040 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-05-14T16:32:27.857Z,1557851547.857 [NAL9602](DEBUG): Fix Requested
2019-05-14T16:32:30.705Z,1557851550.705 [NAL9602](DEBUG): Fix Requested
2019-05-14T16:32:33.513Z,1557851553.513 [NAL9602](DEBUG): Fix Requested
2019-05-14T16:32:36.751Z,1557851556.751 [NAL9602](DEBUG): Fix Requested
2019-05-14T16:32:39.601Z,1557851559.601 [NAL9602](DEBUG): Fix Requested
2019-05-14T16:32:42.833Z,1557851562.833 [NAL9602](DEBUG): Fix Requested
2019-05-14T16:32:45.643Z,1557851565.643 [NAL9602](DEBUG): Fix Requested
2019-05-14T16:32:48.485Z,1557851568.485 [NAL9602](DEBUG): Fix Requested
2019-05-14T16:32:51.733Z,1557851571.733 [NAL9602](DEBUG): Fix Requested
2019-05-14T16:32:54.533Z,1557851574.533 [NAL9602](DEBUG): Fix Requested
2019-05-14T16:32:57.753Z,1557851577.753 [NAL9602](DEBUG): Fix Requested
2019-05-14T16:33:00.597Z,1557851580.597 [NAL9602](DEBUG): Fix Requested
2019-05-14T16:33:03.833Z,1557851583.833 [NAL9602](DEBUG): Fix Requested
2019-05-14T16:33:06.645Z,1557851586.645 [NAL9602](DEBUG): Fix Requested
2019-05-14T16:33:09.877Z,1557851589.877 [NAL9602](DEBUG): Fix Requested
2019-05-14T16:33:12.725Z,1557851592.725 [NAL9602](DEBUG): Fix Requested
2019-05-14T16:33:15.533Z,1557851595.533 [NAL9602](DEBUG): Fix Requested
2019-05-14T16:33:18.765Z,1557851598.765 [NAL9602](DEBUG): Fix Requested
2019-05-14T16:33:21.609Z,1557851601.609 [NAL9602](DEBUG): Fix Requested
2019-05-14T16:33:24.841Z,1557851604.841 [NAL9602](DEBUG): Fix Requested
2019-05-14T16:33:27.653Z,1557851607.653 [NAL9602](DEBUG): Fix Requested
2019-05-14T16:33:30.893Z,1557851610.893 [NAL9602](DEBUG): Fix Requested
2019-05-14T16:33:33.769Z,1557851613.769 [NAL9602](DEBUG): Fix Requested
2019-05-14T16:33:36.969Z,1557851616.969 [NAL9602](DEBUG): Fix Requested
2019-05-14T16:33:39.773Z,1557851619.773 [NAL9602](DEBUG): Fix Requested
2019-05-14T16:33:42.621Z,1557851622.621 [NAL9602](DEBUG): Fix Requested
2019-05-14T16:33:45.849Z,1557851625.849 [NAL9602](DEBUG): Fix Requested
2019-05-14T16:33:48.665Z,1557851628.665 [NAL9602](DEBUG): Fix Requested
2019-05-14T16:33:51.893Z,1557851631.893 [NAL9602](DEBUG): Fix Requested
2019-05-14T16:33:54.741Z,1557851634.741 [NAL9602](DEBUG): Fix Requested
2019-05-14T16:33:57.973Z,1557851637.973 [NAL9602](DEBUG): Fix Requested
2019-05-14T16:33:58.346Z,1557851638.346 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162128.00,A,3648.16259,N,12147.28136,W,0.272,335.11,140519,,,A*77
2019-05-14T16:33:58.348Z,1557851638.348 [NAL9602](INFO): GPS fix at 20190514T162128: (36.802710, -121.788023)
2019-05-14T16:33:58.372Z,1557851638.372 [Default:CheckIn:Read_GPS] Stopped
2019-05-14T16:33:58.373Z,1557851638.373 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-05-14T16:34:01.275Z,1557851641.275 [DVL_micro](ERROR): checksum mismatch: reported110 , calculated:123
2019-05-14T16:34:01.275Z,1557851641.275 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 1 1 1 0.2 9.7 10.2 10.5 -122.9 -9.8 304.7 368.1 19 492 0 1 2 2 -570.7 -504.4 145.6 1 -336.6 687.4 123.9 1 -1303 -9 526 2 346 1257 526 2 2.88 0.38 254.2 0.2 18.6 0.005 35.0 1489 110
2019-05-14T16:34:05.672Z,1557851645.672 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20190514T161510/Courier0010.lzma
2019-05-14T16:34:06.478Z,1557851646.478 [DataOverHttps](INFO): Moved sent file to Logs/20190514T161510/Courier0010.lzma.bak
2019-05-14T16:34:06.478Z,1557851646.478 [DataOverHttps](INFO): SBD MOMSN=11053186
2019-05-14T16:34:20.769Z,1557851660.769 [DataOverHttps](INFO): Sending 369 bytes from file Logs/20190514T161510/Express0011.lzma
2019-05-14T16:34:21.574Z,1557851661.574 [DataOverHttps](INFO): Moved sent file to Logs/20190514T161510/Express0011.lzma.bak
2019-05-14T16:34:21.575Z,1557851661.575 [DataOverHttps](INFO): SBD MOMSN=11053189
2019-05-14T16:34:24.792Z,1557851664.792 [Default:CheckIn:Read_Iridium] Stopped
2019-05-14T16:34:24.792Z,1557851664.792 [Default:CheckIn:C.Wait] Running Loop=1
2019-05-14T16:34:24.792Z,1557851664.792 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-05-14T16:34:30.759Z,1557851670.759 [NAL9602](INFO): Not Powering down - fast GPS
2019-05-14T16:36:32.918Z,1557851792.918 [CommandLine](IMPORTANT): got command report
2019-05-14T16:36:32.918Z,1557851792.918 [Reporter](INFO): acoustic_contact_range reporting when touched
2019-05-14T16:36:36.890Z,1557851796.890 [CommandLine](IMPORTANT): got command run
2019-05-14T16:36:36.893Z,1557851796.893 [CommandLine](IMPORTANT): Running
2019-05-14T16:36:37.340Z,1557851797.340 [Default] Stopped
2019-05-14T16:36:37.340Z,1557851797.340 [Default](DEBUG): Aggregate::uninitialize Default
2019-05-14T16:36:37.340Z,1557851797.340 [Default:B.GoToSurface] Stopped
2019-05-14T16:36:37.340Z,1557851797.340 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-05-14T16:36:37.340Z,1557851797.340 [Default:CheckIn] Stopped
2019-05-14T16:36:37.349Z,1557851797.349 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-05-14T16:36:37.349Z,1557851797.349 [Default:CheckIn:C.Wait] Stopped
2019-05-14T16:36:37.349Z,1557851797.349 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-14T16:36:37.349Z,1557851797.349 [MissionManager](IMPORTANT): Started mission circle_acoustic_contact
2019-05-14T16:36:37.349Z,1557851797.349 [circle_acoustic_contact] Running Loop=1
2019-05-14T16:36:37.350Z,1557851797.350 [circle_acoustic_contact](DEBUG): Aggregate::initialize circle_acoustic_contact
2019-05-14T16:36:37.350Z,1557851797.350 [circle_acoustic_contact:A.] Running Loop=1
2019-05-14T16:36:37.350Z,1557851797.350 [circle_acoustic_contact:A.](INFO): Initializing Tracking.
2019-05-14T16:36:37.350Z,1557851797.350 [circle_acoustic_contact:StandardEnvelopes] Running Loop=1
2019-05-14T16:36:37.350Z,1557851797.350 [circle_acoustic_contact:StandardEnvelopes](DEBUG): Aggregate::initialize circle_acoustic_contact:StandardEnvelopes
2019-05-14T16:36:37.350Z,1557851797.350 [circle_acoustic_contact:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1
2019-05-14T16:36:37.350Z,1557851797.350 [circle_acoustic_contact:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent.
2019-05-14T16:36:37.351Z,1557851797.351 [circle_acoustic_contact:StandardEnvelopes:B.DepthEnvelope] Running Loop=1
2019-05-14T16:36:37.351Z,1557851797.351 [circle_acoustic_contact:StandardEnvelopes:B.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent.
2019-05-14T16:36:37.351Z,1557851797.351 [circle_acoustic_contact:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1
2019-05-14T16:36:37.351Z,1557851797.351 [circle_acoustic_contact:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Initialize OffshoreEnvelopeComponent.
2019-05-14T16:36:37.351Z,1557851797.351 [circle_acoustic_contact:I.Pitch] Running Loop=1
2019-05-14T16:36:37.351Z,1557851797.351 [circle_acoustic_contact:I.Pitch](DEBUG): Initialize.
2019-05-14T16:36:37.351Z,1557851797.351 [circle_acoustic_contact:J.Buoyancy] Running Loop=1
2019-05-14T16:36:37.351Z,1557851797.351 [circle_acoustic_contact:J.Buoyancy](DEBUG): Initialize Buoyancy Component.
2019-05-14T16:36:37.351Z,1557851797.351 [circle_acoustic_contact:Science] Running Loop=1
2019-05-14T16:36:37.352Z,1557851797.352 [circle_acoustic_contact:Science](DEBUG): Aggregate::initialize circle_acoustic_contact:Science
2019-05-14T16:36:37.352Z,1557851797.352 [circle_acoustic_contact:Science:A] Running Loop=1
2019-05-14T16:36:37.352Z,1557851797.352 [circle_acoustic_contact:Science:B] Running Loop=1
2019-05-14T16:36:37.352Z,1557851797.352 [circle_acoustic_contact:Science:C] Running Loop=1
2019-05-14T16:36:37.352Z,1557851797.352 [circle_acoustic_contact:Science:D] Running Loop=1
2019-05-14T16:36:37.352Z,1557851797.352 [circle_acoustic_contact:Science:E] Running Loop=1
2019-05-14T16:36:37.352Z,1557851797.352 [circle_acoustic_contact:Science:F] Running Loop=1
2019-05-14T16:36:37.352Z,1557851797.352 [circle_acoustic_contact:Science:G] Running Loop=1
2019-05-14T16:36:37.352Z,1557851797.352 [circle_acoustic_contact:Science:H] Running Loop=1
2019-05-14T16:36:37.352Z,1557851797.352 [circle_acoustic_contact:Science:Read_Oil] Running Loop=1
2019-05-14T16:36:37.352Z,1557851797.352 [circle_acoustic_contact:Science:PeakDetectChl] Running Loop=1
2019-05-14T16:36:37.352Z,1557851797.352 [circle_acoustic_contact:Science:PeakDetectChl](DEBUG): Aggregate::initialize circle_acoustic_contact:Science:PeakDetectChl
2019-05-14T16:36:37.361Z,1557851797.361 [circle_acoustic_contact:Science:PeakDetectChl:A.PeakDetectVsDepth] Running Loop=1
2019-05-14T16:36:37.361Z,1557851797.361 [circle_acoustic_contact:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Initialize.
2019-05-14T16:36:37.363Z,1557851797.363 [circle_acoustic_contact:Science:HighestChlPeakReport] Running Loop=1
2019-05-14T16:36:37.363Z,1557851797.363 [circle_acoustic_contact:Science:HighestChlPeakReport](DEBUG): Aggregate::initialize circle_acoustic_contact:Science:HighestChlPeakReport
2019-05-14T16:36:37.363Z,1557851797.363 [circle_acoustic_contact:Science:HighestChlPeakReport:A.PeakDetectHorizontal] Running Loop=1
2019-05-14T16:36:37.363Z,1557851797.363 [circle_acoustic_contact:Science:HighestChlPeakReport:A.PeakDetectHorizontal](INFO): Initialize.
2019-05-14T16:36:37.363Z,1557851797.363 [circle_acoustic_contact:Science:PeakDetectNO3] Running Loop=1
2019-05-14T16:36:37.364Z,1557851797.364 [circle_acoustic_contact:Science:PeakDetectNO3](DEBUG): Aggregate::initialize circle_acoustic_contact:Science:PeakDetectNO3
2019-05-14T16:36:37.364Z,1557851797.364 [circle_acoustic_contact:Science:PeakDetectNO3:A.PeakDetectVsDepth] Running Loop=1
2019-05-14T16:36:37.364Z,1557851797.364 [circle_acoustic_contact:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Initialize.
2019-05-14T16:36:37.370Z,1557851797.370 [circle_acoustic_contact:Science:PeakDetectOil] Running Loop=1
2019-05-14T16:36:37.370Z,1557851797.370 [circle_acoustic_contact:Science:PeakDetectOil](DEBUG): Aggregate::initialize circle_acoustic_contact:Science:PeakDetectOil
2019-05-14T16:36:37.370Z,1557851797.370 [circle_acoustic_contact:Science:PeakDetectOil:A.PeakDetectVsDepth] Running Loop=1
2019-05-14T16:36:37.370Z,1557851797.370 [circle_acoustic_contact:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Initialize.
2019-05-14T16:36:37.372Z,1557851797.372 [circle_acoustic_contact:Science:PeakDetectFDOM] Running Loop=1
2019-05-14T16:36:37.373Z,1557851797.373 [circle_acoustic_contact:Science:PeakDetectFDOM](DEBUG): Aggregate::initialize circle_acoustic_contact:Science:PeakDetectFDOM
2019-05-14T16:36:37.389Z,1557851797.389 [circle_acoustic_contact:Science:PeakDetectFDOM:A.PeakDetectVsDepth] Running Loop=1
2019-05-14T16:36:37.389Z,1557851797.389 [circle_acoustic_contact:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Initialize.
2019-05-14T16:36:37.391Z,1557851797.391 [circle_acoustic_contact:L.SetSpeed] Running Loop=1
2019-05-14T16:36:37.391Z,1557851797.391 [circle_acoustic_contact:L.SetSpeed](DEBUG): Initialize.
2019-05-14T16:36:37.391Z,1557851797.391 [circle_acoustic_contact:YoYos] Running Loop=1
2019-05-14T16:36:37.391Z,1557851797.391 [circle_acoustic_contact:YoYos](DEBUG): Aggregate::initialize circle_acoustic_contact:YoYos
2019-05-14T16:36:37.391Z,1557851797.391 [circle_acoustic_contact:YoYos:A.DepthEnvelope] Running Loop=1
2019-05-14T16:36:37.391Z,1557851797.391 [circle_acoustic_contact:YoYos:A.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent.
2019-05-14T16:36:37.392Z,1557851797.392 [circle_acoustic_contact:YoYos:B.AltitudeEnvelope] Running Loop=1
2019-05-14T16:36:37.392Z,1557851797.392 [circle_acoustic_contact:YoYos:B.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent.
2019-05-14T16:36:37.392Z,1557851797.392 [circle_acoustic_contact:YoYos:C.YoYo] Running Loop=1
2019-05-14T16:36:37.392Z,1557851797.392 [circle_acoustic_contact:YoYos:C.YoYo](DEBUG): Initialize YoYoComponent.
2019-05-14T16:36:37.392Z,1557851797.392 [circle_acoustic_contact:D] Running Loop=1
2019-05-14T16:36:37.397Z,1557851797.397 [circle_acoustic_contact:YoYos] Running Loop=1
2019-05-14T16:36:37.397Z,1557851797.397 [circle_acoustic_contact:YoYos:C.YoYo] Running Loop=1
2019-05-14T16:36:37.398Z,1557851797.398 [circle_acoustic_contact:YoYos:B.AltitudeEnvelope] Running Loop=1
2019-05-14T16:36:37.399Z,1557851797.399 [circle_acoustic_contact:YoYos:A.DepthEnvelope] Running Loop=1
2019-05-14T16:36:37.400Z,1557851797.400 [circle_acoustic_contact:L.SetSpeed] Running Loop=1
2019-05-14T16:36:37.409Z,1557851797.409 [circle_acoustic_contact:Science] Running Loop=1
2019-05-14T16:36:37.410Z,1557851797.410 [circle_acoustic_contact:Science:PeakDetectFDOM] Stopped
2019-05-14T16:36:37.411Z,1557851797.411 [circle_acoustic_contact:Science:PeakDetectFDOM](DEBUG): Aggregate::uninitialize circle_acoustic_contact:Science:PeakDetectFDOM
2019-05-14T16:36:37.411Z,1557851797.411 [circle_acoustic_contact:Science:PeakDetectFDOM:A.PeakDetectVsDepth] Stopped
2019-05-14T16:36:37.411Z,1557851797.411 [circle_acoustic_contact:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2019-05-14T16:36:37.411Z,1557851797.411 [circle_acoustic_contact:Science:PeakDetectOil] Stopped
2019-05-14T16:36:37.411Z,1557851797.411 [circle_acoustic_contact:Science:PeakDetectOil](DEBUG): Aggregate::uninitialize circle_acoustic_contact:Science:PeakDetectOil
2019-05-14T16:36:37.411Z,1557851797.411 [circle_acoustic_contact:Science:PeakDetectOil:A.PeakDetectVsDepth] Stopped
2019-05-14T16:36:37.411Z,1557851797.411 [circle_acoustic_contact:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2019-05-14T16:36:37.411Z,1557851797.411 [circle_acoustic_contact:Science:PeakDetectNO3] Stopped
2019-05-14T16:36:37.411Z,1557851797.411 [circle_acoustic_contact:Science:PeakDetectNO3](DEBUG): Aggregate::uninitialize circle_acoustic_contact:Science:PeakDetectNO3
2019-05-14T16:36:37.411Z,1557851797.411 [circle_acoustic_contact:Science:PeakDetectNO3:A.PeakDetectVsDepth] Stopped
2019-05-14T16:36:37.411Z,1557851797.411 [circle_acoustic_contact:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2019-05-14T16:36:37.411Z,1557851797.411 [circle_acoustic_contact:Science:HighestChlPeakReport] Stopped
2019-05-14T16:36:37.412Z,1557851797.412 [circle_acoustic_contact:Science:HighestChlPeakReport](DEBUG): Aggregate::uninitialize circle_acoustic_contact:Science:HighestChlPeakReport
2019-05-14T16:36:37.412Z,1557851797.412 [circle_acoustic_contact:Science:HighestChlPeakReport:A.PeakDetectHorizontal] Stopped
2019-05-14T16:36:37.412Z,1557851797.412 [circle_acoustic_contact:Science:HighestChlPeakReport:A.PeakDetectHorizontal](DEBUG): Uninitialize.
2019-05-14T16:36:37.412Z,1557851797.412 [circle_acoustic_contact:Science:PeakDetectChl] Running Loop=1
2019-05-14T16:36:37.412Z,1557851797.412 [circle_acoustic_contact:Science:Read_Oil] Stopped
2019-05-14T16:36:37.412Z,1557851797.412 [circle_acoustic_contact:Science:H] Stopped
2019-05-14T16:36:37.412Z,1557851797.412 [circle_acoustic_contact:Science:G] Running Loop=1
2019-05-14T16:36:37.417Z,1557851797.417 [circle_acoustic_contact:Science:G](DEBUG): Initialize ReadDataComponent to sense mass_concentration_of_chlorophyll_in_sea_water
2019-05-14T16:36:37.417Z,1557851797.417 [circle_acoustic_contact:Science:F] Stopped
2019-05-14T16:36:37.417Z,1557851797.417 [circle_acoustic_contact:Science:E] Stopped
2019-05-14T16:36:37.417Z,1557851797.417 [circle_acoustic_contact:Science:D] Running Loop=1
2019-05-14T16:36:37.418Z,1557851797.418 [circle_acoustic_contact:Science:D](DEBUG): Initialize ReadDataComponent to sense CTD_Seabird.sea_water_temperature
2019-05-14T16:36:37.419Z,1557851797.419 [circle_acoustic_contact:Science:D](DEBUG): Initialize ReadDataComponent to sense CTD_Seabird.sea_water_salinity
2019-05-14T16:36:37.419Z,1557851797.419 [circle_acoustic_contact:Science:C] Running Loop=1
2019-05-14T16:36:37.419Z,1557851797.419 [circle_acoustic_contact:Science:C](DEBUG): Initialize ReadDataComponent to sense sea_water_temperature
2019-05-14T16:36:37.420Z,1557851797.420 [circle_acoustic_contact:Science:C](DEBUG): Initialize ReadDataComponent to sense sea_water_salinity
2019-05-14T16:36:37.420Z,1557851797.420 [circle_acoustic_contact:Science:B] Stopped
2019-05-14T16:36:37.420Z,1557851797.420 [circle_acoustic_contact:Science:A] Running Loop=1
2019-05-14T16:36:37.441Z,1557851797.441 [circle_acoustic_contact:Science:A](DEBUG): Initialize ReadDataComponent to sense mass_concentration_of_oxygen_in_sea_water
2019-05-14T16:36:37.441Z,1557851797.441 [circle_acoustic_contact:J.Buoyancy] Running Loop=1
2019-05-14T16:36:37.441Z,1557851797.441 [circle_acoustic_contact:I.Pitch] Running Loop=1
2019-05-14T16:36:37.442Z,1557851797.442 [circle_acoustic_contact:StandardEnvelopes] Running Loop=1
2019-05-14T16:36:37.442Z,1557851797.442 [circle_acoustic_contact:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1
2019-05-14T16:36:37.465Z,1557851797.465 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown.
2019-05-14T16:36:37.468Z,1557851797.468 [circle_acoustic_contact:StandardEnvelopes:B.DepthEnvelope] Running Loop=1
2019-05-14T16:36:37.468Z,1557851797.468 [circle_acoustic_contact:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1
2019-05-14T16:36:37.481Z,1557851797.481 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4
2019-05-14T16:36:37.482Z,1557851797.482 [circle_acoustic_contact:D] Stopped
2019-05-14T16:36:37.482Z,1557851797.482 [circle_acoustic_contact:F] Running Loop=1
2019-05-14T16:36:37.482Z,1557851797.482 [circle_acoustic_contact:A.] Running Loop=1
2019-05-14T16:36:37.688Z,1557851797.688 [circle_acoustic_contact:F] Stopped
2019-05-14T16:36:37.688Z,1557851797.688 [circle_acoustic_contact:G] Running Loop=1
2019-05-14T16:36:37.697Z,1557851797.697 [WetLabsBB2FL](INFO): Opening uart, block timeout 10ths=2
2019-05-14T16:36:37.697Z,1557851797.697 [WetLabsBB2FL](INFO): Powering up
2019-05-14T16:36:37.954Z,1557851797.954 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20
2019-05-14T16:36:38.130Z,1557851798.130 [circle_acoustic_contact:G] Stopped
2019-05-14T16:36:38.130Z,1557851798.130 [circle_acoustic_contact:H] Running Loop=1
2019-05-14T16:36:38.215Z,1557851798.215 [BuoyancyServo](FAULT): Reading outside of valid range:0.000000
2019-05-14T16:36:38.215Z,1557851798.215 [BuoyancyServo](FAULT): Buoyancy engine reporting null position
2019-05-14T16:36:38.215Z,1557851798.215 [BuoyancyServo] Hardware Fault, FailCount= 1
2019-05-14T16:36:38.215Z,1557851798.215 [BuoyancyServo](ERROR): Hardware Fault
2019-05-14T16:36:38.269Z,1557851798.269 [CBIT](ERROR): Hardware Fault in component: BuoyancyServo
2019-05-14T16:36:38.517Z,1557851798.517 [circle_acoustic_contact:H] Stopped
2019-05-14T16:36:38.533Z,1557851798.533 [circle_acoustic_contact:CircleWrapper] Running Loop=1
2019-05-14T16:36:38.533Z,1557851798.533 [circle_acoustic_contact:CircleWrapper](DEBUG): Aggregate::initialize circle_acoustic_contact:CircleWrapper
2019-05-14T16:36:38.951Z,1557851798.951 [circle_acoustic_contact:CircleWrapper:CircleContact] Running Loop=1
2019-05-14T16:36:38.952Z,1557851798.952 [circle_acoustic_contact:CircleWrapper:CircleContact](DEBUG): Aggregate::initialize circle_acoustic_contact:CircleWrapper:CircleContact
2019-05-14T16:36:38.952Z,1557851798.952 [circle_acoustic_contact:CircleWrapper:CircleContact:A] Running Loop=1
2019-05-14T16:36:38.952Z,1557851798.952 [circle_acoustic_contact:CircleWrapper:CircleContact:B.Circle] Running Loop=1
2019-05-14T16:36:38.952Z,1557851798.952 [circle_acoustic_contact:CircleWrapper:CircleContact:B.Circle](DEBUG): Initialize CircleComponent.
2019-05-14T16:36:38.962Z,1557851798.962 [circle_acoustic_contact:CircleWrapper:CircleContact:A] Running Loop=1
2019-05-14T16:36:40.114Z,1557851800.114 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2019-05-14T16:36:40.114Z,1557851800.114 [BuoyancyServo](INFO): Powering down
2019-05-14T16:36:40.966Z,1557851800.966 [CTD_Seabird](ERROR): Failed to parse device response:
2019-05-14T16:36:41.408Z,1557851801.408 [CBIT](INFO): Clearing failed state for component BuoyancyServo
2019-05-14T16:36:41.420Z,1557851801.420 [BuoyancyServo] No Fault, FailCount= 1
2019-05-14T16:36:41.635Z,1557851801.635 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2019-05-14T16:36:41.641Z,1557851801.641 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2019-05-14T16:36:48.115Z,1557851808.115 [CommandLine](IMPORTANT): got command show variable contact_latitude
2019-05-14T16:36:48.587Z,1557851808.587 [CommandLine](IMPORTANT): Tracking.contact_latitude (degree)
2019-05-14T16:36:48.588Z,1557851808.588 [CommandLine](IMPORTANT): Tracking.contact_latitude_lowpass (degree)
2019-05-14T16:36:56.092Z,1557851816.092 [DVL_micro](ERROR): checksum mismatch: reported95 , calculated:65
2019-05-14T16:36:56.092Z,1557851816.092 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 1 1 1 0.2 9.9 9.6 10.2 -374.6 -88.6 -52.3 95.8 0 241 0 1 1 2 -430.2 -246.1 -113.2 1 -116.5 489.1 -74.9 1 -1062 419 429 2 683 915 429 2 3.28 6.86 254.8 0.2 18.6 0.005 35.0 1489 95
2019-05-14T16:36:57.727Z,1557851817.727 [DVL_micro](ERROR): checksum mismatch: reported85 , calculated:86
2019-05-14T16:36:57.728Z,1557851817.728 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 1 1 1 0.2 9.8 9.95.5 58.0 89.1 -29.5 0 -329 472 246 0 1 1 2 -246.4 116.8 5.9 1 176.1 202.3 49.6 1 110 -767 -44 2 -768 99 -44 2 3.23 8.69 254.4 0.2 18.6 0.005 35.0 1489 85
2019-05-14T16:36:58.528Z,1557851818.528 [CommandLine](IMPORTANT): got command report touch Tracking.contact_latitude
2019-05-14T16:37:00.198Z,1557851820.198 [DVL_micro](ERROR): only read 44 of 46 data items
2019-05-14T16:37:00.198Z,1557851820.198 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 1 1 0 0.2 9.9 0.6 0 -75.0 -80.9 -368.0 0 0 52 0 -419 0 1 0 2 391.0 375.3 -238.9 1 284.3 -431.9 -288.8 1 0 0 0 0 0 3.42 11.42 254.2 0.2 18.6 0.005 35.0 1489 77
2019-05-14T16:37:02.686Z,1557851822.686 [DVL_micro](ERROR): checksum mismatch: reported81 , calculated:95
2019-05-14T16:37:02.686Z,1557851822.686 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 1 1 0 0.2 10.1 0.6 0 99 -165.1 0 0 -85 0 -652 0 2 0 2 353.3 2 1 -84.3 -323.7 -119.3 1 0 756 0 0 0 0 0 0 3.51 13.97 254.1 0.2 18.6 0.005 35.0 1489 81
2019-05-14T16:37:05.518Z,1557851825.518 [CommandLine](IMPORTANT): got command report touch Tracking.contact_longitude
2019-05-14T16:37:13.095Z,1557851833.095 [CTD_Seabird](ERROR): Salinity reading out of range: 24.875883 psu
2019-05-14T16:37:13.334Z,1557851833.334 [DVL_micro](ERROR): No DVL communication! Re-initializing
2019-05-14T16:37:13.334Z,1557851833.334 [DVL_micro] Communications Fault, FailCount= 1
2019-05-14T16:37:13.334Z,1557851833.334 [DVL_micro](ERROR): Communications Fault
2019-05-14T16:37:13.660Z,1557851833.660 [CBIT](ERROR): Communications Fault in component: DVL_micro
2019-05-14T16:37:13.805Z,1557851833.805 [DVL_micro](INFO): uninitialize:Powering down
2019-05-14T16:37:14.099Z,1557851834.099 [CTD_Seabird](ERROR): Salinity reading out of range: 16.724083 psu
2019-05-14T16:37:14.688Z,1557851834.688 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-05-14T16:37:14.688Z,1557851834.688 [DVL_micro] No Fault, FailCount= 1
2019-05-14T16:37:14.963Z,1557851834.963 [DVL_micro](INFO): Initializing
2019-05-14T16:37:15.105Z,1557851835.105 [CTD_Seabird](ERROR): Salinity reading out of range: 16.625694 psu
2019-05-14T16:37:16.108Z,1557851836.108 [CTD_Seabird](ERROR): Salinity reading out of range: 21.028318 psu
2019-05-14T16:37:17.112Z,1557851837.112 [CTD_Seabird](ERROR): Salinity reading out of range: 27.060205 psu
2019-05-14T16:37:18.119Z,1557851838.119 [CTD_Seabird](ERROR): Salinity reading out of range: 21.592646 psu
2019-05-14T16:37:19.121Z,1557851839.121 [CTD_Seabird](ERROR): Salinity reading out of range: 17.938852 psu
2019-05-14T16:37:20.126Z,1557851840.126 [CTD_Seabird](ERROR): Salinity reading out of range: 17.803087 psu
2019-05-14T16:37:21.128Z,1557851841.128 [CTD_Seabird](ERROR): Salinity reading out of range: 17.117428 psu
2019-05-14T16:37:22.133Z,1557851842.133 [CTD_Seabird](ERROR): Salinity reading out of range: 16.734882 psu
2019-05-14T16:37:23.136Z,1557851843.136 [CTD_Seabird](ERROR): Salinity reading out of range: 16.632408 psu
2019-05-14T16:37:23.206Z,1557851843.206 [DVL_micro](ERROR): only read 45 of 46 data items
2019-05-14T16:37:23.207Z,1557851843.207 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0008 1 1 1 1 0.2 0.2 0.1 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 4.87 25.82 252.5 0.1 18.35.0 1489 77
2019-05-14T16:37:24.139Z,1557851844.139 [CTD_Seabird](ERROR): Salinity reading out of range: 16.342697 psu
2019-05-14T16:37:25.143Z,1557851845.143 [CTD_Seabird](ERROR): Salinity reading out of range: 16.433083 psu
2019-05-14T16:37:26.148Z,1557851846.148 [CTD_Seabird](ERROR): Salinity reading out of range: 16.668793 psu
2019-05-14T16:37:27.151Z,1557851847.151 [CTD_Seabird](ERROR): Salinity reading out of range: 17.835234 psu
2019-05-14T16:37:28.157Z,1557851848.157 [CTD_Seabird](ERROR): Salinity reading out of range: 27.924767 psu
2019-05-14T16:37:31.519Z,1557851851.519 [CommandLine](IMPORTANT): got command configSet DVL_micro.loadAtStartup 0.000000 bool persist
2019-05-14T16:37:31.519Z,1557851851.519 [CommandLine](IMPORTANT): configSet DVL_micro.loadAtStartup requires a restart to take effect.
2019-05-14T16:37:34.507Z,1557851854.507 [DVL_micro](ERROR): No DVL communication! Re-initializing
2019-05-14T16:37:34.507Z,1557851854.507 [DVL_micro] Communications Fault, FailCount= 1
2019-05-14T16:37:34.507Z,1557851854.507 [DVL_micro](ERROR): Communications Fault
2019-05-14T16:37:34.733Z,1557851854.733 [CBIT](ERROR): Communications Fault in component: DVL_micro
2019-05-14T16:37:35.037Z,1557851855.037 [DVL_micro](INFO): uninitialize:Powering down
2019-05-14T16:37:35.084Z,1557851855.084 [ElevatorOffsetCalculator](INFO): New estimator for commanded vars: speed 1.00 m/s, pitch -20.00 deg, mass-position -10.00 mm (1 active estimators).
2019-05-14T16:37:36.038Z,1557851856.038 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-05-14T16:37:36.038Z,1557851856.038 [DVL_micro] No Fault, FailCount= 1
2019-05-14T16:37:36.200Z,1557851856.200 [DVL_micro](INFO): Initializing
2019-05-14T16:37:37.504Z,1557851857.504 [circle_acoustic_contact:A.](INFO): *** querying DAT ***
2019-05-14T16:37:37.840Z,1557851857.840 [DAT](INFO): ****** ping requested ******
2019-05-14T16:37:39.032Z,1557851859.032 [DVL_micro](ERROR): only read 29 of 46 data items
2019-05-14T16:37:39.037Z,1557851859.037 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 1 1 0 0.2 4.2 0.6 0 133.2 403.7 -350 00 0 0 0 0 0 0 4.20 24.60 253.3 0.2 18.6 0.005 35.0 1489 87
2019-05-14T16:37:39.832Z,1557851859.832 [DVL_micro](ERROR): only read 4 of 46 data items
2019-05-14T16:37:39.835Z,1557851859.835 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 2 4.2 0.6 0 135.3 313.9 -222.5 0 0 0 0 -16 0 0 0 2 477.5 954.3 -47.0 1 802.1 -684.1 -171.5 1 0 0 0 0 0 0 0 0 4.19 24.58 253.6 0.2 18.6 0.005 35.0 1489 114
2019-05-14T16:37:41.888Z,1557851861.888 [DAT](FAULT): unknown deviceResponse_: 16:26:18.6898 LVL= 23408, 23681, 19874, 15843, AGC= 27, IDX= 103, 0.28, 1.608, 2.764, 0.953, 1.484, PHS= 0.211, 1.327,-0.534, |v|= 0.959,-0.185, 1.612,-0.355, RAW= 353.4, -12.3, CAL= 352.6, -15.6, ROT= 187.4, 15.6
2019-05-14T16:37:41.888Z,1557851861.888 [DAT] Communications Fault, FailCount= 1
2019-05-14T16:37:41.888Z,1557851861.888 [DAT](ERROR): Communications Fault
2019-05-14T16:37:42.285Z,1557851862.286 [CBIT](ERROR): Communications Fault in component: DAT
2019-05-14T16:37:42.402Z,1557851862.402 [DAT](INFO): Powering down
2019-05-14T16:37:43.658Z,1557851863.658 [CBIT](INFO): Clearing failed state for component DAT
2019-05-14T16:37:43.658Z,1557851863.658 [DAT] No Fault, FailCount= 0
2019-05-14T16:37:44.545Z,1557851864.545 [DVL_micro](ERROR): only read 44 of 46 data items
2019-05-14T16:37:44.546Z,1557851864.546 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 1 1 0 6.0 4.2 5.4 0 40.0 48.0 49.9 0 0 0 0 85 0 0 0 2 -13.2 8.1 48.5 1 2.2 -8.5 50.1 1 0 0 0 0 0 0 0 0 3.91 23.73 253.25 0.005 35.0 1489 105
2019-05-14T16:37:45.328Z,1557851865.328 [DVL_micro](ERROR): only read 45 of 46 data items
2019-05-14T16:37:45.328Z,1557851865.328 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 0 1 0 6.2 0 9.1 0 -31.8 0 -4.0 0 0 94 -361 61 0 2 2 2 -206.9 44.0 83.6 2 101.9 185.3 83.6 2 -206 44 83 2 101 185 83 2 3.90 23.73 253.2 -2..005 35.0 1489 107
2019-05-14T16:37:45.791Z,1557851865.791 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2019-05-14T16:37:45.791Z,1557851865.791 [DAT](INFO): Powering up
2019-05-14T16:37:45.791Z,1557851865.791 [DAT](DEBUG): Initializing DAT.
2019-05-14T16:37:45.801Z,1557851865.801 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2019-05-14T16:37:54.420Z,1557851874.420 [DVL_micro](ERROR): only read 45 of 46 data items
2019-05-14T16:37:54.420Z,1557851874.420 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 1 1 0 5.9 4.2 4.2 0 16.6 -4.2 -37.4 0 0 0 0 21 0 0 0 2 72.1 16.5 -11.2 1 1.6 -64.3 -38.3 1 0 0 0 0 0 0 0 4.15 254.5 4.2 18.5 0.005 35.0 1489 121
2019-05-14T16:37:56.053Z,1557851876.053 [DVL_micro](ERROR): only read 45 of 46 data items
2019-05-14T16:37:56.054Z,1557851876.054 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 1 1 0 5.9 4.3 4.2 0 -3.2 30.1 -12.2 0 0 0 0 -71 0 0 0 2 12.0 100.9 -8.3 1 95.1 -36.5 -4.1 1 0 0 0 0 0 0 0 0 4.73 23.77 254.3 4.2 05 35.0 1489 88
2019-05-14T16:37:57.686Z,1557851877.686 [DVL_micro](ERROR): only read 44 of 46 data items
2019-05-14T16:37:57.686Z,1557851877.686 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 0 1 1 0 0 10.1 4.2 0 0 -4.6 45.6 0 -50 11 0 -108 2 1 0 2 -129.5 158.8 -52.3 2 186.6 84.6 -52.3 2 -129 15186 84 -52 2 4.80 23.05 255.2 -2.0 18.5 0.005 35.0 1489 84
2019-05-14T16:37:58.978Z,1557851878.978 [CommandLine](IMPORTANT): got command stop
2019-05-14T16:37:58.979Z,1557851878.979 [CommandLine](IMPORTANT): Scheduling is paused
2019-05-14T16:37:58.979Z,1557851878.979 [Supervisor](INFO): Stop Mission called by CommandLine::commandStop
2019-05-14T16:37:59.102Z,1557851879.102 [DAT](INFO): setting local address to 2
2019-05-14T16:37:59.204Z,1557851879.204 [MissionManager](INFO): MissionManager is completed.
2019-05-14T16:37:59.213Z,1557851879.213 [MissionManager](INFO): Uninitializing Mission circle_acoustic_contact
2019-05-14T16:37:59.213Z,1557851879.213 [circle_acoustic_contact] Stopped
2019-05-14T16:37:59.213Z,1557851879.213 [circle_acoustic_contact](DEBUG): Aggregate::uninitialize circle_acoustic_contact
2019-05-14T16:37:59.214Z,1557851879.214 [circle_acoustic_contact:A.] Stopped
2019-05-14T16:37:59.214Z,1557851879.214 [circle_acoustic_contact:StandardEnvelopes] Stopped
2019-05-14T16:37:59.214Z,1557851879.214 [circle_acoustic_contact:StandardEnvelopes](DEBUG): Aggregate::uninitialize circle_acoustic_contact:StandardEnvelopes
2019-05-14T16:37:59.214Z,1557851879.214 [circle_acoustic_contact:StandardEnvelopes:A.AltitudeEnvelope] Stopped
2019-05-14T16:37:59.214Z,1557851879.214 [circle_acoustic_contact:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent.
2019-05-14T16:37:59.215Z,1557851879.215 [circle_acoustic_contact:StandardEnvelopes:B.DepthEnvelope] Stopped
2019-05-14T16:37:59.215Z,1557851879.215 [circle_acoustic_contact:StandardEnvelopes:B.DepthEnvelope](DEBUG): Uninitialize.
2019-05-14T16:37:59.215Z,1557851879.215 [circle_acoustic_contact:StandardEnvelopes:C.OffshoreEnvelope] Stopped
2019-05-14T16:37:59.215Z,1557851879.215 [circle_acoustic_contact:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Uninitialize OffshoreEnvelopeComponent.
2019-05-14T16:37:59.215Z,1557851879.215 [circle_acoustic_contact:I.Pitch] Stopped
2019-05-14T16:37:59.215Z,1557851879.215 [circle_acoustic_contact:J.Buoyancy] Stopped
2019-05-14T16:37:59.215Z,1557851879.215 [circle_acoustic_contact:J.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2019-05-14T16:37:59.215Z,1557851879.215 [circle_acoustic_contact:Science] Stopped
2019-05-14T16:37:59.215Z,1557851879.215 [circle_acoustic_contact:Science](DEBUG): Aggregate::uninitialize circle_acoustic_contact:Science
2019-05-14T16:37:59.216Z,1557851879.216 [circle_acoustic_contact:Science:A] Stopped
2019-05-14T16:37:59.216Z,1557851879.216 [circle_acoustic_contact:Science:C] Stopped
2019-05-14T16:37:59.216Z,1557851879.216 [circle_acoustic_contact:Science:D] Stopped
2019-05-14T16:37:59.216Z,1557851879.216 [circle_acoustic_contact:Science:G] Stopped
2019-05-14T16:37:59.216Z,1557851879.216 [circle_acoustic_contact:Science:PeakDetectChl] Stopped
2019-05-14T16:37:59.216Z,1557851879.216 [circle_acoustic_contact:Science:PeakDetectChl](DEBUG): Aggregate::uninitialize circle_acoustic_contact:Science:PeakDetectChl
2019-05-14T16:37:59.216Z,1557851879.216 [circle_acoustic_contact:Science:PeakDetectChl:A.PeakDetectVsDepth] Stopped
2019-05-14T16:37:59.216Z,1557851879.216 [circle_acoustic_contact:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2019-05-14T16:37:59.222Z,1557851879.222 [circle_acoustic_contact:L.SetSpeed] Stopped
2019-05-14T16:37:59.222Z,1557851879.222 [circle_acoustic_contact:L.SetSpeed](DEBUG): Uninitialize.
2019-05-14T16:37:59.222Z,1557851879.222 [circle_acoustic_contact:YoYos] Stopped
2019-05-14T16:37:59.223Z,1557851879.223 [circle_acoustic_contact:YoYos](DEBUG): Aggregate::uninitialize circle_acoustic_contact:YoYos
2019-05-14T16:37:59.223Z,1557851879.223 [circle_acoustic_contact:YoYos:A.DepthEnvelope] Stopped
2019-05-14T16:37:59.223Z,1557851879.223 [circle_acoustic_contact:YoYos:A.DepthEnvelope](DEBUG): Uninitialize.
2019-05-14T16:37:59.223Z,1557851879.223 [circle_acoustic_contact:YoYos:B.AltitudeEnvelope] Stopped
2019-05-14T16:37:59.223Z,1557851879.223 [circle_acoustic_contact:YoYos:B.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent.
2019-05-14T16:37:59.223Z,1557851879.223 [circle_acoustic_contact:YoYos:C.YoYo] Stopped
2019-05-14T16:37:59.223Z,1557851879.223 [circle_acoustic_contact:YoYos:C.YoYo](DEBUG): Uninitialize YoYoComponent.
2019-05-14T16:37:59.224Z,1557851879.224 [circle_acoustic_contact:CircleWrapper] Stopped
2019-05-14T16:37:59.224Z,1557851879.224 [circle_acoustic_contact:CircleWrapper](DEBUG): Aggregate::uninitialize circle_acoustic_contact:CircleWrapper
2019-05-14T16:37:59.224Z,1557851879.224 [circle_acoustic_contact:CircleWrapper:CircleContact] Stopped
2019-05-14T16:37:59.224Z,1557851879.224 [circle_acoustic_contact:CircleWrapper:CircleContact](DEBUG): Aggregate::uninitialize circle_acoustic_contact:CircleWrapper:CircleContact
2019-05-14T16:37:59.224Z,1557851879.224 [circle_acoustic_contact:CircleWrapper:CircleContact:A] Stopped
2019-05-14T16:37:59.224Z,1557851879.224 [circle_acoustic_contact:CircleWrapper:CircleContact:B.Circle] Stopped
2019-05-14T16:37:59.224Z,1557851879.224 [circle_acoustic_contact:CircleWrapper:CircleContact:B.Circle](DEBUG): Uninitialize.
2019-05-14T16:37:59.441Z,1557851879.441 [WetLabsBB2FL](INFO): Powering down
2019-05-14T16:37:59.562Z,1557851879.562 [DVL_micro](ERROR): only read 45 of 46 data items
2019-05-14T16:37:59.562Z,1557851879.562 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 1 1 1 6.1 5.1 4.2 4.2 -152.6 59.0 -52.9 60.7 0 0 0 0 0 0 0 0 -133.1 -2.3 -23.1 1 .5 27.7 1 0 0 0 0 0 0 0 0 4.85 5.3 4.2 18.5 0.005 35.0 1489 112
2019-05-14T16:37:59.578Z,1557851879.578 [DAT](INFO): set local address to 2
2019-05-14T16:37:59.623Z,1557851879.623 [MissionManager](IMPORTANT): Started mission Default
2019-05-14T16:37:59.623Z,1557851879.623 [Default] Running Loop=1
2019-05-14T16:37:59.623Z,1557851879.623 [Default](DEBUG): Aggregate::initialize Default
2019-05-14T16:37:59.623Z,1557851879.623 [Default:B.GoToSurface] Running Loop=1
2019-05-14T16:37:59.623Z,1557851879.623 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-05-14T16:37:59.624Z,1557851879.624 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-05-14T16:37:59.624Z,1557851879.624 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-05-14T16:37:59.629Z,1557851879.629 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-05-14T16:37:59.630Z,1557851879.630 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-05-14T16:37:59.631Z,1557851879.631 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-05-14T16:37:59.631Z,1557851879.631 [Default:A.Wait] Running Loop=1
2019-05-14T16:37:59.631Z,1557851879.631 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-05-14T16:38:00.065Z,1557851880.065 [Aanderaa_O2](INFO): Powering down
2019-05-14T16:38:00.105Z,1557851880.105 [ElevatorOffsetCalculator](INFO): New estimator for commanded vars: speed 1.00 m/s, pitch 30.00 deg, mass-position -35.00 mm (2 active estimators).
2019-05-14T16:38:00.540Z,1557851880.540 [Default:B.GoToSurface](ERROR): Altitude too low: 0.80
2019-05-14T16:38:00.872Z,1557851880.872 [Default:B.GoToSurface](ERROR): Altitude too low: 0.80
2019-05-14T16:38:01.384Z,1557851881.384 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:01.689Z,1557851881.689 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:02.211Z,1557851882.211 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:02.522Z,1557851882.522 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:02.951Z,1557851882.951 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:03.315Z,1557851883.315 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:03.804Z,1557851883.804 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:04.151Z,1557851884.151 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:04.591Z,1557851884.591 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:04.970Z,1557851884.970 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:05.399Z,1557851885.399 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:05.735Z,1557851885.735 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:06.246Z,1557851886.246 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:06.574Z,1557851886.574 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:07.063Z,1557851887.063 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:07.361Z,1557851887.361 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:07.802Z,1557851887.802 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:08.150Z,1557851888.150 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:08.637Z,1557851888.637 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:08.962Z,1557851888.962 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:09.390Z,1557851889.390 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:09.783Z,1557851889.783 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:10.206Z,1557851890.206 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:10.605Z,1557851890.605 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:11.030Z,1557851891.030 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:11.403Z,1557851891.403 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:11.838Z,1557851891.838 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:12.198Z,1557851892.198 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:12.603Z,1557851892.603 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:12.994Z,1557851892.994 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:12.995Z,1557851892.995 [Default:A.Wait](INFO): Done Waiting.
2019-05-14T16:38:12.995Z,1557851892.995 [Default:A.Wait] Stopped
2019-05-14T16:38:12.995Z,1557851892.995 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-05-14T16:38:13.421Z,1557851893.421 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:13.810Z,1557851893.810 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:14.204Z,1557851894.204 [DVL_micro](ERROR): only read 45 of 46 data items
2019-05-14T16:38:14.204Z,1557851894.204 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 1 1 1 0.2 9.4 8.5 10.6 325.5 287.3 105.0 31.3 0 -151 -23 97 0 1 2 2 72.1 -331.0 -29.1 2 -338.1 20.8 -29.1 2 72 -3 -338 20 -29 2 5.51 21.94 254.2 0.2 18.6 0.005 35.0 1489 94
2019-05-14T16:38:14.231Z,1557851894.231 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:14.629Z,1557851894.629 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:15.017Z,1557851895.017 [DVL_micro](ERROR): checksum mismatch: reported113 , calculated:102
2019-05-14T16:38:15.017Z,1557851895.017 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 1 1 1 0.2 9..6 182.8 66.3 77.3 -327.6 0 -32 -497 503 0 1 2 2 140.8 525.7 -0.3 1 469.0 -276.0 -5.0 1 -628 -714 254 2 -518 797 254 2 5.41 22.67 254.4 0.2 18.6 0.005 35.0 1489 113
2019-05-14T16:38:15.063Z,1557851895.063 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:15.431Z,1557851895.431 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:15.932Z,1557851895.932 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:16.296Z,1557851896.296 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:16.662Z,1557851896.662 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:17.043Z,1557851897.043 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:17.490Z,1557851897.490 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:17.836Z,1557851897.836 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:18.266Z,1557851898.266 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:18.644Z,1557851898.644 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:19.078Z,1557851899.078 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:19.455Z,1557851899.455 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:19.888Z,1557851899.888 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:20.274Z,1557851900.274 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:21.519Z,1557851901.519 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:21.884Z,1557851901.884 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:22.470Z,1557851902.470 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:22.832Z,1557851902.832 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:23.247Z,1557851903.247 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:23.621Z,1557851903.621 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:24.047Z,1557851904.047 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:24.442Z,1557851904.442 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:24.882Z,1557851904.882 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:25.255Z,1557851905.255 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:25.686Z,1557851905.686 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:26.051Z,1557851906.051 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:26.462Z,1557851906.462 [Default:B.GoToSurface](ERROR): Altitude too low: 0.10
2019-05-14T16:38:26.855Z,1557851906.855 [Default:B.GoToSurface](ERROR): Altitude too low: 0.10
2019-05-14T16:38:27.271Z,1557851907.271 [Default:B.GoToSurface](ERROR): Altitude too low: 0.10
2019-05-14T16:38:27.670Z,1557851907.670 [Default:B.GoToSurface](ERROR): Altitude too low: 0.10
2019-05-14T16:38:28.102Z,1557851908.102 [Default:B.GoToSurface](ERROR): Altitude too low: 0.10
2019-05-14T16:38:28.476Z,1557851908.476 [Default:B.GoToSurface](ERROR): Altitude too low: 0.10
2019-05-14T16:38:28.931Z,1557851908.931 [Default:B.GoToSurface](ERROR): Altitude too low: 0.10
2019-05-14T16:38:29.270Z,1557851909.270 [Default:B.GoToSurface](ERROR): Altitude too low: 0.10
2019-05-14T16:38:29.694Z,1557851909.694 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:30.075Z,1557851910.075 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:30.494Z,1557851910.494 [Default:B.GoToSurface](ERROR): Altitude too low: 0.10
2019-05-14T16:38:30.883Z,1557851910.883 [Default:B.GoToSurface](ERROR): Altitude too low: 0.10
2019-05-14T16:38:31.311Z,1557851911.311 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:31.702Z,1557851911.702 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:32.134Z,1557851912.134 [Default:B.GoToSurface](ERROR): Altitude too low: 0.10
2019-05-14T16:38:32.521Z,1557851912.521 [Default:B.GoToSurface](ERROR): Altitude too low: 0.10
2019-05-14T16:38:32.971Z,1557851912.971 [Default:B.GoToSurface](ERROR): Altitude too low: 0.10
2019-05-14T16:38:33.304Z,1557851913.304 [Default:B.GoToSurface](ERROR): Altitude too low: 0.10
2019-05-14T16:38:33.732Z,1557851913.732 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:34.118Z,1557851914.118 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:34.540Z,1557851914.540 [Default:B.GoToSurface](ERROR): Altitude too low: 0.10
2019-05-14T16:38:34.934Z,1557851914.934 [Default:B.GoToSurface](ERROR): Altitude too low: 0.10
2019-05-14T16:38:35.382Z,1557851915.382 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:35.753Z,1557851915.753 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:36.221Z,1557851916.221 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:36.582Z,1557851916.582 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:37.010Z,1557851917.010 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:37.354Z,1557851917.354 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:37.791Z,1557851917.791 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:38.161Z,1557851918.161 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:38.609Z,1557851918.609 [Default:B.GoToSurface](ERROR): Altitude too low: 0.10
2019-05-14T16:38:38.978Z,1557851918.978 [Default:B.GoToSurface](ERROR): Altitude too low: 0.10
2019-05-14T16:38:39.438Z,1557851919.438 [Default:B.GoToSurface](ERROR): Altitude too low: 0.10
2019-05-14T16:38:39.804Z,1557851919.804 [Default:B.GoToSurface](ERROR): Altitude too low: 0.10
2019-05-14T16:38:40.192Z,1557851920.192 [Default:B.GoToSurface](ERROR): Altitude too low: 0.10
2019-05-14T16:38:40.582Z,1557851920.582 [Default:B.GoToSurface](ERROR): Altitude too low: 0.10
2019-05-14T16:38:41.003Z,1557851921.003 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:41.390Z,1557851921.390 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:41.812Z,1557851921.812 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:42.210Z,1557851922.210 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:42.638Z,1557851922.638 [Default:B.GoToSurface](ERROR): Altitude too low: 0.10
2019-05-14T16:38:43.022Z,1557851923.022 [Default:B.GoToSurface](ERROR): Altitude too low: 0.10
2019-05-14T16:38:43.439Z,1557851923.439 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:43.814Z,1557851923.814 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:44.238Z,1557851924.238 [Default:B.GoToSurface](ERROR): Altitude too low: 0.10
2019-05-14T16:38:44.617Z,1557851924.617 [Default:B.GoToSurface](ERROR): Altitude too low: 0.10
2019-05-14T16:38:45.046Z,1557851925.046 [Default:B.GoToSurface](ERROR): Altitude too low: 0.10
2019-05-14T16:38:45.438Z,1557851925.438 [Default:B.GoToSurface](ERROR): Altitude too low: 0.10
2019-05-14T16:38:45.878Z,1557851925.878 [Default:B.GoToSurface](ERROR): Altitude too low: 0.10
2019-05-14T16:38:46.251Z,1557851926.251 [Default:B.GoToSurface](ERROR): Altitude too low: 0.10
2019-05-14T16:38:46.662Z,1557851926.662 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:47.054Z,1557851927.054 [Default:B.GoToSurface](ERROR): Altitude too low: 0.20
2019-05-14T16:38:47.475Z,1557851927.475 [Default:B.GoToSurface](ERROR): Altitude too low: 0.10
2019-05-14T16:38:47.862Z,1557851927.862 [Default:B.GoToSurface](ERROR): Altitude too low: 0.10
2019-05-14T16:38:48.311Z,1557851928.311 [Default:B.GoToSurface](ERROR): Altitude too low: 0.10
2019-05-14T16:38:48.662Z,1557851928.662 [Default:B.GoToSurface](ERROR): Altitude too low: 0.10
2019-05-14T16:38:49.086Z,1557851929.086 [Default:B.GoToSurface](ERROR): Altitude too low: 0.10
2019-05-14T16:38:49.470Z,1557851929.470 [Default:B.GoToSurface](ERROR): Altitude too low: 0.10
2019-05-14T16:38:49.894Z,1557851929.894 [Default:B.GoToSurface](ERROR): Altitude too low: 0.10
2019-05-14T16:38:50.286Z,1557851930.286 [Default:B.GoToSurface](ERROR): Altitude too low: 0.10
2019-05-14T16:38:50.722Z,1557851930.722 [Default:B.GoToSurface](ERROR): Altitude too low: 0.10
2019-05-14T16:38:51.094Z,1557851931.094 [Default:B.GoToSurface](ERROR): Altitude too low: 0.10
2019-05-14T16:38:51.540Z,1557851931.540 [Default:B.GoToSurface](ERROR): Altitude too low: 0.10
2019-05-14T16:38:51.894Z,1557851931.894 [Default:B.GoToSurface](ERROR): Altitude too low: 0.10
2019-05-14T16:38:52.345Z,1557851932.345 [Default:B.GoToSurface](ERROR): Altitude too low: 0.10
2019-05-14T16:38:52.702Z,1557851932.702 [Default:B.GoToSurface](ERROR): Altitude too low: 0.10
2019-05-14T16:38:53.119Z,1557851933.119 [Default:B.GoToSurface](ERROR): Altitude too low: 0.10
2019-05-14T16:38:53.510Z,1557851933.510 [Default:B.GoToSurface](ERROR): Altitude too low: 0.10
2019-05-14T16:38:53.932Z,1557851933.932 [Default:B.GoToSurface](ERROR): Altitude too low: 0.10
2019-05-14T16:38:54.330Z,1557851934.330 [Default:B.GoToSurface](ERROR): Altitude too low: 0.10
2019-05-14T16:38:54.774Z,1557851934.774 [Default:B.GoToSurface](ERROR): Altitude too low: 0.10
2019-05-14T16:38:55.140Z,1557851935.140 [Default:B.GoToSurface](ERROR): Altitude too low: 0.10
2019-05-14T16:38:55.564Z,1557851935.564 [Default:B.GoToSurface](ERROR): Altitude too low: 0.10
2019-05-14T16:38:55.946Z,1557851935.946 [Default:B.GoToSurface](ERROR): Altitude too low: 0.10
2019-05-14T16:38:56.358Z,1557851936.358 [Default:B.GoToSurface](ERROR): Altitude too low: 0.10
2019-05-14T16:38:56.742Z,1557851936.742 [Default:B.GoToSurface](ERROR): Altitude too low: 0.10
2019-05-14T16:38:57.159Z,1557851937.159 [Default:B.GoToSurface](ERROR): Altitude too low: 0.10
2019-05-14T16:38:57.552Z,1557851937.552 [Default:B.GoToSurface](ERROR): Altitude too low: 0.10
2019-05-14T16:38:57.996Z,1557851937.996 [Default:B.GoToSurface](ERROR): Altitude too low: 0.10
2019-05-14T16:38:58.371Z,1557851938.371 [Default:B.GoToSurface](ERROR): Altitude too low: 0.10
2019-05-14T16:38:58.830Z,1557851938.830 [Default:B.GoToSurface](ERROR): Altitude too low: 0.10
2019-05-14T16:38:59.192Z,1557851939.192 [Default:B.GoToSurface](ERROR): Altitude too low: 0.10
2019-05-14T16:38:59.590Z,1557851939.590 [Default:B.GoToSurface](ERROR): Altitude too low: 0.10
2019-05-14T16:38:59.982Z,1557851939.982 [Default:CheckIn] Running Loop=1
2019-05-14T16:38:59.983Z,1557851939.983 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-05-14T16:38:59.983Z,1557851939.983 [Default:CheckIn:Read_GPS] Running Loop=1
2019-05-14T16:39:01.585Z,1557851941.585 [NAL9602](DEBUG): Fix Requested
2019-05-14T16:41:51.747Z,1557852111.747 [CommandLine](IMPORTANT): got command restart application
2019-05-14T16:41:52.753Z,1557852112.753 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-14T16:41:52.753Z,1557852112.753 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-05-14T16:41:52.821Z,1557852112.821 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye!
2019-05-14T16:41:52.821Z,1557852112.821 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-05-14T16:41:52.822Z,1557852112.822 [CommandLine](INFO): Join timeout helper Thread ID is 7409
2019-05-14T16:41:52.822Z,1557852112.822 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2019-05-14T16:41:52.822Z,1557852112.822 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-05-14T16:41:52.823Z,1557852112.823 [NavChartDb](INFO): Join timeout helper Thread ID is 7410
2019-05-14T16:41:53.205Z,1557852113.205 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-14T16:41:53.205Z,1557852113.205 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-05-14T16:41:53.213Z,1557852113.213 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2019-05-14T16:41:53.213Z,1557852113.213 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-05-14T16:41:53.213Z,1557852113.213 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 7411
2019-05-14T16:41:53.278Z,1557852113.278 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-14T16:41:53.278Z,1557852113.278 [WetLabsBB2FL](INFO): Powering down
2019-05-14T16:41:53.279Z,1557852113.279 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-05-14T16:41:53.293Z,1557852113.293 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2019-05-14T16:41:53.293Z,1557852113.293 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2019-05-14T16:41:53.293Z,1557852113.293 [CTD_Seabird](INFO): Join timeout helper Thread ID is 7412
2019-05-14T16:41:54.210Z,1557852114.210 [DVL_micro](ERROR): only read 45 of 46 data items
2019-05-14T16:41:54.210Z,1557852114.210 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 1 1 1 0.2 9.7 0.6 10.2 120.6 -7.3 -753.1 -23.6 0 -233 0 229 0 1 0 2 1166.1 21.8 -178.9 1 -314.9 -1120.6 -193.5 1 0 -616 0 0 0 0 0 0 3.35 0.80 252.7 0.2 18.6 .0 1489 112
2019-05-14T16:41:54.281Z,1557852114.281 [CTD_Seabird](INFO): Powering down
2019-05-14T16:41:54.293Z,1557852114.293 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-14T16:41:54.293Z,1557852114.293 [CTD_Seabird](INFO): Powering down
2019-05-14T16:41:54.305Z,1557852114.305 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2019-05-14T16:41:54.321Z,1557852114.321 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2019-05-14T16:41:54.321Z,1557852114.321 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-05-14T16:41:54.321Z,1557852114.321 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 7413
2019-05-14T16:41:54.473Z,1557852114.473 [CTD_NeilBrown](INFO): Powering down
2019-05-14T16:41:54.485Z,1557852114.485 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-14T16:41:54.485Z,1557852114.485 [CTD_NeilBrown](INFO): Powering down
2019-05-14T16:41:54.497Z,1557852114.497 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-05-14T16:41:54.502Z,1557852114.502 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2019-05-14T16:41:54.503Z,1557852114.503 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-05-14T16:41:54.503Z,1557852114.503 [Radio_Surface](INFO): Join timeout helper Thread ID is 7414
2019-05-14T16:41:54.641Z,1557852114.641 [Radio_Surface](INFO): Powering down
2019-05-14T16:41:54.642Z,1557852114.642 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-14T16:41:54.642Z,1557852114.642 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-05-14T16:41:54.658Z,1557852114.658 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2019-05-14T16:41:54.658Z,1557852114.658 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-05-14T16:41:54.658Z,1557852114.658 [DataOverHttps](INFO): Join timeout helper Thread ID is 7415
2019-05-14T16:41:54.981Z,1557852114.981 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-14T16:41:54.981Z,1557852114.981 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-05-14T16:41:55.006Z,1557852115.006 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2019-05-14T16:41:55.006Z,1557852115.006 [logger ThreadHandler](INFO): Thread cancelled.
2019-05-14T16:41:55.006Z,1557852115.006 [logger](INFO): Join timeout helper Thread ID is 7416
2019-05-14T16:41:55.065Z,1557852115.065 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-14T16:41:55.065Z,1557852115.065 [logger ThreadHandler](INFO): Thread cancelled.
2019-05-14T16:41:55.070Z,1557852115.070 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2019-05-14T16:41:55.070Z,1557852115.070 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-05-14T16:41:55.070Z,1557852115.070 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2019-05-14T16:41:55.070Z,1557852115.070 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-05-14T16:41:55.070Z,1557852115.070 [controlThread](INFO): Join timeout helper Thread ID is 7417
2019-05-14T16:41:55.086Z,1557852115.086 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-14T16:41:55.087Z,1557852115.087 [controlThread](DEBUG): Uninitializing ControlThread
2019-05-14T16:41:55.087Z,1557852115.087 [AHRS_M2](INFO): Powering down
2019-05-14T16:41:55.229Z,1557852115.229 [DVL_micro](INFO): uninitialize:Powering down
2019-05-14T16:41:55.230Z,1557852115.230 [NAL9602](INFO): Powering down
2019-05-14T16:41:55.231Z,1557852115.231 [DAT](INFO): Powering down
2019-05-14T16:41:55.349Z,1557852115.349 [Aanderaa_O2](INFO): Powering down
2019-05-14T16:41:55.350Z,1557852115.350 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2019-05-14T16:41:55.351Z,1557852115.351 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2019-05-14T16:41:55.352Z,1557852115.352 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2019-05-14T16:41:55.352Z,1557852115.352 [MissionManager](INFO): Uninitializing Mission Default
2019-05-14T16:41:55.352Z,1557852115.352 [Default] Stopped
2019-05-14T16:41:55.353Z,1557852115.353 [Default](DEBUG): Aggregate::uninitialize Default
2019-05-14T16:41:55.353Z,1557852115.353 [Default:B.GoToSurface] Stopped
2019-05-14T16:41:55.353Z,1557852115.353 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-05-14T16:41:55.353Z,1557852115.353 [Default:CheckIn] Stopped
2019-05-14T16:41:55.353Z,1557852115.353 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-05-14T16:41:55.353Z,1557852115.353 [Default:CheckIn:Read_GPS] Stopped
2019-05-14T16:41:55.355Z,1557852115.355 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2019-05-14T16:41:55.356Z,1557852115.356 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2019-05-14T16:41:55.356Z,1557852115.356 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2019-05-14T16:41:55.356Z,1557852115.356 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2019-05-14T16:41:55.356Z,1557852115.356 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2019-05-14T16:41:55.356Z,1557852115.356 [BuoyancyServo](INFO): Powering down
2019-05-14T16:41:55.369Z,1557852115.369 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2019-05-14T16:41:55.369Z,1557852115.369 [ElevatorServo](INFO): Powering down
2019-05-14T16:41:55.370Z,1557852115.370 [MassServo](DEBUG): Uninitialize Mass Servo.
2019-05-14T16:41:55.370Z,1557852115.370 [MassServo](INFO): Powering down
2019-05-14T16:41:55.371Z,1557852115.371 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-05-14T16:41:55.371Z,1557852115.371 [RudderServo](INFO): Powering down
2019-05-14T16:41:55.372Z,1557852115.372 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2019-05-14T16:41:55.372Z,1557852115.372 [ThrusterServo](INFO): Powering down
2019-05-14T16:41:55.372Z,1557852115.372 [SBIT](DEBUG): Uninitialize SBIT Component.
2019-05-14T16:41:55.373Z,1557852115.373 [IBIT](DEBUG): Uninitialize IBIT Component.
2019-05-14T16:41:55.373Z,1557852115.373 [CBIT](DEBUG): Uninitialize CBIT Component.
2019-05-14T16:41:55.373Z,1557852115.373 [CBIT](DEBUG): Powering off loads.
2019-05-14T16:41:55.385Z,1557852115.385 [CBIT](DEBUG): Disabling WDT.
2019-05-14T16:41:55.397Z,1557852115.397 [CBIT](DEBUG): Opening all GF detection circuits.
2019-05-14T16:41:55.398Z,1557852115.398 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-05-14T16:41:55.440Z,1557852115.440 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-05-14T16:41:55.448Z,1557852115.448 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-05-14T16:41:55.478Z,1557852115.478 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-05-14T16:41:55.481Z,1557852115.481 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2019-05-14T16:41:55.484Z,1557852115.484 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-05-14T16:41:55.520Z,1557852115.520 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-05-14T16:41:55.585Z,1557852115.585 [logger ThreadHandler](INFO): Thread cancelled.