2020-08-28T14:02:41.441Z,1598623361.441 [Supervisor](DEBUG): Initializing supervisor.
2020-08-28T14:02:41.444Z,1598623361.444 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2020-08-28T14:02:41.444Z,1598623361.444 [SyncHandler](INFO): Protected caller Thread ID is 821
2020-08-28T14:02:41.445Z,1598623361.445 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2020-08-28T14:02:41.446Z,1598623361.446 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2020-08-28T14:02:41.446Z,1598623361.446 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 822
2020-08-28T14:02:41.449Z,1598623361.449 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2020-08-28T14:02:41.462Z,1598623361.462 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2020-08-28T14:02:41.463Z,1598623361.463 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2020-08-28T14:02:41.463Z,1598623361.463 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 823
2020-08-28T14:02:41.464Z,1598623361.464 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2020-08-28T14:02:41.465Z,1598623361.465 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2020-08-28T14:02:41.465Z,1598623361.465 [logger ThreadHandler](INFO): Protected caller Thread ID is 824
2020-08-28T14:02:41.467Z,1598623361.467 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2020-08-28T14:02:41.468Z,1598623361.468 [Supervisor](INFO): Looking for Config files in directory: Config/
2020-08-28T14:02:41.472Z,1598623361.472 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2020-08-28T14:02:41.679Z,1598623361.679 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2020-08-28T14:02:41.681Z,1598623361.681 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2020-08-28T14:02:41.762Z,1598623361.762 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2020-08-28T14:02:42.198Z,1598623362.198 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2020-08-28T14:02:42.200Z,1598623362.200 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2020-08-28T14:02:42.537Z,1598623362.537 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2020-08-28T14:02:42.539Z,1598623362.539 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2020-08-28T14:02:42.635Z,1598623362.635 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2020-08-28T14:02:42.637Z,1598623362.637 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2020-08-28T14:02:42.947Z,1598623362.947 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2020-08-28T14:02:42.948Z,1598623362.948 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2020-08-28T14:02:43.143Z,1598623363.143 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2020-08-28T14:02:43.145Z,1598623363.145 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2020-08-28T14:02:43.619Z,1598623363.619 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2020-08-28T14:02:43.621Z,1598623363.621 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2020-08-28T14:02:43.725Z,1598623363.725 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2020-08-28T14:02:43.727Z,1598623363.727 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2020-08-28T14:02:43.827Z,1598623363.827 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2020-08-28T14:02:43.828Z,1598623363.828 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2020-08-28T14:02:44.485Z,1598623364.485 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2020-08-28T14:02:44.487Z,1598623364.487 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2020-08-28T14:02:44.925Z,1598623364.925 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2020-08-28T14:02:44.926Z,1598623364.926 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2020-08-28T14:02:45.687Z,1598623365.687 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2020-08-28T14:02:45.689Z,1598623365.689 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2020-08-28T14:02:45.835Z,1598623365.835 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2020-08-28T14:02:45.836Z,1598623365.836 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2020-08-28T14:02:45.985Z,1598623365.985 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2020-08-28T14:02:45.986Z,1598623365.986 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2020-08-28T14:02:46.194Z,1598623366.194 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2020-08-28T14:02:46.196Z,1598623366.196 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2020-08-28T14:02:46.199Z,1598623366.199 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2020-08-28T14:02:46.290Z,1598623366.290 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2020-08-28T14:02:46.375Z,1598623366.375 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2020-08-28T14:02:46.478Z,1598623366.478 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2020-08-28T14:02:46.561Z,1598623366.561 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2020-08-28T14:02:46.656Z,1598623366.656 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2020-08-28T14:02:46.757Z,1598623366.757 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2020-08-28T14:02:46.967Z,1598623366.967 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2020-08-28T14:02:47.043Z,1598623367.043 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2020-08-28T14:02:47.204Z,1598623367.204 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2020-08-28T14:02:47.351Z,1598623367.351 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2020-08-28T14:02:47.469Z,1598623367.469 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg
2020-08-28T14:02:47.701Z,1598623367.701 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2020-08-28T14:02:47.701Z,1598623367.701 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2020-08-28T14:02:47.713Z,1598623367.713 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2020-08-28T14:02:47.777Z,1598623367.777 [VerticalControl](DEBUG): Construct VerticalControl.
2020-08-28T14:02:47.889Z,1598623367.889 [VerticalControl] Loaded
2020-08-28T14:02:47.889Z,1598623367.889 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2020-08-28T14:02:47.890Z,1598623367.890 [HorizontalControl](DEBUG): Construct HorizontalControl.
2020-08-28T14:02:47.970Z,1598623367.970 [HorizontalControl] Loaded
2020-08-28T14:02:47.970Z,1598623367.970 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2020-08-28T14:02:47.971Z,1598623367.971 [SpeedControl](DEBUG): Construct SpeedControl.
2020-08-28T14:02:47.976Z,1598623367.976 [SpeedControl] Loaded
2020-08-28T14:02:47.977Z,1598623367.977 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2020-08-28T14:02:47.977Z,1598623367.977 [LoopControl](DEBUG): Construct LoopControl.
2020-08-28T14:02:47.978Z,1598623367.978 [LoopControl] Loaded
2020-08-28T14:02:47.978Z,1598623367.978 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2020-08-28T14:02:47.978Z,1598623367.978 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2020-08-28T14:02:47.980Z,1598623367.980 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2020-08-28T14:02:48.010Z,1598623368.010 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2020-08-28T14:02:48.011Z,1598623368.011 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2020-08-28T14:02:48.135Z,1598623368.135 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2020-08-28T14:02:48.135Z,1598623368.135 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2020-08-28T14:02:48.303Z,1598623368.303 [BuoyancyServo] Loaded
2020-08-28T14:02:48.303Z,1598623368.303 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2020-08-28T14:02:48.331Z,1598623368.331 [ElevatorServo] Loaded
2020-08-28T14:02:48.331Z,1598623368.331 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2020-08-28T14:02:48.358Z,1598623368.358 [MassServo] Loaded
2020-08-28T14:02:48.359Z,1598623368.359 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2020-08-28T14:02:48.386Z,1598623368.386 [RudderServo] Loaded
2020-08-28T14:02:48.386Z,1598623368.386 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2020-08-28T14:02:48.412Z,1598623368.412 [ThrusterServo] Loaded
2020-08-28T14:02:48.412Z,1598623368.412 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2020-08-28T14:02:48.413Z,1598623368.413 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2020-08-28T14:02:48.413Z,1598623368.413 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2020-08-28T14:02:48.553Z,1598623368.553 [DeadReckonUsingMultipleVelocitySources] Loaded
2020-08-28T14:02:48.554Z,1598623368.554 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2020-08-28T14:02:48.574Z,1598623368.574 [NavChart] Loaded
2020-08-28T14:02:48.574Z,1598623368.574 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2020-08-28T14:02:48.578Z,1598623368.578 [UniversalFixResidualReporter] Loaded
2020-08-28T14:02:48.578Z,1598623368.578 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2020-08-28T14:02:48.579Z,1598623368.579 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2020-08-28T14:02:48.580Z,1598623368.580 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2020-08-28T14:02:48.703Z,1598623368.703 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2020-08-28T14:02:48.703Z,1598623368.703 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2020-08-28T14:02:49.242Z,1598623369.242 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_orientation
2020-08-28T14:02:49.247Z,1598623369.247 [AHRS_M2](INFO): created writer for : platform_orientation
2020-08-28T14:02:49.248Z,1598623369.248 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_magnetic_orientation
2020-08-28T14:02:49.253Z,1598623369.253 [AHRS_M2](INFO): created writer for : platform_magnetic_orientation
2020-08-28T14:02:49.254Z,1598623369.254 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_pitch_angle
2020-08-28T14:02:49.259Z,1598623369.259 [AHRS_M2](INFO): created writer for : platform_pitch_angle
2020-08-28T14:02:49.259Z,1598623369.259 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_roll_angle
2020-08-28T14:02:49.264Z,1598623369.264 [AHRS_M2](INFO): created writer for : platform_roll_angle
2020-08-28T14:02:49.442Z,1598623369.442 [AHRS_M2] Loaded
2020-08-28T14:02:49.442Z,1598623369.442 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2020-08-28T14:02:49.590Z,1598623369.590 [DataOverHttps] Loaded
2020-08-28T14:02:49.590Z,1598623369.590 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2020-08-28T14:02:49.591Z,1598623369.591 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4089B4E0
2020-08-28T14:02:49.591Z,1598623369.591 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 909
2020-08-28T14:02:49.622Z,1598623369.622 [Depth_Keller] Loaded
2020-08-28T14:02:49.622Z,1598623369.622 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2020-08-28T14:02:49.626Z,1598623369.626 [DropWeight] Loaded
2020-08-28T14:02:49.627Z,1598623369.627 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2020-08-28T14:02:49.739Z,1598623369.739 [NAL9602] Loaded
2020-08-28T14:02:49.739Z,1598623369.739 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2020-08-28T14:02:49.787Z,1598623369.787 [Onboard] Loaded
2020-08-28T14:02:49.787Z,1598623369.787 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2020-08-28T14:02:49.788Z,1598623369.788 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 408CB4E0
2020-08-28T14:02:49.788Z,1598623369.788 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 910
2020-08-28T14:02:49.808Z,1598623369.808 [Radio_Surface] Loaded
2020-08-28T14:02:49.808Z,1598623369.808 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2020-08-28T14:02:49.809Z,1598623369.809 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408FB4E0
2020-08-28T14:02:49.809Z,1598623369.809 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 911
2020-08-28T14:02:51.853Z,1598623371.853 [BPC1] Loaded
2020-08-28T14:02:51.854Z,1598623371.853 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2020-08-28T14:02:51.854Z,1598623371.854 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2020-08-28T14:02:51.855Z,1598623371.855 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2020-08-28T14:02:51.910Z,1598623371.910 [DepthRateCalculator] Loaded
2020-08-28T14:02:51.910Z,1598623371.910 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2020-08-28T14:02:51.916Z,1598623371.916 [PitchRateCalculator] Loaded
2020-08-28T14:02:51.916Z,1598623371.916 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2020-08-28T14:02:51.928Z,1598623371.928 [SpeedCalculator] Loaded
2020-08-28T14:02:51.928Z,1598623371.928 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2020-08-28T14:02:51.949Z,1598623371.949 [TempGradientCalculator] Loaded
2020-08-28T14:02:51.949Z,1598623371.949 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2020-08-28T14:02:51.954Z,1598623371.954 [YawRateCalculator] Loaded
2020-08-28T14:02:51.954Z,1598623371.954 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2020-08-28T14:02:51.983Z,1598623371.983 [ElevatorOffsetCalculator] Loaded
2020-08-28T14:02:51.984Z,1598623371.984 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2020-08-28T14:02:51.984Z,1598623371.984 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2020-08-28T14:02:51.985Z,1598623371.985 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2020-08-28T14:02:52.278Z,1598623372.278 [CANONSampler] Loaded
2020-08-28T14:02:52.279Z,1598623372.279 [ComponentRegistry](DEBUG): SyncComponent "CANONSampler" handled in the control thread.
2020-08-28T14:02:52.307Z,1598623372.307 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density
2020-08-28T14:02:52.312Z,1598623372.312 [CTD_Seabird](INFO): created writer for : sea_water_density
2020-08-28T14:02:52.312Z,1598623372.312 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth
2020-08-28T14:02:52.317Z,1598623372.317 [CTD_Seabird](INFO): created writer for : depth
2020-08-28T14:02:52.318Z,1598623372.318 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure
2020-08-28T14:02:52.322Z,1598623372.322 [CTD_Seabird](INFO): created writer for : sea_water_pressure
2020-08-28T14:02:52.323Z,1598623372.323 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity
2020-08-28T14:02:52.328Z,1598623372.328 [CTD_Seabird](INFO): created writer for : sea_water_salinity
2020-08-28T14:02:52.329Z,1598623372.329 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature
2020-08-28T14:02:52.334Z,1598623372.334 [CTD_Seabird](INFO): created writer for : sea_water_temperature
2020-08-28T14:02:52.334Z,1598623372.334 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity
2020-08-28T14:02:52.340Z,1598623372.340 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity
2020-08-28T14:02:52.340Z,1598623372.340 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water
2020-08-28T14:02:52.345Z,1598623372.345 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water
2020-08-28T14:02:52.346Z,1598623372.346 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): mass_concentration_of_oxygen_in_sea_water
2020-08-28T14:02:52.351Z,1598623372.351 [CTD_Seabird](INFO): created writer for : mass_concentration_of_oxygen_in_sea_water
2020-08-28T14:02:52.352Z,1598623372.352 [CTD_Seabird](DEBUG): LcmSlateWriter::add(DAtaURI): CTD_Seabird.sea_water_dissolved_oxygen_freq
2020-08-28T14:02:52.352Z,1598623372.352 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): dataName: sea_water_dissolved_oxygen_freq
2020-08-28T14:02:52.384Z,1598623372.384 [CTD_Seabird] Loaded
2020-08-28T14:02:52.384Z,1598623372.384 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2020-08-28T14:02:52.385Z,1598623372.385 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40A074E0
2020-08-28T14:02:52.386Z,1598623372.386 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 912
2020-08-28T14:02:52.417Z,1598623372.417 [PAR_Licor] Loaded
2020-08-28T14:02:52.417Z,1598623372.417 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2020-08-28T14:02:52.439Z,1598623372.439 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output470
2020-08-28T14:02:52.439Z,1598623372.439 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output470
2020-08-28T14:02:52.443Z,1598623372.443 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output650
2020-08-28T14:02:52.443Z,1598623372.443 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output650
2020-08-28T14:02:52.447Z,1598623372.447 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.OutputChl
2020-08-28T14:02:52.447Z,1598623372.447 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: OutputChl
2020-08-28T14:02:52.451Z,1598623372.451 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg470nm
2020-08-28T14:02:52.452Z,1598623372.452 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg470nm
2020-08-28T14:02:52.456Z,1598623372.456 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg650nm
2020-08-28T14:02:52.456Z,1598623372.456 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg650nm
2020-08-28T14:02:52.460Z,1598623372.460 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff470nm
2020-08-28T14:02:52.460Z,1598623372.460 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff470nm
2020-08-28T14:02:52.465Z,1598623372.465 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff650nm
2020-08-28T14:02:52.465Z,1598623372.465 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff650nm
2020-08-28T14:02:52.469Z,1598623372.469 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): mass_concentration_of_chlorophyll_in_sea_water
2020-08-28T14:02:52.473Z,1598623372.473 [WetLabsBB2FL](INFO): created writer for : mass_concentration_of_chlorophyll_in_sea_water
2020-08-28T14:02:52.474Z,1598623372.474 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_median_mass_concentration_of_chlorophyll_in_sea_water
2020-08-28T14:02:52.474Z,1598623372.474 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_median_mass_concentration_of_chlorophyll_in_sea_water
2020-08-28T14:02:52.478Z,1598623372.478 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water
2020-08-28T14:02:52.478Z,1598623372.478 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_mean_mass_concentration_of_chlorophyll_in_sea_water
2020-08-28T14:02:52.483Z,1598623372.483 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_variance_mass_concentration_of_chlorophyll_in_sea_water
2020-08-28T14:02:52.483Z,1598623372.483 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_variance_mass_concentration_of_chlorophyll_in_sea_water
2020-08-28T14:02:52.487Z,1598623372.487 [WetLabsBB2FL] Loaded
2020-08-28T14:02:52.487Z,1598623372.487 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2020-08-28T14:02:52.488Z,1598623372.488 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40A374E0
2020-08-28T14:02:52.489Z,1598623372.489 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 913
2020-08-28T14:02:52.490Z,1598623372.490 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2020-08-28T14:02:52.490Z,1598623372.490 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2020-08-28T14:02:52.531Z,1598623372.531 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2020-08-28T14:02:52.531Z,1598623372.531 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2020-08-28T14:02:52.867Z,1598623372.867 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2020-08-28T14:02:52.867Z,1598623372.867 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2020-08-28T14:02:53.029Z,1598623373.029 [SBIT](DEBUG): Construct Startup Built In Test.
2020-08-28T14:02:53.040Z,1598623373.040 [SBIT] Loaded
2020-08-28T14:02:53.040Z,1598623373.040 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2020-08-28T14:02:53.041Z,1598623373.041 [IBIT](DEBUG): Construct Initiated Built In Test.
2020-08-28T14:02:53.054Z,1598623373.054 [IBIT] Loaded
2020-08-28T14:02:53.054Z,1598623373.054 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2020-08-28T14:02:53.057Z,1598623373.057 [CBIT](DEBUG): Construct Continuous Built In Test.
2020-08-28T14:02:53.196Z,1598623373.196 [CBIT] Loaded
2020-08-28T14:02:53.196Z,1598623373.196 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2020-08-28T14:02:53.196Z,1598623373.196 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2020-08-28T14:02:53.197Z,1598623373.197 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2020-08-28T14:02:53.295Z,1598623373.295 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2020-08-28T14:02:53.299Z,1598623373.299 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2020-08-28T14:02:53.299Z,1598623373.299 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2020-08-28T14:02:53.306Z,1598623373.306 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2020-08-28T14:02:53.307Z,1598623373.307 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B5D4E0
2020-08-28T14:02:53.308Z,1598623373.308 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 914
2020-08-28T14:02:53.312Z,1598623373.312 [Supervisor](INFO): Main Thread ID is 817
2020-08-28T14:02:53.312Z,1598623373.312 [Supervisor](DEBUG): Running supervisor.
2020-08-28T14:02:53.313Z,1598623373.313 [CommandLine ThreadHandler](INFO): Handler Thread ID is 915
2020-08-28T14:02:53.315Z,1598623373.315 [controlThread ThreadHandler](INFO): Handler Thread ID is 916
2020-08-28T14:02:53.316Z,1598623373.316 [controlThread](DEBUG): Initializing ControlThread
2020-08-28T14:02:53.316Z,1598623373.316 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2020-08-28T14:02:53.318Z,1598623373.318 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2020-08-28T14:02:53.319Z,1598623373.319 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2020-08-28T14:02:53.319Z,1598623373.319 [LoopControl](DEBUG): Initialize LoopControlComponent.
2020-08-28T14:02:53.321Z,1598623373.321 [NavChart](DEBUG): Initialize NavChart Navigation.
2020-08-28T14:02:53.322Z,1598623373.322 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2020-08-28T14:02:53.327Z,1598623373.327 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2020-08-28T14:02:53.327Z,1598623373.327 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2020-08-28T14:02:53.327Z,1598623373.327 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2020-08-28T14:02:53.327Z,1598623373.327 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2020-08-28T14:02:53.328Z,1598623373.328 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2020-08-28T14:02:53.328Z,1598623373.328 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2020-08-28T14:02:53.333Z,1598623373.333 [SBIT](INFO): Initialize SBIT Component.
2020-08-28T14:02:53.334Z,1598623373.334 [SBIT](IMPORTANT): git: 2020-08-18a
2020-08-28T14:02:53.334Z,1598623373.334 [SBIT](INFO): git hash: 77519d12954ee93339c6cb522e5e7960b0ad92da
2020-08-28T14:02:53.334Z,1598623373.334 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2020-08-28T14:02:53.335Z,1598623373.335 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #1 PREEMPT Wed Nov 13 12:38:10 PST 2019
2020-08-28T14:02:53.336Z,1598623373.336 [SBIT](INFO): Beginning SBIT in 63.000000 seconds.
2020-08-28T14:02:53.337Z,1598623373.337 [IBIT](INFO): Initialize IBIT Component.
2020-08-28T14:02:53.338Z,1598623373.338 [CBIT](DEBUG): Initialize CBIT Component.
2020-08-28T14:02:53.339Z,1598623373.339 [logger ThreadHandler](INFO): Handler Thread ID is 917
2020-08-28T14:02:53.349Z,1598623373.349 [CBIT](DEBUG): Initialized mux pins.
2020-08-28T14:02:53.349Z,1598623373.349 [CBIT](DEBUG): Initializing the watchdog timer.
2020-08-28T14:02:53.357Z,1598623373.357 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 918
2020-08-28T14:02:53.358Z,1598623373.358 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2020-08-28T14:02:53.369Z,1598623373.369 [Onboard ThreadHandler](INFO): Handler Thread ID is 919
2020-08-28T14:02:53.373Z,1598623373.373 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2020-08-28T14:02:53.374Z,1598623373.374 [CBIT](DEBUG): Initializing heartbeat.
2020-08-28T14:02:53.387Z,1598623373.387 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 920
2020-08-28T14:02:53.405Z,1598623373.405 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 921
2020-08-28T14:02:53.406Z,1598623373.406 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2020-08-28T14:02:53.410Z,1598623373.410 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 923
2020-08-28T14:02:53.411Z,1598623373.411 [WetLabsBB2FL](INFO): Powering down
2020-08-28T14:02:53.445Z,1598623373.445 [CBIT](DEBUG): Deactivating GF circuits.
2020-08-28T14:02:53.445Z,1598623373.445 [CBIT](DEBUG): Deactivating emergency mode.
2020-08-28T14:02:53.481Z,1598623373.481 [CBIT](DEBUG): Backplane powered.
2020-08-28T14:02:53.482Z,1598623373.482 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2020-08-28T14:02:53.543Z,1598623373.543 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 924
2020-08-28T14:02:53.631Z,1598623373.631 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2020-08-28T14:02:53.631Z,1598623373.631 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2020-08-28T14:02:53.631Z,1598623373.631 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2020-08-28T14:02:53.631Z,1598623373.631 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2020-08-28T14:02:53.632Z,1598623373.632 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2020-08-28T14:02:53.632Z,1598623373.632 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2020-08-28T14:02:53.632Z,1598623373.632 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2020-08-28T14:02:53.632Z,1598623373.632 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2020-08-28T14:02:53.632Z,1598623373.632 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2020-08-28T14:02:53.632Z,1598623373.632 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2020-08-28T14:02:53.633Z,1598623373.633 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2020-08-28T14:02:53.633Z,1598623373.633 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2020-08-28T14:02:53.633Z,1598623373.633 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2020-08-28T14:02:53.633Z,1598623373.633 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2020-08-28T14:02:53.633Z,1598623373.633 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2020-08-28T14:02:53.634Z,1598623373.634 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2020-08-28T14:02:53.655Z,1598623373.655 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2020-08-28T14:02:53.760Z,1598623373.760 [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-08-28T14:02:53.761Z,1598623373.761 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2020-08-28T14:02:53.793Z,1598623373.793 [Radio_Surface](INFO): Powering up
2020-08-28T14:02:53.856Z,1598623373.856 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2020-08-28T14:02:53.873Z,1598623373.873 [Default:A.Wait](DEBUG): Construct Wait.
2020-08-28T14:02:53.875Z,1598623373.875 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2020-08-28T14:02:53.902Z,1598623373.902 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2020-08-28T14:02:53.929Z,1598623373.929 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2020-08-28T14:02:53.935Z,1598623373.935 [Default:E.Execute](DEBUG): Construct Execute.
2020-08-28T14:02:53.958Z,1598623373.958 [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-08-28T14:02:53.963Z,1598623373.963 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,NAL9602,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-08-28T14:02:53.973Z,1598623373.973 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2020-08-28T14:02:54.101Z,1598623374.101 [Depth_Keller](ERROR): Pressure reading out of range: 1831.023193 decibar
2020-08-28T14:02:54.129Z,1598623374.129 [CANONSampler](INFO): Powering down
2020-08-28T14:02:54.133Z,1598623374.133 [DepthRateCalculator](ERROR): Depth measurement is not active
2020-08-28T14:02:54.170Z,1598623374.170 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2020-08-28T14:02:54.177Z,1598623374.177 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2020-08-28T14:02:54.178Z,1598623374.178 [ElevatorServo](DEBUG): Initializing EZServoServo.
2020-08-28T14:02:54.185Z,1598623374.185 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2020-08-28T14:02:54.186Z,1598623374.186 [MassServo](DEBUG): Initializing EZServoServo.
2020-08-28T14:02:54.193Z,1598623374.193 [MassServo](DEBUG): Initializing MassServo.
2020-08-28T14:02:54.194Z,1598623374.194 [RudderServo](DEBUG): Initializing EZServoServo.
2020-08-28T14:02:54.201Z,1598623374.201 [RudderServo](DEBUG): Initializing RudderServo.
2020-08-28T14:02:54.202Z,1598623374.202 [ThrusterServo](DEBUG): Initializing EZServoServo.
2020-08-28T14:02:54.209Z,1598623374.209 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2020-08-28T14:02:55.121Z,1598623375.121 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2020-08-28T14:02:55.121Z,1598623375.121 [RudderServo](FAULT): Rudder failed to initialize
2020-08-28T14:02:55.121Z,1598623375.121 [RudderServo] Communications Fault, FailCount= 1
2020-08-28T14:02:55.121Z,1598623375.121 [RudderServo](ERROR): Communications Fault
2020-08-28T14:02:55.232Z,1598623375.232 [CBIT](ERROR): Communications Fault in component: RudderServo
2020-08-28T14:02:55.430Z,1598623375.430 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2020-08-28T14:02:55.430Z,1598623375.430 [RudderServo](INFO): Powering down
2020-08-28T14:02:56.064Z,1598623376.064 [RudderServo](DEBUG): Initializing EZServoServo.
2020-08-28T14:02:56.182Z,1598623376.182 [RudderServo](DEBUG): Initializing RudderServo.
2020-08-28T14:02:56.186Z,1598623376.186 [CBIT](INFO): Clearing failed state for component RudderServo
2020-08-28T14:02:56.186Z,1598623376.186 [RudderServo] No Fault, FailCount= 1
2020-08-28T14:03:19.892Z,1598623399.892 [NAL9602](INFO): Powering up NAL9602
2020-08-28T14:03:30.794Z,1598623410.794 [NAL9602](INFO): NAL9602 initialized
2020-08-28T14:03:57.075Z,1598623437.075 [SBIT](IMPORTANT): Beginning Startup BIT
2020-08-28T14:03:57.097Z,1598623437.097 [CBIT](IMPORTANT): Beginning ground fault scan
2020-08-28T14:04:07.995Z,1598623447.995 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): 0.000618
CHAN A1 (24V): 0.000824
CHAN A2 (12V): -0.002056
CHAN A3 (5V): -0.000812
CHAN B0 (3.3V): 0.000085
CHAN B1 (3.15aV): -0.000437
CHAN B2 (3.15bV): 0.000040
CHAN B3 (GND): 0.000137
OPEN: -0.000459
Full Scale Calc: 4.765 mA, -1.589 mA
2020-08-28T14:04:51.215Z,1598623491.215 [SBIT](IMPORTANT): SBIT PASSED
2020-08-28T14:04:51.215Z,1598623491.215 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2020-08-28T14:04:51.216Z,1598623491.216 [SBIT](IMPORTANT): CBIT.gf24Offset=-27 microampere;

2020-08-28T14:04:51.216Z,1598623491.216 [SBIT](IMPORTANT): ElevatorOffsetCalculator.loadAtStartup=1 bool;

2020-08-28T14:04:51.217Z,1598623491.217 [SBIT](IMPORTANT): Express linearApproximation acoustic_contact_range 10.000000 meter;

2020-08-28T14:04:51.217Z,1598623491.217 [SBIT](IMPORTANT): Express linearApproximation platform_average_power 1.000000 watt;

2020-08-28T14:04:51.217Z,1598623491.217 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=210.468208 cubic_centimeter;

2020-08-28T14:04:51.217Z,1598623491.217 [SBIT](IMPORTANT): VerticalControl.massDefault=-10.864258 millimeter;

2020-08-28T14:04:51.626Z,1598623491.626 [MissionManager](IMPORTANT): Started mission Startup
2020-08-28T14:04:51.626Z,1598623491.626 [Startup] Running Loop=1
2020-08-28T14:04:51.626Z,1598623491.626 [Startup](DEBUG): Aggregate::initialize Startup
2020-08-28T14:04:51.627Z,1598623491.627 [Startup:A.GoToSurface] Running Loop=1
2020-08-28T14:04:51.627Z,1598623491.627 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-08-28T14:04:51.627Z,1598623491.627 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-08-28T14:04:51.628Z,1598623491.628 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-08-28T14:04:51.628Z,1598623491.628 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-08-28T14:04:51.628Z,1598623491.628 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-08-28T14:04:51.629Z,1598623491.629 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-08-28T14:04:51.630Z,1598623491.630 [Startup:StartupSatComms] Running Loop=1
2020-08-28T14:04:51.631Z,1598623491.631 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2020-08-28T14:04:51.631Z,1598623491.631 [Startup:StartupSatComms:A] Running Loop=1
2020-08-28T14:04:52.040Z,1598623492.040 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2020-08-28T14:05:12.660Z,1598623512.660 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2020-08-28T14:05:25.103Z,1598623525.103 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004863
2020-08-28T14:05:51.886Z,1598623551.886 [Startup:StartupSatComms:A](INFO): Timed out from 2020-08-28T14:04:51.6Z
2020-08-28T14:05:51.886Z,1598623551.886 [Startup:StartupSatComms:A] Stopped
2020-08-28T14:05:51.886Z,1598623551.886 [Startup:StartupSatComms:B] Running Loop=1
2020-08-28T14:05:52.236Z,1598623552.236 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2020-08-28T14:05:53.535Z,1598623553.535 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2020-08-28T14:05:53.535Z,1598623553.535 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-08-28T14:05:53.588Z,1598623553.588 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-08-28T14:05:53.811Z,1598623553.811 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20200827T212902/Courier0010.lzma
2020-08-28T14:05:53.918Z,1598623553.918 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-08-28T14:05:53.918Z,1598623553.918 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2020-08-28T14:05:54.727Z,1598623554.727 [DataOverHttps](INFO): Moved sent file to Logs/20200827T212902/Courier0010.lzma.bak
2020-08-28T14:05:54.727Z,1598623554.727 [DataOverHttps](INFO): SBD MOMSN=12624307
2020-08-28T14:06:10.114Z,1598623570.114 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20200828T140011/Courier0000.lzma
2020-08-28T14:06:11.114Z,1598623571.114 [DataOverHttps](INFO): Moved sent file to Logs/20200828T140011/Courier0000.lzma.bak
2020-08-28T14:06:11.115Z,1598623571.115 [DataOverHttps](INFO): SBD MOMSN=12624309
2020-08-28T14:06:26.488Z,1598623586.488 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20200828T140241/Courier0000.lzma
2020-08-28T14:06:27.491Z,1598623587.491 [DataOverHttps](INFO): Moved sent file to Logs/20200828T140241/Courier0000.lzma.bak
2020-08-28T14:06:27.491Z,1598623587.491 [DataOverHttps](INFO): SBD MOMSN=12624312
2020-08-28T14:06:42.944Z,1598623602.944 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20200827T212902/Express0011.lzma
2020-08-28T14:06:43.946Z,1598623603.946 [DataOverHttps](INFO): Moved sent file to Logs/20200827T212902/Express0011.lzma.bak
2020-08-28T14:06:43.947Z,1598623603.947 [DataOverHttps](INFO): SBD MOMSN=12624315
2020-08-28T14:06:52.154Z,1598623612.154 [Startup:StartupSatComms:B](INFO): Timed out from 2020-08-28T14:05:51.9Z
2020-08-28T14:06:52.154Z,1598623612.154 [Startup:StartupSatComms:B] Stopped
2020-08-28T14:06:52.154Z,1598623612.154 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2020-08-28T14:06:52.154Z,1598623612.154 [Startup:StartupSatComms] Stopped
2020-08-28T14:06:52.154Z,1598623612.154 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2020-08-28T14:06:52.155Z,1598623612.155 [Startup](INFO): Completed Startup
2020-08-28T14:06:52.155Z,1598623612.155 [MissionManager](INFO): Startup is completed.
2020-08-28T14:06:52.155Z,1598623612.155 [MissionManager](INFO): Uninitializing Mission Startup
2020-08-28T14:06:52.155Z,1598623612.155 [Startup] Stopped
2020-08-28T14:06:52.155Z,1598623612.155 [Startup](DEBUG): Aggregate::uninitialize Startup
2020-08-28T14:06:52.156Z,1598623612.156 [Startup:A.GoToSurface] Stopped
2020-08-28T14:06:52.156Z,1598623612.156 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2020-08-28T14:06:52.498Z,1598623612.498 [MissionManager](IMPORTANT): Started mission Default
2020-08-28T14:06:52.498Z,1598623612.498 [Default] Running Loop=1
2020-08-28T14:06:52.498Z,1598623612.498 [Default](DEBUG): Aggregate::initialize Default
2020-08-28T14:06:52.498Z,1598623612.498 [Default:B.GoToSurface] Running Loop=1
2020-08-28T14:06:52.498Z,1598623612.498 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-08-28T14:06:52.498Z,1598623612.498 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-08-28T14:06:52.499Z,1598623612.499 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-08-28T14:06:52.499Z,1598623612.499 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-08-28T14:06:52.499Z,1598623612.499 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-08-28T14:06:52.500Z,1598623612.500 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-08-28T14:06:52.500Z,1598623612.500 [Default:A.Wait] Running Loop=1
2020-08-28T14:06:52.500Z,1598623612.500 [Default:A.Wait](DEBUG): Initialize Wait Component.
2020-08-28T14:06:59.262Z,1598623619.262 [DataOverHttps](INFO): Sending 677 bytes from file Logs/20200828T140011/Express0001.lzma
2020-08-28T14:07:00.262Z,1598623620.262 [DataOverHttps](INFO): Moved sent file to Logs/20200828T140011/Express0001.lzma.bak
2020-08-28T14:07:00.263Z,1598623620.263 [DataOverHttps](INFO): SBD MOMSN=12624317
2020-08-28T14:07:05.834Z,1598623625.834 [Default:A.Wait](INFO): Done Waiting.
2020-08-28T14:07:05.834Z,1598623625.834 [Default:A.Wait] Stopped
2020-08-28T14:07:05.834Z,1598623625.834 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2020-08-28T14:07:06.243Z,1598623626.243 [Default:CheckIn] Running Loop=1
2020-08-28T14:07:06.244Z,1598623626.244 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-28T14:07:06.244Z,1598623626.244 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-28T14:07:06.655Z,1598623626.655 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2020-08-28T14:07:22.268Z,1598623642.268 [CommandLine](IMPORTANT): got command failComponent
2020-08-28T14:07:22.269Z,1598623642.269 [CommandLine](IMPORTANT): Failed components:
2020-08-28T14:07:22.269Z,1598623642.269 [CommandLine](IMPORTANT): No failed Components.
2020-08-28T14:07:30.276Z,1598623650.276 [CommandLine](IMPORTANT): got command configSet list
2020-08-28T14:07:30.276Z,1598623650.276 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2020-08-28T14:07:30.281Z,1598623650.281 [CommandLine](IMPORTANT): CBIT.gf24Offset=-27 microampere;

2020-08-28T14:07:30.281Z,1598623650.281 [CommandLine](IMPORTANT): ElevatorOffsetCalculator.loadAtStartup=1 bool;

2020-08-28T14:07:30.281Z,1598623650.281 [CommandLine](IMPORTANT): Express linearApproximation acoustic_contact_range 10.000000 meter;

2020-08-28T14:07:30.281Z,1598623650.281 [CommandLine](IMPORTANT): Express linearApproximation platform_average_power 1.000000 watt;

2020-08-28T14:07:30.281Z,1598623650.281 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=210.468208 cubic_centimeter;

2020-08-28T14:07:30.281Z,1598623650.281 [CommandLine](IMPORTANT): VerticalControl.massDefault=-10.864258 millimeter;

2020-08-28T14:07:36.178Z,1598623656.178 [CommandLine](IMPORTANT): got command gfscan
2020-08-28T14:07:36.556Z,1598623656.556 [CBIT](IMPORTANT): Beginning ground fault scan
2020-08-28T14:07:47.473Z,1598623667.473 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): 0.002825
CHAN A1 (24V): 0.000454
CHAN A2 (12V): -0.002448
CHAN A3 (5V): -0.001321
CHAN B0 (3.3V): 0.000022
CHAN B1 (3.15aV): 0.000201
CHAN B2 (3.15bV): -0.000058
CHAN B3 (GND): -0.000277
OPEN: -0.000297
Full Scale Calc: 4.765 mA, -1.589 mA
2020-08-28T14:08:33.886Z,1598623713.886 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-08-28T14:08:54.501Z,1598623734.501 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2020-08-28T14:08:54.501Z,1598623734.501 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-08-28T14:08:54.544Z,1598623734.544 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-08-28T14:08:54.911Z,1598623734.911 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-08-28T14:08:54.911Z,1598623734.911 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2020-08-28T14:10:35.908Z,1598623835.908 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2020-08-28T14:10:35.911Z,1598623835.911 [BPC1](INFO): Received data from all battery sticks.
2020-08-28T14:11:55.519Z,1598623915.519 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2020-08-28T14:11:55.519Z,1598623915.519 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-08-28T14:11:55.529Z,1598623915.529 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-08-28T14:11:55.910Z,1598623915.910 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-08-28T14:11:55.910Z,1598623915.910 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2020-08-28T14:12:06.415Z,1598623926.415 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-08-28T14:07:06.2Z
2020-08-28T14:12:06.415Z,1598623926.415 [Default:CheckIn:Read_GPS] Stopped
2020-08-28T14:12:06.415Z,1598623926.415 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-28T14:12:06.835Z,1598623926.835 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2020-08-28T14:12:13.656Z,1598623933.656 [DataOverHttps](INFO): Sending 169 bytes from file Logs/20200828T140241/Courier0004.lzma
2020-08-28T14:12:14.658Z,1598623934.658 [DataOverHttps](INFO): Moved sent file to Logs/20200828T140241/Courier0004.lzma.bak
2020-08-28T14:12:14.659Z,1598623934.659 [DataOverHttps](INFO): SBD MOMSN=12624332
2020-08-28T14:12:29.982Z,1598623949.982 [DataOverHttps](INFO): Sending 860 bytes from file Logs/20200828T140241/Express0001.lzma
2020-08-28T14:12:30.982Z,1598623950.982 [DataOverHttps](INFO): Moved sent file to Logs/20200828T140241/Express0001.lzma.bak
2020-08-28T14:12:30.983Z,1598623950.983 [DataOverHttps](INFO): SBD MOMSN=12624334
2020-08-28T14:12:46.273Z,1598623966.273 [DataOverHttps](INFO): Sending 718 bytes from file Logs/20200828T140241/Express0005.lzma
2020-08-28T14:12:47.275Z,1598623967.275 [DataOverHttps](INFO): Moved sent file to Logs/20200828T140241/Express0005.lzma.bak
2020-08-28T14:12:47.275Z,1598623967.275 [DataOverHttps](INFO): SBD MOMSN=12624352
2020-08-28T14:12:48.421Z,1598623968.421 [Default:CheckIn:Read_Iridium] Stopped
2020-08-28T14:12:48.422Z,1598623968.422 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-28T14:12:48.422Z,1598623968.422 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-28T14:13:33.666Z,1598624013.666 [NAL9602](FAULT): GPS failed to acquire within timeout.
2020-08-28T14:13:33.666Z,1598624013.666 [NAL9602] Data Fault, FailCount= 1
2020-08-28T14:13:33.666Z,1598624013.666 [NAL9602](ERROR): Data Fault
2020-08-28T14:13:33.683Z,1598624013.683 [CBIT](ERROR): Data Fault in component: NAL9602
2020-08-28T14:13:34.066Z,1598624014.066 [NAL9602](INFO): Powering down
2020-08-28T14:13:34.909Z,1598624014.909 [CBIT](INFO): Clearing failed state for component NAL9602
2020-08-28T14:13:34.909Z,1598624014.909 [NAL9602] No Fault, FailCount= 1
2020-08-28T14:14:04.363Z,1598624044.363 [NAL9602](INFO): Powering up NAL9602
2020-08-28T14:14:15.274Z,1598624055.274 [NAL9602](INFO): NAL9602 initialized
2020-08-28T14:14:56.536Z,1598624096.536 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2020-08-28T14:14:56.536Z,1598624096.536 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-08-28T14:14:56.546Z,1598624096.546 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-08-28T14:14:56.931Z,1598624096.931 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-08-28T14:14:56.931Z,1598624096.931 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2020-08-28T14:17:49.055Z,1598624269.055 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-28T14:17:49.055Z,1598624269.055 [Default:CheckIn:C.Wait] Stopped
2020-08-28T14:17:49.055Z,1598624269.055 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-28T14:17:49.055Z,1598624269.055 [Default:CheckIn:D] Running Loop=1
2020-08-28T14:17:49.459Z,1598624269.459 [Default:CheckIn:D] Stopped
2020-08-28T14:17:49.459Z,1598624269.459 [Default:CheckIn:E] Running Loop=1
2020-08-28T14:17:49.869Z,1598624269.869 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.949349 min 
2020-08-28T14:17:49.870Z,1598624269.870 [Default:CheckIn:E] Stopped
2020-08-28T14:17:49.870Z,1598624269.870 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-28T14:17:49.870Z,1598624269.870 [Default:CheckIn] Stopped
2020-08-28T14:17:49.870Z,1598624269.870 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-28T14:17:49.870Z,1598624269.870 [Default:CheckIn](INFO): Running loop #2
2020-08-28T14:17:49.870Z,1598624269.870 [Default:CheckIn] Running Loop=2
2020-08-28T14:17:49.870Z,1598624269.870 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-28T14:17:49.870Z,1598624269.870 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-28T14:17:57.521Z,1598624277.521 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2020-08-28T14:17:57.521Z,1598624277.521 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-08-28T14:17:57.531Z,1598624277.531 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-08-28T14:17:57.951Z,1598624277.951 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-08-28T14:17:57.951Z,1598624277.951 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2020-08-28T14:19:55.084Z,1598624395.084 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,141955.00,A,3648.17414,N,12147.28604,W,0.680,356.20,280820,,,A*7A
2020-08-28T14:19:55.088Z,1598624395.088 [NAL9602](INFO): GPS fix at 20200828T141955: (36.802902, -121.788101)
2020-08-28T14:19:55.166Z,1598624395.166 [Default:CheckIn:Read_GPS] Stopped
2020-08-28T14:19:55.166Z,1598624395.166 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-28T14:20:00.093Z,1598624400.093 [DataOverHttps](INFO): Sending 223 bytes from file Logs/20200828T140241/Courier0007.lzma
2020-08-28T14:20:01.094Z,1598624401.094 [DataOverHttps](INFO): Moved sent file to Logs/20200828T140241/Courier0007.lzma.bak
2020-08-28T14:20:01.095Z,1598624401.095 [DataOverHttps](INFO): SBD MOMSN=12624370
2020-08-28T14:20:18.086Z,1598624418.086 [DataOverHttps](INFO): Sending 314 bytes from file Logs/20200828T140241/Express0008.lzma
2020-08-28T14:20:19.087Z,1598624419.087 [DataOverHttps](INFO): Moved sent file to Logs/20200828T140241/Express0008.lzma.bak
2020-08-28T14:20:19.087Z,1598624419.087 [DataOverHttps](INFO): SBD MOMSN=12624373
2020-08-28T14:20:20.191Z,1598624420.191 [Default:CheckIn:Read_Iridium] Stopped
2020-08-28T14:20:20.191Z,1598624420.191 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-28T14:20:20.192Z,1598624420.192 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-28T14:20:27.878Z,1598624427.878 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-28T14:25:20.825Z,1598624720.825 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-28T14:25:20.825Z,1598624720.825 [Default:CheckIn:C.Wait] Stopped
2020-08-28T14:25:20.825Z,1598624720.825 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-28T14:25:20.826Z,1598624720.826 [Default:CheckIn:D] Running Loop=1
2020-08-28T14:25:21.245Z,1598624721.245 [Default:CheckIn:D] Stopped
2020-08-28T14:25:21.245Z,1598624721.245 [Default:CheckIn:E] Running Loop=1
2020-08-28T14:25:21.628Z,1598624721.628 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 18.479118 min 
2020-08-28T14:25:21.628Z,1598624721.628 [Default:CheckIn:E] Stopped
2020-08-28T14:25:21.628Z,1598624721.628 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-28T14:25:21.628Z,1598624721.628 [Default:CheckIn] Stopped
2020-08-28T14:25:21.628Z,1598624721.628 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-28T14:25:21.628Z,1598624721.628 [Default:CheckIn](INFO): Running loop #3
2020-08-28T14:25:21.628Z,1598624721.628 [Default:CheckIn] Running Loop=3
2020-08-28T14:25:21.628Z,1598624721.628 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-28T14:25:21.628Z,1598624721.628 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-28T14:25:23.640Z,1598624723.640 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,142523.00,A,3648.17026,N,12147.27511,W,0.661,358.81,280820,,,A*73
2020-08-28T14:25:23.642Z,1598624723.642 [NAL9602](INFO): GPS fix at 20200828T142523: (36.802838, -121.787919)
2020-08-28T14:25:23.676Z,1598624723.676 [Default:CheckIn:Read_GPS] Stopped
2020-08-28T14:25:23.676Z,1598624723.676 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-28T14:25:30.603Z,1598624730.603 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20200828T140241/Courier0010.lzma
2020-08-28T14:25:31.602Z,1598624731.602 [DataOverHttps](INFO): Moved sent file to Logs/20200828T140241/Courier0010.lzma.bak
2020-08-28T14:25:31.603Z,1598624731.603 [DataOverHttps](INFO): SBD MOMSN=12624377
2020-08-28T14:25:34.143Z,1598624734.143 [NAL9602](INFO): SBD MO Status=0, MOMSN=22828, MT Status=0, MTMSN=0
2020-08-28T14:25:34.144Z,1598624734.144 [NAL9602](INFO): No messages in MT queue
2020-08-28T14:25:47.236Z,1598624747.236 [DataOverHttps](INFO): Sending 136 bytes from file Logs/20200828T140241/Express0011.lzma
2020-08-28T14:25:48.239Z,1598624748.239 [DataOverHttps](INFO): Moved sent file to Logs/20200828T140241/Express0011.lzma.bak
2020-08-28T14:25:48.239Z,1598624748.239 [DataOverHttps](INFO): SBD MOMSN=12624380
2020-08-28T14:25:49.499Z,1598624749.499 [Default:CheckIn:Read_Iridium] Stopped
2020-08-28T14:25:49.499Z,1598624749.499 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-28T14:25:49.499Z,1598624749.499 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-28T14:26:04.842Z,1598624764.842 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-28T14:30:50.179Z,1598625050.179 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-28T14:30:50.180Z,1598625050.180 [Default:CheckIn:C.Wait] Stopped
2020-08-28T14:30:50.180Z,1598625050.180 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-28T14:30:50.180Z,1598625050.180 [Default:CheckIn:D] Running Loop=1
2020-08-28T14:30:50.582Z,1598625050.582 [Default:CheckIn:D] Stopped
2020-08-28T14:30:50.582Z,1598625050.582 [Default:CheckIn:E] Running Loop=1
2020-08-28T14:30:50.980Z,1598625050.980 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 23.968064 min 
2020-08-28T14:30:50.980Z,1598625050.980 [Default:CheckIn:E] Stopped
2020-08-28T14:30:50.980Z,1598625050.980 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-28T14:30:50.980Z,1598625050.980 [Default:CheckIn] Stopped
2020-08-28T14:30:50.980Z,1598625050.980 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-28T14:30:50.980Z,1598625050.980 [Default:CheckIn](INFO): Running loop #4
2020-08-28T14:30:50.980Z,1598625050.980 [Default:CheckIn] Running Loop=4
2020-08-28T14:30:50.980Z,1598625050.980 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-28T14:30:50.980Z,1598625050.980 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-28T14:30:52.996Z,1598625052.996 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,143052.00,A,3648.16777,N,12147.28445,W,0.447,0.00,280820,,,A*7D
2020-08-28T14:30:52.998Z,1598625052.998 [NAL9602](INFO): GPS fix at 20200828T143052: (36.802796, -121.788074)
2020-08-28T14:30:53.009Z,1598625053.009 [Default:CheckIn:Read_GPS] Stopped
2020-08-28T14:30:53.009Z,1598625053.009 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-28T14:30:59.364Z,1598625059.364 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20200828T140241/Courier0013.lzma
2020-08-28T14:31:00.366Z,1598625060.366 [DataOverHttps](INFO): Moved sent file to Logs/20200828T140241/Courier0013.lzma.bak
2020-08-28T14:31:00.367Z,1598625060.367 [DataOverHttps](INFO): SBD MOMSN=12624384
2020-08-28T14:31:16.072Z,1598625076.072 [DataOverHttps](INFO): Sending 138 bytes from file Logs/20200828T140241/Express0014.lzma
2020-08-28T14:31:17.074Z,1598625077.074 [DataOverHttps](INFO): Moved sent file to Logs/20200828T140241/Express0014.lzma.bak
2020-08-28T14:31:17.075Z,1598625077.075 [DataOverHttps](INFO): SBD MOMSN=12624387
2020-08-28T14:31:18.450Z,1598625078.450 [Default:CheckIn:Read_Iridium] Stopped
2020-08-28T14:31:18.450Z,1598625078.450 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-28T14:31:18.450Z,1598625078.450 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-28T14:35:06.331Z,1598625306.331 [NAL9602](INFO): SBD MO Status=0, MOMSN=22829, MT Status=0, MTMSN=0
2020-08-28T14:35:06.331Z,1598625306.331 [NAL9602](INFO): No messages in MT queue
2020-08-28T14:35:37.030Z,1598625337.030 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-28T14:36:19.055Z,1598625379.055 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-28T14:36:19.055Z,1598625379.055 [Default:CheckIn:C.Wait] Stopped
2020-08-28T14:36:19.055Z,1598625379.055 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-28T14:36:19.055Z,1598625379.055 [Default:CheckIn:D] Running Loop=1
2020-08-28T14:36:19.478Z,1598625379.478 [Default:CheckIn:D] Stopped
2020-08-28T14:36:19.479Z,1598625379.479 [Default:CheckIn:E] Running Loop=1
2020-08-28T14:36:19.867Z,1598625379.867 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 29.449677 min 
2020-08-28T14:36:19.867Z,1598625379.867 [Default:CheckIn:E] Stopped
2020-08-28T14:36:19.868Z,1598625379.868 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-28T14:36:19.868Z,1598625379.868 [Default:CheckIn] Stopped
2020-08-28T14:36:19.868Z,1598625379.868 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-28T14:36:19.868Z,1598625379.868 [Default:CheckIn](INFO): Running loop #5
2020-08-28T14:36:19.868Z,1598625379.868 [Default:CheckIn] Running Loop=5
2020-08-28T14:36:19.868Z,1598625379.868 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-28T14:36:19.868Z,1598625379.868 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-28T14:36:21.876Z,1598625381.876 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,143621.00,A,3648.16809,N,12147.28499,W,0.253,218.08,280820,,,A*78
2020-08-28T14:36:21.878Z,1598625381.878 [NAL9602](INFO): GPS fix at 20200828T143621: (36.802802, -121.788083)
2020-08-28T14:36:21.893Z,1598625381.893 [Default:CheckIn:Read_GPS] Stopped
2020-08-28T14:36:21.893Z,1598625381.893 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-28T14:36:29.332Z,1598625389.332 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20200828T140241/Courier0016.lzma
2020-08-28T14:36:30.334Z,1598625390.334 [DataOverHttps](INFO): Moved sent file to Logs/20200828T140241/Courier0016.lzma.bak
2020-08-28T14:36:30.335Z,1598625390.335 [DataOverHttps](INFO): SBD MOMSN=12624390
2020-08-28T14:36:46.017Z,1598625406.017 [DataOverHttps](INFO): Sending 139 bytes from file Logs/20200828T140241/Express0017.lzma
2020-08-28T14:36:47.018Z,1598625407.018 [DataOverHttps](INFO): Moved sent file to Logs/20200828T140241/Express0017.lzma.bak
2020-08-28T14:36:47.019Z,1598625407.019 [DataOverHttps](INFO): SBD MOMSN=12624393
2020-08-28T14:36:48.242Z,1598625408.242 [Default:CheckIn:Read_Iridium] Stopped
2020-08-28T14:36:48.242Z,1598625408.242 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-28T14:36:48.242Z,1598625408.242 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-28T14:36:57.929Z,1598625417.929 [NAL9602](INFO): SBD MO Status=2, MOMSN=22830, MT Status=2, MTMSN=0
2020-08-28T14:36:57.929Z,1598625417.929 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-08-28T14:39:41.987Z,1598625581.987 [NAL9602](INFO): SBD MO Status=2, MOMSN=22830, MT Status=2, MTMSN=0
2020-08-28T14:39:41.988Z,1598625581.988 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-08-28T14:41:23.794Z,1598625683.794 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-08-28T14:41:48.865Z,1598625708.865 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-28T14:41:48.865Z,1598625708.865 [Default:CheckIn:C.Wait] Stopped
2020-08-28T14:41:48.865Z,1598625708.865 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-28T14:41:48.866Z,1598625708.866 [Default:CheckIn:D] Running Loop=1
2020-08-28T14:41:49.253Z,1598625709.253 [Default:CheckIn:D] Stopped
2020-08-28T14:41:49.253Z,1598625709.253 [Default:CheckIn:E] Running Loop=1
2020-08-28T14:41:49.655Z,1598625709.655 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 34.945923 min 
2020-08-28T14:41:49.656Z,1598625709.656 [Default:CheckIn:E] Stopped
2020-08-28T14:41:49.656Z,1598625709.656 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-28T14:41:49.656Z,1598625709.656 [Default:CheckIn] Stopped
2020-08-28T14:41:49.656Z,1598625709.656 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-28T14:41:49.656Z,1598625709.656 [Default:CheckIn](INFO): Running loop #6
2020-08-28T14:41:49.656Z,1598625709.656 [Default:CheckIn] Running Loop=6
2020-08-28T14:41:49.656Z,1598625709.656 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-28T14:41:49.656Z,1598625709.656 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-28T14:41:51.668Z,1598625711.668 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,144151.00,A,3648.16317,N,12147.28464,W,1.400,218.08,280820,,,A*78
2020-08-28T14:41:51.673Z,1598625711.673 [NAL9602](INFO): GPS fix at 20200828T144151: (36.802720, -121.788077)
2020-08-28T14:41:51.683Z,1598625711.683 [Default:CheckIn:Read_GPS] Stopped
2020-08-28T14:41:51.683Z,1598625711.683 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-28T14:41:59.396Z,1598625719.396 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20200828T140241/Courier0019.lzma
2020-08-28T14:42:00.399Z,1598625720.399 [DataOverHttps](INFO): Moved sent file to Logs/20200828T140241/Courier0019.lzma.bak
2020-08-28T14:42:00.399Z,1598625720.399 [DataOverHttps](INFO): SBD MOMSN=12624397
2020-08-28T14:42:16.061Z,1598625736.061 [DataOverHttps](INFO): Sending 212 bytes from file Logs/20200828T140241/Express0020.lzma
2020-08-28T14:42:17.062Z,1598625737.062 [DataOverHttps](INFO): Moved sent file to Logs/20200828T140241/Express0020.lzma.bak
2020-08-28T14:42:17.063Z,1598625737.063 [DataOverHttps](INFO): SBD MOMSN=12624400
2020-08-28T14:42:18.352Z,1598625738.352 [Default:CheckIn:Read_Iridium] Stopped
2020-08-28T14:42:18.352Z,1598625738.352 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-28T14:42:18.353Z,1598625738.353 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-28T14:42:23.610Z,1598625743.610 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-28T14:47:18.976Z,1598626038.976 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-28T14:47:18.976Z,1598626038.976 [Default:CheckIn:C.Wait] Stopped
2020-08-28T14:47:18.977Z,1598626038.977 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-28T14:47:18.977Z,1598626038.977 [Default:CheckIn:D] Running Loop=1
2020-08-28T14:47:19.385Z,1598626039.385 [Default:CheckIn:D] Stopped
2020-08-28T14:47:19.385Z,1598626039.385 [Default:CheckIn:E] Running Loop=1
2020-08-28T14:47:19.779Z,1598626039.779 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 40.448120 min 
2020-08-28T14:47:19.779Z,1598626039.779 [Default:CheckIn:E] Stopped
2020-08-28T14:47:19.779Z,1598626039.779 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-28T14:47:19.779Z,1598626039.779 [Default:CheckIn] Stopped
2020-08-28T14:47:19.779Z,1598626039.779 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-28T14:47:19.779Z,1598626039.779 [Default:CheckIn](INFO): Running loop #7
2020-08-28T14:47:19.779Z,1598626039.779 [Default:CheckIn] Running Loop=7
2020-08-28T14:47:19.780Z,1598626039.780 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-28T14:47:19.780Z,1598626039.780 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-28T14:47:21.788Z,1598626041.788 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,144721.00,A,3648.16650,N,12147.28488,W,0.078,220.36,280820,,,A*71
2020-08-28T14:47:21.790Z,1598626041.790 [NAL9602](INFO): GPS fix at 20200828T144721: (36.802775, -121.788081)
2020-08-28T14:47:21.805Z,1598626041.805 [Default:CheckIn:Read_GPS] Stopped
2020-08-28T14:47:21.805Z,1598626041.805 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-28T14:47:28.668Z,1598626048.668 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20200828T140241/Courier0022.lzma
2020-08-28T14:47:29.670Z,1598626049.670 [DataOverHttps](INFO): Moved sent file to Logs/20200828T140241/Courier0022.lzma.bak
2020-08-28T14:47:29.671Z,1598626049.671 [DataOverHttps](INFO): SBD MOMSN=12624404
2020-08-28T14:47:45.372Z,1598626065.372 [DataOverHttps](INFO): Sending 136 bytes from file Logs/20200828T140241/Express0023.lzma
2020-08-28T14:47:46.374Z,1598626066.374 [DataOverHttps](INFO): Moved sent file to Logs/20200828T140241/Express0023.lzma.bak
2020-08-28T14:47:46.375Z,1598626066.375 [DataOverHttps](INFO): SBD MOMSN=12624407
2020-08-28T14:47:47.662Z,1598626067.662 [Default:CheckIn:Read_Iridium] Stopped
2020-08-28T14:47:47.662Z,1598626067.662 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-28T14:47:47.662Z,1598626067.662 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-28T14:47:52.490Z,1598626072.490 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2020-08-28T14:47:52.573Z,1598626072.573 [NAL9602](FAULT): received: 
+CSQ:0

