2019-05-21T14:21:18.321Z,1558448478.321 [Supervisor](DEBUG): Initializing supervisor.
2019-05-21T14:21:18.323Z,1558448478.323 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2019-05-21T14:21:18.324Z,1558448478.324 [SyncHandler](INFO): Protected caller Thread ID is 1979
2019-05-21T14:21:18.324Z,1558448478.324 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2019-05-21T14:21:18.325Z,1558448478.325 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2019-05-21T14:21:18.326Z,1558448478.326 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 1980
2019-05-21T14:21:18.328Z,1558448478.328 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2019-05-21T14:21:18.470Z,1558448478.470 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2019-05-21T14:21:18.471Z,1558448478.471 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2019-05-21T14:21:18.471Z,1558448478.471 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 1981
2019-05-21T14:21:18.472Z,1558448478.472 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2019-05-21T14:21:18.473Z,1558448478.473 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2019-05-21T14:21:18.474Z,1558448478.474 [logger ThreadHandler](INFO): Protected caller Thread ID is 1982
2019-05-21T14:21:18.476Z,1558448478.476 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2019-05-21T14:21:18.476Z,1558448478.476 [Supervisor](INFO): Looking for Config files in directory: Config/
2019-05-21T14:21:18.478Z,1558448478.478 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2019-05-21T14:21:18.898Z,1558448478.898 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2019-05-21T14:21:18.898Z,1558448478.898 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2019-05-21T14:21:18.997Z,1558448478.997 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2019-05-21T14:21:18.998Z,1558448478.998 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2019-05-21T14:21:19.322Z,1558448479.322 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2019-05-21T14:21:19.322Z,1558448479.322 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2019-05-21T14:21:19.465Z,1558448479.465 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2019-05-21T14:21:19.466Z,1558448479.466 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2019-05-21T14:21:19.658Z,1558448479.658 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2019-05-21T14:21:19.658Z,1558448479.658 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2019-05-21T14:21:20.111Z,1558448480.111 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2019-05-21T14:21:20.112Z,1558448480.112 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2019-05-21T14:21:20.322Z,1558448480.322 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2019-05-21T14:21:20.323Z,1558448480.323 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2019-05-21T14:21:20.470Z,1558448480.470 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2019-05-21T14:21:20.470Z,1558448480.470 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2019-05-21T14:21:20.702Z,1558448480.702 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2019-05-21T14:21:20.702Z,1558448480.702 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2019-05-21T14:21:20.801Z,1558448480.801 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2019-05-21T14:21:20.802Z,1558448480.802 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2019-05-21T14:21:21.218Z,1558448481.218 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2019-05-21T14:21:21.218Z,1558448481.218 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2019-05-21T14:21:21.300Z,1558448481.300 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2019-05-21T14:21:21.405Z,1558448481.405 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2019-05-21T14:21:21.405Z,1558448481.405 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2019-05-21T14:21:21.994Z,1558448481.994 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2019-05-21T14:21:21.995Z,1558448481.995 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2019-05-21T14:21:22.384Z,1558448482.384 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2019-05-21T14:21:22.386Z,1558448482.386 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/
2019-05-21T14:21:22.387Z,1558448482.387 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/vehicle.cfg
2019-05-21T14:21:22.596Z,1558448482.596 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Control.cfg
2019-05-21T14:21:22.697Z,1558448482.697 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/BIT.cfg
2019-05-21T14:21:22.797Z,1558448482.797 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Battery.cfg
2019-05-21T14:21:23.025Z,1558448483.025 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2019-05-21T14:21:23.025Z,1558448483.025 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Simulator.cfg
2019-05-21T14:21:23.111Z,1558448483.111 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Navigation.cfg
2019-05-21T14:21:23.206Z,1558448483.206 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/logger.cfg
2019-05-21T14:21:23.305Z,1558448483.305 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/secure.cfg
2019-05-21T14:21:23.389Z,1558448483.389 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Servo.cfg
2019-05-21T14:21:23.499Z,1558448483.499 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Sensor.cfg
2019-05-21T14:21:23.679Z,1558448483.679 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Science.cfg
2019-05-21T14:21:23.812Z,1558448483.812 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/LOGIN/
2019-05-21T14:21:23.813Z,1558448483.813 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2019-05-21T14:21:23.827Z,1558448483.827 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2019-05-21T14:21:24.199Z,1558448484.199 [AHRS_M2] Loaded
2019-05-21T14:21:24.199Z,1558448484.199 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2019-05-21T14:21:24.272Z,1558448484.272 [DataOverHttps] Loaded
2019-05-21T14:21:24.272Z,1558448484.272 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2019-05-21T14:21:24.273Z,1558448484.273 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 407604E0
2019-05-21T14:21:24.274Z,1558448484.274 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 2061
2019-05-21T14:21:24.287Z,1558448484.287 [Depth_Keller] Loaded
2019-05-21T14:21:24.287Z,1558448484.287 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2019-05-21T14:21:24.291Z,1558448484.291 [DropWeight] Loaded
2019-05-21T14:21:24.292Z,1558448484.292 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2019-05-21T14:21:24.347Z,1558448484.347 [DUSBL_Hydroid] Loaded
2019-05-21T14:21:24.348Z,1558448484.348 [ComponentRegistry](DEBUG): SyncComponent "DUSBL_Hydroid" handled in the control thread.
2019-05-21T14:21:24.394Z,1558448484.394 [Micromodem] Loaded
2019-05-21T14:21:24.394Z,1558448484.394 [ComponentRegistry](DEBUG): SyncComponent "Micromodem" handled in the control thread.
2019-05-21T14:21:24.490Z,1558448484.490 [NAL9602] Loaded
2019-05-21T14:21:24.490Z,1558448484.490 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2019-05-21T14:21:24.505Z,1558448484.505 [Onboard] Loaded
2019-05-21T14:21:24.505Z,1558448484.505 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2019-05-21T14:21:24.511Z,1558448484.511 [PowerOnly] Loaded
2019-05-21T14:21:24.511Z,1558448484.511 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread.
2019-05-21T14:21:24.518Z,1558448484.518 [Radio_Surface] Loaded
2019-05-21T14:21:24.518Z,1558448484.518 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2019-05-21T14:21:24.519Z,1558448484.519 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 407904E0
2019-05-21T14:21:24.520Z,1558448484.520 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 2062
2019-05-21T14:21:24.563Z,1558448484.563 [RDI_Pathfinder] Loaded
2019-05-21T14:21:24.564Z,1558448484.564 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2019-05-21T14:21:26.041Z,1558448486.041 [BPC1] Loaded
2019-05-21T14:21:26.041Z,1558448486.041 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2019-05-21T14:21:26.041Z,1558448486.041 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2019-05-21T14:21:26.042Z,1558448486.042 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2019-05-21T14:21:26.071Z,1558448486.071 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2019-05-21T14:21:26.072Z,1558448486.072 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2019-05-21T14:21:26.472Z,1558448486.472 [DeadReckonUsingMultipleVelocitySources] Loaded
2019-05-21T14:21:26.472Z,1558448486.472 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2019-05-21T14:21:26.536Z,1558448486.536 [NavChart] Loaded
2019-05-21T14:21:26.536Z,1558448486.536 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2019-05-21T14:21:26.575Z,1558448486.575 [UniversalFixResidualReporter] Loaded
2019-05-21T14:21:26.575Z,1558448486.575 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2019-05-21T14:21:26.575Z,1558448486.575 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2019-05-21T14:21:26.576Z,1558448486.576 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2019-05-21T14:21:26.710Z,1558448486.710 [BuoyancyServo] Loaded
2019-05-21T14:21:26.710Z,1558448486.710 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2019-05-21T14:21:26.725Z,1558448486.725 [ElevatorServo] Loaded
2019-05-21T14:21:26.725Z,1558448486.725 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2019-05-21T14:21:26.740Z,1558448486.740 [MassServo] Loaded
2019-05-21T14:21:26.740Z,1558448486.740 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2019-05-21T14:21:26.805Z,1558448486.805 [RudderServo] Loaded
2019-05-21T14:21:26.806Z,1558448486.806 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2019-05-21T14:21:26.869Z,1558448486.869 [ThrusterServo] Loaded
2019-05-21T14:21:26.869Z,1558448486.869 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2019-05-21T14:21:26.869Z,1558448486.869 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2019-05-21T14:21:26.870Z,1558448486.870 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2019-05-21T14:21:27.194Z,1558448487.194 [CTD_NeilBrown] Loaded
2019-05-21T14:21:27.195Z,1558448487.195 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2019-05-21T14:21:27.196Z,1558448487.196 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 408D24E0
2019-05-21T14:21:27.196Z,1558448487.196 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 2063
2019-05-21T14:21:27.240Z,1558448487.240 [WetLabsSeaOWL_UV_A] Loaded
2019-05-21T14:21:27.240Z,1558448487.240 [ComponentRegistry](DEBUG): Component "WetLabsSeaOWL_UV_A" handled in its own thread.
2019-05-21T14:21:27.241Z,1558448487.241 [WetLabsSeaOWL_UV_A ThreadHandler](DEBUG): Created PCaller Thread at 409024E0
2019-05-21T14:21:27.242Z,1558448487.242 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Protected caller Thread ID is 2064
2019-05-21T14:21:27.242Z,1558448487.242 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2019-05-21T14:21:27.243Z,1558448487.243 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2019-05-21T14:21:27.526Z,1558448487.526 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2019-05-21T14:21:27.527Z,1558448487.527 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2019-05-21T14:21:27.567Z,1558448487.567 [DepthRateCalculator] Loaded
2019-05-21T14:21:27.568Z,1558448487.568 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2019-05-21T14:21:27.574Z,1558448487.574 [PitchRateCalculator] Loaded
2019-05-21T14:21:27.574Z,1558448487.574 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2019-05-21T14:21:27.586Z,1558448487.586 [SpeedCalculator] Loaded
2019-05-21T14:21:27.586Z,1558448487.586 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2019-05-21T14:21:27.607Z,1558448487.607 [TempGradientCalculator] Loaded
2019-05-21T14:21:27.607Z,1558448487.607 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2019-05-21T14:21:27.613Z,1558448487.613 [YawRateCalculator] Loaded
2019-05-21T14:21:27.613Z,1558448487.613 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2019-05-21T14:21:27.653Z,1558448487.653 [ElevatorOffsetCalculator] Loaded
2019-05-21T14:21:27.653Z,1558448487.653 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2019-05-21T14:21:27.653Z,1558448487.653 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2019-05-21T14:21:27.654Z,1558448487.654 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2019-05-21T14:21:27.786Z,1558448487.786 [SBIT](DEBUG): Construct Startup Built In Test.
2019-05-21T14:21:27.807Z,1558448487.807 [SBIT] Loaded
2019-05-21T14:21:27.807Z,1558448487.807 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2019-05-21T14:21:27.808Z,1558448487.808 [IBIT](DEBUG): Construct Initiated Built In Test.
2019-05-21T14:21:27.820Z,1558448487.820 [IBIT] Loaded
2019-05-21T14:21:27.820Z,1558448487.820 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2019-05-21T14:21:27.823Z,1558448487.823 [CBIT](DEBUG): Construct Continuous Built In Test.
2019-05-21T14:21:27.958Z,1558448487.958 [CBIT] Loaded
2019-05-21T14:21:27.958Z,1558448487.958 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2019-05-21T14:21:27.959Z,1558448487.959 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2019-05-21T14:21:27.959Z,1558448487.959 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2019-05-21T14:21:28.029Z,1558448488.029 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2019-05-21T14:21:28.029Z,1558448488.029 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2019-05-21T14:21:28.123Z,1558448488.123 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2019-05-21T14:21:28.124Z,1558448488.124 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2019-05-21T14:21:28.189Z,1558448488.189 [VerticalControl](DEBUG): Construct VerticalControl.
2019-05-21T14:21:28.272Z,1558448488.272 [VerticalControl] Loaded
2019-05-21T14:21:28.272Z,1558448488.272 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2019-05-21T14:21:28.273Z,1558448488.273 [HorizontalControl](DEBUG): Construct HorizontalControl.
2019-05-21T14:21:28.329Z,1558448488.329 [HorizontalControl] Loaded
2019-05-21T14:21:28.329Z,1558448488.329 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2019-05-21T14:21:28.330Z,1558448488.330 [SpeedControl](DEBUG): Construct SpeedControl.
2019-05-21T14:21:28.332Z,1558448488.332 [SpeedControl] Loaded
2019-05-21T14:21:28.332Z,1558448488.332 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2019-05-21T14:21:28.333Z,1558448488.333 [LoopControl](DEBUG): Construct LoopControl.
2019-05-21T14:21:28.333Z,1558448488.333 [LoopControl] Loaded
2019-05-21T14:21:28.333Z,1558448488.333 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2019-05-21T14:21:28.334Z,1558448488.334 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2019-05-21T14:21:28.334Z,1558448488.334 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2019-05-21T14:21:28.360Z,1558448488.360 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2019-05-21T14:21:28.364Z,1558448488.364 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2019-05-21T14:21:28.365Z,1558448488.365 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2019-05-21T14:21:28.371Z,1558448488.371 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2019-05-21T14:21:28.372Z,1558448488.372 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40AD94E0
2019-05-21T14:21:28.373Z,1558448488.373 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 2065
2019-05-21T14:21:28.377Z,1558448488.377 [Supervisor](INFO): Main Thread ID is 1978
2019-05-21T14:21:28.377Z,1558448488.377 [Supervisor](DEBUG): Running supervisor.
2019-05-21T14:21:28.378Z,1558448488.378 [CommandLine ThreadHandler](INFO): Handler Thread ID is 2066
2019-05-21T14:21:28.380Z,1558448488.380 [controlThread ThreadHandler](INFO): Handler Thread ID is 2067
2019-05-21T14:21:28.380Z,1558448488.380 [controlThread](DEBUG): Initializing ControlThread
2019-05-21T14:21:28.389Z,1558448488.389 [NavChart](DEBUG): Initialize NavChart Navigation.
2019-05-21T14:21:28.389Z,1558448488.389 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2019-05-21T14:21:28.391Z,1558448488.391 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2019-05-21T14:21:28.391Z,1558448488.391 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2019-05-21T14:21:28.391Z,1558448488.391 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2019-05-21T14:21:28.392Z,1558448488.392 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2019-05-21T14:21:28.392Z,1558448488.392 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2019-05-21T14:21:28.393Z,1558448488.393 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2019-05-21T14:21:28.393Z,1558448488.393 [SBIT](INFO): Initialize SBIT Component.
2019-05-21T14:21:28.394Z,1558448488.394 [SBIT](IMPORTANT): git: 2019-05-01-9-g5be6d91
2019-05-21T14:21:28.394Z,1558448488.394 [SBIT](INFO): git hash: 5be6d91bfd1d3ef858080230e47d423d1f938b96
2019-05-21T14:21:28.394Z,1558448488.394 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2019-05-21T14:21:28.395Z,1558448488.395 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #1 PREEMPT Thu Feb 21 11:17:40 PST 2019
2019-05-21T14:21:28.397Z,1558448488.397 [SBIT](INFO): Beginning SBIT in 52.000000 seconds.
2019-05-21T14:21:28.397Z,1558448488.397 [IBIT](INFO): Initialize IBIT Component.
2019-05-21T14:21:28.398Z,1558448488.398 [CBIT](DEBUG): Initialize CBIT Component.
2019-05-21T14:21:28.399Z,1558448488.399 [logger ThreadHandler](INFO): Handler Thread ID is 2068
2019-05-21T14:21:28.409Z,1558448488.409 [CBIT](DEBUG): Initialized mux pins.
2019-05-21T14:21:28.409Z,1558448488.409 [CBIT](DEBUG): Initializing the watchdog timer.
2019-05-21T14:21:28.417Z,1558448488.417 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 2069
2019-05-21T14:21:28.418Z,1558448488.418 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2019-05-21T14:21:28.429Z,1558448488.429 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 2070
2019-05-21T14:21:28.433Z,1558448488.433 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2019-05-21T14:21:28.433Z,1558448488.433 [CBIT](DEBUG): Initializing heartbeat.
2019-05-21T14:21:28.449Z,1558448488.449 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 2071
2019-05-21T14:21:28.450Z,1558448488.450 [CTD_NeilBrown](INFO): Powering down
2019-05-21T14:21:28.485Z,1558448488.485 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Handler Thread ID is 2072
2019-05-21T14:21:28.486Z,1558448488.486 [WetLabsSeaOWL_UV_A](INFO): Powering down
2019-05-21T14:21:28.505Z,1558448488.505 [CBIT](DEBUG): Deactivating GF circuits.
2019-05-21T14:21:28.505Z,1558448488.505 [CBIT](DEBUG): Deactivating emergency mode.
2019-05-21T14:21:28.517Z,1558448488.517 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 2073
2019-05-21T14:21:28.520Z,1558448488.520 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2019-05-21T14:21:28.520Z,1558448488.520 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2019-05-21T14:21:28.521Z,1558448488.521 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2019-05-21T14:21:28.521Z,1558448488.521 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2019-05-21T14:21:28.521Z,1558448488.521 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2019-05-21T14:21:28.521Z,1558448488.521 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2019-05-21T14:21:28.521Z,1558448488.521 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2019-05-21T14:21:28.522Z,1558448488.522 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2019-05-21T14:21:28.522Z,1558448488.522 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2019-05-21T14:21:28.522Z,1558448488.522 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2019-05-21T14:21:28.522Z,1558448488.522 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2019-05-21T14:21:28.522Z,1558448488.522 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2019-05-21T14:21:28.523Z,1558448488.523 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2019-05-21T14:21:28.523Z,1558448488.523 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2019-05-21T14:21:28.523Z,1558448488.523 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2019-05-21T14:21:28.523Z,1558448488.523 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2019-05-21T14:21:28.541Z,1558448488.541 [CBIT](DEBUG): Backplane powered.
2019-05-21T14:21:28.541Z,1558448488.541 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2019-05-21T14:21:28.543Z,1558448488.543 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2019-05-21T14:21:28.544Z,1558448488.544 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2019-05-21T14:21:28.544Z,1558448488.544 [LoopControl](DEBUG): Initialize LoopControlComponent.
2019-05-21T14:21:28.545Z,1558448488.545 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2019-05-21T14:21:28.555Z,1558448488.555 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2019-05-21T14:21:28.578Z,1558448488.578 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
       Id="Startup">

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

    <Aggregate Id="StartupSatComms">

        <Sequence/>

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

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

    </Aggregate>

