2020-01-02T17:13:08.351Z,1577985188.351 [Supervisor](DEBUG): Initializing supervisor.
2020-01-02T17:13:08.354Z,1577985188.354 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2020-01-02T17:13:08.354Z,1577985188.354 [SyncHandler](INFO): Protected caller Thread ID is 809
2020-01-02T17:13:08.355Z,1577985188.355 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2020-01-02T17:13:08.356Z,1577985188.356 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2020-01-02T17:13:08.356Z,1577985188.356 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 810
2020-01-02T17:13:08.359Z,1577985188.359 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2020-01-02T17:13:08.370Z,1577985188.370 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2020-01-02T17:13:08.371Z,1577985188.371 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2020-01-02T17:13:08.371Z,1577985188.371 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 811
2020-01-02T17:13:08.372Z,1577985188.372 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2020-01-02T17:13:08.373Z,1577985188.373 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2020-01-02T17:13:08.373Z,1577985188.373 [logger ThreadHandler](INFO): Protected caller Thread ID is 812
2020-01-02T17:13:08.375Z,1577985188.375 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2020-01-02T17:13:08.375Z,1577985188.375 [Supervisor](INFO): Looking for Config files in directory: Config/
2020-01-02T17:13:08.380Z,1577985188.380 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2020-01-02T17:13:08.576Z,1577985188.576 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2020-01-02T17:13:08.578Z,1577985188.578 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2020-01-02T17:13:08.659Z,1577985188.659 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2020-01-02T17:13:09.095Z,1577985189.095 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2020-01-02T17:13:09.097Z,1577985189.097 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2020-01-02T17:13:09.414Z,1577985189.414 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2020-01-02T17:13:09.416Z,1577985189.416 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2020-01-02T17:13:09.512Z,1577985189.512 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2020-01-02T17:13:09.512Z,1577985189.512 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2020-01-02T17:13:09.802Z,1577985189.802 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2020-01-02T17:13:09.804Z,1577985189.804 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2020-01-02T17:13:09.994Z,1577985189.994 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2020-01-02T17:13:09.996Z,1577985189.996 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2020-01-02T17:13:10.448Z,1577985190.448 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2020-01-02T17:13:10.449Z,1577985190.449 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2020-01-02T17:13:10.551Z,1577985190.551 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2020-01-02T17:13:10.553Z,1577985190.553 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2020-01-02T17:13:10.653Z,1577985190.653 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2020-01-02T17:13:10.655Z,1577985190.655 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2020-01-02T17:13:11.280Z,1577985191.280 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2020-01-02T17:13:11.280Z,1577985191.280 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2020-01-02T17:13:12.394Z,1577985192.394 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2020-01-02T17:13:12.395Z,1577985192.395 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2020-01-02T17:13:12.590Z,1577985192.590 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2020-01-02T17:13:12.590Z,1577985192.590 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2020-01-02T17:13:12.733Z,1577985192.733 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2020-01-02T17:13:12.734Z,1577985192.734 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2020-01-02T17:13:12.884Z,1577985192.884 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2020-01-02T17:13:12.886Z,1577985192.886 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2020-01-02T17:13:12.889Z,1577985192.889 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2020-01-02T17:13:12.978Z,1577985192.978 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2020-01-02T17:13:13.063Z,1577985193.063 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2020-01-02T17:13:13.162Z,1577985193.162 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2020-01-02T17:13:13.245Z,1577985193.245 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2020-01-02T17:13:13.339Z,1577985193.339 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2020-01-02T17:13:13.439Z,1577985193.439 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2020-01-02T17:13:13.640Z,1577985193.640 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2020-01-02T17:13:13.716Z,1577985193.716 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2020-01-02T17:13:13.877Z,1577985193.877 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2020-01-02T17:13:14.020Z,1577985194.020 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2020-01-02T17:13:14.135Z,1577985194.135 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg
2020-01-02T17:13:14.358Z,1577985194.358 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2020-01-02T17:13:14.359Z,1577985194.359 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2020-01-02T17:13:14.372Z,1577985194.372 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2020-01-02T17:13:14.434Z,1577985194.434 [VerticalControl](DEBUG): Construct VerticalControl.
2020-01-02T17:13:14.544Z,1577985194.544 [VerticalControl] Loaded
2020-01-02T17:13:14.545Z,1577985194.545 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2020-01-02T17:13:14.545Z,1577985194.545 [HorizontalControl](DEBUG): Construct HorizontalControl.
2020-01-02T17:13:14.613Z,1577985194.613 [HorizontalControl] Loaded
2020-01-02T17:13:14.614Z,1577985194.614 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2020-01-02T17:13:14.614Z,1577985194.614 [SpeedControl](DEBUG): Construct SpeedControl.
2020-01-02T17:13:14.620Z,1577985194.620 [SpeedControl] Loaded
2020-01-02T17:13:14.620Z,1577985194.620 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2020-01-02T17:13:14.621Z,1577985194.621 [LoopControl](DEBUG): Construct LoopControl.
2020-01-02T17:13:14.621Z,1577985194.621 [LoopControl] Loaded
2020-01-02T17:13:14.621Z,1577985194.621 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2020-01-02T17:13:14.622Z,1577985194.622 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2020-01-02T17:13:14.624Z,1577985194.624 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2020-01-02T17:13:14.647Z,1577985194.647 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2020-01-02T17:13:14.648Z,1577985194.648 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2020-01-02T17:13:14.771Z,1577985194.771 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2020-01-02T17:13:14.772Z,1577985194.772 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2020-01-02T17:13:14.923Z,1577985194.923 [BuoyancyServo] Loaded
2020-01-02T17:13:14.923Z,1577985194.923 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2020-01-02T17:13:14.934Z,1577985194.934 [ElevatorServo] Loaded
2020-01-02T17:13:14.934Z,1577985194.934 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2020-01-02T17:13:14.945Z,1577985194.945 [MassServo] Loaded
2020-01-02T17:13:14.945Z,1577985194.945 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2020-01-02T17:13:14.956Z,1577985194.956 [RudderServo] Loaded
2020-01-02T17:13:14.956Z,1577985194.956 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2020-01-02T17:13:14.967Z,1577985194.967 [ThrusterServo] Loaded
2020-01-02T17:13:14.967Z,1577985194.967 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2020-01-02T17:13:14.968Z,1577985194.968 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2020-01-02T17:13:14.969Z,1577985194.969 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2020-01-02T17:13:15.091Z,1577985195.091 [DeadReckonUsingMultipleVelocitySources] Loaded
2020-01-02T17:13:15.092Z,1577985195.092 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2020-01-02T17:13:15.112Z,1577985195.112 [NavChart] Loaded
2020-01-02T17:13:15.112Z,1577985195.112 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2020-01-02T17:13:15.116Z,1577985195.116 [UniversalFixResidualReporter] Loaded
2020-01-02T17:13:15.116Z,1577985195.116 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2020-01-02T17:13:15.117Z,1577985195.117 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2020-01-02T17:13:15.117Z,1577985195.117 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2020-01-02T17:13:15.229Z,1577985195.229 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2020-01-02T17:13:15.230Z,1577985195.230 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2020-01-02T17:13:15.684Z,1577985195.684 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_orientation
2020-01-02T17:13:15.689Z,1577985195.689 [AHRS_M2](INFO): created writer for : platform_orientation
2020-01-02T17:13:15.691Z,1577985195.691 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_magnetic_orientation
2020-01-02T17:13:15.696Z,1577985195.696 [AHRS_M2](INFO): created writer for : platform_magnetic_orientation
2020-01-02T17:13:15.696Z,1577985195.696 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_pitch_angle
2020-01-02T17:13:15.701Z,1577985195.701 [AHRS_M2](INFO): created writer for : platform_pitch_angle
2020-01-02T17:13:15.702Z,1577985195.702 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_roll_angle
2020-01-02T17:13:15.707Z,1577985195.707 [AHRS_M2](INFO): created writer for : platform_roll_angle
2020-01-02T17:13:15.882Z,1577985195.882 [AHRS_M2] Loaded
2020-01-02T17:13:15.882Z,1577985195.882 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2020-01-02T17:13:16.029Z,1577985196.029 [DataOverHttps] Loaded
2020-01-02T17:13:16.030Z,1577985196.030 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2020-01-02T17:13:16.031Z,1577985196.031 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 408644E0
2020-01-02T17:13:16.031Z,1577985196.031 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 894
2020-01-02T17:13:16.045Z,1577985196.045 [Depth_Keller] Loaded
2020-01-02T17:13:16.045Z,1577985196.045 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2020-01-02T17:13:16.049Z,1577985196.049 [DropWeight] Loaded
2020-01-02T17:13:16.050Z,1577985196.050 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2020-01-02T17:13:16.143Z,1577985196.143 [NAL9602] Loaded
2020-01-02T17:13:16.144Z,1577985196.144 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2020-01-02T17:13:16.159Z,1577985196.159 [Onboard] Loaded
2020-01-02T17:13:16.159Z,1577985196.159 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2020-01-02T17:13:16.162Z,1577985196.162 [Radio_Surface] Loaded
2020-01-02T17:13:16.163Z,1577985196.163 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2020-01-02T17:13:16.164Z,1577985196.164 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408944E0
2020-01-02T17:13:16.164Z,1577985196.164 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 895
2020-01-02T17:13:18.392Z,1577985198.392 [BPC1] Loaded
2020-01-02T17:13:18.392Z,1577985198.392 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2020-01-02T17:13:18.392Z,1577985198.392 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2020-01-02T17:13:18.393Z,1577985198.393 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2020-01-02T17:13:18.447Z,1577985198.447 [DepthRateCalculator] Loaded
2020-01-02T17:13:18.447Z,1577985198.447 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2020-01-02T17:13:18.453Z,1577985198.453 [PitchRateCalculator] Loaded
2020-01-02T17:13:18.453Z,1577985198.453 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2020-01-02T17:13:18.464Z,1577985198.464 [SpeedCalculator] Loaded
2020-01-02T17:13:18.465Z,1577985198.465 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2020-01-02T17:13:18.485Z,1577985198.485 [TempGradientCalculator] Loaded
2020-01-02T17:13:18.486Z,1577985198.486 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2020-01-02T17:13:18.491Z,1577985198.491 [YawRateCalculator] Loaded
2020-01-02T17:13:18.491Z,1577985198.491 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2020-01-02T17:13:18.520Z,1577985198.520 [ElevatorOffsetCalculator] Loaded
2020-01-02T17:13:18.520Z,1577985198.520 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2020-01-02T17:13:18.521Z,1577985198.521 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2020-01-02T17:13:18.522Z,1577985198.522 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2020-01-02T17:13:18.779Z,1577985198.779 [CANONSampler] Loaded
2020-01-02T17:13:18.779Z,1577985198.779 [ComponentRegistry](DEBUG): SyncComponent "CANONSampler" handled in the control thread.
2020-01-02T17:13:18.788Z,1577985198.788 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density
2020-01-02T17:13:18.793Z,1577985198.793 [CTD_Seabird](INFO): created writer for : sea_water_density
2020-01-02T17:13:18.793Z,1577985198.793 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth
2020-01-02T17:13:18.798Z,1577985198.798 [CTD_Seabird](INFO): created writer for : depth
2020-01-02T17:13:18.799Z,1577985198.799 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure
2020-01-02T17:13:18.803Z,1577985198.803 [CTD_Seabird](INFO): created writer for : sea_water_pressure
2020-01-02T17:13:18.804Z,1577985198.804 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity
2020-01-02T17:13:18.809Z,1577985198.809 [CTD_Seabird](INFO): created writer for : sea_water_salinity
2020-01-02T17:13:18.810Z,1577985198.810 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature
2020-01-02T17:13:18.815Z,1577985198.815 [CTD_Seabird](INFO): created writer for : sea_water_temperature
2020-01-02T17:13:18.815Z,1577985198.815 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity
2020-01-02T17:13:18.821Z,1577985198.821 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity
2020-01-02T17:13:18.821Z,1577985198.821 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water
2020-01-02T17:13:18.826Z,1577985198.826 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water
2020-01-02T17:13:18.827Z,1577985198.827 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): mass_concentration_of_oxygen_in_sea_water
2020-01-02T17:13:18.832Z,1577985198.832 [CTD_Seabird](INFO): created writer for : mass_concentration_of_oxygen_in_sea_water
2020-01-02T17:13:18.832Z,1577985198.832 [CTD_Seabird](DEBUG): LcmSlateWriter::add(DAtaURI): CTD_Seabird.sea_water_dissolved_oxygen_freq
2020-01-02T17:13:18.833Z,1577985198.833 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): dataName: sea_water_dissolved_oxygen_freq
2020-01-02T17:13:18.864Z,1577985198.864 [CTD_Seabird] Loaded
2020-01-02T17:13:18.864Z,1577985198.864 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2020-01-02T17:13:18.865Z,1577985198.865 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 409964E0
2020-01-02T17:13:18.866Z,1577985198.866 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 896
2020-01-02T17:13:18.880Z,1577985198.880 [PAR_Licor] Loaded
2020-01-02T17:13:18.880Z,1577985198.880 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2020-01-02T17:13:18.886Z,1577985198.886 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output470
2020-01-02T17:13:18.886Z,1577985198.886 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output470
2020-01-02T17:13:18.891Z,1577985198.891 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output650
2020-01-02T17:13:18.891Z,1577985198.891 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output650
2020-01-02T17:13:18.895Z,1577985198.895 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.OutputChl
2020-01-02T17:13:18.895Z,1577985198.895 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: OutputChl
2020-01-02T17:13:18.900Z,1577985198.900 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg470nm
2020-01-02T17:13:18.900Z,1577985198.900 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg470nm
2020-01-02T17:13:18.904Z,1577985198.904 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg650nm
2020-01-02T17:13:18.904Z,1577985198.904 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg650nm
2020-01-02T17:13:18.909Z,1577985198.909 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff470nm
2020-01-02T17:13:18.909Z,1577985198.909 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff470nm
2020-01-02T17:13:18.913Z,1577985198.913 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff650nm
2020-01-02T17:13:18.913Z,1577985198.913 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff650nm
2020-01-02T17:13:18.917Z,1577985198.917 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): mass_concentration_of_chlorophyll_in_sea_water
2020-01-02T17:13:18.922Z,1577985198.922 [WetLabsBB2FL](INFO): created writer for : mass_concentration_of_chlorophyll_in_sea_water
2020-01-02T17:13:18.922Z,1577985198.922 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_median_mass_concentration_of_chlorophyll_in_sea_water
2020-01-02T17:13:18.922Z,1577985198.922 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_median_mass_concentration_of_chlorophyll_in_sea_water
2020-01-02T17:13:18.927Z,1577985198.927 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water
2020-01-02T17:13:18.927Z,1577985198.927 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_mean_mass_concentration_of_chlorophyll_in_sea_water
2020-01-02T17:13:18.931Z,1577985198.931 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_variance_mass_concentration_of_chlorophyll_in_sea_water
2020-01-02T17:13:18.931Z,1577985198.931 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_variance_mass_concentration_of_chlorophyll_in_sea_water
2020-01-02T17:13:18.935Z,1577985198.935 [WetLabsBB2FL] Loaded
2020-01-02T17:13:18.936Z,1577985198.936 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2020-01-02T17:13:18.937Z,1577985198.937 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 409C64E0
2020-01-02T17:13:18.937Z,1577985198.937 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 897
2020-01-02T17:13:18.938Z,1577985198.938 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2020-01-02T17:13:18.938Z,1577985198.938 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2020-01-02T17:13:18.986Z,1577985198.986 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2020-01-02T17:13:18.986Z,1577985198.986 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2020-01-02T17:13:19.319Z,1577985199.319 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2020-01-02T17:13:19.321Z,1577985199.321 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2020-01-02T17:13:19.481Z,1577985199.481 [SBIT](DEBUG): Construct Startup Built In Test.
2020-01-02T17:13:19.492Z,1577985199.492 [SBIT] Loaded
2020-01-02T17:13:19.492Z,1577985199.492 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2020-01-02T17:13:19.493Z,1577985199.493 [IBIT](DEBUG): Construct Initiated Built In Test.
2020-01-02T17:13:19.506Z,1577985199.506 [IBIT] Loaded
2020-01-02T17:13:19.506Z,1577985199.506 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2020-01-02T17:13:19.509Z,1577985199.509 [CBIT](DEBUG): Construct Continuous Built In Test.
2020-01-02T17:13:19.646Z,1577985199.646 [CBIT] Loaded
2020-01-02T17:13:19.646Z,1577985199.646 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2020-01-02T17:13:19.646Z,1577985199.646 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2020-01-02T17:13:19.650Z,1577985199.650 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2020-01-02T17:13:19.651Z,1577985199.651 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2020-01-02T17:13:19.657Z,1577985199.657 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2020-01-02T17:13:19.658Z,1577985199.658 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40AC54E0
2020-01-02T17:13:19.659Z,1577985199.659 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 898
2020-01-02T17:13:19.663Z,1577985199.663 [Supervisor](INFO): Main Thread ID is 805
2020-01-02T17:13:19.663Z,1577985199.663 [Supervisor](DEBUG): Running supervisor.
2020-01-02T17:13:19.664Z,1577985199.664 [CommandLine ThreadHandler](INFO): Handler Thread ID is 899
2020-01-02T17:13:19.666Z,1577985199.666 [controlThread ThreadHandler](INFO): Handler Thread ID is 900
2020-01-02T17:13:19.667Z,1577985199.667 [controlThread](DEBUG): Initializing ControlThread
2020-01-02T17:13:19.668Z,1577985199.668 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2020-01-02T17:13:19.669Z,1577985199.669 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2020-01-02T17:13:19.670Z,1577985199.670 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2020-01-02T17:13:19.670Z,1577985199.670 [LoopControl](DEBUG): Initialize LoopControlComponent.
2020-01-02T17:13:19.672Z,1577985199.672 [NavChart](DEBUG): Initialize NavChart Navigation.
2020-01-02T17:13:19.673Z,1577985199.673 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2020-01-02T17:13:19.679Z,1577985199.679 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2020-01-02T17:13:19.679Z,1577985199.679 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2020-01-02T17:13:19.679Z,1577985199.679 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2020-01-02T17:13:19.680Z,1577985199.680 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2020-01-02T17:13:19.680Z,1577985199.680 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2020-01-02T17:13:19.681Z,1577985199.681 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2020-01-02T17:13:19.685Z,1577985199.685 [SBIT](INFO): Initialize SBIT Component.
2020-01-02T17:13:19.686Z,1577985199.686 [SBIT](IMPORTANT): git: 2019-11-11
2020-01-02T17:13:19.686Z,1577985199.686 [SBIT](INFO): git hash: d323e2e841967a23cb7fd5209d5be46b38c2f2ac
2020-01-02T17:13:19.686Z,1577985199.686 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2020-01-02T17:13:19.687Z,1577985199.687 [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-02T17:13:19.688Z,1577985199.688 [SBIT](INFO): Beginning SBIT in 39.000000 seconds.
2020-01-02T17:13:19.689Z,1577985199.689 [logger ThreadHandler](INFO): Handler Thread ID is 901
2020-01-02T17:13:19.705Z,1577985199.705 [IBIT](INFO): Initialize IBIT Component.
2020-01-02T17:13:19.706Z,1577985199.706 [CBIT](DEBUG): Initialize CBIT Component.
2020-01-02T17:13:19.713Z,1577985199.713 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 902
2020-01-02T17:13:19.714Z,1577985199.714 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2020-01-02T17:13:19.717Z,1577985199.717 [CBIT](DEBUG): Initialized mux pins.
2020-01-02T17:13:19.717Z,1577985199.717 [CBIT](DEBUG): Initializing the watchdog timer.
2020-01-02T17:13:19.725Z,1577985199.725 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 903
2020-01-02T17:13:19.737Z,1577985199.737 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 904
2020-01-02T17:13:19.738Z,1577985199.738 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2020-01-02T17:13:19.741Z,1577985199.741 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2020-01-02T17:13:19.741Z,1577985199.741 [CBIT](DEBUG): Initializing heartbeat.
2020-01-02T17:13:19.742Z,1577985199.742 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20
2020-01-02T17:13:19.743Z,1577985199.743 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 906
2020-01-02T17:13:19.744Z,1577985199.744 [WetLabsBB2FL](INFO): Powering down
2020-01-02T17:13:19.785Z,1577985199.785 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 907
2020-01-02T17:13:19.813Z,1577985199.813 [CBIT](DEBUG): Deactivating GF circuits.
2020-01-02T17:13:19.813Z,1577985199.813 [CBIT](DEBUG): Deactivating emergency mode.
2020-01-02T17:13:19.880Z,1577985199.880 [CBIT](DEBUG): Backplane powered.
2020-01-02T17:13:19.881Z,1577985199.881 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2020-01-02T17:13:19.992Z,1577985199.992 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2020-01-02T17:13:19.992Z,1577985199.992 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2020-01-02T17:13:20.002Z,1577985200.002 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2020-01-02T17:13:20.005Z,1577985200.005 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2020-01-02T17:13:20.005Z,1577985200.005 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2020-01-02T17:13:20.005Z,1577985200.005 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2020-01-02T17:13:20.005Z,1577985200.005 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2020-01-02T17:13:20.005Z,1577985200.005 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2020-01-02T17:13:20.006Z,1577985200.006 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2020-01-02T17:13:20.006Z,1577985200.006 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2020-01-02T17:13:20.006Z,1577985200.006 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2020-01-02T17:13:20.006Z,1577985200.006 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2020-01-02T17:13:20.006Z,1577985200.006 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2020-01-02T17:13:20.007Z,1577985200.007 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2020-01-02T17:13:20.007Z,1577985200.007 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2020-01-02T17:13:20.007Z,1577985200.007 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2020-01-02T17:13:20.007Z,1577985200.007 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2020-01-02T17:13:20.109Z,1577985200.109 [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-02T17:13:20.111Z,1577985200.111 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2020-01-02T17:13:20.129Z,1577985200.129 [Radio_Surface](INFO): Powering up
2020-01-02T17:13:20.210Z,1577985200.210 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2020-01-02T17:13:20.211Z,1577985200.211 [Default:A.Wait](DEBUG): Construct Wait.
2020-01-02T17:13:20.225Z,1577985200.225 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2020-01-02T17:13:20.252Z,1577985200.252 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2020-01-02T17:13:20.275Z,1577985200.275 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2020-01-02T17:13:20.280Z,1577985200.280 [Default:E.Execute](DEBUG): Construct Execute.
2020-01-02T17:13:20.303Z,1577985200.303 [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-02T17:13:20.308Z,1577985200.308 [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-02T17:13:20.313Z,1577985200.313 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2020-01-02T17:13:20.432Z,1577985200.432 [Depth_Keller](ERROR): Pressure reading out of range: 1831.023193 decibar
2020-01-02T17:13:20.481Z,1577985200.481 [CANONSampler](INFO): Powering down
2020-01-02T17:13:20.527Z,1577985200.527 [DepthRateCalculator](ERROR): Depth measurement is not active
2020-01-02T17:13:20.561Z,1577985200.561 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2020-01-02T17:13:20.565Z,1577985200.565 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2020-01-02T17:13:20.566Z,1577985200.566 [ElevatorServo](DEBUG): Initializing EZServoServo.
2020-01-02T17:13:20.573Z,1577985200.573 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2020-01-02T17:13:20.574Z,1577985200.574 [MassServo](DEBUG): Initializing EZServoServo.
2020-01-02T17:13:20.581Z,1577985200.581 [MassServo](DEBUG): Initializing MassServo.
2020-01-02T17:13:20.582Z,1577985200.582 [RudderServo](DEBUG): Initializing EZServoServo.
2020-01-02T17:13:20.589Z,1577985200.589 [RudderServo](DEBUG): Initializing RudderServo.
2020-01-02T17:13:20.590Z,1577985200.590 [ThrusterServo](DEBUG): Initializing EZServoServo.
2020-01-02T17:13:20.597Z,1577985200.597 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2020-01-02T17:13:21.501Z,1577985201.501 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2020-01-02T17:13:21.501Z,1577985201.501 [RudderServo](FAULT): Rudder failed to initialize
2020-01-02T17:13:21.501Z,1577985201.501 [RudderServo] Communications Fault, FailCount= 1
2020-01-02T17:13:21.501Z,1577985201.501 [RudderServo](ERROR): Communications Fault
2020-01-02T17:13:21.660Z,1577985201.660 [CBIT](ERROR): Communications Fault in component: RudderServo
2020-01-02T17:13:21.866Z,1577985201.866 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2020-01-02T17:13:21.866Z,1577985201.866 [RudderServo](INFO): Powering down
2020-01-02T17:13:22.523Z,1577985202.523 [RudderServo](DEBUG): Initializing EZServoServo.
2020-01-02T17:13:22.642Z,1577985202.642 [RudderServo](DEBUG): Initializing RudderServo.
2020-01-02T17:13:22.646Z,1577985202.646 [CBIT](INFO): Clearing failed state for component RudderServo
2020-01-02T17:13:22.646Z,1577985202.646 [RudderServo] No Fault, FailCount= 1
2020-01-02T17:13:26.805Z,1577985206.805 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit.
2020-01-02T17:13:46.346Z,1577985226.346 [NAL9602](INFO): Powering up NAL9602
2020-01-02T17:13:57.254Z,1577985237.254 [NAL9602](INFO): NAL9602 initialized
2020-01-02T17:13:59.327Z,1577985239.327 [SBIT](IMPORTANT): Beginning Startup BIT
2020-01-02T17:13:59.335Z,1577985239.335 [CBIT](IMPORTANT): Beginning ground fault scan
2020-01-02T17:14:10.762Z,1577985250.762 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): -0.002544
CHAN A1 (24V): -0.180394
CHAN A2 (12V): -0.002135
CHAN A3 (5V): -0.001253
CHAN B0 (3.3V): -0.000051
CHAN B1 (3.15aV): 0.000222
CHAN B2 (3.15bV): -0.000585
CHAN B3 (GND): 0.000256
OPEN: -0.000527
Full Scale Calc: 4.765 mA, -1.589 mA
2020-01-02T17:14:52.679Z,1577985292.679 [SBIT](IMPORTANT): SBIT PASSED
2020-01-02T17:14:52.719Z,1577985292.719 [CommandLine](IMPORTANT): got command configSet list
2020-01-02T17:14:52.719Z,1577985292.719 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2020-01-02T17:14:52.720Z,1577985292.720 [CommandLine](IMPORTANT): CBIT.gf24Offset=154 microampere;

2020-01-02T17:14:52.720Z,1577985292.720 [CommandLine](IMPORTANT): CTD_NeilBrown.loadAtStartup=0 bool;

2020-01-02T17:14:52.720Z,1577985292.720 [CommandLine](IMPORTANT): CTD_Seabird.verbosity=0 count;

2020-01-02T17:14:52.720Z,1577985292.720 [CommandLine](IMPORTANT): DAT.loadAtStartup=0 bool;

2020-01-02T17:14:52.721Z,1577985292.721 [CommandLine](IMPORTANT): DVL_micro.loadAtStartup=0 bool;

2020-01-02T17:14:52.721Z,1577985292.721 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=438 cubic_centimeter;

2020-01-02T17:14:52.721Z,1577985292.721 [CommandLine](IMPORTANT): VerticalControl.massDefault=-5 millimeter;

2020-01-02T17:14:52.721Z,1577985292.721 [CommandLine](IMPORTANT): WetLabsUBAT.loadAtStartup=0 bool;

2020-01-02T17:14:53.080Z,1577985293.080 [MissionManager](IMPORTANT): Started mission Startup
2020-01-02T17:14:53.080Z,1577985293.080 [Startup] Running Loop=1
2020-01-02T17:14:53.080Z,1577985293.080 [Startup](DEBUG): Aggregate::initialize Startup
2020-01-02T17:14:53.080Z,1577985293.080 [Startup:A.GoToSurface] Running Loop=1
2020-01-02T17:14:53.080Z,1577985293.080 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-01-02T17:14:53.081Z,1577985293.081 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-01-02T17:14:53.082Z,1577985293.082 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-01-02T17:14:53.082Z,1577985293.082 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-01-02T17:14:53.082Z,1577985293.082 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-01-02T17:14:53.083Z,1577985293.083 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-01-02T17:14:53.084Z,1577985293.084 [Startup:StartupSatComms] Running Loop=1
2020-01-02T17:14:53.084Z,1577985293.084 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2020-01-02T17:14:53.084Z,1577985293.084 [Startup:StartupSatComms:A] Running Loop=1
2020-01-02T17:14:53.483Z,1577985293.483 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2020-01-02T17:15:52.907Z,1577985352.907 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.005013
2020-01-02T17:15:53.251Z,1577985353.251 [Startup:StartupSatComms:A](INFO): Timed out from 2020-01-02T17:14:53.1Z
2020-01-02T17:15:53.251Z,1577985353.251 [Startup:StartupSatComms:A] Stopped
2020-01-02T17:15:53.251Z,1577985353.251 [Startup:StartupSatComms:B] Running Loop=1
2020-01-02T17:15:53.663Z,1577985353.663 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2020-01-02T17:16:00.266Z,1577985360.266 [DataOverHttps](INFO): Sending 776 bytes from file Logs/20200102T171308/Express0001.lzma
2020-01-02T17:16:02.270Z,1577985362.270 [DataOverHttps](INFO): Moved sent file to Logs/20200102T171308/Express0001.lzma.bak
2020-01-02T17:16:02.271Z,1577985362.271 [DataOverHttps](INFO): SBD MOMSN=12183324
2020-01-02T17:16:03.355Z,1577985363.355 [Startup:StartupSatComms:B] Stopped
2020-01-02T17:16:03.355Z,1577985363.355 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2020-01-02T17:16:03.355Z,1577985363.355 [Startup:StartupSatComms] Stopped
2020-01-02T17:16:03.356Z,1577985363.356 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2020-01-02T17:16:03.356Z,1577985363.356 [Startup](INFO): Completed Startup
2020-01-02T17:16:03.356Z,1577985363.356 [MissionManager](INFO): Startup is completed.
2020-01-02T17:16:03.357Z,1577985363.357 [MissionManager](INFO): Uninitializing Mission Startup
2020-01-02T17:16:03.357Z,1577985363.357 [Startup] Stopped
2020-01-02T17:16:03.357Z,1577985363.357 [Startup](DEBUG): Aggregate::uninitialize Startup
2020-01-02T17:16:03.357Z,1577985363.357 [Startup:A.GoToSurface] Stopped
2020-01-02T17:16:03.357Z,1577985363.357 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2020-01-02T17:16:03.767Z,1577985363.767 [MissionManager](IMPORTANT): Started mission Default
2020-01-02T17:16:03.767Z,1577985363.767 [Default] Running Loop=1
2020-01-02T17:16:03.767Z,1577985363.767 [Default](DEBUG): Aggregate::initialize Default
2020-01-02T17:16:03.767Z,1577985363.767 [Default:B.GoToSurface] Running Loop=1
2020-01-02T17:16:03.767Z,1577985363.767 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-01-02T17:16:03.768Z,1577985363.768 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-01-02T17:16:03.768Z,1577985363.768 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-01-02T17:16:03.768Z,1577985363.768 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-01-02T17:16:03.773Z,1577985363.773 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-01-02T17:16:03.773Z,1577985363.773 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-01-02T17:16:03.773Z,1577985363.773 [Default:A.Wait] Running Loop=1
2020-01-02T17:16:03.773Z,1577985363.773 [Default:A.Wait](DEBUG): Initialize Wait Component.
2020-01-02T17:16:17.099Z,1577985377.099 [Default:A.Wait](INFO): Done Waiting.
2020-01-02T17:16:17.099Z,1577985377.099 [Default:A.Wait] Stopped
2020-01-02T17:16:17.099Z,1577985377.099 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2020-01-02T17:16:17.513Z,1577985377.513 [Default:CheckIn] Running Loop=1
2020-01-02T17:16:17.513Z,1577985377.513 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-01-02T17:16:17.513Z,1577985377.513 [Default:CheckIn:Read_GPS] Running Loop=1
2020-01-02T17:16:17.895Z,1577985377.895 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2020-01-02T17:16:19.926Z,1577985379.926 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2020-01-02T17:16:19.926Z,1577985379.926 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-01-02T17:16:19.935Z,1577985379.935 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-01-02T17:16:20.336Z,1577985380.336 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-01-02T17:16:20.336Z,1577985380.336 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2020-01-02T17:17:22.534Z,1577985442.534 [BPC1](ERROR): BPC1A: No match for serial number 1717 in BPC1A's battery stick inventory (sticks 1-32 in onboard configuration file).
2020-01-02T17:19:00.678Z,1577985540.678 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-01-02T17:19:20.914Z,1577985560.914 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2020-01-02T17:19:20.914Z,1577985560.914 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-01-02T17:19:20.924Z,1577985560.924 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-01-02T17:19:21.331Z,1577985561.331 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-01-02T17:19:21.331Z,1577985561.331 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2020-01-02T17:19:35.477Z,1577985575.477 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2020-01-02T17:19:35.481Z,1577985575.481 [BPC1](INFO): Received data from all battery sticks.
2020-01-02T17:20:53.071Z,1577985653.071 [CommandLine](IMPORTANT): got command burn on
2020-01-02T17:20:53.071Z,1577985653.071 [CommandLine](IMPORTANT): Activating dropweight wire
2020-01-02T17:20:58.127Z,1577985658.127 [CommandLine](IMPORTANT): got command burn off
2020-01-02T17:20:58.127Z,1577985658.127 [CommandLine](IMPORTANT): Deactivating dropweight wire
2020-01-02T17:21:17.670Z,1577985677.670 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-01-02T17:16:17.5Z
2020-01-02T17:21:17.670Z,1577985677.670 [Default:CheckIn:Read_GPS] Stopped
2020-01-02T17:21:17.670Z,1577985677.670 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-01-02T17:21:18.074Z,1577985678.074 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2020-01-02T17:21:25.304Z,1577985685.304 [DataOverHttps](INFO): Sending 187 bytes from file Logs/20200102T171308/Courier0004.lzma
2020-01-02T17:21:27.310Z,1577985687.310 [DataOverHttps](INFO): Moved sent file to Logs/20200102T171308/Courier0004.lzma.bak
2020-01-02T17:21:27.310Z,1577985687.310 [DataOverHttps](INFO): SBD MOMSN=12183346
2020-01-02T17:18:44.679Z,1577985524.679 [DataOverHttps](INFO): Sending 239 bytes from file Logs/20200102T171308/Express0005.lzma
2020-01-02T17:18:46.685Z,1577985526.685 [DataOverHttps](INFO): Moved sent file to Logs/20200102T171308/Express0005.lzma.bak
2020-01-02T17:18:46.685Z,1577985526.685 [DataOverHttps](INFO): SBD MOMSN=12183348
2020-01-02T17:18:47.864Z,1577985527.864 [Default:CheckIn:Read_Iridium] Stopped
2020-01-02T17:18:47.864Z,1577985527.864 [Default:CheckIn:C.Wait] Running Loop=1
2020-01-02T17:18:47.864Z,1577985527.864 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-01-02T17:22:21.969Z,1577985741.969 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2020-01-02T17:22:21.969Z,1577985741.969 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-01-02T17:22:21.980Z,1577985741.980 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-01-02T17:22:22.392Z,1577985742.392 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-01-02T17:22:22.392Z,1577985742.392 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2020-01-02T17:23:48.433Z,1577985828.433 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-01-02T17:23:48.434Z,1577985828.434 [Default:CheckIn:C.Wait] Stopped
2020-01-02T17:23:48.434Z,1577985828.434 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-01-02T17:23:48.434Z,1577985828.434 [Default:CheckIn:D] Running Loop=1
2020-01-02T17:23:48.838Z,1577985828.838 [Default:CheckIn:D] Stopped
2020-01-02T17:23:48.838Z,1577985828.838 [Default:CheckIn:E] Running Loop=1
2020-01-02T17:23:49.246Z,1577985829.246 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 7.751173 min 
2020-01-02T17:23:49.246Z,1577985829.246 [Default:CheckIn:E] Stopped
2020-01-02T17:23:49.247Z,1577985829.247 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-01-02T17:23:49.247Z,1577985829.247 [Default:CheckIn] Stopped
2020-01-02T17:23:49.247Z,1577985829.247 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-01-02T17:23:49.247Z,1577985829.247 [Default:CheckIn](INFO): Running loop #2
2020-01-02T17:23:49.247Z,1577985829.247 [Default:CheckIn] Running Loop=2
2020-01-02T17:23:49.247Z,1577985829.247 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-01-02T17:23:49.247Z,1577985829.247 [Default:CheckIn:Read_GPS] Running Loop=1
2020-01-02T17:23:58.506Z,1577985838.506 [NAL9602](FAULT): GPS failed to acquire within timeout.
2020-01-02T17:23:58.506Z,1577985838.506 [NAL9602] Data Fault, FailCount= 1
2020-01-02T17:23:58.506Z,1577985838.506 [NAL9602](ERROR): Data Fault
2020-01-02T17:23:58.542Z,1577985838.542 [CBIT](ERROR): Data Fault in component: NAL9602
2020-01-02T17:23:58.910Z,1577985838.910 [NAL9602](INFO): Powering down
2020-01-02T17:23:59.742Z,1577985839.742 [CBIT](INFO): Clearing failed state for component NAL9602
2020-01-02T17:23:59.743Z,1577985839.743 [NAL9602] No Fault, FailCount= 1
2020-01-02T17:24:29.209Z,1577985869.209 [NAL9602](INFO): Powering up NAL9602
2020-01-02T17:24:40.113Z,1577985880.113 [NAL9602](INFO): NAL9602 initialized
2020-01-02T17:25:22.977Z,1577985922.977 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2020-01-02T17:25:22.977Z,1577985922.977 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-01-02T17:25:23.012Z,1577985923.012 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-01-02T17:25:23.391Z,1577985923.391 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-01-02T17:25:23.391Z,1577985923.391 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2020-01-02T17:28:23.977Z,1577986103.977 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2020-01-02T17:28:23.977Z,1577986103.977 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-01-02T17:28:23.987Z,1577986103.987 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-01-02T17:28:24.386Z,1577986104.386 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-01-02T17:28:24.386Z,1577986104.386 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2020-01-02T17:28:49.430Z,1577986129.430 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-01-02T17:23:49.2Z
2020-01-02T17:28:49.430Z,1577986129.430 [Default:CheckIn:Read_GPS] Stopped
2020-01-02T17:28:49.430Z,1577986129.430 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-01-02T17:28:57.043Z,1577986137.043 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20200102T171308/Courier0007.lzma
2020-01-02T17:28:59.049Z,1577986139.049 [DataOverHttps](INFO): Moved sent file to Logs/20200102T171308/Courier0007.lzma.bak
2020-01-02T17:28:59.049Z,1577986139.049 [DataOverHttps](INFO): SBD MOMSN=12183356
2020-01-02T17:29:15.583Z,1577986155.583 [DataOverHttps](INFO): Sending 178 bytes from file Logs/20200102T171308/Express0008.lzma
2020-01-02T17:29:17.589Z,1577986157.589 [DataOverHttps](INFO): Moved sent file to Logs/20200102T171308/Express0008.lzma.bak
2020-01-02T17:29:17.589Z,1577986157.589 [DataOverHttps](INFO): SBD MOMSN=12183358
2020-01-02T17:29:18.901Z,1577986158.901 [Default:CheckIn:Read_Iridium] Stopped
2020-01-02T17:29:18.902Z,1577986158.902 [Default:CheckIn:C.Wait] Running Loop=1
2020-01-02T17:29:18.902Z,1577986158.902 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-01-02T17:31:24.996Z,1577986284.996 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6
2020-01-02T17:31:24.996Z,1577986284.996 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-01-02T17:31:25.010Z,1577986285.010 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-01-02T17:31:25.409Z,1577986285.409 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-01-02T17:31:25.409Z,1577986285.409 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6
2020-01-02T17:34:19.534Z,1577986459.534 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-01-02T17:34:19.534Z,1577986459.534 [Default:CheckIn:C.Wait] Stopped
2020-01-02T17:34:19.534Z,1577986459.534 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-01-02T17:34:19.534Z,1577986459.534 [Default:CheckIn:D] Running Loop=1
2020-01-02T17:34:19.946Z,1577986459.946 [Default:CheckIn:D] Stopped
2020-01-02T17:34:19.946Z,1577986459.946 [Default:CheckIn:E] Running Loop=1
2020-01-02T17:34:20.354Z,1577986460.354 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 18.269645 min 
2020-01-02T17:34:20.354Z,1577986460.354 [Default:CheckIn:E] Stopped
2020-01-02T17:34:20.354Z,1577986460.354 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-01-02T17:34:20.354Z,1577986460.354 [Default:CheckIn] Stopped
2020-01-02T17:34:20.354Z,1577986460.354 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-01-02T17:34:20.355Z,1577986460.355 [Default:CheckIn](INFO): Running loop #3
2020-01-02T17:34:20.355Z,1577986460.355 [Default:CheckIn] Running Loop=3
2020-01-02T17:34:20.355Z,1577986460.355 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-01-02T17:34:20.355Z,1577986460.355 [Default:CheckIn:Read_GPS] Running Loop=1
2020-01-02T17:34:26.027Z,1577986466.027 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7
2020-01-02T17:34:26.027Z,1577986466.027 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-01-02T17:34:26.061Z,1577986466.061 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-01-02T17:34:26.436Z,1577986466.436 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-01-02T17:34:26.437Z,1577986466.437 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7
2020-01-02T17:34:42.936Z,1577986482.936 [NAL9602](FAULT): GPS failed to acquire within timeout.
2020-01-02T17:34:42.936Z,1577986482.936 [NAL9602] Data Fault, FailCount= 2
2020-01-02T17:34:42.936Z,1577986482.936 [NAL9602](ERROR): Data Fault
2020-01-02T17:34:42.970Z,1577986482.970 [CBIT](ERROR): Data Fault in component: NAL9602
2020-01-02T17:34:43.333Z,1577986483.333 [NAL9602](INFO): Powering down
2020-01-02T17:34:44.174Z,1577986484.174 [CBIT](INFO): Clearing failed state for component NAL9602
2020-01-02T17:34:44.174Z,1577986484.174 [NAL9602] No Fault, FailCount= 2
2020-01-02T17:35:13.633Z,1577986513.633 [NAL9602](INFO): Powering up NAL9602
2020-01-02T17:35:24.545Z,1577986524.545 [NAL9602](INFO): NAL9602 initialized
2020-01-02T17:37:26.985Z,1577986646.985 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8
2020-01-02T17:37:26.985Z,1577986646.985 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-01-02T17:37:26.995Z,1577986646.995 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-01-02T17:37:27.456Z,1577986647.456 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-01-02T17:37:27.456Z,1577986647.456 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8
2020-01-02T17:38:59.887Z,1577986739.887 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173856.00,A,3648.17766,N,12147.28001,W,0.019,5.01,020120,,,A*7D
2020-01-02T17:38:59.890Z,1577986739.890 [NAL9602](INFO): GPS fix at 20200102T173856: (36.802961, -121.788000)
2020-01-02T17:39:00.059Z,1577986740.059 [Default:CheckIn:Read_GPS] Stopped
2020-01-02T17:39:00.059Z,1577986740.059 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-01-02T17:39:03.171Z,1577986743.171 [DataOverHttps](INFO): Sending 212 bytes from file Logs/20200102T171308/Courier0010.lzma
2020-01-02T17:39:05.177Z,1577986745.177 [DataOverHttps](INFO): Moved sent file to Logs/20200102T171308/Courier0010.lzma.bak
2020-01-02T17:39:05.177Z,1577986745.177 [DataOverHttps](INFO): SBD MOMSN=12183364
2020-01-02T17:39:22.368Z,1577986762.368 [DataOverHttps](INFO): Sending 280 bytes from file Logs/20200102T171308/Express0011.lzma
2020-01-02T17:39:24.373Z,1577986764.373 [DataOverHttps](INFO): Moved sent file to Logs/20200102T171308/Express0011.lzma.bak
2020-01-02T17:39:24.373Z,1577986764.373 [DataOverHttps](INFO): SBD MOMSN=12183367
2020-01-02T17:39:25.494Z,1577986765.494 [Default:CheckIn:Read_Iridium] Stopped
2020-01-02T17:39:25.494Z,1577986765.494 [Default:CheckIn:C.Wait] Running Loop=1
2020-01-02T17:39:25.494Z,1577986765.494 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-01-02T17:39:32.339Z,1577986772.339 [NAL9602](INFO): Not Powering down - fast GPS
2020-01-02T17:40:04.504Z,1577986804.504 [DataOverHttps](IMPORTANT): SBD MTMSN=20200102T174000
2020-01-02T17:40:12.016Z,1577986812.016 [DataOverHttps](INFO): Received command:ibit
2020-01-02T17:40:12.020Z,1577986812.020 [CommandLine](IMPORTANT): got command ibit
2020-01-02T17:40:12.368Z,1577986812.368 [IBIT](IMPORTANT): Beginning Initiated BIT
2020-01-02T17:40:12.368Z,1577986812.368 [IBIT](IMPORTANT): Beginning control surface checks.
2020-01-02T17:40:12.371Z,1577986812.371 [CBIT](IMPORTANT): Beginning ground fault scan
2020-01-02T17:40:13.946Z,1577986813.946 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174010.00,A,3648.17613,N,12147.27963,W,0.078,5.01,020120,,,A*76
2020-01-02T17:40:13.949Z,1577986813.949 [NAL9602](INFO): GPS fix at 20200102T174010: (36.802935, -121.787994)
2020-01-02T17:40:23.271Z,1577986823.271 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): -0.008749
CHAN A1 (24V): -0.180796
CHAN A2 (12V): -0.001706
CHAN A3 (5V): -0.001348
CHAN B0 (3.3V): -0.000057
CHAN B1 (3.15aV): -0.000139
CHAN B2 (3.15bV): -0.000343
CHAN B3 (GND): 0.000338
OPEN: -0.000214
Full Scale Calc: 4.765 mA, -1.589 mA
2020-01-02T17:41:57.415Z,1577986917.415 [IBIT](IMPORTANT): Communications Status:
Fix Status: 1
Iridium Signal Strength: 1
Latitude: 36.802937 Longitude: -121.787994
2020-01-02T17:41:57.824Z,1577986917.824 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 0.000000
Voltage: 0.000000
2020-01-02T17:41:57.825Z,1577986917.825 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah
2020-01-02T17:41:57.825Z,1577986917.825 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V
2020-01-02T17:41:58.197Z,1577986918.197 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2020-01-02T17:41:58.198Z,1577986918.198 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2020-01-02T17:41:58.198Z,1577986918.198 [IBIT](IMPORTANT): Pressure:8.104965 PSI
2020-01-02T17:41:58.198Z,1577986918.198 [IBIT](IMPORTANT): Humidity:8.472714 %
2020-01-02T17:41:58.617Z,1577986918.617 [IBIT](IMPORTANT): Vehicle Pitch:0.066137 degrees
2020-01-02T17:41:58.617Z,1577986918.617 [IBIT](IMPORTANT): Vehicle  Roll:5.449394 degrees
2020-01-02T17:41:58.617Z,1577986918.617 [IBIT](IMPORTANT): Vehicle  Heading:246.569916 degrees
2020-01-02T17:41:59.024Z,1577986919.024 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2020-01-02T17:41:59.024Z,1577986919.024 [IBIT](IMPORTANT): buoyancyNeutral: 438.000000 cc
2020-01-02T17:41:59.025Z,1577986919.025 [IBIT](IMPORTANT): massDefault: -0.500000 cm
2020-01-02T17:41:59.025Z,1577986919.025 [IBIT](IMPORTANT): stopDepth: 205.000000 m
2020-01-02T17:41:59.025Z,1577986919.025 [IBIT](IMPORTANT): abortDepth: 250.000000 m
2020-01-02T17:41:59.025Z,1577986919.025 [IBIT](IMPORTANT): IBIT PASSED
2020-01-02T17:42:33.322Z,1577986953.322 [NAL9602](INFO): SBD MO Status=2, MOMSN=18397, MT Status=2, MTMSN=0
2020-01-02T17:42:33.322Z,1577986953.322 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-01-02T17:44:10.686Z,1577987050.686 [NAL9602](INFO): SBD MO Status=2, MOMSN=18397, MT Status=2, MTMSN=0
2020-01-02T17:44:10.686Z,1577987050.686 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-01-02T17:44:26.075Z,1577987066.075 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-01-02T17:44:26.075Z,1577987066.075 [Default:CheckIn:C.Wait] Stopped
2020-01-02T17:44:26.075Z,1577987066.075 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-01-02T17:44:26.075Z,1577987066.075 [Default:CheckIn:D] Running Loop=1
2020-01-02T17:44:26.479Z,1577987066.479 [Default:CheckIn:D] Stopped
2020-01-02T17:44:26.480Z,1577987066.480 [Default:CheckIn:E] Running Loop=1
2020-01-02T17:44:26.896Z,1577987066.896 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 28.378538 min 
2020-01-02T17:44:26.896Z,1577987066.896 [Default:CheckIn:E] Stopped
2020-01-02T17:44:26.896Z,1577987066.896 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-01-02T17:44:26.896Z,1577987066.896 [Default:CheckIn] Stopped
2020-01-02T17:44:26.897Z,1577987066.897 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-01-02T17:44:26.897Z,1577987066.897 [Default:CheckIn](INFO): Running loop #4
2020-01-02T17:44:26.897Z,1577987066.897 [Default:CheckIn] Running Loop=4
2020-01-02T17:44:26.897Z,1577987066.897 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-01-02T17:44:26.897Z,1577987066.897 [Default:CheckIn:Read_GPS] Running Loop=1
2020-01-02T17:44:40.989Z,1577987080.989 [NAL9602](INFO): SBD MO Status=2, MOMSN=18397, MT Status=2, MTMSN=0
2020-01-02T17:44:40.989Z,1577987080.989 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-01-02T17:45:16.129Z,1577987116.129 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-01-02T17:45:20.578Z,1577987120.578 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174517.00,A,3648.15109,N,12147.21926,W,1.380,24.11,020120,,,A*4A
2020-01-02T17:45:20.581Z,1577987120.581 [NAL9602](INFO): GPS fix at 20200102T174517: (36.802518, -121.786988)
2020-01-02T17:45:20.628Z,1577987120.628 [Default:CheckIn:Read_GPS] Stopped
2020-01-02T17:45:20.628Z,1577987120.628 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-01-02T17:45:28.335Z,1577987128.335 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20200102T171308/Courier0013.lzma
2020-01-02T17:45:30.341Z,1577987130.341 [DataOverHttps](INFO): Moved sent file to Logs/20200102T171308/Courier0013.lzma.bak
2020-01-02T17:45:30.341Z,1577987130.341 [DataOverHttps](INFO): SBD MOMSN=12183374
2020-01-02T17:45:47.291Z,1577987147.291 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20200102T171308/Courier0016.lzma
2020-01-02T17:45:49.297Z,1577987149.297 [DataOverHttps](INFO): Moved sent file to Logs/20200102T171308/Courier0016.lzma.bak
2020-01-02T17:45:49.297Z,1577987149.297 [DataOverHttps](INFO): SBD MOMSN=12183377
2020-01-02T17:45:52.892Z,1577987152.892 [NAL9602](INFO): Not Powering down - fast GPS
2020-01-02T17:46:09.620Z,1577987169.620 [DataOverHttps](INFO): Sending 877 bytes from file Logs/20200102T171308/Express0014.lzma
2020-01-02T17:46:11.625Z,1577987171.625 [DataOverHttps](INFO): Moved sent file to Logs/20200102T171308/Express0014.lzma.bak
2020-01-02T17:46:11.626Z,1577987171.626 [DataOverHttps](INFO): SBD MOMSN=12183379
2020-01-02T17:46:28.607Z,1577987188.607 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20200102T171308/Express0017.lzma
2020-01-02T17:46:30.617Z,1577987190.617 [DataOverHttps](INFO): Moved sent file to Logs/20200102T171308/Express0017.lzma.bak
2020-01-02T17:46:30.617Z,1577987190.617 [DataOverHttps](INFO): SBD MOMSN=12183406
2020-01-02T17:46:31.735Z,1577987191.735 [Default:CheckIn:Read_Iridium] Stopped
2020-01-02T17:46:31.735Z,1577987191.735 [Default:CheckIn:C.Wait] Running Loop=1
2020-01-02T17:46:31.735Z,1577987191.735 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-01-02T17:51:32.308Z,1577987492.308 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-01-02T17:51:32.308Z,1577987492.308 [Default:CheckIn:C.Wait] Stopped
2020-01-02T17:51:32.308Z,1577987492.308 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-01-02T17:51:32.308Z,1577987492.308 [Default:CheckIn:D] Running Loop=1
2020-01-02T17:51:32.724Z,1577987492.724 [Default:CheckIn:D] Stopped
2020-01-02T17:51:32.724Z,1577987492.724 [Default:CheckIn:E] Running Loop=1
2020-01-02T17:51:33.128Z,1577987493.128 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 35.482613 min 
2020-01-02T17:51:33.128Z,1577987493.128 [Default:CheckIn:E] Stopped
2020-01-02T17:51:33.128Z,1577987493.128 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-01-02T17:51:33.128Z,1577987493.128 [Default:CheckIn] Stopped
2020-01-02T17:51:33.128Z,1577987493.128 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-01-02T17:51:33.129Z,1577987493.129 [Default:CheckIn](INFO): Running loop #5
2020-01-02T17:51:33.129Z,1577987493.129 [Default:CheckIn] Running Loop=5
2020-01-02T17:51:33.129Z,1577987493.129 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-01-02T17:51:33.129Z,1577987493.129 [Default:CheckIn:Read_GPS] Running Loop=1
2020-01-02T17:51:35.118Z,1577987495.118 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175131.00,A,3648.16633,N,12147.21523,W,0.078,17.22,020120,,,A*4A
2020-01-02T17:51:35.121Z,1577987495.121 [NAL9602](INFO): GPS fix at 20200102T175131: (36.802772, -121.786920)
2020-01-02T17:51:35.172Z,1577987495.172 [Default:CheckIn:Read_GPS] Stopped
2020-01-02T17:51:35.172Z,1577987495.172 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-01-02T17:51:43.051Z,1577987503.051 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20200102T171308/Courier0019.lzma
2020-01-02T17:51:45.057Z,1577987505.057 [DataOverHttps](INFO): Moved sent file to Logs/20200102T171308/Courier0019.lzma.bak
2020-01-02T17:51:45.057Z,1577987505.057 [DataOverHttps](INFO): SBD MOMSN=12183408
2020-01-02T17:52:02.075Z,1577987522.075 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20200102T171308/Express0020.lzma
2020-01-02T17:52:04.081Z,1577987524.081 [DataOverHttps](INFO): Moved sent file to Logs/20200102T171308/Express0020.lzma.bak
2020-01-02T17:52:04.081Z,1577987524.081 [DataOverHttps](INFO): SBD MOMSN=12183411
2020-01-02T17:52:05.440Z,1577987525.440 [Default:CheckIn:Read_Iridium] Stopped
2020-01-02T17:52:05.440Z,1577987525.440 [Default:CheckIn:C.Wait] Running Loop=1
2020-01-02T17:52:05.440Z,1577987525.440 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-01-02T17:52:05.817Z,1577987525.817 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2020-01-02T17:52:05.892Z,1577987525.892 [NAL9602](FAULT): received: 
+CSQ:0

OK397, 2, 0, 0, 0

OK
2020-01-02T17:52:05.892Z,1577987525.892 [NAL9602] Data Fault, FailCount= 3
2020-01-02T17:52:05.892Z,1577987525.892 [NAL9602](ERROR): Data Fault
2020-01-02T17:52:05.956Z,1577987525.956 [CBIT](ERROR): Data Fault in component: NAL9602
2020-01-02T17:52:06.221Z,1577987526.221 [NAL9602](INFO): Powering down
2020-01-02T17:52:07.063Z,1577987527.063 [CBIT](INFO): Clearing failed state for component NAL9602
2020-01-02T17:52:07.063Z,1577987527.063 [NAL9602] No Fault, FailCount= 3
2020-01-02T17:52:36.525Z,1577987556.525 [NAL9602](INFO): Powering up NAL9602
2020-01-02T17:52:47.429Z,1577987567.429 [NAL9602](INFO): NAL9602 initialized
2020-01-02T17:53:18.540Z,1577987598.540 [NAL9602](INFO): Not Powering down - fast GPS
2020-01-02T17:57:06.028Z,1577987826.028 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-01-02T17:57:06.028Z,1577987826.028 [Default:CheckIn:C.Wait] Stopped
2020-01-02T17:57:06.028Z,1577987826.028 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-01-02T17:57:06.028Z,1577987826.028 [Default:CheckIn:D] Running Loop=1
2020-01-02T17:57:06.426Z,1577987826.426 [Default:CheckIn:D] Stopped
2020-01-02T17:57:06.426Z,1577987826.426 [Default:CheckIn:E] Running Loop=1
2020-01-02T17:57:06.838Z,1577987826.838 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 41.044307 min 
2020-01-02T17:57:06.838Z,1577987826.838 [Default:CheckIn:E] Stopped
2020-01-02T17:57:06.838Z,1577987826.838 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-01-02T17:57:06.838Z,1577987826.838 [Default:CheckIn] Stopped
2020-01-02T17:57:06.838Z,1577987826.838 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-01-02T17:57:06.838Z,1577987826.838 [Default:CheckIn](INFO): Running loop #6
2020-01-02T17:57:06.838Z,1577987826.838 [Default:CheckIn] Running Loop=6
2020-01-02T17:57:06.838Z,1577987826.838 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-01-02T17:57:06.839Z,1577987826.839 [Default:CheckIn:Read_GPS] Running Loop=1
2020-01-02T17:57:08.825Z,1577987828.825 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175704.00,A,3648.17232,N,12147.19740,W,2.002,17.33,020120,,,A*4D
2020-01-02T17:57:08.827Z,1577987828.827 [NAL9602](INFO): GPS fix at 20200102T175704: (36.802872, -121.786623)
2020-01-02T17:57:08.851Z,1577987828.851 [Default:CheckIn:Read_GPS] Stopped
2020-01-02T17:57:08.851Z,1577987828.851 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-01-02T17:57:10.835Z,1577987830.835 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-01-02T17:57:16.563Z,1577987836.563 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20200102T171308/Courier0022.lzma
2020-01-02T17:57:18.569Z,1577987838.569 [DataOverHttps](INFO): Moved sent file to Logs/20200102T171308/Courier0022.lzma.bak
2020-01-02T17:57:18.569Z,1577987838.569 [DataOverHttps](INFO): SBD MOMSN=12183414
2020-01-02T17:57:35.475Z,1577987855.475 [DataOverHttps](INFO): Sending 177 bytes from file Logs/20200102T171308/Express0023.lzma
2020-01-02T17:57:37.481Z,1577987857.481 [DataOverHttps](INFO): Moved sent file to Logs/20200102T171308/Express0023.lzma.bak
2020-01-02T17:57:37.481Z,1577987857.481 [DataOverHttps](INFO): SBD MOMSN=12183417
2020-01-02T17:57:38.752Z,1577987858.752 [Default:CheckIn:Read_Iridium] Stopped
2020-01-02T17:57:38.752Z,1577987858.752 [Default:CheckIn:C.Wait] Running Loop=1
2020-01-02T17:57:38.752Z,1577987858.752 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-01-02T17:57:41.540Z,1577987861.540 [NAL9602](INFO): Not Powering down - fast GPS
2020-01-02T18:02:39.331Z,1577988159.331 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-01-02T18:02:39.331Z,1577988159.331 [Default:CheckIn:C.Wait] Stopped
2020-01-02T18:02:39.331Z,1577988159.331 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-01-02T18:02:39.331Z,1577988159.331 [Default:CheckIn:D] Running Loop=1
2020-01-02T18:02:39.743Z,1577988159.743 [Default:CheckIn:D] Stopped
2020-01-02T18:02:39.743Z,1577988159.743 [Default:CheckIn:E] Running Loop=1
2020-01-02T18:02:40.121Z,1577988160.121 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 46.599337 min 
2020-01-02T18:02:40.121Z,1577988160.121 [Default:CheckIn:E] Stopped
2020-01-02T18:02:40.121Z,1577988160.121 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-01-02T18:02:40.121Z,1577988160.121 [Default:CheckIn] Stopped
2020-01-02T18:02:40.121Z,1577988160.121 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-01-02T18:02:40.121Z,1577988160.121 [Default:CheckIn](INFO): Running loop #7
2020-01-02T18:02:40.121Z,1577988160.121 [Default:CheckIn] Running Loop=7
2020-01-02T18:02:40.121Z,1577988160.121 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-01-02T18:02:40.122Z,1577988160.122 [Default:CheckIn:Read_GPS] Running Loop=1
2020-01-02T18:02:42.119Z,1577988162.119 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180237.00,A,3648.50131,N,12147.23157,W,9.855,245.10,020120,,,A*7D
2020-01-02T18:02:42.132Z,1577988162.132 [NAL9602](INFO): GPS fix at 20200102T180237: (36.808355, -121.787193)
2020-01-02T18:02:42.155Z,1577988162.155 [Default:CheckIn:Read_GPS] Stopped
2020-01-02T18:02:42.155Z,1577988162.155 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-01-02T18:02:49.115Z,1577988169.115 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20200102T171308/Courier0025.lzma
2020-01-02T18:02:51.121Z,1577988171.121 [DataOverHttps](INFO): Moved sent file to Logs/20200102T171308/Courier0025.lzma.bak
2020-01-02T18:02:51.121Z,1577988171.121 [DataOverHttps](INFO): SBD MOMSN=12183421
2020-01-02T18:03:08.115Z,1577988188.115 [DataOverHttps](INFO): Sending 212 bytes from file Logs/20200102T171308/Express0026.lzma
2020-01-02T18:03:10.121Z,1577988190.121 [DataOverHttps](INFO): Moved sent file to Logs/20200102T171308/Express0026.lzma.bak
2020-01-02T18:03:10.121Z,1577988190.121 [DataOverHttps](INFO): SBD MOMSN=12183424
2020-01-02T18:03:11.242Z,1577988191.242 [Default:CheckIn:Read_Iridium] Stopped
2020-01-02T18:03:11.242Z,1577988191.242 [Default:CheckIn:C.Wait] Running Loop=1
2020-01-02T18:03:11.242Z,1577988191.242 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-01-02T18:03:40.702Z,1577988220.702 [NAL9602](INFO): SBD MO Status=0, MOMSN=18397, MT Status=0, MTMSN=0
2020-01-02T18:03:40.702Z,1577988220.702 [NAL9602](INFO): No messages in MT queue
2020-01-02T18:04:11.404Z,1577988251.404 [NAL9602](INFO): Not Powering down - fast GPS
2020-01-02T18:08:11.807Z,1577988491.807 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-01-02T18:08:11.807Z,1577988491.807 [Default:CheckIn:C.Wait] Stopped
2020-01-02T18:08:11.807Z,1577988491.807 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-01-02T18:08:11.807Z,1577988491.807 [Default:CheckIn:D] Running Loop=1
2020-01-02T18:08:12.215Z,1577988492.215 [Default:CheckIn:D] Stopped
2020-01-02T18:08:12.216Z,1577988492.216 [Default:CheckIn:E] Running Loop=1
2020-01-02T18:08:12.621Z,1577988492.621 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 52.140804 min 
2020-01-02T18:08:12.621Z,1577988492.621 [Default:CheckIn:E] Stopped
2020-01-02T18:08:12.621Z,1577988492.621 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-01-02T18:08:12.621Z,1577988492.621 [Default:CheckIn] Stopped
2020-01-02T18:08:12.621Z,1577988492.621 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-01-02T18:08:12.621Z,1577988492.621 [Default:CheckIn](INFO): Running loop #8
2020-01-02T18:08:12.621Z,1577988492.621 [Default:CheckIn] Running Loop=8
2020-01-02T18:08:12.621Z,1577988492.621 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-01-02T18:08:12.621Z,1577988492.621 [Default:CheckIn:Read_GPS] Running Loop=1
2020-01-02T18:08:14.611Z,1577988494.611 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180809.00,A,3648.26883,N,12148.58027,W,15.065,267.72,020120,,,A*4C
2020-01-02T18:08:14.613Z,1577988494.613 [NAL9602](INFO): GPS fix at 20200102T180809: (36.804480, -121.809671)
2020-01-02T18:08:14.661Z,1577988494.661 [Default:CheckIn:Read_GPS] Stopped
2020-01-02T18:08:14.661Z,1577988494.661 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-01-02T18:08:22.199Z,1577988502.199 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20200102T171308/Courier0028.lzma
2020-01-02T18:08:24.205Z,1577988504.205 [DataOverHttps](INFO): Moved sent file to Logs/20200102T171308/Courier0028.lzma.bak
2020-01-02T18:08:24.205Z,1577988504.205 [DataOverHttps](INFO): SBD MOMSN=12183430
2020-01-02T18:08:41.199Z,1577988521.199 [DataOverHttps](INFO): Sending 135 bytes from file Logs/20200102T171308/Express0029.lzma
2020-01-02T18:08:43.205Z,1577988523.205 [DataOverHttps](INFO): Moved sent file to Logs/20200102T171308/Express0029.lzma.bak
2020-01-02T18:08:43.205Z,1577988523.205 [DataOverHttps](INFO): SBD MOMSN=12183433
2020-01-02T18:08:44.556Z,1577988524.556 [Default:CheckIn:Read_Iridium] Stopped
2020-01-02T18:08:44.556Z,1577988524.556 [Default:CheckIn:C.Wait] Running Loop=1
2020-01-02T18:08:44.556Z,1577988524.556 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-01-02T18:09:31.774Z,1577988571.774 [NAL9602](INFO): SBD MO Status=2, MOMSN=18398, MT Status=2, MTMSN=0
2020-01-02T18:09:31.774Z,1577988571.774 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-01-02T18:09:49.554Z,1577988589.554 [NAL9602](INFO): SBD MO Status=0, MOMSN=18398, MT Status=0, MTMSN=0
2020-01-02T18:09:49.554Z,1577988589.554 [NAL9602](INFO): No messages in MT queue
2020-01-02T18:10:20.252Z,1577988620.252 [NAL9602](INFO): Not Powering down - fast GPS
2020-01-02T18:11:17.616Z,1577988677.616 [DataOverHttps](INFO): Exceeded connection timeout, disconnecting.
2020-01-02T18:11:48.742Z,1577988708.742 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2020-01-02T18:12:19.864Z,1577988739.864 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2020-01-02T18:12:50.988Z,1577988770.988 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2020-01-02T18:13:45.123Z,1577988825.123 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-01-02T18:13:45.123Z,1577988825.123 [Default:CheckIn:C.Wait] Stopped
2020-01-02T18:13:45.124Z,1577988825.124 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-01-02T18:13:45.124Z,1577988825.124 [Default:CheckIn:D] Running Loop=1
2020-01-02T18:13:45.519Z,1577988825.519 [Default:CheckIn:D] Stopped
2020-01-02T18:13:45.520Z,1577988825.520 [Default:CheckIn:E] Running Loop=1
2020-01-02T18:13:45.919Z,1577988825.919 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 57.695870 min 
2020-01-02T18:13:45.919Z,1577988825.919 [Default:CheckIn:E] Stopped
2020-01-02T18:13:45.919Z,1577988825.919 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-01-02T18:13:45.919Z,1577988825.919 [Default:CheckIn] Stopped
2020-01-02T18:13:45.919Z,1577988825.919 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-01-02T18:13:45.919Z,1577988825.919 [Default:CheckIn](INFO): Running loop #9
2020-01-02T18:13:45.920Z,1577988825.920 [Default:CheckIn] Running Loop=9
2020-01-02T18:13:45.920Z,1577988825.920 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-01-02T18:13:45.920Z,1577988825.920 [Default:CheckIn:Read_GPS] Running Loop=1
2020-01-02T18:13:47.911Z,1577988827.911 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181342.00,A,3648.35985,N,12149.42054,W,0.311,294.54,020120,,,A*7E
2020-01-02T18:13:47.913Z,1577988827.913 [NAL9602](INFO): GPS fix at 20200102T181342: (36.805997, -121.823676)
2020-01-02T18:13:47.961Z,1577988827.961 [Default:CheckIn:Read_GPS] Stopped
2020-01-02T18:13:47.961Z,1577988827.961 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-01-02T18:14:37.198Z,1577988877.198 [NAL9602](INFO): SBD MO Status=2, MOMSN=18399, MT Status=2, MTMSN=0
2020-01-02T18:14:37.198Z,1577988877.198 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-01-02T18:14:46.894Z,1577988886.894 [NAL9602](INFO): SBD MO Status=0, MOMSN=18399, MT Status=0, MTMSN=0
2020-01-02T18:14:46.894Z,1577988886.894 [NAL9602](INFO): No messages in MT queue
2020-01-02T18:14:50.972Z,1577988890.972 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2020-01-02T18:15:17.600Z,1577988917.600 [NAL9602](INFO): Not Powering down - fast GPS
2020-01-02T18:15:22.096Z,1577988922.096 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2020-01-02T18:15:29.767Z,1577988929.767 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20200102T171308/Courier0031.lzma
2020-01-02T18:15:31.773Z,1577988931.773 [DataOverHttps](INFO): Moved sent file to Logs/20200102T171308/Courier0031.lzma.bak
2020-01-02T18:15:31.774Z,1577988931.774 [DataOverHttps](IMPORTANT): SBD MOMSN=12183440, MTMSN=20200102T181524