2019-08-06T22:54:25.767Z,1565132065.767 [Supervisor](DEBUG): Initializing supervisor.
2019-08-06T22:54:25.770Z,1565132065.770 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2019-08-06T22:54:25.771Z,1565132065.771 [SyncHandler](INFO): Protected caller Thread ID is 807
2019-08-06T22:54:25.771Z,1565132065.771 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2019-08-06T22:54:25.772Z,1565132065.772 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2019-08-06T22:54:25.772Z,1565132065.772 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 808
2019-08-06T22:54:25.775Z,1565132065.775 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2019-08-06T22:54:25.786Z,1565132065.786 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2019-08-06T22:54:25.787Z,1565132065.787 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2019-08-06T22:54:25.788Z,1565132065.788 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 809
2019-08-06T22:54:25.789Z,1565132065.789 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2019-08-06T22:54:25.790Z,1565132065.790 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2019-08-06T22:54:25.790Z,1565132065.790 [logger ThreadHandler](INFO): Protected caller Thread ID is 810
2019-08-06T22:54:25.792Z,1565132065.792 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2019-08-06T22:54:25.792Z,1565132065.792 [Supervisor](INFO): Looking for Config files in directory: Config/
2019-08-06T22:54:25.797Z,1565132065.797 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2019-08-06T22:54:26.015Z,1565132066.015 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2019-08-06T22:54:26.017Z,1565132066.017 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2019-08-06T22:54:26.100Z,1565132066.100 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2019-08-06T22:54:26.574Z,1565132066.574 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2019-08-06T22:54:26.576Z,1565132066.576 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2019-08-06T22:54:26.946Z,1565132066.946 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2019-08-06T22:54:26.947Z,1565132066.947 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2019-08-06T22:54:27.045Z,1565132067.045 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2019-08-06T22:54:27.047Z,1565132067.047 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2019-08-06T22:54:27.374Z,1565132067.374 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2019-08-06T22:54:27.375Z,1565132067.375 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2019-08-06T22:54:27.584Z,1565132067.584 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2019-08-06T22:54:27.585Z,1565132067.585 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2019-08-06T22:54:28.079Z,1565132068.079 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2019-08-06T22:54:28.080Z,1565132068.080 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2019-08-06T22:54:28.189Z,1565132068.189 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2019-08-06T22:54:28.191Z,1565132068.191 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2019-08-06T22:54:28.294Z,1565132068.294 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2019-08-06T22:54:28.295Z,1565132068.295 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2019-08-06T22:54:28.954Z,1565132068.954 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2019-08-06T22:54:28.955Z,1565132068.955 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2019-08-06T22:54:29.582Z,1565132069.582 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2019-08-06T22:54:29.582Z,1565132069.582 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2019-08-06T22:54:30.120Z,1565132070.120 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2019-08-06T22:54:30.122Z,1565132070.122 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2019-08-06T22:54:30.275Z,1565132070.275 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2019-08-06T22:54:30.277Z,1565132070.277 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2019-08-06T22:54:30.435Z,1565132070.435 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2019-08-06T22:54:30.437Z,1565132070.437 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2019-08-06T22:54:30.441Z,1565132070.441 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2019-08-06T22:54:30.535Z,1565132070.535 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2019-08-06T22:54:30.622Z,1565132070.622 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2019-08-06T22:54:30.730Z,1565132070.730 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2019-08-06T22:54:30.815Z,1565132070.815 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2019-08-06T22:54:30.915Z,1565132070.915 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2019-08-06T22:54:31.020Z,1565132071.020 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2019-08-06T22:54:31.255Z,1565132071.255 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2019-08-06T22:54:31.332Z,1565132071.332 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2019-08-06T22:54:31.515Z,1565132071.515 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2019-08-06T22:54:31.660Z,1565132071.660 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2019-08-06T22:54:31.785Z,1565132071.785 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg
2019-08-06T22:54:32.024Z,1565132072.024 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2019-08-06T22:54:32.025Z,1565132072.025 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2019-08-06T22:54:32.040Z,1565132072.040 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2019-08-06T22:54:32.130Z,1565132072.130 [VerticalControl](DEBUG): Construct VerticalControl.
2019-08-06T22:54:32.248Z,1565132072.248 [VerticalControl] Loaded
2019-08-06T22:54:32.248Z,1565132072.248 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2019-08-06T22:54:32.249Z,1565132072.249 [HorizontalControl](DEBUG): Construct HorizontalControl.
2019-08-06T22:54:32.320Z,1565132072.320 [HorizontalControl] Loaded
2019-08-06T22:54:32.320Z,1565132072.320 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2019-08-06T22:54:32.321Z,1565132072.321 [SpeedControl](DEBUG): Construct SpeedControl.
2019-08-06T22:54:32.327Z,1565132072.327 [SpeedControl] Loaded
2019-08-06T22:54:32.327Z,1565132072.327 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2019-08-06T22:54:32.328Z,1565132072.328 [LoopControl](DEBUG): Construct LoopControl.
2019-08-06T22:54:32.328Z,1565132072.328 [LoopControl] Loaded
2019-08-06T22:54:32.329Z,1565132072.329 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2019-08-06T22:54:32.329Z,1565132072.329 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2019-08-06T22:54:32.331Z,1565132072.331 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2019-08-06T22:54:32.355Z,1565132072.355 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2019-08-06T22:54:32.355Z,1565132072.355 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2019-08-06T22:54:32.483Z,1565132072.483 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2019-08-06T22:54:32.483Z,1565132072.483 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2019-08-06T22:54:32.635Z,1565132072.635 [BuoyancyServo] Loaded
2019-08-06T22:54:32.635Z,1565132072.635 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2019-08-06T22:54:32.647Z,1565132072.647 [ElevatorServo] Loaded
2019-08-06T22:54:32.647Z,1565132072.647 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2019-08-06T22:54:32.659Z,1565132072.659 [MassServo] Loaded
2019-08-06T22:54:32.659Z,1565132072.659 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2019-08-06T22:54:32.671Z,1565132072.671 [RudderServo] Loaded
2019-08-06T22:54:32.671Z,1565132072.671 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2019-08-06T22:54:32.683Z,1565132072.683 [ThrusterServo] Loaded
2019-08-06T22:54:32.683Z,1565132072.683 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2019-08-06T22:54:32.683Z,1565132072.683 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2019-08-06T22:54:32.684Z,1565132072.684 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2019-08-06T22:54:32.813Z,1565132072.813 [DeadReckonUsingMultipleVelocitySources] Loaded
2019-08-06T22:54:32.813Z,1565132072.813 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2019-08-06T22:54:32.835Z,1565132072.835 [NavChart] Loaded
2019-08-06T22:54:32.835Z,1565132072.835 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2019-08-06T22:54:32.839Z,1565132072.839 [UniversalFixResidualReporter] Loaded
2019-08-06T22:54:32.839Z,1565132072.839 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2019-08-06T22:54:32.840Z,1565132072.840 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2019-08-06T22:54:32.840Z,1565132072.840 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2019-08-06T22:54:32.954Z,1565132072.954 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2019-08-06T22:54:32.955Z,1565132072.955 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2019-08-06T22:54:33.649Z,1565132073.649 [AHRS_M2] Loaded
2019-08-06T22:54:33.649Z,1565132073.649 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2019-08-06T22:54:33.793Z,1565132073.793 [DataOverHttps] Loaded
2019-08-06T22:54:33.793Z,1565132073.793 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2019-08-06T22:54:33.794Z,1565132073.794 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4087D4E0
2019-08-06T22:54:33.794Z,1565132073.794 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 892
2019-08-06T22:54:33.808Z,1565132073.808 [Depth_Keller] Loaded
2019-08-06T22:54:33.809Z,1565132073.809 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2019-08-06T22:54:33.814Z,1565132073.814 [DropWeight] Loaded
2019-08-06T22:54:33.814Z,1565132073.814 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2019-08-06T22:54:33.916Z,1565132073.916 [NAL9602] Loaded
2019-08-06T22:54:33.916Z,1565132073.916 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2019-08-06T22:54:33.933Z,1565132073.933 [Onboard] Loaded
2019-08-06T22:54:33.933Z,1565132073.933 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2019-08-06T22:54:33.936Z,1565132073.936 [Radio_Surface] Loaded
2019-08-06T22:54:33.937Z,1565132073.937 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2019-08-06T22:54:33.938Z,1565132073.938 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408AD4E0
2019-08-06T22:54:33.938Z,1565132073.938 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 893
2019-08-06T22:54:36.121Z,1565132076.121 [BPC1] Loaded
2019-08-06T22:54:36.122Z,1565132076.122 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2019-08-06T22:54:36.122Z,1565132076.122 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2019-08-06T22:54:36.123Z,1565132076.123 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2019-08-06T22:54:36.180Z,1565132076.180 [DepthRateCalculator] Loaded
2019-08-06T22:54:36.180Z,1565132076.180 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2019-08-06T22:54:36.186Z,1565132076.186 [PitchRateCalculator] Loaded
2019-08-06T22:54:36.186Z,1565132076.186 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2019-08-06T22:54:36.198Z,1565132076.198 [SpeedCalculator] Loaded
2019-08-06T22:54:36.198Z,1565132076.198 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2019-08-06T22:54:36.221Z,1565132076.221 [TempGradientCalculator] Loaded
2019-08-06T22:54:36.221Z,1565132076.221 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2019-08-06T22:54:36.226Z,1565132076.226 [YawRateCalculator] Loaded
2019-08-06T22:54:36.227Z,1565132076.227 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2019-08-06T22:54:36.257Z,1565132076.257 [ElevatorOffsetCalculator] Loaded
2019-08-06T22:54:36.257Z,1565132076.257 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2019-08-06T22:54:36.258Z,1565132076.258 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2019-08-06T22:54:36.260Z,1565132076.260 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2019-08-06T22:54:36.521Z,1565132076.521 [Aanderaa_O2] Loaded
2019-08-06T22:54:36.522Z,1565132076.522 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2019-08-06T22:54:36.534Z,1565132076.534 [CANONSampler] Loaded
2019-08-06T22:54:36.534Z,1565132076.534 [ComponentRegistry](DEBUG): SyncComponent "CANONSampler" handled in the control thread.
2019-08-06T22:54:36.621Z,1565132076.621 [CTD_NeilBrown] Loaded
2019-08-06T22:54:36.622Z,1565132076.622 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2019-08-06T22:54:36.623Z,1565132076.623 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 409AF4E0
2019-08-06T22:54:36.623Z,1565132076.623 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 894
2019-08-06T22:54:36.633Z,1565132076.633 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density
2019-08-06T22:54:36.638Z,1565132076.638 [CTD_Seabird](INFO): created writer for : sea_water_density
2019-08-06T22:54:36.639Z,1565132076.639 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth
2019-08-06T22:54:36.644Z,1565132076.644 [CTD_Seabird](INFO): created writer for : depth
2019-08-06T22:54:36.645Z,1565132076.645 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure
2019-08-06T22:54:36.650Z,1565132076.650 [CTD_Seabird](INFO): created writer for : sea_water_pressure
2019-08-06T22:54:36.651Z,1565132076.651 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity
2019-08-06T22:54:36.656Z,1565132076.656 [CTD_Seabird](INFO): created writer for : sea_water_salinity
2019-08-06T22:54:36.656Z,1565132076.656 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature
2019-08-06T22:54:36.662Z,1565132076.662 [CTD_Seabird](INFO): created writer for : sea_water_temperature
2019-08-06T22:54:36.663Z,1565132076.663 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity
2019-08-06T22:54:36.668Z,1565132076.668 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity
2019-08-06T22:54:36.668Z,1565132076.668 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water
2019-08-06T22:54:36.673Z,1565132076.673 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water
2019-08-06T22:54:36.701Z,1565132076.701 [CTD_Seabird] Loaded
2019-08-06T22:54:36.702Z,1565132076.702 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2019-08-06T22:54:36.703Z,1565132076.703 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 409DF4E0
2019-08-06T22:54:36.703Z,1565132076.703 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 895
2019-08-06T22:54:36.718Z,1565132076.718 [PAR_Licor] Loaded
2019-08-06T22:54:36.719Z,1565132076.719 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2019-08-06T22:54:36.768Z,1565132076.768 [WetLabsBB2FL] Loaded
2019-08-06T22:54:36.768Z,1565132076.768 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2019-08-06T22:54:36.770Z,1565132076.770 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40A0F4E0
2019-08-06T22:54:36.770Z,1565132076.770 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 896
2019-08-06T22:54:36.771Z,1565132076.771 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2019-08-06T22:54:36.771Z,1565132076.771 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2019-08-06T22:54:36.821Z,1565132076.821 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2019-08-06T22:54:36.821Z,1565132076.821 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2019-08-06T22:54:37.176Z,1565132077.176 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2019-08-06T22:54:37.176Z,1565132077.176 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2019-08-06T22:54:37.342Z,1565132077.342 [SBIT](DEBUG): Construct Startup Built In Test.
2019-08-06T22:54:37.353Z,1565132077.353 [SBIT] Loaded
2019-08-06T22:54:37.354Z,1565132077.354 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2019-08-06T22:54:37.354Z,1565132077.354 [IBIT](DEBUG): Construct Initiated Built In Test.
2019-08-06T22:54:37.366Z,1565132077.366 [IBIT] Loaded
2019-08-06T22:54:37.367Z,1565132077.367 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2019-08-06T22:54:37.370Z,1565132077.370 [CBIT](DEBUG): Construct Continuous Built In Test.
2019-08-06T22:54:37.514Z,1565132077.514 [CBIT] Loaded
2019-08-06T22:54:37.514Z,1565132077.514 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2019-08-06T22:54:37.514Z,1565132077.514 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2019-08-06T22:54:37.518Z,1565132077.518 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2019-08-06T22:54:37.519Z,1565132077.519 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2019-08-06T22:54:37.526Z,1565132077.526 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2019-08-06T22:54:37.527Z,1565132077.527 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B0E4E0
2019-08-06T22:54:37.527Z,1565132077.527 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 897
2019-08-06T22:54:37.532Z,1565132077.532 [Supervisor](INFO): Main Thread ID is 803
2019-08-06T22:54:37.532Z,1565132077.532 [Supervisor](DEBUG): Running supervisor.
2019-08-06T22:54:37.533Z,1565132077.533 [CommandLine ThreadHandler](INFO): Handler Thread ID is 898
2019-08-06T22:54:37.535Z,1565132077.535 [controlThread ThreadHandler](INFO): Handler Thread ID is 899
2019-08-06T22:54:37.535Z,1565132077.535 [controlThread](DEBUG): Initializing ControlThread
2019-08-06T22:54:37.536Z,1565132077.536 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2019-08-06T22:54:37.538Z,1565132077.538 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2019-08-06T22:54:37.539Z,1565132077.539 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2019-08-06T22:54:37.539Z,1565132077.539 [LoopControl](DEBUG): Initialize LoopControlComponent.
2019-08-06T22:54:37.541Z,1565132077.541 [NavChart](DEBUG): Initialize NavChart Navigation.
2019-08-06T22:54:37.541Z,1565132077.541 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2019-08-06T22:54:37.547Z,1565132077.547 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2019-08-06T22:54:37.547Z,1565132077.547 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2019-08-06T22:54:37.548Z,1565132077.548 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2019-08-06T22:54:37.548Z,1565132077.548 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2019-08-06T22:54:37.548Z,1565132077.548 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2019-08-06T22:54:37.549Z,1565132077.549 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2019-08-06T22:54:37.553Z,1565132077.553 [SBIT](INFO): Initialize SBIT Component.
2019-08-06T22:54:37.554Z,1565132077.554 [SBIT](IMPORTANT): git: 2019-07-26-1-g6ad825a
2019-08-06T22:54:37.554Z,1565132077.554 [SBIT](INFO): git hash: 6ad825a153e96bf2505e39e5df4d606652139ef6
2019-08-06T22:54:37.554Z,1565132077.554 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2019-08-06T22:54:37.555Z,1565132077.555 [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-08-06T22:54:37.556Z,1565132077.556 [SBIT](INFO): Beginning SBIT in 36.000000 seconds.
2019-08-06T22:54:37.557Z,1565132077.557 [IBIT](INFO): Initialize IBIT Component.
2019-08-06T22:54:37.558Z,1565132077.558 [CBIT](DEBUG): Initialize CBIT Component.
2019-08-06T22:54:37.559Z,1565132077.559 [logger ThreadHandler](INFO): Handler Thread ID is 900
2019-08-06T22:54:37.569Z,1565132077.569 [CBIT](DEBUG): Initialized mux pins.
2019-08-06T22:54:37.569Z,1565132077.569 [CBIT](DEBUG): Initializing the watchdog timer.
2019-08-06T22:54:37.577Z,1565132077.577 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 901
2019-08-06T22:54:37.578Z,1565132077.578 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2019-08-06T22:54:37.590Z,1565132077.590 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 902
2019-08-06T22:54:37.593Z,1565132077.593 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2019-08-06T22:54:37.593Z,1565132077.593 [CBIT](DEBUG): Initializing heartbeat.
2019-08-06T22:54:37.601Z,1565132077.601 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 903
2019-08-06T22:54:37.602Z,1565132077.602 [CTD_NeilBrown](INFO): Powering down
2019-08-06T22:54:37.629Z,1565132077.629 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 904
2019-08-06T22:54:37.630Z,1565132077.630 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2019-08-06T22:54:37.634Z,1565132077.634 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 906
2019-08-06T22:54:37.635Z,1565132077.635 [WetLabsBB2FL](INFO): Powering down
2019-08-06T22:54:37.659Z,1565132077.659 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20
2019-08-06T22:54:37.662Z,1565132077.662 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 907
2019-08-06T22:54:37.665Z,1565132077.665 [CBIT](DEBUG): Deactivating GF circuits.
2019-08-06T22:54:37.665Z,1565132077.665 [CBIT](DEBUG): Deactivating emergency mode.
2019-08-06T22:54:37.671Z,1565132077.671 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2019-08-06T22:54:37.671Z,1565132077.671 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2019-08-06T22:54:37.671Z,1565132077.671 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2019-08-06T22:54:37.671Z,1565132077.671 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2019-08-06T22:54:37.671Z,1565132077.671 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2019-08-06T22:54:37.672Z,1565132077.672 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2019-08-06T22:54:37.672Z,1565132077.672 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2019-08-06T22:54:37.672Z,1565132077.672 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2019-08-06T22:54:37.672Z,1565132077.672 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2019-08-06T22:54:37.672Z,1565132077.672 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2019-08-06T22:54:37.673Z,1565132077.673 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2019-08-06T22:54:37.673Z,1565132077.673 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2019-08-06T22:54:37.674Z,1565132077.674 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2019-08-06T22:54:37.674Z,1565132077.674 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2019-08-06T22:54:37.674Z,1565132077.674 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2019-08-06T22:54:37.674Z,1565132077.674 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2019-08-06T22:54:37.701Z,1565132077.701 [CBIT](DEBUG): Backplane powered.
2019-08-06T22:54:37.702Z,1565132077.702 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2019-08-06T22:54:37.733Z,1565132077.733 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2019-08-06T22:54:37.760Z,1565132077.760 [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-08-06T22:54:37.761Z,1565132077.761 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2019-08-06T22:54:37.835Z,1565132077.835 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2019-08-06T22:54:37.836Z,1565132077.836 [Default:A.Wait](DEBUG): Construct Wait.
2019-08-06T22:54:37.838Z,1565132077.838 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2019-08-06T22:54:37.856Z,1565132077.856 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2019-08-06T22:54:37.879Z,1565132077.879 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2019-08-06T22:54:37.884Z,1565132077.884 [Default:E.Execute](DEBUG): Construct Execute.
2019-08-06T22:54:37.902Z,1565132077.902 [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-08-06T22:54:37.921Z,1565132077.921 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,NAL9602,Onboard,BPC1,Aanderaa_O2,CANONSampler,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-08-06T22:54:37.933Z,1565132077.933 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2019-08-06T22:54:37.993Z,1565132077.993 [Radio_Surface](INFO): Powering up
2019-08-06T22:54:38.145Z,1565132078.145 [CANONSampler](INFO): Powering down
2019-08-06T22:54:38.358Z,1565132078.358 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2019-08-06T22:54:38.365Z,1565132078.365 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2019-08-06T22:54:38.366Z,1565132078.366 [ElevatorServo](DEBUG): Initializing EZServoServo.
2019-08-06T22:54:38.373Z,1565132078.373 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2019-08-06T22:54:38.374Z,1565132078.374 [MassServo](DEBUG): Initializing EZServoServo.
2019-08-06T22:54:38.381Z,1565132078.381 [MassServo](DEBUG): Initializing MassServo.
2019-08-06T22:54:38.382Z,1565132078.382 [RudderServo](DEBUG): Initializing EZServoServo.
2019-08-06T22:54:38.389Z,1565132078.389 [RudderServo](DEBUG): Initializing RudderServo.
2019-08-06T22:54:38.390Z,1565132078.390 [ThrusterServo](DEBUG): Initializing EZServoServo.
2019-08-06T22:54:38.398Z,1565132078.398 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2019-08-06T22:54:41.453Z,1565132081.453 [Aanderaa_O2](INFO): Powering down
2019-08-06T22:54:45.665Z,1565132085.665 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit.
2019-08-06T22:55:04.294Z,1565132104.294 [NAL9602](INFO): Powering up NAL9602
2019-08-06T22:55:14.042Z,1565132114.042 [SBIT](IMPORTANT): Beginning Startup BIT
2019-08-06T22:55:14.050Z,1565132114.050 [CBIT](IMPORTANT): Beginning ground fault scan
2019-08-06T22:55:15.198Z,1565132115.198 [NAL9602](INFO): NAL9602 initialized
2019-08-06T22:55:16.021Z,1565132116.021 [NAL9602](DEBUG): Fix Requested
2019-08-06T22:55:25.083Z,1565132125.083 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): -0.005722
CHAN A1 (24V): -0.198437
CHAN A2 (12V): -0.002409
CHAN A3 (5V): -0.001516
CHAN B0 (3.3V): 0.000051
CHAN B1 (3.15aV): 0.000507
CHAN B2 (3.15bV): -0.000334
CHAN B3 (GND): 0.000308
OPEN: -0.000280
Full Scale Calc: 4.765 mA, -1.589 mA
2019-08-06T22:55:33.964Z,1565132133.964 [NAL9602](INFO): SBD MO Status=0, MOMSN=15850, MT Status=0, MTMSN=0
2019-08-06T22:55:33.964Z,1565132133.964 [NAL9602](INFO): No messages in MT queue
2019-08-06T22:55:34.781Z,1565132134.781 [NAL9602](DEBUG): Fix Requested
2019-08-06T22:55:37.609Z,1565132137.609 [NAL9602](DEBUG): Fix Requested
2019-08-06T22:55:40.448Z,1565132140.448 [NAL9602](DEBUG): Fix Requested
2019-08-06T22:55:43.669Z,1565132143.669 [NAL9602](DEBUG): Fix Requested
2019-08-06T22:55:46.501Z,1565132146.501 [NAL9602](DEBUG): Fix Requested
2019-08-06T22:55:49.725Z,1565132149.725 [NAL9602](DEBUG): Fix Requested
2019-08-06T22:55:52.553Z,1565132152.553 [NAL9602](DEBUG): Fix Requested
2019-08-06T22:55:55.385Z,1565132155.385 [NAL9602](DEBUG): Fix Requested
2019-08-06T22:55:58.725Z,1565132158.725 [NAL9602](DEBUG): Fix Requested
2019-08-06T22:56:01.553Z,1565132161.553 [NAL9602](DEBUG): Fix Requested
2019-08-06T22:56:04.377Z,1565132164.377 [NAL9602](DEBUG): Fix Requested
2019-08-06T22:56:07.617Z,1565132167.617 [NAL9602](DEBUG): Fix Requested
2019-08-06T22:56:07.651Z,1565132167.651 [SBIT](IMPORTANT): SBIT PASSED
2019-08-06T22:56:07.682Z,1565132167.682 [CommandLine](IMPORTANT): got command configSet list
2019-08-06T22:56:07.682Z,1565132167.682 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2019-08-06T22:56:07.683Z,1565132167.683 [CommandLine](IMPORTANT): CANONSampler.loadAtStartup=1 bool;

2019-08-06T22:56:07.683Z,1565132167.683 [CommandLine](IMPORTANT): CBIT.gf24Offset=172 microampere;

2019-08-06T22:56:07.683Z,1565132167.683 [CommandLine](IMPORTANT): DAT.ignoreElevationAngle=1 bool;

2019-08-06T22:56:07.683Z,1565132167.683 [CommandLine](IMPORTANT): DAT.loadAtStartup=0 bool;

2019-08-06T22:56:07.683Z,1565132167.683 [CommandLine](IMPORTANT): DVL_micro.loadAtStartup=0 bool;

2019-08-06T22:56:07.684Z,1565132167.684 [CommandLine](IMPORTANT): ESPComponent.loadAtStartup=0 bool;

2019-08-06T22:56:07.684Z,1565132167.684 [CommandLine](IMPORTANT): NAL9602.fastGPSFix=1 bool;

2019-08-06T22:56:07.684Z,1565132167.684 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=200 cubic_centimeter;

2019-08-06T22:56:07.684Z,1565132167.684 [CommandLine](IMPORTANT): VerticalControl.massDefault=-4 millimeter;

2019-08-06T22:56:07.684Z,1565132167.684 [CommandLine](IMPORTANT): VerticalControl.massPositionLimitAft=-31 millimeter;

2019-08-06T22:56:07.684Z,1565132167.684 [CommandLine](IMPORTANT): VerticalControl.massPositionLimitFwd=30 millimeter;

2019-08-06T22:56:08.055Z,1565132168.055 [MissionManager](IMPORTANT): Started mission Startup
2019-08-06T22:56:08.055Z,1565132168.055 [Startup] Running Loop=1
2019-08-06T22:56:08.055Z,1565132168.055 [Startup](DEBUG): Aggregate::initialize Startup
2019-08-06T22:56:08.055Z,1565132168.055 [Startup:A.GoToSurface] Running Loop=1
2019-08-06T22:56:08.056Z,1565132168.056 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-08-06T22:56:08.056Z,1565132168.056 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-08-06T22:56:08.057Z,1565132168.057 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-08-06T22:56:08.057Z,1565132168.057 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-08-06T22:56:08.058Z,1565132168.058 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-08-06T22:56:08.058Z,1565132168.058 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-08-06T22:56:08.059Z,1565132168.059 [Startup:StartupSatComms] Running Loop=1
2019-08-06T22:56:08.059Z,1565132168.059 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2019-08-06T22:56:08.059Z,1565132168.059 [Startup:StartupSatComms:A] Running Loop=1
2019-08-06T22:56:08.459Z,1565132168.459 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2019-08-06T22:56:10.437Z,1565132170.437 [NAL9602](DEBUG): Fix Requested
2019-08-06T22:56:13.673Z,1565132173.673 [NAL9602](DEBUG): Fix Requested
2019-08-06T22:56:16.501Z,1565132176.501 [NAL9602](DEBUG): Fix Requested
2019-08-06T22:56:19.733Z,1565132179.733 [NAL9602](DEBUG): Fix Requested
2019-08-06T22:56:22.561Z,1565132182.561 [NAL9602](DEBUG): Fix Requested
2019-08-06T22:56:25.789Z,1565132185.789 [NAL9602](DEBUG): Fix Requested
2019-08-06T22:56:28.621Z,1565132188.621 [NAL9602](DEBUG): Fix Requested
2019-08-06T22:56:31.449Z,1565132191.449 [NAL9602](DEBUG): Fix Requested
2019-08-06T22:56:34.677Z,1565132194.677 [NAL9602](DEBUG): Fix Requested
2019-08-06T22:56:37.513Z,1565132197.513 [NAL9602](DEBUG): Fix Requested
2019-08-06T22:56:40.745Z,1565132200.745 [NAL9602](DEBUG): Fix Requested
2019-08-06T22:56:43.569Z,1565132203.569 [NAL9602](DEBUG): Fix Requested
2019-08-06T22:56:46.797Z,1565132206.797 [NAL9602](DEBUG): Fix Requested
2019-08-06T22:56:49.629Z,1565132209.629 [NAL9602](DEBUG): Fix Requested
2019-08-06T22:56:52.857Z,1565132212.857 [NAL9602](DEBUG): Fix Requested
2019-08-06T22:56:55.689Z,1565132215.689 [NAL9602](DEBUG): Fix Requested
2019-08-06T22:56:58.917Z,1565132218.917 [NAL9602](DEBUG): Fix Requested
2019-08-06T22:57:01.745Z,1565132221.745 [NAL9602](DEBUG): Fix Requested
2019-08-06T22:57:04.577Z,1565132224.577 [NAL9602](DEBUG): Fix Requested
2019-08-06T22:57:07.805Z,1565132227.805 [NAL9602](DEBUG): Fix Requested
2019-08-06T22:57:08.250Z,1565132228.250 [Startup:StartupSatComms:A](INFO): Timed out from 2019-08-06T22:56:08.1Z
2019-08-06T22:57:08.251Z,1565132228.251 [Startup:StartupSatComms:A] Stopped
2019-08-06T22:57:08.251Z,1565132228.251 [Startup:StartupSatComms:B] Running Loop=1
2019-08-06T22:57:08.652Z,1565132228.652 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-08-06T22:57:33.712Z,1565132253.712 [NAL9602](INFO): SBD MO Status=2, MOMSN=15851, MT Status=2, MTMSN=0
2019-08-06T22:57:33.712Z,1565132253.712 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-08-06T22:57:34.529Z,1565132254.529 [NAL9602](DEBUG): Fix Requested
2019-08-06T22:57:34.924Z,1565132254.924 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,225630.00,A,3648.16769,N,12147.28216,W,0.486,0.00,060819,,,A*78
2019-08-06T22:57:34.927Z,1565132254.927 [NAL9602](INFO): GPS fix at 20190806T225630: (36.802795, -121.788036)
2019-08-06T22:58:04.236Z,1565132284.236 [NAL9602](INFO): SBD MO Status=2, MOMSN=15851, MT Status=2, MTMSN=0
2019-08-06T22:58:04.236Z,1565132284.236 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-08-06T22:58:08.305Z,1565132288.305 [Startup:StartupSatComms:B](INFO): Timed out from 2019-08-06T22:57:08.3Z
2019-08-06T22:58:08.305Z,1565132288.305 [Startup:StartupSatComms:B] Stopped
2019-08-06T22:58:08.305Z,1565132288.305 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2019-08-06T22:58:08.305Z,1565132288.305 [Startup:StartupSatComms] Stopped
2019-08-06T22:58:08.306Z,1565132288.306 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2019-08-06T22:58:08.306Z,1565132288.306 [Startup](INFO): Completed Startup
2019-08-06T22:58:08.306Z,1565132288.306 [MissionManager](INFO): Startup is completed.
2019-08-06T22:58:08.307Z,1565132288.307 [MissionManager](INFO): Uninitializing Mission Startup
2019-08-06T22:58:08.307Z,1565132288.307 [Startup] Stopped
2019-08-06T22:58:08.307Z,1565132288.307 [Startup](DEBUG): Aggregate::uninitialize Startup
2019-08-06T22:58:08.307Z,1565132288.307 [Startup:A.GoToSurface] Stopped
2019-08-06T22:58:08.307Z,1565132288.307 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-08-06T22:58:08.725Z,1565132288.725 [MissionManager](IMPORTANT): Started mission Default
2019-08-06T22:58:08.725Z,1565132288.725 [Default] Running Loop=1
2019-08-06T22:58:08.725Z,1565132288.725 [Default](DEBUG): Aggregate::initialize Default
2019-08-06T22:58:08.726Z,1565132288.726 [Default:B.GoToSurface] Running Loop=1
2019-08-06T22:58:08.726Z,1565132288.726 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-08-06T22:58:08.726Z,1565132288.726 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-08-06T22:58:08.726Z,1565132288.726 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-08-06T22:58:08.726Z,1565132288.726 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-08-06T22:58:08.727Z,1565132288.727 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-08-06T22:58:08.727Z,1565132288.727 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-08-06T22:58:08.727Z,1565132288.727 [Default:A.Wait] Running Loop=1
2019-08-06T22:58:08.727Z,1565132288.727 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-08-06T22:58:09.411Z,1565132289.411 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004437
2019-08-06T22:58:21.806Z,1565132301.806 [Default:A.Wait](INFO): Done Waiting.
2019-08-06T22:58:21.806Z,1565132301.806 [Default:A.Wait] Stopped
2019-08-06T22:58:21.806Z,1565132301.806 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-08-06T22:58:22.209Z,1565132302.209 [Default:CheckIn] Running Loop=1
2019-08-06T22:58:22.209Z,1565132302.209 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-08-06T22:58:22.210Z,1565132302.210 [Default:CheckIn:Read_GPS] Running Loop=1
2019-08-06T22:58:22.612Z,1565132302.612 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2019-08-06T22:58:23.813Z,1565132303.813 [NAL9602](DEBUG): Fix Requested
2019-08-06T22:58:24.204Z,1565132304.204 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,225720.00,A,3648.16591,N,12147.28206,W,0.408,0.00,060819,,,A*7A
2019-08-06T22:58:24.220Z,1565132304.220 [NAL9602](INFO): GPS fix at 20190806T225720: (36.802765, -121.788034)
2019-08-06T22:58:24.246Z,1565132304.246 [Default:CheckIn:Read_GPS] Stopped
2019-08-06T22:58:24.246Z,1565132304.246 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-08-06T22:58:24.694Z,1565132304.694 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-08-06T22:58:30.926Z,1565132310.926 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190806T223108/Courier0013.lzma
2019-08-06T22:58:31.578Z,1565132311.578 [DataOverHttps](INFO): Moved sent file to Logs/20190806T223108/Courier0013.lzma.bak
2019-08-06T22:58:31.579Z,1565132311.579 [DataOverHttps](INFO): SBD MOMSN=11530052
2019-08-06T22:58:43.528Z,1565132323.528 [DataOverHttps](INFO): Sending 214 bytes from file Logs/20190806T225425/Courier0004.lzma
2019-08-06T22:58:44.334Z,1565132324.334 [DataOverHttps](INFO): Moved sent file to Logs/20190806T225425/Courier0004.lzma.bak
2019-08-06T22:58:44.335Z,1565132324.335 [DataOverHttps](INFO): SBD MOMSN=11530054
2019-08-06T22:58:56.666Z,1565132336.666 [DataOverHttps](INFO): Sending 160 bytes from file Logs/20190806T223108/Express0014.lzma
2019-08-06T22:58:56.750Z,1565132336.750 [NAL9602](INFO): Not Powering down - fast GPS
2019-08-06T22:58:57.470Z,1565132337.470 [DataOverHttps](INFO): Moved sent file to Logs/20190806T223108/Express0014.lzma.bak
2019-08-06T22:58:57.470Z,1565132337.470 [DataOverHttps](INFO): SBD MOMSN=11530058
2019-08-06T22:59:10.038Z,1565132350.038 [DataOverHttps](INFO): Sending 793 bytes from file Logs/20190806T225425/Express0001.lzma
2019-08-06T22:59:10.842Z,1565132350.842 [DataOverHttps](INFO): Moved sent file to Logs/20190806T225425/Express0001.lzma.bak
2019-08-06T22:59:10.842Z,1565132350.842 [DataOverHttps](INFO): SBD MOMSN=11530062
2019-08-06T22:59:23.516Z,1565132363.516 [DataOverHttps](INFO): Sending 225 bytes from file Logs/20190806T225425/Express0005.lzma
2019-08-06T22:59:24.322Z,1565132364.322 [DataOverHttps](INFO): Moved sent file to Logs/20190806T225425/Express0005.lzma.bak
2019-08-06T22:59:24.323Z,1565132364.323 [DataOverHttps](INFO): SBD MOMSN=11530085
2019-08-06T22:59:27.140Z,1565132367.140 [Default:CheckIn:Read_Iridium] Stopped
2019-08-06T22:59:27.140Z,1565132367.140 [Default:CheckIn:C.Wait] Running Loop=1
2019-08-06T22:59:27.140Z,1565132367.140 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-08-06T23:00:59.609Z,1565132459.609 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2019-08-06T23:00:59.613Z,1565132459.613 [BPC1](INFO): Received data from all battery sticks.
2019-08-06T23:04:27.697Z,1565132667.697 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-08-06T23:04:27.697Z,1565132667.697 [Default:CheckIn:C.Wait] Stopped
2019-08-06T23:04:27.697Z,1565132667.697 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-08-06T23:04:27.697Z,1565132667.697 [Default:CheckIn:D] Running Loop=1
2019-08-06T23:04:28.104Z,1565132668.104 [Default:CheckIn:D] Stopped
2019-08-06T23:04:28.104Z,1565132668.104 [Default:CheckIn:E] Running Loop=1
2019-08-06T23:04:28.503Z,1565132668.503 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 6.322982 min 
2019-08-06T23:04:28.503Z,1565132668.503 [Default:CheckIn:E] Stopped
2019-08-06T23:04:28.504Z,1565132668.504 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-08-06T23:04:28.504Z,1565132668.504 [Default:CheckIn] Stopped
2019-08-06T23:04:28.504Z,1565132668.504 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-08-06T23:04:28.504Z,1565132668.504 [Default:CheckIn](INFO): Running loop #2
2019-08-06T23:04:28.504Z,1565132668.504 [Default:CheckIn] Running Loop=2
2019-08-06T23:04:28.504Z,1565132668.504 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-08-06T23:04:28.504Z,1565132668.504 [Default:CheckIn:Read_GPS] Running Loop=1
2019-08-06T23:04:30.112Z,1565132670.112 [NAL9602](DEBUG): Fix Requested
2019-08-06T23:04:30.504Z,1565132670.504 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,230326.00,A,3648.16897,N,12147.28336,W,0.136,0.00,060819,,,A*7D
2019-08-06T23:04:30.506Z,1565132670.506 [NAL9602](INFO): GPS fix at 20190806T230326: (36.802816, -121.788056)
2019-08-06T23:04:30.549Z,1565132670.549 [Default:CheckIn:Read_GPS] Stopped
2019-08-06T23:04:30.549Z,1565132670.549 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-08-06T23:04:42.857Z,1565132682.857 [DataOverHttps](INFO): Sending 222 bytes from file Logs/20190806T225425/Courier0007.lzma
2019-08-06T23:04:43.663Z,1565132683.663 [DataOverHttps](INFO): Moved sent file to Logs/20190806T225425/Courier0007.lzma.bak
2019-08-06T23:04:43.663Z,1565132683.663 [DataOverHttps](INFO): SBD MOMSN=11530124
2019-08-06T23:04:56.056Z,1565132696.056 [DataOverHttps](INFO): Sending 152 bytes from file Logs/20190806T225425/Express0008.lzma
2019-08-06T23:04:56.862Z,1565132696.862 [DataOverHttps](INFO): Moved sent file to Logs/20190806T225425/Express0008.lzma.bak
2019-08-06T23:04:56.862Z,1565132696.862 [DataOverHttps](INFO): SBD MOMSN=11530127
2019-08-06T23:04:58.434Z,1565132698.434 [Default:CheckIn:Read_Iridium] Stopped
2019-08-06T23:04:58.434Z,1565132698.434 [Default:CheckIn:C.Wait] Running Loop=1
2019-08-06T23:04:58.435Z,1565132698.435 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-08-06T23:05:43.227Z,1565132743.227 [NAL9602](INFO): SBD MO Status=1, MOMSN=15851, MT Status=0, MTMSN=0
2019-08-06T23:05:43.228Z,1565132743.228 [NAL9602](INFO): No messages in MT queue
2019-08-06T23:06:13.923Z,1565132773.923 [NAL9602](INFO): Not Powering down - fast GPS
2019-08-06T23:09:58.981Z,1565132998.981 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-08-06T23:09:58.981Z,1565132998.981 [Default:CheckIn:C.Wait] Stopped
2019-08-06T23:09:58.981Z,1565132998.981 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-08-06T23:09:58.981Z,1565132998.981 [Default:CheckIn:D] Running Loop=1
2019-08-06T23:09:59.379Z,1565132999.379 [Default:CheckIn:D] Stopped
2019-08-06T23:09:59.379Z,1565132999.379 [Default:CheckIn:E] Running Loop=1
2019-08-06T23:09:59.797Z,1565132999.797 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 11.844221 min 
2019-08-06T23:09:59.797Z,1565132999.797 [Default:CheckIn:E] Stopped
2019-08-06T23:09:59.797Z,1565132999.797 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-08-06T23:09:59.798Z,1565132999.798 [Default:CheckIn] Stopped
2019-08-06T23:09:59.798Z,1565132999.798 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-08-06T23:09:59.798Z,1565132999.798 [Default:CheckIn](INFO): Running loop #3
2019-08-06T23:09:59.798Z,1565132999.798 [Default:CheckIn] Running Loop=3
2019-08-06T23:09:59.798Z,1565132999.798 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-08-06T23:09:59.798Z,1565132999.798 [Default:CheckIn:Read_GPS] Running Loop=1
2019-08-06T23:10:01.393Z,1565133001.393 [NAL9602](DEBUG): Fix Requested
2019-08-06T23:10:01.788Z,1565133001.788 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,230857.00,A,3648.16836,N,12147.28163,W,0.097,0.00,060819,,,A*73
2019-08-06T23:10:01.790Z,1565133001.790 [NAL9602](INFO): GPS fix at 20190806T230857: (36.802806, -121.788027)
2019-08-06T23:10:01.814Z,1565133001.814 [Default:CheckIn:Read_GPS] Stopped
2019-08-06T23:10:01.814Z,1565133001.814 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-08-06T23:10:07.964Z,1565133007.964 [DataOverHttps](INFO): Sending 64 bytes from file Logs/20190806T225425/Courier0010.lzma
2019-08-06T23:10:08.770Z,1565133008.770 [DataOverHttps](INFO): Moved sent file to Logs/20190806T225425/Courier0010.lzma.bak
2019-08-06T23:10:08.770Z,1565133008.770 [DataOverHttps](INFO): SBD MOMSN=11530132
2019-08-06T23:10:21.840Z,1565133021.840 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20190806T225425/Express0011.lzma
2019-08-06T23:10:22.646Z,1565133022.646 [DataOverHttps](INFO): Moved sent file to Logs/20190806T225425/Express0011.lzma.bak
2019-08-06T23:10:22.646Z,1565133022.646 [DataOverHttps](INFO): SBD MOMSN=11530135
2019-08-06T23:10:24.460Z,1565133024.460 [Default:CheckIn:Read_Iridium] Stopped
2019-08-06T23:10:24.460Z,1565133024.460 [Default:CheckIn:C.Wait] Running Loop=1
2019-08-06T23:10:24.460Z,1565133024.460 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-08-06T23:14:46.212Z,1565133286.212 [NAL9602](INFO): SBD MO Status=2, MOMSN=15852, MT Status=2, MTMSN=0
2019-08-06T23:14:46.212Z,1565133286.212 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-08-06T23:15:03.982Z,1565133303.982 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-08-06T23:15:25.016Z,1565133325.016 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-08-06T23:15:25.041Z,1565133325.041 [Default:CheckIn:C.Wait] Stopped
2019-08-06T23:15:25.041Z,1565133325.041 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-08-06T23:15:25.041Z,1565133325.041 [Default:CheckIn:D] Running Loop=1
2019-08-06T23:15:25.416Z,1565133325.416 [Default:CheckIn:D] Stopped
2019-08-06T23:15:25.416Z,1565133325.416 [Default:CheckIn:E] Running Loop=1
2019-08-06T23:15:25.821Z,1565133325.821 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 17.278172 min 
2019-08-06T23:15:25.821Z,1565133325.821 [Default:CheckIn:E] Stopped
2019-08-06T23:15:25.822Z,1565133325.822 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-08-06T23:15:25.822Z,1565133325.822 [Default:CheckIn] Stopped
2019-08-06T23:15:25.822Z,1565133325.822 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-08-06T23:15:25.822Z,1565133325.822 [Default:CheckIn](INFO): Running loop #4
2019-08-06T23:15:25.822Z,1565133325.822 [Default:CheckIn] Running Loop=4
2019-08-06T23:15:25.822Z,1565133325.822 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-08-06T23:15:25.822Z,1565133325.822 [Default:CheckIn:Read_GPS] Running Loop=1
2019-08-06T23:15:27.434Z,1565133327.434 [NAL9602](DEBUG): Fix Requested
2019-08-06T23:15:27.818Z,1565133327.818 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,231423.00,A,3648.16735,N,12147.28173,W,0.117,181.52,060819,,,A*76
2019-08-06T23:15:27.820Z,1565133327.820 [NAL9602](INFO): GPS fix at 20190806T231423: (36.802789, -121.788029)
2019-08-06T23:15:27.897Z,1565133327.897 [Default:CheckIn:Read_GPS] Stopped
2019-08-06T23:15:27.897Z,1565133327.897 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-08-06T23:15:34.984Z,1565133334.984 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20190806T225425/Courier0013.lzma
2019-08-06T23:15:35.790Z,1565133335.790 [DataOverHttps](INFO): Moved sent file to Logs/20190806T225425/Courier0013.lzma.bak
2019-08-06T23:15:35.791Z,1565133335.791 [DataOverHttps](INFO): SBD MOMSN=11530180
2019-08-06T23:15:48.001Z,1565133348.001 [DataOverHttps](INFO): Sending 220 bytes from file Logs/20190806T225425/Express0014.lzma
2019-08-06T23:15:48.806Z,1565133348.806 [DataOverHttps](INFO): Moved sent file to Logs/20190806T225425/Express0014.lzma.bak
2019-08-06T23:15:48.806Z,1565133348.806 [DataOverHttps](INFO): SBD MOMSN=11530183
2019-08-06T23:15:51.323Z,1565133351.323 [Default:CheckIn:Read_Iridium] Stopped
2019-08-06T23:15:51.323Z,1565133351.323 [Default:CheckIn:C.Wait] Running Loop=1
2019-08-06T23:15:51.323Z,1565133351.323 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-08-06T23:16:00.570Z,1565133360.570 [NAL9602](INFO): Not Powering down - fast GPS
2019-08-06T23:16:58.134Z,1565133418.134 [CommandLine](IMPORTANT): got command get latitude
2019-08-06T23:16:58.135Z,1565133418.135 [CommandLine](IMPORTANT): latitude 36.802789 arcdeg
2019-08-06T23:17:34.890Z,1565133454.890 [DataOverHttps](IMPORTANT): SBD MTMSN=20190806T231629
2019-08-06T23:17:39.990Z,1565133459.990 [DataOverHttps](INFO): Received command:load Maintenance/sample.xml;set sample.MissionTimeout 45 minute;set sample.CartridgeType NaN count;set sample.NumberOfSamples 3 count;set sample.WaitBeforeSample 1 minute;run 
2019-08-06T23:17:40.003Z,1565133460.003 [CommandLine](IMPORTANT): got command load ./Missions/Maintenance/sample.xml
2019-08-06T23:17:40.004Z,1565133460.004 [MissionManager](INFO): Loading Mission: ./Missions/Maintenance/sample.xml
2019-08-06T23:17:40.031Z,1565133460.031 [MissionManager](INFO): DefineArg sample.MissionTimeout = 90.000000 min
2019-08-06T23:17:40.046Z,1565133460.046 [MissionManager](INFO): DefineArg sample.Depth = 7.000000 m
2019-08-06T23:17:40.051Z,1565133460.051 [MissionManager](INFO): DefineArg sample.NumberOfSamples = 1.000000 count
2019-08-06T23:17:40.054Z,1565133460.054 [MissionManager](INFO): DefineArg sample.WaitBeforeSample = 3.000000 min
2019-08-06T23:17:40.055Z,1565133460.055 [sample:A.AbortSample](DEBUG): Construct.
2019-08-06T23:17:40.060Z,1565133460.060 [sample:B.Pitch](DEBUG): Construct.
2019-08-06T23:17:40.070Z,1565133460.070 [sample:C.SetSpeed](DEBUG): Construct.
2019-08-06T23:17:40.072Z,1565133460.072 [MissionManager](INFO): Inserting Stack: Missions/Insert/SampleAtDepth.xml
2019-08-06T23:17:40.262Z,1565133460.262 [MissionManager](INFO): DefineArg sample:SampleAtDepth.TargetDepth = 5.000000 m
2019-08-06T23:17:40.265Z,1565133460.265 [MissionManager](INFO): DefineArg sample:SampleAtDepth.SettleTime = 10.000000 s
2019-08-06T23:17:40.268Z,1565133460.268 [MissionManager](INFO): DefineArg sample:SampleAtDepth.MaxWaitNotReachingDepth = 3.000000 h
2019-08-06T23:17:40.305Z,1565133460.305 [MissionManager](INFO): DefineArg sample:SampleAtDepth.RotateOnly = 0.000000 bool
2019-08-06T23:17:40.308Z,1565133460.308 [MissionManager](INFO): DefineArg sample:SampleAtDepth.UseCANONSampler = 1.000000 bool
2019-08-06T23:17:40.312Z,1565133460.312 [MissionManager](INFO): DefineArg sample:SampleAtDepth.UseESP = 0.000000 bool
2019-08-06T23:17:40.323Z,1565133460.323 [MissionManager](INFO): DefineArg sample:SampleAtDepth.CANONSamplerTriggerTimeout = 1.000000 min
2019-08-06T23:17:40.327Z,1565133460.327 [MissionManager](INFO): DefineArg sample:SampleAtDepth.CANONSamplerTimeout = 6.000000 min
2019-08-06T23:17:40.373Z,1565133460.373 [MissionManager](INFO): DefineArg sample:SampleAtDepth.BuoyancyNeutral = 199.999995 cc
2019-08-06T23:17:40.395Z,1565133460.395 [sample:SampleAtDepth:ApproachDepth:B.Pitch](DEBUG): Construct.
2019-08-06T23:17:40.423Z,1565133460.423 [sample:SampleAtDepth:ApproachDepth:B.Pitch:A_Timeout:B.Execute](DEBUG): Construct Execute.
2019-08-06T23:17:40.438Z,1565133460.438 [sample:SampleAtDepth:SampleWrapper:A.Pitch](DEBUG): Construct.
2019-08-06T23:17:40.486Z,1565133460.486 [sample:SampleAtDepth:SampleWrapper:C.Wait](DEBUG): Construct Wait.
2019-08-06T23:17:40.519Z,1565133460.519 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:TriggerCANONSampler:A_Timeout:B.Execute](DEBUG): Construct Execute.
2019-08-06T23:17:40.543Z,1565133460.543 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:E:A_Timeout:B.Execute](DEBUG): Construct Execute.
2019-08-06T23:17:40.616Z,1565133460.616 [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:Guidance="Tethys/Guidance"
         xmlns:Control="Tethys/Control"
         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/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd"
       Id="sample">

    <Description>
        This mission is designed to be run in the test tank only and samples
        whichever sampler is installed once the vehicle reaches the target
        depth.
    </Description>

    <DefineArg Name="MissionTimeout"><Description>
        How long to let the mission run.
    </Description><Units:minute/><Value>90</Value></DefineArg>

    <DefineArg Name="Depth"><Description>
        Depth to sample at.
    </Description><Units:meter/><Value>7</Value></DefineArg>

    <DefineArg Name="NumberOfSamples"><Description>
        Number of samples to take.
    </Description><Units:count/><Value>1</Value></DefineArg>

    <DefineArg Name="WaitBeforeSample"><Description>
        How long to wait between samples. This starts *before* the first sample
        to exercise the SettleTime setting in the insert aggregate.
    </Description><Units:minute/><Value>3</Value></DefineArg>

    <Timeout Duration="MissionTimeout"/>

     <Trigger:AbortSample>
     	  <Parallel/>
     </Trigger:AbortSample>

    <Guidance:Pitch>
        <Parallel/>
        <Setting><Guidance:Pitch.massPosition/><Control:VerticalControl.massDefault/></Setting>
    </Guidance:Pitch>

    <Guidance:SetSpeed>
        <Parallel/>
        <Setting><Guidance:SetSpeed.speed/><Units:meter_per_second/><Value>0</Value></Setting>
    </Guidance:SetSpeed>

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

    <Assign><Sequence/><Arg Name="SampleAtDepth:TargetDepth"/><Arg Name="Depth"/></Assign>

    <Assign><Sequence/><Arg Name="SampleAtDepth:SettleTime"/><Arg Name="WaitBeforeSample"/></Assign>

    <Aggregate Id="SampleRepeater">

        <Sequence Repeat="NumberOfSamples"/>

        <Call Id="Sample" RefId="SampleAtDepth"/>

    </Aggregate>

</Mission>


2019-08-06T23:17:40.625Z,1565133460.625 [CommandLine](IMPORTANT): Loaded ./Missions/Maintenance/sample.xml
2019-08-06T23:17:57.674Z,1565133477.674 [CommandLine](IMPORTANT): got command set sample.MissionTimeout 45.000000 minute
2019-08-06T23:17:57.675Z,1565133477.675 [CommandLine](IMPORTANT): got command set 
2019-08-06T23:17:57.675Z,1565133477.675 [CommandLine](FAULT): Incomplete syntax. Try: help set
2019-08-06T23:19:11.166Z,1565133551.166 [DataOverHttps](IMPORTANT): SBD MTMSN=20190806T231806
2019-08-06T23:19:16.217Z,1565133556.217 [DataOverHttps](INFO): Received command:load Maintenance/sample.xml;set sample.MissionTimeout 45 minute;set sample.NumberOfSamples 3 count;set sample.WaitBeforeSample 1 minute;run 
2019-08-06T23:19:16.230Z,1565133556.230 [CommandLine](IMPORTANT): got command load ./Missions/Maintenance/sample.xml
2019-08-06T23:19:16.230Z,1565133556.230 [MissionManager](INFO): Uninitializing Mission sample
2019-08-06T23:19:16.237Z,1565133556.237 [MissionManager](INFO): Loading Mission: ./Missions/Maintenance/sample.xml
2019-08-06T23:19:16.258Z,1565133556.258 [MissionManager](INFO): DefineArg sample.MissionTimeout = 90.000000 min
2019-08-06T23:19:16.260Z,1565133556.260 [MissionManager](INFO): DefineArg sample.Depth = 7.000000 m
2019-08-06T23:19:16.263Z,1565133556.263 [MissionManager](INFO): DefineArg sample.NumberOfSamples = 1.000000 count
2019-08-06T23:19:16.265Z,1565133556.265 [MissionManager](INFO): DefineArg sample.WaitBeforeSample = 3.000000 min
2019-08-06T23:19:16.266Z,1565133556.266 [sample:A.AbortSample](DEBUG): Construct.
2019-08-06T23:19:16.267Z,1565133556.267 [sample:B.Pitch](DEBUG): Construct.
2019-08-06T23:19:16.271Z,1565133556.271 [sample:C.SetSpeed](DEBUG): Construct.
2019-08-06T23:19:16.274Z,1565133556.274 [MissionManager](INFO): Inserting Stack: Missions/Insert/SampleAtDepth.xml
2019-08-06T23:19:16.449Z,1565133556.449 [MissionManager](INFO): DefineArg sample:SampleAtDepth.TargetDepth = 5.000000 m
2019-08-06T23:19:16.451Z,1565133556.451 [MissionManager](INFO): DefineArg sample:SampleAtDepth.SettleTime = 10.000000 s
2019-08-06T23:19:16.453Z,1565133556.453 [MissionManager](INFO): DefineArg sample:SampleAtDepth.MaxWaitNotReachingDepth = 3.000000 h
2019-08-06T23:19:16.455Z,1565133556.455 [MissionManager](INFO): DefineArg sample:SampleAtDepth.RotateOnly = 0.000000 bool
2019-08-06T23:19:16.458Z,1565133556.458 [MissionManager](INFO): DefineArg sample:SampleAtDepth.UseCANONSampler = 1.000000 bool
2019-08-06T23:19:16.460Z,1565133556.460 [MissionManager](INFO): DefineArg sample:SampleAtDepth.UseESP = 0.000000 bool
2019-08-06T23:19:16.463Z,1565133556.463 [MissionManager](INFO): DefineArg sample:SampleAtDepth.CANONSamplerTriggerTimeout = 1.000000 min
2019-08-06T23:19:16.465Z,1565133556.465 [MissionManager](INFO): DefineArg sample:SampleAtDepth.CANONSamplerTimeout = 6.000000 min
2019-08-06T23:19:16.467Z,1565133556.467 [MissionManager](INFO): DefineArg sample:SampleAtDepth.BuoyancyNeutral = 199.999995 cc
2019-08-06T23:19:16.470Z,1565133556.470 [sample:SampleAtDepth:ApproachDepth:B.Pitch](DEBUG): Construct.
2019-08-06T23:19:16.475Z,1565133556.475 [sample:SampleAtDepth:ApproachDepth:B.Pitch:A_Timeout:B.Execute](DEBUG): Construct Execute.
2019-08-06T23:19:16.478Z,1565133556.478 [sample:SampleAtDepth:SampleWrapper:A.Pitch](DEBUG): Construct.
2019-08-06T23:19:16.483Z,1565133556.483 [sample:SampleAtDepth:SampleWrapper:C.Wait](DEBUG): Construct Wait.
2019-08-06T23:19:16.491Z,1565133556.491 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:TriggerCANONSampler:A_Timeout:B.Execute](DEBUG): Construct Execute.
2019-08-06T23:19:16.583Z,1565133556.583 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:E:A_Timeout:B.Execute](DEBUG): Construct Execute.
2019-08-06T23:19:16.650Z,1565133556.650 [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:Guidance="Tethys/Guidance"
         xmlns:Control="Tethys/Control"
         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/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd"
       Id="sample">

    <Description>
        This mission is designed to be run in the test tank only and samples
        whichever sampler is installed once the vehicle reaches the target
        depth.
    </Description>

    <DefineArg Name="MissionTimeout"><Description>
        How long to let the mission run.
    </Description><Units:minute/><Value>90</Value></DefineArg>

    <DefineArg Name="Depth"><Description>
        Depth to sample at.
    </Description><Units:meter/><Value>7</Value></DefineArg>

    <DefineArg Name="NumberOfSamples"><Description>
        Number of samples to take.
    </Description><Units:count/><Value>1</Value></DefineArg>

    <DefineArg Name="WaitBeforeSample"><Description>
        How long to wait between samples. This starts *before* the first sample
        to exercise the SettleTime setting in the insert aggregate.
    </Description><Units:minute/><Value>3</Value></DefineArg>

    <Timeout Duration="MissionTimeout"/>

     <Trigger:AbortSample>
     	  <Parallel/>
     </Trigger:AbortSample>

    <Guidance:Pitch>
        <Parallel/>
        <Setting><Guidance:Pitch.massPosition/><Control:VerticalControl.massDefault/></Setting>
    </Guidance:Pitch>

    <Guidance:SetSpeed>
        <Parallel/>
        <Setting><Guidance:SetSpeed.speed/><Units:meter_per_second/><Value>0</Value></Setting>
    </Guidance:SetSpeed>

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

    <Assign><Sequence/><Arg Name="SampleAtDepth:TargetDepth"/><Arg Name="Depth"/></Assign>

    <Assign><Sequence/><Arg Name="SampleAtDepth:SettleTime"/><Arg Name="WaitBeforeSample"/></Assign>

    <Aggregate Id="SampleRepeater">

        <Sequence Repeat="NumberOfSamples"/>

        <Call Id="Sample" RefId="SampleAtDepth"/>

    </Aggregate>

</Mission>


2019-08-06T23:19:16.651Z,1565133556.651 [CommandLine](IMPORTANT): Loaded ./Missions/Maintenance/sample.xml
2019-08-06T23:19:22.139Z,1565133562.139 [CommandLine](IMPORTANT): got command set sample.MissionTimeout 45.000000 minute
2019-08-06T23:19:22.140Z,1565133562.140 [CommandLine](IMPORTANT): got command set sample.NumberOfSamples 3.000000 count
2019-08-06T23:19:22.140Z,1565133562.140 [CommandLine](IMPORTANT): got command set sample.WaitBeforeSample 1.000000 minute
2019-08-06T23:19:22.141Z,1565133562.141 [CommandLine](IMPORTANT): got command run 
2019-08-06T23:19:22.143Z,1565133562.143 [CommandLine](IMPORTANT): Running 
2019-08-06T23:19:22.193Z,1565133562.193 [Default] Stopped
2019-08-06T23:19:22.194Z,1565133562.194 [Default](DEBUG): Aggregate::uninitialize Default
2019-08-06T23:19:22.194Z,1565133562.194 [Default:B.GoToSurface] Stopped
2019-08-06T23:19:22.194Z,1565133562.194 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-08-06T23:19:22.194Z,1565133562.194 [Default:CheckIn] Stopped
2019-08-06T23:19:22.194Z,1565133562.194 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-08-06T23:19:22.194Z,1565133562.194 [Default:CheckIn:C.Wait] Stopped
2019-08-06T23:19:22.194Z,1565133562.194 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-08-06T23:19:22.194Z,1565133562.194 [MissionManager](IMPORTANT): Started mission sample
2019-08-06T23:19:22.194Z,1565133562.194 [sample] Running Loop=1
2019-08-06T23:19:22.195Z,1565133562.195 [sample](DEBUG): Aggregate::initialize sample
2019-08-06T23:19:22.195Z,1565133562.195 [sample:A.AbortSample] Running Loop=1
2019-08-06T23:19:22.195Z,1565133562.195 [sample:A.AbortSample](INFO): Initializing AbortSample.
2019-08-06T23:19:22.195Z,1565133562.195 [sample:B.Pitch] Running Loop=1
2019-08-06T23:19:22.195Z,1565133562.195 [sample:B.Pitch](DEBUG): Initialize.
2019-08-06T23:19:22.195Z,1565133562.195 [sample:C.SetSpeed] Running Loop=1
2019-08-06T23:19:22.195Z,1565133562.195 [sample:C.SetSpeed](DEBUG): Initialize.
2019-08-06T23:19:22.195Z,1565133562.195 [sample:E] Running Loop=1
2019-08-06T23:19:22.196Z,1565133562.196 [sample:E] Stopped
2019-08-06T23:19:22.196Z,1565133562.196 [sample:F] Running Loop=1
2019-08-06T23:19:22.196Z,1565133562.196 [sample:C.SetSpeed] Running Loop=1
2019-08-06T23:19:22.196Z,1565133562.196 [sample:B.Pitch] Running Loop=1
2019-08-06T23:19:22.199Z,1565133562.199 [sample:A.AbortSample] Running Loop=1
2019-08-06T23:19:22.607Z,1565133562.607 [sample:F] Stopped
2019-08-06T23:19:22.607Z,1565133562.607 [sample:SampleRepeater] Running Loop=1
2019-08-06T23:19:22.607Z,1565133562.607 [sample:SampleRepeater](DEBUG): Aggregate::initialize sample:SampleRepeater
2019-08-06T23:19:22.608Z,1565133562.608 [sample:SampleRepeater:Sample] Running Loop=1
2019-08-06T23:19:22.608Z,1565133562.608 [sample:SampleRepeater:Sample](DEBUG): Aggregate::initialize sample:SampleRepeater:Sample
2019-08-06T23:19:23.005Z,1565133563.005 [sample:SampleAtDepth] Running Loop=1
2019-08-06T23:19:23.014Z,1565133563.014 [sample:SampleAtDepth](DEBUG): Aggregate::initialize sample:SampleAtDepth
2019-08-06T23:19:23.014Z,1565133563.014 [sample:SampleAtDepth:ApproachDepth] Running Loop=1
2019-08-06T23:19:23.014Z,1565133563.014 [sample:SampleAtDepth:ApproachDepth](DEBUG): Aggregate::initialize sample:SampleAtDepth:ApproachDepth
2019-08-06T23:19:23.014Z,1565133563.014 [sample:SampleAtDepth:ApproachDepth:A] Running Loop=1
2019-08-06T23:19:23.015Z,1565133563.015 [sample:SampleAtDepth:ApproachDepth:A](INFO): Moving to 7.000000 m 
2019-08-06T23:19:23.015Z,1565133563.015 [sample:SampleAtDepth:ApproachDepth:A] Stopped
2019-08-06T23:19:23.015Z,1565133563.015 [sample:SampleAtDepth:ApproachDepth:B.Pitch] Running Loop=1
2019-08-06T23:19:23.015Z,1565133563.015 [sample:SampleAtDepth:ApproachDepth:B.Pitch](DEBUG): Initialize.
2019-08-06T23:21:42.903Z,1565133702.903 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-06T23:22:01.137Z,1565133721.137 [Radio_Surface](INFO): Powering down
2019-08-06T23:22:13.605Z,1565133733.605 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-06T23:22:14.009Z,1565133734.009 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2019-08-06T23:22:24.405Z,1565133744.405 [sample:SampleAtDepth:ApproachDepth:B.Pitch] Stopped
2019-08-06T23:22:24.406Z,1565133744.406 [sample:SampleAtDepth:ApproachDepth](INFO): Completed sample:SampleAtDepth:ApproachDepth
2019-08-06T23:22:24.406Z,1565133744.406 [sample:SampleAtDepth:ApproachDepth] Stopped
2019-08-06T23:22:24.406Z,1565133744.406 [sample:SampleAtDepth:ApproachDepth](DEBUG): Aggregate::uninitialize sample:SampleAtDepth:ApproachDepth
2019-08-06T23:22:24.406Z,1565133744.406 [sample:SampleAtDepth:SampleWrapper] Running Loop=1
2019-08-06T23:22:24.406Z,1565133744.406 [sample:SampleAtDepth:SampleWrapper](DEBUG): Aggregate::initialize sample:SampleAtDepth:SampleWrapper
2019-08-06T23:22:24.406Z,1565133744.406 [sample:SampleAtDepth:SampleWrapper:A.Pitch] Running Loop=1
2019-08-06T23:22:24.406Z,1565133744.406 [sample:SampleAtDepth:SampleWrapper:A.Pitch](DEBUG): Initialize.
2019-08-06T23:22:24.406Z,1565133744.406 [sample:SampleAtDepth:SampleWrapper:B] Running Loop=1
2019-08-06T23:22:24.802Z,1565133744.802 [sample:SampleAtDepth:SampleWrapper:B](IMPORTANT): At 7.032489 m , settling for 1.000000 min 
2019-08-06T23:22:24.802Z,1565133744.802 [sample:SampleAtDepth:SampleWrapper:B] Stopped
2019-08-06T23:22:24.802Z,1565133744.802 [sample:SampleAtDepth:SampleWrapper:C.Wait] Running Loop=1
2019-08-06T23:22:24.802Z,1565133744.802 [sample:SampleAtDepth:SampleWrapper:C.Wait](DEBUG): Initialize Wait Component.
2019-08-06T23:22:24.802Z,1565133744.802 [sample:SampleAtDepth:SampleWrapper:A.Pitch] Running Loop=1
2019-08-06T23:23:25.399Z,1565133805.399 [sample:SampleAtDepth:SampleWrapper:C.Wait](INFO): Done Waiting.
2019-08-06T23:23:25.399Z,1565133805.399 [sample:SampleAtDepth:SampleWrapper:C.Wait] Stopped
2019-08-06T23:23:25.399Z,1565133805.399 [sample:SampleAtDepth:SampleWrapper:C.Wait](DEBUG): Uninitialize Wait Component.
2019-08-06T23:23:25.399Z,1565133805.399 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler] Running Loop=1
2019-08-06T23:23:25.400Z,1565133805.400 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler](DEBUG): Aggregate::initialize sample:SampleAtDepth:SampleWrapper:SampleCANONSampler
2019-08-06T23:23:25.400Z,1565133805.400 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:A] Running Loop=1
2019-08-06T23:23:25.400Z,1565133805.400 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:B] Running Loop=1
2019-08-06T23:23:25.400Z,1565133805.400 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:TriggerCANONSampler] Running Loop=1
2019-08-06T23:23:25.814Z,1565133805.814 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:TriggerCANONSampler](DEBUG): Initialize ReadDataComponent to sense CANONSampler.sampling
2019-08-06T23:23:25.814Z,1565133805.814 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:B] Running Loop=1
2019-08-06T23:23:25.814Z,1565133805.814 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:A] Running Loop=1
2019-08-06T23:23:26.613Z,1565133806.613 [CANONSampler](INFO): Powering up
2019-08-06T23:23:48.149Z,1565133828.149 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.191406
2019-08-06T23:23:57.732Z,1565133837.732 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:TriggerCANONSampler] Stopped
2019-08-06T23:23:57.732Z,1565133837.732 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:D] Running Loop=1
2019-08-06T23:23:58.126Z,1565133838.126 [CANONSampler](INFO): CANON SAMPLER 1.3