</Mission>


2019-05-21T14:21:28.578Z,1558448488.578 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2019-05-21T14:21:28.652Z,1558448488.652 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2019-05-21T14:21:28.669Z,1558448488.669 [Default:A.Wait](DEBUG): Construct Wait.
2019-05-21T14:21:28.671Z,1558448488.671 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2019-05-21T14:21:28.693Z,1558448488.693 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2019-05-21T14:21:28.696Z,1558448488.696 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2019-05-21T14:21:28.721Z,1558448488.721 [Default:E.Execute](DEBUG): Construct Execute.
2019-05-21T14:21:28.741Z,1558448488.741 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Universal="Tethys/Universal"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
         Id="Default">

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

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

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

    <Aggregate Id="CheckIn">

        <Sequence Repeat="288"/>

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

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

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

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

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

    </Aggregate>

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

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

</Mission>


2019-05-21T14:21:28.753Z,1558448488.753 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,DUSBL_Hydroid,Micromodem,NAL9602,Onboard,PowerOnly,RDI_Pathfinder,BPC1,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2019-05-21T14:21:28.758Z,1558448488.758 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2019-05-21T14:21:28.833Z,1558448488.833 [Radio_Surface](INFO): Powering up
2019-05-21T14:21:28.907Z,1558448488.907 [DUSBL_Hydroid](INFO): Powering up
2019-05-21T14:21:28.907Z,1558448488.907 [DUSBL_Hydroid](DEBUG): Initializing DUSBL_Hydroid.
2019-05-21T14:21:28.925Z,1558448488.925 [Micromodem](INFO): Start
2019-05-21T14:21:28.996Z,1558448488.996 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2019-05-21T14:21:29.001Z,1558448489.001 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2019-05-21T14:21:29.002Z,1558448489.002 [ElevatorServo](DEBUG): Initializing EZServoServo.
2019-05-21T14:21:29.009Z,1558448489.009 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2019-05-21T14:21:29.010Z,1558448489.010 [MassServo](DEBUG): Initializing EZServoServo.
2019-05-21T14:21:29.017Z,1558448489.017 [MassServo](DEBUG): Initializing MassServo.
2019-05-21T14:21:29.018Z,1558448489.018 [RudderServo](DEBUG): Initializing EZServoServo.
2019-05-21T14:21:29.025Z,1558448489.025 [RudderServo](DEBUG): Initializing RudderServo.
2019-05-21T14:21:29.026Z,1558448489.026 [ThrusterServo](DEBUG): Initializing EZServoServo.
2019-05-21T14:21:29.033Z,1558448489.033 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2019-05-21T14:21:29.179Z,1558448489.179 [Micromodem](INFO): Starting
2019-05-21T14:21:29.180Z,1558448489.180 [Micromodem](INFO): Powering up
2019-05-21T14:21:29.180Z,1558448489.180 [Micromodem](DEBUG): Initializing Micromodem.
2019-05-21T14:21:29.570Z,1558448489.570 [Micromodem](INFO): Starting
2019-05-21T14:21:29.909Z,1558448489.909 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2019-05-21T14:21:29.909Z,1558448489.909 [RudderServo](FAULT): Rudder failed to initialize
2019-05-21T14:21:29.909Z,1558448489.909 [RudderServo] Communications Fault, FailCount= 1
2019-05-21T14:21:29.909Z,1558448489.909 [RudderServo](ERROR): Communications Fault
2019-05-21T14:21:30.020Z,1558448490.020 [CBIT](ERROR): Communications Fault in component: RudderServo
2019-05-21T14:21:30.030Z,1558448490.030 [Micromodem](INFO): Starting
2019-05-21T14:21:30.210Z,1558448490.210 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-05-21T14:21:30.225Z,1558448490.225 [RudderServo](INFO): Powering down
2019-05-21T14:21:30.434Z,1558448490.434 [Micromodem](INFO): Starting
2019-05-21T14:21:30.838Z,1558448490.838 [Micromodem](INFO): Starting
2019-05-21T14:21:30.865Z,1558448490.865 [RudderServo](DEBUG): Initializing EZServoServo.
2019-05-21T14:21:30.986Z,1558448490.986 [RudderServo](DEBUG): Initializing RudderServo.
2019-05-21T14:21:30.990Z,1558448490.990 [CBIT](INFO): Clearing failed state for component RudderServo
2019-05-21T14:21:30.990Z,1558448490.990 [RudderServo] No Fault, FailCount= 1
2019-05-21T14:21:31.242Z,1558448491.242 [Micromodem](INFO): Starting
2019-05-21T14:21:31.646Z,1558448491.646 [Micromodem](INFO): Starting
2019-05-21T14:21:32.118Z,1558448492.118 [Micromodem](INFO): Starting
2019-05-21T14:21:32.482Z,1558448492.482 [Micromodem](INFO): Starting
2019-05-21T14:21:32.882Z,1558448492.882 [Micromodem](INFO): Starting
2019-05-21T14:21:33.351Z,1558448493.351 [Micromodem](INFO): Starting
2019-05-21T14:21:33.702Z,1558448493.702 [Micromodem](INFO): Starting
2019-05-21T14:21:34.106Z,1558448494.106 [Micromodem](INFO): Starting
2019-05-21T14:21:34.107Z,1558448494.107 [Micromodem](INFO): Starting
2019-05-21T14:21:34.107Z,1558448494.107 [Micromodem](DEBUG): Nmea buf: $CCCFG,ALL,0*33

