2019-09-23T21:59:02.035Z,1569275942.035 [Supervisor](DEBUG): Initializing supervisor.
2019-09-23T21:59:02.037Z,1569275942.037 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2019-09-23T21:59:02.038Z,1569275942.038 [SyncHandler](INFO): Protected caller Thread ID is 805
2019-09-23T21:59:02.038Z,1569275942.038 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2019-09-23T21:59:02.039Z,1569275942.039 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2019-09-23T21:59:02.040Z,1569275942.040 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 806
2019-09-23T21:59:02.042Z,1569275942.042 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2019-09-23T21:59:02.053Z,1569275942.053 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2019-09-23T21:59:02.054Z,1569275942.054 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2019-09-23T21:59:02.054Z,1569275942.054 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 807
2019-09-23T21:59:02.055Z,1569275942.055 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2019-09-23T21:59:02.056Z,1569275942.056 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2019-09-23T21:59:02.056Z,1569275942.056 [logger ThreadHandler](INFO): Protected caller Thread ID is 808
2019-09-23T21:59:02.058Z,1569275942.058 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2019-09-23T21:59:02.059Z,1569275942.059 [Supervisor](INFO): Looking for Config files in directory: Config/
2019-09-23T21:59:02.063Z,1569275942.063 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2019-09-23T21:59:02.508Z,1569275942.508 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2019-09-23T21:59:02.510Z,1569275942.510 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2019-09-23T21:59:02.657Z,1569275942.657 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2019-09-23T21:59:02.659Z,1569275942.659 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2019-09-23T21:59:02.741Z,1569275942.741 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2019-09-23T21:59:02.842Z,1569275942.842 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2019-09-23T21:59:02.844Z,1569275942.844 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2019-09-23T21:59:02.940Z,1569275942.940 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2019-09-23T21:59:02.942Z,1569275942.942 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2019-09-23T21:59:03.343Z,1569275943.343 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2019-09-23T21:59:03.345Z,1569275943.345 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2019-09-23T21:59:03.448Z,1569275943.448 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2019-09-23T21:59:03.449Z,1569275943.449 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2019-09-23T21:59:03.936Z,1569275943.936 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2019-09-23T21:59:03.938Z,1569275943.938 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2019-09-23T21:59:04.151Z,1569275944.151 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2019-09-23T21:59:04.152Z,1569275944.152 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2019-09-23T21:59:04.470Z,1569275944.470 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2019-09-23T21:59:04.471Z,1569275944.471 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2019-09-23T21:59:04.695Z,1569275944.695 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2019-09-23T21:59:04.697Z,1569275944.697 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2019-09-23T21:59:04.844Z,1569275944.844 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2019-09-23T21:59:04.846Z,1569275944.846 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2019-09-23T21:59:05.506Z,1569275945.506 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2019-09-23T21:59:05.507Z,1569275945.507 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2019-09-23T21:59:06.317Z,1569275946.317 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2019-09-23T21:59:06.319Z,1569275946.319 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2019-09-23T21:59:06.579Z,1569275946.579 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2019-09-23T21:59:06.581Z,1569275946.581 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-triton/
2019-09-23T21:59:06.583Z,1569275946.583 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/vehicle.cfg
2019-09-23T21:59:06.794Z,1569275946.794 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/secure.cfg
2019-09-23T21:59:06.877Z,1569275946.877 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Science.cfg
2019-09-23T21:59:07.017Z,1569275947.017 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Simulator.cfg
2019-09-23T21:59:07.104Z,1569275947.104 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Battery.cfg
2019-09-23T21:59:07.340Z,1569275947.340 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2019-09-23T21:59:07.341Z,1569275947.341 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/logger.cfg
2019-09-23T21:59:07.438Z,1569275947.438 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Servo.cfg
2019-09-23T21:59:07.550Z,1569275947.550 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Navigation.cfg
2019-09-23T21:59:07.646Z,1569275947.646 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Sensor.cfg
2019-09-23T21:59:07.806Z,1569275947.806 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Control.cfg
2019-09-23T21:59:07.908Z,1569275947.908 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/BIT.cfg
2019-09-23T21:59:08.010Z,1569275948.010 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-triton/root/
2019-09-23T21:59:08.010Z,1569275948.010 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2019-09-23T21:59:08.019Z,1569275948.019 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2019-09-23T21:59:08.043Z,1569275948.043 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2019-09-23T21:59:08.045Z,1569275948.045 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2019-09-23T21:59:08.136Z,1569275948.136 [VerticalControl](DEBUG): Construct VerticalControl.
2019-09-23T21:59:08.251Z,1569275948.251 [VerticalControl] Loaded
2019-09-23T21:59:08.251Z,1569275948.251 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2019-09-23T21:59:08.252Z,1569275948.252 [HorizontalControl](DEBUG): Construct HorizontalControl.
2019-09-23T21:59:08.322Z,1569275948.322 [HorizontalControl] Loaded
2019-09-23T21:59:08.322Z,1569275948.322 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2019-09-23T21:59:08.323Z,1569275948.323 [SpeedControl](DEBUG): Construct SpeedControl.
2019-09-23T21:59:08.328Z,1569275948.328 [SpeedControl] Loaded
2019-09-23T21:59:08.329Z,1569275948.329 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2019-09-23T21:59:08.329Z,1569275948.329 [LoopControl](DEBUG): Construct LoopControl.
2019-09-23T21:59:08.330Z,1569275948.330 [LoopControl] Loaded
2019-09-23T21:59:08.330Z,1569275948.330 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2019-09-23T21:59:08.331Z,1569275948.331 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2019-09-23T21:59:08.331Z,1569275948.331 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2019-09-23T21:59:08.483Z,1569275948.483 [BuoyancyServo] Loaded
2019-09-23T21:59:08.483Z,1569275948.483 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2019-09-23T21:59:08.494Z,1569275948.494 [ElevatorServo] Loaded
2019-09-23T21:59:08.495Z,1569275948.495 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2019-09-23T21:59:08.506Z,1569275948.506 [MassServo] Loaded
2019-09-23T21:59:08.506Z,1569275948.506 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2019-09-23T21:59:08.517Z,1569275948.517 [RudderServo] Loaded
2019-09-23T21:59:08.517Z,1569275948.517 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2019-09-23T21:59:08.528Z,1569275948.528 [ThrusterServo] Loaded
2019-09-23T21:59:08.529Z,1569275948.529 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2019-09-23T21:59:08.529Z,1569275948.529 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2019-09-23T21:59:08.530Z,1569275948.530 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2019-09-23T21:59:08.586Z,1569275948.586 [DepthRateCalculator] Loaded
2019-09-23T21:59:08.586Z,1569275948.586 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2019-09-23T21:59:08.592Z,1569275948.592 [PitchRateCalculator] Loaded
2019-09-23T21:59:08.592Z,1569275948.592 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2019-09-23T21:59:08.607Z,1569275948.607 [SpeedCalculator] Loaded
2019-09-23T21:59:08.608Z,1569275948.608 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2019-09-23T21:59:08.629Z,1569275948.629 [TempGradientCalculator] Loaded
2019-09-23T21:59:08.629Z,1569275948.629 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2019-09-23T21:59:08.634Z,1569275948.634 [YawRateCalculator] Loaded
2019-09-23T21:59:08.635Z,1569275948.635 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2019-09-23T21:59:08.665Z,1569275948.665 [ElevatorOffsetCalculator] Loaded
2019-09-23T21:59:08.666Z,1569275948.666 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2019-09-23T21:59:08.666Z,1569275948.666 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2019-09-23T21:59:08.668Z,1569275948.668 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2019-09-23T21:59:08.790Z,1569275948.790 [DeadReckonUsingMultipleVelocitySources] Loaded
2019-09-23T21:59:08.790Z,1569275948.790 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2019-09-23T21:59:08.811Z,1569275948.811 [NavChart] Loaded
2019-09-23T21:59:08.811Z,1569275948.811 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2019-09-23T21:59:08.815Z,1569275948.815 [UniversalFixResidualReporter] Loaded
2019-09-23T21:59:08.816Z,1569275948.816 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2019-09-23T21:59:08.816Z,1569275948.816 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2019-09-23T21:59:08.817Z,1569275948.817 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2019-09-23T21:59:09.294Z,1569275949.294 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_orientation
2019-09-23T21:59:09.300Z,1569275949.300 [AHRS_M2](INFO): created writer for : platform_orientation
2019-09-23T21:59:09.301Z,1569275949.301 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_magnetic_orientation
2019-09-23T21:59:09.307Z,1569275949.307 [AHRS_M2](INFO): created writer for : platform_magnetic_orientation
2019-09-23T21:59:09.307Z,1569275949.307 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_pitch_angle
2019-09-23T21:59:09.312Z,1569275949.312 [AHRS_M2](INFO): created writer for : platform_pitch_angle
2019-09-23T21:59:09.313Z,1569275949.313 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_roll_angle
2019-09-23T21:59:09.318Z,1569275949.318 [AHRS_M2](INFO): created writer for : platform_roll_angle
2019-09-23T21:59:09.497Z,1569275949.497 [AHRS_M2] Loaded
2019-09-23T21:59:09.497Z,1569275949.497 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2019-09-23T21:59:09.638Z,1569275949.638 [DataOverHttps] Loaded
2019-09-23T21:59:09.638Z,1569275949.638 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2019-09-23T21:59:09.639Z,1569275949.639 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 408024E0
2019-09-23T21:59:09.640Z,1569275949.640 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 888
2019-09-23T21:59:09.653Z,1569275949.653 [Depth_Keller] Loaded
2019-09-23T21:59:09.654Z,1569275949.654 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2019-09-23T21:59:09.659Z,1569275949.659 [DropWeight] Loaded
2019-09-23T21:59:09.659Z,1569275949.659 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2019-09-23T21:59:09.706Z,1569275949.706 [DVL_micro] Loaded
2019-09-23T21:59:09.706Z,1569275949.706 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread.
2019-09-23T21:59:09.806Z,1569275949.806 [NAL9602] Loaded
2019-09-23T21:59:09.806Z,1569275949.806 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2019-09-23T21:59:09.822Z,1569275949.822 [Onboard] Loaded
2019-09-23T21:59:09.823Z,1569275949.823 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2019-09-23T21:59:09.826Z,1569275949.826 [Radio_Surface] Loaded
2019-09-23T21:59:09.826Z,1569275949.826 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2019-09-23T21:59:09.827Z,1569275949.827 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408324E0
2019-09-23T21:59:09.828Z,1569275949.828 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 889
2019-09-23T21:59:09.958Z,1569275949.958 [DAT] Loaded
2019-09-23T21:59:09.958Z,1569275949.958 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread.
2019-09-23T21:59:11.999Z,1569275951.999 [BPC1] Loaded
2019-09-23T21:59:11.999Z,1569275951.999 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2019-09-23T21:59:12.021Z,1569275952.021 [BR_Ping1D] Loaded
2019-09-23T21:59:12.021Z,1569275952.021 [ComponentRegistry](DEBUG): SyncComponent "BR_Ping1D" handled in the control thread.
2019-09-23T21:59:12.022Z,1569275952.022 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2019-09-23T21:59:12.024Z,1569275952.024 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2019-09-23T21:59:12.139Z,1569275952.139 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2019-09-23T21:59:12.139Z,1569275952.139 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2019-09-23T21:59:12.267Z,1569275952.267 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2019-09-23T21:59:12.268Z,1569275952.268 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2019-09-23T21:59:12.317Z,1569275952.317 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2019-09-23T21:59:12.317Z,1569275952.317 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2019-09-23T21:59:12.572Z,1569275952.572 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density
2019-09-23T21:59:12.577Z,1569275952.577 [CTD_Seabird](INFO): created writer for : sea_water_density
2019-09-23T21:59:12.578Z,1569275952.578 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth
2019-09-23T21:59:12.583Z,1569275952.583 [CTD_Seabird](INFO): created writer for : depth
2019-09-23T21:59:12.583Z,1569275952.583 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure
2019-09-23T21:59:12.588Z,1569275952.588 [CTD_Seabird](INFO): created writer for : sea_water_pressure
2019-09-23T21:59:12.589Z,1569275952.589 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity
2019-09-23T21:59:12.595Z,1569275952.595 [CTD_Seabird](INFO): created writer for : sea_water_salinity
2019-09-23T21:59:12.595Z,1569275952.595 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature
2019-09-23T21:59:12.601Z,1569275952.601 [CTD_Seabird](INFO): created writer for : sea_water_temperature
2019-09-23T21:59:12.601Z,1569275952.601 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity
2019-09-23T21:59:12.607Z,1569275952.607 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity
2019-09-23T21:59:12.607Z,1569275952.607 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water
2019-09-23T21:59:12.613Z,1569275952.613 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water
2019-09-23T21:59:12.613Z,1569275952.613 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): mass_concentration_of_oxygen_in_sea_water
2019-09-23T21:59:12.619Z,1569275952.619 [CTD_Seabird](INFO): created writer for : mass_concentration_of_oxygen_in_sea_water
2019-09-23T21:59:12.619Z,1569275952.619 [CTD_Seabird](DEBUG): LcmSlateWriter::add(DAtaURI): CTD_Seabird.sea_water_dissolved_oxygen_freq
2019-09-23T21:59:12.620Z,1569275952.620 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): dataName: sea_water_dissolved_oxygen_freq
2019-09-23T21:59:12.653Z,1569275952.653 [CTD_Seabird] Loaded
2019-09-23T21:59:12.654Z,1569275952.654 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2019-09-23T21:59:12.655Z,1569275952.655 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 409C94E0
2019-09-23T21:59:12.655Z,1569275952.655 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 890
2019-09-23T21:59:12.670Z,1569275952.670 [PAR_Licor] Loaded
2019-09-23T21:59:12.670Z,1569275952.670 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2019-09-23T21:59:12.719Z,1569275952.719 [WetLabsBB2FL] Loaded
2019-09-23T21:59:12.720Z,1569275952.720 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2019-09-23T21:59:12.721Z,1569275952.721 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 409F94E0
2019-09-23T21:59:12.721Z,1569275952.721 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 891
2019-09-23T21:59:12.722Z,1569275952.722 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2019-09-23T21:59:12.722Z,1569275952.722 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2019-09-23T21:59:13.068Z,1569275953.068 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2019-09-23T21:59:13.069Z,1569275953.069 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2019-09-23T21:59:13.232Z,1569275953.232 [SBIT](DEBUG): Construct Startup Built In Test.
2019-09-23T21:59:13.243Z,1569275953.243 [SBIT] Loaded
2019-09-23T21:59:13.243Z,1569275953.243 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2019-09-23T21:59:13.244Z,1569275953.244 [IBIT](DEBUG): Construct Initiated Built In Test.
2019-09-23T21:59:13.255Z,1569275953.255 [IBIT] Loaded
2019-09-23T21:59:13.256Z,1569275953.256 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2019-09-23T21:59:13.259Z,1569275953.259 [CBIT](DEBUG): Construct Continuous Built In Test.
2019-09-23T21:59:13.400Z,1569275953.400 [CBIT] Loaded
2019-09-23T21:59:13.400Z,1569275953.400 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2019-09-23T21:59:13.400Z,1569275953.400 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2019-09-23T21:59:13.404Z,1569275953.404 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2019-09-23T21:59:13.405Z,1569275953.405 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2019-09-23T21:59:13.411Z,1569275953.411 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2019-09-23T21:59:13.412Z,1569275953.412 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40AD84E0
2019-09-23T21:59:13.413Z,1569275953.413 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 892
2019-09-23T21:59:13.417Z,1569275953.417 [Supervisor](INFO): Main Thread ID is 801
2019-09-23T21:59:13.417Z,1569275953.417 [Supervisor](DEBUG): Running supervisor.
2019-09-23T21:59:13.418Z,1569275953.418 [CommandLine ThreadHandler](INFO): Handler Thread ID is 893
2019-09-23T21:59:13.420Z,1569275953.420 [controlThread ThreadHandler](INFO): Handler Thread ID is 894
2019-09-23T21:59:13.421Z,1569275953.421 [controlThread](DEBUG): Initializing ControlThread
2019-09-23T21:59:13.422Z,1569275953.422 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2019-09-23T21:59:13.423Z,1569275953.423 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2019-09-23T21:59:13.424Z,1569275953.424 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2019-09-23T21:59:13.424Z,1569275953.424 [LoopControl](DEBUG): Initialize LoopControlComponent.
2019-09-23T21:59:13.426Z,1569275953.426 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2019-09-23T21:59:13.426Z,1569275953.426 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2019-09-23T21:59:13.426Z,1569275953.426 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2019-09-23T21:59:13.427Z,1569275953.427 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2019-09-23T21:59:13.427Z,1569275953.427 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2019-09-23T21:59:13.428Z,1569275953.428 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2019-09-23T21:59:13.429Z,1569275953.429 [NavChart](DEBUG): Initialize NavChart Navigation.
2019-09-23T21:59:13.429Z,1569275953.429 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2019-09-23T21:59:13.437Z,1569275953.437 [SBIT](INFO): Initialize SBIT Component.
2019-09-23T21:59:13.438Z,1569275953.438 [SBIT](IMPORTANT): git: 2019-09-23-triton4
2019-09-23T21:59:13.438Z,1569275953.438 [SBIT](INFO): git hash: 44996ebdb3f43e0ac5b405bbdb4f589f752fd91c
2019-09-23T21:59:13.438Z,1569275953.438 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2019-09-23T21:59:13.439Z,1569275953.439 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #1 PREEMPT Tue Dec 18 21:19:28 PST 2018
Kernel Reported: #1 PREEMPT Thu Feb 21 11:17:40 PST 2019
2019-09-23T21:59:13.440Z,1569275953.440 [SBIT](INFO): Beginning SBIT in 39.000000 seconds.
2019-09-23T21:59:13.441Z,1569275953.441 [IBIT](INFO): Initialize IBIT Component.
2019-09-23T21:59:13.442Z,1569275953.442 [CBIT](DEBUG): Initialize CBIT Component.
2019-09-23T21:59:13.443Z,1569275953.443 [logger ThreadHandler](INFO): Handler Thread ID is 895
2019-09-23T21:59:13.453Z,1569275953.453 [CBIT](DEBUG): Initialized mux pins.
2019-09-23T21:59:13.453Z,1569275953.453 [CBIT](DEBUG): Initializing the watchdog timer.
2019-09-23T21:59:13.461Z,1569275953.461 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 896
2019-09-23T21:59:13.462Z,1569275953.462 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2019-09-23T21:59:13.473Z,1569275953.473 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 897
2019-09-23T21:59:13.477Z,1569275953.477 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2019-09-23T21:59:13.477Z,1569275953.477 [CBIT](DEBUG): Initializing heartbeat.
2019-09-23T21:59:13.485Z,1569275953.485 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 898
2019-09-23T21:59:13.486Z,1569275953.486 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2019-09-23T21:59:13.489Z,1569275953.489 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20
2019-09-23T21:59:13.491Z,1569275953.491 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 900
2019-09-23T21:59:13.492Z,1569275953.492 [WetLabsBB2FL](INFO): Powering down
2019-09-23T21:59:13.519Z,1569275953.519 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 901
2019-09-23T21:59:13.526Z,1569275953.526 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2019-09-23T21:59:13.526Z,1569275953.526 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2019-09-23T21:59:13.527Z,1569275953.527 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2019-09-23T21:59:13.527Z,1569275953.527 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2019-09-23T21:59:13.527Z,1569275953.527 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2019-09-23T21:59:13.527Z,1569275953.527 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2019-09-23T21:59:13.527Z,1569275953.527 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2019-09-23T21:59:13.527Z,1569275953.527 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2019-09-23T21:59:13.528Z,1569275953.528 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2019-09-23T21:59:13.528Z,1569275953.528 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2019-09-23T21:59:13.528Z,1569275953.528 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2019-09-23T21:59:13.528Z,1569275953.528 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2019-09-23T21:59:13.528Z,1569275953.528 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2019-09-23T21:59:13.529Z,1569275953.529 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2019-09-23T21:59:13.529Z,1569275953.529 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2019-09-23T21:59:13.529Z,1569275953.529 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2019-09-23T21:59:13.549Z,1569275953.549 [CBIT](DEBUG): Deactivating GF circuits.
2019-09-23T21:59:13.549Z,1569275953.549 [CBIT](DEBUG): Deactivating emergency mode.
2019-09-23T21:59:13.585Z,1569275953.585 [CBIT](DEBUG): Backplane powered.
2019-09-23T21:59:13.586Z,1569275953.586 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2019-09-23T21:59:13.615Z,1569275953.615 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2019-09-23T21:59:13.641Z,1569275953.641 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
       Id="Startup">

    <Guidance:GoToSurface>
        <Progression/>
    </Guidance:GoToSurface>

    <Aggregate Id="StartupSatComms">

        <Sequence/>

        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:latitude_fix/>
        </ReadDatum>

        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:platform_communications/>
        </ReadDatum>

    </Aggregate>

</Mission>


2019-09-23T21:59:13.642Z,1569275953.642 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2019-09-23T21:59:13.719Z,1569275953.719 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2019-09-23T21:59:13.720Z,1569275953.720 [Default:A.Wait](DEBUG): Construct Wait.
2019-09-23T21:59:13.722Z,1569275953.722 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2019-09-23T21:59:13.772Z,1569275953.772 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2019-09-23T21:59:13.794Z,1569275953.794 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2019-09-23T21:59:13.799Z,1569275953.799 [Default:E.Execute](DEBUG): Construct Execute.
2019-09-23T21:59:13.819Z,1569275953.819 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Universal="Tethys/Universal"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
         Id="Default">

    <DefineArg Name="ElapsedSinceDefaultStarted"><Units:minute/><Value>0</Value></DefineArg>

    <Guidance:Wait>
        <Description>
            Wait a moment to see if the scheduler starts a new mission before
            starting to actually run Default.
        </Description>
        <Sequence/>
        <Setting><Guidance:Wait.duration/><Units:second/><Value>13</Value></Setting>
    </Guidance:Wait>

    <Guidance:GoToSurface>
        <Progression/>
    </Guidance:GoToSurface>

    <Aggregate Id="CheckIn">

        <Sequence Repeat="288"/>

        <ReadDatum Id="Read_GPS">
            <Timeout Duration="P5M"/>
            <Universal:time_fix/>
        </ReadDatum>

        <ReadDatum Id="Read_Iridium">
            <Timeout Duration="P2H">
                <Guidance:Execute>
                    <Sequence/>
                    <Setting><Guidance:Execute.command/><String>Burn on</String></Setting>
                </Guidance:Execute>
                <Syslog Severity="Critical">Dropped weight due to communications timeout.</Syslog>
            </Timeout>
            <Universal:platform_communications/>
        </ReadDatum>

        <Guidance:Wait>
            <Sequence/>
            <Setting><Guidance:Wait.duration/><Units:minute/><Value>5</Value></Setting>
        </Guidance:Wait>

        <Assign><Sequence/><Arg Name="ElapsedSinceDefaultStarted"/><Elapsed><Universal:mission_started/></Elapsed></Assign>

        <Syslog Severity="Important">Default mission has been running for <Arg Name="ElapsedSinceDefaultStarted"/><Units:minute/></Syslog>

    </Aggregate>

    <Syslog Severity="Important">Restarting logs and Default mission.</Syslog>

    <Guidance:Execute>
        <Sequence/>
        <Setting><Guidance:Execute.command/><String>restart logs</String></Setting>
    </Guidance:Execute>

</Mission>