2019-08-06T23:23:58.126Z,1565133838.126 [CANONSampler](INFO): UI[1]=0

2019-08-06T23:23:58.126Z,1565133838.126 [CANONSampler](INFO): Saving.... DONE

2019-08-06T23:23:58.127Z,1565133838.127 [CANONSampler](INFO): S>S

2019-08-06T23:23:58.127Z,1565133838.127 [CANONSampler](INFO): MO=0

2019-08-06T23:23:58.136Z,1565133838.136 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:D](ERROR): data element is not active.
2019-08-06T23:23:58.137Z,1565133838.137 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:D](ERROR): data element is not active.
2019-08-06T23:23:58.137Z,1565133838.137 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:D](IMPORTANT): CANONSampler sampling at 9.521150 m in nan degC water with nan ug/l chlorophyll fluorescence.
2019-08-06T23:23:58.137Z,1565133838.137 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:D] Stopped
2019-08-06T23:23:58.137Z,1565133838.137 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:E] Running Loop=1
2019-08-06T23:23:58.528Z,1565133838.528 [CANONSampler](INFO): ELMO will go to position 1

2019-08-06T23:23:58.528Z,1565133838.528 [CANONSampler](INFO): Initial cnts = 0

2019-08-06T23:23:58.591Z,1565133838.591 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:E](DEBUG): Initialize ReadDataComponent to sense CANONSampler.sample_number
2019-08-06T23:23:59.327Z,1565133839.327 [CANONSampler](INFO): HOMINGMO=1, MF=0, PX=0