2019-05-21T14:21:34.107Z,1558448494.107 [Micromodem](INFO): Nmea out: $CCCFG,ALL,0*33

2019-05-21T14:21:34.108Z,1558448494.108 [Micromodem](DEBUG): Nmea buf: $CCCFG,SRC,1*31

2019-05-21T14:21:34.108Z,1558448494.108 [Micromodem](DEBUG): Nmea buf: $CCCFG,nav.dt.txtrig_gpio4,1*64

2019-05-21T14:21:34.108Z,1558448494.108 [Micromodem](DEBUG): Nmea buf: $CCCFG,BND,1*3B

2019-05-21T14:21:34.510Z,1558448494.510 [Micromodem](INFO): Starting
2019-05-21T14:21:34.954Z,1558448494.954 [Micromodem](INFO): Starting
2019-05-21T14:21:35.366Z,1558448495.366 [Micromodem](INFO): Starting
2019-05-21T14:21:35.762Z,1558448495.762 [Micromodem](INFO): Starting
2019-05-21T14:21:36.166Z,1558448496.166 [Micromodem](INFO): Starting
2019-05-21T14:21:36.167Z,1558448496.167 [Micromodem](INFO): Nmea out: $CCCFG,SRC,1*31

2019-05-21T14:21:36.574Z,1558448496.574 [Micromodem](INFO): Starting
2019-05-21T14:21:36.963Z,1558448496.963 [Micromodem](INFO): Starting
2019-05-21T14:21:37.370Z,1558448497.370 [Micromodem](INFO): Starting
2019-05-21T14:21:37.762Z,1558448497.762 [Micromodem](INFO): Starting
2019-05-21T14:21:38.195Z,1558448498.195 [Micromodem](INFO): Starting
2019-05-21T14:21:38.562Z,1558448498.562 [Micromodem](INFO): Starting
2019-05-21T14:21:38.962Z,1558448498.962 [Micromodem](INFO): Starting
2019-05-21T14:21:39.390Z,1558448499.390 [Micromodem](INFO): Starting
2019-05-21T14:21:39.766Z,1558448499.766 [Micromodem](INFO): Starting
2019-05-21T14:21:40.170Z,1558448500.170 [Micromodem](INFO): Starting
2019-05-21T14:21:40.586Z,1558448500.586 [Micromodem](INFO): Starting
2019-05-21T14:21:40.978Z,1558448500.978 [Micromodem](INFO): Starting
2019-05-21T14:21:41.090Z,1558448501.090 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004530
2019-05-21T14:21:41.382Z,1558448501.382 [Micromodem](INFO): Starting
2019-05-21T14:21:41.790Z,1558448501.790 [Micromodem](INFO): Starting
2019-05-21T14:21:42.190Z,1558448502.190 [Micromodem](INFO): Starting
2019-05-21T14:21:42.216Z,1558448502.216 [RDI_Pathfinder](ERROR): Failed to parse:Pathfinder
2019-05-21T14:21:42.594Z,1558448502.594 [Micromodem](INFO): Starting
2019-05-21T14:21:42.998Z,1558448502.998 [Micromodem](INFO): Starting
2019-05-21T14:21:43.402Z,1558448503.402 [Micromodem](INFO): Starting
2019-05-21T14:21:43.806Z,1558448503.806 [Micromodem](INFO): Starting
2019-05-21T14:21:44.214Z,1558448504.214 [Micromodem](INFO): Starting
2019-05-21T14:21:44.215Z,1558448504.215 [Micromodem](INFO): Nmea out: $CCCFG,nav.dt.txtrig_gpio4,1*64

