2018-05-15T04:54:04.988Z,1526360044.988 [Supervisor](DEBUG): Initializing supervisor.
2018-05-15T04:54:04.990Z,1526360044.990 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2018-05-15T04:54:04.991Z,1526360044.991 [SyncHandler](INFO): Protected caller Thread ID is 9505
2018-05-15T04:54:04.991Z,1526360044.991 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2018-05-15T04:54:04.992Z,1526360044.992 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2018-05-15T04:54:04.993Z,1526360044.993 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 9506
2018-05-15T04:54:04.995Z,1526360044.995 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2018-05-15T04:54:05.006Z,1526360045.006 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2018-05-15T04:54:05.007Z,1526360045.007 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2018-05-15T04:54:05.007Z,1526360045.007 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 9507
2018-05-15T04:54:05.008Z,1526360045.008 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2018-05-15T04:54:05.009Z,1526360045.009 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2018-05-15T04:54:05.009Z,1526360045.009 [logger ThreadHandler](INFO): Protected caller Thread ID is 9508
2018-05-15T04:54:05.011Z,1526360045.011 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2018-05-15T04:54:05.011Z,1526360045.011 [Supervisor](INFO): Looking for Config files in directory: Config/
2018-05-15T04:54:05.013Z,1526360045.013 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2018-05-15T04:54:05.108Z,1526360045.108 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2018-05-15T04:54:05.109Z,1526360045.109 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2018-05-15T04:54:05.206Z,1526360045.206 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2018-05-15T04:54:05.206Z,1526360045.206 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2018-05-15T04:54:05.405Z,1526360045.405 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2018-05-15T04:54:05.406Z,1526360045.406 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2018-05-15T04:54:05.859Z,1526360045.859 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2018-05-15T04:54:05.859Z,1526360045.859 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2018-05-15T04:54:06.171Z,1526360046.171 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2018-05-15T04:54:06.172Z,1526360046.172 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2018-05-15T04:54:06.603Z,1526360046.603 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2018-05-15T04:54:06.604Z,1526360046.604 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2018-05-15T04:54:06.946Z,1526360046.946 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2018-05-15T04:54:06.947Z,1526360046.947 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2018-05-15T04:54:07.362Z,1526360047.362 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2018-05-15T04:54:07.363Z,1526360047.363 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2018-05-15T04:54:07.441Z,1526360047.441 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2018-05-15T04:54:07.721Z,1526360047.721 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2018-05-15T04:54:07.722Z,1526360047.722 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2018-05-15T04:54:07.859Z,1526360047.859 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2018-05-15T04:54:07.860Z,1526360047.860 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2018-05-15T04:54:08.059Z,1526360048.059 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2018-05-15T04:54:08.060Z,1526360048.060 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2018-05-15T04:54:08.260Z,1526360048.260 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2018-05-15T04:54:08.261Z,1526360048.261 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2018-05-15T04:54:08.355Z,1526360048.355 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2018-05-15T04:54:08.356Z,1526360048.356 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2018-05-15T04:54:08.490Z,1526360048.490 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2018-05-15T04:54:08.492Z,1526360048.492 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/
2018-05-15T04:54:08.493Z,1526360048.493 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg
2018-05-15T04:54:08.718Z,1526360048.718 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2018-05-15T04:54:08.719Z,1526360048.719 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg
2018-05-15T04:54:08.795Z,1526360048.795 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg
2018-05-15T04:54:08.930Z,1526360048.930 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg
2018-05-15T04:54:09.019Z,1526360049.019 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg
2018-05-15T04:54:09.102Z,1526360049.102 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg
2018-05-15T04:54:09.234Z,1526360049.234 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg
2018-05-15T04:54:09.400Z,1526360049.400 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg
2018-05-15T04:54:09.493Z,1526360049.493 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg
2018-05-15T04:54:09.583Z,1526360049.583 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg
2018-05-15T04:54:09.676Z,1526360049.676 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg
2018-05-15T04:54:09.758Z,1526360049.758 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/root/
2018-05-15T04:54:09.759Z,1526360049.759 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2018-05-15T04:54:09.772Z,1526360049.772 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2018-05-15T04:54:09.868Z,1526360049.868 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2018-05-15T04:54:09.868Z,1526360049.868 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2018-05-15T04:54:09.881Z,1526360049.881 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2018-05-15T04:54:09.882Z,1526360049.882 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2018-05-15T04:54:09.922Z,1526360049.922 [DepthRateCalculator] Loaded
2018-05-15T04:54:09.922Z,1526360049.922 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2018-05-15T04:54:09.927Z,1526360049.927 [PitchRateCalculator] Loaded
2018-05-15T04:54:09.928Z,1526360049.928 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2018-05-15T04:54:09.943Z,1526360049.943 [SpeedCalculator] Loaded
2018-05-15T04:54:09.943Z,1526360049.943 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2018-05-15T04:54:09.963Z,1526360049.963 [TempGradientCalculator] Loaded
2018-05-15T04:54:09.963Z,1526360049.963 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2018-05-15T04:54:09.978Z,1526360049.978 [VerticalTemperatureHomogeneityIndexCalculator] Loaded
2018-05-15T04:54:09.979Z,1526360049.979 [ComponentRegistry](DEBUG): SyncComponent "VerticalTemperatureHomogeneityIndexCalculator" handled in the control thread.
2018-05-15T04:54:09.984Z,1526360049.984 [YawRateCalculator] Loaded
2018-05-15T04:54:09.984Z,1526360049.984 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2018-05-15T04:54:10.022Z,1526360050.022 [ElevatorOffsetCalculator] Loaded
2018-05-15T04:54:10.022Z,1526360050.022 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2018-05-15T04:54:10.023Z,1526360050.023 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2018-05-15T04:54:10.023Z,1526360050.023 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2018-05-15T04:54:10.047Z,1526360050.047 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2018-05-15T04:54:10.048Z,1526360050.048 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2018-05-15T04:54:10.331Z,1526360050.331 [AHRS_M2] Loaded
2018-05-15T04:54:10.332Z,1526360050.332 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2018-05-15T04:54:10.374Z,1526360050.374 [AcousticModem_Benthos_ATM900] Loaded
2018-05-15T04:54:10.374Z,1526360050.374 [ComponentRegistry](DEBUG): SyncComponent "AcousticModem_Benthos_ATM900" handled in the control thread.
2018-05-15T04:54:10.440Z,1526360050.440 [DataOverHttps] Loaded
2018-05-15T04:54:10.440Z,1526360050.440 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2018-05-15T04:54:10.452Z,1526360050.452 [Depth_Keller] Loaded
2018-05-15T04:54:10.453Z,1526360050.453 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2018-05-15T04:54:10.453Z,1526360050.453 [Module Loader](CRITICAL): Could not find element GobyModem.loadAtStartup
2018-05-15T04:54:10.546Z,1526360050.546 [NAL9602] Loaded
2018-05-15T04:54:10.546Z,1526360050.546 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2018-05-15T04:54:10.561Z,1526360050.561 [Onboard] Loaded
2018-05-15T04:54:10.561Z,1526360050.561 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2018-05-15T04:54:10.571Z,1526360050.571 [Radio_Surface] Loaded
2018-05-15T04:54:10.571Z,1526360050.571 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2018-05-15T04:54:10.572Z,1526360050.572 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 407B74E0
2018-05-15T04:54:10.573Z,1526360050.573 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 9587
2018-05-15T04:54:10.573Z,1526360050.573 [Module Loader](CRITICAL): Could not find element RDI_Pathfinder.loadAtStartup
2018-05-15T04:54:12.582Z,1526360052.582 [BPC1] Loaded
2018-05-15T04:54:12.582Z,1526360052.582 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2018-05-15T04:54:12.583Z,1526360052.583 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2018-05-15T04:54:12.583Z,1526360052.583 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2018-05-15T04:54:12.707Z,1526360052.707 [SBIT](DEBUG): Construct Startup Built In Test.
2018-05-15T04:54:12.729Z,1526360052.729 [SBIT] Loaded
2018-05-15T04:54:12.730Z,1526360052.730 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2018-05-15T04:54:12.730Z,1526360052.730 [IBIT](DEBUG): Construct Initiated Built In Test.
2018-05-15T04:54:12.741Z,1526360052.741 [IBIT] Loaded
2018-05-15T04:54:12.741Z,1526360052.741 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2018-05-15T04:54:12.744Z,1526360052.744 [CBIT](DEBUG): Construct Continuous Built In Test.
2018-05-15T04:54:12.887Z,1526360052.887 [CBIT] Loaded
2018-05-15T04:54:12.888Z,1526360052.888 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2018-05-15T04:54:12.888Z,1526360052.888 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2018-05-15T04:54:12.889Z,1526360052.889 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2018-05-15T04:54:13.052Z,1526360053.052 [CTD_Seabird] Loaded
2018-05-15T04:54:13.052Z,1526360053.052 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2018-05-15T04:54:13.053Z,1526360053.053 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 408774E0
2018-05-15T04:54:13.053Z,1526360053.053 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 9588
2018-05-15T04:54:13.069Z,1526360053.069 [ESPComponent] Loaded
2018-05-15T04:54:13.070Z,1526360053.070 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2018-05-15T04:54:13.083Z,1526360053.083 [PAR_Licor] Loaded
2018-05-15T04:54:13.083Z,1526360053.083 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2018-05-15T04:54:13.084Z,1526360053.084 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2018-05-15T04:54:13.085Z,1526360053.085 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2018-05-15T04:54:13.313Z,1526360053.313 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2018-05-15T04:54:13.314Z,1526360053.314 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2018-05-15T04:54:13.377Z,1526360053.377 [VerticalControl](DEBUG): Construct VerticalControl.
2018-05-15T04:54:13.468Z,1526360053.468 [VerticalControl] Loaded
2018-05-15T04:54:13.468Z,1526360053.468 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2018-05-15T04:54:13.469Z,1526360053.469 [HorizontalControl](DEBUG): Construct HorizontalControl.
2018-05-15T04:54:13.527Z,1526360053.527 [HorizontalControl] Loaded
2018-05-15T04:54:13.527Z,1526360053.527 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2018-05-15T04:54:13.528Z,1526360053.528 [SpeedControl](DEBUG): Construct SpeedControl.
2018-05-15T04:54:13.533Z,1526360053.533 [SpeedControl] Loaded
2018-05-15T04:54:13.533Z,1526360053.533 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2018-05-15T04:54:13.534Z,1526360053.534 [LoopControl](DEBUG): Construct LoopControl.
2018-05-15T04:54:13.534Z,1526360053.534 [LoopControl] Loaded
2018-05-15T04:54:13.534Z,1526360053.534 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2018-05-15T04:54:13.535Z,1526360053.535 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2018-05-15T04:54:13.535Z,1526360053.535 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2018-05-15T04:54:13.615Z,1526360053.615 [StratificationFrontDetector](INFO): threshold set to: 0.399988 degC
2018-05-15T04:54:13.616Z,1526360053.616 [StratificationFrontDetector](DEBUG): (re)initializing
2018-05-15T04:54:13.616Z,1526360053.616 [StratificationFrontDetector] Loaded
2018-05-15T04:54:13.616Z,1526360053.616 [ComponentRegistry](DEBUG): SyncComponent "StratificationFrontDetector" handled in the control thread.
2018-05-15T04:54:13.617Z,1526360053.617 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2018-05-15T04:54:13.617Z,1526360053.617 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2018-05-15T04:54:13.711Z,1526360053.711 [BuoyancyServo] Loaded
2018-05-15T04:54:13.711Z,1526360053.711 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2018-05-15T04:54:13.722Z,1526360053.722 [ElevatorServo] Loaded
2018-05-15T04:54:13.722Z,1526360053.722 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2018-05-15T04:54:13.733Z,1526360053.733 [MassServo] Loaded
2018-05-15T04:54:13.733Z,1526360053.733 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2018-05-15T04:54:13.744Z,1526360053.744 [RudderServo] Loaded
2018-05-15T04:54:13.744Z,1526360053.744 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2018-05-15T04:54:13.754Z,1526360053.754 [ThrusterServo] Loaded
2018-05-15T04:54:13.755Z,1526360053.755 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2018-05-15T04:54:13.755Z,1526360053.755 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2018-05-15T04:54:13.756Z,1526360053.756 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2018-05-15T04:54:13.850Z,1526360053.850 [DeadReckonUsingMultipleVelocitySources] Loaded
2018-05-15T04:54:13.850Z,1526360053.850 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2018-05-15T04:54:13.903Z,1526360053.903 [DeadReckonUsingSpeedCalculator] Loaded
2018-05-15T04:54:13.903Z,1526360053.903 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2018-05-15T04:54:13.919Z,1526360053.919 [NavChart] Loaded
2018-05-15T04:54:13.919Z,1526360053.919 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2018-05-15T04:54:13.923Z,1526360053.923 [UniversalFixResidualReporter] Loaded
2018-05-15T04:54:13.923Z,1526360053.923 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2018-05-15T04:54:13.924Z,1526360053.924 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2018-05-15T04:54:13.927Z,1526360053.927 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2018-05-15T04:54:13.928Z,1526360053.928 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2018-05-15T04:54:13.935Z,1526360053.935 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2018-05-15T04:54:13.936Z,1526360053.936 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 409D04E0
2018-05-15T04:54:13.936Z,1526360053.936 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 9589
2018-05-15T04:54:13.941Z,1526360053.941 [Supervisor](INFO): Main Thread ID is 9372
2018-05-15T04:54:13.941Z,1526360053.941 [Supervisor](DEBUG): Running supervisor.
2018-05-15T04:54:13.941Z,1526360053.941 [CommandLine ThreadHandler](INFO): Handler Thread ID is 9590
2018-05-15T04:54:13.944Z,1526360053.944 [controlThread ThreadHandler](INFO): Handler Thread ID is 9591
2018-05-15T04:54:13.944Z,1526360053.944 [controlThread](DEBUG): Initializing ControlThread
2018-05-15T04:54:13.945Z,1526360053.945 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2018-05-15T04:54:13.945Z,1526360053.945 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2018-05-15T04:54:13.946Z,1526360053.946 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2018-05-15T04:54:13.946Z,1526360053.946 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2018-05-15T04:54:13.947Z,1526360053.947 [VerticalTemperatureHomogeneityIndexCalculator](DEBUG): (re)initializing
2018-05-15T04:54:13.947Z,1526360053.947 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2018-05-15T04:54:13.948Z,1526360053.948 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2018-05-15T04:54:13.954Z,1526360053.954 [SBIT](INFO): Initialize SBIT Component.
2018-05-15T04:54:13.954Z,1526360053.954 [SBIT](IMPORTANT): git: 2018-03-26-63-g035c652
2018-05-15T04:54:13.954Z,1526360053.954 [SBIT](INFO): git hash: 035c652db7f27c72339a0dc8ffe46f005dcbcd78
2018-05-15T04:54:13.955Z,1526360053.955 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2018-05-15T04:54:13.956Z,1526360053.956 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #639 PREEMPT Wed Mar 12 12:53:33 PDT 2014
Kernel Reported: #16 PREEMPT Thu Apr 12 16:20:47 PDT 2018
2018-05-15T04:54:13.957Z,1526360053.957 [SBIT](INFO): Beginning SBIT in 52.000000 seconds.
2018-05-15T04:54:13.957Z,1526360053.957 [IBIT](INFO): Initialize IBIT Component.
2018-05-15T04:54:13.958Z,1526360053.958 [CBIT](DEBUG): Initialize CBIT Component.
2018-05-15T04:54:13.959Z,1526360053.959 [CBIT](CRITICAL): LAST REBOOT DUE TO WATCHDOG TIMER RESET.
2018-05-15T04:54:13.959Z,1526360053.959 [logger ThreadHandler](INFO): Handler Thread ID is 9592
2018-05-15T04:54:13.977Z,1526360053.977 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 9593
2018-05-15T04:54:13.983Z,1526360053.983 [Radio_Surface](INFO): Powering up
2018-05-15T04:54:13.989Z,1526360053.989 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 9594
2018-05-15T04:54:13.990Z,1526360053.990 [CTD_Seabird](INFO): Initializing
2018-05-15T04:54:13.990Z,1526360053.990 [CTD_Seabird](INFO): Checking LCM
2018-05-15T04:54:13.999Z,1526360053.999 [CTD_Seabird](INFO): LCM OK
2018-05-15T04:54:13.999Z,1526360053.999 [CTD_Seabird](INFO): Powering up
2018-05-15T04:54:14.005Z,1526360054.005 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 9595
2018-05-15T04:54:14.008Z,1526360054.008 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2018-05-15T04:54:14.009Z,1526360054.009 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2018-05-15T04:54:14.009Z,1526360054.009 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2018-05-15T04:54:14.009Z,1526360054.009 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2018-05-15T04:54:14.009Z,1526360054.009 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2018-05-15T04:54:14.009Z,1526360054.009 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2018-05-15T04:54:14.010Z,1526360054.010 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2018-05-15T04:54:14.010Z,1526360054.010 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2018-05-15T04:54:14.010Z,1526360054.010 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2018-05-15T04:54:14.010Z,1526360054.010 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2018-05-15T04:54:14.010Z,1526360054.010 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2018-05-15T04:54:14.011Z,1526360054.011 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2018-05-15T04:54:14.011Z,1526360054.011 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2018-05-15T04:54:14.011Z,1526360054.011 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2018-05-15T04:54:14.011Z,1526360054.011 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2018-05-15T04:54:14.011Z,1526360054.011 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2018-05-15T04:54:14.069Z,1526360054.069 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2018-05-15T04:54:14.071Z,1526360054.071 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2018-05-15T04:54:14.071Z,1526360054.071 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2018-05-15T04:54:14.072Z,1526360054.072 [LoopControl](DEBUG): Initialize LoopControlComponent.
2018-05-15T04:54:14.074Z,1526360054.074 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2018-05-15T04:54:14.074Z,1526360054.074 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s.
2018-05-15T04:54:14.075Z,1526360054.075 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s.
2018-05-15T04:54:14.075Z,1526360054.075 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-05-15T04:54:14.076Z,1526360054.076 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-05-15T04:54:14.076Z,1526360054.076 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-05-15T04:54:14.076Z,1526360054.076 [NavChart](DEBUG): Initialize NavChart Navigation.
2018-05-15T04:54:14.077Z,1526360054.077 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2018-05-15T04:54:14.078Z,1526360054.078 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2018-05-15T04:54:14.109Z,1526360054.109 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2018-05-15T04:54:14.131Z,1526360054.131 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
       Id="Startup">

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

    <Aggregate Id="StartupSatComms">

        <Sequence/>

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

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

    </Aggregate>

