2019-10-03T15:20:27.444Z,1570116027.444 [Supervisor](DEBUG): Initializing supervisor.
2019-10-03T15:20:27.447Z,1570116027.447 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2019-10-03T15:20:27.448Z,1570116027.448 [SyncHandler](INFO): Protected caller Thread ID is 1179
2019-10-03T15:20:27.449Z,1570116027.449 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2019-10-03T15:20:27.450Z,1570116027.450 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2019-10-03T15:20:27.450Z,1570116027.450 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 1180
2019-10-03T15:20:27.454Z,1570116027.454 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2019-10-03T15:20:27.466Z,1570116027.466 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2019-10-03T15:20:27.467Z,1570116027.467 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2019-10-03T15:20:27.467Z,1570116027.467 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 1181
2019-10-03T15:20:27.468Z,1570116027.468 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2019-10-03T15:20:27.469Z,1570116027.469 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2019-10-03T15:20:27.469Z,1570116027.469 [logger ThreadHandler](INFO): Protected caller Thread ID is 1182
2019-10-03T15:20:27.471Z,1570116027.471 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2019-10-03T15:20:27.472Z,1570116027.472 [Supervisor](INFO): Looking for Config files in directory: Config/
2019-10-03T15:20:27.473Z,1570116027.473 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2019-10-03T15:20:27.911Z,1570116027.911 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2019-10-03T15:20:27.912Z,1570116027.912 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2019-10-03T15:20:28.059Z,1570116028.059 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2019-10-03T15:20:28.059Z,1570116028.059 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2019-10-03T15:20:28.141Z,1570116028.141 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2019-10-03T15:20:28.241Z,1570116028.241 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2019-10-03T15:20:28.241Z,1570116028.241 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2019-10-03T15:20:28.337Z,1570116028.337 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2019-10-03T15:20:28.338Z,1570116028.338 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2019-10-03T15:20:28.729Z,1570116028.729 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2019-10-03T15:20:28.730Z,1570116028.730 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2019-10-03T15:20:28.834Z,1570116028.834 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2019-10-03T15:20:28.835Z,1570116028.835 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2019-10-03T15:20:29.311Z,1570116029.311 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2019-10-03T15:20:29.311Z,1570116029.311 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2019-10-03T15:20:29.520Z,1570116029.520 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2019-10-03T15:20:29.520Z,1570116029.520 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2019-10-03T15:20:29.834Z,1570116029.834 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2019-10-03T15:20:29.835Z,1570116029.835 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2019-10-03T15:20:30.054Z,1570116030.054 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2019-10-03T15:20:30.054Z,1570116030.054 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2019-10-03T15:20:30.199Z,1570116030.199 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2019-10-03T15:20:30.200Z,1570116030.200 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2019-10-03T15:20:30.861Z,1570116030.861 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2019-10-03T15:20:30.862Z,1570116030.862 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2019-10-03T15:20:31.210Z,1570116031.210 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2019-10-03T15:20:31.211Z,1570116031.211 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2019-10-03T15:20:31.423Z,1570116031.423 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2019-10-03T15:20:31.425Z,1570116031.425 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-triton/
2019-10-03T15:20:31.426Z,1570116031.426 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/vehicle.cfg
2019-10-03T15:20:31.640Z,1570116031.640 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/secure.cfg
2019-10-03T15:20:31.770Z,1570116031.770 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Science.cfg
2019-10-03T15:20:32.098Z,1570116032.098 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Simulator.cfg
2019-10-03T15:20:32.276Z,1570116032.276 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Battery.cfg
2019-10-03T15:20:32.648Z,1570116032.648 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2019-10-03T15:20:32.649Z,1570116032.649 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/logger.cfg
2019-10-03T15:20:32.837Z,1570116032.837 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Servo.cfg
2019-10-03T15:20:32.948Z,1570116032.948 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Navigation.cfg
2019-10-03T15:20:33.042Z,1570116033.042 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Sensor.cfg
2019-10-03T15:20:33.195Z,1570116033.195 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Control.cfg
2019-10-03T15:20:33.296Z,1570116033.296 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/BIT.cfg
2019-10-03T15:20:33.399Z,1570116033.399 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-triton/root/
2019-10-03T15:20:33.399Z,1570116033.399 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2019-10-03T15:20:33.403Z,1570116033.403 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2019-10-03T15:20:33.418Z,1570116033.418 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2019-10-03T15:20:33.418Z,1570116033.418 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2019-10-03T15:20:33.492Z,1570116033.492 [VerticalControl](DEBUG): Construct VerticalControl.
2019-10-03T15:20:33.610Z,1570116033.610 [VerticalControl] Loaded
2019-10-03T15:20:33.611Z,1570116033.611 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2019-10-03T15:20:33.611Z,1570116033.611 [HorizontalControl](DEBUG): Construct HorizontalControl.
2019-10-03T15:20:33.684Z,1570116033.684 [HorizontalControl] Loaded
2019-10-03T15:20:33.684Z,1570116033.684 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2019-10-03T15:20:33.685Z,1570116033.685 [SpeedControl](DEBUG): Construct SpeedControl.
2019-10-03T15:20:33.691Z,1570116033.691 [SpeedControl] Loaded
2019-10-03T15:20:33.691Z,1570116033.691 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2019-10-03T15:20:33.692Z,1570116033.692 [LoopControl](DEBUG): Construct LoopControl.
2019-10-03T15:20:33.692Z,1570116033.692 [LoopControl] Loaded
2019-10-03T15:20:33.692Z,1570116033.692 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2019-10-03T15:20:33.693Z,1570116033.693 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2019-10-03T15:20:33.694Z,1570116033.694 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2019-10-03T15:20:33.829Z,1570116033.829 [BuoyancyServo] Loaded
2019-10-03T15:20:33.829Z,1570116033.829 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2019-10-03T15:20:33.841Z,1570116033.841 [ElevatorServo] Loaded
2019-10-03T15:20:33.841Z,1570116033.841 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2019-10-03T15:20:33.853Z,1570116033.853 [MassServo] Loaded
2019-10-03T15:20:33.853Z,1570116033.853 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2019-10-03T15:20:33.864Z,1570116033.864 [RudderServo] Loaded
2019-10-03T15:20:33.864Z,1570116033.864 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2019-10-03T15:20:33.876Z,1570116033.876 [ThrusterServo] Loaded
2019-10-03T15:20:33.876Z,1570116033.876 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2019-10-03T15:20:33.877Z,1570116033.877 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2019-10-03T15:20:33.877Z,1570116033.877 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2019-10-03T15:20:33.921Z,1570116033.921 [DepthRateCalculator] Loaded
2019-10-03T15:20:33.922Z,1570116033.922 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2019-10-03T15:20:33.927Z,1570116033.927 [PitchRateCalculator] Loaded
2019-10-03T15:20:33.928Z,1570116033.928 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2019-10-03T15:20:33.943Z,1570116033.943 [SpeedCalculator] Loaded
2019-10-03T15:20:33.944Z,1570116033.944 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2019-10-03T15:20:33.966Z,1570116033.966 [TempGradientCalculator] Loaded
2019-10-03T15:20:33.966Z,1570116033.966 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2019-10-03T15:20:33.971Z,1570116033.971 [YawRateCalculator] Loaded
2019-10-03T15:20:33.972Z,1570116033.972 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2019-10-03T15:20:34.003Z,1570116034.003 [ElevatorOffsetCalculator] Loaded
2019-10-03T15:20:34.003Z,1570116034.003 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2019-10-03T15:20:34.004Z,1570116034.004 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2019-10-03T15:20:34.004Z,1570116034.004 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2019-10-03T15:20:34.112Z,1570116034.112 [DeadReckonUsingMultipleVelocitySources] Loaded
2019-10-03T15:20:34.112Z,1570116034.112 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2019-10-03T15:20:34.134Z,1570116034.134 [NavChart] Loaded
2019-10-03T15:20:34.134Z,1570116034.134 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2019-10-03T15:20:34.138Z,1570116034.138 [UniversalFixResidualReporter] Loaded
2019-10-03T15:20:34.138Z,1570116034.138 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2019-10-03T15:20:34.139Z,1570116034.139 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2019-10-03T15:20:34.140Z,1570116034.140 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2019-10-03T15:20:34.402Z,1570116034.402 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_orientation
2019-10-03T15:20:34.407Z,1570116034.407 [AHRS_M2](INFO): created writer for : platform_orientation
2019-10-03T15:20:34.409Z,1570116034.409 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_magnetic_orientation
2019-10-03T15:20:34.414Z,1570116034.414 [AHRS_M2](INFO): created writer for : platform_magnetic_orientation
2019-10-03T15:20:34.415Z,1570116034.415 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_pitch_angle
2019-10-03T15:20:34.420Z,1570116034.420 [AHRS_M2](INFO): created writer for : platform_pitch_angle
2019-10-03T15:20:34.421Z,1570116034.421 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_roll_angle
2019-10-03T15:20:34.426Z,1570116034.426 [AHRS_M2](INFO): created writer for : platform_roll_angle
2019-10-03T15:20:34.500Z,1570116034.500 [AHRS_M2] Loaded
2019-10-03T15:20:34.500Z,1570116034.500 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2019-10-03T15:20:34.577Z,1570116034.577 [DataOverHttps] Loaded
2019-10-03T15:20:34.577Z,1570116034.577 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2019-10-03T15:20:34.578Z,1570116034.578 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 407F84E0
2019-10-03T15:20:34.579Z,1570116034.579 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 1261
2019-10-03T15:20:34.593Z,1570116034.593 [Depth_Keller] Loaded
2019-10-03T15:20:34.593Z,1570116034.593 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2019-10-03T15:20:34.599Z,1570116034.599 [DropWeight] Loaded
2019-10-03T15:20:34.599Z,1570116034.599 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2019-10-03T15:20:34.700Z,1570116034.700 [NAL9602] Loaded
2019-10-03T15:20:34.701Z,1570116034.701 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2019-10-03T15:20:34.717Z,1570116034.717 [Onboard] Loaded
2019-10-03T15:20:34.717Z,1570116034.717 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2019-10-03T15:20:34.721Z,1570116034.721 [Radio_Surface] Loaded
2019-10-03T15:20:34.721Z,1570116034.721 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2019-10-03T15:20:34.722Z,1570116034.722 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408284E0
2019-10-03T15:20:34.722Z,1570116034.722 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 1262
2019-10-03T15:20:34.855Z,1570116034.855 [DAT] Loaded
2019-10-03T15:20:34.855Z,1570116034.855 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread.
2019-10-03T15:20:36.422Z,1570116036.422 [BPC1] Loaded
2019-10-03T15:20:36.423Z,1570116036.423 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2019-10-03T15:20:36.423Z,1570116036.423 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2019-10-03T15:20:36.424Z,1570116036.424 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2019-10-03T15:20:36.501Z,1570116036.501 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2019-10-03T15:20:36.502Z,1570116036.502 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2019-10-03T15:20:36.611Z,1570116036.611 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2019-10-03T15:20:36.611Z,1570116036.611 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2019-10-03T15:20:36.647Z,1570116036.647 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2019-10-03T15:20:36.648Z,1570116036.648 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2019-10-03T15:20:37.108Z,1570116037.108 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density
2019-10-03T15:20:37.113Z,1570116037.113 [CTD_Seabird](INFO): created writer for : sea_water_density
2019-10-03T15:20:37.114Z,1570116037.114 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth
2019-10-03T15:20:37.119Z,1570116037.119 [CTD_Seabird](INFO): created writer for : depth
2019-10-03T15:20:37.120Z,1570116037.120 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure
2019-10-03T15:20:37.125Z,1570116037.125 [CTD_Seabird](INFO): created writer for : sea_water_pressure
2019-10-03T15:20:37.126Z,1570116037.126 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity
2019-10-03T15:20:37.131Z,1570116037.131 [CTD_Seabird](INFO): created writer for : sea_water_salinity
2019-10-03T15:20:37.132Z,1570116037.132 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature
2019-10-03T15:20:37.137Z,1570116037.137 [CTD_Seabird](INFO): created writer for : sea_water_temperature
2019-10-03T15:20:37.138Z,1570116037.138 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity
2019-10-03T15:20:37.143Z,1570116037.143 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity
2019-10-03T15:20:37.144Z,1570116037.144 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water
2019-10-03T15:20:37.149Z,1570116037.149 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water
2019-10-03T15:20:37.150Z,1570116037.150 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): mass_concentration_of_oxygen_in_sea_water
2019-10-03T15:20:37.155Z,1570116037.155 [CTD_Seabird](INFO): created writer for : mass_concentration_of_oxygen_in_sea_water
2019-10-03T15:20:37.156Z,1570116037.156 [CTD_Seabird](DEBUG): LcmSlateWriter::add(DAtaURI): CTD_Seabird.sea_water_dissolved_oxygen_freq
2019-10-03T15:20:37.156Z,1570116037.156 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): dataName: sea_water_dissolved_oxygen_freq
2019-10-03T15:20:37.190Z,1570116037.190 [CTD_Seabird] Loaded
2019-10-03T15:20:37.190Z,1570116037.190 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2019-10-03T15:20:37.199Z,1570116037.199 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 409BF4E0
2019-10-03T15:20:37.200Z,1570116037.200 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 1263
2019-10-03T15:20:37.273Z,1570116037.273 [ESPComponent] Loaded
2019-10-03T15:20:37.274Z,1570116037.274 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2019-10-03T15:20:37.289Z,1570116037.289 [PAR_Licor] Loaded
2019-10-03T15:20:37.289Z,1570116037.289 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2019-10-03T15:20:37.295Z,1570116037.295 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output470
2019-10-03T15:20:37.296Z,1570116037.296 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output470
2019-10-03T15:20:37.300Z,1570116037.300 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output650
2019-10-03T15:20:37.300Z,1570116037.300 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output650
2019-10-03T15:20:37.305Z,1570116037.305 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.OutputChl
2019-10-03T15:20:37.305Z,1570116037.305 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: OutputChl
2019-10-03T15:20:37.310Z,1570116037.310 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg470nm
2019-10-03T15:20:37.310Z,1570116037.310 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg470nm
2019-10-03T15:20:37.314Z,1570116037.314 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg650nm
2019-10-03T15:20:37.314Z,1570116037.314 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg650nm
2019-10-03T15:20:37.319Z,1570116037.319 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff470nm
2019-10-03T15:20:37.319Z,1570116037.319 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff470nm
2019-10-03T15:20:37.324Z,1570116037.324 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff650nm
2019-10-03T15:20:37.324Z,1570116037.324 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff650nm
2019-10-03T15:20:37.328Z,1570116037.328 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): mass_concentration_of_chlorophyll_in_sea_water
2019-10-03T15:20:37.333Z,1570116037.333 [WetLabsBB2FL](INFO): created writer for : mass_concentration_of_chlorophyll_in_sea_water
2019-10-03T15:20:37.333Z,1570116037.333 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_median_mass_concentration_of_chlorophyll_in_sea_water
2019-10-03T15:20:37.333Z,1570116037.333 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_median_mass_concentration_of_chlorophyll_in_sea_water
2019-10-03T15:20:37.338Z,1570116037.338 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water
2019-10-03T15:20:37.338Z,1570116037.338 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_mean_mass_concentration_of_chlorophyll_in_sea_water
2019-10-03T15:20:37.343Z,1570116037.343 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_variance_mass_concentration_of_chlorophyll_in_sea_water
2019-10-03T15:20:37.343Z,1570116037.343 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_variance_mass_concentration_of_chlorophyll_in_sea_water
2019-10-03T15:20:37.347Z,1570116037.347 [WetLabsBB2FL] Loaded
2019-10-03T15:20:37.348Z,1570116037.348 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2019-10-03T15:20:37.349Z,1570116037.349 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 409EF4E0
2019-10-03T15:20:37.349Z,1570116037.349 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 1264
2019-10-03T15:20:37.350Z,1570116037.350 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2019-10-03T15:20:37.350Z,1570116037.350 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2019-10-03T15:20:37.673Z,1570116037.673 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2019-10-03T15:20:37.673Z,1570116037.673 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2019-10-03T15:20:37.815Z,1570116037.815 [SBIT](DEBUG): Construct Startup Built In Test.
2019-10-03T15:20:37.827Z,1570116037.827 [SBIT] Loaded
2019-10-03T15:20:37.827Z,1570116037.827 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2019-10-03T15:20:37.828Z,1570116037.828 [IBIT](DEBUG): Construct Initiated Built In Test.
2019-10-03T15:20:37.840Z,1570116037.840 [IBIT] Loaded
2019-10-03T15:20:37.840Z,1570116037.840 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2019-10-03T15:20:37.843Z,1570116037.843 [CBIT](DEBUG): Construct Continuous Built In Test.
2019-10-03T15:20:37.990Z,1570116037.990 [CBIT] Loaded
2019-10-03T15:20:37.991Z,1570116037.991 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2019-10-03T15:20:37.991Z,1570116037.991 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2019-10-03T15:20:37.995Z,1570116037.995 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2019-10-03T15:20:37.996Z,1570116037.996 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2019-10-03T15:20:38.003Z,1570116038.003 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2019-10-03T15:20:38.004Z,1570116038.004 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40ACE4E0
2019-10-03T15:20:38.004Z,1570116038.004 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 1265
2019-10-03T15:20:38.009Z,1570116038.009 [Supervisor](INFO): Main Thread ID is 803
2019-10-03T15:20:38.010Z,1570116038.010 [Supervisor](DEBUG): Running supervisor.
2019-10-03T15:20:38.010Z,1570116038.010 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1266
2019-10-03T15:20:38.013Z,1570116038.013 [controlThread ThreadHandler](INFO): Handler Thread ID is 1267
2019-10-03T15:20:38.013Z,1570116038.013 [controlThread](DEBUG): Initializing ControlThread
2019-10-03T15:20:38.014Z,1570116038.014 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2019-10-03T15:20:38.015Z,1570116038.016 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2019-10-03T15:20:38.016Z,1570116038.016 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2019-10-03T15:20:38.017Z,1570116038.017 [LoopControl](DEBUG): Initialize LoopControlComponent.
2019-10-03T15:20:38.018Z,1570116038.018 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2019-10-03T15:20:38.018Z,1570116038.018 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2019-10-03T15:20:38.019Z,1570116038.019 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2019-10-03T15:20:38.019Z,1570116038.019 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2019-10-03T15:20:38.020Z,1570116038.020 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2019-10-03T15:20:38.020Z,1570116038.020 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2019-10-03T15:20:38.021Z,1570116038.021 [NavChart](DEBUG): Initialize NavChart Navigation.
2019-10-03T15:20:38.021Z,1570116038.021 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2019-10-03T15:20:38.027Z,1570116038.027 [SBIT](INFO): Initialize SBIT Component.
2019-10-03T15:20:38.028Z,1570116038.028 [SBIT](IMPORTANT): git: 2019-10-03
2019-10-03T15:20:38.028Z,1570116038.028 [SBIT](INFO): git hash: 974860435c728321114cbfe2eb6af3af3fcc7863
2019-10-03T15:20:38.028Z,1570116038.028 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2019-10-03T15:20:38.029Z,1570116038.029 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #1 PREEMPT Tue Dec 18 21:19:28 PST 2018
Kernel Reported: #1 PREEMPT Thu Feb 21 11:17:40 PST 2019
2019-10-03T15:20:38.030Z,1570116038.030 [SBIT](INFO): Beginning SBIT in 38.000000 seconds.
2019-10-03T15:20:38.031Z,1570116038.031 [IBIT](INFO): Initialize IBIT Component.
2019-10-03T15:20:38.032Z,1570116038.032 [CBIT](DEBUG): Initialize CBIT Component.
2019-10-03T15:20:38.033Z,1570116038.033 [logger ThreadHandler](INFO): Handler Thread ID is 1268
2019-10-03T15:20:38.043Z,1570116038.043 [CBIT](DEBUG): Initialized mux pins.
2019-10-03T15:20:38.043Z,1570116038.043 [CBIT](DEBUG): Initializing the watchdog timer.
2019-10-03T15:20:38.051Z,1570116038.051 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 1269
2019-10-03T15:20:38.053Z,1570116038.053 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2019-10-03T15:20:38.063Z,1570116038.063 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 1270
2019-10-03T15:20:38.067Z,1570116038.067 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2019-10-03T15:20:38.067Z,1570116038.067 [CBIT](DEBUG): Initializing heartbeat.
2019-10-03T15:20:38.075Z,1570116038.075 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 1271
2019-10-03T15:20:38.076Z,1570116038.076 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2019-10-03T15:20:38.080Z,1570116038.080 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20
2019-10-03T15:20:38.081Z,1570116038.081 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 1273
2019-10-03T15:20:38.082Z,1570116038.082 [WetLabsBB2FL](INFO): Powering down
2019-10-03T15:20:38.112Z,1570116038.112 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1274
2019-10-03T15:20:38.115Z,1570116038.115 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2019-10-03T15:20:38.115Z,1570116038.115 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2019-10-03T15:20:38.116Z,1570116038.116 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2019-10-03T15:20:38.116Z,1570116038.116 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2019-10-03T15:20:38.116Z,1570116038.116 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2019-10-03T15:20:38.116Z,1570116038.116 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2019-10-03T15:20:38.116Z,1570116038.116 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2019-10-03T15:20:38.116Z,1570116038.116 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2019-10-03T15:20:38.117Z,1570116038.117 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2019-10-03T15:20:38.117Z,1570116038.117 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2019-10-03T15:20:38.117Z,1570116038.117 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2019-10-03T15:20:38.117Z,1570116038.117 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2019-10-03T15:20:38.117Z,1570116038.117 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2019-10-03T15:20:38.118Z,1570116038.118 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2019-10-03T15:20:38.118Z,1570116038.118 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2019-10-03T15:20:38.118Z,1570116038.118 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2019-10-03T15:20:38.139Z,1570116038.139 [CBIT](DEBUG): Deactivating GF circuits.
2019-10-03T15:20:38.139Z,1570116038.139 [CBIT](DEBUG): Deactivating emergency mode.
2019-10-03T15:20:38.175Z,1570116038.175 [CBIT](DEBUG): Backplane powered.
2019-10-03T15:20:38.176Z,1570116038.176 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2019-10-03T15:20:38.186Z,1570116038.186 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2019-10-03T15:20:38.197Z,1570116038.197 [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-03T15:20:38.198Z,1570116038.198 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2019-10-03T15:20:38.269Z,1570116038.269 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2019-10-03T15:20:38.270Z,1570116038.270 [Default:A.Wait](DEBUG): Construct Wait.
2019-10-03T15:20:38.272Z,1570116038.272 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2019-10-03T15:20:38.308Z,1570116038.308 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2019-10-03T15:20:38.310Z,1570116038.310 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2019-10-03T15:20:38.350Z,1570116038.350 [Default:E.Execute](DEBUG): Construct Execute.
2019-10-03T15:20:38.376Z,1570116038.376 [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-03T15:20:38.381Z,1570116038.381 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,NAL9602,Onboard,DAT,BPC1,ESPComponent,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2019-10-03T15:20:38.386Z,1570116038.386 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2019-10-03T15:20:38.427Z,1570116038.427 [Depth_Keller](ERROR): Pressure reading out of range: 1925.893799 decibar
2019-10-03T15:20:38.467Z,1570116038.467 [Radio_Surface](INFO): Powering up
2019-10-03T15:20:38.468Z,1570116038.468 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2019-10-03T15:20:38.468Z,1570116038.468 [DAT](INFO): Powering up
2019-10-03T15:20:38.468Z,1570116038.468 [DAT](DEBUG): Initializing DAT.
2019-10-03T15:20:38.511Z,1570116038.511 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2019-10-03T15:20:38.536Z,1570116038.536 [DepthRateCalculator](ERROR): Depth measurement is not active
2019-10-03T15:20:38.573Z,1570116038.573 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2019-10-03T15:20:38.584Z,1570116038.584 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2019-10-03T15:20:38.585Z,1570116038.585 [ElevatorServo](DEBUG): Initializing EZServoServo.
2019-10-03T15:20:38.595Z,1570116038.595 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2019-10-03T15:20:38.596Z,1570116038.596 [MassServo](DEBUG): Initializing EZServoServo.
2019-10-03T15:20:38.607Z,1570116038.607 [MassServo](DEBUG): Initializing MassServo.
2019-10-03T15:20:38.608Z,1570116038.608 [RudderServo](DEBUG): Initializing EZServoServo.
2019-10-03T15:20:38.619Z,1570116038.619 [RudderServo](DEBUG): Initializing RudderServo.
2019-10-03T15:20:38.620Z,1570116038.620 [ThrusterServo](DEBUG): Initializing EZServoServo.
2019-10-03T15:20:38.633Z,1570116038.633 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2019-10-03T15:20:39.543Z,1570116039.543 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2019-10-03T15:20:39.543Z,1570116039.543 [RudderServo](FAULT): Rudder failed to initialize
2019-10-03T15:20:39.543Z,1570116039.543 [RudderServo] Communications Fault, FailCount= 1
2019-10-03T15:20:39.543Z,1570116039.543 [RudderServo](ERROR): Communications Fault
2019-10-03T15:20:39.654Z,1570116039.654 [CBIT](ERROR): Communications Fault in component: RudderServo
2019-10-03T15:20:39.856Z,1570116039.856 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-10-03T15:20:39.856Z,1570116039.856 [RudderServo](INFO): Powering down
2019-10-03T15:20:40.517Z,1570116040.517 [RudderServo](DEBUG): Initializing EZServoServo.
2019-10-03T15:20:40.636Z,1570116040.636 [RudderServo](DEBUG): Initializing RudderServo.
2019-10-03T15:20:40.640Z,1570116040.640 [CBIT](INFO): Clearing failed state for component RudderServo
2019-10-03T15:20:40.640Z,1570116040.640 [RudderServo] No Fault, FailCount= 1
2019-10-03T15:20:51.800Z,1570116051.800 [DAT](INFO): setting local address to 5
2019-10-03T15:20:52.205Z,1570116052.205 [DAT](INFO): set local address to 5
2019-10-03T15:21:04.712Z,1570116064.712 [NAL9602](INFO): Powering up NAL9602
2019-10-03T15:21:15.624Z,1570116075.624 [NAL9602](INFO): NAL9602 initialized
2019-10-03T15:21:16.447Z,1570116076.447 [NAL9602](DEBUG): Fix Requested
2019-10-03T15:21:16.489Z,1570116076.489 [SBIT](IMPORTANT): Beginning Startup BIT
2019-10-03T15:21:16.517Z,1570116076.517 [CBIT](IMPORTANT): Beginning ground fault scan
2019-10-03T15:21:27.760Z,1570116087.760 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): -0.002235
CHAN A1 (24V): 0.187575
CHAN A2 (12V): -0.000650
CHAN A3 (5V): -0.001019
CHAN B0 (3.3V): 0.000046
CHAN B1 (3.15aV): 0.000222
CHAN B2 (3.15bV): -0.000110
CHAN B3 (GND): -0.000024
OPEN: 0.005338
Full Scale Calc: 4.765 mA, -1.589 mA
2019-10-03T15:21:32.198Z,1570116092.198 [NAL9602](INFO): SBD MO Status=0, MOMSN=2084, MT Status=0, MTMSN=0
2019-10-03T15:21:32.198Z,1570116092.198 [NAL9602](INFO): No messages in MT queue
2019-10-03T15:21:33.011Z,1570116093.011 [NAL9602](DEBUG): Fix Requested
2019-10-03T15:21:33.406Z,1570116093.406 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,152132.00,A,3648.14452,N,12147.22746,W,0.156,0.00,031019,,,A*79
2019-10-03T15:21:33.410Z,1570116093.410 [NAL9602](INFO): GPS fix at 20191003T152132: (36.802409, -121.787124)
2019-10-03T15:22:05.432Z,1570116125.432 [NAL9602](INFO): Not Powering down - fast GPS
2019-10-03T15:22:09.913Z,1570116129.913 [SBIT](IMPORTANT): SBIT PASSED
2019-10-03T15:22:09.967Z,1570116129.967 [CommandLine](IMPORTANT): got command configSet list
2019-10-03T15:22:09.968Z,1570116129.968 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2019-10-03T15:22:09.968Z,1570116129.968 [CommandLine](IMPORTANT): DVL_micro.loadAtStartup=0 bool;

2019-10-03T15:22:10.301Z,1570116130.301 [MissionManager](IMPORTANT): Started mission Startup
2019-10-03T15:22:10.301Z,1570116130.301 [Startup] Running Loop=1
2019-10-03T15:22:10.301Z,1570116130.301 [Startup](DEBUG): Aggregate::initialize Startup
2019-10-03T15:22:10.302Z,1570116130.302 [Startup:A.GoToSurface] Running Loop=1
2019-10-03T15:22:10.302Z,1570116130.302 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-10-03T15:22:10.302Z,1570116130.302 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-10-03T15:22:10.303Z,1570116130.303 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-10-03T15:22:10.303Z,1570116130.303 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-10-03T15:22:10.304Z,1570116130.304 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-10-03T15:22:10.304Z,1570116130.304 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-10-03T15:22:10.305Z,1570116130.305 [Startup:StartupSatComms] Running Loop=1
2019-10-03T15:22:10.306Z,1570116130.306 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2019-10-03T15:22:10.306Z,1570116130.306 [Startup:StartupSatComms:A] Running Loop=1
2019-10-03T15:22:10.714Z,1570116130.714 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2019-10-03T15:22:11.907Z,1570116131.907 [NAL9602](DEBUG): Fix Requested
2019-10-03T15:22:12.296Z,1570116132.296 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,152211.00,A,3648.14512,N,12147.22511,W,0.019,0.00,031019,,,A*74
2019-10-03T15:22:12.298Z,1570116132.298 [NAL9602](INFO): GPS fix at 20191003T152211: (36.802419, -121.787085)
2019-10-03T15:22:12.362Z,1570116132.362 [Startup:StartupSatComms:A] Stopped
2019-10-03T15:22:12.362Z,1570116132.362 [Startup:StartupSatComms:B] Running Loop=1
2019-10-03T15:22:12.881Z,1570116132.881 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-10-03T15:22:22.131Z,1570116142.131 [NAL9602](INFO): SBD MO Status=1, MOMSN=2085, MT Status=0, MTMSN=0
2019-10-03T15:22:22.191Z,1570116142.191 [NAL9602](INFO): Sent 25 bytes from file Logs/20191003T143258/Courier0019.lzma
2019-10-03T15:22:22.192Z,1570116142.192 [NAL9602](INFO): Packets left to send: 0
2019-10-03T15:22:41.206Z,1570116161.206 [NAL9602](INFO): SBD MO Status=1, MOMSN=2086, MT Status=0, MTMSN=0
2019-10-03T15:22:41.256Z,1570116161.256 [NAL9602](INFO): Sent 213 bytes from file Logs/20191003T152027/Courier0000.lzma
2019-10-03T15:22:41.256Z,1570116161.256 [NAL9602](INFO): Packets left to send: 0
2019-10-03T15:23:06.207Z,1570116186.207 [NAL9602](INFO): SBD MO Status=2, MOMSN=2087, MT Status=2, MTMSN=0
2019-10-03T15:23:06.208Z,1570116186.208 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-10-03T15:23:13.360Z,1570116193.360 [Startup:StartupSatComms:B](INFO): Timed out from 2019-10-03T15:22:12.4Z
2019-10-03T15:23:13.360Z,1570116193.360 [Startup:StartupSatComms:B] Stopped
2019-10-03T15:23:13.360Z,1570116193.360 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2019-10-03T15:23:13.360Z,1570116193.360 [Startup:StartupSatComms] Stopped
2019-10-03T15:23:13.360Z,1570116193.360 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2019-10-03T15:23:13.361Z,1570116193.361 [Startup](INFO): Completed Startup
2019-10-03T15:23:13.361Z,1570116193.361 [MissionManager](INFO): Startup is completed.
2019-10-03T15:23:13.361Z,1570116193.361 [MissionManager](INFO): Uninitializing Mission Startup
2019-10-03T15:23:13.361Z,1570116193.361 [Startup] Stopped
2019-10-03T15:23:13.361Z,1570116193.361 [Startup](DEBUG): Aggregate::uninitialize Startup
2019-10-03T15:23:13.361Z,1570116193.361 [Startup:A.GoToSurface] Stopped
2019-10-03T15:23:13.361Z,1570116193.361 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-10-03T15:23:13.483Z,1570116193.483 [MissionManager](IMPORTANT): Started mission Default
2019-10-03T15:23:13.484Z,1570116193.484 [Default] Running Loop=1
2019-10-03T15:23:13.484Z,1570116193.484 [Default](DEBUG): Aggregate::initialize Default
2019-10-03T15:23:13.484Z,1570116193.484 [Default:B.GoToSurface] Running Loop=1
2019-10-03T15:23:13.484Z,1570116193.484 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-10-03T15:23:13.488Z,1570116193.488 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-10-03T15:23:13.489Z,1570116193.489 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-10-03T15:23:13.489Z,1570116193.489 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-10-03T15:23:13.489Z,1570116193.489 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-10-03T15:23:13.490Z,1570116193.490 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-10-03T15:23:13.490Z,1570116193.490 [Default:A.Wait] Running Loop=1
2019-10-03T15:23:13.490Z,1570116193.490 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-10-03T15:23:26.809Z,1570116206.809 [Default:A.Wait](INFO): Done Waiting.
2019-10-03T15:23:26.810Z,1570116206.810 [Default:A.Wait] Stopped
2019-10-03T15:23:26.810Z,1570116206.810 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-10-03T15:23:27.208Z,1570116207.208 [Default:CheckIn] Running Loop=1
2019-10-03T15:23:27.208Z,1570116207.208 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-10-03T15:23:27.208Z,1570116207.208 [Default:CheckIn:Read_GPS] Running Loop=1
2019-10-03T15:23:27.627Z,1570116207.627 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2019-10-03T15:23:37.690Z,1570116217.690 [NAL9602](INFO): SBD MO Status=1, MOMSN=2087, MT Status=0, MTMSN=0
2019-10-03T15:23:37.756Z,1570116217.756 [NAL9602](INFO): Sent 246 bytes from file Logs/20191003T143258/Express0020.lzma
2019-10-03T15:23:37.756Z,1570116217.756 [NAL9602](INFO): Packets left to send: 0
2019-10-03T15:23:38.511Z,1570116218.511 [NAL9602](DEBUG): Fix Requested
2019-10-03T15:23:38.912Z,1570116218.912 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,152339.00,A,3648.14603,N,12147.22797,W,0.019,0.00,031019,,,A*70
2019-10-03T15:23:38.914Z,1570116218.914 [NAL9602](INFO): GPS fix at 20191003T152339: (36.802434, -121.787133)
2019-10-03T15:23:38.939Z,1570116218.939 [Default:CheckIn:Read_GPS] Stopped
2019-10-03T15:23:38.939Z,1570116218.939 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-10-03T15:23:39.356Z,1570116219.356 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-10-03T15:23:54.771Z,1570116234.771 [NAL9602](INFO): SBD MO Status=1, MOMSN=2088, MT Status=0, MTMSN=0
2019-10-03T15:23:54.819Z,1570116234.819 [NAL9602](INFO): Sent 62 bytes from file Logs/20191003T152027/Courier0004.lzma
2019-10-03T15:23:54.820Z,1570116234.820 [NAL9602](INFO): Packets left to send: 0
2019-10-03T15:24:14.068Z,1570116254.068 [NAL9602](INFO): SBD MO Status=1, MOMSN=2089, MT Status=0, MTMSN=0
2019-10-03T15:24:14.115Z,1570116254.115 [NAL9602](INFO): Sent 332 bytes from file Logs/20191003T152027/Express0001.lzma
2019-10-03T15:24:14.116Z,1570116254.116 [NAL9602](INFO): Packets left to send: 2
2019-10-03T15:24:20.497Z,1570116260.497 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004961
2019-10-03T15:24:24.919Z,1570116264.919 [NAL9602](INFO): SBD MO Status=1, MOMSN=2090, MT Status=0, MTMSN=0
2019-10-03T15:24:24.979Z,1570116264.979 [NAL9602](INFO): Sent 332 bytes from file Logs/20191003T152027/Express0001.lzma
2019-10-03T15:24:24.979Z,1570116264.979 [NAL9602](INFO): Packets left to send: 1
2019-10-03T15:24:25.042Z,1570116265.042 [Default:CheckIn:Read_Iridium] Stopped
2019-10-03T15:24:25.042Z,1570116265.042 [Default:CheckIn:C.Wait] Running Loop=1
2019-10-03T15:24:25.042Z,1570116265.042 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-10-03T15:24:30.472Z,1570116270.472 [DataOverHttps](INFO): Sending 754 bytes from file Logs/20191003T152027/Express0001.lzma
2019-10-03T15:24:32.476Z,1570116272.476 [DataOverHttps](INFO): Moved sent file to Logs/20191003T152027/Express0001.lzma.bak
2019-10-03T15:24:32.477Z,1570116272.477 [DataOverHttps](INFO): SBD MOMSN=11844874
2019-10-03T15:24:55.636Z,1570116295.636 [NAL9602](INFO): Not Powering down - fast GPS
2019-10-03T15:25:41.707Z,1570116341.707 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-10-03T15:25:54.643Z,1570116354.643 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-10-03T15:26:07.584Z,1570116367.584 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-10-03T15:26:20.516Z,1570116380.516 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-10-03T15:26:33.474Z,1570116393.474 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-10-03T15:26:46.355Z,1570116406.355 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-10-03T15:26:59.700Z,1570116419.700 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-10-03T15:27:12.211Z,1570116432.211 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-10-03T15:27:25.137Z,1570116445.137 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-10-03T15:27:37.671Z,1570116457.671 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-10-03T15:27:50.601Z,1570116470.601 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-10-03T15:29:19.961Z,1570116559.961 [CommandLine](IMPORTANT): got command show variable stopDepth
2019-10-03T15:29:20.041Z,1570116560.041 [CommandLine](IMPORTANT): VerticalControl.stopDepthExcursion (meter)
2019-10-03T15:29:20.041Z,1570116560.041 [CommandLine](IMPORTANT): CBIT.stopDepth (meter)
2019-10-03T15:29:23.744Z,1570116563.744 [CommandLine](IMPORTANT): got command get CBIT.stopDepth
2019-10-03T15:29:23.745Z,1570116563.745 [CommandLine](IMPORTANT): CBIT.stopDepth 215.000000 m
2019-10-03T15:29:25.562Z,1570116565.562 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-10-03T15:29:25.562Z,1570116565.562 [Default:CheckIn:C.Wait] Stopped
2019-10-03T15:29:25.562Z,1570116565.562 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-10-03T15:29:25.563Z,1570116565.563 [Default:CheckIn:D] Running Loop=1
2019-10-03T15:29:25.993Z,1570116565.993 [Default:CheckIn:D] Stopped
2019-10-03T15:29:25.993Z,1570116565.993 [Default:CheckIn:E] Running Loop=1
2019-10-03T15:29:26.376Z,1570116566.376 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 6.208489 min 
2019-10-03T15:29:26.376Z,1570116566.376 [Default:CheckIn:E] Stopped
2019-10-03T15:29:26.376Z,1570116566.376 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-10-03T15:29:26.376Z,1570116566.376 [Default:CheckIn] Stopped
2019-10-03T15:29:26.376Z,1570116566.376 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-10-03T15:29:26.376Z,1570116566.376 [Default:CheckIn](INFO): Running loop #2
2019-10-03T15:29:26.376Z,1570116566.376 [Default:CheckIn] Running Loop=2
2019-10-03T15:29:26.377Z,1570116566.377 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-10-03T15:29:26.377Z,1570116566.377 [Default:CheckIn:Read_GPS] Running Loop=1
2019-10-03T15:29:27.477Z,1570116567.477 [CommandLine](IMPORTANT): got command get CBIT.abortDepth
2019-10-03T15:29:27.478Z,1570116567.478 [CommandLine](IMPORTANT): CBIT.abortDepth 255.000000 m
2019-10-03T15:29:27.955Z,1570116567.955 [NAL9602](DEBUG): Fix Requested
2019-10-03T15:29:28.355Z,1570116568.355 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,152928.00,A,3648.16450,N,12147.21511,W,0.428,17.48,031019,,,A*4F
2019-10-03T15:29:28.357Z,1570116568.357 [NAL9602](INFO): GPS fix at 20191003T152928: (36.802742, -121.786918)
2019-10-03T15:29:28.387Z,1570116568.387 [Default:CheckIn:Read_GPS] Stopped
2019-10-03T15:29:28.387Z,1570116568.387 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-10-03T15:29:38.330Z,1570116578.330 [CommandLine](IMPORTANT): got command show variable massDefault
2019-10-03T15:29:38.412Z,1570116578.412 [CommandLine](IMPORTANT): VerticalControl.massDefault (centimeter)
2019-10-03T15:29:38.666Z,1570116578.666 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20191003T152027/Courier0007.lzma
2019-10-03T15:29:40.672Z,1570116580.672 [DataOverHttps](INFO): Moved sent file to Logs/20191003T152027/Courier0007.lzma.bak
2019-10-03T15:29:40.673Z,1570116580.673 [DataOverHttps](INFO): SBD MOMSN=11844908
2019-10-03T15:29:41.481Z,1570116581.481 [CommandLine](IMPORTANT): got command show variable massDef
2019-10-03T15:29:41.548Z,1570116581.548 [CommandLine](IMPORTANT): VerticalControl.massDefault (centimeter)
2019-10-03T15:29:45.662Z,1570116585.662 [CommandLine](IMPORTANT): got command get VerticalControl.massDefault
2019-10-03T15:29:45.662Z,1570116585.662 [CommandLine](IMPORTANT): VerticalControl.massDefault 0.460000 cm
2019-10-03T15:29:52.161Z,1570116592.161 [CommandLine](IMPORTANT): got command show variable buoyancyNeutral
2019-10-03T15:29:52.278Z,1570116592.278 [CommandLine](IMPORTANT): Config/Simulator.buoyancyNeutralOffset (cubic_centimeter)
2019-10-03T15:29:52.296Z,1570116592.296 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral (cubic_centimeter)
2019-10-03T15:29:56.625Z,1570116596.625 [NAL9602](INFO): SBD MO Status=0, MOMSN=2091, MT Status=0, MTMSN=0
2019-10-03T15:29:56.625Z,1570116596.625 [NAL9602](INFO): No messages in MT queue
2019-10-03T15:29:57.803Z,1570116597.803 [CommandLine](IMPORTANT): got command get VerticalControl.buoyancyNeutral
2019-10-03T15:29:57.804Z,1570116597.804 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral 237.000000 cc
2019-10-03T15:30:01.442Z,1570116601.442 [DataOverHttps](INFO): Sending 94 bytes from file Logs/20191003T152027/Express0005.lzma
2019-10-03T15:30:03.448Z,1570116603.448 [DataOverHttps](INFO): Moved sent file to Logs/20191003T152027/Express0005.lzma.bak
2019-10-03T15:30:03.449Z,1570116603.449 [DataOverHttps](INFO): SBD MOMSN=11844911
2019-10-03T15:30:27.332Z,1570116627.332 [NAL9602](INFO): Not Powering down - fast GPS
2019-10-03T15:30:27.393Z,1570116627.393 [DataOverHttps](INFO): Sending 287 bytes from file Logs/20191003T152027/Express0008.lzma
2019-10-03T15:30:29.224Z,1570116629.224 [CommandLine](IMPORTANT): got command show variable ping
2019-10-03T15:30:29.269Z,1570116629.269 [CommandLine](IMPORTANT): DUSBL_Hydroid.numberOfPingsRequested (count)
2019-10-03T15:30:29.271Z,1570116629.271 [CommandLine](IMPORTANT): Micromodem.dusblPingCode (none)
2019-10-03T15:30:29.275Z,1570116629.275 [CommandLine](IMPORTANT): Rowe_600.writeGoodBeamPingsProfile (bool)
2019-10-03T15:30:29.275Z,1570116629.275 [CommandLine](IMPORTANT): Rowe_600.writeGoodEarthPingsProfile (bool)
2019-10-03T15:30:29.276Z,1570116629.276 [CommandLine](IMPORTANT): BR_Ping1D.loadAtStartup (bool)
2019-10-03T15:30:29.276Z,1570116629.276 [CommandLine](IMPORTANT): BR_Ping1D.interval (millisecond)
2019-10-03T15:30:29.276Z,1570116629.276 [CommandLine](IMPORTANT): BR_Ping1D.simulateHardware (bool)
2019-10-03T15:30:29.277Z,1570116629.277 [CommandLine](IMPORTANT): BR_Ping1D.verbosity (count)
2019-10-03T15:30:29.277Z,1570116629.277 [CommandLine](IMPORTANT): BR_Ping1D.minRange (meter)
2019-10-03T15:30:29.277Z,1570116629.277 [CommandLine](IMPORTANT): BR_Ping1D.maxRange (meter)
2019-10-03T15:30:29.278Z,1570116629.278 [CommandLine](IMPORTANT): BR_Ping1D.soundSpeed (meter_per_second)
2019-10-03T15:30:29.278Z,1570116629.278 [CommandLine](IMPORTANT): BR_Ping1D.autoMode (bool)
2019-10-03T15:30:29.278Z,1570116629.278 [CommandLine](IMPORTANT): BR_Ping1D.gainIndex (count)
2019-10-03T15:30:29.279Z,1570116629.279 [CommandLine](IMPORTANT): BR_Ping1D.minConfidence (percent)
2019-10-03T15:30:29.279Z,1570116629.279 [CommandLine](IMPORTANT): BR_Ping1D.pingEnable (bool)
2019-10-03T15:30:29.286Z,1570116629.286 [CommandLine](IMPORTANT): BR_Ping1D.loadControl (none)
2019-10-03T15:30:29.287Z,1570116629.287 [CommandLine](IMPORTANT): BR_Ping1D.uart (none)
2019-10-03T15:30:29.287Z,1570116629.287 [CommandLine](IMPORTANT): BR_Ping1D.baud (bit_per_second)
2019-10-03T15:30:29.393Z,1570116629.393 [DataOverHttps](INFO): Moved sent file to Logs/20191003T152027/Express0008.lzma.bak
2019-10-03T15:30:29.393Z,1570116629.393 [DataOverHttps](INFO): SBD MOMSN=11844914
2019-10-03T15:30:33.053Z,1570116633.053 [Default:CheckIn:Read_Iridium] Stopped
2019-10-03T15:30:33.053Z,1570116633.053 [Default:CheckIn:C.Wait] Running Loop=1
2019-10-03T15:30:33.053Z,1570116633.053 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-10-03T15:30:36.664Z,1570116636.664 [CommandLine](IMPORTANT): got command get BR_Ping1D.loadAtStartup
2019-10-03T15:30:36.664Z,1570116636.664 [CommandLine](IMPORTANT): BR_Ping1D.loadAtStartup 1 bool
2019-10-03T15:30:56.633Z,1570116656.633 [CommandLine](IMPORTANT): got command configSet BR_Ping1D.loadAtStartup 0.000000 bool persist
2019-10-03T15:33:05.728Z,1570116785.728 [BPC1](ERROR): BPC1B: No match for serial number 1717 in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2019-10-03T15:35:12.983Z,1570116912.983 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-10-03T15:35:28.339Z,1570116928.339 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-10-03T15:35:33.619Z,1570116933.619 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-10-03T15:35:33.619Z,1570116933.619 [Default:CheckIn:C.Wait] Stopped
2019-10-03T15:35:33.620Z,1570116933.620 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-10-03T15:35:33.620Z,1570116933.620 [Default:CheckIn:D] Running Loop=1
2019-10-03T15:35:34.026Z,1570116934.026 [Default:CheckIn:D] Stopped
2019-10-03T15:35:34.026Z,1570116934.026 [Default:CheckIn:E] Running Loop=1
2019-10-03T15:35:34.450Z,1570116934.450 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 12.342378 min 
2019-10-03T15:35:34.450Z,1570116934.450 [Default:CheckIn:E] Stopped
2019-10-03T15:35:34.450Z,1570116934.450 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-10-03T15:35:34.450Z,1570116934.450 [Default:CheckIn] Stopped
2019-10-03T15:35:34.451Z,1570116934.451 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-10-03T15:35:34.451Z,1570116934.451 [Default:CheckIn](INFO): Running loop #3
2019-10-03T15:35:34.451Z,1570116934.451 [Default:CheckIn] Running Loop=3
2019-10-03T15:35:34.451Z,1570116934.451 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-10-03T15:35:34.451Z,1570116934.451 [Default:CheckIn:Read_GPS] Running Loop=1
2019-10-03T15:35:36.011Z,1570116936.011 [NAL9602](DEBUG): Fix Requested
2019-10-03T15:35:36.417Z,1570116936.417 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,153536.00,A,3648.16364,N,12147.21663,W,0.039,17.48,031019,,,D*4A
2019-10-03T15:35:36.419Z,1570116936.419 [NAL9602](INFO): GPS fix at 20191003T153536: (36.802727, -121.786944)
2019-10-03T15:35:36.451Z,1570116936.451 [Default:CheckIn:Read_GPS] Stopped
2019-10-03T15:35:36.451Z,1570116936.451 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-10-03T15:35:43.302Z,1570116943.302 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-10-03T15:35:46.430Z,1570116946.430 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20191003T152027/Courier0010.lzma
2019-10-03T15:35:48.438Z,1570116948.438 [DataOverHttps](INFO): Moved sent file to Logs/20191003T152027/Courier0010.lzma.bak
2019-10-03T15:35:48.438Z,1570116948.438 [DataOverHttps](IMPORTANT): SBD MOMSN=11844937, MTMSN=20191003T153547
2019-10-03T15:35:58.236Z,1570116958.236 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-10-03T15:35:58.504Z,1570116958.504 [DataOverHttps](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" 3qjbe 1 2
2019-10-03T15:35:58.532Z,1570116958.532 [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" 3qjbe 1 2.000000
2019-10-03T15:35:58.533Z,1570116958.533 [CommandLine](IMPORTANT): Scheduling command #1 of 2 with id=3qjbe
2019-10-03T15:35:58.534Z,1570116958.534 [CommandLine](IMPORTANT): Scheduled #1 (#1 of 2 with id='3qjbe'): "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-03T15:36:00.508Z,1570116960.508 [DataOverHttps](IMPORTANT): SBD MTMSN=20191003T153559
2019-10-03T15:36:07.956Z,1570116967.956 [DataOverHttps](INFO): Sending 683 bytes from file Logs/20191003T152027/Express0011.lzma
2019-10-03T15:36:07.960Z,1570116967.960 [DataOverHttps](INFO): Received command:sched asap "set profile_station.MaxDepth 30 meter;run " 3qjbe 2 2
2019-10-03T15:36:08.048Z,1570116968.048 [CommandLine](IMPORTANT): got command schedule asap "set profile_station.MaxDepth 30 meter;run " 3qjbe 2 2.000000
2019-10-03T15:36:08.049Z,1570116968.049 [CommandLine](IMPORTANT): Scheduling command #2 of 2 with id=3qjbe
2019-10-03T15:36:08.049Z,1570116968.049 [CommandLine](IMPORTANT): Scheduled #2 (#2 of 2 with id='3qjbe'): "set profile_station.MaxDepth 30 meter;run " ASAP
2019-10-03T15:36:08.225Z,1570116968.225 [CommandLine](IMPORTANT): got command load ./Missions/Science/profile_station.xml
2019-10-03T15:36:08.225Z,1570116968.225 [MissionManager](INFO): Loading Mission: ./Missions/Science/profile_station.xml
2019-10-03T15:36:08.309Z,1570116968.309 [MissionManager](INFO): DefineArg profile_station.MissionTimeout = 4.000000 h
2019-10-03T15:36:08.312Z,1570116968.312 [MissionManager](INFO): DefineArg profile_station.NeedCommsTime = 60.000000 min
2019-10-03T15:36:08.315Z,1570116968.315 [MissionManager](INFO): DefineArg profile_station.Lat = 36.806966 arcdeg
2019-10-03T15:36:08.319Z,1570116968.319 [MissionManager](INFO): DefineArg profile_station.Lon = -121.824326 arcdeg
2019-10-03T15:36:08.322Z,1570116968.322 [MissionManager](INFO): DefineArg profile_station.Radius = 300.000000 m
2019-10-03T15:36:08.325Z,1570116968.325 [MissionManager](INFO): DefineArg profile_station.YoYoMinDepth = 2.000000 m
2019-10-03T15:36:08.328Z,1570116968.328 [MissionManager](INFO): DefineArg profile_station.YoYoMaxDepth = 200.000000 m
2019-10-03T15:36:08.331Z,1570116968.331 [MissionManager](INFO): DefineArg profile_station.YoYoMinAltitude = 7.000000 m
2019-10-03T15:36:08.334Z,1570116968.334 [MissionManager](INFO): DefineArg profile_station.YoYoPitch = 20.000000 arcdeg
2019-10-03T15:36:08.397Z,1570116968.397 [MissionManager](INFO): DefineArg profile_station.Speed = 1.000000 m/s
2019-10-03T15:36:08.404Z,1570116968.404 [MissionManager](INFO): DefineArg profile_station.CircleMaxError = 100.000000 m
2019-10-03T15:36:08.419Z,1570116968.419 [MissionManager](INFO): DefineArg profile_station.CircleTurnToPort = 0 bool
2019-10-03T15:36:08.422Z,1570116968.422 [MissionManager](INFO): DefineArg profile_station.KwpHeading = 0.010000 rad/m
2019-10-03T15:36:08.434Z,1570116968.434 [MissionManager](INFO): DefineArg profile_station.MinAltitude = 5.000000 m
2019-10-03T15:36:08.441Z,1570116968.441 [MissionManager](INFO): DefineArg profile_station.MaxDepth = 205.000000 m
2019-10-03T15:36:08.452Z,1570116968.452 [MissionManager](INFO): DefineArg profile_station.MinOffshore = 2.000000 km
2019-10-03T15:36:08.453Z,1570116968.453 [MissionManager](INFO): Inserting Stack: Missions/Insert/Science.xml
2019-10-03T15:36:08.733Z,1570116968.733 [MissionManager](INFO): DefineArg profile_station:Science.SampleISUS = 0 bool
2019-10-03T15:36:08.736Z,1570116968.736 [MissionManager](INFO): DefineArg profile_station:Science.SampleISUSmaxPitch = 60.000000 arcdeg
2019-10-03T15:36:08.757Z,1570116968.757 [MissionManager](INFO): DefineArg profile_station:Science.SampleISUSminPitch = -60.000000 arcdeg
2019-10-03T15:36:08.776Z,1570116968.776 [MissionManager](INFO): DefineArg profile_station:Science.PeakDetectChlActive = 0 bool
2019-10-03T15:36:08.803Z,1570116968.803 [MissionManager](INFO): DefineArg profile_station:Science.TimeWindowPeakReport = nan min
2019-10-03T15:36:08.806Z,1570116968.806 [MissionManager](INFO): DefineArg profile_station:Science.HighestChlPeakReportActive = 0 bool
2019-10-03T15:36:08.817Z,1570116968.817 [MissionManager](INFO): DefineArg profile_station:Science.PatchTracking = 0 bool
2019-10-03T15:36:08.824Z,1570116968.824 [MissionManager](INFO): DefineArg profile_station:Science.FilterWidthHorizontal = 3.000000 count
2019-10-03T15:36:08.840Z,1570116968.840 [MissionManager](INFO): DefineArg profile_station:Science.NumProfilesSlidingwindow = 100.000000 count
2019-10-03T15:36:08.843Z,1570116968.843 [MissionManager](INFO): DefineArg profile_station:Science.OffPeakFractionHorizontal = 80.000000 %
2019-10-03T15:36:08.854Z,1570116968.854 [MissionManager](INFO): DefineArg profile_station:Science.PeakDetectNO3Active = 0 bool
2019-10-03T15:36:08.867Z,1570116968.867 [MissionManager](INFO): DefineArg profile_station:Science.PeakDetectOilActive = 0 bool
2019-10-03T15:36:08.870Z,1570116968.870 [MissionManager](INFO): DefineArg profile_station:Science.PeakDetectFDOMActive = 0 bool
2019-10-03T15:36:08.884Z,1570116968.884 [MissionManager](INFO): DefineArg profile_station:Science.UpwardDerivativeOfTemperatureActive = 0 bool
2019-10-03T15:36:08.892Z,1570116968.892 [MissionManager](INFO): DefineArg profile_station:Science.EnabledAanderaaO2 = 0.000000 bool
2019-10-03T15:36:08.900Z,1570116968.900 [MissionManager](INFO): DefineArg profile_station:Science.EnabledNeilBrown = 0.000000 bool
2019-10-03T15:36:08.918Z,1570116968.918 [MissionManager](INFO): DefineArg profile_station:Science.EnabledSeabird = 1.000000 bool
2019-10-03T15:36:08.932Z,1570116968.932 [MissionManager](INFO): DefineArg profile_station:Science.EnabledTurbulence_NPS = 0.000000 bool
2019-10-03T15:36:08.936Z,1570116968.936 [MissionManager](INFO): DefineArg profile_station:Science.EnabledWetLabsBB2FL = 1.000000 bool
2019-10-03T15:36:08.948Z,1570116968.948 [MissionManager](INFO): DefineArg profile_station:Science.EnabledWetLabsSeaOWL_UV_A = 0.000000 bool
2019-10-03T15:36:08.972Z,1570116968.972 [MissionManager](INFO): DefineArg profile_station:Science.EnabledWetLabsUBAT = 0.000000 bool
2019-10-03T15:36:08.988Z,1570116968.988 [MissionManager](INFO): DefineArg profile_station:Science.EnabledISUS = 0.000000 bool
2019-10-03T15:36:08.995Z,1570116968.995 [MissionManager](INFO): DefineArg profile_station:Science.LowPassWindowLength = 20.000000 count
2019-10-03T15:36:08.998Z,1570116968.998 [MissionManager](INFO): DefineArg profile_station:Science.MedianFilterLen = 5.000000 count
2019-10-03T15:36:09.009Z,1570116969.009 [MissionManager](INFO): DefineArg profile_station:Science.PeakChlShallowBound = nan m
2019-10-03T15:36:09.021Z,1570116969.021 [MissionManager](INFO): DefineArg profile_station:Science.PeakChlDeepBound = nan m
2019-10-03T15:36:09.028Z,1570116969.028 [MissionManager](INFO): DefineArg profile_station:Science.PeakShallowBound = nan m
2019-10-03T15:36:09.047Z,1570116969.047 [MissionManager](INFO): DefineArg profile_station:Science.PeakDeepBound = nan m
2019-10-03T15:36:09.051Z,1570116969.051 [MissionManager](INFO): DefineOutput profile_station:Science.PeakChl = 0.000000 ug/l
2019-10-03T15:36:09.070Z,1570116969.070 [MissionManager](INFO): DefineOutput profile_station:Science.PeakChlDepth = 0.000000 m
2019-10-03T15:36:09.090Z,1570116969.090 [MissionManager](INFO): DefineOutput profile_station:Science.PeakChlTemperature = 0.000000 degC
2019-10-03T15:36:09.097Z,1570116969.097 [MissionManager](INFO): DefineOutput profile_station:Science.PeakChlLatitude = nan arcdeg
2019-10-03T15:36:09.116Z,1570116969.116 [MissionManager](INFO): DefineOutput profile_station:Science.PeakChlLongitude = nan arcdeg
2019-10-03T15:36:09.124Z,1570116969.124 [MissionManager](INFO): DefineOutput profile_station:Science.PeakNO3 = 0.000000 umol/l
2019-10-03T15:36:09.140Z,1570116969.140 [MissionManager](INFO): DefineOutput profile_station:Science.PeakNO3Depth = 0.000000 m
2019-10-03T15:36:09.185Z,1570116969.185 [MissionManager](INFO): DefineOutput profile_station:Science.PeakNO3Latitude = nan arcdeg
2019-10-03T15:36:09.210Z,1570116969.210 [MissionManager](INFO): DefineOutput profile_station:Science.PeakNO3Longitude = nan arcdeg
2019-10-03T15:36:09.222Z,1570116969.222 [MissionManager](INFO): DefineOutput profile_station:Science.PatchChl = 0.000000 m
2019-10-03T15:36:09.237Z,1570116969.237 [MissionManager](INFO): DefineOutput profile_station:Science.PatchChlDepth = 0.000000 m
2019-10-03T15:36:09.260Z,1570116969.260 [MissionManager](INFO): DefineOutput profile_station:Science.PatchChlLatitude = nan arcdeg
2019-10-03T15:36:09.268Z,1570116969.268 [MissionManager](INFO): DefineOutput profile_station:Science.PatchChlLongitude = nan arcdeg
2019-10-03T15:36:09.280Z,1570116969.280 [MissionManager](INFO): DefineOutput profile_station:Science.PatchChlDistance = nan m
2019-10-03T15:36:09.283Z,1570116969.283 [MissionManager](INFO): DefineOutput profile_station:Science.PeakOil = 0.000000 kg/m3
2019-10-03T15:36:09.294Z,1570116969.294 [MissionManager](INFO): DefineOutput profile_station:Science.PeakOilDepth = 0.000000 m
2019-10-03T15:36:09.325Z,1570116969.325 [MissionManager](INFO): DefineOutput profile_station:Science.PeakOilLatitude = nan arcdeg
2019-10-03T15:36:09.332Z,1570116969.332 [MissionManager](INFO): DefineOutput profile_station:Science.PeakOilLongitude = nan arcdeg
2019-10-03T15:36:09.351Z,1570116969.351 [MissionManager](INFO): DefineOutput profile_station:Science.PeakFDOM = 0.000000 ppb
2019-10-03T15:36:09.355Z,1570116969.355 [MissionManager](INFO): DefineOutput profile_station:Science.PeakFDOMDepth = 0.000000 m
2019-10-03T15:36:09.366Z,1570116969.366 [MissionManager](INFO): DefineOutput profile_station:Science.PeakFDOMLatitude = nan arcdeg
2019-10-03T15:36:09.374Z,1570116969.374 [MissionManager](INFO): DefineOutput profile_station:Science.PeakFDOMLongitude = nan arcdeg
2019-10-03T15:36:09.397Z,1570116969.397 [MissionManager](INFO): DefineOutput profile_station:Science.PatchFDOMDistance = nan m
2019-10-03T15:36:09.461Z,1570116969.461 [profile_station:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2019-10-03T15:36:09.512Z,1570116969.512 [profile_station:Science:HighestChlPeakReport:A.PeakDetectHorizontal](DEBUG): Construct PeakDetectHorizontal.
2019-10-03T15:36:09.592Z,1570116969.592 [profile_station:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2019-10-03T15:36:09.631Z,1570116969.631 [profile_station:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2019-10-03T15:36:09.650Z,1570116969.650 [profile_station:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2019-10-03T15:36:09.674Z,1570116969.674 [MissionManager](INFO): RedefineArg profile_station:Science.SampleISUS = value:1 bool
2019-10-03T15:36:09.684Z,1570116969.684 [MissionManager](INFO): RedefineArg profile_station:Science.PeakDetectChlActive = value:1 bool
2019-10-03T15:36:09.685Z,1570116969.685 [MissionManager](INFO): Inserting Stack: Missions/Insert/NeedComms.xml
2019-10-03T15:36:09.780Z,1570116969.780 [MissionManager](INFO): DefineArg profile_station:NeedComms.DiveInterval = 3.000000 h
2019-10-03T15:36:09.792Z,1570116969.792 [MissionManager](INFO): DefineArg profile_station:NeedComms.WaitForPitchUp = 10.000000 min
2019-10-03T15:36:09.806Z,1570116969.806 [MissionManager](INFO): DefineArg profile_station:NeedComms.SurfacePitch = 20.000000 arcdeg
2019-10-03T15:36:09.809Z,1570116969.809 [MissionManager](INFO): DefineArg profile_station:NeedComms.SurfaceDepthRate = nan m/s
2019-10-03T15:36:09.812Z,1570116969.812 [MissionManager](INFO): DefineArg profile_station:NeedComms.SurfaceSpeed = 1.000000 m/s
2019-10-03T15:36:09.827Z,1570116969.827 [MissionManager](INFO): DefineArg profile_station:NeedComms.GPSTimeout = 7.000000 min
2019-10-03T15:36:09.830Z,1570116969.830 [MissionManager](INFO): DefineArg profile_station:NeedComms.CommsTimeout = 30.000000 min
2019-10-03T15:36:09.842Z,1570116969.842 [profile_station:NeedComms:B.GoToSurface](DEBUG): Construct GoToSurface.
2019-10-03T15:36:09.881Z,1570116969.881 [MissionManager](INFO): Inserting Stack: Missions/Insert/StandardEnvelopes.xml
2019-10-03T15:36:09.910Z,1570116969.910 [MissionManager](INFO): DefineArg profile_station:StandardEnvelopes.MinAltitude = 5.000000 m
2019-10-03T15:36:09.913Z,1570116969.913 [MissionManager](INFO): DefineArg profile_station:StandardEnvelopes.MaxDepth = 200.000000 m
2019-10-03T15:36:09.936Z,1570116969.936 [MissionManager](INFO): DefineArg profile_station:StandardEnvelopes.MinOffshore = 2000.000000 m
2019-10-03T15:36:09.937Z,1570116969.937 [profile_station:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope.
2019-10-03T15:36:09.944Z,1570116969.944 [profile_station:StandardEnvelopes:B.DepthEnvelope](DEBUG): Construct DepthEnvelope.
2019-10-03T15:36:09.960Z,1570116969.960 [DataOverHttps](INFO): Moved sent file to Logs/20191003T152027/Express0011.lzma.bak
2019-10-03T15:36:09.961Z,1570116969.961 [DataOverHttps](INFO): SBD MOMSN=11844941
2019-10-03T15:36:10.008Z,1570116970.008 [profile_station:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Construct OffshoreEnvelope.
2019-10-03T15:36:10.046Z,1570116970.046 [profile_station:I.Pitch](DEBUG): Construct.
2019-10-03T15:36:10.084Z,1570116970.084 [profile_station:J.Buoyancy](DEBUG): Construct Buoyancy.
2019-10-03T15:36:10.092Z,1570116970.092 [profile_station:K.SetSpeed](DEBUG): Construct.
2019-10-03T15:36:10.109Z,1570116970.109 [profile_station:L.DepthEnvelope](DEBUG): Construct DepthEnvelope.
2019-10-03T15:36:10.149Z,1570116970.149 [profile_station:M.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope.
2019-10-03T15:36:10.173Z,1570116970.173 [profile_station:N.YoYo](DEBUG): Construct YoYo.
2019-10-03T15:36:10.206Z,1570116970.206 [profile_station:CircleWrapper:B.Circle](DEBUG): Construct.
2019-10-03T15:36:10.298Z,1570116970.298 [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-03T15:36:10.298Z,1570116970.298 [CommandLine](IMPORTANT): Loaded ./Missions/Science/profile_station.xml
2019-10-03T15:36:13.222Z,1570116973.222 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-10-03T15:36:23.181Z,1570116983.181 [CommandLine](IMPORTANT): got command set profile_station.NeedCommsTime 20.000000 minute
2019-10-03T15:36:23.182Z,1570116983.182 [CommandLine](IMPORTANT): got command set profile_station.Lat 36.712109 degree
2019-10-03T15:36:23.183Z,1570116983.183 [CommandLine](IMPORTANT): got command set profile_station.Lon -122.187027 degree
2019-10-03T15:36:23.183Z,1570116983.183 [CommandLine](IMPORTANT): got command set profile_station.YoYoMaxDepth 20.000000 meter
2019-10-03T15:36:25.272Z,1570116985.272 [CommandLine](IMPORTANT): got command set profile_station.MaxDepth 30.000000 meter
2019-10-03T15:36:25.272Z,1570116985.272 [CommandLine](IMPORTANT): got command run 
2019-10-03T15:36:25.275Z,1570116985.275 [CommandLine](IMPORTANT): Running 
2019-10-03T15:36:25.398Z,1570116985.398 [Default] Stopped
2019-10-03T15:36:25.398Z,1570116985.398 [Default](DEBUG): Aggregate::uninitialize Default
2019-10-03T15:36:25.399Z,1570116985.399 [Default:B.GoToSurface] Stopped
2019-10-03T15:36:25.399Z,1570116985.399 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-10-03T15:36:25.403Z,1570116985.403 [Default:CheckIn] Stopped
2019-10-03T15:36:25.403Z,1570116985.403 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-10-03T15:36:25.403Z,1570116985.403 [Default:CheckIn:Read_Iridium] Stopped
2019-10-03T15:36:25.403Z,1570116985.403 [MissionManager](IMPORTANT): Started mission profile_station
2019-10-03T15:36:25.404Z,1570116985.404 [profile_station] Running Loop=1
2019-10-03T15:36:25.404Z,1570116985.404 [profile_station](DEBUG): Aggregate::initialize profile_station
2019-10-03T15:36:25.404Z,1570116985.404 [profile_station:Science] Running Loop=1
2019-10-03T15:36:25.404Z,1570116985.404 [profile_station:Science](DEBUG): Aggregate::initialize profile_station:Science
2019-10-03T15:36:25.404Z,1570116985.404 [profile_station:Science:A] Running Loop=1
2019-10-03T15:36:25.404Z,1570116985.404 [profile_station:Science:B] Running Loop=1
2019-10-03T15:36:25.404Z,1570116985.404 [profile_station:Science:C] Running Loop=1
2019-10-03T15:36:25.404Z,1570116985.404 [profile_station:Science:D] Running Loop=1
2019-10-03T15:36:25.404Z,1570116985.404 [profile_station:Science:E] Running Loop=1
2019-10-03T15:36:25.404Z,1570116985.404 [profile_station:Science:F] Running Loop=1
2019-10-03T15:36:25.404Z,1570116985.404 [profile_station:Science:G] Running Loop=1
2019-10-03T15:36:25.405Z,1570116985.405 [profile_station:Science:H] Running Loop=1
2019-10-03T15:36:25.405Z,1570116985.405 [profile_station:Science:Read_Oil] Running Loop=1
2019-10-03T15:36:25.405Z,1570116985.405 [profile_station:Science:PeakDetectChl] Running Loop=1
2019-10-03T15:36:25.405Z,1570116985.405 [profile_station:Science:PeakDetectChl](DEBUG): Aggregate::initialize profile_station:Science:PeakDetectChl
2019-10-03T15:36:25.405Z,1570116985.405 [profile_station:Science:PeakDetectChl:A.PeakDetectVsDepth] Running Loop=1
2019-10-03T15:36:25.405Z,1570116985.405 [profile_station:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Initialize.
2019-10-03T15:36:25.411Z,1570116985.411 [profile_station:Science:HighestChlPeakReport] Running Loop=1
2019-10-03T15:36:25.411Z,1570116985.411 [profile_station:Science:HighestChlPeakReport](DEBUG): Aggregate::initialize profile_station:Science:HighestChlPeakReport
2019-10-03T15:36:25.411Z,1570116985.411 [profile_station:Science:HighestChlPeakReport:A.PeakDetectHorizontal] Running Loop=1
2019-10-03T15:36:25.411Z,1570116985.411 [profile_station:Science:HighestChlPeakReport:A.PeakDetectHorizontal](INFO): Initialize.
2019-10-03T15:36:25.412Z,1570116985.412 [profile_station:Science:PeakDetectNO3] Running Loop=1
2019-10-03T15:36:25.412Z,1570116985.412 [profile_station:Science:PeakDetectNO3](DEBUG): Aggregate::initialize profile_station:Science:PeakDetectNO3
2019-10-03T15:36:25.412Z,1570116985.412 [profile_station:Science:PeakDetectNO3:A.PeakDetectVsDepth] Running Loop=1
2019-10-03T15:36:25.412Z,1570116985.412 [profile_station:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Initialize.
2019-10-03T15:36:25.414Z,1570116985.414 [profile_station:Science:PeakDetectOil] Running Loop=1
2019-10-03T15:36:25.414Z,1570116985.414 [profile_station:Science:PeakDetectOil](DEBUG): Aggregate::initialize profile_station:Science:PeakDetectOil
2019-10-03T15:36:25.414Z,1570116985.414 [profile_station:Science:PeakDetectOil:A.PeakDetectVsDepth] Running Loop=1
2019-10-03T15:36:25.414Z,1570116985.414 [profile_station:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Initialize.
2019-10-03T15:36:25.421Z,1570116985.421 [profile_station:Science:PeakDetectFDOM] Running Loop=1
2019-10-03T15:36:25.421Z,1570116985.421 [profile_station:Science:PeakDetectFDOM](DEBUG): Aggregate::initialize profile_station:Science:PeakDetectFDOM
2019-10-03T15:36:25.421Z,1570116985.421 [profile_station:Science:PeakDetectFDOM:A.PeakDetectVsDepth] Running Loop=1
2019-10-03T15:36:25.422Z,1570116985.422 [profile_station:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Initialize.
2019-10-03T15:36:25.424Z,1570116985.424 [profile_station:StandardEnvelopes] Running Loop=1
2019-10-03T15:36:25.424Z,1570116985.424 [profile_station:StandardEnvelopes](DEBUG): Aggregate::initialize profile_station:StandardEnvelopes
2019-10-03T15:36:25.424Z,1570116985.424 [profile_station:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1
2019-10-03T15:36:25.424Z,1570116985.424 [profile_station:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent.
2019-10-03T15:36:25.424Z,1570116985.424 [profile_station:StandardEnvelopes:B.DepthEnvelope] Running Loop=1
2019-10-03T15:36:25.424Z,1570116985.424 [profile_station:StandardEnvelopes:B.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent.
2019-10-03T15:36:25.425Z,1570116985.425 [profile_station:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1
2019-10-03T15:36:25.425Z,1570116985.425 [profile_station:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Initialize OffshoreEnvelopeComponent.
2019-10-03T15:36:25.425Z,1570116985.425 [profile_station:I.Pitch] Running Loop=1
2019-10-03T15:36:25.425Z,1570116985.425 [profile_station:I.Pitch](DEBUG): Initialize.
2019-10-03T15:36:25.425Z,1570116985.425 [profile_station:J.Buoyancy] Running Loop=1
2019-10-03T15:36:25.425Z,1570116985.425 [profile_station:J.Buoyancy](DEBUG): Initialize Buoyancy Component.
2019-10-03T15:36:25.425Z,1570116985.425 [profile_station:K.SetSpeed] Running Loop=1
2019-10-03T15:36:25.425Z,1570116985.425 [profile_station:K.SetSpeed](DEBUG): Initialize.
2019-10-03T15:36:25.425Z,1570116985.425 [profile_station:L.DepthEnvelope] Running Loop=1
2019-10-03T15:36:25.425Z,1570116985.425 [profile_station:L.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent.
2019-10-03T15:36:25.426Z,1570116985.426 [profile_station:M.AltitudeEnvelope] Running Loop=1
2019-10-03T15:36:25.426Z,1570116985.426 [profile_station:M.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent.
2019-10-03T15:36:25.426Z,1570116985.426 [profile_station:N.YoYo] Running Loop=1
2019-10-03T15:36:25.426Z,1570116985.426 [profile_station:N.YoYo](DEBUG): Initialize YoYoComponent.
2019-10-03T15:36:25.426Z,1570116985.426 [profile_station:C] Running Loop=1
2019-10-03T15:36:25.435Z,1570116985.435 [profile_station:N.YoYo] Running Loop=1
2019-10-03T15:36:25.436Z,1570116985.436 [profile_station:M.AltitudeEnvelope] Running Loop=1
2019-10-03T15:36:25.436Z,1570116985.436 [profile_station:L.DepthEnvelope] Running Loop=1
2019-10-03T15:36:25.437Z,1570116985.437 [profile_station:K.SetSpeed] Running Loop=1
2019-10-03T15:36:25.438Z,1570116985.438 [profile_station:J.Buoyancy] Running Loop=1
2019-10-03T15:36:25.438Z,1570116985.438 [profile_station:I.Pitch] Running Loop=1
2019-10-03T15:36:25.438Z,1570116985.438 [profile_station:StandardEnvelopes] Running Loop=1
2019-10-03T15:36:25.438Z,1570116985.438 [profile_station:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1
2019-10-03T15:36:25.491Z,1570116985.491 [profile_station:StandardEnvelopes:B.DepthEnvelope] Running Loop=1
2019-10-03T15:36:25.492Z,1570116985.492 [profile_station:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1
2019-10-03T15:36:25.492Z,1570116985.492 [profile_station:C] Stopped
2019-10-03T15:36:25.492Z,1570116985.492 [profile_station:E] Running Loop=1
2019-10-03T15:36:25.492Z,1570116985.492 [profile_station:Science] Running Loop=1
2019-10-03T15:36:25.494Z,1570116985.494 [profile_station:Science:PeakDetectFDOM] Stopped
2019-10-03T15:36:25.494Z,1570116985.494 [profile_station:Science:PeakDetectFDOM](DEBUG): Aggregate::uninitialize profile_station:Science:PeakDetectFDOM
2019-10-03T15:36:25.494Z,1570116985.494 [profile_station:Science:PeakDetectFDOM:A.PeakDetectVsDepth] Stopped
2019-10-03T15:36:25.494Z,1570116985.494 [profile_station:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2019-10-03T15:36:25.494Z,1570116985.494 [profile_station:Science:PeakDetectOil] Stopped
2019-10-03T15:36:25.494Z,1570116985.494 [profile_station:Science:PeakDetectOil](DEBUG): Aggregate::uninitialize profile_station:Science:PeakDetectOil
2019-10-03T15:36:25.494Z,1570116985.494 [profile_station:Science:PeakDetectOil:A.PeakDetectVsDepth] Stopped
2019-10-03T15:36:25.494Z,1570116985.494 [profile_station:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2019-10-03T15:36:25.494Z,1570116985.494 [profile_station:Science:PeakDetectNO3] Stopped
2019-10-03T15:36:25.495Z,1570116985.495 [profile_station:Science:PeakDetectNO3](DEBUG): Aggregate::uninitialize profile_station:Science:PeakDetectNO3
2019-10-03T15:36:25.495Z,1570116985.495 [profile_station:Science:PeakDetectNO3:A.PeakDetectVsDepth] Stopped
2019-10-03T15:36:25.495Z,1570116985.495 [profile_station:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2019-10-03T15:36:25.503Z,1570116985.503 [profile_station:Science:HighestChlPeakReport] Stopped
2019-10-03T15:36:25.503Z,1570116985.503 [profile_station:Science:HighestChlPeakReport](DEBUG): Aggregate::uninitialize profile_station:Science:HighestChlPeakReport
2019-10-03T15:36:25.503Z,1570116985.503 [profile_station:Science:HighestChlPeakReport:A.PeakDetectHorizontal] Stopped
2019-10-03T15:36:25.503Z,1570116985.503 [profile_station:Science:HighestChlPeakReport:A.PeakDetectHorizontal](DEBUG): Uninitialize.
2019-10-03T15:36:25.503Z,1570116985.503 [profile_station:Science:PeakDetectChl] Running Loop=1
2019-10-03T15:36:25.504Z,1570116985.504 [profile_station:Science:Read_Oil] Stopped
2019-10-03T15:36:25.504Z,1570116985.504 [profile_station:Science:H] Stopped
2019-10-03T15:36:25.504Z,1570116985.504 [profile_station:Science:G] Running Loop=1
2019-10-03T15:36:25.504Z,1570116985.504 [profile_station:Science:G](DEBUG): Initialize ReadDataComponent to sense mass_concentration_of_chlorophyll_in_sea_water
2019-10-03T15:36:25.505Z,1570116985.505 [profile_station:Science:F] Stopped
2019-10-03T15:36:25.505Z,1570116985.505 [profile_station:Science:E] Stopped
2019-10-03T15:36:25.505Z,1570116985.505 [profile_station:Science:D] Running Loop=1
2019-10-03T15:36:25.505Z,1570116985.505 [profile_station:Science:D](DEBUG): Initialize ReadDataComponent to sense CTD_Seabird.sea_water_temperature
2019-10-03T15:36:25.506Z,1570116985.506 [profile_station:Science:D](DEBUG): Initialize ReadDataComponent to sense CTD_Seabird.sea_water_salinity
2019-10-03T15:36:25.506Z,1570116985.506 [profile_station:Science:C] Running Loop=1
2019-10-03T15:36:25.515Z,1570116985.515 [profile_station:Science:C](DEBUG): Initialize ReadDataComponent to sense sea_water_temperature
2019-10-03T15:36:25.516Z,1570116985.516 [profile_station:Science:C](DEBUG): Initialize ReadDataComponent to sense sea_water_salinity
2019-10-03T15:36:25.516Z,1570116985.516 [profile_station:Science:B] Stopped
2019-10-03T15:36:25.516Z,1570116985.516 [profile_station:Science:A] Stopped
2019-10-03T15:36:25.553Z,1570116985.553 [WetLabsBB2FL](INFO): Opening uart, block timeout 10ths=2
2019-10-03T15:36:25.553Z,1570116985.553 [WetLabsBB2FL](INFO): Powering up
2019-10-03T15:36:25.848Z,1570116985.848 [profile_station:E] Stopped
2019-10-03T15:36:25.848Z,1570116985.848 [profile_station:F] Running Loop=1
2019-10-03T15:36:25.964Z,1570116985.964 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20
2019-10-03T15:36:26.281Z,1570116986.281 [profile_station:F] Stopped
2019-10-03T15:36:26.281Z,1570116986.281 [profile_station:G] Running Loop=1
2019-10-03T15:36:26.646Z,1570116986.646 [profile_station:G] Stopped
2019-10-03T15:36:26.646Z,1570116986.646 [profile_station:StartingMission] Running Loop=1
2019-10-03T15:36:26.646Z,1570116986.646 [profile_station:StartingMission](DEBUG): Aggregate::initialize profile_station:StartingMission
2019-10-03T15:36:27.143Z,1570116987.143 [profile_station:M.AltitudeEnvelope](ERROR): Altitude Measurement is not Active.
2019-10-03T15:36:27.212Z,1570116987.212 [profile_station:StandardEnvelopes:A.AltitudeEnvelope](ERROR): Altitude Measurement is not Active.
2019-10-03T15:36:27.212Z,1570116987.212 [profile_station:NeedComms] Running Loop=1
2019-10-03T15:36:27.212Z,1570116987.212 [profile_station:NeedComms](DEBUG): Aggregate::initialize profile_station:NeedComms
2019-10-03T15:36:27.212Z,1570116987.212 [profile_station:NeedComms:B.GoToSurface] Running Loop=1
2019-10-03T15:36:27.212Z,1570116987.212 [profile_station:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-10-03T15:36:27.213Z,1570116987.213 [profile_station:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s.
2019-10-03T15:36:27.213Z,1570116987.213 [profile_station:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees.
2019-10-03T15:36:27.213Z,1570116987.213 [profile_station:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s.
2019-10-03T15:36:27.214Z,1570116987.214 [profile_station:NeedComms:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-10-03T15:36:27.214Z,1570116987.214 [profile_station:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-10-03T15:36:27.214Z,1570116987.214 [profile_station:NeedComms:A] Running Loop=1
2019-10-03T15:36:27.216Z,1570116987.216 [profile_station:NeedComms:A](INFO): last time_fix was: 1570116936.000000 second since 1970/01/01T00:00:00Z 
2019-10-03T15:36:27.216Z,1570116987.216 [profile_station:NeedComms:A] Stopped
2019-10-03T15:36:27.582Z,1570116987.582 [profile_station:NeedComms:C] Running Loop=1
2019-10-03T15:36:28.244Z,1570116988.244 [profile_station:NeedComms:C](DEBUG): Initialize ReadDataComponent to sense time_fix
2019-10-03T15:36:28.506Z,1570116988.506 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-10-03T15:36:28.969Z,1570116988.969 [CTD_Seabird](ERROR): Failed to parse device response: <!--startlogging-->
2019-10-03T15:36:30.978Z,1570116990.978 [CTD_Seabird](ERROR): Salinity reading out of range: 0.001966 psu
2019-10-03T15:36:31.981Z,1570116991.981 [CTD_Seabird](ERROR): Salinity reading out of range: 0.001966 psu
2019-10-03T15:36:32.986Z,1570116992.986 [CTD_Seabird](ERROR): Salinity reading out of range: 0.001966 psu
2019-10-03T15:36:33.989Z,1570116993.989 [CTD_Seabird](ERROR): Salinity reading out of range: 0.001966 psu
2019-10-03T15:36:34.994Z,1570116994.994 [CTD_Seabird](ERROR): Salinity reading out of range: 0.001913 psu
2019-10-03T15:36:35.997Z,1570116995.997 [CTD_Seabird](ERROR): Salinity reading out of range: 0.001913 psu
2019-10-03T15:36:37.001Z,1570116997.001 [CTD_Seabird](ERROR): Salinity reading out of range: 0.001912 psu
2019-10-03T15:36:38.008Z,1570116998.008 [CTD_Seabird](ERROR): Salinity reading out of range: 0.001912 psu
2019-10-03T15:36:39.009Z,1570116999.009 [CTD_Seabird](ERROR): Salinity reading out of range: 0.001965 psu
2019-10-03T15:36:39.022Z,1570116999.022 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20191003T152027/Courier0013.lzma
2019-10-03T15:36:40.013Z,1570117000.013 [CTD_Seabird](ERROR): Salinity reading out of range: 0.001912 psu
2019-10-03T15:36:41.017Z,1570117001.017 [CTD_Seabird](ERROR): Salinity reading out of range: 0.001912 psu
2019-10-03T15:36:41.028Z,1570117001.028 [DataOverHttps](INFO): Moved sent file to Logs/20191003T152027/Courier0013.lzma.bak
2019-10-03T15:36:41.029Z,1570117001.029 [DataOverHttps](INFO): SBD MOMSN=11844982
2019-10-03T15:36:42.021Z,1570117002.021 [CTD_Seabird](ERROR): Salinity reading out of range: 0.001912 psu
2019-10-03T15:36:43.025Z,1570117003.025 [CTD_Seabird](ERROR): Salinity reading out of range: 0.001912 psu
2019-10-03T15:36:44.029Z,1570117004.029 [CTD_Seabird](ERROR): Salinity reading out of range: 0.001913 psu
2019-10-03T15:36:44.692Z,1570117004.692 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-10-03T15:36:45.033Z,1570117005.033 [CTD_Seabird](ERROR): Salinity reading out of range: 0.001914 psu
2019-10-03T15:36:46.037Z,1570117006.037 [CTD_Seabird](ERROR): Salinity reading out of range: 0.001914 psu
2019-10-03T15:36:47.042Z,1570117007.042 [CTD_Seabird](ERROR): Salinity reading out of range: 0.001914 psu
2019-10-03T15:36:48.046Z,1570117008.046 [CTD_Seabird](ERROR): Salinity reading out of range: 0.001914 psu
2019-10-03T15:36:49.050Z,1570117009.050 [CTD_Seabird](ERROR): Salinity reading out of range: 0.001914 psu
2019-10-03T15:36:50.054Z,1570117010.054 [CTD_Seabird](ERROR): Salinity reading out of range: 0.001914 psu
2019-10-03T15:36:50.333Z,1570117010.333 [NAL9602](INFO): SBD MO Status=0, MOMSN=2092, MT Status=0, MTMSN=0
2019-10-03T15:36:50.334Z,1570117010.334 [NAL9602](INFO): No messages in MT queue
2019-10-03T15:36:51.058Z,1570117011.058 [CTD_Seabird](ERROR): Salinity reading out of range: 0.001914 psu
2019-10-03T15:36:51.147Z,1570117011.147 [NAL9602](DEBUG): Fix Requested
2019-10-03T15:36:51.553Z,1570117011.553 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,153651.00,A,3648.16299,N,12147.21620,W,0.156,17.48,031019,,,D*44
2019-10-03T15:36:51.556Z,1570117011.556 [NAL9602](INFO): GPS fix at 20191003T153651: (36.802717, -121.786937)
2019-10-03T15:36:51.592Z,1570117011.592 [profile_station:NeedComms:C] Stopped
2019-10-03T15:36:51.593Z,1570117011.593 [profile_station:NeedComms:D] Running Loop=1
2019-10-03T15:36:52.006Z,1570117012.006 [profile_station:NeedComms:D](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-10-03T15:36:52.062Z,1570117012.062 [CTD_Seabird](ERROR): Salinity reading out of range: 0.001914 psu
2019-10-03T15:36:53.065Z,1570117013.065 [CTD_Seabird](ERROR): Salinity reading out of range: 0.001915 psu
2019-10-03T15:36:54.069Z,1570117014.069 [CTD_Seabird](ERROR): Salinity reading out of range: 0.001916 psu
2019-10-03T15:36:55.073Z,1570117015.073 [CTD_Seabird](ERROR): Salinity reading out of range: 0.001917 psu
2019-10-03T15:36:56.078Z,1570117016.078 [CTD_Seabird](ERROR): Salinity reading out of range: 0.001917 psu
2019-10-03T15:36:57.081Z,1570117017.081 [CTD_Seabird](ERROR): Salinity reading out of range: 0.001917 psu
2019-10-03T15:36:58.085Z,1570117018.085 [CTD_Seabird](ERROR): Salinity reading out of range: 0.001916 psu
2019-10-03T15:36:59.089Z,1570117019.089 [CTD_Seabird](ERROR): Salinity reading out of range: 0.001916 psu
2019-10-03T15:37:00.093Z,1570117020.093 [CTD_Seabird](ERROR): Salinity reading out of range: 0.001916 psu
2019-10-03T15:37:00.214Z,1570117020.214 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-10-03T15:37:01.097Z,1570117021.097 [CTD_Seabird](ERROR): Salinity reading out of range: 0.001915 psu
2019-10-03T15:37:02.101Z,1570117022.101 [CTD_Seabird](ERROR): Salinity reading out of range: 0.001915 psu
2019-10-03T15:37:03.105Z,1570117023.105 [CTD_Seabird](ERROR): Salinity reading out of range: 0.001914 psu
2019-10-03T15:37:04.109Z,1570117024.109 [CTD_Seabird](ERROR): Salinity reading out of range: 0.001914 psu
2019-10-03T15:37:05.125Z,1570117025.125 [CTD_Seabird](ERROR): Salinity reading out of range: 0.001913 psu
2019-10-03T15:37:06.129Z,1570117026.129 [CTD_Seabird](ERROR): Salinity reading out of range: 0.001913 psu
2019-10-03T15:37:07.133Z,1570117027.133 [CTD_Seabird](ERROR): Salinity reading out of range: 0.001912 psu
2019-10-03T15:37:08.137Z,1570117028.137 [CTD_Seabird](ERROR): Salinity reading out of range: 0.001912 psu
2019-10-03T15:37:09.141Z,1570117029.141 [CTD_Seabird](ERROR): Salinity reading out of range: 0.001911 psu
2019-10-03T15:37:10.145Z,1570117030.145 [CTD_Seabird](ERROR): Salinity reading out of range: 0.001911 psu
2019-10-03T15:37:11.149Z,1570117031.149 [CTD_Seabird](ERROR): Salinity reading out of range: 0.001910 psu
2019-10-03T15:37:11.578Z,1570117031.578 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20191003T152027/Courier0016.lzma
2019-10-03T15:37:12.153Z,1570117032.153 [CTD_Seabird](ERROR): Salinity reading out of range: 0.001910 psu
2019-10-03T15:37:13.157Z,1570117033.157 [CTD_Seabird](ERROR): Salinity reading out of range: 0.001909 psu
2019-10-03T15:37:13.585Z,1570117033.585 [DataOverHttps](INFO): Moved sent file to Logs/20191003T152027/Courier0016.lzma.bak
2019-10-03T15:37:13.585Z,1570117033.585 [DataOverHttps](IMPORTANT): SBD MOMSN=11844987, MTMSN=20191003T153712
2019-10-03T15:37:14.161Z,1570117034.161 [CTD_Seabird](ERROR): Salinity reading out of range: 0.001909 psu
2019-10-03T15:37:15.165Z,1570117035.165 [CTD_Seabird](ERROR): Salinity reading out of range: 0.001909 psu
2019-10-03T15:37:15.567Z,1570117035.567 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-10-03T15:37:16.169Z,1570117036.169 [CTD_Seabird](ERROR): Salinity reading out of range: 0.001909 psu
2019-10-03T15:37:17.173Z,1570117037.173 [CTD_Seabird](ERROR): Salinity reading out of range: 0.001908 psu
2019-10-03T15:37:18.177Z,1570117038.177 [CTD_Seabird](ERROR): Salinity reading out of range: 0.001908 psu
2019-10-03T15:37:19.181Z,1570117039.181 [CTD_Seabird](ERROR): Salinity reading out of range: 0.001908 psu
2019-10-03T15:37:20.185Z,1570117040.185 [CTD_Seabird](ERROR): Salinity reading out of range: 0.001907 psu
2019-10-03T15:37:21.189Z,1570117041.189 [CTD_Seabird](ERROR): Salinity reading out of range: 0.001907 psu
2019-10-03T15:37:22.193Z,1570117042.193 [CTD_Seabird](ERROR): Salinity reading out of range: 0.001908 psu
2019-10-03T15:37:23.197Z,1570117043.197 [CTD_Seabird](ERROR): Salinity reading out of range: 0.001909 psu
2019-10-03T15:37:23.624Z,1570117043.624 [NAL9602](INFO): Not Powering down - fast GPS
2019-10-03T15:37:24.201Z,1570117044.201 [CTD_Seabird](ERROR): Salinity reading out of range: 0.001909 psu
2019-10-03T15:37:24.811Z,1570117044.811 [DataOverHttps](INFO): Received command:stop
2019-10-03T15:37:24.876Z,1570117044.876 [CommandLine](IMPORTANT): got command stop
2019-10-03T15:37:24.876Z,1570117044.876 [CommandLine](IMPORTANT): Scheduling is paused
2019-10-03T15:37:24.876Z,1570117044.876 [Supervisor](INFO): Stop Mission called by CommandLine::commandStop
2019-10-03T15:37:24.909Z,1570117044.909 [MissionManager](INFO): MissionManager is completed.
2019-10-03T15:37:24.909Z,1570117044.909 [MissionManager](INFO): Uninitializing Mission profile_station
2019-10-03T15:37:24.909Z,1570117044.909 [profile_station] Stopped
2019-10-03T15:37:24.909Z,1570117044.909 [profile_station](DEBUG): Aggregate::uninitialize profile_station
2019-10-03T15:37:24.909Z,1570117044.909 [profile_station:Science] Stopped
2019-10-03T15:37:24.909Z,1570117044.909 [profile_station:Science](DEBUG): Aggregate::uninitialize profile_station:Science
2019-10-03T15:37:24.909Z,1570117044.909 [profile_station:Science:C] Stopped
2019-10-03T15:37:24.909Z,1570117044.909 [profile_station:Science:D] Stopped
2019-10-03T15:37:24.910Z,1570117044.910 [profile_station:Science:G] Stopped
2019-10-03T15:37:24.910Z,1570117044.910 [profile_station:Science:PeakDetectChl] Stopped
2019-10-03T15:37:24.910Z,1570117044.910 [profile_station:Science:PeakDetectChl](DEBUG): Aggregate::uninitialize profile_station:Science:PeakDetectChl
2019-10-03T15:37:24.910Z,1570117044.910 [profile_station:Science:PeakDetectChl:A.PeakDetectVsDepth] Stopped
2019-10-03T15:37:24.910Z,1570117044.910 [profile_station:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2019-10-03T15:37:24.910Z,1570117044.910 [profile_station:NeedComms] Stopped
2019-10-03T15:37:24.910Z,1570117044.910 [profile_station:NeedComms](DEBUG): Aggregate::uninitialize profile_station:NeedComms
2019-10-03T15:37:24.910Z,1570117044.910 [profile_station:NeedComms:B.GoToSurface] Stopped
2019-10-03T15:37:24.910Z,1570117044.910 [profile_station:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-10-03T15:37:24.910Z,1570117044.910 [profile_station:NeedComms:D] Stopped
2019-10-03T15:37:24.910Z,1570117044.910 [profile_station:StandardEnvelopes] Stopped
2019-10-03T15:37:24.910Z,1570117044.910 [profile_station:StandardEnvelopes](DEBUG): Aggregate::uninitialize profile_station:StandardEnvelopes
2019-10-03T15:37:24.910Z,1570117044.910 [profile_station:StandardEnvelopes:A.AltitudeEnvelope] Stopped
2019-10-03T15:37:24.911Z,1570117044.911 [profile_station:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent.
2019-10-03T15:37:24.911Z,1570117044.911 [profile_station:StandardEnvelopes:B.DepthEnvelope] Stopped
2019-10-03T15:37:24.911Z,1570117044.911 [profile_station:StandardEnvelopes:B.DepthEnvelope](DEBUG): Uninitialize.
2019-10-03T15:37:24.915Z,1570117044.915 [profile_station:StandardEnvelopes:C.OffshoreEnvelope] Stopped
2019-10-03T15:37:24.915Z,1570117044.915 [profile_station:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Uninitialize OffshoreEnvelopeComponent.
2019-10-03T15:37:24.915Z,1570117044.915 [profile_station:StartingMission] Stopped
2019-10-03T15:37:24.915Z,1570117044.915 [profile_station:StartingMission](DEBUG): Aggregate::uninitialize profile_station:StartingMission
2019-10-03T15:37:24.915Z,1570117044.915 [profile_station:I.Pitch] Stopped
2019-10-03T15:37:24.915Z,1570117044.915 [profile_station:J.Buoyancy] Stopped
2019-10-03T15:37:24.916Z,1570117044.916 [profile_station:J.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2019-10-03T15:37:24.916Z,1570117044.916 [profile_station:K.SetSpeed] Stopped
2019-10-03T15:37:24.916Z,1570117044.916 [profile_station:K.SetSpeed](DEBUG): Uninitialize.
2019-10-03T15:37:24.916Z,1570117044.916 [profile_station:L.DepthEnvelope] Stopped
2019-10-03T15:37:24.916Z,1570117044.916 [profile_station:L.DepthEnvelope](DEBUG): Uninitialize.
2019-10-03T15:37:24.916Z,1570117044.916 [profile_station:M.AltitudeEnvelope] Stopped
2019-10-03T15:37:24.916Z,1570117044.916 [profile_station:M.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent.
2019-10-03T15:37:24.916Z,1570117044.916 [profile_station:N.YoYo] Stopped
2019-10-03T15:37:24.916Z,1570117044.916 [profile_station:N.YoYo](DEBUG): Uninitialize YoYoComponent.
2019-10-03T15:37:25.139Z,1570117045.139 [WetLabsBB2FL](INFO): Powering down
2019-10-03T15:37:25.275Z,1570117045.275 [MissionManager](IMPORTANT): Started mission Default
2019-10-03T15:37:25.276Z,1570117045.276 [Default] Running Loop=1
2019-10-03T15:37:25.276Z,1570117045.276 [Default](DEBUG): Aggregate::initialize Default
2019-10-03T15:37:25.276Z,1570117045.276 [Default:B.GoToSurface] Running Loop=1
2019-10-03T15:37:25.276Z,1570117045.276 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-10-03T15:37:25.276Z,1570117045.276 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-10-03T15:37:25.277Z,1570117045.277 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-10-03T15:37:25.277Z,1570117045.277 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-10-03T15:37:25.277Z,1570117045.277 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-10-03T15:37:25.278Z,1570117045.278 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-10-03T15:37:25.278Z,1570117045.278 [Default:A.Wait] Running Loop=1
2019-10-03T15:37:25.279Z,1570117045.279 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-10-03T15:37:30.509Z,1570117050.509 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-10-03T15:37:34.534Z,1570117054.534 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20191003T152027/Courier0019.lzma
2019-10-03T15:37:36.540Z,1570117056.540 [DataOverHttps](INFO): Moved sent file to Logs/20191003T152027/Courier0019.lzma.bak
2019-10-03T15:37:36.541Z,1570117056.541 [DataOverHttps](INFO): SBD MOMSN=11844990
2019-10-03T15:37:38.620Z,1570117058.620 [Default:A.Wait](INFO): Done Waiting.
2019-10-03T15:37:38.620Z,1570117058.620 [Default:A.Wait] Stopped
2019-10-03T15:37:38.621Z,1570117058.621 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-10-03T15:37:38.000Z,1570117059.000 [Default:CheckIn] Running Loop=1
2019-10-03T15:37:38.000Z,1570117059.000 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-10-03T15:37:39.000Z,1570117059.000 [Default:CheckIn:Read_GPS] Running Loop=1
2019-10-03T15:37:40.603Z,1570117060.603 [NAL9602](DEBUG): Fix Requested
2019-10-03T15:37:41.008Z,1570117061.008 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,153741.00,A,3648.16357,N,12147.21650,W,0.039,17.48,031019,,,D*48
2019-10-03T15:37:41.010Z,1570117061.010 [NAL9602](INFO): GPS fix at 20191003T153741: (36.802726, -121.786942)
2019-10-03T15:37:41.035Z,1570117061.035 [Default:CheckIn:Read_GPS] Stopped
2019-10-03T15:37:41.035Z,1570117061.035 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-10-03T15:37:57.565Z,1570117077.565 [NAL9602](INFO): SBD MO Status=0, MOMSN=2093, MT Status=0, MTMSN=0
2019-10-03T15:37:57.566Z,1570117077.566 [NAL9602](INFO): No messages in MT queue
2019-10-03T15:37:59.759Z,1570117079.759 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20191003T152027/Courier0022.lzma
2019-10-03T15:38:03.287Z,1570117083.287 [DataOverHttps](INFO): Moved sent file to Logs/20191003T152027/Courier0022.lzma.bak
2019-10-03T15:38:03.287Z,1570117083.287 [DataOverHttps](INFO): SBD MOMSN=11844993
2019-10-03T15:38:20.742Z,1570117100.742 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20191003T152027/Courier0026.lzma
2019-10-03T15:38:22.749Z,1570117102.749 [DataOverHttps](INFO): Moved sent file to Logs/20191003T152027/Courier0026.lzma.bak
2019-10-03T15:38:22.749Z,1570117102.749 [DataOverHttps](INFO): SBD MOMSN=11844996
2019-10-03T15:38:28.292Z,1570117108.292 [NAL9602](INFO): Not Powering down - fast GPS
2019-10-03T15:38:49.204Z,1570117129.204 [DataOverHttps](INFO): Sending 342 bytes from file Logs/20191003T152027/Express0014.lzma
2019-10-03T15:38:51.208Z,1570117131.208 [DataOverHttps](INFO): Moved sent file to Logs/20191003T152027/Express0014.lzma.bak
2019-10-03T15:38:51.209Z,1570117131.209 [DataOverHttps](INFO): SBD MOMSN=11844998
2019-10-03T15:39:10.879Z,1570117150.879 [DataOverHttps](INFO): Sending 265 bytes from file Logs/20191003T152027/Express0017.lzma
2019-10-03T15:39:12.884Z,1570117152.884 [DataOverHttps](INFO): Moved sent file to Logs/20191003T152027/Express0017.lzma.bak
2019-10-03T15:39:12.885Z,1570117152.885 [DataOverHttps](INFO): SBD MOMSN=11845004
2019-10-03T15:39:32.679Z,1570117172.679 [DataOverHttps](INFO): Sending 434 bytes from file Logs/20191003T152027/Express0020.lzma
2019-10-03T15:39:34.684Z,1570117174.684 [DataOverHttps](INFO): Moved sent file to Logs/20191003T152027/Express0020.lzma.bak
2019-10-03T15:39:34.685Z,1570117174.685 [DataOverHttps](INFO): SBD MOMSN=11845013
2019-10-03T15:39:56.431Z,1570117196.431 [DataOverHttps](INFO): Sending 198 bytes from file Logs/20191003T152027/Express0023.lzma
2019-10-03T15:39:58.437Z,1570117198.437 [DataOverHttps](INFO): Moved sent file to Logs/20191003T152027/Express0023.lzma.bak
2019-10-03T15:39:58.437Z,1570117198.437 [DataOverHttps](INFO): SBD MOMSN=11845024
2019-10-03T15:40:18.198Z,1570117218.198 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20191003T152027/Express0028.lzma
2019-10-03T15:40:20.205Z,1570117220.205 [DataOverHttps](INFO): Moved sent file to Logs/20191003T152027/Express0028.lzma.bak
2019-10-03T15:40:20.206Z,1570117220.206 [DataOverHttps](INFO): SBD MOMSN=11845030
2019-10-03T15:40:25.122Z,1570117225.122 [Default:CheckIn:Read_Iridium] Stopped
2019-10-03T15:40:25.123Z,1570117225.123 [Default:CheckIn:C.Wait] Running Loop=1
2019-10-03T15:40:25.123Z,1570117225.123 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-10-03T15:44:46.922Z,1570117486.922 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-10-03T15:44:53.770Z,1570117493.770 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-10-03T15:45:09.121Z,1570117509.121 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-10-03T15:45:24.464Z,1570117524.464 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-10-03T15:45:25.686Z,1570117525.686 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-10-03T15:45:25.686Z,1570117525.686 [Default:CheckIn:C.Wait] Stopped
2019-10-03T15:45:25.686Z,1570117525.686 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-10-03T15:45:25.686Z,1570117525.686 [Default:CheckIn:D] Running Loop=1
2019-10-03T15:45:26.099Z,1570117526.099 [Default:CheckIn:D] Stopped
2019-10-03T15:45:26.099Z,1570117526.099 [Default:CheckIn:E] Running Loop=1
2019-10-03T15:45:26.496Z,1570117526.496 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 8.013719 min 
2019-10-03T15:45:26.496Z,1570117526.496 [Default:CheckIn:E] Stopped
2019-10-03T15:45:26.497Z,1570117526.497 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-10-03T15:45:26.497Z,1570117526.497 [Default:CheckIn] Stopped
2019-10-03T15:45:26.497Z,1570117526.497 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-10-03T15:45:26.497Z,1570117526.497 [Default:CheckIn](INFO): Running loop #2
2019-10-03T15:45:26.497Z,1570117526.497 [Default:CheckIn] Running Loop=2
2019-10-03T15:45:26.497Z,1570117526.497 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-10-03T15:45:26.497Z,1570117526.497 [Default:CheckIn:Read_GPS] Running Loop=1
2019-10-03T15:45:28.099Z,1570117528.099 [NAL9602](DEBUG): Fix Requested
2019-10-03T15:45:28.492Z,1570117528.492 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,154528.00,A,3648.16281,N,12147.21543,W,0.058,17.48,031019,,,A*4B
2019-10-03T15:45:28.494Z,1570117528.494 [NAL9602](INFO): GPS fix at 20191003T154528: (36.802714, -121.786924)
2019-10-03T15:45:28.540Z,1570117528.540 [Default:CheckIn:Read_GPS] Stopped
2019-10-03T15:45:28.540Z,1570117528.540 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-10-03T15:45:36.934Z,1570117536.934 [DataOverHttps](INFO): Sending 60 bytes from file Logs/20191003T152027/Courier0025.lzma
2019-10-03T15:45:38.941Z,1570117538.941 [DataOverHttps](INFO): Moved sent file to Logs/20191003T152027/Courier0025.lzma.bak
2019-10-03T15:45:38.941Z,1570117538.941 [DataOverHttps](INFO): SBD MOMSN=11845061
2019-10-03T15:45:40.236Z,1570117540.236 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-10-03T15:45:43.041Z,1570117543.041 [NAL9602](INFO): SBD MO Status=0, MOMSN=2094, MT Status=0, MTMSN=0
2019-10-03T15:45:43.042Z,1570117543.042 [NAL9602](INFO): No messages in MT queue
2019-10-03T15:45:55.171Z,1570117555.171 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-10-03T15:45:58.874Z,1570117558.874 [DataOverHttps](INFO): Sending 117 bytes from file Logs/20191003T152027/Express0027.lzma
2019-10-03T15:46:00.881Z,1570117560.881 [DataOverHttps](INFO): Moved sent file to Logs/20191003T152027/Express0027.lzma.bak
2019-10-03T15:46:00.881Z,1570117560.881 [DataOverHttps](INFO): SBD MOMSN=11845066
2019-10-03T15:46:05.712Z,1570117565.712 [Default:CheckIn:Read_Iridium] Stopped
2019-10-03T15:46:05.712Z,1570117565.712 [Default:CheckIn:C.Wait] Running Loop=1
2019-10-03T15:46:05.712Z,1570117565.712 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-10-03T15:46:10.125Z,1570117570.125 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-10-03T15:46:13.744Z,1570117573.744 [NAL9602](INFO): Not Powering down - fast GPS
2019-10-03T15:46:14.577Z,1570117574.577 [BPC1](ERROR): BPC1A: No match for serial number 1717 in BPC1A's battery stick inventory (sticks 1-32 in onboard configuration file).
2019-10-03T15:46:25.496Z,1570117585.496 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-10-03T15:46:40.890Z,1570117600.890 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-10-03T15:46:54.564Z,1570117614.564 [BPC1](ERROR): BPC1A: No match for serial number 1717 in BPC1A's battery stick inventory (sticks 1-32 in onboard configuration file).
2019-10-03T15:46:56.180Z,1570117616.180 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-10-03T15:47:11.127Z,1570117631.127 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-10-03T15:51:06.291Z,1570117866.291 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-10-03T15:51:06.292Z,1570117866.292 [Default:CheckIn:C.Wait] Stopped
2019-10-03T15:51:06.292Z,1570117866.292 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-10-03T15:51:06.292Z,1570117866.292 [Default:CheckIn:D] Running Loop=1
2019-10-03T15:51:06.683Z,1570117866.683 [Default:CheckIn:D] Stopped
2019-10-03T15:51:06.683Z,1570117866.683 [Default:CheckIn:E] Running Loop=1
2019-10-03T15:51:07.092Z,1570117867.092 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 13.690122 min 
2019-10-03T15:51:07.092Z,1570117867.092 [Default:CheckIn:E] Stopped
2019-10-03T15:51:07.092Z,1570117867.092 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-10-03T15:51:07.092Z,1570117867.092 [Default:CheckIn] Stopped
2019-10-03T15:51:07.092Z,1570117867.092 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-10-03T15:51:07.092Z,1570117867.092 [Default:CheckIn](INFO): Running loop #3
2019-10-03T15:51:07.092Z,1570117867.092 [Default:CheckIn] Running Loop=3
2019-10-03T15:51:07.092Z,1570117867.092 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-10-03T15:51:07.092Z,1570117867.092 [Default:CheckIn:Read_GPS] Running Loop=1
2019-10-03T15:51:08.677Z,1570117868.677 [NAL9602](DEBUG): Fix Requested
2019-10-03T15:51:09.074Z,1570117869.074 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155109.00,A,3648.31041,N,12147.14325,W,0.214,351.89,031019,,,D*75
2019-10-03T15:51:09.077Z,1570117869.077 [NAL9602](INFO): GPS fix at 20191003T155109: (36.805174, -121.785721)
2019-10-03T15:51:09.120Z,1570117869.120 [Default:CheckIn:Read_GPS] Stopped
2019-10-03T15:51:09.120Z,1570117869.120 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-10-03T15:51:19.154Z,1570117879.154 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20191003T152027/Courier0031.lzma
2019-10-03T15:51:21.160Z,1570117881.160 [DataOverHttps](INFO): Moved sent file to Logs/20191003T152027/Courier0031.lzma.bak
2019-10-03T15:51:21.161Z,1570117881.161 [DataOverHttps](INFO): SBD MOMSN=11845092
2019-10-03T15:51:32.907Z,1570117892.907 [NAL9602](INFO): SBD MO Status=0, MOMSN=2095, MT Status=0, MTMSN=0
2019-10-03T15:51:32.908Z,1570117892.908 [NAL9602](INFO): No messages in MT queue
2019-10-03T15:51:38.989Z,1570117898.989 [BPC1](INFO): Calculating totals. Valid battery stick count: 55. Valid reserve battery stick count: 5.
2019-10-03T15:51:38.992Z,1570117898.992 [BPC1](ERROR): Failed to receive data from all sticks prior to timeout. Will not retry this scan cycle.
2019-10-03T15:51:42.195Z,1570117902.195 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20191003T152027/Express0032.lzma
2019-10-03T15:51:44.201Z,1570117904.201 [DataOverHttps](INFO): Moved sent file to Logs/20191003T152027/Express0032.lzma.bak
2019-10-03T15:51:44.201Z,1570117904.201 [DataOverHttps](INFO): SBD MOMSN=11845099
2019-10-03T15:51:48.318Z,1570117908.318 [Default:CheckIn:Read_Iridium] Stopped
2019-10-03T15:51:48.319Z,1570117908.319 [Default:CheckIn:C.Wait] Running Loop=1
2019-10-03T15:51:48.319Z,1570117908.319 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-10-03T15:52:03.612Z,1570117923.612 [NAL9602](INFO): Not Powering down - fast GPS
2019-10-03T15:53:19.056Z,1570117999.056 [DataOverHttps](IMPORTANT): SBD MTMSN=20191003T155318
2019-10-03T15:53:26.539Z,1570118006.539 [DataOverHttps](INFO): Received command:Ibit
2019-10-03T15:53:26.619Z,1570118006.619 [CommandLine](IMPORTANT): got command ibit
2019-10-03T15:53:26.901Z,1570118006.901 [IBIT](IMPORTANT): Beginning Initiated BIT
2019-10-03T15:53:26.901Z,1570118006.901 [IBIT](IMPORTANT): Beginning control surface checks.
2019-10-03T15:53:26.904Z,1570118006.904 [CBIT](IMPORTANT): Beginning ground fault scan
2019-10-03T15:53:28.087Z,1570118008.087 [NAL9602](DEBUG): Fix Requested
2019-10-03T15:53:28.478Z,1570118008.478 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155328.00,A,3648.31012,N,12147.14398,W,0.019,351.89,031019,,,D*7B
2019-10-03T15:53:28.480Z,1570118008.480 [NAL9602](INFO): GPS fix at 20191003T155328: (36.805169, -121.785733)
2019-10-03T15:53:37.883Z,1570118017.883 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): -0.004362
CHAN A1 (24V): 0.183640
CHAN A2 (12V): -0.003880
CHAN A3 (5V): -0.001768
CHAN B0 (3.3V): -0.000981
CHAN B1 (3.15aV): -0.000778
CHAN B2 (3.15bV): 0.000299
CHAN B3 (GND): -0.000238
OPEN: 0.004950
Full Scale Calc: 4.765 mA, -1.589 mA
2019-10-03T15:53:41.403Z,1570118021.403 [NAL9602](INFO): SBD MO Status=0, MOMSN=2096, MT Status=0, MTMSN=0
2019-10-03T15:53:41.404Z,1570118021.404 [NAL9602](INFO): No messages in MT queue
2019-10-03T15:53:42.223Z,1570118022.223 [NAL9602](DEBUG): Fix Requested
2019-10-03T15:53:42.616Z,1570118022.616 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155342.00,A,3648.31045,N,12147.14425,W,0.097,351.89,031019,,,D*72
2019-10-03T15:53:42.618Z,1570118022.618 [NAL9602](INFO): GPS fix at 20191003T155342: (36.805174, -121.785737)
2019-10-03T15:53:45.458Z,1570118025.458 [NAL9602](DEBUG): Fix Requested
2019-10-03T15:53:45.854Z,1570118025.854 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155346.00,A,3648.31049,N,12147.14433,W,0.097,351.89,031019,,,D*7D
2019-10-03T15:53:45.856Z,1570118025.856 [NAL9602](INFO): GPS fix at 20191003T155346: (36.805175, -121.785739)
2019-10-03T15:53:48.689Z,1570118028.689 [NAL9602](DEBUG): Fix Requested
2019-10-03T15:53:49.086Z,1570118029.086 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155349.00,A,3648.31049,N,12147.14424,W,0.019,351.89,031019,,,D*72
2019-10-03T15:53:49.088Z,1570118029.088 [NAL9602](INFO): GPS fix at 20191003T155349: (36.805175, -121.785737)
2019-10-03T15:53:51.515Z,1570118031.515 [NAL9602](DEBUG): Fix Requested
2019-10-03T15:53:51.910Z,1570118031.910 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155352.00,A,3648.31055,N,12147.14412,W,0.058,351.89,031019,,,D*75
2019-10-03T15:53:51.913Z,1570118031.913 [NAL9602](INFO): GPS fix at 20191003T155352: (36.805176, -121.785735)
2019-10-03T15:53:54.751Z,1570118034.751 [NAL9602](DEBUG): Fix Requested
2019-10-03T15:53:55.142Z,1570118035.142 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155355.00,A,3648.31058,N,12147.14403,W,0.019,351.89,031019,,,D*7A
2019-10-03T15:53:55.144Z,1570118035.144 [NAL9602](INFO): GPS fix at 20191003T155355: (36.805176, -121.785734)
2019-10-03T15:53:57.579Z,1570118037.579 [NAL9602](DEBUG): Fix Requested
2019-10-03T15:53:57.970Z,1570118037.970 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155358.00,A,3648.31051,N,12147.14403,W,0.058,351.89,031019,,,D*7B
2019-10-03T15:53:57.972Z,1570118037.972 [NAL9602](INFO): GPS fix at 20191003T155358: (36.805175, -121.785734)
2019-10-03T15:54:00.403Z,1570118040.403 [NAL9602](DEBUG): Fix Requested
2019-10-03T15:54:00.806Z,1570118040.806 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155401.00,A,3648.31034,N,12147.14409,W,0.039,351.89,031019,,,D*7E
2019-10-03T15:54:00.808Z,1570118040.808 [NAL9602](INFO): GPS fix at 20191003T155401: (36.805172, -121.785735)
2019-10-03T15:54:03.643Z,1570118043.643 [NAL9602](DEBUG): Fix Requested
2019-10-03T15:54:04.034Z,1570118044.034 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155404.00,A,3648.31021,N,12147.14428,W,0.039,351.89,031019,,,D*7C
2019-10-03T15:54:04.036Z,1570118044.036 [NAL9602](INFO): GPS fix at 20191003T155404: (36.805170, -121.785738)
2019-10-03T15:54:06.463Z,1570118046.463 [NAL9602](DEBUG): Fix Requested
2019-10-03T15:54:06.862Z,1570118046.862 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155407.00,A,3648.31018,N,12147.14439,W,0.019,351.89,031019,,,D*77
2019-10-03T15:54:06.864Z,1570118046.864 [NAL9602](INFO): GPS fix at 20191003T155407: (36.805170, -121.785740)
2019-10-03T15:54:09.712Z,1570118049.712 [NAL9602](DEBUG): Fix Requested
2019-10-03T15:54:10.088Z,1570118050.088 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155410.00,A,3648.31010,N,12147.14454,W,0.078,351.89,031019,,,D*75
2019-10-03T15:54:10.090Z,1570118050.090 [NAL9602](INFO): GPS fix at 20191003T155410: (36.805168, -121.785742)
2019-10-03T15:54:12.527Z,1570118052.527 [NAL9602](DEBUG): Fix Requested
2019-10-03T15:54:12.917Z,1570118052.917 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155413.00,A,3648.31003,N,12147.14469,W,0.058,351.89,031019,,,D*78
2019-10-03T15:54:12.923Z,1570118052.923 [NAL9602](INFO): GPS fix at 20191003T155413: (36.805167, -121.785745)
2019-10-03T15:54:12.970Z,1570118052.970 [IBIT](IMPORTANT): Communications Status:
Fix Status: 1
Iridium Signal Strength: 5
Latitude: 36.805168 Longitude: -121.785744
2019-10-03T15:54:13.372Z,1570118053.372 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 0.000000
Voltage: 0.000000
2019-10-03T15:54:13.373Z,1570118053.373 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah
2019-10-03T15:54:13.373Z,1570118053.373 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V
2019-10-03T15:54:13.765Z,1570118053.765 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2019-10-03T15:54:13.765Z,1570118053.765 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2019-10-03T15:54:13.766Z,1570118053.766 [IBIT](IMPORTANT): Pressure:8.067294 PSI
2019-10-03T15:54:13.766Z,1570118053.766 [IBIT](IMPORTANT): Humidity:10.694665 %
2019-10-03T15:54:14.176Z,1570118054.176 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2019-10-03T15:54:14.177Z,1570118054.177 [IBIT](IMPORTANT): buoyancyNeutral: 237.000000 cc
2019-10-03T15:54:14.177Z,1570118054.177 [IBIT](IMPORTANT): massDefault: 0.460000 cm
2019-10-03T15:54:14.177Z,1570118054.177 [IBIT](IMPORTANT): stopDepth: 215.000000 m
2019-10-03T15:54:14.177Z,1570118054.177 [IBIT](IMPORTANT): abortDepth: 255.000000 m
2019-10-03T15:54:14.177Z,1570118054.177 [IBIT](IMPORTANT): IBIT PASSED
2019-10-03T15:54:45.656Z,1570118085.656 [NAL9602](INFO): Not Powering down - fast GPS
2019-10-03T15:56:48.912Z,1570118208.912 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-10-03T15:56:48.913Z,1570118208.913 [Default:CheckIn:C.Wait] Stopped
2019-10-03T15:56:48.913Z,1570118208.913 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-10-03T15:56:48.913Z,1570118208.913 [Default:CheckIn:D] Running Loop=1
2019-10-03T15:56:49.334Z,1570118209.334 [Default:CheckIn:D] Stopped
2019-10-03T15:56:49.334Z,1570118209.334 [Default:CheckIn:E] Running Loop=1
2019-10-03T15:56:49.738Z,1570118209.738 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 19.400977 min 
2019-10-03T15:56:49.738Z,1570118209.738 [Default:CheckIn:E] Stopped
2019-10-03T15:56:49.738Z,1570118209.738 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-10-03T15:56:49.738Z,1570118209.738 [Default:CheckIn] Stopped
2019-10-03T15:56:49.739Z,1570118209.739 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-10-03T15:56:49.739Z,1570118209.739 [Default:CheckIn](INFO): Running loop #4
2019-10-03T15:56:49.739Z,1570118209.739 [Default:CheckIn] Running Loop=4
2019-10-03T15:56:49.739Z,1570118209.739 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-10-03T15:56:49.739Z,1570118209.739 [Default:CheckIn:Read_GPS] Running Loop=1
2019-10-03T15:56:51.319Z,1570118211.319 [NAL9602](DEBUG): Fix Requested
2019-10-03T15:56:51.712Z,1570118211.712 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155652.00,A,3648.31041,N,12147.14337,W,0.019,351.89,031019,,,D*70
2019-10-03T15:56:51.714Z,1570118211.714 [NAL9602](INFO): GPS fix at 20191003T155652: (36.805174, -121.785723)
2019-10-03T15:56:51.739Z,1570118211.739 [Default:CheckIn:Read_GPS] Stopped
2019-10-03T15:56:51.739Z,1570118211.739 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-10-03T15:57:01.123Z,1570118221.123 [DataOverHttps](INFO): Sending 221 bytes from file Logs/20191003T152027/Courier0034.lzma
2019-10-03T15:57:03.154Z,1570118223.154 [DataOverHttps](INFO): Moved sent file to Logs/20191003T152027/Courier0034.lzma.bak
2019-10-03T15:57:03.154Z,1570118223.154 [DataOverHttps](INFO): SBD MOMSN=11845134
2019-10-03T15:57:19.185Z,1570118239.185 [NAL9602](INFO): SBD MO Status=0, MOMSN=2097, MT Status=0, MTMSN=0
2019-10-03T15:57:19.185Z,1570118239.185 [NAL9602](INFO): No messages in MT queue
2019-10-03T15:57:21.654Z,1570118241.654 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20191003T152027/Courier0037.lzma
2019-10-03T15:57:23.661Z,1570118243.661 [DataOverHttps](INFO): Moved sent file to Logs/20191003T152027/Courier0037.lzma.bak
2019-10-03T15:57:23.661Z,1570118243.661 [DataOverHttps](INFO): SBD MOMSN=11845139
2019-10-03T15:57:44.924Z,1570118264.924 [DataOverHttps](INFO): Sending 724 bytes from file Logs/20191003T152027/Express0035.lzma
2019-10-03T15:57:46.928Z,1570118266.928 [DataOverHttps](INFO): Moved sent file to Logs/20191003T152027/Express0035.lzma.bak
2019-10-03T15:57:46.929Z,1570118266.929 [DataOverHttps](INFO): SBD MOMSN=11845141
2019-10-03T15:57:49.892Z,1570118269.892 [NAL9602](INFO): Not Powering down - fast GPS
2019-10-03T15:58:06.538Z,1570118286.538 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20191003T152027/Express0038.lzma
2019-10-03T15:58:08.563Z,1570118288.563 [DataOverHttps](INFO): Moved sent file to Logs/20191003T152027/Express0038.lzma.bak
2019-10-03T15:58:08.563Z,1570118288.563 [DataOverHttps](INFO): SBD MOMSN=11845166
2019-10-03T15:58:12.152Z,1570118292.152 [Default:CheckIn:Read_Iridium] Stopped
2019-10-03T15:58:12.153Z,1570118292.153 [Default:CheckIn:C.Wait] Running Loop=1
2019-10-03T15:58:12.153Z,1570118292.153 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-10-03T16:03:12.783Z,1570118592.783 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-10-03T16:03:12.783Z,1570118592.783 [Default:CheckIn:C.Wait] Stopped
2019-10-03T16:03:12.783Z,1570118592.783 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-10-03T16:03:12.784Z,1570118592.784 [Default:CheckIn:D] Running Loop=1
2019-10-03T16:03:13.191Z,1570118593.191 [Default:CheckIn:D] Stopped
2019-10-03T16:03:13.191Z,1570118593.191 [Default:CheckIn:E] Running Loop=1
2019-10-03T16:03:13.598Z,1570118593.598 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 25.798590 min 
2019-10-03T16:03:13.598Z,1570118593.598 [Default:CheckIn:E] Stopped
2019-10-03T16:03:13.599Z,1570118593.599 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-10-03T16:03:13.599Z,1570118593.599 [Default:CheckIn] Stopped
2019-10-03T16:03:13.603Z,1570118593.603 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-10-03T16:03:13.603Z,1570118593.603 [Default:CheckIn](INFO): Running loop #5
2019-10-03T16:03:13.603Z,1570118593.603 [Default:CheckIn] Running Loop=5
2019-10-03T16:03:13.603Z,1570118593.603 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-10-03T16:03:13.603Z,1570118593.603 [Default:CheckIn:Read_GPS] Running Loop=1
2019-10-03T16:03:15.179Z,1570118595.179 [NAL9602](DEBUG): Fix Requested
2019-10-03T16:03:15.570Z,1570118595.570 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160315.00,A,3648.31033,N,12147.14516,W,0.117,351.89,031019,,,D*7F
2019-10-03T16:03:15.572Z,1570118595.572 [NAL9602](INFO): GPS fix at 20191003T160315: (36.805172, -121.785753)
2019-10-03T16:03:15.596Z,1570118595.596 [Default:CheckIn:Read_GPS] Stopped
2019-10-03T16:03:15.596Z,1570118595.596 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-10-03T16:03:25.686Z,1570118605.686 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20191003T152027/Courier0040.lzma
2019-10-03T16:03:27.694Z,1570118607.694 [DataOverHttps](INFO): Moved sent file to Logs/20191003T152027/Courier0040.lzma.bak
2019-10-03T16:03:27.694Z,1570118607.694 [DataOverHttps](INFO): SBD MOMSN=11845191
2019-10-03T16:03:28.905Z,1570118608.905 [NAL9602](INFO): SBD MO Status=0, MOMSN=2098, MT Status=0, MTMSN=0
2019-10-03T16:03:28.905Z,1570118608.905 [NAL9602](INFO): No messages in MT queue
2019-10-03T16:03:47.403Z,1570118627.403 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20191003T152027/Express0041.lzma
2019-10-03T16:03:49.433Z,1570118629.433 [DataOverHttps](INFO): Moved sent file to Logs/20191003T152027/Express0041.lzma.bak
2019-10-03T16:03:49.433Z,1570118629.433 [DataOverHttps](INFO): SBD MOMSN=11845197
2019-10-03T16:03:53.204Z,1570118633.204 [Default:CheckIn:Read_Iridium] Stopped
2019-10-03T16:03:53.204Z,1570118633.204 [Default:CheckIn:C.Wait] Running Loop=1
2019-10-03T16:03:53.204Z,1570118633.204 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-10-03T16:03:59.608Z,1570118639.608 [NAL9602](INFO): Not Powering down - fast GPS
2019-10-03T16:08:53.781Z,1570118933.781 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-10-03T16:08:53.781Z,1570118933.781 [Default:CheckIn:C.Wait] Stopped
2019-10-03T16:08:53.781Z,1570118933.781 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-10-03T16:08:53.781Z,1570118933.781 [Default:CheckIn:D] Running Loop=1
2019-10-03T16:08:54.193Z,1570118934.193 [Default:CheckIn:D] Stopped
2019-10-03T16:08:54.193Z,1570118934.193 [Default:CheckIn:E] Running Loop=1
2019-10-03T16:08:54.563Z,1570118934.563 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 31.481950 min 
2019-10-03T16:08:54.563Z,1570118934.563 [Default:CheckIn:E] Stopped
2019-10-03T16:08:54.564Z,1570118934.564 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-10-03T16:08:54.564Z,1570118934.564 [Default:CheckIn] Stopped
2019-10-03T16:08:54.564Z,1570118934.564 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-10-03T16:08:54.564Z,1570118934.564 [Default:CheckIn](INFO): Running loop #6
2019-10-03T16:08:54.564Z,1570118934.564 [Default:CheckIn] Running Loop=6
2019-10-03T16:08:54.564Z,1570118934.564 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-10-03T16:08:54.564Z,1570118934.564 [Default:CheckIn:Read_GPS] Running Loop=1
2019-10-03T16:08:56.155Z,1570118936.155 [NAL9602](DEBUG): Fix Requested
2019-10-03T16:08:56.554Z,1570118936.554 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160856.00,A,3648.30971,N,12147.14476,W,0.311,351.89,031019,,,D*7E
2019-10-03T16:08:56.556Z,1570118936.556 [NAL9602](INFO): GPS fix at 20191003T160856: (36.805162, -121.785746)
2019-10-03T16:08:56.601Z,1570118936.601 [Default:CheckIn:Read_GPS] Stopped
2019-10-03T16:08:56.601Z,1570118936.601 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-10-03T16:09:05.654Z,1570118945.654 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20191003T152027/Courier0043.lzma
2019-10-03T16:09:07.661Z,1570118947.661 [DataOverHttps](INFO): Moved sent file to Logs/20191003T152027/Courier0043.lzma.bak
2019-10-03T16:09:07.661Z,1570118947.661 [DataOverHttps](INFO): SBD MOMSN=11845301
2019-10-03T16:09:26.849Z,1570118966.849 [NAL9602](INFO): SBD MO Status=2, MOMSN=2099, MT Status=2, MTMSN=0
2019-10-03T16:09:26.850Z,1570118966.850 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-10-03T16:09:28.272Z,1570118968.272 [DataOverHttps](INFO): Sending 119 bytes from file Logs/20191003T152027/Express0044.lzma
2019-10-03T16:09:30.213Z,1570118970.213 [DataOverHttps](INFO): Moved sent file to Logs/20191003T152027/Express0044.lzma.bak
2019-10-03T16:09:30.213Z,1570118970.213 [DataOverHttps](INFO): SBD MOMSN=11845306
2019-10-03T16:09:34.162Z,1570118974.162 [Default:CheckIn:Read_Iridium] Stopped
2019-10-03T16:09:34.163Z,1570118974.163 [Default:CheckIn:C.Wait] Running Loop=1
2019-10-03T16:09:34.167Z,1570118974.167 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-10-03T16:09:38.162Z,1570118978.162 [NAL9602](INFO): SBD MO Status=0, MOMSN=2099, MT Status=0, MTMSN=0
2019-10-03T16:09:38.162Z,1570118978.162 [NAL9602](INFO): No messages in MT queue
2019-10-03T16:10:08.864Z,1570119008.864 [NAL9602](INFO): Not Powering down - fast GPS
2019-10-03T16:14:34.803Z,1570119274.803 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-10-03T16:14:34.803Z,1570119274.803 [Default:CheckIn:C.Wait] Stopped
2019-10-03T16:14:34.803Z,1570119274.803 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-10-03T16:14:34.804Z,1570119274.804 [Default:CheckIn:D] Running Loop=1
2019-10-03T16:14:35.185Z,1570119275.185 [Default:CheckIn:D] Stopped
2019-10-03T16:14:35.185Z,1570119275.185 [Default:CheckIn:E] Running Loop=1
2019-10-03T16:14:35.605Z,1570119275.605 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 37.165149 min 
2019-10-03T16:14:35.605Z,1570119275.605 [Default:CheckIn:E] Stopped
2019-10-03T16:14:35.605Z,1570119275.605 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-10-03T16:14:35.605Z,1570119275.605 [Default:CheckIn] Stopped
2019-10-03T16:14:35.605Z,1570119275.605 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-10-03T16:14:35.606Z,1570119275.606 [Default:CheckIn](INFO): Running loop #7
2019-10-03T16:14:35.606Z,1570119275.606 [Default:CheckIn] Running Loop=7
2019-10-03T16:14:35.606Z,1570119275.606 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-10-03T16:14:35.606Z,1570119275.606 [Default:CheckIn:Read_GPS] Running Loop=1
2019-10-03T16:14:37.159Z,1570119277.159 [NAL9602](DEBUG): Fix Requested
2019-10-03T16:14:37.544Z,1570119277.544 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,161437.00,A,3648.34970,N,12147.54083,W,17.222,246.66,031019,,,D*4A
2019-10-03T16:14:37.547Z,1570119277.547 [NAL9602](INFO): GPS fix at 20191003T161437: (36.805828, -121.792347)
2019-10-03T16:14:37.592Z,1570119277.592 [Default:CheckIn:Read_GPS] Stopped
2019-10-03T16:14:37.592Z,1570119277.592 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-10-03T16:14:48.622Z,1570119288.622 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20191003T152027/Courier0046.lzma
2019-10-03T16:14:50.629Z,1570119290.629 [DataOverHttps](INFO): Moved sent file to Logs/20191003T152027/Courier0046.lzma.bak
2019-10-03T16:14:50.629Z,1570119290.629 [DataOverHttps](INFO): SBD MOMSN=11845350
2019-10-03T16:15:05.019Z,1570119305.019 [NAL9602](INFO): SBD MO Status=2, MOMSN=2100, MT Status=2, MTMSN=0
2019-10-03T16:15:05.019Z,1570119305.019 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-10-03T16:15:10.307Z,1570119310.307 [DataOverHttps](INFO): Sending 132 bytes from file Logs/20191003T152027/Express0047.lzma
2019-10-03T16:15:12.313Z,1570119312.313 [DataOverHttps](INFO): Moved sent file to Logs/20191003T152027/Express0047.lzma.bak
2019-10-03T16:15:12.313Z,1570119312.313 [DataOverHttps](INFO): SBD MOMSN=11845357
2019-10-03T16:15:16.375Z,1570119316.375 [Default:CheckIn:Read_Iridium] Stopped
2019-10-03T16:15:16.376Z,1570119316.376 [Default:CheckIn:C.Wait] Running Loop=1
2019-10-03T16:15:16.376Z,1570119316.376 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-10-03T16:15:34.104Z,1570119334.104 [NAL9602](INFO): SBD MO Status=0, MOMSN=2100, MT Status=0, MTMSN=0
2019-10-03T16:15:34.104Z,1570119334.104 [NAL9602](INFO): No messages in MT queue
2019-10-03T16:16:04.805Z,1570119364.805 [NAL9602](INFO): Not Powering down - fast GPS
2019-10-03T16:20:16.987Z,1570119616.987 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-10-03T16:20:16.988Z,1570119616.988 [Default:CheckIn:C.Wait] Stopped
2019-10-03T16:20:16.988Z,1570119616.988 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-10-03T16:20:16.988Z,1570119616.988 [Default:CheckIn:D] Running Loop=1
2019-10-03T16:20:17.370Z,1570119617.370 [Default:CheckIn:D] Stopped
2019-10-03T16:20:17.370Z,1570119617.370 [Default:CheckIn:E] Running Loop=1
2019-10-03T16:20:17.763Z,1570119617.763 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 42.868241 min 
2019-10-03T16:20:17.763Z,1570119617.763 [Default:CheckIn:E] Stopped
2019-10-03T16:20:17.764Z,1570119617.764 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-10-03T16:20:17.764Z,1570119617.764 [Default:CheckIn] Stopped
2019-10-03T16:20:17.764Z,1570119617.764 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-10-03T16:20:17.764Z,1570119617.764 [Default:CheckIn](INFO): Running loop #8
2019-10-03T16:20:17.764Z,1570119617.764 [Default:CheckIn] Running Loop=8
2019-10-03T16:20:17.764Z,1570119617.764 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-10-03T16:20:17.764Z,1570119617.764 [Default:CheckIn:Read_GPS] Running Loop=1
2019-10-03T16:20:19.343Z,1570119619.343 [NAL9602](DEBUG): Fix Requested
2019-10-03T16:20:19.746Z,1570119619.746 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162020.00,A,3648.37053,N,12149.73190,W,18.505,269.96,031019,,,A*42
2019-10-03T16:20:19.748Z,1570119619.748 [NAL9602](INFO): GPS fix at 20191003T162020: (36.806176, -121.828865)
2019-10-03T16:20:19.772Z,1570119619.772 [Default:CheckIn:Read_GPS] Stopped
2019-10-03T16:20:19.772Z,1570119619.772 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-10-03T16:20:21.764Z,1570119621.764 [NAL9602](ERROR): parseGSV uart error: serial buffer full
2019-10-03T16:20:30.666Z,1570119630.666 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20191003T152027/Courier0049.lzma
2019-10-03T16:20:32.672Z,1570119632.672 [DataOverHttps](INFO): Moved sent file to Logs/20191003T152027/Courier0049.lzma.bak
2019-10-03T16:20:32.673Z,1570119632.673 [DataOverHttps](INFO): SBD MOMSN=11845379
2019-10-03T16:20:33.893Z,1570119633.893 [NAL9602](INFO): SBD MO Status=0, MOMSN=2101, MT Status=0, MTMSN=0
2019-10-03T16:20:33.894Z,1570119633.894 [NAL9602](INFO): No messages in MT queue
2019-10-03T16:20:52.425Z,1570119652.425 [DataOverHttps](INFO): Sending 132 bytes from file Logs/20191003T152027/Express0050.lzma
2019-10-03T16:20:54.429Z,1570119654.429 [DataOverHttps](INFO): Moved sent file to Logs/20191003T152027/Express0050.lzma.bak
2019-10-03T16:20:54.430Z,1570119654.430 [DataOverHttps](INFO): SBD MOMSN=11845384
2019-10-03T16:20:58.195Z,1570119658.195 [Default:CheckIn:Read_Iridium] Stopped
2019-10-03T16:20:58.195Z,1570119658.195 [Default:CheckIn:C.Wait] Running Loop=1
2019-10-03T16:20:58.195Z,1570119658.195 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-10-03T16:21:04.596Z,1570119664.596 [NAL9602](INFO): Not Powering down - fast GPS
2019-10-03T16:25:58.775Z,1570119958.775 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-10-03T16:25:58.775Z,1570119958.775 [Default:CheckIn:C.Wait] Stopped
2019-10-03T16:25:58.775Z,1570119958.775 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-10-03T16:25:58.775Z,1570119958.775 [Default:CheckIn:D] Running Loop=1
2019-10-03T16:25:59.156Z,1570119959.156 [Default:CheckIn:D] Stopped
2019-10-03T16:25:59.156Z,1570119959.156 [Default:CheckIn:E] Running Loop=1
2019-10-03T16:25:59.599Z,1570119959.599 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 48.564665 min 
2019-10-03T16:25:59.599Z,1570119959.599 [Default:CheckIn:E] Stopped
2019-10-03T16:25:59.599Z,1570119959.599 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-10-03T16:25:59.599Z,1570119959.599 [Default:CheckIn] Stopped
2019-10-03T16:25:59.600Z,1570119959.600 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-10-03T16:25:59.600Z,1570119959.600 [Default:CheckIn](INFO): Running loop #9
2019-10-03T16:25:59.600Z,1570119959.600 [Default:CheckIn] Running Loop=9
2019-10-03T16:25:59.600Z,1570119959.600 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-10-03T16:25:59.600Z,1570119959.600 [Default:CheckIn:Read_GPS] Running Loop=1
2019-10-03T16:26:01.167Z,1570119961.167 [NAL9602](DEBUG): Fix Requested
2019-10-03T16:26:01.568Z,1570119961.568 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162601.00,A,3648.04429,N,12151.96184,W,20.158,255.80,031019,,,A*46
2019-10-03T16:26:01.570Z,1570119961.570 [NAL9602](INFO): GPS fix at 20191003T162601: (36.800738, -121.866031)
2019-10-03T16:26:01.594Z,1570119961.594 [Default:CheckIn:Read_GPS] Stopped
2019-10-03T16:26:01.594Z,1570119961.594 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-10-03T16:26:02.782Z,1570119962.782 [NAL9602](ERROR): parseGSV uart error: serial buffer full
2019-10-03T16:26:15.023Z,1570119975.023 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20191003T152027/Courier0052.lzma
2019-10-03T16:26:17.041Z,1570119977.041 [DataOverHttps](INFO): Moved sent file to Logs/20191003T152027/Courier0052.lzma.bak
2019-10-03T16:26:17.041Z,1570119977.041 [DataOverHttps](INFO): SBD MOMSN=11845473
2019-10-03T16:26:22.192Z,1570119982.192 [NAL9602](INFO): SBD MO Status=0, MOMSN=2102, MT Status=0, MTMSN=0
2019-10-03T16:26:22.192Z,1570119982.192 [NAL9602](INFO): No messages in MT queue
2019-10-03T16:26:36.838Z,1570119996.838 [DataOverHttps](INFO): Sending 135 bytes from file Logs/20191003T152027/Express0053.lzma
2019-10-03T16:26:38.845Z,1570119998.845 [DataOverHttps](INFO): Moved sent file to Logs/20191003T152027/Express0053.lzma.bak
2019-10-03T16:26:38.845Z,1570119998.845 [DataOverHttps](INFO): SBD MOMSN=11845476
2019-10-03T16:26:42.835Z,1570120002.835 [Default:CheckIn:Read_Iridium] Stopped
2019-10-03T16:26:42.835Z,1570120002.835 [Default:CheckIn:C.Wait] Running Loop=1
2019-10-03T16:26:42.835Z,1570120002.835 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-10-03T16:26:52.881Z,1570120012.881 [NAL9602](INFO): Not Powering down - fast GPS
2019-10-03T16:31:43.390Z,1570120303.390 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-10-03T16:31:43.390Z,1570120303.390 [Default:CheckIn:C.Wait] Stopped
2019-10-03T16:31:43.390Z,1570120303.390 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-10-03T16:31:43.391Z,1570120303.391 [Default:CheckIn:D] Running Loop=1
2019-10-03T16:31:43.800Z,1570120303.800 [Default:CheckIn:D] Stopped
2019-10-03T16:31:43.800Z,1570120303.800 [Default:CheckIn:E] Running Loop=1
2019-10-03T16:31:44.196Z,1570120304.196 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 54.308740 min 
2019-10-03T16:31:44.196Z,1570120304.196 [Default:CheckIn:E] Stopped
2019-10-03T16:31:44.196Z,1570120304.196 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-10-03T16:31:44.196Z,1570120304.196 [Default:CheckIn] Stopped
2019-10-03T16:31:44.196Z,1570120304.196 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-10-03T16:31:44.196Z,1570120304.196 [Default:CheckIn](INFO): Running loop #10
2019-10-03T16:31:44.197Z,1570120304.197 [Default:CheckIn] Running Loop=10
2019-10-03T16:31:44.197Z,1570120304.197 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-10-03T16:31:44.197Z,1570120304.197 [Default:CheckIn:Read_GPS] Running Loop=1
2019-10-03T16:31:45.795Z,1570120305.795 [NAL9602](DEBUG): Fix Requested
2019-10-03T16:31:46.194Z,1570120306.194 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163146.00,A,3647.64380,N,12154.14207,W,16.251,256.12,031019,,,D*4B
2019-10-03T16:31:46.196Z,1570120306.196 [NAL9602](INFO): GPS fix at 20191003T163146: (36.794063, -121.902368)
2019-10-03T16:31:46.221Z,1570120306.221 [Default:CheckIn:Read_GPS] Stopped
2019-10-03T16:31:46.221Z,1570120306.221 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-10-03T16:31:47.812Z,1570120307.812 [NAL9602](ERROR): parseGSV uart error: serial buffer full
2019-10-03T16:31:48.554Z,1570120308.554 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20191003T152027/Courier0055.lzma
2019-10-03T16:31:50.564Z,1570120310.564 [DataOverHttps](INFO): Moved sent file to Logs/20191003T152027/Courier0055.lzma.bak
2019-10-03T16:31:50.565Z,1570120310.565 [DataOverHttps](INFO): SBD MOMSN=11845520
2019-10-03T16:32:12.991Z,1570120332.991 [DataOverHttps](INFO): Sending 135 bytes from file Logs/20191003T152027/Express0056.lzma
2019-10-03T16:32:16.001Z,1570120336.001 [DataOverHttps](INFO): Moved sent file to Logs/20191003T152027/Express0056.lzma.bak
2019-10-03T16:32:16.001Z,1570120336.001 [DataOverHttps](INFO): SBD MOMSN=11845523
2019-10-03T16:32:19.772Z,1570120339.772 [Default:CheckIn:Read_Iridium] Stopped
2019-10-03T16:32:19.772Z,1570120339.772 [Default:CheckIn:C.Wait] Running Loop=1
2019-10-03T16:32:19.772Z,1570120339.772 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-10-03T16:33:07.806Z,1570120387.806 [NAL9602](INFO): SBD MO Status=0, MOMSN=2103, MT Status=0, MTMSN=0
2019-10-03T16:33:07.806Z,1570120387.806 [NAL9602](INFO): No messages in MT queue
2019-10-03T16:33:38.500Z,1570120418.500 [NAL9602](INFO): Not Powering down - fast GPS
2019-10-03T16:35:33.112Z,1570120533.112 [DataOverHttps](INFO): Exceeded connection timeout, disconnecting.
2019-10-03T16:35:42.644Z,1570120542.644 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=63.227917
2019-10-03T16:36:21.319Z,1570120581.319 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003316
2019-10-03T16:37:20.359Z,1570120640.359 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-10-03T16:37:20.359Z,1570120640.359 [Default:CheckIn:C.Wait] Stopped
2019-10-03T16:37:20.359Z,1570120640.359 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-10-03T16:37:20.359Z,1570120640.359 [Default:CheckIn:D] Running Loop=1
2019-10-03T16:37:20.745Z,1570120640.745 [Default:CheckIn:D] Stopped
2019-10-03T16:37:20.745Z,1570120640.745 [Default:CheckIn:E] Running Loop=1
2019-10-03T16:37:21.155Z,1570120641.155 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 59.924483 min 
2019-10-03T16:37:21.155Z,1570120641.155 [Default:CheckIn:E] Stopped
2019-10-03T16:37:21.156Z,1570120641.156 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-10-03T16:37:21.156Z,1570120641.156 [Default:CheckIn] Stopped
2019-10-03T16:37:21.156Z,1570120641.156 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-10-03T16:37:21.156Z,1570120641.156 [Default:CheckIn](INFO): Running loop #11
2019-10-03T16:37:21.156Z,1570120641.156 [Default:CheckIn] Running Loop=11
2019-10-03T16:37:21.156Z,1570120641.156 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-10-03T16:37:21.156Z,1570120641.156 [Default:CheckIn:Read_GPS] Running Loop=1
2019-10-03T16:37:22.750Z,1570120642.750 [NAL9602](DEBUG): Fix Requested
2019-10-03T16:37:23.146Z,1570120643.146 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163723.00,A,3647.16874,N,12156.17494,W,18.797,253.04,031019,,,A*40
2019-10-03T16:37:23.148Z,1570120643.148 [NAL9602](INFO): GPS fix at 20191003T163723: (36.786146, -121.936249)
2019-10-03T16:37:23.190Z,1570120643.190 [Default:CheckIn:Read_GPS] Stopped
2019-10-03T16:37:23.190Z,1570120643.190 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-10-03T16:37:24.764Z,1570120644.764 [NAL9602](ERROR): parseGSV uart error: serial buffer full
2019-10-03T16:37:32.292Z,1570120652.292 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20191003T152027/Courier0058.lzma
2019-10-03T16:37:34.297Z,1570120654.297 [DataOverHttps](INFO): Moved sent file to Logs/20191003T152027/Courier0058.lzma.bak
2019-10-03T16:37:34.297Z,1570120654.297 [DataOverHttps](INFO): SBD MOMSN=11845544
2019-10-03T16:37:45.770Z,1570120665.770 [NAL9602](INFO): SBD MO Status=0, MOMSN=2104, MT Status=0, MTMSN=0
2019-10-03T16:37:45.770Z,1570120665.770 [NAL9602](INFO): No messages in MT queue
2019-10-03T16:37:57.219Z,1570120677.219 [DataOverHttps](INFO): Sending 135 bytes from file Logs/20191003T152027/Express0059.lzma
2019-10-03T16:37:59.225Z,1570120679.225 [DataOverHttps](INFO): Moved sent file to Logs/20191003T152027/Express0059.lzma.bak
2019-10-03T16:37:59.225Z,1570120679.225 [DataOverHttps](INFO): SBD MOMSN=11845549
2019-10-03T16:38:03.182Z,1570120683.182 [Default:CheckIn:Read_Iridium] Stopped
2019-10-03T16:38:03.182Z,1570120683.182 [Default:CheckIn:C.Wait] Running Loop=1
2019-10-03T16:38:03.182Z,1570120683.182 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-10-03T16:38:16.472Z,1570120696.472 [NAL9602](INFO): Not Powering down - fast GPS
2019-10-03T16:38:33.775Z,1570120713.775 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-10-03T16:38:59.880Z,1570120739.880 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.655773
2019-10-03T16:40:15.624Z,1570120815.624 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-10-03T16:40:50.771Z,1570120850.771 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-10-03T16:41:25.911Z,1570120885.911 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-10-03T16:42:01.476Z,1570120921.476 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003830
2019-10-03T16:42:36.611Z,1570120956.611 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-10-03T16:43:01.724Z,1570120981.724 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.251671
2019-10-03T16:43:03.758Z,1570120983.758 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-10-03T16:43:03.758Z,1570120983.758 [Default:CheckIn:C.Wait] Stopped
2019-10-03T16:43:03.758Z,1570120983.758 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-10-03T16:43:03.759Z,1570120983.759 [Default:CheckIn:D] Running Loop=1
2019-10-03T16:43:04.150Z,1570120984.150 [Default:CheckIn:D] Stopped
2019-10-03T16:43:04.150Z,1570120984.150 [Default:CheckIn:E] Running Loop=1
2019-10-03T16:43:04.548Z,1570120984.548 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 65.647913 min 
2019-10-03T16:43:04.549Z,1570120984.549 [Default:CheckIn:E] Stopped
2019-10-03T16:43:04.549Z,1570120984.549 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-10-03T16:43:04.549Z,1570120984.549 [Default:CheckIn] Stopped
2019-10-03T16:43:04.549Z,1570120984.549 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-10-03T16:43:04.549Z,1570120984.549 [Default:CheckIn](INFO): Running loop #12
2019-10-03T16:43:04.549Z,1570120984.549 [Default:CheckIn] Running Loop=12
2019-10-03T16:43:04.549Z,1570120984.549 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-10-03T16:43:04.549Z,1570120984.549 [Default:CheckIn:Read_GPS] Running Loop=1
2019-10-03T16:43:06.157Z,1570120986.157 [NAL9602](DEBUG): Fix Requested
2019-10-03T16:43:06.546Z,1570120986.546 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164306.00,A,3646.63859,N,12158.18212,W,18.175,241.99,031019,,,A*4C
2019-10-03T16:43:06.548Z,1570120986.548 [NAL9602](INFO): GPS fix at 20191003T164306: (36.777310, -121.969702)
2019-10-03T16:43:06.593Z,1570120986.593 [Default:CheckIn:Read_GPS] Stopped
2019-10-03T16:43:06.593Z,1570120986.593 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-10-03T16:43:07.764Z,1570120987.764 [NAL9602](ERROR): parseGSV uart error: serial buffer full
2019-10-03T16:43:30.157Z,1570121010.157 [NAL9602](INFO): SBD MO Status=1, MOMSN=2105, MT Status=0, MTMSN=0
2019-10-03T16:43:30.205Z,1570121010.205 [NAL9602](INFO): Sent 63 bytes from file Logs/20191003T152027/Courier0061.lzma
2019-10-03T16:43:30.205Z,1570121010.205 [NAL9602](INFO): Packets left to send: 0
2019-10-03T16:43:41.546Z,1570121021.546 [NAL9602](INFO): SBD MO Status=1, MOMSN=2106, MT Status=0, MTMSN=0
2019-10-03T16:43:41.603Z,1570121021.603 [NAL9602](INFO): Sent 136 bytes from file Logs/20191003T152027/Express0062.lzma
2019-10-03T16:43:41.603Z,1570121021.603 [NAL9602](INFO): Packets left to send: 0
2019-10-03T16:43:46.942Z,1570121026.942 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-10-03T16:44:07.465Z,1570121047.465 [NAL9602](INFO): SBD MO Status=0, MOMSN=2107, MT Status=0, MTMSN=0
2019-10-03T16:44:07.563Z,1570121047.563 [Default:CheckIn:Read_Iridium] Stopped
2019-10-03T16:44:07.563Z,1570121047.563 [Default:CheckIn:C.Wait] Running Loop=1
2019-10-03T16:44:07.564Z,1570121047.564 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-10-03T16:44:22.079Z,1570121062.079 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-10-03T16:44:38.162Z,1570121078.162 [NAL9602](INFO): Not Powering down - fast GPS
2019-10-03T16:44:57.219Z,1570121097.219 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-10-03T16:45:32.373Z,1570121132.373 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-10-03T16:46:07.511Z,1570121167.511 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-10-03T16:46:42.663Z,1570121202.663 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-10-03T16:47:17.815Z,1570121237.815 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-10-03T16:47:52.967Z,1570121272.967 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-10-03T16:48:28.107Z,1570121308.107 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-10-03T16:49:03.247Z,1570121343.247 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-10-03T16:49:08.075Z,1570121348.075 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-10-03T16:49:08.075Z,1570121348.075 [Default:CheckIn:C.Wait] Stopped
2019-10-03T16:49:08.075Z,1570121348.075 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-10-03T16:49:08.076Z,1570121348.076 [Default:CheckIn:D] Running Loop=1
2019-10-03T16:49:08.466Z,1570121348.466 [Default:CheckIn:D] Stopped
2019-10-03T16:49:08.466Z,1570121348.466 [Default:CheckIn:E] Running Loop=1
2019-10-03T16:49:08.877Z,1570121348.877 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 71.719832 min 
2019-10-03T16:49:08.877Z,1570121348.877 [Default:CheckIn:E] Stopped
2019-10-03T16:49:08.877Z,1570121348.877 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-10-03T16:49:08.877Z,1570121348.877 [Default:CheckIn] Stopped
2019-10-03T16:49:08.877Z,1570121348.877 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-10-03T16:49:08.877Z,1570121348.877 [Default:CheckIn](INFO): Running loop #13
2019-10-03T16:49:08.877Z,1570121348.877 [Default:CheckIn] Running Loop=13
2019-10-03T16:49:08.877Z,1570121348.877 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-10-03T16:49:08.878Z,1570121348.878 [Default:CheckIn:Read_GPS] Running Loop=1
2019-10-03T16:49:10.479Z,1570121350.479 [NAL9602](DEBUG): Fix Requested
2019-10-03T16:49:10.868Z,1570121350.868 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164911.00,A,3646.52696,N,12158.41737,W,1.127,118.98,031019,,,A*70
2019-10-03T16:49:10.870Z,1570121350.870 [NAL9602](INFO): GPS fix at 20191003T164911: (36.775449, -121.973623)
2019-10-03T16:49:10.911Z,1570121350.911 [Default:CheckIn:Read_GPS] Stopped
2019-10-03T16:49:10.911Z,1570121350.911 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-10-03T16:49:12.900Z,1570121352.900 [NAL9602](ERROR): parseGSV uart error: serial buffer full
2019-10-03T16:49:36.930Z,1570121376.930 [NAL9602](INFO): SBD MO Status=1, MOMSN=2108, MT Status=0, MTMSN=0
2019-10-03T16:49:36.983Z,1570121376.983 [NAL9602](INFO): Sent 62 bytes from file Logs/20191003T152027/Courier0064.lzma
2019-10-03T16:49:36.983Z,1570121376.983 [NAL9602](INFO): Packets left to send: 0
2019-10-03T16:49:38.387Z,1570121378.387 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-10-03T16:49:49.468Z,1570121389.468 [NAL9602](INFO): SBD MO Status=1, MOMSN=2109, MT Status=0, MTMSN=0
2019-10-03T16:49:49.515Z,1570121389.515 [NAL9602](INFO): Sent 120 bytes from file Logs/20191003T152027/Express0065.lzma
2019-10-03T16:49:49.515Z,1570121389.515 [NAL9602](INFO): Packets left to send: 0
2019-10-03T16:50:00.684Z,1570121400.684 [NAL9602](INFO): SBD MO Status=0, MOMSN=2110, MT Status=0, MTMSN=0
2019-10-03T16:50:00.783Z,1570121400.783 [Default:CheckIn:Read_Iridium] Stopped
2019-10-03T16:50:00.783Z,1570121400.783 [Default:CheckIn:C.Wait] Running Loop=1
2019-10-03T16:50:00.783Z,1570121400.783 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-10-03T16:50:09.198Z,1570121409.198 [ElevatorOffsetCalculator](INFO): New estimator for commanded vars: speed 1.00 m/s, pitch 30.00 deg, mass-position -32.00 mm (1 active estimators).
2019-10-03T16:50:13.540Z,1570121413.540 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-10-03T16:50:31.480Z,1570121431.480 [NAL9602](INFO): Not Powering down - fast GPS
2019-10-03T16:50:48.679Z,1570121448.679 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-10-03T16:51:23.819Z,1570121483.819 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-10-03T16:51:58.963Z,1570121518.963 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-10-03T16:52:34.103Z,1570121554.103 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-10-03T16:53:09.287Z,1570121589.287 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-10-03T16:53:44.443Z,1570121624.443 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-10-03T16:54:19.583Z,1570121659.583 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-10-03T16:54:54.739Z,1570121694.739 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-10-03T16:55:01.375Z,1570121701.375 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-10-03T16:55:01.375Z,1570121701.375 [Default:CheckIn:C.Wait] Stopped
2019-10-03T16:55:01.375Z,1570121701.375 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-10-03T16:55:01.375Z,1570121701.375 [Default:CheckIn:D] Running Loop=1
2019-10-03T16:55:01.865Z,1570121701.865 [Default:CheckIn:D] Stopped
2019-10-03T16:55:01.865Z,1570121701.865 [Default:CheckIn:E] Running Loop=1
2019-10-03T16:55:02.203Z,1570121702.203 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 77.609814 min 
2019-10-03T16:55:02.203Z,1570121702.203 [Default:CheckIn:E] Stopped
2019-10-03T16:55:02.203Z,1570121702.203 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-10-03T16:55:02.203Z,1570121702.203 [Default:CheckIn] Stopped
2019-10-03T16:55:02.203Z,1570121702.203 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-10-03T16:55:02.204Z,1570121702.204 [Default:CheckIn](INFO): Running loop #14
2019-10-03T16:55:02.204Z,1570121702.204 [Default:CheckIn] Running Loop=14
2019-10-03T16:55:02.204Z,1570121702.204 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-10-03T16:55:02.204Z,1570121702.204 [Default:CheckIn:Read_GPS] Running Loop=1
2019-10-03T16:55:03.791Z,1570121703.791 [NAL9602](DEBUG): Fix Requested
2019-10-03T16:55:04.180Z,1570121704.180 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165504.00,A,3646.49522,N,12158.36039,W,1.147,137.52,031019,,,D*7E
2019-10-03T16:55:04.182Z,1570121704.182 [NAL9602](INFO): GPS fix at 20191003T165504: (36.774920, -121.972673)
2019-10-03T16:55:04.234Z,1570121704.234 [Default:CheckIn:Read_GPS] Stopped
2019-10-03T16:55:04.234Z,1570121704.234 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-10-03T16:55:21.773Z,1570121721.773 [NAL9602](IMPORTANT): SBD MO Status=1, MOMSN=2111, MT Status=1, MTMSN=36
2019-10-03T16:55:21.835Z,1570121721.835 [NAL9602](INFO): Sent 61 bytes from file Logs/20191003T152027/Courier0067.lzma
2019-10-03T16:55:21.835Z,1570121721.835 [NAL9602](INFO): Packets left to send: 0