2019-08-06T23:24:00.541Z,1565133840.541 [CANONSampler](INFO): MO=0, MF=0, PX=0

2019-08-06T23:24:00.542Z,1565133840.542 [CANONSampler](INFO):  DONE with MO=0, MF=0

2019-08-06T23:24:13.478Z,1565133853.478 [CANONSampler](INFO): Pumping DONE

2019-08-06T23:24:14.280Z,1565133854.280 [CANONSampler](INFO): Next

2019-08-06T23:24:15.493Z,1565133855.493 [CANONSampler](INFO): MO=1, MF=0, PX=426

2019-08-06T23:24:16.710Z,1565133856.710 [CANONSampler](INFO): MO=1, MF=0, PX=1366

2019-08-06T23:24:17.509Z,1565133857.509 [CANONSampler](INFO): MO=1, MF=0, PX=2308

2019-08-06T23:24:18.719Z,1565133858.719 [CANONSampler](INFO): MO=1, MF=0, PX=3251

2019-08-06T23:24:18.719Z,1565133858.719 [CANONSampler](INFO): MO=0, MF=0, PX=3991

2019-08-06T23:24:18.720Z,1565133858.720 [CANONSampler](INFO):  DONE with MO=0, MF=0, PX=3991

2019-08-06T23:24:18.720Z,1565133858.720 [CANONSampler](INFO): Saving.... DONE