</Mission>


2018-05-15T04:54:14.132Z,1526360054.132 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2018-05-15T04:54:14.234Z,1526360054.234 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2018-05-15T04:54:14.237Z,1526360054.237 [Default:A.Wait](DEBUG): Construct Wait.
2018-05-15T04:54:14.239Z,1526360054.239 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2018-05-15T04:54:14.266Z,1526360054.266 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2018-05-15T04:54:14.268Z,1526360054.268 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2018-05-15T04:54:14.290Z,1526360054.290 [Default:E.Execute](DEBUG): Construct Execute.
2018-05-15T04:54:14.294Z,1526360054.294 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
xmlns:Guidance="Tethys/Guidance"
xmlns:Units="Tethys/Units"
xmlns:Universal="Tethys/Universal"
xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
Id="Default">

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

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

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

    <Aggregate Id="CheckIn">

        <Sequence Repeat="288"/>

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

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

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

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

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

    </Aggregate>

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

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

</Mission>


2018-05-15T04:54:14.313Z,1526360054.313 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,AcousticModem_Benthos_ATM900,DataOverHttps,Depth_Keller,NAL9602,Onboard,BPC1,ESPComponent,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,VerticalTemperatureHomogeneityIndexCalculator,YawRateCalculator,ElevatorOffsetCalculator,StratificationFrontDetector,DeadReckonUsingMultipleVelocitySources,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2018-05-15T04:54:14.321Z,1526360054.321 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2018-05-15T04:54:14.383Z,1526360054.383 [AcousticModem_Benthos_ATM900](INFO): Powering up
2018-05-15T04:54:14.384Z,1526360054.384 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900.
2018-05-15T04:54:14.412Z,1526360054.412 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2018-05-15T04:54:14.420Z,1526360054.420 [Depth_Keller](ERROR): Pressure reading out of range: 1895.584351 decibar
2018-05-15T04:54:14.614Z,1526360054.614 [ESPComponent](INFO): powering down ESP
2018-05-15T04:54:15.030Z,1526360055.030 [DepthRateCalculator](ERROR): Depth measurement is not active
2018-05-15T04:54:15.129Z,1526360055.129 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T04:54:15.149Z,1526360055.149 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T04:54:15.249Z,1526360055.249 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2018-05-15T04:54:15.257Z,1526360055.257 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2018-05-15T04:54:15.271Z,1526360055.271 [ElevatorServo](DEBUG): Initializing EZServoServo.
2018-05-15T04:54:15.277Z,1526360055.277 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2018-05-15T04:54:15.299Z,1526360055.299 [MassServo](DEBUG): Initializing EZServoServo.
2018-05-15T04:54:15.305Z,1526360055.305 [MassServo](DEBUG): Initializing MassServo.
2018-05-15T04:54:15.319Z,1526360055.319 [RudderServo](DEBUG): Initializing EZServoServo.
2018-05-15T04:54:15.325Z,1526360055.325 [RudderServo](DEBUG): Initializing RudderServo.
2018-05-15T04:54:15.338Z,1526360055.338 [ThrusterServo](DEBUG): Initializing EZServoServo.
2018-05-15T04:54:15.345Z,1526360055.345 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2018-05-15T04:54:15.390Z,1526360055.390 [CommandLine](FAULT): Scheduling is paused
2018-05-15T04:54:15.390Z,1526360055.390 [CBIT](INFO): Critical error at 20180515T045413
2018-05-15T04:54:15.390Z,1526360055.390 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2018-05-15T04:54:15.634Z,1526360055.634 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T04:54:15.635Z,1526360055.635 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T04:54:15.913Z,1526360055.913 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T04:54:15.914Z,1526360055.914 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T04:54:16.433Z,1526360056.433 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T04:54:16.434Z,1526360056.434 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T04:54:16.818Z,1526360056.818 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T04:54:16.819Z,1526360056.819 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T04:54:17.208Z,1526360057.208 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T04:54:17.213Z,1526360057.213 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T04:54:17.608Z,1526360057.608 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T04:54:17.617Z,1526360057.617 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T04:54:18.008Z,1526360058.008 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T04:54:18.021Z,1526360058.021 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T04:54:18.405Z,1526360058.405 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T04:54:18.406Z,1526360058.406 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T04:54:18.778Z,1526360058.778 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T04:54:18.779Z,1526360058.779 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T04:54:19.176Z,1526360059.176 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T04:54:19.185Z,1526360059.185 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T04:54:19.521Z,1526360059.521 [AHRS_M2](FAULT): Failed to initialize
2018-05-15T04:54:19.521Z,1526360059.521 [AHRS_M2] Communications Fault, FailCount= 1
2018-05-15T04:54:19.522Z,1526360059.522 [AHRS_M2](ERROR): Communications Fault
2018-05-15T04:54:19.595Z,1526360059.595 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T04:54:19.596Z,1526360059.596 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T04:54:19.609Z,1526360059.609 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface
2018-05-15T04:54:19.708Z,1526360059.708 [CTD_Seabird](INFO): Started Seabird LCM interface with command:nohup ./lrauv-framework/onboard/bin/gpctd -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyC6 -b 9600 >& /dev/null &
2018-05-15T04:54:19.738Z,1526360059.738 [CBIT](ERROR): Communications Fault in component: AHRS_M2
2018-05-15T04:54:19.766Z,1526360059.766 [CTD_Seabird](INFO): LCM subscribed to channel:ctd_t.seabird-gpctd
2018-05-15T04:54:19.946Z,1526360059.946 [AHRS_M2](INFO): Powering down
2018-05-15T04:54:20.003Z,1526360060.003 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T04:54:20.005Z,1526360060.005 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T04:54:20.172Z,1526360060.172 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface
2018-05-15T04:54:20.173Z,1526360060.173 [CTD_Seabird](INFO): Powering down
2018-05-15T04:54:20.373Z,1526360060.373 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T04:54:20.374Z,1526360060.374 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T04:54:20.770Z,1526360060.770 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T04:54:20.771Z,1526360060.771 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T04:54:21.207Z,1526360061.207 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T04:54:21.208Z,1526360061.208 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T04:54:21.554Z,1526360061.554 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T04:54:21.555Z,1526360061.555 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T04:54:21.617Z,1526360061.617 [CBIT](INFO): Clearing failed state for component AHRS_M2
2018-05-15T04:54:21.617Z,1526360061.617 [AHRS_M2] No Fault, FailCount= 1
2018-05-15T04:54:21.921Z,1526360061.921 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2018-05-15T04:54:21.929Z,1526360061.929 [AcousticModem_Benthos_ATM900](DEBUG): 
2018-05-15T04:54:22.005Z,1526360062.005 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T04:54:22.006Z,1526360062.006 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T04:54:22.381Z,1526360062.381 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T04:54:22.382Z,1526360062.382 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T04:54:22.773Z,1526360062.773 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T04:54:22.774Z,1526360062.774 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T04:54:23.147Z,1526360063.147 [AcousticModem_Benthos_ATM900](DEBUG): Teledyne Benthos ATM-900 Series OEM w/burn wire
2018-05-15T04:54:23.148Z,1526360063.148 [AcousticModem_Benthos_ATM900](DEBUG): MF Frequency Band
2018-05-15T04:54:23.148Z,1526360063.148 [AcousticModem_Benthos_ATM900](DEBUG): Standard version 8.6.3
2018-05-15T04:54:23.149Z,1526360063.149 [AcousticModem_Benthos_ATM900](DEBUG): Apr  6 2000 13:19:23 
2018-05-15T04:54:23.217Z,1526360063.217 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T04:54:23.218Z,1526360063.218 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T04:54:23.527Z,1526360063.527 [AcousticModem_Benthos_ATM900](DEBUG): WARNING: battery low
2018-05-15T04:54:24.335Z,1526360064.335 [AcousticModem_Benthos_ATM900](INFO): entering command mode
2018-05-15T04:54:24.723Z,1526360064.723 [AcousticModem_Benthos_ATM900](DEBUG): checking for command mode acknowledgment
2018-05-15T04:54:24.724Z,1526360064.724 [AcousticModem_Benthos_ATM900](DEBUG): read user prompt 1: user:1>
2018-05-15T04:54:24.724Z,1526360064.724 [AcousticModem_Benthos_ATM900](INFO): command mode acknowledged
2018-05-15T04:54:25.123Z,1526360065.123 [AcousticModem_Benthos_ATM900](INFO): setting local address to 3
2018-05-15T04:54:25.535Z,1526360065.535 [AcousticModem_Benthos_ATM900](DEBUG): checking for local address setting acknowledgment
2018-05-15T04:54:25.535Z,1526360065.535 [AcousticModem_Benthos_ATM900](INFO): set local address to 3
2018-05-15T04:54:25.924Z,1526360065.924 [AcousticModem_Benthos_ATM900](DEBUG): read user prompt 2: user:2>
2018-05-15T04:54:46.326Z,1526360086.326 [NAL9602](INFO): No messages in MT queue
2018-05-15T04:55:06.399Z,1526360106.399 [SBIT](IMPORTANT): Beginning Startup BIT
2018-05-15T04:55:06.419Z,1526360106.419 [CBIT](IMPORTANT): Beginning ground fault scan
2018-05-15T04:55:17.345Z,1526360117.345 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.007900
CHAN A1 (24V): -0.010774
CHAN A2 (12V): -0.005532
CHAN A3 (5V): -0.002864
CHAN B0 (3.3V): -0.000896
CHAN B1 (3.15aV): -0.000593
CHAN B2 (3.15bV): -0.001375
CHAN B3 (GND): -0.000126
OPEN: -0.001101
Full Scale Calc: 4.765 mA, -1.589 mA
2018-05-15T04:55:35.815Z,1526360135.815 [CommandLine](IMPORTANT): got command maintain sensor NAL9602.latitude_fix 36.796001 degree
2018-05-15T04:55:35.816Z,1526360135.816 [ComponentRegistry](DEBUG): SyncComponent "Maintain_NAL9602.latitude_fix" handled in the control thread.
2018-05-15T04:55:35.817Z,1526360135.817 [CommandLine](IMPORTANT): got command maintain sensor NAL9602.longitude_fix -121.911003 degree
2018-05-15T04:55:35.818Z,1526360135.818 [ComponentRegistry](DEBUG): SyncComponent "Maintain_NAL9602.longitude_fix" handled in the control thread.
2018-05-15T04:55:35.958Z,1526360135.958 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,AcousticModem_Benthos_ATM900,DataOverHttps,Depth_Keller,NAL9602,Onboard,BPC1,ESPComponent,PAR_Licor,Depth_Keller,PAR_Licor,Maintain_NAL9602.latitude_fix,Maintain_NAL9602.longitude_fix,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,VerticalTemperatureHomogeneityIndexCalculator,YawRateCalculator,ElevatorOffsetCalculator,StratificationFrontDetector,DeadReckonUsingMultipleVelocitySources,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2018-05-15T04:55:56.695Z,1526360156.695 [CommandLine](IMPORTANT): got command maintain sensor Depth_Keller.depth 0.000000 meter
2018-05-15T04:55:56.696Z,1526360156.696 [ComponentRegistry](DEBUG): SyncComponent "Maintain_Depth_Keller.depth" handled in the control thread.
2018-05-15T04:55:56.785Z,1526360156.785 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,AcousticModem_Benthos_ATM900,DataOverHttps,Depth_Keller,NAL9602,Onboard,BPC1,ESPComponent,PAR_Licor,Depth_Keller,PAR_Licor,Maintain_NAL9602.latitude_fix,Maintain_NAL9602.longitude_fix,Maintain_Depth_Keller.depth,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,VerticalTemperatureHomogeneityIndexCalculator,YawRateCalculator,ElevatorOffsetCalculator,StratificationFrontDetector,DeadReckonUsingMultipleVelocitySources,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2018-05-15T04:56:00.385Z,1526360160.385 [SBIT](IMPORTANT): SBIT PASSED
2018-05-15T04:56:00.429Z,1526360160.429 [CommandLine](IMPORTANT): got command configSet list
2018-05-15T04:56:00.429Z,1526360160.429 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2018-05-15T04:56:00.431Z,1526360160.431 [CommandLine](IMPORTANT): Aanderaa_O2.loadAtStartup=0 bool;