OK830, 2, 0, 0, 0

OK
2020-08-28T14:47:52.573Z,1598626072.573 [NAL9602] Data Fault, FailCount= 1
2020-08-28T14:47:52.573Z,1598626072.573 [NAL9602](ERROR): Data Fault
2020-08-28T14:47:52.642Z,1598626072.642 [CBIT](ERROR): Data Fault in component: NAL9602
2020-08-28T14:47:52.894Z,1598626072.894 [NAL9602](INFO): Powering down
2020-08-28T14:47:53.720Z,1598626073.720 [CBIT](INFO): Clearing failed state for component NAL9602
2020-08-28T14:47:53.720Z,1598626073.720 [NAL9602] No Fault, FailCount= 1
2020-08-28T14:48:23.214Z,1598626103.214 [NAL9602](INFO): Powering up NAL9602
2020-08-28T14:48:34.139Z,1598626114.139 [NAL9602](INFO): NAL9602 initialized
2020-08-28T14:49:05.240Z,1598626145.240 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-28T14:52:48.298Z,1598626368.298 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-28T14:52:48.298Z,1598626368.298 [Default:CheckIn:C.Wait] Stopped
2020-08-28T14:52:48.298Z,1598626368.298 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-28T14:52:48.298Z,1598626368.298 [Default:CheckIn:D] Running Loop=1
2020-08-28T14:52:48.695Z,1598626368.695 [Default:CheckIn:D] Stopped
2020-08-28T14:52:48.695Z,1598626368.695 [Default:CheckIn:E] Running Loop=1
2020-08-28T14:52:49.104Z,1598626369.104 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 45.936617 min 
2020-08-28T14:52:49.104Z,1598626369.104 [Default:CheckIn:E] Stopped
2020-08-28T14:52:49.105Z,1598626369.105 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-28T14:52:49.105Z,1598626369.105 [Default:CheckIn] Stopped
2020-08-28T14:52:49.105Z,1598626369.105 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-28T14:52:49.105Z,1598626369.105 [Default:CheckIn](INFO): Running loop #8
2020-08-28T14:52:49.105Z,1598626369.105 [Default:CheckIn] Running Loop=8
2020-08-28T14:52:49.105Z,1598626369.105 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-28T14:52:49.105Z,1598626369.105 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-28T14:52:53.124Z,1598626373.124 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-08-28T14:57:49.289Z,1598626669.289 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-08-28T14:52:49.1Z
2020-08-28T14:57:49.289Z,1598626669.289 [Default:CheckIn:Read_GPS] Stopped
2020-08-28T14:57:49.289Z,1598626669.289 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-28T14:57:56.920Z,1598626676.920 [DataOverHttps](INFO): Sending 38 bytes from file Logs/20200828T140241/Courier0025.lzma
2020-08-28T14:57:57.922Z,1598626677.922 [DataOverHttps](INFO): Moved sent file to Logs/20200828T140241/Courier0025.lzma.bak
2020-08-28T14:57:57.923Z,1598626677.923 [DataOverHttps](INFO): SBD MOMSN=12624410
2020-08-28T14:58:13.668Z,1598626693.668 [DataOverHttps](INFO): Sending 255 bytes from file Logs/20200828T140241/Express0026.lzma
2020-08-28T14:58:14.670Z,1598626694.670 [DataOverHttps](INFO): Moved sent file to Logs/20200828T140241/Express0026.lzma.bak
2020-08-28T14:58:14.671Z,1598626694.671 [DataOverHttps](INFO): SBD MOMSN=12624412
2020-08-28T14:58:15.948Z,1598626695.948 [Default:CheckIn:Read_Iridium] Stopped
2020-08-28T14:58:15.948Z,1598626695.948 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-28T14:58:15.949Z,1598626695.949 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-28T14:58:21.603Z,1598626701.603 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-28T15:03:16.575Z,1598626996.575 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-28T15:03:16.575Z,1598626996.575 [Default:CheckIn:C.Wait] Stopped
2020-08-28T15:03:16.575Z,1598626996.575 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-28T15:03:16.575Z,1598626996.575 [Default:CheckIn:D] Running Loop=1
2020-08-28T15:03:16.979Z,1598626996.979 [Default:CheckIn:D] Stopped
2020-08-28T15:03:16.979Z,1598626996.979 [Default:CheckIn:E] Running Loop=1
2020-08-28T15:03:17.379Z,1598626997.379 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 56.408020 min 
2020-08-28T15:03:17.379Z,1598626997.379 [Default:CheckIn:E] Stopped
2020-08-28T15:03:17.379Z,1598626997.379 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-28T15:03:17.380Z,1598626997.380 [Default:CheckIn] Stopped
2020-08-28T15:03:17.380Z,1598626997.380 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-28T15:03:17.380Z,1598626997.380 [Default:CheckIn](INFO): Running loop #9
2020-08-28T15:03:17.380Z,1598626997.380 [Default:CheckIn] Running Loop=9
2020-08-28T15:03:17.380Z,1598626997.380 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-28T15:03:17.380Z,1598626997.380 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-28T15:03:18.990Z,1598626998.990 [NAL9602](FAULT): GPS failed to acquire within timeout.
2020-08-28T15:03:18.990Z,1598626998.990 [NAL9602] Data Fault, FailCount= 1
2020-08-28T15:03:18.990Z,1598626998.990 [NAL9602](ERROR): Data Fault
2020-08-28T15:03:19.009Z,1598626999.009 [CBIT](ERROR): Data Fault in component: NAL9602
2020-08-28T15:03:19.390Z,1598626999.390 [NAL9602](INFO): Powering down
2020-08-28T15:03:20.221Z,1598627000.221 [CBIT](INFO): Clearing failed state for component NAL9602
2020-08-28T15:03:20.221Z,1598627000.221 [NAL9602] No Fault, FailCount= 1
2020-08-28T15:03:49.688Z,1598627029.688 [NAL9602](INFO): Powering up NAL9602
2020-08-28T15:04:00.610Z,1598627040.610 [NAL9602](INFO): NAL9602 initialized
2020-08-28T15:08:17.587Z,1598627297.587 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-08-28T15:03:17.4Z
2020-08-28T15:08:17.587Z,1598627297.587 [Default:CheckIn:Read_GPS] Stopped
2020-08-28T15:08:17.587Z,1598627297.587 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-28T15:08:27.560Z,1598627307.560 [DataOverHttps](INFO): Sending 38 bytes from file Logs/20200828T140241/Courier0028.lzma
2020-08-28T15:08:28.562Z,1598627308.562 [DataOverHttps](INFO): Moved sent file to Logs/20200828T140241/Courier0028.lzma.bak
2020-08-28T15:08:28.563Z,1598627308.563 [DataOverHttps](INFO): SBD MOMSN=12624417
2020-08-28T15:08:44.504Z,1598627324.504 [DataOverHttps](INFO): Sending 179 bytes from file Logs/20200828T140241/Express0029.lzma
2020-08-28T15:08:45.507Z,1598627325.507 [DataOverHttps](INFO): Moved sent file to Logs/20200828T140241/Express0029.lzma.bak
2020-08-28T15:08:45.507Z,1598627325.507 [DataOverHttps](INFO): SBD MOMSN=12624419
2020-08-28T15:08:46.722Z,1598627326.722 [Default:CheckIn:Read_Iridium] Stopped
2020-08-28T15:08:46.722Z,1598627326.722 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-28T15:08:46.722Z,1598627326.722 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-28T15:09:04.446Z,1598627344.446 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-08-28T15:09:35.144Z,1598627375.144 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-28T15:13:47.496Z,1598627627.496 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-28T15:13:47.496Z,1598627627.496 [Default:CheckIn:C.Wait] Stopped
2020-08-28T15:13:47.496Z,1598627627.496 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-28T15:13:47.496Z,1598627627.496 [Default:CheckIn:D] Running Loop=1
2020-08-28T15:13:47.884Z,1598627627.884 [Default:CheckIn:D] Stopped
2020-08-28T15:13:47.884Z,1598627627.884 [Default:CheckIn:E] Running Loop=1
2020-08-28T15:13:48.288Z,1598627628.288 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 66.923096 min 
2020-08-28T15:13:48.288Z,1598627628.288 [Default:CheckIn:E] Stopped
2020-08-28T15:13:48.288Z,1598627628.288 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-28T15:13:48.288Z,1598627628.288 [Default:CheckIn] Stopped
2020-08-28T15:13:48.288Z,1598627628.288 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-28T15:13:48.288Z,1598627628.288 [Default:CheckIn](INFO): Running loop #10
2020-08-28T15:13:48.288Z,1598627628.288 [Default:CheckIn] Running Loop=10
2020-08-28T15:13:48.288Z,1598627628.288 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-28T15:13:48.289Z,1598627628.289 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-28T15:13:50.295Z,1598627630.295 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,151350.00,A,3648.17007,N,12147.28279,W,0.447,0.00,280820,,,A*77
2020-08-28T15:13:50.298Z,1598627630.298 [NAL9602](INFO): GPS fix at 20200828T151350: (36.802835, -121.788046)
2020-08-28T15:13:50.308Z,1598627630.308 [Default:CheckIn:Read_GPS] Stopped
2020-08-28T15:13:50.308Z,1598627630.308 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-28T15:13:57.404Z,1598627637.404 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20200828T140241/Courier0031.lzma
2020-08-28T15:13:58.406Z,1598627638.406 [DataOverHttps](INFO): Moved sent file to Logs/20200828T140241/Courier0031.lzma.bak
2020-08-28T15:13:58.407Z,1598627638.407 [DataOverHttps](INFO): SBD MOMSN=12624423
2020-08-28T15:14:14.376Z,1598627654.376 [DataOverHttps](INFO): Sending 214 bytes from file Logs/20200828T140241/Express0032.lzma
2020-08-28T15:14:15.378Z,1598627655.378 [DataOverHttps](INFO): Moved sent file to Logs/20200828T140241/Express0032.lzma.bak
2020-08-28T15:14:15.379Z,1598627655.379 [DataOverHttps](INFO): SBD MOMSN=12624426
2020-08-28T15:14:16.572Z,1598627656.572 [Default:CheckIn:Read_Iridium] Stopped
2020-08-28T15:14:16.572Z,1598627656.572 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-28T15:14:16.572Z,1598627656.572 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-28T15:14:20.998Z,1598627660.998 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2020-08-28T15:14:21.077Z,1598627661.077 [NAL9602](FAULT): received: 
+CSQ:0