2019-05-21T14:21:44.614Z,1558448504.614 [Micromodem](INFO): Starting
2019-05-21T14:21:45.018Z,1558448505.018 [Micromodem](INFO): Starting
2019-05-21T14:21:45.426Z,1558448505.426 [Micromodem](INFO): Starting
2019-05-21T14:21:45.826Z,1558448505.826 [Micromodem](INFO): Starting
2019-05-21T14:21:46.230Z,1558448506.230 [Micromodem](INFO): Starting
2019-05-21T14:21:46.651Z,1558448506.651 [Micromodem](INFO): Starting
2019-05-21T14:21:47.038Z,1558448507.038 [DUSBL_Hydroid](INFO): DUSBL Version:O
2019-05-21T14:21:47.053Z,1558448507.053 [Micromodem](INFO): Starting
2019-05-21T14:21:47.442Z,1558448507.442 [Micromodem](INFO): Starting
2019-05-21T14:21:47.850Z,1558448507.850 [Micromodem](INFO): Starting
2019-05-21T14:21:48.250Z,1558448508.250 [Micromodem](INFO): Starting
2019-05-21T14:21:48.654Z,1558448508.654 [Micromodem](INFO): Starting
2019-05-21T14:21:49.062Z,1558448509.062 [Micromodem](INFO): Starting
2019-05-21T14:21:49.462Z,1558448509.462 [Micromodem](INFO): Starting
2019-05-21T14:21:49.866Z,1558448509.866 [Micromodem](INFO): Starting
2019-05-21T14:21:50.274Z,1558448510.274 [Micromodem](INFO): Starting
2019-05-21T14:21:50.674Z,1558448510.674 [Micromodem](INFO): Starting
2019-05-21T14:21:51.090Z,1558448511.090 [Micromodem](INFO): Starting
2019-05-21T14:21:51.486Z,1558448511.486 [Micromodem](INFO): Starting
2019-05-21T14:21:51.890Z,1558448511.890 [Micromodem](INFO): Starting
2019-05-21T14:21:52.290Z,1558448512.290 [Micromodem](INFO): Starting
2019-05-21T14:21:52.694Z,1558448512.694 [Micromodem](INFO): Starting
2019-05-21T14:21:53.110Z,1558448513.110 [Micromodem](INFO): Starting
2019-05-21T14:21:53.502Z,1558448513.502 [Micromodem](INFO): Starting
2019-05-21T14:21:53.910Z,1558448513.910 [Micromodem](INFO): Starting
2019-05-21T14:21:54.310Z,1558448514.310 [Micromodem](INFO): Starting
2019-05-21T14:21:54.311Z,1558448514.311 [Micromodem](INFO): Nmea out: $CCCFG,BND,1*3B

