2019-12-30T19:08:56.085Z,1577732936.085 [Supervisor](DEBUG): Initializing supervisor.
2019-12-30T19:08:56.088Z,1577732936.088 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2019-12-30T19:08:56.088Z,1577732936.088 [SyncHandler](INFO): Protected caller Thread ID is 813
2019-12-30T19:08:56.089Z,1577732936.089 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2019-12-30T19:08:56.090Z,1577732936.090 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2019-12-30T19:08:56.090Z,1577732936.090 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 814
2019-12-30T19:08:56.093Z,1577732936.093 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2019-12-30T19:08:56.104Z,1577732936.104 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2019-12-30T19:08:56.104Z,1577732936.104 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2019-12-30T19:08:56.105Z,1577732936.105 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 815
2019-12-30T19:08:56.106Z,1577732936.106 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2019-12-30T19:08:56.107Z,1577732936.107 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2019-12-30T19:08:56.107Z,1577732936.107 [logger ThreadHandler](INFO): Protected caller Thread ID is 816
2019-12-30T19:08:56.109Z,1577732936.109 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2019-12-30T19:08:56.109Z,1577732936.109 [Supervisor](INFO): Looking for Config files in directory: Config/
2019-12-30T19:08:56.114Z,1577732936.114 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2019-12-30T19:08:56.364Z,1577732936.364 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2019-12-30T19:08:56.366Z,1577732936.366 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2019-12-30T19:08:56.447Z,1577732936.447 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2019-12-30T19:08:56.871Z,1577732936.871 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2019-12-30T19:08:56.873Z,1577732936.873 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2019-12-30T19:08:57.191Z,1577732937.191 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2019-12-30T19:08:57.192Z,1577732937.192 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2019-12-30T19:08:57.288Z,1577732937.288 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2019-12-30T19:08:57.289Z,1577732937.289 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2019-12-30T19:08:57.578Z,1577732937.578 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2019-12-30T19:08:57.580Z,1577732937.580 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2019-12-30T19:08:57.777Z,1577732937.777 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2019-12-30T19:08:57.779Z,1577732937.779 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2019-12-30T19:08:58.230Z,1577732938.230 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2019-12-30T19:08:58.230Z,1577732938.230 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2019-12-30T19:08:58.332Z,1577732938.332 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2019-12-30T19:08:58.334Z,1577732938.334 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2019-12-30T19:08:58.433Z,1577732938.433 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2019-12-30T19:08:58.435Z,1577732938.435 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2019-12-30T19:08:59.057Z,1577732939.057 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2019-12-30T19:08:59.058Z,1577732939.058 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2019-12-30T19:08:59.461Z,1577732939.461 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2019-12-30T19:08:59.462Z,1577732939.462 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2019-12-30T19:09:00.302Z,1577732940.302 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2019-12-30T19:09:00.303Z,1577732940.303 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2019-12-30T19:09:00.445Z,1577732940.445 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2019-12-30T19:09:00.446Z,1577732940.446 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2019-12-30T19:09:00.596Z,1577732940.596 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2019-12-30T19:09:00.598Z,1577732940.598 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2019-12-30T19:09:00.600Z,1577732940.600 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2019-12-30T19:09:00.690Z,1577732940.690 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2019-12-30T19:09:00.776Z,1577732940.776 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2019-12-30T19:09:00.875Z,1577732940.875 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2019-12-30T19:09:00.957Z,1577732940.957 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2019-12-30T19:09:01.052Z,1577732941.052 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2019-12-30T19:09:01.151Z,1577732941.151 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2019-12-30T19:09:01.352Z,1577732941.352 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2019-12-30T19:09:01.428Z,1577732941.428 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2019-12-30T19:09:01.589Z,1577732941.589 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2019-12-30T19:09:01.732Z,1577732941.732 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2019-12-30T19:09:01.846Z,1577732941.846 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg
2019-12-30T19:09:02.070Z,1577732942.070 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2019-12-30T19:09:02.071Z,1577732942.071 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2019-12-30T19:09:02.084Z,1577732942.084 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2019-12-30T19:09:02.146Z,1577732942.146 [VerticalControl](DEBUG): Construct VerticalControl.
2019-12-30T19:09:02.257Z,1577732942.257 [VerticalControl] Loaded
2019-12-30T19:09:02.257Z,1577732942.257 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2019-12-30T19:09:02.258Z,1577732942.258 [HorizontalControl](DEBUG): Construct HorizontalControl.
2019-12-30T19:09:02.326Z,1577732942.326 [HorizontalControl] Loaded
2019-12-30T19:09:02.326Z,1577732942.326 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2019-12-30T19:09:02.327Z,1577732942.327 [SpeedControl](DEBUG): Construct SpeedControl.
2019-12-30T19:09:02.332Z,1577732942.332 [SpeedControl] Loaded
2019-12-30T19:09:02.332Z,1577732942.332 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2019-12-30T19:09:02.333Z,1577732942.333 [LoopControl](DEBUG): Construct LoopControl.
2019-12-30T19:09:02.334Z,1577732942.334 [LoopControl] Loaded
2019-12-30T19:09:02.334Z,1577732942.334 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2019-12-30T19:09:02.334Z,1577732942.334 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2019-12-30T19:09:02.336Z,1577732942.336 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2019-12-30T19:09:02.360Z,1577732942.360 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2019-12-30T19:09:02.360Z,1577732942.360 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2019-12-30T19:09:02.484Z,1577732942.484 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2019-12-30T19:09:02.484Z,1577732942.484 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2019-12-30T19:09:02.679Z,1577732942.679 [BuoyancyServo] Loaded
2019-12-30T19:09:02.679Z,1577732942.679 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2019-12-30T19:09:02.690Z,1577732942.690 [ElevatorServo] Loaded
2019-12-30T19:09:02.690Z,1577732942.690 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2019-12-30T19:09:02.701Z,1577732942.701 [MassServo] Loaded
2019-12-30T19:09:02.701Z,1577732942.701 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2019-12-30T19:09:02.712Z,1577732942.712 [RudderServo] Loaded
2019-12-30T19:09:02.713Z,1577732942.713 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2019-12-30T19:09:02.724Z,1577732942.724 [ThrusterServo] Loaded
2019-12-30T19:09:02.724Z,1577732942.724 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2019-12-30T19:09:02.724Z,1577732942.724 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2019-12-30T19:09:02.725Z,1577732942.725 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2019-12-30T19:09:02.848Z,1577732942.848 [DeadReckonUsingMultipleVelocitySources] Loaded
2019-12-30T19:09:02.848Z,1577732942.848 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2019-12-30T19:09:02.868Z,1577732942.868 [NavChart] Loaded
2019-12-30T19:09:02.869Z,1577732942.869 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2019-12-30T19:09:02.872Z,1577732942.872 [UniversalFixResidualReporter] Loaded
2019-12-30T19:09:02.873Z,1577732942.873 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2019-12-30T19:09:02.873Z,1577732942.873 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2019-12-30T19:09:02.874Z,1577732942.874 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2019-12-30T19:09:02.986Z,1577732942.986 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2019-12-30T19:09:02.986Z,1577732942.986 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2019-12-30T19:09:03.577Z,1577732943.577 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_orientation
2019-12-30T19:09:03.582Z,1577732943.582 [AHRS_M2](INFO): created writer for : platform_orientation
2019-12-30T19:09:03.584Z,1577732943.584 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_magnetic_orientation
2019-12-30T19:09:03.589Z,1577732943.589 [AHRS_M2](INFO): created writer for : platform_magnetic_orientation
2019-12-30T19:09:03.589Z,1577732943.589 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_pitch_angle
2019-12-30T19:09:03.594Z,1577732943.594 [AHRS_M2](INFO): created writer for : platform_pitch_angle
2019-12-30T19:09:03.595Z,1577732943.595 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_roll_angle
2019-12-30T19:09:03.600Z,1577732943.600 [AHRS_M2](INFO): created writer for : platform_roll_angle
2019-12-30T19:09:03.776Z,1577732943.776 [AHRS_M2] Loaded
2019-12-30T19:09:03.776Z,1577732943.776 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2019-12-30T19:09:04.109Z,1577732944.109 [DataOverHttps] Loaded
2019-12-30T19:09:04.109Z,1577732944.109 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2019-12-30T19:09:04.110Z,1577732944.110 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 408644E0
2019-12-30T19:09:04.110Z,1577732944.110 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 899
2019-12-30T19:09:04.124Z,1577732944.124 [Depth_Keller] Loaded
2019-12-30T19:09:04.124Z,1577732944.124 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2019-12-30T19:09:04.129Z,1577732944.129 [DropWeight] Loaded
2019-12-30T19:09:04.129Z,1577732944.129 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2019-12-30T19:09:04.223Z,1577732944.223 [NAL9602] Loaded
2019-12-30T19:09:04.223Z,1577732944.223 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2019-12-30T19:09:04.238Z,1577732944.238 [Onboard] Loaded
2019-12-30T19:09:04.239Z,1577732944.239 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2019-12-30T19:09:04.242Z,1577732944.242 [Radio_Surface] Loaded
2019-12-30T19:09:04.242Z,1577732944.242 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2019-12-30T19:09:04.243Z,1577732944.243 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408944E0
2019-12-30T19:09:04.244Z,1577732944.244 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 900
2019-12-30T19:09:06.229Z,1577732946.229 [BPC1] Loaded
2019-12-30T19:09:06.229Z,1577732946.229 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2019-12-30T19:09:06.230Z,1577732946.230 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2019-12-30T19:09:06.230Z,1577732946.230 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2019-12-30T19:09:06.285Z,1577732946.285 [DepthRateCalculator] Loaded
2019-12-30T19:09:06.285Z,1577732946.285 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2019-12-30T19:09:06.290Z,1577732946.290 [PitchRateCalculator] Loaded
2019-12-30T19:09:06.290Z,1577732946.290 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2019-12-30T19:09:06.302Z,1577732946.302 [SpeedCalculator] Loaded
2019-12-30T19:09:06.302Z,1577732946.302 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2019-12-30T19:09:06.323Z,1577732946.323 [TempGradientCalculator] Loaded
2019-12-30T19:09:06.323Z,1577732946.323 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2019-12-30T19:09:06.328Z,1577732946.328 [YawRateCalculator] Loaded
2019-12-30T19:09:06.329Z,1577732946.329 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2019-12-30T19:09:06.358Z,1577732946.358 [ElevatorOffsetCalculator] Loaded
2019-12-30T19:09:06.358Z,1577732946.358 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2019-12-30T19:09:06.359Z,1577732946.359 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2019-12-30T19:09:06.359Z,1577732946.359 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2019-12-30T19:09:06.617Z,1577732946.617 [CANONSampler] Loaded
2019-12-30T19:09:06.618Z,1577732946.618 [ComponentRegistry](DEBUG): SyncComponent "CANONSampler" handled in the control thread.
2019-12-30T19:09:06.627Z,1577732946.627 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density
2019-12-30T19:09:06.632Z,1577732946.632 [CTD_Seabird](INFO): created writer for : sea_water_density
2019-12-30T19:09:06.633Z,1577732946.633 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth
2019-12-30T19:09:06.638Z,1577732946.638 [CTD_Seabird](INFO): created writer for : depth
2019-12-30T19:09:06.638Z,1577732946.638 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure
2019-12-30T19:09:06.643Z,1577732946.643 [CTD_Seabird](INFO): created writer for : sea_water_pressure
2019-12-30T19:09:06.644Z,1577732946.644 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity
2019-12-30T19:09:06.649Z,1577732946.649 [CTD_Seabird](INFO): created writer for : sea_water_salinity
2019-12-30T19:09:06.649Z,1577732946.649 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature
2019-12-30T19:09:06.654Z,1577732946.654 [CTD_Seabird](INFO): created writer for : sea_water_temperature
2019-12-30T19:09:06.655Z,1577732946.655 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity
2019-12-30T19:09:06.660Z,1577732946.660 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity
2019-12-30T19:09:06.661Z,1577732946.661 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water
2019-12-30T19:09:06.666Z,1577732946.666 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water
2019-12-30T19:09:06.666Z,1577732946.666 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): mass_concentration_of_oxygen_in_sea_water
2019-12-30T19:09:06.671Z,1577732946.671 [CTD_Seabird](INFO): created writer for : mass_concentration_of_oxygen_in_sea_water
2019-12-30T19:09:06.672Z,1577732946.672 [CTD_Seabird](DEBUG): LcmSlateWriter::add(DAtaURI): CTD_Seabird.sea_water_dissolved_oxygen_freq
2019-12-30T19:09:06.672Z,1577732946.672 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): dataName: sea_water_dissolved_oxygen_freq
2019-12-30T19:09:06.704Z,1577732946.704 [CTD_Seabird] Loaded
2019-12-30T19:09:06.704Z,1577732946.704 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2019-12-30T19:09:06.705Z,1577732946.705 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 409964E0
2019-12-30T19:09:06.705Z,1577732946.705 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 901
2019-12-30T19:09:06.720Z,1577732946.720 [PAR_Licor] Loaded
2019-12-30T19:09:06.720Z,1577732946.720 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2019-12-30T19:09:06.726Z,1577732946.726 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output470
2019-12-30T19:09:06.726Z,1577732946.726 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output470
2019-12-30T19:09:06.730Z,1577732946.730 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output650
2019-12-30T19:09:06.730Z,1577732946.730 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output650
2019-12-30T19:09:06.735Z,1577732946.735 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.OutputChl
2019-12-30T19:09:06.735Z,1577732946.735 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: OutputChl
2019-12-30T19:09:06.739Z,1577732946.739 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg470nm
2019-12-30T19:09:06.739Z,1577732946.739 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg470nm
2019-12-30T19:09:06.744Z,1577732946.744 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg650nm
2019-12-30T19:09:06.744Z,1577732946.744 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg650nm
2019-12-30T19:09:06.748Z,1577732946.748 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff470nm
2019-12-30T19:09:06.748Z,1577732946.748 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff470nm
2019-12-30T19:09:06.752Z,1577732946.752 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff650nm
2019-12-30T19:09:06.753Z,1577732946.753 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff650nm
2019-12-30T19:09:06.757Z,1577732946.757 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): mass_concentration_of_chlorophyll_in_sea_water
2019-12-30T19:09:06.761Z,1577732946.761 [WetLabsBB2FL](INFO): created writer for : mass_concentration_of_chlorophyll_in_sea_water
2019-12-30T19:09:06.762Z,1577732946.762 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_median_mass_concentration_of_chlorophyll_in_sea_water
2019-12-30T19:09:06.762Z,1577732946.762 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_median_mass_concentration_of_chlorophyll_in_sea_water
2019-12-30T19:09:06.766Z,1577732946.766 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water
2019-12-30T19:09:06.766Z,1577732946.766 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_mean_mass_concentration_of_chlorophyll_in_sea_water
2019-12-30T19:09:06.771Z,1577732946.771 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_variance_mass_concentration_of_chlorophyll_in_sea_water
2019-12-30T19:09:06.771Z,1577732946.771 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_variance_mass_concentration_of_chlorophyll_in_sea_water
2019-12-30T19:09:06.775Z,1577732946.775 [WetLabsBB2FL] Loaded
2019-12-30T19:09:06.775Z,1577732946.775 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2019-12-30T19:09:06.776Z,1577732946.776 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 409C64E0
2019-12-30T19:09:06.777Z,1577732946.777 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 902
2019-12-30T19:09:06.777Z,1577732946.777 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2019-12-30T19:09:06.778Z,1577732946.778 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2019-12-30T19:09:06.825Z,1577732946.825 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2019-12-30T19:09:06.826Z,1577732946.826 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2019-12-30T19:09:07.158Z,1577732947.158 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2019-12-30T19:09:07.160Z,1577732947.160 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2019-12-30T19:09:07.321Z,1577732947.321 [SBIT](DEBUG): Construct Startup Built In Test.
2019-12-30T19:09:07.332Z,1577732947.332 [SBIT] Loaded
2019-12-30T19:09:07.332Z,1577732947.332 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2019-12-30T19:09:07.333Z,1577732947.333 [IBIT](DEBUG): Construct Initiated Built In Test.
2019-12-30T19:09:07.345Z,1577732947.345 [IBIT] Loaded
2019-12-30T19:09:07.346Z,1577732947.346 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2019-12-30T19:09:07.349Z,1577732947.349 [CBIT](DEBUG): Construct Continuous Built In Test.
2019-12-30T19:09:07.486Z,1577732947.486 [CBIT] Loaded
2019-12-30T19:09:07.487Z,1577732947.487 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2019-12-30T19:09:07.487Z,1577732947.487 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2019-12-30T19:09:07.491Z,1577732947.491 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2019-12-30T19:09:07.491Z,1577732947.491 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2019-12-30T19:09:07.498Z,1577732947.498 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2019-12-30T19:09:07.499Z,1577732947.499 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40AC54E0
2019-12-30T19:09:07.499Z,1577732947.499 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 903
2019-12-30T19:09:07.504Z,1577732947.504 [Supervisor](INFO): Main Thread ID is 809
2019-12-30T19:09:07.504Z,1577732947.504 [Supervisor](DEBUG): Running supervisor.
2019-12-30T19:09:07.505Z,1577732947.505 [CommandLine ThreadHandler](INFO): Handler Thread ID is 904
2019-12-30T19:09:07.507Z,1577732947.507 [controlThread ThreadHandler](INFO): Handler Thread ID is 905
2019-12-30T19:09:07.507Z,1577732947.507 [controlThread](DEBUG): Initializing ControlThread
2019-12-30T19:09:07.508Z,1577732947.508 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2019-12-30T19:09:07.510Z,1577732947.510 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2019-12-30T19:09:07.511Z,1577732947.511 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2019-12-30T19:09:07.511Z,1577732947.511 [LoopControl](DEBUG): Initialize LoopControlComponent.
2019-12-30T19:09:07.513Z,1577732947.513 [NavChart](DEBUG): Initialize NavChart Navigation.
2019-12-30T19:09:07.513Z,1577732947.513 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2019-12-30T19:09:07.519Z,1577732947.519 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2019-12-30T19:09:07.519Z,1577732947.519 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2019-12-30T19:09:07.519Z,1577732947.519 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2019-12-30T19:09:07.520Z,1577732947.520 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2019-12-30T19:09:07.520Z,1577732947.520 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2019-12-30T19:09:07.520Z,1577732947.520 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2019-12-30T19:09:07.525Z,1577732947.525 [SBIT](INFO): Initialize SBIT Component.
2019-12-30T19:09:07.526Z,1577732947.526 [SBIT](IMPORTANT): git: 2019-11-11
2019-12-30T19:09:07.526Z,1577732947.526 [SBIT](INFO): git hash: d323e2e841967a23cb7fd5209d5be46b38c2f2ac
2019-12-30T19:09:07.526Z,1577732947.526 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2019-12-30T19:09:07.527Z,1577732947.527 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #1 PREEMPT Tue Dec 18 21:19:28 PST 2018
2019-12-30T19:09:07.528Z,1577732947.528 [SBIT](INFO): Beginning SBIT in 55.000000 seconds.
2019-12-30T19:09:07.529Z,1577732947.529 [logger ThreadHandler](INFO): Handler Thread ID is 906
2019-12-30T19:09:07.545Z,1577732947.545 [IBIT](INFO): Initialize IBIT Component.
2019-12-30T19:09:07.546Z,1577732947.546 [CBIT](DEBUG): Initialize CBIT Component.
2019-12-30T19:09:07.553Z,1577732947.553 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 907
2019-12-30T19:09:07.554Z,1577732947.554 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2019-12-30T19:09:07.558Z,1577732947.558 [CBIT](DEBUG): Initialized mux pins.
2019-12-30T19:09:07.558Z,1577732947.558 [CBIT](DEBUG): Initializing the watchdog timer.
2019-12-30T19:09:07.581Z,1577732947.581 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2019-12-30T19:09:07.581Z,1577732947.581 [CBIT](DEBUG): Initializing heartbeat.
2019-12-30T19:09:07.609Z,1577732947.609 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 908
2019-12-30T19:09:07.617Z,1577732947.617 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 909
2019-12-30T19:09:07.618Z,1577732947.618 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2019-12-30T19:09:07.621Z,1577732947.621 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20
2019-12-30T19:09:07.623Z,1577732947.623 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 911
2019-12-30T19:09:07.624Z,1577732947.624 [WetLabsBB2FL](INFO): Powering down
2019-12-30T19:09:07.653Z,1577732947.653 [CBIT](DEBUG): Deactivating GF circuits.
2019-12-30T19:09:07.653Z,1577732947.653 [CBIT](DEBUG): Deactivating emergency mode.
2019-12-30T19:09:07.665Z,1577732947.665 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 912
2019-12-30T19:09:07.689Z,1577732947.689 [CBIT](DEBUG): Backplane powered.
2019-12-30T19:09:07.755Z,1577732947.755 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2019-12-30T19:09:07.867Z,1577732947.867 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2019-12-30T19:09:07.867Z,1577732947.867 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2019-12-30T19:09:07.868Z,1577732947.868 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2019-12-30T19:09:07.868Z,1577732947.868 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2019-12-30T19:09:07.868Z,1577732947.868 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2019-12-30T19:09:07.868Z,1577732947.868 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2019-12-30T19:09:07.868Z,1577732947.868 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2019-12-30T19:09:07.868Z,1577732947.868 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2019-12-30T19:09:07.869Z,1577732947.869 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2019-12-30T19:09:07.869Z,1577732947.869 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2019-12-30T19:09:07.869Z,1577732947.869 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2019-12-30T19:09:07.869Z,1577732947.869 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2019-12-30T19:09:07.870Z,1577732947.870 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2019-12-30T19:09:07.870Z,1577732947.870 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2019-12-30T19:09:07.870Z,1577732947.870 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2019-12-30T19:09:07.870Z,1577732947.870 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2019-12-30T19:09:07.887Z,1577732947.887 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2019-12-30T19:09:07.976Z,1577732947.976 [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-12-30T19:09:07.976Z,1577732947.976 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2019-12-30T19:09:08.013Z,1577732948.013 [Radio_Surface](INFO): Powering up
2019-12-30T19:09:08.097Z,1577732948.097 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2019-12-30T19:09:08.099Z,1577732948.099 [Default:A.Wait](DEBUG): Construct Wait.
2019-12-30T19:09:08.100Z,1577732948.100 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2019-12-30T19:09:08.112Z,1577732948.112 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2019-12-30T19:09:08.134Z,1577732948.134 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2019-12-30T19:09:08.157Z,1577732948.157 [Default:E.Execute](DEBUG): Construct Execute.
2019-12-30T19:09:08.185Z,1577732948.185 [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-12-30T19:09:08.189Z,1577732948.189 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,NAL9602,Onboard,BPC1,CANONSampler,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,
2019-12-30T19:09:08.201Z,1577732948.201 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2019-12-30T19:09:08.314Z,1577732948.314 [Depth_Keller](ERROR): Pressure reading out of range: 1831.023193 decibar
2019-12-30T19:09:08.361Z,1577732948.361 [CANONSampler](INFO): Powering down
2019-12-30T19:09:08.433Z,1577732948.433 [DepthRateCalculator](ERROR): Depth measurement is not active
2019-12-30T19:09:08.485Z,1577732948.485 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2019-12-30T19:09:08.493Z,1577732948.493 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2019-12-30T19:09:08.494Z,1577732948.494 [ElevatorServo](DEBUG): Initializing EZServoServo.
2019-12-30T19:09:08.501Z,1577732948.501 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2019-12-30T19:09:08.502Z,1577732948.502 [MassServo](DEBUG): Initializing EZServoServo.
2019-12-30T19:09:08.509Z,1577732948.509 [MassServo](DEBUG): Initializing MassServo.
2019-12-30T19:09:08.510Z,1577732948.510 [RudderServo](DEBUG): Initializing EZServoServo.
2019-12-30T19:09:08.517Z,1577732948.517 [RudderServo](DEBUG): Initializing RudderServo.
2019-12-30T19:09:08.518Z,1577732948.518 [ThrusterServo](DEBUG): Initializing EZServoServo.
2019-12-30T19:09:08.525Z,1577732948.525 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2019-12-30T19:09:09.385Z,1577732949.385 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2019-12-30T19:09:09.385Z,1577732949.385 [RudderServo](FAULT): Rudder failed to initialize
2019-12-30T19:09:09.385Z,1577732949.385 [RudderServo] Communications Fault, FailCount= 1
2019-12-30T19:09:09.385Z,1577732949.385 [RudderServo](ERROR): Communications Fault
2019-12-30T19:09:09.580Z,1577732949.580 [CBIT](ERROR): Communications Fault in component: RudderServo
2019-12-30T19:09:09.782Z,1577732949.782 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-12-30T19:09:09.782Z,1577732949.782 [RudderServo](INFO): Powering down
2019-12-30T19:09:10.464Z,1577732950.464 [RudderServo](DEBUG): Initializing EZServoServo.
2019-12-30T19:09:10.582Z,1577732950.582 [RudderServo](DEBUG): Initializing RudderServo.
2019-12-30T19:09:10.586Z,1577732950.586 [CBIT](INFO): Clearing failed state for component RudderServo
2019-12-30T19:09:10.586Z,1577732950.586 [RudderServo] No Fault, FailCount= 1
2019-12-30T19:09:17.221Z,1577732957.221 [BuoyancyServo](ERROR): getPosition uart error serial timeout
2019-12-30T19:09:17.221Z,1577732957.221 [BuoyancyServo](FAULT): Buoyancy getPosition uart error.serial timeout
2019-12-30T19:09:17.221Z,1577732957.221 [BuoyancyServo] Communications Fault, FailCount= 1
2019-12-30T19:09:17.221Z,1577732957.221 [BuoyancyServo](ERROR): Communications Fault
2019-12-30T19:09:17.313Z,1577732957.313 [CBIT](ERROR): Communications Fault in component: BuoyancyServo
2019-12-30T19:09:19.018Z,1577732959.018 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2019-12-30T19:09:19.018Z,1577732959.018 [BuoyancyServo](INFO): Powering down
2019-12-30T19:09:19.390Z,1577732959.390 [BuoyancyServo](FAULT): LCB fault:  Current Limiter Activated.
2019-12-30T19:09:19.390Z,1577732959.390 [BuoyancyServo] Hardware Fault, FailCount= 1
2019-12-30T19:09:19.390Z,1577732959.390 [BuoyancyServo](ERROR): Hardware Fault
2019-12-30T19:09:19.897Z,1577732959.897 [CBIT](INFO): Clearing failed state for component BuoyancyServo
2019-12-30T19:09:19.897Z,1577732959.897 [BuoyancyServo] No Fault, FailCount= 1
2019-12-30T19:09:20.237Z,1577732960.237 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2019-12-30T19:09:20.245Z,1577732960.245 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2019-12-30T19:09:34.290Z,1577732974.290 [NAL9602](INFO): Powering up NAL9602
2019-12-30T19:09:45.202Z,1577732985.202 [NAL9602](INFO): NAL9602 initialized
2019-12-30T19:10:03.043Z,1577733003.043 [SBIT](IMPORTANT): Beginning Startup BIT
2019-12-30T19:10:03.047Z,1577733003.047 [CBIT](IMPORTANT): Beginning ground fault scan
2019-12-30T19:10:14.158Z,1577733014.158 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): -0.014295
CHAN A1 (24V): -0.180323
CHAN A2 (12V): -0.002086
CHAN A3 (5V): -0.001251
CHAN B0 (3.3V): 0.000022
CHAN B1 (3.15aV): -0.000308
CHAN B2 (3.15bV): -0.000305
CHAN B3 (GND): -0.000004
OPEN: -0.000404
Full Scale Calc: 4.765 mA, -1.589 mA
2019-12-30T19:10:55.860Z,1577733055.860 [NAL9602](INFO): SBD MO Status=0, MOMSN=18396, MT Status=0, MTMSN=0
2019-12-30T19:10:55.860Z,1577733055.860 [NAL9602](INFO): No messages in MT queue
2019-12-30T19:10:56.731Z,1577733056.731 [SBIT](IMPORTANT): SBIT PASSED
2019-12-30T19:10:56.821Z,1577733056.821 [CommandLine](IMPORTANT): got command configSet list
2019-12-30T19:10:56.822Z,1577733056.822 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2019-12-30T19:10:56.822Z,1577733056.822 [CommandLine](IMPORTANT): CBIT.gf24Offset=154 microampere;

2019-12-30T19:10:56.823Z,1577733056.823 [CommandLine](IMPORTANT): CTD_NeilBrown.loadAtStartup=0 bool;

2019-12-30T19:10:56.823Z,1577733056.823 [CommandLine](IMPORTANT): CTD_Seabird.verbosity=0 count;

2019-12-30T19:10:56.823Z,1577733056.823 [CommandLine](IMPORTANT): DAT.loadAtStartup=0 bool;

2019-12-30T19:10:56.823Z,1577733056.823 [CommandLine](IMPORTANT): DVL_micro.loadAtStartup=0 bool;

2019-12-30T19:10:56.823Z,1577733056.823 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=438 cubic_centimeter;

2019-12-30T19:10:56.823Z,1577733056.823 [CommandLine](IMPORTANT): VerticalControl.massDefault=-9 millimeter;

2019-12-30T19:10:56.823Z,1577733056.823 [CommandLine](IMPORTANT): WetLabsUBAT.loadAtStartup=0 bool;

2019-12-30T19:10:57.115Z,1577733057.115 [MissionManager](IMPORTANT): Started mission Startup
2019-12-30T19:10:57.115Z,1577733057.115 [Startup] Running Loop=1
2019-12-30T19:10:57.115Z,1577733057.115 [Startup](DEBUG): Aggregate::initialize Startup
2019-12-30T19:10:57.115Z,1577733057.115 [Startup:A.GoToSurface] Running Loop=1
2019-12-30T19:10:57.116Z,1577733057.116 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-12-30T19:10:57.116Z,1577733057.116 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-12-30T19:10:57.117Z,1577733057.117 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-12-30T19:10:57.117Z,1577733057.117 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-12-30T19:10:57.118Z,1577733057.118 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-12-30T19:10:57.118Z,1577733057.118 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-12-30T19:10:57.119Z,1577733057.119 [Startup:StartupSatComms] Running Loop=1
2019-12-30T19:10:57.119Z,1577733057.119 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2019-12-30T19:10:57.120Z,1577733057.120 [Startup:StartupSatComms:A] Running Loop=1
2019-12-30T19:10:57.519Z,1577733057.519 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2019-12-30T19:11:57.305Z,1577733117.305 [Startup:StartupSatComms:A](INFO): Timed out from 2019-12-30T19:10:57.1Z
2019-12-30T19:11:57.305Z,1577733117.305 [Startup:StartupSatComms:A] Stopped
2019-12-30T19:11:57.305Z,1577733117.305 [Startup:StartupSatComms:B] Running Loop=1
2019-12-30T19:11:57.723Z,1577733117.723 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-12-30T19:12:08.603Z,1577733128.603 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2019-12-30T19:12:08.603Z,1577733128.603 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-12-30T19:12:08.613Z,1577733128.613 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-12-30T19:12:08.727Z,1577733128.727 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-12-30T19:12:08.727Z,1577733128.727 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2019-12-30T19:12:17.112Z,1577733137.112 [NAL9602](INFO): SBD MO Status=2, MOMSN=18397, MT Status=2, MTMSN=0
2019-12-30T19:12:17.112Z,1577733137.112 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-12-30T19:12:39.380Z,1577733159.380 [NAL9602](INFO): SBD MO Status=2, MOMSN=18397, MT Status=2, MTMSN=0
2019-12-30T19:12:39.380Z,1577733159.380 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-12-30T19:12:42.943Z,1577733162.943 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004856
2019-12-30T19:12:52.824Z,1577733172.824 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20191216T202312/Courier0063.lzma
2019-12-30T19:12:54.830Z,1577733174.830 [DataOverHttps](INFO): Moved sent file to Logs/20191216T202312/Courier0063.lzma.bak
2019-12-30T19:12:54.831Z,1577733174.831 [DataOverHttps](INFO): SBD MOMSN=12183123
2019-12-30T19:12:57.668Z,1577733177.668 [Startup:StartupSatComms:B](INFO): Timed out from 2019-12-30T19:11:57.3Z
2019-12-30T19:12:57.669Z,1577733177.669 [Startup:StartupSatComms:B] Stopped
2019-12-30T19:12:57.669Z,1577733177.669 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2019-12-30T19:12:57.669Z,1577733177.669 [Startup:StartupSatComms] Stopped
2019-12-30T19:12:57.669Z,1577733177.669 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2019-12-30T19:12:57.670Z,1577733177.670 [Startup](INFO): Completed Startup
2019-12-30T19:12:57.670Z,1577733177.670 [MissionManager](INFO): Startup is completed.
2019-12-30T19:12:57.670Z,1577733177.670 [MissionManager](INFO): Uninitializing Mission Startup
2019-12-30T19:12:57.670Z,1577733177.670 [Startup] Stopped
2019-12-30T19:12:57.670Z,1577733177.670 [Startup](DEBUG): Aggregate::uninitialize Startup
2019-12-30T19:12:57.670Z,1577733177.670 [Startup:A.GoToSurface] Stopped
2019-12-30T19:12:57.671Z,1577733177.671 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-12-30T19:12:58.082Z,1577733178.082 [MissionManager](IMPORTANT): Started mission Default
2019-12-30T19:12:58.082Z,1577733178.082 [Default] Running Loop=1
2019-12-30T19:12:58.082Z,1577733178.082 [Default](DEBUG): Aggregate::initialize Default
2019-12-30T19:12:58.082Z,1577733178.082 [Default:B.GoToSurface] Running Loop=1
2019-12-30T19:12:58.082Z,1577733178.082 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-12-30T19:12:58.083Z,1577733178.083 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-12-30T19:12:58.083Z,1577733178.083 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-12-30T19:12:58.083Z,1577733178.083 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-12-30T19:12:58.084Z,1577733178.084 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-12-30T19:12:58.084Z,1577733178.084 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-12-30T19:12:58.084Z,1577733178.084 [Default:A.Wait] Running Loop=1
2019-12-30T19:12:58.084Z,1577733178.084 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-12-30T19:13:10.161Z,1577733190.161 [BPC1](ERROR): BPC1A: No match for serial number 1717 in BPC1A's battery stick inventory (sticks 1-32 in onboard configuration file).
2019-12-30T19:13:11.394Z,1577733191.394 [Default:A.Wait](INFO): Done Waiting.
2019-12-30T19:13:11.394Z,1577733191.394 [Default:A.Wait] Stopped
2019-12-30T19:13:11.394Z,1577733191.394 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-12-30T19:13:11.678Z,1577733191.678 [DataOverHttps](INFO): Sending 227 bytes from file Logs/20191216T202312/Express0064.lzma
2019-12-30T19:13:11.815Z,1577733191.815 [Default:CheckIn] Running Loop=1
2019-12-30T19:13:11.815Z,1577733191.815 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-12-30T19:13:11.816Z,1577733191.816 [Default:CheckIn:Read_GPS] Running Loop=1
2019-12-30T19:13:12.221Z,1577733192.221 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2019-12-30T19:13:13.682Z,1577733193.682 [DataOverHttps](INFO): Moved sent file to Logs/20191216T202312/Express0064.lzma.bak
2019-12-30T19:13:13.683Z,1577733193.683 [DataOverHttps](INFO): SBD MOMSN=12183125
2019-12-30T19:15:09.389Z,1577733309.389 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2019-12-30T19:15:09.389Z,1577733309.389 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-12-30T19:15:09.406Z,1577733309.406 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-12-30T19:15:09.775Z,1577733309.775 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-12-30T19:15:09.775Z,1577733309.775 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2019-12-30T19:16:44.394Z,1577733404.394 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2019-12-30T19:16:44.398Z,1577733404.398 [BPC1](INFO): Received data from all battery sticks.
2019-12-30T19:17:16.958Z,1577733436.958 [DataOverHttps](IMPORTANT): SBD MTMSN=20191230T191441
2019-12-30T19:17:20.220Z,1577733440.220 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191445.00,A,3648.16696,N,12147.28844,W,0.039,131.82,301219,,,A*7F
2019-12-30T19:17:20.223Z,1577733440.223 [NAL9602](INFO): GPS fix at 20191230T191445: (36.802783, -121.788141)
2019-12-30T19:17:20.290Z,1577733440.290 [Default:CheckIn:Read_GPS] Stopped
2019-12-30T19:17:20.290Z,1577733440.290 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-12-30T19:17:20.688Z,1577733440.688 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-12-30T19:17:24.991Z,1577733444.991 [DataOverHttps](INFO): Sending 300 bytes from file Logs/20191230T190856/Courier0004.lzma
2019-12-30T19:17:25.010Z,1577733445.010 [DataOverHttps](INFO): Received command:load Maintenance/tank_ballast_and_trim.xml;set ballast_and_trim.MissionTimeout 45 minute;set ballast_and_trim.EstimationTimeout 20 minute;run 
2019-12-30T19:17:25.073Z,1577733445.073 [CommandLine](IMPORTANT): got command load ./Missions/Maintenance/tank_ballast_and_trim.xml
2019-12-30T19:17:25.074Z,1577733445.074 [MissionManager](INFO): Loading Mission: ./Missions/Maintenance/tank_ballast_and_trim.xml
2019-12-30T19:17:25.242Z,1577733445.242 [MissionManager](INFO): DefineArg ballast_and_trim.MissionTimeout = 120.000000 min
2019-12-30T19:17:25.253Z,1577733445.253 [MissionManager](INFO): DefineArg ballast_and_trim.SkipComms = 0 bool
2019-12-30T19:17:25.256Z,1577733445.256 [MissionManager](INFO): DefineArg ballast_and_trim.Depth1 = 7.000000 m
2019-12-30T19:17:25.298Z,1577733445.298 [MissionManager](INFO): DefineArg ballast_and_trim.Depth2 = nan m
2019-12-30T19:17:25.309Z,1577733445.309 [MissionManager](INFO): DefineArg ballast_and_trim.DepthDeadband = 0.100000 m
2019-12-30T19:17:25.312Z,1577733445.312 [MissionManager](INFO): DefineArg ballast_and_trim.SurfaceThreshold = 2.500000 m
2019-12-30T19:17:25.324Z,1577733445.324 [MissionManager](INFO): DefineArg ballast_and_trim.MaxWaitOnSurface = 20.000000 min
2019-12-30T19:17:25.335Z,1577733445.335 [MissionManager](INFO): DefineArg ballast_and_trim.SettleTime = 10.000000 min
2019-12-30T19:17:25.346Z,1577733445.346 [MissionManager](INFO): DefineArg ballast_and_trim.EstimationTimeout = 45.000000 min
2019-12-30T19:17:25.355Z,1577733445.355 [MissionManager](INFO): DefineArg ballast_and_trim.MinEstimationTime = 10.000000 min
2019-12-30T19:17:25.370Z,1577733445.370 [MissionManager](INFO): DefineArg ballast_and_trim.MassEstimationErrorBound = 0.250000 mm
2019-12-30T19:17:25.410Z,1577733445.410 [MissionManager](INFO): DefineArg ballast_and_trim.BuoyEstimationErrorBound = 15.000000 cc
2019-12-30T19:17:25.413Z,1577733445.413 [MissionManager](INFO): DefineArg ballast_and_trim.EstimationConfidence = 99.900000 %
2019-12-30T19:17:25.416Z,1577733445.416 [MissionManager](INFO): DefineArg ballast_and_trim.WaitToFloat = 5.000000 min
2019-12-30T19:17:25.416Z,1577733445.416 [MissionManager](INFO): Inserting Stack: Missions/Insert/Science.xml
2019-12-30T19:17:26.074Z,1577733446.074 [MissionManager](INFO): DefineArg ballast_and_trim:Science.SampleISUS = 0 bool
2019-12-30T19:17:26.089Z,1577733446.089 [MissionManager](INFO): DefineArg ballast_and_trim:Science.SampleISUSmaxPitch = 60.000000 arcdeg
2019-12-30T19:17:26.101Z,1577733446.101 [MissionManager](INFO): DefineArg ballast_and_trim:Science.SampleISUSminPitch = -60.000000 arcdeg
2019-12-30T19:17:26.110Z,1577733446.110 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectChlActive = 0 bool
2019-12-30T19:17:26.118Z,1577733446.118 [MissionManager](INFO): DefineArg ballast_and_trim:Science.TimeWindowPeakReport = nan min
2019-12-30T19:17:26.129Z,1577733446.129 [MissionManager](INFO): DefineArg ballast_and_trim:Science.HighestChlPeakReportActive = 0 bool
2019-12-30T19:17:26.141Z,1577733446.141 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PatchTracking = 0 bool
2019-12-30T19:17:26.144Z,1577733446.144 [MissionManager](INFO): DefineArg ballast_and_trim:Science.FilterWidthHorizontal = 3.000000 count
2019-12-30T19:17:26.156Z,1577733446.156 [MissionManager](INFO): DefineArg ballast_and_trim:Science.NumProfilesSlidingwindow = 100.000000 count
2019-12-30T19:17:26.163Z,1577733446.163 [MissionManager](INFO): DefineArg ballast_and_trim:Science.OffPeakFractionHorizontal = 80.000000 %
2019-12-30T19:17:26.178Z,1577733446.178 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectNO3Active = 0 bool
2019-12-30T19:17:26.189Z,1577733446.189 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectOilActive = 0 bool
2019-12-30T19:17:26.194Z,1577733446.194 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectFDOMActive = 0 bool
2019-12-30T19:17:26.196Z,1577733446.196 [MissionManager](INFO): DefineArg ballast_and_trim:Science.UpwardDerivativeOfTemperatureActive = 0 bool
2019-12-30T19:17:26.204Z,1577733446.204 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledAanderaaO2 = 0.000000 bool
2019-12-30T19:17:26.220Z,1577733446.220 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledNeilBrown = 0.000000 bool
2019-12-30T19:17:26.224Z,1577733446.224 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledSeabird = 1.000000 bool
2019-12-30T19:17:26.247Z,1577733446.247 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledTurbulence_NPS = 0.000000 bool
2019-12-30T19:17:26.251Z,1577733446.251 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledWetLabsBB2FL = 1.000000 bool
2019-12-30T19:17:26.279Z,1577733446.279 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledWetLabsSeaOWL_UV_A = 0.000000 bool
2019-12-30T19:17:26.282Z,1577733446.282 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledWetLabsUBAT = 0.000000 bool
2019-12-30T19:17:26.310Z,1577733446.310 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledISUS = 0.000000 bool
2019-12-30T19:17:26.313Z,1577733446.313 [MissionManager](INFO): DefineArg ballast_and_trim:Science.LowPassWindowLength = 20.000000 count
2019-12-30T19:17:26.316Z,1577733446.316 [MissionManager](INFO): DefineArg ballast_and_trim:Science.MedianFilterLen = 5.000000 count
2019-12-30T19:17:26.347Z,1577733446.347 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakChlShallowBound = nan m
2019-12-30T19:17:26.351Z,1577733446.351 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakChlDeepBound = nan m
2019-12-30T19:17:26.370Z,1577733446.370 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakShallowBound = nan m
2019-12-30T19:17:26.373Z,1577733446.373 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDeepBound = nan m
2019-12-30T19:17:26.376Z,1577733446.376 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChl = 0.000000 ug/l
2019-12-30T19:17:26.461Z,1577733446.461 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChlDepth = 0.000000 m
2019-12-30T19:17:26.464Z,1577733446.464 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChlTemperature = 0.000000 degC
2019-12-30T19:17:26.491Z,1577733446.491 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChlLatitude = nan arcdeg
2019-12-30T19:17:26.502Z,1577733446.502 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChlLongitude = nan arcdeg
2019-12-30T19:17:26.510Z,1577733446.510 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakNO3 = 0.000000 umol/l
2019-12-30T19:17:26.533Z,1577733446.533 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakNO3Depth = 0.000000 m
2019-12-30T19:17:26.536Z,1577733446.536 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakNO3Latitude = nan arcdeg
2019-12-30T19:17:26.548Z,1577733446.548 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakNO3Longitude = nan arcdeg
2019-12-30T19:17:26.567Z,1577733446.567 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChl = 0.000000 m
2019-12-30T19:17:26.575Z,1577733446.575 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChlDepth = 0.000000 m
2019-12-30T19:17:26.586Z,1577733446.586 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChlLatitude = nan arcdeg
2019-12-30T19:17:26.594Z,1577733446.594 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChlLongitude = nan arcdeg
2019-12-30T19:17:26.626Z,1577733446.626 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChlDistance = nan m
2019-12-30T19:17:26.629Z,1577733446.629 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakOil = 0.000000 kg/m3
2019-12-30T19:17:26.649Z,1577733446.649 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakOilDepth = 0.000000 m
2019-12-30T19:17:26.652Z,1577733446.652 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakOilLatitude = nan arcdeg
2019-12-30T19:17:26.655Z,1577733446.655 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakOilLongitude = nan arcdeg
2019-12-30T19:17:26.683Z,1577733446.683 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOM = 0.000000 ppb
2019-12-30T19:17:26.686Z,1577733446.686 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOMDepth = 0.000000 m
2019-12-30T19:17:26.717Z,1577733446.717 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOMLatitude = nan arcdeg
2019-12-30T19:17:26.721Z,1577733446.721 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOMLongitude = nan arcdeg
2019-12-30T19:17:26.745Z,1577733446.745 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchFDOMDistance = nan m
2019-12-30T19:17:26.863Z,1577733446.863 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2019-12-30T19:17:26.927Z,1577733446.927 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal](DEBUG): Construct PeakDetectHorizontal.
2019-12-30T19:17:26.989Z,1577733446.989 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2019-12-30T19:17:27.020Z,1577733447.020 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2019-12-30T19:17:27.073Z,1577733447.073 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2019-12-30T19:17:27.100Z,1577733447.100 [MissionManager](INFO): Inserting Stack: Missions/Insert/BallastAndTrim.xml
2019-12-30T19:17:27.476Z,1577733447.476 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertDepth = 25.000000 m
2019-12-30T19:17:27.496Z,1577733447.496 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachSpeed = 0.000000 m/s
2019-12-30T19:17:27.499Z,1577733447.499 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachDepthRate = 0.400000 m/s
2019-12-30T19:17:27.518Z,1577733447.518 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachPitchLimit = 20.000000 arcdeg
2019-12-30T19:17:27.522Z,1577733447.522 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachSettleTimePreDive = 0.000000 min
2019-12-30T19:17:27.545Z,1577733447.545 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachDepthTimeout = 20.000000 min
2019-12-30T19:17:27.549Z,1577733447.549 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertSettleTime = 10.000000 min
2019-12-30T19:17:27.552Z,1577733447.552 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.EstTimeout = 45.000000 min
2019-12-30T19:17:27.571Z,1577733447.571 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.MinEstTime = 10.000000 min
2019-12-30T19:17:27.575Z,1577733447.575 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.MassEstErrorBound = 0.250000 mm
2019-12-30T19:17:27.602Z,1577733447.602 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.BuoyEstErrorBound = 15.000000 cc
2019-12-30T19:17:27.606Z,1577733447.606 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.EstConfidence = 99.900000 %
2019-12-30T19:17:27.638Z,1577733447.638 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertDepthDeadband = 1.000000 m
2019-12-30T19:17:27.676Z,1577733447.676 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertKiDepthBuoy = 0.300000 1/s
2019-12-30T19:17:27.692Z,1577733447.692 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertMassDeadband = 0.250000 mm
2019-12-30T19:17:27.781Z,1577733447.781 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:A.Point](DEBUG): Construct.
2019-12-30T19:17:27.801Z,1577733447.801 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy](DEBUG): Construct Buoyancy.
2019-12-30T19:17:27.837Z,1577733447.837 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:C.Pitch](DEBUG): Construct.
2019-12-30T19:17:27.854Z,1577733447.854 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait](DEBUG): Construct Wait.
2019-12-30T19:17:27.891Z,1577733447.891 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed](DEBUG): Construct.
2019-12-30T19:17:27.895Z,1577733447.895 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch](DEBUG): Construct.
2019-12-30T19:17:27.918Z,1577733447.918 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch:A_Timeout:B.Execute](DEBUG): Construct Execute.
2019-12-30T19:17:27.942Z,1577733447.942 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed](DEBUG): Construct.
2019-12-30T19:17:27.945Z,1577733447.945 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch](DEBUG): Construct.
2019-12-30T19:17:27.985Z,1577733447.985 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait](DEBUG): Construct Wait.
2019-12-30T19:17:27.988Z,1577733447.988 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](DEBUG): Construct BallastAndTrim.
2019-12-30T19:17:28.125Z,1577733448.125 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertDepthDeadband = reader:ballast_and_trim.DepthDeadband
2019-12-30T19:17:28.127Z,1577733448.127 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachDepthTimeout = reader:ballast_and_trim.MaxWaitOnSurface
2019-12-30T19:17:28.177Z,1577733448.177 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertSettleTime = reader:ballast_and_trim.SettleTime
2019-12-30T19:17:28.179Z,1577733448.179 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.EstTimeout = reader:ballast_and_trim.EstimationTimeout
2019-12-30T19:17:28.181Z,1577733448.181 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.MinEstTime = reader:ballast_and_trim.MinEstimationTime
2019-12-30T19:17:28.183Z,1577733448.183 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.MassEstErrorBound = reader:ballast_and_trim.MassEstimationErrorBound
2019-12-30T19:17:28.202Z,1577733448.202 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.BuoyEstErrorBound = reader:ballast_and_trim.BuoyEstimationErrorBound
2019-12-30T19:17:28.204Z,1577733448.204 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.EstConfidence = reader:ballast_and_trim.EstimationConfidence
2019-12-30T19:17:28.248Z,1577733448.248 [ballast_and_trim:Float_Up:A.Buoyancy](DEBUG): Construct Buoyancy.
2019-12-30T19:17:28.268Z,1577733448.268 [ballast_and_trim:Float_Up:B.Wait](DEBUG): Construct Wait.
2019-12-30T19:17:28.328Z,1577733448.328 [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="ballast_and_trim">

    <DefineArg Name="MissionTimeout"><Description>
        Maximum duration of mission
    </Description><Units:minute/><Value>120</Value></DefineArg>

    <DefineArg Name="SkipComms"><Description>
        Skip communications at start of mission.
    </Description><False/></DefineArg>

    <DefineArg Name="Depth1"><Units:meter/><Value>7</Value></DefineArg>

    <DefineArg Name="Depth2"><Units:meter/><Value>NaN</Value></DefineArg>

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

    <DefineArg Name="SurfaceThreshold"><Description>
        Surface threshold depth.
    </Description><Units:meter/><Value>2.5</Value></DefineArg>

    <DefineArg Name="MaxWaitOnSurface"><Description>
        Maximum wait time for the vehicle to go under the surface (i.e., reach
        the surface threshold depth).
    </Description><Units:minute/><Value>20</Value></DefineArg>

    <DefineArg Name="SettleTime"><Description>
        How long to wait after reaching target depth before starting ballast and
        trim.
    </Description><Units:minute/><Value>10</Value></DefineArg>

    <DefineArg Name="EstimationTimeout"><Description>
        Timeout for ballast and trim estimation.
    </Description><Units:minute/><Value>45</Value></DefineArg>

    <DefineArg Name="MinEstimationTime"><Description>
        Minimum time to run ballast and trim estimation before determining
        convergence (must be shorter than timeout).
    </Description><Units:minute/><Value>10</Value></DefineArg>

    <DefineArg Name="MassEstimationErrorBound"><Description>
        Desired range of the estimated sample mean from the true mean statistic
        (smaller values take longer to converge).
    </Description><Units:millimeter/><Value>0.25</Value></DefineArg>

    <DefineArg Name="BuoyEstimationErrorBound"><Description>
        Desired range of the estimated sample mean from the true mean statistic
        (smaller values take longer to converge).
    </Description><Units:cubic_centimeter/><Value>15</Value></DefineArg>

    <DefineArg Name="EstimationConfidence"><Description>
        Confidence level that the estimator has reached the desired error range
        (larger values take longer to converge).
    </Description><Units:percent/><Value>99.9</Value></DefineArg>

    <DefineArg Name="WaitToFloat"><Units:minute/><Value>5</Value></DefineArg>

    <Timeout Duration="MissionTimeout"/>

    <Insert Filename="Insert/Science.xml"/>

    <Aggregate Id="RunBallastAndTrim">

        <Sequence/>

        <Insert Filename="Insert/BallastAndTrim.xml">
            <RedefineArg Name="InsertDepthDeadband"><Arg Name="DepthDeadband"/></RedefineArg>
            <RedefineArg Name="InsertApproachDepthTimeout"><Arg Name="MaxWaitOnSurface"/></RedefineArg>
            <RedefineArg Name="InsertSettleTime"><Arg Name="SettleTime"/></RedefineArg>
            <RedefineArg Name="EstTimeout"><Arg Name="EstimationTimeout"/></RedefineArg>
            <RedefineArg Name="MinEstTime"><Arg Name="MinEstimationTime"/></RedefineArg>
            <RedefineArg Name="MassEstErrorBound"><Arg Name="MassEstimationErrorBound"/></RedefineArg>
            <RedefineArg Name="BuoyEstErrorBound"><Arg Name="BuoyEstimationErrorBound"/></RedefineArg>
            <RedefineArg Name="EstConfidence"><Arg Name="EstimationConfidence"/></RedefineArg>
        </Insert>
        
        <Aggregate Id="Depth1">

            <Sequence/>

            <Break>
                <IsNaN>
                    <Arg Name="Depth1"/>
                </IsNaN>
            </Break>

            <Assign><Sequence/><Arg Name="BallastAndTrim:InsertDepth"/><Arg Name="Depth1"/></Assign>
            
            <Call RefId="BallastAndTrim"/>

        </Aggregate>

        <Aggregate Id="Depth2">

            <Sequence/>

            <Break>
                <IsNaN>
                    <Arg Name="Depth2"/>
                </IsNaN>
            </Break>

            <Assign><Sequence/><Arg Name="BallastAndTrim:InsertDepth"/><Arg Name="Depth1"/></Assign>

            <Call RefId="BallastAndTrim"/>

        </Aggregate>

    </Aggregate>

    <Aggregate Id="Float_Up">

        <Description>
            Float to surface instead of driving.
        </Description>

        <Sequence/>

        <Break>
            <Universal:depth/>
            <Lt><Control:VerticalControl.surfaceThreshold/></Lt>
        </Break>

        <Guidance:Buoyancy>
            <Parallel/>
            <Setting><Guidance:Buoyancy.position/><Control:VerticalControl.buoyancyDefault/></Setting>
        </Guidance:Buoyancy>

        <Guidance:Wait>
            <Sequence/>
            <Setting><Guidance:Wait.duration/><Arg Name="WaitToFloat"/></Setting>
        </Guidance:Wait>

    </Aggregate>

</Mission>


2019-12-30T19:17:28.328Z,1577733448.328 [CommandLine](IMPORTANT): Loaded ./Missions/Maintenance/tank_ballast_and_trim.xml
2019-12-30T19:17:35.688Z,1577733455.688 [CommandLine](IMPORTANT): got command set ballast_and_trim.MissionTimeout 45.000000 minute
2019-12-30T19:17:35.710Z,1577733455.710 [CommandLine](IMPORTANT): got command set ballast_and_trim.EstimationTimeout 20.000000 minute
2019-12-30T19:17:35.714Z,1577733455.714 [CommandLine](IMPORTANT): got command run 
2019-12-30T19:17:35.732Z,1577733455.732 [CommandLine](IMPORTANT): Running 
2019-12-30T19:17:35.757Z,1577733455.757 [Default] Stopped
2019-12-30T19:17:35.757Z,1577733455.757 [Default](DEBUG): Aggregate::uninitialize Default
2019-12-30T19:17:35.757Z,1577733455.757 [Default:B.GoToSurface] Stopped
2019-12-30T19:17:35.757Z,1577733455.757 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-12-30T19:17:35.757Z,1577733455.757 [Default:CheckIn] Stopped
2019-12-30T19:17:35.757Z,1577733455.757 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-12-30T19:17:35.758Z,1577733455.758 [Default:CheckIn:Read_Iridium] Stopped
2019-12-30T19:17:35.758Z,1577733455.758 [MissionManager](IMPORTANT): Started mission ballast_and_trim
2019-12-30T19:17:35.758Z,1577733455.758 [ballast_and_trim] Running Loop=1
2019-12-30T19:17:35.758Z,1577733455.758 [ballast_and_trim](DEBUG): Aggregate::initialize ballast_and_trim
2019-12-30T19:17:35.758Z,1577733455.758 [ballast_and_trim:Science] Running Loop=1
2019-12-30T19:17:35.758Z,1577733455.758 [ballast_and_trim:Science](DEBUG): Aggregate::initialize ballast_and_trim:Science
2019-12-30T19:17:35.758Z,1577733455.758 [ballast_and_trim:Science:A] Running Loop=1
2019-12-30T19:17:35.758Z,1577733455.758 [ballast_and_trim:Science:B] Running Loop=1
2019-12-30T19:17:35.758Z,1577733455.758 [ballast_and_trim:Science:C] Running Loop=1
2019-12-30T19:17:35.759Z,1577733455.759 [ballast_and_trim:Science:D] Running Loop=1
2019-12-30T19:17:35.759Z,1577733455.759 [ballast_and_trim:Science:E] Running Loop=1
2019-12-30T19:17:35.759Z,1577733455.759 [ballast_and_trim:Science:F] Running Loop=1
2019-12-30T19:17:35.759Z,1577733455.759 [ballast_and_trim:Science:G] Running Loop=1
2019-12-30T19:17:35.759Z,1577733455.759 [ballast_and_trim:Science:H] Running Loop=1
2019-12-30T19:17:35.759Z,1577733455.759 [ballast_and_trim:Science:Read_Oil] Running Loop=1
2019-12-30T19:17:35.759Z,1577733455.759 [ballast_and_trim:Science:PeakDetectChl] Running Loop=1
2019-12-30T19:17:35.759Z,1577733455.759 [ballast_and_trim:Science:PeakDetectChl](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectChl
2019-12-30T19:17:35.759Z,1577733455.759 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth] Running Loop=1
2019-12-30T19:17:35.759Z,1577733455.759 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Initialize.
2019-12-30T19:17:35.769Z,1577733455.769 [ballast_and_trim:Science:HighestChlPeakReport] Running Loop=1
2019-12-30T19:17:35.770Z,1577733455.770 [ballast_and_trim:Science:HighestChlPeakReport](DEBUG): Aggregate::initialize ballast_and_trim:Science:HighestChlPeakReport
2019-12-30T19:17:35.770Z,1577733455.770 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal] Running Loop=1
2019-12-30T19:17:35.770Z,1577733455.770 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal](INFO): Initialize.
2019-12-30T19:17:35.770Z,1577733455.770 [ballast_and_trim:Science:PeakDetectNO3] Running Loop=1
2019-12-30T19:17:35.770Z,1577733455.770 [ballast_and_trim:Science:PeakDetectNO3](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectNO3
2019-12-30T19:17:35.771Z,1577733455.771 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth] Running Loop=1
2019-12-30T19:17:35.771Z,1577733455.771 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Initialize.
2019-12-30T19:17:35.772Z,1577733455.772 [ballast_and_trim:Science:PeakDetectOil] Running Loop=1
2019-12-30T19:17:35.772Z,1577733455.772 [ballast_and_trim:Science:PeakDetectOil](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectOil
2019-12-30T19:17:35.777Z,1577733455.777 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth] Running Loop=1
2019-12-30T19:17:35.777Z,1577733455.777 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Initialize.
2019-12-30T19:17:35.779Z,1577733455.779 [ballast_and_trim:Science:PeakDetectFDOM] Running Loop=1
2019-12-30T19:17:35.779Z,1577733455.779 [ballast_and_trim:Science:PeakDetectFDOM](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectFDOM
2019-12-30T19:17:35.779Z,1577733455.779 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth] Running Loop=1
2019-12-30T19:17:35.779Z,1577733455.779 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Initialize.
2019-12-30T19:17:35.797Z,1577733455.797 [ballast_and_trim:RunBallastAndTrim] Running Loop=1
2019-12-30T19:17:35.797Z,1577733455.797 [ballast_and_trim:RunBallastAndTrim](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim
2019-12-30T19:17:35.798Z,1577733455.798 [ballast_and_trim:RunBallastAndTrim:Depth1] Running Loop=1
2019-12-30T19:17:35.798Z,1577733455.798 [ballast_and_trim:RunBallastAndTrim:Depth1](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:Depth1
2019-12-30T19:17:35.798Z,1577733455.798 [ballast_and_trim:RunBallastAndTrim:Depth1:A] Running Loop=1
2019-12-30T19:17:35.798Z,1577733455.798 [ballast_and_trim:RunBallastAndTrim:Depth1:A] Stopped
2019-12-30T19:17:35.798Z,1577733455.798 [ballast_and_trim:RunBallastAndTrim:Depth1:B] Running Loop=1
2019-12-30T19:17:35.799Z,1577733455.799 [ballast_and_trim:RunBallastAndTrim:Depth1:B](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:Depth1:B
2019-12-30T19:17:35.799Z,1577733455.799 [ballast_and_trim:Science] Running Loop=1
2019-12-30T19:17:35.800Z,1577733455.800 [ballast_and_trim:Science:PeakDetectFDOM] Stopped
2019-12-30T19:17:35.800Z,1577733455.800 [ballast_and_trim:Science:PeakDetectFDOM](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectFDOM
2019-12-30T19:17:35.800Z,1577733455.800 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth] Stopped
2019-12-30T19:17:35.800Z,1577733455.800 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2019-12-30T19:17:35.800Z,1577733455.800 [ballast_and_trim:Science:PeakDetectOil] Stopped
2019-12-30T19:17:35.800Z,1577733455.800 [ballast_and_trim:Science:PeakDetectOil](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectOil
2019-12-30T19:17:35.800Z,1577733455.800 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth] Stopped
2019-12-30T19:17:35.800Z,1577733455.800 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2019-12-30T19:17:35.800Z,1577733455.800 [ballast_and_trim:Science:PeakDetectNO3] Stopped
2019-12-30T19:17:35.800Z,1577733455.800 [ballast_and_trim:Science:PeakDetectNO3](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectNO3
2019-12-30T19:17:35.805Z,1577733455.805 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth] Stopped
2019-12-30T19:17:35.805Z,1577733455.805 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2019-12-30T19:17:35.805Z,1577733455.805 [ballast_and_trim:Science:HighestChlPeakReport] Stopped
2019-12-30T19:17:35.805Z,1577733455.805 [ballast_and_trim:Science:HighestChlPeakReport](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:HighestChlPeakReport
2019-12-30T19:17:35.805Z,1577733455.805 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal] Stopped
2019-12-30T19:17:35.805Z,1577733455.805 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal](DEBUG): Uninitialize.
2019-12-30T19:17:35.805Z,1577733455.805 [ballast_and_trim:Science:PeakDetectChl] Stopped
2019-12-30T19:17:35.805Z,1577733455.805 [ballast_and_trim:Science:PeakDetectChl](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectChl
2019-12-30T19:17:35.806Z,1577733455.806 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth] Stopped
2019-12-30T19:17:35.806Z,1577733455.806 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2019-12-30T19:17:35.806Z,1577733455.806 [ballast_and_trim:Science:Read_Oil] Stopped
2019-12-30T19:17:35.806Z,1577733455.806 [ballast_and_trim:Science:H] Stopped
2019-12-30T19:17:35.806Z,1577733455.806 [ballast_and_trim:Science:G] Running Loop=1
2019-12-30T19:17:35.806Z,1577733455.806 [ballast_and_trim:Science:G](DEBUG): Initialize ReadDataComponent to sense mass_concentration_of_chlorophyll_in_sea_water
2019-12-30T19:17:35.807Z,1577733455.807 [ballast_and_trim:Science:F] Stopped
2019-12-30T19:17:35.807Z,1577733455.807 [ballast_and_trim:Science:E] Stopped
2019-12-30T19:17:35.807Z,1577733455.807 [ballast_and_trim:Science:D] Running Loop=1
2019-12-30T19:17:35.807Z,1577733455.807 [ballast_and_trim:Science:D](DEBUG): Initialize ReadDataComponent to sense CTD_Seabird.sea_water_temperature
2019-12-30T19:17:35.808Z,1577733455.808 [ballast_and_trim:Science:D](DEBUG): Initialize ReadDataComponent to sense CTD_Seabird.sea_water_salinity
2019-12-30T19:17:35.808Z,1577733455.808 [ballast_and_trim:Science:C] Running Loop=1
2019-12-30T19:17:35.809Z,1577733455.809 [ballast_and_trim:Science:C](DEBUG): Initialize ReadDataComponent to sense sea_water_temperature
2019-12-30T19:17:35.810Z,1577733455.810 [ballast_and_trim:Science:C](DEBUG): Initialize ReadDataComponent to sense sea_water_salinity
2019-12-30T19:17:35.810Z,1577733455.810 [ballast_and_trim:Science:B] Stopped
2019-12-30T19:17:35.810Z,1577733455.810 [ballast_and_trim:Science:A] Stopped
2019-12-30T19:17:35.906Z,1577733455.906 [WetLabsBB2FL](INFO): Opening uart, block timeout 10ths=2
2019-12-30T19:17:35.906Z,1577733455.906 [WetLabsBB2FL](INFO): Powering up
2019-12-30T19:17:36.146Z,1577733456.146 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim] Running Loop=1
2019-12-30T19:17:36.146Z,1577733456.146 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim
2019-12-30T19:17:36.146Z,1577733456.146 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:A] Running Loop=1
2019-12-30T19:17:36.146Z,1577733456.146 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:B] Running Loop=1
2019-12-30T19:17:36.146Z,1577733456.146 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:C] Running Loop=1
2019-12-30T19:17:36.146Z,1577733456.146 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:D] Running Loop=1
2019-12-30T19:17:36.146Z,1577733456.146 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:E] Running Loop=1
2019-12-30T19:17:36.146Z,1577733456.146 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:F] Running Loop=1
2019-12-30T19:17:36.147Z,1577733456.147 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:G] Running Loop=1
2019-12-30T19:17:36.149Z,1577733456.149 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:G](INFO): Going to target depth. Speed set to 0.000000 m/s 
2019-12-30T19:17:36.149Z,1577733456.149 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:G] Stopped
2019-12-30T19:17:36.149Z,1577733456.149 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth] Running Loop=1
2019-12-30T19:17:36.149Z,1577733456.149 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth
2019-12-30T19:17:36.149Z,1577733456.149 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:A] Running Loop=1
2019-12-30T19:17:36.149Z,1577733456.149 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold] Running Loop=1
2019-12-30T19:17:36.149Z,1577733456.149 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold
2019-12-30T19:17:36.150Z,1577733456.150 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:A.Point] Running Loop=1
2019-12-30T19:17:36.150Z,1577733456.150 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:A.Point](DEBUG): Initialize.
2019-12-30T19:17:36.150Z,1577733456.150 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy] Running Loop=1
2019-12-30T19:17:36.150Z,1577733456.150 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy](DEBUG): Initialize Buoyancy Component.
2019-12-30T19:17:36.150Z,1577733456.150 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:C.Pitch] Running Loop=1
2019-12-30T19:17:36.150Z,1577733456.150 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:C.Pitch](DEBUG): Initialize.
2019-12-30T19:17:36.150Z,1577733456.150 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive] Running Loop=1
2019-12-30T19:17:36.150Z,1577733456.150 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive
2019-12-30T19:17:36.151Z,1577733456.151 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:A] Running Loop=1
2019-12-30T19:17:36.151Z,1577733456.151 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:F] Running Loop=1
2019-12-30T19:17:36.151Z,1577733456.151 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:E] Running Loop=1
2019-12-30T19:17:36.151Z,1577733456.151 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:D] Running Loop=1
2019-12-30T19:17:36.151Z,1577733456.151 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:C] Running Loop=1
2019-12-30T19:17:36.152Z,1577733456.152 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:B] Running Loop=1
2019-12-30T19:17:36.152Z,1577733456.152 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:A] Running Loop=1
2019-12-30T19:17:36.554Z,1577733456.554 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive] Stopped
2019-12-30T19:17:36.554Z,1577733456.554 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive
2019-12-30T19:17:36.554Z,1577733456.554 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:A] Stopped
2019-12-30T19:17:36.554Z,1577733456.554 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth] Running Loop=1
2019-12-30T19:17:36.554Z,1577733456.554 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth
2019-12-30T19:17:36.555Z,1577733456.555 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed] Running Loop=1
2019-12-30T19:17:36.555Z,1577733456.555 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed](DEBUG): Initialize.
2019-12-30T19:17:36.555Z,1577733456.555 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:A] Running Loop=1
2019-12-30T19:17:36.555Z,1577733456.555 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold] Stopped
2019-12-30T19:17:36.555Z,1577733456.555 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold
2019-12-30T19:17:36.555Z,1577733456.555 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:A.Point] Stopped
2019-12-30T19:17:36.555Z,1577733456.555 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy] Stopped
2019-12-30T19:17:36.555Z,1577733456.555 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2019-12-30T19:17:36.555Z,1577733456.555 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:C.Pitch] Stopped
2019-12-30T19:17:36.555Z,1577733456.555 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:A] Running Loop=1
2019-12-30T19:17:36.766Z,1577733456.766 [DataOverHttps](INFO): Moved sent file to Logs/20191230T190856/Courier0004.lzma.bak
2019-12-30T19:17:36.766Z,1577733456.766 [DataOverHttps](INFO): SBD MOMSN=12183133
2019-12-30T19:17:36.786Z,1577733456.786 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20
2019-12-30T19:17:36.963Z,1577733456.963 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed] Running Loop=1
2019-12-30T19:17:36.964Z,1577733456.964 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:A](INFO): Moving to 7.000000 m 
2019-12-30T19:17:36.964Z,1577733456.964 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:A] Stopped
2019-12-30T19:17:36.964Z,1577733456.964 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch] Running Loop=1
2019-12-30T19:17:36.964Z,1577733456.964 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch](DEBUG): Initialize.
2019-12-30T19:17:39.798Z,1577733459.798 [CTD_Seabird](ERROR): Failed to parse device response: <!--startlogging-->
2019-12-30T19:17:41.807Z,1577733461.807 [CTD_Seabird](ERROR): Salinity reading out of range: 13.694898 psu
2019-12-30T19:17:42.811Z,1577733462.811 [CTD_Seabird](ERROR): Salinity reading out of range: 24.507185 psu
2019-12-30T19:17:52.682Z,1577733472.682 [NAL9602](INFO): Not Powering down - fast GPS
2019-12-30T19:20:27.561Z,1577733627.561 [CTD_Seabird](ERROR): Failed to parse device response: ,4.32174,3926.16
2019-12-30T19:20:48.651Z,1577733648.651 [CTD_Seabird](ERROR): Salinity reading out of range: 24.481070 psu
2019-12-30T19:24:47.699Z,1577733887.699 [CTD_Seabird](ERROR): Salinity reading out of range: 25.430668 psu
2019-12-30T19:26:14.313Z,1577733974.313 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-12-30T19:26:29.701Z,1577733989.701 [Radio_Surface](INFO): Powering down
2019-12-30T19:26:45.449Z,1577734005.449 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-12-30T19:26:46.453Z,1577734006.453 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2019-12-30T19:27:09.948Z,1577734029.948 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch] Stopped
2019-12-30T19:27:09.948Z,1577734029.948 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth](INFO): Completed ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth
2019-12-30T19:27:09.948Z,1577734029.948 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth] Stopped
2019-12-30T19:27:09.949Z,1577734029.949 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth
2019-12-30T19:27:09.949Z,1577734029.949 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed] Stopped
2019-12-30T19:27:09.949Z,1577734029.949 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed](DEBUG): Uninitialize.
2019-12-30T19:27:09.949Z,1577734029.949 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth](INFO): Completed ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth
2019-12-30T19:27:09.949Z,1577734029.949 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth] Stopped
2019-12-30T19:27:09.950Z,1577734029.950 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth
2019-12-30T19:27:09.950Z,1577734029.950 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:A] Stopped
2019-12-30T19:27:09.950Z,1577734029.950 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth] Running Loop=1
2019-12-30T19:27:09.950Z,1577734029.950 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth
2019-12-30T19:27:09.950Z,1577734029.950 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed] Running Loop=1
2019-12-30T19:27:09.950Z,1577734029.950 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed](DEBUG): Initialize.
2019-12-30T19:27:09.950Z,1577734029.950 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch] Running Loop=1
2019-12-30T19:27:09.950Z,1577734029.950 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch](DEBUG): Initialize.
2019-12-30T19:27:09.950Z,1577734029.950 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:C] Running Loop=1
2019-12-30T19:27:10.354Z,1577734030.354 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:C](INFO): Waiting for the vehicle to settle. Depth = 7.015592 m 
2019-12-30T19:27:10.355Z,1577734030.355 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:C] Stopped
2019-12-30T19:27:10.355Z,1577734030.355 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait] Running Loop=1
2019-12-30T19:27:10.355Z,1577734030.355 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait](DEBUG): Initialize Wait Component.
2019-12-30T19:27:10.355Z,1577734030.355 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch] Running Loop=1
2019-12-30T19:27:10.355Z,1577734030.355 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed] Running Loop=1
2019-12-30T19:27:52.733Z,1577734072.733 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.719543
2019-12-30T19:30:54.239Z,1577734254.239 [CTD_Seabird](ERROR): Failed to parse device response: 9,4.35606,3947.62
2019-12-30T19:37:11.063Z,1577734631.063 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait](INFO): Done Waiting.
2019-12-30T19:37:11.063Z,1577734631.063 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait] Stopped
2019-12-30T19:37:11.063Z,1577734631.063 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait](DEBUG): Uninitialize Wait Component.
2019-12-30T19:37:11.063Z,1577734631.063 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:E] Running Loop=1
2019-12-30T19:37:11.444Z,1577734631.444 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:E](INFO): Running ballast and trim. Depth = 7.343141 m 
2019-12-30T19:37:11.444Z,1577734631.444 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:E] Stopped
2019-12-30T19:37:11.444Z,1577734631.444 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.] Running Loop=1
2019-12-30T19:37:11.444Z,1577734631.444 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](INFO): Initializing BallastAndTrim.
2019-12-30T19:57:12.206Z,1577735832.206 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): BallastAndTrim completed. Estimation time: 20.01 minutes (time-out limit reached).
2019-12-30T19:57:12.207Z,1577735832.207 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): Estimated buoyancyNeutral: 400.786288 +/- 8.786416 cc (conf. level 99.90%, sigma: 15.101295 cc).
2019-12-30T19:57:12.208Z,1577735832.208 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): Estimated massDefault: -31.024909 +/- 0.318192 mm (conf. level 99.90%, sigma: 0.546879 mm).
2019-12-30T19:57:12.209Z,1577735832.209 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.] Stopped
2019-12-30T19:57:12.209Z,1577735832.209 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](INFO): Uninitializing BallastAndTrim.
2019-12-30T19:57:12.210Z,1577735832.210 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth](INFO): Completed ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth
2019-12-30T19:57:12.210Z,1577735832.210 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth] Stopped
2019-12-30T19:57:12.210Z,1577735832.210 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth
2019-12-30T19:57:12.210Z,1577735832.210 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed] Stopped
2019-12-30T19:57:12.210Z,1577735832.210 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed](DEBUG): Uninitialize.
2019-12-30T19:57:12.210Z,1577735832.210 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch] Stopped
2019-12-30T19:57:12.211Z,1577735832.211 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim](INFO): Completed ballast_and_trim:RunBallastAndTrim:BallastAndTrim
2019-12-30T19:57:12.211Z,1577735832.211 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim] Stopped
2019-12-30T19:57:12.212Z,1577735832.212 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim
2019-12-30T19:57:12.212Z,1577735832.212 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:A] Stopped
2019-12-30T19:57:12.212Z,1577735832.212 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:B] Stopped
2019-12-30T19:57:12.212Z,1577735832.212 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:C] Stopped
2019-12-30T19:57:12.212Z,1577735832.212 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:D] Stopped
2019-12-30T19:57:12.212Z,1577735832.212 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:E] Stopped
2019-12-30T19:57:12.212Z,1577735832.212 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:F] Stopped
2019-12-30T19:57:12.614Z,1577735832.614 [ballast_and_trim:RunBallastAndTrim:Depth1:B](INFO): Completed ballast_and_trim:RunBallastAndTrim:Depth1:B
2019-12-30T19:57:12.615Z,1577735832.615 [ballast_and_trim:RunBallastAndTrim:Depth1:B] Stopped
2019-12-30T19:57:12.615Z,1577735832.615 [ballast_and_trim:RunBallastAndTrim:Depth1:B](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:Depth1:B
2019-12-30T19:57:12.615Z,1577735832.615 [ballast_and_trim:RunBallastAndTrim:Depth1](INFO): Completed ballast_and_trim:RunBallastAndTrim:Depth1
2019-12-30T19:57:12.615Z,1577735832.615 [ballast_and_trim:RunBallastAndTrim:Depth1] Stopped
2019-12-30T19:57:12.615Z,1577735832.615 [ballast_and_trim:RunBallastAndTrim:Depth1](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:Depth1
2019-12-30T19:57:12.615Z,1577735832.615 [ballast_and_trim:RunBallastAndTrim:Depth2] Running Loop=1
2019-12-30T19:57:12.615Z,1577735832.615 [ballast_and_trim:RunBallastAndTrim:Depth2](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:Depth2
2019-12-30T19:57:12.615Z,1577735832.615 [ballast_and_trim:RunBallastAndTrim:Depth2:A] Running Loop=1
2019-12-30T19:57:13.029Z,1577735833.029 [ballast_and_trim:RunBallastAndTrim:Depth2] Stopped
2019-12-30T19:57:13.030Z,1577735833.030 [ballast_and_trim:RunBallastAndTrim:Depth2](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:Depth2
2019-12-30T19:57:13.030Z,1577735833.030 [ballast_and_trim:RunBallastAndTrim:Depth2:A] Stopped
2019-12-30T19:57:13.030Z,1577735833.030 [ballast_and_trim:RunBallastAndTrim](INFO): Completed ballast_and_trim:RunBallastAndTrim
2019-12-30T19:57:13.030Z,1577735833.030 [ballast_and_trim:RunBallastAndTrim] Stopped
2019-12-30T19:57:13.030Z,1577735833.030 [ballast_and_trim:RunBallastAndTrim](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim
2019-12-30T19:57:13.030Z,1577735833.030 [ballast_and_trim:Float_Up] Running Loop=1
2019-12-30T19:57:13.030Z,1577735833.030 [ballast_and_trim:Float_Up](DEBUG): Aggregate::initialize ballast_and_trim:Float_Up
2019-12-30T19:57:13.030Z,1577735833.030 [ballast_and_trim:Float_Up:A.Buoyancy] Running Loop=1
2019-12-30T19:57:13.030Z,1577735833.030 [ballast_and_trim:Float_Up:A.Buoyancy](DEBUG): Initialize Buoyancy Component.
2019-12-30T19:57:13.031Z,1577735833.031 [ballast_and_trim:Float_Up:B.Wait] Running Loop=1
2019-12-30T19:57:13.031Z,1577735833.031 [ballast_and_trim:Float_Up:B.Wait](DEBUG): Initialize Wait Component.
2019-12-30T19:57:13.440Z,1577735833.440 [ballast_and_trim:Float_Up:A.Buoyancy] Running Loop=1
2019-12-30T19:58:37.246Z,1577735917.246 [ballast_and_trim:Float_Up] Stopped
2019-12-30T19:58:37.246Z,1577735917.246 [ballast_and_trim:Float_Up](DEBUG): Aggregate::uninitialize ballast_and_trim:Float_Up
2019-12-30T19:58:37.246Z,1577735917.246 [ballast_and_trim:Float_Up:A.Buoyancy] Stopped
2019-12-30T19:58:37.246Z,1577735917.246 [ballast_and_trim:Float_Up:A.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2019-12-30T19:58:37.246Z,1577735917.246 [ballast_and_trim:Float_Up:B.Wait] Stopped
2019-12-30T19:58:37.246Z,1577735917.246 [ballast_and_trim:Float_Up:B.Wait](DEBUG): Uninitialize Wait Component.
2019-12-30T19:58:37.248Z,1577735917.248 [ballast_and_trim](INFO): Completed ballast_and_trim
2019-12-30T19:58:37.248Z,1577735917.248 [MissionManager](INFO): ballast_and_trim is completed.
2019-12-30T19:58:37.248Z,1577735917.248 [MissionManager](INFO): Uninitializing Mission ballast_and_trim
2019-12-30T19:58:37.248Z,1577735917.248 [ballast_and_trim] Stopped
2019-12-30T19:58:37.248Z,1577735917.248 [ballast_and_trim](DEBUG): Aggregate::uninitialize ballast_and_trim
2019-12-30T19:58:37.248Z,1577735917.248 [ballast_and_trim:Science] Stopped
2019-12-30T19:58:37.248Z,1577735917.248 [ballast_and_trim:Science](DEBUG): Aggregate::uninitialize ballast_and_trim:Science
2019-12-30T19:58:37.248Z,1577735917.248 [ballast_and_trim:Science:C] Stopped
2019-12-30T19:58:37.248Z,1577735917.248 [ballast_and_trim:Science:D] Stopped
2019-12-30T19:58:37.249Z,1577735917.249 [ballast_and_trim:Science:G] Stopped
2019-12-30T19:58:37.629Z,1577735917.629 [MissionManager](IMPORTANT): Started mission Default
2019-12-30T19:58:37.630Z,1577735917.630 [Default] Running Loop=1
2019-12-30T19:58:37.630Z,1577735917.630 [Default](DEBUG): Aggregate::initialize Default
2019-12-30T19:58:37.630Z,1577735917.630 [Default:B.GoToSurface] Running Loop=1
2019-12-30T19:58:37.630Z,1577735917.630 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-12-30T19:58:37.630Z,1577735917.630 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-12-30T19:58:37.630Z,1577735917.630 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-12-30T19:58:37.631Z,1577735917.631 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-12-30T19:58:37.631Z,1577735917.631 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-12-30T19:58:37.631Z,1577735917.631 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-12-30T19:58:37.632Z,1577735917.632 [Default:A.Wait] Running Loop=1
2019-12-30T19:58:37.632Z,1577735917.632 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-12-30T19:58:37.737Z,1577735917.737 [Radio_Surface](INFO): Powering up
2019-12-30T19:58:37.789Z,1577735917.789 [WetLabsBB2FL](INFO): Powering down
2019-12-30T19:58:43.389Z,1577735923.389 [DataOverHttps](INFO): Radio surface powered ON.
2019-12-30T19:58:50.965Z,1577735930.965 [Default:A.Wait](INFO): Done Waiting.
2019-12-30T19:58:50.966Z,1577735930.966 [Default:A.Wait] Stopped
2019-12-30T19:58:50.966Z,1577735930.966 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-12-30T19:58:51.381Z,1577735931.381 [Default:CheckIn] Running Loop=1
2019-12-30T19:58:51.381Z,1577735931.381 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-12-30T19:58:51.381Z,1577735931.381 [Default:CheckIn:Read_GPS] Running Loop=1
2019-12-30T19:58:53.368Z,1577735933.368 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,195615.00,A,3648.16332,N,12147.28314,W,0.292,0.00,301219,,,A*73
2019-12-30T19:58:53.370Z,1577735933.370 [NAL9602](INFO): GPS fix at 20191230T195615: (36.802722, -121.788052)
2019-12-30T19:58:53.414Z,1577735933.414 [Default:CheckIn:Read_GPS] Stopped
2019-12-30T19:58:53.414Z,1577735933.414 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-12-30T19:59:13.521Z,1577735953.521 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-12-30T19:59:44.645Z,1577735984.645 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-12-30T20:00:15.769Z,1577736015.769 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-12-30T20:00:46.897Z,1577736046.897 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-12-30T20:01:18.021Z,1577736078.021 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-12-30T20:01:49.145Z,1577736109.145 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-12-30T20:02:18.849Z,1577736138.849 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003273
2019-12-30T20:02:26.432Z,1577736146.432 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20191230T190856/Courier0007.lzma
2019-12-30T20:02:28.438Z,1577736148.438 [DataOverHttps](INFO): Moved sent file to Logs/20191230T190856/Courier0007.lzma.bak
2019-12-30T20:02:28.439Z,1577736148.439 [DataOverHttps](INFO): SBD MOMSN=12183138
2019-12-30T20:02:46.028Z,1577736166.028 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20191230T190856/Courier0010.lzma
2019-12-30T20:02:48.034Z,1577736168.034 [DataOverHttps](INFO): Moved sent file to Logs/20191230T190856/Courier0010.lzma.bak
2019-12-30T20:02:48.034Z,1577736168.034 [DataOverHttps](INFO): SBD MOMSN=12183141
2019-12-30T20:02:51.738Z,1577736171.738 [NAL9602](INFO): Not Powering down - fast GPS
2019-12-30T20:03:05.042Z,1577736185.042 [DataOverHttps](INFO): Sending 854 bytes from file Logs/20191230T190856/Express0001.lzma
2019-12-30T20:03:07.042Z,1577736187.042 [DataOverHttps](INFO): Moved sent file to Logs/20191230T190856/Express0001.lzma.bak
2019-12-30T20:03:07.043Z,1577736187.043 [DataOverHttps](INFO): SBD MOMSN=12183143
2019-12-30T20:03:23.946Z,1577736203.946 [DataOverHttps](INFO): Sending 275 bytes from file Logs/20191230T190856/Express0005.lzma
2019-12-30T20:03:25.950Z,1577736205.950 [DataOverHttps](INFO): Moved sent file to Logs/20191230T190856/Express0005.lzma.bak
2019-12-30T20:03:25.951Z,1577736205.951 [DataOverHttps](INFO): SBD MOMSN=12183166
2019-12-30T20:03:43.047Z,1577736223.047 [DataOverHttps](INFO): Sending 919 bytes from file Logs/20191230T190856/Express0008.lzma
2019-12-30T20:03:45.050Z,1577736225.050 [DataOverHttps](INFO): Moved sent file to Logs/20191230T190856/Express0008.lzma.bak
2019-12-30T20:03:45.051Z,1577736225.051 [DataOverHttps](INFO): SBD MOMSN=12183170
2019-12-30T20:04:02.046Z,1577736242.046 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20191230T190856/Express0011.lzma
2019-12-30T20:04:04.051Z,1577736244.051 [DataOverHttps](INFO): Moved sent file to Logs/20191230T190856/Express0011.lzma.bak
2019-12-30T20:04:04.052Z,1577736244.052 [DataOverHttps](INFO): SBD MOMSN=12183183
2019-12-30T20:04:05.285Z,1577736245.285 [Default:CheckIn:Read_Iridium] Stopped
2019-12-30T20:04:05.285Z,1577736245.285 [Default:CheckIn:C.Wait] Running Loop=1
2019-12-30T20:04:05.285Z,1577736245.285 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-12-30T20:09:05.872Z,1577736545.872 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-12-30T20:09:05.872Z,1577736545.872 [Default:CheckIn:C.Wait] Stopped
2019-12-30T20:09:05.873Z,1577736545.873 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-12-30T20:09:05.873Z,1577736545.873 [Default:CheckIn:D] Running Loop=1
2019-12-30T20:09:06.282Z,1577736546.282 [Default:CheckIn:D] Stopped
2019-12-30T20:09:06.283Z,1577736546.283 [Default:CheckIn:E] Running Loop=1
2019-12-30T20:09:06.696Z,1577736546.696 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.477519 min 
2019-12-30T20:09:06.696Z,1577736546.696 [Default:CheckIn:E] Stopped
2019-12-30T20:09:06.697Z,1577736546.697 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-12-30T20:09:06.697Z,1577736546.697 [Default:CheckIn] Stopped
2019-12-30T20:09:06.697Z,1577736546.697 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-12-30T20:09:06.697Z,1577736546.697 [Default:CheckIn](INFO): Running loop #2
2019-12-30T20:09:06.697Z,1577736546.697 [Default:CheckIn] Running Loop=2
2019-12-30T20:09:06.697Z,1577736546.697 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-12-30T20:09:06.697Z,1577736546.697 [Default:CheckIn:Read_GPS] Running Loop=1
2019-12-30T20:09:08.680Z,1577736548.680 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200629.00,A,3648.16516,N,12147.27762,W,0.214,239.13,301219,,,A*7D
2019-12-30T20:09:08.682Z,1577736548.682 [NAL9602](INFO): GPS fix at 20191230T200629: (36.802753, -121.787960)
2019-12-30T20:09:08.726Z,1577736548.726 [Default:CheckIn:Read_GPS] Stopped
2019-12-30T20:09:08.726Z,1577736548.726 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-12-30T20:09:16.349Z,1577736556.349 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20191230T190856/Courier0013.lzma
2019-12-30T20:09:18.354Z,1577736558.354 [DataOverHttps](INFO): Moved sent file to Logs/20191230T190856/Courier0013.lzma.bak
2019-12-30T20:09:18.354Z,1577736558.354 [DataOverHttps](INFO): SBD MOMSN=12183185
2019-12-30T20:09:35.581Z,1577736575.581 [DataOverHttps](INFO): Sending 153 bytes from file Logs/20191230T190856/Express0014.lzma
2019-12-30T20:09:37.586Z,1577736577.586 [DataOverHttps](INFO): Moved sent file to Logs/20191230T190856/Express0014.lzma.bak
2019-12-30T20:09:37.586Z,1577736577.586 [DataOverHttps](INFO): SBD MOMSN=12183188
2019-12-30T20:09:39.014Z,1577736579.014 [Default:CheckIn:Read_Iridium] Stopped
2019-12-30T20:09:39.014Z,1577736579.014 [Default:CheckIn:C.Wait] Running Loop=1
2019-12-30T20:09:39.014Z,1577736579.014 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-12-30T20:14:10.474Z,1577736850.474 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-12-30T20:14:39.597Z,1577736879.597 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-12-30T20:14:39.597Z,1577736879.597 [Default:CheckIn:C.Wait] Stopped
2019-12-30T20:14:39.597Z,1577736879.597 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-12-30T20:14:39.597Z,1577736879.597 [Default:CheckIn:D] Running Loop=1
2019-12-30T20:14:40.010Z,1577736880.010 [Default:CheckIn:D] Stopped
2019-12-30T20:14:40.010Z,1577736880.010 [Default:CheckIn:E] Running Loop=1
2019-12-30T20:14:40.391Z,1577736880.391 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 16.039662 min 
2019-12-30T20:14:40.391Z,1577736880.391 [Default:CheckIn:E] Stopped
2019-12-30T20:14:40.392Z,1577736880.392 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-12-30T20:14:40.392Z,1577736880.392 [Default:CheckIn] Stopped
2019-12-30T20:14:40.392Z,1577736880.392 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-12-30T20:14:40.392Z,1577736880.392 [Default:CheckIn](INFO): Running loop #3
2019-12-30T20:14:40.392Z,1577736880.392 [Default:CheckIn] Running Loop=3
2019-12-30T20:14:40.392Z,1577736880.392 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-12-30T20:14:40.392Z,1577736880.392 [Default:CheckIn:Read_GPS] Running Loop=1
2019-12-30T20:19:40.601Z,1577737180.601 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-12-30T20:14:40.4Z
2019-12-30T20:19:40.601Z,1577737180.601 [Default:CheckIn:Read_GPS] Stopped
2019-12-30T20:19:40.602Z,1577737180.602 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-12-30T20:19:48.044Z,1577737188.044 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20191230T190856/Courier0016.lzma
2019-12-30T20:19:50.050Z,1577737190.050 [DataOverHttps](INFO): Moved sent file to Logs/20191230T190856/Courier0016.lzma.bak
2019-12-30T20:19:50.051Z,1577737190.051 [DataOverHttps](INFO): SBD MOMSN=12183191
2019-12-30T20:20:07.261Z,1577737207.261 [DataOverHttps](INFO): Sending 222 bytes from file Logs/20191230T190856/Express0017.lzma
2019-12-30T20:20:09.266Z,1577737209.266 [DataOverHttps](INFO): Moved sent file to Logs/20191230T190856/Express0017.lzma.bak
2019-12-30T20:20:09.267Z,1577737209.267 [DataOverHttps](INFO): SBD MOMSN=12183193
2019-12-30T20:20:10.467Z,1577737210.467 [Default:CheckIn:Read_Iridium] Stopped
2019-12-30T20:20:10.467Z,1577737210.467 [Default:CheckIn:C.Wait] Running Loop=1
2019-12-30T20:20:10.467Z,1577737210.467 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-12-30T20:20:12.858Z,1577737212.858 [NAL9602](INFO): Not Powering down - fast GPS
2019-12-30T20:24:15.693Z,1577737455.693 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2019-12-30T20:24:15.695Z,1577737455.695 [BPC1](INFO): Received data from all battery sticks.
2019-12-30T20:25:11.045Z,1577737511.045 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-12-30T20:25:11.045Z,1577737511.045 [Default:CheckIn:C.Wait] Stopped
2019-12-30T20:25:11.045Z,1577737511.045 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-12-30T20:25:11.045Z,1577737511.045 [Default:CheckIn:D] Running Loop=1
2019-12-30T20:25:11.449Z,1577737511.449 [Default:CheckIn:D] Stopped
2019-12-30T20:25:11.450Z,1577737511.450 [Default:CheckIn:E] Running Loop=1
2019-12-30T20:25:11.869Z,1577737511.869 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 26.563660 min 
2019-12-30T20:25:11.869Z,1577737511.869 [Default:CheckIn:E] Stopped
2019-12-30T20:25:11.869Z,1577737511.869 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-12-30T20:25:11.869Z,1577737511.869 [Default:CheckIn] Stopped
2019-12-30T20:25:11.869Z,1577737511.869 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-12-30T20:25:11.870Z,1577737511.870 [Default:CheckIn](INFO): Running loop #4
2019-12-30T20:25:11.870Z,1577737511.870 [Default:CheckIn] Running Loop=4
2019-12-30T20:25:11.870Z,1577737511.870 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-12-30T20:25:11.870Z,1577737511.870 [Default:CheckIn:Read_GPS] Running Loop=1
2019-12-30T20:25:13.444Z,1577737513.444 [NAL9602](FAULT): GPS failed to acquire within timeout.
2019-12-30T20:25:13.445Z,1577737513.445 [NAL9602] Data Fault, FailCount= 1
2019-12-30T20:25:13.445Z,1577737513.445 [NAL9602](ERROR): Data Fault
2019-12-30T20:25:13.510Z,1577737513.510 [CBIT](ERROR): Data Fault in component: NAL9602
2019-12-30T20:25:13.854Z,1577737513.854 [NAL9602](INFO): Powering down
2019-12-30T20:25:14.258Z,1577737514.258 [NAL9602](FAULT): LCB fault:  Software Overcurrent.
2019-12-30T20:25:14.258Z,1577737514.258 [NAL9602] Hardware Fault, FailCount= 1
2019-12-30T20:25:14.258Z,1577737514.258 [NAL9602](ERROR): Hardware Fault
2019-12-30T20:25:14.697Z,1577737514.697 [CBIT](INFO): Clearing failed state for component NAL9602
2019-12-30T20:25:14.697Z,1577737514.697 [NAL9602] No Fault, FailCount= 1
2019-12-30T20:25:44.151Z,1577737544.151 [NAL9602](INFO): Powering up NAL9602
2019-12-30T20:25:55.058Z,1577737555.058 [NAL9602](INFO): NAL9602 initialized
2019-12-30T20:30:12.034Z,1577737812.034 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-12-30T20:25:11.9Z
2019-12-30T20:30:12.034Z,1577737812.034 [Default:CheckIn:Read_GPS] Stopped
2019-12-30T20:30:12.035Z,1577737812.035 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-12-30T20:30:19.588Z,1577737819.588 [DataOverHttps](INFO): Sending 45 bytes from file Logs/20191230T190856/Courier0019.lzma
2019-12-30T20:30:21.594Z,1577737821.594 [DataOverHttps](INFO): Moved sent file to Logs/20191230T190856/Courier0019.lzma.bak
2019-12-30T20:30:21.594Z,1577737821.594 [DataOverHttps](INFO): SBD MOMSN=12183197
2019-12-30T20:30:38.801Z,1577737838.801 [DataOverHttps](INFO): Sending 194 bytes from file Logs/20191230T190856/Express0020.lzma
2019-12-30T20:30:40.807Z,1577737840.807 [DataOverHttps](INFO): Moved sent file to Logs/20191230T190856/Express0020.lzma.bak
2019-12-30T20:30:40.807Z,1577737840.807 [DataOverHttps](INFO): SBD MOMSN=12183199
2019-12-30T20:30:41.998Z,1577737841.999 [Default:CheckIn:Read_Iridium] Stopped
2019-12-30T20:30:41.999Z,1577737841.999 [Default:CheckIn:C.Wait] Running Loop=1
2019-12-30T20:30:41.999Z,1577737841.999 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-12-30T20:30:58.474Z,1577737858.474 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-12-30T20:31:29.174Z,1577737889.174 [NAL9602](INFO): Not Powering down - fast GPS
2019-12-30T20:35:42.526Z,1577738142.526 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-12-30T20:35:42.526Z,1577738142.526 [Default:CheckIn:C.Wait] Stopped
2019-12-30T20:35:42.526Z,1577738142.526 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-12-30T20:35:42.527Z,1577738142.527 [Default:CheckIn:D] Running Loop=1
2019-12-30T20:35:42.938Z,1577738142.938 [Default:CheckIn:D] Stopped
2019-12-30T20:35:42.938Z,1577738142.938 [Default:CheckIn:E] Running Loop=1
2019-12-30T20:35:43.321Z,1577738143.321 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 37.088468 min 
2019-12-30T20:35:43.321Z,1577738143.321 [Default:CheckIn:E] Stopped
2019-12-30T20:35:43.321Z,1577738143.321 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-12-30T20:35:43.321Z,1577738143.321 [Default:CheckIn] Stopped
2019-12-30T20:35:43.321Z,1577738143.321 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-12-30T20:35:43.321Z,1577738143.321 [Default:CheckIn](INFO): Running loop #5
2019-12-30T20:35:43.321Z,1577738143.321 [Default:CheckIn] Running Loop=5
2019-12-30T20:35:43.322Z,1577738143.322 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-12-30T20:35:43.322Z,1577738143.322 [Default:CheckIn:Read_GPS] Running Loop=1
2019-12-30T20:40:43.528Z,1577738443.528 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-12-30T20:35:43.3Z
2019-12-30T20:40:43.537Z,1577738443.537 [Default:CheckIn:Read_GPS] Stopped
2019-12-30T20:40:43.538Z,1577738443.538 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-12-30T20:40:47.910Z,1577738447.910 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-12-30T20:40:51.044Z,1577738451.044 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20191230T190856/Courier0022.lzma
2019-12-30T20:40:53.051Z,1577738453.051 [DataOverHttps](INFO): Moved sent file to Logs/20191230T190856/Courier0022.lzma.bak
2019-12-30T20:40:53.051Z,1577738453.051 [DataOverHttps](INFO): SBD MOMSN=12183204
2019-12-30T20:41:10.049Z,1577738470.049 [DataOverHttps](INFO): Sending 196 bytes from file Logs/20191230T190856/Express0023.lzma
2019-12-30T20:41:12.054Z,1577738472.054 [DataOverHttps](INFO): Moved sent file to Logs/20191230T190856/Express0023.lzma.bak
2019-12-30T20:41:12.055Z,1577738472.055 [DataOverHttps](INFO): SBD MOMSN=12183206
2019-12-30T20:41:13.392Z,1577738473.392 [Default:CheckIn:Read_Iridium] Stopped
2019-12-30T20:41:13.392Z,1577738473.392 [Default:CheckIn:C.Wait] Running Loop=1
2019-12-30T20:41:13.392Z,1577738473.392 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-12-30T20:41:18.620Z,1577738478.620 [NAL9602](INFO): Not Powering down - fast GPS
2019-12-30T20:46:13.968Z,1577738773.968 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-12-30T20:46:13.968Z,1577738773.968 [Default:CheckIn:C.Wait] Stopped
2019-12-30T20:46:13.968Z,1577738773.968 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-12-30T20:46:13.968Z,1577738773.968 [Default:CheckIn:D] Running Loop=1
2019-12-30T20:46:14.377Z,1577738774.377 [Default:CheckIn:D] Stopped
2019-12-30T20:46:14.377Z,1577738774.377 [Default:CheckIn:E] Running Loop=1
2019-12-30T20:46:14.770Z,1577738774.770 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 47.612459 min 
2019-12-30T20:46:14.770Z,1577738774.770 [Default:CheckIn:E] Stopped
2019-12-30T20:46:14.770Z,1577738774.770 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-12-30T20:46:14.771Z,1577738774.771 [Default:CheckIn] Stopped
2019-12-30T20:46:14.771Z,1577738774.771 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-12-30T20:46:14.771Z,1577738774.771 [Default:CheckIn](INFO): Running loop #6
2019-12-30T20:46:14.771Z,1577738774.771 [Default:CheckIn] Running Loop=6
2019-12-30T20:46:14.771Z,1577738774.771 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-12-30T20:46:14.771Z,1577738774.771 [Default:CheckIn:Read_GPS] Running Loop=1
2019-12-30T20:46:16.366Z,1577738776.366 [NAL9602](FAULT): GPS failed to acquire within timeout.
2019-12-30T20:46:16.366Z,1577738776.366 [NAL9602] Data Fault, FailCount= 2
2019-12-30T20:46:16.366Z,1577738776.366 [NAL9602](ERROR): Data Fault
2019-12-30T20:46:16.442Z,1577738776.442 [CBIT](ERROR): Data Fault in component: NAL9602
2019-12-30T20:46:16.765Z,1577738776.765 [NAL9602](INFO): Powering down
2019-12-30T20:46:17.626Z,1577738777.626 [CBIT](INFO): Clearing failed state for component NAL9602
2019-12-30T20:46:17.626Z,1577738777.626 [NAL9602] No Fault, FailCount= 2
2019-12-30T20:46:47.070Z,1577738807.070 [NAL9602](INFO): Powering up NAL9602
2019-12-30T20:46:57.976Z,1577738817.976 [NAL9602](INFO): NAL9602 initialized
2019-12-30T20:51:14.958Z,1577739074.958 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-12-30T20:46:14.8Z
2019-12-30T20:51:14.958Z,1577739074.958 [Default:CheckIn:Read_GPS] Stopped
2019-12-30T20:51:14.958Z,1577739074.958 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-12-30T20:51:22.940Z,1577739082.940 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20191230T190856/Courier0025.lzma
2019-12-30T20:51:24.946Z,1577739084.946 [DataOverHttps](INFO): Moved sent file to Logs/20191230T190856/Courier0025.lzma.bak
2019-12-30T20:51:24.947Z,1577739084.947 [DataOverHttps](INFO): SBD MOMSN=12183210
2019-12-30T20:51:41.953Z,1577739101.953 [DataOverHttps](INFO): Sending 215 bytes from file Logs/20191230T190856/Express0026.lzma
2019-12-30T20:51:43.958Z,1577739103.958 [DataOverHttps](INFO): Moved sent file to Logs/20191230T190856/Express0026.lzma.bak
2019-12-30T20:51:43.959Z,1577739103.959 [DataOverHttps](INFO): SBD MOMSN=12183212
2019-12-30T20:51:45.277Z,1577739105.277 [Default:CheckIn:Read_Iridium] Stopped
2019-12-30T20:51:45.277Z,1577739105.277 [Default:CheckIn:C.Wait] Running Loop=1
2019-12-30T20:51:45.277Z,1577739105.277 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-12-30T20:52:01.386Z,1577739121.386 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-12-30T20:52:32.094Z,1577739152.094 [NAL9602](INFO): Not Powering down - fast GPS
2019-12-30T20:56:45.856Z,1577739405.856 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-12-30T20:56:45.865Z,1577739405.865 [Default:CheckIn:C.Wait] Stopped
2019-12-30T20:56:45.865Z,1577739405.865 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-12-30T20:56:45.865Z,1577739405.865 [Default:CheckIn:D] Running Loop=1
2019-12-30T20:56:46.279Z,1577739406.279 [Default:CheckIn:D] Stopped
2019-12-30T20:56:46.279Z,1577739406.279 [Default:CheckIn:E] Running Loop=1
2019-12-30T20:56:46.638Z,1577739406.638 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 58.144153 min 
2019-12-30T20:56:46.638Z,1577739406.638 [Default:CheckIn:E] Stopped
2019-12-30T20:56:46.638Z,1577739406.638 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-12-30T20:56:46.638Z,1577739406.638 [Default:CheckIn] Stopped
2019-12-30T20:56:46.638Z,1577739406.638 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-12-30T20:56:46.638Z,1577739406.638 [Default:CheckIn](INFO): Running loop #7
2019-12-30T20:56:46.638Z,1577739406.638 [Default:CheckIn] Running Loop=7
2019-12-30T20:56:46.639Z,1577739406.639 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-12-30T20:56:46.639Z,1577739406.639 [Default:CheckIn:Read_GPS] Running Loop=1
2019-12-30T21:01:46.814Z,1577739706.814 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-12-30T20:56:46.6Z
2019-12-30T21:01:46.814Z,1577739706.814 [Default:CheckIn:Read_GPS] Stopped
2019-12-30T21:01:46.814Z,1577739706.814 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-12-30T21:01:50.830Z,1577739710.830 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-12-30T21:01:54.416Z,1577739714.416 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20191230T190856/Courier0028.lzma
2019-12-30T21:01:56.422Z,1577739716.422 [DataOverHttps](INFO): Moved sent file to Logs/20191230T190856/Courier0028.lzma.bak
2019-12-30T21:01:56.423Z,1577739716.423 [DataOverHttps](INFO): SBD MOMSN=12183217
2019-12-30T21:02:13.310Z,1577739733.310 [DataOverHttps](INFO): Sending 199 bytes from file Logs/20191230T190856/Express0029.lzma
2019-12-30T21:02:15.330Z,1577739735.330 [DataOverHttps](INFO): Moved sent file to Logs/20191230T190856/Express0029.lzma.bak
2019-12-30T21:02:15.331Z,1577739735.331 [DataOverHttps](INFO): SBD MOMSN=12183219
2019-12-30T21:02:16.721Z,1577739736.721 [Default:CheckIn:Read_Iridium] Stopped
2019-12-30T21:02:16.721Z,1577739736.721 [Default:CheckIn:C.Wait] Running Loop=1
2019-12-30T21:02:16.721Z,1577739736.721 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-12-30T21:02:21.534Z,1577739741.534 [NAL9602](INFO): Not Powering down - fast GPS
2019-12-30T21:07:17.313Z,1577740037.313 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-12-30T21:07:17.313Z,1577740037.313 [Default:CheckIn:C.Wait] Stopped
2019-12-30T21:07:17.313Z,1577740037.313 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-12-30T21:07:17.313Z,1577740037.313 [Default:CheckIn:D] Running Loop=1
2019-12-30T21:07:17.694Z,1577740037.694 [Default:CheckIn:D] Stopped
2019-12-30T21:07:17.694Z,1577740037.694 [Default:CheckIn:E] Running Loop=1
2019-12-30T21:07:18.102Z,1577740038.102 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 68.667733 min 
2019-12-30T21:07:18.102Z,1577740038.102 [Default:CheckIn:E] Stopped
2019-12-30T21:07:18.102Z,1577740038.102 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-12-30T21:07:18.102Z,1577740038.102 [Default:CheckIn] Stopped
2019-12-30T21:07:18.102Z,1577740038.102 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-12-30T21:07:18.102Z,1577740038.102 [Default:CheckIn](INFO): Running loop #8
2019-12-30T21:07:18.102Z,1577740038.102 [Default:CheckIn] Running Loop=8
2019-12-30T21:07:18.102Z,1577740038.102 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-12-30T21:07:18.103Z,1577740038.103 [Default:CheckIn:Read_GPS] Running Loop=1
2019-12-30T21:07:19.684Z,1577740039.684 [NAL9602](FAULT): GPS failed to acquire within timeout.
2019-12-30T21:07:19.684Z,1577740039.684 [NAL9602] Data Fault, FailCount= 3
2019-12-30T21:07:19.684Z,1577740039.684 [NAL9602](ERROR): Data Fault
2019-12-30T21:07:19.738Z,1577740039.738 [CBIT](ERROR): Data Fault in component: NAL9602
2019-12-30T21:07:20.094Z,1577740040.094 [NAL9602](INFO): Powering down
2019-12-30T21:07:20.934Z,1577740040.934 [CBIT](INFO): Clearing failed state for component NAL9602
2019-12-30T21:07:20.934Z,1577740040.934 [NAL9602] No Fault, FailCount= 3
2019-12-30T21:07:50.394Z,1577740070.394 [NAL9602](INFO): Powering up NAL9602
2019-12-30T21:08:01.302Z,1577740081.302 [NAL9602](INFO): NAL9602 initialized
2019-12-30T21:12:18.280Z,1577740338.280 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-12-30T21:07:18.1Z
2019-12-30T21:12:18.280Z,1577740338.280 [Default:CheckIn:Read_GPS] Stopped
2019-12-30T21:12:18.280Z,1577740338.280 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-12-30T21:12:25.276Z,1577740345.276 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20191230T190856/Courier0031.lzma
2019-12-30T21:12:27.282Z,1577740347.282 [DataOverHttps](INFO): Moved sent file to Logs/20191230T190856/Courier0031.lzma.bak
2019-12-30T21:12:27.283Z,1577740347.283 [DataOverHttps](INFO): SBD MOMSN=12183223
2019-12-30T21:12:45.257Z,1577740365.257 [DataOverHttps](INFO): Sending 215 bytes from file Logs/20191230T190856/Express0032.lzma
2019-12-30T21:12:47.262Z,1577740367.262 [DataOverHttps](INFO): Moved sent file to Logs/20191230T190856/Express0032.lzma.bak
2019-12-30T21:12:47.263Z,1577740367.263 [DataOverHttps](INFO): SBD MOMSN=12183225
2019-12-30T21:12:48.600Z,1577740368.600 [Default:CheckIn:Read_Iridium] Stopped
2019-12-30T21:12:48.600Z,1577740368.600 [Default:CheckIn:C.Wait] Running Loop=1
2019-12-30T21:12:48.600Z,1577740368.600 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-12-30T21:13:04.710Z,1577740384.710 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-12-30T21:13:35.404Z,1577740415.404 [NAL9602](INFO): Not Powering down - fast GPS
2019-12-30T21:17:49.168Z,1577740669.168 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-12-30T21:17:49.168Z,1577740669.168 [Default:CheckIn:C.Wait] Stopped
2019-12-30T21:17:49.168Z,1577740669.168 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-12-30T21:17:49.168Z,1577740669.168 [Default:CheckIn:D] Running Loop=1
2019-12-30T21:17:49.562Z,1577740669.562 [Default:CheckIn:D] Stopped
2019-12-30T21:17:49.562Z,1577740669.562 [Default:CheckIn:E] Running Loop=1
2019-12-30T21:17:49.963Z,1577740669.963 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 79.198861 min 
2019-12-30T21:17:49.963Z,1577740669.963 [Default:CheckIn:E] Stopped
2019-12-30T21:17:49.963Z,1577740669.963 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-12-30T21:17:49.963Z,1577740669.963 [Default:CheckIn] Stopped
2019-12-30T21:17:49.963Z,1577740669.963 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-12-30T21:17:49.963Z,1577740669.963 [Default:CheckIn](INFO): Running loop #9
2019-12-30T21:17:49.963Z,1577740669.963 [Default:CheckIn] Running Loop=9
2019-12-30T21:17:49.963Z,1577740669.963 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-12-30T21:17:49.964Z,1577740669.964 [Default:CheckIn:Read_GPS] Running Loop=1
2019-12-30T21:22:50.137Z,1577740970.137 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-12-30T21:17:49.0Z
2019-12-30T21:22:50.137Z,1577740970.137 [Default:CheckIn:Read_GPS] Stopped
2019-12-30T21:22:50.138Z,1577740970.138 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-12-30T21:22:53.742Z,1577740973.742 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-12-30T21:22:57.380Z,1577740977.380 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20191230T190856/Courier0034.lzma
2019-12-30T21:22:59.386Z,1577740979.386 [DataOverHttps](INFO): Moved sent file to Logs/20191230T190856/Courier0034.lzma.bak
2019-12-30T21:22:59.387Z,1577740979.387 [DataOverHttps](INFO): SBD MOMSN=12183230
2019-12-30T21:23:16.745Z,1577740996.745 [DataOverHttps](INFO): Sending 196 bytes from file Logs/20191230T190856/Express0035.lzma
2019-12-30T21:23:18.750Z,1577740998.750 [DataOverHttps](INFO): Moved sent file to Logs/20191230T190856/Express0035.lzma.bak
2019-12-30T21:23:18.751Z,1577740998.751 [DataOverHttps](INFO): SBD MOMSN=12183232
2019-12-30T21:23:20.053Z,1577741000.053 [Default:CheckIn:Read_Iridium] Stopped
2019-12-30T21:23:20.053Z,1577741000.053 [Default:CheckIn:C.Wait] Running Loop=1
2019-12-30T21:23:20.053Z,1577741000.053 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-12-30T21:23:24.446Z,1577741004.446 [NAL9602](INFO): Not Powering down - fast GPS
2019-12-30T21:28:20.621Z,1577741300.621 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-12-30T21:28:20.621Z,1577741300.621 [Default:CheckIn:C.Wait] Stopped
2019-12-30T21:28:20.621Z,1577741300.621 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-12-30T21:28:20.621Z,1577741300.621 [Default:CheckIn:D] Running Loop=1
2019-12-30T21:28:21.014Z,1577741301.014 [Default:CheckIn:D] Stopped
2019-12-30T21:28:21.014Z,1577741301.014 [Default:CheckIn:E] Running Loop=1
2019-12-30T21:28:21.419Z,1577741301.419 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 89.723063 min 
2019-12-30T21:28:21.419Z,1577741301.419 [Default:CheckIn:E] Stopped
2019-12-30T21:28:21.419Z,1577741301.419 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-12-30T21:28:21.419Z,1577741301.419 [Default:CheckIn] Stopped
2019-12-30T21:28:21.419Z,1577741301.419 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-12-30T21:28:21.419Z,1577741301.419 [Default:CheckIn](INFO): Running loop #10
2019-12-30T21:28:21.420Z,1577741301.420 [Default:CheckIn] Running Loop=10
2019-12-30T21:28:21.420Z,1577741301.420 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-12-30T21:28:21.420Z,1577741301.420 [Default:CheckIn:Read_GPS] Running Loop=1
2019-12-30T21:28:22.000Z,1577741303.000 [NAL9602](FAULT): GPS failed to acquire within timeout.
2019-12-30T21:28:22.000Z,1577741303.000 [NAL9602] Data Fault, FailCount= 4
2019-12-30T21:28:22.000Z,1577741303.000 [NAL9602](ERROR): Data Fault
2019-12-30T21:28:23.069Z,1577741303.069 [CBIT](ERROR): Data Fault in component: NAL9602
2019-12-30T21:28:23.410Z,1577741303.410 [NAL9602](INFO): Powering down
2019-12-30T21:28:24.250Z,1577741304.250 [CBIT](INFO): Clearing failed state for component NAL9602
2019-12-30T21:28:24.250Z,1577741304.250 [NAL9602] No Fault, FailCount= 4
2019-12-30T21:28:53.706Z,1577741333.706 [NAL9602](INFO): Powering up NAL9602
2019-12-30T21:29:04.618Z,1577741344.618 [NAL9602](INFO): NAL9602 initialized
2019-12-30T21:31:45.050Z,1577741505.050 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2019-12-30T21:31:45.053Z,1577741505.053 [BPC1](INFO): Received data from all battery sticks.
2019-12-30T21:33:21.601Z,1577741601.601 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-12-30T21:28:21.4Z
2019-12-30T21:33:21.601Z,1577741601.601 [Default:CheckIn:Read_GPS] Stopped
2019-12-30T21:33:21.602Z,1577741601.602 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-12-30T21:33:29.292Z,1577741609.292 [DataOverHttps](INFO): Sending 45 bytes from file Logs/20191230T190856/Courier0037.lzma
2019-12-30T21:33:31.298Z,1577741611.298 [DataOverHttps](INFO): Moved sent file to Logs/20191230T190856/Courier0037.lzma.bak
2019-12-30T21:33:31.298Z,1577741611.298 [DataOverHttps](INFO): SBD MOMSN=12183236
2019-12-30T21:33:48.533Z,1577741628.533 [DataOverHttps](INFO): Sending 215 bytes from file Logs/20191230T190856/Express0038.lzma
2019-12-30T21:33:50.538Z,1577741630.538 [DataOverHttps](INFO): Moved sent file to Logs/20191230T190856/Express0038.lzma.bak
2019-12-30T21:33:50.539Z,1577741630.539 [DataOverHttps](INFO): SBD MOMSN=12183238
2019-12-30T21:33:51.920Z,1577741631.920 [Default:CheckIn:Read_Iridium] Stopped
2019-12-30T21:33:51.920Z,1577741631.920 [Default:CheckIn:C.Wait] Running Loop=1
2019-12-30T21:33:51.920Z,1577741631.920 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-12-30T21:34:08.030Z,1577741648.030 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-12-30T21:34:38.726Z,1577741678.726 [NAL9602](INFO): Not Powering down - fast GPS
2019-12-30T21:38:52.474Z,1577741932.474 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-12-30T21:38:52.474Z,1577741932.474 [Default:CheckIn:C.Wait] Stopped
2019-12-30T21:38:52.474Z,1577741932.474 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-12-30T21:38:52.475Z,1577741932.475 [Default:CheckIn:D] Running Loop=1
2019-12-30T21:38:52.863Z,1577741932.863 [Default:CheckIn:D] Stopped
2019-12-30T21:38:52.863Z,1577741932.863 [Default:CheckIn:E] Running Loop=1
2019-12-30T21:38:53.281Z,1577741933.281 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 100.253882 min 
2019-12-30T21:38:53.281Z,1577741933.281 [Default:CheckIn:E] Stopped
2019-12-30T21:38:53.282Z,1577741933.282 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-12-30T21:38:53.282Z,1577741933.282 [Default:CheckIn] Stopped
2019-12-30T21:38:53.282Z,1577741933.282 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-12-30T21:38:53.282Z,1577741933.282 [Default:CheckIn](INFO): Running loop #11
2019-12-30T21:38:53.282Z,1577741933.282 [Default:CheckIn] Running Loop=11
2019-12-30T21:38:53.282Z,1577741933.282 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-12-30T21:38:53.282Z,1577741933.282 [Default:CheckIn:Read_GPS] Running Loop=1
2019-12-30T21:43:53.462Z,1577742233.462 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-12-30T21:38:53.3Z
2019-12-30T21:43:53.462Z,1577742233.462 [Default:CheckIn:Read_GPS] Stopped
2019-12-30T21:43:53.462Z,1577742233.462 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-12-30T21:43:57.066Z,1577742237.066 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-12-30T21:44:00.296Z,1577742240.296 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20191230T190856/Courier0040.lzma
2019-12-30T21:44:02.302Z,1577742242.302 [DataOverHttps](INFO): Moved sent file to Logs/20191230T190856/Courier0040.lzma.bak
2019-12-30T21:44:02.303Z,1577742242.303 [DataOverHttps](INFO): SBD MOMSN=12183243
2019-12-30T21:44:19.389Z,1577742259.389 [DataOverHttps](INFO): Sending 197 bytes from file Logs/20191230T190856/Express0041.lzma
2019-12-30T21:44:21.395Z,1577742261.395 [DataOverHttps](INFO): Moved sent file to Logs/20191230T190856/Express0041.lzma.bak
2019-12-30T21:44:21.395Z,1577742261.395 [DataOverHttps](INFO): SBD MOMSN=12183245
2019-12-30T21:44:22.529Z,1577742262.529 [Default:CheckIn:Read_Iridium] Stopped
2019-12-30T21:44:22.529Z,1577742262.529 [Default:CheckIn:C.Wait] Running Loop=1
2019-12-30T21:44:22.529Z,1577742262.529 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-12-30T21:44:27.764Z,1577742267.764 [NAL9602](INFO): Not Powering down - fast GPS
2019-12-30T21:49:23.121Z,1577742563.121 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-12-30T21:49:23.121Z,1577742563.121 [Default:CheckIn:C.Wait] Stopped
2019-12-30T21:49:23.121Z,1577742563.121 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-12-30T21:49:23.121Z,1577742563.121 [Default:CheckIn:D] Running Loop=1
2019-12-30T21:49:23.522Z,1577742563.522 [Default:CheckIn:D] Stopped
2019-12-30T21:49:23.522Z,1577742563.522 [Default:CheckIn:E] Running Loop=1
2019-12-30T21:49:23.913Z,1577742563.913 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 110.764876 min 
2019-12-30T21:49:23.913Z,1577742563.913 [Default:CheckIn:E] Stopped
2019-12-30T21:49:23.913Z,1577742563.913 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-12-30T21:49:23.913Z,1577742563.913 [Default:CheckIn] Stopped
2019-12-30T21:49:23.913Z,1577742563.913 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-12-30T21:49:23.914Z,1577742563.914 [Default:CheckIn](INFO): Running loop #12
2019-12-30T21:49:23.914Z,1577742563.914 [Default:CheckIn] Running Loop=12
2019-12-30T21:49:23.914Z,1577742563.914 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-12-30T21:49:23.914Z,1577742563.914 [Default:CheckIn:Read_GPS] Running Loop=1
2019-12-30T21:49:25.504Z,1577742565.504 [NAL9602](FAULT): GPS failed to acquire within timeout.
2019-12-30T21:49:25.504Z,1577742565.504 [NAL9602] Data Fault, FailCount= 5
2019-12-30T21:49:25.504Z,1577742565.504 [NAL9602](ERROR): Data Fault
2019-12-30T21:49:25.536Z,1577742565.536 [CBIT](ERROR): Data Fault in component: NAL9602
2019-12-30T21:49:25.553Z,1577742565.553 [CBIT](CRITICAL): Data Fault in component: NAL9602
2019-12-30T21:49:25.914Z,1577742565.914 [NAL9602](INFO): Powering down
2019-12-30T21:49:25.945Z,1577742565.945 [CommandLine](FAULT): Scheduling is paused
2019-12-30T21:49:25.945Z,1577742565.945 [CBIT](INFO): Critical error at 20191230T214925
2019-12-30T21:49:25.946Z,1577742565.946 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2019-12-30T21:51:25.534Z,1577742685.534 [CBIT](INFO): Clearing failed state for component NAL9602
2019-12-30T21:51:25.534Z,1577742685.534 [NAL9602] No Fault, FailCount= 5
2019-12-30T21:51:25.902Z,1577742685.902 [NAL9602](INFO): Powering up NAL9602
2019-12-30T21:51:36.813Z,1577742696.813 [NAL9602](INFO): NAL9602 initialized
2019-12-30T21:54:24.129Z,1577742864.129 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-12-30T21:49:23.9Z
2019-12-30T21:54:24.129Z,1577742864.129 [Default:CheckIn:Read_GPS] Stopped
2019-12-30T21:54:24.129Z,1577742864.129 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-12-30T21:54:31.860Z,1577742871.860 [DataOverHttps](INFO): Sending 93 bytes from file Logs/20191230T190856/Courier0043.lzma
2019-12-30T21:54:33.866Z,1577742873.866 [DataOverHttps](INFO): Moved sent file to Logs/20191230T190856/Courier0043.lzma.bak
2019-12-30T21:54:33.867Z,1577742873.867 [DataOverHttps](INFO): SBD MOMSN=12183249
2019-12-30T21:54:54.529Z,1577742894.529 [DataOverHttps](INFO): Sending 238 bytes from file Logs/20191230T190856/Express0044.lzma
2019-12-30T21:54:56.534Z,1577742896.534 [DataOverHttps](INFO): Moved sent file to Logs/20191230T190856/Express0044.lzma.bak
2019-12-30T21:54:56.535Z,1577742896.535 [DataOverHttps](INFO): SBD MOMSN=12183252
2019-12-30T21:54:58.066Z,1577742898.066 [Default:CheckIn:Read_Iridium] Stopped
2019-12-30T21:54:58.066Z,1577742898.066 [Default:CheckIn:C.Wait] Running Loop=1
2019-12-30T21:54:58.066Z,1577742898.066 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-12-30T21:56:40.235Z,1577743000.235 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-12-30T21:57:10.931Z,1577743030.931 [NAL9602](INFO): Not Powering down - fast GPS
2019-12-30T21:59:58.625Z,1577743198.625 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-12-30T21:59:58.625Z,1577743198.625 [Default:CheckIn:C.Wait] Stopped
2019-12-30T21:59:58.625Z,1577743198.625 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-12-30T21:59:58.626Z,1577743198.626 [Default:CheckIn:D] Running Loop=1
2019-12-30T21:59:59.037Z,1577743199.037 [Default:CheckIn:D] Stopped
2019-12-30T21:59:59.037Z,1577743199.037 [Default:CheckIn:E] Running Loop=1
2019-12-30T21:59:59.440Z,1577743199.440 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 121.356787 min 
2019-12-30T21:59:59.440Z,1577743199.440 [Default:CheckIn:E] Stopped
2019-12-30T21:59:59.440Z,1577743199.440 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-12-30T21:59:59.440Z,1577743199.440 [Default:CheckIn] Stopped
2019-12-30T21:59:59.440Z,1577743199.440 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-12-30T21:59:59.440Z,1577743199.440 [Default:CheckIn](INFO): Running loop #13
2019-12-30T21:59:59.440Z,1577743199.440 [Default:CheckIn] Running Loop=13
2019-12-30T21:59:59.441Z,1577743199.441 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-12-30T21:59:59.441Z,1577743199.441 [Default:CheckIn:Read_GPS] Running Loop=1
2019-12-30T22:04:59.633Z,1577743499.633 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-12-30T21:59:59.4Z
2019-12-30T22:04:59.633Z,1577743499.633 [Default:CheckIn:Read_GPS] Stopped
2019-12-30T22:04:59.633Z,1577743499.633 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-12-30T22:05:03.238Z,1577743503.238 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-12-30T22:05:06.624Z,1577743506.624 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20191230T190856/Courier0046.lzma
2019-12-30T22:05:08.626Z,1577743508.626 [DataOverHttps](INFO): Moved sent file to Logs/20191230T190856/Courier0046.lzma.bak
2019-12-30T22:05:08.627Z,1577743508.627 [DataOverHttps](INFO): SBD MOMSN=12183258
2019-12-30T22:05:25.745Z,1577743525.745 [DataOverHttps](INFO): Sending 199 bytes from file Logs/20191230T190856/Express0047.lzma
2019-12-30T22:05:27.750Z,1577743527.750 [DataOverHttps](INFO): Moved sent file to Logs/20191230T190856/Express0047.lzma.bak
2019-12-30T22:05:27.751Z,1577743527.751 [DataOverHttps](INFO): SBD MOMSN=12183260
2019-12-30T22:05:29.129Z,1577743529.129 [Default:CheckIn:Read_Iridium] Stopped
2019-12-30T22:05:29.129Z,1577743529.129 [Default:CheckIn:C.Wait] Running Loop=1
2019-12-30T22:05:29.129Z,1577743529.129 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-12-30T22:05:33.942Z,1577743533.942 [NAL9602](INFO): Not Powering down - fast GPS
2019-12-30T22:10:29.701Z,1577743829.701 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-12-30T22:10:29.701Z,1577743829.701 [Default:CheckIn:C.Wait] Stopped
2019-12-30T22:10:29.701Z,1577743829.701 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-12-30T22:10:29.701Z,1577743829.701 [Default:CheckIn:D] Running Loop=1
2019-12-30T22:10:30.117Z,1577743830.117 [Default:CheckIn:D] Stopped
2019-12-30T22:10:30.117Z,1577743830.117 [Default:CheckIn:E] Running Loop=1
2019-12-30T22:10:30.524Z,1577743830.524 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 131.874788 min 
2019-12-30T22:10:30.524Z,1577743830.524 [Default:CheckIn:E] Stopped
2019-12-30T22:10:30.524Z,1577743830.524 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-12-30T22:10:30.524Z,1577743830.524 [Default:CheckIn] Stopped
2019-12-30T22:10:30.524Z,1577743830.524 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-12-30T22:10:30.524Z,1577743830.524 [Default:CheckIn](INFO): Running loop #14
2019-12-30T22:10:30.524Z,1577743830.524 [Default:CheckIn] Running Loop=14
2019-12-30T22:10:30.524Z,1577743830.524 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-12-30T22:10:30.525Z,1577743830.525 [Default:CheckIn:Read_GPS] Running Loop=1
2019-12-30T22:10:32.100Z,1577743832.100 [NAL9602](FAULT): GPS failed to acquire within timeout.
2019-12-30T22:10:32.100Z,1577743832.100 [NAL9602] Data Fault, FailCount= 1
2019-12-30T22:10:32.100Z,1577743832.100 [NAL9602](ERROR): Data Fault
2019-12-30T22:10:32.157Z,1577743832.157 [CBIT](ERROR): Data Fault in component: NAL9602
2019-12-30T22:10:32.506Z,1577743832.506 [NAL9602](INFO): Powering down
2019-12-30T22:10:33.351Z,1577743833.351 [CBIT](INFO): Clearing failed state for component NAL9602
2019-12-30T22:10:33.351Z,1577743833.351 [NAL9602] No Fault, FailCount= 1
2019-12-30T22:11:02.813Z,1577743862.813 [NAL9602](INFO): Powering up NAL9602
2019-12-30T22:11:13.718Z,1577743873.718 [NAL9602](INFO): NAL9602 initialized
2019-12-30T22:15:30.693Z,1577744130.693 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-12-30T22:10:30.5Z
2019-12-30T22:15:30.694Z,1577744130.694 [Default:CheckIn:Read_GPS] Stopped
2019-12-30T22:15:30.694Z,1577744130.694 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-12-30T22:15:38.748Z,1577744138.748 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20191230T190856/Courier0049.lzma
2019-12-30T22:15:40.750Z,1577744140.750 [DataOverHttps](INFO): Moved sent file to Logs/20191230T190856/Courier0049.lzma.bak
2019-12-30T22:15:40.751Z,1577744140.751 [DataOverHttps](INFO): SBD MOMSN=12183264
2019-12-30T22:15:57.857Z,1577744157.857 [DataOverHttps](INFO): Sending 218 bytes from file Logs/20191230T190856/Express0050.lzma
2019-12-30T22:15:59.862Z,1577744159.862 [DataOverHttps](INFO): Moved sent file to Logs/20191230T190856/Express0050.lzma.bak
2019-12-30T22:15:59.863Z,1577744159.863 [DataOverHttps](INFO): SBD MOMSN=12183266
2019-12-30T22:16:00.982Z,1577744160.982 [Default:CheckIn:Read_Iridium] Stopped
2019-12-30T22:16:00.982Z,1577744160.982 [Default:CheckIn:C.Wait] Running Loop=1
2019-12-30T22:16:00.982Z,1577744160.982 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-12-30T22:16:17.126Z,1577744177.126 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-12-30T22:16:47.819Z,1577744207.819 [NAL9602](INFO): Not Powering down - fast GPS
2019-12-30T22:17:57.872Z,1577744277.872 [CommandLine](IMPORTANT): got command show variable limitFwd
2019-12-30T22:17:57.918Z,1577744277.918 [CommandLine](IMPORTANT): VerticalControl.massPositionLimitFwd (millimeter)
2019-12-30T22:18:03.083Z,1577744283.083 [CommandLine](IMPORTANT): got command get VerticalControl.massPositionLimitFwd
2019-12-30T22:18:03.084Z,1577744283.084 [CommandLine](IMPORTANT): VerticalControl.massPositionLimitFwd 25.000000 mm
2019-12-30T22:18:06.393Z,1577744286.393 [CommandLine](IMPORTANT): got command get VerticalControl.massPositionLimitAft
2019-12-30T22:18:06.393Z,1577744286.393 [CommandLine](IMPORTANT): VerticalControl.massPositionLimitAft -35.000000 mm
2019-12-30T22:18:52.713Z,1577744332.713 [CommandLine](IMPORTANT): got command get platform_mass_position
2019-12-30T22:18:52.714Z,1577744332.714 [CommandLine](IMPORTANT): platform_mass_position -0.008999 m
2019-12-30T22:18:56.647Z,1577744336.647 [CommandLine](IMPORTANT): got command get platform_mass_position millimeter
2019-12-30T22:18:56.648Z,1577744336.648 [CommandLine](IMPORTANT): platform_mass_position -8.998872 mm
2019-12-30T22:19:10.793Z,1577744350.793 [CommandLine](IMPORTANT): got command configSet VerticalControl.massDefault -5.000000 millimeter persist
2019-12-30T22:19:15.815Z,1577744355.815 [CommandLine](IMPORTANT): got command get platform_mass_position millimeter
2019-12-30T22:19:15.816Z,1577744355.816 [CommandLine](IMPORTANT): platform_mass_position -7.369235 mm
2019-12-30T22:19:19.458Z,1577744359.458 [CommandLine](IMPORTANT): got command get platform_mass_position millimeter
2019-12-30T22:19:19.459Z,1577744359.459 [CommandLine](IMPORTANT): platform_mass_position -5.000270 mm
2019-12-30T22:19:34.602Z,1577744374.602 [CommandLine](IMPORTANT): got command maintain control VerticalControl.buoyancyAction 300.000000 cubic_centimeter
2019-12-30T22:19:34.603Z,1577744374.603 [ComponentRegistry](DEBUG): SyncComponent "Maintain_VerticalControl.buoyancyAction" handled in the control thread.
2019-12-30T22:19:34.823Z,1577744374.823 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,NAL9602,Onboard,BPC1,CANONSampler,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,Maintain_VerticalControl.buoyancyAction,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2019-12-30T22:19:42.741Z,1577744382.741 [CommandLine](IMPORTANT): got command report mod platform_buoyancy_position
2019-12-30T22:19:42.951Z,1577744382.951 [Reporter](INFO): platform_buoyancy_position 917.930420 cc
2019-12-30T22:19:43.351Z,1577744383.351 [Reporter](INFO): platform_buoyancy_position 911.484070 cc
2019-12-30T22:19:43.727Z,1577744383.727 [Reporter](INFO): platform_buoyancy_position 907.052124 cc
2019-12-30T22:19:44.153Z,1577744384.153 [Reporter](INFO): platform_buoyancy_position 900.740051 cc
2019-12-30T22:19:44.562Z,1577744384.562 [Reporter](INFO): platform_buoyancy_position 896.308167 cc
2019-12-30T22:19:44.960Z,1577744384.960 [Reporter](INFO): platform_buoyancy_position 889.996033 cc
2019-12-30T22:19:45.358Z,1577744385.358 [Reporter](INFO): platform_buoyancy_position 885.564148 cc
2019-12-30T22:19:45.755Z,1577744385.755 [Reporter](INFO): platform_buoyancy_position 880.729370 cc
2019-12-30T22:19:46.170Z,1577744386.170 [Reporter](INFO): platform_buoyancy_position 874.954468 cc
2019-12-30T22:19:46.576Z,1577744386.576 [Reporter](INFO): platform_buoyancy_position 870.522522 cc
2019-12-30T22:19:46.970Z,1577744386.970 [Reporter](INFO): platform_buoyancy_position 865.687744 cc
2019-12-30T22:19:47.371Z,1577744387.371 [Reporter](INFO): platform_buoyancy_position 859.912842 cc
2019-12-30T22:19:47.799Z,1577744387.799 [Reporter](INFO): platform_buoyancy_position 855.212341 cc
2019-12-30T22:19:48.199Z,1577744388.199 [Reporter](INFO): platform_buoyancy_position 849.034546 cc
2019-12-30T22:19:48.574Z,1577744388.574 [Reporter](INFO): platform_buoyancy_position 844.602661 cc
2019-12-30T22:19:48.994Z,1577744388.994 [Reporter](INFO): platform_buoyancy_position 838.290527 cc
2019-12-30T22:19:49.399Z,1577744389.399 [Reporter](INFO): platform_buoyancy_position 833.321472 cc
2019-12-30T22:19:49.804Z,1577744389.804 [Reporter](INFO): platform_buoyancy_position 827.680847 cc
2019-12-30T22:19:50.195Z,1577744390.195 [Reporter](INFO): platform_buoyancy_position 823.383240 cc
2019-12-30T22:19:50.607Z,1577744390.607 [Reporter](INFO): platform_buoyancy_position 816.802551 cc
2019-12-30T22:19:51.018Z,1577744391.018 [Reporter](INFO): platform_buoyancy_position 812.370667 cc
2019-12-30T22:19:51.431Z,1577744391.431 [Reporter](INFO): platform_buoyancy_position 806.058533 cc
2019-12-30T22:19:51.807Z,1577744391.807 [Reporter](INFO): platform_buoyancy_position 801.760925 cc
2019-12-30T22:19:52.223Z,1577744392.223 [Reporter](INFO): platform_buoyancy_position 795.314514 cc
2019-12-30T22:19:52.638Z,1577744392.638 [Reporter](INFO): platform_buoyancy_position 790.882629 cc
2019-12-30T22:19:53.036Z,1577744393.036 [Reporter](INFO): platform_buoyancy_position 784.704834 cc
2019-12-30T22:19:53.423Z,1577744393.423 [Reporter](INFO): platform_buoyancy_position 780.272949 cc
2019-12-30T22:19:53.849Z,1577744393.849 [Reporter](INFO): platform_buoyancy_position 774.095154 cc
2019-12-30T22:19:54.247Z,1577744394.247 [Reporter](INFO): platform_buoyancy_position 769.528931 cc
2019-12-30T22:19:54.654Z,1577744394.654 [Reporter](INFO): platform_buoyancy_position 763.082520 cc
2019-12-30T22:19:55.046Z,1577744395.046 [Reporter](INFO): platform_buoyancy_position 758.784912 cc
2019-12-30T22:19:55.455Z,1577744395.455 [Reporter](INFO): platform_buoyancy_position 754.084412 cc
2019-12-30T22:19:55.850Z,1577744395.850 [Reporter](INFO): platform_buoyancy_position 748.175232 cc
2019-12-30T22:19:56.243Z,1577744396.243 [Reporter](INFO): platform_buoyancy_position 743.877625 cc
2019-12-30T22:19:56.658Z,1577744396.658 [Reporter](INFO): platform_buoyancy_position 737.431213 cc
2019-12-30T22:19:57.067Z,1577744397.067 [Reporter](INFO): platform_buoyancy_position 732.865051 cc
2019-12-30T22:19:57.495Z,1577744397.495 [Reporter](INFO): platform_buoyancy_position 727.493042 cc
2019-12-30T22:19:57.895Z,1577744397.895 [Reporter](INFO): platform_buoyancy_position 721.180908 cc
2019-12-30T22:19:58.307Z,1577744398.307 [Reporter](INFO): platform_buoyancy_position 715.943237 cc
2019-12-30T22:19:58.694Z,1577744398.694 [Reporter](INFO): platform_buoyancy_position 711.645630 cc
2019-12-30T22:19:59.095Z,1577744399.095 [Reporter](INFO): platform_buoyancy_position 705.199219 cc
2019-12-30T22:19:59.495Z,1577744399.495 [Reporter](INFO): platform_buoyancy_position 700.767334 cc
2019-12-30T22:19:59.902Z,1577744399.902 [Reporter](INFO): platform_buoyancy_position 695.529602 cc
2019-12-30T22:20:00.303Z,1577744400.303 [Reporter](INFO): platform_buoyancy_position 690.023315 cc
2019-12-30T22:20:00.718Z,1577744400.718 [Reporter](INFO): platform_buoyancy_position 684.651306 cc
2019-12-30T22:20:01.126Z,1577744401.126 [Reporter](INFO): platform_buoyancy_position 679.279358 cc
2019-12-30T22:20:01.502Z,1577744401.502 [Reporter](INFO): platform_buoyancy_position 674.981750 cc
2019-12-30T22:20:01.918Z,1577744401.918 [Reporter](INFO): platform_buoyancy_position 668.535339 cc
2019-12-30T22:20:02.342Z,1577744402.342 [Reporter](INFO): platform_buoyancy_position 664.237732 cc
2019-12-30T22:20:02.743Z,1577744402.743 [Reporter](INFO): platform_buoyancy_position 657.791321 cc
2019-12-30T22:20:03.127Z,1577744403.127 [Reporter](INFO): platform_buoyancy_position 653.493713 cc
2019-12-30T22:20:03.550Z,1577744403.550 [Reporter](INFO): platform_buoyancy_position 647.047302 cc
2019-12-30T22:20:03.954Z,1577744403.954 [Reporter](INFO): platform_buoyancy_position 642.749756 cc
2019-12-30T22:20:04.331Z,1577744404.331 [Reporter](INFO): platform_buoyancy_position 636.437622 cc
2019-12-30T22:20:04.743Z,1577744404.743 [Reporter](INFO): platform_buoyancy_position 632.140015 cc
2019-12-30T22:20:05.151Z,1577744405.151 [Reporter](INFO): platform_buoyancy_position 625.693604 cc
2019-12-30T22:20:05.552Z,1577744405.552 [Reporter](INFO): platform_buoyancy_position 621.261719 cc
2019-12-30T22:20:05.939Z,1577744405.939 [Reporter](INFO): platform_buoyancy_position 615.621155 cc
2019-12-30T22:20:06.359Z,1577744406.359 [Reporter](INFO): platform_buoyancy_position 610.517700 cc
2019-12-30T22:20:06.767Z,1577744406.767 [Reporter](INFO): platform_buoyancy_position 604.742798 cc
2019-12-30T22:20:07.191Z,1577744407.191 [Reporter](INFO): platform_buoyancy_position 599.773743 cc
2019-12-30T22:20:07.615Z,1577744407.615 [Reporter](INFO): platform_buoyancy_position 593.461609 cc
2019-12-30T22:20:07.983Z,1577744407.983 [Reporter](INFO): platform_buoyancy_position 589.164001 cc
2019-12-30T22:20:08.435Z,1577744408.435 [Reporter](INFO): platform_buoyancy_position 584.732117 cc
2019-12-30T22:20:08.817Z,1577744408.817 [Reporter](INFO): platform_buoyancy_position 578.285706 cc
2019-12-30T22:20:09.215Z,1577744409.215 [Reporter](INFO): platform_buoyancy_position 573.853821 cc
2019-12-30T22:20:09.641Z,1577744409.641 [Reporter](INFO): platform_buoyancy_position 567.541748 cc
2019-12-30T22:20:10.023Z,1577744410.023 [Reporter](INFO): platform_buoyancy_position 563.244141 cc
2019-12-30T22:20:10.415Z,1577744410.415 [Reporter](INFO): platform_buoyancy_position 556.932007 cc
2019-12-30T22:20:10.818Z,1577744410.818 [Reporter](INFO): platform_buoyancy_position 552.500122 cc
2019-12-30T22:20:11.213Z,1577744411.213 [Reporter](INFO): platform_buoyancy_position 546.188049 cc
2019-12-30T22:20:11.615Z,1577744411.615 [Reporter](INFO): platform_buoyancy_position 541.756104 cc
2019-12-30T22:20:12.011Z,1577744412.011 [Reporter](INFO): platform_buoyancy_position 535.444031 cc
2019-12-30T22:20:12.426Z,1577744412.426 [Reporter](INFO): platform_buoyancy_position 531.146423 cc
2019-12-30T22:20:12.834Z,1577744412.834 [Reporter](INFO): platform_buoyancy_position 524.565735 cc
2019-12-30T22:20:13.258Z,1577744413.258 [Reporter](INFO): platform_buoyancy_position 520.268127 cc
2019-12-30T22:20:13.626Z,1577744413.626 [Reporter](INFO): platform_buoyancy_position 516.104797 cc
2019-12-30T22:20:14.043Z,1577744414.043 [Reporter](INFO): platform_buoyancy_position 509.524139 cc
2019-12-30T22:20:14.462Z,1577744414.462 [Reporter](INFO): platform_buoyancy_position 503.212036 cc
2019-12-30T22:20:14.843Z,1577744414.843 [Reporter](INFO): platform_buoyancy_position 498.914459 cc
2019-12-30T22:20:15.254Z,1577744415.254 [Reporter](INFO): platform_buoyancy_position 494.482574 cc
2019-12-30T22:20:15.678Z,1577744415.678 [Reporter](INFO): platform_buoyancy_position 488.170441 cc
2019-12-30T22:20:16.051Z,1577744416.051 [Reporter](INFO): platform_buoyancy_position 483.604218 cc
2019-12-30T22:20:16.459Z,1577744416.459 [Reporter](INFO): platform_buoyancy_position 477.292145 cc
2019-12-30T22:20:16.875Z,1577744416.875 [Reporter](INFO): platform_buoyancy_position 472.994537 cc
2019-12-30T22:20:17.294Z,1577744417.294 [Reporter](INFO): platform_buoyancy_position 466.682465 cc
2019-12-30T22:20:17.667Z,1577744417.667 [Reporter](INFO): platform_buoyancy_position 462.250519 cc
2019-12-30T22:20:18.070Z,1577744418.070 [Reporter](INFO): platform_buoyancy_position 457.952972 cc
2019-12-30T22:20:18.490Z,1577744418.490 [Reporter](INFO): platform_buoyancy_position 451.775116 cc
2019-12-30T22:20:18.892Z,1577744418.892 [Reporter](INFO): platform_buoyancy_position 447.208954 cc
2019-12-30T22:20:19.298Z,1577744419.298 [Reporter](INFO): platform_buoyancy_position 442.777069 cc
2019-12-30T22:20:19.702Z,1577744419.702 [Reporter](INFO): platform_buoyancy_position 436.464935 cc
2019-12-30T22:20:20.111Z,1577744420.111 [Reporter](INFO): platform_buoyancy_position 430.287140 cc
2019-12-30T22:20:20.519Z,1577744420.519 [Reporter](INFO): platform_buoyancy_position 425.720917 cc
2019-12-30T22:20:20.891Z,1577744420.891 [Reporter](INFO): platform_buoyancy_position 419.408844 cc
2019-12-30T22:20:21.311Z,1577744421.311 [Reporter](INFO): platform_buoyancy_position 414.976959 cc
2019-12-30T22:20:21.735Z,1577744421.735 [Reporter](INFO): platform_buoyancy_position 409.470642 cc
2019-12-30T22:20:22.135Z,1577744422.135 [Reporter](INFO): platform_buoyancy_position 404.232941 cc
2019-12-30T22:20:22.510Z,1577744422.510 [Reporter](INFO): platform_buoyancy_position 399.801056 cc
2019-12-30T22:20:22.940Z,1577744422.940 [Reporter](INFO): platform_buoyancy_position 393.623230 cc
2019-12-30T22:20:23.331Z,1577744423.331 [Reporter](INFO): platform_buoyancy_position 387.579742 cc
2019-12-30T22:20:23.719Z,1577744423.719 [Reporter](INFO): platform_buoyancy_position 382.744934 cc
2019-12-30T22:20:24.150Z,1577744424.150 [Reporter](INFO): platform_buoyancy_position 376.835724 cc
2019-12-30T22:20:24.546Z,1577744424.546 [Reporter](INFO): platform_buoyancy_position 372.000946 cc
2019-12-30T22:20:24.935Z,1577744424.935 [Reporter](INFO): platform_buoyancy_position 367.434753 cc
2019-12-30T22:20:25.363Z,1577744425.363 [Reporter](INFO): platform_buoyancy_position 361.256927 cc
2019-12-30T22:20:25.759Z,1577744425.759 [Reporter](INFO): platform_buoyancy_position 356.959351 cc
2019-12-30T22:20:26.171Z,1577744426.171 [Reporter](INFO): platform_buoyancy_position 350.647247 cc
2019-12-30T22:20:26.555Z,1577744426.555 [Reporter](INFO): platform_buoyancy_position 346.215332 cc
2019-12-30T22:20:26.967Z,1577744426.967 [Reporter](INFO): platform_buoyancy_position 341.246246 cc
2019-12-30T22:20:27.371Z,1577744427.371 [Reporter](INFO): platform_buoyancy_position 335.471344 cc
2019-12-30T22:20:27.800Z,1577744427.800 [Reporter](INFO): platform_buoyancy_position 329.562134 cc
2019-12-30T22:20:28.170Z,1577744428.170 [Reporter](INFO): platform_buoyancy_position 324.861633 cc
2019-12-30T22:20:28.583Z,1577744428.583 [Reporter](INFO): platform_buoyancy_position 320.295441 cc
2019-12-30T22:20:29.002Z,1577744429.002 [Reporter](INFO): platform_buoyancy_position 314.117645 cc
2019-12-30T22:20:29.442Z,1577744429.442 [Reporter](INFO): platform_buoyancy_position 309.685730 cc
2019-12-30T22:20:37.827Z,1577744437.827 [CommandLine](IMPORTANT): got command maintain control VerticalControl.buoyancyAction 150.000000 cubic_centimeter
2019-12-30T22:20:38.710Z,1577744438.710 [Reporter](INFO): platform_buoyancy_position 303.105042 cc
2019-12-30T22:20:39.146Z,1577744439.146 [Reporter](INFO): platform_buoyancy_position 302.164948 cc
2019-12-30T22:20:39.511Z,1577744439.511 [Reporter](INFO): platform_buoyancy_position 300.821930 cc
2019-12-30T22:20:39.912Z,1577744439.912 [Reporter](INFO): platform_buoyancy_position 296.927246 cc
2019-12-30T22:20:40.338Z,1577744440.338 [Reporter](INFO): platform_buoyancy_position 292.629639 cc
2019-12-30T22:20:40.715Z,1577744440.715 [Reporter](INFO): platform_buoyancy_position 288.197723 cc
2019-12-30T22:20:41.126Z,1577744441.126 [Reporter](INFO): platform_buoyancy_position 283.900146 cc
2019-12-30T22:20:41.551Z,1577744441.551 [Reporter](INFO): platform_buoyancy_position 277.588043 cc
2019-12-30T22:20:41.919Z,1577744441.919 [Reporter](INFO): platform_buoyancy_position 273.156128 cc
2019-12-30T22:20:42.338Z,1577744442.338 [Reporter](INFO): platform_buoyancy_position 267.515533 cc
2019-12-30T22:20:42.737Z,1577744442.737 [Reporter](INFO): platform_buoyancy_position 262.546417 cc
2019-12-30T22:20:43.119Z,1577744443.119 [Reporter](INFO): platform_buoyancy_position 257.711639 cc
2019-12-30T22:20:43.545Z,1577744443.545 [Reporter](INFO): platform_buoyancy_position 251.668121 cc
2019-12-30T22:20:43.940Z,1577744443.940 [Reporter](INFO): platform_buoyancy_position 247.370544 cc
2019-12-30T22:20:44.343Z,1577744444.343 [Reporter](INFO): platform_buoyancy_position 241.058441 cc
2019-12-30T22:20:44.746Z,1577744444.746 [Reporter](INFO): platform_buoyancy_position 236.626526 cc
2019-12-30T22:20:45.143Z,1577744445.143 [Reporter](INFO): platform_buoyancy_position 230.314423 cc
2019-12-30T22:20:45.555Z,1577744445.555 [Reporter](INFO): platform_buoyancy_position 225.345337 cc
2019-12-30T22:20:45.970Z,1577744445.970 [Reporter](INFO): platform_buoyancy_position 219.436127 cc
2019-12-30T22:20:46.354Z,1577744446.354 [Reporter](INFO): platform_buoyancy_position 215.272827 cc
2019-12-30T22:20:46.774Z,1577744446.774 [Reporter](INFO): platform_buoyancy_position 208.826416 cc
2019-12-30T22:20:47.198Z,1577744447.198 [Reporter](INFO): platform_buoyancy_position 204.394531 cc
2019-12-30T22:20:47.567Z,1577744447.567 [Reporter](INFO): platform_buoyancy_position 200.096924 cc
2019-12-30T22:20:47.975Z,1577744447.975 [Reporter](INFO): platform_buoyancy_position 193.784821 cc
2019-12-30T22:20:48.391Z,1577744448.391 [Reporter](INFO): platform_buoyancy_position 188.815735 cc
2019-12-30T22:20:48.775Z,1577744448.775 [Reporter](INFO): platform_buoyancy_position 183.040833 cc
2019-12-30T22:20:49.175Z,1577744449.175 [Reporter](INFO): platform_buoyancy_position 178.608917 cc
2019-12-30T22:20:49.607Z,1577744449.607 [Reporter](INFO): platform_buoyancy_position 172.296814 cc
2019-12-30T22:20:50.059Z,1577744450.059 [Reporter](INFO): platform_buoyancy_position 165.850433 cc
2019-12-30T22:20:54.063Z,1577744454.063 [Reporter](INFO): platform_buoyancy_position 150.808807 cc
2019-12-30T22:21:01.661Z,1577744461.661 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-12-30T22:21:01.661Z,1577744461.661 [Default:CheckIn:C.Wait] Stopped
2019-12-30T22:21:01.661Z,1577744461.661 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-12-30T22:21:01.662Z,1577744461.662 [Default:CheckIn:D] Running Loop=1
2019-12-30T22:21:02.072Z,1577744462.072 [Default:CheckIn:D] Stopped
2019-12-30T22:21:02.072Z,1577744462.072 [Default:CheckIn:E] Running Loop=1
2019-12-30T22:21:02.480Z,1577744462.480 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 142.407373 min 
2019-12-30T22:21:02.480Z,1577744462.480 [Default:CheckIn:E] Stopped
2019-12-30T22:21:02.481Z,1577744462.481 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-12-30T22:21:02.481Z,1577744462.481 [Default:CheckIn] Stopped
2019-12-30T22:21:02.481Z,1577744462.481 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-12-30T22:21:02.481Z,1577744462.481 [Default:CheckIn](INFO): Running loop #15
2019-12-30T22:21:02.481Z,1577744462.481 [Default:CheckIn] Running Loop=15
2019-12-30T22:21:02.481Z,1577744462.481 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-12-30T22:21:02.481Z,1577744462.481 [Default:CheckIn:Read_GPS] Running Loop=1
2019-12-30T22:21:15.396Z,1577744475.396 [CommandLine](IMPORTANT): got command maintain control VerticalControl.buoyancyAction 90.000000 cubic_centimeter
2019-12-30T22:21:16.287Z,1577744476.287 [Reporter](INFO): platform_buoyancy_position 150.674530 cc
2019-12-30T22:21:16.669Z,1577744476.669 [Reporter](INFO): platform_buoyancy_position 150.808807 cc
2019-12-30T22:21:17.063Z,1577744477.063 [Reporter](INFO): platform_buoyancy_position 150.271606 cc
2019-12-30T22:21:17.463Z,1577744477.463 [Reporter](INFO): platform_buoyancy_position 148.928619 cc
2019-12-30T22:21:17.887Z,1577744477.887 [Reporter](INFO): platform_buoyancy_position 148.525726 cc
2019-12-30T22:21:18.279Z,1577744478.279 [Reporter](INFO): platform_buoyancy_position 148.391418 cc
2019-12-30T22:21:18.671Z,1577744478.671 [Reporter](INFO): platform_buoyancy_position 146.376923 cc
2019-12-30T22:21:19.079Z,1577744479.079 [Reporter](INFO): platform_buoyancy_position 145.033905 cc
2019-12-30T22:21:19.494Z,1577744479.494 [Reporter](INFO): platform_buoyancy_position 144.228119 cc
2019-12-30T22:21:19.922Z,1577744479.922 [Reporter](INFO): platform_buoyancy_position 142.347900 cc
2019-12-30T22:21:20.287Z,1577744480.287 [Reporter](INFO): platform_buoyancy_position 142.079315 cc
2019-12-30T22:21:20.702Z,1577744480.702 [Reporter](INFO): platform_buoyancy_position 139.930511 cc
2019-12-30T22:21:21.115Z,1577744481.115 [Reporter](INFO): platform_buoyancy_position 137.916016 cc
2019-12-30T22:21:21.906Z,1577744481.906 [Reporter](INFO): platform_buoyancy_position 135.632904 cc
2019-12-30T22:21:22.319Z,1577744482.319 [Reporter](INFO): platform_buoyancy_position 134.692810 cc
2019-12-30T22:21:22.730Z,1577744482.730 [Reporter](INFO): platform_buoyancy_position 133.618408 cc
2019-12-30T22:21:23.127Z,1577744483.127 [Reporter](INFO): platform_buoyancy_position 131.469604 cc
2019-12-30T22:21:23.519Z,1577744483.519 [Reporter](INFO): platform_buoyancy_position 131.335327 cc
2019-12-30T22:21:23.931Z,1577744483.931 [Reporter](INFO): platform_buoyancy_position 129.186523 cc
2019-12-30T22:21:24.351Z,1577744484.351 [Reporter](INFO): platform_buoyancy_position 127.172028 cc
2019-12-30T22:21:25.131Z,1577744485.131 [Reporter](INFO): platform_buoyancy_position 125.023216 cc
2019-12-30T22:21:25.550Z,1577744485.550 [Reporter](INFO): platform_buoyancy_position 124.888901 cc
2019-12-30T22:21:25.967Z,1577744485.967 [Reporter](INFO): platform_buoyancy_position 122.874405 cc
2019-12-30T22:21:26.347Z,1577744486.347 [Reporter](INFO): platform_buoyancy_position 120.994209 cc
2019-12-30T22:21:26.755Z,1577744486.755 [Reporter](INFO): platform_buoyancy_position 120.725609 cc
2019-12-30T22:21:27.177Z,1577744487.177 [Reporter](INFO): platform_buoyancy_position 118.576805 cc
2019-12-30T22:21:27.577Z,1577744487.577 [Reporter](INFO): platform_buoyancy_position 117.636711 cc
2019-12-30T22:21:27.963Z,1577744487.963 [Reporter](INFO): platform_buoyancy_position 116.428017 cc
2019-12-30T22:21:28.381Z,1577744488.381 [Reporter](INFO): platform_buoyancy_position 114.144905 cc
2019-12-30T22:21:29.215Z,1577744489.215 [Reporter](INFO): platform_buoyancy_position 112.130409 cc
2019-12-30T22:21:29.575Z,1577744489.575 [Reporter](INFO): platform_buoyancy_position 109.981606 cc
2019-12-30T22:21:30.406Z,1577744490.406 [Reporter](INFO): platform_buoyancy_position 107.698509 cc
2019-12-30T22:21:30.815Z,1577744490.815 [Reporter](INFO): platform_buoyancy_position 106.221214 cc
2019-12-30T22:21:31.199Z,1577744491.199 [Reporter](INFO): platform_buoyancy_position 105.684013 cc
2019-12-30T22:21:31.603Z,1577744491.603 [Reporter](INFO): platform_buoyancy_position 103.535210 cc
2019-12-30T22:21:32.026Z,1577744492.026 [Reporter](INFO): platform_buoyancy_position 103.400917 cc
2019-12-30T22:21:32.407Z,1577744492.407 [Reporter](INFO): platform_buoyancy_position 101.252113 cc
2019-12-30T22:21:32.815Z,1577744492.815 [Reporter](INFO): platform_buoyancy_position 100.983513 cc
2019-12-30T22:21:33.230Z,1577744493.230 [Reporter](INFO): platform_buoyancy_position 99.103310 cc
2019-12-30T22:21:35.164Z,1577744495.164 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2019-12-30T22:21:35.237Z,1577744495.237 [NAL9602](FAULT): received: 
+CSQ:0

OK397, 2, 0, 0, 0

OK
2019-12-30T22:21:35.237Z,1577744495.237 [NAL9602] Data Fault, FailCount= 2
2019-12-30T22:21:35.237Z,1577744495.237 [NAL9602](ERROR): Data Fault
2019-12-30T22:21:35.458Z,1577744495.458 [CBIT](ERROR): Data Fault in component: NAL9602
2019-12-30T22:21:35.569Z,1577744495.569 [NAL9602](INFO): Powering down
2019-12-30T22:21:36.434Z,1577744496.434 [CBIT](INFO): Clearing failed state for component NAL9602
2019-12-30T22:21:36.434Z,1577744496.434 [NAL9602] No Fault, FailCount= 2
2019-12-30T22:22:04.512Z,1577744524.512 [CommandLine](IMPORTANT): got command maintain clear
2019-12-30T22:22:04.704Z,1577744524.704 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,NAL9602,Onboard,BPC1,CANONSampler,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,
2019-12-30T22:22:05.878Z,1577744525.878 [NAL9602](INFO): Powering up NAL9602
2019-12-30T22:22:09.623Z,1577744529.623 [Reporter](INFO): platform_buoyancy_position 90.508110 cc
2019-12-30T22:22:10.399Z,1577744530.399 [Reporter](INFO): platform_buoyancy_position 90.776711 cc
2019-12-30T22:22:10.844Z,1577744530.844 [Reporter](INFO): platform_buoyancy_position 94.940010 cc
2019-12-30T22:22:11.222Z,1577744531.222 [Reporter](INFO): platform_buoyancy_position 99.103310 cc
2019-12-30T22:22:11.639Z,1577744531.639 [Reporter](INFO): platform_buoyancy_position 105.549706 cc
2019-12-30T22:22:12.057Z,1577744532.057 [Reporter](INFO): platform_buoyancy_position 109.847313 cc
2019-12-30T22:22:12.426Z,1577744532.426 [Reporter](INFO): platform_buoyancy_position 114.413506 cc
2019-12-30T22:22:12.838Z,1577744532.838 [Reporter](INFO): platform_buoyancy_position 120.591316 cc
2019-12-30T22:22:13.235Z,1577744533.235 [Reporter](INFO): platform_buoyancy_position 125.023216 cc
2019-12-30T22:22:13.630Z,1577744533.630 [Reporter](INFO): platform_buoyancy_position 131.335327 cc
2019-12-30T22:22:14.043Z,1577744534.043 [Reporter](INFO): platform_buoyancy_position 135.632904 cc
2019-12-30T22:22:14.423Z,1577744534.423 [Reporter](INFO): platform_buoyancy_position 142.079315 cc
2019-12-30T22:22:14.839Z,1577744534.839 [Reporter](INFO): platform_buoyancy_position 146.376923 cc
2019-12-30T22:22:15.243Z,1577744535.243 [Reporter](INFO): platform_buoyancy_position 150.808807 cc
2019-12-30T22:22:15.655Z,1577744535.655 [Reporter](INFO): platform_buoyancy_position 157.120911 cc
2019-12-30T22:22:16.050Z,1577744536.050 [Reporter](INFO): platform_buoyancy_position 161.418518 cc
2019-12-30T22:22:16.451Z,1577744536.451 [Reporter](INFO): platform_buoyancy_position 167.864929 cc
2019-12-30T22:22:16.778Z,1577744536.778 [NAL9602](INFO): NAL9602 initialized
2019-12-30T22:22:16.859Z,1577744536.859 [Reporter](INFO): platform_buoyancy_position 172.296814 cc
2019-12-30T22:22:17.274Z,1577744537.274 [Reporter](INFO): platform_buoyancy_position 178.743225 cc
2019-12-30T22:22:17.585Z,1577744537.585 [NAL9602](FAULT): GPS failed to acquire within timeout.
2019-12-30T22:22:17.586Z,1577744537.586 [NAL9602] Data Fault, FailCount= 3
2019-12-30T22:22:17.586Z,1577744537.586 [NAL9602](ERROR): Data Fault
2019-12-30T22:22:17.642Z,1577744537.642 [CBIT](ERROR): Data Fault in component: NAL9602
2019-12-30T22:22:17.643Z,1577744537.643 [Reporter](INFO): platform_buoyancy_position 182.906525 cc
2019-12-30T22:22:17.990Z,1577744537.990 [NAL9602](INFO): Powering down
2019-12-30T22:22:18.075Z,1577744538.075 [Reporter](INFO): platform_buoyancy_position 189.352936 cc
2019-12-30T22:22:18.485Z,1577744538.485 [Reporter](INFO): platform_buoyancy_position 193.784821 cc
2019-12-30T22:22:18.854Z,1577744538.854 [CBIT](INFO): Clearing failed state for component NAL9602
2019-12-30T22:22:18.854Z,1577744538.854 [NAL9602] No Fault, FailCount= 3
2019-12-30T22:22:18.855Z,1577744538.855 [Reporter](INFO): platform_buoyancy_position 198.485321 cc
2019-12-30T22:22:19.266Z,1577744539.266 [Reporter](INFO): platform_buoyancy_position 204.528839 cc
2019-12-30T22:22:19.687Z,1577744539.687 [Reporter](INFO): platform_buoyancy_position 209.229340 cc
2019-12-30T22:22:20.079Z,1577744540.079 [Reporter](INFO): platform_buoyancy_position 215.138519 cc
2019-12-30T22:22:20.500Z,1577744540.500 [Reporter](INFO): platform_buoyancy_position 219.570435 cc
2019-12-30T22:22:20.898Z,1577744540.898 [Reporter](INFO): platform_buoyancy_position 226.016815 cc
2019-12-30T22:22:21.295Z,1577744541.295 [Reporter](INFO): platform_buoyancy_position 230.448730 cc
2019-12-30T22:22:21.702Z,1577744541.702 [Reporter](INFO): platform_buoyancy_position 236.626526 cc
2019-12-30T22:22:22.122Z,1577744542.122 [Reporter](INFO): platform_buoyancy_position 241.058441 cc
2019-12-30T22:22:22.502Z,1577744542.502 [Reporter](INFO): platform_buoyancy_position 246.699020 cc
2019-12-30T22:22:22.907Z,1577744542.907 [Reporter](INFO): platform_buoyancy_position 251.668121 cc
2019-12-30T22:22:23.336Z,1577744543.336 [Reporter](INFO): platform_buoyancy_position 256.100037 cc
2019-12-30T22:22:23.731Z,1577744543.731 [Reporter](INFO): platform_buoyancy_position 262.546417 cc
2019-12-30T22:22:24.119Z,1577744544.119 [Reporter](INFO): platform_buoyancy_position 266.844025 cc
2019-12-30T22:22:24.572Z,1577744544.572 [Reporter](INFO): platform_buoyancy_position 273.290436 cc
2019-12-30T22:22:24.940Z,1577744544.940 [Reporter](INFO): platform_buoyancy_position 277.856628 cc
2019-12-30T22:22:25.331Z,1577744545.331 [Reporter](INFO): platform_buoyancy_position 283.900146 cc
2019-12-30T22:22:25.751Z,1577744545.751 [Reporter](INFO): platform_buoyancy_position 288.332031 cc
2019-12-30T22:22:26.147Z,1577744546.147 [Reporter](INFO): platform_buoyancy_position 294.644135 cc
2019-12-30T22:22:26.543Z,1577744546.543 [Reporter](INFO): platform_buoyancy_position 299.076019 cc
2019-12-30T22:22:26.965Z,1577744546.965 [Reporter](INFO): platform_buoyancy_position 305.388123 cc
2019-12-30T22:22:27.370Z,1577744547.370 [Reporter](INFO): platform_buoyancy_position 309.820038 cc
2019-12-30T22:22:27.743Z,1577744547.743 [Reporter](INFO): platform_buoyancy_position 314.117645 cc
2019-12-30T22:22:28.169Z,1577744548.169 [Reporter](INFO): platform_buoyancy_position 319.489624 cc
2019-12-30T22:22:28.563Z,1577744548.563 [Reporter](INFO): platform_buoyancy_position 324.861633 cc
2019-12-30T22:22:28.978Z,1577744548.978 [Reporter](INFO): platform_buoyancy_position 331.173737 cc
2019-12-30T22:22:29.382Z,1577744549.382 [Reporter](INFO): platform_buoyancy_position 335.605621 cc
2019-12-30T22:22:29.770Z,1577744549.770 [Reporter](INFO): platform_buoyancy_position 341.917725 cc
2019-12-30T22:22:30.183Z,1577744550.183 [Reporter](INFO): platform_buoyancy_position 347.021149 cc
2019-12-30T22:22:30.608Z,1577744550.608 [Reporter](INFO): platform_buoyancy_position 352.661743 cc
2019-12-30T22:22:30.979Z,1577744550.979 [Reporter](INFO): platform_buoyancy_position 356.959351 cc
2019-12-30T22:22:31.391Z,1577744551.391 [Reporter](INFO): platform_buoyancy_position 363.405731 cc
2019-12-30T22:22:31.820Z,1577744551.820 [Reporter](INFO): platform_buoyancy_position 367.971924 cc
2019-12-30T22:22:32.219Z,1577744552.219 [Reporter](INFO): platform_buoyancy_position 374.149750 cc
2019-12-30T22:22:32.627Z,1577744552.627 [Reporter](INFO): platform_buoyancy_position 378.581635 cc
2019-12-30T22:22:33.014Z,1577744553.014 [Reporter](INFO): platform_buoyancy_position 384.893738 cc
2019-12-30T22:22:33.411Z,1577744553.411 [Reporter](INFO): platform_buoyancy_position 389.325653 cc
2019-12-30T22:22:33.827Z,1577744553.827 [Reporter](INFO): platform_buoyancy_position 395.637726 cc
2019-12-30T22:22:34.250Z,1577744554.250 [Reporter](INFO): platform_buoyancy_position 400.069641 cc
2019-12-30T22:22:34.626Z,1577744554.626 [Reporter](INFO): platform_buoyancy_position 405.844543 cc
2019-12-30T22:22:35.039Z,1577744555.039 [Reporter](INFO): platform_buoyancy_position 410.679352 cc
2019-12-30T22:22:35.458Z,1577744555.458 [Reporter](INFO): platform_buoyancy_position 415.379852 cc
2019-12-30T22:22:35.823Z,1577744555.823 [Reporter](INFO): platform_buoyancy_position 421.423370 cc
2019-12-30T22:22:36.239Z,1577744556.239 [Reporter](INFO): platform_buoyancy_position 425.855255 cc
2019-12-30T22:22:36.666Z,1577744556.666 [Reporter](INFO): platform_buoyancy_position 432.167328 cc
2019-12-30T22:22:37.061Z,1577744557.061 [Reporter](INFO): platform_buoyancy_position 436.464935 cc
2019-12-30T22:22:37.475Z,1577744557.475 [Reporter](INFO): platform_buoyancy_position 442.911346 cc
2019-12-30T22:22:37.867Z,1577744557.867 [Reporter](INFO): platform_buoyancy_position 447.208954 cc
2019-12-30T22:22:38.259Z,1577744558.259 [Reporter](INFO): platform_buoyancy_position 451.640839 cc
2019-12-30T22:22:38.670Z,1577744558.670 [Reporter](INFO): platform_buoyancy_position 457.952972 cc
2019-12-30T22:22:39.098Z,1577744559.098 [Reporter](INFO): platform_buoyancy_position 462.384857 cc
2019-12-30T22:22:39.470Z,1577744559.470 [Reporter](INFO): platform_buoyancy_position 468.831268 cc
2019-12-30T22:22:39.887Z,1577744559.887 [Reporter](INFO): platform_buoyancy_position 473.128876 cc
2019-12-30T22:22:40.330Z,1577744560.330 [Reporter](INFO): platform_buoyancy_position 479.575226 cc
2019-12-30T22:22:40.719Z,1577744560.719 [Reporter](INFO): platform_buoyancy_position 485.887360 cc
2019-12-30T22:22:41.123Z,1577744561.123 [Reporter](INFO): platform_buoyancy_position 490.184998 cc
2019-12-30T22:22:41.527Z,1577744561.527 [Reporter](INFO): platform_buoyancy_position 495.019714 cc
2019-12-30T22:22:41.931Z,1577744561.931 [Reporter](INFO): platform_buoyancy_position 500.928894 cc
2019-12-30T22:22:42.346Z,1577744562.346 [Reporter](INFO): platform_buoyancy_position 507.241058 cc
2019-12-30T22:22:42.742Z,1577744562.742 [Reporter](INFO): platform_buoyancy_position 511.941559 cc
2019-12-30T22:22:43.130Z,1577744563.130 [Reporter](INFO): platform_buoyancy_position 516.104797 cc
2019-12-30T22:22:43.566Z,1577744563.566 [Reporter](INFO): platform_buoyancy_position 522.416931 cc
2019-12-30T22:22:43.950Z,1577744563.950 [Reporter](INFO): platform_buoyancy_position 526.848816 cc
2019-12-30T22:22:44.331Z,1577744564.331 [Reporter](INFO): platform_buoyancy_position 533.160950 cc
2019-12-30T22:22:44.746Z,1577744564.746 [Reporter](INFO): platform_buoyancy_position 537.592834 cc
2019-12-30T22:22:45.134Z,1577744565.134 [Reporter](INFO): platform_buoyancy_position 543.367737 cc
2019-12-30T22:22:45.531Z,1577744565.531 [Reporter](INFO): platform_buoyancy_position 548.202515 cc
2019-12-30T22:22:45.958Z,1577744565.958 [Reporter](INFO): platform_buoyancy_position 554.783203 cc
2019-12-30T22:22:46.346Z,1577744566.346 [Reporter](INFO): platform_buoyancy_position 559.080811 cc
2019-12-30T22:22:46.747Z,1577744566.747 [Reporter](INFO): platform_buoyancy_position 563.378418 cc
2019-12-30T22:22:47.202Z,1577744567.202 [Reporter](INFO): platform_buoyancy_position 569.824829 cc
2019-12-30T22:22:47.571Z,1577744567.571 [Reporter](INFO): platform_buoyancy_position 575.196838 cc
2019-12-30T22:22:47.958Z,1577744567.958 [Reporter](INFO): platform_buoyancy_position 580.434509 cc
2019-12-30T22:22:48.289Z,1577744568.289 [NAL9602](INFO): Powering up NAL9602
2019-12-30T22:22:48.359Z,1577744568.359 [Reporter](INFO): platform_buoyancy_position 584.866394 cc
2019-12-30T22:22:48.778Z,1577744568.778 [Reporter](INFO): platform_buoyancy_position 589.164001 cc
2019-12-30T22:22:49.206Z,1577744569.206 [Reporter](INFO): platform_buoyancy_position 595.610413 cc
2019-12-30T22:22:49.652Z,1577744569.652 [Reporter](INFO): platform_buoyancy_position 602.056824 cc
2019-12-30T22:22:50.067Z,1577744570.067 [Reporter](INFO): platform_buoyancy_position 606.354431 cc
2019-12-30T22:22:50.410Z,1577744570.410 [Reporter](INFO): platform_buoyancy_position 612.666504 cc
2019-12-30T22:22:50.815Z,1577744570.815 [Reporter](INFO): platform_buoyancy_position 617.098450 cc
2019-12-30T22:22:51.235Z,1577744571.235 [Reporter](INFO): platform_buoyancy_position 623.544800 cc
2019-12-30T22:22:51.673Z,1577744571.673 [Reporter](INFO): platform_buoyancy_position 628.111023 cc
2019-12-30T22:22:52.075Z,1577744572.075 [Reporter](INFO): platform_buoyancy_position 634.154541 cc
2019-12-30T22:22:52.483Z,1577744572.483 [Reporter](INFO): platform_buoyancy_position 638.586426 cc
2019-12-30T22:22:52.819Z,1577744572.819 [Reporter](INFO): platform_buoyancy_position 642.749756 cc
2019-12-30T22:22:53.226Z,1577744573.226 [Reporter](INFO): platform_buoyancy_position 649.196106 cc
2019-12-30T22:22:53.607Z,1577744573.607 [Reporter](INFO): platform_buoyancy_position 653.628052 cc
2019-12-30T22:22:54.022Z,1577744574.022 [Reporter](INFO): platform_buoyancy_position 660.074402 cc
2019-12-30T22:22:54.434Z,1577744574.434 [Reporter](INFO): platform_buoyancy_position 664.237732 cc
2019-12-30T22:22:54.846Z,1577744574.846 [Reporter](INFO): platform_buoyancy_position 670.818420 cc
2019-12-30T22:22:55.222Z,1577744575.222 [Reporter](INFO): platform_buoyancy_position 674.981750 cc
2019-12-30T22:22:55.635Z,1577744575.635 [Reporter](INFO): platform_buoyancy_position 679.413635 cc
2019-12-30T22:22:56.058Z,1577744576.058 [Reporter](INFO): platform_buoyancy_position 685.860046 cc
2019-12-30T22:22:56.423Z,1577744576.423 [Reporter](INFO): platform_buoyancy_position 690.157654 cc
2019-12-30T22:22:56.843Z,1577744576.843 [Reporter](INFO): platform_buoyancy_position 696.469727 cc
2019-12-30T22:22:57.259Z,1577744577.259 [Reporter](INFO): platform_buoyancy_position 700.901611 cc
2019-12-30T22:22:57.659Z,1577744577.659 [Reporter](INFO): platform_buoyancy_position 707.213745 cc
2019-12-30T22:22:58.075Z,1577744578.075 [Reporter](INFO): platform_buoyancy_position 711.645630 cc
2019-12-30T22:22:58.462Z,1577744578.462 [Reporter](INFO): platform_buoyancy_position 718.092041 cc
2019-12-30T22:22:58.875Z,1577744578.875 [Reporter](INFO): platform_buoyancy_position 722.389648 cc
2019-12-30T22:22:59.198Z,1577744579.198 [NAL9602](INFO): NAL9602 initialized
2019-12-30T22:22:59.283Z,1577744579.283 [Reporter](INFO): platform_buoyancy_position 728.701721 cc
2019-12-30T22:22:59.688Z,1577744579.688 [Reporter](INFO): platform_buoyancy_position 733.133606 cc
2019-12-30T22:23:00.087Z,1577744580.087 [Reporter](INFO): platform_buoyancy_position 739.445740 cc
2019-12-30T22:23:00.491Z,1577744580.491 [Reporter](INFO): platform_buoyancy_position 743.877625 cc
2019-12-30T22:23:00.903Z,1577744580.903 [Reporter](INFO): platform_buoyancy_position 750.189758 cc
2019-12-30T22:23:01.304Z,1577744581.304 [Reporter](INFO): platform_buoyancy_position 754.487366 cc
2019-12-30T22:23:01.695Z,1577744581.695 [Reporter](INFO): platform_buoyancy_position 759.053528 cc
2019-12-30T22:23:02.103Z,1577744582.103 [Reporter](INFO): platform_buoyancy_position 765.231323 cc
2019-12-30T22:23:02.523Z,1577744582.523 [Reporter](INFO): platform_buoyancy_position 769.797546 cc
2019-12-30T22:23:02.934Z,1577744582.934 [Reporter](INFO): platform_buoyancy_position 776.109619 cc
2019-12-30T22:23:03.340Z,1577744583.340 [Reporter](INFO): platform_buoyancy_position 780.675842 cc
2019-12-30T22:23:03.719Z,1577744583.719 [Reporter](INFO): platform_buoyancy_position 786.719360 cc
2019-12-30T22:23:04.122Z,1577744584.122 [Reporter](INFO): platform_buoyancy_position 791.151245 cc
2019-12-30T22:23:04.514Z,1577744584.514 [Reporter](INFO): platform_buoyancy_position 797.463318 cc
2019-12-30T22:23:04.923Z,1577744584.923 [Reporter](INFO): platform_buoyancy_position 802.029541 cc
2019-12-30T22:23:05.342Z,1577744585.342 [Reporter](INFO): platform_buoyancy_position 808.207336 cc
2019-12-30T22:23:05.735Z,1577744585.735 [Reporter](INFO): platform_buoyancy_position 812.639221 cc
2019-12-30T22:23:06.143Z,1577744586.143 [Reporter](INFO): platform_buoyancy_position 817.474060 cc
2019-12-30T22:23:06.555Z,1577744586.555 [Reporter](INFO): platform_buoyancy_position 823.383240 cc
2019-12-30T22:23:06.959Z,1577744586.959 [Reporter](INFO): platform_buoyancy_position 829.695312 cc
2019-12-30T22:23:07.382Z,1577744587.382 [Reporter](INFO): platform_buoyancy_position 833.992920 cc
2019-12-30T22:23:07.788Z,1577744587.788 [Reporter](INFO): platform_buoyancy_position 840.439331 cc
2019-12-30T22:23:08.175Z,1577744588.175 [Reporter](INFO): platform_buoyancy_position 844.871216 cc
2019-12-30T22:23:08.587Z,1577744588.587 [Reporter](INFO): platform_buoyancy_position 849.303162 cc
2019-12-30T22:23:08.959Z,1577744588.959 [Reporter](INFO): platform_buoyancy_position 855.615234 cc
2019-12-30T22:23:09.375Z,1577744589.375 [Reporter](INFO): platform_buoyancy_position 859.778564 cc
2019-12-30T22:23:09.775Z,1577744589.775 [Reporter](INFO): platform_buoyancy_position 864.344727 cc
2019-12-30T22:23:10.198Z,1577744590.198 [Reporter](INFO): platform_buoyancy_position 870.656860 cc
2019-12-30T22:23:10.607Z,1577744590.607 [Reporter](INFO): platform_buoyancy_position 875.223022 cc
2019-12-30T22:23:10.987Z,1577744590.987 [Reporter](INFO): platform_buoyancy_position 881.266541 cc
2019-12-30T22:23:11.427Z,1577744591.427 [Reporter](INFO): platform_buoyancy_position 887.712952 cc
2019-12-30T22:23:11.814Z,1577744591.814 [Reporter](INFO): platform_buoyancy_position 892.144836 cc
2019-12-30T22:23:12.223Z,1577744592.223 [Reporter](INFO): platform_buoyancy_position 898.456970 cc
2019-12-30T22:23:12.639Z,1577744592.639 [Reporter](INFO): platform_buoyancy_position 902.754517 cc
2019-12-30T22:23:13.078Z,1577744593.078 [Reporter](INFO): platform_buoyancy_position 909.200928 cc
2019-12-30T22:23:13.443Z,1577744593.443 [Reporter](INFO): platform_buoyancy_position 913.498535 cc
2019-12-30T22:23:13.859Z,1577744593.859 [Reporter](INFO): platform_buoyancy_position 919.944946 cc
2019-12-30T22:23:14.255Z,1577744594.255 [Reporter](INFO): platform_buoyancy_position 924.376831 cc
2019-12-30T22:23:14.634Z,1577744594.634 [Reporter](INFO): platform_buoyancy_position 928.674438 cc
2019-12-30T22:23:15.039Z,1577744595.039 [Reporter](INFO): platform_buoyancy_position 934.986572 cc
2019-12-30T22:23:15.430Z,1577744595.430 [Reporter](INFO): platform_buoyancy_position 939.284180 cc
2019-12-30T22:23:19.519Z,1577744599.519 [Reporter](INFO): platform_buoyancy_position 954.325806 cc
2019-12-30T22:25:44.697Z,1577744744.697 [CommandLine](IMPORTANT): got command report clear
2019-12-30T22:25:49.770Z,1577744749.770 [CommandLine](IMPORTANT): got command get platform_battery_charge
2019-12-30T22:25:49.770Z,1577744749.770 [CommandLine](FAULT): Element has no value
2019-12-30T22:26:02.659Z,1577744762.659 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-12-30T22:21:02.5Z
2019-12-30T22:26:02.660Z,1577744762.660 [Default:CheckIn:Read_GPS] Stopped
2019-12-30T22:26:02.660Z,1577744762.660 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-12-30T22:26:06.662Z,1577744766.662 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-12-30T22:26:10.588Z,1577744770.588 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20191230T190856/Courier0052.lzma
2019-12-30T22:26:12.594Z,1577744772.594 [DataOverHttps](INFO): Moved sent file to Logs/20191230T190856/Courier0052.lzma.bak
2019-12-30T22:26:12.595Z,1577744772.595 [DataOverHttps](INFO): SBD MOMSN=12183271
2019-12-30T22:26:29.774Z,1577744789.774 [DataOverHttps](INFO): Sending 640 bytes from file Logs/20191230T190856/Express0053.lzma
2019-12-30T22:26:31.790Z,1577744791.790 [DataOverHttps](INFO): Moved sent file to Logs/20191230T190856/Express0053.lzma.bak
2019-12-30T22:26:31.791Z,1577744791.791 [DataOverHttps](INFO): SBD MOMSN=12183273
2019-12-30T22:26:32.956Z,1577744792.956 [Default:CheckIn:Read_Iridium] Stopped
2019-12-30T22:26:32.956Z,1577744792.956 [Default:CheckIn:C.Wait] Running Loop=1
2019-12-30T22:26:32.956Z,1577744792.956 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-12-30T22:26:37.366Z,1577744797.366 [NAL9602](INFO): Not Powering down - fast GPS
2019-12-30T22:31:33.534Z,1577745093.534 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-12-30T22:31:33.534Z,1577745093.534 [Default:CheckIn:C.Wait] Stopped
2019-12-30T22:31:33.534Z,1577745093.534 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-12-30T22:31:33.535Z,1577745093.535 [Default:CheckIn:D] Running Loop=1
2019-12-30T22:31:33.931Z,1577745093.931 [Default:CheckIn:D] Stopped
2019-12-30T22:31:33.931Z,1577745093.931 [Default:CheckIn:E] Running Loop=1
2019-12-30T22:31:34.333Z,1577745094.333 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 152.938363 min 
2019-12-30T22:31:34.333Z,1577745094.333 [Default:CheckIn:E] Stopped
2019-12-30T22:31:34.333Z,1577745094.333 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-12-30T22:31:34.333Z,1577745094.333 [Default:CheckIn] Stopped
2019-12-30T22:31:34.333Z,1577745094.333 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-12-30T22:31:34.334Z,1577745094.334 [Default:CheckIn](INFO): Running loop #16
2019-12-30T22:31:34.334Z,1577745094.334 [Default:CheckIn] Running Loop=16
2019-12-30T22:31:34.334Z,1577745094.334 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-12-30T22:31:34.334Z,1577745094.334 [Default:CheckIn:Read_GPS] Running Loop=1
2019-12-30T22:32:07.034Z,1577745127.034 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2019-12-30T22:32:07.113Z,1577745127.113 [NAL9602](FAULT): received: 
+CSQ:0

OK397, 2, 0, 0, 0

OK
2019-12-30T22:32:07.113Z,1577745127.113 [NAL9602] Data Fault, FailCount= 4
2019-12-30T22:32:07.113Z,1577745127.113 [NAL9602](ERROR): Data Fault
2019-12-30T22:32:07.175Z,1577745127.175 [CBIT](ERROR): Data Fault in component: NAL9602
2019-12-30T22:32:07.434Z,1577745127.434 [NAL9602](INFO): Powering down
2019-12-30T22:32:08.308Z,1577745128.308 [CBIT](INFO): Clearing failed state for component NAL9602
2019-12-30T22:32:08.308Z,1577745128.308 [NAL9602] No Fault, FailCount= 4
2019-12-30T22:32:37.738Z,1577745157.738 [NAL9602](INFO): Powering up NAL9602
2019-12-30T22:32:48.647Z,1577745168.647 [NAL9602](INFO): NAL9602 initialized
2019-12-30T22:33:47.717Z,1577745227.717 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-12-30T22:36:34.506Z,1577745394.506 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-12-30T22:31:34.3Z
2019-12-30T22:36:34.506Z,1577745394.506 [Default:CheckIn:Read_GPS] Stopped
2019-12-30T22:36:34.507Z,1577745394.507 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-12-30T22:36:38.518Z,1577745398.518 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-12-30T22:36:41.865Z,1577745401.865 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20191230T190856/Courier0055.lzma
2019-12-30T22:36:43.870Z,1577745403.870 [DataOverHttps](INFO): Moved sent file to Logs/20191230T190856/Courier0055.lzma.bak
2019-12-30T22:36:43.871Z,1577745403.871 [DataOverHttps](INFO): SBD MOMSN=12183302
2019-12-30T22:36:53.150Z,1577745413.150 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-12-30T22:37:01.081Z,1577745421.081 [DataOverHttps](INFO): Sending 238 bytes from file Logs/20191230T190856/Express0056.lzma
2019-12-30T22:37:03.086Z,1577745423.086 [DataOverHttps](INFO): Moved sent file to Logs/20191230T190856/Express0056.lzma.bak
2019-12-30T22:37:03.087Z,1577745423.087 [DataOverHttps](INFO): SBD MOMSN=12183304
2019-12-30T22:37:04.442Z,1577745424.442 [Default:CheckIn:Read_Iridium] Stopped
2019-12-30T22:37:04.442Z,1577745424.442 [Default:CheckIn:C.Wait] Running Loop=1
2019-12-30T22:37:04.442Z,1577745424.442 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-12-30T22:37:09.226Z,1577745429.226 [NAL9602](INFO): Not Powering down - fast GPS
2019-12-30T22:37:45.668Z,1577745465.668 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-12-30T22:37:54.151Z,1577745474.151 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-12-30T22:39:19.797Z,1577745559.797 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-12-30T22:39:33.485Z,1577745573.485 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2019-12-30T22:39:33.488Z,1577745573.488 [BPC1](INFO): Received data from all battery sticks.
2019-12-30T22:42:04.983Z,1577745724.983 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-12-30T22:42:04.983Z,1577745724.983 [Default:CheckIn:C.Wait] Stopped
2019-12-30T22:42:04.983Z,1577745724.983 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-12-30T22:42:04.984Z,1577745724.984 [Default:CheckIn:D] Running Loop=1
2019-12-30T22:42:05.391Z,1577745725.391 [Default:CheckIn:D] Stopped
2019-12-30T22:42:05.391Z,1577745725.391 [Default:CheckIn:E] Running Loop=1
2019-12-30T22:42:05.781Z,1577745725.781 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 163.462695 min 
2019-12-30T22:42:05.781Z,1577745725.781 [Default:CheckIn:E] Stopped
2019-12-30T22:42:05.781Z,1577745725.781 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-12-30T22:42:05.781Z,1577745725.781 [Default:CheckIn] Stopped
2019-12-30T22:42:05.781Z,1577745725.781 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-12-30T22:42:05.781Z,1577745725.781 [Default:CheckIn](INFO): Running loop #17
2019-12-30T22:42:05.781Z,1577745725.781 [Default:CheckIn] Running Loop=17
2019-12-30T22:42:05.782Z,1577745725.782 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-12-30T22:42:05.782Z,1577745725.782 [Default:CheckIn:Read_GPS] Running Loop=1
2019-12-30T22:42:07.378Z,1577745727.378 [NAL9602](FAULT): GPS failed to acquire within timeout.
2019-12-30T22:42:07.378Z,1577745727.378 [NAL9602] Data Fault, FailCount= 5
2019-12-30T22:42:07.378Z,1577745727.378 [NAL9602](ERROR): Data Fault
2019-12-30T22:42:07.450Z,1577745727.450 [CBIT](ERROR): Data Fault in component: NAL9602
2019-12-30T22:42:07.450Z,1577745727.450 [CBIT](CRITICAL): Data Fault in component: NAL9602
2019-12-30T22:42:07.778Z,1577745727.778 [NAL9602](INFO): Powering down
2019-12-30T22:42:07.809Z,1577745727.809 [CBIT](INFO): Critical error at 20191230T224207
2019-12-30T22:44:07.407Z,1577745847.407 [CBIT](INFO): Clearing failed state for component NAL9602
2019-12-30T22:44:07.407Z,1577745847.407 [NAL9602] No Fault, FailCount= 5
2019-12-30T22:44:07.770Z,1577745847.770 [NAL9602](INFO): Powering up NAL9602
2019-12-30T22:44:18.674Z,1577745858.674 [NAL9602](INFO): NAL9602 initialized
2019-12-30T22:47:05.976Z,1577746025.976 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-12-30T22:42:05.8Z
2019-12-30T22:47:05.976Z,1577746025.976 [Default:CheckIn:Read_GPS] Stopped
2019-12-30T22:47:05.977Z,1577746025.977 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-12-30T22:47:13.233Z,1577746033.233 [DataOverHttps](INFO): Sending 88 bytes from file Logs/20191230T190856/Courier0058.lzma
2019-12-30T22:47:15.239Z,1577746035.239 [DataOverHttps](INFO): Moved sent file to Logs/20191230T190856/Courier0058.lzma.bak
2019-12-30T22:47:15.239Z,1577746035.239 [DataOverHttps](INFO): SBD MOMSN=12183309
2019-12-30T22:47:32.245Z,1577746052.245 [DataOverHttps](INFO): Sending 215 bytes from file Logs/20191230T190856/Express0059.lzma
2019-12-30T22:47:34.251Z,1577746054.251 [DataOverHttps](INFO): Moved sent file to Logs/20191230T190856/Express0059.lzma.bak
2019-12-30T22:47:34.251Z,1577746054.251 [DataOverHttps](INFO): SBD MOMSN=12183312
2019-12-30T22:47:35.457Z,1577746055.457 [Default:CheckIn:Read_Iridium] Stopped
2019-12-30T22:47:35.457Z,1577746055.457 [Default:CheckIn:C.Wait] Running Loop=1
2019-12-30T22:47:35.457Z,1577746055.457 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-12-30T22:49:22.086Z,1577746162.086 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-12-30T22:49:52.780Z,1577746192.780 [NAL9602](INFO): Not Powering down - fast GPS
2019-12-30T22:52:36.033Z,1577746356.033 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-12-30T22:52:36.033Z,1577746356.033 [Default:CheckIn:C.Wait] Stopped
2019-12-30T22:52:36.033Z,1577746356.033 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-12-30T22:52:36.033Z,1577746356.033 [Default:CheckIn:D] Running Loop=1
2019-12-30T22:52:36.429Z,1577746356.429 [Default:CheckIn:D] Stopped
2019-12-30T22:52:36.429Z,1577746356.429 [Default:CheckIn:E] Running Loop=1
2019-12-30T22:52:36.829Z,1577746356.829 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 173.979980 min 
2019-12-30T22:52:36.829Z,1577746356.829 [Default:CheckIn:E] Stopped
2019-12-30T22:52:36.829Z,1577746356.829 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-12-30T22:52:36.830Z,1577746356.830 [Default:CheckIn] Stopped
2019-12-30T22:52:36.830Z,1577746356.830 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-12-30T22:52:36.830Z,1577746356.830 [Default:CheckIn](INFO): Running loop #18
2019-12-30T22:52:36.830Z,1577746356.830 [Default:CheckIn] Running Loop=18
2019-12-30T22:52:36.830Z,1577746356.830 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-12-30T22:52:36.830Z,1577746356.830 [Default:CheckIn:Read_GPS] Running Loop=1
2019-12-30T22:57:37.016Z,1577746657.016 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-12-30T22:52:36.8Z
2019-12-30T22:57:37.016Z,1577746657.016 [Default:CheckIn:Read_GPS] Stopped
2019-12-30T22:57:37.017Z,1577746657.017 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-12-30T22:57:41.022Z,1577746661.022 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-12-30T22:57:44.597Z,1577746664.597 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20191230T190856/Courier0061.lzma
2019-12-30T22:57:46.602Z,1577746666.602 [DataOverHttps](INFO): Moved sent file to Logs/20191230T190856/Courier0061.lzma.bak
2019-12-30T22:57:46.603Z,1577746666.603 [DataOverHttps](INFO): SBD MOMSN=12183317
2019-12-30T22:58:03.887Z,1577746683.887 [DataOverHttps](INFO): Sending 199 bytes from file Logs/20191230T190856/Express0062.lzma
2019-12-30T22:58:05.890Z,1577746685.890 [DataOverHttps](INFO): Moved sent file to Logs/20191230T190856/Express0062.lzma.bak
2019-12-30T22:58:05.891Z,1577746685.891 [DataOverHttps](INFO): SBD MOMSN=12183319
2019-12-30T22:58:07.308Z,1577746687.308 [Default:CheckIn:Read_Iridium] Stopped
2019-12-30T22:58:07.308Z,1577746687.308 [Default:CheckIn:C.Wait] Running Loop=1
2019-12-30T22:58:07.308Z,1577746687.308 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-12-30T22:58:11.726Z,1577746691.726 [NAL9602](INFO): Not Powering down - fast GPS
2019-12-30T23:03:07.905Z,1577746987.905 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-12-30T23:03:07.905Z,1577746987.905 [Default:CheckIn:C.Wait] Stopped
2019-12-30T23:03:07.905Z,1577746987.905 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-12-30T23:03:07.906Z,1577746987.906 [Default:CheckIn:D] Running Loop=1
2019-12-30T23:03:08.312Z,1577746988.312 [Default:CheckIn:D] Stopped
2019-12-30T23:03:08.312Z,1577746988.312 [Default:CheckIn:E] Running Loop=1
2019-12-30T23:03:08.706Z,1577746988.706 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 184.511361 min 
2019-12-30T23:03:08.706Z,1577746988.706 [Default:CheckIn:E] Stopped
2019-12-30T23:03:08.706Z,1577746988.706 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-12-30T23:03:08.706Z,1577746988.706 [Default:CheckIn] Stopped
2019-12-30T23:03:08.706Z,1577746988.706 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-12-30T23:03:08.706Z,1577746988.706 [Default:CheckIn](INFO): Running loop #19
2019-12-30T23:03:08.707Z,1577746988.707 [Default:CheckIn] Running Loop=19
2019-12-30T23:03:08.707Z,1577746988.707 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-12-30T23:03:08.707Z,1577746988.707 [Default:CheckIn:Read_GPS] Running Loop=1
2019-12-30T23:03:10.292Z,1577746990.292 [NAL9602](FAULT): GPS failed to acquire within timeout.
2019-12-30T23:03:10.292Z,1577746990.292 [NAL9602] Data Fault, FailCount= 1
2019-12-30T23:03:10.292Z,1577746990.292 [NAL9602](ERROR): Data Fault
2019-12-30T23:03:10.345Z,1577746990.345 [CBIT](ERROR): Data Fault in component: NAL9602
2019-12-30T23:03:10.702Z,1577746990.702 [NAL9602](INFO): Powering down
2019-12-30T23:03:11.557Z,1577746991.557 [CBIT](INFO): Clearing failed state for component NAL9602
2019-12-30T23:03:11.557Z,1577746991.557 [NAL9602] No Fault, FailCount= 1
2019-12-30T23:03:40.996Z,1577747020.996 [NAL9602](INFO): Powering up NAL9602
2019-12-30T23:03:51.566Z,1577747031.566 [CommandLine](IMPORTANT): got command quit
2019-12-30T23:03:51.910Z,1577747031.910 [NAL9602](INFO): NAL9602 initialized
2019-12-30T23:03:52.569Z,1577747032.569 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2019-12-30T23:03:52.569Z,1577747032.569 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-12-30T23:03:52.629Z,1577747032.629 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2019-12-30T23:03:52.629Z,1577747032.629 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-12-30T23:03:52.630Z,1577747032.630 [CommandLine](INFO): Join timeout helper Thread ID is 1976
2019-12-30T23:03:52.630Z,1577747032.630 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2019-12-30T23:03:52.630Z,1577747032.630 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-12-30T23:03:52.631Z,1577747032.631 [NavChartDb](INFO): Join timeout helper Thread ID is 1977
2019-12-30T23:03:52.985Z,1577747032.985 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2019-12-30T23:03:52.985Z,1577747032.985 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-12-30T23:03:52.997Z,1577747032.997 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2019-12-30T23:03:52.997Z,1577747032.997 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-12-30T23:03:52.997Z,1577747032.997 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 1978
2019-12-30T23:03:53.061Z,1577747033.061 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2019-12-30T23:03:53.061Z,1577747033.061 [WetLabsBB2FL](INFO): Powering down
2019-12-30T23:03:53.062Z,1577747033.062 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-12-30T23:03:53.077Z,1577747033.077 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2019-12-30T23:03:53.077Z,1577747033.077 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2019-12-30T23:03:53.077Z,1577747033.077 [CTD_Seabird](INFO): Join timeout helper Thread ID is 1979
2019-12-30T23:03:53.173Z,1577747033.173 [CTD_Seabird](INFO): Powering down
2019-12-30T23:03:53.185Z,1577747033.185 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2019-12-30T23:03:53.185Z,1577747033.185 [CTD_Seabird](INFO): Powering down
2019-12-30T23:03:53.209Z,1577747033.209 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2019-12-30T23:03:53.221Z,1577747033.221 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2019-12-30T23:03:53.221Z,1577747033.221 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-12-30T23:03:53.221Z,1577747033.221 [Radio_Surface](INFO): Join timeout helper Thread ID is 1980
2019-12-30T23:03:53.329Z,1577747033.329 [Radio_Surface](INFO): Powering down
2019-12-30T23:03:53.330Z,1577747033.330 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2019-12-30T23:03:53.330Z,1577747033.330 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-12-30T23:03:53.354Z,1577747033.354 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2019-12-30T23:03:53.354Z,1577747033.354 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-12-30T23:03:53.354Z,1577747033.354 [DataOverHttps](INFO): Join timeout helper Thread ID is 1981
2019-12-30T23:03:53.501Z,1577747033.501 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2019-12-30T23:03:53.504Z,1577747033.504 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-12-30T23:03:53.538Z,1577747033.538 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2019-12-30T23:03:53.538Z,1577747033.538 [logger ThreadHandler](INFO): Thread cancelled.
2019-12-30T23:03:53.538Z,1577747033.538 [logger](INFO): Join timeout helper Thread ID is 1982
2019-12-30T23:03:53.550Z,1577747033.550 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2019-12-30T23:03:53.551Z,1577747033.551 [logger ThreadHandler](INFO): Thread cancelled.
2019-12-30T23:03:53.570Z,1577747033.570 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2019-12-30T23:03:53.570Z,1577747033.570 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-12-30T23:03:53.570Z,1577747033.570 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2019-12-30T23:03:53.570Z,1577747033.570 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-12-30T23:03:53.570Z,1577747033.570 [controlThread](INFO): Join timeout helper Thread ID is 1983
2019-12-30T23:03:53.579Z,1577747033.579 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2019-12-30T23:03:53.579Z,1577747033.579 [controlThread](DEBUG): Uninitializing ControlThread
2019-12-30T23:03:53.579Z,1577747033.579 [AHRS_M2](INFO): Powering down
2019-12-30T23:03:53.649Z,1577747033.649 [NAL9602](INFO): Powering down
2019-12-30T23:03:53.652Z,1577747033.652 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2019-12-30T23:03:53.653Z,1577747033.653 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2019-12-30T23:03:53.653Z,1577747033.653 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2019-12-30T23:03:53.654Z,1577747033.654 [MissionManager](INFO): Uninitializing Mission Default
2019-12-30T23:03:53.654Z,1577747033.654 [Default] Stopped
2019-12-30T23:03:53.654Z,1577747033.654 [Default](DEBUG): Aggregate::uninitialize Default
2019-12-30T23:03:53.654Z,1577747033.654 [Default:B.GoToSurface] Stopped
2019-12-30T23:03:53.654Z,1577747033.654 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-12-30T23:03:53.654Z,1577747033.654 [Default:CheckIn] Stopped
2019-12-30T23:03:53.654Z,1577747033.654 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-12-30T23:03:53.655Z,1577747033.655 [Default:CheckIn:Read_GPS] Stopped
2019-12-30T23:03:53.657Z,1577747033.657 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2019-12-30T23:03:53.657Z,1577747033.657 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2019-12-30T23:03:53.658Z,1577747033.658 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2019-12-30T23:03:53.658Z,1577747033.658 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2019-12-30T23:03:53.658Z,1577747033.658 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2019-12-30T23:03:53.658Z,1577747033.658 [BuoyancyServo](INFO): Powering down
2019-12-30T23:03:53.673Z,1577747033.673 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2019-12-30T23:03:53.673Z,1577747033.673 [ElevatorServo](INFO): Powering down
2019-12-30T23:03:53.674Z,1577747033.674 [MassServo](DEBUG): Uninitialize Mass Servo.
2019-12-30T23:03:53.674Z,1577747033.674 [MassServo](INFO): Powering down
2019-12-30T23:03:53.675Z,1577747033.675 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-12-30T23:03:53.675Z,1577747033.675 [RudderServo](INFO): Powering down
2019-12-30T23:03:53.675Z,1577747033.675 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2019-12-30T23:03:53.676Z,1577747033.676 [ThrusterServo](INFO): Powering down
2019-12-30T23:03:53.676Z,1577747033.676 [SBIT](DEBUG): Uninitialize SBIT Component.
2019-12-30T23:03:53.677Z,1577747033.677 [IBIT](DEBUG): Uninitialize IBIT Component.
2019-12-30T23:03:53.677Z,1577747033.677 [CBIT](DEBUG): Uninitialize CBIT Component.
2019-12-30T23:03:53.677Z,1577747033.677 [CBIT](DEBUG): Powering off loads.
2019-12-30T23:03:53.689Z,1577747033.689 [CBIT](DEBUG): Disabling WDT.
2019-12-30T23:03:53.701Z,1577747033.701 [CBIT](DEBUG): Opening all GF detection circuits.
2019-12-30T23:03:53.701Z,1577747033.701 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-12-30T23:03:53.787Z,1577747033.787 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-12-30T23:03:53.793Z,1577747033.793 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-12-30T23:03:53.822Z,1577747033.822 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-12-30T23:03:53.825Z,1577747033.825 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2019-12-30T23:03:53.860Z,1577747033.860 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-12-30T23:03:53.934Z,1577747033.934 [logger ThreadHandler](INFO): Thread cancelled.