2019-09-23T21:59:13.823Z,1569275953.823 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,DVL_micro,NAL9602,Onboard,DAT,BPC1,BR_Ping1D,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2019-09-23T21:59:13.828Z,1569275953.828 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2019-09-23T21:59:13.877Z,1569275953.877 [Radio_Surface](INFO): Powering up
2019-09-23T21:59:14.055Z,1569275954.055 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2019-09-23T21:59:14.055Z,1569275954.055 [DAT](INFO): Powering up
2019-09-23T21:59:14.055Z,1569275954.055 [DAT](DEBUG): Initializing DAT.
2019-09-23T21:59:14.117Z,1569275954.117 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2019-09-23T21:59:14.169Z,1569275954.169 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2019-09-23T21:59:14.181Z,1569275954.181 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2019-09-23T21:59:14.183Z,1569275954.183 [ElevatorServo](DEBUG): Initializing EZServoServo.
2019-09-23T21:59:14.193Z,1569275954.193 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2019-09-23T21:59:14.194Z,1569275954.194 [MassServo](DEBUG): Initializing EZServoServo.
2019-09-23T21:59:14.205Z,1569275954.205 [MassServo](DEBUG): Initializing MassServo.
2019-09-23T21:59:14.206Z,1569275954.206 [RudderServo](DEBUG): Initializing EZServoServo.
2019-09-23T21:59:14.217Z,1569275954.217 [RudderServo](DEBUG): Initializing RudderServo.
2019-09-23T21:59:14.218Z,1569275954.218 [ThrusterServo](DEBUG): Initializing EZServoServo.
2019-09-23T21:59:14.230Z,1569275954.230 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2019-09-23T21:59:19.974Z,1569275959.974 [BR_Ping1D](FAULT): Failed to set parameters in time during initialization.
2019-09-23T21:59:19.974Z,1569275959.974 [BR_Ping1D] Data Fault, FailCount= 1
2019-09-23T21:59:19.975Z,1569275959.975 [BR_Ping1D](ERROR): Data Fault
2019-09-23T21:59:20.058Z,1569275960.058 [CBIT](ERROR): Data Fault in component: BR_Ping1D
2019-09-23T21:59:20.370Z,1569275960.370 [BR_Ping1D](INFO): Powering down
2019-09-23T21:59:21.752Z,1569275961.752 [CBIT](INFO): Clearing failed state for component BR_Ping1D
2019-09-23T21:59:21.752Z,1569275961.752 [BR_Ping1D] No Fault, FailCount= 1
2019-09-23T21:59:27.494Z,1569275967.494 [DAT](INFO): setting local address to 5
2019-09-23T21:59:27.901Z,1569275967.901 [DAT](INFO): set local address to 5
2019-09-23T21:59:40.021Z,1569275980.021 [NAL9602](INFO): Powering up NAL9602
2019-09-23T21:59:50.921Z,1569275990.921 [NAL9602](INFO): NAL9602 initialized
2019-09-23T21:59:51.733Z,1569275991.733 [NAL9602](DEBUG): Fix Requested
2019-09-23T21:59:52.033Z,1569275992.033 [CommandLine](IMPORTANT): got command failComponent
2019-09-23T21:59:52.034Z,1569275992.034 [CommandLine](IMPORTANT): Failed components:
2019-09-23T21:59:52.034Z,1569275992.034 [CommandLine](IMPORTANT): No failed Components.
2019-09-23T21:59:53.039Z,1569275993.039 [SBIT](IMPORTANT): Beginning Startup BIT
2019-09-23T21:59:53.043Z,1569275993.043 [CBIT](IMPORTANT): Beginning ground fault scan
2019-09-23T21:59:58.013Z,1569275998.013 [DVL_micro](ERROR): Failed to parse:
:WI,-00014,-00016,+00581,+00000,A
2019-09-23T22:00:03.806Z,1569276003.806 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.018735
CHAN A1 (24V): 0.038042
CHAN A2 (12V): -0.008837
CHAN A3 (5V): -0.019864
CHAN B0 (3.3V): -0.014279
CHAN B1 (3.15aV): -0.009144
CHAN B2 (3.15bV): -0.007676
CHAN B3 (GND): -0.014116
OPEN: 0.006376
Full Scale Calc: 4.765 mA, -1.589 mA
2019-09-23T22:00:13.082Z,1569276013.082 [NAL9602](INFO): SBD MO Status=2, MOMSN=1569, MT Status=2, MTMSN=0
2019-09-23T22:00:13.082Z,1569276013.082 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-09-23T22:00:25.596Z,1569276025.596 [NAL9602](INFO): SBD MO Status=2, MOMSN=1569, MT Status=2, MTMSN=0
2019-09-23T22:00:25.596Z,1569276025.596 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-09-23T22:00:46.864Z,1569276046.864 [SBIT](IMPORTANT): SBIT PASSED
2019-09-23T22:00:46.900Z,1569276046.900 [CommandLine](IMPORTANT): got command configSet list
2019-09-23T22:00:46.900Z,1569276046.900 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2019-09-23T22:00:46.901Z,1569276046.901 [CommandLine](IMPORTANT): CBIT.gf24Offset=150 microampere;

2019-09-23T22:00:46.901Z,1569276046.901 [CommandLine](IMPORTANT): VerticalControl.buoyancyDefault=200 cubic_centimeter;

2019-09-23T22:00:46.901Z,1569276046.901 [CommandLine](IMPORTANT): VerticalControl.massDefault=5 millimeter;

2019-09-23T22:00:47.272Z,1569276047.272 [MissionManager](IMPORTANT): Started mission Startup
2019-09-23T22:00:47.272Z,1569276047.272 [Startup] Running Loop=1
2019-09-23T22:00:47.272Z,1569276047.272 [Startup](DEBUG): Aggregate::initialize Startup
2019-09-23T22:00:47.272Z,1569276047.272 [Startup:A.GoToSurface] Running Loop=1
2019-09-23T22:00:47.272Z,1569276047.272 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-09-23T22:00:47.277Z,1569276047.277 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-09-23T22:00:47.278Z,1569276047.278 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-09-23T22:00:47.278Z,1569276047.278 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-09-23T22:00:47.278Z,1569276047.278 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-09-23T22:00:47.279Z,1569276047.279 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-09-23T22:00:47.280Z,1569276047.280 [Startup:StartupSatComms] Running Loop=1
2019-09-23T22:00:47.280Z,1569276047.280 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2019-09-23T22:00:47.280Z,1569276047.280 [Startup:StartupSatComms:A] Running Loop=1
2019-09-23T22:00:47.660Z,1569276047.660 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2019-09-23T22:00:52.478Z,1569276052.478 [NAL9602](INFO): SBD MO Status=2, MOMSN=1569, MT Status=2, MTMSN=0
2019-09-23T22:00:52.478Z,1569276052.478 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-09-23T22:01:09.848Z,1569276069.848 [NAL9602](INFO): SBD MO Status=2, MOMSN=1569, MT Status=2, MTMSN=0
2019-09-23T22:01:09.848Z,1569276069.848 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-09-23T22:01:22.769Z,1569276082.769 [NAL9602](INFO): SBD MO Status=2, MOMSN=1569, MT Status=2, MTMSN=0
2019-09-23T22:01:22.769Z,1569276082.769 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-09-23T22:01:43.467Z,1569276103.467 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-09-23T22:01:47.454Z,1569276107.454 [Startup:StartupSatComms:A](INFO): Timed out from 2019-09-23T22:00:47.3Z
2019-09-23T22:01:47.454Z,1569276107.454 [Startup:StartupSatComms:A] Stopped
2019-09-23T22:01:47.454Z,1569276107.454 [Startup:StartupSatComms:B] Running Loop=1
2019-09-23T22:01:47.852Z,1569276107.852 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-09-23T22:01:56.782Z,1569276116.782 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-09-23T22:02:03.169Z,1569276123.169 [NAL9602](INFO): SBD MO Status=2, MOMSN=1569, MT Status=2, MTMSN=0
2019-09-23T22:02:03.169Z,1569276123.169 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-09-23T22:02:08.699Z,1569276128.699 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004957
2019-09-23T22:02:13.717Z,1569276133.717 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2019-09-23T22:02:13.717Z,1569276133.717 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-09-23T22:02:13.727Z,1569276133.727 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-09-23T22:02:14.160Z,1569276134.160 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-09-23T22:02:14.160Z,1569276134.160 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2019-09-23T22:02:18.195Z,1569276138.195 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20190923T215103/Courier0004.lzma
2019-09-23T22:02:20.198Z,1569276140.198 [DataOverHttps](INFO): Moved sent file to Logs/20190923T215103/Courier0004.lzma.bak
2019-09-23T22:02:20.199Z,1569276140.199 [DataOverHttps](INFO): SBD MOMSN=11805998
2019-09-23T22:02:28.234Z,1569276148.234 [NAL9602](INFO): SBD MO Status=2, MOMSN=1569, MT Status=2, MTMSN=0
2019-09-23T22:02:28.234Z,1569276148.234 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-09-23T22:02:39.132Z,1569276159.132 [NAL9602](IMPORTANT): SBD MO Status=0, MOMSN=1569, MT Status=1, MTMSN=6
2019-09-23T22:02:39.132Z,1569276159.132 [NAL9602](INFO): Data available in MT queue
2019-09-23T22:02:39.690Z,1569276159.690 [NAL9602](INFO): Received command:configSet Express linearApproximation Tracking.range_to_contact 10 meter persist
2019-09-23T22:02:41.042Z,1569276161.042 [DataOverHttps](INFO): Sending 99 bytes from file Logs/20190923T215529/Courier0000.lzma
2019-09-23T22:02:41.428Z,1569276161.428 [CommandLine](IMPORTANT): got command configSet Express linearApproximation time persist
2019-09-23T22:02:41.428Z,1569276161.428 [CommandLine](FAULT): Initializing LinearApproxWriter with NULL parameter value
2019-09-23T22:02:41.909Z,1569276161.909 [NAL9602](DEBUG): Fix Requested
2019-09-23T22:02:42.301Z,1569276162.301 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,220240.00,A,3648.17546,N,12147.27717,W,0.641,49.87,230919,,,A*46
2019-09-23T22:02:42.304Z,1569276162.304 [NAL9602](INFO): GPS fix at 20190923T220240: (36.802924, -121.787953)
2019-09-23T22:02:43.046Z,1569276163.046 [DataOverHttps](INFO): Moved sent file to Logs/20190923T215529/Courier0000.lzma.bak
2019-09-23T22:02:43.047Z,1569276163.047 [DataOverHttps](INFO): SBD MOMSN=11806001
2019-09-23T22:02:47.623Z,1569276167.623 [Startup:StartupSatComms:B](INFO): Timed out from 2019-09-23T22:01:47.5Z
2019-09-23T22:02:47.623Z,1569276167.623 [Startup:StartupSatComms:B] Stopped
2019-09-23T22:02:47.624Z,1569276167.624 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2019-09-23T22:02:47.624Z,1569276167.624 [Startup:StartupSatComms] Stopped
2019-09-23T22:02:47.624Z,1569276167.624 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2019-09-23T22:02:47.624Z,1569276167.624 [Startup](INFO): Completed Startup
2019-09-23T22:02:47.633Z,1569276167.633 [MissionManager](INFO): Startup is completed.
2019-09-23T22:02:47.633Z,1569276167.633 [MissionManager](INFO): Uninitializing Mission Startup
2019-09-23T22:02:47.633Z,1569276167.633 [Startup] Stopped
2019-09-23T22:02:47.633Z,1569276167.633 [Startup](DEBUG): Aggregate::uninitialize Startup
2019-09-23T22:02:47.633Z,1569276167.633 [Startup:A.GoToSurface] Stopped
2019-09-23T22:02:47.633Z,1569276167.633 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-09-23T22:02:48.008Z,1569276168.008 [MissionManager](IMPORTANT): Started mission Default
2019-09-23T22:02:48.008Z,1569276168.008 [Default] Running Loop=1
2019-09-23T22:02:48.037Z,1569276168.037 [Default](DEBUG): Aggregate::initialize Default
2019-09-23T22:02:48.037Z,1569276168.037 [Default:B.GoToSurface] Running Loop=1
2019-09-23T22:02:48.037Z,1569276168.037 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-09-23T22:02:48.037Z,1569276168.037 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-09-23T22:02:48.038Z,1569276168.038 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-09-23T22:02:48.038Z,1569276168.038 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-09-23T22:02:48.038Z,1569276168.038 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-09-23T22:02:48.039Z,1569276168.039 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-09-23T22:02:48.039Z,1569276168.039 [Default:A.Wait] Running Loop=1
2019-09-23T22:02:48.039Z,1569276168.039 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-09-23T22:02:56.449Z,1569276176.449 [DVL_micro](ERROR): Failed to parse:
:WI,-00020,-00213,+00613,+00000,A
2019-09-23T22:03:01.346Z,1569276181.346 [Default:A.Wait](INFO): Done Waiting.
2019-09-23T22:03:01.346Z,1569276181.346 [Default:A.Wait] Stopped
2019-09-23T22:03:01.346Z,1569276181.346 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-09-23T22:03:01.750Z,1569276181.750 [Default:CheckIn] Running Loop=1
2019-09-23T22:03:01.750Z,1569276181.750 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-09-23T22:03:01.751Z,1569276181.751 [Default:CheckIn:Read_GPS] Running Loop=1
2019-09-23T22:03:02.151Z,1569276182.151 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2019-09-23T22:03:03.333Z,1569276183.333 [NAL9602](DEBUG): Fix Requested
2019-09-23T22:03:03.744Z,1569276183.744 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,220302.00,A,3648.17392,N,12147.27667,W,0.214,49.87,230919,,,A*4C
2019-09-23T22:03:03.746Z,1569276183.746 [NAL9602](INFO): GPS fix at 20190923T220302: (36.802899, -121.787944)
2019-09-23T22:03:03.828Z,1569276183.828 [Default:CheckIn:Read_GPS] Stopped
2019-09-23T22:03:03.828Z,1569276183.828 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-09-23T22:03:04.259Z,1569276184.259 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-09-23T22:03:12.926Z,1569276192.926 [DataOverHttps](INFO): Sending 195 bytes from file Logs/20190923T212020/Express0014.lzma
2019-09-23T22:03:14.930Z,1569276194.930 [DataOverHttps](INFO): Moved sent file to Logs/20190923T212020/Express0014.lzma.bak
2019-09-23T22:03:14.931Z,1569276194.931 [DataOverHttps](INFO): SBD MOMSN=11806005
2019-09-23T22:03:30.934Z,1569276210.934 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-09-23T22:03:36.042Z,1569276216.042 [NAL9602](INFO): Not Powering down - fast GPS
2019-09-23T22:03:54.681Z,1569276234.681 [DataOverHttps](INFO): Sending 212 bytes from file Logs/20190923T215902/Courier0004.lzma
2019-09-23T22:03:56.686Z,1569276236.686 [DataOverHttps](INFO): Moved sent file to Logs/20190923T215902/Courier0004.lzma.bak
2019-09-23T22:03:56.686Z,1569276236.686 [DataOverHttps](INFO): SBD MOMSN=11806009
2019-09-23T22:04:10.078Z,1569276250.078 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-09-23T22:04:10.875Z,1569276250.875 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-09-23T22:04:15.870Z,1569276255.870 [DataOverHttps](INFO): Sending 96 bytes from file Logs/20190923T212020/Express0017.lzma
2019-09-23T22:04:17.874Z,1569276257.874 [DataOverHttps](INFO): Moved sent file to Logs/20190923T212020/Express0017.lzma.bak
2019-09-23T22:04:17.875Z,1569276257.875 [DataOverHttps](INFO): SBD MOMSN=11806013
2019-09-23T22:04:36.716Z,1569276276.716 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-09-23T22:04:36.784Z,1569276276.784 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-09-23T22:04:43.522Z,1569276283.522 [DVL_micro](ERROR): Failed to parse:
:RD,+9999.99,+9999.99,+9999.99,+9999.99
2019-09-23T22:04:49.991Z,1569276289.991 [DataOverHttps](INFO): Sending 898 bytes from file Logs/20190923T214728/Express0001.lzma
2019-09-23T22:04:51.990Z,1569276291.990 [DataOverHttps](INFO): Moved sent file to Logs/20190923T214728/Express0001.lzma.bak
2019-09-23T22:04:51.991Z,1569276291.991 [DataOverHttps](INFO): SBD MOMSN=11806016
2019-09-23T22:05:16.650Z,1569276316.650 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2019-09-23T22:05:16.650Z,1569276316.650 [DVL_micro](ERROR): Failed to parse:
:TS,000,+21.0,0000.0,1489.0,000
2019-09-23T22:05:53.491Z,1569276353.491 [DataOverHttps](INFO): Sending 728 bytes from file Logs/20190923T215103/Express0001.lzma
2019-09-23T22:05:55.486Z,1569276355.486 [DataOverHttps](INFO): Moved sent file to Logs/20190923T215103/Express0001.lzma.bak
2019-09-23T22:05:55.487Z,1569276355.487 [DataOverHttps](INFO): SBD MOMSN=11806049
2019-09-23T22:05:57.444Z,1569276357.444 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2019-09-23T22:05:57.463Z,1569276357.463 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0000.0,1489.0,000
2019-09-23T22:06:15.512Z,1569276375.512 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20190923T215103/Express0005.lzma
2019-09-23T22:06:17.518Z,1569276377.518 [DataOverHttps](INFO): Moved sent file to Logs/20190923T215103/Express0005.lzma.bak
2019-09-23T22:06:17.519Z,1569276377.519 [DataOverHttps](INFO): SBD MOMSN=11806066
2019-09-23T22:06:25.494Z,1569276385.494 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-09-23T22:06:42.904Z,1569276402.904 [DataOverHttps](INFO): Sending 1027 bytes from file Logs/20190923T215529/Express0001.lzma
2019-09-23T22:06:44.906Z,1569276404.906 [DataOverHttps](INFO): Moved sent file to Logs/20190923T215529/Express0001.lzma.bak
2019-09-23T22:06:44.906Z,1569276404.906 [DataOverHttps](INFO): SBD MOMSN=11806068
2019-09-23T22:06:51.814Z,1569276411.814 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2019-09-23T22:06:51.817Z,1569276411.817 [BPC1](INFO): Received data from all battery sticks.
2019-09-23T22:07:20.962Z,1569276440.962 [DataOverHttps](INFO): Sending 783 bytes from file Logs/20190923T215902/Express0001.lzma
2019-09-23T22:07:22.966Z,1569276442.966 [DataOverHttps](INFO): Moved sent file to Logs/20190923T215902/Express0001.lzma.bak
2019-09-23T22:07:22.967Z,1569276442.967 [DataOverHttps](INFO): SBD MOMSN=11806091
2019-09-23T22:07:41.580Z,1569276461.580 [DataOverHttps](INFO): Sending 415 bytes from file Logs/20190923T215902/Express0005.lzma
2019-09-23T22:07:43.574Z,1569276463.574 [DataOverHttps](INFO): Moved sent file to Logs/20190923T215902/Express0005.lzma.bak
2019-09-23T22:07:43.575Z,1569276463.575 [DataOverHttps](INFO): SBD MOMSN=11806113
2019-09-23T22:07:45.090Z,1569276465.090 [CommandLine](IMPORTANT): got command failComponent
2019-09-23T22:07:45.090Z,1569276465.090 [CommandLine](IMPORTANT): Failed components:
2019-09-23T22:07:45.090Z,1569276465.090 [CommandLine](IMPORTANT): No failed Components.
2019-09-23T22:07:47.958Z,1569276467.958 [Default:CheckIn:Read_Iridium] Stopped
2019-09-23T22:07:47.958Z,1569276467.958 [Default:CheckIn:C.Wait] Running Loop=1
2019-09-23T22:07:47.958Z,1569276467.958 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-09-23T22:09:52.021Z,1569276592.021 [DVL_micro](ERROR): DVL uart error: serial timeout
2019-09-23T22:09:52.021Z,1569276592.021 [DVL_micro] Communications Fault, FailCount= 1
2019-09-23T22:09:52.021Z,1569276592.021 [DVL_micro](ERROR): Communications Fault
2019-09-23T22:09:52.021Z,1569276592.021 [DVL_micro](ERROR): Failed to parse:
2019-09-23T22:09:52.064Z,1569276592.064 [CBIT](ERROR): Communications Fault in component: DVL_micro
2019-09-23T22:09:52.429Z,1569276592.429 [DVL_micro](INFO): Powering down
2019-09-23T22:09:53.210Z,1569276593.210 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-09-23T22:09:53.210Z,1569276593.210 [DVL_micro] No Fault, FailCount= 1
2019-09-23T22:10:06.913Z,1569276606.913 [DVL_micro](ERROR): only read 0 of 4 data items
2019-09-23T22:10:06.914Z,1569276606.914 [DVL_micro](ERROR): Failed to parse:
:RD,,+9999.99,+9999.99,+9999.99
2019-09-23T22:11:23.264Z,1569276683.264 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2019-09-23T22:11:23.264Z,1569276683.264 [DVL_micro](ERROR): Failed to parse:
:TS,000000,35.0000.0,148

2019-09-23T22:12:47.303Z,1569276767.303 [DVL_micro](ERROR): Failed to parse:
:BD,+00000000.00,+00000000.00,+00000000.00,900.00
2019-09-23T22:12:48.579Z,1569276768.579 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-09-23T22:12:48.580Z,1569276768.580 [Default:CheckIn:C.Wait] Stopped
2019-09-23T22:12:48.580Z,1569276768.580 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-09-23T22:12:48.580Z,1569276768.580 [Default:CheckIn:D] Running Loop=1
2019-09-23T22:12:48.966Z,1569276768.966 [Default:CheckIn:D] Stopped
2019-09-23T22:12:48.966Z,1569276768.966 [Default:CheckIn:E] Running Loop=1
2019-09-23T22:12:49.374Z,1569276769.374 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.015956 min 
2019-09-23T22:12:49.374Z,1569276769.374 [Default:CheckIn:E] Stopped
2019-09-23T22:12:49.374Z,1569276769.374 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-09-23T22:12:49.374Z,1569276769.374 [Default:CheckIn] Stopped
2019-09-23T22:12:49.375Z,1569276769.375 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-09-23T22:12:49.375Z,1569276769.375 [Default:CheckIn](INFO): Running loop #2
2019-09-23T22:12:49.375Z,1569276769.375 [Default:CheckIn] Running Loop=2
2019-09-23T22:12:49.375Z,1569276769.375 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-09-23T22:12:49.375Z,1569276769.375 [Default:CheckIn:Read_GPS] Running Loop=1
2019-09-23T22:12:50.960Z,1569276770.960 [NAL9602](DEBUG): Fix Requested
2019-09-23T22:12:51.344Z,1569276771.344 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,221250.00,A,3648.16479,N,12147.27960,W,0.369,71.09,230919,,,A*46
2019-09-23T22:12:51.346Z,1569276771.346 [NAL9602](INFO): GPS fix at 20190923T221250: (36.802746, -121.787993)
2019-09-23T22:12:51.406Z,1569276771.406 [Default:CheckIn:Read_GPS] Stopped
2019-09-23T22:12:51.406Z,1569276771.406 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-09-23T22:13:00.605Z,1569276780.605 [DataOverHttps](INFO): Sending 223 bytes from file Logs/20190923T215902/Courier0007.lzma
2019-09-23T22:13:02.610Z,1569276782.610 [DataOverHttps](INFO): Moved sent file to Logs/20190923T215902/Courier0007.lzma.bak
2019-09-23T22:13:02.611Z,1569276782.611 [DataOverHttps](INFO): SBD MOMSN=11806164
2019-09-23T22:13:12.750Z,1569276792.750 [DVL_micro](ERROR): Failed to parse:
:000000000,35.0,+21.1,0000.0,1489.0,000
2019-09-23T22:13:23.393Z,1569276803.393 [DataOverHttps](INFO): Sending 209 bytes from file Logs/20190923T215902/Express0008.lzma
2019-09-23T22:13:25.398Z,1569276805.398 [DataOverHttps](INFO): Moved sent file to Logs/20190923T215902/Express0008.lzma.bak
2019-09-23T22:13:25.399Z,1569276805.399 [DataOverHttps](INFO): SBD MOMSN=11806167
2019-09-23T22:13:29.370Z,1569276809.370 [Default:CheckIn:Read_Iridium] Stopped
2019-09-23T22:13:29.371Z,1569276809.371 [Default:CheckIn:C.Wait] Running Loop=1
2019-09-23T22:13:29.371Z,1569276809.371 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-09-23T22:14:03.661Z,1569276843.661 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2019-09-23T22:14:03.662Z,1569276843.662 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+21.1,0000.0,1489.0,,+00335,+00022,+00601,+00000,A
2019-09-23T22:14:36.793Z,1569276876.793 [DVL_micro](ERROR): DVL BIT error. See manual. Result code: 164
2019-09-23T22:14:36.795Z,1569276876.795 [DVL_micro](ERROR): Failed to parse:
:RD,,+9999.999,+9999.99
2019-09-23T22:15:27.710Z,1569276927.710 [DVL_micro](ERROR): only read 3 of 4 data items
2019-09-23T22:15:27.710Z,1569276927.710 [DVL_micro](ERROR): Failed to parse:
:BI,+00120,+00475,00000,I
2019-09-23T22:17:17.180Z,1569277037.180 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2019-09-23T22:17:17.180Z,1569277037.180 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000,+21.2,0000.0,1489.0,000
2019-09-23T22:17:39.817Z,1569277059.817 [NAL9602](INFO): SBD MO Status=2, MOMSN=1570, MT Status=2, MTMSN=0
2019-09-23T22:17:39.817Z,1569277059.817 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-09-23T22:17:53.135Z,1569277073.135 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-09-23T22:18:23.842Z,1569277103.842 [NAL9602](INFO): Not Powering down - fast GPS
2019-09-23T22:18:29.947Z,1569277109.947 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-09-23T22:18:29.947Z,1569277109.947 [Default:CheckIn:C.Wait] Stopped
2019-09-23T22:18:29.947Z,1569277109.947 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-09-23T22:18:29.947Z,1569277109.947 [Default:CheckIn:D] Running Loop=1
2019-09-23T22:18:30.356Z,1569277110.356 [Default:CheckIn:D] Stopped
2019-09-23T22:18:30.356Z,1569277110.356 [Default:CheckIn:E] Running Loop=1
2019-09-23T22:18:30.782Z,1569277110.782 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 15.705788 min 
2019-09-23T22:18:30.782Z,1569277110.782 [Default:CheckIn:E] Stopped
2019-09-23T22:18:30.782Z,1569277110.782 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-09-23T22:18:30.782Z,1569277110.782 [Default:CheckIn] Stopped
2019-09-23T22:18:30.782Z,1569277110.782 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-09-23T22:18:30.782Z,1569277110.782 [Default:CheckIn](INFO): Running loop #3
2019-09-23T22:18:30.782Z,1569277110.782 [Default:CheckIn] Running Loop=3
2019-09-23T22:18:30.782Z,1569277110.782 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-09-23T22:18:30.782Z,1569277110.782 [Default:CheckIn:Read_GPS] Running Loop=1
2019-09-23T22:18:32.333Z,1569277112.333 [NAL9602](DEBUG): Fix Requested
2019-09-23T22:18:32.726Z,1569277112.726 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,221832.00,A,3648.17282,N,12147.28750,W,0.525,71.09,230919,,,A*47
2019-09-23T22:18:32.728Z,1569277112.728 [NAL9602](INFO): GPS fix at 20190923T221832: (36.802880, -121.788125)
2019-09-23T22:18:32.782Z,1569277112.782 [Default:CheckIn:Read_GPS] Stopped
2019-09-23T22:18:32.782Z,1569277112.782 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-09-23T22:18:41.220Z,1569277121.220 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2019-09-23T22:18:41.220Z,1569277121.220 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35,0000.0,148