OK830, 2, 0, 0, 0

OK
2020-08-28T15:14:21.077Z,1598627661.077 [NAL9602] Data Fault, FailCount= 2
2020-08-28T15:14:21.077Z,1598627661.077 [NAL9602](ERROR): Data Fault
2020-08-28T15:14:21.182Z,1598627661.182 [CBIT](ERROR): Data Fault in component: NAL9602
2020-08-28T15:14:21.410Z,1598627661.410 [NAL9602](INFO): Powering down
2020-08-28T15:14:22.335Z,1598627662.335 [CBIT](INFO): Clearing failed state for component NAL9602
2020-08-28T15:14:22.335Z,1598627662.335 [NAL9602] No Fault, FailCount= 2
2020-08-28T15:14:51.722Z,1598627691.722 [NAL9602](INFO): Powering up NAL9602
2020-08-28T15:15:02.623Z,1598627702.623 [NAL9602](INFO): NAL9602 initialized
2020-08-28T15:15:33.730Z,1598627733.730 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-28T15:18:00.410Z,1598627880.410 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2020-08-28T15:18:00.413Z,1598627880.413 [BPC1](INFO): Received data from all battery sticks.
2020-08-28T15:19:17.171Z,1598627957.171 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-28T15:19:17.171Z,1598627957.171 [Default:CheckIn:C.Wait] Stopped
2020-08-28T15:19:17.171Z,1598627957.171 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-28T15:19:17.171Z,1598627957.171 [Default:CheckIn:D] Running Loop=1
2020-08-28T15:19:17.584Z,1598627957.584 [Default:CheckIn:D] Stopped
2020-08-28T15:19:17.584Z,1598627957.584 [Default:CheckIn:E] Running Loop=1
2020-08-28T15:19:17.975Z,1598627957.975 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 72.418107 min 
2020-08-28T15:19:17.975Z,1598627957.975 [Default:CheckIn:E] Stopped
2020-08-28T15:19:17.976Z,1598627957.976 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-28T15:19:17.976Z,1598627957.976 [Default:CheckIn] Stopped
2020-08-28T15:19:17.976Z,1598627957.976 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-28T15:19:17.976Z,1598627957.976 [Default:CheckIn](INFO): Running loop #11
2020-08-28T15:19:17.976Z,1598627957.976 [Default:CheckIn] Running Loop=11
2020-08-28T15:19:17.976Z,1598627957.976 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-28T15:19:17.976Z,1598627957.976 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-28T15:19:22.414Z,1598627962.414 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-08-28T15:19:29.284Z,1598627969.284 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,151928.00,A,3648.17382,N,12147.28519,W,0.039,0.00,280820,,,A*70
2020-08-28T15:19:29.286Z,1598627969.286 [NAL9602](INFO): GPS fix at 20200828T151928: (36.802897, -121.788087)
2020-08-28T15:19:29.321Z,1598627969.321 [Default:CheckIn:Read_GPS] Stopped
2020-08-28T15:19:29.321Z,1598627969.321 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-28T15:19:36.904Z,1598627976.904 [DataOverHttps](INFO): Sending 85 bytes from file Logs/20200828T140241/Courier0034.lzma
2020-08-28T15:19:37.906Z,1598627977.906 [DataOverHttps](INFO): Moved sent file to Logs/20200828T140241/Courier0034.lzma.bak
2020-08-28T15:19:37.907Z,1598627977.907 [DataOverHttps](INFO): SBD MOMSN=12624430
2020-08-28T15:19:53.593Z,1598627993.593 [DataOverHttps](INFO): Sending 251 bytes from file Logs/20200828T140241/Express0035.lzma
2020-08-28T15:19:54.595Z,1598627994.595 [DataOverHttps](INFO): Moved sent file to Logs/20200828T140241/Express0035.lzma.bak
2020-08-28T15:19:54.595Z,1598627994.595 [DataOverHttps](INFO): SBD MOMSN=12624433
2020-08-28T15:19:55.955Z,1598627995.955 [Default:CheckIn:Read_Iridium] Stopped
2020-08-28T15:19:55.955Z,1598627995.955 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-28T15:19:55.955Z,1598627995.955 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-28T15:20:01.598Z,1598628001.598 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-28T15:24:56.593Z,1598628296.593 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-28T15:24:56.593Z,1598628296.593 [Default:CheckIn:C.Wait] Stopped
2020-08-28T15:24:56.593Z,1598628296.593 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-28T15:24:56.593Z,1598628296.593 [Default:CheckIn:D] Running Loop=1
2020-08-28T15:24:56.940Z,1598628296.940 [Default:CheckIn:D] Stopped
2020-08-28T15:24:56.940Z,1598628296.940 [Default:CheckIn:E] Running Loop=1
2020-08-28T15:24:57.339Z,1598628297.339 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 78.074023 min 
2020-08-28T15:24:57.339Z,1598628297.339 [Default:CheckIn:E] Stopped
2020-08-28T15:24:57.339Z,1598628297.339 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-28T15:24:57.339Z,1598628297.339 [Default:CheckIn] Stopped
2020-08-28T15:24:57.340Z,1598628297.340 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-28T15:24:57.340Z,1598628297.340 [Default:CheckIn](INFO): Running loop #12
2020-08-28T15:24:57.340Z,1598628297.340 [Default:CheckIn] Running Loop=12
2020-08-28T15:24:57.340Z,1598628297.340 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-28T15:24:57.340Z,1598628297.340 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-28T15:24:59.352Z,1598628299.352 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,152459.00,A,3648.16948,N,12147.28273,W,0.486,181.49,280820,,,A*7B
2020-08-28T15:24:59.364Z,1598628299.364 [NAL9602](INFO): GPS fix at 20200828T152459: (36.802825, -121.788045)
2020-08-28T15:24:59.374Z,1598628299.374 [Default:CheckIn:Read_GPS] Stopped
2020-08-28T15:24:59.374Z,1598628299.374 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-28T15:25:06.500Z,1598628306.500 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20200828T140241/Courier0037.lzma
2020-08-28T15:25:07.502Z,1598628307.503 [DataOverHttps](INFO): Moved sent file to Logs/20200828T140241/Courier0037.lzma.bak
2020-08-28T15:25:07.503Z,1598628307.503 [DataOverHttps](INFO): SBD MOMSN=12624438
2020-08-28T15:25:23.124Z,1598628323.124 [DataOverHttps](INFO): Sending 135 bytes from file Logs/20200828T140241/Express0038.lzma
2020-08-28T15:25:24.127Z,1598628324.127 [DataOverHttps](INFO): Moved sent file to Logs/20200828T140241/Express0038.lzma.bak
2020-08-28T15:25:24.127Z,1598628324.127 [DataOverHttps](INFO): SBD MOMSN=12624441
2020-08-28T15:25:25.215Z,1598628325.215 [Default:CheckIn:Read_Iridium] Stopped
2020-08-28T15:25:25.215Z,1598628325.215 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-28T15:25:25.216Z,1598628325.216 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-28T15:30:01.554Z,1598628601.554 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-08-28T15:30:25.816Z,1598628625.816 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-28T15:30:25.816Z,1598628625.816 [Default:CheckIn:C.Wait] Stopped
2020-08-28T15:30:25.816Z,1598628625.816 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-28T15:30:25.816Z,1598628625.816 [Default:CheckIn:D] Running Loop=1
2020-08-28T15:30:26.211Z,1598628626.211 [Default:CheckIn:D] Stopped
2020-08-28T15:30:26.211Z,1598628626.211 [Default:CheckIn:E] Running Loop=1
2020-08-28T15:30:26.610Z,1598628626.610 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 83.561882 min 
2020-08-28T15:30:26.610Z,1598628626.610 [Default:CheckIn:E] Stopped
2020-08-28T15:30:26.610Z,1598628626.610 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-28T15:30:26.610Z,1598628626.610 [Default:CheckIn] Stopped
2020-08-28T15:30:26.610Z,1598628626.610 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-28T15:30:26.610Z,1598628626.610 [Default:CheckIn](INFO): Running loop #13
2020-08-28T15:30:26.611Z,1598628626.611 [Default:CheckIn] Running Loop=13
2020-08-28T15:30:26.611Z,1598628626.611 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-28T15:30:26.611Z,1598628626.611 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-28T15:30:28.624Z,1598628628.624 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,153028.00,A,3648.17262,N,12147.28031,W,1.380,179.31,280820,,,A*76
2020-08-28T15:30:28.626Z,1598628628.626 [NAL9602](INFO): GPS fix at 20200828T153028: (36.802877, -121.788005)
2020-08-28T15:30:28.657Z,1598628628.657 [Default:CheckIn:Read_GPS] Stopped
2020-08-28T15:30:28.657Z,1598628628.657 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-28T15:30:36.224Z,1598628636.224 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20200828T140241/Courier0040.lzma
2020-08-28T15:30:37.227Z,1598628637.227 [DataOverHttps](INFO): Moved sent file to Logs/20200828T140241/Courier0040.lzma.bak
2020-08-28T15:30:37.227Z,1598628637.227 [DataOverHttps](INFO): SBD MOMSN=12624444
2020-08-28T15:30:52.873Z,1598628652.873 [DataOverHttps](INFO): Sending 211 bytes from file Logs/20200828T140241/Express0041.lzma
2020-08-28T15:30:53.875Z,1598628653.875 [DataOverHttps](INFO): Moved sent file to Logs/20200828T140241/Express0041.lzma.bak
2020-08-28T15:30:53.875Z,1598628653.875 [DataOverHttps](INFO): SBD MOMSN=12624447
2020-08-28T15:30:54.911Z,1598628654.911 [Default:CheckIn:Read_Iridium] Stopped
2020-08-28T15:30:54.911Z,1598628654.911 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-28T15:30:54.911Z,1598628654.911 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-28T15:31:00.966Z,1598628660.966 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-28T15:35:55.506Z,1598628955.506 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-28T15:35:55.506Z,1598628955.506 [Default:CheckIn:C.Wait] Stopped
2020-08-28T15:35:55.507Z,1598628955.507 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-28T15:35:55.507Z,1598628955.507 [Default:CheckIn:D] Running Loop=1
2020-08-28T15:35:55.899Z,1598628955.899 [Default:CheckIn:D] Stopped
2020-08-28T15:35:55.899Z,1598628955.899 [Default:CheckIn:E] Running Loop=1
2020-08-28T15:35:56.298Z,1598628956.298 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 89.056681 min 
2020-08-28T15:35:56.299Z,1598628956.299 [Default:CheckIn:E] Stopped
2020-08-28T15:35:56.299Z,1598628956.299 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-28T15:35:56.299Z,1598628956.299 [Default:CheckIn] Stopped
2020-08-28T15:35:56.299Z,1598628956.299 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-28T15:35:56.299Z,1598628956.299 [Default:CheckIn](INFO): Running loop #14
2020-08-28T15:35:56.299Z,1598628956.299 [Default:CheckIn] Running Loop=14
2020-08-28T15:35:56.299Z,1598628956.299 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-28T15:35:56.299Z,1598628956.299 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-28T15:35:58.327Z,1598628958.327 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,153558.00,A,3648.16307,N,12147.28071,W,0.369,150.99,280820,,,A*7C
2020-08-28T15:35:58.330Z,1598628958.330 [NAL9602](INFO): GPS fix at 20200828T153558: (36.802718, -121.788012)
2020-08-28T15:35:58.340Z,1598628958.340 [Default:CheckIn:Read_GPS] Stopped
2020-08-28T15:35:58.340Z,1598628958.340 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-28T15:36:05.596Z,1598628965.596 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20200828T140241/Courier0043.lzma
2020-08-28T15:36:06.599Z,1598628966.599 [DataOverHttps](INFO): Moved sent file to Logs/20200828T140241/Courier0043.lzma.bak
2020-08-28T15:36:06.599Z,1598628966.599 [DataOverHttps](INFO): SBD MOMSN=12624451
2020-08-28T15:36:22.992Z,1598628982.992 [DataOverHttps](INFO): Sending 137 bytes from file Logs/20200828T140241/Express0044.lzma
2020-08-28T15:36:23.995Z,1598628983.995 [DataOverHttps](INFO): Moved sent file to Logs/20200828T140241/Express0044.lzma.bak
2020-08-28T15:36:23.995Z,1598628983.995 [DataOverHttps](INFO): SBD MOMSN=12624454
2020-08-28T15:36:25.019Z,1598628985.019 [Default:CheckIn:Read_Iridium] Stopped
2020-08-28T15:36:25.019Z,1598628985.019 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-28T15:36:25.019Z,1598628985.019 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-28T15:36:29.022Z,1598628989.022 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2020-08-28T15:36:29.105Z,1598628989.105 [NAL9602](FAULT): received: 
+CSQ:0

