2019-11-26T22:44:03.891Z,1574808243.891 [Supervisor](DEBUG): Initializing supervisor.
2019-11-26T22:44:03.894Z,1574808243.894 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2019-11-26T22:44:03.894Z,1574808243.894 [SyncHandler](INFO): Protected caller Thread ID is 5905
2019-11-26T22:44:03.895Z,1574808243.895 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2019-11-26T22:44:03.896Z,1574808243.896 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2019-11-26T22:44:03.896Z,1574808243.896 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 5906
2019-11-26T22:44:03.900Z,1574808243.900 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2019-11-26T22:44:03.911Z,1574808243.911 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2019-11-26T22:44:03.912Z,1574808243.912 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2019-11-26T22:44:03.912Z,1574808243.912 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 5907
2019-11-26T22:44:03.913Z,1574808243.913 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2019-11-26T22:44:03.914Z,1574808243.914 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2019-11-26T22:44:03.914Z,1574808243.914 [logger ThreadHandler](INFO): Protected caller Thread ID is 5908
2019-11-26T22:44:03.916Z,1574808243.916 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2019-11-26T22:44:03.917Z,1574808243.917 [Supervisor](INFO): Looking for Config files in directory: Config/
2019-11-26T22:44:03.918Z,1574808243.918 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2019-11-26T22:44:04.014Z,1574808244.014 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2019-11-26T22:44:04.014Z,1574808244.014 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2019-11-26T22:44:04.594Z,1574808244.594 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2019-11-26T22:44:04.595Z,1574808244.595 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2019-11-26T22:44:04.692Z,1574808244.692 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2019-11-26T22:44:04.692Z,1574808244.692 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2019-11-26T22:44:04.793Z,1574808244.793 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2019-11-26T22:44:04.794Z,1574808244.794 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2019-11-26T22:44:04.875Z,1574808244.875 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2019-11-26T22:44:05.010Z,1574808245.010 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2019-11-26T22:44:05.011Z,1574808245.011 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2019-11-26T22:44:05.289Z,1574808245.289 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2019-11-26T22:44:05.290Z,1574808245.290 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2019-11-26T22:44:05.725Z,1574808245.725 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2019-11-26T22:44:05.725Z,1574808245.726 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2019-11-26T22:44:05.870Z,1574808245.870 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2019-11-26T22:44:05.871Z,1574808245.871 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2019-11-26T22:44:06.054Z,1574808246.054 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2019-11-26T22:44:06.054Z,1574808246.054 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2019-11-26T22:44:06.497Z,1574808246.497 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2019-11-26T22:44:06.498Z,1574808246.498 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2019-11-26T22:44:06.703Z,1574808246.703 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2019-11-26T22:44:06.703Z,1574808246.703 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2019-11-26T22:44:06.897Z,1574808246.897 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2019-11-26T22:44:06.898Z,1574808246.898 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2019-11-26T22:44:07.291Z,1574808247.291 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2019-11-26T22:44:07.292Z,1574808247.292 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2019-11-26T22:44:07.604Z,1574808247.604 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2019-11-26T22:44:07.606Z,1574808247.606 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-pontus/
2019-11-26T22:44:07.606Z,1574808247.606 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/secure.cfg
2019-11-26T22:44:07.690Z,1574808247.690 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Sensor.cfg
2019-11-26T22:44:07.840Z,1574808247.840 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Servo.cfg
2019-11-26T22:44:07.947Z,1574808247.947 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Simulator.cfg
2019-11-26T22:44:08.032Z,1574808248.032 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/logger.cfg
2019-11-26T22:44:08.152Z,1574808248.152 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/vehicle.cfg
2019-11-26T22:44:08.456Z,1574808248.456 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Battery.cfg
2019-11-26T22:44:08.846Z,1574808248.846 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2019-11-26T22:44:08.847Z,1574808248.847 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Navigation.cfg
2019-11-26T22:44:09.067Z,1574808249.067 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/BIT.cfg
2019-11-26T22:44:09.164Z,1574808249.164 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Science.cfg
2019-11-26T22:44:09.299Z,1574808249.299 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Control.cfg
2019-11-26T22:44:09.398Z,1574808249.398 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-pontus/root/
2019-11-26T22:44:09.398Z,1574808249.398 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2019-11-26T22:44:09.403Z,1574808249.403 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2019-11-26T22:44:09.450Z,1574808249.450 [VerticalControl](DEBUG): Construct VerticalControl.
2019-11-26T22:44:09.558Z,1574808249.558 [VerticalControl] Loaded
2019-11-26T22:44:09.558Z,1574808249.558 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2019-11-26T22:44:09.559Z,1574808249.559 [HorizontalControl](DEBUG): Construct HorizontalControl.
2019-11-26T22:44:09.638Z,1574808249.638 [HorizontalControl] Loaded
2019-11-26T22:44:09.639Z,1574808249.639 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2019-11-26T22:44:09.639Z,1574808249.639 [SpeedControl](DEBUG): Construct SpeedControl.
2019-11-26T22:44:09.644Z,1574808249.644 [SpeedControl] Loaded
2019-11-26T22:44:09.645Z,1574808249.645 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2019-11-26T22:44:09.645Z,1574808249.645 [LoopControl](DEBUG): Construct LoopControl.
2019-11-26T22:44:09.646Z,1574808249.646 [LoopControl] Loaded
2019-11-26T22:44:09.646Z,1574808249.646 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2019-11-26T22:44:09.647Z,1574808249.647 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2019-11-26T22:44:09.647Z,1574808249.647 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2019-11-26T22:44:09.687Z,1574808249.687 [DepthRateCalculator] Loaded
2019-11-26T22:44:09.687Z,1574808249.687 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2019-11-26T22:44:09.692Z,1574808249.692 [PitchRateCalculator] Loaded
2019-11-26T22:44:09.693Z,1574808249.693 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2019-11-26T22:44:09.707Z,1574808249.707 [SpeedCalculator] Loaded
2019-11-26T22:44:09.708Z,1574808249.708 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2019-11-26T22:44:09.728Z,1574808249.728 [TempGradientCalculator] Loaded
2019-11-26T22:44:09.728Z,1574808249.728 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2019-11-26T22:44:09.733Z,1574808249.733 [YawRateCalculator] Loaded
2019-11-26T22:44:09.734Z,1574808249.734 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2019-11-26T22:44:09.762Z,1574808249.762 [ElevatorOffsetCalculator] Loaded
2019-11-26T22:44:09.762Z,1574808249.762 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2019-11-26T22:44:09.762Z,1574808249.762 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2019-11-26T22:44:09.763Z,1574808249.763 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2019-11-26T22:44:09.795Z,1574808249.795 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2019-11-26T22:44:09.796Z,1574808249.796 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2019-11-26T22:44:09.874Z,1574808249.874 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2019-11-26T22:44:09.875Z,1574808249.875 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2019-11-26T22:44:10.176Z,1574808250.176 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2019-11-26T22:44:10.176Z,1574808250.176 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2019-11-26T22:44:10.272Z,1574808250.272 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2019-11-26T22:44:10.272Z,1574808250.272 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2019-11-26T22:44:10.559Z,1574808250.559 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_orientation
2019-11-26T22:44:10.564Z,1574808250.564 [AHRS_M2](INFO): created writer for : platform_orientation
2019-11-26T22:44:10.565Z,1574808250.565 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_magnetic_orientation
2019-11-26T22:44:10.571Z,1574808250.571 [AHRS_M2](INFO): created writer for : platform_magnetic_orientation
2019-11-26T22:44:10.571Z,1574808250.571 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_pitch_angle
2019-11-26T22:44:10.576Z,1574808250.576 [AHRS_M2](INFO): created writer for : platform_pitch_angle
2019-11-26T22:44:10.577Z,1574808250.577 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_roll_angle
2019-11-26T22:44:10.582Z,1574808250.582 [AHRS_M2](INFO): created writer for : platform_roll_angle
2019-11-26T22:44:10.652Z,1574808250.652 [AHRS_M2] Loaded
2019-11-26T22:44:10.652Z,1574808250.652 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2019-11-26T22:44:10.730Z,1574808250.730 [DataOverHttps] Loaded
2019-11-26T22:44:10.731Z,1574808250.731 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2019-11-26T22:44:10.732Z,1574808250.732 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 408DE4E0
2019-11-26T22:44:10.732Z,1574808250.732 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 5987
2019-11-26T22:44:10.745Z,1574808250.745 [Depth_Keller] Loaded
2019-11-26T22:44:10.746Z,1574808250.746 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2019-11-26T22:44:10.750Z,1574808250.750 [DropWeight] Loaded
2019-11-26T22:44:10.751Z,1574808250.751 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2019-11-26T22:44:10.845Z,1574808250.845 [NAL9602] Loaded
2019-11-26T22:44:10.845Z,1574808250.845 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2019-11-26T22:44:10.860Z,1574808250.860 [Onboard] Loaded
2019-11-26T22:44:10.861Z,1574808250.861 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2019-11-26T22:44:10.864Z,1574808250.864 [Radio_Surface] Loaded
2019-11-26T22:44:10.864Z,1574808250.864 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2019-11-26T22:44:10.865Z,1574808250.865 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4090E4E0
2019-11-26T22:44:10.866Z,1574808250.866 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 5988
2019-11-26T22:44:10.908Z,1574808250.908 [RDI_Pathfinder] Loaded
2019-11-26T22:44:10.909Z,1574808250.909 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2019-11-26T22:44:11.039Z,1574808251.039 [DAT] Loaded
2019-11-26T22:44:11.039Z,1574808251.039 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread.
2019-11-26T22:44:12.501Z,1574808252.501 [BPC1] Loaded
2019-11-26T22:44:12.501Z,1574808252.501 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2019-11-26T22:44:12.501Z,1574808252.501 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2019-11-26T22:44:12.502Z,1574808252.502 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2019-11-26T22:44:12.601Z,1574808252.601 [DeadReckonUsingMultipleVelocitySources] Loaded
2019-11-26T22:44:12.601Z,1574808252.601 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2019-11-26T22:44:12.621Z,1574808252.621 [NavChart] Loaded
2019-11-26T22:44:12.621Z,1574808252.621 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2019-11-26T22:44:12.625Z,1574808252.625 [UniversalFixResidualReporter] Loaded
2019-11-26T22:44:12.625Z,1574808252.625 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2019-11-26T22:44:12.626Z,1574808252.626 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2019-11-26T22:44:12.626Z,1574808252.626 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2019-11-26T22:44:12.881Z,1574808252.881 [SBIT](DEBUG): Construct Startup Built In Test.
2019-11-26T22:44:12.892Z,1574808252.892 [SBIT] Loaded
2019-11-26T22:44:12.892Z,1574808252.892 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2019-11-26T22:44:12.893Z,1574808252.893 [IBIT](DEBUG): Construct Initiated Built In Test.
2019-11-26T22:44:12.905Z,1574808252.905 [IBIT] Loaded
2019-11-26T22:44:12.905Z,1574808252.905 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2019-11-26T22:44:12.908Z,1574808252.908 [CBIT](DEBUG): Construct Continuous Built In Test.
2019-11-26T22:44:13.042Z,1574808253.042 [CBIT] Loaded
2019-11-26T22:44:13.042Z,1574808253.042 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2019-11-26T22:44:13.043Z,1574808253.043 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2019-11-26T22:44:13.043Z,1574808253.043 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2019-11-26T22:44:13.143Z,1574808253.143 [BuoyancyServo] Loaded
2019-11-26T22:44:13.143Z,1574808253.143 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2019-11-26T22:44:13.154Z,1574808253.154 [ElevatorServo] Loaded
2019-11-26T22:44:13.154Z,1574808253.154 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2019-11-26T22:44:13.164Z,1574808253.164 [MassServo] Loaded
2019-11-26T22:44:13.165Z,1574808253.165 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2019-11-26T22:44:13.175Z,1574808253.175 [RudderServo] Loaded
2019-11-26T22:44:13.176Z,1574808253.176 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2019-11-26T22:44:13.186Z,1574808253.186 [ThrusterServo] Loaded
2019-11-26T22:44:13.187Z,1574808253.187 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2019-11-26T22:44:13.187Z,1574808253.187 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2019-11-26T22:44:13.188Z,1574808253.188 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2019-11-26T22:44:13.248Z,1574808253.248 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2019-11-26T22:44:13.249Z,1574808253.249 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2019-11-26T22:44:13.572Z,1574808253.572 [BackSeatDriver] Loaded
2019-11-26T22:44:13.572Z,1574808253.572 [ComponentRegistry](DEBUG): Component "BackSeatDriver" handled in its own thread.
2019-11-26T22:44:13.573Z,1574808253.573 [BackSeatDriver ThreadHandler](DEBUG): Created PCaller Thread at 40A944E0
2019-11-26T22:44:13.574Z,1574808253.574 [BackSeatDriver ThreadHandler](INFO): Protected caller Thread ID is 5989
2019-11-26T22:44:13.583Z,1574808253.583 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density
2019-11-26T22:44:13.588Z,1574808253.588 [CTD_Seabird](INFO): created writer for : sea_water_density
2019-11-26T22:44:13.588Z,1574808253.588 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth
2019-11-26T22:44:13.593Z,1574808253.593 [CTD_Seabird](INFO): created writer for : depth
2019-11-26T22:44:13.593Z,1574808253.593 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure
2019-11-26T22:44:13.598Z,1574808253.598 [CTD_Seabird](INFO): created writer for : sea_water_pressure
2019-11-26T22:44:13.599Z,1574808253.599 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity
2019-11-26T22:44:13.604Z,1574808253.604 [CTD_Seabird](INFO): created writer for : sea_water_salinity
2019-11-26T22:44:13.604Z,1574808253.604 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature
2019-11-26T22:44:13.609Z,1574808253.609 [CTD_Seabird](INFO): created writer for : sea_water_temperature
2019-11-26T22:44:13.610Z,1574808253.610 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity
2019-11-26T22:44:13.616Z,1574808253.616 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity
2019-11-26T22:44:13.616Z,1574808253.616 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water
2019-11-26T22:44:13.621Z,1574808253.621 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water
2019-11-26T22:44:13.648Z,1574808253.648 [CTD_Seabird] Loaded
2019-11-26T22:44:13.648Z,1574808253.648 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2019-11-26T22:44:13.649Z,1574808253.649 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40AC44E0
2019-11-26T22:44:13.649Z,1574808253.649 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 5990
2019-11-26T22:44:13.656Z,1574808253.656 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output470
2019-11-26T22:44:13.656Z,1574808253.656 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output470
2019-11-26T22:44:13.660Z,1574808253.660 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output650
2019-11-26T22:44:13.661Z,1574808253.661 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output650
2019-11-26T22:44:13.665Z,1574808253.665 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.OutputChl
2019-11-26T22:44:13.665Z,1574808253.665 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: OutputChl
2019-11-26T22:44:13.670Z,1574808253.670 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg470nm
2019-11-26T22:44:13.670Z,1574808253.670 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg470nm
2019-11-26T22:44:13.674Z,1574808253.674 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg650nm
2019-11-26T22:44:13.674Z,1574808253.674 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg650nm
2019-11-26T22:44:13.678Z,1574808253.678 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff470nm
2019-11-26T22:44:13.678Z,1574808253.678 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff470nm
2019-11-26T22:44:13.683Z,1574808253.683 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff650nm
2019-11-26T22:44:13.683Z,1574808253.683 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff650nm
2019-11-26T22:44:13.687Z,1574808253.687 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): mass_concentration_of_chlorophyll_in_sea_water
2019-11-26T22:44:13.691Z,1574808253.691 [WetLabsBB2FL](INFO): created writer for : mass_concentration_of_chlorophyll_in_sea_water
2019-11-26T22:44:13.692Z,1574808253.692 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_median_mass_concentration_of_chlorophyll_in_sea_water
2019-11-26T22:44:13.692Z,1574808253.692 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_median_mass_concentration_of_chlorophyll_in_sea_water
2019-11-26T22:44:13.696Z,1574808253.696 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water
2019-11-26T22:44:13.696Z,1574808253.696 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_mean_mass_concentration_of_chlorophyll_in_sea_water
2019-11-26T22:44:13.700Z,1574808253.700 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_variance_mass_concentration_of_chlorophyll_in_sea_water
2019-11-26T22:44:13.700Z,1574808253.700 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_variance_mass_concentration_of_chlorophyll_in_sea_water
2019-11-26T22:44:13.705Z,1574808253.705 [WetLabsBB2FL] Loaded
2019-11-26T22:44:13.705Z,1574808253.705 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2019-11-26T22:44:13.706Z,1574808253.706 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40AF44E0
2019-11-26T22:44:13.706Z,1574808253.706 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 5991
2019-11-26T22:44:13.720Z,1574808253.720 [WetLabsUBAT..SerialDriver](INFO): Created logger
2019-11-26T22:44:13.721Z,1574808253.721 [WetLabsUBAT..SerialDriver](INFO): publishing on LCM channel WetLabsUBAT
2019-11-26T22:44:13.721Z,1574808253.721 [WetLabsUBAT..StreamSerialDriver](INFO): Created logger
2019-11-26T22:44:13.726Z,1574808253.726 [WetLabsUBAT](INFO): readConfig(): serialNo_: UBAT0051, uartName_: /dev/ttyC1, optionalArgs_: -ldir /mnt/mmc/LRAUV/Logs/latest
2019-11-26T22:44:13.727Z,1574808253.727 [WetLabsUBAT](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsUBAT.biolum_potential
2019-11-26T22:44:13.727Z,1574808253.727 [WetLabsUBAT](DEBUG): LcmSlateWriter::add(): dataName: biolum_potential
2019-11-26T22:44:13.731Z,1574808253.731 [WetLabsUBAT](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsUBAT.flow_rate
2019-11-26T22:44:13.731Z,1574808253.731 [WetLabsUBAT](DEBUG): LcmSlateWriter::add(): dataName: flow_rate
2019-11-26T22:44:13.735Z,1574808253.735 [WetLabsUBAT] Loaded
2019-11-26T22:44:13.736Z,1574808253.736 [ComponentRegistry](DEBUG): Component "WetLabsUBAT" handled in its own thread.
2019-11-26T22:44:13.737Z,1574808253.737 [WetLabsUBAT ThreadHandler](DEBUG): Created PCaller Thread at 40B244E0
2019-11-26T22:44:13.737Z,1574808253.737 [WetLabsUBAT ThreadHandler](INFO): Protected caller Thread ID is 5992
2019-11-26T22:44:13.737Z,1574808253.737 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2019-11-26T22:44:13.741Z,1574808253.741 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2019-11-26T22:44:13.742Z,1574808253.742 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2019-11-26T22:44:13.748Z,1574808253.748 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2019-11-26T22:44:13.749Z,1574808253.749 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B544E0
2019-11-26T22:44:13.750Z,1574808253.750 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 5993
2019-11-26T22:44:13.754Z,1574808253.754 [Supervisor](INFO): Main Thread ID is 5741
2019-11-26T22:44:13.754Z,1574808253.754 [Supervisor](DEBUG): Running supervisor.
2019-11-26T22:44:13.755Z,1574808253.755 [CommandLine ThreadHandler](INFO): Handler Thread ID is 5994
2019-11-26T22:44:13.758Z,1574808253.758 [controlThread ThreadHandler](INFO): Handler Thread ID is 5995
2019-11-26T22:44:13.758Z,1574808253.758 [controlThread](DEBUG): Initializing ControlThread
2019-11-26T22:44:13.759Z,1574808253.759 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2019-11-26T22:44:13.761Z,1574808253.761 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2019-11-26T22:44:13.761Z,1574808253.761 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2019-11-26T22:44:13.762Z,1574808253.762 [LoopControl](DEBUG): Initialize LoopControlComponent.
2019-11-26T22:44:13.762Z,1574808253.762 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2019-11-26T22:44:13.762Z,1574808253.762 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2019-11-26T22:44:13.763Z,1574808253.763 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2019-11-26T22:44:13.763Z,1574808253.763 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2019-11-26T22:44:13.764Z,1574808253.764 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2019-11-26T22:44:13.764Z,1574808253.764 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2019-11-26T22:44:13.772Z,1574808253.772 [NavChart](DEBUG): Initialize NavChart Navigation.
2019-11-26T22:44:13.772Z,1574808253.772 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2019-11-26T22:44:13.772Z,1574808253.772 [SBIT](INFO): Initialize SBIT Component.
2019-11-26T22:44:13.773Z,1574808253.773 [SBIT](IMPORTANT): git: 2019-11-25
2019-11-26T22:44:13.773Z,1574808253.773 [SBIT](INFO): git hash: 613c3b988797d140e74aeade4f971920e69097b8
2019-11-26T22:44:13.774Z,1574808253.774 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2019-11-26T22:44:13.774Z,1574808253.774 [SBIT](IMPORTANT): Kernel Version:#1 PREEMPT Thu Feb 21 11:17:40 PST 2019
2019-11-26T22:44:13.775Z,1574808253.775 [SBIT](INFO): Beginning SBIT in 39.000000 seconds.
2019-11-26T22:44:13.775Z,1574808253.775 [IBIT](INFO): Initialize IBIT Component.
2019-11-26T22:44:13.776Z,1574808253.776 [CBIT](DEBUG): Initialize CBIT Component.
2019-11-26T22:44:13.777Z,1574808253.777 [logger ThreadHandler](INFO): Handler Thread ID is 5996
2019-11-26T22:44:13.789Z,1574808253.789 [CBIT](DEBUG): Initialized mux pins.
2019-11-26T22:44:13.789Z,1574808253.789 [CBIT](DEBUG): Initializing the watchdog timer.
2019-11-26T22:44:13.797Z,1574808253.797 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 5997
2019-11-26T22:44:13.798Z,1574808253.798 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2019-11-26T22:44:13.809Z,1574808253.809 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 5998
2019-11-26T22:44:13.813Z,1574808253.813 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2019-11-26T22:44:13.813Z,1574808253.813 [CBIT](DEBUG): Initializing heartbeat.
2019-11-26T22:44:13.821Z,1574808253.821 [BackSeatDriver ThreadHandler](INFO): Handler Thread ID is 5999
2019-11-26T22:44:13.841Z,1574808253.841 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 6000
2019-11-26T22:44:13.842Z,1574808253.842 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2019-11-26T22:44:13.845Z,1574808253.845 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20
2019-11-26T22:44:13.847Z,1574808253.847 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 6002
2019-11-26T22:44:13.848Z,1574808253.848 [WetLabsBB2FL](INFO): Powering down
2019-11-26T22:44:13.877Z,1574808253.877 [WetLabsUBAT ThreadHandler](INFO): Handler Thread ID is 6003
2019-11-26T22:44:13.885Z,1574808253.885 [CBIT](DEBUG): Deactivating GF circuits.
2019-11-26T22:44:13.885Z,1574808253.885 [CBIT](DEBUG): Deactivating emergency mode.
2019-11-26T22:44:13.897Z,1574808253.897 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 6004
2019-11-26T22:44:13.900Z,1574808253.900 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2019-11-26T22:44:13.900Z,1574808253.900 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2019-11-26T22:44:13.901Z,1574808253.901 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2019-11-26T22:44:13.901Z,1574808253.901 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2019-11-26T22:44:13.901Z,1574808253.901 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2019-11-26T22:44:13.901Z,1574808253.901 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2019-11-26T22:44:13.901Z,1574808253.901 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2019-11-26T22:44:13.902Z,1574808253.902 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2019-11-26T22:44:13.902Z,1574808253.902 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2019-11-26T22:44:13.902Z,1574808253.902 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2019-11-26T22:44:13.902Z,1574808253.902 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2019-11-26T22:44:13.902Z,1574808253.902 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2019-11-26T22:44:13.903Z,1574808253.903 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2019-11-26T22:44:13.903Z,1574808253.903 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2019-11-26T22:44:13.903Z,1574808253.903 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2019-11-26T22:44:13.903Z,1574808253.903 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2019-11-26T22:44:13.921Z,1574808253.921 [CBIT](DEBUG): Backplane powered.
2019-11-26T22:44:13.922Z,1574808253.922 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2019-11-26T22:44:13.933Z,1574808253.933 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2019-11-26T22:44:13.943Z,1574808253.943 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
       Id="Startup">

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

    <Aggregate Id="StartupSatComms">

        <Sequence/>

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

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

    </Aggregate>

</Mission>


2019-11-26T22:44:13.944Z,1574808253.944 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2019-11-26T22:44:14.023Z,1574808254.023 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2019-11-26T22:44:14.024Z,1574808254.024 [Default:A.Wait](DEBUG): Construct Wait.
2019-11-26T22:44:14.052Z,1574808254.052 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2019-11-26T22:44:14.088Z,1574808254.088 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2019-11-26T22:44:14.091Z,1574808254.091 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2019-11-26T22:44:14.116Z,1574808254.116 [Default:E.Execute](DEBUG): Construct Execute.
2019-11-26T22:44:14.120Z,1574808254.120 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Universal="Tethys/Universal"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
         Id="Default">

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

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

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

    <Aggregate Id="CheckIn">

        <Sequence Repeat="288"/>

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

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

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

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

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

    </Aggregate>

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

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

</Mission>


2019-11-26T22:44:14.137Z,1574808254.137 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,NAL9602,Onboard,RDI_Pathfinder,DAT,BPC1,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2019-11-26T22:44:14.149Z,1574808254.149 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2019-11-26T22:44:14.186Z,1574808254.186 [Depth_Keller](ERROR): Pressure reading out of range: 1650.297119 decibar
2019-11-26T22:44:14.213Z,1574808254.213 [Radio_Surface](INFO): Powering up
2019-11-26T22:44:14.220Z,1574808254.220 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2019-11-26T22:44:14.220Z,1574808254.220 [DAT](INFO): Powering up
2019-11-26T22:44:14.220Z,1574808254.220 [DAT](DEBUG): Initializing DAT.
2019-11-26T22:44:14.257Z,1574808254.257 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2019-11-26T22:44:14.282Z,1574808254.282 [DepthRateCalculator](ERROR): Depth measurement is not active
2019-11-26T22:44:14.330Z,1574808254.330 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2019-11-26T22:44:14.341Z,1574808254.341 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2019-11-26T22:44:14.343Z,1574808254.343 [ElevatorServo](DEBUG): Initializing EZServoServo.
2019-11-26T22:44:14.353Z,1574808254.353 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2019-11-26T22:44:14.354Z,1574808254.354 [MassServo](DEBUG): Initializing EZServoServo.
2019-11-26T22:44:14.365Z,1574808254.365 [MassServo](DEBUG): Initializing MassServo.
2019-11-26T22:44:14.366Z,1574808254.366 [RudderServo](DEBUG): Initializing EZServoServo.
2019-11-26T22:44:14.377Z,1574808254.377 [RudderServo](DEBUG): Initializing RudderServo.
2019-11-26T22:44:14.378Z,1574808254.378 [ThrusterServo](DEBUG): Initializing EZServoServo.
2019-11-26T22:44:14.392Z,1574808254.392 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2019-11-26T22:44:14.564Z,1574808254.564 [DropWeight](CRITICAL): DROP WEIGHT MISSING.

2019-11-26T22:44:14.564Z,1574808254.564 [DropWeight] Hardware Fault, FailCount= 1
2019-11-26T22:44:14.564Z,1574808254.564 [DropWeight](ERROR): Hardware Fault
2019-11-26T22:44:14.585Z,1574808254.585 [DepthRateCalculator](ERROR): Depth measurement is not active
2019-11-26T22:44:14.609Z,1574808254.609 [CommandLine](FAULT): Scheduling is paused
2019-11-26T22:44:14.610Z,1574808254.610 [CBIT](INFO): Critical error at 20191126T224414
2019-11-26T22:44:14.610Z,1574808254.610 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2019-11-26T22:44:14.612Z,1574808254.612 [CBIT](ERROR): Hardware Fault in component: DropWeight
2019-11-26T22:44:14.613Z,1574808254.613 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2019-11-26T22:44:15.293Z,1574808255.293 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2019-11-26T22:44:15.293Z,1574808255.293 [RudderServo](FAULT): Rudder failed to initialize
2019-11-26T22:44:15.293Z,1574808255.293 [RudderServo] Communications Fault, FailCount= 1
2019-11-26T22:44:15.293Z,1574808255.293 [RudderServo](ERROR): Communications Fault
2019-11-26T22:44:15.402Z,1574808255.402 [CBIT](INFO): Critical error at 20191126T224414
2019-11-26T22:44:15.405Z,1574808255.405 [CBIT](ERROR): Communications Fault in component: RudderServo
2019-11-26T22:44:15.570Z,1574808255.570 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-11-26T22:44:15.570Z,1574808255.570 [RudderServo](INFO): Powering down
2019-11-26T22:44:16.249Z,1574808256.249 [RudderServo](DEBUG): Initializing EZServoServo.
2019-11-26T22:44:16.370Z,1574808256.370 [RudderServo](DEBUG): Initializing RudderServo.
2019-11-26T22:44:16.374Z,1574808256.374 [CBIT](INFO): Clearing failed state for component RudderServo
2019-11-26T22:44:16.374Z,1574808256.374 [RudderServo] No Fault, FailCount= 1
2019-11-26T22:44:20.874Z,1574808260.874 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit.
2019-11-26T22:44:24.745Z,1574808264.745 [DAT](DEBUG): 
2019-11-26T22:44:24.746Z,1574808264.746 [DAT](DEBUG): Teledyne Benthos DAT-900 Series
2019-11-26T22:44:25.947Z,1574808265.947 [DAT](DEBUG): MF Frequency Band
2019-11-26T22:44:25.948Z,1574808265.948 [DAT](DEBUG): Directional Acoustic Transponder version 8.12.21
2019-11-26T22:44:25.948Z,1574808265.948 [DAT](DEBUG): Nov 26 2019 22:44:22 
2019-11-26T22:44:26.759Z,1574808266.759 [DAT](DEBUG): Features enabled [Bearing]
2019-11-26T22:44:26.760Z,1574808266.760 [DAT](DEBUG): CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP
2019-11-26T22:44:26.760Z,1574808266.760 [DAT](INFO): commRate: 800
2019-11-26T22:44:27.166Z,1574808267.166 [DAT](INFO): entering command mode
2019-11-26T22:44:27.571Z,1574808267.571 [DAT](DEBUG): checking for command mode acknowledgment
2019-11-26T22:44:27.974Z,1574808267.974 [DAT](DEBUG): checking for command mode acknowledgment
2019-11-26T22:44:27.974Z,1574808267.974 [DAT](INFO): command mode acknowledged
2019-11-26T22:44:27.974Z,1574808267.974 [DAT](INFO): setting verbose to 3
2019-11-26T22:44:28.369Z,1574808268.369 [DAT](DEBUG): checking for verbose setting acknowledgment
2019-11-26T22:44:28.370Z,1574808268.370 [DAT](INFO): set verbose to 3
2019-11-26T22:44:28.783Z,1574808268.783 [DAT](INFO): setting transmit power to 8
2019-11-26T22:44:29.182Z,1574808269.182 [DAT](DEBUG): checking for transmit power setting acknowledgment
2019-11-26T22:44:29.581Z,1574808269.581 [DAT](DEBUG): checking for transmit power setting acknowledgment
2019-11-26T22:44:29.582Z,1574808269.582 [DAT](INFO): set transmit power to 8
2019-11-26T22:44:29.986Z,1574808269.986 [DAT](INFO): setting local address to 9
2019-11-26T22:44:30.389Z,1574808270.389 [DAT](DEBUG): checking for local address setting acknowledgment
2019-11-26T22:44:30.796Z,1574808270.796 [DAT](DEBUG): checking for local address setting acknowledgment
2019-11-26T22:44:30.797Z,1574808270.797 [DAT](INFO): set local address to 9
2019-11-26T22:44:36.460Z,1574808276.460 [RDI_Pathfinder](ERROR): No DVL communication! Re-initializing
2019-11-26T22:44:36.460Z,1574808276.460 [RDI_Pathfinder] Communications Fault, FailCount= 1
2019-11-26T22:44:36.460Z,1574808276.460 [RDI_Pathfinder](ERROR): Communications Fault
2019-11-26T22:44:36.485Z,1574808276.485 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2019-11-26T22:44:36.921Z,1574808276.921 [RDI_Pathfinder](INFO): Powering down
2019-11-26T22:44:37.681Z,1574808277.681 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2019-11-26T22:44:37.681Z,1574808277.681 [RDI_Pathfinder] No Fault, FailCount= 1
2019-11-26T22:44:40.874Z,1574808280.874 [NAL9602](INFO): Powering up NAL9602
2019-11-26T22:44:51.782Z,1574808291.782 [NAL9602](INFO): NAL9602 initialized
2019-11-26T22:44:53.467Z,1574808293.467 [SBIT](IMPORTANT): Beginning Startup BIT
2019-11-26T22:44:53.500Z,1574808293.500 [CBIT](IMPORTANT): Beginning ground fault scan
2019-11-26T22:45:00.403Z,1574808300.403 [RDI_Pathfinder](ERROR): No DVL communication! Re-initializing
2019-11-26T22:45:00.403Z,1574808300.403 [RDI_Pathfinder] Communications Fault, FailCount= 2
2019-11-26T22:45:00.403Z,1574808300.403 [RDI_Pathfinder](ERROR): Communications Fault
2019-11-26T22:45:00.494Z,1574808300.494 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2019-11-26T22:45:00.881Z,1574808300.881 [RDI_Pathfinder](INFO): Powering down
2019-11-26T22:45:01.671Z,1574808301.671 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2019-11-26T22:45:01.671Z,1574808301.671 [RDI_Pathfinder] No Fault, FailCount= 2
2019-11-26T22:45:04.505Z,1574808304.505 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.011340
CHAN A1 (24V): -0.000640
CHAN A2 (12V): -0.007759
CHAN A3 (5V): -0.001471
CHAN B0 (3.3V): 0.000052
CHAN B1 (3.15aV): -0.000505
CHAN B2 (3.15bV): -0.000452
CHAN B3 (GND): 0.001771
OPEN: 0.005077
Full Scale Calc: 4.765 mA, -1.589 mA
2019-11-26T22:45:24.384Z,1574808324.384 [RDI_Pathfinder](ERROR): No DVL communication! Re-initializing
2019-11-26T22:45:24.384Z,1574808324.384 [RDI_Pathfinder] Communications Fault, FailCount= 3
2019-11-26T22:45:24.385Z,1574808324.385 [RDI_Pathfinder](ERROR): Communications Fault
2019-11-26T22:45:24.446Z,1574808324.446 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2019-11-26T22:45:24.446Z,1574808324.446 [CBIT](CRITICAL): Communications Fault in component: RDI_Pathfinder
2019-11-26T22:45:24.849Z,1574808324.849 [RDI_Pathfinder](INFO): Powering down
2019-11-26T22:45:24.987Z,1574808324.987 [CBIT](INFO): Critical error at 20191126T224524
2019-11-26T22:45:46.749Z,1574808346.749 [SBIT](IMPORTANT): SBIT PASSED
2019-11-26T22:45:46.793Z,1574808346.793 [CommandLine](IMPORTANT): got command configSet list
2019-11-26T22:45:46.793Z,1574808346.793 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2019-11-26T22:45:46.794Z,1574808346.794 [CommandLine](IMPORTANT): CBIT.gf24Offset=143 microampere;

2019-11-26T22:45:46.794Z,1574808346.794 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=198 cubic_centimeter;

2019-11-26T22:45:46.794Z,1574808346.794 [CommandLine](IMPORTANT): VerticalControl.massDefault=5 millimeter;

2019-11-26T22:45:47.138Z,1574808347.138 [MissionManager](IMPORTANT): Started mission Startup
2019-11-26T22:45:47.138Z,1574808347.138 [Startup] Running Loop=1
2019-11-26T22:45:47.138Z,1574808347.138 [Startup](DEBUG): Aggregate::initialize Startup
2019-11-26T22:45:47.138Z,1574808347.138 [Startup:A.GoToSurface] Running Loop=1
2019-11-26T22:45:47.138Z,1574808347.138 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-11-26T22:45:47.139Z,1574808347.139 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-11-26T22:45:47.139Z,1574808347.139 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-11-26T22:45:47.140Z,1574808347.140 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-11-26T22:45:47.140Z,1574808347.140 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-11-26T22:45:47.141Z,1574808347.141 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-11-26T22:45:47.143Z,1574808347.143 [Startup:StartupSatComms] Running Loop=1
2019-11-26T22:45:47.143Z,1574808347.143 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2019-11-26T22:45:47.143Z,1574808347.143 [Startup:StartupSatComms:A] Running Loop=1
2019-11-26T22:45:47.547Z,1574808347.547 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2019-11-26T22:46:42.651Z,1574808402.651 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.005004
2019-11-26T22:46:47.324Z,1574808407.324 [Startup:StartupSatComms:A](INFO): Timed out from 2019-11-26T22:45:47.1Z
2019-11-26T22:46:47.325Z,1574808407.325 [Startup:StartupSatComms:A] Stopped
2019-11-26T22:46:47.325Z,1574808407.325 [Startup:StartupSatComms:B] Running Loop=1
2019-11-26T22:46:47.730Z,1574808407.730 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-11-26T22:46:54.936Z,1574808414.936 [DataOverHttps](INFO): Sending 91 bytes from file Logs/20191126T222714/Courier0007.lzma
2019-11-26T22:46:56.943Z,1574808416.943 [DataOverHttps](INFO): Moved sent file to Logs/20191126T222714/Courier0007.lzma.bak
2019-11-26T22:46:56.943Z,1574808416.943 [DataOverHttps](INFO): SBD MOMSN=12107848
2019-11-26T22:47:12.792Z,1574808432.792 [DataOverHttps](INFO): Sending 169 bytes from file Logs/20191126T224403/Courier0000.lzma
2019-11-26T22:47:13.982Z,1574808433.982 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2019-11-26T22:47:13.982Z,1574808433.982 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-11-26T22:47:13.991Z,1574808433.991 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-11-26T22:47:14.394Z,1574808434.394 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-11-26T22:47:14.394Z,1574808434.394 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2019-11-26T22:47:14.794Z,1574808434.794 [DataOverHttps](INFO): Moved sent file to Logs/20191126T224403/Courier0000.lzma.bak
2019-11-26T22:47:14.794Z,1574808434.794 [DataOverHttps](INFO): SBD MOMSN=12107852
2019-11-26T22:47:31.289Z,1574808451.289 [DataOverHttps](INFO): Sending 2118 bytes from file Logs/20191126T222714/Express0008.lzma
2019-11-26T22:47:33.290Z,1574808453.290 [DataOverHttps](INFO): Moved sent file to Logs/20191126T222714/Express0008.lzma.bak
2019-11-26T22:47:33.291Z,1574808453.291 [DataOverHttps](INFO): SBD MOMSN=12107858
2019-11-26T22:47:47.538Z,1574808467.538 [Startup:StartupSatComms:B](INFO): Timed out from 2019-11-26T22:46:47.3Z
2019-11-26T22:47:47.538Z,1574808467.538 [Startup:StartupSatComms:B] Stopped
2019-11-26T22:47:47.538Z,1574808467.538 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2019-11-26T22:47:47.538Z,1574808467.538 [Startup:StartupSatComms] Stopped
2019-11-26T22:47:47.539Z,1574808467.539 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2019-11-26T22:47:47.539Z,1574808467.539 [Startup](INFO): Completed Startup
2019-11-26T22:47:47.539Z,1574808467.539 [MissionManager](INFO): Startup is completed.
2019-11-26T22:47:47.540Z,1574808467.540 [MissionManager](INFO): Uninitializing Mission Startup
2019-11-26T22:47:47.540Z,1574808467.540 [Startup] Stopped
2019-11-26T22:47:47.540Z,1574808467.540 [Startup](DEBUG): Aggregate::uninitialize Startup
2019-11-26T22:47:47.540Z,1574808467.540 [Startup:A.GoToSurface] Stopped
2019-11-26T22:47:47.540Z,1574808467.540 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-11-26T22:47:47.939Z,1574808467.939 [MissionManager](IMPORTANT): Started mission Default
2019-11-26T22:47:47.940Z,1574808467.940 [Default] Running Loop=1
2019-11-26T22:47:47.940Z,1574808467.940 [Default](DEBUG): Aggregate::initialize Default
2019-11-26T22:47:47.940Z,1574808467.940 [Default:B.GoToSurface] Running Loop=1
2019-11-26T22:47:47.940Z,1574808467.940 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-11-26T22:47:47.940Z,1574808467.940 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-11-26T22:47:47.941Z,1574808467.941 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-11-26T22:47:47.941Z,1574808467.941 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-11-26T22:47:47.941Z,1574808467.941 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-11-26T22:47:47.942Z,1574808467.942 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-11-26T22:47:47.942Z,1574808467.942 [Default:A.Wait] Running Loop=1
2019-11-26T22:47:47.942Z,1574808467.942 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-11-26T22:47:50.238Z,1574808470.238 [DataOverHttps](INFO): Sending 786 bytes from file Logs/20191126T224403/Express0001.lzma
2019-11-26T22:47:52.242Z,1574808472.242 [DataOverHttps](INFO): Moved sent file to Logs/20191126T224403/Express0001.lzma.bak
2019-11-26T22:47:52.242Z,1574808472.242 [DataOverHttps](INFO): SBD MOMSN=12108019
2019-11-26T22:48:01.258Z,1574808481.258 [Default:A.Wait](INFO): Done Waiting.
2019-11-26T22:48:01.258Z,1574808481.258 [Default:A.Wait] Stopped
2019-11-26T22:48:01.258Z,1574808481.258 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-11-26T22:48:01.718Z,1574808481.718 [Default:CheckIn] Running Loop=1
2019-11-26T22:48:01.718Z,1574808481.718 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-11-26T22:48:01.718Z,1574808481.718 [Default:CheckIn:Read_GPS] Running Loop=1
2019-11-26T22:48:02.073Z,1574808482.073 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2019-11-26T22:48:24.710Z,1574808504.710 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2019-11-26T22:48:24.710Z,1574808504.710 [RDI_Pathfinder] No Fault, FailCount= 3
2019-11-26T22:48:37.605Z,1574808517.605 [RDI_Pathfinder](FAULT): DVL failed to acquire valid data within timeout.
2019-11-26T22:48:37.605Z,1574808517.605 [RDI_Pathfinder] Data Fault, FailCount= 1
2019-11-26T22:48:37.605Z,1574808517.605 [RDI_Pathfinder](ERROR): Data Fault
2019-11-26T22:48:37.648Z,1574808517.648 [CBIT](ERROR): Data Fault in component: RDI_Pathfinder
2019-11-26T22:48:38.085Z,1574808518.085 [RDI_Pathfinder](INFO): Powering down
2019-11-26T22:48:38.847Z,1574808518.847 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2019-11-26T22:48:38.847Z,1574808518.847 [RDI_Pathfinder] No Fault, FailCount= 1
2019-11-26T22:49:01.461Z,1574808541.461 [RDI_Pathfinder](ERROR): No DVL communication! Re-initializing
2019-11-26T22:49:01.461Z,1574808541.461 [RDI_Pathfinder] Communications Fault, FailCount= 2
2019-11-26T22:49:01.462Z,1574808541.462 [RDI_Pathfinder](ERROR): Communications Fault
2019-11-26T22:49:01.482Z,1574808541.482 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2019-11-26T22:49:01.925Z,1574808541.925 [RDI_Pathfinder](INFO): Powering down
2019-11-26T22:49:02.668Z,1574808542.668 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2019-11-26T22:49:02.668Z,1574808542.668 [RDI_Pathfinder] No Fault, FailCount= 2
2019-11-26T22:49:25.275Z,1574808565.275 [RDI_Pathfinder](ERROR): No DVL communication! Re-initializing
2019-11-26T22:49:25.275Z,1574808565.275 [RDI_Pathfinder] Communications Fault, FailCount= 3
2019-11-26T22:49:25.275Z,1574808565.275 [RDI_Pathfinder](ERROR): Communications Fault
2019-11-26T22:49:25.326Z,1574808565.326 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2019-11-26T22:49:25.327Z,1574808565.327 [CBIT](CRITICAL): Communications Fault in component: RDI_Pathfinder
2019-11-26T22:49:25.753Z,1574808565.753 [RDI_Pathfinder](INFO): Powering down
2019-11-26T22:49:25.792Z,1574808565.792 [CBIT](INFO): Critical error at 20191126T224925
2019-11-26T22:49:55.158Z,1574808595.158 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-11-26T22:50:14.980Z,1574808614.980 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2019-11-26T22:50:14.980Z,1574808614.980 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-11-26T22:50:14.991Z,1574808614.991 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-11-26T22:50:15.402Z,1574808615.402 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-11-26T22:50:15.402Z,1574808615.402 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2019-11-26T22:51:42.646Z,1574808702.646 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2019-11-26T22:51:42.648Z,1574808702.648 [BPC1](INFO): Received data from all battery sticks.
2019-11-26T22:52:25.480Z,1574808745.480 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2019-11-26T22:52:25.480Z,1574808745.480 [RDI_Pathfinder] No Fault, FailCount= 3
2019-11-26T22:52:38.412Z,1574808758.412 [RDI_Pathfinder](FAULT): DVL failed to acquire valid data within timeout.
2019-11-26T22:52:38.412Z,1574808758.412 [RDI_Pathfinder] Data Fault, FailCount= 1
2019-11-26T22:52:38.412Z,1574808758.412 [RDI_Pathfinder](ERROR): Data Fault
2019-11-26T22:52:38.483Z,1574808758.483 [CBIT](ERROR): Data Fault in component: RDI_Pathfinder
2019-11-26T22:52:38.881Z,1574808758.881 [RDI_Pathfinder](INFO): Powering down
2019-11-26T22:52:39.653Z,1574808759.653 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2019-11-26T22:52:39.654Z,1574808759.654 [RDI_Pathfinder] No Fault, FailCount= 1
2019-11-26T22:53:01.837Z,1574808781.837 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-11-26T22:48:01.7Z
2019-11-26T22:53:01.837Z,1574808781.837 [Default:CheckIn:Read_GPS] Stopped
2019-11-26T22:53:01.837Z,1574808781.837 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-11-26T22:53:02.221Z,1574808782.221 [RDI_Pathfinder](ERROR): No DVL communication! Re-initializing
2019-11-26T22:53:02.221Z,1574808782.221 [RDI_Pathfinder] Communications Fault, FailCount= 2
2019-11-26T22:53:02.221Z,1574808782.221 [RDI_Pathfinder](ERROR): Communications Fault
2019-11-26T22:53:02.228Z,1574808782.228 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-11-26T22:53:02.268Z,1574808782.268 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2019-11-26T22:53:02.705Z,1574808782.705 [RDI_Pathfinder](INFO): Powering down
2019-11-26T22:53:03.474Z,1574808783.474 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2019-11-26T22:53:03.474Z,1574808783.474 [RDI_Pathfinder] No Fault, FailCount= 2
2019-11-26T22:53:09.156Z,1574808789.156 [DataOverHttps](INFO): Sending 238 bytes from file Logs/20191126T224403/Courier0004.lzma
2019-11-26T22:53:11.162Z,1574808791.162 [DataOverHttps](INFO): Moved sent file to Logs/20191126T224403/Courier0004.lzma.bak
2019-11-26T22:53:11.163Z,1574808791.163 [DataOverHttps](INFO): SBD MOMSN=12108043
2019-11-26T22:53:15.964Z,1574808795.964 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2019-11-26T22:53:15.964Z,1574808795.964 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-11-26T22:53:15.979Z,1574808795.979 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-11-26T22:53:16.393Z,1574808796.393 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-11-26T22:53:16.394Z,1574808796.394 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2019-11-26T22:53:26.056Z,1574808806.056 [RDI_Pathfinder](ERROR): No DVL communication! Re-initializing
2019-11-26T22:53:26.056Z,1574808806.056 [RDI_Pathfinder] Communications Fault, FailCount= 3
2019-11-26T22:53:26.056Z,1574808806.056 [RDI_Pathfinder](ERROR): Communications Fault
2019-11-26T22:53:26.106Z,1574808806.106 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2019-11-26T22:53:26.106Z,1574808806.106 [CBIT](CRITICAL): Communications Fault in component: RDI_Pathfinder
2019-11-26T22:53:26.533Z,1574808806.533 [RDI_Pathfinder](INFO): Powering down
2019-11-26T22:53:26.552Z,1574808806.552 [CBIT](INFO): Critical error at 20191126T225326
2019-11-26T22:53:27.741Z,1574808807.741 [DataOverHttps](INFO): Sending 229 bytes from file Logs/20191126T224403/Express0005.lzma
2019-11-26T22:53:29.746Z,1574808809.746 [DataOverHttps](INFO): Moved sent file to Logs/20191126T224403/Express0005.lzma.bak
2019-11-26T22:53:29.746Z,1574808809.746 [DataOverHttps](INFO): SBD MOMSN=12108065
2019-11-26T22:53:30.940Z,1574808810.940 [Default:CheckIn:Read_Iridium] Stopped
2019-11-26T22:53:30.940Z,1574808810.940 [Default:CheckIn:C.Wait] Running Loop=1
2019-11-26T22:53:30.940Z,1574808810.940 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-11-26T22:54:52.910Z,1574808892.910 [NAL9602](FAULT): GPS failed to acquire within timeout.
2019-11-26T22:54:52.910Z,1574808892.910 [NAL9602] Data Fault, FailCount= 1
2019-11-26T22:54:52.910Z,1574808892.910 [NAL9602](ERROR): Data Fault
2019-11-26T22:54:52.939Z,1574808892.939 [CBIT](ERROR): Data Fault in component: NAL9602
2019-11-26T22:54:53.306Z,1574808893.306 [NAL9602](INFO): Powering down
2019-11-26T22:54:54.162Z,1574808894.162 [CBIT](INFO): Clearing failed state for component NAL9602
2019-11-26T22:54:54.162Z,1574808894.162 [NAL9602] No Fault, FailCount= 1
2019-11-26T22:55:23.606Z,1574808923.606 [NAL9602](INFO): Powering up NAL9602
2019-11-26T22:55:34.514Z,1574808934.514 [NAL9602](INFO): NAL9602 initialized
2019-11-26T22:56:16.980Z,1574808976.980 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2019-11-26T22:56:16.981Z,1574808976.981 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-11-26T22:56:17.014Z,1574808977.014 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-11-26T22:56:17.378Z,1574808977.378 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-11-26T22:56:17.378Z,1574808977.378 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2019-11-26T22:56:26.280Z,1574808986.280 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2019-11-26T22:56:26.280Z,1574808986.280 [RDI_Pathfinder] No Fault, FailCount= 3
2019-11-26T22:56:39.170Z,1574808999.170 [RDI_Pathfinder](FAULT): DVL failed to acquire valid data within timeout.
2019-11-26T22:56:39.170Z,1574808999.170 [RDI_Pathfinder] Data Fault, FailCount= 1
2019-11-26T22:56:39.170Z,1574808999.170 [RDI_Pathfinder](ERROR): Data Fault
2019-11-26T22:56:39.186Z,1574808999.186 [CBIT](ERROR): Data Fault in component: RDI_Pathfinder
2019-11-26T22:56:39.649Z,1574808999.649 [RDI_Pathfinder](INFO): Powering down
2019-11-26T22:56:40.423Z,1574809000.423 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2019-11-26T22:56:40.423Z,1574809000.423 [RDI_Pathfinder] No Fault, FailCount= 1
2019-11-26T22:57:03.026Z,1574809023.026 [RDI_Pathfinder](ERROR): No DVL communication! Re-initializing
2019-11-26T22:57:03.026Z,1574809023.026 [RDI_Pathfinder] Communications Fault, FailCount= 2
2019-11-26T22:57:03.026Z,1574809023.026 [RDI_Pathfinder](ERROR): Communications Fault
2019-11-26T22:57:03.046Z,1574809023.046 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2019-11-26T22:57:03.489Z,1574809023.489 [RDI_Pathfinder](INFO): Powering down
2019-11-26T22:57:04.240Z,1574809024.240 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2019-11-26T22:57:04.240Z,1574809024.240 [RDI_Pathfinder] No Fault, FailCount= 2
2019-11-26T22:57:26.852Z,1574809046.852 [RDI_Pathfinder](ERROR): No DVL communication! Re-initializing
2019-11-26T22:57:26.852Z,1574809046.852 [RDI_Pathfinder] Communications Fault, FailCount= 3
2019-11-26T22:57:26.852Z,1574809046.852 [RDI_Pathfinder](ERROR): Communications Fault
2019-11-26T22:57:26.898Z,1574809046.898 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2019-11-26T22:57:26.899Z,1574809046.899 [CBIT](CRITICAL): Communications Fault in component: RDI_Pathfinder
2019-11-26T22:57:27.337Z,1574809047.337 [RDI_Pathfinder](INFO): Powering down
2019-11-26T22:57:27.370Z,1574809047.370 [CBIT](INFO): Critical error at 20191126T225726
2019-11-26T22:58:31.527Z,1574809111.527 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-11-26T22:58:31.527Z,1574809111.527 [Default:CheckIn:C.Wait] Stopped
2019-11-26T22:58:31.527Z,1574809111.527 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-11-26T22:58:31.527Z,1574809111.527 [Default:CheckIn:D] Running Loop=1
2019-11-26T22:58:31.910Z,1574809111.910 [Default:CheckIn:D] Stopped
2019-11-26T22:58:31.910Z,1574809111.910 [Default:CheckIn:E] Running Loop=1
2019-11-26T22:58:32.311Z,1574809112.311 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.732833 min 
2019-11-26T22:58:32.311Z,1574809112.311 [Default:CheckIn:E] Stopped
2019-11-26T22:58:32.312Z,1574809112.312 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-11-26T22:58:32.312Z,1574809112.312 [Default:CheckIn] Stopped
2019-11-26T22:58:32.312Z,1574809112.312 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-11-26T22:58:32.312Z,1574809112.312 [Default:CheckIn](INFO): Running loop #2
2019-11-26T22:58:32.312Z,1574809112.312 [Default:CheckIn] Running Loop=2
2019-11-26T22:58:32.312Z,1574809112.312 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-11-26T22:58:32.312Z,1574809112.312 [Default:CheckIn:Read_GPS] Running Loop=1
2019-11-26T22:59:14.762Z,1574809154.762 [CBIT](INFO): Clearing failed state for component DropWeight
2019-11-26T22:59:14.762Z,1574809154.762 [DropWeight] No Fault, FailCount= 1
2019-11-26T22:59:17.976Z,1574809157.976 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2019-11-26T22:59:17.976Z,1574809157.976 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-11-26T22:59:17.986Z,1574809157.986 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-11-26T22:59:18.394Z,1574809158.394 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-11-26T22:59:18.394Z,1574809158.394 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2019-11-26T23:00:27.086Z,1574809227.086 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2019-11-26T23:00:27.086Z,1574809227.086 [RDI_Pathfinder] No Fault, FailCount= 3
2019-11-26T23:00:39.985Z,1574809239.985 [RDI_Pathfinder](FAULT): DVL failed to acquire valid data within timeout.
2019-11-26T23:00:39.985Z,1574809239.985 [RDI_Pathfinder] Data Fault, FailCount= 1
2019-11-26T23:00:39.985Z,1574809239.985 [RDI_Pathfinder](ERROR): Data Fault
2019-11-26T23:00:40.006Z,1574809240.006 [CBIT](ERROR): Data Fault in component: RDI_Pathfinder
2019-11-26T23:00:40.449Z,1574809240.449 [RDI_Pathfinder](INFO): Powering down
2019-11-26T23:00:41.243Z,1574809241.243 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2019-11-26T23:00:41.243Z,1574809241.243 [RDI_Pathfinder] No Fault, FailCount= 1
2019-11-26T23:01:03.817Z,1574809263.817 [RDI_Pathfinder](ERROR): No DVL communication! Re-initializing
2019-11-26T23:01:03.817Z,1574809263.817 [RDI_Pathfinder] Communications Fault, FailCount= 2
2019-11-26T23:01:03.817Z,1574809263.817 [RDI_Pathfinder](ERROR): Communications Fault
2019-11-26T23:01:03.832Z,1574809263.832 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2019-11-26T23:01:04.302Z,1574809264.302 [RDI_Pathfinder](INFO): Powering down
2019-11-26T23:01:05.070Z,1574809265.070 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2019-11-26T23:01:05.070Z,1574809265.070 [RDI_Pathfinder] No Fault, FailCount= 2
2019-11-26T23:01:27.655Z,1574809287.655 [RDI_Pathfinder](ERROR): No DVL communication! Re-initializing
2019-11-26T23:01:27.656Z,1574809287.656 [RDI_Pathfinder] Communications Fault, FailCount= 3
2019-11-26T23:01:27.656Z,1574809287.656 [RDI_Pathfinder](ERROR): Communications Fault
2019-11-26T23:01:27.678Z,1574809287.678 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2019-11-26T23:01:27.678Z,1574809287.678 [CBIT](CRITICAL): Communications Fault in component: RDI_Pathfinder
2019-11-26T23:01:28.125Z,1574809288.125 [RDI_Pathfinder](INFO): Powering down
2019-11-26T23:01:28.145Z,1574809288.145 [CBIT](INFO): Critical error at 20191126T230127
2019-11-26T23:02:18.963Z,1574809338.963 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6
2019-11-26T23:02:18.963Z,1574809338.963 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-11-26T23:02:18.995Z,1574809338.995 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-11-26T23:02:19.380Z,1574809339.380 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-11-26T23:02:19.380Z,1574809339.380 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6
2019-11-26T23:03:32.496Z,1574809412.496 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-11-26T22:58:32.3Z
2019-11-26T23:03:32.496Z,1574809412.496 [Default:CheckIn:Read_GPS] Stopped
2019-11-26T23:03:32.496Z,1574809412.496 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-11-26T23:03:37.992Z,1574809417.992 [DataOverHttps](INFO): Sending 96 bytes from file Logs/20191126T224403/Courier0007.lzma
2019-11-26T23:03:39.998Z,1574809419.998 [DataOverHttps](INFO): Moved sent file to Logs/20191126T224403/Courier0007.lzma.bak
2019-11-26T23:03:39.998Z,1574809419.998 [DataOverHttps](INFO): SBD MOMSN=12108258
2019-11-26T23:03:56.845Z,1574809436.845 [DataOverHttps](INFO): Sending 202 bytes from file Logs/20191126T224403/Express0008.lzma
2019-11-26T23:03:58.851Z,1574809438.851 [DataOverHttps](INFO): Moved sent file to Logs/20191126T224403/Express0008.lzma.bak
2019-11-26T23:03:58.851Z,1574809438.851 [DataOverHttps](INFO): SBD MOMSN=12108263
2019-11-26T23:04:00.381Z,1574809440.381 [Default:CheckIn:Read_Iridium] Stopped
2019-11-26T23:04:00.381Z,1574809440.381 [Default:CheckIn:C.Wait] Running Loop=1
2019-11-26T23:04:00.381Z,1574809440.381 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-11-26T23:04:09.850Z,1574809449.850 [CommandLine](IMPORTANT): got command configSet list
2019-11-26T23:04:09.850Z,1574809449.850 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2019-11-26T23:04:09.851Z,1574809449.851 [CommandLine](IMPORTANT): CBIT.gf24Offset=143 microampere;

2019-11-26T23:04:09.851Z,1574809449.851 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=198 cubic_centimeter;

2019-11-26T23:04:09.851Z,1574809449.851 [CommandLine](IMPORTANT): VerticalControl.massDefault=5 millimeter;

2019-11-26T23:04:15.015Z,1574809455.015 [CommandLine](IMPORTANT): got command get DAT.sbdAddress
2019-11-26T23:04:15.016Z,1574809455.016 [CommandLine](IMPORTANT): DAT.sbdAddress -1 enum
2019-11-26T23:04:21.442Z,1574809461.442 [CommandLine](IMPORTANT): got command get DAT.localAddress
2019-11-26T23:04:21.442Z,1574809461.442 [CommandLine](IMPORTANT): DAT.localAddress 9 count
2019-11-26T23:04:27.877Z,1574809467.877 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2019-11-26T23:04:27.877Z,1574809467.877 [RDI_Pathfinder] No Fault, FailCount= 3
2019-11-26T23:04:40.776Z,1574809480.776 [RDI_Pathfinder](FAULT): DVL failed to acquire valid data within timeout.
2019-11-26T23:04:40.776Z,1574809480.776 [RDI_Pathfinder] Data Fault, FailCount= 1
2019-11-26T23:04:40.776Z,1574809480.776 [RDI_Pathfinder](ERROR): Data Fault
2019-11-26T23:04:40.798Z,1574809480.798 [CBIT](ERROR): Data Fault in component: RDI_Pathfinder
2019-11-26T23:04:41.229Z,1574809481.229 [RDI_Pathfinder](INFO): Powering down
2019-11-26T23:04:41.993Z,1574809481.993 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2019-11-26T23:04:41.993Z,1574809481.993 [RDI_Pathfinder] No Fault, FailCount= 1
2019-11-26T23:05:04.597Z,1574809504.597 [RDI_Pathfinder](ERROR): No DVL communication! Re-initializing
2019-11-26T23:05:04.597Z,1574809504.597 [RDI_Pathfinder] Communications Fault, FailCount= 2
2019-11-26T23:05:04.597Z,1574809504.597 [RDI_Pathfinder](ERROR): Communications Fault
2019-11-26T23:05:04.612Z,1574809504.612 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2019-11-26T23:05:05.077Z,1574809505.077 [RDI_Pathfinder](INFO): Powering down
2019-11-26T23:05:05.846Z,1574809505.846 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2019-11-26T23:05:05.846Z,1574809505.846 [RDI_Pathfinder] No Fault, FailCount= 2
2019-11-26T23:05:19.964Z,1574809519.964 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7
2019-11-26T23:05:19.965Z,1574809519.965 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-11-26T23:05:19.974Z,1574809519.974 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-11-26T23:05:20.377Z,1574809520.377 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-11-26T23:05:20.377Z,1574809520.377 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7
2019-11-26T23:05:28.453Z,1574809528.453 [RDI_Pathfinder](ERROR): No DVL communication! Re-initializing
2019-11-26T23:05:28.454Z,1574809528.454 [RDI_Pathfinder] Communications Fault, FailCount= 3
2019-11-26T23:05:28.454Z,1574809528.454 [RDI_Pathfinder](ERROR): Communications Fault
2019-11-26T23:05:28.469Z,1574809528.469 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2019-11-26T23:05:28.469Z,1574809528.469 [CBIT](CRITICAL): Communications Fault in component: RDI_Pathfinder
2019-11-26T23:05:28.917Z,1574809528.917 [RDI_Pathfinder](INFO): Powering down
2019-11-26T23:05:28.936Z,1574809528.936 [CBIT](INFO): Critical error at 20191126T230528
2019-11-26T23:05:33.559Z,1574809533.559 [CommandLine](IMPORTANT): got command configSet DAT.verbosity 3.000000 count persist
2019-11-26T23:05:36.902Z,1574809536.902 [NAL9602](FAULT): GPS failed to acquire within timeout.
2019-11-26T23:05:36.903Z,1574809536.903 [NAL9602] Data Fault, FailCount= 2
2019-11-26T23:05:36.903Z,1574809536.903 [NAL9602](ERROR): Data Fault
2019-11-26T23:05:36.960Z,1574809536.960 [CBIT](ERROR): Data Fault in component: NAL9602
2019-11-26T23:05:37.306Z,1574809537.306 [NAL9602](INFO): Powering down
2019-11-26T23:05:38.154Z,1574809538.154 [CBIT](INFO): Clearing failed state for component NAL9602
2019-11-26T23:05:38.154Z,1574809538.154 [NAL9602] No Fault, FailCount= 2
2019-11-26T23:06:07.602Z,1574809567.602 [NAL9602](INFO): Powering up NAL9602
2019-11-26T23:06:18.515Z,1574809578.515 [NAL9602](INFO): NAL9602 initialized
2019-11-26T23:06:23.366Z,1574809583.366 [CommandLine](IMPORTANT): got command configSet DAT.sbdAddress 8.000000 enum persist
2019-11-26T23:06:25.255Z,1574809585.255 [CommandLine](IMPORTANT): got command configSet list
2019-11-26T23:06:25.255Z,1574809585.255 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2019-11-26T23:06:25.256Z,1574809585.256 [CommandLine](IMPORTANT): CBIT.gf24Offset=143 microampere;

2019-11-26T23:06:25.256Z,1574809585.256 [CommandLine](IMPORTANT): DAT.sbdAddress=8 enum;

2019-11-26T23:06:25.256Z,1574809585.256 [CommandLine](IMPORTANT): DAT.verbosity=3 count;

2019-11-26T23:06:25.256Z,1574809585.256 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=198 cubic_centimeter;

2019-11-26T23:06:25.256Z,1574809585.256 [CommandLine](IMPORTANT): VerticalControl.massDefault=5 millimeter;

2019-11-26T23:07:03.199Z,1574809623.199 [CommandLine](IMPORTANT): got command restart application
2019-11-26T23:07:04.205Z,1574809624.205 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2019-11-26T23:07:04.205Z,1574809624.205 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-11-26T23:07:04.329Z,1574809624.329 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2019-11-26T23:07:04.329Z,1574809624.329 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-11-26T23:07:04.330Z,1574809624.330 [CommandLine](INFO): Join timeout helper Thread ID is 6063
2019-11-26T23:07:04.335Z,1574809624.335 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2019-11-26T23:07:04.335Z,1574809624.335 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-11-26T23:07:04.336Z,1574809624.336 [NavChartDb](INFO): Join timeout helper Thread ID is 6064
2019-11-26T23:07:04.446Z,1574809624.446 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2019-11-26T23:07:04.446Z,1574809624.446 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-11-26T23:07:04.453Z,1574809624.453 [ComponentRegistry](INFO): Shutting down WetLabsUBAT ThreadHandler
2019-11-26T23:07:04.453Z,1574809624.453 [WetLabsUBAT ThreadHandler](INFO): Thread cancelled.
2019-11-26T23:07:04.453Z,1574809624.453 [WetLabsUBAT](INFO): Join timeout helper Thread ID is 6065
2019-11-26T23:07:04.730Z,1574809624.730 [WetLabsUBAT ThreadHandler](INFO): Uninitializing protected caller thread.
2019-11-26T23:07:04.730Z,1574809624.730 [WetLabsUBAT](INFO): Powering down
2019-11-26T23:07:04.761Z,1574809624.761 [WetLabsUBAT ThreadHandler](INFO): Thread cancelled.
2019-11-26T23:07:04.781Z,1574809624.781 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2019-11-26T23:07:04.781Z,1574809624.781 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-11-26T23:07:04.781Z,1574809624.781 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 6066
2019-11-26T23:07:04.949Z,1574809624.949 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2019-11-26T23:07:04.950Z,1574809624.950 [WetLabsBB2FL](INFO): Powering down
2019-11-26T23:07:04.950Z,1574809624.950 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-11-26T23:07:04.961Z,1574809624.961 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2019-11-26T23:07:04.961Z,1574809624.961 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2019-11-26T23:07:04.961Z,1574809624.961 [CTD_Seabird](INFO): Join timeout helper Thread ID is 6067
2019-11-26T23:07:05.497Z,1574809625.497 [CTD_Seabird](INFO): Powering down
2019-11-26T23:07:05.509Z,1574809625.509 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2019-11-26T23:07:05.509Z,1574809625.509 [CTD_Seabird](INFO): Powering down
2019-11-26T23:07:05.521Z,1574809625.521 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2019-11-26T23:07:05.539Z,1574809625.539 [ComponentRegistry](INFO): Shutting down BackSeatDriver ThreadHandler
2019-11-26T23:07:05.539Z,1574809625.539 [BackSeatDriver ThreadHandler](INFO): Thread cancelled.
2019-11-26T23:07:05.539Z,1574809625.539 [BackSeatDriver](INFO): Join timeout helper Thread ID is 6068
2019-11-26T23:07:05.885Z,1574809625.885 [BackSeatDriver ThreadHandler](INFO): Uninitializing protected caller thread.
2019-11-26T23:07:05.885Z,1574809625.885 [BackSeatDriver ThreadHandler](INFO): Thread cancelled.
2019-11-26T23:07:05.890Z,1574809625.890 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2019-11-26T23:07:05.890Z,1574809625.890 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-11-26T23:07:05.890Z,1574809625.890 [Radio_Surface](INFO): Join timeout helper Thread ID is 6069
2019-11-26T23:07:05.941Z,1574809625.941 [Radio_Surface](INFO): Powering down
2019-11-26T23:07:05.945Z,1574809625.945 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2019-11-26T23:07:05.951Z,1574809625.951 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-11-26T23:07:05.970Z,1574809625.970 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2019-11-26T23:07:05.970Z,1574809625.970 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-11-26T23:07:05.970Z,1574809625.970 [DataOverHttps](INFO): Join timeout helper Thread ID is 6070
2019-11-26T23:07:06.185Z,1574809626.185 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2019-11-26T23:07:06.185Z,1574809626.185 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-11-26T23:07:06.190Z,1574809626.190 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2019-11-26T23:07:06.190Z,1574809626.190 [logger ThreadHandler](INFO): Thread cancelled.
2019-11-26T23:07:06.190Z,1574809626.190 [logger](INFO): Join timeout helper Thread ID is 6071
2019-11-26T23:07:06.205Z,1574809626.205 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2019-11-26T23:07:06.205Z,1574809626.205 [logger ThreadHandler](INFO): Thread cancelled.
2019-11-26T23:07:06.214Z,1574809626.214 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2019-11-26T23:07:06.214Z,1574809626.214 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-11-26T23:07:06.214Z,1574809626.214 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2019-11-26T23:07:06.214Z,1574809626.214 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-11-26T23:07:06.214Z,1574809626.214 [controlThread](INFO): Join timeout helper Thread ID is 6072
2019-11-26T23:07:06.230Z,1574809626.230 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2019-11-26T23:07:06.230Z,1574809626.230 [controlThread](DEBUG): Uninitializing ControlThread
2019-11-26T23:07:06.230Z,1574809626.230 [AHRS_M2](INFO): Powering down
2019-11-26T23:07:06.302Z,1574809626.302 [NAL9602](INFO): Powering down
2019-11-26T23:07:06.303Z,1574809626.303 [RDI_Pathfinder](INFO): Powering down
2019-11-26T23:07:06.304Z,1574809626.304 [DAT](INFO): Powering down
2019-11-26T23:07:06.421Z,1574809626.421 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2019-11-26T23:07:06.422Z,1574809626.422 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2019-11-26T23:07:06.423Z,1574809626.423 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2019-11-26T23:07:06.423Z,1574809626.423 [MissionManager](INFO): Uninitializing Mission Default
2019-11-26T23:07:06.423Z,1574809626.423 [Default] Stopped
2019-11-26T23:07:06.423Z,1574809626.423 [Default](DEBUG): Aggregate::uninitialize Default
2019-11-26T23:07:06.424Z,1574809626.424 [Default:B.GoToSurface] Stopped
2019-11-26T23:07:06.424Z,1574809626.424 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-11-26T23:07:06.424Z,1574809626.424 [Default:CheckIn] Stopped
2019-11-26T23:07:06.424Z,1574809626.424 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-11-26T23:07:06.424Z,1574809626.424 [Default:CheckIn:C.Wait] Stopped
2019-11-26T23:07:06.424Z,1574809626.424 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-11-26T23:07:06.426Z,1574809626.426 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2019-11-26T23:07:06.426Z,1574809626.426 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2019-11-26T23:07:06.427Z,1574809626.427 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2019-11-26T23:07:06.427Z,1574809626.427 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2019-11-26T23:07:06.427Z,1574809626.427 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2019-11-26T23:07:06.427Z,1574809626.427 [BuoyancyServo](INFO): Powering down
2019-11-26T23:07:06.441Z,1574809626.441 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2019-11-26T23:07:06.441Z,1574809626.441 [ElevatorServo](INFO): Powering down
2019-11-26T23:07:06.442Z,1574809626.442 [MassServo](DEBUG): Uninitialize Mass Servo.
2019-11-26T23:07:06.442Z,1574809626.442 [MassServo](INFO): Powering down
2019-11-26T23:07:06.443Z,1574809626.443 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-11-26T23:07:06.443Z,1574809626.443 [RudderServo](INFO): Powering down
2019-11-26T23:07:06.443Z,1574809626.443 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2019-11-26T23:07:06.444Z,1574809626.444 [ThrusterServo](INFO): Powering down
2019-11-26T23:07:06.444Z,1574809626.444 [SBIT](DEBUG): Uninitialize SBIT Component.
2019-11-26T23:07:06.445Z,1574809626.445 [IBIT](DEBUG): Uninitialize IBIT Component.
2019-11-26T23:07:06.445Z,1574809626.445 [CBIT](DEBUG): Uninitialize CBIT Component.
2019-11-26T23:07:06.445Z,1574809626.445 [CBIT](DEBUG): Powering off loads.
2019-11-26T23:07:06.457Z,1574809626.457 [CBIT](DEBUG): Disabling WDT.
2019-11-26T23:07:06.469Z,1574809626.469 [CBIT](DEBUG): Opening all GF detection circuits.
2019-11-26T23:07:06.470Z,1574809626.470 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-11-26T23:07:06.571Z,1574809626.571 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-11-26T23:07:06.576Z,1574809626.576 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-11-26T23:07:06.633Z,1574809626.633 [WetLabsUBAT ThreadHandler](INFO): Thread cancelled.
2019-11-26T23:07:06.635Z,1574809626.635 [WetLabsUBAT](INFO): WetLabs destructor: _dataLog is not open
2019-11-26T23:07:06.635Z,1574809626.635 [WetLabsUBAT](INFO): WetLabs destructor: done
2019-11-26T23:07:06.638Z,1574809626.638 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-11-26T23:07:06.640Z,1574809626.640 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2019-11-26T23:07:06.643Z,1574809626.643 [BackSeatDriver ThreadHandler](INFO): Thread cancelled.
2019-11-26T23:07:06.652Z,1574809626.652 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-11-26T23:07:06.713Z,1574809626.713 [logger ThreadHandler](INFO): Thread cancelled.