2019-09-23T22:18:41.760Z,1569277121.760 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20190923T215902/Courier0010.lzma
2019-09-23T22:18:43.766Z,1569277123.766 [DataOverHttps](INFO): Moved sent file to Logs/20190923T215902/Courier0010.lzma.bak
2019-09-23T22:18:43.767Z,1569277123.767 [DataOverHttps](INFO): SBD MOMSN=11806226
2019-09-23T22:19:03.431Z,1569277143.431 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2019-09-23T22:19:03.513Z,1569277143.513 [NAL9602](FAULT): received: 
+CSQ:0

OK70, 2, 0, 0, 0

OK
2019-09-23T22:19:03.513Z,1569277143.513 [NAL9602] Data Fault, FailCount= 1
2019-09-23T22:19:03.513Z,1569277143.513 [NAL9602](ERROR): Data Fault
2019-09-23T22:19:03.634Z,1569277143.634 [CBIT](ERROR): Data Fault in component: NAL9602
2019-09-23T22:19:03.844Z,1569277143.844 [NAL9602](INFO): Powering down
2019-09-23T22:19:04.740Z,1569277144.740 [CBIT](INFO): Clearing failed state for component NAL9602
2019-09-23T22:19:04.740Z,1569277144.740 [NAL9602] No Fault, FailCount= 1
2019-09-23T22:19:06.664Z,1569277146.664 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2019-09-23T22:19:06.664Z,1569277146.664 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,00.0,1489.WI,0558,+

2019-09-23T22:19:07.729Z,1569277147.729 [DataOverHttps](INFO): Sending 194 bytes from file Logs/20190923T215902/Express0011.lzma
2019-09-23T22:19:09.734Z,1569277149.734 [DataOverHttps](INFO): Moved sent file to Logs/20190923T215902/Express0011.lzma.bak
2019-09-23T22:19:09.735Z,1569277149.735 [DataOverHttps](INFO): SBD MOMSN=11806232
2019-09-23T22:19:13.564Z,1569277153.564 [Default:CheckIn:Read_Iridium] Stopped
2019-09-23T22:19:13.564Z,1569277153.564 [Default:CheckIn:C.Wait] Running Loop=1
2019-09-23T22:19:13.569Z,1569277153.569 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-09-23T22:19:24.440Z,1569277164.440 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2019-09-23T22:19:24.441Z,1569277164.441 [DVL_micro](ERROR): Failed to parse:
:TS,000000035.0,+21.2,0000.0,1489.0,000
2019-09-23T22:19:32.123Z,1569277172.123 [DVL_micro](ERROR): Failed to parse:
:BD,+00000000.00,+00000000.00,+00000000.00,9999.99,000.00
2019-09-23T22:19:34.138Z,1569277174.138 [NAL9602](INFO): Powering up NAL9602
2019-09-23T22:19:45.063Z,1569277185.063 [NAL9602](INFO): NAL9602 initialized
2019-09-23T22:19:57.577Z,1569277197.577 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2019-09-23T22:19:57.577Z,1569277197.577 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+21.2,0000.0,1489.0I,+01577+00282,+00000,A
2019-09-23T22:20:16.163Z,1569277216.163 [NAL9602](INFO): Not Powering down - fast GPS
2019-09-23T22:20:23.031Z,1569277223.031 [DVL_micro](ERROR): only read 3 of 4 data items
2019-09-23T22:20:23.031Z,1569277223.031 [DVL_micro](ERROR): Failed to parse:
:BI,+0015,+00495,+00000,I
2019-09-23T22:20:58.587Z,1569277258.587 [DVL_micro](ERROR): Failed to parse:
:BD,+00000000.00,+00000000.00,+00000000.00,999900
2019-09-23T22:22:14.946Z,1569277334.946 [DVL_micro](ERROR): Failed to parse:
9.99,+9999.99,+9999.99,+9999.99
2019-09-23T22:23:28.871Z,1569277408.871 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2019-09-23T22:23:28.871Z,1569277408.871 [DVL_micro](ERROR): Failed to parse:
:TS0000000,35.0,+21.3,0000.0,1489.0,000
2019-09-23T22:24:14.155Z,1569277454.155 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-09-23T22:24:14.155Z,1569277454.155 [Default:CheckIn:C.Wait] Stopped
2019-09-23T22:24:14.155Z,1569277454.155 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-09-23T22:24:14.155Z,1569277454.155 [Default:CheckIn:D] Running Loop=1
2019-09-23T22:24:14.605Z,1569277454.605 [Default:CheckIn:D] Stopped
2019-09-23T22:24:14.605Z,1569277454.605 [Default:CheckIn:E] Running Loop=1
2019-09-23T22:24:14.975Z,1569277454.975 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 21.443278 min 
2019-09-23T22:24:14.975Z,1569277454.975 [Default:CheckIn:E] Stopped
2019-09-23T22:24:14.975Z,1569277454.975 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-09-23T22:24:14.975Z,1569277454.975 [Default:CheckIn] Stopped
2019-09-23T22:24:14.975Z,1569277454.975 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-09-23T22:24:14.975Z,1569277454.975 [Default:CheckIn](INFO): Running loop #4
2019-09-23T22:24:14.975Z,1569277454.975 [Default:CheckIn] Running Loop=4
2019-09-23T22:24:14.976Z,1569277454.976 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-09-23T22:24:14.976Z,1569277454.976 [Default:CheckIn:Read_GPS] Running Loop=1
2019-09-23T22:24:16.553Z,1569277456.553 [NAL9602](DEBUG): Fix Requested
2019-09-23T22:24:16.973Z,1569277456.973 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,222416.00,A,3648.16369,N,12147.28468,W,0.156,190.88,230919,,,A*74
2019-09-23T22:24:16.976Z,1569277456.976 [NAL9602](INFO): GPS fix at 20190923T222416: (36.802728, -121.788078)
2019-09-23T22:24:17.025Z,1569277457.025 [Default:CheckIn:Read_GPS] Stopped
2019-09-23T22:24:17.025Z,1569277457.025 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-09-23T22:24:18.970Z,1569277458.970 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-09-23T22:24:33.096Z,1569277473.096 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20190923T215902/Courier0013.lzma
2019-09-23T22:24:35.102Z,1569277475.102 [DataOverHttps](INFO): Moved sent file to Logs/20190923T215902/Courier0013.lzma.bak
2019-09-23T22:24:35.103Z,1569277475.103 [DataOverHttps](INFO): SBD MOMSN=11806243
2019-09-23T22:24:49.682Z,1569277489.682 [NAL9602](INFO): Not Powering down - fast GPS
2019-09-23T22:24:55.346Z,1569277495.346 [DVL_micro](ERROR): Failed to parse:
:WI,+00284+00588,+00000,A
2019-09-23T22:25:04.973Z,1569277504.973 [DataOverHttps](INFO): Sending 162 bytes from file Logs/20190923T215902/Express0014.lzma
2019-09-23T22:25:06.978Z,1569277506.978 [DataOverHttps](INFO): Moved sent file to Logs/20190923T215902/Express0014.lzma.bak
2019-09-23T22:25:06.979Z,1569277506.979 [DataOverHttps](INFO): SBD MOMSN=11806246
2019-09-23T22:25:10.772Z,1569277510.772 [Default:CheckIn:Read_Iridium] Stopped
2019-09-23T22:25:10.772Z,1569277510.772 [Default:CheckIn:C.Wait] Running Loop=1
2019-09-23T22:25:10.772Z,1569277510.772 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-09-23T22:25:18.370Z,1569277518.370 [DVL_micro](ERROR): Failed to parse:
:T00000000,35.0,+21.3,0000.0,1489.0,000
2019-09-23T22:26:29.498Z,1569277589.498 [DVL_micro](ERROR): Failed to parse:
:SA,-01.48,-02.91,143.4
2019-09-23T22:27:00.202Z,1569277620.202 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2019-09-23T22:27:00.203Z,1569277620.203 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+21.4,0000.0,1489.0I,+00281,+00117,+00563,+00000,A
2019-09-23T22:27:58.775Z,1569277678.775 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2019-09-23T22:27:58.775Z,1569277678.775 [DVL_micro](ERROR): Failed to parse:
:TS0000000,35.0,+21.4,0000.0,1489.0,000
2019-09-23T22:30:11.356Z,1569277811.356 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-09-23T22:30:11.356Z,1569277811.356 [Default:CheckIn:C.Wait] Stopped
2019-09-23T22:30:11.356Z,1569277811.356 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-09-23T22:30:11.356Z,1569277811.356 [Default:CheckIn:D] Running Loop=1
2019-09-23T22:30:11.764Z,1569277811.764 [Default:CheckIn:D] Stopped
2019-09-23T22:30:11.764Z,1569277811.764 [Default:CheckIn:E] Running Loop=1
2019-09-23T22:30:12.174Z,1569277812.174 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 27.395931 min 
2019-09-23T22:30:12.174Z,1569277812.174 [Default:CheckIn:E] Stopped
2019-09-23T22:30:12.174Z,1569277812.174 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-09-23T22:30:12.174Z,1569277812.174 [Default:CheckIn] Stopped
2019-09-23T22:30:12.174Z,1569277812.174 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-09-23T22:30:12.175Z,1569277812.175 [Default:CheckIn](INFO): Running loop #5
2019-09-23T22:30:12.175Z,1569277812.175 [Default:CheckIn] Running Loop=5
2019-09-23T22:30:12.175Z,1569277812.175 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-09-23T22:30:12.175Z,1569277812.175 [Default:CheckIn:Read_GPS] Running Loop=1
2019-09-23T22:30:13.749Z,1569277813.749 [NAL9602](DEBUG): Fix Requested
2019-09-23T22:30:14.144Z,1569277814.144 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,223013.00,A,3648.16550,N,12147.28041,W,0.447,190.88,230919,,,A*72
2019-09-23T22:30:14.147Z,1569277814.147 [NAL9602](INFO): GPS fix at 20190923T223013: (36.802758, -121.788007)
2019-09-23T22:30:14.196Z,1569277814.196 [Default:CheckIn:Read_GPS] Stopped
2019-09-23T22:30:14.196Z,1569277814.196 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-09-23T22:30:25.056Z,1569277825.056 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20190923T215902/Courier0016.lzma
2019-09-23T22:30:27.062Z,1569277827.062 [DataOverHttps](INFO): Moved sent file to Logs/20190923T215902/Courier0016.lzma.bak
2019-09-23T22:30:27.063Z,1569277827.063 [DataOverHttps](INFO): SBD MOMSN=11806265
2019-09-23T22:30:32.756Z,1569277832.756 [NAL9602](INFO): SBD MO Status=2, MOMSN=1570, MT Status=2, MTMSN=0
2019-09-23T22:30:32.756Z,1569277832.756 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-09-23T22:30:49.320Z,1569277849.320 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2019-09-23T22:30:49.321Z,1569277849.321 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+21.4,0000.0,148

2019-09-23T22:30:52.960Z,1569277852.960 [NAL9602](INFO): SBD MO Status=0, MOMSN=1570, MT Status=0, MTMSN=0
2019-09-23T22:30:52.960Z,1569277852.960 [NAL9602](INFO): No messages in MT queue
2019-09-23T22:30:53.001Z,1569277853.001 [DataOverHttps](INFO): Sending 195 bytes from file Logs/20190923T215902/Express0017.lzma
2019-09-23T22:30:56.106Z,1569277856.106 [DataOverHttps](INFO): Moved sent file to Logs/20190923T215902/Express0017.lzma.bak
2019-09-23T22:30:56.106Z,1569277856.106 [DataOverHttps](INFO): SBD MOMSN=11806268
2019-09-23T22:30:59.064Z,1569277859.064 [Default:CheckIn:Read_Iridium] Stopped
2019-09-23T22:30:59.064Z,1569277859.064 [Default:CheckIn:C.Wait] Running Loop=1
2019-09-23T22:30:59.064Z,1569277859.064 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-09-23T22:31:14.784Z,1569277874.784 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2019-09-23T22:31:14.785Z,1569277874.785 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,.4,0000.0,1489.0,000
2019-09-23T22:31:23.666Z,1569277883.666 [NAL9602](INFO): Not Powering down - fast GPS
2019-09-23T22:31:32.556Z,1569277892.556 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2019-09-23T22:31:32.556Z,1569277892.556 [DVL_micro](ERROR): Failed to parse:
:TS0000000,35.0,+21.4,0000.0,1489.0,000
2019-09-23T22:31:40.230Z,1569277900.230 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2019-09-23T22:31:40.231Z,1569277900.231 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,00.0,1489:WI,+0033,+00572,+00000,A
2019-09-23T22:32:05.688Z,1569277925.688 [DVL_micro](ERROR): Failed to parse:
:BD,+00000000.00,+00000000.00,+00000000.00,9999.99,000.00
2019-09-23T22:34:20.634Z,1569278060.634 [DVL_micro](ERROR): only read 3 of 4 data items
2019-09-23T22:34:20.634Z,1569278060.634 [DVL_micro](ERROR): Failed to parse:
:BI,-0141,+00692,+00000,I
2019-09-23T22:34:46.077Z,1569278086.077 [DVL_micro](ERROR): only read 3 of 4 data items
2019-09-23T22:34:46.077Z,1569278086.077 [DVL_micro](ERROR): Failed to parse:
:BI,+00225,+0693,+00000,I
2019-09-23T22:35:11.532Z,1569278111.532 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2019-09-23T22:35:11.533Z,1569278111.533 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+21.4,0000.0,148

2019-09-23T22:35:59.681Z,1569278159.681 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-09-23T22:35:59.681Z,1569278159.681 [Default:CheckIn:C.Wait] Stopped
2019-09-23T22:35:59.681Z,1569278159.681 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-09-23T22:35:59.681Z,1569278159.681 [Default:CheckIn:D] Running Loop=1
2019-09-23T22:36:00.039Z,1569278160.039 [Default:CheckIn:D] Stopped
2019-09-23T22:36:00.039Z,1569278160.039 [Default:CheckIn:E] Running Loop=1
2019-09-23T22:36:00.474Z,1569278160.474 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 33.200500 min 
2019-09-23T22:36:00.474Z,1569278160.474 [Default:CheckIn:E] Stopped
2019-09-23T22:36:00.474Z,1569278160.474 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-09-23T22:36:00.474Z,1569278160.474 [Default:CheckIn] Stopped
2019-09-23T22:36:00.474Z,1569278160.474 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-09-23T22:36:00.474Z,1569278160.474 [Default:CheckIn](INFO): Running loop #6
2019-09-23T22:36:00.474Z,1569278160.474 [Default:CheckIn] Running Loop=6
2019-09-23T22:36:00.475Z,1569278160.475 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-09-23T22:36:00.475Z,1569278160.475 [Default:CheckIn:Read_GPS] Running Loop=1
2019-09-23T22:36:02.042Z,1569278162.042 [NAL9602](DEBUG): Fix Requested
2019-09-23T22:36:02.445Z,1569278162.445 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,223601.00,A,3648.13818,N,12147.23361,W,0.058,108.31,230919,,,A*70
2019-09-23T22:36:02.447Z,1569278162.447 [NAL9602](INFO): GPS fix at 20190923T223601: (36.802303, -121.787227)
2019-09-23T22:36:02.504Z,1569278162.504 [Default:CheckIn:Read_GPS] Stopped
2019-09-23T22:36:02.504Z,1569278162.504 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-09-23T22:36:03.650Z,1569278163.650 [NAL9602](ERROR): parseGSV uart error: serial buffer full
2019-09-23T22:36:12.576Z,1569278172.576 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20190923T215902/Courier0019.lzma
2019-09-23T22:36:14.582Z,1569278174.582 [DataOverHttps](INFO): Moved sent file to Logs/20190923T215902/Courier0019.lzma.bak
2019-09-23T22:36:14.583Z,1569278174.583 [DataOverHttps](INFO): SBD MOMSN=11806280
2019-09-23T22:36:37.993Z,1569278197.993 [DataOverHttps](INFO): Sending 119 bytes from file Logs/20190923T215902/Express0020.lzma
2019-09-23T22:36:40.005Z,1569278200.005 [DataOverHttps](INFO): Moved sent file to Logs/20190923T215902/Express0020.lzma.bak
2019-09-23T22:36:40.005Z,1569278200.005 [DataOverHttps](INFO): SBD MOMSN=11806284
2019-09-23T22:36:43.720Z,1569278203.720 [Default:CheckIn:Read_Iridium] Stopped
2019-09-23T22:36:43.720Z,1569278203.720 [Default:CheckIn:C.Wait] Running Loop=1
2019-09-23T22:36:43.720Z,1569278203.720 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-09-23T22:37:18.809Z,1569278238.809 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2019-09-23T22:37:18.809Z,1569278238.809 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+21.5,0000.0,148

2019-09-23T22:37:18.811Z,1569278238.811 [NAL9602](INFO): SBD MO Status=0, MOMSN=1571, MT Status=0, MTMSN=0
2019-09-23T22:37:18.812Z,1569278238.812 [NAL9602](INFO): No messages in MT queue
2019-09-23T22:37:44.253Z,1569278264.253 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2019-09-23T22:37:44.253Z,1569278264.253 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+21.,1489.0,000
2019-09-23T22:37:49.506Z,1569278269.506 [NAL9602](INFO): Not Powering down - fast GPS
2019-09-23T22:38:47.681Z,1569278327.681 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2019-09-23T22:38:47.681Z,1569278327.681 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+2.0,1489.0,000
2019-09-23T22:39:10.722Z,1569278350.722 [DVL_micro](ERROR): Failed to parse:
:SA,-01.29,-02.88,110.2
2019-09-23T22:40:42.440Z,1569278442.440 [DVL_micro](ERROR): Failed to parse:
:WI+00128,+0000,A
2019-09-23T22:41:07.892Z,1569278467.892 [DVL_micro](ERROR): only read 3 of 4 data items
2019-09-23T22:41:07.892Z,1569278467.892 [DVL_micro](ERROR): Failed to parse:
:RD,+9999.99,+9999.99,+9999.99,+

