2020-07-17T20:32:09.206Z,1595017929.206 [Supervisor](DEBUG): Initializing supervisor.
2020-07-17T20:32:09.208Z,1595017929.208 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2020-07-17T20:32:09.209Z,1595017929.209 [SyncHandler](INFO): Protected caller Thread ID is 2391
2020-07-17T20:32:09.209Z,1595017929.209 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2020-07-17T20:32:09.210Z,1595017929.210 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2020-07-17T20:32:09.211Z,1595017929.211 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 2392
2020-07-17T20:32:09.213Z,1595017929.213 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2020-07-17T20:32:09.226Z,1595017929.226 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2020-07-17T20:32:09.227Z,1595017929.227 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2020-07-17T20:32:09.228Z,1595017929.228 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 2393
2020-07-17T20:32:09.228Z,1595017929.228 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2020-07-17T20:32:09.229Z,1595017929.229 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2020-07-17T20:32:09.230Z,1595017929.230 [logger ThreadHandler](INFO): Protected caller Thread ID is 2394
2020-07-17T20:32:09.232Z,1595017929.232 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2020-07-17T20:32:09.232Z,1595017929.232 [Supervisor](INFO): Looking for Config files in directory: Config/
2020-07-17T20:32:09.234Z,1595017929.234 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2020-07-17T20:32:09.538Z,1595017929.538 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2020-07-17T20:32:09.539Z,1595017929.539 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2020-07-17T20:32:10.110Z,1595017930.110 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2020-07-17T20:32:10.111Z,1595017930.111 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2020-07-17T20:32:10.245Z,1595017930.245 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2020-07-17T20:32:10.246Z,1595017930.246 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2020-07-17T20:32:10.684Z,1595017930.684 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2020-07-17T20:32:10.685Z,1595017930.685 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2020-07-17T20:32:10.779Z,1595017930.779 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2020-07-17T20:32:10.780Z,1595017930.780 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2020-07-17T20:32:10.858Z,1595017930.858 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2020-07-17T20:32:11.145Z,1595017931.145 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2020-07-17T20:32:11.145Z,1595017931.145 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2020-07-17T20:32:11.287Z,1595017931.287 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2020-07-17T20:32:11.287Z,1595017931.287 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2020-07-17T20:32:11.387Z,1595017931.387 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2020-07-17T20:32:11.388Z,1595017931.388 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2020-07-17T20:32:11.580Z,1595017931.580 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2020-07-17T20:32:11.581Z,1595017931.581 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2020-07-17T20:32:12.045Z,1595017932.045 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2020-07-17T20:32:12.046Z,1595017932.046 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2020-07-17T20:32:12.454Z,1595017932.454 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2020-07-17T20:32:12.455Z,1595017932.455 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2020-07-17T20:32:12.583Z,1595017932.583 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2020-07-17T20:32:12.584Z,1595017932.584 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2020-07-17T20:32:12.804Z,1595017932.804 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2020-07-17T20:32:12.805Z,1595017932.805 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2020-07-17T20:32:13.004Z,1595017933.004 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2020-07-17T20:32:13.005Z,1595017933.005 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2020-07-17T20:32:13.222Z,1595017933.222 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2020-07-17T20:32:13.224Z,1595017933.224 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-brizo/
2020-07-17T20:32:13.224Z,1595017933.224 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Control.cfg
2020-07-17T20:32:13.316Z,1595017933.316 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Sensor.cfg
2020-07-17T20:32:13.451Z,1595017933.451 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Simulator.cfg
2020-07-17T20:32:13.533Z,1595017933.533 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/secure.cfg
2020-07-17T20:32:13.614Z,1595017933.614 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Servo.cfg
2020-07-17T20:32:13.717Z,1595017933.717 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/vehicle.cfg
2020-07-17T20:32:13.940Z,1595017933.940 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Battery.cfg
2020-07-17T20:32:14.324Z,1595017934.324 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2020-07-17T20:32:14.324Z,1595017934.324 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Science.cfg
2020-07-17T20:32:14.521Z,1595017934.521 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/logger.cfg
2020-07-17T20:32:14.704Z,1595017934.704 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/BIT.cfg
2020-07-17T20:32:15.205Z,1595017935.205 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Navigation.cfg
2020-07-17T20:32:15.467Z,1595017935.467 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-brizo/root/
2020-07-17T20:32:15.467Z,1595017935.467 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2020-07-17T20:32:15.472Z,1595017935.472 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2020-07-17T20:32:15.676Z,1595017935.676 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2020-07-17T20:32:15.677Z,1595017935.677 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2020-07-17T20:32:15.708Z,1595017935.708 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2020-07-17T20:32:15.708Z,1595017935.708 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2020-07-17T20:32:15.768Z,1595017935.768 [DepthRateCalculator] Loaded
2020-07-17T20:32:15.769Z,1595017935.769 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2020-07-17T20:32:15.774Z,1595017935.774 [PitchRateCalculator] Loaded
2020-07-17T20:32:15.775Z,1595017935.775 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2020-07-17T20:32:15.806Z,1595017935.806 [SpeedCalculator] Loaded
2020-07-17T20:32:15.807Z,1595017935.807 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2020-07-17T20:32:15.855Z,1595017935.855 [TempGradientCalculator] Loaded
2020-07-17T20:32:15.856Z,1595017935.856 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2020-07-17T20:32:15.868Z,1595017935.868 [YawRateCalculator] Loaded
2020-07-17T20:32:15.869Z,1595017935.869 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2020-07-17T20:32:15.956Z,1595017935.956 [ElevatorOffsetCalculator] Loaded
2020-07-17T20:32:15.956Z,1595017935.956 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2020-07-17T20:32:15.957Z,1595017935.957 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2020-07-17T20:32:15.959Z,1595017935.959 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2020-07-17T20:32:16.056Z,1595017936.056 [VerticalControl](DEBUG): Construct VerticalControl.
2020-07-17T20:32:16.276Z,1595017936.276 [VerticalControl] Loaded
2020-07-17T20:32:16.277Z,1595017936.277 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2020-07-17T20:32:16.278Z,1595017936.278 [HorizontalControl](DEBUG): Construct HorizontalControl.
2020-07-17T20:32:16.440Z,1595017936.440 [HorizontalControl] Loaded
2020-07-17T20:32:16.441Z,1595017936.441 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2020-07-17T20:32:16.442Z,1595017936.442 [SpeedControl](DEBUG): Construct SpeedControl.
2020-07-17T20:32:16.453Z,1595017936.453 [SpeedControl] Loaded
2020-07-17T20:32:16.454Z,1595017936.454 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2020-07-17T20:32:16.456Z,1595017936.456 [LoopControl](DEBUG): Construct LoopControl.
2020-07-17T20:32:16.457Z,1595017936.457 [LoopControl] Loaded
2020-07-17T20:32:16.457Z,1595017936.457 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2020-07-17T20:32:16.458Z,1595017936.458 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2020-07-17T20:32:16.459Z,1595017936.459 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2020-07-17T20:32:16.709Z,1595017936.709 [DeadReckonUsingMultipleVelocitySources] Loaded
2020-07-17T20:32:16.710Z,1595017936.710 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2020-07-17T20:32:16.753Z,1595017936.753 [NavChart] Loaded
2020-07-17T20:32:16.754Z,1595017936.754 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2020-07-17T20:32:16.764Z,1595017936.764 [UniversalFixResidualReporter] Loaded
2020-07-17T20:32:16.764Z,1595017936.764 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2020-07-17T20:32:16.765Z,1595017936.765 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2020-07-17T20:32:16.766Z,1595017936.766 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2020-07-17T20:32:16.928Z,1595017936.928 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2020-07-17T20:32:16.929Z,1595017936.929 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2020-07-17T20:32:17.252Z,1595017937.252 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_orientation
2020-07-17T20:32:17.257Z,1595017937.257 [AHRS_M2](INFO): created writer for : platform_orientation
2020-07-17T20:32:17.258Z,1595017937.258 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_magnetic_orientation
2020-07-17T20:32:17.263Z,1595017937.263 [AHRS_M2](INFO): created writer for : platform_magnetic_orientation
2020-07-17T20:32:17.264Z,1595017937.264 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_pitch_angle
2020-07-17T20:32:17.269Z,1595017937.269 [AHRS_M2](INFO): created writer for : platform_pitch_angle
2020-07-17T20:32:17.269Z,1595017937.269 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_roll_angle
2020-07-17T20:32:17.274Z,1595017937.274 [AHRS_M2](INFO): created writer for : platform_roll_angle
2020-07-17T20:32:17.344Z,1595017937.344 [AHRS_M2] Loaded
2020-07-17T20:32:17.344Z,1595017937.344 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2020-07-17T20:32:17.422Z,1595017937.422 [DataOverHttps] Loaded
2020-07-17T20:32:17.422Z,1595017937.422 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2020-07-17T20:32:17.423Z,1595017937.423 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 408564E0
2020-07-17T20:32:17.424Z,1595017937.424 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 2477
2020-07-17T20:32:17.453Z,1595017937.453 [Depth_Keller] Loaded
2020-07-17T20:32:17.454Z,1595017937.454 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2020-07-17T20:32:17.458Z,1595017937.458 [DropWeight] Loaded
2020-07-17T20:32:17.458Z,1595017937.458 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2020-07-17T20:32:17.520Z,1595017937.520 [DVL_micro] Loaded
2020-07-17T20:32:17.520Z,1595017937.520 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread.
2020-07-17T20:32:17.632Z,1595017937.632 [NAL9602] Loaded
2020-07-17T20:32:17.632Z,1595017937.632 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2020-07-17T20:32:17.680Z,1595017937.680 [Onboard] Loaded
2020-07-17T20:32:17.680Z,1595017937.680 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2020-07-17T20:32:17.681Z,1595017937.681 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 408864E0
2020-07-17T20:32:17.681Z,1595017937.681 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 2478
2020-07-17T20:32:17.700Z,1595017937.700 [Radio_Surface] Loaded
2020-07-17T20:32:17.700Z,1595017937.700 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2020-07-17T20:32:17.701Z,1595017937.701 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408B64E0
2020-07-17T20:32:17.702Z,1595017937.702 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 2479
2020-07-17T20:32:19.179Z,1595017939.179 [BPC1] Loaded
2020-07-17T20:32:19.179Z,1595017939.179 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2020-07-17T20:32:19.180Z,1595017939.180 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2020-07-17T20:32:19.180Z,1595017939.180 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2020-07-17T20:32:19.299Z,1595017939.299 [BuoyancyServo] Loaded
2020-07-17T20:32:19.299Z,1595017939.299 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2020-07-17T20:32:19.327Z,1595017939.327 [ElevatorServo] Loaded
2020-07-17T20:32:19.327Z,1595017939.327 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2020-07-17T20:32:19.354Z,1595017939.354 [MassServo] Loaded
2020-07-17T20:32:19.355Z,1595017939.355 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2020-07-17T20:32:19.381Z,1595017939.381 [RudderServo] Loaded
2020-07-17T20:32:19.381Z,1595017939.381 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2020-07-17T20:32:19.407Z,1595017939.407 [ThrusterServo] Loaded
2020-07-17T20:32:19.408Z,1595017939.408 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2020-07-17T20:32:19.408Z,1595017939.408 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2020-07-17T20:32:19.408Z,1595017939.408 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2020-07-17T20:32:19.487Z,1595017939.487 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2020-07-17T20:32:19.487Z,1595017939.487 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2020-07-17T20:32:19.513Z,1595017939.513 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2020-07-17T20:32:19.514Z,1595017939.514 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2020-07-17T20:32:19.796Z,1595017939.796 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2020-07-17T20:32:19.797Z,1595017939.797 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2020-07-17T20:32:20.053Z,1595017940.053 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density
2020-07-17T20:32:20.058Z,1595017940.058 [CTD_Seabird](INFO): created writer for : sea_water_density
2020-07-17T20:32:20.058Z,1595017940.058 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth
2020-07-17T20:32:20.063Z,1595017940.063 [CTD_Seabird](INFO): created writer for : depth
2020-07-17T20:32:20.063Z,1595017940.063 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure
2020-07-17T20:32:20.068Z,1595017940.068 [CTD_Seabird](INFO): created writer for : sea_water_pressure
2020-07-17T20:32:20.069Z,1595017940.069 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity
2020-07-17T20:32:20.074Z,1595017940.074 [CTD_Seabird](INFO): created writer for : sea_water_salinity
2020-07-17T20:32:20.075Z,1595017940.075 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature
2020-07-17T20:32:20.080Z,1595017940.080 [CTD_Seabird](INFO): created writer for : sea_water_temperature
2020-07-17T20:32:20.081Z,1595017940.081 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity
2020-07-17T20:32:20.086Z,1595017940.086 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity
2020-07-17T20:32:20.086Z,1595017940.086 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water
2020-07-17T20:32:20.091Z,1595017940.091 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water
2020-07-17T20:32:20.118Z,1595017940.118 [CTD_Seabird] Loaded
2020-07-17T20:32:20.118Z,1595017940.118 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2020-07-17T20:32:20.119Z,1595017940.119 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40AC24E0
2020-07-17T20:32:20.120Z,1595017940.120 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 2480
2020-07-17T20:32:20.168Z,1595017940.168 [ESPComponent] Loaded
2020-07-17T20:32:20.169Z,1595017940.169 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2020-07-17T20:32:20.199Z,1595017940.199 [PAR_Licor] Loaded
2020-07-17T20:32:20.199Z,1595017940.199 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2020-07-17T20:32:20.220Z,1595017940.220 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output470
2020-07-17T20:32:20.221Z,1595017940.221 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output470
2020-07-17T20:32:20.225Z,1595017940.225 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output650
2020-07-17T20:32:20.225Z,1595017940.225 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output650
2020-07-17T20:32:20.229Z,1595017940.229 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.OutputChl
2020-07-17T20:32:20.229Z,1595017940.229 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: OutputChl
2020-07-17T20:32:20.234Z,1595017940.234 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg470nm
2020-07-17T20:32:20.234Z,1595017940.234 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg470nm
2020-07-17T20:32:20.238Z,1595017940.238 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg650nm
2020-07-17T20:32:20.238Z,1595017940.238 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg650nm
2020-07-17T20:32:20.242Z,1595017940.242 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff470nm
2020-07-17T20:32:20.242Z,1595017940.242 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff470nm
2020-07-17T20:32:20.246Z,1595017940.246 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff650nm
2020-07-17T20:32:20.247Z,1595017940.247 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff650nm
2020-07-17T20:32:20.251Z,1595017940.251 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): mass_concentration_of_chlorophyll_in_sea_water
2020-07-17T20:32:20.255Z,1595017940.255 [WetLabsBB2FL](INFO): created writer for : mass_concentration_of_chlorophyll_in_sea_water
2020-07-17T20:32:20.256Z,1595017940.256 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_median_mass_concentration_of_chlorophyll_in_sea_water
2020-07-17T20:32:20.256Z,1595017940.256 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_median_mass_concentration_of_chlorophyll_in_sea_water
2020-07-17T20:32:20.260Z,1595017940.260 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water
2020-07-17T20:32:20.260Z,1595017940.260 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_mean_mass_concentration_of_chlorophyll_in_sea_water
2020-07-17T20:32:20.264Z,1595017940.264 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_variance_mass_concentration_of_chlorophyll_in_sea_water
2020-07-17T20:32:20.265Z,1595017940.265 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_variance_mass_concentration_of_chlorophyll_in_sea_water
2020-07-17T20:32:20.269Z,1595017940.269 [WetLabsBB2FL] Loaded
2020-07-17T20:32:20.269Z,1595017940.269 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2020-07-17T20:32:20.270Z,1595017940.270 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40AF24E0
2020-07-17T20:32:20.270Z,1595017940.270 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 2481
2020-07-17T20:32:20.271Z,1595017940.271 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2020-07-17T20:32:20.272Z,1595017940.272 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2020-07-17T20:32:20.402Z,1595017940.402 [SBIT](DEBUG): Construct Startup Built In Test.
2020-07-17T20:32:20.413Z,1595017940.413 [SBIT] Loaded
2020-07-17T20:32:20.413Z,1595017940.413 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2020-07-17T20:32:20.414Z,1595017940.414 [IBIT](DEBUG): Construct Initiated Built In Test.
2020-07-17T20:32:20.426Z,1595017940.426 [IBIT] Loaded
2020-07-17T20:32:20.426Z,1595017940.426 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2020-07-17T20:32:20.429Z,1595017940.429 [CBIT](DEBUG): Construct Continuous Built In Test.
2020-07-17T20:32:20.567Z,1595017940.567 [CBIT] Loaded
2020-07-17T20:32:20.567Z,1595017940.567 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2020-07-17T20:32:20.568Z,1595017940.568 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2020-07-17T20:32:20.571Z,1595017940.571 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2020-07-17T20:32:20.572Z,1595017940.572 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2020-07-17T20:32:20.579Z,1595017940.579 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2020-07-17T20:32:20.580Z,1595017940.580 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B5D4E0
2020-07-17T20:32:20.580Z,1595017940.580 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 2482
2020-07-17T20:32:20.585Z,1595017940.585 [Supervisor](INFO): Main Thread ID is 1957
2020-07-17T20:32:20.585Z,1595017940.585 [Supervisor](DEBUG): Running supervisor.
2020-07-17T20:32:20.586Z,1595017940.586 [CommandLine ThreadHandler](INFO): Handler Thread ID is 2483
2020-07-17T20:32:20.589Z,1595017940.589 [controlThread ThreadHandler](INFO): Handler Thread ID is 2484
2020-07-17T20:32:20.589Z,1595017940.589 [controlThread](DEBUG): Initializing ControlThread
2020-07-17T20:32:20.590Z,1595017940.590 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2020-07-17T20:32:20.591Z,1595017940.591 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2020-07-17T20:32:20.591Z,1595017940.591 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2020-07-17T20:32:20.591Z,1595017940.591 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2020-07-17T20:32:20.592Z,1595017940.592 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2020-07-17T20:32:20.592Z,1595017940.592 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2020-07-17T20:32:20.593Z,1595017940.593 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2020-07-17T20:32:20.594Z,1595017940.594 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2020-07-17T20:32:20.595Z,1595017940.595 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2020-07-17T20:32:20.596Z,1595017940.596 [LoopControl](DEBUG): Initialize LoopControlComponent.
2020-07-17T20:32:20.597Z,1595017940.597 [NavChart](DEBUG): Initialize NavChart Navigation.
2020-07-17T20:32:20.597Z,1595017940.597 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2020-07-17T20:32:20.606Z,1595017940.606 [SBIT](INFO): Initialize SBIT Component.
2020-07-17T20:32:20.606Z,1595017940.606 [SBIT](IMPORTANT): git: 2020-07-17
2020-07-17T20:32:20.607Z,1595017940.607 [SBIT](INFO): git hash: e190d94ed20392517662b2bcc897c2f9e7dd6614
2020-07-17T20:32:20.607Z,1595017940.607 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2020-07-17T20:32:20.607Z,1595017940.607 [SBIT](IMPORTANT): Kernel Version:#1 PREEMPT Tue Sep 24 11:12:27 PDT 2019
2020-07-17T20:32:20.608Z,1595017940.608 [SBIT](INFO): Beginning SBIT in 39.000000 seconds.
2020-07-17T20:32:20.609Z,1595017940.609 [IBIT](INFO): Initialize IBIT Component.
2020-07-17T20:32:20.610Z,1595017940.610 [CBIT](DEBUG): Initialize CBIT Component.
2020-07-17T20:32:20.611Z,1595017940.611 [logger ThreadHandler](INFO): Handler Thread ID is 2485
2020-07-17T20:32:20.622Z,1595017940.622 [CBIT](DEBUG): Initialized mux pins.
2020-07-17T20:32:20.622Z,1595017940.622 [CBIT](DEBUG): Initializing the watchdog timer.
2020-07-17T20:32:20.630Z,1595017940.630 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 2486
2020-07-17T20:32:20.631Z,1595017940.631 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2020-07-17T20:32:20.642Z,1595017940.642 [Onboard ThreadHandler](INFO): Handler Thread ID is 2487
2020-07-17T20:32:20.646Z,1595017940.646 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2020-07-17T20:32:20.646Z,1595017940.646 [CBIT](DEBUG): Initializing heartbeat.
2020-07-17T20:32:20.671Z,1595017940.671 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 2488
2020-07-17T20:32:20.678Z,1595017940.678 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 2489
2020-07-17T20:32:20.679Z,1595017940.679 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2020-07-17T20:32:20.683Z,1595017940.683 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 2491
2020-07-17T20:32:20.684Z,1595017940.684 [WetLabsBB2FL](INFO): Powering down
2020-07-17T20:32:20.706Z,1595017940.706 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 2492
2020-07-17T20:32:20.709Z,1595017940.709 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2020-07-17T20:32:20.709Z,1595017940.709 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2020-07-17T20:32:20.710Z,1595017940.710 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2020-07-17T20:32:20.710Z,1595017940.710 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2020-07-17T20:32:20.710Z,1595017940.710 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2020-07-17T20:32:20.710Z,1595017940.710 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2020-07-17T20:32:20.710Z,1595017940.710 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2020-07-17T20:32:20.710Z,1595017940.710 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2020-07-17T20:32:20.711Z,1595017940.711 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2020-07-17T20:32:20.711Z,1595017940.711 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2020-07-17T20:32:20.711Z,1595017940.711 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2020-07-17T20:32:20.711Z,1595017940.711 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2020-07-17T20:32:20.711Z,1595017940.711 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2020-07-17T20:32:20.711Z,1595017940.711 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2020-07-17T20:32:20.711Z,1595017940.711 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2020-07-17T20:32:20.712Z,1595017940.712 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2020-07-17T20:32:20.718Z,1595017940.718 [CBIT](DEBUG): Deactivating GF circuits.
2020-07-17T20:32:20.718Z,1595017940.718 [CBIT](DEBUG): Deactivating emergency mode.
2020-07-17T20:32:20.754Z,1595017940.754 [CBIT](DEBUG): Backplane powered.
2020-07-17T20:32:20.755Z,1595017940.755 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2020-07-17T20:32:20.764Z,1595017940.764 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2020-07-17T20:32:20.775Z,1595017940.775 [MissionManager](DEBUG):
2020-07-17T20:32:20.775Z,1595017940.775 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2020-07-17T20:32:20.850Z,1595017940.850 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2020-07-17T20:32:20.851Z,1595017940.851 [Default:A.Wait](DEBUG): Construct Wait.
2020-07-17T20:32:20.852Z,1595017940.852 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2020-07-17T20:32:20.895Z,1595017940.895 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2020-07-17T20:32:20.898Z,1595017940.898 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2020-07-17T20:32:20.923Z,1595017940.923 [Default:E.Execute](DEBUG): Construct Execute.
2020-07-17T20:32:20.942Z,1595017940.942 [MissionManager](DEBUG):
0
Wait a moment to see if the scheduler starts a new mission before
starting to actually run Default.
13
Burn on
Dropped weight due to communications timeout.
5
Default mission has been running for
Restarting logs and Default mission.
restart logs
2020-07-17T20:32:20.947Z,1595017940.947 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,DVL_micro,NAL9602,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,
2020-07-17T20:32:20.966Z,1595017940.966 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2020-07-17T20:32:20.999Z,1595017940.999 [Depth_Keller](ERROR): Pressure reading out of range: 1829.799438 decibar
2020-07-17T20:32:21.059Z,1595017941.059 [DepthRateCalculator](ERROR): Depth measurement is not active
2020-07-17T20:32:21.074Z,1595017941.074 [Radio_Surface](INFO): Powering up
2020-07-17T20:32:21.084Z,1595017941.084 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2020-07-17T20:32:21.108Z,1595017941.108 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2020-07-17T20:32:21.109Z,1595017941.109 [ElevatorServo](DEBUG): Initializing EZServoServo.
2020-07-17T20:32:21.114Z,1595017941.114 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2020-07-17T20:32:21.115Z,1595017941.115 [MassServo](DEBUG): Initializing EZServoServo.
2020-07-17T20:32:21.122Z,1595017941.122 [MassServo](DEBUG): Initializing MassServo.
2020-07-17T20:32:21.123Z,1595017941.123 [RudderServo](DEBUG): Initializing EZServoServo.
2020-07-17T20:32:21.130Z,1595017941.130 [RudderServo](DEBUG): Initializing RudderServo.
2020-07-17T20:32:21.131Z,1595017941.131 [ThrusterServo](DEBUG): Initializing EZServoServo.
2020-07-17T20:32:21.138Z,1595017941.138 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2020-07-17T20:32:41.161Z,1595017961.161 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2020-07-17T20:32:41.162Z,1595017961.162 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+20.1,0000.0,00
2020-07-17T20:32:48.024Z,1595017968.024 [NAL9602](INFO): Powering up NAL9602
2020-07-17T20:32:58.951Z,1595017978.951 [NAL9602](INFO): NAL9602 initialized
2020-07-17T20:33:00.200Z,1595017980.200 [SBIT](IMPORTANT): Beginning Startup BIT
2020-07-17T20:33:00.209Z,1595017980.209 [CBIT](IMPORTANT): Beginning ground fault scan
2020-07-17T20:33:11.139Z,1595017991.139 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): 0.009823
CHAN A1 (24V): 0.018379
CHAN A2 (12V): 0.003606
CHAN A3 (5V): -0.001868
CHAN B0 (3.3V): -0.002127
CHAN B1 (3.15aV): -0.001941
CHAN B2 (3.15bV): -0.001051
CHAN B3 (GND): 0.000617
OPEN: 0.003700
Full Scale Calc: 4.765 mA, -1.589 mA
2020-07-17T20:33:30.937Z,1595018010.937 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2020-07-17T20:33:33.329Z,1595018013.329 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2020-07-17T20:33:42.661Z,1595018022.661 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2020-07-17T20:33:54.302Z,1595018034.302 [SBIT](IMPORTANT): SBIT PASSED
2020-07-17T20:33:54.302Z,1595018034.302 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2020-07-17T20:33:54.303Z,1595018034.303 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=2 count;
2020-07-17T20:33:54.303Z,1595018034.303 [SBIT](IMPORTANT): ESPComponent.loadAtStartup=1 bool;
2020-07-17T20:33:54.303Z,1595018034.303 [SBIT](IMPORTANT): ESPComponent.simulateHardware=0 bool;
2020-07-17T20:33:54.704Z,1595018034.704 [MissionManager](IMPORTANT): Started mission Startup
2020-07-17T20:33:54.704Z,1595018034.704 [Startup] Running Loop=1
2020-07-17T20:33:54.704Z,1595018034.704 [Startup](DEBUG): Aggregate::initialize Startup
2020-07-17T20:33:54.704Z,1595018034.704 [Startup:A.GoToSurface] Running Loop=1
2020-07-17T20:33:54.704Z,1595018034.704 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-07-17T20:33:54.705Z,1595018034.705 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-07-17T20:33:54.706Z,1595018034.706 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-07-17T20:33:54.706Z,1595018034.706 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-07-17T20:33:54.706Z,1595018034.706 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-07-17T20:33:54.707Z,1595018034.707 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-07-17T20:33:54.708Z,1595018034.708 [Startup:StartupSatComms] Running Loop=1
2020-07-17T20:33:54.708Z,1595018034.708 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2020-07-17T20:33:54.708Z,1595018034.708 [Startup:StartupSatComms:A] Running Loop=1
2020-07-17T20:33:55.120Z,1595018035.120 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2020-07-17T20:34:11.315Z,1595018051.315 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2020-07-17T20:34:48.581Z,1595018088.581 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.005337
2020-07-17T20:34:54.544Z,1595018094.544 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2020-07-17T20:34:54.916Z,1595018094.916 [Startup:StartupSatComms:A](INFO): Timed out from 2020-07-17T20:33:54.7Z
2020-07-17T20:34:54.916Z,1595018094.916 [Startup:StartupSatComms:A] Stopped
2020-07-17T20:34:54.916Z,1595018094.916 [Startup:StartupSatComms:B] Running Loop=1
2020-07-17T20:34:55.324Z,1595018095.324 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2020-07-17T20:35:01.886Z,1595018101.886 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20200717T203209/Courier0000.lzma
2020-07-17T20:35:02.887Z,1595018102.887 [DataOverHttps](INFO): Moved sent file to Logs/20200717T203209/Courier0000.lzma.bak
2020-07-17T20:35:02.888Z,1595018102.888 [DataOverHttps](INFO): SBD MOMSN=12446271
2020-07-17T20:35:18.634Z,1595018118.634 [DataOverHttps](INFO): Sending 713 bytes from file Logs/20200717T203209/Express0001.lzma
2020-07-17T20:35:19.635Z,1595018119.635 [DataOverHttps](INFO): Moved sent file to Logs/20200717T203209/Express0001.lzma.bak
2020-07-17T20:35:19.636Z,1595018119.636 [DataOverHttps](INFO): SBD MOMSN=12446274
2020-07-17T20:35:20.752Z,1595018120.752 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2020-07-17T20:35:20.752Z,1595018120.752 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-07-17T20:35:20.753Z,1595018120.753 [Startup:StartupSatComms:B] Stopped
2020-07-17T20:35:20.753Z,1595018120.753 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2020-07-17T20:35:20.753Z,1595018120.753 [Startup:StartupSatComms] Stopped
2020-07-17T20:35:20.754Z,1595018120.754 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2020-07-17T20:35:20.754Z,1595018120.754 [Startup](INFO): Completed Startup
2020-07-17T20:35:20.755Z,1595018120.755 [MissionManager](INFO): Startup is completed.
2020-07-17T20:35:20.755Z,1595018120.755 [MissionManager](INFO): Uninitializing Mission Startup
2020-07-17T20:35:20.755Z,1595018120.755 [Startup] Stopped
2020-07-17T20:35:20.755Z,1595018120.755 [Startup](DEBUG): Aggregate::uninitialize Startup
2020-07-17T20:35:20.755Z,1595018120.755 [Startup:A.GoToSurface] Stopped
2020-07-17T20:35:20.755Z,1595018120.755 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2020-07-17T20:35:20.765Z,1595018120.765 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-07-17T20:35:21.166Z,1595018121.166 [MissionManager](IMPORTANT): Started mission Default
2020-07-17T20:35:21.166Z,1595018121.166 [Default] Running Loop=1
2020-07-17T20:35:21.167Z,1595018121.167 [Default](DEBUG): Aggregate::initialize Default
2020-07-17T20:35:21.167Z,1595018121.167 [Default:B.GoToSurface] Running Loop=1
2020-07-17T20:35:21.167Z,1595018121.167 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-07-17T20:35:21.167Z,1595018121.167 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-07-17T20:35:21.167Z,1595018121.167 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-07-17T20:35:21.168Z,1595018121.168 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-07-17T20:35:21.168Z,1595018121.168 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-07-17T20:35:21.168Z,1595018121.168 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-07-17T20:35:21.168Z,1595018121.168 [Default:A.Wait] Running Loop=1
2020-07-17T20:35:21.169Z,1595018121.169 [Default:A.Wait](DEBUG): Initialize Wait Component.
2020-07-17T20:35:21.178Z,1595018121.178 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-07-17T20:35:21.178Z,1595018121.178 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2020-07-17T20:35:29.298Z,1595018129.298 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2020-07-17T20:35:34.492Z,1595018134.492 [Default:A.Wait](INFO): Done Waiting.
2020-07-17T20:35:34.492Z,1595018134.492 [Default:A.Wait] Stopped
2020-07-17T20:35:34.492Z,1595018134.492 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2020-07-17T20:35:34.901Z,1595018134.901 [Default:CheckIn] Running Loop=1
2020-07-17T20:35:34.901Z,1595018134.901 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-07-17T20:35:34.901Z,1595018134.901 [Default:CheckIn:Read_GPS] Running Loop=1
2020-07-17T20:35:35.305Z,1595018135.305 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2020-07-17T20:35:35.749Z,1595018135.749 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2020-07-17T20:35:43.445Z,1595018143.445 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2020-07-17T20:36:18.983Z,1595018178.983 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2020-07-17T20:36:47.581Z,1595018207.581 [CommandLine](IMPORTANT): got command burn on
2020-07-17T20:36:47.581Z,1595018207.581 [CommandLine](IMPORTANT): Activating dropweight wire
2020-07-17T20:36:48.068Z,1595018208.068 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2020-07-17T20:36:54.523Z,1595018214.523 [CommandLine](IMPORTANT): got command burn off
2020-07-17T20:36:54.523Z,1595018214.523 [CommandLine](IMPORTANT): Deactivating dropweight wire
2020-07-17T20:36:55.746Z,1595018215.746 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2020-07-17T20:38:01.940Z,1595018281.940 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-07-17T20:38:14.669Z,1595018294.669 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.253029
2020-07-17T20:38:21.965Z,1595018301.965 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2020-07-17T20:38:21.965Z,1595018301.965 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-07-17T20:38:22.033Z,1595018302.033 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-07-17T20:38:22.251Z,1595018302.251 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-07-17T20:38:22.251Z,1595018302.251 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2020-07-17T20:38:26.531Z,1595018306.531 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003548
2020-07-17T20:38:51.254Z,1595018331.254 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2020-07-17T20:38:51.254Z,1595018331.254 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,.3,0000.0,14
2020-07-17T20:40:35.095Z,1595018435.095 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-07-17T20:35:34.9Z
2020-07-17T20:40:35.095Z,1595018435.095 [Default:CheckIn:Read_GPS] Stopped
2020-07-17T20:40:35.095Z,1595018435.095 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-07-17T20:40:35.493Z,1595018435.493 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2020-07-17T20:40:42.051Z,1595018442.051 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20200717T203209/Courier0004.lzma
2020-07-17T20:40:43.052Z,1595018443.052 [DataOverHttps](INFO): Moved sent file to Logs/20200717T203209/Courier0004.lzma.bak
2020-07-17T20:40:43.052Z,1595018443.052 [DataOverHttps](INFO): SBD MOMSN=12446298
2020-07-17T20:40:58.806Z,1595018458.806 [DataOverHttps](INFO): Sending 267 bytes from file Logs/20200717T203209/Express0005.lzma
2020-07-17T20:40:59.807Z,1595018459.807 [DataOverHttps](INFO): Moved sent file to Logs/20200717T203209/Express0005.lzma.bak
2020-07-17T20:40:59.808Z,1595018459.808 [DataOverHttps](INFO): SBD MOMSN=12446300
2020-07-17T20:41:00.952Z,1595018460.952 [Default:CheckIn:Read_Iridium] Stopped
2020-07-17T20:41:00.952Z,1595018460.952 [Default:CheckIn:C.Wait] Running Loop=1
2020-07-17T20:41:00.952Z,1595018460.952 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-07-17T20:41:01.336Z,1595018461.336 [DVL_micro](ERROR): Failed to parse:
:RD,+9999.99,+9999.99,+9999.99,+9999.99
2020-07-17T20:41:08.616Z,1595018468.616 [BPC1](ERROR): Battery stick #6 (s/n: 00CA) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0.
2020-07-17T20:41:08.617Z,1595018468.617 [BPC1](INFO): Calculating totals. Valid battery stick count: 55. Valid reserve battery stick count: 6.
2020-07-17T20:41:08.620Z,1595018468.620 [BPC1](INFO): Received data from all battery sticks.
2020-07-17T20:41:22.775Z,1595018482.775 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2020-07-17T20:41:22.775Z,1595018482.775 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-07-17T20:41:22.785Z,1595018482.785 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-07-17T20:41:23.195Z,1595018483.195 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-07-17T20:41:23.195Z,1595018483.195 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2020-07-17T20:42:20.533Z,1595018540.533 [DVL_micro](ERROR): only read 3 of 4 data items
2020-07-17T20:42:20.533Z,1595018540.533 [DVL_micro](ERROR): Failed to parse:
:BI,+00042,+0002,+00000,I
2020-07-17T20:43:01.333Z,1595018581.333 [NAL9602](FAULT): GPS failed to acquire within timeout.
2020-07-17T20:43:01.333Z,1595018581.333 [NAL9602] Data Fault, FailCount= 1
2020-07-17T20:43:01.333Z,1595018581.333 [NAL9602](ERROR): Data Fault
2020-07-17T20:43:01.351Z,1595018581.351 [CBIT](ERROR): Data Fault in component: NAL9602
2020-07-17T20:43:01.727Z,1595018581.727 [NAL9602](INFO): Powering down
2020-07-17T20:43:02.552Z,1595018582.552 [CBIT](INFO): Clearing failed state for component NAL9602
2020-07-17T20:43:02.552Z,1595018582.552 [NAL9602] No Fault, FailCount= 1
2020-07-17T20:43:32.033Z,1595018612.033 [NAL9602](INFO): Powering up NAL9602
2020-07-17T20:43:42.936Z,1595018622.936 [NAL9602](INFO): NAL9602 initialized
2020-07-17T20:44:23.761Z,1595018663.761 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2020-07-17T20:44:23.761Z,1595018663.761 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-07-17T20:44:23.788Z,1595018663.788 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-07-17T20:44:24.199Z,1595018664.199 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-07-17T20:44:24.199Z,1595018664.199 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2020-07-17T20:46:01.521Z,1595018761.521 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-07-17T20:46:01.521Z,1595018761.521 [Default:CheckIn:C.Wait] Stopped
2020-07-17T20:46:01.521Z,1595018761.521 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-07-17T20:46:01.521Z,1595018761.521 [Default:CheckIn:D] Running Loop=1
2020-07-17T20:46:01.930Z,1595018761.930 [Default:CheckIn:D] Stopped
2020-07-17T20:46:01.930Z,1595018761.930 [Default:CheckIn:E] Running Loop=1
2020-07-17T20:46:02.358Z,1595018762.358 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.679395 min
2020-07-17T20:46:02.358Z,1595018762.358 [Default:CheckIn:E] Stopped
2020-07-17T20:46:02.359Z,1595018762.359 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-07-17T20:46:02.359Z,1595018762.359 [Default:CheckIn] Stopped
2020-07-17T20:46:02.359Z,1595018762.359 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-07-17T20:46:02.359Z,1595018762.359 [Default:CheckIn](INFO): Running loop #2
2020-07-17T20:46:02.359Z,1595018762.359 [Default:CheckIn] Running Loop=2
2020-07-17T20:46:02.359Z,1595018762.359 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-07-17T20:46:02.359Z,1595018762.359 [Default:CheckIn:Read_GPS] Running Loop=1
2020-07-17T20:47:24.766Z,1595018844.766 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2020-07-17T20:47:24.766Z,1595018844.766 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-07-17T20:47:24.777Z,1595018844.777 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-07-17T20:47:25.187Z,1595018845.187 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-07-17T20:47:25.187Z,1595018845.187 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2020-07-17T20:48:58.410Z,1595018938.410 [CommandLine](IMPORTANT): got command get CBIT.abortDepth
2020-07-17T20:48:58.411Z,1595018938.411 [CommandLine](IMPORTANT): CBIT.abortDepth 300.000000 m
2020-07-17T20:49:07.803Z,1595018947.803 [CommandLine](IMPORTANT): got command get CBIT.stopDepth
2020-07-17T20:49:07.803Z,1595018947.803 [CommandLine](IMPORTANT): CBIT.stopDepth 265.000000 m
2020-07-17T20:49:35.524Z,1595018975.524 [CommandLine](IMPORTANT): got command get VerticalControl.buoyancyNeutral
2020-07-17T20:49:35.525Z,1595018975.525 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral 236.199997 cc
2020-07-17T20:49:46.280Z,1595018986.280 [CommandLine](IMPORTANT): got command get VerticalControl.buoyancyDefault
2020-07-17T20:49:46.281Z,1595018986.281 [CommandLine](IMPORTANT): VerticalControl.buoyancyDefault 916.000000 cc
2020-07-17T20:50:25.857Z,1595019025.857 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6
2020-07-17T20:50:25.857Z,1595019025.857 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-07-17T20:50:25.877Z,1595019025.877 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-07-17T20:50:26.230Z,1595019026.230 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-07-17T20:50:26.230Z,1595019026.230 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6
2020-07-17T20:50:46.160Z,1595019046.160 [CommandLine](IMPORTANT): got command get BPC1.platform_battery_voltage
2020-07-17T20:50:46.161Z,1595019046.161 [CommandLine](IMPORTANT): BPC1.platform_battery_voltage 16.685545 V
2020-07-17T20:51:01.793Z,1595019061.793 [CommandLine](IMPORTANT): got command get BPC1.platform_battery_charge
2020-07-17T20:51:01.794Z,1595019061.794 [CommandLine](IMPORTANT): BPC1.platform_battery_charge 359.964935 Ah
2020-07-17T20:51:02.551Z,1595019062.551 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-07-17T20:46:02.4Z
2020-07-17T20:51:02.552Z,1595019062.552 [Default:CheckIn:Read_GPS] Stopped
2020-07-17T20:51:02.552Z,1595019062.552 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-07-17T20:51:08.237Z,1595019068.237 [DataOverHttps](INFO): Sending 169 bytes from file Logs/20200717T203209/Courier0007.lzma
2020-07-17T20:51:09.239Z,1595019069.239 [DataOverHttps](INFO): Moved sent file to Logs/20200717T203209/Courier0007.lzma.bak
2020-07-17T20:51:09.240Z,1595019069.240 [DataOverHttps](INFO): SBD MOMSN=12446317
2020-07-17T20:51:24.666Z,1595019084.666 [DataOverHttps](INFO): Sending 407 bytes from file Logs/20200717T203209/Express0008.lzma
2020-07-17T20:51:25.668Z,1595019085.668 [DataOverHttps](INFO): Moved sent file to Logs/20200717T203209/Express0008.lzma.bak
2020-07-17T20:51:25.668Z,1595019085.668 [DataOverHttps](INFO): SBD MOMSN=12446319
2020-07-17T20:51:26.798Z,1595019086.798 [Default:CheckIn:Read_Iridium] Stopped
2020-07-17T20:51:26.798Z,1595019086.798 [Default:CheckIn:C.Wait] Running Loop=1
2020-07-17T20:51:26.798Z,1595019086.798 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-07-17T20:53:26.807Z,1595019206.807 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7
2020-07-17T20:53:26.807Z,1595019206.807 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-07-17T20:53:26.843Z,1595019206.843 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-07-17T20:53:27.203Z,1595019207.203 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-07-17T20:53:27.203Z,1595019207.203 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7
2020-07-17T20:53:28.397Z,1595019208.397 [DVL_micro](ERROR): Failed to parse:
:BD,+00000000.00,+00000000.00,+00000000.00,9999.99,000.00
2020-07-17T20:53:44.148Z,1595019224.148 [NAL9602](FAULT): GPS failed to acquire within timeout.
2020-07-17T20:53:44.148Z,1595019224.148 [NAL9602] Data Fault, FailCount= 2
2020-07-17T20:53:44.148Z,1595019224.148 [NAL9602](ERROR): Data Fault
2020-07-17T20:53:44.202Z,1595019224.202 [CBIT](ERROR): Data Fault in component: NAL9602
2020-07-17T20:53:44.552Z,1595019224.552 [NAL9602](INFO): Powering down
2020-07-17T20:53:45.386Z,1595019225.386 [CBIT](INFO): Clearing failed state for component NAL9602
2020-07-17T20:53:45.387Z,1595019225.387 [NAL9602] No Fault, FailCount= 2
2020-07-17T20:54:14.848Z,1595019254.848 [NAL9602](INFO): Powering up NAL9602
2020-07-17T20:54:25.758Z,1595019265.758 [NAL9602](INFO): NAL9602 initialized
2020-07-17T20:54:58.270Z,1595019298.270 [CommandLine](IMPORTANT): got command strobe off
2020-07-17T20:54:58.270Z,1595019298.270 [CommandLine](IMPORTANT): Deactivating strobe
2020-07-17T20:55:29.206Z,1595019329.206 [DataOverHttps](INFO): Exceeded connection timeout, disconnecting.
2020-07-17T20:55:31.214Z,1595019331.214 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.411427
2020-07-17T20:56:04.346Z,1595019364.346 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2020-07-17T20:56:27.395Z,1595019387.395 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-07-17T20:56:27.395Z,1595019387.395 [Default:CheckIn:C.Wait] Stopped
2020-07-17T20:56:27.395Z,1595019387.395 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-07-17T20:56:27.395Z,1595019387.395 [Default:CheckIn:D] Running Loop=1
2020-07-17T20:56:27.791Z,1595019387.791 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8
2020-07-17T20:56:27.791Z,1595019387.791 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-07-17T20:56:27.792Z,1595019387.792 [Default:CheckIn:D] Stopped
2020-07-17T20:56:27.792Z,1595019387.792 [Default:CheckIn:E] Running Loop=1
2020-07-17T20:56:27.828Z,1595019387.828 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-07-17T20:56:28.179Z,1595019388.179 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 21.110431 min
2020-07-17T20:56:28.180Z,1595019388.180 [Default:CheckIn:E] Stopped
2020-07-17T20:56:28.180Z,1595019388.180 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-07-17T20:56:28.180Z,1595019388.180 [Default:CheckIn] Stopped
2020-07-17T20:56:28.180Z,1595019388.180 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-07-17T20:56:28.180Z,1595019388.180 [Default:CheckIn](INFO): Running loop #3
2020-07-17T20:56:28.180Z,1595019388.180 [Default:CheckIn] Running Loop=3
2020-07-17T20:56:28.180Z,1595019388.180 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-07-17T20:56:28.180Z,1595019388.180 [Default:CheckIn:Read_GPS] Running Loop=1
2020-07-17T20:56:28.190Z,1595019388.190 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-07-17T20:56:28.190Z,1595019388.190 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8
2020-07-17T20:56:39.486Z,1595019399.486 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2020-07-17T20:57:14.626Z,1595019434.626 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2020-07-17T20:57:49.766Z,1595019469.766 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2020-07-17T20:58:07.015Z,1595019487.015 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004098
2020-07-17T20:59:28.794Z,1595019568.794 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 9
2020-07-17T20:59:28.794Z,1595019568.794 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-07-17T20:59:28.804Z,1595019568.804 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-07-17T20:59:29.215Z,1595019569.215 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-07-17T20:59:29.215Z,1595019569.215 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 9
2020-07-17T20:59:52.363Z,1595019592.363 [CommandLine](IMPORTANT): got command strobe on
2020-07-17T20:59:52.364Z,1595019592.364 [CommandLine](IMPORTANT): Activating strobe
2020-07-17T21:01:28.368Z,1595019688.368 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-07-17T20:56:28.2Z
2020-07-17T21:01:28.368Z,1595019688.368 [Default:CheckIn:Read_GPS] Stopped
2020-07-17T21:01:28.368Z,1595019688.368 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-07-17T21:01:33.053Z,1595019693.053 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20200717T203209/Courier0010.lzma
2020-07-17T21:01:34.055Z,1595019694.055 [DataOverHttps](INFO): Moved sent file to Logs/20200717T203209/Courier0010.lzma.bak
2020-07-17T21:01:34.056Z,1595019694.056 [DataOverHttps](INFO): SBD MOMSN=12446342
2020-07-17T21:01:49.538Z,1595019709.538 [DataOverHttps](INFO): Sending 208 bytes from file Logs/20200717T203209/Express0011.lzma
2020-07-17T21:01:50.539Z,1595019710.539 [DataOverHttps](INFO): Moved sent file to Logs/20200717T203209/Express0011.lzma.bak
2020-07-17T21:01:50.540Z,1595019710.540 [DataOverHttps](INFO): SBD MOMSN=12446344
2020-07-17T21:01:51.807Z,1595019711.807 [Default:CheckIn:Read_Iridium] Stopped
2020-07-17T21:01:51.808Z,1595019711.808 [Default:CheckIn:C.Wait] Running Loop=1
2020-07-17T21:01:51.808Z,1595019711.808 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-07-17T21:02:29.818Z,1595019749.818 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 10
2020-07-17T21:02:29.818Z,1595019749.818 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-07-17T21:02:29.833Z,1595019749.833 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-07-17T21:02:30.246Z,1595019750.246 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-07-17T21:02:30.246Z,1595019750.246 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 10
2020-07-17T21:04:28.960Z,1595019868.960 [NAL9602](FAULT): GPS failed to acquire within timeout.
2020-07-17T21:04:28.960Z,1595019868.960 [NAL9602] Data Fault, FailCount= 3
2020-07-17T21:04:28.960Z,1595019868.960 [NAL9602](ERROR): Data Fault
2020-07-17T21:04:28.977Z,1595019868.977 [CBIT](ERROR): Data Fault in component: NAL9602
2020-07-17T21:04:29.364Z,1595019869.364 [NAL9602](INFO): Powering down
2020-07-17T21:04:30.203Z,1595019870.203 [CBIT](INFO): Clearing failed state for component NAL9602
2020-07-17T21:04:30.203Z,1595019870.203 [NAL9602] No Fault, FailCount= 3
2020-07-17T21:04:59.660Z,1595019899.660 [NAL9602](INFO): Powering up NAL9602
2020-07-17T21:05:10.568Z,1595019910.568 [NAL9602](INFO): NAL9602 initialized
2020-07-17T21:05:30.789Z,1595019930.789 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 11
2020-07-17T21:05:30.789Z,1595019930.789 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-07-17T21:05:30.815Z,1595019930.815 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-07-17T21:05:31.231Z,1595019931.231 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-07-17T21:05:31.231Z,1595019931.231 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 11
2020-07-17T21:06:15.214Z,1595019975.214 [DVL_micro](ERROR): only read 3 of 4 data items
2020-07-17T21:06:15.214Z,1595019975.214 [DVL_micro](ERROR): Failed to parse:
:BI,-00252,-00226,+0050,I
2020-07-17T21:06:52.421Z,1595020012.421 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-07-17T21:06:52.421Z,1595020012.421 [Default:CheckIn:C.Wait] Stopped
2020-07-17T21:06:52.421Z,1595020012.421 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-07-17T21:06:52.422Z,1595020012.422 [Default:CheckIn:D] Running Loop=1
2020-07-17T21:06:52.815Z,1595020012.815 [Default:CheckIn:D] Stopped
2020-07-17T21:06:52.815Z,1595020012.815 [Default:CheckIn:E] Running Loop=1
2020-07-17T21:06:53.242Z,1595020013.242 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 31.527472 min
2020-07-17T21:06:53.242Z,1595020013.242 [Default:CheckIn:E] Stopped
2020-07-17T21:06:53.242Z,1595020013.242 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-07-17T21:06:53.242Z,1595020013.242 [Default:CheckIn] Stopped
2020-07-17T21:06:53.242Z,1595020013.242 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-07-17T21:06:53.243Z,1595020013.243 [Default:CheckIn](INFO): Running loop #4
2020-07-17T21:06:53.243Z,1595020013.243 [Default:CheckIn] Running Loop=4
2020-07-17T21:06:53.243Z,1595020013.243 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-07-17T21:06:53.243Z,1595020013.243 [Default:CheckIn:Read_GPS] Running Loop=1
2020-07-17T21:08:31.807Z,1595020111.807 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 12
2020-07-17T21:08:31.807Z,1595020111.807 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-07-17T21:08:31.817Z,1595020111.817 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-07-17T21:08:32.216Z,1595020112.216 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-07-17T21:08:32.216Z,1595020112.216 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 12
2020-07-17T21:11:09.130Z,1595020269.130 [CommandLine](IMPORTANT): got command run ./Missions/Insert/Science.xml
2020-07-17T21:11:09.130Z,1595020269.130 [MissionManager](INFO): Loading Mission: ./Missions/Insert/Science.xml
2020-07-17T21:11:09.304Z,1595020269.304 [MissionManager](INFO): DefineArg Science.SampleISUS = 0 bool
2020-07-17T21:11:09.308Z,1595020269.308 [MissionManager](INFO): DefineArg Science.SampleISUSmaxPitch = 60.000000 arcdeg
2020-07-17T21:11:09.311Z,1595020269.311 [MissionManager](INFO): DefineArg Science.SampleISUSminPitch = -60.000000 arcdeg
2020-07-17T21:11:09.314Z,1595020269.314 [MissionManager](INFO): DefineArg Science.PeakDetectChlActive = 0 bool
2020-07-17T21:11:09.317Z,1595020269.317 [MissionManager](INFO): DefineArg Science.TimeWindowPeakReport = nan min
2020-07-17T21:11:09.320Z,1595020269.320 [MissionManager](INFO): DefineArg Science.HighestChlPeakReportActive = 0 bool
2020-07-17T21:11:09.359Z,1595020269.359 [MissionManager](INFO): DefineArg Science.PatchTracking = 0 bool
2020-07-17T21:11:09.366Z,1595020269.366 [MissionManager](INFO): DefineArg Science.FilterWidthHorizontal = 3.000000 count
2020-07-17T21:11:09.369Z,1595020269.369 [MissionManager](INFO): DefineArg Science.NumProfilesSlidingwindow = 100.000000 count
2020-07-17T21:11:09.381Z,1595020269.381 [MissionManager](INFO): DefineArg Science.OffPeakFractionHorizontal = 80.000000 %
2020-07-17T21:11:09.400Z,1595020269.400 [MissionManager](INFO): DefineArg Science.PeakDetectNO3Active = 0 bool
2020-07-17T21:11:09.411Z,1595020269.411 [MissionManager](INFO): DefineArg Science.PeakDetectOilActive = 0 bool
2020-07-17T21:11:09.426Z,1595020269.426 [MissionManager](INFO): DefineArg Science.PeakDetectFDOMActive = 0 bool
2020-07-17T21:11:09.429Z,1595020269.429 [MissionManager](INFO): DefineArg Science.UpwardDerivativeOfTemperatureActive = 0 bool
2020-07-17T21:11:09.450Z,1595020269.450 [MissionManager](INFO): DefineArg Science.EnabledAanderaaO2 = 0.000000 bool
2020-07-17T21:11:09.458Z,1595020269.458 [MissionManager](INFO): DefineArg Science.EnabledNeilBrown = 0.000000 bool
2020-07-17T21:11:09.462Z,1595020269.462 [MissionManager](INFO): DefineArg Science.EnabledSeabird = 1.000000 bool
2020-07-17T21:11:09.480Z,1595020269.480 [MissionManager](INFO): DefineArg Science.EnabledTurbulence_NPS = 0.000000 bool
2020-07-17T21:11:09.485Z,1595020269.485 [MissionManager](INFO): DefineArg Science.EnabledWetLabsBB2FL = 1.000000 bool
2020-07-17T21:11:09.489Z,1595020269.489 [MissionManager](INFO): DefineArg Science.EnabledWetLabsSeaOWL_UV_A = 0.000000 bool
2020-07-17T21:11:09.492Z,1595020269.492 [MissionManager](INFO): DefineArg Science.EnabledWetLabsUBAT = 0.000000 bool
2020-07-17T21:11:09.513Z,1595020269.513 [MissionManager](INFO): DefineArg Science.EnabledISUS = 0.000000 bool
2020-07-17T21:11:09.520Z,1595020269.520 [MissionManager](INFO): DefineArg Science.LowPassWindowLength = 20.000000 count
2020-07-17T21:11:09.523Z,1595020269.523 [MissionManager](INFO): DefineArg Science.MedianFilterLen = 5.000000 count
2020-07-17T21:11:09.534Z,1595020269.534 [MissionManager](INFO): DefineArg Science.PeakChlShallowBound = nan m
2020-07-17T21:11:09.537Z,1595020269.537 [MissionManager](INFO): DefineArg Science.PeakChlDeepBound = nan m
2020-07-17T21:11:09.552Z,1595020269.552 [MissionManager](INFO): DefineArg Science.PeakShallowBound = nan m
2020-07-17T21:11:09.563Z,1595020269.563 [MissionManager](INFO): DefineArg Science.PeakDeepBound = nan m
2020-07-17T21:11:09.571Z,1595020269.571 [MissionManager](INFO): DefineOutput Science.PeakChl = 0.000000 ug/l
2020-07-17T21:11:09.586Z,1595020269.586 [MissionManager](INFO): DefineOutput Science.PeakChlDepth = 0.000000 m
2020-07-17T21:11:09.594Z,1595020269.594 [MissionManager](INFO): DefineOutput Science.PeakChlTemperature = 0.000000 degC
2020-07-17T21:11:09.607Z,1595020269.607 [MissionManager](INFO): DefineOutput Science.PeakChlLatitude = nan arcdeg
2020-07-17T21:11:09.611Z,1595020269.611 [MissionManager](INFO): DefineOutput Science.PeakChlLongitude = nan arcdeg
2020-07-17T21:11:09.622Z,1595020269.622 [MissionManager](INFO): DefineOutput Science.PeakNO3 = 0.000000 umol/l
2020-07-17T21:11:09.638Z,1595020269.638 [MissionManager](INFO): DefineOutput Science.PeakNO3Depth = 0.000000 m
2020-07-17T21:11:09.641Z,1595020269.641 [MissionManager](INFO): DefineOutput Science.PeakNO3Latitude = nan arcdeg
2020-07-17T21:11:09.648Z,1595020269.648 [MissionManager](INFO): DefineOutput Science.PeakNO3Longitude = nan arcdeg
2020-07-17T21:11:09.652Z,1595020269.652 [MissionManager](INFO): DefineOutput Science.PatchChl = 0.000000 m
2020-07-17T21:11:09.671Z,1595020269.671 [MissionManager](INFO): DefineOutput Science.PatchChlDepth = 0.000000 m
2020-07-17T21:11:09.677Z,1595020269.677 [MissionManager](INFO): DefineOutput Science.PatchChlLatitude = nan arcdeg
2020-07-17T21:11:09.685Z,1595020269.685 [MissionManager](INFO): DefineOutput Science.PatchChlLongitude = nan arcdeg
2020-07-17T21:11:09.705Z,1595020269.705 [MissionManager](INFO): DefineOutput Science.PatchChlDistance = nan m
2020-07-17T21:11:09.723Z,1595020269.723 [MissionManager](INFO): DefineOutput Science.PeakOil = 0.000000 kg/m3
2020-07-17T21:11:09.766Z,1595020269.766 [MissionManager](INFO): DefineOutput Science.PeakOilDepth = 0.000000 m
2020-07-17T21:11:09.769Z,1595020269.769 [MissionManager](INFO): DefineOutput Science.PeakOilLatitude = nan arcdeg
2020-07-17T21:11:09.777Z,1595020269.777 [MissionManager](INFO): DefineOutput Science.PeakOilLongitude = nan arcdeg
2020-07-17T21:11:09.788Z,1595020269.788 [MissionManager](INFO): DefineOutput Science.PeakFDOM = 0.000000 ppb
2020-07-17T21:11:09.797Z,1595020269.797 [MissionManager](INFO): DefineOutput Science.PeakFDOMDepth = 0.000000 m
2020-07-17T21:11:09.825Z,1595020269.825 [MissionManager](INFO): DefineOutput Science.PeakFDOMLatitude = nan arcdeg
2020-07-17T21:11:09.846Z,1595020269.846 [MissionManager](INFO): DefineOutput Science.PeakFDOMLongitude = nan arcdeg
2020-07-17T21:11:09.854Z,1595020269.854 [MissionManager](INFO): DefineOutput Science.PatchFDOMDistance = nan m
2020-07-17T21:11:09.893Z,1595020269.893 [Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2020-07-17T21:11:09.921Z,1595020269.921 [Science:HighestChlPeakReport:A.PeakDetectHorizontal](DEBUG): Construct PeakDetectHorizontal.
2020-07-17T21:11:09.996Z,1595020269.996 [Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2020-07-17T21:11:10.023Z,1595020270.023 [Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2020-07-17T21:11:10.032Z,1595020270.032 [Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2020-07-17T21:11:10.092Z,1595020270.092 [MissionManager](DEBUG):
Set either this or PeakDetectNO3Active to True in order to sample
Nitrate. EnabledISUS must also be true.
Maximum pitch to sample ISUS. (EnabledISUS must also be true.)
60.0
Minimum pitch to sample ISUS. (EnabledISUS must also be true.)
-60.0
Turns on peak detection of Cholorphyll.
If greater than zero, report a peak every window. If NaN or zero, this
variable is ignored.
NaN
Turns on reporting of the highest peak value on yo-yo profiles in a
horizontal sliding window (of length numProfilesSlidingwindow)
If tracking a patch
Width of boxcar filter applied to yoyo-wise chl peaks to pick out the
highest peak.
3
Length of horizontal sliding window. The highest yoyo-wise chl peak
(after low-pass filtering by a filter of length FilterWidthHorizontal)
within this window.
100
When filtered horizontal value is this fraction of the peak, consider it
outside the patch.
80
Turns on peak detection of Nitrate (and turns on ISUS).
Turns on peak detection of Dissolved Oil.
Turns on peak detection of concentration_of_chromophoric_dissolved_organic_matter_in_sea_water from FDOM sensor.
Turns on seawater temperature derivative.
Automatically set to True if the Aanderaa O2 sensor is installed. Set to
false to disable reading Aandera O2.
Automatically set to true if the Neil Brown CTD is enabled. Set to false
to disable reading from the Neil Brown.
Automatically set to true if the CTD is enabled. Set to false to disable
reading from the CTD.
Automatically set to true if the NPS Turbulence sensor is enabled. Set
to false to disable reading from the NPS Turbulence sensor.
Automatically set to true if the the WetLabs BB2FL is enabled. Set to
false to disable the WetLabs BB2FL.
Automatically set to true if the the WetLabs SeaOWL UV-A is enabled. Set
to false to disable the WetLabs SeaOWL UV-A.
Automatically set to true if the the WetLabs UBAT is enabled. Set
to false to disable the WetLabs UBAT.
Automatically set to True if ISUS is enabled. Set to false to disable
ISUS.
Low-pass window length (based on depth sensor sampling interval 0.4
second) for low-pass filtering.
20
Median filter length (only for chlorophyll fluorescence which tends to have spikes)
5
Shallow depth bound for detecting chl peak on each descent or ascent
profile.
NaN
Deep depth bound for detecting chl peak on each descent or ascent
profile.
NaN
Shallow depth bound for detecting any peak on each descent or ascent
profile.
NaN
Deep depth bound for detecting any peak on each descent or ascent
profile.
NaN
0
0
0
NaN
NaN
0
0
NaN
NaN
0
0
NaN
NaN
NaN
0
0
NaN
NaN
0
0
NaN
NaN
NaN
2020-07-17T21:11:10.124Z,1595020270.124 [CommandLine](IMPORTANT): Running ./Missions/Insert/Science.xml
2020-07-17T21:11:10.168Z,1595020270.168 [Default] Stopped
2020-07-17T21:11:10.168Z,1595020270.168 [Default](DEBUG): Aggregate::uninitialize Default
2020-07-17T21:11:10.169Z,1595020270.169 [Default:B.GoToSurface] Stopped
2020-07-17T21:11:10.169Z,1595020270.169 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2020-07-17T21:11:10.169Z,1595020270.169 [Default:CheckIn] Stopped
2020-07-17T21:11:10.169Z,1595020270.169 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-07-17T21:11:10.169Z,1595020270.169 [Default:CheckIn:Read_GPS] Stopped
2020-07-17T21:11:10.169Z,1595020270.169 [MissionManager](IMPORTANT): Started mission Science
2020-07-17T21:11:10.169Z,1595020270.169 [Science] Running Loop=1
2020-07-17T21:11:10.169Z,1595020270.169 [Science](DEBUG): Aggregate::initialize Science
2020-07-17T21:11:10.169Z,1595020270.169 [Science:A] Running Loop=1
2020-07-17T21:11:10.170Z,1595020270.170 [Science:B] Running Loop=1
2020-07-17T21:11:10.170Z,1595020270.170 [Science:C] Running Loop=1
2020-07-17T21:11:10.170Z,1595020270.170 [Science:D] Running Loop=1
2020-07-17T21:11:10.170Z,1595020270.170 [Science:E] Running Loop=1
2020-07-17T21:11:10.170Z,1595020270.170 [Science:F] Running Loop=1
2020-07-17T21:11:10.170Z,1595020270.170 [Science:G] Running Loop=1
2020-07-17T21:11:10.170Z,1595020270.170 [Science:H] Running Loop=1
2020-07-17T21:11:10.170Z,1595020270.170 [Science:Read_Oil] Running Loop=1
2020-07-17T21:11:10.170Z,1595020270.170 [Science:PeakDetectChl] Running Loop=1
2020-07-17T21:11:10.170Z,1595020270.170 [Science:PeakDetectChl](DEBUG): Aggregate::initialize Science:PeakDetectChl
2020-07-17T21:11:10.170Z,1595020270.170 [Science:PeakDetectChl:A.PeakDetectVsDepth] Running Loop=1
2020-07-17T21:11:10.170Z,1595020270.170 [Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Initialize.
2020-07-17T21:11:10.172Z,1595020270.172 [Science:HighestChlPeakReport] Running Loop=1
2020-07-17T21:11:10.172Z,1595020270.172 [Science:HighestChlPeakReport](DEBUG): Aggregate::initialize Science:HighestChlPeakReport
2020-07-17T21:11:10.172Z,1595020270.172 [Science:HighestChlPeakReport:A.PeakDetectHorizontal] Running Loop=1
2020-07-17T21:11:10.173Z,1595020270.173 [Science:HighestChlPeakReport:A.PeakDetectHorizontal](INFO): Initialize.
2020-07-17T21:11:10.173Z,1595020270.173 [Science:PeakDetectNO3] Running Loop=1
2020-07-17T21:11:10.173Z,1595020270.173 [Science:PeakDetectNO3](DEBUG): Aggregate::initialize Science:PeakDetectNO3
2020-07-17T21:11:10.173Z,1595020270.173 [Science:PeakDetectNO3:A.PeakDetectVsDepth] Running Loop=1
2020-07-17T21:11:10.173Z,1595020270.173 [Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Initialize.
2020-07-17T21:11:10.175Z,1595020270.175 [Science:PeakDetectOil] Running Loop=1
2020-07-17T21:11:10.175Z,1595020270.175 [Science:PeakDetectOil](DEBUG): Aggregate::initialize Science:PeakDetectOil
2020-07-17T21:11:10.176Z,1595020270.176 [Science:PeakDetectOil:A.PeakDetectVsDepth] Running Loop=1
2020-07-17T21:11:10.176Z,1595020270.176 [Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Initialize.
2020-07-17T21:11:10.203Z,1595020270.203 [Science:PeakDetectFDOM] Running Loop=1
2020-07-17T21:11:10.203Z,1595020270.203 [Science:PeakDetectFDOM](DEBUG): Aggregate::initialize Science:PeakDetectFDOM
2020-07-17T21:11:10.203Z,1595020270.203 [Science:PeakDetectFDOM:A.PeakDetectVsDepth] Running Loop=1
2020-07-17T21:11:10.203Z,1595020270.203 [Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Initialize.
2020-07-17T21:11:10.206Z,1595020270.206 [Science:PeakDetectFDOM] Stopped
2020-07-17T21:11:10.206Z,1595020270.206 [Science:PeakDetectFDOM](DEBUG): Aggregate::uninitialize Science:PeakDetectFDOM
2020-07-17T21:11:10.206Z,1595020270.206 [Science:PeakDetectFDOM:A.PeakDetectVsDepth] Stopped
2020-07-17T21:11:10.206Z,1595020270.206 [Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2020-07-17T21:11:10.206Z,1595020270.206 [Science:PeakDetectOil] Stopped
2020-07-17T21:11:10.206Z,1595020270.206 [Science:PeakDetectOil](DEBUG): Aggregate::uninitialize Science:PeakDetectOil
2020-07-17T21:11:10.206Z,1595020270.206 [Science:PeakDetectOil:A.PeakDetectVsDepth] Stopped
2020-07-17T21:11:10.207Z,1595020270.207 [Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2020-07-17T21:11:10.207Z,1595020270.207 [Science:PeakDetectNO3] Stopped
2020-07-17T21:11:10.207Z,1595020270.207 [Science:PeakDetectNO3](DEBUG): Aggregate::uninitialize Science:PeakDetectNO3
2020-07-17T21:11:10.207Z,1595020270.207 [Science:PeakDetectNO3:A.PeakDetectVsDepth] Stopped
2020-07-17T21:11:10.207Z,1595020270.207 [Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2020-07-17T21:11:10.207Z,1595020270.207 [Science:HighestChlPeakReport] Stopped
2020-07-17T21:11:10.207Z,1595020270.207 [Science:HighestChlPeakReport](DEBUG): Aggregate::uninitialize Science:HighestChlPeakReport
2020-07-17T21:11:10.207Z,1595020270.207 [Science:HighestChlPeakReport:A.PeakDetectHorizontal] Stopped
2020-07-17T21:11:10.207Z,1595020270.207 [Science:HighestChlPeakReport:A.PeakDetectHorizontal](DEBUG): Uninitialize.
2020-07-17T21:11:10.207Z,1595020270.207 [Science:PeakDetectChl] Stopped
2020-07-17T21:11:10.207Z,1595020270.207 [Science:PeakDetectChl](DEBUG): Aggregate::uninitialize Science:PeakDetectChl
2020-07-17T21:11:10.207Z,1595020270.207 [Science:PeakDetectChl:A.PeakDetectVsDepth] Stopped
2020-07-17T21:11:10.207Z,1595020270.207 [Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2020-07-17T21:11:10.208Z,1595020270.208 [Science:Read_Oil] Stopped
2020-07-17T21:11:10.208Z,1595020270.208 [Science:H] Stopped
2020-07-17T21:11:10.208Z,1595020270.208 [Science:G] Running Loop=1
2020-07-17T21:11:10.208Z,1595020270.208 [Science:G](DEBUG): Initialize ReadDataComponent to sense mass_concentration_of_chlorophyll_in_sea_water
2020-07-17T21:11:10.208Z,1595020270.208 [Science:F] Stopped
2020-07-17T21:11:10.208Z,1595020270.208 [Science:E] Stopped
2020-07-17T21:11:10.208Z,1595020270.208 [Science:D] Running Loop=1
2020-07-17T21:11:10.209Z,1595020270.209 [Science:D](DEBUG): Initialize ReadDataComponent to sense CTD_Seabird.sea_water_temperature
2020-07-17T21:11:10.210Z,1595020270.210 [Science:D](DEBUG): Initialize ReadDataComponent to sense CTD_Seabird.sea_water_salinity
2020-07-17T21:11:10.210Z,1595020270.210 [Science:C] Running Loop=1
2020-07-17T21:11:10.210Z,1595020270.210 [Science:C](DEBUG): Initialize ReadDataComponent to sense sea_water_temperature
2020-07-17T21:11:10.211Z,1595020270.211 [Science:C](DEBUG): Initialize ReadDataComponent to sense sea_water_salinity
2020-07-17T21:11:10.211Z,1595020270.211 [Science:B] Stopped
2020-07-17T21:11:10.211Z,1595020270.211 [Science:A] Stopped
2020-07-17T21:11:10.391Z,1595020270.391 [WetLabsBB2FL](INFO): Powering up
2020-07-17T21:11:13.327Z,1595020273.327 [CTD_Seabird](ERROR): Failed to parse device response:
2020-07-17T21:11:23.908Z,1595020283.908 [DVL_micro](ERROR): only read 3 of 4 data items
2020-07-17T21:11:23.908Z,1595020283.908 [DVL_micro](ERROR): Failed to parse:
:BI,-0788,+00046,+00000,A
2020-07-17T21:11:25.956Z,1595020285.956 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,211124.00,A,3648.16306,N,12147.28211,W,0.136,0.00,170720,,,A*7C
2020-07-17T21:11:25.959Z,1595020285.959 [NAL9602](INFO): GPS fix at 20200717T211124: (36.802718, -121.788035)
2020-07-17T21:11:32.516Z,1595020292.516 [CommandLine](IMPORTANT): got command maintain control VerticalControl.buoyancyAction 200.000000 cubic_centimeter
2020-07-17T21:11:32.522Z,1595020292.522 [ComponentRegistry](DEBUG): SyncComponent "Maintain_VerticalControl.buoyancyAction" handled in the control thread.
2020-07-17T21:11:32.816Z,1595020292.816 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,DVL_micro,NAL9602,BPC1,ESPComponent,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,Maintain_VerticalControl.buoyancyAction,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2020-07-17T21:11:46.245Z,1595020306.245 [CommandLine](IMPORTANT): got command report touch platform_buoyancy_position
2020-07-17T21:11:46.575Z,1595020306.575 [Reporter](INFO): platform_buoyancy_position 833.707153 cc
2020-07-17T21:11:47.172Z,1595020307.172 [Reporter](INFO): platform_buoyancy_position 826.723633 cc
2020-07-17T21:11:47.361Z,1595020307.361 [Reporter](INFO): platform_buoyancy_position 822.694580 cc
2020-07-17T21:11:47.783Z,1595020307.783 [Reporter](INFO): platform_buoyancy_position 818.396973 cc
2020-07-17T21:11:48.200Z,1595020308.200 [Reporter](INFO): platform_buoyancy_position 811.950562 cc
2020-07-17T21:11:48.587Z,1595020308.587 [Reporter](INFO): platform_buoyancy_position 807.652954 cc
2020-07-17T21:11:49.003Z,1595020309.003 [Reporter](INFO): platform_buoyancy_position 801.340881 cc
2020-07-17T21:11:49.391Z,1595020309.391 [Reporter](INFO): platform_buoyancy_position 796.908997 cc
2020-07-17T21:11:49.835Z,1595020309.835 [Reporter](INFO): platform_buoyancy_position 790.596863 cc
2020-07-17T21:11:50.199Z,1595020310.199 [Reporter](INFO): platform_buoyancy_position 786.164978 cc
2020-07-17T21:11:50.684Z,1595020310.684 [Reporter](INFO): platform_buoyancy_position 779.852844 cc
2020-07-17T21:11:51.052Z,1595020311.052 [Reporter](INFO): platform_buoyancy_position 775.555298 cc
2020-07-17T21:11:51.472Z,1595020311.472 [Reporter](INFO): platform_buoyancy_position 770.989075 cc
2020-07-17T21:11:51.843Z,1595020311.843 [Reporter](INFO): platform_buoyancy_position 764.811279 cc
2020-07-17T21:11:52.243Z,1595020312.243 [Reporter](INFO): platform_buoyancy_position 760.379395 cc
2020-07-17T21:11:52.639Z,1595020312.639 [Reporter](INFO): platform_buoyancy_position 755.813171 cc
2020-07-17T21:11:53.046Z,1595020313.046 [Reporter](INFO): platform_buoyancy_position 749.635376 cc
2020-07-17T21:11:53.435Z,1595020313.435 [Reporter](INFO): platform_buoyancy_position 745.337769 cc
2020-07-17T21:11:53.869Z,1595020313.869 [Reporter](INFO): platform_buoyancy_position 738.891357 cc
2020-07-17T21:11:54.239Z,1595020314.239 [Reporter](INFO): platform_buoyancy_position 734.190857 cc
2020-07-17T21:11:54.651Z,1595020314.651 [Reporter](INFO): platform_buoyancy_position 728.147339 cc
2020-07-17T21:11:55.087Z,1595020315.087 [Reporter](INFO): platform_buoyancy_position 722.506775 cc
2020-07-17T21:11:55.486Z,1595020315.486 [Reporter](INFO): platform_buoyancy_position 717.403381 cc
2020-07-17T21:11:55.888Z,1595020315.888 [Reporter](INFO): platform_buoyancy_position 711.091248 cc
2020-07-17T21:11:56.299Z,1595020316.299 [Reporter](INFO): platform_buoyancy_position 706.659363 cc
2020-07-17T21:11:56.690Z,1595020316.690 [Reporter](INFO): platform_buoyancy_position 701.958862 cc
2020-07-17T21:11:57.103Z,1595020317.103 [Reporter](INFO): platform_buoyancy_position 695.915344 cc
2020-07-17T21:11:57.499Z,1595020317.499 [Reporter](INFO): platform_buoyancy_position 689.871887 cc
2020-07-17T21:11:57.919Z,1595020317.919 [Reporter](INFO): platform_buoyancy_position 685.171387 cc
2020-07-17T21:11:58.227Z,1595020318.227 [NAL9602](INFO): Not Powering down - fast GPS
2020-07-17T21:11:58.355Z,1595020318.355 [Reporter](INFO): platform_buoyancy_position 678.859253 cc
2020-07-17T21:11:58.739Z,1595020318.739 [Reporter](INFO): platform_buoyancy_position 674.561646 cc
2020-07-17T21:11:59.126Z,1595020319.126 [Reporter](INFO): platform_buoyancy_position 669.995483 cc
2020-07-17T21:11:59.507Z,1595020319.507 [Reporter](INFO): platform_buoyancy_position 663.817688 cc
2020-07-17T21:11:59.923Z,1595020319.923 [Reporter](INFO): platform_buoyancy_position 659.385742 cc
2020-07-17T21:12:00.303Z,1595020320.303 [Reporter](INFO): platform_buoyancy_position 654.819580 cc
2020-07-17T21:12:00.710Z,1595020320.710 [Reporter](INFO): platform_buoyancy_position 648.641785 cc
2020-07-17T21:12:01.126Z,1595020321.126 [Reporter](INFO): platform_buoyancy_position 642.463989 cc
2020-07-17T21:12:01.543Z,1595020321.543 [Reporter](INFO): platform_buoyancy_position 637.897766 cc
2020-07-17T21:12:01.943Z,1595020321.943 [Reporter](INFO): platform_buoyancy_position 631.719971 cc
2020-07-17T21:12:02.380Z,1595020322.380 [Reporter](INFO): platform_buoyancy_position 627.153748 cc
2020-07-17T21:12:02.744Z,1595020322.744 [Reporter](INFO): platform_buoyancy_position 622.990479 cc
2020-07-17T21:12:03.145Z,1595020323.145 [Reporter](INFO): platform_buoyancy_position 616.544067 cc
2020-07-17T21:12:03.545Z,1595020323.545 [Reporter](INFO): platform_buoyancy_position 612.112183 cc
2020-07-17T21:12:03.995Z,1595020323.995 [Reporter](INFO): platform_buoyancy_position 605.665771 cc
2020-07-17T21:12:04.365Z,1595020324.365 [Reporter](INFO): platform_buoyancy_position 601.099548 cc
2020-07-17T21:12:04.747Z,1595020324.747 [Reporter](INFO): platform_buoyancy_position 595.056030 cc
2020-07-17T21:12:05.147Z,1595020325.147 [Reporter](INFO): platform_buoyancy_position 590.758484 cc
2020-07-17T21:12:05.563Z,1595020325.563 [Reporter](INFO): platform_buoyancy_position 584.312073 cc
2020-07-17T21:12:05.983Z,1595020325.983 [Reporter](INFO): platform_buoyancy_position 579.880127 cc
2020-07-17T21:12:06.356Z,1595020326.356 [Reporter](INFO): platform_buoyancy_position 573.568054 cc
2020-07-17T21:12:06.767Z,1595020326.767 [Reporter](INFO): platform_buoyancy_position 569.136169 cc
2020-07-17T21:12:07.179Z,1595020327.179 [Reporter](INFO): platform_buoyancy_position 562.824036 cc
2020-07-17T21:12:07.599Z,1595020327.599 [Reporter](INFO): platform_buoyancy_position 558.526428 cc
2020-07-17T21:12:08.007Z,1595020328.007 [Reporter](INFO): platform_buoyancy_position 553.557373 cc
2020-07-17T21:12:08.391Z,1595020328.391 [Reporter](INFO): platform_buoyancy_position 547.782471 cc
2020-07-17T21:12:08.799Z,1595020328.799 [Reporter](INFO): platform_buoyancy_position 543.350525 cc
2020-07-17T21:12:09.211Z,1595020329.211 [Reporter](INFO): platform_buoyancy_position 536.904175 cc
2020-07-17T21:12:09.615Z,1595020329.615 [Reporter](INFO): platform_buoyancy_position 532.740845 cc
2020-07-17T21:12:10.008Z,1595020330.008 [Reporter](INFO): platform_buoyancy_position 526.294434 cc
2020-07-17T21:12:10.427Z,1595020330.427 [Reporter](INFO): platform_buoyancy_position 521.862549 cc
2020-07-17T21:12:10.824Z,1595020330.824 [Reporter](INFO): platform_buoyancy_position 515.550476 cc
2020-07-17T21:12:11.216Z,1595020331.216 [Reporter](INFO): platform_buoyancy_position 511.252838 cc
2020-07-17T21:12:11.627Z,1595020331.627 [Reporter](INFO): platform_buoyancy_position 504.806458 cc
2020-07-17T21:12:12.047Z,1595020332.047 [Reporter](INFO): platform_buoyancy_position 500.374603 cc
2020-07-17T21:12:12.435Z,1595020332.435 [Reporter](INFO): platform_buoyancy_position 494.196777 cc
2020-07-17T21:12:12.830Z,1595020332.830 [Reporter](INFO): platform_buoyancy_position 489.764862 cc
2020-07-17T21:12:13.239Z,1595020333.239 [Reporter](INFO): platform_buoyancy_position 485.467224 cc
2020-07-17T21:12:13.658Z,1595020333.658 [Reporter](INFO): platform_buoyancy_position 479.020874 cc
2020-07-17T21:12:14.067Z,1595020334.067 [Reporter](INFO): platform_buoyancy_position 474.454651 cc
2020-07-17T21:12:14.443Z,1595020334.443 [Reporter](INFO): platform_buoyancy_position 468.142578 cc
2020-07-17T21:12:14.859Z,1595020334.859 [Reporter](INFO): platform_buoyancy_position 463.710632 cc
2020-07-17T21:12:15.276Z,1595020335.276 [Reporter](INFO): platform_buoyancy_position 457.532837 cc
2020-07-17T21:12:15.694Z,1595020335.694 [Reporter](INFO): platform_buoyancy_position 452.966675 cc
2020-07-17T21:12:16.071Z,1595020336.071 [Reporter](INFO): platform_buoyancy_position 446.788818 cc
2020-07-17T21:12:16.471Z,1595020336.471 [Reporter](INFO): platform_buoyancy_position 442.491272 cc
2020-07-17T21:12:16.895Z,1595020336.895 [Reporter](INFO): platform_buoyancy_position 436.044861 cc
2020-07-17T21:12:17.264Z,1595020337.264 [Reporter](INFO): platform_buoyancy_position 431.747253 cc
2020-07-17T21:12:17.743Z,1595020337.743 [Reporter](INFO): platform_buoyancy_position 425.300842 cc
2020-07-17T21:12:18.099Z,1595020338.099 [Reporter](INFO): platform_buoyancy_position 420.868958 cc
2020-07-17T21:12:18.479Z,1595020338.479 [Reporter](INFO): platform_buoyancy_position 414.556824 cc
2020-07-17T21:12:18.895Z,1595020338.895 [Reporter](INFO): platform_buoyancy_position 410.124939 cc
2020-07-17T21:12:19.351Z,1595020339.351 [Reporter](INFO): platform_buoyancy_position 403.678528 cc
2020-07-17T21:12:19.719Z,1595020339.719 [Reporter](INFO): platform_buoyancy_position 399.380920 cc
2020-07-17T21:12:20.091Z,1595020340.091 [Reporter](INFO): platform_buoyancy_position 394.949036 cc
2020-07-17T21:12:20.504Z,1595020340.504 [Reporter](INFO): platform_buoyancy_position 388.905518 cc
2020-07-17T21:12:20.928Z,1595020340.928 [Reporter](INFO): platform_buoyancy_position 382.862061 cc
2020-07-17T21:12:21.334Z,1595020341.334 [Reporter](INFO): platform_buoyancy_position 378.027222 cc
2020-07-17T21:12:21.719Z,1595020341.719 [Reporter](INFO): platform_buoyancy_position 373.595337 cc
2020-07-17T21:12:22.128Z,1595020342.128 [Reporter](INFO): platform_buoyancy_position 367.148926 cc
2020-07-17T21:12:22.582Z,1595020342.582 [Reporter](INFO): platform_buoyancy_position 361.239746 cc
2020-07-17T21:12:22.984Z,1595020342.984 [Reporter](INFO): platform_buoyancy_position 356.539246 cc
2020-07-17T21:12:23.355Z,1595020343.355 [Reporter](INFO): platform_buoyancy_position 352.107361 cc
2020-07-17T21:12:23.783Z,1595020343.783 [Reporter](INFO): platform_buoyancy_position 347.809753 cc
2020-07-17T21:12:24.145Z,1595020344.145 [Reporter](INFO): platform_buoyancy_position 342.169128 cc
2020-07-17T21:12:24.584Z,1595020344.584 [Reporter](INFO): platform_buoyancy_position 335.185547 cc
2020-07-17T21:12:24.987Z,1595020344.987 [Reporter](INFO): platform_buoyancy_position 330.753662 cc
2020-07-17T21:12:25.399Z,1595020345.399 [Reporter](INFO): platform_buoyancy_position 324.307251 cc
2020-07-17T21:12:25.709Z,1595020345.709 [DVL_micro](ERROR): Failed to parse:
:WI,-00452,+00052,+00021,+00000,A
2020-07-17T21:12:25.818Z,1595020345.818 [Reporter](INFO): platform_buoyancy_position 319.875366 cc
2020-07-17T21:12:26.187Z,1595020346.187 [Reporter](INFO): platform_buoyancy_position 315.577759 cc
2020-07-17T21:12:26.571Z,1595020346.571 [Reporter](INFO): platform_buoyancy_position 309.265625 cc
2020-07-17T21:12:26.970Z,1595020346.970 [Reporter](INFO): platform_buoyancy_position 304.968048 cc
2020-07-17T21:12:27.380Z,1595020347.380 [Reporter](INFO): platform_buoyancy_position 298.521637 cc
2020-07-17T21:12:27.799Z,1595020347.799 [Reporter](INFO): platform_buoyancy_position 292.478149 cc
2020-07-17T21:12:28.171Z,1595020348.171 [Reporter](INFO): platform_buoyancy_position 287.777649 cc
2020-07-17T21:12:28.598Z,1595020348.598 [Reporter](INFO): platform_buoyancy_position 283.480042 cc
2020-07-17T21:12:28.988Z,1595020348.988 [Reporter](INFO): platform_buoyancy_position 277.033630 cc
2020-07-17T21:12:29.415Z,1595020349.415 [Reporter](INFO): platform_buoyancy_position 272.333130 cc
2020-07-17T21:12:29.803Z,1595020349.803 [Reporter](INFO): platform_buoyancy_position 266.423920 cc
2020-07-17T21:12:30.213Z,1595020350.213 [Reporter](INFO): platform_buoyancy_position 261.857727 cc
2020-07-17T21:12:30.627Z,1595020350.627 [Reporter](INFO): platform_buoyancy_position 255.545624 cc
2020-07-17T21:12:31.032Z,1595020351.032 [Reporter](INFO): platform_buoyancy_position 251.113724 cc
2020-07-17T21:12:31.444Z,1595020351.444 [Reporter](INFO): platform_buoyancy_position 244.801636 cc
2020-07-17T21:12:31.831Z,1595020351.831 [Reporter](INFO): platform_buoyancy_position 240.369720 cc
2020-07-17T21:12:32.251Z,1595020352.251 [Reporter](INFO): platform_buoyancy_position 235.132019 cc
2020-07-17T21:12:32.703Z,1595020352.703 [Reporter](INFO): platform_buoyancy_position 229.625732 cc
2020-07-17T21:12:33.035Z,1595020353.035 [Reporter](INFO): platform_buoyancy_position 224.790924 cc
2020-07-17T21:12:33.455Z,1595020353.455 [Reporter](INFO): platform_buoyancy_position 219.016022 cc
2020-07-17T21:12:33.875Z,1595020353.875 [Reporter](INFO): platform_buoyancy_position 214.584137 cc
2020-07-17T21:12:34.279Z,1595020354.279 [Reporter](INFO): platform_buoyancy_position 208.272034 cc
2020-07-17T21:13:08.046Z,1595020388.046 [CommandLine](IMPORTANT): got command report clear
2020-07-17T21:13:12.202Z,1595020392.202 [CommandLine](IMPORTANT): got command maintain clear
2020-07-17T21:13:12.594Z,1595020392.594 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,DVL_micro,NAL9602,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,
2020-07-17T21:13:14.243Z,1595020394.243 [CommandLine](IMPORTANT): got command stop
2020-07-17T21:13:14.244Z,1595020394.244 [CommandLine](IMPORTANT): Scheduling is paused
2020-07-17T21:13:14.244Z,1595020394.244 [Supervisor](INFO): Stop Mission called by CommandLine::commandStop
2020-07-17T21:13:14.608Z,1595020394.608 [MissionManager](INFO): MissionManager is completed.
2020-07-17T21:13:14.608Z,1595020394.608 [MissionManager](INFO): Uninitializing Mission Science
2020-07-17T21:13:14.608Z,1595020394.608 [Science] Stopped
2020-07-17T21:13:14.608Z,1595020394.608 [Science](DEBUG): Aggregate::uninitialize Science
2020-07-17T21:13:14.608Z,1595020394.608 [Science:C] Stopped
2020-07-17T21:13:14.608Z,1595020394.608 [Science:D] Stopped
2020-07-17T21:13:14.608Z,1595020394.608 [Science:G] Stopped
2020-07-17T21:13:15.001Z,1595020395.001 [MissionManager](IMPORTANT): Started mission Default
2020-07-17T21:13:15.001Z,1595020395.001 [Default] Running Loop=1
2020-07-17T21:13:15.001Z,1595020395.001 [Default](DEBUG): Aggregate::initialize Default
2020-07-17T21:13:15.001Z,1595020395.001 [Default:B.GoToSurface] Running Loop=1
2020-07-17T21:13:15.001Z,1595020395.001 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-07-17T21:13:15.001Z,1595020395.001 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-07-17T21:13:15.002Z,1595020395.002 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-07-17T21:13:15.002Z,1595020395.002 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-07-17T21:13:15.002Z,1595020395.002 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-07-17T21:13:15.003Z,1595020395.003 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-07-17T21:13:15.003Z,1595020395.003 [Default:A.Wait] Running Loop=1
2020-07-17T21:13:15.003Z,1595020395.003 [Default:A.Wait](DEBUG): Initialize Wait Component.
2020-07-17T21:13:15.038Z,1595020395.038 [WetLabsBB2FL](INFO): Powering down
2020-07-17T21:13:28.344Z,1595020408.344 [Default:A.Wait](INFO): Done Waiting.
2020-07-17T21:13:28.344Z,1595020408.344 [Default:A.Wait] Stopped
2020-07-17T21:13:28.344Z,1595020408.344 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2020-07-17T21:13:28.742Z,1595020408.742 [Default:CheckIn] Running Loop=1
2020-07-17T21:13:28.742Z,1595020408.742 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-07-17T21:13:28.742Z,1595020408.742 [Default:CheckIn:Read_GPS] Running Loop=1
2020-07-17T21:13:30.747Z,1595020410.747 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,211329.00,A,3648.16603,N,12147.28644,W,0.175,0.00,170720,,,A*70
2020-07-17T21:13:30.749Z,1595020410.749 [NAL9602](INFO): GPS fix at 20200717T211329: (36.802767, -121.788107)
2020-07-17T21:13:30.760Z,1595020410.760 [Default:CheckIn:Read_GPS] Stopped
2020-07-17T21:13:30.760Z,1595020410.760 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-07-17T21:13:38.850Z,1595020418.850 [DataOverHttps](INFO): Sending 223 bytes from file Logs/20200717T203209/Courier0013.lzma
2020-07-17T21:13:39.851Z,1595020419.851 [DataOverHttps](INFO): Moved sent file to Logs/20200717T203209/Courier0013.lzma.bak
2020-07-17T21:13:39.852Z,1595020419.852 [DataOverHttps](INFO): SBD MOMSN=12446360
2020-07-17T21:13:56.174Z,1595020436.174 [DataOverHttps](INFO): Sending 746 bytes from file Logs/20200717T203209/Express0014.lzma
2020-07-17T21:13:57.175Z,1595020437.175 [DataOverHttps](INFO): Moved sent file to Logs/20200717T203209/Express0014.lzma.bak
2020-07-17T21:13:57.176Z,1595020437.176 [DataOverHttps](INFO): SBD MOMSN=12446363
2020-07-17T21:13:58.227Z,1595020438.227 [Default:CheckIn:Read_Iridium] Stopped
2020-07-17T21:13:58.228Z,1595020438.228 [Default:CheckIn:C.Wait] Running Loop=1
2020-07-17T21:13:58.228Z,1595020438.228 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-07-17T21:14:11.557Z,1595020451.557 [NAL9602](INFO): SBD MO Status=2, MOMSN=637, MT Status=2, MTMSN=0
2020-07-17T21:14:11.557Z,1595020451.557 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-07-17T21:14:32.971Z,1595020472.971 [DVL_micro](ERROR): Failed to parse:
:B,+00000,+00000,+00000,I
2020-07-17T21:14:51.553Z,1595020491.553 [NAL9602](INFO): SBD MO Status=2, MOMSN=637, MT Status=2, MTMSN=0
2020-07-17T21:14:51.553Z,1595020491.553 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-07-17T21:15:08.519Z,1595020508.519 [NAL9602](INFO): SBD MO Status=2, MOMSN=637, MT Status=2, MTMSN=0
2020-07-17T21:15:08.519Z,1595020508.519 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-07-17T21:16:30.538Z,1595020590.538 [NAL9602](INFO): SBD MO Status=0, MOMSN=637, MT Status=0, MTMSN=0
2020-07-17T21:16:30.538Z,1595020590.538 [NAL9602](INFO): No messages in MT queue
2020-07-17T21:16:32.961Z,1595020592.961 [DVL_micro](ERROR): only read 0 of 4 data items
2020-07-17T21:16:32.961Z,1595020592.961 [DVL_micro](ERROR): Failed to parse:
:RD,,+9999.999,+9999.99
2020-07-17T21:17:01.254Z,1595020621.254 [NAL9602](INFO): Not Powering down - fast GPS
2020-07-17T21:18:14.571Z,1595020694.571 [DataOverHttps](IMPORTANT): SBD MTMSN=20200717T211813
2020-07-17T21:18:21.950Z,1595020701.950 [DataOverHttps](INFO): Received command:ibit
2020-07-17T21:18:22.038Z,1595020702.038 [CommandLine](IMPORTANT): got command ibit
2020-07-17T21:18:22.117Z,1595020702.117 [IBIT](IMPORTANT): Beginning Initiated BIT
2020-07-17T21:18:22.117Z,1595020702.117 [IBIT](IMPORTANT): Beginning control surface checks.
2020-07-17T21:18:22.132Z,1595020702.132 [CBIT](IMPORTANT): Beginning ground fault scan
2020-07-17T21:18:23.649Z,1595020703.649 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,211821.00,A,3648.16184,N,12147.24756,W,3.168,148.23,170720,,,A*76
2020-07-17T21:18:23.651Z,1595020703.651 [NAL9602](INFO): GPS fix at 20200717T211821: (36.802697, -121.787459)
2020-07-17T21:18:33.034Z,1595020713.034 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): 0.018497
CHAN A1 (24V): 0.027802
CHAN A2 (12V): -0.000148
CHAN A3 (5V): -0.007311
CHAN B0 (3.3V): -0.006656
CHAN B1 (3.15aV): -0.005120
CHAN B2 (3.15bV): -0.003945
CHAN B3 (GND): -0.008085
OPEN: 0.004000
Full Scale Calc: 4.765 mA, -1.589 mA
2020-07-17T21:18:49.509Z,1595020729.509 [NAL9602](INFO): SBD MO Status=0, MOMSN=638, MT Status=0, MTMSN=0
2020-07-17T21:18:49.509Z,1595020729.509 [NAL9602](INFO): No messages in MT queue
2020-07-17T21:18:50.721Z,1595020730.721 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,211849.00,A,3648.14482,N,12147.25289,W,1.341,128.51,170720,,,D*72
2020-07-17T21:18:50.732Z,1595020730.732 [NAL9602](INFO): GPS fix at 20200717T211849: (36.802414, -121.787548)
2020-07-17T21:18:53.949Z,1595020733.949 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,211852.00,A,3648.14457,N,12147.25144,W,1.983,122.05,170720,,,D*7D
2020-07-17T21:18:53.951Z,1595020733.951 [NAL9602](INFO): GPS fix at 20200717T211852: (36.802410, -121.787524)
2020-07-17T21:18:56.786Z,1595020736.786 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,211855.00,A,3648.14365,N,12147.24975,W,1.711,121.27,170720,,,D*71
2020-07-17T21:18:56.788Z,1595020736.788 [NAL9602](INFO): GPS fix at 20200717T211855: (36.802394, -121.787496)
2020-07-17T21:19:00.013Z,1595020740.013 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,211858.00,A,3648.14224,N,12147.24702,W,2.644,120.49,170720,,,D*7D
2020-07-17T21:19:00.015Z,1595020740.015 [NAL9602](INFO): GPS fix at 20200717T211858: (36.802371, -121.787450)
2020-07-17T21:19:02.841Z,1595020742.841 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,211901.00,A,3648.14106,N,12147.24398,W,3.227,117.01,170720,,,D*7C
2020-07-17T21:19:02.844Z,1595020742.844 [NAL9602](INFO): GPS fix at 20200717T211901: (36.802351, -121.787400)
2020-07-17T21:19:06.073Z,1595020746.073 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,211904.00,A,3648.13922,N,12147.24073,W,3.324,125.79,170720,,,D*7A
2020-07-17T21:19:06.075Z,1595020746.075 [NAL9602](INFO): GPS fix at 20200717T211904: (36.802320, -121.787346)
2020-07-17T21:19:08.533Z,1595020748.533 [IBIT](IMPORTANT): Communications Status:
Fix Status: 1
Iridium Signal Strength: 2
Latitude: 36.802319 Longitude: -121.787346
2020-07-17T21:19:08.906Z,1595020748.906 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,211907.00,A,3648.13820,N,12147.23855,W,2.041,116.03,170720,,,D*7D
2020-07-17T21:19:08.908Z,1595020748.908 [NAL9602](INFO): GPS fix at 20200717T211907: (36.802303, -121.787309)
2020-07-17T21:19:08.964Z,1595020748.964 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 0.000000
Voltage: 16.532000
2020-07-17T21:19:08.964Z,1595020748.964 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah
2020-07-17T21:19:08.964Z,1595020748.964 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V
2020-07-17T21:19:09.340Z,1595020749.340 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2020-07-17T21:19:09.340Z,1595020749.340 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2020-07-17T21:19:09.340Z,1595020749.340 [IBIT](IMPORTANT): Pressure:7.633410 PSI
2020-07-17T21:19:09.341Z,1595020749.341 [IBIT](IMPORTANT): Humidity:11.421072 %
2020-07-17T21:19:09.734Z,1595020749.734 [IBIT](IMPORTANT): Vehicle Pitch:-1.979895 degrees
2020-07-17T21:19:09.734Z,1595020749.734 [IBIT](IMPORTANT): Vehicle Roll:-8.982980 degrees
2020-07-17T21:19:09.734Z,1595020749.734 [IBIT](IMPORTANT): Vehicle Heading:5.146848 degrees
2020-07-17T21:19:10.127Z,1595020750.127 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2020-07-17T21:19:10.127Z,1595020750.127 [IBIT](IMPORTANT): buoyancyNeutral: 236.199997 cc
2020-07-17T21:19:10.128Z,1595020750.128 [IBIT](IMPORTANT): massDefault: 0.477000 cm
2020-07-17T21:19:10.128Z,1595020750.128 [IBIT](IMPORTANT): stopDepth: 265.000000 m
2020-07-17T21:19:10.128Z,1595020750.128 [IBIT](IMPORTANT): abortDepth: 300.000000 m
2020-07-17T21:19:10.128Z,1595020750.128 [IBIT](IMPORTANT): IBIT PASSED
2020-07-17T21:19:10.532Z,1595020750.532 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-07-17T21:19:10.532Z,1595020750.532 [Default:CheckIn:C.Wait] Stopped
2020-07-17T21:19:10.532Z,1595020750.532 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-07-17T21:19:10.533Z,1595020750.533 [Default:CheckIn:D] Running Loop=1
2020-07-17T21:19:10.939Z,1595020750.939 [Default:CheckIn:D] Stopped
2020-07-17T21:19:10.939Z,1595020750.939 [Default:CheckIn:E] Running Loop=1
2020-07-17T21:19:11.363Z,1595020751.363 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 5.932299 min
2020-07-17T21:19:11.364Z,1595020751.364 [Default:CheckIn:E] Stopped
2020-07-17T21:19:11.364Z,1595020751.364 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-07-17T21:19:11.364Z,1595020751.364 [Default:CheckIn] Stopped
2020-07-17T21:19:11.364Z,1595020751.364 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-07-17T21:19:11.364Z,1595020751.364 [Default:CheckIn](INFO): Running loop #2
2020-07-17T21:19:11.364Z,1595020751.364 [Default:CheckIn] Running Loop=2
2020-07-17T21:19:11.364Z,1595020751.364 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-07-17T21:19:11.364Z,1595020751.364 [Default:CheckIn:Read_GPS] Running Loop=1
2020-07-17T21:19:13.345Z,1595020753.345 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,211911.00,A,3648.13679,N,12147.23518,W,2.721,110.60,170720,,,D*7E
2020-07-17T21:19:13.348Z,1595020753.348 [NAL9602](INFO): GPS fix at 20200717T211911: (36.802280, -121.787253)
2020-07-17T21:19:13.358Z,1595020753.358 [Default:CheckIn:Read_GPS] Stopped
2020-07-17T21:19:13.358Z,1595020753.358 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-07-17T21:19:20.997Z,1595020760.997 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20200717T203209/Courier0016.lzma
2020-07-17T21:19:21.999Z,1595020761.999 [DataOverHttps](INFO): Moved sent file to Logs/20200717T203209/Courier0016.lzma.bak
2020-07-17T21:19:21.000Z,1595020762.000 [DataOverHttps](INFO): SBD MOMSN=12446391
2020-07-17T21:19:22.055Z,1595020762.055 [CommandLine](IMPORTANT): got command failComponent
2020-07-17T21:19:22.056Z,1595020762.056 [CommandLine](IMPORTANT): Failed components:
2020-07-17T21:19:22.056Z,1595020762.056 [CommandLine](IMPORTANT): No failed Components.
2020-07-17T21:19:37.794Z,1595020777.794 [DataOverHttps](INFO): Sending 816 bytes from file Logs/20200717T203209/Express0017.lzma
2020-07-17T21:19:38.795Z,1595020778.795 [DataOverHttps](INFO): Moved sent file to Logs/20200717T203209/Express0017.lzma.bak
2020-07-17T21:19:38.795Z,1595020778.795 [DataOverHttps](INFO): SBD MOMSN=12446394
2020-07-17T21:19:40.017Z,1595020780.017 [Default:CheckIn:Read_Iridium] Stopped
2020-07-17T21:19:40.017Z,1595020780.017 [Default:CheckIn:C.Wait] Running Loop=1
2020-07-17T21:19:40.018Z,1595020780.018 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-07-17T21:19:45.255Z,1595020785.255 [NAL9602](INFO): Not Powering down - fast GPS
2020-07-17T21:20:33.333Z,1595020833.333 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2020-07-17T21:20:33.334Z,1595020833.334 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+17.9,489.0,000
2020-07-17T21:22:51.554Z,1595020971.554 [DVL_micro](ERROR): Failed to parse:
9.99,+9999.99,+9999.99,+9999.99
2020-07-17T21:24:40.625Z,1595021080.625 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-07-17T21:24:40.625Z,1595021080.625 [Default:CheckIn:C.Wait] Stopped
2020-07-17T21:24:40.625Z,1595021080.625 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-07-17T21:24:40.625Z,1595021080.625 [Default:CheckIn:D] Running Loop=1
2020-07-17T21:24:41.026Z,1595021081.026 [Default:CheckIn:D] Stopped
2020-07-17T21:24:41.026Z,1595021081.026 [Default:CheckIn:E] Running Loop=1
2020-07-17T21:24:41.444Z,1595021081.444 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 11.433751 min
2020-07-17T21:24:41.444Z,1595021081.444 [Default:CheckIn:E] Stopped
2020-07-17T21:24:41.444Z,1595021081.444 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-07-17T21:24:41.444Z,1595021081.444 [Default:CheckIn] Stopped
2020-07-17T21:24:41.445Z,1595021081.445 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-07-17T21:24:41.445Z,1595021081.445 [Default:CheckIn](INFO): Running loop #3
2020-07-17T21:24:41.445Z,1595021081.445 [Default:CheckIn] Running Loop=3
2020-07-17T21:24:41.445Z,1595021081.445 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-07-17T21:24:41.445Z,1595021081.445 [Default:CheckIn:Read_GPS] Running Loop=1
2020-07-17T21:24:43.441Z,1595021083.441 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,212442.00,A,3648.14034,N,12147.20973,W,0.039,29.29,170720,,,D*46
2020-07-17T21:24:43.443Z,1595021083.443 [NAL9602](INFO): GPS fix at 20200717T212442: (36.802339, -121.786829)
2020-07-17T21:24:43.453Z,1595021083.453 [Default:CheckIn:Read_GPS] Stopped
2020-07-17T21:24:43.453Z,1595021083.453 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-07-17T21:24:51.125Z,1595021091.125 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20200717T203209/Courier0022.lzma
2020-07-17T21:24:52.127Z,1595021092.127 [DataOverHttps](INFO): Moved sent file to Logs/20200717T203209/Courier0022.lzma.bak
2020-07-17T21:24:52.128Z,1595021092.128 [DataOverHttps](INFO): SBD MOMSN=12446420
2020-07-17T21:24:58.401Z,1595021098.401 [NAL9602](INFO): SBD MO Status=0, MOMSN=639, MT Status=0, MTMSN=0
2020-07-17T21:24:58.401Z,1595021098.401 [NAL9602](INFO): No messages in MT queue
2020-07-17T21:25:08.106Z,1595021108.106 [DataOverHttps](INFO): Sending 188 bytes from file Logs/20200717T203209/Express0023.lzma
2020-07-17T21:25:09.108Z,1595021109.108 [DataOverHttps](INFO): Moved sent file to Logs/20200717T203209/Express0023.lzma.bak
2020-07-17T21:25:09.108Z,1595021109.108 [DataOverHttps](INFO): SBD MOMSN=12446423
2020-07-17T21:25:10.132Z,1595021110.132 [Default:CheckIn:Read_Iridium] Stopped
2020-07-17T21:25:10.132Z,1595021110.132 [Default:CheckIn:C.Wait] Running Loop=1
2020-07-17T21:25:10.132Z,1595021110.132 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-07-17T21:25:29.096Z,1595021129.096 [NAL9602](INFO): Not Powering down - fast GPS
2020-07-17T21:30:10.702Z,1595021410.702 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-07-17T21:30:10.702Z,1595021410.702 [Default:CheckIn:C.Wait] Stopped
2020-07-17T21:30:10.702Z,1595021410.702 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-07-17T21:30:10.703Z,1595021410.703 [Default:CheckIn:D] Running Loop=1
2020-07-17T21:30:11.098Z,1595021411.098 [Default:CheckIn:D] Stopped
2020-07-17T21:30:11.099Z,1595021411.099 [Default:CheckIn:E] Running Loop=1
2020-07-17T21:30:11.515Z,1595021411.515 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 16.934958 min
2020-07-17T21:30:11.515Z,1595021411.515 [Default:CheckIn:E] Stopped
2020-07-17T21:30:11.515Z,1595021411.515 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-07-17T21:30:11.515Z,1595021411.515 [Default:CheckIn] Stopped
2020-07-17T21:30:11.515Z,1595021411.515 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-07-17T21:30:11.515Z,1595021411.515 [Default:CheckIn](INFO): Running loop #4
2020-07-17T21:30:11.515Z,1595021411.515 [Default:CheckIn] Running Loop=4
2020-07-17T21:30:11.515Z,1595021411.515 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-07-17T21:30:11.515Z,1595021411.515 [Default:CheckIn:Read_GPS] Running Loop=1
2020-07-17T21:30:13.520Z,1595021413.520 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,213012.00,A,3648.13962,N,12147.20873,W,0.019,29.29,170720,,,A*4D
2020-07-17T21:30:13.522Z,1595021413.522 [NAL9602](INFO): GPS fix at 20200717T213012: (36.802327, -121.786812)
2020-07-17T21:30:13.546Z,1595021413.546 [Default:CheckIn:Read_GPS] Stopped
2020-07-17T21:30:13.546Z,1595021413.546 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-07-17T21:30:21.273Z,1595021421.273 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20200717T203209/Courier0025.lzma
2020-07-17T21:30:22.275Z,1595021422.275 [DataOverHttps](INFO): Moved sent file to Logs/20200717T203209/Courier0025.lzma.bak
2020-07-17T21:30:22.276Z,1595021422.276 [DataOverHttps](INFO): SBD MOMSN=12446439
2020-07-17T21:30:27.669Z,1595021427.669 [NAL9602](INFO): SBD MO Status=0, MOMSN=640, MT Status=0, MTMSN=0
2020-07-17T21:30:27.669Z,1595021427.669 [NAL9602](INFO): No messages in MT queue
2020-07-17T21:30:38.573Z,1595021438.573 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20200717T203209/Express0026.lzma
2020-07-17T21:30:39.575Z,1595021439.575 [DataOverHttps](INFO): Moved sent file to Logs/20200717T203209/Express0026.lzma.bak
2020-07-17T21:30:39.576Z,1595021439.576 [DataOverHttps](INFO): SBD MOMSN=12446442
2020-07-17T21:30:40.613Z,1595021440.613 [Default:CheckIn:Read_Iridium] Stopped
2020-07-17T21:30:40.613Z,1595021440.613 [Default:CheckIn:C.Wait] Running Loop=1
2020-07-17T21:30:40.613Z,1595021440.613 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-07-17T21:30:58.369Z,1595021458.369 [NAL9602](INFO): Not Powering down - fast GPS
2020-07-17T21:32:09.080Z,1595021529.080 [DVL_micro](ERROR): only read 3 of 4 data items
2020-07-17T21:32:09.080Z,1595021529.080 [DVL_micro](ERROR): Failed to parse:
:BI,-00225,-00028,+00035,+000D,+00000000.00,+0000000000000.00,9999.99,000.00
2020-07-17T21:35:41.227Z,1595021741.227 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-07-17T21:35:41.227Z,1595021741.227 [Default:CheckIn:C.Wait] Stopped
2020-07-17T21:35:41.227Z,1595021741.227 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-07-17T21:35:41.227Z,1595021741.227 [Default:CheckIn:D] Running Loop=1
2020-07-17T21:35:41.633Z,1595021741.633 [Default:CheckIn:D] Stopped
2020-07-17T21:35:41.633Z,1595021741.633 [Default:CheckIn:E] Running Loop=1
2020-07-17T21:35:42.020Z,1595021742.020 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 22.443866 min
2020-07-17T21:35:42.020Z,1595021742.020 [Default:CheckIn:E] Stopped
2020-07-17T21:35:42.020Z,1595021742.020 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-07-17T21:35:42.020Z,1595021742.020 [Default:CheckIn] Stopped
2020-07-17T21:35:42.020Z,1595021742.020 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-07-17T21:35:42.020Z,1595021742.020 [Default:CheckIn](INFO): Running loop #5
2020-07-17T21:35:42.020Z,1595021742.020 [Default:CheckIn] Running Loop=5
2020-07-17T21:35:42.020Z,1595021742.020 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-07-17T21:35:42.020Z,1595021742.020 [Default:CheckIn:Read_GPS] Running Loop=1
2020-07-17T21:35:44.037Z,1595021744.037 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,213543.00,A,3648.14009,N,12147.20825,W,0.019,29.29,170720,,,A*4C
2020-07-17T21:35:44.039Z,1595021744.039 [NAL9602](INFO): GPS fix at 20200717T213543: (36.802335, -121.786804)
2020-07-17T21:35:44.054Z,1595021744.054 [Default:CheckIn:Read_GPS] Stopped
2020-07-17T21:35:44.054Z,1595021744.054 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-07-17T21:35:51.833Z,1595021751.833 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20200717T203209/Courier0028.lzma
2020-07-17T21:35:52.836Z,1595021752.836 [DataOverHttps](INFO): Moved sent file to Logs/20200717T203209/Courier0028.lzma.bak
2020-07-17T21:35:52.836Z,1595021752.836 [DataOverHttps](INFO): SBD MOMSN=12446446
2020-07-17T21:36:00.192Z,1595021760.192 [NAL9602](INFO): SBD MO Status=0, MOMSN=641, MT Status=0, MTMSN=0
2020-07-17T21:36:00.193Z,1595021760.193 [NAL9602](INFO): No messages in MT queue
2020-07-17T21:36:08.673Z,1595021768.673 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20200717T203209/Express0029.lzma
2020-07-17T21:36:09.680Z,1595021769.680 [DataOverHttps](INFO): Moved sent file to Logs/20200717T203209/Express0029.lzma.bak
2020-07-17T21:36:09.680Z,1595021769.680 [DataOverHttps](INFO): SBD MOMSN=12446449
2020-07-17T21:36:10.719Z,1595021770.719 [Default:CheckIn:Read_Iridium] Stopped
2020-07-17T21:36:10.719Z,1595021770.719 [Default:CheckIn:C.Wait] Running Loop=1
2020-07-17T21:36:10.719Z,1595021770.719 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-07-17T21:36:30.920Z,1595021790.920 [NAL9602](INFO): Not Powering down - fast GPS
2020-07-17T21:40:11.914Z,1595022011.914 [DVL_micro](ERROR): Failed to parse:
:SA,-00.87,-04.96,016.1
2020-07-17T21:41:11.328Z,1595022071.328 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-07-17T21:41:11.328Z,1595022071.328 [Default:CheckIn:C.Wait] Stopped
2020-07-17T21:41:11.328Z,1595022071.328 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-07-17T21:41:11.329Z,1595022071.329 [Default:CheckIn:D] Running Loop=1
2020-07-17T21:41:11.723Z,1595022071.723 [Default:CheckIn:D] Stopped
2020-07-17T21:41:11.723Z,1595022071.723 [Default:CheckIn:E] Running Loop=1
2020-07-17T21:41:12.133Z,1595022072.133 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 27.945369 min
2020-07-17T21:41:12.133Z,1595022072.133 [Default:CheckIn:E] Stopped
2020-07-17T21:41:12.133Z,1595022072.133 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-07-17T21:41:12.133Z,1595022072.133 [Default:CheckIn] Stopped
2020-07-17T21:41:12.133Z,1595022072.133 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-07-17T21:41:12.134Z,1595022072.134 [Default:CheckIn](INFO): Running loop #6
2020-07-17T21:41:12.134Z,1595022072.134 [Default:CheckIn] Running Loop=6
2020-07-17T21:41:12.134Z,1595022072.134 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-07-17T21:41:12.134Z,1595022072.134 [Default:CheckIn:Read_GPS] Running Loop=1
2020-07-17T21:41:14.141Z,1595022074.141 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,214113.00,A,3648.14061,N,12147.20994,W,0.019,29.29,170720,,,A*4F
2020-07-17T21:41:14.143Z,1595022074.143 [NAL9602](INFO): GPS fix at 20200717T214113: (36.802343, -121.786832)
2020-07-17T21:41:14.177Z,1595022074.177 [Default:CheckIn:Read_GPS] Stopped
2020-07-17T21:41:14.177Z,1595022074.177 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-07-17T21:41:21.829Z,1595022081.829 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20200717T203209/Courier0031.lzma
2020-07-17T21:41:22.831Z,1595022082.831 [DataOverHttps](INFO): Moved sent file to Logs/20200717T203209/Courier0031.lzma.bak
2020-07-17T21:41:22.832Z,1595022082.832 [DataOverHttps](INFO): SBD MOMSN=12446462
2020-07-17T21:41:27.877Z,1595022087.877 [NAL9602](INFO): SBD MO Status=0, MOMSN=642, MT Status=0, MTMSN=0
2020-07-17T21:41:27.877Z,1595022087.877 [NAL9602](INFO): No messages in MT queue
2020-07-17T21:41:38.689Z,1595022098.689 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20200717T203209/Express0032.lzma
2020-07-17T21:41:39.692Z,1595022099.692 [DataOverHttps](INFO): Moved sent file to Logs/20200717T203209/Express0032.lzma.bak
2020-07-17T21:41:39.692Z,1595022099.692 [DataOverHttps](INFO): SBD MOMSN=12446465
2020-07-17T21:41:40.817Z,1595022100.817 [Default:CheckIn:Read_Iridium] Stopped
2020-07-17T21:41:40.817Z,1595022100.817 [Default:CheckIn:C.Wait] Running Loop=1
2020-07-17T21:41:40.817Z,1595022100.817 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-07-17T21:41:58.583Z,1595022118.583 [NAL9602](INFO): Not Powering down - fast GPS
2020-07-17T21:46:17.145Z,1595022377.145 [DVL_micro](ERROR): Failed to parse:
:9,+00110,-0000,I
2020-07-17T21:46:41.401Z,1595022401.401 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-07-17T21:46:41.401Z,1595022401.401 [Default:CheckIn:C.Wait] Stopped
2020-07-17T21:46:41.401Z,1595022401.401 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-07-17T21:46:41.402Z,1595022401.402 [Default:CheckIn:D] Running Loop=1
2020-07-17T21:46:41.797Z,1595022401.797 [Default:CheckIn:D] Stopped
2020-07-17T21:46:41.798Z,1595022401.798 [Default:CheckIn:E] Running Loop=1
2020-07-17T21:46:42.197Z,1595022402.197 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 33.446606 min
2020-07-17T21:46:42.197Z,1595022402.197 [Default:CheckIn:E] Stopped
2020-07-17T21:46:42.198Z,1595022402.198 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-07-17T21:46:42.198Z,1595022402.198 [Default:CheckIn] Stopped
2020-07-17T21:46:42.198Z,1595022402.198 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-07-17T21:46:42.198Z,1595022402.198 [Default:CheckIn](INFO): Running loop #7
2020-07-17T21:46:42.198Z,1595022402.198 [Default:CheckIn] Running Loop=7
2020-07-17T21:46:42.198Z,1595022402.198 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-07-17T21:46:42.198Z,1595022402.198 [Default:CheckIn:Read_GPS] Running Loop=1
2020-07-17T21:46:44.217Z,1595022404.217 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,214643.00,A,3648.13995,N,12147.20879,W,0.019,29.29,170720,,,A*4A
2020-07-17T21:46:44.219Z,1595022404.219 [NAL9602](INFO): GPS fix at 20200717T214643: (36.802332, -121.786813)
2020-07-17T21:46:44.230Z,1595022404.230 [Default:CheckIn:Read_GPS] Stopped
2020-07-17T21:46:44.230Z,1595022404.230 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-07-17T21:46:47.844Z,1595022407.844 [DVL_micro](ERROR): Failed to parse:
:SA,-00.92,-04.99,016.1
2020-07-17T21:46:52.233Z,1595022412.233 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20200717T203209/Courier0034.lzma
2020-07-17T21:46:53.236Z,1595022413.236 [DataOverHttps](INFO): Moved sent file to Logs/20200717T203209/Courier0034.lzma.bak
2020-07-17T21:46:53.236Z,1595022413.236 [DataOverHttps](INFO): SBD MOMSN=12446469
2020-07-17T21:47:09.409Z,1595022429.409 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20200717T203209/Express0035.lzma
2020-07-17T21:47:10.412Z,1595022430.412 [DataOverHttps](INFO): Moved sent file to Logs/20200717T203209/Express0035.lzma.bak
2020-07-17T21:47:10.412Z,1595022430.412 [DataOverHttps](INFO): SBD MOMSN=12446472
2020-07-17T21:47:11.706Z,1595022431.706 [Default:CheckIn:Read_Iridium] Stopped
2020-07-17T21:47:11.706Z,1595022431.706 [Default:CheckIn:C.Wait] Running Loop=1
2020-07-17T21:47:11.707Z,1595022431.707 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-07-17T21:47:21.381Z,1595022441.381 [NAL9602](INFO): SBD MO Status=0, MOMSN=643, MT Status=0, MTMSN=0
2020-07-17T21:47:21.381Z,1595022441.381 [NAL9602](INFO): No messages in MT queue
2020-07-17T21:47:52.079Z,1595022472.079 [NAL9602](INFO): Not Powering down - fast GPS
2020-07-17T21:48:19.569Z,1595022499.569 [DVL_micro](ERROR): Failed to parse:
:WI,-00045,+00352,+00186,+00000,A0045,+00352,+00186,+00000,I
2020-07-17T21:48:44.626Z,1595022524.626 [BPC1](ERROR): Battery stick #6 (s/n: 00CA) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0.
2020-07-17T21:48:44.626Z,1595022524.626 [BPC1](INFO): Calculating totals. Valid battery stick count: 55. Valid reserve battery stick count: 6.
2020-07-17T21:48:44.628Z,1595022524.628 [BPC1](INFO): Received data from all battery sticks.
2020-07-17T21:50:27.230Z,1595022627.230 [DVL_micro](ERROR): only read 3 of 4 data items
2020-07-17T21:50:27.230Z,1595022627.230 [DVL_micro](ERROR): Failed to parse:
:BI,+00367,+00093,+0020,I
2020-07-17T21:52:12.267Z,1595022732.267 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-07-17T21:52:12.267Z,1595022732.267 [Default:CheckIn:C.Wait] Stopped
2020-07-17T21:52:12.267Z,1595022732.267 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-07-17T21:52:12.268Z,1595022732.268 [Default:CheckIn:D] Running Loop=1
2020-07-17T21:52:12.677Z,1595022732.677 [Default:CheckIn:D] Stopped
2020-07-17T21:52:12.677Z,1595022732.677 [Default:CheckIn:E] Running Loop=1
2020-07-17T21:52:13.085Z,1595022733.085 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 38.961263 min
2020-07-17T21:52:13.085Z,1595022733.085 [Default:CheckIn:E] Stopped
2020-07-17T21:52:13.085Z,1595022733.085 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-07-17T21:52:13.085Z,1595022733.085 [Default:CheckIn] Stopped
2020-07-17T21:52:13.085Z,1595022733.085 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-07-17T21:52:13.085Z,1595022733.085 [Default:CheckIn](INFO): Running loop #8
2020-07-17T21:52:13.085Z,1595022733.085 [Default:CheckIn] Running Loop=8
2020-07-17T21:52:13.085Z,1595022733.085 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-07-17T21:52:13.086Z,1595022733.086 [Default:CheckIn:Read_GPS] Running Loop=1
2020-07-17T21:52:15.093Z,1595022735.093 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,215214.00,A,3648.13910,N,12147.20811,W,0.019,29.29,170720,,,A*4E
2020-07-17T21:52:15.103Z,1595022735.103 [NAL9602](INFO): GPS fix at 20200717T215214: (36.802318, -121.786802)
2020-07-17T21:52:15.114Z,1595022735.114 [Default:CheckIn:Read_GPS] Stopped
2020-07-17T21:52:15.114Z,1595022735.114 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-07-17T21:52:22.449Z,1595022742.449 [DataOverHttps](INFO): Sending 85 bytes from file Logs/20200717T203209/Courier0037.lzma
2020-07-17T21:52:23.452Z,1595022743.452 [DataOverHttps](INFO): Moved sent file to Logs/20200717T203209/Courier0037.lzma.bak
2020-07-17T21:52:23.452Z,1595022743.452 [DataOverHttps](INFO): SBD MOMSN=12446483
2020-07-17T21:52:30.050Z,1595022750.050 [NAL9602](INFO): SBD MO Status=0, MOMSN=644, MT Status=0, MTMSN=0
2020-07-17T21:52:30.050Z,1595022750.050 [NAL9602](INFO): No messages in MT queue
2020-07-17T21:52:39.201Z,1595022759.201 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20200717T203209/Express0038.lzma
2020-07-17T21:52:40.204Z,1595022760.204 [DataOverHttps](INFO): Moved sent file to Logs/20200717T203209/Express0038.lzma.bak
2020-07-17T21:52:40.204Z,1595022760.204 [DataOverHttps](INFO): SBD MOMSN=12446486
2020-07-17T21:52:41.365Z,1595022761.365 [Default:CheckIn:Read_Iridium] Stopped
2020-07-17T21:52:41.365Z,1595022761.365 [Default:CheckIn:C.Wait] Running Loop=1
2020-07-17T21:52:41.365Z,1595022761.365 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-07-17T21:53:00.741Z,1595022780.741 [NAL9602](INFO): Not Powering down - fast GPS
2020-07-17T21:57:41.953Z,1595023061.953 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-07-17T21:57:41.953Z,1595023061.953 [Default:CheckIn:C.Wait] Stopped
2020-07-17T21:57:41.953Z,1595023061.953 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-07-17T21:57:41.970Z,1595023061.970 [Default:CheckIn:D] Running Loop=1
2020-07-17T21:57:42.370Z,1595023062.370 [Default:CheckIn:D] Stopped
2020-07-17T21:57:42.370Z,1595023062.370 [Default:CheckIn:E] Running Loop=1
2020-07-17T21:57:42.765Z,1595023062.765 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 44.456156 min
2020-07-17T21:57:42.765Z,1595023062.765 [Default:CheckIn:E] Stopped
2020-07-17T21:57:42.765Z,1595023062.765 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-07-17T21:57:42.765Z,1595023062.765 [Default:CheckIn] Stopped
2020-07-17T21:57:42.765Z,1595023062.765 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-07-17T21:57:42.765Z,1595023062.765 [Default:CheckIn](INFO): Running loop #9
2020-07-17T21:57:42.765Z,1595023062.765 [Default:CheckIn] Running Loop=9
2020-07-17T21:57:42.765Z,1595023062.765 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-07-17T21:57:42.766Z,1595023062.766 [Default:CheckIn:Read_GPS] Running Loop=1
2020-07-17T21:57:44.773Z,1595023064.773 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,215744.00,A,3648.13831,N,12147.20475,W,0.039,169.13,170720,,,A*7C
2020-07-17T21:57:44.776Z,1595023064.776 [NAL9602](INFO): GPS fix at 20200717T215744: (36.802305, -121.786746)
2020-07-17T21:57:44.810Z,1595023064.810 [Default:CheckIn:Read_GPS] Stopped
2020-07-17T21:57:44.810Z,1595023064.810 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-07-17T21:57:52.021Z,1595023072.021 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20200717T203209/Courier0040.lzma
2020-07-17T21:57:53.023Z,1595023073.023 [DataOverHttps](INFO): Moved sent file to Logs/20200717T203209/Courier0040.lzma.bak
2020-07-17T21:57:53.024Z,1595023073.024 [DataOverHttps](INFO): SBD MOMSN=12446490
2020-07-17T21:58:08.817Z,1595023088.817 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20200717T203209/Express0041.lzma
2020-07-17T21:58:09.026Z,1595023089.026 [NAL9602](INFO): SBD MO Status=0, MOMSN=645, MT Status=0, MTMSN=0
2020-07-17T21:58:09.026Z,1595023089.026 [NAL9602](INFO): No messages in MT queue
2020-07-17T21:58:09.819Z,1595023089.819 [DataOverHttps](INFO): Moved sent file to Logs/20200717T203209/Express0041.lzma.bak
2020-07-17T21:58:09.820Z,1595023089.820 [DataOverHttps](INFO): SBD MOMSN=12446493
2020-07-17T21:58:11.053Z,1595023091.053 [Default:CheckIn:Read_Iridium] Stopped
2020-07-17T21:58:11.053Z,1595023091.053 [Default:CheckIn:C.Wait] Running Loop=1
2020-07-17T21:58:11.053Z,1595023091.053 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-07-17T21:58:39.730Z,1595023119.730 [NAL9602](INFO): Not Powering down - fast GPS
2020-07-17T22:03:11.655Z,1595023391.655 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-07-17T22:03:11.655Z,1595023391.655 [Default:CheckIn:C.Wait] Stopped
2020-07-17T22:03:11.655Z,1595023391.655 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-07-17T22:03:11.656Z,1595023391.656 [Default:CheckIn:D] Running Loop=1
2020-07-17T22:03:12.053Z,1595023392.053 [Default:CheckIn:D] Stopped
2020-07-17T22:03:12.053Z,1595023392.053 [Default:CheckIn:E] Running Loop=1
2020-07-17T22:03:12.470Z,1595023392.470 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 49.950867 min
2020-07-17T22:03:12.470Z,1595023392.470 [Default:CheckIn:E] Stopped
2020-07-17T22:03:12.470Z,1595023392.470 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-07-17T22:03:12.471Z,1595023392.471 [Default:CheckIn] Stopped
2020-07-17T22:03:12.471Z,1595023392.471 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-07-17T22:03:12.471Z,1595023392.471 [Default:CheckIn](INFO): Running loop #10
2020-07-17T22:03:12.471Z,1595023392.471 [Default:CheckIn] Running Loop=10
2020-07-17T22:03:12.471Z,1595023392.471 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-07-17T22:03:12.471Z,1595023392.471 [Default:CheckIn:Read_GPS] Running Loop=1
2020-07-17T22:03:14.473Z,1595023394.473 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,220313.00,A,3648.13893,N,12147.20528,W,0.019,169.13,170720,,,D*7A
2020-07-17T22:03:14.475Z,1595023394.475 [NAL9602](INFO): GPS fix at 20200717T220313: (36.802315, -121.786755)
2020-07-17T22:03:14.487Z,1595023394.487 [Default:CheckIn:Read_GPS] Stopped
2020-07-17T22:03:14.488Z,1595023394.488 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-07-17T22:03:22.449Z,1595023402.449 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20200717T203209/Courier0043.lzma
2020-07-17T22:03:23.451Z,1595023403.451 [DataOverHttps](INFO): Moved sent file to Logs/20200717T203209/Courier0043.lzma.bak
2020-07-17T22:03:23.452Z,1595023403.452 [DataOverHttps](INFO): SBD MOMSN=12446506
2020-07-17T22:03:39.210Z,1595023419.210 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20200717T203209/Express0044.lzma
2020-07-17T22:03:40.211Z,1595023420.211 [DataOverHttps](INFO): Moved sent file to Logs/20200717T203209/Express0044.lzma.bak
2020-07-17T22:03:40.212Z,1595023420.212 [DataOverHttps](INFO): SBD MOMSN=12446509
2020-07-17T22:03:41.545Z,1595023421.545 [Default:CheckIn:Read_Iridium] Stopped
2020-07-17T22:03:41.545Z,1595023421.545 [Default:CheckIn:C.Wait] Running Loop=1
2020-07-17T22:03:41.545Z,1595023421.545 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-07-17T22:03:46.785Z,1595023426.785 [NAL9602](INFO): SBD MO Status=0, MOMSN=646, MT Status=0, MTMSN=0
2020-07-17T22:03:46.785Z,1595023426.785 [NAL9602](INFO): No messages in MT queue
2020-07-17T22:04:17.491Z,1595023457.491 [NAL9602](INFO): Not Powering down - fast GPS
2020-07-17T22:06:21.119Z,1595023581.119 [DVL_micro](ERROR): only read 3 of 4 data items
2020-07-17T22:06:21.119Z,1595023581.119 [DVL_micro](ERROR): Failed to parse:
:BI,+01382,+00208,+0007,I
2020-07-17T22:08:20.699Z,1595023700.699 [DVL_micro](ERROR): only read 3 of 4 data items
2020-07-17T22:08:20.699Z,1595023700.699 [DVL_micro](ERROR): Failed to parse:
:BI,+00173,+0002,+00000,I
2020-07-17T22:08:42.125Z,1595023722.125 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-07-17T22:08:42.126Z,1595023722.126 [Default:CheckIn:C.Wait] Stopped
2020-07-17T22:08:42.126Z,1595023722.126 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-07-17T22:08:42.126Z,1595023722.126 [Default:CheckIn:D] Running Loop=1
2020-07-17T22:08:42.524Z,1595023722.524 [Default:CheckIn:D] Stopped
2020-07-17T22:08:42.524Z,1595023722.524 [Default:CheckIn:E] Running Loop=1
2020-07-17T22:08:42.933Z,1595023722.933 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 55.458720 min
2020-07-17T22:08:42.933Z,1595023722.933 [Default:CheckIn:E] Stopped
2020-07-17T22:08:42.934Z,1595023722.934 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-07-17T22:08:42.934Z,1595023722.934 [Default:CheckIn] Stopped
2020-07-17T22:08:42.934Z,1595023722.934 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-07-17T22:08:42.934Z,1595023722.934 [Default:CheckIn](INFO): Running loop #11
2020-07-17T22:08:42.934Z,1595023722.934 [Default:CheckIn] Running Loop=11
2020-07-17T22:08:42.934Z,1595023722.934 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-07-17T22:08:42.934Z,1595023722.934 [Default:CheckIn:Read_GPS] Running Loop=1
2020-07-17T22:08:44.941Z,1595023724.941 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,220844.00,A,3648.13981,N,12147.20376,W,0.797,50.44,170720,,,D*44
2020-07-17T22:08:44.944Z,1595023724.944 [NAL9602](INFO): GPS fix at 20200717T220844: (36.802330, -121.786729)
2020-07-17T22:08:44.954Z,1595023724.954 [Default:CheckIn:Read_GPS] Stopped
2020-07-17T22:08:44.954Z,1595023724.954 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-07-17T22:08:52.257Z,1595023732.257 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20200717T203209/Courier0046.lzma
2020-07-17T22:08:53.260Z,1595023733.260 [DataOverHttps](INFO): Moved sent file to Logs/20200717T203209/Courier0046.lzma.bak
2020-07-17T22:08:53.260Z,1595023733.260 [DataOverHttps](INFO): SBD MOMSN=12446513
2020-07-17T22:09:05.949Z,1595023745.949 [NAL9602](INFO): SBD MO Status=0, MOMSN=647, MT Status=0, MTMSN=0
2020-07-17T22:09:05.949Z,1595023745.949 [NAL9602](INFO): No messages in MT queue
2020-07-17T22:09:09.134Z,1595023749.134 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20200717T203209/Express0047.lzma
2020-07-17T22:09:10.140Z,1595023750.140 [DataOverHttps](INFO): Moved sent file to Logs/20200717T203209/Express0047.lzma.bak
2020-07-17T22:09:10.140Z,1595023750.140 [DataOverHttps](INFO): SBD MOMSN=12446516
2020-07-17T22:09:11.231Z,1595023751.231 [Default:CheckIn:Read_Iridium] Stopped
2020-07-17T22:09:11.231Z,1595023751.231 [Default:CheckIn:C.Wait] Running Loop=1
2020-07-17T22:09:11.231Z,1595023751.231 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-07-17T22:09:36.655Z,1595023776.655 [NAL9602](INFO): Not Powering down - fast GPS
2020-07-17T22:10:35.670Z,1595023835.670 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2020-07-17T22:10:35.670Z,1595023835.670 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+20.,1489.0,000
2020-07-17T22:12:50.990Z,1595023970.990 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2020-07-17T22:12:50.990Z,1595023970.990 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+20.5,000.0,000
2020-07-17T22:14:11.797Z,1595024051.797 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-07-17T22:14:11.797Z,1595024051.797 [Default:CheckIn:C.Wait] Stopped
2020-07-17T22:14:11.797Z,1595024051.797 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-07-17T22:14:11.798Z,1595024051.798 [Default:CheckIn:D] Running Loop=1
2020-07-17T22:14:12.201Z,1595024052.201 [Default:CheckIn:D] Stopped
2020-07-17T22:14:12.201Z,1595024052.201 [Default:CheckIn:E] Running Loop=1
2020-07-17T22:14:12.619Z,1595024052.619 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 60.953337 min
2020-07-17T22:14:12.619Z,1595024052.619 [Default:CheckIn:E] Stopped
2020-07-17T22:14:12.619Z,1595024052.619 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-07-17T22:14:12.619Z,1595024052.619 [Default:CheckIn] Stopped
2020-07-17T22:14:12.620Z,1595024052.620 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-07-17T22:14:12.620Z,1595024052.620 [Default:CheckIn](INFO): Running loop #12
2020-07-17T22:14:12.620Z,1595024052.620 [Default:CheckIn] Running Loop=12
2020-07-17T22:14:12.620Z,1595024052.620 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-07-17T22:14:12.620Z,1595024052.620 [Default:CheckIn:Read_GPS] Running Loop=1
2020-07-17T22:14:14.612Z,1595024054.612 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,221413.00,A,3648.50701,N,12147.13647,W,8.533,295.08,170720,,,D*7A
2020-07-17T22:14:14.614Z,1595024054.614 [NAL9602](INFO): GPS fix at 20200717T221413: (36.808450, -121.785608)
2020-07-17T22:14:14.624Z,1595024054.624 [Default:CheckIn:Read_GPS] Stopped
2020-07-17T22:14:14.624Z,1595024054.624 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-07-17T22:14:21.877Z,1595024061.877 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20200717T203209/Courier0049.lzma
2020-07-17T22:14:22.880Z,1595024062.880 [DataOverHttps](INFO): Moved sent file to Logs/20200717T203209/Courier0049.lzma.bak
2020-07-17T22:14:22.880Z,1595024062.880 [DataOverHttps](INFO): SBD MOMSN=12446529
2020-07-17T22:14:25.521Z,1595024065.521 [NAL9602](INFO): SBD MO Status=0, MOMSN=648, MT Status=0, MTMSN=0
2020-07-17T22:14:25.521Z,1595024065.521 [NAL9602](INFO): No messages in MT queue
2020-07-17T22:14:39.173Z,1595024079.173 [DataOverHttps](INFO): Sending 138 bytes from file Logs/20200717T203209/Express0050.lzma
2020-07-17T22:14:40.176Z,1595024080.176 [DataOverHttps](INFO): Moved sent file to Logs/20200717T203209/Express0050.lzma.bak
2020-07-17T22:14:40.176Z,1595024080.176 [DataOverHttps](INFO): SBD MOMSN=12446532
2020-07-17T22:14:41.295Z,1595024081.295 [Default:CheckIn:Read_Iridium] Stopped
2020-07-17T22:14:41.295Z,1595024081.295 [Default:CheckIn:C.Wait] Running Loop=1
2020-07-17T22:14:41.295Z,1595024081.295 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-07-17T22:14:56.227Z,1595024096.227 [NAL9602](INFO): Not Powering down - fast GPS
2020-07-17T22:17:26.113Z,1595024246.113 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2020-07-17T22:17:26.114Z,1595024246.114 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+20.6,009.0,000
2020-07-17T22:19:41.870Z,1595024381.870 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-07-17T22:19:41.870Z,1595024381.870 [Default:CheckIn:C.Wait] Stopped
2020-07-17T22:19:41.870Z,1595024381.870 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-07-17T22:19:41.871Z,1595024381.871 [Default:CheckIn:D] Running Loop=1
2020-07-17T22:19:42.269Z,1595024382.269 [Default:CheckIn:D] Stopped
2020-07-17T22:19:42.269Z,1595024382.269 [Default:CheckIn:E] Running Loop=1
2020-07-17T22:19:42.677Z,1595024382.677 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 66.454464 min
2020-07-17T22:19:42.677Z,1595024382.677 [Default:CheckIn:E] Stopped
2020-07-17T22:19:42.677Z,1595024382.677 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-07-17T22:19:42.677Z,1595024382.677 [Default:CheckIn] Stopped
2020-07-17T22:19:42.677Z,1595024382.677 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-07-17T22:19:42.677Z,1595024382.677 [Default:CheckIn](INFO): Running loop #13
2020-07-17T22:19:42.677Z,1595024382.677 [Default:CheckIn] Running Loop=13
2020-07-17T22:19:42.677Z,1595024382.677 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-07-17T22:19:42.677Z,1595024382.677 [Default:CheckIn:Read_GPS] Running Loop=1
2020-07-17T22:19:44.685Z,1595024384.685 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,221943.00,A,3648.16622,N,12148.46499,W,17.883,251.83,170720,,,D*4D
2020-07-17T22:19:44.687Z,1595024384.687 [NAL9602](INFO): GPS fix at 20200717T221943: (36.802770, -121.807750)
2020-07-17T22:19:44.720Z,1595024384.720 [Default:CheckIn:Read_GPS] Stopped
2020-07-17T22:19:44.720Z,1595024384.720 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-07-17T22:19:51.669Z,1595024391.669 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20200717T203209/Courier0052.lzma
2020-07-17T22:19:52.672Z,1595024392.672 [DataOverHttps](INFO): Moved sent file to Logs/20200717T203209/Courier0052.lzma.bak
2020-07-17T22:19:52.672Z,1595024392.672 [DataOverHttps](INFO): SBD MOMSN=12446536
2020-07-17T22:19:55.597Z,1595024395.597 [NAL9602](INFO): SBD MO Status=0, MOMSN=649, MT Status=0, MTMSN=0
2020-07-17T22:19:55.597Z,1595024395.597 [NAL9602](INFO): No messages in MT queue
2020-07-17T22:20:08.465Z,1595024408.465 [DataOverHttps](INFO): Sending 144 bytes from file Logs/20200717T203209/Express0053.lzma
2020-07-17T22:20:09.468Z,1595024409.468 [DataOverHttps](INFO): Moved sent file to Logs/20200717T203209/Express0053.lzma.bak
2020-07-17T22:20:09.468Z,1595024409.468 [DataOverHttps](INFO): SBD MOMSN=12446539
2020-07-17T22:20:10.552Z,1595024410.552 [Default:CheckIn:Read_Iridium] Stopped
2020-07-17T22:20:10.552Z,1595024410.552 [Default:CheckIn:C.Wait] Running Loop=1
2020-07-17T22:20:10.552Z,1595024410.552 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-07-17T22:20:26.291Z,1595024426.291 [NAL9602](INFO): Not Powering down - fast GPS
2020-07-17T22:25:11.152Z,1595024711.152 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-07-17T22:25:11.153Z,1595024711.153 [Default:CheckIn:C.Wait] Stopped
2020-07-17T22:25:11.153Z,1595024711.153 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-07-17T22:25:11.153Z,1595024711.153 [Default:CheckIn:D] Running Loop=1
2020-07-17T22:25:11.567Z,1595024711.567 [Default:CheckIn:D] Stopped
2020-07-17T22:25:11.568Z,1595024711.568 [Default:CheckIn:E] Running Loop=1
2020-07-17T22:25:11.961Z,1595024711.961 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 71.942773 min
2020-07-17T22:25:11.961Z,1595024711.961 [Default:CheckIn:E] Stopped
2020-07-17T22:25:11.961Z,1595024711.961 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-07-17T22:25:11.962Z,1595024711.962 [Default:CheckIn] Stopped
2020-07-17T22:25:11.962Z,1595024711.962 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-07-17T22:25:11.962Z,1595024711.962 [Default:CheckIn](INFO): Running loop #14
2020-07-17T22:25:11.962Z,1595024711.962 [Default:CheckIn] Running Loop=14
2020-07-17T22:25:11.962Z,1595024711.962 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-07-17T22:25:11.962Z,1595024711.962 [Default:CheckIn:Read_GPS] Running Loop=1
2020-07-17T22:25:13.969Z,1595024713.969 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,222513.00,A,3647.81869,N,12150.70722,W,20.430,267.53,170720,,,D*40
2020-07-17T22:25:13.971Z,1595024713.971 [NAL9602](INFO): GPS fix at 20200717T222513: (36.796978, -121.845120)
2020-07-17T22:25:13.982Z,1595024713.982 [Default:CheckIn:Read_GPS] Stopped
2020-07-17T22:25:13.982Z,1595024713.982 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-07-17T22:25:21.981Z,1595024721.981 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20200717T203209/Courier0055.lzma
2020-07-17T22:25:22.984Z,1595024722.984 [DataOverHttps](INFO): Moved sent file to Logs/20200717T203209/Courier0055.lzma.bak
2020-07-17T22:25:22.984Z,1595024722.984 [DataOverHttps](INFO): SBD MOMSN=12446550
2020-07-17T22:25:25.688Z,1595024725.688 [NAL9602](INFO): SBD MO Status=0, MOMSN=650, MT Status=0, MTMSN=0
2020-07-17T22:25:25.689Z,1595024725.689 [NAL9602](INFO): No messages in MT queue
2020-07-17T22:25:38.621Z,1595024738.621 [DataOverHttps](INFO): Sending 146 bytes from file Logs/20200717T203209/Express0056.lzma
2020-07-17T22:25:39.624Z,1595024739.624 [DataOverHttps](INFO): Moved sent file to Logs/20200717T203209/Express0056.lzma.bak
2020-07-17T22:25:39.624Z,1595024739.624 [DataOverHttps](INFO): SBD MOMSN=12446553
2020-07-17T22:25:40.659Z,1595024740.659 [Default:CheckIn:Read_Iridium] Stopped
2020-07-17T22:25:40.659Z,1595024740.659 [Default:CheckIn:C.Wait] Running Loop=1
2020-07-17T22:25:40.660Z,1595024740.660 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-07-17T22:25:56.409Z,1595024756.409 [NAL9602](INFO): Not Powering down - fast GPS
2020-07-17T22:26:26.693Z,1595024786.693 [DVL_micro](ERROR): only read 3 of 4 data items
2020-07-17T22:26:26.694Z,1595024786.694 [DVL_micro](ERROR): Failed to parse:
:RD,+9999.99,+9999.99,+99999.99
2020-07-17T22:30:41.217Z,1595025041.217 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-07-17T22:30:41.217Z,1595025041.217 [Default:CheckIn:C.Wait] Stopped
2020-07-17T22:30:41.217Z,1595025041.217 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-07-17T22:30:41.218Z,1595025041.218 [Default:CheckIn:D] Running Loop=1
2020-07-17T22:30:41.675Z,1595025041.675 [Default:CheckIn:D] Stopped
2020-07-17T22:30:41.676Z,1595025041.676 [Default:CheckIn:E] Running Loop=1
2020-07-17T22:30:42.025Z,1595025042.025 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 77.444572 min
2020-07-17T22:30:42.025Z,1595025042.025 [Default:CheckIn:E] Stopped
2020-07-17T22:30:42.025Z,1595025042.025 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-07-17T22:30:42.025Z,1595025042.025 [Default:CheckIn] Stopped
2020-07-17T22:30:42.025Z,1595025042.025 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-07-17T22:30:42.025Z,1595025042.025 [Default:CheckIn](INFO): Running loop #15
2020-07-17T22:30:42.026Z,1595025042.026 [Default:CheckIn] Running Loop=15
2020-07-17T22:30:42.026Z,1595025042.026 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-07-17T22:30:42.026Z,1595025042.026 [Default:CheckIn:Read_GPS] Running Loop=1
2020-07-17T22:30:44.051Z,1595025044.051 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,223043.00,A,3647.80767,N,12150.77790,W,0.836,193.11,170720,,,D*79
2020-07-17T22:30:44.053Z,1595025044.053 [NAL9602](INFO): GPS fix at 20200717T223043: (36.796794, -121.846298)
2020-07-17T22:30:44.063Z,1595025044.063 [Default:CheckIn:Read_GPS] Stopped
2020-07-17T22:30:44.063Z,1595025044.063 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-07-17T22:30:55.178Z,1595025055.178 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2020-07-17T22:30:56.971Z,1595025056.971 [DVL_micro](ERROR): only read 3 of 4 data items
2020-07-17T22:30:56.972Z,1595025056.972 [DVL_micro](ERROR): Failed to parse:
:BI,+00008,+00028,+00455I
2020-07-17T22:30:57.186Z,1595025057.186 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.251453
2020-07-17T22:31:08.631Z,1595025068.631 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003555
2020-07-17T22:31:15.956Z,1595025075.956 [NAL9602](INFO): SBD MO Status=2, MOMSN=651, MT Status=2, MTMSN=0
2020-07-17T22:31:15.957Z,1595025075.957 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-07-17T22:31:15.969Z,1595025075.969 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20200717T203209/Courier0058.lzma
2020-07-17T22:31:17.102Z,1595025077.102 [DataOverHttps](INFO): Moved sent file to Logs/20200717T203209/Courier0058.lzma.bak
2020-07-17T22:31:17.102Z,1595025077.102 [DataOverHttps](INFO): SBD MOMSN=12446565
2020-07-17T22:31:32.937Z,1595025092.937 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20200717T203209/Express0059.lzma
2020-07-17T22:31:33.939Z,1595025093.939 [DataOverHttps](INFO): Moved sent file to Logs/20200717T203209/Express0059.lzma.bak
2020-07-17T22:31:33.940Z,1595025093.940 [DataOverHttps](INFO): SBD MOMSN=12446568
2020-07-17T22:31:34.993Z,1595025094.993 [Default:CheckIn:Read_Iridium] Stopped
2020-07-17T22:31:34.993Z,1595025094.993 [Default:CheckIn:C.Wait] Running Loop=1
2020-07-17T22:31:34.993Z,1595025094.993 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-07-17T22:31:41.807Z,1595025101.807 [NAL9602](INFO): SBD MO Status=0, MOMSN=651, MT Status=0, MTMSN=0
2020-07-17T22:31:41.807Z,1595025101.807 [NAL9602](INFO): No messages in MT queue
2020-07-17T22:32:12.512Z,1595025132.512 [NAL9602](INFO): Not Powering down - fast GPS
2020-07-17T22:33:51.718Z,1595025231.718 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2020-07-17T22:33:58.746Z,1595025238.746 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.299545
2020-07-17T22:35:00.383Z,1595025300.383 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003592
2020-07-17T22:35:50.431Z,1595025350.431 [DataOverHttps](IMPORTANT): SBD MTMSN=20200717T223549
2020-07-17T22:35:58.037Z,1595025358.037 [DataOverHttps](INFO): Received command:restart logs