2019-05-21T14:21:54.714Z,1558448514.714 [Micromodem](INFO): Starting
2019-05-21T14:21:54.716Z,1558448514.716 [NAL9602](INFO): Powering up NAL9602
2019-05-21T14:21:55.122Z,1558448515.122 [Micromodem](INFO): Starting
2019-05-21T14:21:55.522Z,1558448515.522 [Micromodem](INFO): Starting
2019-05-21T14:21:55.926Z,1558448515.926 [Micromodem](INFO): Starting
2019-05-21T14:21:56.334Z,1558448516.334 [Micromodem](INFO): Starting
2019-05-21T14:21:56.734Z,1558448516.734 [Micromodem](INFO): Starting
2019-05-21T14:21:57.138Z,1558448517.138 [Micromodem](INFO): Starting
2019-05-21T14:21:57.554Z,1558448517.554 [Micromodem](INFO): Starting
2019-05-21T14:21:57.946Z,1558448517.946 [Micromodem](INFO): Starting
2019-05-21T14:21:58.350Z,1558448518.350 [Micromodem](INFO): Starting
2019-05-21T14:21:58.758Z,1558448518.758 [Micromodem](INFO): Starting
2019-05-21T14:21:59.158Z,1558448519.158 [Micromodem](INFO): Starting
2019-05-21T14:21:59.562Z,1558448519.562 [Micromodem](INFO): Starting
2019-05-21T14:21:59.966Z,1558448519.966 [Micromodem](INFO): Starting
2019-05-21T14:22:00.370Z,1558448520.370 [Micromodem](INFO): Starting
2019-05-21T14:22:00.774Z,1558448520.774 [Micromodem](INFO): Starting
2019-05-21T14:22:01.178Z,1558448521.178 [Micromodem](INFO): Starting
2019-05-21T14:22:01.582Z,1558448521.582 [Micromodem](INFO): Starting
2019-05-21T14:22:01.986Z,1558448521.986 [Micromodem](INFO): Starting
2019-05-21T14:22:02.390Z,1558448522.390 [Micromodem](INFO): Starting
2019-05-21T14:22:02.794Z,1558448522.794 [Micromodem](INFO): Starting
2019-05-21T14:22:03.198Z,1558448523.198 [Micromodem](INFO): Starting
2019-05-21T14:22:03.606Z,1558448523.606 [Micromodem](INFO): Starting
2019-05-21T14:22:04.006Z,1558448524.006 [Micromodem](INFO): Starting
2019-05-21T14:22:04.410Z,1558448524.410 [Micromodem](INFO): Starting
2019-05-21T14:22:04.814Z,1558448524.814 [Micromodem](INFO): Starting
2019-05-21T14:22:05.218Z,1558448525.218 [Micromodem](INFO): Starting
2019-05-21T14:22:05.622Z,1558448525.622 [Micromodem](INFO): Starting
2019-05-21T14:22:05.623Z,1558448525.623 [NAL9602](INFO): NAL9602 initialized
2019-05-21T14:22:06.038Z,1558448526.038 [Micromodem](INFO): Starting
2019-05-21T14:22:06.430Z,1558448526.430 [Micromodem](INFO): Starting
2019-05-21T14:22:06.449Z,1558448526.449 [NAL9602](DEBUG): Fix Requested
2019-05-21T14:22:06.469Z,1558448526.469 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2019-05-21T14:22:06.469Z,1558448526.469 [RDI_Pathfinder](ERROR): Failed to parse:
:RA,  0.00,   0.00,   0.00,   0.00
2019-05-21T14:22:06.834Z,1558448526.834 [Micromodem](INFO): Starting
2019-05-21T14:22:07.238Z,1558448527.238 [Micromodem](INFO): Starting
2019-05-21T14:22:07.642Z,1558448527.642 [Micromodem](INFO): Starting
2019-05-21T14:22:08.046Z,1558448528.046 [Micromodem](INFO): Starting
2019-05-21T14:22:08.454Z,1558448528.454 [Micromodem](INFO): Starting
2019-05-21T14:22:08.854Z,1558448528.854 [Micromodem](INFO): Starting
2019-05-21T14:22:09.277Z,1558448529.277 [Micromodem](INFO): Starting
2019-05-21T14:22:09.678Z,1558448529.678 [Micromodem](INFO): Starting
2019-05-21T14:22:10.066Z,1558448530.066 [Micromodem](INFO): Starting
2019-05-21T14:22:10.470Z,1558448530.470 [Micromodem](INFO): Starting
2019-05-21T14:22:10.878Z,1558448530.878 [Micromodem](INFO): Starting
2019-05-21T14:22:11.278Z,1558448531.278 [Micromodem](INFO): Starting
2019-05-21T14:22:11.682Z,1558448531.682 [Micromodem](INFO): Starting
2019-05-21T14:22:12.107Z,1558448532.107 [Micromodem](INFO): Starting
2019-05-21T14:22:12.490Z,1558448532.490 [Micromodem](INFO): Starting
2019-05-21T14:22:12.909Z,1558448532.909 [Micromodem](INFO): Starting
2019-05-21T14:22:13.318Z,1558448533.318 [Micromodem](INFO): Starting
2019-05-21T14:22:13.706Z,1558448533.706 [Micromodem](INFO): Starting
2019-05-21T14:22:14.114Z,1558448534.114 [Micromodem](INFO): Starting
2019-05-21T14:22:14.514Z,1558448534.514 [Micromodem](INFO): Starting
2019-05-21T14:22:14.918Z,1558448534.918 [Micromodem](INFO): Starting
2019-05-21T14:22:15.318Z,1558448535.318 [Micromodem](INFO): Starting
2019-05-21T14:22:15.722Z,1558448535.722 [Micromodem](INFO): Starting
2019-05-21T14:22:16.126Z,1558448536.126 [Micromodem](INFO): Starting
2019-05-21T14:22:16.530Z,1558448536.530 [Micromodem](INFO): Starting
2019-05-21T14:22:16.938Z,1558448536.938 [Micromodem](INFO): Starting
2019-05-21T14:22:17.337Z,1558448537.337 [Micromodem](INFO): Starting
2019-05-21T14:22:17.742Z,1558448537.742 [Micromodem](INFO): Starting
2019-05-21T14:22:18.165Z,1558448538.165 [Micromodem](INFO): Starting
2019-05-21T14:22:18.550Z,1558448538.550 [Micromodem](INFO): Starting
2019-05-21T14:22:18.954Z,1558448538.954 [Micromodem](INFO): Starting
2019-05-21T14:22:19.370Z,1558448539.370 [Micromodem](INFO): Starting
2019-05-21T14:22:19.762Z,1558448539.762 [Micromodem](INFO): Starting
2019-05-21T14:22:20.166Z,1558448540.166 [Micromodem](INFO): Starting
2019-05-21T14:22:20.570Z,1558448540.570 [Micromodem](INFO): Starting
2019-05-21T14:22:20.974Z,1558448540.974 [Micromodem](INFO): Starting
2019-05-21T14:22:21.003Z,1558448541.003 [SBIT](IMPORTANT): Beginning Startup BIT
2019-05-21T14:22:21.011Z,1558448541.011 [CBIT](IMPORTANT): Beginning ground fault scan
2019-05-21T14:22:21.378Z,1558448541.378 [Micromodem](INFO): Starting
2019-05-21T14:22:21.782Z,1558448541.782 [Micromodem](INFO): Starting
2019-05-21T14:22:22.186Z,1558448542.186 [Micromodem](INFO): Starting
2019-05-21T14:22:22.590Z,1558448542.590 [Micromodem](INFO): Starting
2019-05-21T14:22:22.998Z,1558448542.998 [Micromodem](INFO): Starting
2019-05-21T14:22:23.398Z,1558448543.398 [Micromodem](INFO): Starting
2019-05-21T14:22:24.050Z,1558448544.050 [Micromodem](INFO): Starting
2019-05-21T14:22:24.418Z,1558448544.418 [Micromodem](INFO): Starting
2019-05-21T14:22:24.830Z,1558448544.830 [Micromodem](INFO): Starting
2019-05-21T14:22:25.227Z,1558448545.227 [Micromodem](INFO): Starting
2019-05-21T14:22:25.638Z,1558448545.638 [Micromodem](INFO): Starting
2019-05-21T14:22:26.045Z,1558448546.045 [Micromodem](INFO): Starting
2019-05-21T14:22:26.439Z,1558448546.439 [Micromodem](INFO): Starting
2019-05-21T14:22:26.854Z,1558448546.854 [Micromodem](INFO): Starting
2019-05-21T14:22:27.254Z,1558448547.254 [Micromodem](INFO): Starting
2019-05-21T14:22:27.654Z,1558448547.654 [Micromodem](INFO): Starting
2019-05-21T14:22:28.055Z,1558448548.055 [Micromodem](INFO): Starting
2019-05-21T14:22:28.459Z,1558448548.459 [Micromodem](INFO): Starting
2019-05-21T14:22:28.866Z,1558448548.866 [Micromodem](INFO): Starting
2019-05-21T14:22:29.279Z,1558448549.279 [Micromodem](INFO): Starting
2019-05-21T14:22:29.687Z,1558448549.687 [Micromodem](INFO): Starting
2019-05-21T14:22:30.078Z,1558448550.078 [Micromodem](INFO): Starting
2019-05-21T14:22:30.482Z,1558448550.482 [Micromodem](INFO): Starting
2019-05-21T14:22:30.894Z,1558448550.894 [Micromodem](INFO): Starting
2019-05-21T14:22:31.294Z,1558448551.294 [Micromodem](INFO): Starting
2019-05-21T14:22:31.694Z,1558448551.694 [Micromodem](INFO): Starting
2019-05-21T14:22:32.111Z,1558448552.111 [Micromodem](INFO): Starting
2019-05-21T14:22:32.202Z,1558448552.202 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.009912
CHAN A1 (24V): -0.028584
CHAN A2 (12V): -0.007268
CHAN A3 (5V): -0.002557
CHAN B0 (3.3V): 0.000290
CHAN B1 (3.15aV): -0.000243
CHAN B2 (3.15bV): 0.000042
CHAN B3 (GND): 0.002263
OPEN: 0.005350
Full Scale Calc: 4.765 mA, -1.589 mA
2019-05-21T14:22:32.502Z,1558448552.502 [Micromodem](INFO): Starting
2019-05-21T14:22:32.906Z,1558448552.906 [Micromodem](INFO): Starting
2019-05-21T14:22:33.310Z,1558448553.310 [Micromodem](INFO): Starting
2019-05-21T14:22:33.718Z,1558448553.718 [Micromodem](INFO): Starting
2019-05-21T14:22:34.115Z,1558448554.115 [Micromodem](INFO): Starting
2019-05-21T14:22:34.519Z,1558448554.519 [Micromodem](INFO): Starting
2019-05-21T14:22:34.923Z,1558448554.923 [Micromodem](INFO): Starting
2019-05-21T14:22:35.330Z,1558448555.330 [Micromodem](INFO): Starting
2019-05-21T14:22:35.734Z,1558448555.734 [Micromodem](INFO): Starting
2019-05-21T14:22:36.135Z,1558448556.135 [Micromodem](INFO): Starting
2019-05-21T14:22:36.726Z,1558448556.726 [Micromodem](INFO): Starting
2019-05-21T14:22:37.129Z,1558448557.129 [Micromodem](INFO): Starting
2019-05-21T14:22:37.530Z,1558448557.530 [Micromodem](INFO): Starting
2019-05-21T14:22:37.934Z,1558448557.934 [Micromodem](INFO): Starting
2019-05-21T14:22:38.338Z,1558448558.338 [Micromodem](INFO): Starting
2019-05-21T14:22:38.742Z,1558448558.742 [Micromodem](INFO): Starting
2019-05-21T14:22:39.146Z,1558448559.146 [Micromodem](INFO): Starting
2019-05-21T14:22:39.550Z,1558448559.550 [Micromodem](INFO): Starting
2019-05-21T14:22:39.958Z,1558448559.958 [Micromodem](INFO): Starting
2019-05-21T14:22:40.354Z,1558448560.354 [Micromodem](INFO): Starting
2019-05-21T14:22:40.774Z,1558448560.774 [Micromodem](INFO): Starting
2019-05-21T14:22:41.166Z,1558448561.166 [Micromodem](INFO): Starting
2019-05-21T14:22:41.566Z,1558448561.566 [Micromodem](INFO): Starting
2019-05-21T14:22:41.970Z,1558448561.970 [Micromodem](INFO): Starting
2019-05-21T14:22:42.378Z,1558448562.378 [Micromodem](INFO): Starting
2019-05-21T14:22:42.778Z,1558448562.778 [Micromodem](INFO): Starting
2019-05-21T14:22:43.182Z,1558448563.182 [Micromodem](INFO): Starting
2019-05-21T14:22:43.590Z,1558448563.590 [Micromodem](INFO): Starting
2019-05-21T14:22:43.990Z,1558448563.990 [Micromodem](INFO): Starting
2019-05-21T14:22:44.407Z,1558448564.407 [Micromodem](INFO): Starting
2019-05-21T14:22:44.810Z,1558448564.810 [Micromodem](INFO): Starting
2019-05-21T14:22:45.206Z,1558448565.206 [Micromodem](INFO): Starting
2019-05-21T14:22:45.611Z,1558448565.611 [Micromodem](INFO): Starting
2019-05-21T14:22:46.014Z,1558448566.014 [Micromodem](INFO): Starting
2019-05-21T14:22:46.426Z,1558448566.426 [Micromodem](INFO): Starting
2019-05-21T14:22:46.822Z,1558448566.822 [Micromodem](INFO): Starting
2019-05-21T14:22:47.222Z,1558448567.222 [Micromodem](INFO): Starting
2019-05-21T14:22:47.626Z,1558448567.626 [Micromodem](INFO): Starting
2019-05-21T14:22:48.034Z,1558448568.034 [Micromodem](INFO): Starting
2019-05-21T14:22:48.036Z,1558448568.036 [NAL9602](INFO): SBD MO Status=0, MOMSN=4822, MT Status=0, MTMSN=0
2019-05-21T14:22:48.036Z,1558448568.036 [NAL9602](INFO): No messages in MT queue
2019-05-21T14:22:48.434Z,1558448568.434 [Micromodem](INFO): Starting
2019-05-21T14:22:48.838Z,1558448568.838 [Micromodem](INFO): Starting
2019-05-21T14:22:48.853Z,1558448568.853 [NAL9602](DEBUG): Fix Requested
2019-05-21T14:22:49.268Z,1558448569.268 [Micromodem](INFO): Starting
2019-05-21T14:22:49.659Z,1558448569.659 [Micromodem](INFO): Starting
2019-05-21T14:22:50.059Z,1558448570.059 [Micromodem](INFO): Starting
2019-05-21T14:22:50.470Z,1558448570.470 [Micromodem](INFO): Starting
2019-05-21T14:22:50.862Z,1558448570.862 [Micromodem](INFO): Starting
2019-05-21T14:22:51.271Z,1558448571.271 [Micromodem](INFO): Starting
2019-05-21T14:22:51.670Z,1558448571.670 [Micromodem](INFO): Starting
2019-05-21T14:22:51.685Z,1558448571.685 [NAL9602](DEBUG): Fix Requested
2019-05-21T14:22:52.074Z,1558448572.074 [Micromodem](INFO): Starting
2019-05-21T14:22:52.474Z,1558448572.474 [Micromodem](INFO): Starting
2019-05-21T14:22:52.882Z,1558448572.882 [Micromodem](INFO): Starting
2019-05-21T14:22:53.282Z,1558448573.282 [Micromodem](INFO): Starting
2019-05-21T14:22:53.686Z,1558448573.686 [Micromodem](INFO): Starting
2019-05-21T14:22:54.110Z,1558448574.110 [Micromodem](INFO): Starting
2019-05-21T14:22:54.498Z,1558448574.498 [Micromodem](INFO): Starting
2019-05-21T14:22:54.898Z,1558448574.898 [Micromodem](INFO): Starting
2019-05-21T14:22:54.913Z,1558448574.913 [NAL9602](DEBUG): Fix Requested
2019-05-21T14:22:55.302Z,1558448575.302 [Micromodem](INFO): Starting
2019-05-21T14:22:55.710Z,1558448575.710 [Micromodem](INFO): Starting
2019-05-21T14:22:56.119Z,1558448576.119 [Micromodem](INFO): Starting
2019-05-21T14:22:56.514Z,1558448576.514 [Micromodem](INFO): Starting
2019-05-21T14:22:56.922Z,1558448576.922 [Micromodem](INFO): Starting
2019-05-21T14:22:57.322Z,1558448577.322 [Micromodem](INFO): Starting
2019-05-21T14:22:57.726Z,1558448577.726 [Micromodem](INFO): Starting
2019-05-21T14:22:57.741Z,1558448577.741 [NAL9602](DEBUG): Fix Requested
2019-05-21T14:22:58.134Z,1558448578.134 [Micromodem](INFO): Starting
2019-05-21T14:22:58.534Z,1558448578.534 [Micromodem](INFO): Starting
2019-05-21T14:22:58.942Z,1558448578.942 [Micromodem](INFO): Starting
2019-05-21T14:22:59.346Z,1558448579.346 [Micromodem](INFO): Starting
2019-05-21T14:22:59.746Z,1558448579.746 [Micromodem](INFO): Starting
2019-05-21T14:23:00.150Z,1558448580.150 [Micromodem](INFO): Starting
2019-05-21T14:23:00.554Z,1558448580.554 [Micromodem](INFO): Starting
2019-05-21T14:23:00.958Z,1558448580.958 [Micromodem](INFO): Starting
2019-05-21T14:23:00.973Z,1558448580.973 [NAL9602](DEBUG): Fix Requested
2019-05-21T14:23:01.366Z,1558448581.366 [Micromodem](INFO): Starting
2019-05-21T14:23:01.775Z,1558448581.775 [Micromodem](INFO): Starting
2019-05-21T14:23:02.170Z,1558448582.170 [Micromodem](INFO): Starting
2019-05-21T14:23:02.583Z,1558448582.583 [Micromodem](INFO): Starting
2019-05-21T14:23:02.982Z,1558448582.982 [Micromodem](INFO): Starting
2019-05-21T14:23:03.486Z,1558448583.486 [Micromodem](INFO): Starting
2019-05-21T14:23:03.886Z,1558448583.886 [Micromodem](INFO): Starting
2019-05-21T14:23:03.901Z,1558448583.901 [NAL9602](DEBUG): Fix Requested
2019-05-21T14:23:04.290Z,1558448584.290 [Micromodem](INFO): Starting
2019-05-21T14:23:04.694Z,1558448584.694 [Micromodem](INFO): Starting
2019-05-21T14:23:05.104Z,1558448585.104 [Micromodem](INFO): Starting
2019-05-21T14:23:05.502Z,1558448585.502 [Micromodem](INFO): Starting
2019-05-21T14:23:05.906Z,1558448585.906 [Micromodem](INFO): Starting
2019-05-21T14:23:06.310Z,1558448586.310 [Micromodem](INFO): Starting
2019-05-21T14:23:06.714Z,1558448586.714 [Micromodem](INFO): Starting
2019-05-21T14:23:06.729Z,1558448586.729 [NAL9602](DEBUG): Fix Requested
2019-05-21T14:23:07.125Z,1558448587.125 [Micromodem](INFO): Starting
2019-05-21T14:23:07.518Z,1558448587.518 [Micromodem](INFO): Starting
2019-05-21T14:23:07.942Z,1558448587.942 [Micromodem](INFO): Starting
2019-05-21T14:23:08.326Z,1558448588.326 [Micromodem](INFO): Starting
2019-05-21T14:23:08.734Z,1558448588.734 [Micromodem](INFO): Starting
2019-05-21T14:23:09.142Z,1558448589.142 [Micromodem](INFO): Starting
2019-05-21T14:23:09.538Z,1558448589.538 [Micromodem](INFO): Starting
2019-05-21T14:23:09.553Z,1558448589.553 [NAL9602](DEBUG): Fix Requested
2019-05-21T14:23:09.946Z,1558448589.946 [Micromodem](INFO): Starting
2019-05-21T14:23:10.350Z,1558448590.350 [Micromodem](INFO): Starting
2019-05-21T14:23:10.754Z,1558448590.754 [Micromodem](INFO): Starting
2019-05-21T14:23:11.162Z,1558448591.162 [Micromodem](INFO): Starting
2019-05-21T14:23:11.562Z,1558448591.562 [Micromodem](INFO): Starting
2019-05-21T14:23:11.962Z,1558448591.962 [Micromodem](INFO): Starting
2019-05-21T14:23:12.374Z,1558448592.374 [Micromodem](INFO): Starting
2019-05-21T14:23:12.774Z,1558448592.774 [Micromodem](INFO): Starting
2019-05-21T14:23:12.793Z,1558448592.793 [NAL9602](DEBUG): Fix Requested
2019-05-21T14:23:13.174Z,1558448593.174 [Micromodem](INFO): Starting
2019-05-21T14:23:13.578Z,1558448593.578 [Micromodem](INFO): Starting
2019-05-21T14:23:13.987Z,1558448593.987 [Micromodem](INFO): Starting
2019-05-21T14:23:14.390Z,1558448594.390 [Micromodem](INFO): Starting
2019-05-21T14:23:14.790Z,1558448594.790 [Micromodem](INFO): Starting
2019-05-21T14:23:14.893Z,1558448594.893 [SBIT](IMPORTANT): SBIT PASSED
2019-05-21T14:23:14.993Z,1558448594.993 [CommandLine](IMPORTANT): got command configSet list
2019-05-21T14:23:14.994Z,1558448594.994 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2019-05-21T14:23:14.995Z,1558448594.995 [CommandLine](IMPORTANT): BPC1.batterySamplingInterval=3 hour;