2019-08-06T23:25:58.514Z,1565133958.514 [CANONSampler](INFO): Pumping DONE

2019-08-06T23:25:59.318Z,1565133959.318 [CANONSampler](INFO): HOMINGMO=1, MF=0, PX=0

2019-08-06T23:26:00.531Z,1565133960.531 [CANONSampler](INFO): MO=1, MF=0, PX=448

2019-08-06T23:26:01.350Z,1565133961.350 [CANONSampler](INFO): MO=1, MF=0, PX=1561

2019-08-06T23:26:02.549Z,1565133962.549 [CANONSampler](INFO): MO=1, MF=0, PX=2696

2019-08-06T23:26:03.761Z,1565133963.761 [CANONSampler](INFO): MO=1, MF=0, PX=3827

2019-08-06T23:26:04.576Z,1565133964.576 [CANONSampler](INFO): MO=1, MF=0, PX=4956

2019-08-06T23:26:05.786Z,1565133965.786 [CANONSampler](INFO): MO=1, MF=0, PX=6087

2019-08-06T23:26:06.587Z,1565133966.587 [CANONSampler](INFO): MO=1, MF=0, PX=7220

2019-08-06T23:26:07.802Z,1565133967.802 [CANONSampler](INFO): MO=1, MF=0, PX=8352

2019-08-06T23:26:08.620Z,1565133968.620 [CANONSampler](INFO): MO=1, MF=0, PX=9485

2019-08-06T23:26:09.821Z,1565133969.821 [CANONSampler](INFO): MO=1, MF=0, PX=10616

2019-08-06T23:26:10.630Z,1565133970.630 [CANONSampler](INFO): MO=1, MF=0, PX=11748

2019-08-06T23:26:11.849Z,1565133971.849 [CANONSampler](INFO): MO=1, MF=0, PX=12883

2019-08-06T23:26:12.647Z,1565133972.647 [CANONSampler](INFO): MO=1, MF=0, PX=14014

2019-08-06T23:26:13.862Z,1565133973.862 [CANONSampler](INFO): MO=1, MF=0, PX=15146

2019-08-06T23:26:14.676Z,1565133974.676 [CANONSampler](INFO): MO=1, MF=0, PX=16281

2019-08-06T23:26:15.881Z,1565133975.881 [CANONSampler](INFO): MO=1, MF=0, PX=17415

2019-08-06T23:26:16.689Z,1565133976.689 [CANONSampler](INFO): MO=1, MF=0, PX=18553

2019-08-06T23:26:17.906Z,1565133977.906 [CANONSampler](INFO): MO=1, MF=0, PX=19690

2019-08-06T23:26:18.707Z,1565133978.707 [CANONSampler](INFO): MO=1, MF=0, PX=20827

2019-08-06T23:26:19.921Z,1565133979.921 [CANONSampler](INFO): MO=1, MF=0, PX=21964

2019-08-06T23:26:20.729Z,1565133980.729 [CANONSampler](INFO): MO=1, MF=0, PX=23100

2019-08-06T23:26:21.941Z,1565133981.941 [CANONSampler](INFO): MO=1, MF=0, PX=24239

2019-08-06T23:26:22.749Z,1565133982.749 [CANONSampler](INFO): MO=1, MF=0, PX=25378

2019-08-06T23:26:23.961Z,1565133983.961 [CANONSampler](INFO): MO=1, MF=0, PX=26517

2019-08-06T23:26:24.778Z,1565133984.778 [CANONSampler](INFO): MO=1, MF=0, PX=27657

2019-08-06T23:26:25.985Z,1565133985.985 [CANONSampler](INFO): MO=1, MF=0, PX=28798

2019-08-06T23:26:27.197Z,1565133987.197 [CANONSampler](INFO): MO=1, MF=0, PX=29939

2019-08-06T23:26:28.009Z,1565133988.009 [CANONSampler](INFO): MO=1, MF=0, PX=31080

2019-08-06T23:26:29.217Z,1565133989.217 [CANONSampler](INFO): MO=1, MF=0, PX=32220

2019-08-06T23:26:30.022Z,1565133990.022 [CANONSampler](INFO): MO=1, MF=0, PX=-32173

2019-08-06T23:26:31.265Z,1565133991.265 [CANONSampler](INFO): MO=1, MF=0, PX=-31030

2019-08-06T23:26:32.042Z,1565133992.042 [CANONSampler](INFO): MO=1, MF=0, PX=-29893

2019-08-06T23:26:33.251Z,1565133993.251 [CANONSampler](INFO): MO=1, MF=0, PX=-28752

2019-08-06T23:26:34.069Z,1565133994.069 [CANONSampler](INFO): MO=1, MF=0, PX=-27608

2019-08-06T23:26:35.275Z,1565133995.275 [CANONSampler](INFO): MO=1, MF=0, PX=-26465

2019-08-06T23:26:36.083Z,1565133996.083 [CANONSampler](INFO): MO=1, MF=0, PX=-25318

2019-08-06T23:26:37.303Z,1565133997.303 [CANONSampler](INFO): MO=1, MF=0, PX=-24170

2019-08-06T23:26:38.101Z,1565133998.101 [CANONSampler](INFO): MO=1, MF=0, PX=-23021

2019-08-06T23:26:39.311Z,1565133999.311 [CANONSampler](INFO): MO=1, MF=0, PX=-21870

2019-08-06T23:26:40.121Z,1565134000.121 [CANONSampler](INFO): MO=1, MF=0, PX=-20721

2019-08-06T23:26:41.333Z,1565134001.333 [CANONSampler](INFO): MO=1, MF=0, PX=-19572

2019-08-06T23:26:42.139Z,1565134002.139 [CANONSampler](INFO): MO=1, MF=0, PX=-18422

2019-08-06T23:26:43.353Z,1565134003.353 [CANONSampler](INFO): MO=1, MF=0, PX=-17273

2019-08-06T23:26:44.174Z,1565134004.174 [CANONSampler](INFO): MO=1, MF=0, PX=-16123

2019-08-06T23:26:45.371Z,1565134005.371 [CANONSampler](INFO): MO=1, MF=0, PX=-14974

2019-08-06T23:26:46.186Z,1565134006.186 [CANONSampler](INFO): MO=1, MF=0, PX=-13825

2019-08-06T23:26:47.400Z,1565134007.400 [CANONSampler](INFO): MO=1, MF=0, PX=-12676

2019-08-06T23:26:48.605Z,1565134008.605 [CANONSampler](INFO): MO=1, MF=0, PX=-11529

2019-08-06T23:26:49.414Z,1565134009.414 [CANONSampler](INFO): MO=1, MF=0, PX=-10379

2019-08-06T23:26:50.638Z,1565134010.638 [CANONSampler](INFO): MO=1, MF=0, PX=-9228

2019-08-06T23:26:51.430Z,1565134011.430 [CANONSampler](INFO): MO=1, MF=0, PX=-8813

2019-08-06T23:26:52.644Z,1565134012.644 [CANONSampler](INFO): MO=1, MF=0, PX=219

2019-08-06T23:26:53.459Z,1565134013.459 [CANONSampler](INFO): MO=1, MF=0, PX=1182

2019-08-06T23:26:54.665Z,1565134014.665 [CANONSampler](INFO): MO=1, MF=0, PX=1501

2019-08-06T23:26:55.471Z,1565134015.471 [CANONSampler](INFO): MO=1, MF=0, PX=1501

2019-08-06T23:26:56.690Z,1565134016.690 [CANONSampler](INFO): MO=1, MF=0, PX=1501

2019-08-06T23:26:57.491Z,1565134017.491 [CANONSampler](INFO): MO=0, MF=0, PX=0

2019-08-06T23:26:57.491Z,1565134017.491 [CANONSampler](INFO):  DONE with MO=0, MF=0

2019-08-06T23:26:58.703Z,1565134018.703 [CANONSampler](INFO): HOMINGMO=1, MF=0, PX=0

2019-08-06T23:26:59.513Z,1565134019.513 [CANONSampler](INFO): MO=0, MF=0, PX=0

2019-08-06T23:26:59.513Z,1565134019.513 [CANONSampler](INFO):  DONE with MO=0, MF=0

2019-08-06T23:26:59.514Z,1565134019.514 [CANONSampler](INFO): Sample 1, err_code=0

2019-08-06T23:26:59.514Z,1565134019.514 [CANONSampler](IMPORTANT): Sample 1, err_code=0

2019-08-06T23:26:59.529Z,1565134019.529 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:E] Stopped
2019-08-06T23:26:59.530Z,1565134019.530 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler](INFO): Completed sample:SampleAtDepth:SampleWrapper:SampleCANONSampler
2019-08-06T23:26:59.530Z,1565134019.530 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler] Stopped
2019-08-06T23:26:59.530Z,1565134019.530 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler](DEBUG): Aggregate::uninitialize sample:SampleAtDepth:SampleWrapper:SampleCANONSampler
2019-08-06T23:26:59.530Z,1565134019.530 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:A] Stopped
2019-08-06T23:26:59.530Z,1565134019.530 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:B] Stopped
2019-08-06T23:26:59.530Z,1565134019.530 [sample:SampleAtDepth:SampleWrapper:SampleESP] Running Loop=1
2019-08-06T23:26:59.530Z,1565134019.530 [sample:SampleAtDepth:SampleWrapper:SampleESP](DEBUG): Aggregate::initialize sample:SampleAtDepth:SampleWrapper:SampleESP
2019-08-06T23:26:59.530Z,1565134019.530 [sample:SampleAtDepth:SampleWrapper:SampleESP:TriggerESP] Running Loop=1
2019-08-06T23:26:59.941Z,1565134019.941 [sample:SampleAtDepth:SampleWrapper:SampleESP] Stopped
2019-08-06T23:26:59.941Z,1565134019.941 [sample:SampleAtDepth:SampleWrapper:SampleESP](DEBUG): Aggregate::uninitialize sample:SampleAtDepth:SampleWrapper:SampleESP
2019-08-06T23:26:59.941Z,1565134019.941 [sample:SampleAtDepth:SampleWrapper:SampleESP:TriggerESP] Stopped
2019-08-06T23:26:59.942Z,1565134019.942 [sample:SampleAtDepth:SampleWrapper](INFO): Completed sample:SampleAtDepth:SampleWrapper
2019-08-06T23:26:59.942Z,1565134019.942 [sample:SampleAtDepth:SampleWrapper] Stopped
2019-08-06T23:26:59.942Z,1565134019.942 [sample:SampleAtDepth:SampleWrapper](DEBUG): Aggregate::uninitialize sample:SampleAtDepth:SampleWrapper
2019-08-06T23:26:59.942Z,1565134019.942 [sample:SampleAtDepth:SampleWrapper:A.Pitch] Stopped
2019-08-06T23:26:59.942Z,1565134019.942 [sample:SampleAtDepth](INFO): Completed sample:SampleAtDepth
2019-08-06T23:26:59.942Z,1565134019.942 [sample:SampleAtDepth] Stopped
2019-08-06T23:26:59.942Z,1565134019.942 [sample:SampleAtDepth](DEBUG): Aggregate::uninitialize sample:SampleAtDepth
2019-08-06T23:27:00.324Z,1565134020.324 [CANONSampler](INFO): Powering down
2019-08-06T23:27:00.439Z,1565134020.439 [sample:SampleRepeater:Sample](INFO): Completed sample:SampleRepeater:Sample
2019-08-06T23:27:00.439Z,1565134020.439 [sample:SampleRepeater:Sample] Stopped
2019-08-06T23:27:00.439Z,1565134020.439 [sample:SampleRepeater:Sample](DEBUG): Aggregate::uninitialize sample:SampleRepeater:Sample
2019-08-06T23:27:00.439Z,1565134020.439 [sample:SampleRepeater](INFO): Completed sample:SampleRepeater
2019-08-06T23:27:00.439Z,1565134020.439 [sample:SampleRepeater] Stopped
2019-08-06T23:27:00.440Z,1565134020.440 [sample:SampleRepeater](DEBUG): Aggregate::uninitialize sample:SampleRepeater
2019-08-06T23:27:00.440Z,1565134020.440 [sample:SampleRepeater](INFO): Running loop #2
2019-08-06T23:27:00.440Z,1565134020.440 [sample:SampleRepeater] Running Loop=2
2019-08-06T23:27:00.440Z,1565134020.440 [sample:SampleRepeater](DEBUG): Aggregate::initialize sample:SampleRepeater
2019-08-06T23:27:00.440Z,1565134020.440 [sample:SampleRepeater:Sample] Running Loop=1
2019-08-06T23:27:00.440Z,1565134020.440 [sample:SampleRepeater:Sample](DEBUG): Aggregate::initialize sample:SampleRepeater:Sample
2019-08-06T23:27:00.745Z,1565134020.745 [sample:SampleAtDepth] Running Loop=1
2019-08-06T23:27:00.745Z,1565134020.745 [sample:SampleAtDepth](DEBUG): Aggregate::initialize sample:SampleAtDepth
2019-08-06T23:27:00.745Z,1565134020.745 [sample:SampleAtDepth:ApproachDepth] Running Loop=1
2019-08-06T23:27:00.745Z,1565134020.745 [sample:SampleAtDepth:ApproachDepth](DEBUG): Aggregate::initialize sample:SampleAtDepth:ApproachDepth
2019-08-06T23:27:00.745Z,1565134020.745 [sample:SampleAtDepth:ApproachDepth:A] Running Loop=1
2019-08-06T23:27:00.746Z,1565134020.746 [sample:SampleAtDepth:ApproachDepth:A](INFO): Moving to 7.000000 m 
2019-08-06T23:27:00.746Z,1565134020.746 [sample:SampleAtDepth:ApproachDepth:A] Stopped
2019-08-06T23:27:00.746Z,1565134020.746 [sample:SampleAtDepth:ApproachDepth:B.Pitch] Running Loop=1
2019-08-06T23:27:00.746Z,1565134020.746 [sample:SampleAtDepth:ApproachDepth:B.Pitch](DEBUG): Initialize.
2019-08-06T23:28:03.763Z,1565134083.763 [sample:SampleAtDepth:ApproachDepth:B.Pitch] Stopped
2019-08-06T23:28:03.763Z,1565134083.763 [sample:SampleAtDepth:ApproachDepth](INFO): Completed sample:SampleAtDepth:ApproachDepth
2019-08-06T23:28:03.763Z,1565134083.763 [sample:SampleAtDepth:ApproachDepth] Stopped
2019-08-06T23:28:03.763Z,1565134083.763 [sample:SampleAtDepth:ApproachDepth](DEBUG): Aggregate::uninitialize sample:SampleAtDepth:ApproachDepth
2019-08-06T23:28:03.763Z,1565134083.763 [sample:SampleAtDepth:SampleWrapper] Running Loop=1
2019-08-06T23:28:03.763Z,1565134083.763 [sample:SampleAtDepth:SampleWrapper](DEBUG): Aggregate::initialize sample:SampleAtDepth:SampleWrapper
2019-08-06T23:28:03.763Z,1565134083.763 [sample:SampleAtDepth:SampleWrapper:A.Pitch] Running Loop=1
2019-08-06T23:28:03.763Z,1565134083.763 [sample:SampleAtDepth:SampleWrapper:A.Pitch](DEBUG): Initialize.
2019-08-06T23:28:03.764Z,1565134083.764 [sample:SampleAtDepth:SampleWrapper:B] Running Loop=1
2019-08-06T23:28:04.165Z,1565134084.165 [sample:SampleAtDepth:SampleWrapper:B](IMPORTANT): At 6.965333 m , settling for 1.000000 min 
2019-08-06T23:28:04.166Z,1565134084.166 [sample:SampleAtDepth:SampleWrapper:B] Stopped
2019-08-06T23:28:04.166Z,1565134084.166 [sample:SampleAtDepth:SampleWrapper:C.Wait] Running Loop=1
2019-08-06T23:28:04.166Z,1565134084.166 [sample:SampleAtDepth:SampleWrapper:C.Wait](DEBUG): Initialize Wait Component.
2019-08-06T23:29:04.759Z,1565134144.759 [sample:SampleAtDepth:SampleWrapper:C.Wait](INFO): Done Waiting.
2019-08-06T23:29:04.759Z,1565134144.759 [sample:SampleAtDepth:SampleWrapper:C.Wait] Stopped
2019-08-06T23:29:04.759Z,1565134144.759 [sample:SampleAtDepth:SampleWrapper:C.Wait](DEBUG): Uninitialize Wait Component.
2019-08-06T23:29:04.759Z,1565134144.759 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler] Running Loop=1
2019-08-06T23:29:04.760Z,1565134144.760 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler](DEBUG): Aggregate::initialize sample:SampleAtDepth:SampleWrapper:SampleCANONSampler
2019-08-06T23:29:04.760Z,1565134144.760 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:A] Running Loop=1
2019-08-06T23:29:04.760Z,1565134144.760 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:B] Running Loop=1
2019-08-06T23:29:04.760Z,1565134144.760 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:TriggerCANONSampler] Running Loop=1
2019-08-06T23:29:05.969Z,1565134145.969 [CANONSampler](INFO): Powering up
2019-08-06T23:29:37.095Z,1565134177.095 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:TriggerCANONSampler] Stopped
2019-08-06T23:29:37.096Z,1565134177.096 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:D] Running Loop=1
2019-08-06T23:29:37.485Z,1565134177.485 [CANONSampler](INFO): CANON SAMPLER 1.3

2019-08-06T23:29:37.485Z,1565134177.485 [CANONSampler](INFO): UI[1]=1

2019-08-06T23:29:37.486Z,1565134177.486 [CANONSampler](INFO): Saving.... DONE

2019-08-06T23:29:37.486Z,1565134177.486 [CANONSampler](INFO): S>S

2019-08-06T23:29:37.486Z,1565134177.486 [CANONSampler](INFO): MO=0

2019-08-06T23:29:37.496Z,1565134177.496 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:D](ERROR): data element is not active.
2019-08-06T23:29:37.496Z,1565134177.496 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:D](ERROR): data element is not active.
2019-08-06T23:29:37.497Z,1565134177.497 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:D](IMPORTANT): CANONSampler sampling at 8.521616 m in nan degC water with nan ug/l chlorophyll fluorescence.
2019-08-06T23:29:37.497Z,1565134177.497 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:D] Stopped
2019-08-06T23:29:37.497Z,1565134177.497 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:E] Running Loop=1
2019-08-06T23:29:37.882Z,1565134177.882 [CANONSampler](INFO): ELMO will go to position 2

2019-08-06T23:29:37.882Z,1565134177.882 [CANONSampler](INFO): Initial cnts = 0

2019-08-06T23:29:38.687Z,1565134178.687 [CANONSampler](INFO): HOMINGMO=1, MF=0, PX=0

2019-08-06T23:29:39.905Z,1565134179.905 [CANONSampler](INFO): MO=0, MF=0, PX=0

2019-08-06T23:29:39.906Z,1565134179.906 [CANONSampler](INFO):  DONE with MO=0, MF=0

2019-08-06T23:29:52.829Z,1565134192.829 [CANONSampler](INFO): Pumping DONE

