2019-03-08T21:49:01.351Z,1552081741.351 [Supervisor](DEBUG): Initializing supervisor.
2019-03-08T21:49:01.353Z,1552081741.353 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2019-03-08T21:49:01.354Z,1552081741.354 [SyncHandler](INFO): Protected caller Thread ID is 6568
2019-03-08T21:49:01.354Z,1552081741.354 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2019-03-08T21:49:01.355Z,1552081741.355 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2019-03-08T21:49:01.356Z,1552081741.356 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 6569
2019-03-08T21:49:01.358Z,1552081741.358 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2019-03-08T21:49:01.370Z,1552081741.370 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2019-03-08T21:49:01.371Z,1552081741.371 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2019-03-08T21:49:01.371Z,1552081741.371 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 6570
2019-03-08T21:49:01.372Z,1552081741.372 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2019-03-08T21:49:01.373Z,1552081741.373 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2019-03-08T21:49:01.373Z,1552081741.373 [logger ThreadHandler](INFO): Protected caller Thread ID is 6571
2019-03-08T21:49:01.375Z,1552081741.375 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2019-03-08T21:49:01.376Z,1552081741.376 [Supervisor](INFO): Looking for Config files in directory: Config/
2019-03-08T21:49:01.377Z,1552081741.377 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2019-03-08T21:49:01.814Z,1552081741.814 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2019-03-08T21:49:01.815Z,1552081741.815 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2019-03-08T21:49:01.913Z,1552081741.913 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2019-03-08T21:49:01.914Z,1552081741.914 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2019-03-08T21:49:02.251Z,1552081742.251 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2019-03-08T21:49:02.252Z,1552081742.252 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2019-03-08T21:49:02.396Z,1552081742.396 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2019-03-08T21:49:02.397Z,1552081742.397 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2019-03-08T21:49:02.598Z,1552081742.598 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2019-03-08T21:49:02.599Z,1552081742.599 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2019-03-08T21:49:03.201Z,1552081743.201 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2019-03-08T21:49:03.202Z,1552081743.202 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2019-03-08T21:49:03.418Z,1552081743.418 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2019-03-08T21:49:03.419Z,1552081743.419 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2019-03-08T21:49:03.571Z,1552081743.571 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2019-03-08T21:49:03.571Z,1552081743.571 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2019-03-08T21:49:03.773Z,1552081743.773 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2019-03-08T21:49:03.773Z,1552081743.773 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2019-03-08T21:49:03.870Z,1552081743.870 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2019-03-08T21:49:03.870Z,1552081743.870 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2019-03-08T21:49:04.189Z,1552081744.189 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2019-03-08T21:49:04.189Z,1552081744.189 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2019-03-08T21:49:04.269Z,1552081744.269 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2019-03-08T21:49:04.373Z,1552081744.373 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2019-03-08T21:49:04.374Z,1552081744.374 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2019-03-08T21:49:04.886Z,1552081744.886 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2019-03-08T21:49:04.887Z,1552081744.887 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2019-03-08T21:49:05.291Z,1552081745.291 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2019-03-08T21:49:05.293Z,1552081745.293 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/
2019-03-08T21:49:05.294Z,1552081745.294 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/vehicle.cfg
2019-03-08T21:49:05.508Z,1552081745.508 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Control.cfg
2019-03-08T21:49:05.609Z,1552081745.609 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/BIT.cfg
2019-03-08T21:49:05.708Z,1552081745.708 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Battery.cfg
2019-03-08T21:49:05.941Z,1552081745.941 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2019-03-08T21:49:05.942Z,1552081745.942 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Simulator.cfg
2019-03-08T21:49:06.026Z,1552081746.026 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Navigation.cfg
2019-03-08T21:49:06.120Z,1552081746.120 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/logger.cfg
2019-03-08T21:49:06.218Z,1552081746.218 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/secure.cfg
2019-03-08T21:49:06.300Z,1552081746.300 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Servo.cfg
2019-03-08T21:49:06.410Z,1552081746.410 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Sensor.cfg
2019-03-08T21:49:06.587Z,1552081746.587 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Science.cfg
2019-03-08T21:49:06.721Z,1552081746.721 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2019-03-08T21:49:06.724Z,1552081746.724 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2019-03-08T21:49:07.049Z,1552081747.049 [DataOverHttps] Loaded
2019-03-08T21:49:07.049Z,1552081747.049 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2019-03-08T21:49:07.050Z,1552081747.050 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4074D4E0
2019-03-08T21:49:07.051Z,1552081747.051 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 6650
2019-03-08T21:49:07.089Z,1552081747.089 [Depth_Keller] Loaded
2019-03-08T21:49:07.089Z,1552081747.089 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2019-03-08T21:49:07.094Z,1552081747.094 [DropWeight] Loaded
2019-03-08T21:49:07.094Z,1552081747.094 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2019-03-08T21:49:07.144Z,1552081747.144 [DUSBL_Hydroid] Loaded
2019-03-08T21:49:07.144Z,1552081747.144 [ComponentRegistry](DEBUG): SyncComponent "DUSBL_Hydroid" handled in the control thread.
2019-03-08T21:49:07.186Z,1552081747.186 [Micromodem] Loaded
2019-03-08T21:49:07.187Z,1552081747.187 [ComponentRegistry](DEBUG): SyncComponent "Micromodem" handled in the control thread.
2019-03-08T21:49:07.286Z,1552081747.286 [NAL9602] Loaded
2019-03-08T21:49:07.287Z,1552081747.287 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2019-03-08T21:49:07.303Z,1552081747.303 [Onboard] Loaded
2019-03-08T21:49:07.303Z,1552081747.303 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2019-03-08T21:49:07.310Z,1552081747.310 [Radio_Surface] Loaded
2019-03-08T21:49:07.310Z,1552081747.310 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2019-03-08T21:49:07.311Z,1552081747.311 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4077D4E0
2019-03-08T21:49:07.311Z,1552081747.311 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 6651
2019-03-08T21:49:07.357Z,1552081747.357 [RDI_Pathfinder] Loaded
2019-03-08T21:49:07.358Z,1552081747.358 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2019-03-08T21:49:07.380Z,1552081747.380 [RDI_PathfinderUp] Loaded
2019-03-08T21:49:07.380Z,1552081747.380 [ComponentRegistry](DEBUG): SyncComponent "RDI_PathfinderUp" handled in the control thread.
2019-03-08T21:49:09.672Z,1552081749.672 [BPC1] Loaded
2019-03-08T21:49:09.672Z,1552081749.672 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2019-03-08T21:49:09.673Z,1552081749.673 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2019-03-08T21:49:09.673Z,1552081749.673 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2019-03-08T21:49:09.687Z,1552081749.687 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2019-03-08T21:49:09.687Z,1552081749.687 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2019-03-08T21:49:09.797Z,1552081749.797 [DeadReckonUsingMultipleVelocitySources] Loaded
2019-03-08T21:49:09.797Z,1552081749.797 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2019-03-08T21:49:09.858Z,1552081749.858 [DeadReckonUsingSpeedCalculator] Loaded
2019-03-08T21:49:09.858Z,1552081749.858 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2019-03-08T21:49:09.919Z,1552081749.919 [DeadReckonWithRespectToSeafloor] Loaded
2019-03-08T21:49:09.919Z,1552081749.919 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonWithRespectToSeafloor" handled in the control thread.
2019-03-08T21:49:09.940Z,1552081749.940 [NavChart] Loaded
2019-03-08T21:49:09.940Z,1552081749.940 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2019-03-08T21:49:09.944Z,1552081749.944 [UniversalFixResidualReporter] Loaded
2019-03-08T21:49:09.945Z,1552081749.945 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2019-03-08T21:49:09.945Z,1552081749.945 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2019-03-08T21:49:09.946Z,1552081749.946 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2019-03-08T21:49:10.052Z,1552081750.052 [BuoyancyServo] Loaded
2019-03-08T21:49:10.052Z,1552081750.052 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2019-03-08T21:49:10.068Z,1552081750.068 [ElevatorServo] Loaded
2019-03-08T21:49:10.068Z,1552081750.068 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2019-03-08T21:49:10.083Z,1552081750.083 [MassServo] Loaded
2019-03-08T21:49:10.083Z,1552081750.083 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2019-03-08T21:49:10.099Z,1552081750.099 [RudderServo] Loaded
2019-03-08T21:49:10.099Z,1552081750.099 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2019-03-08T21:49:10.113Z,1552081750.113 [ThrusterServo] Loaded
2019-03-08T21:49:10.114Z,1552081750.114 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2019-03-08T21:49:10.114Z,1552081750.114 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2019-03-08T21:49:10.115Z,1552081750.115 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2019-03-08T21:49:10.306Z,1552081750.306 [Aanderaa_O2] Loaded
2019-03-08T21:49:10.307Z,1552081750.307 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2019-03-08T21:49:10.395Z,1552081750.395 [CTD_NeilBrown] Loaded
2019-03-08T21:49:10.396Z,1552081750.396 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2019-03-08T21:49:10.397Z,1552081750.397 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 408C24E0
2019-03-08T21:49:10.397Z,1552081750.397 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 6652
2019-03-08T21:49:10.443Z,1552081750.443 [WetLabsSeaOWL_UV_A] Loaded
2019-03-08T21:49:10.443Z,1552081750.443 [ComponentRegistry](DEBUG): Component "WetLabsSeaOWL_UV_A" handled in its own thread.
2019-03-08T21:49:10.444Z,1552081750.444 [WetLabsSeaOWL_UV_A ThreadHandler](DEBUG): Created PCaller Thread at 408F24E0
2019-03-08T21:49:10.444Z,1552081750.444 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Protected caller Thread ID is 6653
2019-03-08T21:49:10.445Z,1552081750.445 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2019-03-08T21:49:10.446Z,1552081750.446 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2019-03-08T21:49:10.700Z,1552081750.700 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2019-03-08T21:49:10.701Z,1552081750.701 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2019-03-08T21:49:10.745Z,1552081750.745 [DepthRateCalculator] Loaded
2019-03-08T21:49:10.745Z,1552081750.745 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2019-03-08T21:49:10.751Z,1552081750.751 [PitchRateCalculator] Loaded
2019-03-08T21:49:10.751Z,1552081750.751 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2019-03-08T21:49:10.764Z,1552081750.764 [SpeedCalculator] Loaded
2019-03-08T21:49:10.764Z,1552081750.764 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2019-03-08T21:49:10.785Z,1552081750.785 [TempGradientCalculator] Loaded
2019-03-08T21:49:10.786Z,1552081750.786 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2019-03-08T21:49:10.791Z,1552081750.791 [YawRateCalculator] Loaded
2019-03-08T21:49:10.792Z,1552081750.792 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2019-03-08T21:49:10.833Z,1552081750.833 [ElevatorOffsetCalculator] Loaded
2019-03-08T21:49:10.834Z,1552081750.834 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2019-03-08T21:49:10.834Z,1552081750.834 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2019-03-08T21:49:10.835Z,1552081750.835 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2019-03-08T21:49:10.977Z,1552081750.977 [SBIT](DEBUG): Construct Startup Built In Test.
2019-03-08T21:49:11.000Z,1552081751.000 [SBIT] Loaded
2019-03-08T21:49:11.001Z,1552081751.001 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2019-03-08T21:49:11.001Z,1552081751.001 [IBIT](DEBUG): Construct Initiated Built In Test.
2019-03-08T21:49:11.013Z,1552081751.013 [IBIT] Loaded
2019-03-08T21:49:11.013Z,1552081751.013 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2019-03-08T21:49:11.016Z,1552081751.016 [CBIT](DEBUG): Construct Continuous Built In Test.
2019-03-08T21:49:11.157Z,1552081751.157 [CBIT] Loaded
2019-03-08T21:49:11.157Z,1552081751.157 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2019-03-08T21:49:11.158Z,1552081751.158 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2019-03-08T21:49:11.158Z,1552081751.158 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2019-03-08T21:49:11.224Z,1552081751.224 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2019-03-08T21:49:11.225Z,1552081751.225 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2019-03-08T21:49:11.329Z,1552081751.329 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2019-03-08T21:49:11.329Z,1552081751.329 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2019-03-08T21:49:11.401Z,1552081751.401 [VerticalControl](DEBUG): Construct VerticalControl.
2019-03-08T21:49:11.486Z,1552081751.486 [VerticalControl] Loaded
2019-03-08T21:49:11.486Z,1552081751.486 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2019-03-08T21:49:11.487Z,1552081751.487 [HorizontalControl](DEBUG): Construct HorizontalControl.
2019-03-08T21:49:11.545Z,1552081751.545 [HorizontalControl] Loaded
2019-03-08T21:49:11.545Z,1552081751.545 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2019-03-08T21:49:11.546Z,1552081751.546 [SpeedControl](DEBUG): Construct SpeedControl.
2019-03-08T21:49:11.548Z,1552081751.548 [SpeedControl] Loaded
2019-03-08T21:49:11.548Z,1552081751.548 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2019-03-08T21:49:11.549Z,1552081751.549 [LoopControl](DEBUG): Construct LoopControl.
2019-03-08T21:49:11.549Z,1552081751.549 [LoopControl] Loaded
2019-03-08T21:49:11.550Z,1552081751.550 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2019-03-08T21:49:11.550Z,1552081751.550 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2019-03-08T21:49:11.550Z,1552081751.550 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2019-03-08T21:49:11.579Z,1552081751.579 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2019-03-08T21:49:11.583Z,1552081751.583 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2019-03-08T21:49:11.584Z,1552081751.584 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2019-03-08T21:49:11.590Z,1552081751.590 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2019-03-08T21:49:11.591Z,1552081751.591 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40AB04E0
2019-03-08T21:49:11.592Z,1552081751.592 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 6654
2019-03-08T21:49:11.596Z,1552081751.596 [Supervisor](INFO): Main Thread ID is 5883
2019-03-08T21:49:11.596Z,1552081751.596 [Supervisor](DEBUG): Running supervisor.
2019-03-08T21:49:11.597Z,1552081751.597 [CommandLine ThreadHandler](INFO): Handler Thread ID is 6655
2019-03-08T21:49:11.599Z,1552081751.599 [controlThread ThreadHandler](INFO): Handler Thread ID is 6656
2019-03-08T21:49:11.600Z,1552081751.600 [controlThread](DEBUG): Initializing ControlThread
2019-03-08T21:49:11.609Z,1552081751.609 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2019-03-08T21:49:11.610Z,1552081751.610 [NavChart](DEBUG): Initialize NavChart Navigation.
2019-03-08T21:49:11.610Z,1552081751.610 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2019-03-08T21:49:11.611Z,1552081751.611 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2019-03-08T21:49:11.611Z,1552081751.611 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2019-03-08T21:49:11.612Z,1552081751.612 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2019-03-08T21:49:11.612Z,1552081751.612 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2019-03-08T21:49:11.613Z,1552081751.613 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2019-03-08T21:49:11.613Z,1552081751.613 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2019-03-08T21:49:11.614Z,1552081751.614 [SBIT](INFO): Initialize SBIT Component.
2019-03-08T21:49:11.614Z,1552081751.614 [SBIT](IMPORTANT): git: 2019-03-04-36-g743def3
2019-03-08T21:49:11.614Z,1552081751.614 [SBIT](INFO): git hash: 743def31acf12ef8e20e672f0fefb031590b97fa
2019-03-08T21:49:11.615Z,1552081751.615 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2019-03-08T21:49:11.615Z,1552081751.615 [SBIT](IMPORTANT): Kernel Version:#2 PREEMPT Thu Jan 11 20:13:48 PST 2018
2019-03-08T21:49:11.616Z,1552081751.616 [SBIT](INFO): Beginning SBIT in 28.000000 seconds.
2019-03-08T21:49:11.616Z,1552081751.616 [IBIT](INFO): Initialize IBIT Component.
2019-03-08T21:49:11.617Z,1552081751.617 [CBIT](DEBUG): Initialize CBIT Component.
2019-03-08T21:49:11.618Z,1552081751.618 [logger ThreadHandler](INFO): Handler Thread ID is 6657
2019-03-08T21:49:11.629Z,1552081751.629 [CBIT](DEBUG): Initialized mux pins.
2019-03-08T21:49:11.629Z,1552081751.629 [CBIT](DEBUG): Initializing the watchdog timer.
2019-03-08T21:49:11.637Z,1552081751.637 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 6658
2019-03-08T21:49:11.638Z,1552081751.638 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2019-03-08T21:49:11.649Z,1552081751.649 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 6659
2019-03-08T21:49:11.653Z,1552081751.653 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2019-03-08T21:49:11.653Z,1552081751.653 [CBIT](DEBUG): Initializing heartbeat.
2019-03-08T21:49:11.669Z,1552081751.669 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 6660
2019-03-08T21:49:11.670Z,1552081751.670 [CTD_NeilBrown](INFO): Powering down
2019-03-08T21:49:11.709Z,1552081751.709 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Handler Thread ID is 6661
2019-03-08T21:49:11.710Z,1552081751.710 [WetLabsSeaOWL_UV_A](INFO): Powering down
2019-03-08T21:49:11.725Z,1552081751.725 [CBIT](DEBUG): Deactivating GF circuits.
2019-03-08T21:49:11.725Z,1552081751.725 [CBIT](DEBUG): Deactivating emergency mode.
2019-03-08T21:49:11.729Z,1552081751.729 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 6662
2019-03-08T21:49:11.732Z,1552081751.732 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2019-03-08T21:49:11.732Z,1552081751.732 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2019-03-08T21:49:11.733Z,1552081751.733 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2019-03-08T21:49:11.733Z,1552081751.733 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2019-03-08T21:49:11.733Z,1552081751.733 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2019-03-08T21:49:11.733Z,1552081751.733 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2019-03-08T21:49:11.733Z,1552081751.733 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2019-03-08T21:49:11.734Z,1552081751.734 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2019-03-08T21:49:11.734Z,1552081751.734 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2019-03-08T21:49:11.734Z,1552081751.734 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2019-03-08T21:49:11.734Z,1552081751.734 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2019-03-08T21:49:11.734Z,1552081751.734 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2019-03-08T21:49:11.735Z,1552081751.735 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2019-03-08T21:49:11.735Z,1552081751.735 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2019-03-08T21:49:11.735Z,1552081751.735 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2019-03-08T21:49:11.735Z,1552081751.735 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2019-03-08T21:49:11.761Z,1552081751.761 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2019-03-08T21:49:11.763Z,1552081751.763 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2019-03-08T21:49:11.763Z,1552081751.763 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2019-03-08T21:49:11.764Z,1552081751.764 [LoopControl](DEBUG): Initialize LoopControlComponent.
2019-03-08T21:49:11.765Z,1552081751.765 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2019-03-08T21:49:11.775Z,1552081751.775 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2019-03-08T21:49:11.798Z,1552081751.798 [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-03-08T21:49:11.805Z,1552081751.805 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2019-03-08T21:49:11.860Z,1552081751.860 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2019-03-08T21:49:11.873Z,1552081751.873 [Default:A.Wait](DEBUG): Construct Wait.
2019-03-08T21:49:11.875Z,1552081751.875 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2019-03-08T21:49:11.894Z,1552081751.894 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2019-03-08T21:49:11.896Z,1552081751.896 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2019-03-08T21:49:11.926Z,1552081751.926 [Default:E.Execute](DEBUG): Construct Execute.
2019-03-08T21:49:11.939Z,1552081751.939 [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-03-08T21:49:11.948Z,1552081751.948 [controlThread](DEBUG): Component order: CycleStarter,Depth_Keller,DropWeight,DUSBL_Hydroid,Micromodem,NAL9602,Onboard,RDI_Pathfinder,RDI_PathfinderUp,BPC1,Aanderaa_O2,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,DeadReckonUsingSpeedCalculator,DeadReckonWithRespectToSeafloor,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2019-03-08T21:49:11.994Z,1552081751.994 [Depth_Keller](ERROR): Pressure reading out of range: 1913.424561 decibar
2019-03-08T21:49:11.994Z,1552081751.994 [DUSBL_Hydroid](INFO): Powering up
2019-03-08T21:49:11.995Z,1552081751.995 [DUSBL_Hydroid](DEBUG): Initializing DUSBL_Hydroid.
2019-03-08T21:49:12.013Z,1552081752.013 [Micromodem](INFO): Start
2019-03-08T21:49:12.053Z,1552081752.053 [Radio_Surface](INFO): Powering up
2019-03-08T21:49:12.069Z,1552081752.069 [DepthRateCalculator](ERROR): Depth measurement is not active
2019-03-08T21:49:12.109Z,1552081752.109 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2019-03-08T21:49:12.118Z,1552081752.118 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2019-03-08T21:49:12.119Z,1552081752.119 [ElevatorServo](DEBUG): Initializing EZServoServo.
2019-03-08T21:49:12.125Z,1552081752.125 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2019-03-08T21:49:12.126Z,1552081752.126 [MassServo](DEBUG): Initializing EZServoServo.
2019-03-08T21:49:12.133Z,1552081752.133 [MassServo](DEBUG): Initializing MassServo.
2019-03-08T21:49:12.134Z,1552081752.134 [RudderServo](DEBUG): Initializing EZServoServo.
2019-03-08T21:49:12.141Z,1552081752.141 [RudderServo](DEBUG): Initializing RudderServo.
2019-03-08T21:49:12.142Z,1552081752.142 [ThrusterServo](DEBUG): Initializing EZServoServo.
2019-03-08T21:49:12.149Z,1552081752.149 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2019-03-08T21:49:12.370Z,1552081752.370 [Micromodem](INFO): Starting
2019-03-08T21:49:12.371Z,1552081752.371 [Micromodem](INFO): Powering up
2019-03-08T21:49:12.371Z,1552081752.371 [Micromodem](DEBUG): Initializing Micromodem.
2019-03-08T21:49:12.473Z,1552081752.473 [RDI_PathfinderUp](INFO): Powering down
2019-03-08T21:49:12.545Z,1552081752.545 [DepthRateCalculator](ERROR): Depth measurement is not active
2019-03-08T21:49:12.762Z,1552081752.762 [Micromodem](INFO): Starting
2019-03-08T21:49:12.781Z,1552081752.781 [DepthRateCalculator](ERROR): Depth measurement is not active
2019-03-08T21:49:13.097Z,1552081753.097 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2019-03-08T21:49:13.097Z,1552081753.097 [RudderServo](FAULT): Rudder failed to initialize
2019-03-08T21:49:13.097Z,1552081753.097 [RudderServo] Communications Fault, FailCount= 1
2019-03-08T21:49:13.097Z,1552081753.097 [RudderServo](ERROR): Communications Fault
2019-03-08T21:49:13.208Z,1552081753.208 [CBIT](ERROR): Communications Fault in component: RudderServo
2019-03-08T21:49:13.219Z,1552081753.219 [Micromodem](INFO): Starting
2019-03-08T21:49:13.394Z,1552081753.394 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-03-08T21:49:13.394Z,1552081753.394 [RudderServo](INFO): Powering down
2019-03-08T21:49:13.622Z,1552081753.622 [Micromodem](INFO): Starting
2019-03-08T21:49:14.026Z,1552081754.026 [Micromodem](INFO): Starting
2019-03-08T21:49:14.054Z,1552081754.054 [RudderServo](DEBUG): Initializing EZServoServo.
2019-03-08T21:49:14.174Z,1552081754.174 [RudderServo](DEBUG): Initializing RudderServo.
2019-03-08T21:49:14.178Z,1552081754.178 [CBIT](INFO): Clearing failed state for component RudderServo
2019-03-08T21:49:14.178Z,1552081754.178 [RudderServo] No Fault, FailCount= 1
2019-03-08T21:49:14.430Z,1552081754.430 [Micromodem](INFO): Starting
2019-03-08T21:49:14.834Z,1552081754.834 [Micromodem](INFO): Starting
2019-03-08T21:49:15.239Z,1552081755.239 [Micromodem](INFO): Starting
2019-03-08T21:49:15.377Z,1552081755.377 [Aanderaa_O2](INFO): Powering down
2019-03-08T21:49:15.642Z,1552081755.642 [Micromodem](INFO): Starting
2019-03-08T21:49:16.046Z,1552081756.046 [Micromodem](INFO): Starting
2019-03-08T21:49:16.450Z,1552081756.450 [Micromodem](INFO): Starting
2019-03-08T21:49:16.854Z,1552081756.854 [Micromodem](INFO): Starting
2019-03-08T21:49:17.258Z,1552081757.258 [Micromodem](INFO): Starting
2019-03-08T21:49:17.259Z,1552081757.259 [Micromodem](INFO): Starting
2019-03-08T21:49:17.259Z,1552081757.259 [Micromodem](DEBUG): Nmea buf: $CCCFG,CST,1*37

2019-03-08T21:49:17.259Z,1552081757.259 [Micromodem](IMPORTANT): Nmea buf: $CCCFG,CST,1*37

2019-03-08T21:49:17.259Z,1552081757.259 [Micromodem](INFO): Nmea out: $CCCFG,CST,1*37

2019-03-08T21:49:17.260Z,1552081757.260 [Micromodem](DEBUG): Nmea buf: $CCCFG,SRC,1*31

2019-03-08T21:49:17.260Z,1552081757.260 [Micromodem](IMPORTANT): Nmea buf: $CCCFG,SRC,1*31

2019-03-08T21:49:17.260Z,1552081757.260 [Micromodem](DEBUG): Nmea buf: $CCCFG,REV,1*32

2019-03-08T21:49:17.260Z,1552081757.260 [Micromodem](IMPORTANT): Nmea buf: $CCCFG,REV,1*32

2019-03-08T21:49:17.260Z,1552081757.260 [Micromodem](DEBUG): Nmea buf: $CCCFG,RXP,1*29

2019-03-08T21:49:17.262Z,1552081757.262 [Micromodem](IMPORTANT): Nmea buf: $CCCFG,RXP,1*29

2019-03-08T21:49:17.662Z,1552081757.662 [Micromodem](INFO): Starting
2019-03-08T21:49:18.115Z,1552081758.115 [Micromodem](INFO): Starting
2019-03-08T21:49:18.514Z,1552081758.514 [Micromodem](INFO): Starting
2019-03-08T21:49:18.919Z,1552081758.919 [Micromodem](INFO): Starting
2019-03-08T21:49:19.334Z,1552081759.334 [Micromodem](INFO): Starting
2019-03-08T21:49:19.727Z,1552081759.727 [Micromodem](INFO): Starting
2019-03-08T21:49:20.131Z,1552081760.131 [Micromodem](INFO): Starting
2019-03-08T21:49:20.543Z,1552081760.543 [Micromodem](INFO): Starting
2019-03-08T21:49:20.939Z,1552081760.939 [Micromodem](INFO): Starting
2019-03-08T21:49:21.343Z,1552081761.343 [Micromodem](INFO): Starting
2019-03-08T21:49:21.747Z,1552081761.747 [Micromodem](INFO): Starting
2019-03-08T21:49:22.158Z,1552081762.158 [Micromodem](INFO): Starting
2019-03-08T21:49:22.555Z,1552081762.555 [Micromodem](INFO): Starting
2019-03-08T21:49:22.959Z,1552081762.959 [Micromodem](INFO): Starting
2019-03-08T21:49:23.363Z,1552081763.363 [Micromodem](INFO): Starting
2019-03-08T21:49:23.767Z,1552081763.767 [Micromodem](INFO): Starting
2019-03-08T21:49:24.171Z,1552081764.171 [Micromodem](INFO): Starting
2019-03-08T21:49:24.575Z,1552081764.575 [Micromodem](INFO): Starting
2019-03-08T21:49:24.979Z,1552081764.979 [Micromodem](INFO): Starting
2019-03-08T21:49:25.383Z,1552081765.383 [Micromodem](INFO): Starting
2019-03-08T21:49:25.409Z,1552081765.409 [RDI_Pathfinder](ERROR): Failed to parse:Pathfinder
2019-03-08T21:49:25.787Z,1552081765.787 [Micromodem](INFO): Starting
2019-03-08T21:49:26.198Z,1552081766.198 [Micromodem](INFO): Starting
2019-03-08T21:49:26.595Z,1552081766.595 [Micromodem](INFO): Starting
2019-03-08T21:49:26.999Z,1552081766.999 [Micromodem](INFO): Starting
2019-03-08T21:49:27.403Z,1552081767.403 [Micromodem](INFO): Starting
2019-03-08T21:49:27.807Z,1552081767.807 [Micromodem](INFO): Starting
2019-03-08T21:49:28.211Z,1552081768.211 [Micromodem](INFO): Starting
2019-03-08T21:49:28.623Z,1552081768.623 [Micromodem](INFO): Starting
2019-03-08T21:49:28.624Z,1552081768.624 [Micromodem](ERROR): Nmea resend: $CCCFG,CST,1*37

2019-03-08T21:49:29.020Z,1552081769.020 [Micromodem](INFO): Starting
2019-03-08T21:49:29.424Z,1552081769.424 [Micromodem](INFO): Starting
2019-03-08T21:49:29.827Z,1552081769.827 [DUSBL_Hydroid](INFO): DUSBL Version:O
2019-03-08T21:49:29.841Z,1552081769.841 [Micromodem](INFO): Starting
2019-03-08T21:49:30.231Z,1552081770.231 [Micromodem](INFO): Starting
2019-03-08T21:49:30.642Z,1552081770.642 [Micromodem](INFO): Starting
2019-03-08T21:49:31.039Z,1552081771.039 [Micromodem](INFO): Starting
2019-03-08T21:49:31.443Z,1552081771.443 [Micromodem](INFO): Starting
2019-03-08T21:49:31.847Z,1552081771.847 [Micromodem](INFO): Starting
2019-03-08T21:49:32.251Z,1552081772.251 [Micromodem](INFO): Starting
2019-03-08T21:49:32.658Z,1552081772.658 [Micromodem](INFO): Starting
2019-03-08T21:49:33.059Z,1552081773.059 [Micromodem](INFO): Starting
2019-03-08T21:49:33.463Z,1552081773.463 [Micromodem](INFO): Starting
2019-03-08T21:49:33.867Z,1552081773.867 [Micromodem](INFO): Starting
2019-03-08T21:49:34.271Z,1552081774.271 [Micromodem](INFO): Starting
2019-03-08T21:49:34.679Z,1552081774.679 [Micromodem](INFO): Starting
2019-03-08T21:49:35.079Z,1552081775.079 [Micromodem](INFO): Starting
2019-03-08T21:49:35.483Z,1552081775.483 [Micromodem](INFO): Starting
2019-03-08T21:49:35.884Z,1552081775.884 [Micromodem](INFO): Starting
2019-03-08T21:49:36.291Z,1552081776.291 [Micromodem](INFO): Starting
2019-03-08T21:49:36.695Z,1552081776.695 [Micromodem](INFO): Starting
2019-03-08T21:49:37.095Z,1552081777.095 [Micromodem](INFO): Starting
2019-03-08T21:49:37.503Z,1552081777.503 [Micromodem](INFO): Starting
2019-03-08T21:49:37.504Z,1552081777.504 [NAL9602](INFO): Powering up NAL9602
2019-03-08T21:49:37.907Z,1552081777.907 [Micromodem](INFO): Starting
2019-03-08T21:49:38.311Z,1552081778.311 [Micromodem](INFO): Starting
2019-03-08T21:49:38.715Z,1552081778.715 [Micromodem](INFO): Starting
2019-03-08T21:49:38.716Z,1552081778.716 [Micromodem](IMPORTANT): CACFG stsring$CACFG,CST,1*35

2019-03-08T21:49:38.716Z,1552081778.716 [Micromodem](INFO): Nmea out: $CCCFG,SRC,1*31

2019-03-08T21:49:39.126Z,1552081779.126 [Micromodem](INFO): Starting
2019-03-08T21:49:39.524Z,1552081779.524 [Micromodem](INFO): Starting
2019-03-08T21:49:39.923Z,1552081779.923 [Micromodem](INFO): Starting
2019-03-08T21:49:40.331Z,1552081780.331 [Micromodem](INFO): Starting
2019-03-08T21:49:40.384Z,1552081780.384 [SBIT](IMPORTANT): Beginning Startup BIT
2019-03-08T21:49:40.397Z,1552081780.397 [CBIT](IMPORTANT): Beginning ground fault scan
2019-03-08T21:49:40.742Z,1552081780.742 [Micromodem](INFO): Starting
2019-03-08T21:49:41.146Z,1552081781.146 [Micromodem](INFO): Starting
2019-03-08T21:49:41.543Z,1552081781.543 [Micromodem](INFO): Starting
2019-03-08T21:49:41.947Z,1552081781.947 [Micromodem](INFO): Starting
2019-03-08T21:49:42.351Z,1552081782.351 [Micromodem](INFO): Starting
2019-03-08T21:49:42.755Z,1552081782.755 [Micromodem](INFO): Starting
2019-03-08T21:49:43.336Z,1552081783.336 [Micromodem](INFO): Starting
2019-03-08T21:49:43.738Z,1552081783.738 [Micromodem](INFO): Starting
2019-03-08T21:49:44.142Z,1552081784.142 [Micromodem](INFO): Starting
2019-03-08T21:49:44.550Z,1552081784.550 [Micromodem](INFO): Starting
2019-03-08T21:49:44.950Z,1552081784.950 [Micromodem](INFO): Starting
2019-03-08T21:49:45.354Z,1552081785.354 [Micromodem](INFO): Starting
2019-03-08T21:49:45.758Z,1552081785.758 [Micromodem](INFO): Starting
2019-03-08T21:49:46.173Z,1552081786.173 [Micromodem](INFO): Starting
2019-03-08T21:49:46.566Z,1552081786.566 [Micromodem](INFO): Starting
2019-03-08T21:49:46.970Z,1552081786.970 [Micromodem](INFO): Starting
2019-03-08T21:49:47.374Z,1552081787.374 [Micromodem](INFO): Starting
2019-03-08T21:49:47.778Z,1552081787.778 [Micromodem](INFO): Starting
2019-03-08T21:49:48.191Z,1552081788.191 [Micromodem](INFO): Starting
2019-03-08T21:49:48.586Z,1552081788.586 [Micromodem](INFO): Starting
2019-03-08T21:49:48.587Z,1552081788.587 [Micromodem](IMPORTANT): CACFG stsring$CACFG,SRC,1*33

2019-03-08T21:49:48.587Z,1552081788.587 [Micromodem](INFO): Nmea out: $CCCFG,REV,1*32

2019-03-08T21:49:48.588Z,1552081788.588 [NAL9602](INFO): NAL9602 initialized
2019-03-08T21:49:48.992Z,1552081788.992 [Micromodem](INFO): Starting
2019-03-08T21:49:49.394Z,1552081789.394 [Micromodem](INFO): Starting
2019-03-08T21:49:49.409Z,1552081789.409 [NAL9602](DEBUG): Fix Requested
2019-03-08T21:49:49.798Z,1552081789.798 [Micromodem](INFO): Starting
2019-03-08T21:49:50.202Z,1552081790.202 [Micromodem](INFO): Starting
2019-03-08T21:49:50.606Z,1552081790.606 [Micromodem](INFO): Starting
2019-03-08T21:49:51.010Z,1552081791.010 [Micromodem](INFO): Starting
2019-03-08T21:49:51.101Z,1552081791.101 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.007075
CHAN A1 (24V): -0.026080
CHAN A2 (12V): -0.007158
CHAN A3 (5V): -0.001530
CHAN B0 (3.3V): -0.000652
CHAN B1 (3.15aV): -0.000435
CHAN B2 (3.15bV): 0.000314
CHAN B3 (GND): 0.000489
OPEN: 0.009338
Full Scale Calc: 4.765 mA, -1.589 mA
2019-03-08T21:49:51.414Z,1552081791.414 [Micromodem](INFO): Starting
2019-03-08T21:49:51.818Z,1552081791.818 [Micromodem](INFO): Starting
2019-03-08T21:49:52.222Z,1552081792.222 [Micromodem](INFO): Starting
2019-03-08T21:49:52.623Z,1552081792.623 [Micromodem](INFO): Starting
2019-03-08T21:49:53.030Z,1552081793.030 [Micromodem](INFO): Starting
2019-03-08T21:49:53.434Z,1552081793.434 [Micromodem](INFO): Starting
2019-03-08T21:49:53.838Z,1552081793.838 [Micromodem](INFO): Starting
2019-03-08T21:49:54.242Z,1552081794.242 [Micromodem](INFO): Starting
2019-03-08T21:49:54.646Z,1552081794.646 [Micromodem](INFO): Starting
2019-03-08T21:49:55.047Z,1552081795.047 [Micromodem](INFO): Starting
2019-03-08T21:49:55.462Z,1552081795.462 [Micromodem](INFO): Starting
2019-03-08T21:49:55.856Z,1552081795.856 [Micromodem](INFO): Starting
2019-03-08T21:49:56.330Z,1552081796.330 [Micromodem](INFO): Starting
2019-03-08T21:49:56.734Z,1552081796.734 [Micromodem](INFO): Starting
2019-03-08T21:49:57.138Z,1552081797.138 [Micromodem](INFO): Starting
2019-03-08T21:49:57.542Z,1552081797.542 [Micromodem](INFO): Starting
2019-03-08T21:49:57.946Z,1552081797.946 [Micromodem](INFO): Starting
2019-03-08T21:49:58.358Z,1552081798.358 [Micromodem](INFO): Starting
2019-03-08T21:49:58.754Z,1552081798.754 [Micromodem](INFO): Starting
2019-03-08T21:49:58.755Z,1552081798.755 [Micromodem](IMPORTANT): CACFG stsring$CACFG,REV,1*30

2019-03-08T21:49:58.755Z,1552081798.755 [Micromodem](INFO): Nmea out: $CCCFG,RXP,1*29

2019-03-08T21:49:59.161Z,1552081799.161 [Micromodem](INFO): Starting
2019-03-08T21:49:59.562Z,1552081799.562 [Micromodem](INFO): Starting
2019-03-08T21:49:59.966Z,1552081799.966 [Micromodem](INFO): Starting
2019-03-08T21:50:00.370Z,1552081800.370 [Micromodem](INFO): Starting
2019-03-08T21:50:00.774Z,1552081800.774 [Micromodem](INFO): Starting
2019-03-08T21:50:01.184Z,1552081801.184 [Micromodem](INFO): Starting
2019-03-08T21:50:01.586Z,1552081801.586 [Micromodem](INFO): Starting
2019-03-08T21:50:01.986Z,1552081801.986 [Micromodem](INFO): Starting
2019-03-08T21:50:02.390Z,1552081802.390 [Micromodem](INFO): Starting
2019-03-08T21:50:02.794Z,1552081802.794 [Micromodem](INFO): Starting
2019-03-08T21:50:03.198Z,1552081803.198 [Micromodem](INFO): Starting
2019-03-08T21:50:03.602Z,1552081803.602 [Micromodem](INFO): Starting
2019-03-08T21:50:04.006Z,1552081804.006 [Micromodem](INFO): Starting
2019-03-08T21:50:04.410Z,1552081804.410 [Micromodem](INFO): Starting
2019-03-08T21:50:04.814Z,1552081804.814 [Micromodem](INFO): Starting
2019-03-08T21:50:05.218Z,1552081805.218 [Micromodem](INFO): Starting
2019-03-08T21:50:05.630Z,1552081805.630 [Micromodem](INFO): Starting
2019-03-08T21:50:06.030Z,1552081806.030 [Micromodem](INFO): Starting
2019-03-08T21:50:06.430Z,1552081806.430 [Micromodem](INFO): Starting
2019-03-08T21:50:06.834Z,1552081806.834 [Micromodem](INFO): Starting
2019-03-08T21:50:07.242Z,1552081807.242 [Micromodem](INFO): Starting
2019-03-08T21:50:07.642Z,1552081807.642 [Micromodem](INFO): Starting
2019-03-08T21:50:08.046Z,1552081808.046 [Micromodem](INFO): Starting
2019-03-08T21:50:08.450Z,1552081808.450 [Micromodem](INFO): Starting
2019-03-08T21:50:08.451Z,1552081808.451 [Micromodem](IMPORTANT): CACFG stsring$CACFG,RXP,1*2B

2019-03-08T21:50:08.452Z,1552081808.452 [Micromodem](DEBUG): Nmea buf: $CCTMS,2019-03-08T21:50:09Z,0*7A

2019-03-08T21:50:08.452Z,1552081808.452 [Micromodem](IMPORTANT): Nmea buf: $CCTMS,2019-03-08T21:50:09Z,0*7A

2019-03-08T21:50:08.452Z,1552081808.452 [Micromodem](INFO): Nmea out: $CCTMS,2019-03-08T21:50:09Z,0*7A

2019-03-08T21:50:08.854Z,1552081808.854 [Micromodem](INFO): Starting
2019-03-08T21:50:09.258Z,1552081809.258 [Micromodem](INFO): Starting
2019-03-08T21:50:09.666Z,1552081809.666 [Micromodem](INFO): Starting
2019-03-08T21:50:10.070Z,1552081810.070 [Micromodem](INFO): Starting
2019-03-08T21:50:34.051Z,1552081834.051 [SBIT](IMPORTANT): SBIT PASSED
2019-03-08T21:50:34.089Z,1552081834.089 [CommandLine](IMPORTANT): got command configSet list
2019-03-08T21:50:34.089Z,1552081834.089 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2019-03-08T21:50:34.090Z,1552081834.090 [CommandLine](IMPORTANT): AHRS_M2.loadAtStartup=0 bool;

2019-03-08T21:50:34.452Z,1552081834.452 [MissionManager](IMPORTANT): Started mission Startup
2019-03-08T21:50:34.452Z,1552081834.452 [Startup] Running Loop=1
2019-03-08T21:50:34.453Z,1552081834.453 [Startup](DEBUG): Aggregate::initialize Startup
2019-03-08T21:50:34.453Z,1552081834.453 [Startup:A.GoToSurface] Running Loop=1
2019-03-08T21:50:34.453Z,1552081834.453 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-03-08T21:50:34.454Z,1552081834.454 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-03-08T21:50:34.454Z,1552081834.454 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-03-08T21:50:34.454Z,1552081834.454 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-03-08T21:50:34.455Z,1552081834.455 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-03-08T21:50:34.455Z,1552081834.455 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-03-08T21:50:34.456Z,1552081834.456 [Startup:StartupSatComms] Running Loop=1
2019-03-08T21:50:34.457Z,1552081834.457 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2019-03-08T21:50:34.457Z,1552081834.457 [Startup:StartupSatComms:A] Running Loop=1
2019-03-08T21:50:34.841Z,1552081834.841 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2019-03-08T21:51:11.620Z,1552081871.620 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2019-03-08T21:51:11.620Z,1552081871.620 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2019-03-08T21:51:11.620Z,1552081871.620 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-03-08T21:51:11.622Z,1552081871.622 [DeadReckonUsingSpeedCalculator](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2019-03-08T21:51:11.622Z,1552081871.622 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1
2019-03-08T21:51:11.622Z,1552081871.622 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2019-03-08T21:51:11.623Z,1552081871.623 [DeadReckonWithRespectToSeafloor](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2019-03-08T21:51:11.623Z,1552081871.623 [DeadReckonWithRespectToSeafloor] Software Fault, FailCount= 1
2019-03-08T21:51:11.624Z,1552081871.624 [DeadReckonWithRespectToSeafloor](ERROR): Software Fault
2019-03-08T21:51:11.655Z,1552081871.655 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-03-08T21:51:11.655Z,1552081871.655 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2019-03-08T21:51:11.655Z,1552081871.655 [CBIT](ERROR): Software Fault in component: DeadReckonWithRespectToSeafloor
2019-03-08T21:51:12.026Z,1552081872.026 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-03-08T21:51:12.026Z,1552081872.026 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2019-03-08T21:51:12.026Z,1552081872.026 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2019-03-08T21:51:12.026Z,1552081872.026 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1
2019-03-08T21:51:12.027Z,1552081872.027 [CBIT](INFO): Clearing failed state for component DeadReckonWithRespectToSeafloor
2019-03-08T21:51:12.027Z,1552081872.027 [DeadReckonWithRespectToSeafloor] No Fault, FailCount= 1
2019-03-08T21:51:12.430Z,1552081872.430 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2019-03-08T21:51:34.627Z,1552081894.627 [Startup:StartupSatComms:A](INFO): Timed out from 2019-03-08T21:50:34.5Z
2019-03-08T21:51:34.627Z,1552081894.627 [Startup:StartupSatComms:A] Stopped
2019-03-08T21:51:34.627Z,1552081894.627 [Startup:StartupSatComms:B] Running Loop=1
2019-03-08T21:51:35.031Z,1552081895.031 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-03-08T21:51:37.715Z,1552081897.715 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004974
2019-03-08T21:51:42.625Z,1552081902.625 [DataOverHttps](INFO): Sending 190 bytes from file Logs/20190308T214046/Courier0007.lzma
2019-03-08T21:51:43.430Z,1552081903.430 [DataOverHttps](INFO): Moved sent file to Logs/20190308T214046/Courier0007.lzma.bak
2019-03-08T21:51:43.430Z,1552081903.430 [DataOverHttps](INFO): SBD MOMSN=10116952
2019-03-08T21:51:54.101Z,1552081914.101 [DataOverHttps](INFO): Sending 470 bytes from file Logs/20190308T214046/Express0008.lzma
2019-03-08T21:51:54.906Z,1552081914.906 [DataOverHttps](INFO): Moved sent file to Logs/20190308T214046/Express0008.lzma.bak
2019-03-08T21:51:54.906Z,1552081914.906 [DataOverHttps](INFO): SBD MOMSN=10116954
2019-03-08T21:52:05.814Z,1552081925.814 [DataOverHttps](INFO): Sending 969 bytes from file Logs/20190308T214901/Express0001.lzma
2019-03-08T21:52:06.634Z,1552081926.634 [DataOverHttps](INFO): Moved sent file to Logs/20190308T214901/Express0001.lzma.bak
2019-03-08T21:52:06.634Z,1552081926.634 [DataOverHttps](INFO): SBD MOMSN=10116983
2019-03-08T21:52:07.386Z,1552081927.386 [Startup:StartupSatComms:B] Stopped
2019-03-08T21:52:07.386Z,1552081927.386 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2019-03-08T21:52:07.386Z,1552081927.386 [Startup:StartupSatComms] Stopped
2019-03-08T21:52:07.387Z,1552081927.387 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2019-03-08T21:52:07.387Z,1552081927.387 [Startup](INFO): Completed Startup
2019-03-08T21:52:07.387Z,1552081927.387 [MissionManager](INFO): Startup is completed.
2019-03-08T21:52:07.388Z,1552081927.388 [MissionManager](INFO): Uninitializing Mission Startup
2019-03-08T21:52:07.388Z,1552081927.388 [Startup] Stopped
2019-03-08T21:52:07.388Z,1552081927.388 [Startup](DEBUG): Aggregate::uninitialize Startup
2019-03-08T21:52:07.388Z,1552081927.388 [Startup:A.GoToSurface] Stopped
2019-03-08T21:52:07.388Z,1552081927.388 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-03-08T21:52:07.774Z,1552081927.774 [MissionManager](IMPORTANT): Started mission Default
2019-03-08T21:52:07.774Z,1552081927.774 [Default] Running Loop=1
2019-03-08T21:52:07.774Z,1552081927.774 [Default](DEBUG): Aggregate::initialize Default
2019-03-08T21:52:07.774Z,1552081927.774 [Default:B.GoToSurface] Running Loop=1
2019-03-08T21:52:07.775Z,1552081927.775 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-03-08T21:52:07.775Z,1552081927.775 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-03-08T21:52:07.775Z,1552081927.775 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-03-08T21:52:07.775Z,1552081927.775 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-03-08T21:52:07.776Z,1552081927.776 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-03-08T21:52:07.776Z,1552081927.776 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-03-08T21:52:07.776Z,1552081927.776 [Default:A.Wait] Running Loop=1
2019-03-08T21:52:07.776Z,1552081927.776 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-03-08T21:52:21.115Z,1552081941.115 [Default:A.Wait](INFO): Done Waiting.
2019-03-08T21:52:21.115Z,1552081941.115 [Default:A.Wait] Stopped
2019-03-08T21:52:21.115Z,1552081941.115 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-03-08T21:52:21.502Z,1552081941.502 [Default:CheckIn] Running Loop=1
2019-03-08T21:52:21.502Z,1552081941.502 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-03-08T21:52:21.503Z,1552081941.503 [Default:CheckIn:Read_GPS] Running Loop=1
2019-03-08T21:52:21.898Z,1552081941.898 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2019-03-08T21:52:31.200Z,1552081951.200 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude
2019-03-08T21:52:31.200Z,1552081951.200 [RDI_Pathfinder](ERROR): Failed to parse:
:BD,       -1.78,     ,       -0.45,   9.59,  0.00
2019-03-08T21:53:12.799Z,1552081992.799 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2019-03-08T21:53:12.799Z,1552081992.799 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2019-03-08T21:53:12.799Z,1552081992.799 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-03-08T21:53:12.801Z,1552081992.801 [DeadReckonUsingSpeedCalculator](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2019-03-08T21:53:12.801Z,1552081992.801 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 2
2019-03-08T21:53:12.801Z,1552081992.801 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2019-03-08T21:53:12.802Z,1552081992.802 [DeadReckonWithRespectToSeafloor](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2019-03-08T21:53:12.802Z,1552081992.802 [DeadReckonWithRespectToSeafloor] Software Fault, FailCount= 2
2019-03-08T21:53:12.802Z,1552081992.802 [DeadReckonWithRespectToSeafloor](ERROR): Software Fault
2019-03-08T21:53:12.846Z,1552081992.846 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-03-08T21:53:12.846Z,1552081992.846 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2019-03-08T21:53:12.846Z,1552081992.846 [CBIT](ERROR): Software Fault in component: DeadReckonWithRespectToSeafloor
2019-03-08T21:53:13.226Z,1552081993.226 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-03-08T21:53:13.226Z,1552081993.226 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2019-03-08T21:53:13.227Z,1552081993.227 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2019-03-08T21:53:13.227Z,1552081993.227 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 2
2019-03-08T21:53:13.227Z,1552081993.227 [CBIT](INFO): Clearing failed state for component DeadReckonWithRespectToSeafloor
2019-03-08T21:53:13.227Z,1552081993.227 [DeadReckonWithRespectToSeafloor] No Fault, FailCount= 2
2019-03-08T21:53:13.608Z,1552081993.608 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2019-03-08T21:54:04.491Z,1552082044.491 [CommandLine](IMPORTANT): got command show variable DUSBL
2019-03-08T21:54:04.570Z,1552082044.570 [CommandLine](IMPORTANT): DUSBL_Hydroid.loadAtStartup (bool)
2019-03-08T21:54:04.570Z,1552082044.570 [CommandLine](IMPORTANT): DUSBL_Hydroid.simulateHardware (bool)
2019-03-08T21:54:04.571Z,1552082044.571 [CommandLine](IMPORTANT): DUSBL_Hydroid.defaultTurnAroundTime (meter_per_second)
2019-03-08T21:54:04.571Z,1552082044.571 [CommandLine](IMPORTANT): DUSBL_Hydroid.defaultSoundSpeed (meter_per_second)
2019-03-08T21:54:04.571Z,1552082044.571 [CommandLine](IMPORTANT): DUSBL_Hydroid.detectionThreshold (count)
2019-03-08T21:54:04.572Z,1552082044.572 [CommandLine](IMPORTANT): DUSBL_Hydroid.recieveTimeout (millisecond)
2019-03-08T21:54:04.572Z,1552082044.572 [CommandLine](IMPORTANT): DUSBL_Hydroid.transmitLockout (millisecond)
2019-03-08T21:54:04.572Z,1552082044.572 [CommandLine](IMPORTANT): DUSBL_Hydroid.transponderCode (enum)
2019-03-08T21:54:04.577Z,1552082044.577 [CommandLine](IMPORTANT): DUSBL_Hydroid.numberOfPingsRequested (count)
2019-03-08T21:54:04.577Z,1552082044.577 [CommandLine](IMPORTANT): DUSBL_Hydroid.verbosity (enum)
2019-03-08T21:54:04.578Z,1552082044.578 [CommandLine](IMPORTANT): DUSBL_Hydroid.xCenter (angular_degree)
2019-03-08T21:54:04.578Z,1552082044.578 [CommandLine](IMPORTANT): DUSBL_Hydroid.yCenter (angular_degree)
2019-03-08T21:54:04.602Z,1552082044.602 [CommandLine](IMPORTANT): DUSBL_Hydroid.loadControl (none)
2019-03-08T21:54:04.603Z,1552082044.603 [CommandLine](IMPORTANT): DUSBL_Hydroid.uart (none)
2019-03-08T21:54:04.603Z,1552082044.603 [CommandLine](IMPORTANT): DUSBL_Hydroid.baud (bit_per_second)
2019-03-08T21:54:04.606Z,1552082044.606 [CommandLine](IMPORTANT): Micromodem.dusblPingCode (enum)
2019-03-08T21:54:04.607Z,1552082044.607 [CommandLine](IMPORTANT): DUSBL_Hydroid.xAngle (angular_degree)
2019-03-08T21:54:04.607Z,1552082044.607 [CommandLine](IMPORTANT): DUSBL_Hydroid.yAngle (angular_degree)
2019-03-08T21:54:04.607Z,1552082044.607 [CommandLine](IMPORTANT): DUSBL_Hydroid.travelTime (microsecond)
2019-03-08T21:54:04.608Z,1552082044.608 [CommandLine](IMPORTANT): DUSBL_Hydroid.latency (microsecond)
2019-03-08T21:54:04.608Z,1552082044.608 [CommandLine](IMPORTANT): DUSBL_Hydroid.gain (ratio)
2019-03-08T21:54:04.608Z,1552082044.608 [CommandLine](IMPORTANT): DUSBL_Hydroid.inBandSignalToNoise (ratio)
2019-03-08T21:54:04.609Z,1552082044.609 [CommandLine](IMPORTANT): DUSBL_Hydroid.outBandSignalToNoise (ratio)
2019-03-08T21:54:04.609Z,1552082044.609 [CommandLine](IMPORTANT): DUSBL_Hydroid.range (meter)
2019-03-08T21:54:04.610Z,1552082044.610 [CommandLine](IMPORTANT): DUSBL_Hydroid.direction (none)
2019-03-08T21:54:12.734Z,1552082052.734 [CommandLine](IMPORTANT): got command report touch DUSBL_Hydroid.range
2019-03-08T21:54:21.511Z,1552082061.511 [CommandLine](IMPORTANT): got command report touch DUSBL_Hydroid.xAngle
2019-03-08T21:54:30.178Z,1552082070.178 [CommandLine](IMPORTANT): got command show variable detectionThre
2019-03-08T21:54:30.278Z,1552082070.278 [CommandLine](IMPORTANT): DUSBL_Hydroid.detectionThreshold (count)
2019-03-08T21:54:35.489Z,1552082075.489 [CommandLine](IMPORTANT): got command get DUSBL_Hydroid.detectionThreshold
2019-03-08T21:54:35.490Z,1552082075.490 [CommandLine](IMPORTANT): DUSBL_Hydroid.detectionThreshold 32 count
2019-03-08T21:54:42.179Z,1552082082.179 [CommandLine](IMPORTANT): got command run ./Missions/Maintenance/DUSBL.xml
2019-03-08T21:54:42.180Z,1552082082.180 [MissionManager](INFO): Loading Mission: ./Missions/Maintenance/DUSBL.xml
2019-03-08T21:54:42.242Z,1552082082.242 [MissionManager](INFO): DefineArg DUSBL.MissionTimeout = 90.000000 min
2019-03-08T21:54:42.246Z,1552082082.246 [MissionManager](INFO): DefineArg DUSBL.NumberOfRequests = 10.000000 count
2019-03-08T21:54:42.250Z,1552082082.250 [MissionManager](INFO): DefineArg DUSBL.TransponderCode = 2.000000 count
2019-03-08T21:54:42.254Z,1552082082.254 [MissionManager](INFO): DefineArg DUSBL.NumberOfPings = 1.000000 count
2019-03-08T21:54:42.258Z,1552082082.258 [MissionManager](INFO): DefineArg DUSBL.EnabledDUSBL = 1.000000 bool
2019-03-08T21:54:42.259Z,1552082082.259 [DUSBL:A.Pitch](DEBUG): Construct.
2019-03-08T21:54:42.266Z,1552082082.266 [DUSBL:B.SetSpeed](DEBUG): Construct.
2019-03-08T21:54:42.274Z,1552082082.274 [DUSBL:RequestRepeater:C.Wait](DEBUG): Construct Wait.
2019-03-08T21:54:42.299Z,1552082082.299 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<!-- ====================
     Generated by TethysL
     ==================== -->
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Control="Tethys/Control"
         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/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd"
       Id="DUSBL">

    <Description>
        This mission is requests a DUSBL arming.
    </Description>

    <DefineArg Name="MissionTimeout"><Description>
        How long to let the mission run.
    </Description><Units:minute/><Value>90</Value></DefineArg>

    <DefineArg Name="NumberOfRequests"><Description>
        Number of pings to requst.
    </Description><Units:count/><Value>10</Value></DefineArg>

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

    <DefineArg Name="NumberOfPings"><Description>
        Number of pings requested each time.
    </Description><Units:count/><Value>1</Value></DefineArg>      
    
    <DefineArg Name="EnabledDUSBL"><Description>
        Automatically set to true if the DUSBL is enabled. Set to false to disable
        reading from the DUSBL.
    </Description><Science:DUSBL_Hydroid.loadAtStartup/></DefineArg>    

    <Timeout Duration="MissionTimeout"/>

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

    <Guidance:SetSpeed>
        <Parallel/>
        <Setting><Guidance:SetSpeed.speed/><Units:meter_per_second/><Value>0</Value></Setting>
    </Guidance:SetSpeed>

    <ReadData>
        <While>
            <Arg Name="EnabledDUSBL"/>
        </While>
        <Sensor:DUSBL_Hydroid.range/>
        <Sensor:DUSBL_Hydroid.direction/>
    </ReadData>
    
      <Aggregate Id="RequestRepeater">

        <Sequence Repeat="NumberOfRequests"/>
        <Assign><Parallel/><Sensor:DUSBL_Hydroid.transponderCode/><Arg Name="TransponderCode"/></Assign>
        <Assign><Parallel/><Sensor:DUSBL_Hydroid.numberOfPingsRequested/><Arg Name="NumberOfPings"/></Assign>
          <Guidance:Wait>
            <Sequence/>
            <Setting><Guidance:Wait.duration/><Units:second/><Value>10</Value></Setting>
          </Guidance:Wait>
      </Aggregate>    
</Mission>


2019-03-08T21:54:42.305Z,1552082082.305 [CommandLine](IMPORTANT): Running ./Missions/Maintenance/DUSBL.xml
2019-03-08T21:54:42.526Z,1552082082.526 [Default] Stopped
2019-03-08T21:54:42.526Z,1552082082.526 [Default](DEBUG): Aggregate::uninitialize Default
2019-03-08T21:54:42.526Z,1552082082.526 [Default:B.GoToSurface] Stopped
2019-03-08T21:54:42.526Z,1552082082.526 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-03-08T21:54:42.526Z,1552082082.526 [Default:CheckIn] Stopped
2019-03-08T21:54:42.526Z,1552082082.526 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-03-08T21:54:42.526Z,1552082082.526 [Default:CheckIn:Read_GPS] Stopped
2019-03-08T21:54:42.526Z,1552082082.526 [MissionManager](IMPORTANT): Started mission DUSBL
2019-03-08T21:54:42.527Z,1552082082.527 [DUSBL] Running Loop=1
2019-03-08T21:54:42.527Z,1552082082.527 [DUSBL](DEBUG): Aggregate::initialize DUSBL
2019-03-08T21:54:42.527Z,1552082082.527 [DUSBL:A.Pitch] Running Loop=1
2019-03-08T21:54:42.527Z,1552082082.527 [DUSBL:A.Pitch](DEBUG): Initialize.
2019-03-08T21:54:42.527Z,1552082082.527 [DUSBL:B.SetSpeed] Running Loop=1
2019-03-08T21:54:42.527Z,1552082082.527 [DUSBL:B.SetSpeed](DEBUG): Initialize.
2019-03-08T21:54:42.527Z,1552082082.527 [DUSBL:C] Running Loop=1
2019-03-08T21:54:42.528Z,1552082082.528 [DUSBL:RequestRepeater] Running Loop=1
2019-03-08T21:54:42.528Z,1552082082.528 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-03-08T21:54:42.528Z,1552082082.528 [DUSBL:RequestRepeater:A] Running Loop=1
2019-03-08T21:54:42.528Z,1552082082.528 [DUSBL:RequestRepeater:B] Running Loop=1
2019-03-08T21:54:42.528Z,1552082082.528 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-03-08T21:54:42.528Z,1552082082.528 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-03-08T21:54:42.528Z,1552082082.528 [DUSBL:RequestRepeater:B] Running Loop=1
2019-03-08T21:54:42.529Z,1552082082.529 [DUSBL:RequestRepeater:A] Running Loop=1
2019-03-08T21:54:42.529Z,1552082082.529 [DUSBL:C] Running Loop=1
2019-03-08T21:54:42.530Z,1552082082.530 [DUSBL:C](DEBUG): Initialize ReadDataComponent to sense DUSBL_Hydroid.range
2019-03-08T21:54:42.530Z,1552082082.530 [DUSBL:C](DEBUG): Initialize ReadDataComponent to sense DUSBL_Hydroid.direction
2019-03-08T21:54:42.530Z,1552082082.530 [DUSBL:B.SetSpeed] Running Loop=1
2019-03-08T21:54:42.531Z,1552082082.531 [DUSBL:A.Pitch] Running Loop=1
2019-03-08T21:54:44.079Z,1552082084.079 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-03-08T21:54:44.080Z,1552082084.080 [Micromodem](INFO): **** IS COMMANDED  IN Runnable **** 
2019-03-08T21:54:44.080Z,1552082084.080 [Micromodem](DEBUG): Nmea buf: $CCPGT,26000,28,4A1C0370,54,24000,0,0,0,0,1000,0*54

2019-03-08T21:54:44.080Z,1552082084.080 [Micromodem](IMPORTANT): Nmea buf: $CCPGT,26000,28,4A1C0370,54,24000,0,0,0,0,1000,0*54

2019-03-08T21:54:44.080Z,1552082084.080 [Micromodem](INFO): Nmea out: $CCPGT,26000,28,4A1C0370,54,24000,0,0,0,0,1000,0*54

2019-03-08T21:54:48.174Z,1552082088.174 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-03-08T21:54:48.193Z,1552082088.193 [Micromodem](INFO): **** IS COMMANDED  IN Runnable **** 
2019-03-08T21:54:48.193Z,1552082088.193 [Micromodem](DEBUG): Nmea buf: $CCPGT,26000,28,4A1C0370,54,24000,0,0,0,0,1000,0*54

2019-03-08T21:54:48.194Z,1552082088.194 [Micromodem](IMPORTANT): Nmea buf: $CCPGT,26000,28,4A1C0370,54,24000,0,0,0,0,1000,0*54

2019-03-08T21:54:48.194Z,1552082088.194 [Micromodem](INFO): Nmea out: $CCPGT,26000,28,4A1C0370,54,24000,0,0,0,0,1000,0*54

2019-03-08T21:54:52.170Z,1552082092.170 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-03-08T21:54:52.563Z,1552082092.563 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-03-08T21:54:52.566Z,1552082092.566 [Micromodem](INFO): **** IS COMMANDED  IN Runnable **** 
2019-03-08T21:54:52.567Z,1552082092.567 [Micromodem](DEBUG): Nmea buf: $CCPGT,26000,28,4A1C0370,54,24000,0,0,0,0,1000,0*54

2019-03-08T21:54:52.568Z,1552082092.568 [Micromodem](IMPORTANT): Nmea buf: $CCPGT,26000,28,4A1C0370,54,24000,0,0,0,0,1000,0*54

2019-03-08T21:54:52.568Z,1552082092.568 [Micromodem](INFO): Nmea out: $CCPGT,26000,28,4A1C0370,54,24000,0,0,0,0,1000,0*54

2019-03-08T21:54:52.640Z,1552082092.640 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-03-08T21:54:52.640Z,1552082092.640 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-03-08T21:54:52.640Z,1552082092.640 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-03-08T21:54:52.641Z,1552082092.641 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-03-08T21:54:52.641Z,1552082092.641 [DUSBL:RequestRepeater] Stopped
2019-03-08T21:54:52.642Z,1552082092.642 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-03-08T21:54:52.642Z,1552082092.642 [DUSBL:RequestRepeater:A] Stopped
2019-03-08T21:54:52.642Z,1552082092.642 [DUSBL:RequestRepeater:B] Stopped
2019-03-08T21:54:52.642Z,1552082092.642 [DUSBL:RequestRepeater](INFO): Running loop #2
2019-03-08T21:54:52.642Z,1552082092.642 [DUSBL:RequestRepeater] Running Loop=2
2019-03-08T21:54:52.642Z,1552082092.642 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-03-08T21:54:52.642Z,1552082092.642 [DUSBL:RequestRepeater:A] Running Loop=1
2019-03-08T21:54:52.642Z,1552082092.642 [DUSBL:RequestRepeater:B] Running Loop=1
2019-03-08T21:54:52.642Z,1552082092.642 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-03-08T21:54:52.642Z,1552082092.642 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-03-08T21:54:52.981Z,1552082092.981 [NAL9602](DEBUG): Fix Requested
2019-03-08T21:54:53.378Z,1552082093.378 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,215028.00,A,3648.16390,N,12147.28829,W,0.097,0.00,080319,,,A*71
2019-03-08T21:54:53.382Z,1552082093.382 [NAL9602](INFO): GPS fix at 20190308T215028: (36.802732, -121.788138)
2019-03-08T21:54:56.602Z,1552082096.602 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-03-08T21:54:56.603Z,1552082096.603 [Micromodem](INFO): **** IS COMMANDED  IN Runnable **** 
2019-03-08T21:54:56.603Z,1552082096.603 [Micromodem](DEBUG): Nmea buf: $CCPGT,26000,28,4A1C0370,54,24000,0,0,0,0,1000,0*54

2019-03-08T21:54:56.603Z,1552082096.603 [Micromodem](IMPORTANT): Nmea buf: $CCPGT,26000,28,4A1C0370,54,24000,0,0,0,0,1000,0*54

2019-03-08T21:54:56.603Z,1552082096.603 [Micromodem](INFO): Nmea out: $CCPGT,26000,28,4A1C0370,54,24000,0,0,0,0,1000,0*54

2019-03-08T21:55:00.644Z,1552082100.644 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-03-08T21:55:00.649Z,1552082100.649 [Micromodem](INFO): **** IS COMMANDED  IN Runnable **** 
2019-03-08T21:55:00.649Z,1552082100.649 [Micromodem](DEBUG): Nmea buf: $CCPGT,26000,28,4A1C0370,54,24000,0,0,0,0,1000,0*54

2019-03-08T21:55:00.650Z,1552082100.650 [Micromodem](IMPORTANT): Nmea buf: $CCPGT,26000,28,4A1C0370,54,24000,0,0,0,0,1000,0*54

2019-03-08T21:55:00.650Z,1552082100.650 [Micromodem](INFO): Nmea out: $CCPGT,26000,28,4A1C0370,54,24000,0,0,0,0,1000,0*54

2019-03-08T21:55:03.100Z,1552082103.100 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-03-08T21:55:03.100Z,1552082103.100 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-03-08T21:55:03.100Z,1552082103.100 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-03-08T21:55:03.101Z,1552082103.101 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-03-08T21:55:03.101Z,1552082103.101 [DUSBL:RequestRepeater] Stopped
2019-03-08T21:55:03.101Z,1552082103.101 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-03-08T21:55:03.101Z,1552082103.101 [DUSBL:RequestRepeater:A] Stopped
2019-03-08T21:55:03.101Z,1552082103.101 [DUSBL:RequestRepeater:B] Stopped
2019-03-08T21:55:03.101Z,1552082103.101 [DUSBL:RequestRepeater](INFO): Running loop #3
2019-03-08T21:55:03.102Z,1552082103.102 [DUSBL:RequestRepeater] Running Loop=3
2019-03-08T21:55:03.102Z,1552082103.102 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-03-08T21:55:03.102Z,1552082103.102 [DUSBL:RequestRepeater:A] Running Loop=1
2019-03-08T21:55:03.102Z,1552082103.102 [DUSBL:RequestRepeater:B] Running Loop=1
2019-03-08T21:55:03.102Z,1552082103.102 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-03-08T21:55:03.102Z,1552082103.102 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-03-08T21:55:04.682Z,1552082104.682 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-03-08T21:55:04.684Z,1552082104.684 [Micromodem](INFO): **** IS COMMANDED  IN Runnable **** 
2019-03-08T21:55:04.686Z,1552082104.686 [Micromodem](DEBUG): Nmea buf: $CCPGT,26000,28,4A1C0370,54,24000,0,0,0,0,1000,0*54

2019-03-08T21:55:04.687Z,1552082104.687 [Micromodem](IMPORTANT): Nmea buf: $CCPGT,26000,28,4A1C0370,54,24000,0,0,0,0,1000,0*54

2019-03-08T21:55:04.688Z,1552082104.688 [Micromodem](INFO): Nmea out: $CCPGT,26000,28,4A1C0370,54,24000,0,0,0,0,1000,0*54

2019-03-08T21:55:08.722Z,1552082108.722 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-03-08T21:55:08.723Z,1552082108.723 [Micromodem](INFO): **** IS COMMANDED  IN Runnable **** 
2019-03-08T21:55:08.723Z,1552082108.723 [Micromodem](DEBUG): Nmea buf: $CCPGT,26000,28,4A1C0370,54,24000,0,0,0,0,1000,0*54

2019-03-08T21:55:08.723Z,1552082108.723 [Micromodem](IMPORTANT): Nmea buf: $CCPGT,26000,28,4A1C0370,54,24000,0,0,0,0,1000,0*54

2019-03-08T21:55:08.723Z,1552082108.723 [Micromodem](INFO): Nmea out: $CCPGT,26000,28,4A1C0370,54,24000,0,0,0,0,1000,0*54

2019-03-08T21:55:12.763Z,1552082112.763 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-03-08T21:55:12.767Z,1552082112.767 [Micromodem](INFO): **** IS COMMANDED  IN Runnable **** 
2019-03-08T21:55:12.768Z,1552082112.768 [Micromodem](DEBUG): Nmea buf: $CCPGT,26000,28,4A1C0370,54,24000,0,0,0,0,1000,0*54

2019-03-08T21:55:12.768Z,1552082112.768 [Micromodem](IMPORTANT): Nmea buf: $CCPGT,26000,28,4A1C0370,54,24000,0,0,0,0,1000,0*54

2019-03-08T21:55:12.768Z,1552082112.768 [Micromodem](INFO): Nmea out: $CCPGT,26000,28,4A1C0370,54,24000,0,0,0,0,1000,0*54

2019-03-08T21:55:13.604Z,1552082113.604 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-03-08T21:55:13.604Z,1552082113.604 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-03-08T21:55:13.604Z,1552082113.604 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-03-08T21:55:13.605Z,1552082113.605 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-03-08T21:55:13.605Z,1552082113.605 [DUSBL:RequestRepeater] Stopped
2019-03-08T21:55:13.605Z,1552082113.605 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-03-08T21:55:13.606Z,1552082113.606 [DUSBL:RequestRepeater:A] Stopped
2019-03-08T21:55:13.606Z,1552082113.606 [DUSBL:RequestRepeater:B] Stopped
2019-03-08T21:55:13.606Z,1552082113.606 [DUSBL:RequestRepeater](INFO): Running loop #4
2019-03-08T21:55:13.606Z,1552082113.606 [DUSBL:RequestRepeater] Running Loop=4
2019-03-08T21:55:13.606Z,1552082113.606 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-03-08T21:55:13.606Z,1552082113.606 [DUSBL:RequestRepeater:A] Running Loop=1
2019-03-08T21:55:13.606Z,1552082113.606 [DUSBL:RequestRepeater:B] Running Loop=1
2019-03-08T21:55:13.606Z,1552082113.606 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-03-08T21:55:13.606Z,1552082113.606 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-03-08T21:55:14.008Z,1552082114.008 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2019-03-08T21:55:14.008Z,1552082114.008 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2019-03-08T21:55:14.008Z,1552082114.008 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-03-08T21:55:14.010Z,1552082114.010 [DeadReckonUsingSpeedCalculator](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2019-03-08T21:55:14.010Z,1552082114.010 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1
2019-03-08T21:55:14.010Z,1552082114.010 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2019-03-08T21:55:14.012Z,1552082114.012 [DeadReckonWithRespectToSeafloor](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2019-03-08T21:55:14.012Z,1552082114.012 [DeadReckonWithRespectToSeafloor] Software Fault, FailCount= 1
2019-03-08T21:55:14.012Z,1552082114.012 [DeadReckonWithRespectToSeafloor](ERROR): Software Fault
2019-03-08T21:55:14.024Z,1552082114.024 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-03-08T21:55:14.024Z,1552082114.024 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2019-03-08T21:55:14.024Z,1552082114.024 [CBIT](ERROR): Software Fault in component: DeadReckonWithRespectToSeafloor
2019-03-08T21:55:14.427Z,1552082114.427 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-03-08T21:55:14.427Z,1552082114.427 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2019-03-08T21:55:14.427Z,1552082114.427 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2019-03-08T21:55:14.427Z,1552082114.427 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1
2019-03-08T21:55:14.428Z,1552082114.428 [CBIT](INFO): Clearing failed state for component DeadReckonWithRespectToSeafloor
2019-03-08T21:55:14.428Z,1552082114.428 [DeadReckonWithRespectToSeafloor] No Fault, FailCount= 1
2019-03-08T21:55:14.806Z,1552082114.806 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2019-03-08T21:55:16.803Z,1552082116.803 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-03-08T21:55:16.805Z,1552082116.805 [Micromodem](INFO): **** IS COMMANDED  IN Runnable **** 
2019-03-08T21:55:16.807Z,1552082116.807 [Micromodem](DEBUG): Nmea buf: $CCPGT,26000,28,4A1C0370,54,24000,0,0,0,0,1000,0*54

2019-03-08T21:55:16.807Z,1552082116.807 [Micromodem](IMPORTANT): Nmea buf: $CCPGT,26000,28,4A1C0370,54,24000,0,0,0,0,1000,0*54

2019-03-08T21:55:16.808Z,1552082116.808 [Micromodem](INFO): Nmea out: $CCPGT,26000,28,4A1C0370,54,24000,0,0,0,0,1000,0*54

2019-03-08T21:55:20.847Z,1552082120.847 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-03-08T21:55:20.849Z,1552082120.849 [Micromodem](INFO): **** IS COMMANDED  IN Runnable **** 
2019-03-08T21:55:20.851Z,1552082120.851 [Micromodem](DEBUG): Nmea buf: $CCPGT,26000,28,4A1C0370,54,24000,0,0,0,0,1000,0*54

2019-03-08T21:55:20.851Z,1552082120.851 [Micromodem](IMPORTANT): Nmea buf: $CCPGT,26000,28,4A1C0370,54,24000,0,0,0,0,1000,0*54

2019-03-08T21:55:20.851Z,1552082120.851 [Micromodem](INFO): Nmea out: $CCPGT,26000,28,4A1C0370,54,24000,0,0,0,0,1000,0*54

2019-03-08T21:55:24.116Z,1552082124.116 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-03-08T21:55:24.116Z,1552082124.116 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-03-08T21:55:24.116Z,1552082124.116 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-03-08T21:55:24.117Z,1552082124.117 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-03-08T21:55:24.117Z,1552082124.117 [DUSBL:RequestRepeater] Stopped
2019-03-08T21:55:24.117Z,1552082124.117 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-03-08T21:55:24.117Z,1552082124.117 [DUSBL:RequestRepeater:A] Stopped
2019-03-08T21:55:24.117Z,1552082124.117 [DUSBL:RequestRepeater:B] Stopped
2019-03-08T21:55:24.117Z,1552082124.117 [DUSBL:RequestRepeater](INFO): Running loop #5
2019-03-08T21:55:24.118Z,1552082124.118 [DUSBL:RequestRepeater] Running Loop=5
2019-03-08T21:55:24.118Z,1552082124.118 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-03-08T21:55:24.118Z,1552082124.118 [DUSBL:RequestRepeater:A] Running Loop=1
2019-03-08T21:55:24.118Z,1552082124.118 [DUSBL:RequestRepeater:B] Running Loop=1
2019-03-08T21:55:24.118Z,1552082124.118 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-03-08T21:55:24.118Z,1552082124.118 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-03-08T21:55:24.883Z,1552082124.883 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-03-08T21:55:24.888Z,1552082124.888 [Micromodem](INFO): **** IS COMMANDED  IN Runnable **** 
2019-03-08T21:55:24.888Z,1552082124.888 [Micromodem](DEBUG): Nmea buf: $CCPGT,26000,28,4A1C0370,54,24000,0,0,0,0,1000,0*54

2019-03-08T21:55:24.888Z,1552082124.888 [Micromodem](IMPORTANT): Nmea buf: $CCPGT,26000,28,4A1C0370,54,24000,0,0,0,0,1000,0*54

2019-03-08T21:55:24.888Z,1552082124.888 [Micromodem](INFO): Nmea out: $CCPGT,26000,28,4A1C0370,54,24000,0,0,0,0,1000,0*54

2019-03-08T21:55:25.691Z,1552082125.691 [NAL9602](INFO): Powering down
2019-03-08T21:55:28.927Z,1552082128.927 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-03-08T21:55:28.961Z,1552082128.961 [Micromodem](INFO): **** IS COMMANDED  IN Runnable **** 
2019-03-08T21:55:28.961Z,1552082128.961 [Micromodem](DEBUG): Nmea buf: $CCPGT,26000,28,4A1C0370,54,24000,0,0,0,0,1000,0*54

2019-03-08T21:55:28.961Z,1552082128.961 [Micromodem](IMPORTANT): Nmea buf: $CCPGT,26000,28,4A1C0370,54,24000,0,0,0,0,1000,0*54

2019-03-08T21:55:28.962Z,1552082128.962 [Micromodem](INFO): Nmea out: $CCPGT,26000,28,4A1C0370,54,24000,0,0,0,0,1000,0*54

2019-03-08T21:55:32.967Z,1552082132.967 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-03-08T21:55:32.969Z,1552082132.969 [Micromodem](INFO): **** IS COMMANDED  IN Runnable **** 
2019-03-08T21:55:32.971Z,1552082132.971 [Micromodem](DEBUG): Nmea buf: $CCPGT,26000,28,4A1C0370,54,24000,0,0,0,0,1000,0*54

2019-03-08T21:55:32.971Z,1552082132.971 [Micromodem](IMPORTANT): Nmea buf: $CCPGT,26000,28,4A1C0370,54,24000,0,0,0,0,1000,0*54

2019-03-08T21:55:32.971Z,1552082132.971 [Micromodem](INFO): Nmea out: $CCPGT,26000,28,4A1C0370,54,24000,0,0,0,0,1000,0*54

2019-03-08T21:55:34.615Z,1552082134.615 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-03-08T21:55:34.615Z,1552082134.615 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-03-08T21:55:34.615Z,1552082134.615 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-03-08T21:55:34.616Z,1552082134.616 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-03-08T21:55:34.616Z,1552082134.616 [DUSBL:RequestRepeater] Stopped
2019-03-08T21:55:34.616Z,1552082134.616 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-03-08T21:55:34.616Z,1552082134.616 [DUSBL:RequestRepeater:A] Stopped
2019-03-08T21:55:34.616Z,1552082134.616 [DUSBL:RequestRepeater:B] Stopped
2019-03-08T21:55:34.616Z,1552082134.616 [DUSBL:RequestRepeater](INFO): Running loop #6
2019-03-08T21:55:34.616Z,1552082134.616 [DUSBL:RequestRepeater] Running Loop=6
2019-03-08T21:55:34.617Z,1552082134.617 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-03-08T21:55:34.617Z,1552082134.617 [DUSBL:RequestRepeater:A] Running Loop=1
2019-03-08T21:55:34.617Z,1552082134.617 [DUSBL:RequestRepeater:B] Running Loop=1
2019-03-08T21:55:34.617Z,1552082134.617 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-03-08T21:55:34.617Z,1552082134.617 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-03-08T21:55:37.004Z,1552082137.004 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-03-08T21:55:37.009Z,1552082137.009 [Micromodem](INFO): **** IS COMMANDED  IN Runnable **** 
2019-03-08T21:55:37.009Z,1552082137.009 [Micromodem](DEBUG): Nmea buf: $CCPGT,26000,28,4A1C0370,54,24000,0,0,0,0,1000,0*54

2019-03-08T21:55:37.009Z,1552082137.009 [Micromodem](IMPORTANT): Nmea buf: $CCPGT,26000,28,4A1C0370,54,24000,0,0,0,0,1000,0*54

2019-03-08T21:55:37.010Z,1552082137.010 [Micromodem](INFO): Nmea out: $CCPGT,26000,28,4A1C0370,54,24000,0,0,0,0,1000,0*54

2019-03-08T21:55:41.042Z,1552082141.042 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-03-08T21:55:41.043Z,1552082141.043 [Micromodem](INFO): **** IS COMMANDED  IN Runnable **** 
2019-03-08T21:55:41.043Z,1552082141.043 [Micromodem](DEBUG): Nmea buf: $CCPGT,26000,28,4A1C0370,54,24000,0,0,0,0,1000,0*54

2019-03-08T21:55:41.043Z,1552082141.043 [Micromodem](IMPORTANT): Nmea buf: $CCPGT,26000,28,4A1C0370,54,24000,0,0,0,0,1000,0*54

2019-03-08T21:55:41.043Z,1552082141.043 [Micromodem](INFO): Nmea out: $CCPGT,26000,28,4A1C0370,54,24000,0,0,0,0,1000,0*54

2019-03-08T21:55:45.083Z,1552082145.083 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-03-08T21:55:45.085Z,1552082145.085 [Micromodem](INFO): **** IS COMMANDED  IN Runnable **** 
2019-03-08T21:55:45.087Z,1552082145.087 [Micromodem](DEBUG): Nmea buf: $CCPGT,26000,28,4A1C0370,54,24000,0,0,0,0,1000,0*54

2019-03-08T21:55:45.087Z,1552082145.087 [Micromodem](IMPORTANT): Nmea buf: $CCPGT,26000,28,4A1C0370,54,24000,0,0,0,0,1000,0*54

2019-03-08T21:55:45.087Z,1552082145.087 [Micromodem](INFO): Nmea out: $CCPGT,26000,28,4A1C0370,54,24000,0,0,0,0,1000,0*54

2019-03-08T21:55:45.127Z,1552082145.127 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2019-03-08T21:55:45.190Z,1552082145.190 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-03-08T21:55:45.190Z,1552082145.190 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-03-08T21:55:45.190Z,1552082145.190 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-03-08T21:55:45.190Z,1552082145.190 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-03-08T21:55:45.191Z,1552082145.191 [DUSBL:RequestRepeater] Stopped
2019-03-08T21:55:45.191Z,1552082145.191 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-03-08T21:55:45.191Z,1552082145.191 [DUSBL:RequestRepeater:A] Stopped
2019-03-08T21:55:45.191Z,1552082145.191 [DUSBL:RequestRepeater:B] Stopped
2019-03-08T21:55:45.191Z,1552082145.191 [DUSBL:RequestRepeater](INFO): Running loop #7
2019-03-08T21:55:45.191Z,1552082145.191 [DUSBL:RequestRepeater] Running Loop=7
2019-03-08T21:55:45.191Z,1552082145.191 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-03-08T21:55:45.191Z,1552082145.191 [DUSBL:RequestRepeater:A] Running Loop=1
2019-03-08T21:55:45.191Z,1552082145.191 [DUSBL:RequestRepeater:B] Running Loop=1
2019-03-08T21:55:45.191Z,1552082145.191 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-03-08T21:55:45.191Z,1552082145.191 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-03-08T21:55:49.123Z,1552082149.123 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-03-08T21:55:49.128Z,1552082149.128 [Micromodem](INFO): **** IS COMMANDED  IN Runnable **** 
2019-03-08T21:55:49.129Z,1552082149.129 [Micromodem](DEBUG): Nmea buf: $CCPGT,26000,28,4A1C0370,54,24000,0,0,0,0,1000,0*54

2019-03-08T21:55:49.129Z,1552082149.129 [Micromodem](IMPORTANT): Nmea buf: $CCPGT,26000,28,4A1C0370,54,24000,0,0,0,0,1000,0*54

2019-03-08T21:55:49.130Z,1552082149.130 [Micromodem](INFO): Nmea out: $CCPGT,26000,28,4A1C0370,54,24000,0,0,0,0,1000,0*54

2019-03-08T21:55:53.174Z,1552082153.174 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-03-08T21:55:53.176Z,1552082153.176 [Micromodem](INFO): **** IS COMMANDED  IN Runnable **** 
2019-03-08T21:55:53.178Z,1552082153.178 [Micromodem](DEBUG): Nmea buf: $CCPGT,26000,28,4A1C0370,54,24000,0,0,0,0,1000,0*54

2019-03-08T21:55:53.179Z,1552082153.179 [Micromodem](IMPORTANT): Nmea buf: $CCPGT,26000,28,4A1C0370,54,24000,0,0,0,0,1000,0*54

2019-03-08T21:55:53.179Z,1552082153.179 [Micromodem](INFO): Nmea out: $CCPGT,26000,28,4A1C0370,54,24000,0,0,0,0,1000,0*54

2019-03-08T21:55:55.616Z,1552082155.616 [DUSBL:RequestRepeater:C.Wait](INFO): Done Waiting.
2019-03-08T21:55:55.616Z,1552082155.616 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-03-08T21:55:55.616Z,1552082155.616 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-03-08T21:55:55.621Z,1552082155.621 [DUSBL:RequestRepeater](INFO): Completed DUSBL:RequestRepeater
2019-03-08T21:55:55.621Z,1552082155.621 [DUSBL:RequestRepeater] Stopped
2019-03-08T21:55:55.621Z,1552082155.621 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-03-08T21:55:55.622Z,1552082155.622 [DUSBL:RequestRepeater:A] Stopped
2019-03-08T21:55:55.622Z,1552082155.622 [DUSBL:RequestRepeater:B] Stopped
2019-03-08T21:55:55.622Z,1552082155.622 [DUSBL:RequestRepeater](INFO): Running loop #8
2019-03-08T21:55:55.622Z,1552082155.622 [DUSBL:RequestRepeater] Running Loop=8
2019-03-08T21:55:55.622Z,1552082155.622 [DUSBL:RequestRepeater](DEBUG): Aggregate::initialize DUSBL:RequestRepeater
2019-03-08T21:55:55.622Z,1552082155.622 [DUSBL:RequestRepeater:A] Running Loop=1
2019-03-08T21:55:55.622Z,1552082155.622 [DUSBL:RequestRepeater:B] Running Loop=1
2019-03-08T21:55:55.622Z,1552082155.622 [DUSBL:RequestRepeater:C.Wait] Running Loop=1
2019-03-08T21:55:55.622Z,1552082155.622 [DUSBL:RequestRepeater:C.Wait](DEBUG): Initialize Wait Component.
2019-03-08T21:55:57.207Z,1552082157.207 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-03-08T21:55:57.209Z,1552082157.209 [Micromodem](INFO): **** IS COMMANDED  IN Runnable **** 
2019-03-08T21:55:57.211Z,1552082157.211 [Micromodem](DEBUG): Nmea buf: $CCPGT,26000,28,4A1C0370,54,24000,0,0,0,0,1000,0*54

2019-03-08T21:55:57.211Z,1552082157.211 [Micromodem](IMPORTANT): Nmea buf: $CCPGT,26000,28,4A1C0370,54,24000,0,0,0,0,1000,0*54

2019-03-08T21:55:57.211Z,1552082157.211 [Micromodem](INFO): Nmea out: $CCPGT,26000,28,4A1C0370,54,24000,0,0,0,0,1000,0*54

2019-03-08T21:56:01.247Z,1552082161.247 [DUSBL_Hydroid](INFO): ****** ping requested ******
2019-03-08T21:56:01.252Z,1552082161.252 [Micromodem](INFO): **** IS COMMANDED  IN Runnable **** 
2019-03-08T21:56:01.252Z,1552082161.252 [Micromodem](DEBUG): Nmea buf: $CCPGT,26000,28,4A1C0370,54,24000,0,0,0,0,1000,0*54

2019-03-08T21:56:01.252Z,1552082161.252 [Micromodem](IMPORTANT): Nmea buf: $CCPGT,26000,28,4A1C0370,54,24000,0,0,0,0,1000,0*54

2019-03-08T21:56:01.252Z,1552082161.252 [Micromodem](INFO): Nmea out: $CCPGT,26000,28,4A1C0370,54,24000,0,0,0,0,1000,0*54

2019-03-08T21:56:03.134Z,1552082163.134 [CommandLine](IMPORTANT): got command stop
2019-03-08T21:56:03.135Z,1552082163.135 [CommandLine](IMPORTANT): Scheduling is paused
2019-03-08T21:56:03.135Z,1552082163.135 [Supervisor](INFO): Stop Mission called by CommandLine::commandStop
2019-03-08T21:56:03.298Z,1552082163.298 [MissionManager](INFO): MissionManager is completed.
2019-03-08T21:56:03.298Z,1552082163.298 [MissionManager](INFO): Uninitializing Mission DUSBL
2019-03-08T21:56:03.298Z,1552082163.298 [DUSBL] Stopped
2019-03-08T21:56:03.298Z,1552082163.298 [DUSBL](DEBUG): Aggregate::uninitialize DUSBL
2019-03-08T21:56:03.298Z,1552082163.298 [DUSBL:A.Pitch] Stopped
2019-03-08T21:56:03.298Z,1552082163.298 [DUSBL:B.SetSpeed] Stopped
2019-03-08T21:56:03.298Z,1552082163.298 [DUSBL:B.SetSpeed](DEBUG): Uninitialize.
2019-03-08T21:56:03.298Z,1552082163.298 [DUSBL:C] Stopped
2019-03-08T21:56:03.298Z,1552082163.298 [DUSBL:RequestRepeater] Stopped
2019-03-08T21:56:03.299Z,1552082163.299 [DUSBL:RequestRepeater](DEBUG): Aggregate::uninitialize DUSBL:RequestRepeater
2019-03-08T21:56:03.299Z,1552082163.299 [DUSBL:RequestRepeater:A] Stopped
2019-03-08T21:56:03.299Z,1552082163.299 [DUSBL:RequestRepeater:B] Stopped
2019-03-08T21:56:03.299Z,1552082163.299 [DUSBL:RequestRepeater:C.Wait] Stopped
2019-03-08T21:56:03.299Z,1552082163.299 [DUSBL:RequestRepeater:C.Wait](DEBUG): Uninitialize Wait Component.
2019-03-08T21:56:03.702Z,1552082163.702 [MissionManager](IMPORTANT): Started mission Default
2019-03-08T21:56:03.703Z,1552082163.703 [Default] Running Loop=1
2019-03-08T21:56:03.703Z,1552082163.703 [Default](DEBUG): Aggregate::initialize Default
2019-03-08T21:56:03.703Z,1552082163.703 [Default:B.GoToSurface] Running Loop=1
2019-03-08T21:56:03.703Z,1552082163.703 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-03-08T21:56:03.703Z,1552082163.703 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-03-08T21:56:03.703Z,1552082163.703 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-03-08T21:56:03.704Z,1552082163.704 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-03-08T21:56:03.704Z,1552082163.704 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-03-08T21:56:03.704Z,1552082163.704 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-03-08T21:56:03.705Z,1552082163.705 [Default:A.Wait] Running Loop=1
2019-03-08T21:56:03.705Z,1552082163.705 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-03-08T21:56:08.662Z,1552082168.662 [CommandLine](IMPORTANT): got command get DUSBL_Hydroid.detectionThreshold
2019-03-08T21:56:08.662Z,1552082168.662 [CommandLine](IMPORTANT): DUSBL_Hydroid.detectionThreshold 32 count
2019-03-08T21:56:17.029Z,1552082177.029 [Default:A.Wait](INFO): Done Waiting.
2019-03-08T21:56:17.029Z,1552082177.029 [Default:A.Wait] Stopped
2019-03-08T21:56:17.029Z,1552082177.029 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-03-08T21:56:17.457Z,1552082177.457 [Default:CheckIn] Running Loop=1
2019-03-08T21:56:17.457Z,1552082177.457 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-03-08T21:56:17.457Z,1552082177.457 [Default:CheckIn:Read_GPS] Running Loop=1
2019-03-08T21:56:18.211Z,1552082178.211 [NAL9602](INFO): Powering up
2019-03-08T21:56:20.295Z,1552082180.295 [CommandLine](IMPORTANT): got command configSet DUSBL_Hydroid.detectionThreshold 20.000000 count persist
2019-03-08T21:56:22.215Z,1552082182.215 [CommandLine](IMPORTANT): got command restart application
2019-03-08T21:56:23.221Z,1552082183.221 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2019-03-08T21:56:23.221Z,1552082183.221 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-03-08T21:56:23.281Z,1552082183.281 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2019-03-08T21:56:23.281Z,1552082183.281 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-03-08T21:56:23.282Z,1552082183.282 [CommandLine](INFO): Join timeout helper Thread ID is 6689
2019-03-08T21:56:23.282Z,1552082183.282 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2019-03-08T21:56:23.282Z,1552082183.282 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-03-08T21:56:23.283Z,1552082183.283 [NavChartDb](INFO): Join timeout helper Thread ID is 6690
2019-03-08T21:56:23.353Z,1552082183.353 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2019-03-08T21:56:23.353Z,1552082183.353 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-03-08T21:56:23.362Z,1552082183.362 [ComponentRegistry](INFO): Shutting down WetLabsSeaOWL_UV_A ThreadHandler
2019-03-08T21:56:23.362Z,1552082183.362 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2019-03-08T21:56:23.363Z,1552082183.363 [WetLabsSeaOWL_UV_A](INFO): Join timeout helper Thread ID is 6691
2019-03-08T21:56:23.621Z,1552082183.621 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Uninitializing protected caller thread.
2019-03-08T21:56:23.621Z,1552082183.621 [WetLabsSeaOWL_UV_A](INFO): Powering down
2019-03-08T21:56:23.622Z,1552082183.622 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2019-03-08T21:56:23.629Z,1552082183.629 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2019-03-08T21:56:23.629Z,1552082183.629 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-03-08T21:56:23.629Z,1552082183.629 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 6692
2019-03-08T21:56:23.733Z,1552082183.733 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2019-03-08T21:56:23.733Z,1552082183.733 [CTD_NeilBrown](INFO): Powering down
2019-03-08T21:56:23.745Z,1552082183.745 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-03-08T21:56:23.749Z,1552082183.749 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2019-03-08T21:56:23.749Z,1552082183.749 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-03-08T21:56:23.749Z,1552082183.749 [Radio_Surface](INFO): Join timeout helper Thread ID is 6693
2019-03-08T21:56:24.041Z,1552082184.041 [Radio_Surface](INFO): Powering down
2019-03-08T21:56:24.042Z,1552082184.042 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2019-03-08T21:56:24.042Z,1552082184.042 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-03-08T21:56:24.058Z,1552082184.058 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2019-03-08T21:56:24.058Z,1552082184.058 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-03-08T21:56:24.058Z,1552082184.058 [DataOverHttps](INFO): Join timeout helper Thread ID is 6694
2019-03-08T21:56:24.109Z,1552082184.109 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2019-03-08T21:56:24.109Z,1552082184.109 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-03-08T21:56:24.117Z,1552082184.117 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2019-03-08T21:56:24.118Z,1552082184.118 [logger ThreadHandler](INFO): Thread cancelled.
2019-03-08T21:56:24.118Z,1552082184.118 [logger](INFO): Join timeout helper Thread ID is 6695
2019-03-08T21:56:24.186Z,1552082184.186 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2019-03-08T21:56:24.186Z,1552082184.186 [logger ThreadHandler](INFO): Thread cancelled.
2019-03-08T21:56:24.197Z,1552082184.197 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2019-03-08T21:56:24.198Z,1552082184.198 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-03-08T21:56:24.198Z,1552082184.198 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2019-03-08T21:56:24.198Z,1552082184.198 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-03-08T21:56:24.198Z,1552082184.198 [controlThread](INFO): Join timeout helper Thread ID is 6696
2019-03-08T21:56:24.265Z,1552082184.265 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2019-03-08T21:56:24.265Z,1552082184.265 [controlThread](DEBUG): Uninitializing ControlThread
2019-03-08T21:56:24.266Z,1552082184.266 [DUSBL_Hydroid](INFO): Powering down
2019-03-08T21:56:24.337Z,1552082184.337 [Micromodem](INFO): uninitialize
2019-03-08T21:56:24.337Z,1552082184.337 [Micromodem](INFO): Powering down
2019-03-08T21:56:24.433Z,1552082184.433 [NAL9602](INFO): Powering down
2019-03-08T21:56:24.505Z,1552082184.505 [RDI_Pathfinder](INFO): Powering down
2019-03-08T21:56:24.506Z,1552082184.506 [RDI_PathfinderUp](INFO): Powering down
2019-03-08T21:56:24.507Z,1552082184.507 [Aanderaa_O2](INFO): Powering down
2019-03-08T21:56:24.508Z,1552082184.508 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2019-03-08T21:56:24.509Z,1552082184.509 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2019-03-08T21:56:24.510Z,1552082184.510 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2019-03-08T21:56:24.510Z,1552082184.510 [MissionManager](INFO): Uninitializing Mission Default
2019-03-08T21:56:24.510Z,1552082184.510 [Default] Stopped
2019-03-08T21:56:24.510Z,1552082184.510 [Default](DEBUG): Aggregate::uninitialize Default
2019-03-08T21:56:24.510Z,1552082184.510 [Default:B.GoToSurface] Stopped
2019-03-08T21:56:24.511Z,1552082184.511 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-03-08T21:56:24.511Z,1552082184.511 [Default:CheckIn] Stopped
2019-03-08T21:56:24.511Z,1552082184.511 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-03-08T21:56:24.511Z,1552082184.511 [Default:CheckIn:Read_GPS] Stopped
2019-03-08T21:56:24.513Z,1552082184.513 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2019-03-08T21:56:24.513Z,1552082184.513 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2019-03-08T21:56:24.514Z,1552082184.514 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2019-03-08T21:56:24.514Z,1552082184.514 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2019-03-08T21:56:24.514Z,1552082184.514 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2019-03-08T21:56:24.514Z,1552082184.514 [BuoyancyServo](INFO): Powering down
2019-03-08T21:56:24.529Z,1552082184.529 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2019-03-08T21:56:24.529Z,1552082184.529 [ElevatorServo](INFO): Powering down
2019-03-08T21:56:24.530Z,1552082184.530 [MassServo](DEBUG): Uninitialize Mass Servo.
2019-03-08T21:56:24.530Z,1552082184.530 [MassServo](INFO): Powering down
2019-03-08T21:56:24.531Z,1552082184.531 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-03-08T21:56:24.531Z,1552082184.531 [RudderServo](INFO): Powering down
2019-03-08T21:56:24.532Z,1552082184.532 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2019-03-08T21:56:24.532Z,1552082184.532 [ThrusterServo](INFO): Powering down
2019-03-08T21:56:24.533Z,1552082184.533 [SBIT](DEBUG): Uninitialize SBIT Component.
2019-03-08T21:56:24.533Z,1552082184.533 [IBIT](DEBUG): Uninitialize IBIT Component.
2019-03-08T21:56:24.533Z,1552082184.533 [CBIT](DEBUG): Uninitialize CBIT Component.
2019-03-08T21:56:24.533Z,1552082184.533 [CBIT](DEBUG): Powering off loads.
2019-03-08T21:56:24.545Z,1552082184.545 [CBIT](DEBUG): Disabling WDT.
2019-03-08T21:56:24.557Z,1552082184.557 [CBIT](DEBUG): Opening all GF detection circuits.
2019-03-08T21:56:24.558Z,1552082184.558 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-03-08T21:56:24.627Z,1552082184.627 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-03-08T21:56:24.636Z,1552082184.636 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-03-08T21:56:24.675Z,1552082184.675 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2019-03-08T21:56:24.677Z,1552082184.677 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-03-08T21:56:24.731Z,1552082184.731 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-03-08T21:56:24.798Z,1552082184.798 [logger ThreadHandler](INFO): Thread cancelled.