2019-05-21T14:23:14.995Z,1558448594.995 [CommandLine](IMPORTANT): BPC1.loadAtStartup=1 bool;

2019-05-21T14:23:14.997Z,1558448594.997 [CommandLine](IMPORTANT): DUSBL_Hydroid.detectionThreshold=75 count;

2019-05-21T14:23:14.998Z,1558448594.998 [CommandLine](IMPORTANT): Express linearApproximation DUSBL_Hydroid.range 2.000000 meter;

2019-05-21T14:23:14.998Z,1558448594.998 [CommandLine](IMPORTANT): Express linearApproximation DUSBL_Hydroid.xAngle 2.000000 angular_degree;

2019-05-21T14:23:14.998Z,1558448594.998 [CommandLine](IMPORTANT): Express linearApproximation RDI_Pathfinder.BottomVelocityFlag 0.000000 count;

2019-05-21T14:23:14.998Z,1558448594.998 [CommandLine](IMPORTANT): Express linearApproximation RDI_Pathfinder.height_above_sea_floor 2.000000 meter;

2019-05-21T14:23:14.998Z,1558448594.998 [CommandLine](IMPORTANT): Express none TrackAcousticContact.contact_latitude;

2019-05-21T14:23:14.998Z,1558448594.998 [CommandLine](IMPORTANT): Express none TrackAcousticContact.contact_longitude;

2019-05-21T14:23:14.998Z,1558448594.998 [CommandLine](IMPORTANT): Express linearApproximation acoustic_contact_range 1.000000 meter;

2019-05-21T14:23:14.998Z,1558448594.998 [CommandLine](IMPORTANT): Express linearApproximation mass_concentration_of_chlorophyll_in_sea_water 5.000000 microgram_per_liter;

2019-05-21T14:23:14.998Z,1558448594.998 [CommandLine](IMPORTANT): Express none mass_concentration_of_oxygen_in_sea_water;

2019-05-21T14:23:14.999Z,1558448594.999 [CommandLine](IMPORTANT): NAL9602.fastGPSFix=1 bool;

2019-05-21T14:23:14.999Z,1558448594.999 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=525 cubic_centimeter;

2019-05-21T14:23:14.999Z,1558448594.999 [CommandLine](IMPORTANT): VerticalControl.massDefault=-8 millimeter;

