2020-01-23T19:25:04.172Z,1579807504.172 [Supervisor](DEBUG): Initializing supervisor.
2020-01-23T19:25:04.175Z,1579807504.175 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2020-01-23T19:25:04.176Z,1579807504.176 [SyncHandler](INFO): Protected caller Thread ID is 7915
2020-01-23T19:25:04.177Z,1579807504.177 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2020-01-23T19:25:04.178Z,1579807504.178 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2020-01-23T19:25:04.178Z,1579807504.178 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 7916
2020-01-23T19:25:04.181Z,1579807504.181 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2020-01-23T19:25:04.193Z,1579807504.193 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2020-01-23T19:25:04.194Z,1579807504.194 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2020-01-23T19:25:04.194Z,1579807504.194 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 7917
2020-01-23T19:25:04.195Z,1579807504.195 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2020-01-23T19:25:04.196Z,1579807504.196 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2020-01-23T19:25:04.196Z,1579807504.196 [logger ThreadHandler](INFO): Protected caller Thread ID is 7918
2020-01-23T19:25:04.198Z,1579807504.198 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2020-01-23T19:25:04.199Z,1579807504.199 [Supervisor](INFO): Looking for Config files in directory: Config/
2020-01-23T19:25:04.200Z,1579807504.200 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2020-01-23T19:25:04.636Z,1579807504.636 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2020-01-23T19:25:04.636Z,1579807504.636 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2020-01-23T19:25:04.734Z,1579807504.734 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2020-01-23T19:25:04.734Z,1579807504.734 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2020-01-23T19:25:05.046Z,1579807505.046 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2020-01-23T19:25:05.047Z,1579807505.047 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2020-01-23T19:25:05.184Z,1579807505.184 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2020-01-23T19:25:05.185Z,1579807505.185 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2020-01-23T19:25:05.375Z,1579807505.375 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2020-01-23T19:25:05.375Z,1579807505.375 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2020-01-23T19:25:05.821Z,1579807505.821 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2020-01-23T19:25:05.821Z,1579807505.821 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2020-01-23T19:25:06.029Z,1579807506.029 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2020-01-23T19:25:06.029Z,1579807506.029 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2020-01-23T19:25:06.172Z,1579807506.172 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2020-01-23T19:25:06.172Z,1579807506.172 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2020-01-23T19:25:06.361Z,1579807506.361 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2020-01-23T19:25:06.361Z,1579807506.361 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2020-01-23T19:25:06.456Z,1579807506.456 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2020-01-23T19:25:06.457Z,1579807506.457 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2020-01-23T19:25:06.753Z,1579807506.753 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2020-01-23T19:25:06.753Z,1579807506.753 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2020-01-23T19:25:06.833Z,1579807506.833 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2020-01-23T19:25:06.935Z,1579807506.935 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2020-01-23T19:25:06.935Z,1579807506.935 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2020-01-23T19:25:08.076Z,1579807508.076 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2020-01-23T19:25:08.077Z,1579807508.077 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2020-01-23T19:25:08.483Z,1579807508.483 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2020-01-23T19:25:08.484Z,1579807508.484 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/
2020-01-23T19:25:08.485Z,1579807508.485 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/vehicle.cfg
2020-01-23T19:25:08.695Z,1579807508.695 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Control.cfg
2020-01-23T19:25:08.794Z,1579807508.794 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/BIT.cfg
2020-01-23T19:25:08.893Z,1579807508.893 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Battery.cfg
2020-01-23T19:25:09.121Z,1579807509.121 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2020-01-23T19:25:09.121Z,1579807509.121 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Simulator.cfg
2020-01-23T19:25:09.205Z,1579807509.205 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Navigation.cfg
2020-01-23T19:25:09.298Z,1579807509.298 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/logger.cfg
2020-01-23T19:25:09.394Z,1579807509.394 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/secure.cfg
2020-01-23T19:25:09.476Z,1579807509.476 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Servo.cfg
2020-01-23T19:25:09.583Z,1579807509.583 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/workSite.cfg
2020-01-23T19:25:09.675Z,1579807509.675 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Sensor.cfg
2020-01-23T19:25:09.856Z,1579807509.856 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Science.cfg
2020-01-23T19:25:09.985Z,1579807509.985 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/root/
2020-01-23T19:25:09.985Z,1579807509.985 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2020-01-23T19:25:09.992Z,1579807509.992 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2020-01-23T19:25:10.312Z,1579807510.312 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_orientation
2020-01-23T19:25:10.317Z,1579807510.317 [AHRS_M2](INFO): created writer for : platform_orientation
2020-01-23T19:25:10.319Z,1579807510.319 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_magnetic_orientation
2020-01-23T19:25:10.324Z,1579807510.324 [AHRS_M2](INFO): created writer for : platform_magnetic_orientation
2020-01-23T19:25:10.325Z,1579807510.325 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_pitch_angle
2020-01-23T19:25:10.330Z,1579807510.330 [AHRS_M2](INFO): created writer for : platform_pitch_angle
2020-01-23T19:25:10.330Z,1579807510.330 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_roll_angle
2020-01-23T19:25:10.336Z,1579807510.336 [AHRS_M2](INFO): created writer for : platform_roll_angle
2020-01-23T19:25:10.405Z,1579807510.405 [AHRS_M2] Loaded
2020-01-23T19:25:10.406Z,1579807510.406 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2020-01-23T19:25:10.484Z,1579807510.484 [DataOverHttps] Loaded
2020-01-23T19:25:10.485Z,1579807510.485 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2020-01-23T19:25:10.486Z,1579807510.486 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 407684E0
2020-01-23T19:25:10.486Z,1579807510.486 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 8000
2020-01-23T19:25:10.510Z,1579807510.510 [DDM] Loaded
2020-01-23T19:25:10.510Z,1579807510.510 [ComponentRegistry](DEBUG): SyncComponent "DDM" handled in the control thread.
2020-01-23T19:25:10.523Z,1579807510.523 [Depth_Keller] Loaded
2020-01-23T19:25:10.523Z,1579807510.523 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2020-01-23T19:25:10.528Z,1579807510.528 [DropWeight] Loaded
2020-01-23T19:25:10.528Z,1579807510.528 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2020-01-23T19:25:10.589Z,1579807510.589 [DUSBL_Hydroid] Loaded
2020-01-23T19:25:10.589Z,1579807510.589 [ComponentRegistry](DEBUG): SyncComponent "DUSBL_Hydroid" handled in the control thread.
2020-01-23T19:25:10.635Z,1579807510.635 [Micromodem] Loaded
2020-01-23T19:25:10.635Z,1579807510.635 [ComponentRegistry](DEBUG): SyncComponent "Micromodem" handled in the control thread.
2020-01-23T19:25:10.732Z,1579807510.732 [NAL9602] Loaded
2020-01-23T19:25:10.732Z,1579807510.732 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2020-01-23T19:25:10.772Z,1579807510.772 [Onboard] Loaded
2020-01-23T19:25:10.772Z,1579807510.772 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2020-01-23T19:25:10.778Z,1579807510.778 [PowerOnly] Loaded
2020-01-23T19:25:10.778Z,1579807510.778 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread.
2020-01-23T19:25:10.784Z,1579807510.784 [Radio_Surface] Loaded
2020-01-23T19:25:10.785Z,1579807510.785 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2020-01-23T19:25:10.786Z,1579807510.786 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 407984E0
2020-01-23T19:25:10.786Z,1579807510.786 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 8001
2020-01-23T19:25:10.829Z,1579807510.829 [RDI_Pathfinder] Loaded
2020-01-23T19:25:10.829Z,1579807510.829 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2020-01-23T19:25:12.314Z,1579807512.314 [BPC1] Loaded
2020-01-23T19:25:12.314Z,1579807512.314 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2020-01-23T19:25:12.314Z,1579807512.314 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2020-01-23T19:25:12.315Z,1579807512.315 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2020-01-23T19:25:12.328Z,1579807512.328 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2020-01-23T19:25:12.328Z,1579807512.328 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2020-01-23T19:25:12.445Z,1579807512.445 [DeadReckonUsingMultipleVelocitySources] Loaded
2020-01-23T19:25:12.446Z,1579807512.446 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2020-01-23T19:25:12.466Z,1579807512.466 [NavChart] Loaded
2020-01-23T19:25:12.466Z,1579807512.466 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2020-01-23T19:25:12.470Z,1579807512.470 [UniversalFixResidualReporter] Loaded
2020-01-23T19:25:12.470Z,1579807512.470 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2020-01-23T19:25:12.470Z,1579807512.470 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2020-01-23T19:25:12.471Z,1579807512.471 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2020-01-23T19:25:12.581Z,1579807512.581 [BuoyancyServo] Loaded
2020-01-23T19:25:12.582Z,1579807512.582 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2020-01-23T19:25:12.596Z,1579807512.596 [ElevatorServo] Loaded
2020-01-23T19:25:12.596Z,1579807512.596 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2020-01-23T19:25:12.611Z,1579807512.611 [MassServo] Loaded
2020-01-23T19:25:12.611Z,1579807512.611 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2020-01-23T19:25:12.626Z,1579807512.626 [RudderServo] Loaded
2020-01-23T19:25:12.626Z,1579807512.626 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2020-01-23T19:25:12.640Z,1579807512.640 [ThrusterServo] Loaded
2020-01-23T19:25:12.640Z,1579807512.640 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2020-01-23T19:25:12.641Z,1579807512.641 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2020-01-23T19:25:12.641Z,1579807512.641 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2020-01-23T19:25:12.905Z,1579807512.905 [CTD_NeilBrown] Loaded
2020-01-23T19:25:12.905Z,1579807512.905 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2020-01-23T19:25:12.906Z,1579807512.906 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 408EC4E0
2020-01-23T19:25:12.907Z,1579807512.907 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 8002
2020-01-23T19:25:12.921Z,1579807512.921 [PAR_Licor] Loaded
2020-01-23T19:25:12.921Z,1579807512.921 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2020-01-23T19:25:12.964Z,1579807512.964 [WetLabsSeaOWL_UV_A] Loaded
2020-01-23T19:25:12.964Z,1579807512.964 [ComponentRegistry](DEBUG): Component "WetLabsSeaOWL_UV_A" handled in its own thread.
2020-01-23T19:25:12.965Z,1579807512.965 [WetLabsSeaOWL_UV_A ThreadHandler](DEBUG): Created PCaller Thread at 4091C4E0
2020-01-23T19:25:12.966Z,1579807512.966 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Protected caller Thread ID is 8003
2020-01-23T19:25:12.966Z,1579807512.966 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2020-01-23T19:25:12.967Z,1579807512.967 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2020-01-23T19:25:13.341Z,1579807513.341 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2020-01-23T19:25:13.342Z,1579807513.342 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2020-01-23T19:25:13.524Z,1579807513.524 [DepthRateCalculator] Loaded
2020-01-23T19:25:13.524Z,1579807513.524 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2020-01-23T19:25:13.565Z,1579807513.565 [PitchRateCalculator] Loaded
2020-01-23T19:25:13.565Z,1579807513.565 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2020-01-23T19:25:13.586Z,1579807513.586 [SpeedCalculator] Loaded
2020-01-23T19:25:13.586Z,1579807513.586 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2020-01-23T19:25:13.627Z,1579807513.627 [TempGradientCalculator] Loaded
2020-01-23T19:25:13.627Z,1579807513.627 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2020-01-23T19:25:13.660Z,1579807513.660 [YawRateCalculator] Loaded
2020-01-23T19:25:13.660Z,1579807513.660 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2020-01-23T19:25:13.945Z,1579807513.945 [ElevatorOffsetCalculator] Loaded
2020-01-23T19:25:13.945Z,1579807513.945 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2020-01-23T19:25:13.946Z,1579807513.946 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2020-01-23T19:25:13.946Z,1579807513.946 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2020-01-23T19:25:14.147Z,1579807514.147 [SBIT](DEBUG): Construct Startup Built In Test.
2020-01-23T19:25:14.197Z,1579807514.197 [SBIT] Loaded
2020-01-23T19:25:14.197Z,1579807514.197 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2020-01-23T19:25:14.198Z,1579807514.198 [IBIT](DEBUG): Construct Initiated Built In Test.
2020-01-23T19:25:14.219Z,1579807514.219 [IBIT] Loaded
2020-01-23T19:25:14.220Z,1579807514.220 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2020-01-23T19:25:14.224Z,1579807514.224 [CBIT](DEBUG): Construct Continuous Built In Test.
2020-01-23T19:25:14.359Z,1579807514.359 [CBIT] Loaded
2020-01-23T19:25:14.359Z,1579807514.359 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2020-01-23T19:25:14.359Z,1579807514.359 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2020-01-23T19:25:14.360Z,1579807514.360 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2020-01-23T19:25:14.444Z,1579807514.444 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2020-01-23T19:25:14.445Z,1579807514.445 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2020-01-23T19:25:14.547Z,1579807514.547 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2020-01-23T19:25:14.548Z,1579807514.548 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2020-01-23T19:25:14.598Z,1579807514.598 [VerticalControl](DEBUG): Construct VerticalControl.
2020-01-23T19:25:14.679Z,1579807514.679 [VerticalControl] Loaded
2020-01-23T19:25:14.680Z,1579807514.680 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2020-01-23T19:25:14.680Z,1579807514.680 [HorizontalControl](DEBUG): Construct HorizontalControl.
2020-01-23T19:25:14.748Z,1579807514.748 [HorizontalControl] Loaded
2020-01-23T19:25:14.748Z,1579807514.748 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2020-01-23T19:25:14.749Z,1579807514.749 [SpeedControl](DEBUG): Construct SpeedControl.
2020-01-23T19:25:14.750Z,1579807514.750 [SpeedControl] Loaded
2020-01-23T19:25:14.750Z,1579807514.750 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2020-01-23T19:25:14.751Z,1579807514.751 [LoopControl](DEBUG): Construct LoopControl.
2020-01-23T19:25:14.751Z,1579807514.751 [LoopControl] Loaded
2020-01-23T19:25:14.752Z,1579807514.752 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2020-01-23T19:25:14.752Z,1579807514.752 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2020-01-23T19:25:14.753Z,1579807514.753 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2020-01-23T19:25:14.786Z,1579807514.786 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2020-01-23T19:25:14.789Z,1579807514.789 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2020-01-23T19:25:14.790Z,1579807514.790 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2020-01-23T19:25:14.796Z,1579807514.796 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2020-01-23T19:25:14.797Z,1579807514.797 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40AFC4E0
2020-01-23T19:25:14.798Z,1579807514.798 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 8004
2020-01-23T19:25:14.802Z,1579807514.802 [Supervisor](INFO): Main Thread ID is 6574
2020-01-23T19:25:14.802Z,1579807514.802 [Supervisor](DEBUG): Running supervisor.
2020-01-23T19:25:14.803Z,1579807514.803 [CommandLine ThreadHandler](INFO): Handler Thread ID is 8005
2020-01-23T19:25:14.805Z,1579807514.805 [controlThread ThreadHandler](INFO): Handler Thread ID is 8006
2020-01-23T19:25:14.806Z,1579807514.806 [controlThread](DEBUG): Initializing ControlThread
2020-01-23T19:25:14.813Z,1579807514.813 [NavChart](DEBUG): Initialize NavChart Navigation.
2020-01-23T19:25:14.813Z,1579807514.813 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2020-01-23T19:25:14.817Z,1579807514.817 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2020-01-23T19:25:14.818Z,1579807514.818 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2020-01-23T19:25:14.818Z,1579807514.818 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2020-01-23T19:25:14.818Z,1579807514.818 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2020-01-23T19:25:14.819Z,1579807514.819 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2020-01-23T19:25:14.819Z,1579807514.819 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2020-01-23T19:25:14.820Z,1579807514.820 [SBIT](INFO): Initialize SBIT Component.
2020-01-23T19:25:14.820Z,1579807514.820 [SBIT](IMPORTANT): git: 2019-12-03-66-g3ff2a14
2020-01-23T19:25:14.820Z,1579807514.820 [SBIT](INFO): git hash: 3ff2a141e314d0ff24dfcdecba8589fc2363d401
2020-01-23T19:25:14.821Z,1579807514.821 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2020-01-23T19:25:14.822Z,1579807514.822 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #1 PREEMPT Wed Nov 13 12:38:10 PST 2019
2020-01-23T19:25:14.823Z,1579807514.823 [SBIT](INFO): Beginning SBIT in 39.000000 seconds.
2020-01-23T19:25:14.824Z,1579807514.824 [IBIT](INFO): Initialize IBIT Component.
2020-01-23T19:25:14.824Z,1579807514.824 [CBIT](DEBUG): Initialize CBIT Component.
2020-01-23T19:25:14.825Z,1579807514.825 [logger ThreadHandler](INFO): Handler Thread ID is 8007
2020-01-23T19:25:14.837Z,1579807514.837 [CBIT](DEBUG): Initialized mux pins.
2020-01-23T19:25:14.837Z,1579807514.837 [CBIT](DEBUG): Initializing the watchdog timer.
2020-01-23T19:25:14.845Z,1579807514.845 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 8008
2020-01-23T19:25:14.846Z,1579807514.846 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2020-01-23T19:25:14.857Z,1579807514.857 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 8009
2020-01-23T19:25:14.861Z,1579807514.861 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2020-01-23T19:25:14.861Z,1579807514.861 [CBIT](DEBUG): Initializing heartbeat.
2020-01-23T19:25:14.869Z,1579807514.869 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 8010
2020-01-23T19:25:14.870Z,1579807514.870 [CTD_NeilBrown](INFO): Powering down
2020-01-23T19:25:14.897Z,1579807514.897 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Handler Thread ID is 8011
2020-01-23T19:25:14.898Z,1579807514.898 [WetLabsSeaOWL_UV_A](INFO): Powering down
2020-01-23T19:25:14.921Z,1579807514.921 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 8012
2020-01-23T19:25:14.924Z,1579807514.924 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2020-01-23T19:25:14.924Z,1579807514.924 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2020-01-23T19:25:14.924Z,1579807514.924 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2020-01-23T19:25:14.925Z,1579807514.925 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2020-01-23T19:25:14.925Z,1579807514.925 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2020-01-23T19:25:14.925Z,1579807514.925 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2020-01-23T19:25:14.925Z,1579807514.925 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2020-01-23T19:25:14.925Z,1579807514.925 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2020-01-23T19:25:14.926Z,1579807514.926 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2020-01-23T19:25:14.926Z,1579807514.926 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2020-01-23T19:25:14.926Z,1579807514.926 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2020-01-23T19:25:14.926Z,1579807514.926 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2020-01-23T19:25:14.926Z,1579807514.926 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2020-01-23T19:25:14.926Z,1579807514.926 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2020-01-23T19:25:14.927Z,1579807514.927 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2020-01-23T19:25:14.927Z,1579807514.927 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2020-01-23T19:25:14.933Z,1579807514.933 [CBIT](DEBUG): Deactivating GF circuits.
2020-01-23T19:25:14.933Z,1579807514.933 [CBIT](DEBUG): Deactivating emergency mode.
2020-01-23T19:25:14.969Z,1579807514.969 [CBIT](DEBUG): Backplane powered.
2020-01-23T19:25:14.969Z,1579807514.969 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2020-01-23T19:25:14.971Z,1579807514.971 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2020-01-23T19:25:14.972Z,1579807514.972 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2020-01-23T19:25:14.972Z,1579807514.972 [LoopControl](DEBUG): Initialize LoopControlComponent.
2020-01-23T19:25:14.973Z,1579807514.973 [MissionManager](INFO): Loading Mission: Missions/underIce/StartupUnder.xml
2020-01-23T19:25:14.978Z,1579807514.978 [MissionManager](ERROR): Top node has no child nodes: Mission
2020-01-23T19:25:14.979Z,1579807514.979 [MissionManager](ERROR): Could not load startup mission.
2020-01-23T19:25:14.979Z,1579807514.979 [MissionManager](INFO): Loading Mission: Missions/underIce/DefaultUnder.xml
2020-01-23T19:25:15.216Z,1579807515.216 [MissionManager](INFO): DefineArg DefaultUnder.uModemCommsInterval = 5.000000 min
2020-01-23T19:25:15.219Z,1579807515.219 [MissionManager](INFO): DefineArg DefaultUnder.TransponderCode = 2.000000 count
2020-01-23T19:25:15.233Z,1579807515.233 [MissionManager](INFO): DefineArg DefaultUnder.AcousticUpdatePeriod = 60.000000 s
2020-01-23T19:25:15.250Z,1579807515.250 [MissionManager](INFO): DefineArg DefaultUnder.DockingAcousticUpdatePeriod = 2.500000 s
2020-01-23T19:25:15.261Z,1579807515.261 [Radio_Surface](INFO): Powering up
2020-01-23T19:25:15.278Z,1579807515.278 [MissionManager](INFO): DefineArg DefaultUnder.NumberOfPings = 1.000000 count
2020-01-23T19:25:15.281Z,1579807515.281 [MissionManager](INFO): DefineOutput DefaultUnder.TrackingUpdatePeriod = 60.000000 n/a
2020-01-23T19:25:15.313Z,1579807515.313 [MissionManager](INFO): DefineOutput DefaultUnder.Surface = -1.000000 count
2020-01-23T19:25:15.316Z,1579807515.316 [MissionManager](INFO): DefineOutput DefaultUnder.Docked = 0.000000 count
2020-01-23T19:25:15.324Z,1579807515.324 [MissionManager](INFO): DefineOutput DefaultUnder.Home = 1.000000 count
2020-01-23T19:25:15.328Z,1579807515.328 [MissionManager](INFO): DefineOutput DefaultUnder.DefaultMode = 0.000000 n/a
2020-01-23T19:25:15.351Z,1579807515.351 [MissionManager](INFO): DefineOutput DefaultUnder.CaptureMode = -1.000000 count
2020-01-23T19:25:15.354Z,1579807515.354 [MissionManager](INFO): DefineOutput DefaultUnder.ElapsedSinceDefaultStarted = 0.000000 min
2020-01-23T19:25:15.385Z,1579807515.385 [DefaultUnder:Notify:A:A:A.Wait](DEBUG): Construct Wait.
2020-01-23T19:25:15.407Z,1579807515.407 [DefaultUnder:Notify:A:C.Execute](DEBUG): Construct Execute.
2020-01-23T19:25:15.638Z,1579807515.638 [MissionManager](INFO): Inserting Stack: Missions/Insert/LineCapture.xml
2020-01-23T19:25:16.133Z,1579807516.133 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.DockDepth = 6.000000 _
2020-01-23T19:25:16.153Z,1579807516.153 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.DockLat = 0.642341 _
2020-01-23T19:25:16.156Z,1579807516.156 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.DockLon = -2.126200 _
2020-01-23T19:25:16.160Z,1579807516.160 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.DetachRange = 8.000000 m
2020-01-23T19:25:16.187Z,1579807516.187 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.DetachTimeout = 30.000000 min
2020-01-23T19:25:16.190Z,1579807516.190 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.MidcourseDepth = 15.000000 m
2020-01-23T19:25:16.205Z,1579807516.205 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.MidcourseSpeed = 1.000000 m/s
2020-01-23T19:25:16.208Z,1579807516.208 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.MidcourseTimeout = 12.000000 h
2020-01-23T19:25:16.212Z,1579807516.212 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.TerminalRange = 650.000000 m
2020-01-23T19:25:16.231Z,1579807516.231 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.ArmRange = 40.000000 m
2020-01-23T19:25:16.234Z,1579807516.234 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.DockRange = 2.000000 m
2020-01-23T19:25:16.262Z,1579807516.262 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.DockTimeout = 60.000000 s
2020-01-23T19:25:16.281Z,1579807516.281 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.RolloutDistance = 250.000000 m
2020-01-23T19:25:16.284Z,1579807516.284 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.UpdateNav = 1 bool
2020-01-23T19:25:16.287Z,1579807516.287 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.AcousticTimeout = 10.000000 min
2020-01-23T19:25:16.299Z,1579807516.299 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.TerminalSpeed = 0.800000 m/s
2020-01-23T19:25:16.303Z,1579807516.303 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.SearchTimeout = 60.000000 min
2020-01-23T19:25:16.330Z,1579807516.330 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.CircleRadius = 300.000000 m
2020-01-23T19:25:16.333Z,1579807516.333 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.CircleMaxError = 100.000000 m
2020-01-23T19:25:16.336Z,1579807516.336 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.CircleTurnToPort = 0 bool
2020-01-23T19:25:16.356Z,1579807516.356 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.DepthDeadband = 0.010000 m
2020-01-23T19:25:16.359Z,1579807516.359 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.RudderDeadband = 0.001000 arcdeg
2020-01-23T19:25:16.374Z,1579807516.374 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.MinAltitude = 5.000000 m
2020-01-23T19:25:16.378Z,1579807516.378 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.MaxDepth = 205.000000 m
2020-01-23T19:25:16.405Z,1579807516.405 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.MinOffshore = 500.000000 m
2020-01-23T19:25:16.408Z,1579807516.408 [MissionManager](INFO): DefineOutput DefaultUnder:LineCapture.Depth = 15.000000 n/a
2020-01-23T19:25:16.412Z,1579807516.412 [MissionManager](INFO): DefineOutput DefaultUnder:LineCapture.Speed = 1.000000 n/a
2020-01-23T19:25:16.427Z,1579807516.427 [MissionManager](INFO): DefineOutput DefaultUnder:LineCapture.DoneTimeout = -1.000000 count
2020-01-23T19:25:16.431Z,1579807516.431 [MissionManager](INFO): DefineOutput DefaultUnder:LineCapture.Done = 0.000000 count
2020-01-23T19:25:16.462Z,1579807516.462 [MissionManager](INFO): DefineOutput DefaultUnder:LineCapture.DetachFromDock = 1.000000 count
2020-01-23T19:25:16.465Z,1579807516.465 [MissionManager](INFO): DefineOutput DefaultUnder:LineCapture.Midcourse = 2.000000 count
2020-01-23T19:25:16.481Z,1579807516.481 [MissionManager](INFO): DefineOutput DefaultUnder:LineCapture.Terminal = 3.000000 count
2020-01-23T19:25:16.484Z,1579807516.484 [MissionManager](INFO): DefineOutput DefaultUnder:LineCapture.GuidanceMode = 1.000000 n/a
2020-01-23T19:25:16.487Z,1579807516.487 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.ElapsedRange = 0.000000 min
2020-01-23T19:25:16.515Z,1579807516.515 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture.Range = nan m
2020-01-23T19:25:16.517Z,1579807516.517 [MissionManager](INFO): Inserting Stack: Missions/Insert/StandardEnvelopes.xml
2020-01-23T19:25:16.558Z,1579807516.558 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture:StandardEnvelopes.MinAltitude = 5.000000 m
2020-01-23T19:25:16.578Z,1579807516.578 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture:StandardEnvelopes.MaxDepth = 200.000000 m
2020-01-23T19:25:16.581Z,1579807516.581 [MissionManager](INFO): DefineArg DefaultUnder:LineCapture:StandardEnvelopes.MinOffshore = 2000.000000 m
2020-01-23T19:25:16.582Z,1579807516.582 [DefaultUnder:LineCapture:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope.
2020-01-23T19:25:16.617Z,1579807516.617 [DefaultUnder:LineCapture:StandardEnvelopes:B.DepthEnvelope](DEBUG): Construct DepthEnvelope.
2020-01-23T19:25:16.641Z,1579807516.641 [DefaultUnder:LineCapture:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Construct OffshoreEnvelope.
2020-01-23T19:25:16.672Z,1579807516.672 [DefaultUnder:LineCapture:H.Mass](DEBUG): Construct.
2020-01-23T19:25:16.700Z,1579807516.700 [DefaultUnder:LineCapture:DiveCmd:Guided:dive:B.Buoyancy](DEBUG): Construct Buoyancy.
2020-01-23T19:25:16.723Z,1579807516.723 [DefaultUnder:LineCapture:DiveCmd:Guided:dive:C.SetSpeed](DEBUG): Construct.
2020-01-23T19:25:16.726Z,1579807516.726 [DefaultUnder:LineCapture:DiveCmd:Guided:dive:D.Pitch](DEBUG): Construct.
2020-01-23T19:25:16.745Z,1579807516.745 [DefaultUnder:LineCapture:DiveCmd:DriftAwayFromDock:dive:A.SetSpeed](DEBUG): Construct.
2020-01-23T19:25:16.748Z,1579807516.748 [DefaultUnder:LineCapture:DiveCmd:DriftAwayFromDock:dive:B.Pitch](DEBUG): Construct.
2020-01-23T19:25:16.799Z,1579807516.799 [DefaultUnder:LineCapture:HomingSequence:DetachFromDock:guide:A.Undock](DEBUG): Construct.
2020-01-23T19:25:16.847Z,1579807516.847 [DefaultUnder:LineCapture:HomingSequence:MidcourseGuidance:guide:E.Waypoint](DEBUG): Construct Waypoint.
2020-01-23T19:25:16.884Z,1579807516.884 [DefaultUnder:LineCapture:HomingSequence:MidcourseGuidance:guide:G.Circle](DEBUG): Construct.
2020-01-23T19:25:16.967Z,1579807516.967 [DefaultUnder:LineCapture:HomingSequence:TerminalGuidance:guide:UpdateNav:B.SetNav](DEBUG): Construct SetNav.
2020-01-23T19:25:16.986Z,1579807516.986 [DefaultUnder:LineCapture:HomingSequence:TerminalGuidance:guide:H.LineCapture](DEBUG): Construct.
2020-01-23T19:25:17.016Z,1579807517.016 [DefaultUnder:LineCapture:K.Wait](DEBUG): Construct Wait.
2020-01-23T19:25:17.019Z,1579807517.019 [DefaultUnder:E.Wait](DEBUG): Construct Wait.
2020-01-23T19:25:17.041Z,1579807517.041 [DefaultUnder:Default:Docked:run:B.Docked](DEBUG): Construct.
2020-01-23T19:25:17.119Z,1579807517.119 [DefaultUnder:Default:Surface:run:B.GoToSurface](DEBUG): Construct GoToSurface.
2020-01-23T19:25:17.166Z,1579807517.166 [DefaultUnder:Default:Surface:run:SurfaceComms:Read_Iridium_uModem:A_Timeout:A.Execute](DEBUG): Construct Execute.
2020-01-23T19:25:17.168Z,1579807517.168 [DefaultUnder:Default:Surface:run:SurfaceComms:C.Wait](DEBUG): Construct Wait.
2020-01-23T19:25:17.220Z,1579807517.220 [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="DefaultUnder">


    <DefineArg Name="uModemCommsInterval"><Description>
        How often to trigger uModem communications
    </Description><Units:minute/><Value>5</Value></DefineArg>

    <DefineArg Name="TransponderCode"><Description>
        Dock transponder Address.
    </Description><Units:count/><Value>2</Value></DefineArg>

    <DefineArg Name="AcousticUpdatePeriod"><Description>
        How long to wait between acoustic queries while the mission
        is in an idle state (on the dock or surface).
    </Description><Units:second/><Value>60</Value></DefineArg>

    <DefineArg Name="DockingAcousticUpdatePeriod"><Description>
        How long to wait between acoustic queries while the mission
        is actively docking (line capture)
    </Description><Units:second/><Value>2.5</Value></DefineArg>

    <DefineArg Name="NumberOfPings"><Description>
        Number of pings requested each time.
    </Description><Units:count/><Value>1</Value></DefineArg>

    <!-- Mission Variables (don't change!) -->

    <DefineOutput Name="TrackingUpdatePeriod"><Description>
        How long to wait between acoustic queries.
    </Description><Arg Name="AcousticUpdatePeriod"/></DefineOutput>

    <DefineOutput Name="Surface"><Description>
        Mission variable (don't change).
        The mission will run in this mode to go to the surface after homing attempts have failed.
    </Description><Units:count/><Value>-1</Value></DefineOutput>

    <DefineOutput Name="Docked"><Description>
        Mission variable (don't change).
        The mission will run in this mode when the vehicle is docked.
    </Description><Units:count/><Value>0</Value></DefineOutput>

    <DefineOutput Name="Home"><Description>
        Mission variable (don't change).
        The mission will run in this mode when homing to the dock.
    </Description><Units:count/><Value>1</Value></DefineOutput>

    <DefineOutput Name="DefaultMode"><Description>
        Mission variable (don't change).
        The mission sets this variable to switch between default modes.
    </Description><Arg Name="Docked"/></DefineOutput>

    <DefineOutput Name="CaptureMode"><Description>
        Mission variable (don't change).
        The mission sets this variable to reflect the termination status of the LineCapture insert.
    </Description><Units:count/><Value>-1</Value></DefineOutput>

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

    <!-- TODO: Safety nets and surfacing behaviors? -->

    <!-- Communication directives -->

    <Aggregate Id="uModemComms">
        <While>
            <Arg Name="DefaultMode"/><Eq><Arg Name="Docked"/></Eq>
        </While>

        <Aggregate Id="CheckIn">

            <When>
                <Elapsed><Universal:platform_communications/></Elapsed>
                <Gt><Arg Name="uModemCommsInterval"/></Gt>
            </When>

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

        </Aggregate>
    </Aggregate>

    <!-- Notify directives. -->

    <Aggregate Id="Notify">
        <Parallel/>

        <Aggregate>
            <Sequence/>

            <Aggregate>
                <Sequence Repeat="288"/>

                <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.</Syslog>

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

   <!-- Add track acoustic contact directives. -->

    <Estimation:TrackAcousticContact>
        <Parallel/>
        <Setting><Estimation:TrackAcousticContact.contactLabelSetting/><Arg Name="TransponderCode"/></Setting>
        <Setting><Estimation:TrackAcousticContact.numberOfSamplesSetting/><Arg Name="NumberOfPings"/></Setting>
        <Setting><Estimation:TrackAcousticContact.updatePeriodSetting/><Arg Name="TrackingUpdatePeriod"/></Setting>
    </Estimation:TrackAcousticContact>

    <!-- Add LineCapture directives. -->

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

    <!-- Default mission sequence. -->

    <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>

    <Aggregate Id="Default">

        <Sequence/>

        <Aggregate Id="Docked">

            <While>
                <Arg Name="DefaultMode"/><Eq><Arg Name="Docked"/></Eq>
            </While>

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

                <Assign><Sequence/><Arg Name="TrackingUpdatePeriod"/><Arg Name="AcousticUpdatePeriod"/></Assign>

                <Guidance:Docked>
                    <Sequence/>
                </Guidance:Docked>

                <Assign><Sequence/><Arg Name="DefaultMode"/><Arg Name="Home"/></Assign>

            </Aggregate>
        </Aggregate>


        <Aggregate Id="Home">

            <While>
                <Arg Name="DefaultMode"/><Eq><Arg Name="Home"/></Eq>
            </While>

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

                <Assign><Sequence/><Arg Name="TrackingUpdatePeriod"/><Arg Name="DockingAcousticUpdatePeriod"/></Assign>

                <Assign><Sequence/><Arg Name="CaptureMode"/><Arg Name="Surface"/></Assign>

                <Call RefId="LineCapture"/>

                <Assign><Sequence/><Arg Name="CaptureMode"/><Arg Name="LineCapture:GuidanceMode"/></Assign>

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

                    <Break>
                        <Not><Arg Name="CaptureMode"/><Eq><Arg Name="Docked"/></Eq></Not>
                    </Break>

                    <Assign><Sequence/><Arg Name="DefaultMode"/><Arg Name="Docked"/></Assign>
                </Aggregate>

                <Assign><Sequence/><Arg Name="DefaultMode"/><Arg Name="Surface"/></Assign>

            </Aggregate>
        </Aggregate>


        <Aggregate Id="Surface">

            <While>
                <Arg Name="DefaultMode"/><Eq><Arg Name="Surface"/></Eq>
            </While>

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

                <Assign><Sequence/><Arg Name="TrackingUpdatePeriod"/><Arg Name="AcousticUpdatePeriod"/></Assign>

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

                <Aggregate Id="SurfaceComms">

                    <Sequence Repeat="288"/>

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

                    <ReadDatum Id="Read_Iridium_uModem">
                        <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>

                </Aggregate>
            </Aggregate>

        </Aggregate>

    </Aggregate>

</Mission>


2020-01-23T19:25:17.241Z,1579807517.241 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,DDM,Depth_Keller,DropWeight,DUSBL_Hydroid,Micromodem,NAL9602,Onboard,PowerOnly,RDI_Pathfinder,BPC1,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2020-01-23T19:25:17.257Z,1579807517.257 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2020-01-23T19:25:17.301Z,1579807517.301 [DDM](INFO): Powering up
2020-01-23T19:25:17.301Z,1579807517.301 [DDM](DEBUG): Initializing DDM.
2020-01-23T19:25:17.326Z,1579807517.326 [Depth_Keller](ERROR): Pressure reading out of range: 1913.424561 decibar
2020-01-23T19:25:17.326Z,1579807517.326 [DUSBL_Hydroid](INFO): Powering up
2020-01-23T19:25:17.327Z,1579807517.327 [DUSBL_Hydroid](DEBUG): Initializing DUSBL_Hydroid.
2020-01-23T19:25:17.507Z,1579807517.507 [DepthRateCalculator](ERROR): Depth measurement is not active
2020-01-23T19:25:17.523Z,1579807517.523 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2020-01-23T19:25:17.529Z,1579807517.529 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2020-01-23T19:25:17.530Z,1579807517.530 [ElevatorServo](DEBUG): Initializing EZServoServo.
2020-01-23T19:25:17.537Z,1579807517.537 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2020-01-23T19:25:17.538Z,1579807517.538 [MassServo](DEBUG): Initializing EZServoServo.
2020-01-23T19:25:17.545Z,1579807517.545 [MassServo](DEBUG): Initializing MassServo.
2020-01-23T19:25:17.546Z,1579807517.546 [RudderServo](DEBUG): Initializing EZServoServo.
2020-01-23T19:25:17.553Z,1579807517.553 [RudderServo](DEBUG): Initializing RudderServo.
2020-01-23T19:25:17.554Z,1579807517.554 [ThrusterServo](DEBUG): Initializing EZServoServo.
2020-01-23T19:25:17.561Z,1579807517.561 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2020-01-23T19:25:17.669Z,1579807517.669 [Micromodem](INFO): Powering up
2020-01-23T19:25:17.669Z,1579807517.669 [Micromodem](DEBUG): Initializing Micromodem.
2020-01-23T19:25:17.713Z,1579807517.713 [DepthRateCalculator](ERROR): Depth measurement is not active
2020-01-23T19:25:18.401Z,1579807518.401 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2020-01-23T19:25:18.401Z,1579807518.401 [RudderServo](FAULT): Rudder failed to initialize
2020-01-23T19:25:18.401Z,1579807518.401 [RudderServo] Communications Fault, FailCount= 1
2020-01-23T19:25:18.401Z,1579807518.401 [RudderServo](ERROR): Communications Fault
2020-01-23T19:25:18.512Z,1579807518.512 [CBIT](ERROR): Communications Fault in component: RudderServo
2020-01-23T19:25:18.710Z,1579807518.710 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2020-01-23T19:25:18.710Z,1579807518.710 [RudderServo](INFO): Powering down
2020-01-23T19:25:19.369Z,1579807519.369 [RudderServo](DEBUG): Initializing EZServoServo.
2020-01-23T19:25:19.486Z,1579807519.486 [RudderServo](DEBUG): Initializing RudderServo.
2020-01-23T19:25:19.490Z,1579807519.490 [CBIT](INFO): Clearing failed state for component RudderServo
2020-01-23T19:25:19.490Z,1579807519.490 [RudderServo] No Fault, FailCount= 1
2020-01-23T19:25:22.600Z,1579807522.600 [Micromodem](INFO): Nmea out: $CCCFG,ALL,0*33

2020-01-23T19:25:24.624Z,1579807524.624 [Micromodem](INFO): Nmea in: $CACFG,ALL,0*31

2020-01-23T19:25:24.624Z,1579807524.624 [Micromodem](INFO): Nmea out: $CCCFG,SRC,1*31

2020-01-23T19:25:25.028Z,1579807525.028 [Micromodem](INFO): Nmea in: $CATMG,2020-01-23T19:25:24.506895Z,RTC,RTC*5E

2020-01-23T19:25:25.028Z,1579807525.028 [Micromodem](ERROR): CFG response from modem unexpected: $CATMG,2020-01-23T19:25:24.506895Z,RTC,RTC*5E

2020-01-23T19:25:25.427Z,1579807525.427 [Micromodem](INFO): Nmea in: $CACFG,SRC,1*33

2020-01-23T19:25:25.427Z,1579807525.427 [Micromodem](INFO): Nmea out: $CCCFG,nav.dt.txtrig_gpio4,1*64

2020-01-23T19:25:25.847Z,1579807525.847 [Micromodem](INFO): Nmea in: $CACFG,nav.dt.txtrig_gpio4,1*66

2020-01-23T19:25:25.848Z,1579807525.848 [Micromodem](INFO): Nmea out: $CCCFG,pwramp.txlevel,0*2F

2020-01-23T19:25:26.216Z,1579807526.216 [Micromodem](INFO): Nmea in: $CACFG,pwramp.txlevel,0*2D

2020-01-23T19:25:26.216Z,1579807526.216 [Micromodem](INFO): Nmea out: $CCCFG,DTO,30*1E

2020-01-23T19:25:26.619Z,1579807526.619 [Micromodem](INFO): Nmea in: $CACFG,DTO,30*1C

2020-01-23T19:25:26.619Z,1579807526.619 [Micromodem](INFO): Nmea out: $CCCFG,FC0,10000*46

2020-01-23T19:25:27.016Z,1579807527.016 [Micromodem](INFO): Nmea in: $CACFG,FC0,10000*44

2020-01-23T19:25:27.016Z,1579807527.016 [Micromodem](INFO): Nmea out: $CCCFG,BW0,4000*63

2020-01-23T19:25:27.427Z,1579807527.427 [Micromodem](INFO): Nmea in: $CACFG,BW0,4000*61

2020-01-23T19:25:27.427Z,1579807527.427 [Micromodem](INFO): Nmea out: $CCCFG,BND,0*3A

2020-01-23T19:25:27.830Z,1579807527.830 [DDM](INFO): Dynamic Docking Module:
2020-01-23T19:25:27.947Z,1579807527.947 [Micromodem](INFO): Nmea in: $CACFG,BND,0*38

2020-01-23T19:25:27.948Z,1579807527.948 [Micromodem](INFO): Nmea out: $CCCLK,2020,01,23,19,25,28*41

2020-01-23T19:25:28.234Z,1579807528.234 [Micromodem](INFO): Nmea in: $CACLK,2020,1,23,19,25,28*73

2020-01-23T19:25:28.237Z,1579807528.237 [Micromodem](INFO): Nmea in: $CATMS,0,2020-01-23T19:25:29Z*72

2020-01-23T19:25:28.652Z,1579807528.652 [Micromodem](INFO): Nmea in: $CATMG,2020-01-23T19:25:29.027006Z,USER_CMD,RTC*16

2020-01-23T19:25:30.672Z,1579807530.672 [RDI_Pathfinder](ERROR): Failed to parse:Pathfinder
2020-01-23T19:25:35.494Z,1579807535.494 [DUSBL_Hydroid](INFO): DUSBL Version:O
2020-01-23T19:25:40.747Z,1579807540.747 [NAL9602](INFO): Powering up NAL9602
2020-01-23T19:25:51.655Z,1579807551.655 [NAL9602](INFO): NAL9602 initialized
2020-01-23T19:25:54.171Z,1579807554.171 [SBIT](IMPORTANT): Beginning Startup BIT
2020-01-23T19:25:54.194Z,1579807554.194 [CBIT](IMPORTANT): Beginning ground fault scan
2020-01-23T19:25:59.718Z,1579807559.718 [CommandLine](IMPORTANT): got command get latitude
2020-01-23T19:25:59.718Z,1579807559.718 [CommandLine](FAULT): Element has no value
2020-01-23T19:26:02.755Z,1579807562.755 [CommandLine](IMPORTANT): got command show stack
2020-01-23T19:26:02.755Z,1579807562.755 [CommandLine](IMPORTANT): Behavior Stack:

2020-01-23T19:26:02.756Z,1579807562.756 [DefaultUnder](IMPORTANT): Priority 0: DefaultUnder:C.
2020-01-23T19:26:05.244Z,1579807565.244 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.009340
CHAN A1 (24V): -0.028678
CHAN A2 (12V): -0.006939
CHAN A3 (5V): -0.002189
CHAN B0 (3.3V): 0.000310
CHAN B1 (3.15aV): 0.000198
CHAN B2 (3.15bV): 0.000120
CHAN B3 (GND): 0.002191
OPEN: 0.004965
Full Scale Calc: 4.765 mA, -1.589 mA
2020-01-23T19:26:15.370Z,1579807575.370 [CommandLine](IMPORTANT): got command strobe off
2020-01-23T19:26:15.370Z,1579807575.370 [CommandLine](IMPORTANT): Deactivating strobe
2020-01-23T19:26:23.964Z,1579807583.964 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2020-01-23T19:26:23.964Z,1579807583.964 [RDI_Pathfinder](ERROR): Failed to parse:
:RA,  0.00,   0.00,   0.00,   0.-32768,-32768,-32768,-32768,V
2020-01-23T19:26:47.508Z,1579807607.508 [SBIT](IMPORTANT): SBIT PASSED
2020-01-23T19:26:47.509Z,1579807607.509 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2020-01-23T19:26:47.510Z,1579807607.510 [SBIT](IMPORTANT): DDM.verbosity=3 count;

2020-01-23T19:26:47.510Z,1579807607.510 [SBIT](IMPORTANT): DUSBL_Hydroid.detectionThreshold=30 count;

2020-01-23T19:26:47.510Z,1579807607.510 [SBIT](IMPORTANT): Micromodem.pwrampTXLevel=0 enum;

2020-01-23T19:26:47.510Z,1579807607.510 [SBIT](IMPORTANT): Micromodem.sendExpress=1 bool;

2020-01-23T19:26:47.510Z,1579807607.510 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=105 cubic_centimeter;

2020-01-23T19:26:47.510Z,1579807607.510 [SBIT](IMPORTANT): VerticalControl.massDefault=-5 millimeter;

2020-01-23T19:26:47.925Z,1579807607.925 [MissionManager](IMPORTANT): Started mission DefaultUnder
2020-01-23T19:26:47.925Z,1579807607.925 [DefaultUnder] Running Loop=1
2020-01-23T19:26:47.925Z,1579807607.925 [DefaultUnder](DEBUG): Aggregate::initialize DefaultUnder
2020-01-23T19:26:47.925Z,1579807607.925 [DefaultUnder:uModemComms] Running Loop=1
2020-01-23T19:26:47.925Z,1579807607.925 [DefaultUnder:uModemComms](DEBUG): Aggregate::initialize DefaultUnder:uModemComms
2020-01-23T19:26:47.925Z,1579807607.925 [DefaultUnder:Notify] Running Loop=1
2020-01-23T19:26:47.926Z,1579807607.926 [DefaultUnder:Notify](DEBUG): Aggregate::initialize DefaultUnder:Notify
2020-01-23T19:26:47.926Z,1579807607.926 [DefaultUnder:Notify:A] Running Loop=1
2020-01-23T19:26:47.926Z,1579807607.926 [DefaultUnder:Notify:A](DEBUG): Aggregate::initialize DefaultUnder:Notify:A
2020-01-23T19:26:47.926Z,1579807607.926 [DefaultUnder:Notify:A:A] Running Loop=1
2020-01-23T19:26:47.926Z,1579807607.926 [DefaultUnder:Notify:A:A](DEBUG): Aggregate::initialize DefaultUnder:Notify:A:A
2020-01-23T19:26:47.926Z,1579807607.926 [DefaultUnder:Notify:A:A:A.Wait] Running Loop=1
2020-01-23T19:26:47.926Z,1579807607.926 [DefaultUnder:Notify:A:A:A.Wait](DEBUG): Initialize Wait Component.
2020-01-23T19:26:47.926Z,1579807607.926 [DefaultUnder:C.] Running Loop=1
2020-01-23T19:26:47.926Z,1579807607.926 [DefaultUnder:C.](INFO): Initializing TrackAcousticContact.
2020-01-23T19:26:47.927Z,1579807607.927 [DefaultUnder:E.Wait] Running Loop=1
2020-01-23T19:26:47.927Z,1579807607.927 [DefaultUnder:E.Wait](DEBUG): Initialize Wait Component.
2020-01-23T19:26:47.928Z,1579807607.928 [DefaultUnder:C.] Running Loop=1
2020-01-23T19:26:47.928Z,1579807607.928 [DefaultUnder:Notify] Running Loop=1
2020-01-23T19:26:47.928Z,1579807607.928 [DefaultUnder:uModemComms] Running Loop=1
2020-01-23T19:26:47.933Z,1579807607.933 [DefaultUnder:uModemComms:CheckIn] Running Loop=1
2020-01-23T19:26:47.933Z,1579807607.933 [DefaultUnder:uModemComms:CheckIn](DEBUG): Aggregate::initialize DefaultUnder:uModemComms:CheckIn
2020-01-23T19:26:47.933Z,1579807607.933 [DefaultUnder:uModemComms:CheckIn:A] Running Loop=1
2020-01-23T19:26:47.934Z,1579807607.934 [DefaultUnder:uModemComms:CheckIn:A](DEBUG): Initialize ReadDataComponent to sense platform_communications
2020-01-23T19:27:01.247Z,1579807621.247 [DefaultUnder:E.Wait](INFO): Done Waiting.
2020-01-23T19:27:01.247Z,1579807621.247 [DefaultUnder:E.Wait] Stopped
2020-01-23T19:27:01.247Z,1579807621.247 [DefaultUnder:E.Wait](DEBUG): Uninitialize Wait Component.
2020-01-23T19:27:01.248Z,1579807621.248 [DefaultUnder:Default] Running Loop=1
2020-01-23T19:27:01.248Z,1579807621.248 [DefaultUnder:Default](DEBUG): Aggregate::initialize DefaultUnder:Default
2020-01-23T19:27:01.248Z,1579807621.248 [DefaultUnder:Default:Docked] Running Loop=1
2020-01-23T19:27:01.248Z,1579807621.248 [DefaultUnder:Default:Docked](DEBUG): Aggregate::initialize DefaultUnder:Default:Docked
2020-01-23T19:27:01.248Z,1579807621.248 [DefaultUnder:Default:Docked:run] Running Loop=1
2020-01-23T19:27:01.248Z,1579807621.248 [DefaultUnder:Default:Docked:run](DEBUG): Aggregate::initialize DefaultUnder:Default:Docked:run
2020-01-23T19:27:01.248Z,1579807621.248 [DefaultUnder:Default:Docked:run:A] Running Loop=1
2020-01-23T19:27:01.248Z,1579807621.248 [DefaultUnder:Default:Home] Running Loop=1
2020-01-23T19:27:01.248Z,1579807621.248 [DefaultUnder:Default:Home](DEBUG): Aggregate::initialize DefaultUnder:Default:Home
2020-01-23T19:27:01.248Z,1579807621.248 [DefaultUnder:Default:Home:run] Running Loop=1
2020-01-23T19:27:01.249Z,1579807621.249 [DefaultUnder:Default:Home:run](DEBUG): Aggregate::initialize DefaultUnder:Default:Home:run
2020-01-23T19:27:01.249Z,1579807621.249 [DefaultUnder:Default:Home:run:A] Running Loop=1
2020-01-23T19:27:01.249Z,1579807621.249 [DefaultUnder:Default:Surface] Running Loop=1
2020-01-23T19:27:01.249Z,1579807621.249 [DefaultUnder:Default:Surface](DEBUG): Aggregate::initialize DefaultUnder:Default:Surface
2020-01-23T19:27:01.249Z,1579807621.249 [DefaultUnder:Default:Surface:run] Running Loop=1
2020-01-23T19:27:01.249Z,1579807621.249 [DefaultUnder:Default:Surface:run](DEBUG): Aggregate::initialize DefaultUnder:Default:Surface:run
2020-01-23T19:27:01.249Z,1579807621.249 [DefaultUnder:Default:Surface:run:B.GoToSurface] Running Loop=1
2020-01-23T19:27:01.249Z,1579807621.249 [DefaultUnder:Default:Surface:run:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-01-23T19:27:01.250Z,1579807621.250 [DefaultUnder:Default:Surface:run:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-01-23T19:27:01.250Z,1579807621.250 [DefaultUnder:Default:Surface:run:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-01-23T19:27:01.251Z,1579807621.251 [DefaultUnder:Default:Surface:run:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-01-23T19:27:01.251Z,1579807621.251 [DefaultUnder:Default:Surface:run:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-01-23T19:27:01.251Z,1579807621.251 [DefaultUnder:Default:Surface:run:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-01-23T19:27:01.252Z,1579807621.252 [DefaultUnder:Default:Surface:run:A] Running Loop=1
2020-01-23T19:27:01.657Z,1579807621.657 [DefaultUnder:Default:Surface] Stopped
2020-01-23T19:27:01.657Z,1579807621.657 [DefaultUnder:Default:Surface](DEBUG): Aggregate::uninitialize DefaultUnder:Default:Surface
2020-01-23T19:27:01.657Z,1579807621.657 [DefaultUnder:Default:Surface:run] Stopped
2020-01-23T19:27:01.657Z,1579807621.657 [DefaultUnder:Default:Surface:run](DEBUG): Aggregate::uninitialize DefaultUnder:Default:Surface:run
2020-01-23T19:27:01.657Z,1579807621.657 [DefaultUnder:Default:Surface:run:A] Stopped
2020-01-23T19:27:01.657Z,1579807621.657 [DefaultUnder:Default:Surface:run:B.GoToSurface] Stopped
2020-01-23T19:27:01.657Z,1579807621.657 [DefaultUnder:Default:Surface:run:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2020-01-23T19:27:01.657Z,1579807621.657 [DefaultUnder:Default:Home] Stopped
2020-01-23T19:27:01.657Z,1579807621.657 [DefaultUnder:Default:Home](DEBUG): Aggregate::uninitialize DefaultUnder:Default:Home
2020-01-23T19:27:01.657Z,1579807621.657 [DefaultUnder:Default:Home:run] Stopped
2020-01-23T19:27:01.658Z,1579807621.658 [DefaultUnder:Default:Home:run](DEBUG): Aggregate::uninitialize DefaultUnder:Default:Home:run
2020-01-23T19:27:01.658Z,1579807621.658 [DefaultUnder:Default:Home:run:A] Stopped
2020-01-23T19:27:01.658Z,1579807621.658 [DefaultUnder:Default:Docked] Running Loop=1
2020-01-23T19:27:01.658Z,1579807621.658 [DefaultUnder:Default:Docked:run:A] Stopped
2020-01-23T19:27:01.658Z,1579807621.658 [DefaultUnder:Default:Docked:run:B.Docked] Running Loop=1
2020-01-23T19:27:01.658Z,1579807621.658 [DefaultUnder:Default:Docked:run:B.Docked](DEBUG): Initialize.
2020-01-23T19:27:01.659Z,1579807621.659 [DefaultUnder:Default:Docked:run:B.Docked](INFO): Depth unspecified. Maintaining workSite beacon depth of 6.000000 m.
2020-01-23T19:27:08.121Z,1579807628.121 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2020-01-23T19:27:08.121Z,1579807628.121 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,200123125.0, -0.1,   0.0,1448.9,  0
2020-01-23T19:27:12.003Z,1579807632.003 [CommandLine](IMPORTANT): got command report mod latitude
2020-01-23T19:27:12.250Z,1579807632.250 [Reporter](INFO): latitude no_value
2020-01-23T19:27:18.122Z,1579807638.122 [CommandLine](IMPORTANT): got command run ./Missions/Demo/setNav.xml
2020-01-23T19:27:18.123Z,1579807638.123 [MissionManager](INFO): Loading Mission: ./Missions/Demo/setNav.xml
2020-01-23T19:27:18.158Z,1579807638.158 [MissionManager](INFO): DefineArg SetNav.DockLat = 0.642341 _
2020-01-23T19:27:18.173Z,1579807638.173 [MissionManager](INFO): DefineArg SetNav.DockLon = -2.126200 _
2020-01-23T19:27:18.176Z,1579807638.176 [SetNav:UpdateNav:B.SetNav](DEBUG): Construct SetNav.
2020-01-23T19:27:18.217Z,1579807638.217 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Aggregate xmlns="Tethys"
    xmlns:Control="Tethys/Control"
    xmlns:Estimation="Tethys/Estimation"
    xmlns:Guidance="Tethys/Guidance"
    xmlns:Sensor="Tethys/Sensor"
    xmlns:Servo="Tethys/Servo"
    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/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/Servo http://okeanids.mbari.org/tethys/Xml/Servo.xsd
                        Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                        Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
    Id="SetNav">

    <Description>
        Just a test to set position
    </Description>


    <DefineArg Name="DockLat"><Description>
        Latitude of docking station waypoint (defaults to Config/workSite.beaconLat).
    </Description><CustomUri Uri="Config/workSite.beaconLat"/></DefineArg>

    <DefineArg Name="DockLon"><Description>
        Longitude of docking station waypoint (defaults to Config/workSite.beaconLon).
    </Description><CustomUri Uri="Config/workSite.beaconLon"/></DefineArg>


                <Aggregate Id="UpdateNav">
                    <Description>Reset nav to dock location if the vehicle is within dock range.</Description>


                    <Syslog Severity="Info">Reseting nav to dock location at range<Arg Name="Range"/><Units:meter/></Syslog>

                    <Guidance:SetNav>
                        <Sequence/>
                        <Setting><Guidance:SetNav.latitude/><Arg Name="DockLat"/></Setting>
                        <Setting><Guidance:SetNav.longitude/><Arg Name="DockLon"/></Setting>
                    </Guidance:SetNav>
                </Aggregate>

</Aggregate>


2020-01-23T19:27:18.220Z,1579807638.220 [CommandLine](IMPORTANT): Running ./Missions/Demo/setNav.xml
2020-01-23T19:27:18.234Z,1579807638.234 [DefaultUnder] Stopped
2020-01-23T19:27:18.234Z,1579807638.234 [DefaultUnder](DEBUG): Aggregate::uninitialize DefaultUnder
2020-01-23T19:27:18.234Z,1579807638.234 [DefaultUnder:uModemComms] Stopped
2020-01-23T19:27:18.234Z,1579807638.234 [DefaultUnder:uModemComms](DEBUG): Aggregate::uninitialize DefaultUnder:uModemComms
2020-01-23T19:27:18.234Z,1579807638.234 [DefaultUnder:uModemComms:CheckIn] Stopped
2020-01-23T19:27:18.234Z,1579807638.234 [DefaultUnder:uModemComms:CheckIn](DEBUG): Aggregate::uninitialize DefaultUnder:uModemComms:CheckIn
2020-01-23T19:27:18.234Z,1579807638.234 [DefaultUnder:uModemComms:CheckIn:A] Stopped
2020-01-23T19:27:18.234Z,1579807638.234 [DefaultUnder:Notify] Stopped
2020-01-23T19:27:18.235Z,1579807638.235 [DefaultUnder:Notify](DEBUG): Aggregate::uninitialize DefaultUnder:Notify
2020-01-23T19:27:18.235Z,1579807638.235 [DefaultUnder:Notify:A] Stopped
2020-01-23T19:27:18.235Z,1579807638.235 [DefaultUnder:Notify:A](DEBUG): Aggregate::uninitialize DefaultUnder:Notify:A
2020-01-23T19:27:18.235Z,1579807638.235 [DefaultUnder:Notify:A:A] Stopped
2020-01-23T19:27:18.235Z,1579807638.235 [DefaultUnder:Notify:A:A](DEBUG): Aggregate::uninitialize DefaultUnder:Notify:A:A
2020-01-23T19:27:18.235Z,1579807638.235 [DefaultUnder:Notify:A:A:A.Wait] Stopped
2020-01-23T19:27:18.235Z,1579807638.235 [DefaultUnder:Notify:A:A:A.Wait](DEBUG): Uninitialize Wait Component.
2020-01-23T19:27:18.235Z,1579807638.235 [DefaultUnder:C.] Stopped
2020-01-23T19:27:18.235Z,1579807638.235 [DefaultUnder:Default] Stopped
2020-01-23T19:27:18.235Z,1579807638.235 [DefaultUnder:Default](DEBUG): Aggregate::uninitialize DefaultUnder:Default
2020-01-23T19:27:18.235Z,1579807638.235 [DefaultUnder:Default:Docked] Stopped
2020-01-23T19:27:18.235Z,1579807638.235 [DefaultUnder:Default:Docked](DEBUG): Aggregate::uninitialize DefaultUnder:Default:Docked
2020-01-23T19:27:18.235Z,1579807638.235 [DefaultUnder:Default:Docked:run] Stopped
2020-01-23T19:27:18.236Z,1579807638.236 [DefaultUnder:Default:Docked:run](DEBUG): Aggregate::uninitialize DefaultUnder:Default:Docked:run
2020-01-23T19:27:18.236Z,1579807638.236 [DefaultUnder:Default:Docked:run:B.Docked] Stopped
2020-01-23T19:27:18.236Z,1579807638.236 [MissionManager](IMPORTANT): Started mission SetNav
2020-01-23T19:27:18.236Z,1579807638.236 [SetNav] Running Loop=1
2020-01-23T19:27:18.236Z,1579807638.236 [SetNav](DEBUG): Aggregate::initialize SetNav
2020-01-23T19:27:18.236Z,1579807638.236 [SetNav:UpdateNav] Running Loop=1
2020-01-23T19:27:18.236Z,1579807638.236 [SetNav:UpdateNav](DEBUG): Aggregate::initialize SetNav:UpdateNav
2020-01-23T19:27:18.236Z,1579807638.236 [SetNav:UpdateNav:A] Running Loop=1
2020-01-23T19:27:18.241Z,1579807638.241 [SetNav:UpdateNav:A](INFO): Reseting nav to dock location at range <Undefined> m 
2020-01-23T19:27:18.241Z,1579807638.241 [SetNav:UpdateNav:A] Stopped
2020-01-23T19:27:18.241Z,1579807638.241 [SetNav:UpdateNav:B.SetNav] Running Loop=1
2020-01-23T19:27:18.241Z,1579807638.241 [SetNav:UpdateNav:B.SetNav](DEBUG): Initialize SetNavComponent.
2020-01-23T19:27:18.624Z,1579807638.624 [SetNav:UpdateNav:B.SetNav](INFO): SetNav fix at 20200123T192718: (36.803398, -121.822304)
2020-01-23T19:27:18.629Z,1579807638.629 [SetNav:UpdateNav:B.SetNav] Stopped
2020-01-23T19:27:18.629Z,1579807638.629 [SetNav:UpdateNav:B.SetNav](DEBUG): Uninitialize SetNavComponent.
2020-01-23T19:27:18.629Z,1579807638.629 [SetNav:UpdateNav](INFO): Completed SetNav:UpdateNav
2020-01-23T19:27:18.629Z,1579807638.629 [SetNav:UpdateNav] Stopped
2020-01-23T19:27:18.629Z,1579807638.629 [SetNav:UpdateNav](DEBUG): Aggregate::uninitialize SetNav:UpdateNav
2020-01-23T19:27:18.629Z,1579807638.629 [SetNav](INFO): Completed SetNav
2020-01-23T19:27:18.629Z,1579807638.629 [MissionManager](INFO): SetNav is completed.
2020-01-23T19:27:18.630Z,1579807638.630 [MissionManager](INFO): Uninitializing Mission SetNav
2020-01-23T19:27:18.630Z,1579807638.630 [SetNav] Stopped
2020-01-23T19:27:18.630Z,1579807638.630 [SetNav](DEBUG): Aggregate::uninitialize SetNav
2020-01-23T19:27:19.045Z,1579807639.045 [MissionManager](IMPORTANT): Started mission DefaultUnder
2020-01-23T19:27:19.046Z,1579807639.046 [DefaultUnder] Running Loop=1
2020-01-23T19:27:19.046Z,1579807639.046 [DefaultUnder](DEBUG): Aggregate::initialize DefaultUnder
2020-01-23T19:27:19.046Z,1579807639.046 [DefaultUnder:uModemComms] Running Loop=1
2020-01-23T19:27:19.046Z,1579807639.046 [DefaultUnder:uModemComms](DEBUG): Aggregate::initialize DefaultUnder:uModemComms
2020-01-23T19:27:19.046Z,1579807639.046 [DefaultUnder:Notify] Running Loop=1
2020-01-23T19:27:19.046Z,1579807639.046 [DefaultUnder:Notify](DEBUG): Aggregate::initialize DefaultUnder:Notify
2020-01-23T19:27:19.046Z,1579807639.046 [DefaultUnder:Notify:A] Running Loop=1
2020-01-23T19:27:19.046Z,1579807639.046 [DefaultUnder:Notify:A](DEBUG): Aggregate::initialize DefaultUnder:Notify:A
2020-01-23T19:27:19.046Z,1579807639.046 [DefaultUnder:Notify:A:A] Running Loop=1
2020-01-23T19:27:19.046Z,1579807639.046 [DefaultUnder:Notify:A:A](DEBUG): Aggregate::initialize DefaultUnder:Notify:A:A
2020-01-23T19:27:19.046Z,1579807639.046 [DefaultUnder:Notify:A:A:A.Wait] Running Loop=1
2020-01-23T19:27:19.047Z,1579807639.047 [DefaultUnder:Notify:A:A:A.Wait](DEBUG): Initialize Wait Component.
2020-01-23T19:27:19.047Z,1579807639.047 [DefaultUnder:C.] Running Loop=1
2020-01-23T19:27:19.047Z,1579807639.047 [DefaultUnder:C.](INFO): Initializing TrackAcousticContact.
2020-01-23T19:27:19.047Z,1579807639.047 [DefaultUnder:E.Wait] Running Loop=1
2020-01-23T19:27:19.047Z,1579807639.047 [DefaultUnder:E.Wait](DEBUG): Initialize Wait Component.
2020-01-23T19:27:19.048Z,1579807639.048 [DefaultUnder:uModemComms:CheckIn] Running Loop=1
2020-01-23T19:27:19.048Z,1579807639.048 [DefaultUnder:uModemComms:CheckIn](DEBUG): Aggregate::initialize DefaultUnder:uModemComms:CheckIn
2020-01-23T19:27:19.048Z,1579807639.048 [DefaultUnder:uModemComms:CheckIn:A] Running Loop=1
2020-01-23T19:27:27.938Z,1579807647.938 [CommandLine](IMPORTANT): got command get latitude
2020-01-23T19:27:27.938Z,1579807647.938 [CommandLine](FAULT): Element has no value
2020-01-23T19:27:32.371Z,1579807652.371 [DefaultUnder:E.Wait](INFO): Done Waiting.
2020-01-23T19:27:32.371Z,1579807652.371 [DefaultUnder:E.Wait] Stopped
2020-01-23T19:27:32.371Z,1579807652.371 [DefaultUnder:E.Wait](DEBUG): Uninitialize Wait Component.
2020-01-23T19:27:32.372Z,1579807652.372 [DefaultUnder:Default] Running Loop=1
2020-01-23T19:27:32.372Z,1579807652.372 [DefaultUnder:Default](DEBUG): Aggregate::initialize DefaultUnder:Default
2020-01-23T19:27:32.372Z,1579807652.372 [DefaultUnder:Default:Docked] Running Loop=1
2020-01-23T19:27:32.372Z,1579807652.372 [DefaultUnder:Default:Docked](DEBUG): Aggregate::initialize DefaultUnder:Default:Docked
2020-01-23T19:27:32.372Z,1579807652.372 [DefaultUnder:Default:Docked:run] Running Loop=1
2020-01-23T19:27:32.372Z,1579807652.372 [DefaultUnder:Default:Docked:run](DEBUG): Aggregate::initialize DefaultUnder:Default:Docked:run
2020-01-23T19:27:32.372Z,1579807652.372 [DefaultUnder:Default:Docked:run:A] Running Loop=1
2020-01-23T19:27:32.372Z,1579807652.372 [DefaultUnder:Default:Home] Running Loop=1
2020-01-23T19:27:32.372Z,1579807652.372 [DefaultUnder:Default:Home](DEBUG): Aggregate::initialize DefaultUnder:Default:Home
2020-01-23T19:27:32.372Z,1579807652.372 [DefaultUnder:Default:Home:run] Running Loop=1
2020-01-23T19:27:32.372Z,1579807652.372 [DefaultUnder:Default:Home:run](DEBUG): Aggregate::initialize DefaultUnder:Default:Home:run
2020-01-23T19:27:32.373Z,1579807652.373 [DefaultUnder:Default:Home:run:A] Running Loop=1
2020-01-23T19:27:32.373Z,1579807652.373 [DefaultUnder:Default:Surface] Running Loop=1
2020-01-23T19:27:32.373Z,1579807652.373 [DefaultUnder:Default:Surface](DEBUG): Aggregate::initialize DefaultUnder:Default:Surface
2020-01-23T19:27:32.373Z,1579807652.373 [DefaultUnder:Default:Surface:run] Running Loop=1
2020-01-23T19:27:32.373Z,1579807652.373 [DefaultUnder:Default:Surface:run](DEBUG): Aggregate::initialize DefaultUnder:Default:Surface:run
2020-01-23T19:27:32.373Z,1579807652.373 [DefaultUnder:Default:Surface:run:B.GoToSurface] Running Loop=1
2020-01-23T19:27:32.373Z,1579807652.373 [DefaultUnder:Default:Surface:run:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-01-23T19:27:32.374Z,1579807652.374 [DefaultUnder:Default:Surface:run:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-01-23T19:27:32.374Z,1579807652.374 [DefaultUnder:Default:Surface:run:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-01-23T19:27:32.374Z,1579807652.374 [DefaultUnder:Default:Surface:run:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-01-23T19:27:32.374Z,1579807652.374 [DefaultUnder:Default:Surface:run:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-01-23T19:27:32.375Z,1579807652.375 [DefaultUnder:Default:Surface:run:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-01-23T19:27:32.375Z,1579807652.375 [DefaultUnder:Default:Surface:run:A] Running Loop=1
2020-01-23T19:27:32.770Z,1579807652.770 [DefaultUnder:Default:Surface] Stopped
2020-01-23T19:27:32.770Z,1579807652.770 [DefaultUnder:Default:Surface](DEBUG): Aggregate::uninitialize DefaultUnder:Default:Surface
2020-01-23T19:27:32.770Z,1579807652.770 [DefaultUnder:Default:Surface:run] Stopped
2020-01-23T19:27:32.770Z,1579807652.770 [DefaultUnder:Default:Surface:run](DEBUG): Aggregate::uninitialize DefaultUnder:Default:Surface:run
2020-01-23T19:27:32.770Z,1579807652.770 [DefaultUnder:Default:Surface:run:A] Stopped
2020-01-23T19:27:32.770Z,1579807652.770 [DefaultUnder:Default:Surface:run:B.GoToSurface] Stopped
2020-01-23T19:27:32.771Z,1579807652.771 [DefaultUnder:Default:Surface:run:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2020-01-23T19:27:32.771Z,1579807652.771 [DefaultUnder:Default:Home] Stopped
2020-01-23T19:27:32.771Z,1579807652.771 [DefaultUnder:Default:Home](DEBUG): Aggregate::uninitialize DefaultUnder:Default:Home
2020-01-23T19:27:32.771Z,1579807652.771 [DefaultUnder:Default:Home:run] Stopped
2020-01-23T19:27:32.771Z,1579807652.771 [DefaultUnder:Default:Home:run](DEBUG): Aggregate::uninitialize DefaultUnder:Default:Home:run
2020-01-23T19:27:32.771Z,1579807652.771 [DefaultUnder:Default:Home:run:A] Stopped
2020-01-23T19:27:32.771Z,1579807652.771 [DefaultUnder:Default:Docked:run:A] Stopped
2020-01-23T19:27:32.771Z,1579807652.771 [DefaultUnder:Default:Docked:run:B.Docked] Running Loop=1
2020-01-23T19:27:32.771Z,1579807652.771 [DefaultUnder:Default:Docked:run:B.Docked](DEBUG): Initialize.
2020-01-23T19:27:32.772Z,1579807652.772 [DefaultUnder:Default:Docked:run:B.Docked](INFO): Depth unspecified. Maintaining workSite beacon depth of 6.000000 m.
2020-01-23T19:27:44.367Z,1579807664.367 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004947
2020-01-23T19:27:47.753Z,1579807667.753 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2020-01-23T19:27:47.753Z,1579807667.753 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,20012312390569,35.0, -0.1,   0.0,1448.RA,  0.00,   0.00,   0.00,   0.00,   0.00
2020-01-23T19:27:52.108Z,1579807672.108 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20200123T192007/Courier0004.lzma
2020-01-23T19:27:54.114Z,1579807674.114 [DataOverHttps](INFO): Moved sent file to Logs/20200123T192007/Courier0004.lzma.bak
2020-01-23T19:27:54.115Z,1579807674.115 [DataOverHttps](INFO): SBD MOMSN=12199008
2020-01-23T19:28:11.680Z,1579807691.680 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20200123T192504/Courier0000.lzma
2020-01-23T19:28:13.686Z,1579807693.686 [DataOverHttps](INFO): Moved sent file to Logs/20200123T192504/Courier0000.lzma.bak
2020-01-23T19:28:13.686Z,1579807693.686 [DataOverHttps](INFO): SBD MOMSN=12199010
2020-01-23T19:28:15.170Z,1579807695.170 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2020-01-23T19:28:15.170Z,1579807695.170 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-01-23T19:28:15.213Z,1579807695.214 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-01-23T19:28:15.649Z,1579807695.649 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-01-23T19:28:15.649Z,1579807695.649 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2020-01-23T19:28:19.246Z,1579807699.246 [DefaultUnder:C.](INFO): *** querying acoustic contact ***
2020-01-23T19:28:19.992Z,1579807699.992 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77

2020-01-23T19:28:20.401Z,1579807700.401 [Micromodem](INFO): Nmea in: $SNPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*6A

2020-01-23T19:28:21.204Z,1579807701.204 [Micromodem](INFO): Nmea in: $SNTTA,,,,,192820.89*5F

2020-01-23T19:28:23.626Z,1579807703.626 [DUSBL_Hydroid](ERROR): No response from remote modem.
2020-01-23T19:28:31.611Z,1579807711.611 [CommandLine](IMPORTANT): got command maintain sensor NAL9602.latitude_fix 36.500000 degree
2020-01-23T19:28:31.612Z,1579807711.612 [ComponentRegistry](DEBUG): SyncComponent "Maintain_NAL9602.latitude_fix" handled in the control thread.
2020-01-23T19:28:31.612Z,1579807711.612 [CommandLine](IMPORTANT): got command maintain sensor NAL9602.longitude_fix -121.900002 degree
2020-01-23T19:28:31.618Z,1579807711.618 [ComponentRegistry](DEBUG): SyncComponent "Maintain_NAL9602.longitude_fix" handled in the control thread.
2020-01-23T19:28:31.819Z,1579807711.819 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,DDM,Depth_Keller,DropWeight,DUSBL_Hydroid,Micromodem,NAL9602,Onboard,PowerOnly,RDI_Pathfinder,BPC1,PAR_Licor,Depth_Keller,PAR_Licor,Maintain_NAL9602.latitude_fix,Maintain_NAL9602.longitude_fix,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2020-01-23T19:28:32.141Z,1579807712.141 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20200123T192504/Courier0004.lzma
2020-01-23T19:28:32.203Z,1579807712.203 [Reporter](INFO): latitude 36.803398 arcdeg
2020-01-23T19:28:34.144Z,1579807714.144 [DataOverHttps](INFO): Moved sent file to Logs/20200123T192504/Courier0004.lzma.bak
2020-01-23T19:28:34.144Z,1579807714.144 [DataOverHttps](INFO): SBD MOMSN=12199013
2020-01-23T19:28:45.482Z,1579807725.482 [CommandLine](IMPORTANT): got command set NAL9602.time_fix 1579807744.000000 second
2020-01-23T19:28:45.778Z,1579807725.778 [Reporter](INFO): latitude 36.500000 arcdeg
2020-01-23T19:28:48.225Z,1579807728.225 [CommandLine](IMPORTANT): got command get latitude
2020-01-23T19:28:48.226Z,1579807728.226 [CommandLine](IMPORTANT): latitude 36.500000 arcdeg
2020-01-23T19:28:55.522Z,1579807735.522 [CommandLine](IMPORTANT): got command run ./Missions/Demo/setNav.xml
2020-01-23T19:28:55.522Z,1579807735.522 [MissionManager](INFO): Loading Mission: ./Missions/Demo/setNav.xml
2020-01-23T19:28:55.548Z,1579807735.548 [MissionManager](INFO): DefineArg SetNav.DockLat = 0.642341 _
2020-01-23T19:28:55.637Z,1579807735.637 [MissionManager](INFO): DefineArg SetNav.DockLon = -2.126200 _
2020-01-23T19:28:55.640Z,1579807735.640 [SetNav:UpdateNav:B.SetNav](DEBUG): Construct SetNav.
2020-01-23T19:28:55.672Z,1579807735.672 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Aggregate xmlns="Tethys"
    xmlns:Control="Tethys/Control"
    xmlns:Estimation="Tethys/Estimation"
    xmlns:Guidance="Tethys/Guidance"
    xmlns:Sensor="Tethys/Sensor"
    xmlns:Servo="Tethys/Servo"
    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/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/Servo http://okeanids.mbari.org/tethys/Xml/Servo.xsd
                        Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                        Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
    Id="SetNav">

    <Description>
        Just a test to set position
    </Description>


    <DefineArg Name="DockLat"><Description>
        Latitude of docking station waypoint (defaults to Config/workSite.beaconLat).
    </Description><CustomUri Uri="Config/workSite.beaconLat"/></DefineArg>

    <DefineArg Name="DockLon"><Description>
        Longitude of docking station waypoint (defaults to Config/workSite.beaconLon).
    </Description><CustomUri Uri="Config/workSite.beaconLon"/></DefineArg>


                <Aggregate Id="UpdateNav">
                    <Description>Reset nav to dock location if the vehicle is within dock range.</Description>


                    <Syslog Severity="Info">Reseting nav to dock location at range<Arg Name="Range"/><Units:meter/></Syslog>

                    <Guidance:SetNav>
                        <Sequence/>
                        <Setting><Guidance:SetNav.latitude/><Arg Name="DockLat"/></Setting>
                        <Setting><Guidance:SetNav.longitude/><Arg Name="DockLon"/></Setting>
                    </Guidance:SetNav>
                </Aggregate>

</Aggregate>


2020-01-23T19:28:55.690Z,1579807735.690 [CommandLine](IMPORTANT): Running ./Missions/Demo/setNav.xml
2020-01-23T19:28:55.719Z,1579807735.719 [DefaultUnder] Stopped
2020-01-23T19:28:55.720Z,1579807735.720 [DefaultUnder](DEBUG): Aggregate::uninitialize DefaultUnder
2020-01-23T19:28:55.720Z,1579807735.720 [DefaultUnder:uModemComms] Stopped
2020-01-23T19:28:55.720Z,1579807735.720 [DefaultUnder:uModemComms](DEBUG): Aggregate::uninitialize DefaultUnder:uModemComms
2020-01-23T19:28:55.720Z,1579807735.720 [DefaultUnder:uModemComms:CheckIn] Stopped
2020-01-23T19:28:55.720Z,1579807735.720 [DefaultUnder:uModemComms:CheckIn](DEBUG): Aggregate::uninitialize DefaultUnder:uModemComms:CheckIn
2020-01-23T19:28:55.720Z,1579807735.720 [DefaultUnder:uModemComms:CheckIn:A] Stopped
2020-01-23T19:28:55.720Z,1579807735.720 [DefaultUnder:Notify] Stopped
2020-01-23T19:28:55.720Z,1579807735.720 [DefaultUnder:Notify](DEBUG): Aggregate::uninitialize DefaultUnder:Notify
2020-01-23T19:28:55.720Z,1579807735.720 [DefaultUnder:Notify:A] Stopped
2020-01-23T19:28:55.720Z,1579807735.720 [DefaultUnder:Notify:A](DEBUG): Aggregate::uninitialize DefaultUnder:Notify:A
2020-01-23T19:28:55.720Z,1579807735.720 [DefaultUnder:Notify:A:A] Stopped
2020-01-23T19:28:55.720Z,1579807735.720 [DefaultUnder:Notify:A:A](DEBUG): Aggregate::uninitialize DefaultUnder:Notify:A:A
2020-01-23T19:28:55.729Z,1579807735.729 [DefaultUnder:Notify:A:A:A.Wait] Stopped
2020-01-23T19:28:55.729Z,1579807735.729 [DefaultUnder:Notify:A:A:A.Wait](DEBUG): Uninitialize Wait Component.
2020-01-23T19:28:55.729Z,1579807735.729 [DefaultUnder:C.] Stopped
2020-01-23T19:28:55.729Z,1579807735.729 [DefaultUnder:Default] Stopped
2020-01-23T19:28:55.729Z,1579807735.729 [DefaultUnder:Default](DEBUG): Aggregate::uninitialize DefaultUnder:Default
2020-01-23T19:28:55.729Z,1579807735.729 [DefaultUnder:Default:Docked] Stopped
2020-01-23T19:28:55.729Z,1579807735.729 [DefaultUnder:Default:Docked](DEBUG): Aggregate::uninitialize DefaultUnder:Default:Docked
2020-01-23T19:28:55.729Z,1579807735.729 [DefaultUnder:Default:Docked:run] Stopped
2020-01-23T19:28:55.729Z,1579807735.729 [DefaultUnder:Default:Docked:run](DEBUG): Aggregate::uninitialize DefaultUnder:Default:Docked:run
2020-01-23T19:28:55.729Z,1579807735.729 [DefaultUnder:Default:Docked:run:B.Docked] Stopped
2020-01-23T19:28:55.730Z,1579807735.730 [MissionManager](IMPORTANT): Started mission SetNav
2020-01-23T19:28:55.730Z,1579807735.730 [SetNav] Running Loop=1
2020-01-23T19:28:55.730Z,1579807735.730 [SetNav](DEBUG): Aggregate::initialize SetNav
2020-01-23T19:28:55.730Z,1579807735.730 [SetNav:UpdateNav] Running Loop=1
2020-01-23T19:28:55.730Z,1579807735.730 [SetNav:UpdateNav](DEBUG): Aggregate::initialize SetNav:UpdateNav
2020-01-23T19:28:55.730Z,1579807735.730 [SetNav:UpdateNav:A] Running Loop=1
2020-01-23T19:28:55.731Z,1579807735.731 [SetNav:UpdateNav:A](INFO): Reseting nav to dock location at range <Undefined> m 
2020-01-23T19:28:55.731Z,1579807735.731 [SetNav:UpdateNav:A] Stopped
2020-01-23T19:28:55.731Z,1579807735.731 [SetNav:UpdateNav:B.SetNav] Running Loop=1
2020-01-23T19:28:55.731Z,1579807735.731 [SetNav:UpdateNav:B.SetNav](DEBUG): Initialize SetNavComponent.
2020-01-23T19:28:56.029Z,1579807736.029 [SetNav:UpdateNav:B.SetNav](INFO): SetNav fix at 20200123T192856: (36.803398, -121.822304)
2020-01-23T19:28:56.029Z,1579807736.029 [SetNav:UpdateNav:B.SetNav] Stopped
2020-01-23T19:28:56.030Z,1579807736.030 [SetNav:UpdateNav:B.SetNav](DEBUG): Uninitialize SetNavComponent.
2020-01-23T19:28:56.030Z,1579807736.030 [SetNav:UpdateNav](INFO): Completed SetNav:UpdateNav
2020-01-23T19:28:56.030Z,1579807736.030 [SetNav:UpdateNav] Stopped
2020-01-23T19:28:56.030Z,1579807736.030 [SetNav:UpdateNav](DEBUG): Aggregate::uninitialize SetNav:UpdateNav
2020-01-23T19:28:56.030Z,1579807736.030 [SetNav](INFO): Completed SetNav
2020-01-23T19:28:56.030Z,1579807736.030 [MissionManager](INFO): SetNav is completed.
2020-01-23T19:28:56.030Z,1579807736.030 [MissionManager](INFO): Uninitializing Mission SetNav
2020-01-23T19:28:56.030Z,1579807736.030 [SetNav] Stopped
2020-01-23T19:28:56.030Z,1579807736.030 [SetNav](DEBUG): Aggregate::uninitialize SetNav
2020-01-23T19:28:56.436Z,1579807736.436 [MissionManager](IMPORTANT): Started mission DefaultUnder
2020-01-23T19:28:56.441Z,1579807736.441 [DefaultUnder] Running Loop=1
2020-01-23T19:28:56.441Z,1579807736.441 [DefaultUnder](DEBUG): Aggregate::initialize DefaultUnder
2020-01-23T19:28:56.441Z,1579807736.441 [DefaultUnder:uModemComms] Running Loop=1
2020-01-23T19:28:56.441Z,1579807736.441 [DefaultUnder:uModemComms](DEBUG): Aggregate::initialize DefaultUnder:uModemComms
2020-01-23T19:28:56.441Z,1579807736.441 [DefaultUnder:Notify] Running Loop=1
2020-01-23T19:28:56.441Z,1579807736.441 [DefaultUnder:Notify](DEBUG): Aggregate::initialize DefaultUnder:Notify
2020-01-23T19:28:56.442Z,1579807736.442 [DefaultUnder:Notify:A] Running Loop=1
2020-01-23T19:28:56.442Z,1579807736.442 [DefaultUnder:Notify:A](DEBUG): Aggregate::initialize DefaultUnder:Notify:A
2020-01-23T19:28:56.442Z,1579807736.442 [DefaultUnder:Notify:A:A] Running Loop=1
2020-01-23T19:28:56.442Z,1579807736.442 [DefaultUnder:Notify:A:A](DEBUG): Aggregate::initialize DefaultUnder:Notify:A:A
2020-01-23T19:28:56.442Z,1579807736.442 [DefaultUnder:Notify:A:A:A.Wait] Running Loop=1
2020-01-23T19:28:56.442Z,1579807736.442 [DefaultUnder:Notify:A:A:A.Wait](DEBUG): Initialize Wait Component.
2020-01-23T19:28:56.442Z,1579807736.442 [DefaultUnder:C.] Running Loop=1
2020-01-23T19:28:56.442Z,1579807736.442 [DefaultUnder:C.](INFO): Initializing TrackAcousticContact.
2020-01-23T19:28:56.442Z,1579807736.442 [DefaultUnder:E.Wait] Running Loop=1
2020-01-23T19:28:56.442Z,1579807736.442 [DefaultUnder:E.Wait](DEBUG): Initialize Wait Component.
2020-01-23T19:28:56.443Z,1579807736.443 [DefaultUnder:uModemComms:CheckIn] Running Loop=1
2020-01-23T19:28:56.444Z,1579807736.444 [DefaultUnder:uModemComms:CheckIn](DEBUG): Aggregate::initialize DefaultUnder:uModemComms:CheckIn
2020-01-23T19:28:56.444Z,1579807736.444 [DefaultUnder:uModemComms:CheckIn:A] Running Loop=1
2020-01-23T19:28:56.505Z,1579807736.505 [BuoyancyServo](FAULT): Reading outside of valid range:0.000000

2020-01-23T19:28:56.505Z,1579807736.505 [BuoyancyServo](FAULT): Buoyancy engine reporting null position
2020-01-23T19:28:56.506Z,1579807736.506 [BuoyancyServo] Hardware Fault, FailCount= 1
2020-01-23T19:28:56.506Z,1579807736.506 [BuoyancyServo](ERROR): Hardware Fault
2020-01-23T19:28:56.510Z,1579807736.510 [CBIT](ERROR): Hardware Fault in component: BuoyancyServo
2020-01-23T19:28:56.511Z,1579807736.511 [Reporter](INFO): latitude 36.803398 arcdeg
2020-01-23T19:28:58.868Z,1579807738.868 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2020-01-23T19:28:58.868Z,1579807738.868 [BuoyancyServo](INFO): Powering down
2020-01-23T19:28:59.677Z,1579807739.677 [CBIT](INFO): Clearing failed state for component BuoyancyServo
2020-01-23T19:28:59.677Z,1579807739.677 [BuoyancyServo] No Fault, FailCount= 1
2020-01-23T19:29:00.042Z,1579807740.042 [CommandLine](IMPORTANT): got command get latitude
2020-01-23T19:29:00.042Z,1579807740.042 [CommandLine](IMPORTANT): latitude 36.803398 arcdeg
2020-01-23T19:29:00.113Z,1579807740.113 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2020-01-23T19:29:00.121Z,1579807740.121 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2020-01-23T19:29:00.399Z,1579807740.399 [DataOverHttps](INFO): Sending 1011 bytes from file Logs/20200123T191257/Express0001.lzma
2020-01-23T19:29:02.402Z,1579807742.402 [DataOverHttps](INFO): Moved sent file to Logs/20200123T191257/Express0001.lzma.bak
2020-01-23T19:29:02.402Z,1579807742.402 [DataOverHttps](INFO): SBD MOMSN=12199015
2020-01-23T19:29:06.098Z,1579807746.098 [CommandLine](IMPORTANT): got command maintain clear
2020-01-23T19:29:06.195Z,1579807746.195 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,DDM,Depth_Keller,DropWeight,DUSBL_Hydroid,Micromodem,NAL9602,Onboard,PowerOnly,RDI_Pathfinder,BPC1,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2020-01-23T19:29:09.258Z,1579807749.258 [CommandLine](IMPORTANT): got command maintain clear
2020-01-23T19:29:09.780Z,1579807749.780 [DefaultUnder:E.Wait](INFO): Done Waiting.
2020-01-23T19:29:09.781Z,1579807749.781 [DefaultUnder:E.Wait] Stopped
2020-01-23T19:29:09.781Z,1579807749.781 [DefaultUnder:E.Wait](DEBUG): Uninitialize Wait Component.
2020-01-23T19:29:09.781Z,1579807749.781 [DefaultUnder:Default] Running Loop=1
2020-01-23T19:29:09.781Z,1579807749.781 [DefaultUnder:Default](DEBUG): Aggregate::initialize DefaultUnder:Default
2020-01-23T19:29:09.781Z,1579807749.781 [DefaultUnder:Default:Docked] Running Loop=1
2020-01-23T19:29:09.781Z,1579807749.781 [DefaultUnder:Default:Docked](DEBUG): Aggregate::initialize DefaultUnder:Default:Docked
2020-01-23T19:29:09.781Z,1579807749.781 [DefaultUnder:Default:Docked:run] Running Loop=1
2020-01-23T19:29:09.782Z,1579807749.782 [DefaultUnder:Default:Docked:run](DEBUG): Aggregate::initialize DefaultUnder:Default:Docked:run
2020-01-23T19:29:09.782Z,1579807749.782 [DefaultUnder:Default:Docked:run:A] Running Loop=1
2020-01-23T19:29:09.782Z,1579807749.782 [DefaultUnder:Default:Home] Running Loop=1
2020-01-23T19:29:09.782Z,1579807749.782 [DefaultUnder:Default:Home](DEBUG): Aggregate::initialize DefaultUnder:Default:Home
2020-01-23T19:29:09.782Z,1579807749.782 [DefaultUnder:Default:Home:run] Running Loop=1
2020-01-23T19:29:09.782Z,1579807749.782 [DefaultUnder:Default:Home:run](DEBUG): Aggregate::initialize DefaultUnder:Default:Home:run
2020-01-23T19:29:09.782Z,1579807749.782 [DefaultUnder:Default:Home:run:A] Running Loop=1
2020-01-23T19:29:09.782Z,1579807749.782 [DefaultUnder:Default:Surface] Running Loop=1
2020-01-23T19:29:09.782Z,1579807749.782 [DefaultUnder:Default:Surface](DEBUG): Aggregate::initialize DefaultUnder:Default:Surface
2020-01-23T19:29:09.782Z,1579807749.782 [DefaultUnder:Default:Surface:run] Running Loop=1
2020-01-23T19:29:09.783Z,1579807749.783 [DefaultUnder:Default:Surface:run](DEBUG): Aggregate::initialize DefaultUnder:Default:Surface:run
2020-01-23T19:29:09.783Z,1579807749.783 [DefaultUnder:Default:Surface:run:B.GoToSurface] Running Loop=1
2020-01-23T19:29:09.783Z,1579807749.783 [DefaultUnder:Default:Surface:run:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-01-23T19:29:09.783Z,1579807749.783 [DefaultUnder:Default:Surface:run:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-01-23T19:29:09.783Z,1579807749.783 [DefaultUnder:Default:Surface:run:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-01-23T19:29:09.783Z,1579807749.783 [DefaultUnder:Default:Surface:run:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-01-23T19:29:09.784Z,1579807749.784 [DefaultUnder:Default:Surface:run:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-01-23T19:29:09.784Z,1579807749.784 [DefaultUnder:Default:Surface:run:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-01-23T19:29:09.784Z,1579807749.784 [DefaultUnder:Default:Surface:run:A] Running Loop=1
2020-01-23T19:29:10.175Z,1579807750.175 [DefaultUnder:Default:Surface] Stopped
2020-01-23T19:29:10.176Z,1579807750.176 [DefaultUnder:Default:Surface](DEBUG): Aggregate::uninitialize DefaultUnder:Default:Surface
2020-01-23T19:29:10.176Z,1579807750.176 [DefaultUnder:Default:Surface:run] Stopped
2020-01-23T19:29:10.176Z,1579807750.176 [DefaultUnder:Default:Surface:run](DEBUG): Aggregate::uninitialize DefaultUnder:Default:Surface:run
2020-01-23T19:29:10.176Z,1579807750.176 [DefaultUnder:Default:Surface:run:A] Stopped
2020-01-23T19:29:10.176Z,1579807750.176 [DefaultUnder:Default:Surface:run:B.GoToSurface] Stopped
2020-01-23T19:29:10.176Z,1579807750.176 [DefaultUnder:Default:Surface:run:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2020-01-23T19:29:10.176Z,1579807750.176 [DefaultUnder:Default:Home] Stopped
2020-01-23T19:29:10.176Z,1579807750.176 [DefaultUnder:Default:Home](DEBUG): Aggregate::uninitialize DefaultUnder:Default:Home
2020-01-23T19:29:10.176Z,1579807750.176 [DefaultUnder:Default:Home:run] Stopped
2020-01-23T19:29:10.176Z,1579807750.176 [DefaultUnder:Default:Home:run](DEBUG): Aggregate::uninitialize DefaultUnder:Default:Home:run
2020-01-23T19:29:10.176Z,1579807750.176 [DefaultUnder:Default:Home:run:A] Stopped
2020-01-23T19:29:10.177Z,1579807750.177 [DefaultUnder:Default:Docked:run:A] Stopped
2020-01-23T19:29:10.177Z,1579807750.177 [DefaultUnder:Default:Docked:run:B.Docked] Running Loop=1
2020-01-23T19:29:10.177Z,1579807750.177 [DefaultUnder:Default:Docked:run:B.Docked](DEBUG): Initialize.
2020-01-23T19:29:10.178Z,1579807750.178 [DefaultUnder:Default:Docked:run:B.Docked](INFO): Depth unspecified. Maintaining workSite beacon depth of 6.000000 m.
2020-01-23T19:29:12.107Z,1579807752.107 [CommandLine](IMPORTANT): got command get latitude
2020-01-23T19:29:12.107Z,1579807752.107 [CommandLine](IMPORTANT): latitude 36.803398 arcdeg
2020-01-23T19:29:22.324Z,1579807762.324 [DataOverHttps](INFO): Sending 155 bytes from file Logs/20200123T192504/Courier0007.lzma
2020-01-23T19:29:24.336Z,1579807764.336 [DataOverHttps](INFO): Moved sent file to Logs/20200123T192504/Courier0007.lzma.bak
2020-01-23T19:29:24.336Z,1579807764.336 [DataOverHttps](INFO): SBD MOMSN=12199042
2020-01-23T19:29:42.644Z,1579807782.644 [DataOverHttps](INFO): Sending 179 bytes from file Logs/20200123T191257/Express0005.lzma
2020-01-23T19:29:44.650Z,1579807784.650 [DataOverHttps](INFO): Moved sent file to Logs/20200123T191257/Express0005.lzma.bak
2020-01-23T19:29:44.650Z,1579807784.650 [DataOverHttps](INFO): SBD MOMSN=12199044
2020-01-23T19:29:46.016Z,1579807786.016 [CommandLine](IMPORTANT): got command maintain sensor NAL9602.latitude_fix 36.500000 degree
2020-01-23T19:29:46.016Z,1579807786.016 [ComponentRegistry](DEBUG): SyncComponent "Maintain_NAL9602.latitude_fix" handled in the control thread.
2020-01-23T19:29:46.017Z,1579807786.017 [CommandLine](IMPORTANT): got command maintain sensor NAL9602.longitude_fix -121.900002 degree
2020-01-23T19:29:46.018Z,1579807786.018 [ComponentRegistry](DEBUG): SyncComponent "Maintain_NAL9602.longitude_fix" handled in the control thread.
2020-01-23T19:29:46.192Z,1579807786.192 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,DDM,Depth_Keller,DropWeight,DUSBL_Hydroid,Micromodem,NAL9602,Onboard,PowerOnly,RDI_Pathfinder,BPC1,PAR_Licor,Depth_Keller,PAR_Licor,Maintain_NAL9602.latitude_fix,Maintain_NAL9602.longitude_fix,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2020-01-23T19:29:53.915Z,1579807793.915 [CommandLine](IMPORTANT): got command set NAL9602.time_fix 1579807744.000000 second
2020-01-23T19:29:54.230Z,1579807794.230 [Reporter](INFO): latitude 36.500000 arcdeg
2020-01-23T19:29:56.679Z,1579807796.679 [DefaultUnder:C.](INFO): *** querying acoustic contact ***
2020-01-23T19:29:57.400Z,1579807797.400 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77

2020-01-23T19:29:57.805Z,1579807797.805 [Micromodem](INFO): Nmea in: $SNPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*6A

2020-01-23T19:29:58.612Z,1579807798.612 [Micromodem](INFO): Nmea in: $SNTTA,,,,,192958.30*53

2020-01-23T19:30:01.043Z,1579807801.043 [DUSBL_Hydroid](ERROR): No response from remote modem.
2020-01-23T19:30:03.323Z,1579807803.323 [CommandLine](IMPORTANT): got command run ./Missions/Demo/setNav.xml
2020-01-23T19:30:03.323Z,1579807803.323 [MissionManager](INFO): Loading Mission: ./Missions/Demo/setNav.xml
2020-01-23T19:30:03.360Z,1579807803.360 [MissionManager](INFO): DefineArg SetNav.DockLat = 0.642341 _
2020-01-23T19:30:03.362Z,1579807803.362 [MissionManager](INFO): DefineArg SetNav.DockLon = -2.126200 _
2020-01-23T19:30:03.364Z,1579807803.364 [SetNav:UpdateNav:B.SetNav](DEBUG): Construct SetNav.
2020-01-23T19:30:03.369Z,1579807803.369 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Aggregate xmlns="Tethys"
    xmlns:Control="Tethys/Control"
    xmlns:Estimation="Tethys/Estimation"
    xmlns:Guidance="Tethys/Guidance"
    xmlns:Sensor="Tethys/Sensor"
    xmlns:Servo="Tethys/Servo"
    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/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/Servo http://okeanids.mbari.org/tethys/Xml/Servo.xsd
                        Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                        Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
    Id="SetNav">

    <Description>
        Just a test to set position
    </Description>


    <DefineArg Name="DockLat"><Description>
        Latitude of docking station waypoint (defaults to Config/workSite.beaconLat).
    </Description><CustomUri Uri="Config/workSite.beaconLat"/></DefineArg>

    <DefineArg Name="DockLon"><Description>
        Longitude of docking station waypoint (defaults to Config/workSite.beaconLon).
    </Description><CustomUri Uri="Config/workSite.beaconLon"/></DefineArg>


                <Aggregate Id="UpdateNav">
                    <Description>Reset nav to dock location if the vehicle is within dock range.</Description>


                    <Syslog Severity="Info">Reseting nav to dock location at range<Arg Name="Range"/><Units:meter/></Syslog>

                    <Guidance:SetNav>
                        <Sequence/>
                        <Setting><Guidance:SetNav.latitude/><Arg Name="DockLat"/></Setting>
                        <Setting><Guidance:SetNav.longitude/><Arg Name="DockLon"/></Setting>
                    </Guidance:SetNav>
                </Aggregate>

</Aggregate>


2020-01-23T19:30:03.370Z,1579807803.370 [CommandLine](IMPORTANT): Running ./Missions/Demo/setNav.xml
2020-01-23T19:30:03.505Z,1579807803.505 [DataOverHttps](INFO): Sending 644 bytes from file Logs/20200123T191257/Express0008.lzma
2020-01-23T19:30:03.523Z,1579807803.523 [DefaultUnder] Stopped
2020-01-23T19:30:03.523Z,1579807803.523 [DefaultUnder](DEBUG): Aggregate::uninitialize DefaultUnder
2020-01-23T19:30:03.523Z,1579807803.523 [DefaultUnder:uModemComms] Stopped
2020-01-23T19:30:03.523Z,1579807803.523 [DefaultUnder:uModemComms](DEBUG): Aggregate::uninitialize DefaultUnder:uModemComms
2020-01-23T19:30:03.523Z,1579807803.523 [DefaultUnder:uModemComms:CheckIn] Stopped
2020-01-23T19:30:03.523Z,1579807803.523 [DefaultUnder:uModemComms:CheckIn](DEBUG): Aggregate::uninitialize DefaultUnder:uModemComms:CheckIn
2020-01-23T19:30:03.523Z,1579807803.523 [DefaultUnder:uModemComms:CheckIn:A] Stopped
2020-01-23T19:30:03.523Z,1579807803.523 [DefaultUnder:Notify] Stopped
2020-01-23T19:30:03.523Z,1579807803.523 [DefaultUnder:Notify](DEBUG): Aggregate::uninitialize DefaultUnder:Notify
2020-01-23T19:30:03.523Z,1579807803.523 [DefaultUnder:Notify:A] Stopped
2020-01-23T19:30:03.524Z,1579807803.524 [DefaultUnder:Notify:A](DEBUG): Aggregate::uninitialize DefaultUnder:Notify:A
2020-01-23T19:30:03.524Z,1579807803.524 [DefaultUnder:Notify:A:A] Stopped
2020-01-23T19:30:03.524Z,1579807803.524 [DefaultUnder:Notify:A:A](DEBUG): Aggregate::uninitialize DefaultUnder:Notify:A:A
2020-01-23T19:30:03.524Z,1579807803.524 [DefaultUnder:Notify:A:A:A.Wait] Stopped
2020-01-23T19:30:03.524Z,1579807803.524 [DefaultUnder:Notify:A:A:A.Wait](DEBUG): Uninitialize Wait Component.
2020-01-23T19:30:03.524Z,1579807803.524 [DefaultUnder:C.] Stopped
2020-01-23T19:30:03.524Z,1579807803.524 [DefaultUnder:Default] Stopped
2020-01-23T19:30:03.524Z,1579807803.524 [DefaultUnder:Default](DEBUG): Aggregate::uninitialize DefaultUnder:Default
2020-01-23T19:30:03.524Z,1579807803.524 [DefaultUnder:Default:Docked] Stopped
2020-01-23T19:30:03.524Z,1579807803.524 [DefaultUnder:Default:Docked](DEBUG): Aggregate::uninitialize DefaultUnder:Default:Docked
2020-01-23T19:30:03.524Z,1579807803.524 [DefaultUnder:Default:Docked:run] Stopped
2020-01-23T19:30:03.524Z,1579807803.524 [DefaultUnder:Default:Docked:run](DEBUG): Aggregate::uninitialize DefaultUnder:Default:Docked:run
2020-01-23T19:30:03.529Z,1579807803.529 [DefaultUnder:Default:Docked:run:B.Docked] Stopped
2020-01-23T19:30:03.529Z,1579807803.529 [MissionManager](IMPORTANT): Started mission SetNav
2020-01-23T19:30:03.529Z,1579807803.529 [SetNav] Running Loop=1
2020-01-23T19:30:03.529Z,1579807803.529 [SetNav](DEBUG): Aggregate::initialize SetNav
2020-01-23T19:30:03.530Z,1579807803.530 [SetNav:UpdateNav] Running Loop=1
2020-01-23T19:30:03.530Z,1579807803.530 [SetNav:UpdateNav](DEBUG): Aggregate::initialize SetNav:UpdateNav
2020-01-23T19:30:03.531Z,1579807803.531 [SetNav:UpdateNav:A] Running Loop=1
2020-01-23T19:30:03.532Z,1579807803.532 [SetNav:UpdateNav:A](INFO): Reseting nav to dock location at range <Undefined> m 
2020-01-23T19:30:03.537Z,1579807803.537 [SetNav:UpdateNav:A] Stopped
2020-01-23T19:30:03.537Z,1579807803.537 [SetNav:UpdateNav:B.SetNav] Running Loop=1
2020-01-23T19:30:03.538Z,1579807803.538 [SetNav:UpdateNav:B.SetNav](DEBUG): Initialize SetNavComponent.
2020-01-23T19:30:03.908Z,1579807803.908 [SetNav:UpdateNav:B.SetNav](INFO): SetNav fix at 20200123T193003: (36.803398, -121.822304)
2020-01-23T19:30:03.908Z,1579807803.908 [SetNav:UpdateNav:B.SetNav] Stopped
2020-01-23T19:30:03.908Z,1579807803.908 [SetNav:UpdateNav:B.SetNav](DEBUG): Uninitialize SetNavComponent.
2020-01-23T19:30:03.908Z,1579807803.908 [SetNav:UpdateNav](INFO): Completed SetNav:UpdateNav
2020-01-23T19:30:03.908Z,1579807803.908 [SetNav:UpdateNav] Stopped
2020-01-23T19:30:03.908Z,1579807803.908 [SetNav:UpdateNav](DEBUG): Aggregate::uninitialize SetNav:UpdateNav
2020-01-23T19:30:03.909Z,1579807803.909 [SetNav](INFO): Completed SetNav
2020-01-23T19:30:03.909Z,1579807803.909 [MissionManager](INFO): SetNav is completed.
2020-01-23T19:30:03.909Z,1579807803.909 [MissionManager](INFO): Uninitializing Mission SetNav
2020-01-23T19:30:03.909Z,1579807803.909 [SetNav] Stopped
2020-01-23T19:30:03.909Z,1579807803.909 [SetNav](DEBUG): Aggregate::uninitialize SetNav
2020-01-23T19:30:04.310Z,1579807804.310 [MissionManager](IMPORTANT): Started mission DefaultUnder
2020-01-23T19:30:04.310Z,1579807804.310 [DefaultUnder] Running Loop=1
2020-01-23T19:30:04.310Z,1579807804.310 [DefaultUnder](DEBUG): Aggregate::initialize DefaultUnder
2020-01-23T19:30:04.310Z,1579807804.310 [DefaultUnder:uModemComms] Running Loop=1
2020-01-23T19:30:04.311Z,1579807804.311 [DefaultUnder:uModemComms](DEBUG): Aggregate::initialize DefaultUnder:uModemComms
2020-01-23T19:30:04.311Z,1579807804.311 [DefaultUnder:Notify] Running Loop=1
2020-01-23T19:30:04.311Z,1579807804.311 [DefaultUnder:Notify](DEBUG): Aggregate::initialize DefaultUnder:Notify
2020-01-23T19:30:04.311Z,1579807804.311 [DefaultUnder:Notify:A] Running Loop=1
2020-01-23T19:30:04.311Z,1579807804.311 [DefaultUnder:Notify:A](DEBUG): Aggregate::initialize DefaultUnder:Notify:A
2020-01-23T19:30:04.311Z,1579807804.311 [DefaultUnder:Notify:A:A] Running Loop=1
2020-01-23T19:30:04.311Z,1579807804.311 [DefaultUnder:Notify:A:A](DEBUG): Aggregate::initialize DefaultUnder:Notify:A:A
2020-01-23T19:30:04.311Z,1579807804.311 [DefaultUnder:Notify:A:A:A.Wait] Running Loop=1
2020-01-23T19:30:04.311Z,1579807804.311 [DefaultUnder:Notify:A:A:A.Wait](DEBUG): Initialize Wait Component.
2020-01-23T19:30:04.311Z,1579807804.311 [DefaultUnder:C.] Running Loop=1
2020-01-23T19:30:04.312Z,1579807804.312 [DefaultUnder:C.](INFO): Initializing TrackAcousticContact.
2020-01-23T19:30:04.312Z,1579807804.312 [DefaultUnder:E.Wait] Running Loop=1
2020-01-23T19:30:04.312Z,1579807804.312 [DefaultUnder:E.Wait](DEBUG): Initialize Wait Component.
2020-01-23T19:30:04.313Z,1579807804.313 [DefaultUnder:uModemComms:CheckIn] Running Loop=1
2020-01-23T19:30:04.313Z,1579807804.313 [DefaultUnder:uModemComms:CheckIn](DEBUG): Aggregate::initialize DefaultUnder:uModemComms:CheckIn
2020-01-23T19:30:04.313Z,1579807804.313 [DefaultUnder:uModemComms:CheckIn:A] Running Loop=1
2020-01-23T19:30:04.355Z,1579807804.355 [Reporter](INFO): latitude 36.803398 arcdeg
2020-01-23T19:30:05.510Z,1579807805.510 [DataOverHttps](INFO): Moved sent file to Logs/20200123T191257/Express0008.lzma.bak
2020-01-23T19:30:05.511Z,1579807805.511 [DataOverHttps](INFO): SBD MOMSN=12199052
2020-01-23T19:30:12.226Z,1579807812.226 [CommandLine](IMPORTANT): got command restart application
2020-01-23T19:30:13.229Z,1579807813.229 [Supervisor](INFO): Stop Mission called by Supervisor::terminate
2020-01-23T19:30:13.229Z,1579807813.229 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2020-01-23T19:30:13.229Z,1579807813.229 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-01-23T19:30:13.361Z,1579807813.361 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2020-01-23T19:30:13.361Z,1579807813.361 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-01-23T19:30:13.362Z,1579807813.362 [CommandLine](INFO): Join timeout helper Thread ID is 8042
2020-01-23T19:30:13.365Z,1579807813.365 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2020-01-23T19:30:13.365Z,1579807813.365 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-01-23T19:30:13.365Z,1579807813.365 [NavChartDb](INFO): Join timeout helper Thread ID is 8043
2020-01-23T19:30:13.441Z,1579807813.441 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2020-01-23T19:30:13.441Z,1579807813.441 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-01-23T19:30:13.449Z,1579807813.449 [ComponentRegistry](INFO): Shutting down WetLabsSeaOWL_UV_A ThreadHandler
2020-01-23T19:30:13.449Z,1579807813.449 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2020-01-23T19:30:13.449Z,1579807813.449 [WetLabsSeaOWL_UV_A](INFO): Join timeout helper Thread ID is 8044
2020-01-23T19:30:13.701Z,1579807813.701 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Uninitializing protected caller thread.
2020-01-23T19:30:13.701Z,1579807813.701 [WetLabsSeaOWL_UV_A](INFO): Powering down
2020-01-23T19:30:13.702Z,1579807813.702 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2020-01-23T19:30:13.713Z,1579807813.713 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2020-01-23T19:30:13.713Z,1579807813.713 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2020-01-23T19:30:13.713Z,1579807813.713 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 8045
2020-01-23T19:30:13.901Z,1579807813.901 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2020-01-23T19:30:13.901Z,1579807813.901 [CTD_NeilBrown](INFO): Powering down
2020-01-23T19:30:13.913Z,1579807813.913 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2020-01-23T19:30:13.913Z,1579807813.913 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2020-01-23T19:30:13.913Z,1579807813.913 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-01-23T19:30:13.914Z,1579807813.914 [Radio_Surface](INFO): Join timeout helper Thread ID is 8046
2020-01-23T19:30:14.257Z,1579807814.257 [Radio_Surface](INFO): Powering down
2020-01-23T19:30:14.258Z,1579807814.258 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2020-01-23T19:30:14.258Z,1579807814.258 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-01-23T19:30:14.266Z,1579807814.266 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2020-01-23T19:30:14.266Z,1579807814.266 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2020-01-23T19:30:14.266Z,1579807814.266 [DataOverHttps](INFO): Join timeout helper Thread ID is 8047