2019-05-01T18:17:43.973Z,1556734663.973 [Supervisor](DEBUG): Initializing supervisor.
2019-05-01T18:17:43.976Z,1556734663.976 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2019-05-01T18:17:43.976Z,1556734663.976 [SyncHandler](INFO): Protected caller Thread ID is 809
2019-05-01T18:17:43.977Z,1556734663.977 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2019-05-01T18:17:43.978Z,1556734663.978 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2019-05-01T18:17:43.978Z,1556734663.978 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 810
2019-05-01T18:17:43.981Z,1556734663.981 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2019-05-01T18:17:43.992Z,1556734663.992 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2019-05-01T18:17:43.993Z,1556734663.993 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2019-05-01T18:17:43.994Z,1556734663.994 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 811
2019-05-01T18:17:43.995Z,1556734663.995 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2019-05-01T18:17:43.996Z,1556734663.996 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2019-05-01T18:17:43.996Z,1556734663.996 [logger ThreadHandler](INFO): Protected caller Thread ID is 812
2019-05-01T18:17:43.998Z,1556734663.998 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2019-05-01T18:17:43.998Z,1556734663.998 [Supervisor](INFO): Looking for Config files in directory: Config/
2019-05-01T18:17:44.003Z,1556734664.003 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2019-05-01T18:17:44.255Z,1556734664.255 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2019-05-01T18:17:44.257Z,1556734664.257 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2019-05-01T18:17:44.339Z,1556734664.339 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2019-05-01T18:17:44.775Z,1556734664.775 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2019-05-01T18:17:44.777Z,1556734664.777 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2019-05-01T18:17:45.114Z,1556734665.114 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2019-05-01T18:17:45.116Z,1556734665.116 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2019-05-01T18:17:45.213Z,1556734665.213 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2019-05-01T18:17:45.214Z,1556734665.214 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2019-05-01T18:17:45.513Z,1556734665.513 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2019-05-01T18:17:45.514Z,1556734665.514 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2019-05-01T18:17:45.711Z,1556734665.711 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2019-05-01T18:17:45.712Z,1556734665.712 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2019-05-01T18:17:46.168Z,1556734666.168 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2019-05-01T18:17:46.168Z,1556734666.168 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2019-05-01T18:17:46.274Z,1556734666.274 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2019-05-01T18:17:46.274Z,1556734666.274 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2019-05-01T18:17:46.375Z,1556734666.375 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2019-05-01T18:17:46.375Z,1556734666.375 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2019-05-01T18:17:46.950Z,1556734666.950 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2019-05-01T18:17:46.951Z,1556734666.951 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2019-05-01T18:17:47.732Z,1556734667.732 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2019-05-01T18:17:47.733Z,1556734667.733 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2019-05-01T18:17:47.929Z,1556734667.929 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2019-05-01T18:17:47.930Z,1556734667.930 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2019-05-01T18:17:48.075Z,1556734668.075 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2019-05-01T18:17:48.076Z,1556734668.076 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2019-05-01T18:17:48.225Z,1556734668.225 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2019-05-01T18:17:48.227Z,1556734668.227 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2019-05-01T18:17:48.229Z,1556734668.229 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2019-05-01T18:17:48.320Z,1556734668.320 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2019-05-01T18:17:48.407Z,1556734668.407 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2019-05-01T18:17:48.509Z,1556734668.509 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2019-05-01T18:17:48.592Z,1556734668.592 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2019-05-01T18:17:48.688Z,1556734668.688 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2019-05-01T18:17:48.788Z,1556734668.788 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2019-05-01T18:17:48.993Z,1556734668.993 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2019-05-01T18:17:49.071Z,1556734669.071 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2019-05-01T18:17:49.242Z,1556734669.242 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2019-05-01T18:17:49.378Z,1556734669.378 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2019-05-01T18:17:49.499Z,1556734669.499 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg
2019-05-01T18:17:49.728Z,1556734669.728 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2019-05-01T18:17:49.729Z,1556734669.729 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2019-05-01T18:17:49.737Z,1556734669.737 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2019-05-01T18:17:49.824Z,1556734669.824 [VerticalControl](DEBUG): Construct VerticalControl.
2019-05-01T18:17:49.936Z,1556734669.936 [VerticalControl] Loaded
2019-05-01T18:17:49.936Z,1556734669.936 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2019-05-01T18:17:49.937Z,1556734669.937 [HorizontalControl](DEBUG): Construct HorizontalControl.
2019-05-01T18:17:50.005Z,1556734670.005 [HorizontalControl] Loaded
2019-05-01T18:17:50.005Z,1556734670.005 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2019-05-01T18:17:50.005Z,1556734670.005 [SpeedControl](DEBUG): Construct SpeedControl.
2019-05-01T18:17:50.011Z,1556734670.011 [SpeedControl] Loaded
2019-05-01T18:17:50.011Z,1556734670.011 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2019-05-01T18:17:50.012Z,1556734670.012 [LoopControl](DEBUG): Construct LoopControl.
2019-05-01T18:17:50.012Z,1556734670.012 [LoopControl] Loaded
2019-05-01T18:17:50.013Z,1556734670.013 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2019-05-01T18:17:50.013Z,1556734670.013 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2019-05-01T18:17:50.015Z,1556734670.015 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2019-05-01T18:17:50.039Z,1556734670.039 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2019-05-01T18:17:50.039Z,1556734670.039 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2019-05-01T18:17:50.164Z,1556734670.164 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2019-05-01T18:17:50.164Z,1556734670.164 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2019-05-01T18:17:50.314Z,1556734670.314 [BuoyancyServo] Loaded
2019-05-01T18:17:50.315Z,1556734670.315 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2019-05-01T18:17:50.326Z,1556734670.326 [ElevatorServo] Loaded
2019-05-01T18:17:50.326Z,1556734670.326 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2019-05-01T18:17:50.337Z,1556734670.337 [MassServo] Loaded
2019-05-01T18:17:50.337Z,1556734670.337 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2019-05-01T18:17:50.348Z,1556734670.348 [RudderServo] Loaded
2019-05-01T18:17:50.348Z,1556734670.348 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2019-05-01T18:17:50.359Z,1556734670.359 [ThrusterServo] Loaded
2019-05-01T18:17:50.360Z,1556734670.360 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2019-05-01T18:17:50.360Z,1556734670.360 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2019-05-01T18:17:50.361Z,1556734670.361 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2019-05-01T18:17:50.485Z,1556734670.485 [DeadReckonUsingMultipleVelocitySources] Loaded
2019-05-01T18:17:50.485Z,1556734670.485 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2019-05-01T18:17:50.505Z,1556734670.505 [NavChart] Loaded
2019-05-01T18:17:50.506Z,1556734670.506 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2019-05-01T18:17:50.509Z,1556734670.509 [UniversalFixResidualReporter] Loaded
2019-05-01T18:17:50.510Z,1556734670.510 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2019-05-01T18:17:50.510Z,1556734670.510 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2019-05-01T18:17:50.511Z,1556734670.511 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2019-05-01T18:17:50.622Z,1556734670.622 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2019-05-01T18:17:50.622Z,1556734670.622 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2019-05-01T18:17:51.438Z,1556734671.438 [AHRS_M2] Loaded
2019-05-01T18:17:51.438Z,1556734671.438 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2019-05-01T18:17:51.810Z,1556734671.810 [DataOverHttps] Loaded
2019-05-01T18:17:51.810Z,1556734671.810 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2019-05-01T18:17:51.811Z,1556734671.811 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4087B4E0
2019-05-01T18:17:51.812Z,1556734671.812 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 895
2019-05-01T18:17:51.825Z,1556734671.825 [Depth_Keller] Loaded
2019-05-01T18:17:51.825Z,1556734671.825 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2019-05-01T18:17:51.830Z,1556734671.830 [DropWeight] Loaded
2019-05-01T18:17:51.830Z,1556734671.830 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2019-05-01T18:17:51.959Z,1556734671.959 [DVL_micro] Loaded
2019-05-01T18:17:51.959Z,1556734671.959 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread.
2019-05-01T18:17:52.055Z,1556734672.055 [NAL9602] Loaded
2019-05-01T18:17:52.056Z,1556734672.056 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2019-05-01T18:17:52.071Z,1556734672.071 [Onboard] Loaded
2019-05-01T18:17:52.072Z,1556734672.072 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2019-05-01T18:17:52.075Z,1556734672.075 [Radio_Surface] Loaded
2019-05-01T18:17:52.075Z,1556734672.075 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2019-05-01T18:17:52.076Z,1556734672.076 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408AB4E0
2019-05-01T18:17:52.077Z,1556734672.077 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 896
2019-05-01T18:17:52.205Z,1556734672.205 [DAT] Loaded
2019-05-01T18:17:52.205Z,1556734672.205 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread.
2019-05-01T18:17:54.170Z,1556734674.170 [BPC1] Loaded
2019-05-01T18:17:54.171Z,1556734674.171 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2019-05-01T18:17:54.171Z,1556734674.171 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2019-05-01T18:17:54.172Z,1556734674.172 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2019-05-01T18:17:54.227Z,1556734674.227 [DepthRateCalculator] Loaded
2019-05-01T18:17:54.227Z,1556734674.227 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2019-05-01T18:17:54.232Z,1556734674.232 [PitchRateCalculator] Loaded
2019-05-01T18:17:54.233Z,1556734674.233 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2019-05-01T18:17:54.244Z,1556734674.244 [SpeedCalculator] Loaded
2019-05-01T18:17:54.244Z,1556734674.244 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2019-05-01T18:17:54.265Z,1556734674.265 [TempGradientCalculator] Loaded
2019-05-01T18:17:54.266Z,1556734674.266 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2019-05-01T18:17:54.271Z,1556734674.271 [YawRateCalculator] Loaded
2019-05-01T18:17:54.271Z,1556734674.271 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2019-05-01T18:17:54.300Z,1556734674.300 [ElevatorOffsetCalculator] Loaded
2019-05-01T18:17:54.301Z,1556734674.301 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2019-05-01T18:17:54.301Z,1556734674.301 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2019-05-01T18:17:54.302Z,1556734674.302 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2019-05-01T18:17:54.623Z,1556734674.623 [CTD_NeilBrown] Loaded
2019-05-01T18:17:54.623Z,1556734674.623 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2019-05-01T18:17:54.624Z,1556734674.624 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 409A54E0
2019-05-01T18:17:54.625Z,1556734674.625 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 897
2019-05-01T18:17:54.634Z,1556734674.634 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density
2019-05-01T18:17:54.639Z,1556734674.639 [CTD_Seabird](INFO): created writer for : sea_water_density
2019-05-01T18:17:54.641Z,1556734674.641 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth
2019-05-01T18:17:54.646Z,1556734674.646 [CTD_Seabird](INFO): created writer for : depth
2019-05-01T18:17:54.646Z,1556734674.646 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure
2019-05-01T18:17:54.651Z,1556734674.651 [CTD_Seabird](INFO): created writer for : sea_water_pressure
2019-05-01T18:17:54.652Z,1556734674.652 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity
2019-05-01T18:17:54.657Z,1556734674.657 [CTD_Seabird](INFO): created writer for : sea_water_salinity
2019-05-01T18:17:54.657Z,1556734674.657 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature
2019-05-01T18:17:54.662Z,1556734674.662 [CTD_Seabird](INFO): created writer for : sea_water_temperature
2019-05-01T18:17:54.663Z,1556734674.663 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity
2019-05-01T18:17:54.668Z,1556734674.668 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity
2019-05-01T18:17:54.668Z,1556734674.668 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water
2019-05-01T18:17:54.673Z,1556734674.673 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water
2019-05-01T18:17:54.700Z,1556734674.700 [CTD_Seabird] Loaded
2019-05-01T18:17:54.701Z,1556734674.701 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2019-05-01T18:17:54.702Z,1556734674.702 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 409D54E0
2019-05-01T18:17:54.702Z,1556734674.702 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 898
2019-05-01T18:17:54.717Z,1556734674.717 [PAR_Licor] Loaded
2019-05-01T18:17:54.717Z,1556734674.717 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2019-05-01T18:17:54.765Z,1556734674.765 [WetLabsBB2FL] Loaded
2019-05-01T18:17:54.765Z,1556734674.765 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2019-05-01T18:17:54.766Z,1556734674.766 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40A054E0
2019-05-01T18:17:54.766Z,1556734674.766 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 899
2019-05-01T18:17:54.767Z,1556734674.767 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2019-05-01T18:17:54.768Z,1556734674.768 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2019-05-01T18:17:54.809Z,1556734674.809 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2019-05-01T18:17:54.809Z,1556734674.809 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2019-05-01T18:17:55.147Z,1556734675.147 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2019-05-01T18:17:55.148Z,1556734675.148 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2019-05-01T18:17:55.306Z,1556734675.306 [SBIT](DEBUG): Construct Startup Built In Test.
2019-05-01T18:17:55.317Z,1556734675.317 [SBIT] Loaded
2019-05-01T18:17:55.317Z,1556734675.317 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2019-05-01T18:17:55.318Z,1556734675.318 [IBIT](DEBUG): Construct Initiated Built In Test.
2019-05-01T18:17:55.330Z,1556734675.330 [IBIT] Loaded
2019-05-01T18:17:55.330Z,1556734675.330 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2019-05-01T18:17:55.333Z,1556734675.333 [CBIT](DEBUG): Construct Continuous Built In Test.
2019-05-01T18:17:55.472Z,1556734675.472 [CBIT] Loaded
2019-05-01T18:17:55.472Z,1556734675.472 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2019-05-01T18:17:55.472Z,1556734675.472 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2019-05-01T18:17:55.476Z,1556734675.476 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2019-05-01T18:17:55.477Z,1556734675.477 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2019-05-01T18:17:55.484Z,1556734675.484 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2019-05-01T18:17:55.485Z,1556734675.485 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B034E0
2019-05-01T18:17:55.485Z,1556734675.485 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 900
2019-05-01T18:17:55.490Z,1556734675.490 [Supervisor](INFO): Main Thread ID is 805
2019-05-01T18:17:55.490Z,1556734675.490 [Supervisor](DEBUG): Running supervisor.
2019-05-01T18:17:55.491Z,1556734675.491 [CommandLine ThreadHandler](INFO): Handler Thread ID is 901
2019-05-01T18:17:55.493Z,1556734675.493 [controlThread ThreadHandler](INFO): Handler Thread ID is 902
2019-05-01T18:17:55.493Z,1556734675.493 [controlThread](DEBUG): Initializing ControlThread
2019-05-01T18:17:55.494Z,1556734675.494 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2019-05-01T18:17:55.496Z,1556734675.496 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2019-05-01T18:17:55.497Z,1556734675.497 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2019-05-01T18:17:55.497Z,1556734675.497 [LoopControl](DEBUG): Initialize LoopControlComponent.
2019-05-01T18:17:55.499Z,1556734675.499 [NavChart](DEBUG): Initialize NavChart Navigation.
2019-05-01T18:17:55.499Z,1556734675.499 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2019-05-01T18:17:55.503Z,1556734675.503 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2019-05-01T18:17:55.504Z,1556734675.504 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2019-05-01T18:17:55.504Z,1556734675.504 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2019-05-01T18:17:55.504Z,1556734675.504 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2019-05-01T18:17:55.505Z,1556734675.505 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2019-05-01T18:17:55.505Z,1556734675.505 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2019-05-01T18:17:55.509Z,1556734675.509 [SBIT](INFO): Initialize SBIT Component.
2019-05-01T18:17:55.510Z,1556734675.510 [SBIT](IMPORTANT): git: 2019-05-01
2019-05-01T18:17:55.510Z,1556734675.510 [SBIT](INFO): git hash: 3bc3661fb14b6835d149c973dfcca2cbbf86477c
2019-05-01T18:17:55.510Z,1556734675.510 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2019-05-01T18:17:55.511Z,1556734675.511 [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-01T18:17:55.512Z,1556734675.512 [SBIT](INFO): Beginning SBIT in 59.000000 seconds.
2019-05-01T18:17:55.513Z,1556734675.513 [IBIT](INFO): Initialize IBIT Component.
2019-05-01T18:17:55.514Z,1556734675.514 [CBIT](DEBUG): Initialize CBIT Component.
2019-05-01T18:17:55.515Z,1556734675.515 [logger ThreadHandler](INFO): Handler Thread ID is 903
2019-05-01T18:17:55.525Z,1556734675.525 [CBIT](DEBUG): Initialized mux pins.
2019-05-01T18:17:55.525Z,1556734675.525 [CBIT](DEBUG): Initializing the watchdog timer.
2019-05-01T18:17:55.533Z,1556734675.533 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 904
2019-05-01T18:17:55.534Z,1556734675.534 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2019-05-01T18:17:55.549Z,1556734675.549 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2019-05-01T18:17:55.549Z,1556734675.549 [CBIT](DEBUG): Initializing heartbeat.
2019-05-01T18:17:55.583Z,1556734675.583 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 905
2019-05-01T18:17:55.589Z,1556734675.589 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 906
2019-05-01T18:17:55.590Z,1556734675.590 [CTD_NeilBrown](INFO): Powering down
2019-05-01T18:17:55.610Z,1556734675.610 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 907
2019-05-01T18:17:55.617Z,1556734675.617 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2019-05-01T18:17:55.621Z,1556734675.621 [CBIT](DEBUG): Deactivating GF circuits.
2019-05-01T18:17:55.621Z,1556734675.621 [CBIT](DEBUG): Deactivating emergency mode.
2019-05-01T18:17:55.625Z,1556734675.625 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 909
2019-05-01T18:17:55.626Z,1556734675.626 [WetLabsBB2FL](INFO): Powering down
2019-05-01T18:17:55.628Z,1556734675.628 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20
2019-05-01T18:17:55.653Z,1556734675.653 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 910
2019-05-01T18:17:55.657Z,1556734675.657 [CBIT](DEBUG): Backplane powered.
2019-05-01T18:17:55.658Z,1556734675.658 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2019-05-01T18:17:55.692Z,1556734675.692 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2019-05-01T18:17:55.703Z,1556734675.703 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2019-05-01T18:17:55.703Z,1556734675.703 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2019-05-01T18:17:55.703Z,1556734675.703 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2019-05-01T18:17:55.704Z,1556734675.704 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2019-05-01T18:17:55.704Z,1556734675.704 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2019-05-01T18:17:55.704Z,1556734675.704 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2019-05-01T18:17:55.704Z,1556734675.704 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2019-05-01T18:17:55.704Z,1556734675.704 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2019-05-01T18:17:55.705Z,1556734675.705 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2019-05-01T18:17:55.705Z,1556734675.705 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2019-05-01T18:17:55.705Z,1556734675.705 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2019-05-01T18:17:55.705Z,1556734675.705 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2019-05-01T18:17:55.706Z,1556734675.706 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2019-05-01T18:17:55.706Z,1556734675.706 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2019-05-01T18:17:55.706Z,1556734675.706 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2019-05-01T18:17:55.706Z,1556734675.706 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2019-05-01T18:17:55.731Z,1556734675.731 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
       Id="Startup">

    <Guidance:GoToSurface>
        <Progression/>
    </Guidance:GoToSurface>

    <Aggregate Id="StartupSatComms">

        <Sequence/>

        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:latitude_fix/>
        </ReadDatum>

        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:platform_communications/>
        </ReadDatum>

    </Aggregate>

</Mission>


2019-05-01T18:17:55.732Z,1556734675.732 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2019-05-01T18:17:55.793Z,1556734675.793 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2019-05-01T18:17:55.794Z,1556734675.794 [Default:A.Wait](DEBUG): Construct Wait.
2019-05-01T18:17:55.796Z,1556734675.796 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2019-05-01T18:17:55.827Z,1556734675.827 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2019-05-01T18:17:55.845Z,1556734675.845 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2019-05-01T18:17:55.851Z,1556734675.851 [Default:E.Execute](DEBUG): Construct Execute.
2019-05-01T18:17:55.870Z,1556734675.870 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Universal="Tethys/Universal"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
         Id="Default">

    <DefineArg Name="ElapsedSinceDefaultStarted"><Units:minute/><Value>0</Value></DefineArg>

    <Guidance:Wait>
        <Description>
            Wait a moment to see if the scheduler starts a new mission before
            starting to actually run Default.
        </Description>
        <Sequence/>
        <Setting><Guidance:Wait.duration/><Units:second/><Value>13</Value></Setting>
    </Guidance:Wait>

    <Guidance:GoToSurface>
        <Progression/>
    </Guidance:GoToSurface>

    <Aggregate Id="CheckIn">

        <Sequence Repeat="288"/>

        <ReadDatum Id="Read_GPS">
            <Timeout Duration="P5M"/>
            <Universal:time_fix/>
        </ReadDatum>

        <ReadDatum Id="Read_Iridium">
            <Timeout Duration="P2H">
                <Guidance:Execute>
                    <Sequence/>
                    <Setting><Guidance:Execute.command/><String>Burn on</String></Setting>
                </Guidance:Execute>
                <Syslog Severity="Critical">Dropped weight due to communications timeout.</Syslog>
            </Timeout>
            <Universal:platform_communications/>
        </ReadDatum>

        <Guidance:Wait>
            <Sequence/>
            <Setting><Guidance:Wait.duration/><Units:minute/><Value>5</Value></Setting>
        </Guidance:Wait>

        <Assign><Sequence/><Arg Name="ElapsedSinceDefaultStarted"/><Elapsed><Universal:mission_started/></Elapsed></Assign>

        <Syslog Severity="Important">Default mission has been running for <Arg Name="ElapsedSinceDefaultStarted"/><Units:minute/></Syslog>

    </Aggregate>

    <Syslog Severity="Important">Restarting logs and Default mission.</Syslog>

    <Guidance:Execute>
        <Sequence/>
        <Setting><Guidance:Execute.command/><String>restart logs</String></Setting>
    </Guidance:Execute>

</Mission>


2019-05-01T18:17:55.875Z,1556734675.875 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,DVL_micro,NAL9602,Onboard,DAT,BPC1,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-01T18:17:55.889Z,1556734675.889 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2019-05-01T18:17:55.985Z,1556734675.985 [Radio_Surface](INFO): Powering up
2019-05-01T18:17:56.050Z,1556734676.050 [DVL_micro](INFO): Initializing
2019-05-01T18:17:56.075Z,1556734676.075 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2019-05-01T18:17:56.075Z,1556734676.075 [DAT](INFO): Powering up
2019-05-01T18:17:56.075Z,1556734676.075 [DAT](DEBUG): Initializing DAT.
2019-05-01T18:17:56.096Z,1556734676.096 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2019-05-01T18:17:56.262Z,1556734676.262 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2019-05-01T18:17:56.269Z,1556734676.269 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2019-05-01T18:17:56.271Z,1556734676.271 [ElevatorServo](DEBUG): Initializing EZServoServo.
2019-05-01T18:17:56.277Z,1556734676.277 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2019-05-01T18:17:56.278Z,1556734676.278 [MassServo](DEBUG): Initializing EZServoServo.
2019-05-01T18:17:56.285Z,1556734676.285 [MassServo](DEBUG): Initializing MassServo.
2019-05-01T18:17:56.286Z,1556734676.286 [RudderServo](DEBUG): Initializing EZServoServo.
2019-05-01T18:17:56.293Z,1556734676.293 [RudderServo](DEBUG): Initializing RudderServo.
2019-05-01T18:17:56.294Z,1556734676.294 [ThrusterServo](DEBUG): Initializing EZServoServo.
2019-05-01T18:17:56.301Z,1556734676.301 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2019-05-01T18:18:06.822Z,1556734686.822 [DVL_micro](ERROR): No DVL communication! Re-initializing
2019-05-01T18:18:06.822Z,1556734686.822 [DVL_micro] Communications Fault, FailCount= 1
2019-05-01T18:18:06.822Z,1556734686.822 [DVL_micro](ERROR): Communications Fault
2019-05-01T18:18:06.929Z,1556734686.929 [CBIT](ERROR): Communications Fault in component: DVL_micro
2019-05-01T18:18:07.297Z,1556734687.297 [DVL_micro](INFO): uninitialize:Powering down
2019-05-01T18:18:08.137Z,1556734688.137 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-05-01T18:18:08.137Z,1556734688.137 [DVL_micro] No Fault, FailCount= 1
2019-05-01T18:18:08.445Z,1556734688.445 [DVL_micro](INFO): Initializing
2019-05-01T18:18:09.665Z,1556734689.665 [DAT](INFO): setting local address to 2
2019-05-01T18:18:10.074Z,1556734690.074 [DAT](INFO): set local address to 2
2019-05-01T18:18:22.175Z,1556734702.175 [NAL9602](INFO): Powering up NAL9602
2019-05-01T18:18:33.083Z,1556734713.083 [NAL9602](INFO): NAL9602 initialized
2019-05-01T18:18:33.905Z,1556734713.905 [NAL9602](DEBUG): Fix Requested
2019-05-01T18:18:54.929Z,1556734734.929 [SBIT](IMPORTANT): Beginning Startup BIT
2019-05-01T18:18:54.933Z,1556734734.933 [CBIT](IMPORTANT): Beginning ground fault scan
2019-05-01T18:19:06.024Z,1556734746.024 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.005628
CHAN A1 (24V): -0.017263
CHAN A2 (12V): -0.002618
CHAN A3 (5V): -0.001790
CHAN B0 (3.3V): -0.000187
CHAN B1 (3.15aV): -0.000134
CHAN B2 (3.15bV): -0.000046
CHAN B3 (GND): -0.000250
OPEN: -0.000421
Full Scale Calc: 4.765 mA, -1.589 mA
2019-05-01T18:19:48.480Z,1556734788.480 [SBIT](IMPORTANT): SBIT PASSED
2019-05-01T18:19:48.533Z,1556734788.533 [CommandLine](IMPORTANT): got command configSet list
2019-05-01T18:19:48.533Z,1556734788.533 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2019-05-01T18:19:48.536Z,1556734788.536 [CommandLine](IMPORTANT): Aanderaa_O2.loadAtStartup=0 bool;

2019-05-01T18:19:48.538Z,1556734788.538 [CommandLine](IMPORTANT): CBIT.gf24Offset=172 microampere;

2019-05-01T18:19:48.539Z,1556734788.539 [CommandLine](IMPORTANT): Express linearApproximation DVL_micro.height_above_sea_floor 2.000000 meter;

2019-05-01T18:19:48.540Z,1556734788.540 [CommandLine](IMPORTANT): VerticalControl.massDefault=1 centimeter;

2019-05-01T18:19:48.889Z,1556734788.889 [MissionManager](IMPORTANT): Started mission Startup
2019-05-01T18:19:48.889Z,1556734788.889 [Startup] Running Loop=1
2019-05-01T18:19:48.889Z,1556734788.889 [Startup](DEBUG): Aggregate::initialize Startup
2019-05-01T18:19:48.889Z,1556734788.889 [Startup:A.GoToSurface] Running Loop=1
2019-05-01T18:19:48.889Z,1556734788.889 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-05-01T18:19:48.890Z,1556734788.890 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-05-01T18:19:48.890Z,1556734788.890 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-05-01T18:19:48.891Z,1556734788.891 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-05-01T18:19:48.891Z,1556734788.891 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-05-01T18:19:48.892Z,1556734788.892 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-05-01T18:19:48.893Z,1556734788.893 [Startup:StartupSatComms] Running Loop=1
2019-05-01T18:19:48.893Z,1556734788.893 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2019-05-01T18:19:48.893Z,1556734788.893 [Startup:StartupSatComms:A] Running Loop=1
2019-05-01T18:19:49.291Z,1556734789.291 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2019-05-01T18:19:53.696Z,1556734793.696 [NAL9602](INFO): SBD MO Status=2, MOMSN=11649, MT Status=2, MTMSN=0
2019-05-01T18:19:53.696Z,1556734793.696 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-05-01T18:20:49.090Z,1556734849.090 [Startup:StartupSatComms:A](INFO): Timed out from 2019-05-01T18:19:48.9Z
2019-05-01T18:20:49.090Z,1556734849.090 [Startup:StartupSatComms:A] Stopped
2019-05-01T18:20:49.091Z,1556734849.091 [Startup:StartupSatComms:B] Running Loop=1
2019-05-01T18:20:49.476Z,1556734849.476 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-05-01T18:20:55.541Z,1556734855.541 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2019-05-01T18:20:55.541Z,1556734855.541 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-05-01T18:20:55.551Z,1556734855.551 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-05-01T18:20:55.955Z,1556734855.955 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-05-01T18:20:55.956Z,1556734855.956 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2019-05-01T18:21:12.878Z,1556734872.878 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-05-01T18:21:12.878Z,1556734872.878 [DVL_micro] Data Fault, FailCount= 1
2019-05-01T18:21:12.878Z,1556734872.878 [DVL_micro](ERROR): Data Fault
2019-05-01T18:21:12.944Z,1556734872.944 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-05-01T18:21:13.349Z,1556734873.349 [DVL_micro](INFO): uninitialize:Powering down
2019-05-01T18:21:14.144Z,1556734874.144 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-05-01T18:21:14.144Z,1556734874.144 [DVL_micro] No Fault, FailCount= 1
2019-05-01T18:21:14.523Z,1556734874.523 [DVL_micro](INFO): Initializing
2019-05-01T18:21:42.523Z,1556734902.523 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004799
2019-05-01T18:21:49.399Z,1556734909.399 [Startup:StartupSatComms:B](INFO): Timed out from 2019-05-01T18:20:49.1Z
2019-05-01T18:21:49.400Z,1556734909.400 [Startup:StartupSatComms:B] Stopped
2019-05-01T18:21:49.400Z,1556734909.400 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2019-05-01T18:21:49.400Z,1556734909.400 [Startup:StartupSatComms] Stopped
2019-05-01T18:21:49.400Z,1556734909.400 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2019-05-01T18:21:49.405Z,1556734909.405 [Startup](INFO): Completed Startup
2019-05-01T18:21:49.405Z,1556734909.405 [MissionManager](INFO): Startup is completed.
2019-05-01T18:21:49.405Z,1556734909.405 [MissionManager](INFO): Uninitializing Mission Startup
2019-05-01T18:21:49.405Z,1556734909.405 [Startup] Stopped
2019-05-01T18:21:49.405Z,1556734909.405 [Startup](DEBUG): Aggregate::uninitialize Startup
2019-05-01T18:21:49.405Z,1556734909.405 [Startup:A.GoToSurface] Stopped
2019-05-01T18:21:49.406Z,1556734909.406 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-05-01T18:21:49.754Z,1556734909.754 [MissionManager](IMPORTANT): Started mission Default
2019-05-01T18:21:49.754Z,1556734909.754 [Default] Running Loop=1
2019-05-01T18:21:49.754Z,1556734909.754 [Default](DEBUG): Aggregate::initialize Default
2019-05-01T18:21:49.754Z,1556734909.754 [Default:B.GoToSurface] Running Loop=1
2019-05-01T18:21:49.754Z,1556734909.754 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-05-01T18:21:49.755Z,1556734909.755 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-05-01T18:21:49.756Z,1556734909.756 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-05-01T18:21:49.766Z,1556734909.766 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-05-01T18:21:49.767Z,1556734909.767 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-05-01T18:21:49.777Z,1556734909.777 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-05-01T18:21:49.777Z,1556734909.777 [Default:A.Wait] Running Loop=1
2019-05-01T18:21:49.777Z,1556734909.777 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-05-01T18:21:50.264Z,1556734910.264 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20190501T162158/Courier0028.lzma
2019-05-01T18:21:51.070Z,1556734911.070 [DataOverHttps](INFO): Moved sent file to Logs/20190501T162158/Courier0028.lzma.bak
2019-05-01T18:21:51.070Z,1556734911.070 [DataOverHttps](INFO): SBD MOMSN=10890476
2019-05-01T18:22:03.071Z,1556734923.071 [Default:A.Wait](INFO): Done Waiting.
2019-05-01T18:22:03.071Z,1556734923.071 [Default:A.Wait] Stopped
2019-05-01T18:22:03.071Z,1556734923.071 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-05-01T18:22:03.463Z,1556734923.463 [Default:CheckIn] Running Loop=1
2019-05-01T18:22:03.463Z,1556734923.463 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-05-01T18:22:03.463Z,1556734923.463 [Default:CheckIn:Read_GPS] Running Loop=1
2019-05-01T18:22:03.847Z,1556734923.847 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2019-05-01T18:23:36.383Z,1556735016.383 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-05-01T18:23:37.205Z,1556735017.205 [NAL9602](DEBUG): Fix Requested
2019-05-01T18:23:40.061Z,1556735020.061 [NAL9602](DEBUG): Fix Requested
2019-05-01T18:23:42.861Z,1556735022.861 [NAL9602](DEBUG): Fix Requested
2019-05-01T18:23:46.093Z,1556735026.093 [NAL9602](DEBUG): Fix Requested
2019-05-01T18:23:48.921Z,1556735028.921 [NAL9602](DEBUG): Fix Requested
2019-05-01T18:23:51.749Z,1556735031.749 [NAL9602](DEBUG): Fix Requested
2019-05-01T18:23:54.981Z,1556735034.981 [NAL9602](DEBUG): Fix Requested
2019-05-01T18:23:56.639Z,1556735036.639 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2019-05-01T18:23:56.639Z,1556735036.639 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-05-01T18:23:56.649Z,1556735036.649 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-05-01T18:23:57.036Z,1556735037.036 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-05-01T18:23:57.036Z,1556735037.036 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2019-05-01T18:23:57.813Z,1556735037.813 [NAL9602](DEBUG): Fix Requested
2019-05-01T18:24:01.041Z,1556735041.041 [NAL9602](DEBUG): Fix Requested
2019-05-01T18:24:03.893Z,1556735043.893 [NAL9602](DEBUG): Fix Requested
2019-05-01T18:24:07.101Z,1556735047.101 [NAL9602](DEBUG): Fix Requested
2019-05-01T18:24:09.936Z,1556735049.936 [NAL9602](DEBUG): Fix Requested
2019-05-01T18:24:13.165Z,1556735053.165 [NAL9602](DEBUG): Fix Requested
2019-05-01T18:24:15.997Z,1556735055.997 [NAL9602](DEBUG): Fix Requested
2019-05-01T18:24:18.802Z,1556735058.802 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-05-01T18:24:18.802Z,1556735058.802 [DVL_micro] Data Fault, FailCount= 1
2019-05-01T18:24:18.803Z,1556735058.803 [DVL_micro](ERROR): Data Fault
2019-05-01T18:24:18.840Z,1556735058.840 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-05-01T18:24:19.277Z,1556735059.277 [DVL_micro](INFO): uninitialize:Powering down
2019-05-01T18:24:19.289Z,1556735059.289 [NAL9602](DEBUG): Fix Requested
2019-05-01T18:24:20.071Z,1556735060.071 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-05-01T18:24:20.071Z,1556735060.071 [DVL_micro] No Fault, FailCount= 1
2019-05-01T18:24:20.424Z,1556735060.424 [DVL_micro](INFO): Initializing
2019-05-01T18:24:22.049Z,1556735062.049 [NAL9602](DEBUG): Fix Requested
2019-05-01T18:24:25.281Z,1556735065.281 [NAL9602](DEBUG): Fix Requested
2019-05-01T18:24:28.113Z,1556735068.113 [NAL9602](DEBUG): Fix Requested
2019-05-01T18:24:30.945Z,1556735070.945 [NAL9602](DEBUG): Fix Requested
2019-05-01T18:24:34.173Z,1556735074.173 [NAL9602](DEBUG): Fix Requested
2019-05-01T18:24:37.005Z,1556735077.005 [NAL9602](DEBUG): Fix Requested
2019-05-01T18:24:37.393Z,1556735077.393 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182436.00,A,3648.16606,N,12147.27833,W,0.097,12.38,010519,,,A*4E
2019-05-01T18:24:37.396Z,1556735077.396 [NAL9602](INFO): GPS fix at 20190501T182436: (36.802768, -121.787972)
2019-05-01T18:24:37.470Z,1556735077.470 [Default:CheckIn:Read_GPS] Stopped
2019-05-01T18:24:37.470Z,1556735077.470 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-05-01T18:24:37.882Z,1556735077.882 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-05-01T18:24:42.479Z,1556735082.479 [CommandLine](IMPORTANT): got command failComponent
2019-05-01T18:24:42.479Z,1556735082.479 [CommandLine](IMPORTANT): Failed components:
2019-05-01T18:24:42.479Z,1556735082.479 [CommandLine](IMPORTANT): No failed Components.
2019-05-01T18:24:47.545Z,1556735087.545 [DataOverHttps](INFO): Sending 211 bytes from file Logs/20190501T181743/Courier0004.lzma
2019-05-01T18:24:48.350Z,1556735088.350 [DataOverHttps](INFO): Moved sent file to Logs/20190501T181743/Courier0004.lzma.bak
2019-05-01T18:24:48.350Z,1556735088.350 [DataOverHttps](INFO): SBD MOMSN=10890566
2019-05-01T18:25:03.145Z,1556735103.145 [DataOverHttps](INFO): Sending 2696 bytes from file Logs/20190501T162158/Express0029.lzma
2019-05-01T18:25:03.946Z,1556735103.946 [DataOverHttps](INFO): Moved sent file to Logs/20190501T162158/Express0029.lzma.bak
2019-05-01T18:25:03.946Z,1556735103.946 [DataOverHttps](INFO): SBD MOMSN=10890570
2019-05-01T18:25:10.134Z,1556735110.134 [NAL9602](INFO): Powering down
2019-05-01T18:25:17.467Z,1556735117.467 [DataOverHttps](INFO): Sending 788 bytes from file Logs/20190501T181322/Express0001.lzma
2019-05-01T18:25:18.270Z,1556735118.270 [DataOverHttps](INFO): Moved sent file to Logs/20190501T181322/Express0001.lzma.bak
2019-05-01T18:25:18.270Z,1556735118.270 [DataOverHttps](INFO): SBD MOMSN=10890676
2019-05-01T18:25:31.434Z,1556735131.434 [DataOverHttps](INFO): Sending 774 bytes from file Logs/20190501T181743/Express0001.lzma
2019-05-01T18:25:32.238Z,1556735132.238 [DataOverHttps](INFO): Moved sent file to Logs/20190501T181743/Express0001.lzma.bak
2019-05-01T18:25:32.238Z,1556735132.238 [DataOverHttps](INFO): SBD MOMSN=10890696
2019-05-01T18:25:46.353Z,1556735146.353 [DataOverHttps](INFO): Sending 360 bytes from file Logs/20190501T181743/Express0005.lzma
2019-05-01T18:25:47.158Z,1556735147.158 [DataOverHttps](INFO): Moved sent file to Logs/20190501T181743/Express0005.lzma.bak
2019-05-01T18:25:47.158Z,1556735147.158 [DataOverHttps](INFO): SBD MOMSN=10890713
2019-05-01T18:25:49.475Z,1556735149.475 [Default:CheckIn:Read_Iridium] Stopped
2019-05-01T18:25:49.475Z,1556735149.475 [Default:CheckIn:C.Wait] Running Loop=1
2019-05-01T18:25:49.476Z,1556735149.476 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-05-01T18:27:24.647Z,1556735244.647 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-05-01T18:27:24.647Z,1556735244.647 [DVL_micro] Data Fault, FailCount= 1
2019-05-01T18:27:24.648Z,1556735244.648 [DVL_micro](ERROR): Data Fault
2019-05-01T18:27:24.706Z,1556735244.706 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-05-01T18:27:25.129Z,1556735245.129 [DVL_micro](INFO): uninitialize:Powering down
2019-05-01T18:27:25.892Z,1556735245.892 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-05-01T18:27:25.892Z,1556735245.892 [DVL_micro] No Fault, FailCount= 1
2019-05-01T18:27:26.272Z,1556735246.272 [DVL_micro](INFO): Initializing
2019-05-01T18:30:30.494Z,1556735430.494 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-05-01T18:30:30.494Z,1556735430.494 [DVL_micro] Data Fault, FailCount= 1
2019-05-01T18:30:30.494Z,1556735430.494 [DVL_micro](ERROR): Data Fault
2019-05-01T18:30:30.543Z,1556735430.543 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-05-01T18:30:30.973Z,1556735430.973 [DVL_micro](INFO): uninitialize:Powering down
2019-05-01T18:30:31.775Z,1556735431.775 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-05-01T18:30:31.775Z,1556735431.775 [DVL_micro] No Fault, FailCount= 1
2019-05-01T18:30:32.120Z,1556735432.120 [DVL_micro](INFO): Initializing
2019-05-01T18:30:49.913Z,1556735449.913 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-05-01T18:30:49.913Z,1556735449.913 [Default:CheckIn:C.Wait] Stopped
2019-05-01T18:30:49.914Z,1556735449.914 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-01T18:30:49.914Z,1556735449.914 [Default:CheckIn:D] Running Loop=1
2019-05-01T18:30:50.325Z,1556735450.325 [Default:CheckIn:D] Stopped
2019-05-01T18:30:50.325Z,1556735450.325 [Default:CheckIn:E] Running Loop=1
2019-05-01T18:30:50.722Z,1556735450.722 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 9.009512 min 
2019-05-01T18:30:50.722Z,1556735450.722 [Default:CheckIn:E] Stopped
2019-05-01T18:30:50.722Z,1556735450.722 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-05-01T18:30:50.722Z,1556735450.722 [Default:CheckIn] Stopped
2019-05-01T18:30:50.722Z,1556735450.722 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-05-01T18:30:50.723Z,1556735450.723 [Default:CheckIn](INFO): Running loop #2
2019-05-01T18:30:50.723Z,1556735450.723 [Default:CheckIn] Running Loop=2
2019-05-01T18:30:50.723Z,1556735450.723 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-05-01T18:30:50.723Z,1556735450.723 [Default:CheckIn:Read_GPS] Running Loop=1
2019-05-01T18:30:51.527Z,1556735451.527 [NAL9602](INFO): Powering up
2019-05-01T18:31:02.411Z,1556735462.411 [NAL9602](INFO): NAL9602 initialized
2019-05-01T18:31:03.233Z,1556735463.233 [NAL9602](DEBUG): Fix Requested
2019-05-01T18:31:34.326Z,1556735494.326 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2019-05-01T18:31:34.409Z,1556735494.409 [NAL9602](FAULT): received: 
+CSQ:0

OK649, 2, 0, 0, 0

OK
2019-05-01T18:31:34.409Z,1556735494.409 [NAL9602] Data Fault, FailCount= 1
2019-05-01T18:31:34.410Z,1556735494.410 [NAL9602](ERROR): Data Fault
2019-05-01T18:31:34.450Z,1556735494.450 [CBIT](ERROR): Data Fault in component: NAL9602
2019-05-01T18:31:34.731Z,1556735494.731 [NAL9602](INFO): Powering down
2019-05-01T18:31:35.595Z,1556735495.595 [CBIT](INFO): Clearing failed state for component NAL9602
2019-05-01T18:31:35.595Z,1556735495.595 [NAL9602] No Fault, FailCount= 1
2019-05-01T18:32:05.031Z,1556735525.031 [NAL9602](INFO): Powering up NAL9602
2019-05-01T18:32:15.945Z,1556735535.945 [NAL9602](INFO): NAL9602 initialized
2019-05-01T18:32:16.765Z,1556735536.765 [NAL9602](DEBUG): Fix Requested
2019-05-01T18:32:34.949Z,1556735554.949 [NAL9602](INFO): SBD MO Status=0, MOMSN=11649, MT Status=0, MTMSN=0
2019-05-01T18:32:34.950Z,1556735554.950 [NAL9602](INFO): No messages in MT queue
2019-05-01T18:32:35.757Z,1556735555.757 [NAL9602](DEBUG): Fix Requested
2019-05-01T18:32:36.140Z,1556735556.140 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183233.00,A,3648.14233,N,12147.23006,W,0.447,0.00,010519,,,A*77
2019-05-01T18:32:36.143Z,1556735556.143 [NAL9602](INFO): GPS fix at 20190501T183233: (36.802372, -121.787168)
2019-05-01T18:32:36.197Z,1556735556.197 [Default:CheckIn:Read_GPS] Stopped
2019-05-01T18:32:36.197Z,1556735556.197 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-05-01T18:32:43.188Z,1556735563.188 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20190501T181743/Courier0007.lzma
2019-05-01T18:32:43.994Z,1556735563.994 [DataOverHttps](INFO): Moved sent file to Logs/20190501T181743/Courier0007.lzma.bak
2019-05-01T18:32:43.994Z,1556735563.994 [DataOverHttps](INFO): SBD MOMSN=10890817
2019-05-01T18:32:58.053Z,1556735578.053 [DataOverHttps](INFO): Sending 322 bytes from file Logs/20190501T181743/Express0008.lzma
2019-05-01T18:32:58.858Z,1556735578.858 [DataOverHttps](INFO): Moved sent file to Logs/20190501T181743/Express0008.lzma.bak
2019-05-01T18:32:58.859Z,1556735578.859 [DataOverHttps](INFO): SBD MOMSN=10890820
2019-05-01T18:33:01.220Z,1556735581.220 [Default:CheckIn:Read_Iridium] Stopped
2019-05-01T18:33:01.220Z,1556735581.220 [Default:CheckIn:C.Wait] Running Loop=1
2019-05-01T18:33:01.220Z,1556735581.220 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-05-01T18:33:08.866Z,1556735588.866 [NAL9602](INFO): Powering down
2019-05-01T18:33:20.191Z,1556735600.191 [DVL_micro](ERROR): only read 17 of 46 data items
2019-05-01T18:33:20.192Z,1556735600.192 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 0 0 0 0 -733 -604 -89 74
2019-05-01T18:33:36.334Z,1556735616.334 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-05-01T18:33:36.334Z,1556735616.334 [DVL_micro] Data Fault, FailCount= 1
2019-05-01T18:33:36.334Z,1556735616.334 [DVL_micro](ERROR): Data Fault
2019-05-01T18:33:36.369Z,1556735616.369 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-05-01T18:33:36.809Z,1556735616.809 [DVL_micro](INFO): uninitialize:Powering down
2019-05-01T18:33:37.611Z,1556735617.611 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-05-01T18:33:37.611Z,1556735617.611 [DVL_micro] No Fault, FailCount= 1
2019-05-01T18:33:37.954Z,1556735617.954 [DVL_micro](INFO): Initializing
2019-05-01T18:36:42.174Z,1556735802.174 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-05-01T18:36:42.174Z,1556735802.174 [DVL_micro] Data Fault, FailCount= 1
2019-05-01T18:36:42.174Z,1556735802.174 [DVL_micro](ERROR): Data Fault
2019-05-01T18:36:42.358Z,1556735802.358 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-05-01T18:36:42.649Z,1556735802.649 [DVL_micro](INFO): uninitialize:Powering down
2019-05-01T18:36:43.462Z,1556735803.462 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-05-01T18:36:43.462Z,1556735803.462 [DVL_micro] No Fault, FailCount= 1
2019-05-01T18:36:43.796Z,1556735803.796 [DVL_micro](INFO): Initializing
2019-05-01T18:38:01.806Z,1556735881.806 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-05-01T18:38:01.807Z,1556735881.807 [Default:CheckIn:C.Wait] Stopped
2019-05-01T18:38:01.807Z,1556735881.807 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-01T18:38:01.807Z,1556735881.807 [Default:CheckIn:D] Running Loop=1
2019-05-01T18:38:02.208Z,1556735882.208 [Default:CheckIn:D] Stopped
2019-05-01T18:38:02.208Z,1556735882.208 [Default:CheckIn:E] Running Loop=1
2019-05-01T18:38:02.621Z,1556735882.621 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 16.207561 min 
2019-05-01T18:38:02.621Z,1556735882.621 [Default:CheckIn:E] Stopped
2019-05-01T18:38:02.622Z,1556735882.622 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-05-01T18:38:02.622Z,1556735882.622 [Default:CheckIn] Stopped
2019-05-01T18:38:02.622Z,1556735882.622 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-05-01T18:38:02.622Z,1556735882.622 [Default:CheckIn](INFO): Running loop #3
2019-05-01T18:38:02.622Z,1556735882.622 [Default:CheckIn] Running Loop=3
2019-05-01T18:38:02.622Z,1556735882.622 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-05-01T18:38:02.622Z,1556735882.622 [Default:CheckIn:Read_GPS] Running Loop=1
2019-05-01T18:38:03.376Z,1556735883.376 [NAL9602](INFO): Powering up
2019-05-01T18:38:14.323Z,1556735894.323 [NAL9602](INFO): NAL9602 initialized
2019-05-01T18:38:15.109Z,1556735895.109 [NAL9602](DEBUG): Fix Requested
2019-05-01T18:39:11.662Z,1556735951.662 [NAL9602](INFO): SBD MO Status=2, MOMSN=11650, MT Status=2, MTMSN=0
2019-05-01T18:39:11.662Z,1556735951.662 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-05-01T18:39:48.018Z,1556735988.018 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-05-01T18:39:48.018Z,1556735988.018 [DVL_micro] Data Fault, FailCount= 1
2019-05-01T18:39:48.018Z,1556735988.018 [DVL_micro](ERROR): Data Fault
2019-05-01T18:39:48.077Z,1556735988.077 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-05-01T18:39:48.493Z,1556735988.493 [DVL_micro](INFO): uninitialize:Powering down
2019-05-01T18:39:49.339Z,1556735989.339 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-05-01T18:39:49.339Z,1556735989.339 [DVL_micro] No Fault, FailCount= 1
2019-05-01T18:39:49.640Z,1556735989.640 [DVL_micro](INFO): Initializing
2019-05-01T18:39:52.457Z,1556735992.457 [NAL9602](INFO): SBD MO Status=2, MOMSN=11650, MT Status=2, MTMSN=0
2019-05-01T18:39:52.457Z,1556735992.457 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-05-01T18:40:14.688Z,1556736014.688 [NAL9602](INFO): SBD MO Status=0, MOMSN=11650, MT Status=0, MTMSN=0
2019-05-01T18:40:14.688Z,1556736014.688 [NAL9602](INFO): No messages in MT queue
2019-05-01T18:40:15.565Z,1556736015.565 [NAL9602](DEBUG): Fix Requested
2019-05-01T18:40:15.898Z,1556736015.898 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184012.00,A,3648.15615,N,12147.21816,W,0.039,0.00,010519,,,A*76
2019-05-01T18:40:15.900Z,1556736015.900 [NAL9602](INFO): GPS fix at 20190501T184012: (36.802602, -121.786969)
2019-05-01T18:40:15.957Z,1556736015.957 [Default:CheckIn:Read_GPS] Stopped
2019-05-01T18:40:15.958Z,1556736015.958 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-05-01T18:40:17.657Z,1556736017.657 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20190501T181743/Courier0010.lzma
2019-05-01T18:40:18.466Z,1556736018.466 [DataOverHttps](INFO): Moved sent file to Logs/20190501T181743/Courier0010.lzma.bak
2019-05-01T18:40:18.466Z,1556736018.466 [DataOverHttps](INFO): SBD MOMSN=10890958
2019-05-01T18:40:33.648Z,1556736033.648 [DataOverHttps](INFO): Sending 200 bytes from file Logs/20190501T181743/Express0011.lzma
2019-05-01T18:40:34.454Z,1556736034.454 [DataOverHttps](INFO): Moved sent file to Logs/20190501T181743/Express0011.lzma.bak
2019-05-01T18:40:34.454Z,1556736034.454 [DataOverHttps](INFO): SBD MOMSN=10890961
2019-05-01T18:40:37.058Z,1556736037.058 [Default:CheckIn:Read_Iridium] Stopped
2019-05-01T18:40:37.058Z,1556736037.058 [Default:CheckIn:C.Wait] Running Loop=1
2019-05-01T18:40:37.058Z,1556736037.058 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-05-01T18:40:48.627Z,1556736048.627 [NAL9602](INFO): Powering down
2019-05-01T18:42:53.862Z,1556736173.862 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-05-01T18:42:53.862Z,1556736173.862 [DVL_micro] Data Fault, FailCount= 1
2019-05-01T18:42:53.862Z,1556736173.862 [DVL_micro](ERROR): Data Fault
2019-05-01T18:42:53.896Z,1556736173.896 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-05-01T18:42:54.337Z,1556736174.337 [DVL_micro](INFO): uninitialize:Powering down
2019-05-01T18:42:55.167Z,1556736175.167 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-05-01T18:42:55.168Z,1556736175.168 [DVL_micro] No Fault, FailCount= 1
2019-05-01T18:42:55.480Z,1556736175.480 [DVL_micro](INFO): Initializing
2019-05-01T18:43:52.006Z,1556736232.006 [DataOverHttps](IMPORTANT): SBD MTMSN=20190501T184348
2019-05-01T18:43:57.413Z,1556736237.413 [DataOverHttps](INFO): Received command:ibit
2019-05-01T18:43:57.489Z,1556736237.489 [CommandLine](IMPORTANT): got command ibit
2019-05-01T18:43:57.743Z,1556736237.743 [IBIT](IMPORTANT): Beginning Initiated BIT
2019-05-01T18:43:57.743Z,1556736237.743 [IBIT](IMPORTANT): Beginning control surface checks.
2019-05-01T18:43:57.746Z,1556736237.746 [CBIT](IMPORTANT): Beginning ground fault scan
2019-05-01T18:43:58.098Z,1556736238.098 [NAL9602](INFO): Powering up
2019-05-01T18:44:08.689Z,1556736248.689 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.006280
CHAN A1 (24V): -0.017660
CHAN A2 (12V): -0.002504
CHAN A3 (5V): -0.001313
CHAN B0 (3.3V): 0.000101
CHAN B1 (3.15aV): -0.000301
CHAN B2 (3.15bV): -0.000649
CHAN B3 (GND): 0.000224
OPEN: -0.000115
Full Scale Calc: 4.765 mA, -1.589 mA
2019-05-01T18:44:09.003Z,1556736249.003 [NAL9602](INFO): NAL9602 initialized
2019-05-01T18:44:09.845Z,1556736249.845 [NAL9602](DEBUG): Fix Requested
2019-05-01T18:44:25.576Z,1556736265.576 [NAL9602](INFO): SBD MO Status=0, MOMSN=11651, MT Status=0, MTMSN=0
2019-05-01T18:44:25.576Z,1556736265.576 [NAL9602](INFO): No messages in MT queue
2019-05-01T18:44:26.453Z,1556736266.453 [NAL9602](DEBUG): Fix Requested
2019-05-01T18:44:28.813Z,1556736268.813 [NAL9602](DEBUG): Fix Requested
2019-05-01T18:44:32.041Z,1556736272.041 [NAL9602](DEBUG): Fix Requested
2019-05-01T18:44:34.873Z,1556736274.873 [NAL9602](DEBUG): Fix Requested
2019-05-01T18:44:38.109Z,1556736278.109 [NAL9602](DEBUG): Fix Requested
2019-05-01T18:44:40.937Z,1556736280.937 [NAL9602](DEBUG): Fix Requested
2019-05-01T18:44:44.169Z,1556736284.169 [NAL9602](DEBUG): Fix Requested
2019-05-01T18:44:46.997Z,1556736286.997 [NAL9602](DEBUG): Fix Requested
2019-05-01T18:44:50.229Z,1556736290.229 [NAL9602](DEBUG): Fix Requested
2019-05-01T18:44:53.056Z,1556736293.056 [NAL9602](DEBUG): Fix Requested
2019-05-01T18:44:55.877Z,1556736295.877 [NAL9602](DEBUG): Fix Requested
2019-05-01T18:44:59.117Z,1556736299.117 [NAL9602](DEBUG): Fix Requested
2019-05-01T18:44:59.508Z,1556736299.508 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184455.00,A,3648.16510,N,12147.21376,W,0.097,0.00,010519,,,A*7D
2019-05-01T18:44:59.510Z,1556736299.510 [NAL9602](INFO): GPS fix at 20190501T184455: (36.802752, -121.786896)
2019-05-01T18:44:59.578Z,1556736299.578 [IBIT](IMPORTANT): Communications Status:
Fix Status: 1
Iridium Signal Strength: 4
Latitude: 36.802753 Longitude: -121.786896
2019-05-01T18:44:59.964Z,1556736299.964 [IBIT](FAULT): Warning: Battery Data not active. Expected only when running primaries. Threshold checking not active.
2019-05-01T18:45:00.344Z,1556736300.344 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2019-05-01T18:45:00.344Z,1556736300.344 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2019-05-01T18:45:00.344Z,1556736300.344 [IBIT](IMPORTANT): Pressure:9.768231 PSI
2019-05-01T18:45:00.345Z,1556736300.345 [IBIT](IMPORTANT): Humidity:12.080332 %
2019-05-01T18:45:00.743Z,1556736300.743 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2019-05-01T18:45:00.744Z,1556736300.744 [IBIT](IMPORTANT): buoyancyNeutral: 315.000000 cc
2019-05-01T18:45:00.744Z,1556736300.744 [IBIT](IMPORTANT): massDefault: 1.000000 cm
2019-05-01T18:45:00.744Z,1556736300.744 [IBIT](IMPORTANT): stopDepth: 205.000000 m
2019-05-01T18:45:00.745Z,1556736300.745 [IBIT](IMPORTANT): abortDepth: 250.000000 m
2019-05-01T18:45:00.745Z,1556736300.745 [IBIT](IMPORTANT): IBIT PASSED
2019-05-01T18:45:31.826Z,1556736331.826 [NAL9602](INFO): Powering down
2019-05-01T18:45:37.522Z,1556736337.522 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-05-01T18:45:37.522Z,1556736337.522 [Default:CheckIn:C.Wait] Stopped
2019-05-01T18:45:37.522Z,1556736337.522 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-01T18:45:37.522Z,1556736337.522 [Default:CheckIn:D] Running Loop=1
2019-05-01T18:45:37.925Z,1556736337.925 [Default:CheckIn:D] Stopped
2019-05-01T18:45:37.925Z,1556736337.925 [Default:CheckIn:E] Running Loop=1
2019-05-01T18:45:38.332Z,1556736338.332 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 23.802852 min 
2019-05-01T18:45:38.332Z,1556736338.332 [Default:CheckIn:E] Stopped
2019-05-01T18:45:38.332Z,1556736338.332 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-05-01T18:45:38.332Z,1556736338.332 [Default:CheckIn] Stopped
2019-05-01T18:45:38.332Z,1556736338.332 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-05-01T18:45:38.333Z,1556736338.333 [Default:CheckIn](INFO): Running loop #4
2019-05-01T18:45:38.333Z,1556736338.333 [Default:CheckIn] Running Loop=4
2019-05-01T18:45:38.333Z,1556736338.333 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-05-01T18:45:38.333Z,1556736338.333 [Default:CheckIn:Read_GPS] Running Loop=1
2019-05-01T18:45:39.092Z,1556736339.092 [NAL9602](INFO): Powering up
2019-05-01T18:45:50.024Z,1556736350.024 [NAL9602](INFO): NAL9602 initialized
2019-05-01T18:45:50.829Z,1556736350.829 [NAL9602](DEBUG): Fix Requested
2019-05-01T18:45:59.698Z,1556736359.698 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-05-01T18:45:59.698Z,1556736359.698 [DVL_micro] Data Fault, FailCount= 1
2019-05-01T18:45:59.698Z,1556736359.698 [DVL_micro](ERROR): Data Fault
2019-05-01T18:45:59.738Z,1556736359.738 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-05-01T18:46:00.173Z,1556736360.173 [DVL_micro](INFO): uninitialize:Powering down
2019-05-01T18:46:01.012Z,1556736361.012 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-05-01T18:46:01.013Z,1556736361.013 [DVL_micro] No Fault, FailCount= 1
2019-05-01T18:46:01.324Z,1556736361.324 [DVL_micro](INFO): Initializing
2019-05-01T18:46:13.844Z,1556736373.844 [NAL9602](INFO): SBD MO Status=2, MOMSN=11652, MT Status=2, MTMSN=0
2019-05-01T18:46:13.844Z,1556736373.844 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-05-01T18:46:46.970Z,1556736406.970 [NAL9602](INFO): SBD MO Status=2, MOMSN=11652, MT Status=2, MTMSN=0
2019-05-01T18:46:46.970Z,1556736406.970 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-05-01T18:48:07.388Z,1556736487.388 [NAL9602](INFO): SBD MO Status=2, MOMSN=11652, MT Status=2, MTMSN=0
2019-05-01T18:48:07.389Z,1556736487.389 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-05-01T18:48:56.265Z,1556736536.265 [BPC1](INFO): Calculating totals. Valid battery stick count: 51. Valid reserve battery stick count: 5.
2019-05-01T18:48:56.268Z,1556736536.268 [BPC1](ERROR): Failed to receive data from all sticks prior to timeout. Will not retry this scan cycle.
2019-05-01T18:49:05.542Z,1556736545.542 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-05-01T18:49:05.542Z,1556736545.542 [DVL_micro] Data Fault, FailCount= 1
2019-05-01T18:49:05.542Z,1556736545.542 [DVL_micro](ERROR): Data Fault
2019-05-01T18:49:05.593Z,1556736545.593 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-05-01T18:49:06.017Z,1556736546.017 [DVL_micro](INFO): uninitialize:Powering down
2019-05-01T18:49:06.791Z,1556736546.791 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-05-01T18:49:06.791Z,1556736546.791 [DVL_micro] No Fault, FailCount= 1
2019-05-01T18:49:07.164Z,1556736547.164 [DVL_micro](INFO): Initializing
2019-05-01T18:49:39.495Z,1556736579.495 [DVL_micro](ERROR): only read 45 of 46 data items
2019-05-01T18:49:39.495Z,1556736579.495 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 0 0 0 0 -639 -632 -620 -676 2 2 3 3 -25.4 58.7 -692.2 2 -10.2 -63.1 -692.2 2 -25 58 10 -63 -692 2 0.66 1.04 147.4 -3.0 19.6 0.005 35.0 1489 74
2019-05-01T18:50:15.038Z,1556736615.038 [DVL_micro](ERROR): only read 44 of 46 data items
2019-05-01T18:50:15.038Z,1556736615.038 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 0 0 0 0 -689 -653 -742 -509 2 2 3 2 70.7 -192.2 -699.2 2 41.9 200.5 -699.2 2 70 -192 -699  -699 2 0.28 0.89 148.0 -3.0 19.6 0.005 35.0 1489 69
2019-05-01T18:50:16.644Z,1556736616.644 [NAL9602](INFO): SBD MO Status=2, MOMSN=11652, MT Status=2, MTMSN=0
2019-05-01T18:50:16.644Z,1556736616.644 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-05-01T18:50:38.516Z,1556736638.516 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-05-01T18:45:38.3Z
2019-05-01T18:50:38.516Z,1556736638.516 [Default:CheckIn:Read_GPS] Stopped
2019-05-01T18:50:38.517Z,1556736638.517 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-05-01T18:50:45.237Z,1556736645.237 [DataOverHttps](INFO): Sending 221 bytes from file Logs/20190501T181743/Courier0013.lzma
2019-05-01T18:50:46.042Z,1556736646.042 [DataOverHttps](INFO): Moved sent file to Logs/20190501T181743/Courier0013.lzma.bak
2019-05-01T18:50:46.042Z,1556736646.042 [DataOverHttps](INFO): SBD MOMSN=10891024
2019-05-01T18:50:51.408Z,1556736651.408 [NAL9602](INFO): SBD MO Status=2, MOMSN=11652, MT Status=2, MTMSN=0
2019-05-01T18:50:51.408Z,1556736651.408 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-05-01T18:50:53.851Z,1556736653.851 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-05-01T18:50:58.148Z,1556736658.148 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20190501T181743/Courier0016.lzma
2019-05-01T18:50:58.954Z,1556736658.954 [DataOverHttps](INFO): Moved sent file to Logs/20190501T181743/Courier0016.lzma.bak
2019-05-01T18:50:58.954Z,1556736658.954 [DataOverHttps](INFO): SBD MOMSN=10891029
2019-05-01T18:51:12.138Z,1556736672.138 [DataOverHttps](INFO): Sending 817 bytes from file Logs/20190501T181743/Express0014.lzma
2019-05-01T18:51:12.942Z,1556736672.942 [DataOverHttps](INFO): Moved sent file to Logs/20190501T181743/Express0014.lzma.bak
2019-05-01T18:51:12.942Z,1556736672.942 [DataOverHttps](INFO): SBD MOMSN=10891031
2019-05-01T18:51:24.534Z,1556736684.534 [NAL9602](INFO): Powering down
2019-05-01T18:51:25.913Z,1556736685.913 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20190501T181743/Express0018.lzma
2019-05-01T18:51:26.718Z,1556736686.718 [DataOverHttps](INFO): Moved sent file to Logs/20190501T181743/Express0018.lzma.bak
2019-05-01T18:51:26.719Z,1556736686.719 [DataOverHttps](INFO): SBD MOMSN=10891055
2019-05-01T18:51:29.010Z,1556736689.010 [Default:CheckIn:Read_Iridium] Stopped
2019-05-01T18:51:29.010Z,1556736689.010 [Default:CheckIn:C.Wait] Running Loop=1
2019-05-01T18:51:29.010Z,1556736689.010 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-05-01T18:52:11.398Z,1556736731.398 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-05-01T18:52:11.398Z,1556736731.398 [DVL_micro] Data Fault, FailCount= 1
2019-05-01T18:52:11.398Z,1556736731.398 [DVL_micro](ERROR): Data Fault
2019-05-01T18:52:11.438Z,1556736731.438 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-05-01T18:52:11.869Z,1556736731.869 [DVL_micro](INFO): uninitialize:Powering down
2019-05-01T18:52:12.674Z,1556736732.674 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-05-01T18:52:12.674Z,1556736732.674 [DVL_micro] No Fault, FailCount= 1
2019-05-01T18:52:13.017Z,1556736733.017 [DVL_micro](INFO): Initializing
2019-05-01T18:52:42.434Z,1556736762.434 [DataOverHttps](IMPORTANT): SBD MTMSN=20190501T185238
2019-05-01T18:52:47.644Z,1556736767.644 [DataOverHttps](INFO): Received command:ibit
2019-05-01T18:52:47.678Z,1556736767.678 [CommandLine](IMPORTANT): got command ibit
2019-05-01T18:52:47.807Z,1556736767.807 [IBIT](IMPORTANT): Beginning Initiated BIT
2019-05-01T18:52:47.807Z,1556736767.807 [IBIT](IMPORTANT): Beginning control surface checks.
2019-05-01T18:52:47.810Z,1556736767.810 [CBIT](IMPORTANT): Beginning ground fault scan
2019-05-01T18:52:48.169Z,1556736768.169 [NAL9602](INFO): Powering up
2019-05-01T18:52:58.740Z,1556736778.740 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.128179
CHAN A1 (24V): -0.017479
CHAN A2 (12V): -0.002522
CHAN A3 (5V): -0.000968
CHAN B0 (3.3V): -0.000501
CHAN B1 (3.15aV): -0.000431
CHAN B2 (3.15bV): -0.000261
CHAN B3 (GND): 0.000006
OPEN: -0.000115
Full Scale Calc: 4.765 mA, -1.589 mA
2019-05-01T18:52:59.071Z,1556736779.071 [NAL9602](INFO): NAL9602 initialized
2019-05-01T18:52:59.897Z,1556736779.897 [NAL9602](DEBUG): Fix Requested
2019-05-01T18:53:30.988Z,1556736810.988 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2019-05-01T18:53:31.061Z,1556736811.061 [NAL9602](FAULT): received: 
+SBDI: 2, 11652, 2, 0, 0, 0

OK
2019-05-01T18:53:31.061Z,1556736811.061 [NAL9602] Data Fault, FailCount= 1
2019-05-01T18:53:31.061Z,1556736811.061 [NAL9602](ERROR): Data Fault
2019-05-01T18:53:31.129Z,1556736811.129 [CBIT](ERROR): Data Fault in component: NAL9602
2019-05-01T18:53:31.394Z,1556736811.394 [NAL9602](INFO): Powering down
2019-05-01T18:53:32.250Z,1556736812.250 [CBIT](INFO): Clearing failed state for component NAL9602
2019-05-01T18:53:32.250Z,1556736812.250 [NAL9602] No Fault, FailCount= 1
2019-05-01T18:54:01.688Z,1556736841.688 [NAL9602](INFO): Powering up NAL9602
2019-05-01T18:54:12.623Z,1556736852.623 [NAL9602](INFO): NAL9602 initialized
2019-05-01T18:54:13.421Z,1556736853.421 [NAL9602](DEBUG): Fix Requested
2019-05-01T18:54:35.245Z,1556736875.245 [NAL9602](INFO): SBD MO Status=0, MOMSN=11652, MT Status=0, MTMSN=0
2019-05-01T18:54:35.245Z,1556736875.245 [NAL9602](INFO): No messages in MT queue
2019-05-01T18:54:36.049Z,1556736876.049 [NAL9602](DEBUG): Fix Requested
2019-05-01T18:54:38.873Z,1556736878.873 [NAL9602](DEBUG): Fix Requested
2019-05-01T18:54:38.906Z,1556736878.906 [IBIT](FAULT): Error acquiring IBIT communications status. Timeout expired.
2019-05-01T18:54:39.318Z,1556736879.318 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 0.000000
Voltage: 0.000000
2019-05-01T18:54:39.319Z,1556736879.319 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah
2019-05-01T18:54:39.319Z,1556736879.319 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V
2019-05-01T18:54:39.718Z,1556736879.718 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2019-05-01T18:54:39.718Z,1556736879.718 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2019-05-01T18:54:39.719Z,1556736879.719 [IBIT](IMPORTANT): Pressure:9.688726 PSI
2019-05-01T18:54:39.719Z,1556736879.719 [IBIT](IMPORTANT): Humidity:11.823953 %
2019-05-01T18:54:40.112Z,1556736880.112 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2019-05-01T18:54:40.112Z,1556736880.112 [IBIT](IMPORTANT): buoyancyNeutral: 315.000000 cc
2019-05-01T18:54:40.112Z,1556736880.112 [IBIT](IMPORTANT): massDefault: 1.000000 cm
2019-05-01T18:54:40.113Z,1556736880.113 [IBIT](IMPORTANT): stopDepth: 205.000000 m
2019-05-01T18:54:40.113Z,1556736880.113 [IBIT](IMPORTANT): abortDepth: 250.000000 m
2019-05-01T18:54:40.113Z,1556736880.113 [IBIT](IMPORTANT): IBIT FAILED
2019-05-01T18:55:11.984Z,1556736911.984 [NAL9602](INFO): Powering down
2019-05-01T18:55:17.238Z,1556736917.238 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-05-01T18:55:17.238Z,1556736917.238 [DVL_micro] Data Fault, FailCount= 1
2019-05-01T18:55:17.238Z,1556736917.238 [DVL_micro](ERROR): Data Fault
2019-05-01T18:55:17.289Z,1556736917.289 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-05-01T18:55:17.709Z,1556736917.709 [DVL_micro](INFO): uninitialize:Powering down
2019-05-01T18:55:18.506Z,1556736918.506 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-05-01T18:55:18.506Z,1556736918.506 [DVL_micro] No Fault, FailCount= 1
2019-05-01T18:55:18.864Z,1556736918.864 [DVL_micro](INFO): Initializing
2019-05-01T18:56:29.579Z,1556736989.579 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-05-01T18:56:29.579Z,1556736989.579 [Default:CheckIn:C.Wait] Stopped
2019-05-01T18:56:29.579Z,1556736989.579 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-01T18:56:29.579Z,1556736989.579 [Default:CheckIn:D] Running Loop=1
2019-05-01T18:56:30.037Z,1556736990.037 [Default:CheckIn:D] Stopped
2019-05-01T18:56:30.037Z,1556736990.037 [Default:CheckIn:E] Running Loop=1
2019-05-01T18:56:30.404Z,1556736990.404 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 34.671383 min 
2019-05-01T18:56:30.404Z,1556736990.404 [Default:CheckIn:E] Stopped
2019-05-01T18:56:30.404Z,1556736990.404 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-05-01T18:56:30.405Z,1556736990.405 [Default:CheckIn] Stopped
2019-05-01T18:56:30.405Z,1556736990.405 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-05-01T18:56:30.405Z,1556736990.405 [Default:CheckIn](INFO): Running loop #5
2019-05-01T18:56:30.405Z,1556736990.405 [Default:CheckIn] Running Loop=5
2019-05-01T18:56:30.405Z,1556736990.405 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-05-01T18:56:30.405Z,1556736990.405 [Default:CheckIn:Read_GPS] Running Loop=1
2019-05-01T18:56:31.174Z,1556736991.174 [NAL9602](INFO): Powering up
2019-05-01T18:56:42.079Z,1556737002.079 [NAL9602](INFO): NAL9602 initialized
2019-05-01T18:56:42.931Z,1556737002.931 [NAL9602](FAULT): GPS failed to acquire within timeout.
2019-05-01T18:56:42.932Z,1556737002.932 [NAL9602] Data Fault, FailCount= 1
2019-05-01T18:56:42.932Z,1556737002.932 [NAL9602](ERROR): Data Fault
2019-05-01T18:56:42.993Z,1556737002.993 [CBIT](ERROR): Data Fault in component: NAL9602
2019-05-01T18:56:43.292Z,1556737003.292 [NAL9602](INFO): Powering down
2019-05-01T18:56:44.134Z,1556737004.134 [CBIT](INFO): Clearing failed state for component NAL9602
2019-05-01T18:56:44.135Z,1556737004.135 [NAL9602] No Fault, FailCount= 1
2019-05-01T18:57:13.591Z,1556737033.591 [NAL9602](INFO): Powering up NAL9602
2019-05-01T18:57:24.496Z,1556737044.496 [NAL9602](INFO): NAL9602 initialized
2019-05-01T18:57:25.329Z,1556737045.329 [NAL9602](DEBUG): Fix Requested
2019-05-01T18:57:51.334Z,1556737071.334 [DataOverHttps](IMPORTANT): SBD MTMSN=20190501T185746
2019-05-01T18:57:56.573Z,1556737076.573 [DataOverHttps](INFO): Received command:load Science/sci2.xml;set sci2.NeedCommsTime 30 minute;set sci2.Lat1 36.750 degree;set sci2.Lon1 -122.022 degree;set sci2.YoYoMaxDepth 20 meter;set sci2.MaxDepth 30 meter;run 
2019-05-01T18:57:56.588Z,1556737076.588 [CommandLine](IMPORTANT): got command load ./Missions/Science/sci2.xml
2019-05-01T18:57:56.588Z,1556737076.588 [MissionManager](INFO): Loading Mission: ./Missions/Science/sci2.xml
2019-05-01T18:57:56.706Z,1556737076.706 [MissionManager](INFO): DefineArg sci2.MissionTimeout = 2.000000 h
2019-05-01T18:57:56.710Z,1556737076.710 [MissionManager](INFO): DefineArg sci2.NeedCommsTime = 60.000000 min
2019-05-01T18:57:56.712Z,1556737076.712 [MissionManager](INFO): DefineArg sci2.Repeat = 1.000000 count
2019-05-01T18:57:56.716Z,1556737076.716 [MissionManager](INFO): DefineArg sci2.Lat1 = nan arcdeg
2019-05-01T18:57:56.719Z,1556737076.719 [MissionManager](INFO): DefineArg sci2.Lon1 = nan arcdeg
2019-05-01T18:57:56.722Z,1556737076.722 [MissionManager](INFO): DefineArg sci2.Lat2 = nan arcdeg
2019-05-01T18:57:56.724Z,1556737076.724 [MissionManager](INFO): DefineArg sci2.Lon2 = nan arcdeg
2019-05-01T18:57:56.727Z,1556737076.727 [MissionManager](INFO): DefineArg sci2.Lat3 = nan arcdeg
2019-05-01T18:57:56.731Z,1556737076.731 [MissionManager](INFO): DefineArg sci2.Lon3 = nan arcdeg
2019-05-01T18:57:56.734Z,1556737076.734 [MissionManager](INFO): DefineArg sci2.Lat4 = nan arcdeg
2019-05-01T18:57:56.737Z,1556737076.737 [MissionManager](INFO): DefineArg sci2.Lon4 = nan arcdeg
2019-05-01T18:57:56.740Z,1556737076.740 [MissionManager](INFO): DefineArg sci2.Lat5 = nan arcdeg
2019-05-01T18:57:56.743Z,1556737076.743 [MissionManager](INFO): DefineArg sci2.Lon5 = nan arcdeg
2019-05-01T18:57:56.746Z,1556737076.746 [MissionManager](INFO): DefineArg sci2.Lat6 = nan arcdeg
2019-05-01T18:57:56.749Z,1556737076.749 [MissionManager](INFO): DefineArg sci2.Lon6 = nan arcdeg
2019-05-01T18:57:56.752Z,1556737076.752 [MissionManager](INFO): DefineArg sci2.Lat7 = nan arcdeg
2019-05-01T18:57:56.755Z,1556737076.755 [MissionManager](INFO): DefineArg sci2.Lon7 = nan arcdeg
2019-05-01T18:57:56.774Z,1556737076.774 [MissionManager](INFO): DefineArg sci2.Speed = 1.000000 m/s
2019-05-01T18:57:56.778Z,1556737076.778 [MissionManager](INFO): DefineArg sci2.CaptureRadius = nan m
2019-05-01T18:57:56.789Z,1556737076.789 [MissionManager](INFO): DefineArg sci2.YoYoMinDepth = 2.000000 m
2019-05-01T18:57:56.792Z,1556737076.792 [MissionManager](INFO): DefineArg sci2.YoYoMaxDepth = 200.000000 m
2019-05-01T18:57:56.799Z,1556737076.799 [MissionManager](INFO): DefineArg sci2.YoYoMinAltitude = 9.000000 m
2019-05-01T18:57:56.842Z,1556737076.842 [MissionManager](INFO): DefineArg sci2.YoYoUpPitch = 20.000000 arcdeg
2019-05-01T18:57:56.849Z,1556737076.849 [MissionManager](INFO): DefineArg sci2.YoYoDownPitch = -20.000000 arcdeg
2019-05-01T18:57:56.852Z,1556737076.852 [MissionManager](INFO): DefineArg sci2.BuoyancyNeutral = 315.000012 cc
2019-05-01T18:57:56.870Z,1556737076.870 [MissionManager](INFO): DefineArg sci2.MassDefault = 1.000000 cm
2019-05-01T18:57:56.885Z,1556737076.885 [MissionManager](INFO): DefineArg sci2.MinAltitude = 5.000000 m
2019-05-01T18:57:56.888Z,1556737076.888 [MissionManager](INFO): DefineArg sci2.MaxDepth = 205.000000 m
2019-05-01T18:57:56.912Z,1556737076.912 [MissionManager](INFO): DefineArg sci2.MinOffshore = 2.000000 km
2019-05-01T18:57:56.921Z,1556737076.921 [MissionManager](INFO): Inserting Stack: Missions/Insert/Science.xml
2019-05-01T18:57:57.330Z,1556737077.330 [MissionManager](INFO): DefineArg sci2:Science.SampleISUS = 0 bool
2019-05-01T18:57:57.341Z,1556737077.341 [MissionManager](INFO): DefineArg sci2:Science.SampleISUSmaxPitch = 60.000000 arcdeg
2019-05-01T18:57:57.344Z,1556737077.344 [MissionManager](INFO): DefineArg sci2:Science.SampleISUSminPitch = -60.000000 arcdeg
2019-05-01T18:57:57.351Z,1556737077.351 [MissionManager](INFO): DefineArg sci2:Science.PeakDetectChlActive = 0 bool
2019-05-01T18:57:57.354Z,1556737077.354 [MissionManager](INFO): DefineArg sci2:Science.TimeWindowPeakReport = nan min
2019-05-01T18:57:57.365Z,1556737077.365 [MissionManager](INFO): DefineArg sci2:Science.HighestChlPeakReportActive = 0 bool
2019-05-01T18:57:57.368Z,1556737077.368 [MissionManager](INFO): DefineArg sci2:Science.PatchTracking = 0 bool
2019-05-01T18:57:57.375Z,1556737077.375 [MissionManager](INFO): DefineArg sci2:Science.FilterWidthHorizontal = 3.000000 count
2019-05-01T18:57:57.378Z,1556737077.378 [MissionManager](INFO): DefineArg sci2:Science.NumProfilesSlidingwindow = 100.000000 count
2019-05-01T18:57:57.397Z,1556737077.397 [MissionManager](INFO): DefineArg sci2:Science.OffPeakFractionHorizontal = 80.000000 %
2019-05-01T18:57:57.400Z,1556737077.400 [MissionManager](INFO): DefineArg sci2:Science.PeakDetectNO3Active = 0 bool
2019-05-01T18:57:57.407Z,1556737077.407 [MissionManager](INFO): DefineArg sci2:Science.PeakDetectOilActive = 0 bool
2019-05-01T18:57:57.412Z,1556737077.412 [MissionManager](INFO): DefineArg sci2:Science.PeakDetectFDOMActive = 0 bool
2019-05-01T18:57:57.422Z,1556737077.422 [MissionManager](INFO): DefineArg sci2:Science.UpwardDerivativeOfTemperatureActive = 0 bool
2019-05-01T18:57:57.426Z,1556737077.426 [MissionManager](INFO): DefineArg sci2:Science.EnabledAanderaaO2 = 0.000000 bool
2019-05-01T18:57:57.437Z,1556737077.437 [MissionManager](INFO): DefineArg sci2:Science.EnabledNeilBrown = 1.000000 bool
2019-05-01T18:57:57.441Z,1556737077.441 [MissionManager](INFO): DefineArg sci2:Science.EnabledSeabird = 1.000000 bool
2019-05-01T18:57:57.444Z,1556737077.444 [MissionManager](INFO): DefineArg sci2:Science.EnabledTurbulence_NPS = 0.000000 bool
2019-05-01T18:57:57.447Z,1556737077.447 [MissionManager](INFO): DefineArg sci2:Science.EnabledWetLabsBB2FL = 1.000000 bool
2019-05-01T18:57:57.467Z,1556737077.467 [MissionManager](INFO): DefineArg sci2:Science.EnabledWetLabsSeaOWL_UV_A = 0.000000 bool
2019-05-01T18:57:57.470Z,1556737077.470 [MissionManager](INFO): DefineArg sci2:Science.EnabledWetLabsUBAT = 0.000000 bool
2019-05-01T18:57:57.474Z,1556737077.474 [MissionManager](INFO): DefineArg sci2:Science.EnabledISUS = 0.000000 bool
2019-05-01T18:57:57.476Z,1556737077.476 [MissionManager](INFO): DefineArg sci2:Science.LowPassWindowLength = 20.000000 count
2019-05-01T18:57:57.492Z,1556737077.492 [MissionManager](INFO): DefineArg sci2:Science.MedianFilterLen = 5.000000 count
2019-05-01T18:57:57.495Z,1556737077.495 [MissionManager](INFO): DefineArg sci2:Science.PeakChlShallowBound = nan m
2019-05-01T18:57:57.498Z,1556737077.498 [MissionManager](INFO): DefineArg sci2:Science.PeakChlDeepBound = nan m
2019-05-01T18:57:57.511Z,1556737077.511 [MissionManager](INFO): DefineArg sci2:Science.PeakShallowBound = nan m
2019-05-01T18:57:57.514Z,1556737077.514 [MissionManager](INFO): DefineArg sci2:Science.PeakDeepBound = nan m
2019-05-01T18:57:57.517Z,1556737077.517 [MissionManager](INFO): DefineOutput sci2:Science.PeakChl = 0.000000 ug/l
2019-05-01T18:57:57.520Z,1556737077.520 [MissionManager](INFO): DefineOutput sci2:Science.PeakChlDepth = 0.000000 m
2019-05-01T18:57:57.551Z,1556737077.551 [MissionManager](INFO): DefineOutput sci2:Science.PeakChlTemperature = 0.000000 degC
2019-05-01T18:57:57.554Z,1556737077.554 [MissionManager](INFO): DefineOutput sci2:Science.PeakChlLatitude = nan arcdeg
2019-05-01T18:57:57.557Z,1556737077.557 [MissionManager](INFO): DefineOutput sci2:Science.PeakChlLongitude = nan arcdeg
2019-05-01T18:57:57.560Z,1556737077.560 [MissionManager](INFO): DefineOutput sci2:Science.PeakNO3 = 0.000000 umol/l
2019-05-01T18:57:57.563Z,1556737077.563 [MissionManager](INFO): DefineOutput sci2:Science.PeakNO3Depth = 0.000000 m
2019-05-01T18:57:57.578Z,1556737077.578 [MissionManager](INFO): DefineOutput sci2:Science.PeakNO3Latitude = nan arcdeg
2019-05-01T18:57:57.581Z,1556737077.581 [MissionManager](INFO): DefineOutput sci2:Science.PeakNO3Longitude = nan arcdeg
2019-05-01T18:57:57.584Z,1556737077.584 [MissionManager](INFO): DefineOutput sci2:Science.PatchChl = 0.000000 m
2019-05-01T18:57:57.587Z,1556737077.587 [MissionManager](INFO): DefineOutput sci2:Science.PatchChlDepth = 0.000000 m
2019-05-01T18:57:57.602Z,1556737077.602 [MissionManager](INFO): DefineOutput sci2:Science.PatchChlLatitude = nan arcdeg
2019-05-01T18:57:57.605Z,1556737077.605 [MissionManager](INFO): DefineOutput sci2:Science.PatchChlLongitude = nan arcdeg
2019-05-01T18:57:57.608Z,1556737077.608 [MissionManager](INFO): DefineOutput sci2:Science.PatchChlDistance = nan m
2019-05-01T18:57:57.651Z,1556737077.651 [MissionManager](INFO): DefineOutput sci2:Science.PeakOil = 0.000000 kg/m3
2019-05-01T18:57:57.654Z,1556737077.654 [MissionManager](INFO): DefineOutput sci2:Science.PeakOilDepth = 0.000000 m
2019-05-01T18:57:57.670Z,1556737077.670 [MissionManager](INFO): DefineOutput sci2:Science.PeakOilLatitude = nan arcdeg
2019-05-01T18:57:57.677Z,1556737077.677 [MissionManager](INFO): DefineOutput sci2:Science.PeakOilLongitude = nan arcdeg
2019-05-01T18:57:57.680Z,1556737077.680 [MissionManager](INFO): DefineOutput sci2:Science.PeakFDOM = 0.000000 ppb
2019-05-01T18:57:57.692Z,1556737077.692 [MissionManager](INFO): DefineOutput sci2:Science.PeakFDOMDepth = 0.000000 m
2019-05-01T18:57:57.699Z,1556737077.699 [MissionManager](INFO): DefineOutput sci2:Science.PeakFDOMLatitude = nan arcdeg
2019-05-01T18:57:57.714Z,1556737077.714 [MissionManager](INFO): DefineOutput sci2:Science.PeakFDOMLongitude = nan arcdeg
2019-05-01T18:57:57.717Z,1556737077.717 [MissionManager](INFO): DefineOutput sci2:Science.PatchFDOMDistance = nan m
2019-05-01T18:57:57.751Z,1556737077.751 [sci2:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2019-05-01T18:57:57.775Z,1556737077.775 [sci2:Science:HighestChlPeakReport:A.PeakDetectHorizontal](DEBUG): Construct PeakDetectHorizontal.
2019-05-01T18:57:57.805Z,1556737077.805 [sci2:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2019-05-01T18:57:57.827Z,1556737077.827 [sci2:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2019-05-01T18:57:57.846Z,1556737077.846 [sci2:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2019-05-01T18:57:57.877Z,1556737077.877 [MissionManager](INFO): RedefineArg sci2:Science.SampleISUS = value:1 bool
2019-05-01T18:57:57.879Z,1556737077.879 [MissionManager](INFO): RedefineArg sci2:Science.PeakDetectChlActive = value:1 bool
2019-05-01T18:57:57.879Z,1556737077.879 [MissionManager](INFO): Inserting Stack: Missions/Insert/NeedComms.xml
2019-05-01T18:57:57.942Z,1556737077.942 [MissionManager](INFO): DefineArg sci2:NeedComms.DiveInterval = 3.000000 h
2019-05-01T18:57:57.953Z,1556737077.953 [MissionManager](INFO): DefineArg sci2:NeedComms.WaitForPitchUp = 10.000000 min
2019-05-01T18:57:57.956Z,1556737077.956 [MissionManager](INFO): DefineArg sci2:NeedComms.SurfacePitch = 20.000000 arcdeg
2019-05-01T18:57:57.967Z,1556737077.967 [MissionManager](INFO): DefineArg sci2:NeedComms.SurfaceDepthRate = nan m/s
2019-05-01T18:57:57.970Z,1556737077.970 [MissionManager](INFO): DefineArg sci2:NeedComms.SurfaceSpeed = 1.000000 m/s
2019-05-01T18:57:57.977Z,1556737077.977 [MissionManager](INFO): DefineArg sci2:NeedComms.GPSTimeout = 7.000000 min
2019-05-01T18:57:57.980Z,1556737077.980 [MissionManager](INFO): DefineArg sci2:NeedComms.CommsTimeout = 30.000000 min
2019-05-01T18:57:57.995Z,1556737077.995 [sci2:NeedComms:B.GoToSurface](DEBUG): Construct GoToSurface.
2019-05-01T18:57:58.076Z,1556737078.076 [MissionManager](INFO): Inserting Stack: Missions/Insert/StandardEnvelopes.xml
2019-05-01T18:57:58.114Z,1556737078.114 [MissionManager](INFO): DefineArg sci2:StandardEnvelopes.MinAltitude = 5.000000 m
2019-05-01T18:57:58.121Z,1556737078.121 [MissionManager](INFO): DefineArg sci2:StandardEnvelopes.MaxDepth = 200.000000 m
2019-05-01T18:57:58.124Z,1556737078.124 [MissionManager](INFO): DefineArg sci2:StandardEnvelopes.MinOffshore = 2000.000000 m
2019-05-01T18:57:58.130Z,1556737078.130 [sci2:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope.
2019-05-01T18:57:58.140Z,1556737078.140 [sci2:StandardEnvelopes:B.DepthEnvelope](DEBUG): Construct DepthEnvelope.
2019-05-01T18:57:58.162Z,1556737078.162 [sci2:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Construct OffshoreEnvelope.
2019-05-01T18:57:58.187Z,1556737078.187 [sci2:I.Pitch](DEBUG): Construct.
2019-05-01T18:57:58.201Z,1556737078.201 [sci2:J.Buoyancy](DEBUG): Construct Buoyancy.
2019-05-01T18:57:58.204Z,1556737078.204 [sci2:K.SetSpeed](DEBUG): Construct.
2019-05-01T18:57:58.217Z,1556737078.217 [sci2:L.DepthEnvelope](DEBUG): Construct DepthEnvelope.
2019-05-01T18:57:58.235Z,1556737078.235 [sci2:M.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope.
2019-05-01T18:57:58.251Z,1556737078.251 [sci2:N.YoYo](DEBUG): Construct YoYo.
2019-05-01T18:57:58.281Z,1556737078.281 [sci2:Lap:Wpt1:A.Waypoint](DEBUG): Construct Waypoint.
2019-05-01T18:57:58.298Z,1556737078.298 [sci2:Lap:Wpt2:A.Waypoint](DEBUG): Construct Waypoint.
2019-05-01T18:57:58.316Z,1556737078.316 [sci2:Lap:Wpt3:A.Waypoint](DEBUG): Construct Waypoint.
2019-05-01T18:57:58.328Z,1556737078.328 [sci2:Lap:Wpt4:A.Waypoint](DEBUG): Construct Waypoint.
2019-05-01T18:57:58.348Z,1556737078.348 [sci2:Lap:Wpt5:A.Waypoint](DEBUG): Construct Waypoint.
2019-05-01T18:57:58.366Z,1556737078.366 [sci2:Lap:Wpt6:A.Waypoint](DEBUG): Construct Waypoint.
2019-05-01T18:57:58.382Z,1556737078.382 [sci2:Lap:Wpt7:A.Waypoint](DEBUG): Construct Waypoint.
2019-05-01T18:57:58.521Z,1556737078.521 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<!-- ====================
     Generated by TethysL
     ==================== -->
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Control="Tethys/Control"
         xmlns:Guidance="Tethys/Guidance"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd"
       Id="sci2">

    <Description>
        Vehicle yo-yo's to the specified waypoints, with science turned on.
    </Description>
    <DefineArg Name="MissionTimeout"><Description>
        Maximum duration of mission
    </Description><Units:hour/><Value>2</Value></DefineArg>

    <DefineArg Name="NeedCommsTime"><Description>
        How often to surface for commumications
    </Description><Units:minute/><Value>60</Value></DefineArg>

    <DefineArg Name="Repeat"><Description>
        Number of times the vehicle should try to cycle through waypoints..
    </Description><Units:count/><Value>1</Value></DefineArg>

    <DefineArg Name="Lat1"><Description>
        Latitude of waypoint 1. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>NaN</Value></DefineArg>

    <DefineArg Name="Lon1"><Description>
        Longitude of waypoint 1. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>NaN</Value></DefineArg>

    <DefineArg Name="Lat2"><Description>
        Latitude of waypoint 2. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>NaN</Value></DefineArg>

    <DefineArg Name="Lon2"><Description>
        Longitude of waypoint 2. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>NaN</Value></DefineArg>

    <DefineArg Name="Lat3"><Description>
        Latitude of waypoint 3. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>NaN</Value></DefineArg>

    <DefineArg Name="Lon3"><Description>
        Longitude of waypoint 3. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>NaN</Value></DefineArg>

    <DefineArg Name="Lat4"><Description>
        Latitude of waypoint 4. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>NaN</Value></DefineArg>

    <DefineArg Name="Lon4"><Description>
        Longitude of waypoint 4. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>NaN</Value></DefineArg>

    <DefineArg Name="Lat5"><Description>
        Latitude of waypoint 5. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>NaN</Value></DefineArg>

    <DefineArg Name="Lon5"><Description>
        Longitude of waypoint 5. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>NaN</Value></DefineArg>

    <DefineArg Name="Lat6"><Description>
        Latitude of waypoint 6. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>NaN</Value></DefineArg>

    <DefineArg Name="Lon6"><Description>
        Longitude of waypoint 6. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>NaN</Value></DefineArg>

    <DefineArg Name="Lat7"><Description>
        Latitude of waypoint 7. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>NaN</Value></DefineArg>

    <DefineArg Name="Lon7"><Description>
        Longitude of waypoint 7. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>NaN</Value></DefineArg>

    <DefineArg Name="Speed"><Description>
        Speed while performing the YoYo behavior.
    </Description><Units:meter_per_second/><Value>1</Value></DefineArg>

    <DefineArg Name="CaptureRadius"><Description>
        Speed while performing the YoYo behavior.
    </Description><Units:meter/><Value>NaN</Value></DefineArg>

    
    <DefineArg Name="YoYoMinDepth"><Description>
        Minimum depth while performing the YoYo behavior.
    </Description><Units:meter/><Value>2</Value></DefineArg>

    <DefineArg Name="YoYoMaxDepth"><Description>
        Maximum depth while performing the YoYo behavior.
    </Description><Units:meter/><Value>200</Value></DefineArg>

    <DefineArg Name="YoYoMinAltitude"><Description>
        Minimum altitude while performing the YoYo behavior (for
        bottom-terminated YoYos).
    </Description><Units:meter/><Value>9</Value></DefineArg>

    <DefineArg Name="YoYoUpPitch"><Description>
        Vehicle up pitch while performing the YoYo behavior.
    </Description><Units:degree/><Value>20</Value></DefineArg>

    <DefineArg Name="YoYoDownPitch"><Description>
        Vehicle down pitch while performing the YoYo behavior.
    </Description><Units:degree/><Value>-20</Value></DefineArg>

    <DefineArg Name="BuoyancyNeutral"><Description>
        Buoyancy bladder position while performing the YoYo behavior. Defaults
        to buoyancyNeutral setting in the Config/Control.cfg file. Set to NaN cc
        for active buoyancy
    </Description><Control:VerticalControl.buoyancyNeutral/></DefineArg>

    <DefineArg Name="MassDefault"><Description>
        Static setting for mass during the mission. Set to NaN mm for active
        mass position
    </Description><Control:VerticalControl.massDefault/></DefineArg>

    <DefineArg Name="MinAltitude"><Description>
        Minimum height above the sea floor for the entire mission.
    </Description><Units:meter/><Value>5</Value></DefineArg>

    <DefineArg Name="MaxDepth"><Description>
        Maximum depth for the entire mission.
    </Description><Units:meter/><Value>205</Value></DefineArg>

    <DefineArg Name="MinOffshore"><Description>
        Minimum offshore distance for the entire mission.
    </Description><Units:kilometer/><Value>2</Value></DefineArg>
    <Timeout Duration="MissionTimeout"/>

    <Insert Filename="Insert/Science.xml">
        <Description>
            Most missions will run the science sensors. If you don't place this
            aggregate above NeedComms, science instruments get turned off on the
            last upcast and while floating on the surface.
        </Description>
        <RedefineArg Name="SampleISUS"><True/></RedefineArg>
        <RedefineArg Name="PeakDetectChlActive"><True/></RedefineArg>
    </Insert>

    <Insert Filename="Insert/NeedComms.xml" Id="NeedComms"/>

    <Assign><Sequence/><Arg Name="NeedComms:DiveInterval"/><Arg Name="NeedCommsTime"/></Assign>

    <Insert Filename="Insert/StandardEnvelopes.xml"/>

    <Assign><Sequence/><Arg Name="StandardEnvelopes:MinAltitude"/><Arg Name="MinAltitude"/></Assign>

    <Assign><Sequence/><Arg Name="StandardEnvelopes:MaxDepth"/><Arg Name="MaxDepth"/></Assign>

    <Assign><Sequence/><Arg Name="StandardEnvelopes:MinOffshore"/><Arg Name="MinOffshore"/></Assign>

    <Call Id="StartingMission" RefId="NeedComms"/>

    <Guidance:Pitch>
        <Parallel/>
        <Setting><Guidance:Pitch.massPosition/><Arg Name="MassDefault"/></Setting>
    </Guidance:Pitch>

    <Guidance:Buoyancy>
        <Parallel/>
        <Setting><Guidance:Buoyancy.position/><Arg Name="BuoyancyNeutral"/></Setting>
    </Guidance:Buoyancy>

    <Guidance:SetSpeed>
        <Parallel/>
        <Setting><Guidance:SetSpeed.speed/><Arg Name="Speed"/></Setting>
    </Guidance:SetSpeed>

    <Guidance:DepthEnvelope>
        <Description>
            Another depth envelope for the YoYo behavior. This envelope should
            fall within the limits of the standard safety envelopes in
            Insert/StandardEnvelopes.xml in order to avoid commanding high pitch
            angles for depth-terminated YoYos.
        </Description>
        <Parallel/>
        <Setting><Guidance:DepthEnvelope.minDepth/><Arg Name="YoYoMinDepth"/></Setting>
        <Setting><Guidance:DepthEnvelope.maxDepth/><Arg Name="YoYoMaxDepth"/></Setting>
        <Setting><Guidance:DepthEnvelope.downPitch/><Arg Name="YoYoDownPitch"/></Setting>
        <Setting><Guidance:DepthEnvelope.upPitch/><Arg Name="YoYoUpPitch"/></Setting>
    </Guidance:DepthEnvelope>

    <Guidance:AltitudeEnvelope>
        <Description>
            Another altitude envelope for the YoYo behavior. This envelope
            should fall within the limits of the standard safety envelopes in
            Insert/StandardEnvelopes.xml in order to avoid commanding high pitch
            angles for bottom-terminated YoYos.
        </Description>
        <Parallel/>
        <Setting><Guidance:AltitudeEnvelope.minAltitude/><Arg Name="YoYoMinAltitude"/></Setting>
        <Setting><Guidance:AltitudeEnvelope.upPitch/><Arg Name="YoYoUpPitch"/></Setting>
    </Guidance:AltitudeEnvelope>

    <Guidance:YoYo>
        <Parallel/>
        <Setting><Guidance:YoYo.downPitch/><Arg Name="YoYoDownPitch"/></Setting>
        <Setting><Guidance:YoYo.upPitch/><Arg Name="YoYoUpPitch"/></Setting>
    </Guidance:YoYo>

    <Aggregate Id="Lap">
        <Sequence Repeat="Repeat"/>

        <Aggregate Id="Wpt1">
            <Sequence/>

            <Guidance:Waypoint>
                <Sequence/>
                <Setting><Guidance:Waypoint.latitude/><Arg Name="Lat1"/></Setting>
                <Setting><Guidance:Waypoint.longitude/><Arg Name="Lon1"/></Setting>
                <Setting><Guidance:Waypoint.captureRadius/><Arg Name="CaptureRadius"/></Setting>
            </Guidance:Waypoint>
        </Aggregate>

        <Aggregate Id="Wpt2">
            <Sequence/>

            <Guidance:Waypoint>
                <Sequence/>
                <Setting><Guidance:Waypoint.latitude/><Arg Name="Lat2"/></Setting>
                <Setting><Guidance:Waypoint.longitude/><Arg Name="Lon2"/></Setting>
            </Guidance:Waypoint>
        </Aggregate>

        <Aggregate Id="Wpt3">
            <Sequence/>

            <Guidance:Waypoint>
                <Sequence/>
                <Setting><Guidance:Waypoint.latitude/><Arg Name="Lat3"/></Setting>
                <Setting><Guidance:Waypoint.longitude/><Arg Name="Lon3"/></Setting>
            </Guidance:Waypoint>
        </Aggregate>

        <Aggregate Id="Wpt4">
            <Sequence/>

            <Guidance:Waypoint>
                <Sequence/>
                <Setting><Guidance:Waypoint.latitude/><Arg Name="Lat4"/></Setting>
                <Setting><Guidance:Waypoint.longitude/><Arg Name="Lon4"/></Setting>
            </Guidance:Waypoint>
        </Aggregate>

        <Aggregate Id="Wpt5">
            <Sequence/>

            <Guidance:Waypoint>
                <Sequence/>
                <Setting><Guidance:Waypoint.latitude/><Arg Name="Lat5"/></Setting>
                <Setting><Guidance:Waypoint.longitude/><Arg Name="Lon5"/></Setting>
            </Guidance:Waypoint>
        </Aggregate>

        <Aggregate Id="Wpt6">
            <Sequence/>

            <Guidance:Waypoint>
                <Sequence/>
                <Setting><Guidance:Waypoint.latitude/><Arg Name="Lat6"/></Setting>
                <Setting><Guidance:Waypoint.longitude/><Arg Name="Lon6"/></Setting>
            </Guidance:Waypoint>
        </Aggregate>

        <Aggregate Id="Wpt7">
            <Sequence/>

            <Guidance:Waypoint>
                <Sequence/>
                <Setting><Guidance:Waypoint.latitude/><Arg Name="Lat7"/></Setting>
                <Setting><Guidance:Waypoint.longitude/><Arg Name="Lon7"/></Setting>
            </Guidance:Waypoint>
        </Aggregate>
    </Aggregate>
</Mission>


2019-05-01T18:57:58.522Z,1556737078.522 [CommandLine](IMPORTANT): Loaded ./Missions/Science/sci2.xml
2019-05-01T18:58:07.472Z,1556737087.472 [CommandLine](IMPORTANT): got command set sci2.NeedCommsTime 30.000000 minute
2019-05-01T18:58:07.473Z,1556737087.473 [CommandLine](IMPORTANT): got command set sci2.Lat1 36.750000 degree
2019-05-01T18:58:07.474Z,1556737087.474 [CommandLine](IMPORTANT): got command set sci2.Lon1 -122.022003 degree
2019-05-01T18:58:07.475Z,1556737087.475 [CommandLine](IMPORTANT): got command set sci2.YoYoMaxDepth 20.000000 meter
2019-05-01T18:58:07.476Z,1556737087.476 [CommandLine](IMPORTANT): got command set sci2.MaxDepth 30.000000 meter
2019-05-01T18:58:07.476Z,1556737087.476 [CommandLine](IMPORTANT): got command run 
2019-05-01T18:58:07.479Z,1556737087.479 [CommandLine](IMPORTANT): Running 
2019-05-01T18:58:07.757Z,1556737087.757 [Default] Stopped
2019-05-01T18:58:07.757Z,1556737087.757 [Default](DEBUG): Aggregate::uninitialize Default
2019-05-01T18:58:07.757Z,1556737087.757 [Default:B.GoToSurface] Stopped
2019-05-01T18:58:07.757Z,1556737087.757 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-05-01T18:58:07.757Z,1556737087.757 [Default:CheckIn] Stopped
2019-05-01T18:58:07.757Z,1556737087.757 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-05-01T18:58:07.757Z,1556737087.757 [Default:CheckIn:Read_GPS] Stopped
2019-05-01T18:58:07.757Z,1556737087.757 [MissionManager](IMPORTANT): Started mission sci2
2019-05-01T18:58:07.758Z,1556737087.758 [sci2] Running Loop=1
2019-05-01T18:58:07.758Z,1556737087.758 [sci2](DEBUG): Aggregate::initialize sci2
2019-05-01T18:58:07.758Z,1556737087.758 [sci2:Science] Running Loop=1
2019-05-01T18:58:07.758Z,1556737087.758 [sci2:Science](DEBUG): Aggregate::initialize sci2:Science
2019-05-01T18:58:07.758Z,1556737087.758 [sci2:Science:A] Running Loop=1
2019-05-01T18:58:07.758Z,1556737087.758 [sci2:Science:B] Running Loop=1
2019-05-01T18:58:07.758Z,1556737087.758 [sci2:Science:C] Running Loop=1
2019-05-01T18:58:07.758Z,1556737087.758 [sci2:Science:D] Running Loop=1
2019-05-01T18:58:07.758Z,1556737087.758 [sci2:Science:E] Running Loop=1
2019-05-01T18:58:07.758Z,1556737087.758 [sci2:Science:F] Running Loop=1
2019-05-01T18:58:07.759Z,1556737087.759 [sci2:Science:G] Running Loop=1
2019-05-01T18:58:07.759Z,1556737087.759 [sci2:Science:H] Running Loop=1
2019-05-01T18:58:07.759Z,1556737087.759 [sci2:Science:Read_Oil] Running Loop=1
2019-05-01T18:58:07.759Z,1556737087.759 [sci2:Science:PeakDetectChl] Running Loop=1
2019-05-01T18:58:07.759Z,1556737087.759 [sci2:Science:PeakDetectChl](DEBUG): Aggregate::initialize sci2:Science:PeakDetectChl
2019-05-01T18:58:07.759Z,1556737087.759 [sci2:Science:PeakDetectChl:A.PeakDetectVsDepth] Running Loop=1
2019-05-01T18:58:07.759Z,1556737087.759 [sci2:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Initialize.
2019-05-01T18:58:07.761Z,1556737087.761 [sci2:Science:HighestChlPeakReport] Running Loop=1
2019-05-01T18:58:07.761Z,1556737087.761 [sci2:Science:HighestChlPeakReport](DEBUG): Aggregate::initialize sci2:Science:HighestChlPeakReport
2019-05-01T18:58:07.761Z,1556737087.761 [sci2:Science:HighestChlPeakReport:A.PeakDetectHorizontal] Running Loop=1
2019-05-01T18:58:07.762Z,1556737087.762 [sci2:Science:HighestChlPeakReport:A.PeakDetectHorizontal](INFO): Initialize.
2019-05-01T18:58:07.762Z,1556737087.762 [sci2:Science:PeakDetectNO3] Running Loop=1
2019-05-01T18:58:07.762Z,1556737087.762 [sci2:Science:PeakDetectNO3](DEBUG): Aggregate::initialize sci2:Science:PeakDetectNO3
2019-05-01T18:58:07.762Z,1556737087.762 [sci2:Science:PeakDetectNO3:A.PeakDetectVsDepth] Running Loop=1
2019-05-01T18:58:07.762Z,1556737087.762 [sci2:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Initialize.
2019-05-01T18:58:07.764Z,1556737087.764 [sci2:Science:PeakDetectOil] Running Loop=1
2019-05-01T18:58:07.764Z,1556737087.764 [sci2:Science:PeakDetectOil](DEBUG): Aggregate::initialize sci2:Science:PeakDetectOil
2019-05-01T18:58:07.764Z,1556737087.764 [sci2:Science:PeakDetectOil:A.PeakDetectVsDepth] Running Loop=1
2019-05-01T18:58:07.765Z,1556737087.765 [sci2:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Initialize.
2019-05-01T18:58:07.767Z,1556737087.767 [sci2:Science:PeakDetectFDOM] Running Loop=1
2019-05-01T18:58:07.767Z,1556737087.767 [sci2:Science:PeakDetectFDOM](DEBUG): Aggregate::initialize sci2:Science:PeakDetectFDOM
2019-05-01T18:58:07.767Z,1556737087.767 [sci2:Science:PeakDetectFDOM:A.PeakDetectVsDepth] Running Loop=1
2019-05-01T18:58:07.767Z,1556737087.767 [sci2:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Initialize.
2019-05-01T18:58:07.769Z,1556737087.769 [sci2:StandardEnvelopes] Running Loop=1
2019-05-01T18:58:07.769Z,1556737087.769 [sci2:StandardEnvelopes](DEBUG): Aggregate::initialize sci2:StandardEnvelopes
2019-05-01T18:58:07.769Z,1556737087.769 [sci2:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1
2019-05-01T18:58:07.769Z,1556737087.769 [sci2:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent.
2019-05-01T18:58:07.770Z,1556737087.770 [sci2:StandardEnvelopes:B.DepthEnvelope] Running Loop=1
2019-05-01T18:58:07.770Z,1556737087.770 [sci2:StandardEnvelopes:B.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent.
2019-05-01T18:58:07.770Z,1556737087.770 [sci2:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1
2019-05-01T18:58:07.770Z,1556737087.770 [sci2:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Initialize OffshoreEnvelopeComponent.
2019-05-01T18:58:07.770Z,1556737087.770 [sci2:I.Pitch] Running Loop=1
2019-05-01T18:58:07.770Z,1556737087.770 [sci2:I.Pitch](DEBUG): Initialize.
2019-05-01T18:58:07.770Z,1556737087.770 [sci2:J.Buoyancy] Running Loop=1
2019-05-01T18:58:07.771Z,1556737087.771 [sci2:J.Buoyancy](DEBUG): Initialize Buoyancy Component.
2019-05-01T18:58:07.771Z,1556737087.771 [sci2:K.SetSpeed] Running Loop=1
2019-05-01T18:58:07.771Z,1556737087.771 [sci2:K.SetSpeed](DEBUG): Initialize.
2019-05-01T18:58:07.771Z,1556737087.771 [sci2:L.DepthEnvelope] Running Loop=1
2019-05-01T18:58:07.771Z,1556737087.771 [sci2:L.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent.
2019-05-01T18:58:07.771Z,1556737087.771 [sci2:M.AltitudeEnvelope] Running Loop=1
2019-05-01T18:58:07.771Z,1556737087.771 [sci2:M.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent.
2019-05-01T18:58:07.771Z,1556737087.771 [sci2:N.YoYo] Running Loop=1
2019-05-01T18:58:07.771Z,1556737087.771 [sci2:N.YoYo](DEBUG): Initialize YoYoComponent.
2019-05-01T18:58:07.772Z,1556737087.772 [sci2:C] Running Loop=1
2019-05-01T18:58:07.772Z,1556737087.772 [sci2:N.YoYo] Running Loop=1
2019-05-01T18:58:07.773Z,1556737087.773 [sci2:M.AltitudeEnvelope] Running Loop=1
2019-05-01T18:58:07.774Z,1556737087.774 [sci2:L.DepthEnvelope] Running Loop=1
2019-05-01T18:58:07.775Z,1556737087.775 [sci2:K.SetSpeed] Running Loop=1
2019-05-01T18:58:07.775Z,1556737087.775 [sci2:J.Buoyancy] Running Loop=1
2019-05-01T18:58:07.775Z,1556737087.775 [sci2:I.Pitch] Running Loop=1
2019-05-01T18:58:07.776Z,1556737087.776 [sci2:StandardEnvelopes] Running Loop=1
2019-05-01T18:58:07.776Z,1556737087.776 [sci2:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1
2019-05-01T18:58:07.785Z,1556737087.785 [sci2:StandardEnvelopes:B.DepthEnvelope] Running Loop=1
2019-05-01T18:58:07.786Z,1556737087.786 [sci2:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1
2019-05-01T18:58:07.786Z,1556737087.786 [sci2:C] Stopped
2019-05-01T18:58:07.786Z,1556737087.786 [sci2:E] Running Loop=1
2019-05-01T18:58:07.786Z,1556737087.786 [sci2:Science] Running Loop=1
2019-05-01T18:58:07.788Z,1556737087.788 [sci2:Science:PeakDetectFDOM] Stopped
2019-05-01T18:58:07.788Z,1556737087.788 [sci2:Science:PeakDetectFDOM](DEBUG): Aggregate::uninitialize sci2:Science:PeakDetectFDOM
2019-05-01T18:58:07.788Z,1556737087.788 [sci2:Science:PeakDetectFDOM:A.PeakDetectVsDepth] Stopped
2019-05-01T18:58:07.788Z,1556737087.788 [sci2:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2019-05-01T18:58:07.788Z,1556737087.788 [sci2:Science:PeakDetectOil] Stopped
2019-05-01T18:58:07.788Z,1556737087.788 [sci2:Science:PeakDetectOil](DEBUG): Aggregate::uninitialize sci2:Science:PeakDetectOil
2019-05-01T18:58:07.788Z,1556737087.788 [sci2:Science:PeakDetectOil:A.PeakDetectVsDepth] Stopped
2019-05-01T18:58:07.788Z,1556737087.788 [sci2:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2019-05-01T18:58:07.788Z,1556737087.788 [sci2:Science:PeakDetectNO3] Stopped
2019-05-01T18:58:07.788Z,1556737087.788 [sci2:Science:PeakDetectNO3](DEBUG): Aggregate::uninitialize sci2:Science:PeakDetectNO3
2019-05-01T18:58:07.788Z,1556737087.788 [sci2:Science:PeakDetectNO3:A.PeakDetectVsDepth] Stopped
2019-05-01T18:58:07.789Z,1556737087.789 [sci2:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2019-05-01T18:58:07.789Z,1556737087.789 [sci2:Science:HighestChlPeakReport] Stopped
2019-05-01T18:58:07.789Z,1556737087.789 [sci2:Science:HighestChlPeakReport](DEBUG): Aggregate::uninitialize sci2:Science:HighestChlPeakReport
2019-05-01T18:58:07.789Z,1556737087.789 [sci2:Science:HighestChlPeakReport:A.PeakDetectHorizontal] Stopped
2019-05-01T18:58:07.789Z,1556737087.789 [sci2:Science:HighestChlPeakReport:A.PeakDetectHorizontal](DEBUG): Uninitialize.
2019-05-01T18:58:07.789Z,1556737087.789 [sci2:Science:PeakDetectChl] Running Loop=1
2019-05-01T18:58:07.789Z,1556737087.789 [sci2:Science:Read_Oil] Stopped
2019-05-01T18:58:07.789Z,1556737087.789 [sci2:Science:H] Stopped
2019-05-01T18:58:07.790Z,1556737087.790 [sci2:Science:G] Running Loop=1
2019-05-01T18:58:07.790Z,1556737087.790 [sci2:Science:G](DEBUG): Initialize ReadDataComponent to sense mass_concentration_of_chlorophyll_in_sea_water
2019-05-01T18:58:07.790Z,1556737087.790 [sci2:Science:F] Stopped
2019-05-01T18:58:07.790Z,1556737087.790 [sci2:Science:E] Stopped
2019-05-01T18:58:07.790Z,1556737087.790 [sci2:Science:D] Running Loop=1
2019-05-01T18:58:07.791Z,1556737087.791 [sci2:Science:D](DEBUG): Initialize ReadDataComponent to sense CTD_Seabird.sea_water_temperature
2019-05-01T18:58:07.792Z,1556737087.792 [sci2:Science:D](DEBUG): Initialize ReadDataComponent to sense CTD_Seabird.sea_water_salinity
2019-05-01T18:58:07.792Z,1556737087.792 [sci2:Science:C] Running Loop=1
2019-05-01T18:58:07.793Z,1556737087.793 [sci2:Science:C](DEBUG): Initialize ReadDataComponent to sense sea_water_temperature
2019-05-01T18:58:07.794Z,1556737087.794 [sci2:Science:C](DEBUG): Initialize ReadDataComponent to sense sea_water_salinity
2019-05-01T18:58:07.794Z,1556737087.794 [sci2:Science:B] Stopped
2019-05-01T18:58:07.794Z,1556737087.794 [sci2:Science:A] Stopped
2019-05-01T18:58:07.914Z,1556737087.914 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20
2019-05-01T18:58:07.922Z,1556737087.922 [WetLabsBB2FL](INFO): Opening uart, block timeout 10ths=2
2019-05-01T18:58:07.922Z,1556737087.922 [WetLabsBB2FL](INFO): Powering up
2019-05-01T18:58:07.985Z,1556737087.985 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown.
2019-05-01T18:58:07.987Z,1556737087.987 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4
2019-05-01T18:58:08.171Z,1556737088.171 [sci2:E] Stopped
2019-05-01T18:58:08.171Z,1556737088.171 [sci2:F] Running Loop=1
2019-05-01T18:58:08.583Z,1556737088.583 [sci2:F] Stopped
2019-05-01T18:58:08.584Z,1556737088.584 [sci2:G] Running Loop=1
2019-05-01T18:58:08.976Z,1556737088.976 [sci2:G] Stopped
2019-05-01T18:58:08.976Z,1556737088.976 [sci2:StartingMission] Running Loop=1
2019-05-01T18:58:08.977Z,1556737088.977 [sci2:StartingMission](DEBUG): Aggregate::initialize sci2:StartingMission
2019-05-01T18:58:09.381Z,1556737089.381 [sci2:M.AltitudeEnvelope](ERROR): Altitude Measurement is not Active.
2019-05-01T18:58:09.391Z,1556737089.391 [sci2:StandardEnvelopes:A.AltitudeEnvelope](ERROR): Altitude Measurement is not Active.
2019-05-01T18:58:09.391Z,1556737089.391 [sci2:NeedComms] Running Loop=1
2019-05-01T18:58:09.391Z,1556737089.391 [sci2:NeedComms](DEBUG): Aggregate::initialize sci2:NeedComms
2019-05-01T18:58:09.392Z,1556737089.392 [sci2:NeedComms:B.GoToSurface] Running Loop=1
2019-05-01T18:58:09.392Z,1556737089.392 [sci2:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-05-01T18:58:09.392Z,1556737089.392 [sci2:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s.
2019-05-01T18:58:09.392Z,1556737089.392 [sci2:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees.
2019-05-01T18:58:09.393Z,1556737089.393 [sci2:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s.
2019-05-01T18:58:09.393Z,1556737089.393 [sci2:NeedComms:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-05-01T18:58:09.394Z,1556737089.394 [sci2:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-05-01T18:58:09.394Z,1556737089.394 [sci2:NeedComms:A] Running Loop=1
2019-05-01T18:58:09.395Z,1556737089.395 [sci2:NeedComms:A](INFO): last time_fix was: 1556736295.000000 second since 1970/01/01T00:00:00Z 
2019-05-01T18:58:09.395Z,1556737089.395 [sci2:NeedComms:A] Stopped
2019-05-01T18:58:09.619Z,1556737089.619 [CTD_NeilBrown](ERROR): Salinity reading out of range: 1617.261475 psu
2019-05-01T18:58:09.907Z,1556737089.907 [sci2:NeedComms:C] Running Loop=1
2019-05-01T18:58:10.080Z,1556737090.080 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:10.121Z,1556737090.121 [CTD_NeilBrown](ERROR): Salinity reading out of range: 2213.164062 psu
2019-05-01T18:58:10.126Z,1556737090.126 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:10.238Z,1556737090.238 [DVL_micro](ERROR): only read 43 of 46 data items
2019-05-01T18:58:10.238Z,1556737090.238 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 0566 -574 -558 -525 2 2 2 2 -10.7 -65.4 -599.4 2 -53.4 39.2 -599.4 2 -10 -65 -599 2 -53 39 -599 2 0.66 0.85 243.0 -3.0 19.8 0.005 35.0 1489 75
2019-05-01T18:58:10.303Z,1556737090.303 [sci2:NeedComms:C](DEBUG): Initialize ReadDataComponent to sense time_fix
2019-05-01T18:58:10.487Z,1556737090.487 [CTD_NeilBrown](ERROR): Salinity reading out of range: 2703.711426 psu
2019-05-01T18:58:10.490Z,1556737090.490 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:10.690Z,1556737090.690 [CTD_NeilBrown](ERROR): Salinity reading out of range: 3123.404785 psu
2019-05-01T18:58:10.696Z,1556737090.696 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:10.895Z,1556737090.895 [CTD_NeilBrown](ERROR): Salinity reading out of range: 3269.838623 psu
2019-05-01T18:58:10.899Z,1556737090.899 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:10.926Z,1556737090.926 [CTD_Seabird](ERROR): Failed to parse device response: <!--startlogging-->
2019-05-01T18:58:11.100Z,1556737091.100 [CTD_NeilBrown](ERROR): Salinity reading out of range: 5896.799805 psu
2019-05-01T18:58:11.104Z,1556737091.104 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:11.302Z,1556737091.302 [CTD_NeilBrown](ERROR): Salinity reading out of range: 2203.781250 psu
2019-05-01T18:58:11.306Z,1556737091.306 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:11.524Z,1556737091.524 [CTD_NeilBrown](ERROR): Salinity reading out of range: 2848.848389 psu
2019-05-01T18:58:11.528Z,1556737091.528 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:11.733Z,1556737091.733 [CTD_NeilBrown](ERROR): Salinity reading out of range: 2449.416260 psu
2019-05-01T18:58:11.737Z,1556737091.737 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:11.950Z,1556737091.950 [CTD_NeilBrown](ERROR): Salinity reading out of range: 2368.730713 psu
2019-05-01T18:58:11.981Z,1556737091.981 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:12.166Z,1556737092.166 [CTD_NeilBrown](ERROR): Salinity reading out of range: 4733.762207 psu
2019-05-01T18:58:12.170Z,1556737092.170 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:12.526Z,1556737092.526 [CTD_NeilBrown](ERROR): Salinity reading out of range: 2581.027588 psu
2019-05-01T18:58:12.530Z,1556737092.530 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:12.731Z,1556737092.731 [CTD_NeilBrown](ERROR): Salinity reading out of range: 3678.301270 psu
2019-05-01T18:58:12.734Z,1556737092.734 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:12.935Z,1556737092.935 [CTD_Seabird](ERROR): Salinity reading out of range: 0.121002 psu
2019-05-01T18:58:12.941Z,1556737092.941 [CTD_NeilBrown](ERROR): Salinity reading out of range: 2957.440674 psu
2019-05-01T18:58:12.945Z,1556737092.945 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:13.142Z,1556737093.142 [CTD_NeilBrown](ERROR): Salinity reading out of range: 2291.329834 psu
2019-05-01T18:58:13.146Z,1556737093.146 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:13.346Z,1556737093.346 [CTD_NeilBrown](ERROR): Salinity reading out of range: 2556.892090 psu
2019-05-01T18:58:13.350Z,1556737093.350 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:13.551Z,1556737093.551 [CTD_NeilBrown](ERROR): Salinity reading out of range: 3387.526855 psu
2019-05-01T18:58:13.555Z,1556737093.555 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:13.765Z,1556737093.765 [CTD_NeilBrown](ERROR): Salinity reading out of range: 837.131287 psu
2019-05-01T18:58:13.769Z,1556737093.769 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:13.940Z,1556737093.940 [CTD_Seabird](ERROR): Salinity reading out of range: 0.118589 psu
2019-05-01T18:58:13.975Z,1556737093.975 [CTD_NeilBrown](ERROR): Salinity reading out of range: 2430.870850 psu
2019-05-01T18:58:13.989Z,1556737093.989 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:14.366Z,1556737094.366 [CTD_NeilBrown](ERROR): Salinity reading out of range: 2922.614014 psu
2019-05-01T18:58:14.370Z,1556737094.370 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:14.570Z,1556737094.570 [CTD_NeilBrown](ERROR): Salinity reading out of range: 3497.592773 psu
2019-05-01T18:58:14.574Z,1556737094.574 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:14.778Z,1556737094.778 [CTD_NeilBrown](ERROR): Salinity reading out of range: 2273.843506 psu
2019-05-01T18:58:14.791Z,1556737094.791 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:14.943Z,1556737094.943 [CTD_Seabird](ERROR): Salinity reading out of range: 0.116973 psu
2019-05-01T18:58:14.980Z,1556737094.980 [CTD_NeilBrown](ERROR): Salinity reading out of range: 2147.893066 psu
2019-05-01T18:58:14.983Z,1556737094.983 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:15.186Z,1556737095.186 [CTD_NeilBrown](ERROR): Salinity reading out of range: 1681.258667 psu
2019-05-01T18:58:15.190Z,1556737095.190 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:15.386Z,1556737095.386 [CTD_NeilBrown](ERROR): Salinity reading out of range: 2138.953613 psu
2019-05-01T18:58:15.390Z,1556737095.390 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:15.591Z,1556737095.591 [CTD_NeilBrown](ERROR): Salinity reading out of range: 15985.486328 psu
2019-05-01T18:58:15.594Z,1556737095.594 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:15.948Z,1556737095.948 [CTD_Seabird](ERROR): Salinity reading out of range: 0.117260 psu
2019-05-01T18:58:15.999Z,1556737095.999 [CTD_NeilBrown](ERROR): Salinity reading out of range: 2309.969727 psu
2019-05-01T18:58:16.003Z,1556737096.003 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:16.203Z,1556737096.203 [CTD_NeilBrown](ERROR): Salinity reading out of range: 2108.448242 psu
2019-05-01T18:58:16.206Z,1556737096.206 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:16.406Z,1556737096.406 [CTD_NeilBrown](ERROR): Salinity reading out of range: 1587.242554 psu
2019-05-01T18:58:16.410Z,1556737096.410 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:16.610Z,1556737096.610 [CTD_NeilBrown](ERROR): Salinity reading out of range: 2300.721191 psu
2019-05-01T18:58:16.614Z,1556737096.614 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:16.815Z,1556737096.815 [CTD_NeilBrown](ERROR): Salinity reading out of range: 1350.518921 psu
2019-05-01T18:58:16.818Z,1556737096.818 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:16.952Z,1556737096.952 [CTD_Seabird](ERROR): Salinity reading out of range: 0.115721 psu
2019-05-01T18:58:17.018Z,1556737097.018 [CTD_NeilBrown](ERROR): Salinity reading out of range: 2085.032959 psu
2019-05-01T18:58:17.023Z,1556737097.023 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:17.222Z,1556737097.222 [CTD_NeilBrown](ERROR): Salinity reading out of range: 1456.755249 psu
2019-05-01T18:58:17.226Z,1556737097.226 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:17.634Z,1556737097.634 [CTD_NeilBrown](ERROR): Salinity reading out of range: 2088.727051 psu
2019-05-01T18:58:17.638Z,1556737097.638 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:17.834Z,1556737097.834 [CTD_NeilBrown](ERROR): Salinity reading out of range: 2232.231934 psu
2019-05-01T18:58:17.838Z,1556737097.838 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:17.956Z,1556737097.956 [CTD_Seabird](ERROR): Salinity reading out of range: 0.115038 psu
2019-05-01T18:58:18.039Z,1556737098.039 [CTD_NeilBrown](ERROR): Salinity reading out of range: 1462.727417 psu
2019-05-01T18:58:18.044Z,1556737098.044 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:18.243Z,1556737098.243 [CTD_NeilBrown](ERROR): Salinity reading out of range: 1417.100952 psu
2019-05-01T18:58:18.247Z,1556737098.247 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:18.447Z,1556737098.447 [CTD_NeilBrown](ERROR): Salinity reading out of range: 1629.039429 psu
2019-05-01T18:58:18.453Z,1556737098.453 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:18.650Z,1556737098.650 [CTD_NeilBrown](ERROR): Salinity reading out of range: 10877.242188 psu
2019-05-01T18:58:18.654Z,1556737098.654 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:18.854Z,1556737098.854 [CTD_NeilBrown](ERROR): Salinity reading out of range: 1521.951416 psu
2019-05-01T18:58:18.858Z,1556737098.858 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:18.960Z,1556737098.960 [CTD_Seabird](ERROR): Salinity reading out of range: 0.114876 psu
2019-05-01T18:58:19.094Z,1556737099.094 [CTD_NeilBrown](ERROR): Salinity reading out of range: 350.220398 psu
2019-05-01T18:58:19.098Z,1556737099.098 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:19.467Z,1556737099.467 [CTD_NeilBrown](ERROR): Salinity reading out of range: 1540.006714 psu
2019-05-01T18:58:19.473Z,1556737099.473 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:19.670Z,1556737099.670 [CTD_NeilBrown](ERROR): Salinity reading out of range: 1344.332275 psu
2019-05-01T18:58:19.674Z,1556737099.674 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:19.874Z,1556737099.874 [CTD_NeilBrown](ERROR): Salinity reading out of range: 2924.587158 psu
2019-05-01T18:58:19.878Z,1556737099.878 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:19.964Z,1556737099.964 [CTD_Seabird](ERROR): Salinity reading out of range: 0.114039 psu
2019-05-01T18:58:20.079Z,1556737100.079 [CTD_NeilBrown](ERROR): Salinity reading out of range: 1269.500854 psu
2019-05-01T18:58:20.082Z,1556737100.082 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:20.282Z,1556737100.282 [CTD_NeilBrown](ERROR): Salinity reading out of range: 1877.613525 psu
2019-05-01T18:58:20.298Z,1556737100.298 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:20.486Z,1556737100.486 [CTD_NeilBrown](ERROR): Salinity reading out of range: 1589.807739 psu
2019-05-01T18:58:20.490Z,1556737100.490 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:20.703Z,1556737100.703 [CTD_NeilBrown](ERROR): Salinity reading out of range: 1610.241577 psu
2019-05-01T18:58:20.707Z,1556737100.707 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:20.907Z,1556737100.907 [CTD_NeilBrown](ERROR): Salinity reading out of range: 1852.013062 psu
2019-05-01T18:58:20.911Z,1556737100.911 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:20.968Z,1556737100.968 [CTD_Seabird](ERROR): Salinity reading out of range: 0.113739 psu
2019-05-01T18:58:21.133Z,1556737101.133 [CTD_NeilBrown](ERROR): Salinity reading out of range: 1322.248169 psu
2019-05-01T18:58:21.137Z,1556737101.137 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:21.338Z,1556737101.338 [CTD_NeilBrown](ERROR): Salinity reading out of range: 465.618195 psu
2019-05-01T18:58:21.344Z,1556737101.344 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:21.554Z,1556737101.554 [CTD_NeilBrown](ERROR): Salinity reading out of range: 1254.233154 psu
2019-05-01T18:58:21.558Z,1556737101.558 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:21.927Z,1556737101.927 [CTD_NeilBrown](ERROR): Salinity reading out of range: 910.297913 psu
2019-05-01T18:58:21.931Z,1556737101.931 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:21.972Z,1556737101.972 [CTD_Seabird](ERROR): Salinity reading out of range: 0.113197 psu
2019-05-01T18:58:22.130Z,1556737102.130 [CTD_NeilBrown](ERROR): Salinity reading out of range: 1156.959961 psu
2019-05-01T18:58:22.135Z,1556737102.135 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:22.336Z,1556737102.336 [CTD_NeilBrown](ERROR): Salinity reading out of range: 1022.083923 psu
2019-05-01T18:58:22.339Z,1556737102.339 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:22.538Z,1556737102.538 [CTD_NeilBrown](ERROR): Salinity reading out of range: 1344.135132 psu
2019-05-01T18:58:22.545Z,1556737102.545 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:22.743Z,1556737102.743 [CTD_NeilBrown](ERROR): Salinity reading out of range: 1800.401611 psu
2019-05-01T18:58:22.746Z,1556737102.746 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:22.947Z,1556737102.947 [CTD_NeilBrown](ERROR): Salinity reading out of range: 1712.042969 psu
2019-05-01T18:58:22.955Z,1556737102.955 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:22.976Z,1556737102.976 [CTD_Seabird](ERROR): Salinity reading out of range: 0.112854 psu
2019-05-01T18:58:23.134Z,1556737103.134 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-05-01T18:58:23.135Z,1556737103.135 [DVL_micro] Data Fault, FailCount= 1
2019-05-01T18:58:23.135Z,1556737103.135 [DVL_micro](ERROR): Data Fault
2019-05-01T18:58:23.166Z,1556737103.166 [CTD_NeilBrown](ERROR): Salinity reading out of range: 1411.855713 psu
2019-05-01T18:58:23.169Z,1556737103.169 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:23.261Z,1556737103.261 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-05-01T18:58:23.378Z,1556737103.378 [CTD_NeilBrown](ERROR): Salinity reading out of range: 1027.151001 psu
2019-05-01T18:58:23.381Z,1556737103.381 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:23.594Z,1556737103.594 [CTD_NeilBrown](ERROR): Salinity reading out of range: 610.253174 psu
2019-05-01T18:58:23.598Z,1556737103.598 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:23.605Z,1556737103.605 [DVL_micro](INFO): uninitialize:Powering down
2019-05-01T18:58:23.967Z,1556737103.967 [CTD_NeilBrown](ERROR): Salinity reading out of range: 1515.855469 psu
2019-05-01T18:58:23.972Z,1556737103.972 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:23.980Z,1556737103.980 [CTD_Seabird](ERROR): Salinity reading out of range: 0.112756 psu
2019-05-01T18:58:24.171Z,1556737104.171 [CTD_NeilBrown](ERROR): Salinity reading out of range: 1816.559570 psu
2019-05-01T18:58:24.174Z,1556737104.174 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:24.375Z,1556737104.375 [CTD_NeilBrown](ERROR): Salinity reading out of range: 1866.875244 psu
2019-05-01T18:58:24.378Z,1556737104.378 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:24.435Z,1556737104.435 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-05-01T18:58:24.435Z,1556737104.435 [DVL_micro] No Fault, FailCount= 1
2019-05-01T18:58:24.594Z,1556737104.594 [CTD_NeilBrown](ERROR): Salinity reading out of range: 975.532715 psu
2019-05-01T18:58:24.598Z,1556737104.598 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:24.767Z,1556737104.767 [DVL_micro](INFO): Initializing
2019-05-01T18:58:24.798Z,1556737104.798 [CTD_NeilBrown](ERROR): Salinity reading out of range: 1539.964966 psu
2019-05-01T18:58:24.802Z,1556737104.802 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:24.984Z,1556737104.984 [CTD_Seabird](ERROR): Salinity reading out of range: 0.112287 psu
2019-05-01T18:58:25.003Z,1556737105.003 [CTD_NeilBrown](ERROR): Salinity reading out of range: 1790.052124 psu
2019-05-01T18:58:25.006Z,1556737105.006 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:25.207Z,1556737105.207 [CTD_NeilBrown](ERROR): Salinity reading out of range: 1227.592041 psu
2019-05-01T18:58:25.220Z,1556737105.220 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:25.615Z,1556737105.615 [CTD_NeilBrown](ERROR): Salinity reading out of range: 1695.899658 psu
2019-05-01T18:58:25.623Z,1556737105.623 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:25.819Z,1556737105.819 [CTD_NeilBrown](ERROR): Salinity reading out of range: 1478.651611 psu
2019-05-01T18:58:25.822Z,1556737105.822 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:25.987Z,1556737105.987 [CTD_Seabird](ERROR): Salinity reading out of range: 0.112459 psu
2019-05-01T18:58:26.024Z,1556737106.024 [CTD_NeilBrown](ERROR): Salinity reading out of range: 1532.165039 psu
2019-05-01T18:58:26.028Z,1556737106.028 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:26.227Z,1556737106.227 [CTD_NeilBrown](ERROR): Salinity reading out of range: 1271.050171 psu
2019-05-01T18:58:26.230Z,1556737106.230 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:26.431Z,1556737106.431 [CTD_NeilBrown](ERROR): Salinity reading out of range: 1901.010864 psu
2019-05-01T18:58:26.443Z,1556737106.443 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:26.635Z,1556737106.635 [CTD_NeilBrown](ERROR): Salinity reading out of range: 3444.441650 psu
2019-05-01T18:58:26.638Z,1556737106.638 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:26.838Z,1556737106.838 [CTD_NeilBrown](ERROR): Salinity reading out of range: 1325.814575 psu
2019-05-01T18:58:26.850Z,1556737106.850 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:26.995Z,1556737106.995 [CTD_Seabird](ERROR): Salinity reading out of range: 0.110882 psu
2019-05-01T18:58:27.247Z,1556737107.247 [CTD_NeilBrown](ERROR): Salinity reading out of range: 12002.096680 psu
2019-05-01T18:58:27.259Z,1556737107.259 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:27.451Z,1556737107.451 [CTD_NeilBrown](ERROR): Salinity reading out of range: 1588.513672 psu
2019-05-01T18:58:27.458Z,1556737107.458 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:27.669Z,1556737107.669 [CTD_NeilBrown](ERROR): Salinity reading out of range: 1684.057251 psu
2019-05-01T18:58:27.673Z,1556737107.673 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:27.858Z,1556737107.858 [CTD_NeilBrown](ERROR): Salinity reading out of range: 1333.175049 psu
2019-05-01T18:58:27.862Z,1556737107.862 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:27.999Z,1556737107.999 [CTD_Seabird](ERROR): Salinity reading out of range: 0.112150 psu
2019-05-01T18:58:28.063Z,1556737108.063 [CTD_NeilBrown](ERROR): Salinity reading out of range: 1595.178955 psu
2019-05-01T18:58:28.068Z,1556737108.068 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:28.267Z,1556737108.267 [CTD_NeilBrown](ERROR): Salinity reading out of range: 1626.456177 psu
2019-05-01T18:58:28.271Z,1556737108.271 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:28.471Z,1556737108.471 [CTD_NeilBrown](ERROR): Salinity reading out of range: 1695.774048 psu
2019-05-01T18:58:28.478Z,1556737108.478 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:28.710Z,1556737108.710 [CTD_NeilBrown](ERROR): Salinity reading out of range: 1562.663940 psu
2019-05-01T18:58:28.713Z,1556737108.713 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:29.003Z,1556737109.003 [CTD_Seabird](ERROR): Salinity reading out of range: 0.110899 psu
2019-05-01T18:58:29.083Z,1556737109.083 [CTD_NeilBrown](ERROR): Salinity reading out of range: 2031.001343 psu
2019-05-01T18:58:29.087Z,1556737109.087 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:29.286Z,1556737109.286 [CTD_NeilBrown](ERROR): Salinity reading out of range: 2128.297607 psu
2019-05-01T18:58:29.290Z,1556737109.290 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:29.491Z,1556737109.491 [CTD_NeilBrown](ERROR): Salinity reading out of range: 2087.502930 psu
2019-05-01T18:58:29.494Z,1556737109.494 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:29.695Z,1556737109.695 [CTD_NeilBrown](ERROR): Salinity reading out of range: 780.887817 psu
2019-05-01T18:58:29.699Z,1556737109.699 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:29.899Z,1556737109.899 [CTD_NeilBrown](ERROR): Salinity reading out of range: 2186.257080 psu
2019-05-01T18:58:29.903Z,1556737109.903 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:30.007Z,1556737110.007 [CTD_Seabird](ERROR): Salinity reading out of range: 0.110213 psu
2019-05-01T18:58:30.114Z,1556737110.114 [CTD_NeilBrown](ERROR): Salinity reading out of range: 1696.021851 psu
2019-05-01T18:58:30.119Z,1556737110.119 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:30.318Z,1556737110.318 [CTD_NeilBrown](ERROR): Salinity reading out of range: 2114.907959 psu
2019-05-01T18:58:30.322Z,1556737110.322 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:30.533Z,1556737110.533 [CTD_NeilBrown](ERROR): Salinity reading out of range: 10490.908203 psu
2019-05-01T18:58:30.537Z,1556737110.537 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:30.749Z,1556737110.749 [CTD_NeilBrown](ERROR): Salinity reading out of range: 1787.849731 psu
2019-05-01T18:58:30.753Z,1556737110.753 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:30.966Z,1556737110.966 [CTD_NeilBrown](ERROR): Salinity reading out of range: 1702.546631 psu
2019-05-01T18:58:30.974Z,1556737110.974 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:31.011Z,1556737111.011 [CTD_Seabird](ERROR): Salinity reading out of range: 0.111868 psu
2019-05-01T18:58:31.181Z,1556737111.181 [CTD_NeilBrown](ERROR): Salinity reading out of range: 1586.634277 psu
2019-05-01T18:58:31.185Z,1556737111.185 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:31.397Z,1556737111.397 [CTD_NeilBrown](ERROR): Salinity reading out of range: 1793.675171 psu
2019-05-01T18:58:31.402Z,1556737111.402 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:31.758Z,1556737111.758 [CTD_NeilBrown](ERROR): Salinity reading out of range: 1430.782471 psu
2019-05-01T18:58:31.766Z,1556737111.766 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:31.963Z,1556737111.963 [CTD_NeilBrown](ERROR): Salinity reading out of range: 1776.509644 psu
2019-05-01T18:58:31.969Z,1556737111.969 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:31.979Z,1556737111.979 [DataOverHttps](IMPORTANT): SBD MTMSN=20190501T185827
2019-05-01T18:58:32.031Z,1556737112.031 [CTD_Seabird](ERROR): Salinity reading out of range: 0.109415 psu
2019-05-01T18:58:32.167Z,1556737112.167 [CTD_NeilBrown](ERROR): Salinity reading out of range: 1329.210327 psu
2019-05-01T18:58:32.171Z,1556737112.171 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:32.370Z,1556737112.370 [CTD_NeilBrown](ERROR): Salinity reading out of range: 2215.603271 psu
2019-05-01T18:58:32.375Z,1556737112.375 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:32.574Z,1556737112.574 [CTD_NeilBrown](ERROR): Salinity reading out of range: 1545.433350 psu
2019-05-01T18:58:32.579Z,1556737112.579 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:32.779Z,1556737112.779 [CTD_NeilBrown](ERROR): Salinity reading out of range: 2029.730469 psu
2019-05-01T18:58:32.783Z,1556737112.783 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:32.997Z,1556737112.997 [CTD_NeilBrown](ERROR): Salinity reading out of range: 1815.971436 psu
2019-05-01T18:58:33.001Z,1556737113.001 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:33.035Z,1556737113.035 [CTD_Seabird](ERROR): Salinity reading out of range: 0.111001 psu
2019-05-01T18:58:33.212Z,1556737113.212 [CTD_NeilBrown](ERROR): Salinity reading out of range: 1725.167847 psu
2019-05-01T18:58:33.216Z,1556737113.216 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:33.595Z,1556737113.595 [CTD_NeilBrown](ERROR): Salinity reading out of range: 1349.506104 psu
2019-05-01T18:58:33.599Z,1556737113.599 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:33.799Z,1556737113.799 [CTD_NeilBrown](ERROR): Salinity reading out of range: 2339.095215 psu
2019-05-01T18:58:33.803Z,1556737113.803 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:34.003Z,1556737114.003 [CTD_NeilBrown](ERROR): Salinity reading out of range: 1508.607544 psu
2019-05-01T18:58:34.012Z,1556737114.011 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:34.039Z,1556737114.039 [CTD_Seabird](ERROR): Salinity reading out of range: 0.111150 psu
2019-05-01T18:58:34.207Z,1556737114.207 [CTD_NeilBrown](ERROR): Salinity reading out of range: 1422.898071 psu
2019-05-01T18:58:34.211Z,1556737114.211 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:34.412Z,1556737114.412 [CTD_NeilBrown](ERROR): Salinity reading out of range: 1428.536011 psu
2019-05-01T18:58:34.416Z,1556737114.416 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:34.615Z,1556737114.615 [CTD_NeilBrown](ERROR): Salinity reading out of range: 2118.277832 psu
2019-05-01T18:58:34.619Z,1556737114.619 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:34.819Z,1556737114.819 [CTD_NeilBrown](ERROR): Salinity reading out of range: 1472.828125 psu
2019-05-01T18:58:34.823Z,1556737114.823 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:35.043Z,1556737115.043 [CTD_Seabird](ERROR): Salinity reading out of range: 0.109077 psu
2019-05-01T18:58:35.226Z,1556737115.226 [CTD_NeilBrown](ERROR): Salinity reading out of range: 1350.170654 psu
2019-05-01T18:58:35.231Z,1556737115.231 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:35.431Z,1556737115.431 [CTD_NeilBrown](ERROR): Salinity reading out of range: 1454.424072 psu
2019-05-01T18:58:35.435Z,1556737115.435 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:35.635Z,1556737115.635 [CTD_NeilBrown](ERROR): Salinity reading out of range: 1653.965454 psu
2019-05-01T18:58:35.639Z,1556737115.639 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:35.839Z,1556737115.839 [CTD_NeilBrown](ERROR): Salinity reading out of range: 1271.717773 psu
2019-05-01T18:58:35.843Z,1556737115.843 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:36.043Z,1556737116.043 [CTD_NeilBrown](ERROR): Salinity reading out of range: 1074.835815 psu
2019-05-01T18:58:36.047Z,1556737116.047 [CTD_Seabird](ERROR): Salinity reading out of range: 0.111768 psu
2019-05-01T18:58:36.052Z,1556737116.052 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:36.247Z,1556737116.247 [CTD_NeilBrown](ERROR): Salinity reading out of range: 1533.079956 psu
2019-05-01T18:58:36.251Z,1556737116.251 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:36.451Z,1556737116.451 [CTD_NeilBrown](ERROR): Salinity reading out of range: 1257.044556 psu
2019-05-01T18:58:36.481Z,1556737116.481 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:36.858Z,1556737116.858 [CTD_NeilBrown](ERROR): Salinity reading out of range: 1391.996216 psu
2019-05-01T18:58:36.901Z,1556737116.901 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:37.051Z,1556737117.051 [CTD_Seabird](ERROR): Salinity reading out of range: 0.111088 psu
2019-05-01T18:58:37.063Z,1556737117.063 [CTD_NeilBrown](ERROR): Salinity reading out of range: 1304.907471 psu
2019-05-01T18:58:37.068Z,1556737117.068 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:37.267Z,1556737117.267 [CTD_NeilBrown](ERROR): Salinity reading out of range: 1369.085815 psu
2019-05-01T18:58:37.270Z,1556737117.270 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:37.471Z,1556737117.471 [CTD_NeilBrown](ERROR): Salinity reading out of range: 1401.165527 psu
2019-05-01T18:58:37.477Z,1556737117.477 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:37.706Z,1556737117.706 [CTD_NeilBrown](ERROR): Salinity reading out of range: 1745.277222 psu
2019-05-01T18:58:37.710Z,1556737117.710 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:37.911Z,1556737117.911 [CTD_NeilBrown](ERROR): Salinity reading out of range: 1267.937744 psu
2019-05-01T18:58:37.915Z,1556737117.915 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:38.094Z,1556737118.094 [CTD_Seabird](ERROR): Salinity reading out of range: 0.111044 psu
2019-05-01T18:58:38.115Z,1556737118.115 [CTD_NeilBrown](ERROR): Salinity reading out of range: 1380.182373 psu
2019-05-01T18:58:38.119Z,1556737118.119 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:38.329Z,1556737118.329 [CTD_NeilBrown](ERROR): Salinity reading out of range: 1289.065552 psu
2019-05-01T18:58:38.333Z,1556737118.333 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:38.545Z,1556737118.545 [CTD_NeilBrown](ERROR): Salinity reading out of range: 1689.176147 psu
2019-05-01T18:58:38.549Z,1556737118.549 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:38.761Z,1556737118.761 [CTD_NeilBrown](ERROR): Salinity reading out of range: 1190.123901 psu
2019-05-01T18:58:38.765Z,1556737118.765 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:38.978Z,1556737118.978 [CTD_NeilBrown](ERROR): Salinity reading out of range: 995.090576 psu
2019-05-01T18:58:38.984Z,1556737118.984 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:39.094Z,1556737119.094 [CTD_Seabird](ERROR): Salinity reading out of range: 0.107903 psu
2019-05-01T18:58:39.338Z,1556737119.338 [CTD_NeilBrown](ERROR): Salinity reading out of range: 710.095093 psu
2019-05-01T18:58:39.342Z,1556737119.342 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:39.453Z,1556737119.453 [DataOverHttps](INFO): Received command:stop
2019-05-01T18:58:39.513Z,1556737119.513 [CommandLine](IMPORTANT): got command stop
2019-05-01T18:58:39.513Z,1556737119.513 [CommandLine](IMPORTANT): Scheduling is paused
2019-05-01T18:58:39.513Z,1556737119.513 [Supervisor](INFO): Stop Mission called by CommandLine::commandStop
2019-05-01T18:58:39.543Z,1556737119.543 [CTD_NeilBrown](ERROR): Salinity reading out of range: 1098.691162 psu
2019-05-01T18:58:39.546Z,1556737119.546 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:39.746Z,1556737119.746 [CTD_NeilBrown](ERROR): Salinity reading out of range: 1211.331543 psu
2019-05-01T18:58:39.750Z,1556737119.750 [CTD_NeilBrown](INFO): some bad data, not updating bins
2019-05-01T18:58:39.786Z,1556737119.786 [MissionManager](INFO): MissionManager is completed.
2019-05-01T18:58:39.786Z,1556737119.786 [MissionManager](INFO): Uninitializing Mission sci2
2019-05-01T18:58:39.786Z,1556737119.786 [sci2] Stopped
2019-05-01T18:58:39.786Z,1556737119.786 [sci2](DEBUG): Aggregate::uninitialize sci2
2019-05-01T18:58:39.786Z,1556737119.786 [sci2:Science] Stopped
2019-05-01T18:58:39.787Z,1556737119.787 [sci2:Science](DEBUG): Aggregate::uninitialize sci2:Science
2019-05-01T18:58:39.787Z,1556737119.787 [sci2:Science:C] Stopped
2019-05-01T18:58:39.787Z,1556737119.787 [sci2:Science:D] Stopped
2019-05-01T18:58:39.787Z,1556737119.787 [sci2:Science:G] Stopped
2019-05-01T18:58:39.787Z,1556737119.787 [sci2:Science:PeakDetectChl] Stopped
2019-05-01T18:58:39.787Z,1556737119.787 [sci2:Science:PeakDetectChl](DEBUG): Aggregate::uninitialize sci2:Science:PeakDetectChl
2019-05-01T18:58:39.787Z,1556737119.787 [sci2:Science:PeakDetectChl:A.PeakDetectVsDepth] Stopped
2019-05-01T18:58:39.787Z,1556737119.787 [sci2:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2019-05-01T18:58:39.787Z,1556737119.787 [sci2:NeedComms] Stopped
2019-05-01T18:58:39.787Z,1556737119.787 [sci2:NeedComms](DEBUG): Aggregate::uninitialize sci2:NeedComms
2019-05-01T18:58:39.787Z,1556737119.787 [sci2:NeedComms:B.GoToSurface] Stopped
2019-05-01T18:58:39.787Z,1556737119.787 [sci2:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-05-01T18:58:39.787Z,1556737119.787 [sci2:NeedComms:C] Stopped
2019-05-01T18:58:39.787Z,1556737119.787 [sci2:StandardEnvelopes] Stopped
2019-05-01T18:58:39.788Z,1556737119.788 [sci2:StandardEnvelopes](DEBUG): Aggregate::uninitialize sci2:StandardEnvelopes
2019-05-01T18:58:39.788Z,1556737119.788 [sci2:StandardEnvelopes:A.AltitudeEnvelope] Stopped
2019-05-01T18:58:39.788Z,1556737119.788 [sci2:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent.
2019-05-01T18:58:39.788Z,1556737119.788 [sci2:StandardEnvelopes:B.DepthEnvelope] Stopped
2019-05-01T18:58:39.788Z,1556737119.788 [sci2:StandardEnvelopes:B.DepthEnvelope](DEBUG): Uninitialize.
2019-05-01T18:58:39.788Z,1556737119.788 [sci2:StandardEnvelopes:C.OffshoreEnvelope] Stopped
2019-05-01T18:58:39.788Z,1556737119.788 [sci2:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Uninitialize OffshoreEnvelopeComponent.
2019-05-01T18:58:39.788Z,1556737119.788 [sci2:StartingMission] Stopped
2019-05-01T18:58:39.788Z,1556737119.788 [sci2:StartingMission](DEBUG): Aggregate::uninitialize sci2:StartingMission
2019-05-01T18:58:39.788Z,1556737119.788 [sci2:I.Pitch] Stopped
2019-05-01T18:58:39.788Z,1556737119.788 [sci2:J.Buoyancy] Stopped
2019-05-01T18:58:39.788Z,1556737119.788 [sci2:J.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2019-05-01T18:58:39.793Z,1556737119.793 [sci2:K.SetSpeed] Stopped
2019-05-01T18:58:39.793Z,1556737119.793 [sci2:K.SetSpeed](DEBUG): Uninitialize.
2019-05-01T18:58:39.793Z,1556737119.793 [sci2:L.DepthEnvelope] Stopped
2019-05-01T18:58:39.793Z,1556737119.793 [sci2:L.DepthEnvelope](DEBUG): Uninitialize.
2019-05-01T18:58:39.793Z,1556737119.793 [sci2:M.AltitudeEnvelope] Stopped
2019-05-01T18:58:39.793Z,1556737119.793 [sci2:M.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent.
2019-05-01T18:58:39.793Z,1556737119.793 [sci2:N.YoYo] Stopped
2019-05-01T18:58:39.793Z,1556737119.793 [sci2:N.YoYo](DEBUG): Uninitialize YoYoComponent.
2019-05-01T18:58:40.172Z,1556737120.172 [MissionManager](IMPORTANT): Started mission Default
2019-05-01T18:58:40.172Z,1556737120.172 [Default] Running Loop=1
2019-05-01T18:58:40.172Z,1556737120.172 [Default](DEBUG): Aggregate::initialize Default
2019-05-01T18:58:40.172Z,1556737120.172 [Default:B.GoToSurface] Running Loop=1
2019-05-01T18:58:40.172Z,1556737120.172 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-05-01T18:58:40.177Z,1556737120.177 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-05-01T18:58:40.177Z,1556737120.177 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-05-01T18:58:40.178Z,1556737120.178 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-05-01T18:58:40.178Z,1556737120.178 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-05-01T18:58:40.178Z,1556737120.178 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-05-01T18:58:40.179Z,1556737120.179 [Default:A.Wait] Running Loop=1
2019-05-01T18:58:40.179Z,1556737120.179 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-05-01T18:58:40.297Z,1556737120.297 [WetLabsBB2FL](INFO): Powering down
2019-05-01T18:58:52.638Z,1556737132.638 [NAL9602](INFO): SBD MO Status=2, MOMSN=11653, MT Status=2, MTMSN=0
2019-05-01T18:58:52.638Z,1556737132.638 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-05-01T18:58:53.478Z,1556737133.478 [Default:A.Wait](INFO): Done Waiting.
2019-05-01T18:58:53.478Z,1556737133.478 [Default:A.Wait] Stopped
2019-05-01T18:58:53.478Z,1556737133.478 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-05-01T18:58:53.899Z,1556737133.899 [Default:CheckIn] Running Loop=1
2019-05-01T18:58:53.899Z,1556737133.899 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-05-01T18:58:53.899Z,1556737133.899 [Default:CheckIn:Read_GPS] Running Loop=1
2019-05-01T18:59:11.628Z,1556737151.628 [NAL9602](INFO): SBD MO Status=2, MOMSN=11653, MT Status=2, MTMSN=0
2019-05-01T18:59:11.628Z,1556737151.628 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-05-01T18:59:22.968Z,1556737162.968 [NAL9602](INFO): SBD MO Status=0, MOMSN=11653, MT Status=0, MTMSN=0
2019-05-01T18:59:22.968Z,1556737162.968 [NAL9602](INFO): No messages in MT queue
2019-05-01T18:59:23.761Z,1556737163.761 [NAL9602](DEBUG): Fix Requested
2019-05-01T18:59:24.156Z,1556737164.156 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185919.00,A,3648.50701,N,12147.19700,W,9.097,250.64,010519,,,A*7B
2019-05-01T18:59:24.159Z,1556737164.159 [NAL9602](INFO): GPS fix at 20190501T185919: (36.808450, -121.786617)
2019-05-01T18:59:24.199Z,1556737164.199 [Default:CheckIn:Read_GPS] Stopped
2019-05-01T18:59:24.199Z,1556737164.199 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-05-01T18:59:30.932Z,1556737170.932 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190501T181743/Courier0017.lzma
2019-05-01T18:59:32.295Z,1556737172.295 [DataOverHttps](INFO): Moved sent file to Logs/20190501T181743/Courier0017.lzma.bak
2019-05-01T18:59:32.295Z,1556737172.295 [DataOverHttps](INFO): SBD MOMSN=10891216
2019-05-01T18:59:44.204Z,1556737184.204 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190501T181743/Courier0022.lzma
2019-05-01T18:59:45.010Z,1556737185.010 [DataOverHttps](INFO): Moved sent file to Logs/20190501T181743/Courier0022.lzma.bak
2019-05-01T18:59:45.010Z,1556737185.010 [DataOverHttps](INFO): SBD MOMSN=10891218
2019-05-01T18:59:56.470Z,1556737196.470 [NAL9602](INFO): Powering down
2019-05-01T18:59:58.000Z,1556737198.000 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190501T181743/Express0019.lzma
2019-05-01T18:59:58.806Z,1556737198.806 [DataOverHttps](INFO): Moved sent file to Logs/20190501T181743/Express0019.lzma.bak
2019-05-01T18:59:58.806Z,1556737198.806 [DataOverHttps](INFO): SBD MOMSN=10891220
2019-05-01T19:00:12.788Z,1556737212.788 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190501T181743/Express0023.lzma
2019-05-01T19:00:13.594Z,1556737213.594 [DataOverHttps](INFO): Moved sent file to Logs/20190501T181743/Express0023.lzma.bak
2019-05-01T19:00:13.594Z,1556737213.594 [DataOverHttps](INFO): SBD MOMSN=10891222
2019-05-01T19:00:16.308Z,1556737216.308 [Default:CheckIn:Read_Iridium] Stopped
2019-05-01T19:00:16.313Z,1556737216.313 [Default:CheckIn:C.Wait] Running Loop=1
2019-05-01T19:00:16.313Z,1556737216.313 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-05-01T19:01:29.423Z,1556737289.423 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-05-01T19:01:29.423Z,1556737289.423 [DVL_micro] Data Fault, FailCount= 1
2019-05-01T19:01:29.423Z,1556737289.423 [DVL_micro](ERROR): Data Fault
2019-05-01T19:01:29.478Z,1556737289.478 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-05-01T19:01:29.897Z,1556737289.897 [DVL_micro](INFO): uninitialize:Powering down
2019-05-01T19:01:30.675Z,1556737290.675 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-05-01T19:01:30.675Z,1556737290.675 [DVL_micro] No Fault, FailCount= 1
2019-05-01T19:01:31.053Z,1556737291.053 [DVL_micro](INFO): Initializing
2019-05-01T19:04:35.274Z,1556737475.274 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-05-01T19:04:35.274Z,1556737475.274 [DVL_micro] Data Fault, FailCount= 1
2019-05-01T19:04:35.275Z,1556737475.275 [DVL_micro](ERROR): Data Fault
2019-05-01T19:04:35.313Z,1556737475.313 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-05-01T19:04:35.753Z,1556737475.753 [DVL_micro](INFO): uninitialize:Powering down
2019-05-01T19:04:36.525Z,1556737476.525 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-05-01T19:04:36.526Z,1556737476.526 [DVL_micro] No Fault, FailCount= 1
2019-05-01T19:04:36.896Z,1556737476.896 [DVL_micro](INFO): Initializing
2019-05-01T19:05:16.914Z,1556737516.914 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-05-01T19:05:16.914Z,1556737516.914 [Default:CheckIn:C.Wait] Stopped
2019-05-01T19:05:16.914Z,1556737516.914 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-01T19:05:16.914Z,1556737516.914 [Default:CheckIn:D] Running Loop=1
2019-05-01T19:05:17.318Z,1556737517.318 [Default:CheckIn:D] Stopped
2019-05-01T19:05:17.318Z,1556737517.318 [Default:CheckIn:E] Running Loop=1
2019-05-01T19:05:17.725Z,1556737517.725 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 6.619099 min 
2019-05-01T19:05:17.725Z,1556737517.725 [Default:CheckIn:E] Stopped
2019-05-01T19:05:17.725Z,1556737517.725 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-05-01T19:05:17.725Z,1556737517.725 [Default:CheckIn] Stopped
2019-05-01T19:05:17.725Z,1556737517.725 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-05-01T19:05:17.726Z,1556737517.726 [Default:CheckIn](INFO): Running loop #2
2019-05-01T19:05:17.726Z,1556737517.726 [Default:CheckIn] Running Loop=2
2019-05-01T19:05:17.726Z,1556737517.726 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-05-01T19:05:17.726Z,1556737517.726 [Default:CheckIn:Read_GPS] Running Loop=1
2019-05-01T19:05:18.506Z,1556737518.506 [NAL9602](INFO): Powering up
2019-05-01T19:05:29.410Z,1556737529.410 [NAL9602](INFO): NAL9602 initialized
2019-05-01T19:05:30.233Z,1556737530.233 [NAL9602](DEBUG): Fix Requested
2019-05-01T19:05:53.252Z,1556737553.252 [NAL9602](INFO): SBD MO Status=2, MOMSN=11654, MT Status=2, MTMSN=0
2019-05-01T19:05:53.252Z,1556737553.252 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-05-01T19:06:28.416Z,1556737588.416 [ElevatorOffsetCalculator](INFO): New estimator for commanded vars: speed 1.00 m/s, pitch 30.00 deg, mass-position -35.00 mm (1 active estimators).
2019-05-01T19:06:40.211Z,1556737600.211 [DVL_micro](ERROR): checksum mismatch: reported98 , calculated:112
2019-05-01T19:06:40.211Z,1556737600.211 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 1 1 1 37.4 41.9 38.9 34.8 -27.8 -155.6 -16.7 3 -225 -101 42 4 7 6 8 -14.8 -343.4 -26.6 1 276.5 -203.8 29.0 1 50 -356 -93 2 324 -156 -93 2 -9.38 -2.95 56.1 34.8 19.4 0.005 35.0 1489 98
2019-05-01T19:07:03.078Z,1556737623.078 [DataOverHttps](IMPORTANT): SBD MTMSN=20190501T190657
2019-05-01T19:07:08.732Z,1556737628.732 [DataOverHttps](INFO): Received command:restart logs