2020-01-30T18:45:51.953Z,1580409951.953 [Supervisor](DEBUG): Initializing supervisor.
2020-01-30T18:45:51.956Z,1580409951.956 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2020-01-30T18:45:51.956Z,1580409951.956 [SyncHandler](INFO): Protected caller Thread ID is 969
2020-01-30T18:45:51.957Z,1580409951.957 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2020-01-30T18:45:51.958Z,1580409951.958 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2020-01-30T18:45:51.958Z,1580409951.958 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 970
2020-01-30T18:45:51.961Z,1580409951.961 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2020-01-30T18:45:51.971Z,1580409951.971 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2020-01-30T18:45:51.972Z,1580409951.972 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2020-01-30T18:45:51.973Z,1580409951.973 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 971
2020-01-30T18:45:51.974Z,1580409951.974 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2020-01-30T18:45:51.975Z,1580409951.975 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2020-01-30T18:45:51.975Z,1580409951.975 [logger ThreadHandler](INFO): Protected caller Thread ID is 972
2020-01-30T18:45:51.977Z,1580409951.977 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2020-01-30T18:45:51.977Z,1580409951.977 [Supervisor](INFO): Looking for Config files in directory: Config/
2020-01-30T18:45:51.979Z,1580409951.979 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2020-01-30T18:45:52.173Z,1580409952.173 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2020-01-30T18:45:52.174Z,1580409952.174 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2020-01-30T18:45:52.252Z,1580409952.252 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2020-01-30T18:45:52.679Z,1580409952.679 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2020-01-30T18:45:52.680Z,1580409952.680 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2020-01-30T18:45:53.083Z,1580409953.083 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2020-01-30T18:45:53.084Z,1580409953.084 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2020-01-30T18:45:53.178Z,1580409953.178 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2020-01-30T18:45:53.178Z,1580409953.178 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2020-01-30T18:45:53.467Z,1580409953.467 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2020-01-30T18:45:53.467Z,1580409953.467 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2020-01-30T18:45:53.657Z,1580409953.657 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2020-01-30T18:45:53.657Z,1580409953.657 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2020-01-30T18:45:54.115Z,1580409954.115 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2020-01-30T18:45:54.115Z,1580409954.115 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2020-01-30T18:45:54.216Z,1580409954.216 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2020-01-30T18:45:54.217Z,1580409954.217 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2020-01-30T18:45:54.315Z,1580409954.315 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2020-01-30T18:45:54.315Z,1580409954.315 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2020-01-30T18:45:54.943Z,1580409954.943 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2020-01-30T18:45:54.944Z,1580409954.944 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2020-01-30T18:45:55.348Z,1580409955.348 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2020-01-30T18:45:55.349Z,1580409955.349 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2020-01-30T18:45:55.537Z,1580409955.537 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2020-01-30T18:45:55.537Z,1580409955.537 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2020-01-30T18:45:55.679Z,1580409955.679 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2020-01-30T18:45:55.680Z,1580409955.680 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2020-01-30T18:45:55.825Z,1580409955.825 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2020-01-30T18:45:55.827Z,1580409955.827 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2020-01-30T18:45:55.828Z,1580409955.828 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2020-01-30T18:45:55.917Z,1580409955.917 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2020-01-30T18:45:55.000Z,1580409956.000 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2020-01-30T18:45:56.098Z,1580409956.098 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2020-01-30T18:45:56.179Z,1580409956.179 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2020-01-30T18:45:56.272Z,1580409956.272 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2020-01-30T18:45:56.370Z,1580409956.370 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2020-01-30T18:45:56.570Z,1580409956.570 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2020-01-30T18:45:56.645Z,1580409956.645 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2020-01-30T18:45:56.805Z,1580409956.805 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2020-01-30T18:45:56.947Z,1580409956.947 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2020-01-30T18:45:57.060Z,1580409957.060 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg
2020-01-30T18:45:57.284Z,1580409957.284 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2020-01-30T18:45:57.284Z,1580409957.284 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2020-01-30T18:45:57.290Z,1580409957.290 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2020-01-30T18:45:57.337Z,1580409957.337 [VerticalControl](DEBUG): Construct VerticalControl.
2020-01-30T18:45:57.447Z,1580409957.447 [VerticalControl] Loaded
2020-01-30T18:45:57.447Z,1580409957.447 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2020-01-30T18:45:57.448Z,1580409957.448 [HorizontalControl](DEBUG): Construct HorizontalControl.
2020-01-30T18:45:57.515Z,1580409957.515 [HorizontalControl] Loaded
2020-01-30T18:45:57.516Z,1580409957.516 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2020-01-30T18:45:57.516Z,1580409957.516 [SpeedControl](DEBUG): Construct SpeedControl.
2020-01-30T18:45:57.522Z,1580409957.522 [SpeedControl] Loaded
2020-01-30T18:45:57.522Z,1580409957.522 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2020-01-30T18:45:57.523Z,1580409957.523 [LoopControl](DEBUG): Construct LoopControl.
2020-01-30T18:45:57.523Z,1580409957.523 [LoopControl] Loaded
2020-01-30T18:45:57.523Z,1580409957.523 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2020-01-30T18:45:57.524Z,1580409957.524 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2020-01-30T18:45:57.524Z,1580409957.524 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2020-01-30T18:45:57.537Z,1580409957.537 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2020-01-30T18:45:57.538Z,1580409957.538 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2020-01-30T18:45:57.634Z,1580409957.634 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2020-01-30T18:45:57.634Z,1580409957.634 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2020-01-30T18:45:57.759Z,1580409957.759 [BuoyancyServo] Loaded
2020-01-30T18:45:57.759Z,1580409957.759 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2020-01-30T18:45:57.770Z,1580409957.770 [ElevatorServo] Loaded
2020-01-30T18:45:57.770Z,1580409957.770 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2020-01-30T18:45:57.781Z,1580409957.781 [MassServo] Loaded
2020-01-30T18:45:57.781Z,1580409957.781 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2020-01-30T18:45:57.792Z,1580409957.792 [RudderServo] Loaded
2020-01-30T18:45:57.792Z,1580409957.792 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2020-01-30T18:45:57.803Z,1580409957.803 [ThrusterServo] Loaded
2020-01-30T18:45:57.803Z,1580409957.803 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2020-01-30T18:45:57.804Z,1580409957.804 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2020-01-30T18:45:57.804Z,1580409957.804 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2020-01-30T18:45:58.302Z,1580409958.302 [DeadReckonUsingMultipleVelocitySources] Loaded
2020-01-30T18:45:58.302Z,1580409958.302 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2020-01-30T18:45:58.354Z,1580409958.354 [NavChart] Loaded
2020-01-30T18:45:58.354Z,1580409958.354 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2020-01-30T18:45:58.370Z,1580409958.370 [UniversalFixResidualReporter] Loaded
2020-01-30T18:45:58.371Z,1580409958.371 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2020-01-30T18:45:58.371Z,1580409958.371 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2020-01-30T18:45:58.371Z,1580409958.372 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2020-01-30T18:45:58.443Z,1580409958.443 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2020-01-30T18:45:58.444Z,1580409958.444 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2020-01-30T18:45:58.824Z,1580409958.824 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_orientation
2020-01-30T18:45:58.829Z,1580409958.829 [AHRS_M2](INFO): created writer for : platform_orientation
2020-01-30T18:45:58.830Z,1580409958.830 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_magnetic_orientation
2020-01-30T18:45:58.835Z,1580409958.835 [AHRS_M2](INFO): created writer for : platform_magnetic_orientation
2020-01-30T18:45:58.836Z,1580409958.836 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_pitch_angle
2020-01-30T18:45:58.841Z,1580409958.841 [AHRS_M2](INFO): created writer for : platform_pitch_angle
2020-01-30T18:45:58.841Z,1580409958.841 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_roll_angle
2020-01-30T18:45:58.846Z,1580409958.846 [AHRS_M2](INFO): created writer for : platform_roll_angle
2020-01-30T18:45:58.916Z,1580409958.916 [AHRS_M2] Loaded
2020-01-30T18:45:58.916Z,1580409958.916 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2020-01-30T18:45:58.995Z,1580409958.995 [DataOverHttps] Loaded
2020-01-30T18:45:58.995Z,1580409958.995 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2020-01-30T18:45:58.996Z,1580409958.996 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 408644E0
2020-01-30T18:45:58.996Z,1580409958.996 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 1054
2020-01-30T18:45:59.010Z,1580409959.010 [Depth_Keller] Loaded
2020-01-30T18:45:59.010Z,1580409959.010 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2020-01-30T18:45:59.014Z,1580409959.014 [DropWeight] Loaded
2020-01-30T18:45:59.015Z,1580409959.015 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2020-01-30T18:45:59.108Z,1580409959.108 [NAL9602] Loaded
2020-01-30T18:45:59.108Z,1580409959.108 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2020-01-30T18:45:59.124Z,1580409959.124 [Onboard] Loaded
2020-01-30T18:45:59.124Z,1580409959.124 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2020-01-30T18:45:59.127Z,1580409959.127 [Radio_Surface] Loaded
2020-01-30T18:45:59.128Z,1580409959.128 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2020-01-30T18:45:59.129Z,1580409959.129 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408944E0
2020-01-30T18:45:59.129Z,1580409959.129 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 1055
2020-01-30T18:46:00.590Z,1580409960.590 [BPC1] Loaded
2020-01-30T18:46:00.590Z,1580409960.590 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2020-01-30T18:46:00.590Z,1580409960.590 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2020-01-30T18:46:00.591Z,1580409960.591 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2020-01-30T18:46:00.630Z,1580409960.630 [DepthRateCalculator] Loaded
2020-01-30T18:46:00.631Z,1580409960.631 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2020-01-30T18:46:00.636Z,1580409960.636 [PitchRateCalculator] Loaded
2020-01-30T18:46:00.636Z,1580409960.636 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2020-01-30T18:46:00.648Z,1580409960.648 [SpeedCalculator] Loaded
2020-01-30T18:46:00.648Z,1580409960.648 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2020-01-30T18:46:00.669Z,1580409960.669 [TempGradientCalculator] Loaded
2020-01-30T18:46:00.669Z,1580409960.669 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2020-01-30T18:46:00.674Z,1580409960.674 [YawRateCalculator] Loaded
2020-01-30T18:46:00.674Z,1580409960.674 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2020-01-30T18:46:00.703Z,1580409960.703 [ElevatorOffsetCalculator] Loaded
2020-01-30T18:46:00.704Z,1580409960.704 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2020-01-30T18:46:00.704Z,1580409960.704 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2020-01-30T18:46:00.705Z,1580409960.705 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2020-01-30T18:46:00.887Z,1580409960.887 [CANONSampler] Loaded
2020-01-30T18:46:00.887Z,1580409960.887 [ComponentRegistry](DEBUG): SyncComponent "CANONSampler" handled in the control thread.
2020-01-30T18:46:00.896Z,1580409960.896 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density
2020-01-30T18:46:00.901Z,1580409960.901 [CTD_Seabird](INFO): created writer for : sea_water_density
2020-01-30T18:46:00.902Z,1580409960.902 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth
2020-01-30T18:46:00.906Z,1580409960.906 [CTD_Seabird](INFO): created writer for : depth
2020-01-30T18:46:00.907Z,1580409960.907 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure
2020-01-30T18:46:00.912Z,1580409960.912 [CTD_Seabird](INFO): created writer for : sea_water_pressure
2020-01-30T18:46:00.912Z,1580409960.912 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity
2020-01-30T18:46:00.918Z,1580409960.918 [CTD_Seabird](INFO): created writer for : sea_water_salinity
2020-01-30T18:46:00.918Z,1580409960.918 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature
2020-01-30T18:46:00.923Z,1580409960.923 [CTD_Seabird](INFO): created writer for : sea_water_temperature
2020-01-30T18:46:00.924Z,1580409960.924 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity
2020-01-30T18:46:00.929Z,1580409960.929 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity
2020-01-30T18:46:00.929Z,1580409960.929 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water
2020-01-30T18:46:00.934Z,1580409960.934 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water
2020-01-30T18:46:00.935Z,1580409960.935 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): mass_concentration_of_oxygen_in_sea_water
2020-01-30T18:46:00.940Z,1580409960.940 [CTD_Seabird](INFO): created writer for : mass_concentration_of_oxygen_in_sea_water
2020-01-30T18:46:00.941Z,1580409960.941 [CTD_Seabird](DEBUG): LcmSlateWriter::add(DAtaURI): CTD_Seabird.sea_water_dissolved_oxygen_freq
2020-01-30T18:46:00.941Z,1580409960.941 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): dataName: sea_water_dissolved_oxygen_freq
2020-01-30T18:46:00.972Z,1580409960.972 [CTD_Seabird] Loaded
2020-01-30T18:46:00.973Z,1580409960.973 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2020-01-30T18:46:00.974Z,1580409960.974 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 409964E0
2020-01-30T18:46:00.974Z,1580409960.974 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 1056
2020-01-30T18:46:00.988Z,1580409960.988 [PAR_Licor] Loaded
2020-01-30T18:46:00.989Z,1580409960.989 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2020-01-30T18:46:00.995Z,1580409960.995 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output470
2020-01-30T18:46:00.995Z,1580409960.995 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output470
2020-01-30T18:46:00.999Z,1580409960.999 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output650
2020-01-30T18:46:00.999Z,1580409960.999 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output650
2020-01-30T18:46:01.003Z,1580409961.003 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.OutputChl
2020-01-30T18:46:01.004Z,1580409961.004 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: OutputChl
2020-01-30T18:46:01.008Z,1580409961.008 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg470nm
2020-01-30T18:46:01.008Z,1580409961.008 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg470nm
2020-01-30T18:46:01.012Z,1580409961.012 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg650nm
2020-01-30T18:46:01.012Z,1580409961.012 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg650nm
2020-01-30T18:46:01.017Z,1580409961.017 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff470nm
2020-01-30T18:46:01.017Z,1580409961.017 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff470nm
2020-01-30T18:46:01.021Z,1580409961.021 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff650nm
2020-01-30T18:46:01.021Z,1580409961.021 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff650nm
2020-01-30T18:46:01.026Z,1580409961.026 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): mass_concentration_of_chlorophyll_in_sea_water
2020-01-30T18:46:01.030Z,1580409961.030 [WetLabsBB2FL](INFO): created writer for : mass_concentration_of_chlorophyll_in_sea_water
2020-01-30T18:46:01.031Z,1580409961.031 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_median_mass_concentration_of_chlorophyll_in_sea_water
2020-01-30T18:46:01.031Z,1580409961.031 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_median_mass_concentration_of_chlorophyll_in_sea_water
2020-01-30T18:46:01.035Z,1580409961.035 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water
2020-01-30T18:46:01.035Z,1580409961.035 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_mean_mass_concentration_of_chlorophyll_in_sea_water
2020-01-30T18:46:01.039Z,1580409961.039 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_variance_mass_concentration_of_chlorophyll_in_sea_water
2020-01-30T18:46:01.039Z,1580409961.039 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_variance_mass_concentration_of_chlorophyll_in_sea_water
2020-01-30T18:46:01.044Z,1580409961.044 [WetLabsBB2FL] Loaded
2020-01-30T18:46:01.044Z,1580409961.044 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2020-01-30T18:46:01.045Z,1580409961.045 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 409C64E0
2020-01-30T18:46:01.045Z,1580409961.045 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 1057
2020-01-30T18:46:01.046Z,1580409961.046 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2020-01-30T18:46:01.047Z,1580409961.047 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2020-01-30T18:46:01.078Z,1580409961.078 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2020-01-30T18:46:01.078Z,1580409961.078 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2020-01-30T18:46:01.363Z,1580409961.363 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2020-01-30T18:46:01.364Z,1580409961.364 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2020-01-30T18:46:01.495Z,1580409961.495 [SBIT](DEBUG): Construct Startup Built In Test.
2020-01-30T18:46:01.506Z,1580409961.506 [SBIT] Loaded
2020-01-30T18:46:01.506Z,1580409961.506 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2020-01-30T18:46:01.507Z,1580409961.507 [IBIT](DEBUG): Construct Initiated Built In Test.
2020-01-30T18:46:01.520Z,1580409961.520 [IBIT] Loaded
2020-01-30T18:46:01.520Z,1580409961.520 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2020-01-30T18:46:01.523Z,1580409961.523 [CBIT](DEBUG): Construct Continuous Built In Test.
2020-01-30T18:46:01.658Z,1580409961.658 [CBIT] Loaded
2020-01-30T18:46:01.658Z,1580409961.658 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2020-01-30T18:46:01.659Z,1580409961.659 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2020-01-30T18:46:01.662Z,1580409961.662 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2020-01-30T18:46:01.663Z,1580409961.663 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2020-01-30T18:46:01.670Z,1580409961.670 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2020-01-30T18:46:01.671Z,1580409961.671 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40AC54E0
2020-01-30T18:46:01.671Z,1580409961.671 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 1058
2020-01-30T18:46:01.676Z,1580409961.676 [Supervisor](INFO): Main Thread ID is 805
2020-01-30T18:46:01.676Z,1580409961.676 [Supervisor](DEBUG): Running supervisor.
2020-01-30T18:46:01.676Z,1580409961.676 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1059
2020-01-30T18:46:01.679Z,1580409961.679 [controlThread ThreadHandler](INFO): Handler Thread ID is 1060
2020-01-30T18:46:01.679Z,1580409961.679 [controlThread](DEBUG): Initializing ControlThread
2020-01-30T18:46:01.680Z,1580409961.680 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2020-01-30T18:46:01.682Z,1580409961.682 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2020-01-30T18:46:01.682Z,1580409961.682 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2020-01-30T18:46:01.683Z,1580409961.683 [LoopControl](DEBUG): Initialize LoopControlComponent.
2020-01-30T18:46:01.684Z,1580409961.684 [NavChart](DEBUG): Initialize NavChart Navigation.
2020-01-30T18:46:01.685Z,1580409961.685 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2020-01-30T18:46:01.691Z,1580409961.691 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2020-01-30T18:46:01.691Z,1580409961.691 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2020-01-30T18:46:01.691Z,1580409961.691 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2020-01-30T18:46:01.692Z,1580409961.692 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2020-01-30T18:46:01.692Z,1580409961.692 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2020-01-30T18:46:01.693Z,1580409961.693 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2020-01-30T18:46:01.697Z,1580409961.697 [SBIT](INFO): Initialize SBIT Component.
2020-01-30T18:46:01.698Z,1580409961.698 [SBIT](IMPORTANT): git: 2020-01-30
2020-01-30T18:46:01.698Z,1580409961.698 [SBIT](INFO): git hash: bb4c3e083af240d331c28efc6837de49dd3f09f0
2020-01-30T18:46:01.698Z,1580409961.698 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2020-01-30T18:46:01.699Z,1580409961.699 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #1 PREEMPT Tue Dec 18 21:19:28 PST 2018
2020-01-30T18:46:01.700Z,1580409961.700 [SBIT](INFO): Beginning SBIT in 39.000000 seconds.
2020-01-30T18:46:01.701Z,1580409961.701 [IBIT](INFO): Initialize IBIT Component.
2020-01-30T18:46:01.702Z,1580409961.702 [CBIT](DEBUG): Initialize CBIT Component.
2020-01-30T18:46:01.703Z,1580409961.703 [logger ThreadHandler](INFO): Handler Thread ID is 1061
2020-01-30T18:46:01.713Z,1580409961.713 [CBIT](DEBUG): Initialized mux pins.
2020-01-30T18:46:01.713Z,1580409961.713 [CBIT](DEBUG): Initializing the watchdog timer.
2020-01-30T18:46:01.721Z,1580409961.721 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 1062
2020-01-30T18:46:01.722Z,1580409961.722 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2020-01-30T18:46:01.733Z,1580409961.733 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 1063
2020-01-30T18:46:01.737Z,1580409961.737 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2020-01-30T18:46:01.737Z,1580409961.737 [CBIT](DEBUG): Initializing heartbeat.
2020-01-30T18:46:01.745Z,1580409961.745 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 1064
2020-01-30T18:46:01.746Z,1580409961.746 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2020-01-30T18:46:01.749Z,1580409961.749 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20
2020-01-30T18:46:01.750Z,1580409961.750 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 1066
2020-01-30T18:46:01.752Z,1580409961.752 [WetLabsBB2FL](INFO): Powering down
2020-01-30T18:46:01.781Z,1580409961.781 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1067
2020-01-30T18:46:01.784Z,1580409961.784 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2020-01-30T18:46:01.784Z,1580409961.784 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2020-01-30T18:46:01.785Z,1580409961.785 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2020-01-30T18:46:01.785Z,1580409961.785 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2020-01-30T18:46:01.785Z,1580409961.785 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2020-01-30T18:46:01.786Z,1580409961.786 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2020-01-30T18:46:01.786Z,1580409961.786 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2020-01-30T18:46:01.786Z,1580409961.786 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2020-01-30T18:46:01.786Z,1580409961.786 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2020-01-30T18:46:01.786Z,1580409961.786 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2020-01-30T18:46:01.786Z,1580409961.786 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2020-01-30T18:46:01.787Z,1580409961.787 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2020-01-30T18:46:01.787Z,1580409961.787 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2020-01-30T18:46:01.787Z,1580409961.787 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2020-01-30T18:46:01.787Z,1580409961.787 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2020-01-30T18:46:01.787Z,1580409961.787 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2020-01-30T18:46:01.809Z,1580409961.809 [CBIT](DEBUG): Deactivating GF circuits.
2020-01-30T18:46:01.809Z,1580409961.809 [CBIT](DEBUG): Deactivating emergency mode.
2020-01-30T18:46:01.845Z,1580409961.845 [CBIT](DEBUG): Backplane powered.
2020-01-30T18:46:01.846Z,1580409961.846 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2020-01-30T18:46:01.866Z,1580409961.866 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2020-01-30T18:46:01.877Z,1580409961.877 [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>


2020-01-30T18:46:01.878Z,1580409961.878 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2020-01-30T18:46:01.949Z,1580409961.949 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2020-01-30T18:46:01.950Z,1580409961.950 [Default:A.Wait](DEBUG): Construct Wait.
2020-01-30T18:46:01.952Z,1580409961.952 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2020-01-30T18:46:01.971Z,1580409961.971 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2020-01-30T18:46:01.993Z,1580409961.993 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2020-01-30T18:46:01.999Z,1580409961.999 [Default:E.Execute](DEBUG): Construct Execute.
2020-01-30T18:46:02.018Z,1580409962.018 [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>


2020-01-30T18:46:02.023Z,1580409962.023 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,NAL9602,Onboard,BPC1,CANONSampler,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2020-01-30T18:46:02.041Z,1580409962.041 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2020-01-30T18:46:02.075Z,1580409962.075 [Depth_Keller](ERROR): Pressure reading out of range: 1831.023193 decibar
2020-01-30T18:46:02.125Z,1580409962.125 [CANONSampler](INFO): Powering down
2020-01-30T18:46:02.137Z,1580409962.137 [Radio_Surface](INFO): Powering up
2020-01-30T18:46:02.175Z,1580409962.175 [DepthRateCalculator](ERROR): Depth measurement is not active
2020-01-30T18:46:02.198Z,1580409962.198 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2020-01-30T18:46:02.205Z,1580409962.205 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2020-01-30T18:46:02.206Z,1580409962.206 [ElevatorServo](DEBUG): Initializing EZServoServo.
2020-01-30T18:46:02.213Z,1580409962.213 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2020-01-30T18:46:02.214Z,1580409962.214 [MassServo](DEBUG): Initializing EZServoServo.
2020-01-30T18:46:02.221Z,1580409962.221 [MassServo](DEBUG): Initializing MassServo.
2020-01-30T18:46:02.222Z,1580409962.222 [RudderServo](DEBUG): Initializing EZServoServo.
2020-01-30T18:46:02.229Z,1580409962.229 [RudderServo](DEBUG): Initializing RudderServo.
2020-01-30T18:46:02.230Z,1580409962.230 [ThrusterServo](DEBUG): Initializing EZServoServo.
2020-01-30T18:46:02.241Z,1580409962.241 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2020-01-30T18:46:29.506Z,1580409989.506 [NAL9602](INFO): Powering up NAL9602
2020-01-30T18:46:40.418Z,1580410000.418 [NAL9602](INFO): NAL9602 initialized
2020-01-30T18:46:41.287Z,1580410001.287 [SBIT](IMPORTANT): Beginning Startup BIT
2020-01-30T18:46:41.321Z,1580410001.321 [CBIT](IMPORTANT): Beginning ground fault scan
2020-01-30T18:46:51.996Z,1580410011.996 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.005746
CHAN A1 (24V): -0.001082
CHAN A2 (12V): -0.002216
CHAN A3 (5V): -0.001336
CHAN B0 (3.3V): -0.000742
CHAN B1 (3.15aV): -0.000160
CHAN B2 (3.15bV): -0.000260
CHAN B3 (GND): 0.000126
OPEN: -0.000380
Full Scale Calc: 4.765 mA, -1.589 mA
2020-01-30T18:47:34.732Z,1580410054.732 [SBIT](IMPORTANT): SBIT PASSED
2020-01-30T18:47:34.732Z,1580410054.732 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2020-01-30T18:47:34.737Z,1580410054.737 [SBIT](IMPORTANT): CBIT.gf24Offset=-26 microampere;

2020-01-30T18:47:34.737Z,1580410054.737 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=205 cubic_centimeter;

2020-01-30T18:47:34.737Z,1580410054.737 [SBIT](IMPORTANT): VerticalControl.massDefault=-5 millimeter;

2020-01-30T18:47:35.097Z,1580410055.097 [MissionManager](IMPORTANT): Started mission Startup
2020-01-30T18:47:35.098Z,1580410055.098 [Startup] Running Loop=1
2020-01-30T18:47:35.098Z,1580410055.098 [Startup](DEBUG): Aggregate::initialize Startup
2020-01-30T18:47:35.098Z,1580410055.098 [Startup:A.GoToSurface] Running Loop=1
2020-01-30T18:47:35.098Z,1580410055.098 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-01-30T18:47:35.099Z,1580410055.099 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-01-30T18:47:35.099Z,1580410055.099 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-01-30T18:47:35.099Z,1580410055.099 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-01-30T18:47:35.100Z,1580410055.100 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-01-30T18:47:35.100Z,1580410055.100 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-01-30T18:47:35.102Z,1580410055.102 [Startup:StartupSatComms] Running Loop=1
2020-01-30T18:47:35.102Z,1580410055.102 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2020-01-30T18:47:35.102Z,1580410055.102 [Startup:StartupSatComms:A] Running Loop=1
2020-01-30T18:47:35.519Z,1580410055.519 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2020-01-30T18:48:35.288Z,1580410115.288 [Startup:StartupSatComms:A](INFO): Timed out from 2020-01-30T18:47:35.1Z
2020-01-30T18:48:35.289Z,1580410115.289 [Startup:StartupSatComms:A] Stopped
2020-01-30T18:48:35.289Z,1580410115.289 [Startup:StartupSatComms:B] Running Loop=1
2020-01-30T18:48:35.698Z,1580410115.698 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2020-01-30T18:49:01.969Z,1580410141.969 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2020-01-30T18:49:01.969Z,1580410141.969 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-01-30T18:49:01.979Z,1580410141.979 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-01-30T18:49:02.388Z,1580410142.388 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-01-30T18:49:02.388Z,1580410142.388 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2020-01-30T18:49:35.512Z,1580410175.512 [Startup:StartupSatComms:B](INFO): Timed out from 2020-01-30T18:48:35.3Z
2020-01-30T18:49:35.512Z,1580410175.512 [Startup:StartupSatComms:B] Stopped
2020-01-30T18:49:35.512Z,1580410175.512 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2020-01-30T18:49:35.513Z,1580410175.513 [Startup:StartupSatComms] Stopped
2020-01-30T18:49:35.513Z,1580410175.513 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2020-01-30T18:49:35.513Z,1580410175.513 [Startup](INFO): Completed Startup
2020-01-30T18:49:35.514Z,1580410175.514 [MissionManager](INFO): Startup is completed.
2020-01-30T18:49:35.514Z,1580410175.514 [MissionManager](INFO): Uninitializing Mission Startup
2020-01-30T18:49:35.514Z,1580410175.514 [Startup] Stopped
2020-01-30T18:49:35.514Z,1580410175.514 [Startup](DEBUG): Aggregate::uninitialize Startup
2020-01-30T18:49:35.514Z,1580410175.514 [Startup:A.GoToSurface] Stopped
2020-01-30T18:49:35.514Z,1580410175.514 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2020-01-30T18:49:35.888Z,1580410175.888 [MissionManager](IMPORTANT): Started mission Default
2020-01-30T18:49:35.888Z,1580410175.888 [Default] Running Loop=1
2020-01-30T18:49:35.888Z,1580410175.888 [Default](DEBUG): Aggregate::initialize Default
2020-01-30T18:49:35.888Z,1580410175.888 [Default:B.GoToSurface] Running Loop=1
2020-01-30T18:49:35.888Z,1580410175.888 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-01-30T18:49:35.889Z,1580410175.889 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-01-30T18:49:35.889Z,1580410175.889 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-01-30T18:49:35.889Z,1580410175.889 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-01-30T18:49:35.890Z,1580410175.890 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-01-30T18:49:35.890Z,1580410175.890 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-01-30T18:49:35.890Z,1580410175.890 [Default:A.Wait] Running Loop=1
2020-01-30T18:49:35.890Z,1580410175.890 [Default:A.Wait](DEBUG): Initialize Wait Component.
2020-01-30T18:49:36.979Z,1580410176.979 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.005018
2020-01-30T18:49:49.251Z,1580410189.251 [Default:A.Wait](INFO): Done Waiting.
2020-01-30T18:49:49.251Z,1580410189.251 [Default:A.Wait] Stopped
2020-01-30T18:49:49.251Z,1580410189.251 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2020-01-30T18:49:49.648Z,1580410189.648 [Default:CheckIn] Running Loop=1
2020-01-30T18:49:49.648Z,1580410189.648 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-01-30T18:49:49.648Z,1580410189.648 [Default:CheckIn:Read_GPS] Running Loop=1
2020-01-30T18:49:50.031Z,1580410190.031 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2020-01-30T18:51:43.978Z,1580410303.978 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-01-30T18:51:45.204Z,1580410305.204 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185142.00,A,3648.17027,N,12147.27925,W,0.214,0.00,300120,,,A*70
2020-01-30T18:51:45.207Z,1580410305.207 [NAL9602](INFO): GPS fix at 20200130T185142: (36.802838, -121.787987)
2020-01-30T18:51:45.292Z,1580410305.292 [Default:CheckIn:Read_GPS] Stopped
2020-01-30T18:51:45.292Z,1580410305.292 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-01-30T18:51:45.677Z,1580410305.677 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2020-01-30T18:51:47.506Z,1580410307.506 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20200130T183854/Courier0004.lzma
2020-01-30T18:51:49.510Z,1580410309.510 [DataOverHttps](INFO): Moved sent file to Logs/20200130T183854/Courier0004.lzma.bak
2020-01-30T18:51:49.511Z,1580410309.511 [DataOverHttps](INFO): SBD MOMSN=12206278
2020-01-30T18:52:07.941Z,1580410327.941 [DataOverHttps](INFO): Sending 189 bytes from file Logs/20200130T183854/Courier0007.lzma
2020-01-30T18:52:09.946Z,1580410329.946 [DataOverHttps](INFO): Moved sent file to Logs/20200130T183854/Courier0007.lzma.bak
2020-01-30T18:52:09.946Z,1580410329.946 [DataOverHttps](INFO): SBD MOMSN=12206281
2020-01-30T18:52:17.254Z,1580410337.254 [NAL9602](INFO): Not Powering down - fast GPS
2020-01-30T18:52:28.129Z,1580410348.129 [DataOverHttps](INFO): Sending 212 bytes from file Logs/20200130T184551/Courier0004.lzma
2020-01-30T18:52:30.134Z,1580410350.134 [DataOverHttps](INFO): Moved sent file to Logs/20200130T184551/Courier0004.lzma.bak
2020-01-30T18:52:30.134Z,1580410350.134 [DataOverHttps](INFO): SBD MOMSN=12206292
2020-01-30T18:52:47.410Z,1580410367.410 [DataOverHttps](INFO): Sending 657 bytes from file Logs/20200130T183854/Express0001.lzma
2020-01-30T18:52:49.414Z,1580410369.414 [DataOverHttps](INFO): Moved sent file to Logs/20200130T183854/Express0001.lzma.bak
2020-01-30T18:52:49.414Z,1580410369.414 [DataOverHttps](INFO): SBD MOMSN=12206296
2020-01-30T18:53:06.513Z,1580410386.513 [DataOverHttps](INFO): Sending 94 bytes from file Logs/20200130T183854/Express0005.lzma
2020-01-30T18:53:08.519Z,1580410388.519 [DataOverHttps](INFO): Moved sent file to Logs/20200130T183854/Express0005.lzma.bak
2020-01-30T18:53:08.519Z,1580410388.519 [DataOverHttps](INFO): SBD MOMSN=12206308
2020-01-30T18:53:25.831Z,1580410405.831 [DataOverHttps](INFO): Sending 924 bytes from file Logs/20200130T183854/Express0008.lzma
2020-01-30T18:53:27.835Z,1580410407.835 [DataOverHttps](INFO): Moved sent file to Logs/20200130T183854/Express0008.lzma.bak
2020-01-30T18:53:27.835Z,1580410407.835 [DataOverHttps](INFO): SBD MOMSN=12206311
2020-01-30T18:53:44.879Z,1580410424.879 [DataOverHttps](INFO): Sending 623 bytes from file Logs/20200130T184551/Express0001.lzma
2020-01-30T18:53:46.882Z,1580410426.882 [DataOverHttps](INFO): Moved sent file to Logs/20200130T184551/Express0001.lzma.bak
2020-01-30T18:53:46.882Z,1580410426.882 [DataOverHttps](INFO): SBD MOMSN=12206344
2020-01-30T18:54:03.977Z,1580410443.977 [DataOverHttps](INFO): Sending 301 bytes from file Logs/20200130T184551/Express0005.lzma
2020-01-30T18:54:05.982Z,1580410445.982 [DataOverHttps](INFO): Moved sent file to Logs/20200130T184551/Express0005.lzma.bak
2020-01-30T18:54:05.983Z,1580410445.983 [DataOverHttps](INFO): SBD MOMSN=12206358
2020-01-30T18:54:07.170Z,1580410447.170 [Default:CheckIn:Read_Iridium] Stopped
2020-01-30T18:54:07.170Z,1580410447.170 [Default:CheckIn:C.Wait] Running Loop=1
2020-01-30T18:54:07.170Z,1580410447.170 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-01-30T18:54:31.013Z,1580410471.013 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2020-01-30T18:54:31.016Z,1580410471.016 [BPC1](INFO): Received data from all battery sticks.
2020-01-30T18:59:07.781Z,1580410747.781 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-01-30T18:59:07.781Z,1580410747.781 [Default:CheckIn:C.Wait] Stopped
2020-01-30T18:59:07.781Z,1580410747.781 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-01-30T18:59:07.781Z,1580410747.781 [Default:CheckIn:D] Running Loop=1
2020-01-30T18:59:08.187Z,1580410748.187 [Default:CheckIn:D] Stopped
2020-01-30T18:59:08.187Z,1580410748.187 [Default:CheckIn:E] Running Loop=1
2020-01-30T18:59:08.577Z,1580410748.577 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 9.538318 min 
2020-01-30T18:59:08.577Z,1580410748.577 [Default:CheckIn:E] Stopped
2020-01-30T18:59:08.577Z,1580410748.577 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-01-30T18:59:08.578Z,1580410748.578 [Default:CheckIn] Stopped
2020-01-30T18:59:08.578Z,1580410748.578 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-01-30T18:59:08.578Z,1580410748.578 [Default:CheckIn](INFO): Running loop #2
2020-01-30T18:59:08.578Z,1580410748.578 [Default:CheckIn] Running Loop=2
2020-01-30T18:59:08.578Z,1580410748.578 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-01-30T18:59:08.578Z,1580410748.578 [Default:CheckIn:Read_GPS] Running Loop=1
2020-01-30T18:59:10.578Z,1580410750.578 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185908.00,A,3648.17077,N,12147.29265,W,0.447,273.64,300120,,,A*76
2020-01-30T18:59:10.580Z,1580410750.580 [NAL9602](INFO): GPS fix at 20200130T185908: (36.802846, -121.788211)
2020-01-30T18:59:10.603Z,1580410750.603 [Default:CheckIn:Read_GPS] Stopped
2020-01-30T18:59:10.603Z,1580410750.603 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-01-30T18:59:17.861Z,1580410757.861 [DataOverHttps](INFO): Sending 220 bytes from file Logs/20200130T184551/Courier0007.lzma
2020-01-30T18:59:19.866Z,1580410759.866 [DataOverHttps](INFO): Moved sent file to Logs/20200130T184551/Courier0007.lzma.bak
2020-01-30T18:59:19.866Z,1580410759.866 [DataOverHttps](INFO): SBD MOMSN=12206362
2020-01-30T18:59:36.861Z,1580410776.861 [DataOverHttps](INFO): Sending 163 bytes from file Logs/20200130T184551/Express0008.lzma
2020-01-30T18:59:38.866Z,1580410778.866 [DataOverHttps](INFO): Moved sent file to Logs/20200130T184551/Express0008.lzma.bak
2020-01-30T18:59:38.866Z,1580410778.866 [DataOverHttps](INFO): SBD MOMSN=12206365
2020-01-30T18:59:40.106Z,1580410780.106 [Default:CheckIn:Read_Iridium] Stopped
2020-01-30T18:59:40.106Z,1580410780.106 [Default:CheckIn:C.Wait] Running Loop=1
2020-01-30T18:59:40.106Z,1580410780.106 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-01-30T18:59:41.278Z,1580410781.278 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2020-01-30T18:59:41.361Z,1580410781.361 [NAL9602](FAULT): received: 
+CSQ:0

OK
2020-01-30T18:59:41.361Z,1580410781.361 [NAL9602] Data Fault, FailCount= 1
2020-01-30T18:59:41.361Z,1580410781.361 [NAL9602](ERROR): Data Fault
2020-01-30T18:59:41.430Z,1580410781.430 [CBIT](ERROR): Data Fault in component: NAL9602
2020-01-30T18:59:41.682Z,1580410781.682 [NAL9602](INFO): Powering down
2020-01-30T18:59:42.558Z,1580410782.558 [CBIT](INFO): Clearing failed state for component NAL9602
2020-01-30T18:59:42.558Z,1580410782.558 [NAL9602] No Fault, FailCount= 1
2020-01-30T19:00:11.989Z,1580410811.989 [NAL9602](INFO): Powering up NAL9602
2020-01-30T19:00:22.890Z,1580410822.890 [NAL9602](INFO): NAL9602 initialized
2020-01-30T19:00:53.998Z,1580410853.998 [NAL9602](INFO): Not Powering down - fast GPS
2020-01-30T19:04:40.673Z,1580411080.673 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-01-30T19:04:40.673Z,1580411080.673 [Default:CheckIn:C.Wait] Stopped
2020-01-30T19:04:40.673Z,1580411080.673 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-01-30T19:04:40.673Z,1580411080.673 [Default:CheckIn:D] Running Loop=1
2020-01-30T19:04:41.077Z,1580411081.077 [Default:CheckIn:D] Stopped
2020-01-30T19:04:41.077Z,1580411081.077 [Default:CheckIn:E] Running Loop=1
2020-01-30T19:04:41.475Z,1580411081.475 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 15.086484 min 
2020-01-30T19:04:41.475Z,1580411081.475 [Default:CheckIn:E] Stopped
2020-01-30T19:04:41.475Z,1580411081.475 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-01-30T19:04:41.476Z,1580411081.476 [Default:CheckIn] Stopped
2020-01-30T19:04:41.476Z,1580411081.476 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-01-30T19:04:41.476Z,1580411081.476 [Default:CheckIn](INFO): Running loop #3
2020-01-30T19:04:41.476Z,1580411081.476 [Default:CheckIn] Running Loop=3
2020-01-30T19:04:41.476Z,1580411081.476 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-01-30T19:04:41.476Z,1580411081.476 [Default:CheckIn:Read_GPS] Running Loop=1
2020-01-30T19:04:45.082Z,1580411085.082 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-01-30T19:05:46.324Z,1580411146.324 [CommandLine](IMPORTANT): got command ibit
2020-01-30T19:05:46.575Z,1580411146.575 [IBIT](IMPORTANT): Beginning Initiated BIT
2020-01-30T19:05:46.575Z,1580411146.575 [IBIT](IMPORTANT): Beginning control surface checks.
2020-01-30T19:05:46.578Z,1580411146.578 [CBIT](IMPORTANT): Beginning ground fault scan
2020-01-30T19:05:57.528Z,1580411157.528 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.006189
CHAN A1 (24V): -0.000543
CHAN A2 (12V): -0.002007
CHAN A3 (5V): -0.001880
CHAN B0 (3.3V): -0.000107
CHAN B1 (3.15aV): -0.000332
CHAN B2 (3.15bV): -0.000245
CHAN B3 (GND): 0.000200
OPEN: -0.000488
Full Scale Calc: 4.765 mA, -1.589 mA
2020-01-30T19:07:37.248Z,1580411257.248 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190733.00,A,3648.15857,N,12147.22989,W,1.944,130.53,300120,,,A*71
2020-01-30T19:07:37.250Z,1580411257.250 [NAL9602](INFO): GPS fix at 20200130T190733: (36.802643, -121.787165)
2020-01-30T19:07:37.702Z,1580411257.702 [IBIT](FAULT): Error acquiring IBIT communications status. Timeout expired.
2020-01-30T19:07:38.087Z,1580411258.087 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 0.000000
Voltage: 0.000000
2020-01-30T19:07:38.087Z,1580411258.087 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah
2020-01-30T19:07:38.087Z,1580411258.087 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V
2020-01-30T19:07:38.493Z,1580411258.493 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2020-01-30T19:07:38.493Z,1580411258.493 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2020-01-30T19:07:38.493Z,1580411258.493 [IBIT](IMPORTANT): Pressure:8.004346 PSI
2020-01-30T19:07:38.494Z,1580411258.494 [IBIT](IMPORTANT): Humidity:8.423880 %
2020-01-30T19:07:38.925Z,1580411258.925 [IBIT](IMPORTANT): Vehicle Pitch:1.075717 degrees
2020-01-30T19:07:38.926Z,1580411258.926 [IBIT](IMPORTANT): Vehicle  Roll:5.752894 degrees
2020-01-30T19:07:38.926Z,1580411258.926 [IBIT](IMPORTANT): Vehicle  Heading:351.474091 degrees
2020-01-30T19:07:39.294Z,1580411259.294 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2020-01-30T19:07:39.295Z,1580411259.295 [IBIT](IMPORTANT): buoyancyNeutral: 205.000000 cc
2020-01-30T19:07:39.295Z,1580411259.295 [IBIT](IMPORTANT): massDefault: -0.500000 cm
2020-01-30T19:07:39.295Z,1580411259.295 [IBIT](IMPORTANT): stopDepth: 205.000000 m
2020-01-30T19:07:39.296Z,1580411259.296 [IBIT](IMPORTANT): abortDepth: 250.000000 m
2020-01-30T19:07:39.296Z,1580411259.296 [IBIT](IMPORTANT): IBIT FAILED
2020-01-30T19:07:39.705Z,1580411259.705 [Default:CheckIn:Read_GPS] Stopped
2020-01-30T19:07:39.705Z,1580411259.705 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-01-30T19:07:40.076Z,1580411260.076 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190736.00,A,3648.15974,N,12147.23958,W,2.469,130.53,300120,,,A*78
2020-01-30T19:07:40.078Z,1580411260.078 [NAL9602](INFO): GPS fix at 20200130T190736: (36.802662, -121.787326)
2020-01-30T19:07:47.468Z,1580411267.468 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20200130T184551/Courier0010.lzma
2020-01-30T19:07:49.474Z,1580411269.474 [DataOverHttps](INFO): Moved sent file to Logs/20200130T184551/Courier0010.lzma.bak
2020-01-30T19:07:49.475Z,1580411269.475 [DataOverHttps](INFO): SBD MOMSN=12206368
2020-01-30T19:07:50.805Z,1580411270.805 [CommandLine](IMPORTANT): got command ibit
2020-01-30T19:07:51.021Z,1580411271.021 [IBIT](IMPORTANT): Beginning Initiated BIT
2020-01-30T19:07:51.021Z,1580411271.021 [IBIT](IMPORTANT): Beginning control surface checks.
2020-01-30T19:07:51.024Z,1580411271.024 [CBIT](IMPORTANT): Beginning ground fault scan
2020-01-30T19:07:52.596Z,1580411272.596 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190748.00,A,3648.15415,N,12147.25434,W,3.188,224.62,300120,,,A*75
2020-01-30T19:07:52.602Z,1580411272.602 [NAL9602](INFO): GPS fix at 20200130T190748: (36.802569, -121.787572)
2020-01-30T19:07:55.020Z,1580411275.020 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190751.00,A,3648.15214,N,12147.25657,W,2.857,224.62,300120,,,A*77
2020-01-30T19:07:55.023Z,1580411275.023 [NAL9602](INFO): GPS fix at 20200130T190751: (36.802536, -121.787610)
2020-01-30T19:07:58.250Z,1580411278.250 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190754.00,A,3648.15031,N,12147.25836,W,2.313,224.62,300120,,,A*75
2020-01-30T19:07:58.252Z,1580411278.252 [NAL9602](INFO): GPS fix at 20200130T190754: (36.802505, -121.787639)
2020-01-30T19:08:01.083Z,1580411281.083 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190757.00,A,3648.14835,N,12147.25905,W,2.488,224.62,300120,,,A*7F
2020-01-30T19:08:01.086Z,1580411281.086 [NAL9602](INFO): GPS fix at 20200130T190757: (36.802473, -121.787651)
2020-01-30T19:08:02.340Z,1580411282.340 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.006034
CHAN A1 (24V): -0.000833
CHAN A2 (12V): -0.002074
CHAN A3 (5V): -0.001174
CHAN B0 (3.3V): 0.000273
CHAN B1 (3.15aV): 0.000425
CHAN B2 (3.15bV): 0.000243
CHAN B3 (GND): 0.000061
OPEN: -0.000386
Full Scale Calc: 4.765 mA, -1.589 mA
2020-01-30T19:08:04.312Z,1580411284.312 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190800.00,A,3648.14650,N,12147.25815,W,2.099,224.62,300120,,,A*7B
2020-01-30T19:08:04.314Z,1580411284.314 [NAL9602](INFO): GPS fix at 20200130T190800: (36.802442, -121.787636)
2020-01-30T19:08:07.143Z,1580411287.143 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190803.00,A,3648.14541,N,12147.25740,W,1.205,224.62,300120,,,A*70
2020-01-30T19:08:07.146Z,1580411287.146 [NAL9602](INFO): GPS fix at 20200130T190803: (36.802424, -121.787623)
2020-01-30T19:08:07.571Z,1580411287.571 [DataOverHttps](INFO): Sending 840 bytes from file Logs/20200130T184551/Express0011.lzma
2020-01-30T19:08:09.575Z,1580411289.575 [DataOverHttps](INFO): Moved sent file to Logs/20200130T184551/Express0011.lzma.bak
2020-01-30T19:08:09.575Z,1580411289.575 [DataOverHttps](INFO): SBD MOMSN=12206371
2020-01-30T19:08:10.390Z,1580411290.390 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190806.00,A,3648.14459,N,12147.25543,W,1.263,178.02,300120,,,A*70
2020-01-30T19:08:10.393Z,1580411290.393 [NAL9602](INFO): GPS fix at 20200130T190806: (36.802410, -121.787590)
2020-01-30T19:08:13.212Z,1580411293.212 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190809.00,A,3648.14426,N,12147.25526,W,1.380,129.85,300120,,,A*73
2020-01-30T19:08:13.219Z,1580411293.219 [NAL9602](INFO): GPS fix at 20200130T190809: (36.802404, -121.787588)
2020-01-30T19:08:16.434Z,1580411296.434 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190812.00,A,3648.14332,N,12147.25372,W,2.158,126.27,300120,,,A*7F
2020-01-30T19:08:16.436Z,1580411296.436 [NAL9602](INFO): GPS fix at 20200130T190812: (36.802389, -121.787562)
2020-01-30T19:08:19.264Z,1580411299.264 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190815.00,A,3648.14227,N,12147.25115,W,1.827,123.29,300120,,,A*77
2020-01-30T19:08:19.266Z,1580411299.266 [NAL9602](INFO): GPS fix at 20200130T190815: (36.802371, -121.787519)
2020-01-30T19:08:22.088Z,1580411302.088 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190818.00,A,3648.14174,N,12147.24961,W,1.749,116.25,300120,,,A*78
2020-01-30T19:08:22.090Z,1580411302.090 [NAL9602](INFO): GPS fix at 20200130T190818: (36.802362, -121.787493)
2020-01-30T19:08:25.320Z,1580411305.320 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190821.00,A,3648.14146,N,12147.24611,W,2.294,97.76,300120,,,A*43
2020-01-30T19:08:25.322Z,1580411305.322 [NAL9602](INFO): GPS fix at 20200130T190821: (36.802358, -121.787435)
2020-01-30T19:08:28.148Z,1580411308.148 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190824.00,A,3648.14113,N,12147.24212,W,1.166,97.76,300120,,,A*4C
2020-01-30T19:08:28.150Z,1580411308.150 [NAL9602](INFO): GPS fix at 20200130T190824: (36.802352, -121.787369)
2020-01-30T19:08:31.388Z,1580411311.388 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190827.00,A,3648.14060,N,12147.23852,W,1.633,96.84,300120,,,A*48
2020-01-30T19:08:31.390Z,1580411311.390 [NAL9602](INFO): GPS fix at 20200130T190827: (36.802343, -121.787309)
2020-01-30T19:08:34.220Z,1580411314.220 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190830.00,A,3648.13960,N,12147.23297,W,1.808,89.76,300120,,,A*46
2020-01-30T19:08:34.234Z,1580411314.234 [NAL9602](INFO): GPS fix at 20200130T190830: (36.802327, -121.787216)
2020-01-30T19:08:37.451Z,1580411317.451 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190833.00,A,3648.14040,N,12147.23085,W,2.060,63.53,300120,,,A*4E
2020-01-30T19:08:37.454Z,1580411317.454 [NAL9602](INFO): GPS fix at 20200130T190833: (36.802340, -121.787181)
2020-01-30T19:08:40.280Z,1580411320.280 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190837.00,A,3648.14140,N,12147.22936,W,2.177,53.35,300120,,,A*4F
2020-01-30T19:08:40.282Z,1580411320.282 [NAL9602](INFO): GPS fix at 20200130T190837: (36.802357, -121.787156)
2020-01-30T19:08:43.104Z,1580411323.104 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190840.00,A,3648.14263,N,12147.22818,W,1.963,44.05,300120,,,A*4B
2020-01-30T19:08:43.106Z,1580411323.106 [NAL9602](INFO): GPS fix at 20200130T190840: (36.802377, -121.787136)
2020-01-30T19:08:46.342Z,1580411326.342 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190843.00,A,3648.14329,N,12147.22724,W,0.505,47.01,300120,,,A*4D
2020-01-30T19:08:46.344Z,1580411326.344 [NAL9602](INFO): GPS fix at 20200130T190843: (36.802388, -121.787121)
2020-01-30T19:08:49.168Z,1580411329.168 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190846.00,A,3648.14332,N,12147.22742,W,0.117,47.01,300120,,,A*45
2020-01-30T19:08:49.170Z,1580411329.170 [NAL9602](INFO): GPS fix at 20200130T190846: (36.802389, -121.787124)
2020-01-30T19:08:52.396Z,1580411332.396 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190849.00,A,3648.14332,N,12147.22734,W,0.175,47.01,300120,,,A*4F
2020-01-30T19:08:52.398Z,1580411332.398 [NAL9602](INFO): GPS fix at 20200130T190849: (36.802389, -121.787122)
2020-01-30T19:08:55.224Z,1580411335.224 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190852.00,A,3648.14331,N,12147.22743,W,0.233,47.01,300120,,,A*47
2020-01-30T19:08:55.226Z,1580411335.226 [NAL9602](INFO): GPS fix at 20200130T190852: (36.802388, -121.787124)
2020-01-30T19:08:58.460Z,1580411338.460 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190855.00,A,3648.14327,N,12147.22760,W,0.156,47.01,300120,,,A*46
2020-01-30T19:08:58.462Z,1580411338.462 [NAL9602](INFO): GPS fix at 20200130T190855: (36.802388, -121.787127)
2020-01-30T19:09:01.284Z,1580411341.284 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190858.00,A,3648.14326,N,12147.22791,W,0.136,47.01,300120,,,A*42
2020-01-30T19:09:01.286Z,1580411341.286 [NAL9602](INFO): GPS fix at 20200130T190858: (36.802388, -121.787132)
2020-01-30T19:09:04.516Z,1580411344.516 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190901.00,A,3648.14316,N,12147.22752,W,0.058,47.01,300120,,,A*4A
2020-01-30T19:09:04.518Z,1580411344.518 [NAL9602](INFO): GPS fix at 20200130T190901: (36.802386, -121.787125)
2020-01-30T19:09:07.348Z,1580411347.348 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190904.00,A,3648.14311,N,12147.22713,W,0.097,47.01,300120,,,A*4E
2020-01-30T19:09:07.363Z,1580411347.363 [NAL9602](INFO): GPS fix at 20200130T190904: (36.802385, -121.787119)
2020-01-30T19:09:10.169Z,1580411350.169 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190907.00,A,3648.14310,N,12147.22710,W,0.058,47.01,300120,,,A*4C
2020-01-30T19:09:10.172Z,1580411350.172 [NAL9602](INFO): GPS fix at 20200130T190907: (36.802385, -121.787118)
2020-01-30T19:09:13.404Z,1580411353.404 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190910.00,A,3648.14307,N,12147.22719,W,0.078,47.01,300120,,,A*47
2020-01-30T19:09:13.406Z,1580411353.406 [NAL9602](INFO): GPS fix at 20200130T190910: (36.802385, -121.787120)
2020-01-30T19:09:16.229Z,1580411356.229 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190913.00,A,3648.14307,N,12147.22721,W,0.039,47.01,300120,,,A*4A
2020-01-30T19:09:16.231Z,1580411356.231 [NAL9602](INFO): GPS fix at 20200130T190913: (36.802385, -121.787120)
2020-01-30T19:09:19.480Z,1580411359.480 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190916.00,A,3648.14303,N,12147.22712,W,0.039,47.01,300120,,,A*4B
2020-01-30T19:09:19.482Z,1580411359.482 [NAL9602](INFO): GPS fix at 20200130T190916: (36.802384, -121.787119)
2020-01-30T19:09:22.292Z,1580411362.292 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190919.00,A,3648.14293,N,12147.22699,W,0.039,47.01,300120,,,A*4E
2020-01-30T19:09:22.298Z,1580411362.298 [NAL9602](INFO): GPS fix at 20200130T190919: (36.802382, -121.787116)
2020-01-30T19:09:25.527Z,1580411365.527 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190922.00,A,3648.14288,N,12147.22699,W,0.019,47.01,300120,,,A*4E
2020-01-30T19:09:25.529Z,1580411365.529 [NAL9602](INFO): GPS fix at 20200130T190922: (36.802381, -121.787116)
2020-01-30T19:09:28.355Z,1580411368.355 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190925.00,A,3648.14285,N,12147.22701,W,0.078,47.01,300120,,,A*43
2020-01-30T19:09:28.358Z,1580411368.358 [NAL9602](INFO): GPS fix at 20200130T190925: (36.802381, -121.787117)
2020-01-30T19:09:31.180Z,1580411371.180 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190928.00,A,3648.14282,N,12147.22704,W,0.039,47.01,300120,,,A*49
2020-01-30T19:09:31.182Z,1580411371.182 [NAL9602](INFO): GPS fix at 20200130T190928: (36.802380, -121.787117)
2020-01-30T19:09:34.411Z,1580411374.411 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190931.00,A,3648.14281,N,12147.22712,W,0.058,47.01,300120,,,A*42
2020-01-30T19:09:34.414Z,1580411374.414 [NAL9602](INFO): GPS fix at 20200130T190931: (36.802380, -121.787119)
2020-01-30T19:09:37.240Z,1580411377.240 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190934.00,A,3648.14279,N,12147.22718,W,0.039,47.01,300120,,,A*4D
2020-01-30T19:09:37.242Z,1580411377.242 [NAL9602](INFO): GPS fix at 20200130T190934: (36.802380, -121.787120)
2020-01-30T19:09:40.475Z,1580411380.475 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190937.00,A,3648.14278,N,12147.22721,W,0.058,47.01,300120,,,A*42
2020-01-30T19:09:40.478Z,1580411380.478 [NAL9602](INFO): GPS fix at 20200130T190937: (36.802380, -121.787120)
2020-01-30T19:09:41.742Z,1580411381.742 [IBIT](FAULT): Error acquiring IBIT communications status. Timeout expired.
2020-01-30T19:09:42.158Z,1580411382.158 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 0.000000
Voltage: 0.000000
2020-01-30T19:09:42.158Z,1580411382.158 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah
2020-01-30T19:09:42.158Z,1580411382.158 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V
2020-01-30T19:09:42.549Z,1580411382.549 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2020-01-30T19:09:42.550Z,1580411382.550 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2020-01-30T19:09:42.550Z,1580411382.550 [IBIT](IMPORTANT): Pressure:8.041198 PSI
2020-01-30T19:09:42.550Z,1580411382.550 [IBIT](IMPORTANT): Humidity:8.448297 %
2020-01-30T19:09:42.969Z,1580411382.969 [IBIT](IMPORTANT): Vehicle Pitch:0.966776 degrees
2020-01-30T19:09:42.969Z,1580411382.969 [IBIT](IMPORTANT): Vehicle  Roll:1.918211 degrees
2020-01-30T19:09:42.969Z,1580411382.969 [IBIT](IMPORTANT): Vehicle  Heading:218.425812 degrees
2020-01-30T19:09:43.304Z,1580411383.304 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190940.00,A,3648.14277,N,12147.22731,W,0.058,47.01,300120,,,A*4C
2020-01-30T19:09:43.306Z,1580411383.306 [NAL9602](INFO): GPS fix at 20200130T190940: (36.802380, -121.787122)
2020-01-30T19:09:43.430Z,1580411383.430 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2020-01-30T19:09:43.430Z,1580411383.430 [IBIT](IMPORTANT): buoyancyNeutral: 205.000000 cc
2020-01-30T19:09:43.431Z,1580411383.431 [IBIT](IMPORTANT): massDefault: -0.500000 cm
2020-01-30T19:09:43.431Z,1580411383.431 [IBIT](IMPORTANT): stopDepth: 205.000000 m
2020-01-30T19:09:43.431Z,1580411383.431 [IBIT](IMPORTANT): abortDepth: 250.000000 m
2020-01-30T19:09:43.431Z,1580411383.431 [IBIT](IMPORTANT): IBIT FAILED
2020-01-30T19:09:43.756Z,1580411383.756 [Default:CheckIn:Read_Iridium] Stopped
2020-01-30T19:09:43.756Z,1580411383.756 [Default:CheckIn:C.Wait] Running Loop=1
2020-01-30T19:09:43.756Z,1580411383.756 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-01-30T19:10:16.030Z,1580411416.030 [NAL9602](INFO): Not Powering down - fast GPS
2020-01-30T19:11:34.971Z,1580411494.971 [CommandLine](IMPORTANT): got command ibit
2020-01-30T19:11:35.250Z,1580411495.250 [IBIT](IMPORTANT): Beginning Initiated BIT
2020-01-30T19:11:35.250Z,1580411495.250 [IBIT](IMPORTANT): Beginning control surface checks.
2020-01-30T19:11:35.254Z,1580411495.254 [CBIT](IMPORTANT): Beginning ground fault scan
2020-01-30T19:11:36.831Z,1580411496.831 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191133.00,A,3648.14392,N,12147.22776,W,0.019,47.01,300120,,,A*4D
2020-01-30T19:11:36.834Z,1580411496.834 [NAL9602](INFO): GPS fix at 20200130T191133: (36.802399, -121.787129)
2020-01-30T19:11:46.162Z,1580411506.162 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.005925
CHAN A1 (24V): -0.000362
CHAN A2 (12V): -0.002118
CHAN A3 (5V): -0.001625
CHAN B0 (3.3V): -0.000148
CHAN B1 (3.15aV): -0.000232
CHAN B2 (3.15bV): -0.000332
CHAN B3 (GND): -0.000504
OPEN: -0.000494
Full Scale Calc: 4.765 mA, -1.589 mA
2020-01-30T19:12:01.067Z,1580411521.067 [NAL9602](INFO): SBD MO Status=2, MOMSN=18970, MT Status=2, MTMSN=0
2020-01-30T19:12:01.067Z,1580411521.067 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-01-30T19:12:21.715Z,1580411541.715 [IBIT](IMPORTANT): Communications Status:
Fix Status: 1
Iridium Signal Strength: 2
Latitude: 36.802399 Longitude: -121.787132
2020-01-30T19:12:22.110Z,1580411542.110 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 0.000000
Voltage: 0.000000
2020-01-30T19:12:22.110Z,1580411542.110 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah
2020-01-30T19:12:22.110Z,1580411542.110 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V
2020-01-30T19:12:22.515Z,1580411542.515 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2020-01-30T19:12:22.516Z,1580411542.516 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2020-01-30T19:12:22.516Z,1580411542.516 [IBIT](IMPORTANT): Pressure:8.008159 PSI
2020-01-30T19:12:22.516Z,1580411542.516 [IBIT](IMPORTANT): Humidity:8.472714 %
2020-01-30T19:12:22.930Z,1580411542.930 [IBIT](IMPORTANT): Vehicle Pitch:0.974830 degrees
2020-01-30T19:12:22.931Z,1580411542.931 [IBIT](IMPORTANT): Vehicle  Roll:1.925611 degrees
2020-01-30T19:12:22.931Z,1580411542.931 [IBIT](IMPORTANT): Vehicle  Heading:218.424698 degrees
2020-01-30T19:12:23.318Z,1580411543.318 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2020-01-30T19:12:23.318Z,1580411543.318 [IBIT](IMPORTANT): buoyancyNeutral: 205.000000 cc
2020-01-30T19:12:23.318Z,1580411543.318 [IBIT](IMPORTANT): massDefault: -0.500000 cm
2020-01-30T19:12:23.319Z,1580411543.319 [IBIT](IMPORTANT): stopDepth: 205.000000 m
2020-01-30T19:12:23.319Z,1580411543.319 [IBIT](IMPORTANT): abortDepth: 250.000000 m
2020-01-30T19:12:23.319Z,1580411543.319 [IBIT](IMPORTANT): IBIT PASSED
2020-01-30T19:12:24.495Z,1580411544.495 [NAL9602](INFO): SBD MO Status=2, MOMSN=18970, MT Status=2, MTMSN=0
2020-01-30T19:12:24.495Z,1580411544.495 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-01-30T19:12:34.191Z,1580411554.191 [NAL9602](INFO): SBD MO Status=0, MOMSN=18970, MT Status=0, MTMSN=0
2020-01-30T19:12:34.192Z,1580411554.192 [NAL9602](INFO): No messages in MT queue
2020-01-30T19:13:04.894Z,1580411584.894 [NAL9602](INFO): Not Powering down - fast GPS
2020-01-30T19:14:44.343Z,1580411684.343 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-01-30T19:14:44.343Z,1580411684.343 [Default:CheckIn:C.Wait] Stopped
2020-01-30T19:14:44.343Z,1580411684.343 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-01-30T19:14:44.343Z,1580411684.343 [Default:CheckIn:D] Running Loop=1
2020-01-30T19:14:44.750Z,1580411684.750 [Default:CheckIn:D] Stopped
2020-01-30T19:14:44.750Z,1580411684.750 [Default:CheckIn:E] Running Loop=1
2020-01-30T19:14:45.165Z,1580411685.165 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 25.147689 min 
2020-01-30T19:14:45.165Z,1580411685.165 [Default:CheckIn:E] Stopped
2020-01-30T19:14:45.165Z,1580411685.165 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-01-30T19:14:45.165Z,1580411685.165 [Default:CheckIn] Stopped
2020-01-30T19:14:45.165Z,1580411685.165 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-01-30T19:14:45.166Z,1580411685.166 [Default:CheckIn](INFO): Running loop #4
2020-01-30T19:14:45.166Z,1580411685.166 [Default:CheckIn] Running Loop=4
2020-01-30T19:14:45.166Z,1580411685.166 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-01-30T19:14:45.166Z,1580411685.166 [Default:CheckIn:Read_GPS] Running Loop=1
2020-01-30T19:14:47.139Z,1580411687.139 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191443.00,A,3648.15887,N,12147.21948,W,0.058,23.95,300120,,,A*4B
2020-01-30T19:14:47.142Z,1580411687.142 [NAL9602](INFO): GPS fix at 20200130T191443: (36.802648, -121.786991)
2020-01-30T19:14:47.166Z,1580411687.166 [Default:CheckIn:Read_GPS] Stopped
2020-01-30T19:14:47.166Z,1580411687.166 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-01-30T19:14:54.564Z,1580411694.564 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20200130T184551/Courier0013.lzma
2020-01-30T19:14:56.570Z,1580411696.570 [DataOverHttps](INFO): Moved sent file to Logs/20200130T184551/Courier0013.lzma.bak
2020-01-30T19:14:56.570Z,1580411696.570 [DataOverHttps](INFO): SBD MOMSN=12206399
2020-01-30T19:15:10.163Z,1580411710.163 [NAL9602](INFO): SBD MO Status=2, MOMSN=18971, MT Status=2, MTMSN=0
2020-01-30T19:15:10.163Z,1580411710.163 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-01-30T19:15:13.623Z,1580411713.623 [DataOverHttps](INFO): Sending 981 bytes from file Logs/20200130T184551/Express0014.lzma
2020-01-30T19:15:15.626Z,1580411715.626 [DataOverHttps](INFO): Moved sent file to Logs/20200130T184551/Express0014.lzma.bak
2020-01-30T19:15:15.626Z,1580411715.626 [DataOverHttps](INFO): SBD MOMSN=12206402
2020-01-30T19:15:16.683Z,1580411716.683 [Default:CheckIn:Read_Iridium] Stopped
2020-01-30T19:15:16.683Z,1580411716.683 [Default:CheckIn:C.Wait] Running Loop=1
2020-01-30T19:15:16.683Z,1580411716.683 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-01-30T19:15:51.775Z,1580411751.775 [NAL9602](INFO): SBD MO Status=0, MOMSN=18971, MT Status=0, MTMSN=0
2020-01-30T19:15:51.775Z,1580411751.775 [NAL9602](INFO): No messages in MT queue
2020-01-30T19:16:22.478Z,1580411782.478 [NAL9602](INFO): Not Powering down - fast GPS
2020-01-30T19:20:17.250Z,1580412017.250 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-01-30T19:20:17.250Z,1580412017.250 [Default:CheckIn:C.Wait] Stopped
2020-01-30T19:20:17.250Z,1580412017.250 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-01-30T19:20:17.251Z,1580412017.251 [Default:CheckIn:D] Running Loop=1
2020-01-30T19:20:17.661Z,1580412017.661 [Default:CheckIn:D] Stopped
2020-01-30T19:20:17.661Z,1580412017.661 [Default:CheckIn:E] Running Loop=1
2020-01-30T19:20:18.037Z,1580412018.037 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 30.696214 min 
2020-01-30T19:20:18.037Z,1580412018.037 [Default:CheckIn:E] Stopped
2020-01-30T19:20:18.038Z,1580412018.038 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-01-30T19:20:18.038Z,1580412018.038 [Default:CheckIn] Stopped
2020-01-30T19:20:18.038Z,1580412018.038 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-01-30T19:20:18.038Z,1580412018.038 [Default:CheckIn](INFO): Running loop #5
2020-01-30T19:20:18.038Z,1580412018.038 [Default:CheckIn] Running Loop=5
2020-01-30T19:20:18.038Z,1580412018.038 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-01-30T19:20:18.038Z,1580412018.038 [Default:CheckIn:Read_GPS] Running Loop=1
2020-01-30T19:20:20.039Z,1580412020.039 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,192015.00,A,3648.34659,N,12147.12134,W,5.287,2.54,300120,,,A*79
2020-01-30T19:20:20.054Z,1580412020.054 [NAL9602](INFO): GPS fix at 20200130T192015: (36.805777, -121.785356)
2020-01-30T19:20:20.078Z,1580412020.078 [Default:CheckIn:Read_GPS] Stopped
2020-01-30T19:20:20.078Z,1580412020.078 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-01-30T19:20:27.789Z,1580412027.789 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20200130T184551/Courier0016.lzma
2020-01-30T19:20:29.794Z,1580412029.794 [DataOverHttps](INFO): Moved sent file to Logs/20200130T184551/Courier0016.lzma.bak
2020-01-30T19:20:29.794Z,1580412029.794 [DataOverHttps](INFO): SBD MOMSN=12206450
2020-01-30T19:20:46.829Z,1580412046.829 [DataOverHttps](INFO): Sending 135 bytes from file Logs/20200130T184551/Express0017.lzma
2020-01-30T19:20:48.834Z,1580412048.834 [DataOverHttps](INFO): Moved sent file to Logs/20200130T184551/Express0017.lzma.bak
2020-01-30T19:20:48.834Z,1580412048.834 [DataOverHttps](INFO): SBD MOMSN=12206453
2020-01-30T19:20:49.953Z,1580412049.953 [Default:CheckIn:Read_Iridium] Stopped
2020-01-30T19:20:49.953Z,1580412049.953 [Default:CheckIn:C.Wait] Running Loop=1
2020-01-30T19:20:49.953Z,1580412049.953 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-01-30T19:22:22.859Z,1580412142.859 [NAL9602](INFO): SBD MO Status=2, MOMSN=18972, MT Status=2, MTMSN=0
2020-01-30T19:22:22.860Z,1580412142.860 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-01-30T19:22:55.995Z,1580412175.995 [NAL9602](INFO): SBD MO Status=2, MOMSN=18972, MT Status=2, MTMSN=0
2020-01-30T19:22:55.995Z,1580412175.995 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-01-30T19:23:06.515Z,1580412186.515 [NAL9602](INFO): SBD MO Status=0, MOMSN=18972, MT Status=0, MTMSN=0
2020-01-30T19:23:06.516Z,1580412186.516 [NAL9602](INFO): No messages in MT queue
2020-01-30T19:23:37.202Z,1580412217.202 [NAL9602](INFO): Not Powering down - fast GPS
2020-01-30T19:25:50.552Z,1580412350.552 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-01-30T19:25:50.552Z,1580412350.552 [Default:CheckIn:C.Wait] Stopped
2020-01-30T19:25:50.552Z,1580412350.552 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-01-30T19:25:50.552Z,1580412350.552 [Default:CheckIn:D] Running Loop=1
2020-01-30T19:25:50.965Z,1580412350.965 [Default:CheckIn:D] Stopped
2020-01-30T19:25:50.965Z,1580412350.965 [Default:CheckIn:E] Running Loop=1
2020-01-30T19:25:51.367Z,1580412351.367 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 36.251282 min 
2020-01-30T19:25:51.367Z,1580412351.367 [Default:CheckIn:E] Stopped
2020-01-30T19:25:51.367Z,1580412351.367 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-01-30T19:25:51.367Z,1580412351.367 [Default:CheckIn] Stopped
2020-01-30T19:25:51.367Z,1580412351.367 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-01-30T19:25:51.367Z,1580412351.367 [Default:CheckIn](INFO): Running loop #6
2020-01-30T19:25:51.367Z,1580412351.367 [Default:CheckIn] Running Loop=6
2020-01-30T19:25:51.368Z,1580412351.368 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-01-30T19:25:51.368Z,1580412351.368 [Default:CheckIn:Read_GPS] Running Loop=1
2020-01-30T19:25:53.360Z,1580412353.360 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,192548.00,A,3648.38368,N,12148.59670,W,24.201,279.00,300120,,,A*4A
2020-01-30T19:25:53.362Z,1580412353.362 [NAL9602](INFO): GPS fix at 20200130T192548: (36.806395, -121.809945)
2020-01-30T19:25:53.409Z,1580412353.409 [Default:CheckIn:Read_GPS] Stopped
2020-01-30T19:25:53.409Z,1580412353.409 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-01-30T19:26:01.201Z,1580412361.201 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20200130T184551/Courier0019.lzma
2020-01-30T19:26:03.206Z,1580412363.206 [DataOverHttps](INFO): Moved sent file to Logs/20200130T184551/Courier0019.lzma.bak
2020-01-30T19:26:03.206Z,1580412363.206 [DataOverHttps](INFO): SBD MOMSN=12206458
2020-01-30T19:26:20.181Z,1580412380.181 [DataOverHttps](INFO): Sending 135 bytes from file Logs/20200130T184551/Express0020.lzma
2020-01-30T19:26:22.186Z,1580412382.186 [DataOverHttps](INFO): Moved sent file to Logs/20200130T184551/Express0020.lzma.bak
2020-01-30T19:26:22.186Z,1580412382.186 [DataOverHttps](INFO): SBD MOMSN=12206461
2020-01-30T19:26:23.293Z,1580412383.293 [Default:CheckIn:Read_Iridium] Stopped
2020-01-30T19:26:23.293Z,1580412383.293 [Default:CheckIn:C.Wait] Running Loop=1
2020-01-30T19:26:23.293Z,1580412383.293 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-01-30T19:27:11.735Z,1580412431.735 [NAL9602](INFO): SBD MO Status=0, MOMSN=18973, MT Status=0, MTMSN=0
2020-01-30T19:27:11.736Z,1580412431.736 [NAL9602](INFO): No messages in MT queue
2020-01-30T19:27:42.435Z,1580412462.435 [NAL9602](INFO): Not Powering down - fast GPS
2020-01-30T19:31:23.892Z,1580412683.892 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-01-30T19:31:23.893Z,1580412683.893 [Default:CheckIn:C.Wait] Stopped
2020-01-30T19:31:23.893Z,1580412683.893 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-01-30T19:31:23.893Z,1580412683.893 [Default:CheckIn:D] Running Loop=1
2020-01-30T19:31:24.301Z,1580412684.301 [Default:CheckIn:D] Stopped
2020-01-30T19:31:24.301Z,1580412684.301 [Default:CheckIn:E] Running Loop=1
2020-01-30T19:31:24.707Z,1580412684.707 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 41.806877 min 
2020-01-30T19:31:24.707Z,1580412684.707 [Default:CheckIn:E] Stopped
2020-01-30T19:31:24.707Z,1580412684.707 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-01-30T19:31:24.707Z,1580412684.707 [Default:CheckIn] Stopped
2020-01-30T19:31:24.708Z,1580412684.708 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-01-30T19:31:24.708Z,1580412684.708 [Default:CheckIn](INFO): Running loop #7
2020-01-30T19:31:24.708Z,1580412684.708 [Default:CheckIn] Running Loop=7
2020-01-30T19:31:24.708Z,1580412684.708 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-01-30T19:31:24.708Z,1580412684.708 [Default:CheckIn:Read_GPS] Running Loop=1
2020-01-30T19:31:26.696Z,1580412686.696 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,193121.00,A,3648.41455,N,12150.15200,W,1.924,83.56,300120,,,A*4A
2020-01-30T19:31:26.698Z,1580412686.698 [NAL9602](INFO): GPS fix at 20200130T193121: (36.806909, -121.835867)
2020-01-30T19:31:26.744Z,1580412686.744 [Default:CheckIn:Read_GPS] Stopped
2020-01-30T19:31:26.744Z,1580412686.744 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-01-30T19:31:47.701Z,1580412707.701 [NAL9602](INFO): SBD MO Status=0, MOMSN=18974, MT Status=0, MTMSN=0
2020-01-30T19:31:47.701Z,1580412707.701 [NAL9602](INFO): No messages in MT queue
2020-01-30T19:31:58.350Z,1580412718.350 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2020-01-30T19:32:14.800Z,1580412734.800 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20200130T184551/Courier0022.lzma
2020-01-30T19:32:16.806Z,1580412736.806 [DataOverHttps](INFO): Moved sent file to Logs/20200130T184551/Courier0022.lzma.bak
2020-01-30T19:32:16.807Z,1580412736.807 [DataOverHttps](INFO): SBD MOMSN=12206465
2020-01-30T19:32:18.406Z,1580412738.406 [NAL9602](INFO): Not Powering down - fast GPS
2020-01-30T19:32:37.117Z,1580412757.117 [DataOverHttps](INFO): Sending 134 bytes from file Logs/20200130T184551/Express0023.lzma
2020-01-30T19:32:41.130Z,1580412761.130 [DataOverHttps](INFO): Moved sent file to Logs/20200130T184551/Express0023.lzma.bak
2020-01-30T19:32:41.131Z,1580412761.131 [DataOverHttps](INFO): SBD MOMSN=12206468
2020-01-30T19:32:42.293Z,1580412762.293 [Default:CheckIn:Read_Iridium] Stopped
2020-01-30T19:32:42.293Z,1580412762.293 [Default:CheckIn:C.Wait] Running Loop=1
2020-01-30T19:32:42.293Z,1580412762.293 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-01-30T19:34:22.274Z,1580412862.274 [DataOverHttps](IMPORTANT): SBD MTMSN=20200130T193415
2020-01-30T19:34:29.993Z,1580412869.993 [DataOverHttps](INFO): Received command:restart logs