2019-05-15T01:39:28.909Z,1557884368.909 [Supervisor](DEBUG): Initializing supervisor.
2019-05-15T01:39:28.912Z,1557884368.912 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2019-05-15T01:39:28.912Z,1557884368.912 [SyncHandler](INFO): Protected caller Thread ID is 2382
2019-05-15T01:39:28.913Z,1557884368.913 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2019-05-15T01:39:28.914Z,1557884368.914 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2019-05-15T01:39:28.914Z,1557884368.914 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 2383
2019-05-15T01:39:28.917Z,1557884368.917 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2019-05-15T01:39:28.929Z,1557884368.929 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2019-05-15T01:39:28.930Z,1557884368.930 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2019-05-15T01:39:28.931Z,1557884368.931 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 2384
2019-05-15T01:39:28.931Z,1557884368.931 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2019-05-15T01:39:28.932Z,1557884368.932 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2019-05-15T01:39:28.933Z,1557884368.933 [logger ThreadHandler](INFO): Protected caller Thread ID is 2385
2019-05-15T01:39:28.935Z,1557884368.935 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2019-05-15T01:39:28.935Z,1557884368.935 [Supervisor](INFO): Looking for Config files in directory: Config/
2019-05-15T01:39:28.937Z,1557884368.937 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2019-05-15T01:39:29.138Z,1557884369.138 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2019-05-15T01:39:29.139Z,1557884369.139 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2019-05-15T01:39:29.218Z,1557884369.218 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2019-05-15T01:39:29.658Z,1557884369.658 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2019-05-15T01:39:29.658Z,1557884369.658 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2019-05-15T01:39:29.994Z,1557884369.994 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2019-05-15T01:39:29.995Z,1557884369.995 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2019-05-15T01:39:30.090Z,1557884370.090 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2019-05-15T01:39:30.091Z,1557884370.091 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2019-05-15T01:39:30.389Z,1557884370.389 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2019-05-15T01:39:30.390Z,1557884370.390 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2019-05-15T01:39:30.585Z,1557884370.585 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2019-05-15T01:39:30.586Z,1557884370.586 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2019-05-15T01:39:31.041Z,1557884371.041 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2019-05-15T01:39:31.042Z,1557884371.042 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2019-05-15T01:39:31.147Z,1557884371.147 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2019-05-15T01:39:31.147Z,1557884371.147 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2019-05-15T01:39:31.247Z,1557884371.247 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2019-05-15T01:39:31.248Z,1557884371.248 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2019-05-15T01:39:31.825Z,1557884371.825 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2019-05-15T01:39:31.826Z,1557884371.826 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2019-05-15T01:39:32.214Z,1557884372.214 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2019-05-15T01:39:32.215Z,1557884372.215 [Supervisor](INFO): Opening Config file at: Config/._workSite.cfg
2019-05-15T01:39:32.287Z,1557884372.287 [Config/._workSite](ERROR): Could not parse value: resource
2019-05-15T01:39:32.359Z,1557884372.359 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2019-05-15T01:39:32.554Z,1557884372.554 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2019-05-15T01:39:32.554Z,1557884372.554 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2019-05-15T01:39:32.699Z,1557884372.699 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2019-05-15T01:39:32.700Z,1557884372.700 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2019-05-15T01:39:32.848Z,1557884372.848 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2019-05-15T01:39:32.851Z,1557884372.851 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2019-05-15T01:39:32.851Z,1557884372.851 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2019-05-15T01:39:32.942Z,1557884372.942 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2019-05-15T01:39:33.054Z,1557884373.054 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2019-05-15T01:39:33.351Z,1557884373.351 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2019-05-15T01:39:33.506Z,1557884373.506 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2019-05-15T01:39:33.730Z,1557884373.730 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2019-05-15T01:39:33.919Z,1557884373.919 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2019-05-15T01:39:34.222Z,1557884374.222 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2019-05-15T01:39:34.299Z,1557884374.299 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2019-05-15T01:39:34.467Z,1557884374.467 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2019-05-15T01:39:34.602Z,1557884374.602 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2019-05-15T01:39:34.722Z,1557884374.722 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg
2019-05-15T01:39:34.955Z,1557884374.955 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2019-05-15T01:39:34.956Z,1557884374.956 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/root/
2019-05-15T01:39:34.957Z,1557884374.957 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2019-05-15T01:39:34.967Z,1557884374.967 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2019-05-15T01:39:35.037Z,1557884375.037 [VerticalControl](DEBUG): Construct VerticalControl.
2019-05-15T01:39:35.154Z,1557884375.154 [VerticalControl] Loaded
2019-05-15T01:39:35.154Z,1557884375.154 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2019-05-15T01:39:35.155Z,1557884375.155 [HorizontalControl](DEBUG): Construct HorizontalControl.
2019-05-15T01:39:35.226Z,1557884375.226 [HorizontalControl] Loaded
2019-05-15T01:39:35.227Z,1557884375.227 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2019-05-15T01:39:35.227Z,1557884375.227 [SpeedControl](DEBUG): Construct SpeedControl.
2019-05-15T01:39:35.233Z,1557884375.233 [SpeedControl] Loaded
2019-05-15T01:39:35.233Z,1557884375.233 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2019-05-15T01:39:35.234Z,1557884375.234 [LoopControl](DEBUG): Construct LoopControl.
2019-05-15T01:39:35.234Z,1557884375.234 [LoopControl] Loaded
2019-05-15T01:39:35.235Z,1557884375.235 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2019-05-15T01:39:35.235Z,1557884375.235 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2019-05-15T01:39:35.236Z,1557884375.236 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2019-05-15T01:39:35.249Z,1557884375.249 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2019-05-15T01:39:35.249Z,1557884375.249 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2019-05-15T01:39:35.354Z,1557884375.354 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2019-05-15T01:39:35.354Z,1557884375.354 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2019-05-15T01:39:35.487Z,1557884375.487 [BuoyancyServo] Loaded
2019-05-15T01:39:35.487Z,1557884375.487 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2019-05-15T01:39:35.499Z,1557884375.499 [ElevatorServo] Loaded
2019-05-15T01:39:35.499Z,1557884375.499 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2019-05-15T01:39:35.510Z,1557884375.510 [MassServo] Loaded
2019-05-15T01:39:35.510Z,1557884375.510 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2019-05-15T01:39:35.522Z,1557884375.522 [RudderServo] Loaded
2019-05-15T01:39:35.522Z,1557884375.522 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2019-05-15T01:39:35.533Z,1557884375.533 [ThrusterServo] Loaded
2019-05-15T01:39:35.533Z,1557884375.533 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2019-05-15T01:39:35.534Z,1557884375.534 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2019-05-15T01:39:35.534Z,1557884375.534 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2019-05-15T01:39:35.646Z,1557884375.646 [DeadReckonUsingMultipleVelocitySources] Loaded
2019-05-15T01:39:35.646Z,1557884375.646 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2019-05-15T01:39:35.668Z,1557884375.668 [NavChart] Loaded
2019-05-15T01:39:35.668Z,1557884375.668 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2019-05-15T01:39:35.672Z,1557884375.672 [UniversalFixResidualReporter] Loaded
2019-05-15T01:39:35.672Z,1557884375.672 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2019-05-15T01:39:35.673Z,1557884375.673 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2019-05-15T01:39:35.673Z,1557884375.673 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2019-05-15T01:39:35.751Z,1557884375.751 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2019-05-15T01:39:35.752Z,1557884375.752 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2019-05-15T01:39:36.118Z,1557884376.118 [AHRS_M2] Loaded
2019-05-15T01:39:36.119Z,1557884376.119 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2019-05-15T01:39:36.195Z,1557884376.195 [DataOverHttps] Loaded
2019-05-15T01:39:36.195Z,1557884376.195 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2019-05-15T01:39:36.197Z,1557884376.197 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4087D4E0
2019-05-15T01:39:36.197Z,1557884376.197 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 2470
2019-05-15T01:39:36.211Z,1557884376.211 [Depth_Keller] Loaded
2019-05-15T01:39:36.211Z,1557884376.211 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2019-05-15T01:39:36.313Z,1557884376.313 [NAL9602] Loaded
2019-05-15T01:39:36.313Z,1557884376.313 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2019-05-15T01:39:36.330Z,1557884376.330 [Onboard] Loaded
2019-05-15T01:39:36.330Z,1557884376.330 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2019-05-15T01:39:36.333Z,1557884376.333 [Radio_Surface] Loaded
2019-05-15T01:39:36.333Z,1557884376.333 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2019-05-15T01:39:36.334Z,1557884376.334 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408AD4E0
2019-05-15T01:39:36.335Z,1557884376.335 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 2471
2019-05-15T01:39:36.469Z,1557884376.469 [DAT] Loaded
2019-05-15T01:39:36.469Z,1557884376.469 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread.
2019-05-15T01:39:36.470Z,1557884376.470 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2019-05-15T01:39:36.470Z,1557884376.470 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2019-05-15T01:39:36.512Z,1557884376.512 [DepthRateCalculator] Loaded
2019-05-15T01:39:36.513Z,1557884376.513 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2019-05-15T01:39:36.518Z,1557884376.518 [PitchRateCalculator] Loaded
2019-05-15T01:39:36.519Z,1557884376.519 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2019-05-15T01:39:36.532Z,1557884376.532 [SpeedCalculator] Loaded
2019-05-15T01:39:36.532Z,1557884376.532 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2019-05-15T01:39:36.555Z,1557884376.555 [TempGradientCalculator] Loaded
2019-05-15T01:39:36.555Z,1557884376.555 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2019-05-15T01:39:36.560Z,1557884376.560 [YawRateCalculator] Loaded
2019-05-15T01:39:36.560Z,1557884376.560 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2019-05-15T01:39:36.591Z,1557884376.591 [ElevatorOffsetCalculator] Loaded
2019-05-15T01:39:36.591Z,1557884376.591 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2019-05-15T01:39:36.591Z,1557884376.591 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2019-05-15T01:39:36.592Z,1557884376.592 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2019-05-15T01:39:36.780Z,1557884376.780 [Aanderaa_O2] Loaded
2019-05-15T01:39:36.780Z,1557884376.780 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2019-05-15T01:39:36.868Z,1557884376.868 [CTD_NeilBrown] Loaded
2019-05-15T01:39:36.868Z,1557884376.868 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2019-05-15T01:39:36.869Z,1557884376.869 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 409A74E0
2019-05-15T01:39:36.870Z,1557884376.870 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 2472
2019-05-15T01:39:36.879Z,1557884376.879 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density
2019-05-15T01:39:36.884Z,1557884376.884 [CTD_Seabird](INFO): created writer for : sea_water_density
2019-05-15T01:39:36.886Z,1557884376.886 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth
2019-05-15T01:39:36.891Z,1557884376.891 [CTD_Seabird](INFO): created writer for : depth
2019-05-15T01:39:36.891Z,1557884376.891 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure
2019-05-15T01:39:36.896Z,1557884376.896 [CTD_Seabird](INFO): created writer for : sea_water_pressure
2019-05-15T01:39:36.898Z,1557884376.898 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity
2019-05-15T01:39:36.903Z,1557884376.903 [CTD_Seabird](INFO): created writer for : sea_water_salinity
2019-05-15T01:39:36.903Z,1557884376.903 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature
2019-05-15T01:39:36.908Z,1557884376.908 [CTD_Seabird](INFO): created writer for : sea_water_temperature
2019-05-15T01:39:36.909Z,1557884376.909 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity
2019-05-15T01:39:36.915Z,1557884376.915 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity
2019-05-15T01:39:36.915Z,1557884376.915 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water
2019-05-15T01:39:36.920Z,1557884376.920 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water
2019-05-15T01:39:36.948Z,1557884376.948 [CTD_Seabird] Loaded
2019-05-15T01:39:36.948Z,1557884376.948 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2019-05-15T01:39:36.949Z,1557884376.949 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 409D74E0
2019-05-15T01:39:36.950Z,1557884376.950 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 2473
2019-05-15T01:39:36.965Z,1557884376.965 [PAR_Licor] Loaded
2019-05-15T01:39:36.965Z,1557884376.965 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2019-05-15T01:39:37.015Z,1557884377.015 [WetLabsBB2FL] Loaded
2019-05-15T01:39:37.015Z,1557884377.015 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2019-05-15T01:39:37.016Z,1557884377.016 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40A074E0
2019-05-15T01:39:37.016Z,1557884377.016 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 2474
2019-05-15T01:39:37.017Z,1557884377.017 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2019-05-15T01:39:37.018Z,1557884377.018 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2019-05-15T01:39:37.045Z,1557884377.045 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2019-05-15T01:39:37.046Z,1557884377.046 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2019-05-15T01:39:37.352Z,1557884377.352 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2019-05-15T01:39:37.353Z,1557884377.353 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2019-05-15T01:39:37.493Z,1557884377.493 [SBIT](DEBUG): Construct Startup Built In Test.
2019-05-15T01:39:37.505Z,1557884377.505 [SBIT] Loaded
2019-05-15T01:39:37.505Z,1557884377.505 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2019-05-15T01:39:37.506Z,1557884377.506 [IBIT](DEBUG): Construct Initiated Built In Test.
2019-05-15T01:39:37.518Z,1557884377.518 [IBIT] Loaded
2019-05-15T01:39:37.519Z,1557884377.519 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2019-05-15T01:39:37.522Z,1557884377.522 [CBIT](DEBUG): Construct Continuous Built In Test.
2019-05-15T01:39:37.922Z,1557884377.922 [CBIT] Loaded
2019-05-15T01:39:37.923Z,1557884377.923 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2019-05-15T01:39:37.923Z,1557884377.923 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2019-05-15T01:39:37.927Z,1557884377.927 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2019-05-15T01:39:37.927Z,1557884377.927 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2019-05-15T01:39:37.934Z,1557884377.934 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2019-05-15T01:39:37.935Z,1557884377.935 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B054E0
2019-05-15T01:39:37.935Z,1557884377.935 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 2475
2019-05-15T01:39:37.940Z,1557884377.940 [Supervisor](INFO): Main Thread ID is 802
2019-05-15T01:39:37.940Z,1557884377.940 [Supervisor](DEBUG): Running supervisor.
2019-05-15T01:39:37.941Z,1557884377.941 [CommandLine ThreadHandler](INFO): Handler Thread ID is 2476
2019-05-15T01:39:37.943Z,1557884377.943 [controlThread ThreadHandler](INFO): Handler Thread ID is 2477
2019-05-15T01:39:37.944Z,1557884377.944 [controlThread](DEBUG): Initializing ControlThread
2019-05-15T01:39:37.944Z,1557884377.944 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2019-05-15T01:39:37.946Z,1557884377.946 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2019-05-15T01:39:37.947Z,1557884377.947 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2019-05-15T01:39:37.947Z,1557884377.947 [LoopControl](DEBUG): Initialize LoopControlComponent.
2019-05-15T01:39:37.949Z,1557884377.949 [NavChart](DEBUG): Initialize NavChart Navigation.
2019-05-15T01:39:37.949Z,1557884377.949 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2019-05-15T01:39:37.954Z,1557884377.954 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2019-05-15T01:39:37.954Z,1557884377.954 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2019-05-15T01:39:37.954Z,1557884377.954 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2019-05-15T01:39:37.955Z,1557884377.955 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2019-05-15T01:39:37.955Z,1557884377.955 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2019-05-15T01:39:37.955Z,1557884377.955 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2019-05-15T01:39:37.957Z,1557884377.957 [SBIT](INFO): Initialize SBIT Component.
2019-05-15T01:39:37.958Z,1557884377.958 [SBIT](IMPORTANT): git: 2019-04-10-19-gda15b3b
2019-05-15T01:39:37.958Z,1557884377.958 [SBIT](INFO): git hash: da15b3bc615cce9b5cb8428ed44ec3695b388448
2019-05-15T01:39:37.958Z,1557884377.958 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2019-05-15T01:39:37.959Z,1557884377.959 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #1 PREEMPT Tue Dec 18 21:19:28 PST 2018
2019-05-15T01:39:37.960Z,1557884377.960 [SBIT](INFO): Beginning SBIT in 59.000000 seconds.
2019-05-15T01:39:37.961Z,1557884377.961 [IBIT](INFO): Initialize IBIT Component.
2019-05-15T01:39:37.962Z,1557884377.962 [CBIT](DEBUG): Initialize CBIT Component.
2019-05-15T01:39:37.963Z,1557884377.963 [logger ThreadHandler](INFO): Handler Thread ID is 2478
2019-05-15T01:39:37.973Z,1557884377.973 [CBIT](DEBUG): Initialized mux pins.
2019-05-15T01:39:37.973Z,1557884377.973 [CBIT](DEBUG): Initializing the watchdog timer.
2019-05-15T01:39:37.981Z,1557884377.981 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 2479
2019-05-15T01:39:37.982Z,1557884377.982 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2019-05-15T01:39:37.993Z,1557884377.993 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 2480
2019-05-15T01:39:37.997Z,1557884377.997 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2019-05-15T01:39:37.997Z,1557884377.997 [CBIT](DEBUG): Initializing heartbeat.
2019-05-15T01:39:38.005Z,1557884378.005 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 2481
2019-05-15T01:39:38.006Z,1557884378.006 [CTD_NeilBrown](INFO): Powering down
2019-05-15T01:39:38.025Z,1557884378.025 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 2482
2019-05-15T01:39:38.026Z,1557884378.026 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2019-05-15T01:39:38.033Z,1557884378.033 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20
2019-05-15T01:39:38.037Z,1557884378.037 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 2484
2019-05-15T01:39:38.038Z,1557884378.038 [WetLabsBB2FL](INFO): Powering down
2019-05-15T01:39:38.069Z,1557884378.069 [CBIT](DEBUG): Deactivating GF circuits.
2019-05-15T01:39:38.069Z,1557884378.069 [CBIT](DEBUG): Deactivating emergency mode.
2019-05-15T01:39:38.070Z,1557884378.070 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 2485
2019-05-15T01:39:38.074Z,1557884378.074 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2019-05-15T01:39:38.074Z,1557884378.074 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2019-05-15T01:39:38.074Z,1557884378.074 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2019-05-15T01:39:38.075Z,1557884378.075 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2019-05-15T01:39:38.075Z,1557884378.075 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2019-05-15T01:39:38.075Z,1557884378.075 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2019-05-15T01:39:38.075Z,1557884378.075 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2019-05-15T01:39:38.075Z,1557884378.075 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2019-05-15T01:39:38.076Z,1557884378.076 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2019-05-15T01:39:38.076Z,1557884378.076 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2019-05-15T01:39:38.076Z,1557884378.076 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2019-05-15T01:39:38.076Z,1557884378.076 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2019-05-15T01:39:38.076Z,1557884378.076 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2019-05-15T01:39:38.077Z,1557884378.077 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2019-05-15T01:39:38.077Z,1557884378.077 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2019-05-15T01:39:38.077Z,1557884378.077 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2019-05-15T01:39:38.105Z,1557884378.105 [CBIT](DEBUG): Backplane powered.
2019-05-15T01:39:38.106Z,1557884378.106 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2019-05-15T01:39:38.116Z,1557884378.116 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2019-05-15T01:39:38.143Z,1557884378.143 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
       Id="Startup">

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

    <Aggregate Id="StartupSatComms">

        <Sequence/>

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

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

    </Aggregate>

