2020-01-17T16:57:01.287Z,1579280221.287 [Supervisor](DEBUG): Initializing supervisor.
2020-01-17T16:57:01.290Z,1579280221.290 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2020-01-17T16:57:01.291Z,1579280221.291 [SyncHandler](INFO): Protected caller Thread ID is 4178
2020-01-17T16:57:01.291Z,1579280221.291 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2020-01-17T16:57:01.292Z,1579280221.292 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2020-01-17T16:57:01.292Z,1579280221.292 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 4179
2020-01-17T16:57:01.295Z,1579280221.295 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2020-01-17T16:57:01.306Z,1579280221.306 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2020-01-17T16:57:01.307Z,1579280221.307 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2020-01-17T16:57:01.308Z,1579280221.308 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 4180
2020-01-17T16:57:01.308Z,1579280221.308 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2020-01-17T16:57:01.309Z,1579280221.309 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2020-01-17T16:57:01.310Z,1579280221.310 [logger ThreadHandler](INFO): Protected caller Thread ID is 4181
2020-01-17T16:57:01.312Z,1579280221.312 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2020-01-17T16:57:01.312Z,1579280221.312 [Supervisor](INFO): Looking for Config files in directory: Config/
2020-01-17T16:57:01.314Z,1579280221.314 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2020-01-17T16:57:01.742Z,1579280221.742 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2020-01-17T16:57:01.743Z,1579280221.743 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2020-01-17T16:57:01.841Z,1579280221.841 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2020-01-17T16:57:01.842Z,1579280221.842 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2020-01-17T16:57:02.152Z,1579280222.152 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2020-01-17T16:57:02.153Z,1579280222.153 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2020-01-17T16:57:02.291Z,1579280222.291 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2020-01-17T16:57:02.291Z,1579280222.291 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2020-01-17T16:57:02.482Z,1579280222.482 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2020-01-17T16:57:02.482Z,1579280222.482 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2020-01-17T16:57:02.921Z,1579280222.921 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2020-01-17T16:57:02.922Z,1579280222.922 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2020-01-17T16:57:03.130Z,1579280223.130 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2020-01-17T16:57:03.130Z,1579280223.130 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2020-01-17T16:57:03.272Z,1579280223.272 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2020-01-17T16:57:03.273Z,1579280223.273 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2020-01-17T16:57:03.461Z,1579280223.461 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2020-01-17T16:57:03.462Z,1579280223.462 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2020-01-17T16:57:03.557Z,1579280223.557 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2020-01-17T16:57:03.558Z,1579280223.558 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2020-01-17T16:57:03.853Z,1579280223.853 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2020-01-17T16:57:03.853Z,1579280223.853 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2020-01-17T16:57:03.934Z,1579280223.934 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2020-01-17T16:57:04.036Z,1579280224.036 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2020-01-17T16:57:04.037Z,1579280224.037 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2020-01-17T16:57:04.663Z,1579280224.663 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2020-01-17T16:57:04.663Z,1579280224.663 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2020-01-17T16:57:05.140Z,1579280225.140 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2020-01-17T16:57:05.142Z,1579280225.142 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/
2020-01-17T16:57:05.142Z,1579280225.142 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/vehicle.cfg
2020-01-17T16:57:05.352Z,1579280225.352 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Control.cfg
2020-01-17T16:57:05.452Z,1579280225.452 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/BIT.cfg
2020-01-17T16:57:05.551Z,1579280225.551 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Battery.cfg
2020-01-17T16:57:05.776Z,1579280225.776 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2020-01-17T16:57:05.776Z,1579280225.776 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Simulator.cfg
2020-01-17T16:57:05.862Z,1579280225.862 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Navigation.cfg
2020-01-17T16:57:05.956Z,1579280225.956 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/logger.cfg
2020-01-17T16:57:06.055Z,1579280226.055 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/secure.cfg
2020-01-17T16:57:06.138Z,1579280226.138 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Servo.cfg
2020-01-17T16:57:06.246Z,1579280226.246 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/workSite.cfg
2020-01-17T16:57:06.376Z,1579280226.376 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Sensor.cfg
2020-01-17T16:57:06.947Z,1579280226.947 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Science.cfg
2020-01-17T16:57:07.396Z,1579280227.396 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/root/
2020-01-17T16:57:07.396Z,1579280227.396 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2020-01-17T16:57:07.402Z,1579280227.402 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2020-01-17T16:57:07.675Z,1579280227.675 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_orientation
2020-01-17T16:57:07.680Z,1579280227.680 [AHRS_M2](INFO): created writer for : platform_orientation
2020-01-17T16:57:07.682Z,1579280227.682 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_magnetic_orientation
2020-01-17T16:57:07.687Z,1579280227.687 [AHRS_M2](INFO): created writer for : platform_magnetic_orientation
2020-01-17T16:57:07.687Z,1579280227.687 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_pitch_angle
2020-01-17T16:57:07.692Z,1579280227.692 [AHRS_M2](INFO): created writer for : platform_pitch_angle
2020-01-17T16:57:07.693Z,1579280227.693 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_roll_angle
2020-01-17T16:57:07.698Z,1579280227.698 [AHRS_M2](INFO): created writer for : platform_roll_angle
2020-01-17T16:57:07.764Z,1579280227.764 [AHRS_M2] Loaded
2020-01-17T16:57:07.764Z,1579280227.764 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2020-01-17T16:57:07.843Z,1579280227.843 [DataOverHttps] Loaded
2020-01-17T16:57:07.843Z,1579280227.843 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2020-01-17T16:57:07.844Z,1579280227.844 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 407684E0
2020-01-17T16:57:07.844Z,1579280227.844 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 4264
2020-01-17T16:57:07.867Z,1579280227.867 [DDM] Loaded
2020-01-17T16:57:07.867Z,1579280227.867 [ComponentRegistry](DEBUG): SyncComponent "DDM" handled in the control thread.
2020-01-17T16:57:07.880Z,1579280227.880 [Depth_Keller] Loaded
2020-01-17T16:57:07.880Z,1579280227.880 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2020-01-17T16:57:07.884Z,1579280227.884 [DropWeight] Loaded
2020-01-17T16:57:07.884Z,1579280227.884 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2020-01-17T16:57:07.942Z,1579280227.942 [DUSBL_Hydroid] Loaded
2020-01-17T16:57:07.942Z,1579280227.942 [ComponentRegistry](DEBUG): SyncComponent "DUSBL_Hydroid" handled in the control thread.
2020-01-17T16:57:07.986Z,1579280227.986 [Micromodem] Loaded
2020-01-17T16:57:07.986Z,1579280227.986 [ComponentRegistry](DEBUG): SyncComponent "Micromodem" handled in the control thread.
2020-01-17T16:57:08.077Z,1579280228.077 [NAL9602] Loaded
2020-01-17T16:57:08.078Z,1579280228.078 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2020-01-17T16:57:08.113Z,1579280228.113 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-0/voltage_now
2020-01-17T16:57:08.113Z,1579280228.113 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-0/current_now
2020-01-17T16:57:08.114Z,1579280228.114 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-0/charge_now
2020-01-17T16:57:08.114Z,1579280228.114 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-0/charge_full
2020-01-17T16:57:08.115Z,1579280228.115 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-1/voltage_now
2020-01-17T16:57:08.115Z,1579280228.115 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-1/current_now
2020-01-17T16:57:08.115Z,1579280228.115 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-1/charge_now
2020-01-17T16:57:08.116Z,1579280228.116 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-1/charge_full
2020-01-17T16:57:08.116Z,1579280228.116 [Onboard] Loaded
2020-01-17T16:57:08.116Z,1579280228.116 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2020-01-17T16:57:08.122Z,1579280228.122 [PowerOnly] Loaded
2020-01-17T16:57:08.122Z,1579280228.122 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread.
2020-01-17T16:57:08.128Z,1579280228.128 [Radio_Surface] Loaded
2020-01-17T16:57:08.129Z,1579280228.129 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2020-01-17T16:57:08.130Z,1579280228.129 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 407984E0
2020-01-17T16:57:08.130Z,1579280228.130 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 4265
2020-01-17T16:57:08.171Z,1579280228.171 [RDI_Pathfinder] Loaded
2020-01-17T16:57:08.171Z,1579280228.171 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2020-01-17T16:57:09.557Z,1579280229.557 [BPC1] Loaded
2020-01-17T16:57:09.557Z,1579280229.557 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2020-01-17T16:57:09.558Z,1579280229.558 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2020-01-17T16:57:09.558Z,1579280229.558 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2020-01-17T16:57:09.571Z,1579280229.571 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2020-01-17T16:57:09.571Z,1579280229.571 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2020-01-17T16:57:09.670Z,1579280229.670 [DeadReckonUsingMultipleVelocitySources] Loaded
2020-01-17T16:57:09.670Z,1579280229.670 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2020-01-17T16:57:09.689Z,1579280229.689 [NavChart] Loaded
2020-01-17T16:57:09.690Z,1579280229.690 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2020-01-17T16:57:09.693Z,1579280229.693 [UniversalFixResidualReporter] Loaded
2020-01-17T16:57:09.694Z,1579280229.694 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2020-01-17T16:57:09.694Z,1579280229.694 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2020-01-17T16:57:09.695Z,1579280229.695 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2020-01-17T16:57:09.796Z,1579280229.796 [BuoyancyServo] Loaded
2020-01-17T16:57:09.797Z,1579280229.797 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2020-01-17T16:57:09.811Z,1579280229.811 [ElevatorServo] Loaded
2020-01-17T16:57:09.811Z,1579280229.811 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2020-01-17T16:57:09.826Z,1579280229.826 [MassServo] Loaded
2020-01-17T16:57:09.826Z,1579280229.826 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2020-01-17T16:57:09.840Z,1579280229.840 [RudderServo] Loaded
2020-01-17T16:57:09.840Z,1579280229.840 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2020-01-17T16:57:09.854Z,1579280229.854 [ThrusterServo] Loaded
2020-01-17T16:57:09.854Z,1579280229.854 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2020-01-17T16:57:09.855Z,1579280229.855 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2020-01-17T16:57:09.856Z,1579280229.856 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2020-01-17T16:57:10.100Z,1579280230.100 [CTD_NeilBrown] Loaded
2020-01-17T16:57:10.100Z,1579280230.100 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2020-01-17T16:57:10.101Z,1579280230.101 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 408EC4E0
2020-01-17T16:57:10.101Z,1579280230.101 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 4266
2020-01-17T16:57:10.115Z,1579280230.115 [PAR_Licor] Loaded
2020-01-17T16:57:10.115Z,1579280230.115 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2020-01-17T16:57:10.156Z,1579280230.156 [WetLabsSeaOWL_UV_A] Loaded
2020-01-17T16:57:10.157Z,1579280230.157 [ComponentRegistry](DEBUG): Component "WetLabsSeaOWL_UV_A" handled in its own thread.
2020-01-17T16:57:10.158Z,1579280230.158 [WetLabsSeaOWL_UV_A ThreadHandler](DEBUG): Created PCaller Thread at 4091C4E0
2020-01-17T16:57:10.158Z,1579280230.158 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Protected caller Thread ID is 4267
2020-01-17T16:57:10.158Z,1579280230.158 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2020-01-17T16:57:10.159Z,1579280230.159 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2020-01-17T16:57:10.471Z,1579280230.471 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2020-01-17T16:57:10.471Z,1579280230.471 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2020-01-17T16:57:10.510Z,1579280230.510 [DepthRateCalculator] Loaded
2020-01-17T16:57:10.510Z,1579280230.510 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2020-01-17T16:57:10.516Z,1579280230.516 [PitchRateCalculator] Loaded
2020-01-17T16:57:10.516Z,1579280230.516 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2020-01-17T16:57:10.528Z,1579280230.528 [SpeedCalculator] Loaded
2020-01-17T16:57:10.528Z,1579280230.528 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2020-01-17T16:57:10.547Z,1579280230.547 [TempGradientCalculator] Loaded
2020-01-17T16:57:10.548Z,1579280230.548 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2020-01-17T16:57:10.553Z,1579280230.553 [YawRateCalculator] Loaded
2020-01-17T16:57:10.553Z,1579280230.553 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2020-01-17T16:57:10.592Z,1579280230.592 [ElevatorOffsetCalculator] Loaded
2020-01-17T16:57:10.592Z,1579280230.592 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2020-01-17T16:57:10.593Z,1579280230.593 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2020-01-17T16:57:10.593Z,1579280230.593 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2020-01-17T16:57:10.720Z,1579280230.720 [SBIT](DEBUG): Construct Startup Built In Test.
2020-01-17T16:57:10.740Z,1579280230.740 [SBIT] Loaded
2020-01-17T16:57:10.740Z,1579280230.740 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2020-01-17T16:57:10.741Z,1579280230.741 [IBIT](DEBUG): Construct Initiated Built In Test.
2020-01-17T16:57:10.753Z,1579280230.753 [IBIT] Loaded
2020-01-17T16:57:10.753Z,1579280230.753 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2020-01-17T16:57:10.756Z,1579280230.756 [CBIT](DEBUG): Construct Continuous Built In Test.
2020-01-17T16:57:10.888Z,1579280230.888 [CBIT] Loaded
2020-01-17T16:57:10.888Z,1579280230.888 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2020-01-17T16:57:10.889Z,1579280230.889 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2020-01-17T16:57:10.889Z,1579280230.889 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2020-01-17T16:57:10.967Z,1579280230.967 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2020-01-17T16:57:10.968Z,1579280230.968 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2020-01-17T16:57:11.060Z,1579280231.060 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2020-01-17T16:57:11.060Z,1579280231.060 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2020-01-17T16:57:11.106Z,1579280231.106 [VerticalControl](DEBUG): Construct VerticalControl.
2020-01-17T16:57:11.186Z,1579280231.186 [VerticalControl] Loaded
2020-01-17T16:57:11.187Z,1579280231.187 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2020-01-17T16:57:11.187Z,1579280231.187 [HorizontalControl](DEBUG): Construct HorizontalControl.
2020-01-17T16:57:11.252Z,1579280231.252 [HorizontalControl] Loaded
2020-01-17T16:57:11.252Z,1579280231.252 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2020-01-17T16:57:11.253Z,1579280231.253 [SpeedControl](DEBUG): Construct SpeedControl.
2020-01-17T16:57:11.255Z,1579280231.255 [SpeedControl] Loaded
2020-01-17T16:57:11.255Z,1579280231.255 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2020-01-17T16:57:11.255Z,1579280231.255 [LoopControl](DEBUG): Construct LoopControl.
2020-01-17T16:57:11.256Z,1579280231.256 [LoopControl] Loaded
2020-01-17T16:57:11.256Z,1579280231.256 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2020-01-17T16:57:11.257Z,1579280231.257 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2020-01-17T16:57:11.257Z,1579280231.257 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2020-01-17T16:57:11.288Z,1579280231.288 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2020-01-17T16:57:11.291Z,1579280231.291 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2020-01-17T16:57:11.292Z,1579280231.292 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2020-01-17T16:57:11.298Z,1579280231.298 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2020-01-17T16:57:11.299Z,1579280231.299 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B034E0
2020-01-17T16:57:11.300Z,1579280231.300 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 4268
2020-01-17T16:57:11.304Z,1579280231.304 [Supervisor](INFO): Main Thread ID is 4177
2020-01-17T16:57:11.304Z,1579280231.304 [Supervisor](DEBUG): Running supervisor.
2020-01-17T16:57:11.305Z,1579280231.305 [CommandLine ThreadHandler](INFO): Handler Thread ID is 4269
2020-01-17T16:57:11.307Z,1579280231.307 [controlThread ThreadHandler](INFO): Handler Thread ID is 4270
2020-01-17T16:57:11.308Z,1579280231.308 [controlThread](DEBUG): Initializing ControlThread
2020-01-17T16:57:11.316Z,1579280231.316 [NavChart](DEBUG): Initialize NavChart Navigation.
2020-01-17T16:57:11.316Z,1579280231.316 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2020-01-17T16:57:11.321Z,1579280231.321 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2020-01-17T16:57:11.322Z,1579280231.322 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2020-01-17T16:57:11.322Z,1579280231.322 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2020-01-17T16:57:11.322Z,1579280231.322 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2020-01-17T16:57:11.323Z,1579280231.323 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2020-01-17T16:57:11.323Z,1579280231.323 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2020-01-17T16:57:11.324Z,1579280231.324 [SBIT](INFO): Initialize SBIT Component.
2020-01-17T16:57:11.324Z,1579280231.324 [SBIT](IMPORTANT): git: 2019-12-03-55-gabd6466
2020-01-17T16:57:11.324Z,1579280231.324 [SBIT](INFO): git hash: abd6466b03967f3b67cd1e0718a820876be3c92a
2020-01-17T16:57:11.325Z,1579280231.325 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2020-01-17T16:57:11.326Z,1579280231.326 [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-17T16:57:11.327Z,1579280231.327 [SBIT](INFO): Beginning SBIT in 39.000000 seconds.
2020-01-17T16:57:11.328Z,1579280231.328 [IBIT](INFO): Initialize IBIT Component.
2020-01-17T16:57:11.328Z,1579280231.328 [CBIT](DEBUG): Initialize CBIT Component.
2020-01-17T16:57:11.329Z,1579280231.329 [logger ThreadHandler](INFO): Handler Thread ID is 4271
2020-01-17T16:57:11.341Z,1579280231.341 [CBIT](DEBUG): Initialized mux pins.
2020-01-17T16:57:11.341Z,1579280231.341 [CBIT](DEBUG): Initializing the watchdog timer.
2020-01-17T16:57:11.349Z,1579280231.349 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 4272
2020-01-17T16:57:11.350Z,1579280231.350 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2020-01-17T16:57:11.361Z,1579280231.361 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 4273
2020-01-17T16:57:11.365Z,1579280231.365 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2020-01-17T16:57:11.365Z,1579280231.365 [CBIT](DEBUG): Initializing heartbeat.
2020-01-17T16:57:11.373Z,1579280231.373 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 4274
2020-01-17T16:57:11.374Z,1579280231.374 [CTD_NeilBrown](INFO): Powering down
2020-01-17T16:57:11.401Z,1579280231.401 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Handler Thread ID is 4275
2020-01-17T16:57:11.402Z,1579280231.402 [WetLabsSeaOWL_UV_A](INFO): Powering down
2020-01-17T16:57:11.425Z,1579280231.425 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 4276
2020-01-17T16:57:11.428Z,1579280231.428 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2020-01-17T16:57:11.428Z,1579280231.428 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2020-01-17T16:57:11.428Z,1579280231.428 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2020-01-17T16:57:11.429Z,1579280231.429 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2020-01-17T16:57:11.430Z,1579280231.430 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2020-01-17T16:57:11.430Z,1579280231.430 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2020-01-17T16:57:11.430Z,1579280231.430 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2020-01-17T16:57:11.430Z,1579280231.430 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2020-01-17T16:57:11.430Z,1579280231.430 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2020-01-17T16:57:11.431Z,1579280231.431 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2020-01-17T16:57:11.431Z,1579280231.431 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2020-01-17T16:57:11.431Z,1579280231.431 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2020-01-17T16:57:11.431Z,1579280231.431 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2020-01-17T16:57:11.431Z,1579280231.431 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2020-01-17T16:57:11.431Z,1579280231.431 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2020-01-17T16:57:11.432Z,1579280231.432 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2020-01-17T16:57:11.437Z,1579280231.437 [CBIT](DEBUG): Deactivating GF circuits.
2020-01-17T16:57:11.437Z,1579280231.437 [CBIT](DEBUG): Deactivating emergency mode.
2020-01-17T16:57:11.473Z,1579280231.473 [CBIT](DEBUG): Backplane powered.
2020-01-17T16:57:11.473Z,1579280231.473 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2020-01-17T16:57:11.475Z,1579280231.475 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2020-01-17T16:57:11.475Z,1579280231.475 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2020-01-17T16:57:11.476Z,1579280231.476 [LoopControl](DEBUG): Initialize LoopControlComponent.
2020-01-17T16:57:11.477Z,1579280231.477 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2020-01-17T16:57:11.488Z,1579280231.488 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2020-01-17T16:57:11.498Z,1579280231.498 [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-17T16:57:11.499Z,1579280231.499 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2020-01-17T16:57:11.644Z,1579280231.644 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2020-01-17T16:57:11.645Z,1579280231.645 [Default:A.Wait](DEBUG): Construct Wait.
2020-01-17T16:57:11.647Z,1579280231.647 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2020-01-17T16:57:11.694Z,1579280231.694 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2020-01-17T16:57:11.697Z,1579280231.697 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2020-01-17T16:57:11.719Z,1579280231.719 [Default:E.Execute](DEBUG): Construct Execute.
2020-01-17T16:57:11.734Z,1579280231.734 [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-17T16:57:11.739Z,1579280231.739 [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-17T16:57:11.754Z,1579280231.754 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2020-01-17T16:57:11.765Z,1579280231.765 [Radio_Surface](INFO): Powering up
2020-01-17T16:57:11.793Z,1579280231.793 [DDM](INFO): Powering up
2020-01-17T16:57:11.793Z,1579280231.793 [DDM](DEBUG): Initializing DDM.
2020-01-17T16:57:11.819Z,1579280231.819 [DUSBL_Hydroid](INFO): Powering up
2020-01-17T16:57:11.819Z,1579280231.819 [DUSBL_Hydroid](DEBUG): Initializing DUSBL_Hydroid.
2020-01-17T16:57:12.049Z,1579280232.049 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2020-01-17T16:57:12.053Z,1579280232.053 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2020-01-17T16:57:12.054Z,1579280232.054 [ElevatorServo](DEBUG): Initializing EZServoServo.
2020-01-17T16:57:12.061Z,1579280232.061 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2020-01-17T16:57:12.062Z,1579280232.062 [MassServo](DEBUG): Initializing EZServoServo.
2020-01-17T16:57:12.069Z,1579280232.069 [MassServo](DEBUG): Initializing MassServo.
2020-01-17T16:57:12.070Z,1579280232.070 [RudderServo](DEBUG): Initializing EZServoServo.
2020-01-17T16:57:12.077Z,1579280232.077 [RudderServo](DEBUG): Initializing RudderServo.
2020-01-17T16:57:12.078Z,1579280232.078 [ThrusterServo](DEBUG): Initializing EZServoServo.
2020-01-17T16:57:12.085Z,1579280232.085 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2020-01-17T16:57:12.179Z,1579280232.179 [Micromodem](INFO): Powering up
2020-01-17T16:57:12.180Z,1579280232.180 [Micromodem](DEBUG): Initializing Micromodem.
2020-01-17T16:57:12.929Z,1579280232.929 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2020-01-17T16:57:12.929Z,1579280232.929 [RudderServo](FAULT): Rudder failed to initialize
2020-01-17T16:57:12.929Z,1579280232.929 [RudderServo] Communications Fault, FailCount= 1
2020-01-17T16:57:12.929Z,1579280232.929 [RudderServo](ERROR): Communications Fault
2020-01-17T16:57:13.040Z,1579280233.040 [CBIT](ERROR): Communications Fault in component: RudderServo
2020-01-17T16:57:13.214Z,1579280233.214 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2020-01-17T16:57:13.214Z,1579280233.214 [RudderServo](INFO): Powering down
2020-01-17T16:57:13.917Z,1579280233.917 [RudderServo](DEBUG): Initializing EZServoServo.
2020-01-17T16:57:14.034Z,1579280234.034 [RudderServo](DEBUG): Initializing RudderServo.
2020-01-17T16:57:14.038Z,1579280234.038 [CBIT](INFO): Clearing failed state for component RudderServo
2020-01-17T16:57:14.038Z,1579280234.038 [RudderServo] No Fault, FailCount= 1
2020-01-17T16:57:17.129Z,1579280237.129 [Micromodem](INFO): Nmea out: $CCCFG,ALL,0*33

2020-01-17T16:57:17.532Z,1579280237.532 [Micromodem](INFO): Nmea in: $CATMG,2020-01-17T16:57:17.103510Z,RTC,RTC*52

2020-01-17T16:57:17.532Z,1579280237.532 [Micromodem](ERROR): CFG response from modem unexpected: $CATMG,2020-01-17T16:57:17.103510Z,RTC,RTC*52

2020-01-17T16:57:17.935Z,1579280237.935 [Micromodem](INFO): Nmea in: $CACFG,ALL,0*31

2020-01-17T16:57:17.935Z,1579280237.935 [Micromodem](INFO): Nmea out: $CCCFG,SRC,1*31

2020-01-17T16:57:18.339Z,1579280238.339 [Micromodem](INFO): Nmea in: $CACFG,SRC,1*33

2020-01-17T16:57:18.339Z,1579280238.339 [Micromodem](INFO): Nmea out: $CCCFG,nav.dt.txtrig_gpio4,1*64

2020-01-17T16:57:18.747Z,1579280238.747 [Micromodem](INFO): Nmea in: $CACFG,nav.dt.txtrig_gpio4,1*66

2020-01-17T16:57:18.748Z,1579280238.748 [Micromodem](INFO): Nmea out: $CCCFG,pwramp.txlevel,0*2F

2020-01-17T16:57:19.151Z,1579280239.151 [Micromodem](INFO): Nmea in: $CACFG,pwramp.txlevel,0*2D

2020-01-17T16:57:19.151Z,1579280239.151 [Micromodem](INFO): Nmea out: $CCCFG,DTO,30*1E

2020-01-17T16:57:19.555Z,1579280239.555 [Micromodem](INFO): Nmea in: $CACFG,DTO,30*1C

2020-01-17T16:57:19.555Z,1579280239.555 [Micromodem](INFO): Nmea out: $CCCFG,FC0,10000*46

2020-01-17T16:57:19.956Z,1579280239.956 [Micromodem](INFO): Nmea in: $CACFG,FC0,10000*44

2020-01-17T16:57:19.956Z,1579280239.956 [Micromodem](INFO): Nmea out: $CCCFG,BW0,4000*63

2020-01-17T16:57:20.360Z,1579280240.360 [Micromodem](INFO): Nmea in: $CACFG,BW0,4000*61

2020-01-17T16:57:20.360Z,1579280240.360 [Micromodem](INFO): Nmea out: $CCCFG,BND,0*3A

2020-01-17T16:57:20.742Z,1579280240.742 [Micromodem](INFO): Nmea in: $CACFG,BND,0*38

2020-01-17T16:57:20.742Z,1579280240.742 [Micromodem](INFO): Nmea out: $CCCLK,2020,01,17,16,57,21*45

2020-01-17T16:57:21.193Z,1579280241.193 [Micromodem](INFO): Nmea in: $CACLK,2020,1,17,16,57,21*77

2020-01-17T16:57:21.195Z,1579280241.195 [Micromodem](INFO): Nmea in: $CATMS,0,2020-01-17T16:57:22Z*74

2020-01-17T16:57:21.196Z,1579280241.196 [Micromodem](INFO): Nmea in: $CATMG,2020-01-17T16:57:22.027707Z,USER_CMD,RTC*16

2020-01-17T16:57:22.371Z,1579280242.371 [DDM](INFO): Dynamic Docking Module:Q
2020-01-17T16:57:25.595Z,1579280245.595 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004397
2020-01-17T16:57:25.602Z,1579280245.602 [RDI_Pathfinder](ERROR): Failed to parse:Pathfinder
2020-01-17T16:57:30.022Z,1579280250.022 [DUSBL_Hydroid](INFO): DUSBL Version:O
2020-01-17T16:57:30.456Z,1579280250.456 [RDI_Pathfinder](ERROR): Failed to parse:
    +0.00,        +0.00,        +0.00,   0.00,  4.00
2020-01-17T16:57:38.103Z,1579280258.103 [NAL9602](INFO): Powering up NAL9602
2020-01-17T16:57:44.626Z,1579280264.626 [RDI_Pathfinder](ERROR): Failed to parse:
:BE,-3276,-32768,V
2020-01-17T16:57:49.023Z,1579280269.023 [NAL9602](INFO): NAL9602 initialized
2020-01-17T16:57:50.742Z,1579280270.742 [SBIT](IMPORTANT): Beginning Startup BIT
2020-01-17T16:57:50.746Z,1579280270.746 [CBIT](IMPORTANT): Beginning ground fault scan
2020-01-17T16:57:58.618Z,1579280278.618 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2020-01-17T16:57:58.618Z,1579280278.618 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,20011710095953,35.0, -00,1448.9,  0
2020-01-17T16:58:01.561Z,1579280281.561 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.018049
CHAN A1 (24V): -0.028600
CHAN A2 (12V): -0.007701
CHAN A3 (5V): -0.003063
CHAN B0 (3.3V): 0.000690
CHAN B1 (3.15aV): 0.000735
CHAN B2 (3.15bV): 0.000167
CHAN B3 (GND): 0.002209
OPEN: 0.004979
Full Scale Calc: 4.765 mA, -1.589 mA
2020-01-17T16:58:10.203Z,1579280290.203 [CommandLine](IMPORTANT): got command strobe off
2020-01-17T16:58:10.203Z,1579280290.203 [CommandLine](IMPORTANT): Deactivating strobe
2020-01-17T16:58:29.618Z,1579280309.618 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2020-01-17T16:58:29.619Z,1579280309.619 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,20011710103053,35.0, -0.1,448.9,  0
2020-01-17T16:58:44.362Z,1579280324.362 [SBIT](IMPORTANT): SBIT PASSED
2020-01-17T16:58:44.362Z,1579280324.362 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2020-01-17T16:58:44.363Z,1579280324.363 [SBIT](IMPORTANT): DDM.verbosity=3 count;

2020-01-17T16:58:44.363Z,1579280324.363 [SBIT](IMPORTANT): DUSBL_Hydroid.detectionThreshold=30 count;

2020-01-17T16:58:44.363Z,1579280324.363 [SBIT](IMPORTANT): Micromodem.sendExpress=1 bool;

2020-01-17T16:58:44.364Z,1579280324.364 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=105 cubic_centimeter;

2020-01-17T16:58:44.364Z,1579280324.364 [SBIT](IMPORTANT): VerticalControl.massDefault=-5 millimeter;

2020-01-17T16:58:44.754Z,1579280324.754 [MissionManager](IMPORTANT): Started mission Startup
2020-01-17T16:58:44.754Z,1579280324.754 [Startup] Running Loop=1
2020-01-17T16:58:44.754Z,1579280324.754 [Startup](DEBUG): Aggregate::initialize Startup
2020-01-17T16:58:44.754Z,1579280324.754 [Startup:A.GoToSurface] Running Loop=1
2020-01-17T16:58:44.754Z,1579280324.754 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-01-17T16:58:44.755Z,1579280324.755 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-01-17T16:58:44.756Z,1579280324.756 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-01-17T16:58:44.756Z,1579280324.756 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-01-17T16:58:44.756Z,1579280324.756 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-01-17T16:58:44.756Z,1579280324.756 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-01-17T16:58:44.758Z,1579280324.758 [Startup:StartupSatComms] Running Loop=1
2020-01-17T16:58:44.758Z,1579280324.758 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2020-01-17T16:58:44.758Z,1579280324.758 [Startup:StartupSatComms:A] Running Loop=1
2020-01-17T16:58:45.168Z,1579280325.168 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2020-01-17T16:59:44.947Z,1579280384.947 [Startup:StartupSatComms:A](INFO): Timed out from 2020-01-17T16:58:44.8Z
2020-01-17T16:59:44.947Z,1579280384.947 [Startup:StartupSatComms:A] Stopped
2020-01-17T16:59:44.947Z,1579280384.947 [Startup:StartupSatComms:B] Running Loop=1
2020-01-17T16:59:45.351Z,1579280385.351 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2020-01-17T16:59:54.212Z,1579280394.212 [DataOverHttps](INFO): Sending 1327 bytes from file Logs/20200117T030155/Courier0004.lzma
2020-01-17T16:59:56.214Z,1579280396.214 [DataOverHttps](INFO): Moved sent file to Logs/20200117T030155/Courier0004.lzma.bak
2020-01-17T16:59:56.215Z,1579280396.215 [DataOverHttps](INFO): SBD MOMSN=12196545
2020-01-17T17:00:11.609Z,1579280411.609 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2020-01-17T17:00:11.609Z,1579280411.609 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-01-17T17:00:11.619Z,1579280411.619 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-01-17T17:00:12.034Z,1579280412.034 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-01-17T17:00:12.034Z,1579280412.034 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2020-01-17T17:00:16.388Z,1579280416.388 [DataOverHttps](INFO): Sending 182 bytes from file Logs/20200117T165701/Courier0000.lzma
2020-01-17T17:00:16.534Z,1579280416.534 [CommandLine](IMPORTANT): got command run ./Missions/Docked.xml
2020-01-17T17:00:16.534Z,1579280416.534 [MissionManager](INFO): Loading Mission: ./Missions/Docked.xml
2020-01-17T17:00:16.578Z,1579280416.578 [MissionManager](INFO): DefineArg Docked.MaxDockRange = 8.000000 m
2020-01-17T17:00:16.598Z,1579280416.598 [MissionManager](INFO): DefineArg Docked.DetachedTimeout = 20.000000 s
2020-01-17T17:00:16.605Z,1579280416.605 [MissionManager](INFO): DefineArg Docked.DockedTimeout = 30.000000 s
2020-01-17T17:00:16.613Z,1579280416.613 [MissionManager](INFO): DefineArg Docked.TransponderCode = 2.000000 count
2020-01-17T17:00:16.616Z,1579280416.616 [MissionManager](INFO): DefineArg Docked.TrackingUpdatePeriod = 60.000000 s
2020-01-17T17:00:16.624Z,1579280416.624 [MissionManager](INFO): DefineArg Docked.NumberOfPings = 1.000000 count
2020-01-17T17:00:16.635Z,1579280416.635 [MissionManager](INFO): DefineArg Docked.DepthDeadband = 1.500000 m
2020-01-17T17:00:16.639Z,1579280416.639 [MissionManager](INFO): DefineArg Docked.PitchLimit = 20.000000 arcdeg
2020-01-17T17:00:16.656Z,1579280416.656 [MissionManager](INFO): DefineArg Docked.MinDepth = 1.000000 m
2020-01-17T17:00:16.669Z,1579280416.669 [MissionManager](INFO): DefineArg Docked.MaxDepth = 215.000000 m
2020-01-17T17:00:16.670Z,1579280416.670 [Docked:A.DepthEnvelope](DEBUG): Construct DepthEnvelope.
2020-01-17T17:00:16.975Z,1579280416.975 [Docked:E.Docked](DEBUG): Construct.
2020-01-17T17:00:16.991Z,1579280416.991 [Docked:G.Wait](DEBUG): Construct Wait.
2020-01-17T17:00:17.005Z,1579280417.005 [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-17T17:00:17.007Z,1579280417.007 [CommandLine](IMPORTANT): Running ./Missions/Docked.xml
2020-01-17T17:00:18.394Z,1579280418.394 [DataOverHttps](INFO): Moved sent file to Logs/20200117T165701/Courier0000.lzma.bak
2020-01-17T17:00:18.394Z,1579280418.394 [DataOverHttps](INFO): SBD MOMSN=12196547
2020-01-17T17:00:23.653Z,1579280423.653 [CommandLine](IMPORTANT): got command show stack
2020-01-17T17:00:23.654Z,1579280423.654 [CommandLine](IMPORTANT): Behavior Stack:

2020-01-17T17:00:23.654Z,1579280423.654 [Startup](IMPORTANT): Priority 0: Startup:A.GoToSurface
2020-01-17T17:00:23.654Z,1579280423.654 [Startup:StartupSatComms](IMPORTANT): Priority 1: Startup:StartupSatComms:B
2020-01-17T17:00:40.729Z,1579280440.729 [DataOverHttps](INFO): Sending 472 bytes from file Logs/20200117T030155/Express0005.lzma
2020-01-17T17:00:42.734Z,1579280442.734 [DataOverHttps](INFO): Moved sent file to Logs/20200117T030155/Express0005.lzma.bak
2020-01-17T17:00:42.735Z,1579280442.735 [DataOverHttps](INFO): SBD MOMSN=12196550
2020-01-17T17:00:45.143Z,1579280445.143 [Startup:StartupSatComms:B](INFO): Timed out from 2020-01-17T16:59:44.9Z
2020-01-17T17:00:45.143Z,1579280445.143 [Startup:StartupSatComms:B] Stopped
2020-01-17T17:00:45.143Z,1579280445.143 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2020-01-17T17:00:45.143Z,1579280445.143 [Startup:StartupSatComms] Stopped
2020-01-17T17:00:45.143Z,1579280445.143 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2020-01-17T17:00:45.144Z,1579280445.144 [Startup](INFO): Completed Startup
2020-01-17T17:00:45.144Z,1579280445.144 [MissionManager](INFO): Startup is completed.
2020-01-17T17:00:45.144Z,1579280445.144 [MissionManager](INFO): Uninitializing Mission Startup
2020-01-17T17:00:45.145Z,1579280445.145 [Startup] Stopped
2020-01-17T17:00:45.145Z,1579280445.145 [Startup](DEBUG): Aggregate::uninitialize Startup
2020-01-17T17:00:45.145Z,1579280445.145 [Startup:A.GoToSurface] Stopped
2020-01-17T17:00:45.145Z,1579280445.145 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2020-01-17T17:00:45.562Z,1579280445.562 [MissionManager](IMPORTANT): Started mission Docked
2020-01-17T17:00:45.562Z,1579280445.562 [Docked] Running Loop=1
2020-01-17T17:00:45.562Z,1579280445.562 [Docked](DEBUG): Aggregate::initialize Docked
2020-01-17T17:00:45.562Z,1579280445.562 [Docked:A.DepthEnvelope] Running Loop=1
2020-01-17T17:00:45.562Z,1579280445.562 [Docked:A.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent.
2020-01-17T17:00:45.562Z,1579280445.562 [Docked:B.] Running Loop=1
2020-01-17T17:00:45.562Z,1579280445.562 [Docked:B.](INFO): Initializing TrackAcousticContact.
2020-01-17T17:00:45.563Z,1579280445.563 [Docked:C] Running Loop=1
2020-01-17T17:00:45.563Z,1579280445.563 [Docked:D] Running Loop=1
2020-01-17T17:00:45.563Z,1579280445.563 [Docked:E.Docked] Running Loop=1
2020-01-17T17:00:45.563Z,1579280445.563 [Docked:E.Docked](DEBUG): Initialize.
2020-01-17T17:00:45.564Z,1579280445.564 [Docked:E.Docked](INFO): Depth unspecified. Maintaining workSite beacon depth of 6.000000 m.
2020-01-17T17:00:45.564Z,1579280445.564 [Docked:D] Running Loop=1
2020-01-17T17:00:45.565Z,1579280445.565 [Docked:C] Running Loop=1
2020-01-17T17:00:45.565Z,1579280445.565 [Docked:B.] Running Loop=1
2020-01-17T17:00:45.566Z,1579280445.566 [Docked:A.DepthEnvelope] Running Loop=1
2020-01-17T17:00:46.851Z,1579280446.851 [Docked:E.Docked](INFO): Detected possible state switch to DETACHED.
2020-01-17T17:01:05.847Z,1579280465.847 [DataOverHttps](INFO): Sending 771 bytes from file Logs/20200117T165701/Express0001.lzma
2020-01-17T17:01:07.851Z,1579280467.851 [DataOverHttps](INFO): Moved sent file to Logs/20200117T165701/Express0001.lzma.bak
2020-01-17T17:01:07.851Z,1579280467.851 [DataOverHttps](INFO): SBD MOMSN=12196572
2020-01-17T17:01:10.306Z,1579280470.306 [CommandLine](IMPORTANT): got command report mod DDM.cablePresent
2020-01-17T17:01:10.712Z,1579280470.712 [Reporter](INFO): DDM.cablePresent 1 bool
2020-01-17T17:01:45.908Z,1579280505.908 [Docked:B.](INFO): *** querying acoustic contact ***
2020-01-17T17:01:46.676Z,1579280506.676 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77

2020-01-17T17:01:47.309Z,1579280507.309 [Micromodem](INFO): Nmea in: $SNPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*6A

2020-01-17T17:01:48.103Z,1579280508.103 [Micromodem](INFO): Nmea in: $SNTTA,,,,,170147.78*55

2020-01-17T17:01:50.122Z,1579280510.122 [DUSBL_Hydroid](ERROR): No response from remote modem.
2020-01-17T17:02:00.652Z,1579280520.652 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2020-01-17T17:02:00.652Z,1579280520.652 [RDI_Pathfinder](ERROR): Failed to parse:
:RA,  0.00,   0.00,   0.00,   0.00
2020-01-17T17:02:10.256Z,1579280530.256 [CommandLine](IMPORTANT): got command get platform_buoyancy_position
2020-01-17T17:02:10.260Z,1579280530.260 [CommandLine](IMPORTANT): platform_buoyancy_position 308.594147 cc
2020-01-17T17:02:21.099Z,1579280541.099 [CommandLine](IMPORTANT): got command maintain sensor Depth_Keller.depth 6.000000 meter
2020-01-17T17:02:21.100Z,1579280541.100 [ComponentRegistry](DEBUG): SyncComponent "Maintain_Depth_Keller.depth" handled in the control thread.
2020-01-17T17:02:21.147Z,1579280541.147 [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_Depth_Keller.depth,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-17T17:02:35.255Z,1579280555.255 [CommandLine](IMPORTANT): got command get depth
2020-01-17T17:02:35.256Z,1579280555.256 [CommandLine](IMPORTANT): depth 6.000000 m
2020-01-17T17:02:46.095Z,1579280566.095 [Docked:B.](INFO): *** querying acoustic contact ***
2020-01-17T17:02:46.848Z,1579280566.848 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77

2020-01-17T17:02:47.256Z,1579280567.256 [Micromodem](INFO): Nmea in: $SNPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*6A

2020-01-17T17:02:48.055Z,1579280568.055 [Micromodem](INFO): Nmea in: $SNTTA,,,,,170247.95*55

2020-01-17T17:02:50.178Z,1579280570.178 [DUSBL_Hydroid](ERROR): No response from remote modem.
2020-01-17T17:02:52.592Z,1579280572.592 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-01-17T17:03:12.535Z,1579280592.535 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2020-01-17T17:03:12.535Z,1579280592.535 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-01-17T17:03:12.546Z,1579280592.546 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-01-17T17:03:12.927Z,1579280592.927 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-01-17T17:03:12.927Z,1579280592.927 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2020-01-17T17:03:46.132Z,1579280626.132 [Docked:B.](INFO): *** querying acoustic contact ***
2020-01-17T17:03:46.896Z,1579280626.896 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77

2020-01-17T17:03:47.301Z,1579280627.301 [Micromodem](INFO): Nmea in: $SNPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*6A

2020-01-17T17:03:48.115Z,1579280628.115 [Micromodem](INFO): Nmea in: $SNTTA,,,,,170348.00*57

2020-01-17T17:03:50.530Z,1579280630.530 [DUSBL_Hydroid](ERROR): No response from remote modem.
2020-01-17T17:04:35.198Z,1579280675.198 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2020-01-17T17:04:35.202Z,1579280675.202 [BPC1](INFO): Received data from all battery sticks.
2020-01-17T17:04:46.136Z,1579280686.136 [Docked:B.](INFO): *** querying acoustic contact ***
2020-01-17T17:04:46.884Z,1579280686.884 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77

2020-01-17T17:04:47.305Z,1579280687.305 [Micromodem](INFO): Nmea in: $SNPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*6A

2020-01-17T17:04:48.103Z,1579280688.103 [Micromodem](INFO): Nmea in: $SNTTA,,,,,170447.99*5F

2020-01-17T17:04:50.530Z,1579280690.530 [DUSBL_Hydroid](ERROR): No response from remote modem.
2020-01-17T17:05:16.462Z,1579280716.462 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2020-01-17T17:05:16.462Z,1579280716.462 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,20011710171653,35.0, -0.
2020-01-17T17:05:33.117Z,1579280733.117 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2020-01-17T17:05:33.329Z,1579280733.329 [Radio_Surface](INFO): Powering down
2020-01-17T17:05:46.503Z,1579280746.503 [Docked:B.](INFO): *** querying acoustic contact ***
2020-01-17T17:05:47.247Z,1579280747.247 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77

2020-01-17T17:05:47.646Z,1579280747.646 [Micromodem](INFO): Nmea in: $SNPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*6A

2020-01-17T17:05:48.455Z,1579280748.455 [Micromodem](INFO): Nmea in: $SNTTA,,,,,170548.35*57

2020-01-17T17:05:50.866Z,1579280750.866 [DUSBL_Hydroid](ERROR): No response from remote modem.
2020-01-17T17:05:51.704Z,1579280751.704 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2020-01-17T17:05:51.709Z,1579280751.709 [RDI_Pathfinder](ERROR): Failed to parse:
:RA,  0.00,   0.00,   0.00,   0.00
2020-01-17T17:06:13.508Z,1579280773.508 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2020-01-17T17:06:13.508Z,1579280773.508 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-01-17T17:06:13.519Z,1579280773.519 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-01-17T17:06:14.016Z,1579280774.016 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-01-17T17:06:14.017Z,1579280774.017 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2020-01-17T17:06:15.294Z,1579280775.294 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.248352
2020-01-17T17:06:28.178Z,1579280788.178 [CommandLine](IMPORTANT): got command show variable TrackAcoustic
2020-01-17T17:06:28.398Z,1579280788.398 [CommandLine](IMPORTANT): TrackAcousticContact.contact_label (enum)
2020-01-17T17:06:28.398Z,1579280788.398 [CommandLine](IMPORTANT): TrackAcousticContact.contact_latitude (degree)
2020-01-17T17:06:28.399Z,1579280788.399 [CommandLine](IMPORTANT): TrackAcousticContact.contact_latitude_lowpass (degree)
2020-01-17T17:06:28.399Z,1579280788.399 [CommandLine](IMPORTANT): TrackAcousticContact.contact_longitude (degree)
2020-01-17T17:06:28.399Z,1579280788.399 [CommandLine](IMPORTANT): TrackAcousticContact.contact_longitude_lowpass (degree)
2020-01-17T17:06:28.400Z,1579280788.400 [CommandLine](IMPORTANT): TrackAcousticContact.eastings_to_contact (meter)
2020-01-17T17:06:28.400Z,1579280788.400 [CommandLine](IMPORTANT): TrackAcousticContact.northings_to_contact (meter)
2020-01-17T17:06:28.401Z,1579280788.401 [CommandLine](IMPORTANT): TrackAcousticContact.contact_depth (meter)
2020-01-17T17:06:28.401Z,1579280788.401 [CommandLine](IMPORTANT): TrackAcousticContact.contact_depth_lowpass (meter)
2020-01-17T17:06:28.402Z,1579280788.402 [CommandLine](IMPORTANT): TrackAcousticContact.range_to_contact (meter)
2020-01-17T17:06:28.402Z,1579280788.402 [CommandLine](IMPORTANT): TrackAcousticContact.azimuth_to_contact_vehicle_frame (radian)
2020-01-17T17:06:28.402Z,1579280788.402 [CommandLine](IMPORTANT): TrackAcousticContact.elevation_to_contact_vehicle_frame (radian)
2020-01-17T17:06:28.403Z,1579280788.403 [CommandLine](IMPORTANT): TrackAcousticContact.heading_to_contact (radian)
2020-01-17T17:06:28.403Z,1579280788.403 [CommandLine](IMPORTANT): TrackAcousticContact.direction_vehicle_frame (none)
2020-01-17T17:06:28.403Z,1579280788.403 [CommandLine](IMPORTANT): TrackAcousticContact.direction_navigation_frame (none)
2020-01-17T17:06:28.404Z,1579280788.404 [CommandLine](IMPORTANT): TrackAcousticContact.relativePosition_vehicleFrame (meter)
2020-01-17T17:06:28.404Z,1579280788.404 [CommandLine](IMPORTANT): TrackAcousticContact.relativePosition_navigationFrame (meter)
2020-01-17T17:06:36.640Z,1579280796.640 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2020-01-17T17:06:36.640Z,1579280796.640 [RDI_Pathfinder](ERROR): Failed to parse:
:RA,  0.00,   0.00,   0.00,   0.00
2020-01-17T17:06:46.748Z,1579280806.748 [Docked:B.](INFO): *** querying acoustic contact ***
2020-01-17T17:06:47.516Z,1579280807.516 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77

2020-01-17T17:06:48.094Z,1579280808.094 [Micromodem](INFO): Nmea in: $SNPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*6A

2020-01-17T17:06:48.891Z,1579280808.891 [Micromodem](INFO): Nmea in: $SNTTA,,,,,170648.62*56

2020-01-17T17:06:50.910Z,1579280810.910 [DUSBL_Hydroid](ERROR): No response from remote modem.
2020-01-17T17:06:54.611Z,1579280814.611 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2020-01-17T17:06:54.611Z,1579280814.611 [RDI_Pathfinder](ERROR): Failed to parse:
:RA,  0.00,   0.00,   0.00,   0.00
2020-01-17T17:07:01.013Z,1579280821.013 [Radio_Surface](INFO): Powering up
2020-01-17T17:07:06.497Z,1579280826.497 [DataOverHttps](INFO): Radio surface powered ON.
2020-01-17T17:07:07.073Z,1579280827.073 [Radio_Surface](INFO): Powering down
2020-01-17T17:07:36.617Z,1579280856.617 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2020-01-17T17:07:37.621Z,1579280857.621 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2020-01-17T17:07:46.788Z,1579280866.788 [Docked:B.](INFO): *** querying acoustic contact ***
2020-01-17T17:07:47.564Z,1579280867.564 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77

2020-01-17T17:07:47.969Z,1579280867.969 [Micromodem](INFO): Nmea in: $SNPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*6A

2020-01-17T17:07:48.779Z,1579280868.779 [Micromodem](INFO): Nmea in: $SNTTA,,,,,170748.67*52

2020-01-17T17:07:49.623Z,1579280869.623 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2020-01-17T17:07:49.623Z,1579280869.623 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,20011710190, -0.1,   0.0,1448.9,  0
2020-01-17T17:07:51.202Z,1579280871.202 [DUSBL_Hydroid](ERROR): No response from remote modem.
2020-01-17T17:07:51.607Z,1579280871.607 [NAL9602](FAULT): GPS failed to acquire within timeout.
2020-01-17T17:07:51.608Z,1579280871.608 [NAL9602] Data Fault, FailCount= 1
2020-01-17T17:07:51.608Z,1579280871.608 [NAL9602](ERROR): Data Fault
2020-01-17T17:07:51.678Z,1579280871.678 [CBIT](ERROR): Data Fault in component: NAL9602
2020-01-17T17:07:52.007Z,1579280872.007 [NAL9602](INFO): Powering down
2020-01-17T17:07:52.859Z,1579280872.859 [CBIT](INFO): Clearing failed state for component NAL9602
2020-01-17T17:07:52.859Z,1579280872.859 [NAL9602] No Fault, FailCount= 1
2020-01-17T17:08:15.654Z,1579280895.654 [CommandLine](IMPORTANT): got command set TrackAcousticContact.range_to_contact 4.000000 meter
2020-01-17T17:08:22.416Z,1579280902.416 [NAL9602](INFO): Powering up NAL9602
2020-01-17T17:08:30.519Z,1579280910.519 [CommandLine](IMPORTANT): got command get TrackAcousticContact.range_to_contact
2020-01-17T17:08:30.519Z,1579280910.519 [CommandLine](IMPORTANT): TrackAcousticContact.range_to_contact 4.000000 m
2020-01-17T17:08:33.363Z,1579280913.363 [NAL9602](INFO): NAL9602 initialized
2020-01-17T17:08:47.144Z,1579280927.144 [Docked:B.](INFO): *** querying acoustic contact ***
2020-01-17T17:08:47.907Z,1579280927.907 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77

2020-01-17T17:08:48.317Z,1579280928.317 [Micromodem](INFO): Nmea in: $SNPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*6A

2020-01-17T17:08:49.130Z,1579280929.130 [Micromodem](INFO): Nmea in: $SNTTA,,,,,170849.01*5C

2020-01-17T17:08:51.546Z,1579280931.546 [DUSBL_Hydroid](ERROR): No response from remote modem.
2020-01-17T17:08:56.054Z,1579280936.054 [CommandLine](IMPORTANT): got command get depth
2020-01-17T17:08:56.054Z,1579280936.054 [CommandLine](IMPORTANT): depth 6.000000 m
2020-01-17T17:09:04.996Z,1579280944.996 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2020-01-17T17:09:04.996Z,1579280944.996 [RDI_Pathfinder](ERROR): Failed to parse:
:RA,  0.00,   0.00,   0.00,   0.00
2020-01-17T17:09:14.691Z,1579280954.691 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2020-01-17T17:09:14.691Z,1579280954.691 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-01-17T17:09:14.702Z,1579280954.702 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-01-17T17:09:15.094Z,1579280955.094 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-01-17T17:09:15.094Z,1579280955.094 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2020-01-17T17:09:34.158Z,1579280974.158 [Radio_Surface](INFO): Powering up
2020-01-17T17:09:38.602Z,1579280978.602 [RDI_Pathfinder](ERROR): Failed to parse:
:RA,  0.00,   0.00,   0.00,   0.00,   0.00
2020-01-17T17:09:40.137Z,1579280980.137 [DataOverHttps](INFO): Radio surface powered ON.
2020-01-17T17:09:47.508Z,1579280987.508 [Docked:B.](INFO): *** querying acoustic contact ***
2020-01-17T17:09:48.284Z,1579280988.284 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77

2020-01-17T17:09:48.690Z,1579280988.690 [Micromodem](INFO): Nmea in: $SNPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*6A

2020-01-17T17:09:49.491Z,1579280989.491 [Micromodem](INFO): Nmea in: $SNTTA,,,,,170949.39*56

2020-01-17T17:09:51.910Z,1579280991.910 [DUSBL_Hydroid](ERROR): No response from remote modem.
2020-01-17T17:10:10.267Z,1579281010.267 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2020-01-17T17:10:45.405Z,1579281045.405 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2020-01-17T17:10:47.732Z,1579281047.732 [Docked:B.](INFO): *** querying acoustic contact ***
2020-01-17T17:10:48.482Z,1579281048.482 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77

2020-01-17T17:10:48.873Z,1579281048.873 [Micromodem](INFO): Nmea in: $SNPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*6A

2020-01-17T17:10:49.692Z,1579281049.692 [Micromodem](INFO): Nmea in: $SNTTA,,,,,171049.58*59

2020-01-17T17:10:52.106Z,1579281052.106 [DUSBL_Hydroid](ERROR): No response from remote modem.
2020-01-17T17:10:54.159Z,1579281054.159 [CommandLine](IMPORTANT): got command maintain clear
2020-01-17T17:10:54.182Z,1579281054.182 [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-17T17:10:57.018Z,1579281057.018 [CommandLine](IMPORTANT): got command stop
2020-01-17T17:10:57.019Z,1579281057.019 [CommandLine](IMPORTANT): Scheduling is paused
2020-01-17T17:10:57.019Z,1579281057.019 [Supervisor](INFO): Stop Mission called by CommandLine::commandStop
2020-01-17T17:10:57.401Z,1579281057.401 [MissionManager](INFO): MissionManager is completed.
2020-01-17T17:10:57.401Z,1579281057.401 [MissionManager](INFO): Uninitializing Mission Docked
2020-01-17T17:10:57.401Z,1579281057.401 [Docked] Stopped
2020-01-17T17:10:57.401Z,1579281057.401 [Docked](DEBUG): Aggregate::uninitialize Docked
2020-01-17T17:10:57.401Z,1579281057.401 [Docked:A.DepthEnvelope] Stopped
2020-01-17T17:10:57.401Z,1579281057.401 [Docked:A.DepthEnvelope](DEBUG): Uninitialize.
2020-01-17T17:10:57.401Z,1579281057.401 [Docked:B.] Stopped
2020-01-17T17:10:57.401Z,1579281057.401 [Docked:C] Stopped
2020-01-17T17:10:57.401Z,1579281057.401 [Docked:D] Stopped
2020-01-17T17:10:57.401Z,1579281057.401 [Docked:E.Docked] Stopped
2020-01-17T17:10:57.767Z,1579281057.767 [MissionManager](IMPORTANT): Started mission Default
2020-01-17T17:10:57.767Z,1579281057.767 [Default] Running Loop=1
2020-01-17T17:10:57.767Z,1579281057.767 [Default](DEBUG): Aggregate::initialize Default
2020-01-17T17:10:57.767Z,1579281057.767 [Default:B.GoToSurface] Running Loop=1
2020-01-17T17:10:57.767Z,1579281057.767 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-01-17T17:10:57.768Z,1579281057.768 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-01-17T17:10:57.768Z,1579281057.768 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-01-17T17:10:57.768Z,1579281057.768 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-01-17T17:10:57.768Z,1579281057.768 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-01-17T17:10:57.769Z,1579281057.769 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-01-17T17:10:57.770Z,1579281057.770 [Default:A.Wait] Running Loop=1
2020-01-17T17:10:57.770Z,1579281057.770 [Default:A.Wait](DEBUG): Initialize Wait Component.
2020-01-17T17:10:57.850Z,1579281057.850 [Reporter](INFO): DDM.cablePresent no_value
2020-01-17T17:11:10.789Z,1579281070.789 [Default:A.Wait](INFO): Done Waiting.
2020-01-17T17:11:10.789Z,1579281070.789 [Default:A.Wait] Stopped
2020-01-17T17:11:10.789Z,1579281070.789 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2020-01-17T17:11:11.219Z,1579281071.219 [Default:CheckIn] Running Loop=1
2020-01-17T17:11:11.219Z,1579281071.219 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-01-17T17:11:11.219Z,1579281071.219 [Default:CheckIn:Read_GPS] Running Loop=1
2020-01-17T17:11:11.625Z,1579281071.625 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2020-01-17T17:11:20.545Z,1579281080.545 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2020-01-17T17:11:21.702Z,1579281081.702 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2020-01-17T17:11:21.703Z,1579281081.703 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,20011710232253,35.0, -0.1,  8.9,  0
2020-01-17T17:11:55.634Z,1579281115.634 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2020-01-17T17:11:55.635Z,1579281115.635 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,20011710230, -0.1,   0.0,1448.9,  0
2020-01-17T17:11:55.685Z,1579281115.685 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2020-01-17T17:12:09.314Z,1579281129.314 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003797
2020-01-17T17:12:15.834Z,1579281135.834 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2020-01-17T17:12:15.834Z,1579281135.834 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-01-17T17:12:15.848Z,1579281135.848 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-01-17T17:12:16.287Z,1579281136.287 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-01-17T17:12:16.287Z,1579281136.287 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2020-01-17T17:12:56.265Z,1579281176.265 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2020-01-17T17:12:56.265Z,1579281176.265 [RDI_Pathfinder](ERROR): Failed to parse:
:BS,-32768,-32768V
2020-01-17T17:13:52.789Z,1579281232.789 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2020-01-17T17:13:52.789Z,1579281232.789 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,200117105.0, -0.1,   0.0,1448.9,  0
2020-01-17T17:15:16.838Z,1579281316.838 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6
2020-01-17T17:15:16.838Z,1579281316.838 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-01-17T17:15:16.852Z,1579281316.852 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-01-17T17:15:17.288Z,1579281317.288 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-01-17T17:15:17.288Z,1579281317.288 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6
2020-01-17T17:16:10.123Z,1579281370.123 [Micromodem](ERROR): Response from modem failed NMEA checksum: $CAREV,171610,COPRO.46*40
 expected 2E
2020-01-17T17:16:11.387Z,1579281371.387 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-01-17T17:11:11.2Z
2020-01-17T17:16:11.387Z,1579281371.387 [Default:CheckIn:Read_GPS] Stopped
2020-01-17T17:16:11.388Z,1579281371.388 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-01-17T17:16:11.790Z,1579281371.790 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2020-01-17T17:16:19.122Z,1579281379.122 [DataOverHttps](INFO): Sending 4359 bytes from file Logs/20200117T165701/Courier0004.lzma
2020-01-17T17:16:21.110Z,1579281381.110 [DataOverHttps](INFO): Moved sent file to Logs/20200117T165701/Courier0004.lzma.bak
2020-01-17T17:16:21.110Z,1579281381.110 [DataOverHttps](INFO): SBD MOMSN=12196591
2020-01-17T17:16:43.238Z,1579281403.238 [DataOverHttps](INFO): Sending 846 bytes from file Logs/20200117T165701/Express0005.lzma
2020-01-17T17:16:45.245Z,1579281405.245 [DataOverHttps](INFO): Moved sent file to Logs/20200117T165701/Express0005.lzma.bak
2020-01-17T17:16:45.245Z,1579281405.245 [DataOverHttps](INFO): SBD MOMSN=12196593
2020-01-17T17:16:46.586Z,1579281406.586 [Default:CheckIn:Read_Iridium] Stopped
2020-01-17T17:16:46.586Z,1579281406.586 [Default:CheckIn:C.Wait] Running Loop=1
2020-01-17T17:16:46.586Z,1579281406.586 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-01-17T17:17:21.340Z,1579281441.340 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude
2020-01-17T17:17:21.341Z,1579281441.341 [RDI_Pathfinder](ERROR): Failed to parse:
:BD,        +0.00,        +0    +0.00,   0.00,1195.94
2020-01-17T17:18:10.514Z,1579281490.514 [CommandLine](IMPORTANT): got command restart application
2020-01-17T17:18:11.521Z,1579281491.521 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2020-01-17T17:18:11.521Z,1579281491.521 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-01-17T17:18:11.585Z,1579281491.585 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2020-01-17T17:18:11.585Z,1579281491.585 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-01-17T17:18:11.586Z,1579281491.586 [CommandLine](INFO): Join timeout helper Thread ID is 4354
2020-01-17T17:18:11.586Z,1579281491.586 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2020-01-17T17:18:11.586Z,1579281491.586 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-01-17T17:18:11.587Z,1579281491.587 [NavChartDb](INFO): Join timeout helper Thread ID is 4355
2020-01-17T17:18:11.921Z,1579281491.921 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2020-01-17T17:18:11.921Z,1579281491.921 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-01-17T17:18:11.937Z,1579281491.937 [ComponentRegistry](INFO): Shutting down WetLabsSeaOWL_UV_A ThreadHandler
2020-01-17T17:18:11.937Z,1579281491.937 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2020-01-17T17:18:11.937Z,1579281491.937 [WetLabsSeaOWL_UV_A](INFO): Join timeout helper Thread ID is 4356
2020-01-17T17:18:12.301Z,1579281492.301 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Uninitializing protected caller thread.
2020-01-17T17:18:12.301Z,1579281492.301 [WetLabsSeaOWL_UV_A](INFO): Powering down
2020-01-17T17:18:12.302Z,1579281492.302 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2020-01-17T17:18:12.321Z,1579281492.321 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2020-01-17T17:18:12.321Z,1579281492.321 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2020-01-17T17:18:12.321Z,1579281492.321 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 4357
2020-01-17T17:18:12.353Z,1579281492.353 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2020-01-17T17:18:12.353Z,1579281492.353 [CTD_NeilBrown](INFO): Powering down
2020-01-17T17:18:12.365Z,1579281492.365 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2020-01-17T17:18:12.381Z,1579281492.381 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2020-01-17T17:18:12.381Z,1579281492.381 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-01-17T17:18:12.382Z,1579281492.382 [Radio_Surface](INFO): Join timeout helper Thread ID is 4358
2020-01-17T17:18:12.517Z,1579281492.517 [Radio_Surface](INFO): Powering down
2020-01-17T17:18:12.518Z,1579281492.518 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2020-01-17T17:18:12.518Z,1579281492.518 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-01-17T17:18:12.530Z,1579281492.530 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2020-01-17T17:18:12.530Z,1579281492.530 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2020-01-17T17:18:12.530Z,1579281492.530 [DataOverHttps](INFO): Join timeout helper Thread ID is 4359
2020-01-17T17:18:12.961Z,1579281492.961 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2020-01-17T17:18:12.961Z,1579281492.961 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2020-01-17T17:18:12.977Z,1579281492.977 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2020-01-17T17:18:12.978Z,1579281492.978 [logger ThreadHandler](INFO): Thread cancelled.
2020-01-17T17:18:12.978Z,1579281492.978 [logger](INFO): Join timeout helper Thread ID is 4360
2020-01-17T17:18:12.993Z,1579281492.993 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2020-01-17T17:18:12.993Z,1579281492.993 [logger ThreadHandler](INFO): Thread cancelled.
2020-01-17T17:18:13.006Z,1579281493.006 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2020-01-17T17:18:13.006Z,1579281493.006 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-01-17T17:18:13.006Z,1579281493.006 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2020-01-17T17:18:13.006Z,1579281493.006 [controlThread ThreadHandler](INFO): Thread cancelled.
2020-01-17T17:18:13.006Z,1579281493.006 [controlThread](INFO): Join timeout helper Thread ID is 4361
2020-01-17T17:18:13.046Z,1579281493.046 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2020-01-17T17:18:13.046Z,1579281493.046 [controlThread](DEBUG): Uninitializing ControlThread
2020-01-17T17:18:13.046Z,1579281493.046 [AHRS_M2](INFO): Powering down
2020-01-17T17:18:13.117Z,1579281493.117 [DDM](INFO): Powering down
2020-01-17T17:18:13.210Z,1579281493.210 [DUSBL_Hydroid](INFO): Powering down
2020-01-17T17:18:13.281Z,1579281493.281 [Micromodem](INFO): Powering down
2020-01-17T17:18:13.377Z,1579281493.377 [NAL9602](INFO): Powering down
2020-01-17T17:18:13.449Z,1579281493.449 [RDI_Pathfinder](INFO): Powering down
2020-01-17T17:18:13.451Z,1579281493.451 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2020-01-17T17:18:13.451Z,1579281493.451 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2020-01-17T17:18:13.452Z,1579281493.452 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2020-01-17T17:18:13.452Z,1579281493.452 [MissionManager](INFO): Uninitializing Mission Default
2020-01-17T17:18:13.452Z,1579281493.452 [Default] Stopped
2020-01-17T17:18:13.452Z,1579281493.452 [Default](DEBUG): Aggregate::uninitialize Default
2020-01-17T17:18:13.453Z,1579281493.453 [Default:B.GoToSurface] Stopped
2020-01-17T17:18:13.453Z,1579281493.453 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2020-01-17T17:18:13.453Z,1579281493.453 [Default:CheckIn] Stopped
2020-01-17T17:18:13.453Z,1579281493.453 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-01-17T17:18:13.453Z,1579281493.453 [Default:CheckIn:C.Wait] Stopped
2020-01-17T17:18:13.453Z,1579281493.453 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-01-17T17:18:13.455Z,1579281493.455 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2020-01-17T17:18:13.455Z,1579281493.455 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2020-01-17T17:18:13.456Z,1579281493.456 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2020-01-17T17:18:13.456Z,1579281493.456 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2020-01-17T17:18:13.456Z,1579281493.456 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2020-01-17T17:18:13.456Z,1579281493.456 [BuoyancyServo](INFO): Powering down
2020-01-17T17:18:13.469Z,1579281493.469 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2020-01-17T17:18:13.469Z,1579281493.469 [ElevatorServo](INFO): Powering down
2020-01-17T17:18:13.470Z,1579281493.470 [MassServo](DEBUG): Uninitialize Mass Servo.
2020-01-17T17:18:13.470Z,1579281493.470 [MassServo](INFO): Powering down
2020-01-17T17:18:13.471Z,1579281493.471 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2020-01-17T17:18:13.471Z,1579281493.471 [RudderServo](INFO): Powering down
2020-01-17T17:18:13.472Z,1579281493.472 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2020-01-17T17:18:13.472Z,1579281493.472 [ThrusterServo](INFO): Powering down
2020-01-17T17:18:13.472Z,1579281493.472 [SBIT](DEBUG): Uninitialize SBIT Component.
2020-01-17T17:18:13.473Z,1579281493.473 [IBIT](DEBUG): Uninitialize IBIT Component.
2020-01-17T17:18:13.473Z,1579281493.473 [CBIT](DEBUG): Uninitialize CBIT Component.
2020-01-17T17:18:13.473Z,1579281493.473 [CBIT](DEBUG): Powering off loads.
2020-01-17T17:18:13.485Z,1579281493.485 [CBIT](DEBUG): Disabling WDT.
2020-01-17T17:18:13.497Z,1579281493.497 [CBIT](DEBUG): Opening all GF detection circuits.
2020-01-17T17:18:13.498Z,1579281493.498 [controlThread ThreadHandler](INFO): Thread cancelled.
2020-01-17T17:18:13.546Z,1579281493.546 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-01-17T17:18:13.556Z,1579281493.556 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2020-01-17T17:18:13.606Z,1579281493.606 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2020-01-17T17:18:13.609Z,1579281493.609 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2020-01-17T17:18:13.684Z,1579281493.684 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-01-17T17:18:13.746Z,1579281493.746 [logger ThreadHandler](INFO): Thread cancelled.