2018-05-15T04:56:00.431Z,1526360160.431 [CommandLine](IMPORTANT): CBIT.abortDepth=300 meter;

2018-05-15T04:56:00.431Z,1526360160.431 [CommandLine](IMPORTANT): CBIT.gf24Offset=107 microampere;

2018-05-15T04:56:00.431Z,1526360160.431 [CommandLine](IMPORTANT): CBIT.stopDepth=285 meter;

2018-05-15T04:56:00.431Z,1526360160.431 [CommandLine](IMPORTANT): DropWeight.loadAtStartup=0 bool;

2018-05-15T04:56:00.431Z,1526360160.431 [CommandLine](IMPORTANT): ESPComponent.simulateHardware=0 bool;

2018-05-15T04:56:00.431Z,1526360160.431 [CommandLine](IMPORTANT): ElevatorOffsetCalculator.loadAtStartup=1 bool;

2018-05-15T04:56:00.432Z,1526360160.432 [CommandLine](IMPORTANT): NAL9602.simulateHardware=1 bool;

2018-05-15T04:56:00.432Z,1526360160.432 [CommandLine](IMPORTANT): Normal all CTD_Seabird.sea_water_salinity;

2018-05-15T04:56:00.432Z,1526360160.432 [CommandLine](IMPORTANT): Normal all CTD_Seabird.sea_water_temperature;

2018-05-15T04:56:00.432Z,1526360160.432 [CommandLine](IMPORTANT): Rowe_600LCM.loadAtStartup=0 bool;

2018-05-15T04:56:00.432Z,1526360160.432 [CommandLine](IMPORTANT): RudderServo.offsetAngle=0.5 degree;

2018-05-15T04:56:00.432Z,1526360160.432 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=130 cubic_centimeter;

2018-05-15T04:56:00.432Z,1526360160.432 [CommandLine](IMPORTANT): VerticalControl.massDefault=8 millimeter;

2018-05-15T04:56:00.433Z,1526360160.433 [CommandLine](IMPORTANT): WetLabsBB2FL.loadAtStartup=0 bool;