2019-08-06T23:29:53.651Z,1565134193.651 [CANONSampler](INFO): Next

2019-08-06T23:29:54.853Z,1565134194.853 [CANONSampler](INFO): MO=1, MF=0, PX=424

2019-08-06T23:29:56.065Z,1565134196.065 [CANONSampler](INFO): MO=1, MF=0, PX=1364

2019-08-06T23:29:56.877Z,1565134196.877 [CANONSampler](INFO): MO=1, MF=0, PX=2305

2019-08-06T23:29:58.085Z,1565134198.085 [CANONSampler](INFO): MO=1, MF=0, PX=3244

2019-08-06T23:29:58.889Z,1565134198.889 [CANONSampler](INFO): MO=1, MF=0, PX=4186

2019-08-06T23:30:00.110Z,1565134200.110 [CANONSampler](INFO): MO=1, MF=0, PX=5129

2019-08-06T23:30:00.907Z,1565134200.907 [CANONSampler](INFO): MO=1, MF=0, PX=6073

2019-08-06T23:30:02.125Z,1565134202.125 [CANONSampler](INFO): MO=1, MF=0, PX=7014

2019-08-06T23:30:02.126Z,1565134202.126 [CANONSampler](INFO): MO=0, MF=0, PX=7852

2019-08-06T23:30:02.126Z,1565134202.126 [CANONSampler](INFO):  DONE with MO=0, MF=0, PX=7852

2019-08-06T23:30:02.127Z,1565134202.127 [CANONSampler](INFO): Saving.... DONE

2019-08-06T23:31:41.913Z,1565134301.913 [CANONSampler](INFO): Pumping DONE

2019-08-06T23:31:43.121Z,1565134303.121 [CANONSampler](INFO): HOMINGMO=1, MF=0, PX=0

2019-08-06T23:31:43.940Z,1565134303.940 [CANONSampler](INFO): MO=1, MF=0, PX=437

2019-08-06T23:31:45.145Z,1565134305.145 [CANONSampler](INFO): MO=1, MF=0, PX=1544

2019-08-06T23:31:45.949Z,1565134305.949 [CANONSampler](INFO): MO=1, MF=0, PX=2674

2019-08-06T23:31:47.168Z,1565134307.168 [CANONSampler](INFO): MO=1, MF=0, PX=3801

2019-08-06T23:31:47.969Z,1565134307.969 [CANONSampler](INFO): MO=1, MF=0, PX=4926

2019-08-06T23:31:49.181Z,1565134309.181 [CANONSampler](INFO): MO=1, MF=0, PX=6052

2019-08-06T23:31:49.997Z,1565134309.997 [CANONSampler](INFO): MO=1, MF=0, PX=7183

2019-08-06T23:31:51.206Z,1565134311.206 [CANONSampler](INFO): MO=1, MF=0, PX=8311

2019-08-06T23:31:52.011Z,1565134312.011 [CANONSampler](INFO): MO=1, MF=0, PX=9441

2019-08-06T23:31:53.233Z,1565134313.233 [CANONSampler](INFO): MO=1, MF=0, PX=10569

2019-08-06T23:31:54.029Z,1565134314.029 [CANONSampler](INFO): MO=1, MF=0, PX=11692

2019-08-06T23:31:55.245Z,1565134315.245 [CANONSampler](INFO): MO=1, MF=0, PX=12823

2019-08-06T23:31:56.049Z,1565134316.049 [CANONSampler](INFO): MO=1, MF=0, PX=13948

2019-08-06T23:31:57.262Z,1565134317.262 [CANONSampler](INFO): MO=1, MF=0, PX=15076

2019-08-06T23:31:58.068Z,1565134318.068 [CANONSampler](INFO): MO=1, MF=0, PX=16204

2019-08-06T23:31:59.281Z,1565134319.281 [CANONSampler](INFO): MO=1, MF=0, PX=17333

2019-08-06T23:32:00.098Z,1565134320.098 [CANONSampler](INFO): MO=1, MF=0, PX=18460

2019-08-06T23:32:01.301Z,1565134321.301 [CANONSampler](INFO): MO=1, MF=0, PX=19589

2019-08-06T23:32:02.108Z,1565134322.108 [CANONSampler](INFO): MO=1, MF=0, PX=20724

2019-08-06T23:32:03.334Z,1565134323.334 [CANONSampler](INFO): MO=1, MF=0, PX=21858

2019-08-06T23:32:04.537Z,1565134324.537 [CANONSampler](INFO): MO=1, MF=0, PX=22991

2019-08-06T23:32:05.341Z,1565134325.341 [CANONSampler](INFO): MO=1, MF=0, PX=24126

2019-08-06T23:32:06.559Z,1565134326.559 [CANONSampler](INFO): MO=1, MF=0, PX=25265

2019-08-06T23:32:07.361Z,1565134327.361 [CANONSampler](INFO): MO=1, MF=0, PX=26402

2019-08-06T23:32:08.573Z,1565134328.573 [CANONSampler](INFO): MO=1, MF=0, PX=27540

2019-08-06T23:32:09.385Z,1565134329.385 [CANONSampler](INFO): MO=1, MF=0, PX=28680

2019-08-06T23:32:10.597Z,1565134330.597 [CANONSampler](INFO): MO=1, MF=0, PX=29822

2019-08-06T23:32:11.399Z,1565134331.399 [CANONSampler](INFO): MO=1, MF=0, PX=30964

2019-08-06T23:32:12.614Z,1565134332.614 [CANONSampler](INFO): MO=1, MF=0, PX=32104

2019-08-06T23:32:13.435Z,1565134333.435 [CANONSampler](INFO): MO=1, MF=0, PX=-32292

2019-08-06T23:32:14.637Z,1565134334.637 [CANONSampler](INFO): MO=1, MF=0, PX=-31147

2019-08-06T23:32:15.445Z,1565134335.445 [CANONSampler](INFO): MO=1, MF=0, PX=-30006

2019-08-06T23:32:16.662Z,1565134336.662 [CANONSampler](INFO): MO=1, MF=0, PX=-28863

2019-08-06T23:32:17.459Z,1565134337.459 [CANONSampler](INFO): MO=1, MF=0, PX=-27716

2019-08-06T23:32:18.670Z,1565134338.670 [CANONSampler](INFO): MO=1, MF=0, PX=-26569

2019-08-06T23:32:19.487Z,1565134339.487 [CANONSampler](INFO): MO=1, MF=0, PX=-25420

2019-08-06T23:32:20.693Z,1565134340.693 [CANONSampler](INFO): MO=1, MF=0, PX=-24273

2019-08-06T23:32:21.505Z,1565134341.505 [CANONSampler](INFO): MO=1, MF=0, PX=-23124

2019-08-06T23:32:22.717Z,1565134342.717 [CANONSampler](INFO): MO=1, MF=0, PX=-21975

2019-08-06T23:32:23.521Z,1565134343.521 [CANONSampler](INFO): MO=1, MF=0, PX=-20828

2019-08-06T23:32:24.733Z,1565134344.733 [CANONSampler](INFO): MO=1, MF=0, PX=-19679

2019-08-06T23:32:25.546Z,1565134345.546 [CANONSampler](INFO): MO=1, MF=0, PX=-18530

2019-08-06T23:32:26.765Z,1565134346.765 [CANONSampler](INFO): MO=1, MF=0, PX=-17383

2019-08-06T23:32:27.973Z,1565134347.973 [CANONSampler](INFO): MO=1, MF=0, PX=-16234

2019-08-06T23:32:28.774Z,1565134348.774 [CANONSampler](INFO): MO=1, MF=0, PX=-15084

2019-08-06T23:32:29.989Z,1565134349.989 [CANONSampler](INFO): MO=1, MF=0, PX=-13933

2019-08-06T23:32:30.796Z,1565134350.796 [CANONSampler](INFO): MO=1, MF=0, PX=-12782

2019-08-06T23:32:32.010Z,1565134352.010 [CANONSampler](INFO): MO=1, MF=0, PX=-12685

2019-08-06T23:32:32.823Z,1565134352.823 [CANONSampler](INFO): MO=1, MF=0, PX=448

2019-08-06T23:32:34.029Z,1565134354.029 [CANONSampler](INFO): MO=1, MF=0, PX=1464

2019-08-06T23:32:34.837Z,1565134354.837 [CANONSampler](INFO): MO=1, MF=0, PX=1501

2019-08-06T23:32:36.058Z,1565134356.058 [CANONSampler](INFO): MO=1, MF=0, PX=1501

2019-08-06T23:32:36.851Z,1565134356.851 [CANONSampler](INFO): MO=0, MF=0, PX=1501

2019-08-06T23:32:36.851Z,1565134356.851 [CANONSampler](INFO):  DONE with MO=0, MF=0

2019-08-06T23:32:36.852Z,1565134356.852 [CANONSampler](INFO): Sample 2, err_code=0

2019-08-06T23:32:36.852Z,1565134356.852 [CANONSampler](IMPORTANT): Sample 2, err_code=0

2019-08-06T23:32:36.862Z,1565134356.862 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:E] Stopped
2019-08-06T23:32:36.863Z,1565134356.863 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler](INFO): Completed sample:SampleAtDepth:SampleWrapper:SampleCANONSampler
2019-08-06T23:32:36.863Z,1565134356.863 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler] Stopped
2019-08-06T23:32:36.863Z,1565134356.863 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler](DEBUG): Aggregate::uninitialize sample:SampleAtDepth:SampleWrapper:SampleCANONSampler
2019-08-06T23:32:36.863Z,1565134356.863 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:A] Stopped
2019-08-06T23:32:36.863Z,1565134356.863 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:B] Stopped
2019-08-06T23:32:36.863Z,1565134356.863 [sample:SampleAtDepth:SampleWrapper:SampleESP] Running Loop=1
2019-08-06T23:32:36.863Z,1565134356.863 [sample:SampleAtDepth:SampleWrapper:SampleESP](DEBUG): Aggregate::initialize sample:SampleAtDepth:SampleWrapper:SampleESP
2019-08-06T23:32:36.863Z,1565134356.863 [sample:SampleAtDepth:SampleWrapper:SampleESP:TriggerESP] Running Loop=1
2019-08-06T23:32:37.273Z,1565134357.273 [sample:SampleAtDepth:SampleWrapper:SampleESP] Stopped
2019-08-06T23:32:37.273Z,1565134357.273 [sample:SampleAtDepth:SampleWrapper:SampleESP](DEBUG): Aggregate::uninitialize sample:SampleAtDepth:SampleWrapper:SampleESP
2019-08-06T23:32:37.273Z,1565134357.273 [sample:SampleAtDepth:SampleWrapper:SampleESP:TriggerESP] Stopped
2019-08-06T23:32:37.274Z,1565134357.274 [sample:SampleAtDepth:SampleWrapper](INFO): Completed sample:SampleAtDepth:SampleWrapper
2019-08-06T23:32:37.274Z,1565134357.274 [sample:SampleAtDepth:SampleWrapper] Stopped
2019-08-06T23:32:37.274Z,1565134357.274 [sample:SampleAtDepth:SampleWrapper](DEBUG): Aggregate::uninitialize sample:SampleAtDepth:SampleWrapper
2019-08-06T23:32:37.274Z,1565134357.274 [sample:SampleAtDepth:SampleWrapper:A.Pitch] Stopped
2019-08-06T23:32:37.274Z,1565134357.274 [sample:SampleAtDepth](INFO): Completed sample:SampleAtDepth
2019-08-06T23:32:37.274Z,1565134357.274 [sample:SampleAtDepth] Stopped
2019-08-06T23:32:37.274Z,1565134357.274 [sample:SampleAtDepth](DEBUG): Aggregate::uninitialize sample:SampleAtDepth
2019-08-06T23:32:37.661Z,1565134357.661 [CANONSampler](INFO): Powering down
2019-08-06T23:32:37.769Z,1565134357.769 [sample:SampleRepeater:Sample](INFO): Completed sample:SampleRepeater:Sample
2019-08-06T23:32:37.769Z,1565134357.769 [sample:SampleRepeater:Sample] Stopped
2019-08-06T23:32:37.769Z,1565134357.769 [sample:SampleRepeater:Sample](DEBUG): Aggregate::uninitialize sample:SampleRepeater:Sample
2019-08-06T23:32:37.769Z,1565134357.769 [sample:SampleRepeater](INFO): Completed sample:SampleRepeater
2019-08-06T23:32:37.769Z,1565134357.769 [sample:SampleRepeater] Stopped
2019-08-06T23:32:37.769Z,1565134357.769 [sample:SampleRepeater](DEBUG): Aggregate::uninitialize sample:SampleRepeater
2019-08-06T23:32:37.770Z,1565134357.770 [sample:SampleRepeater](INFO): Running loop #3
2019-08-06T23:32:37.770Z,1565134357.770 [sample:SampleRepeater] Running Loop=3
2019-08-06T23:32:37.770Z,1565134357.770 [sample:SampleRepeater](DEBUG): Aggregate::initialize sample:SampleRepeater
2019-08-06T23:32:37.770Z,1565134357.770 [sample:SampleRepeater:Sample] Running Loop=1
2019-08-06T23:32:37.770Z,1565134357.770 [sample:SampleRepeater:Sample](DEBUG): Aggregate::initialize sample:SampleRepeater:Sample
2019-08-06T23:32:38.070Z,1565134358.070 [sample:SampleAtDepth] Running Loop=1
2019-08-06T23:32:38.070Z,1565134358.070 [sample:SampleAtDepth](DEBUG): Aggregate::initialize sample:SampleAtDepth
2019-08-06T23:32:38.070Z,1565134358.070 [sample:SampleAtDepth:ApproachDepth] Running Loop=1
2019-08-06T23:32:38.071Z,1565134358.070 [sample:SampleAtDepth:ApproachDepth](DEBUG): Aggregate::initialize sample:SampleAtDepth:ApproachDepth
2019-08-06T23:32:38.071Z,1565134358.071 [sample:SampleAtDepth:ApproachDepth:A] Running Loop=1
2019-08-06T23:32:38.071Z,1565134358.071 [sample:SampleAtDepth:ApproachDepth:A](INFO): Moving to 7.000000 m 
2019-08-06T23:32:38.071Z,1565134358.071 [sample:SampleAtDepth:ApproachDepth:A] Stopped
2019-08-06T23:32:38.071Z,1565134358.071 [sample:SampleAtDepth:ApproachDepth:B.Pitch] Running Loop=1
2019-08-06T23:32:38.071Z,1565134358.071 [sample:SampleAtDepth:ApproachDepth:B.Pitch](DEBUG): Initialize.
2019-08-06T23:34:21.906Z,1565134461.906 [sample:SampleAtDepth:ApproachDepth:B.Pitch] Stopped
2019-08-06T23:34:21.906Z,1565134461.906 [sample:SampleAtDepth:ApproachDepth](INFO): Completed sample:SampleAtDepth:ApproachDepth
2019-08-06T23:34:21.907Z,1565134461.907 [sample:SampleAtDepth:ApproachDepth] Stopped
2019-08-06T23:34:21.907Z,1565134461.907 [sample:SampleAtDepth:ApproachDepth](DEBUG): Aggregate::uninitialize sample:SampleAtDepth:ApproachDepth
2019-08-06T23:34:21.907Z,1565134461.907 [sample:SampleAtDepth:SampleWrapper] Running Loop=1
2019-08-06T23:34:21.907Z,1565134461.907 [sample:SampleAtDepth:SampleWrapper](DEBUG): Aggregate::initialize sample:SampleAtDepth:SampleWrapper
2019-08-06T23:34:21.907Z,1565134461.907 [sample:SampleAtDepth:SampleWrapper:A.Pitch] Running Loop=1
2019-08-06T23:34:21.907Z,1565134461.907 [sample:SampleAtDepth:SampleWrapper:A.Pitch](DEBUG): Initialize.
2019-08-06T23:34:21.907Z,1565134461.907 [sample:SampleAtDepth:SampleWrapper:B] Running Loop=1
2019-08-06T23:34:22.315Z,1565134462.315 [sample:SampleAtDepth:SampleWrapper:B](IMPORTANT): At 6.976165 m , settling for 1.000000 min 
2019-08-06T23:34:22.315Z,1565134462.315 [sample:SampleAtDepth:SampleWrapper:B] Stopped
2019-08-06T23:34:22.315Z,1565134462.315 [sample:SampleAtDepth:SampleWrapper:C.Wait] Running Loop=1
2019-08-06T23:34:22.315Z,1565134462.315 [sample:SampleAtDepth:SampleWrapper:C.Wait](DEBUG): Initialize Wait Component.
2019-08-06T23:35:22.908Z,1565134522.908 [sample:SampleAtDepth:SampleWrapper:C.Wait](INFO): Done Waiting.
2019-08-06T23:35:22.908Z,1565134522.908 [sample:SampleAtDepth:SampleWrapper:C.Wait] Stopped
2019-08-06T23:35:22.908Z,1565134522.908 [sample:SampleAtDepth:SampleWrapper:C.Wait](DEBUG): Uninitialize Wait Component.
2019-08-06T23:35:22.909Z,1565134522.909 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler] Running Loop=1
2019-08-06T23:35:22.909Z,1565134522.909 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler](DEBUG): Aggregate::initialize sample:SampleAtDepth:SampleWrapper:SampleCANONSampler
2019-08-06T23:35:22.909Z,1565134522.909 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:A] Running Loop=1
2019-08-06T23:35:22.909Z,1565134522.909 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:B] Running Loop=1
2019-08-06T23:35:22.909Z,1565134522.909 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:TriggerCANONSampler] Running Loop=1
2019-08-06T23:35:24.118Z,1565134524.118 [CANONSampler](INFO): Powering up
2019-08-06T23:35:55.241Z,1565134555.241 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:TriggerCANONSampler] Stopped
2019-08-06T23:35:55.242Z,1565134555.242 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:D] Running Loop=1
2019-08-06T23:35:55.622Z,1565134555.622 [CANONSampler](INFO): CANON SAMPLER 1.3

2019-08-06T23:35:55.622Z,1565134555.622 [CANONSampler](INFO): UI[1]=2

2019-08-06T23:35:55.622Z,1565134555.622 [CANONSampler](INFO): Saving.... DONE

2019-08-06T23:35:55.623Z,1565134555.623 [CANONSampler](INFO): S>S

2019-08-06T23:35:55.623Z,1565134555.623 [CANONSampler](INFO): MO=0

2019-08-06T23:35:55.637Z,1565134555.637 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:D](ERROR): data element is not active.
2019-08-06T23:35:55.638Z,1565134555.638 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:D](ERROR): data element is not active.
2019-08-06T23:35:55.638Z,1565134555.638 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:D](IMPORTANT): CANONSampler sampling at 8.308452 m in nan degC water with nan ug/l chlorophyll fluorescence.
2019-08-06T23:35:55.638Z,1565134555.638 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:D] Stopped
2019-08-06T23:35:55.638Z,1565134555.638 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:E] Running Loop=1
2019-08-06T23:35:56.035Z,1565134556.035 [CANONSampler](INFO): ELMO will go to position 3

2019-08-06T23:35:56.036Z,1565134556.036 [CANONSampler](INFO): Initial cnts = 0

2019-08-06T23:35:56.832Z,1565134556.832 [CANONSampler](INFO): HOMINGMO=1, MF=0, PX=0

2019-08-06T23:35:58.049Z,1565134558.049 [CANONSampler](INFO): MO=0, MF=0, PX=0

2019-08-06T23:35:58.049Z,1565134558.049 [CANONSampler](INFO):  DONE with MO=0, MF=0

2019-08-06T23:36:10.973Z,1565134570.973 [CANONSampler](INFO): Pumping DONE

2019-08-06T23:36:11.792Z,1565134571.792 [CANONSampler](INFO): Next

2019-08-06T23:36:12.997Z,1565134572.997 [CANONSampler](INFO): MO=1, MF=0, PX=426

2019-08-06T23:36:14.206Z,1565134574.206 [CANONSampler](INFO): MO=1, MF=0, PX=1367

2019-08-06T23:36:15.023Z,1565134575.023 [CANONSampler](INFO): MO=1, MF=0, PX=2307

2019-08-06T23:36:16.225Z,1565134576.225 [CANONSampler](INFO): MO=1, MF=0, PX=3244

2019-08-06T23:36:17.033Z,1565134577.033 [CANONSampler](INFO): MO=1, MF=0, PX=4183

2019-08-06T23:36:18.253Z,1565134578.253 [CANONSampler](INFO): MO=1, MF=0, PX=5127

2019-08-06T23:36:19.054Z,1565134579.054 [CANONSampler](INFO): MO=1, MF=0, PX=6068

2019-08-06T23:36:20.263Z,1565134580.263 [CANONSampler](INFO): MO=1, MF=0, PX=7009

2019-08-06T23:36:21.070Z,1565134581.070 [CANONSampler](INFO): MO=1, MF=0, PX=7946

2019-08-06T23:36:22.299Z,1565134582.299 [CANONSampler](INFO): MO=1, MF=0, PX=8885

2019-08-06T23:36:23.097Z,1565134583.097 [CANONSampler](INFO): MO=1, MF=0, PX=9824

2019-08-06T23:36:24.309Z,1565134584.309 [CANONSampler](INFO): MO=1, MF=0, PX=10761

2019-08-06T23:36:24.309Z,1565134584.309 [CANONSampler](INFO): MO=0, MF=0, PX=11672

2019-08-06T23:36:24.310Z,1565134584.310 [CANONSampler](INFO):  DONE with MO=0, MF=0, PX=11679

2019-08-06T23:36:24.311Z,1565134584.311 [CANONSampler](INFO): Saving.... DONE

2019-08-06T23:38:04.093Z,1565134684.093 [CANONSampler](INFO): Pumping DONE

2019-08-06T23:38:05.305Z,1565134685.305 [CANONSampler](INFO): HOMINGMO=1, MF=0, PX=18

2019-08-06T23:38:06.125Z,1565134686.125 [CANONSampler](INFO): MO=1, MF=0, PX=458

2019-08-06T23:38:07.329Z,1565134687.329 [CANONSampler](INFO): MO=1, MF=0, PX=1563

2019-08-06T23:38:08.134Z,1565134688.134 [CANONSampler](INFO): MO=1, MF=0, PX=2683

2019-08-06T23:38:09.354Z,1565134689.354 [CANONSampler](INFO): MO=1, MF=0, PX=3805

2019-08-06T23:38:10.153Z,1565134690.153 [CANONSampler](INFO): MO=1, MF=0, PX=4932

2019-08-06T23:38:11.370Z,1565134691.370 [CANONSampler](INFO): MO=1, MF=0, PX=6059

2019-08-06T23:38:12.180Z,1565134692.180 [CANONSampler](INFO): MO=1, MF=0, PX=7185

