2025-10-08T15:39:42.061Z,1759937982.061 [Supervisor](DEBUG): Initializing supervisor.
2025-10-08T15:39:42.065Z,1759937982.065 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2025-10-08T15:39:42.066Z,1759937982.066 [SyncHandler](INFO): Protected caller Thread ID is 839
2025-10-08T15:39:42.066Z,1759937982.066 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2025-10-08T15:39:42.067Z,1759937982.067 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2025-10-08T15:39:42.067Z,1759937982.067 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 840
2025-10-08T15:39:42.071Z,1759937982.071 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2025-10-08T15:39:42.092Z,1759937982.092 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2025-10-08T15:39:42.093Z,1759937982.093 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2025-10-08T15:39:42.093Z,1759937982.093 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 841
2025-10-08T15:39:42.097Z,1759937982.097 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2025-10-08T15:39:42.098Z,1759937982.098 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2025-10-08T15:39:42.099Z,1759937982.099 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 842
2025-10-08T15:39:42.101Z,1759937982.101 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2025-10-08T15:39:42.102Z,1759937982.102 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2025-10-08T15:39:42.102Z,1759937982.102 [logger ThreadHandler](INFO): Protected caller Thread ID is 843
2025-10-08T15:39:42.106Z,1759937982.106 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2025-10-08T15:39:42.107Z,1759937982.107 [Supervisor](INFO): Looking for Config files in directory: Config/
2025-10-08T15:39:42.111Z,1759937982.111 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2025-10-08T15:39:42.482Z,1759937982.482 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2025-10-08T15:39:42.482Z,1759937982.482 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2025-10-08T15:39:42.587Z,1759937982.587 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Guidance
2025-10-08T15:39:42.589Z,1759937982.589 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2025-10-08T15:39:42.711Z,1759937982.711 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2025-10-08T15:39:42.713Z,1759937982.713 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2025-10-08T15:39:42.861Z,1759937982.861 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2025-10-08T15:39:42.863Z,1759937982.863 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2025-10-08T15:39:43.249Z,1759937983.249 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2025-10-08T15:39:43.250Z,1759937983.250 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2025-10-08T15:39:43.360Z,1759937983.360 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2025-10-08T15:39:43.361Z,1759937983.361 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2025-10-08T15:39:43.817Z,1759937983.817 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2025-10-08T15:39:43.818Z,1759937983.818 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2025-10-08T15:39:44.075Z,1759937984.075 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2025-10-08T15:39:44.077Z,1759937984.077 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2025-10-08T15:39:44.169Z,1759937984.169 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2025-10-08T15:39:44.479Z,1759937984.479 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2025-10-08T15:39:44.481Z,1759937984.481 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2025-10-08T15:39:44.784Z,1759937984.784 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2025-10-08T15:39:44.805Z,1759937984.805 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2025-10-08T15:39:45.413Z,1759937985.413 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2025-10-08T15:39:45.415Z,1759937985.415 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2025-10-08T15:39:45.637Z,1759937985.637 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2025-10-08T15:39:45.639Z,1759937985.639 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2025-10-08T15:39:45.954Z,1759937985.954 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2025-10-08T15:39:45.954Z,1759937985.954 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2025-10-08T15:39:46.872Z,1759937986.872 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2025-10-08T15:39:46.874Z,1759937986.874 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2025-10-08T15:39:47.504Z,1759937987.504 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2025-10-08T15:39:47.506Z,1759937987.506 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-ahi/
2025-10-08T15:39:47.509Z,1759937987.509 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Control.cfg
2025-10-08T15:39:47.621Z,1759937987.621 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Science.cfg
2025-10-08T15:39:47.770Z,1759937987.770 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/secure.cfg
2025-10-08T15:39:47.867Z,1759937987.867 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Servo.cfg
2025-10-08T15:39:47.990Z,1759937987.990 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/BIT.cfg
2025-10-08T15:39:48.096Z,1759937988.096 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Battery.cfg
2025-10-08T15:39:48.384Z,1759937988.384 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2025-10-08T15:39:48.386Z,1759937988.386 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/vehicle.cfg
2025-10-08T15:39:48.510Z,1759937988.510 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/logger.cfg
2025-10-08T15:39:48.621Z,1759937988.621 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Sensor.cfg
2025-10-08T15:39:48.777Z,1759937988.777 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Simulator.cfg
2025-10-08T15:39:48.876Z,1759937988.876 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-ahi/root/
2025-10-08T15:39:48.877Z,1759937988.877 [Supervisor](IMPORTANT): Reloading configuration overrides from Data/persisted.cfg
2025-10-08T15:39:48.889Z,1759937988.889 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2025-10-08T15:39:49.080Z,1759937989.080 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2025-10-08T15:39:49.082Z,1759937989.082 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2025-10-08T15:39:49.161Z,1759937989.161 [VerticalControl](DEBUG): Construct VerticalControl.
2025-10-08T15:39:49.225Z,1759937989.225 [VerticalControl] Loaded
2025-10-08T15:39:49.226Z,1759937989.226 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2025-10-08T15:39:49.228Z,1759937989.228 [HorizontalControl](DEBUG): Construct HorizontalControl.
2025-10-08T15:39:49.278Z,1759937989.278 [HorizontalControl] Loaded
2025-10-08T15:39:49.279Z,1759937989.279 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2025-10-08T15:39:49.281Z,1759937989.281 [SpeedControl](DEBUG): Construct SpeedControl.
2025-10-08T15:39:49.284Z,1759937989.284 [SpeedControl] Loaded
2025-10-08T15:39:49.285Z,1759937989.285 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2025-10-08T15:39:49.287Z,1759937989.287 [LoopControl](DEBUG): Construct LoopControl.
2025-10-08T15:39:49.288Z,1759937989.288 [LoopControl] Loaded
2025-10-08T15:39:49.288Z,1759937989.288 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2025-10-08T15:39:49.289Z,1759937989.289 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2025-10-08T15:39:49.289Z,1759937989.289 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2025-10-08T15:39:49.385Z,1759937989.385 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2025-10-08T15:39:49.386Z,1759937989.386 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2025-10-08T15:39:50.290Z,1759937990.290 [AHRS_M2] Loaded
2025-10-08T15:39:50.291Z,1759937990.291 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2025-10-08T15:39:50.546Z,1759937990.546 [BackseatComponent] Loaded
2025-10-08T15:39:50.546Z,1759937990.546 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2025-10-08T15:39:50.547Z,1759937990.547 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 408BD4E0
2025-10-08T15:39:50.548Z,1759937990.548 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 923
2025-10-08T15:39:50.551Z,1759937990.551 [LcmUniversalReporter] Loaded
2025-10-08T15:39:50.551Z,1759937990.551 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2025-10-08T15:39:51.429Z,1759937991.429 [BPC1] Loaded
2025-10-08T15:39:51.430Z,1759937991.430 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2025-10-08T15:39:51.533Z,1759937991.533 [DAT] Loaded
2025-10-08T15:39:51.533Z,1759937991.533 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread.
2025-10-08T15:39:51.534Z,1759937991.534 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 408ED4E0
2025-10-08T15:39:51.534Z,1759937991.534 [DAT ThreadHandler](INFO): Protected caller Thread ID is 924
2025-10-08T15:39:51.692Z,1759937991.692 [DataOverHttps] Loaded
2025-10-08T15:39:51.692Z,1759937991.692 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2025-10-08T15:39:51.693Z,1759937991.693 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4091D4E0
2025-10-08T15:39:51.694Z,1759937991.694 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 925
2025-10-08T15:39:51.718Z,1759937991.718 [Depth_Keller] Loaded
2025-10-08T15:39:51.718Z,1759937991.718 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2025-10-08T15:39:51.724Z,1759937991.724 [DropWeight] Loaded
2025-10-08T15:39:51.724Z,1759937991.724 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2025-10-08T15:39:51.793Z,1759937991.793 [NAL9602] Loaded
2025-10-08T15:39:51.793Z,1759937991.793 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2025-10-08T15:39:51.826Z,1759937991.826 [Onboard] Loaded
2025-10-08T15:39:51.826Z,1759937991.826 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2025-10-08T15:39:51.827Z,1759937991.827 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 4094D4E0
2025-10-08T15:39:51.827Z,1759937991.827 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 926
2025-10-08T15:39:51.842Z,1759937991.842 [Power24vConverter] Loaded
2025-10-08T15:39:51.843Z,1759937991.843 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2025-10-08T15:39:51.860Z,1759937991.860 [Radio_Surface] Loaded
2025-10-08T15:39:51.860Z,1759937991.860 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2025-10-08T15:39:51.861Z,1759937991.861 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4097D4E0
2025-10-08T15:39:51.861Z,1759937991.861 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 927
2025-10-08T15:39:51.878Z,1759937991.878 [Sonardyne_Nano] Loaded
2025-10-08T15:39:51.878Z,1759937991.878 [ComponentRegistry](DEBUG): SyncComponent "Sonardyne_Nano" handled in the control thread.
2025-10-08T15:39:51.904Z,1759937991.904 [Waterlinked] Loaded
2025-10-08T15:39:51.904Z,1759937991.904 [ComponentRegistry](DEBUG): SyncComponent "Waterlinked" handled in the control thread.
2025-10-08T15:39:51.905Z,1759937991.905 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2025-10-08T15:39:51.906Z,1759937991.906 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2025-10-08T15:39:51.929Z,1759937991.929 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2025-10-08T15:39:51.930Z,1759937991.930 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2025-10-08T15:39:51.995Z,1759937991.995 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2025-10-08T15:39:51.997Z,1759937991.997 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2025-10-08T15:39:52.221Z,1759937992.221 [SBIT](DEBUG): Construct Startup Built In Test.
2025-10-08T15:39:52.231Z,1759937992.231 [SBIT] Loaded
2025-10-08T15:39:52.231Z,1759937992.231 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2025-10-08T15:39:52.234Z,1759937992.234 [IBIT](DEBUG): Construct Initiated Built In Test.
2025-10-08T15:39:52.247Z,1759937992.247 [IBIT] Loaded
2025-10-08T15:39:52.248Z,1759937992.248 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2025-10-08T15:39:52.253Z,1759937992.253 [CBIT](DEBUG): Construct Continuous Built In Test.
2025-10-08T15:39:52.339Z,1759937992.339 [CBIT] Loaded
2025-10-08T15:39:52.339Z,1759937992.339 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2025-10-08T15:39:52.375Z,1759937992.375 [GFScanner] Loaded
2025-10-08T15:39:52.375Z,1759937992.375 [ComponentRegistry](DEBUG): SyncComponent "GFScanner" handled in the control thread.
2025-10-08T15:39:52.376Z,1759937992.376 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2025-10-08T15:39:52.376Z,1759937992.376 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2025-10-08T15:39:52.840Z,1759937992.840 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2025-10-08T15:39:52.841Z,1759937992.841 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2025-10-08T15:39:52.917Z,1759937992.917 [DepthRateCalculator] Loaded
2025-10-08T15:39:52.918Z,1759937992.918 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2025-10-08T15:39:52.923Z,1759937992.923 [PitchRateCalculator] Loaded
2025-10-08T15:39:52.923Z,1759937992.923 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2025-10-08T15:39:52.934Z,1759937992.934 [SpeedCalculator] Loaded
2025-10-08T15:39:52.934Z,1759937992.934 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2025-10-08T15:39:52.939Z,1759937992.939 [YawRateCalculator] Loaded
2025-10-08T15:39:52.939Z,1759937992.939 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2025-10-08T15:39:52.960Z,1759937992.960 [ElevatorOffsetCalculator] Loaded
2025-10-08T15:39:52.960Z,1759937992.960 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2025-10-08T15:39:52.961Z,1759937992.961 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2025-10-08T15:39:52.961Z,1759937992.961 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2025-10-08T15:39:53.252Z,1759937993.252 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2025-10-08T15:39:53.252Z,1759937993.252 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2025-10-08T15:39:53.403Z,1759937993.403 [DeadReckonUsingMultipleVelocitySources] Loaded
2025-10-08T15:39:53.404Z,1759937993.404 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2025-10-08T15:39:53.419Z,1759937993.419 [NavChart] Loaded
2025-10-08T15:39:53.419Z,1759937993.419 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2025-10-08T15:39:53.425Z,1759937993.425 [UniversalFixResidualReporter] Loaded
2025-10-08T15:39:53.425Z,1759937993.425 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2025-10-08T15:39:53.426Z,1759937993.426 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2025-10-08T15:39:53.426Z,1759937993.426 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2025-10-08T15:39:53.610Z,1759937993.610 [BuoyancyServo] Loaded
2025-10-08T15:39:53.610Z,1759937993.610 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2025-10-08T15:39:53.634Z,1759937993.634 [ElevatorServo] Loaded
2025-10-08T15:39:53.635Z,1759937993.635 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2025-10-08T15:39:53.658Z,1759937993.658 [MassServo] Loaded
2025-10-08T15:39:53.659Z,1759937993.659 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2025-10-08T15:39:53.681Z,1759937993.681 [RudderServo] Loaded
2025-10-08T15:39:53.681Z,1759937993.681 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2025-10-08T15:39:53.699Z,1759937993.699 [ThrusterHE] Loaded
2025-10-08T15:39:53.699Z,1759937993.699 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2025-10-08T15:39:53.700Z,1759937993.700 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2025-10-08T15:39:53.700Z,1759937993.700 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2025-10-08T15:39:53.941Z,1759937993.941 [CTD_Seabird] Loaded
2025-10-08T15:39:53.942Z,1759937993.942 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2025-10-08T15:39:53.943Z,1759937993.943 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40C0D4E0
2025-10-08T15:39:53.943Z,1759937993.943 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 929
2025-10-08T15:39:53.983Z,1759937993.983 [ESPComponent] Loaded
2025-10-08T15:39:53.983Z,1759937993.983 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2025-10-08T15:39:54.007Z,1759937994.007 [PAR_Licor] Loaded
2025-10-08T15:39:54.007Z,1759937994.007 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2025-10-08T15:39:54.055Z,1759937994.055 [WetLabsBB2FL] Loaded
2025-10-08T15:39:54.056Z,1759937994.056 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2025-10-08T15:39:54.057Z,1759937994.057 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40C3D4E0
2025-10-08T15:39:54.057Z,1759937994.057 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 930
2025-10-08T15:39:54.058Z,1759937994.058 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2025-10-08T15:39:54.064Z,1759937994.064 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2025-10-08T15:39:54.067Z,1759937994.067 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2025-10-08T15:39:54.079Z,1759937994.079 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2025-10-08T15:39:54.080Z,1759937994.080 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C6D4E0
2025-10-08T15:39:54.081Z,1759937994.081 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 931
2025-10-08T15:39:54.085Z,1759937994.085 [Supervisor](INFO): Main Thread ID is 830
2025-10-08T15:39:54.085Z,1759937994.085 [Supervisor](DEBUG): Running supervisor.
2025-10-08T15:39:54.086Z,1759937994.086 [CommandExec ThreadHandler](INFO): Handler Thread ID is 932
2025-10-08T15:39:54.086Z,1759937994.086 [CommandExec](INFO): Initializing the command executive.
2025-10-08T15:39:54.088Z,1759937994.088 [CommandLine ThreadHandler](INFO): Handler Thread ID is 933
2025-10-08T15:39:54.090Z,1759937994.090 [controlThread ThreadHandler](INFO): Handler Thread ID is 934
2025-10-08T15:39:54.091Z,1759937994.091 [controlThread](DEBUG): Initializing ControlThread
2025-10-08T15:39:54.091Z,1759937994.091 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2025-10-08T15:39:54.093Z,1759937994.093 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2025-10-08T15:39:54.094Z,1759937994.094 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2025-10-08T15:39:54.094Z,1759937994.094 [LoopControl](DEBUG): Initialize LoopControlComponent.
2025-10-08T15:39:54.097Z,1759937994.097 [SBIT](INFO): Initialize SBIT Component.
2025-10-08T15:39:54.098Z,1759937994.098 [SBIT](IMPORTANT): git: 2025-09-19
2025-10-08T15:39:54.098Z,1759937994.098 [SBIT](INFO): git hash: f5f7d10969816d125effdffd07357c8d50a3a0d0
2025-10-08T15:39:54.098Z,1759937994.098 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2025-10-08T15:39:54.100Z,1759937994.100 [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-10-08T15:39:54.101Z,1759937994.101 [SBIT](INFO): Beginning SBIT in 114.000000 seconds.
2025-10-08T15:39:54.101Z,1759937994.101 [IBIT](INFO): Initialize IBIT Component.
2025-10-08T15:39:54.102Z,1759937994.102 [CBIT](DEBUG): Initialize CBIT Component.
2025-10-08T15:39:54.103Z,1759937994.103 [logger ThreadHandler](INFO): Handler Thread ID is 935
2025-10-08T15:39:54.113Z,1759937994.113 [CBIT](DEBUG): Initialized mux pins.
2025-10-08T15:39:54.113Z,1759937994.113 [CBIT](DEBUG): Initializing the watchdog timer.
2025-10-08T15:39:54.121Z,1759937994.121 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 936
2025-10-08T15:39:54.137Z,1759937994.137 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2025-10-08T15:39:54.137Z,1759937994.137 [CBIT](DEBUG): Initializing heartbeat.
2025-10-08T15:39:54.138Z,1759937994.138 [DAT ThreadHandler](INFO): Handler Thread ID is 937
2025-10-08T15:39:54.139Z,1759937994.139 [DAT](INFO): Powering up
2025-10-08T15:39:54.139Z,1759937994.139 [DAT](DEBUG): Initializing DAT.
2025-10-08T15:39:54.142Z,1759937994.142 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 939
2025-10-08T15:39:54.144Z,1759937994.144 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2025-10-08T15:39:54.165Z,1759937994.165 [Onboard ThreadHandler](INFO): Handler Thread ID is 940
2025-10-08T15:39:54.182Z,1759937994.182 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 941
2025-10-08T15:39:54.205Z,1759937994.205 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 942
2025-10-08T15:39:54.206Z,1759937994.206 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2025-10-08T15:39:54.209Z,1759937994.209 [CBIT](DEBUG): Deactivating emergency mode.
2025-10-08T15:39:54.211Z,1759937994.211 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 944
2025-10-08T15:39:54.213Z,1759937994.213 [WetLabsBB2FL](INFO): Powering up
2025-10-08T15:39:54.215Z,1759937994.215 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 946
2025-10-08T15:39:54.222Z,1759937994.222 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2025-10-08T15:39:54.222Z,1759937994.222 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2025-10-08T15:39:54.222Z,1759937994.222 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2025-10-08T15:39:54.222Z,1759937994.222 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2025-10-08T15:39:54.222Z,1759937994.222 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2025-10-08T15:39:54.222Z,1759937994.222 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2025-10-08T15:39:54.223Z,1759937994.223 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2025-10-08T15:39:54.223Z,1759937994.223 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2025-10-08T15:39:54.249Z,1759937994.249 [CBIT](DEBUG): Backplane powered.
2025-10-08T15:39:54.249Z,1759937994.249 [GFScanner](DEBUG): Initializing GFScanner
2025-10-08T15:39:54.249Z,1759937994.249 [GFScanner](DEBUG): Deactivating GF circuits.
2025-10-08T15:39:54.254Z,1759937994.254 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2025-10-08T15:39:54.254Z,1759937994.254 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2025-10-08T15:39:54.254Z,1759937994.254 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2025-10-08T15:39:54.255Z,1759937994.255 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2025-10-08T15:39:54.255Z,1759937994.255 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2025-10-08T15:39:54.256Z,1759937994.256 [NavChart](DEBUG): Initialize NavChart Navigation.
2025-10-08T15:39:54.257Z,1759937994.257 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2025-10-08T15:39:54.266Z,1759937994.266 [MissionManager](IMPORTANT): Using TethysL tl-to-tx parser
2025-10-08T15:39:54.267Z,1759937994.267 [MissionManager](INFO): Loading Mission from file: Missions/Startup.tl
2025-10-08T15:39:54.267Z,1759937994.267 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Startup.tl
2025-10-08T15:39:54.271Z,1759937994.271 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Startup.tl
2025-10-08T15:39:54.363Z,1759937994.363 [MissionManager](DEBUG): TethyslAPI: Missions/Startup.tl translated into:
2025-10-08T15:39:54.367Z,1759937994.367 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2025-10-08T15:39:54.434Z,1759937994.434 [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-10-08T15:39:54.435Z,1759937994.435 [MissionManager](INFO): Loading Mission from file: Missions/Default.tl
2025-10-08T15:39:54.435Z,1759937994.435 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Default.tl
2025-10-08T15:39:54.439Z,1759937994.439 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Default.tl
2025-10-08T15:39:54.589Z,1759937994.589 [Radio_Surface](INFO): Powering up
2025-10-08T15:39:54.749Z,1759937994.749 [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-10-08T15:39:54.763Z,1759937994.763 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2025-10-08T15:39:54.764Z,1759937994.764 [Default:A.Wait](DEBUG): Construct Wait.
2025-10-08T15:39:54.766Z,1759937994.766 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2025-10-08T15:39:54.824Z,1759937994.824 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2025-10-08T15:39:54.827Z,1759937994.827 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2025-10-08T15:39:54.860Z,1759937994.860 [Default:E.Execute](DEBUG): Construct Execute.
2025-10-08T15:39:54.863Z,1759937994.863 [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-10-08T15:39:54.873Z,1759937994.873 [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-10-08T15:39:54.885Z,1759937994.885 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2025-10-08T15:39:55.022Z,1759937995.022 [Depth_Keller](INFO): Initializing.
2025-10-08T15:39:55.023Z,1759937995.023 [Power24vConverter](INFO): Powering up.
2025-10-08T15:39:55.024Z,1759937995.024 [Sonardyne_Nano](INFO): Initializing.
2025-10-08T15:39:55.066Z,1759937995.066 [DepthRateCalculator](ERROR): Depth measurement is not active
2025-10-08T15:39:55.092Z,1759937995.092 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2025-10-08T15:39:55.101Z,1759937995.101 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2025-10-08T15:39:55.102Z,1759937995.102 [ElevatorServo](DEBUG): Initializing EZServoServo.
2025-10-08T15:39:55.110Z,1759937995.110 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2025-10-08T15:39:55.111Z,1759937995.111 [MassServo](DEBUG): Initializing EZServoServo.
2025-10-08T15:39:55.117Z,1759937995.117 [MassServo](DEBUG): Initializing MassServo.
2025-10-08T15:39:55.118Z,1759937995.118 [RudderServo](DEBUG): Initializing EZServoServo.
2025-10-08T15:39:55.126Z,1759937995.126 [RudderServo](DEBUG): Initializing RudderServo.
2025-10-08T15:39:55.127Z,1759937995.127 [ThrusterHE](DEBUG): Initializing EZServoServo.
2025-10-08T15:39:55.133Z,1759937995.133 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2025-10-08T15:39:56.321Z,1759937996.321 [WetLabsBB2FL](INFO): Powering down
2025-10-08T15:39:57.307Z,1759937997.307 [Sonardyne_Nano](ERROR): Failed to get valid response or reached max queue size, flushing UART
2025-10-08T15:39:58.562Z,1759937998.562 [Sonardyne_Nano](IMPORTANT): Found beacon with acoustic ID 2311
2025-10-08T15:40:00.782Z,1759938000.782 [ThrusterHE](ERROR): Zero Speed Commanded.
2025-10-08T15:40:07.495Z,1759938007.495 [DAT](INFO): DAT read:
2025-10-08T15:40:07.497Z,1759938007.497 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series
2025-10-08T15:40:09.258Z,1759938009.258 [DAT](INFO): DAT read: MF Frequency Band
2025-10-08T15:40:09.259Z,1759938009.259 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0
2025-10-08T15:40:09.260Z,1759938009.260 [DAT](INFO): DAT read: Oct 7 2025 19:35:34
2025-10-08T15:40:10.518Z,1759938010.518 [DAT](INFO): DAT read: Features enabled [Bearing]
2025-10-08T15:40:10.519Z,1759938010.519 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP
2025-10-08T15:40:10.520Z,1759938010.520 [DAT](INFO): commRate: 800
2025-10-08T15:40:12.585Z,1759938012.585 [DAT](INFO): entering command mode
2025-10-08T15:40:12.786Z,1759938012.786 [DAT](INFO): DAT read:
2025-10-08T15:40:12.786Z,1759938012.786 [DAT](INFO): DAT read: user:1>
2025-10-08T15:40:12.787Z,1759938012.787 [DAT](INFO): setting verbose to 3
2025-10-08T15:40:13.038Z,1759938013.038 [DAT](INFO): DAT read: user:1>
2025-10-08T15:40:13.039Z,1759938013.039 [DAT](INFO): DAT read: Verbose | 3
2025-10-08T15:40:13.039Z,1759938013.039 [DAT](INFO): set verbose to 3
2025-10-08T15:40:13.039Z,1759938013.039 [DAT](INFO): setting DatVerbose to 27440
2025-10-08T15:40:13.290Z,1759938013.290 [DAT](INFO): DAT read: user:2>
2025-10-08T15:40:13.291Z,1759938013.291 [DAT](INFO): DAT read: DatVerbose | 27440
2025-10-08T15:40:13.291Z,1759938013.291 [DAT](INFO): set DatVerbose to 27440
2025-10-08T15:40:13.291Z,1759938013.291 [DAT](INFO): setting transmit power to 8
2025-10-08T15:40:13.543Z,1759938013.543 [DAT](INFO): DAT read: user:3>
2025-10-08T15:40:13.544Z,1759938013.544 [DAT](INFO): DAT read: TxPower | 8 (Max)
2025-10-08T15:40:13.545Z,1759938013.545 [DAT](INFO): set transmit power to 8
2025-10-08T15:40:13.546Z,1759938013.546 [DAT](INFO): setting local address to 1
2025-10-08T15:40:13.794Z,1759938013.794 [DAT](INFO): DAT read: user:4>
2025-10-08T15:40:13.795Z,1759938013.795 [DAT](INFO): DAT read: LocalAddr | 1
2025-10-08T15:40:13.795Z,1759938013.795 [DAT](INFO): set local address to 1
2025-10-08T15:40:13.796Z,1759938013.796 [DAT](INFO): Setting time to: 15:40:13 And date to:10/8/2025
2025-10-08T15:40:14.046Z,1759938014.046 [DAT](INFO): DAT read: user:5>
2025-10-08T15:40:14.047Z,1759938014.047 [DAT](INFO): DAT read: Wed Oct 8, 2025 15:40:13
2025-10-08T15:40:14.047Z,1759938014.047 [DAT](INFO): Local DAT time set to Wed Oct 8, 2025 15:40:13
2025-10-08T15:40:22.142Z,1759938022.142 [NAL9602](INFO): Powering up NAL9602
2025-10-08T15:40:25.134Z,1759938025.134 [CommandExec](IMPORTANT): got command get Sonardyne_Nano.chargePercent
2025-10-08T15:40:25.135Z,1759938025.135 [CommandExec](IMPORTANT): Sonardyne_Nano.chargePercent 96.000000 %
2025-10-08T15:40:31.753Z,1759938031.753 [Waterlinked](INFO): Powering down
2025-10-08T15:40:33.207Z,1759938033.207 [NAL9602](INFO): NAL9602 initialized
2025-10-08T15:41:02.289Z,1759938062.289 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-10-08T15:41:17.640Z,1759938077.640 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-10-08T15:41:32.587Z,1759938092.587 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-10-08T15:41:47.939Z,1759938107.939 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-10-08T15:41:48.780Z,1759938108.780 [SBIT](IMPORTANT): Beginning Startup BIT
2025-10-08T15:41:48.801Z,1759938108.801 [GFScanner](IMPORTANT): Beginning ground fault scan
2025-10-08T15:41:53.317Z,1759938113.317 [GFScanner](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): 0.017815
CHAN A1 (24V): 0.000995
CHAN A2 (12V): 0.000730
CHAN A3 (5V): -0.001198
CHAN B0 (3.3V): 0.000991
CHAN B1 (3.15aV): -0.000060
CHAN B2 (3.15bV): 0.000699
CHAN B3 (GND): -0.000160
OPEN: 0.006429
Full Scale: +/- 1 mA
2025-10-08T15:42:03.325Z,1759938123.325 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-10-08T15:42:42.616Z,1759938162.616 [SBIT](IMPORTANT): SBIT PASSED
2025-10-08T15:42:42.637Z,1759938162.637 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2025-10-08T15:42:42.638Z,1759938162.638 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=19 count;
2025-10-08T15:42:42.638Z,1759938162.638 [SBIT](IMPORTANT): Express linearApproximation TrackAcousticContact.range_to_contact 15.000000 meter;
2025-10-08T15:42:42.638Z,1759938162.638 [SBIT](IMPORTANT): Express linearApproximation _.planktivore_HM_AvgRois 2.000000 count_per_second;
2025-10-08T15:42:42.638Z,1759938162.638 [SBIT](IMPORTANT): Express linearApproximation _.planktivore_LM_AvgRois 100.000000 count_per_second;
2025-10-08T15:42:42.638Z,1759938162.638 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=212.440356 cubic_centimeter;
2025-10-08T15:42:42.638Z,1759938162.638 [SBIT](IMPORTANT): VerticalControl.massDefault=23.585494 millimeter;
2025-10-08T15:42:43.015Z,1759938163.015 [MissionManager](IMPORTANT): Started mission Startup
2025-10-08T15:42:43.015Z,1759938163.015 [Startup] Running Loop=1
2025-10-08T15:42:43.016Z,1759938163.016 [Startup](DEBUG): Aggregate::initialize Startup
2025-10-08T15:42:43.016Z,1759938163.016 [Startup:A.GoToSurface] Running Loop=1
2025-10-08T15:42:43.016Z,1759938163.016 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-10-08T15:42:43.016Z,1759938163.016 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2025-10-08T15:42:43.021Z,1759938163.021 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2025-10-08T15:42:43.021Z,1759938163.021 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2025-10-08T15:42:43.022Z,1759938163.022 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2025-10-08T15:42:43.022Z,1759938163.022 [Startup:A.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-10-08T15:42:43.022Z,1759938163.022 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-10-08T15:42:43.024Z,1759938163.024 [Startup:StartupSatComms] Running Loop=1
2025-10-08T15:42:43.024Z,1759938163.024 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2025-10-08T15:42:43.024Z,1759938163.024 [Startup:StartupSatComms:A] Running Loop=1
2025-10-08T15:42:43.394Z,1759938163.394 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2025-10-08T15:42:47.304Z,1759938167.304 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.009460
2025-10-08T15:42:54.550Z,1759938174.550 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2025-10-08T15:42:54.550Z,1759938174.550 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-10-08T15:42:54.592Z,1759938174.592 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-10-08T15:42:54.974Z,1759938174.974 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-10-08T15:42:54.974Z,1759938174.974 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2025-10-08T15:43:43.031Z,1759938223.031 [Startup:StartupSatComms:A](INFO): Timed out from 2025-10-08T15:42:43.0Z
2025-10-08T15:43:43.032Z,1759938223.032 [Startup:StartupSatComms:A] Stopped
2025-10-08T15:43:43.032Z,1759938223.032 [Startup:StartupSatComms:B] Running Loop=1
2025-10-08T15:43:43.447Z,1759938223.447 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2025-10-08T15:43:47.672Z,1759938227.672 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20251008T153942/Courier0000.lzma
2025-10-08T15:43:48.674Z,1759938228.674 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153942/Courier0000.lzma.bak
2025-10-08T15:43:48.674Z,1759938228.674 [DataOverHttps](INFO): SBD MOMSN=26147646
2025-10-08T15:44:04.402Z,1759938244.402 [DataOverHttps](INFO): Sending 945 bytes from file Logs/20251008T153942/Express0001.lzma
2025-10-08T15:44:05.402Z,1759938245.402 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153942/Express0001.lzma.bak
2025-10-08T15:44:05.403Z,1759938245.403 [DataOverHttps](INFO): SBD MOMSN=26147649
2025-10-08T15:44:06.566Z,1759938246.566 [Startup:StartupSatComms:B] Stopped
2025-10-08T15:44:06.566Z,1759938246.566 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2025-10-08T15:44:06.566Z,1759938246.566 [Startup:StartupSatComms] Stopped
2025-10-08T15:44:06.566Z,1759938246.566 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2025-10-08T15:44:06.567Z,1759938246.567 [Startup](INFO): Completed Startup
2025-10-08T15:44:06.567Z,1759938246.567 [MissionManager](INFO): Startup is completed.
2025-10-08T15:44:06.567Z,1759938246.567 [MissionManager](INFO): Uninitializing Mission Startup
2025-10-08T15:44:06.567Z,1759938246.567 [Startup] Stopped
2025-10-08T15:44:06.567Z,1759938246.567 [Startup](DEBUG): Aggregate::uninitialize Startup
2025-10-08T15:44:06.567Z,1759938246.567 [Startup:A.GoToSurface] Stopped
2025-10-08T15:44:06.567Z,1759938246.567 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-10-08T15:44:07.010Z,1759938247.010 [MissionManager](IMPORTANT): Started mission Default
2025-10-08T15:44:07.010Z,1759938247.010 [Default] Running Loop=1
2025-10-08T15:44:07.011Z,1759938247.011 [Default](DEBUG): Aggregate::initialize Default
2025-10-08T15:44:07.011Z,1759938247.011 [Default:B.GoToSurface] Running Loop=1
2025-10-08T15:44:07.011Z,1759938247.011 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-10-08T15:44:07.011Z,1759938247.011 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2025-10-08T15:44:07.011Z,1759938247.011 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2025-10-08T15:44:07.012Z,1759938247.012 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2025-10-08T15:44:07.012Z,1759938247.012 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2025-10-08T15:44:07.036Z,1759938247.036 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-10-08T15:44:07.037Z,1759938247.037 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-10-08T15:44:07.037Z,1759938247.037 [Default:A.Wait] Running Loop=1
2025-10-08T15:44:07.037Z,1759938247.037 [Default:A.Wait](DEBUG): Initialize Wait Component.
2025-10-08T15:44:20.290Z,1759938260.290 [Default:A.Wait](INFO): Done Waiting.
2025-10-08T15:44:20.290Z,1759938260.290 [Default:A.Wait] Stopped
2025-10-08T15:44:20.290Z,1759938260.290 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2025-10-08T15:44:20.755Z,1759938260.755 [Default:CheckIn] Running Loop=1
2025-10-08T15:44:20.755Z,1759938260.755 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-10-08T15:44:20.755Z,1759938260.755 [Default:CheckIn:Read_GPS] Running Loop=1
2025-10-08T15:44:21.081Z,1759938261.081 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2025-10-08T15:44:38.843Z,1759938278.843 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-10-08T15:44:53.382Z,1759938293.382 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-10-08T15:45:07.926Z,1759938307.926 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-10-08T15:45:21.678Z,1759938321.678 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-10-08T15:45:35.804Z,1759938335.804 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-10-08T15:45:36.230Z,1759938336.230 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2025-10-08T15:45:49.942Z,1759938349.942 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-10-08T15:45:55.617Z,1759938355.617 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2025-10-08T15:45:55.617Z,1759938355.617 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-10-08T15:45:55.628Z,1759938355.628 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-10-08T15:45:56.035Z,1759938356.035 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-10-08T15:45:56.035Z,1759938356.035 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2025-10-08T15:46:04.084Z,1759938364.084 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-10-08T15:46:18.627Z,1759938378.627 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-10-08T15:46:32.767Z,1759938392.767 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-10-08T15:46:46.940Z,1759938406.940 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-10-08T15:47:47.535Z,1759938467.535 [BPC1](ERROR): Battery stick #17 (s/n: 0084) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0.
2025-10-08T15:47:47.536Z,1759938467.536 [BPC1](ERROR): Battery stick #24 (s/n: 01D3) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0.
2025-10-08T15:47:47.537Z,1759938467.537 [BPC1](ERROR): Battery stick #29 (s/n: 00A7) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4AD0.
2025-10-08T15:47:47.537Z,1759938467.537 [BPC1](ERROR): Battery stick #38 (s/n: 01BC) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0.
2025-10-08T15:47:47.538Z,1759938467.538 [BPC1](ERROR): Battery stick #51 (s/n: 01D6) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0.
2025-10-08T15:47:47.539Z,1759938467.539 [BPC1](ERROR): Battery stick #57 (s/n: 019F) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0.
2025-10-08T15:47:47.540Z,1759938467.540 [BPC1](ERROR): Battery stick #59 (s/n: 0184) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4AD0.
2025-10-08T15:47:47.540Z,1759938467.540 [BPC1](INFO): Calculating totals. Valid battery stick count: 39. Valid reserve battery stick count: 4.
2025-10-08T15:47:47.543Z,1759938467.543 [BPC1](INFO): Received data from all battery sticks.
2025-10-08T15:48:56.641Z,1759938536.641 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2025-10-08T15:48:56.641Z,1759938536.641 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-10-08T15:48:56.652Z,1759938536.652 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-10-08T15:48:57.058Z,1759938537.058 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-10-08T15:48:57.058Z,1759938537.058 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2025-10-08T15:49:09.074Z,1759938549.074 [CommandExec](IMPORTANT): got command burn on
2025-10-08T15:49:09.074Z,1759938549.074 [CommandExec](IMPORTANT): Activating dropweight wire
2025-10-08T15:49:20.890Z,1759938560.890 [Default:CheckIn:Read_GPS](INFO): Timed out from 2025-10-08T15:44:20.8Z
2025-10-08T15:49:20.890Z,1759938560.890 [Default:CheckIn:Read_GPS] Stopped
2025-10-08T15:49:20.890Z,1759938560.890 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-10-08T15:49:21.282Z,1759938561.282 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2025-10-08T15:49:28.024Z,1759938568.024 [DataOverHttps](INFO): Sending 168 bytes from file Logs/20251008T153942/Courier0004.lzma
2025-10-08T15:49:29.027Z,1759938569.027 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153942/Courier0004.lzma.bak
2025-10-08T15:49:29.027Z,1759938569.027 [DataOverHttps](INFO): SBD MOMSN=26147729
2025-10-08T15:49:44.588Z,1759938584.588 [DataOverHttps](INFO): Sending 231 bytes from file Logs/20251008T153942/Express0005.lzma
2025-10-08T15:49:45.590Z,1759938585.590 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153942/Express0005.lzma.bak
2025-10-08T15:49:45.590Z,1759938585.590 [DataOverHttps](INFO): SBD MOMSN=26147738
2025-10-08T15:49:46.722Z,1759938586.722 [Default:CheckIn:Read_Iridium] Stopped
2025-10-08T15:49:46.722Z,1759938586.722 [Default:CheckIn:C.Wait] Running Loop=1
2025-10-08T15:49:46.723Z,1759938586.723 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-10-08T15:50:35.598Z,1759938635.598 [NAL9602](FAULT): GPS failed to acquire within timeout.
2025-10-08T15:50:35.598Z,1759938635.598 [NAL9602] Data Fault, FailCount= 1
2025-10-08T15:50:35.598Z,1759938635.598 [NAL9602](ERROR): Data Fault
2025-10-08T15:50:35.644Z,1759938635.644 [CBIT](ERROR): Data Fault in component: NAL9602
2025-10-08T15:50:36.001Z,1759938636.001 [NAL9602](INFO): Powering down
2025-10-08T15:50:36.834Z,1759938636.834 [CBIT](INFO): Clearing failed state for component NAL9602
2025-10-08T15:50:36.834Z,1759938636.834 [NAL9602] No Fault, FailCount= 1
2025-10-08T15:50:45.982Z,1759938645.982 [CommandExec](IMPORTANT): got command burn off
2025-10-08T15:50:45.982Z,1759938645.982 [CommandExec](IMPORTANT): Deactivating dropweight wire
2025-10-08T15:51:06.298Z,1759938666.298 [NAL9602](INFO): Powering up NAL9602
2025-10-08T15:51:17.210Z,1759938677.210 [NAL9602](INFO): NAL9602 initialized
2025-10-08T15:51:57.612Z,1759938717.612 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2025-10-08T15:51:57.613Z,1759938717.613 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-10-08T15:51:57.623Z,1759938717.623 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-10-08T15:51:58.034Z,1759938718.034 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-10-08T15:51:58.034Z,1759938718.034 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2025-10-08T15:54:47.314Z,1759938887.314 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-10-08T15:54:47.315Z,1759938887.315 [Default:CheckIn:C.Wait] Stopped
2025-10-08T15:54:47.315Z,1759938887.315 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-10-08T15:54:47.315Z,1759938887.315 [Default:CheckIn:D] Running Loop=1
2025-10-08T15:54:47.709Z,1759938887.709 [Default:CheckIn:D] Stopped
2025-10-08T15:54:47.709Z,1759938887.709 [Default:CheckIn:E] Running Loop=1
2025-10-08T15:54:48.106Z,1759938888.106 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.678308 min
2025-10-08T15:54:48.107Z,1759938888.107 [Default:CheckIn:E] Stopped
2025-10-08T15:54:48.107Z,1759938888.107 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-10-08T15:54:48.107Z,1759938888.107 [Default:CheckIn] Stopped
2025-10-08T15:54:48.107Z,1759938888.107 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-10-08T15:54:48.107Z,1759938888.107 [Default:CheckIn](INFO): Running loop #2
2025-10-08T15:54:48.107Z,1759938888.107 [Default:CheckIn] Running Loop=2
2025-10-08T15:54:48.107Z,1759938888.107 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-10-08T15:54:48.107Z,1759938888.107 [Default:CheckIn:Read_GPS] Running Loop=1
2025-10-08T15:54:58.629Z,1759938898.629 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2025-10-08T15:54:58.629Z,1759938898.629 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-10-08T15:54:58.640Z,1759938898.640 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-10-08T15:54:59.039Z,1759938899.039 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-10-08T15:54:59.039Z,1759938899.039 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2025-10-08T15:57:59.653Z,1759939079.653 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6
2025-10-08T15:57:59.653Z,1759939079.653 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-10-08T15:57:59.684Z,1759939079.684 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-10-08T15:58:00.061Z,1759939080.061 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-10-08T15:58:00.061Z,1759939080.061 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6
2025-10-08T15:59:48.409Z,1759939188.409 [Default:CheckIn:Read_GPS](INFO): Timed out from 2025-10-08T15:54:48.1Z
2025-10-08T15:59:48.410Z,1759939188.410 [Default:CheckIn:Read_GPS] Stopped
2025-10-08T15:59:48.410Z,1759939188.410 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-10-08T15:59:56.536Z,1759939196.536 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20251008T153942/Courier0007.lzma
2025-10-08T15:59:57.538Z,1759939197.538 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153942/Courier0007.lzma.bak
2025-10-08T15:59:57.538Z,1759939197.538 [DataOverHttps](INFO): SBD MOMSN=26147854
2025-10-08T16:00:13.152Z,1759939213.152 [DataOverHttps](INFO): Sending 230 bytes from file Logs/20251008T153942/Express0008.lzma
2025-10-08T16:00:14.154Z,1759939214.154 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153942/Express0008.lzma.bak
2025-10-08T16:00:14.154Z,1759939214.154 [DataOverHttps](INFO): SBD MOMSN=26147863
2025-10-08T16:00:15.478Z,1759939215.478 [Default:CheckIn:Read_Iridium] Stopped
2025-10-08T16:00:15.478Z,1759939215.478 [Default:CheckIn:C.Wait] Running Loop=1
2025-10-08T16:00:15.478Z,1759939215.478 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-10-08T16:01:00.761Z,1759939260.761 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7
2025-10-08T16:01:00.761Z,1759939260.761 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-10-08T16:01:00.772Z,1759939260.772 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-10-08T16:01:01.175Z,1759939261.175 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-10-08T16:01:01.175Z,1759939261.175 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7
2025-10-08T16:01:19.334Z,1759939279.334 [NAL9602](FAULT): GPS failed to acquire within timeout.
2025-10-08T16:01:19.334Z,1759939279.334 [NAL9602] Data Fault, FailCount= 2
2025-10-08T16:01:19.334Z,1759939279.334 [NAL9602](ERROR): Data Fault
2025-10-08T16:01:19.401Z,1759939279.401 [CBIT](ERROR): Data Fault in component: NAL9602
2025-10-08T16:01:19.737Z,1759939279.737 [NAL9602](INFO): Powering down
2025-10-08T16:01:20.595Z,1759939280.595 [CBIT](INFO): Clearing failed state for component NAL9602
2025-10-08T16:01:20.595Z,1759939280.595 [NAL9602] No Fault, FailCount= 2
2025-10-08T16:01:50.038Z,1759939310.038 [NAL9602](INFO): Powering up NAL9602
2025-10-08T16:02:00.946Z,1759939320.946 [NAL9602](INFO): NAL9602 initialized
2025-10-08T16:04:01.813Z,1759939441.813 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8
2025-10-08T16:04:01.813Z,1759939441.813 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-10-08T16:04:01.823Z,1759939441.823 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-10-08T16:04:02.227Z,1759939442.227 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-10-08T16:04:02.227Z,1759939442.227 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8
2025-10-08T16:05:16.202Z,1759939516.202 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-10-08T16:05:16.203Z,1759939516.203 [Default:CheckIn:C.Wait] Stopped
2025-10-08T16:05:16.203Z,1759939516.203 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-10-08T16:05:16.203Z,1759939516.203 [Default:CheckIn:D] Running Loop=1
2025-10-08T16:05:16.607Z,1759939516.607 [Default:CheckIn:D] Stopped
2025-10-08T16:05:16.608Z,1759939516.608 [Default:CheckIn:E] Running Loop=1
2025-10-08T16:05:17.015Z,1759939517.015 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 21.159951 min
2025-10-08T16:05:17.015Z,1759939517.015 [Default:CheckIn:E] Stopped
2025-10-08T16:05:17.015Z,1759939517.015 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-10-08T16:05:17.015Z,1759939517.015 [Default:CheckIn] Stopped
2025-10-08T16:05:17.015Z,1759939517.015 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-10-08T16:05:17.015Z,1759939517.015 [Default:CheckIn](INFO): Running loop #3
2025-10-08T16:05:17.015Z,1759939517.015 [Default:CheckIn] Running Loop=3
2025-10-08T16:05:17.015Z,1759939517.015 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-10-08T16:05:17.015Z,1759939517.015 [Default:CheckIn:Read_GPS] Running Loop=1
2025-10-08T16:07:02.868Z,1759939622.868 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 9
2025-10-08T16:07:02.868Z,1759939622.868 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-10-08T16:07:02.878Z,1759939622.878 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-10-08T16:07:03.317Z,1759939623.317 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-10-08T16:07:03.317Z,1759939623.317 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 9
2025-10-08T16:08:03.875Z,1759939683.875 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160803.00,A,3648.16933,N,12147.28168,W,0.330,0.00,081025,,,A*7D
2025-10-08T16:08:03.879Z,1759939683.879 [NAL9602](INFO): GPS fix at 20251008T160803: (36.802822, -121.788028)
2025-10-08T16:08:03.891Z,1759939683.891 [Default:CheckIn:Read_GPS] Stopped
2025-10-08T16:08:03.891Z,1759939683.891 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-10-08T16:08:11.304Z,1759939691.304 [DataOverHttps](INFO): Sending 223 bytes from file Logs/20251008T153942/Courier0010.lzma
2025-10-08T16:08:12.306Z,1759939692.306 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153942/Courier0010.lzma.bak
2025-10-08T16:08:12.306Z,1759939692.306 [DataOverHttps](INFO): SBD MOMSN=26147967
2025-10-08T16:08:29.081Z,1759939709.081 [DataOverHttps](INFO): Sending 374 bytes from file Logs/20251008T153942/Express0011.lzma
2025-10-08T16:08:30.082Z,1759939710.082 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153942/Express0011.lzma.bak
2025-10-08T16:08:30.082Z,1759939710.082 [DataOverHttps](INFO): SBD MOMSN=26147970
2025-10-08T16:08:31.353Z,1759939711.353 [Default:CheckIn:Read_Iridium] Stopped
2025-10-08T16:08:31.353Z,1759939711.353 [Default:CheckIn:C.Wait] Running Loop=1
2025-10-08T16:08:31.353Z,1759939711.353 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-10-08T16:08:36.602Z,1759939716.602 [NAL9602](INFO): Not Powering down - fast GPS
2025-10-08T16:13:31.955Z,1759940011.955 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-10-08T16:13:31.955Z,1759940011.955 [Default:CheckIn:C.Wait] Stopped
2025-10-08T16:13:31.955Z,1759940011.955 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-10-08T16:13:31.955Z,1759940011.955 [Default:CheckIn:D] Running Loop=1
2025-10-08T16:13:32.356Z,1759940012.356 [Default:CheckIn:D] Stopped
2025-10-08T16:13:32.356Z,1759940012.356 [Default:CheckIn:E] Running Loop=1
2025-10-08T16:13:32.753Z,1759940012.753 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 29.422422 min
2025-10-08T16:13:32.753Z,1759940012.753 [Default:CheckIn:E] Stopped
2025-10-08T16:13:32.753Z,1759940012.753 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-10-08T16:13:32.753Z,1759940012.753 [Default:CheckIn] Stopped
2025-10-08T16:13:32.753Z,1759940012.753 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-10-08T16:13:32.753Z,1759940012.753 [Default:CheckIn](INFO): Running loop #4
2025-10-08T16:13:32.753Z,1759940012.753 [Default:CheckIn] Running Loop=4
2025-10-08T16:13:32.753Z,1759940012.753 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-10-08T16:13:32.753Z,1759940012.753 [Default:CheckIn:Read_GPS] Running Loop=1
2025-10-08T16:13:34.768Z,1759940014.768 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,161334.00,A,3648.15000,N,12147.22647,W,0.078,35.37,081025,,,D*41
2025-10-08T16:13:34.770Z,1759940014.770 [NAL9602](INFO): GPS fix at 20251008T161334: (36.802500, -121.787108)
2025-10-08T16:13:34.782Z,1759940014.782 [Default:CheckIn:Read_GPS] Stopped
2025-10-08T16:13:34.782Z,1759940014.782 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-10-08T16:13:42.404Z,1759940022.404 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20251008T153942/Courier0013.lzma
2025-10-08T16:13:43.406Z,1759940023.406 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153942/Courier0013.lzma.bak
2025-10-08T16:13:43.406Z,1759940023.406 [DataOverHttps](INFO): SBD MOMSN=26148016
2025-10-08T16:13:50.115Z,1759940030.115 [NAL9602](INFO): SBD MO Status=0, MOMSN=28361, MT Status=0, MTMSN=0
2025-10-08T16:13:50.116Z,1759940030.116 [NAL9602](INFO): No messages in MT queue
2025-10-08T16:13:59.352Z,1759940039.352 [DataOverHttps](INFO): Sending 173 bytes from file Logs/20251008T153942/Express0014.lzma
2025-10-08T16:14:00.354Z,1759940040.354 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153942/Express0014.lzma.bak
2025-10-08T16:14:00.354Z,1759940040.354 [DataOverHttps](INFO): SBD MOMSN=26148019
2025-10-08T16:14:01.441Z,1759940041.441 [Default:CheckIn:Read_Iridium] Stopped
2025-10-08T16:14:01.442Z,1759940041.442 [Default:CheckIn:C.Wait] Running Loop=1
2025-10-08T16:14:01.442Z,1759940041.442 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-10-08T16:14:20.821Z,1759940060.821 [NAL9602](INFO): Not Powering down - fast GPS
2025-10-08T16:19:02.021Z,1759940342.021 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-10-08T16:19:02.021Z,1759940342.021 [Default:CheckIn:C.Wait] Stopped
2025-10-08T16:19:02.021Z,1759940342.021 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-10-08T16:19:02.021Z,1759940342.021 [Default:CheckIn:D] Running Loop=1
2025-10-08T16:19:02.427Z,1759940342.427 [Default:CheckIn:D] Stopped
2025-10-08T16:19:02.427Z,1759940342.427 [Default:CheckIn:E] Running Loop=1
2025-10-08T16:19:02.840Z,1759940342.840 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 34.923604 min
2025-10-08T16:19:02.840Z,1759940342.840 [Default:CheckIn:E] Stopped
2025-10-08T16:19:02.840Z,1759940342.840 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-10-08T16:19:02.840Z,1759940342.840 [Default:CheckIn] Stopped
2025-10-08T16:19:02.840Z,1759940342.840 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-10-08T16:19:02.840Z,1759940342.840 [Default:CheckIn](INFO): Running loop #5
2025-10-08T16:19:02.841Z,1759940342.841 [Default:CheckIn] Running Loop=5
2025-10-08T16:19:02.841Z,1759940342.841 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-10-08T16:19:02.841Z,1759940342.841 [Default:CheckIn:Read_GPS] Running Loop=1
2025-10-08T16:19:04.839Z,1759940344.839 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,161904.00,A,3648.15066,N,12147.22983,W,0.078,35.37,081025,,,D*4F
2025-10-08T16:19:04.842Z,1759940344.842 [NAL9602](INFO): GPS fix at 20251008T161904: (36.802511, -121.787164)
2025-10-08T16:19:04.869Z,1759940344.869 [Default:CheckIn:Read_GPS] Stopped
2025-10-08T16:19:04.869Z,1759940344.869 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-10-08T16:19:12.580Z,1759940352.580 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20251008T153942/Courier0016.lzma
2025-10-08T16:19:13.582Z,1759940353.582 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153942/Courier0016.lzma.bak
2025-10-08T16:19:13.582Z,1759940353.582 [DataOverHttps](INFO): SBD MOMSN=26148092
2025-10-08T16:19:29.472Z,1759940369.472 [DataOverHttps](INFO): Sending 152 bytes from file Logs/20251008T153942/Express0017.lzma
2025-10-08T16:19:30.474Z,1759940370.474 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153942/Express0017.lzma.bak
2025-10-08T16:19:30.474Z,1759940370.474 [DataOverHttps](INFO): SBD MOMSN=26148095
2025-10-08T16:19:31.543Z,1759940371.543 [Default:CheckIn:Read_Iridium] Stopped
2025-10-08T16:19:31.543Z,1759940371.543 [Default:CheckIn:C.Wait] Running Loop=1
2025-10-08T16:19:31.543Z,1759940371.543 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-10-08T16:19:34.363Z,1759940374.363 [NAL9602](INFO): SBD MO Status=2, MOMSN=28362, MT Status=2, MTMSN=0
2025-10-08T16:19:34.363Z,1759940374.363 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-10-08T16:20:09.511Z,1759940409.511 [NAL9602](INFO): SBD MO Status=0, MOMSN=28362, MT Status=0, MTMSN=0
2025-10-08T16:20:09.511Z,1759940409.511 [NAL9602](INFO): No messages in MT queue
2025-10-08T16:20:40.217Z,1759940440.217 [NAL9602](INFO): Not Powering down - fast GPS
2025-10-08T16:24:32.139Z,1759940672.139 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-10-08T16:24:32.139Z,1759940672.139 [Default:CheckIn:C.Wait] Stopped
2025-10-08T16:24:32.139Z,1759940672.139 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-10-08T16:24:32.139Z,1759940672.139 [Default:CheckIn:D] Running Loop=1
2025-10-08T16:24:32.547Z,1759940672.547 [Default:CheckIn:D] Stopped
2025-10-08T16:24:32.548Z,1759940672.548 [Default:CheckIn:E] Running Loop=1
2025-10-08T16:24:32.946Z,1759940672.946 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 40.425618 min
2025-10-08T16:24:32.946Z,1759940672.946 [Default:CheckIn:E] Stopped
2025-10-08T16:24:32.946Z,1759940672.946 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-10-08T16:24:32.946Z,1759940672.946 [Default:CheckIn] Stopped
2025-10-08T16:24:32.946Z,1759940672.946 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-10-08T16:24:32.946Z,1759940672.946 [Default:CheckIn](INFO): Running loop #6
2025-10-08T16:24:32.946Z,1759940672.946 [Default:CheckIn] Running Loop=6
2025-10-08T16:24:32.946Z,1759940672.946 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-10-08T16:24:32.947Z,1759940672.947 [Default:CheckIn:Read_GPS] Running Loop=1
2025-10-08T16:24:34.956Z,1759940674.956 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162434.00,A,3648.15278,N,12147.22316,W,0.253,8.18,081025,,,D*71
2025-10-08T16:24:34.958Z,1759940674.958 [NAL9602](INFO): GPS fix at 20251008T162434: (36.802546, -121.787053)
2025-10-08T16:24:34.970Z,1759940674.970 [Default:CheckIn:Read_GPS] Stopped
2025-10-08T16:24:34.970Z,1759940674.970 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-10-08T16:24:42.732Z,1759940682.732 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20251008T153942/Courier0019.lzma
2025-10-08T16:24:43.734Z,1759940683.734 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153942/Courier0019.lzma.bak
2025-10-08T16:24:43.734Z,1759940683.734 [DataOverHttps](INFO): SBD MOMSN=26148140
2025-10-08T16:24:55.611Z,1759940695.611 [NAL9602](INFO): SBD MO Status=0, MOMSN=28363, MT Status=0, MTMSN=0
2025-10-08T16:24:55.611Z,1759940695.611 [NAL9602](INFO): No messages in MT queue
2025-10-08T16:25:02.388Z,1759940702.388 [DataOverHttps](INFO): Sending 157 bytes from file Logs/20251008T153942/Express0020.lzma
2025-10-08T16:25:03.391Z,1759940703.391 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153942/Express0020.lzma.bak
2025-10-08T16:25:03.391Z,1759940703.391 [DataOverHttps](INFO): SBD MOMSN=26148146
2025-10-08T16:25:04.505Z,1759940704.505 [Default:CheckIn:Read_Iridium] Stopped
2025-10-08T16:25:04.505Z,1759940704.505 [Default:CheckIn:C.Wait] Running Loop=1
2025-10-08T16:25:04.505Z,1759940704.505 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-10-08T16:25:26.309Z,1759940726.309 [NAL9602](INFO): Not Powering down - fast GPS
2025-10-08T16:27:06.173Z,1759940826.173 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-10-08T16:27:37.317Z,1759940857.317 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-10-08T16:28:49.750Z,1759940929.750 [DataOverHttps](IMPORTANT): SBD MTMSN=20251008T162848
2025-10-08T16:28:57.724Z,1759940937.724 [DataOverHttps](INFO): Received command: failc
2025-10-08T16:28:57.761Z,1759940937.761 [CommandExec](IMPORTANT): got command failComponent
2025-10-08T16:28:57.761Z,1759940937.761 [CommandExec](IMPORTANT): Failed components:
2025-10-08T16:28:57.761Z,1759940937.761 [CommandExec](IMPORTANT): No failed Components.
2025-10-08T16:28:58.727Z,1759940938.727 [DataOverHttps](IMPORTANT): SBD MTMSN=20251008T162857
2025-10-08T16:29:06.252Z,1759940946.252 [DataOverHttps](INFO): Received command: ibit
2025-10-08T16:29:06.317Z,1759940946.317 [CommandExec](IMPORTANT): got command ibit
2025-10-08T16:29:06.563Z,1759940946.563 [IBIT](IMPORTANT): Beginning Initiated BIT
2025-10-08T16:29:06.563Z,1759940946.563 [IBIT](IMPORTANT): Beginning control surface checks.
2025-10-08T16:29:06.567Z,1759940946.567 [GFScanner](IMPORTANT): Beginning ground fault scan
2025-10-08T16:29:08.155Z,1759940948.155 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162907.00,A,3648.15173,N,12147.22103,W,0.097,17.82,081025,,,D*45
2025-10-08T16:29:08.165Z,1759940948.165 [NAL9602](INFO): GPS fix at 20251008T162907: (36.802529, -121.787017)
2025-10-08T16:29:11.080Z,1759940951.080 [GFScanner](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): 0.002293
CHAN A1 (24V): 0.000927
CHAN A2 (12V): 0.000693
CHAN A3 (5V): -0.001783
CHAN B0 (3.3V): 0.000476
CHAN B1 (3.15aV): 0.000140
CHAN B2 (3.15bV): -0.000029
CHAN B3 (GND): -0.000350
OPEN: 0.006538
Full Scale: +/- 1 mA
2025-10-08T16:29:28.367Z,1759940968.367 [NAL9602](INFO): SBD MO Status=0, MOMSN=28364, MT Status=0, MTMSN=0
2025-10-08T16:29:28.368Z,1759940968.368 [NAL9602](INFO): No messages in MT queue
2025-10-08T16:29:29.587Z,1759940969.587 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162928.00,A,3648.15098,N,12147.22247,W,0.078,17.82,081025,,,D*4E
2025-10-08T16:29:29.590Z,1759940969.590 [NAL9602](INFO): GPS fix at 20251008T162928: (36.802516, -121.787041)
2025-10-08T16:29:32.008Z,1759940972.008 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162931.00,A,3648.15100,N,12147.22274,W,0.058,17.82,081025,,,D*44
2025-10-08T16:29:32.010Z,1759940972.010 [NAL9602](INFO): GPS fix at 20251008T162931: (36.802517, -121.787046)
2025-10-08T16:29:34.831Z,1759940974.831 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162934.00,A,3648.15106,N,12147.22287,W,0.058,17.82,081025,,,D*4B
2025-10-08T16:29:34.834Z,1759940974.834 [NAL9602](INFO): GPS fix at 20251008T162934: (36.802518, -121.787048)
2025-10-08T16:29:38.063Z,1759940978.063 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162937.00,A,3648.15112,N,12147.22291,W,0.078,17.82,081025,,,D*48
2025-10-08T16:29:38.066Z,1759940978.066 [NAL9602](INFO): GPS fix at 20251008T162937: (36.802519, -121.787048)
2025-10-08T16:29:40.892Z,1759940980.892 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162940.00,A,3648.15121,N,12147.22293,W,0.019,17.82,081025,,,D*4D
2025-10-08T16:29:40.894Z,1759940980.894 [NAL9602](INFO): GPS fix at 20251008T162940: (36.802520, -121.787049)
2025-10-08T16:29:44.127Z,1759940984.127 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162943.00,A,3648.15136,N,12147.22287,W,0.019,17.82,081025,,,D*4D
2025-10-08T16:29:44.129Z,1759940984.129 [NAL9602](INFO): GPS fix at 20251008T162943: (36.802523, -121.787048)
2025-10-08T16:29:46.955Z,1759940986.955 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162946.00,A,3648.15146,N,12147.22278,W,0.019,17.82,081025,,,D*4F
2025-10-08T16:29:46.957Z,1759940986.957 [NAL9602](INFO): GPS fix at 20251008T162946: (36.802524, -121.787046)
2025-10-08T16:29:49.787Z,1759940989.787 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162949.00,A,3648.15161,N,12147.22268,W,0.019,17.82,081025,,,D*44
2025-10-08T16:29:49.790Z,1759940989.790 [NAL9602](INFO): GPS fix at 20251008T162949: (36.802527, -121.787045)
2025-10-08T16:29:53.015Z,1759940993.015 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162952.00,A,3648.15168,N,12147.22256,W,0.019,17.82,081025,,,D*4A
2025-10-08T16:29:53.017Z,1759940993.017 [NAL9602](INFO): GPS fix at 20251008T162952: (36.802528, -121.787043)
2025-10-08T16:29:53.060Z,1759940993.060 [IBIT](IMPORTANT): Communications Status:
Fix Status: 1
Iridium Signal Strength: 5
Latitude: 36.802528 Longitude: -121.787041
2025-10-08T16:29:53.474Z,1759940993.474 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 0.000000
Voltage: 16.650999
2025-10-08T16:29:53.474Z,1759940993.474 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah
2025-10-08T16:29:53.474Z,1759940993.474 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V
2025-10-08T16:29:53.836Z,1759940993.836 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2025-10-08T16:29:53.836Z,1759940993.836 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2025-10-08T16:29:53.837Z,1759940993.837 [IBIT](IMPORTANT): Pressure:10.142414 PSI
2025-10-08T16:29:53.837Z,1759940993.837 [IBIT](IMPORTANT): Humidity:23.818825 %
2025-10-08T16:29:54.256Z,1759940994.256 [IBIT](IMPORTANT): Vehicle Pitch:0.212541 degrees
2025-10-08T16:29:54.257Z,1759940994.257 [IBIT](IMPORTANT): Vehicle Roll:4.742583 degrees
2025-10-08T16:29:54.257Z,1759940994.257 [IBIT](IMPORTANT): Vehicle Heading:209.395493 degrees
2025-10-08T16:29:54.668Z,1759940994.668 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2025-10-08T16:29:54.669Z,1759940994.669 [IBIT](IMPORTANT): buoyancyNeutral: 212.440353 cc
2025-10-08T16:29:54.669Z,1759940994.669 [IBIT](IMPORTANT): massDefault: 2.358549 cm
2025-10-08T16:29:54.669Z,1759940994.669 [IBIT](IMPORTANT): stopDepth: 290.000000 m
2025-10-08T16:29:54.670Z,1759940994.670 [IBIT](IMPORTANT): abortDepth: 300.000000 m
2025-10-08T16:29:54.670Z,1759940994.670 [IBIT](IMPORTANT): IBIT PASSED
2025-10-08T16:30:05.158Z,1759941005.158 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-10-08T16:30:05.158Z,1759941005.158 [Default:CheckIn:C.Wait] Stopped
2025-10-08T16:30:05.158Z,1759941005.158 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-10-08T16:30:05.158Z,1759941005.158 [Default:CheckIn:D] Running Loop=1
2025-10-08T16:30:05.569Z,1759941005.569 [Default:CheckIn:D] Stopped
2025-10-08T16:30:05.569Z,1759941005.569 [Default:CheckIn:E] Running Loop=1
2025-10-08T16:30:05.983Z,1759941005.983 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 45.975977 min
2025-10-08T16:30:05.984Z,1759941005.984 [Default:CheckIn:E] Stopped
2025-10-08T16:30:05.984Z,1759941005.984 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-10-08T16:30:05.984Z,1759941005.984 [Default:CheckIn] Stopped
2025-10-08T16:30:05.988Z,1759941005.988 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-10-08T16:30:05.988Z,1759941005.988 [Default:CheckIn](INFO): Running loop #7
2025-10-08T16:30:05.988Z,1759941005.988 [Default:CheckIn] Running Loop=7
2025-10-08T16:30:05.988Z,1759941005.988 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-10-08T16:30:05.989Z,1759941005.989 [Default:CheckIn:Read_GPS] Running Loop=1
2025-10-08T16:30:07.962Z,1759941007.962 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163007.00,A,3648.15206,N,12147.22208,W,0.039,17.82,081025,,,D*40
2025-10-08T16:30:07.965Z,1759941007.965 [NAL9602](INFO): GPS fix at 20251008T163007: (36.802534, -121.787035)
2025-10-08T16:30:07.976Z,1759941007.976 [Default:CheckIn:Read_GPS] Stopped
2025-10-08T16:30:07.976Z,1759941007.976 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-10-08T16:30:16.028Z,1759941016.028 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20251008T153942/Courier0022.lzma
2025-10-08T16:30:17.030Z,1759941017.030 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153942/Courier0022.lzma.bak
2025-10-08T16:30:17.030Z,1759941017.030 [DataOverHttps](INFO): SBD MOMSN=26148233
2025-10-08T16:30:32.955Z,1759941032.955 [DataOverHttps](INFO): Sending 1021 bytes from file Logs/20251008T153942/Express0023.lzma
2025-10-08T16:30:33.954Z,1759941033.954 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153942/Express0023.lzma.bak
2025-10-08T16:30:33.954Z,1759941033.954 [DataOverHttps](INFO): SBD MOMSN=26148236
2025-10-08T16:30:35.038Z,1759941035.038 [Default:CheckIn:Read_Iridium] Stopped
2025-10-08T16:30:35.038Z,1759941035.038 [Default:CheckIn:C.Wait] Running Loop=1
2025-10-08T16:30:35.038Z,1759941035.038 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-10-08T16:30:40.290Z,1759941040.290 [NAL9602](INFO): Not Powering down - fast GPS
2025-10-08T16:35:35.613Z,1759941335.613 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-10-08T16:35:35.614Z,1759941335.614 [Default:CheckIn:C.Wait] Stopped
2025-10-08T16:35:35.614Z,1759941335.614 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-10-08T16:35:35.614Z,1759941335.614 [Default:CheckIn:D] Running Loop=1
2025-10-08T16:35:36.020Z,1759941336.020 [Default:CheckIn:D] Stopped
2025-10-08T16:35:36.020Z,1759941336.020 [Default:CheckIn:E] Running Loop=1
2025-10-08T16:35:36.422Z,1759941336.422 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 51.483488 min
2025-10-08T16:35:36.423Z,1759941336.423 [Default:CheckIn:E] Stopped
2025-10-08T16:35:36.423Z,1759941336.423 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-10-08T16:35:36.423Z,1759941336.423 [Default:CheckIn] Stopped
2025-10-08T16:35:36.423Z,1759941336.423 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-10-08T16:35:36.423Z,1759941336.423 [Default:CheckIn](INFO): Running loop #8
2025-10-08T16:35:36.423Z,1759941336.423 [Default:CheckIn] Running Loop=8
2025-10-08T16:35:36.423Z,1759941336.423 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-10-08T16:35:36.423Z,1759941336.423 [Default:CheckIn:Read_GPS] Running Loop=1
2025-10-08T16:35:38.435Z,1759941338.435 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163537.00,A,3648.16702,N,12147.20808,W,0.350,58.44,081025,,,A*44
2025-10-08T16:35:38.437Z,1759941338.437 [NAL9602](INFO): GPS fix at 20251008T163537: (36.802784, -121.786801)
2025-10-08T16:35:38.464Z,1759941338.464 [Default:CheckIn:Read_GPS] Stopped
2025-10-08T16:35:38.465Z,1759941338.465 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-10-08T16:35:45.992Z,1759941345.992 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20251008T153942/Courier0025.lzma
2025-10-08T16:35:46.994Z,1759941346.994 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153942/Courier0025.lzma.bak
2025-10-08T16:35:46.994Z,1759941346.994 [DataOverHttps](INFO): SBD MOMSN=26148360
2025-10-08T16:35:54.607Z,1759941354.607 [NAL9602](INFO): SBD MO Status=0, MOMSN=28365, MT Status=0, MTMSN=0
2025-10-08T16:35:54.608Z,1759941354.608 [NAL9602](INFO): No messages in MT queue
2025-10-08T16:36:02.920Z,1759941362.920 [DataOverHttps](INFO): Sending 173 bytes from file Logs/20251008T153942/Express0027.lzma
2025-10-08T16:36:03.922Z,1759941363.922 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153942/Express0027.lzma.bak
2025-10-08T16:36:03.922Z,1759941363.922 [DataOverHttps](INFO): SBD MOMSN=26148363
2025-10-08T16:36:05.117Z,1759941365.117 [Default:CheckIn:Read_Iridium] Stopped
2025-10-08T16:36:05.117Z,1759941365.117 [Default:CheckIn:C.Wait] Running Loop=1
2025-10-08T16:36:05.117Z,1759941365.117 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-10-08T16:36:25.309Z,1759941385.309 [NAL9602](INFO): Not Powering down - fast GPS
2025-10-08T16:41:05.737Z,1759941665.737 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-10-08T16:41:05.737Z,1759941665.737 [Default:CheckIn:C.Wait] Stopped
2025-10-08T16:41:05.737Z,1759941665.737 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-10-08T16:41:05.737Z,1759941665.737 [Default:CheckIn:D] Running Loop=1
2025-10-08T16:41:06.144Z,1759941666.144 [Default:CheckIn:D] Stopped
2025-10-08T16:41:06.145Z,1759941666.145 [Default:CheckIn:E] Running Loop=1
2025-10-08T16:41:06.556Z,1759941666.556 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 56.985567 min
2025-10-08T16:41:06.556Z,1759941666.556 [Default:CheckIn:E] Stopped
2025-10-08T16:41:06.556Z,1759941666.556 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-10-08T16:41:06.557Z,1759941666.556 [Default:CheckIn] Stopped
2025-10-08T16:41:06.557Z,1759941666.557 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-10-08T16:41:06.557Z,1759941666.557 [Default:CheckIn](INFO): Running loop #9
2025-10-08T16:41:06.557Z,1759941666.557 [Default:CheckIn] Running Loop=9
2025-10-08T16:41:06.557Z,1759941666.557 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-10-08T16:41:06.557Z,1759941666.557 [Default:CheckIn:Read_GPS] Running Loop=1
2025-10-08T16:41:08.555Z,1759941668.555 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164107.00,A,3648.16363,N,12147.21312,W,0.039,359.15,081025,,,D*79
2025-10-08T16:41:08.558Z,1759941668.558 [NAL9602](INFO): GPS fix at 20251008T164107: (36.802727, -121.786885)
2025-10-08T16:41:08.585Z,1759941668.585 [Default:CheckIn:Read_GPS] Stopped
2025-10-08T16:41:08.586Z,1759941668.586 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-10-08T16:41:15.668Z,1759941675.668 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20251008T153942/Courier0031.lzma
2025-10-08T16:41:16.670Z,1759941676.670 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153942/Courier0031.lzma.bak
2025-10-08T16:41:16.670Z,1759941676.670 [DataOverHttps](INFO): SBD MOMSN=26148436
2025-10-08T16:41:22.704Z,1759941682.704 [NAL9602](INFO): SBD MO Status=0, MOMSN=28366, MT Status=0, MTMSN=0
2025-10-08T16:41:22.704Z,1759941682.704 [NAL9602](INFO): No messages in MT queue
2025-10-08T16:41:32.500Z,1759941692.500 [DataOverHttps](INFO): Sending 154 bytes from file Logs/20251008T153942/Express0032.lzma
2025-10-08T16:41:33.502Z,1759941693.502 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153942/Express0032.lzma.bak
2025-10-08T16:41:33.502Z,1759941693.502 [DataOverHttps](INFO): SBD MOMSN=26148439
2025-10-08T16:41:34.824Z,1759941694.824 [Default:CheckIn:Read_Iridium] Stopped
2025-10-08T16:41:34.824Z,1759941694.824 [Default:CheckIn:C.Wait] Running Loop=1
2025-10-08T16:41:34.825Z,1759941694.825 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-10-08T16:41:53.401Z,1759941713.401 [NAL9602](INFO): Not Powering down - fast GPS
2025-10-08T16:46:35.424Z,1759941995.424 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-10-08T16:46:35.424Z,1759941995.424 [Default:CheckIn:C.Wait] Stopped
2025-10-08T16:46:35.424Z,1759941995.424 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-10-08T16:46:35.425Z,1759941995.425 [Default:CheckIn:D] Running Loop=1
2025-10-08T16:46:35.829Z,1759941995.829 [Default:CheckIn:D] Stopped
2025-10-08T16:46:35.829Z,1759941995.829 [Default:CheckIn:E] Running Loop=1
2025-10-08T16:46:36.235Z,1759941996.235 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 62.480306 min
2025-10-08T16:46:36.235Z,1759941996.235 [Default:CheckIn:E] Stopped
2025-10-08T16:46:36.235Z,1759941996.235 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-10-08T16:46:36.235Z,1759941996.235 [Default:CheckIn] Stopped
2025-10-08T16:46:36.235Z,1759941996.235 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-10-08T16:46:36.235Z,1759941996.235 [Default:CheckIn](INFO): Running loop #10
2025-10-08T16:46:36.235Z,1759941996.235 [Default:CheckIn] Running Loop=10
2025-10-08T16:46:36.235Z,1759941996.235 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-10-08T16:46:36.236Z,1759941996.236 [Default:CheckIn:Read_GPS] Running Loop=1
2025-10-08T16:46:38.243Z,1759941998.243 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164637.00,A,3648.16178,N,12147.21312,W,0.097,359.15,081025,,,D*71
2025-10-08T16:46:38.255Z,1759941998.255 [NAL9602](INFO): GPS fix at 20251008T164637: (36.802696, -121.786885)
2025-10-08T16:46:38.267Z,1759941998.267 [Default:CheckIn:Read_GPS] Stopped
2025-10-08T16:46:38.267Z,1759941998.267 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-10-08T16:46:47.696Z,1759942007.696 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20251008T153942/Courier0034.lzma
2025-10-08T16:46:48.701Z,1759942008.701 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153942/Courier0034.lzma.bak
2025-10-08T16:46:48.702Z,1759942008.702 [DataOverHttps](INFO): SBD MOMSN=26148487
2025-10-08T16:47:05.800Z,1759942025.800 [DataOverHttps](INFO): Sending 158 bytes from file Logs/20251008T153942/Express0035.lzma
2025-10-08T16:47:06.802Z,1759942026.802 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153942/Express0035.lzma.bak
2025-10-08T16:47:06.802Z,1759942026.802 [DataOverHttps](INFO): SBD MOMSN=26148490
2025-10-08T16:47:08.187Z,1759942028.187 [Default:CheckIn:Read_Iridium] Stopped
2025-10-08T16:47:08.187Z,1759942028.187 [Default:CheckIn:C.Wait] Running Loop=1
2025-10-08T16:47:08.187Z,1759942028.187 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-10-08T16:47:08.579Z,1759942028.579 [NAL9602](INFO): SBD MO Status=0, MOMSN=28367, MT Status=0, MTMSN=0
2025-10-08T16:47:08.579Z,1759942028.579 [NAL9602](INFO): No messages in MT queue
2025-10-08T16:47:39.277Z,1759942059.277 [NAL9602](INFO): Not Powering down - fast GPS
2025-10-08T16:50:14.081Z,1759942214.081 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-10-08T16:50:27.816Z,1759942227.816 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-10-08T16:50:41.553Z,1759942241.553 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-10-08T16:50:55.694Z,1759942255.694 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-10-08T16:51:09.024Z,1759942269.024 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-10-08T16:51:22.760Z,1759942282.760 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-10-08T16:51:36.900Z,1759942296.900 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-10-08T16:51:51.047Z,1759942311.047 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-10-08T16:52:05.192Z,1759942325.192 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-10-08T16:52:08.832Z,1759942328.832 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-10-08T16:52:08.832Z,1759942328.832 [Default:CheckIn:C.Wait] Stopped
2025-10-08T16:52:08.832Z,1759942328.832 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-10-08T16:52:08.832Z,1759942328.832 [Default:CheckIn:D] Running Loop=1
2025-10-08T16:52:09.244Z,1759942329.244 [Default:CheckIn:D] Stopped
2025-10-08T16:52:09.244Z,1759942329.244 [Default:CheckIn:E] Running Loop=1
2025-10-08T16:52:09.649Z,1759942329.649 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 68.037231 min
2025-10-08T16:52:09.649Z,1759942329.649 [Default:CheckIn:E] Stopped
2025-10-08T16:52:09.649Z,1759942329.649 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-10-08T16:52:09.649Z,1759942329.649 [Default:CheckIn] Stopped
2025-10-08T16:52:09.649Z,1759942329.649 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-10-08T16:52:09.649Z,1759942329.649 [Default:CheckIn](INFO): Running loop #11
2025-10-08T16:52:09.649Z,1759942329.649 [Default:CheckIn] Running Loop=11
2025-10-08T16:52:09.650Z,1759942329.650 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-10-08T16:52:09.650Z,1759942329.650 [Default:CheckIn:Read_GPS] Running Loop=1
2025-10-08T16:52:11.649Z,1759942331.649 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165210.00,A,3648.16340,N,12147.21347,W,0.019,359.15,081025,,,D*7E
2025-10-08T16:52:11.651Z,1759942331.651 [NAL9602](INFO): GPS fix at 20251008T165210: (36.802723, -121.786891)
2025-10-08T16:52:11.662Z,1759942331.662 [Default:CheckIn:Read_GPS] Stopped
2025-10-08T16:52:11.662Z,1759942331.662 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-10-08T16:52:18.525Z,1759942338.525 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-10-08T16:52:19.684Z,1759942339.684 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20251008T153942/Courier0037.lzma
2025-10-08T16:52:20.687Z,1759942340.687 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153942/Courier0037.lzma.bak
2025-10-08T16:52:20.687Z,1759942340.687 [DataOverHttps](INFO): SBD MOMSN=26148579
2025-10-08T16:52:25.791Z,1759942345.791 [NAL9602](INFO): SBD MO Status=0, MOMSN=28368, MT Status=0, MTMSN=0
2025-10-08T16:52:25.791Z,1759942345.791 [NAL9602](INFO): No messages in MT queue
2025-10-08T16:52:31.862Z,1759942351.862 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-10-08T16:52:38.468Z,1759942358.468 [DataOverHttps](INFO): Sending 154 bytes from file Logs/20251008T153942/Express0038.lzma
2025-10-08T16:52:39.470Z,1759942359.470 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153942/Express0038.lzma.bak
2025-10-08T16:52:39.470Z,1759942359.470 [DataOverHttps](INFO): SBD MOMSN=26148589
2025-10-08T16:52:40.744Z,1759942360.744 [Default:CheckIn:Read_Iridium] Stopped
2025-10-08T16:52:40.745Z,1759942360.745 [Default:CheckIn:C.Wait] Running Loop=1
2025-10-08T16:52:40.745Z,1759942360.745 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-10-08T16:52:56.546Z,1759942376.546 [NAL9602](INFO): Not Powering down - fast GPS
2025-10-08T16:54:55.784Z,1759942495.784 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-10-08T16:55:02.652Z,1759942502.652 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-10-08T16:55:17.611Z,1759942517.611 [BPC1](ERROR): Battery stick #17 (s/n: 0084) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0.
2025-10-08T16:55:17.612Z,1759942517.612 [BPC1](ERROR): Battery stick #24 (s/n: 01D3) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0.
2025-10-08T16:55:17.613Z,1759942517.613 [BPC1](ERROR): Battery stick #29 (s/n: 00A7) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4AD0.
2025-10-08T16:55:17.613Z,1759942517.613 [BPC1](ERROR): Battery stick #38 (s/n: 01BC) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0.
2025-10-08T16:55:17.614Z,1759942517.614 [BPC1](ERROR): Battery stick #51 (s/n: 01D6) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0.
2025-10-08T16:55:17.615Z,1759942517.615 [BPC1](ERROR): Battery stick #57 (s/n: 019F) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0.
2025-10-08T16:55:17.616Z,1759942517.616 [BPC1](ERROR): Battery stick #59 (s/n: 0184) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4AD0.
2025-10-08T16:55:17.620Z,1759942517.620 [BPC1](INFO): Calculating totals. Valid battery stick count: 39. Valid reserve battery stick count: 4.
2025-10-08T16:55:17.623Z,1759942517.623 [BPC1](INFO): Received data from all battery sticks.
2025-10-08T16:57:41.520Z,1759942661.520 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-10-08T16:57:41.520Z,1759942661.520 [Default:CheckIn:C.Wait] Stopped
2025-10-08T16:57:41.520Z,1759942661.520 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-10-08T16:57:41.520Z,1759942661.520 [Default:CheckIn:D] Running Loop=1
2025-10-08T16:57:41.925Z,1759942661.925 [Default:CheckIn:D] Stopped
2025-10-08T16:57:41.925Z,1759942661.925 [Default:CheckIn:E] Running Loop=1
2025-10-08T16:57:42.330Z,1759942662.330 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 73.581901 min
2025-10-08T16:57:42.330Z,1759942662.330 [Default:CheckIn:E] Stopped
2025-10-08T16:57:42.331Z,1759942662.331 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-10-08T16:57:42.331Z,1759942662.331 [Default:CheckIn] Stopped
2025-10-08T16:57:42.331Z,1759942662.331 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-10-08T16:57:42.331Z,1759942662.331 [Default:CheckIn](INFO): Running loop #12
2025-10-08T16:57:42.331Z,1759942662.331 [Default:CheckIn] Running Loop=12
2025-10-08T16:57:42.331Z,1759942662.331 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-10-08T16:57:42.331Z,1759942662.331 [Default:CheckIn:Read_GPS] Running Loop=1
2025-10-08T16:57:44.331Z,1759942664.331 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165743.00,A,3648.16121,N,12147.21150,W,0.078,359.15,081025,,,D*7B
2025-10-08T16:57:44.334Z,1759942664.334 [NAL9602](INFO): GPS fix at 20251008T165743: (36.802687, -121.786858)
2025-10-08T16:57:44.345Z,1759942664.345 [Default:CheckIn:Read_GPS] Stopped
2025-10-08T16:57:44.345Z,1759942664.345 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-10-08T16:57:51.992Z,1759942671.992 [DataOverHttps](INFO): Sending 83 bytes from file Logs/20251008T153942/Courier0040.lzma
2025-10-08T16:57:52.994Z,1759942672.994 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153942/Courier0040.lzma.bak
2025-10-08T16:57:52.994Z,1759942672.994 [DataOverHttps](INFO): SBD MOMSN=26148629
2025-10-08T16:58:08.952Z,1759942688.952 [DataOverHttps](INFO): Sending 155 bytes from file Logs/20251008T153942/Express0041.lzma
2025-10-08T16:58:09.954Z,1759942689.954 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153942/Express0041.lzma.bak
2025-10-08T16:58:09.954Z,1759942689.954 [DataOverHttps](INFO): SBD MOMSN=26148632
2025-10-08T16:58:11.033Z,1759942691.033 [Default:CheckIn:Read_Iridium] Stopped
2025-10-08T16:58:11.033Z,1759942691.033 [Default:CheckIn:C.Wait] Running Loop=1
2025-10-08T16:58:11.033Z,1759942691.033 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-10-08T16:58:32.013Z,1759942712.013 [NAL9602](INFO): SBD MO Status=0, MOMSN=28369, MT Status=0, MTMSN=0
2025-10-08T16:58:32.013Z,1759942712.013 [NAL9602](INFO): No messages in MT queue
2025-10-08T16:59:02.746Z,1759942742.746 [NAL9602](INFO): Not Powering down - fast GPS
2025-10-08T17:03:11.716Z,1759942991.716 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-10-08T17:03:11.716Z,1759942991.716 [Default:CheckIn:C.Wait] Stopped
2025-10-08T17:03:11.717Z,1759942991.717 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-10-08T17:03:11.717Z,1759942991.717 [Default:CheckIn:D] Running Loop=1
2025-10-08T17:03:12.121Z,1759942992.121 [Default:CheckIn:D] Stopped
2025-10-08T17:03:12.121Z,1759942992.121 [Default:CheckIn:E] Running Loop=1
2025-10-08T17:03:12.535Z,1759942992.535 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 79.085181 min
2025-10-08T17:03:12.535Z,1759942992.535 [Default:CheckIn:E] Stopped
2025-10-08T17:03:12.535Z,1759942992.535 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-10-08T17:03:12.535Z,1759942992.535 [Default:CheckIn] Stopped
2025-10-08T17:03:12.535Z,1759942992.535 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-10-08T17:03:12.535Z,1759942992.535 [Default:CheckIn](INFO): Running loop #13
2025-10-08T17:03:12.535Z,1759942992.535 [Default:CheckIn] Running Loop=13
2025-10-08T17:03:12.535Z,1759942992.535 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-10-08T17:03:12.535Z,1759942992.535 [Default:CheckIn:Read_GPS] Running Loop=1
2025-10-08T17:03:14.539Z,1759942994.539 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170313.00,A,3648.16364,N,12147.21450,W,0.000,359.15,081025,,,D*77
2025-10-08T17:03:14.541Z,1759942994.541 [NAL9602](INFO): GPS fix at 20251008T170313: (36.802727, -121.786908)
2025-10-08T17:03:14.569Z,1759942994.569 [Default:CheckIn:Read_GPS] Stopped
2025-10-08T17:03:14.569Z,1759942994.569 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-10-08T17:03:22.316Z,1759943002.316 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20251008T153942/Courier0043.lzma
2025-10-08T17:03:23.318Z,1759943003.318 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153942/Courier0043.lzma.bak
2025-10-08T17:03:23.318Z,1759943003.318 [DataOverHttps](INFO): SBD MOMSN=26148743
2025-10-08T17:03:29.079Z,1759943009.079 [NAL9602](INFO): SBD MO Status=0, MOMSN=28370, MT Status=0, MTMSN=0
2025-10-08T17:03:29.079Z,1759943009.079 [NAL9602](INFO): No messages in MT queue
2025-10-08T17:03:39.152Z,1759943019.152 [DataOverHttps](INFO): Sending 154 bytes from file Logs/20251008T153942/Express0044.lzma
2025-10-08T17:03:40.154Z,1759943020.154 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153942/Express0044.lzma.bak
2025-10-08T17:03:40.154Z,1759943020.154 [DataOverHttps](INFO): SBD MOMSN=26148746
2025-10-08T17:03:41.210Z,1759943021.210 [Default:CheckIn:Read_Iridium] Stopped
2025-10-08T17:03:41.210Z,1759943021.210 [Default:CheckIn:C.Wait] Running Loop=1
2025-10-08T17:03:41.210Z,1759943021.210 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-10-08T17:03:59.782Z,1759943039.782 [NAL9602](INFO): Not Powering down - fast GPS
2025-10-08T17:08:41.868Z,1759943321.868 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-10-08T17:08:41.868Z,1759943321.868 [Default:CheckIn:C.Wait] Stopped
2025-10-08T17:08:41.868Z,1759943321.868 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-10-08T17:08:41.868Z,1759943321.868 [Default:CheckIn:D] Running Loop=1
2025-10-08T17:08:42.273Z,1759943322.273 [Default:CheckIn:D] Stopped
2025-10-08T17:08:42.273Z,1759943322.273 [Default:CheckIn:E] Running Loop=1
2025-10-08T17:08:42.678Z,1759943322.678 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 84.587712 min
2025-10-08T17:08:42.678Z,1759943322.678 [Default:CheckIn:E] Stopped
2025-10-08T17:08:42.678Z,1759943322.678 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-10-08T17:08:42.679Z,1759943322.679 [Default:CheckIn] Stopped
2025-10-08T17:08:42.679Z,1759943322.679 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-10-08T17:08:42.679Z,1759943322.679 [Default:CheckIn](INFO): Running loop #14
2025-10-08T17:08:42.679Z,1759943322.679 [Default:CheckIn] Running Loop=14
2025-10-08T17:08:42.679Z,1759943322.679 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-10-08T17:08:42.679Z,1759943322.679 [Default:CheckIn:Read_GPS] Running Loop=1
2025-10-08T17:08:44.691Z,1759943324.691 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170843.00,A,3648.16727,N,12147.20576,W,1.380,41.52,081025,,,D*4D
2025-10-08T17:08:44.710Z,1759943324.710 [NAL9602](INFO): GPS fix at 20251008T170843: (36.802788, -121.786763)
2025-10-08T17:08:44.730Z,1759943324.730 [Default:CheckIn:Read_GPS] Stopped
2025-10-08T17:08:44.730Z,1759943324.730 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-10-08T17:08:55.336Z,1759943335.336 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20251008T153942/Courier0046.lzma
2025-10-08T17:08:56.338Z,1759943336.338 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153942/Courier0046.lzma.bak
2025-10-08T17:08:56.338Z,1759943336.338 [DataOverHttps](INFO): SBD MOMSN=26148759
2025-10-08T17:09:01.703Z,1759943341.703 [NAL9602](INFO): SBD MO Status=0, MOMSN=28371, MT Status=0, MTMSN=0
2025-10-08T17:09:01.703Z,1759943341.703 [NAL9602](INFO): No messages in MT queue
2025-10-08T17:09:12.190Z,1759943352.190 [DataOverHttps](INFO): Sending 158 bytes from file Logs/20251008T153942/Express0047.lzma
2025-10-08T17:09:13.187Z,1759943353.187 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153942/Express0047.lzma.bak
2025-10-08T17:09:13.187Z,1759943353.187 [DataOverHttps](INFO): SBD MOMSN=26148762
2025-10-08T17:09:14.233Z,1759943354.233 [Default:CheckIn:Read_Iridium] Stopped
2025-10-08T17:09:14.233Z,1759943354.233 [Default:CheckIn:C.Wait] Running Loop=1
2025-10-08T17:09:14.233Z,1759943354.233 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-10-08T17:09:32.401Z,1759943372.401 [NAL9602](INFO): Not Powering down - fast GPS
2025-10-08T17:14:14.849Z,1759943654.849 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-10-08T17:14:14.849Z,1759943654.849 [Default:CheckIn:C.Wait] Stopped
2025-10-08T17:14:14.849Z,1759943654.849 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-10-08T17:14:14.849Z,1759943654.849 [Default:CheckIn:D] Running Loop=1
2025-10-08T17:14:15.242Z,1759943655.242 [Default:CheckIn:D] Stopped
2025-10-08T17:14:15.242Z,1759943655.242 [Default:CheckIn:E] Running Loop=1
2025-10-08T17:14:15.649Z,1759943655.649 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 90.137183 min
2025-10-08T17:14:15.649Z,1759943655.649 [Default:CheckIn:E] Stopped
2025-10-08T17:14:15.649Z,1759943655.649 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-10-08T17:14:15.649Z,1759943655.649 [Default:CheckIn] Stopped
2025-10-08T17:14:15.649Z,1759943655.649 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-10-08T17:14:15.649Z,1759943655.649 [Default:CheckIn](INFO): Running loop #15
2025-10-08T17:14:15.649Z,1759943655.649 [Default:CheckIn] Running Loop=15
2025-10-08T17:14:15.649Z,1759943655.649 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-10-08T17:14:15.650Z,1759943655.650 [Default:CheckIn:Read_GPS] Running Loop=1
2025-10-08T17:14:17.663Z,1759943657.663 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171416.00,A,3648.47247,N,12147.11424,W,3.518,359.43,081025,,,D*7C
2025-10-08T17:14:17.665Z,1759943657.665 [NAL9602](INFO): GPS fix at 20251008T171416: (36.807874, -121.785237)
2025-10-08T17:14:17.677Z,1759943657.677 [Default:CheckIn:Read_GPS] Stopped
2025-10-08T17:14:17.677Z,1759943657.677 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-10-08T17:14:25.396Z,1759943665.396 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20251008T153942/Courier0049.lzma
2025-10-08T17:14:26.398Z,1759943666.398 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153942/Courier0049.lzma.bak
2025-10-08T17:14:26.398Z,1759943666.398 [DataOverHttps](INFO): SBD MOMSN=26148874
2025-10-08T17:14:28.967Z,1759943668.967 [NAL9602](INFO): SBD MO Status=0, MOMSN=28372, MT Status=0, MTMSN=0
2025-10-08T17:14:28.967Z,1759943668.967 [NAL9602](INFO): No messages in MT queue
2025-10-08T17:14:42.264Z,1759943682.264 [DataOverHttps](INFO): Sending 175 bytes from file Logs/20251008T153942/Express0050.lzma
2025-10-08T17:14:43.266Z,1759943683.266 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153942/Express0050.lzma.bak
2025-10-08T17:14:43.266Z,1759943683.266 [DataOverHttps](INFO): SBD MOMSN=26148880
2025-10-08T17:14:44.361Z,1759943684.361 [Default:CheckIn:Read_Iridium] Stopped
2025-10-08T17:14:44.361Z,1759943684.361 [Default:CheckIn:C.Wait] Running Loop=1
2025-10-08T17:14:44.361Z,1759943684.361 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-10-08T17:14:59.725Z,1759943699.725 [NAL9602](INFO): Not Powering down - fast GPS
2025-10-08T17:19:45.018Z,1759943985.018 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-10-08T17:19:45.018Z,1759943985.018 [Default:CheckIn:C.Wait] Stopped
2025-10-08T17:19:45.018Z,1759943985.018 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-10-08T17:19:45.018Z,1759943985.018 [Default:CheckIn:D] Running Loop=1
2025-10-08T17:19:45.430Z,1759943985.430 [Default:CheckIn:D] Stopped
2025-10-08T17:19:45.430Z,1759943985.430 [Default:CheckIn:E] Running Loop=1
2025-10-08T17:19:45.846Z,1759943985.846 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 95.640332 min
2025-10-08T17:19:45.846Z,1759943985.846 [Default:CheckIn:E] Stopped
2025-10-08T17:19:45.846Z,1759943985.846 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-10-08T17:19:45.846Z,1759943985.846 [Default:CheckIn] Stopped
2025-10-08T17:19:45.846Z,1759943985.846 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-10-08T17:19:45.846Z,1759943985.846 [Default:CheckIn](INFO): Running loop #16
2025-10-08T17:19:45.846Z,1759943985.846 [Default:CheckIn] Running Loop=16
2025-10-08T17:19:45.846Z,1759943985.846 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-10-08T17:19:45.846Z,1759943985.846 [Default:CheckIn:Read_GPS] Running Loop=1
2025-10-08T17:19:47.836Z,1759943987.836 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171947.00,A,3648.36752,N,12147.46871,W,5.870,236.48,081025,,,D*7A
2025-10-08T17:19:47.839Z,1759943987.839 [NAL9602](INFO): GPS fix at 20251008T171947: (36.806125, -121.791145)
2025-10-08T17:19:47.850Z,1759943987.850 [Default:CheckIn:Read_GPS] Stopped
2025-10-08T17:19:47.850Z,1759943987.850 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-10-08T17:19:56.736Z,1759943996.736 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20251008T153942/Courier0052.lzma
2025-10-08T17:19:57.738Z,1759943997.738 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153942/Courier0052.lzma.bak
2025-10-08T17:19:57.738Z,1759943997.738 [DataOverHttps](INFO): SBD MOMSN=26148894
2025-10-08T17:20:10.871Z,1759944010.871 [NAL9602](INFO): SBD MO Status=0, MOMSN=28373, MT Status=0, MTMSN=0
2025-10-08T17:20:10.871Z,1759944010.871 [NAL9602](INFO): No messages in MT queue
2025-10-08T17:20:13.677Z,1759944013.677 [DataOverHttps](INFO): Sending 176 bytes from file Logs/20251008T153942/Express0053.lzma
2025-10-08T17:20:14.675Z,1759944014.675 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153942/Express0053.lzma.bak
2025-10-08T17:20:14.675Z,1759944014.675 [DataOverHttps](INFO): SBD MOMSN=26148897
2025-10-08T17:20:15.731Z,1759944015.731 [Default:CheckIn:Read_Iridium] Stopped
2025-10-08T17:20:15.731Z,1759944015.731 [Default:CheckIn:C.Wait] Running Loop=1
2025-10-08T17:20:15.731Z,1759944015.731 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-10-08T17:20:41.569Z,1759944041.569 [NAL9602](INFO): Not Powering down - fast GPS
2025-10-08T17:25:16.333Z,1759944316.333 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-10-08T17:25:16.333Z,1759944316.333 [Default:CheckIn:C.Wait] Stopped
2025-10-08T17:25:16.333Z,1759944316.333 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-10-08T17:25:16.333Z,1759944316.333 [Default:CheckIn:D] Running Loop=1
2025-10-08T17:25:16.737Z,1759944316.737 [Default:CheckIn:D] Stopped
2025-10-08T17:25:16.737Z,1759944316.737 [Default:CheckIn:E] Running Loop=1
2025-10-08T17:25:17.141Z,1759944317.141 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 101.162101 min
2025-10-08T17:25:17.141Z,1759944317.141 [Default:CheckIn:E] Stopped
2025-10-08T17:25:17.141Z,1759944317.141 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-10-08T17:25:17.141Z,1759944317.141 [Default:CheckIn] Stopped
2025-10-08T17:25:17.142Z,1759944317.142 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-10-08T17:25:17.142Z,1759944317.142 [Default:CheckIn](INFO): Running loop #17
2025-10-08T17:25:17.142Z,1759944317.142 [Default:CheckIn] Running Loop=17
2025-10-08T17:25:17.142Z,1759944317.142 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-10-08T17:25:17.142Z,1759944317.142 [Default:CheckIn:Read_GPS] Running Loop=1
2025-10-08T17:25:19.151Z,1759944319.151 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172518.00,A,3648.25447,N,12148.07357,W,5.657,263.86,081025,,,A*73
2025-10-08T17:25:19.161Z,1759944319.161 [NAL9602](INFO): GPS fix at 20251008T172518: (36.804241, -121.801226)
2025-10-08T17:25:19.173Z,1759944319.173 [Default:CheckIn:Read_GPS] Stopped
2025-10-08T17:25:19.173Z,1759944319.173 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-10-08T17:25:26.440Z,1759944326.440 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20251008T153942/Courier0055.lzma
2025-10-08T17:25:27.442Z,1759944327.442 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153942/Courier0055.lzma.bak
2025-10-08T17:25:27.442Z,1759944327.442 [DataOverHttps](INFO): SBD MOMSN=26149009
2025-10-08T17:25:34.107Z,1759944334.107 [NAL9602](INFO): SBD MO Status=0, MOMSN=28374, MT Status=0, MTMSN=0
2025-10-08T17:25:34.107Z,1759944334.107 [NAL9602](INFO): No messages in MT queue
2025-10-08T17:25:43.340Z,1759944343.340 [DataOverHttps](INFO): Sending 172 bytes from file Logs/20251008T153942/Express0056.lzma
2025-10-08T17:25:44.342Z,1759944344.342 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153942/Express0056.lzma.bak
2025-10-08T17:25:44.342Z,1759944344.342 [DataOverHttps](INFO): SBD MOMSN=26149012
2025-10-08T17:25:45.421Z,1759944345.421 [Default:CheckIn:Read_Iridium] Stopped
2025-10-08T17:25:45.421Z,1759944345.421 [Default:CheckIn:C.Wait] Running Loop=1
2025-10-08T17:25:45.421Z,1759944345.421 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-10-08T17:26:04.805Z,1759944364.805 [NAL9602](INFO): Not Powering down - fast GPS
2025-10-08T17:30:46.070Z,1759944646.070 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-10-08T17:30:46.070Z,1759944646.070 [Default:CheckIn:C.Wait] Stopped
2025-10-08T17:30:46.070Z,1759944646.070 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-10-08T17:30:46.070Z,1759944646.070 [Default:CheckIn:D] Running Loop=1
2025-10-08T17:30:46.465Z,1759944646.465 [Default:CheckIn:D] Stopped
2025-10-08T17:30:46.465Z,1759944646.465 [Default:CheckIn:E] Running Loop=1
2025-10-08T17:30:46.868Z,1759944646.868 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 106.657576 min
2025-10-08T17:30:46.868Z,1759944646.868 [Default:CheckIn:E] Stopped
2025-10-08T17:30:46.868Z,1759944646.868 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-10-08T17:30:46.868Z,1759944646.868 [Default:CheckIn] Stopped
2025-10-08T17:30:46.868Z,1759944646.868 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-10-08T17:30:46.869Z,1759944646.869 [Default:CheckIn](INFO): Running loop #18
2025-10-08T17:30:46.869Z,1759944646.869 [Default:CheckIn] Running Loop=18
2025-10-08T17:30:46.869Z,1759944646.869 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-10-08T17:30:46.869Z,1759944646.869 [Default:CheckIn:Read_GPS] Running Loop=1
2025-10-08T17:30:48.883Z,1759944648.883 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173048.00,A,3648.36429,N,12148.72754,W,5.968,281.98,081025,,,A*7D
2025-10-08T17:30:48.894Z,1759944648.894 [NAL9602](INFO): GPS fix at 20251008T173048: (36.806072, -121.812126)
2025-10-08T17:30:48.905Z,1759944648.905 [Default:CheckIn:Read_GPS] Stopped
2025-10-08T17:30:48.905Z,1759944648.905 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-10-08T17:31:01.047Z,1759944661.047 [NAL9602](INFO): SBD MO Status=0, MOMSN=28375, MT Status=0, MTMSN=0
2025-10-08T17:31:01.047Z,1759944661.047 [NAL9602](INFO): No messages in MT queue
2025-10-08T17:31:03.144Z,1759944663.144 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20251008T153942/Courier0058.lzma
2025-10-08T17:31:10.170Z,1759944670.170 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153942/Courier0058.lzma.bak
2025-10-08T17:31:10.170Z,1759944670.170 [DataOverHttps](INFO): SBD MOMSN=26149023
2025-10-08T17:31:26.048Z,1759944686.048 [DataOverHttps](INFO): Sending 175 bytes from file Logs/20251008T153942/Express0059.lzma
2025-10-08T17:31:27.051Z,1759944687.051 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153942/Express0059.lzma.bak
2025-10-08T17:31:27.051Z,1759944687.051 [DataOverHttps](INFO): SBD MOMSN=26149026
2025-10-08T17:31:28.127Z,1759944688.127 [Default:CheckIn:Read_Iridium] Stopped
2025-10-08T17:31:28.127Z,1759944688.127 [Default:CheckIn:C.Wait] Running Loop=1
2025-10-08T17:31:28.127Z,1759944688.127 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-10-08T17:31:31.749Z,1759944691.749 [NAL9602](INFO): Not Powering down - fast GPS
2025-10-08T17:36:28.713Z,1759944988.713 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-10-08T17:36:28.713Z,1759944988.713 [Default:CheckIn:C.Wait] Stopped
2025-10-08T17:36:28.713Z,1759944988.713 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-10-08T17:36:28.713Z,1759944988.713 [Default:CheckIn:D] Running Loop=1
2025-10-08T17:36:29.116Z,1759944989.116 [Default:CheckIn:D] Stopped
2025-10-08T17:36:29.116Z,1759944989.116 [Default:CheckIn:E] Running Loop=1
2025-10-08T17:36:29.525Z,1759944989.525 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 112.368416 min
2025-10-08T17:36:29.525Z,1759944989.525 [Default:CheckIn:E] Stopped
2025-10-08T17:36:29.525Z,1759944989.525 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-10-08T17:36:29.525Z,1759944989.525 [Default:CheckIn] Stopped
2025-10-08T17:36:29.525Z,1759944989.525 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-10-08T17:36:29.525Z,1759944989.525 [Default:CheckIn](INFO): Running loop #19
2025-10-08T17:36:29.525Z,1759944989.525 [Default:CheckIn] Running Loop=19
2025-10-08T17:36:29.525Z,1759944989.525 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-10-08T17:36:29.525Z,1759944989.525 [Default:CheckIn:Read_GPS] Running Loop=1
2025-10-08T17:36:31.531Z,1759944991.531 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173630.00,A,3648.42782,N,12149.34252,W,0.972,14.78,081025,,,A*4B
2025-10-08T17:36:31.533Z,1759944991.533 [NAL9602](INFO): GPS fix at 20251008T173630: (36.807130, -121.822375)
2025-10-08T17:36:31.566Z,1759944991.566 [Default:CheckIn:Read_GPS] Stopped
2025-10-08T17:36:31.566Z,1759944991.566 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-10-08T17:36:39.160Z,1759944999.160 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20251008T153942/Courier0061.lzma
2025-10-08T17:36:40.162Z,1759945000.162 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153942/Courier0061.lzma.bak
2025-10-08T17:36:40.162Z,1759945000.162 [DataOverHttps](INFO): SBD MOMSN=26149130
2025-10-08T17:36:45.671Z,1759945005.671 [NAL9602](INFO): SBD MO Status=0, MOMSN=28376, MT Status=0, MTMSN=0
2025-10-08T17:36:45.671Z,1759945005.671 [NAL9602](INFO): No messages in MT queue
2025-10-08T17:36:59.340Z,1759945019.340 [DataOverHttps](INFO): Sending 175 bytes from file Logs/20251008T153942/Express0062.lzma
2025-10-08T17:37:00.342Z,1759945020.342 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153942/Express0062.lzma.bak
2025-10-08T17:37:00.342Z,1759945020.342 [DataOverHttps](INFO): SBD MOMSN=26149133
2025-10-08T17:37:01.481Z,1759945021.481 [Default:CheckIn:Read_Iridium] Stopped
2025-10-08T17:37:01.481Z,1759945021.481 [Default:CheckIn:C.Wait] Running Loop=1
2025-10-08T17:37:01.481Z,1759945021.481 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-10-08T17:37:16.409Z,1759945036.409 [NAL9602](INFO): Not Powering down - fast GPS
2025-10-08T17:42:02.064Z,1759945322.064 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-10-08T17:42:02.064Z,1759945322.064 [Default:CheckIn:C.Wait] Stopped
2025-10-08T17:42:02.064Z,1759945322.064 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-10-08T17:42:02.064Z,1759945322.064 [Default:CheckIn:D] Running Loop=1
2025-10-08T17:42:02.470Z,1759945322.470 [Default:CheckIn:D] Stopped
2025-10-08T17:42:02.470Z,1759945322.470 [Default:CheckIn:E] Running Loop=1
2025-10-08T17:42:02.881Z,1759945322.881 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 117.924333 min
2025-10-08T17:42:02.881Z,1759945322.881 [Default:CheckIn:E] Stopped
2025-10-08T17:42:02.881Z,1759945322.881 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-10-08T17:42:02.881Z,1759945322.881 [Default:CheckIn] Stopped
2025-10-08T17:42:02.881Z,1759945322.881 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-10-08T17:42:02.881Z,1759945322.881 [Default:CheckIn](INFO): Running loop #20
2025-10-08T17:42:02.881Z,1759945322.881 [Default:CheckIn] Running Loop=20
2025-10-08T17:42:02.881Z,1759945322.881 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-10-08T17:42:02.881Z,1759945322.881 [Default:CheckIn:Read_GPS] Running Loop=1
2025-10-08T17:42:04.891Z,1759945324.891 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174204.00,A,3648.44111,N,12149.33490,W,0.525,13.88,081025,,,D*49
2025-10-08T17:42:04.902Z,1759945324.902 [NAL9602](INFO): GPS fix at 20251008T174204: (36.807352, -121.822248)
2025-10-08T17:42:04.914Z,1759945324.914 [Default:CheckIn:Read_GPS] Stopped
2025-10-08T17:42:04.914Z,1759945324.914 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-10-08T17:42:12.476Z,1759945332.476 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20251008T153942/Courier0064.lzma
2025-10-08T17:42:13.478Z,1759945333.478 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153942/Courier0064.lzma.bak
2025-10-08T17:42:13.478Z,1759945333.478 [DataOverHttps](INFO): SBD MOMSN=26149144
2025-10-08T17:42:22.675Z,1759945342.675 [NAL9602](INFO): SBD MO Status=0, MOMSN=28377, MT Status=0, MTMSN=0
2025-10-08T17:42:22.675Z,1759945342.675 [NAL9602](INFO): No messages in MT queue
2025-10-08T17:42:29.420Z,1759945349.420 [DataOverHttps](INFO): Sending 164 bytes from file Logs/20251008T153942/Express0065.lzma
2025-10-08T17:42:30.422Z,1759945350.422 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153942/Express0065.lzma.bak
2025-10-08T17:42:30.422Z,1759945350.422 [DataOverHttps](INFO): SBD MOMSN=26149160
2025-10-08T17:42:31.556Z,1759945351.556 [Default:CheckIn:Read_Iridium] Stopped
2025-10-08T17:42:31.556Z,1759945351.556 [Default:CheckIn:C.Wait] Running Loop=1
2025-10-08T17:42:31.557Z,1759945351.557 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-10-08T17:42:53.363Z,1759945373.363 [NAL9602](INFO): Not Powering down - fast GPS
2025-10-08T17:47:32.141Z,1759945652.141 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-10-08T17:47:32.141Z,1759945652.141 [Default:CheckIn:C.Wait] Stopped
2025-10-08T17:47:32.141Z,1759945652.141 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-10-08T17:47:32.141Z,1759945652.141 [Default:CheckIn:D] Running Loop=1
2025-10-08T17:47:32.536Z,1759945652.536 [Default:CheckIn:D] Stopped
2025-10-08T17:47:32.536Z,1759945652.536 [Default:CheckIn:E] Running Loop=1
2025-10-08T17:47:32.945Z,1759945652.945 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 123.425423 min
2025-10-08T17:47:32.945Z,1759945652.945 [Default:CheckIn:E] Stopped
2025-10-08T17:47:32.945Z,1759945652.945 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-10-08T17:47:32.945Z,1759945652.945 [Default:CheckIn] Stopped
2025-10-08T17:47:32.945Z,1759945652.945 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-10-08T17:47:32.945Z,1759945652.945 [Default:CheckIn](INFO): Running loop #21
2025-10-08T17:47:32.945Z,1759945652.945 [Default:CheckIn] Running Loop=21
2025-10-08T17:47:32.945Z,1759945652.945 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-10-08T17:47:32.945Z,1759945652.945 [Default:CheckIn:Read_GPS] Running Loop=1
2025-10-08T17:47:34.959Z,1759945654.959 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174734.00,A,3648.26590,N,12149.60732,W,19.963,242.73,081025,,,D*4F
2025-10-08T17:47:34.962Z,1759945654.962 [NAL9602](INFO): GPS fix at 20251008T174734: (36.804432, -121.826789)
2025-10-08T17:47:34.973Z,1759945654.973 [Default:CheckIn:Read_GPS] Stopped
2025-10-08T17:47:34.973Z,1759945654.973 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-10-08T17:47:42.536Z,1759945662.536 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20251008T153942/Courier0067.lzma
2025-10-08T17:47:43.538Z,1759945663.538 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153942/Courier0067.lzma.bak
2025-10-08T17:47:43.538Z,1759945663.538 [DataOverHttps](INFO): SBD MOMSN=26149267
2025-10-08T17:47:54.748Z,1759945674.748 [NAL9602](INFO): SBD MO Status=0, MOMSN=28378, MT Status=0, MTMSN=0
2025-10-08T17:47:54.748Z,1759945674.748 [NAL9602](INFO): No messages in MT queue
2025-10-08T17:48:00.489Z,1759945680.489 [DataOverHttps](INFO): Sending 175 bytes from file Logs/20251008T153942/Express0068.lzma
2025-10-08T17:48:01.490Z,1759945681.490 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153942/Express0068.lzma.bak
2025-10-08T17:48:01.491Z,1759945681.491 [DataOverHttps](INFO): SBD MOMSN=26149270
2025-10-08T17:48:02.836Z,1759945682.836 [Default:CheckIn:Read_Iridium] Stopped
2025-10-08T17:48:02.836Z,1759945682.836 [Default:CheckIn:C.Wait] Running Loop=1
2025-10-08T17:48:02.836Z,1759945682.836 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-10-08T17:48:25.459Z,1759945705.459 [NAL9602](INFO): Not Powering down - fast GPS
2025-10-08T17:53:03.449Z,1759945983.449 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-10-08T17:53:03.449Z,1759945983.449 [Default:CheckIn:C.Wait] Stopped
2025-10-08T17:53:03.449Z,1759945983.449 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-10-08T17:53:03.449Z,1759945983.449 [Default:CheckIn:D] Running Loop=1
2025-10-08T17:53:03.856Z,1759945983.856 [Default:CheckIn:D] Stopped
2025-10-08T17:53:03.856Z,1759945983.856 [Default:CheckIn:E] Running Loop=1
2025-10-08T17:53:04.268Z,1759945984.268 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 128.947420 min
2025-10-08T17:53:04.268Z,1759945984.268 [Default:CheckIn:E] Stopped
2025-10-08T17:53:04.268Z,1759945984.268 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-10-08T17:53:04.269Z,1759945984.269 [Default:CheckIn] Stopped
2025-10-08T17:53:04.269Z,1759945984.269 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-10-08T17:53:04.269Z,1759945984.269 [Default:CheckIn](INFO): Running loop #22
2025-10-08T17:53:04.269Z,1759945984.269 [Default:CheckIn] Running Loop=22
2025-10-08T17:53:04.269Z,1759945984.269 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-10-08T17:53:04.269Z,1759945984.269 [Default:CheckIn:Read_GPS] Running Loop=1
2025-10-08T17:53:06.297Z,1759945986.297 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175305.00,A,3647.80193,N,12150.82501,W,0.447,249.12,081025,,,D*75
2025-10-08T17:53:06.299Z,1759945986.299 [NAL9602](INFO): GPS fix at 20251008T175305: (36.796699, -121.847083)
2025-10-08T17:53:06.310Z,1759945986.310 [Default:CheckIn:Read_GPS] Stopped
2025-10-08T17:53:06.310Z,1759945986.310 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-10-08T17:53:13.468Z,1759945993.468 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20251008T153942/Courier0070.lzma
2025-10-08T17:53:14.471Z,1759945994.471 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153942/Courier0070.lzma.bak
2025-10-08T17:53:14.471Z,1759945994.471 [DataOverHttps](INFO): SBD MOMSN=26149346
2025-10-08T17:53:23.247Z,1759946003.247 [NAL9602](INFO): SBD MO Status=0, MOMSN=28379, MT Status=0, MTMSN=0
2025-10-08T17:53:23.247Z,1759946003.247 [NAL9602](INFO): No messages in MT queue
2025-10-08T17:53:30.501Z,1759946010.501 [DataOverHttps](INFO): Sending 177 bytes from file Logs/20251008T153942/Express0071.lzma
2025-10-08T17:53:31.486Z,1759946011.486 [DataOverHttps](INFO): Moved sent file to Logs/20251008T153942/Express0071.lzma.bak
2025-10-08T17:53:31.486Z,1759946011.486 [DataOverHttps](INFO): SBD MOMSN=26149349
2025-10-08T17:53:32.533Z,1759946012.533 [Default:CheckIn:Read_Iridium] Stopped
2025-10-08T17:53:32.533Z,1759946012.533 [Default:CheckIn:C.Wait] Running Loop=1
2025-10-08T17:53:32.533Z,1759946012.533 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-10-08T17:53:53.933Z,1759946033.933 [NAL9602](INFO): Not Powering down - fast GPS
2025-10-08T17:55:11.693Z,1759946111.693 [DataOverHttps](IMPORTANT): SBD MTMSN=20251008T175510
2025-10-08T17:55:19.184Z,1759946119.184 [DataOverHttps](INFO): Received command: restart logs