OK830, 2, 0, 0, 0

OK
2020-08-28T15:36:29.105Z,1598628989.105 [NAL9602] Data Fault, FailCount= 1
2020-08-28T15:36:29.105Z,1598628989.105 [NAL9602](ERROR): Data Fault
2020-08-28T15:36:29.181Z,1598628989.181 [CBIT](ERROR): Data Fault in component: NAL9602
2020-08-28T15:36:29.431Z,1598628989.431 [NAL9602](INFO): Powering down
2020-08-28T15:36:30.302Z,1598628990.302 [CBIT](INFO): Clearing failed state for component NAL9602
2020-08-28T15:36:30.302Z,1598628990.302 [NAL9602] No Fault, FailCount= 1
2020-08-28T15:36:59.726Z,1598629019.726 [NAL9602](INFO): Powering up NAL9602
2020-08-28T15:37:10.638Z,1598629030.638 [NAL9602](INFO): NAL9602 initialized
2020-08-28T15:37:41.740Z,1598629061.740 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-28T15:41:25.572Z,1598629285.572 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-28T15:41:25.572Z,1598629285.572 [Default:CheckIn:C.Wait] Stopped
2020-08-28T15:41:25.572Z,1598629285.572 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-28T15:41:25.572Z,1598629285.572 [Default:CheckIn:D] Running Loop=1
2020-08-28T15:41:25.979Z,1598629285.979 [Default:CheckIn:D] Stopped
2020-08-28T15:41:25.979Z,1598629285.979 [Default:CheckIn:E] Running Loop=1
2020-08-28T15:41:26.389Z,1598629286.389 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 94.558024 min 
2020-08-28T15:41:26.389Z,1598629286.389 [Default:CheckIn:E] Stopped
2020-08-28T15:41:26.389Z,1598629286.389 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-28T15:41:26.389Z,1598629286.389 [Default:CheckIn] Stopped
2020-08-28T15:41:26.389Z,1598629286.389 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-28T15:41:26.389Z,1598629286.389 [Default:CheckIn](INFO): Running loop #15
2020-08-28T15:41:26.390Z,1598629286.390 [Default:CheckIn] Running Loop=15
2020-08-28T15:41:26.390Z,1598629286.390 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-28T15:41:26.390Z,1598629286.390 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-28T15:41:30.414Z,1598629290.414 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-08-28T15:44:28.176Z,1598629468.176 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,154427.00,A,3648.16762,N,12147.28348,W,0.350,0.00,280820,,,A*72
2020-08-28T15:44:28.178Z,1598629468.178 [NAL9602](INFO): GPS fix at 20200828T154427: (36.802794, -121.788058)
2020-08-28T15:44:28.188Z,1598629468.188 [Default:CheckIn:Read_GPS] Stopped
2020-08-28T15:44:28.188Z,1598629468.188 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-28T15:44:35.884Z,1598629475.884 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20200828T140241/Courier0046.lzma
2020-08-28T15:44:36.887Z,1598629476.887 [DataOverHttps](INFO): Moved sent file to Logs/20200828T140241/Courier0046.lzma.bak
2020-08-28T15:44:36.887Z,1598629476.887 [DataOverHttps](INFO): SBD MOMSN=12624457
2020-08-28T15:44:52.441Z,1598629492.441 [DataOverHttps](INFO): Sending 255 bytes from file Logs/20200828T140241/Express0047.lzma
2020-08-28T15:44:53.443Z,1598629493.443 [DataOverHttps](INFO): Moved sent file to Logs/20200828T140241/Express0047.lzma.bak
2020-08-28T15:44:53.443Z,1598629493.443 [DataOverHttps](INFO): SBD MOMSN=12624460
2020-08-28T15:44:54.847Z,1598629494.847 [Default:CheckIn:Read_Iridium] Stopped
2020-08-28T15:44:54.847Z,1598629494.847 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-28T15:44:54.847Z,1598629494.847 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-28T15:45:00.898Z,1598629500.898 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-28T15:49:55.485Z,1598629795.485 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-28T15:49:55.485Z,1598629795.485 [Default:CheckIn:C.Wait] Stopped
2020-08-28T15:49:55.485Z,1598629795.485 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-28T15:49:55.485Z,1598629795.485 [Default:CheckIn:D] Running Loop=1
2020-08-28T15:49:55.903Z,1598629795.903 [Default:CheckIn:D] Stopped
2020-08-28T15:49:55.903Z,1598629795.903 [Default:CheckIn:E] Running Loop=1
2020-08-28T15:49:56.286Z,1598629796.286 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 103.056746 min 
2020-08-28T15:49:56.287Z,1598629796.287 [Default:CheckIn:E] Stopped
2020-08-28T15:49:56.287Z,1598629796.287 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-28T15:49:56.287Z,1598629796.287 [Default:CheckIn] Stopped
2020-08-28T15:49:56.287Z,1598629796.287 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-28T15:49:56.287Z,1598629796.287 [Default:CheckIn](INFO): Running loop #16
2020-08-28T15:49:56.287Z,1598629796.287 [Default:CheckIn] Running Loop=16
2020-08-28T15:49:56.287Z,1598629796.287 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-28T15:49:56.287Z,1598629796.287 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-28T15:49:58.304Z,1598629798.304 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,154958.00,A,3648.16670,N,12147.28278,W,0.039,0.00,280820,,,A*7B
2020-08-28T15:49:58.306Z,1598629798.306 [NAL9602](INFO): GPS fix at 20200828T154958: (36.802778, -121.788046)
2020-08-28T15:49:58.316Z,1598629798.316 [Default:CheckIn:Read_GPS] Stopped
2020-08-28T15:49:58.316Z,1598629798.316 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-28T15:50:05.144Z,1598629805.144 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20200828T140241/Courier0049.lzma
2020-08-28T15:50:06.147Z,1598629806.147 [DataOverHttps](INFO): Moved sent file to Logs/20200828T140241/Courier0049.lzma.bak
2020-08-28T15:50:06.147Z,1598629806.147 [DataOverHttps](INFO): SBD MOMSN=12624465
2020-08-28T15:50:16.881Z,1598629816.881 [NAL9602](INFO): SBD MO Status=2, MOMSN=22830, MT Status=2, MTMSN=0
2020-08-28T15:50:16.882Z,1598629816.882 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-08-28T15:50:21.905Z,1598629821.905 [DataOverHttps](INFO): Sending 137 bytes from file Logs/20200828T140241/Express0050.lzma
2020-08-28T15:50:22.907Z,1598629822.907 [DataOverHttps](INFO): Moved sent file to Logs/20200828T140241/Express0050.lzma.bak
2020-08-28T15:50:22.907Z,1598629822.907 [DataOverHttps](INFO): SBD MOMSN=12624469
2020-08-28T15:50:24.176Z,1598629824.176 [Default:CheckIn:Read_Iridium] Stopped
2020-08-28T15:50:24.176Z,1598629824.176 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-28T15:50:24.176Z,1598629824.176 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-28T15:52:46.771Z,1598629966.771 [NAL9602](INFO): SBD MO Status=2, MOMSN=22830, MT Status=2, MTMSN=0
2020-08-28T15:52:46.772Z,1598629966.772 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-08-28T15:55:00.490Z,1598630100.490 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-08-28T15:55:24.761Z,1598630124.761 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-28T15:55:24.761Z,1598630124.761 [Default:CheckIn:C.Wait] Stopped
2020-08-28T15:55:24.761Z,1598630124.761 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-28T15:55:24.762Z,1598630124.762 [Default:CheckIn:D] Running Loop=1
2020-08-28T15:55:25.147Z,1598630125.147 [Default:CheckIn:D] Stopped
2020-08-28T15:55:25.147Z,1598630125.147 [Default:CheckIn:E] Running Loop=1
2020-08-28T15:55:25.548Z,1598630125.548 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 108.544149 min 
2020-08-28T15:55:25.548Z,1598630125.548 [Default:CheckIn:E] Stopped
2020-08-28T15:55:25.549Z,1598630125.549 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-28T15:55:25.549Z,1598630125.549 [Default:CheckIn] Stopped
2020-08-28T15:55:25.549Z,1598630125.549 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-28T15:55:25.549Z,1598630125.549 [Default:CheckIn](INFO): Running loop #17
2020-08-28T15:55:25.549Z,1598630125.549 [Default:CheckIn] Running Loop=17
2020-08-28T15:55:25.549Z,1598630125.549 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-28T15:55:25.549Z,1598630125.549 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-28T15:55:27.564Z,1598630127.564 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155527.00,A,3648.16917,N,12147.28018,W,0.058,0.00,280820,,,A*73
2020-08-28T15:55:27.576Z,1598630127.576 [NAL9602](INFO): GPS fix at 20200828T155527: (36.802819, -121.788003)
2020-08-28T15:55:27.586Z,1598630127.586 [Default:CheckIn:Read_GPS] Stopped
2020-08-28T15:55:27.586Z,1598630127.586 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-28T15:55:35.216Z,1598630135.216 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20200828T140241/Courier0052.lzma
2020-08-28T15:55:36.218Z,1598630136.218 [DataOverHttps](INFO): Moved sent file to Logs/20200828T140241/Courier0052.lzma.bak
2020-08-28T15:55:36.219Z,1598630136.219 [DataOverHttps](INFO): SBD MOMSN=12624473
2020-08-28T15:55:51.892Z,1598630151.892 [DataOverHttps](INFO): Sending 216 bytes from file Logs/20200828T140241/Express0053.lzma
2020-08-28T15:55:52.895Z,1598630152.895 [DataOverHttps](INFO): Moved sent file to Logs/20200828T140241/Express0053.lzma.bak
2020-08-28T15:55:52.895Z,1598630152.895 [DataOverHttps](INFO): SBD MOMSN=12624476
2020-08-28T15:55:54.235Z,1598630154.235 [Default:CheckIn:Read_Iridium] Stopped
2020-08-28T15:55:54.235Z,1598630154.235 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-28T15:55:54.235Z,1598630154.235 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-28T15:55:59.876Z,1598630159.876 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-28T16:00:54.811Z,1598630454.811 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-28T16:00:54.811Z,1598630454.811 [Default:CheckIn:C.Wait] Stopped
2020-08-28T16:00:54.811Z,1598630454.811 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-28T16:00:54.811Z,1598630454.811 [Default:CheckIn:D] Running Loop=1
2020-08-28T16:00:55.220Z,1598630455.220 [Default:CheckIn:D] Stopped
2020-08-28T16:00:55.220Z,1598630455.220 [Default:CheckIn:E] Running Loop=1
2020-08-28T16:00:55.641Z,1598630455.641 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 114.045369 min 
2020-08-28T16:00:55.641Z,1598630455.641 [Default:CheckIn:E] Stopped
2020-08-28T16:00:55.641Z,1598630455.641 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-28T16:00:55.641Z,1598630455.641 [Default:CheckIn] Stopped
2020-08-28T16:00:55.641Z,1598630455.641 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-28T16:00:55.641Z,1598630455.641 [Default:CheckIn](INFO): Running loop #18
2020-08-28T16:00:55.642Z,1598630455.642 [Default:CheckIn] Running Loop=18
2020-08-28T16:00:55.642Z,1598630455.642 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-28T16:00:55.642Z,1598630455.642 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-28T16:00:57.628Z,1598630457.628 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160057.00,A,3648.17080,N,12147.27903,W,0.544,0.00,280820,,,A*75
2020-08-28T16:00:57.631Z,1598630457.631 [NAL9602](INFO): GPS fix at 20200828T160057: (36.802847, -121.787984)
2020-08-28T16:00:57.645Z,1598630457.645 [Default:CheckIn:Read_GPS] Stopped
2020-08-28T16:00:57.646Z,1598630457.646 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-28T16:01:04.592Z,1598630464.592 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20200828T140241/Courier0055.lzma
2020-08-28T16:01:05.595Z,1598630465.595 [DataOverHttps](INFO): Moved sent file to Logs/20200828T140241/Courier0055.lzma.bak
2020-08-28T16:01:05.595Z,1598630465.595 [DataOverHttps](INFO): SBD MOMSN=12624482
2020-08-28T16:01:21.300Z,1598630481.300 [DataOverHttps](INFO): Sending 137 bytes from file Logs/20200828T140241/Express0056.lzma
2020-08-28T16:01:22.303Z,1598630482.303 [DataOverHttps](INFO): Moved sent file to Logs/20200828T140241/Express0056.lzma.bak
2020-08-28T16:01:22.303Z,1598630482.303 [DataOverHttps](INFO): SBD MOMSN=12624485
2020-08-28T16:01:23.490Z,1598630483.490 [Default:CheckIn:Read_Iridium] Stopped
2020-08-28T16:01:23.490Z,1598630483.490 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-28T16:01:23.490Z,1598630483.490 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-28T16:05:59.818Z,1598630759.818 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-08-28T16:06:24.133Z,1598630784.133 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-28T16:06:24.133Z,1598630784.133 [Default:CheckIn:C.Wait] Stopped
2020-08-28T16:06:24.133Z,1598630784.133 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-28T16:06:24.133Z,1598630784.133 [Default:CheckIn:D] Running Loop=1
2020-08-28T16:06:24.510Z,1598630784.510 [Default:CheckIn:D] Stopped
2020-08-28T16:06:24.510Z,1598630784.510 [Default:CheckIn:E] Running Loop=1
2020-08-28T16:06:24.920Z,1598630784.920 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 119.533537 min 
2020-08-28T16:06:24.920Z,1598630784.920 [Default:CheckIn:E] Stopped
2020-08-28T16:06:24.945Z,1598630784.945 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-28T16:06:24.945Z,1598630784.945 [Default:CheckIn] Stopped
2020-08-28T16:06:24.945Z,1598630784.945 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-28T16:06:24.945Z,1598630784.945 [Default:CheckIn](INFO): Running loop #19
2020-08-28T16:06:24.945Z,1598630784.945 [Default:CheckIn] Running Loop=19
2020-08-28T16:06:24.945Z,1598630784.945 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-28T16:06:24.945Z,1598630784.945 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-28T16:06:26.906Z,1598630786.906 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160626.00,A,3648.16750,N,12147.28514,W,0.214,294.55,280820,,,A*76
2020-08-28T16:06:26.908Z,1598630786.908 [NAL9602](INFO): GPS fix at 20200828T160626: (36.802792, -121.788086)
2020-08-28T16:06:26.925Z,1598630786.925 [Default:CheckIn:Read_GPS] Stopped
2020-08-28T16:06:26.925Z,1598630786.925 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-28T16:06:34.088Z,1598630794.088 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20200828T140241/Courier0058.lzma
2020-08-28T16:06:35.091Z,1598630795.091 [DataOverHttps](INFO): Moved sent file to Logs/20200828T140241/Courier0058.lzma.bak
2020-08-28T16:06:35.091Z,1598630795.091 [DataOverHttps](INFO): SBD MOMSN=12624488
2020-08-28T16:06:50.749Z,1598630810.749 [DataOverHttps](INFO): Sending 213 bytes from file Logs/20200828T140241/Express0059.lzma
2020-08-28T16:06:51.751Z,1598630811.751 [DataOverHttps](INFO): Moved sent file to Logs/20200828T140241/Express0059.lzma.bak
2020-08-28T16:06:51.751Z,1598630811.751 [DataOverHttps](INFO): SBD MOMSN=12624491
2020-08-28T16:06:52.782Z,1598630812.782 [Default:CheckIn:Read_Iridium] Stopped
2020-08-28T16:06:52.782Z,1598630812.782 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-28T16:06:52.782Z,1598630812.782 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-28T16:06:58.816Z,1598630818.816 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-28T16:11:53.356Z,1598631113.356 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-28T16:11:53.356Z,1598631113.356 [Default:CheckIn:C.Wait] Stopped
2020-08-28T16:11:53.357Z,1598631113.357 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-28T16:11:53.357Z,1598631113.357 [Default:CheckIn:D] Running Loop=1
2020-08-28T16:11:53.766Z,1598631113.766 [Default:CheckIn:D] Stopped
2020-08-28T16:11:53.766Z,1598631113.766 [Default:CheckIn:E] Running Loop=1
2020-08-28T16:11:54.167Z,1598631114.167 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 125.021134 min 
2020-08-28T16:11:54.167Z,1598631114.167 [Default:CheckIn:E] Stopped
2020-08-28T16:11:54.167Z,1598631114.167 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-28T16:11:54.168Z,1598631114.168 [Default:CheckIn] Stopped
2020-08-28T16:11:54.168Z,1598631114.168 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-28T16:11:54.168Z,1598631114.168 [Default:CheckIn](INFO): Running loop #20
2020-08-28T16:11:54.168Z,1598631114.168 [Default:CheckIn] Running Loop=20
2020-08-28T16:11:54.168Z,1598631114.168 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-28T16:11:54.168Z,1598631114.168 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-28T16:11:56.180Z,1598631116.180 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,161156.00,A,3648.16739,N,12147.28280,W,0.253,294.55,280820,,,A*71
2020-08-28T16:11:56.182Z,1598631116.182 [NAL9602](INFO): GPS fix at 20200828T161156: (36.802790, -121.788047)
2020-08-28T16:11:56.192Z,1598631116.192 [Default:CheckIn:Read_GPS] Stopped
2020-08-28T16:11:56.192Z,1598631116.192 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-28T16:12:03.168Z,1598631123.168 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20200828T140241/Courier0061.lzma
2020-08-28T16:12:04.171Z,1598631124.171 [DataOverHttps](INFO): Moved sent file to Logs/20200828T140241/Courier0061.lzma.bak
2020-08-28T16:12:04.171Z,1598631124.171 [DataOverHttps](INFO): SBD MOMSN=12624496
2020-08-28T16:12:19.860Z,1598631139.860 [DataOverHttps](INFO): Sending 135 bytes from file Logs/20200828T140241/Express0062.lzma
2020-08-28T16:12:20.863Z,1598631140.863 [DataOverHttps](INFO): Moved sent file to Logs/20200828T140241/Express0062.lzma.bak
2020-08-28T16:12:20.863Z,1598631140.863 [DataOverHttps](INFO): SBD MOMSN=12624499
2020-08-28T16:12:22.066Z,1598631142.066 [Default:CheckIn:Read_Iridium] Stopped
2020-08-28T16:12:22.066Z,1598631142.066 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-28T16:12:22.067Z,1598631142.067 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-28T16:12:26.886Z,1598631146.886 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2020-08-28T16:12:26.969Z,1598631146.969 [NAL9602](FAULT): received: 
+CSQ:0

