2018-05-15T18:25:16.050Z,1526408716.050 [Supervisor](DEBUG): Initializing supervisor.
2018-05-15T18:25:16.053Z,1526408716.053 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2018-05-15T18:25:16.053Z,1526408716.053 [SyncHandler](INFO): Protected caller Thread ID is 2028
2018-05-15T18:25:16.053Z,1526408716.053 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2018-05-15T18:25:16.054Z,1526408716.054 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2018-05-15T18:25:16.055Z,1526408716.055 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 2029
2018-05-15T18:25:16.057Z,1526408716.057 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2018-05-15T18:25:16.068Z,1526408716.068 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2018-05-15T18:25:16.069Z,1526408716.069 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2018-05-15T18:25:16.069Z,1526408716.069 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 2030
2018-05-15T18:25:16.070Z,1526408716.070 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2018-05-15T18:25:16.071Z,1526408716.071 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2018-05-15T18:25:16.071Z,1526408716.071 [logger ThreadHandler](INFO): Protected caller Thread ID is 2031
2018-05-15T18:25:16.073Z,1526408716.073 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2018-05-15T18:25:16.074Z,1526408716.074 [Supervisor](INFO): Looking for Config files in directory: Config/
2018-05-15T18:25:16.075Z,1526408716.075 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2018-05-15T18:25:16.168Z,1526408716.168 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2018-05-15T18:25:16.169Z,1526408716.169 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2018-05-15T18:25:16.266Z,1526408716.266 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2018-05-15T18:25:16.266Z,1526408716.266 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2018-05-15T18:25:16.455Z,1526408716.455 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2018-05-15T18:25:16.455Z,1526408716.455 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2018-05-15T18:25:16.755Z,1526408716.755 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2018-05-15T18:25:16.755Z,1526408716.755 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2018-05-15T18:25:17.068Z,1526408717.068 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2018-05-15T18:25:17.069Z,1526408717.069 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2018-05-15T18:25:17.506Z,1526408717.506 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2018-05-15T18:25:17.507Z,1526408717.507 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2018-05-15T18:25:17.852Z,1526408717.852 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2018-05-15T18:25:17.853Z,1526408717.853 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2018-05-15T18:25:18.273Z,1526408718.273 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2018-05-15T18:25:18.273Z,1526408718.273 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2018-05-15T18:25:18.352Z,1526408718.352 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2018-05-15T18:25:18.644Z,1526408718.644 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2018-05-15T18:25:18.645Z,1526408718.645 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2018-05-15T18:25:18.782Z,1526408718.782 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2018-05-15T18:25:18.783Z,1526408718.783 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2018-05-15T18:25:18.983Z,1526408718.983 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2018-05-15T18:25:18.984Z,1526408718.984 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2018-05-15T18:25:19.185Z,1526408719.185 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2018-05-15T18:25:19.186Z,1526408719.186 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2018-05-15T18:25:19.280Z,1526408719.280 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2018-05-15T18:25:19.281Z,1526408719.281 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2018-05-15T18:25:19.415Z,1526408719.415 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2018-05-15T18:25:19.417Z,1526408719.417 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/
2018-05-15T18:25:19.418Z,1526408719.418 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg
2018-05-15T18:25:19.647Z,1526408719.647 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2018-05-15T18:25:19.648Z,1526408719.648 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg
2018-05-15T18:25:19.723Z,1526408719.723 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg
2018-05-15T18:25:19.859Z,1526408719.859 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg
2018-05-15T18:25:19.948Z,1526408719.948 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg
2018-05-15T18:25:20.031Z,1526408720.031 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg
2018-05-15T18:25:20.162Z,1526408720.162 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg
2018-05-15T18:25:20.328Z,1526408720.328 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg
2018-05-15T18:25:20.422Z,1526408720.422 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg
2018-05-15T18:25:20.511Z,1526408720.511 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg
2018-05-15T18:25:20.604Z,1526408720.604 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg
2018-05-15T18:25:20.685Z,1526408720.685 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2018-05-15T18:25:20.698Z,1526408720.698 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2018-05-15T18:25:20.801Z,1526408720.801 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2018-05-15T18:25:20.802Z,1526408720.802 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2018-05-15T18:25:20.845Z,1526408720.845 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2018-05-15T18:25:20.846Z,1526408720.846 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2018-05-15T18:25:21.010Z,1526408721.010 [DepthRateCalculator] Loaded
2018-05-15T18:25:21.010Z,1526408721.010 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2018-05-15T18:25:21.071Z,1526408721.071 [PitchRateCalculator] Loaded
2018-05-15T18:25:21.072Z,1526408721.072 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2018-05-15T18:25:21.110Z,1526408721.110 [SpeedCalculator] Loaded
2018-05-15T18:25:21.110Z,1526408721.110 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2018-05-15T18:25:21.213Z,1526408721.213 [TempGradientCalculator] Loaded
2018-05-15T18:25:21.214Z,1526408721.214 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2018-05-15T18:25:21.230Z,1526408721.230 [VerticalTemperatureHomogeneityIndexCalculator] Loaded
2018-05-15T18:25:21.230Z,1526408721.230 [ComponentRegistry](DEBUG): SyncComponent "VerticalTemperatureHomogeneityIndexCalculator" handled in the control thread.
2018-05-15T18:25:21.235Z,1526408721.235 [YawRateCalculator] Loaded
2018-05-15T18:25:21.236Z,1526408721.236 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2018-05-15T18:25:21.342Z,1526408721.342 [ElevatorOffsetCalculator] Loaded
2018-05-15T18:25:21.343Z,1526408721.343 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2018-05-15T18:25:21.343Z,1526408721.343 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2018-05-15T18:25:21.344Z,1526408721.344 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2018-05-15T18:25:21.370Z,1526408721.370 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2018-05-15T18:25:21.370Z,1526408721.370 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2018-05-15T18:25:21.775Z,1526408721.775 [AHRS_M2] Loaded
2018-05-15T18:25:21.775Z,1526408721.775 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2018-05-15T18:25:21.818Z,1526408721.818 [AcousticModem_Benthos_ATM900] Loaded
2018-05-15T18:25:21.819Z,1526408721.819 [ComponentRegistry](DEBUG): SyncComponent "AcousticModem_Benthos_ATM900" handled in the control thread.
2018-05-15T18:25:21.885Z,1526408721.885 [DataOverHttps] Loaded
2018-05-15T18:25:21.885Z,1526408721.885 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2018-05-15T18:25:21.898Z,1526408721.898 [Depth_Keller] Loaded
2018-05-15T18:25:21.899Z,1526408721.899 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2018-05-15T18:25:21.899Z,1526408721.899 [Module Loader](CRITICAL): Could not find element GobyModem.loadAtStartup
2018-05-15T18:25:21.997Z,1526408721.997 [NAL9602] Loaded
2018-05-15T18:25:21.997Z,1526408721.997 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2018-05-15T18:25:22.013Z,1526408722.013 [Onboard] Loaded
2018-05-15T18:25:22.013Z,1526408722.013 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2018-05-15T18:25:22.023Z,1526408722.023 [Radio_Surface] Loaded
2018-05-15T18:25:22.023Z,1526408722.023 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2018-05-15T18:25:22.025Z,1526408722.025 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 407B74E0
2018-05-15T18:25:22.025Z,1526408722.025 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 2110
2018-05-15T18:25:22.025Z,1526408722.025 [Module Loader](CRITICAL): Could not find element RDI_Pathfinder.loadAtStartup
2018-05-15T18:25:23.797Z,1526408723.797 [BPC1] Loaded
2018-05-15T18:25:23.797Z,1526408723.797 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2018-05-15T18:25:23.798Z,1526408723.798 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2018-05-15T18:25:23.798Z,1526408723.798 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2018-05-15T18:25:23.932Z,1526408723.932 [SBIT](DEBUG): Construct Startup Built In Test.
2018-05-15T18:25:23.955Z,1526408723.955 [SBIT] Loaded
2018-05-15T18:25:23.955Z,1526408723.955 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2018-05-15T18:25:23.956Z,1526408723.956 [IBIT](DEBUG): Construct Initiated Built In Test.
2018-05-15T18:25:23.967Z,1526408723.967 [IBIT] Loaded
2018-05-15T18:25:23.968Z,1526408723.968 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2018-05-15T18:25:23.971Z,1526408723.971 [CBIT](DEBUG): Construct Continuous Built In Test.
2018-05-15T18:25:24.119Z,1526408724.119 [CBIT] Loaded
2018-05-15T18:25:24.119Z,1526408724.119 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2018-05-15T18:25:24.119Z,1526408724.119 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2018-05-15T18:25:24.120Z,1526408724.120 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2018-05-15T18:25:24.294Z,1526408724.294 [CTD_Seabird] Loaded
2018-05-15T18:25:24.294Z,1526408724.294 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2018-05-15T18:25:24.295Z,1526408724.295 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 408774E0
2018-05-15T18:25:24.295Z,1526408724.295 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 2111
2018-05-15T18:25:24.312Z,1526408724.312 [ESPComponent] Loaded
2018-05-15T18:25:24.312Z,1526408724.312 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2018-05-15T18:25:24.326Z,1526408724.326 [PAR_Licor] Loaded
2018-05-15T18:25:24.326Z,1526408724.326 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2018-05-15T18:25:24.327Z,1526408724.327 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2018-05-15T18:25:24.327Z,1526408724.327 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2018-05-15T18:25:24.573Z,1526408724.573 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2018-05-15T18:25:24.574Z,1526408724.574 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2018-05-15T18:25:24.642Z,1526408724.642 [VerticalControl](DEBUG): Construct VerticalControl.
2018-05-15T18:25:24.735Z,1526408724.735 [VerticalControl] Loaded
2018-05-15T18:25:24.736Z,1526408724.736 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2018-05-15T18:25:24.736Z,1526408724.736 [HorizontalControl](DEBUG): Construct HorizontalControl.
2018-05-15T18:25:24.796Z,1526408724.796 [HorizontalControl] Loaded
2018-05-15T18:25:24.796Z,1526408724.796 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2018-05-15T18:25:24.797Z,1526408724.797 [SpeedControl](DEBUG): Construct SpeedControl.
2018-05-15T18:25:24.802Z,1526408724.802 [SpeedControl] Loaded
2018-05-15T18:25:24.802Z,1526408724.802 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2018-05-15T18:25:24.803Z,1526408724.803 [LoopControl](DEBUG): Construct LoopControl.
2018-05-15T18:25:24.803Z,1526408724.803 [LoopControl] Loaded
2018-05-15T18:25:24.804Z,1526408724.804 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2018-05-15T18:25:24.804Z,1526408724.804 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2018-05-15T18:25:24.805Z,1526408724.805 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2018-05-15T18:25:24.889Z,1526408724.889 [StratificationFrontDetector](INFO): threshold set to: 0.399988 degC
2018-05-15T18:25:24.889Z,1526408724.889 [StratificationFrontDetector](DEBUG): (re)initializing
2018-05-15T18:25:24.889Z,1526408724.889 [StratificationFrontDetector] Loaded
2018-05-15T18:25:24.889Z,1526408724.889 [ComponentRegistry](DEBUG): SyncComponent "StratificationFrontDetector" handled in the control thread.
2018-05-15T18:25:24.890Z,1526408724.890 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2018-05-15T18:25:24.890Z,1526408724.890 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2018-05-15T18:25:24.990Z,1526408724.990 [BuoyancyServo] Loaded
2018-05-15T18:25:24.990Z,1526408724.990 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2018-05-15T18:25:25.001Z,1526408725.001 [ElevatorServo] Loaded
2018-05-15T18:25:25.002Z,1526408725.002 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2018-05-15T18:25:25.012Z,1526408725.012 [MassServo] Loaded
2018-05-15T18:25:25.012Z,1526408725.012 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2018-05-15T18:25:25.023Z,1526408725.023 [RudderServo] Loaded
2018-05-15T18:25:25.024Z,1526408725.024 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2018-05-15T18:25:25.034Z,1526408725.034 [ThrusterServo] Loaded
2018-05-15T18:25:25.034Z,1526408725.034 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2018-05-15T18:25:25.035Z,1526408725.035 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2018-05-15T18:25:25.035Z,1526408725.035 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2018-05-15T18:25:25.132Z,1526408725.132 [DeadReckonUsingMultipleVelocitySources] Loaded
2018-05-15T18:25:25.133Z,1526408725.133 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2018-05-15T18:25:25.188Z,1526408725.188 [DeadReckonUsingSpeedCalculator] Loaded
2018-05-15T18:25:25.188Z,1526408725.188 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2018-05-15T18:25:25.205Z,1526408725.205 [NavChart] Loaded
2018-05-15T18:25:25.205Z,1526408725.205 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2018-05-15T18:25:25.209Z,1526408725.209 [UniversalFixResidualReporter] Loaded
2018-05-15T18:25:25.209Z,1526408725.209 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2018-05-15T18:25:25.209Z,1526408725.209 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2018-05-15T18:25:25.213Z,1526408725.213 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2018-05-15T18:25:25.214Z,1526408725.214 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2018-05-15T18:25:25.220Z,1526408725.220 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2018-05-15T18:25:25.221Z,1526408725.221 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 409D04E0
2018-05-15T18:25:25.222Z,1526408725.222 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 2112
2018-05-15T18:25:25.226Z,1526408725.226 [Supervisor](INFO): Main Thread ID is 2027
2018-05-15T18:25:25.226Z,1526408725.226 [Supervisor](DEBUG): Running supervisor.
2018-05-15T18:25:25.227Z,1526408725.227 [CommandLine ThreadHandler](INFO): Handler Thread ID is 2113
2018-05-15T18:25:25.229Z,1526408725.229 [controlThread ThreadHandler](INFO): Handler Thread ID is 2114
2018-05-15T18:25:25.230Z,1526408725.230 [controlThread](DEBUG): Initializing ControlThread
2018-05-15T18:25:25.230Z,1526408725.230 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2018-05-15T18:25:25.231Z,1526408725.231 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2018-05-15T18:25:25.231Z,1526408725.231 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2018-05-15T18:25:25.231Z,1526408725.231 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2018-05-15T18:25:25.232Z,1526408725.232 [VerticalTemperatureHomogeneityIndexCalculator](DEBUG): (re)initializing
2018-05-15T18:25:25.233Z,1526408725.233 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2018-05-15T18:25:25.233Z,1526408725.233 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2018-05-15T18:25:25.238Z,1526408725.238 [SBIT](INFO): Initialize SBIT Component.
2018-05-15T18:25:25.238Z,1526408725.238 [SBIT](IMPORTANT): git: 2018-03-26-63-g035c652
2018-05-15T18:25:25.238Z,1526408725.238 [SBIT](INFO): git hash: 035c652db7f27c72339a0dc8ffe46f005dcbcd78
2018-05-15T18:25:25.239Z,1526408725.239 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2018-05-15T18:25:25.240Z,1526408725.240 [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-15T18:25:25.241Z,1526408725.241 [SBIT](INFO): Beginning SBIT in 52.000000 seconds.
2018-05-15T18:25:25.241Z,1526408725.241 [IBIT](INFO): Initialize IBIT Component.
2018-05-15T18:25:25.242Z,1526408725.242 [CBIT](DEBUG): Initialize CBIT Component.
2018-05-15T18:25:25.242Z,1526408725.242 [CBIT](CRITICAL): LAST REBOOT DUE TO WATCHDOG TIMER RESET.
2018-05-15T18:25:25.243Z,1526408725.243 [logger ThreadHandler](INFO): Handler Thread ID is 2115
2018-05-15T18:25:25.261Z,1526408725.261 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 2116
2018-05-15T18:25:25.267Z,1526408725.267 [Radio_Surface](INFO): Powering up
2018-05-15T18:25:25.273Z,1526408725.273 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 2117
2018-05-15T18:25:25.274Z,1526408725.274 [CTD_Seabird](INFO): Initializing
2018-05-15T18:25:25.274Z,1526408725.274 [CTD_Seabird](INFO): Checking LCM
2018-05-15T18:25:25.283Z,1526408725.283 [CTD_Seabird](INFO): LCM OK
2018-05-15T18:25:25.283Z,1526408725.283 [CTD_Seabird](INFO): Powering up
2018-05-15T18:25:25.289Z,1526408725.289 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 2118
2018-05-15T18:25:25.292Z,1526408725.292 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2018-05-15T18:25:25.293Z,1526408725.293 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2018-05-15T18:25:25.293Z,1526408725.293 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2018-05-15T18:25:25.293Z,1526408725.293 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2018-05-15T18:25:25.293Z,1526408725.293 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2018-05-15T18:25:25.293Z,1526408725.293 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2018-05-15T18:25:25.294Z,1526408725.294 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2018-05-15T18:25:25.294Z,1526408725.294 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2018-05-15T18:25:25.294Z,1526408725.294 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2018-05-15T18:25:25.294Z,1526408725.294 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2018-05-15T18:25:25.294Z,1526408725.294 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2018-05-15T18:25:25.295Z,1526408725.295 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2018-05-15T18:25:25.295Z,1526408725.295 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2018-05-15T18:25:25.295Z,1526408725.295 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2018-05-15T18:25:25.295Z,1526408725.295 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2018-05-15T18:25:25.295Z,1526408725.295 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2018-05-15T18:25:25.353Z,1526408725.353 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2018-05-15T18:25:25.355Z,1526408725.355 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2018-05-15T18:25:25.355Z,1526408725.355 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2018-05-15T18:25:25.356Z,1526408725.356 [LoopControl](DEBUG): Initialize LoopControlComponent.
2018-05-15T18:25:25.358Z,1526408725.358 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2018-05-15T18:25:25.358Z,1526408725.358 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s.
2018-05-15T18:25:25.359Z,1526408725.359 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s.
2018-05-15T18:25:25.359Z,1526408725.359 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-05-15T18:25:25.360Z,1526408725.360 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-05-15T18:25:25.360Z,1526408725.360 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-05-15T18:25:25.360Z,1526408725.360 [NavChart](DEBUG): Initialize NavChart Navigation.
2018-05-15T18:25:25.361Z,1526408725.361 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2018-05-15T18:25:25.362Z,1526408725.362 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2018-05-15T18:25:25.397Z,1526408725.397 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2018-05-15T18:25:25.423Z,1526408725.423 [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-15T18:25:25.424Z,1526408725.424 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2018-05-15T18:25:25.533Z,1526408725.533 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2018-05-15T18:25:25.534Z,1526408725.534 [Default:A.Wait](DEBUG): Construct Wait.
2018-05-15T18:25:25.536Z,1526408725.536 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2018-05-15T18:25:25.591Z,1526408725.591 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2018-05-15T18:25:25.593Z,1526408725.593 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2018-05-15T18:25:25.639Z,1526408725.639 [Default:E.Execute](DEBUG): Construct Execute.
2018-05-15T18:25:25.642Z,1526408725.642 [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-15T18:25:25.661Z,1526408725.661 [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-15T18:25:25.669Z,1526408725.669 [AHRS_M2](INFO): Start
2018-05-15T18:25:25.669Z,1526408725.669 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2018-05-15T18:25:25.728Z,1526408725.728 [AcousticModem_Benthos_ATM900](INFO): Powering up
2018-05-15T18:25:25.728Z,1526408725.728 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900.
2018-05-15T18:25:25.762Z,1526408725.762 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2018-05-15T18:25:26.054Z,1526408726.054 [ESPComponent](INFO): powering down ESP
2018-05-15T18:25:26.473Z,1526408726.473 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T18:25:26.497Z,1526408726.497 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T18:25:26.605Z,1526408726.605 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2018-05-15T18:25:26.613Z,1526408726.613 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2018-05-15T18:25:26.627Z,1526408726.627 [ElevatorServo](DEBUG): Initializing EZServoServo.
2018-05-15T18:25:26.633Z,1526408726.633 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2018-05-15T18:25:26.655Z,1526408726.655 [MassServo](DEBUG): Initializing EZServoServo.
2018-05-15T18:25:26.665Z,1526408726.665 [MassServo](DEBUG): Initializing MassServo.
2018-05-15T18:25:26.678Z,1526408726.678 [RudderServo](DEBUG): Initializing EZServoServo.
2018-05-15T18:25:26.685Z,1526408726.685 [RudderServo](DEBUG): Initializing RudderServo.
2018-05-15T18:25:26.698Z,1526408726.698 [ThrusterServo](DEBUG): Initializing EZServoServo.
2018-05-15T18:25:26.705Z,1526408726.705 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2018-05-15T18:25:26.730Z,1526408726.730 [CommandLine](FAULT): Scheduling is paused
2018-05-15T18:25:26.731Z,1526408726.731 [CBIT](INFO): Critical error at 20180515T182525
2018-05-15T18:25:26.731Z,1526408726.731 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2018-05-15T18:25:26.829Z,1526408726.829 [AHRS_M2](INFO): Starting
2018-05-15T18:25:26.923Z,1526408726.923 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T18:25:26.924Z,1526408726.924 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T18:25:27.185Z,1526408727.185 [AHRS_M2](INFO): Starting
2018-05-15T18:25:30.785Z,1526408730.785 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface
2018-05-15T18:25:30.900Z,1526408730.900 [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-15T18:25:30.974Z,1526408730.974 [CTD_Seabird](INFO): LCM subscribed to channel:ctd_t.seabird-gpctd
2018-05-15T18:25:31.379Z,1526408731.379 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface
2018-05-15T18:25:31.379Z,1526408731.379 [CTD_Seabird](INFO): Powering down
2018-05-15T18:25:35.831Z,1526408735.831 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T18:25:35.832Z,1526408735.832 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T18:25:36.138Z,1526408736.138 [AHRS_M2](INFO): Starting
2018-05-15T18:25:36.165Z,1526408736.165 [AHRS_M2](FAULT): Failed to initialize
2018-05-15T18:25:36.165Z,1526408736.165 [AHRS_M2] Communications Fault, FailCount= 1
2018-05-15T18:25:36.165Z,1526408736.165 [AHRS_M2](ERROR): Communications Fault
2018-05-15T18:25:36.167Z,1526408736.167 [AcousticModem_Benthos_ATM900](DEBUG): 
2018-05-15T18:25:36.168Z,1526408736.168 [AcousticModem_Benthos_ATM900](DEBUG): Teledyne Benthos ATM-900 Series OEM w/burn wire
2018-05-15T18:25:36.169Z,1526408736.169 [AcousticModem_Benthos_ATM900](DEBUG): MF Frequency Band
2018-05-15T18:25:36.170Z,1526408736.170 [AcousticModem_Benthos_ATM900](DEBUG): Standard version 8.6.3
2018-05-15T18:25:36.170Z,1526408736.170 [AcousticModem_Benthos_ATM900](DEBUG): Apr  6 2000 14:13:07 
2018-05-15T18:25:36.171Z,1526408736.171 [AcousticModem_Benthos_ATM900](DEBUG): WARNING: battery low
2018-05-15T18:25:36.238Z,1526408736.238 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T18:25:36.239Z,1526408736.239 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T18:25:36.270Z,1526408736.270 [CBIT](ERROR): Communications Fault in component: AHRS_M2
2018-05-15T18:25:36.541Z,1526408736.541 [AHRS_M2](INFO): Stop
2018-05-15T18:25:36.541Z,1526408736.541 [AHRS_M2](INFO): uninitialize
2018-05-15T18:25:36.565Z,1526408736.565 [AHRS_M2](INFO): Data-stream disabled.
2018-05-15T18:25:36.566Z,1526408736.566 [AHRS_M2](INFO): Powering down
2018-05-15T18:25:36.697Z,1526408736.697 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T18:25:36.698Z,1526408736.698 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T18:25:36.941Z,1526408736.941 [AHRS_M2](INFO): Stopping
2018-05-15T18:25:36.941Z,1526408736.941 [AcousticModem_Benthos_ATM900](INFO): entering command mode
2018-05-15T18:25:36.948Z,1526408736.948 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004377
2018-05-15T18:25:37.007Z,1526408737.007 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T18:25:37.008Z,1526408737.008 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T18:25:37.341Z,1526408737.341 [AHRS_M2](INFO): Stopping
2018-05-15T18:25:37.341Z,1526408737.341 [AcousticModem_Benthos_ATM900](DEBUG): checking for command mode acknowledgment
2018-05-15T18:25:37.342Z,1526408737.342 [AcousticModem_Benthos_ATM900](DEBUG): read user prompt 1: user:1>
2018-05-15T18:25:37.342Z,1526408737.342 [AcousticModem_Benthos_ATM900](INFO): command mode acknowledged
2018-05-15T18:25:37.396Z,1526408737.396 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T18:25:37.401Z,1526408737.401 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T18:25:37.741Z,1526408737.741 [AHRS_M2](INFO): Stopping
2018-05-15T18:25:37.741Z,1526408737.741 [AcousticModem_Benthos_ATM900](INFO): setting local address to 3
2018-05-15T18:25:37.795Z,1526408737.795 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T18:25:37.797Z,1526408737.797 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T18:25:38.141Z,1526408738.141 [AHRS_M2](INFO): Stopped
2018-05-15T18:25:38.141Z,1526408738.141 [AcousticModem_Benthos_ATM900](DEBUG): checking for local address setting acknowledgment
2018-05-15T18:25:38.142Z,1526408738.142 [AcousticModem_Benthos_ATM900](INFO): set local address to 3
2018-05-15T18:25:38.196Z,1526408738.196 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T18:25:38.198Z,1526408738.198 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T18:25:38.373Z,1526408738.373 [CBIT](INFO): Clearing failed state for component AHRS_M2
2018-05-15T18:25:38.373Z,1526408738.373 [AHRS_M2] No Fault, FailCount= 1
2018-05-15T18:25:38.541Z,1526408738.541 [AHRS_M2](INFO): Start
2018-05-15T18:25:38.541Z,1526408738.541 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2018-05-15T18:25:38.550Z,1526408738.550 [AcousticModem_Benthos_ATM900](DEBUG): read user prompt 2: user:2>
2018-05-15T18:25:38.589Z,1526408738.589 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T18:25:38.591Z,1526408738.591 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T18:25:38.941Z,1526408738.941 [AHRS_M2](INFO): Starting
2018-05-15T18:25:38.981Z,1526408738.981 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T18:25:38.982Z,1526408738.982 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T18:25:39.341Z,1526408739.341 [AHRS_M2](INFO): Starting
2018-05-15T18:25:39.382Z,1526408739.382 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T18:25:39.383Z,1526408739.383 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T18:25:39.741Z,1526408739.741 [AHRS_M2](INFO): Starting
2018-05-15T18:25:39.822Z,1526408739.822 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T18:25:39.823Z,1526408739.823 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T18:25:40.141Z,1526408740.141 [AHRS_M2](INFO): Starting
2018-05-15T18:25:40.214Z,1526408740.214 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T18:25:40.215Z,1526408740.215 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T18:25:40.541Z,1526408740.541 [AHRS_M2](INFO): Starting
2018-05-15T18:25:40.646Z,1526408740.646 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T18:25:40.647Z,1526408740.647 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T18:25:40.941Z,1526408740.941 [AHRS_M2](INFO): Starting
2018-05-15T18:25:41.006Z,1526408741.006 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T18:25:41.007Z,1526408741.007 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T18:25:41.340Z,1526408741.340 [AHRS_M2](INFO): Starting
2018-05-15T18:25:41.412Z,1526408741.412 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T18:25:41.413Z,1526408741.413 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T18:25:41.741Z,1526408741.741 [AHRS_M2](INFO): Starting
2018-05-15T18:25:41.782Z,1526408741.782 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T18:25:41.783Z,1526408741.783 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T18:25:42.141Z,1526408742.141 [AHRS_M2](INFO): Starting
2018-05-15T18:25:42.202Z,1526408742.202 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T18:25:42.203Z,1526408742.203 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T18:25:42.541Z,1526408742.541 [AHRS_M2](INFO): Starting
2018-05-15T18:25:42.597Z,1526408742.597 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T18:25:42.598Z,1526408742.598 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T18:25:42.941Z,1526408742.941 [AHRS_M2](INFO): Starting
2018-05-15T18:25:42.965Z,1526408742.965 [AHRS_M2](INFO): Data-stream active.
2018-05-15T18:25:43.014Z,1526408743.014 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T18:25:43.015Z,1526408743.015 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-05-15T18:25:57.750Z,1526408757.750 [NAL9602](INFO): No messages in MT queue
2018-05-15T18:26:17.815Z,1526408777.815 [SBIT](IMPORTANT): Beginning Startup BIT
2018-05-15T18:26:17.819Z,1526408777.819 [CBIT](IMPORTANT): Beginning ground fault scan
2018-05-15T18:26:31.256Z,1526408791.256 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.007865
CHAN A1 (24V): -0.011884
CHAN A2 (12V): -0.005067
CHAN A3 (5V): -0.002549
CHAN B0 (3.3V): -0.001129
CHAN B1 (3.15aV): -0.001087
CHAN B2 (3.15bV): -0.001464
CHAN B3 (GND): 0.000132
OPEN: -0.000795
Full Scale Calc: 4.765 mA, -1.589 mA
2018-05-15T18:26:55.059Z,1526408815.059 [CommandLine](IMPORTANT): got command load ./Missions/Maintenance/calibrateAHRS_M2.xml
2018-05-15T18:26:55.060Z,1526408815.060 [MissionManager](INFO): Loading Mission: ./Missions/Maintenance/calibrateAHRS_M2.xml
2018-05-15T18:26:55.143Z,1526408815.143 [MissionManager](INFO): DefineArg compassCal.MissionTimeout = 60.000000 min
2018-05-15T18:26:55.146Z,1526408815.146 [MissionManager](INFO): DefineArg compassCal.NeedCommsTime = 6.000000 min
2018-05-15T18:26:55.149Z,1526408815.149 [MissionManager](INFO): DefineArg compassCal.YoYoMinDepth = 2.000000 m
2018-05-15T18:26:55.152Z,1526408815.152 [MissionManager](INFO): DefineArg compassCal.YoYoMaxDepth = 200.000000 m
2018-05-15T18:26:55.179Z,1526408815.179 [MissionManager](INFO): DefineArg compassCal.YoYoMinAltitude = 7.000000 m
2018-05-15T18:26:55.190Z,1526408815.190 [MissionManager](INFO): DefineArg compassCal.YoYoPitch = 30.000000 arcdeg
2018-05-15T18:26:55.202Z,1526408815.202 [MissionManager](INFO): DefineArg compassCal.RudderAngle = 13.000000 arcdeg
2018-05-15T18:26:55.205Z,1526408815.205 [MissionManager](INFO): DefineArg compassCal.Speed = 1.000000 m/s
2018-05-15T18:26:55.211Z,1526408815.211 [MissionManager](INFO): DefineArg compassCal.CalibrationInitTimeout = 2.000000 min
2018-05-15T18:26:55.215Z,1526408815.215 [MissionManager](INFO): DefineArg compassCal.MinAltitude = 5.000000 m
2018-05-15T18:26:55.221Z,1526408815.221 [MissionManager](INFO): DefineArg compassCal.MaxDepth = 205.000000 m
2018-05-15T18:26:55.224Z,1526408815.224 [MissionManager](INFO): DefineArg compassCal.MinOffshore = 2.000000 km
2018-05-15T18:26:55.224Z,1526408815.224 [MissionManager](INFO): Inserting Stack: Missions/Insert/NeedComms.xml
2018-05-15T18:26:55.330Z,1526408815.330 [MissionManager](INFO): DefineArg compassCal:NeedComms.DiveInterval = 3.000000 h
2018-05-15T18:26:55.362Z,1526408815.362 [MissionManager](INFO): DefineArg compassCal:NeedComms.WaitForPitchUp = 10.000000 min
2018-05-15T18:26:55.380Z,1526408815.380 [MissionManager](INFO): DefineArg compassCal:NeedComms.SurfacePitch = 20.000000 arcdeg
2018-05-15T18:26:55.391Z,1526408815.391 [MissionManager](INFO): DefineArg compassCal:NeedComms.SurfaceDepthRate = nan m/s
2018-05-15T18:26:55.399Z,1526408815.399 [MissionManager](INFO): DefineArg compassCal:NeedComms.SurfaceSpeed = 1.000000 m/s
2018-05-15T18:26:55.442Z,1526408815.442 [MissionManager](INFO): DefineArg compassCal:NeedComms.GPSTimeout = 7.000000 min
2018-05-15T18:26:55.452Z,1526408815.452 [MissionManager](INFO): DefineArg compassCal:NeedComms.CommsTimeout = 30.000000 min
2018-05-15T18:26:55.477Z,1526408815.477 [compassCal:NeedComms:B.GoToSurface](DEBUG): Construct GoToSurface.
2018-05-15T18:26:55.507Z,1526408815.507 [MissionManager](INFO): Inserting Stack: Missions/Insert/StandardEnvelopes.xml
2018-05-15T18:26:55.554Z,1526408815.554 [MissionManager](INFO): DefineArg compassCal:StandardEnvelopes.MinAltitude = 5.000000 m
2018-05-15T18:26:55.561Z,1526408815.561 [MissionManager](INFO): DefineArg compassCal:StandardEnvelopes.MaxDepth = 200.000000 m
2018-05-15T18:26:55.569Z,1526408815.569 [MissionManager](INFO): DefineArg compassCal:StandardEnvelopes.MinOffshore = 2000.000000 m
2018-05-15T18:26:55.570Z,1526408815.570 [compassCal:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope.
2018-05-15T18:26:55.582Z,1526408815.582 [compassCal:StandardEnvelopes:B.DepthEnvelope](DEBUG): Construct DepthEnvelope.
2018-05-15T18:26:55.603Z,1526408815.603 [compassCal:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Construct OffshoreEnvelope.
2018-05-15T18:26:55.632Z,1526408815.632 [compassCal:H.Pitch](DEBUG): Construct.
2018-05-15T18:26:55.643Z,1526408815.643 [compassCal:I.Buoyancy](DEBUG): Construct Buoyancy.
2018-05-15T18:26:55.651Z,1526408815.651 [compassCal:J.DepthEnvelope](DEBUG): Construct DepthEnvelope.
2018-05-15T18:26:55.669Z,1526408815.669 [compassCal:K.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope.
2018-05-15T18:26:55.689Z,1526408815.689 [compassCal:L.YoYo](DEBUG): Construct YoYo.
2018-05-15T18:26:55.715Z,1526408815.715 [compassCal:Calibration:WaitForCalibrationInit:A_Timeout:B.Execute](DEBUG): Construct Execute.
2018-05-15T18:26:55.719Z,1526408815.719 [compassCal:Calibration:AcquireCalibrationPoints:A.Point](DEBUG): Construct.
2018-05-15T18:26:55.768Z,1526408815.768 [compassCal:Calibration:AcquireCalibrationPoints:B.SetSpeed](DEBUG): Construct.
2018-05-15T18:26:55.771Z,1526408815.771 [compassCal:Calibration:D.CalibrateAHRS_M2](DEBUG): Construct CalibrateSparton.
2018-05-15T18:26:55.816Z,1526408815.816 [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>60</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>6</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-15T18:26:55.816Z,1526408815.816 [CommandLine](IMPORTANT): Loaded ./Missions/Maintenance/calibrateAHRS_M2.xml
2018-05-15T18:27:09.011Z,1526408829.011 [CommandLine](IMPORTANT): got command maintain sensor NAL9602.latitude_fix 36.796001 degree
2018-05-15T18:27:09.012Z,1526408829.012 [ComponentRegistry](DEBUG): SyncComponent "Maintain_NAL9602.latitude_fix" handled in the control thread.
2018-05-15T18:27:09.013Z,1526408829.013 [CommandLine](IMPORTANT): got command maintain sensor NAL9602.longitude_fix -121.911003 degree
2018-05-15T18:27:09.014Z,1526408829.014 [ComponentRegistry](DEBUG): SyncComponent "Maintain_NAL9602.longitude_fix" handled in the control thread.
2018-05-15T18:27:09.121Z,1526408829.121 [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-15T18:27:11.480Z,1526408831.480 [SBIT](IMPORTANT): SBIT PASSED
2018-05-15T18:27:11.541Z,1526408831.541 [CommandLine](IMPORTANT): got command configSet list
2018-05-15T18:27:11.542Z,1526408831.542 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2018-05-15T18:27:11.542Z,1526408831.542 [CommandLine](IMPORTANT): Aanderaa_O2.loadAtStartup=0 bool;

2018-05-15T18:27:11.543Z,1526408831.543 [CommandLine](IMPORTANT): CBIT.abortDepth=300 meter;

2018-05-15T18:27:11.543Z,1526408831.543 [CommandLine](IMPORTANT): CBIT.gf24Offset=107 microampere;

2018-05-15T18:27:11.543Z,1526408831.543 [CommandLine](IMPORTANT): CBIT.stopDepth=285 meter;

2018-05-15T18:27:11.543Z,1526408831.543 [CommandLine](IMPORTANT): DropWeight.loadAtStartup=0 bool;

2018-05-15T18:27:11.543Z,1526408831.543 [CommandLine](IMPORTANT): ESPComponent.simulateHardware=0 bool;

2018-05-15T18:27:11.543Z,1526408831.543 [CommandLine](IMPORTANT): ElevatorOffsetCalculator.loadAtStartup=1 bool;

2018-05-15T18:27:11.543Z,1526408831.543 [CommandLine](IMPORTANT): NAL9602.simulateHardware=1 bool;

2018-05-15T18:27:11.543Z,1526408831.543 [CommandLine](IMPORTANT): Normal all CTD_Seabird.sea_water_salinity;

2018-05-15T18:27:11.543Z,1526408831.543 [CommandLine](IMPORTANT): Normal all CTD_Seabird.sea_water_temperature;

2018-05-15T18:27:11.544Z,1526408831.544 [CommandLine](IMPORTANT): Rowe_600LCM.loadAtStartup=0 bool;

2018-05-15T18:27:11.544Z,1526408831.544 [CommandLine](IMPORTANT): RudderServo.offsetAngle=0.5 degree;

2018-05-15T18:27:11.544Z,1526408831.544 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=130 cubic_centimeter;

2018-05-15T18:27:11.544Z,1526408831.544 [CommandLine](IMPORTANT): VerticalControl.massDefault=8 millimeter;

2018-05-15T18:27:11.544Z,1526408831.544 [CommandLine](IMPORTANT): WetLabsBB2FL.loadAtStartup=0 bool;

2018-05-15T18:27:11.892Z,1526408831.892 [MissionManager](IMPORTANT): Started mission Startup
2018-05-15T18:27:11.892Z,1526408831.892 [Startup] Running Loop=1
2018-05-15T18:27:11.892Z,1526408831.892 [Startup](DEBUG): Aggregate::initialize Startup
2018-05-15T18:27:11.913Z,1526408831.913 [Startup:A.GoToSurface] Running Loop=1
2018-05-15T18:27:11.913Z,1526408831.913 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-05-15T18:27:11.914Z,1526408831.914 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2018-05-15T18:27:11.914Z,1526408831.914 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2018-05-15T18:27:11.915Z,1526408831.915 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2018-05-15T18:27:11.915Z,1526408831.915 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-05-15T18:27:11.915Z,1526408831.915 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2018-05-15T18:27:11.925Z,1526408831.925 [Startup:StartupSatComms] Running Loop=1
2018-05-15T18:27:11.925Z,1526408831.925 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2018-05-15T18:27:11.925Z,1526408831.925 [Startup:StartupSatComms:A] Running Loop=1
2018-05-15T18:27:12.287Z,1526408832.287 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2018-05-15T18:27:12.289Z,1526408832.289 [Startup:StartupSatComms:A] Stopped
2018-05-15T18:27:12.289Z,1526408832.289 [Startup:StartupSatComms:B] Running Loop=1
2018-05-15T18:27:12.687Z,1526408832.687 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2018-05-15T18:27:18.289Z,1526408838.289 [DataOverHttps](INFO): Sending 43 bytes from file Logs/20180515T180049/Courier0010.lzma
2018-05-15T18:27:19.057Z,1526408839.057 [DataOverHttps](INFO): Moved sent file to Logs/20180515T180049/Courier0010.lzma.bak
2018-05-15T18:27:19.057Z,1526408839.057 [DataOverHttps](INFO): SBD MOMSN=8282505
2018-05-15T18:27:26.677Z,1526408846.677 [AHRS_M2](ERROR): SAPP frame error: SOH not found.
2018-05-15T18:27:29.879Z,1526408849.879 [DataOverHttps](INFO): Sending 188 bytes from file Logs/20180515T182516/Courier0000.lzma
2018-05-15T18:27:30.631Z,1526408850.631 [CommandLine](IMPORTANT): got command set NAL9602.time_fix 1526408832.000000 second
2018-05-15T18:27:30.678Z,1526408850.678 [DataOverHttps](INFO): Moved sent file to Logs/20180515T182516/Courier0000.lzma.bak
2018-05-15T18:27:30.678Z,1526408850.678 [DataOverHttps](INFO): SBD MOMSN=8282507
2018-05-15T18:27:40.948Z,1526408860.948 [DataOverHttps](INFO): Sending 370 bytes from file Logs/20180515T180049/Express0011.lzma
2018-05-15T18:27:41.746Z,1526408861.746 [DataOverHttps](INFO): Moved sent file to Logs/20180515T180049/Express0011.lzma.bak
2018-05-15T18:27:41.746Z,1526408861.746 [DataOverHttps](INFO): SBD MOMSN=8282513
2018-05-15T18:27:51.655Z,1526408871.655 [DataOverHttps](INFO): Sending 1050 bytes from file Logs/20180515T182516/Express0001.lzma
2018-05-15T18:27:52.427Z,1526408872.427 [DataOverHttps](INFO): Moved sent file to Logs/20180515T182516/Express0001.lzma.bak
2018-05-15T18:27:52.427Z,1526408872.427 [DataOverHttps](INFO): SBD MOMSN=8282525
2018-05-15T18:27:53.482Z,1526408873.482 [Startup:StartupSatComms:B] Stopped
2018-05-15T18:27:53.482Z,1526408873.482 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2018-05-15T18:27:53.482Z,1526408873.482 [Startup:StartupSatComms] Stopped
2018-05-15T18:27:53.483Z,1526408873.483 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2018-05-15T18:27:53.483Z,1526408873.483 [Startup](INFO): Completed Startup
2018-05-15T18:27:53.484Z,1526408873.484 [MissionManager](INFO): Startup is completed.
2018-05-15T18:27:53.484Z,1526408873.484 [MissionManager](INFO): Uninitializing Mission Startup
2018-05-15T18:27:53.484Z,1526408873.484 [Startup] Stopped
2018-05-15T18:27:53.484Z,1526408873.484 [Startup](DEBUG): Aggregate::uninitialize Startup
2018-05-15T18:27:53.484Z,1526408873.484 [Startup:A.GoToSurface] Stopped
2018-05-15T18:27:53.484Z,1526408873.484 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2018-05-15T18:27:53.625Z,1526408873.625 [MissionManager](IMPORTANT): Started mission Default
2018-05-15T18:27:53.626Z,1526408873.626 [Default] Running Loop=1
2018-05-15T18:27:53.626Z,1526408873.626 [Default](DEBUG): Aggregate::initialize Default
2018-05-15T18:27:53.626Z,1526408873.626 [Default:B.GoToSurface] Running Loop=1
2018-05-15T18:27:53.626Z,1526408873.626 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-05-15T18:27:53.626Z,1526408873.626 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2018-05-15T18:27:53.627Z,1526408873.627 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2018-05-15T18:27:53.627Z,1526408873.627 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2018-05-15T18:27:53.627Z,1526408873.627 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-05-15T18:27:53.627Z,1526408873.627 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2018-05-15T18:27:53.628Z,1526408873.628 [Default:A.Wait] Running Loop=1
2018-05-15T18:27:53.628Z,1526408873.628 [Default:A.Wait](DEBUG): Initialize Wait Component.
2018-05-15T18:28:03.789Z,1526408883.789 [CommandLine](IMPORTANT): got command run
2018-05-15T18:28:03.798Z,1526408883.798 [CommandLine](IMPORTANT): Running 
2018-05-15T18:28:04.005Z,1526408884.005 [Default] Stopped
2018-05-15T18:28:04.005Z,1526408884.005 [Default](DEBUG): Aggregate::uninitialize Default
2018-05-15T18:28:04.005Z,1526408884.005 [Default:A.Wait] Stopped
2018-05-15T18:28:04.005Z,1526408884.005 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2018-05-15T18:28:04.006Z,1526408884.006 [Default:B.GoToSurface] Stopped
2018-05-15T18:28:04.006Z,1526408884.006 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2018-05-15T18:28:04.006Z,1526408884.006 [MissionManager](IMPORTANT): Started mission compassCal
2018-05-15T18:28:04.006Z,1526408884.006 [compassCal] Running Loop=1
2018-05-15T18:28:04.006Z,1526408884.006 [compassCal](DEBUG): Aggregate::initialize compassCal
2018-05-15T18:28:04.006Z,1526408884.006 [compassCal:StandardEnvelopes] Running Loop=1
2018-05-15T18:28:04.006Z,1526408884.006 [compassCal:StandardEnvelopes](DEBUG): Aggregate::initialize compassCal:StandardEnvelopes
2018-05-15T18:28:04.006Z,1526408884.006 [compassCal:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1
2018-05-15T18:28:04.006Z,1526408884.006 [compassCal:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent.
2018-05-15T18:28:04.007Z,1526408884.007 [compassCal:StandardEnvelopes:B.DepthEnvelope] Running Loop=1
2018-05-15T18:28:04.007Z,1526408884.007 [compassCal:StandardEnvelopes:B.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent.
2018-05-15T18:28:04.007Z,1526408884.007 [compassCal:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1
2018-05-15T18:28:04.007Z,1526408884.007 [compassCal:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Initialize OffshoreEnvelopeComponent.
2018-05-15T18:28:04.007Z,1526408884.007 [compassCal:H.Pitch] Running Loop=1
2018-05-15T18:28:04.007Z,1526408884.007 [compassCal:H.Pitch](DEBUG): Initialize.
2018-05-15T18:28:04.008Z,1526408884.008 [compassCal:I.Buoyancy] Running Loop=1
2018-05-15T18:28:04.008Z,1526408884.008 [compassCal:I.Buoyancy](DEBUG): Initialize Buoyancy Component.
2018-05-15T18:28:04.008Z,1526408884.008 [compassCal:J.DepthEnvelope] Running Loop=1
2018-05-15T18:28:04.008Z,1526408884.008 [compassCal:J.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent.
2018-05-15T18:28:04.008Z,1526408884.008 [compassCal:K.AltitudeEnvelope] Running Loop=1
2018-05-15T18:28:04.008Z,1526408884.008 [compassCal:K.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent.
2018-05-15T18:28:04.008Z,1526408884.008 [compassCal:L.YoYo] Running Loop=1
2018-05-15T18:28:04.008Z,1526408884.008 [compassCal:L.YoYo](DEBUG): Initialize YoYoComponent.
2018-05-15T18:28:04.009Z,1526408884.009 [compassCal:B] Running Loop=1
2018-05-15T18:28:04.009Z,1526408884.009 [compassCal:L.YoYo] Running Loop=1
2018-05-15T18:28:04.014Z,1526408884.014 [compassCal:K.AltitudeEnvelope] Running Loop=1
2018-05-15T18:28:04.019Z,1526408884.019 [compassCal:J.DepthEnvelope] Running Loop=1
2018-05-15T18:28:04.024Z,1526408884.024 [compassCal:I.Buoyancy] Running Loop=1
2018-05-15T18:28:04.055Z,1526408884.055 [compassCal:H.Pitch] Running Loop=1
2018-05-15T18:28:04.060Z,1526408884.060 [compassCal:StandardEnvelopes] Running Loop=1
2018-05-15T18:28:04.060Z,1526408884.060 [compassCal:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1
2018-05-15T18:28:04.077Z,1526408884.077 [compassCal:StandardEnvelopes:B.DepthEnvelope] Running Loop=1
2018-05-15T18:28:04.081Z,1526408884.081 [compassCal:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1
2018-05-15T18:28:04.087Z,1526408884.087 [compassCal:B] Stopped
2018-05-15T18:28:04.087Z,1526408884.087 [compassCal:D] Running Loop=1
2018-05-15T18:28:04.418Z,1526408884.418 [compassCal:D] Stopped
2018-05-15T18:28:04.418Z,1526408884.418 [compassCal:E] Running Loop=1
2018-05-15T18:28:04.805Z,1526408884.805 [compassCal:E] Stopped
2018-05-15T18:28:04.805Z,1526408884.805 [compassCal:F] Running Loop=1
2018-05-15T18:28:05.206Z,1526408885.206 [compassCal:F] Stopped
2018-05-15T18:28:05.206Z,1526408885.206 [compassCal:StartingMission] Running Loop=1
2018-05-15T18:28:05.206Z,1526408885.206 [compassCal:StartingMission](DEBUG): Aggregate::initialize compassCal:StartingMission
2018-05-15T18:28:05.605Z,1526408885.605 [compassCal:NeedComms] Running Loop=1
2018-05-15T18:28:05.605Z,1526408885.605 [compassCal:NeedComms](DEBUG): Aggregate::initialize compassCal:NeedComms
2018-05-15T18:28:05.605Z,1526408885.605 [compassCal:NeedComms:B.GoToSurface] Running Loop=1
2018-05-15T18:28:05.605Z,1526408885.605 [compassCal:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-05-15T18:28:05.606Z,1526408885.606 [compassCal:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s.
2018-05-15T18:28:05.606Z,1526408885.606 [compassCal:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees.
2018-05-15T18:28:05.606Z,1526408885.606 [compassCal:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s.
2018-05-15T18:28:05.607Z,1526408885.607 [compassCal:NeedComms:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-05-15T18:28:05.607Z,1526408885.607 [compassCal:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2018-05-15T18:28:05.607Z,1526408885.607 [compassCal:NeedComms:A] Running Loop=1
2018-05-15T18:28:05.613Z,1526408885.613 [compassCal:NeedComms:A](INFO): last time_fix was: 1526408832.000000 second since 1970/01/01T00:00:00Z 
2018-05-15T18:28:05.614Z,1526408885.614 [compassCal:NeedComms:A] Stopped
2018-05-15T18:28:05.957Z,1526408885.957 [NAL9602](INFO): Powering down
2018-05-15T18:28:06.072Z,1526408886.072 [compassCal:NeedComms:C] Running Loop=1
2018-05-15T18:28:06.421Z,1526408886.421 [compassCal:NeedComms:C](DEBUG): Initialize ReadDataComponent to sense time_fix
2018-05-15T18:28:06.761Z,1526408886.761 [NAL9602](INFO): Powering up
2018-05-15T18:28:13.158Z,1526408893.158 [NAL9602](INFO): No messages in MT queue
2018-05-15T18:28:23.343Z,1526408903.343 [CommandLine](IMPORTANT): got command set NAL9602.time_fix 1526408832.000000 second
2018-05-15T18:28:23.607Z,1526408903.607 [compassCal:NeedComms:C] Stopped
2018-05-15T18:28:23.607Z,1526408903.607 [compassCal:NeedComms:D] Running Loop=1
2018-05-15T18:28:24.002Z,1526408904.002 [compassCal:NeedComms:D](DEBUG): Initialize ReadDataComponent to sense platform_communications
2018-05-15T18:28:28.042Z,1526408908.042 [DataOverHttps](INFO): Sending 146 bytes from file Logs/20180515T182516/Courier0004.lzma
2018-05-15T18:28:28.826Z,1526408908.826 [DataOverHttps](INFO): Moved sent file to Logs/20180515T182516/Courier0004.lzma.bak
2018-05-15T18:28:28.827Z,1526408908.827 [DataOverHttps](INFO): SBD MOMSN=8282558
2018-05-15T18:28:40.434Z,1526408920.434 [DataOverHttps](INFO): Sending 321 bytes from file Logs/20180515T182516/Express0005.lzma
2018-05-15T18:28:41.203Z,1526408921.203 [DataOverHttps](INFO): Moved sent file to Logs/20180515T182516/Express0005.lzma.bak
2018-05-15T18:28:41.203Z,1526408921.203 [DataOverHttps](INFO): SBD MOMSN=8282560
2018-05-15T18:28:42.506Z,1526408922.506 [CommandLine](IMPORTANT): got command set NAL9602.time_fix 1526408960.000000 second
2018-05-15T18:28:43.271Z,1526408923.271 [compassCal:NeedComms:D] Stopped
2018-05-15T18:28:43.272Z,1526408923.272 [compassCal:NeedComms:E] Running Loop=1
2018-05-15T18:28:43.466Z,1526408923.466 [compassCal:NeedComms:E](DEBUG): Initialize ReadDataComponent to sense time_fix
2018-05-15T18:29:04.437Z,1526408944.437 [CommandLine](IMPORTANT): got command set NAL9602.time_fix 1526408960.000000 second
2018-05-15T18:29:04.672Z,1526408944.672 [compassCal:NeedComms:E] Stopped
2018-05-15T18:29:04.677Z,1526408944.677 [compassCal:NeedComms](INFO): Completed compassCal:NeedComms
2018-05-15T18:29:04.677Z,1526408944.677 [compassCal:NeedComms] Stopped
2018-05-15T18:29:04.677Z,1526408944.677 [compassCal:NeedComms](DEBUG): Aggregate::uninitialize compassCal:NeedComms
2018-05-15T18:29:04.677Z,1526408944.677 [compassCal:NeedComms:B.GoToSurface] Stopped
2018-05-15T18:29:04.677Z,1526408944.677 [compassCal:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2018-05-15T18:29:05.068Z,1526408945.068 [compassCal:StartingMission](INFO): Completed compassCal:StartingMission
2018-05-15T18:29:05.069Z,1526408945.069 [compassCal:StartingMission] Stopped
2018-05-15T18:29:05.069Z,1526408945.069 [compassCal:StartingMission](DEBUG): Aggregate::uninitialize compassCal:StartingMission
2018-05-15T18:29:05.069Z,1526408945.069 [compassCal:Calibration] Running Loop=1
2018-05-15T18:29:05.069Z,1526408945.069 [compassCal:Calibration](DEBUG): Aggregate::initialize compassCal:Calibration
2018-05-15T18:29:05.069Z,1526408945.069 [compassCal:Calibration:D.CalibrateAHRS_M2] Running Loop=1
2018-05-15T18:29:05.069Z,1526408945.069 [compassCal:Calibration:D.CalibrateAHRS_M2](INFO): Initialize CalibrateSpartonComponent.
2018-05-15T18:29:05.069Z,1526408945.069 [compassCal:Calibration:WaitForCalibrationInit] Running Loop=1
2018-05-15T18:29:05.461Z,1526408945.461 [AHRS_M2](INFO): Data-stream disabled.
2018-05-15T18:29:05.485Z,1526408945.485 [AHRS_M2](INFO): Set clearPointCal.
2018-05-15T18:29:05.552Z,1526408945.552 [DeadReckonUsingMultipleVelocitySources](DEBUG): Most recent orientation data is 0.490493 seconds old.
2018-05-15T18:29:05.554Z,1526408945.554 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 0.491048 seconds old.
2018-05-15T18:29:05.562Z,1526408945.562 [compassCal:Calibration:D.CalibrateAHRS_M2] Running Loop=1
2018-05-15T18:29:05.562Z,1526408945.562 [compassCal:Calibration:D.CalibrateAHRS_M2](INFO): Initialize CalibrateSpartonComponent.
2018-05-15T18:29:05.571Z,1526408945.571 [compassCal:Calibration:WaitForCalibrationInit](DEBUG): Initialize ReadDataComponent to sense AHRS_M2.CompassCalState
2018-05-15T18:29:05.829Z,1526408945.829 [AHRS_M2](INFO): Set initCalPointBuffer.
2018-05-15T18:29:05.892Z,1526408945.892 [DeadReckonUsingMultipleVelocitySources](DEBUG): Most recent orientation data is 0.830426 seconds old.
2018-05-15T18:29:05.909Z,1526408945.909 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 0.845875 seconds old.
2018-05-15T18:29:05.913Z,1526408945.913 [compassCal:Calibration:D.CalibrateAHRS_M2](INFO): Initialize CalibrateSpartonComponent.
2018-05-15T18:29:06.229Z,1526408946.229 [AHRS_M2](INFO): Set autoFieldCalActive.
2018-05-15T18:29:06.254Z,1526408946.254 [AHRS_M2](INFO): Data-stream active.
2018-05-15T18:29:06.285Z,1526408946.285 [DeadReckonUsingMultipleVelocitySources](DEBUG): Most recent orientation data is 1.224143 seconds old.
2018-05-15T18:29:06.287Z,1526408946.287 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 1.224460 seconds old.
2018-05-15T18:29:06.313Z,1526408946.313 [compassCal:Calibration:D.CalibrateAHRS_M2](INFO): Initialize CalibrateSpartonComponent.
2018-05-15T18:29:06.313Z,1526408946.313 [compassCal:Calibration:WaitForCalibrationInit] Stopped
2018-05-15T18:29:06.314Z,1526408946.314 [compassCal:Calibration:B] Running Loop=1
2018-05-15T18:29:06.662Z,1526408946.662 [compassCal:Calibration:B](IMPORTANT): AdaptCal initialized. Acquiring calibration points.
2018-05-15T18:29:06.663Z,1526408946.663 [compassCal:Calibration:B] Stopped
2018-05-15T18:29:06.663Z,1526408946.663 [compassCal:Calibration:AcquireCalibrationPoints] Running Loop=1
2018-05-15T18:29:06.663Z,1526408946.663 [compassCal:Calibration:AcquireCalibrationPoints](DEBUG): Aggregate::initialize compassCal:Calibration:AcquireCalibrationPoints
2018-05-15T18:29:06.663Z,1526408946.663 [compassCal:Calibration:AcquireCalibrationPoints:A.Point] Running Loop=1
2018-05-15T18:29:06.664Z,1526408946.664 [compassCal:Calibration:AcquireCalibrationPoints:A.Point](DEBUG): Initialize.
2018-05-15T18:29:06.664Z,1526408946.664 [compassCal:Calibration:AcquireCalibrationPoints:B.SetSpeed] Running Loop=1
2018-05-15T18:29:06.664Z,1526408946.664 [compassCal:Calibration:AcquireCalibrationPoints:B.SetSpeed](DEBUG): Initialize.
2018-05-15T18:29:07.070Z,1526408947.070 [compassCal:Calibration:AcquireCalibrationPoints:B.SetSpeed] Running Loop=1
2018-05-15T18:29:07.079Z,1526408947.079 [compassCal:Calibration:AcquireCalibrationPoints:A.Point] Running Loop=1
2018-05-15T18:29:38.229Z,1526408978.229 [NAL9602](INFO): Powering down
2018-05-15T18:29:44.803Z,1526408984.803 [CommandLine](IMPORTANT): got command configSet AHRS_M2.verbosity 1.000000 count
2018-05-15T18:29:47.115Z,1526408987.115 [AHRS_M2](INFO): CRC match. PITCH: -89.012849 deg, ROLL: -92.926629 deg, YAW: 243.753305 deg, TEMP: 28.093636 C.
2018-05-15T18:29:47.516Z,1526408987.516 [AHRS_M2](INFO): CRC match. PITCH: -89.014632 deg, ROLL: -92.691439 deg, YAW: 243.508347 deg, TEMP: 28.081396 C.
2018-05-15T18:29:47.913Z,1526408987.913 [AHRS_M2](INFO): CRC match. PITCH: -89.014830 deg, ROLL: -93.283554 deg, YAW: 244.125933 deg, TEMP: 28.087515 C.
2018-05-15T18:29:48.314Z,1526408988.314 [AHRS_M2](INFO): CRC match. PITCH: -89.015424 deg, ROLL: -93.145878 deg, YAW: 243.975286 deg, TEMP: 28.090576 C.
2018-05-15T18:29:48.714Z,1526408988.714 [AHRS_M2](INFO): CRC match. PITCH: -89.010274 deg, ROLL: -92.629448 deg, YAW: 243.457203 deg, TEMP: 28.090576 C.
2018-05-15T18:29:49.114Z,1526408989.114 [AHRS_M2](INFO): CRC match. PITCH: -89.011073 deg, ROLL: -92.507829 deg, YAW: 243.333767 deg, TEMP: 28.087515 C.
2018-05-15T18:29:49.514Z,1526408989.514 [AHRS_M2](INFO): CRC match. PITCH: -89.006920 deg, ROLL: -92.759016 deg, YAW: 243.616483 deg, TEMP: 28.093636 C.
2018-05-15T18:29:49.914Z,1526408989.914 [AHRS_M2](INFO): CRC match. PITCH: -89.015226 deg, ROLL: -93.151431 deg, YAW: 243.985723 deg, TEMP: 28.096695 C.
2018-05-15T18:29:50.313Z,1526408990.313 [AHRS_M2](INFO): CRC match. PITCH: -89.015226 deg, ROLL: -93.355914 deg, YAW: 244.195409 deg, TEMP: 28.084455 C.
2018-05-15T18:29:50.715Z,1526408990.715 [AHRS_M2](INFO): CRC match. PITCH: -89.010076 deg, ROLL: -93.324952 deg, YAW: 244.183252 deg, TEMP: 28.087515 C.
2018-05-15T18:29:51.116Z,1526408991.116 [AHRS_M2](INFO): CRC match. PITCH: -89.015226 deg, ROLL: -93.452404 deg, YAW: 244.291387 deg, TEMP: 28.111996 C.
2018-05-15T18:29:51.516Z,1526408991.516 [AHRS_M2](INFO): CRC match. PITCH: -89.017220 deg, ROLL: -93.593556 deg, YAW: 244.424357 deg, TEMP: 28.102816 C.
2018-05-15T18:29:51.917Z,1526408991.917 [AHRS_M2](INFO): CRC match. PITCH: -89.020212 deg, ROLL: -92.971674 deg, YAW: 243.774533 deg, TEMP: 28.099754 C.
2018-05-15T18:29:52.314Z,1526408992.314 [AHRS_M2](INFO): CRC match. PITCH: -89.015424 deg, ROLL: -93.117178 deg, YAW: 243.945916 deg, TEMP: 28.096695 C.
2018-05-15T18:29:52.713Z,1526408992.713 [AHRS_M2](INFO): CRC match. PITCH: -89.018614 deg, ROLL: -93.264177 deg, YAW: 244.084460 deg, TEMP: 28.099754 C.
2018-05-15T18:29:53.114Z,1526408993.114 [AHRS_M2](INFO): CRC match. PITCH: -89.020212 deg, ROLL: -93.555628 deg, YAW: 244.381136 deg, TEMP: 28.090576 C.
2018-05-15T18:29:53.514Z,1526408993.514 [AHRS_M2](INFO): CRC match. PITCH: -89.015636 deg, ROLL: -93.650882 deg, YAW: 244.498533 deg, TEMP: 28.099754 C.
2018-05-15T18:29:53.913Z,1526408993.913 [AHRS_M2](INFO): CRC match. PITCH: -89.012453 deg, ROLL: -93.348585 deg, YAW: 244.194644 deg, TEMP: 28.105875 C.
2018-05-15T18:29:54.314Z,1526408994.314 [AHRS_M2](INFO): CRC match. PITCH: -89.021407 deg, ROLL: -93.231563 deg, YAW: 244.035774 deg, TEMP: 28.087515 C.
2018-05-15T18:29:54.714Z,1526408994.714 [AHRS_M2](INFO): CRC match. PITCH: -89.009482 deg, ROLL: -93.425882 deg, YAW: 244.297480 deg, TEMP: 28.111996 C.
2018-05-15T18:29:55.113Z,1526408995.113 [AHRS_M2](INFO): CRC match. PITCH: -89.010677 deg, ROLL: -93.742837 deg, YAW: 244.626422 deg, TEMP: 28.099754 C.
2018-05-15T18:29:55.515Z,1526408995.515 [AHRS_M2](INFO): CRC match. PITCH: -89.007706 deg, ROLL: -93.362307 deg, YAW: 244.246581 deg, TEMP: 28.090576 C.
2018-05-15T18:29:55.916Z,1526408995.916 [AHRS_M2](INFO): CRC match. PITCH: -89.011073 deg, ROLL: -93.583728 deg, YAW: 244.445777 deg, TEMP: 28.081396 C.
2018-05-15T18:29:56.316Z,1526408996.316 [AHRS_M2](INFO): CRC match. PITCH: -89.015028 deg, ROLL: -93.767187 deg, YAW: 244.618307 deg, TEMP: 28.096695 C.
2018-05-15T18:29:56.714Z,1526408996.714 [AHRS_M2](INFO): CRC match. PITCH: -89.018013 deg, ROLL: -94.047006 deg, YAW: 244.895586 deg, TEMP: 28.099754 C.
2018-05-15T18:29:57.114Z,1526408997.114 [AHRS_M2](INFO): CRC match. PITCH: -89.016626 deg, ROLL: -94.517981 deg, YAW: 245.391294 deg, TEMP: 28.090576 C.
2018-05-15T18:29:57.513Z,1526408997.513 [AHRS_M2](INFO): CRC match. PITCH: -89.014830 deg, ROLL: -93.994345 deg, YAW: 244.851736 deg, TEMP: 28.072216 C.
2018-05-15T18:29:57.914Z,1526408997.914 [AHRS_M2](INFO): CRC match. PITCH: -89.018416 deg, ROLL: -93.567800 deg, YAW: 244.389961 deg, TEMP: 28.090576 C.
2018-05-15T18:29:58.314Z,1526408998.314 [AHRS_M2](INFO): CRC match. PITCH: -89.024214 deg, ROLL: -93.613200 deg, YAW: 244.425150 deg, TEMP: 28.105875 C.
2018-05-15T18:29:58.713Z,1526408998.713 [AHRS_M2](INFO): CRC match. PITCH: -89.022206 deg, ROLL: -93.744654 deg, YAW: 244.570824 deg, TEMP: 28.099754 C.
2018-05-15T18:29:59.114Z,1526408999.114 [AHRS_M2](INFO): CRC match. PITCH: -89.017418 deg, ROLL: -93.267763 deg, YAW: 244.096754 deg, TEMP: 28.078335 C.
2018-05-15T18:29:59.514Z,1526408999.514 [AHRS_M2](INFO): CRC match. PITCH: -89.020014 deg, ROLL: -93.311422 deg, YAW: 244.123747 deg, TEMP: 28.099754 C.
2018-05-15T18:29:59.913Z,1526408999.913 [AHRS_M2](INFO): CRC match. PITCH: -89.012651 deg, ROLL: -93.601623 deg, YAW: 244.456896 deg, TEMP: 28.105875 C.
2018-05-15T18:30:00.314Z,1526409000.314 [AHRS_M2](INFO): CRC match. PITCH: -89.015834 deg, ROLL: -93.286061 deg, YAW: 244.111589 deg, TEMP: 28.108936 C.
2018-05-15T18:30:00.714Z,1526409000.714 [AHRS_M2](INFO): CRC match. PITCH: -89.021810 deg, ROLL: -93.135210 deg, YAW: 243.933485 deg, TEMP: 28.087515 C.
2018-05-15T18:30:01.113Z,1526409001.113 [AHRS_M2](INFO): CRC match. PITCH: -89.021605 deg, ROLL: -93.217862 deg, YAW: 244.017524 deg, TEMP: 28.087515 C.
2018-05-15T18:30:01.514Z,1526409001.514 [AHRS_M2](INFO): CRC match. PITCH: -89.026823 deg, ROLL: -93.130142 deg, YAW: 243.896739 deg, TEMP: 28.087515 C.
2018-05-15T18:30:01.913Z,1526409001.913 [AHRS_M2](INFO): CRC match. PITCH: -89.021810 deg, ROLL: -93.249615 deg, YAW: 244.042987 deg, TEMP: 28.099754 C.
2018-05-15T18:30:02.314Z,1526409002.314 [AHRS_M2](INFO): CRC match. PITCH: -89.023606 deg, ROLL: -93.730017 deg, YAW: 244.540361 deg, TEMP: 28.078335 C.
2018-05-15T18:30:02.717Z,1526409002.717 [AHRS_M2](INFO): CRC match. PITCH: -89.021004 deg, ROLL: -93.740692 deg, YAW: 244.569704 deg, TEMP: 28.099754 C.
2018-05-15T18:30:03.113Z,1526409003.113 [AHRS_M2](INFO): CRC match. PITCH: -89.014632 deg, ROLL: -93.510119 deg, YAW: 244.358760 deg, TEMP: 28.075275 C.
2018-05-15T18:30:03.516Z,1526409003.516 [AHRS_M2](INFO): CRC match. PITCH: -89.012651 deg, ROLL: -93.411272 deg, YAW: 244.256826 deg, TEMP: 28.093636 C.
2018-05-15T18:30:03.914Z,1526409003.914 [AHRS_M2](INFO): CRC match. PITCH: -89.015834 deg, ROLL: -93.377825 deg, YAW: 244.221337 deg, TEMP: 28.099754 C.
2018-05-15T18:30:04.314Z,1526409004.314 [AHRS_M2](INFO): CRC match. PITCH: -89.019010 deg, ROLL: -93.309386 deg, YAW: 244.135276 deg, TEMP: 28.105875 C.
2018-05-15T18:30:04.713Z,1526409004.713 [AHRS_M2](INFO): CRC match. PITCH: -89.015834 deg, ROLL: -93.017491 deg, YAW: 243.843545 deg, TEMP: 28.096695 C.
2018-05-15T18:30:05.114Z,1526409005.114 [AHRS_M2](INFO): CRC match. PITCH: -89.012262 deg, ROLL: -93.093156 deg, YAW: 243.939469 deg, TEMP: 28.087515 C.
2018-05-15T18:30:05.514Z,1526409005.514 [AHRS_M2](INFO): CRC match. PITCH: -89.011865 deg, ROLL: -93.277653 deg, YAW: 244.135031 deg, TEMP: 28.084455 C.
2018-05-15T18:30:05.913Z,1526409005.913 [AHRS_M2](INFO): CRC match. PITCH: -89.019208 deg, ROLL: -93.077529 deg, YAW: 243.889472 deg, TEMP: 28.078335 C.
2018-05-15T18:30:06.314Z,1526409006.314 [AHRS_M2](INFO): CRC match. PITCH: -89.018614 deg, ROLL: -93.011508 deg, YAW: 243.824038 deg, TEMP: 28.087515 C.
2018-05-15T18:30:06.714Z,1526409006.714 [AHRS_M2](INFO): CRC match. PITCH: -89.020410 deg, ROLL: -92.967064 deg, YAW: 243.774806 deg, TEMP: 28.087515 C.
2018-05-15T18:30:07.113Z,1526409007.113 [AHRS_M2](INFO): CRC match. PITCH: -89.016824 deg, ROLL: -92.902061 deg, YAW: 243.705849 deg, TEMP: 28.093636 C.
2018-05-15T18:30:07.514Z,1526409007.514 [AHRS_M2](INFO): CRC match. PITCH: -89.016824 deg, ROLL: -92.928118 deg, YAW: 243.735656 deg, TEMP: 28.096695 C.
2018-05-15T18:30:07.915Z,1526409007.915 [AHRS_M2](INFO): CRC match. PITCH: -89.020212 deg, ROLL: -92.475680 deg, YAW: 243.257160 deg, TEMP: 28.087515 C.
2018-05-15T18:30:08.316Z,1526409008.316 [AHRS_M2](INFO): CRC match. PITCH: -89.021605 deg, ROLL: -92.928118 deg, YAW: 243.718771 deg, TEMP: 28.081396 C.
2018-05-15T18:30:08.718Z,1526409008.718 [AHRS_M2](INFO): CRC match. PITCH: -89.020806 deg, ROLL: -93.168739 deg, YAW: 243.972417 deg, TEMP: 28.096695 C.
2018-05-15T18:30:09.117Z,1526409009.117 [AHRS_M2](INFO): CRC match. PITCH: -89.020608 deg, ROLL: -93.516532 deg, YAW: 244.332669 deg, TEMP: 28.099754 C.
2018-05-15T18:30:09.513Z,1526409009.513 [AHRS_M2](INFO): CRC match. PITCH: -89.011865 deg, ROLL: -93.480551 deg, YAW: 244.352367 deg, TEMP: 28.090576 C.
2018-05-15T18:30:09.914Z,1526409009.914 [AHRS_M2](INFO): CRC match. PITCH: -89.015834 deg, ROLL: -93.153132 deg, YAW: 243.978428 deg, TEMP: 28.096695 C.
2018-05-15T18:30:10.314Z,1526409010.314 [AHRS_M2](INFO): CRC match. PITCH: -89.017616 deg, ROLL: -93.756361 deg, YAW: 244.591424 deg, TEMP: 28.087515 C.
2018-05-15T18:30:10.713Z,1526409010.713 [AHRS_M2](INFO): CRC match. PITCH: -89.014830 deg, ROLL: -93.382524 deg, YAW: 244.220435 deg, TEMP: 28.090576 C.
2018-05-15T18:30:11.114Z,1526409011.114 [AHRS_M2](INFO): CRC match. PITCH: -89.016824 deg, ROLL: -93.005422 deg, YAW: 243.825732 deg, TEMP: 28.102816 C.
2018-05-15T18:30:11.514Z,1526409011.514 [AHRS_M2](INFO): CRC match. PITCH: -89.017418 deg, ROLL: -93.220860 deg, YAW: 244.051292 deg, TEMP: 28.093636 C.
2018-05-15T18:30:11.913Z,1526409011.913 [AHRS_M2](INFO): CRC match. PITCH: -89.021407 deg, ROLL: -93.682007 deg, YAW: 244.508177 deg, TEMP: 28.081396 C.
2018-05-15T18:30:12.314Z,1526409012.314 [AHRS_M2](INFO): CRC match. PITCH: -89.024009 deg, ROLL: -93.824485 deg, YAW: 244.635984 deg, TEMP: 28.087515 C.
2018-05-15T18:30:12.713Z,1526409012.713 [AHRS_M2](INFO): CRC match. PITCH: -89.023012 deg, ROLL: -93.505624 deg, YAW: 244.314610 deg, TEMP: 28.087515 C.
2018-05-15T18:30:13.113Z,1526409013.113 [AHRS_M2](INFO): CRC match. PITCH: -89.022206 deg, ROLL: -93.245230 deg, YAW: 244.046047 deg, TEMP: 28.099754 C.
2018-05-15T18:30:13.517Z,1526409013.517 [AHRS_M2](INFO): CRC match. PITCH: -89.022008 deg, ROLL: -93.099597 deg, YAW: 243.897832 deg, TEMP: 28.081396 C.
2018-05-15T18:30:13.913Z,1526409013.913 [AHRS_M2](INFO): CRC match. PITCH: -89.018013 deg, ROLL: -93.075275 deg, YAW: 243.897012 deg, TEMP: 28.102816 C.
2018-05-15T18:30:14.313Z,1526409014.313 [AHRS_M2](INFO): CRC match. PITCH: -89.015636 deg, ROLL: -93.218251 deg, YAW: 244.054953 deg, TEMP: 28.081396 C.
2018-05-15T18:30:14.713Z,1526409014.713 [AHRS_M2](INFO): CRC match. PITCH: -89.027022 deg, ROLL: -93.110976 deg, YAW: 243.894225 deg, TEMP: 28.099754 C.
2018-05-15T18:30:15.113Z,1526409015.113 [AHRS_M2](INFO): CRC match. PITCH: -89.022814 deg, ROLL: -93.067932 deg, YAW: 243.869828 deg, TEMP: 28.099754 C.
2018-05-15T18:30:15.513Z,1526409015.513 [AHRS_M2](INFO): CRC match. PITCH: -89.017814 deg, ROLL: -93.548696 deg, YAW: 244.390971 deg, TEMP: 28.093636 C.
2018-05-15T18:30:15.913Z,1526409015.913 [AHRS_M2](INFO): CRC match. PITCH: -89.019208 deg, ROLL: -93.334986 deg, YAW: 244.158772 deg, TEMP: 28.093636 C.
2018-05-15T18:30:16.312Z,1526409016.312 [AHRS_M2](INFO): CRC match. PITCH: -89.011469 deg, ROLL: -93.566707 deg, YAW: 244.442526 deg, TEMP: 28.087515 C.
2018-05-15T18:30:16.712Z,1526409016.712 [AHRS_M2](INFO): CRC match. PITCH: -89.016824 deg, ROLL: -93.464814 deg, YAW: 244.314309 deg, TEMP: 28.093636 C.
2018-05-15T18:30:17.112Z,1526409017.112 [AHRS_M2](INFO): CRC match. PITCH: -89.016626 deg, ROLL: -93.150537 deg, YAW: 243.989220 deg, TEMP: 28.087515 C.
2018-05-15T18:30:17.512Z,1526409017.512 [AHRS_M2](INFO): CRC match. PITCH: -89.023210 deg, ROLL: -93.120115 deg, YAW: 243.919169 deg, TEMP: 28.090576 C.
2018-05-15T18:30:17.912Z,1526409017.912 [AHRS_M2](INFO): CRC match. PITCH: -89.026823 deg, ROLL: -93.435745 deg, YAW: 244.237893 deg, TEMP: 28.078335 C.
2018-05-15T18:30:18.312Z,1526409018.312 [AHRS_M2](INFO): CRC match. PITCH: -89.028231 deg, ROLL: -92.688181 deg, YAW: 243.454498 deg, TEMP: 28.108936 C.
2018-05-15T18:30:18.712Z,1526409018.712 [AHRS_M2](INFO): CRC match. PITCH: -89.021004 deg, ROLL: -92.982541 deg, YAW: 243.796198 deg, TEMP: 28.096695 C.
2018-05-15T18:30:19.112Z,1526409019.112 [AHRS_M2](INFO): CRC match. PITCH: -89.026619 deg, ROLL: -93.197501 deg, YAW: 244.000285 deg, TEMP: 28.093636 C.
2018-05-15T18:30:19.517Z,1526409019.517 [AHRS_M2](INFO): CRC match. PITCH: -89.017616 deg, ROLL: -93.230860 deg, YAW: 244.070717 deg, TEMP: 28.118114 C.
2018-05-15T18:30:19.912Z,1526409019.912 [AHRS_M2](INFO): CRC match. PITCH: -89.020212 deg, ROLL: -93.238236 deg, YAW: 244.067712 deg, TEMP: 28.090576 C.
2018-05-15T18:30:20.295Z,1526409020.295 [CommandLine](IMPORTANT): got command configSet AHRS_M2.verbosity 0.000000 count
2018-05-15T18:30:37.514Z,1526409037.514 [AHRS_M2](ERROR): SAPP frame error: SOH not found.
2018-05-15T18:31:13.119Z,1526409073.119 [AHRS_M2](ERROR): SAPP frame error: SOH not found.
2018-05-15T18:31:18.320Z,1526409078.320 [AHRS_M2](ERROR): SAPP frame error: SOH not found.
2018-05-15T18:31:22.319Z,1526409082.319 [AHRS_M2](ERROR): SAPP frame error: SOH not found.
2018-05-15T18:31:29.119Z,1526409089.119 [AHRS_M2](ERROR): SAPP frame error: SOH not found.
2018-05-15T18:31:32.318Z,1526409092.318 [AHRS_M2](ERROR): SAPP frame error: SOH not found.
2018-05-15T18:31:39.519Z,1526409099.519 [AHRS_M2](ERROR): SAPP frame error: SOH not found.
2018-05-15T18:32:13.139Z,1526409133.139 [AHRS_M2](ERROR): SAPP frame error: SOH not found.
2018-05-15T18:32:14.614Z,1526409134.614 [CommandLine](IMPORTANT): got command show stack
2018-05-15T18:32:14.615Z,1526409134.615 [CommandLine](IMPORTANT): Behavior Stack:

2018-05-15T18:32:14.615Z,1526409134.615 [compassCal:StandardEnvelopes](IMPORTANT): Priority 0: compassCal:StandardEnvelopes:A.AltitudeEnvelope
2018-05-15T18:32:14.616Z,1526409134.616 [compassCal:StandardEnvelopes](IMPORTANT): Priority 1: compassCal:StandardEnvelopes:B.DepthEnvelope
2018-05-15T18:32:14.616Z,1526409134.616 [compassCal:StandardEnvelopes](IMPORTANT): Priority 2: compassCal:StandardEnvelopes:C.OffshoreEnvelope
2018-05-15T18:32:14.616Z,1526409134.616 [compassCal](IMPORTANT): Priority 3: compassCal:H.Pitch
2018-05-15T18:32:14.616Z,1526409134.616 [compassCal](IMPORTANT): Priority 4: compassCal:I.Buoyancy
2018-05-15T18:32:14.617Z,1526409134.617 [compassCal](IMPORTANT): Priority 5: compassCal:J.DepthEnvelope
2018-05-15T18:32:14.617Z,1526409134.617 [compassCal](IMPORTANT): Priority 6: compassCal:K.AltitudeEnvelope
2018-05-15T18:32:14.617Z,1526409134.617 [compassCal](IMPORTANT): Priority 7: compassCal:L.YoYo
2018-05-15T18:32:14.618Z,1526409134.618 [compassCal:Calibration:AcquireCalibrationPoints](IMPORTANT): Priority 8: compassCal:Calibration:AcquireCalibrationPoints:A.Point
2018-05-15T18:32:14.618Z,1526409134.618 [compassCal:Calibration:AcquireCalibrationPoints](IMPORTANT): Priority 9: compassCal:Calibration:AcquireCalibrationPoints:B.SetSpeed
2018-05-15T18:32:14.618Z,1526409134.618 [compassCal:Calibration](IMPORTANT): Priority 10: compassCal:Calibration:D.CalibrateAHRS_M2
2018-05-15T18:32:25.139Z,1526409145.139 [AHRS_M2](ERROR): SAPP frame error: SOH not found.
2018-05-15T18:32:37.982Z,1526409157.982 [CommandLine](IMPORTANT): got command get compassCal.MissionTimeout
2018-05-15T18:32:37.983Z,1526409157.983 [CommandLine](IMPORTANT): compassCal.MissionTimeout 60.000000 min
2018-05-15T18:32:40.339Z,1526409160.339 [AHRS_M2](ERROR): SAPP frame error: SOH not found.
2018-05-15T18:32:43.113Z,1526409163.113 [CommandLine](IMPORTANT): got command stop
2018-05-15T18:32:43.113Z,1526409163.113 [CommandLine](IMPORTANT): Scheduling is paused
2018-05-15T18:32:43.113Z,1526409163.113 [Supervisor](INFO): Stop Mission called by CommandLine::commandStop
2018-05-15T18:32:43.222Z,1526409163.222 [MissionManager](INFO): MissionManager is completed.
2018-05-15T18:32:43.222Z,1526409163.222 [MissionManager](INFO): Uninitializing Mission compassCal
2018-05-15T18:32:43.222Z,1526409163.222 [compassCal] Stopped
2018-05-15T18:32:43.222Z,1526409163.222 [compassCal](DEBUG): Aggregate::uninitialize compassCal
2018-05-15T18:32:43.222Z,1526409163.222 [compassCal:StandardEnvelopes] Stopped
2018-05-15T18:32:43.222Z,1526409163.222 [compassCal:StandardEnvelopes](DEBUG): Aggregate::uninitialize compassCal:StandardEnvelopes
2018-05-15T18:32:43.222Z,1526409163.222 [compassCal:StandardEnvelopes:A.AltitudeEnvelope] Stopped
2018-05-15T18:32:43.222Z,1526409163.222 [compassCal:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent.
2018-05-15T18:32:43.223Z,1526409163.223 [compassCal:StandardEnvelopes:B.DepthEnvelope] Stopped
2018-05-15T18:32:43.223Z,1526409163.223 [compassCal:StandardEnvelopes:B.DepthEnvelope](DEBUG): Uninitialize.
2018-05-15T18:32:43.223Z,1526409163.223 [compassCal:StandardEnvelopes:C.OffshoreEnvelope] Stopped
2018-05-15T18:32:43.223Z,1526409163.223 [compassCal:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Uninitialize OffshoreEnvelopeComponent.
2018-05-15T18:32:43.223Z,1526409163.223 [compassCal:H.Pitch] Stopped
2018-05-15T18:32:43.223Z,1526409163.223 [compassCal:I.Buoyancy] Stopped
2018-05-15T18:32:43.223Z,1526409163.223 [compassCal:I.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2018-05-15T18:32:43.223Z,1526409163.223 [compassCal:J.DepthEnvelope] Stopped
2018-05-15T18:32:43.223Z,1526409163.223 [compassCal:J.DepthEnvelope](DEBUG): Uninitialize.
2018-05-15T18:32:43.223Z,1526409163.223 [compassCal:K.AltitudeEnvelope] Stopped
2018-05-15T18:32:43.223Z,1526409163.223 [compassCal:K.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent.
2018-05-15T18:32:43.223Z,1526409163.223 [compassCal:L.YoYo] Stopped
2018-05-15T18:32:43.223Z,1526409163.223 [compassCal:L.YoYo](DEBUG): Uninitialize YoYoComponent.
2018-05-15T18:32:43.223Z,1526409163.223 [compassCal:Calibration] Stopped
2018-05-15T18:32:43.224Z,1526409163.224 [compassCal:Calibration](DEBUG): Aggregate::uninitialize compassCal:Calibration
2018-05-15T18:32:43.224Z,1526409163.224 [compassCal:Calibration:AcquireCalibrationPoints] Stopped
2018-05-15T18:32:43.224Z,1526409163.224 [compassCal:Calibration:AcquireCalibrationPoints](DEBUG): Aggregate::uninitialize compassCal:Calibration:AcquireCalibrationPoints
2018-05-15T18:32:43.224Z,1526409163.224 [compassCal:Calibration:AcquireCalibrationPoints:A.Point] Stopped
2018-05-15T18:32:43.224Z,1526409163.224 [compassCal:Calibration:AcquireCalibrationPoints:B.SetSpeed] Stopped
2018-05-15T18:32:43.224Z,1526409163.224 [compassCal:Calibration:AcquireCalibrationPoints:B.SetSpeed](DEBUG): Uninitialize.
2018-05-15T18:32:43.224Z,1526409163.224 [compassCal:Calibration:D.CalibrateAHRS_M2] Stopped
2018-05-15T18:32:43.224Z,1526409163.224 [compassCal:Calibration:D.CalibrateAHRS_M2](INFO): Uninitialize CalibrateSpartonComponent.
2018-05-15T18:32:43.557Z,1526409163.557 [AHRS_M2](INFO): Data-stream disabled.
2018-05-15T18:32:43.585Z,1526409163.585 [AHRS_M2](INFO): Un-set autoFieldCalActive.
2018-05-15T18:32:43.625Z,1526409163.625 [DeadReckonUsingMultipleVelocitySources](DEBUG): Most recent orientation data is 0.413348 seconds old.
2018-05-15T18:32:43.627Z,1526409163.627 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 0.421686 seconds old.
2018-05-15T18:32:43.642Z,1526409163.642 [MissionManager](IMPORTANT): Started mission Default
2018-05-15T18:32:43.642Z,1526409163.642 [Default] Running Loop=1
2018-05-15T18:32:43.643Z,1526409163.643 [Default](DEBUG): Aggregate::initialize Default
2018-05-15T18:32:43.643Z,1526409163.643 [Default:B.GoToSurface] Running Loop=1
2018-05-15T18:32:43.643Z,1526409163.643 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-05-15T18:32:43.643Z,1526409163.643 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2018-05-15T18:32:43.643Z,1526409163.643 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2018-05-15T18:32:43.644Z,1526409163.644 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2018-05-15T18:32:43.644Z,1526409163.644 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-05-15T18:32:43.644Z,1526409163.644 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2018-05-15T18:32:43.645Z,1526409163.645 [Default:A.Wait] Running Loop=1
2018-05-15T18:32:43.645Z,1526409163.645 [Default:A.Wait](DEBUG): Initialize Wait Component.
2018-05-15T18:32:43.957Z,1526409163.957 [AHRS_M2](IMPORTANT): Magnetic calibration quality is unknown. Response was $PSRFS,error*10
2018-05-15T18:32:43.985Z,1526409163.985 [AHRS_M2](INFO): Data-stream active.
2018-05-15T18:32:44.037Z,1526409164.037 [DeadReckonUsingMultipleVelocitySources](DEBUG): Most recent orientation data is 0.838110 seconds old.
2018-05-15T18:32:44.040Z,1526409164.040 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 0.834099 seconds old.
2018-05-15T18:32:56.843Z,1526409176.843 [Default:A.Wait](INFO): Done Waiting.
2018-05-15T18:32:56.843Z,1526409176.843 [Default:A.Wait] Stopped
2018-05-15T18:32:56.843Z,1526409176.843 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2018-05-15T18:32:57.247Z,1526409177.247 [Default:CheckIn] Running Loop=1
2018-05-15T18:32:57.247Z,1526409177.247 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-05-15T18:32:57.247Z,1526409177.247 [Default:CheckIn:Read_GPS] Running Loop=1
2018-05-15T18:32:57.644Z,1526409177.644 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2018-05-15T18:32:57.998Z,1526409177.998 [NAL9602](INFO): Powering up
2018-05-15T18:33:04.399Z,1526409184.399 [NAL9602](INFO): No messages in MT queue
2018-05-15T18:33:25.991Z,1526409205.991 [AHRS_M2](ERROR): SAPP frame error: SOH not found.
2018-05-15T18:33:37.991Z,1526409217.991 [AHRS_M2](ERROR): SAPP frame error: SOH not found.
2018-05-15T18:34:10.434Z,1526409250.434 [CommandLine](IMPORTANT): got command load ./Missions/Maintenance/calibrateAHRS_M2.xml
2018-05-15T18:34:10.435Z,1526409250.435 [MissionManager](INFO): Loading Mission: ./Missions/Maintenance/calibrateAHRS_M2.xml
2018-05-15T18:34:10.522Z,1526409250.522 [MissionManager](INFO): DefineArg compassCal.MissionTimeout = 60.000000 min
2018-05-15T18:34:10.524Z,1526409250.524 [MissionManager](INFO): DefineArg compassCal.NeedCommsTime = 6.000000 min
2018-05-15T18:34:10.526Z,1526409250.526 [MissionManager](INFO): DefineArg compassCal.YoYoMinDepth = 2.000000 m
2018-05-15T18:34:10.528Z,1526409250.528 [MissionManager](INFO): DefineArg compassCal.YoYoMaxDepth = 200.000000 m
2018-05-15T18:34:10.530Z,1526409250.530 [MissionManager](INFO): DefineArg compassCal.YoYoMinAltitude = 7.000000 m
2018-05-15T18:34:10.532Z,1526409250.532 [MissionManager](INFO): DefineArg compassCal.YoYoPitch = 30.000000 arcdeg
2018-05-15T18:34:10.534Z,1526409250.534 [MissionManager](INFO): DefineArg compassCal.RudderAngle = 13.000000 arcdeg
2018-05-15T18:34:10.536Z,1526409250.536 [MissionManager](INFO): DefineArg compassCal.Speed = 1.000000 m/s
2018-05-15T18:34:10.584Z,1526409250.584 [MissionManager](INFO): DefineArg compassCal.CalibrationInitTimeout = 2.000000 min
2018-05-15T18:34:10.614Z,1526409250.614 [MissionManager](INFO): DefineArg compassCal.MinAltitude = 5.000000 m
2018-05-15T18:34:10.616Z,1526409250.616 [MissionManager](INFO): DefineArg compassCal.MaxDepth = 205.000000 m
2018-05-15T18:34:10.630Z,1526409250.630 [MissionManager](INFO): DefineArg compassCal.MinOffshore = 2.000000 km
2018-05-15T18:34:10.631Z,1526409250.631 [MissionManager](INFO): Inserting Stack: Missions/Insert/NeedComms.xml
2018-05-15T18:34:10.745Z,1526409250.745 [MissionManager](INFO): DefineArg compassCal:NeedComms.DiveInterval = 3.000000 h
2018-05-15T18:34:10.747Z,1526409250.747 [MissionManager](INFO): DefineArg compassCal:NeedComms.WaitForPitchUp = 10.000000 min
2018-05-15T18:34:10.770Z,1526409250.770 [MissionManager](INFO): DefineArg compassCal:NeedComms.SurfacePitch = 20.000000 arcdeg
2018-05-15T18:34:10.772Z,1526409250.772 [MissionManager](INFO): DefineArg compassCal:NeedComms.SurfaceDepthRate = nan m/s
2018-05-15T18:34:10.774Z,1526409250.774 [MissionManager](INFO): DefineArg compassCal:NeedComms.SurfaceSpeed = 1.000000 m/s
2018-05-15T18:34:10.786Z,1526409250.786 [MissionManager](INFO): DefineArg compassCal:NeedComms.GPSTimeout = 7.000000 min
2018-05-15T18:34:10.789Z,1526409250.789 [MissionManager](INFO): DefineArg compassCal:NeedComms.CommsTimeout = 30.000000 min
2018-05-15T18:34:10.793Z,1526409250.793 [compassCal:NeedComms:B.GoToSurface](DEBUG): Construct GoToSurface.
2018-05-15T18:34:10.806Z,1526409250.806 [MissionManager](INFO): Inserting Stack: Missions/Insert/StandardEnvelopes.xml
2018-05-15T18:34:10.862Z,1526409250.862 [MissionManager](INFO): DefineArg compassCal:StandardEnvelopes.MinAltitude = 5.000000 m
2018-05-15T18:34:10.866Z,1526409250.866 [MissionManager](INFO): DefineArg compassCal:StandardEnvelopes.MaxDepth = 200.000000 m
2018-05-15T18:34:10.868Z,1526409250.868 [MissionManager](INFO): DefineArg compassCal:StandardEnvelopes.MinOffshore = 2000.000000 m
2018-05-15T18:34:10.869Z,1526409250.869 [compassCal:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope.
2018-05-15T18:34:10.891Z,1526409250.891 [compassCal:StandardEnvelopes:B.DepthEnvelope](DEBUG): Construct DepthEnvelope.
2018-05-15T18:34:10.897Z,1526409250.897 [compassCal:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Construct OffshoreEnvelope.
2018-05-15T18:34:10.998Z,1526409250.998 [compassCal:H.Pitch](DEBUG): Construct.
2018-05-15T18:34:11.003Z,1526409251.003 [compassCal:I.Buoyancy](DEBUG): Construct Buoyancy.
2018-05-15T18:34:11.015Z,1526409251.015 [compassCal:J.DepthEnvelope](DEBUG): Construct DepthEnvelope.
2018-05-15T18:34:11.042Z,1526409251.042 [compassCal:K.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope.
2018-05-15T18:34:11.063Z,1526409251.063 [compassCal:L.YoYo](DEBUG): Construct YoYo.
2018-05-15T18:34:11.071Z,1526409251.071 [compassCal:Calibration:WaitForCalibrationInit:A_Timeout:B.Execute](DEBUG): Construct Execute.
2018-05-15T18:34:11.086Z,1526409251.086 [compassCal:Calibration:AcquireCalibrationPoints:A.Point](DEBUG): Construct.
2018-05-15T18:34:11.090Z,1526409251.090 [compassCal:Calibration:AcquireCalibrationPoints:B.SetSpeed](DEBUG): Construct.
2018-05-15T18:34:11.093Z,1526409251.093 [compassCal:Calibration:D.CalibrateAHRS_M2](DEBUG): Construct CalibrateSparton.
2018-05-15T18:34:11.115Z,1526409251.115 [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>60</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>6</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-15T18:34:11.115Z,1526409251.115 [CommandLine](IMPORTANT): Loaded ./Missions/Maintenance/calibrateAHRS_M2.xml
2018-05-15T18:34:17.286Z,1526409257.286 [CommandLine](IMPORTANT): got command run
2018-05-15T18:34:17.288Z,1526409257.288 [CommandLine](IMPORTANT): Running 
2018-05-15T18:34:17.417Z,1526409257.417 [Default] Stopped
2018-05-15T18:34:17.417Z,1526409257.417 [Default](DEBUG): Aggregate::uninitialize Default
2018-05-15T18:34:17.417Z,1526409257.417 [Default:B.GoToSurface] Stopped
2018-05-15T18:34:17.417Z,1526409257.417 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2018-05-15T18:34:17.417Z,1526409257.417 [Default:CheckIn] Stopped
2018-05-15T18:34:17.417Z,1526409257.417 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-05-15T18:34:17.417Z,1526409257.417 [Default:CheckIn:Read_GPS] Stopped
2018-05-15T18:34:17.417Z,1526409257.417 [MissionManager](IMPORTANT): Started mission compassCal
2018-05-15T18:34:17.418Z,1526409257.418 [compassCal] Running Loop=1
2018-05-15T18:34:17.418Z,1526409257.418 [compassCal](DEBUG): Aggregate::initialize compassCal
2018-05-15T18:34:17.418Z,1526409257.418 [compassCal:StandardEnvelopes] Running Loop=1
2018-05-15T18:34:17.418Z,1526409257.418 [compassCal:StandardEnvelopes](DEBUG): Aggregate::initialize compassCal:StandardEnvelopes
2018-05-15T18:34:17.418Z,1526409257.418 [compassCal:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1
2018-05-15T18:34:17.418Z,1526409257.418 [compassCal:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent.
2018-05-15T18:34:17.419Z,1526409257.419 [compassCal:StandardEnvelopes:B.DepthEnvelope] Running Loop=1
2018-05-15T18:34:17.419Z,1526409257.419 [compassCal:StandardEnvelopes:B.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent.
2018-05-15T18:34:17.419Z,1526409257.419 [compassCal:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1
2018-05-15T18:34:17.419Z,1526409257.419 [compassCal:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Initialize OffshoreEnvelopeComponent.
2018-05-15T18:34:17.419Z,1526409257.419 [compassCal:H.Pitch] Running Loop=1
2018-05-15T18:34:17.419Z,1526409257.419 [compassCal:H.Pitch](DEBUG): Initialize.
2018-05-15T18:34:17.419Z,1526409257.419 [compassCal:I.Buoyancy] Running Loop=1
2018-05-15T18:34:17.419Z,1526409257.419 [compassCal:I.Buoyancy](DEBUG): Initialize Buoyancy Component.
2018-05-15T18:34:17.419Z,1526409257.419 [compassCal:J.DepthEnvelope] Running Loop=1
2018-05-15T18:34:17.419Z,1526409257.419 [compassCal:J.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent.
2018-05-15T18:34:17.420Z,1526409257.420 [compassCal:K.AltitudeEnvelope] Running Loop=1
2018-05-15T18:34:17.420Z,1526409257.420 [compassCal:K.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent.
2018-05-15T18:34:17.420Z,1526409257.420 [compassCal:L.YoYo] Running Loop=1
2018-05-15T18:34:17.420Z,1526409257.420 [compassCal:L.YoYo](DEBUG): Initialize YoYoComponent.
2018-05-15T18:34:17.420Z,1526409257.420 [compassCal:B] Running Loop=1
2018-05-15T18:34:17.425Z,1526409257.425 [compassCal:L.YoYo] Running Loop=1
2018-05-15T18:34:17.426Z,1526409257.426 [compassCal:K.AltitudeEnvelope] Running Loop=1
2018-05-15T18:34:17.427Z,1526409257.427 [compassCal:J.DepthEnvelope] Running Loop=1
2018-05-15T18:34:17.433Z,1526409257.433 [compassCal:I.Buoyancy] Running Loop=1
2018-05-15T18:34:17.434Z,1526409257.434 [compassCal:H.Pitch] Running Loop=1
2018-05-15T18:34:17.435Z,1526409257.435 [compassCal:StandardEnvelopes] Running Loop=1
2018-05-15T18:34:17.435Z,1526409257.435 [compassCal:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1
2018-05-15T18:34:17.441Z,1526409257.441 [compassCal:StandardEnvelopes:B.DepthEnvelope] Running Loop=1
2018-05-15T18:34:17.442Z,1526409257.442 [compassCal:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1
2018-05-15T18:34:17.444Z,1526409257.444 [compassCal:B] Stopped
2018-05-15T18:34:17.444Z,1526409257.444 [compassCal:D] Running Loop=1
2018-05-15T18:34:17.824Z,1526409257.824 [compassCal:D] Stopped
2018-05-15T18:34:17.829Z,1526409257.829 [compassCal:E] Running Loop=1
2018-05-15T18:34:18.207Z,1526409258.207 [compassCal:E] Stopped
2018-05-15T18:34:18.207Z,1526409258.207 [compassCal:F] Running Loop=1
2018-05-15T18:34:18.609Z,1526409258.609 [compassCal:F] Stopped
2018-05-15T18:34:18.609Z,1526409258.609 [compassCal:StartingMission] Running Loop=1
2018-05-15T18:34:18.609Z,1526409258.609 [compassCal:StartingMission](DEBUG): Aggregate::initialize compassCal:StartingMission
2018-05-15T18:34:19.007Z,1526409259.007 [compassCal:NeedComms] Running Loop=1
2018-05-15T18:34:19.008Z,1526409259.008 [compassCal:NeedComms](DEBUG): Aggregate::initialize compassCal:NeedComms
2018-05-15T18:34:19.008Z,1526409259.008 [compassCal:NeedComms:B.GoToSurface] Running Loop=1
2018-05-15T18:34:19.008Z,1526409259.008 [compassCal:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-05-15T18:34:19.008Z,1526409259.008 [compassCal:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s.
2018-05-15T18:34:19.009Z,1526409259.009 [compassCal:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees.
2018-05-15T18:34:19.009Z,1526409259.009 [compassCal:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s.
2018-05-15T18:34:19.010Z,1526409259.010 [compassCal:NeedComms:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-05-15T18:34:19.010Z,1526409259.010 [compassCal:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2018-05-15T18:34:19.010Z,1526409259.010 [compassCal:NeedComms:A] Running Loop=1
2018-05-15T18:34:19.012Z,1526409259.012 [compassCal:NeedComms:A](INFO): last time_fix was: 1526408960.000000 second since 1970/01/01T00:00:00Z 
2018-05-15T18:34:19.013Z,1526409259.013 [compassCal:NeedComms:A] Stopped
2018-05-15T18:34:19.418Z,1526409259.418 [compassCal:NeedComms:C] Running Loop=1
2018-05-15T18:34:19.823Z,1526409259.823 [compassCal:NeedComms:C](DEBUG): Initialize ReadDataComponent to sense time_fix
2018-05-15T18:34:38.593Z,1526409278.593 [CommandLine](IMPORTANT): got command set NAL9602.time_fix 1526409216.000000
2018-05-15T18:34:38.593Z,1526409278.593 [CommandLine](FAULT): Incomplete syntax. Try: help set
2018-05-15T18:34:48.728Z,1526409288.728 [BPC1](ERROR): Failed to receive data from both battery packs
2018-05-15T18:34:48.728Z,1526409288.728 [BPC1] Communications Fault, FailCount= 1
2018-05-15T18:34:48.728Z,1526409288.728 [BPC1](ERROR): Communications Fault
2018-05-15T18:34:48.794Z,1526409288.794 [CBIT](ERROR): Communications Fault in component: BPC1
2018-05-15T18:34:49.966Z,1526409289.966 [CBIT](INFO): Clearing failed state for component BPC1
2018-05-15T18:34:49.966Z,1526409289.966 [BPC1] No Fault, FailCount= 1
2018-05-15T18:34:56.291Z,1526409296.291 [CommandLine](IMPORTANT): got command set NAL9602.time_fix 1526409344.000000 second
2018-05-15T18:34:56.361Z,1526409296.361 [compassCal:NeedComms:C] Stopped
2018-05-15T18:34:56.362Z,1526409296.362 [compassCal:NeedComms:D] Running Loop=1
2018-05-15T18:34:56.756Z,1526409296.756 [compassCal:NeedComms:D](DEBUG): Initialize ReadDataComponent to sense platform_communications
2018-05-15T18:35:00.786Z,1526409300.786 [DataOverHttps](INFO): Sending 43 bytes from file Logs/20180515T182516/Courier0007.lzma
2018-05-15T18:35:01.586Z,1526409301.586 [DataOverHttps](INFO): Moved sent file to Logs/20180515T182516/Courier0007.lzma.bak
2018-05-15T18:35:01.586Z,1526409301.586 [DataOverHttps](INFO): SBD MOMSN=8282568
2018-05-15T18:35:11.377Z,1526409311.377 [DataOverHttps](INFO): Sending 779 bytes from file Logs/20180515T182516/Express0008.lzma
2018-05-15T18:35:12.158Z,1526409312.158 [DataOverHttps](INFO): Moved sent file to Logs/20180515T182516/Express0008.lzma.bak
2018-05-15T18:35:12.158Z,1526409312.158 [DataOverHttps](INFO): SBD MOMSN=8282570
2018-05-15T18:35:13.218Z,1526409313.218 [compassCal:NeedComms:D] Stopped
2018-05-15T18:35:13.218Z,1526409313.218 [compassCal:NeedComms:E] Running Loop=1
2018-05-15T18:35:13.349Z,1526409313.349 [compassCal:NeedComms:E](DEBUG): Initialize ReadDataComponent to sense time_fix
2018-05-15T18:35:15.906Z,1526409315.906 [CommandLine](IMPORTANT): got command set NAL9602.time_fix 1526409344.000000 second
2018-05-15T18:35:16.466Z,1526409316.466 [compassCal:NeedComms:E] Stopped
2018-05-15T18:35:16.467Z,1526409316.467 [compassCal:NeedComms](INFO): Completed compassCal:NeedComms
2018-05-15T18:35:16.467Z,1526409316.467 [compassCal:NeedComms] Stopped
2018-05-15T18:35:16.467Z,1526409316.467 [compassCal:NeedComms](DEBUG): Aggregate::uninitialize compassCal:NeedComms
2018-05-15T18:35:16.467Z,1526409316.467 [compassCal:NeedComms:B.GoToSurface] Stopped
2018-05-15T18:35:16.467Z,1526409316.467 [compassCal:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2018-05-15T18:35:16.610Z,1526409316.610 [compassCal:StartingMission](INFO): Completed compassCal:StartingMission
2018-05-15T18:35:16.610Z,1526409316.610 [compassCal:StartingMission] Stopped
2018-05-15T18:35:16.610Z,1526409316.610 [compassCal:StartingMission](DEBUG): Aggregate::uninitialize compassCal:StartingMission
2018-05-15T18:35:16.610Z,1526409316.610 [compassCal:Calibration] Running Loop=1
2018-05-15T18:35:16.611Z,1526409316.611 [compassCal:Calibration](DEBUG): Aggregate::initialize compassCal:Calibration
2018-05-15T18:35:16.611Z,1526409316.611 [compassCal:Calibration:D.CalibrateAHRS_M2] Running Loop=1
2018-05-15T18:35:16.611Z,1526409316.611 [compassCal:Calibration:D.CalibrateAHRS_M2](INFO): Initialize CalibrateSpartonComponent.
2018-05-15T18:35:16.611Z,1526409316.611 [compassCal:Calibration:WaitForCalibrationInit] Running Loop=1
2018-05-15T18:35:16.929Z,1526409316.929 [AHRS_M2](INFO): Data-stream disabled.
2018-05-15T18:35:16.961Z,1526409316.961 [AHRS_M2](INFO): Set clearPointCal.
2018-05-15T18:35:17.012Z,1526409317.012 [DeadReckonUsingMultipleVelocitySources](DEBUG): Most recent orientation data is 0.409521 seconds old.
2018-05-15T18:35:17.014Z,1526409317.014 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 0.410041 seconds old.
2018-05-15T18:35:17.018Z,1526409317.018 [compassCal:Calibration:D.CalibrateAHRS_M2] Running Loop=1
2018-05-15T18:35:17.018Z,1526409317.018 [compassCal:Calibration:D.CalibrateAHRS_M2](INFO): Initialize CalibrateSpartonComponent.
2018-05-15T18:35:17.020Z,1526409317.020 [compassCal:Calibration:WaitForCalibrationInit](DEBUG): Initialize ReadDataComponent to sense AHRS_M2.CompassCalState
2018-05-15T18:35:17.309Z,1526409317.309 [AHRS_M2](INFO): Set initCalPointBuffer.
2018-05-15T18:35:17.360Z,1526409317.360 [DeadReckonUsingMultipleVelocitySources](DEBUG): Most recent orientation data is 0.757561 seconds old.
2018-05-15T18:35:17.363Z,1526409317.363 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 0.758180 seconds old.
2018-05-15T18:35:17.366Z,1526409317.366 [compassCal:Calibration:D.CalibrateAHRS_M2](INFO): Initialize CalibrateSpartonComponent.
2018-05-15T18:35:17.709Z,1526409317.709 [AHRS_M2](INFO): Set autoFieldCalActive.
2018-05-15T18:35:17.733Z,1526409317.733 [AHRS_M2](INFO): Data-stream active.
2018-05-15T18:35:17.781Z,1526409317.781 [DeadReckonUsingMultipleVelocitySources](DEBUG): Most recent orientation data is 1.178663 seconds old.
2018-05-15T18:35:17.783Z,1526409317.783 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 1.178954 seconds old.
2018-05-15T18:35:17.808Z,1526409317.808 [compassCal:Calibration:D.CalibrateAHRS_M2](INFO): Initialize CalibrateSpartonComponent.
2018-05-15T18:35:17.819Z,1526409317.819 [compassCal:Calibration:WaitForCalibrationInit] Stopped
2018-05-15T18:35:17.819Z,1526409317.819 [compassCal:Calibration:B] Running Loop=1
2018-05-15T18:35:18.149Z,1526409318.149 [compassCal:Calibration:B](IMPORTANT): AdaptCal initialized. Acquiring calibration points.
2018-05-15T18:35:18.150Z,1526409318.150 [compassCal:Calibration:B] Stopped
2018-05-15T18:35:18.150Z,1526409318.150 [compassCal:Calibration:AcquireCalibrationPoints] Running Loop=1
2018-05-15T18:35:18.150Z,1526409318.150 [compassCal:Calibration:AcquireCalibrationPoints](DEBUG): Aggregate::initialize compassCal:Calibration:AcquireCalibrationPoints
2018-05-15T18:35:18.151Z,1526409318.151 [compassCal:Calibration:AcquireCalibrationPoints:A.Point] Running Loop=1
2018-05-15T18:35:18.151Z,1526409318.151 [compassCal:Calibration:AcquireCalibrationPoints:A.Point](DEBUG): Initialize.
2018-05-15T18:35:18.151Z,1526409318.151 [compassCal:Calibration:AcquireCalibrationPoints:B.SetSpeed] Running Loop=1
2018-05-15T18:35:18.151Z,1526409318.151 [compassCal:Calibration:AcquireCalibrationPoints:B.SetSpeed](DEBUG): Initialize.
2018-05-15T18:35:18.550Z,1526409318.550 [compassCal:Calibration:AcquireCalibrationPoints:B.SetSpeed] Running Loop=1
2018-05-15T18:35:18.551Z,1526409318.551 [compassCal:Calibration:AcquireCalibrationPoints:A.Point] Running Loop=1
2018-05-15T18:35:47.301Z,1526409347.301 [NAL9602](INFO): Powering down
2018-05-15T18:35:53.407Z,1526409353.407 [CommandLine](IMPORTANT): got command stop
2018-05-15T18:35:53.407Z,1526409353.407 [Supervisor](INFO): Stop Mission called by CommandLine::commandStop
2018-05-15T18:35:53.757Z,1526409353.757 [MissionManager](INFO): MissionManager is completed.
2018-05-15T18:35:53.758Z,1526409353.758 [MissionManager](INFO): Uninitializing Mission compassCal
2018-05-15T18:35:53.758Z,1526409353.758 [compassCal] Stopped
2018-05-15T18:35:53.758Z,1526409353.758 [compassCal](DEBUG): Aggregate::uninitialize compassCal
2018-05-15T18:35:53.758Z,1526409353.758 [compassCal:StandardEnvelopes] Stopped
2018-05-15T18:35:53.758Z,1526409353.758 [compassCal:StandardEnvelopes](DEBUG): Aggregate::uninitialize compassCal:StandardEnvelopes
2018-05-15T18:35:53.758Z,1526409353.758 [compassCal:StandardEnvelopes:A.AltitudeEnvelope] Stopped
2018-05-15T18:35:53.758Z,1526409353.758 [compassCal:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent.
2018-05-15T18:35:53.758Z,1526409353.758 [compassCal:StandardEnvelopes:B.DepthEnvelope] Stopped
2018-05-15T18:35:53.758Z,1526409353.758 [compassCal:StandardEnvelopes:B.DepthEnvelope](DEBUG): Uninitialize.
2018-05-15T18:35:53.758Z,1526409353.758 [compassCal:StandardEnvelopes:C.OffshoreEnvelope] Stopped
2018-05-15T18:35:53.759Z,1526409353.759 [compassCal:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Uninitialize OffshoreEnvelopeComponent.
2018-05-15T18:35:53.759Z,1526409353.759 [compassCal:H.Pitch] Stopped
2018-05-15T18:35:53.759Z,1526409353.759 [compassCal:I.Buoyancy] Stopped
2018-05-15T18:35:53.759Z,1526409353.759 [compassCal:I.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2018-05-15T18:35:53.759Z,1526409353.759 [compassCal:J.DepthEnvelope] Stopped
2018-05-15T18:35:53.759Z,1526409353.759 [compassCal:J.DepthEnvelope](DEBUG): Uninitialize.
2018-05-15T18:35:53.759Z,1526409353.759 [compassCal:K.AltitudeEnvelope] Stopped
2018-05-15T18:35:53.759Z,1526409353.759 [compassCal:K.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent.
2018-05-15T18:35:53.759Z,1526409353.759 [compassCal:L.YoYo] Stopped
2018-05-15T18:35:53.759Z,1526409353.759 [compassCal:L.YoYo](DEBUG): Uninitialize YoYoComponent.
2018-05-15T18:35:53.759Z,1526409353.759 [compassCal:Calibration] Stopped
2018-05-15T18:35:53.759Z,1526409353.759 [compassCal:Calibration](DEBUG): Aggregate::uninitialize compassCal:Calibration
2018-05-15T18:35:53.759Z,1526409353.759 [compassCal:Calibration:AcquireCalibrationPoints] Stopped
2018-05-15T18:35:53.760Z,1526409353.760 [compassCal:Calibration:AcquireCalibrationPoints](DEBUG): Aggregate::uninitialize compassCal:Calibration:AcquireCalibrationPoints
2018-05-15T18:35:53.760Z,1526409353.760 [compassCal:Calibration:AcquireCalibrationPoints:A.Point] Stopped
2018-05-15T18:35:53.760Z,1526409353.760 [compassCal:Calibration:AcquireCalibrationPoints:B.SetSpeed] Stopped
2018-05-15T18:35:53.760Z,1526409353.760 [compassCal:Calibration:AcquireCalibrationPoints:B.SetSpeed](DEBUG): Uninitialize.
2018-05-15T18:35:53.760Z,1526409353.760 [compassCal:Calibration:D.CalibrateAHRS_M2] Stopped
2018-05-15T18:35:53.760Z,1526409353.760 [compassCal:Calibration:D.CalibrateAHRS_M2](INFO): Uninitialize CalibrateSpartonComponent.
2018-05-15T18:35:54.113Z,1526409354.113 [AHRS_M2](INFO): Data-stream disabled.
2018-05-15T18:35:54.137Z,1526409354.137 [AHRS_M2](INFO): Un-set autoFieldCalActive.
2018-05-15T18:35:54.196Z,1526409354.196 [DeadReckonUsingMultipleVelocitySources](DEBUG): Most recent orientation data is 0.447752 seconds old.
2018-05-15T18:35:54.202Z,1526409354.202 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 0.452244 seconds old.
2018-05-15T18:35:54.210Z,1526409354.210 [MissionManager](IMPORTANT): Started mission Default
2018-05-15T18:35:54.211Z,1526409354.211 [Default] Running Loop=1
2018-05-15T18:35:54.211Z,1526409354.211 [Default](DEBUG): Aggregate::initialize Default
2018-05-15T18:35:54.211Z,1526409354.211 [Default:B.GoToSurface] Running Loop=1
2018-05-15T18:35:54.211Z,1526409354.211 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-05-15T18:35:54.211Z,1526409354.211 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2018-05-15T18:35:54.211Z,1526409354.211 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2018-05-15T18:35:54.212Z,1526409354.212 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2018-05-15T18:35:54.212Z,1526409354.212 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-05-15T18:35:54.212Z,1526409354.212 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2018-05-15T18:35:54.217Z,1526409354.217 [Default:A.Wait] Running Loop=1
2018-05-15T18:35:54.217Z,1526409354.217 [Default:A.Wait](DEBUG): Initialize Wait Component.
2018-05-15T18:35:54.509Z,1526409354.509 [AHRS_M2](IMPORTANT): Magnetic calibration quality is unknown. Response was $PSRFS,error*10
2018-05-15T18:35:54.533Z,1526409354.533 [AHRS_M2](INFO): Data-stream active.
2018-05-15T18:35:54.601Z,1526409354.601 [DeadReckonUsingMultipleVelocitySources](DEBUG): Most recent orientation data is 0.853072 seconds old.
2018-05-15T18:35:54.603Z,1526409354.603 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 0.853306 seconds old.
2018-05-15T18:36:07.348Z,1526409367.348 [Default:A.Wait](INFO): Done Waiting.
2018-05-15T18:36:07.349Z,1526409367.349 [Default:A.Wait] Stopped
2018-05-15T18:36:07.349Z,1526409367.349 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2018-05-15T18:36:07.746Z,1526409367.746 [Default:CheckIn] Running Loop=1
2018-05-15T18:36:07.746Z,1526409367.746 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-05-15T18:36:07.746Z,1526409367.746 [Default:CheckIn:Read_GPS] Running Loop=1
2018-05-15T18:36:08.501Z,1526409368.501 [NAL9602](INFO): Powering up
2018-05-15T18:36:10.496Z,1526409370.496 [NAL9602](FAULT): GPS failed to acquire within timeout.
2018-05-15T18:36:10.496Z,1526409370.496 [NAL9602] Data Fault, FailCount= 1
2018-05-15T18:36:10.496Z,1526409370.496 [NAL9602](ERROR): Data Fault
2018-05-15T18:36:10.599Z,1526409370.599 [CBIT](ERROR): Data Fault in component: NAL9602
2018-05-15T18:36:10.906Z,1526409370.906 [NAL9602](INFO): Powering down
2018-05-15T18:36:11.797Z,1526409371.797 [CBIT](INFO): Clearing failed state for component NAL9602
2018-05-15T18:36:11.797Z,1526409371.797 [NAL9602] No Fault, FailCount= 1
2018-05-15T18:36:44.150Z,1526409404.150 [NAL9602](INFO): No messages in MT queue
2018-05-15T18:37:39.142Z,1526409459.142 [CommandLine](IMPORTANT): got command restart application
2018-05-15T18:37:40.152Z,1526409460.152 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2018-05-15T18:37:40.152Z,1526409460.152 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-05-15T18:37:40.237Z,1526409460.237 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2018-05-15T18:37:40.237Z,1526409460.237 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-05-15T18:37:40.237Z,1526409460.237 [CommandLine](INFO): Join timeout helper Thread ID is 2173
2018-05-15T18:37:40.238Z,1526409460.238 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2018-05-15T18:37:40.238Z,1526409460.238 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-05-15T18:37:40.238Z,1526409460.238 [NavChartDb](INFO): Join timeout helper Thread ID is 2174
2018-05-15T18:37:40.585Z,1526409460.585 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2018-05-15T18:37:40.585Z,1526409460.585 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-05-15T18:37:40.597Z,1526409460.597 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2018-05-15T18:37:40.597Z,1526409460.597 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2018-05-15T18:37:40.597Z,1526409460.597 [CTD_Seabird](INFO): Join timeout helper Thread ID is 2175
2018-05-15T18:37:40.645Z,1526409460.645 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2018-05-15T18:37:40.729Z,1526409460.729 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface
2018-05-15T18:37:40.729Z,1526409460.729 [CTD_Seabird](INFO): Powering down
2018-05-15T18:37:40.730Z,1526409460.730 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2018-05-15T18:37:40.741Z,1526409460.741 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2018-05-15T18:37:40.741Z,1526409460.741 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-05-15T18:37:40.741Z,1526409460.741 [Radio_Surface](INFO): Join timeout helper Thread ID is 2177
2018-05-15T18:37:41.009Z,1526409461.009 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2018-05-15T18:37:41.009Z,1526409461.009 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-05-15T18:37:41.017Z,1526409461.017 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2018-05-15T18:37:41.017Z,1526409461.017 [logger ThreadHandler](INFO): Thread cancelled.
2018-05-15T18:37:41.017Z,1526409461.017 [logger](INFO): Join timeout helper Thread ID is 2178
2018-05-15T18:37:41.041Z,1526409461.041 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2018-05-15T18:37:41.041Z,1526409461.041 [logger ThreadHandler](INFO): Thread cancelled.
2018-05-15T18:37:41.058Z,1526409461.058 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2018-05-15T18:37:41.058Z,1526409461.058 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-05-15T18:37:41.058Z,1526409461.058 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2018-05-15T18:37:41.058Z,1526409461.058 [controlThread ThreadHandler](INFO): Thread cancelled.
2018-05-15T18:37:41.058Z,1526409461.058 [controlThread](INFO): Join timeout helper Thread ID is 2179
2018-05-15T18:37:41.221Z,1526409461.221 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2018-05-15T18:37:41.221Z,1526409461.221 [controlThread](DEBUG): Uninitializing ControlThread
2018-05-15T18:37:41.221Z,1526409461.221 [AHRS_M2](INFO): uninitialize
2018-05-15T18:37:41.253Z,1526409461.253 [AHRS_M2](INFO): Data-stream disabled.
2018-05-15T18:37:41.254Z,1526409461.254 [AHRS_M2](INFO): Powering down
2018-05-15T18:37:41.325Z,1526409461.325 [AcousticModem_Benthos_ATM900](INFO): Powering down
2018-05-15T18:37:41.445Z,1526409461.445 [NAL9602](INFO): Powering down
2018-05-15T18:37:41.449Z,1526409461.449 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2018-05-15T18:37:41.450Z,1526409461.450 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2018-05-15T18:37:41.450Z,1526409461.450 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2018-05-15T18:37:41.451Z,1526409461.451 [MissionManager](INFO): Uninitializing Mission Default
2018-05-15T18:37:41.451Z,1526409461.451 [Default] Stopped
2018-05-15T18:37:41.451Z,1526409461.451 [Default](DEBUG): Aggregate::uninitialize Default
2018-05-15T18:37:41.452Z,1526409461.452 [Default:B.GoToSurface] Stopped
2018-05-15T18:37:41.452Z,1526409461.452 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2018-05-15T18:37:41.452Z,1526409461.452 [Default:CheckIn] Stopped
2018-05-15T18:37:41.452Z,1526409461.452 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-05-15T18:37:41.452Z,1526409461.452 [Default:CheckIn:Read_GPS] Stopped
2018-05-15T18:37:41.455Z,1526409461.455 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2018-05-15T18:37:41.455Z,1526409461.455 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2018-05-15T18:37:41.455Z,1526409461.455 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2018-05-15T18:37:41.456Z,1526409461.456 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2018-05-15T18:37:41.456Z,1526409461.456 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2018-05-15T18:37:41.457Z,1526409461.457 [BuoyancyServo](INFO): Powering down
2018-05-15T18:37:41.469Z,1526409461.469 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2018-05-15T18:37:41.469Z,1526409461.469 [ElevatorServo](INFO): Powering down
2018-05-15T18:37:41.470Z,1526409461.470 [MassServo](DEBUG): Uninitialize Mass Servo.
2018-05-15T18:37:41.470Z,1526409461.470 [MassServo](INFO): Powering down
2018-05-15T18:37:41.471Z,1526409461.471 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2018-05-15T18:37:41.471Z,1526409461.471 [RudderServo](INFO): Powering down
2018-05-15T18:37:41.472Z,1526409461.472 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2018-05-15T18:37:41.472Z,1526409461.472 [ThrusterServo](INFO): Powering down
2018-05-15T18:37:41.473Z,1526409461.473 [SBIT](DEBUG): Uninitialize SBIT Component.
2018-05-15T18:37:41.473Z,1526409461.473 [IBIT](DEBUG): Uninitialize IBIT Component.
2018-05-15T18:37:41.474Z,1526409461.474 [CBIT](DEBUG): Uninitialize CBIT Component.
2018-05-15T18:37:41.475Z,1526409461.475 [controlThread ThreadHandler](INFO): Thread cancelled.
2018-05-15T18:37:41.560Z,1526409461.560 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-05-15T18:37:41.604Z,1526409461.604 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2018-05-15T18:37:41.653Z,1526409461.653 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-05-15T18:37:41.712Z,1526409461.712 [logger ThreadHandler](INFO): Thread cancelled.