2019-08-06T23:38:13.389Z,1565134693.389 [CANONSampler](INFO): MO=1, MF=0, PX=8311

2019-08-06T23:38:14.190Z,1565134694.190 [CANONSampler](INFO): MO=1, MF=0, PX=9443

2019-08-06T23:38:15.413Z,1565134695.413 [CANONSampler](INFO): MO=1, MF=0, PX=10574

2019-08-06T23:38:16.232Z,1565134696.232 [CANONSampler](INFO): MO=1, MF=0, PX=11702

2019-08-06T23:38:17.432Z,1565134697.432 [CANONSampler](INFO): MO=1, MF=0, PX=12833

2019-08-06T23:38:18.241Z,1565134698.241 [CANONSampler](INFO): MO=1, MF=0, PX=13961

2019-08-06T23:38:19.459Z,1565134699.459 [CANONSampler](INFO): MO=1, MF=0, PX=15089

2019-08-06T23:38:20.254Z,1565134700.254 [CANONSampler](INFO): MO=1, MF=0, PX=16217

2019-08-06T23:38:21.469Z,1565134701.469 [CANONSampler](INFO): MO=1, MF=0, PX=17346

2019-08-06T23:38:22.288Z,1565134702.288 [CANONSampler](INFO): MO=1, MF=0, PX=18476

2019-08-06T23:38:23.483Z,1565134703.483 [CANONSampler](INFO): MO=1, MF=0, PX=19603

2019-08-06T23:38:24.694Z,1565134704.694 [CANONSampler](INFO): MO=1, MF=0, PX=20734

2019-08-06T23:38:25.512Z,1565134705.512 [CANONSampler](INFO): MO=1, MF=0, PX=21868

2019-08-06T23:38:26.718Z,1565134706.718 [CANONSampler](INFO): MO=1, MF=0, PX=22997

2019-08-06T23:38:27.530Z,1565134707.530 [CANONSampler](INFO): MO=1, MF=0, PX=24129

2019-08-06T23:38:28.750Z,1565134708.750 [CANONSampler](INFO): MO=1, MF=0, PX=25267

2019-08-06T23:38:29.542Z,1565134709.542 [CANONSampler](INFO): MO=1, MF=0, PX=26403

2019-08-06T23:38:30.755Z,1565134710.755 [CANONSampler](INFO): MO=1, MF=0, PX=27537

2019-08-06T23:38:31.572Z,1565134711.572 [CANONSampler](INFO): MO=1, MF=0, PX=28674

2019-08-06T23:38:32.777Z,1565134712.777 [CANONSampler](INFO): MO=1, MF=0, PX=29811

2019-08-06T23:38:33.589Z,1565134713.589 [CANONSampler](INFO): MO=1, MF=0, PX=30953

2019-08-06T23:38:34.804Z,1565134714.804 [CANONSampler](INFO): MO=1, MF=0, PX=32095

2019-08-06T23:38:35.603Z,1565134715.603 [CANONSampler](INFO): MO=1, MF=0, PX=-32299

2019-08-06T23:38:36.817Z,1565134716.817 [CANONSampler](INFO): MO=1, MF=0, PX=-31152

2019-08-06T23:38:37.625Z,1565134717.625 [CANONSampler](INFO): MO=1, MF=0, PX=-30006

2019-08-06T23:38:38.838Z,1565134718.838 [CANONSampler](INFO): MO=1, MF=0, PX=-28859

2019-08-06T23:38:39.650Z,1565134719.650 [CANONSampler](INFO): MO=1, MF=0, PX=-27711

2019-08-06T23:38:40.861Z,1565134720.861 [CANONSampler](INFO): MO=1, MF=0, PX=-26564

2019-08-06T23:38:41.674Z,1565134721.674 [CANONSampler](INFO): MO=1, MF=0, PX=-25415

2019-08-06T23:38:42.875Z,1565134722.875 [CANONSampler](INFO): MO=1, MF=0, PX=-24270

2019-08-06T23:38:43.689Z,1565134723.689 [CANONSampler](INFO): MO=1, MF=0, PX=-23126

2019-08-06T23:38:44.905Z,1565134724.905 [CANONSampler](INFO): MO=1, MF=0, PX=-21979

2019-08-06T23:38:45.711Z,1565134725.711 [CANONSampler](INFO): MO=1, MF=0, PX=-20834

2019-08-06T23:38:46.918Z,1565134726.918 [CANONSampler](INFO): MO=1, MF=0, PX=-19691

2019-08-06T23:38:48.135Z,1565134728.135 [CANONSampler](INFO): MO=1, MF=0, PX=-18544

2019-08-06T23:38:48.934Z,1565134728.934 [CANONSampler](INFO): MO=1, MF=0, PX=-17394

2019-08-06T23:38:50.148Z,1565134730.148 [CANONSampler](INFO): MO=1, MF=0, PX=-16507

2019-08-06T23:38:50.957Z,1565134730.957 [CANONSampler](INFO): MO=1, MF=0, PX=27

2019-08-06T23:38:52.172Z,1565134732.172 [CANONSampler](INFO): MO=1, MF=0, PX=763

2019-08-06T23:38:52.981Z,1565134732.981 [CANONSampler](INFO): MO=1, MF=0, PX=1501

2019-08-06T23:38:54.197Z,1565134734.197 [CANONSampler](INFO): MO=1, MF=0, PX=1501

2019-08-06T23:38:55.004Z,1565134735.004 [CANONSampler](INFO): MO=1, MF=0, PX=1501

2019-08-06T23:38:56.213Z,1565134736.213 [CANONSampler](INFO): MO=0, MF=0, PX=1501

2019-08-06T23:38:56.214Z,1565134736.214 [CANONSampler](INFO):  DONE with MO=0, MF=0

2019-08-06T23:38:56.214Z,1565134736.214 [CANONSampler](INFO): Sample 3, err_code=0

2019-08-06T23:38:56.214Z,1565134736.214 [CANONSampler](IMPORTANT): Sample 3, err_code=0

2019-08-06T23:38:56.224Z,1565134736.224 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:E] Stopped
2019-08-06T23:38:56.224Z,1565134736.224 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler](INFO): Completed sample:SampleAtDepth:SampleWrapper:SampleCANONSampler
2019-08-06T23:38:56.225Z,1565134736.225 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler] Stopped
2019-08-06T23:38:56.225Z,1565134736.225 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler](DEBUG): Aggregate::uninitialize sample:SampleAtDepth:SampleWrapper:SampleCANONSampler
2019-08-06T23:38:56.225Z,1565134736.225 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:A] Stopped
2019-08-06T23:38:56.225Z,1565134736.225 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:B] Stopped
2019-08-06T23:38:56.225Z,1565134736.225 [sample:SampleAtDepth:SampleWrapper:SampleESP] Running Loop=1
2019-08-06T23:38:56.225Z,1565134736.225 [sample:SampleAtDepth:SampleWrapper:SampleESP](DEBUG): Aggregate::initialize sample:SampleAtDepth:SampleWrapper:SampleESP
2019-08-06T23:38:56.225Z,1565134736.225 [sample:SampleAtDepth:SampleWrapper:SampleESP:TriggerESP] Running Loop=1
2019-08-06T23:38:56.629Z,1565134736.629 [sample:SampleAtDepth:SampleWrapper:SampleESP] Stopped
2019-08-06T23:38:56.630Z,1565134736.630 [sample:SampleAtDepth:SampleWrapper:SampleESP](DEBUG): Aggregate::uninitialize sample:SampleAtDepth:SampleWrapper:SampleESP
2019-08-06T23:38:56.630Z,1565134736.630 [sample:SampleAtDepth:SampleWrapper:SampleESP:TriggerESP] Stopped
2019-08-06T23:38:56.630Z,1565134736.630 [sample:SampleAtDepth:SampleWrapper](INFO): Completed sample:SampleAtDepth:SampleWrapper
2019-08-06T23:38:56.630Z,1565134736.630 [sample:SampleAtDepth:SampleWrapper] Stopped
2019-08-06T23:38:56.630Z,1565134736.630 [sample:SampleAtDepth:SampleWrapper](DEBUG): Aggregate::uninitialize sample:SampleAtDepth:SampleWrapper
2019-08-06T23:38:56.630Z,1565134736.630 [sample:SampleAtDepth:SampleWrapper:A.Pitch] Stopped
2019-08-06T23:38:56.631Z,1565134736.631 [sample:SampleAtDepth](INFO): Completed sample:SampleAtDepth
2019-08-06T23:38:56.631Z,1565134736.631 [sample:SampleAtDepth] Stopped
2019-08-06T23:38:56.631Z,1565134736.631 [sample:SampleAtDepth](DEBUG): Aggregate::uninitialize sample:SampleAtDepth
2019-08-06T23:38:57.016Z,1565134737.016 [CANONSampler](INFO): Powering down
2019-08-06T23:38:57.129Z,1565134737.129 [sample:SampleRepeater:Sample](INFO): Completed sample:SampleRepeater:Sample
2019-08-06T23:38:57.129Z,1565134737.129 [sample:SampleRepeater:Sample] Stopped
2019-08-06T23:38:57.129Z,1565134737.129 [sample:SampleRepeater:Sample](DEBUG): Aggregate::uninitialize sample:SampleRepeater:Sample
2019-08-06T23:38:57.129Z,1565134737.129 [sample:SampleRepeater](INFO): Completed sample:SampleRepeater
2019-08-06T23:38:57.129Z,1565134737.129 [sample:SampleRepeater] Stopped
2019-08-06T23:38:57.130Z,1565134737.130 [sample:SampleRepeater](DEBUG): Aggregate::uninitialize sample:SampleRepeater
2019-08-06T23:38:57.130Z,1565134737.130 [sample](INFO): Completed sample
2019-08-06T23:38:57.130Z,1565134737.130 [MissionManager](INFO): sample is completed.
2019-08-06T23:38:57.130Z,1565134737.130 [MissionManager](INFO): Uninitializing Mission sample
2019-08-06T23:38:57.131Z,1565134737.131 [sample] Stopped
2019-08-06T23:38:57.131Z,1565134737.131 [sample](DEBUG): Aggregate::uninitialize sample
2019-08-06T23:38:57.131Z,1565134737.131 [sample:A.AbortSample] Stopped
2019-08-06T23:38:57.131Z,1565134737.131 [sample:A.AbortSample](INFO): Uninitializing AbortSample.
2019-08-06T23:38:57.131Z,1565134737.131 [sample:B.Pitch] Stopped
2019-08-06T23:38:57.131Z,1565134737.131 [sample:C.SetSpeed] Stopped
2019-08-06T23:38:57.131Z,1565134737.131 [sample:C.SetSpeed](DEBUG): Uninitialize.
2019-08-06T23:38:57.429Z,1565134737.429 [MissionManager](IMPORTANT): Started mission Default
2019-08-06T23:38:57.429Z,1565134737.429 [Default] Running Loop=1
2019-08-06T23:38:57.429Z,1565134737.429 [Default](DEBUG): Aggregate::initialize Default
2019-08-06T23:38:57.429Z,1565134737.429 [Default:B.GoToSurface] Running Loop=1
2019-08-06T23:38:57.429Z,1565134737.429 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-08-06T23:38:57.430Z,1565134737.430 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-08-06T23:38:57.430Z,1565134737.430 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-08-06T23:38:57.430Z,1565134737.430 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-08-06T23:38:57.431Z,1565134737.431 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-08-06T23:38:57.431Z,1565134737.431 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-08-06T23:38:57.431Z,1565134737.431 [Default:A.Wait] Running Loop=1
2019-08-06T23:38:57.431Z,1565134737.431 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-08-06T23:38:57.843Z,1565134737.843 [ElevatorOffsetCalculator](INFO): New estimator for commanded vars: speed 1.00 m/s, pitch 30.00 deg, mass-position -31.00 mm (1 active estimators).
2019-08-06T23:38:58.009Z,1565134738.009 [Radio_Surface](INFO): Powering up
2019-08-06T23:39:03.637Z,1565134743.637 [DataOverHttps](INFO): Radio surface powered ON.
2019-08-06T23:39:10.459Z,1565134750.459 [Default:A.Wait](INFO): Done Waiting.
2019-08-06T23:39:10.459Z,1565134750.459 [Default:A.Wait] Stopped
2019-08-06T23:39:10.459Z,1565134750.459 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-08-06T23:39:33.970Z,1565134773.970 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-06T23:40:04.681Z,1565134804.681 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-06T23:40:35.417Z,1565134835.417 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-06T23:40:55.507Z,1565134855.507 [Default:CheckIn] Running Loop=1
2019-08-06T23:40:55.507Z,1565134855.507 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-08-06T23:40:55.507Z,1565134855.507 [Default:CheckIn:Read_GPS] Running Loop=1
2019-08-06T23:40:57.109Z,1565134857.109 [NAL9602](DEBUG): Fix Requested
2019-08-06T23:41:06.125Z,1565134866.125 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-06T23:41:28.311Z,1565134888.311 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2019-08-06T23:41:28.389Z,1565134888.389 [NAL9602](FAULT): received: 
+CSQ:1

OK852, 2, 0, 0, 0

