2023-04-03T15:22:39.475Z,1680535359.475 [Supervisor](DEBUG): Initializing supervisor.
2023-04-03T15:22:39.481Z,1680535359.481 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2023-04-03T15:22:39.481Z,1680535359.481 [SyncHandler](INFO): Protected caller Thread ID is 3655
2023-04-03T15:22:39.482Z,1680535359.482 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2023-04-03T15:22:39.483Z,1680535359.483 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2023-04-03T15:22:39.483Z,1680535359.483 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 3656
2023-04-03T15:22:39.487Z,1680535359.487 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2023-04-03T15:22:39.505Z,1680535359.505 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2023-04-03T15:22:39.506Z,1680535359.506 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2023-04-03T15:22:39.506Z,1680535359.506 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 3657
2023-04-03T15:22:39.511Z,1680535359.511 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2023-04-03T15:22:39.512Z,1680535359.512 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2023-04-03T15:22:39.512Z,1680535359.512 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 3658
2023-04-03T15:22:39.514Z,1680535359.514 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2023-04-03T15:22:39.515Z,1680535359.515 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2023-04-03T15:22:39.515Z,1680535359.515 [logger ThreadHandler](INFO): Protected caller Thread ID is 3659
2023-04-03T15:22:39.519Z,1680535359.519 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2023-04-03T15:22:39.519Z,1680535359.519 [Supervisor](INFO): Looking for Config files in directory: Config/
2023-04-03T15:22:39.521Z,1680535359.521 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2023-04-03T15:22:39.734Z,1680535359.734 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2023-04-03T15:22:39.735Z,1680535359.735 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2023-04-03T15:22:39.839Z,1680535359.839 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2023-04-03T15:22:39.839Z,1680535359.839 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2023-04-03T15:22:39.932Z,1680535359.932 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2023-04-03T15:22:39.933Z,1680535359.933 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2023-04-03T15:22:40.384Z,1680535360.384 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2023-04-03T15:22:40.385Z,1680535360.385 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2023-04-03T15:22:40.730Z,1680535360.730 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2023-04-03T15:22:40.730Z,1680535360.730 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2023-04-03T15:22:41.063Z,1680535361.063 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2023-04-03T15:22:41.063Z,1680535361.063 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2023-04-03T15:22:41.248Z,1680535361.248 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2023-04-03T15:22:41.248Z,1680535361.248 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2023-04-03T15:22:41.325Z,1680535361.325 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2023-04-03T15:22:41.404Z,1680535361.404 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2023-04-03T15:22:41.792Z,1680535361.792 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2023-04-03T15:22:41.793Z,1680535361.793 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2023-04-03T15:22:42.076Z,1680535362.076 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2023-04-03T15:22:42.077Z,1680535362.077 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2023-04-03T15:22:42.645Z,1680535362.645 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2023-04-03T15:22:42.646Z,1680535362.646 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2023-04-03T15:22:42.855Z,1680535362.855 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2023-04-03T15:22:42.855Z,1680535362.855 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2023-04-03T15:22:43.093Z,1680535363.093 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2023-04-03T15:22:43.093Z,1680535363.093 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2023-04-03T15:22:43.229Z,1680535363.229 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2023-04-03T15:22:43.230Z,1680535363.230 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2023-04-03T15:22:43.987Z,1680535363.987 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2023-04-03T15:22:43.989Z,1680535363.989 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-galene/
2023-04-03T15:22:43.990Z,1680535363.990 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/secure.cfg
2023-04-03T15:22:44.072Z,1680535364.072 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/vehicle.cfg
2023-04-03T15:22:44.290Z,1680535364.290 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Battery.cfg
2023-04-03T15:22:44.829Z,1680535364.829 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2023-04-03T15:22:44.829Z,1680535364.829 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Science.cfg
2023-04-03T15:22:44.949Z,1680535364.949 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Control.cfg
2023-04-03T15:22:45.047Z,1680535365.047 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/logger.cfg
2023-04-03T15:22:45.139Z,1680535365.139 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Servo.cfg
2023-04-03T15:22:45.244Z,1680535365.244 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Navigation.cfg
2023-04-03T15:22:45.336Z,1680535365.336 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Simulator.cfg
2023-04-03T15:22:45.420Z,1680535365.420 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/BIT.cfg
2023-04-03T15:22:45.517Z,1680535365.517 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Sensor.cfg
2023-04-03T15:22:45.674Z,1680535365.674 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-galene/root/
2023-04-03T15:22:45.674Z,1680535365.674 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2023-04-03T15:22:45.683Z,1680535365.683 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2023-04-03T15:22:45.736Z,1680535365.736 [DepthRateCalculator] Loaded
2023-04-03T15:22:45.736Z,1680535365.736 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2023-04-03T15:22:45.742Z,1680535365.742 [PitchRateCalculator] Loaded
2023-04-03T15:22:45.742Z,1680535365.742 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2023-04-03T15:22:45.752Z,1680535365.752 [SpeedCalculator] Loaded
2023-04-03T15:22:45.752Z,1680535365.752 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2023-04-03T15:22:45.757Z,1680535365.757 [YawRateCalculator] Loaded
2023-04-03T15:22:45.757Z,1680535365.757 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2023-04-03T15:22:45.778Z,1680535365.778 [ElevatorOffsetCalculator] Loaded
2023-04-03T15:22:45.779Z,1680535365.779 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2023-04-03T15:22:45.779Z,1680535365.779 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2023-04-03T15:22:45.780Z,1680535365.780 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2023-04-03T15:22:45.807Z,1680535365.807 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2023-04-03T15:22:45.808Z,1680535365.808 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2023-04-03T15:22:45.818Z,1680535365.818 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2023-04-03T15:22:45.819Z,1680535365.819 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2023-04-03T15:22:46.255Z,1680535366.255 [AHRS_M2] Loaded
2023-04-03T15:22:46.255Z,1680535366.255 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2023-04-03T15:22:46.290Z,1680535366.290 [BackseatComponent] Loaded
2023-04-03T15:22:46.290Z,1680535366.290 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2023-04-03T15:22:46.291Z,1680535366.291 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 408474E0
2023-04-03T15:22:46.292Z,1680535366.292 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 3742
2023-04-03T15:22:46.294Z,1680535366.294 [LcmUniversalReporter] Loaded
2023-04-03T15:22:46.295Z,1680535366.295 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2023-04-03T15:22:47.095Z,1680535367.095 [BPC1] Loaded
2023-04-03T15:22:47.095Z,1680535367.095 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2023-04-03T15:22:47.166Z,1680535367.166 [DataOverHttps] Loaded
2023-04-03T15:22:47.166Z,1680535367.166 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2023-04-03T15:22:47.167Z,1680535367.167 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 408774E0
2023-04-03T15:22:47.167Z,1680535367.167 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 3743
2023-04-03T15:22:47.188Z,1680535367.188 [Depth_Keller] Loaded
2023-04-03T15:22:47.188Z,1680535367.188 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2023-04-03T15:22:47.193Z,1680535367.193 [DropWeight] Loaded
2023-04-03T15:22:47.193Z,1680535367.193 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2023-04-03T15:22:47.256Z,1680535367.256 [NAL9602] Loaded
2023-04-03T15:22:47.256Z,1680535367.256 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2023-04-03T15:22:47.286Z,1680535367.286 [Onboard] Loaded
2023-04-03T15:22:47.286Z,1680535367.286 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2023-04-03T15:22:47.287Z,1680535367.287 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 408A74E0
2023-04-03T15:22:47.287Z,1680535367.287 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 3744
2023-04-03T15:22:47.293Z,1680535367.293 [PowerOnly](INFO): Adding load control power supply at /dev/loadC3
2023-04-03T15:22:47.304Z,1680535367.304 [PowerOnly] Loaded
2023-04-03T15:22:47.304Z,1680535367.304 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread.
2023-04-03T15:22:47.316Z,1680535367.316 [Power24vConverter] Loaded
2023-04-03T15:22:47.316Z,1680535367.316 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2023-04-03T15:22:47.330Z,1680535367.330 [Radio_Surface] Loaded
2023-04-03T15:22:47.330Z,1680535367.330 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2023-04-03T15:22:47.331Z,1680535367.331 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408D74E0
2023-04-03T15:22:47.332Z,1680535367.332 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 3745
2023-04-03T15:22:47.355Z,1680535367.355 [Waterlinked] Loaded
2023-04-03T15:22:47.355Z,1680535367.355 [ComponentRegistry](DEBUG): SyncComponent "Waterlinked" handled in the control thread.
2023-04-03T15:22:47.356Z,1680535367.356 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2023-04-03T15:22:47.356Z,1680535367.356 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2023-04-03T15:22:47.471Z,1680535367.471 [DeadReckonUsingMultipleVelocitySources] Loaded
2023-04-03T15:22:47.471Z,1680535367.471 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2023-04-03T15:22:47.512Z,1680535367.512 [DeadReckonUsingSpeedCalculator] Loaded
2023-04-03T15:22:47.513Z,1680535367.513 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2023-04-03T15:22:47.526Z,1680535367.526 [NavChart] Loaded
2023-04-03T15:22:47.526Z,1680535367.526 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2023-04-03T15:22:47.532Z,1680535367.532 [UniversalFixResidualReporter] Loaded
2023-04-03T15:22:47.532Z,1680535367.532 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2023-04-03T15:22:47.533Z,1680535367.533 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2023-04-03T15:22:47.534Z,1680535367.534 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2023-04-03T15:22:47.677Z,1680535367.677 [SBIT](DEBUG): Construct Startup Built In Test.
2023-04-03T15:22:47.692Z,1680535367.692 [SBIT] Loaded
2023-04-03T15:22:47.692Z,1680535367.692 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2023-04-03T15:22:47.695Z,1680535367.695 [IBIT](DEBUG): Construct Initiated Built In Test.
2023-04-03T15:22:47.707Z,1680535367.707 [IBIT] Loaded
2023-04-03T15:22:47.708Z,1680535367.708 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2023-04-03T15:22:47.713Z,1680535367.713 [CBIT](DEBUG): Construct Continuous Built In Test.
2023-04-03T15:22:47.815Z,1680535367.815 [CBIT] Loaded
2023-04-03T15:22:47.815Z,1680535367.815 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2023-04-03T15:22:47.815Z,1680535367.815 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2023-04-03T15:22:47.816Z,1680535367.816 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2023-04-03T15:22:47.992Z,1680535367.992 [CTD_Seabird] Loaded
2023-04-03T15:22:47.992Z,1680535367.992 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2023-04-03T15:22:47.993Z,1680535367.993 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 409DB4E0
2023-04-03T15:22:47.994Z,1680535367.994 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 3746
2023-04-03T15:22:48.014Z,1680535368.014 [PAR_Licor] Loaded
2023-04-03T15:22:48.014Z,1680535368.014 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2023-04-03T15:22:48.045Z,1680535368.045 [WetLabsBB2FL] Loaded
2023-04-03T15:22:48.045Z,1680535368.045 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2023-04-03T15:22:48.046Z,1680535368.046 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40A0B4E0
2023-04-03T15:22:48.047Z,1680535368.047 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 3747
2023-04-03T15:22:48.047Z,1680535368.047 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2023-04-03T15:22:48.048Z,1680535368.048 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2023-04-03T15:22:48.185Z,1680535368.185 [BuoyancyServo] Loaded
2023-04-03T15:22:48.186Z,1680535368.186 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2023-04-03T15:22:48.207Z,1680535368.207 [ElevatorServo] Loaded
2023-04-03T15:22:48.208Z,1680535368.208 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2023-04-03T15:22:48.229Z,1680535368.229 [MassServo] Loaded
2023-04-03T15:22:48.229Z,1680535368.229 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2023-04-03T15:22:48.250Z,1680535368.250 [RudderServo] Loaded
2023-04-03T15:22:48.250Z,1680535368.250 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2023-04-03T15:22:48.266Z,1680535368.266 [ThrusterHE] Loaded
2023-04-03T15:22:48.266Z,1680535368.266 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2023-04-03T15:22:48.267Z,1680535368.267 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2023-04-03T15:22:48.267Z,1680535368.267 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2023-04-03T15:22:48.320Z,1680535368.320 [VerticalControl](DEBUG): Construct VerticalControl.
2023-04-03T15:22:48.371Z,1680535368.371 [VerticalControl] Loaded
2023-04-03T15:22:48.371Z,1680535368.371 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2023-04-03T15:22:48.374Z,1680535368.374 [HorizontalControl](DEBUG): Construct HorizontalControl.
2023-04-03T15:22:48.411Z,1680535368.411 [HorizontalControl] Loaded
2023-04-03T15:22:48.412Z,1680535368.412 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2023-04-03T15:22:48.414Z,1680535368.414 [SpeedControl](DEBUG): Construct SpeedControl.
2023-04-03T15:22:48.416Z,1680535368.416 [SpeedControl] Loaded
2023-04-03T15:22:48.416Z,1680535368.416 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2023-04-03T15:22:48.419Z,1680535368.419 [LoopControl](DEBUG): Construct LoopControl.
2023-04-03T15:22:48.419Z,1680535368.419 [LoopControl] Loaded
2023-04-03T15:22:48.419Z,1680535368.419 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2023-04-03T15:22:48.420Z,1680535368.420 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2023-04-03T15:22:48.420Z,1680535368.420 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2023-04-03T15:22:48.520Z,1680535368.520 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2023-04-03T15:22:48.521Z,1680535368.521 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2023-04-03T15:22:48.675Z,1680535368.675 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2023-04-03T15:22:48.676Z,1680535368.676 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2023-04-03T15:22:48.986Z,1680535368.986 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2023-04-03T15:22:48.987Z,1680535368.987 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2023-04-03T15:22:49.045Z,1680535369.045 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2023-04-03T15:22:49.051Z,1680535369.051 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2023-04-03T15:22:49.054Z,1680535369.054 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2023-04-03T15:22:49.066Z,1680535369.066 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2023-04-03T15:22:49.067Z,1680535369.067 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40BAE4E0
2023-04-03T15:22:49.067Z,1680535369.067 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 3748
2023-04-03T15:22:49.072Z,1680535369.072 [Supervisor](INFO): Main Thread ID is 3654
2023-04-03T15:22:49.072Z,1680535369.072 [Supervisor](DEBUG): Running supervisor.
2023-04-03T15:22:49.073Z,1680535369.073 [CommandExec ThreadHandler](INFO): Handler Thread ID is 3749
2023-04-03T15:22:49.073Z,1680535369.073 [CommandExec](INFO): Initializing the command executive.
2023-04-03T15:22:49.075Z,1680535369.075 [CommandLine ThreadHandler](INFO): Handler Thread ID is 3750
2023-04-03T15:22:49.077Z,1680535369.077 [controlThread ThreadHandler](INFO): Handler Thread ID is 3751
2023-04-03T15:22:49.078Z,1680535369.078 [controlThread](DEBUG): Initializing ControlThread
2023-04-03T15:22:49.079Z,1680535369.079 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2023-04-03T15:22:49.079Z,1680535369.079 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2023-04-03T15:22:49.079Z,1680535369.079 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2023-04-03T15:22:49.080Z,1680535369.080 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2023-04-03T15:22:49.080Z,1680535369.080 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2023-04-03T15:22:49.087Z,1680535369.087 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2023-04-03T15:22:49.087Z,1680535369.087 [NavChart](DEBUG): Initialize NavChart Navigation.
2023-04-03T15:22:49.088Z,1680535369.088 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2023-04-03T15:22:49.088Z,1680535369.088 [SBIT](INFO): Initialize SBIT Component.
2023-04-03T15:22:49.089Z,1680535369.089 [SBIT](IMPORTANT): git: 2023-03-31_A
2023-04-03T15:22:49.089Z,1680535369.089 [SBIT](INFO): git hash: af64d0505c79dd7b718d6df4bbafdde730718da9
2023-04-03T15:22:49.089Z,1680535369.089 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2023-04-03T15:22:49.090Z,1680535369.090 [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 Mar 17 08:23:48 PDT 2021
2023-04-03T15:22:49.092Z,1680535369.092 [SBIT](INFO): Beginning SBIT in 91.000000 seconds.
2023-04-03T15:22:49.092Z,1680535369.092 [IBIT](INFO): Initialize IBIT Component.
2023-04-03T15:22:49.093Z,1680535369.093 [CBIT](DEBUG): Initialize CBIT Component.
2023-04-03T15:22:49.094Z,1680535369.094 [logger ThreadHandler](INFO): Handler Thread ID is 3752
2023-04-03T15:22:49.104Z,1680535369.104 [CBIT](DEBUG): Initialized mux pins.
2023-04-03T15:22:49.104Z,1680535369.104 [CBIT](DEBUG): Initializing the watchdog timer.
2023-04-03T15:22:49.114Z,1680535369.114 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 3753
2023-04-03T15:22:49.124Z,1680535369.124 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 3754
2023-04-03T15:22:49.125Z,1680535369.125 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2023-04-03T15:22:49.128Z,1680535369.128 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2023-04-03T15:22:49.129Z,1680535369.129 [CBIT](DEBUG): Initializing heartbeat.
2023-04-03T15:22:49.136Z,1680535369.136 [Onboard ThreadHandler](INFO): Handler Thread ID is 3755
2023-04-03T15:22:49.154Z,1680535369.154 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 3756
2023-04-03T15:22:49.177Z,1680535369.177 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 3757
2023-04-03T15:22:49.178Z,1680535369.178 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2023-04-03T15:22:49.181Z,1680535369.181 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 3759
2023-04-03T15:22:49.185Z,1680535369.185 [WetLabsBB2FL](INFO): Powering up
2023-04-03T15:22:49.186Z,1680535369.186 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 3761
2023-04-03T15:22:49.188Z,1680535369.188 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2023-04-03T15:22:49.188Z,1680535369.188 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2023-04-03T15:22:49.189Z,1680535369.189 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2023-04-03T15:22:49.189Z,1680535369.189 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2023-04-03T15:22:49.189Z,1680535369.189 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2023-04-03T15:22:49.189Z,1680535369.189 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2023-04-03T15:22:49.189Z,1680535369.189 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2023-04-03T15:22:49.189Z,1680535369.189 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2023-04-03T15:22:49.200Z,1680535369.200 [CBIT](DEBUG): Deactivating GF circuits.
2023-04-03T15:22:49.200Z,1680535369.200 [CBIT](DEBUG): Deactivating emergency mode.
2023-04-03T15:22:49.240Z,1680535369.240 [CBIT](DEBUG): Backplane powered.
2023-04-03T15:22:49.245Z,1680535369.245 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2023-04-03T15:22:49.247Z,1680535369.247 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2023-04-03T15:22:49.248Z,1680535369.248 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2023-04-03T15:22:49.249Z,1680535369.249 [LoopControl](DEBUG): Initialize LoopControlComponent.
2023-04-03T15:22:49.250Z,1680535369.250 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml
2023-04-03T15:22:49.268Z,1680535369.268 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2023-04-03T15:22:49.287Z,1680535369.287 [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>


2023-04-03T15:22:49.292Z,1680535369.292 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml
2023-04-03T15:22:49.410Z,1680535369.410 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2023-04-03T15:22:49.411Z,1680535369.411 [Default:A.Wait](DEBUG): Construct Wait.
2023-04-03T15:22:49.429Z,1680535369.429 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2023-04-03T15:22:49.526Z,1680535369.526 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2023-04-03T15:22:49.551Z,1680535369.551 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2023-04-03T15:22:49.560Z,1680535369.560 [Radio_Surface](INFO): Powering up
2023-04-03T15:22:49.606Z,1680535369.606 [Default:E.Execute](DEBUG): Construct Execute.
2023-04-03T15:22:49.609Z,1680535369.609 [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="P4H">
                <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>


2023-04-03T15:22:49.614Z,1680535369.614 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,PowerOnly,Power24vConverter,Waterlinked,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter,
2023-04-03T15:22:49.630Z,1680535369.630 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2023-04-03T15:22:49.691Z,1680535369.691 [Power24vConverter](INFO): Powering up.
2023-04-03T15:22:49.738Z,1680535369.738 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2023-04-03T15:22:49.796Z,1680535369.796 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2023-04-03T15:22:49.797Z,1680535369.797 [ElevatorServo](DEBUG): Initializing EZServoServo.
2023-04-03T15:22:49.801Z,1680535369.801 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2023-04-03T15:22:49.802Z,1680535369.802 [MassServo](DEBUG): Initializing EZServoServo.
2023-04-03T15:22:49.808Z,1680535369.808 [MassServo](DEBUG): Initializing MassServo.
2023-04-03T15:22:49.809Z,1680535369.809 [RudderServo](DEBUG): Initializing EZServoServo.
2023-04-03T15:22:49.826Z,1680535369.826 [RudderServo](DEBUG): Initializing RudderServo.
2023-04-03T15:22:49.827Z,1680535369.827 [ThrusterHE](DEBUG): Initializing EZServoServo.
2023-04-03T15:22:49.840Z,1680535369.840 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2023-04-03T15:22:51.796Z,1680535371.796 [WetLabsBB2FL](INFO): Powering down
2023-04-03T15:22:55.517Z,1680535375.517 [ThrusterHE](ERROR): Zero Speed Commanded.
2023-04-03T15:22:58.842Z,1680535378.842 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004687
2023-04-03T15:23:17.502Z,1680535397.502 [NAL9602](INFO): Powering up NAL9602
2023-04-03T15:23:24.060Z,1680535404.060 [Waterlinked](INFO): Powering down
2023-04-03T15:23:28.410Z,1680535408.410 [NAL9602](INFO): NAL9602 initialized
2023-04-03T15:24:14.565Z,1680535454.565 [CommandExec](IMPORTANT): got command failComponent
2023-04-03T15:24:14.565Z,1680535454.565 [CommandExec](IMPORTANT): Failed components:
2023-04-03T15:24:14.565Z,1680535454.565 [CommandExec](IMPORTANT): No failed Components.
2023-04-03T15:24:20.562Z,1680535460.562 [SBIT](IMPORTANT): Beginning Startup BIT
2023-04-03T15:24:20.566Z,1680535460.566 [CBIT](IMPORTANT): Beginning ground fault scan
2023-04-03T15:24:23.803Z,1680535463.803 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2023-04-03T15:24:26.179Z,1680535466.179 [BPC1](ERROR): BPC1B: No match for serial number 0000 in BPC1B's battery stick inventory (sticks 32-62 in onboard configuration file).
2023-04-03T15:24:31.500Z,1680535471.500 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.006050
CHAN A1 (24V): 0.000428
CHAN A2 (12V): -0.005320
CHAN A3 (5V): -0.002524
CHAN B0 (3.3V): -0.000767
CHAN B1 (3.15aV): -0.001006
CHAN B2 (3.15bV): -0.001673
CHAN B3 (GND): -0.000325
OPEN: 0.003840
Full Scale: +/- 1 mA
2023-04-03T15:25:14.697Z,1680535514.697 [SBIT](IMPORTANT): SBIT PASSED
2023-04-03T15:25:14.697Z,1680535514.697 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2023-04-03T15:25:14.698Z,1680535514.698 [SBIT](IMPORTANT): DAT.loadAtStartup=0 bool;

2023-04-03T15:25:14.698Z,1680535514.698 [SBIT](IMPORTANT): ESPComponent.sampleTimeout=2 minute;

2023-04-03T15:25:14.700Z,1680535514.700 [SBIT](IMPORTANT): Express linearApproximation _.ayeris_disk_space 100.000000 gigabyte;

2023-04-03T15:25:14.701Z,1680535514.701 [SBIT](IMPORTANT): Express linearApproximation _.ayeris_particle_counts 300.000000 count_per_second;

2023-04-03T15:25:14.701Z,1680535514.701 [SBIT](IMPORTANT): Express linearApproximation _.ayeris_particle_shape 10.000000 count_per_second;

2023-04-03T15:25:14.701Z,1680535514.701 [SBIT](IMPORTANT): Express linearApproximation _.ayeris_particle_slope 0.200000 count_per_millimeter;

2023-04-03T15:25:14.701Z,1680535514.701 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=236.612869 cubic_centimeter;

2023-04-03T15:25:14.701Z,1680535514.701 [SBIT](IMPORTANT): VerticalControl.massDefault=17.883769 millimeter;

2023-04-03T15:25:15.091Z,1680535515.091 [MissionManager](IMPORTANT): Started mission Startup
2023-04-03T15:25:15.091Z,1680535515.091 [Startup] Running Loop=1
2023-04-03T15:25:15.091Z,1680535515.091 [Startup](DEBUG): Aggregate::initialize Startup
2023-04-03T15:25:15.091Z,1680535515.091 [Startup:A.GoToSurface] Running Loop=1
2023-04-03T15:25:15.092Z,1680535515.092 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-04-03T15:25:15.092Z,1680535515.092 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-04-03T15:25:15.093Z,1680535515.093 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-04-03T15:25:15.093Z,1680535515.093 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-04-03T15:25:15.093Z,1680535515.093 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-04-03T15:25:15.094Z,1680535515.094 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-04-03T15:25:15.095Z,1680535515.095 [Startup:StartupSatComms] Running Loop=1
2023-04-03T15:25:15.095Z,1680535515.095 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2023-04-03T15:25:15.095Z,1680535515.095 [Startup:StartupSatComms:A] Running Loop=1
2023-04-03T15:25:15.494Z,1680535515.494 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2023-04-03T15:25:17.541Z,1680535517.541 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2023-04-03T15:25:28.466Z,1680535528.466 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2023-04-03T15:25:39.778Z,1680535539.778 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2023-04-03T15:25:49.530Z,1680535549.530 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2023-04-03T15:25:49.530Z,1680535549.530 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-04-03T15:25:49.531Z,1680535549.531 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1
2023-04-03T15:25:49.531Z,1680535549.531 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2023-04-03T15:25:49.601Z,1680535549.601 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-04-03T15:25:49.601Z,1680535549.601 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2023-04-03T15:25:49.888Z,1680535549.888 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-04-03T15:25:49.888Z,1680535549.888 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2023-04-03T15:25:49.892Z,1680535549.892 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2023-04-03T15:25:49.892Z,1680535549.892 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1
2023-04-03T15:25:50.245Z,1680535550.245 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2023-04-03T15:26:09.609Z,1680535569.609 [BPC1](ERROR): BPC1A: No match for serial number 0000 in BPC1A's battery stick inventory (sticks 1-31 in onboard configuration file).
2023-04-03T15:26:15.279Z,1680535575.279 [Startup:StartupSatComms:A](INFO): Timed out from 2023-04-03T15:25:15.1Z
2023-04-03T15:26:15.279Z,1680535575.279 [Startup:StartupSatComms:A] Stopped
2023-04-03T15:26:15.279Z,1680535575.279 [Startup:StartupSatComms:B] Running Loop=1
2023-04-03T15:26:15.679Z,1680535575.679 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2023-04-03T15:26:16.526Z,1680535576.526 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2023-04-03T15:26:22.876Z,1680535582.876 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20230331T213634/Courier0031.lzma
2023-04-03T15:26:23.878Z,1680535583.878 [DataOverHttps](INFO): Moved sent file to Logs/20230331T213634/Courier0031.lzma.bak
2023-04-03T15:26:23.878Z,1680535583.878 [DataOverHttps](INFO): SBD MOMSN=18010216
2023-04-03T15:26:39.248Z,1680535599.248 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20230403T152239/Courier0000.lzma
2023-04-03T15:26:40.250Z,1680535600.250 [DataOverHttps](INFO): Moved sent file to Logs/20230403T152239/Courier0000.lzma.bak
2023-04-03T15:26:40.250Z,1680535600.250 [DataOverHttps](INFO): SBD MOMSN=18010218
2023-04-03T15:26:55.728Z,1680535615.728 [DataOverHttps](INFO): Sending 192 bytes from file Logs/20230331T213634/Express0032.lzma
2023-04-03T15:26:56.730Z,1680535616.730 [DataOverHttps](INFO): Moved sent file to Logs/20230331T213634/Express0032.lzma.bak
2023-04-03T15:26:56.730Z,1680535616.730 [DataOverHttps](INFO): SBD MOMSN=18010222
2023-04-03T15:27:11.025Z,1680535631.025 [BPC1](ERROR): BPC1A: No match for serial number 0000 in BPC1A's battery stick inventory (sticks 1-31 in onboard configuration file).
2023-04-03T15:27:12.322Z,1680535632.322 [DataOverHttps](INFO): Sending 879 bytes from file Logs/20230403T152239/Express0001.lzma
2023-04-03T15:27:13.322Z,1680535633.322 [DataOverHttps](INFO): Moved sent file to Logs/20230403T152239/Express0001.lzma.bak
2023-04-03T15:27:13.322Z,1680535633.322 [DataOverHttps](INFO): SBD MOMSN=18010227
2023-04-03T15:27:14.674Z,1680535634.674 [Startup:StartupSatComms:B] Stopped
2023-04-03T15:27:14.675Z,1680535634.675 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2023-04-03T15:27:14.675Z,1680535634.675 [Startup:StartupSatComms] Stopped
2023-04-03T15:27:14.675Z,1680535634.675 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2023-04-03T15:27:14.675Z,1680535634.675 [Startup](INFO): Completed Startup
2023-04-03T15:27:14.676Z,1680535634.676 [MissionManager](INFO): Startup is completed.
2023-04-03T15:27:14.676Z,1680535634.676 [MissionManager](INFO): Uninitializing Mission Startup
2023-04-03T15:27:14.676Z,1680535634.676 [Startup] Stopped
2023-04-03T15:27:14.676Z,1680535634.676 [Startup](DEBUG): Aggregate::uninitialize Startup
2023-04-03T15:27:14.676Z,1680535634.676 [Startup:A.GoToSurface] Stopped
2023-04-03T15:27:14.676Z,1680535634.676 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2023-04-03T15:27:15.063Z,1680535635.063 [MissionManager](IMPORTANT): Started mission Default
2023-04-03T15:27:15.063Z,1680535635.063 [Default] Running Loop=1
2023-04-03T15:27:15.064Z,1680535635.064 [Default](DEBUG): Aggregate::initialize Default
2023-04-03T15:27:15.064Z,1680535635.064 [Default:B.GoToSurface] Running Loop=1
2023-04-03T15:27:15.064Z,1680535635.064 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-04-03T15:27:15.064Z,1680535635.064 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-04-03T15:27:15.064Z,1680535635.064 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-04-03T15:27:15.065Z,1680535635.065 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-04-03T15:27:15.065Z,1680535635.065 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-04-03T15:27:15.065Z,1680535635.065 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-04-03T15:27:15.066Z,1680535635.066 [Default:A.Wait] Running Loop=1
2023-04-03T15:27:15.066Z,1680535635.066 [Default:A.Wait](DEBUG): Initialize Wait Component.
2023-04-03T15:27:28.393Z,1680535648.393 [Default:A.Wait](INFO): Done Waiting.
2023-04-03T15:27:28.393Z,1680535648.393 [Default:A.Wait] Stopped
2023-04-03T15:27:28.393Z,1680535648.393 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2023-04-03T15:27:28.800Z,1680535648.800 [Default:CheckIn] Running Loop=1
2023-04-03T15:27:28.801Z,1680535648.801 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-03T15:27:28.801Z,1680535648.801 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-03T15:27:29.214Z,1680535649.214 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2023-04-03T15:27:37.733Z,1680535657.733 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2023-04-03T15:28:14.497Z,1680535694.497 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2023-04-03T15:28:31.818Z,1680535711.818 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-04-03T15:28:50.418Z,1680535730.418 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2023-04-03T15:28:50.418Z,1680535730.418 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-04-03T15:28:50.419Z,1680535730.419 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 2
2023-04-03T15:28:50.419Z,1680535730.419 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2023-04-03T15:28:50.430Z,1680535730.430 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-04-03T15:28:50.430Z,1680535730.430 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2023-04-03T15:28:50.850Z,1680535730.850 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-04-03T15:28:50.850Z,1680535730.850 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2023-04-03T15:28:50.851Z,1680535730.851 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2023-04-03T15:28:50.851Z,1680535730.851 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 2
2023-04-03T15:28:51.233Z,1680535731.233 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2023-04-03T15:28:58.950Z,1680535738.950 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2023-04-03T15:29:13.485Z,1680535753.485 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2023-04-03T15:29:58.735Z,1680535798.735 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2023-04-03T15:30:58.065Z,1680535858.065 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2023-04-03T15:30:58.068Z,1680535858.068 [BPC1](INFO): Received data from all battery sticks.
2023-04-03T15:31:51.401Z,1680535911.401 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2023-04-03T15:31:51.401Z,1680535911.401 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-04-03T15:31:51.402Z,1680535911.402 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 3
2023-04-03T15:31:51.402Z,1680535911.402 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2023-04-03T15:31:51.441Z,1680535911.441 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-04-03T15:31:51.441Z,1680535911.441 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2023-04-03T15:31:51.815Z,1680535911.815 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-04-03T15:31:51.815Z,1680535911.815 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2023-04-03T15:31:51.815Z,1680535911.815 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2023-04-03T15:31:51.815Z,1680535911.815 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 3
2023-04-03T15:31:52.212Z,1680535912.212 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2023-04-03T15:32:28.976Z,1680535948.976 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-04-03T15:27:28.8Z
2023-04-03T15:32:28.976Z,1680535948.976 [Default:CheckIn:Read_GPS] Stopped
2023-04-03T15:32:28.976Z,1680535948.976 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-03T15:32:29.379Z,1680535949.379 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2023-04-03T15:32:35.864Z,1680535955.864 [DataOverHttps](INFO): Sending 168 bytes from file Logs/20230403T152239/Courier0004.lzma
2023-04-03T15:32:36.866Z,1680535956.866 [DataOverHttps](INFO): Moved sent file to Logs/20230403T152239/Courier0004.lzma.bak
2023-04-03T15:32:36.866Z,1680535956.866 [DataOverHttps](INFO): SBD MOMSN=18010706
2023-04-03T15:32:52.236Z,1680535972.236 [DataOverHttps](INFO): Sending 186 bytes from file Logs/20230403T152239/Express0005.lzma
2023-04-03T15:32:53.238Z,1680535973.238 [DataOverHttps](INFO): Moved sent file to Logs/20230403T152239/Express0005.lzma.bak
2023-04-03T15:32:53.238Z,1680535973.238 [DataOverHttps](INFO): SBD MOMSN=18010708
2023-04-03T15:32:54.435Z,1680535974.435 [Default:CheckIn:Read_Iridium] Stopped
2023-04-03T15:32:54.436Z,1680535974.436 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-03T15:32:54.436Z,1680535974.436 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-03T15:33:25.137Z,1680536005.137 [Power24vConverter](INFO): Powering down.
2023-04-03T15:33:30.782Z,1680536010.782 [NAL9602](FAULT): GPS failed to acquire within timeout.
2023-04-03T15:33:30.782Z,1680536010.782 [NAL9602] Data Fault, FailCount= 1
2023-04-03T15:33:30.782Z,1680536010.782 [NAL9602](ERROR): Data Fault
2023-04-03T15:33:30.847Z,1680536010.847 [CBIT](ERROR): Data Fault in component: NAL9602
2023-04-03T15:33:31.177Z,1680536011.177 [NAL9602](INFO): Powering down
2023-04-03T15:33:32.027Z,1680536012.027 [CBIT](INFO): Clearing failed state for component NAL9602
2023-04-03T15:33:32.027Z,1680536012.027 [NAL9602] No Fault, FailCount= 1
2023-04-03T15:34:01.481Z,1680536041.481 [NAL9602](INFO): Powering up NAL9602
2023-04-03T15:34:12.394Z,1680536052.394 [NAL9602](INFO): NAL9602 initialized
2023-04-03T15:34:52.413Z,1680536092.413 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2023-04-03T15:34:52.413Z,1680536092.413 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-04-03T15:34:52.414Z,1680536092.414 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 4
2023-04-03T15:34:52.414Z,1680536092.414 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2023-04-03T15:34:52.425Z,1680536092.425 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-04-03T15:34:52.425Z,1680536092.425 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2023-04-03T15:34:52.834Z,1680536092.834 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-04-03T15:34:52.834Z,1680536092.834 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2023-04-03T15:34:52.835Z,1680536092.835 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2023-04-03T15:34:52.835Z,1680536092.835 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 4
2023-04-03T15:34:53.197Z,1680536093.197 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2023-04-03T15:37:53.405Z,1680536273.405 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2023-04-03T15:37:53.405Z,1680536273.405 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-04-03T15:37:53.406Z,1680536273.406 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 5
2023-04-03T15:37:53.406Z,1680536273.406 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2023-04-03T15:37:53.417Z,1680536273.417 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-04-03T15:37:53.417Z,1680536273.417 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2023-04-03T15:37:53.822Z,1680536273.822 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-04-03T15:37:53.822Z,1680536273.822 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2023-04-03T15:37:53.823Z,1680536273.823 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2023-04-03T15:37:53.823Z,1680536273.823 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 5
2023-04-03T15:37:54.192Z,1680536274.192 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2023-04-03T15:37:55.010Z,1680536275.010 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-03T15:37:55.010Z,1680536275.010 [Default:CheckIn:C.Wait] Stopped
2023-04-03T15:37:55.011Z,1680536275.011 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-03T15:37:55.011Z,1680536275.011 [Default:CheckIn:D] Running Loop=1
2023-04-03T15:37:55.407Z,1680536275.407 [Default:CheckIn:D] Stopped
2023-04-03T15:37:55.407Z,1680536275.407 [Default:CheckIn:E] Running Loop=1
2023-04-03T15:37:55.843Z,1680536275.843 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.672390 min 
2023-04-03T15:37:55.843Z,1680536275.843 [Default:CheckIn:E] Stopped
2023-04-03T15:37:55.843Z,1680536275.843 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-03T15:37:55.843Z,1680536275.843 [Default:CheckIn] Stopped
2023-04-03T15:37:55.843Z,1680536275.843 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-03T15:37:55.844Z,1680536275.844 [Default:CheckIn](INFO): Running loop #2
2023-04-03T15:37:55.844Z,1680536275.844 [Default:CheckIn] Running Loop=2
2023-04-03T15:37:55.845Z,1680536275.845 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-03T15:37:55.845Z,1680536275.845 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-03T15:40:54.381Z,1680536454.381 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6
2023-04-03T15:40:54.381Z,1680536454.381 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-04-03T15:40:54.382Z,1680536454.382 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 6
2023-04-03T15:40:54.382Z,1680536454.382 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2023-04-03T15:40:54.413Z,1680536454.413 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-04-03T15:40:54.413Z,1680536454.413 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2023-04-03T15:40:54.791Z,1680536454.791 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-04-03T15:40:54.791Z,1680536454.791 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6
2023-04-03T15:40:54.791Z,1680536454.791 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2023-04-03T15:40:54.791Z,1680536454.791 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 6
2023-04-03T15:40:55.181Z,1680536455.181 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2023-04-03T15:42:55.992Z,1680536575.992 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-04-03T15:37:55.8Z
2023-04-03T15:42:55.993Z,1680536575.993 [Default:CheckIn:Read_GPS] Stopped
2023-04-03T15:42:55.993Z,1680536575.993 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-03T15:43:00.039Z,1680536580.039 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20230403T152239/Courier0007.lzma
2023-04-03T15:43:01.042Z,1680536581.042 [DataOverHttps](INFO): Moved sent file to Logs/20230403T152239/Courier0007.lzma.bak
2023-04-03T15:43:01.042Z,1680536581.042 [DataOverHttps](INFO): SBD MOMSN=18011087
2023-04-03T15:43:16.420Z,1680536596.420 [DataOverHttps](INFO): Sending 181 bytes from file Logs/20230403T152239/Express0008.lzma
2023-04-03T15:43:17.422Z,1680536597.422 [DataOverHttps](INFO): Moved sent file to Logs/20230403T152239/Express0008.lzma.bak
2023-04-03T15:43:17.422Z,1680536597.422 [DataOverHttps](INFO): SBD MOMSN=18011089
2023-04-03T15:43:18.614Z,1680536598.614 [Default:CheckIn:Read_Iridium] Stopped
2023-04-03T15:43:18.614Z,1680536598.614 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-03T15:43:18.614Z,1680536598.614 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-03T15:43:55.374Z,1680536635.374 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7
2023-04-03T15:43:55.374Z,1680536635.374 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-04-03T15:43:55.375Z,1680536635.375 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 7
2023-04-03T15:43:55.375Z,1680536635.375 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2023-04-03T15:43:55.386Z,1680536635.386 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-04-03T15:43:55.386Z,1680536635.386 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2023-04-03T15:43:55.808Z,1680536635.808 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-04-03T15:43:55.808Z,1680536635.808 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7
2023-04-03T15:43:55.812Z,1680536635.812 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2023-04-03T15:43:55.812Z,1680536635.812 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 7
2023-04-03T15:43:56.177Z,1680536636.177 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2023-04-03T15:44:14.750Z,1680536654.750 [NAL9602](FAULT): GPS failed to acquire within timeout.
2023-04-03T15:44:14.750Z,1680536654.750 [NAL9602] Data Fault, FailCount= 2
2023-04-03T15:44:14.750Z,1680536654.750 [NAL9602](ERROR): Data Fault
2023-04-03T15:44:14.812Z,1680536654.812 [CBIT](ERROR): Data Fault in component: NAL9602
2023-04-03T15:44:15.157Z,1680536655.157 [NAL9602](INFO): Powering down
2023-04-03T15:44:15.989Z,1680536655.989 [CBIT](INFO): Clearing failed state for component NAL9602
2023-04-03T15:44:15.989Z,1680536655.989 [NAL9602] No Fault, FailCount= 2
2023-04-03T15:44:45.460Z,1680536685.460 [NAL9602](INFO): Powering up NAL9602
2023-04-03T15:44:56.366Z,1680536696.366 [NAL9602](INFO): NAL9602 initialized
2023-04-03T15:46:56.366Z,1680536816.366 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8
2023-04-03T15:46:56.366Z,1680536816.366 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-04-03T15:46:56.367Z,1680536816.367 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 8
2023-04-03T15:46:56.367Z,1680536816.367 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2023-04-03T15:46:56.378Z,1680536816.378 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-04-03T15:46:56.378Z,1680536816.378 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2023-04-03T15:46:56.798Z,1680536816.798 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-04-03T15:46:56.798Z,1680536816.798 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8
2023-04-03T15:46:56.799Z,1680536816.799 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2023-04-03T15:46:56.799Z,1680536816.799 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 8
2023-04-03T15:46:57.185Z,1680536817.185 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2023-04-03T15:48:19.183Z,1680536899.183 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-03T15:48:19.183Z,1680536899.183 [Default:CheckIn:C.Wait] Stopped
2023-04-03T15:48:19.183Z,1680536899.183 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-03T15:48:19.183Z,1680536899.183 [Default:CheckIn:D] Running Loop=1
2023-04-03T15:48:19.587Z,1680536899.587 [Default:CheckIn:D] Stopped
2023-04-03T15:48:19.587Z,1680536899.587 [Default:CheckIn:E] Running Loop=1
2023-04-03T15:48:20.011Z,1680536900.011 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 21.075387 min 
2023-04-03T15:48:20.011Z,1680536900.011 [Default:CheckIn:E] Stopped
2023-04-03T15:48:20.011Z,1680536900.011 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-03T15:48:20.012Z,1680536900.012 [Default:CheckIn] Stopped
2023-04-03T15:48:20.012Z,1680536900.012 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-03T15:48:20.012Z,1680536900.012 [Default:CheckIn](INFO): Running loop #3
2023-04-03T15:48:20.012Z,1680536900.012 [Default:CheckIn] Running Loop=3
2023-04-03T15:48:20.012Z,1680536900.012 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-03T15:48:20.012Z,1680536900.012 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-03T15:49:57.373Z,1680536997.373 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 9
2023-04-03T15:49:57.373Z,1680536997.373 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-04-03T15:49:57.374Z,1680536997.374 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 9
2023-04-03T15:49:57.374Z,1680536997.374 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2023-04-03T15:49:57.385Z,1680536997.385 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-04-03T15:49:57.385Z,1680536997.385 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2023-04-03T15:49:57.786Z,1680536997.786 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-04-03T15:49:57.786Z,1680536997.786 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 9
2023-04-03T15:49:57.787Z,1680536997.787 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2023-04-03T15:49:57.787Z,1680536997.787 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 9
2023-04-03T15:49:58.161Z,1680536998.161 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2023-04-03T15:52:58.369Z,1680537178.369 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 10
2023-04-03T15:52:58.369Z,1680537178.369 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-04-03T15:52:58.370Z,1680537178.370 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 10
2023-04-03T15:52:58.370Z,1680537178.370 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2023-04-03T15:52:58.382Z,1680537178.382 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-04-03T15:52:58.382Z,1680537178.382 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2023-04-03T15:52:58.786Z,1680537178.786 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-04-03T15:52:58.786Z,1680537178.786 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 10
2023-04-03T15:52:58.786Z,1680537178.786 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2023-04-03T15:52:58.786Z,1680537178.786 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 10
2023-04-03T15:52:59.153Z,1680537179.153 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2023-04-03T15:53:20.176Z,1680537200.176 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-04-03T15:48:20.0Z
2023-04-03T15:53:20.176Z,1680537200.176 [Default:CheckIn:Read_GPS] Stopped
2023-04-03T15:53:20.176Z,1680537200.176 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-03T15:53:25.147Z,1680537205.147 [DataOverHttps](INFO): Sending 38 bytes from file Logs/20230403T152239/Courier0010.lzma
2023-04-03T15:53:26.150Z,1680537206.150 [DataOverHttps](INFO): Moved sent file to Logs/20230403T152239/Courier0010.lzma.bak
2023-04-03T15:53:26.150Z,1680537206.150 [DataOverHttps](INFO): SBD MOMSN=18011485
2023-04-03T15:53:41.504Z,1680537221.504 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20230403T152239/Express0011.lzma
2023-04-03T15:53:42.506Z,1680537222.506 [DataOverHttps](INFO): Moved sent file to Logs/20230403T152239/Express0011.lzma.bak
2023-04-03T15:53:42.506Z,1680537222.506 [DataOverHttps](INFO): SBD MOMSN=18011487
2023-04-03T15:53:43.670Z,1680537223.670 [Default:CheckIn:Read_Iridium] Stopped
2023-04-03T15:53:43.670Z,1680537223.670 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-03T15:53:43.670Z,1680537223.670 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-03T15:54:58.054Z,1680537298.054 [NAL9602](FAULT): GPS failed to acquire within timeout.
2023-04-03T15:54:58.054Z,1680537298.054 [NAL9602] Data Fault, FailCount= 3
2023-04-03T15:54:58.054Z,1680537298.054 [NAL9602](ERROR): Data Fault
2023-04-03T15:54:58.133Z,1680537298.133 [CBIT](ERROR): Data Fault in component: NAL9602
2023-04-03T15:54:58.457Z,1680537298.457 [NAL9602](INFO): Powering down
2023-04-03T15:54:59.308Z,1680537299.308 [CBIT](INFO): Clearing failed state for component NAL9602
2023-04-03T15:54:59.309Z,1680537299.309 [NAL9602] No Fault, FailCount= 3
2023-04-03T15:55:28.762Z,1680537328.762 [NAL9602](INFO): Powering up NAL9602
2023-04-03T15:55:39.670Z,1680537339.670 [NAL9602](INFO): NAL9602 initialized
2023-04-03T15:55:59.518Z,1680537359.518 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 11
2023-04-03T15:55:59.518Z,1680537359.518 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-04-03T15:55:59.519Z,1680537359.519 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 11
2023-04-03T15:55:59.519Z,1680537359.519 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2023-04-03T15:55:59.530Z,1680537359.530 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-04-03T15:55:59.530Z,1680537359.530 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2023-04-03T15:55:59.931Z,1680537359.931 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-04-03T15:55:59.931Z,1680537359.931 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 11
2023-04-03T15:55:59.931Z,1680537359.931 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2023-04-03T15:55:59.932Z,1680537359.932 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 11
2023-04-03T15:56:00.299Z,1680537360.299 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2023-04-03T15:58:44.315Z,1680537524.315 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-03T15:58:44.315Z,1680537524.315 [Default:CheckIn:C.Wait] Stopped
2023-04-03T15:58:44.316Z,1680537524.316 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-03T15:58:44.316Z,1680537524.316 [Default:CheckIn:D] Running Loop=1
2023-04-03T15:58:44.727Z,1680537524.727 [Default:CheckIn:D] Stopped
2023-04-03T15:58:44.728Z,1680537524.728 [Default:CheckIn:E] Running Loop=1
2023-04-03T15:58:45.131Z,1680537525.131 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 31.494399 min 
2023-04-03T15:58:45.131Z,1680537525.131 [Default:CheckIn:E] Stopped
2023-04-03T15:58:45.131Z,1680537525.131 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-03T15:58:45.132Z,1680537525.132 [Default:CheckIn] Stopped
2023-04-03T15:58:45.132Z,1680537525.132 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-03T15:58:45.132Z,1680537525.132 [Default:CheckIn](INFO): Running loop #4
2023-04-03T15:58:45.132Z,1680537525.132 [Default:CheckIn] Running Loop=4
2023-04-03T15:58:45.132Z,1680537525.132 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-03T15:58:45.132Z,1680537525.132 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-03T15:59:00.497Z,1680537540.497 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 12
2023-04-03T15:59:00.497Z,1680537540.497 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-04-03T15:59:00.498Z,1680537540.498 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 12
2023-04-03T15:59:00.498Z,1680537540.498 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2023-04-03T15:59:00.537Z,1680537540.537 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-04-03T15:59:00.537Z,1680537540.537 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2023-04-03T15:59:00.908Z,1680537540.908 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-04-03T15:59:00.908Z,1680537540.908 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 12
2023-04-03T15:59:00.908Z,1680537540.908 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2023-04-03T15:59:00.908Z,1680537540.908 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 12
2023-04-03T15:59:01.321Z,1680537541.321 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2023-04-03T16:02:01.516Z,1680537721.516 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 13
2023-04-03T16:02:01.516Z,1680537721.516 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-04-03T16:02:01.528Z,1680537721.528 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 13
2023-04-03T16:02:01.529Z,1680537721.529 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2023-04-03T16:02:01.539Z,1680537721.539 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-04-03T16:02:01.539Z,1680537721.539 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2023-04-03T16:02:01.952Z,1680537721.952 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-04-03T16:02:01.953Z,1680537721.953 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 13
2023-04-03T16:02:01.954Z,1680537721.954 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2023-04-03T16:02:01.954Z,1680537721.954 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 13
2023-04-03T16:02:02.316Z,1680537722.316 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2023-04-03T16:03:45.343Z,1680537825.343 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-04-03T15:58:45.1Z
2023-04-03T16:03:45.343Z,1680537825.343 [Default:CheckIn:Read_GPS] Stopped
2023-04-03T16:03:45.343Z,1680537825.343 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-03T16:03:51.123Z,1680537831.123 [DataOverHttps](INFO): Sending 38 bytes from file Logs/20230403T152239/Courier0013.lzma
2023-04-03T16:03:52.126Z,1680537832.126 [DataOverHttps](INFO): Moved sent file to Logs/20230403T152239/Courier0013.lzma.bak
2023-04-03T16:03:52.126Z,1680537832.126 [DataOverHttps](INFO): SBD MOMSN=18011864
2023-04-03T16:04:03.904Z,1680537843.904 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160402.00,A,3648.17054,N,12147.28238,W,0.039,0.00,030423,,,A*7D
2023-04-03T16:04:03.907Z,1680537843.907 [NAL9602](INFO): GPS fix at 20230403T160402: (36.802842, -121.788040)
2023-04-03T16:04:07.876Z,1680537847.876 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20230403T152239/Express0014.lzma
2023-04-03T16:04:08.878Z,1680537848.878 [DataOverHttps](INFO): Moved sent file to Logs/20230403T152239/Express0014.lzma.bak
2023-04-03T16:04:08.878Z,1680537848.878 [DataOverHttps](INFO): SBD MOMSN=18011866
2023-04-03T16:04:09.984Z,1680537849.984 [Default:CheckIn:Read_Iridium] Stopped
2023-04-03T16:04:09.984Z,1680537849.984 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-03T16:04:09.984Z,1680537849.984 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-03T16:04:36.223Z,1680537876.223 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-03T16:09:10.609Z,1680538150.609 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-03T16:09:10.609Z,1680538150.609 [Default:CheckIn:C.Wait] Stopped
2023-04-03T16:09:10.609Z,1680538150.609 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-03T16:09:10.609Z,1680538150.609 [Default:CheckIn:D] Running Loop=1
2023-04-03T16:09:11.020Z,1680538151.020 [Default:CheckIn:D] Stopped
2023-04-03T16:09:11.020Z,1680538151.020 [Default:CheckIn:E] Running Loop=1
2023-04-03T16:09:11.412Z,1680538151.412 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 41.932406 min 
2023-04-03T16:09:11.412Z,1680538151.412 [Default:CheckIn:E] Stopped
2023-04-03T16:09:11.412Z,1680538151.412 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-03T16:09:11.412Z,1680538151.412 [Default:CheckIn] Stopped
2023-04-03T16:09:11.412Z,1680538151.412 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-03T16:09:11.413Z,1680538151.413 [Default:CheckIn](INFO): Running loop #5
2023-04-03T16:09:11.413Z,1680538151.413 [Default:CheckIn] Running Loop=5
2023-04-03T16:09:11.413Z,1680538151.413 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-03T16:09:11.413Z,1680538151.413 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-03T16:09:13.425Z,1680538153.425 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160912.00,A,3648.16537,N,12147.28466,W,0.739,202.63,030423,,,A*7F
2023-04-03T16:09:13.427Z,1680538153.427 [NAL9602](INFO): GPS fix at 20230403T160912: (36.802756, -121.788078)
2023-04-03T16:09:13.439Z,1680538153.439 [Default:CheckIn:Read_GPS] Stopped
2023-04-03T16:09:13.439Z,1680538153.439 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-03T16:09:20.860Z,1680538160.860 [DataOverHttps](INFO): Sending 222 bytes from file Logs/20230403T152239/Courier0016.lzma
2023-04-03T16:09:21.862Z,1680538161.862 [DataOverHttps](INFO): Moved sent file to Logs/20230403T152239/Courier0016.lzma.bak
2023-04-03T16:09:21.862Z,1680538161.862 [DataOverHttps](INFO): SBD MOMSN=18011876
2023-04-03T16:09:37.656Z,1680538177.656 [DataOverHttps](INFO): Sending 262 bytes from file Logs/20230403T152239/Express0017.lzma
2023-04-03T16:09:38.658Z,1680538178.658 [DataOverHttps](INFO): Moved sent file to Logs/20230403T152239/Express0017.lzma.bak
2023-04-03T16:09:38.658Z,1680538178.658 [DataOverHttps](INFO): SBD MOMSN=18011879
2023-04-03T16:09:40.126Z,1680538180.126 [Default:CheckIn:Read_Iridium] Stopped
2023-04-03T16:09:40.126Z,1680538180.126 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-03T16:09:40.127Z,1680538180.127 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-03T16:14:15.289Z,1680538455.289 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-04-03T16:14:40.757Z,1680538480.757 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-03T16:14:40.757Z,1680538480.757 [Default:CheckIn:C.Wait] Stopped
2023-04-03T16:14:40.757Z,1680538480.757 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-03T16:14:40.757Z,1680538480.757 [Default:CheckIn:D] Running Loop=1
2023-04-03T16:14:41.163Z,1680538481.163 [Default:CheckIn:D] Stopped
2023-04-03T16:14:41.163Z,1680538481.163 [Default:CheckIn:E] Running Loop=1
2023-04-03T16:14:41.560Z,1680538481.560 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 47.434998 min 
2023-04-03T16:14:41.560Z,1680538481.560 [Default:CheckIn:E] Stopped
2023-04-03T16:14:41.561Z,1680538481.561 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-03T16:14:41.561Z,1680538481.561 [Default:CheckIn] Stopped
2023-04-03T16:14:41.561Z,1680538481.561 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-03T16:14:41.561Z,1680538481.561 [Default:CheckIn](INFO): Running loop #6
2023-04-03T16:14:41.561Z,1680538481.561 [Default:CheckIn] Running Loop=6
2023-04-03T16:14:41.561Z,1680538481.561 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-03T16:14:41.561Z,1680538481.561 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-03T16:14:43.568Z,1680538483.568 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,161442.00,A,3648.16436,N,12147.28181,W,0.369,202.63,030423,,,A*7B
2023-04-03T16:14:43.570Z,1680538483.570 [NAL9602](INFO): GPS fix at 20230403T161442: (36.802739, -121.788030)
2023-04-03T16:14:43.582Z,1680538483.582 [Default:CheckIn:Read_GPS] Stopped
2023-04-03T16:14:43.582Z,1680538483.582 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-03T16:14:51.135Z,1680538491.135 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230403T152239/Courier0019.lzma
2023-04-03T16:14:52.138Z,1680538492.138 [DataOverHttps](INFO): Moved sent file to Logs/20230403T152239/Courier0019.lzma.bak
2023-04-03T16:14:52.138Z,1680538492.138 [DataOverHttps](INFO): SBD MOMSN=18012269
2023-04-03T16:15:07.852Z,1680538507.852 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20230403T152239/Express0020.lzma
2023-04-03T16:15:08.854Z,1680538508.854 [DataOverHttps](INFO): Moved sent file to Logs/20230403T152239/Express0020.lzma.bak
2023-04-03T16:15:08.854Z,1680538508.854 [DataOverHttps](INFO): SBD MOMSN=18012272
2023-04-03T16:15:10.239Z,1680538510.239 [Default:CheckIn:Read_Iridium] Stopped
2023-04-03T16:15:10.239Z,1680538510.239 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-03T16:15:10.239Z,1680538510.239 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-03T16:15:15.481Z,1680538515.481 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-03T16:20:10.815Z,1680538810.815 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-03T16:20:10.815Z,1680538810.815 [Default:CheckIn:C.Wait] Stopped
2023-04-03T16:20:10.815Z,1680538810.815 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-03T16:20:10.816Z,1680538810.816 [Default:CheckIn:D] Running Loop=1
2023-04-03T16:20:11.225Z,1680538811.225 [Default:CheckIn:D] Stopped
2023-04-03T16:20:11.225Z,1680538811.225 [Default:CheckIn:E] Running Loop=1
2023-04-03T16:20:11.627Z,1680538811.627 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 52.936019 min 
2023-04-03T16:20:11.627Z,1680538811.627 [Default:CheckIn:E] Stopped
2023-04-03T16:20:11.627Z,1680538811.627 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-03T16:20:11.627Z,1680538811.627 [Default:CheckIn] Stopped
2023-04-03T16:20:11.627Z,1680538811.627 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-03T16:20:11.627Z,1680538811.627 [Default:CheckIn](INFO): Running loop #7
2023-04-03T16:20:11.627Z,1680538811.627 [Default:CheckIn] Running Loop=7
2023-04-03T16:20:11.627Z,1680538811.627 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-03T16:20:11.627Z,1680538811.627 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-03T16:20:13.639Z,1680538813.639 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162012.00,A,3648.15842,N,12147.29956,W,0.136,234.61,030423,,,A*79
2023-04-03T16:20:13.641Z,1680538813.641 [NAL9602](INFO): GPS fix at 20230403T162012: (36.802640, -121.788326)
2023-04-03T16:20:13.682Z,1680538813.682 [Default:CheckIn:Read_GPS] Stopped
2023-04-03T16:20:13.683Z,1680538813.683 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-03T16:20:20.971Z,1680538820.971 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230403T152239/Courier0022.lzma
2023-04-03T16:20:21.987Z,1680538821.987 [DataOverHttps](INFO): Moved sent file to Logs/20230403T152239/Courier0022.lzma.bak
2023-04-03T16:20:21.988Z,1680538821.988 [DataOverHttps](INFO): SBD MOMSN=18012315
2023-04-03T16:20:37.780Z,1680538837.780 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20230403T152239/Express0023.lzma
2023-04-03T16:20:38.782Z,1680538838.782 [DataOverHttps](INFO): Moved sent file to Logs/20230403T152239/Express0023.lzma.bak
2023-04-03T16:20:38.782Z,1680538838.782 [DataOverHttps](INFO): SBD MOMSN=18012319
2023-04-03T16:20:39.905Z,1680538839.905 [Default:CheckIn:Read_Iridium] Stopped
2023-04-03T16:20:39.905Z,1680538839.905 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-03T16:20:39.905Z,1680538839.905 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-03T16:20:44.338Z,1680538844.338 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-04-03T16:20:44.412Z,1680538844.412 [NAL9602](ERROR): received: 
+CSQ:0

OK
2023-04-03T16:25:16.236Z,1680539116.236 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-04-03T16:25:40.498Z,1680539140.498 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-03T16:25:40.498Z,1680539140.498 [Default:CheckIn:C.Wait] Stopped
2023-04-03T16:25:40.498Z,1680539140.498 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-03T16:25:40.498Z,1680539140.498 [Default:CheckIn:D] Running Loop=1
2023-04-03T16:25:40.917Z,1680539140.917 [Default:CheckIn:D] Stopped
2023-04-03T16:25:40.917Z,1680539140.917 [Default:CheckIn:E] Running Loop=1
2023-04-03T16:25:41.330Z,1680539141.330 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 58.430892 min 
2023-04-03T16:25:41.330Z,1680539141.330 [Default:CheckIn:E] Stopped
2023-04-03T16:25:41.330Z,1680539141.330 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-03T16:25:41.330Z,1680539141.330 [Default:CheckIn] Stopped
2023-04-03T16:25:41.330Z,1680539141.330 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-03T16:25:41.330Z,1680539141.330 [Default:CheckIn](INFO): Running loop #8
2023-04-03T16:25:41.330Z,1680539141.330 [Default:CheckIn] Running Loop=8
2023-04-03T16:25:41.330Z,1680539141.330 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-03T16:25:41.330Z,1680539141.330 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-03T16:25:43.311Z,1680539143.311 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162542.00,A,3648.16508,N,12147.29570,W,0.097,59.40,030423,,,A*41
2023-04-03T16:25:43.314Z,1680539143.314 [NAL9602](INFO): GPS fix at 20230403T162542: (36.802751, -121.788262)
2023-04-03T16:25:43.374Z,1680539143.374 [Default:CheckIn:Read_GPS] Stopped
2023-04-03T16:25:43.374Z,1680539143.374 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-03T16:25:50.971Z,1680539150.971 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230403T152239/Courier0025.lzma
2023-04-03T16:25:51.974Z,1680539151.974 [DataOverHttps](INFO): Moved sent file to Logs/20230403T152239/Courier0025.lzma.bak
2023-04-03T16:25:51.974Z,1680539151.974 [DataOverHttps](INFO): SBD MOMSN=18012747
2023-04-03T16:26:07.668Z,1680539167.668 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20230403T152239/Express0026.lzma
2023-04-03T16:26:08.670Z,1680539168.670 [DataOverHttps](INFO): Moved sent file to Logs/20230403T152239/Express0026.lzma.bak
2023-04-03T16:26:08.670Z,1680539168.670 [DataOverHttps](INFO): SBD MOMSN=18012750
2023-04-03T16:26:09.990Z,1680539169.990 [Default:CheckIn:Read_Iridium] Stopped
2023-04-03T16:26:09.990Z,1680539169.990 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-03T16:26:09.990Z,1680539169.990 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-03T16:26:15.629Z,1680539175.629 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-03T16:31:10.618Z,1680539470.618 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-03T16:31:10.618Z,1680539470.618 [Default:CheckIn:C.Wait] Stopped
2023-04-03T16:31:10.618Z,1680539470.618 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-03T16:31:10.618Z,1680539470.618 [Default:CheckIn:D] Running Loop=1
2023-04-03T16:31:11.025Z,1680539471.025 [Default:CheckIn:D] Stopped
2023-04-03T16:31:11.025Z,1680539471.025 [Default:CheckIn:E] Running Loop=1
2023-04-03T16:31:11.427Z,1680539471.427 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 63.932694 min 
2023-04-03T16:31:11.427Z,1680539471.427 [Default:CheckIn:E] Stopped
2023-04-03T16:31:11.428Z,1680539471.428 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-03T16:31:11.428Z,1680539471.428 [Default:CheckIn] Stopped
2023-04-03T16:31:11.428Z,1680539471.428 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-03T16:31:11.428Z,1680539471.428 [Default:CheckIn](INFO): Running loop #9
2023-04-03T16:31:11.428Z,1680539471.428 [Default:CheckIn] Running Loop=9
2023-04-03T16:31:11.428Z,1680539471.428 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-03T16:31:11.428Z,1680539471.428 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-03T16:31:13.435Z,1680539473.435 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163112.00,A,3648.16790,N,12147.28245,W,0.097,59.40,030423,,,A*42
2023-04-03T16:31:13.437Z,1680539473.437 [NAL9602](INFO): GPS fix at 20230403T163112: (36.802798, -121.788041)
2023-04-03T16:31:13.478Z,1680539473.478 [Default:CheckIn:Read_GPS] Stopped
2023-04-03T16:31:13.478Z,1680539473.478 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-03T16:31:20.523Z,1680539480.523 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230403T152239/Courier0028.lzma
2023-04-03T16:31:21.538Z,1680539481.538 [DataOverHttps](INFO): Moved sent file to Logs/20230403T152239/Courier0028.lzma.bak
2023-04-03T16:31:21.538Z,1680539481.538 [DataOverHttps](INFO): SBD MOMSN=18012784
2023-04-03T16:31:37.195Z,1680539497.195 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20230403T152239/Express0029.lzma
2023-04-03T16:31:38.198Z,1680539498.198 [DataOverHttps](INFO): Moved sent file to Logs/20230403T152239/Express0029.lzma.bak
2023-04-03T16:31:38.198Z,1680539498.198 [DataOverHttps](INFO): SBD MOMSN=18012787
2023-04-03T16:31:39.305Z,1680539499.305 [Default:CheckIn:Read_Iridium] Stopped
2023-04-03T16:31:39.306Z,1680539499.306 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-03T16:31:39.306Z,1680539499.306 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-03T16:31:44.181Z,1680539504.181 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-04-03T16:31:44.264Z,1680539504.264 [NAL9602](ERROR): received: 
+CSQ:0

OK
2023-04-03T16:36:15.282Z,1680539775.282 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-04-03T16:36:39.931Z,1680539799.931 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-03T16:36:39.932Z,1680539799.932 [Default:CheckIn:C.Wait] Stopped
2023-04-03T16:36:39.932Z,1680539799.932 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-03T16:36:39.932Z,1680539799.932 [Default:CheckIn:D] Running Loop=1
2023-04-03T16:36:40.341Z,1680539800.341 [Default:CheckIn:D] Stopped
2023-04-03T16:36:40.341Z,1680539800.341 [Default:CheckIn:E] Running Loop=1
2023-04-03T16:36:40.753Z,1680539800.753 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 69.421297 min 
2023-04-03T16:36:40.753Z,1680539800.753 [Default:CheckIn:E] Stopped
2023-04-03T16:36:40.753Z,1680539800.753 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-03T16:36:40.753Z,1680539800.753 [Default:CheckIn] Stopped
2023-04-03T16:36:40.753Z,1680539800.753 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-03T16:36:40.753Z,1680539800.753 [Default:CheckIn](INFO): Running loop #10
2023-04-03T16:36:40.753Z,1680539800.753 [Default:CheckIn] Running Loop=10
2023-04-03T16:36:40.753Z,1680539800.753 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-03T16:36:40.753Z,1680539800.753 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-03T16:36:42.755Z,1680539802.755 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163642.00,A,3648.16585,N,12147.28217,W,0.855,69.26,030423,,,A*44
2023-04-03T16:36:42.757Z,1680539802.757 [NAL9602](INFO): GPS fix at 20230403T163642: (36.802764, -121.788036)
2023-04-03T16:36:42.805Z,1680539802.805 [Default:CheckIn:Read_GPS] Stopped
2023-04-03T16:36:42.805Z,1680539802.805 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-03T16:36:50.211Z,1680539810.211 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230403T152239/Courier0031.lzma
2023-04-03T16:36:51.214Z,1680539811.214 [DataOverHttps](INFO): Moved sent file to Logs/20230403T152239/Courier0031.lzma.bak
2023-04-03T16:36:51.214Z,1680539811.214 [DataOverHttps](INFO): SBD MOMSN=18012841
2023-04-03T16:37:06.924Z,1680539826.924 [DataOverHttps](INFO): Sending 205 bytes from file Logs/20230403T152239/Express0032.lzma
2023-04-03T16:37:07.922Z,1680539827.922 [DataOverHttps](INFO): Moved sent file to Logs/20230403T152239/Express0032.lzma.bak
2023-04-03T16:37:07.922Z,1680539827.922 [DataOverHttps](INFO): SBD MOMSN=18013170
2023-04-03T16:37:09.151Z,1680539829.151 [Default:CheckIn:Read_Iridium] Stopped
2023-04-03T16:37:09.151Z,1680539829.151 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-03T16:37:09.151Z,1680539829.151 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-03T16:37:15.617Z,1680539835.617 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-03T16:38:22.692Z,1680539902.692 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2023-04-03T16:38:22.695Z,1680539902.695 [BPC1](INFO): Received data from all battery sticks.
2023-04-03T16:42:09.729Z,1680540129.729 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-03T16:42:09.729Z,1680540129.729 [Default:CheckIn:C.Wait] Stopped
2023-04-03T16:42:09.729Z,1680540129.729 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-03T16:42:09.729Z,1680540129.729 [Default:CheckIn:D] Running Loop=1
2023-04-03T16:42:10.144Z,1680540130.144 [Default:CheckIn:D] Stopped
2023-04-03T16:42:10.144Z,1680540130.144 [Default:CheckIn:E] Running Loop=1
2023-04-03T16:42:10.540Z,1680540130.540 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 74.918009 min 
2023-04-03T16:42:10.540Z,1680540130.540 [Default:CheckIn:E] Stopped
2023-04-03T16:42:10.541Z,1680540130.541 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-03T16:42:10.541Z,1680540130.541 [Default:CheckIn] Stopped
2023-04-03T16:42:10.541Z,1680540130.541 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-03T16:42:10.541Z,1680540130.541 [Default:CheckIn](INFO): Running loop #11
2023-04-03T16:42:10.541Z,1680540130.541 [Default:CheckIn] Running Loop=11
2023-04-03T16:42:10.541Z,1680540130.541 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-03T16:42:10.541Z,1680540130.541 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-03T16:42:12.551Z,1680540132.551 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164211.00,A,3648.16649,N,12147.28073,W,0.156,69.26,030423,,,A*48
2023-04-03T16:42:12.553Z,1680540132.553 [NAL9602](INFO): GPS fix at 20230403T164211: (36.802775, -121.788012)
2023-04-03T16:42:12.565Z,1680540132.565 [Default:CheckIn:Read_GPS] Stopped
2023-04-03T16:42:12.565Z,1680540132.565 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-03T16:42:13.365Z,1680540133.365 [Default:CheckIn:Read_Iridium] Stopped
2023-04-03T16:42:13.365Z,1680540133.365 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-03T16:42:13.365Z,1680540133.365 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-03T16:42:43.250Z,1680540163.250 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-04-03T16:42:43.324Z,1680540163.324 [NAL9602](ERROR): received: 
+CSQ:0

OK
2023-04-03T16:47:13.940Z,1680540433.940 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-03T16:47:13.940Z,1680540433.940 [Default:CheckIn:C.Wait] Stopped
2023-04-03T16:47:13.940Z,1680540433.940 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-03T16:47:13.941Z,1680540433.941 [Default:CheckIn:D] Running Loop=1
2023-04-03T16:47:14.334Z,1680540434.334 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-04-03T16:47:14.347Z,1680540434.347 [Default:CheckIn:D] Stopped
2023-04-03T16:47:14.347Z,1680540434.347 [Default:CheckIn:E] Running Loop=1
2023-04-03T16:47:14.763Z,1680540434.763 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 79.988053 min 
2023-04-03T16:47:14.763Z,1680540434.763 [Default:CheckIn:E] Stopped
2023-04-03T16:47:14.763Z,1680540434.763 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-03T16:47:14.763Z,1680540434.763 [Default:CheckIn] Stopped
2023-04-03T16:47:14.763Z,1680540434.763 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-03T16:47:14.763Z,1680540434.763 [Default:CheckIn](INFO): Running loop #12
2023-04-03T16:47:14.763Z,1680540434.763 [Default:CheckIn] Running Loop=12
2023-04-03T16:47:14.763Z,1680540434.763 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-03T16:47:14.763Z,1680540434.763 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-03T16:47:16.759Z,1680540436.759 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164716.00,A,3648.17762,N,12147.28143,W,0.933,0.00,030423,,,A*71
2023-04-03T16:47:16.762Z,1680540436.762 [NAL9602](INFO): GPS fix at 20230403T164716: (36.802960, -121.788024)
2023-04-03T16:47:16.773Z,1680540436.773 [Default:CheckIn:Read_GPS] Stopped
2023-04-03T16:47:16.774Z,1680540436.774 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-03T16:47:24.064Z,1680540444.064 [DataOverHttps](INFO): Sending 85 bytes from file Logs/20230403T152239/Courier0034.lzma
2023-04-03T16:47:25.066Z,1680540445.066 [DataOverHttps](INFO): Moved sent file to Logs/20230403T152239/Courier0034.lzma.bak
2023-04-03T16:47:25.066Z,1680540445.066 [DataOverHttps](INFO): SBD MOMSN=18013301
2023-04-03T16:47:40.743Z,1680540460.743 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230403T152239/Courier0037.lzma
2023-04-03T16:47:41.746Z,1680540461.746 [DataOverHttps](INFO): Moved sent file to Logs/20230403T152239/Courier0037.lzma.bak
2023-04-03T16:47:41.746Z,1680540461.746 [DataOverHttps](INFO): SBD MOMSN=18013305
2023-04-03T16:47:49.553Z,1680540469.553 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-03T16:47:59.999Z,1680540479.999 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20230403T152239/Express0035.lzma
2023-04-03T16:48:01.002Z,1680540481.002 [DataOverHttps](INFO): Moved sent file to Logs/20230403T152239/Express0035.lzma.bak
2023-04-03T16:48:01.002Z,1680540481.002 [DataOverHttps](INFO): SBD MOMSN=18013310
2023-04-03T16:48:16.600Z,1680540496.600 [DataOverHttps](INFO): Sending 205 bytes from file Logs/20230403T152239/Express0038.lzma
2023-04-03T16:48:17.602Z,1680540497.602 [DataOverHttps](INFO): Moved sent file to Logs/20230403T152239/Express0038.lzma.bak
2023-04-03T16:48:17.602Z,1680540497.602 [DataOverHttps](INFO): SBD MOMSN=18013313
2023-04-03T16:48:18.660Z,1680540498.660 [Default:CheckIn:Read_Iridium] Stopped
2023-04-03T16:48:18.660Z,1680540498.660 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-03T16:48:18.660Z,1680540498.660 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-03T16:53:19.240Z,1680540799.240 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-03T16:53:19.240Z,1680540799.240 [Default:CheckIn:C.Wait] Stopped
2023-04-03T16:53:19.241Z,1680540799.241 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-03T16:53:19.241Z,1680540799.241 [Default:CheckIn:D] Running Loop=1
2023-04-03T16:53:19.636Z,1680540799.636 [Default:CheckIn:D] Stopped
2023-04-03T16:53:19.636Z,1680540799.636 [Default:CheckIn:E] Running Loop=1
2023-04-03T16:53:20.036Z,1680540800.036 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 86.076213 min 
2023-04-03T16:53:20.036Z,1680540800.036 [Default:CheckIn:E] Stopped
2023-04-03T16:53:20.036Z,1680540800.036 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-03T16:53:20.036Z,1680540800.036 [Default:CheckIn] Stopped
2023-04-03T16:53:20.036Z,1680540800.036 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-03T16:53:20.036Z,1680540800.036 [Default:CheckIn](INFO): Running loop #13
2023-04-03T16:53:20.036Z,1680540800.036 [Default:CheckIn] Running Loop=13
2023-04-03T16:53:20.037Z,1680540800.037 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-03T16:53:20.037Z,1680540800.037 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-03T16:53:22.055Z,1680540802.055 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165321.00,A,3648.16772,N,12147.28368,W,0.467,0.00,030423,,,A*77
2023-04-03T16:53:22.057Z,1680540802.057 [NAL9602](INFO): GPS fix at 20230403T165321: (36.802795, -121.788061)
2023-04-03T16:53:22.069Z,1680540802.069 [Default:CheckIn:Read_GPS] Stopped
2023-04-03T16:53:22.069Z,1680540802.069 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-03T16:53:28.856Z,1680540808.856 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230403T152239/Courier0040.lzma
2023-04-03T16:53:29.858Z,1680540809.858 [DataOverHttps](INFO): Moved sent file to Logs/20230403T152239/Courier0040.lzma.bak
2023-04-03T16:53:29.858Z,1680540809.858 [DataOverHttps](INFO): SBD MOMSN=18013727
2023-04-03T16:53:48.375Z,1680540828.375 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20230403T152239/Express0041.lzma
2023-04-03T16:53:49.378Z,1680540829.378 [DataOverHttps](INFO): Moved sent file to Logs/20230403T152239/Express0041.lzma.bak
2023-04-03T16:53:49.378Z,1680540829.378 [DataOverHttps](INFO): SBD MOMSN=18013734
2023-04-03T16:53:50.437Z,1680540830.437 [Default:CheckIn:Read_Iridium] Stopped
2023-04-03T16:53:50.438Z,1680540830.438 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-03T16:53:50.438Z,1680540830.438 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-03T16:53:52.801Z,1680540832.801 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-04-03T16:53:52.876Z,1680540832.876 [NAL9602](ERROR): received: 
+CSQ:0

OK
2023-04-03T16:58:24.365Z,1680541104.365 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-04-03T16:58:51.039Z,1680541131.039 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-03T16:58:51.039Z,1680541131.039 [Default:CheckIn:C.Wait] Stopped
2023-04-03T16:58:51.039Z,1680541131.039 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-03T16:58:51.039Z,1680541131.039 [Default:CheckIn:D] Running Loop=1
2023-04-03T16:58:51.448Z,1680541131.448 [Default:CheckIn:D] Stopped
2023-04-03T16:58:51.448Z,1680541131.448 [Default:CheckIn:E] Running Loop=1
2023-04-03T16:58:51.861Z,1680541131.861 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 91.606413 min 
2023-04-03T16:58:51.861Z,1680541131.861 [Default:CheckIn:E] Stopped
2023-04-03T16:58:51.861Z,1680541131.861 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-03T16:58:51.861Z,1680541131.861 [Default:CheckIn] Stopped
2023-04-03T16:58:51.861Z,1680541131.861 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-03T16:58:51.861Z,1680541131.861 [Default:CheckIn](INFO): Running loop #14
2023-04-03T16:58:51.861Z,1680541131.861 [Default:CheckIn] Running Loop=14
2023-04-03T16:58:51.861Z,1680541131.861 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-03T16:58:51.861Z,1680541131.861 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-03T16:58:53.863Z,1680541133.863 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165853.00,A,3648.16756,N,12147.28002,W,0.058,0.00,030423,,,A*78
2023-04-03T16:58:53.865Z,1680541133.865 [NAL9602](INFO): GPS fix at 20230403T165853: (36.802793, -121.788000)
2023-04-03T16:58:53.909Z,1680541133.909 [Default:CheckIn:Read_GPS] Stopped
2023-04-03T16:58:53.909Z,1680541133.909 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-03T16:59:01.175Z,1680541141.175 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20230403T152239/Courier0043.lzma
2023-04-03T16:59:02.178Z,1680541142.178 [DataOverHttps](INFO): Moved sent file to Logs/20230403T152239/Courier0043.lzma.bak
2023-04-03T16:59:02.178Z,1680541142.178 [DataOverHttps](INFO): SBD MOMSN=18013789
2023-04-03T16:59:18.012Z,1680541158.012 [DataOverHttps](INFO): Sending 204 bytes from file Logs/20230403T152239/Express0044.lzma
2023-04-03T16:59:19.014Z,1680541159.014 [DataOverHttps](INFO): Moved sent file to Logs/20230403T152239/Express0044.lzma.bak
2023-04-03T16:59:19.014Z,1680541159.014 [DataOverHttps](INFO): SBD MOMSN=18013792
2023-04-03T16:59:20.132Z,1680541160.132 [Default:CheckIn:Read_Iridium] Stopped
2023-04-03T16:59:20.133Z,1680541160.133 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-03T16:59:20.133Z,1680541160.133 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-03T16:59:26.585Z,1680541166.585 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-03T17:04:20.756Z,1680541460.756 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-03T17:04:20.756Z,1680541460.756 [Default:CheckIn:C.Wait] Stopped
2023-04-03T17:04:20.756Z,1680541460.756 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-03T17:04:20.756Z,1680541460.756 [Default:CheckIn:D] Running Loop=1
2023-04-03T17:04:21.156Z,1680541461.156 [Default:CheckIn:D] Stopped
2023-04-03T17:04:21.156Z,1680541461.156 [Default:CheckIn:E] Running Loop=1
2023-04-03T17:04:21.560Z,1680541461.560 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 97.101546 min 
2023-04-03T17:04:21.560Z,1680541461.560 [Default:CheckIn:E] Stopped
2023-04-03T17:04:21.561Z,1680541461.561 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-03T17:04:21.561Z,1680541461.561 [Default:CheckIn] Stopped
2023-04-03T17:04:21.561Z,1680541461.561 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-03T17:04:21.561Z,1680541461.561 [Default:CheckIn](INFO): Running loop #15
2023-04-03T17:04:21.561Z,1680541461.561 [Default:CheckIn] Running Loop=15
2023-04-03T17:04:21.561Z,1680541461.561 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-03T17:04:21.561Z,1680541461.561 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-03T17:04:23.567Z,1680541463.567 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170422.00,A,3648.16695,N,12147.28259,W,0.408,0.00,030423,,,A*75
2023-04-03T17:04:23.569Z,1680541463.569 [NAL9602](INFO): GPS fix at 20230403T170422: (36.802782, -121.788043)
2023-04-03T17:04:23.581Z,1680541463.581 [Default:CheckIn:Read_GPS] Stopped
2023-04-03T17:04:23.581Z,1680541463.581 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-03T17:04:31.183Z,1680541471.183 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230403T152239/Courier0046.lzma
2023-04-03T17:04:32.186Z,1680541472.186 [DataOverHttps](INFO): Moved sent file to Logs/20230403T152239/Courier0046.lzma.bak
2023-04-03T17:04:32.186Z,1680541472.186 [DataOverHttps](INFO): SBD MOMSN=18014155
2023-04-03T17:04:47.811Z,1680541487.811 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20230403T152239/Express0047.lzma
2023-04-03T17:04:48.814Z,1680541488.814 [DataOverHttps](INFO): Moved sent file to Logs/20230403T152239/Express0047.lzma.bak
2023-04-03T17:04:48.814Z,1680541488.814 [DataOverHttps](INFO): SBD MOMSN=18014163
2023-04-03T17:04:49.869Z,1680541489.869 [Default:CheckIn:Read_Iridium] Stopped
2023-04-03T17:04:49.869Z,1680541489.869 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-03T17:04:49.869Z,1680541489.869 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-03T17:04:54.269Z,1680541494.269 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-04-03T17:04:54.344Z,1680541494.344 [NAL9602](ERROR): received: 
+CSQ:0

OK
2023-04-03T17:09:25.357Z,1680541765.357 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-04-03T17:09:50.413Z,1680541790.413 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-03T17:09:50.413Z,1680541790.413 [Default:CheckIn:C.Wait] Stopped
2023-04-03T17:09:50.413Z,1680541790.413 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-03T17:09:50.413Z,1680541790.413 [Default:CheckIn:D] Running Loop=1
2023-04-03T17:09:50.828Z,1680541790.828 [Default:CheckIn:D] Stopped
2023-04-03T17:09:50.828Z,1680541790.828 [Default:CheckIn:E] Running Loop=1
2023-04-03T17:09:51.220Z,1680541791.220 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 102.596069 min 
2023-04-03T17:09:51.220Z,1680541791.220 [Default:CheckIn:E] Stopped
2023-04-03T17:09:51.220Z,1680541791.220 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-03T17:09:51.220Z,1680541791.220 [Default:CheckIn] Stopped
2023-04-03T17:09:51.220Z,1680541791.220 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-03T17:09:51.220Z,1680541791.220 [Default:CheckIn](INFO): Running loop #16
2023-04-03T17:09:51.220Z,1680541791.220 [Default:CheckIn] Running Loop=16
2023-04-03T17:09:51.220Z,1680541791.220 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-03T17:09:51.221Z,1680541791.221 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-03T17:09:53.235Z,1680541793.235 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170952.00,A,3648.16747,N,12147.27911,W,0.408,0.00,030423,,,A*79
2023-04-03T17:09:53.237Z,1680541793.237 [NAL9602](INFO): GPS fix at 20230403T170952: (36.802791, -121.787985)
2023-04-03T17:09:53.249Z,1680541793.249 [Default:CheckIn:Read_GPS] Stopped
2023-04-03T17:09:53.249Z,1680541793.249 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-03T17:10:00.911Z,1680541800.911 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230403T152239/Courier0049.lzma
2023-04-03T17:10:01.914Z,1680541801.914 [DataOverHttps](INFO): Moved sent file to Logs/20230403T152239/Courier0049.lzma.bak
2023-04-03T17:10:01.914Z,1680541801.914 [DataOverHttps](INFO): SBD MOMSN=18014273
2023-04-03T17:10:17.612Z,1680541817.612 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20230403T152239/Express0050.lzma
2023-04-03T17:10:18.614Z,1680541818.614 [DataOverHttps](INFO): Moved sent file to Logs/20230403T152239/Express0050.lzma.bak
2023-04-03T17:10:18.614Z,1680541818.614 [DataOverHttps](INFO): SBD MOMSN=18014277
2023-04-03T17:10:19.912Z,1680541819.912 [Default:CheckIn:Read_Iridium] Stopped
2023-04-03T17:10:19.912Z,1680541819.912 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-03T17:10:19.912Z,1680541819.912 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-03T17:10:25.547Z,1680541825.547 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-03T17:15:20.484Z,1680542120.484 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-03T17:15:20.484Z,1680542120.484 [Default:CheckIn:C.Wait] Stopped
2023-04-03T17:15:20.484Z,1680542120.484 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-03T17:15:20.484Z,1680542120.484 [Default:CheckIn:D] Running Loop=1
2023-04-03T17:15:20.898Z,1680542120.898 [Default:CheckIn:D] Stopped
2023-04-03T17:15:20.898Z,1680542120.898 [Default:CheckIn:E] Running Loop=1
2023-04-03T17:15:21.287Z,1680542121.287 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 108.097249 min 
2023-04-03T17:15:21.287Z,1680542121.287 [Default:CheckIn:E] Stopped
2023-04-03T17:15:21.287Z,1680542121.287 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-03T17:15:21.288Z,1680542121.288 [Default:CheckIn] Stopped
2023-04-03T17:15:21.288Z,1680542121.288 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-03T17:15:21.288Z,1680542121.288 [Default:CheckIn](INFO): Running loop #17
2023-04-03T17:15:21.288Z,1680542121.288 [Default:CheckIn] Running Loop=17
2023-04-03T17:15:21.288Z,1680542121.288 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-03T17:15:21.288Z,1680542121.288 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-03T17:15:23.303Z,1680542123.303 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171522.00,A,3648.16489,N,12147.28586,W,0.136,0.00,030423,,,A*77
2023-04-03T17:15:23.306Z,1680542123.306 [NAL9602](INFO): GPS fix at 20230403T171522: (36.802748, -121.788098)
2023-04-03T17:15:23.317Z,1680542123.317 [Default:CheckIn:Read_GPS] Stopped
2023-04-03T17:15:23.318Z,1680542123.318 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-03T17:15:30.319Z,1680542130.319 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230403T152239/Courier0052.lzma
2023-04-03T17:15:31.322Z,1680542131.322 [DataOverHttps](INFO): Moved sent file to Logs/20230403T152239/Courier0052.lzma.bak
2023-04-03T17:15:31.322Z,1680542131.322 [DataOverHttps](INFO): SBD MOMSN=18014618
2023-04-03T17:15:49.788Z,1680542149.788 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20230403T152239/Express0053.lzma
2023-04-03T17:15:50.790Z,1680542150.790 [DataOverHttps](INFO): Moved sent file to Logs/20230403T152239/Express0053.lzma.bak
2023-04-03T17:15:50.790Z,1680542150.790 [DataOverHttps](INFO): SBD MOMSN=18014624
2023-04-03T17:15:52.058Z,1680542152.058 [Default:CheckIn:Read_Iridium] Stopped
2023-04-03T17:15:52.058Z,1680542152.058 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-03T17:15:52.058Z,1680542152.058 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-03T17:15:54.065Z,1680542154.065 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-04-03T17:15:54.140Z,1680542154.140 [NAL9602](ERROR): received: 
+CSQ:0

OK
2023-04-03T17:20:25.158Z,1680542425.158 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-04-03T17:20:52.652Z,1680542452.652 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-03T17:20:52.652Z,1680542452.652 [Default:CheckIn:C.Wait] Stopped
2023-04-03T17:20:52.652Z,1680542452.652 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-03T17:20:52.652Z,1680542452.652 [Default:CheckIn:D] Running Loop=1
2023-04-03T17:20:53.048Z,1680542453.048 [Default:CheckIn:D] Stopped
2023-04-03T17:20:53.048Z,1680542453.048 [Default:CheckIn:E] Running Loop=1
2023-04-03T17:20:53.448Z,1680542453.448 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 113.633081 min 
2023-04-03T17:20:53.448Z,1680542453.448 [Default:CheckIn:E] Stopped
2023-04-03T17:20:53.448Z,1680542453.448 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-03T17:20:53.448Z,1680542453.448 [Default:CheckIn] Stopped
2023-04-03T17:20:53.448Z,1680542453.448 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-03T17:20:53.449Z,1680542453.449 [Default:CheckIn](INFO): Running loop #18
2023-04-03T17:20:53.449Z,1680542453.449 [Default:CheckIn] Running Loop=18
2023-04-03T17:20:53.449Z,1680542453.449 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-03T17:20:53.449Z,1680542453.449 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-03T17:20:55.467Z,1680542455.467 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172054.00,A,3648.16863,N,12147.28152,W,0.369,0.00,030423,,,A*7D
2023-04-03T17:20:55.469Z,1680542455.469 [NAL9602](INFO): GPS fix at 20230403T172054: (36.802810, -121.788025)
2023-04-03T17:20:55.481Z,1680542455.481 [Default:CheckIn:Read_GPS] Stopped
2023-04-03T17:20:55.481Z,1680542455.481 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-03T17:21:02.603Z,1680542462.603 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230403T152239/Courier0055.lzma
2023-04-03T17:21:03.606Z,1680542463.606 [DataOverHttps](INFO): Moved sent file to Logs/20230403T152239/Courier0055.lzma.bak
2023-04-03T17:21:03.606Z,1680542463.606 [DataOverHttps](INFO): SBD MOMSN=18014661
2023-04-03T17:21:19.224Z,1680542479.224 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20230403T152239/Express0056.lzma
2023-04-03T17:21:20.230Z,1680542480.230 [DataOverHttps](INFO): Moved sent file to Logs/20230403T152239/Express0056.lzma.bak
2023-04-03T17:21:20.230Z,1680542480.230 [DataOverHttps](INFO): SBD MOMSN=18014685
2023-04-03T17:21:21.335Z,1680542481.335 [Default:CheckIn:Read_Iridium] Stopped
2023-04-03T17:21:21.335Z,1680542481.335 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-03T17:21:21.335Z,1680542481.335 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-03T17:21:27.371Z,1680542487.371 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-03T17:26:21.971Z,1680542781.971 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-03T17:26:21.972Z,1680542781.972 [Default:CheckIn:C.Wait] Stopped
2023-04-03T17:26:21.972Z,1680542781.972 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-03T17:26:21.972Z,1680542781.972 [Default:CheckIn:D] Running Loop=1
2023-04-03T17:26:22.382Z,1680542782.382 [Default:CheckIn:D] Stopped
2023-04-03T17:26:22.382Z,1680542782.382 [Default:CheckIn:E] Running Loop=1
2023-04-03T17:26:22.783Z,1680542782.783 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 119.121981 min 
2023-04-03T17:26:22.783Z,1680542782.783 [Default:CheckIn:E] Stopped
2023-04-03T17:26:22.783Z,1680542782.783 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-03T17:26:22.783Z,1680542782.783 [Default:CheckIn] Stopped
2023-04-03T17:26:22.784Z,1680542782.784 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-03T17:26:22.784Z,1680542782.784 [Default:CheckIn](INFO): Running loop #19
2023-04-03T17:26:22.785Z,1680542782.785 [Default:CheckIn] Running Loop=19
2023-04-03T17:26:22.785Z,1680542782.785 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-03T17:26:22.785Z,1680542782.785 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-03T17:26:24.799Z,1680542784.799 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172624.00,A,3648.16210,N,12147.28965,W,0.214,0.00,030423,,,A*75
2023-04-03T17:26:24.801Z,1680542784.801 [NAL9602](INFO): GPS fix at 20230403T172624: (36.802702, -121.788161)
2023-04-03T17:26:24.813Z,1680542784.813 [Default:CheckIn:Read_GPS] Stopped
2023-04-03T17:26:24.813Z,1680542784.813 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-03T17:26:32.403Z,1680542792.403 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230403T152239/Courier0058.lzma
2023-04-03T17:26:33.406Z,1680542793.406 [DataOverHttps](INFO): Moved sent file to Logs/20230403T152239/Courier0058.lzma.bak
2023-04-03T17:26:33.406Z,1680542793.406 [DataOverHttps](INFO): SBD MOMSN=18015036
2023-04-03T17:26:49.028Z,1680542809.028 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20230403T152239/Express0059.lzma
2023-04-03T17:26:50.030Z,1680542810.030 [DataOverHttps](INFO): Moved sent file to Logs/20230403T152239/Express0059.lzma.bak
2023-04-03T17:26:50.030Z,1680542810.030 [DataOverHttps](INFO): SBD MOMSN=18015039
2023-04-03T17:26:51.105Z,1680542811.105 [Default:CheckIn:Read_Iridium] Stopped
2023-04-03T17:26:51.105Z,1680542811.105 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-03T17:26:51.105Z,1680542811.105 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-03T17:26:55.517Z,1680542815.517 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-04-03T17:26:55.596Z,1680542815.596 [NAL9602](ERROR): received: 
+CSQ:0

OK
2023-04-03T17:31:21.787Z,1680543081.787 [NAL9602](INFO): SBD MO Status=2, MOMSN=11270, MT Status=2, MTMSN=0
2023-04-03T17:31:21.787Z,1680543081.787 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-04-03T17:31:27.432Z,1680543087.432 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-04-03T17:31:51.691Z,1680543111.691 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-03T17:31:51.691Z,1680543111.691 [Default:CheckIn:C.Wait] Stopped
2023-04-03T17:31:51.691Z,1680543111.691 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-03T17:31:51.691Z,1680543111.691 [Default:CheckIn:D] Running Loop=1
2023-04-03T17:31:52.092Z,1680543112.092 [Default:CheckIn:D] Stopped
2023-04-03T17:31:52.092Z,1680543112.092 [Default:CheckIn:E] Running Loop=1
2023-04-03T17:31:52.500Z,1680543112.500 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 124.617147 min 
2023-04-03T17:31:52.500Z,1680543112.500 [Default:CheckIn:E] Stopped
2023-04-03T17:31:52.501Z,1680543112.501 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-03T17:31:52.501Z,1680543112.501 [Default:CheckIn] Stopped
2023-04-03T17:31:52.501Z,1680543112.501 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-03T17:31:52.501Z,1680543112.501 [Default:CheckIn](INFO): Running loop #20
2023-04-03T17:31:52.501Z,1680543112.501 [Default:CheckIn] Running Loop=20
2023-04-03T17:31:52.501Z,1680543112.501 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-03T17:31:52.501Z,1680543112.501 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-03T17:31:54.503Z,1680543114.503 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173153.00,A,3648.15592,N,12147.28839,W,0.292,0.00,030423,,,A*7B
2023-04-03T17:31:54.514Z,1680543114.514 [NAL9602](INFO): GPS fix at 20230403T173153: (36.802599, -121.788140)
2023-04-03T17:31:54.530Z,1680543114.530 [Default:CheckIn:Read_GPS] Stopped
2023-04-03T17:31:54.530Z,1680543114.530 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-03T17:32:01.695Z,1680543121.695 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230403T152239/Courier0061.lzma
2023-04-03T17:32:02.698Z,1680543122.698 [DataOverHttps](INFO): Moved sent file to Logs/20230403T152239/Courier0061.lzma.bak
2023-04-03T17:32:02.698Z,1680543122.698 [DataOverHttps](INFO): SBD MOMSN=18015045
2023-04-03T17:32:18.348Z,1680543138.348 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20230403T152239/Express0062.lzma
2023-04-03T17:32:19.350Z,1680543139.350 [DataOverHttps](INFO): Moved sent file to Logs/20230403T152239/Express0062.lzma.bak
2023-04-03T17:32:19.350Z,1680543139.350 [DataOverHttps](INFO): SBD MOMSN=18015048
2023-04-03T17:32:20.404Z,1680543140.404 [Default:CheckIn:Read_Iridium] Stopped
2023-04-03T17:32:20.404Z,1680543140.404 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-03T17:32:20.404Z,1680543140.404 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-03T17:32:26.445Z,1680543146.445 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-03T17:37:20.000Z,1680543441.000 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-03T17:37:21.000Z,1680543441.000 [Default:CheckIn:C.Wait] Stopped
2023-04-03T17:37:21.000Z,1680543441.000 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-03T17:37:21.000Z,1680543441.000 [Default:CheckIn:D] Running Loop=1
2023-04-03T17:37:21.401Z,1680543441.401 [Default:CheckIn:D] Stopped
2023-04-03T17:37:21.401Z,1680543441.401 [Default:CheckIn:E] Running Loop=1
2023-04-03T17:37:21.818Z,1680543441.818 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 130.105623 min 
2023-04-03T17:37:21.818Z,1680543441.818 [Default:CheckIn:E] Stopped
2023-04-03T17:37:21.818Z,1680543441.818 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-03T17:37:21.818Z,1680543441.818 [Default:CheckIn] Stopped
2023-04-03T17:37:21.819Z,1680543441.819 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-03T17:37:21.819Z,1680543441.819 [Default:CheckIn](INFO): Running loop #21
2023-04-03T17:37:21.819Z,1680543441.819 [Default:CheckIn] Running Loop=21
2023-04-03T17:37:21.819Z,1680543441.819 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-03T17:37:21.819Z,1680543441.819 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-03T17:37:23.819Z,1680543443.819 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173723.00,A,3648.16050,N,12147.28901,W,1.380,0.00,030423,,,A*7B
2023-04-03T17:37:23.821Z,1680543443.821 [NAL9602](INFO): GPS fix at 20230403T173723: (36.802675, -121.788150)
2023-04-03T17:37:23.833Z,1680543443.833 [Default:CheckIn:Read_GPS] Stopped
2023-04-03T17:37:23.834Z,1680543443.834 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-03T17:37:30.903Z,1680543450.903 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230403T152239/Courier0064.lzma
2023-04-03T17:37:31.906Z,1680543451.906 [DataOverHttps](INFO): Moved sent file to Logs/20230403T152239/Courier0064.lzma.bak
2023-04-03T17:37:31.906Z,1680543451.906 [DataOverHttps](INFO): SBD MOMSN=18015426
2023-04-03T17:37:50.496Z,1680543470.496 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20230403T152239/Express0065.lzma
2023-04-03T17:37:51.498Z,1680543471.498 [DataOverHttps](INFO): Moved sent file to Logs/20230403T152239/Express0065.lzma.bak
2023-04-03T17:37:51.498Z,1680543471.498 [DataOverHttps](INFO): SBD MOMSN=18015429
2023-04-03T17:37:52.577Z,1680543472.577 [Default:CheckIn:Read_Iridium] Stopped
2023-04-03T17:37:52.577Z,1680543472.577 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-03T17:37:52.577Z,1680543472.577 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-03T17:37:54.577Z,1680543474.577 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-04-03T17:37:54.660Z,1680543474.660 [NAL9602](ERROR): received: 
+CSQ:0

OK270, 2, 0, 0, 0

OK
2023-04-03T17:40:44.355Z,1680543644.355 [NAL9602](INFO): SBD MO Status=2, MOMSN=11270, MT Status=2, MTMSN=0
2023-04-03T17:40:44.355Z,1680543644.355 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-04-03T17:41:39.295Z,1680543699.295 [NAL9602](INFO): SBD MO Status=2, MOMSN=11270, MT Status=2, MTMSN=0
2023-04-03T17:41:39.295Z,1680543699.295 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-04-03T17:42:26.581Z,1680543746.581 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-04-03T17:42:53.256Z,1680543773.256 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-03T17:42:53.256Z,1680543773.256 [Default:CheckIn:C.Wait] Stopped
2023-04-03T17:42:53.256Z,1680543773.256 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-03T17:42:53.256Z,1680543773.256 [Default:CheckIn:D] Running Loop=1
2023-04-03T17:42:53.704Z,1680543773.704 [Default:CheckIn:D] Stopped
2023-04-03T17:42:53.704Z,1680543773.704 [Default:CheckIn:E] Running Loop=1
2023-04-03T17:42:54.052Z,1680543774.052 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 135.644010 min 
2023-04-03T17:42:54.052Z,1680543774.052 [Default:CheckIn:E] Stopped
2023-04-03T17:42:54.052Z,1680543774.052 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-03T17:42:54.052Z,1680543774.052 [Default:CheckIn] Stopped
2023-04-03T17:42:54.053Z,1680543774.053 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-03T17:42:54.053Z,1680543774.053 [Default:CheckIn](INFO): Running loop #22
2023-04-03T17:42:54.053Z,1680543774.053 [Default:CheckIn] Running Loop=22
2023-04-03T17:42:54.053Z,1680543774.053 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-03T17:42:54.053Z,1680543774.053 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-03T17:42:56.054Z,1680543776.054 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174255.00,A,3648.16769,N,12147.28284,W,0.330,0.00,030423,,,A*79
2023-04-03T17:42:56.056Z,1680543776.056 [NAL9602](INFO): GPS fix at 20230403T174255: (36.802795, -121.788047)
2023-04-03T17:42:56.093Z,1680543776.093 [Default:CheckIn:Read_GPS] Stopped
2023-04-03T17:42:56.093Z,1680543776.093 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-03T17:43:03.659Z,1680543783.659 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230403T152239/Courier0067.lzma
2023-04-03T17:43:04.663Z,1680543784.663 [DataOverHttps](INFO): Moved sent file to Logs/20230403T152239/Courier0067.lzma.bak
2023-04-03T17:43:04.664Z,1680543784.664 [DataOverHttps](INFO): SBD MOMSN=18015432
2023-04-03T17:43:20.572Z,1680543800.572 [DataOverHttps](INFO): Sending 208 bytes from file Logs/20230403T152239/Express0068.lzma
2023-04-03T17:43:22.578Z,1680543802.578 [DataOverHttps](INFO): Moved sent file to Logs/20230403T152239/Express0068.lzma.bak
2023-04-03T17:43:22.578Z,1680543802.578 [DataOverHttps](INFO): SBD MOMSN=18015436
2023-04-03T17:43:23.945Z,1680543803.945 [Default:CheckIn:Read_Iridium] Stopped
2023-04-03T17:43:23.945Z,1680543803.945 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-03T17:43:23.945Z,1680543803.945 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-03T17:43:28.373Z,1680543808.373 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-03T17:45:48.583Z,1680543948.583 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2023-04-03T17:45:48.585Z,1680543948.585 [BPC1](INFO): Received data from all battery sticks.
2023-04-03T17:48:24.564Z,1680544104.564 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-03T17:48:24.564Z,1680544104.564 [Default:CheckIn:C.Wait] Stopped
2023-04-03T17:48:24.564Z,1680544104.564 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-03T17:48:24.564Z,1680544104.564 [Default:CheckIn:D] Running Loop=1
2023-04-03T17:48:24.978Z,1680544104.978 [Default:CheckIn:D] Stopped
2023-04-03T17:48:24.978Z,1680544104.978 [Default:CheckIn:E] Running Loop=1
2023-04-03T17:48:25.391Z,1680544105.391 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 141.165251 min 
2023-04-03T17:48:25.391Z,1680544105.391 [Default:CheckIn:E] Stopped
2023-04-03T17:48:25.391Z,1680544105.391 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-03T17:48:25.391Z,1680544105.391 [Default:CheckIn] Stopped
2023-04-03T17:48:25.391Z,1680544105.391 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-03T17:48:25.391Z,1680544105.391 [Default:CheckIn](INFO): Running loop #23
2023-04-03T17:48:25.391Z,1680544105.391 [Default:CheckIn] Running Loop=23
2023-04-03T17:48:25.392Z,1680544105.392 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-03T17:48:25.392Z,1680544105.392 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-03T17:48:27.383Z,1680544107.383 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174826.00,A,3648.16693,N,12147.28266,W,0.467,27.70,030423,,,A*48
2023-04-03T17:48:27.386Z,1680544107.386 [NAL9602](INFO): GPS fix at 20230403T174826: (36.802782, -121.788044)
2023-04-03T17:48:27.442Z,1680544107.442 [Default:CheckIn:Read_GPS] Stopped
2023-04-03T17:48:27.442Z,1680544107.442 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-03T17:48:34.803Z,1680544114.803 [DataOverHttps](INFO): Sending 85 bytes from file Logs/20230403T152239/Courier0070.lzma
2023-04-03T17:48:35.807Z,1680544115.807 [DataOverHttps](INFO): Moved sent file to Logs/20230403T152239/Courier0070.lzma.bak
2023-04-03T17:48:35.807Z,1680544115.807 [DataOverHttps](INFO): SBD MOMSN=18015852
2023-04-03T17:48:51.520Z,1680544131.520 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20230403T152239/Express0071.lzma
2023-04-03T17:48:52.522Z,1680544132.522 [DataOverHttps](INFO): Moved sent file to Logs/20230403T152239/Express0071.lzma.bak
2023-04-03T17:48:52.522Z,1680544132.522 [DataOverHttps](INFO): SBD MOMSN=18015855
2023-04-03T17:48:53.651Z,1680544133.651 [Default:CheckIn:Read_Iridium] Stopped
2023-04-03T17:48:53.651Z,1680544133.651 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-03T17:48:53.652Z,1680544133.652 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-03T17:48:58.086Z,1680544138.086 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-04-03T17:48:58.168Z,1680544138.168 [NAL9602](ERROR): received: 
+CSQ:1

OK270, 2, 0, 0, 0

OK
2023-04-03T17:49:31.223Z,1680544171.223 [NAL9602](INFO): SBD MO Status=0, MOMSN=11270, MT Status=0, MTMSN=0
2023-04-03T17:49:31.223Z,1680544171.223 [NAL9602](INFO): No messages in MT queue
2023-04-03T17:50:01.925Z,1680544201.925 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-03T17:53:54.258Z,1680544434.258 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-03T17:53:54.258Z,1680544434.258 [Default:CheckIn:C.Wait] Stopped
2023-04-03T17:53:54.258Z,1680544434.258 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-03T17:53:54.258Z,1680544434.258 [Default:CheckIn:D] Running Loop=1
2023-04-03T17:53:54.673Z,1680544434.673 [Default:CheckIn:D] Stopped
2023-04-03T17:53:54.673Z,1680544434.673 [Default:CheckIn:E] Running Loop=1
2023-04-03T17:53:55.093Z,1680544435.093 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 146.660156 min 
2023-04-03T17:53:55.093Z,1680544435.093 [Default:CheckIn:E] Stopped
2023-04-03T17:53:55.093Z,1680544435.093 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-03T17:53:55.093Z,1680544435.093 [Default:CheckIn] Stopped
2023-04-03T17:53:55.093Z,1680544435.093 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-03T17:53:55.093Z,1680544435.093 [Default:CheckIn](INFO): Running loop #24
2023-04-03T17:53:55.093Z,1680544435.093 [Default:CheckIn] Running Loop=24
2023-04-03T17:53:55.093Z,1680544435.093 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-03T17:53:55.094Z,1680544435.094 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-03T17:53:57.079Z,1680544437.079 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175356.00,A,3648.16444,N,12147.28499,W,0.058,170.06,030423,,,A*71
2023-04-03T17:53:57.081Z,1680544437.081 [NAL9602](INFO): GPS fix at 20230403T175356: (36.802741, -121.788083)
2023-04-03T17:53:57.093Z,1680544437.093 [Default:CheckIn:Read_GPS] Stopped
2023-04-03T17:53:57.093Z,1680544437.093 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-03T17:54:04.119Z,1680544444.119 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230403T152239/Courier0073.lzma
2023-04-03T17:54:05.122Z,1680544445.122 [DataOverHttps](INFO): Moved sent file to Logs/20230403T152239/Courier0073.lzma.bak
2023-04-03T17:54:05.122Z,1680544445.122 [DataOverHttps](INFO): SBD MOMSN=18015861
2023-04-03T17:54:20.868Z,1680544460.868 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20230403T152239/Express0074.lzma
2023-04-03T17:54:21.870Z,1680544461.870 [DataOverHttps](INFO): Moved sent file to Logs/20230403T152239/Express0074.lzma.bak
2023-04-03T17:54:21.870Z,1680544461.870 [DataOverHttps](INFO): SBD MOMSN=18015864
2023-04-03T17:54:22.938Z,1680544462.938 [Default:CheckIn:Read_Iridium] Stopped
2023-04-03T17:54:22.938Z,1680544462.938 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-03T17:54:22.938Z,1680544462.938 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-03T17:58:31.407Z,1680544711.407 [NAL9602](INFO): SBD MO Status=2, MOMSN=11271, MT Status=2, MTMSN=0
2023-04-03T17:58:31.407Z,1680544711.407 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-04-03T17:58:59.281Z,1680544739.281 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-04-03T17:59:23.540Z,1680544763.540 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-03T17:59:23.540Z,1680544763.540 [Default:CheckIn:C.Wait] Stopped
2023-04-03T17:59:23.540Z,1680544763.540 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-03T17:59:23.540Z,1680544763.540 [Default:CheckIn:D] Running Loop=1
2023-04-03T17:59:23.931Z,1680544763.931 [Default:CheckIn:D] Stopped
2023-04-03T17:59:23.931Z,1680544763.931 [Default:CheckIn:E] Running Loop=1
2023-04-03T17:59:24.337Z,1680544764.337 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 152.147786 min 
2023-04-03T17:59:24.337Z,1680544764.337 [Default:CheckIn:E] Stopped
2023-04-03T17:59:24.337Z,1680544764.337 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-03T17:59:24.337Z,1680544764.337 [Default:CheckIn] Stopped
2023-04-03T17:59:24.337Z,1680544764.337 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-03T17:59:24.337Z,1680544764.337 [Default:CheckIn](INFO): Running loop #25
2023-04-03T17:59:24.337Z,1680544764.337 [Default:CheckIn] Running Loop=25
2023-04-03T17:59:24.337Z,1680544764.337 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-03T17:59:24.337Z,1680544764.337 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-03T17:59:26.347Z,1680544766.347 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175925.00,A,3648.16654,N,12147.28652,W,0.408,170.06,030423,,,A*78
2023-04-03T17:59:26.350Z,1680544766.350 [NAL9602](INFO): GPS fix at 20230403T175925: (36.802776, -121.788109)
2023-04-03T17:59:26.362Z,1680544766.362 [Default:CheckIn:Read_GPS] Stopped
2023-04-03T17:59:26.362Z,1680544766.362 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-03T17:59:33.539Z,1680544773.539 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230403T152239/Courier0076.lzma
2023-04-03T17:59:34.542Z,1680544774.542 [DataOverHttps](INFO): Moved sent file to Logs/20230403T152239/Courier0076.lzma.bak
2023-04-03T17:59:34.542Z,1680544774.542 [DataOverHttps](INFO): SBD MOMSN=18016237
2023-04-03T17:59:52.696Z,1680544792.696 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20230403T152239/Express0077.lzma
2023-04-03T17:59:53.698Z,1680544793.698 [DataOverHttps](INFO): Moved sent file to Logs/20230403T152239/Express0077.lzma.bak
2023-04-03T17:59:53.698Z,1680544793.698 [DataOverHttps](INFO): SBD MOMSN=18016240
2023-04-03T17:59:54.745Z,1680544794.745 [Default:CheckIn:Read_Iridium] Stopped
2023-04-03T17:59:54.745Z,1680544794.745 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-03T17:59:54.745Z,1680544794.745 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-03T17:59:58.321Z,1680544798.321 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-03T18:01:50.905Z,1680544910.905 [DataOverHttps](IMPORTANT): SBD MTMSN=20230403T180149
2023-04-03T18:02:01.099Z,1680544921.099 [DataOverHttps](INFO): Received command: ibit
2023-04-03T18:02:01.169Z,1680544921.169 [CommandExec](IMPORTANT): got command ibit
2023-04-03T18:02:01.379Z,1680544921.379 [IBIT](IMPORTANT): Beginning Initiated BIT
2023-04-03T18:02:01.379Z,1680544921.379 [IBIT](IMPORTANT): Beginning control surface checks.
2023-04-03T18:02:01.382Z,1680544921.382 [CBIT](IMPORTANT): Beginning ground fault scan
2023-04-03T18:02:02.927Z,1680544922.927 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180202.00,A,3648.17988,N,12147.28083,W,0.117,51.17,030423,,,A*40
2023-04-03T18:02:02.929Z,1680544922.929 [NAL9602](INFO): GPS fix at 20230403T180202: (36.802998, -121.788014)
2023-04-03T18:02:04.227Z,1680544924.227 [CBIT](ERROR): Error reading 24V bus power status. Assuming off for scan purposes.
2023-04-03T18:02:12.265Z,1680544932.265 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): 0.023620
CHAN A1 (24V) N/A reporting off
CHAN A2 (12V): 0.014961
CHAN A3 (5V): 0.003190
CHAN B0 (3.3V): 0.001979
CHAN B1 (3.15aV): 0.002388
CHAN B2 (3.15bV): 0.001690
CHAN B3 (GND): -0.001106
OPEN: 0.004800
Full Scale: +/- 1 mA
2023-04-03T18:02:33.630Z,1680544953.630 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-04-03T18:02:33.712Z,1680544953.712 [NAL9602](ERROR): received: 
+CSQ:0

OK271, 2, 0, 0, 0

OK
2023-04-03T18:03:11.229Z,1680544991.229 [CommandExec](IMPORTANT): got command show variable water
2023-04-03T18:03:11.235Z,1680544991.235 [CommandExec](IMPORTANT): concentration_of_colored_dissolved_organic_matter_in_sea_water (unknown)
2023-04-03T18:03:11.235Z,1680544991.235 [CommandExec](IMPORTANT): direction_of_sea_water_velocity (unknown)
2023-04-03T18:03:11.236Z,1680544991.236 [CommandExec](IMPORTANT): downwelling_photosynthetic_photon_flux_in_sea_water (unknown)
2023-04-03T18:03:11.236Z,1680544991.236 [CommandExec](IMPORTANT): downward_sea_water_velocity (unknown)
2023-04-03T18:03:11.237Z,1680544991.237 [CommandExec](IMPORTANT): eastward_sea_water_velocity (unknown)
2023-04-03T18:03:11.237Z,1680544991.237 [CommandExec](IMPORTANT): northward_sea_water_velocity (unknown)
2023-04-03T18:03:11.238Z,1680544991.238 [CommandExec](IMPORTANT): mass_concentration_of_chlorophyll_in_sea_water (unknown)
2023-04-03T18:03:11.238Z,1680544991.238 [CommandExec](IMPORTANT): mass_concentration_of_oxygen_in_sea_water (unknown)
2023-04-03T18:03:11.238Z,1680544991.238 [CommandExec](IMPORTANT): mass_concentration_of_petroleum_hydrocarbons_in_sea_water (unknown)
2023-04-03T18:03:11.239Z,1680544991.239 [CommandExec](IMPORTANT): mole_concentration_of_nitrate_in_sea_water (unknown)
2023-04-03T18:03:11.239Z,1680544991.239 [CommandExec](IMPORTANT): platform_distance_wrt_sea_water (meter)
2023-04-03T18:03:11.241Z,1680544991.241 [CommandExec](IMPORTANT): platform_speed_wrt_sea_water (meter_per_second)
2023-04-03T18:03:11.241Z,1680544991.241 [CommandExec](IMPORTANT): platform_x_sea_water_velocity (unknown)
2023-04-03T18:03:11.242Z,1680544991.242 [CommandExec](IMPORTANT): platform_x_velocity_wrt_sea_water (meter_per_second)
2023-04-03T18:03:11.242Z,1680544991.242 [CommandExec](IMPORTANT): platform_y_sea_water_velocity (unknown)
2023-04-03T18:03:11.243Z,1680544991.243 [CommandExec](IMPORTANT): platform_y_velocity_wrt_sea_water (unknown)
2023-04-03T18:03:11.243Z,1680544991.243 [CommandExec](IMPORTANT): platform_z_sea_water_velocity (unknown)
2023-04-03T18:03:11.248Z,1680544991.248 [CommandExec](IMPORTANT): platform_z_velocity_wrt_sea_water (unknown)
2023-04-03T18:03:11.249Z,1680544991.249 [CommandExec](IMPORTANT): sea_water_density (unknown)
2023-04-03T18:03:11.250Z,1680544991.250 [CommandExec](IMPORTANT): sea_water_electrical_conductivity (unknown)
2023-04-03T18:03:11.250Z,1680544991.250 [CommandExec](IMPORTANT): sea_water_potential_density (unknown)
2023-04-03T18:03:11.250Z,1680544991.250 [CommandExec](IMPORTANT): sea_water_potential_temperature (unknown)
2023-04-03T18:03:11.251Z,1680544991.251 [CommandExec](IMPORTANT): sea_water_pressure (decibar)
2023-04-03T18:03:11.251Z,1680544991.251 [CommandExec](IMPORTANT): sea_water_rhodamine (unknown)
2023-04-03T18:03:11.251Z,1680544991.251 [CommandExec](IMPORTANT): sea_water_salinity (unknown)
2023-04-03T18:03:11.252Z,1680544991.252 [CommandExec](IMPORTANT): sea_water_sigma_t (unknown)
2023-04-03T18:03:11.252Z,1680544991.252 [CommandExec](IMPORTANT): sea_water_sigma_theta (unknown)
2023-04-03T18:03:11.252Z,1680544991.252 [CommandExec](IMPORTANT): sea_water_speed (unknown)
2023-04-03T18:03:11.253Z,1680544991.253 [CommandExec](IMPORTANT): sea_water_temperature (unknown)
2023-04-03T18:03:11.253Z,1680544991.253 [CommandExec](IMPORTANT): speed_of_sound_in_sea_water (unknown)
2023-04-03T18:03:11.254Z,1680544991.254 [CommandExec](IMPORTANT): surface_eastward_sea_water_velocity (unknown)
2023-04-03T18:03:11.254Z,1680544991.254 [CommandExec](IMPORTANT): surface_northward_sea_water_velocity (unknown)
2023-04-03T18:03:11.254Z,1680544991.254 [CommandExec](IMPORTANT): upward_derivative_of_sea_water_temperature (unknown)
2023-04-03T18:03:11.255Z,1680544991.255 [CommandExec](IMPORTANT): volume_backwards_scattering_coefficient_of_radiative_flux_in_sea_water (unknown)
2023-04-03T18:03:11.295Z,1680544991.295 [CommandExec](IMPORTANT): StratificationFrontDetector.highWaterMark (count)
2023-04-03T18:03:11.297Z,1680544991.297 [CommandExec](IMPORTANT): CBITWaterAlarmBow.ad (none)
2023-04-03T18:03:11.297Z,1680544991.297 [CommandExec](IMPORTANT): CBITWaterAlarmBow.adRes (bit)
2023-04-03T18:03:11.298Z,1680544991.298 [CommandExec](IMPORTANT): CBITWaterAlarmBow.adVref (volt)
2023-04-03T18:03:11.298Z,1680544991.298 [CommandExec](IMPORTANT): CBITWaterAlarmStern.ad (none)
2023-04-03T18:03:11.298Z,1680544991.298 [CommandExec](IMPORTANT): CBITWaterAlarmStern.adRes (bit)
2023-04-03T18:03:11.299Z,1680544991.299 [CommandExec](IMPORTANT): CBITWaterAlarmStern.adVref (volt)
2023-04-03T18:03:11.299Z,1680544991.299 [CommandExec](IMPORTANT): CBITWaterAlarmAux.ad (none)
2023-04-03T18:03:11.299Z,1680544991.299 [CommandExec](IMPORTANT): CBITWaterAlarmAux.adRes (bit)
2023-04-03T18:03:11.336Z,1680544991.336 [CommandExec](IMPORTANT): CBITWaterAlarmAux.adVref (volt)
2023-04-03T18:03:11.339Z,1680544991.339 [CommandExec](IMPORTANT): Waterlinked.loadControl (none)
2023-04-03T18:03:11.339Z,1680544991.339 [CommandExec](IMPORTANT): Waterlinked.uart (none)
2023-04-03T18:03:11.348Z,1680544991.348 [CommandExec](IMPORTANT): Waterlinked.baud (bit_per_second)
2023-04-03T18:03:11.388Z,1680544991.388 [CommandExec](IMPORTANT): DeadReckonWithRespectToWater.loadAtStartup (bool)
2023-04-03T18:03:11.389Z,1680544991.389 [CommandExec](IMPORTANT): DeadReckonWithRespectToWater.accuracyPremultiplier (none)
2023-04-03T18:03:11.389Z,1680544991.389 [CommandExec](IMPORTANT): DeadReckonWithRespectToWater.allowableFailures (count)
2023-04-03T18:03:11.389Z,1680544991.389 [CommandExec](IMPORTANT): DeadReckonWithRespectToWater.orientationStaleAfter (minute)
2023-04-03T18:03:11.390Z,1680544991.390 [CommandExec](IMPORTANT): DeadReckonWithRespectToWater.velocityStaleAfter (second)
2023-04-03T18:03:11.390Z,1680544991.390 [CommandExec](IMPORTANT): DeadReckonWithRespectToWater.verbosity (count)
2023-04-03T18:03:11.391Z,1680544991.391 [CommandExec](IMPORTANT): DeadReckonUsingDVLWaterTrack.loadAtStartup (bool)
2023-04-03T18:03:11.391Z,1680544991.391 [CommandExec](IMPORTANT): DeadReckonUsingDVLWaterTrack.accuracyPremultiplier (none)
2023-04-03T18:03:11.392Z,1680544991.392 [CommandExec](IMPORTANT): DeadReckonUsingDVLWaterTrack.allowableFailures (count)
2023-04-03T18:03:11.393Z,1680544991.393 [CommandExec](IMPORTANT): DeadReckonUsingDVLWaterTrack.orientationStaleAfter (minute)
2023-04-03T18:03:11.393Z,1680544991.393 [CommandExec](IMPORTANT): DeadReckonUsingDVLWaterTrack.velocityStaleAfter (second)
2023-04-03T18:03:11.393Z,1680544991.393 [CommandExec](IMPORTANT): DeadReckonUsingDVLWaterTrack.verbosity (count)
2023-04-03T18:03:11.474Z,1680544991.474 [CommandExec](IMPORTANT): Rowe_600.waterReferenceLayerBin (count)
2023-04-03T18:03:11.474Z,1680544991.474 [CommandExec](IMPORTANT): Rowe_600.waterTrackVelocityAccuracy (meter_per_second)
2023-04-03T18:03:11.475Z,1680544991.475 [CommandExec](IMPORTANT): Waterlinked.loadAtStartup (bool)
2023-04-03T18:03:11.476Z,1680544991.476 [CommandExec](IMPORTANT): Waterlinked.simulateHardware (bool)
2023-04-03T18:03:11.490Z,1680544991.490 [CommandExec](IMPORTANT): SpeedCalculator.platform_speed_wrt_sea_water (meter_per_second)
2023-04-03T18:03:11.490Z,1680544991.490 [CommandExec](IMPORTANT): SpeedCalculator.platform_x_velocity_wrt_sea_water (meter_per_second)
2023-04-03T18:03:11.491Z,1680544991.491 [CommandExec](IMPORTANT): SpeedCalculator.platform_distance_wrt_sea_water (meter)
2023-04-03T18:03:11.508Z,1680544991.508 [CommandExec](IMPORTANT): Depth_Keller.sea_water_pressure (decibar)
2023-04-03T18:03:11.511Z,1680544991.511 [CommandExec](IMPORTANT): Waterlinked.enableBroadcast (bool)
2023-04-03T18:03:11.511Z,1680544991.511 [CommandExec](IMPORTANT): Waterlinked.component_voltage (volt)
2023-04-03T18:03:11.511Z,1680544991.511 [CommandExec](IMPORTANT): Waterlinked.component_avgVoltage (volt)
2023-04-03T18:03:11.530Z,1680544991.530 [CommandExec](IMPORTANT): Waterlinked.component_current (milliampere)
2023-04-03T18:03:11.530Z,1680544991.530 [CommandExec](IMPORTANT): Waterlinked.component_avgCurrent (milliampere)
2023-04-03T18:03:11.531Z,1680544991.531 [CommandExec](IMPORTANT): Waterlinked.height_above_sea_floor (meter)
2023-04-03T18:03:11.531Z,1680544991.531 [CommandExec](IMPORTANT): Waterlinked.platform_velocity_wrt_ground (meter_per_second)
2023-04-03T18:03:11.531Z,1680544991.531 [CommandExec](IMPORTANT): Waterlinked.platform_x_velocity_wrt_ground (meter_per_second)
2023-04-03T18:03:11.532Z,1680544991.532 [CommandExec](IMPORTANT): Waterlinked.platform_y_velocity_wrt_ground (meter_per_second)
2023-04-03T18:03:11.532Z,1680544991.532 [CommandExec](IMPORTANT): Waterlinked.platform_z_velocity_wrt_ground (meter_per_second)
2023-04-03T18:03:11.533Z,1680544991.533 [CommandExec](IMPORTANT): Waterlinked.BottomVelocityFlag (count)
2023-04-03T18:03:11.535Z,1680544991.535 [CommandExec](IMPORTANT): CTD_Seabird.sea_water_electrical_conductivity (siemens_per_meter)
2023-04-03T18:03:11.535Z,1680544991.535 [CommandExec](IMPORTANT): CTD_Seabird.sea_water_temperature (celsius)
2023-04-03T18:03:11.536Z,1680544991.536 [CommandExec](IMPORTANT): CTD_Seabird.sea_water_pressure (decibar)
2023-04-03T18:03:11.536Z,1680544991.536 [CommandExec](IMPORTANT): CTD_Seabird.sea_water_salinity (practical_salinity_unit)
2023-04-03T18:03:11.536Z,1680544991.536 [CommandExec](IMPORTANT): CTD_Seabird.sea_water_density (kilogram_per_cubic_meter)
2023-04-03T18:03:11.537Z,1680544991.537 [CommandExec](IMPORTANT): CTD_Seabird.speed_of_sound_in_sea_water (meter_per_second)
2023-04-03T18:03:11.537Z,1680544991.537 [CommandExec](IMPORTANT): CTD_Seabird.mass_concentration_of_oxygen_in_sea_water (microgram_per_liter)
2023-04-03T18:03:11.538Z,1680544991.538 [CommandExec](IMPORTANT): CTD_Seabird.sea_water_dissolved_oxygen_freq (hertz)
2023-04-03T18:03:11.538Z,1680544991.538 [CommandExec](IMPORTANT): CTD_Seabird.bin_median_sea_water_temperature (celsius)
2023-04-03T18:03:11.538Z,1680544991.538 [CommandExec](IMPORTANT): CTD_Seabird.bin_mean_sea_water_temperature (celsius)
2023-04-03T18:03:11.539Z,1680544991.539 [CommandExec](IMPORTANT): CTD_Seabird.bin_standard_deviation_sea_water_temperature (celsius)
2023-04-03T18:03:11.539Z,1680544991.539 [CommandExec](IMPORTANT): CTD_Seabird.bin_median_sea_water_salinity (practical_salinity_unit)
2023-04-03T18:03:11.539Z,1680544991.539 [CommandExec](IMPORTANT): CTD_Seabird.bin_mean_sea_water_salinity (practical_salinity_unit)
2023-04-03T18:03:11.540Z,1680544991.540 [CommandExec](IMPORTANT): CTD_Seabird.bin_standard_deviation_sea_water_salinity (practical_salinity_unit)
2023-04-03T18:03:11.568Z,1680544991.568 [CommandExec](IMPORTANT): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water (micromole_per_second_per_square_meter)
2023-04-03T18:03:11.569Z,1680544991.569 [CommandExec](IMPORTANT): WetLabsBB2FL.mass_concentration_of_chlorophyll_in_sea_water (microgram_per_liter)
2023-04-03T18:03:11.570Z,1680544991.570 [CommandExec](IMPORTANT): WetLabsBB2FL.bin_median_mass_concentration_of_chlorophyll_in_sea_water (microgram_per_liter)
2023-04-03T18:03:11.570Z,1680544991.570 [CommandExec](IMPORTANT): WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water (microgram_per_liter)
2023-04-03T18:03:11.571Z,1680544991.571 [CommandExec](IMPORTANT): WetLabsBB2FL.bin_variance_mass_concentration_of_chlorophyll_in_sea_water (microgram_per_liter)
2023-04-03T18:03:18.787Z,1680544998.787 [CommandExec](IMPORTANT): got command get Waterlinked.uart
2023-04-03T18:03:18.788Z,1680544998.788 [CommandExec](IMPORTANT): Waterlinked.uart /dev/ttyB4
2023-04-03T18:03:32.978Z,1680545012.978 [CommandExec](IMPORTANT): got command get Waterlinked.loadControl
2023-04-03T18:03:32.978Z,1680545012.978 [CommandExec](IMPORTANT): Waterlinked.loadControl /dev/loadB4
2023-04-03T18:03:37.949Z,1680545017.949 [IBIT](IMPORTANT): Communications Status:
Fix Status: 1
Iridium Signal Strength: 2
Latitude: 36.802998 Longitude: -121.788017
2023-04-03T18:03:37.977Z,1680545017.977 [CommandExec](IMPORTANT): got command failComponent
2023-04-03T18:03:37.977Z,1680545017.977 [CommandExec](IMPORTANT): Failed components:
2023-04-03T18:03:37.977Z,1680545017.977 [CommandExec](IMPORTANT): No failed Components.
2023-04-03T18:03:38.314Z,1680545018.314 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 0.000000
Voltage: 16.650999
2023-04-03T18:03:38.315Z,1680545018.315 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah
2023-04-03T18:03:38.315Z,1680545018.315 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V
2023-04-03T18:03:38.694Z,1680545018.694 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2023-04-03T18:03:38.695Z,1680545018.695 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2023-04-03T18:03:38.697Z,1680545018.697 [IBIT](IMPORTANT): Pressure:9.188049 PSI
2023-04-03T18:03:38.697Z,1680545018.697 [IBIT](IMPORTANT): Humidity:17.250641 %
2023-04-03T18:03:39.130Z,1680545019.130 [IBIT](IMPORTANT): Vehicle Pitch:0.107731 degrees
2023-04-03T18:03:39.130Z,1680545019.130 [IBIT](IMPORTANT): Vehicle  Roll:0.761960 degrees
2023-04-03T18:03:39.131Z,1680545019.131 [IBIT](IMPORTANT): Vehicle  Heading:255.486481 degrees
2023-04-03T18:03:39.511Z,1680545019.511 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2023-04-03T18:03:39.511Z,1680545019.511 [IBIT](IMPORTANT): buoyancyNeutral: 236.612869 cc
2023-04-03T18:03:39.511Z,1680545019.511 [IBIT](IMPORTANT): massDefault: 1.788377 cm
2023-04-03T18:03:39.512Z,1680545019.512 [IBIT](IMPORTANT): stopDepth: 290.000000 m
2023-04-03T18:03:39.512Z,1680545019.512 [IBIT](IMPORTANT): abortDepth: 300.000000 m
2023-04-03T18:03:39.512Z,1680545019.512 [IBIT](IMPORTANT): IBIT PASSED
2023-04-03T18:03:52.839Z,1680545032.839 [NAL9602](INFO): SBD MO Status=2, MOMSN=11271, MT Status=2, MTMSN=0
2023-04-03T18:03:52.839Z,1680545032.839 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-04-03T18:04:55.482Z,1680545095.482 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-03T18:04:55.482Z,1680545095.482 [Default:CheckIn:C.Wait] Stopped
2023-04-03T18:04:55.482Z,1680545095.482 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-03T18:04:55.482Z,1680545095.482 [Default:CheckIn:D] Running Loop=1
2023-04-03T18:04:55.874Z,1680545095.874 [Default:CheckIn:D] Stopped
2023-04-03T18:04:55.874Z,1680545095.874 [Default:CheckIn:E] Running Loop=1
2023-04-03T18:04:56.278Z,1680545096.278 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 157.680176 min 
2023-04-03T18:04:56.278Z,1680545096.278 [Default:CheckIn:E] Stopped
2023-04-03T18:04:56.278Z,1680545096.278 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-03T18:04:56.278Z,1680545096.278 [Default:CheckIn] Stopped
2023-04-03T18:04:56.278Z,1680545096.278 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-03T18:04:56.279Z,1680545096.279 [Default:CheckIn](INFO): Running loop #26
2023-04-03T18:04:56.279Z,1680545096.279 [Default:CheckIn] Running Loop=26
2023-04-03T18:04:56.279Z,1680545096.279 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-03T18:04:56.279Z,1680545096.279 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-03T18:05:31.409Z,1680545131.409 [NAL