2020-01-17T02:22:12.622Z,1579227732.622 [Supervisor](DEBUG): Initializing supervisor.
2020-01-17T02:22:12.626Z,1579227732.626 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2020-01-17T02:22:12.626Z,1579227732.626 [SyncHandler](INFO): Protected caller Thread ID is 7549
2020-01-17T02:22:12.627Z,1579227732.627 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2020-01-17T02:22:12.628Z,1579227732.628 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2020-01-17T02:22:12.628Z,1579227732.628 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 7550
2020-01-17T02:22:12.632Z,1579227732.632 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2020-01-17T02:22:12.644Z,1579227732.644 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2020-01-17T02:22:12.645Z,1579227732.645 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2020-01-17T02:22:12.645Z,1579227732.645 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 7551
2020-01-17T02:22:12.646Z,1579227732.646 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2020-01-17T02:22:12.647Z,1579227732.647 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2020-01-17T02:22:12.647Z,1579227732.647 [logger ThreadHandler](INFO): Protected caller Thread ID is 7552
2020-01-17T02:22:12.649Z,1579227732.649 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2020-01-17T02:22:12.649Z,1579227732.649 [Supervisor](INFO): Looking for Config files in directory: Config/
2020-01-17T02:22:12.651Z,1579227732.651 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2020-01-17T02:22:13.081Z,1579227733.081 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2020-01-17T02:22:13.081Z,1579227733.081 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2020-01-17T02:22:13.194Z,1579227733.194 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2020-01-17T02:22:13.195Z,1579227733.195 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2020-01-17T02:22:13.505Z,1579227733.505 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2020-01-17T02:22:13.505Z,1579227733.505 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2020-01-17T02:22:13.642Z,1579227733.642 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2020-01-17T02:22:13.642Z,1579227733.642 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2020-01-17T02:22:13.832Z,1579227733.832 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2020-01-17T02:22:13.832Z,1579227733.832 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2020-01-17T02:22:14.269Z,1579227734.269 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2020-01-17T02:22:14.269Z,1579227734.269 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2020-01-17T02:22:14.476Z,1579227734.476 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2020-01-17T02:22:14.476Z,1579227734.476 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2020-01-17T02:22:14.619Z,1579227734.619 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2020-01-17T02:22:14.620Z,1579227734.620 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2020-01-17T02:22:14.808Z,1579227734.808 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2020-01-17T02:22:14.808Z,1579227734.808 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2020-01-17T02:22:14.905Z,1579227734.905 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2020-01-17T02:22:14.905Z,1579227734.905 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2020-01-17T02:22:15.199Z,1579227735.199 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2020-01-17T02:22:15.200Z,1579227735.200 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2020-01-17T02:22:15.281Z,1579227735.281 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2020-01-17T02:22:15.383Z,1579227735.383 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2020-01-17T02:22:15.384Z,1579227735.384 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2020-01-17T02:22:16.030Z,1579227736.030 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2020-01-17T02:22:16.030Z,1579227736.030 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2020-01-17T02:22:16.758Z,1579227736.758 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2020-01-17T02:22:16.760Z,1579227736.760 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/
2020-01-17T02:22:16.761Z,1579227736.761 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/vehicle.cfg
2020-01-17T02:22:16.971Z,1579227736.971 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Control.cfg
2020-01-17T02:22:17.071Z,1579227737.071 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/BIT.cfg
2020-01-17T02:22:17.171Z,1579227737.171 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Battery.cfg
2020-01-17T02:22:17.395Z,1579227737.395 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2020-01-17T02:22:17.396Z,1579227737.396 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Simulator.cfg
2020-01-17T02:22:17.481Z,1579227737.481 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Navigation.cfg
2020-01-17T02:22:17.574Z,1579227737.574 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/logger.cfg
2020-01-17T02:22:17.673Z,1579227737.673 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/secure.cfg
2020-01-17T02:22:17.756Z,1579227737.756 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Servo.cfg
2020-01-17T02:22:17.864Z,1579227737.864 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/workSite.cfg
2020-01-17T02:22:17.957Z,1579227737.957 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Sensor.cfg
2020-01-17T02:22:18.139Z,1579227738.139 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Science.cfg
2020-01-17T02:22:18.269Z,1579227738.269 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/root/
2020-01-17T02:22:18.269Z,1579227738.269 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2020-01-17T02:22:18.275Z,1579227738.275 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2020-01-17T02:22:18.580Z,1579227738.580 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_orientation
2020-01-17T02:22:18.585Z,1579227738.585 [AHRS_M2](INFO): created writer for : platform_orientation
2020-01-17T02:22:18.588Z,1579227738.588 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_magnetic_orientation
2020-01-17T02:22:18.592Z,1579227738.592 [AHRS_M2](INFO): created writer for : platform_magnetic_orientation
2020-01-17T02:22:18.593Z,1579227738.593 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_pitch_angle
2020-01-17T02:22:18.598Z,1579227738.598 [AHRS_M2](INFO): created writer for : platform_pitch_angle
2020-01-17T02:22:18.598Z,1579227738.598 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_roll_angle
2020-01-17T02:22:18.603Z,1579227738.603 [AHRS_M2](INFO): created writer for : platform_roll_angle
2020-01-17T02:22:18.670Z,1579227738.670 [AHRS_M2] Loaded
2020-01-17T02:22:18.670Z,1579227738.670 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2020-01-17T02:22:18.748Z,1579227738.748 [DataOverHttps] Loaded
2020-01-17T02:22:18.748Z,1579227738.748 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2020-01-17T02:22:18.749Z,1579227738.749 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 407684E0
2020-01-17T02:22:18.750Z,1579227738.750 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 7634
2020-01-17T02:22:18.772Z,1579227738.772 [DDM] Loaded
2020-01-17T02:22:18.772Z,1579227738.772 [ComponentRegistry](DEBUG): SyncComponent "DDM" handled in the control thread.
2020-01-17T02:22:18.784Z,1579227738.784 [Depth_Keller] Loaded
2020-01-17T02:22:18.785Z,1579227738.785 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2020-01-17T02:22:18.789Z,1579227738.789 [DropWeight] Loaded
2020-01-17T02:22:18.789Z,1579227738.789 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2020-01-17T02:22:18.847Z,1579227738.847 [DUSBL_Hydroid] Loaded
2020-01-17T02:22:18.847Z,1579227738.847 [ComponentRegistry](DEBUG): SyncComponent "DUSBL_Hydroid" handled in the control thread.
2020-01-17T02:22:18.891Z,1579227738.891 [Micromodem] Loaded
2020-01-17T02:22:18.891Z,1579227738.891 [ComponentRegistry](DEBUG): SyncComponent "Micromodem" handled in the control thread.
2020-01-17T02:22:18.982Z,1579227738.982 [NAL9602] Loaded
2020-01-17T02:22:18.982Z,1579227738.982 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2020-01-17T02:22:19.017Z,1579227739.017 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-0/voltage_now
2020-01-17T02:22:19.018Z,1579227739.018 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-0/current_now
2020-01-17T02:22:19.018Z,1579227739.018 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-0/charge_now
2020-01-17T02:22:19.018Z,1579227739.018 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-0/charge_full
2020-01-17T02:22:19.019Z,1579227739.019 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-1/voltage_now
2020-01-17T02:22:19.019Z,1579227739.019 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-1/current_now
2020-01-17T02:22:19.020Z,1579227739.020 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-1/charge_now
2020-01-17T02:22:19.020Z,1579227739.020 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-1/charge_full
2020-01-17T02:22:19.020Z,1579227739.020 [Onboard] Loaded
2020-01-17T02:22:19.021Z,1579227739.021 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2020-01-17T02:22:19.026Z,1579227739.026 [PowerOnly] Loaded
2020-01-17T02:22:19.027Z,1579227739.027 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread.
2020-01-17T02:22:19.033Z,1579227739.033 [Radio_Surface] Loaded
2020-01-17T02:22:19.033Z,1579227739.033 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2020-01-17T02:22:19.034Z,1579227739.034 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 407984E0
2020-01-17T02:22:19.034Z,1579227739.034 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 7635
2020-01-17T02:22:19.075Z,1579227739.075 [RDI_Pathfinder] Loaded
2020-01-17T02:22:19.075Z,1579227739.075 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2020-01-17T02:22:20.455Z,1579227740.455 [BPC1] Loaded
2020-01-17T02:22:20.455Z,1579227740.455 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2020-01-17T02:22:20.455Z,1579227740.455 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2020-01-17T02:22:20.456Z,1579227740.456 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2020-01-17T02:22:20.469Z,1579227740.469 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2020-01-17T02:22:20.470Z,1579227740.470 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2020-01-17T02:22:20.569Z,1579227740.569 [DeadReckonUsingMultipleVelocitySources] Loaded
2020-01-17T02:22:20.569Z,1579227740.569 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2020-01-17T02:22:20.588Z,1579227740.588 [NavChart] Loaded
2020-01-17T02:22:20.588Z,1579227740.588 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2020-01-17T02:22:20.592Z,1579227740.592 [UniversalFixResidualReporter] Loaded
2020-01-17T02:22:20.592Z,1579227740.592 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2020-01-17T02:22:20.593Z,1579227740.593 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2020-01-17T02:22:20.593Z,1579227740.593 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2020-01-17T02:22:20.696Z,1579227740.696 [BuoyancyServo] Loaded
2020-01-17T02:22:20.696Z,1579227740.696 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2020-01-17T02:22:20.711Z,1579227740.711 [ElevatorServo] Loaded
2020-01-17T02:22:20.711Z,1579227740.711 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2020-01-17T02:22:20.725Z,1579227740.725 [MassServo] Loaded
2020-01-17T02:22:20.725Z,1579227740.725 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2020-01-17T02:22:20.739Z,1579227740.739 [RudderServo] Loaded
2020-01-17T02:22:20.740Z,1579227740.740 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2020-01-17T02:22:20.753Z,1579227740.753 [ThrusterServo] Loaded
2020-01-17T02:22:20.753Z,1579227740.753 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2020-01-17T02:22:20.754Z,1579227740.754 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2020-01-17T02:22:20.754Z,1579227740.754 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2020-01-17T02:22:21.006Z,1579227741.006 [CTD_NeilBrown] Loaded
2020-01-17T02:22:21.006Z,1579227741.006 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2020-01-17T02:22:21.007Z,1579227741.007 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 408EC4E0
2020-01-17T02:22:21.007Z,1579227741.007 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 7636
2020-01-17T02:22:21.021Z,1579227741.021 [PAR_Licor] Loaded
2020-01-17T02:22:21.021Z,1579227741.021 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2020-01-17T02:22:21.062Z,1579227741.062 [WetLabsSeaOWL_UV_A] Loaded
2020-01-17T02:22:21.062Z,1579227741.062 [ComponentRegistry](DEBUG): Component "WetLabsSeaOWL_UV_A" handled in its own thread.
2020-01-17T02:22:21.063Z,1579227741.063 [WetLabsSeaOWL_UV_A ThreadHandler](DEBUG): Created PCaller Thread at 4091C4E0
2020-01-17T02:22:21.063Z,1579227741.063 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Protected caller Thread ID is 7637
2020-01-17T02:22:21.064Z,1579227741.064 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2020-01-17T02:22:21.064Z,1579227741.064 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2020-01-17T02:22:21.894Z,1579227741.894 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2020-01-17T02:22:21.895Z,1579227741.895 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2020-01-17T02:22:21.935Z,1579227741.935 [DepthRateCalculator] Loaded
2020-01-17T02:22:21.935Z,1579227741.935 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2020-01-17T02:22:21.940Z,1579227741.940 [PitchRateCalculator] Loaded
2020-01-17T02:22:21.940Z,1579227741.940 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2020-01-17T02:22:21.952Z,1579227741.952 [SpeedCalculator] Loaded
2020-01-17T02:22:21.952Z,1579227741.952 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2020-01-17T02:22:21.972Z,1579227741.972 [TempGradientCalculator] Loaded
2020-01-17T02:22:21.972Z,1579227741.972 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2020-01-17T02:22:21.977Z,1579227741.977 [YawRateCalculator] Loaded
2020-01-17T02:22:21.977Z,1579227741.977 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2020-01-17T02:22:22.016Z,1579227742.016 [ElevatorOffsetCalculator] Loaded
2020-01-17T02:22:22.016Z,1579227742.016 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2020-01-17T02:22:22.016Z,1579227742.016 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2020-01-17T02:22:22.017Z,1579227742.017 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2020-01-17T02:22:22.144Z,1579227742.144 [SBIT](DEBUG): Construct Startup Built In Test.
2020-01-17T02:22:22.164Z,1579227742.164 [SBIT] Loaded
2020-01-17T02:22:22.165Z,1579227742.165 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2020-01-17T02:22:22.165Z,1579227742.165 [IBIT](DEBUG): Construct Initiated Built In Test.
2020-01-17T02:22:22.177Z,1579227742.177 [IBIT] Loaded
2020-01-17T02:22:22.177Z,1579227742.177 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2020-01-17T02:22:22.180Z,1579227742.180 [CBIT](DEBUG): Construct Continuous Built In Test.
2020-01-17T02:22:22.310Z,1579227742.310 [CBIT] Loaded
2020-01-17T02:22:22.311Z,1579227742.311 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2020-01-17T02:22:22.311Z,1579227742.311 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2020-01-17T02:22:22.311Z,1579227742.311 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2020-01-17T02:22:22.393Z,1579227742.393 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2020-01-17T02:22:22.394Z,1579227742.394 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2020-01-17T02:22:22.487Z,1579227742.487 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2020-01-17T02:22:22.488Z,1579227742.488 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2020-01-17T02:22:22.534Z,1579227742.534 [VerticalControl](DEBUG): Construct VerticalControl.
2020-01-17T02:22:22.613Z,1579227742.613 [VerticalControl] Loaded
2020-01-17T02:22:22.614Z,1579227742.614 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2020-01-17T02:22:22.614Z,1579227742.614 [HorizontalControl](DEBUG): Construct HorizontalControl.
2020-01-17T02:22:22.679Z,1579227742.679 [HorizontalControl] Loaded
2020-01-17T02:22:22.680Z,1579227742.680 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2020-01-17T02:22:22.680Z,1579227742.680 [SpeedControl](DEBUG): Construct SpeedControl.
2020-01-17T02:22:22.682Z,1579227742.682 [SpeedControl] Loaded
2020-01-17T02:22:22.682Z,1579227742.682 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2020-01-17T02:22:22.683Z,1579227742.683 [LoopControl](DEBUG): Construct LoopControl.
2020-01-17T02:22:22.683Z,1579227742.683 [LoopControl] Loaded
2020-01-17T02:22:22.683Z,1579227742.683 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2020-01-17T02:22:22.684Z,1579227742.684 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2020-01-17T02:22:22.684Z,1579227742.684 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2020-01-17T02:22:22.716Z,1579227742.716 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2020-01-17T02:22:22.719Z,1579227742.719 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2020-01-17T02:22:22.720Z,1579227742.720 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2020-01-17T02:22:22.727Z,1579227742.727 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2020-01-17T02:22:22.728Z,1579227742.728 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B034E0
2020-01-17T02:22:22.728Z,1579227742.728 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 7638
2020-01-17T02:22:22.733Z,1579227742.733 [Supervisor](INFO): Main Thread ID is 6780
2020-01-17T02:22:22.733Z,1579227742.733 [Supervisor](DEBUG): Running supervisor.
2020-01-17T02:22:22.734Z,1579227742.734 [CommandLine ThreadHandler](INFO): Handler Thread ID is 7639
2020-01-17T02:22:22.736Z,1579227742.736 [controlThread ThreadHandler](INFO): Handler Thread ID is 7640
2020-01-17T02:22:22.737Z,1579227742.737 [controlThread](DEBUG): Initializing ControlThread
2020-01-17T02:22:22.745Z,1579227742.745 [NavChart](DEBUG): Initialize NavChart Navigation.
2020-01-17T02:22:22.745Z,1579227742.745 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2020-01-17T02:22:22.749Z,1579227742.749 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2020-01-17T02:22:22.749Z,1579227742.749 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2020-01-17T02:22:22.750Z,1579227742.750 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2020-01-17T02:22:22.750Z,1579227742.750 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2020-01-17T02:22:22.750Z,1579227742.750 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2020-01-17T02:22:22.751Z,1579227742.751 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2020-01-17T02:22:22.751Z,1579227742.751 [SBIT](INFO): Initialize SBIT Component.
2020-01-17T02:22:22.752Z,1579227742.752 [SBIT](IMPORTANT): git: 2019-12-03-55-gabd6466
2020-01-17T02:22:22.752Z,1579227742.752 [SBIT](INFO): git hash: abd6466b03967f3b67cd1e0718a820876be3c92a
2020-01-17T02:22:22.752Z,1579227742.752 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2020-01-17T02:22:22.754Z,1579227742.754 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #2 PREEMPT Wed May 15 08:34:03 PDT 2019
2020-01-17T02:22:22.755Z,1579227742.755 [SBIT](INFO): Beginning SBIT in 39.000000 seconds.
2020-01-17T02:22:22.755Z,1579227742.755 [IBIT](INFO): Initialize IBIT Component.
2020-01-17T02:22:22.756Z,1579227742.756 [CBIT](DEBUG): Initialize CBIT Component.
2020-01-17T02:22:22.757Z,1579227742.757 [logger ThreadHandler](INFO): Handler Thread ID is 7641
2020-01-17T02:22:22.769Z,1579227742.769 [CBIT](DEBUG): Initialized mux pins.
2020-01-17T02:22:22.769Z,1579227742.769 [CBIT](DEBUG): Initializing the watchdog timer.
2020-01-17T02:22:22.777Z,1579227742.777 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 7642
2020-01-17T02:22:22.778Z,1579227742.778 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2020-01-17T02:22:22.789Z,1579227742.789 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 7643
2020-01-17T02:22:22.793Z,1579227742.793 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2020-01-17T02:22:22.793Z,1579227742.793 [CBIT](DEBUG): Initializing heartbeat.
2020-01-17T02:22:22.801Z,1579227742.801 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 7644
2020-01-17T02:22:22.802Z,1579227742.802 [CTD_NeilBrown](INFO): Powering down
2020-01-17T02:22:22.826Z,1579227742.826 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Handler Thread ID is 7645
2020-01-17T02:22:22.826Z,1579227742.826 [WetLabsSeaOWL_UV_A](INFO): Powering down
2020-01-17T02:22:22.854Z,1579227742.854 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 7646
2020-01-17T02:22:22.857Z,1579227742.857 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2020-01-17T02:22:22.857Z,1579227742.857 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2020-01-17T02:22:22.857Z,1579227742.857 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2020-01-17T02:22:22.858Z,1579227742.858 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2020-01-17T02:22:22.858Z,1579227742.858 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2020-01-17T02:22:22.858Z,1579227742.858 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2020-01-17T02:22:22.858Z,1579227742.858 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2020-01-17T02:22:22.858Z,1579227742.858 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2020-01-17T02:22:22.858Z,1579227742.858 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2020-01-17T02:22:22.859Z,1579227742.859 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2020-01-17T02:22:22.859Z,1579227742.859 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2020-01-17T02:22:22.859Z,1579227742.859 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2020-01-17T02:22:22.859Z,1579227742.859 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2020-01-17T02:22:22.859Z,1579227742.859 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2020-01-17T02:22:22.859Z,1579227742.859 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2020-01-17T02:22:22.860Z,1579227742.860 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2020-01-17T02:22:22.865Z,1579227742.865 [CBIT](DEBUG): Deactivating GF circuits.
2020-01-17T02:22:22.865Z,1579227742.865 [CBIT](DEBUG): Deactivating emergency mode.
2020-01-17T02:22:22.901Z,1579227742.901 [CBIT](DEBUG): Backplane powered.
2020-01-17T02:22:22.901Z,1579227742.901 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2020-01-17T02:22:22.903Z,1579227742.903 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2020-01-17T02:22:22.904Z,1579227742.904 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2020-01-17T02:22:22.904Z,1579227742.904 [LoopControl](DEBUG): Initialize LoopControlComponent.
2020-01-17T02:22:22.905Z,1579227742.905 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2020-01-17T02:22:22.916Z,1579227742.916 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2020-01-17T02:22:22.962Z,1579227742.962 [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>


2020-01-17T02:22:22.963Z,1579227742.963 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2020-01-17T02:22:23.035Z,1579227743.035 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2020-01-17T02:22:23.036Z,1579227743.036 [Default:A.Wait](DEBUG): Construct Wait.
2020-01-17T02:22:23.037Z,1579227743.037 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2020-01-17T02:22:23.085Z,1579227743.085 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2020-01-17T02:22:23.088Z,1579227743.088 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2020-01-17T02:22:23.123Z,1579227743.123 [Default:E.Execute](DEBUG): Construct Execute.
2020-01-17T02:22:23.126Z,1579227743.126 [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>


2020-01-17T02:22:23.131Z,1579227743.131 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,DDM,Depth_Keller,DropWeight,DUSBL_Hydroid,Micromodem,NAL9602,Onboard,PowerOnly,RDI_Pathfinder,BPC1,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2020-01-17T02:22:23.153Z,1579227743.153 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2020-01-17T02:22:23.193Z,1579227743.193 [Radio_Surface](INFO): Powering up
2020-01-17T02:22:23.197Z,1579227743.197 [DDM](INFO): Powering up
2020-01-17T02:22:23.197Z,1579227743.197 [DDM](DEBUG): Initializing DDM.
2020-01-17T02:22:23.223Z,1579227743.223 [DUSBL_Hydroid](INFO): Powering up
2020-01-17T02:22:23.223Z,1579227743.223 [DUSBL_Hydroid](DEBUG): Initializing DUSBL_Hydroid.
2020-01-17T02:22:23.410Z,1579227743.410 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2020-01-17T02:22:23.417Z,1579227743.417 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2020-01-17T02:22:23.418Z,1579227743.418 [ElevatorServo](DEBUG): Initializing EZServoServo.
2020-01-17T02:22:23.425Z,1579227743.425 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2020-01-17T02:22:23.426Z,1579227743.426 [MassServo](DEBUG): Initializing EZServoServo.
2020-01-17T02:22:23.433Z,1579227743.433 [MassServo](DEBUG): Initializing MassServo.
2020-01-17T02:22:23.434Z,1579227743.434 [RudderServo](DEBUG): Initializing EZServoServo.
2020-01-17T02:22:23.441Z,1579227743.441 [RudderServo](DEBUG): Initializing RudderServo.
2020-01-17T02:22:23.442Z,1579227743.442 [ThrusterServo](DEBUG): Initializing EZServoServo.
2020-01-17T02:22:23.449Z,1579227743.449 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2020-01-17T02:22:23.558Z,1579227743.558 [Micromodem](INFO): Powering up
2020-01-17T02:22:23.558Z,1579227743.558 [Micromodem](DEBUG): Initializing Micromodem.
2020-01-17T02:22:24.297Z,1579227744.297 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2020-01-17T02:22:24.297Z,1579227744.297 [RudderServo](FAULT): Rudder failed to initialize
2020-01-17T02:22:24.297Z,1579227744.297 [RudderServo] Communications Fault, FailCount= 1
2020-01-17T02:22:24.297Z,1579227744.297 [RudderServo](ERROR): Communications Fault
2020-01-17T02:22:24.408Z,1579227744.408 [CBIT](ERROR): Communications Fault in component: RudderServo
2020-01-17T02:22:24.590Z,1579227744.590 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2020-01-17T02:22:24.590Z,1579227744.590 [RudderServo](INFO): Powering down
2020-01-17T02:22:25.293Z,1579227745.293 [RudderServo](DEBUG): Initializing EZServoServo.
2020-01-17T02:22:25.414Z,1579227745.414 [RudderServo](DEBUG): Initializing RudderServo.
2020-01-17T02:22:25.418Z,1579227745.418 [CBIT](INFO): Clearing failed state for component RudderServo
2020-01-17T02:22:25.418Z,1579227745.418 [RudderServo] No Fault, FailCount= 1
2020-01-17T02:22:28.497Z,1579227748.497 [Micromodem](INFO): Nmea out: $CCCFG,ALL,0*33

2020-01-17T02:22:28.908Z,1579227748.908 [Micromodem](INFO): Nmea in: $CATMG,2020-01-17T02:22:28.460767Z,RTC,RTC*5B

2020-01-17T02:22:28.908Z,1579227748.908 [Micromodem](ERROR): CFG response from modem unexpected: $CATMG,2020-01-17T02:22:28.460767Z,RTC,RTC*5B

2020-01-17T02:22:29.303Z,1579227749.303 [Micromodem](INFO): Nmea in: $CACFG,ALL,0*31

2020-01-17T02:22:29.303Z,1579227749.303 [Micromodem](INFO): Nmea out: $CCCFG,SRC,1*31

2020-01-17T02:22:29.712Z,1579227749.712 [Micromodem](INFO): Nmea in: $CACFG,SRC,1*33

2020-01-17T02:22:29.713Z,1579227749.713 [Micromodem](INFO): Nmea out: $CCCFG,nav.dt.txtrig_gpio4,1*64

2020-01-17T02:22:30.111Z,1579227750.111 [Micromodem](INFO): Nmea in: $CACFG,nav.dt.txtrig_gpio4,1*66

2020-01-17T02:22:30.112Z,1579227750.112 [Micromodem](INFO): Nmea out: $CCCFG,pwramp.txlevel,0*2F

2020-01-17T02:22:30.515Z,1579227750.515 [Micromodem](INFO): Nmea in: $CACFG,pwramp.txlevel,0*2D

2020-01-17T02:22:30.515Z,1579227750.515 [Micromodem](INFO): Nmea out: $CCCFG,DTO,30*1E

2020-01-17T02:22:30.935Z,1579227750.935 [Micromodem](INFO): Nmea in: $CACFG,DTO,30*1C

2020-01-17T02:22:30.935Z,1579227750.935 [Micromodem](INFO): Nmea out: $CCCFG,FC0,10000*46

2020-01-17T02:22:31.311Z,1579227751.311 [Micromodem](INFO): Nmea in: $CACFG,FC0,10000*44

2020-01-17T02:22:31.311Z,1579227751.311 [Micromodem](INFO): Nmea out: $CCCFG,BW0,4000*63

2020-01-17T02:22:31.732Z,1579227751.732 [Micromodem](INFO): Nmea in: $CACFG,BW0,4000*61

2020-01-17T02:22:31.732Z,1579227751.732 [Micromodem](INFO): Nmea out: $CCCFG,BND,0*3A

2020-01-17T02:22:32.107Z,1579227752.107 [Micromodem](INFO): Nmea in: $CACFG,BND,0*38

2020-01-17T02:22:32.108Z,1579227752.108 [Micromodem](INFO): Nmea out: $CCCLK,2020,01,17,02,22,33*41

2020-01-17T02:22:32.519Z,1579227752.519 [Micromodem](INFO): Nmea in: $CACLK,2020,1,17,2,22,33*43

2020-01-17T02:22:33.317Z,1579227753.317 [Micromodem](INFO): Nmea in: $CATMS,0,2020-01-17T02:22:34Z*74

2020-01-17T02:22:33.328Z,1579227753.328 [Micromodem](INFO): Nmea in: $CATMG,2020-01-17T02:22:34.026776Z,USER_CMD,RTC*11

2020-01-17T02:22:33.721Z,1579227753.721 [DDM](INFO): Dynamic Docking Module:!C REMUS Capture Rev 1.1
2020-01-17T02:22:36.568Z,1579227756.568 [RDI_Pathfinder](ERROR): Failed to parse:Pathfinder
2020-01-17T02:22:41.390Z,1579227761.390 [DUSBL_Hydroid](INFO): DUSBL Version:O
2020-01-17T02:22:49.064Z,1579227769.064 [NAL9602](INFO): Powering up NAL9602
2020-01-17T02:22:59.976Z,1579227779.976 [NAL9602](INFO): NAL9602 initialized
2020-01-17T02:23:00.835Z,1579227780.835 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2020-01-17T02:23:00.835Z,1579227780.835 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,20011619350109,35.0, -0.1,   0.0,1448.9A,  0.00,   0.00,   0.00,   0.00,   0.00
2020-01-17T02:23:02.453Z,1579227782.453 [SBIT](IMPORTANT): Beginning Startup BIT
2020-01-17T02:23:02.479Z,1579227782.479 [CBIT](IMPORTANT): Beginning ground fault scan
2020-01-17T02:23:05.090Z,1579227785.090 [CommandLine](IMPORTANT): got command strobe off
2020-01-17T02:23:05.090Z,1579227785.090 [CommandLine](IMPORTANT): Deactivating strobe
2020-01-17T02:23:10.862Z,1579227790.862 [CommandLine](IMPORTANT): got command maintain sensor NAL9602.latitude_fix 38.000000 degree
2020-01-17T02:23:10.863Z,1579227790.863 [ComponentRegistry](DEBUG): SyncComponent "Maintain_NAL9602.latitude_fix" handled in the control thread.
2020-01-17T02:23:10.864Z,1579227790.864 [CommandLine](IMPORTANT): got command maintain sensor NAL9602.longitude_fix -122.000000 degree
2020-01-17T02:23:10.865Z,1579227790.865 [ComponentRegistry](DEBUG): SyncComponent "Maintain_NAL9602.longitude_fix" handled in the control thread.
2020-01-17T02:23:11.103Z,1579227791.103 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,DDM,Depth_Keller,DropWeight,DUSBL_Hydroid,Micromodem,NAL9602,Onboard,PowerOnly,RDI_Pathfinder,BPC1,PAR_Licor,Depth_Keller,PAR_Licor,Maintain_NAL9602.latitude_fix,Maintain_NAL9602.longitude_fix,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2020-01-17T02:23:11.472Z,1579227791.472 [DeadReckonUsingMultipleVelocitySources](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2020-01-17T02:23:11.481Z,1579227791.481 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2020-01-17T02:23:11.481Z,1579227791.481 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-01-17T02:23:11.538Z,1579227791.538 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-01-17T02:23:11.937Z,1579227791.937 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-01-17T02:23:11.937Z,1579227791.937 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2020-01-17T02:23:12.694Z,1579227792.694 [DeadReckonUsingMultipleVelocitySources](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2020-01-17T02:23:12.694Z,1579227792.694 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2020-01-17T02:23:12.694Z,1579227792.694 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-01-17T02:23:12.770Z,1579227792.770 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-01-17T02:23:13.154Z,1579227793.154 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-01-17T02:23:13.154Z,1579227793.154 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2020-01-17T02:23:13.550Z,1579227793.550 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.012352
CHAN A1 (24V): -0.029076
CHAN A2 (12V): -0.007259
CHAN A3 (5V): -0.002295
CHAN B0 (3.3V): 0.000526
CHAN B1 (3.15aV): 0.000077
CHAN B2 (3.15bV): 0.000307
CHAN B3 (GND): 0.002269
OPEN: 0.005194
Full Scale Calc: 4.765 mA, -1.589 mA
2020-01-17T02:23:13.925Z,1579227793.925 [DeadReckonUsingMultipleVelocitySources](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2020-01-17T02:23:13.925Z,1579227793.925 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2020-01-17T02:23:13.925Z,1579227793.925 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-01-17T02:23:14.054Z,1579227794.054 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-01-17T02:23:14.321Z,1579227794.321 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-01-17T02:23:14.321Z,1579227794.321 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2020-01-17T02:23:15.111Z,1579227795.111 [DeadReckonUsingMultipleVelocitySources](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2020-01-17T02:23:15.111Z,1579227795.111 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2020-01-17T02:23:15.111Z,1579227795.111 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-01-17T02:23:15.128Z,1579227795.128 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-01-17T02:23:15.540Z,1579227795.540 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-01-17T02:23:15.540Z,1579227795.540 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2020-01-17T02:23:16.300Z,1579227796.300 [DeadReckonUsingMultipleVelocitySources](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2020-01-17T02:23:16.300Z,1579227796.300 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2020-01-17T02:23:16.300Z,1579227796.300 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-01-17T02:23:16.322Z,1579227796.322 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-01-17T02:23:16.764Z,1579227796.764 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-01-17T02:23:16.764Z,1579227796.764 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2020-01-17T02:23:17.542Z,1579227797.542 [DeadReckonUsingMultipleVelocitySources](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2020-01-17T02:23:17.543Z,1579227797.543 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6
2020-01-17T02:23:17.543Z,1579227797.543 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-01-17T02:23:18.077Z,1579227798.077 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-01-17T02:23:18.270Z,1579227798.270 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-01-17T02:23:18.270Z,1579227798.270 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6
2020-01-17T02:23:18.954Z,1579227798.954 [DeadReckonUsingMultipleVelocitySources](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2020-01-17T02:23:18.954Z,1579227798.954 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7
2020-01-17T02:23:18.954Z,1579227798.954 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-01-17T02:23:19.070Z,1579227799.070 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-01-17T02:23:19.486Z,1579227799.486 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-01-17T02:23:19.486Z,1579227799.486 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7
2020-01-17T02:23:20.158Z,1579227800.158 [DeadReckonUsingMultipleVelocitySources](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2020-01-17T02:23:20.158Z,1579227800.158 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8
2020-01-17T02:23:20.158Z,1579227800.158 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-01-17T02:23:20.281Z,1579227800.281 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-01-17T02:23:20.670Z,1579227800.670 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-01-17T02:23:20.670Z,1579227800.670 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8
2020-01-17T02:23:21.350Z,1579227801.350 [DeadReckonUsingMultipleVelocitySources](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2020-01-17T02:23:21.350Z,1579227801.350 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 9
2020-01-17T02:23:21.350Z,1579227801.350 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-01-17T02:23:21.462Z,1579227801.462 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-01-17T02:23:21.921Z,1579227801.921 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-01-17T02:23:21.921Z,1579227801.921 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 9
2020-01-17T02:23:22.571Z,1579227802.571 [DeadReckonUsingMultipleVelocitySources](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2020-01-17T02:23:22.571Z,1579227802.571 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 10
2020-01-17T02:23:22.571Z,1579227802.571 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-01-17T02:23:22.729Z,1579227802.729 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-01-17T02:23:23.201Z,1579227803.201 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-01-17T02:23:23.201Z,1579227803.201 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 10
2020-01-17T02:23:23.846Z,1579227803.846 [DeadReckonUsingMultipleVelocitySources](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2020-01-17T02:23:23.846Z,1579227803.846 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 11
2020-01-17T02:23:23.846Z,1579227803.846 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-01-17T02:23:23.902Z,1579227803.902 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-01-17T02:23:24.289Z,1579227804.289 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-01-17T02:23:24.289Z,1579227804.289 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 11
2020-01-17T02:23:25.016Z,1579227805.016 [DeadReckonUsingMultipleVelocitySources](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2020-01-17T02:23:25.016Z,1579227805.016 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 12
2020-01-17T02:23:25.016Z,1579227805.016 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-01-17T02:23:25.082Z,1579227805.082 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-01-17T02:23:25.445Z,1579227805.445 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-01-17T02:23:25.445Z,1579227805.445 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 12
2020-01-17T02:23:26.202Z,1579227806.202 [DeadReckonUsingMultipleVelocitySources](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2020-01-17T02:23:26.202Z,1579227806.202 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 13
2020-01-17T02:23:26.203Z,1579227806.203 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-01-17T02:23:26.266Z,1579227806.266 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-01-17T02:23:26.686Z,1579227806.686 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-01-17T02:23:26.686Z,1579227806.686 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 13
2020-01-17T02:23:27.445Z,1579227807.445 [DeadReckonUsingMultipleVelocitySources](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2020-01-17T02:23:27.445Z,1579227807.445 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 14
2020-01-17T02:23:27.445Z,1579227807.445 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-01-17T02:23:27.502Z,1579227807.502 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-01-17T02:23:27.894Z,1579227807.894 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-01-17T02:23:27.894Z,1579227807.894 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 14
2020-01-17T02:23:28.651Z,1579227808.651 [DeadReckonUsingMultipleVelocitySources](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2020-01-17T02:23:28.651Z,1579227808.651 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 15
2020-01-17T02:23:28.651Z,1579227808.651 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-01-17T02:23:28.706Z,1579227808.706 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-01-17T02:23:29.113Z,1579227809.113 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-01-17T02:23:29.113Z,1579227809.113 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 15
2020-01-17T02:23:29.860Z,1579227809.860 [DeadReckonUsingMultipleVelocitySources](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2020-01-17T02:23:29.860Z,1579227809.860 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 16
2020-01-17T02:23:29.860Z,1579227809.860 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-01-17T02:23:29.925Z,1579227809.925 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-01-17T02:23:30.326Z,1579227810.326 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-01-17T02:23:30.326Z,1579227810.326 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 16
2020-01-17T02:23:31.082Z,1579227811.082 [DeadReckonUsingMultipleVelocitySources](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2020-01-17T02:23:31.082Z,1579227811.082 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 17
2020-01-17T02:23:31.082Z,1579227811.082 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-01-17T02:23:31.152Z,1579227811.152 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-01-17T02:23:31.561Z,1579227811.561 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-01-17T02:23:31.561Z,1579227811.561 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 17
2020-01-17T02:23:32.264Z,1579227812.264 [DeadReckonUsingMultipleVelocitySources](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2020-01-17T02:23:32.264Z,1579227812.264 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 18
2020-01-17T02:23:32.264Z,1579227812.264 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-01-17T02:23:32.334Z,1579227812.334 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-01-17T02:23:32.797Z,1579227812.797 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-01-17T02:23:32.797Z,1579227812.797 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 18
2020-01-17T02:23:33.477Z,1579227813.477 [DeadReckonUsingMultipleVelocitySources](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2020-01-17T02:23:33.477Z,1579227813.477 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 19
2020-01-17T02:23:33.477Z,1579227813.477 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-01-17T02:23:33.500Z,1579227813.500 [CommandLine](IMPORTANT): got command set NAL9602.time_fix 1579227776.000000 second
2020-01-17T02:23:33.516Z,1579227813.516 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-01-17T02:23:33.910Z,1579227813.910 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-01-17T02:23:33.911Z,1579227813.911 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 19
2020-01-17T02:23:47.154Z,1579227827.154 [CommandLine](IMPORTANT): got command set NAL9602.time_fix 1579227776.000000 second
2020-01-17T02:23:55.877Z,1579227835.877 [SBIT](IMPORTANT): SBIT PASSED
2020-01-17T02:23:55.878Z,1579227835.878 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2020-01-17T02:23:55.878Z,1579227835.878 [SBIT](IMPORTANT): DDM.verbosity=3 count;

2020-01-17T02:23:55.879Z,1579227835.879 [SBIT](IMPORTANT): DUSBL_Hydroid.detectionThreshold=30 count;

2020-01-17T02:23:55.879Z,1579227835.879 [SBIT](IMPORTANT): Micromodem.sendExpress=1 bool;

2020-01-17T02:23:55.879Z,1579227835.879 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=105 cubic_centimeter;

2020-01-17T02:23:55.879Z,1579227835.879 [SBIT](IMPORTANT): VerticalControl.massDefault=-5 millimeter;

2020-01-17T02:23:56.307Z,1579227836.307 [MissionManager](IMPORTANT): Started mission Startup
2020-01-17T02:23:56.307Z,1579227836.307 [Startup] Running Loop=1
2020-01-17T02:23:56.307Z,1579227836.307 [Startup](DEBUG): Aggregate::initialize Startup
2020-01-17T02:23:56.307Z,1579227836.307 [Startup:A.GoToSurface] Running Loop=1
2020-01-17T02:23:56.308Z,1579227836.308 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-01-17T02:23:56.308Z,1579227836.308 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-01-17T02:23:56.309Z,1579227836.309 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-01-17T02:23:56.309Z,1579227836.309 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-01-17T02:23:56.310Z,1579227836.310 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-01-17T02:23:56.310Z,1579227836.310 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-01-17T02:23:56.311Z,1579227836.311 [Startup:StartupSatComms] Running Loop=1
2020-01-17T02:23:56.311Z,1579227836.311 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2020-01-17T02:23:56.311Z,1579227836.311 [Startup:StartupSatComms:A] Running Loop=1
2020-01-17T02:23:56.656Z,1579227836.656 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2020-01-17T02:23:56.657Z,1579227836.657 [Startup:StartupSatComms:A] Stopped
2020-01-17T02:23:56.657Z,1579227836.657 [Startup:StartupSatComms:B] Running Loop=1
2020-01-17T02:23:57.118Z,1579227837.118 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2020-01-17T02:24:05.275Z,1579227845.275 [CommandLine](IMPORTANT): got command set NAL9602.time_fix 1579227776.000000
2020-01-17T02:24:05.275Z,1579227845.275 [CommandLine](FAULT): Incomplete syntax. Try: help set
2020-01-17T02:24:08.838Z,1579227848.838 [CommandLine](IMPORTANT): got command set NAL9602.time_fix 1579227776.000000 second
2020-01-17T02:24:29.755Z,1579227869.755 [CommandLine](IMPORTANT): got command set NAL9602.time_fix 1579227904.000000 second
2020-01-17T02:24:37.678Z,1579227877.678 [CommandLine](IMPORTANT): got command 
2020-01-17T02:24:37.678Z,1579227877.678 [CommandLine](FAULT): Incomplete syntax. Try: help
2020-01-17T02:24:41.047Z,1579227881.047 [CommandLine](IMPORTANT): got command failComponent
2020-01-17T02:24:41.047Z,1579227881.047 [CommandLine](IMPORTANT): Failed components:
2020-01-17T02:24:41.047Z,1579227881.047 [CommandLine](IMPORTANT): No failed Components.
2020-01-17T02:24:46.447Z,1579227886.447 [CommandLine](IMPORTANT): got command show stack
2020-01-17T02:24:46.448Z,1579227886.448 [CommandLine](IMPORTANT): Behavior Stack:

2020-01-17T02:24:46.448Z,1579227886.448 [Startup](IMPORTANT): Priority 0: Startup:A.GoToSurface
2020-01-17T02:24:46.452Z,1579227886.452 [Startup:StartupSatComms](IMPORTANT): Priority 1: Startup:StartupSatComms:B
2020-01-17T02:24:52.210Z,1579227892.210 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004278
2020-01-17T02:24:56.845Z,1579227896.845 [Startup:StartupSatComms:B](INFO): Timed out from 2020-01-17T02:23:56.7Z
2020-01-17T02:24:56.845Z,1579227896.845 [Startup:StartupSatComms:B] Stopped
2020-01-17T02:24:56.846Z,1579227896.846 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2020-01-17T02:24:56.846Z,1579227896.846 [Startup:StartupSatComms] Stopped
2020-01-17T02:24:56.846Z,1579227896.846 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2020-01-17T02:24:56.846Z,1579227896.846 [Startup](INFO): Completed Startup
2020-01-17T02:24:56.847Z,1579227896.847 [MissionManager](INFO): Startup is completed.
2020-01-17T02:24:56.847Z,1579227896.847 [MissionManager](INFO): Uninitializing Mission Startup
2020-01-17T02:24:56.847Z,1579227896.847 [Startup] Stopped
2020-01-17T02:24:56.847Z,1579227896.847 [Startup](DEBUG): Aggregate::uninitialize Startup
2020-01-17T02:24:56.847Z,1579227896.847 [Startup:A.GoToSurface] Stopped
2020-01-17T02:24:56.847Z,1579227896.847 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2020-01-17T02:24:57.255Z,1579227897.255 [MissionManager](IMPORTANT): Started mission Default
2020-01-17T02:24:57.255Z,1579227897.255 [Default] Running Loop=1
2020-01-17T02:24:57.255Z,1579227897.255 [Default](DEBUG): Aggregate::initialize Default
2020-01-17T02:24:57.255Z,1579227897.255 [Default:B.GoToSurface] Running Loop=1
2020-01-17T02:24:57.255Z,1579227897.255 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-01-17T02:24:57.256Z,1579227897.256 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-01-17T02:24:57.256Z,1579227897.256 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-01-17T02:24:57.256Z,1579227897.256 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-01-17T02:24:57.256Z,1579227897.256 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-01-17T02:24:57.261Z,1579227897.261 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-01-17T02:24:57.261Z,1579227897.261 [Default:A.Wait] Running Loop=1
2020-01-17T02:24:57.261Z,1579227897.261 [Default:A.Wait](DEBUG): Initialize Wait Component.
2020-01-17T02:25:02.016Z,1579227902.016 [DataOverHttps](INFO): Sending 4542 bytes from file Logs/20200117T020507/Courier0004.lzma
2020-01-17T02:25:04.011Z,1579227904.011 [DataOverHttps](INFO): Moved sent file to Logs/20200117T020507/Courier0004.lzma.bak
2020-01-17T02:25:04.011Z,1579227904.011 [DataOverHttps](INFO): SBD MOMSN=12196362
2020-01-17T02:25:05.703Z,1579227905.703 [CommandLine](IMPORTANT): got command maintain clear
2020-01-17T02:25:05.785Z,1579227905.785 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,DDM,Depth_Keller,DropWeight,DUSBL_Hydroid,Micromodem,NAL9602,Onboard,PowerOnly,RDI_Pathfinder,BPC1,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2020-01-17T02:25:10.617Z,1579227910.617 [Default:A.Wait](INFO): Done Waiting.
2020-01-17T02:25:10.617Z,1579227910.617 [Default:A.Wait] Stopped
2020-01-17T02:25:10.617Z,1579227910.617 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2020-01-17T02:25:11.012Z,1579227911.012 [Default:CheckIn] Running Loop=1
2020-01-17T02:25:11.012Z,1579227911.012 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-01-17T02:25:11.012Z,1579227911.012 [Default:CheckIn:Read_GPS] Running Loop=1
2020-01-17T02:25:11.446Z,1579227911.446 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2020-01-17T02:25:21.119Z,1579227921.119 [CommandLine](IMPORTANT): got command load ./Missions/Docked.xml
2020-01-17T02:25:21.119Z,1579227921.119 [MissionManager](INFO): Loading Mission: ./Missions/Docked.xml
2020-01-17T02:25:21.277Z,1579227921.277 [MissionManager](INFO): DefineArg Docked.MaxDockRange = 8.000000 m
2020-01-17T02:25:21.285Z,1579227921.285 [MissionManager](INFO): DefineArg Docked.DetachedTimeout = 20.000000 s
2020-01-17T02:25:21.288Z,1579227921.288 [MissionManager](INFO): DefineArg Docked.DockedTimeout = 30.000000 s
2020-01-17T02:25:21.295Z,1579227921.295 [MissionManager](INFO): DefineArg Docked.TransponderCode = 2.000000 count
2020-01-17T02:25:21.303Z,1579227921.303 [MissionManager](INFO): DefineArg Docked.TrackingUpdatePeriod = 60.000000 s
2020-01-17T02:25:21.310Z,1579227921.310 [MissionManager](INFO): DefineArg Docked.NumberOfPings = 1.000000 count
2020-01-17T02:25:21.338Z,1579227921.338 [MissionManager](INFO): DefineArg Docked.DepthDeadband = 1.500000 m
2020-01-17T02:25:21.345Z,1579227921.345 [MissionManager](INFO): DefineArg Docked.PitchLimit = 20.000000 arcdeg
2020-01-17T02:25:21.365Z,1579227921.365 [MissionManager](INFO): DefineArg Docked.MinDepth = 1.000000 m
2020-01-17T02:25:21.378Z,1579227921.378 [MissionManager](INFO): DefineArg Docked.MaxDepth = 215.000000 m
2020-01-17T02:25:21.379Z,1579227921.379 [Docked:A.DepthEnvelope](DEBUG): Construct DepthEnvelope.
2020-01-17T02:25:21.779Z,1579227921.779 [Docked:E.Docked](DEBUG): Construct.
2020-01-17T02:25:21.807Z,1579227921.807 [Docked:G.Wait](DEBUG): Construct Wait.
2020-01-17T02:25:21.820Z,1579227921.820 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<!-- ====================
     Generated by TethysL
     ==================== -->
<Aggregate xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
           xmlns="Tethys"
           xmlns:Units="Tethys/Units"
           xmlns:Universal="Tethys/Universal"
           xmlns:BIT="Tethys/BIT"
           xmlns:Estimation="Tethys/Estimation"
           xmlns:Guidance="Tethys/Guidance"
           xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                               Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                               Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd
                               Tethys/BIT http://okeanids.mbari.org/tethys/Xml/BIT.xsd
                               Tethys/Estimation http://okeanids.mbari.org/tethys/Xml/Estimation.xsd
                               Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd"
       Id="Docked">

   <DefineArg Name="MaxDockRange"><Description>
       Maximum range allowed from the dock.
   </Description><Units:meter/><Value>8</Value></DefineArg>

   <DefineArg Name="DetachedTimeout"><Description>
       Time duration limit for determining if the vehicle is detached from the dock.
   </Description><Units:second/><Value>20</Value></DefineArg>

   <DefineArg Name="DockedTimeout"><Description>
       Time duration limit for determining if the vehicle is ON the dock.
   </Description><Units:second/><Value>30</Value></DefineArg>

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

    <DefineArg Name="TrackingUpdatePeriod"><Description>
        How long to wait between acoustic queries.
    </Description><Units:second/><Value>60</Value></DefineArg>

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

    <DefineArg Name="DepthDeadband"><Description>
        How much vertical drift from the specified depth is allowed while docked.
    </Description><Units:meter/><Value>1.5</Value></DefineArg>

    <DefineArg Name="PitchLimit"><Description>
        Max vehicle pitch (+/-) while on dock.
    </Description><Units:degree/><Value>20</Value></DefineArg>

    <DefineArg Name="MinDepth"><Description>
        Minimum depth while docked.
    </Description><Control:VerticalControl.surfaceThreshold/></DefineArg>

    <DefineArg Name="MaxDepth"><Description>
        Maximum depth while docked.
    </Description><BIT:CBIT.stopDepth/></DefineArg>


    <Sequence/>

    <Guidance:DepthEnvelope>
        <Parallel/>
        <Setting><Guidance:DepthEnvelope.minDepth/><Arg Name="MinDepth"/></Setting>
        <Setting><Guidance:DepthEnvelope.maxDepth/><Arg Name="MaxDepth"/></Setting>
    </Guidance:DepthEnvelope>

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

    <Assign><Parallel/><Control:VerticalControl.pitchLimit/><Arg Name="PitchLimit"/></Assign>
    <Assign><Parallel/><Control:VerticalControl.depthDeadband/><Arg Name="DepthDeadband"/></Assign>

    <Guidance:Docked>
        <Progression/>
        <Setting><Guidance:Docked.StopDepth/><Arg Name="MaxDepth"/></Setting>
        <Setting><Guidance:Docked.DockRange/><Arg Name="MaxDockRange"/></Setting>
        <Setting><Guidance:Docked.DetachedTimeout/><Arg Name="DetachedTimeout"/></Setting>
        <Setting><Guidance:Docked.DockedTimeout/><Arg Name="DockedTimeout"/></Setting>
    </Guidance:Docked>

    <Syslog Severity="Info">Docked satisfied!</Syslog>

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

</Aggregate>


2020-01-17T02:25:21.820Z,1579227921.820 [CommandLine](IMPORTANT): Loaded ./Missions/Docked.xml
2020-01-17T02:25:27.633Z,1579227927.633 [CommandLine](IMPORTANT): got command run
2020-01-17T02:25:27.636Z,1579227927.636 [CommandLine](IMPORTANT): Running 
2020-01-17T02:25:27.946Z,1579227927.946 [Default] Stopped
2020-01-17T02:25:27.947Z,1579227927.947 [Default](DEBUG): Aggregate::uninitialize Default
2020-01-17T02:25:27.947Z,1579227927.947 [Default:B.GoToSurface] Stopped
2020-01-17T02:25:27.947Z,1579227927.947 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2020-01-17T02:25:27.947Z,1579227927.947 [Default:CheckIn] Stopped
2020-01-17T02:25:27.947Z,1579227927.947 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-01-17T02:25:27.947Z,1579227927.947 [Default:CheckIn:Read_GPS] Stopped
2020-01-17T02:25:27.947Z,1579227927.947 [MissionManager](IMPORTANT): Started mission Docked
2020-01-17T02:25:27.947Z,1579227927.947 [Docked] Running Loop=1
2020-01-17T02:25:27.947Z,1579227927.947 [Docked](DEBUG): Aggregate::initialize Docked
2020-01-17T02:25:27.948Z,1579227927.948 [Docked:A.DepthEnvelope] Running Loop=1
2020-01-17T02:25:27.948Z,1579227927.948 [Docked:A.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent.
2020-01-17T02:25:27.948Z,1579227927.948 [Docked:B.] Running Loop=1
2020-01-17T02:25:27.948Z,1579227927.948 [Docked:B.](INFO): Initializing TrackAcousticContact.
2020-01-17T02:25:27.948Z,1579227927.948 [Docked:C] Running Loop=1
2020-01-17T02:25:27.948Z,1579227927.948 [Docked:D] Running Loop=1
2020-01-17T02:25:27.948Z,1579227927.948 [Docked:E.Docked] Running Loop=1
2020-01-17T02:25:27.948Z,1579227927.948 [Docked:E.Docked](DEBUG): Initialize.
2020-01-17T02:25:27.949Z,1579227927.949 [Docked:E.Docked](INFO): Depth unspecified. Maintaining workSite beacon depth of 6.000000 m.
2020-01-17T02:25:27.950Z,1579227927.950 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:25:27.950Z,1579227927.950 [Docked:D] Running Loop=1
2020-01-17T02:25:27.951Z,1579227927.951 [Docked:C] Running Loop=1
2020-01-17T02:25:27.951Z,1579227927.951 [Docked:B.] Running Loop=1
2020-01-17T02:25:27.951Z,1579227927.951 [Docked:A.DepthEnvelope] Running Loop=1
2020-01-17T02:25:28.357Z,1579227928.357 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:25:28.766Z,1579227928.766 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:25:29.285Z,1579227929.285 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:25:29.285Z,1579227929.285 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:25:29.683Z,1579227929.683 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:25:29.683Z,1579227929.683 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:25:30.028Z,1579227930.028 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:25:30.029Z,1579227930.029 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:25:30.487Z,1579227930.487 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:25:30.488Z,1579227930.488 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:25:30.829Z,1579227930.829 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:25:30.829Z,1579227930.829 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:25:31.267Z,1579227931.267 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:25:31.267Z,1579227931.267 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:25:31.655Z,1579227931.655 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:25:31.656Z,1579227931.656 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:25:32.043Z,1579227932.043 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:25:32.044Z,1579227932.044 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:25:32.445Z,1579227932.445 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:25:32.446Z,1579227932.446 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:25:32.850Z,1579227932.850 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:25:32.850Z,1579227932.850 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:25:33.223Z,1579227933.223 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:25:33.224Z,1579227933.224 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:25:33.652Z,1579227933.652 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:25:33.652Z,1579227933.652 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:25:34.039Z,1579227934.039 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:25:34.039Z,1579227934.039 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:25:34.454Z,1579227934.454 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:25:34.454Z,1579227934.454 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:25:34.885Z,1579227934.885 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:25:34.886Z,1579227934.886 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:25:35.272Z,1579227935.272 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:25:35.273Z,1579227935.273 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:25:35.672Z,1579227935.672 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:25:35.673Z,1579227935.673 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:25:36.062Z,1579227936.062 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:25:36.062Z,1579227936.062 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:25:36.510Z,1579227936.510 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:25:36.511Z,1579227936.511 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:25:36.855Z,1579227936.855 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:25:36.856Z,1579227936.856 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:25:37.263Z,1579227937.263 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:25:37.263Z,1579227937.263 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:25:37.686Z,1579227937.686 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:25:37.686Z,1579227937.686 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:25:38.080Z,1579227938.080 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:25:38.080Z,1579227938.080 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:25:38.522Z,1579227938.522 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:25:38.522Z,1579227938.522 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:25:38.887Z,1579227938.887 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:25:38.888Z,1579227938.888 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:25:39.288Z,1579227939.288 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:25:39.306Z,1579227939.306 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:25:39.734Z,1579227939.734 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:25:39.735Z,1579227939.735 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:25:40.105Z,1579227940.105 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:25:40.105Z,1579227940.105 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:25:40.527Z,1579227940.527 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:25:40.528Z,1579227940.528 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:25:40.925Z,1579227940.925 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:25:40.925Z,1579227940.925 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:25:41.309Z,1579227941.309 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:25:41.309Z,1579227941.309 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:25:41.726Z,1579227941.726 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:25:41.726Z,1579227941.726 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:25:42.136Z,1579227942.136 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:25:42.136Z,1579227942.136 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:25:42.562Z,1579227942.562 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:25:42.562Z,1579227942.562 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:25:43.104Z,1579227943.104 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:25:43.104Z,1579227943.104 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:25:43.368Z,1579227943.368 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:25:43.368Z,1579227943.368 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:25:43.789Z,1579227943.789 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:25:43.789Z,1579227943.789 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:25:44.164Z,1579227944.164 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:25:44.164Z,1579227944.164 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:25:44.660Z,1579227944.660 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:25:44.660Z,1579227944.660 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:25:45.012Z,1579227945.012 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:25:45.012Z,1579227945.012 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:25:45.376Z,1579227945.376 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:25:45.376Z,1579227945.376 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:25:45.806Z,1579227945.806 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:25:45.806Z,1579227945.806 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:25:46.190Z,1579227946.190 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:25:46.191Z,1579227946.191 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:25:46.586Z,1579227946.586 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:25:46.586Z,1579227946.586 [Docked:E.Docked](INFO): State switch to DETACHED. starting timer
2020-01-17T02:25:46.969Z,1579227946.969 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:25:47.416Z,1579227947.416 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:25:47.803Z,1579227947.803 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:25:48.181Z,1579227948.181 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:25:48.604Z,1579227948.604 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:25:48.979Z,1579227948.979 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:25:49.404Z,1579227949.404 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:25:49.809Z,1579227949.809 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:25:50.212Z,1579227950.212 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:25:50.630Z,1579227950.630 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:25:51.009Z,1579227951.009 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:25:51.458Z,1579227951.458 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:25:51.797Z,1579227951.797 [RDI_Pathfinder](ERROR): Failed to parse:
:RA,  0.00,   0.00,   0.00,   0.00,   0.00
2020-01-17T02:25:51.840Z,1579227951.840 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:25:52.217Z,1579227952.217 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:25:52.639Z,1579227952.639 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:25:53.024Z,1579227953.024 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:25:53.445Z,1579227953.445 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:25:53.859Z,1579227953.859 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:25:54.242Z,1579227954.242 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:25:54.646Z,1579227954.646 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:25:55.066Z,1579227955.066 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:25:55.466Z,1579227955.466 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:25:55.901Z,1579227955.901 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:25:56.325Z,1579227956.325 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:25:56.875Z,1579227956.875 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:25:57.241Z,1579227957.240 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:25:57.670Z,1579227957.670 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:25:58.096Z,1579227958.096 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:25:58.503Z,1579227958.503 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:25:58.869Z,1579227958.869 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:25:59.272Z,1579227959.272 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:25:59.660Z,1579227959.660 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:26:00.063Z,1579227960.063 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:26:00.507Z,1579227960.507 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:26:00.888Z,1579227960.888 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:26:01.276Z,1579227961.276 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:26:01.700Z,1579227961.700 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:26:02.071Z,1579227962.071 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:26:02.513Z,1579227962.513 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:26:02.898Z,1579227962.898 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:26:03.295Z,1579227963.295 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:26:03.718Z,1579227963.718 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:26:04.101Z,1579227964.101 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:26:04.512Z,1579227964.512 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:26:04.922Z,1579227964.922 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:26:05.321Z,1579227965.321 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:26:05.738Z,1579227965.738 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:26:06.155Z,1579227966.155 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:26:06.549Z,1579227966.549 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:26:06.941Z,1579227966.941 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:26:06.941Z,1579227966.941 [Docked:E.Docked](IMPORTANT): VEHICLE DETACHED FROM DOCK.
2020-01-17T02:26:06.941Z,1579227966.941 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:26:06.942Z,1579227966.941 [Docked:F] Running Loop=1
2020-01-17T02:26:07.323Z,1579227967.323 [Docked:F](INFO): Docked satisfied!
2020-01-17T02:26:07.323Z,1579227967.323 [Docked:F] Stopped
2020-01-17T02:26:07.324Z,1579227967.324 [Docked:G.Wait] Running Loop=1
2020-01-17T02:26:07.324Z,1579227967.324 [Docked:G.Wait](DEBUG): Initialize Wait Component.
2020-01-17T02:26:07.324Z,1579227967.324 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:26:07.324Z,1579227967.324 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:26:07.748Z,1579227967.748 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:26:07.748Z,1579227967.748 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:26:08.144Z,1579227968.144 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:26:08.144Z,1579227968.144 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:26:08.561Z,1579227968.561 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:26:08.562Z,1579227968.562 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:26:08.949Z,1579227968.949 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:26:08.949Z,1579227968.949 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:26:09.353Z,1579227969.353 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:26:09.353Z,1579227969.353 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:26:09.774Z,1579227969.774 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:26:09.775Z,1579227969.775 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:26:10.239Z,1579227970.239 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:26:10.239Z,1579227970.239 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:26:10.586Z,1579227970.586 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:26:10.586Z,1579227970.586 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:26:11.004Z,1579227971.004 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:26:11.021Z,1579227971.021 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:26:11.493Z,1579227971.493 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:26:11.493Z,1579227971.493 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:26:11.830Z,1579227971.830 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:26:11.830Z,1579227971.830 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:26:12.221Z,1579227972.221 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:26:12.222Z,1579227972.222 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:26:12.618Z,1579227972.618 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:26:12.618Z,1579227972.618 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:26:12.000Z,1579227973.000 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:26:12.000Z,1579227973.000 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:26:13.389Z,1579227973.389 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:26:13.389Z,1579227973.389 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:26:13.813Z,1579227973.813 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:26:13.813Z,1579227973.813 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:26:14.213Z,1579227974.213 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:26:14.214Z,1579227974.214 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:26:14.596Z,1579227974.596 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:26:14.596Z,1579227974.596 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:26:15.023Z,1579227975.023 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:26:15.023Z,1579227975.023 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:26:15.421Z,1579227975.421 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:26:15.421Z,1579227975.421 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:26:15.850Z,1579227975.850 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:26:15.850Z,1579227975.850 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:26:16.237Z,1579227976.237 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:26:16.237Z,1579227976.237 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:26:16.651Z,1579227976.651 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:26:16.651Z,1579227976.651 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:26:17.060Z,1579227977.060 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:26:17.061Z,1579227977.061 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:26:17.476Z,1579227977.476 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:26:17.476Z,1579227977.476 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:26:17.843Z,1579227977.843 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:26:17.843Z,1579227977.843 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:26:18.249Z,1579227978.249 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:26:18.250Z,1579227978.250 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:26:18.684Z,1579227978.684 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:26:18.684Z,1579227978.684 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:26:19.057Z,1579227979.057 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:26:19.057Z,1579227979.057 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:26:19.482Z,1579227979.482 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:26:19.482Z,1579227979.482 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:26:19.864Z,1579227979.864 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:26:19.864Z,1579227979.864 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:26:20.257Z,1579227980.257 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:26:20.257Z,1579227980.257 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:26:20.698Z,1579227980.698 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:26:20.698Z,1579227980.698 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:26:21.084Z,1579227981.084 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:26:21.084Z,1579227981.084 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:26:21.512Z,1579227981.512 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:26:21.512Z,1579227981.512 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:26:21.904Z,1579227981.904 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:26:21.904Z,1579227981.904 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:26:22.289Z,1579227982.289 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:26:22.289Z,1579227982.289 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:26:22.712Z,1579227982.712 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:26:22.712Z,1579227982.712 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:26:23.083Z,1579227983.083 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:26:23.083Z,1579227983.083 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:26:23.550Z,1579227983.550 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:26:23.550Z,1579227983.550 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:26:23.917Z,1579227983.917 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:26:23.917Z,1579227983.917 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:26:24.314Z,1579227984.314 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:26:24.314Z,1579227984.314 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:26:24.804Z,1579227984.804 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:26:24.804Z,1579227984.804 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:26:25.130Z,1579227985.130 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:26:25.130Z,1579227985.130 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:26:25.518Z,1579227985.518 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:26:25.518Z,1579227985.518 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:26:25.951Z,1579227985.951 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:26:25.952Z,1579227985.952 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:26:26.173Z,1579227986.173 [CommandLine](IMPORTANT): got command stop
2020-01-17T02:26:26.174Z,1579227986.174 [CommandLine](IMPORTANT): Scheduling is paused
2020-01-17T02:26:26.174Z,1579227986.174 [Supervisor](INFO): Stop Mission called by CommandLine::commandStop
2020-01-17T02:26:26.325Z,1579227986.325 [Docked:E.Docked](INFO): runIfUnsatisfied 
2020-01-17T02:26:26.325Z,1579227986.325 [Docked:E.Docked](INFO): Resetting timers 
2020-01-17T02:26:26.326Z,1579227986.326 [MissionManager](INFO): MissionManager is completed.
2020-01-17T02:26:26.326Z,1579227986.326 [MissionManager](INFO): Uninitializing Mission Docked
2020-01-17T02:26:26.327Z,1579227986.327 [Docked] Stopped
2020-01-17T02:26:26.327Z,1579227986.327 [Docked](DEBUG): Aggregate::uninitialize Docked
2020-01-17T02:26:26.327Z,1579227986.327 [Docked:A.DepthEnvelope] Stopped
2020-01-17T02:26:26.327Z,1579227986.327 [Docked:A.DepthEnvelope](DEBUG): Uninitialize.
2020-01-17T02:26:26.327Z,1579227986.327 [Docked:B.] Stopped
2020-01-17T02:26:26.327Z,1579227986.327 [Docked:C] Stopped
2020-01-17T02:26:26.327Z,1579227986.327 [Docked:D] Stopped
2020-01-17T02:26:26.327Z,1579227986.327 [Docked:E.Docked] Stopped
2020-01-17T02:26:26.327Z,1579227986.327 [Docked:G.Wait] Stopped
2020-01-17T02:26:26.327Z,1579227986.327 [Docked:G.Wait](DEBUG): Uninitialize Wait Component.
2020-01-17T02:26:26.731Z,1579227986.731 [MissionManager](IMPORTANT): Started mission Default
2020-01-17T02:26:26.731Z,1579227986.731 [Default] Running Loop=1
2020-01-17T02:26:26.731Z,1579227986.731 [Default](DEBUG): Aggregate::initialize Default
2020-01-17T02:26:26.731Z,1579227986.731 [Default:B.GoToSurface] Running Loop=1
2020-01-17T02:26:26.731Z,1579227986.731 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-01-17T02:26:26.732Z,1579227986.732 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-01-17T02:26:26.732Z,1579227986.732 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-01-17T02:26:26.732Z,1579227986.732 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-01-17T02:26:26.732Z,1579227986.732 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-01-17T02:26:26.741Z,1579227986.741 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-01-17T02:26:26.741Z,1579227986.741 [Default:A.Wait] Running Loop=1
2020-01-17T02:26:26.741Z,1579227986.741 [Default:A.Wait](DEBUG): Initialize Wait Component.
2020-01-17T02:26:40.110Z,1579228000.110 [Default:A.Wait](INFO): Done Waiting.
2020-01-17T02:26:40.110Z,1579228000.110 [Default:A.Wait] Stopped
2020-01-17T02:26:40.110Z,1579228000.110 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2020-01-17T02:26:40.530Z,1579228000.530 [Default:CheckIn] Running Loop=1
2020-01-17T02:26:40.530Z,1579228000.530 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-01-17T02:26:40.531Z,1579228000.531 [Default:CheckIn:Read_GPS] Running Loop=1
2020-01-17T02:27:05.136Z,1579228025.136 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2020-01-17T02:27:05.137Z,1579228025.137 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,20011619390509,35.0, -.0,1448.9,  0
2020-01-17T02:28:03.298Z,1579228083.298 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-01-17T02:29:29.804Z,1579228169.804 [RDI_Pathfinder](ERROR): Failed to parse:
:BE,-32768,-32768,-32768,V
2020-01-17T02:29:44.374Z,1579228184.374 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2020-01-17T02:29:44.377Z,1579228184.377 [BPC1](INFO): Received data from all battery sticks.
2020-01-17T02:30:30.815Z,1579228230.815 [RDI_Pathfinder](ERROR): Failed to parse:
:BE,-32768,-32768,-32768,V
2020-01-17T02:31:40.724Z,1579228300.724 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-01-17T02:26:40.5Z
2020-01-17T02:31:40.724Z,1579228300.724 [Default:CheckIn:Read_GPS] Stopped
2020-01-17T02:31:40.724Z,1579228300.724 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-01-17T02:31:41.128Z,1579228301.128 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2020-01-17T02:31:46.560Z,1579228306.560 [DataOverHttps](INFO): Sending 236 bytes from file Logs/20200117T022212/Courier0000.lzma
2020-01-17T02:31:48.570Z,1579228308.570 [DataOverHttps](INFO): Moved sent file to Logs/20200117T022212/Courier0000.lzma.bak
2020-01-17T02:31:48.570Z,1579228308.570 [DataOverHttps](INFO): SBD MOMSN=12196364
2020-01-17T02:32:08.121Z,1579228328.121 [DataOverHttps](INFO): Sending 716 bytes from file Logs/20200117T022212/Courier0004.lzma
2020-01-17T02:32:10.126Z,1579228330.126 [DataOverHttps](INFO): Moved sent file to Logs/20200117T022212/Courier0004.lzma.bak
2020-01-17T02:32:10.126Z,1579228330.126 [DataOverHttps](INFO): SBD MOMSN=12196367
2020-01-17T02:32:11.263Z,1579228331.263 [NAL9602](INFO): Not Powering down - fast GPS
2020-01-17T02:32:37.482Z,1579228357.482 [DataOverHttps](INFO): Sending 792 bytes from file Logs/20200117T020507/Express0001.lzma
2020-01-17T02:32:39.486Z,1579228359.486 [DataOverHttps](INFO): Moved sent file to Logs/20200117T020507/Express0001.lzma.bak
2020-01-17T02:32:39.486Z,1579228359.486 [DataOverHttps](INFO): SBD MOMSN=12196369
2020-01-17T02:33:01.073Z,1579228381.073 [DataOverHttps](INFO): Sending 529 bytes from file Logs/20200117T020507/Express0005.lzma
2020-01-17T02:33:03.078Z,1579228383.078 [DataOverHttps](INFO): Moved sent file to Logs/20200117T020507/Express0005.lzma.bak
2020-01-17T02:33:03.078Z,1579228383.078 [DataOverHttps](INFO): SBD MOMSN=12196389
2020-01-17T02:33:27.671Z,1579228407.671 [RDI_Pathfinder](ERROR): Failed to parse:
:SA,   +0.00,   +0.00,  0.00
2020-01-17T02:33:30.454Z,1579228410.454 [DataOverHttps](INFO): Sending 953 bytes from file Logs/20200117T022212/Express0001.lzma
2020-01-17T02:33:32.459Z,1579228412.459 [DataOverHttps](INFO): Moved sent file to Logs/20200117T022212/Express0001.lzma.bak
2020-01-17T02:33:32.460Z,1579228412.460 [DataOverHttps](INFO): SBD MOMSN=12196420
2020-01-17T02:33:52.893Z,1579228432.893 [DataOverHttps](INFO): Sending 615 bytes from file Logs/20200117T022212/Express0005.lzma
2020-01-17T02:33:54.898Z,1579228434.898 [DataOverHttps](INFO): Moved sent file to Logs/20200117T022212/Express0005.lzma.bak
2020-01-17T02:33:54.898Z,1579228434.898 [DataOverHttps](INFO): SBD MOMSN=12196443
2020-01-17T02:33:56.330Z,1579228436.330 [Default:CheckIn:Read_Iridium] Stopped
2020-01-17T02:33:56.331Z,1579228436.331 [Default:CheckIn:C.Wait] Running Loop=1
2020-01-17T02:33:56.331Z,1579228436.331 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-01-17T02:35:36.255Z,1579228536.255 [CommandLine](IMPORTANT): got command restart application
2020-01-17T02:35:37.261Z,1579228537.261 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2020-01-17T02:35:37.261Z,1579228537.261 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-01-17T02:35:37.425Z,1579228537.425 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2020-01-17T02:35:37.425Z,1579228537.425 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-01-17T02:35:37.427Z,1579228537.427 [CommandLine](INFO): Join timeout helper Thread ID is 7682
2020-01-17T02:35:37.428Z,1579228537.428 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2020-01-17T02:35:37.428Z,1579228537.428 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-01-17T02:35:37.430Z,1579228537.430 [NavChartDb](INFO): Join timeout helper Thread ID is 7683
2020-01-17T02:35:37.453Z,1579228537.453 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2020-01-17T02:35:37.453Z,1579228537.453 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-01-17T02:35:37.473Z,1579228537.473 [ComponentRegistry](INFO): Shutting down WetLabsSeaOWL_UV_A ThreadHandler
2020-01-17T02:35:37.473Z,1579228537.473 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2020-01-17T02:35:37.473Z,1579228537.473 [WetLabsSeaOWL_UV_A](INFO): Join timeout helper Thread ID is 7684
2020-01-17T02:35:37.657Z,1579228537.657 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Uninitializing protected caller thread.
2020-01-17T02:35:37.657Z,1579228537.657 [WetLabsSeaOWL_UV_A](INFO): Powering down
2020-01-17T02:35:37.658Z,1579228537.658 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2020-01-17T02:35:37.661Z,1579228537.661 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2020-01-17T02:35:37.661Z,1579228537.661 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2020-01-17T02:35:37.661Z,1579228537.661 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 7685
2020-01-17T02:35:37.705Z,1579228537.705 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2020-01-17T02:35:37.705Z,1579228537.705 [CTD_NeilBrown](INFO): Powering down
2020-01-17T02:35:37.717Z,1579228537.717 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2020-01-17T02:35:37.725Z,1579228537.725 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2020-01-17T02:35:37.725Z,1579228537.725 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-01-17T02:35:37.725Z,1579228537.725 [Radio_Surface](INFO): Join timeout helper Thread ID is 7686
2020-01-17T02:35:37.985Z,1579228537.985 [Radio_Surface](INFO): Powering down
2020-01-17T02:35:37.986Z,1579228537.986 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2020-01-17T02:35:37.986Z,1579228537.986 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-01-17T02:35:37.994Z,1579228537.994 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2020-01-17T02:35:37.994Z,1579228537.994 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2020-01-17T02:35:37.994Z,1579228537.994 [DataOverHttps](INFO): Join timeout helper Thread ID is 7687
2020-01-17T02:35:38.145Z,1579228538.145 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2020-01-17T02:35:38.145Z,1579228538.145 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2020-01-17T02:35:38.154Z,1579228538.154 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2020-01-17T02:35:38.154Z,1579228538.154 [logger ThreadHandler](INFO): Thread cancelled.
2020-01-17T02:35:38.154Z,1579228538.154 [logger](INFO): Join timeout helper Thread ID is 7688
2020-01-17T02:35:38.187Z,1579228538.187 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2020-01-17T02:35:38.187Z,1579228538.187 [logger ThreadHandler](INFO): Thread cancelled.
2020-01-17T02:35:38.193Z,1579228538.193 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2020-01-17T02:35:38.194Z,1579228538.194 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-01-17T02:35:38.194Z,1579228538.194 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2020-01-17T02:35:38.194Z,1579228538.194 [controlThread ThreadHandler](INFO): Thread cancelled.
2020-01-17T02:35:38.194Z,1579228538.194 [controlThread](INFO): Join timeout helper Thread ID is 7689
2020-01-17T02:35:38.497Z,1579228538.497 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2020-01-17T02:35:38.497Z,1579228538.497 [controlThread](DEBUG): Uninitializing ControlThread
2020-01-17T02:35:38.498Z,1579228538.498 [AHRS_M2](INFO): Powering down
2020-01-17T02:35:38.569Z,1579228538.569 [DDM](INFO): Powering down
2020-01-17T02:35:38.662Z,1579228538.662 [DUSBL_Hydroid](INFO): Powering down
2020-01-17T02:35:38.733Z,1579228538.733 [Micromodem](INFO): Powering down
2020-01-17T02:35:38.829Z,1579228538.829 [NAL9602](INFO): Powering down
2020-01-17T02:35:38.901Z,1579228538.901 [RDI_Pathfinder](INFO): Powering down
2020-01-17T02:35:38.902Z,1579228538.902 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2020-01-17T02:35:38.903Z,1579228538.903 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2020-01-17T02:35:38.904Z,1579228538.904 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2020-01-17T02:35:38.904Z,1579228538.904 [MissionManager](INFO): Uninitializing Mission Default
2020-01-17T02:35:38.904Z,1579228538.904 [Default] Stopped
2020-01-17T02:35:38.904Z,1579228538.904 [Default](DEBUG): Aggregate::uninitialize Default
2020-01-17T02:35:38.904Z,1579228538.904 [Default:B.GoToSurface] Stopped
2020-01-17T02:35:38.905Z,1579228538.905 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2020-01-17T02:35:38.905Z,1579228538.905 [Default:CheckIn] Stopped
2020-01-17T02:35:38.905Z,1579228538.905 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-01-17T02:35:38.905Z,1579228538.905 [Default:CheckIn:C.Wait] Stopped
2020-01-17T02:35:38.905Z,1579228538.905 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-01-17T02:35:38.907Z,1579228538.907 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2020-01-17T02:35:38.907Z,1579228538.907 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2020-01-17T02:35:38.908Z,1579228538.908 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2020-01-17T02:35:38.908Z,1579228538.908 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2020-01-17T02:35:38.908Z,1579228538.908 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2020-01-17T02:35:38.908Z,1579228538.908 [BuoyancyServo](INFO): Powering down
2020-01-17T02:35:38.921Z,1579228538.921 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2020-01-17T02:35:38.921Z,1579228538.921 [ElevatorServo](INFO): Powering down
2020-01-17T02:35:38.922Z,1579228538.922 [MassServo](DEBUG): Uninitialize Mass Servo.
2020-01-17T02:35:38.922Z,1579228538.922 [MassServo](INFO): Powering down
2020-01-17T02:35:38.923Z,1579228538.923 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2020-01-17T02:35:38.923Z,1579228538.923 [RudderServo](INFO): Powering down
2020-01-17T02:35:38.924Z,1579228538.924 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2020-01-17T02:35:38.924Z,1579228538.924 [ThrusterServo](INFO): Powering down
2020-01-17T02:35:38.924Z,1579228538.924 [SBIT](DEBUG): Uninitialize SBIT Component.
2020-01-17T02:35:38.925Z,1579228538.925 [IBIT](DEBUG): Uninitialize IBIT Component.
2020-01-17T02:35:38.925Z,1579228538.925 [CBIT](DEBUG): Uninitialize CBIT Component.
2020-01-17T02:35:38.925Z,1579228538.925 [CBIT](DEBUG): Powering off loads.
2020-01-17T02:35:38.937Z,1579228538.937 [CBIT](DEBUG): Disabling WDT.
2020-01-17T02:35:38.949Z,1579228538.949 [CBIT](DEBUG): Opening all GF detection circuits.
2020-01-17T02:35:38.950Z,1579228538.950 [controlThread ThreadHandler](INFO): Thread cancelled.
2020-01-17T02:35:38.995Z,1579228538.995 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-01-17T02:35:39.005Z,1579228539.005 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2020-01-17T02:35:39.046Z,1579228539.046 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2020-01-17T02:35:39.049Z,1579228539.049 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2020-01-17T02:35:39.109Z,1579228539.109 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-01-17T02:35:39.182Z,1579228539.182 [logger ThreadHandler](INFO): Thread cancelled.