</Mission>


2019-05-15T01:39:38.144Z,1557884378.144 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2019-05-15T01:39:38.307Z,1557884378.307 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2019-05-15T01:39:38.325Z,1557884378.325 [Default:A.Wait](DEBUG): Construct Wait.
2019-05-15T01:39:38.327Z,1557884378.327 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2019-05-15T01:39:38.371Z,1557884378.371 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2019-05-15T01:39:38.373Z,1557884378.373 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2019-05-15T01:39:38.389Z,1557884378.389 [Default:E.Execute](DEBUG): Construct Execute.
2019-05-15T01:39:38.397Z,1557884378.397 [Radio_Surface](INFO): Powering up
2019-05-15T01:39:38.406Z,1557884378.406 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Universal="Tethys/Universal"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
         Id="Default">

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

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

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

    <Aggregate Id="CheckIn">

        <Sequence Repeat="288"/>

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

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

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

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

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

    </Aggregate>

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

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

</Mission>


2019-05-15T01:39:38.411Z,1557884378.411 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,NAL9602,Onboard,DAT,Aanderaa_O2,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2019-05-15T01:39:38.432Z,1557884378.432 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2019-05-15T01:39:38.483Z,1557884378.483 [Depth_Keller](ERROR): Pressure reading out of range: 1831.023193 decibar
2019-05-15T01:39:38.504Z,1557884378.504 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2019-05-15T01:39:38.504Z,1557884378.504 [DAT](INFO): Powering up
2019-05-15T01:39:38.504Z,1557884378.504 [DAT](DEBUG): Initializing DAT.
2019-05-15T01:39:38.543Z,1557884378.543 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2019-05-15T01:39:38.621Z,1557884378.621 [DepthRateCalculator](ERROR): Depth measurement is not active
2019-05-15T01:39:38.679Z,1557884378.679 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2019-05-15T01:39:38.689Z,1557884378.689 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2019-05-15T01:39:38.690Z,1557884378.690 [ElevatorServo](DEBUG): Initializing EZServoServo.
2019-05-15T01:39:38.701Z,1557884378.701 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2019-05-15T01:39:38.702Z,1557884378.702 [MassServo](DEBUG): Initializing EZServoServo.
2019-05-15T01:39:38.713Z,1557884378.713 [MassServo](DEBUG): Initializing MassServo.
2019-05-15T01:39:38.714Z,1557884378.714 [RudderServo](DEBUG): Initializing EZServoServo.
2019-05-15T01:39:38.725Z,1557884378.725 [RudderServo](DEBUG): Initializing RudderServo.
2019-05-15T01:39:38.726Z,1557884378.726 [ThrusterServo](DEBUG): Initializing EZServoServo.
2019-05-15T01:39:38.733Z,1557884378.733 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2019-05-15T01:39:39.605Z,1557884379.605 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2019-05-15T01:39:39.605Z,1557884379.605 [RudderServo](FAULT): Rudder failed to initialize
2019-05-15T01:39:39.605Z,1557884379.605 [RudderServo] Communications Fault, FailCount= 1
2019-05-15T01:39:39.605Z,1557884379.605 [RudderServo](ERROR): Communications Fault
2019-05-15T01:39:39.716Z,1557884379.716 [CBIT](ERROR): Communications Fault in component: RudderServo
2019-05-15T01:39:39.926Z,1557884379.926 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-05-15T01:39:39.926Z,1557884379.926 [RudderServo](INFO): Powering down
2019-05-15T01:39:40.595Z,1557884380.595 [RudderServo](DEBUG): Initializing EZServoServo.
2019-05-15T01:39:40.714Z,1557884380.714 [RudderServo](DEBUG): Initializing RudderServo.
2019-05-15T01:39:40.718Z,1557884380.718 [CBIT](INFO): Clearing failed state for component RudderServo
2019-05-15T01:39:40.718Z,1557884380.718 [RudderServo] No Fault, FailCount= 1
2019-05-15T01:39:41.953Z,1557884381.953 [Aanderaa_O2](INFO): Powering down
2019-05-15T01:39:51.877Z,1557884391.877 [DAT](INFO): setting local address to 2
2019-05-15T01:39:52.281Z,1557884392.281 [DAT](INFO): set local address to 2
2019-05-15T01:40:06.406Z,1557884406.406 [NAL9602](INFO): Powering up NAL9602
2019-05-15T01:40:17.314Z,1557884417.314 [NAL9602](INFO): NAL9602 initialized
2019-05-15T01:40:18.133Z,1557884418.133 [NAL9602](DEBUG): Fix Requested
2019-05-15T01:40:37.560Z,1557884437.560 [SBIT](IMPORTANT): Beginning Startup BIT
2019-05-15T01:40:37.564Z,1557884437.564 [CBIT](IMPORTANT): Beginning ground fault scan
2019-05-15T01:40:48.571Z,1557884448.571 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.007625
CHAN A1 (24V): -0.017585
CHAN A2 (12V): -0.001974
CHAN A3 (5V): -0.001107
CHAN B0 (3.3V): -0.000337
CHAN B1 (3.15aV): 0.000063
CHAN B2 (3.15bV): 0.000071
CHAN B3 (GND): -0.000319
OPEN: -0.000471
Full Scale Calc: 4.765 mA, -1.589 mA
2019-05-15T01:41:31.148Z,1557884491.148 [SBIT](IMPORTANT): SBIT PASSED
2019-05-15T01:41:31.222Z,1557884491.222 [CommandLine](IMPORTANT): got command configSet list
2019-05-15T01:41:31.222Z,1557884491.222 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2019-05-15T01:41:31.223Z,1557884491.223 [CommandLine](IMPORTANT): Aanderaa_O2.loadAtStartup=1 bool;

2019-05-15T01:41:31.223Z,1557884491.223 [CommandLine](IMPORTANT): BPC1.batteryMissingStickThreshold=8 count;

2019-05-15T01:41:31.223Z,1557884491.223 [CommandLine](IMPORTANT): BPC1.batterySamplingInterval=3 hour;

2019-05-15T01:41:31.223Z,1557884491.223 [CommandLine](IMPORTANT): BPC1.loadAtStartup=0 bool;

2019-05-15T01:41:31.223Z,1557884491.223 [CommandLine](IMPORTANT): CBIT.gf24Offset=172 microampere;

2019-05-15T01:41:31.223Z,1557884491.223 [CommandLine](IMPORTANT): DVL_micro.loadAtStartup=0 bool;

2019-05-15T01:41:31.223Z,1557884491.223 [CommandLine](IMPORTANT): DropWeight.loadAtStartup=0 bool;

2019-05-15T01:41:31.224Z,1557884491.224 [CommandLine](IMPORTANT): Express none DVL_micro.height_above_sea_floor;

2019-05-15T01:41:31.224Z,1557884491.224 [CommandLine](IMPORTANT): NAL9602.fastGPSFix=1 bool;

2019-05-15T01:41:31.224Z,1557884491.224 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=90 cubic_centimeter;

2019-05-15T01:41:31.224Z,1557884491.224 [CommandLine](IMPORTANT): VerticalControl.massDefault=-1 centimeter;