2019-09-23T22:41:44.317Z,1569278504.317 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-09-23T22:41:44.317Z,1569278504.317 [Default:CheckIn:C.Wait] Stopped
2019-09-23T22:41:44.317Z,1569278504.317 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-09-23T22:41:44.317Z,1569278504.317 [Default:CheckIn:D] Running Loop=1
2019-09-23T22:41:44.705Z,1569278504.705 [Default:CheckIn:D] Stopped
2019-09-23T22:41:44.706Z,1569278504.706 [Default:CheckIn:E] Running Loop=1
2019-09-23T22:41:45.131Z,1569278505.131 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 38.944950 min 
2019-09-23T22:41:45.131Z,1569278505.131 [Default:CheckIn:E] Stopped
2019-09-23T22:41:45.131Z,1569278505.131 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-09-23T22:41:45.131Z,1569278505.131 [Default:CheckIn] Stopped
2019-09-23T22:41:45.131Z,1569278505.131 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-09-23T22:41:45.131Z,1569278505.131 [Default:CheckIn](INFO): Running loop #7
2019-09-23T22:41:45.131Z,1569278505.131 [Default:CheckIn] Running Loop=7
2019-09-23T22:41:45.132Z,1569278505.132 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-09-23T22:41:45.132Z,1569278505.132 [Default:CheckIn:Read_GPS] Running Loop=1
2019-09-23T22:41:46.685Z,1569278506.685 [NAL9602](DEBUG): Fix Requested
2019-09-23T22:41:47.080Z,1569278507.080 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,224146.00,A,3648.13667,N,12147.23340,W,0.039,108.31,230919,,,D*74
2019-09-23T22:41:47.082Z,1569278507.082 [NAL9602](INFO): GPS fix at 20190923T224146: (36.802278, -121.787223)
2019-09-23T22:41:47.110Z,1569278507.110 [Default:CheckIn:Read_GPS] Stopped
2019-09-23T22:41:47.110Z,1569278507.110 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-09-23T22:41:48.706Z,1569278508.706 [NAL9602](ERROR): parseGSV uart error: serial buffer full
2019-09-23T22:41:50.668Z,1569278510.668 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20190923T215902/Courier0022.lzma
2019-09-23T22:41:52.674Z,1569278512.674 [DataOverHttps](INFO): Moved sent file to Logs/20190923T215902/Courier0022.lzma.bak
2019-09-23T22:41:52.675Z,1569278512.675 [DataOverHttps](INFO): SBD MOMSN=11806306
2019-09-23T22:41:58.795Z,1569278518.795 [DVL_micro](ERROR): Failed to parse:
:RD,+9999.99,+9999.99,+99999.99
2019-09-23T22:42:00.004Z,1569278520.004 [NAL9602](INFO): SBD MO Status=0, MOMSN=1572, MT Status=0, MTMSN=0
2019-09-23T22:42:00.004Z,1569278520.004 [NAL9602](INFO): No messages in MT queue
2019-09-23T22:42:12.432Z,1569278532.432 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20190923T215902/Express0023.lzma
2019-09-23T22:42:14.438Z,1569278534.438 [DataOverHttps](INFO): Moved sent file to Logs/20190923T215902/Express0023.lzma.bak
2019-09-23T22:42:14.439Z,1569278534.439 [DataOverHttps](INFO): SBD MOMSN=11806310
2019-09-23T22:42:17.858Z,1569278537.858 [Default:CheckIn:Read_Iridium] Stopped
2019-09-23T22:42:17.859Z,1569278537.859 [Default:CheckIn:C.Wait] Running Loop=1
2019-09-23T22:42:17.859Z,1569278537.859 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-09-23T22:42:30.714Z,1569278550.714 [NAL9602](INFO): Not Powering down - fast GPS
2019-09-23T22:42:49.708Z,1569278569.708 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2019-09-23T22:42:49.708Z,1569278569.708 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,.6,0000.0,1489.0,000
2019-09-23T22:43:15.156Z,1569278595.156 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2019-09-23T22:43:15.157Z,1569278595.157 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,00.0,1489.0,000
2019-09-23T22:43:58.392Z,1569278638.392 [DVL_micro](ERROR): only read 0 of 4 data items
2019-09-23T22:43:58.392Z,1569278638.392 [DVL_micro](ERROR): Failed to parse:
:RD,++9999.99,+9999.99,+9999.99
2019-09-23T22:45:17.179Z,1569278717.179 [DVL_micro](ERROR): Failed to parse:
:WI,-00173,-00009,+00803,+00000,A
2019-09-23T22:45:40.204Z,1569278740.204 [DVL_micro](ERROR): only read 2 of 4 data items
2019-09-23T22:45:40.204Z,1569278740.204 [DVL_micro](ERROR): Failed to parse:
:RD,+9999.99,+9999.99,++9999.99
2019-09-23T22:46:05.670Z,1569278765.670 [DVL_micro](ERROR): only read 0 of 4 data items
2019-09-23T22:46:05.670Z,1569278765.670 [DVL_micro](ERROR): Failed to parse::RD,,+9999.99,+9999.99,+9999.99
2019-09-23T22:46:31.109Z,1569278791.109 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2019-09-23T22:46:31.110Z,1569278791.110 [DVL_micro](ERROR): Failed to parse:
:TS0000000,35,0000.0,1489.0,000
2019-09-23T22:47:18.399Z,1569278838.399 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-09-23T22:47:18.399Z,1569278838.399 [Default:CheckIn:C.Wait] Stopped
2019-09-23T22:47:18.399Z,1569278838.399 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-09-23T22:47:18.400Z,1569278838.400 [Default:CheckIn:D] Running Loop=1
2019-09-23T22:47:18.814Z,1569278838.814 [Default:CheckIn:D] Stopped
2019-09-23T22:47:18.814Z,1569278838.814 [Default:CheckIn:E] Running Loop=1
2019-09-23T22:47:19.240Z,1569278839.240 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 44.513428 min 
2019-09-23T22:47:19.240Z,1569278839.240 [Default:CheckIn:E] Stopped
2019-09-23T22:47:19.240Z,1569278839.240 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-09-23T22:47:19.240Z,1569278839.240 [Default:CheckIn] Stopped
2019-09-23T22:47:19.240Z,1569278839.240 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-09-23T22:47:19.240Z,1569278839.240 [Default:CheckIn](INFO): Running loop #8
2019-09-23T22:47:19.240Z,1569278839.240 [Default:CheckIn] Running Loop=8
2019-09-23T22:47:19.241Z,1569278839.241 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-09-23T22:47:19.241Z,1569278839.241 [Default:CheckIn:Read_GPS] Running Loop=1
2019-09-23T22:47:20.809Z,1569278840.809 [NAL9602](DEBUG): Fix Requested
2019-09-23T22:47:21.201Z,1569278841.201 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,224720.00,A,3648.15130,N,12147.22205,W,0.000,24.36,230919,,,D*42
2019-09-23T22:47:21.203Z,1569278841.203 [NAL9602](INFO): GPS fix at 20190923T224720: (36.802522, -121.787034)
2019-09-23T22:47:21.266Z,1569278841.266 [Default:CheckIn:Read_GPS] Stopped
2019-09-23T22:47:21.266Z,1569278841.266 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-09-23T22:47:22.116Z,1569278842.116 [DVL_micro](ERROR): only read 0 of 4 data items
2019-09-23T22:47:22.116Z,1569278842.116 [DVL_micro](ERROR): Failed to parse:
:RD,++9999.99,+9999.99,+9999.99
2019-09-23T22:47:22.519Z,1569278842.519 [NAL9602](ERROR): parseGSV uart error: serial buffer full
2019-09-23T22:47:26.820Z,1569278846.820 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20190923T215902/Courier0025.lzma
2019-09-23T22:47:28.839Z,1569278848.839 [DataOverHttps](INFO): Moved sent file to Logs/20190923T215902/Courier0025.lzma.bak
2019-09-23T22:47:28.839Z,1569278848.839 [DataOverHttps](INFO): SBD MOMSN=11806325
2019-09-23T22:47:40.676Z,1569278860.676 [NAL9602](INFO): SBD MO Status=0, MOMSN=1573, MT Status=0, MTMSN=0
2019-09-23T22:47:40.676Z,1569278860.676 [NAL9602](INFO): No messages in MT queue
2019-09-23T22:47:48.436Z,1569278868.436 [DataOverHttps](INFO): Sending 119 bytes from file Logs/20190923T215902/Express0026.lzma
2019-09-23T22:47:49.980Z,1569278869.980 [DVL_micro](ERROR): Failed to parse:
:BI,+00308,+00014,+00620,+00000,I
2019-09-23T22:47:50.442Z,1569278870.442 [DataOverHttps](INFO): Moved sent file to Logs/20190923T215902/Express0026.lzma.bak
2019-09-23T22:47:50.443Z,1569278870.443 [DataOverHttps](INFO): SBD MOMSN=11806328
2019-09-23T22:47:54.053Z,1569278874.053 [Default:CheckIn:Read_Iridium] Stopped
2019-09-23T22:47:54.053Z,1569278874.053 [Default:CheckIn:C.Wait] Running Loop=1
2019-09-23T22:47:54.053Z,1569278874.053 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-09-23T22:48:11.382Z,1569278891.382 [NAL9602](INFO): Not Powering down - fast GPS
2019-09-23T22:50:58.276Z,1569279058.276 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2019-09-23T22:50:58.276Z,1569279058.276 [DVL_micro](ERROR): Failed to parse:
:TS0000000,30,0000.0,1489.0,000
2019-09-23T22:51:41.566Z,1569279101.566 [DVL_micro](ERROR): only read 3 of 4 data items
2019-09-23T22:51:41.566Z,1569279101.566 [DVL_micro](ERROR): Failed to parse:
:BI,+00288,+0746,+00000,I
2019-09-23T22:52:54.695Z,1569279174.695 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-09-23T22:52:54.695Z,1569279174.695 [Default:CheckIn:C.Wait] Stopped
2019-09-23T22:52:54.695Z,1569279174.695 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-09-23T22:52:54.695Z,1569279174.695 [Default:CheckIn:D] Running Loop=1
2019-09-23T22:52:55.117Z,1569279175.117 [Default:CheckIn:D] Stopped
2019-09-23T22:52:55.117Z,1569279175.117 [Default:CheckIn:E] Running Loop=1
2019-09-23T22:52:55.542Z,1569279175.542 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 50.118473 min 
2019-09-23T22:52:55.542Z,1569279175.542 [Default:CheckIn:E] Stopped
2019-09-23T22:52:55.542Z,1569279175.542 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-09-23T22:52:55.542Z,1569279175.542 [Default:CheckIn] Stopped
2019-09-23T22:52:55.542Z,1569279175.542 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-09-23T22:52:55.542Z,1569279175.542 [Default:CheckIn](INFO): Running loop #9
2019-09-23T22:52:55.542Z,1569279175.542 [Default:CheckIn] Running Loop=9
2019-09-23T22:52:55.542Z,1569279175.542 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-09-23T22:52:55.543Z,1569279175.543 [Default:CheckIn:Read_GPS] Running Loop=1
2019-09-23T22:52:57.077Z,1569279177.077 [NAL9602](DEBUG): Fix Requested
2019-09-23T22:52:57.482Z,1569279177.482 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,225256.00,A,3648.15752,N,12147.21856,W,0.019,24.82,230919,,,D*4D
2019-09-23T22:52:57.484Z,1569279177.484 [NAL9602](INFO): GPS fix at 20190923T225256: (36.802625, -121.786976)
2019-09-23T22:52:57.531Z,1569279177.531 [Default:CheckIn:Read_GPS] Stopped
2019-09-23T22:52:57.531Z,1569279177.531 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-09-23T22:52:59.510Z,1569279179.510 [NAL9602](ERROR): parseGSV uart error: serial buffer full
2019-09-23T22:53:02.731Z,1569279182.731 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2019-09-23T22:53:02.731Z,1569279182.731 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+22.0,0000.0,1489.WI,+00238,-00016,+00735,+00000,A
2019-09-23T22:53:14.852Z,1569279194.852 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20190923T215902/Courier0028.lzma
2019-09-23T22:53:16.858Z,1569279196.858 [DataOverHttps](INFO): Moved sent file to Logs/20190923T215902/Courier0028.lzma.bak
2019-09-23T22:53:16.859Z,1569279196.859 [DataOverHttps](INFO): SBD MOMSN=11806344
2019-09-23T22:53:26.564Z,1569279206.564 [NAL9602](INFO): SBD MO Status=2, MOMSN=1574, MT Status=2, MTMSN=0
2019-09-23T22:53:26.564Z,1569279206.564 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-09-23T22:53:35.876Z,1569279215.876 [DVL_micro](ERROR): Failed to parse:99.99,+9999.99,+9999.99,+9999.99
2019-09-23T22:53:37.428Z,1569279217.428 [DataOverHttps](INFO): Sending 119 bytes from file Logs/20190923T215902/Express0029.lzma
2019-09-23T22:53:42.447Z,1569279222.447 [DataOverHttps](INFO): Moved sent file to Logs/20190923T215902/Express0029.lzma.bak
2019-09-23T22:53:42.447Z,1569279222.447 [DataOverHttps](IMPORTANT): SBD MOMSN=11806348, MTMSN=20190923T225341
2019-09-23T22:53:43.932Z,1569279223.932 [NAL9602](INFO): SBD MO Status=2, MOMSN=1574, MT Status=2, MTMSN=0
2019-09-23T22:53:43.932Z,1569279223.932 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-09-23T22:53:46.030Z,1569279226.030 [Default:CheckIn:Read_Iridium] Stopped
2019-09-23T22:53:46.030Z,1569279226.030 [Default:CheckIn:C.Wait] Running Loop=1
2019-09-23T22:53:46.031Z,1569279226.031 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-09-23T22:53:53.921Z,1569279233.921 [DataOverHttps](INFO): Received command:Ibit
2019-09-23T22:53:53.946Z,1569279233.946 [CommandLine](IMPORTANT): got command ibit
2019-09-23T22:53:54.082Z,1569279234.082 [IBIT](IMPORTANT): Beginning Initiated BIT
2019-09-23T22:53:54.082Z,1569279234.082 [IBIT](IMPORTANT): Beginning control surface checks.
2019-09-23T22:53:54.085Z,1569279234.085 [CBIT](IMPORTANT): Beginning ground fault scan
2019-09-23T22:54:05.101Z,1569279245.101 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.062307
CHAN A1 (24V): 0.110323
CHAN A2 (12V): 0.027568
CHAN A3 (5V): -0.003558
CHAN B0 (3.3V): -0.002556
CHAN B1 (3.15aV): 0.000246
CHAN B2 (3.15bV): 0.003800
CHAN B3 (GND): -0.014278
OPEN: 0.008948
Full Scale Calc: 4.765 mA, -1.589 mA
2019-09-23T22:54:34.476Z,1569279274.476 [DVL_micro](ERROR): only read 3 of 4 data items
2019-09-23T22:54:34.476Z,1569279274.476 [DVL_micro](ERROR): Failed to parse:
:RD,+9999.99,+9999.99,+9999..99
2019-09-23T22:55:02.357Z,1569279302.357 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+22.1,0000.0,1489.0,000
2019-09-23T22:55:12.486Z,1569279312.486 [DVL_micro](ERROR): Failed to parse:
:SA,+01.62,-04.33,109.6
2019-09-23T22:55:22.624Z,1569279322.624 [IBIT](IMPORTANT): Communications Status:
Fix Status: 1
Iridium Signal Strength: 2
Latitude: 36.802624 Longitude: -121.786980
2019-09-23T22:55:23.004Z,1569279323.004 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 0.000000
Voltage: 0.000000
2019-09-23T22:55:23.004Z,1569279323.004 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah
2019-09-23T22:55:23.004Z,1569279323.004 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V
2019-09-23T22:55:23.418Z,1569279323.418 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2019-09-23T22:55:23.418Z,1569279323.418 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2019-09-23T22:55:23.419Z,1569279323.419 [IBIT](IMPORTANT): Pressure:8.126734 PSI
2019-09-23T22:55:23.419Z,1569279323.419 [IBIT](IMPORTANT): Humidity:7.648639 %
2019-09-23T22:55:23.805Z,1569279323.805 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2019-09-23T22:55:23.805Z,1569279323.805 [IBIT](IMPORTANT): buoyancyNeutral: 172.000000 cc
2019-09-23T22:55:23.806Z,1569279323.806 [IBIT](IMPORTANT): massDefault: 0.500000 cm
2019-09-23T22:55:23.806Z,1569279323.806 [IBIT](IMPORTANT): stopDepth: 215.000000 m
2019-09-23T22:55:23.806Z,1569279323.806 [IBIT](IMPORTANT): abortDepth: 255.000000 m
2019-09-23T22:55:23.806Z,1569279323.806 [IBIT](IMPORTANT): IBIT PASSED
2019-09-23T22:55:25.383Z,1569279325.383 [DVL_micro](ERROR): only read 3 of 4 data items
2019-09-23T22:55:25.383Z,1569279325.383 [DVL_micro](ERROR): Failed to parse:
:RD,+9999.99,+9999.99,+99999.99
2019-09-23T22:55:40.331Z,1569279340.331 [NAL9602](INFO): SBD MO Status=2, MOMSN=1574, MT Status=2, MTMSN=0
2019-09-23T22:55:40.331Z,1569279340.331 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-09-23T22:55:57.706Z,1569279357.706 [NAL9602](INFO): SBD MO Status=0, MOMSN=1574, MT Status=0, MTMSN=0
2019-09-23T22:55:57.706Z,1569279357.706 [NAL9602](INFO): No messages in MT queue
2019-09-23T22:56:28.412Z,1569279388.412 [NAL9602](INFO): Not Powering down - fast GPS
2019-09-23T22:56:34.137Z,1569279394.137 [DVL_micro](ERROR): DVL uart error: serial timeout
2019-09-23T22:56:34.137Z,1569279394.137 [DVL_micro] Communications Fault, FailCount= 1
2019-09-23T22:56:34.137Z,1569279394.137 [DVL_micro](ERROR): Communications Fault
2019-09-23T22:56:34.138Z,1569279394.138 [DVL_micro](ERROR): Failed to parse:
2019-09-23T22:56:34.247Z,1569279394.247 [CBIT](ERROR): Communications Fault in component: DVL_micro
2019-09-23T22:56:34.545Z,1569279394.545 [DVL_micro](INFO): Powering down
2019-09-23T22:56:35.326Z,1569279395.326 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-09-23T22:56:35.326Z,1569279395.326 [DVL_micro] No Fault, FailCount= 1
2019-09-23T22:56:41.340Z,1569279401.340 [DVL_micro](ERROR): Failed to parse:
00000000002.1,0000.0,1489.0,000
2019-09-23T22:57:06.794Z,1569279426.794 [DVL_micro](ERROR): only read 3 of 4 data items
2019-09-23T22:57:06.794Z,1569279426.794 [DVL_micro](ERROR): Failed to parse:
:BI,+00400,-00017,00000,I
2019-09-23T22:58:07.793Z,1569279487.793 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2019-09-23T22:58:07.793Z,1569279487.793 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+22.1,009.0,000
2019-09-23T22:58:15.472Z,1569279495.472 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2019-09-23T22:58:15.472Z,1569279495.472 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000,+22.2,0000.0,1489.0,000
2019-09-23T22:58:40.931Z,1569279520.931 [DVL_micro](ERROR): only read 3 of 4 data items
2019-09-23T22:58:40.931Z,1569279520.931 [DVL_micro](ERROR): Failed to parse:
:BI,+01764,+0074,+00000,I
2019-09-23T22:58:46.626Z,1569279526.626 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-09-23T22:58:46.627Z,1569279526.627 [Default:CheckIn:C.Wait] Stopped
2019-09-23T22:58:46.627Z,1569279526.627 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-09-23T22:58:46.627Z,1569279526.627 [Default:CheckIn:D] Running Loop=1
2019-09-23T22:58:47.018Z,1569279527.018 [Default:CheckIn:D] Stopped
2019-09-23T22:58:47.019Z,1569279527.019 [Default:CheckIn:E] Running Loop=1
2019-09-23T22:58:47.426Z,1569279527.426 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 55.983500 min 
2019-09-23T22:58:47.426Z,1569279527.426 [Default:CheckIn:E] Stopped
2019-09-23T22:58:47.426Z,1569279527.426 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-09-23T22:58:47.426Z,1569279527.426 [Default:CheckIn] Stopped
2019-09-23T22:58:47.426Z,1569279527.426 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-09-23T22:58:47.426Z,1569279527.426 [Default:CheckIn](INFO): Running loop #10
2019-09-23T22:58:47.426Z,1569279527.426 [Default:CheckIn] Running Loop=10
2019-09-23T22:58:47.426Z,1569279527.426 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-09-23T22:58:47.426Z,1569279527.426 [Default:CheckIn:Read_GPS] Running Loop=1
2019-09-23T22:58:49.017Z,1569279529.017 [NAL9602](DEBUG): Fix Requested
2019-09-23T22:58:49.402Z,1569279529.402 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,225848.00,A,3648.16147,N,12147.20507,W,1.302,36.79,230919,,,D*4E
2019-09-23T22:58:49.404Z,1569279529.404 [NAL9602](INFO): GPS fix at 20190923T225848: (36.802691, -121.786751)
2019-09-23T22:58:49.456Z,1569279529.456 [Default:CheckIn:Read_GPS] Stopped
2019-09-23T22:58:49.456Z,1569279529.456 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-09-23T22:58:50.622Z,1569279530.622 [NAL9602](ERROR): parseGSV uart error: serial buffer full
2019-09-23T22:58:59.896Z,1569279539.896 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20190923T215902/Courier0031.lzma
2019-09-23T22:59:01.902Z,1569279541.902 [DataOverHttps](INFO): Moved sent file to Logs/20190923T215902/Courier0031.lzma.bak
2019-09-23T22:59:01.903Z,1569279541.903 [DataOverHttps](INFO): SBD MOMSN=11806387
2019-09-23T22:59:16.477Z,1569279556.477 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2019-09-23T22:59:16.477Z,1569279556.477 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+22.1,0000.0,10
2019-09-23T22:59:17.692Z,1569279557.692 [NAL9602](INFO): SBD MO Status=0, MOMSN=1575, MT Status=0, MTMSN=0
2019-09-23T22:59:17.692Z,1569279557.692 [NAL9602](INFO): No messages in MT queue
2019-09-23T22:59:29.736Z,1569279569.736 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190923T215902/Courier0034.lzma
2019-09-23T22:59:31.742Z,1569279571.742 [DataOverHttps](INFO): Moved sent file to Logs/20190923T215902/Courier0034.lzma.bak
2019-09-23T22:59:31.743Z,1569279571.743 [DataOverHttps](INFO): SBD MOMSN=11806390
2019-09-23T22:59:48.386Z,1569279588.386 [NAL9602](INFO): Not Powering down - fast GPS
2019-09-23T22:59:51.546Z,1569279591.546 [DataOverHttps](INFO): Sending 745 bytes from file Logs/20190923T215902/Express0032.lzma
2019-09-23T22:59:53.550Z,1569279593.550 [DataOverHttps](INFO): Moved sent file to Logs/20190923T215902/Express0032.lzma.bak
2019-09-23T22:59:53.551Z,1569279593.551 [DataOverHttps](INFO): SBD MOMSN=11806392
2019-09-23T23:00:14.768Z,1569279614.768 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20190923T215902/Express0035.lzma
2019-09-23T23:00:16.774Z,1569279616.774 [DataOverHttps](INFO): Moved sent file to Logs/20190923T215902/Express0035.lzma.bak
2019-09-23T23:00:16.775Z,1569279616.775 [DataOverHttps](INFO): SBD MOMSN=11806416
2019-09-23T23:00:17.486Z,1569279617.486 [DVL_micro](ERROR): Failed to parse:
:SA,+01.03,-04.73,276.5
2019-09-23T23:00:20.380Z,1569279620.380 [Default:CheckIn:Read_Iridium] Stopped
2019-09-23T23:00:20.380Z,1569279620.380 [Default:CheckIn:C.Wait] Running Loop=1
2019-09-23T23:00:20.380Z,1569279620.380 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-09-23T23:00:53.051Z,1569279653.051 [DVL_micro](ERROR): Failed to parse:
:.99,+9999.99,+9999.99,+9999.99
2019-09-23T23:01:00.706Z,1569279660.706 [DVL_micro](ERROR): Failed to parse:
:WI,+00061,+00373,+00833,+00000,A
2019-09-23T23:01:23.734Z,1569279683.734 [DVL_micro](ERROR): only read 2 of 4 data items
2019-09-23T23:01:23.734Z,1569279683.734 [DVL_micro](ERROR): Failed to parse:
:RD,+9999.99,+9999.99,,+9999.99
2019-09-23T23:02:37.293Z,1569279757.293 [DVL_micro](ERROR): Failed to parse:
:WI,-00180,+00409,+00783,+00000,A
2019-09-23T23:05:00.859Z,1569279900.859 [DataOverHttps](IMPORTANT): SBD MTMSN=20190923T230459
2019-09-23T23:05:08.469Z,1569279908.469 [DataOverHttps](INFO): Received command:sched asap "load Engineering/portuguese_ledge.xml;set portuguese_ledge.NeedCommsTime 20 minute;set portuguese_ledge.Depth 20 meter;set portuguese_ledge.MaxDepth 30 meter;set portuguese_ledge.MinOffshore 2 kilometer" 38lg6 1 2
2019-09-23T23:05:08.558Z,1569279908.558 [CommandLine](IMPORTANT): got command schedule asap "load Engineering/portuguese_ledge.xml;set portuguese_ledge.NeedCommsTime 20 minute;set portuguese_ledge.Depth 20 meter;set portuguese_ledge.MaxDepth 30 meter;set portuguese_ledge.MinOffshore 2 kilometer" 38lg6 1 2.000000
2019-09-23T23:05:08.558Z,1569279908.558 [CommandLine](IMPORTANT): Scheduling command #1 of 2 with id=38lg6
2019-09-23T23:05:08.559Z,1569279908.559 [CommandLine](IMPORTANT): Scheduled #1 (#1 of 2 with id='38lg6'): "load Engineering/portuguese_ledge.xml;set portuguese_ledge.NeedCommsTime 20 minute;set portuguese_ledge.Depth 20 meter;set portuguese_ledge.MaxDepth 30 meter;set portuguese_ledge.MinOffshore 2 kilometer" ASAP
2019-09-23T23:05:10.474Z,1569279910.474 [DataOverHttps](IMPORTANT): SBD MTMSN=20190923T230508
2019-09-23T23:05:18.205Z,1569279918.205 [DataOverHttps](INFO): Received command:sched asap "set portuguese_ledge.MinAltitude 7 meter;set portuguese_ledge.ContactLabel 4 count;set portuguese_ledge.TrackingUpdatePeriod 45 second;run " 38lg6 2 2
2019-09-23T23:05:18.266Z,1569279918.266 [CommandLine](IMPORTANT): got command schedule asap "set portuguese_ledge.MinAltitude 7 meter;set portuguese_ledge.ContactLabel 4 count;set portuguese_ledge.TrackingUpdatePeriod 45 second;run " 38lg6 2 2.000000
2019-09-23T23:05:18.266Z,1569279918.266 [CommandLine](IMPORTANT): Scheduling command #2 of 2 with id=38lg6
2019-09-23T23:05:18.267Z,1569279918.267 [CommandLine](IMPORTANT): Scheduled #2 (#2 of 2 with id='38lg6'): "set portuguese_ledge.MinAltitude 7 meter;set portuguese_ledge.ContactLabel 4 count;set portuguese_ledge.TrackingUpdatePeriod 45 second;run " ASAP
2019-09-23T23:05:18.368Z,1569279918.368 [CommandLine](IMPORTANT): got command load ./Missions/Engineering/portuguese_ledge.xml
2019-09-23T23:05:18.368Z,1569279918.368 [MissionManager](INFO): Loading Mission: ./Missions/Engineering/portuguese_ledge.xml
2019-09-23T23:05:18.468Z,1569279918.468 [MissionManager](INFO): DefineArg portuguese_ledge.MissionTimeout = 4.000000 h
2019-09-23T23:05:18.472Z,1569279918.472 [MissionManager](INFO): DefineArg portuguese_ledge.NeedCommsTime = 120.000000 min
2019-09-23T23:05:18.475Z,1569279918.475 [MissionManager](INFO): DefineArg portuguese_ledge.AcousticContactTimeout = 15.000000 min
2019-09-23T23:05:18.538Z,1569279918.538 [MissionManager](INFO): DefineArg portuguese_ledge.Depth = 50.000000 m
2019-09-23T23:05:18.565Z,1569279918.565 [MissionManager](INFO): DefineArg portuguese_ledge.Speed = 1.000000 m/s
2019-09-23T23:05:18.568Z,1569279918.568 [MissionManager](INFO): DefineArg portuguese_ledge.MaxDepth = 60.000000 m
2019-09-23T23:05:18.587Z,1569279918.587 [MissionManager](INFO): DefineArg portuguese_ledge.MinOffshore = 4.000000 km
2019-09-23T23:05:18.590Z,1569279918.590 [MissionManager](INFO): DefineArg portuguese_ledge.MinAltitude = 5.000000 m
2019-09-23T23:05:18.612Z,1569279918.612 [MissionManager](INFO): DefineArg portuguese_ledge.MassHold = 1 bool
2019-09-23T23:05:18.615Z,1569279918.615 [MissionManager](INFO): DefineArg portuguese_ledge.BuoyancyHold = 1 bool
2019-09-23T23:05:18.638Z,1569279918.638 [MissionManager](INFO): DefineArg portuguese_ledge.Repeat = 4.000000 count
2019-09-23T23:05:18.641Z,1569279918.641 [MissionManager](INFO): DefineArg portuguese_ledge.Lat1 = 36.695944 arcdeg
2019-09-23T23:05:18.644Z,1569279918.644 [MissionManager](INFO): DefineArg portuguese_ledge.Lon1 = -121.945120 arcdeg
2019-09-23T23:05:18.659Z,1569279918.659 [MissionManager](INFO): DefineArg portuguese_ledge.Lat2 = 36.696536 arcdeg
2019-09-23T23:05:18.663Z,1569279918.663 [MissionManager](INFO): DefineArg portuguese_ledge.Lon2 = -121.937544 arcdeg
2019-09-23T23:05:18.667Z,1569279918.667 [MissionManager](INFO): DefineArg portuguese_ledge.Lat3 = 36.693760 arcdeg
2019-09-23T23:05:18.674Z,1569279918.674 [MissionManager](INFO): DefineArg portuguese_ledge.Lon3 = -121.938647 arcdeg
2019-09-23T23:05:18.682Z,1569279918.682 [MissionManager](INFO): DefineArg portuguese_ledge.Lat4 = 36.698094 arcdeg
2019-09-23T23:05:18.689Z,1569279918.689 [MissionManager](INFO): DefineArg portuguese_ledge.Lon4 = -121.940450 arcdeg
2019-09-23T23:05:18.693Z,1569279918.693 [MissionManager](INFO): DefineArg portuguese_ledge.Lat5 = 36.695944 arcdeg
2019-09-23T23:05:18.700Z,1569279918.700 [MissionManager](INFO): DefineArg portuguese_ledge.Lon5 = -121.945120 arcdeg
2019-09-23T23:05:18.703Z,1569279918.703 [MissionManager](INFO): DefineArg portuguese_ledge.ContactLabel = 0.000000 count
2019-09-23T23:05:18.714Z,1569279918.714 [MissionManager](INFO): DefineArg portuguese_ledge.ContactDepth = nan m
2019-09-23T23:05:18.722Z,1569279918.722 [MissionManager](INFO): DefineArg portuguese_ledge.TrackingUpdatePeriod = 60.000000 s
2019-09-23T23:05:18.729Z,1569279918.729 [MissionManager](INFO): DefineArg portuguese_ledge.NumberOfPings = 1.000000 count
2019-09-23T23:05:18.730Z,1569279918.730 [MissionManager](INFO): Inserting Stack: Missions/Insert/AbortDrift.xml
2019-09-23T23:05:18.790Z,1569279918.790 [MissionManager](INFO): DefineArg portuguese_ledge:AbortDrift.AcousticTimeout = 96.000000 h
2019-09-23T23:05:18.792Z,1569279918.792 [portuguese_ledge:AbortDrift:B.AbortDrift](DEBUG): Construct AbortDrift.
2019-09-23T23:05:18.803Z,1569279918.803 [portuguese_ledge:AbortDrift:C.Execute](DEBUG): Construct Execute.
2019-09-23T23:05:18.806Z,1569279918.806 [MissionManager](INFO): RedefineArg portuguese_ledge:AbortDrift.AcousticTimeout = reader:portuguese_ledge.AcousticContactTimeout
2019-09-23T23:05:19.043Z,1569279919.043 [MissionManager](INFO): Inserting Stack: Missions/Insert/Science.xml
2019-09-23T23:05:19.481Z,1569279919.481 [MissionManager](INFO): DefineArg portuguese_ledge:Science.SampleISUS = 0 bool
2019-09-23T23:05:19.487Z,1569279919.487 [MissionManager](INFO): DefineArg portuguese_ledge:Science.SampleISUSmaxPitch = 60.000000 arcdeg
2019-09-23T23:05:19.491Z,1569279919.491 [MissionManager](INFO): DefineArg portuguese_ledge:Science.SampleISUSminPitch = -60.000000 arcdeg
2019-09-23T23:05:19.495Z,1569279919.495 [MissionManager](INFO): DefineArg portuguese_ledge:Science.PeakDetectChlActive = 0 bool
2019-09-23T23:05:19.500Z,1569279919.500 [MissionManager](INFO): DefineArg portuguese_ledge:Science.TimeWindowPeakReport = nan min
2019-09-23T23:05:19.513Z,1569279919.513 [MissionManager](INFO): DefineArg portuguese_ledge:Science.HighestChlPeakReportActive = 0 bool
2019-09-23T23:05:19.516Z,1569279919.516 [MissionManager](INFO): DefineArg portuguese_ledge:Science.PatchTracking = 0 bool
2019-09-23T23:05:19.523Z,1569279919.523 [MissionManager](INFO): DefineArg portuguese_ledge:Science.FilterWidthHorizontal = 3.000000 count
2019-09-23T23:05:19.528Z,1569279919.528 [MissionManager](INFO): DefineArg portuguese_ledge:Science.NumProfilesSlidingwindow = 100.000000 count
2019-09-23T23:05:19.539Z,1569279919.539 [MissionManager](INFO): DefineArg portuguese_ledge:Science.OffPeakFractionHorizontal = 80.000000 %
2019-09-23T23:05:19.542Z,1569279919.542 [MissionManager](INFO): DefineArg portuguese_ledge:Science.PeakDetectNO3Active = 0 bool
2019-09-23T23:05:19.553Z,1569279919.553 [MissionManager](INFO): DefineArg portuguese_ledge:Science.PeakDetectOilActive = 0 bool
2019-09-23T23:05:19.556Z,1569279919.556 [MissionManager](INFO): DefineArg portuguese_ledge:Science.PeakDetectFDOMActive = 0 bool
2019-09-23T23:05:19.570Z,1569279919.570 [MissionManager](INFO): DefineArg portuguese_ledge:Science.UpwardDerivativeOfTemperatureActive = 0 bool
2019-09-23T23:05:19.574Z,1569279919.574 [MissionManager](INFO): DefineArg portuguese_ledge:Science.EnabledAanderaaO2 = 0.000000 bool
2019-09-23T23:05:19.588Z,1569279919.588 [MissionManager](INFO): DefineArg portuguese_ledge:Science.EnabledNeilBrown = 0.000000 bool
2019-09-23T23:05:19.596Z,1569279919.596 [MissionManager](INFO): DefineArg portuguese_ledge:Science.EnabledSeabird = 1.000000 bool
2019-09-23T23:05:19.600Z,1569279919.600 [MissionManager](INFO): DefineArg portuguese_ledge:Science.EnabledTurbulence_NPS = 0.000000 bool
2019-09-23T23:05:19.611Z,1569279919.611 [MissionManager](INFO): DefineArg portuguese_ledge:Science.EnabledWetLabsBB2FL = 1.000000 bool
2019-09-23T23:05:19.619Z,1569279919.619 [MissionManager](INFO): DefineArg portuguese_ledge:Science.EnabledWetLabsSeaOWL_UV_A = 0.000000 bool
2019-09-23T23:05:19.623Z,1569279919.623 [MissionManager](INFO): DefineArg portuguese_ledge:Science.EnabledWetLabsUBAT = 0.000000 bool
2019-09-23T23:05:19.635Z,1569279919.635 [MissionManager](INFO): DefineArg portuguese_ledge:Science.EnabledISUS = 0.000000 bool
2019-09-23T23:05:19.638Z,1569279919.638 [MissionManager](INFO): DefineArg portuguese_ledge:Science.LowPassWindowLength = 20.000000 count
2019-09-23T23:05:19.649Z,1569279919.649 [MissionManager](INFO): DefineArg portuguese_ledge:Science.MedianFilterLen = 5.000000 count
2019-09-23T23:05:19.652Z,1569279919.652 [MissionManager](INFO): DefineArg portuguese_ledge:Science.PeakChlShallowBound = nan m
2019-09-23T23:05:19.659Z,1569279919.659 [MissionManager](INFO): DefineArg portuguese_ledge:Science.PeakChlDeepBound = nan m
2019-09-23T23:05:19.662Z,1569279919.662 [MissionManager](INFO): DefineArg portuguese_ledge:Science.PeakShallowBound = nan m
2019-09-23T23:05:19.674Z,1569279919.674 [MissionManager](INFO): DefineArg portuguese_ledge:Science.PeakDeepBound = nan m
2019-09-23T23:05:19.685Z,1569279919.685 [MissionManager](INFO): DefineOutput portuguese_ledge:Science.PeakChl = 0.000000 ug/l
2019-09-23T23:05:19.688Z,1569279919.688 [MissionManager](INFO): DefineOutput portuguese_ledge:Science.PeakChlDepth = 0.000000 m
2019-09-23T23:05:19.696Z,1569279919.696 [MissionManager](INFO): DefineOutput portuguese_ledge:Science.PeakChlTemperature = 0.000000 degC
2019-09-23T23:05:19.699Z,1569279919.699 [MissionManager](INFO): DefineOutput portuguese_ledge:Science.PeakChlLatitude = nan arcdeg
2019-09-23T23:05:19.742Z,1569279919.742 [MissionManager](INFO): DefineOutput portuguese_ledge:Science.PeakChlLongitude = nan arcdeg
2019-09-23T23:05:19.746Z,1569279919.746 [MissionManager](INFO): DefineOutput portuguese_ledge:Science.PeakNO3 = 0.000000 umol/l
2019-09-23T23:05:19.757Z,1569279919.757 [MissionManager](INFO): DefineOutput portuguese_ledge:Science.PeakNO3Depth = 0.000000 m
2019-09-23T23:05:19.760Z,1569279919.760 [MissionManager](INFO): DefineOutput portuguese_ledge:Science.PeakNO3Latitude = nan arcdeg
2019-09-23T23:05:19.767Z,1569279919.767 [MissionManager](INFO): DefineOutput portuguese_ledge:Science.PeakNO3Longitude = nan arcdeg
2019-09-23T23:05:19.775Z,1569279919.775 [MissionManager](INFO): DefineOutput portuguese_ledge:Science.PatchChl = 0.000000 m
2019-09-23T23:05:19.794Z,1569279919.794 [MissionManager](INFO): DefineOutput portuguese_ledge:Science.PatchChlDepth = 0.000000 m
2019-09-23T23:05:19.801Z,1569279919.801 [MissionManager](INFO): DefineOutput portuguese_ledge:Science.PatchChlLatitude = nan arcdeg
2019-09-23T23:05:19.804Z,1569279919.804 [MissionManager](INFO): DefineOutput portuguese_ledge:Science.PatchChlLongitude = nan arcdeg
2019-09-23T23:05:19.820Z,1569279919.820 [MissionManager](INFO): DefineOutput portuguese_ledge:Science.PatchChlDistance = nan m
2019-09-23T23:05:19.827Z,1569279919.827 [MissionManager](INFO): DefineOutput portuguese_ledge:Science.PeakOil = 0.000000 kg/m3
2019-09-23T23:05:19.835Z,1569279919.835 [MissionManager](INFO): DefineOutput portuguese_ledge:Science.PeakOilDepth = 0.000000 m
2019-09-23T23:05:19.839Z,1569279919.839 [MissionManager](INFO): DefineOutput portuguese_ledge:Science.PeakOilLatitude = nan arcdeg
2019-09-23T23:05:19.854Z,1569279919.854 [MissionManager](INFO): DefineOutput portuguese_ledge:Science.PeakOilLongitude = nan arcdeg
2019-09-23T23:05:19.860Z,1569279919.860 [MissionManager](INFO): DefineOutput portuguese_ledge:Science.PeakFDOM = 0.000000 ppb
2019-09-23T23:05:19.884Z,1569279919.884 [MissionManager](INFO): DefineOutput portuguese_ledge:Science.PeakFDOMDepth = 0.000000 m
2019-09-23T23:05:19.892Z,1569279919.892 [MissionManager](INFO): DefineOutput portuguese_ledge:Science.PeakFDOMLatitude = nan arcdeg
2019-09-23T23:05:19.914Z,1569279919.914 [MissionManager](INFO): DefineOutput portuguese_ledge:Science.PeakFDOMLongitude = nan arcdeg
2019-09-23T23:05:19.918Z,1569279919.918 [MissionManager](INFO): DefineOutput portuguese_ledge:Science.PatchFDOMDistance = nan m
2019-09-23T23:05:19.998Z,1569279919.998 [portuguese_ledge:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2019-09-23T23:05:20.023Z,1569279920.023 [portuguese_ledge:Science:HighestChlPeakReport:A.PeakDetectHorizontal](DEBUG): Construct PeakDetectHorizontal.
2019-09-23T23:05:20.061Z,1569279920.061 [portuguese_ledge:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2019-09-23T23:05:20.088Z,1569279920.088 [portuguese_ledge:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2019-09-23T23:05:20.157Z,1569279920.157 [portuguese_ledge:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2019-09-23T23:05:20.199Z,1569279920.199 [MissionManager](INFO): RedefineArg portuguese_ledge:Science.SampleISUS = value:1 bool
2019-09-23T23:05:20.217Z,1569279920.217 [MissionManager](INFO): RedefineArg portuguese_ledge:Science.PeakDetectChlActive = value:1 bool
2019-09-23T23:05:20.218Z,1569279920.218 [MissionManager](INFO): Inserting Stack: Missions/Insert/NeedComms.xml
2019-09-23T23:05:20.332Z,1569279920.332 [MissionManager](INFO): DefineArg portuguese_ledge:NeedComms.DiveInterval = 3.000000 h
2019-09-23T23:05:20.340Z,1569279920.340 [MissionManager](INFO): DefineArg portuguese_ledge:NeedComms.WaitForPitchUp = 10.000000 min
2019-09-23T23:05:20.348Z,1569279920.348 [MissionManager](INFO): DefineArg portuguese_ledge:NeedComms.SurfacePitch = 20.000000 arcdeg
2019-09-23T23:05:20.356Z,1569279920.356 [MissionManager](INFO): DefineArg portuguese_ledge:NeedComms.SurfaceDepthRate = nan m/s
2019-09-23T23:05:20.367Z,1569279920.367 [MissionManager](INFO): DefineArg portuguese_ledge:NeedComms.SurfaceSpeed = 1.000000 m/s
2019-09-23T23:05:20.372Z,1569279920.372 [MissionManager](INFO): DefineArg portuguese_ledge:NeedComms.GPSTimeout = 7.000000 min
2019-09-23T23:05:20.384Z,1569279920.384 [MissionManager](INFO): DefineArg portuguese_ledge:NeedComms.CommsTimeout = 30.000000 min
2019-09-23T23:05:20.403Z,1569279920.403 [portuguese_ledge:NeedComms:B.GoToSurface](DEBUG): Construct GoToSurface.
2019-09-23T23:05:20.440Z,1569279920.440 [MissionManager](INFO): Inserting Stack: Missions/Insert/StandardEnvelopes.xml
2019-09-23T23:05:20.486Z,1569279920.486 [MissionManager](INFO): DefineArg portuguese_ledge:StandardEnvelopes.MinAltitude = 5.000000 m
2019-09-23T23:05:20.488Z,1569279920.488 [MissionManager](INFO): DefineArg portuguese_ledge:StandardEnvelopes.MaxDepth = 200.000000 m
2019-09-23T23:05:20.496Z,1569279920.496 [MissionManager](INFO): DefineArg portuguese_ledge:StandardEnvelopes.MinOffshore = 2000.000000 m
2019-09-23T23:05:20.501Z,1569279920.501 [portuguese_ledge:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope.
2019-09-23T23:05:20.555Z,1569279920.555 [portuguese_ledge:StandardEnvelopes:B.DepthEnvelope](DEBUG): Construct DepthEnvelope.
2019-09-23T23:05:20.603Z,1569279920.603 [portuguese_ledge:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Construct OffshoreEnvelope.
2019-09-23T23:05:20.640Z,1569279920.640 [portuguese_ledge:BuoyancyHold.Buoyancy](DEBUG): Construct Buoyancy.
2019-09-23T23:05:20.644Z,1569279920.644 [portuguese_ledge:MassHold.Pitch](DEBUG): Construct.
2019-09-23T23:05:20.663Z,1569279920.663 [portuguese_ledge:Transit:A.Pitch](DEBUG): Construct.
2019-09-23T23:05:20.680Z,1569279920.680 [portuguese_ledge:Transit:B.SetSpeed](DEBUG): Construct.
2019-09-23T23:05:20.694Z,1569279920.694 [portuguese_ledge:Transit:Lap:Wpt1:A.Waypoint](DEBUG): Construct Waypoint.
2019-09-23T23:05:20.726Z,1569279920.726 [portuguese_ledge:Transit:Lap:Wpt2:A.Waypoint](DEBUG): Construct Waypoint.
2019-09-23T23:05:20.743Z,1569279920.743 [portuguese_ledge:Transit:Lap:Wpt3:A.Waypoint](DEBUG): Construct Waypoint.
2019-09-23T23:05:20.759Z,1569279920.759 [portuguese_ledge:Transit:Lap:Wpt4:A.Waypoint](DEBUG): Construct Waypoint.
2019-09-23T23:05:20.779Z,1569279920.779 [portuguese_ledge:Transit:Lap:Wpt5:A.Waypoint](DEBUG): Construct Waypoint.
2019-09-23T23:05:20.857Z,1569279920.857 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="utf-8"?>
<Mission xmlns="Tethys"
        xmlns:Control="Tethys/Control"
        xmlns:Guidance="Tethys/Guidance" 
        xmlns:Units="Tethys/Units"
        xmlns:Universal="Tethys/Universal"
        xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
        xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                            Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
                            Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd                            
                            Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                            Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd" 
        Id="portuguese_ledge">

    <Description>
        O ve좵lo nada uma vez ao redor do percurso e depois vem �uperf좩e.
    </Description>

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

    <DefineArg Name="NeedCommsTime"><Description>
        How often to surface for commumications
    </Description><Units:minute/><Value>120</Value></DefineArg>

    <DefineArg Name="AcousticContactTimeout"><Description>
        If the vehicle does not receive an acoustic signal for more than this
        length of time, it will surface for communications with shore.
    </Description><Units:minute/><Value>15</Value></DefineArg>

    <DefineArg Name="Depth"><Description>
        Depth of flat and level flight during the mission.
    </Description><Units:meter /><Value>50</Value></DefineArg>

    <DefineArg Name="Speed"><Description>
        Speed of vehicle (relative to water) during the mission.
    </Description><Units:meter_per_second/><Value>1</Value></DefineArg>

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

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

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

    <DefineArg Name="MassHold"><Description>
        Set to True in order to hold mass at default position, False to allow
        mass to run on its own.
    </Description><True/></DefineArg>

    <DefineArg Name="BuoyancyHold"><Description>
        Set to True in order to hold buoyancy at neutral position, False to
        allow buoyancy to run on its own.
    </Description><True/></DefineArg>

    <DefineArg Name="Repeat"><Description>
        Number of times the vehicle should try to cycle through waypoints..
    </Description><Units:count/><Value>4</Value></DefineArg>

    <DefineArg Name="Lat1"><Description>
        Latitude of waypoint 1. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>36.695944</Value></DefineArg>

    <DefineArg Name="Lon1"><Description>
        Longitude of waypoint 1. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>-121.945120</Value></DefineArg>

    <DefineArg Name="Lat2"><Description>
        Latitude of waypoint 2. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>36.696536</Value></DefineArg>

    <DefineArg Name="Lon2"><Description>
        Longitude of waypoint 2. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>-121.937544</Value></DefineArg>

    <DefineArg Name="Lat3"><Description>
        Latitude of waypoint 3. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>36.693760</Value></DefineArg>

    <DefineArg Name="Lon3"><Description>
        Longitude of waypoint 3. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>-121.938647</Value></DefineArg>

    <DefineArg Name="Lat4"><Description>
        Latitude of waypoint 4. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>36.698094</Value></DefineArg>

    <DefineArg Name="Lon4"><Description>
        Longitude of waypoint 4. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>-121.940450</Value></DefineArg>

    <DefineArg Name="Lat5"><Description>
        Latitude of waypoint 5. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>36.695944</Value></DefineArg>

    <DefineArg Name="Lon5"><Description>
        Longitude of waypoint 5. If nan, waypoint is skipped.
    </Description><Units:degree/><Value>-121.945120</Value></DefineArg>

    <DefineArg Name="ContactLabel"><Description>
        The acoustic address of the asset to be tracked
    </Description><Units:count/><Value>0</Value></DefineArg>

    <DefineArg Name="ContactDepth"><Description>
        The acoustic address of the asset to be tracked
    </Description><Units:meter/><Value>NaN</Value></DefineArg>

    <DefineArg Name="TrackingUpdatePeriod"><Description>
        How long to wait between acoustic queries
    </Description><Units:second/><Value>60</Value></DefineArg>

    <DefineArg Name="NumberOfPings"><Description>
        Number of return pings to request with each acoustic query (more than 1 will
        activate oneway mode)
    </Description><Units:count/><Value>1</Value></DefineArg>

    <Timeout Duration="MissionTimeout"/>

    <!-- Add tracking directive high in the stack (above NeedComms to enable tracking from surface). -->

    <Insert Filename="Insert/AbortDrift.xml">
        <RedefineArg Name="AcousticTimeout"><Arg Name="AcousticContactTimeout"/></RedefineArg>
    </Insert>

    <Estimation:Tracking>
        <Parallel/>
        <Setting><Estimation:Tracking.contactDepthSetting/><Arg Name="ContactDepth"/></Setting>
        <Setting><Estimation:Tracking.contactLabelSetting/><Arg Name="ContactLabel"/></Setting>
        <Setting><Estimation:Tracking.numberOfSamplesSetting/><Arg Name="NumberOfPings"/></Setting>
        <Setting><Estimation:Tracking.updatePeriodSetting/><Arg Name="TrackingUpdatePeriod"/></Setting>
    </Estimation:Tracking>

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

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

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

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

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

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

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

    <Guidance:Buoyancy Id="BuoyancyHold">
        <While>
            <Arg Name="BuoyancyHold"/>
        </While>
        <Setting><Guidance:Buoyancy.position/><Control:VerticalControl.buoyancyNeutral/></Setting>
    </Guidance:Buoyancy>

    <Guidance:Pitch Id="MassHold">
        <While>
            <Arg Name="MassHold"/>
        </While>
        <Setting><Guidance:Pitch.massPosition/><Control:VerticalControl.massDefault/></Setting>
    </Guidance:Pitch>

    <Aggregate Id="Transit">

        <Sequence/>

        <Guidance:Pitch>
            <Parallel/>
            <Setting><Guidance:Pitch.depth/><Arg Name="Depth"/></Setting>
        </Guidance:Pitch>

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

        <Aggregate Id="Lap">

            <Sequence Repeat="Repeat"/>

            <Aggregate Id="Wpt1">

                <Sequence/>

                <Guidance:Waypoint>
                    <Sequence/>
                    <Setting><Guidance:Waypoint.latitude/><Arg Name="Lat1"/></Setting>
                    <Setting><Guidance:Waypoint.longitude/><Arg Name="Lon1"/></Setting>
                </Guidance:Waypoint>

            </Aggregate>

            <Aggregate Id="Wpt2">

                <Sequence/>

                <Guidance:Waypoint>
                    <Sequence/>
                    <Setting><Guidance:Waypoint.latitude/><Arg Name="Lat2"/></Setting>
                    <Setting><Guidance:Waypoint.longitude/><Arg Name="Lon2"/></Setting>
                </Guidance:Waypoint>

            </Aggregate>

            <Aggregate Id="Wpt3">

                <Sequence/>

                <Guidance:Waypoint>
                    <Sequence/>
                    <Setting><Guidance:Waypoint.latitude/><Arg Name="Lat3"/></Setting>
                    <Setting><Guidance:Waypoint.longitude/><Arg Name="Lon3"/></Setting>
                </Guidance:Waypoint>

            </Aggregate>

            <Aggregate Id="Wpt4">

                <Sequence/>

                <Guidance:Waypoint>
                    <Sequence/>
                    <Setting><Guidance:Waypoint.latitude/><Arg Name="Lat4"/></Setting>
                    <Setting><Guidance:Waypoint.longitude/><Arg Name="Lon4"/></Setting>
                </Guidance:Waypoint>

            </Aggregate>

            <Aggregate Id="Wpt5">

                <Sequence/>

                <Guidance:Waypoint>
                    <Sequence/>
                    <Setting><Guidance:Waypoint.latitude/><Arg Name="Lat5"/></Setting>
                    <Setting><Guidance:Waypoint.longitude/><Arg Name="Lon5"/></Setting>
                </Guidance:Waypoint>

            </Aggregate>

            <Call Id="Ligue para casa" RefId="NeedComms"/>

        </Aggregate>

    </Aggregate>

</Mission>


2019-09-23T23:05:20.858Z,1569279920.858 [CommandLine](IMPORTANT): Loaded ./Missions/Engineering/portuguese_ledge.xml
2019-09-23T23:05:20.998Z,1569279920.998 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-09-23T23:05:20.998Z,1569279920.998 [Default:CheckIn:C.Wait] Stopped
2019-09-23T23:05:20.998Z,1569279920.998 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-09-23T23:05:20.998Z,1569279920.998 [Default:CheckIn:D] Running Loop=1
2019-09-23T23:05:21.406Z,1569279921.406 [Default:CheckIn:D] Stopped
2019-09-23T23:05:21.406Z,1569279921.406 [Default:CheckIn:E] Running Loop=1
2019-09-23T23:05:21.812Z,1569279921.812 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 62.556616 min 
2019-09-23T23:05:21.812Z,1569279921.812 [Default:CheckIn:E] Stopped
2019-09-23T23:05:21.817Z,1569279921.817 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-09-23T23:05:21.817Z,1569279921.817 [Default:CheckIn] Stopped
2019-09-23T23:05:21.817Z,1569279921.817 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-09-23T23:05:21.818Z,1569279921.818 [Default:CheckIn](INFO): Running loop #11
2019-09-23T23:05:21.818Z,1569279921.818 [Default:CheckIn] Running Loop=11
2019-09-23T23:05:21.818Z,1569279921.818 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-09-23T23:05:21.818Z,1569279921.818 [Default:CheckIn:Read_GPS] Running Loop=1
2019-09-23T23:05:23.369Z,1569279923.369 [NAL9602](DEBUG): Fix Requested
2019-09-23T23:05:23.760Z,1569279923.760 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,230523.00,A,3648.43159,N,12147.35093,W,5.521,234.33,230919,,,D*74
2019-09-23T23:05:23.762Z,1569279923.762 [NAL9602](INFO): GPS fix at 20190923T230523: (36.807193, -121.789182)
2019-09-23T23:05:23.800Z,1569279923.800 [Default:CheckIn:Read_GPS] Stopped
2019-09-23T23:05:23.800Z,1569279923.800 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-09-23T23:05:25.495Z,1569279925.495 [NAL9602](ERROR): parseGSV uart error: serial buffer full
2019-09-23T23:05:30.336Z,1569279930.336 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2019-09-23T23:05:30.336Z,1569279930.336 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+22.3,009.0,000
2019-09-23T23:05:34.622Z,1569279934.622 [CommandLine](IMPORTANT): got command set portuguese_ledge.NeedCommsTime 20.000000 minute
2019-09-23T23:05:34.623Z,1569279934.623 [CommandLine](IMPORTANT): got command set portuguese_ledge.Depth 20.000000 meter
2019-09-23T23:05:34.624Z,1569279934.624 [CommandLine](IMPORTANT): got command set portuguese_ledge.MaxDepth 30.000000 meter
2019-09-23T23:05:34.624Z,1569279934.624 [CommandLine](IMPORTANT): got command set portuguese_ledge.MinOffshore 2.000000 kilometer
2019-09-23T23:05:38.015Z,1569279938.015 [DVL_micro](ERROR): Failed to parse:
:WI,+00002,+00068,+00853,+00000,A
2019-09-23T23:05:38.433Z,1569279938.433 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20190923T215902/Courier0037.lzma
2019-09-23T23:05:40.438Z,1569279940.438 [DataOverHttps](INFO): Moved sent file to Logs/20190923T215902/Courier0037.lzma.bak
2019-09-23T23:05:40.439Z,1569279940.439 [DataOverHttps](INFO): SBD MOMSN=11806438
2019-09-23T23:05:41.260Z,1569279941.260 [NAL9602](INFO): SBD MO Status=0, MOMSN=1576, MT Status=0, MTMSN=0
2019-09-23T23:05:41.260Z,1569279941.260 [NAL9602](INFO): No messages in MT queue
2019-09-23T23:05:44.490Z,1569279944.490 [CommandLine](IMPORTANT): got command set portuguese_ledge.MinAltitude 7.000000 meter
2019-09-23T23:05:44.515Z,1569279944.515 [CommandLine](IMPORTANT): got command set portuguese_ledge.ContactLabel 4.000000 count
2019-09-23T23:05:44.515Z,1569279944.515 [CommandLine](IMPORTANT): got command set portuguese_ledge.TrackingUpdatePeriod 45.000000 second
2019-09-23T23:05:44.516Z,1569279944.516 [CommandLine](IMPORTANT): got command run 
2019-09-23T23:05:44.524Z,1569279944.524 [CommandLine](IMPORTANT): Running 
2019-09-23T23:05:44.537Z,1569279944.537 [Default] Stopped
2019-09-23T23:05:44.538Z,1569279944.538 [Default](DEBUG): Aggregate::uninitialize Default
2019-09-23T23:05:44.538Z,1569279944.538 [Default:B.GoToSurface] Stopped
2019-09-23T23:05:44.538Z,1569279944.538 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-09-23T23:05:44.538Z,1569279944.538 [Default:CheckIn] Stopped
2019-09-23T23:05:44.538Z,1569279944.538 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-09-23T23:05:44.538Z,1569279944.538 [Default:CheckIn:Read_Iridium] Stopped
2019-09-23T23:05:44.538Z,1569279944.538 [MissionManager](IMPORTANT): Started mission portuguese_ledge
2019-09-23T23:05:44.538Z,1569279944.538 [portuguese_ledge] Running Loop=1
2019-09-23T23:05:44.539Z,1569279944.539 [portuguese_ledge](DEBUG): Aggregate::initialize portuguese_ledge
2019-09-23T23:05:44.539Z,1569279944.539 [portuguese_ledge:AbortDrift] Running Loop=1
2019-09-23T23:05:44.539Z,1569279944.539 [portuguese_ledge:AbortDrift](DEBUG): Aggregate::initialize portuguese_ledge:AbortDrift
2019-09-23T23:05:44.539Z,1569279944.539 [portuguese_ledge:AbortDrift:A] Running Loop=1
2019-09-23T23:05:44.539Z,1569279944.539 [portuguese_ledge:B.] Running Loop=1
2019-09-23T23:05:44.539Z,1569279944.539 [portuguese_ledge:B.](INFO): Initializing Tracking.
2019-09-23T23:05:44.539Z,1569279944.539 [portuguese_ledge:Science] Running Loop=1
2019-09-23T23:05:44.540Z,1569279944.540 [portuguese_ledge:Science](DEBUG): Aggregate::initialize portuguese_ledge:Science
2019-09-23T23:05:44.540Z,1569279944.540 [portuguese_ledge:Science:A] Running Loop=1
2019-09-23T23:05:44.540Z,1569279944.540 [portuguese_ledge:Science:B] Running Loop=1
2019-09-23T23:05:44.540Z,1569279944.540 [portuguese_ledge:Science:C] Running Loop=1
2019-09-23T23:05:44.540Z,1569279944.540 [portuguese_ledge:Science:D] Running Loop=1
2019-09-23T23:05:44.540Z,1569279944.540 [portuguese_ledge:Science:E] Running Loop=1
2019-09-23T23:05:44.540Z,1569279944.540 [portuguese_ledge:Science:F] Running Loop=1
2019-09-23T23:05:44.540Z,1569279944.540 [portuguese_ledge:Science:G] Running Loop=1
2019-09-23T23:05:44.540Z,1569279944.540 [portuguese_ledge:Science:H] Running Loop=1
2019-09-23T23:05:44.540Z,1569279944.540 [portuguese_ledge:Science:Read_Oil] Running Loop=1
2019-09-23T23:05:44.540Z,1569279944.540 [portuguese_ledge:Science:PeakDetectChl] Running Loop=1
2019-09-23T23:05:44.540Z,1569279944.540 [portuguese_ledge:Science:PeakDetectChl](DEBUG): Aggregate::initialize portuguese_ledge:Science:PeakDetectChl
2019-09-23T23:05:44.541Z,1569279944.541 [portuguese_ledge:Science:PeakDetectChl:A.PeakDetectVsDepth] Running Loop=1
2019-09-23T23:05:44.541Z,1569279944.541 [portuguese_ledge:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Initialize.
2019-09-23T23:05:44.543Z,1569279944.543 [portuguese_ledge:Science:HighestChlPeakReport] Running Loop=1
2019-09-23T23:05:44.543Z,1569279944.543 [portuguese_ledge:Science:HighestChlPeakReport](DEBUG): Aggregate::initialize portuguese_ledge:Science:HighestChlPeakReport
2019-09-23T23:05:44.544Z,1569279944.544 [portuguese_ledge:Science:HighestChlPeakReport:A.PeakDetectHorizontal] Running Loop=1
2019-09-23T23:05:44.544Z,1569279944.544 [portuguese_ledge:Science:HighestChlPeakReport:A.PeakDetectHorizontal](INFO): Initialize.
2019-09-23T23:05:44.544Z,1569279944.544 [portuguese_ledge:Science:PeakDetectNO3] Running Loop=1
2019-09-23T23:05:44.544Z,1569279944.544 [portuguese_ledge:Science:PeakDetectNO3](DEBUG): Aggregate::initialize portuguese_ledge:Science:PeakDetectNO3
2019-09-23T23:05:44.544Z,1569279944.544 [portuguese_ledge:Science:PeakDetectNO3:A.PeakDetectVsDepth] Running Loop=1
2019-09-23T23:05:44.544Z,1569279944.544 [portuguese_ledge:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Initialize.
2019-09-23T23:05:44.571Z,1569279944.571 [portuguese_ledge:Science:PeakDetectOil] Running Loop=1
2019-09-23T23:05:44.571Z,1569279944.571 [portuguese_ledge:Science:PeakDetectOil](DEBUG): Aggregate::initialize portuguese_ledge:Science:PeakDetectOil
2019-09-23T23:05:44.571Z,1569279944.571 [portuguese_ledge:Science:PeakDetectOil:A.PeakDetectVsDepth] Running Loop=1
2019-09-23T23:05:44.571Z,1569279944.571 [portuguese_ledge:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Initialize.
2019-09-23T23:05:44.578Z,1569279944.578 [portuguese_ledge:Science:PeakDetectFDOM] Running Loop=1
2019-09-23T23:05:44.579Z,1569279944.579 [portuguese_ledge:Science:PeakDetectFDOM](DEBUG): Aggregate::initialize portuguese_ledge:Science:PeakDetectFDOM
2019-09-23T23:05:44.579Z,1569279944.579 [portuguese_ledge:Science:PeakDetectFDOM:A.PeakDetectVsDepth] Running Loop=1
2019-09-23T23:05:44.579Z,1569279944.579 [portuguese_ledge:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Initialize.
2019-09-23T23:05:44.586Z,1569279944.586 [portuguese_ledge:StandardEnvelopes] Running Loop=1
2019-09-23T23:05:44.587Z,1569279944.587 [portuguese_ledge:StandardEnvelopes](DEBUG): Aggregate::initialize portuguese_ledge:StandardEnvelopes
2019-09-23T23:05:44.587Z,1569279944.587 [portuguese_ledge:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1
2019-09-23T23:05:44.587Z,1569279944.587 [portuguese_ledge:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent.
2019-09-23T23:05:44.587Z,1569279944.587 [portuguese_ledge:StandardEnvelopes:B.DepthEnvelope] Running Loop=1
2019-09-23T23:05:44.587Z,1569279944.587 [portuguese_ledge:StandardEnvelopes:B.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent.
2019-09-23T23:05:44.587Z,1569279944.587 [portuguese_ledge:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1
2019-09-23T23:05:44.587Z,1569279944.587 [portuguese_ledge:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Initialize OffshoreEnvelopeComponent.
2019-09-23T23:05:44.587Z,1569279944.587 [portuguese_ledge:BuoyancyHold.Buoyancy] Running Loop=1
2019-09-23T23:05:44.587Z,1569279944.587 [portuguese_ledge:BuoyancyHold.Buoyancy](DEBUG): Initialize Buoyancy Component.
2019-09-23T23:05:44.588Z,1569279944.588 [portuguese_ledge:MassHold.Pitch] Running Loop=1
2019-09-23T23:05:44.588Z,1569279944.588 [portuguese_ledge:MassHold.Pitch](DEBUG): Initialize.
2019-09-23T23:05:44.588Z,1569279944.588 [portuguese_ledge:E] Running Loop=1
2019-09-23T23:05:44.593Z,1569279944.593 [portuguese_ledge:MassHold.Pitch] Running Loop=1
2019-09-23T23:05:44.594Z,1569279944.594 [portuguese_ledge:BuoyancyHold.Buoyancy] Running Loop=1
2019-09-23T23:05:44.594Z,1569279944.594 [portuguese_ledge:StandardEnvelopes] Running Loop=1
2019-09-23T23:05:44.594Z,1569279944.594 [portuguese_ledge:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1
2019-09-23T23:05:44.611Z,1569279944.611 [portuguese_ledge:StandardEnvelopes:B.DepthEnvelope] Running Loop=1
2019-09-23T23:05:44.612Z,1569279944.612 [portuguese_ledge:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1
2019-09-23T23:05:44.617Z,1569279944.617 [portuguese_ledge:E] Stopped
2019-09-23T23:05:44.617Z,1569279944.617 [portuguese_ledge:G] Running Loop=1
2019-09-23T23:05:44.617Z,1569279944.617 [portuguese_ledge:Science] Running Loop=1
2019-09-23T23:05:44.618Z,1569279944.618 [portuguese_ledge:Science:PeakDetectFDOM] Stopped
2019-09-23T23:05:44.619Z,1569279944.619 [portuguese_ledge:Science:PeakDetectFDOM](DEBUG): Aggregate::uninitialize portuguese_ledge:Science:PeakDetectFDOM
2019-09-23T23:05:44.619Z,1569279944.619 [portuguese_ledge:Science:PeakDetectFDOM:A.PeakDetectVsDepth] Stopped
2019-09-23T23:05:44.619Z,1569279944.619 [portuguese_ledge:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2019-09-23T23:05:44.619Z,1569279944.619 [portuguese_ledge:Science:PeakDetectOil] Stopped
2019-09-23T23:05:44.619Z,1569279944.619 [portuguese_ledge:Science:PeakDetectOil](DEBUG): Aggregate::uninitialize portuguese_ledge:Science:PeakDetectOil
2019-09-23T23:05:44.619Z,1569279944.619 [portuguese_ledge:Science:PeakDetectOil:A.PeakDetectVsDepth] Stopped
2019-09-23T23:05:44.619Z,1569279944.619 [portuguese_ledge:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2019-09-23T23:05:44.619Z,1569279944.619 [portuguese_ledge:Science:PeakDetectNO3] Stopped
2019-09-23T23:05:44.619Z,1569279944.619 [portuguese_ledge:Science:PeakDetectNO3](DEBUG): Aggregate::uninitialize portuguese_ledge:Science:PeakDetectNO3
2019-09-23T23:05:44.619Z,1569279944.619 [portuguese_ledge:Science:PeakDetectNO3:A.PeakDetectVsDepth] Stopped
2019-09-23T23:05:44.619Z,1569279944.619 [portuguese_ledge:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2019-09-23T23:05:44.619Z,1569279944.619 [portuguese_ledge:Science:HighestChlPeakReport] Stopped
2019-09-23T23:05:44.620Z,1569279944.620 [portuguese_ledge:Science:HighestChlPeakReport](DEBUG): Aggregate::uninitialize portuguese_ledge:Science:HighestChlPeakReport
2019-09-23T23:05:44.620Z,1569279944.620 [portuguese_ledge:Science:HighestChlPeakReport:A.PeakDetectHorizontal] Stopped
2019-09-23T23:05:44.620Z,1569279944.620 [portuguese_ledge:Science:HighestChlPeakReport:A.PeakDetectHorizontal](DEBUG): Uninitialize.
2019-09-23T23:05:44.620Z,1569279944.620 [portuguese_ledge:Science:PeakDetectChl] Running Loop=1
2019-09-23T23:05:44.620Z,1569279944.620 [portuguese_ledge:Science:Read_Oil] Stopped
2019-09-23T23:05:44.620Z,1569279944.620 [portuguese_ledge:Science:H] Stopped
2019-09-23T23:05:44.620Z,1569279944.620 [portuguese_ledge:Science:G] Running Loop=1
2019-09-23T23:05:44.625Z,1569279944.625 [portuguese_ledge:Science:G](DEBUG): Initialize ReadDataComponent to sense mass_concentration_of_chlorophyll_in_sea_water
2019-09-23T23:05:44.625Z,1569279944.625 [portuguese_ledge:Science:F] Stopped
2019-09-23T23:05:44.626Z,1569279944.626 [portuguese_ledge:Science:E] Stopped
2019-09-23T23:05:44.626Z,1569279944.626 [portuguese_ledge:Science:D] Running Loop=1
2019-09-23T23:05:44.626Z,1569279944.626 [portuguese_ledge:Science:D](DEBUG): Initialize ReadDataComponent to sense CTD_Seabird.sea_water_temperature
2019-09-23T23:05:44.627Z,1569279944.627 [portuguese_ledge:Science:D](DEBUG): Initialize ReadDataComponent to sense CTD_Seabird.sea_water_salinity
2019-09-23T23:05:44.627Z,1569279944.627 [portuguese_ledge:Science:C] Running Loop=1
2019-09-23T23:05:44.628Z,1569279944.628 [portuguese_ledge:Science:C](DEBUG): Initialize ReadDataComponent to sense sea_water_temperature
2019-09-23T23:05:44.628Z,1569279944.628 [portuguese_ledge:Science:C](DEBUG): Initialize ReadDataComponent to sense sea_water_salinity
2019-09-23T23:05:44.629Z,1569279944.629 [portuguese_ledge:Science:B] Stopped
2019-09-23T23:05:44.633Z,1569279944.633 [portuguese_ledge:Science:A] Stopped
2019-09-23T23:05:44.633Z,1569279944.633 [portuguese_ledge:B.] Running Loop=1
2019-09-23T23:05:44.633Z,1569279944.633 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:05:44.634Z,1569279944.634 [portuguese_ledge:AbortDrift] Running Loop=1
2019-09-23T23:05:44.634Z,1569279944.634 [portuguese_ledge:AbortDrift:A](INFO): Insert acoustic timeout set to 0.250000 h .
2019-09-23T23:05:44.635Z,1569279944.635 [portuguese_ledge:AbortDrift:A] Stopped
2019-09-23T23:05:44.635Z,1569279944.635 [portuguese_ledge:AbortDrift:B.AbortDrift] Running Loop=1
2019-09-23T23:05:44.635Z,1569279944.635 [portuguese_ledge:AbortDrift:B.AbortDrift](INFO): Initializing AbortDrift.
2019-09-23T23:05:44.636Z,1569279944.636 [portuguese_ledge:AbortDrift:B.AbortDrift](IMPORTANT): Acoustic timeout set to: 0.25 hours.
2019-09-23T23:05:44.818Z,1569279944.818 [WetLabsBB2FL](INFO): Opening uart, block timeout 10ths=2
2019-09-23T23:05:44.818Z,1569279944.818 [WetLabsBB2FL](INFO): Powering up
2019-09-23T23:05:44.930Z,1569279944.930 [portuguese_ledge:G] Stopped
2019-09-23T23:05:44.930Z,1569279944.930 [portuguese_ledge:H] Running Loop=1
2019-09-23T23:05:44.948Z,1569279944.948 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:05:44.953Z,1569279944.953 [portuguese_ledge:AbortDrift:B.AbortDrift](INFO): Received valid gps time fix: 1569279872.00. Resetting abort timer.
2019-09-23T23:05:45.298Z,1569279945.298 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20
2019-09-23T23:05:45.323Z,1569279945.323 [portuguese_ledge:H] Stopped
2019-09-23T23:05:45.323Z,1569279945.323 [portuguese_ledge:I] Running Loop=1
2019-09-23T23:05:45.359Z,1569279945.359 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:05:45.732Z,1569279945.732 [portuguese_ledge:I] Stopped
2019-09-23T23:05:45.732Z,1569279945.732 [portuguese_ledge:Transit] Running Loop=1
2019-09-23T23:05:45.732Z,1569279945.732 [portuguese_ledge:Transit](DEBUG): Aggregate::initialize portuguese_ledge:Transit
2019-09-23T23:05:45.732Z,1569279945.732 [portuguese_ledge:Transit:A.Pitch] Running Loop=1
2019-09-23T23:05:45.732Z,1569279945.732 [portuguese_ledge:Transit:A.Pitch](DEBUG): Initialize.
2019-09-23T23:05:45.733Z,1569279945.733 [portuguese_ledge:Transit:B.SetSpeed] Running Loop=1
2019-09-23T23:05:45.733Z,1569279945.733 [portuguese_ledge:Transit:B.SetSpeed](DEBUG): Initialize.
2019-09-23T23:05:45.733Z,1569279945.733 [portuguese_ledge:Transit:Lap] Running Loop=1
2019-09-23T23:05:45.733Z,1569279945.733 [portuguese_ledge:Transit:Lap](DEBUG): Aggregate::initialize portuguese_ledge:Transit:Lap
2019-09-23T23:05:45.733Z,1569279945.733 [portuguese_ledge:Transit:Lap:Wpt1] Running Loop=1
2019-09-23T23:05:45.734Z,1569279945.734 [portuguese_ledge:Transit:Lap:Wpt1](DEBUG): Aggregate::initialize portuguese_ledge:Transit:Lap:Wpt1
2019-09-23T23:05:45.734Z,1569279945.734 [portuguese_ledge:Transit:Lap:Wpt1:A.Waypoint] Running Loop=1
2019-09-23T23:05:45.734Z,1569279945.734 [portuguese_ledge:Transit:Lap:Wpt1:A.Waypoint](DEBUG): Initialize WaypointComponent.
2019-09-23T23:05:45.764Z,1569279945.764 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:05:46.139Z,1569279946.139 [portuguese_ledge:Transit:B.SetSpeed] Running Loop=1
2019-09-23T23:05:46.139Z,1569279946.139 [portuguese_ledge:Transit:A.Pitch] Running Loop=1
2019-09-23T23:05:46.182Z,1569279946.182 [portuguese_ledge:StandardEnvelopes:A.AltitudeEnvelope](ERROR): Altitude Measurement is not Active.
2019-09-23T23:05:46.183Z,1569279946.183 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:05:46.599Z,1569279946.599 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:05:46.987Z,1569279946.987 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:05:47.427Z,1569279947.427 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:05:47.778Z,1569279947.778 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:05:48.231Z,1569279948.231 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:05:48.306Z,1569279948.306 [CTD_Seabird](ERROR): Failed to parse device response: <!--startlogging-->
2019-09-23T23:05:48.603Z,1569279948.603 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:05:49.030Z,1569279949.030 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:05:49.440Z,1569279949.440 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:05:49.812Z,1569279949.812 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:05:50.221Z,1569279950.221 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:05:50.317Z,1569279950.317 [CTD_Seabird](ERROR): Salinity reading out of range: 0.000000 psu
2019-09-23T23:05:50.685Z,1569279950.685 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:05:51.039Z,1569279951.039 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:05:51.422Z,1569279951.422 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:05:51.789Z,1569279951.789 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:05:52.205Z,1569279952.205 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:05:52.620Z,1569279952.620 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:05:53.052Z,1569279953.052 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:05:53.375Z,1569279953.375 [DVL_micro](ERROR): Failed to parse:
84,+00016,+00819,+00000,I
2019-09-23T23:05:53.451Z,1569279953.451 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:05:53.820Z,1569279953.820 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:05:54.229Z,1569279954.229 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:05:54.645Z,1569279954.645 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:05:55.038Z,1569279955.038 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:05:55.337Z,1569279955.337 [CTD_Seabird](ERROR): Salinity reading out of range: 0.000646 psu
2019-09-23T23:05:55.470Z,1569279955.470 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:05:55.886Z,1569279955.886 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:05:56.246Z,1569279956.246 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:05:56.660Z,1569279956.660 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:05:57.053Z,1569279957.053 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:05:57.503Z,1569279957.503 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:05:57.912Z,1569279957.912 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:05:58.228Z,1569279958.228 [DVL_micro](ERROR): only read 3 of 4 data items
2019-09-23T23:05:58.228Z,1569279958.228 [DVL_micro](ERROR): Failed to parse:
:BI,-00172,-00056,+00892,+000D,+00000000.00,+00000000.00,+00000000.00,9999.99,000.00
2019-09-23T23:05:58.370Z,1569279958.370 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:05:58.733Z,1569279958.733 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:05:59.112Z,1569279959.112 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:05:59.549Z,1569279959.549 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:05:59.920Z,1569279959.920 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:00.335Z,1569279960.335 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:00.746Z,1569279960.746 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:01.040Z,1569279961.040 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2019-09-23T23:06:01.040Z,1569279961.040 [DVL_micro](ERROR): Failed to parse:
:TS0000000,35.0,+22.3,0000.0,1489.0,000
2019-09-23T23:06:01.148Z,1569279961.148 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:01.548Z,1569279961.548 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:01.954Z,1569279961.954 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:02.328Z,1569279962.328 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:02.713Z,1569279962.713 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:03.100Z,1569279963.100 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190923T215902/Courier0040.lzma
2019-09-23T23:06:03.114Z,1569279963.114 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:03.564Z,1569279963.564 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:03.922Z,1569279963.922 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:04.334Z,1569279964.334 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:04.730Z,1569279964.730 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:05.106Z,1569279965.106 [DataOverHttps](INFO): Moved sent file to Logs/20190923T215902/Courier0040.lzma.bak
2019-09-23T23:06:05.107Z,1569279965.107 [DataOverHttps](INFO): SBD MOMSN=11806442
2019-09-23T23:06:05.177Z,1569279965.177 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:05.544Z,1569279965.544 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:05.959Z,1569279965.959 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:06.348Z,1569279966.348 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:06.745Z,1569279966.745 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:07.151Z,1569279967.151 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:07.570Z,1569279967.570 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:07.955Z,1569279967.955 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:08.422Z,1569279968.422 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:08.771Z,1569279968.771 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:09.159Z,1569279969.159 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:09.610Z,1569279969.610 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:10.073Z,1569279970.073 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:10.564Z,1569279970.564 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:10.809Z,1569279970.809 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:11.364Z,1569279971.364 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:11.399Z,1569279971.399 [CTD_Seabird](ERROR): Salinity reading out of range: 10.750091 psu
2019-09-23T23:06:11.631Z,1569279971.631 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:11.944Z,1569279971.944 [NAL9602](INFO): Not Powering down - fast GPS
2019-09-23T23:06:12.018Z,1569279972.018 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:12.391Z,1569279972.391 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:12.403Z,1569279972.403 [CTD_Seabird](ERROR): Salinity reading out of range: 1.005144 psu
2019-09-23T23:06:12.828Z,1569279972.828 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:13.215Z,1569279973.215 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:13.407Z,1569279973.407 [CTD_Seabird](ERROR): Salinity reading out of range: 0.000000 psu
2019-09-23T23:06:13.661Z,1569279973.661 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:14.022Z,1569279974.022 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:14.444Z,1569279974.444 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:14.885Z,1569279974.885 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:15.234Z,1569279975.234 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:15.655Z,1569279975.655 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:16.070Z,1569279976.070 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:16.452Z,1569279976.452 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:16.854Z,1569279976.854 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:17.260Z,1569279977.260 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:17.682Z,1569279977.682 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:18.060Z,1569279978.060 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:18.506Z,1569279978.506 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:18.915Z,1569279978.915 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:19.262Z,1569279979.262 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:19.716Z,1569279979.716 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:20.078Z,1569279980.078 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:20.508Z,1569279980.508 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:20.906Z,1569279980.906 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:21.326Z,1569279981.326 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:21.439Z,1569279981.439 [CTD_Seabird](ERROR): Salinity reading out of range: 4.140278 psu
2019-09-23T23:06:21.708Z,1569279981.708 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:22.108Z,1569279982.108 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:22.443Z,1569279982.443 [CTD_Seabird](ERROR): Salinity reading out of range: 1.629603 psu
2019-09-23T23:06:22.530Z,1569279982.530 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:22.910Z,1569279982.910 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:23.320Z,1569279983.320 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:23.758Z,1569279983.758 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:24.126Z,1569279984.126 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:24.548Z,1569279984.548 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:24.927Z,1569279984.927 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:25.342Z,1569279985.342 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:25.742Z,1569279985.742 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:26.162Z,1569279986.162 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:26.459Z,1569279986.459 [CTD_Seabird](ERROR): Salinity reading out of range: 14.093825 psu
2019-09-23T23:06:26.490Z,1569279986.490 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2019-09-23T23:06:26.490Z,1569279986.490 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+22.3,0000.,000
2019-09-23T23:06:26.617Z,1569279986.617 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:26.957Z,1569279986.957 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:27.416Z,1569279987.416 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:27.463Z,1569279987.463 [CTD_Seabird](ERROR): Salinity reading out of range: 0.073800 psu
2019-09-23T23:06:27.819Z,1569279987.819 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:28.287Z,1569279988.287 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:28.671Z,1569279988.671 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:29.058Z,1569279989.058 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:29.394Z,1569279989.394 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:29.891Z,1569279989.891 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:29.891Z,1569279989.891 [portuguese_ledge:B.](INFO): update period (45.000000 s) has elapsed, querying...
2019-09-23T23:06:29.892Z,1569279989.892 [portuguese_ledge:B.](INFO): *** querying DAT ***
2019-09-23T23:06:30.220Z,1569279990.220 [DAT](INFO): ****** ping requested ******
2019-09-23T23:06:30.424Z,1569279990.424 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:30.503Z,1569279990.503 [CTD_Seabird](ERROR): Salinity reading out of range: 6.430649 psu
2019-09-23T23:06:30.824Z,1569279990.824 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:31.251Z,1569279991.251 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:31.507Z,1569279991.507 [CTD_Seabird](ERROR): Salinity reading out of range: 0.032843 psu
2019-09-23T23:06:31.718Z,1569279991.718 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:32.114Z,1569279992.114 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:32.545Z,1569279992.545 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:32.929Z,1569279992.929 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:33.315Z,1569279993.315 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:33.753Z,1569279993.753 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:34.123Z,1569279994.123 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:34.514Z,1569279994.514 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:34.535Z,1569279994.535 [CTD_Seabird](ERROR): Salinity reading out of range: 4.665336 psu
2019-09-23T23:06:34.936Z,1569279994.936 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:35.361Z,1569279995.361 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:35.523Z,1569279995.523 [CTD_Seabird](ERROR): Salinity reading out of range: 2.663950 psu
2019-09-23T23:06:35.808Z,1569279995.808 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:36.115Z,1569279996.115 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:36.404Z,1569279996.404 [DVL_micro](ERROR): only read 3 of 4 data items
2019-09-23T23:06:36.404Z,1569279996.404 [DVL_micro](ERROR): Failed to parse:
:RD,+9999.99,+9999.99,+99999.99
2019-09-23T23:06:36.527Z,1569279996.527 [CTD_Seabird](ERROR): Salinity reading out of range: 0.019135 psu
2019-09-23T23:06:36.612Z,1569279996.612 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:36.963Z,1569279996.963 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:37.395Z,1569279997.395 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:37.531Z,1569279997.531 [CTD_Seabird](ERROR): Salinity reading out of range: 3.949707 psu
2019-09-23T23:06:37.857Z,1569279997.857 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:38.165Z,1569279998.165 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:38.535Z,1569279998.535 [CTD_Seabird](ERROR): Salinity reading out of range: 0.205706 psu
2019-09-23T23:06:38.576Z,1569279998.576 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:38.972Z,1569279998.972 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:39.371Z,1569279999.371 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:39.780Z,1569279999.780 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:40.178Z,1569280000.178 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:40.543Z,1569280000.543 [CTD_Seabird](ERROR): Salinity reading out of range: 0.001112 psu
2019-09-23T23:06:40.600Z,1569280000.600 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:40.988Z,1569280000.988 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:41.424Z,1569280001.424 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:41.547Z,1569280001.547 [CTD_Seabird](ERROR): Salinity reading out of range: 0.001373 psu
2019-09-23T23:06:41.910Z,1569280001.910 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:42.223Z,1569280002.223 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:42.553Z,1569280002.553 [CTD_Seabird](ERROR): Salinity reading out of range: 5.700290 psu
2019-09-23T23:06:42.671Z,1569280002.671 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:43.032Z,1569280003.032 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:43.464Z,1569280003.464 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:43.558Z,1569280003.558 [CTD_Seabird](ERROR): Salinity reading out of range: 1.507401 psu
2019-09-23T23:06:43.863Z,1569280003.863 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:44.107Z,1569280004.107 [DVL_micro](ERROR): only read 3 of 4 data items
2019-09-23T23:06:44.107Z,1569280004.107 [DVL_micro](ERROR): Failed to parse:
:BI,-00308,+00341,+0000,I
2019-09-23T23:06:44.294Z,1569280004.294 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:44.559Z,1569280004.559 [CTD_Seabird](ERROR): Salinity reading out of range: 1.221535 psu
2019-09-23T23:06:44.682Z,1569280004.682 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:45.129Z,1569280005.129 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:45.504Z,1569280005.504 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:45.563Z,1569280005.563 [CTD_Seabird](ERROR): Salinity reading out of range: 6.400817 psu
2019-09-23T23:06:45.883Z,1569280005.883 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:46.283Z,1569280006.283 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:46.606Z,1569280006.606 [CTD_Seabird](ERROR): Salinity reading out of range: 3.138707 psu
2019-09-23T23:06:46.760Z,1569280006.760 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:47.085Z,1569280007.085 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:47.547Z,1569280007.547 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:47.610Z,1569280007.610 [CTD_Seabird](ERROR): Salinity reading out of range: 2.785308 psu
2019-09-23T23:06:47.934Z,1569280007.934 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:48.306Z,1569280008.306 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:48.610Z,1569280008.610 [CTD_Seabird](ERROR): Salinity reading out of range: 0.766443 psu
2019-09-23T23:06:48.742Z,1569280008.742 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:49.092Z,1569280009.092 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:49.413Z,1569280009.413 [DVL_micro](ERROR): DVL BIT error. See manual. Result code: 98
2019-09-23T23:06:49.416Z,1569280009.416 [DVL_micro](ERROR): Failed to parse:
:BD,+00000000.00,+00000000.00,+00000000.00,9999.99,000.00
2019-09-23T23:06:49.594Z,1569280009.594 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:49.602Z,1569280009.602 [CTD_Seabird](ERROR): Salinity reading out of range: 7.825998 psu
2019-09-23T23:06:49.893Z,1569280009.893 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:50.291Z,1569280010.291 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:50.606Z,1569280010.606 [CTD_Seabird](ERROR): Salinity reading out of range: 0.054685 psu
2019-09-23T23:06:50.698Z,1569280010.698 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:51.092Z,1569280011.092 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:51.406Z,1569280011.406 [DataOverHttps](IMPORTANT): SBD MTMSN=20190923T230649
2019-09-23T23:06:51.508Z,1569280011.508 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:51.920Z,1569280011.920 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:52.332Z,1569280012.332 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:52.606Z,1569280012.606 [CTD_Seabird](ERROR): Salinity reading out of range: 3.908360 psu
2019-09-23T23:06:52.718Z,1569280012.718 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:53.072Z,1569280013.072 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:53.485Z,1569280013.485 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:53.606Z,1569280013.606 [CTD_Seabird](ERROR): Salinity reading out of range: 8.087155 psu
2019-09-23T23:06:53.871Z,1569280013.871 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:54.310Z,1569280014.310 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:54.614Z,1569280014.614 [CTD_Seabird](ERROR): Salinity reading out of range: 11.873857 psu
2019-09-23T23:06:54.748Z,1569280014.748 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:55.122Z,1569280015.122 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:55.537Z,1569280015.537 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:55.603Z,1569280015.603 [CTD_Seabird](ERROR): Salinity reading out of range: 12.271427 psu
2019-09-23T23:06:55.926Z,1569280015.926 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:56.342Z,1569280016.342 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:56.608Z,1569280016.608 [CTD_Seabird](ERROR): Salinity reading out of range: 12.021478 psu
2019-09-23T23:06:56.694Z,1569280016.694 [DVL_micro](ERROR): Failed to parse:
:B,-00185,+00858,+00000,I
2019-09-23T23:06:56.803Z,1569280016.803 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:57.146Z,1569280017.146 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:57.543Z,1569280017.543 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:57.611Z,1569280017.611 [CTD_Seabird](ERROR): Salinity reading out of range: 12.270594 psu
2019-09-23T23:06:57.949Z,1569280017.949 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:58.354Z,1569280018.354 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:58.615Z,1569280018.615 [CTD_Seabird](ERROR): Salinity reading out of range: 11.742775 psu
2019-09-23T23:06:58.777Z,1569280018.777 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:59.151Z,1569280019.151 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:59.558Z,1569280019.558 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:06:59.620Z,1569280019.620 [CTD_Seabird](ERROR): Salinity reading out of range: 12.333623 psu
2019-09-23T23:06:59.938Z,1569280019.938 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:07:00.338Z,1569280020.338 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:07:00.623Z,1569280020.623 [CTD_Seabird](ERROR): Salinity reading out of range: 12.110411 psu
2019-09-23T23:07:00.760Z,1569280020.760 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:07:01.170Z,1569280021.170 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:07:01.570Z,1569280021.570 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:07:01.628Z,1569280021.628 [CTD_Seabird](ERROR): Salinity reading out of range: 2.796485 psu
2019-09-23T23:07:01.990Z,1569280021.990 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:07:02.168Z,1569280022.168 [DataOverHttps](INFO): Received command:Stop
2019-09-23T23:07:02.186Z,1569280022.186 [CommandLine](IMPORTANT): got command stop
2019-09-23T23:07:02.186Z,1569280022.186 [CommandLine](IMPORTANT): Scheduling is paused
2019-09-23T23:07:02.186Z,1569280022.186 [Supervisor](INFO): Stop Mission called by CommandLine::commandStop
2019-09-23T23:07:02.367Z,1569280022.367 [portuguese_ledge:B.](DEBUG): Tracking...
2019-09-23T23:07:02.368Z,1569280022.368 [MissionManager](INFO): MissionManager is completed.
2019-09-23T23:07:02.368Z,1569280022.368 [MissionManager](INFO): Uninitializing Mission portuguese_ledge
2019-09-23T23:07:02.368Z,1569280022.368 [portuguese_ledge] Stopped
2019-09-23T23:07:02.368Z,1569280022.368 [portuguese_ledge](DEBUG): Aggregate::uninitialize portuguese_ledge
2019-09-23T23:07:02.368Z,1569280022.368 [portuguese_ledge:AbortDrift] Stopped
2019-09-23T23:07:02.368Z,1569280022.368 [portuguese_ledge:AbortDrift](DEBUG): Aggregate::uninitialize portuguese_ledge:AbortDrift
2019-09-23T23:07:02.368Z,1569280022.368 [portuguese_ledge:AbortDrift:B.AbortDrift] Stopped
2019-09-23T23:07:02.369Z,1569280022.369 [portuguese_ledge:AbortDrift:B.AbortDrift](INFO): Uninitializing AbortDrift.
2019-09-23T23:07:02.369Z,1569280022.369 [portuguese_ledge:B.] Stopped
2019-09-23T23:07:02.369Z,1569280022.369 [portuguese_ledge:B.](DEBUG): Uninitializing Tracking.
2019-09-23T23:07:02.369Z,1569280022.369 [portuguese_ledge:Science] Stopped
2019-09-23T23:07:02.369Z,1569280022.369 [portuguese_ledge:Science](DEBUG): Aggregate::uninitialize portuguese_ledge:Science
2019-09-23T23:07:02.369Z,1569280022.369 [portuguese_ledge:Science:C] Stopped
2019-09-23T23:07:02.369Z,1569280022.369 [portuguese_ledge:Science:D] Stopped
2019-09-23T23:07:02.369Z,1569280022.369 [portuguese_ledge:Science:G] Stopped
2019-09-23T23:07:02.369Z,1569280022.369 [portuguese_ledge:Science:PeakDetectChl] Stopped
2019-09-23T23:07:02.370Z,1569280022.370 [portuguese_ledge:Science:PeakDetectChl](DEBUG): Aggregate::uninitialize portuguese_ledge:Science:PeakDetectChl
2019-09-23T23:07:02.370Z,1569280022.370 [portuguese_ledge:Science:PeakDetectChl:A.PeakDetectVsDepth] Stopped
2019-09-23T23:07:02.370Z,1569280022.370 [portuguese_ledge:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2019-09-23T23:07:02.370Z,1569280022.370 [portuguese_ledge:StandardEnvelopes] Stopped
2019-09-23T23:07:02.370Z,1569280022.370 [portuguese_ledge:StandardEnvelopes](DEBUG): Aggregate::uninitialize portuguese_ledge:StandardEnvelopes
2019-09-23T23:07:02.370Z,1569280022.370 [portuguese_ledge:StandardEnvelopes:A.AltitudeEnvelope] Stopped
2019-09-23T23:07:02.370Z,1569280022.370 [portuguese_ledge:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent.
2019-09-23T23:07:02.370Z,1569280022.370 [portuguese_ledge:StandardEnvelopes:B.DepthEnvelope] Stopped
2019-09-23T23:07:02.370Z,1569280022.370 [portuguese_ledge:StandardEnvelopes:B.DepthEnvelope](DEBUG): Uninitialize.
2019-09-23T23:07:02.370Z,1569280022.370 [portuguese_ledge:StandardEnvelopes:C.OffshoreEnvelope] Stopped
2019-09-23T23:07:02.370Z,1569280022.370 [portuguese_ledge:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Uninitialize OffshoreEnvelopeComponent.
2019-09-23T23:07:02.370Z,1569280022.370 [portuguese_ledge:BuoyancyHold.Buoyancy] Stopped
2019-09-23T23:07:02.370Z,1569280022.370 [portuguese_ledge:BuoyancyHold.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2019-09-23T23:07:02.371Z,1569280022.371 [portuguese_ledge:MassHold.Pitch] Stopped
2019-09-23T23:07:02.371Z,1569280022.371 [portuguese_ledge:Transit] Stopped
2019-09-23T23:07:02.371Z,1569280022.371 [portuguese_ledge:Transit](DEBUG): Aggregate::uninitialize portuguese_ledge:Transit
2019-09-23T23:07:02.371Z,1569280022.371 [portuguese_ledge:Transit:A.Pitch] Stopped
2019-09-23T23:07:02.371Z,1569280022.371 [portuguese_ledge:Transit:B.SetSpeed] Stopped
2019-09-23T23:07:02.371Z,1569280022.371 [portuguese_ledge:Transit:B.SetSpeed](DEBUG): Uninitialize.
2019-09-23T23:07:02.371Z,1569280022.371 [portuguese_ledge:Transit:Lap] Stopped
2019-09-23T23:07:02.371Z,1569280022.371 [portuguese_ledge:Transit:Lap](DEBUG): Aggregate::uninitialize portuguese_ledge:Transit:Lap
2019-09-23T23:07:02.371Z,1569280022.371 [portuguese_ledge:Transit:Lap:Wpt1] Stopped
2019-09-23T23:07:02.371Z,1569280022.371 [portuguese_ledge:Transit:Lap:Wpt1](DEBUG): Aggregate::uninitialize portuguese_ledge:Transit:Lap:Wpt1
2019-09-23T23:07:02.371Z,1569280022.371 [portuguese_ledge:Transit:Lap:Wpt1:A.Waypoint] Stopped
2019-09-23T23:07:02.371Z,1569280022.371 [portuguese_ledge:Transit:Lap:Wpt1:A.Waypoint](DEBUG): Uninitialize WaypointComponent.
2019-09-23T23:07:02.585Z,1569280022.585 [WetLabsBB2FL](INFO): Powering down
2019-09-23T23:07:02.743Z,1569280022.743 [MissionManager](IMPORTANT): Started mission Default
2019-09-23T23:07:02.744Z,1569280022.744 [Default] Running Loop=1
2019-09-23T23:07:02.744Z,1569280022.744 [Default](DEBUG): Aggregate::initialize Default
2019-09-23T23:07:02.744Z,1569280022.744 [Default:B.GoToSurface] Running Loop=1
2019-09-23T23:07:02.744Z,1569280022.744 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-09-23T23:07:02.744Z,1569280022.744 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-09-23T23:07:02.744Z,1569280022.744 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-09-23T23:07:02.745Z,1569280022.745 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-09-23T23:07:02.745Z,1569280022.745 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-09-23T23:07:02.746Z,1569280022.746 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-09-23T23:07:02.746Z,1569280022.746 [Default:A.Wait] Running Loop=1
2019-09-23T23:07:02.746Z,1569280022.746 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-09-23T23:07:03.186Z,1569280023.186 [BuoyancyServo](FAULT): Reading outside of valid range:0.000000

2019-09-23T23:07:03.186Z,1569280023.186 [BuoyancyServo](FAULT): Buoyancy engine reporting null position
2019-09-23T23:07:03.186Z,1569280023.186 [BuoyancyServo] Hardware Fault, FailCount= 1
2019-09-23T23:07:03.186Z,1569280023.186 [BuoyancyServo](ERROR): Hardware Fault
2019-09-23T23:07:03.316Z,1569280023.316 [CBIT](ERROR): Hardware Fault in component: BuoyancyServo
2019-09-23T23:07:05.181Z,1569280025.181 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2019-09-23T23:07:05.182Z,1569280025.182 [BuoyancyServo](INFO): Powering down
2019-09-23T23:07:06.128Z,1569280026.128 [CBIT](INFO): Clearing failed state for component BuoyancyServo
2019-09-23T23:07:06.128Z,1569280026.128 [BuoyancyServo] No Fault, FailCount= 1
2019-09-23T23:07:06.381Z,1569280026.381 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2019-09-23T23:07:06.382Z,1569280026.382 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2019-09-23T23:07:16.069Z,1569280036.069 [Default:A.Wait](INFO): Done Waiting.
2019-09-23T23:07:16.069Z,1569280036.069 [Default:A.Wait] Stopped
2019-09-23T23:07:16.069Z,1569280036.069 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-09-23T23:07:16.482Z,1569280036.482 [Default:CheckIn] Running Loop=1
2019-09-23T23:07:16.482Z,1569280036.482 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-09-23T23:07:16.482Z,1569280036.482 [Default:CheckIn:Read_GPS] Running Loop=1
2019-09-23T23:07:18.061Z,1569280038.061 [NAL9602](DEBUG): Fix Requested
2019-09-23T23:07:18.460Z,1569280038.460 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,230717.00,A,3648.32959,N,12147.53258,W,6.706,245.65,230919,,,D*7B
2019-09-23T23:07:18.462Z,1569280038.462 [NAL9602](INFO): GPS fix at 20190923T230717: (36.805493, -121.792210)
2019-09-23T23:07:18.524Z,1569280038.524 [Default:CheckIn:Read_GPS] Stopped
2019-09-23T23:07:18.524Z,1569280038.524 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-09-23T23:07:20.887Z,1569280040.887 [NAL9602](ERROR): parseGSV uart error: serial buffer full
2019-09-23T23:07:28.665Z,1569280048.665 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20190923T215902/Courier0043.lzma
2019-09-23T23:07:30.670Z,1569280050.670 [DataOverHttps](INFO): Moved sent file to Logs/20190923T215902/Courier0043.lzma.bak
2019-09-23T23:07:30.671Z,1569280050.671 [DataOverHttps](INFO): SBD MOMSN=11806460
2019-09-23T23:07:33.004Z,1569280053.004 [NAL9602](INFO): SBD MO Status=0, MOMSN=1577, MT Status=0, MTMSN=0
2019-09-23T23:07:33.004Z,1569280053.004 [NAL9602](INFO): No messages in MT queue
2019-09-23T23:07:49.628Z,1569280069.628 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190923T215902/Courier0046.lzma
2019-09-23T23:07:51.635Z,1569280071.635 [DataOverHttps](INFO): Moved sent file to Logs/20190923T215902/Courier0046.lzma.bak
2019-09-23T23:07:51.635Z,1569280071.635 [DataOverHttps](INFO): SBD MOMSN=11806475
2019-09-23T23:08:03.705Z,1569280083.705 [NAL9602](INFO): Not Powering down - fast GPS
2019-09-23T23:08:21.421Z,1569280101.421 [DataOverHttps](INFO): Sending 472 bytes from file Logs/20190923T215902/Express0038.lzma
2019-09-23T23:08:23.426Z,1569280103.426 [DataOverHttps](INFO): Moved sent file to Logs/20190923T215902/Express0038.lzma.bak
2019-09-23T23:08:23.427Z,1569280103.427 [DataOverHttps](INFO): SBD MOMSN=11806499
2019-09-23T23:08:48.520Z,1569280128.520 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20190923T215902/Express0041.lzma
2019-09-23T23:08:50.526Z,1569280130.526 [DataOverHttps](INFO): Moved sent file to Logs/20190923T215902/Express0041.lzma.bak
2019-09-23T23:08:50.527Z,1569280130.527 [DataOverHttps](INFO): SBD MOMSN=11806513
2019-09-23T23:09:10.867Z,1569280150.867 [DataOverHttps](INFO): Sending 775 bytes from file Logs/20190923T215902/Express0044.lzma
2019-09-23T23:09:12.871Z,1569280152.871 [DataOverHttps](INFO): Moved sent file to Logs/20190923T215902/Express0044.lzma.bak
2019-09-23T23:09:12.871Z,1569280152.871 [DataOverHttps](INFO): SBD MOMSN=11806515
2019-09-23T23:09:33.124Z,1569280173.124 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190923T215902/Express0047.lzma
2019-09-23T23:09:35.130Z,1569280175.130 [DataOverHttps](INFO): Moved sent file to Logs/20190923T215902/Express0047.lzma.bak
2019-09-23T23:09:35.131Z,1569280175.131 [DataOverHttps](INFO): SBD MOMSN=11806534
2019-09-23T23:09:38.730Z,1569280178.730 [Default:CheckIn:Read_Iridium] Stopped
2019-09-23T23:09:38.730Z,1569280178.730 [Default:CheckIn:C.Wait] Running Loop=1
2019-09-23T23:09:38.730Z,1569280178.730 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-09-23T23:10:38.235Z,1569280238.235 [DVL_micro](ERROR): only read 3 of 4 data items
2019-09-23T23:10:38.235Z,1569280238.235 [DVL_micro](ERROR): Failed to parse:
:BI,+0289,+00511,+00000,I
2019-09-23T23:11:08.692Z,1569280268.692 [CommandLine](IMPORTANT): got command get platform_orientation degree
2019-09-23T23:11:08.692Z,1569280268.692 [CommandLine](IMPORTANT): platform_orientation 174.872240 arcdeg
2019-09-23T23:11:18.627Z,1569280278.627 [CommandLine](IMPORTANT): got command get platform_orientation degree
2019-09-23T23:11:18.628Z,1569280278.628 [CommandLine](IMPORTANT): platform_orientation 159.143763 arcdeg
2019-09-23T23:11:19.031Z,1569280279.031 [DVL_micro](ERROR): only read 3 of 4 data items
2019-09-23T23:11:19.031Z,1569280279.031 [DVL_micro](ERROR): Failed to parse:
:BI,+00387,+0021,+00000,I
2019-09-23T23:11:23.310Z,1569280283.310 [CommandLine](IMPORTANT): got command get platform_orientation degree
2019-09-23T23:11:23.311Z,1569280283.311 [CommandLine](IMPORTANT): platform_orientation 118.848351 arcdeg
2019-09-23T23:11:26.535Z,1569280286.535 [CommandLine](IMPORTANT): got command get platform_orientation degree
2019-09-23T23:11:26.536Z,1569280286.536 [CommandLine](IMPORTANT): platform_orientation 91.482263 arcdeg
2019-09-23T23:11:28.664Z,1569280288.664 [CommandLine](IMPORTANT): got command get platform_orientation degree
2019-09-23T23:11:28.664Z,1569280288.664 [CommandLine](IMPORTANT): platform_orientation 83.909714 arcdeg
2019-09-23T23:11:30.617Z,1569280290.617 [CommandLine](IMPORTANT): got command get platform_orientation degree
2019-09-23T23:11:30.618Z,1569280290.618 [CommandLine](IMPORTANT): platform_orientation 59.331552 arcdeg
2019-09-23T23:11:33.312Z,1569280293.312 [CommandLine](IMPORTANT): got command get platform_orientation degree
2019-09-23T23:11:33.313Z,1569280293.313 [CommandLine](IMPORTANT): platform_orientation 34.146803 arcdeg
2019-09-23T23:11:35.224Z,1569280295.224 [CommandLine](IMPORTANT): got command get platform_orientation degree
2019-09-23T23:11:35.224Z,1569280295.224 [CommandLine](IMPORTANT): platform_orientation 12.902063 arcdeg
2019-09-23T23:11:37.516Z,1569280297.516 [CommandLine](IMPORTANT): got command get platform_orientation degree
2019-09-23T23:11:37.517Z,1569280297.517 [CommandLine](IMPORTANT): platform_orientation 351.142211 arcdeg
2019-09-23T23:11:40.251Z,1569280300.251 [CommandLine](IMPORTANT): got command get platform_orientation degree
2019-09-23T23:11:40.252Z,1569280300.252 [CommandLine](IMPORTANT): platform_orientation 327.192836 arcdeg
2019-09-23T23:11:42.548Z,1569280302.548 [CommandLine](IMPORTANT): got command get platform_orientation degree
2019-09-23T23:11:42.549Z,1569280302.549 [CommandLine](IMPORTANT): platform_orientation 303.422985 arcdeg
2019-09-23T23:11:44.476Z,1569280304.476 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2019-09-23T23:11:44.484Z,1569280304.484 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+22.31489.0,000
2019-09-23T23:11:44.696Z,1569280304.696 [CommandLine](IMPORTANT): got command get platform_orientation degree
2019-09-23T23:11:44.706Z,1569280304.706 [CommandLine](IMPORTANT): platform_orientation 289.178243 arcdeg
2019-09-23T23:11:47.629Z,1569280307.629 [CommandLine](IMPORTANT): got command get platform_orientation degree
2019-09-23T23:11:47.629Z,1569280307.629 [CommandLine](IMPORTANT): platform_orientation 264.537816 arcdeg
2019-09-23T23:11:49.698Z,1569280309.698 [CommandLine](IMPORTANT): got command get platform_orientation degree
2019-09-23T23:11:49.699Z,1569280309.699 [CommandLine](IMPORTANT): platform_orientation 248.643529 arcdeg
2019-09-23T23:11:51.234Z,1569280311.234 [CommandLine](IMPORTANT): got command get platform_orientation degree
2019-09-23T23:11:51.234Z,1569280311.234 [CommandLine](IMPORTANT): platform_orientation 236.022214 arcdeg
2019-09-23T23:11:53.006Z,1569280313.006 [CommandLine](IMPORTANT): got command get platform_orientation degree
2019-09-23T23:11:53.006Z,1569280313.006 [CommandLine](IMPORTANT): platform_orientation 224.732567 arcdeg
2019-09-23T23:11:54.853Z,1569280314.853 [CommandLine](IMPORTANT): got command get platform_orientation degree
2019-09-23T23:11:54.853Z,1569280314.853 [CommandLine](IMPORTANT): platform_orientation 217.972155 arcdeg
2019-09-23T23:11:56.616Z,1569280316.616 [CommandLine](IMPORTANT): got command get platform_orientation degree
2019-09-23T23:11:56.617Z,1569280316.617 [CommandLine](IMPORTANT): platform_orientation 211.515823 arcdeg
2019-09-23T23:11:58.301Z,1569280318.301 [CommandLine](IMPORTANT): got command get platform_orientation degree
2019-09-23T23:11:58.301Z,1569280318.301 [CommandLine](IMPORTANT): platform_orientation 205.376330 arcdeg
2019-09-23T23:12:09.929Z,1569280329.929 [DVL_micro](ERROR): Failed to parse:
44,+003,I0000000.00,+00000000.00,+00000000.00,9999.99,000.00
2019-09-23T23:12:30.243Z,1569280350.243 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-09-23T23:12:35.384Z,1569280355.384 [DVL_micro](ERROR): only read 1 of 4 data items
2019-09-23T23:12:35.385Z,1569280355.385 [DVL_micro](ERROR): Failed to parse:
:RD,+9999.99,++9999.99,+9999.99
2019-09-23T23:13:26.714Z,1569280406.714 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-09-23T23:13:41.654Z,1569280421.654 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-09-23T23:13:44.059Z,1569280424.059 [DVL_micro](ERROR): Failed to parse:
:WI,+00176,-00076,+00912,+00000,A
2019-09-23T23:13:57.006Z,1569280437.006 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-09-23T23:14:11.945Z,1569280451.945 [DVL_micro](ERROR): Failed to parse:
:R99,+9999.99,+9999.99,+9999.99
2019-09-23T23:14:11.976Z,1569280451.976 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-09-23T23:14:19.667Z,1569280459.667 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2019-09-23T23:14:19.674Z,1569280459.674 [BPC1](INFO): Received data from all battery sticks.
2019-09-23T23:14:39.482Z,1569280479.482 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-09-23T23:14:39.482Z,1569280479.482 [Default:CheckIn:C.Wait] Stopped
2019-09-23T23:14:39.482Z,1569280479.482 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-09-23T23:14:39.482Z,1569280479.482 [Default:CheckIn:D] Running Loop=1
2019-09-23T23:14:39.901Z,1569280479.901 [Default:CheckIn:D] Stopped
2019-09-23T23:14:39.902Z,1569280479.902 [Default:CheckIn:E] Running Loop=1
2019-09-23T23:14:40.284Z,1569280480.284 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 7.619296 min 
2019-09-23T23:14:40.284Z,1569280480.284 [Default:CheckIn:E] Stopped
2019-09-23T23:14:40.284Z,1569280480.284 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-09-23T23:14:40.284Z,1569280480.284 [Default:CheckIn] Stopped
2019-09-23T23:14:40.284Z,1569280480.284 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-09-23T23:14:40.337Z,1569280480.337 [Default:CheckIn](INFO): Running loop #2
2019-09-23T23:14:40.337Z,1569280480.337 [Default:CheckIn] Running Loop=2
2019-09-23T23:14:40.337Z,1569280480.337 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-09-23T23:14:40.337Z,1569280480.337 [Default:CheckIn:Read_GPS] Running Loop=1
2019-09-23T23:14:41.865Z,1569280481.865 [NAL9602](DEBUG): Fix Requested
2019-09-23T23:14:42.263Z,1569280482.263 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,231441.00,A,3648.22600,N,12148.53220,W,9.991,274.80,230919,,,A*7B
2019-09-23T23:14:42.266Z,1569280482.266 [NAL9602](INFO): GPS fix at 20190923T231441: (36.803767, -121.808870)
2019-09-23T23:14:42.330Z,1569280482.330 [Default:CheckIn:Read_GPS] Stopped
2019-09-23T23:14:42.330Z,1569280482.330 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-09-23T23:14:43.600Z,1569280483.600 [NAL9602](ERROR): parseGSV uart error: serial buffer full
2019-09-23T23:14:44.520Z,1569280484.520 [DataOverHttps](INFO): Sending 81 bytes from file Logs/20190923T215902/Courier0049.lzma
2019-09-23T23:14:46.530Z,1569280486.530 [DataOverHttps](INFO): Moved sent file to Logs/20190923T215902/Courier0049.lzma.bak
2019-09-23T23:14:46.531Z,1569280486.531 [DataOverHttps](INFO): SBD MOMSN=11806547
2019-09-23T23:14:54.941Z,1569280494.941 [NAL9602](INFO): SBD MO Status=0, MOMSN=1578, MT Status=0, MTMSN=0
2019-09-23T23:14:54.942Z,1569280494.942 [NAL9602](INFO): No messages in MT queue
2019-09-23T23:15:06.310Z,1569280506.310 [DataOverHttps](INFO): Sending 453 bytes from file Logs/20190923T215902/Express0050.lzma
2019-09-23T23:15:08.315Z,1569280508.315 [DataOverHttps](INFO): Moved sent file to Logs/20190923T215902/Express0050.lzma.bak
2019-09-23T23:15:08.315Z,1569280508.315 [DataOverHttps](INFO): SBD MOMSN=11806550
2019-09-23T23:15:11.927Z,1569280511.927 [Default:CheckIn:Read_Iridium] Stopped
2019-09-23T23:15:11.927Z,1569280511.927 [Default:CheckIn:C.Wait] Running Loop=1
2019-09-23T23:15:11.927Z,1569280511.927 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-09-23T23:15:25.620Z,1569280525.620 [NAL9602](INFO): Not Powering down - fast GPS
2019-09-23T23:15:38.540Z,1569280538.540 [DVL_micro](ERROR): Failed to parse:
:T00000000,35.0,+22.3,0000.0,1489.0,000
2019-09-23T23:15:56.324Z,1569280556.324 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2019-09-23T23:15:56.325Z,1569280556.325 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+22.,1489.0,000
2019-09-23T23:16:39.583Z,1569280599.583 [DVL_micro](ERROR): only read 3 of 4 data items
2019-09-23T23:16:39.583Z,1569280599.583 [DVL_micro](ERROR): Failed to parse:
:BI,+01516,+00367,+0000,I
2019-09-23T23:17:05.037Z,1569280625.037 [DVL_micro](ERROR): Failed to parse:00000000,+22.3,0000.0,1489.0,000
2019-09-23T23:17:32.918Z,1569280652.918 [DVL_micro](ERROR): only read 3 of 4 data items
2019-09-23T23:17:32.919Z,1569280652.919 [DVL_micro](ERROR): Failed to parse:
:BI,-00365,-00081,+0092,I
2019-09-23T23:19:14.749Z,1569280754.749 [DVL_micro](ERROR): only read 3 of 4 data items
2019-09-23T23:19:14.749Z,1569280754.749 [DVL_micro](ERROR): Failed to parse:
:RD,+9999.99,+9999.999,+9999.99
2019-09-23T23:19:28.406Z,1569280768.406 [CommandLine](IMPORTANT): got command show variable ping
2019-09-23T23:19:28.455Z,1569280768.455 [CommandLine](IMPORTANT): DUSBL_Hydroid.numberOfPingsRequested (count)
2019-09-23T23:19:28.456Z,1569280768.456 [CommandLine](IMPORTANT): Micromodem.dusblPingCode (none)
2019-09-23T23:19:28.522Z,1569280768.522 [CommandLine](IMPORTANT): Rowe_600.writeGoodBeamPingsProfile (bool)
2019-09-23T23:19:28.523Z,1569280768.523 [CommandLine](IMPORTANT): Rowe_600.writeGoodEarthPingsProfile (bool)
2019-09-23T23:19:28.524Z,1569280768.524 [CommandLine](IMPORTANT): BR_Ping1D.loadAtStartup (bool)
2019-09-23T23:19:28.524Z,1569280768.524 [CommandLine](IMPORTANT): BR_Ping1D.interval (millisecond)
2019-09-23T23:19:28.524Z,1569280768.524 [CommandLine](IMPORTANT): BR_Ping1D.simulateHardware (bool)
2019-09-23T23:19:28.533Z,1569280768.533 [CommandLine](IMPORTANT): BR_Ping1D.verbosity (count)
2019-09-23T23:19:28.541Z,1569280768.541 [CommandLine](IMPORTANT): BR_Ping1D.minRange (meter)
2019-09-23T23:19:28.542Z,1569280768.542 [CommandLine](IMPORTANT): BR_Ping1D.maxRange (meter)
2019-09-23T23:19:28.542Z,1569280768.542 [CommandLine](IMPORTANT): BR_Ping1D.soundSpeed (meter_per_second)
2019-09-23T23:19:28.542Z,1569280768.542 [CommandLine](IMPORTANT): BR_Ping1D.autoMode (bool)
2019-09-23T23:19:28.543Z,1569280768.543 [CommandLine](IMPORTANT): BR_Ping1D.gainIndex (count)
2019-09-23T23:19:28.543Z,1569280768.543 [CommandLine](IMPORTANT): BR_Ping1D.minConfidence (percent)
2019-09-23T23:19:28.543Z,1569280768.543 [CommandLine](IMPORTANT): BR_Ping1D.pingEnable (bool)
2019-09-23T23:19:28.557Z,1569280768.557 [CommandLine](IMPORTANT): BR_Ping1D.loadControl (none)
2019-09-23T23:19:28.557Z,1569280768.557 [CommandLine](IMPORTANT): BR_Ping1D.uart (none)
2019-09-23T23:19:28.558Z,1569280768.558 [CommandLine](IMPORTANT): BR_Ping1D.baud (bit_per_second)
2019-09-23T23:19:28.652Z,1569280768.652 [CommandLine](IMPORTANT): BR_Ping1D.height_above_sea_floor (meter)
2019-09-23T23:19:28.652Z,1569280768.652 [CommandLine](IMPORTANT): BR_Ping1D.distance (millimeter)
2019-09-23T23:19:28.661Z,1569280768.661 [CommandLine](IMPORTANT): BR_Ping1D.confidence (percent)
2019-09-23T23:19:28.669Z,1569280768.669 [CommandLine](IMPORTANT): BR_Ping1D.component_voltage (volt)
2019-09-23T23:19:28.669Z,1569280768.669 [CommandLine](IMPORTANT): BR_Ping1D.component_avgVoltage (volt)
2019-09-23T23:19:28.670Z,1569280768.670 [CommandLine](IMPORTANT): BR_Ping1D.component_current (milliampere)
2019-09-23T23:19:28.670Z,1569280768.670 [CommandLine](IMPORTANT): BR_Ping1D.component_avgCurrent (milliampere)
2019-09-23T23:19:40.196Z,1569280780.196 [DVL_micro](ERROR): Failed to parse:
:T00000000,35.0,+22.3,0000.0,1489.0,000
2019-09-23T23:20:12.561Z,1569280812.561 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-09-23T23:20:12.561Z,1569280812.561 [Default:CheckIn:C.Wait] Stopped
2019-09-23T23:20:12.561Z,1569280812.561 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-09-23T23:20:12.562Z,1569280812.562 [Default:CheckIn:D] Running Loop=1
2019-09-23T23:20:12.995Z,1569280812.995 [Default:CheckIn:D] Stopped
2019-09-23T23:20:12.995Z,1569280812.995 [Default:CheckIn:E] Running Loop=1
2019-09-23T23:20:13.366Z,1569280813.366 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 13.170849 min 
2019-09-23T23:20:13.366Z,1569280813.366 [Default:CheckIn:E] Stopped
2019-09-23T23:20:13.366Z,1569280813.366 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-09-23T23:20:13.366Z,1569280813.366 [Default:CheckIn] Stopped
2019-09-23T23:20:13.366Z,1569280813.366 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-09-23T23:20:13.366Z,1569280813.366 [Default:CheckIn](INFO): Running loop #3
2019-09-23T23:20:13.366Z,1569280813.366 [Default:CheckIn] Running Loop=3
2019-09-23T23:20:13.366Z,1569280813.366 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-09-23T23:20:13.367Z,1569280813.367 [Default:CheckIn:Read_GPS] Running Loop=1
2019-09-23T23:20:14.956Z,1569280814.956 [NAL9602](DEBUG): Fix Requested
2019-09-23T23:20:15.348Z,1569280815.348 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,232014.00,A,3648.38159,N,12149.08109,W,0.622,108.86,230919,,,A*7B
2019-09-23T23:20:15.350Z,1569280815.350 [NAL9602](INFO): GPS fix at 20190923T232014: (36.806360, -121.818018)
2019-09-23T23:20:15.401Z,1569280815.401 [Default:CheckIn:Read_GPS] Stopped
2019-09-23T23:20:15.401Z,1569280815.401 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-09-23T23:20:16.558Z,1569280816.558 [NAL9602](ERROR): parseGSV uart error: serial buffer full
2019-09-23T23:20:34.504Z,1569280834.504 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20190923T215902/Courier0052.lzma
2019-09-23T23:20:36.510Z,1569280836.510 [DataOverHttps](INFO): Moved sent file to Logs/20190923T215902/Courier0052.lzma.bak
2019-09-23T23:20:36.511Z,1569280836.511 [DataOverHttps](INFO): SBD MOMSN=11806611
2019-09-23T23:20:39.580Z,1569280839.580 [NAL9602](INFO): SBD MO Status=0, MOMSN=1579, MT Status=0, MTMSN=0
2019-09-23T23:20:39.580Z,1569280839.580 [NAL9602](INFO): No messages in MT queue
2019-09-23T23:21:00.765Z,1569280860.765 [DataOverHttps](INFO): Sending 584 bytes from file Logs/20190923T215902/Express0053.lzma
2019-09-23T23:21:02.771Z,1569280862.771 [DataOverHttps](INFO): Moved sent file to Logs/20190923T215902/Express0053.lzma.bak
2019-09-23T23:21:02.771Z,1569280862.771 [DataOverHttps](INFO): SBD MOMSN=11806614
2019-09-23T23:21:06.758Z,1569280866.758 [Default:CheckIn:Read_Iridium] Stopped
2019-09-23T23:21:06.758Z,1569280866.758 [Default:CheckIn:C.Wait] Running Loop=1
2019-09-23T23:21:06.758Z,1569280866.758 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-09-23T23:21:10.306Z,1569280870.306 [NAL9602](INFO): Not Powering down - fast GPS
2019-09-23T23:21:17.318Z,1569280877.318 [DataOverHttps](IMPORTANT): SBD MTMSN=20190923T232115
2019-09-23T23:21:25.176Z,1569280885.176 [DataOverHttps](INFO): Received command:configSet Express linearApproximation BR_Ping1D.height_above_sea_floor 5 meter persist
2019-09-23T23:21:27.442Z,1569280887.442 [CommandLine](IMPORTANT): got command configSet Express linearApproximation BR_Ping1D.height_above_sea_floor 5.000000 meter persist
2019-09-23T23:22:08.318Z,1569280928.318 [DataOverHttps](IMPORTANT): SBD MTMSN=20190923T232206
2019-09-23T23:22:16.120Z,1569280936.120 [DataOverHttps](INFO): Received command:restart logs