OK
2019-08-06T23:41:28.389Z,1565134888.389 [NAL9602] Data Fault, FailCount= 1
2019-08-06T23:41:28.389Z,1565134888.389 [NAL9602](ERROR): Data Fault
2019-08-06T23:41:28.493Z,1565134888.493 [CBIT](ERROR): Data Fault in component: NAL9602
2019-08-06T23:41:28.722Z,1565134888.722 [NAL9602](INFO): Powering down
2019-08-06T23:41:29.637Z,1565134889.637 [CBIT](INFO): Clearing failed state for component NAL9602
2019-08-06T23:41:29.637Z,1565134889.637 [NAL9602] No Fault, FailCount= 1
2019-08-06T23:41:36.829Z,1565134896.829 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-06T23:41:59.026Z,1565134919.026 [NAL9602](INFO): Powering up NAL9602
2019-08-06T23:42:07.533Z,1565134927.533 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-08-06T23:42:09.926Z,1565134929.926 [NAL9602](INFO): NAL9602 initialized
2019-08-06T23:42:10.749Z,1565134930.749 [NAL9602](DEBUG): Fix Requested
2019-08-06T23:42:34.681Z,1565134954.681 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003191
2019-08-06T23:44:44.255Z,1565135084.255 [NAL9602](INFO): SBD MO Status=2, MOMSN=15852, MT Status=2, MTMSN=0
2019-08-06T23:44:44.255Z,1565135084.255 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-08-06T23:45:55.808Z,1565135155.808 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-08-06T23:40:55.5Z
2019-08-06T23:45:55.809Z,1565135155.809 [Default:CheckIn:Read_GPS] Stopped
2019-08-06T23:45:55.809Z,1565135155.809 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-08-06T23:45:59.802Z,1565135159.802 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-08-06T23:46:02.104Z,1565135162.104 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190806T225425/Courier0016.lzma
2019-08-06T23:46:02.910Z,1565135162.910 [DataOverHttps](INFO): Moved sent file to Logs/20190806T225425/Courier0016.lzma.bak
2019-08-06T23:46:02.910Z,1565135162.910 [DataOverHttps](INFO): SBD MOMSN=11530296
2019-08-06T23:46:14.308Z,1565135174.308 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190806T225425/Courier0019.lzma
2019-08-06T23:46:15.110Z,1565135175.110 [DataOverHttps](INFO): Moved sent file to Logs/20190806T225425/Courier0019.lzma.bak
2019-08-06T23:46:15.110Z,1565135175.110 [DataOverHttps](INFO): SBD MOMSN=11530298
2019-08-06T23:46:27.450Z,1565135187.450 [DataOverHttps](INFO): Sending 999 bytes from file Logs/20190806T225425/Express0017.lzma
2019-08-06T23:46:28.254Z,1565135188.254 [DataOverHttps](INFO): Moved sent file to Logs/20190806T225425/Express0017.lzma.bak
2019-08-06T23:46:28.255Z,1565135188.255 [DataOverHttps](INFO): SBD MOMSN=11530300
2019-08-06T23:46:30.510Z,1565135190.510 [NAL9602](INFO): Not Powering down - fast GPS
2019-08-06T23:46:40.548Z,1565135200.548 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190806T225425/Express0020.lzma
2019-08-06T23:46:41.354Z,1565135201.354 [DataOverHttps](INFO): Moved sent file to Logs/20190806T225425/Express0020.lzma.bak
2019-08-06T23:46:41.354Z,1565135201.354 [DataOverHttps](INFO): SBD MOMSN=11530330
2019-08-06T23:46:43.071Z,1565135203.071 [Default:CheckIn:Read_Iridium] Stopped
2019-08-06T23:46:43.072Z,1565135203.072 [Default:CheckIn:C.Wait] Running Loop=1
2019-08-06T23:46:43.072Z,1565135203.072 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-08-06T23:51:43.636Z,1565135503.636 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-08-06T23:51:43.636Z,1565135503.636 [Default:CheckIn:C.Wait] Stopped
2019-08-06T23:51:43.636Z,1565135503.636 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-08-06T23:51:43.636Z,1565135503.636 [Default:CheckIn:D] Running Loop=1
2019-08-06T23:51:44.049Z,1565135504.049 [Default:CheckIn:D] Stopped
2019-08-06T23:51:44.049Z,1565135504.049 [Default:CheckIn:E] Running Loop=1
2019-08-06T23:51:44.450Z,1565135504.450 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 12.776998 min 
2019-08-06T23:51:44.450Z,1565135504.450 [Default:CheckIn:E] Stopped
2019-08-06T23:51:44.450Z,1565135504.450 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-08-06T23:51:44.450Z,1565135504.450 [Default:CheckIn] Stopped
2019-08-06T23:51:44.450Z,1565135504.450 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-08-06T23:51:44.450Z,1565135504.450 [Default:CheckIn](INFO): Running loop #2
2019-08-06T23:51:44.450Z,1565135504.450 [Default:CheckIn] Running Loop=2
2019-08-06T23:51:44.451Z,1565135504.451 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-08-06T23:51:44.451Z,1565135504.451 [Default:CheckIn:Read_GPS] Running Loop=1
2019-08-06T23:51:46.035Z,1565135506.035 [NAL9602](FAULT): GPS failed to acquire within timeout.
2019-08-06T23:51:46.036Z,1565135506.036 [NAL9602] Data Fault, FailCount= 2
2019-08-06T23:51:46.036Z,1565135506.036 [NAL9602](ERROR): Data Fault
2019-08-06T23:51:46.113Z,1565135506.113 [CBIT](ERROR): Data Fault in component: NAL9602
2019-08-06T23:51:46.446Z,1565135506.446 [NAL9602](INFO): Powering down
2019-08-06T23:51:47.279Z,1565135507.279 [CBIT](INFO): Clearing failed state for component NAL9602
2019-08-06T23:51:47.279Z,1565135507.279 [NAL9602] No Fault, FailCount= 2
2019-08-06T23:52:16.742Z,1565135536.742 [NAL9602](INFO): Powering up NAL9602
2019-08-06T23:52:27.658Z,1565135547.658 [NAL9602](INFO): NAL9602 initialized
2019-08-06T23:52:28.469Z,1565135548.469 [NAL9602](DEBUG): Fix Requested
2019-08-06T23:56:08.247Z,1565135768.247 [NAL9602](INFO): SBD MO Status=2, MOMSN=15852, MT Status=2, MTMSN=0
2019-08-06T23:56:08.248Z,1565135768.248 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-08-06T23:56:44.635Z,1565135804.635 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-08-06T23:51:44.5Z
2019-08-06T23:56:44.635Z,1565135804.635 [Default:CheckIn:Read_GPS] Stopped
2019-08-06T23:56:44.635Z,1565135804.635 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-08-06T23:56:50.787Z,1565135810.787 [CommandLine](IMPORTANT): got command show variable chloro
2019-08-06T23:56:50.792Z,1565135810.792 [CommandLine](IMPORTANT): mass_concentration_of_chlorophyll_in_sea_water (unknown)
2019-08-06T23:56:50.957Z,1565135810.957 [CommandLine](IMPORTANT): WetLabsBB2FL.bin_median_mass_concentration_of_chlorophyll_in_sea_water (microgram_per_liter)
2019-08-06T23:56:50.957Z,1565135810.957 [CommandLine](IMPORTANT): WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water (microgram_per_liter)
2019-08-06T23:56:50.958Z,1565135810.958 [CommandLine](IMPORTANT): WetLabsBB2FL.bin_variance_mass_concentration_of_chlorophyll_in_sea_water (microgram_per_liter)
2019-08-06T23:56:50.958Z,1565135810.958 [CommandLine](IMPORTANT): WetLabsBB2FL.mass_concentration_of_chlorophyll_in_sea_water (microgram_per_liter)
2019-08-06T23:56:51.288Z,1565135811.288 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190806T225425/Courier0022.lzma
2019-08-06T23:56:52.094Z,1565135812.094 [DataOverHttps](INFO): Moved sent file to Logs/20190806T225425/Courier0022.lzma.bak
2019-08-06T23:56:52.094Z,1565135812.094 [DataOverHttps](INFO): SBD MOMSN=11530372
2019-08-06T23:57:03.437Z,1565135823.437 [CommandLine](IMPORTANT): got command report touch WetLabsBB2FL.mass_concentration_of_chlorophyll_in_sea_water
2019-08-06T23:57:06.916Z,1565135826.916 [DataOverHttps](INFO): Sending 213 bytes from file Logs/20190806T225425/Express0023.lzma
2019-08-06T23:57:07.363Z,1565135827.363 [CommandLine](IMPORTANT): got command run ./Missions/Insert/Science.xml
2019-08-06T23:57:07.363Z,1565135827.363 [MissionManager](INFO): Loading Mission: ./Missions/Insert/Science.xml
2019-08-06T23:57:07.554Z,1565135827.554 [MissionManager](INFO): DefineArg Science.SampleISUS = 0 bool
2019-08-06T23:57:07.558Z,1565135827.558 [MissionManager](INFO): DefineArg Science.SampleISUSmaxPitch = 60.000000 arcdeg
2019-08-06T23:57:07.561Z,1565135827.561 [MissionManager](INFO): DefineArg Science.SampleISUSminPitch = -60.000000 arcdeg
2019-08-06T23:57:07.564Z,1565135827.564 [MissionManager](INFO): DefineArg Science.PeakDetectChlActive = 0 bool
2019-08-06T23:57:07.567Z,1565135827.567 [MissionManager](INFO): DefineArg Science.TimeWindowPeakReport = nan min
2019-08-06T23:57:07.571Z,1565135827.571 [MissionManager](INFO): DefineArg Science.HighestChlPeakReportActive = 0 bool
2019-08-06T23:57:07.574Z,1565135827.574 [MissionManager](INFO): DefineArg Science.PatchTracking = 0 bool
2019-08-06T23:57:07.577Z,1565135827.577 [MissionManager](INFO): DefineArg Science.FilterWidthHorizontal = 3.000000 count
2019-08-06T23:57:07.580Z,1565135827.580 [MissionManager](INFO): DefineArg Science.NumProfilesSlidingwindow = 100.000000 count
2019-08-06T23:57:07.583Z,1565135827.583 [MissionManager](INFO): DefineArg Science.OffPeakFractionHorizontal = 80.000000 %
2019-08-06T23:57:07.611Z,1565135827.611 [MissionManager](INFO): DefineArg Science.PeakDetectNO3Active = 0 bool
2019-08-06T23:57:07.669Z,1565135827.669 [MissionManager](INFO): DefineArg Science.PeakDetectOilActive = 0 bool
2019-08-06T23:57:07.672Z,1565135827.672 [MissionManager](INFO): DefineArg Science.PeakDetectFDOMActive = 0 bool
2019-08-06T23:57:07.684Z,1565135827.684 [MissionManager](INFO): DefineArg Science.UpwardDerivativeOfTemperatureActive = 0 bool
2019-08-06T23:57:07.696Z,1565135827.696 [MissionManager](INFO): DefineArg Science.EnabledAanderaaO2 = 1.000000 bool
2019-08-06T23:57:07.723Z,1565135827.723 [DataOverHttps](INFO): Moved sent file to Logs/20190806T225425/Express0023.lzma.bak
2019-08-06T23:57:07.723Z,1565135827.723 [DataOverHttps](INFO): SBD MOMSN=11530374
2019-08-06T23:57:07.721Z,1565135827.721 [MissionManager](INFO): DefineArg Science.EnabledNeilBrown = 1.000000 bool
2019-08-06T23:57:07.736Z,1565135827.736 [MissionManager](INFO): DefineArg Science.EnabledSeabird = 1.000000 bool
2019-08-06T23:57:07.740Z,1565135827.740 [MissionManager](INFO): DefineArg Science.EnabledTurbulence_NPS = 0.000000 bool
2019-08-06T23:57:07.760Z,1565135827.760 [MissionManager](INFO): DefineArg Science.EnabledWetLabsBB2FL = 1.000000 bool
2019-08-06T23:57:07.768Z,1565135827.768 [MissionManager](INFO): DefineArg Science.EnabledWetLabsSeaOWL_UV_A = 0.000000 bool
2019-08-06T23:57:07.789Z,1565135827.789 [MissionManager](INFO): DefineArg Science.EnabledWetLabsUBAT = 0.000000 bool
2019-08-06T23:57:07.809Z,1565135827.809 [MissionManager](INFO): DefineArg Science.EnabledISUS = 0.000000 bool
2019-08-06T23:57:07.817Z,1565135827.817 [MissionManager](INFO): DefineArg Science.LowPassWindowLength = 20.000000 count
2019-08-06T23:57:07.820Z,1565135827.820 [MissionManager](INFO): DefineArg Science.MedianFilterLen = 5.000000 count
2019-08-06T23:57:07.828Z,1565135827.828 [MissionManager](INFO): DefineArg Science.PeakChlShallowBound = nan m
2019-08-06T23:57:07.855Z,1565135827.855 [MissionManager](INFO): DefineArg Science.PeakChlDeepBound = nan m
2019-08-06T23:57:07.858Z,1565135827.858 [MissionManager](INFO): DefineArg Science.PeakShallowBound = nan m
2019-08-06T23:57:07.874Z,1565135827.874 [MissionManager](INFO): DefineArg Science.PeakDeepBound = nan m
2019-08-06T23:57:07.877Z,1565135827.877 [MissionManager](INFO): DefineOutput Science.PeakChl = 0.000000 ug/l
2019-08-06T23:57:07.880Z,1565135827.880 [MissionManager](INFO): DefineOutput Science.PeakChlDepth = 0.000000 m
2019-08-06T23:57:07.884Z,1565135827.884 [MissionManager](INFO): DefineOutput Science.PeakChlTemperature = 0.000000 degC
2019-08-06T23:57:07.920Z,1565135827.920 [MissionManager](INFO): DefineOutput Science.PeakChlLatitude = nan arcdeg
2019-08-06T23:57:07.924Z,1565135827.924 [MissionManager](INFO): DefineOutput Science.PeakChlLongitude = nan arcdeg
2019-08-06T23:57:07.927Z,1565135827.927 [MissionManager](INFO): DefineOutput Science.PeakNO3 = 0.000000 umol/l
2019-08-06T23:57:07.942Z,1565135827.942 [MissionManager](INFO): DefineOutput Science.PeakNO3Depth = 0.000000 m
2019-08-06T23:57:07.945Z,1565135827.945 [MissionManager](INFO): DefineOutput Science.PeakNO3Latitude = nan arcdeg
2019-08-06T23:57:07.949Z,1565135827.949 [MissionManager](INFO): DefineOutput Science.PeakNO3Longitude = nan arcdeg
2019-08-06T23:57:07.952Z,1565135827.952 [MissionManager](INFO): DefineOutput Science.PatchChl = 0.000000 m
2019-08-06T23:57:07.976Z,1565135827.976 [MissionManager](INFO): DefineOutput Science.PatchChlDepth = 0.000000 m
2019-08-06T23:57:07.979Z,1565135827.979 [MissionManager](INFO): DefineOutput Science.PatchChlLatitude = nan arcdeg
2019-08-06T23:57:07.983Z,1565135827.983 [MissionManager](INFO): DefineOutput Science.PatchChlLongitude = nan arcdeg
2019-08-06T23:57:07.000Z,1565135828.000 [MissionManager](INFO): DefineOutput Science.PatchChlDistance = nan m
2019-08-06T23:57:08.003Z,1565135828.003 [MissionManager](INFO): DefineOutput Science.PeakOil = 0.000000 kg/m3
2019-08-06T23:57:08.006Z,1565135828.006 [MissionManager](INFO): DefineOutput Science.PeakOilDepth = 0.000000 m
2019-08-06T23:57:08.046Z,1565135828.046 [MissionManager](INFO): DefineOutput Science.PeakOilLatitude = nan arcdeg
2019-08-06T23:57:08.077Z,1565135828.077 [MissionManager](INFO): DefineOutput Science.PeakOilLongitude = nan arcdeg
2019-08-06T23:57:08.080Z,1565135828.080 [MissionManager](INFO): DefineOutput Science.PeakFDOM = 0.000000 ppb
2019-08-06T23:57:08.084Z,1565135828.084 [MissionManager](INFO): DefineOutput Science.PeakFDOMDepth = 0.000000 m
2019-08-06T23:57:08.101Z,1565135828.101 [MissionManager](INFO): DefineOutput Science.PeakFDOMLatitude = nan arcdeg
2019-08-06T23:57:08.104Z,1565135828.104 [MissionManager](INFO): DefineOutput Science.PeakFDOMLongitude = nan arcdeg
2019-08-06T23:57:08.168Z,1565135828.168 [MissionManager](INFO): DefineOutput Science.PatchFDOMDistance = nan m
2019-08-06T23:57:08.242Z,1565135828.242 [Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2019-08-06T23:57:08.270Z,1565135828.270 [Science:HighestChlPeakReport:A.PeakDetectHorizontal](DEBUG): Construct PeakDetectHorizontal.
2019-08-06T23:57:08.369Z,1565135828.369 [Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2019-08-06T23:57:08.404Z,1565135828.404 [Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2019-08-06T23:57:08.495Z,1565135828.495 [Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2019-08-06T23:57:08.611Z,1565135828.611 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<!-- ====================
     Generated by TethysL
     ==================== -->
<Aggregate xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
           xmlns="Tethys"
           xmlns:Units="Tethys/Units"
           xmlns:Science="Tethys/Science"
           xmlns:Universal="Tethys/Universal"
           xmlns:Trigger="Tethys/Trigger"
           xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                               Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                               Tethys/Science http://okeanids.mbari.org/tethys/Xml/Science.xsd
                               Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd
                               Tethys/Trigger http://okeanids.mbari.org/tethys/Xml/Trigger.xsd"
       Id="Science">

    <DefineArg Name="SampleISUS"><Description>
        Set either this or PeakDetectNO3Active to True in order to sample
        Nitrate. EnabledISUS must also be true.
    </Description><False/></DefineArg>

    <DefineArg Name="SampleISUSmaxPitch"><Description>
        Maximum pitch to sample ISUS. (EnabledISUS must also be true.)
    </Description><Units:degree/><Value>60.0</Value></DefineArg>

    <DefineArg Name="SampleISUSminPitch"><Description>
        Minimum pitch to sample ISUS. (EnabledISUS must also be true.)
    </Description><Units:degree/><Value>-60.0</Value></DefineArg>

    <DefineArg Name="PeakDetectChlActive"><Description>
        Turns on peak detection of Cholorphyll.
    </Description><False/></DefineArg>

    <DefineArg Name="TimeWindowPeakReport"><Description>
        If greater than zero, report a peak every window. If NaN or zero, this
        variable is ignored.
    </Description><Units:minute/><Value>NaN</Value></DefineArg>

    <DefineArg Name="HighestChlPeakReportActive"><Description>
        Turns on reporting of the highest peak value on yo-yo profiles in a
        horizontal sliding window (of length numProfilesSlidingwindow)
    </Description><False/></DefineArg>

    <DefineArg Name="PatchTracking"><Description>
        If tracking a patch
    </Description><False/></DefineArg>

<!--debug
    </Description><True/></DefineArg>
-->

    <DefineArg Name="FilterWidthHorizontal"><Description>
        Width of boxcar filter applied to yoyo-wise chl peaks to pick out the
        highest peak.
    </Description><Units:count/><Value>3</Value></DefineArg>

    <DefineArg Name="NumProfilesSlidingwindow"><Description>
        Length of horizontal sliding window. The highest yoyo-wise chl peak
        (after low-pass filtering by a filter of length FilterWidthHorizontal)
        within this window.
    </Description><Units:count/><Value>100</Value></DefineArg>

    <DefineArg Name="OffPeakFractionHorizontal"><Description>
        When filtered horizontal value is this fraction of the peak, consider it
        outside the patch.
    </Description><Units:percent/><Value>80</Value></DefineArg>

    <DefineArg Name="PeakDetectNO3Active"><Description>
        Turns on peak detection of Nitrate (and turns on ISUS).
    </Description><False/></DefineArg>

    <DefineArg Name="PeakDetectOilActive"><Description>
        Turns on peak detection of Dissolved Oil.
    </Description><False/></DefineArg>

    <DefineArg Name="PeakDetectFDOMActive"><Description>
        Turns on peak detection of concentration_of_chromophoric_dissolved_organic_matter_in_sea_water from FDOM sensor.
    </Description><False/></DefineArg>
    
    <DefineArg Name="UpwardDerivativeOfTemperatureActive"><Description>
        Turns on seawater temperature derivative.
    </Description><False/></DefineArg>

    <DefineArg Name="EnabledAanderaaO2"><Description>
        Automatically set to True if the Aanderaa O2 sensor is installed. Set to
        false to disable reading Aandera O2.
    </Description><Science:Aanderaa_O2.loadAtStartup/></DefineArg>

    <DefineArg Name="EnabledNeilBrown"><Description>
        Automatically set to true if the Neil Brown CTD is enabled. Set to false
        to disable reading from the Neil Brown.
    </Description><Science:CTD_NeilBrown.loadAtStartup/></DefineArg>

    <DefineArg Name="EnabledSeabird"><Description>
        Automatically set to true if the CTD is enabled. Set to false to disable
        reading from the CTD.
    </Description><Science:CTD_Seabird.loadAtStartup/></DefineArg>

    <DefineArg Name="EnabledTurbulence_NPS"><Description>
        Automatically set to true if the NPS Turbulence sensor is enabled. Set
        to false to disable reading from the NPS Turbulence sensor.
    </Description><Science:Turbulence_NPS.loadAtStartup/></DefineArg>

    <DefineArg Name="EnabledWetLabsBB2FL"><Description>
        Automatically set to true if the the WetLabs BB2FL is enabled. Set to
        false to disable the WetLabs BB2FL.
    </Description><Science:WetLabsBB2FL.loadAtStartup/></DefineArg>

    <DefineArg Name="EnabledWetLabsSeaOWL_UV_A"><Description>
        Automatically set to true if the the WetLabs SeaOWL UV-A is enabled. Set
        to false to disable the WetLabs SeaOWL UV-A.
    </Description><Science:WetLabsSeaOWL_UV_A.loadAtStartup/></DefineArg>

    <DefineArg Name="EnabledWetLabsUBAT"><Description>
        Automatically set to true if the the WetLabs UBAT is enabled. Set
        to false to disable the WetLabs UBAT.
    </Description><Science:WetLabsUBAT.loadAtStartup/></DefineArg>    

    <DefineArg Name="EnabledISUS"><Description>
        Automatically set to True if ISUS is enabled. Set to false to disable
        ISUS.
    </Description><Science:ISUS.loadAtStartup/></DefineArg>

    <DefineArg Name="LowPassWindowLength"><Description>
        Low-pass window length (based on depth sensor sampling interval 0.4
        second) for low-pass filtering.
    </Description><Units:count/><Value>20</Value></DefineArg>

    <DefineArg Name="MedianFilterLen"><Description>
        Median filter length (only for chlorophyll fluorescence which tends to have spikes)
    </Description><Units:count/><Value>5</Value></DefineArg>

    <DefineArg Name="PeakChlShallowBound"><Description>
        Shallow depth bound for detecting chl peak on each descent or ascent
        profile.
    </Description><Units:meter/><Value>NaN</Value></DefineArg>

<!--debug
    </Description><Units:meter/><Value>10</Value></DefineArg>
-->

    <DefineArg Name="PeakChlDeepBound"><Description>
        Deep depth bound for detecting chl peak on each descent or ascent
        profile.
    </Description><Units:meter/><Value>NaN</Value></DefineArg>

<!--debug
    </Description><Units:meter/><Value>20</Value></DefineArg>
-->

    <DefineArg Name="PeakShallowBound"><Description>
        Shallow depth bound for detecting any peak on each descent or ascent
        profile.
    </Description><Units:meter/><Value>NaN</Value></DefineArg>

    <DefineArg Name="PeakDeepBound"><Description>
        Deep depth bound for detecting any peak on each descent or ascent
        profile.
    </Description><Units:meter/><Value>NaN</Value></DefineArg>

    <DefineOutput Name="PeakChl"><Units:microgram_per_liter/><Value>0</Value></DefineOutput>

    <DefineOutput Name="PeakChlDepth"><Units:meter/><Value>0</Value></DefineOutput>

    <DefineOutput Name="PeakChlTemperature"><Units:celsius/><Value>0</Value></DefineOutput>

    <DefineOutput Name="PeakChlLatitude"><Units:degree/><Value>NaN</Value></DefineOutput>

    <DefineOutput Name="PeakChlLongitude"><Units:degree/><Value>NaN</Value></DefineOutput>

    <DefineOutput Name="PeakNO3"><Units:micromole_per_liter/><Value>0</Value></DefineOutput>

    <DefineOutput Name="PeakNO3Depth"><Units:meter/><Value>0</Value></DefineOutput>

    <DefineOutput Name="PeakNO3Latitude"><Units:degree/><Value>NaN</Value></DefineOutput>

    <DefineOutput Name="PeakNO3Longitude"><Units:degree/><Value>NaN</Value></DefineOutput>

    <DefineOutput Name="PatchChl"><Units:meter/><Value>0</Value></DefineOutput>

    <DefineOutput Name="PatchChlDepth"><Units:meter/><Value>0</Value></DefineOutput>

    <DefineOutput Name="PatchChlLatitude"><Units:degree/><Value>NaN</Value></DefineOutput>

    <DefineOutput Name="PatchChlLongitude"><Units:degree/><Value>NaN</Value></DefineOutput>

    <DefineOutput Name="PatchChlDistance"><Units:meter/><Value>NaN</Value></DefineOutput>

    <DefineOutput Name="PeakOil"><Units:kilogram_per_cubic_meter/><Value>0</Value></DefineOutput>

    <DefineOutput Name="PeakOilDepth"><Units:meter/><Value>0</Value></DefineOutput>

    <DefineOutput Name="PeakOilLatitude"><Units:degree/><Value>NaN</Value></DefineOutput>

    <DefineOutput Name="PeakOilLongitude"><Units:degree/><Value>NaN</Value></DefineOutput>

    <DefineOutput Name="PeakFDOM"><Units:part_per_billion/><Value>0</Value></DefineOutput>

    <DefineOutput Name="PeakFDOMDepth"><Units:meter/><Value>0</Value></DefineOutput>

    <DefineOutput Name="PeakFDOMLatitude"><Units:degree/><Value>NaN</Value></DefineOutput>

    <DefineOutput Name="PeakFDOMLongitude"><Units:degree/><Value>NaN</Value></DefineOutput>
    
    <DefineOutput Name="PatchFDOMDistance"><Units:meter/><Value>NaN</Value></DefineOutput>    
    
    <Parallel/>

    <ReadData Strategy="MinError">
        <While>
            <Arg Name="EnabledAanderaaO2"/>
        </While>
        <Universal:mass_concentration_of_oxygen_in_sea_water/>
    </ReadData>

    <ReadData>
        <While>
            <Arg Name="EnabledISUS"/>
            <And><Universal:platform_pitch_angle/><Lt><Arg Name="SampleISUSmaxPitch"/></Lt><And><Universal:platform_pitch_angle/><Gt><Arg Name="SampleISUSminPitch"/></Gt><And><Arg Name="SampleISUS"/><Or><Arg Name="PeakDetectNO3Active"/></Or></And></And></And>
        </While>
        <Universal:mole_concentration_of_nitrate_in_sea_water/>
    </ReadData>

    <ReadData Strategy="MinError">
        <While>
            <Arg Name="EnabledNeilBrown"/>
            <Or><Arg Name="EnabledSeabird"/></Or>
        </While>
        <Universal:sea_water_temperature/>
        <Universal:sea_water_salinity/>
    </ReadData>

    <ReadData Strategy="MinError">
        <While>
            <Arg Name="EnabledSeabird"/>
        </While>
        <Science:CTD_Seabird.sea_water_temperature/>
        <Science:CTD_Seabird.sea_water_salinity/>
    </ReadData>

    <ReadData Strategy="MinError">
        <While>
            <Arg Name="EnabledNeilBrown"/>
            <Or><Arg Name="EnabledSeabird"/></Or>
            <And><Arg Name="UpwardDerivativeOfTemperatureActive"/></And>
        </While>
        <Universal:upward_derivative_of_sea_water_temperature/>
    </ReadData>

    <ReadData Strategy="MinError">
        <While>
            <Arg Name="EnabledTurbulence_NPS"/>
        </While>
        <Science:Turbulence_NPS.MicroCond/>
    </ReadData>

    <ReadData Strategy="MinError">
        <While>
            <Arg Name="EnabledWetLabsBB2FL"/>
            <Or><Arg Name="PeakDetectChlActive"/></Or>
        </While>
        <Universal:mass_concentration_of_chlorophyll_in_sea_water/>
    </ReadData>

    <ReadData Strategy="MinError">
        <While>
            <Arg Name="EnabledWetLabsUBAT"/>
        </While>
        <Science:WetLabsUBAT.biolum_potential/>
    </ReadData>

<!--debug-->

    <ReadData Id="Read_Oil" Strategy="MinError">
        <While>
            <Arg Name="EnabledWetLabsSeaOWL_UV_A"/>
            <Or><Arg Name="PeakDetectOilActive"/></Or>
        </While>
        <Universal:mass_concentration_of_chlorophyll_in_sea_water/>
    </ReadData>

    <Aggregate Id="PeakDetectChl">

        <While>
            <Arg Name="PeakDetectChlActive"/>
        </While>

        <Trigger:PeakDetectVsDepth>
            <Sequence/>
            <Setting><Trigger:PeakDetectVsDepth.detect/><Universal:mass_concentration_of_chlorophyll_in_sea_water/></Setting>
            <Setting><Trigger:PeakDetectVsDepth.timeWindowPeakReport/><Arg Name="TimeWindowPeakReport"/></Setting>
            <Setting><Trigger:PeakDetectVsDepth.windowLength/><Arg Name="LowPassWindowLength"/></Setting>
            <Setting><Trigger:PeakDetectVsDepth.medianFilterLength/><Arg Name="MedianFilterLen"/></Setting>
            <Setting><Trigger:PeakDetectVsDepth.shallowBound/><Arg Name="PeakChlShallowBound"/></Setting>
            <Setting><Trigger:PeakDetectVsDepth.deepBound/><Arg Name="PeakChlDeepBound"/></Setting>
            <OutputArg Name="PeakChl"><Trigger:PeakDetectVsDepth.peakDetect/></OutputArg>
            <OutputArg Name="PeakChlDepth"><Trigger:PeakDetectVsDepth.peakDepth/></OutputArg>
            <OutputArg Name="PeakChlTemperature"><Trigger:PeakDetectVsDepth.peakTemperature/></OutputArg>
            <OutputArg Name="PeakChlLatitude"><Trigger:PeakDetectVsDepth.peakLatitude/></OutputArg>
            <OutputArg Name="PeakChlLongitude"><Trigger:PeakDetectVsDepth.peakLongitude/></OutputArg>
        </Trigger:PeakDetectVsDepth>

<!--debug
        <Syslog Severity="Important">PeakChl, PeakChlLatitude, PeakChlLongitude = <Arg Name="PeakChl"/><Units:microgram_per_liter/>, <Arg Name="PeakChlLatitude"/><Units:degree/>, <Arg Name="PeakChlLongitude"/><Units:degree/></Syslog>
-->

        <SendData Service="Express"><Arg Name="PeakChl"/><Arg Name="PeakChlDepth"/>
        </SendData>

    </Aggregate>

    <Aggregate Id="HighestChlPeakReport">

        <While>
            <Arg Name="HighestChlPeakReportActive"/>
        </While>

        <Trigger:PeakDetectHorizontal>
            <Sequence/>
            <Setting><Trigger:PeakDetectHorizontal.detectFrom/><Arg Name="PeakChl"/></Setting>
            <Setting><Trigger:PeakDetectHorizontal.depthFrom/><Arg Name="PeakChlDepth"/></Setting>
            <Setting><Trigger:PeakDetectHorizontal.latitudeFrom/><Arg Name="PeakChlLatitude"/></Setting>
            <Setting><Trigger:PeakDetectHorizontal.longitudeFrom/><Arg Name="PeakChlLongitude"/></Setting>
            <Setting><Trigger:PeakDetectHorizontal.patchTracking/><Arg Name="PatchTracking"/></Setting>
            <Setting><Trigger:PeakDetectHorizontal.filterWidth/><Arg Name="FilterWidthHorizontal"/></Setting>
            <Setting><Trigger:PeakDetectHorizontal.numProfilesSlidingwindow/><Arg Name="NumProfilesSlidingwindow"/></Setting>
            <Setting><Trigger:PeakDetectHorizontal.offPeakFraction/><Arg Name="OffPeakFractionHorizontal"/></Setting>
            <OutputArg Name="PatchChl"><Trigger:PeakDetectHorizontal.peakDetect/></OutputArg>
            <OutputArg Name="PatchChlDepth"><Trigger:PeakDetectHorizontal.peakDepth/></OutputArg>
            <OutputArg Name="PatchChlLatitude"><Trigger:PeakDetectHorizontal.peakLatitude/></OutputArg>
            <OutputArg Name="PatchChlLongitude"><Trigger:PeakDetectHorizontal.peakLongitude/></OutputArg>
            <OutputArg Name="PatchChlDistance"><Trigger:PeakDetectHorizontal.peakDistance/></OutputArg>
        </Trigger:PeakDetectHorizontal>

    </Aggregate>

    <Aggregate Id="PeakDetectNO3">

        <While>
            <Arg Name="PeakDetectNO3Active"/>
        </While>

        <Trigger:PeakDetectVsDepth>
            <Sequence/>
            <Setting><Trigger:PeakDetectVsDepth.detect/><Universal:mole_concentration_of_nitrate_in_sea_water/></Setting>
            <Setting><Trigger:PeakDetectVsDepth.timeWindowPeakReport/><Arg Name="TimeWindowPeakReport"/></Setting>
            <Setting><Trigger:PeakDetectVsDepth.windowLength/><Arg Name="LowPassWindowLength"/></Setting>
            <Setting><Trigger:PeakDetectVsDepth.shallowBound/><Arg Name="PeakShallowBound"/></Setting>
            <Setting><Trigger:PeakDetectVsDepth.deepBound/><Arg Name="PeakDeepBound"/></Setting>
            <OutputArg Name="PeakNO3"><Trigger:PeakDetectVsDepth.peakDetect/></OutputArg>
            <OutputArg Name="PeakNO3Depth"><Trigger:PeakDetectVsDepth.peakDepth/></OutputArg>
            <OutputArg Name="PeakNO3Latitude"><Trigger:PeakDetectVsDepth.peakLatitude/></OutputArg>
            <OutputArg Name="PeakNO3Longitude"><Trigger:PeakDetectVsDepth.peakLongitude/></OutputArg>
        </Trigger:PeakDetectVsDepth>

        <SendData Service="Express"><Arg Name="PeakNO3"/><Arg Name="PeakNO3Depth"/>
        </SendData>

    </Aggregate>

    <Aggregate Id="PeakDetectOil">

        <While>
            <Arg Name="PeakDetectOilActive"/>
        </While>

        <Trigger:PeakDetectVsDepth>
            <Sequence/>
            <Setting><Trigger:PeakDetectVsDepth.detect/><Universal:mass_concentration_of_petroleum_hydrocarbons_in_sea_water/></Setting>
            <Setting><Trigger:PeakDetectVsDepth.timeWindowPeakReport/><Arg Name="TimeWindowPeakReport"/></Setting>
            <Setting><Trigger:PeakDetectVsDepth.windowLength/><Arg Name="LowPassWindowLength"/></Setting>
            <Setting><Trigger:PeakDetectVsDepth.shallowBound/><Arg Name="PeakShallowBound"/></Setting>
            <Setting><Trigger:PeakDetectVsDepth.deepBound/><Arg Name="PeakDeepBound"/></Setting>
            <OutputArg Name="PeakOil"><Trigger:PeakDetectVsDepth.peakDetect/></OutputArg>
            <OutputArg Name="PeakOilDepth"><Trigger:PeakDetectVsDepth.peakDepth/></OutputArg>
            <OutputArg Name="PeakOilLatitude"><Trigger:PeakDetectVsDepth.peakLatitude/></OutputArg>
            <OutputArg Name="PeakOilLongitude"><Trigger:PeakDetectVsDepth.peakLongitude/></OutputArg>
        </Trigger:PeakDetectVsDepth>

        <SendData Service="Express"><Arg Name="PeakOil"/><Arg Name="PeakOilDepth"/>
        </SendData>

    </Aggregate>

    <Aggregate Id="PeakDetectFDOM">

        <While>
            <Arg Name="PeakDetectFDOMActive"/>
        </While>

        <Trigger:PeakDetectVsDepth>
            <Sequence/>
            <Setting><Trigger:PeakDetectVsDepth.detect/><Universal:concentration_of_chromophoric_dissolved_organic_matter_in_sea_water/></Setting>
            <Setting><Trigger:PeakDetectVsDepth.timeWindowPeakReport/><Arg Name="TimeWindowPeakReport"/></Setting>
            <Setting><Trigger:PeakDetectVsDepth.windowLength/><Arg Name="LowPassWindowLength"/></Setting>
            <Setting><Trigger:PeakDetectVsDepth.shallowBound/><Arg Name="PeakShallowBound"/></Setting>
            <Setting><Trigger:PeakDetectVsDepth.deepBound/><Arg Name="PeakDeepBound"/></Setting>
            <OutputArg Name="PeakFDOM"><Trigger:PeakDetectVsDepth.peakDetect/></OutputArg>
            <OutputArg Name="PeakFDOMDepth"><Trigger:PeakDetectVsDepth.peakDepth/></OutputArg>
            <OutputArg Name="PeakFDOMTemperature"><Trigger:PeakDetectVsDepth.peakTemperature/></OutputArg>
            <OutputArg Name="PeakFDOMLatitude"><Trigger:PeakDetectVsDepth.peakLatitude/></OutputArg>
            <OutputArg Name="PeakFDOMLongitude"><Trigger:PeakDetectVsDepth.peakLongitude/></OutputArg>
        </Trigger:PeakDetectVsDepth>

        <SendData Service="Express"><Arg Name="PeakFDOM"/><Arg Name="PeakFDOMDepth"/>
        </SendData>

    </Aggregate>

</Aggregate>


2019-08-06T23:57:08.628Z,1565135828.628 [CommandLine](IMPORTANT): Running ./Missions/Insert/Science.xml
2019-08-06T23:57:08.907Z,1565135828.907 [Default] Stopped
2019-08-06T23:57:08.907Z,1565135828.907 [Default](DEBUG): Aggregate::uninitialize Default
2019-08-06T23:57:08.907Z,1565135828.907 [Default:B.GoToSurface] Stopped
2019-08-06T23:57:08.907Z,1565135828.907 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-08-06T23:57:08.907Z,1565135828.907 [Default:CheckIn] Stopped
2019-08-06T23:57:08.907Z,1565135828.907 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-08-06T23:57:08.907Z,1565135828.907 [Default:CheckIn:Read_Iridium] Stopped
2019-08-06T23:57:08.907Z,1565135828.907 [MissionManager](IMPORTANT): Started mission Science
2019-08-06T23:57:08.908Z,1565135828.908 [Science] Running Loop=1
2019-08-06T23:57:08.908Z,1565135828.908 [Science](DEBUG): Aggregate::initialize Science
2019-08-06T23:57:08.908Z,1565135828.908 [Science:A] Running Loop=1
2019-08-06T23:57:08.908Z,1565135828.908 [Science:B] Running Loop=1
2019-08-06T23:57:08.908Z,1565135828.908 [Science:C] Running Loop=1
2019-08-06T23:57:08.908Z,1565135828.908 [Science:D] Running Loop=1
2019-08-06T23:57:08.908Z,1565135828.908 [Science:E] Running Loop=1
2019-08-06T23:57:08.908Z,1565135828.908 [Science:F] Running Loop=1
2019-08-06T23:57:08.908Z,1565135828.908 [Science:G] Running Loop=1
2019-08-06T23:57:08.908Z,1565135828.908 [Science:H] Running Loop=1
2019-08-06T23:57:08.908Z,1565135828.908 [Science:Read_Oil] Running Loop=1
2019-08-06T23:57:08.908Z,1565135828.908 [Science:PeakDetectChl] Running Loop=1
2019-08-06T23:57:08.925Z,1565135828.925 [Science:PeakDetectChl](DEBUG): Aggregate::initialize Science:PeakDetectChl
2019-08-06T23:57:08.926Z,1565135828.926 [Science:PeakDetectChl:A.PeakDetectVsDepth] Running Loop=1
2019-08-06T23:57:08.926Z,1565135828.926 [Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Initialize.
2019-08-06T23:57:08.934Z,1565135828.934 [Science:HighestChlPeakReport] Running Loop=1
2019-08-06T23:57:08.934Z,1565135828.934 [Science:HighestChlPeakReport](DEBUG): Aggregate::initialize Science:HighestChlPeakReport
2019-08-06T23:57:08.934Z,1565135828.934 [Science:HighestChlPeakReport:A.PeakDetectHorizontal] Running Loop=1
2019-08-06T23:57:08.934Z,1565135828.934 [Science:HighestChlPeakReport:A.PeakDetectHorizontal](INFO): Initialize.
2019-08-06T23:57:08.934Z,1565135828.934 [Science:PeakDetectNO3] Running Loop=1
2019-08-06T23:57:08.935Z,1565135828.935 [Science:PeakDetectNO3](DEBUG): Aggregate::initialize Science:PeakDetectNO3
2019-08-06T23:57:08.935Z,1565135828.935 [Science:PeakDetectNO3:A.PeakDetectVsDepth] Running Loop=1
2019-08-06T23:57:08.935Z,1565135828.935 [Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Initialize.
2019-08-06T23:57:08.949Z,1565135828.949 [Science:PeakDetectOil] Running Loop=1
2019-08-06T23:57:08.949Z,1565135828.949 [Science:PeakDetectOil](DEBUG): Aggregate::initialize Science:PeakDetectOil
2019-08-06T23:57:08.949Z,1565135828.949 [Science:PeakDetectOil:A.PeakDetectVsDepth] Running Loop=1
2019-08-06T23:57:08.949Z,1565135828.949 [Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Initialize.
2019-08-06T23:57:08.951Z,1565135828.951 [Science:PeakDetectFDOM] Running Loop=1
2019-08-06T23:57:08.951Z,1565135828.951 [Science:PeakDetectFDOM](DEBUG): Aggregate::initialize Science:PeakDetectFDOM
2019-08-06T23:57:08.951Z,1565135828.951 [Science:PeakDetectFDOM:A.PeakDetectVsDepth] Running Loop=1
2019-08-06T23:57:08.951Z,1565135828.951 [Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Initialize.
2019-08-06T23:57:08.966Z,1565135828.966 [Science:PeakDetectFDOM] Stopped
2019-08-06T23:57:08.966Z,1565135828.966 [Science:PeakDetectFDOM](DEBUG): Aggregate::uninitialize Science:PeakDetectFDOM
2019-08-06T23:57:08.966Z,1565135828.966 [Science:PeakDetectFDOM:A.PeakDetectVsDepth] Stopped
2019-08-06T23:57:08.966Z,1565135828.966 [Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2019-08-06T23:57:08.966Z,1565135828.966 [Science:PeakDetectOil] Stopped
2019-08-06T23:57:08.967Z,1565135828.967 [Science:PeakDetectOil](DEBUG): Aggregate::uninitialize Science:PeakDetectOil
2019-08-06T23:57:08.967Z,1565135828.967 [Science:PeakDetectOil:A.PeakDetectVsDepth] Stopped
2019-08-06T23:57:08.967Z,1565135828.967 [Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2019-08-06T23:57:08.967Z,1565135828.967 [Science:PeakDetectNO3] Stopped
2019-08-06T23:57:08.967Z,1565135828.967 [Science:PeakDetectNO3](DEBUG): Aggregate::uninitialize Science:PeakDetectNO3
2019-08-06T23:57:08.967Z,1565135828.967 [Science:PeakDetectNO3:A.PeakDetectVsDepth] Stopped
2019-08-06T23:57:08.967Z,1565135828.967 [Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2019-08-06T23:57:08.967Z,1565135828.967 [Science:HighestChlPeakReport] Stopped
2019-08-06T23:57:08.967Z,1565135828.967 [Science:HighestChlPeakReport](DEBUG): Aggregate::uninitialize Science:HighestChlPeakReport
2019-08-06T23:57:08.967Z,1565135828.967 [Science:HighestChlPeakReport:A.PeakDetectHorizontal] Stopped
2019-08-06T23:57:08.967Z,1565135828.967 [Science:HighestChlPeakReport:A.PeakDetectHorizontal](DEBUG): Uninitialize.
2019-08-06T23:57:08.967Z,1565135828.967 [Science:PeakDetectChl] Stopped
2019-08-06T23:57:08.967Z,1565135828.967 [Science:PeakDetectChl](DEBUG): Aggregate::uninitialize Science:PeakDetectChl
2019-08-06T23:57:08.968Z,1565135828.968 [Science:PeakDetectChl:A.PeakDetectVsDepth] Stopped
2019-08-06T23:57:08.968Z,1565135828.968 [Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2019-08-06T23:57:08.968Z,1565135828.968 [Science:Read_Oil] Stopped
2019-08-06T23:57:08.968Z,1565135828.968 [Science:H] Stopped
2019-08-06T23:57:08.968Z,1565135828.968 [Science:G] Running Loop=1
2019-08-06T23:57:08.968Z,1565135828.968 [Science:G](DEBUG): Initialize ReadDataComponent to sense mass_concentration_of_chlorophyll_in_sea_water
2019-08-06T23:57:08.981Z,1565135828.981 [Science:F] Stopped
2019-08-06T23:57:08.981Z,1565135828.981 [Science:E] Stopped
2019-08-06T23:57:08.981Z,1565135828.981 [Science:D] Running Loop=1
2019-08-06T23:57:08.982Z,1565135828.982 [Science:D](DEBUG): Initialize ReadDataComponent to sense CTD_Seabird.sea_water_temperature
2019-08-06T23:57:08.982Z,1565135828.982 [Science:D](DEBUG): Initialize ReadDataComponent to sense CTD_Seabird.sea_water_salinity
2019-08-06T23:57:08.982Z,1565135828.982 [Science:C] Running Loop=1
2019-08-06T23:57:08.983Z,1565135828.983 [Science:C](DEBUG): Initialize ReadDataComponent to sense sea_water_temperature
2019-08-06T23:57:08.984Z,1565135828.984 [Science:C](DEBUG): Initialize ReadDataComponent to sense sea_water_salinity
2019-08-06T23:57:08.984Z,1565135828.984 [Science:B] Stopped
2019-08-06T23:57:08.984Z,1565135828.984 [Science:A] Running Loop=1
2019-08-06T23:57:08.984Z,1565135828.984 [Science:A](DEBUG): Initialize ReadDataComponent to sense mass_concentration_of_oxygen_in_sea_water
2019-08-06T23:57:09.033Z,1565135829.033 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown.
2019-08-06T23:57:09.046Z,1565135829.046 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4
2019-08-06T23:57:09.349Z,1565135829.349 [WetLabsBB2FL](INFO): Opening uart, block timeout 10ths=2
2019-08-06T23:57:09.350Z,1565135829.350 [WetLabsBB2FL](INFO): Powering up
2019-08-06T23:57:09.358Z,1565135829.358 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20
2019-08-06T23:57:12.131Z,1565135832.131 [Reporter](INFO): WetLabsBB2FL.mass_concentration_of_chlorophyll_in_sea_water 0.000000 ug/l
2019-08-06T23:57:12.366Z,1565135832.366 [CTD_Seabird](ERROR): Failed to parse device response: <!--startlogging-->
2019-08-06T23:57:12.582Z,1565135832.582 [Reporter](INFO): WetLabsBB2FL.mass_concentration_of_chlorophyll_in_sea_water 0.056500 ug/l
2019-08-06T23:57:13.005Z,1565135833.005 [Reporter](INFO): WetLabsBB2FL.mass_concentration_of_chlorophyll_in_sea_water 0.056500 ug/l
2019-08-06T23:57:13.765Z,1565135833.765 [Reporter](INFO): WetLabsBB2FL.mass_concentration_of_chlorophyll_in_sea_water 0.011300 ug/l
2019-08-06T23:57:14.169Z,1565135834.169 [Reporter](INFO): WetLabsBB2FL.mass_concentration_of_chlorophyll_in_sea_water 0.011300 ug/l
2019-08-06T23:57:14.583Z,1565135834.583 [Reporter](INFO): WetLabsBB2FL.mass_concentration_of_chlorophyll_in_sea_water 0.011300 ug/l
2019-08-06T23:57:15.015Z,1565135835.015 [Reporter](INFO): WetLabsBB2FL.mass_concentration_of_chlorophyll_in_sea_water 0.033900 ug/l
2019-08-06T23:57:15.465Z,1565135835.465 [Reporter](INFO): WetLabsBB2FL.mass_concentration_of_chlorophyll_in_sea_water 0.067800 ug/l
2019-08-06T23:57:16.192Z,1565135836.192 [Reporter](INFO): WetLabsBB2FL.mass_concentration_of_chlorophyll_in_sea_water 0.022600 ug/l
2019-08-06T23:57:16.638Z,1565135836.638 [Reporter](INFO): WetLabsBB2FL.mass_concentration_of_chlorophyll_in_sea_water 0.067800 ug/l
2019-08-06T23:57:17.015Z,1565135837.015 [Reporter](INFO): WetLabsBB2FL.mass_concentration_of_chlorophyll_in_sea_water 0.067800 ug/l
2019-08-06T23:57:17.407Z,1565135837.407 [Reporter](INFO): WetLabsBB2FL.mass_concentration_of_chlorophyll_in_sea_water 0.079100 ug/l
2019-08-06T23:57:17.869Z,1565135837.869 [CommandLine](IMPORTANT): got command stop
2019-08-06T23:57:17.869Z,1565135837.869 [CommandLine](IMPORTANT): Scheduling is paused
2019-08-06T23:57:17.869Z,1565135837.869 [Supervisor](INFO): Stop Mission called by CommandLine::commandStop
2019-08-06T23:57:18.205Z,1565135838.205 [MissionManager](INFO): MissionManager is completed.
2019-08-06T23:57:18.206Z,1565135838.206 [MissionManager](INFO): Uninitializing Mission Science
2019-08-06T23:57:18.206Z,1565135838.206 [Science] Stopped
2019-08-06T23:57:18.206Z,1565135838.206 [Science](DEBUG): Aggregate::uninitialize Science
2019-08-06T23:57:18.206Z,1565135838.206 [Science:A] Stopped
2019-08-06T23:57:18.206Z,1565135838.206 [Science:C] Stopped
2019-08-06T23:57:18.206Z,1565135838.206 [Science:D] Stopped
2019-08-06T23:57:18.206Z,1565135838.206 [Science:G] Stopped
2019-08-06T23:57:18.249Z,1565135838.249 [Reporter](INFO): WetLabsBB2FL.mass_concentration_of_chlorophyll_in_sea_water 0.011300 ug/l
2019-08-06T23:57:18.505Z,1565135838.505 [WetLabsBB2FL](INFO): Powering down
2019-08-06T23:57:18.613Z,1565135838.613 [MissionManager](IMPORTANT): Started mission Default
2019-08-06T23:57:18.613Z,1565135838.613 [Default] Running Loop=1
2019-08-06T23:57:18.613Z,1565135838.613 [Default](DEBUG): Aggregate::initialize Default
2019-08-06T23:57:18.614Z,1565135838.614 [Default:B.GoToSurface] Running Loop=1
2019-08-06T23:57:18.614Z,1565135838.614 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-08-06T23:57:18.614Z,1565135838.614 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-08-06T23:57:18.614Z,1565135838.614 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-08-06T23:57:18.615Z,1565135838.615 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-08-06T23:57:18.615Z,1565135838.615 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-08-06T23:57:18.615Z,1565135838.615 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-08-06T23:57:18.616Z,1565135838.616 [Default:A.Wait] Running Loop=1
2019-08-06T23:57:18.616Z,1565135838.616 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-08-06T23:57:19.093Z,1565135839.093 [Aanderaa_O2](INFO): Powering down
2019-08-06T23:57:19.454Z,1565135839.454 [CommandLine](IMPORTANT): got command report clear
2019-08-06T23:57:31.082Z,1565135851.082 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-08-06T23:57:31.962Z,1565135851.962 [Default:A.Wait](INFO): Done Waiting.
2019-08-06T23:57:31.962Z,1565135851.962 [Default:A.Wait] Stopped
2019-08-06T23:57:31.962Z,1565135851.962 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-08-06T23:57:32.382Z,1565135852.382 [Default:CheckIn] Running Loop=1
2019-08-06T23:57:32.382Z,1565135852.382 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-08-06T23:57:32.382Z,1565135852.382 [Default:CheckIn:Read_GPS] Running Loop=1
2019-08-06T23:57:33.925Z,1565135853.925 [NAL9602](DEBUG): Fix Requested
2019-08-06T23:57:34.320Z,1565135854.320 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,235624.00,A,3648.16478,N,12147.28692,W,0.078,337.28,060819,,,A*7F
2019-08-06T23:57:34.322Z,1565135854.322 [NAL9602](INFO): GPS fix at 20190806T235624: (36.802746, -121.788115)
2019-08-06T23:57:34.381Z,1565135854.381 [Default:CheckIn:Read_GPS] Stopped
2019-08-06T23:57:34.381Z,1565135854.381 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-08-06T23:57:40.596Z,1565135860.596 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20190806T225425/Courier0025.lzma
2019-08-06T23:57:41.402Z,1565135861.402 [DataOverHttps](INFO): Moved sent file to Logs/20190806T225425/Courier0025.lzma.bak
2019-08-06T23:57:41.403Z,1565135861.403 [DataOverHttps](INFO): SBD MOMSN=11530379
2019-08-06T23:57:54.069Z,1565135874.069 [DataOverHttps](INFO): Sending 647 bytes from file Logs/20190806T225425/Express0026.lzma
2019-08-06T23:57:54.874Z,1565135874.874 [DataOverHttps](INFO): Moved sent file to Logs/20190806T225425/Express0026.lzma.bak
2019-08-06T23:57:54.875Z,1565135874.875 [DataOverHttps](INFO): SBD MOMSN=11530382
2019-08-06T23:57:57.012Z,1565135877.012 [Default:CheckIn:Read_Iridium] Stopped
2019-08-06T23:57:57.017Z,1565135877.017 [Default:CheckIn:C.Wait] Running Loop=1
2019-08-06T23:57:57.017Z,1565135877.017 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-08-06T23:58:07.474Z,1565135887.474 [NAL9602](INFO): Not Powering down - fast GPS
2019-08-06T23:59:39.318Z,1565135979.318 [DataOverHttps](IMPORTANT): SBD MTMSN=20190806T235830
2019-08-06T23:59:44.320Z,1565135984.320 [DataOverHttps](INFO): Received command:restart logs