2019-05-15T01:41:31.556Z,1557884491.556 [MissionManager](IMPORTANT): Started mission Startup
2019-05-15T01:41:31.556Z,1557884491.556 [Startup] Running Loop=1
2019-05-15T01:41:31.556Z,1557884491.556 [Startup](DEBUG): Aggregate::initialize Startup
2019-05-15T01:41:31.556Z,1557884491.556 [Startup:A.GoToSurface] Running Loop=1
2019-05-15T01:41:31.556Z,1557884491.556 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-05-15T01:41:31.557Z,1557884491.557 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-05-15T01:41:31.558Z,1557884491.558 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-05-15T01:41:31.558Z,1557884491.558 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-05-15T01:41:31.558Z,1557884491.558 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-05-15T01:41:31.559Z,1557884491.559 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-05-15T01:41:31.560Z,1557884491.560 [Startup:StartupSatComms] Running Loop=1
2019-05-15T01:41:31.560Z,1557884491.560 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2019-05-15T01:41:31.560Z,1557884491.560 [Startup:StartupSatComms:A] Running Loop=1
2019-05-15T01:41:31.960Z,1557884491.960 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2019-05-15T01:42:16.864Z,1557884536.864 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.005588
2019-05-15T01:42:31.752Z,1557884551.752 [Startup:StartupSatComms:A](INFO): Timed out from 2019-05-15T01:41:31.6Z
2019-05-15T01:42:31.752Z,1557884551.752 [Startup:StartupSatComms:A] Stopped
2019-05-15T01:42:31.752Z,1557884551.752 [Startup:StartupSatComms:B] Running Loop=1
2019-05-15T01:42:32.155Z,1557884552.155 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-05-15T01:42:37.932Z,1557884557.932 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20190514T235754/Courier0046.lzma
2019-05-15T01:42:38.211Z,1557884558.211 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2019-05-15T01:42:38.211Z,1557884558.211 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-05-15T01:42:38.221Z,1557884558.221 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-05-15T01:42:38.634Z,1557884558.634 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-05-15T01:42:38.634Z,1557884558.634 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2019-05-15T01:42:38.739Z,1557884558.739 [DataOverHttps](INFO): Moved sent file to Logs/20190514T235754/Courier0046.lzma.bak
2019-05-15T01:42:38.739Z,1557884558.739 [DataOverHttps](INFO): SBD MOMSN=11060136
2019-05-15T01:42:57.460Z,1557884577.460 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190514T235754/Courier0049.lzma
2019-05-15T01:42:58.266Z,1557884578.266 [DataOverHttps](INFO): Moved sent file to Logs/20190514T235754/Courier0049.lzma.bak
2019-05-15T01:42:58.267Z,1557884578.267 [DataOverHttps](INFO): SBD MOMSN=11060157
2019-05-15T01:43:15.152Z,1557884595.152 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20190514T235754/Express0047.lzma
2019-05-15T01:43:15.958Z,1557884595.958 [DataOverHttps](INFO): Moved sent file to Logs/20190514T235754/Express0047.lzma.bak
2019-05-15T01:43:15.959Z,1557884595.959 [DataOverHttps](INFO): SBD MOMSN=11060159
2019-05-15T01:43:16.546Z,1557884596.546 [CommandLine](IMPORTANT): got command maintain control VerticalControl.massPositionAction 3.000000 centimeter
2019-05-15T01:43:16.547Z,1557884596.547 [ComponentRegistry](DEBUG): SyncComponent "Maintain_VerticalControl.massPositionAction" handled in the control thread.
2019-05-15T01:43:16.668Z,1557884596.668 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,NAL9602,Onboard,DAT,Aanderaa_O2,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,Maintain_VerticalControl.massPositionAction,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2019-05-15T01:43:29.064Z,1557884609.064 [DataOverHttps](INFO): Sending 100 bytes from file Logs/20190514T235754/Express0050.lzma
2019-05-15T01:43:29.870Z,1557884609.870 [DataOverHttps](INFO): Moved sent file to Logs/20190514T235754/Express0050.lzma.bak
2019-05-15T01:43:29.871Z,1557884609.871 [DataOverHttps](INFO): SBD MOMSN=11060162
2019-05-15T01:43:32.024Z,1557884612.024 [Startup:StartupSatComms:B](INFO): Timed out from 2019-05-15T01:42:31.8Z
2019-05-15T01:43:32.024Z,1557884612.024 [Startup:StartupSatComms:B] Stopped
2019-05-15T01:43:32.024Z,1557884612.024 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2019-05-15T01:43:32.024Z,1557884612.024 [Startup:StartupSatComms] Stopped
2019-05-15T01:43:32.024Z,1557884612.024 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2019-05-15T01:43:32.029Z,1557884612.029 [Startup](INFO): Completed Startup
2019-05-15T01:43:32.029Z,1557884612.029 [MissionManager](INFO): Startup is completed.
2019-05-15T01:43:32.030Z,1557884612.030 [MissionManager](INFO): Uninitializing Mission Startup
2019-05-15T01:43:32.030Z,1557884612.030 [Startup] Stopped
2019-05-15T01:43:32.030Z,1557884612.030 [Startup](DEBUG): Aggregate::uninitialize Startup
2019-05-15T01:43:32.030Z,1557884612.030 [Startup:A.GoToSurface] Stopped
2019-05-15T01:43:32.030Z,1557884612.030 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-05-15T01:43:32.418Z,1557884612.418 [MissionManager](IMPORTANT): Started mission Default
2019-05-15T01:43:32.418Z,1557884612.418 [Default] Running Loop=1
2019-05-15T01:43:32.418Z,1557884612.418 [Default](DEBUG): Aggregate::initialize Default
2019-05-15T01:43:32.419Z,1557884612.419 [Default:B.GoToSurface] Running Loop=1
2019-05-15T01:43:32.419Z,1557884612.419 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-05-15T01:43:32.419Z,1557884612.419 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-05-15T01:43:32.419Z,1557884612.419 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-05-15T01:43:32.419Z,1557884612.419 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-05-15T01:43:32.420Z,1557884612.420 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-05-15T01:43:32.420Z,1557884612.420 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-05-15T01:43:32.420Z,1557884612.420 [Default:A.Wait] Running Loop=1
2019-05-15T01:43:32.420Z,1557884612.420 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-05-15T01:43:45.735Z,1557884625.735 [Default:A.Wait](INFO): Done Waiting.
2019-05-15T01:43:45.735Z,1557884625.735 [Default:A.Wait] Stopped
2019-05-15T01:43:45.735Z,1557884625.735 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-05-15T01:43:46.139Z,1557884626.139 [Default:CheckIn] Running Loop=1
2019-05-15T01:43:46.139Z,1557884626.139 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-05-15T01:43:46.140Z,1557884626.140 [Default:CheckIn:Read_GPS] Running Loop=1
2019-05-15T01:43:46.540Z,1557884626.540 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2019-05-15T01:44:07.406Z,1557884647.406 [DataOverHttps](INFO): Sending 885 bytes from file Logs/20190515T013928/Express0001.lzma
2019-05-15T01:44:08.210Z,1557884648.210 [DataOverHttps](INFO): Moved sent file to Logs/20190515T013928/Express0001.lzma.bak
2019-05-15T01:44:08.210Z,1557884648.210 [DataOverHttps](INFO): SBD MOMSN=11060165
2019-05-15T01:44:58.802Z,1557884698.802 [CommandLine](IMPORTANT): got command get latitude_fix
2019-05-15T01:44:58.803Z,1557884698.803 [CommandLine](FAULT): Element has no value
2019-05-15T01:45:26.303Z,1557884726.303 [NAL9602](INFO): SBD MO Status=2, MOMSN=12109, MT Status=2, MTMSN=0
2019-05-15T01:45:26.304Z,1557884726.304 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-05-15T01:45:26.713Z,1557884726.713 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-05-15T01:45:27.525Z,1557884727.525 [NAL9602](DEBUG): Fix Requested
2019-05-15T01:45:27.920Z,1557884727.920 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,014258.00,A,3648.16157,N,12147.27982,W,0.389,0.00,150519,,,A*77
2019-05-15T01:45:27.923Z,1557884727.923 [NAL9602](INFO): GPS fix at 20190515T014258: (36.802693, -121.787997)
2019-05-15T01:45:27.948Z,1557884727.948 [Default:CheckIn:Read_GPS] Stopped
2019-05-15T01:45:27.948Z,1557884727.948 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-05-15T01:45:28.385Z,1557884728.385 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-05-15T01:46:00.361Z,1557884760.361 [NAL9602](INFO): Not Powering down - fast GPS
2019-05-15T01:46:27.177Z,1557884787.177 [DataOverHttps](INFO): Sending 213 bytes from file Logs/20190515T013928/Courier0004.lzma
2019-05-15T01:46:27.982Z,1557884787.982 [DataOverHttps](INFO): Moved sent file to Logs/20190515T013928/Courier0004.lzma.bak
2019-05-15T01:46:27.982Z,1557884787.982 [DataOverHttps](INFO): SBD MOMSN=11060199
2019-05-15T01:46:40.924Z,1557884800.924 [DataOverHttps](INFO): Sending 409 bytes from file Logs/20190515T013928/Express0005.lzma
2019-05-15T01:46:41.726Z,1557884801.726 [DataOverHttps](INFO): Moved sent file to Logs/20190515T013928/Express0005.lzma.bak
2019-05-15T01:46:41.727Z,1557884801.727 [DataOverHttps](INFO): SBD MOMSN=11060244
2019-05-15T01:46:44.860Z,1557884804.860 [Default:CheckIn:Read_Iridium] Stopped
2019-05-15T01:46:44.860Z,1557884804.860 [Default:CheckIn:C.Wait] Running Loop=1
2019-05-15T01:46:44.860Z,1557884804.860 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-05-15T01:51:45.417Z,1557885105.417 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-05-15T01:51:45.417Z,1557885105.417 [Default:CheckIn:C.Wait] Stopped
2019-05-15T01:51:45.417Z,1557885105.417 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-15T01:51:45.417Z,1557885105.417 [Default:CheckIn:D] Running Loop=1
2019-05-15T01:51:45.813Z,1557885105.813 [Default:CheckIn:D] Stopped
2019-05-15T01:51:45.813Z,1557885105.813 [Default:CheckIn:E] Running Loop=1
2019-05-15T01:51:46.226Z,1557885106.226 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 8.223248 min 
2019-05-15T01:51:46.226Z,1557885106.226 [Default:CheckIn:E] Stopped
2019-05-15T01:51:46.226Z,1557885106.226 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-05-15T01:51:46.226Z,1557885106.226 [Default:CheckIn] Stopped
2019-05-15T01:51:46.226Z,1557885106.226 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-05-15T01:51:46.226Z,1557885106.226 [Default:CheckIn](INFO): Running loop #2
2019-05-15T01:51:46.226Z,1557885106.226 [Default:CheckIn] Running Loop=2
2019-05-15T01:51:46.226Z,1557885106.226 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-05-15T01:51:46.227Z,1557885106.227 [Default:CheckIn:Read_GPS] Running Loop=1
2019-05-15T01:51:47.825Z,1557885107.825 [NAL9602](DEBUG): Fix Requested
2019-05-15T01:51:48.219Z,1557885108.219 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,014917.00,A,3648.16054,N,12147.27477,W,0.194,0.00,150519,,,A*7C
2019-05-15T01:51:48.221Z,1557885108.221 [NAL9602](INFO): GPS fix at 20190515T014917: (36.802676, -121.787913)
2019-05-15T01:51:48.246Z,1557885108.246 [Default:CheckIn:Read_GPS] Stopped
2019-05-15T01:51:48.246Z,1557885108.246 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-05-15T01:51:55.128Z,1557885115.128 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20190515T013928/Courier0007.lzma
2019-05-15T01:51:55.938Z,1557885115.938 [DataOverHttps](INFO): Moved sent file to Logs/20190515T013928/Courier0007.lzma.bak
2019-05-15T01:51:55.939Z,1557885115.939 [DataOverHttps](INFO): SBD MOMSN=11060270
2019-05-15T01:52:10.317Z,1557885130.317 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20190515T013928/Express0008.lzma
2019-05-15T01:52:11.118Z,1557885131.118 [DataOverHttps](INFO): Moved sent file to Logs/20190515T013928/Express0008.lzma.bak
2019-05-15T01:52:11.118Z,1557885131.118 [DataOverHttps](INFO): SBD MOMSN=11060273
2019-05-15T01:52:14.209Z,1557885134.209 [Default:CheckIn:Read_Iridium] Stopped
2019-05-15T01:52:14.209Z,1557885134.209 [Default:CheckIn:C.Wait] Running Loop=1
2019-05-15T01:52:14.209Z,1557885134.209 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-05-15T01:55:11.931Z,1557885311.931 [NAL9602](INFO): SBD MO Status=2, MOMSN=12109, MT Status=2, MTMSN=0
2019-05-15T01:55:11.931Z,1557885311.931 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-05-15T01:55:41.019Z,1557885341.019 [NAL9602](INFO): SBD MO Status=0, MOMSN=12109, MT Status=0, MTMSN=0
2019-05-15T01:55:41.020Z,1557885341.020 [NAL9602](INFO): No messages in MT queue
2019-05-15T01:56:11.721Z,1557885371.721 [NAL9602](INFO): Not Powering down - fast GPS
2019-05-15T01:57:14.773Z,1557885434.773 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-05-15T01:57:14.773Z,1557885434.773 [Default:CheckIn:C.Wait] Stopped
2019-05-15T01:57:14.774Z,1557885434.774 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-15T01:57:14.774Z,1557885434.774 [Default:CheckIn:D] Running Loop=1
2019-05-15T01:57:15.219Z,1557885435.219 [Default:CheckIn:D] Stopped
2019-05-15T01:57:15.220Z,1557885435.220 [Default:CheckIn:E] Running Loop=1
2019-05-15T01:57:15.571Z,1557885435.571 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 13.713351 min 
2019-05-15T01:57:15.571Z,1557885435.571 [Default:CheckIn:E] Stopped
2019-05-15T01:57:15.571Z,1557885435.571 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-05-15T01:57:15.571Z,1557885435.571 [Default:CheckIn] Stopped
2019-05-15T01:57:15.572Z,1557885435.572 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-05-15T01:57:15.572Z,1557885435.572 [Default:CheckIn](INFO): Running loop #3
2019-05-15T01:57:15.572Z,1557885435.572 [Default:CheckIn] Running Loop=3
2019-05-15T01:57:15.572Z,1557885435.572 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-05-15T01:57:15.572Z,1557885435.572 [Default:CheckIn:Read_GPS] Running Loop=1
2019-05-15T01:57:17.177Z,1557885437.177 [NAL9602](DEBUG): Fix Requested
2019-05-15T01:57:17.572Z,1557885437.572 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,015446.00,A,3648.17105,N,12147.29018,W,0.389,120.40,150519,,,A*7A
2019-05-15T01:57:17.574Z,1557885437.574 [NAL9602](INFO): GPS fix at 20190515T015446: (36.802851, -121.788170)
2019-05-15T01:57:17.598Z,1557885437.598 [Default:CheckIn:Read_GPS] Stopped
2019-05-15T01:57:17.598Z,1557885437.598 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-05-15T01:57:35.347Z,1557885455.347 [NAL9602](INFO): SBD MO Status=2, MOMSN=12110, MT Status=2, MTMSN=0
2019-05-15T01:57:35.347Z,1557885455.347 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-05-15T01:58:23.444Z,1557885503.444 [NAL9602](INFO): SBD MO Status=2, MOMSN=12110, MT Status=2, MTMSN=0
2019-05-15T01:58:23.444Z,1557885503.444 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-05-15T01:58:58.187Z,1557885538.187 [NAL9602](INFO): SBD MO Status=2, MOMSN=12110, MT Status=2, MTMSN=0
2019-05-15T01:58:58.187Z,1557885538.187 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-05-15T01:59:02.872Z,1557885542.872 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20190515T013928/Courier0010.lzma
2019-05-15T01:59:03.679Z,1557885543.679 [DataOverHttps](INFO): Moved sent file to Logs/20190515T013928/Courier0010.lzma.bak
2019-05-15T01:59:03.679Z,1557885543.679 [DataOverHttps](INFO): SBD MOMSN=11060351
2019-05-15T01:59:15.563Z,1557885555.563 [NAL9602](INFO): SBD MO Status=2, MOMSN=12110, MT Status=2, MTMSN=0
2019-05-15T01:59:15.563Z,1557885555.563 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-05-15T01:59:16.520Z,1557885556.520 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20190515T013928/Express0011.lzma
2019-05-15T01:59:17.326Z,1557885557.326 [DataOverHttps](INFO): Moved sent file to Logs/20190515T013928/Express0011.lzma.bak
2019-05-15T01:59:17.326Z,1557885557.326 [DataOverHttps](INFO): SBD MOMSN=11060355
2019-05-15T01:59:20.500Z,1557885560.500 [Default:CheckIn:Read_Iridium] Stopped
2019-05-15T01:59:20.500Z,1557885560.500 [Default:CheckIn:C.Wait] Running Loop=1
2019-05-15T01:59:20.500Z,1557885560.500 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-05-15T02:02:19.378Z,1557885739.378 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-05-15T02:02:50.079Z,1557885770.079 [NAL9602](INFO): Not Powering down - fast GPS
2019-05-15T02:04:21.010Z,1557885861.010 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-05-15T02:04:21.010Z,1557885861.010 [Default:CheckIn:C.Wait] Stopped
2019-05-15T02:04:21.010Z,1557885861.010 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-15T02:04:21.010Z,1557885861.010 [Default:CheckIn:D] Running Loop=1
2019-05-15T02:04:21.413Z,1557885861.413 [Default:CheckIn:D] Stopped
2019-05-15T02:04:21.413Z,1557885861.413 [Default:CheckIn:E] Running Loop=1
2019-05-15T02:04:21.821Z,1557885861.821 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 20.816571 min 
2019-05-15T02:04:21.821Z,1557885861.821 [Default:CheckIn:E] Stopped
2019-05-15T02:04:21.821Z,1557885861.821 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-05-15T02:04:21.821Z,1557885861.821 [Default:CheckIn] Stopped
2019-05-15T02:04:21.821Z,1557885861.821 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-05-15T02:04:21.822Z,1557885861.822 [Default:CheckIn](INFO): Running loop #4
2019-05-15T02:04:21.822Z,1557885861.822 [Default:CheckIn] Running Loop=4
2019-05-15T02:04:21.822Z,1557885861.822 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-05-15T02:04:21.822Z,1557885861.822 [Default:CheckIn:Read_GPS] Running Loop=1
2019-05-15T02:04:23.417Z,1557885863.417 [NAL9602](DEBUG): Fix Requested
2019-05-15T02:04:23.815Z,1557885863.815 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,020152.00,A,3648.16376,N,12147.28493,W,0.194,337.53,150519,,,A*75
2019-05-15T02:04:23.818Z,1557885863.818 [NAL9602](INFO): GPS fix at 20190515T020152: (36.802729, -121.788082)
2019-05-15T02:04:23.842Z,1557885863.842 [Default:CheckIn:Read_GPS] Stopped
2019-05-15T02:04:23.842Z,1557885863.842 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-05-15T02:04:30.349Z,1557885870.349 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20190515T013928/Courier0013.lzma
2019-05-15T02:04:31.154Z,1557885871.154 [DataOverHttps](INFO): Moved sent file to Logs/20190515T013928/Courier0013.lzma.bak
2019-05-15T02:04:31.154Z,1557885871.154 [DataOverHttps](INFO): SBD MOMSN=11060401
2019-05-15T02:04:44.745Z,1557885884.745 [DataOverHttps](INFO): Sending 193 bytes from file Logs/20190515T013928/Express0014.lzma
2019-05-15T02:04:45.550Z,1557885885.550 [DataOverHttps](INFO): Moved sent file to Logs/20190515T013928/Express0014.lzma.bak
2019-05-15T02:04:45.550Z,1557885885.550 [DataOverHttps](INFO): SBD MOMSN=11060404
2019-05-15T02:04:48.548Z,1557885888.548 [Default:CheckIn:Read_Iridium] Stopped
2019-05-15T02:04:48.548Z,1557885888.548 [Default:CheckIn:C.Wait] Running Loop=1
2019-05-15T02:04:48.548Z,1557885888.548 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-05-15T02:04:54.542Z,1557885894.542 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2019-05-15T02:04:54.617Z,1557885894.617 [NAL9602](FAULT): received: 
+CSQ:0

OK110, 2, 0, 0, 0

