2019-10-03T04:38:08.435Z,1570077488.435 [Supervisor](DEBUG): Initializing supervisor.
2019-10-03T04:38:08.438Z,1570077488.438 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2019-10-03T04:38:08.438Z,1570077488.438 [SyncHandler](INFO): Protected caller Thread ID is 811
2019-10-03T04:38:08.438Z,1570077488.438 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2019-10-03T04:38:08.439Z,1570077488.439 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2019-10-03T04:38:08.440Z,1570077488.440 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 812
2019-10-03T04:38:08.442Z,1570077488.442 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2019-10-03T04:38:08.453Z,1570077488.453 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2019-10-03T04:38:08.454Z,1570077488.454 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2019-10-03T04:38:08.454Z,1570077488.454 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 813
2019-10-03T04:38:08.455Z,1570077488.455 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2019-10-03T04:38:08.456Z,1570077488.456 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2019-10-03T04:38:08.457Z,1570077488.457 [logger ThreadHandler](INFO): Protected caller Thread ID is 814
2019-10-03T04:38:08.458Z,1570077488.458 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2019-10-03T04:38:08.459Z,1570077488.459 [Supervisor](INFO): Looking for Config files in directory: Config/
2019-10-03T04:38:08.463Z,1570077488.463 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2019-10-03T04:38:08.960Z,1570077488.960 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2019-10-03T04:38:08.962Z,1570077488.962 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2019-10-03T04:38:09.110Z,1570077489.110 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2019-10-03T04:38:09.112Z,1570077489.112 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2019-10-03T04:38:09.193Z,1570077489.193 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2019-10-03T04:38:09.293Z,1570077489.293 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2019-10-03T04:38:09.295Z,1570077489.295 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2019-10-03T04:38:09.392Z,1570077489.392 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2019-10-03T04:38:09.392Z,1570077489.392 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2019-10-03T04:38:09.787Z,1570077489.787 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2019-10-03T04:38:09.788Z,1570077489.788 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2019-10-03T04:38:09.892Z,1570077489.892 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2019-10-03T04:38:09.893Z,1570077489.893 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2019-10-03T04:38:10.378Z,1570077490.378 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2019-10-03T04:38:10.379Z,1570077490.379 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2019-10-03T04:38:10.590Z,1570077490.590 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2019-10-03T04:38:10.592Z,1570077490.592 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2019-10-03T04:38:10.913Z,1570077490.913 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2019-10-03T04:38:10.915Z,1570077490.915 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2019-10-03T04:38:11.146Z,1570077491.146 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2019-10-03T04:38:11.148Z,1570077491.148 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2019-10-03T04:38:11.496Z,1570077491.496 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2019-10-03T04:38:11.609Z,1570077491.609 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2019-10-03T04:38:12.295Z,1570077492.295 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2019-10-03T04:38:12.297Z,1570077492.297 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2019-10-03T04:38:12.653Z,1570077492.653 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2019-10-03T04:38:12.655Z,1570077492.655 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2019-10-03T04:38:12.870Z,1570077492.870 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2019-10-03T04:38:12.872Z,1570077492.872 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-triton/
2019-10-03T04:38:12.875Z,1570077492.875 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/vehicle.cfg
2019-10-03T04:38:13.074Z,1570077493.074 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/secure.cfg
2019-10-03T04:38:13.158Z,1570077493.158 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Science.cfg
2019-10-03T04:38:13.301Z,1570077493.301 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Simulator.cfg
2019-10-03T04:38:13.387Z,1570077493.387 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Battery.cfg
2019-10-03T04:38:13.620Z,1570077493.620 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2019-10-03T04:38:13.621Z,1570077493.621 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/logger.cfg
2019-10-03T04:38:13.718Z,1570077493.718 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Servo.cfg
2019-10-03T04:38:13.829Z,1570077493.829 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Navigation.cfg
2019-10-03T04:38:13.924Z,1570077493.924 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Sensor.cfg
2019-10-03T04:38:14.080Z,1570077494.080 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Control.cfg
2019-10-03T04:38:14.181Z,1570077494.181 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/BIT.cfg
2019-10-03T04:38:14.282Z,1570077494.282 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg
2019-10-03T04:38:14.285Z,1570077494.285 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2019-10-03T04:38:14.309Z,1570077494.309 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2019-10-03T04:38:14.311Z,1570077494.311 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2019-10-03T04:38:14.402Z,1570077494.402 [VerticalControl](DEBUG): Construct VerticalControl.
2019-10-03T04:38:14.518Z,1570077494.518 [VerticalControl] Loaded
2019-10-03T04:38:14.518Z,1570077494.518 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2019-10-03T04:38:14.519Z,1570077494.519 [HorizontalControl](DEBUG): Construct HorizontalControl.
2019-10-03T04:38:14.589Z,1570077494.589 [HorizontalControl] Loaded
2019-10-03T04:38:14.589Z,1570077494.589 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2019-10-03T04:38:14.590Z,1570077494.590 [SpeedControl](DEBUG): Construct SpeedControl.
2019-10-03T04:38:14.596Z,1570077494.596 [SpeedControl] Loaded
2019-10-03T04:38:14.596Z,1570077494.596 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2019-10-03T04:38:14.597Z,1570077494.597 [LoopControl](DEBUG): Construct LoopControl.
2019-10-03T04:38:14.597Z,1570077494.597 [LoopControl] Loaded
2019-10-03T04:38:14.598Z,1570077494.598 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2019-10-03T04:38:14.598Z,1570077494.598 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2019-10-03T04:38:14.599Z,1570077494.599 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2019-10-03T04:38:14.753Z,1570077494.753 [BuoyancyServo] Loaded
2019-10-03T04:38:14.753Z,1570077494.753 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2019-10-03T04:38:14.765Z,1570077494.765 [ElevatorServo] Loaded
2019-10-03T04:38:14.765Z,1570077494.765 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2019-10-03T04:38:14.776Z,1570077494.776 [MassServo] Loaded
2019-10-03T04:38:14.776Z,1570077494.776 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2019-10-03T04:38:14.787Z,1570077494.787 [RudderServo] Loaded
2019-10-03T04:38:14.788Z,1570077494.788 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2019-10-03T04:38:14.799Z,1570077494.799 [ThrusterServo] Loaded
2019-10-03T04:38:14.799Z,1570077494.799 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2019-10-03T04:38:14.799Z,1570077494.799 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2019-10-03T04:38:14.800Z,1570077494.800 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2019-10-03T04:38:14.857Z,1570077494.857 [DepthRateCalculator] Loaded
2019-10-03T04:38:14.857Z,1570077494.857 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2019-10-03T04:38:14.862Z,1570077494.862 [PitchRateCalculator] Loaded
2019-10-03T04:38:14.863Z,1570077494.863 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2019-10-03T04:38:14.878Z,1570077494.878 [SpeedCalculator] Loaded
2019-10-03T04:38:14.878Z,1570077494.878 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2019-10-03T04:38:14.900Z,1570077494.900 [TempGradientCalculator] Loaded
2019-10-03T04:38:14.900Z,1570077494.900 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2019-10-03T04:38:14.905Z,1570077494.905 [YawRateCalculator] Loaded
2019-10-03T04:38:14.906Z,1570077494.906 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2019-10-03T04:38:14.936Z,1570077494.936 [ElevatorOffsetCalculator] Loaded
2019-10-03T04:38:14.937Z,1570077494.937 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2019-10-03T04:38:14.937Z,1570077494.937 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2019-10-03T04:38:14.939Z,1570077494.939 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2019-10-03T04:38:15.060Z,1570077495.060 [DeadReckonUsingMultipleVelocitySources] Loaded
2019-10-03T04:38:15.060Z,1570077495.060 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2019-10-03T04:38:15.082Z,1570077495.082 [NavChart] Loaded
2019-10-03T04:38:15.082Z,1570077495.082 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2019-10-03T04:38:15.086Z,1570077495.086 [UniversalFixResidualReporter] Loaded
2019-10-03T04:38:15.086Z,1570077495.086 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2019-10-03T04:38:15.087Z,1570077495.087 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2019-10-03T04:38:15.087Z,1570077495.087 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2019-10-03T04:38:15.689Z,1570077495.689 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_orientation
2019-10-03T04:38:15.694Z,1570077495.694 [AHRS_M2](INFO): created writer for : platform_orientation
2019-10-03T04:38:15.696Z,1570077495.696 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_magnetic_orientation
2019-10-03T04:38:15.701Z,1570077495.701 [AHRS_M2](INFO): created writer for : platform_magnetic_orientation
2019-10-03T04:38:15.702Z,1570077495.702 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_pitch_angle
2019-10-03T04:38:15.707Z,1570077495.707 [AHRS_M2](INFO): created writer for : platform_pitch_angle
2019-10-03T04:38:15.708Z,1570077495.708 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_roll_angle
2019-10-03T04:38:15.713Z,1570077495.713 [AHRS_M2](INFO): created writer for : platform_roll_angle
2019-10-03T04:38:15.891Z,1570077495.891 [AHRS_M2] Loaded
2019-10-03T04:38:15.892Z,1570077495.892 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2019-10-03T04:38:16.226Z,1570077496.226 [DataOverHttps] Loaded
2019-10-03T04:38:16.226Z,1570077496.226 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2019-10-03T04:38:16.228Z,1570077496.228 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 407F84E0
2019-10-03T04:38:16.228Z,1570077496.228 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 893
2019-10-03T04:38:16.242Z,1570077496.242 [Depth_Keller] Loaded
2019-10-03T04:38:16.242Z,1570077496.242 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2019-10-03T04:38:16.247Z,1570077496.247 [DropWeight] Loaded
2019-10-03T04:38:16.248Z,1570077496.248 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2019-10-03T04:38:16.294Z,1570077496.294 [DVL_micro] Loaded
2019-10-03T04:38:16.295Z,1570077496.295 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread.
2019-10-03T04:38:16.394Z,1570077496.394 [NAL9602] Loaded
2019-10-03T04:38:16.394Z,1570077496.394 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2019-10-03T04:38:16.410Z,1570077496.410 [Onboard] Loaded
2019-10-03T04:38:16.411Z,1570077496.411 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2019-10-03T04:38:16.414Z,1570077496.414 [Radio_Surface] Loaded
2019-10-03T04:38:16.414Z,1570077496.414 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2019-10-03T04:38:16.415Z,1570077496.415 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408284E0
2019-10-03T04:38:16.416Z,1570077496.416 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 894
2019-10-03T04:38:16.546Z,1570077496.546 [DAT] Loaded
2019-10-03T04:38:16.546Z,1570077496.546 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread.
2019-10-03T04:38:18.687Z,1570077498.687 [BPC1] Loaded
2019-10-03T04:38:18.687Z,1570077498.687 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2019-10-03T04:38:18.687Z,1570077498.687 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2019-10-03T04:38:18.689Z,1570077498.689 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2019-10-03T04:38:18.804Z,1570077498.804 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2019-10-03T04:38:18.805Z,1570077498.805 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2019-10-03T04:38:18.935Z,1570077498.935 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2019-10-03T04:38:18.936Z,1570077498.936 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2019-10-03T04:38:18.985Z,1570077498.985 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2019-10-03T04:38:18.985Z,1570077498.985 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2019-10-03T04:38:19.279Z,1570077499.279 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density
2019-10-03T04:38:19.285Z,1570077499.285 [CTD_Seabird](INFO): created writer for : sea_water_density
2019-10-03T04:38:19.285Z,1570077499.285 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth
2019-10-03T04:38:19.290Z,1570077499.290 [CTD_Seabird](INFO): created writer for : depth
2019-10-03T04:38:19.290Z,1570077499.290 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure
2019-10-03T04:38:19.296Z,1570077499.296 [CTD_Seabird](INFO): created writer for : sea_water_pressure
2019-10-03T04:38:19.296Z,1570077499.296 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity
2019-10-03T04:38:19.302Z,1570077499.302 [CTD_Seabird](INFO): created writer for : sea_water_salinity
2019-10-03T04:38:19.302Z,1570077499.302 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature
2019-10-03T04:38:19.307Z,1570077499.307 [CTD_Seabird](INFO): created writer for : sea_water_temperature
2019-10-03T04:38:19.308Z,1570077499.308 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity
2019-10-03T04:38:19.314Z,1570077499.314 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity
2019-10-03T04:38:19.314Z,1570077499.314 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water
2019-10-03T04:38:19.320Z,1570077499.320 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water
2019-10-03T04:38:19.320Z,1570077499.320 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): mass_concentration_of_oxygen_in_sea_water
2019-10-03T04:38:19.326Z,1570077499.326 [CTD_Seabird](INFO): created writer for : mass_concentration_of_oxygen_in_sea_water
2019-10-03T04:38:19.326Z,1570077499.326 [CTD_Seabird](DEBUG): LcmSlateWriter::add(DAtaURI): CTD_Seabird.sea_water_dissolved_oxygen_freq
2019-10-03T04:38:19.327Z,1570077499.327 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): dataName: sea_water_dissolved_oxygen_freq
2019-10-03T04:38:19.360Z,1570077499.360 [CTD_Seabird] Loaded
2019-10-03T04:38:19.361Z,1570077499.361 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2019-10-03T04:38:19.362Z,1570077499.362 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 409BF4E0
2019-10-03T04:38:19.362Z,1570077499.362 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 896
2019-10-03T04:38:19.394Z,1570077499.394 [ESPComponent] Loaded
2019-10-03T04:38:19.394Z,1570077499.394 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2019-10-03T04:38:19.408Z,1570077499.408 [PAR_Licor] Loaded
2019-10-03T04:38:19.408Z,1570077499.408 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2019-10-03T04:38:19.415Z,1570077499.415 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output470
2019-10-03T04:38:19.415Z,1570077499.415 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output470
2019-10-03T04:38:19.419Z,1570077499.419 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output650
2019-10-03T04:38:19.419Z,1570077499.419 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output650
2019-10-03T04:38:19.424Z,1570077499.424 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.OutputChl
2019-10-03T04:38:19.424Z,1570077499.424 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: OutputChl
2019-10-03T04:38:19.428Z,1570077499.428 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg470nm
2019-10-03T04:38:19.428Z,1570077499.428 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg470nm
2019-10-03T04:38:19.433Z,1570077499.433 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg650nm
2019-10-03T04:38:19.433Z,1570077499.433 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg650nm
2019-10-03T04:38:19.438Z,1570077499.438 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff470nm
2019-10-03T04:38:19.438Z,1570077499.438 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff470nm
2019-10-03T04:38:19.442Z,1570077499.442 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff650nm
2019-10-03T04:38:19.442Z,1570077499.442 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff650nm
2019-10-03T04:38:19.447Z,1570077499.447 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): mass_concentration_of_chlorophyll_in_sea_water
2019-10-03T04:38:19.451Z,1570077499.451 [WetLabsBB2FL](INFO): created writer for : mass_concentration_of_chlorophyll_in_sea_water
2019-10-03T04:38:19.452Z,1570077499.452 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_median_mass_concentration_of_chlorophyll_in_sea_water
2019-10-03T04:38:19.452Z,1570077499.452 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_median_mass_concentration_of_chlorophyll_in_sea_water
2019-10-03T04:38:19.456Z,1570077499.456 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water
2019-10-03T04:38:19.457Z,1570077499.457 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_mean_mass_concentration_of_chlorophyll_in_sea_water
2019-10-03T04:38:19.461Z,1570077499.461 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_variance_mass_concentration_of_chlorophyll_in_sea_water
2019-10-03T04:38:19.461Z,1570077499.461 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_variance_mass_concentration_of_chlorophyll_in_sea_water
2019-10-03T04:38:19.466Z,1570077499.466 [WetLabsBB2FL] Loaded
2019-10-03T04:38:19.466Z,1570077499.466 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2019-10-03T04:38:19.467Z,1570077499.467 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 409EF4E0
2019-10-03T04:38:19.468Z,1570077499.468 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 897
2019-10-03T04:38:19.468Z,1570077499.468 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2019-10-03T04:38:19.469Z,1570077499.469 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2019-10-03T04:38:19.825Z,1570077499.825 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2019-10-03T04:38:19.826Z,1570077499.826 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2019-10-03T04:38:19.992Z,1570077499.992 [SBIT](DEBUG): Construct Startup Built In Test.
2019-10-03T04:38:20.003Z,1570077500.003 [SBIT] Loaded
2019-10-03T04:38:20.003Z,1570077500.003 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2019-10-03T04:38:20.004Z,1570077500.004 [IBIT](DEBUG): Construct Initiated Built In Test.
2019-10-03T04:38:20.015Z,1570077500.015 [IBIT] Loaded
2019-10-03T04:38:20.016Z,1570077500.016 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2019-10-03T04:38:20.019Z,1570077500.019 [CBIT](DEBUG): Construct Continuous Built In Test.
2019-10-03T04:38:20.162Z,1570077500.162 [CBIT] Loaded
2019-10-03T04:38:20.162Z,1570077500.162 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2019-10-03T04:38:20.163Z,1570077500.163 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2019-10-03T04:38:20.166Z,1570077500.166 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2019-10-03T04:38:20.167Z,1570077500.167 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2019-10-03T04:38:20.174Z,1570077500.174 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2019-10-03T04:38:20.175Z,1570077500.175 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40ACE4E0
2019-10-03T04:38:20.175Z,1570077500.175 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 898
2019-10-03T04:38:20.180Z,1570077500.180 [Supervisor](INFO): Main Thread ID is 807
2019-10-03T04:38:20.180Z,1570077500.180 [Supervisor](DEBUG): Running supervisor.
2019-10-03T04:38:20.181Z,1570077500.181 [CommandLine ThreadHandler](INFO): Handler Thread ID is 899
2019-10-03T04:38:20.183Z,1570077500.183 [controlThread ThreadHandler](INFO): Handler Thread ID is 900
2019-10-03T04:38:20.183Z,1570077500.183 [controlThread](DEBUG): Initializing ControlThread
2019-10-03T04:38:20.184Z,1570077500.184 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2019-10-03T04:38:20.186Z,1570077500.186 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2019-10-03T04:38:20.186Z,1570077500.186 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2019-10-03T04:38:20.187Z,1570077500.187 [LoopControl](DEBUG): Initialize LoopControlComponent.
2019-10-03T04:38:20.188Z,1570077500.188 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2019-10-03T04:38:20.188Z,1570077500.188 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2019-10-03T04:38:20.189Z,1570077500.189 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2019-10-03T04:38:20.189Z,1570077500.189 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2019-10-03T04:38:20.190Z,1570077500.190 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2019-10-03T04:38:20.190Z,1570077500.190 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2019-10-03T04:38:20.191Z,1570077500.191 [NavChart](DEBUG): Initialize NavChart Navigation.
2019-10-03T04:38:20.192Z,1570077500.192 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2019-10-03T04:38:20.200Z,1570077500.200 [SBIT](INFO): Initialize SBIT Component.
2019-10-03T04:38:20.200Z,1570077500.200 [SBIT](IMPORTANT): git: 2019-10-03_B
2019-10-03T04:38:20.200Z,1570077500.200 [SBIT](INFO): git hash: 395bdff68a97d6c59eee2553e61a5ed127931da4
2019-10-03T04:38:20.201Z,1570077500.201 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2019-10-03T04:38:20.202Z,1570077500.202 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #1 PREEMPT Tue Dec 18 21:19:28 PST 2018
Kernel Reported: #1 PREEMPT Thu Feb 21 11:17:40 PST 2019
2019-10-03T04:38:20.203Z,1570077500.203 [SBIT](INFO): Beginning SBIT in 30.000000 seconds.
2019-10-03T04:38:20.203Z,1570077500.203 [IBIT](INFO): Initialize IBIT Component.
2019-10-03T04:38:20.204Z,1570077500.204 [CBIT](DEBUG): Initialize CBIT Component.
2019-10-03T04:38:20.205Z,1570077500.205 [logger ThreadHandler](INFO): Handler Thread ID is 901
2019-10-03T04:38:20.215Z,1570077500.215 [CBIT](DEBUG): Initialized mux pins.
2019-10-03T04:38:20.215Z,1570077500.215 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL.
2019-10-03T04:38:20.216Z,1570077500.216 [CBIT](DEBUG): Initializing the watchdog timer.
2019-10-03T04:38:20.224Z,1570077500.224 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 902
2019-10-03T04:38:20.225Z,1570077500.225 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2019-10-03T04:38:20.239Z,1570077500.239 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2019-10-03T04:38:20.240Z,1570077500.240 [CBIT](DEBUG): Initializing heartbeat.
2019-10-03T04:38:20.270Z,1570077500.270 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 903
2019-10-03T04:38:20.276Z,1570077500.276 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 904
2019-10-03T04:38:20.276Z,1570077500.276 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2019-10-03T04:38:20.280Z,1570077500.280 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20
2019-10-03T04:38:20.281Z,1570077500.281 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 906
2019-10-03T04:38:20.282Z,1570077500.282 [WetLabsBB2FL](INFO): Powering down
2019-10-03T04:38:20.324Z,1570077500.324 [CBIT](DEBUG): Deactivating GF circuits.
2019-10-03T04:38:20.325Z,1570077500.325 [CBIT](DEBUG): Deactivating emergency mode.
2019-10-03T04:38:20.325Z,1570077500.325 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 907
2019-10-03T04:38:20.359Z,1570077500.359 [CBIT](DEBUG): Backplane powered.
2019-10-03T04:38:20.403Z,1570077500.403 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2019-10-03T04:38:20.412Z,1570077500.412 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2019-10-03T04:38:20.412Z,1570077500.412 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2019-10-03T04:38:20.412Z,1570077500.412 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2019-10-03T04:38:20.412Z,1570077500.412 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2019-10-03T04:38:20.412Z,1570077500.412 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2019-10-03T04:38:20.417Z,1570077500.417 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2019-10-03T04:38:20.417Z,1570077500.417 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2019-10-03T04:38:20.417Z,1570077500.417 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2019-10-03T04:38:20.423Z,1570077500.423 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2019-10-03T04:38:20.423Z,1570077500.423 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2019-10-03T04:38:20.424Z,1570077500.424 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2019-10-03T04:38:20.424Z,1570077500.424 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2019-10-03T04:38:20.424Z,1570077500.424 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2019-10-03T04:38:20.424Z,1570077500.424 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2019-10-03T04:38:20.424Z,1570077500.424 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2019-10-03T04:38:20.424Z,1570077500.424 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2019-10-03T04:38:20.443Z,1570077500.443 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2019-10-03T04:38:20.564Z,1570077500.564 [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-10-03T04:38:20.565Z,1570077500.565 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2019-10-03T04:38:20.672Z,1570077500.672 [Radio_Surface](INFO): Powering up
2019-10-03T04:38:20.683Z,1570077500.683 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2019-10-03T04:38:20.684Z,1570077500.684 [Default:A.Wait](DEBUG): Construct Wait.
2019-10-03T04:38:20.686Z,1570077500.686 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2019-10-03T04:38:20.746Z,1570077500.746 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2019-10-03T04:38:20.748Z,1570077500.748 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2019-10-03T04:38:20.796Z,1570077500.796 [Default:E.Execute](DEBUG): Construct Execute.
2019-10-03T04:38:20.799Z,1570077500.799 [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-10-03T04:38:20.814Z,1570077500.814 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,DVL_micro,NAL9602,Onboard,DAT,BPC1,ESPComponent,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-10-03T04:38:20.842Z,1570077500.842 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2019-10-03T04:38:20.989Z,1570077500.989 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2019-10-03T04:38:20.989Z,1570077500.989 [DAT](INFO): Powering up
2019-10-03T04:38:20.990Z,1570077500.990 [DAT](DEBUG): Initializing DAT.
2019-10-03T04:38:21.077Z,1570077501.077 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2019-10-03T04:38:21.080Z,1570077501.080 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2019-10-03T04:38:21.119Z,1570077501.119 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2019-10-03T04:38:21.121Z,1570077501.121 [ElevatorServo](DEBUG): Initializing EZServoServo.
2019-10-03T04:38:21.124Z,1570077501.124 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2019-10-03T04:38:21.125Z,1570077501.125 [MassServo](DEBUG): Initializing EZServoServo.
2019-10-03T04:38:21.136Z,1570077501.136 [MassServo](DEBUG): Initializing MassServo.
2019-10-03T04:38:21.137Z,1570077501.137 [RudderServo](DEBUG): Initializing EZServoServo.
2019-10-03T04:38:21.148Z,1570077501.148 [RudderServo](DEBUG): Initializing RudderServo.
2019-10-03T04:38:21.149Z,1570077501.149 [ThrusterServo](DEBUG): Initializing EZServoServo.
2019-10-03T04:38:21.160Z,1570077501.160 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2019-10-03T04:38:21.975Z,1570077501.975 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2019-10-03T04:38:21.976Z,1570077501.976 [RudderServo](FAULT): Rudder failed to initialize
2019-10-03T04:38:21.976Z,1570077501.976 [RudderServo] Communications Fault, FailCount= 1
2019-10-03T04:38:21.976Z,1570077501.976 [RudderServo](ERROR): Communications Fault
2019-10-03T04:38:22.171Z,1570077502.171 [CBIT](ERROR): Communications Fault in component: RudderServo
2019-10-03T04:38:22.384Z,1570077502.384 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-10-03T04:38:22.385Z,1570077502.385 [RudderServo](INFO): Powering down
2019-10-03T04:38:23.038Z,1570077503.038 [RudderServo](DEBUG): Initializing EZServoServo.
2019-10-03T04:38:23.156Z,1570077503.156 [RudderServo](DEBUG): Initializing RudderServo.
2019-10-03T04:38:23.160Z,1570077503.160 [CBIT](INFO): Clearing failed state for component RudderServo
2019-10-03T04:38:23.160Z,1570077503.160 [RudderServo] No Fault, FailCount= 1
2019-10-03T04:38:34.452Z,1570077514.452 [DAT](INFO): setting local address to 5
2019-10-03T04:38:34.856Z,1570077514.856 [DAT](INFO): set local address to 5
2019-10-03T04:38:46.558Z,1570077526.558 [NAL9602](INFO): Powering up NAL9602
2019-10-03T04:38:50.661Z,1570077530.661 [SBIT](IMPORTANT): Beginning Startup BIT
2019-10-03T04:38:50.677Z,1570077530.677 [CBIT](IMPORTANT): Beginning ground fault scan
2019-10-03T04:38:57.701Z,1570077537.701 [NAL9602](INFO): NAL9602 initialized
2019-10-03T04:38:58.519Z,1570077538.519 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:39:01.444Z,1570077541.444 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.051812
CHAN A1 (24V): 0.197713
CHAN A2 (12V): -0.017483
CHAN A3 (5V): -0.026744
CHAN B0 (3.3V): -0.012672
CHAN B1 (3.15aV): -0.006856
CHAN B2 (3.15bV): -0.003319
CHAN B3 (GND): -0.011942
OPEN: -0.000235
Full Scale Calc: 4.765 mA, -1.589 mA
2019-10-03T04:39:20.032Z,1570077560.032 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2019-10-03T04:39:20.033Z,1570077560.033 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0000.0,1489.0,000
2019-10-03T04:39:42.467Z,1570077582.467 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-10-03T04:39:44.045Z,1570077584.045 [SBIT](IMPORTANT): SBIT PASSED
2019-10-03T04:39:44.068Z,1570077584.068 [CommandLine](IMPORTANT): got command configSet list
2019-10-03T04:39:44.069Z,1570077584.069 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2019-10-03T04:39:44.072Z,1570077584.072 [CommandLine](IMPORTANT): CBIT.gf24Offset=155 microampere;

2019-10-03T04:39:44.072Z,1570077584.072 [CommandLine](IMPORTANT): ESPComponent.loadAtStartup=1 bool;

2019-10-03T04:39:44.072Z,1570077584.072 [CommandLine](IMPORTANT): Express linearApproximation DVL_micro.height_above_sea_floor 5.000000 meter;

2019-10-03T04:39:44.429Z,1570077584.429 [MissionManager](IMPORTANT): Started mission Startup
2019-10-03T04:39:44.430Z,1570077584.430 [Startup] Running Loop=1
2019-10-03T04:39:44.430Z,1570077584.430 [Startup](DEBUG): Aggregate::initialize Startup
2019-10-03T04:39:44.430Z,1570077584.430 [Startup:A.GoToSurface] Running Loop=1
2019-10-03T04:39:44.430Z,1570077584.430 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-10-03T04:39:44.431Z,1570077584.431 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-10-03T04:39:44.431Z,1570077584.431 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-10-03T04:39:44.432Z,1570077584.432 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-10-03T04:39:44.432Z,1570077584.432 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-10-03T04:39:44.433Z,1570077584.433 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-10-03T04:39:44.434Z,1570077584.434 [Startup:StartupSatComms] Running Loop=1
2019-10-03T04:39:44.434Z,1570077584.434 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2019-10-03T04:39:44.434Z,1570077584.434 [Startup:StartupSatComms:A] Running Loop=1
2019-10-03T04:39:44.830Z,1570077584.830 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2019-10-03T04:39:45.614Z,1570077585.614 [DVL_micro](ERROR): Failed to parse:
:BD,+00000000.00,+00000000.00,+00000000.00,9999.99,000.00
2019-10-03T04:40:11.063Z,1570077611.063 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2019-10-03T04:40:11.063Z,1570077611.063 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+19.6,0000.0000
2019-10-03T04:40:16.804Z,1570077616.804 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-10-03T04:40:44.681Z,1570077644.681 [Startup:StartupSatComms:A](INFO): Timed out from 2019-10-03T04:39:44.4Z
2019-10-03T04:40:44.681Z,1570077644.681 [Startup:StartupSatComms:A] Stopped
2019-10-03T04:40:44.681Z,1570077644.681 [Startup:StartupSatComms:B] Running Loop=1
2019-10-03T04:40:45.046Z,1570077645.046 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-10-03T04:41:20.466Z,1570077680.466 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.005931
2019-10-03T04:41:20.584Z,1570077680.584 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2019-10-03T04:41:20.584Z,1570077680.584 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-10-03T04:41:20.594Z,1570077680.594 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-10-03T04:41:21.006Z,1570077681.006 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-10-03T04:41:21.006Z,1570077681.006 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2019-10-03T04:41:29.979Z,1570077689.979 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20191002T232619/Courier0088.lzma
2019-10-03T04:41:31.986Z,1570077691.986 [DataOverHttps](INFO): Moved sent file to Logs/20191002T232619/Courier0088.lzma.bak
2019-10-03T04:41:31.986Z,1570077691.986 [DataOverHttps](INFO): SBD MOMSN=11842790
2019-10-03T04:41:44.929Z,1570077704.929 [Startup:StartupSatComms:B](INFO): Timed out from 2019-10-03T04:40:44.7Z
2019-10-03T04:41:44.930Z,1570077704.930 [Startup:StartupSatComms:B] Stopped
2019-10-03T04:41:44.930Z,1570077704.930 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2019-10-03T04:41:44.935Z,1570077704.935 [Startup:StartupSatComms] Stopped
2019-10-03T04:41:44.935Z,1570077704.935 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2019-10-03T04:41:44.936Z,1570077704.936 [Startup](INFO): Completed Startup
2019-10-03T04:41:44.936Z,1570077704.936 [MissionManager](INFO): Startup is completed.
2019-10-03T04:41:44.937Z,1570077704.937 [MissionManager](INFO): Uninitializing Mission Startup
2019-10-03T04:41:44.937Z,1570077704.937 [Startup] Stopped
2019-10-03T04:41:44.937Z,1570077704.937 [Startup](DEBUG): Aggregate::uninitialize Startup
2019-10-03T04:41:44.937Z,1570077704.937 [Startup:A.GoToSurface] Stopped
2019-10-03T04:41:44.937Z,1570077704.937 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-10-03T04:41:45.256Z,1570077705.256 [MissionManager](IMPORTANT): Started mission Default
2019-10-03T04:41:45.256Z,1570077705.256 [Default] Running Loop=1
2019-10-03T04:41:45.256Z,1570077705.256 [Default](DEBUG): Aggregate::initialize Default
2019-10-03T04:41:45.256Z,1570077705.256 [Default:B.GoToSurface] Running Loop=1
2019-10-03T04:41:45.256Z,1570077705.256 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-10-03T04:41:45.257Z,1570077705.257 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-10-03T04:41:45.257Z,1570077705.257 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-10-03T04:41:45.257Z,1570077705.257 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-10-03T04:41:45.257Z,1570077705.257 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-10-03T04:41:45.258Z,1570077705.258 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-10-03T04:41:45.258Z,1570077705.258 [Default:A.Wait] Running Loop=1
2019-10-03T04:41:45.258Z,1570077705.258 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-10-03T04:41:56.495Z,1570077716.495 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20191002T232619/Express0089.lzma
2019-10-03T04:41:58.607Z,1570077718.607 [Default:A.Wait](INFO): Done Waiting.
2019-10-03T04:41:58.609Z,1570077718.609 [Default:A.Wait] Stopped
2019-10-03T04:41:58.609Z,1570077718.609 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-10-03T04:41:58.956Z,1570077718.956 [DataOverHttps](INFO): Moved sent file to Logs/20191002T232619/Express0089.lzma.bak
2019-10-03T04:41:58.956Z,1570077718.956 [DataOverHttps](INFO): SBD MOMSN=11842792
2019-10-03T04:41:59.021Z,1570077719.021 [Default:CheckIn] Running Loop=1
2019-10-03T04:41:59.022Z,1570077719.022 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-10-03T04:41:59.022Z,1570077719.022 [Default:CheckIn:Read_GPS] Running Loop=1
2019-10-03T04:41:59.418Z,1570077719.418 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2019-10-03T04:43:19.351Z,1570077799.351 [DVL_micro](ERROR): only read 1 of 4 data items
2019-10-03T04:43:19.351Z,1570077799.351 [DVL_micro](ERROR): Failed to parse::RD,+9999..99,+99999.99
2019-10-03T04:43:48.920Z,1570077828.920 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-10-03T04:44:00.553Z,1570077840.553 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-10-03T04:44:01.377Z,1570077841.377 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:44:02.581Z,1570077842.581 [DVL_micro](ERROR): Failed to parse:
:WI,+02567,+02878,+00029,+00000,A
2019-10-03T04:44:03.799Z,1570077843.799 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:44:06.631Z,1570077846.631 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:44:09.059Z,1570077849.059 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:44:11.883Z,1570077851.883 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:44:15.131Z,1570077855.131 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:44:17.943Z,1570077857.943 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:44:20.775Z,1570077860.775 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:44:21.612Z,1570077861.612 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2019-10-03T04:44:21.612Z,1570077861.612 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-10-03T04:44:21.622Z,1570077861.622 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-10-03T04:44:22.008Z,1570077862.008 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-10-03T04:44:22.008Z,1570077862.008 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2019-10-03T04:44:23.595Z,1570077863.595 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:44:26.827Z,1570077866.827 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:44:28.929Z,1570077868.929 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-10-03T04:44:29.657Z,1570077869.657 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:44:30.454Z,1570077870.454 [DVL_micro](ERROR): Failed to parse::WI,+02561,-01697,+00946,+00000,A
2019-10-03T04:44:32.907Z,1570077872.907 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:44:35.727Z,1570077875.727 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:44:38.955Z,1570077878.955 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:44:41.775Z,1570077881.775 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:44:45.008Z,1570077885.008 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:44:47.850Z,1570077887.850 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:44:51.067Z,1570077891.067 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:44:53.897Z,1570077893.897 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:44:56.727Z,1570077896.727 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:44:59.555Z,1570077899.555 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:45:02.792Z,1570077902.792 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:45:05.627Z,1570077905.627 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:45:08.843Z,1570077908.843 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:45:11.675Z,1570077911.675 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:45:14.907Z,1570077914.907 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:45:17.731Z,1570077917.731 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:45:18.934Z,1570077918.934 [DVL_micro](ERROR): only read 3 of 4 data items
2019-10-03T04:45:18.934Z,1570077918.934 [DVL_micro](ERROR): Failed to parse:
:BI,+01489,+01804,+0000,I
2019-10-03T04:45:20.967Z,1570077920.967 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:45:22.581Z,1570077922.581 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-10-03T04:45:23.815Z,1570077923.815 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:45:27.031Z,1570077927.031 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:45:29.855Z,1570077929.855 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:45:33.087Z,1570077933.087 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:45:34.772Z,1570077934.772 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-10-03T04:45:35.911Z,1570077935.911 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:45:38.382Z,1570077938.382 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-10-03T04:45:38.739Z,1570077938.739 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:45:41.972Z,1570077941.972 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:45:44.801Z,1570077944.801 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:45:47.284Z,1570077947.284 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-10-03T04:45:47.635Z,1570077947.635 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:45:50.871Z,1570077950.871 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:45:53.687Z,1570077953.687 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:45:56.532Z,1570077956.532 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-10-03T04:45:56.956Z,1570077956.956 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:45:59.439Z,1570077959.439 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-10-03T04:45:59.765Z,1570077959.765 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:46:02.979Z,1570077962.979 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:46:05.819Z,1570077965.819 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:46:09.047Z,1570077969.047 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:46:11.875Z,1570077971.875 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:46:14.728Z,1570077974.728 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-10-03T04:46:15.103Z,1570077975.103 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:46:17.927Z,1570077977.927 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:46:20.757Z,1570077980.757 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:46:23.587Z,1570077983.587 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:46:26.819Z,1570077986.819 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:46:29.643Z,1570077989.643 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:46:30.053Z,1570077990.053 [DVL_micro](ERROR): only read 3 of 4 data items
2019-10-03T04:46:30.053Z,1570077990.053 [DVL_micro](ERROR): Failed to parse:
:BI,-00919,-0733,+00000,I
2019-10-03T04:46:32.507Z,1570077992.507 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-10-03T04:46:32.875Z,1570077992.875 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:46:35.703Z,1570077995.703 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:46:38.935Z,1570077998.935 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:46:41.764Z,1570078001.764 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:46:44.998Z,1570078004.998 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:46:47.835Z,1570078007.835 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:46:50.663Z,1570078010.663 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-10-03T04:46:51.055Z,1570078011.055 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:46:53.883Z,1570078013.883 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:46:57.115Z,1570078017.115 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:46:59.200Z,1570078019.200 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-10-03T04:41:59.0Z
2019-10-03T04:46:59.200Z,1570078019.200 [Default:CheckIn:Read_GPS] Stopped
2019-10-03T04:46:59.200Z,1570078019.200 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-10-03T04:46:59.618Z,1570078019.618 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-10-03T04:47:00.028Z,1570078020.028 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:47:02.832Z,1570078022.832 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:47:05.655Z,1570078025.655 [DVL_micro](ERROR): Failed to parse:
:SA,-01.00,-03.00,139.6
2019-10-03T04:47:05.667Z,1570078025.667 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:47:08.488Z,1570078028.488 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-10-03T04:47:08.871Z,1570078028.871 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20191003T043808/Courier0004.lzma
2019-10-03T04:47:08.899Z,1570078028.899 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:47:10.877Z,1570078030.877 [DataOverHttps](INFO): Moved sent file to Logs/20191003T043808/Courier0004.lzma.bak
2019-10-03T04:47:10.877Z,1570078030.877 [DataOverHttps](INFO): SBD MOMSN=11842803
2019-10-03T04:47:11.719Z,1570078031.719 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:47:14.951Z,1570078034.951 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:47:17.778Z,1570078037.778 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:47:21.027Z,1570078041.027 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:47:22.641Z,1570078042.641 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2019-10-03T04:47:22.641Z,1570078042.641 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-10-03T04:47:22.659Z,1570078042.659 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-10-03T04:47:23.060Z,1570078043.060 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-10-03T04:47:23.060Z,1570078043.060 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2019-10-03T04:47:23.835Z,1570078043.835 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:47:26.268Z,1570078046.268 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-10-03T04:47:27.071Z,1570078047.071 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:47:28.675Z,1570078048.675 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2019-10-03T04:47:28.675Z,1570078048.675 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+1.0,1489.0,000
2019-10-03T04:47:29.899Z,1570078049.899 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:47:30.224Z,1570078050.224 [DataOverHttps](INFO): Sending 784 bytes from file Logs/20191003T043808/Express0001.lzma
2019-10-03T04:47:32.229Z,1570078052.229 [DataOverHttps](INFO): Moved sent file to Logs/20191003T043808/Express0001.lzma.bak
2019-10-03T04:47:32.229Z,1570078052.229 [DataOverHttps](INFO): SBD MOMSN=11842806
2019-10-03T04:47:32.726Z,1570078052.726 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:47:35.567Z,1570078055.567 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:47:38.807Z,1570078058.807 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:47:41.611Z,1570078061.611 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:47:44.110Z,1570078064.110 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-10-03T04:47:44.847Z,1570078064.847 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:47:47.675Z,1570078067.675 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:47:50.910Z,1570078070.910 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:47:51.543Z,1570078071.543 [DataOverHttps](INFO): Sending 176 bytes from file Logs/20191003T043808/Express0005.lzma
2019-10-03T04:47:53.549Z,1570078073.549 [DataOverHttps](INFO): Moved sent file to Logs/20191003T043808/Express0005.lzma.bak
2019-10-03T04:47:53.549Z,1570078073.549 [DataOverHttps](INFO): SBD MOMSN=11842824
2019-10-03T04:47:53.755Z,1570078073.755 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:47:56.963Z,1570078076.963 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:47:57.409Z,1570078077.409 [Default:CheckIn:Read_Iridium] Stopped
2019-10-03T04:47:57.409Z,1570078077.409 [Default:CheckIn:C.Wait] Running Loop=1
2019-10-03T04:47:57.409Z,1570078077.409 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-10-03T04:47:59.795Z,1570078079.795 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:48:03.019Z,1570078083.019 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:48:05.859Z,1570078085.859 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:48:09.103Z,1570078089.103 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:48:11.963Z,1570078091.963 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:48:14.739Z,1570078094.739 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:48:17.594Z,1570078097.594 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:48:20.803Z,1570078100.803 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:48:23.634Z,1570078103.634 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:48:26.883Z,1570078106.883 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:48:29.707Z,1570078109.707 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:48:32.923Z,1570078112.923 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:48:35.747Z,1570078115.747 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:48:38.979Z,1570078118.979 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:48:41.814Z,1570078121.814 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:48:41.889Z,1570078121.889 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-10-03T04:48:45.043Z,1570078125.043 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:48:47.879Z,1570078127.879 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:48:50.707Z,1570078130.707 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:48:53.931Z,1570078133.931 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:48:56.759Z,1570078136.759 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:48:59.573Z,1570078139.573 [NAL9602](FAULT): GPS failed to acquire within timeout.
2019-10-03T04:48:59.574Z,1570078139.574 [NAL9602] Data Fault, FailCount= 1
2019-10-03T04:48:59.574Z,1570078139.574 [NAL9602](ERROR): Data Fault
2019-10-03T04:48:59.646Z,1570078139.646 [CBIT](ERROR): Data Fault in component: NAL9602
2019-10-03T04:48:59.988Z,1570078139.988 [NAL9602](INFO): Powering down
2019-10-03T04:49:00.817Z,1570078140.817 [CBIT](INFO): Clearing failed state for component NAL9602
2019-10-03T04:49:00.818Z,1570078140.818 [NAL9602] No Fault, FailCount= 1
2019-10-03T04:49:26.367Z,1570078166.367 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-10-03T04:49:30.277Z,1570078170.277 [NAL9602](INFO): Powering up NAL9602
2019-10-03T04:49:41.185Z,1570078181.185 [NAL9602](INFO): NAL9602 initialized
2019-10-03T04:49:42.007Z,1570078182.007 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:49:44.431Z,1570078184.431 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:49:47.659Z,1570078187.659 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:49:50.491Z,1570078190.491 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:49:53.723Z,1570078193.723 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:49:56.550Z,1570078196.550 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:49:59.391Z,1570078199.391 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:50:01.396Z,1570078201.396 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:50:02.232Z,1570078202.232 [BPC1](ERROR): BPC1B: No match for serial number 0000 in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2019-10-03T04:50:03.419Z,1570078203.419 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:50:06.651Z,1570078206.651 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:50:09.479Z,1570078209.479 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:50:12.709Z,1570078212.709 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:50:15.543Z,1570078215.543 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:50:16.443Z,1570078216.443 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-10-03T04:50:17.559Z,1570078217.559 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:50:19.575Z,1570078219.575 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:50:22.811Z,1570078222.811 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:50:23.664Z,1570078223.664 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2019-10-03T04:50:23.664Z,1570078223.664 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-10-03T04:50:23.674Z,1570078223.674 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-10-03T04:50:24.096Z,1570078224.096 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-10-03T04:50:24.096Z,1570078224.096 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2019-10-03T04:50:25.639Z,1570078225.639 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:50:28.871Z,1570078228.871 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:50:31.711Z,1570078231.711 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:50:34.523Z,1570078234.523 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:50:36.551Z,1570078236.551 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:50:38.967Z,1570078238.967 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:50:41.812Z,1570078241.812 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:50:45.031Z,1570078245.031 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:50:45.103Z,1570078245.103 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-10-03T04:50:47.863Z,1570078247.863 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:50:50.699Z,1570078250.699 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:50:53.514Z,1570078253.514 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:50:55.535Z,1570078255.535 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:50:58.763Z,1570078258.763 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:51:01.599Z,1570078261.599 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:51:04.813Z,1570078264.813 [DVL_micro](ERROR): Failed to parse:
:WI,-01907,+00792,-00559,+00000,A
2019-10-03T04:51:04.831Z,1570078264.831 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:51:07.659Z,1570078267.659 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:51:10.899Z,1570078270.899 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:51:13.719Z,1570078273.719 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:51:16.543Z,1570078276.543 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:51:19.775Z,1570078279.775 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:51:22.627Z,1570078282.627 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:51:25.834Z,1570078285.834 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:51:28.663Z,1570078288.663 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:51:31.900Z,1570078291.900 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:51:34.310Z,1570078294.310 [CommandLine](IMPORTANT): got command restart application
2019-10-03T04:51:34.719Z,1570078294.719 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:51:35.315Z,1570078295.315 [Supervisor](INFO): Stop Mission called by Supervisor::terminate
2019-10-03T04:51:35.316Z,1570078295.316 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2019-10-03T04:51:35.316Z,1570078295.316 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-10-03T04:51:35.331Z,1570078295.331 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2019-10-03T04:51:35.331Z,1570078295.331 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-10-03T04:51:35.332Z,1570078295.332 [CommandLine](INFO): Join timeout helper Thread ID is 946
2019-10-03T04:51:35.333Z,1570078295.333 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2019-10-03T04:51:35.333Z,1570078295.333 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-10-03T04:51:35.333Z,1570078295.333 [NavChartDb](INFO): Join timeout helper Thread ID is 947
2019-10-03T04:51:35.459Z,1570078295.459 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2019-10-03T04:51:35.460Z,1570078295.460 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-10-03T04:51:35.475Z,1570078295.475 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2019-10-03T04:51:35.475Z,1570078295.475 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-10-03T04:51:35.476Z,1570078295.476 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 948
2019-10-03T04:51:35.812Z,1570078295.812 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2019-10-03T04:51:35.812Z,1570078295.812 [WetLabsBB2FL](INFO): Powering down
2019-10-03T04:51:35.813Z,1570078295.813 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-10-03T04:51:35.819Z,1570078295.819 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2019-10-03T04:51:35.819Z,1570078295.819 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2019-10-03T04:51:35.820Z,1570078295.820 [CTD_Seabird](INFO): Join timeout helper Thread ID is 949
2019-10-03T04:51:36.624Z,1570078296.624 [CTD_Seabird](INFO): Powering down
2019-10-03T04:51:36.635Z,1570078296.635 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2019-10-03T04:51:36.636Z,1570078296.636 [CTD_Seabird](INFO): Powering down
2019-10-03T04:51:36.647Z,1570078296.647 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2019-10-03T04:51:36.663Z,1570078296.663 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2019-10-03T04:51:36.663Z,1570078296.663 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-10-03T04:51:36.664Z,1570078296.664 [Radio_Surface](INFO): Join timeout helper Thread ID is 950
2019-10-03T04:51:36.999Z,1570078296.999 [Radio_Surface](INFO): Powering down
2019-10-03T04:51:37.000Z,1570078297.000 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2019-10-03T04:51:37.000Z,1570078297.000 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-10-03T04:51:37.012Z,1570078297.012 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2019-10-03T04:51:37.012Z,1570078297.012 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-10-03T04:51:37.013Z,1570078297.013 [DataOverHttps](INFO): Join timeout helper Thread ID is 951
2019-10-03T04:51:37.547Z,1570078297.547 [NAL9602](DEBUG): Fix Requested
2019-10-03T04:51:37.939Z,1570078297.939 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2019-10-03T04:51:37.940Z,1570078297.940 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-10-03T04:51:37.952Z,1570078297.952 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2019-10-03T04:51:37.952Z,1570078297.952 [logger ThreadHandler](INFO): Thread cancelled.
2019-10-03T04:51:37.953Z,1570078297.953 [logger](INFO): Join timeout helper Thread ID is 952
2019-10-03T04:51:37.973Z,1570078297.973 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2019-10-03T04:51:37.973Z,1570078297.973 [logger ThreadHandler](INFO): Thread cancelled.
2019-10-03T04:51:37.976Z,1570078297.976 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2019-10-03T04:51:37.976Z,1570078297.976 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-10-03T04:51:37.976Z,1570078297.976 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2019-10-03T04:51:37.976Z,1570078297.976 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-10-03T04:51:37.976Z,1570078297.976 [controlThread](INFO): Join timeout helper Thread ID is 953
2019-10-03T04:51:38.005Z,1570078298.005 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2019-10-03T04:51:38.005Z,1570078298.005 [controlThread](DEBUG): Uninitializing ControlThread
2019-10-03T04:51:38.005Z,1570078298.005 [AHRS_M2](INFO): Powering down
2019-10-03T04:51:38.147Z,1570078298.147 [DVL_micro](INFO): Powering down
2019-10-03T04:51:38.148Z,1570078298.148 [NAL9602](INFO): Powering down
2019-10-03T04:51:38.149Z,1570078298.149 [DAT](INFO): Powering down
2019-10-03T04:51:38.288Z,1570078298.288 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2019-10-03T04:51:38.289Z,1570078298.289 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2019-10-03T04:51:38.290Z,1570078298.290 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2019-10-03T04:51:38.290Z,1570078298.290 [MissionManager](INFO): Uninitializing Mission Default
2019-10-03T04:51:38.290Z,1570078298.290 [Default] Stopped
2019-10-03T04:51:38.290Z,1570078298.290 [Default](DEBUG): Aggregate::uninitialize Default
2019-10-03T04:51:38.290Z,1570078298.290 [Default:B.GoToSurface] Stopped
2019-10-03T04:51:38.290Z,1570078298.290 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-10-03T04:51:38.291Z,1570078298.291 [Default:CheckIn] Stopped
2019-10-03T04:51:38.291Z,1570078298.291 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-10-03T04:51:38.291Z,1570078298.291 [Default:CheckIn:C.Wait] Stopped
2019-10-03T04:51:38.291Z,1570078298.291 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-10-03T04:51:38.293Z,1570078298.293 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2019-10-03T04:51:38.293Z,1570078298.293 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2019-10-03T04:51:38.294Z,1570078298.294 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2019-10-03T04:51:38.294Z,1570078298.294 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2019-10-03T04:51:38.294Z,1570078298.294 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2019-10-03T04:51:38.294Z,1570078298.294 [BuoyancyServo](INFO): Powering down
2019-10-03T04:51:38.307Z,1570078298.307 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2019-10-03T04:51:38.307Z,1570078298.307 [ElevatorServo](INFO): Powering down
2019-10-03T04:51:38.308Z,1570078298.308 [MassServo](DEBUG): Uninitialize Mass Servo.
2019-10-03T04:51:38.308Z,1570078298.308 [MassServo](INFO): Powering down
2019-10-03T04:51:38.309Z,1570078298.309 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-10-03T04:51:38.309Z,1570078298.309 [RudderServo](INFO): Powering down
2019-10-03T04:51:38.310Z,1570078298.310 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2019-10-03T04:51:38.310Z,1570078298.310 [ThrusterServo](INFO): Powering down
2019-10-03T04:51:38.311Z,1570078298.311 [SBIT](DEBUG): Uninitialize SBIT Component.
2019-10-03T04:51:38.311Z,1570078298.311 [IBIT](DEBUG): Uninitialize IBIT Component.
2019-10-03T04:51:38.312Z,1570078298.312 [CBIT](DEBUG): Uninitialize CBIT Component.
2019-10-03T04:51:38.312Z,1570078298.312 [CBIT](DEBUG): Powering off loads.
2019-10-03T04:51:38.323Z,1570078298.323 [CBIT](DEBUG): Disabling WDT.
2019-10-03T04:51:38.335Z,1570078298.335 [CBIT](DEBUG): Opening all GF detection circuits.
2019-10-03T04:51:38.336Z,1570078298.336 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-10-03T04:51:38.425Z,1570078298.425 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-10-03T04:51:38.432Z,1570078298.432 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-10-03T04:51:38.468Z,1570078298.468 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-10-03T04:51:38.473Z,1570078298.473 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2019-10-03T04:51:38.506Z,1570078298.506 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-10-03T04:51:38.564Z,1570078298.564 [logger ThreadHandler](INFO): Thread cancelled.