2019-05-21T14:23:15.194Z,1558448595.194 [Micromodem](INFO): Starting
2019-05-21T14:23:15.239Z,1558448595.239 [MissionManager](IMPORTANT): Started mission Startup
2019-05-21T14:23:15.239Z,1558448595.239 [Startup] Running Loop=1
2019-05-21T14:23:15.239Z,1558448595.239 [Startup](DEBUG): Aggregate::initialize Startup
2019-05-21T14:23:15.239Z,1558448595.239 [Startup:A.GoToSurface] Running Loop=1
2019-05-21T14:23:15.239Z,1558448595.239 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-05-21T14:23:15.240Z,1558448595.240 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-05-21T14:23:15.240Z,1558448595.240 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-05-21T14:23:15.241Z,1558448595.241 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-05-21T14:23:15.241Z,1558448595.241 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-05-21T14:23:15.242Z,1558448595.242 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-05-21T14:23:15.243Z,1558448595.243 [Startup:StartupSatComms] Running Loop=1
2019-05-21T14:23:15.243Z,1558448595.243 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2019-05-21T14:23:15.243Z,1558448595.243 [Startup:StartupSatComms:A] Running Loop=1
2019-05-21T14:23:15.606Z,1558448595.606 [Micromodem](INFO): Starting
2019-05-21T14:23:15.621Z,1558448595.621 [NAL9602](DEBUG): Fix Requested
2019-05-21T14:23:15.662Z,1558448595.662 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2019-05-21T14:23:16.002Z,1558448596.002 [Micromodem](INFO): Starting
2019-05-21T14:23:16.429Z,1558448596.429 [Micromodem](INFO): Starting
2019-05-21T14:23:16.814Z,1558448596.814 [Micromodem](INFO): Starting
2019-05-21T14:23:17.230Z,1558448597.230 [Micromodem](INFO): Starting
2019-05-21T14:23:17.623Z,1558448597.623 [Micromodem](INFO): Starting
2019-05-21T14:23:18.030Z,1558448598.030 [Micromodem](INFO): Starting
2019-05-21T14:23:18.434Z,1558448598.434 [Micromodem](INFO): Starting
2019-05-21T14:23:18.834Z,1558448598.834 [Micromodem](INFO): Starting
2019-05-21T14:23:18.849Z,1558448598.849 [NAL9602](DEBUG): Fix Requested
2019-05-21T14:23:19.261Z,1558448599.261 [Micromodem](INFO): Starting
2019-05-21T14:23:19.638Z,1558448599.638 [Micromodem](INFO): Starting
2019-05-21T14:23:20.046Z,1558448600.046 [Micromodem](INFO): Starting
2019-05-21T14:23:20.466Z,1558448600.466 [Micromodem](INFO): Starting
2019-05-21T14:23:20.850Z,1558448600.850 [Micromodem](INFO): Starting
2019-05-21T14:23:21.258Z,1558448601.258 [Micromodem](INFO): Starting
2019-05-21T14:23:21.658Z,1558448601.658 [Micromodem](INFO): Starting
2019-05-21T14:23:21.673Z,1558448601.673 [NAL9602](DEBUG): Fix Requested
2019-05-21T14:23:22.066Z,1558448602.066 [Micromodem](INFO): Starting
2019-05-21T14:23:22.474Z,1558448602.474 [Micromodem](INFO): Starting
2019-05-21T14:23:22.870Z,1558448602.870 [Micromodem](INFO): Starting
2019-05-21T14:23:23.274Z,1558448603.274 [Micromodem](INFO): Starting
2019-05-21T14:23:23.682Z,1558448603.682 [Micromodem](INFO): Starting
2019-05-21T14:23:24.099Z,1558448604.099 [Micromodem](INFO): Starting
2019-05-21T14:23:24.490Z,1558448604.490 [Micromodem](INFO): Starting
2019-05-21T14:23:24.894Z,1558448604.894 [Micromodem](INFO): Starting
2019-05-21T14:23:24.909Z,1558448604.909 [NAL9602](DEBUG): Fix Requested
2019-05-21T14:23:25.294Z,1558448605.294 [Micromodem](INFO): Starting
2019-05-21T14:23:25.698Z,1558448605.698 [Micromodem](INFO): Starting
2019-05-21T14:23:26.114Z,1558448606.114 [Micromodem](INFO): Starting
2019-05-21T14:23:26.506Z,1558448606.506 [Micromodem](INFO): Starting
2019-05-21T14:23:26.910Z,1558448606.910 [Micromodem](INFO): Starting
2019-05-21T14:23:27.314Z,1558448607.314 [Micromodem](INFO): Starting
2019-05-21T14:23:27.718Z,1558448607.718 [Micromodem](INFO): Starting
2019-05-21T14:23:27.733Z,1558448607.733 [NAL9602](DEBUG): Fix Requested
2019-05-21T14:23:28.126Z,1558448608.126 [Micromodem](INFO): Starting
2019-05-21T14:23:28.530Z,1558448608.530 [Micromodem](INFO): Starting
2019-05-21T14:23:28.938Z,1558448608.938 [Micromodem](INFO): Starting
2019-05-21T14:23:28.939Z,1558448608.939 [Micromodem](FAULT): failed to initialize; deviceResponse_ loaded: $CAREV,142323,AUV,2.0.27690*10
, available: $CAREV,142323,COPROC,0.10.0.46*45

2019-05-21T14:23:28.939Z,1558448608.939 [Micromodem] Communications Fault, FailCount= 1
2019-05-21T14:23:28.939Z,1558448608.939 [Micromodem](ERROR): Communications Fault
2019-05-21T14:23:28.990Z,1558448608.990 [CBIT](ERROR): Communications Fault in component: Micromodem
2019-05-21T14:23:29.342Z,1558448609.342 [Micromodem](INFO): Stop
2019-05-21T14:23:29.342Z,1558448609.342 [Micromodem](INFO): uninitialize
2019-05-21T14:23:29.342Z,1558448609.342 [Micromodem](INFO): Powering down
2019-05-21T14:23:29.750Z,1558448609.750 [Micromodem](INFO): Stopping
2019-05-21T14:23:30.146Z,1558448610.146 [Micromodem](INFO): Stopped
2019-05-21T14:23:30.190Z,1558448610.190 [CBIT](INFO): Clearing failed state for component Micromodem
2019-05-21T14:23:30.191Z,1558448610.191 [Micromodem] No Fault, FailCount= 1
2019-05-21T14:23:30.546Z,1558448610.546 [Micromodem](INFO): Start
2019-05-21T14:23:30.950Z,1558448610.950 [Micromodem](INFO): Start
2019-05-21T14:23:30.965Z,1558448610.965 [NAL9602](DEBUG): Fix Requested
2019-05-21T14:23:31.354Z,1558448611.354 [Micromodem](INFO): Start
2019-05-21T14:23:31.762Z,1558448611.762 [Micromodem](INFO): Start
2019-05-21T14:23:32.166Z,1558448612.166 [Micromodem](INFO): Start
2019-05-21T14:23:32.570Z,1558448612.570 [Micromodem](INFO): Start
2019-05-21T14:23:32.975Z,1558448612.975 [Micromodem](INFO): Starting
2019-05-21T14:23:32.975Z,1558448612.975 [Micromodem](INFO): Powering up
2019-05-21T14:23:32.975Z,1558448612.975 [Micromodem](DEBUG): Initializing Micromodem.
2019-05-21T14:23:33.379Z,1558448613.379 [Micromodem](INFO): Starting
2019-05-21T14:23:33.778Z,1558448613.778 [Micromodem](INFO): Starting
2019-05-21T14:23:33.793Z,1558448613.793 [NAL9602](DEBUG): Fix Requested
2019-05-21T14:23:34.186Z,1558448614.186 [Micromodem](INFO): Starting
2019-05-21T14:23:34.590Z,1558448614.590 [Micromodem](INFO): Starting
2019-05-21T14:23:34.994Z,1558448614.994 [Micromodem](INFO): Starting
2019-05-21T14:23:35.394Z,1558448615.394 [Micromodem](INFO): Starting
2019-05-21T14:23:35.802Z,1558448615.802 [Micromodem](INFO): Starting
2019-05-21T14:23:36.202Z,1558448616.202 [Micromodem](INFO): Starting
2019-05-21T14:23:36.621Z,1558448616.621 [Micromodem](INFO): Starting
2019-05-21T14:23:37.014Z,1558448617.014 [Micromodem](INFO): Starting
2019-05-21T14:23:37.033Z,1558448617.033 [NAL9602](DEBUG): Fix Requested
2019-05-21T14:23:37.414Z,1558448617.414 [Micromodem](INFO): Starting
2019-05-21T14:23:37.818Z,1558448617.818 [Micromodem](INFO): Starting
2019-05-21T14:23:37.818Z,1558448617.818 [Micromodem](INFO): Starting
2019-05-21T14:23:37.819Z,1558448617.819 [Micromodem](DEBUG): Nmea buf: $CCCFG,ALL,0*33

2019-05-21T14:23:37.819Z,1558448617.819 [Micromodem](INFO): Nmea out: $CCCFG,ALL,0*33

2019-05-21T14:23:37.820Z,1558448617.820 [Micromodem](DEBUG): Nmea buf: $CCCFG,SRC,1*31

2019-05-21T14:23:37.822Z,1558448617.822 [Micromodem](DEBUG): Nmea buf: $CCCFG,nav.dt.txtrig_gpio4,1*64

2019-05-21T14:23:37.823Z,1558448617.823 [Micromodem](DEBUG): Nmea buf: $CCCFG,BND,1*3B