OK
2019-05-15T02:04:54.617Z,1557885894.617 [NAL9602] Data Fault, FailCount= 1
2019-05-15T02:04:54.617Z,1557885894.617 [NAL9602](ERROR): Data Fault
2019-05-15T02:04:54.680Z,1557885894.680 [CBIT](ERROR): Data Fault in component: NAL9602
2019-05-15T02:04:54.944Z,1557885894.944 [NAL9602](INFO): Powering down
2019-05-15T02:04:55.790Z,1557885895.790 [CBIT](INFO): Clearing failed state for component NAL9602
2019-05-15T02:04:55.790Z,1557885895.790 [NAL9602] No Fault, FailCount= 1
2019-05-15T02:05:25.243Z,1557885925.243 [NAL9602](INFO): Powering up NAL9602
2019-05-15T02:05:36.158Z,1557885936.158 [NAL9602](INFO): NAL9602 initialized
2019-05-15T02:05:54.779Z,1557885954.779 [CommandLine](IMPORTANT): got command run ./Missions/test.xml
2019-05-15T02:05:54.779Z,1557885954.779 [MissionManager](INFO): Loading Mission: ./Missions/test.xml
2019-05-15T02:05:54.941Z,1557885954.941 [MissionManager](INFO): DefineArg circle_acoustic_contact.MissionTimeout = 2.000000 h
2019-05-15T02:05:54.944Z,1557885954.944 [MissionManager](INFO): DefineArg circle_acoustic_contact.NeedCommsTime = 60.000000 min
2019-05-15T02:05:54.948Z,1557885954.948 [MissionManager](INFO): DefineArg circle_acoustic_contact.AcousticContactTimeout = 15.000000 min
2019-05-15T02:05:54.951Z,1557885954.951 [MissionManager](INFO): DefineArg circle_acoustic_contact.ContactLabel = 0.000000 count
2019-05-15T02:05:54.954Z,1557885954.954 [MissionManager](INFO): DefineArg circle_acoustic_contact.ContactDepth = 0.000000 m
2019-05-15T02:05:54.957Z,1557885954.957 [MissionManager](INFO): DefineArg circle_acoustic_contact.CenterLatitude = 36.815440 arcdeg
2019-05-15T02:05:54.960Z,1557885954.960 [MissionManager](INFO): DefineArg circle_acoustic_contact.CenterLongitude = -121.825060 arcdeg
2019-05-15T02:05:54.963Z,1557885954.963 [MissionManager](INFO): DefineArg circle_acoustic_contact.OuterCircleRadius = 300.000000 m
2019-05-15T02:05:54.966Z,1557885954.966 [MissionManager](INFO): DefineArg circle_acoustic_contact.InnerCircleRadius = 50.000000 m
2019-05-15T02:05:54.970Z,1557885954.970 [MissionManager](INFO): DefineArg circle_acoustic_contact.TrackingUpdatePeriod = 20.000000 s
2019-05-15T02:05:54.973Z,1557885954.973 [MissionManager](INFO): DefineArg circle_acoustic_contact.NumberOfPings = 1.000000 count
2019-05-15T02:05:54.976Z,1557885954.976 [MissionManager](INFO): DefineArg circle_acoustic_contact.InnerCircleTime = 0.000000 min
2019-05-15T02:05:54.980Z,1557885954.980 [MissionManager](INFO): DefineArg circle_acoustic_contact.CircleMaxError = 100.000000 m
2019-05-15T02:05:54.982Z,1557885954.982 [MissionManager](INFO): DefineArg circle_acoustic_contact.CircleTurnToPort = 0 bool
2019-05-15T02:05:54.986Z,1557885954.986 [MissionManager](INFO): DefineArg circle_acoustic_contact.YoYoMinDepth = 3.000000 m
2019-05-15T02:05:54.989Z,1557885954.989 [MissionManager](INFO): DefineArg circle_acoustic_contact.YoYoMaxDepth = 33.000000 m
2019-05-15T02:05:54.992Z,1557885954.992 [MissionManager](INFO): DefineArg circle_acoustic_contact.YoYoMinAltitude = 10.000000 m
2019-05-15T02:05:54.995Z,1557885954.995 [MissionManager](INFO): DefineArg circle_acoustic_contact.YoYoPitch = 20.000000 arcdeg
2019-05-15T02:05:54.998Z,1557885954.998 [MissionManager](INFO): DefineArg circle_acoustic_contact.Speed = 0.000000 m/s
2019-05-15T02:05:55.001Z,1557885955.001 [MissionManager](INFO): DefineArg circle_acoustic_contact.KwpHeading = 0.010000 rad/m
2019-05-15T02:05:55.004Z,1557885955.004 [MissionManager](INFO): DefineArg circle_acoustic_contact.MinAltitude = 7.000000 m
2019-05-15T02:05:55.007Z,1557885955.007 [MissionManager](INFO): DefineArg circle_acoustic_contact.MaxDepth = 105.000000 m
2019-05-15T02:05:55.011Z,1557885955.011 [MissionManager](INFO): DefineArg circle_acoustic_contact.MinOffshore = 1.500000 km
2019-05-15T02:05:55.288Z,1557885955.288 [MissionManager](INFO): Inserting Stack: Missions/Insert/NeedComms.xml
2019-05-15T02:05:55.400Z,1557885955.400 [MissionManager](INFO): DefineArg circle_acoustic_contact:NeedComms.DiveInterval = 3.000000 h
2019-05-15T02:05:55.404Z,1557885955.404 [MissionManager](INFO): DefineArg circle_acoustic_contact:NeedComms.WaitForPitchUp = 10.000000 min
2019-05-15T02:05:55.420Z,1557885955.420 [MissionManager](INFO): DefineArg circle_acoustic_contact:NeedComms.SurfacePitch = 20.000000 arcdeg
2019-05-15T02:05:55.438Z,1557885955.438 [MissionManager](INFO): DefineArg circle_acoustic_contact:NeedComms.SurfaceDepthRate = nan m/s
2019-05-15T02:05:55.441Z,1557885955.441 [MissionManager](INFO): DefineArg circle_acoustic_contact:NeedComms.SurfaceSpeed = 1.000000 m/s
2019-05-15T02:05:55.444Z,1557885955.444 [MissionManager](INFO): DefineArg circle_acoustic_contact:NeedComms.GPSTimeout = 7.000000 min
2019-05-15T02:05:55.448Z,1557885955.448 [MissionManager](INFO): DefineArg circle_acoustic_contact:NeedComms.CommsTimeout = 30.000000 min
2019-05-15T02:05:55.490Z,1557885955.490 [circle_acoustic_contact:NeedComms:B.GoToSurface](DEBUG): Construct GoToSurface.
2019-05-15T02:05:55.591Z,1557885955.591 [MissionManager](INFO): Inserting Stack: Missions/Insert/StandardEnvelopes.xml
2019-05-15T02:05:55.643Z,1557885955.643 [MissionManager](INFO): DefineArg circle_acoustic_contact:StandardEnvelopes.MinAltitude = 5.000000 m
2019-05-15T02:05:55.655Z,1557885955.655 [MissionManager](INFO): DefineArg circle_acoustic_contact:StandardEnvelopes.MaxDepth = 200.000000 m
2019-05-15T02:05:55.661Z,1557885955.661 [MissionManager](INFO): DefineArg circle_acoustic_contact:StandardEnvelopes.MinOffshore = 2000.000000 m
2019-05-15T02:05:55.662Z,1557885955.662 [circle_acoustic_contact:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope.
2019-05-15T02:05:55.678Z,1557885955.678 [circle_acoustic_contact:StandardEnvelopes:B.DepthEnvelope](DEBUG): Construct DepthEnvelope.
2019-05-15T02:05:55.695Z,1557885955.695 [circle_acoustic_contact:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Construct OffshoreEnvelope.
2019-05-15T02:05:55.719Z,1557885955.719 [circle_acoustic_contact:I.Pitch](DEBUG): Construct.
2019-05-15T02:05:55.734Z,1557885955.734 [circle_acoustic_contact:J.Buoyancy](DEBUG): Construct Buoyancy.
2019-05-15T02:05:55.736Z,1557885955.736 [MissionManager](INFO): Inserting Stack: Missions/Insert/Science.xml
2019-05-15T02:05:56.140Z,1557885956.140 [MissionManager](INFO): DefineArg circle_acoustic_contact:Science.SampleISUS = 0 bool
2019-05-15T02:05:56.156Z,1557885956.156 [MissionManager](INFO): DefineArg circle_acoustic_contact:Science.SampleISUSmaxPitch = 60.000000 arcdeg
2019-05-15T02:05:56.173Z,1557885956.173 [MissionManager](INFO): DefineArg circle_acoustic_contact:Science.SampleISUSminPitch = -60.000000 arcdeg
2019-05-15T02:05:56.175Z,1557885956.175 [MissionManager](INFO): DefineArg circle_acoustic_contact:Science.PeakDetectChlActive = 0 bool
2019-05-15T02:05:56.180Z,1557885956.180 [MissionManager](INFO): DefineArg circle_acoustic_contact:Science.TimeWindowPeakReport = nan min
2019-05-15T02:05:56.191Z,1557885956.191 [MissionManager](INFO): DefineArg circle_acoustic_contact:Science.HighestChlPeakReportActive = 0 bool
2019-05-15T02:05:56.197Z,1557885956.197 [MissionManager](INFO): DefineArg circle_acoustic_contact:Science.PatchTracking = 0 bool
2019-05-15T02:05:56.200Z,1557885956.200 [MissionManager](INFO): DefineArg circle_acoustic_contact:Science.FilterWidthHorizontal = 3.000000 count
2019-05-15T02:05:56.224Z,1557885956.224 [MissionManager](INFO): DefineArg circle_acoustic_contact:Science.NumProfilesSlidingwindow = 100.000000 count
2019-05-15T02:05:56.235Z,1557885956.235 [MissionManager](INFO): DefineArg circle_acoustic_contact:Science.OffPeakFractionHorizontal = 80.000000 %
2019-05-15T02:05:56.254Z,1557885956.254 [MissionManager](INFO): DefineArg circle_acoustic_contact:Science.PeakDetectNO3Active = 0 bool
2019-05-15T02:05:56.270Z,1557885956.270 [MissionManager](INFO): DefineArg circle_acoustic_contact:Science.PeakDetectOilActive = 0 bool
2019-05-15T02:05:56.279Z,1557885956.279 [MissionManager](INFO): DefineArg circle_acoustic_contact:Science.PeakDetectFDOMActive = 0 bool
2019-05-15T02:05:56.286Z,1557885956.286 [MissionManager](INFO): DefineArg circle_acoustic_contact:Science.UpwardDerivativeOfTemperatureActive = 0 bool
2019-05-15T02:05:56.306Z,1557885956.306 [MissionManager](INFO): DefineArg circle_acoustic_contact:Science.EnabledAanderaaO2 = 1.000000 bool
2019-05-15T02:05:56.309Z,1557885956.309 [MissionManager](INFO): DefineArg circle_acoustic_contact:Science.EnabledNeilBrown = 1.000000 bool
2019-05-15T02:05:56.318Z,1557885956.318 [MissionManager](INFO): DefineArg circle_acoustic_contact:Science.EnabledSeabird = 1.000000 bool
2019-05-15T02:05:56.323Z,1557885956.323 [MissionManager](INFO): DefineArg circle_acoustic_contact:Science.EnabledTurbulence_NPS = 0.000000 bool
2019-05-15T02:05:56.335Z,1557885956.335 [MissionManager](INFO): DefineArg circle_acoustic_contact:Science.EnabledWetLabsBB2FL = 1.000000 bool
2019-05-15T02:05:56.374Z,1557885956.374 [MissionManager](INFO): DefineArg circle_acoustic_contact:Science.EnabledWetLabsSeaOWL_UV_A = 0.000000 bool
2019-05-15T02:05:56.378Z,1557885956.378 [MissionManager](INFO): DefineArg circle_acoustic_contact:Science.EnabledWetLabsUBAT = 0.000000 bool
2019-05-15T02:05:56.393Z,1557885956.393 [MissionManager](INFO): DefineArg circle_acoustic_contact:Science.EnabledISUS = 0.000000 bool
2019-05-15T02:05:56.396Z,1557885956.396 [MissionManager](INFO): DefineArg circle_acoustic_contact:Science.LowPassWindowLength = 20.000000 count
2019-05-15T02:05:56.399Z,1557885956.399 [MissionManager](INFO): DefineArg circle_acoustic_contact:Science.MedianFilterLen = 5.000000 count
2019-05-15T02:05:56.427Z,1557885956.427 [MissionManager](INFO): DefineArg circle_acoustic_contact:Science.PeakChlShallowBound = nan m
2019-05-15T02:05:56.430Z,1557885956.430 [MissionManager](INFO): DefineArg circle_acoustic_contact:Science.PeakChlDeepBound = nan m
2019-05-15T02:05:56.432Z,1557885956.432 [MissionManager](INFO): DefineArg circle_acoustic_contact:Science.PeakShallowBound = nan m
2019-05-15T02:05:56.444Z,1557885956.444 [MissionManager](INFO): DefineArg circle_acoustic_contact:Science.PeakDeepBound = nan m
2019-05-15T02:05:56.447Z,1557885956.447 [MissionManager](INFO): DefineOutput circle_acoustic_contact:Science.PeakChl = 0.000000 ug/l
2019-05-15T02:05:56.451Z,1557885956.451 [MissionManager](INFO): DefineOutput circle_acoustic_contact:Science.PeakChlDepth = 0.000000 m
2019-05-15T02:05:56.482Z,1557885956.482 [MissionManager](INFO): DefineOutput circle_acoustic_contact:Science.PeakChlTemperature = 0.000000 degC
2019-05-15T02:05:56.485Z,1557885956.485 [MissionManager](INFO): DefineOutput circle_acoustic_contact:Science.PeakChlLatitude = nan arcdeg
2019-05-15T02:05:56.488Z,1557885956.488 [MissionManager](INFO): DefineOutput circle_acoustic_contact:Science.PeakChlLongitude = nan arcdeg
2019-05-15T02:05:56.491Z,1557885956.491 [MissionManager](INFO): DefineOutput circle_acoustic_contact:Science.PeakNO3 = 0.000000 umol/l
2019-05-15T02:05:56.495Z,1557885956.495 [MissionManager](INFO): DefineOutput circle_acoustic_contact:Science.PeakNO3Depth = 0.000000 m
2019-05-15T02:05:56.498Z,1557885956.498 [MissionManager](INFO): DefineOutput circle_acoustic_contact:Science.PeakNO3Latitude = nan arcdeg
2019-05-15T02:05:56.501Z,1557885956.501 [MissionManager](INFO): DefineOutput circle_acoustic_contact:Science.PeakNO3Longitude = nan arcdeg
2019-05-15T02:05:56.504Z,1557885956.504 [MissionManager](INFO): DefineOutput circle_acoustic_contact:Science.PatchChl = 0.000000 m
2019-05-15T02:05:56.528Z,1557885956.528 [MissionManager](INFO): DefineOutput circle_acoustic_contact:Science.PatchChlDepth = 0.000000 m
2019-05-15T02:05:56.531Z,1557885956.531 [MissionManager](INFO): DefineOutput circle_acoustic_contact:Science.PatchChlLatitude = nan arcdeg
2019-05-15T02:05:56.534Z,1557885956.534 [MissionManager](INFO): DefineOutput circle_acoustic_contact:Science.PatchChlLongitude = nan arcdeg
2019-05-15T02:05:56.561Z,1557885956.561 [MissionManager](INFO): DefineOutput circle_acoustic_contact:Science.PatchChlDistance = nan m
2019-05-15T02:05:56.564Z,1557885956.564 [MissionManager](INFO): DefineOutput circle_acoustic_contact:Science.PeakOil = 0.000000 kg/m3
2019-05-15T02:05:56.567Z,1557885956.567 [MissionManager](INFO): DefineOutput circle_acoustic_contact:Science.PeakOilDepth = 0.000000 m
2019-05-15T02:05:56.571Z,1557885956.571 [MissionManager](INFO): DefineOutput circle_acoustic_contact:Science.PeakOilLatitude = nan arcdeg
2019-05-15T02:05:56.575Z,1557885956.575 [MissionManager](INFO): DefineOutput circle_acoustic_contact:Science.PeakOilLongitude = nan arcdeg
2019-05-15T02:05:56.578Z,1557885956.578 [MissionManager](INFO): DefineOutput circle_acoustic_contact:Science.PeakFDOM = 0.000000 ppb
2019-05-15T02:05:56.581Z,1557885956.581 [MissionManager](INFO): DefineOutput circle_acoustic_contact:Science.PeakFDOMDepth = 0.000000 m
2019-05-15T02:05:56.584Z,1557885956.584 [MissionManager](INFO): DefineOutput circle_acoustic_contact:Science.PeakFDOMLatitude = nan arcdeg
2019-05-15T02:05:56.612Z,1557885956.612 [MissionManager](INFO): DefineOutput circle_acoustic_contact:Science.PeakFDOMLongitude = nan arcdeg
2019-05-15T02:05:56.615Z,1557885956.615 [MissionManager](INFO): DefineOutput circle_acoustic_contact:Science.PatchFDOMDistance = nan m
2019-05-15T02:05:56.646Z,1557885956.646 [circle_acoustic_contact:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2019-05-15T02:05:56.678Z,1557885956.678 [circle_acoustic_contact:Science:HighestChlPeakReport:A.PeakDetectHorizontal](DEBUG): Construct PeakDetectHorizontal.
2019-05-15T02:05:56.707Z,1557885956.707 [circle_acoustic_contact:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2019-05-15T02:05:56.724Z,1557885956.724 [circle_acoustic_contact:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2019-05-15T02:05:56.794Z,1557885956.794 [circle_acoustic_contact:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2019-05-15T02:05:56.827Z,1557885956.827 [MissionManager](INFO): RedefineArg circle_acoustic_contact:Science.PeakDetectChlActive = value:1 bool
2019-05-15T02:05:56.833Z,1557885956.833 [MissionManager](INFO): RedefineArg circle_acoustic_contact:Science.SampleISUS = value:1 bool
2019-05-15T02:05:56.836Z,1557885956.836 [MissionManager](INFO): RedefineArg circle_acoustic_contact:Science.SampleISUSmaxPitch = value:30.000000 arcdeg
2019-05-15T02:05:56.842Z,1557885956.842 [MissionManager](INFO): RedefineArg circle_acoustic_contact:Science.SampleISUSminPitch = value:10.000000 arcdeg
2019-05-15T02:05:56.843Z,1557885956.843 [circle_acoustic_contact:L.SetSpeed](DEBUG): Construct.
2019-05-15T02:05:56.848Z,1557885956.848 [circle_acoustic_contact:YoYos:A.DepthEnvelope](DEBUG): Construct DepthEnvelope.
2019-05-15T02:05:56.874Z,1557885956.874 [circle_acoustic_contact:YoYos:B.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope.
2019-05-15T02:05:56.894Z,1557885956.894 [circle_acoustic_contact:YoYos:C.YoYo](DEBUG): Construct YoYo.
2019-05-15T02:05:56.925Z,1557885956.925 [circle_acoustic_contact:CircleWrapper:CircleContact:B.Circle](DEBUG): Construct.
2019-05-15T02:05:56.944Z,1557885956.944 [circle_acoustic_contact:CircleWrapper:CircleContactClose:B.Circle](DEBUG): Construct.
2019-05-15T02:05:57.015Z,1557885957.015 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Derivation="Tethys/Derivation"
       xmlns:Estimation="Tethys/Estimation"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Sensor="Tethys/Sensor"
       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/Derivation http://okeanids.mbari.org/tethys/Xml/Derivation.xsd
                           Tethys/Estimation http://okeanids.mbari.org/tethys/Xml/Estimation.xsd
                           Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Sensor http://okeanids.mbari.org/tethys/Xml/Sensor.xsd
                           Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
       Id="circle_acoustic_contact">

    <Description>
        This mission runs a circle around a specified acoustic contact. The
        tracking behavior periodically queries the DAT for range and direction
        to the contact, and the DAT acoustically interrogates the contact. The
        tracking component then calculates the position of the contact to update
        the center of the circle. When the vehicle surfaces and updates its own
        position with GPS, it queries the contact again, then sends the contact
        position to shore.
    </Description>

<!-- Mission-wide settings -->

    <DefineArg Name="MissionTimeout"><Description>
        Maximum duration of mission
    </Description><Units:hour/><Value>2</Value></DefineArg>

    <DefineArg Name="NeedCommsTime"><Description>
        Elapsed time after previous surface communications when vehicle will
        begin to ascend for additional surface communications
    </Description><Units:minute/><Value>60</Value></DefineArg>

    <DefineArg Name="AcousticContactTimeout"><Description>
        If the vehicle does not receive an acoustic signal for more than this
        length of time, it will surface for communications with shore.
    </Description><Units:minute/><Value>15</Value></DefineArg>

<!-- You probably need to change these. -->

    <DefineArg Name="ContactLabel"><Description>
        The acoustic address of the asset to be tracked
    </Description><Units:count/><Value>0</Value></DefineArg>
    
    <DefineArg Name="ContactDepth"><Description>
        The acoustic address of the asset to be tracked
    </Description><Units:meter/><Value>0</Value></DefineArg>

    <DefineArg Name="CenterLatitude"><Description>
        The latitude of the center of the circle. Fill this in to specify a
        start position, it will be overwritten once the vehicle receives an
        acoustic signal from the contact.
    </Description><Units:degree/><Value>36.81544</Value></DefineArg>

    <DefineArg Name="CenterLongitude"><Description>
        The longitude of the center of the circle. Fill this in to specify a
        start position, it will be overwritten once the vehicle receives an
        acoustic signal from the contact.
    </Description><Units:degree/><Value>-121.82506</Value></DefineArg>

    <DefineArg Name="OuterCircleRadius"><Description>
        Radius of circle around acoustic contact during wait time
    </Description><Units:meter/><Value>300</Value></DefineArg>

    <DefineArg Name="InnerCircleRadius"><Description>
        Radius of circle around acoustic contact during wait time
    </Description><Units:meter/><Value>50</Value></DefineArg>

<!-- You probably do not need to change these. -->

    <DefineArg Name="TrackingUpdatePeriod"><Description>
        How long to wait between acoustic queries
    </Description><Units:second/><Value>20</Value></DefineArg>

    <DefineArg Name="NumberOfPings"><Description>
        Number of return pings to request with each acoustic query (more than 1
        will activate oneway mode)
    </Description><Units:count/><Value>1</Value></DefineArg>

    <DefineArg Name="InnerCircleTime"><Description>
        Time before each normal communication cycle to move to the inner circle.
        Default value of 0 means vehicle will stay at OuterCircleRadius the
        whole time.
    </Description><Units:minute/><Value>0</Value></DefineArg>

    <DefineArg Name="CircleMaxError"><Description>
        If this distance away from the circle, drive straight towards (or away
        from the center). Otherwise, try to reduce distance from the ideal
        circle.
    </Description><Units:meter/><Value>100</Value></DefineArg>

    <DefineArg Name="CircleTurnToPort"><Description>
        If true, vehicle turns to the left around the center point. If false,
        vehicle turns to the right.
    </Description><False/></DefineArg>

    <DefineArg Name="YoYoMinDepth"><Description>
        Minimum depth during yo-yo's.
    </Description><Units:meter/><Value>3</Value></DefineArg>

    <DefineArg Name="YoYoMaxDepth"><Description>
        Maximum depth during yo-yo's.
    </Description><Units:meter/><Value>33</Value></DefineArg>

    <DefineArg Name="YoYoMinAltitude"><Description>
        Min altitude while in yo-yo mode.
    </Description><Units:meter/><Value>10</Value></DefineArg>

    <DefineArg Name="YoYoPitch"><Description>
        Pitch (plus and minus) for yo-yo behavior.
    </Description><Units:degree/><Value>20</Value></DefineArg>

    <DefineArg Name="Speed"><Description>
        Vehicle speed.
    </Description><Units:meter_per_second/><Value>0</Value></DefineArg>

<!-- You are even less likely to need to change these. -->

    <DefineArg Name="KwpHeading"><Description>
        Used to relax waypoint cross-track error constant that is adjusted for
        docking. (You can override this setting by passing an argument.)
    </Description><Units:radian_per_meter/><Value>0.010</Value></DefineArg>

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

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

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

<!-- Missions should always start with a timeout. -->

    <Timeout Duration="MissionTimeout"/>

<!-- Add tracking directive high in the stack (above NeedComms to enable tracking from surface). -->

    <Estimation:Tracking>
        <Parallel/>
        <Setting><Estimation:Tracking.contactDepthSetting/><Arg Name="ContactDepth"/></Setting>
        <Setting><Estimation:Tracking.contactLabelSetting/><Arg Name="ContactLabel"/></Setting>
        <Setting><Estimation:Tracking.numberOfSamplesSetting/><Arg Name="NumberOfPings"/></Setting>
        <Setting><Estimation:Tracking.updatePeriodSetting/><Arg Name="TrackingUpdatePeriod"/></Setting>
    </Estimation:Tracking>

    <Aggregate Id="UpdateCenter">

        <When>
            <Elapsed><Estimation:Tracking.range_to_contact/></Elapsed>
            <Lt><Arg Name="AcousticContactTimeout"/></Lt>
        </When>

        <Assign><Sequence/><Arg Name="CenterLatitude"/><Estimation:Tracking.contact_latitude/></Assign>

        <Assign><Sequence/><Arg Name="CenterLongitude"/><Estimation:Tracking.contact_longitude/></Assign>

    </Aggregate>

<!-- Most missions have the NeedComms aggregate at high priority. -->

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

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

<!-- Missions should almost always start with standard safety envelopes; most missions should not expose the parameters of these envelopes. -->

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

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

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

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

<!-- Many missions will keep mass position and buoyancy volume fixed at defaults. -->

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

    <Guidance:Buoyancy>
        <Parallel/>
        <Setting><Guidance:Buoyancy.position/><Control:VerticalControl.buoyancyNeutral/></Setting>
    </Guidance:Buoyancy>

    <Insert Filename="Insert/Science.xml" Id="Science">
        <Description>
            Get science data, including PeakDetectChl
        </Description>
        <RedefineArg Name="PeakDetectChlActive"><True/></RedefineArg>
        <RedefineArg Name="SampleISUS"><True/></RedefineArg>
        <RedefineArg Name="SampleISUSmaxPitch"><Units:degree/><Value>30.0</Value></RedefineArg>
        <RedefineArg Name="SampleISUSminPitch"><Units:degree/><Value>10.0</Value></RedefineArg>
    </Insert>

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

    <Aggregate Id="YoYos">

        <Parallel/>

        <Guidance:DepthEnvelope>
            <Parallel/>
            <Setting><Guidance:DepthEnvelope.minDepth/><Arg Name="YoYoMinDepth"/></Setting>
            <Setting><Guidance:DepthEnvelope.maxDepth/><Arg Name="YoYoMaxDepth"/></Setting>
            <Setting><Guidance:DepthEnvelope.pitch/><Arg Name="YoYoPitch"/></Setting>
        </Guidance:DepthEnvelope>

        <Guidance:AltitudeEnvelope>
            <Parallel/>
            <Setting><Guidance:AltitudeEnvelope.minAltitude/><Arg Name="YoYoMinAltitude"/></Setting>
            <Setting><Guidance:AltitudeEnvelope.pitch/><Arg Name="YoYoPitch"/></Setting>
        </Guidance:AltitudeEnvelope>

        <Guidance:YoYo>
            <Parallel/>
            <Setting><Guidance:YoYo.pitch/><Arg Name="YoYoPitch"/></Setting>
        </Guidance:YoYo>

    </Aggregate>

    <Aggregate Id="CircleWrapper">

        <Sequence/>

        <Aggregate Id="CircleContact">

            <Description>
                Circle the contact while updating its position using the
                tracking behavior.
            </Description>

            <When>
                <Elapsed><Universal:time_fix/></Elapsed>
                <Lt><Arg Name="NeedCommsTime"/><Sub><Arg Name="InnerCircleTime"/></Sub></Lt>
            </When>

            <Assign><Parallel/><Control:HorizontalControl.kwpHeading/><Arg Name="KwpHeading"/></Assign>

            <Guidance:Circle>
                <Sequence/>
                <Setting><Guidance:Circle.latitude/><Arg Name="CenterLatitude"/></Setting>
                <Setting><Guidance:Circle.longitude/><Arg Name="CenterLongitude"/></Setting>
                <Setting><Guidance:Circle.radius/><Arg Name="OuterCircleRadius"/></Setting>
                <Setting><Guidance:Circle.maxError/><Arg Name="CircleMaxError"/></Setting>
                <Setting><Guidance:Circle.turnToPort/><Arg Name="CircleTurnToPort"/></Setting>
            </Guidance:Circle>

        </Aggregate>

        <Aggregate Id="CircleContactClose">

            <Description>
                Circle the contact closely while updating its position using the
                tracking behavior.
            </Description>

            <When>
                <Elapsed><Universal:time_fix/></Elapsed>
                <Ge><Arg Name="NeedCommsTime"/><Sub><Arg Name="InnerCircleTime"/></Sub></Ge>
            </When>

            <Assign><Parallel/><Control:HorizontalControl.kwpHeading/><Arg Name="KwpHeading"/></Assign>

            <Guidance:Circle>
                <Sequence/>
                <Setting><Guidance:Circle.latitude/><Arg Name="CenterLatitude"/></Setting>
                <Setting><Guidance:Circle.longitude/><Arg Name="CenterLongitude"/></Setting>
                <Setting><Guidance:Circle.radius/><Arg Name="InnerCircleRadius"/></Setting>
                <Setting><Guidance:Circle.maxError/><Arg Name="CircleMaxError"/></Setting>
                <Setting><Guidance:Circle.turnToPort/><Arg Name="CircleTurnToPort"/></Setting>
            </Guidance:Circle>

        </Aggregate>

    </Aggregate>

</Mission>


2019-05-15T02:05:57.023Z,1557885957.023 [CommandLine](IMPORTANT): Running ./Missions/test.xml
2019-05-15T02:05:57.201Z,1557885957.201 [Default] Stopped
2019-05-15T02:05:57.201Z,1557885957.201 [Default](DEBUG): Aggregate::uninitialize Default
2019-05-15T02:05:57.201Z,1557885957.201 [Default:B.GoToSurface] Stopped
2019-05-15T02:05:57.201Z,1557885957.201 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-05-15T02:05:57.201Z,1557885957.201 [Default:CheckIn] Stopped
2019-05-15T02:05:57.201Z,1557885957.201 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-05-15T02:05:57.201Z,1557885957.201 [Default:CheckIn:C.Wait] Stopped
2019-05-15T02:05:57.202Z,1557885957.202 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-15T02:05:57.202Z,1557885957.202 [MissionManager](IMPORTANT): Started mission circle_acoustic_contact
2019-05-15T02:05:57.202Z,1557885957.202 [circle_acoustic_contact] Running Loop=1
2019-05-15T02:05:57.202Z,1557885957.202 [circle_acoustic_contact](DEBUG): Aggregate::initialize circle_acoustic_contact
2019-05-15T02:05:57.202Z,1557885957.202 [circle_acoustic_contact:A.] Running Loop=1
2019-05-15T02:05:57.202Z,1557885957.202 [circle_acoustic_contact:A.](INFO): Initializing Tracking.
2019-05-15T02:05:57.203Z,1557885957.203 [circle_acoustic_contact:StandardEnvelopes] Running Loop=1
2019-05-15T02:05:57.203Z,1557885957.203 [circle_acoustic_contact:StandardEnvelopes](DEBUG): Aggregate::initialize circle_acoustic_contact:StandardEnvelopes
2019-05-15T02:05:57.203Z,1557885957.203 [circle_acoustic_contact:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1
2019-05-15T02:05:57.203Z,1557885957.203 [circle_acoustic_contact:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent.
2019-05-15T02:05:57.203Z,1557885957.203 [circle_acoustic_contact:StandardEnvelopes:B.DepthEnvelope] Running Loop=1
2019-05-15T02:05:57.203Z,1557885957.203 [circle_acoustic_contact:StandardEnvelopes:B.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent.
2019-05-15T02:05:57.203Z,1557885957.203 [circle_acoustic_contact:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1
2019-05-15T02:05:57.203Z,1557885957.203 [circle_acoustic_contact:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Initialize OffshoreEnvelopeComponent.
2019-05-15T02:05:57.204Z,1557885957.204 [circle_acoustic_contact:I.Pitch] Running Loop=1
2019-05-15T02:05:57.204Z,1557885957.204 [circle_acoustic_contact:I.Pitch](DEBUG): Initialize.
2019-05-15T02:05:57.204Z,1557885957.204 [circle_acoustic_contact:J.Buoyancy] Running Loop=1
2019-05-15T02:05:57.204Z,1557885957.204 [circle_acoustic_contact:J.Buoyancy](DEBUG): Initialize Buoyancy Component.
2019-05-15T02:05:57.204Z,1557885957.204 [circle_acoustic_contact:Science] Running Loop=1
2019-05-15T02:05:57.204Z,1557885957.204 [circle_acoustic_contact:Science](DEBUG): Aggregate::initialize circle_acoustic_contact:Science
2019-05-15T02:05:57.204Z,1557885957.204 [circle_acoustic_contact:Science:A] Running Loop=1
2019-05-15T02:05:57.204Z,1557885957.204 [circle_acoustic_contact:Science:B] Running Loop=1
2019-05-15T02:05:57.204Z,1557885957.204 [circle_acoustic_contact:Science:C] Running Loop=1
2019-05-15T02:05:57.204Z,1557885957.204 [circle_acoustic_contact:Science:D] Running Loop=1
2019-05-15T02:05:57.204Z,1557885957.204 [circle_acoustic_contact:Science:E] Running Loop=1
2019-05-15T02:05:57.205Z,1557885957.205 [circle_acoustic_contact:Science:F] Running Loop=1
2019-05-15T02:05:57.205Z,1557885957.205 [circle_acoustic_contact:Science:G] Running Loop=1
2019-05-15T02:05:57.205Z,1557885957.205 [circle_acoustic_contact:Science:H] Running Loop=1
2019-05-15T02:05:57.205Z,1557885957.205 [circle_acoustic_contact:Science:Read_Oil] Running Loop=1
2019-05-15T02:05:57.205Z,1557885957.205 [circle_acoustic_contact:Science:PeakDetectChl] Running Loop=1
2019-05-15T02:05:57.205Z,1557885957.205 [circle_acoustic_contact:Science:PeakDetectChl](DEBUG): Aggregate::initialize circle_acoustic_contact:Science:PeakDetectChl
2019-05-15T02:05:57.207Z,1557885957.207 [circle_acoustic_contact:Science:PeakDetectChl:A.PeakDetectVsDepth] Running Loop=1
2019-05-15T02:05:57.207Z,1557885957.207 [circle_acoustic_contact:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Initialize.
2019-05-15T02:05:57.221Z,1557885957.221 [circle_acoustic_contact:Science:HighestChlPeakReport] Running Loop=1
2019-05-15T02:05:57.221Z,1557885957.221 [circle_acoustic_contact:Science:HighestChlPeakReport](DEBUG): Aggregate::initialize circle_acoustic_contact:Science:HighestChlPeakReport
2019-05-15T02:05:57.222Z,1557885957.222 [circle_acoustic_contact:Science:HighestChlPeakReport:A.PeakDetectHorizontal] Running Loop=1
2019-05-15T02:05:57.222Z,1557885957.222 [circle_acoustic_contact:Science:HighestChlPeakReport:A.PeakDetectHorizontal](INFO): Initialize.
2019-05-15T02:05:57.222Z,1557885957.222 [circle_acoustic_contact:Science:PeakDetectNO3] Running Loop=1
2019-05-15T02:05:57.222Z,1557885957.222 [circle_acoustic_contact:Science:PeakDetectNO3](DEBUG): Aggregate::initialize circle_acoustic_contact:Science:PeakDetectNO3
2019-05-15T02:05:57.222Z,1557885957.222 [circle_acoustic_contact:Science:PeakDetectNO3:A.PeakDetectVsDepth] Running Loop=1
2019-05-15T02:05:57.222Z,1557885957.222 [circle_acoustic_contact:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Initialize.
2019-05-15T02:05:57.224Z,1557885957.224 [circle_acoustic_contact:Science:PeakDetectOil] Running Loop=1
2019-05-15T02:05:57.224Z,1557885957.224 [circle_acoustic_contact:Science:PeakDetectOil](DEBUG): Aggregate::initialize circle_acoustic_contact:Science:PeakDetectOil
2019-05-15T02:05:57.238Z,1557885957.238 [circle_acoustic_contact:Science:PeakDetectOil:A.PeakDetectVsDepth] Running Loop=1
2019-05-15T02:05:57.238Z,1557885957.238 [circle_acoustic_contact:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Initialize.
2019-05-15T02:05:57.240Z,1557885957.240 [circle_acoustic_contact:Science:PeakDetectFDOM] Running Loop=1
2019-05-15T02:05:57.240Z,1557885957.240 [circle_acoustic_contact:Science:PeakDetectFDOM](DEBUG): Aggregate::initialize circle_acoustic_contact:Science:PeakDetectFDOM
2019-05-15T02:05:57.240Z,1557885957.240 [circle_acoustic_contact:Science:PeakDetectFDOM:A.PeakDetectVsDepth] Running Loop=1
2019-05-15T02:05:57.241Z,1557885957.241 [circle_acoustic_contact:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Initialize.
2019-05-15T02:05:57.242Z,1557885957.242 [circle_acoustic_contact:L.SetSpeed] Running Loop=1
2019-05-15T02:05:57.242Z,1557885957.242 [circle_acoustic_contact:L.SetSpeed](DEBUG): Initialize.
2019-05-15T02:05:57.243Z,1557885957.243 [circle_acoustic_contact:YoYos] Running Loop=1
2019-05-15T02:05:57.243Z,1557885957.243 [circle_acoustic_contact:YoYos](DEBUG): Aggregate::initialize circle_acoustic_contact:YoYos
2019-05-15T02:05:57.243Z,1557885957.243 [circle_acoustic_contact:YoYos:A.DepthEnvelope] Running Loop=1
2019-05-15T02:05:57.243Z,1557885957.243 [circle_acoustic_contact:YoYos:A.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent.
2019-05-15T02:05:57.243Z,1557885957.243 [circle_acoustic_contact:YoYos:B.AltitudeEnvelope] Running Loop=1
2019-05-15T02:05:57.243Z,1557885957.243 [circle_acoustic_contact:YoYos:B.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent.
2019-05-15T02:05:57.243Z,1557885957.243 [circle_acoustic_contact:YoYos:C.YoYo] Running Loop=1
2019-05-15T02:05:57.243Z,1557885957.243 [circle_acoustic_contact:YoYos:C.YoYo](DEBUG): Initialize YoYoComponent.
2019-05-15T02:05:57.244Z,1557885957.244 [circle_acoustic_contact:D] Running Loop=1
2019-05-15T02:05:57.244Z,1557885957.244 [circle_acoustic_contact:YoYos] Running Loop=1
2019-05-15T02:05:57.244Z,1557885957.244 [circle_acoustic_contact:YoYos:C.YoYo] Running Loop=1
2019-05-15T02:05:57.245Z,1557885957.245 [circle_acoustic_contact:YoYos:B.AltitudeEnvelope] Running Loop=1
2019-05-15T02:05:57.245Z,1557885957.245 [circle_acoustic_contact:YoYos:A.DepthEnvelope] Running Loop=1
2019-05-15T02:05:57.247Z,1557885957.247 [circle_acoustic_contact:L.SetSpeed] Running Loop=1
2019-05-15T02:05:57.247Z,1557885957.247 [circle_acoustic_contact:Science] Running Loop=1
2019-05-15T02:05:57.248Z,1557885957.248 [circle_acoustic_contact:Science:PeakDetectFDOM] Stopped
2019-05-15T02:05:57.264Z,1557885957.264 [circle_acoustic_contact:Science:PeakDetectFDOM](DEBUG): Aggregate::uninitialize circle_acoustic_contact:Science:PeakDetectFDOM
2019-05-15T02:05:57.264Z,1557885957.264 [circle_acoustic_contact:Science:PeakDetectFDOM:A.PeakDetectVsDepth] Stopped
2019-05-15T02:05:57.264Z,1557885957.264 [circle_acoustic_contact:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2019-05-15T02:05:57.264Z,1557885957.264 [circle_acoustic_contact:Science:PeakDetectOil] Stopped
2019-05-15T02:05:57.264Z,1557885957.264 [circle_acoustic_contact:Science:PeakDetectOil](DEBUG): Aggregate::uninitialize circle_acoustic_contact:Science:PeakDetectOil
2019-05-15T02:05:57.264Z,1557885957.264 [circle_acoustic_contact:Science:PeakDetectOil:A.PeakDetectVsDepth] Stopped
2019-05-15T02:05:57.264Z,1557885957.264 [circle_acoustic_contact:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2019-05-15T02:05:57.265Z,1557885957.265 [circle_acoustic_contact:Science:PeakDetectNO3] Stopped
2019-05-15T02:05:57.265Z,1557885957.265 [circle_acoustic_contact:Science:PeakDetectNO3](DEBUG): Aggregate::uninitialize circle_acoustic_contact:Science:PeakDetectNO3
2019-05-15T02:05:57.265Z,1557885957.265 [circle_acoustic_contact:Science:PeakDetectNO3:A.PeakDetectVsDepth] Stopped
2019-05-15T02:05:57.265Z,1557885957.265 [circle_acoustic_contact:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2019-05-15T02:05:57.265Z,1557885957.265 [circle_acoustic_contact:Science:HighestChlPeakReport] Stopped
2019-05-15T02:05:57.265Z,1557885957.265 [circle_acoustic_contact:Science:HighestChlPeakReport](DEBUG): Aggregate::uninitialize circle_acoustic_contact:Science:HighestChlPeakReport
2019-05-15T02:05:57.265Z,1557885957.265 [circle_acoustic_contact:Science:HighestChlPeakReport:A.PeakDetectHorizontal] Stopped
2019-05-15T02:05:57.265Z,1557885957.265 [circle_acoustic_contact:Science:HighestChlPeakReport:A.PeakDetectHorizontal](DEBUG): Uninitialize.
2019-05-15T02:05:57.265Z,1557885957.265 [circle_acoustic_contact:Science:PeakDetectChl] Running Loop=1
2019-05-15T02:05:57.266Z,1557885957.266 [circle_acoustic_contact:Science:Read_Oil] Stopped
2019-05-15T02:05:57.266Z,1557885957.266 [circle_acoustic_contact:Science:H] Stopped
2019-05-15T02:05:57.266Z,1557885957.266 [circle_acoustic_contact:Science:G] Running Loop=1
2019-05-15T02:05:57.266Z,1557885957.266 [circle_acoustic_contact:Science:G](DEBUG): Initialize ReadDataComponent to sense mass_concentration_of_chlorophyll_in_sea_water
2019-05-15T02:05:57.266Z,1557885957.266 [circle_acoustic_contact:Science:F] Stopped
2019-05-15T02:05:57.266Z,1557885957.266 [circle_acoustic_contact:Science:E] Stopped
2019-05-15T02:05:57.267Z,1557885957.267 [circle_acoustic_contact:Science:D] Running Loop=1
2019-05-15T02:05:57.267Z,1557885957.267 [circle_acoustic_contact:Science:D](DEBUG): Initialize ReadDataComponent to sense CTD_Seabird.sea_water_temperature
2019-05-15T02:05:57.268Z,1557885957.268 [circle_acoustic_contact:Science:D](DEBUG): Initialize ReadDataComponent to sense CTD_Seabird.sea_water_salinity
2019-05-15T02:05:57.268Z,1557885957.268 [circle_acoustic_contact:Science:C] Running Loop=1
2019-05-15T02:05:57.280Z,1557885957.280 [circle_acoustic_contact:Science:C](DEBUG): Initialize ReadDataComponent to sense sea_water_temperature
2019-05-15T02:05:57.282Z,1557885957.282 [WetLabsBB2FL](INFO): Opening uart, block timeout 10ths=2
2019-05-15T02:05:57.282Z,1557885957.282 [WetLabsBB2FL](INFO): Powering up
2019-05-15T02:05:57.283Z,1557885957.283 [circle_acoustic_contact:Science:C](DEBUG): Initialize ReadDataComponent to sense sea_water_salinity
2019-05-15T02:05:57.283Z,1557885957.283 [circle_acoustic_contact:Science:B] Stopped
2019-05-15T02:05:57.283Z,1557885957.283 [circle_acoustic_contact:Science:A] Running Loop=1
2019-05-15T02:05:57.284Z,1557885957.284 [circle_acoustic_contact:Science:A](DEBUG): Initialize ReadDataComponent to sense mass_concentration_of_oxygen_in_sea_water
2019-05-15T02:05:57.284Z,1557885957.284 [circle_acoustic_contact:J.Buoyancy] Running Loop=1
2019-05-15T02:05:57.289Z,1557885957.289 [circle_acoustic_contact:I.Pitch] Running Loop=1
2019-05-15T02:05:57.289Z,1557885957.289 [circle_acoustic_contact:StandardEnvelopes] Running Loop=1
2019-05-15T02:05:57.289Z,1557885957.289 [circle_acoustic_contact:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1
2019-05-15T02:05:57.298Z,1557885957.298 [circle_acoustic_contact:StandardEnvelopes:B.DepthEnvelope] Running Loop=1
2019-05-15T02:05:57.298Z,1557885957.298 [circle_acoustic_contact:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1
2019-05-15T02:05:57.299Z,1557885957.299 [circle_acoustic_contact:D] Stopped
2019-05-15T02:05:57.299Z,1557885957.299 [circle_acoustic_contact:F] Running Loop=1
2019-05-15T02:05:57.299Z,1557885957.299 [circle_acoustic_contact:A.] Running Loop=1
2019-05-15T02:05:57.299Z,1557885957.299 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:05:57.300Z,1557885957.300 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:05:57.425Z,1557885957.425 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown.
2019-05-15T02:05:57.426Z,1557885957.426 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4
2019-05-15T02:05:57.673Z,1557885957.673 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20
2019-05-15T02:05:57.676Z,1557885957.676 [circle_acoustic_contact:F] Stopped
2019-05-15T02:05:57.680Z,1557885957.680 [circle_acoustic_contact:G] Running Loop=1
2019-05-15T02:05:57.700Z,1557885957.700 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:05:57.701Z,1557885957.701 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:05:58.029Z,1557885958.029 [circle_acoustic_contact:G] Stopped
2019-05-15T02:05:58.029Z,1557885958.029 [circle_acoustic_contact:H] Running Loop=1
2019-05-15T02:05:58.053Z,1557885958.053 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:05:58.054Z,1557885958.054 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:05:58.438Z,1557885958.438 [circle_acoustic_contact:H] Stopped
2019-05-15T02:05:58.438Z,1557885958.438 [circle_acoustic_contact:CircleWrapper] Running Loop=1
2019-05-15T02:05:58.438Z,1557885958.438 [circle_acoustic_contact:CircleWrapper](DEBUG): Aggregate::initialize circle_acoustic_contact:CircleWrapper
2019-05-15T02:05:58.463Z,1557885958.463 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:05:58.463Z,1557885958.463 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:05:58.886Z,1557885958.886 [circle_acoustic_contact:CircleWrapper:CircleContact] Running Loop=1
2019-05-15T02:05:58.887Z,1557885958.887 [circle_acoustic_contact:CircleWrapper:CircleContact](DEBUG): Aggregate::initialize circle_acoustic_contact:CircleWrapper:CircleContact
2019-05-15T02:05:58.887Z,1557885958.887 [circle_acoustic_contact:CircleWrapper:CircleContact:A] Running Loop=1
2019-05-15T02:05:58.887Z,1557885958.887 [circle_acoustic_contact:CircleWrapper:CircleContact:B.Circle] Running Loop=1
2019-05-15T02:05:58.887Z,1557885958.887 [circle_acoustic_contact:CircleWrapper:CircleContact:B.Circle](DEBUG): Initialize CircleComponent.
2019-05-15T02:05:58.898Z,1557885958.898 [circle_acoustic_contact:CircleWrapper:CircleContact:A] Running Loop=1
2019-05-15T02:05:58.899Z,1557885958.899 [circle_acoustic_contact:YoYos:B.AltitudeEnvelope](ERROR): Altitude Measurement is not Active.
2019-05-15T02:05:58.935Z,1557885958.935 [circle_acoustic_contact:StandardEnvelopes:A.AltitudeEnvelope](ERROR): Altitude Measurement is not Active.
2019-05-15T02:05:58.935Z,1557885958.935 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:05:58.936Z,1557885958.936 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:05:59.315Z,1557885959.315 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:05:59.315Z,1557885959.315 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:05:59.718Z,1557885959.718 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:05:59.719Z,1557885959.719 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:00.123Z,1557885960.123 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:00.124Z,1557885960.124 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:00.521Z,1557885960.521 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:00.522Z,1557885960.522 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:00.674Z,1557885960.674 [CTD_Seabird](ERROR): Failed to parse device response: <!--startlogging-->
2019-05-15T02:06:00.907Z,1557885960.907 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:00.908Z,1557885960.908 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:01.331Z,1557885961.331 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:01.332Z,1557885961.332 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:01.719Z,1557885961.719 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:01.720Z,1557885961.720 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:02.140Z,1557885962.140 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:02.145Z,1557885962.145 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:02.557Z,1557885962.557 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:02.558Z,1557885962.558 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:02.932Z,1557885962.932 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:02.961Z,1557885962.961 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:03.362Z,1557885963.362 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:03.362Z,1557885963.362 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:03.719Z,1557885963.719 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:03.719Z,1557885963.719 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:04.125Z,1557885964.125 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:04.126Z,1557885964.126 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:04.554Z,1557885964.554 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:04.555Z,1557885964.555 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:04.936Z,1557885964.936 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:04.945Z,1557885964.945 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:05.366Z,1557885965.366 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:05.366Z,1557885965.366 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:05.726Z,1557885965.726 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:05.727Z,1557885965.727 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:06.117Z,1557885966.117 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:06.118Z,1557885966.118 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:06.566Z,1557885966.566 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:06.566Z,1557885966.566 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:06.966Z,1557885966.966 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:06.967Z,1557885966.967 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:07.274Z,1557885967.274 [NAL9602](INFO): Not Powering down - fast GPS
2019-05-15T02:06:07.403Z,1557885967.403 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:07.404Z,1557885967.404 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:07.772Z,1557885967.772 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:07.777Z,1557885967.777 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:08.168Z,1557885968.168 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:08.177Z,1557885968.177 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:08.550Z,1557885968.550 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:08.551Z,1557885968.551 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:08.937Z,1557885968.937 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:08.938Z,1557885968.938 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:09.347Z,1557885969.347 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:09.348Z,1557885969.348 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:09.761Z,1557885969.761 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:09.762Z,1557885969.762 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:10.195Z,1557885970.195 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:10.196Z,1557885970.196 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:10.560Z,1557885970.560 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:10.561Z,1557885970.561 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:10.979Z,1557885970.979 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:10.980Z,1557885970.980 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:11.379Z,1557885971.379 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:11.379Z,1557885971.379 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:11.800Z,1557885971.800 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:11.800Z,1557885971.800 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:12.168Z,1557885972.168 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:12.169Z,1557885972.169 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:12.567Z,1557885972.567 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:12.567Z,1557885972.567 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:13.004Z,1557885973.004 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:13.005Z,1557885973.005 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:13.398Z,1557885973.398 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:13.399Z,1557885973.399 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:13.805Z,1557885973.805 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:13.806Z,1557885973.806 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:14.196Z,1557885974.196 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:14.197Z,1557885974.197 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:14.603Z,1557885974.603 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:14.604Z,1557885974.604 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:15.060Z,1557885975.060 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:15.065Z,1557885975.065 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:15.412Z,1557885975.412 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:15.412Z,1557885975.412 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:15.798Z,1557885975.798 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:15.799Z,1557885975.799 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:16.242Z,1557885976.242 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:16.250Z,1557885976.250 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:16.610Z,1557885976.610 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:16.611Z,1557885976.611 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:17.028Z,1557885977.028 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:17.033Z,1557885977.033 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:17.451Z,1557885977.451 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:17.451Z,1557885977.451 [circle_acoustic_contact:A.](INFO): update period (20.000000 s) has elapsed, querying...
2019-05-15T02:06:17.451Z,1557885977.451 [circle_acoustic_contact:A.](INFO): *** querying DAT ***
2019-05-15T02:06:17.782Z,1557885977.782 [DAT](INFO): ****** ping requested ******
2019-05-15T02:06:17.812Z,1557885977.812 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:17.812Z,1557885977.812 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:18.215Z,1557885978.215 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:18.216Z,1557885978.216 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:18.647Z,1557885978.647 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:18.648Z,1557885978.648 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:19.050Z,1557885979.050 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:19.050Z,1557885979.050 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:19.521Z,1557885979.521 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:19.522Z,1557885979.522 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:19.870Z,1557885979.870 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:19.870Z,1557885979.870 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:20.284Z,1557885980.284 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:20.289Z,1557885980.289 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:20.664Z,1557885980.664 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:20.664Z,1557885980.664 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:21.071Z,1557885981.071 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:21.072Z,1557885981.072 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:21.524Z,1557885981.524 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:21.533Z,1557885981.533 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:21.828Z,1557885981.828 [DAT](INFO): got valid direction response:
 02:04:57.3173 LVL= 20976, 20513, 17458, 29555, AGC= 18, IDX=  75, 0.39, 1.487, 2.956,-2.264,-3.100, PHS=-1.608,-0.179, 0.833, RAW= 245.6,   9.0, CAL= 245.8,   8.1, ROT= 294.2,  -8.1

2019-05-15T02:06:21.834Z,1557885981.834 [DAT](INFO): rotatedAzimuthRad = 0.000000 forward, 0.000000 starboard, 0.000000 keelward ]
2019-05-15T02:06:21.868Z,1557885981.868 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:21.910Z,1557885981.910 [circle_acoustic_contact:A.](INFO): direction in vehicle frame: [ 0.405834 forward, -0.903020 starboard, -0.140901 keelward ]
2019-05-15T02:06:21.910Z,1557885981.910 [circle_acoustic_contact:A.](DEBUG): processing response from DAT
2019-05-15T02:06:21.912Z,1557885981.912 [circle_acoustic_contact:A.](INFO): rotationFromVehicleToNavigationFrame_ = [ 0.647177,-0.711976,0.272493;0.726652,0.684211,0.061907;-0.230519,0.157943,0.960164 ]
2019-05-15T02:06:21.916Z,1557885981.916 [circle_acoustic_contact:A.](INFO): rangeToContact_ = 2.353499 m
2019-05-15T02:06:21.929Z,1557885981.929 [circle_acoustic_contact:A.](INFO): direction in world frame: [ -0.361055 forward, -0.929055 starboard, -0.080605 keelward ]
2019-05-15T02:06:21.930Z,1557885981.930 [circle_acoustic_contact:A.](INFO): relPosInFSK: [ 0.955129 forward, -2.125258 starboard, -0.331611 keelward ]
2019-05-15T02:06:21.930Z,1557885981.930 [circle_acoustic_contact:A.](INFO): relPosInNED: [ -0.849742 forward, -2.186529 starboard, -0.189703 keelward ]
2019-05-15T02:06:21.931Z,1557885981.931 [circle_acoustic_contact:A.](INFO): azimuthInNED_ = -1.941459 rad -- adding 2pi
2019-05-15T02:06:21.932Z,1557885981.932 [circle_acoustic_contact:A.](INFO): azimuthInNED_ = 4.341726 rad after adding 2pi
2019-05-15T02:06:21.932Z,1557885981.932 [circle_acoustic_contact:A.](DEBUG): First numStartingFixesToIgnoreSetting_ hits rejected because the vehicle just left the surface, and the bearing estimate can be way wrong.
2019-05-15T02:06:22.334Z,1557885982.334 [circle_acoustic_contact:UpdateCenter] Running Loop=1
2019-05-15T02:06:22.334Z,1557885982.334 [circle_acoustic_contact:UpdateCenter](DEBUG): Aggregate::initialize circle_acoustic_contact:UpdateCenter
2019-05-15T02:06:22.335Z,1557885982.335 [circle_acoustic_contact:UpdateCenter:A] Running Loop=1
2019-05-15T02:06:22.335Z,1557885982.335 [circle_acoustic_contact:UpdateCenter:A] Stopped
2019-05-15T02:06:22.335Z,1557885982.335 [circle_acoustic_contact:UpdateCenter:B] Running Loop=1
2019-05-15T02:06:22.335Z,1557885982.335 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:22.336Z,1557885982.336 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:22.681Z,1557885982.681 [circle_acoustic_contact:UpdateCenter:B] Stopped
2019-05-15T02:06:22.682Z,1557885982.682 [circle_acoustic_contact:UpdateCenter](INFO): Completed circle_acoustic_contact:UpdateCenter
2019-05-15T02:06:22.682Z,1557885982.682 [circle_acoustic_contact:UpdateCenter] Stopped
2019-05-15T02:06:22.682Z,1557885982.682 [circle_acoustic_contact:UpdateCenter](DEBUG): Aggregate::uninitialize circle_acoustic_contact:UpdateCenter
2019-05-15T02:06:22.682Z,1557885982.682 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:22.683Z,1557885982.683 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:23.112Z,1557885983.112 [circle_acoustic_contact:UpdateCenter] Running Loop=1
2019-05-15T02:06:23.112Z,1557885983.112 [circle_acoustic_contact:UpdateCenter](DEBUG): Aggregate::initialize circle_acoustic_contact:UpdateCenter
2019-05-15T02:06:23.112Z,1557885983.112 [circle_acoustic_contact:UpdateCenter:A] Running Loop=1
2019-05-15T02:06:23.112Z,1557885983.112 [circle_acoustic_contact:UpdateCenter:A] Stopped
2019-05-15T02:06:23.112Z,1557885983.112 [circle_acoustic_contact:UpdateCenter:B] Running Loop=1
2019-05-15T02:06:23.112Z,1557885983.112 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:23.133Z,1557885983.133 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:23.479Z,1557885983.479 [circle_acoustic_contact:UpdateCenter:B] Stopped
2019-05-15T02:06:23.479Z,1557885983.479 [circle_acoustic_contact:UpdateCenter](INFO): Completed circle_acoustic_contact:UpdateCenter
2019-05-15T02:06:23.479Z,1557885983.479 [circle_acoustic_contact:UpdateCenter] Stopped
2019-05-15T02:06:23.479Z,1557885983.479 [circle_acoustic_contact:UpdateCenter](DEBUG): Aggregate::uninitialize circle_acoustic_contact:UpdateCenter
2019-05-15T02:06:23.479Z,1557885983.479 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:23.480Z,1557885983.480 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:23.931Z,1557885983.931 [circle_acoustic_contact:UpdateCenter] Running Loop=1
2019-05-15T02:06:23.931Z,1557885983.931 [circle_acoustic_contact:UpdateCenter](DEBUG): Aggregate::initialize circle_acoustic_contact:UpdateCenter
2019-05-15T02:06:23.932Z,1557885983.932 [circle_acoustic_contact:UpdateCenter:A] Running Loop=1
2019-05-15T02:06:23.932Z,1557885983.932 [circle_acoustic_contact:UpdateCenter:A] Stopped
2019-05-15T02:06:23.932Z,1557885983.932 [circle_acoustic_contact:UpdateCenter:B] Running Loop=1
2019-05-15T02:06:23.932Z,1557885983.932 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:23.937Z,1557885983.937 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:24.325Z,1557885984.325 [circle_acoustic_contact:UpdateCenter:B] Stopped
2019-05-15T02:06:24.325Z,1557885984.325 [circle_acoustic_contact:UpdateCenter](INFO): Completed circle_acoustic_contact:UpdateCenter
2019-05-15T02:06:24.326Z,1557885984.326 [circle_acoustic_contact:UpdateCenter] Stopped
2019-05-15T02:06:24.326Z,1557885984.326 [circle_acoustic_contact:UpdateCenter](DEBUG): Aggregate::uninitialize circle_acoustic_contact:UpdateCenter
2019-05-15T02:06:24.326Z,1557885984.326 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:24.326Z,1557885984.326 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:24.774Z,1557885984.774 [circle_acoustic_contact:UpdateCenter] Running Loop=1
2019-05-15T02:06:24.774Z,1557885984.774 [circle_acoustic_contact:UpdateCenter](DEBUG): Aggregate::initialize circle_acoustic_contact:UpdateCenter
2019-05-15T02:06:24.774Z,1557885984.774 [circle_acoustic_contact:UpdateCenter:A] Running Loop=1
2019-05-15T02:06:24.774Z,1557885984.774 [circle_acoustic_contact:UpdateCenter:A] Stopped
2019-05-15T02:06:24.774Z,1557885984.774 [circle_acoustic_contact:UpdateCenter:B] Running Loop=1
2019-05-15T02:06:24.774Z,1557885984.774 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:24.775Z,1557885984.775 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:25.120Z,1557885985.120 [circle_acoustic_contact:UpdateCenter:B] Stopped
2019-05-15T02:06:25.120Z,1557885985.120 [circle_acoustic_contact:UpdateCenter](INFO): Completed circle_acoustic_contact:UpdateCenter
2019-05-15T02:06:25.120Z,1557885985.120 [circle_acoustic_contact:UpdateCenter] Stopped
2019-05-15T02:06:25.120Z,1557885985.120 [circle_acoustic_contact:UpdateCenter](DEBUG): Aggregate::uninitialize circle_acoustic_contact:UpdateCenter
2019-05-15T02:06:25.125Z,1557885985.125 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:25.125Z,1557885985.125 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:25.486Z,1557885985.486 [circle_acoustic_contact:UpdateCenter] Running Loop=1
2019-05-15T02:06:25.486Z,1557885985.486 [circle_acoustic_contact:UpdateCenter](DEBUG): Aggregate::initialize circle_acoustic_contact:UpdateCenter
2019-05-15T02:06:25.486Z,1557885985.486 [circle_acoustic_contact:UpdateCenter:A] Running Loop=1
2019-05-15T02:06:25.487Z,1557885985.487 [circle_acoustic_contact:UpdateCenter:A] Stopped
2019-05-15T02:06:25.487Z,1557885985.487 [circle_acoustic_contact:UpdateCenter:B] Running Loop=1
2019-05-15T02:06:25.487Z,1557885985.487 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:25.488Z,1557885985.488 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:25.936Z,1557885985.936 [circle_acoustic_contact:UpdateCenter:B] Stopped
2019-05-15T02:06:25.936Z,1557885985.936 [circle_acoustic_contact:UpdateCenter](INFO): Completed circle_acoustic_contact:UpdateCenter
2019-05-15T02:06:25.936Z,1557885985.936 [circle_acoustic_contact:UpdateCenter] Stopped
2019-05-15T02:06:25.936Z,1557885985.936 [circle_acoustic_contact:UpdateCenter](DEBUG): Aggregate::uninitialize circle_acoustic_contact:UpdateCenter
2019-05-15T02:06:25.941Z,1557885985.941 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:25.941Z,1557885985.941 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:26.320Z,1557885986.320 [circle_acoustic_contact:UpdateCenter] Running Loop=1
2019-05-15T02:06:26.320Z,1557885986.320 [circle_acoustic_contact:UpdateCenter](DEBUG): Aggregate::initialize circle_acoustic_contact:UpdateCenter
2019-05-15T02:06:26.320Z,1557885986.320 [circle_acoustic_contact:UpdateCenter:A] Running Loop=1
2019-05-15T02:06:26.320Z,1557885986.320 [circle_acoustic_contact:UpdateCenter:A] Stopped
2019-05-15T02:06:26.320Z,1557885986.320 [circle_acoustic_contact:UpdateCenter:B] Running Loop=1
2019-05-15T02:06:26.320Z,1557885986.320 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:26.321Z,1557885986.321 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:26.741Z,1557885986.741 [circle_acoustic_contact:UpdateCenter:B] Stopped
2019-05-15T02:06:26.742Z,1557885986.742 [circle_acoustic_contact:UpdateCenter](INFO): Completed circle_acoustic_contact:UpdateCenter
2019-05-15T02:06:26.742Z,1557885986.742 [circle_acoustic_contact:UpdateCenter] Stopped
2019-05-15T02:06:26.742Z,1557885986.742 [circle_acoustic_contact:UpdateCenter](DEBUG): Aggregate::uninitialize circle_acoustic_contact:UpdateCenter
2019-05-15T02:06:26.742Z,1557885986.742 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:26.743Z,1557885986.743 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:27.152Z,1557885987.152 [circle_acoustic_contact:UpdateCenter] Running Loop=1
2019-05-15T02:06:27.152Z,1557885987.152 [circle_acoustic_contact:UpdateCenter](DEBUG): Aggregate::initialize circle_acoustic_contact:UpdateCenter
2019-05-15T02:06:27.152Z,1557885987.152 [circle_acoustic_contact:UpdateCenter:A] Running Loop=1
2019-05-15T02:06:27.152Z,1557885987.152 [circle_acoustic_contact:UpdateCenter:A] Stopped
2019-05-15T02:06:27.157Z,1557885987.157 [circle_acoustic_contact:UpdateCenter:B] Running Loop=1
2019-05-15T02:06:27.157Z,1557885987.157 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:27.158Z,1557885987.158 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:27.536Z,1557885987.536 [circle_acoustic_contact:UpdateCenter:B] Stopped
2019-05-15T02:06:27.536Z,1557885987.536 [circle_acoustic_contact:UpdateCenter](INFO): Completed circle_acoustic_contact:UpdateCenter
2019-05-15T02:06:27.536Z,1557885987.536 [circle_acoustic_contact:UpdateCenter] Stopped
2019-05-15T02:06:27.536Z,1557885987.536 [circle_acoustic_contact:UpdateCenter](DEBUG): Aggregate::uninitialize circle_acoustic_contact:UpdateCenter
2019-05-15T02:06:27.536Z,1557885987.536 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:27.541Z,1557885987.541 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:28.032Z,1557885988.032 [circle_acoustic_contact:UpdateCenter] Running Loop=1
2019-05-15T02:06:28.032Z,1557885988.032 [circle_acoustic_contact:UpdateCenter](DEBUG): Aggregate::initialize circle_acoustic_contact:UpdateCenter
2019-05-15T02:06:28.032Z,1557885988.032 [circle_acoustic_contact:UpdateCenter:A] Running Loop=1
2019-05-15T02:06:28.032Z,1557885988.032 [circle_acoustic_contact:UpdateCenter:A] Stopped
2019-05-15T02:06:28.032Z,1557885988.032 [circle_acoustic_contact:UpdateCenter:B] Running Loop=1
2019-05-15T02:06:28.032Z,1557885988.032 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:28.041Z,1557885988.041 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:28.368Z,1557885988.368 [circle_acoustic_contact:UpdateCenter:B] Stopped
2019-05-15T02:06:28.368Z,1557885988.368 [circle_acoustic_contact:UpdateCenter](INFO): Completed circle_acoustic_contact:UpdateCenter
2019-05-15T02:06:28.368Z,1557885988.368 [circle_acoustic_contact:UpdateCenter] Stopped
2019-05-15T02:06:28.368Z,1557885988.368 [circle_acoustic_contact:UpdateCenter](DEBUG): Aggregate::uninitialize circle_acoustic_contact:UpdateCenter
2019-05-15T02:06:28.368Z,1557885988.368 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:28.377Z,1557885988.377 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:28.810Z,1557885988.810 [circle_acoustic_contact:UpdateCenter] Running Loop=1
2019-05-15T02:06:28.810Z,1557885988.810 [circle_acoustic_contact:UpdateCenter](DEBUG): Aggregate::initialize circle_acoustic_contact:UpdateCenter
2019-05-15T02:06:28.811Z,1557885988.811 [circle_acoustic_contact:UpdateCenter:A] Running Loop=1
2019-05-15T02:06:28.811Z,1557885988.811 [circle_acoustic_contact:UpdateCenter:A] Stopped
2019-05-15T02:06:28.811Z,1557885988.811 [circle_acoustic_contact:UpdateCenter:B] Running Loop=1
2019-05-15T02:06:28.811Z,1557885988.811 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:28.812Z,1557885988.812 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:29.256Z,1557885989.256 [circle_acoustic_contact:UpdateCenter:B] Stopped
2019-05-15T02:06:29.265Z,1557885989.265 [circle_acoustic_contact:UpdateCenter](INFO): Completed circle_acoustic_contact:UpdateCenter
2019-05-15T02:06:29.265Z,1557885989.265 [circle_acoustic_contact:UpdateCenter] Stopped
2019-05-15T02:06:29.265Z,1557885989.265 [circle_acoustic_contact:UpdateCenter](DEBUG): Aggregate::uninitialize circle_acoustic_contact:UpdateCenter
2019-05-15T02:06:29.265Z,1557885989.265 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:29.266Z,1557885989.266 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:29.563Z,1557885989.563 [circle_acoustic_contact:UpdateCenter] Running Loop=1
2019-05-15T02:06:29.563Z,1557885989.563 [circle_acoustic_contact:UpdateCenter](DEBUG): Aggregate::initialize circle_acoustic_contact:UpdateCenter
2019-05-15T02:06:29.564Z,1557885989.564 [circle_acoustic_contact:UpdateCenter:A] Running Loop=1
2019-05-15T02:06:29.564Z,1557885989.564 [circle_acoustic_contact:UpdateCenter:A] Stopped
2019-05-15T02:06:29.564Z,1557885989.564 [circle_acoustic_contact:UpdateCenter:B] Running Loop=1
2019-05-15T02:06:29.564Z,1557885989.564 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:29.597Z,1557885989.597 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:29.976Z,1557885989.976 [circle_acoustic_contact:UpdateCenter:B] Stopped
2019-05-15T02:06:29.976Z,1557885989.976 [circle_acoustic_contact:UpdateCenter](INFO): Completed circle_acoustic_contact:UpdateCenter
2019-05-15T02:06:29.976Z,1557885989.976 [circle_acoustic_contact:UpdateCenter] Stopped
2019-05-15T02:06:29.981Z,1557885989.981 [circle_acoustic_contact:UpdateCenter](DEBUG): Aggregate::uninitialize circle_acoustic_contact:UpdateCenter
2019-05-15T02:06:29.981Z,1557885989.981 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:29.982Z,1557885989.982 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:30.387Z,1557885990.387 [circle_acoustic_contact:UpdateCenter] Running Loop=1
2019-05-15T02:06:30.387Z,1557885990.387 [circle_acoustic_contact:UpdateCenter](DEBUG): Aggregate::initialize circle_acoustic_contact:UpdateCenter
2019-05-15T02:06:30.387Z,1557885990.387 [circle_acoustic_contact:UpdateCenter:A] Running Loop=1
2019-05-15T02:06:30.388Z,1557885990.388 [circle_acoustic_contact:UpdateCenter:A] Stopped
2019-05-15T02:06:30.388Z,1557885990.388 [circle_acoustic_contact:UpdateCenter:B] Running Loop=1
2019-05-15T02:06:30.388Z,1557885990.388 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:30.388Z,1557885990.388 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:30.808Z,1557885990.808 [circle_acoustic_contact:UpdateCenter:B] Stopped
2019-05-15T02:06:30.808Z,1557885990.808 [circle_acoustic_contact:UpdateCenter](INFO): Completed circle_acoustic_contact:UpdateCenter
2019-05-15T02:06:30.808Z,1557885990.808 [circle_acoustic_contact:UpdateCenter] Stopped
2019-05-15T02:06:30.808Z,1557885990.808 [circle_acoustic_contact:UpdateCenter](DEBUG): Aggregate::uninitialize circle_acoustic_contact:UpdateCenter
2019-05-15T02:06:30.808Z,1557885990.808 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:30.813Z,1557885990.813 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:30.831Z,1557885990.831 [CommandLine](IMPORTANT): got command get SpeedControl.propOmegaAction
2019-05-15T02:06:30.832Z,1557885990.832 [CommandLine](IMPORTANT): SpeedControl.propOmegaAction 31.416014 rad/s
2019-05-15T02:06:31.190Z,1557885991.190 [circle_acoustic_contact:UpdateCenter] Running Loop=1
2019-05-15T02:06:31.190Z,1557885991.190 [circle_acoustic_contact:UpdateCenter](DEBUG): Aggregate::initialize circle_acoustic_contact:UpdateCenter
2019-05-15T02:06:31.190Z,1557885991.190 [circle_acoustic_contact:UpdateCenter:A] Running Loop=1
2019-05-15T02:06:31.190Z,1557885991.190 [circle_acoustic_contact:UpdateCenter:A] Stopped
2019-05-15T02:06:31.190Z,1557885991.190 [circle_acoustic_contact:UpdateCenter:B] Running Loop=1
2019-05-15T02:06:31.191Z,1557885991.191 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:31.191Z,1557885991.191 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:31.607Z,1557885991.607 [circle_acoustic_contact:UpdateCenter:B] Stopped
2019-05-15T02:06:31.608Z,1557885991.608 [circle_acoustic_contact:UpdateCenter](INFO): Completed circle_acoustic_contact:UpdateCenter
2019-05-15T02:06:31.608Z,1557885991.608 [circle_acoustic_contact:UpdateCenter] Stopped
2019-05-15T02:06:31.608Z,1557885991.608 [circle_acoustic_contact:UpdateCenter](DEBUG): Aggregate::uninitialize circle_acoustic_contact:UpdateCenter
2019-05-15T02:06:31.608Z,1557885991.608 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:31.613Z,1557885991.613 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:32.003Z,1557885992.003 [circle_acoustic_contact:UpdateCenter] Running Loop=1
2019-05-15T02:06:32.003Z,1557885992.003 [circle_acoustic_contact:UpdateCenter](DEBUG): Aggregate::initialize circle_acoustic_contact:UpdateCenter
2019-05-15T02:06:32.004Z,1557885992.004 [circle_acoustic_contact:UpdateCenter:A] Running Loop=1
2019-05-15T02:06:32.004Z,1557885992.004 [circle_acoustic_contact:UpdateCenter:A] Stopped
2019-05-15T02:06:32.004Z,1557885992.004 [circle_acoustic_contact:UpdateCenter:B] Running Loop=1
2019-05-15T02:06:32.004Z,1557885992.004 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:32.009Z,1557885992.009 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:32.417Z,1557885992.417 [circle_acoustic_contact:UpdateCenter:B] Stopped
2019-05-15T02:06:32.417Z,1557885992.417 [circle_acoustic_contact:UpdateCenter](INFO): Completed circle_acoustic_contact:UpdateCenter
2019-05-15T02:06:32.417Z,1557885992.417 [circle_acoustic_contact:UpdateCenter] Stopped
2019-05-15T02:06:32.417Z,1557885992.417 [circle_acoustic_contact:UpdateCenter](DEBUG): Aggregate::uninitialize circle_acoustic_contact:UpdateCenter
2019-05-15T02:06:32.417Z,1557885992.417 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:32.418Z,1557885992.418 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:32.828Z,1557885992.828 [circle_acoustic_contact:UpdateCenter] Running Loop=1
2019-05-15T02:06:32.828Z,1557885992.828 [circle_acoustic_contact:UpdateCenter](DEBUG): Aggregate::initialize circle_acoustic_contact:UpdateCenter
2019-05-15T02:06:32.828Z,1557885992.828 [circle_acoustic_contact:UpdateCenter:A] Running Loop=1
2019-05-15T02:06:32.828Z,1557885992.828 [circle_acoustic_contact:UpdateCenter:A] Stopped
2019-05-15T02:06:32.833Z,1557885992.833 [circle_acoustic_contact:UpdateCenter:B] Running Loop=1
2019-05-15T02:06:32.833Z,1557885992.833 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:32.834Z,1557885992.834 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:33.254Z,1557885993.254 [circle_acoustic_contact:UpdateCenter:B] Stopped
2019-05-15T02:06:33.254Z,1557885993.254 [circle_acoustic_contact:UpdateCenter](INFO): Completed circle_acoustic_contact:UpdateCenter
2019-05-15T02:06:33.254Z,1557885993.254 [circle_acoustic_contact:UpdateCenter] Stopped
2019-05-15T02:06:33.254Z,1557885993.254 [circle_acoustic_contact:UpdateCenter](DEBUG): Aggregate::uninitialize circle_acoustic_contact:UpdateCenter
2019-05-15T02:06:33.255Z,1557885993.255 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:33.255Z,1557885993.255 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:33.622Z,1557885993.622 [circle_acoustic_contact:UpdateCenter] Running Loop=1
2019-05-15T02:06:33.622Z,1557885993.622 [circle_acoustic_contact:UpdateCenter](DEBUG): Aggregate::initialize circle_acoustic_contact:UpdateCenter
2019-05-15T02:06:33.622Z,1557885993.622 [circle_acoustic_contact:UpdateCenter:A] Running Loop=1
2019-05-15T02:06:33.622Z,1557885993.622 [circle_acoustic_contact:UpdateCenter:A] Stopped
2019-05-15T02:06:33.622Z,1557885993.622 [circle_acoustic_contact:UpdateCenter:B] Running Loop=1
2019-05-15T02:06:33.622Z,1557885993.622 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:33.623Z,1557885993.623 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:34.045Z,1557885994.045 [circle_acoustic_contact:UpdateCenter:B] Stopped
2019-05-15T02:06:34.045Z,1557885994.045 [circle_acoustic_contact:UpdateCenter](INFO): Completed circle_acoustic_contact:UpdateCenter
2019-05-15T02:06:34.045Z,1557885994.045 [circle_acoustic_contact:UpdateCenter] Stopped
2019-05-15T02:06:34.045Z,1557885994.045 [circle_acoustic_contact:UpdateCenter](DEBUG): Aggregate::uninitialize circle_acoustic_contact:UpdateCenter
2019-05-15T02:06:34.046Z,1557885994.046 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:34.046Z,1557885994.046 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:34.293Z,1557885994.293 [CommandLine](IMPORTANT): got command stop
2019-05-15T02:06:34.294Z,1557885994.294 [CommandLine](IMPORTANT): Scheduling is paused
2019-05-15T02:06:34.294Z,1557885994.294 [Supervisor](INFO): Stop Mission called by CommandLine::commandStop
2019-05-15T02:06:34.468Z,1557885994.468 [circle_acoustic_contact:UpdateCenter] Running Loop=1
2019-05-15T02:06:34.468Z,1557885994.468 [circle_acoustic_contact:UpdateCenter](DEBUG): Aggregate::initialize circle_acoustic_contact:UpdateCenter
2019-05-15T02:06:34.468Z,1557885994.468 [circle_acoustic_contact:UpdateCenter:A] Running Loop=1
2019-05-15T02:06:34.477Z,1557885994.477 [circle_acoustic_contact:UpdateCenter:A] Stopped
2019-05-15T02:06:34.477Z,1557885994.477 [circle_acoustic_contact:UpdateCenter:B] Running Loop=1
2019-05-15T02:06:34.477Z,1557885994.477 [circle_acoustic_contact:A.](DEBUG): Tracking...
2019-05-15T02:06:34.478Z,1557885994.478 [circle_acoustic_contact:A.](INFO): waiting for update period (20.000000 s) to elapse
2019-05-15T02:06:34.478Z,1557885994.478 [MissionManager](INFO): MissionManager is completed.
2019-05-15T02:06:34.478Z,1557885994.478 [MissionManager](INFO): Uninitializing Mission circle_acoustic_contact
2019-05-15T02:06:34.478Z,1557885994.478 [circle_acoustic_contact] Stopped
2019-05-15T02:06:34.478Z,1557885994.478 [circle_acoustic_contact](DEBUG): Aggregate::uninitialize circle_acoustic_contact
2019-05-15T02:06:34.478Z,1557885994.478 [circle_acoustic_contact:A.] Stopped
2019-05-15T02:06:34.478Z,1557885994.478 [circle_acoustic_contact:A.](DEBUG): Uninitializing Tracking.
2019-05-15T02:06:34.478Z,1557885994.478 [circle_acoustic_contact:UpdateCenter] Stopped
2019-05-15T02:06:34.478Z,1557885994.478 [circle_acoustic_contact:UpdateCenter](DEBUG): Aggregate::uninitialize circle_acoustic_contact:UpdateCenter
2019-05-15T02:06:34.479Z,1557885994.479 [circle_acoustic_contact:UpdateCenter:B] Stopped
2019-05-15T02:06:34.479Z,1557885994.479 [circle_acoustic_contact:StandardEnvelopes] Stopped
2019-05-15T02:06:34.479Z,1557885994.479 [circle_acoustic_contact:StandardEnvelopes](DEBUG): Aggregate::uninitialize circle_acoustic_contact:StandardEnvelopes
2019-05-15T02:06:34.479Z,1557885994.479 [circle_acoustic_contact:StandardEnvelopes:A.AltitudeEnvelope] Stopped
2019-05-15T02:06:34.479Z,1557885994.479 [circle_acoustic_contact:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent.
2019-05-15T02:06:34.479Z,1557885994.479 [circle_acoustic_contact:StandardEnvelopes:B.DepthEnvelope] Stopped
2019-05-15T02:06:34.479Z,1557885994.479 [circle_acoustic_contact:StandardEnvelopes:B.DepthEnvelope](DEBUG): Uninitialize.
2019-05-15T02:06:34.479Z,1557885994.479 [circle_acoustic_contact:StandardEnvelopes:C.OffshoreEnvelope] Stopped
2019-05-15T02:06:34.479Z,1557885994.479 [circle_acoustic_contact:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Uninitialize OffshoreEnvelopeComponent.
2019-05-15T02:06:34.479Z,1557885994.479 [circle_acoustic_contact:I.Pitch] Stopped
2019-05-15T02:06:34.479Z,1557885994.479 [circle_acoustic_contact:J.Buoyancy] Stopped
2019-05-15T02:06:34.479Z,1557885994.479 [circle_acoustic_contact:J.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2019-05-15T02:06:34.479Z,1557885994.479 [circle_acoustic_contact:Science] Stopped
2019-05-15T02:06:34.479Z,1557885994.479 [circle_acoustic_contact:Science](DEBUG): Aggregate::uninitialize circle_acoustic_contact:Science
2019-05-15T02:06:34.480Z,1557885994.480 [circle_acoustic_contact:Science:A] Stopped
2019-05-15T02:06:34.480Z,1557885994.480 [circle_acoustic_contact:Science:C] Stopped
2019-05-15T02:06:34.480Z,1557885994.480 [circle_acoustic_contact:Science:D] Stopped
2019-05-15T02:06:34.480Z,1557885994.480 [circle_acoustic_contact:Science:G] Stopped
2019-05-15T02:06:34.480Z,1557885994.480 [circle_acoustic_contact:Science:PeakDetectChl] Stopped
2019-05-15T02:06:34.480Z,1557885994.480 [circle_acoustic_contact:Science:PeakDetectChl](DEBUG): Aggregate::uninitialize circle_acoustic_contact:Science:PeakDetectChl
2019-05-15T02:06:34.480Z,1557885994.480 [circle_acoustic_contact:Science:PeakDetectChl:A.PeakDetectVsDepth] Stopped
2019-05-15T02:06:34.480Z,1557885994.480 [circle_acoustic_contact:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2019-05-15T02:06:34.480Z,1557885994.480 [circle_acoustic_contact:L.SetSpeed] Stopped
2019-05-15T02:06:34.480Z,1557885994.480 [circle_acoustic_contact:L.SetSpeed](DEBUG): Uninitialize.
2019-05-15T02:06:34.480Z,1557885994.480 [circle_acoustic_contact:YoYos] Stopped
2019-05-15T02:06:34.480Z,1557885994.480 [circle_acoustic_contact:YoYos](DEBUG): Aggregate::uninitialize circle_acoustic_contact:YoYos
2019-05-15T02:06:34.480Z,1557885994.480 [circle_acoustic_contact:YoYos:A.DepthEnvelope] Stopped
2019-05-15T02:06:34.489Z,1557885994.489 [circle_acoustic_contact:YoYos:A.DepthEnvelope](DEBUG): Uninitialize.
2019-05-15T02:06:34.489Z,1557885994.489 [circle_acoustic_contact:YoYos:B.AltitudeEnvelope] Stopped
2019-05-15T02:06:34.489Z,1557885994.489 [circle_acoustic_contact:YoYos:B.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent.
2019-05-15T02:06:34.489Z,1557885994.489 [circle_acoustic_contact:YoYos:C.YoYo] Stopped
2019-05-15T02:06:34.489Z,1557885994.489 [circle_acoustic_contact:YoYos:C.YoYo](DEBUG): Uninitialize YoYoComponent.
2019-05-15T02:06:34.489Z,1557885994.489 [circle_acoustic_contact:CircleWrapper] Stopped
2019-05-15T02:06:34.489Z,1557885994.489 [circle_acoustic_contact:CircleWrapper](DEBUG): Aggregate::uninitialize circle_acoustic_contact:CircleWrapper
2019-05-15T02:06:34.489Z,1557885994.489 [circle_acoustic_contact:CircleWrapper:CircleContact] Stopped
2019-05-15T02:06:34.489Z,1557885994.489 [circle_acoustic_contact:CircleWrapper:CircleContact](DEBUG): Aggregate::uninitialize circle_acoustic_contact:CircleWrapper:CircleContact
2019-05-15T02:06:34.489Z,1557885994.489 [circle_acoustic_contact:CircleWrapper:CircleContact:A] Stopped
2019-05-15T02:06:34.490Z,1557885994.490 [circle_acoustic_contact:CircleWrapper:CircleContact:B.Circle] Stopped
2019-05-15T02:06:34.490Z,1557885994.490 [circle_acoustic_contact:CircleWrapper:CircleContact:B.Circle](DEBUG): Uninitialize.
2019-05-15T02:06:34.709Z,1557885994.709 [WetLabsBB2FL](INFO): Powering down
2019-05-15T02:06:34.846Z,1557885994.846 [MissionManager](IMPORTANT): Started mission Default
2019-05-15T02:06:34.846Z,1557885994.846 [Default] Running Loop=1
2019-05-15T02:06:34.847Z,1557885994.847 [Default](DEBUG): Aggregate::initialize Default
2019-05-15T02:06:34.847Z,1557885994.847 [Default:B.GoToSurface] Running Loop=1
2019-05-15T02:06:34.847Z,1557885994.847 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-05-15T02:06:34.847Z,1557885994.847 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-05-15T02:06:34.847Z,1557885994.847 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-05-15T02:06:34.848Z,1557885994.848 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-05-15T02:06:34.848Z,1557885994.848 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-05-15T02:06:34.848Z,1557885994.848 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-05-15T02:06:34.857Z,1557885994.857 [Default:A.Wait] Running Loop=1
2019-05-15T02:06:34.857Z,1557885994.857 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-05-15T02:06:35.305Z,1557885995.305 [Aanderaa_O2](INFO): Powering down
2019-05-15T02:06:48.124Z,1557886008.124 [Default:A.Wait](INFO): Done Waiting.
2019-05-15T02:06:48.124Z,1557886008.124 [Default:A.Wait] Stopped
2019-05-15T02:06:48.124Z,1557886008.124 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-05-15T02:06:48.534Z,1557886008.534 [Default:CheckIn] Running Loop=1
2019-05-15T02:06:48.534Z,1557886008.534 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-05-15T02:06:48.534Z,1557886008.534 [Default:CheckIn:Read_GPS] Running Loop=1
2019-05-15T02:06:50.121Z,1557886010.121 [NAL9602](DEBUG): Fix Requested
2019-05-15T02:07:37.379Z,1557886057.379 [NAL9602](INFO): SBD MO Status=2, MOMSN=12110, MT Status=2, MTMSN=0
2019-05-15T02:07:37.379Z,1557886057.379 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-05-15T02:07:55.155Z,1557886075.155 [NAL9602](INFO): SBD MO Status=0, MOMSN=12110, MT Status=0, MTMSN=0
2019-05-15T02:07:55.155Z,1557886075.155 [NAL9602](INFO): No messages in MT queue
2019-05-15T02:07:55.985Z,1557886075.985 [NAL9602](DEBUG): Fix Requested
2019-05-15T02:07:58.401Z,1557886078.401 [NAL9602](DEBUG): Fix Requested
2019-05-15T02:08:01.629Z,1557886081.629 [NAL9602](DEBUG): Fix Requested
2019-05-15T02:08:04.457Z,1557886084.457 [NAL9602](DEBUG): Fix Requested
2019-05-15T02:08:07.297Z,1557886087.297 [NAL9602](DEBUG): Fix Requested
2019-05-15T02:08:10.521Z,1557886090.521 [NAL9602](DEBUG): Fix Requested
2019-05-15T02:08:13.349Z,1557886093.349 [NAL9602](DEBUG): Fix Requested
2019-05-15T02:08:16.585Z,1557886096.585 [NAL9602](DEBUG): Fix Requested
2019-05-15T02:08:19.405Z,1557886099.405 [NAL9602](DEBUG): Fix Requested
2019-05-15T02:08:22.637Z,1557886102.637 [NAL9602](DEBUG): Fix Requested
2019-05-15T02:08:25.465Z,1557886105.465 [NAL9602](DEBUG): Fix Requested