OK830, 2, 0, 0, 0

OK
2020-08-28T16:12:26.969Z,1598631146.969 [NAL9602] Data Fault, FailCount= 1
2020-08-28T16:12:26.969Z,1598631146.969 [NAL9602](ERROR): Data Fault
2020-08-28T16:12:27.061Z,1598631147.061 [CBIT](ERROR): Data Fault in component: NAL9602
2020-08-28T16:12:27.290Z,1598631147.290 [NAL9602](INFO): Powering down
2020-08-28T16:12:28.136Z,1598631148.136 [CBIT](INFO): Clearing failed state for component NAL9602
2020-08-28T16:12:28.136Z,1598631148.136 [NAL9602] No Fault, FailCount= 1
2020-08-28T16:12:57.590Z,1598631177.590 [NAL9602](INFO): Powering up NAL9602
2020-08-28T16:13:08.502Z,1598631188.502 [NAL9602](INFO): NAL9602 initialized
2020-08-28T16:13:39.614Z,1598631219.614 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-28T16:17:22.627Z,1598631442.627 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-28T16:17:22.628Z,1598631442.628 [Default:CheckIn:C.Wait] Stopped
2020-08-28T16:17:22.628Z,1598631442.628 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-28T16:17:22.628Z,1598631442.628 [Default:CheckIn:D] Running Loop=1
2020-08-28T16:17:23.031Z,1598631443.031 [Default:CheckIn:D] Stopped
2020-08-28T16:17:23.031Z,1598631443.031 [Default:CheckIn:E] Running Loop=1
2020-08-28T16:17:23.442Z,1598631443.442 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 130.508887 min 
2020-08-28T16:17:23.442Z,1598631443.442 [Default:CheckIn:E] Stopped
2020-08-28T16:17:23.442Z,1598631443.442 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-28T16:17:23.442Z,1598631443.442 [Default:CheckIn] Stopped
2020-08-28T16:17:23.442Z,1598631443.442 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-28T16:17:23.442Z,1598631443.442 [Default:CheckIn](INFO): Running loop #21
2020-08-28T16:17:23.442Z,1598631443.442 [Default:CheckIn] Running Loop=21
2020-08-28T16:17:23.442Z,1598631443.442 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-28T16:17:23.442Z,1598631443.442 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-28T16:17:27.056Z,1598631447.056 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-08-28T16:22:07.052Z,1598631727.052 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162205.00,A,3648.16640,N,12147.27699,W,0.175,289.33,280820,,,A*70
2020-08-28T16:22:07.054Z,1598631727.054 [NAL9602](INFO): GPS fix at 20200828T162205: (36.802773, -121.787950)
2020-08-28T16:22:07.069Z,1598631727.069 [Default:CheckIn:Read_GPS] Stopped
2020-08-28T16:22:07.070Z,1598631727.070 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-28T16:22:07.816Z,1598631727.816 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20200828T140241/Courier0064.lzma
2020-08-28T16:22:08.811Z,1598631728.811 [DataOverHttps](INFO): Moved sent file to Logs/20200828T140241/Courier0064.lzma.bak
2020-08-28T16:22:08.811Z,1598631728.811 [DataOverHttps](INFO): SBD MOMSN=12624503
2020-08-28T16:22:28.488Z,1598631748.488 [DataOverHttps](INFO): Sending 253 bytes from file Logs/20200828T140241/Express0065.lzma
2020-08-28T16:22:29.491Z,1598631749.491 [DataOverHttps](INFO): Moved sent file to Logs/20200828T140241/Express0065.lzma.bak
2020-08-28T16:22:29.491Z,1598631749.491 [DataOverHttps](INFO): SBD MOMSN=12624506
2020-08-28T16:22:30.624Z,1598631750.624 [Default:CheckIn:Read_Iridium] Stopped
2020-08-28T16:22:30.624Z,1598631750.624 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-28T16:22:30.624Z,1598631750.624 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-28T16:22:39.798Z,1598631759.798 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-28T16:25:28.267Z,1598631928.267 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2020-08-28T16:25:28.270Z,1598631928.270 [BPC1](INFO): Received data from all battery sticks.
2020-08-28T16:27:31.093Z,1598632051.093 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-28T16:27:31.093Z,1598632051.093 [Default:CheckIn:C.Wait] Stopped
2020-08-28T16:27:31.093Z,1598632051.093 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-28T16:27:31.093Z,1598632051.093 [Default:CheckIn:D] Running Loop=1
2020-08-28T16:27:31.499Z,1598632051.499 [Default:CheckIn:D] Stopped
2020-08-28T16:27:31.499Z,1598632051.499 [Default:CheckIn:E] Running Loop=1
2020-08-28T16:27:31.902Z,1598632051.902 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 140.650016 min 
2020-08-28T16:27:31.902Z,1598632051.902 [Default:CheckIn:E] Stopped
2020-08-28T16:27:31.902Z,1598632051.902 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-28T16:27:31.902Z,1598632051.902 [Default:CheckIn] Stopped
2020-08-28T16:27:31.902Z,1598632051.902 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-28T16:27:31.902Z,1598632051.902 [Default:CheckIn](INFO): Running loop #22
2020-08-28T16:27:31.902Z,1598632051.902 [Default:CheckIn] Running Loop=22
2020-08-28T16:27:31.902Z,1598632051.902 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-28T16:27:31.903Z,1598632051.903 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-28T16:27:33.912Z,1598632053.912 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162732.00,A,3648.17079,N,12147.28192,W,0.097,69.65,280820,,,A*4D
2020-08-28T16:27:33.914Z,1598632053.914 [NAL9602](INFO): GPS fix at 20200828T162732: (36.802847, -121.788032)
2020-08-28T16:27:33.924Z,1598632053.924 [Default:CheckIn:Read_GPS] Stopped
2020-08-28T16:27:33.924Z,1598632053.924 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-28T16:27:40.844Z,1598632060.844 [DataOverHttps](INFO): Sending 85 bytes from file Logs/20200828T140241/Courier0067.lzma
2020-08-28T16:27:41.847Z,1598632061.847 [DataOverHttps](INFO): Moved sent file to Logs/20200828T140241/Courier0067.lzma.bak
2020-08-28T16:27:41.847Z,1598632061.847 [DataOverHttps](INFO): SBD MOMSN=12624511
2020-08-28T16:27:57.560Z,1598632077.560 [DataOverHttps](INFO): Sending 136 bytes from file Logs/20200828T140241/Express0068.lzma
2020-08-28T16:27:58.563Z,1598632078.563 [DataOverHttps](INFO): Moved sent file to Logs/20200828T140241/Express0068.lzma.bak
2020-08-28T16:27:58.563Z,1598632078.563 [DataOverHttps](INFO): SBD MOMSN=12624514
2020-08-28T16:27:59.778Z,1598632079.778 [Default:CheckIn:Read_Iridium] Stopped
2020-08-28T16:27:59.778Z,1598632079.778 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-28T16:27:59.778Z,1598632079.778 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-28T16:28:21.175Z,1598632101.175 [NAL9602](INFO): SBD MO Status=2, MOMSN=22830, MT Status=2, MTMSN=0
2020-08-28T16:28:21.176Z,1598632101.176 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-08-28T16:29:16.126Z,1598632156.126 [NAL9602](INFO): SBD MO Status=2, MOMSN=22830, MT Status=2, MTMSN=0
2020-08-28T16:29:16.126Z,1598632156.126 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-08-28T16:29:47.239Z,1598632187.239 [NAL9602](INFO): SBD MO Status=0, MOMSN=22830, MT Status=0, MTMSN=0
2020-08-28T16:29:47.239Z,1598632187.239 [NAL9602](INFO): No messages in MT queue
2020-08-28T16:30:17.938Z,1598632217.938 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-28T16:33:00.355Z,1598632380.355 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-28T16:33:00.355Z,1598632380.355 [Default:CheckIn:C.Wait] Stopped
2020-08-28T16:33:00.356Z,1598632380.356 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-28T16:33:00.356Z,1598632380.356 [Default:CheckIn:D] Running Loop=1
2020-08-28T16:33:00.768Z,1598632380.768 [Default:CheckIn:D] Stopped
2020-08-28T16:33:00.768Z,1598632380.768 [Default:CheckIn:E] Running Loop=1
2020-08-28T16:33:01.185Z,1598632381.185 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 146.137842 min 
2020-08-28T16:33:01.185Z,1598632381.185 [Default:CheckIn:E] Stopped
2020-08-28T16:33:01.185Z,1598632381.185 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-28T16:33:01.185Z,1598632381.185 [Default:CheckIn] Stopped
2020-08-28T16:33:01.186Z,1598632381.186 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-28T16:33:01.186Z,1598632381.186 [Default:CheckIn](INFO): Running loop #23
2020-08-28T16:33:01.186Z,1598632381.186 [Default:CheckIn] Running Loop=23
2020-08-28T16:33:01.186Z,1598632381.186 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-28T16:33:01.186Z,1598632381.186 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-28T16:33:03.180Z,1598632383.180 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163302.00,A,3648.14965,N,12147.22314,W,0.078,25.95,280820,,,A*4C
2020-08-28T16:33:03.182Z,1598632383.182 [NAL9602](INFO): GPS fix at 20200828T163302: (36.802494, -121.787052)
2020-08-28T16:33:03.192Z,1598632383.192 [Default:CheckIn:Read_GPS] Stopped
2020-08-28T16:33:03.192Z,1598632383.192 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-28T16:33:10.428Z,1598632390.428 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20200828T140241/Courier0070.lzma
2020-08-28T16:33:11.431Z,1598632391.431 [DataOverHttps](INFO): Moved sent file to Logs/20200828T140241/Courier0070.lzma.bak
2020-08-28T16:33:11.431Z,1598632391.431 [DataOverHttps](INFO): SBD MOMSN=12624518
2020-08-28T16:33:16.147Z,1598632396.147 [NAL9602](INFO): SBD MO Status=0, MOMSN=22831, MT Status=0, MTMSN=0
2020-08-28T16:33:16.147Z,1598632396.147 [NAL9602](INFO): No messages in MT queue
2020-08-28T16:33:27.156Z,1598632407.156 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20200828T140241/Express0071.lzma
2020-08-28T16:33:28.159Z,1598632408.159 [DataOverHttps](INFO): Moved sent file to Logs/20200828T140241/Express0071.lzma.bak
2020-08-28T16:33:28.159Z,1598632408.159 [DataOverHttps](INFO): SBD MOMSN=12624521
2020-08-28T16:33:29.441Z,1598632409.441 [Default:CheckIn:Read_Iridium] Stopped
2020-08-28T16:33:29.442Z,1598632409.442 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-28T16:33:29.442Z,1598632409.442 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-28T16:33:46.810Z,1598632426.810 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-28T16:35:38.058Z,1598632538.058 [DataOverHttps](IMPORTANT): SBD MTMSN=20200828T163537
2020-08-28T16:35:45.313Z,1598632545.313 [DataOverHttps](INFO): Received command:ibit
2020-08-28T16:35:45.369Z,1598632545.369 [CommandLine](IMPORTANT): got command ibit
2020-08-28T16:35:45.603Z,1598632545.603 [IBIT](IMPORTANT): Beginning Initiated BIT
2020-08-28T16:35:45.603Z,1598632545.603 [IBIT](IMPORTANT): Beginning control surface checks.
2020-08-28T16:35:45.606Z,1598632545.606 [CBIT](IMPORTANT): Beginning ground fault scan
2020-08-28T16:35:47.204Z,1598632547.204 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163546.00,A,3648.15026,N,12147.22371,W,0.000,25.95,280820,,,A*49
2020-08-28T16:35:47.206Z,1598632547.206 [NAL9602](INFO): GPS fix at 20200828T163546: (36.802504, -121.787062)
2020-08-28T16:35:56.511Z,1598632556.511 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.002020
CHAN A1 (24V): 0.000339
CHAN A2 (12V): -0.002183
CHAN A3 (5V): -0.000880
CHAN B0 (3.3V): -0.000213
CHAN B1 (3.15aV): -0.000263
CHAN B2 (3.15bV): -0.000488
CHAN B3 (GND): -0.000027
OPEN: -0.000497
Full Scale Calc: 4.765 mA, -1.589 mA
2020-08-28T16:36:08.609Z,1598632568.609 [NAL9602](INFO): SBD MO Status=2, MOMSN=22832, MT Status=2, MTMSN=0
2020-08-28T16:36:08.610Z,1598632568.610 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-08-28T16:36:19.114Z,1598632579.114 [NAL9602](INFO): SBD MO Status=0, MOMSN=22832, MT Status=0, MTMSN=0
2020-08-28T16:36:19.114Z,1598632579.114 [NAL9602](INFO): No messages in MT queue
2020-08-28T16:36:20.338Z,1598632580.338 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163620.00,A,3648.15033,N,12147.22296,W,0.175,25.95,280820,,,A*45
2020-08-28T16:36:20.340Z,1598632580.340 [NAL9602](INFO): GPS fix at 20200828T163620: (36.802506, -121.787049)
2020-08-28T16:36:23.172Z,1598632583.172 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163623.00,A,3648.15019,N,12147.22272,W,0.039,25.95,280820,,,A*4D
2020-08-28T16:36:23.174Z,1598632583.174 [NAL9602](INFO): GPS fix at 20200828T163623: (36.802503, -121.787045)
2020-08-28T16:36:26.408Z,1598632586.408 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163626.00,A,3648.15008,N,12147.22256,W,0.058,25.95,280820,,,A*49
2020-08-28T16:36:26.410Z,1598632586.410 [NAL9602](INFO): GPS fix at 20200828T163626: (36.802501, -121.787043)
2020-08-28T16:36:29.232Z,1598632589.232 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163629.00,A,3648.15002,N,12147.22242,W,0.039,25.95,280820,,,A*4E
2020-08-28T16:36:29.234Z,1598632589.234 [NAL9602](INFO): GPS fix at 20200828T163629: (36.802500, -121.787040)
2020-08-28T16:36:31.675Z,1598632591.675 [IBIT](IMPORTANT): Communications Status:
Fix Status: 1
Iridium Signal Strength: 3
Latitude: 36.802502 Longitude: -121.787041
2020-08-28T16:36:32.092Z,1598632592.092 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 0.000000
Voltage: 16.611000
2020-08-28T16:36:32.092Z,1598632592.092 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah
2020-08-28T16:36:32.092Z,1598632592.092 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V
2020-08-28T16:36:32.462Z,1598632592.462 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163632.00,A,3648.14999,N,12147.22239,W,0.000,25.95,280820,,,A*48
2020-08-28T16:36:32.464Z,1598632592.464 [NAL9602](INFO): GPS fix at 20200828T163632: (36.802500, -121.787040)
2020-08-28T16:36:32.492Z,1598632592.492 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2020-08-28T16:36:32.492Z,1598632592.492 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2020-08-28T16:36:32.497Z,1598632592.497 [IBIT](IMPORTANT): Pressure:8.491188 PSI
2020-08-28T16:36:32.497Z,1598632592.497 [IBIT](IMPORTANT): Humidity:11.311195 %
2020-08-28T16:36:32.911Z,1598632592.911 [IBIT](IMPORTANT): Vehicle Pitch:2.442047 degrees
2020-08-28T16:36:32.911Z,1598632592.911 [IBIT](IMPORTANT): Vehicle  Roll:6.211403 degrees
2020-08-28T16:36:32.912Z,1598632592.912 [IBIT](IMPORTANT): Vehicle  Heading:223.291199 degrees
2020-08-28T16:36:33.289Z,1598632593.289 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2020-08-28T16:36:33.289Z,1598632593.289 [IBIT](IMPORTANT): buoyancyNeutral: 210.468201 cc
2020-08-28T16:36:33.289Z,1598632593.289 [IBIT](IMPORTANT): massDefault: -1.086426 cm
2020-08-28T16:36:33.290Z,1598632593.290 [IBIT](IMPORTANT): stopDepth: 205.000000 m
2020-08-28T16:36:33.290Z,1598632593.290 [IBIT](IMPORTANT): abortDepth: 250.000000 m
2020-08-28T16:36:33.290Z,1598632593.290 [IBIT](IMPORTANT): IBIT PASSED
2020-08-28T16:37:04.783Z,1598632624.783 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-28T16:38:30.035Z,1598632710.035 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-28T16:38:30.035Z,1598632710.035 [Default:CheckIn:C.Wait] Stopped
2020-08-28T16:38:30.035Z,1598632710.035 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-28T16:38:30.035Z,1598632710.035 [Default:CheckIn:D] Running Loop=1
2020-08-28T16:38:30.449Z,1598632710.449 [Default:CheckIn:D] Stopped
2020-08-28T16:38:30.449Z,1598632710.449 [Default:CheckIn:E] Running Loop=1
2020-08-28T16:38:30.842Z,1598632710.842 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 151.632503 min 
2020-08-28T16:38:30.842Z,1598632710.842 [Default:CheckIn:E] Stopped
2020-08-28T16:38:30.842Z,1598632710.842 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-28T16:38:30.842Z,1598632710.842 [Default:CheckIn] Stopped
2020-08-28T16:38:30.842Z,1598632710.842 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-28T16:38:30.842Z,1598632710.842 [Default:CheckIn](INFO): Running loop #24
2020-08-28T16:38:30.842Z,1598632710.842 [Default:CheckIn] Running Loop=24
2020-08-28T16:38:30.842Z,1598632710.842 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-28T16:38:30.843Z,1598632710.843 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-28T16:38:32.860Z,1598632712.860 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163832.00,A,3648.15075,N,12147.22307,W,0.039,25.95,280820,,,A*4A
2020-08-28T16:38:32.862Z,1598632712.862 [NAL9602](INFO): GPS fix at 20200828T163832: (36.802512, -121.787051)
2020-08-28T16:38:32.872Z,1598632712.872 [Default:CheckIn:Read_GPS] Stopped
2020-08-28T16:38:32.872Z,1598632712.872 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-28T16:38:39.716Z,1598632719.716 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20200828T140241/Courier0073.lzma
2020-08-28T16:38:40.719Z,1598632720.719 [DataOverHttps](INFO): Moved sent file to Logs/20200828T140241/Courier0073.lzma.bak
2020-08-28T16:38:40.719Z,1598632720.719 [DataOverHttps](INFO): SBD MOMSN=12624528
2020-08-28T16:38:56.457Z,1598632736.457 [DataOverHttps](INFO): Sending 825 bytes from file Logs/20200828T140241/Express0074.lzma
2020-08-28T16:38:57.459Z,1598632737.459 [DataOverHttps](INFO): Moved sent file to Logs/20200828T140241/Express0074.lzma.bak
2020-08-28T16:38:57.459Z,1598632737.459 [DataOverHttps](INFO): SBD MOMSN=12624531
2020-08-28T16:38:58.718Z,1598632738.718 [Default:CheckIn:Read_Iridium] Stopped
2020-08-28T16:38:58.718Z,1598632738.718 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-28T16:38:58.718Z,1598632738.718 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-28T16:40:06.534Z,1598632806.534 [DataOverHttps](IMPORTANT): SBD MTMSN=20200828T164006
2020-08-28T16:40:10.624Z,1598632810.624 [NAL9602](INFO): SBD MO Status=2, MOMSN=22833, MT Status=2, MTMSN=0
2020-08-28T16:40:10.624Z,1598632810.624 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-08-28T16:40:14.056Z,1598632814.056 [DataOverHttps](INFO): Received command:failc
2020-08-28T16:40:14.105Z,1598632814.105 [CommandLine](IMPORTANT): got command failComponent
2020-08-28T16:40:14.105Z,1598632814.105 [CommandLine](IMPORTANT): Failed components:
2020-08-28T16:40:14.106Z,1598632814.106 [CommandLine](IMPORTANT): No failed Components.
2020-08-28T16:40:19.106Z,1598632819.106 [NAL9602](INFO): SBD MO Status=0, MOMSN=22833, MT Status=0, MTMSN=0
2020-08-28T16:40:19.106Z,1598632819.106 [NAL9602](INFO): No messages in MT queue
2020-08-28T16:40:49.814Z,1598632849.814 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-28T16:43:59.314Z,1598633039.314 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-28T16:43:59.314Z,1598633039.314 [Default:CheckIn:C.Wait] Stopped
2020-08-28T16:43:59.314Z,1598633039.314 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-28T16:43:59.314Z,1598633039.314 [Default:CheckIn:D] Running Loop=1
2020-08-28T16:43:59.698Z,1598633039.698 [Default:CheckIn:D] Stopped
2020-08-28T16:43:59.698Z,1598633039.698 [Default:CheckIn:E] Running Loop=1
2020-08-28T16:44:00.103Z,1598633040.103 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 157.120003 min 
2020-08-28T16:44:00.103Z,1598633040.103 [Default:CheckIn:E] Stopped
2020-08-28T16:44:00.104Z,1598633040.104 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-28T16:44:00.104Z,1598633040.104 [Default:CheckIn] Stopped
2020-08-28T16:44:00.104Z,1598633040.104 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-28T16:44:00.104Z,1598633040.104 [Default:CheckIn](INFO): Running loop #25
2020-08-28T16:44:00.104Z,1598633040.104 [Default:CheckIn] Running Loop=25
2020-08-28T16:44:00.104Z,1598633040.104 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-28T16:44:00.104Z,1598633040.104 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-28T16:44:02.116Z,1598633042.116 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164402.00,A,3648.14939,N,12147.22244,W,0.272,25.95,280820,,,A*49
2020-08-28T16:44:02.118Z,1598633042.118 [NAL9602](INFO): GPS fix at 20200828T164402: (36.802490, -121.787041)
2020-08-28T16:44:02.128Z,1598633042.128 [Default:CheckIn:Read_GPS] Stopped
2020-08-28T16:44:02.128Z,1598633042.128 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-28T16:44:09.536Z,1598633049.536 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20200828T140241/Courier0076.lzma
2020-08-28T16:44:10.539Z,1598633050.539 [DataOverHttps](INFO): Moved sent file to Logs/20200828T140241/Courier0076.lzma.bak
2020-08-28T16:44:10.539Z,1598633050.539 [DataOverHttps](INFO): SBD MOMSN=12624561
2020-08-28T16:44:29.244Z,1598633069.244 [DataOverHttps](INFO): Sending 222 bytes from file Logs/20200828T140241/Express0078.lzma
2020-08-28T16:44:30.247Z,1598633070.247 [DataOverHttps](INFO): Moved sent file to Logs/20200828T140241/Express0078.lzma.bak
2020-08-28T16:44:30.247Z,1598633070.247 [DataOverHttps](INFO): SBD MOMSN=12624564
2020-08-28T16:44:32.843Z,1598633072.843 [NAL9602](INFO): SBD MO Status=2, MOMSN=22834, MT Status=2, MTMSN=0
2020-08-28T16:44:32.844Z,1598633072.844 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-08-28T16:44:46.024Z,1598633086.024 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20200828T140241/Express0083.lzma
2020-08-28T16:44:47.027Z,1598633087.027 [DataOverHttps](INFO): Moved sent file to Logs/20200828T140241/Express0083.lzma.bak
2020-08-28T16:44:47.027Z,1598633087.027 [DataOverHttps](INFO): SBD MOMSN=12624571
2020-08-28T16:44:47.795Z,1598633087.795 [NAL9602](INFO): SBD MO Status=0, MOMSN=22834, MT Status=0, MTMSN=0
2020-08-28T16:44:47.796Z,1598633087.796 [NAL9602](INFO): No messages in MT queue
2020-08-28T16:44:48.211Z,1598633088.211 [Default:CheckIn:Read_Iridium] Stopped
2020-08-28T16:44:48.211Z,1598633088.211 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-28T16:44:48.211Z,1598633088.211 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-28T16:45:18.493Z,1598633118.493 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-28T16:49:48.811Z,1598633388.811 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-28T16:49:48.811Z,1598633388.811 [Default:CheckIn:C.Wait] Stopped
2020-08-28T16:49:48.812Z,1598633388.812 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-28T16:49:48.812Z,1598633388.812 [Default:CheckIn:D] Running Loop=1
2020-08-28T16:49:49.219Z,1598633389.219 [Default:CheckIn:D] Stopped
2020-08-28T16:49:49.219Z,1598633389.219 [Default:CheckIn:E] Running Loop=1
2020-08-28T16:49:49.630Z,1598633389.630 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 162.945345 min 
2020-08-28T16:49:49.630Z,1598633389.630 [Default:CheckIn:E] Stopped
2020-08-28T16:49:49.630Z,1598633389.630 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-28T16:49:49.630Z,1598633389.630 [Default:CheckIn] Stopped
2020-08-28T16:49:49.630Z,1598633389.630 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-28T16:49:49.631Z,1598633389.631 [Default:CheckIn](INFO): Running loop #26
2020-08-28T16:49:49.631Z,1598633389.631 [Default:CheckIn] Running Loop=26
2020-08-28T16:49:49.631Z,1598633389.631 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-28T16:49:49.631Z,1598633389.631 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-28T16:49:51.628Z,1598633391.628 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164951.00,A,3648.14890,N,12147.22320,W,0.019,25.95,280820,,,D*49
2020-08-28T16:49:51.630Z,1598633391.630 [NAL9602](INFO): GPS fix at 20200828T164951: (36.802482, -121.787053)
2020-08-28T16:49:51.640Z,1598633391.640 [Default:CheckIn:Read_GPS] Stopped
2020-08-28T16:49:51.640Z,1598633391.640 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-28T16:49:58.056Z,1598633398.056 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20200828T140241/Courier0085.lzma
2020-08-28T16:49:59.059Z,1598633399.059 [DataOverHttps](INFO): Moved sent file to Logs/20200828T140241/Courier0085.lzma.bak
2020-08-28T16:49:59.059Z,1598633399.059 [DataOverHttps](INFO): SBD MOMSN=12624574
2020-08-28T16:50:14.255Z,1598633414.255 [NAL9602](INFO): SBD MO Status=0, MOMSN=22835, MT Status=0, MTMSN=0
2020-08-28T16:50:14.255Z,1598633414.255 [NAL9602](INFO): No messages in MT queue
2020-08-28T16:50:14.668Z,1598633414.668 [DataOverHttps](INFO): Sending 136 bytes from file Logs/20200828T140241/Express0086.lzma
2020-08-28T16:50:15.671Z,1598633415.671 [DataOverHttps](INFO): Moved sent file to Logs/20200828T140241/Express0086.lzma.bak
2020-08-28T16:50:15.671Z,1598633415.671 [DataOverHttps](INFO): SBD MOMSN=12624577
2020-08-28T16:50:16.702Z,1598633416.702 [Default:CheckIn:Read_Iridium] Stopped
2020-08-28T16:50:16.702Z,1598633416.702 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-28T16:50:16.702Z,1598633416.702 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-28T16:50:44.970Z,1598633444.970 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-28T16:55:17.298Z,1598633717.298 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-28T16:55:17.298Z,1598633717.298 [Default:CheckIn:C.Wait] Stopped
2020-08-28T16:55:17.298Z,1598633717.298 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-28T16:55:17.298Z,1598633717.298 [Default:CheckIn:D] Running Loop=1
2020-08-28T16:55:17.748Z,1598633717.748 [Default:CheckIn:D] Stopped
2020-08-28T16:55:17.748Z,1598633717.748 [Default:CheckIn:E] Running Loop=1
2020-08-28T16:55:18.106Z,1598633718.106 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 168.420833 min 
2020-08-28T16:55:18.106Z,1598633718.106 [Default:CheckIn:E] Stopped
2020-08-28T16:55:18.106Z,1598633718.106 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-28T16:55:18.106Z,1598633718.106 [Default:CheckIn] Stopped
2020-08-28T16:55:18.106Z,1598633718.106 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-28T16:55:18.106Z,1598633718.106 [Default:CheckIn](INFO): Running loop #27
2020-08-28T16:55:18.106Z,1598633718.106 [Default:CheckIn] Running Loop=27
2020-08-28T16:55:18.106Z,1598633718.106 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-28T16:55:18.107Z,1598633718.107 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-28T16:55:20.116Z,1598633720.116 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165520.00,A,3648.44673,N,12147.11553,W,5.248,355.79,280820,,,D*73
2020-08-28T16:55:20.118Z,1598633720.118 [NAL9602](INFO): GPS fix at 20200828T165520: (36.807446, -121.785259)
2020-08-28T16:55:20.128Z,1598633720.128 [Default:CheckIn:Read_GPS] Stopped
2020-08-28T16:55:20.128Z,1598633720.128 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-28T16:55:26.948Z,1598633726.948 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20200828T140241/Courier0088.lzma
2020-08-28T16:55:27.951Z,1598633727.951 [DataOverHttps](INFO): Moved sent file to Logs/20200828T140241/Courier0088.lzma.bak
2020-08-28T16:55:27.951Z,1598633727.951 [DataOverHttps](INFO): SBD MOMSN=12624581
2020-08-28T16:55:39.503Z,1598633739.503 [NAL9602](INFO): SBD MO Status=2, MOMSN=22836, MT Status=2, MTMSN=0
2020-08-28T16:55:39.503Z,1598633739.503 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-08-28T16:55:43.616Z,1598633743.616 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20200828T140241/Express0089.lzma
2020-08-28T16:55:44.619Z,1598633744.619 [DataOverHttps](INFO): Moved sent file to Logs/20200828T140241/Express0089.lzma.bak
2020-08-28T16:55:44.619Z,1598633744.619 [DataOverHttps](INFO): SBD MOMSN=12624584
2020-08-28T16:55:45.989Z,1598633745.989 [Default:CheckIn:Read_Iridium] Stopped
2020-08-28T16:55:45.989Z,1598633745.989 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-28T16:55:45.989Z,1598633745.989 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-28T16:56:19.907Z,1598633779.907 [NAL9602](INFO): SBD MO Status=0, MOMSN=22836, MT Status=0, MTMSN=0
2020-08-28T16:56:19.907Z,1598633779.907 [NAL9602](INFO): No messages in MT queue
2020-08-28T16:56:50.634Z,1598633810.634 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-28T17:00:46.638Z,1598634046.638 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-28T17:00:46.638Z,1598634046.638 [Default:CheckIn:C.Wait] Stopped
2020-08-28T17:00:46.638Z,1598634046.638 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-28T17:00:46.638Z,1598634046.638 [Default:CheckIn:D] Running Loop=1
2020-08-28T17:00:47.047Z,1598634047.047 [Default:CheckIn:D] Stopped
2020-08-28T17:00:47.048Z,1598634047.048 [Default:CheckIn:E] Running Loop=1
2020-08-28T17:00:47.455Z,1598634047.455 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 173.909163 min 
2020-08-28T17:00:47.455Z,1598634047.455 [Default:CheckIn:E] Stopped
2020-08-28T17:00:47.455Z,1598634047.455 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-28T17:00:47.456Z,1598634047.456 [Default:CheckIn] Stopped
2020-08-28T17:00:47.456Z,1598634047.456 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-28T17:00:47.456Z,1598634047.456 [Default:CheckIn](INFO): Running loop #28
2020-08-28T17:00:47.456Z,1598634047.456 [Default:CheckIn] Running Loop=28
2020-08-28T17:00:47.456Z,1598634047.456 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-28T17:00:47.456Z,1598634047.456 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-28T17:00:49.460Z,1598634049.460 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170049.00,A,3648.11659,N,12148.57095,W,22.063,259.67,280820,,,D*4B
2020-08-28T17:00:49.462Z,1598634049.462 [NAL9602](INFO): GPS fix at 20200828T170049: (36.801943, -121.809516)
2020-08-28T17:00:49.492Z,1598634049.492 [Default:CheckIn:Read_GPS] Stopped
2020-08-28T17:00:49.492Z,1598634049.492 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-28T17:00:56.396Z,1598634056.396 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20200828T140241/Courier0091.lzma
2020-08-28T17:00:57.399Z,1598634057.399 [DataOverHttps](INFO): Moved sent file to Logs/20200828T140241/Courier0091.lzma.bak
2020-08-28T17:00:57.399Z,1598634057.399 [DataOverHttps](INFO): SBD MOMSN=12624588
2020-08-28T17:01:13.100Z,1598634073.100 [DataOverHttps](INFO): Sending 153 bytes from file Logs/20200828T140241/Express0092.lzma
2020-08-28T17:01:14.104Z,1598634074.104 [DataOverHttps](INFO): Moved sent file to Logs/20200828T140241/Express0092.lzma.bak
2020-08-28T17:01:14.104Z,1598634074.104 [DataOverHttps](INFO): SBD MOMSN=12624591
2020-08-28T17:01:15.329Z,1598634075.329 [Default:CheckIn:Read_Iridium] Stopped
2020-08-28T17:01:15.329Z,1598634075.329 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-28T17:01:15.329Z,1598634075.329 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-28T17:02:10.661Z,1598634130.661 [NAL9602](INFO): SBD MO Status=0, MOMSN=22837, MT Status=0, MTMSN=0
2020-08-28T17:02:10.662Z,1598634130.662 [NAL9602](INFO): No messages in MT queue
2020-08-28T17:02:41.370Z,1598634161.370 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-28T17:06:15.993Z,1598634375.993 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-28T17:06:15.993Z,1598634375.993 [Default:CheckIn:C.Wait] Stopped
2020-08-28T17:06:15.993Z,1598634375.993 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-28T17:06:15.993Z,1598634375.993 [Default:CheckIn:D] Running Loop=1
2020-08-28T17:06:16.353Z,1598634376.353 [Default:CheckIn:D] Stopped
2020-08-28T17:06:16.353Z,1598634376.353 [Default:CheckIn:E] Running Loop=1
2020-08-28T17:06:16.742Z,1598634376.742 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 179.397591 min 
2020-08-28T17:06:16.742Z,1598634376.742 [Default:CheckIn:E] Stopped
2020-08-28T17:06:16.742Z,1598634376.742 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-28T17:06:16.742Z,1598634376.742 [Default:CheckIn] Stopped
2020-08-28T17:06:16.742Z,1598634376.742 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-28T17:06:16.742Z,1598634376.742 [Default:CheckIn](INFO): Running loop #29
2020-08-28T17:06:16.742Z,1598634376.742 [Default:CheckIn] Running Loop=29
2020-08-28T17:06:16.742Z,1598634376.742 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-28T17:06:16.742Z,1598634376.742 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-28T17:06:18.760Z,1598634378.760 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170618.00,A,3647.80386,N,12150.83097,W,7.503,203.20,280820,,,A*76
2020-08-28T17:06:18.762Z,1598634378.762 [NAL9602](INFO): GPS fix at 20200828T170618: (36.796731, -121.847183)
2020-08-28T17:06:18.772Z,1598634378.772 [Default:CheckIn:Read_GPS] Stopped
2020-08-28T17:06:18.772Z,1598634378.772 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-28T17:06:29.876Z,1598634389.876 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20200828T140241/Courier0094.lzma
2020-08-28T17:06:30.879Z,1598634390.879 [DataOverHttps](INFO): Moved sent file to Logs/20200828T140241/Courier0094.lzma.bak
2020-08-28T17:06:30.879Z,1598634390.879 [DataOverHttps](INFO): SBD MOMSN=12624595
2020-08-28T17:06:38.158Z,1598634398.158 [NAL9602](INFO): SBD MO Status=2, MOMSN=22838, MT Status=2, MTMSN=0
2020-08-28T17:06:38.158Z,1598634398.158 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-08-28T17:06:46.692Z,1598634406.692 [DataOverHttps](INFO): Sending 152 bytes from file Logs/20200828T140241/Express0095.lzma
2020-08-28T17:06:47.695Z,1598634407.695 [DataOverHttps](INFO): Moved sent file to Logs/20200828T140241/Express0095.lzma.bak
2020-08-28T17:06:47.695Z,1598634407.695 [DataOverHttps](INFO): SBD MOMSN=12624598
2020-08-28T17:06:48.721Z,1598634408.721 [Default:CheckIn:Read_Iridium] Stopped
2020-08-28T17:06:48.721Z,1598634408.721 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-28T17:06:48.721Z,1598634408.721 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-28T17:07:35.127Z,1598634455.127 [NAL9602](INFO): SBD MO Status=0, MOMSN=22838, MT Status=0, MTMSN=0
2020-08-28T17:07:35.127Z,1598634455.127 [NAL9602](INFO): No messages in MT queue
2020-08-28T17:07:49.525Z,1598634469.525 [DataOverHttps](INFO): Exceeded connection timeout, disconnecting.
2020-08-28T17:08:05.826Z,1598634485.826 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-28T17:10:00.254Z,1598634600.254 [DataOverHttps](IMPORTANT): SBD MTMSN=20200828T170959