2019-05-21T14:23:38.222Z,1558448618.222 [Micromodem](INFO): Starting
2019-05-21T14:23:38.626Z,1558448618.626 [Micromodem](INFO): Starting
2019-05-21T14:23:39.035Z,1558448619.035 [Micromodem](INFO): Starting
2019-05-21T14:23:39.439Z,1558448619.439 [Micromodem](INFO): Starting
2019-05-21T14:23:39.838Z,1558448619.838 [Micromodem](INFO): Starting
2019-05-21T14:23:39.857Z,1558448619.857 [NAL9602](DEBUG): Fix Requested
2019-05-21T14:23:40.242Z,1558448620.242 [Micromodem](INFO): Starting
2019-05-21T14:23:40.646Z,1558448620.646 [Micromodem](INFO): Starting
2019-05-21T14:23:41.050Z,1558448621.050 [Micromodem](INFO): Starting
2019-05-21T14:23:41.470Z,1558448621.470 [Micromodem](INFO): Starting
2019-05-21T14:23:41.858Z,1558448621.858 [Micromodem](INFO): Starting
2019-05-21T14:23:42.266Z,1558448622.266 [Micromodem](INFO): Starting
2019-05-21T14:23:42.674Z,1558448622.674 [Micromodem](INFO): Starting
2019-05-21T14:23:42.689Z,1558448622.689 [NAL9602](DEBUG): Fix Requested
2019-05-21T14:23:43.106Z,1558448623.106 [Micromodem](INFO): Starting
2019-05-21T14:23:43.478Z,1558448623.478 [Micromodem](INFO): Starting
2019-05-21T14:23:43.878Z,1558448623.878 [Micromodem](INFO): Starting
2019-05-21T14:23:43.957Z,1558448623.957 [CommandLine](IMPORTANT): got command quit
2019-05-21T14:23:44.286Z,1558448624.286 [Micromodem](INFO): Starting
2019-05-21T14:23:44.686Z,1558448624.686 [Micromodem](INFO): Starting
2019-05-21T14:23:44.961Z,1558448624.961 [Supervisor](INFO): Stop Mission called by Supervisor::terminate
2019-05-21T14:23:44.961Z,1558448624.961 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-21T14:23:44.961Z,1558448624.961 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-05-21T14:23:45.110Z,1558448625.110 [Micromodem](INFO): Starting
2019-05-21T14:23:45.125Z,1558448625.125 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2019-05-21T14:23:45.125Z,1558448625.125 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-05-21T14:23:45.126Z,1558448625.126 [CommandLine](INFO): Join timeout helper Thread ID is 2093
2019-05-21T14:23:45.133Z,1558448625.133 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2019-05-21T14:23:45.133Z,1558448625.133 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-05-21T14:23:45.133Z,1558448625.133 [NavChartDb](INFO): Join timeout helper Thread ID is 2094
2019-05-21T14:23:45.289Z,1558448625.289 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-21T14:23:45.289Z,1558448625.289 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-05-21T14:23:45.309Z,1558448625.309 [ComponentRegistry](INFO): Shutting down WetLabsSeaOWL_UV_A ThreadHandler
2019-05-21T14:23:45.309Z,1558448625.309 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2019-05-21T14:23:45.309Z,1558448625.309 [WetLabsSeaOWL_UV_A](INFO): Join timeout helper Thread ID is 2095
2019-05-21T14:23:45.465Z,1558448625.465 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-21T14:23:45.465Z,1558448625.465 [WetLabsSeaOWL_UV_A](INFO): Powering down
2019-05-21T14:23:45.466Z,1558448625.466 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2019-05-21T14:23:45.473Z,1558448625.473 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2019-05-21T14:23:45.473Z,1558448625.473 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-05-21T14:23:45.473Z,1558448625.473 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 2096
2019-05-21T14:23:45.494Z,1558448625.494 [Micromodem](INFO): Starting
2019-05-21T14:23:45.509Z,1558448625.509 [NAL9602](DEBUG): Fix Requested
2019-05-21T14:23:45.629Z,1558448625.629 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-21T14:23:45.629Z,1558448625.629 [CTD_NeilBrown](INFO): Powering down
2019-05-21T14:23:45.641Z,1558448625.641 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-05-21T14:23:45.661Z,1558448625.661 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2019-05-21T14:23:45.661Z,1558448625.661 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-05-21T14:23:45.661Z,1558448625.661 [Radio_Surface](INFO): Join timeout helper Thread ID is 2097
2019-05-21T14:23:45.789Z,1558448625.789 [Radio_Surface](INFO): Powering down
2019-05-21T14:23:45.790Z,1558448625.790 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-21T14:23:45.790Z,1558448625.790 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-05-21T14:23:45.802Z,1558448625.802 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2019-05-21T14:23:45.802Z,1558448625.802 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-05-21T14:23:45.802Z,1558448625.802 [DataOverHttps](INFO): Join timeout helper Thread ID is 2098
2019-05-21T14:23:45.825Z,1558448625.825 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-21T14:23:45.825Z,1558448625.825 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-05-21T14:23:45.841Z,1558448625.841 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2019-05-21T14:23:45.842Z,1558448625.842 [logger ThreadHandler](INFO): Thread cancelled.
2019-05-21T14:23:45.842Z,1558448625.842 [logger](INFO): Join timeout helper Thread ID is 2099
2019-05-21T14:23:45.881Z,1558448625.881 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-21T14:23:45.881Z,1558448625.881 [logger ThreadHandler](INFO): Thread cancelled.
2019-05-21T14:23:45.898Z,1558448625.898 [Micromodem](INFO): Starting
2019-05-21T14:23:45.902Z,1558448625.902 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2019-05-21T14:23:45.902Z,1558448625.902 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-05-21T14:23:45.902Z,1558448625.902 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2019-05-21T14:23:45.902Z,1558448625.902 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-05-21T14:23:45.902Z,1558448625.902 [controlThread](INFO): Join timeout helper Thread ID is 2100
2019-05-21T14:23:45.964Z,1558448625.964 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-21T14:23:45.964Z,1558448625.964 [controlThread](DEBUG): Uninitializing ControlThread
2019-05-21T14:23:45.964Z,1558448625.964 [AHRS_M2](INFO): Powering down
2019-05-21T14:23:46.037Z,1558448626.037 [DUSBL_Hydroid](INFO): Powering down
2019-05-21T14:23:46.137Z,1558448626.137 [Micromodem](INFO): uninitialize
2019-05-21T14:23:46.137Z,1558448626.137 [Micromodem](INFO): Powering down
2019-05-21T14:23:46.233Z,1558448626.233 [NAL9602](INFO): Powering down
2019-05-21T14:23:46.305Z,1558448626.305 [RDI_Pathfinder](INFO): Powering down
2019-05-21T14:23:46.307Z,1558448626.307 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2019-05-21T14:23:46.307Z,1558448626.307 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2019-05-21T14:23:46.308Z,1558448626.308 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2019-05-21T14:23:46.308Z,1558448626.308 [MissionManager](INFO): Uninitializing Mission Default
2019-05-21T14:23:46.311Z,1558448626.311 [MissionManager](INFO): Uninitializing Mission Startup
2019-05-21T14:23:46.311Z,1558448626.311 [Startup] Stopped
2019-05-21T14:23:46.311Z,1558448626.311 [Startup](DEBUG): Aggregate::uninitialize Startup
2019-05-21T14:23:46.311Z,1558448626.311 [Startup:A.GoToSurface] Stopped
2019-05-21T14:23:46.311Z,1558448626.311 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-05-21T14:23:46.311Z,1558448626.311 [Startup:StartupSatComms] Stopped
2019-05-21T14:23:46.311Z,1558448626.311 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2019-05-21T14:23:46.311Z,1558448626.311 [Startup:StartupSatComms:A] Stopped
2019-05-21T14:23:46.312Z,1558448626.312 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2019-05-21T14:23:46.313Z,1558448626.313 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2019-05-21T14:23:46.313Z,1558448626.313 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2019-05-21T14:23:46.313Z,1558448626.313 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2019-05-21T14:23:46.314Z,1558448626.314 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2019-05-21T14:23:46.314Z,1558448626.314 [BuoyancyServo](INFO): Powering down
2019-05-21T14:23:46.325Z,1558448626.325 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2019-05-21T14:23:46.325Z,1558448626.325 [ElevatorServo](INFO): Powering down
2019-05-21T14:23:46.326Z,1558448626.326 [MassServo](DEBUG): Uninitialize Mass Servo.
2019-05-21T14:23:46.326Z,1558448626.326 [MassServo](INFO): Powering down
2019-05-21T14:23:46.327Z,1558448626.327 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-05-21T14:23:46.327Z,1558448626.327 [RudderServo](INFO): Powering down
2019-05-21T14:23:46.327Z,1558448626.327 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2019-05-21T14:23:46.328Z,1558448626.328 [ThrusterServo](INFO): Powering down
2019-05-21T14:23:46.328Z,1558448626.328 [SBIT](DEBUG): Uninitialize SBIT Component.
2019-05-21T14:23:46.329Z,1558448626.329 [IBIT](DEBUG): Uninitialize IBIT Component.
2019-05-21T14:23:46.329Z,1558448626.329 [CBIT](DEBUG): Uninitialize CBIT Component.
2019-05-21T14:23:46.329Z,1558448626.329 [CBIT](DEBUG): Powering off loads.
2019-05-21T14:23:46.341Z,1558448626.341 [CBIT](DEBUG): Disabling WDT.
2019-05-21T14:23:46.353Z,1558448626.353 [CBIT](DEBUG): Opening all GF detection circuits.
2019-05-21T14:23:46.354Z,1558448626.354 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-05-21T14:23:46.401Z,1558448626.401 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-05-21T14:23:46.410Z,1558448626.410 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-05-21T14:23:46.449Z,1558448626.449 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2019-05-21T14:23:46.452Z,1558448626.452 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-05-21T14:23:46.506Z,1558448626.506 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-05-21T14:23:46.562Z,1558448626.562 [logger ThreadHandler](INFO): Thread cancelled.