2018-05-15T04:56:00.767Z,1526360160.767 [MissionManager](IMPORTANT): Started mission Startup
2018-05-15T04:56:00.768Z,1526360160.768 [Startup] Running Loop=1
2018-05-15T04:56:00.768Z,1526360160.768 [Startup](DEBUG): Aggregate::initialize Startup
2018-05-15T04:56:00.768Z,1526360160.768 [Startup:A.GoToSurface] Running Loop=1
2018-05-15T04:56:00.768Z,1526360160.768 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-05-15T04:56:00.769Z,1526360160.769 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2018-05-15T04:56:00.769Z,1526360160.769 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2018-05-15T04:56:00.769Z,1526360160.769 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2018-05-15T04:56:00.770Z,1526360160.770 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-05-15T04:56:00.770Z,1526360160.770 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2018-05-15T04:56:00.776Z,1526360160.776 [Startup:StartupSatComms] Running Loop=1
2018-05-15T04:56:00.776Z,1526360160.776 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2018-05-15T04:56:00.776Z,1526360160.776 [Startup:StartupSatComms:A] Running Loop=1
2018-05-15T04:56:01.179Z,1526360161.179 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2018-05-15T04:56:01.181Z,1526360161.181 [Startup:StartupSatComms:A] Stopped
2018-05-15T04:56:01.181Z,1526360161.181 [Startup:StartupSatComms:B] Running Loop=1
2018-05-15T04:56:01.575Z,1526360161.575 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2018-05-15T04:56:37.526Z,1526360197.526 [NAL9602](INFO): Sent 43 bytes from file Logs/20180514T235826/Courier0025.lzma
2018-05-15T04:56:37.526Z,1526360197.526 [NAL9602](INFO): Packets left to send: 0
2018-05-15T04:56:37.528Z,1526360197.528 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180514T235826/Courier0025.lzma.parts/0000.sbd
2018-05-15T04:56:37.529Z,1526360197.529 [NAL9602](DEBUG): Completed sending Logs/20180514T235826/Courier0025.lzma
2018-05-15T04:57:01.563Z,1526360221.563 [Startup:StartupSatComms:B](INFO): Timed out from 2018-05-15T04:56:01.2Z
2018-05-15T04:57:01.563Z,1526360221.563 [Startup:StartupSatComms:B] Stopped
2018-05-15T04:57:01.563Z,1526360221.563 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2018-05-15T04:57:01.563Z,1526360221.563 [Startup:StartupSatComms] Stopped
2018-05-15T04:57:01.564Z,1526360221.564 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2018-05-15T04:57:01.564Z,1526360221.564 [Startup](INFO): Completed Startup
2018-05-15T04:57:01.565Z,1526360221.565 [MissionManager](INFO): Startup is completed.
2018-05-15T04:57:01.565Z,1526360221.565 [MissionManager](INFO): Uninitializing Mission Startup
2018-05-15T04:57:01.565Z,1526360221.565 [Startup] Stopped
2018-05-15T04:57:01.565Z,1526360221.565 [Startup](DEBUG): Aggregate::uninitialize Startup
2018-05-15T04:57:01.565Z,1526360221.565 [Startup:A.GoToSurface] Stopped
2018-05-15T04:57:01.565Z,1526360221.565 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2018-05-15T04:57:01.974Z,1526360221.974 [MissionManager](IMPORTANT): Started mission Default
2018-05-15T04:57:01.974Z,1526360221.974 [Default] Running Loop=1
2018-05-15T04:57:01.974Z,1526360221.974 [Default](DEBUG): Aggregate::initialize Default
2018-05-15T04:57:01.974Z,1526360221.974 [Default:B.GoToSurface] Running Loop=1
2018-05-15T04:57:01.974Z,1526360221.974 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-05-15T04:57:01.974Z,1526360221.974 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2018-05-15T04:57:01.975Z,1526360221.975 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2018-05-15T04:57:01.975Z,1526360221.975 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2018-05-15T04:57:01.975Z,1526360221.975 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-05-15T04:57:01.976Z,1526360221.976 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2018-05-15T04:57:01.976Z,1526360221.976 [Default:A.Wait] Running Loop=1
2018-05-15T04:57:01.976Z,1526360221.976 [Default:A.Wait](DEBUG): Initialize Wait Component.
2018-05-15T04:57:08.726Z,1526360228.726 [NAL9602](INFO): Sent 188 bytes from file Logs/20180515T045110/Courier0000.lzma
2018-05-15T04:57:08.726Z,1526360228.726 [NAL9602](INFO): Packets left to send: 0
2018-05-15T04:57:08.728Z,1526360228.728 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180515T045110/Courier0000.lzma.parts/0000.sbd
2018-05-15T04:57:08.728Z,1526360228.728 [NAL9602](DEBUG): Completed sending Logs/20180515T045110/Courier0000.lzma
2018-05-15T04:57:14.371Z,1526360234.371 [DeadReckonUsingMultipleVelocitySources](ERROR): Will not write estimated position: latitudeAccuracy_ = 0.000000, longitudeAccuracy_ = 0.000000, depthAccuracy_ = nan
2018-05-15T04:57:14.371Z,1526360234.371 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2018-05-15T04:57:14.371Z,1526360234.371 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2018-05-15T04:57:14.373Z,1526360234.373 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = 0.000000, longitudeAccuracy_ = 0.000000, depthAccuracy_ = nan
2018-05-15T04:57:14.373Z,1526360234.373 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1
2018-05-15T04:57:14.373Z,1526360234.373 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-05-15T04:57:14.385Z,1526360234.385 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2018-05-15T04:57:14.385Z,1526360234.385 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-05-15T04:57:14.788Z,1526360234.788 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2018-05-15T04:57:14.788Z,1526360234.788 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2018-05-15T04:57:14.789Z,1526360234.789 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-05-15T04:57:14.789Z,1526360234.789 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1
2018-05-15T04:57:15.176Z,1526360235.176 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2018-05-15T04:57:15.176Z,1526360235.176 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s.
2018-05-15T04:57:15.177Z,1526360235.177 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s.
2018-05-15T04:57:15.189Z,1526360235.189 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-05-15T04:57:15.189Z,1526360235.189 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-05-15T04:57:15.190Z,1526360235.190 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-05-15T04:57:15.191Z,1526360235.191 [Default:A.Wait](INFO): Done Waiting.
2018-05-15T04:57:15.192Z,1526360235.192 [Default:A.Wait] Stopped
2018-05-15T04:57:15.192Z,1526360235.192 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2018-05-15T04:57:18.278Z,1526360238.278 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 3.9 s old, using for 20.0 s.
2018-05-15T04:57:18.281Z,1526360238.281 [Default:CheckIn] Running Loop=1
2018-05-15T04:57:18.281Z,1526360238.281 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-05-15T04:57:18.281Z,1526360238.281 [Default:CheckIn:Read_GPS] Running Loop=1
2018-05-15T04:57:18.400Z,1526360238.400 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.0 s old, using for 20.0 s.
2018-05-15T04:57:18.415Z,1526360238.415 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2018-05-15T04:57:18.748Z,1526360238.748 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.4 s old, using for 20.0 s.
2018-05-15T04:57:19.105Z,1526360239.105 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004427
2018-05-15T04:57:19.153Z,1526360239.153 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.8 s old, using for 20.0 s.
2018-05-15T04:57:19.545Z,1526360239.545 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 5.2 s old, using for 20.0 s.
2018-05-15T04:57:19.944Z,1526360239.944 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 5.6 s old, using for 20.0 s.
2018-05-15T04:57:20.343Z,1526360240.343 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.0 s old, using for 20.0 s.
2018-05-15T04:57:20.745Z,1526360240.745 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.4 s old, using for 20.0 s.
2018-05-15T04:57:21.144Z,1526360241.144 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.8 s old, using for 20.0 s.
2018-05-15T04:57:21.543Z,1526360241.543 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 7.2 s old, using for 20.0 s.
2018-05-15T04:57:21.945Z,1526360241.945 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 7.6 s old, using for 20.0 s.
2018-05-15T04:57:22.335Z,1526360242.335 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 8.0 s old, using for 20.0 s.
2018-05-15T04:57:22.749Z,1526360242.749 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 8.4 s old, using for 20.0 s.
2018-05-15T04:57:23.151Z,1526360243.151 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 8.8 s old, using for 20.0 s.
2018-05-15T04:57:23.527Z,1526360243.527 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 9.2 s old, using for 20.0 s.
2018-05-15T04:57:23.932Z,1526360243.932 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 9.6 s old, using for 20.0 s.
2018-05-15T04:57:24.332Z,1526360244.332 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 10.0 s old, using for 20.0 s.
2018-05-15T04:57:24.733Z,1526360244.733 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 10.4 s old, using for 20.0 s.
2018-05-15T04:57:25.133Z,1526360245.133 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 10.8 s old, using for 20.0 s.
2018-05-15T04:57:25.532Z,1526360245.532 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 11.2 s old, using for 20.0 s.
2018-05-15T04:57:25.932Z,1526360245.932 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 11.6 s old, using for 20.0 s.
2018-05-15T04:57:26.332Z,1526360246.332 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 12.0 s old, using for 20.0 s.
2018-05-15T04:57:26.736Z,1526360246.736 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 12.4 s old, using for 20.0 s.
2018-05-15T04:57:27.133Z,1526360247.133 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 12.8 s old, using for 20.0 s.
2018-05-15T04:57:27.532Z,1526360247.532 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 13.2 s old, using for 20.0 s.
2018-05-15T04:57:27.932Z,1526360247.932 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 13.6 s old, using for 20.0 s.
2018-05-15T04:57:28.333Z,1526360248.333 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 14.0 s old, using for 20.0 s.
2018-05-15T04:57:28.732Z,1526360248.732 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 14.4 s old, using for 20.0 s.
2018-05-15T04:57:29.133Z,1526360249.133 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 14.8 s old, using for 20.0 s.
2018-05-15T04:57:29.533Z,1526360249.533 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 15.2 s old, using for 20.0 s.
2018-05-15T04:57:29.933Z,1526360249.933 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 15.6 s old, using for 20.0 s.
2018-05-15T04:57:30.340Z,1526360250.340 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 16.0 s old, using for 20.0 s.
2018-05-15T04:57:30.758Z,1526360250.758 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 16.4 s old, using for 20.0 s.
2018-05-15T04:57:31.143Z,1526360251.143 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 16.8 s old, using for 20.0 s.
2018-05-15T04:57:31.535Z,1526360251.535 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 17.2 s old, using for 20.0 s.
2018-05-15T04:57:31.941Z,1526360251.941 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 17.6 s old, using for 20.0 s.
2018-05-15T04:57:32.340Z,1526360252.340 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 18.0 s old, using for 20.0 s.
2018-05-15T04:57:32.779Z,1526360252.779 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 18.4 s old, using for 20.0 s.
2018-05-15T04:57:33.132Z,1526360253.132 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 18.8 s old, using for 20.0 s.
2018-05-15T04:57:33.579Z,1526360253.579 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 19.2 s old, using for 20.0 s.
2018-05-15T04:57:33.979Z,1526360253.979 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 19.6 s old, using for 20.0 s.
2018-05-15T04:57:34.367Z,1526360254.367 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 20.0 s old, using for 20.0 s.
2018-05-15T04:58:08.763Z,1526360288.763 [CommandLine](IMPORTANT): got command set NAL9602.time_fix 1526360192.000000 second
2018-05-15T04:58:09.162Z,1526360289.162 [Default:CheckIn:Read_GPS] Stopped
2018-05-15T04:58:09.162Z,1526360289.162 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-05-15T04:58:09.555Z,1526360289.555 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2018-05-15T04:58:14.192Z,1526360294.192 [DataOverHttps](INFO): Sending 188 bytes from file Logs/20180515T045404/Courier0000.lzma
2018-05-15T04:58:14.972Z,1526360294.972 [DataOverHttps](INFO): Moved sent file to Logs/20180515T045404/Courier0000.lzma.bak
2018-05-15T04:58:14.973Z,1526360294.973 [DataOverHttps](INFO): SBD MOMSN=8282234
2018-05-15T04:58:23.821Z,1526360303.821 [DataOverHttps](INFO): Sending 146 bytes from file Logs/20180515T045404/Courier0004.lzma
2018-05-15T04:58:24.603Z,1526360304.603 [DataOverHttps](INFO): Moved sent file to Logs/20180515T045404/Courier0004.lzma.bak
2018-05-15T04:58:24.603Z,1526360304.603 [DataOverHttps](INFO): SBD MOMSN=8282240
2018-05-15T04:58:34.605Z,1526360314.605 [DataOverHttps](INFO): Sending 491 bytes from file Logs/20180514T235826/Express0026.lzma
2018-05-15T04:58:35.398Z,1526360315.398 [DataOverHttps](INFO): Moved sent file to Logs/20180514T235826/Express0026.lzma.bak
2018-05-15T04:58:35.399Z,1526360315.399 [DataOverHttps](INFO): SBD MOMSN=8282242
2018-05-15T04:58:39.385Z,1526360319.385 [CommandLine](IMPORTANT): got command load ./Missions/Maintenance/calibrateAHRS_M2.xml
2018-05-15T04:58:39.386Z,1526360319.386 [MissionManager](INFO): Loading Mission: ./Missions/Maintenance/calibrateAHRS_M2.xml
2018-05-15T04:58:39.524Z,1526360319.524 [MissionManager](INFO): DefineArg compassCal.MissionTimeout = 6.000000 min
2018-05-15T04:58:39.527Z,1526360319.527 [MissionManager](INFO): DefineArg compassCal.NeedCommsTime = 60.000000 min
2018-05-15T04:58:39.558Z,1526360319.558 [MissionManager](INFO): DefineArg compassCal.YoYoMinDepth = 2.000000 m
2018-05-15T04:58:39.561Z,1526360319.561 [MissionManager](INFO): DefineArg compassCal.YoYoMaxDepth = 200.000000 m
2018-05-15T04:58:39.564Z,1526360319.564 [MissionManager](INFO): DefineArg compassCal.YoYoMinAltitude = 7.000000 m
2018-05-15T04:58:39.567Z,1526360319.567 [MissionManager](INFO): DefineArg compassCal.YoYoPitch = 30.000000 arcdeg
2018-05-15T04:58:39.605Z,1526360319.605 [MissionManager](INFO): DefineArg compassCal.RudderAngle = 13.000000 arcdeg
2018-05-15T04:58:39.608Z,1526360319.608 [MissionManager](INFO): DefineArg compassCal.Speed = 1.000000 m/s
2018-05-15T04:58:39.611Z,1526360319.611 [MissionManager](INFO): DefineArg compassCal.CalibrationInitTimeout = 2.000000 min
2018-05-15T04:58:39.634Z,1526360319.634 [MissionManager](INFO): DefineArg compassCal.MinAltitude = 5.000000 m
2018-05-15T04:58:39.637Z,1526360319.637 [MissionManager](INFO): DefineArg compassCal.MaxDepth = 205.000000 m
2018-05-15T04:58:39.640Z,1526360319.640 [MissionManager](INFO): DefineArg compassCal.MinOffshore = 2.000000 km
2018-05-15T04:58:39.653Z,1526360319.653 [MissionManager](INFO): Inserting Stack: Missions/Insert/NeedComms.xml
2018-05-15T04:58:39.871Z,1526360319.871 [MissionManager](INFO): DefineArg compassCal:NeedComms.DiveInterval = 3.000000 h
2018-05-15T04:58:39.877Z,1526360319.877 [MissionManager](INFO): DefineArg compassCal:NeedComms.WaitForPitchUp = 10.000000 min
2018-05-15T04:58:39.880Z,1526360319.880 [MissionManager](INFO): DefineArg compassCal:NeedComms.SurfacePitch = 20.000000 arcdeg
2018-05-15T04:58:39.883Z,1526360319.883 [MissionManager](INFO): DefineArg compassCal:NeedComms.SurfaceDepthRate = nan m/s
2018-05-15T04:58:39.886Z,1526360319.886 [MissionManager](INFO): DefineArg compassCal:NeedComms.SurfaceSpeed = 1.000000 m/s
2018-05-15T04:58:39.906Z,1526360319.906 [MissionManager](INFO): DefineArg compassCal:NeedComms.GPSTimeout = 7.000000 min
2018-05-15T04:58:39.917Z,1526360319.917 [MissionManager](INFO): DefineArg compassCal:NeedComms.CommsTimeout = 30.000000 min
2018-05-15T04:58:39.946Z,1526360319.946 [compassCal:NeedComms:B.GoToSurface](DEBUG): Construct GoToSurface.
2018-05-15T04:58:40.017Z,1526360320.017 [MissionManager](INFO): Inserting Stack: Missions/Insert/StandardEnvelopes.xml
2018-05-15T04:58:40.098Z,1526360320.098 [MissionManager](INFO): DefineArg compassCal:StandardEnvelopes.MinAltitude = 5.000000 m
2018-05-15T04:58:40.119Z,1526360320.119 [MissionManager](INFO): DefineArg compassCal:StandardEnvelopes.MaxDepth = 200.000000 m
2018-05-15T04:58:40.122Z,1526360320.122 [MissionManager](INFO): DefineArg compassCal:StandardEnvelopes.MinOffshore = 2000.000000 m
2018-05-15T04:58:40.124Z,1526360320.124 [compassCal:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope.
2018-05-15T04:58:40.169Z,1526360320.169 [compassCal:StandardEnvelopes:B.DepthEnvelope](DEBUG): Construct DepthEnvelope.
2018-05-15T04:58:40.253Z,1526360320.253 [compassCal:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Construct OffshoreEnvelope.
2018-05-15T04:58:40.284Z,1526360320.284 [compassCal:H.Pitch](DEBUG): Construct.
2018-05-15T04:58:40.302Z,1526360320.302 [compassCal:I.Buoyancy](DEBUG): Construct Buoyancy.
2018-05-15T04:58:40.330Z,1526360320.330 [compassCal:J.DepthEnvelope](DEBUG): Construct DepthEnvelope.
2018-05-15T04:58:40.345Z,1526360320.345 [compassCal:K.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope.
2018-05-15T04:58:40.377Z,1526360320.377 [compassCal:L.YoYo](DEBUG): Construct YoYo.
2018-05-15T04:58:40.420Z,1526360320.420 [compassCal:Calibration:WaitForCalibrationInit:A_Timeout:B.Execute](DEBUG): Construct Execute.
2018-05-15T04:58:40.439Z,1526360320.439 [compassCal:Calibration:AcquireCalibrationPoints:A.Point](DEBUG): Construct.
2018-05-15T04:58:40.462Z,1526360320.462 [compassCal:Calibration:AcquireCalibrationPoints:B.SetSpeed](DEBUG): Construct.
2018-05-15T04:58:40.473Z,1526360320.473 [compassCal:Calibration:D.CalibrateAHRS_M2](DEBUG): Construct CalibrateSparton.
2018-05-15T04:58:40.501Z,1526360320.501 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
    xmlns:Control="Tethys/Control"
    xmlns:Derivation="Tethys/Derivation"
    xmlns:Estimation="Tethys/Estimation"
    xmlns:Guidance="Tethys/Guidance"
    xmlns:Sensor="Tethys/Sensor"
    xmlns:Units="Tethys/Units"
    xmlns:Universal="Tethys/Universal"
    xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
    xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
    Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
    Tethys/Derivation http://okeanids.mbari.org/tethys/Xml/Derivation.xsd
    Tethys/Estimation http://okeanids.mbari.org/tethys/Xml/Estimation.xsd
    Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
    Tethys/Sensor http://okeanids.mbari.org/tethys/Xml/Sensor.xsd
    Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
    Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
    Id="compassCal">
    
    <Description>
        This mission yoyos in a spiral while calibrating the Sparton AHRS-M2 Micro AHRS/IMU with AdaptCal.
    </Description>
    
    <!-- Mission-wide settings -->
    
    <DefineArg Name="MissionTimeout"><Description>
        Maximum duration of mission
    </Description><Units:minute/><Value>6</Value></DefineArg>
    
    <DefineArg Name="NeedCommsTime"><Description>
        Elapsed time after previous surface communications when vehicle will
        begin to ascend for additional surface communications
    </Description><Units:minute/><Value>60</Value></DefineArg>
    
    <!-- You probably need to change these. -->
    
    <!-- You probably do not need to change these. -->
    
    <DefineArg Name="YoYoMinDepth"><Description>
        Minimum depth while performing the YoYo behavior.
    </Description><Units:meter/><Value>2</Value></DefineArg>
    
    <DefineArg Name="YoYoMaxDepth"><Description>
        Maximum depth while performing the YoYo behavior.
    </Description><Units:meter/><Value>200</Value></DefineArg>
    
    <DefineArg Name="YoYoMinAltitude"><Description>
        Minimum altitude while performing the YoYo behavior (for
        bottom-terminated YoYos).
    </Description><Units:meter/><Value>7</Value></DefineArg>
    
    <DefineArg Name="YoYoPitch"><Description>
        Pitch (plus and minus) for yo-yo behavior.
    </Description><Units:degree/><Value>30</Value></DefineArg>
    
    <DefineArg Name="RudderAngle"><Description>
        Rudder angle to use while performing the spiral cast.
    </Description><Units:degree/><Value>13</Value></DefineArg>
    
    <DefineArg Name="Speed"><Description>
        Vehicle speed.
    </Description><Units:meter_per_second/><Value>1</Value></DefineArg>
    
    <DefineArg Name="CalibrationInitTimeout"><Description>
        Elapsed time allowed for calibration to initialize
    </Description><Units:minute/><Value>2</Value></DefineArg>
    
    <!-- You are even less likely to need to change these. -->
    
    <DefineArg Name="MinAltitude"><Description>
        Minimum height above the sea floor for the entire mission.
    </Description><Units:meter/><Value>5</Value></DefineArg>
    
    <DefineArg Name="MaxDepth"><Description>
        Maximum depth for the entire mission.
    </Description><Units:meter/><Value>205</Value></DefineArg>
    
    <DefineArg Name="MinOffshore"><Description>
        Minimum offshore distance for the entire mission.
    </Description><Units:kilometer/><Value>2</Value></DefineArg>
    
    <!-- Missions should almost always start with a timeout -->
    
    <Timeout Duration="MissionTimeout"/>

    <!--    
    <Insert Filename="Insert/Science.xml">
        <Description>
            Most missions will run the science sensors. If you don't place this
            aggregate above NeedComms, science instruments get turned off on the
            last upcast and while floating on the surface.
        </Description>
        <RedefineArg Name="SampleISUS"><True/></RedefineArg>
        <RedefineArg Name="PeakDetectChlActive"><True/></RedefineArg>
    </Insert>
   -->
 
    <!-- Most missions should use the NeedComms aggregate. -->
    
    <Insert Filename="Insert/NeedComms.xml" Id="NeedComms"/>
    
    <Assign><Sequence/><Arg Name="NeedComms:DiveInterval"/><Arg Name="NeedCommsTime"/></Assign>
    
    <!-- Missions should almost always start with standard safety envelopes; most missions should not expose the parameters of these envelopes. -->
    
    <Insert Filename="Insert/StandardEnvelopes.xml"/>
    
    <Assign><Sequence/><Arg Name="StandardEnvelopes:MinAltitude"/><Arg Name="MinAltitude"/></Assign>
    
    <Assign><Sequence/><Arg Name="StandardEnvelopes:MaxDepth"/><Arg Name="MaxDepth"/></Assign>
    
    <Assign><Sequence/><Arg Name="StandardEnvelopes:MinOffshore"/><Arg Name="MinOffshore"/></Assign>
    
    <!-- Check for additional instructions first. -->
    
    <Call Id="StartingMission" RefId="NeedComms"/>
    
    <!-- Many missions will keep mass position and buoyancy volume fixed at defaults. -->
    
    <Guidance:Pitch>
        <Parallel/>
        <Setting><Guidance:Pitch.massPosition/><Control:VerticalControl.massDefault/></Setting>
    </Guidance:Pitch>
    
    <Guidance:Buoyancy>
        <Parallel/>
        <Setting><Guidance:Buoyancy.position/><Control:VerticalControl.buoyancyNeutral/></Setting>
    </Guidance:Buoyancy>
    
    <Guidance:DepthEnvelope>
        <Description>
            Another depth envelope for the YoYo behavior. This envelope should
            fall within the limits of the standard safety envelopes in
            Insert/StandardEnvelopes.xml in order to avoid commanding high pitch
            angles for depth-terminated YoYos.
        </Description>
        <Parallel/>
        <Setting><Guidance:DepthEnvelope.minDepth/><Arg Name="YoYoMinDepth"/></Setting>
        <Setting><Guidance:DepthEnvelope.maxDepth/><Arg Name="YoYoMaxDepth"/></Setting>
        <Setting><Guidance:DepthEnvelope.pitch/><Arg Name="YoYoPitch"/></Setting>
    </Guidance:DepthEnvelope>
    
    <Guidance:AltitudeEnvelope>
        <Description>
            Another altitude envelope for the YoYo behavior. This envelope
            should fall within the limits of the standard safety envelopes in
            Insert/StandardEnvelopes.xml in order to avoid commanding high pitch
            angles for bottom-terminated YoYos.
        </Description>
        <Parallel/>
        <Setting><Guidance:AltitudeEnvelope.minAltitude/><Arg Name="YoYoMinAltitude"/></Setting>
        <Setting><Guidance:AltitudeEnvelope.pitch/><Arg Name="YoYoPitch"/></Setting>
    </Guidance:AltitudeEnvelope>
    
    <Guidance:YoYo>
        <Parallel/>
        <Setting><Guidance:YoYo.pitch/><Arg Name="YoYoPitch"/></Setting>
    </Guidance:YoYo>

    <Aggregate Id="Calibration">
        
        <Sequence/>
        
        <ReadDatum Id="WaitForCalibrationInit">
            <Timeout Duration="CalibrationInitTimeout">
                <Syslog Severity="Important">Failed to initialize calibration within timeout. Stopping mission.</Syslog>
                <Guidance:Execute>
                    <Sequence/>
                    <Setting><Guidance:Execute.command/><String>stop</String></Setting>
                </Guidance:Execute>
            </Timeout>
            <Sensor:AHRS_M2.CompassCalState/>
        </ReadDatum>
        
        <Syslog Severity="Important">AdaptCal initialized. Acquiring calibration points.</Syslog>

        <Aggregate Id="AcquireCalibrationPoints">
            
            <Sequence/>
            
            <Guidance:Point>
                <Parallel/>
                <Setting><Guidance:Point.rudderAngle/><Arg Name="RudderAngle"/></Setting>
            </Guidance:Point>
            
            <Guidance:SetSpeed>
                <Parallel/>
                <Setting><Guidance:SetSpeed.speed/><Arg Name="Speed"/></Setting>
            </Guidance:SetSpeed>
            
        </Aggregate>
    
        <Sensor:CalibrateAHRS_M2>
            <Parallel/>
        </Sensor:CalibrateAHRS_M2>
    
    </Aggregate>
    
</Mission>


2018-05-15T04:58:40.502Z,1526360320.502 [CommandLine](IMPORTANT): Loaded ./Missions/Maintenance/calibrateAHRS_M2.xml
2018-05-15T04:58:45.054Z,1526360325.054 [NAL9602](INFO): Powering down
2018-05-15T04:58:45.204Z,1526360325.204 [DataOverHttps](INFO): Sending 1092 bytes from file Logs/20180515T045110/Express0001.lzma
2018-05-15T04:58:45.990Z,1526360325.990 [DataOverHttps](INFO): Moved sent file to Logs/20180515T045110/Express0001.lzma.bak
2018-05-15T04:58:45.990Z,1526360325.990 [DataOverHttps](INFO): SBD MOMSN=8282263
2018-05-15T04:58:51.886Z,1526360331.886 [CommandLine](IMPORTANT): got command run
2018-05-15T04:58:51.889Z,1526360331.889 [CommandLine](IMPORTANT): Running 
2018-05-15T04:58:51.933Z,1526360331.933 [Default] Stopped
2018-05-15T04:58:51.933Z,1526360331.933 [Default](DEBUG): Aggregate::uninitialize Default
2018-05-15T04:58:51.933Z,1526360331.933 [Default:B.GoToSurface] Stopped
2018-05-15T04:58:51.934Z,1526360331.934 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2018-05-15T04:58:51.934Z,1526360331.934 [Default:CheckIn] Stopped
2018-05-15T04:58:51.934Z,1526360331.934 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-05-15T04:58:51.934Z,1526360331.934 [Default:CheckIn:Read_Iridium] Stopped
2018-05-15T04:58:51.934Z,1526360331.934 [MissionManager](IMPORTANT): Started mission compassCal
2018-05-15T04:58:51.934Z,1526360331.934 [compassCal] Running Loop=1
2018-05-15T04:58:51.934Z,1526360331.934 [compassCal](DEBUG): Aggregate::initialize compassCal
2018-05-15T04:58:51.934Z,1526360331.934 [compassCal:StandardEnvelopes] Running Loop=1
2018-05-15T04:58:51.935Z,1526360331.935 [compassCal:StandardEnvelopes](DEBUG): Aggregate::initialize compassCal:StandardEnvelopes
2018-05-15T04:58:51.935Z,1526360331.935 [compassCal:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1
2018-05-15T04:58:51.935Z,1526360331.935 [compassCal:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent.
2018-05-15T04:58:51.935Z,1526360331.935 [compassCal:StandardEnvelopes:B.DepthEnvelope] Running Loop=1
2018-05-15T04:58:51.935Z,1526360331.935 [compassCal:StandardEnvelopes:B.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent.
2018-05-15T04:58:51.935Z,1526360331.935 [compassCal:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1
2018-05-15T04:58:51.935Z,1526360331.935 [compassCal:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Initialize OffshoreEnvelopeComponent.
2018-05-15T04:58:51.935Z,1526360331.935 [compassCal:H.Pitch] Running Loop=1
2018-05-15T04:58:51.935Z,1526360331.935 [compassCal:H.Pitch](DEBUG): Initialize.
2018-05-15T04:58:51.936Z,1526360331.936 [compassCal:I.Buoyancy] Running Loop=1
2018-05-15T04:58:51.936Z,1526360331.936 [compassCal:I.Buoyancy](DEBUG): Initialize Buoyancy Component.
2018-05-15T04:58:51.936Z,1526360331.936 [compassCal:J.DepthEnvelope] Running Loop=1
2018-05-15T04:58:51.936Z,1526360331.936 [compassCal:J.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent.
2018-05-15T04:58:51.936Z,1526360331.936 [compassCal:K.AltitudeEnvelope] Running Loop=1
2018-05-15T04:58:51.936Z,1526360331.936 [compassCal:K.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent.
2018-05-15T04:58:51.937Z,1526360331.937 [compassCal:L.YoYo] Running Loop=1
2018-05-15T04:58:51.937Z,1526360331.937 [compassCal:L.YoYo](DEBUG): Initialize YoYoComponent.
2018-05-15T04:58:51.937Z,1526360331.937 [compassCal:B] Running Loop=1
2018-05-15T04:58:51.938Z,1526360331.938 [compassCal:L.YoYo] Running Loop=1
2018-05-15T04:58:51.949Z,1526360331.949 [compassCal:K.AltitudeEnvelope] Running Loop=1
2018-05-15T04:58:51.954Z,1526360331.954 [compassCal:J.DepthEnvelope] Running Loop=1
2018-05-15T04:58:51.964Z,1526360331.964 [compassCal:I.Buoyancy] Running Loop=1
2018-05-15T04:58:51.977Z,1526360331.977 [compassCal:H.Pitch] Running Loop=1
2018-05-15T04:58:51.986Z,1526360331.986 [compassCal:StandardEnvelopes] Running Loop=1
2018-05-15T04:58:51.986Z,1526360331.986 [compassCal:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1
2018-05-15T04:58:51.997Z,1526360331.997 [compassCal:StandardEnvelopes:B.DepthEnvelope] Running Loop=1
2018-05-15T04:58:52.002Z,1526360332.002 [compassCal:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1
2018-05-15T04:58:52.012Z,1526360332.012 [compassCal:B] Stopped
2018-05-15T04:58:52.021Z,1526360332.021 [compassCal:D] Running Loop=1
2018-05-15T04:58:55.008Z,1526360335.008 [compassCal:D] Stopped
2018-05-15T04:58:55.008Z,1526360335.008 [compassCal:E] Running Loop=1
2018-05-15T04:58:55.091Z,1526360335.091 [DataOverHttps](INFO): Sending 1024 bytes from file Logs/20180515T045404/Express0001.lzma
2018-05-15T04:58:55.189Z,1526360335.189 [compassCal:E] Stopped
2018-05-15T04:58:55.189Z,1526360335.189 [compassCal:F] Running Loop=1
2018-05-15T04:58:55.526Z,1526360335.526 [compassCal:F] Stopped
2018-05-15T04:58:55.526Z,1526360335.526 [compassCal:StartingMission] Running Loop=1
2018-05-15T04:58:55.526Z,1526360335.526 [compassCal:StartingMission](DEBUG): Aggregate::initialize compassCal:StartingMission
2018-05-15T04:58:55.866Z,1526360335.866 [DataOverHttps](INFO): Moved sent file to Logs/20180515T045404/Express0001.lzma.bak
2018-05-15T04:58:55.866Z,1526360335.866 [DataOverHttps](INFO): SBD MOMSN=8282301
2018-05-15T04:58:55.933Z,1526360335.933 [compassCal:NeedComms] Running Loop=1
2018-05-15T04:58:55.934Z,1526360335.934 [compassCal:NeedComms](DEBUG): Aggregate::initialize compassCal:NeedComms
2018-05-15T04:58:55.934Z,1526360335.934 [compassCal:NeedComms:B.GoToSurface] Running Loop=1
2018-05-15T04:58:55.934Z,1526360335.934 [compassCal:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-05-15T04:58:55.934Z,1526360335.934 [compassCal:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s.
2018-05-15T04:58:55.935Z,1526360335.935 [compassCal:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees.
2018-05-15T04:58:55.935Z,1526360335.935 [compassCal:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s.
2018-05-15T04:58:55.935Z,1526360335.935 [compassCal:NeedComms:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-05-15T04:58:55.936Z,1526360335.936 [compassCal:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2018-05-15T04:58:55.936Z,1526360335.936 [compassCal:NeedComms:A] Running Loop=1
2018-05-15T04:58:55.950Z,1526360335.950 [compassCal:NeedComms:A](INFO): last time_fix was: 1526360192.000000 second since 1970/01/01T00:00:00Z 
2018-05-15T04:58:55.951Z,1526360335.951 [compassCal:NeedComms:A] Stopped
2018-05-15T04:58:56.328Z,1526360336.328 [compassCal:NeedComms:C] Running Loop=1
2018-05-15T04:58:56.733Z,1526360336.733 [compassCal:NeedComms:C](DEBUG): Initialize ReadDataComponent to sense time_fix
2018-05-15T04:58:57.073Z,1526360337.073 [NAL9602](INFO): Powering up
2018-05-15T04:59:05.926Z,1526360345.926 [NAL9602](INFO): No messages in MT queue
2018-05-15T04:59:08.595Z,1526360348.595 [CommandLine](IMPORTANT): got command set NAL9602.time_fix 1526360192.000000 second
2018-05-15T04:59:08.772Z,1526360348.772 [compassCal:NeedComms:C] Stopped
2018-05-15T04:59:08.773Z,1526360348.773 [compassCal:NeedComms:D] Running Loop=1
2018-05-15T04:59:09.176Z,1526360349.176 [compassCal:NeedComms:D](DEBUG): Initialize ReadDataComponent to sense platform_communications
2018-05-15T04:59:14.199Z,1526360354.199 [DataOverHttps](INFO): Sending 43 bytes from file Logs/20180515T045404/Courier0007.lzma
2018-05-15T04:59:14.992Z,1526360354.992 [DataOverHttps](INFO): Moved sent file to Logs/20180515T045404/Courier0007.lzma.bak
2018-05-15T04:59:14.992Z,1526360354.992 [DataOverHttps](INFO): SBD MOMSN=8282333
2018-05-15T04:59:24.702Z,1526360364.702 [DataOverHttps](INFO): Sending 263 bytes from file Logs/20180515T045404/Express0005.lzma
2018-05-15T04:59:25.491Z,1526360365.491 [DataOverHttps](INFO): Moved sent file to Logs/20180515T045404/Express0005.lzma.bak
2018-05-15T04:59:25.491Z,1526360365.491 [DataOverHttps](INFO): SBD MOMSN=8282335
2018-05-15T04:59:27.363Z,1526360367.363 [CommandLine](IMPORTANT): got command set NAL9602.time_fix 1526360320.000000 second
2018-05-15T04:59:35.816Z,1526360375.816 [DataOverHttps](INFO): Sending 233 bytes from file Logs/20180515T045404/Express0008.lzma
2018-05-15T04:59:36.596Z,1526360376.596 [DataOverHttps](INFO): Moved sent file to Logs/20180515T045404/Express0008.lzma.bak
2018-05-15T04:59:36.596Z,1526360376.596 [DataOverHttps](INFO): SBD MOMSN=8282339
2018-05-15T04:59:37.644Z,1526360377.644 [compassCal:NeedComms:D] Stopped
2018-05-15T04:59:37.645Z,1526360377.645 [compassCal:NeedComms:E] Running Loop=1
2018-05-15T04:59:37.790Z,1526360377.790 [compassCal:NeedComms:E](DEBUG): Initialize ReadDataComponent to sense time_fix
2018-05-15T05:00:08.459Z,1526360408.459 [CommandLine](IMPORTANT): got command set NAL9602.time_fix 1526360320.000000 second
2018-05-15T05:00:08.549Z,1526360408.549 [compassCal:NeedComms:E] Stopped
2018-05-15T05:00:08.550Z,1526360408.550 [compassCal:NeedComms](INFO): Completed compassCal:NeedComms
2018-05-15T05:00:08.550Z,1526360408.550 [compassCal:NeedComms] Stopped
2018-05-15T05:00:08.550Z,1526360408.550 [compassCal:NeedComms](DEBUG): Aggregate::uninitialize compassCal:NeedComms
2018-05-15T05:00:08.550Z,1526360408.550 [compassCal:NeedComms:B.GoToSurface] Stopped
2018-05-15T05:00:08.550Z,1526360408.550 [compassCal:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2018-05-15T05:00:08.953Z,1526360408.953 [compassCal:StartingMission](INFO): Completed compassCal:StartingMission
2018-05-15T05:00:08.953Z,1526360408.953 [compassCal:StartingMission] Stopped
2018-05-15T05:00:08.953Z,1526360408.953 [compassCal:StartingMission](DEBUG): Aggregate::uninitialize compassCal:StartingMission
2018-05-15T05:00:08.954Z,1526360408.954 [compassCal:Calibration] Running Loop=1
2018-05-15T05:00:08.954Z,1526360408.954 [compassCal:Calibration](DEBUG): Aggregate::initialize compassCal:Calibration
2018-05-15T05:00:08.954Z,1526360408.954 [compassCal:Calibration:D.CalibrateAHRS_M2] Running Loop=1
2018-05-15T05:00:08.954Z,1526360408.954 [compassCal:Calibration:D.CalibrateAHRS_M2](INFO): Initialize CalibrateSpartonComponent.
2018-05-15T05:00:08.954Z,1526360408.954 [compassCal:Calibration:WaitForCalibrationInit] Running Loop=1
2018-05-15T05:00:09.383Z,1526360409.383 [DeadReckonUsingMultipleVelocitySources](DEBUG): Most recent orientation data is 0.437076 seconds old.
2018-05-15T05:00:09.385Z,1526360409.385 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 0.437570 seconds old.
2018-05-15T05:00:09.393Z,1526360409.393 [compassCal:Calibration:D.CalibrateAHRS_M2] Running Loop=1
2018-05-15T05:00:09.393Z,1526360409.393 [compassCal:Calibration:D.CalibrateAHRS_M2](INFO): Initialize CalibrateSpartonComponent.
2018-05-15T05:00:09.402Z,1526360409.402 [compassCal:Calibration:WaitForCalibrationInit](DEBUG): Initialize ReadDataComponent to sense AHRS_M2.CompassCalState
2018-05-15T05:00:09.760Z,1526360409.760 [DeadReckonUsingMultipleVelocitySources](DEBUG): Most recent orientation data is 0.813994 seconds old.
2018-05-15T05:00:09.762Z,1526360409.762 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 0.814463 seconds old.
2018-05-15T05:00:09.766Z,1526360409.766 [compassCal:Calibration:D.CalibrateAHRS_M2](INFO): Initialize CalibrateSpartonComponent.
2018-05-15T05:00:10.178Z,1526360410.178 [DeadReckonUsingMultipleVelocitySources](DEBUG): Most recent orientation data is 1.232013 seconds old.
2018-05-15T05:00:10.180Z,1526360410.180 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 1.232283 seconds old.
2018-05-15T05:00:10.200Z,1526360410.200 [compassCal:Calibration:D.CalibrateAHRS_M2](INFO): Initialize CalibrateSpartonComponent.
2018-05-15T05:00:10.205Z,1526360410.205 [compassCal:Calibration:WaitForCalibrationInit] Stopped
2018-05-15T05:00:10.205Z,1526360410.205 [compassCal:Calibration:B] Running Loop=1
2018-05-15T05:00:10.568Z,1526360410.568 [compassCal:Calibration:B](IMPORTANT): AdaptCal initialized. Acquiring calibration points.
2018-05-15T05:00:10.570Z,1526360410.570 [compassCal:Calibration:B] Stopped
2018-05-15T05:00:10.570Z,1526360410.570 [compassCal:Calibration:AcquireCalibrationPoints] Running Loop=1
2018-05-15T05:00:10.570Z,1526360410.570 [compassCal:Calibration:AcquireCalibrationPoints](DEBUG): Aggregate::initialize compassCal:Calibration:AcquireCalibrationPoints
2018-05-15T05:00:10.570Z,1526360410.570 [compassCal:Calibration:AcquireCalibrationPoints:A.Point] Running Loop=1
2018-05-15T05:00:10.570Z,1526360410.570 [compassCal:Calibration:AcquireCalibrationPoints:A.Point](DEBUG): Initialize.
2018-05-15T05:00:10.570Z,1526360410.570 [compassCal:Calibration:AcquireCalibrationPoints:B.SetSpeed] Running Loop=1
2018-05-15T05:00:10.570Z,1526360410.570 [compassCal:Calibration:AcquireCalibrationPoints:B.SetSpeed](DEBUG): Initialize.
2018-05-15T05:00:10.953Z,1526360410.953 [compassCal:Calibration:AcquireCalibrationPoints:B.SetSpeed] Running Loop=1
2018-05-15T05:00:10.961Z,1526360410.961 [compassCal:Calibration:AcquireCalibrationPoints:A.Point] Running Loop=1
2018-05-15T05:00:41.761Z,1526360441.761 [NAL9602](INFO): Powering down
2018-05-15T05:01:12.645Z,1526360472.645 [CommandLine](IMPORTANT): got command stop
2018-05-15T05:01:12.646Z,1526360472.646 [CommandLine](IMPORTANT): Scheduling is paused
2018-05-15T05:01:12.646Z,1526360472.646 [Supervisor](INFO): Stop Mission called by CommandLine::commandStop
2018-05-15T05:01:13.002Z,1526360473.002 [MissionManager](INFO): MissionManager is completed.
2018-05-15T05:01:13.002Z,1526360473.002 [MissionManager](INFO): Uninitializing Mission compassCal
2018-05-15T05:01:13.002Z,1526360473.002 [compassCal] Stopped
2018-05-15T05:01:13.002Z,1526360473.002 [compassCal](DEBUG): Aggregate::uninitialize compassCal
2018-05-15T05:01:13.002Z,1526360473.002 [compassCal:StandardEnvelopes] Stopped
2018-05-15T05:01:13.002Z,1526360473.002 [compassCal:StandardEnvelopes](DEBUG): Aggregate::uninitialize compassCal:StandardEnvelopes
2018-05-15T05:01:13.002Z,1526360473.002 [compassCal:StandardEnvelopes:A.AltitudeEnvelope] Stopped
2018-05-15T05:01:13.002Z,1526360473.002 [compassCal:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent.
2018-05-15T05:01:13.002Z,1526360473.002 [compassCal:StandardEnvelopes:B.DepthEnvelope] Stopped
2018-05-15T05:01:13.003Z,1526360473.003 [compassCal:StandardEnvelopes:B.DepthEnvelope](DEBUG): Uninitialize.
2018-05-15T05:01:13.003Z,1526360473.003 [compassCal:StandardEnvelopes:C.OffshoreEnvelope] Stopped
2018-05-15T05:01:13.003Z,1526360473.003 [compassCal:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Uninitialize OffshoreEnvelopeComponent.
2018-05-15T05:01:13.003Z,1526360473.003 [compassCal:H.Pitch] Stopped
2018-05-15T05:01:13.003Z,1526360473.003 [compassCal:I.Buoyancy] Stopped
2018-05-15T05:01:13.003Z,1526360473.003 [compassCal:I.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2018-05-15T05:01:13.003Z,1526360473.003 [compassCal:J.DepthEnvelope] Stopped
2018-05-15T05:01:13.003Z,1526360473.003 [compassCal:J.DepthEnvelope](DEBUG): Uninitialize.
2018-05-15T05:01:13.003Z,1526360473.003 [compassCal:K.AltitudeEnvelope] Stopped
2018-05-15T05:01:13.003Z,1526360473.003 [compassCal:K.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent.
2018-05-15T05:01:13.003Z,1526360473.003 [compassCal:L.YoYo] Stopped
2018-05-15T05:01:13.003Z,1526360473.003 [compassCal:L.YoYo](DEBUG): Uninitialize YoYoComponent.
2018-05-15T05:01:13.003Z,1526360473.003 [compassCal:Calibration] Stopped
2018-05-15T05:01:13.004Z,1526360473.004 [compassCal:Calibration](DEBUG): Aggregate::uninitialize compassCal:Calibration
2018-05-15T05:01:13.004Z,1526360473.004 [compassCal:Calibration:AcquireCalibrationPoints] Stopped
2018-05-15T05:01:13.004Z,1526360473.004 [compassCal:Calibration:AcquireCalibrationPoints](DEBUG): Aggregate::uninitialize compassCal:Calibration:AcquireCalibrationPoints
2018-05-15T05:01:13.004Z,1526360473.004 [compassCal:Calibration:AcquireCalibrationPoints:A.Point] Stopped
2018-05-15T05:01:13.004Z,1526360473.004 [compassCal:Calibration:AcquireCalibrationPoints:B.SetSpeed] Stopped
2018-05-15T05:01:13.004Z,1526360473.004 [compassCal:Calibration:AcquireCalibrationPoints:B.SetSpeed](DEBUG): Uninitialize.
2018-05-15T05:01:13.004Z,1526360473.004 [compassCal:Calibration:D.CalibrateAHRS_M2] Stopped
2018-05-15T05:01:13.004Z,1526360473.004 [compassCal:Calibration:D.CalibrateAHRS_M2](INFO): Uninitialize CalibrateSpartonComponent.
2018-05-15T05:01:13.424Z,1526360473.424 [DeadReckonUsingMultipleVelocitySources](DEBUG): Most recent orientation data is 0.432168 seconds old.
2018-05-15T05:01:13.426Z,1526360473.426 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 0.432303 seconds old.
2018-05-15T05:01:13.430Z,1526360473.430 [MissionManager](IMPORTANT): Started mission Default
2018-05-15T05:01:13.430Z,1526360473.430 [Default] Running Loop=1
2018-05-15T05:01:13.430Z,1526360473.430 [Default](DEBUG): Aggregate::initialize Default
2018-05-15T05:01:13.430Z,1526360473.430 [Default:B.GoToSurface] Running Loop=1
2018-05-15T05:01:13.430Z,1526360473.430 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-05-15T05:01:13.431Z,1526360473.431 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2018-05-15T05:01:13.431Z,1526360473.431 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2018-05-15T05:01:13.431Z,1526360473.431 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2018-05-15T05:01:13.432Z,1526360473.432 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-05-15T05:01:13.432Z,1526360473.432 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2018-05-15T05:01:13.432Z,1526360473.432 [Default:A.Wait] Running Loop=1
2018-05-15T05:01:13.461Z,1526360473.461 [Default:A.Wait](DEBUG): Initialize Wait Component.
2018-05-15T05:01:13.766Z,1526360473.766 [AHRS_M2](IMPORTANT): Magnetic calibration quality (0[best] to 10000) is 0.000000.
2018-05-15T05:01:13.826Z,1526360473.826 [DeadReckonUsingMultipleVelocitySources](DEBUG): Most recent orientation data is 0.834483 seconds old.
2018-05-15T05:01:13.829Z,1526360473.829 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 0.834504 seconds old.
2018-05-15T05:01:26.589Z,1526360486.589 [Default:A.Wait](INFO): Done Waiting.
2018-05-15T05:01:26.589Z,1526360486.589 [Default:A.Wait] Stopped
2018-05-15T05:01:26.589Z,1526360486.589 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2018-05-15T05:01:26.996Z,1526360486.996 [Default:CheckIn] Running Loop=1
2018-05-15T05:01:26.996Z,1526360486.996 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-05-15T05:01:26.996Z,1526360486.996 [Default:CheckIn:Read_GPS] Running Loop=1
2018-05-15T05:01:27.754Z,1526360487.754 [NAL9602](INFO): Powering up
2018-05-15T05:01:34.154Z,1526360494.154 [NAL9602](INFO): No messages in MT queue
2018-05-15T05:04:40.545Z,1526360680.545 [CommandLine](IMPORTANT): got command restart application
2018-05-15T05:04:41.552Z,1526360681.552 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2018-05-15T05:04:41.552Z,1526360681.552 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-05-15T05:04:41.605Z,1526360681.605 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2018-05-15T05:04:41.605Z,1526360681.605 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-05-15T05:04:41.605Z,1526360681.605 [CommandLine](INFO): Join timeout helper Thread ID is 9645
2018-05-15T05:04:41.625Z,1526360681.625 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2018-05-15T05:04:41.625Z,1526360681.625 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-05-15T05:04:41.625Z,1526360681.625 [NavChartDb](INFO): Join timeout helper Thread ID is 9646
2018-05-15T05:04:41.961Z,1526360681.961 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2018-05-15T05:04:41.961Z,1526360681.961 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-05-15T05:04:41.965Z,1526360681.965 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2018-05-15T05:04:41.965Z,1526360681.965 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2018-05-15T05:04:41.965Z,1526360681.965 [CTD_Seabird](INFO): Join timeout helper Thread ID is 9647
2018-05-15T05:04:41.973Z,1526360681.973 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2018-05-15T05:04:42.122Z,1526360682.122 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface
2018-05-15T05:04:42.122Z,1526360682.122 [CTD_Seabird](INFO): Powering down
2018-05-15T05:04:42.123Z,1526360682.123 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2018-05-15T05:04:42.125Z,1526360682.125 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2018-05-15T05:04:42.125Z,1526360682.125 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-05-15T05:04:42.125Z,1526360682.125 [Radio_Surface](INFO): Join timeout helper Thread ID is 9649
2018-05-15T05:04:42.237Z,1526360682.237 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2018-05-15T05:04:42.237Z,1526360682.237 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-05-15T05:04:42.241Z,1526360682.241 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2018-05-15T05:04:42.241Z,1526360682.241 [logger ThreadHandler](INFO): Thread cancelled.
2018-05-15T05:04:42.241Z,1526360682.241 [logger](INFO): Join timeout helper Thread ID is 9650
2018-05-15T05:04:42.281Z,1526360682.281 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2018-05-15T05:04:42.281Z,1526360682.281 [logger ThreadHandler](INFO): Thread cancelled.
2018-05-15T05:04:42.294Z,1526360682.294 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2018-05-15T05:04:42.294Z,1526360682.294 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-05-15T05:04:42.294Z,1526360682.294 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2018-05-15T05:04:42.294Z,1526360682.294 [controlThread ThreadHandler](INFO): Thread cancelled.
2018-05-15T05:04:42.295Z,1526360682.295 [controlThread](INFO): Join timeout helper Thread ID is 9651
2018-05-15T05:04:42.641Z,1526360682.641 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2018-05-15T05:04:42.641Z,1526360682.641 [controlThread](DEBUG): Uninitializing ControlThread
2018-05-15T05:04:42.678Z,1526360682.678 [AHRS_M2](INFO): Powering down
2018-05-15T05:04:42.749Z,1526360682.749 [AcousticModem_Benthos_ATM900](INFO): Powering down
2018-05-15T05:04:42.875Z,1526360682.875 [NAL9602](INFO): Powering down
2018-05-15T05:04:42.878Z,1526360682.878 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2018-05-15T05:04:42.880Z,1526360682.880 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2018-05-15T05:04:42.880Z,1526360682.880 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2018-05-15T05:04:42.881Z,1526360682.881 [MissionManager](INFO): Uninitializing Mission Default
2018-05-15T05:04:42.881Z,1526360682.881 [Default] Stopped
2018-05-15T05:04:42.881Z,1526360682.881 [Default](DEBUG): Aggregate::uninitialize Default
2018-05-15T05:04:42.881Z,1526360682.881 [Default:B.GoToSurface] Stopped
2018-05-15T05:04:42.881Z,1526360682.881 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2018-05-15T05:04:42.881Z,1526360682.881 [Default:CheckIn] Stopped
2018-05-15T05:04:42.882Z,1526360682.882 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-05-15T05:04:42.882Z,1526360682.882 [Default:CheckIn:Read_GPS] Stopped
2018-05-15T05:04:42.885Z,1526360682.885 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2018-05-15T05:04:42.885Z,1526360682.885 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2018-05-15T05:04:42.885Z,1526360682.885 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2018-05-15T05:04:42.886Z,1526360682.886 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2018-05-15T05:04:42.886Z,1526360682.886 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2018-05-15T05:04:42.886Z,1526360682.886 [BuoyancyServo](INFO): Powering down
2018-05-15T05:04:42.901Z,1526360682.901 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2018-05-15T05:04:42.901Z,1526360682.901 [ElevatorServo](INFO): Powering down
2018-05-15T05:04:42.902Z,1526360682.902 [MassServo](DEBUG): Uninitialize Mass Servo.
2018-05-15T05:04:42.902Z,1526360682.902 [MassServo](INFO): Powering down
2018-05-15T05:04:42.903Z,1526360682.903 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2018-05-15T05:04:42.903Z,1526360682.903 [RudderServo](INFO): Powering down
2018-05-15T05:04:42.904Z,1526360682.904 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2018-05-15T05:04:42.904Z,1526360682.904 [ThrusterServo](INFO): Powering down
2018-05-15T05:04:42.905Z,1526360682.905 [SBIT](DEBUG): Uninitialize SBIT Component.
2018-05-15T05:04:42.905Z,1526360682.905 [IBIT](DEBUG): Uninitialize IBIT Component.
2018-05-15T05:04:42.905Z,1526360682.905 [CBIT](DEBUG): Uninitialize CBIT Component.
2018-05-15T05:04:42.906Z,1526360682.906 [controlThread ThreadHandler](INFO): Thread cancelled.
2018-05-15T05:04:43.005Z,1526360683.005 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-05-15T05:04:43.050Z,1526360683.050 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2018-05-15T05:04:43.099Z,1526360683.099 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-05-15T05:04:43.158Z,1526360683.158 [logger ThreadHandler](INFO): Thread cancelled.