2025-05-27T15:04:09.337Z,1748358249.337 [Supervisor](DEBUG): Initializing supervisor.
2025-05-27T15:04:09.342Z,1748358249.342 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2025-05-27T15:04:09.342Z,1748358249.342 [SyncHandler](INFO): Protected caller Thread ID is 999
2025-05-27T15:04:09.343Z,1748358249.343 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2025-05-27T15:04:09.344Z,1748358249.344 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2025-05-27T15:04:09.345Z,1748358249.345 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 1000
2025-05-27T15:04:09.349Z,1748358249.349 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2025-05-27T15:04:09.370Z,1748358249.370 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2025-05-27T15:04:09.371Z,1748358249.371 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2025-05-27T15:04:09.372Z,1748358249.372 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 1001
2025-05-27T15:04:09.376Z,1748358249.376 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2025-05-27T15:04:09.377Z,1748358249.377 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2025-05-27T15:04:09.378Z,1748358249.378 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 1002
2025-05-27T15:04:09.380Z,1748358249.380 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2025-05-27T15:04:09.381Z,1748358249.381 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2025-05-27T15:04:09.381Z,1748358249.381 [logger ThreadHandler](INFO): Protected caller Thread ID is 1003
2025-05-27T15:04:09.385Z,1748358249.385 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2025-05-27T15:04:09.386Z,1748358249.386 [Supervisor](INFO): Looking for Config files in directory: Config/
2025-05-27T15:04:09.387Z,1748358249.387 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2025-05-27T15:04:09.745Z,1748358249.745 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2025-05-27T15:04:09.746Z,1748358249.746 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2025-05-27T15:04:09.847Z,1748358249.847 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Guidance
2025-05-27T15:04:09.848Z,1748358249.848 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2025-05-27T15:04:09.967Z,1748358249.967 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2025-05-27T15:04:09.967Z,1748358249.967 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2025-05-27T15:04:10.112Z,1748358250.112 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2025-05-27T15:04:10.113Z,1748358250.113 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2025-05-27T15:04:10.484Z,1748358250.484 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2025-05-27T15:04:10.485Z,1748358250.485 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2025-05-27T15:04:10.592Z,1748358250.592 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2025-05-27T15:04:10.593Z,1748358250.593 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2025-05-27T15:04:11.030Z,1748358251.030 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2025-05-27T15:04:11.031Z,1748358251.031 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2025-05-27T15:04:11.277Z,1748358251.277 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2025-05-27T15:04:11.277Z,1748358251.277 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2025-05-27T15:04:11.368Z,1748358251.368 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2025-05-27T15:04:11.622Z,1748358251.622 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2025-05-27T15:04:11.623Z,1748358251.623 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2025-05-27T15:04:11.859Z,1748358251.859 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2025-05-27T15:04:11.860Z,1748358251.860 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2025-05-27T15:04:12.423Z,1748358252.423 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2025-05-27T15:04:12.424Z,1748358252.424 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2025-05-27T15:04:12.642Z,1748358252.642 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2025-05-27T15:04:12.643Z,1748358252.643 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2025-05-27T15:04:12.954Z,1748358252.954 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2025-05-27T15:04:12.955Z,1748358252.955 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2025-05-27T15:04:13.874Z,1748358253.874 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2025-05-27T15:04:13.875Z,1748358253.875 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2025-05-27T15:04:14.472Z,1748358254.472 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2025-05-27T15:04:14.474Z,1748358254.474 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-ahi/
2025-05-27T15:04:14.474Z,1748358254.474 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Control.cfg
2025-05-27T15:04:14.581Z,1748358254.581 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Science.cfg
2025-05-27T15:04:14.724Z,1748358254.724 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/secure.cfg
2025-05-27T15:04:14.819Z,1748358254.819 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Servo.cfg
2025-05-27T15:04:14.937Z,1748358254.937 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/BIT.cfg
2025-05-27T15:04:15.035Z,1748358255.035 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Battery.cfg
2025-05-27T15:04:15.314Z,1748358255.314 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2025-05-27T15:04:15.315Z,1748358255.315 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/vehicle.cfg
2025-05-27T15:04:15.438Z,1748358255.438 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/logger.cfg
2025-05-27T15:04:15.548Z,1748358255.548 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Sensor.cfg
2025-05-27T15:04:15.703Z,1748358255.703 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Simulator.cfg
2025-05-27T15:04:15.800Z,1748358255.800 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-ahi/root/
2025-05-27T15:04:15.801Z,1748358255.801 [Supervisor](IMPORTANT): Reloading configuration overrides from Data/persisted.cfg
2025-05-27T15:04:15.812Z,1748358255.812 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2025-05-27T15:04:15.961Z,1748358255.961 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2025-05-27T15:04:15.962Z,1748358255.962 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2025-05-27T15:04:16.020Z,1748358256.020 [VerticalControl](DEBUG): Construct VerticalControl.
2025-05-27T15:04:16.085Z,1748358256.085 [VerticalControl] Loaded
2025-05-27T15:04:16.085Z,1748358256.085 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2025-05-27T15:04:16.088Z,1748358256.088 [HorizontalControl](DEBUG): Construct HorizontalControl.
2025-05-27T15:04:16.138Z,1748358256.138 [HorizontalControl] Loaded
2025-05-27T15:04:16.138Z,1748358256.138 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2025-05-27T15:04:16.140Z,1748358256.140 [SpeedControl](DEBUG): Construct SpeedControl.
2025-05-27T15:04:16.144Z,1748358256.144 [SpeedControl] Loaded
2025-05-27T15:04:16.144Z,1748358256.144 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2025-05-27T15:04:16.147Z,1748358256.147 [LoopControl](DEBUG): Construct LoopControl.
2025-05-27T15:04:16.147Z,1748358256.147 [LoopControl] Loaded
2025-05-27T15:04:16.148Z,1748358256.148 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2025-05-27T15:04:16.148Z,1748358256.148 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2025-05-27T15:04:16.149Z,1748358256.149 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2025-05-27T15:04:16.213Z,1748358256.213 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2025-05-27T15:04:16.213Z,1748358256.213 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2025-05-27T15:04:16.754Z,1748358256.754 [AHRS_M2] Loaded
2025-05-27T15:04:16.754Z,1748358256.754 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2025-05-27T15:04:16.794Z,1748358256.794 [BackseatComponent] Loaded
2025-05-27T15:04:16.794Z,1748358256.794 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2025-05-27T15:04:16.795Z,1748358256.795 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 408BA4E0
2025-05-27T15:04:16.796Z,1748358256.796 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 1082
2025-05-27T15:04:16.799Z,1748358256.799 [LcmUniversalReporter] Loaded
2025-05-27T15:04:16.799Z,1748358256.799 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2025-05-27T15:04:17.651Z,1748358257.651 [BPC1] Loaded
2025-05-27T15:04:17.651Z,1748358257.651 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2025-05-27T15:04:17.751Z,1748358257.751 [DAT] Loaded
2025-05-27T15:04:17.751Z,1748358257.751 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread.
2025-05-27T15:04:17.752Z,1748358257.752 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 408EA4E0
2025-05-27T15:04:17.753Z,1748358257.753 [DAT ThreadHandler](INFO): Protected caller Thread ID is 1083
2025-05-27T15:04:17.826Z,1748358257.826 [DataOverHttps] Loaded
2025-05-27T15:04:17.826Z,1748358257.826 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2025-05-27T15:04:17.827Z,1748358257.827 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4091A4E0
2025-05-27T15:04:17.828Z,1748358257.828 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 1084
2025-05-27T15:04:17.851Z,1748358257.851 [Depth_Keller] Loaded
2025-05-27T15:04:17.852Z,1748358257.852 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2025-05-27T15:04:17.857Z,1748358257.857 [DropWeight] Loaded
2025-05-27T15:04:17.857Z,1748358257.857 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2025-05-27T15:04:17.924Z,1748358257.924 [NAL9602] Loaded
2025-05-27T15:04:17.924Z,1748358257.924 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2025-05-27T15:04:17.955Z,1748358257.955 [Onboard] Loaded
2025-05-27T15:04:17.956Z,1748358257.956 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2025-05-27T15:04:17.957Z,1748358257.957 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 4094A4E0
2025-05-27T15:04:17.957Z,1748358257.957 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 1085
2025-05-27T15:04:17.972Z,1748358257.972 [Power24vConverter] Loaded
2025-05-27T15:04:17.972Z,1748358257.972 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2025-05-27T15:04:17.988Z,1748358257.988 [Radio_Surface] Loaded
2025-05-27T15:04:17.989Z,1748358257.989 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2025-05-27T15:04:17.990Z,1748358257.990 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4097A4E0
2025-05-27T15:04:17.990Z,1748358257.990 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 1086
2025-05-27T15:04:18.006Z,1748358258.006 [Sonardyne_Nano] Loaded
2025-05-27T15:04:18.006Z,1748358258.006 [ComponentRegistry](DEBUG): SyncComponent "Sonardyne_Nano" handled in the control thread.
2025-05-27T15:04:18.032Z,1748358258.032 [Waterlinked] Loaded
2025-05-27T15:04:18.032Z,1748358258.032 [ComponentRegistry](DEBUG): SyncComponent "Waterlinked" handled in the control thread.
2025-05-27T15:04:18.032Z,1748358258.032 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2025-05-27T15:04:18.033Z,1748358258.033 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2025-05-27T15:04:18.044Z,1748358258.044 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2025-05-27T15:04:18.044Z,1748358258.044 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2025-05-27T15:04:18.075Z,1748358258.075 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2025-05-27T15:04:18.076Z,1748358258.076 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2025-05-27T15:04:18.258Z,1748358258.258 [SBIT](DEBUG): Construct Startup Built In Test.
2025-05-27T15:04:18.267Z,1748358258.267 [SBIT] Loaded
2025-05-27T15:04:18.267Z,1748358258.267 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2025-05-27T15:04:18.270Z,1748358258.270 [IBIT](DEBUG): Construct Initiated Built In Test.
2025-05-27T15:04:18.284Z,1748358258.284 [IBIT] Loaded
2025-05-27T15:04:18.284Z,1748358258.284 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2025-05-27T15:04:18.290Z,1748358258.290 [CBIT](DEBUG): Construct Continuous Built In Test.
2025-05-27T15:04:18.374Z,1748358258.374 [CBIT] Loaded
2025-05-27T15:04:18.375Z,1748358258.375 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2025-05-27T15:04:18.409Z,1748358258.409 [GFScanner] Loaded
2025-05-27T15:04:18.410Z,1748358258.410 [ComponentRegistry](DEBUG): SyncComponent "GFScanner" handled in the control thread.
2025-05-27T15:04:18.410Z,1748358258.410 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2025-05-27T15:04:18.411Z,1748358258.411 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2025-05-27T15:04:18.797Z,1748358258.797 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2025-05-27T15:04:18.798Z,1748358258.798 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2025-05-27T15:04:18.867Z,1748358258.867 [DepthRateCalculator] Loaded
2025-05-27T15:04:18.867Z,1748358258.867 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2025-05-27T15:04:18.873Z,1748358258.873 [PitchRateCalculator] Loaded
2025-05-27T15:04:18.873Z,1748358258.873 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2025-05-27T15:04:18.886Z,1748358258.886 [SpeedCalculator] Loaded
2025-05-27T15:04:18.886Z,1748358258.886 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2025-05-27T15:04:18.891Z,1748358258.891 [YawRateCalculator] Loaded
2025-05-27T15:04:18.891Z,1748358258.891 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2025-05-27T15:04:18.911Z,1748358258.911 [ElevatorOffsetCalculator] Loaded
2025-05-27T15:04:18.912Z,1748358258.912 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2025-05-27T15:04:18.912Z,1748358258.912 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2025-05-27T15:04:18.913Z,1748358258.913 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2025-05-27T15:04:19.111Z,1748358259.111 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2025-05-27T15:04:19.112Z,1748358259.112 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2025-05-27T15:04:19.232Z,1748358259.232 [DeadReckonUsingMultipleVelocitySources] Loaded
2025-05-27T15:04:19.232Z,1748358259.232 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2025-05-27T15:04:19.247Z,1748358259.247 [NavChart] Loaded
2025-05-27T15:04:19.247Z,1748358259.247 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2025-05-27T15:04:19.253Z,1748358259.253 [UniversalFixResidualReporter] Loaded
2025-05-27T15:04:19.253Z,1748358259.253 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2025-05-27T15:04:19.254Z,1748358259.254 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2025-05-27T15:04:19.255Z,1748358259.255 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2025-05-27T15:04:19.404Z,1748358259.404 [BuoyancyServo] Loaded
2025-05-27T15:04:19.405Z,1748358259.405 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2025-05-27T15:04:19.429Z,1748358259.429 [ElevatorServo] Loaded
2025-05-27T15:04:19.429Z,1748358259.429 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2025-05-27T15:04:19.452Z,1748358259.452 [MassServo] Loaded
2025-05-27T15:04:19.452Z,1748358259.452 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2025-05-27T15:04:19.474Z,1748358259.474 [RudderServo] Loaded
2025-05-27T15:04:19.475Z,1748358259.475 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2025-05-27T15:04:19.492Z,1748358259.492 [ThrusterHE] Loaded
2025-05-27T15:04:19.493Z,1748358259.493 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2025-05-27T15:04:19.493Z,1748358259.493 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2025-05-27T15:04:19.494Z,1748358259.494 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2025-05-27T15:04:19.677Z,1748358259.677 [CTD_Seabird] Loaded
2025-05-27T15:04:19.678Z,1748358259.678 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2025-05-27T15:04:19.679Z,1748358259.679 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40C084E0
2025-05-27T15:04:19.679Z,1748358259.679 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 1087
2025-05-27T15:04:19.717Z,1748358259.717 [ESPComponent] Loaded
2025-05-27T15:04:19.718Z,1748358259.718 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2025-05-27T15:04:19.742Z,1748358259.742 [PAR_Licor] Loaded
2025-05-27T15:04:19.742Z,1748358259.742 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2025-05-27T15:04:19.790Z,1748358259.790 [WetLabsBB2FL] Loaded
2025-05-27T15:04:19.790Z,1748358259.790 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2025-05-27T15:04:19.791Z,1748358259.791 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40C384E0
2025-05-27T15:04:19.791Z,1748358259.791 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 1088
2025-05-27T15:04:19.792Z,1748358259.792 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2025-05-27T15:04:19.799Z,1748358259.799 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2025-05-27T15:04:19.802Z,1748358259.802 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2025-05-27T15:04:19.813Z,1748358259.813 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2025-05-27T15:04:19.814Z,1748358259.814 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C684E0
2025-05-27T15:04:19.815Z,1748358259.815 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 1089
2025-05-27T15:04:19.821Z,1748358259.821 [Supervisor](INFO): Main Thread ID is 828
2025-05-27T15:04:19.821Z,1748358259.821 [Supervisor](DEBUG): Running supervisor.
2025-05-27T15:04:19.821Z,1748358259.821 [CommandExec ThreadHandler](INFO): Handler Thread ID is 1090
2025-05-27T15:04:19.822Z,1748358259.822 [CommandExec](INFO): Initializing the command executive.
2025-05-27T15:04:19.824Z,1748358259.824 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1091
2025-05-27T15:04:19.826Z,1748358259.826 [controlThread ThreadHandler](INFO): Handler Thread ID is 1092
2025-05-27T15:04:19.826Z,1748358259.826 [controlThread](DEBUG): Initializing ControlThread
2025-05-27T15:04:19.827Z,1748358259.827 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2025-05-27T15:04:19.829Z,1748358259.829 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2025-05-27T15:04:19.829Z,1748358259.829 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2025-05-27T15:04:19.830Z,1748358259.830 [LoopControl](DEBUG): Initialize LoopControlComponent.
2025-05-27T15:04:19.833Z,1748358259.833 [SBIT](INFO): Initialize SBIT Component.
2025-05-27T15:04:19.834Z,1748358259.834 [SBIT](IMPORTANT): git: 2025-05-23_A
2025-05-27T15:04:19.834Z,1748358259.834 [SBIT](INFO): git hash: 0cebe5b25683db7ef36342411ce18bf4893139b3
2025-05-27T15:04:19.834Z,1748358259.834 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2025-05-27T15:04:19.835Z,1748358259.835 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #639 PREEMPT Wed Mar 12 12:53:33 PDT 2014
Kernel Reported: #1 PREEMPT Tue Nov 28 15:04:22 PST 2023
2025-05-27T15:04:19.836Z,1748358259.836 [SBIT](INFO): Beginning SBIT in 112.000000 seconds.
2025-05-27T15:04:19.837Z,1748358259.837 [IBIT](INFO): Initialize IBIT Component.
2025-05-27T15:04:19.838Z,1748358259.838 [CBIT](DEBUG): Initialize CBIT Component.
2025-05-27T15:04:19.839Z,1748358259.839 [logger ThreadHandler](INFO): Handler Thread ID is 1093
2025-05-27T15:04:19.851Z,1748358259.851 [CBIT](DEBUG): Initialized mux pins.
2025-05-27T15:04:19.851Z,1748358259.851 [CBIT](DEBUG): Initializing the watchdog timer.
2025-05-27T15:04:19.859Z,1748358259.859 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 1094
2025-05-27T15:04:19.875Z,1748358259.875 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2025-05-27T15:04:19.875Z,1748358259.875 [CBIT](DEBUG): Initializing heartbeat.
2025-05-27T15:04:19.876Z,1748358259.876 [DAT ThreadHandler](INFO): Handler Thread ID is 1095
2025-05-27T15:04:19.877Z,1748358259.877 [DAT](INFO): Powering up
2025-05-27T15:04:19.877Z,1748358259.877 [DAT](DEBUG): Initializing DAT.
2025-05-27T15:04:19.880Z,1748358259.880 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 1097
2025-05-27T15:04:19.882Z,1748358259.882 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2025-05-27T15:04:19.903Z,1748358259.903 [Onboard ThreadHandler](INFO): Handler Thread ID is 1098
2025-05-27T15:04:19.921Z,1748358259.921 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 1099
2025-05-27T15:04:19.941Z,1748358259.941 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 1100
2025-05-27T15:04:19.942Z,1748358259.942 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2025-05-27T15:04:19.947Z,1748358259.947 [CBIT](DEBUG): Deactivating emergency mode.
2025-05-27T15:04:19.956Z,1748358259.956 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 1102
2025-05-27T15:04:19.959Z,1748358259.959 [WetLabsBB2FL](INFO): Powering up
2025-05-27T15:04:19.961Z,1748358259.961 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1104
2025-05-27T15:04:19.963Z,1748358259.963 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2025-05-27T15:04:19.963Z,1748358259.963 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2025-05-27T15:04:19.963Z,1748358259.963 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2025-05-27T15:04:19.964Z,1748358259.964 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2025-05-27T15:04:19.964Z,1748358259.964 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2025-05-27T15:04:19.964Z,1748358259.964 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2025-05-27T15:04:19.964Z,1748358259.964 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2025-05-27T15:04:19.964Z,1748358259.964 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2025-05-27T15:04:19.987Z,1748358259.987 [CBIT](DEBUG): Backplane powered.
2025-05-27T15:04:19.988Z,1748358259.988 [GFScanner](DEBUG): Initializing GFScanner
2025-05-27T15:04:19.988Z,1748358259.988 [GFScanner](DEBUG): Deactivating GF circuits.
2025-05-27T15:04:19.992Z,1748358259.992 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2025-05-27T15:04:19.992Z,1748358259.992 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2025-05-27T15:04:19.992Z,1748358259.992 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2025-05-27T15:04:19.993Z,1748358259.993 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2025-05-27T15:04:19.993Z,1748358259.993 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2025-05-27T15:04:19.994Z,1748358259.994 [NavChart](DEBUG): Initialize NavChart Navigation.
2025-05-27T15:04:19.995Z,1748358259.995 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2025-05-27T15:04:19.000Z,1748358260.000 [MissionManager](IMPORTANT): Using TethysL tl-to-tx parser
2025-05-27T15:04:20.000Z,1748358260.000 [MissionManager](INFO): Loading Mission from file: Missions/Startup.tl
2025-05-27T15:04:20.001Z,1748358260.001 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Startup.tl
2025-05-27T15:04:20.002Z,1748358260.002 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Startup.tl
2025-05-27T15:04:20.098Z,1748358260.098 [MissionManager](DEBUG): TethyslAPI: Missions/Startup.tl translated into:
2025-05-27T15:04:20.103Z,1748358260.103 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2025-05-27T15:04:20.151Z,1748358260.151 [MissionManager](DEBUG):
# Copyright (c) 2024 MBARI
# MBARI Proprietary Information. Confidential. All Rights Reserved
# Unauthorized copying or distribution of this file via any medium is strictly
# prohibited.
#
# WARNING - This file contains information whose export is restricted by the
# Export Administration Act of 1979 (Title 50, U.S.C., App. 2401 et seq.), as
# amended. Violations of these export laws are subject to severe civil and/or
# criminal penalties.
mission Startup {
behavior Guidance:GoToSurface {
run in progression
}
aggregate StartupSatComms {
run in sequence
readDatum {
timeout duration=P1M
Universal:latitude_fix
}
readDatum {
timeout duration=P1M
Universal:platform_communications
}
}
}
2025-05-27T15:04:20.152Z,1748358260.152 [MissionManager](INFO): Loading Mission from file: Missions/Default.tl
2025-05-27T15:04:20.152Z,1748358260.152 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Default.tl
2025-05-27T15:04:20.153Z,1748358260.153 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Default.tl
2025-05-27T15:04:20.327Z,1748358260.327 [Radio_Surface](INFO): Powering up
2025-05-27T15:04:20.474Z,1748358260.474 [MissionManager](DEBUG): TethyslAPI: Missions/Default.tl translated into:
0
13
Burn on
Dropped weight due to communications timeout.
5
Default mission has been running for
Restarting logs and Default mission.
restart logs
2025-05-27T15:04:20.496Z,1748358260.496 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2025-05-27T15:04:20.497Z,1748358260.497 [Default:A.Wait](DEBUG): Construct Wait.
2025-05-27T15:04:20.500Z,1748358260.500 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2025-05-27T15:04:20.549Z,1748358260.549 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2025-05-27T15:04:20.552Z,1748358260.552 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2025-05-27T15:04:20.578Z,1748358260.578 [Default:E.Execute](DEBUG): Construct Execute.
2025-05-27T15:04:20.581Z,1748358260.581 [MissionManager](DEBUG):
# Copyright (c) 2024 MBARI
# MBARI Proprietary Information. Confidential. All Rights Reserved
# Unauthorized copying or distribution of this file via any medium is strictly
# prohibited.
#
# WARNING - This file contains information whose export is restricted by the
# Export Administration Act of 1979 (Title 50, U.S.C., App. 2401 et seq.), as
# amended. Violations of these export laws are subject to severe civil and/or
# criminal penalties.
mission Default {
arguments {
ElapsedSinceDefaultStarted = 0 minute
}
behavior Guidance:Wait {
"""
Wait a moment to see if the scheduler starts a new mission before
starting to actually run Default.
"""
run in sequence
set duration = 13 second
}
behavior Guidance:GoToSurface {
run in progression
}
aggregate CheckIn {
run in sequence repeat=288
readDatum id="Read_GPS" {
timeout duration=P5M
Universal:time_fix
}
readDatum id="Read_Iridium" {
timeout duration=P4H {
behavior Guidance:Execute {
run in sequence
set command = "Burn on"
}
syslog critical "Dropped weight due to communications timeout."
}
Universal:platform_communications
}
behavior Guidance:Wait {
run in sequence
set duration = 5 minute
}
assign in sequence ElapsedSinceDefaultStarted = elapsed ( Universal:mission_started )
syslog important "Default mission has been running for " + ElapsedSinceDefaultStarted~minute
}
syslog important "Restarting logs and Default mission."
behavior Guidance:Execute {
run in sequence
set command = "restart logs"
}
}
2025-05-27T15:04:20.591Z,1748358260.591 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,Sonardyne_Nano,Waterlinked,ESPComponent,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,GFScanner,LcmUniversalReporter,Reporter,LogSplitter,
2025-05-27T15:04:20.603Z,1748358260.603 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2025-05-27T15:04:20.663Z,1748358260.663 [Depth_Keller](INFO): Initializing.
2025-05-27T15:04:20.665Z,1748358260.665 [Power24vConverter](INFO): Powering up.
2025-05-27T15:04:20.665Z,1748358260.665 [Sonardyne_Nano](INFO): Initializing.
2025-05-27T15:04:20.712Z,1748358260.712 [DepthRateCalculator](ERROR): Depth measurement is not active
2025-05-27T15:04:20.738Z,1748358260.738 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2025-05-27T15:04:20.743Z,1748358260.743 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2025-05-27T15:04:20.744Z,1748358260.744 [ElevatorServo](DEBUG): Initializing EZServoServo.
2025-05-27T15:04:20.751Z,1748358260.751 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2025-05-27T15:04:20.752Z,1748358260.752 [MassServo](DEBUG): Initializing EZServoServo.
2025-05-27T15:04:20.759Z,1748358260.759 [MassServo](DEBUG): Initializing MassServo.
2025-05-27T15:04:20.760Z,1748358260.760 [RudderServo](DEBUG): Initializing EZServoServo.
2025-05-27T15:04:20.767Z,1748358260.767 [RudderServo](DEBUG): Initializing RudderServo.
2025-05-27T15:04:20.768Z,1748358260.768 [ThrusterHE](DEBUG): Initializing EZServoServo.
2025-05-27T15:04:20.775Z,1748358260.775 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2025-05-27T15:04:22.067Z,1748358262.067 [WetLabsBB2FL](INFO): Powering down
2025-05-27T15:04:22.621Z,1748358262.621 [Sonardyne_Nano](ERROR): Failed to get valid response or reached max queue size, flushing UART
2025-05-27T15:04:23.915Z,1748358263.915 [Sonardyne_Nano](IMPORTANT): Found beacon with acoustic ID 2311
2025-05-27T15:04:26.512Z,1748358266.512 [ThrusterHE](ERROR): Zero Speed Commanded.
2025-05-27T15:04:26.971Z,1748358266.971 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit.
2025-05-27T15:04:32.224Z,1748358272.224 [DAT](INFO): DAT read:
2025-05-27T15:04:32.225Z,1748358272.225 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series
2025-05-27T15:04:33.990Z,1748358273.990 [DAT](INFO): DAT read: MF Frequency Band
2025-05-27T15:04:33.992Z,1748358273.992 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0
2025-05-27T15:04:33.992Z,1748358273.992 [DAT](INFO): DAT read: May 27 2025 15:04:27
2025-05-27T15:04:34.996Z,1748358274.996 [DAT](INFO): DAT read: Features enabled [Bearing]
2025-05-27T15:04:34.997Z,1748358274.997 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP
2025-05-27T15:04:34.998Z,1748358274.998 [DAT](INFO): commRate: 800
2025-05-27T15:04:37.063Z,1748358277.063 [DAT](INFO): entering command mode
2025-05-27T15:04:37.264Z,1748358277.264 [DAT](INFO): DAT read:
2025-05-27T15:04:37.264Z,1748358277.264 [DAT](INFO): DAT read: user:1>
2025-05-27T15:04:37.265Z,1748358277.265 [DAT](INFO): setting verbose to 3
2025-05-27T15:04:37.516Z,1748358277.516 [DAT](INFO): DAT read: user:1>
2025-05-27T15:04:37.517Z,1748358277.517 [DAT](INFO): DAT read: Verbose | 3
2025-05-27T15:04:37.517Z,1748358277.517 [DAT](INFO): set verbose to 3
2025-05-27T15:04:37.517Z,1748358277.517 [DAT](INFO): setting DatVerbose to 27440
2025-05-27T15:04:37.768Z,1748358277.768 [DAT](INFO): DAT read: user:2>
2025-05-27T15:04:37.769Z,1748358277.769 [DAT](INFO): DAT read: DatVerbose | 27440
2025-05-27T15:04:37.769Z,1748358277.769 [DAT](INFO): set DatVerbose to 27440
2025-05-27T15:04:37.769Z,1748358277.769 [DAT](INFO): setting transmit power to 8
2025-05-27T15:04:38.020Z,1748358278.020 [DAT](INFO): DAT read: user:3>
2025-05-27T15:04:38.021Z,1748358278.021 [DAT](INFO): DAT read: TxPower | 8 (Max)
2025-05-27T15:04:38.021Z,1748358278.021 [DAT](INFO): set transmit power to 8
2025-05-27T15:04:38.021Z,1748358278.021 [DAT](INFO): setting local address to 1
2025-05-27T15:04:38.272Z,1748358278.272 [DAT](INFO): DAT read: user:4>
2025-05-27T15:04:38.273Z,1748358278.273 [DAT](INFO): DAT read: LocalAddr | 1
2025-05-27T15:04:38.273Z,1748358278.273 [DAT](INFO): set local address to 1
2025-05-27T15:04:38.274Z,1748358278.274 [DAT](INFO): Setting time to: 15:4:38 And date to:5/27/2025
2025-05-27T15:04:38.524Z,1748358278.524 [DAT](INFO): DAT read: user:5>
2025-05-27T15:04:38.525Z,1748358278.525 [DAT](INFO): DAT read: Tue May 27, 2025 15:04:38
2025-05-27T15:04:38.525Z,1748358278.525 [DAT](INFO): Local DAT time set to Tue May 27, 2025 15:04:38
2025-05-27T15:04:48.093Z,1748358288.093 [NAL9602](INFO): Powering up NAL9602
2025-05-27T15:04:51.945Z,1748358291.945 [Waterlinked](ERROR): only read 3 of 5 data items. Device response::BI, +0, +0,0,V
2025-05-27T15:04:58.136Z,1748358298.136 [Waterlinked](INFO): Powering down
2025-05-27T15:04:59.261Z,1748358299.261 [NAL9602](INFO): NAL9602 initialized
2025-05-27T15:05:27.533Z,1748358327.533 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-05-27T15:05:42.482Z,1748358342.482 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-05-27T15:05:57.833Z,1748358357.833 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-05-27T15:06:12.399Z,1748358372.399 [SBIT](IMPORTANT): Beginning Startup BIT
2025-05-27T15:06:12.404Z,1748358372.404 [GFScanner](IMPORTANT): Beginning ground fault scan
2025-05-27T15:06:13.185Z,1748358373.185 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-05-27T15:06:16.926Z,1748358376.926 [GFScanner](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): 0.022032
CHAN A1 (24V): 0.001407
CHAN A2 (12V): 0.000716
CHAN A3 (5V): -0.001447
CHAN B0 (3.3V): 0.000084
CHAN B1 (3.15aV): -0.000089
CHAN B2 (3.15bV): -0.000299
CHAN B3 (GND): -0.000736
OPEN: 0.006397
Full Scale: +/- 1 mA
2025-05-27T15:06:28.149Z,1748358388.149 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-05-27T15:06:43.097Z,1748358403.097 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-05-27T15:06:58.077Z,1748358418.077 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-05-27T15:07:02.998Z,1748358422.998 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.013373
2025-05-27T15:07:06.197Z,1748358426.197 [SBIT](IMPORTANT): SBIT PASSED
2025-05-27T15:07:06.197Z,1748358426.197 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2025-05-27T15:07:06.197Z,1748358426.197 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=15 count;
2025-05-27T15:07:06.198Z,1748358426.198 [SBIT](IMPORTANT): Express linearApproximation TrackAcousticContact.range_to_contact 15.000000 meter;
2025-05-27T15:07:06.198Z,1748358426.198 [SBIT](IMPORTANT): Express linearApproximation _.planktivore_HM_AvgRois 0.200000 count_per_second;
2025-05-27T15:07:06.198Z,1748358426.198 [SBIT](IMPORTANT): Express linearApproximation _.planktivore_LM_AvgRois 0.200000 count_per_second;
2025-05-27T15:07:06.198Z,1748358426.198 [SBIT](IMPORTANT): Express linearApproximation latitude 0.001000 degree;
2025-05-27T15:07:06.198Z,1748358426.198 [SBIT](IMPORTANT): Express linearApproximation longitude 0.001000 degree;
2025-05-27T15:07:06.198Z,1748358426.198 [SBIT](IMPORTANT): IBIT.batteryCapacityThreshold=-0.5 ampere_hour;
2025-05-27T15:07:06.198Z,1748358426.198 [SBIT](IMPORTANT): IBIT.batteryVoltageThreshold=10 volt;
2025-05-27T15:07:06.198Z,1748358426.198 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=162.296537 cubic_centimeter;
2025-05-27T15:07:06.198Z,1748358426.198 [SBIT](IMPORTANT): VerticalControl.massDefault=23.162221 millimeter;
2025-05-27T15:07:06.199Z,1748358426.199 [SBIT](IMPORTANT): Waterlinked.loadAtStartup=1 bool;
2025-05-27T15:07:06.601Z,1748358426.601 [MissionManager](IMPORTANT): Started mission Startup
2025-05-27T15:07:06.602Z,1748358426.602 [Startup] Running Loop=1
2025-05-27T15:07:06.602Z,1748358426.602 [Startup](DEBUG): Aggregate::initialize Startup
2025-05-27T15:07:06.602Z,1748358426.602 [Startup:A.GoToSurface] Running Loop=1
2025-05-27T15:07:06.602Z,1748358426.602 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-05-27T15:07:06.602Z,1748358426.602 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2025-05-27T15:07:06.603Z,1748358426.603 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2025-05-27T15:07:06.603Z,1748358426.603 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2025-05-27T15:07:06.604Z,1748358426.604 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2025-05-27T15:07:06.604Z,1748358426.604 [Startup:A.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-05-27T15:07:06.604Z,1748358426.604 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-05-27T15:07:06.607Z,1748358426.607 [Startup:StartupSatComms] Running Loop=1
2025-05-27T15:07:06.607Z,1748358426.607 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2025-05-27T15:07:06.607Z,1748358426.607 [Startup:StartupSatComms:A] Running Loop=1
2025-05-27T15:07:06.978Z,1748358426.978 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2025-05-27T15:07:13.430Z,1748358433.430 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-05-27T15:07:17.168Z,1748358437.168 [CommandExec](IMPORTANT): got command failComponent
2025-05-27T15:07:17.168Z,1748358437.168 [CommandExec](IMPORTANT): Failed components:
2025-05-27T15:07:17.168Z,1748358437.168 [CommandExec](IMPORTANT): No failed Components.
2025-05-27T15:07:20.336Z,1748358440.336 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2025-05-27T15:07:20.336Z,1748358440.336 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-05-27T15:07:20.347Z,1748358440.347 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-05-27T15:07:20.741Z,1748358440.741 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-05-27T15:07:20.741Z,1748358440.741 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2025-05-27T15:07:21.873Z,1748358441.873 [CommandExec](IMPORTANT): got command strobe off
2025-05-27T15:07:21.873Z,1748358441.873 [CommandExec](IMPORTANT): Deactivating strobe
2025-05-27T15:07:28.379Z,1748358448.379 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-05-27T15:07:28.814Z,1748358448.814 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2025-05-27T15:08:06.814Z,1748358486.814 [Startup:StartupSatComms:A](INFO): Timed out from 2025-05-27T15:07:06.6Z
2025-05-27T15:08:06.814Z,1748358486.814 [Startup:StartupSatComms:A] Stopped
2025-05-27T15:08:06.814Z,1748358486.814 [Startup:StartupSatComms:B] Running Loop=1
2025-05-27T15:08:07.214Z,1748358487.214 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2025-05-27T15:08:14.331Z,1748358494.331 [DataOverHttps](INFO): Sending 38 bytes from file Logs/20250527T145044/Courier0007.lzma
2025-05-27T15:08:15.333Z,1748358495.333 [DataOverHttps](INFO): Moved sent file to Logs/20250527T145044/Courier0007.lzma.bak
2025-05-27T15:08:15.333Z,1748358495.333 [DataOverHttps](INFO): SBD MOMSN=25007085
2025-05-27T15:08:30.919Z,1748358510.919 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20250527T150409/Courier0000.lzma
2025-05-27T15:08:31.921Z,1748358511.921 [DataOverHttps](INFO): Moved sent file to Logs/20250527T150409/Courier0000.lzma.bak
2025-05-27T15:08:31.921Z,1748358511.921 [DataOverHttps](INFO): SBD MOMSN=25007087
2025-05-27T15:08:47.539Z,1748358527.539 [DataOverHttps](INFO): Sending 244 bytes from file Logs/20250527T145044/Express0008.lzma
2025-05-27T15:08:48.541Z,1748358528.541 [DataOverHttps](INFO): Moved sent file to Logs/20250527T145044/Express0008.lzma.bak
2025-05-27T15:08:48.541Z,1748358528.541 [DataOverHttps](INFO): SBD MOMSN=25007090
2025-05-27T15:09:05.677Z,1748358545.677 [DataOverHttps](INFO): Sending 1055 bytes from file Logs/20250527T150409/Express0001.lzma
2025-05-27T15:09:06.677Z,1748358546.677 [DataOverHttps](INFO): Moved sent file to Logs/20250527T150409/Express0001.lzma.bak
2025-05-27T15:09:06.677Z,1748358546.677 [DataOverHttps](INFO): SBD MOMSN=25007096
2025-05-27T15:09:06.976Z,1748358546.976 [Startup:StartupSatComms:B](INFO): Timed out from 2025-05-27T15:08:06.8Z
2025-05-27T15:09:06.976Z,1748358546.976 [Startup:StartupSatComms:B] Stopped
2025-05-27T15:09:06.976Z,1748358546.976 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2025-05-27T15:09:06.976Z,1748358546.976 [Startup:StartupSatComms] Stopped
2025-05-27T15:09:06.976Z,1748358546.976 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2025-05-27T15:09:06.977Z,1748358546.977 [Startup](INFO): Completed Startup
2025-05-27T15:09:06.977Z,1748358546.977 [MissionManager](INFO): Startup is completed.
2025-05-27T15:09:06.977Z,1748358546.977 [MissionManager](INFO): Uninitializing Mission Startup
2025-05-27T15:09:06.978Z,1748358546.978 [Startup] Stopped
2025-05-27T15:09:06.978Z,1748358546.978 [Startup](DEBUG): Aggregate::uninitialize Startup
2025-05-27T15:09:06.978Z,1748358546.978 [Startup:A.GoToSurface] Stopped
2025-05-27T15:09:06.978Z,1748358546.978 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-05-27T15:09:07.391Z,1748358547.391 [MissionManager](IMPORTANT): Started mission Default
2025-05-27T15:09:07.392Z,1748358547.392 [Default] Running Loop=1
2025-05-27T15:09:07.392Z,1748358547.392 [Default](DEBUG): Aggregate::initialize Default
2025-05-27T15:09:07.392Z,1748358547.392 [Default:B.GoToSurface] Running Loop=1
2025-05-27T15:09:07.392Z,1748358547.392 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-05-27T15:09:07.392Z,1748358547.392 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2025-05-27T15:09:07.392Z,1748358547.392 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2025-05-27T15:09:07.393Z,1748358547.393 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2025-05-27T15:09:07.393Z,1748358547.393 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2025-05-27T15:09:07.393Z,1748358547.393 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-05-27T15:09:07.394Z,1748358547.394 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-05-27T15:09:07.394Z,1748358547.394 [Default:A.Wait] Running Loop=1
2025-05-27T15:09:07.394Z,1748358547.394 [Default:A.Wait](DEBUG): Initialize Wait Component.
2025-05-27T15:09:20.398Z,1748358560.398 [Default:A.Wait](INFO): Done Waiting.
2025-05-27T15:09:20.398Z,1748358560.398 [Default:A.Wait] Stopped
2025-05-27T15:09:20.398Z,1748358560.398 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2025-05-27T15:09:20.773Z,1748358560.773 [Default:CheckIn] Running Loop=1
2025-05-27T15:09:20.774Z,1748358560.774 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-05-27T15:09:20.774Z,1748358560.774 [Default:CheckIn:Read_GPS] Running Loop=1
2025-05-27T15:09:21.158Z,1748358561.158 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2025-05-27T15:09:46.610Z,1748358586.610 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2025-05-27T15:09:58.671Z,1748358598.671 [BPC1](ERROR): BPC1B got IPBS message with 5 sticks (min is 7).
2025-05-27T15:10:03.121Z,1748358603.121 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2025-05-27T15:10:05.139Z,1748358605.139 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-05-27T15:10:18.869Z,1748358618.869 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-05-27T15:10:21.305Z,1748358621.305 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2025-05-27T15:10:21.305Z,1748358621.305 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-05-27T15:10:21.325Z,1748358621.325 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-05-27T15:10:21.729Z,1748358621.729 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-05-27T15:10:21.729Z,1748358621.729 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2025-05-27T15:10:32.607Z,1748358632.607 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-05-27T15:10:45.937Z,1748358645.937 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-05-27T15:10:59.269Z,1748358659.269 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-05-27T15:11:13.007Z,1748358673.007 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-05-27T15:11:27.145Z,1748358687.145 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-05-27T15:11:40.885Z,1748358700.885 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-05-27T15:11:55.021Z,1748358715.021 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-05-27T15:12:08.760Z,1748358728.760 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-05-27T15:12:22.501Z,1748358742.501 [BPC1](ERROR): Battery stick #29 (s/n: 00A7) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4AD0.
2025-05-27T15:12:22.502Z,1748358742.502 [BPC1](ERROR): Battery stick #51 (s/n: 01D6) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0.
2025-05-27T15:12:22.503Z,1748358742.503 [BPC1](ERROR): Battery stick #57 (s/n: 019F) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0.
2025-05-27T15:12:22.504Z,1748358742.504 [BPC1](ERROR): Battery stick #59 (s/n: 0184) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0.
2025-05-27T15:12:22.504Z,1748358742.504 [BPC1](INFO): Calculating totals. Valid battery stick count: 41. Valid reserve battery stick count: 5.
2025-05-27T15:12:22.507Z,1748358742.507 [BPC1](INFO): Received data from all battery sticks.
2025-05-27T15:13:22.302Z,1748358802.302 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2025-05-27T15:13:22.302Z,1748358802.302 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-05-27T15:13:22.313Z,1748358802.313 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-05-27T15:13:22.724Z,1748358802.724 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-05-27T15:13:22.725Z,1748358802.725 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2025-05-27T15:14:20.881Z,1748358860.881 [Default:CheckIn:Read_GPS](INFO): Timed out from 2025-05-27T15:09:20.8Z
2025-05-27T15:14:20.881Z,1748358860.881 [Default:CheckIn:Read_GPS] Stopped
2025-05-27T15:14:20.881Z,1748358860.881 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-05-27T15:14:21.285Z,1748358861.285 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2025-05-27T15:14:27.731Z,1748358867.731 [DataOverHttps](INFO): Sending 168 bytes from file Logs/20250527T150409/Courier0004.lzma
2025-05-27T15:14:28.733Z,1748358868.733 [DataOverHttps](INFO): Moved sent file to Logs/20250527T150409/Courier0004.lzma.bak
2025-05-27T15:14:28.733Z,1748358868.733 [DataOverHttps](INFO): SBD MOMSN=25007182
2025-05-27T15:14:44.391Z,1748358884.391 [DataOverHttps](INFO): Sending 187 bytes from file Logs/20250527T150409/Express0005.lzma
2025-05-27T15:14:45.393Z,1748358885.393 [DataOverHttps](INFO): Moved sent file to Logs/20250527T150409/Express0005.lzma.bak
2025-05-27T15:14:45.393Z,1748358885.393 [DataOverHttps](INFO): SBD MOMSN=25007184
2025-05-27T15:14:46.753Z,1748358886.753 [Default:CheckIn:Read_Iridium] Stopped
2025-05-27T15:14:46.753Z,1748358886.753 [Default:CheckIn:C.Wait] Running Loop=1
2025-05-27T15:14:46.753Z,1748358886.753 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-05-27T15:15:02.081Z,1748358902.081 [NAL9602](FAULT): GPS failed to acquire within timeout.
2025-05-27T15:15:02.081Z,1748358902.081 [NAL9602] Data Fault, FailCount= 1
2025-05-27T15:15:02.081Z,1748358902.081 [NAL9602](ERROR): Data Fault
2025-05-27T15:15:02.123Z,1748358902.123 [CBIT](ERROR): Data Fault in component: NAL9602
2025-05-27T15:15:02.484Z,1748358902.484 [NAL9602](INFO): Powering down
2025-05-27T15:15:03.317Z,1748358903.317 [CBIT](INFO): Clearing failed state for component NAL9602
2025-05-27T15:15:03.317Z,1748358903.317 [NAL9602] No Fault, FailCount= 1
2025-05-27T15:15:32.800Z,1748358932.800 [NAL9602](INFO): Powering up NAL9602
2025-05-27T15:15:43.705Z,1748358943.705 [NAL9602](INFO): NAL9602 initialized
2025-05-27T15:16:23.315Z,1748358983.315 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2025-05-27T15:16:23.315Z,1748358983.315 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-05-27T15:16:23.334Z,1748358983.334 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-05-27T15:16:23.733Z,1748358983.733 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-05-27T15:16:23.733Z,1748358983.733 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2025-05-27T15:19:24.324Z,1748359164.324 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2025-05-27T15:19:24.324Z,1748359164.324 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-05-27T15:19:24.338Z,1748359164.338 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-05-27T15:19:24.745Z,1748359164.745 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-05-27T15:19:24.745Z,1748359164.745 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2025-05-27T15:19:47.328Z,1748359187.328 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-05-27T15:19:47.329Z,1748359187.329 [Default:CheckIn:C.Wait] Stopped
2025-05-27T15:19:47.329Z,1748359187.329 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-05-27T15:19:47.329Z,1748359187.329 [Default:CheckIn:D] Running Loop=1
2025-05-27T15:19:47.753Z,1748359187.753 [Default:CheckIn:D] Stopped
2025-05-27T15:19:47.753Z,1748359187.753 [Default:CheckIn:E] Running Loop=1
2025-05-27T15:19:48.157Z,1748359188.157 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.672693 min
2025-05-27T15:19:48.157Z,1748359188.157 [Default:CheckIn:E] Stopped
2025-05-27T15:19:48.158Z,1748359188.158 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-05-27T15:19:48.158Z,1748359188.158 [Default:CheckIn] Stopped
2025-05-27T15:19:48.158Z,1748359188.158 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-05-27T15:19:48.158Z,1748359188.158 [Default:CheckIn](INFO): Running loop #2
2025-05-27T15:19:48.158Z,1748359188.158 [Default:CheckIn] Running Loop=2
2025-05-27T15:19:48.158Z,1748359188.158 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-05-27T15:19:48.158Z,1748359188.158 [Default:CheckIn:Read_GPS] Running Loop=1
2025-05-27T15:22:25.357Z,1748359345.357 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6
2025-05-27T15:22:25.357Z,1748359345.357 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-05-27T15:22:25.376Z,1748359345.376 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-05-27T15:22:25.778Z,1748359345.778 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-05-27T15:22:25.778Z,1748359345.778 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6
2025-05-27T15:24:48.381Z,1748359488.381 [Default:CheckIn:Read_GPS](INFO): Timed out from 2025-05-27T15:19:48.2Z
2025-05-27T15:24:48.381Z,1748359488.381 [Default:CheckIn:Read_GPS] Stopped
2025-05-27T15:24:48.381Z,1748359488.381 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-05-27T15:24:55.358Z,1748359495.358 [DataOverHttps](INFO): Sending 38 bytes from file Logs/20250527T150409/Courier0007.lzma
2025-05-27T15:24:56.361Z,1748359496.361 [DataOverHttps](INFO): Moved sent file to Logs/20250527T150409/Courier0007.lzma.bak
2025-05-27T15:24:56.361Z,1748359496.361 [DataOverHttps](INFO): SBD MOMSN=25007259
2025-05-27T15:25:11.915Z,1748359511.915 [DataOverHttps](INFO): Sending 182 bytes from file Logs/20250527T150409/Express0008.lzma
2025-05-27T15:25:12.917Z,1748359512.917 [DataOverHttps](INFO): Moved sent file to Logs/20250527T150409/Express0008.lzma.bak
2025-05-27T15:25:12.917Z,1748359512.917 [DataOverHttps](INFO): SBD MOMSN=25007261
2025-05-27T15:25:14.221Z,1748359514.221 [Default:CheckIn:Read_Iridium] Stopped
2025-05-27T15:25:14.221Z,1748359514.221 [Default:CheckIn:C.Wait] Running Loop=1
2025-05-27T15:25:14.221Z,1748359514.221 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-05-27T15:25:26.338Z,1748359526.338 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7
2025-05-27T15:25:26.339Z,1748359526.339 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-05-27T15:25:26.349Z,1748359526.349 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-05-27T15:25:26.761Z,1748359526.761 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-05-27T15:25:26.761Z,1748359526.761 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7
2025-05-27T15:25:45.717Z,1748359545.717 [NAL9602](FAULT): GPS failed to acquire within timeout.
2025-05-27T15:25:45.717Z,1748359545.717 [NAL9602] Data Fault, FailCount= 2
2025-05-27T15:25:45.717Z,1748359545.717 [NAL9602](ERROR): Data Fault
2025-05-27T15:25:45.734Z,1748359545.734 [CBIT](ERROR): Data Fault in component: NAL9602
2025-05-27T15:25:46.120Z,1748359546.120 [NAL9602](INFO): Powering down
2025-05-27T15:25:46.984Z,1748359546.984 [CBIT](INFO): Clearing failed state for component NAL9602
2025-05-27T15:25:46.984Z,1748359546.984 [NAL9602] No Fault, FailCount= 2
2025-05-27T15:26:16.420Z,1748359576.420 [NAL9602](INFO): Powering up NAL9602
2025-05-27T15:26:27.329Z,1748359587.329 [NAL9602](INFO): NAL9602 initialized
2025-05-27T15:28:27.344Z,1748359707.344 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8
2025-05-27T15:28:27.344Z,1748359707.344 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-05-27T15:28:27.355Z,1748359707.355 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-05-27T15:28:27.755Z,1748359707.755 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-05-27T15:28:27.755Z,1748359707.755 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8
2025-05-27T15:30:14.789Z,1748359814.789 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-05-27T15:30:14.789Z,1748359814.789 [Default:CheckIn:C.Wait] Stopped
2025-05-27T15:30:14.789Z,1748359814.789 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-05-27T15:30:14.789Z,1748359814.789 [Default:CheckIn:D] Running Loop=1
2025-05-27T15:30:15.200Z,1748359815.200 [Default:CheckIn:D] Stopped
2025-05-27T15:30:15.200Z,1748359815.200 [Default:CheckIn:E] Running Loop=1
2025-05-27T15:30:15.597Z,1748359815.597 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 21.130143 min
2025-05-27T15:30:15.598Z,1748359815.598 [Default:CheckIn:E] Stopped
2025-05-27T15:30:15.598Z,1748359815.598 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-05-27T15:30:15.598Z,1748359815.598 [Default:CheckIn] Stopped
2025-05-27T15:30:15.598Z,1748359815.598 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-05-27T15:30:15.598Z,1748359815.598 [Default:CheckIn](INFO): Running loop #3
2025-05-27T15:30:15.598Z,1748359815.598 [Default:CheckIn] Running Loop=3
2025-05-27T15:30:15.598Z,1748359815.598 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-05-27T15:30:15.598Z,1748359815.598 [Default:CheckIn:Read_GPS] Running Loop=1
2025-05-27T15:31:28.389Z,1748359888.389 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 9
2025-05-27T15:31:28.389Z,1748359888.389 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-05-27T15:31:28.422Z,1748359888.422 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-05-27T15:31:28.789Z,1748359888.789 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-05-27T15:31:28.789Z,1748359888.789 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 9
2025-05-27T15:32:48.984Z,1748359968.984 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-05-27T15:34:29.400Z,1748360069.400 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 10
2025-05-27T15:34:29.400Z,1748360069.400 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-05-27T15:34:29.432Z,1748360069.432 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-05-27T15:34:29.797Z,1748360069.797 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-05-27T15:34:29.798Z,1748360069.798 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 10
2025-05-27T15:35:15.849Z,1748360115.849 [Default:CheckIn:Read_GPS](INFO): Timed out from 2025-05-27T15:30:15.6Z
2025-05-27T15:35:15.849Z,1748360115.849 [Default:CheckIn:Read_GPS] Stopped
2025-05-27T15:35:15.849Z,1748360115.849 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-05-27T15:35:22.670Z,1748360122.670 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250527T150409/Courier0010.lzma
2025-05-27T15:35:23.673Z,1748360123.673 [DataOverHttps](INFO): Moved sent file to Logs/20250527T150409/Courier0010.lzma.bak
2025-05-27T15:35:23.673Z,1748360123.673 [DataOverHttps](INFO): SBD MOMSN=25007347
2025-05-27T15:35:39.211Z,1748360139.211 [DataOverHttps](INFO): Sending 152 bytes from file Logs/20250527T150409/Express0011.lzma
2025-05-27T15:35:40.213Z,1748360140.213 [DataOverHttps](INFO): Moved sent file to Logs/20250527T150409/Express0011.lzma.bak
2025-05-27T15:35:40.213Z,1748360140.213 [DataOverHttps](INFO): SBD MOMSN=25007349
2025-05-27T15:35:41.298Z,1748360141.298 [Default:CheckIn:Read_Iridium] Stopped
2025-05-27T15:35:41.298Z,1748360141.298 [Default:CheckIn:C.Wait] Running Loop=1
2025-05-27T15:35:41.298Z,1748360141.298 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-05-27T15:36:30.577Z,1748360190.577 [NAL9602](FAULT): GPS failed to acquire within timeout.
2025-05-27T15:36:30.577Z,1748360190.577 [NAL9602] Data Fault, FailCount= 3
2025-05-27T15:36:30.577Z,1748360190.577 [NAL9602](ERROR): Data Fault
2025-05-27T15:36:30.628Z,1748360190.628 [CBIT](ERROR): Data Fault in component: NAL9602
2025-05-27T15:36:30.981Z,1748360190.981 [NAL9602](INFO): Powering down
2025-05-27T15:36:31.814Z,1748360191.814 [CBIT](INFO): Clearing failed state for component NAL9602
2025-05-27T15:36:31.814Z,1748360191.814 [NAL9602] No Fault, FailCount= 3
2025-05-27T15:37:01.297Z,1748360221.297 [NAL9602](INFO): Powering up NAL9602
2025-05-27T15:37:12.205Z,1748360232.205 [NAL9602](INFO): NAL9602 initialized
2025-05-27T15:37:30.408Z,1748360250.408 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 11
2025-05-27T15:37:30.408Z,1748360250.408 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-05-27T15:37:30.443Z,1748360250.443 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-05-27T15:37:30.821Z,1748360250.821 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-05-27T15:37:30.821Z,1748360250.821 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 11
2025-05-27T15:39:34.036Z,1748360374.036 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,153932.00,A,3648.16582,N,12147.28391,W,0.156,0.00,270525,,,A*77
2025-05-27T15:39:34.040Z,1748360374.040 [NAL9602](INFO): GPS fix at 20250527T153932: (36.802764, -121.788065)
2025-05-27T15:40:06.360Z,1748360406.360 [NAL9602](INFO): Not Powering down - fast GPS
2025-05-27T15:40:41.928Z,1748360441.928 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-05-27T15:40:41.928Z,1748360441.928 [Default:CheckIn:C.Wait] Stopped
2025-05-27T15:40:41.928Z,1748360441.928 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-05-27T15:40:41.928Z,1748360441.928 [Default:CheckIn:D] Running Loop=1
2025-05-27T15:40:42.321Z,1748360442.321 [Default:CheckIn:D] Stopped
2025-05-27T15:40:42.321Z,1748360442.321 [Default:CheckIn:E] Running Loop=1
2025-05-27T15:40:42.728Z,1748360442.728 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 31.582153 min
2025-05-27T15:40:42.728Z,1748360442.728 [Default:CheckIn:E] Stopped
2025-05-27T15:40:42.728Z,1748360442.728 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-05-27T15:40:42.728Z,1748360442.728 [Default:CheckIn] Stopped
2025-05-27T15:40:42.728Z,1748360442.728 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-05-27T15:40:42.728Z,1748360442.728 [Default:CheckIn](INFO): Running loop #4
2025-05-27T15:40:42.728Z,1748360442.728 [Default:CheckIn] Running Loop=4
2025-05-27T15:40:42.728Z,1748360442.728 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-05-27T15:40:42.728Z,1748360442.728 [Default:CheckIn:Read_GPS] Running Loop=1
2025-05-27T15:40:44.736Z,1748360444.736 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,154043.00,A,3648.16722,N,12147.28222,W,0.525,0.00,270525,,,A*7E
2025-05-27T15:40:44.738Z,1748360444.738 [NAL9602](INFO): GPS fix at 20250527T154043: (36.802787, -121.788037)
2025-05-27T15:40:44.750Z,1748360444.750 [Default:CheckIn:Read_GPS] Stopped
2025-05-27T15:40:44.750Z,1748360444.750 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-05-27T15:40:54.623Z,1748360454.623 [DataOverHttps](INFO): Sending 222 bytes from file Logs/20250527T150409/Courier0013.lzma
2025-05-27T15:40:55.625Z,1748360455.625 [DataOverHttps](INFO): Moved sent file to Logs/20250527T150409/Courier0013.lzma.bak
2025-05-27T15:40:55.625Z,1748360455.625 [DataOverHttps](INFO): SBD MOMSN=25007372
2025-05-27T15:41:11.640Z,1748360471.640 [DataOverHttps](INFO): Sending 407 bytes from file Logs/20250527T150409/Express0014.lzma
2025-05-27T15:41:12.641Z,1748360472.641 [DataOverHttps](INFO): Moved sent file to Logs/20250527T150409/Express0014.lzma.bak
2025-05-27T15:41:12.641Z,1748360472.641 [DataOverHttps](INFO): SBD MOMSN=25007375
2025-05-27T15:41:13.928Z,1748360473.928 [Default:CheckIn:Read_Iridium] Stopped
2025-05-27T15:41:13.928Z,1748360473.928 [Default:CheckIn:C.Wait] Running Loop=1
2025-05-27T15:41:13.928Z,1748360473.928 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-05-27T15:44:33.971Z,1748360673.971 [NAL9602](INFO): SBD MO Status=2, MOMSN=24665, MT Status=2, MTMSN=0
2025-05-27T15:44:33.972Z,1748360673.972 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-05-27T15:44:55.458Z,1748360695.458 [NAL9602](INFO): SBD MO Status=2, MOMSN=24665, MT Status=2, MTMSN=0
2025-05-27T15:44:55.458Z,1748360695.458 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-05-27T15:45:05.134Z,1748360705.134 [NAL9602](INFO): SBD MO Status=0, MOMSN=24665, MT Status=0, MTMSN=0
2025-05-27T15:45:05.134Z,1748360705.134 [NAL9602](INFO): No messages in MT queue
2025-05-27T15:45:35.844Z,1748360735.844 [NAL9602](INFO): Not Powering down - fast GPS
2025-05-27T15:46:14.640Z,1748360774.640 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-05-27T15:46:14.640Z,1748360774.640 [Default:CheckIn:C.Wait] Stopped
2025-05-27T15:46:14.640Z,1748360774.640 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-05-27T15:46:14.640Z,1748360774.640 [Default:CheckIn:D] Running Loop=1
2025-05-27T15:46:15.035Z,1748360775.035 [Default:CheckIn:D] Stopped
2025-05-27T15:46:15.035Z,1748360775.035 [Default:CheckIn:E] Running Loop=1
2025-05-27T15:46:15.448Z,1748360775.448 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 37.127393 min
2025-05-27T15:46:15.448Z,1748360775.448 [Default:CheckIn:E] Stopped
2025-05-27T15:46:15.448Z,1748360775.448 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-05-27T15:46:15.448Z,1748360775.448 [Default:CheckIn] Stopped
2025-05-27T15:46:15.448Z,1748360775.448 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-05-27T15:46:15.448Z,1748360775.448 [Default:CheckIn](INFO): Running loop #5
2025-05-27T15:46:15.448Z,1748360775.448 [Default:CheckIn] Running Loop=5
2025-05-27T15:46:15.448Z,1748360775.448 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-05-27T15:46:15.449Z,1748360775.449 [Default:CheckIn:Read_GPS] Running Loop=1
2025-05-27T15:46:17.455Z,1748360777.455 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,154616.00,A,3648.17467,N,12147.28104,W,0.019,0.00,270525,,,A*76
2025-05-27T15:46:17.457Z,1748360777.457 [NAL9602](INFO): GPS fix at 20250527T154616: (36.802911, -121.788017)
2025-05-27T15:46:17.468Z,1748360777.468 [Default:CheckIn:Read_GPS] Stopped
2025-05-27T15:46:17.469Z,1748360777.469 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-05-27T15:46:24.470Z,1748360784.470 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20250527T150409/Courier0016.lzma
2025-05-27T15:46:25.473Z,1748360785.473 [DataOverHttps](INFO): Moved sent file to Logs/20250527T150409/Courier0016.lzma.bak
2025-05-27T15:46:25.473Z,1748360785.473 [DataOverHttps](INFO): SBD MOMSN=25007438
2025-05-27T15:46:41.291Z,1748360801.291 [DataOverHttps](INFO): Sending 152 bytes from file Logs/20250527T150409/Express0017.lzma
2025-05-27T15:46:42.293Z,1748360802.293 [DataOverHttps](INFO): Moved sent file to Logs/20250527T150409/Express0017.lzma.bak
2025-05-27T15:46:42.293Z,1748360802.293 [DataOverHttps](INFO): SBD MOMSN=25007441
2025-05-27T15:46:43.327Z,1748360803.327 [Default:CheckIn:Read_Iridium] Stopped
2025-05-27T15:46:43.328Z,1748360803.328 [Default:CheckIn:C.Wait] Running Loop=1
2025-05-27T15:46:43.328Z,1748360803.328 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-05-27T15:46:54.630Z,1748360814.630 [NAL9602](INFO): SBD MO Status=2, MOMSN=24666, MT Status=2, MTMSN=0
2025-05-27T15:46:54.630Z,1748360814.630 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-05-27T15:47:31.798Z,1748360851.798 [NAL9602](INFO): SBD MO Status=0, MOMSN=24666, MT Status=0, MTMSN=0
2025-05-27T15:47:31.798Z,1748360851.798 [NAL9602](INFO): No messages in MT queue
2025-05-27T15:48:02.512Z,1748360882.512 [NAL9602](INFO): Not Powering down - fast GPS
2025-05-27T15:51:44.012Z,1748361104.012 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-05-27T15:51:44.012Z,1748361104.012 [Default:CheckIn:C.Wait] Stopped
2025-05-27T15:51:44.012Z,1748361104.012 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-05-27T15:51:44.012Z,1748361104.012 [Default:CheckIn:D] Running Loop=1
2025-05-27T15:51:44.418Z,1748361104.418 [Default:CheckIn:D] Stopped
2025-05-27T15:51:44.418Z,1748361104.418 [Default:CheckIn:E] Running Loop=1
2025-05-27T15:51:44.828Z,1748361104.828 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 42.617098 min
2025-05-27T15:51:44.828Z,1748361104.828 [Default:CheckIn:E] Stopped
2025-05-27T15:51:44.828Z,1748361104.828 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-05-27T15:51:44.828Z,1748361104.828 [Default:CheckIn] Stopped
2025-05-27T15:51:44.828Z,1748361104.828 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-05-27T15:51:44.829Z,1748361104.829 [Default:CheckIn](INFO): Running loop #6
2025-05-27T15:51:44.829Z,1748361104.829 [Default:CheckIn] Running Loop=6
2025-05-27T15:51:44.829Z,1748361104.829 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-05-27T15:51:44.829Z,1748361104.829 [Default:CheckIn:Read_GPS] Running Loop=1
2025-05-27T15:51:46.838Z,1748361106.838 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155146.00,A,3648.14209,N,12147.24357,W,0.058,107.83,270525,,,D*7D
2025-05-27T15:51:46.840Z,1748361106.840 [NAL9602](INFO): GPS fix at 20250527T155146: (36.802368, -121.787393)
2025-05-27T15:51:46.870Z,1748361106.870 [Default:CheckIn:Read_GPS] Stopped
2025-05-27T15:51:46.871Z,1748361106.871 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-05-27T15:51:54.511Z,1748361114.511 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250527T150409/Courier0019.lzma
2025-05-27T15:51:55.513Z,1748361115.513 [DataOverHttps](INFO): Moved sent file to Logs/20250527T150409/Courier0019.lzma.bak
2025-05-27T15:51:55.513Z,1748361115.513 [DataOverHttps](INFO): SBD MOMSN=25007463
2025-05-27T15:52:04.206Z,1748361124.206 [NAL9602](INFO): SBD MO Status=0, MOMSN=24667, MT Status=0, MTMSN=0
2025-05-27T15:52:04.206Z,1748361124.206 [NAL9602](INFO): No messages in MT queue
2025-05-27T15:52:11.431Z,1748361131.431 [DataOverHttps](INFO): Sending 154 bytes from file Logs/20250527T150409/Express0020.lzma
2025-05-27T15:52:12.433Z,1748361132.433 [DataOverHttps](INFO): Moved sent file to Logs/20250527T150409/Express0020.lzma.bak
2025-05-27T15:52:12.433Z,1748361132.433 [DataOverHttps](INFO): SBD MOMSN=25007466
2025-05-27T15:52:13.504Z,1748361133.504 [Default:CheckIn:Read_Iridium] Stopped
2025-05-27T15:52:13.504Z,1748361133.504 [Default:CheckIn:C.Wait] Running Loop=1
2025-05-27T15:52:13.504Z,1748361133.504 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-05-27T15:52:34.905Z,1748361154.905 [NAL9602](INFO): Not Powering down - fast GPS
2025-05-27T15:53:52.196Z,1748361232.196 [DataOverHttps](IMPORTANT): SBD MTMSN=20250527T155351
2025-05-27T15:53:59.615Z,1748361239.615 [DataOverHttps](INFO): Received command: ibit
2025-05-27T15:53:59.700Z,1748361239.700 [CommandExec](IMPORTANT): got command ibit
2025-05-27T15:53:59.810Z,1748361239.810 [IBIT](IMPORTANT): Beginning Initiated BIT
2025-05-27T15:53:59.810Z,1748361239.810 [IBIT](IMPORTANT): Beginning control surface checks.
2025-05-27T15:53:59.813Z,1748361239.813 [GFScanner](IMPORTANT): Beginning ground fault scan
2025-05-27T15:54:00.616Z,1748361240.616 [DataOverHttps](IMPORTANT): SBD MTMSN=20250527T155359
2025-05-27T15:54:01.409Z,1748361241.409 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155400.00,A,3648.14571,N,12147.22931,W,0.039,24.33,270525,,,D*42
2025-05-27T15:54:01.411Z,1748361241.411 [NAL9602](INFO): GPS fix at 20250527T155400: (36.802428, -121.787155)
2025-05-27T15:54:04.439Z,1748361244.439 [GFScanner](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): -0.000198
CHAN A1 (24V): -0.183090
CHAN A2 (12V): 0.000542
CHAN A3 (5V): -0.001186
CHAN B0 (3.3V): 0.000685
CHAN B1 (3.15aV): -0.000566
CHAN B2 (3.15bV): -0.000266
CHAN B3 (GND): 0.000223
OPEN: 0.006410
Full Scale: +/- 1 mA
2025-05-27T15:54:08.375Z,1748361248.375 [DataOverHttps](INFO): Received command: failc
2025-05-27T15:54:08.440Z,1748361248.440 [CommandExec](IMPORTANT): got command failComponent
2025-05-27T15:54:08.440Z,1748361248.440 [CommandExec](IMPORTANT): Failed components:
2025-05-27T15:54:08.440Z,1748361248.440 [CommandExec](IMPORTANT): No failed Components.
2025-05-27T15:54:15.546Z,1748361255.546 [NAL9602](INFO): SBD MO Status=0, MOMSN=24668, MT Status=0, MTMSN=0
2025-05-27T15:54:15.547Z,1748361255.547 [NAL9602](INFO): No messages in MT queue
2025-05-27T15:54:16.759Z,1748361256.759 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155416.00,A,3648.14541,N,12147.22856,W,0.039,24.33,270525,,,D*46
2025-05-27T15:54:16.761Z,1748361256.761 [NAL9602](INFO): GPS fix at 20250527T155416: (36.802424, -121.787143)
2025-05-27T15:54:19.990Z,1748361259.990 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155419.00,A,3648.14533,N,12147.22844,W,0.039,24.33,270525,,,D*4F
2025-05-27T15:54:19.993Z,1748361259.993 [NAL9602](INFO): GPS fix at 20250527T155419: (36.802422, -121.787141)
2025-05-27T15:54:22.822Z,1748361262.822 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155422.00,A,3648.14533,N,12147.22840,W,0.039,24.33,270525,,,D*43
2025-05-27T15:54:22.824Z,1748361262.824 [NAL9602](INFO): GPS fix at 20250527T155422: (36.802422, -121.787140)
2025-05-27T15:54:26.052Z,1748361266.052 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155425.00,A,3648.14539,N,12147.22847,W,0.058,24.33,270525,,,D*4E
2025-05-27T15:54:26.054Z,1748361266.055 [NAL9602](INFO): GPS fix at 20250527T155425: (36.802423, -121.787141)
2025-05-27T15:54:28.880Z,1748361268.880 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155428.00,A,3648.14543,N,12147.22854,W,0.078,24.33,270525,,,D*4E
2025-05-27T15:54:28.882Z,1748361268.882 [NAL9602](INFO): GPS fix at 20250527T155428: (36.802424, -121.787142)
2025-05-27T15:54:32.111Z,1748361272.111 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155431.00,A,3648.14549,N,12147.22858,W,0.058,24.33,270525,,,D*42
2025-05-27T15:54:32.113Z,1748361272.113 [NAL9602](INFO): GPS fix at 20250527T155431: (36.802425, -121.787143)
2025-05-27T15:54:34.948Z,1748361274.948 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155434.00,A,3648.14555,N,12147.22862,W,0.019,24.33,270525,,,D*46
2025-05-27T15:54:34.950Z,1748361274.950 [NAL9602](INFO): GPS fix at 20250527T155434: (36.802426, -121.787144)
2025-05-27T15:54:38.171Z,1748361278.171 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155437.00,A,3648.14560,N,12147.22860,W,0.000,24.33,270525,,,D*49
2025-05-27T15:54:38.173Z,1748361278.173 [NAL9602](INFO): GPS fix at 20250527T155437: (36.802427, -121.787143)
2025-05-27T15:54:41.001Z,1748361281.001 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155440.00,A,3648.14558,N,12147.22841,W,0.019,24.33,270525,,,D*49
2025-05-27T15:54:41.003Z,1748361281.003 [NAL9602](INFO): GPS fix at 20250527T155440: (36.802426, -121.787140)
2025-05-27T15:54:43.826Z,1748361283.826 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155443.00,A,3648.14553,N,12147.22811,W,0.058,24.33,270525,,,D*41
2025-05-27T15:54:43.828Z,1748361283.828 [NAL9602](INFO): GPS fix at 20250527T155443: (36.802425, -121.787135)
2025-05-27T15:54:45.878Z,1748361285.878 [IBIT](IMPORTANT): Communications Status:
Fix Status: 1
Iridium Signal Strength: 5
Latitude: 36.802425 Longitude: -121.787132
2025-05-27T15:54:46.288Z,1748361286.288 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 0.000000
Voltage: 16.650999
2025-05-27T15:54:46.288Z,1748361286.288 [IBIT](IMPORTANT): batteryCapacityThreshold: -0.500000 Ah
2025-05-27T15:54:46.288Z,1748361286.288 [IBIT](IMPORTANT): batteryVoltageThreshold: 10.000000 V
2025-05-27T15:54:46.702Z,1748361286.702 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2025-05-27T15:54:46.702Z,1748361286.702 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2025-05-27T15:54:46.702Z,1748361286.702 [IBIT](IMPORTANT): Pressure:10.060363 PSI
2025-05-27T15:54:46.711Z,1748361286.711 [IBIT](IMPORTANT): Humidity:23.464779 %
2025-05-27T15:54:47.096Z,1748361287.096 [IBIT](IMPORTANT): Vehicle Pitch:-1.127531 degrees
2025-05-27T15:54:47.097Z,1748361287.097 [IBIT](IMPORTANT): Vehicle Roll:-3.120092 degrees
2025-05-27T15:54:47.097Z,1748361287.097 [IBIT](IMPORTANT): Vehicle Heading:3.897770 degrees
2025-05-27T15:54:47.504Z,1748361287.504 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2025-05-27T15:54:47.504Z,1748361287.504 [IBIT](IMPORTANT): buoyancyNeutral: 162.296539 cc
2025-05-27T15:54:47.505Z,1748361287.505 [IBIT](IMPORTANT): massDefault: 2.316222 cm
2025-05-27T15:54:47.505Z,1748361287.505 [IBIT](IMPORTANT): stopDepth: 275.000000 m
2025-05-27T15:54:47.505Z,1748361287.505 [IBIT](IMPORTANT): abortDepth: 300.000000 m
2025-05-27T15:54:47.505Z,1748361287.505 [IBIT](IMPORTANT): IBIT PASSED
2025-05-27T15:55:16.549Z,1748361316.549 [NAL9602](INFO): Not Powering down - fast GPS
2025-05-27T15:57:14.127Z,1748361434.127 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-05-27T15:57:14.127Z,1748361434.127 [Default:CheckIn:C.Wait] Stopped
2025-05-27T15:57:14.127Z,1748361434.127 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-05-27T15:57:14.127Z,1748361434.127 [Default:CheckIn:D] Running Loop=1
2025-05-27T15:57:14.528Z,1748361434.528 [Default:CheckIn:D] Stopped
2025-05-27T15:57:14.528Z,1748361434.528 [Default:CheckIn:E] Running Loop=1
2025-05-27T15:57:14.940Z,1748361434.940 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 48.118937 min
2025-05-27T15:57:14.940Z,1748361434.940 [Default:CheckIn:E] Stopped
2025-05-27T15:57:14.940Z,1748361434.940 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-05-27T15:57:14.941Z,1748361434.941 [Default:CheckIn] Stopped
2025-05-27T15:57:14.941Z,1748361434.941 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-05-27T15:57:14.941Z,1748361434.941 [Default:CheckIn](INFO): Running loop #7
2025-05-27T15:57:14.941Z,1748361434.941 [Default:CheckIn] Running Loop=7
2025-05-27T15:57:14.941Z,1748361434.941 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-05-27T15:57:14.941Z,1748361434.941 [Default:CheckIn:Read_GPS] Running Loop=1
2025-05-27T15:57:16.942Z,1748361436.942 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155716.00,A,3648.14473,N,12147.22742,W,0.039,24.33,270525,,,D*4F
2025-05-27T15:57:16.944Z,1748361436.944 [NAL9602](INFO): GPS fix at 20250527T155716: (36.802412, -121.787124)
2025-05-27T15:57:16.979Z,1748361436.979 [Default:CheckIn:Read_GPS] Stopped
2025-05-27T15:57:16.979Z,1748361436.979 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-05-27T15:57:24.462Z,1748361444.462 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250527T150409/Courier0022.lzma
2025-05-27T15:57:25.465Z,1748361445.465 [DataOverHttps](INFO): Moved sent file to Logs/20250527T150409/Courier0022.lzma.bak
2025-05-27T15:57:25.465Z,1748361445.465 [DataOverHttps](INFO): SBD MOMSN=25007528
2025-05-27T15:57:26.235Z,1748361446.235 [NAL9602](INFO): SBD MO Status=0, MOMSN=24669, MT Status=0, MTMSN=0
2025-05-27T15:57:26.235Z,1748361446.235 [NAL9602](INFO): No messages in MT queue
2025-05-27T15:57:41.226Z,1748361461.226 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250527T150409/Courier0025.lzma
2025-05-27T15:57:42.229Z,1748361462.229 [DataOverHttps](INFO): Moved sent file to Logs/20250527T150409/Courier0025.lzma.bak
2025-05-27T15:57:42.229Z,1748361462.229 [DataOverHttps](INFO): SBD MOMSN=25007531
2025-05-27T15:57:56.936Z,1748361476.936 [NAL9602](INFO): Not Powering down - fast GPS
2025-05-27T15:57:58.101Z,1748361478.101 [DataOverHttps](INFO): Sending 1055 bytes from file Logs/20250527T150409/Express0023.lzma
2025-05-27T15:57:59.101Z,1748361479.101 [DataOverHttps](INFO): Moved sent file to Logs/20250527T150409/Express0023.lzma.bak
2025-05-27T15:57:59.101Z,1748361479.101 [DataOverHttps](INFO): SBD MOMSN=25007534
2025-05-27T15:58:15.094Z,1748361495.094 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250527T150409/Express0026.lzma
2025-05-27T15:58:16.098Z,1748361496.098 [DataOverHttps](INFO): Moved sent file to Logs/20250527T150409/Express0026.lzma.bak
2025-05-27T15:58:16.098Z,1748361496.098 [DataOverHttps](INFO): SBD MOMSN=25007576
2025-05-27T15:58:17.158Z,1748361497.158 [Default:CheckIn:Read_Iridium] Stopped
2025-05-27T15:58:17.158Z,1748361497.158 [Default:CheckIn:C.Wait] Running Loop=1
2025-05-27T15:58:17.159Z,1748361497.159 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-05-27T16:03:17.888Z,1748361797.888 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-05-27T16:03:17.888Z,1748361797.888 [Default:CheckIn:C.Wait] Stopped
2025-05-27T16:03:17.889Z,1748361797.889 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-05-27T16:03:17.889Z,1748361797.889 [Default:CheckIn:D] Running Loop=1
2025-05-27T16:03:18.276Z,1748361798.276 [Default:CheckIn:D] Stopped
2025-05-27T16:03:18.276Z,1748361798.276 [Default:CheckIn:E] Running Loop=1
2025-05-27T16:03:18.675Z,1748361798.675 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 54.181401 min
2025-05-27T16:03:18.675Z,1748361798.675 [Default:CheckIn:E] Stopped
2025-05-27T16:03:18.675Z,1748361798.675 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-05-27T16:03:18.675Z,1748361798.675 [Default:CheckIn] Stopped
2025-05-27T16:03:18.675Z,1748361798.675 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-05-27T16:03:18.676Z,1748361798.676 [Default:CheckIn](INFO): Running loop #8
2025-05-27T16:03:18.676Z,1748361798.676 [Default:CheckIn] Running Loop=8
2025-05-27T16:03:18.676Z,1748361798.676 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-05-27T16:03:18.676Z,1748361798.676 [Default:CheckIn:Read_GPS] Running Loop=1
2025-05-27T16:03:20.688Z,1748361800.688 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160319.00,A,3648.14622,N,12147.22622,W,0.039,24.33,270525,,,D*43
2025-05-27T16:03:20.690Z,1748361800.690 [NAL9602](INFO): GPS fix at 20250527T160319: (36.802437, -121.787104)
2025-05-27T16:03:20.702Z,1748361800.702 [Default:CheckIn:Read_GPS] Stopped
2025-05-27T16:03:20.702Z,1748361800.702 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-05-27T16:03:28.038Z,1748361808.038 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250527T150409/Courier0028.lzma
2025-05-27T16:03:29.041Z,1748361809.041 [DataOverHttps](INFO): Moved sent file to Logs/20250527T150409/Courier0028.lzma.bak
2025-05-27T16:03:29.041Z,1748361809.041 [DataOverHttps](INFO): SBD MOMSN=25007597
2025-05-27T16:03:34.018Z,1748361814.018 [NAL9602](INFO): SBD MO Status=0, MOMSN=24670, MT Status=0, MTMSN=0
2025-05-27T16:03:34.018Z,1748361814.018 [NAL9602](INFO): No messages in MT queue
2025-05-27T16:03:44.911Z,1748361824.911 [DataOverHttps](INFO): Sending 153 bytes from file Logs/20250527T150409/Express0029.lzma
2025-05-27T16:03:45.913Z,1748361825.913 [DataOverHttps](INFO): Moved sent file to Logs/20250527T150409/Express0029.lzma.bak
2025-05-27T16:03:45.913Z,1748361825.913 [DataOverHttps](INFO): SBD MOMSN=25007607
2025-05-27T16:03:46.959Z,1748361826.959 [Default:CheckIn:Read_Iridium] Stopped
2025-05-27T16:03:46.959Z,1748361826.959 [Default:CheckIn:C.Wait] Running Loop=1
2025-05-27T16:03:46.959Z,1748361826.959 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-05-27T16:04:04.727Z,1748361844.727 [NAL9602](INFO): Not Powering down - fast GPS
2025-05-27T16:08:47.654Z,1748362127.654 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-05-27T16:08:47.654Z,1748362127.654 [Default:CheckIn:C.Wait] Stopped
2025-05-27T16:08:47.655Z,1748362127.655 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-05-27T16:08:47.655Z,1748362127.655 [Default:CheckIn:D] Running Loop=1
2025-05-27T16:08:48.053Z,1748362128.053 [Default:CheckIn:D] Stopped
2025-05-27T16:08:48.053Z,1748362128.053 [Default:CheckIn:E] Running Loop=1
2025-05-27T16:08:48.477Z,1748362128.477 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 59.677698 min
2025-05-27T16:08:48.477Z,1748362128.477 [Default:CheckIn:E] Stopped
2025-05-27T16:08:48.477Z,1748362128.477 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-05-27T16:08:48.477Z,1748362128.477 [Default:CheckIn] Stopped
2025-05-27T16:08:48.477Z,1748362128.477 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-05-27T16:08:48.478Z,1748362128.478 [Default:CheckIn](INFO): Running loop #9
2025-05-27T16:08:48.478Z,1748362128.478 [Default:CheckIn] Running Loop=9
2025-05-27T16:08:48.478Z,1748362128.478 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-05-27T16:08:48.478Z,1748362128.478 [Default:CheckIn:Read_GPS] Running Loop=1
2025-05-27T16:08:50.472Z,1748362130.472 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160849.00,A,3648.14494,N,12147.22685,W,0.019,24.33,270525,,,D*4D
2025-05-27T16:08:50.474Z,1748362130.474 [NAL9602](INFO): GPS fix at 20250527T160849: (36.802416, -121.787114)
2025-05-27T16:08:50.485Z,1748362130.485 [Default:CheckIn:Read_GPS] Stopped
2025-05-27T16:08:50.485Z,1748362130.485 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-05-27T16:09:00.066Z,1748362140.066 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20250527T150409/Courier0031.lzma
2025-05-27T16:09:01.069Z,1748362141.069 [DataOverHttps](INFO): Moved sent file to Logs/20250527T150409/Courier0031.lzma.bak
2025-05-27T16:09:01.069Z,1748362141.069 [DataOverHttps](INFO): SBD MOMSN=25007663
2025-05-27T16:09:08.420Z,1748362148.420 [NAL9602](INFO): SBD MO Status=0, MOMSN=24671, MT Status=0, MTMSN=0
2025-05-27T16:09:08.420Z,1748362148.420 [NAL9602](INFO): No messages in MT queue
2025-05-27T16:09:16.851Z,1748362156.851 [DataOverHttps](INFO): Sending 153 bytes from file Logs/20250527T150409/Express0032.lzma
2025-05-27T16:09:17.853Z,1748362157.853 [DataOverHttps](INFO): Moved sent file to Logs/20250527T150409/Express0032.lzma.bak
2025-05-27T16:09:17.853Z,1748362157.853 [DataOverHttps](INFO): SBD MOMSN=25007670
2025-05-27T16:09:18.944Z,1748362158.944 [Default:CheckIn:Read_Iridium] Stopped
2025-05-27T16:09:18.944Z,1748362158.944 [Default:CheckIn:C.Wait] Running Loop=1
2025-05-27T16:09:18.944Z,1748362158.944 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-05-27T16:09:39.106Z,1748362179.106 [NAL9602](INFO): Not Powering down - fast GPS
2025-05-27T16:14:19.574Z,1748362459.574 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-05-27T16:14:19.574Z,1748362459.574 [Default:CheckIn:C.Wait] Stopped
2025-05-27T16:14:19.574Z,1748362459.574 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-05-27T16:14:19.574Z,1748362459.574 [Default:CheckIn:D] Running Loop=1
2025-05-27T16:14:19.964Z,1748362459.964 [Default:CheckIn:D] Stopped
2025-05-27T16:14:19.964Z,1748362459.964 [Default:CheckIn:E] Running Loop=1
2025-05-27T16:14:20.359Z,1748362460.359 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 65.209534 min
2025-05-27T16:14:20.359Z,1748362460.359 [Default:CheckIn:E] Stopped
2025-05-27T16:14:20.360Z,1748362460.360 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-05-27T16:14:20.360Z,1748362460.360 [Default:CheckIn] Stopped
2025-05-27T16:14:20.360Z,1748362460.360 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-05-27T16:14:20.360Z,1748362460.360 [Default:CheckIn](INFO): Running loop #10
2025-05-27T16:14:20.360Z,1748362460.360 [Default:CheckIn] Running Loop=10
2025-05-27T16:14:20.360Z,1748362460.360 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-05-27T16:14:20.360Z,1748362460.360 [Default:CheckIn:Read_GPS] Running Loop=1
2025-05-27T16:14:22.372Z,1748362462.372 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,161421.00,A,3648.14516,N,12147.22619,W,0.078,24.33,270525,,,D*47
2025-05-27T16:14:22.374Z,1748362462.374 [NAL9602](INFO): GPS fix at 20250527T161421: (36.802419, -121.787103)
2025-05-27T16:14:22.385Z,1748362462.385 [Default:CheckIn:Read_GPS] Stopped
2025-05-27T16:14:22.385Z,1748362462.385 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-05-27T16:14:25.198Z,1748362465.198 [Sonardyne_Nano](INFO): Battery at maximum, disabling charging
2025-05-27T16:14:29.398Z,1748362469.398 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20250527T150409/Courier0034.lzma
2025-05-27T16:14:30.401Z,1748362470.401 [DataOverHttps](INFO): Moved sent file to Logs/20250527T150409/Courier0034.lzma.bak
2025-05-27T16:14:30.401Z,1748362470.401 [DataOverHttps](INFO): SBD MOMSN=25007735
2025-05-27T16:14:36.114Z,1748362476.114 [NAL9602](INFO): SBD MO Status=0, MOMSN=24672, MT Status=0, MTMSN=0
2025-05-27T16:14:36.115Z,1748362476.115 [NAL9602](INFO): No messages in MT queue
2025-05-27T16:14:46.267Z,1748362486.267 [DataOverHttps](INFO): Sending 154 bytes from file Logs/20250527T150409/Express0035.lzma
2025-05-27T16:14:47.269Z,1748362487.269 [DataOverHttps](INFO): Moved sent file to Logs/20250527T150409/Express0035.lzma.bak
2025-05-27T16:14:47.269Z,1748362487.269 [DataOverHttps](INFO): SBD MOMSN=25007738
2025-05-27T16:14:48.649Z,1748362488.649 [Default:CheckIn:Read_Iridium] Stopped
2025-05-27T16:14:48.649Z,1748362488.649 [Default:CheckIn:C.Wait] Running Loop=1
2025-05-27T16:14:48.649Z,1748362488.649 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-05-27T16:15:06.910Z,1748362506.910 [NAL9602](INFO): Not Powering down - fast GPS
2025-05-27T16:15:43.615Z,1748362543.615 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-05-27T16:15:56.948Z,1748362556.948 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-05-27T16:16:10.683Z,1748362570.683 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-05-27T16:16:24.822Z,1748362584.822 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-05-27T16:16:38.583Z,1748362598.583 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-05-27T16:16:51.891Z,1748362611.891 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-05-27T16:17:05.655Z,1748362625.655 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-05-27T16:17:19.791Z,1748362639.791 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-05-27T16:17:33.125Z,1748362653.125 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-05-27T16:17:46.859Z,1748362666.859 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-05-27T16:18:00.598Z,1748362680.598 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-05-27T16:19:49.304Z,1748362789.304 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-05-27T16:19:49.304Z,1748362789.304 [Default:CheckIn:C.Wait] Stopped
2025-05-27T16:19:49.304Z,1748362789.304 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-05-27T16:19:49.304Z,1748362789.304 [Default:CheckIn:D] Running Loop=1
2025-05-27T16:19:49.702Z,1748362789.702 [Default:CheckIn:D] Stopped
2025-05-27T16:19:49.702Z,1748362789.702 [Default:CheckIn:E] Running Loop=1
2025-05-27T16:19:50.100Z,1748362790.100 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 70.705176 min
2025-05-27T16:19:50.100Z,1748362790.100 [Default:CheckIn:E] Stopped
2025-05-27T16:19:50.101Z,1748362790.101 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-05-27T16:19:50.101Z,1748362790.101 [Default:CheckIn] Stopped
2025-05-27T16:19:50.101Z,1748362790.101 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-05-27T16:19:50.101Z,1748362790.101 [Default:CheckIn](INFO): Running loop #11
2025-05-27T16:19:50.101Z,1748362790.101 [Default:CheckIn] Running Loop=11
2025-05-27T16:19:50.101Z,1748362790.101 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-05-27T16:19:50.101Z,1748362790.101 [Default:CheckIn:Read_GPS] Running Loop=1
2025-05-27T16:19:52.111Z,1748362792.111 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,161951.00,A,3648.14513,N,12147.22652,W,0.097,24.33,270525,,,D*46
2025-05-27T16:19:52.120Z,1748362792.120 [NAL9602](INFO): GPS fix at 20250527T161951: (36.802419, -121.787109)
2025-05-27T16:19:52.131Z,1748362792.131 [Default:CheckIn:Read_GPS] Stopped
2025-05-27T16:19:52.131Z,1748362792.131 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-05-27T16:19:59.318Z,1748362799.318 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250527T150409/Courier0037.lzma
2025-05-27T16:20:00.321Z,1748362800.321 [DataOverHttps](INFO): Moved sent file to Logs/20250527T150409/Courier0037.lzma.bak
2025-05-27T16:20:00.321Z,1748362800.321 [DataOverHttps](INFO): SBD MOMSN=25007757
2025-05-27T16:20:16.387Z,1748362816.387 [DataOverHttps](INFO): Sending 155 bytes from file Logs/20250527T150409/Express0038.lzma
2025-05-27T16:20:17.389Z,1748362817.389 [DataOverHttps](INFO): Moved sent file to Logs/20250527T150409/Express0038.lzma.bak
2025-05-27T16:20:17.389Z,1748362817.389 [DataOverHttps](INFO): SBD MOMSN=25007760
2025-05-27T16:20:18.800Z,1748362818.800 [Default:CheckIn:Read_Iridium] Stopped
2025-05-27T16:20:18.800Z,1748362818.800 [Default:CheckIn:C.Wait] Running Loop=1
2025-05-27T16:20:18.800Z,1748362818.800 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-05-27T16:20:22.093Z,1748362822.093 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2025-05-27T16:20:23.222Z,1748362823.222 [NAL9602](INFO): SBD MO Status=2, MOMSN=24673, MT Status=2, MTMSN=0
2025-05-27T16:20:23.222Z,1748362823.222 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-05-27T16:20:28.873Z,1748362828.873 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-05-27T16:20:43.819Z,1748362843.819 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-05-27T16:20:44.246Z,1748362844.246 [NAL9602](INFO): SBD MO Status=0, MOMSN=24673, MT Status=0, MTMSN=0
2025-05-27T16:20:44.247Z,1748362844.247 [NAL9602](INFO): No messages in MT queue
2025-05-27T16:20:59.214Z,1748362859.214 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-05-27T16:21:14.165Z,1748362874.165 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-05-27T16:21:14.972Z,1748362874.972 [NAL9602](INFO): Not Powering down - fast GPS
2025-05-27T16:21:30.335Z,1748362890.335 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-05-27T16:21:45.713Z,1748362905.713 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-05-27T16:22:00.751Z,1748362920.751 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-05-27T16:22:15.611Z,1748362935.611 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-05-27T16:22:30.579Z,1748362950.579 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-05-27T16:24:39.252Z,1748363079.252 [BPC1](ERROR): Battery stick #29 (s/n: 00A7) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4AD0.
2025-05-27T16:24:39.252Z,1748363079.252 [BPC1](ERROR): Battery stick #51 (s/n: 01D6) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0.
2025-05-27T16:24:39.253Z,1748363079.253 [BPC1](ERROR): Battery stick #57 (s/n: 019F) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0.
2025-05-27T16:24:39.254Z,1748363079.254 [BPC1](ERROR): Battery stick #59 (s/n: 0184) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0.
2025-05-27T16:24:39.254Z,1748363079.254 [BPC1](INFO): Calculating totals. Valid battery stick count: 41. Valid reserve battery stick count: 6.
2025-05-27T16:24:39.257Z,1748363079.257 [BPC1](INFO): Received data from all battery sticks.
2025-05-27T16:25:19.283Z,1748363119.283 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-05-27T16:25:19.283Z,1748363119.283 [Default:CheckIn:C.Wait] Stopped
2025-05-27T16:25:19.283Z,1748363119.283 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-05-27T16:25:19.284Z,1748363119.284 [Default:CheckIn:D] Running Loop=1
2025-05-27T16:25:19.656Z,1748363119.656 [Default:CheckIn:D] Stopped
2025-05-27T16:25:19.656Z,1748363119.656 [Default:CheckIn:E] Running Loop=1
2025-05-27T16:25:20.068Z,1748363120.068 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 76.204411 min
2025-05-27T16:25:20.068Z,1748363120.068 [Default:CheckIn:E] Stopped
2025-05-27T16:25:20.068Z,1748363120.068 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-05-27T16:25:20.068Z,1748363120.068 [Default:CheckIn] Stopped
2025-05-27T16:25:20.068Z,1748363120.068 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-05-27T16:25:20.068Z,1748363120.068 [Default:CheckIn](INFO): Running loop #12
2025-05-27T16:25:20.069Z,1748363120.069 [Default:CheckIn] Running Loop=12
2025-05-27T16:25:20.069Z,1748363120.069 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-05-27T16:25:20.069Z,1748363120.069 [Default:CheckIn:Read_GPS] Running Loop=1
2025-05-27T16:25:22.070Z,1748363122.070 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162521.00,A,3648.14584,N,12147.22950,W,0.019,24.33,270525,,,D*4B
2025-05-27T16:25:22.072Z,1748363122.072 [NAL9602](INFO): GPS fix at 20250527T162521: (36.802431, -121.787158)
2025-05-27T16:25:22.096Z,1748363122.096 [Default:CheckIn:Read_GPS] Stopped
2025-05-27T16:25:22.096Z,1748363122.096 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-05-27T16:25:28.875Z,1748363128.875 [DataOverHttps](INFO): Sending 85 bytes from file Logs/20250527T150409/Courier0040.lzma
2025-05-27T16:25:29.877Z,1748363129.877 [DataOverHttps](INFO): Moved sent file to Logs/20250527T150409/Courier0040.lzma.bak
2025-05-27T16:25:29.877Z,1748363129.877 [DataOverHttps](INFO): SBD MOMSN=25007826
2025-05-27T16:25:31.376Z,1748363131.376 [NAL9602](INFO): SBD MO Status=0, MOMSN=24674, MT Status=0, MTMSN=0
2025-05-27T16:25:31.376Z,1748363131.376 [NAL9602](INFO): No messages in MT queue
2025-05-27T16:25:45.782Z,1748363145.782 [DataOverHttps](INFO): Sending 154 bytes from file Logs/20250527T150409/Express0041.lzma
2025-05-27T16:25:46.781Z,1748363146.781 [DataOverHttps](INFO): Moved sent file to Logs/20250527T150409/Express0041.lzma.bak
2025-05-27T16:25:46.781Z,1748363146.781 [DataOverHttps](INFO): SBD MOMSN=25007829
2025-05-27T16:25:47.939Z,1748363147.939 [Default:CheckIn:Read_Iridium] Stopped
2025-05-27T16:25:47.939Z,1748363147.939 [Default:CheckIn:C.Wait] Running Loop=1
2025-05-27T16:25:47.939Z,1748363147.939 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-05-27T16:26:02.068Z,1748363162.068 [NAL9602](INFO): Not Powering down - fast GPS
2025-05-27T16:30:48.633Z,1748363448.633 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-05-27T16:30:48.633Z,1748363448.633 [Default:CheckIn:C.Wait] Stopped
2025-05-27T16:30:48.633Z,1748363448.633 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-05-27T16:30:48.633Z,1748363448.633 [Default:CheckIn:D] Running Loop=1
2025-05-27T16:30:49.032Z,1748363449.032 [Default:CheckIn:D] Stopped
2025-05-27T16:30:49.032Z,1748363449.032 [Default:CheckIn:E] Running Loop=1
2025-05-27T16:30:49.433Z,1748363449.433 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 81.694010 min
2025-05-27T16:30:49.433Z,1748363449.433 [Default:CheckIn:E] Stopped
2025-05-27T16:30:49.433Z,1748363449.433 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-05-27T16:30:49.433Z,1748363449.433 [Default:CheckIn] Stopped
2025-05-27T16:30:49.433Z,1748363449.433 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-05-27T16:30:49.434Z,1748363449.434 [Default:CheckIn](INFO): Running loop #13
2025-05-27T16:30:49.434Z,1748363449.434 [Default:CheckIn] Running Loop=13
2025-05-27T16:30:49.434Z,1748363449.434 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-05-27T16:30:49.434Z,1748363449.434 [Default:CheckIn:Read_GPS] Running Loop=1
2025-05-27T16:30:51.448Z,1748363451.448 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163050.00,A,3648.15223,N,12147.22589,W,0.019,93.41,270525,,,D*43
2025-05-27T16:30:51.450Z,1748363451.450 [NAL9602](INFO): GPS fix at 20250527T163050: (36.802537, -121.787098)
2025-05-27T16:30:51.461Z,1748363451.461 [Default:CheckIn:Read_GPS] Stopped
2025-05-27T16:30:51.461Z,1748363451.461 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-05-27T16:30:59.602Z,1748363459.602 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250527T150409/Courier0043.lzma
2025-05-27T16:31:00.605Z,1748363460.605 [DataOverHttps](INFO): Moved sent file to Logs/20250527T150409/Courier0043.lzma.bak
2025-05-27T16:31:00.605Z,1748363460.605 [DataOverHttps](INFO): SBD MOMSN=25007846
2025-05-27T16:31:05.981Z,1748363465.981 [NAL9602](INFO): SBD MO Status=0, MOMSN=24675, MT Status=0, MTMSN=0
2025-05-27T16:31:05.982Z,1748363465.982 [NAL9602](INFO): No messages in MT queue
2025-05-27T16:31:16.471Z,1748363476.471 [DataOverHttps](INFO): Sending 155 bytes from file Logs/20250527T150409/Express0044.lzma
2025-05-27T16:31:17.473Z,1748363477.473 [DataOverHttps](INFO): Moved sent file to Logs/20250527T150409/Express0044.lzma.bak
2025-05-27T16:31:17.473Z,1748363477.473 [DataOverHttps](INFO): SBD MOMSN=25007849
2025-05-27T16:31:18.519Z,1748363478.519 [Default:CheckIn:Read_Iridium] Stopped
2025-05-27T16:31:18.519Z,1748363478.519 [Default:CheckIn:C.Wait] Running Loop=1
2025-05-27T16:31:18.519Z,1748363478.519 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-05-27T16:31:36.681Z,1748363496.681 [NAL9602](INFO): Not Powering down - fast GPS
2025-05-27T16:36:19.120Z,1748363779.120 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-05-27T16:36:19.120Z,1748363779.120 [Default:CheckIn:C.Wait] Stopped
2025-05-27T16:36:19.121Z,1748363779.121 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-05-27T16:36:19.121Z,1748363779.121 [Default:CheckIn:D] Running Loop=1
2025-05-27T16:36:19.532Z,1748363779.532 [Default:CheckIn:D] Stopped
2025-05-27T16:36:19.532Z,1748363779.532 [Default:CheckIn:E] Running Loop=1
2025-05-27T16:36:19.948Z,1748363779.948 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 87.202336 min
2025-05-27T16:36:19.948Z,1748363779.948 [Default:CheckIn:E] Stopped
2025-05-27T16:36:19.948Z,1748363779.948 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-05-27T16:36:19.948Z,1748363779.948 [Default:CheckIn] Stopped
2025-05-27T16:36:19.948Z,1748363779.948 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-05-27T16:36:19.948Z,1748363779.948 [Default:CheckIn](INFO): Running loop #14
2025-05-27T16:36:19.948Z,1748363779.948 [Default:CheckIn] Running Loop=14
2025-05-27T16:36:19.948Z,1748363779.948 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-05-27T16:36:19.949Z,1748363779.949 [Default:CheckIn:Read_GPS] Running Loop=1
2025-05-27T16:36:21.942Z,1748363781.942 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163621.00,A,3648.14933,N,12147.22028,W,0.019,90.49,270525,,,D*4D
2025-05-27T16:36:21.945Z,1748363781.945 [NAL9602](INFO): GPS fix at 20250527T163621: (36.802489, -121.787005)
2025-05-27T16:36:21.956Z,1748363781.956 [Default:CheckIn:Read_GPS] Stopped
2025-05-27T16:36:21.956Z,1748363781.956 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-05-27T16:36:29.251Z,1748363789.251 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250527T150409/Courier0046.lzma
2025-05-27T16:36:30.253Z,1748363790.253 [DataOverHttps](INFO): Moved sent file to Logs/20250527T150409/Courier0046.lzma.bak
2025-05-27T16:36:30.253Z,1748363790.253 [DataOverHttps](INFO): SBD MOMSN=25007915
2025-05-27T16:36:38.922Z,1748363798.922 [NAL9602](INFO): SBD MO Status=0, MOMSN=24676, MT Status=0, MTMSN=0
2025-05-27T16:36:38.923Z,1748363798.923 [NAL9602](INFO): No messages in MT queue
2025-05-27T16:36:46.207Z,1748363806.207 [DataOverHttps](INFO): Sending 155 bytes from file Logs/20250527T150409/Express0047.lzma
2025-05-27T16:36:47.209Z,1748363807.209 [DataOverHttps](INFO): Moved sent file to Logs/20250527T150409/Express0047.lzma.bak
2025-05-27T16:36:47.209Z,1748363807.209 [DataOverHttps](INFO): SBD MOMSN=25007918
2025-05-27T16:36:48.262Z,1748363808.262 [Default:CheckIn:Read_Iridium] Stopped
2025-05-27T16:36:48.262Z,1748363808.262 [Default:CheckIn:C.Wait] Running Loop=1
2025-05-27T16:36:48.262Z,1748363808.262 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-05-27T16:37:09.692Z,1748363829.692 [NAL9602](INFO): Not Powering down - fast GPS
2025-05-27T16:41:48.919Z,1748364108.919 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-05-27T16:41:48.919Z,1748364108.919 [Default:CheckIn:C.Wait] Stopped
2025-05-27T16:41:48.920Z,1748364108.920 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-05-27T16:41:48.920Z,1748364108.920 [Default:CheckIn:D] Running Loop=1
2025-05-27T16:41:49.325Z,1748364109.325 [Default:CheckIn:D] Stopped
2025-05-27T16:41:49.325Z,1748364109.325 [Default:CheckIn:E] Running Loop=1
2025-05-27T16:41:49.740Z,1748364109.740 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 92.698893 min
2025-05-27T16:41:49.740Z,1748364109.740 [Default:CheckIn:E] Stopped
2025-05-27T16:41:49.740Z,1748364109.740 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-05-27T16:41:49.740Z,1748364109.740 [Default:CheckIn] Stopped
2025-05-27T16:41:49.740Z,1748364109.740 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-05-27T16:41:49.740Z,1748364109.740 [Default:CheckIn](INFO): Running loop #15
2025-05-27T16:41:49.740Z,1748364109.740 [Default:CheckIn] Running Loop=15
2025-05-27T16:41:49.741Z,1748364109.741 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-05-27T16:41:49.741Z,1748364109.741 [Default:CheckIn:Read_GPS] Running Loop=1
2025-05-27T16:41:51.742Z,1748364111.742 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164150.00,A,3648.14890,N,12147.22023,W,0.019,90.49,270525,,,D*48
2025-05-27T16:41:51.744Z,1748364111.744 [NAL9602](INFO): GPS fix at 20250527T164150: (36.802482, -121.787004)
2025-05-27T16:41:51.755Z,1748364111.755 [Default:CheckIn:Read_GPS] Stopped
2025-05-27T16:41:51.755Z,1748364111.755 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-05-27T16:41:59.139Z,1748364119.139 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250527T150409/Courier0049.lzma
2025-05-27T16:42:00.141Z,1748364120.141 [DataOverHttps](INFO): Moved sent file to Logs/20250527T150409/Courier0049.lzma.bak
2025-05-27T16:42:00.141Z,1748364120.141 [DataOverHttps](INFO): SBD MOMSN=25007934
2025-05-27T16:42:05.487Z,1748364125.487 [NAL9602](INFO): SBD MO Status=0, MOMSN=24677, MT Status=0, MTMSN=0
2025-05-27T16:42:05.487Z,1748364125.487 [NAL9602](INFO): No messages in MT queue
2025-05-27T16:42:15.983Z,1748364135.983 [DataOverHttps](INFO): Sending 153 bytes from file Logs/20250527T150409/Express0050.lzma
2025-05-27T16:42:16.985Z,1748364136.985 [DataOverHttps](INFO): Moved sent file to Logs/20250527T150409/Express0050.lzma.bak
2025-05-27T16:42:16.985Z,1748364136.985 [DataOverHttps](INFO): SBD MOMSN=25007937
2025-05-27T16:42:18.030Z,1748364138.030 [Default:CheckIn:Read_Iridium] Stopped
2025-05-27T16:42:18.030Z,1748364138.030 [Default:CheckIn:C.Wait] Running Loop=1
2025-05-27T16:42:18.030Z,1748364138.030 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-05-27T16:42:36.188Z,1748364156.188 [NAL9602](INFO): Not Powering down - fast GPS
2025-05-27T16:47:18.668Z,1748364438.668 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-05-27T16:47:18.668Z,1748364438.668 [Default:CheckIn:C.Wait] Stopped
2025-05-27T16:47:18.668Z,1748364438.668 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-05-27T16:47:18.669Z,1748364438.669 [Default:CheckIn:D] Running Loop=1
2025-05-27T16:47:19.078Z,1748364439.078 [Default:CheckIn:D] Stopped
2025-05-27T16:47:19.078Z,1748364439.078 [Default:CheckIn:E] Running Loop=1
2025-05-27T16:47:19.467Z,1748364439.467 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 98.194775 min
2025-05-27T16:47:19.467Z,1748364439.467 [Default:CheckIn:E] Stopped
2025-05-27T16:47:19.467Z,1748364439.467 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-05-27T16:47:19.468Z,1748364439.468 [Default:CheckIn] Stopped
2025-05-27T16:47:19.468Z,1748364439.468 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-05-27T16:47:19.468Z,1748364439.468 [Default:CheckIn](INFO): Running loop #16
2025-05-27T16:47:19.468Z,1748364439.468 [Default:CheckIn] Running Loop=16
2025-05-27T16:47:19.468Z,1748364439.468 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-05-27T16:47:19.468Z,1748364439.468 [Default:CheckIn:Read_GPS] Running Loop=1
2025-05-27T16:47:21.482Z,1748364441.482 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164720.00,A,3648.14940,N,12147.21986,W,0.019,90.49,270525,,,D*40
2025-05-27T16:47:21.484Z,1748364441.484 [NAL9602](INFO): GPS fix at 20250527T164720: (36.802490, -121.786998)
2025-05-27T16:47:21.495Z,1748364441.495 [Default:CheckIn:Read_GPS] Stopped
2025-05-27T16:47:21.495Z,1748364441.495 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-05-27T16:47:28.694Z,1748364448.694 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20250527T150409/Courier0052.lzma
2025-05-27T16:47:29.697Z,1748364449.697 [DataOverHttps](INFO): Moved sent file to Logs/20250527T150409/Courier0052.lzma.bak
2025-05-27T16:47:29.698Z,1748364449.698 [DataOverHttps](INFO): SBD MOMSN=25008000
2025-05-27T16:47:45.655Z,1748364465.655 [DataOverHttps](INFO): Sending 154 bytes from file Logs/20250527T150409/Express0053.lzma
2025-05-27T16:47:46.657Z,1748364466.657 [DataOverHttps](INFO): Moved sent file to Logs/20250527T150409/Express0053.lzma.bak
2025-05-27T16:47:46.658Z,1748364466.658 [DataOverHttps](INFO): SBD MOMSN=25008003
2025-05-27T16:47:47.751Z,1748364467.751 [Default:CheckIn:Read_Iridium] Stopped
2025-05-27T16:47:47.751Z,1748364467.751 [Default:CheckIn:C.Wait] Running Loop=1
2025-05-27T16:47:47.751Z,1748364467.751 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-05-27T16:47:52.998Z,1748364472.998 [NAL9602](INFO): SBD MO Status=2, MOMSN=24678, MT Status=2, MTMSN=0
2025-05-27T16:47:52.999Z,1748364472.999 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-05-27T16:48:22.486Z,1748364502.486 [NAL9602](INFO): SBD MO Status=2, MOMSN=24678, MT Status=2, MTMSN=0
2025-05-27T16:48:22.486Z,1748364502.486 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-05-27T16:48:33.398Z,1748364513.398 [NAL9602](INFO): SBD MO Status=0, MOMSN=24678, MT Status=0, MTMSN=0
2025-05-27T16:48:33.398Z,1748364513.398 [NAL9602](INFO): No messages in MT queue
2025-05-27T16:49:04.141Z,1748364544.141 [NAL9602](INFO): Not Powering down - fast GPS
2025-05-27T16:52:48.396Z,1748364768.396 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-05-27T16:52:48.396Z,1748364768.396 [Default:CheckIn:C.Wait] Stopped
2025-05-27T16:52:48.396Z,1748364768.396 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-05-27T16:52:48.396Z,1748364768.396 [Default:CheckIn:D] Running Loop=1
2025-05-27T16:52:48.802Z,1748364768.802 [Default:CheckIn:D] Stopped
2025-05-27T16:52:48.802Z,1748364768.802 [Default:CheckIn:E] Running Loop=1
2025-05-27T16:52:49.209Z,1748364769.209 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 103.690169 min
2025-05-27T16:52:49.209Z,1748364769.209 [Default:CheckIn:E] Stopped
2025-05-27T16:52:49.209Z,1748364769.209 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-05-27T16:52:49.209Z,1748364769.209 [Default:CheckIn] Stopped
2025-05-27T16:52:49.209Z,1748364769.209 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-05-27T16:52:49.209Z,1748364769.209 [Default:CheckIn](INFO): Running loop #17
2025-05-27T16:52:49.209Z,1748364769.209 [Default:CheckIn] Running Loop=17
2025-05-27T16:52:49.209Z,1748364769.209 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-05-27T16:52:49.210Z,1748364769.210 [Default:CheckIn:Read_GPS] Running Loop=1
2025-05-27T16:52:51.210Z,1748364771.210 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165250.00,A,3648.15074,N,12147.22053,W,0.019,90.49,270525,,,D*4E
2025-05-27T16:52:51.220Z,1748364771.220 [NAL9602](INFO): GPS fix at 20250527T165250: (36.802512, -121.787009)
2025-05-27T16:52:51.267Z,1748364771.267 [Default:CheckIn:Read_GPS] Stopped
2025-05-27T16:52:51.268Z,1748364771.268 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-05-27T16:52:59.782Z,1748364779.782 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250527T150409/Courier0055.lzma
2025-05-27T16:53:00.642Z,1748364780.642 [NAL9602](INFO): SBD MO Status=0, MOMSN=24679, MT Status=0, MTMSN=0
2025-05-27T16:53:00.642Z,1748364780.642 [NAL9602](INFO): No messages in MT queue
2025-05-27T16:53:00.785Z,1748364780.785 [DataOverHttps](INFO): Moved sent file to Logs/20250527T150409/Courier0055.lzma.bak
2025-05-27T16:53:00.785Z,1748364780.785 [DataOverHttps](INFO): SBD MOMSN=25008019
2025-05-27T16:53:16.731Z,1748364796.731 [DataOverHttps](INFO): Sending 157 bytes from file Logs/20250527T150409/Express0056.lzma
2025-05-27T16:53:17.733Z,1748364797.733 [DataOverHttps](INFO): Moved sent file to Logs/20250527T150409/Express0056.lzma.bak
2025-05-27T16:53:17.733Z,1748364797.733 [DataOverHttps](INFO): SBD MOMSN=25008025
2025-05-27T16:53:18.824Z,1748364798.824 [Default:CheckIn:Read_Iridium] Stopped
2025-05-27T16:53:18.824Z,1748364798.824 [Default:CheckIn:C.Wait] Running Loop=1
2025-05-27T16:53:18.825Z,1748364798.825 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-05-27T16:53:31.337Z,1748364811.337 [NAL9602](INFO): Not Powering down - fast GPS
2025-05-27T16:58:19.463Z,1748365099.463 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-05-27T16:58:19.463Z,1748365099.463 [Default:CheckIn:C.Wait] Stopped
2025-05-27T16:58:19.463Z,1748365099.463 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-05-27T16:58:19.463Z,1748365099.463 [Default:CheckIn:D] Running Loop=1
2025-05-27T16:58:19.870Z,1748365099.870 [Default:CheckIn:D] Stopped
2025-05-27T16:58:19.870Z,1748365099.870 [Default:CheckIn:E] Running Loop=1
2025-05-27T16:58:20.291Z,1748365100.291 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 109.207975 min
2025-05-27T16:58:20.291Z,1748365100.291 [Default:CheckIn:E] Stopped
2025-05-27T16:58:20.291Z,1748365100.291 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-05-27T16:58:20.291Z,1748365100.291 [Default:CheckIn] Stopped
2025-05-27T16:58:20.291Z,1748365100.291 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-05-27T16:58:20.291Z,1748365100.291 [Default:CheckIn](INFO): Running loop #18
2025-05-27T16:58:20.292Z,1748365100.292 [Default:CheckIn] Running Loop=18
2025-05-27T16:58:20.292Z,1748365100.292 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-05-27T16:58:20.292Z,1748365100.292 [Default:CheckIn:Read_GPS] Running Loop=1
2025-05-27T16:58:22.279Z,1748365102.279 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165821.00,A,3648.14981,N,12147.22068,W,0.058,90.49,270525,,,D*4D
2025-05-27T16:58:22.281Z,1748365102.281 [NAL9602](INFO): GPS fix at 20250527T165821: (36.802497, -121.787011)
2025-05-27T16:58:22.292Z,1748365102.292 [Default:CheckIn:Read_GPS] Stopped
2025-05-27T16:58:22.293Z,1748365102.293 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-05-27T16:58:29.515Z,1748365109.515 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250527T150409/Courier0058.lzma
2025-05-27T16:58:30.518Z,1748365110.518 [DataOverHttps](INFO): Moved sent file to Logs/20250527T150409/Courier0058.lzma.bak
2025-05-27T16:58:30.518Z,1748365110.518 [DataOverHttps](INFO): SBD MOMSN=25008088
2025-05-27T16:58:46.487Z,1748365126.487 [DataOverHttps](INFO): Sending 154 bytes from file Logs/20250527T150409/Express0059.lzma
2025-05-27T16:58:47.489Z,1748365127.489 [DataOverHttps](INFO): Moved sent file to Logs/20250527T150409/Express0059.lzma.bak
2025-05-27T16:58:47.489Z,1748365127.489 [DataOverHttps](INFO): SBD MOMSN=25008094
2025-05-27T16:58:48.570Z,1748365128.570 [Default:CheckIn:Read_Iridium] Stopped
2025-05-27T16:58:48.570Z,1748365128.570 [Default:CheckIn:C.Wait] Running Loop=1
2025-05-27T16:58:48.570Z,1748365128.570 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-05-27T16:58:57.077Z,1748365137.077 [NAL9602](INFO): SBD MO Status=0, MOMSN=24680, MT Status=0, MTMSN=0
2025-05-27T16:58:57.078Z,1748365137.078 [NAL9602](INFO): No messages in MT queue
2025-05-27T16:59:27.784Z,1748365167.784 [NAL9602](INFO): Not Powering down - fast GPS
2025-05-27T17:03:49.242Z,1748365429.242 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-05-27T17:03:49.242Z,1748365429.242 [Default:CheckIn:C.Wait] Stopped
2025-05-27T17:03:49.243Z,1748365429.243 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-05-27T17:03:49.243Z,1748365429.243 [Default:CheckIn:D] Running Loop=1
2025-05-27T17:03:49.654Z,1748365429.654 [Default:CheckIn:D] Stopped
2025-05-27T17:03:49.654Z,1748365429.654 [Default:CheckIn:E] Running Loop=1
2025-05-27T17:03:50.055Z,1748365430.055 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 114.704378 min
2025-05-27T17:03:50.055Z,1748365430.055 [Default:CheckIn:E] Stopped
2025-05-27T17:03:50.055Z,1748365430.055 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-05-27T17:03:50.055Z,1748365430.055 [Default:CheckIn] Stopped
2025-05-27T17:03:50.055Z,1748365430.055 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-05-27T17:03:50.056Z,1748365430.056 [Default:CheckIn](INFO): Running loop #19
2025-05-27T17:03:50.056Z,1748365430.056 [Default:CheckIn] Running Loop=19
2025-05-27T17:03:50.056Z,1748365430.056 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-05-27T17:03:50.056Z,1748365430.056 [Default:CheckIn:Read_GPS] Running Loop=1
2025-05-27T17:03:52.069Z,1748365432.069 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170351.00,A,3648.14996,N,12147.22019,W,0.039,90.49,270525,,,D*42
2025-05-27T17:03:52.072Z,1748365432.072 [NAL9602](INFO): GPS fix at 20250527T170351: (36.802499, -121.787003)
2025-05-27T17:03:52.083Z,1748365432.083 [Default:CheckIn:Read_GPS] Stopped
2025-05-27T17:03:52.083Z,1748365432.083 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-05-27T17:03:59.798Z,1748365439.798 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250527T150409/Courier0061.lzma
2025-05-27T17:04:00.801Z,1748365440.801 [DataOverHttps](INFO): Moved sent file to Logs/20250527T150409/Courier0061.lzma.bak
2025-05-27T17:04:00.801Z,1748365440.801 [DataOverHttps](INFO): SBD MOMSN=25008112
2025-05-27T17:04:07.014Z,1748365447.014 [NAL9602](INFO): SBD MO Status=0, MOMSN=24681, MT Status=0, MTMSN=0
2025-05-27T17:04:07.014Z,1748365447.014 [NAL9602](INFO): No messages in MT queue
2025-05-27T17:04:16.651Z,1748365456.651 [DataOverHttps](INFO): Sending 156 bytes from file Logs/20250527T150409/Express0062.lzma
2025-05-27T17:04:17.653Z,1748365457.653 [DataOverHttps](INFO): Moved sent file to Logs/20250527T150409/Express0062.lzma.bak
2025-05-27T17:04:17.653Z,1748365457.653 [DataOverHttps](INFO): SBD MOMSN=25008115
2025-05-27T17:04:18.742Z,1748365458.742 [Default:CheckIn:Read_Iridium] Stopped
2025-05-27T17:04:18.742Z,1748365458.742 [Default:CheckIn:C.Wait] Running Loop=1
2025-05-27T17:04:18.742Z,1748365458.742 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-05-27T17:04:37.713Z,1748365477.713 [NAL9602](INFO): Not Powering down - fast GPS
2025-05-27T17:09:19.375Z,1748365759.375 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-05-27T17:09:19.376Z,1748365759.376 [Default:CheckIn:C.Wait] Stopped
2025-05-27T17:09:19.376Z,1748365759.376 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-05-27T17:09:19.376Z,1748365759.376 [Default:CheckIn:D] Running Loop=1
2025-05-27T17:09:19.785Z,1748365759.785 [Default:CheckIn:D] Stopped
2025-05-27T17:09:19.785Z,1748365759.785 [Default:CheckIn:E] Running Loop=1
2025-05-27T17:09:20.182Z,1748365760.182 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 120.206559 min
2025-05-27T17:09:20.182Z,1748365760.182 [Default:CheckIn:E] Stopped
2025-05-27T17:09:20.182Z,1748365760.182 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-05-27T17:09:20.182Z,1748365760.182 [Default:CheckIn] Stopped
2025-05-27T17:09:20.182Z,1748365760.182 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-05-27T17:09:20.183Z,1748365760.183 [Default:CheckIn](INFO): Running loop #20
2025-05-27T17:09:20.199Z,1748365760.199 [Default:CheckIn] Running Loop=20
2025-05-27T17:09:20.199Z,1748365760.199 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-05-27T17:09:20.199Z,1748365760.199 [Default:CheckIn:Read_GPS] Running Loop=1
2025-05-27T17:09:22.198Z,1748365762.198 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170921.00,A,3648.15031,N,12147.22100,W,0.019,90.49,270525,,,D*41
2025-05-27T17:09:22.200Z,1748365762.200 [NAL9602](INFO): GPS fix at 20250527T170921: (36.802505, -121.787017)
2025-05-27T17:09:22.211Z,1748365762.211 [Default:CheckIn:Read_GPS] Stopped
2025-05-27T17:09:22.211Z,1748365762.211 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-05-27T17:09:29.762Z,1748365769.762 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20250527T150409/Courier0064.lzma
2025-05-27T17:09:30.765Z,1748365770.765 [DataOverHttps](INFO): Moved sent file to Logs/20250527T150409/Courier0064.lzma.bak
2025-05-27T17:09:30.765Z,1748365770.765 [DataOverHttps](INFO): SBD MOMSN=25008183
2025-05-27T17:09:41.989Z,1748365781.989 [NAL9602](INFO): SBD MO Status=0, MOMSN=24682, MT Status=0, MTMSN=0
2025-05-27T17:09:41.990Z,1748365781.990 [NAL9602](INFO): No messages in MT queue
2025-05-27T17:09:46.735Z,1748365786.735 [DataOverHttps](INFO): Sending 156 bytes from file Logs/20250527T150409/Express0065.lzma
2025-05-27T17:09:47.737Z,1748365787.737 [DataOverHttps](INFO): Moved sent file to Logs/20250527T150409/Express0065.lzma.bak
2025-05-27T17:09:47.737Z,1748365787.737 [DataOverHttps](INFO): SBD MOMSN=25008186
2025-05-27T17:09:48.870Z,1748365788.870 [Default:CheckIn:Read_Iridium] Stopped
2025-05-27T17:09:48.870Z,1748365788.870 [Default:CheckIn:C.Wait] Running Loop=1
2025-05-27T17:09:48.870Z,1748365788.870 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-05-27T17:10:12.696Z,1748365812.696 [NAL9602](INFO): Not Powering down - fast GPS
2025-05-27T17:14:49.499Z,1748366089.499 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-05-27T17:14:49.500Z,1748366089.500 [Default:CheckIn:C.Wait] Stopped
2025-05-27T17:14:49.500Z,1748366089.500 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-05-27T17:14:49.500Z,1748366089.500 [Default:CheckIn:D] Running Loop=1
2025-05-27T17:14:49.908Z,1748366089.908 [Default:CheckIn:D] Stopped
2025-05-27T17:14:49.908Z,1748366089.908 [Default:CheckIn:E] Running Loop=1
2025-05-27T17:14:50.304Z,1748366090.304 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 125.708602 min
2025-05-27T17:14:50.304Z,1748366090.304 [Default:CheckIn:E] Stopped
2025-05-27T17:14:50.305Z,1748366090.305 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-05-27T17:14:50.305Z,1748366090.305 [Default:CheckIn] Stopped
2025-05-27T17:14:50.305Z,1748366090.305 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-05-27T17:14:50.305Z,1748366090.305 [Default:CheckIn](INFO): Running loop #21
2025-05-27T17:14:50.305Z,1748366090.305 [Default:CheckIn] Running Loop=21
2025-05-27T17:14:50.305Z,1748366090.305 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-05-27T17:14:50.305Z,1748366090.305 [Default:CheckIn:Read_GPS] Running Loop=1
2025-05-27T17:14:52.320Z,1748366092.320 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171451.00,A,3648.16475,N,12147.20276,W,1.536,57.05,270525,,,D*47
2025-05-27T17:14:52.322Z,1748366092.322 [NAL9602](INFO): GPS fix at 20250527T171451: (36.802746, -121.786713)
2025-05-27T17:14:52.333Z,1748366092.333 [Default:CheckIn:Read_GPS] Stopped
2025-05-27T17:14:52.333Z,1748366092.333 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-05-27T17:15:00.323Z,1748366100.323 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250527T150409/Courier0067.lzma
2025-05-27T17:15:01.325Z,1748366101.325 [DataOverHttps](INFO): Moved sent file to Logs/20250527T150409/Courier0067.lzma.bak
2025-05-27T17:15:01.325Z,1748366101.325 [DataOverHttps](INFO): SBD MOMSN=25008205
2025-05-27T17:15:12.918Z,1748366112.918 [NAL9602](INFO): SBD MO Status=0, MOMSN=24683, MT Status=0, MTMSN=0
2025-05-27T17:15:12.918Z,1748366112.918 [NAL9602](INFO): No messages in MT queue
2025-05-27T17:15:17.263Z,1748366117.263 [DataOverHttps](INFO): Sending 155 bytes from file Logs/20250527T150409/Express0068.lzma
2025-05-27T17:15:18.265Z,1748366118.265 [DataOverHttps](INFO): Moved sent file to Logs/20250527T150409/Express0068.lzma.bak
2025-05-27T17:15:18.265Z,1748366118.265 [DataOverHttps](INFO): SBD MOMSN=25008209
2025-05-27T17:15:19.402Z,1748366119.402 [Default:CheckIn:Read_Iridium] Stopped
2025-05-27T17:15:19.402Z,1748366119.402 [Default:CheckIn:C.Wait] Running Loop=1
2025-05-27T17:15:19.402Z,1748366119.402 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-05-27T17:15:43.612Z,1748366143.612 [NAL9602](INFO): Not Powering down - fast GPS
2025-05-27T17:20:20.057Z,1748366420.057 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-05-27T17:20:20.057Z,1748366420.057 [Default:CheckIn:C.Wait] Stopped
2025-05-27T17:20:20.058Z,1748366420.058 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-05-27T17:20:20.058Z,1748366420.058 [Default:CheckIn:D] Running Loop=1
2025-05-27T17:20:20.458Z,1748366420.458 [Default:CheckIn:D] Stopped
2025-05-27T17:20:20.458Z,1748366420.458 [Default:CheckIn:E] Running Loop=1
2025-05-27T17:20:20.859Z,1748366420.859 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 131.217782 min
2025-05-27T17:20:20.859Z,1748366420.859 [Default:CheckIn:E] Stopped
2025-05-27T17:20:20.859Z,1748366420.859 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-05-27T17:20:20.859Z,1748366420.859 [Default:CheckIn] Stopped
2025-05-27T17:20:20.859Z,1748366420.859 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-05-27T17:20:20.859Z,1748366420.859 [Default:CheckIn](INFO): Running loop #22
2025-05-27T17:20:20.860Z,1748366420.860 [Default:CheckIn] Running Loop=22
2025-05-27T17:20:20.860Z,1748366420.860 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-05-27T17:20:20.860Z,1748366420.860 [Default:CheckIn:Read_GPS] Running Loop=1
2025-05-27T17:20:22.869Z,1748366422.869 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172022.00,A,3648.40363,N,12147.11507,W,3.246,354.41,270525,,,D*76
2025-05-27T17:20:22.871Z,1748366422.871 [NAL9602](INFO): GPS fix at 20250527T172022: (36.806727, -121.785251)
2025-05-27T17:20:22.882Z,1748366422.882 [Default:CheckIn:Read_GPS] Stopped
2025-05-27T17:20:22.882Z,1748366422.882 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-05-27T17:20:30.314Z,1748366430.314 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250527T150409/Courier0070.lzma
2025-05-27T17:20:31.317Z,1748366431.317 [DataOverHttps](INFO): Moved sent file to Logs/20250527T150409/Courier0070.lzma.bak
2025-05-27T17:20:31.317Z,1748366431.317 [DataOverHttps](INFO): SBD MOMSN=25008266
2025-05-27T17:20:41.450Z,1748366441.450 [NAL9602](INFO): SBD MO Status=0, MOMSN=24684, MT Status=0, MTMSN=0
2025-05-27T17:20:41.450Z,1748366441.450 [NAL9602](INFO): No messages in MT queue
2025-05-27T17:20:47.103Z,1748366447.103 [DataOverHttps](INFO): Sending 175 bytes from file Logs/20250527T150409/Express0071.lzma
2025-05-27T17:20:48.106Z,1748366448.106 [DataOverHttps](INFO): Moved sent file to Logs/20250527T150409/Express0071.lzma.bak
2025-05-27T17:20:48.106Z,1748366448.106 [DataOverHttps](INFO): SBD MOMSN=25008269
2025-05-27T17:20:49.188Z,1748366449.188 [Default:CheckIn:Read_Iridium] Stopped
2025-05-27T17:20:49.188Z,1748366449.188 [Default:CheckIn:C.Wait] Running Loop=1
2025-05-27T17:20:49.188Z,1748366449.188 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-05-27T17:21:12.240Z,1748366472.240 [NAL9602](INFO): Not Powering down - fast GPS
2025-05-27T17:25:49.834Z,1748366749.834 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-05-27T17:25:49.834Z,1748366749.834 [Default:CheckIn:C.Wait] Stopped
2025-05-27T17:25:49.834Z,1748366749.834 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-05-27T17:25:49.834Z,1748366749.834 [Default:CheckIn:D] Running Loop=1
2025-05-27T17:25:50.248Z,1748366750.248 [Default:CheckIn:D] Stopped
2025-05-27T17:25:50.248Z,1748366750.248 [Default:CheckIn:E] Running Loop=1
2025-05-27T17:25:50.647Z,1748366750.647 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 136.714274 min
2025-05-27T17:25:50.663Z,1748366750.663 [Default:CheckIn:E] Stopped
2025-05-27T17:25:50.663Z,1748366750.663 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-05-27T17:25:50.663Z,1748366750.663 [Default:CheckIn] Stopped
2025-05-27T17:25:50.663Z,1748366750.663 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-05-27T17:25:50.663Z,1748366750.663 [Default:CheckIn](INFO): Running loop #23
2025-05-27T17:25:50.664Z,1748366750.664 [Default:CheckIn] Running Loop=23
2025-05-27T17:25:50.664Z,1748366750.664 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-05-27T17:25:50.664Z,1748366750.664 [Default:CheckIn:Read_GPS] Running Loop=1
2025-05-27T17:25:52.652Z,1748366752.652 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172551.00,A,3648.39880,N,12147.42623,W,6.240,229.71,270525,,,D*77
2025-05-27T17:25:52.654Z,1748366752.654 [NAL9602](INFO): GPS fix at 20250527T172551: (36.806647, -121.790437)
2025-05-27T17:25:52.665Z,1748366752.665 [Default:CheckIn:Read_GPS] Stopped
2025-05-27T17:25:52.665Z,1748366752.665 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-05-27T17:26:00.494Z,1748366760.494 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250527T150409/Courier0073.lzma
2025-05-27T17:26:01.137Z,1748366761.137 [NAL9602](INFO): SBD MO Status=0, MOMSN=24685, MT Status=0, MTMSN=0
2025-05-27T17:26:01.137Z,1748366761.137 [NAL9602](INFO): No messages in MT queue
2025-05-27T17:26:01.497Z,1748366761.497 [DataOverHttps](INFO): Moved sent file to Logs/20250527T150409/Courier0073.lzma.bak
2025-05-27T17:26:01.497Z,1748366761.497 [DataOverHttps](INFO): SBD MOMSN=25008291
2025-05-27T17:26:09.229Z,1748366769.229 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-05-27T17:26:16.904Z,1748366776.904 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-05-27T17:26:17.283Z,1748366777.283 [DataOverHttps](INFO): Sending 169 bytes from file Logs/20250527T150409/Express0074.lzma
2025-05-27T17:26:18.285Z,1748366778.285 [DataOverHttps](INFO): Moved sent file to Logs/20250527T150409/Express0074.lzma.bak
2025-05-27T17:26:18.285Z,1748366778.285 [DataOverHttps](INFO): SBD MOMSN=25008294
2025-05-27T17:26:19.342Z,1748366779.342 [Default:CheckIn:Read_Iridium] Stopped
2025-05-27T17:26:19.342Z,1748366779.342 [Default:CheckIn:C.Wait] Running Loop=1
2025-05-27T17:26:19.342Z,1748366779.342 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-05-27T17:26:31.852Z,1748366791.852 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-05-27T17:26:31.860Z,1748366791.860 [NAL9602](INFO): Not Powering down - fast GPS
2025-05-27T17:26:46.804Z,1748366806.804 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-05-27T17:27:01.780Z,1748366821.780 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-05-27T17:27:16.724Z,1748366836.724 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-05-27T17:27:32.480Z,1748366852.480 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-05-27T17:27:47.832Z,1748366867.832 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-05-27T17:28:03.588Z,1748366883.588 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-05-27T17:28:18.534Z,1748366898.534 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-05-27T17:30:54.080Z,1748367054.080 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-05-27T17:31:08.219Z,1748367068.219 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-05-27T17:31:19.947Z,1748367079.947 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-05-27T17:31:19.947Z,1748367079.947 [Default:CheckIn:C.Wait] Stopped
2025-05-27T17:31:19.947Z,1748367079.947 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-05-27T17:31:19.947Z,1748367079.947 [Default:CheckIn:D] Running Loop=1
2025-05-27T17:31:20.354Z,1748367080.354 [Default:CheckIn:D] Stopped
2025-05-27T17:31:20.354Z,1748367080.354 [Default:CheckIn:E] Running Loop=1
2025-05-27T17:31:20.766Z,1748367080.766 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 142.216048 min
2025-05-27T17:31:20.766Z,1748367080.766 [Default:CheckIn:E] Stopped
2025-05-27T17:31:20.766Z,1748367080.766 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-05-27T17:31:20.766Z,1748367080.766 [Default:CheckIn] Stopped
2025-05-27T17:31:20.766Z,1748367080.766 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-05-27T17:31:20.767Z,1748367080.767 [Default:CheckIn](INFO): Running loop #24
2025-05-27T17:31:20.767Z,1748367080.767 [Default:CheckIn] Running Loop=24
2025-05-27T17:31:20.767Z,1748367080.767 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-05-27T17:31:20.767Z,1748367080.767 [Default:CheckIn:Read_GPS] Running Loop=1
2025-05-27T17:31:21.956Z,1748367081.956 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-05-27T17:31:22.791Z,1748367082.791 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173122.00,A,3648.25030,N,12148.96308,W,15.298,290.24,270525,,,D*47
2025-05-27T17:31:22.793Z,1748367082.793 [NAL9602](INFO): GPS fix at 20250527T173122: (36.804172, -121.816051)
2025-05-27T17:31:22.804Z,1748367082.804 [Default:CheckIn:Read_GPS] Stopped
2025-05-27T17:31:22.804Z,1748367082.804 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-05-27T17:31:30.695Z,1748367090.695 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250527T150409/Courier0076.lzma
2025-05-27T17:31:31.697Z,1748367091.697 [DataOverHttps](INFO): Moved sent file to Logs/20250527T150409/Courier0076.lzma.bak
2025-05-27T17:31:31.697Z,1748367091.697 [DataOverHttps](INFO): SBD MOMSN=25008357
2025-05-27T17:31:35.691Z,1748367095.691 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-05-27T17:31:38.122Z,1748367098.122 [NAL9602](INFO): SBD MO Status=0, MOMSN=24686, MT Status=0, MTMSN=0
2025-05-27T17:31:38.122Z,1748367098.122 [NAL9602](INFO): No messages in MT queue
2025-05-27T17:31:47.683Z,1748367107.683 [DataOverHttps](INFO): Sending 174 bytes from file Logs/20250527T150409/Express0077.lzma
2025-05-27T17:31:48.685Z,1748367108.685 [DataOverHttps](INFO): Moved sent file to Logs/20250527T150409/Express0077.lzma.bak
2025-05-27T17:31:48.685Z,1748367108.685 [DataOverHttps](INFO): SBD MOMSN=25008360
2025-05-27T17:31:49.833Z,1748367109.833 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-05-27T17:31:49.851Z,1748367109.851 [Default:CheckIn:Read_Iridium] Stopped
2025-05-27T17:31:49.851Z,1748367109.851 [Default:CheckIn:C.Wait] Running Loop=1
2025-05-27T17:31:49.851Z,1748367109.851 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-05-27T17:32:03.971Z,1748367123.971 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-05-27T17:32:08.829Z,1748367128.829 [NAL9602](INFO): Not Powering down - fast GPS
2025-05-27T17:32:17.707Z,1748367137.707 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-05-27T17:32:31.846Z,1748367151.846 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-05-27T17:32:45.987Z,1748367165.987 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-05-27T17:33:00.163Z,1748367180.163 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-05-27T17:35:36.108Z,1748367336.108 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-05-27T17:35:51.459Z,1748367351.459 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-05-27T17:36:06.812Z,1748367366.812 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-05-27T17:36:20.953Z,1748367380.953 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-05-27T17:36:35.898Z,1748367395.898 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-05-27T17:36:50.542Z,1748367410.542 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-05-27T17:36:50.542Z,1748367410.542 [Default:CheckIn:C.Wait] Stopped
2025-05-27T17:36:50.542Z,1748367410.542 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-05-27T17:36:50.542Z,1748367410.542 [Default:CheckIn:D] Running Loop=1
2025-05-27T17:36:50.848Z,1748367410.848 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-05-27T17:36:50.899Z,1748367410.899 [Default:CheckIn:D] Stopped
2025-05-27T17:36:50.899Z,1748367410.899 [Default:CheckIn:E] Running Loop=1
2025-05-27T17:36:51.283Z,1748367411.283 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 147.724723 min
2025-05-27T17:36:51.283Z,1748367411.283 [Default:CheckIn:E] Stopped
2025-05-27T17:36:51.283Z,1748367411.283 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-05-27T17:36:51.283Z,1748367411.283 [Default:CheckIn] Stopped
2025-05-27T17:36:51.283Z,1748367411.283 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-05-27T17:36:51.283Z,1748367411.283 [Default:CheckIn](INFO): Running loop #25
2025-05-27T17:36:51.283Z,1748367411.283 [Default:CheckIn] Running Loop=25
2025-05-27T17:36:51.284Z,1748367411.284 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-05-27T17:36:51.284Z,1748367411.284 [Default:CheckIn:Read_GPS] Running Loop=1
2025-05-27T17:36:53.276Z,1748367413.276 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173652.00,A,3648.13669,N,12149.76239,W,18.311,262.24,270525,,,D*44
2025-05-27T17:36:53.278Z,1748367413.278 [NAL9602](INFO): GPS fix at 20250527T173652: (36.802278, -121.829373)
2025-05-27T17:36:53.323Z,1748367413.323 [Default:CheckIn:Read_GPS] Stopped
2025-05-27T17:36:53.323Z,1748367413.323 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-05-27T17:37:02.412Z,1748367422.412 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20250527T150409/Courier0079.lzma
2025-05-27T17:37:03.413Z,1748367423.413 [DataOverHttps](INFO): Moved sent file to Logs/20250527T150409/Courier0079.lzma.bak
2025-05-27T17:37:03.413Z,1748367423.413 [DataOverHttps](INFO): SBD MOMSN=25008382
2025-05-27T17:37:06.600Z,1748367426.600 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-05-27T17:37:21.467Z,1748367441.467 [DataOverHttps](INFO): Sending 177 bytes from file Logs/20250527T150409/Express0080.lzma
2025-05-27T17:37:21.547Z,1748367441.547 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-05-27T17:37:22.469Z,1748367442.469 [DataOverHttps](INFO): Moved sent file to Logs/20250527T150409/Express0080.lzma.bak
2025-05-27T17:37:22.470Z,1748367442.470 [DataOverHttps](INFO): SBD MOMSN=25008385
2025-05-27T17:37:23.582Z,1748367443.582 [Default:CheckIn:Read_Iridium] Stopped
2025-05-27T17:37:23.582Z,1748367443.582 [Default:CheckIn:C.Wait] Running Loop=1
2025-05-27T17:37:23.583Z,1748367443.583 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-05-27T17:37:25.606Z,1748367445.606 [NAL9602](INFO): SBD MO Status=2, MOMSN=24687, MT Status=2, MTMSN=0
2025-05-27T17:37:25.606Z,1748367445.606 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-05-27T17:37:36.901Z,1748367456.901 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-05-27T17:37:48.626Z,1748367468.626 [NAL9602](INFO): SBD MO Status=0, MOMSN=24687, MT Status=0, MTMSN=0
2025-05-27T17:37:48.626Z,1748367468.626 [NAL9602](INFO): No messages in MT queue
2025-05-27T17:38:19.350Z,1748367499.350 [NAL9602](INFO): Not Powering down - fast GPS
2025-05-27T17:40:13.658Z,1748367613.658 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-05-27T17:40:27.394Z,1748367627.394 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-05-27T17:40:41.537Z,1748367641.537 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-05-27T17:40:55.676Z,1748367655.676 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-05-27T17:41:09.815Z,1748367669.815 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-05-27T17:41:23.954Z,1748367683.954 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-05-27T17:41:37.288Z,1748367697.288 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-05-27T17:41:51.027Z,1748367711.027 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-05-27T17:41:58.396Z,1748367718.396 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-05-27T17:42:04.760Z,1748367724.760 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-05-27T17:42:18.494Z,1748367738.494 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-05-27T17:42:24.166Z,1748367744.166 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-05-27T17:42:24.166Z,1748367744.166 [Default:CheckIn:C.Wait] Stopped
2025-05-27T17:42:24.167Z,1748367744.167 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-05-27T17:42:24.167Z,1748367744.167 [Default:CheckIn:D] Running Loop=1
2025-05-27T17:42:24.576Z,1748367744.576 [Default:CheckIn:D] Stopped
2025-05-27T17:42:24.576Z,1748367744.576 [Default:CheckIn:E] Running Loop=1
2025-05-27T17:42:24.979Z,1748367744.979 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 153.286393 min
2025-05-27T17:42:24.995Z,1748367744.995 [Default:CheckIn:E] Stopped
2025-05-27T17:42:24.995Z,1748367744.995 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-05-27T17:42:24.995Z,1748367744.995 [Default:CheckIn] Stopped
2025-05-27T17:42:24.995Z,1748367744.995 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-05-27T17:42:24.995Z,1748367744.995 [Default:CheckIn](INFO): Running loop #26
2025-05-27T17:42:24.995Z,1748367744.995 [Default:CheckIn] Running Loop=26
2025-05-27T17:42:24.996Z,1748367744.996 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-05-27T17:42:24.996Z,1748367744.996 [Default:CheckIn:Read_GPS] Running Loop=1
2025-05-27T17:42:26.984Z,1748367746.984 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174226.00,A,3647.89610,N,12150.77480,W,0.544,92.67,270525,,,D*4E
2025-05-27T17:42:26.986Z,1748367746.986 [NAL9602](INFO): GPS fix at 20250527T174226: (36.798268, -121.846247)
2025-05-27T17:42:26.997Z,1748367746.997 [Default:CheckIn:Read_GPS] Stopped
2025-05-27T17:42:26.997Z,1748367746.997 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-05-27T17:42:32.233Z,1748367752.233 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-05-27T17:42:43.149Z,1748367763.149 [NAL9602](INFO): SBD MO Status=0, MOMSN=24688, MT Status=0, MTMSN=0
2025-05-27T17:42:43.149Z,1748367763.149 [NAL9602](INFO): No messages in MT queue
2025-05-27T17:42:43.667Z,1748367763.667 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250527T150409/Courier0082.lzma
2025-05-27T17:42:44.669Z,1748367764.669 [DataOverHttps](INFO): Moved sent file to Logs/20250527T150409/Courier0082.lzma.bak
2025-05-27T17:42:44.669Z,1748367764.669 [DataOverHttps](INFO): SBD MOMSN=25008447
2025-05-27T17:43:03.807Z,1748367783.807 [DataOverHttps](INFO): Sending 176 bytes from file Logs/20250527T150409/Express0083.lzma
2025-05-27T17:43:04.810Z,1748367784.810 [DataOverHttps](INFO): Moved sent file to Logs/20250527T150409/Express0083.lzma.bak
2025-05-27T17:43:04.810Z,1748367784.810 [DataOverHttps](INFO): SBD MOMSN=25008450
2025-05-27T17:43:05.912Z,1748367785.912 [Default:CheckIn:Read_Iridium] Stopped
2025-05-27T17:43:05.912Z,1748367785.912 [Default:CheckIn:C.Wait] Running Loop=1
2025-05-27T17:43:05.912Z,1748367785.912 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-05-27T17:43:13.898Z,1748367793.898 [NAL9602](INFO): Not Powering down - fast GPS
2025-05-27T17:44:45.108Z,1748367885.108 [DataOverHttps](IMPORTANT): SBD MTMSN=20250527T174444