2019-10-03T16:01:29.086Z,1570118489.086 [Supervisor](DEBUG): Initializing supervisor.
2019-10-03T16:01:29.088Z,1570118489.088 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2019-10-03T16:01:29.089Z,1570118489.089 [SyncHandler](INFO): Protected caller Thread ID is 5526
2019-10-03T16:01:29.089Z,1570118489.089 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2019-10-03T16:01:29.090Z,1570118489.090 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2019-10-03T16:01:29.091Z,1570118489.091 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 5527
2019-10-03T16:01:29.093Z,1570118489.093 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2019-10-03T16:01:29.104Z,1570118489.104 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2019-10-03T16:01:29.105Z,1570118489.105 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2019-10-03T16:01:29.105Z,1570118489.105 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 5528
2019-10-03T16:01:29.106Z,1570118489.106 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2019-10-03T16:01:29.107Z,1570118489.107 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2019-10-03T16:01:29.107Z,1570118489.107 [logger ThreadHandler](INFO): Protected caller Thread ID is 5529
2019-10-03T16:01:29.109Z,1570118489.109 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2019-10-03T16:01:29.110Z,1570118489.110 [Supervisor](INFO): Looking for Config files in directory: Config/
2019-10-03T16:01:29.111Z,1570118489.111 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2019-10-03T16:01:29.207Z,1570118489.207 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2019-10-03T16:01:29.207Z,1570118489.207 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2019-10-03T16:01:29.774Z,1570118489.774 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2019-10-03T16:01:29.774Z,1570118489.774 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2019-10-03T16:01:29.872Z,1570118489.872 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2019-10-03T16:01:29.873Z,1570118489.873 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2019-10-03T16:01:29.975Z,1570118489.975 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2019-10-03T16:01:29.976Z,1570118489.976 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2019-10-03T16:01:30.058Z,1570118490.058 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2019-10-03T16:01:30.197Z,1570118490.197 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2019-10-03T16:01:30.198Z,1570118490.198 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2019-10-03T16:01:30.501Z,1570118490.501 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2019-10-03T16:01:30.502Z,1570118490.502 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2019-10-03T16:01:30.961Z,1570118490.961 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2019-10-03T16:01:30.962Z,1570118490.962 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2019-10-03T16:01:31.106Z,1570118491.106 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2019-10-03T16:01:31.107Z,1570118491.107 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2019-10-03T16:01:31.296Z,1570118491.296 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2019-10-03T16:01:31.297Z,1570118491.297 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2019-10-03T16:01:31.753Z,1570118491.753 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2019-10-03T16:01:31.754Z,1570118491.754 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2019-10-03T16:01:31.963Z,1570118491.963 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2019-10-03T16:01:31.964Z,1570118491.964 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2019-10-03T16:01:32.235Z,1570118492.235 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2019-10-03T16:01:32.235Z,1570118492.235 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2019-10-03T16:01:32.649Z,1570118492.649 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2019-10-03T16:01:32.649Z,1570118492.649 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2019-10-03T16:01:32.985Z,1570118492.985 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2019-10-03T16:01:32.988Z,1570118492.988 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-pontus/
2019-10-03T16:01:32.988Z,1570118492.988 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/secure.cfg
2019-10-03T16:01:33.072Z,1570118493.072 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Sensor.cfg
2019-10-03T16:01:33.227Z,1570118493.227 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Servo.cfg
2019-10-03T16:01:33.335Z,1570118493.335 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Simulator.cfg
2019-10-03T16:01:33.421Z,1570118493.421 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/logger.cfg
2019-10-03T16:01:33.516Z,1570118493.516 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/vehicle.cfg
2019-10-03T16:01:33.710Z,1570118493.710 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Battery.cfg
2019-10-03T16:01:33.936Z,1570118493.936 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2019-10-03T16:01:33.937Z,1570118493.937 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Navigation.cfg
2019-10-03T16:01:34.032Z,1570118494.032 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/BIT.cfg
2019-10-03T16:01:34.141Z,1570118494.141 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Science.cfg
2019-10-03T16:01:34.489Z,1570118494.489 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Control.cfg
2019-10-03T16:01:34.802Z,1570118494.802 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-pontus/root/
2019-10-03T16:01:34.802Z,1570118494.802 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2019-10-03T16:01:34.811Z,1570118494.811 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2019-10-03T16:01:34.886Z,1570118494.886 [VerticalControl](DEBUG): Construct VerticalControl.
2019-10-03T16:01:35.142Z,1570118495.142 [VerticalControl] Loaded
2019-10-03T16:01:35.143Z,1570118495.143 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2019-10-03T16:01:35.143Z,1570118495.143 [HorizontalControl](DEBUG): Construct HorizontalControl.
2019-10-03T16:01:35.212Z,1570118495.212 [HorizontalControl] Loaded
2019-10-03T16:01:35.213Z,1570118495.213 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2019-10-03T16:01:35.213Z,1570118495.213 [SpeedControl](DEBUG): Construct SpeedControl.
2019-10-03T16:01:35.219Z,1570118495.219 [SpeedControl] Loaded
2019-10-03T16:01:35.219Z,1570118495.219 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2019-10-03T16:01:35.220Z,1570118495.220 [LoopControl](DEBUG): Construct LoopControl.
2019-10-03T16:01:35.220Z,1570118495.220 [LoopControl] Loaded
2019-10-03T16:01:35.220Z,1570118495.220 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2019-10-03T16:01:35.221Z,1570118495.221 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2019-10-03T16:01:35.221Z,1570118495.221 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2019-10-03T16:01:35.357Z,1570118495.357 [DepthRateCalculator] Loaded
2019-10-03T16:01:35.357Z,1570118495.357 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2019-10-03T16:01:35.362Z,1570118495.362 [PitchRateCalculator] Loaded
2019-10-03T16:01:35.363Z,1570118495.363 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2019-10-03T16:01:35.378Z,1570118495.378 [SpeedCalculator] Loaded
2019-10-03T16:01:35.378Z,1570118495.378 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2019-10-03T16:01:35.399Z,1570118495.399 [TempGradientCalculator] Loaded
2019-10-03T16:01:35.400Z,1570118495.400 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2019-10-03T16:01:35.405Z,1570118495.405 [YawRateCalculator] Loaded
2019-10-03T16:01:35.405Z,1570118495.405 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2019-10-03T16:01:35.434Z,1570118495.434 [ElevatorOffsetCalculator] Loaded
2019-10-03T16:01:35.435Z,1570118495.435 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2019-10-03T16:01:35.435Z,1570118495.435 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2019-10-03T16:01:35.435Z,1570118495.435 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2019-10-03T16:01:35.468Z,1570118495.468 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2019-10-03T16:01:35.468Z,1570118495.468 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2019-10-03T16:01:35.537Z,1570118495.537 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2019-10-03T16:01:35.538Z,1570118495.538 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2019-10-03T16:01:35.826Z,1570118495.826 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2019-10-03T16:01:35.827Z,1570118495.827 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2019-10-03T16:01:35.924Z,1570118495.924 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2019-10-03T16:01:35.925Z,1570118495.925 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2019-10-03T16:01:36.163Z,1570118496.163 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_orientation
2019-10-03T16:01:36.168Z,1570118496.168 [AHRS_M2](INFO): created writer for : platform_orientation
2019-10-03T16:01:36.169Z,1570118496.169 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_magnetic_orientation
2019-10-03T16:01:36.175Z,1570118496.175 [AHRS_M2](INFO): created writer for : platform_magnetic_orientation
2019-10-03T16:01:36.175Z,1570118496.175 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_pitch_angle
2019-10-03T16:01:36.180Z,1570118496.180 [AHRS_M2](INFO): created writer for : platform_pitch_angle
2019-10-03T16:01:36.181Z,1570118496.181 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_roll_angle
2019-10-03T16:01:36.186Z,1570118496.186 [AHRS_M2](INFO): created writer for : platform_roll_angle
2019-10-03T16:01:36.258Z,1570118496.258 [AHRS_M2] Loaded
2019-10-03T16:01:36.258Z,1570118496.258 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2019-10-03T16:01:36.330Z,1570118496.330 [DataOverHttps] Loaded
2019-10-03T16:01:36.330Z,1570118496.330 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2019-10-03T16:01:36.331Z,1570118496.331 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 408B14E0
2019-10-03T16:01:36.332Z,1570118496.332 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 5609
2019-10-03T16:01:36.345Z,1570118496.345 [Depth_Keller] Loaded
2019-10-03T16:01:36.345Z,1570118496.345 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2019-10-03T16:01:36.350Z,1570118496.350 [DropWeight] Loaded
2019-10-03T16:01:36.350Z,1570118496.350 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2019-10-03T16:01:36.448Z,1570118496.448 [NAL9602] Loaded
2019-10-03T16:01:36.448Z,1570118496.448 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2019-10-03T16:01:36.464Z,1570118496.464 [Onboard] Loaded
2019-10-03T16:01:36.464Z,1570118496.464 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2019-10-03T16:01:36.467Z,1570118496.467 [Radio_Surface] Loaded
2019-10-03T16:01:36.468Z,1570118496.468 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2019-10-03T16:01:36.469Z,1570118496.469 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408E14E0
2019-10-03T16:01:36.469Z,1570118496.469 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 5610
2019-10-03T16:01:36.513Z,1570118496.513 [RDI_Pathfinder] Loaded
2019-10-03T16:01:36.513Z,1570118496.513 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2019-10-03T16:01:36.639Z,1570118496.639 [DAT] Loaded
2019-10-03T16:01:36.639Z,1570118496.639 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread.
2019-10-03T16:01:38.149Z,1570118498.149 [BPC1] Loaded
2019-10-03T16:01:38.150Z,1570118498.150 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2019-10-03T16:01:38.150Z,1570118498.150 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2019-10-03T16:01:38.151Z,1570118498.151 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2019-10-03T16:01:38.252Z,1570118498.252 [DeadReckonUsingMultipleVelocitySources] Loaded
2019-10-03T16:01:38.252Z,1570118498.252 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2019-10-03T16:01:38.273Z,1570118498.273 [NavChart] Loaded
2019-10-03T16:01:38.273Z,1570118498.273 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2019-10-03T16:01:38.277Z,1570118498.277 [UniversalFixResidualReporter] Loaded
2019-10-03T16:01:38.277Z,1570118498.277 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2019-10-03T16:01:38.278Z,1570118498.278 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2019-10-03T16:01:38.278Z,1570118498.278 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2019-10-03T16:01:38.414Z,1570118498.414 [SBIT](DEBUG): Construct Startup Built In Test.
2019-10-03T16:01:38.425Z,1570118498.425 [SBIT] Loaded
2019-10-03T16:01:38.425Z,1570118498.425 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2019-10-03T16:01:38.426Z,1570118498.426 [IBIT](DEBUG): Construct Initiated Built In Test.
2019-10-03T16:01:38.437Z,1570118498.437 [IBIT] Loaded
2019-10-03T16:01:38.437Z,1570118498.437 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2019-10-03T16:01:38.440Z,1570118498.440 [CBIT](DEBUG): Construct Continuous Built In Test.
2019-10-03T16:01:38.577Z,1570118498.577 [CBIT] Loaded
2019-10-03T16:01:38.577Z,1570118498.577 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2019-10-03T16:01:38.578Z,1570118498.578 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2019-10-03T16:01:38.578Z,1570118498.578 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2019-10-03T16:01:38.681Z,1570118498.681 [BuoyancyServo] Loaded
2019-10-03T16:01:38.682Z,1570118498.682 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2019-10-03T16:01:38.693Z,1570118498.693 [ElevatorServo] Loaded
2019-10-03T16:01:38.693Z,1570118498.693 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2019-10-03T16:01:38.704Z,1570118498.704 [MassServo] Loaded
2019-10-03T16:01:38.704Z,1570118498.704 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2019-10-03T16:01:38.715Z,1570118498.715 [RudderServo] Loaded
2019-10-03T16:01:38.715Z,1570118498.715 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2019-10-03T16:01:38.727Z,1570118498.727 [ThrusterServo] Loaded
2019-10-03T16:01:38.727Z,1570118498.727 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2019-10-03T16:01:38.728Z,1570118498.728 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2019-10-03T16:01:38.728Z,1570118498.728 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2019-10-03T16:01:38.741Z,1570118498.741 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2019-10-03T16:01:38.742Z,1570118498.742 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2019-10-03T16:01:38.953Z,1570118498.953 [BackSeatDriver] Loaded
2019-10-03T16:01:38.953Z,1570118498.953 [ComponentRegistry](DEBUG): Component "BackSeatDriver" handled in its own thread.
2019-10-03T16:01:38.955Z,1570118498.955 [BackSeatDriver ThreadHandler](DEBUG): Created PCaller Thread at 40A654E0
2019-10-03T16:01:38.955Z,1570118498.955 [BackSeatDriver ThreadHandler](INFO): Protected caller Thread ID is 5611
2019-10-03T16:01:38.964Z,1570118498.964 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density
2019-10-03T16:01:38.970Z,1570118498.970 [CTD_Seabird](INFO): created writer for : sea_water_density
2019-10-03T16:01:38.970Z,1570118498.970 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth
2019-10-03T16:01:38.975Z,1570118498.975 [CTD_Seabird](INFO): created writer for : depth
2019-10-03T16:01:38.976Z,1570118498.976 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure
2019-10-03T16:01:38.981Z,1570118498.981 [CTD_Seabird](INFO): created writer for : sea_water_pressure
2019-10-03T16:01:38.981Z,1570118498.981 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity
2019-10-03T16:01:38.987Z,1570118498.987 [CTD_Seabird](INFO): created writer for : sea_water_salinity
2019-10-03T16:01:38.987Z,1570118498.987 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature
2019-10-03T16:01:38.992Z,1570118498.992 [CTD_Seabird](INFO): created writer for : sea_water_temperature
2019-10-03T16:01:38.993Z,1570118498.993 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity
2019-10-03T16:01:38.999Z,1570118498.999 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity
2019-10-03T16:01:38.999Z,1570118498.999 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water
2019-10-03T16:01:39.005Z,1570118499.005 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water
2019-10-03T16:01:39.031Z,1570118499.031 [CTD_Seabird] Loaded
2019-10-03T16:01:39.032Z,1570118499.032 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2019-10-03T16:01:39.033Z,1570118499.033 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40A954E0
2019-10-03T16:01:39.033Z,1570118499.033 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 5612
2019-10-03T16:01:39.040Z,1570118499.040 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output470
2019-10-03T16:01:39.040Z,1570118499.040 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output470
2019-10-03T16:01:39.044Z,1570118499.044 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output650
2019-10-03T16:01:39.045Z,1570118499.045 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output650
2019-10-03T16:01:39.049Z,1570118499.049 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.OutputChl
2019-10-03T16:01:39.049Z,1570118499.049 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: OutputChl
2019-10-03T16:01:39.053Z,1570118499.053 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg470nm
2019-10-03T16:01:39.054Z,1570118499.054 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg470nm
2019-10-03T16:01:39.058Z,1570118499.058 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg650nm
2019-10-03T16:01:39.058Z,1570118499.058 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg650nm
2019-10-03T16:01:39.063Z,1570118499.063 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff470nm
2019-10-03T16:01:39.063Z,1570118499.063 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff470nm
2019-10-03T16:01:39.067Z,1570118499.067 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff650nm
2019-10-03T16:01:39.067Z,1570118499.067 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff650nm
2019-10-03T16:01:39.071Z,1570118499.071 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): mass_concentration_of_chlorophyll_in_sea_water
2019-10-03T16:01:39.076Z,1570118499.076 [WetLabsBB2FL](INFO): created writer for : mass_concentration_of_chlorophyll_in_sea_water
2019-10-03T16:01:39.076Z,1570118499.076 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_median_mass_concentration_of_chlorophyll_in_sea_water
2019-10-03T16:01:39.076Z,1570118499.076 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_median_mass_concentration_of_chlorophyll_in_sea_water
2019-10-03T16:01:39.081Z,1570118499.081 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water
2019-10-03T16:01:39.081Z,1570118499.081 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_mean_mass_concentration_of_chlorophyll_in_sea_water
2019-10-03T16:01:39.085Z,1570118499.085 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_variance_mass_concentration_of_chlorophyll_in_sea_water
2019-10-03T16:01:39.085Z,1570118499.085 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_variance_mass_concentration_of_chlorophyll_in_sea_water
2019-10-03T16:01:39.090Z,1570118499.090 [WetLabsBB2FL] Loaded
2019-10-03T16:01:39.090Z,1570118499.090 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2019-10-03T16:01:39.091Z,1570118499.091 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40AC54E0
2019-10-03T16:01:39.092Z,1570118499.092 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 5613
2019-10-03T16:01:39.108Z,1570118499.108 [WetLabsUBAT..SerialDriver](INFO): Created logger
2019-10-03T16:01:39.108Z,1570118499.108 [WetLabsUBAT..SerialDriver](INFO): publishing on LCM channel WetLabsUBAT
2019-10-03T16:01:39.109Z,1570118499.109 [WetLabsUBAT..StreamSerialDriver](INFO): Created logger
2019-10-03T16:01:39.114Z,1570118499.114 [WetLabsUBAT](INFO): readConfig(): serialNo_: UBAT0051, uartName_: /dev/ttyC1, optionalArgs_: -ldir /mnt/mmc/LRAUV/Logs/latest
2019-10-03T16:01:39.114Z,1570118499.114 [WetLabsUBAT](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsUBAT.biolum_potential
2019-10-03T16:01:39.114Z,1570118499.114 [WetLabsUBAT](DEBUG): LcmSlateWriter::add(): dataName: biolum_potential
2019-10-03T16:01:39.119Z,1570118499.119 [WetLabsUBAT](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsUBAT.flow_rate
2019-10-03T16:01:39.119Z,1570118499.119 [WetLabsUBAT](DEBUG): LcmSlateWriter::add(): dataName: flow_rate
2019-10-03T16:01:39.124Z,1570118499.124 [WetLabsUBAT] Loaded
2019-10-03T16:01:39.124Z,1570118499.124 [ComponentRegistry](DEBUG): Component "WetLabsUBAT" handled in its own thread.
2019-10-03T16:01:39.125Z,1570118499.125 [WetLabsUBAT ThreadHandler](DEBUG): Created PCaller Thread at 40AF54E0
2019-10-03T16:01:39.125Z,1570118499.125 [WetLabsUBAT ThreadHandler](INFO): Protected caller Thread ID is 5614
2019-10-03T16:01:39.126Z,1570118499.126 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2019-10-03T16:01:39.129Z,1570118499.129 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2019-10-03T16:01:39.130Z,1570118499.130 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2019-10-03T16:01:39.137Z,1570118499.137 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2019-10-03T16:01:39.138Z,1570118499.138 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B254E0
2019-10-03T16:01:39.138Z,1570118499.138 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 5615
2019-10-03T16:01:39.149Z,1570118499.149 [Supervisor](INFO): Main Thread ID is 5525
2019-10-03T16:01:39.149Z,1570118499.149 [Supervisor](DEBUG): Running supervisor.
2019-10-03T16:01:39.149Z,1570118499.149 [CommandLine ThreadHandler](INFO): Handler Thread ID is 5616
2019-10-03T16:01:39.155Z,1570118499.155 [controlThread ThreadHandler](INFO): Handler Thread ID is 5617
2019-10-03T16:01:39.156Z,1570118499.156 [controlThread](DEBUG): Initializing ControlThread
2019-10-03T16:01:39.156Z,1570118499.156 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2019-10-03T16:01:39.158Z,1570118499.158 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2019-10-03T16:01:39.158Z,1570118499.158 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2019-10-03T16:01:39.159Z,1570118499.159 [LoopControl](DEBUG): Initialize LoopControlComponent.
2019-10-03T16:01:39.159Z,1570118499.159 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2019-10-03T16:01:39.159Z,1570118499.159 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2019-10-03T16:01:39.160Z,1570118499.160 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2019-10-03T16:01:39.160Z,1570118499.160 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2019-10-03T16:01:39.160Z,1570118499.160 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2019-10-03T16:01:39.161Z,1570118499.161 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2019-10-03T16:01:39.166Z,1570118499.166 [NavChart](DEBUG): Initialize NavChart Navigation.
2019-10-03T16:01:39.166Z,1570118499.166 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2019-10-03T16:01:39.167Z,1570118499.167 [SBIT](INFO): Initialize SBIT Component.
2019-10-03T16:01:39.167Z,1570118499.167 [SBIT](IMPORTANT): git: 2019-10-03_bsd
2019-10-03T16:01:39.167Z,1570118499.167 [SBIT](INFO): git hash: c0737ec0000e1c9d4bf2eea0c11ce458bb27ad8a
2019-10-03T16:01:39.168Z,1570118499.168 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2019-10-03T16:01:39.168Z,1570118499.168 [SBIT](IMPORTANT): Kernel Version:#1 PREEMPT Thu Feb 21 11:17:40 PST 2019
2019-10-03T16:01:39.169Z,1570118499.169 [SBIT](INFO): Beginning SBIT in 59.000000 seconds.
2019-10-03T16:01:39.169Z,1570118499.169 [IBIT](INFO): Initialize IBIT Component.
2019-10-03T16:01:39.170Z,1570118499.170 [CBIT](DEBUG): Initialize CBIT Component.
2019-10-03T16:01:39.172Z,1570118499.172 [logger ThreadHandler](INFO): Handler Thread ID is 5618
2019-10-03T16:01:39.182Z,1570118499.182 [CBIT](DEBUG): Initialized mux pins.
2019-10-03T16:01:39.182Z,1570118499.182 [CBIT](DEBUG): Initializing the watchdog timer.
2019-10-03T16:01:39.191Z,1570118499.191 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 5619
2019-10-03T16:01:39.192Z,1570118499.192 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2019-10-03T16:01:39.203Z,1570118499.203 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 5620
2019-10-03T16:01:39.206Z,1570118499.206 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2019-10-03T16:01:39.206Z,1570118499.206 [CBIT](DEBUG): Initializing heartbeat.
2019-10-03T16:01:39.215Z,1570118499.215 [BackSeatDriver ThreadHandler](INFO): Handler Thread ID is 5621
2019-10-03T16:01:39.223Z,1570118499.223 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 5622
2019-10-03T16:01:39.223Z,1570118499.223 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2019-10-03T16:01:39.227Z,1570118499.227 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20
2019-10-03T16:01:39.228Z,1570118499.228 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 5624
2019-10-03T16:01:39.229Z,1570118499.229 [WetLabsBB2FL](INFO): Powering down
2019-10-03T16:01:39.259Z,1570118499.259 [WetLabsUBAT ThreadHandler](INFO): Handler Thread ID is 5625
2019-10-03T16:01:39.268Z,1570118499.268 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 5626
2019-10-03T16:01:39.271Z,1570118499.271 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2019-10-03T16:01:39.271Z,1570118499.271 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2019-10-03T16:01:39.272Z,1570118499.272 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2019-10-03T16:01:39.272Z,1570118499.272 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2019-10-03T16:01:39.272Z,1570118499.272 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2019-10-03T16:01:39.272Z,1570118499.272 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2019-10-03T16:01:39.272Z,1570118499.272 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2019-10-03T16:01:39.273Z,1570118499.273 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2019-10-03T16:01:39.273Z,1570118499.273 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2019-10-03T16:01:39.273Z,1570118499.273 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2019-10-03T16:01:39.273Z,1570118499.273 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2019-10-03T16:01:39.273Z,1570118499.273 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2019-10-03T16:01:39.274Z,1570118499.274 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2019-10-03T16:01:39.274Z,1570118499.274 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2019-10-03T16:01:39.274Z,1570118499.274 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2019-10-03T16:01:39.274Z,1570118499.274 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2019-10-03T16:01:39.278Z,1570118499.278 [CBIT](DEBUG): Deactivating GF circuits.
2019-10-03T16:01:39.278Z,1570118499.278 [CBIT](DEBUG): Deactivating emergency mode.
2019-10-03T16:01:39.314Z,1570118499.314 [CBIT](DEBUG): Backplane powered.
2019-10-03T16:01:39.316Z,1570118499.316 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2019-10-03T16:01:39.326Z,1570118499.326 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2019-10-03T16:01:39.336Z,1570118499.336 [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-03T16:01:39.337Z,1570118499.337 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2019-10-03T16:01:39.403Z,1570118499.403 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2019-10-03T16:01:39.405Z,1570118499.405 [Default:A.Wait](DEBUG): Construct Wait.
2019-10-03T16:01:39.422Z,1570118499.422 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2019-10-03T16:01:39.453Z,1570118499.453 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2019-10-03T16:01:39.456Z,1570118499.456 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2019-10-03T16:01:39.470Z,1570118499.470 [Default:E.Execute](DEBUG): Construct Execute.
2019-10-03T16:01:39.473Z,1570118499.473 [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-03T16:01:39.490Z,1570118499.490 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,NAL9602,Onboard,RDI_Pathfinder,DAT,BPC1,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2019-10-03T16:01:39.513Z,1570118499.513 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2019-10-03T16:01:39.555Z,1570118499.555 [Depth_Keller](ERROR): Pressure reading out of range: 1650.297119 decibar
2019-10-03T16:01:39.581Z,1570118499.581 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2019-10-03T16:01:39.582Z,1570118499.582 [DAT](INFO): Powering up
2019-10-03T16:01:39.582Z,1570118499.582 [DAT](DEBUG): Initializing DAT.
2019-10-03T16:01:39.606Z,1570118499.606 [Radio_Surface](INFO): Powering up
2019-10-03T16:01:39.635Z,1570118499.635 [DepthRateCalculator](ERROR): Depth measurement is not active
2019-10-03T16:01:39.652Z,1570118499.652 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2019-10-03T16:01:39.661Z,1570118499.661 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2019-10-03T16:01:39.683Z,1570118499.683 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2019-10-03T16:01:39.685Z,1570118499.685 [ElevatorServo](DEBUG): Initializing EZServoServo.
2019-10-03T16:01:39.695Z,1570118499.695 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2019-10-03T16:01:39.696Z,1570118499.696 [MassServo](DEBUG): Initializing EZServoServo.
2019-10-03T16:01:39.707Z,1570118499.707 [MassServo](DEBUG): Initializing MassServo.
2019-10-03T16:01:39.708Z,1570118499.708 [RudderServo](DEBUG): Initializing EZServoServo.
2019-10-03T16:01:39.719Z,1570118499.719 [RudderServo](DEBUG): Initializing RudderServo.
2019-10-03T16:01:39.720Z,1570118499.720 [ThrusterServo](DEBUG): Initializing EZServoServo.
2019-10-03T16:01:39.731Z,1570118499.731 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2019-10-03T16:01:39.950Z,1570118499.950 [DepthRateCalculator](ERROR): Depth measurement is not active
2019-10-03T16:01:40.650Z,1570118500.650 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2019-10-03T16:01:40.650Z,1570118500.650 [RudderServo](FAULT): Rudder failed to initialize
2019-10-03T16:01:40.651Z,1570118500.651 [RudderServo] Communications Fault, FailCount= 1
2019-10-03T16:01:40.651Z,1570118500.651 [RudderServo](ERROR): Communications Fault
2019-10-03T16:01:40.762Z,1570118500.762 [CBIT](ERROR): Communications Fault in component: RudderServo
2019-10-03T16:01:40.935Z,1570118500.935 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-10-03T16:01:40.935Z,1570118500.935 [RudderServo](INFO): Powering down
2019-10-03T16:01:41.629Z,1570118501.629 [RudderServo](DEBUG): Initializing EZServoServo.
2019-10-03T16:01:41.748Z,1570118501.748 [RudderServo](DEBUG): Initializing RudderServo.
2019-10-03T16:01:41.752Z,1570118501.752 [CBIT](INFO): Clearing failed state for component RudderServo
2019-10-03T16:01:41.752Z,1570118501.752 [RudderServo] No Fault, FailCount= 1
2019-10-03T16:01:43.122Z,1570118503.122 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout
2019-10-03T16:01:43.503Z,1570118503.503 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout
2019-10-03T16:01:43.982Z,1570118503.982 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout
2019-10-03T16:01:53.252Z,1570118513.252 [RDI_Pathfinder](ERROR): Failed to parse:Pathfinder
2019-10-03T16:01:54.099Z,1570118514.099 [DAT](INFO): setting local address to 4
2019-10-03T16:01:54.200Z,1570118514.200 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004744
2019-10-03T16:01:54.463Z,1570118514.463 [DAT](INFO): set local address to 4
2019-10-03T16:02:06.564Z,1570118526.564 [NAL9602](INFO): Powering up NAL9602
2019-10-03T16:02:08.210Z,1570118528.210 [RDI_Pathfinder](ERROR): Failed to parse:
:BE,-32768,-32768,-32768,V
2019-10-03T16:02:17.472Z,1570118537.472 [NAL9602](INFO): NAL9602 initialized
2019-10-03T16:02:18.314Z,1570118538.314 [NAL9602](DEBUG): Fix Requested
2019-10-03T16:02:32.441Z,1570118552.441 [NAL9602](IMPORTANT): SBD MO Status=0, MOMSN=1895, MT Status=1, MTMSN=53
2019-10-03T16:02:32.441Z,1570118552.441 [NAL9602](INFO): Data available in MT queue
2019-10-03T16:02:33.175Z,1570118553.175 [NAL9602](INFO): Received command:sched asap "load Science/profile_station.xml;set profile_station.NeedCommsTime 20 minute;set profile_station.Lat 36.712110 degree;set profile_station.Lon -122.187028 degree;set profile_station.YoYoMaxDepth 20 meter" 3qjca 1 2
2019-10-03T16:02:33.208Z,1570118553.208 [CommandLine](IMPORTANT): got command schedule asap "load Science/profile_station.xml;set profile_station.NeedCommsTime 20 minute;set profile_station.Lat 36.712110 degree;set profile_station.Lon -122.187028 degree;set profile_station.YoYoMaxDepth 20 meter" 3qjca 1 2.000000
2019-10-03T16:02:33.209Z,1570118553.209 [CommandLine](IMPORTANT): Scheduling command #1 of 2 with id=3qjca
2019-10-03T16:02:33.210Z,1570118553.210 [CommandLine](IMPORTANT): Scheduled #1 (#1 of 2 with id='3qjca'): "load Science/profile_station.xml;set profile_station.NeedCommsTime 20 minute;set profile_station.Lat 36.712110 degree;set profile_station.Lon -122.187028 degree;set profile_station.YoYoMaxDepth 20 meter" ASAP
2019-10-03T16:02:33.746Z,1570118553.746 [NAL9602](DEBUG): Fix Requested
2019-10-03T16:02:36.586Z,1570118556.586 [NAL9602](DEBUG): Fix Requested
2019-10-03T16:02:38.624Z,1570118558.624 [SBIT](IMPORTANT): Beginning Startup BIT
2019-10-03T16:02:38.632Z,1570118558.632 [CBIT](IMPORTANT): Beginning ground fault scan
2019-10-03T16:02:39.402Z,1570118559.402 [NAL9602](DEBUG): Fix Requested
2019-10-03T16:02:42.358Z,1570118562.358 [NAL9602](DEBUG): Fix Requested
2019-10-03T16:02:45.594Z,1570118565.594 [NAL9602](DEBUG): Fix Requested
2019-10-03T16:02:48.418Z,1570118568.418 [NAL9602](DEBUG): Fix Requested
2019-10-03T16:02:49.710Z,1570118569.710 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.002438
CHAN A1 (24V): 0.039754
CHAN A2 (12V): -0.006955
CHAN A3 (5V): -0.001360
CHAN B0 (3.3V): -0.000004
CHAN B1 (3.15aV): -0.000066
CHAN B2 (3.15bV): -0.000082
CHAN B3 (GND): 0.001429
OPEN: 0.005259
Full Scale Calc: 4.765 mA, -1.589 mA
2019-10-03T16:02:51.251Z,1570118571.251 [NAL9602](DEBUG): Fix Requested
2019-10-03T16:02:51.642Z,1570118571.642 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160250.00,A,3648.30877,N,12147.14165,W,0.136,41.65,031019,,,A*40
2019-10-03T16:02:51.645Z,1570118571.645 [NAL9602](INFO): GPS fix at 20191003T160250: (36.805146, -121.785694)
2019-10-03T16:03:24.187Z,1570118604.187 [NAL9602](INFO): Not Powering down - fast GPS
2019-10-03T16:03:31.898Z,1570118611.898 [SBIT](IMPORTANT): SBIT PASSED
2019-10-03T16:03:31.974Z,1570118611.974 [CommandLine](IMPORTANT): got command configSet list
2019-10-03T16:03:31.975Z,1570118611.975 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2019-10-03T16:03:31.976Z,1570118611.976 [CommandLine](IMPORTANT): CBIT.gf24Offset=143 microampere;

2019-10-03T16:03:31.976Z,1570118611.976 [CommandLine](IMPORTANT): Express none RDI_Pathfinder.height_above_sea_floor;

2019-10-03T16:03:31.976Z,1570118611.976 [CommandLine](IMPORTANT): Express linearApproximation Tracking.range_to_contact 10.000000 meter;

2019-10-03T16:03:31.976Z,1570118611.976 [CommandLine](IMPORTANT): Express none WetLabsUBAT.biolum_potential;

2019-10-03T16:03:31.976Z,1570118611.976 [CommandLine](IMPORTANT): Express none WetLabsUBAT.flow_rate;

2019-10-03T16:03:31.976Z,1570118611.976 [CommandLine](IMPORTANT): Express linearApproximation height_above_sea_floor 10.000000 meter;

2019-10-03T16:03:31.976Z,1570118611.976 [CommandLine](IMPORTANT): Normal linearApproximation WetLabsUBAT.biolum_potential 1000000.000000 none;

2019-10-03T16:03:31.976Z,1570118611.976 [CommandLine](IMPORTANT): VerticalControl.massDefault=10 millimeter;

2019-10-03T16:03:32.334Z,1570118612.334 [MissionManager](IMPORTANT): Started mission Startup
2019-10-03T16:03:32.334Z,1570118612.334 [Startup] Running Loop=1
2019-10-03T16:03:32.334Z,1570118612.334 [Startup](DEBUG): Aggregate::initialize Startup
2019-10-03T16:03:32.335Z,1570118612.335 [Startup:A.GoToSurface] Running Loop=1
2019-10-03T16:03:32.335Z,1570118612.335 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-10-03T16:03:32.335Z,1570118612.335 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-10-03T16:03:32.336Z,1570118612.336 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-10-03T16:03:32.336Z,1570118612.336 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-10-03T16:03:32.336Z,1570118612.336 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-10-03T16:03:32.337Z,1570118612.337 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-10-03T16:03:32.350Z,1570118612.350 [Startup:StartupSatComms] Running Loop=1
2019-10-03T16:03:32.350Z,1570118612.350 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2019-10-03T16:03:32.350Z,1570118612.350 [Startup:StartupSatComms:A] Running Loop=1
2019-10-03T16:03:32.695Z,1570118612.695 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2019-10-03T16:03:33.894Z,1570118613.894 [NAL9602](DEBUG): Fix Requested
2019-10-03T16:03:34.293Z,1570118614.293 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160332.00,A,3648.30890,N,12147.14457,W,0.136,41.65,031019,,,A*48
2019-10-03T16:03:34.295Z,1570118614.295 [NAL9602](INFO): GPS fix at 20191003T160332: (36.805148, -121.785743)
2019-10-03T16:03:34.347Z,1570118614.347 [Startup:StartupSatComms:A] Stopped
2019-10-03T16:03:34.347Z,1570118614.347 [Startup:StartupSatComms:B] Running Loop=1
2019-10-03T16:03:34.737Z,1570118614.737 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-10-03T16:03:42.929Z,1570118622.929 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20191003T142624/Courier0004.lzma
2019-10-03T16:03:44.936Z,1570118624.936 [DataOverHttps](INFO): Moved sent file to Logs/20191003T142624/Courier0004.lzma.bak
2019-10-03T16:03:44.937Z,1570118624.937 [DataOverHttps](INFO): SBD MOMSN=11845194
2019-10-03T16:03:45.709Z,1570118625.709 [NAL9602](IMPORTANT): SBD MO Status=0, MOMSN=1896, MT Status=1, MTMSN=54
2019-10-03T16:03:45.709Z,1570118625.709 [NAL9602](INFO): Data available in MT queue
2019-10-03T16:03:46.267Z,1570118626.267 [NAL9602](INFO): Received command:sched asap "set profile_station.MaxDepth 30 meter;run " 3qjca 2 2
2019-10-03T16:03:46.299Z,1570118626.299 [CommandLine](IMPORTANT): got command schedule asap "set profile_station.MaxDepth 30 meter;run " 3qjca 2 2.000000
2019-10-03T16:03:46.300Z,1570118626.300 [CommandLine](IMPORTANT): Scheduling command #2 of 2 with id=3qjca
2019-10-03T16:03:46.301Z,1570118626.301 [CommandLine](IMPORTANT): Scheduled #2 (#2 of 2 with id='3qjca'): "set profile_station.MaxDepth 30 meter;run " ASAP
2019-10-03T16:03:46.364Z,1570118626.364 [CommandLine](IMPORTANT): got command load ./Missions/Science/profile_station.xml
2019-10-03T16:03:46.364Z,1570118626.364 [MissionManager](INFO): Loading Mission: ./Missions/Science/profile_station.xml
2019-10-03T16:03:46.482Z,1570118626.482 [MissionManager](INFO): DefineArg profile_station.MissionTimeout = 4.000000 h
2019-10-03T16:03:46.485Z,1570118626.485 [MissionManager](INFO): DefineArg profile_station.NeedCommsTime = 60.000000 min
2019-10-03T16:03:46.488Z,1570118626.488 [MissionManager](INFO): DefineArg profile_station.Lat = 36.806966 arcdeg
2019-10-03T16:03:46.541Z,1570118626.541 [MissionManager](INFO): DefineArg profile_station.Lon = -121.824326 arcdeg
2019-10-03T16:03:46.548Z,1570118626.548 [MissionManager](INFO): DefineArg profile_station.Radius = 300.000000 m
2019-10-03T16:03:46.563Z,1570118626.563 [MissionManager](INFO): DefineArg profile_station.YoYoMinDepth = 2.000000 m
2019-10-03T16:03:46.574Z,1570118626.574 [MissionManager](INFO): DefineArg profile_station.YoYoMaxDepth = 200.000000 m
2019-10-03T16:03:46.580Z,1570118626.580 [MissionManager](INFO): DefineArg profile_station.YoYoMinAltitude = 7.000000 m
2019-10-03T16:03:46.584Z,1570118626.584 [MissionManager](INFO): DefineArg profile_station.YoYoPitch = 20.000000 arcdeg
2019-10-03T16:03:46.591Z,1570118626.591 [MissionManager](INFO): DefineArg profile_station.Speed = 1.000000 m/s
2019-10-03T16:03:46.594Z,1570118626.594 [MissionManager](INFO): DefineArg profile_station.CircleMaxError = 100.000000 m
2019-10-03T16:03:46.601Z,1570118626.601 [MissionManager](INFO): DefineArg profile_station.CircleTurnToPort = 0 bool
2019-10-03T16:03:46.604Z,1570118626.604 [MissionManager](INFO): DefineArg profile_station.KwpHeading = 0.010000 rad/m
2019-10-03T16:03:46.615Z,1570118626.615 [MissionManager](INFO): DefineArg profile_station.MinAltitude = 5.000000 m
2019-10-03T16:03:46.622Z,1570118626.622 [MissionManager](INFO): DefineArg profile_station.MaxDepth = 205.000000 m
2019-10-03T16:03:46.625Z,1570118626.625 [MissionManager](INFO): DefineArg profile_station.MinOffshore = 2.000000 km
2019-10-03T16:03:46.626Z,1570118626.626 [MissionManager](INFO): Inserting Stack: Missions/Insert/Science.xml
2019-10-03T16:03:47.017Z,1570118627.017 [MissionManager](INFO): DefineArg profile_station:Science.SampleISUS = 0 bool
2019-10-03T16:03:47.024Z,1570118627.024 [MissionManager](INFO): DefineArg profile_station:Science.SampleISUSmaxPitch = 60.000000 arcdeg
2019-10-03T16:03:47.027Z,1570118627.027 [MissionManager](INFO): DefineArg profile_station:Science.SampleISUSminPitch = -60.000000 arcdeg
2019-10-03T16:03:47.050Z,1570118627.050 [MissionManager](INFO): DefineArg profile_station:Science.PeakDetectChlActive = 0 bool
2019-10-03T16:03:47.053Z,1570118627.053 [MissionManager](INFO): DefineArg profile_station:Science.TimeWindowPeakReport = nan min
2019-10-03T16:03:47.056Z,1570118627.056 [MissionManager](INFO): DefineArg profile_station:Science.HighestChlPeakReportActive = 0 bool
2019-10-03T16:03:47.058Z,1570118627.058 [MissionManager](INFO): DefineArg profile_station:Science.PatchTracking = 0 bool
2019-10-03T16:03:47.061Z,1570118627.061 [MissionManager](INFO): DefineArg profile_station:Science.FilterWidthHorizontal = 3.000000 count
2019-10-03T16:03:47.064Z,1570118627.064 [MissionManager](INFO): DefineArg profile_station:Science.NumProfilesSlidingwindow = 100.000000 count
2019-10-03T16:03:47.067Z,1570118627.067 [MissionManager](INFO): DefineArg profile_station:Science.OffPeakFractionHorizontal = 80.000000 %
2019-10-03T16:03:47.070Z,1570118627.070 [MissionManager](INFO): DefineArg profile_station:Science.PeakDetectNO3Active = 0 bool
2019-10-03T16:03:47.072Z,1570118627.072 [MissionManager](INFO): DefineArg profile_station:Science.PeakDetectOilActive = 0 bool
2019-10-03T16:03:47.098Z,1570118627.098 [MissionManager](INFO): DefineArg profile_station:Science.PeakDetectFDOMActive = 0 bool
2019-10-03T16:03:47.101Z,1570118627.101 [MissionManager](INFO): DefineArg profile_station:Science.UpwardDerivativeOfTemperatureActive = 0 bool
2019-10-03T16:03:47.105Z,1570118627.105 [MissionManager](INFO): DefineArg profile_station:Science.EnabledAanderaaO2 = 0.000000 bool
2019-10-03T16:03:47.120Z,1570118627.120 [MissionManager](INFO): DefineArg profile_station:Science.EnabledNeilBrown = 0.000000 bool
2019-10-03T16:03:47.123Z,1570118627.123 [MissionManager](INFO): DefineArg profile_station:Science.EnabledSeabird = 1.000000 bool
2019-10-03T16:03:47.146Z,1570118627.146 [MissionManager](INFO): DefineArg profile_station:Science.EnabledTurbulence_NPS = 0.000000 bool
2019-10-03T16:03:47.150Z,1570118627.150 [MissionManager](INFO): DefineArg profile_station:Science.EnabledWetLabsBB2FL = 1.000000 bool
2019-10-03T16:03:47.153Z,1570118627.153 [MissionManager](INFO): DefineArg profile_station:Science.EnabledWetLabsSeaOWL_UV_A = 0.000000 bool
2019-10-03T16:03:47.167Z,1570118627.167 [MissionManager](INFO): DefineArg profile_station:Science.EnabledWetLabsUBAT = 1.000000 bool
2019-10-03T16:03:47.170Z,1570118627.170 [MissionManager](INFO): DefineArg profile_station:Science.EnabledBackSeatDriver = 1.000000 bool
2019-10-03T16:03:47.174Z,1570118627.174 [MissionManager](INFO): DefineArg profile_station:Science.EnabledISUS = 0.000000 bool
2019-10-03T16:03:47.196Z,1570118627.196 [MissionManager](INFO): DefineArg profile_station:Science.LowPassWindowLength = 20.000000 count
2019-10-03T16:03:47.199Z,1570118627.199 [MissionManager](INFO): DefineArg profile_station:Science.MedianFilterLen = 5.000000 count
2019-10-03T16:03:47.202Z,1570118627.202 [MissionManager](INFO): DefineArg profile_station:Science.PeakChlShallowBound = nan m
2019-10-03T16:03:47.214Z,1570118627.214 [MissionManager](INFO): DefineArg profile_station:Science.PeakChlDeepBound = nan m
2019-10-03T16:03:47.217Z,1570118627.217 [MissionManager](INFO): DefineArg profile_station:Science.PeakShallowBound = nan m
2019-10-03T16:03:47.220Z,1570118627.220 [MissionManager](INFO): DefineArg profile_station:Science.PeakDeepBound = nan m
2019-10-03T16:03:47.238Z,1570118627.238 [MissionManager](INFO): DefineOutput profile_station:Science.PeakChl = 0.000000 ug/l
2019-10-03T16:03:47.241Z,1570118627.241 [MissionManager](INFO): DefineOutput profile_station:Science.PeakChlDepth = 0.000000 m
2019-10-03T16:03:47.244Z,1570118627.244 [MissionManager](INFO): DefineOutput profile_station:Science.PeakChlTemperature = 0.000000 degC
2019-10-03T16:03:47.266Z,1570118627.266 [MissionManager](INFO): DefineOutput profile_station:Science.PeakChlLatitude = nan arcdeg
2019-10-03T16:03:47.269Z,1570118627.269 [MissionManager](INFO): DefineOutput profile_station:Science.PeakChlLongitude = nan arcdeg
2019-10-03T16:03:47.273Z,1570118627.273 [MissionManager](INFO): DefineOutput profile_station:Science.PeakNO3 = 0.000000 umol/l
2019-10-03T16:03:47.276Z,1570118627.276 [MissionManager](INFO): DefineOutput profile_station:Science.PeakNO3Depth = 0.000000 m
2019-10-03T16:03:47.279Z,1570118627.279 [MissionManager](INFO): DefineOutput profile_station:Science.PeakNO3Latitude = nan arcdeg
2019-10-03T16:03:47.301Z,1570118627.301 [MissionManager](INFO): DefineOutput profile_station:Science.PeakNO3Longitude = nan arcdeg
2019-10-03T16:03:47.349Z,1570118627.349 [MissionManager](INFO): DefineOutput profile_station:Science.PatchChl = 0.000000 m
2019-10-03T16:03:47.365Z,1570118627.365 [MissionManager](INFO): DefineOutput profile_station:Science.PatchChlDepth = 0.000000 m
2019-10-03T16:03:47.369Z,1570118627.369 [MissionManager](INFO): DefineOutput profile_station:Science.PatchChlLatitude = nan arcdeg
2019-10-03T16:03:47.382Z,1570118627.382 [MissionManager](INFO): DefineOutput profile_station:Science.PatchChlLongitude = nan arcdeg
2019-10-03T16:03:47.385Z,1570118627.385 [MissionManager](INFO): DefineOutput profile_station:Science.PatchChlDistance = nan m
2019-10-03T16:03:47.389Z,1570118627.389 [MissionManager](INFO): DefineOutput profile_station:Science.PeakOil = 0.000000 kg/m3
2019-10-03T16:03:47.392Z,1570118627.392 [MissionManager](INFO): DefineOutput profile_station:Science.PeakOilDepth = 0.000000 m
2019-10-03T16:03:47.403Z,1570118627.403 [MissionManager](INFO): DefineOutput profile_station:Science.PeakOilLatitude = nan arcdeg
2019-10-03T16:03:47.411Z,1570118627.411 [MissionManager](INFO): DefineOutput profile_station:Science.PeakOilLongitude = nan arcdeg
2019-10-03T16:03:47.414Z,1570118627.414 [MissionManager](INFO): DefineOutput profile_station:Science.PeakFDOM = 0.000000 ppb
2019-10-03T16:03:47.421Z,1570118627.421 [MissionManager](INFO): DefineOutput profile_station:Science.PeakFDOMDepth = 0.000000 m
2019-10-03T16:03:47.424Z,1570118627.424 [MissionManager](INFO): DefineOutput profile_station:Science.PeakFDOMLatitude = nan arcdeg
2019-10-03T16:03:47.440Z,1570118627.440 [MissionManager](INFO): DefineOutput profile_station:Science.PeakFDOMLongitude = nan arcdeg
2019-10-03T16:03:47.447Z,1570118627.447 [MissionManager](INFO): DefineOutput profile_station:Science.PatchFDOMDistance = nan m
2019-10-03T16:03:47.486Z,1570118627.486 [profile_station:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2019-10-03T16:03:47.511Z,1570118627.511 [profile_station:Science:HighestChlPeakReport:A.PeakDetectHorizontal](DEBUG): Construct PeakDetectHorizontal.
2019-10-03T16:03:47.536Z,1570118627.536 [profile_station:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2019-10-03T16:03:47.551Z,1570118627.551 [profile_station:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2019-10-03T16:03:47.576Z,1570118627.576 [profile_station:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2019-10-03T16:03:47.598Z,1570118627.598 [MissionManager](INFO): RedefineArg profile_station:Science.SampleISUS = value:1 bool
2019-10-03T16:03:47.600Z,1570118627.600 [MissionManager](INFO): RedefineArg profile_station:Science.PeakDetectChlActive = value:1 bool
2019-10-03T16:03:47.601Z,1570118627.601 [MissionManager](INFO): Inserting Stack: Missions/Insert/NeedComms.xml
2019-10-03T16:03:47.668Z,1570118627.668 [MissionManager](INFO): DefineArg profile_station:NeedComms.DiveInterval = 3.000000 h
2019-10-03T16:03:47.679Z,1570118627.679 [MissionManager](INFO): DefineArg profile_station:NeedComms.WaitForPitchUp = 10.000000 min
2019-10-03T16:03:47.682Z,1570118627.682 [MissionManager](INFO): DefineArg profile_station:NeedComms.SurfacePitch = 20.000000 arcdeg
2019-10-03T16:03:47.689Z,1570118627.689 [MissionManager](INFO): DefineArg profile_station:NeedComms.SurfaceDepthRate = nan m/s
2019-10-03T16:03:47.696Z,1570118627.696 [MissionManager](INFO): DefineArg profile_station:NeedComms.SurfaceSpeed = 1.000000 m/s
2019-10-03T16:03:47.729Z,1570118627.729 [MissionManager](INFO): DefineArg profile_station:NeedComms.GPSTimeout = 7.000000 min
2019-10-03T16:03:47.767Z,1570118627.767 [MissionManager](INFO): DefineArg profile_station:NeedComms.CommsTimeout = 30.000000 min
2019-10-03T16:03:47.780Z,1570118627.780 [profile_station:NeedComms:B.GoToSurface](DEBUG): Construct GoToSurface.
2019-10-03T16:03:47.814Z,1570118627.814 [MissionManager](INFO): Inserting Stack: Missions/Insert/StandardEnvelopes.xml
2019-10-03T16:03:47.855Z,1570118627.855 [MissionManager](INFO): DefineArg profile_station:StandardEnvelopes.MinAltitude = 5.000000 m
2019-10-03T16:03:47.862Z,1570118627.862 [MissionManager](INFO): DefineArg profile_station:StandardEnvelopes.MaxDepth = 200.000000 m
2019-10-03T16:03:47.865Z,1570118627.865 [MissionManager](INFO): DefineArg profile_station:StandardEnvelopes.MinOffshore = 2000.000000 m
2019-10-03T16:03:47.875Z,1570118627.875 [profile_station:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope.
2019-10-03T16:03:47.882Z,1570118627.882 [profile_station:StandardEnvelopes:B.DepthEnvelope](DEBUG): Construct DepthEnvelope.
2019-10-03T16:03:47.906Z,1570118627.906 [profile_station:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Construct OffshoreEnvelope.
2019-10-03T16:03:47.941Z,1570118627.941 [profile_station:I.Pitch](DEBUG): Construct.
2019-10-03T16:03:47.988Z,1570118627.988 [profile_station:J.Buoyancy](DEBUG): Construct Buoyancy.
2019-10-03T16:03:48.010Z,1570118628.010 [profile_station:K.SetSpeed](DEBUG): Construct.
2019-10-03T16:03:48.013Z,1570118628.013 [profile_station:L.DepthEnvelope](DEBUG): Construct DepthEnvelope.
2019-10-03T16:03:48.063Z,1570118628.063 [profile_station:M.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope.
2019-10-03T16:03:48.099Z,1570118628.099 [profile_station:N.YoYo](DEBUG): Construct YoYo.
2019-10-03T16:03:48.179Z,1570118628.179 [profile_station:CircleWrapper:B.Circle](DEBUG): Construct.
2019-10-03T16:03:48.270Z,1570118628.270 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Derivation="Tethys/Derivation"
       xmlns:Estimation="Tethys/Estimation"
       xmlns:Guidance="Tethys/Guidance"
       xmlns:Sensor="Tethys/Sensor"
       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/Derivation http://okeanids.mbari.org/tethys/Xml/Derivation.xsd
                           Tethys/Estimation http://okeanids.mbari.org/tethys/Xml/Estimation.xsd
                           Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Sensor http://okeanids.mbari.org/tethys/Xml/Sensor.xsd
                           Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
       Id="profile_station">

    <Description>
        This mission yoyos in a circle around a specified location.
    </Description>

<!-- Mission-wide settings -->

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

    <DefineArg Name="NeedCommsTime"><Description>
        Elapsed time after previous surface communications when vehicle will
        begin to ascend for additional surface communications
    </Description><Units:minute/><Value>60</Value></DefineArg>

<!-- You probably need to change these. -->

    <DefineArg Name="Lat"><Description>
        The latitude of the center of the circle.
    </Description><Units:degree/><Value>36.806966</Value></DefineArg>

    <DefineArg Name="Lon"><Description>
        The longitude of the center of the circle.
    </Description><Units:degree/><Value>-121.824326</Value></DefineArg>

    <DefineArg Name="Radius"><Description>
        Radius to circle at
    </Description><Units:meter/><Value>300</Value></DefineArg>

<!-- You probably do not need to change these. -->

    <DefineArg Name="YoYoMinDepth"><Description>
        Minimum depth while performing the YoYo behavior.
    </Description><Units:meter/><Value>2</Value></DefineArg>

    <DefineArg Name="YoYoMaxDepth"><Description>
        Maximum depth while performing the YoYo behavior.
    </Description><Units:meter/><Value>200</Value></DefineArg>

    <DefineArg Name="YoYoMinAltitude"><Description>
        Minimum altitude while performing the YoYo behavior (for
        bottom-terminated YoYos).
    </Description><Units:meter/><Value>7</Value></DefineArg>

    <DefineArg Name="YoYoPitch"><Description>
        Pitch (plus and minus) for yo-yo behavior.
    </Description><Units:degree/><Value>20</Value></DefineArg>

    <DefineArg Name="Speed"><Description>
        Vehicle speed.
    </Description><Units:meter_per_second/><Value>1</Value></DefineArg>

<!-- You are even less likely to need to change these. -->

    <DefineArg Name="CircleMaxError"><Description>
        If this distance away from the circle, drive straight towards (or away
        from the center). Otherwise, try to reduce distance from the ideal
        circle.
    </Description><Units:meter/><Value>100</Value></DefineArg>

    <DefineArg Name="CircleTurnToPort"><Description>
        If true, vehicle turns to the left around the center point. If false,
        vehicle turns to the right.
    </Description><False/></DefineArg>

    <DefineArg Name="KwpHeading"><Description>
        Used to relax waypoint cross-track error constant that is adjusted for
        docking. (You can override this setting by passing an argument.)
    </Description><Units:radian_per_meter/><Value>0.010</Value></DefineArg>

    <DefineArg Name="MinAltitude"><Description>
        Minimum height above the sea floor for the entire mission.
    </Description><Units:meter/><Value>5</Value></DefineArg>

    <DefineArg Name="MaxDepth"><Description>
        Maximum depth for the entire mission.
    </Description><Units:meter/><Value>205</Value></DefineArg>

    <DefineArg Name="MinOffshore"><Description>
        Minimum offshore distance for the entire mission.
    </Description><Units:kilometer/><Value>2</Value></DefineArg>

<!-- Missions should almost always start with a timeout -->

    <Timeout Duration="MissionTimeout"/>

    <Insert Filename="Insert/Science.xml">
        <Description>
            Most missions will run the science sensors. If you don't place this
            aggregate above NeedComms, science instruments get turned off on the
            last upcast and while floating on the surface.
        </Description>
        <RedefineArg Name="SampleISUS"><True/></RedefineArg>
        <RedefineArg Name="PeakDetectChlActive"><True/></RedefineArg>
    </Insert>

<!-- Most missions should use the NeedComms aggregate. -->

    <Insert Filename="Insert/NeedComms.xml" Id="NeedComms"/>

    <Assign><Sequence/><Arg Name="NeedComms:DiveInterval"/><Arg Name="NeedCommsTime"/></Assign>

<!-- Missions should almost always start with standard safety envelopes; most missions should not expose the parameters of these envelopes. -->

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

    <Assign><Sequence/><Arg Name="StandardEnvelopes:MinAltitude"/><Arg Name="MinAltitude"/></Assign>

    <Assign><Sequence/><Arg Name="StandardEnvelopes:MaxDepth"/><Arg Name="MaxDepth"/></Assign>

    <Assign><Sequence/><Arg Name="StandardEnvelopes:MinOffshore"/><Arg Name="MinOffshore"/></Assign>

<!-- Check for additional instructions first. -->

    <Call Id="StartingMission" RefId="NeedComms"/>

<!-- Many missions will keep mass position and buoyancy volume fixed at defaults. -->

    <Guidance:Pitch>
        <Parallel/>
        <Setting><Guidance:Pitch.massPosition/><Control:VerticalControl.massDefault/></Setting>
    </Guidance:Pitch>

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

    <Guidance:SetSpeed>
        <Parallel/>
        <Setting><Guidance:SetSpeed.speed/><Arg Name="Speed"/></Setting>
    </Guidance:SetSpeed>

    <Guidance:DepthEnvelope>
        <Description>
            Another depth envelope for the YoYo behavior. This envelope should
            fall within the limits of the standard safety envelopes in
            Insert/StandardEnvelopes.xml in order to avoid commanding high pitch
            angles for depth-terminated YoYos.
        </Description>
        <Parallel/>
        <Setting><Guidance:DepthEnvelope.minDepth/><Arg Name="YoYoMinDepth"/></Setting>
        <Setting><Guidance:DepthEnvelope.maxDepth/><Arg Name="YoYoMaxDepth"/></Setting>
        <Setting><Guidance:DepthEnvelope.pitch/><Arg Name="YoYoPitch"/></Setting>
    </Guidance:DepthEnvelope>

    <Guidance:AltitudeEnvelope>
        <Description>
            Another altitude envelope for the YoYo behavior. This envelope
            should fall within the limits of the standard safety envelopes in
            Insert/StandardEnvelopes.xml in order to avoid commanding high pitch
            angles for bottom-terminated YoYos.
        </Description>
        <Parallel/>
        <Setting><Guidance:AltitudeEnvelope.minAltitude/><Arg Name="YoYoMinAltitude"/></Setting>
        <Setting><Guidance:AltitudeEnvelope.pitch/><Arg Name="YoYoPitch"/></Setting>
    </Guidance:AltitudeEnvelope>

    <Guidance:YoYo>
        <Parallel/>
        <Setting><Guidance:YoYo.pitch/><Arg Name="YoYoPitch"/></Setting>
    </Guidance:YoYo>

    <Aggregate Id="CircleWrapper">

        <Sequence Repeat="4096"/>

        <Assign><Parallel/><Control:HorizontalControl.kwpHeading/><Arg Name="KwpHeading"/></Assign>

        <Guidance:Circle>
            <Sequence/>
            <Setting><Guidance:Circle.latitude/><Arg Name="Lat"/></Setting>
            <Setting><Guidance:Circle.longitude/><Arg Name="Lon"/></Setting>
            <Setting><Guidance:Circle.radius/><Arg Name="Radius"/></Setting>
            <Setting><Guidance:Circle.maxError/><Arg Name="CircleMaxError"/></Setting>
            <Setting><Guidance:Circle.turnToPort/><Arg Name="CircleTurnToPort"/></Setting>
        </Guidance:Circle>

    </Aggregate>

</Mission>


2019-10-03T16:03:48.271Z,1570118628.271 [CommandLine](IMPORTANT): Loaded ./Missions/Science/profile_station.xml
2019-10-03T16:04:00.316Z,1570118640.316 [CommandLine](IMPORTANT): got command set profile_station.NeedCommsTime 20.000000 minute
2019-10-03T16:04:00.316Z,1570118640.316 [CommandLine](IMPORTANT): got command set profile_station.Lat 36.712109 degree
2019-10-03T16:04:00.317Z,1570118640.317 [CommandLine](IMPORTANT): got command set profile_station.Lon -122.187027 degree
2019-10-03T16:04:00.318Z,1570118640.318 [CommandLine](IMPORTANT): got command set profile_station.YoYoMaxDepth 20.000000 meter
2019-10-03T16:04:02.213Z,1570118642.213 [CommandLine](IMPORTANT): got command set profile_station.MaxDepth 30.000000 meter
2019-10-03T16:04:02.214Z,1570118642.214 [CommandLine](IMPORTANT): got command run 
2019-10-03T16:04:02.217Z,1570118642.217 [CommandLine](IMPORTANT): Running 
2019-10-03T16:04:07.571Z,1570118647.571 [DataOverHttps](INFO): Sending 213 bytes from file Logs/20191003T160129/Courier0000.lzma
2019-10-03T16:04:09.577Z,1570118649.577 [DataOverHttps](INFO): Moved sent file to Logs/20191003T160129/Courier0000.lzma.bak
2019-10-03T16:04:09.577Z,1570118649.577 [DataOverHttps](INFO): SBD MOMSN=11845201
2019-10-03T16:04:16.843Z,1570118656.843 [NAL9602](INFO): Not Powering down - fast GPS
2019-10-03T16:04:29.294Z,1570118669.294 [DataOverHttps](INFO): Sending 139 bytes from file Logs/20191003T142624/Express0005.lzma
2019-10-03T16:04:31.303Z,1570118671.303 [DataOverHttps](INFO): Moved sent file to Logs/20191003T142624/Express0005.lzma.bak
2019-10-03T16:04:31.303Z,1570118671.303 [DataOverHttps](INFO): SBD MOMSN=11845208
2019-10-03T16:04:34.678Z,1570118674.678 [Startup:StartupSatComms:B](INFO): Timed out from 2019-10-03T16:03:34.3Z
2019-10-03T16:04:34.678Z,1570118674.678 [Startup:StartupSatComms:B] Stopped
2019-10-03T16:04:34.682Z,1570118674.682 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2019-10-03T16:04:34.682Z,1570118674.682 [Startup:StartupSatComms] Stopped
2019-10-03T16:04:34.682Z,1570118674.682 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2019-10-03T16:04:34.683Z,1570118674.683 [Startup](INFO): Completed Startup
2019-10-03T16:04:34.683Z,1570118674.683 [MissionManager](INFO): Startup is completed.
2019-10-03T16:04:34.683Z,1570118674.683 [MissionManager](INFO): Uninitializing Mission Startup
2019-10-03T16:04:34.684Z,1570118674.684 [Startup] Stopped
2019-10-03T16:04:34.684Z,1570118674.684 [Startup](DEBUG): Aggregate::uninitialize Startup
2019-10-03T16:04:34.684Z,1570118674.684 [Startup:A.GoToSurface] Stopped
2019-10-03T16:04:34.684Z,1570118674.684 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-10-03T16:04:35.101Z,1570118675.101 [MissionManager](IMPORTANT): Started mission profile_station
2019-10-03T16:04:35.102Z,1570118675.102 [profile_station] Running Loop=1
2019-10-03T16:04:35.102Z,1570118675.102 [profile_station](DEBUG): Aggregate::initialize profile_station
2019-10-03T16:04:35.110Z,1570118675.110 [profile_station:Science] Running Loop=1
2019-10-03T16:04:35.110Z,1570118675.110 [profile_station:Science](DEBUG): Aggregate::initialize profile_station:Science
2019-10-03T16:04:35.110Z,1570118675.110 [profile_station:Science:A] Running Loop=1
2019-10-03T16:04:35.110Z,1570118675.110 [profile_station:Science:B] Running Loop=1
2019-10-03T16:04:35.111Z,1570118675.111 [profile_station:Science:C] Running Loop=1
2019-10-03T16:04:35.111Z,1570118675.111 [profile_station:Science:D] Running Loop=1
2019-10-03T16:04:35.111Z,1570118675.111 [profile_station:Science:E] Running Loop=1
2019-10-03T16:04:35.111Z,1570118675.111 [profile_station:Science:F] Running Loop=1
2019-10-03T16:04:35.111Z,1570118675.111 [profile_station:Science:G] Running Loop=1
2019-10-03T16:04:35.111Z,1570118675.111 [profile_station:Science:H] Running Loop=1
2019-10-03T16:04:35.111Z,1570118675.111 [profile_station:Science:I] Running Loop=1
2019-10-03T16:04:35.111Z,1570118675.111 [profile_station:Science:Read_Oil] Running Loop=1
2019-10-03T16:04:35.111Z,1570118675.111 [profile_station:Science:PeakDetectChl] Running Loop=1
2019-10-03T16:04:35.111Z,1570118675.111 [profile_station:Science:PeakDetectChl](DEBUG): Aggregate::initialize profile_station:Science:PeakDetectChl
2019-10-03T16:04:35.111Z,1570118675.111 [profile_station:Science:PeakDetectChl:A.PeakDetectVsDepth] Running Loop=1
2019-10-03T16:04:35.111Z,1570118675.111 [profile_station:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Initialize.
2019-10-03T16:04:35.113Z,1570118675.113 [profile_station:Science:HighestChlPeakReport] Running Loop=1
2019-10-03T16:04:35.113Z,1570118675.113 [profile_station:Science:HighestChlPeakReport](DEBUG): Aggregate::initialize profile_station:Science:HighestChlPeakReport
2019-10-03T16:04:35.113Z,1570118675.113 [profile_station:Science:HighestChlPeakReport:A.PeakDetectHorizontal] Running Loop=1
2019-10-03T16:04:35.114Z,1570118675.114 [profile_station:Science:HighestChlPeakReport:A.PeakDetectHorizontal](INFO): Initialize.
2019-10-03T16:04:35.114Z,1570118675.114 [profile_station:Science:PeakDetectNO3] Running Loop=1
2019-10-03T16:04:35.123Z,1570118675.123 [profile_station:Science:PeakDetectNO3](DEBUG): Aggregate::initialize profile_station:Science:PeakDetectNO3
2019-10-03T16:04:35.123Z,1570118675.123 [profile_station:Science:PeakDetectNO3:A.PeakDetectVsDepth] Running Loop=1
2019-10-03T16:04:35.123Z,1570118675.123 [profile_station:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Initialize.
2019-10-03T16:04:35.125Z,1570118675.125 [profile_station:Science:PeakDetectOil] Running Loop=1
2019-10-03T16:04:35.125Z,1570118675.125 [profile_station:Science:PeakDetectOil](DEBUG): Aggregate::initialize profile_station:Science:PeakDetectOil
2019-10-03T16:04:35.125Z,1570118675.125 [profile_station:Science:PeakDetectOil:A.PeakDetectVsDepth] Running Loop=1
2019-10-03T16:04:35.125Z,1570118675.125 [profile_station:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Initialize.
2019-10-03T16:04:35.135Z,1570118675.135 [profile_station:Science:PeakDetectFDOM] Running Loop=1
2019-10-03T16:04:35.136Z,1570118675.136 [profile_station:Science:PeakDetectFDOM](DEBUG): Aggregate::initialize profile_station:Science:PeakDetectFDOM
2019-10-03T16:04:35.136Z,1570118675.136 [profile_station:Science:PeakDetectFDOM:A.PeakDetectVsDepth] Running Loop=1
2019-10-03T16:04:35.136Z,1570118675.136 [profile_station:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Initialize.
2019-10-03T16:04:35.143Z,1570118675.143 [profile_station:StandardEnvelopes] Running Loop=1
2019-10-03T16:04:35.143Z,1570118675.143 [profile_station:StandardEnvelopes](DEBUG): Aggregate::initialize profile_station:StandardEnvelopes
2019-10-03T16:04:35.143Z,1570118675.143 [profile_station:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1
2019-10-03T16:04:35.143Z,1570118675.143 [profile_station:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent.
2019-10-03T16:04:35.143Z,1570118675.143 [profile_station:StandardEnvelopes:B.DepthEnvelope] Running Loop=1
2019-10-03T16:04:35.143Z,1570118675.143 [profile_station:StandardEnvelopes:B.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent.
2019-10-03T16:04:35.143Z,1570118675.143 [profile_station:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1
2019-10-03T16:04:35.144Z,1570118675.144 [profile_station:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Initialize OffshoreEnvelopeComponent.
2019-10-03T16:04:35.144Z,1570118675.144 [profile_station:I.Pitch] Running Loop=1
2019-10-03T16:04:35.144Z,1570118675.144 [profile_station:I.Pitch](DEBUG): Initialize.
2019-10-03T16:04:35.144Z,1570118675.144 [profile_station:J.Buoyancy] Running Loop=1
2019-10-03T16:04:35.144Z,1570118675.144 [profile_station:J.Buoyancy](DEBUG): Initialize Buoyancy Component.
2019-10-03T16:04:35.144Z,1570118675.144 [profile_station:K.SetSpeed] Running Loop=1
2019-10-03T16:04:35.144Z,1570118675.144 [profile_station:K.SetSpeed](DEBUG): Initialize.
2019-10-03T16:04:35.144Z,1570118675.144 [profile_station:L.DepthEnvelope] Running Loop=1
2019-10-03T16:04:35.144Z,1570118675.144 [profile_station:L.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent.
2019-10-03T16:04:35.145Z,1570118675.145 [profile_station:M.AltitudeEnvelope] Running Loop=1
2019-10-03T16:04:35.145Z,1570118675.145 [profile_station:M.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent.
2019-10-03T16:04:35.145Z,1570118675.145 [profile_station:N.YoYo] Running Loop=1
2019-10-03T16:04:35.145Z,1570118675.145 [profile_station:N.YoYo](DEBUG): Initialize YoYoComponent.
2019-10-03T16:04:35.145Z,1570118675.145 [profile_station:C] Running Loop=1
2019-10-03T16:04:35.146Z,1570118675.146 [profile_station:N.YoYo] Running Loop=1
2019-10-03T16:04:35.159Z,1570118675.159 [profile_station:M.AltitudeEnvelope] Running Loop=1
2019-10-03T16:04:35.159Z,1570118675.159 [profile_station:L.DepthEnvelope] Running Loop=1
2019-10-03T16:04:35.160Z,1570118675.160 [profile_station:K.SetSpeed] Running Loop=1
2019-10-03T16:04:35.161Z,1570118675.161 [profile_station:J.Buoyancy] Running Loop=1
2019-10-03T16:04:35.161Z,1570118675.161 [profile_station:I.Pitch] Running Loop=1
2019-10-03T16:04:35.161Z,1570118675.161 [profile_station:StandardEnvelopes] Running Loop=1
2019-10-03T16:04:35.161Z,1570118675.161 [profile_station:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1
2019-10-03T16:04:35.194Z,1570118675.194 [profile_station:StandardEnvelopes:B.DepthEnvelope] Running Loop=1
2019-10-03T16:04:35.203Z,1570118675.203 [profile_station:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1
2019-10-03T16:04:35.203Z,1570118675.203 [profile_station:C] Stopped
2019-10-03T16:04:35.203Z,1570118675.203 [profile_station:E] Running Loop=1
2019-10-03T16:04:35.203Z,1570118675.203 [profile_station:Science] Running Loop=1
2019-10-03T16:04:35.205Z,1570118675.205 [profile_station:Science:PeakDetectFDOM] Stopped
2019-10-03T16:04:35.205Z,1570118675.205 [profile_station:Science:PeakDetectFDOM](DEBUG): Aggregate::uninitialize profile_station:Science:PeakDetectFDOM
2019-10-03T16:04:35.205Z,1570118675.205 [profile_station:Science:PeakDetectFDOM:A.PeakDetectVsDepth] Stopped
2019-10-03T16:04:35.205Z,1570118675.205 [profile_station:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2019-10-03T16:04:35.205Z,1570118675.205 [profile_station:Science:PeakDetectOil] Stopped
2019-10-03T16:04:35.205Z,1570118675.205 [profile_station:Science:PeakDetectOil](DEBUG): Aggregate::uninitialize profile_station:Science:PeakDetectOil
2019-10-03T16:04:35.205Z,1570118675.205 [profile_station:Science:PeakDetectOil:A.PeakDetectVsDepth] Stopped
2019-10-03T16:04:35.205Z,1570118675.205 [profile_station:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2019-10-03T16:04:35.205Z,1570118675.205 [profile_station:Science:PeakDetectNO3] Stopped
2019-10-03T16:04:35.205Z,1570118675.205 [profile_station:Science:PeakDetectNO3](DEBUG): Aggregate::uninitialize profile_station:Science:PeakDetectNO3
2019-10-03T16:04:35.206Z,1570118675.206 [profile_station:Science:PeakDetectNO3:A.PeakDetectVsDepth] Stopped
2019-10-03T16:04:35.206Z,1570118675.206 [profile_station:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2019-10-03T16:04:35.206Z,1570118675.206 [profile_station:Science:HighestChlPeakReport] Stopped
2019-10-03T16:04:35.206Z,1570118675.206 [profile_station:Science:HighestChlPeakReport](DEBUG): Aggregate::uninitialize profile_station:Science:HighestChlPeakReport
2019-10-03T16:04:35.214Z,1570118675.214 [profile_station:Science:HighestChlPeakReport:A.PeakDetectHorizontal] Stopped
2019-10-03T16:04:35.214Z,1570118675.214 [profile_station:Science:HighestChlPeakReport:A.PeakDetectHorizontal](DEBUG): Uninitialize.
2019-10-03T16:04:35.214Z,1570118675.214 [profile_station:Science:PeakDetectChl] Running Loop=1
2019-10-03T16:04:35.215Z,1570118675.215 [profile_station:Science:Read_Oil] Stopped
2019-10-03T16:04:35.215Z,1570118675.215 [profile_station:Science:I] Running Loop=1
2019-10-03T16:04:35.215Z,1570118675.215 [profile_station:Science:I](DEBUG): Initialize ReadDataComponent to sense BackSeatDriver.power_back_seat_driver
2019-10-03T16:04:35.216Z,1570118675.216 [profile_station:Science:H] Running Loop=1
2019-10-03T16:04:35.216Z,1570118675.216 [profile_station:Science:H](DEBUG): Initialize ReadDataComponent to sense WetLabsUBAT.biolum_potential
2019-10-03T16:04:35.216Z,1570118675.216 [profile_station:Science:G] Running Loop=1
2019-10-03T16:04:35.217Z,1570118675.217 [profile_station:Science:G](DEBUG): Initialize ReadDataComponent to sense mass_concentration_of_chlorophyll_in_sea_water
2019-10-03T16:04:35.217Z,1570118675.217 [profile_station:Science:F] Stopped
2019-10-03T16:04:35.217Z,1570118675.217 [profile_station:Science:E] Stopped
2019-10-03T16:04:35.217Z,1570118675.217 [profile_station:Science:D] Running Loop=1
2019-10-03T16:04:35.218Z,1570118675.218 [profile_station:Science:D](DEBUG): Initialize ReadDataComponent to sense CTD_Seabird.sea_water_temperature
2019-10-03T16:04:35.223Z,1570118675.223 [profile_station:Science:D](DEBUG): Initialize ReadDataComponent to sense CTD_Seabird.sea_water_salinity
2019-10-03T16:04:35.223Z,1570118675.223 [profile_station:Science:C] Running Loop=1
2019-10-03T16:04:35.224Z,1570118675.224 [profile_station:Science:C](DEBUG): Initialize ReadDataComponent to sense sea_water_temperature
2019-10-03T16:04:35.224Z,1570118675.224 [profile_station:Science:C](DEBUG): Initialize ReadDataComponent to sense sea_water_salinity
2019-10-03T16:04:35.225Z,1570118675.225 [profile_station:Science:B] Stopped
2019-10-03T16:04:35.225Z,1570118675.225 [profile_station:Science:A] Stopped
2019-10-03T16:04:35.550Z,1570118675.550 [BackSeatDriver](INFO): Powering up
2019-10-03T16:04:35.551Z,1570118675.551 [BackSeatDriver](INFO): Subscribing to LCM channel: BackSeatDriverStatus
2019-10-03T16:04:35.672Z,1570118675.672 [BackSeatDriver](INFO): Subscribing to LCM channel: BioLumProxies
2019-10-03T16:04:35.683Z,1570118675.683 [profile_station:E] Stopped
2019-10-03T16:04:35.683Z,1570118675.683 [profile_station:F] Running Loop=1
2019-10-03T16:04:35.712Z,1570118675.712 [WetLabsBB2FL](INFO): Opening uart, block timeout 10ths=2
2019-10-03T16:04:35.712Z,1570118675.712 [WetLabsBB2FL](INFO): Powering up
2019-10-03T16:04:35.851Z,1570118675.851 [WetLabsUBAT](INFO): Initializing
2019-10-03T16:04:35.853Z,1570118675.853 [WetLabsUBAT](INFO): readConfig(): serialNo_: UBAT0051, uartName_: /dev/ttyC1, optionalArgs_: -ldir /mnt/mmc/LRAUV/Logs/latest
2019-10-03T16:04:35.853Z,1570118675.853 [WetLabsUBAT](INFO): Powering up
2019-10-03T16:04:35.853Z,1570118675.853 [WetLabsUBAT](INFO): Checking LCM
2019-10-03T16:04:35.853Z,1570118675.853 [WetLabsUBAT](INFO): LCM OK
2019-10-03T16:04:35.857Z,1570118675.857 [WetLabsUBAT](INFO): setup() - setLineFormat()
2019-10-03T16:04:35.931Z,1570118675.931 [profile_station:F] Stopped
2019-10-03T16:04:35.932Z,1570118675.932 [profile_station:G] Running Loop=1
2019-10-03T16:04:36.007Z,1570118676.007 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20
2019-10-03T16:04:36.332Z,1570118676.332 [profile_station:G] Stopped
2019-10-03T16:04:36.332Z,1570118676.332 [profile_station:StartingMission] Running Loop=1
2019-10-03T16:04:36.332Z,1570118676.332 [profile_station:StartingMission](DEBUG): Aggregate::initialize profile_station:StartingMission
2019-10-03T16:04:36.718Z,1570118676.718 [profile_station:M.AltitudeEnvelope](ERROR): Altitude Measurement is not Active.
2019-10-03T16:04:36.744Z,1570118676.744 [profile_station:StandardEnvelopes:A.AltitudeEnvelope](ERROR): Altitude Measurement is not Active.
2019-10-03T16:04:36.744Z,1570118676.744 [profile_station:NeedComms] Running Loop=1
2019-10-03T16:04:36.744Z,1570118676.744 [profile_station:NeedComms](DEBUG): Aggregate::initialize profile_station:NeedComms
2019-10-03T16:04:36.745Z,1570118676.745 [profile_station:NeedComms:B.GoToSurface] Running Loop=1
2019-10-03T16:04:36.745Z,1570118676.745 [profile_station:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-10-03T16:04:36.745Z,1570118676.745 [profile_station:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s.
2019-10-03T16:04:36.745Z,1570118676.745 [profile_station:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees.
2019-10-03T16:04:36.746Z,1570118676.746 [profile_station:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s.
2019-10-03T16:04:36.763Z,1570118676.763 [profile_station:NeedComms:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-10-03T16:04:36.763Z,1570118676.763 [profile_station:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-10-03T16:04:36.764Z,1570118676.764 [profile_station:NeedComms:A] Running Loop=1
2019-10-03T16:04:36.765Z,1570118676.765 [profile_station:NeedComms:A](INFO): last time_fix was: 1570118612.000000 second since 1970/01/01T00:00:00Z 
2019-10-03T16:04:36.765Z,1570118676.765 [profile_station:NeedComms:A] Stopped
2019-10-03T16:04:37.154Z,1570118677.154 [profile_station:NeedComms:C] Running Loop=1
2019-10-03T16:04:37.520Z,1570118677.520 [profile_station:NeedComms:C](DEBUG): Initialize ReadDataComponent to sense time_fix
2019-10-03T16:04:38.686Z,1570118678.686 [NAL9602](DEBUG): Fix Requested
2019-10-03T16:04:39.012Z,1570118679.012 [CTD_Seabird](ERROR): Failed to parse device response: <!--startlogging-->
2019-10-03T16:04:39.081Z,1570118679.081 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160437.00,A,3648.30875,N,12147.14448,W,0.019,41.65,031019,,,A*43
2019-10-03T16:04:39.083Z,1570118679.083 [NAL9602](INFO): GPS fix at 20191003T160437: (36.805146, -121.785741)
2019-10-03T16:04:39.196Z,1570118679.196 [profile_station:NeedComms:C] Stopped
2019-10-03T16:04:39.197Z,1570118679.197 [profile_station:NeedComms:D] Running Loop=1
2019-10-03T16:04:39.572Z,1570118679.572 [profile_station:NeedComms:D](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-10-03T16:04:40.505Z,1570118680.505 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2019-10-03T16:04:40.505Z,1570118680.505 [RDI_Pathfinder](ERROR): Failed to parse:
:TS6054402,35.0, -0.1,   0.0,1448.9,  0
2019-10-03T16:04:41.017Z,1570118681.017 [CTD_Seabird](ERROR): Salinity reading out of range: 0.008792 psu
2019-10-03T16:04:42.020Z,1570118682.020 [CTD_Seabird](ERROR): Salinity reading out of range: 0.008737 psu
2019-10-03T16:04:42.152Z,1570118682.152 [CommandLine](IMPORTANT): got command stop
2019-10-03T16:04:42.152Z,1570118682.152 [CommandLine](IMPORTANT): Scheduling is paused
2019-10-03T16:04:42.152Z,1570118682.152 [Supervisor](INFO): Stop Mission called by CommandLine::commandStop
2019-10-03T16:04:42.171Z,1570118682.171 [MissionManager](INFO): MissionManager is completed.
2019-10-03T16:04:42.171Z,1570118682.171 [MissionManager](INFO): Uninitializing Mission profile_station
2019-10-03T16:04:42.171Z,1570118682.171 [profile_station] Stopped
2019-10-03T16:04:42.171Z,1570118682.171 [profile_station](DEBUG): Aggregate::uninitialize profile_station
2019-10-03T16:04:42.171Z,1570118682.171 [profile_station:Science] Stopped
2019-10-03T16:04:42.171Z,1570118682.171 [profile_station:Science](DEBUG): Aggregate::uninitialize profile_station:Science
2019-10-03T16:04:42.171Z,1570118682.171 [profile_station:Science:C] Stopped
2019-10-03T16:04:42.171Z,1570118682.171 [profile_station:Science:D] Stopped
2019-10-03T16:04:42.171Z,1570118682.171 [profile_station:Science:G] Stopped
2019-10-03T16:04:42.171Z,1570118682.171 [profile_station:Science:H] Stopped
2019-10-03T16:04:42.171Z,1570118682.171 [profile_station:Science:I] Stopped
2019-10-03T16:04:42.172Z,1570118682.172 [profile_station:Science:PeakDetectChl] Stopped
2019-10-03T16:04:42.172Z,1570118682.172 [profile_station:Science:PeakDetectChl](DEBUG): Aggregate::uninitialize profile_station:Science:PeakDetectChl
2019-10-03T16:04:42.172Z,1570118682.172 [profile_station:Science:PeakDetectChl:A.PeakDetectVsDepth] Stopped
2019-10-03T16:04:42.172Z,1570118682.172 [profile_station:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2019-10-03T16:04:42.172Z,1570118682.172 [profile_station:NeedComms] Stopped
2019-10-03T16:04:42.172Z,1570118682.172 [profile_station:NeedComms](DEBUG): Aggregate::uninitialize profile_station:NeedComms
2019-10-03T16:04:42.172Z,1570118682.172 [profile_station:NeedComms:B.GoToSurface] Stopped
2019-10-03T16:04:42.172Z,1570118682.172 [profile_station:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-10-03T16:04:42.172Z,1570118682.172 [profile_station:NeedComms:D] Stopped
2019-10-03T16:04:42.172Z,1570118682.172 [profile_station:StandardEnvelopes] Stopped
2019-10-03T16:04:42.172Z,1570118682.172 [profile_station:StandardEnvelopes](DEBUG): Aggregate::uninitialize profile_station:StandardEnvelopes
2019-10-03T16:04:42.172Z,1570118682.172 [profile_station:StandardEnvelopes:A.AltitudeEnvelope] Stopped
2019-10-03T16:04:42.172Z,1570118682.172 [profile_station:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent.
2019-10-03T16:04:42.173Z,1570118682.173 [profile_station:StandardEnvelopes:B.DepthEnvelope] Stopped
2019-10-03T16:04:42.173Z,1570118682.173 [profile_station:StandardEnvelopes:B.DepthEnvelope](DEBUG): Uninitialize.
2019-10-03T16:04:42.173Z,1570118682.173 [profile_station:StandardEnvelopes:C.OffshoreEnvelope] Stopped
2019-10-03T16:04:42.173Z,1570118682.173 [profile_station:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Uninitialize OffshoreEnvelopeComponent.
2019-10-03T16:04:42.173Z,1570118682.173 [profile_station:StartingMission] Stopped
2019-10-03T16:04:42.173Z,1570118682.173 [profile_station:StartingMission](DEBUG): Aggregate::uninitialize profile_station:StartingMission
2019-10-03T16:04:42.173Z,1570118682.173 [profile_station:I.Pitch] Stopped
2019-10-03T16:04:42.173Z,1570118682.173 [profile_station:J.Buoyancy] Stopped
2019-10-03T16:04:42.173Z,1570118682.173 [profile_station:J.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2019-10-03T16:04:42.173Z,1570118682.173 [profile_station:K.SetSpeed] Stopped
2019-10-03T16:04:42.173Z,1570118682.173 [profile_station:K.SetSpeed](DEBUG): Uninitialize.
2019-10-03T16:04:42.173Z,1570118682.173 [profile_station:L.DepthEnvelope] Stopped
2019-10-03T16:04:42.173Z,1570118682.173 [profile_station:L.DepthEnvelope](DEBUG): Uninitialize.
2019-10-03T16:04:42.173Z,1570118682.173 [profile_station:M.AltitudeEnvelope] Stopped
2019-10-03T16:04:42.174Z,1570118682.174 [profile_station:M.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent.
2019-10-03T16:04:42.174Z,1570118682.174 [profile_station:N.YoYo] Stopped
2019-10-03T16:04:42.174Z,1570118682.174 [profile_station:N.YoYo](DEBUG): Uninitialize YoYoComponent.
2019-10-03T16:04:42.351Z,1570118682.351 [WetLabsBB2FL](INFO): Powering down
2019-10-03T16:04:42.545Z,1570118682.545 [MissionManager](IMPORTANT): Started mission Default
2019-10-03T16:04:42.545Z,1570118682.545 [Default] Running Loop=1
2019-10-03T16:04:42.545Z,1570118682.545 [Default](DEBUG): Aggregate::initialize Default
2019-10-03T16:04:42.545Z,1570118682.545 [Default:B.GoToSurface] Running Loop=1
2019-10-03T16:04:42.545Z,1570118682.545 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-10-03T16:04:42.545Z,1570118682.545 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-10-03T16:04:42.546Z,1570118682.546 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-10-03T16:04:42.546Z,1570118682.546 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-10-03T16:04:42.547Z,1570118682.547 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-10-03T16:04:42.547Z,1570118682.547 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-10-03T16:04:42.547Z,1570118682.547 [Default:A.Wait] Running Loop=1
2019-10-03T16:04:42.547Z,1570118682.547 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-10-03T16:04:47.288Z,1570118687.288 [WetLabsUBAT](INFO): Got instrument prompt
2019-10-03T16:04:49.420Z,1570118689.420 [WetLabsUBAT](INFO): Got instrument prompt
2019-10-03T16:04:50.486Z,1570118690.486 [WetLabsUBAT..StreamSerialDriver](INFO): device metadata:
Override SerialDriver::getDeviceMetadata()
2019-10-03T16:04:51.905Z,1570118691.905 [DataOverHttps](INFO): Sending 1193 bytes from file Logs/20191003T160129/Express0001.lzma
2019-10-03T16:04:52.993Z,1570118692.993 [NAL9602](IMPORTANT): SBD MO Status=0, MOMSN=1897, MT Status=1, MTMSN=55
2019-10-03T16:04:52.993Z,1570118692.993 [NAL9602](INFO): Data available in MT queue
2019-10-03T16:04:53.483Z,1570118693.483 [NAL9602](INFO): Received command:Ibit
2019-10-03T16:04:53.558Z,1570118693.559 [CommandLine](IMPORTANT): got command ibit
2019-10-03T16:04:53.812Z,1570118693.812 [BackSeatDriver](INFO): Sent LCM shutdown request.
2019-10-03T16:04:53.832Z,1570118693.832 [IBIT](IMPORTANT): Beginning Initiated BIT
2019-10-03T16:04:53.832Z,1570118693.832 [IBIT](IMPORTANT): Beginning control surface checks.
2019-10-03T16:04:53.835Z,1570118693.835 [CBIT](IMPORTANT): Beginning ground fault scan
2019-10-03T16:04:53.908Z,1570118693.908 [DataOverHttps](INFO): Moved sent file to Logs/20191003T160129/Express0001.lzma.bak
2019-10-03T16:04:53.908Z,1570118693.908 [DataOverHttps](INFO): SBD MOMSN=11845219
2019-10-03T16:04:54.630Z,1570118694.630 [WetLabsUBAT](INFO): isDataRequested() is false
2019-10-03T16:04:55.034Z,1570118695.034 [WetLabsUBAT](INFO): Powering down
2019-10-03T16:04:55.426Z,1570118695.426 [NAL9602](DEBUG): Fix Requested
2019-10-03T16:04:55.819Z,1570118695.819 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160454.00,A,3648.30820,N,12147.14456,W,0.019,41.65,031019,,,A*49
2019-10-03T16:04:55.821Z,1570118695.821 [NAL9602](INFO): GPS fix at 20191003T160454: (36.805137, -121.785743)
2019-10-03T16:04:58.658Z,1570118698.658 [NAL9602](DEBUG): Fix Requested
2019-10-03T16:04:59.057Z,1570118699.057 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160457.00,A,3648.30809,N,12147.14467,W,0.019,41.65,031019,,,A*43
2019-10-03T16:04:59.060Z,1570118699.060 [NAL9602](INFO): GPS fix at 20191003T160457: (36.805135, -121.785745)
2019-10-03T16:05:01.510Z,1570118701.510 [NAL9602](DEBUG): Fix Requested
2019-10-03T16:05:01.905Z,1570118701.905 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160500.00,A,3648.30806,N,12147.14474,W,0.019,41.65,031019,,,A*4D
2019-10-03T16:05:01.919Z,1570118701.919 [NAL9602](INFO): GPS fix at 20191003T160500: (36.805134, -121.785746)
2019-10-03T16:05:04.342Z,1570118704.342 [NAL9602](DEBUG): Fix Requested
2019-10-03T16:05:04.728Z,1570118704.728 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160503.00,A,3648.30809,N,12147.14475,W,0.019,41.65,031019,,,A*40
2019-10-03T16:05:04.730Z,1570118704.730 [NAL9602](INFO): GPS fix at 20191003T160503: (36.805135, -121.785746)
2019-10-03T16:05:04.800Z,1570118704.800 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.051203
CHAN A1 (24V): 0.087734
CHAN A2 (12V): 0.030809
CHAN A3 (5V): 0.009426
CHAN B0 (3.3V): 0.006999
CHAN B1 (3.15aV): 0.005819
CHAN B2 (3.15bV): 0.006726
CHAN B3 (GND): -0.002410
OPEN: -0.001712
Full Scale Calc: 4.765 mA, -1.589 mA
2019-10-03T16:05:07.571Z,1570118707.571 [NAL9602](DEBUG): Fix Requested
2019-10-03T16:05:07.985Z,1570118707.985 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160506.00,A,3648.30812,N,12147.14481,W,0.136,41.65,031019,,,D*4D
2019-10-03T16:05:07.988Z,1570118707.988 [NAL9602](INFO): GPS fix at 20191003T160506: (36.805135, -121.785747)
2019-10-03T16:05:09.162Z,1570118709.162 [BackSeatDriver](INFO): Powering down
2019-10-03T16:05:09.566Z,1570118709.566 [BackSeatDriver](INFO): Unsubscribing from LCM channel: BackSeatDriverStatus
2019-10-03T16:05:09.567Z,1570118709.567 [BackSeatDriver](INFO): Unsubscribing from LCM channel: BioLumProxies
2019-10-03T16:05:10.399Z,1570118710.399 [NAL9602](DEBUG): Fix Requested
2019-10-03T16:05:10.799Z,1570118710.799 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160509.00,A,3648.30808,N,12147.14475,W,0.019,41.65,031019,,,D*4E
2019-10-03T16:05:10.801Z,1570118710.801 [NAL9602](INFO): GPS fix at 20191003T160509: (36.805135, -121.785746)
2019-10-03T16:05:13.626Z,1570118713.626 [NAL9602](DEBUG): Fix Requested
2019-10-03T16:05:14.020Z,1570118714.020 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160512.00,A,3648.30814,N,12147.14464,W,0.097,41.65,031019,,,D*4F
2019-10-03T16:05:14.022Z,1570118714.022 [NAL9602](INFO): GPS fix at 20191003T160512: (36.805136, -121.785744)
2019-10-03T16:05:16.458Z,1570118716.458 [NAL9602](DEBUG): Fix Requested
2019-10-03T16:05:16.856Z,1570118716.856 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160515.00,A,3648.30808,N,12147.14477,W,0.019,41.65,031019,,,D*41
2019-10-03T16:05:16.858Z,1570118716.858 [NAL9602](INFO): GPS fix at 20191003T160515: (36.805135, -121.785746)
2019-10-03T16:05:19.690Z,1570118719.690 [NAL9602](DEBUG): Fix Requested
2019-10-03T16:05:20.098Z,1570118720.098 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160518.00,A,3648.30808,N,12147.14483,W,0.058,41.65,031019,,,D*42
2019-10-03T16:05:20.104Z,1570118720.104 [NAL9602](INFO): GPS fix at 20191003T160518: (36.805135, -121.785747)
2019-10-03T16:05:22.514Z,1570118722.514 [NAL9602](DEBUG): Fix Requested
2019-10-03T16:05:22.914Z,1570118722.914 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160521.00,A,3648.30812,N,12147.14501,W,0.097,41.65,031019,,,D*4B
2019-10-03T16:05:22.916Z,1570118722.916 [NAL9602](INFO): GPS fix at 20191003T160521: (36.805135, -121.785750)
2019-10-03T16:05:25.355Z,1570118725.355 [NAL9602](DEBUG): Fix Requested
2019-10-03T16:05:25.737Z,1570118725.737 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160524.00,A,3648.30821,N,12147.14511,W,0.039,41.65,031019,,,D*4B
2019-10-03T16:05:25.740Z,1570118725.740 [NAL9602](INFO): GPS fix at 20191003T160524: (36.805137, -121.785752)
2019-10-03T16:05:28.610Z,1570118728.610 [NAL9602](DEBUG): Fix Requested
2019-10-03T16:05:28.973Z,1570118728.973 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160527.00,A,3648.30815,N,12147.14535,W,0.019,41.65,031019,,,D*4B
2019-10-03T16:05:28.978Z,1570118728.978 [NAL9602](INFO): GPS fix at 20191003T160527: (36.805136, -121.785756)
2019-10-03T16:05:31.414Z,1570118731.414 [NAL9602](DEBUG): Fix Requested
2019-10-03T16:05:31.801Z,1570118731.801 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160530.00,A,3648.30805,N,12147.14549,W,0.039,41.65,031019,,,D*45
2019-10-03T16:05:31.803Z,1570118731.803 [NAL9602](INFO): GPS fix at 20191003T160530: (36.805134, -121.785758)
2019-10-03T16:05:34.646Z,1570118734.646 [NAL9602](DEBUG): Fix Requested
2019-10-03T16:05:35.028Z,1570118735.028 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160533.00,A,3648.30806,N,12147.14539,W,0.019,41.65,031019,,,D*40
2019-10-03T16:05:35.030Z,1570118735.030 [NAL9602](INFO): GPS fix at 20191003T160533: (36.805134, -121.785757)
2019-10-03T16:05:37.466Z,1570118737.466 [NAL9602](DEBUG): Fix Requested
2019-10-03T16:05:37.858Z,1570118737.858 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160536.00,A,3648.30823,N,12147.14532,W,0.019,41.65,031019,,,D*49
2019-10-03T16:05:37.861Z,1570118737.861 [NAL9602](INFO): GPS fix at 20191003T160536: (36.805137, -121.785755)
2019-10-03T16:05:40.349Z,1570118740.349 [IBIT](IMPORTANT): Communications Status:
Fix Status: 1
Iridium Signal Strength: 3
Latitude: 36.805138 Longitude: -121.785759
2019-10-03T16:05:40.702Z,1570118740.702 [NAL9602](DEBUG): Fix Requested
2019-10-03T16:05:40.803Z,1570118740.803 [IBIT](FAULT): Warning: Battery Data not active. Expected only when running primaries. Threshold checking not active.
2019-10-03T16:05:41.093Z,1570118741.093 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160539.00,A,3648.30833,N,12147.14531,W,0.058,41.65,031019,,,D*41
2019-10-03T16:05:41.106Z,1570118741.106 [NAL9602](INFO): GPS fix at 20191003T160539: (36.805139, -121.785755)
2019-10-03T16:05:41.143Z,1570118741.143 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2019-10-03T16:05:41.144Z,1570118741.144 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2019-10-03T16:05:41.144Z,1570118741.144 [IBIT](IMPORTANT): Pressure:7.297362 PSI
2019-10-03T16:05:41.144Z,1570118741.144 [IBIT](IMPORTANT): Humidity:8.686363 %
2019-10-03T16:05:41.562Z,1570118741.562 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2019-10-03T16:05:41.563Z,1570118741.563 [IBIT](IMPORTANT): buoyancyNeutral: 300.000000 cc
2019-10-03T16:05:41.563Z,1570118741.563 [IBIT](IMPORTANT): massDefault: 1.000000 cm
2019-10-03T16:05:41.563Z,1570118741.563 [IBIT](IMPORTANT): stopDepth: 215.000000 m
2019-10-03T16:05:41.564Z,1570118741.564 [IBIT](IMPORTANT): abortDepth: 255.000000 m
2019-10-03T16:05:41.564Z,1570118741.564 [IBIT](IMPORTANT): IBIT PASSED
2019-10-03T16:05:41.926Z,1570118741.926 [Default:A.Wait](INFO): Done Waiting.
2019-10-03T16:05:41.927Z,1570118741.927 [Default:A.Wait] Stopped
2019-10-03T16:05:41.927Z,1570118741.927 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-10-03T16:05:42.469Z,1570118742.469 [Default:CheckIn] Running Loop=1
2019-10-03T16:05:42.469Z,1570118742.469 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-10-03T16:05:42.469Z,1570118742.469 [Default:CheckIn:Read_GPS] Running Loop=1
2019-10-03T16:05:42.761Z,1570118742.761 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2019-10-03T16:05:43.522Z,1570118743.522 [NAL9602](DEBUG): Fix Requested
2019-10-03T16:05:43.952Z,1570118743.952 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160542.00,A,3648.30853,N,12147.14528,W,0.039,41.65,031019,,,D*44
2019-10-03T16:05:43.959Z,1570118743.959 [NAL9602](INFO): GPS fix at 20191003T160542: (36.805142, -121.785755)
2019-10-03T16:05:44.009Z,1570118744.009 [Default:CheckIn:Read_GPS] Stopped
2019-10-03T16:05:44.010Z,1570118744.010 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-10-03T16:05:44.374Z,1570118744.374 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-10-03T16:05:51.546Z,1570118751.546 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20191003T160129/Courier0004.lzma
2019-10-03T16:05:53.553Z,1570118753.553 [DataOverHttps](INFO): Moved sent file to Logs/20191003T160129/Courier0004.lzma.bak
2019-10-03T16:05:53.553Z,1570118753.553 [DataOverHttps](INFO): SBD MOMSN=11845249
2019-10-03T16:06:11.842Z,1570118771.842 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20191003T160129/Courier0007.lzma
2019-10-03T16:06:13.848Z,1570118773.848 [DataOverHttps](INFO): Moved sent file to Logs/20191003T160129/Courier0007.lzma.bak
2019-10-03T16:06:13.848Z,1570118773.848 [DataOverHttps](INFO): SBD MOMSN=11845253
2019-10-03T16:06:16.235Z,1570118776.235 [NAL9602](INFO): Not Powering down - fast GPS
2019-10-03T16:06:34.359Z,1570118794.359 [DataOverHttps](INFO): Sending 423 bytes from file Logs/20191003T160129/Express0005.lzma
2019-10-03T16:06:36.364Z,1570118796.364 [DataOverHttps](INFO): Moved sent file to Logs/20191003T160129/Express0005.lzma.bak
2019-10-03T16:06:36.364Z,1570118796.364 [DataOverHttps](INFO): SBD MOMSN=11845256
2019-10-03T16:06:54.732Z,1570118814.732 [DataOverHttps](INFO): Sending 740 bytes from file Logs/20191003T160129/Express0008.lzma
2019-10-03T16:06:56.736Z,1570118816.736 [DataOverHttps](INFO): Moved sent file to Logs/20191003T160129/Express0008.lzma.bak
2019-10-03T16:06:56.736Z,1570118816.736 [DataOverHttps](INFO): SBD MOMSN=11845272
2019-10-03T16:06:58.701Z,1570118818.701 [Default:CheckIn:Read_Iridium] Stopped
2019-10-03T16:06:58.702Z,1570118818.702 [Default:CheckIn:C.Wait] Running Loop=1
2019-10-03T16:06:58.702Z,1570118818.702 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-10-03T16:07:26.252Z,1570118846.252 [CommandLine](IMPORTANT): got command configSet list
2019-10-03T16:07:26.252Z,1570118846.252 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2019-10-03T16:07:26.253Z,1570118846.253 [CommandLine](IMPORTANT): CBIT.gf24Offset=143 microampere;

2019-10-03T16:07:26.253Z,1570118846.253 [CommandLine](IMPORTANT): Express none RDI_Pathfinder.height_above_sea_floor;

2019-10-03T16:07:26.253Z,1570118846.253 [CommandLine](IMPORTANT): Express linearApproximation Tracking.range_to_contact 10.000000 meter;

2019-10-03T16:07:26.254Z,1570118846.254 [CommandLine](IMPORTANT): Express none WetLabsUBAT.biolum_potential;

2019-10-03T16:07:26.254Z,1570118846.254 [CommandLine](IMPORTANT): Express none WetLabsUBAT.flow_rate;

2019-10-03T16:07:26.254Z,1570118846.254 [CommandLine](IMPORTANT): Express linearApproximation height_above_sea_floor 10.000000 meter;

2019-10-03T16:07:26.254Z,1570118846.254 [CommandLine](IMPORTANT): Normal linearApproximation WetLabsUBAT.biolum_potential 1000000.000000 none;

2019-10-03T16:07:26.254Z,1570118846.254 [CommandLine](IMPORTANT): VerticalControl.massDefault=10 millimeter;

2019-10-03T16:07:44.937Z,1570118864.937 [CommandLine](IMPORTANT): got command get platform_battery_voltage
2019-10-03T16:07:44.938Z,1570118864.938 [CommandLine](FAULT): Element has no value
2019-10-03T16:08:07.047Z,1570118887.047 [CommandLine](IMPORTANT): got command get BPC1.platform_battery_voltage
2019-10-03T16:08:07.047Z,1570118887.047 [CommandLine](IMPORTANT): BPC1.platform_battery_voltage nan V
2019-10-03T16:08:53.166Z,1570118933.166 [CommandLine](IMPORTANT): got command failComponent
2019-10-03T16:08:53.167Z,1570118933.167 [CommandLine](IMPORTANT): Failed components:
2019-10-03T16:08:53.167Z,1570118933.167 [CommandLine](IMPORTANT): No failed Components.
2019-10-03T16:09:12.839Z,1570118952.839 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2019-10-03T16:09:12.846Z,1570118952.846 [BPC1](INFO): Received data from all battery sticks.
2019-10-03T16:11:59.286Z,1570119119.286 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-10-03T16:11:59.286Z,1570119119.286 [Default:CheckIn:C.Wait] Stopped
2019-10-03T16:11:59.286Z,1570119119.286 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-10-03T16:11:59.286Z,1570119119.286 [Default:CheckIn:D] Running Loop=1
2019-10-03T16:11:59.677Z,1570119119.677 [Default:CheckIn:D] Stopped
2019-10-03T16:11:59.677Z,1570119119.677 [Default:CheckIn:E] Running Loop=1
2019-10-03T16:12:00.078Z,1570119120.078 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 7.285536 min 
2019-10-03T16:12:00.078Z,1570119120.078 [Default:CheckIn:E] Stopped
2019-10-03T16:12:00.078Z,1570119120.078 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-10-03T16:12:00.078Z,1570119120.078 [Default:CheckIn] Stopped
2019-10-03T16:12:00.078Z,1570119120.078 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-10-03T16:12:00.079Z,1570119120.079 [Default:CheckIn](INFO): Running loop #2
2019-10-03T16:12:00.079Z,1570119120.079 [Default:CheckIn] Running Loop=2
2019-10-03T16:12:00.079Z,1570119120.079 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-10-03T16:12:00.079Z,1570119120.079 [Default:CheckIn:Read_GPS] Running Loop=1
2019-10-03T16:12:01.678Z,1570119121.678 [NAL9602](DEBUG): Fix Requested
2019-10-03T16:12:02.087Z,1570119122.087 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,161200.00,A,3648.52046,N,12147.13986,W,5.851,306.05,031019,,,D*76
2019-10-03T16:12:02.089Z,1570119122.089 [NAL9602](INFO): GPS fix at 20191003T161200: (36.808674, -121.785664)
2019-10-03T16:12:02.142Z,1570119122.142 [Default:CheckIn:Read_GPS] Stopped
2019-10-03T16:12:02.142Z,1570119122.142 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-10-03T16:12:11.603Z,1570119131.603 [DataOverHttps](INFO): Sending 222 bytes from file Logs/20191003T160129/Courier0010.lzma
2019-10-03T16:12:13.608Z,1570119133.608 [DataOverHttps](INFO): Moved sent file to Logs/20191003T160129/Courier0010.lzma.bak
2019-10-03T16:12:13.608Z,1570119133.608 [DataOverHttps](INFO): SBD MOMSN=11845321
2019-10-03T16:12:23.617Z,1570119143.617 [NAL9602](INFO): SBD MO Status=0, MOMSN=1898, MT Status=0, MTMSN=0
2019-10-03T16:12:23.617Z,1570119143.617 [NAL9602](INFO): No messages in MT queue
2019-10-03T16:12:31.055Z,1570119151.055 [DataOverHttps](INFO): Sending 564 bytes from file Logs/20191003T160129/Express0011.lzma
2019-10-03T16:12:33.060Z,1570119153.060 [DataOverHttps](INFO): Moved sent file to Logs/20191003T160129/Express0011.lzma.bak
2019-10-03T16:12:33.060Z,1570119153.060 [DataOverHttps](INFO): SBD MOMSN=11845324
2019-10-03T16:12:34.985Z,1570119154.985 [Default:CheckIn:Read_Iridium] Stopped
2019-10-03T16:12:34.985Z,1570119154.985 [Default:CheckIn:C.Wait] Running Loop=1
2019-10-03T16:12:34.985Z,1570119154.985 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-10-03T16:12:54.317Z,1570119174.317 [NAL9602](INFO): Not Powering down - fast GPS
2019-10-03T16:17:35.527Z,1570119455.527 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-10-03T16:17:35.527Z,1570119455.527 [Default:CheckIn:C.Wait] Stopped
2019-10-03T16:17:35.527Z,1570119455.527 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-10-03T16:17:35.527Z,1570119455.527 [Default:CheckIn:D] Running Loop=1
2019-10-03T16:17:35.995Z,1570119455.995 [Default:CheckIn:D] Stopped
2019-10-03T16:17:35.995Z,1570119455.995 [Default:CheckIn:E] Running Loop=1
2019-10-03T16:17:36.348Z,1570119456.348 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 12.890835 min 
2019-10-03T16:17:36.348Z,1570119456.348 [Default:CheckIn:E] Stopped
2019-10-03T16:17:36.349Z,1570119456.349 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-10-03T16:17:36.349Z,1570119456.349 [Default:CheckIn] Stopped
2019-10-03T16:17:36.349Z,1570119456.349 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-10-03T16:17:36.349Z,1570119456.349 [Default:CheckIn](INFO): Running loop #3
2019-10-03T16:17:36.349Z,1570119456.349 [Default:CheckIn] Running Loop=3
2019-10-03T16:17:36.349Z,1570119456.349 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-10-03T16:17:36.349Z,1570119456.349 [Default:CheckIn:Read_GPS] Running Loop=1
2019-10-03T16:17:37.947Z,1570119457.947 [NAL9602](DEBUG): Fix Requested
2019-10-03T16:17:38.337Z,1570119458.337 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,161737.00,A,3648.28901,N,12148.73508,W,12.285,280.73,031019,,,D*48
2019-10-03T16:17:38.340Z,1570119458.340 [NAL9602](INFO): GPS fix at 20191003T161737: (36.804817, -121.812251)
2019-10-03T16:17:38.388Z,1570119458.388 [Default:CheckIn:Read_GPS] Stopped
2019-10-03T16:17:38.388Z,1570119458.388 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-10-03T16:17:46.330Z,1570119466.330 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20191003T160129/Courier0013.lzma
2019-10-03T16:17:48.336Z,1570119468.336 [DataOverHttps](INFO): Moved sent file to Logs/20191003T160129/Courier0013.lzma.bak
2019-10-03T16:17:48.336Z,1570119468.336 [DataOverHttps](INFO): SBD MOMSN=11845362
2019-10-03T16:17:58.533Z,1570119478.533 [NAL9602](INFO): SBD MO Status=2, MOMSN=1899, MT Status=2, MTMSN=0
2019-10-03T16:17:58.533Z,1570119478.533 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-10-03T16:18:08.257Z,1570119488.257 [NAL9602](INFO): SBD MO Status=0, MOMSN=1899, MT Status=0, MTMSN=0
2019-10-03T16:18:08.257Z,1570119488.257 [NAL9602](INFO): No messages in MT queue
2019-10-03T16:18:08.638Z,1570119488.638 [DataOverHttps](INFO): Sending 132 bytes from file Logs/20191003T160129/Express0014.lzma
2019-10-03T16:18:10.644Z,1570119490.644 [DataOverHttps](INFO): Moved sent file to Logs/20191003T160129/Express0014.lzma.bak
2019-10-03T16:18:10.644Z,1570119490.644 [DataOverHttps](INFO): SBD MOMSN=11845366
2019-10-03T16:18:12.348Z,1570119492.348 [Default:CheckIn:Read_Iridium] Stopped
2019-10-03T16:18:12.348Z,1570119492.348 [Default:CheckIn:C.Wait] Running Loop=1
2019-10-03T16:18:12.348Z,1570119492.348 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-10-03T16:18:38.947Z,1570119518.947 [NAL9602](INFO): Not Powering down - fast GPS
2019-10-03T16:21:15.330Z,1570119675.330 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2019-10-03T16:21:15.330Z,1570119675.330 [RDI_Pathfinder](ERROR): Failed to parse:
:RA,  0.00,   0.00,   0.00,   0.00
2019-10-03T16:23:12.961Z,1570119792.961 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-10-03T16:23:12.961Z,1570119792.961 [Default:CheckIn:C.Wait] Stopped
2019-10-03T16:23:12.961Z,1570119792.961 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-10-03T16:23:12.961Z,1570119792.961 [Default:CheckIn:D] Running Loop=1
2019-10-03T16:23:13.347Z,1570119793.347 [Default:CheckIn:D] Stopped
2019-10-03T16:23:13.347Z,1570119793.347 [Default:CheckIn:E] Running Loop=1
2019-10-03T16:23:13.739Z,1570119793.739 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 18.513371 min 
2019-10-03T16:23:13.739Z,1570119793.739 [Default:CheckIn:E] Stopped
2019-10-03T16:23:13.739Z,1570119793.739 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-10-03T16:23:13.739Z,1570119793.739 [Default:CheckIn] Stopped
2019-10-03T16:23:13.739Z,1570119793.739 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-10-03T16:23:13.739Z,1570119793.739 [Default:CheckIn](INFO): Running loop #4
2019-10-03T16:23:13.740Z,1570119793.740 [Default:CheckIn] Running Loop=4
2019-10-03T16:23:13.740Z,1570119793.740 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-10-03T16:23:13.740Z,1570119793.740 [Default:CheckIn:Read_GPS] Running Loop=1
2019-10-03T16:23:15.334Z,1570119795.334 [NAL9602](DEBUG): Fix Requested
2019-10-03T16:23:15.769Z,1570119795.769 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162315.00,A,3648.21920,N,12150.85334,W,14.793,262.91,031019,,,A*4D
2019-10-03T16:23:15.788Z,1570119795.788 [NAL9602](INFO): GPS fix at 20191003T162315: (36.803653, -121.847556)
2019-10-03T16:23:15.827Z,1570119795.827 [Default:CheckIn:Read_GPS] Stopped
2019-10-03T16:23:15.827Z,1570119795.827 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-10-03T16:23:24.602Z,1570119804.602 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20191003T160129/Courier0016.lzma
2019-10-03T16:23:26.608Z,1570119806.608 [DataOverHttps](INFO): Moved sent file to Logs/20191003T160129/Courier0016.lzma.bak
2019-10-03T16:23:26.608Z,1570119806.608 [DataOverHttps](INFO): SBD MOMSN=11845390
2019-10-03T16:23:47.410Z,1570119827.410 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20191003T160129/Express0017.lzma
2019-10-03T16:23:49.416Z,1570119829.416 [DataOverHttps](INFO): Moved sent file to Logs/20191003T160129/Express0017.lzma.bak
2019-10-03T16:23:49.416Z,1570119829.416 [DataOverHttps](INFO): SBD MOMSN=11845418
2019-10-03T16:23:51.343Z,1570119831.342 [Default:CheckIn:Read_Iridium] Stopped
2019-10-03T16:23:51.343Z,1570119831.343 [Default:CheckIn:C.Wait] Running Loop=1
2019-10-03T16:23:51.343Z,1570119831.343 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-10-03T16:24:44.617Z,1570119884.617 [NAL9602](INFO): SBD MO Status=0, MOMSN=1900, MT Status=0, MTMSN=0
2019-10-03T16:24:44.618Z,1570119884.618 [NAL9602](INFO): No messages in MT queue
2019-10-03T16:25:14.960Z,1570119914.960 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude
2019-10-03T16:25:14.960Z,1570119914.960 [RDI_Pathfinder](ERROR): Failed to parse:
:BD +0.00,        +0.00,        +0.00,   0.00,1401.91
2019-10-03T16:25:15.327Z,1570119915.327 [NAL9602](INFO): Not Powering down - fast GPS
2019-10-03T16:28:51.909Z,1570120131.909 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-10-03T16:28:51.909Z,1570120131.909 [Default:CheckIn:C.Wait] Stopped
2019-10-03T16:28:51.909Z,1570120131.909 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-10-03T16:28:51.909Z,1570120131.909 [Default:CheckIn:D] Running Loop=1
2019-10-03T16:28:52.358Z,1570120132.358 [Default:CheckIn:D] Stopped
2019-10-03T16:28:52.358Z,1570120132.358 [Default:CheckIn:E] Running Loop=1
2019-10-03T16:28:52.720Z,1570120132.720 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 24.163544 min 
2019-10-03T16:28:52.720Z,1570120132.720 [Default:CheckIn:E] Stopped
2019-10-03T16:28:52.721Z,1570120132.721 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-10-03T16:28:52.721Z,1570120132.721 [Default:CheckIn] Stopped
2019-10-03T16:28:52.721Z,1570120132.721 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-10-03T16:28:52.721Z,1570120132.721 [Default:CheckIn](INFO): Running loop #5
2019-10-03T16:28:52.721Z,1570120132.721 [Default:CheckIn] Running Loop=5
2019-10-03T16:28:52.721Z,1570120132.721 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-10-03T16:28:52.721Z,1570120132.721 [Default:CheckIn:Read_GPS] Running Loop=1
2019-10-03T16:28:53.946Z,1570120133.946 [RDI_Pathfinder](ERROR): only read 1 of 4 data items
2019-10-03T16:28:53.946Z,1570120133.946 [RDI_Pathfinder](ERROR): Failed to parse:
:BS,-32768-32768,V
2019-10-03T16:28:54.318Z,1570120134.318 [NAL9602](DEBUG): Fix Requested
2019-10-03T16:28:54.709Z,1570120134.709 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162854.00,A,3647.84309,N,12153.06482,W,19.827,259.83,031019,,,A*46
2019-10-03T16:28:54.711Z,1570120134.711 [NAL9602](INFO): GPS fix at 20191003T162854: (36.797385, -121.884414)
2019-10-03T16:28:54.761Z,1570120134.761 [Default:CheckIn:Read_GPS] Stopped
2019-10-03T16:28:54.761Z,1570120134.761 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-10-03T16:29:03.090Z,1570120143.090 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20191003T160129/Courier0019.lzma
2019-10-03T16:29:05.096Z,1570120145.096 [DataOverHttps](INFO): Moved sent file to Logs/20191003T160129/Courier0019.lzma.bak
2019-10-03T16:29:05.096Z,1570120145.096 [DataOverHttps](INFO): SBD MOMSN=11845513
2019-10-03T16:29:08.869Z,1570120148.869 [NAL9602](INFO): SBD MO Status=0, MOMSN=1901, MT Status=0, MTMSN=0
2019-10-03T16:29:08.869Z,1570120148.869 [NAL9602](INFO): No messages in MT queue
2019-10-03T16:29:22.546Z,1570120162.546 [DataOverHttps](INFO): Sending 135 bytes from file Logs/20191003T160129/Express0020.lzma
2019-10-03T16:29:24.552Z,1570120164.552 [DataOverHttps](INFO): Moved sent file to Logs/20191003T160129/Express0020.lzma.bak
2019-10-03T16:29:24.552Z,1570120164.552 [DataOverHttps](INFO): SBD MOMSN=11845516
2019-10-03T16:29:26.287Z,1570120166.287 [Default:CheckIn:Read_Iridium] Stopped
2019-10-03T16:29:26.288Z,1570120166.288 [Default:CheckIn:C.Wait] Running Loop=1
2019-10-03T16:29:26.288Z,1570120166.288 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-10-03T16:29:39.578Z,1570120179.578 [NAL9602](INFO): Not Powering down - fast GPS
2019-10-03T16:34:26.884Z,1570120466.884 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-10-03T16:34:26.884Z,1570120466.884 [Default:CheckIn:C.Wait] Stopped
2019-10-03T16:34:26.884Z,1570120466.884 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-10-03T16:34:26.884Z,1570120466.884 [Default:CheckIn:D] Running Loop=1
2019-10-03T16:34:27.287Z,1570120467.287 [Default:CheckIn:D] Stopped
2019-10-03T16:34:27.287Z,1570120467.287 [Default:CheckIn:E] Running Loop=1
2019-10-03T16:34:27.673Z,1570120467.673 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 29.745691 min 
2019-10-03T16:34:27.673Z,1570120467.673 [Default:CheckIn:E] Stopped
2019-10-03T16:34:27.673Z,1570120467.673 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-10-03T16:34:27.673Z,1570120467.673 [Default:CheckIn] Stopped
2019-10-03T16:34:27.673Z,1570120467.673 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-10-03T16:34:27.673Z,1570120467.673 [Default:CheckIn](INFO): Running loop #6
2019-10-03T16:34:27.673Z,1570120467.673 [Default:CheckIn] Running Loop=6
2019-10-03T16:34:27.673Z,1570120467.673 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-10-03T16:34:27.674Z,1570120467.674 [Default:CheckIn:Read_GPS] Running Loop=1
2019-10-03T16:34:29.274Z,1570120469.274 [NAL9602](DEBUG): Fix Requested
2019-10-03T16:34:29.669Z,1570120469.669 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163429.00,A,3647.43275,N,12155.11543,W,17.456,250.63,031019,,,A*4F
2019-10-03T16:34:29.672Z,1570120469.672 [NAL9602](INFO): GPS fix at 20191003T163429: (36.790546, -121.918590)
2019-10-03T16:34:29.695Z,1570120469.695 [Default:CheckIn:Read_GPS] Stopped
2019-10-03T16:34:29.695Z,1570120469.695 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-10-03T16:34:37.694Z,1570120477.694 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20191003T160129/Courier0022.lzma
2019-10-03T16:34:39.700Z,1570120479.700 [DataOverHttps](INFO): Moved sent file to Logs/20191003T160129/Courier0022.lzma.bak
2019-10-03T16:34:39.700Z,1570120479.700 [DataOverHttps](INFO): SBD MOMSN=11845527
2019-10-03T16:34:54.313Z,1570120494.313 [NAL9602](INFO): SBD MO Status=0, MOMSN=1902, MT Status=0, MTMSN=0
2019-10-03T16:34:54.313Z,1570120494.313 [NAL9602](INFO): No messages in MT queue
2019-10-03T16:34:58.858Z,1570120498.858 [DataOverHttps](INFO): Sending 136 bytes from file Logs/20191003T160129/Express0023.lzma
2019-10-03T16:35:00.864Z,1570120500.864 [DataOverHttps](INFO): Moved sent file to Logs/20191003T160129/Express0023.lzma.bak
2019-10-03T16:35:00.864Z,1570120500.864 [DataOverHttps](INFO): SBD MOMSN=11845530
2019-10-03T16:35:02.829Z,1570120502.829 [Default:CheckIn:Read_Iridium] Stopped
2019-10-03T16:35:02.829Z,1570120502.829 [Default:CheckIn:C.Wait] Running Loop=1
2019-10-03T16:35:02.829Z,1570120502.829 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-10-03T16:35:25.015Z,1570120525.015 [NAL9602](INFO): Not Powering down - fast GPS
2019-10-03T16:39:42.235Z,1570120782.235 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-10-03T16:39:45.259Z,1570120785.259 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.252953
2019-10-03T16:40:03.409Z,1570120803.409 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-10-03T16:40:03.409Z,1570120803.409 [Default:CheckIn:C.Wait] Stopped
2019-10-03T16:40:03.409Z,1570120803.409 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-10-03T16:40:03.409Z,1570120803.409 [Default:CheckIn:D] Running Loop=1
2019-10-03T16:40:03.814Z,1570120803.814 [Default:CheckIn:D] Stopped
2019-10-03T16:40:03.814Z,1570120803.814 [Default:CheckIn:E] Running Loop=1
2019-10-03T16:40:04.231Z,1570120804.231 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 35.354476 min 
2019-10-03T16:40:04.231Z,1570120804.231 [Default:CheckIn:E] Stopped
2019-10-03T16:40:04.231Z,1570120804.231 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-10-03T16:40:04.231Z,1570120804.231 [Default:CheckIn] Stopped
2019-10-03T16:40:04.231Z,1570120804.231 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-10-03T16:40:04.231Z,1570120804.231 [Default:CheckIn](INFO): Running loop #7
2019-10-03T16:40:04.231Z,1570120804.231 [Default:CheckIn] Running Loop=7
2019-10-03T16:40:04.232Z,1570120804.232 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-10-03T16:40:04.232Z,1570120804.232 [Default:CheckIn:Read_GPS] Running Loop=1
2019-10-03T16:40:05.810Z,1570120805.810 [NAL9602](DEBUG): Fix Requested
2019-10-03T16:40:06.209Z,1570120806.209 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164005.00,A,3646.87604,N,12157.13432,W,18.058,252.67,031019,,,A*4D
2019-10-03T16:40:06.211Z,1570120806.211 [NAL9602](INFO): GPS fix at 20191003T164005: (36.781267, -121.952239)
2019-10-03T16:40:06.266Z,1570120806.266 [Default:CheckIn:Read_GPS] Stopped
2019-10-03T16:40:06.266Z,1570120806.266 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-10-03T16:40:17.386Z,1570120817.386 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-10-03T16:40:27.761Z,1570120827.761 [NAL9602](INFO): SBD MO Status=1, MOMSN=1903, MT Status=0, MTMSN=0
2019-10-03T16:40:27.819Z,1570120827.819 [NAL9602](INFO): Sent 62 bytes from file Logs/20191003T160129/Courier0025.lzma
2019-10-03T16:40:27.819Z,1570120827.819 [NAL9602](INFO): Packets left to send: 0
2019-10-03T16:40:36.101Z,1570120836.101 [NAL9602](INFO): SBD MO Status=1, MOMSN=1904, MT Status=0, MTMSN=0
2019-10-03T16:40:36.158Z,1570120836.158 [NAL9602](INFO): Sent 135 bytes from file Logs/20191003T160129/Express0026.lzma
2019-10-03T16:40:36.159Z,1570120836.159 [NAL9602](INFO): Packets left to send: 0
2019-10-03T16:40:44.345Z,1570120844.345 [NAL9602](INFO): SBD MO Status=0, MOMSN=1905, MT Status=0, MTMSN=0
2019-10-03T16:40:44.453Z,1570120844.453 [Default:CheckIn:Read_Iridium] Stopped
2019-10-03T16:40:44.453Z,1570120844.453 [Default:CheckIn:C.Wait] Running Loop=1
2019-10-03T16:40:44.454Z,1570120844.454 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-10-03T16:40:52.526Z,1570120852.526 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-10-03T16:41:15.051Z,1570120875.051 [NAL9602](INFO): Not Powering down - fast GPS
2019-10-03T16:41:27.673Z,1570120887.673 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-10-03T16:42:02.822Z,1570120922.822 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-10-03T16:42:37.970Z,1570120957.970 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-10-03T16:43:13.142Z,1570120993.142 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-10-03T16:43:43.031Z,1570121023.031 [RDI_Pathfinder](ERROR): DVL uart error: serial timeout
2019-10-03T16:43:43.031Z,1570121023.031 [RDI_Pathfinder] Communications Fault, FailCount= 1
2019-10-03T16:43:43.031Z,1570121023.031 [RDI_Pathfinder](ERROR): Communications Fault
2019-10-03T16:43:43.033Z,1570121023.033 [RDI_Pathfinder](ERROR): Failed to parse:
2019-10-03T16:43:43.077Z,1570121023.077 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2019-10-03T16:43:43.406Z,1570121023.406 [RDI_Pathfinder](INFO): Powering down
2019-10-03T16:43:44.166Z,1570121024.166 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2019-10-03T16:43:44.166Z,1570121024.166 [RDI_Pathfinder] No Fault, FailCount= 1
2019-10-03T16:43:48.298Z,1570121028.298 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-10-03T16:43:57.887Z,1570121037.887 [RDI_Pathfinder](ERROR): Failed to parse:Pathfinder
2019-10-03T16:44:23.451Z,1570121063.451 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-10-03T16:44:58.615Z,1570121098.615 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-10-03T16:45:33.760Z,1570121133.760 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-10-03T16:45:44.961Z,1570121144.961 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-10-03T16:45:44.962Z,1570121144.962 [Default:CheckIn:C.Wait] Stopped
2019-10-03T16:45:44.962Z,1570121144.962 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-10-03T16:45:44.962Z,1570121144.962 [Default:CheckIn:D] Running Loop=1
2019-10-03T16:45:45.357Z,1570121145.357 [Default:CheckIn:D] Stopped
2019-10-03T16:45:45.357Z,1570121145.357 [Default:CheckIn:E] Running Loop=1
2019-10-03T16:45:45.755Z,1570121145.755 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 41.046867 min 
2019-10-03T16:45:45.755Z,1570121145.755 [Default:CheckIn:E] Stopped
2019-10-03T16:45:45.755Z,1570121145.755 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-10-03T16:45:45.755Z,1570121145.755 [Default:CheckIn] Stopped
2019-10-03T16:45:45.755Z,1570121145.755 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-10-03T16:45:45.755Z,1570121145.755 [Default:CheckIn](INFO): Running loop #8
2019-10-03T16:45:45.755Z,1570121145.755 [Default:CheckIn] Running Loop=8
2019-10-03T16:45:45.756Z,1570121145.756 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-10-03T16:45:45.756Z,1570121145.756 [Default:CheckIn:Read_GPS] Running Loop=1
2019-10-03T16:45:47.354Z,1570121147.354 [NAL9602](DEBUG): Fix Requested
2019-10-03T16:45:47.757Z,1570121147.757 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164547.00,A,3646.55442,N,12158.43502,W,0.486,161.08,031019,,,A*7D
2019-10-03T16:45:47.759Z,1570121147.759 [NAL9602](INFO): GPS fix at 20191003T164547: (36.775907, -121.973917)
2019-10-03T16:45:47.819Z,1570121147.819 [Default:CheckIn:Read_GPS] Stopped
2019-10-03T16:45:47.819Z,1570121147.819 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-10-03T16:46:03.640Z,1570121163.640 [NAL9602](INFO): SBD MO Status=1, MOMSN=1906, MT Status=0, MTMSN=0
2019-10-03T16:46:03.691Z,1570121163.691 [NAL9602](INFO): Sent 63 bytes from file Logs/20191003T160129/Courier0028.lzma
2019-10-03T16:46:03.691Z,1570121163.691 [NAL9602](INFO): Packets left to send: 0
2019-10-03T16:46:08.899Z,1570121168.899 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-10-03T16:46:16.433Z,1570121176.433 [NAL9602](INFO): SBD MO Status=1, MOMSN=1907, MT Status=0, MTMSN=0
2019-10-03T16:46:16.482Z,1570121176.482 [NAL9602](INFO): Sent 134 bytes from file Logs/20191003T160129/Express0029.lzma
2019-10-03T16:46:16.483Z,1570121176.483 [NAL9602](INFO): Packets left to send: 0
2019-10-03T16:46:23.437Z,1570121183.437 [NAL9602](INFO): SBD MO Status=0, MOMSN=1908, MT Status=0, MTMSN=0
2019-10-03T16:46:23.528Z,1570121183.528 [Default:CheckIn:Read_Iridium] Stopped
2019-10-03T16:46:23.528Z,1570121183.528 [Default:CheckIn:C.Wait] Running Loop=1
2019-10-03T16:46:23.528Z,1570121183.528 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-10-03T16:46:44.043Z,1570121204.043 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-10-03T16:46:54.142Z,1570121214.142 [NAL9602](INFO): Not Powering down - fast GPS
2019-10-03T16:47:19.183Z,1570121239.183 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-10-03T16:47:54.323Z,1570121274.323 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-10-03T16:48:07.723Z,1570121287.723 [RDI_Pathfinder](ERROR): only read 1 of 4 data items
2019-10-03T16:48:07.723Z,1570121287.723 [RDI_Pathfinder](ERROR): Failed to parse:
:BS,-32768-32768,V
2019-10-03T16:48:26.333Z,1570121306.333 [CommandLine](IMPORTANT): got command show stack
2019-10-03T16:48:26.334Z,1570121306.334 [CommandLine](IMPORTANT): Behavior Stack:

2019-10-03T16:48:26.334Z,1570121306.334 [Default](IMPORTANT): Priority 0: Default:B.GoToSurface
2019-10-03T16:48:26.334Z,1570121306.334 [Default:CheckIn](IMPORTANT): Priority 1: Default:CheckIn:C.Wait
2019-10-03T16:48:29.463Z,1570121309.463 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-10-03T16:48:40.889Z,1570121320.889 [CommandLine](IMPORTANT): got command stop
2019-10-03T16:49:04.606Z,1570121344.606 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-10-03T16:49:15.136Z,1570121355.136 [CommandLine](IMPORTANT): got command get platform_rudder_angle 
2019-10-03T16:49:15.137Z,1570121355.137 [CommandLine](FAULT): Incomplete syntax. Try: help get
2019-10-03T16:49:39.305Z,1570121379.305 [CommandLine](IMPORTANT): got command get platform_rudder_angle degree
2019-10-03T16:49:39.305Z,1570121379.305 [CommandLine](IMPORTANT): platform_rudder_angle 0.015396 arcdeg
2019-10-03T16:49:39.747Z,1570121379.747 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-10-03T16:49:56.031Z,1570121396.031 [CommandLine](IMPORTANT): got command ibit
2019-10-03T16:49:56.389Z,1570121396.389 [IBIT](IMPORTANT): Beginning Initiated BIT
2019-10-03T16:49:56.389Z,1570121396.389 [IBIT](IMPORTANT): Beginning control surface checks.
2019-10-03T16:49:56.396Z,1570121396.396 [CBIT](IMPORTANT): Beginning ground fault scan
2019-10-03T16:49:57.582Z,1570121397.582 [NAL9602](DEBUG): Fix Requested
2019-10-03T16:49:57.988Z,1570121397.988 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164957.00,A,3646.52146,N,12158.41260,W,0.603,141.99,031019,,,D*77
2019-10-03T16:49:57.990Z,1570121397.990 [NAL9602](INFO): GPS fix at 20191003T164957: (36.775358, -121.973543)
2019-10-03T16:50:07.378Z,1570121407.378 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.032395
CHAN A1 (24V): 0.063732
CHAN A2 (12V): 0.021327
CHAN A3 (5V): 0.008086
CHAN B0 (3.3V): 0.006243
CHAN B1 (3.15aV): 0.005633
CHAN B2 (3.15bV): 0.006055
CHAN B3 (GND): -0.000116
OPEN: 0.007646
Full Scale Calc: 4.765 mA, -1.589 mA
2019-10-03T16:50:11.297Z,1570121411.297 [NAL9602](INFO): SBD MO Status=0, MOMSN=1909, MT Status=0, MTMSN=0
2019-10-03T16:50:11.297Z,1570121411.297 [NAL9602](INFO): No messages in MT queue
2019-10-03T16:50:12.118Z,1570121412.118 [NAL9602](DEBUG): Fix Requested
2019-10-03T16:50:12.509Z,1570121412.509 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165011.00,A,3646.51982,N,12158.41007,W,1.283,125.30,031019,,,D*71
2019-10-03T16:50:12.512Z,1570121412.512 [NAL9602](INFO): GPS fix at 20191003T165011: (36.775330, -121.973501)
2019-10-03T16:50:14.891Z,1570121414.891 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-10-03T16:50:15.342Z,1570121415.342 [NAL9602](DEBUG): Fix Requested
2019-10-03T16:50:15.739Z,1570121415.739 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165015.00,A,3646.51930,N,12158.40968,W,0.311,121.88,031019,,,A*74
2019-10-03T16:50:15.742Z,1570121415.742 [NAL9602](INFO): GPS fix at 20191003T165015: (36.775322, -121.973495)
2019-10-03T16:50:18.574Z,1570121418.574 [NAL9602](DEBUG): Fix Requested
2019-10-03T16:50:18.968Z,1570121418.968 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165018.00,A,3646.51883,N,12158.40884,W,1.341,113.52,031019,,,A*71
2019-10-03T16:50:18.970Z,1570121418.970 [NAL9602](INFO): GPS fix at 20191003T165018: (36.775314, -121.973481)
2019-10-03T16:50:21.414Z,1570121421.414 [NAL9602](DEBUG): Fix Requested
2019-10-03T16:50:21.801Z,1570121421.801 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165021.00,A,3646.51844,N,12158.40830,W,1.011,138.96,031019,,,A*78
2019-10-03T16:50:21.803Z,1570121421.803 [NAL9602](INFO): GPS fix at 20191003T165021: (36.775307, -121.973472)
2019-10-03T16:50:24.642Z,1570121424.642 [NAL9602](DEBUG): Fix Requested
2019-10-03T16:50:25.030Z,1570121425.030 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165024.00,A,3646.51759,N,12158.40720,W,2.274,132.68,031019,,,A*79
2019-10-03T16:50:25.032Z,1570121425.032 [NAL9602](INFO): GPS fix at 20191003T165024: (36.775293, -121.973453)
2019-10-03T16:50:27.470Z,1570121427.470 [NAL9602](DEBUG): Fix Requested
2019-10-03T16:50:27.857Z,1570121427.857 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165027.00,A,3646.51629,N,12158.40630,W,1.400,147.57,031019,,,A*74
2019-10-03T16:50:27.859Z,1570121427.859 [NAL9602](INFO): GPS fix at 20191003T165027: (36.775272, -121.973438)
2019-10-03T16:50:28.714Z,1570121428.714 [RDI_Pathfinder](ERROR): Failed to parse:
:BE,-32768,-32768,-32768,V
2019-10-03T16:50:30.714Z,1570121430.714 [NAL9602](DEBUG): Fix Requested
2019-10-03T16:50:31.089Z,1570121431.089 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165030.00,A,3646.51488,N,12158.40540,W,2.352,151.49,031019,,,A*74
2019-10-03T16:50:31.092Z,1570121431.092 [NAL9602](INFO): GPS fix at 20191003T165030: (36.775248, -121.973423)
2019-10-03T16:50:33.522Z,1570121433.522 [NAL9602](DEBUG): Fix Requested
2019-10-03T16:50:33.924Z,1570121433.924 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165033.00,A,3646.51325,N,12158.40500,W,1.944,169.53,031019,,,A*7D
2019-10-03T16:50:33.926Z,1570121433.926 [NAL9602](INFO): GPS fix at 20191003T165033: (36.775221, -121.973417)
2019-10-03T16:50:36.350Z,1570121436.350 [NAL9602](DEBUG): Fix Requested
2019-10-03T16:50:36.761Z,1570121436.761 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165036.00,A,3646.51127,N,12158.40486,W,2.119,172.34,031019,,,A*7F
2019-10-03T16:50:36.764Z,1570121436.764 [NAL9602](INFO): GPS fix at 20191003T165036: (36.775188, -121.973414)
2019-10-03T16:50:39.582Z,1570121439.582 [NAL9602](DEBUG): Fix Requested
2019-10-03T16:50:39.981Z,1570121439.981 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165039.00,A,3646.50921,N,12158.40581,W,2.371,202.28,031019,,,A*7C
2019-10-03T16:50:39.983Z,1570121439.983 [NAL9602](INFO): GPS fix at 20191003T165039: (36.775154, -121.973430)
2019-10-03T16:50:42.410Z,1570121442.410 [NAL9602](DEBUG): Fix Requested
2019-10-03T16:50:42.809Z,1570121442.809 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165042.00,A,3646.50776,N,12158.40709,W,2.119,211.70,031019,,,A*7D
2019-10-03T16:50:42.812Z,1570121442.812 [NAL9602](INFO): GPS fix at 20191003T165042: (36.775129, -121.973451)
2019-10-03T16:50:42.881Z,1570121442.881 [IBIT](IMPORTANT): Communications Status:
Fix Status: 1
Iridium Signal Strength: 2
Latitude: 36.775131 Longitude: -121.973450
2019-10-03T16:50:43.251Z,1570121443.251 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 0.000000
Voltage: 0.000000
2019-10-03T16:50:43.251Z,1570121443.251 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah
2019-10-03T16:50:43.251Z,1570121443.251 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V
2019-10-03T16:50:43.657Z,1570121443.657 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2019-10-03T16:50:43.657Z,1570121443.657 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2019-10-03T16:50:43.658Z,1570121443.658 [IBIT](IMPORTANT): Pressure:7.270817 PSI
2019-10-03T16:50:43.658Z,1570121443.658 [IBIT](IMPORTANT): Humidity:8.625320 %
2019-10-03T16:50:44.060Z,1570121444.060 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2019-10-03T16:50:44.060Z,1570121444.060 [IBIT](IMPORTANT): buoyancyNeutral: 300.000000 cc
2019-10-03T16:50:44.060Z,1570121444.060 [IBIT](IMPORTANT): massDefault: 1.000000 cm
2019-10-03T16:50:44.060Z,1570121444.060 [IBIT](IMPORTANT): stopDepth: 215.000000 m
2019-10-03T16:50:44.061Z,1570121444.061 [IBIT](IMPORTANT): abortDepth: 255.000000 m
2019-10-03T16:50:44.061Z,1570121444.061 [IBIT](IMPORTANT): IBIT PASSED
2019-10-03T16:50:50.055Z,1570121450.055 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-10-03T16:50:53.767Z,1570121453.767 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2019-10-03T16:50:53.767Z,1570121453.767 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,19100316515779,35.0, -0.1,   0.0,1448:RA,  0.00,   0.00,   0.00,   0.00,   0.00
2019-10-03T16:51:15.531Z,1570121475.531 [NAL9602](INFO): Not Powering down - fast GPS
2019-10-03T16:51:24.057Z,1570121484.057 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-10-03T16:51:24.057Z,1570121484.057 [Default:CheckIn:C.Wait] Stopped
2019-10-03T16:51:24.057Z,1570121484.057 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-10-03T16:51:24.057Z,1570121484.057 [Default:CheckIn:D] Running Loop=1
2019-10-03T16:51:24.455Z,1570121484.455 [Default:CheckIn:D] Stopped
2019-10-03T16:51:24.456Z,1570121484.456 [Default:CheckIn:E] Running Loop=1
2019-10-03T16:51:24.880Z,1570121484.880 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 46.698507 min 
2019-10-03T16:51:24.880Z,1570121484.880 [Default:CheckIn:E] Stopped
2019-10-03T16:51:24.880Z,1570121484.880 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-10-03T16:51:24.880Z,1570121484.880 [Default:CheckIn] Stopped
2019-10-03T16:51:24.881Z,1570121484.881 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-10-03T16:51:24.881Z,1570121484.881 [Default:CheckIn](INFO): Running loop #9
2019-10-03T16:51:24.881Z,1570121484.881 [Default:CheckIn] Running Loop=9
2019-10-03T16:51:24.881Z,1570121484.881 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-10-03T16:51:24.881Z,1570121484.881 [Default:CheckIn:Read_GPS] Running Loop=1
2019-10-03T16:51:25.210Z,1570121485.210 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-10-03T16:51:26.450Z,1570121486.450 [NAL9602](DEBUG): Fix Requested
2019-10-03T16:51:26.839Z,1570121486.839 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165126.00,A,3646.52684,N,12158.41371,W,3.460,51.05,031019,,,D*41
2019-10-03T16:51:26.841Z,1570121486.841 [NAL9602](INFO): GPS fix at 20191003T165126: (36.775447, -121.973562)
2019-10-03T16:51:26.889Z,1570121486.889 [Default:CheckIn:Read_GPS] Stopped
2019-10-03T16:51:26.889Z,1570121486.889 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-10-03T16:51:52.979Z,1570121512.979 [NAL9602](INFO): SBD MO Status=1, MOMSN=1910, MT Status=0, MTMSN=0
2019-10-03T16:51:53.028Z,1570121513.028 [NAL9602](INFO): Sent 63 bytes from file Logs/20191003T160129/Courier0031.lzma
2019-10-03T16:51:53.029Z,1570121513.029 [NAL9602](INFO): Packets left to send: 0
2019-10-03T16:52:00.351Z,1570121520.351 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-10-03T16:52:02.985Z,1570121522.985 [NAL9602](INFO): SBD MO Status=1, MOMSN=1911, MT Status=0, MTMSN=0
2019-10-03T16:52:03.043Z,1570121523.043 [NAL9602](INFO): Sent 332 bytes from file Logs/20191003T160129/Express0032.lzma
2019-10-03T16:52:03.043Z,1570121523.043 [NAL9602](INFO): Packets left to send: 2
2019-10-03T16:52:11.829Z,1570121531.829 [NAL9602](INFO): SBD MO Status=1, MOMSN=1912, MT Status=0, MTMSN=0
2019-10-03T16:52:11.883Z,1570121531.883 [NAL9602](INFO): Sent 332 bytes from file Logs/20191003T160129/Express0032.lzma
2019-10-03T16:52:11.883Z,1570121531.883 [NAL9602](INFO): Packets left to send: 1
2019-10-03T16:52:17.434Z,1570121537.434 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2019-10-03T16:52:17.434Z,1570121537.434 [RDI_Pathfinder](ERROR): Failed to parse:
:RA,  0.00,   0.00,   0.00,   0.00
2019-10-03T16:52:19.413Z,1570121539.413 [NAL9602](INFO): SBD MO Status=1, MOMSN=1913, MT Status=0, MTMSN=0
2019-10-03T16:52:19.467Z,1570121539.467 [NAL9602](INFO): Sent 194 bytes from file Logs/20191003T160129/Express0032.lzma
2019-10-03T16:52:19.467Z,1570121539.467 [NAL9602](INFO): Packets left to send: 0
2019-10-03T16:52:27.249Z,1570121547.249 [NAL9602](INFO): SBD MO Status=0, MOMSN=1914, MT Status=0, MTMSN=0
2019-10-03T16:52:27.356Z,1570121547.356 [Default:CheckIn:Read_Iridium] Stopped
2019-10-03T16:52:27.356Z,1570121547.356 [Default:CheckIn:C.Wait] Running Loop=1
2019-10-03T16:52:27.356Z,1570121547.356 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-10-03T16:52:35.495Z,1570121555.495 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-10-03T16:52:57.945Z,1570121577.945 [NAL9602](INFO): Not Powering down - fast GPS
2019-10-03T16:53:10.635Z,1570121590.635 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-10-03T16:53:45.775Z,1570121625.775 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-10-03T16:54:20.915Z,1570121660.915 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-10-03T16:54:56.055Z,1570121696.055 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-10-03T16:55:04.432Z,1570121704.432 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2019-10-03T16:55:04.432Z,1570121704.432 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,160, -0.1,   0.0,1448.9,  0
2019-10-03T16:55:28.696Z,1570121728.696 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2019-10-03T16:55:28.696Z,1570121728.696 [RDI_Pathfinder](ERROR): Failed to parse:
:RA,  0.00,   0.00,   0.00,   0.00
2019-10-03T16:55:31.211Z,1570121731.211 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-10-03T16:56:06.351Z,1570121766.351 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-10-03T16:56:41.516Z,1570121801.516 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-10-03T16:57:16.657Z,1570121836.657 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-10-03T16:57:27.852Z,1570121847.852 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-10-03T16:57:27.852Z,1570121847.852 [Default:CheckIn:C.Wait] Stopped
2019-10-03T16:57:27.853Z,1570121847.853 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-10-03T16:57:27.853Z,1570121847.853 [Default:CheckIn:D] Running Loop=1
2019-10-03T16:57:28.254Z,1570121848.254 [Default:CheckIn:D] Stopped
2019-10-03T16:57:28.254Z,1570121848.254 [Default:CheckIn:E] Running Loop=1
2019-10-03T16:57:28.704Z,1570121848.704 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 52.761808 min 
2019-10-03T16:57:28.705Z,1570121848.705 [Default:CheckIn:E] Stopped
2019-10-03T16:57:28.705Z,1570121848.705 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-10-03T16:57:28.705Z,1570121848.705 [Default:CheckIn] Stopped
2019-10-03T16:57:28.705Z,1570121848.705 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-10-03T16:57:28.705Z,1570121848.705 [Default:CheckIn](INFO): Running loop #10
2019-10-03T16:57:28.705Z,1570121848.705 [Default:CheckIn] Running Loop=10
2019-10-03T16:57:28.705Z,1570121848.705 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-10-03T16:57:28.705Z,1570121848.705 [Default:CheckIn:Read_GPS] Running Loop=1
2019-10-03T16:57:30.254Z,1570121850.254 [NAL9602](DEBUG): Fix Requested
2019-10-03T16:57:30.649Z,1570121850.649 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165730.00,A,3646.50064,N,12158.32742,W,0.292,122.79,031019,,,D*7C
2019-10-03T16:57:30.651Z,1570121850.651 [NAL9602](INFO): GPS fix at 20191003T165730: (36.775011, -121.972124)
2019-10-03T16:57:30.683Z,1570121850.683 [Default:CheckIn:Read_GPS] Stopped
2019-10-03T16:57:30.683Z,1570121850.683 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-10-03T16:57:48.141Z,1570121868.141 [NAL9602](IMPORTANT): SBD MO Status=1, MOMSN=1915, MT Status=1, MTMSN=56
2019-10-03T16:57:48.191Z,1570121868.191 [NAL9602](INFO): Sent 62 bytes from file Logs/20191003T160129/Courier0034.lzma
2019-10-03T16:57:48.191Z,1570121868.191 [NAL9602](INFO): Packets left to send: 0
2019-10-03T16:57:48.639Z,1570121868.639 [NAL9602](INFO): Received command:restart logs
2019-10-03T16:57:48.659Z,1570121868.659 [CommandLine](IMPORTANT): got command restart logs