2025-11-18T15:30:46.030Z,1763479846.030 [Supervisor](DEBUG): Initializing supervisor.
2025-11-18T15:30:46.035Z,1763479846.035 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2025-11-18T15:30:46.035Z,1763479846.035 [SyncHandler](INFO): Protected caller Thread ID is 842
2025-11-18T15:30:46.036Z,1763479846.036 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2025-11-18T15:30:46.037Z,1763479846.037 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2025-11-18T15:30:46.037Z,1763479846.037 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 843
2025-11-18T15:30:46.042Z,1763479846.042 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2025-11-18T15:30:46.062Z,1763479846.062 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2025-11-18T15:30:46.063Z,1763479846.063 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2025-11-18T15:30:46.064Z,1763479846.064 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 844
2025-11-18T15:30:46.068Z,1763479846.068 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2025-11-18T15:30:46.069Z,1763479846.069 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2025-11-18T15:30:46.070Z,1763479846.070 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 845
2025-11-18T15:30:46.072Z,1763479846.072 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2025-11-18T15:30:46.073Z,1763479846.073 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2025-11-18T15:30:46.073Z,1763479846.073 [logger ThreadHandler](INFO): Protected caller Thread ID is 846
2025-11-18T15:30:46.077Z,1763479846.077 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2025-11-18T15:30:46.077Z,1763479846.077 [Supervisor](INFO): Looking for Config files in directory: Config/
2025-11-18T15:30:46.082Z,1763479846.082 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2025-11-18T15:30:46.663Z,1763479846.663 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2025-11-18T15:30:46.665Z,1763479846.665 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2025-11-18T15:30:46.903Z,1763479846.903 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2025-11-18T15:30:46.904Z,1763479846.904 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2025-11-18T15:30:47.009Z,1763479847.009 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Guidance
2025-11-18T15:30:47.011Z,1763479847.011 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2025-11-18T15:30:47.279Z,1763479847.279 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2025-11-18T15:30:47.281Z,1763479847.281 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2025-11-18T15:30:47.373Z,1763479847.373 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2025-11-18T15:30:47.482Z,1763479847.482 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2025-11-18T15:30:47.483Z,1763479847.483 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2025-11-18T15:30:47.877Z,1763479847.877 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2025-11-18T15:30:47.879Z,1763479847.879 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2025-11-18T15:30:48.030Z,1763479848.030 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2025-11-18T15:30:48.031Z,1763479848.031 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2025-11-18T15:30:49.187Z,1763479849.187 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2025-11-18T15:30:49.188Z,1763479849.188 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2025-11-18T15:30:49.400Z,1763479849.400 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2025-11-18T15:30:49.402Z,1763479849.402 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2025-11-18T15:30:49.872Z,1763479849.872 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2025-11-18T15:30:49.873Z,1763479849.873 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2025-11-18T15:30:50.198Z,1763479850.198 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2025-11-18T15:30:50.200Z,1763479850.200 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2025-11-18T15:30:50.325Z,1763479850.325 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2025-11-18T15:30:50.326Z,1763479850.326 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2025-11-18T15:30:51.253Z,1763479851.253 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2025-11-18T15:30:51.254Z,1763479851.254 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2025-11-18T15:30:51.690Z,1763479851.690 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2025-11-18T15:30:51.692Z,1763479851.692 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2025-11-18T15:30:51.961Z,1763479851.961 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2025-11-18T15:30:51.963Z,1763479851.963 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-triton/
2025-11-18T15:30:51.967Z,1763479851.967 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/vehicle.cfg
2025-11-18T15:30:52.103Z,1763479852.103 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/secure.cfg
2025-11-18T15:30:52.200Z,1763479852.200 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Science.cfg
2025-11-18T15:30:52.358Z,1763479852.358 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Simulator.cfg
2025-11-18T15:30:52.457Z,1763479852.457 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Battery.cfg
2025-11-18T15:30:52.740Z,1763479852.740 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2025-11-18T15:30:52.742Z,1763479852.742 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/logger.cfg
2025-11-18T15:30:52.862Z,1763479852.862 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Servo.cfg
2025-11-18T15:30:52.985Z,1763479852.985 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Navigation.cfg
2025-11-18T15:30:53.100Z,1763479853.100 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Sensor.cfg
2025-11-18T15:30:53.276Z,1763479853.276 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Control.cfg
2025-11-18T15:30:53.389Z,1763479853.389 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/BIT.cfg
2025-11-18T15:30:53.489Z,1763479853.489 [Supervisor](IMPORTANT): Reloading configuration overrides from Data/persisted.cfg
2025-11-18T15:30:53.499Z,1763479853.499 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2025-11-18T15:30:53.516Z,1763479853.516 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2025-11-18T15:30:53.516Z,1763479853.516 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2025-11-18T15:30:53.686Z,1763479853.686 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2025-11-18T15:30:53.688Z,1763479853.688 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2025-11-18T15:30:53.763Z,1763479853.763 [VerticalControl](DEBUG): Construct VerticalControl.
2025-11-18T15:30:53.826Z,1763479853.826 [VerticalControl] Loaded
2025-11-18T15:30:53.826Z,1763479853.826 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2025-11-18T15:30:53.829Z,1763479853.829 [HorizontalControl](DEBUG): Construct HorizontalControl.
2025-11-18T15:30:53.877Z,1763479853.877 [HorizontalControl] Loaded
2025-11-18T15:30:53.877Z,1763479853.877 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2025-11-18T15:30:53.879Z,1763479853.879 [SpeedControl](DEBUG): Construct SpeedControl.
2025-11-18T15:30:53.882Z,1763479853.882 [SpeedControl] Loaded
2025-11-18T15:30:53.883Z,1763479853.883 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2025-11-18T15:30:53.886Z,1763479853.886 [LoopControl](DEBUG): Construct LoopControl.
2025-11-18T15:30:53.886Z,1763479853.886 [LoopControl] Loaded
2025-11-18T15:30:53.886Z,1763479853.886 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2025-11-18T15:30:53.887Z,1763479853.887 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2025-11-18T15:30:53.887Z,1763479853.887 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2025-11-18T15:30:54.084Z,1763479854.084 [BuoyancyServo] Loaded
2025-11-18T15:30:54.084Z,1763479854.084 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2025-11-18T15:30:54.106Z,1763479854.106 [ElevatorServo] Loaded
2025-11-18T15:30:54.107Z,1763479854.107 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2025-11-18T15:30:54.128Z,1763479854.128 [MassServo] Loaded
2025-11-18T15:30:54.128Z,1763479854.128 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2025-11-18T15:30:54.149Z,1763479854.149 [RudderServo] Loaded
2025-11-18T15:30:54.149Z,1763479854.149 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2025-11-18T15:30:54.166Z,1763479854.166 [ThrusterHE] Loaded
2025-11-18T15:30:54.167Z,1763479854.167 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2025-11-18T15:30:54.167Z,1763479854.167 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2025-11-18T15:30:54.168Z,1763479854.168 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2025-11-18T15:30:54.363Z,1763479854.363 [DepthRateCalculator] Loaded
2025-11-18T15:30:54.364Z,1763479854.364 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2025-11-18T15:30:54.377Z,1763479854.377 [PitchRateCalculator] Loaded
2025-11-18T15:30:54.377Z,1763479854.377 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2025-11-18T15:30:54.433Z,1763479854.433 [SpeedCalculator] Loaded
2025-11-18T15:30:54.434Z,1763479854.434 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2025-11-18T15:30:54.438Z,1763479854.438 [YawRateCalculator] Loaded
2025-11-18T15:30:54.438Z,1763479854.438 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2025-11-18T15:30:54.475Z,1763479854.475 [ElevatorOffsetCalculator] Loaded
2025-11-18T15:30:54.475Z,1763479854.475 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2025-11-18T15:30:54.476Z,1763479854.476 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2025-11-18T15:30:54.476Z,1763479854.476 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2025-11-18T15:30:55.477Z,1763479855.477 [DeadReckonUsingMultipleVelocitySources] Loaded
2025-11-18T15:30:55.477Z,1763479855.477 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2025-11-18T15:30:55.491Z,1763479855.491 [NavChart] Loaded
2025-11-18T15:30:55.491Z,1763479855.491 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2025-11-18T15:30:55.497Z,1763479855.497 [UniversalFixResidualReporter] Loaded
2025-11-18T15:30:55.497Z,1763479855.497 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2025-11-18T15:30:55.497Z,1763479855.497 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2025-11-18T15:30:55.498Z,1763479855.498 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2025-11-18T15:30:56.500Z,1763479856.500 [AHRS_M2] Loaded
2025-11-18T15:30:56.500Z,1763479856.500 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2025-11-18T15:30:56.753Z,1763479856.753 [BackseatComponent] Loaded
2025-11-18T15:30:56.754Z,1763479856.754 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2025-11-18T15:30:56.755Z,1763479856.755 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 4092B4E0
2025-11-18T15:30:56.755Z,1763479856.755 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 929
2025-11-18T15:30:56.759Z,1763479856.759 [LcmPublisher] Loaded
2025-11-18T15:30:56.759Z,1763479856.759 [ComponentRegistry](DEBUG): SyncComponent "LcmPublisher" handled in the control thread.
2025-11-18T15:30:56.765Z,1763479856.765 [BioacousticsDataBridge] Loaded
2025-11-18T15:30:56.765Z,1763479856.765 [ComponentRegistry](DEBUG): SyncComponent "BioacousticsDataBridge" handled in the control thread.
2025-11-18T15:30:57.646Z,1763479857.646 [BPC1] Loaded
2025-11-18T15:30:57.646Z,1763479857.646 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2025-11-18T15:30:57.839Z,1763479857.839 [DAT] Loaded
2025-11-18T15:30:57.839Z,1763479857.839 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread.
2025-11-18T15:30:57.840Z,1763479857.840 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 4095B4E0
2025-11-18T15:30:57.841Z,1763479857.841 [DAT ThreadHandler](INFO): Protected caller Thread ID is 930
2025-11-18T15:30:58.303Z,1763479858.303 [DataOverHttps] Loaded
2025-11-18T15:30:58.303Z,1763479858.303 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2025-11-18T15:30:58.304Z,1763479858.304 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4098B4E0
2025-11-18T15:30:58.305Z,1763479858.305 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 931
2025-11-18T15:30:58.328Z,1763479858.328 [Depth_Keller] Loaded
2025-11-18T15:30:58.329Z,1763479858.329 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2025-11-18T15:30:58.334Z,1763479858.334 [DropWeight] Loaded
2025-11-18T15:30:58.334Z,1763479858.334 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2025-11-18T15:30:58.399Z,1763479858.399 [NAL9602] Loaded
2025-11-18T15:30:58.399Z,1763479858.399 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2025-11-18T15:30:58.430Z,1763479858.430 [Onboard] Loaded
2025-11-18T15:30:58.430Z,1763479858.430 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2025-11-18T15:30:58.431Z,1763479858.431 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 409BB4E0
2025-11-18T15:30:58.431Z,1763479858.431 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 932
2025-11-18T15:30:58.446Z,1763479858.446 [Power24vConverter] Loaded
2025-11-18T15:30:58.446Z,1763479858.446 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2025-11-18T15:30:58.464Z,1763479858.464 [Radio_Surface] Loaded
2025-11-18T15:30:58.464Z,1763479858.464 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2025-11-18T15:30:58.465Z,1763479858.465 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409EB4E0
2025-11-18T15:30:58.465Z,1763479858.465 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 933
2025-11-18T15:30:58.479Z,1763479858.479 [Sonardyne_Nano] Loaded
2025-11-18T15:30:58.479Z,1763479858.479 [ComponentRegistry](DEBUG): SyncComponent "Sonardyne_Nano" handled in the control thread.
2025-11-18T15:30:58.480Z,1763479858.480 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2025-11-18T15:30:58.480Z,1763479858.480 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2025-11-18T15:30:58.569Z,1763479858.569 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2025-11-18T15:30:58.570Z,1763479858.570 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2025-11-18T15:30:58.794Z,1763479858.794 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2025-11-18T15:30:58.795Z,1763479858.795 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2025-11-18T15:30:58.845Z,1763479858.845 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2025-11-18T15:30:58.846Z,1763479858.846 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2025-11-18T15:30:59.072Z,1763479859.072 [CTD_Seabird] Loaded
2025-11-18T15:30:59.073Z,1763479859.073 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2025-11-18T15:30:59.074Z,1763479859.074 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40B344E0
2025-11-18T15:30:59.074Z,1763479859.074 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 934
2025-11-18T15:30:59.097Z,1763479859.097 [PAR_Licor] Loaded
2025-11-18T15:30:59.097Z,1763479859.097 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2025-11-18T15:30:59.143Z,1763479859.143 [WetLabsBB2FL] Loaded
2025-11-18T15:30:59.143Z,1763479859.143 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2025-11-18T15:30:59.144Z,1763479859.144 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40B644E0
2025-11-18T15:30:59.144Z,1763479859.144 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 935
2025-11-18T15:30:59.145Z,1763479859.145 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2025-11-18T15:30:59.146Z,1763479859.146 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2025-11-18T15:30:59.559Z,1763479859.559 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2025-11-18T15:30:59.560Z,1763479859.560 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2025-11-18T15:30:59.761Z,1763479859.761 [SBIT](DEBUG): Construct Startup Built In Test.
2025-11-18T15:30:59.770Z,1763479859.770 [SBIT] Loaded
2025-11-18T15:30:59.770Z,1763479859.770 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2025-11-18T15:30:59.773Z,1763479859.773 [IBIT](DEBUG): Construct Initiated Built In Test.
2025-11-18T15:30:59.787Z,1763479859.787 [IBIT] Loaded
2025-11-18T15:30:59.787Z,1763479859.787 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2025-11-18T15:30:59.792Z,1763479859.792 [CBIT](DEBUG): Construct Continuous Built In Test.
2025-11-18T15:30:59.874Z,1763479859.874 [CBIT] Loaded
2025-11-18T15:30:59.874Z,1763479859.874 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2025-11-18T15:30:59.908Z,1763479859.908 [GFScanner] Loaded
2025-11-18T15:30:59.908Z,1763479859.908 [ComponentRegistry](DEBUG): SyncComponent "GFScanner" handled in the control thread.
2025-11-18T15:30:59.908Z,1763479859.908 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2025-11-18T15:30:59.915Z,1763479859.915 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2025-11-18T15:30:59.919Z,1763479859.919 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2025-11-18T15:30:59.930Z,1763479859.930 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2025-11-18T15:30:59.931Z,1763479859.931 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C6D4E0
2025-11-18T15:30:59.931Z,1763479859.931 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 936
2025-11-18T15:30:59.936Z,1763479859.936 [Supervisor](INFO): Main Thread ID is 835
2025-11-18T15:30:59.936Z,1763479859.936 [Supervisor](DEBUG): Running supervisor.
2025-11-18T15:30:59.937Z,1763479859.937 [CommandExec ThreadHandler](INFO): Handler Thread ID is 937
2025-11-18T15:30:59.937Z,1763479859.937 [CommandExec](INFO): Initializing the command executive.
2025-11-18T15:30:59.939Z,1763479859.939 [CommandLine ThreadHandler](INFO): Handler Thread ID is 938
2025-11-18T15:30:59.941Z,1763479859.941 [controlThread ThreadHandler](INFO): Handler Thread ID is 939
2025-11-18T15:30:59.942Z,1763479859.942 [controlThread](DEBUG): Initializing ControlThread
2025-11-18T15:30:59.942Z,1763479859.942 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2025-11-18T15:30:59.944Z,1763479859.944 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2025-11-18T15:30:59.945Z,1763479859.945 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2025-11-18T15:30:59.945Z,1763479859.945 [LoopControl](DEBUG): Initialize LoopControlComponent.
2025-11-18T15:30:59.947Z,1763479859.947 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2025-11-18T15:30:59.947Z,1763479859.947 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2025-11-18T15:30:59.947Z,1763479859.947 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2025-11-18T15:30:59.948Z,1763479859.948 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2025-11-18T15:30:59.948Z,1763479859.948 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2025-11-18T15:30:59.949Z,1763479859.949 [NavChart](DEBUG): Initialize NavChart Navigation.
2025-11-18T15:30:59.949Z,1763479859.949 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2025-11-18T15:30:59.956Z,1763479859.956 [SBIT](INFO): Initialize SBIT Component.
2025-11-18T15:30:59.957Z,1763479859.957 [SBIT](IMPORTANT): git: 2025-11-13_A
2025-11-18T15:30:59.957Z,1763479859.957 [SBIT](INFO): git hash: b8ea03c59866f18cc80863f24d4b42bc555cb33f
2025-11-18T15:30:59.957Z,1763479859.957 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2025-11-18T15:30:59.958Z,1763479859.958 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #1 PREEMPT Tue Dec 18 21:19:28 PST 2018
Kernel Reported: #1 PREEMPT Wed Mar 17 08:23:48 PDT 2021
2025-11-18T15:30:59.959Z,1763479859.959 [SBIT](INFO): Beginning SBIT in 35.000000 seconds.
2025-11-18T15:30:59.960Z,1763479859.960 [IBIT](INFO): Initialize IBIT Component.
2025-11-18T15:30:59.961Z,1763479859.961 [CBIT](DEBUG): Initialize CBIT Component.
2025-11-18T15:30:59.962Z,1763479859.962 [logger ThreadHandler](INFO): Handler Thread ID is 940
2025-11-18T15:30:59.972Z,1763479859.972 [CBIT](DEBUG): Initialized mux pins.
2025-11-18T15:30:59.972Z,1763479859.972 [CBIT](DEBUG): Initializing the watchdog timer.
2025-11-18T15:30:59.980Z,1763479859.980 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 941
2025-11-18T15:30:59.992Z,1763479859.992 [DAT ThreadHandler](INFO): Handler Thread ID is 942
2025-11-18T15:30:59.993Z,1763479859.993 [DAT](INFO): Powering up
2025-11-18T15:30:59.993Z,1763479859.993 [DAT](DEBUG): Initializing DAT.
2025-11-18T15:30:59.996Z,1763479859.996 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2025-11-18T15:30:59.996Z,1763479859.996 [CBIT](DEBUG): Initializing heartbeat.
2025-11-18T15:30:59.998Z,1763479859.998 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 944
2025-11-18T15:30:59.000Z,1763479860.000 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2025-11-18T15:31:00.009Z,1763479860.009 [Onboard ThreadHandler](INFO): Handler Thread ID is 945
2025-11-18T15:31:00.026Z,1763479860.026 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 946
2025-11-18T15:31:00.045Z,1763479860.045 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 947
2025-11-18T15:31:00.045Z,1763479860.045 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2025-11-18T15:31:00.049Z,1763479860.049 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 949
2025-11-18T15:31:00.052Z,1763479860.052 [WetLabsBB2FL](INFO): Powering up
2025-11-18T15:31:00.054Z,1763479860.054 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 951
2025-11-18T15:31:00.062Z,1763479860.062 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2MI79M.000
2025-11-18T15:31:00.062Z,1763479860.062 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2MI79M.000
2025-11-18T15:31:00.062Z,1763479860.062 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4MI2QL.000
2025-11-18T15:31:00.062Z,1763479860.062 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4MI2QL.000
2025-11-18T15:31:00.062Z,1763479860.062 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4MI2QM.000
2025-11-18T15:31:00.063Z,1763479860.063 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4MI2QM.000
2025-11-18T15:31:00.063Z,1763479860.063 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4MI2PM.000
2025-11-18T15:31:00.063Z,1763479860.063 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4MI2PM.000
2025-11-18T15:31:00.063Z,1763479860.063 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5MI74M.000
2025-11-18T15:31:00.063Z,1763479860.063 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5MI74M.000
2025-11-18T15:31:00.064Z,1763479860.064 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4MI2QN.000
2025-11-18T15:31:00.064Z,1763479860.064 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4MI2QN.000
2025-11-18T15:31:00.064Z,1763479860.064 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4MI2QO.000
2025-11-18T15:31:00.064Z,1763479860.064 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4MI2QO.000
2025-11-18T15:31:00.064Z,1763479860.064 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4MI2RO.000
2025-11-18T15:31:00.065Z,1763479860.065 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4MI2RO.000
2025-11-18T15:31:00.065Z,1763479860.065 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4MI2RN.000
2025-11-18T15:31:00.065Z,1763479860.065 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4MI2RN.000
2025-11-18T15:31:00.065Z,1763479860.065 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4MI2QP.000
2025-11-18T15:31:00.065Z,1763479860.065 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4MI2QP.000
2025-11-18T15:31:00.068Z,1763479860.068 [CBIT](DEBUG): Deactivating emergency mode.
2025-11-18T15:31:00.108Z,1763479860.108 [CBIT](DEBUG): Backplane powered.
2025-11-18T15:31:00.108Z,1763479860.108 [GFScanner](DEBUG): Initializing GFScanner
2025-11-18T15:31:00.108Z,1763479860.108 [GFScanner](DEBUG): Deactivating GF circuits.
2025-11-18T15:31:00.113Z,1763479860.113 [MissionManager](IMPORTANT): Using TethysL tl-to-tx parser
2025-11-18T15:31:00.114Z,1763479860.114 [MissionManager](INFO): Loading Mission from file: Missions/Startup.tl
2025-11-18T15:31:00.114Z,1763479860.114 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Startup.tl
2025-11-18T15:31:00.165Z,1763479860.165 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Startup.tl
2025-11-18T15:31:00.243Z,1763479860.243 [MissionManager](DEBUG): TethyslAPI: Missions/Startup.tl translated into:
2025-11-18T15:31:00.252Z,1763479860.252 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2025-11-18T15:31:00.316Z,1763479860.316 [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-11-18T15:31:00.317Z,1763479860.317 [MissionManager](INFO): Loading Mission from file: Missions/Default.tl
2025-11-18T15:31:00.317Z,1763479860.317 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Default.tl
2025-11-18T15:31:00.320Z,1763479860.320 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Default.tl
2025-11-18T15:31:00.432Z,1763479860.432 [Radio_Surface](INFO): Powering up
2025-11-18T15:31:00.621Z,1763479860.621 [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-11-18T15:31:00.634Z,1763479860.634 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2025-11-18T15:31:00.636Z,1763479860.636 [Default:A.Wait](DEBUG): Construct Wait.
2025-11-18T15:31:00.638Z,1763479860.638 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2025-11-18T15:31:00.688Z,1763479860.688 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2025-11-18T15:31:00.691Z,1763479860.691 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2025-11-18T15:31:00.712Z,1763479860.712 [Default:E.Execute](DEBUG): Construct Execute.
2025-11-18T15:31:00.715Z,1763479860.715 [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-11-18T15:31:00.740Z,1763479860.740 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BioacousticsDataBridge,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,Sonardyne_Nano,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,LcmPublisher,Reporter,LogSplitter,
2025-11-18T15:31:00.747Z,1763479860.747 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2025-11-18T15:31:00.812Z,1763479860.812 [Depth_Keller](INFO): Initializing.
2025-11-18T15:31:00.814Z,1763479860.814 [Power24vConverter](INFO): Powering up.
2025-11-18T15:31:00.814Z,1763479860.814 [Sonardyne_Nano](INFO): Initializing.
2025-11-18T15:31:00.857Z,1763479860.857 [DepthRateCalculator](ERROR): Depth measurement is not active
2025-11-18T15:31:00.928Z,1763479860.928 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2025-11-18T15:31:00.936Z,1763479860.936 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2025-11-18T15:31:00.937Z,1763479860.937 [ElevatorServo](DEBUG): Initializing EZServoServo.
2025-11-18T15:31:00.944Z,1763479860.944 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2025-11-18T15:31:00.945Z,1763479860.945 [MassServo](DEBUG): Initializing EZServoServo.
2025-11-18T15:31:00.952Z,1763479860.952 [MassServo](DEBUG): Initializing MassServo.
2025-11-18T15:31:00.953Z,1763479860.953 [RudderServo](DEBUG): Initializing EZServoServo.
2025-11-18T15:31:00.960Z,1763479860.960 [RudderServo](DEBUG): Initializing RudderServo.
2025-11-18T15:31:00.961Z,1763479860.961 [ThrusterHE](DEBUG): Initializing EZServoServo.
2025-11-18T15:31:00.968Z,1763479860.968 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2025-11-18T15:31:02.676Z,1763479862.676 [WetLabsBB2FL](INFO): Powering down
2025-11-18T15:31:02.770Z,1763479862.770 [Sonardyne_Nano](ERROR): Failed to get valid response or reached max queue size, flushing UART
2025-11-18T15:31:04.062Z,1763479864.062 [Sonardyne_Nano](IMPORTANT): Found beacon with acoustic ID 2107
2025-11-18T15:31:06.677Z,1763479866.677 [ThrusterHE](ERROR): Zero Speed Commanded.
2025-11-18T15:31:07.101Z,1763479867.101 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit.
2025-11-18T15:31:13.349Z,1763479873.349 [DAT](INFO): DAT read:
2025-11-18T15:31:13.350Z,1763479873.350 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series
2025-11-18T15:31:15.113Z,1763479875.113 [DAT](INFO): DAT read: MF Frequency Band
2025-11-18T15:31:15.114Z,1763479875.114 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0
2025-11-18T15:31:15.115Z,1763479875.115 [DAT](INFO): DAT read: Nov 17 2025 21:28:52
2025-11-18T15:31:16.121Z,1763479876.121 [DAT](INFO): DAT read: Features enabled [Bearing]
2025-11-18T15:31:16.122Z,1763479876.122 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP
2025-11-18T15:31:16.123Z,1763479876.123 [DAT](INFO): commRate: 800
2025-11-18T15:31:18.188Z,1763479878.188 [DAT](INFO): entering command mode
2025-11-18T15:31:18.388Z,1763479878.388 [DAT](INFO): DAT read:
2025-11-18T15:31:18.389Z,1763479878.389 [DAT](INFO): DAT read: user:1>
2025-11-18T15:31:18.389Z,1763479878.389 [DAT](INFO): setting verbose to 3
2025-11-18T15:31:18.641Z,1763479878.641 [DAT](INFO): DAT read: user:1>
2025-11-18T15:31:18.642Z,1763479878.642 [DAT](INFO): DAT read: Verbose | 3
2025-11-18T15:31:18.642Z,1763479878.642 [DAT](INFO): set verbose to 3
2025-11-18T15:31:18.642Z,1763479878.642 [DAT](INFO): setting DatVerbose to 27440
2025-11-18T15:31:18.892Z,1763479878.892 [DAT](INFO): DAT read: user:2>
2025-11-18T15:31:18.893Z,1763479878.893 [DAT](INFO): DAT read: DatVerbose | 27440
2025-11-18T15:31:18.894Z,1763479878.894 [DAT](INFO): set DatVerbose to 27440
2025-11-18T15:31:18.894Z,1763479878.894 [DAT](INFO): setting transmit power to 8
2025-11-18T15:31:19.145Z,1763479879.145 [DAT](INFO): DAT read: user:3>
2025-11-18T15:31:19.145Z,1763479879.145 [DAT](INFO): DAT read: TxPower | 8 (Max)
2025-11-18T15:31:19.146Z,1763479879.146 [DAT](INFO): set transmit power to 8
2025-11-18T15:31:19.146Z,1763479879.146 [DAT](INFO): setting local address to 12
2025-11-18T15:31:19.397Z,1763479879.397 [DAT](INFO): DAT read: user:4>
2025-11-18T15:31:19.398Z,1763479879.398 [DAT](INFO): DAT read: LocalAddr | 12
2025-11-18T15:31:19.398Z,1763479879.398 [DAT](INFO): set local address to 12
2025-11-18T15:31:19.399Z,1763479879.399 [DAT](INFO): Setting time to: 15:31:19 And date to:11/18/2025
2025-11-18T15:31:19.649Z,1763479879.649 [DAT](INFO): DAT read: user:5>
2025-11-18T15:31:19.650Z,1763479879.650 [DAT](INFO): DAT read: Tue Nov 18, 2025 15:31:19
2025-11-18T15:31:19.650Z,1763479879.650 [DAT](INFO): Local DAT time set to Tue Nov 18, 2025 15:31:19
2025-11-18T15:31:28.634Z,1763479888.634 [NAL9602](INFO): Powering up NAL9602
2025-11-18T15:31:35.514Z,1763479895.514 [SBIT](IMPORTANT): Beginning Startup BIT
2025-11-18T15:31:35.518Z,1763479895.518 [GFScanner](IMPORTANT): Beginning ground fault scan
2025-11-18T15:31:35.535Z,1763479895.535 [CommandExec](IMPORTANT): got command strobe off
2025-11-18T15:31:35.536Z,1763479895.536 [CommandExec](IMPORTANT): Deactivating strobe
2025-11-18T15:31:39.542Z,1763479899.542 [NAL9602](INFO): NAL9602 initialized
2025-11-18T15:31:40.024Z,1763479900.024 [GFScanner](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.003888
CHAN A1 (24V): -0.007615
CHAN A2 (12V): -0.004682
CHAN A3 (5V): -0.003220
CHAN B0 (3.3V): -0.000546
CHAN B1 (3.15aV): -0.001346
CHAN B2 (3.15bV): -0.001552
CHAN B3 (GND): 0.000071
OPEN: 0.006247
Full Scale: +/- 1 mA
2025-11-18T15:32:00.605Z,1763479920.605 [CommandExec](IMPORTANT): got command strobe off
2025-11-18T15:32:00.605Z,1763479920.605 [CommandExec](IMPORTANT): Deactivating strobe
2025-11-18T15:32:09.464Z,1763479929.464 [CommandExec](IMPORTANT): got command failComponent
2025-11-18T15:32:09.465Z,1763479929.465 [CommandExec](IMPORTANT): Failed components:
2025-11-18T15:32:09.465Z,1763479929.465 [CommandExec](IMPORTANT): No failed Components.
2025-11-18T15:32:29.703Z,1763479949.703 [SBIT](IMPORTANT): SBIT PASSED
2025-11-18T15:32:29.703Z,1763479949.703 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2025-11-18T15:32:29.721Z,1763479949.721 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=15 count;
2025-11-18T15:32:29.721Z,1763479949.721 [SBIT](IMPORTANT): Express linearApproximation _.planktivore_LM_AvgRois 1.000000 count_per_second;
2025-11-18T15:32:29.721Z,1763479949.721 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=217.372209 cubic_centimeter;
2025-11-18T15:32:29.721Z,1763479949.721 [SBIT](IMPORTANT): VerticalControl.massDefault=3.965159 millimeter;
2025-11-18T15:32:29.723Z,1763479949.723 [SBIT](IMPORTANT): Waterlinked.loadAtStartup=0 bool;
2025-11-18T15:32:30.127Z,1763479950.127 [MissionManager](IMPORTANT): Started mission Startup
2025-11-18T15:32:30.127Z,1763479950.127 [Startup] Running Loop=1
2025-11-18T15:32:30.128Z,1763479950.128 [Startup](DEBUG): Aggregate::initialize Startup
2025-11-18T15:32:30.128Z,1763479950.128 [Startup:A.GoToSurface] Running Loop=1
2025-11-18T15:32:30.128Z,1763479950.128 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-11-18T15:32:30.129Z,1763479950.129 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2025-11-18T15:32:30.129Z,1763479950.129 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2025-11-18T15:32:30.129Z,1763479950.129 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2025-11-18T15:32:30.130Z,1763479950.130 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2025-11-18T15:32:30.130Z,1763479950.130 [Startup:A.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-11-18T15:32:30.130Z,1763479950.130 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-11-18T15:32:30.148Z,1763479950.148 [Startup:StartupSatComms] Running Loop=1
2025-11-18T15:32:30.148Z,1763479950.148 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2025-11-18T15:32:30.148Z,1763479950.148 [Startup:StartupSatComms:A] Running Loop=1
2025-11-18T15:32:30.578Z,1763479950.578 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2025-11-18T15:32:34.993Z,1763479954.993 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2025-11-18T15:32:50.281Z,1763479970.281 [BPC1](ERROR): BPC1B: No match for serial number 0000 in BPC1B's battery stick inventory (sticks 32-62 in onboard configuration file).
2025-11-18T15:33:25.424Z,1763480005.424 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2025-11-18T15:33:30.287Z,1763480010.287 [Startup:StartupSatComms:A](INFO): Timed out from 2025-11-18T15:32:30.1Z
2025-11-18T15:33:30.287Z,1763480010.287 [Startup:StartupSatComms:A] Stopped
2025-11-18T15:33:30.287Z,1763480010.287 [Startup:StartupSatComms:B] Running Loop=1
2025-11-18T15:33:30.695Z,1763480010.695 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2025-11-18T15:33:42.393Z,1763480022.393 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2025-11-18T15:33:45.143Z,1763480025.143 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.005078
2025-11-18T15:33:51.283Z,1763480031.283 [BPC1](ERROR): BPC1B: No match for serial number 0000 in BPC1B's battery stick inventory (sticks 32-62 in onboard configuration file).
2025-11-18T15:33:52.516Z,1763480032.516 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20251118T153045/Courier0000.lzma
2025-11-18T15:33:53.518Z,1763480033.518 [DataOverHttps](INFO): Moved sent file to Logs/20251118T153045/Courier0000.lzma.bak
2025-11-18T15:33:53.518Z,1763480033.518 [DataOverHttps](INFO): SBD MOMSN=26313189
2025-11-18T15:33:59.359Z,1763480039.359 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2025-11-18T15:34:00.241Z,1763480040.241 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2025-11-18T15:34:00.241Z,1763480040.241 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-11-18T15:34:00.251Z,1763480040.251 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-11-18T15:34:00.599Z,1763480040.599 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-11-18T15:34:00.599Z,1763480040.599 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2025-11-18T15:34:09.337Z,1763480049.337 [DataOverHttps](INFO): Sending 954 bytes from file Logs/20251118T153045/Express0001.lzma
2025-11-18T15:34:10.338Z,1763480050.338 [DataOverHttps](INFO): Moved sent file to Logs/20251118T153045/Express0001.lzma.bak
2025-11-18T15:34:10.338Z,1763480050.338 [DataOverHttps](INFO): SBD MOMSN=26313192
2025-11-18T15:34:11.493Z,1763480051.493 [Startup:StartupSatComms:B] Stopped
2025-11-18T15:34:11.493Z,1763480051.493 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2025-11-18T15:34:11.493Z,1763480051.493 [Startup:StartupSatComms] Stopped
2025-11-18T15:34:11.494Z,1763480051.494 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2025-11-18T15:34:11.494Z,1763480051.494 [Startup](INFO): Completed Startup
2025-11-18T15:34:11.494Z,1763480051.494 [MissionManager](INFO): Startup is completed.
2025-11-18T15:34:11.495Z,1763480051.495 [MissionManager](INFO): Uninitializing Mission Startup
2025-11-18T15:34:11.495Z,1763480051.495 [Startup] Stopped
2025-11-18T15:34:11.495Z,1763480051.495 [Startup](DEBUG): Aggregate::uninitialize Startup
2025-11-18T15:34:11.495Z,1763480051.495 [Startup:A.GoToSurface] Stopped
2025-11-18T15:34:11.495Z,1763480051.495 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-11-18T15:34:11.897Z,1763480051.897 [MissionManager](IMPORTANT): Started mission Default
2025-11-18T15:34:11.898Z,1763480051.898 [Default] Running Loop=1
2025-11-18T15:34:11.898Z,1763480051.898 [Default](DEBUG): Aggregate::initialize Default
2025-11-18T15:34:11.898Z,1763480051.898 [Default:B.GoToSurface] Running Loop=1
2025-11-18T15:34:11.898Z,1763480051.898 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-11-18T15:34:11.898Z,1763480051.898 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2025-11-18T15:34:11.898Z,1763480051.898 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2025-11-18T15:34:11.899Z,1763480051.899 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2025-11-18T15:34:11.899Z,1763480051.899 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2025-11-18T15:34:11.899Z,1763480051.899 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-11-18T15:34:11.900Z,1763480051.900 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-11-18T15:34:11.900Z,1763480051.900 [Default:A.Wait] Running Loop=1
2025-11-18T15:34:11.900Z,1763480051.900 [Default:A.Wait](DEBUG): Initialize Wait Component.
2025-11-18T15:34:15.922Z,1763480055.922 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2025-11-18T15:34:25.263Z,1763480065.263 [Default:A.Wait](INFO): Done Waiting.
2025-11-18T15:34:25.263Z,1763480065.263 [Default:A.Wait] Stopped
2025-11-18T15:34:25.264Z,1763480065.264 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2025-11-18T15:34:25.658Z,1763480065.658 [Default:CheckIn] Running Loop=1
2025-11-18T15:34:25.658Z,1763480065.658 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-11-18T15:34:25.658Z,1763480065.658 [Default:CheckIn:Read_GPS] Running Loop=1
2025-11-18T15:34:26.053Z,1763480066.053 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2025-11-18T15:34:32.889Z,1763480072.889 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2025-11-18T15:34:49.857Z,1763480089.857 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2025-11-18T15:35:04.055Z,1763480104.055 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2025-11-18T15:35:06.825Z,1763480106.825 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2025-11-18T15:35:23.797Z,1763480123.797 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2025-11-18T15:35:24.558Z,1763480124.558 [CommandExec](IMPORTANT): got command get Sonardyne_Nano.chargePercent
2025-11-18T15:35:24.559Z,1763480124.559 [CommandExec](IMPORTANT): Sonardyne_Nano.chargePercent 100.000000 %
2025-11-18T15:35:40.401Z,1763480140.401 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2025-11-18T15:35:41.974Z,1763480141.974 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-11-18T15:35:59.749Z,1763480159.749 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-11-18T15:36:17.929Z,1763480177.929 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-11-18T15:36:35.323Z,1763480195.323 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-11-18T15:36:42.986Z,1763480202.986 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2025-11-18T15:36:53.485Z,1763480213.485 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-11-18T15:37:01.205Z,1763480221.205 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2025-11-18T15:37:01.205Z,1763480221.205 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-11-18T15:37:01.216Z,1763480221.216 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-11-18T15:37:01.618Z,1763480221.618 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-11-18T15:37:01.618Z,1763480221.618 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2025-11-18T15:37:08.577Z,1763480228.577 [CommandExec](IMPORTANT): got command burn on
2025-11-18T15:37:08.577Z,1763480228.577 [CommandExec](IMPORTANT): Activating dropweight wire
2025-11-18T15:37:10.491Z,1763480230.491 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2025-11-18T15:37:28.640Z,1763480248.640 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-11-18T15:37:46.811Z,1763480266.811 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-11-18T15:38:03.397Z,1763480283.397 [BPC1](INFO): Calculating totals. Valid battery stick count: 46. Valid reserve battery stick count: 4.
2025-11-18T15:38:03.404Z,1763480283.404 [BPC1](INFO): Received data from all battery sticks.
2025-11-18T15:39:25.745Z,1763480365.745 [Default:CheckIn:Read_GPS](INFO): Timed out from 2025-11-18T15:34:25.7Z
2025-11-18T15:39:25.745Z,1763480365.745 [Default:CheckIn:Read_GPS] Stopped
2025-11-18T15:39:25.745Z,1763480365.745 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-11-18T15:39:26.168Z,1763480366.168 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2025-11-18T15:39:26.579Z,1763480366.579 [Default:CheckIn:Read_Iridium] Stopped
2025-11-18T15:39:26.579Z,1763480366.579 [Default:CheckIn:C.Wait] Running Loop=1
2025-11-18T15:39:26.580Z,1763480366.580 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-11-18T15:40:02.131Z,1763480402.131 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2025-11-18T15:40:02.131Z,1763480402.131 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-11-18T15:40:02.142Z,1763480402.142 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-11-18T15:40:02.550Z,1763480402.550 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-11-18T15:40:02.550Z,1763480402.550 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2025-11-18T15:41:04.721Z,1763480464.721 [Sonardyne_Nano](INFO): Battery at maximum, disabling charging
2025-11-18T15:41:41.075Z,1763480501.075 [NAL9602](FAULT): GPS failed to acquire within timeout.
2025-11-18T15:41:41.075Z,1763480501.075 [NAL9602] Data Fault, FailCount= 1
2025-11-18T15:41:41.075Z,1763480501.075 [NAL9602](ERROR): Data Fault
2025-11-18T15:41:41.129Z,1763480501.129 [CBIT](ERROR): Data Fault in component: NAL9602
2025-11-18T15:41:41.479Z,1763480501.479 [NAL9602](INFO): Powering down
2025-11-18T15:41:42.313Z,1763480502.313 [CBIT](INFO): Clearing failed state for component NAL9602
2025-11-18T15:41:42.313Z,1763480502.313 [NAL9602] No Fault, FailCount= 1
2025-11-18T15:41:47.190Z,1763480507.190 [CommandExec](IMPORTANT): got command failComponent
2025-11-18T15:41:47.190Z,1763480507.190 [CommandExec](IMPORTANT): Failed components:
2025-11-18T15:41:47.190Z,1763480507.190 [CommandExec](IMPORTANT): No failed Components.
2025-11-18T15:42:11.783Z,1763480531.783 [NAL9602](INFO): Powering up NAL9602
2025-11-18T15:42:22.691Z,1763480542.691 [NAL9602](INFO): NAL9602 initialized
2025-11-18T15:43:03.109Z,1763480583.109 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2025-11-18T15:43:03.109Z,1763480583.109 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-11-18T15:43:03.152Z,1763480583.152 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-11-18T15:43:03.536Z,1763480583.536 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-11-18T15:43:03.536Z,1763480583.536 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2025-11-18T15:44:27.130Z,1763480667.130 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-11-18T15:44:27.131Z,1763480667.131 [Default:CheckIn:C.Wait] Stopped
2025-11-18T15:44:27.131Z,1763480667.131 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-11-18T15:44:27.131Z,1763480667.131 [Default:CheckIn:D] Running Loop=1
2025-11-18T15:44:27.529Z,1763480667.529 [Default:CheckIn:D] Stopped
2025-11-18T15:44:27.529Z,1763480667.529 [Default:CheckIn:E] Running Loop=1
2025-11-18T15:44:27.940Z,1763480667.940 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.260516 min
2025-11-18T15:44:27.940Z,1763480667.940 [Default:CheckIn:E] Stopped
2025-11-18T15:44:27.940Z,1763480667.940 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-11-18T15:44:27.940Z,1763480667.940 [Default:CheckIn] Stopped
2025-11-18T15:44:27.940Z,1763480667.940 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-11-18T15:44:27.940Z,1763480667.940 [Default:CheckIn](INFO): Running loop #2
2025-11-18T15:44:27.940Z,1763480667.940 [Default:CheckIn] Running Loop=2
2025-11-18T15:44:27.941Z,1763480667.941 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-11-18T15:44:27.941Z,1763480667.941 [Default:CheckIn:Read_GPS] Running Loop=1
2025-11-18T15:45:58.002Z,1763480758.002 [CommandExec](IMPORTANT): got command burn off
2025-11-18T15:45:58.003Z,1763480758.003 [CommandExec](IMPORTANT): Deactivating dropweight wire
2025-11-18T15:46:04.113Z,1763480764.113 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2025-11-18T15:46:04.113Z,1763480764.113 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-11-18T15:46:04.150Z,1763480764.150 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-11-18T15:46:04.511Z,1763480764.511 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-11-18T15:46:04.512Z,1763480764.512 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2025-11-18T15:47:01.346Z,1763480821.346 [DataOverHttps](INFO): Exceeded connection timeout, disconnecting.
2025-11-18T15:47:03.354Z,1763480823.354 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.487331
2025-11-18T15:47:13.670Z,1763480833.670 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.002955
2025-11-18T15:49:05.085Z,1763480945.085 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6
2025-11-18T15:49:05.085Z,1763480945.085 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-11-18T15:49:05.095Z,1763480945.095 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-11-18T15:49:05.530Z,1763480945.530 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-11-18T15:49:05.531Z,1763480945.531 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6
2025-11-18T15:49:28.112Z,1763480968.112 [Default:CheckIn:Read_GPS](INFO): Timed out from 2025-11-18T15:44:27.9Z
2025-11-18T15:49:28.112Z,1763480968.112 [Default:CheckIn:Read_GPS] Stopped
2025-11-18T15:49:28.112Z,1763480968.112 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-11-18T15:49:34.289Z,1763480974.289 [DataOverHttps](INFO): Sending 168 bytes from file Logs/20251118T153045/Courier0004.lzma
2025-11-18T15:49:35.291Z,1763480975.291 [DataOverHttps](INFO): Moved sent file to Logs/20251118T153045/Courier0004.lzma.bak
2025-11-18T15:49:35.291Z,1763480975.291 [DataOverHttps](INFO): SBD MOMSN=26313242
2025-11-18T15:49:50.821Z,1763480990.821 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20251118T153045/Courier0007.lzma
2025-11-18T15:49:51.824Z,1763480991.824 [DataOverHttps](INFO): Moved sent file to Logs/20251118T153045/Courier0007.lzma.bak
2025-11-18T15:49:51.824Z,1763480991.824 [DataOverHttps](INFO): SBD MOMSN=26313244
2025-11-18T15:50:07.373Z,1763481007.373 [DataOverHttps](INFO): Sending 285 bytes from file Logs/20251118T153045/Express0005.lzma
2025-11-18T15:50:08.375Z,1763481008.375 [DataOverHttps](INFO): Moved sent file to Logs/20251118T153045/Express0005.lzma.bak
2025-11-18T15:50:08.376Z,1763481008.376 [DataOverHttps](INFO): SBD MOMSN=26313246
2025-11-18T15:50:23.945Z,1763481023.945 [DataOverHttps](INFO): Sending 273 bytes from file Logs/20251118T153045/Express0008.lzma
2025-11-18T15:50:24.947Z,1763481024.947 [DataOverHttps](INFO): Moved sent file to Logs/20251118T153045/Express0008.lzma.bak
2025-11-18T15:50:24.947Z,1763481024.947 [DataOverHttps](INFO): SBD MOMSN=26313254
2025-11-18T15:50:26.294Z,1763481026.294 [Default:CheckIn:Read_Iridium] Stopped
2025-11-18T15:50:26.294Z,1763481026.294 [Default:CheckIn:C.Wait] Running Loop=1
2025-11-18T15:50:26.294Z,1763481026.294 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-11-18T15:52:06.103Z,1763481126.103 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7
2025-11-18T15:52:06.103Z,1763481126.103 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-11-18T15:52:06.113Z,1763481126.113 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-11-18T15:52:06.524Z,1763481126.524 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-11-18T15:52:06.524Z,1763481126.524 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7
2025-11-18T15:52:23.847Z,1763481143.847 [NAL9602](FAULT): GPS failed to acquire within timeout.
2025-11-18T15:52:23.847Z,1763481143.847 [NAL9602] Data Fault, FailCount= 2
2025-11-18T15:52:23.848Z,1763481143.848 [NAL9602](ERROR): Data Fault
2025-11-18T15:52:23.865Z,1763481143.865 [CBIT](ERROR): Data Fault in component: NAL9602
2025-11-18T15:52:24.251Z,1763481144.251 [NAL9602](INFO): Powering down
2025-11-18T15:52:25.076Z,1763481145.076 [CBIT](INFO): Clearing failed state for component NAL9602
2025-11-18T15:52:25.076Z,1763481145.076 [NAL9602] No Fault, FailCount= 2
2025-11-18T15:52:54.548Z,1763481174.548 [NAL9602](INFO): Powering up NAL9602
2025-11-18T15:53:05.463Z,1763481185.463 [NAL9602](INFO): NAL9602 initialized
2025-11-18T15:55:07.075Z,1763481307.075 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8
2025-11-18T15:55:07.075Z,1763481307.075 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-11-18T15:55:07.086Z,1763481307.086 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-11-18T15:55:07.488Z,1763481307.488 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-11-18T15:55:07.488Z,1763481307.488 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8
2025-11-18T15:55:26.870Z,1763481326.870 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-11-18T15:55:26.870Z,1763481326.870 [Default:CheckIn:C.Wait] Stopped
2025-11-18T15:55:26.870Z,1763481326.870 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-11-18T15:55:26.870Z,1763481326.870 [Default:CheckIn:D] Running Loop=1
2025-11-18T15:55:27.275Z,1763481327.275 [Default:CheckIn:D] Stopped
2025-11-18T15:55:27.275Z,1763481327.275 [Default:CheckIn:E] Running Loop=1
2025-11-18T15:55:27.680Z,1763481327.680 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 21.256287 min
2025-11-18T15:55:27.680Z,1763481327.680 [Default:CheckIn:E] Stopped
2025-11-18T15:55:27.680Z,1763481327.680 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-11-18T15:55:27.680Z,1763481327.680 [Default:CheckIn] Stopped
2025-11-18T15:55:27.680Z,1763481327.680 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-11-18T15:55:27.680Z,1763481327.680 [Default:CheckIn](INFO): Running loop #3
2025-11-18T15:55:27.681Z,1763481327.681 [Default:CheckIn] Running Loop=3
2025-11-18T15:55:27.681Z,1763481327.681 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-11-18T15:55:27.681Z,1763481327.681 [Default:CheckIn:Read_GPS] Running Loop=1
2025-11-18T15:58:02.409Z,1763481482.409 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155801.00,A,3648.17337,N,12147.27272,W,2.022,114.53,181125,,,A*71
2025-11-18T15:58:02.412Z,1763481482.412 [NAL9602](INFO): GPS fix at 20251118T155801: (36.802889, -121.787879)
2025-11-18T15:58:02.423Z,1763481482.423 [Default:CheckIn:Read_GPS] Stopped
2025-11-18T15:58:02.424Z,1763481482.424 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-11-18T15:58:09.653Z,1763481489.653 [DataOverHttps](INFO): Sending 223 bytes from file Logs/20251118T153045/Courier0010.lzma
2025-11-18T15:58:10.655Z,1763481490.655 [DataOverHttps](INFO): Moved sent file to Logs/20251118T153045/Courier0010.lzma.bak
2025-11-18T15:58:10.655Z,1763481490.655 [DataOverHttps](INFO): SBD MOMSN=26313303
2025-11-18T15:58:26.385Z,1763481506.385 [DataOverHttps](INFO): Sending 372 bytes from file Logs/20251118T153045/Express0011.lzma
2025-11-18T15:58:27.387Z,1763481507.387 [DataOverHttps](INFO): Moved sent file to Logs/20251118T153045/Express0011.lzma.bak
2025-11-18T15:58:27.387Z,1763481507.387 [DataOverHttps](INFO): SBD MOMSN=26313307
2025-11-18T15:58:28.676Z,1763481508.676 [Default:CheckIn:Read_Iridium] Stopped
2025-11-18T15:58:28.676Z,1763481508.676 [Default:CheckIn:C.Wait] Running Loop=1
2025-11-18T15:58:28.676Z,1763481508.676 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-11-18T15:58:34.738Z,1763481514.738 [NAL9602](INFO): Not Powering down - fast GPS
2025-11-18T15:59:11.147Z,1763481551.147 [DataOverHttps](IMPORTANT): SBD MTMSN=20251118T155909
2025-11-18T15:59:18.497Z,1763481558.497 [DataOverHttps](INFO): Received command: failc
2025-11-18T15:59:18.542Z,1763481558.542 [CommandExec](IMPORTANT): got command failComponent
2025-11-18T15:59:18.542Z,1763481558.542 [CommandExec](IMPORTANT): Failed components:
2025-11-18T15:59:18.542Z,1763481558.542 [CommandExec](IMPORTANT): No failed Components.
2025-11-18T15:59:19.499Z,1763481559.499 [DataOverHttps](IMPORTANT): SBD MTMSN=20251118T155918
2025-11-18T15:59:26.825Z,1763481566.825 [DataOverHttps](INFO): Received command: ibit
2025-11-18T15:59:26.882Z,1763481566.882 [CommandExec](IMPORTANT): got command ibit
2025-11-18T15:59:27.290Z,1763481567.290 [IBIT](IMPORTANT): Beginning Initiated BIT
2025-11-18T15:59:27.290Z,1763481567.290 [IBIT](IMPORTANT): Beginning control surface checks.
2025-11-18T15:59:27.294Z,1763481567.294 [GFScanner](IMPORTANT): Beginning ground fault scan
2025-11-18T15:59:28.877Z,1763481568.877 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155927.00,A,3648.14789,N,12147.25376,W,0.019,181.76,181125,,,A*70
2025-11-18T15:59:28.879Z,1763481568.879 [NAL9602](INFO): GPS fix at 20251118T155927: (36.802465, -121.787563)
2025-11-18T15:59:31.801Z,1763481571.801 [GFScanner](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.005357
CHAN A1 (24V): -0.007257
CHAN A2 (12V): -0.005172
CHAN A3 (5V): -0.002693
CHAN B0 (3.3V): -0.001269
CHAN B1 (3.15aV): -0.001320
CHAN B2 (3.15bV): -0.001624
CHAN B3 (GND): -0.000119
OPEN: 0.004702
Full Scale: +/- 1 mA
2025-11-18T15:59:44.232Z,1763481584.232 [NAL9602](INFO): SBD MO Status=0, MOMSN=11530, MT Status=0, MTMSN=0
2025-11-18T15:59:44.232Z,1763481584.232 [NAL9602](INFO): No messages in MT queue
2025-11-18T15:59:45.446Z,1763481585.446 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155944.00,A,3648.14810,N,12147.25401,W,0.039,181.76,181125,,,A*7F
2025-11-18T15:59:45.448Z,1763481585.448 [NAL9602](INFO): GPS fix at 20251118T155944: (36.802468, -121.787567)
2025-11-18T15:59:48.268Z,1763481588.268 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155947.00,A,3648.14820,N,12147.25418,W,0.039,181.76,181125,,,A*77
2025-11-18T15:59:48.270Z,1763481588.270 [NAL9602](INFO): GPS fix at 20251118T155947: (36.802470, -121.787570)
2025-11-18T15:59:51.504Z,1763481591.504 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155950.00,A,3648.14827,N,12147.25442,W,0.019,181.76,181125,,,A*7B
2025-11-18T15:59:51.507Z,1763481591.507 [NAL9602](INFO): GPS fix at 20251118T155950: (36.802471, -121.787574)
2025-11-18T15:59:54.328Z,1763481594.328 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155953.00,A,3648.14825,N,12147.25472,W,0.039,181.76,181125,,,A*7B
2025-11-18T15:59:54.346Z,1763481594.346 [NAL9602](INFO): GPS fix at 20251118T155953: (36.802471, -121.787579)
2025-11-18T15:59:57.569Z,1763481597.569 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155956.00,A,3648.14833,N,12147.25505,W,0.039,181.76,181125,,,A*78
2025-11-18T15:59:57.571Z,1763481597.571 [NAL9602](INFO): GPS fix at 20251118T155956: (36.802472, -121.787584)
2025-11-18T15:59:59.981Z,1763481599.981 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155959.00,A,3648.14846,N,12147.25527,W,0.039,181.76,181125,,,A*75
2025-11-18T15:59:59.988Z,1763481599.988 [NAL9602](INFO): GPS fix at 20251118T155959: (36.802474, -121.787588)
2025-11-18T16:00:03.207Z,1763481603.207 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160002.00,A,3648.14864,N,12147.25552,W,0.039,181.76,181125,,,A*76
2025-11-18T16:00:03.210Z,1763481603.210 [NAL9602](INFO): GPS fix at 20251118T160002: (36.802477, -121.787592)
2025-11-18T16:00:06.033Z,1763481606.033 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160005.00,A,3648.14879,N,12147.25590,W,0.039,181.76,181125,,,A*73
2025-11-18T16:00:06.035Z,1763481606.035 [NAL9602](INFO): GPS fix at 20251118T160005: (36.802480, -121.787598)
2025-11-18T16:00:08.865Z,1763481608.865 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160008.00,A,3648.14886,N,12147.25625,W,0.019,181.76,181125,,,A*71
2025-11-18T16:00:08.868Z,1763481608.868 [NAL9602](INFO): GPS fix at 20251118T160008: (36.802481, -121.787604)
2025-11-18T16:00:12.097Z,1763481612.097 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160011.00,A,3648.14894,N,12147.25649,W,0.019,181.76,181125,,,A*70
2025-11-18T16:00:12.100Z,1763481612.100 [NAL9602](INFO): GPS fix at 20251118T160011: (36.802482, -121.787608)
2025-11-18T16:00:13.749Z,1763481613.749 [IBIT](IMPORTANT): Communications Status:
Fix Status: 1
Iridium Signal Strength: 3
Latitude: 36.802483 Longitude: -121.787605
2025-11-18T16:00:14.126Z,1763481614.126 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 0.000000
Voltage: 16.770000
2025-11-18T16:00:14.127Z,1763481614.127 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah
2025-11-18T16:00:14.127Z,1763481614.127 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V
2025-11-18T16:00:14.532Z,1763481614.532 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2025-11-18T16:00:14.532Z,1763481614.532 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2025-11-18T16:00:14.532Z,1763481614.532 [IBIT](IMPORTANT): Pressure:9.714521 PSI
2025-11-18T16:00:14.533Z,1763481614.533 [IBIT](IMPORTANT): Humidity:19.545843 %
2025-11-18T16:00:14.955Z,1763481614.955 [IBIT](IMPORTANT): Vehicle Pitch:0.167675 degrees
2025-11-18T16:00:14.955Z,1763481614.955 [IBIT](IMPORTANT): Vehicle Roll:-4.431721 degrees
2025-11-18T16:00:14.955Z,1763481614.955 [IBIT](IMPORTANT): Vehicle Heading:192.711609 degrees
2025-11-18T16:00:15.337Z,1763481615.337 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2025-11-18T16:00:15.338Z,1763481615.338 [IBIT](IMPORTANT): buoyancyNeutral: 217.372208 cc
2025-11-18T16:00:15.338Z,1763481615.338 [IBIT](IMPORTANT): massDefault: 0.396516 cm
2025-11-18T16:00:15.339Z,1763481615.339 [IBIT](IMPORTANT): stopDepth: 275.000000 m
2025-11-18T16:00:15.339Z,1763481615.339 [IBIT](IMPORTANT): abortDepth: 300.000000 m
2025-11-18T16:00:15.339Z,1763481615.339 [IBIT](IMPORTANT): IBIT PASSED
2025-11-18T16:00:44.411Z,1763481644.411 [NAL9602](INFO): Not Powering down - fast GPS
2025-11-18T16:03:29.262Z,1763481809.262 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-11-18T16:03:29.262Z,1763481809.262 [Default:CheckIn:C.Wait] Stopped
2025-11-18T16:03:29.263Z,1763481809.263 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-11-18T16:03:29.263Z,1763481809.263 [Default:CheckIn:D] Running Loop=1
2025-11-18T16:03:29.661Z,1763481809.661 [Default:CheckIn:D] Stopped
2025-11-18T16:03:29.661Z,1763481809.661 [Default:CheckIn:E] Running Loop=1
2025-11-18T16:03:30.062Z,1763481810.062 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 29.296051 min
2025-11-18T16:03:30.062Z,1763481810.062 [Default:CheckIn:E] Stopped
2025-11-18T16:03:30.063Z,1763481810.063 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-11-18T16:03:30.063Z,1763481810.063 [Default:CheckIn] Stopped
2025-11-18T16:03:30.063Z,1763481810.063 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-11-18T16:03:30.063Z,1763481810.063 [Default:CheckIn](INFO): Running loop #4
2025-11-18T16:03:30.063Z,1763481810.063 [Default:CheckIn] Running Loop=4
2025-11-18T16:03:30.063Z,1763481810.063 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-11-18T16:03:30.063Z,1763481810.063 [Default:CheckIn:Read_GPS] Running Loop=1
2025-11-18T16:03:32.077Z,1763481812.077 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160331.00,A,3648.15038,N,12147.22254,W,0.097,9.05,181125,,,D*77
2025-11-18T16:03:32.080Z,1763481812.080 [NAL9602](INFO): GPS fix at 20251118T160331: (36.802506, -121.787042)
2025-11-18T16:03:32.103Z,1763481812.103 [Default:CheckIn:Read_GPS] Stopped
2025-11-18T16:03:32.103Z,1763481812.103 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-11-18T16:03:34.364Z,1763481814.364 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20251118T153045/Courier0013.lzma
2025-11-18T16:03:35.108Z,1763481815.108 [DataOverHttps](INFO): Moved sent file to Logs/20251118T153045/Courier0013.lzma.bak
2025-11-18T16:03:35.108Z,1763481815.108 [DataOverHttps](INFO): SBD MOMSN=26313829
2025-11-18T16:03:47.101Z,1763481827.101 [NAL9602](INFO): SBD MO Status=0, MOMSN=11531, MT Status=0, MTMSN=0
2025-11-18T16:03:47.101Z,1763481827.101 [NAL9602](INFO): No messages in MT queue
2025-11-18T16:03:50.840Z,1763481830.840 [DataOverHttps](INFO): Sending 1082 bytes from file Logs/20251118T153045/Express0014.lzma
2025-11-18T16:03:51.840Z,1763481831.840 [DataOverHttps](INFO): Moved sent file to Logs/20251118T153045/Express0014.lzma.bak
2025-11-18T16:03:51.841Z,1763481831.841 [DataOverHttps](INFO): SBD MOMSN=26313834
2025-11-18T16:04:07.538Z,1763481847.538 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20251118T153045/Express0017.lzma
2025-11-18T16:04:08.540Z,1763481848.540 [DataOverHttps](INFO): Moved sent file to Logs/20251118T153045/Express0017.lzma.bak
2025-11-18T16:04:08.541Z,1763481848.541 [DataOverHttps](INFO): SBD MOMSN=26313916
2025-11-18T16:04:09.737Z,1763481849.737 [Default:CheckIn:Read_Iridium] Stopped
2025-11-18T16:04:09.737Z,1763481849.737 [Default:CheckIn:C.Wait] Running Loop=1
2025-11-18T16:04:09.737Z,1763481849.737 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-11-18T16:04:17.799Z,1763481857.799 [NAL9602](INFO): Not Powering down - fast GPS
2025-11-18T16:09:10.332Z,1763482150.332 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-11-18T16:09:10.332Z,1763482150.332 [Default:CheckIn:C.Wait] Stopped
2025-11-18T16:09:10.332Z,1763482150.332 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-11-18T16:09:10.332Z,1763482150.332 [Default:CheckIn:D] Running Loop=1
2025-11-18T16:09:10.717Z,1763482150.717 [Default:CheckIn:D] Stopped
2025-11-18T16:09:10.717Z,1763482150.717 [Default:CheckIn:E] Running Loop=1
2025-11-18T16:09:11.123Z,1763482151.123 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 34.980326 min
2025-11-18T16:09:11.123Z,1763482151.123 [Default:CheckIn:E] Stopped
2025-11-18T16:09:11.124Z,1763482151.124 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-11-18T16:09:11.124Z,1763482151.124 [Default:CheckIn] Stopped
2025-11-18T16:09:11.124Z,1763482151.124 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-11-18T16:09:11.124Z,1763482151.124 [Default:CheckIn](INFO): Running loop #5
2025-11-18T16:09:11.124Z,1763482151.124 [Default:CheckIn] Running Loop=5
2025-11-18T16:09:11.124Z,1763482151.124 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-11-18T16:09:11.124Z,1763482151.124 [Default:CheckIn:Read_GPS] Running Loop=1
2025-11-18T16:09:13.137Z,1763482153.137 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160912.00,A,3648.15379,N,12147.22180,W,0.058,115.53,181125,,,A*79
2025-11-18T16:09:13.140Z,1763482153.140 [NAL9602](INFO): GPS fix at 20251118T160912: (36.802563, -121.787030)
2025-11-18T16:09:13.150Z,1763482153.150 [Default:CheckIn:Read_GPS] Stopped
2025-11-18T16:09:13.150Z,1763482153.150 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-11-18T16:09:20.558Z,1763482160.558 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20251118T153045/Courier0019.lzma
2025-11-18T16:09:21.560Z,1763482161.560 [DataOverHttps](INFO): Moved sent file to Logs/20251118T153045/Courier0019.lzma.bak
2025-11-18T16:09:21.561Z,1763482161.561 [DataOverHttps](INFO): SBD MOMSN=26314279
2025-11-18T16:09:37.294Z,1763482177.294 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20251118T153045/Express0020.lzma
2025-11-18T16:09:38.296Z,1763482178.296 [DataOverHttps](INFO): Moved sent file to Logs/20251118T153045/Express0020.lzma.bak
2025-11-18T16:09:38.297Z,1763482178.297 [DataOverHttps](INFO): SBD MOMSN=26314323
2025-11-18T16:09:39.405Z,1763482179.405 [Default:CheckIn:Read_Iridium] Stopped
2025-11-18T16:09:39.405Z,1763482179.405 [Default:CheckIn:C.Wait] Running Loop=1
2025-11-18T16:09:39.405Z,1763482179.405 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-11-18T16:09:42.629Z,1763482182.629 [NAL9602](INFO): SBD MO Status=0, MOMSN=11532, MT Status=0, MTMSN=0
2025-11-18T16:09:42.629Z,1763482182.629 [NAL9602](INFO): No messages in MT queue
2025-11-18T16:10:13.323Z,1763482213.323 [NAL9602](INFO): Not Powering down - fast GPS
2025-11-18T16:14:39.977Z,1763482479.977 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-11-18T16:14:39.977Z,1763482479.977 [Default:CheckIn:C.Wait] Stopped
2025-11-18T16:14:39.977Z,1763482479.977 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-11-18T16:14:39.977Z,1763482479.977 [Default:CheckIn:D] Running Loop=1
2025-11-18T16:14:40.379Z,1763482480.379 [Default:CheckIn:D] Stopped
2025-11-18T16:14:40.379Z,1763482480.379 [Default:CheckIn:E] Running Loop=1
2025-11-18T16:14:40.788Z,1763482480.788 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 40.474683 min
2025-11-18T16:14:40.788Z,1763482480.788 [Default:CheckIn:E] Stopped
2025-11-18T16:14:40.788Z,1763482480.788 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-11-18T16:14:40.788Z,1763482480.788 [Default:CheckIn] Stopped
2025-11-18T16:14:40.788Z,1763482480.788 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-11-18T16:14:40.789Z,1763482480.789 [Default:CheckIn](INFO): Running loop #6
2025-11-18T16:14:40.789Z,1763482480.789 [Default:CheckIn] Running Loop=6
2025-11-18T16:14:40.789Z,1763482480.789 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-11-18T16:14:40.789Z,1763482480.789 [Default:CheckIn:Read_GPS] Running Loop=1
2025-11-18T16:14:42.801Z,1763482482.801 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,161441.00,A,3648.15331,N,12147.22114,W,0.019,115.53,181125,,,D*72
2025-11-18T16:14:42.804Z,1763482482.804 [NAL9602](INFO): GPS fix at 20251118T161441: (36.802555, -121.787019)
2025-11-18T16:14:42.834Z,1763482482.834 [Default:CheckIn:Read_GPS] Stopped
2025-11-18T16:14:42.834Z,1763482482.834 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-11-18T16:14:49.902Z,1763482489.902 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20251118T153045/Courier0022.lzma
2025-11-18T16:14:50.904Z,1763482490.904 [DataOverHttps](INFO): Moved sent file to Logs/20251118T153045/Courier0022.lzma.bak
2025-11-18T16:14:50.905Z,1763482490.905 [DataOverHttps](INFO): SBD MOMSN=26314517
2025-11-18T16:15:03.082Z,1763482503.082 [NAL9602](INFO): SBD MO Status=2, MOMSN=11533, MT Status=2, MTMSN=0
2025-11-18T16:15:03.082Z,1763482503.082 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-11-18T16:15:06.351Z,1763482506.351 [DataOverHttps](INFO): Sending 153 bytes from file Logs/20251118T153045/Express0023.lzma
2025-11-18T16:15:07.353Z,1763482507.353 [DataOverHttps](INFO): Moved sent file to Logs/20251118T153045/Express0023.lzma.bak
2025-11-18T16:15:07.354Z,1763482507.354 [DataOverHttps](INFO): SBD MOMSN=26314539
2025-11-18T16:15:08.745Z,1763482508.745 [Default:CheckIn:Read_Iridium] Stopped
2025-11-18T16:15:08.745Z,1763482508.745 [Default:CheckIn:C.Wait] Running Loop=1
2025-11-18T16:15:08.745Z,1763482508.745 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-11-18T16:15:34.998Z,1763482534.998 [NAL9602](INFO): SBD MO Status=2, MOMSN=11533, MT Status=2, MTMSN=0
2025-11-18T16:15:34.998Z,1763482534.998 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-11-18T16:16:00.449Z,1763482560.449 [NAL9602](INFO): SBD MO Status=2, MOMSN=11533, MT Status=2, MTMSN=0
2025-11-18T16:16:00.449Z,1763482560.449 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-11-18T16:16:18.228Z,1763482578.228 [NAL9602](INFO): SBD MO Status=2, MOMSN=11533, MT Status=2, MTMSN=0
2025-11-18T16:16:18.228Z,1763482578.228 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-11-18T16:17:03.879Z,1763482623.879 [NAL9602](INFO): SBD MO Status=2, MOMSN=11533, MT Status=2, MTMSN=0
2025-11-18T16:17:03.879Z,1763482623.879 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-11-18T16:17:23.271Z,1763482643.271 [NAL9602](INFO): SBD MO Status=0, MOMSN=11533, MT Status=0, MTMSN=0
2025-11-18T16:17:23.271Z,1763482643.271 [NAL9602](INFO): No messages in MT queue
2025-11-18T16:17:53.977Z,1763482673.977 [NAL9602](INFO): Not Powering down - fast GPS
2025-11-18T16:20:09.326Z,1763482809.326 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-11-18T16:20:09.326Z,1763482809.326 [Default:CheckIn:C.Wait] Stopped
2025-11-18T16:20:09.326Z,1763482809.326 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-11-18T16:20:09.326Z,1763482809.326 [Default:CheckIn:D] Running Loop=1
2025-11-18T16:20:09.725Z,1763482809.725 [Default:CheckIn:D] Stopped
2025-11-18T16:20:09.725Z,1763482809.725 [Default:CheckIn:E] Running Loop=1
2025-11-18T16:20:10.138Z,1763482810.138 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 45.963790 min
2025-11-18T16:20:10.138Z,1763482810.138 [Default:CheckIn:E] Stopped
2025-11-18T16:20:10.138Z,1763482810.138 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-11-18T16:20:10.139Z,1763482810.139 [Default:CheckIn] Stopped
2025-11-18T16:20:10.139Z,1763482810.139 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-11-18T16:20:10.139Z,1763482810.139 [Default:CheckIn](INFO): Running loop #7
2025-11-18T16:20:10.139Z,1763482810.139 [Default:CheckIn] Running Loop=7
2025-11-18T16:20:10.139Z,1763482810.139 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-11-18T16:20:10.139Z,1763482810.139 [Default:CheckIn:Read_GPS] Running Loop=1
2025-11-18T16:20:12.142Z,1763482812.142 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162011.00,A,3648.31904,N,12147.12417,W,4.413,8.15,181125,,,D*7A
2025-11-18T16:20:12.153Z,1763482812.153 [NAL9602](INFO): GPS fix at 20251118T162011: (36.805317, -121.785403)
2025-11-18T16:20:12.175Z,1763482812.175 [Default:CheckIn:Read_GPS] Stopped
2025-11-18T16:20:12.175Z,1763482812.175 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-11-18T16:20:19.283Z,1763482819.283 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20251118T153045/Courier0025.lzma
2025-11-18T16:20:20.285Z,1763482820.285 [DataOverHttps](INFO): Moved sent file to Logs/20251118T153045/Courier0025.lzma.bak
2025-11-18T16:20:20.285Z,1763482820.285 [DataOverHttps](INFO): SBD MOMSN=26314637
2025-11-18T16:20:27.503Z,1763482827.503 [NAL9602](INFO): SBD MO Status=0, MOMSN=11534, MT Status=0, MTMSN=0
2025-11-18T16:20:27.504Z,1763482827.504 [NAL9602](INFO): No messages in MT queue
2025-11-18T16:20:36.139Z,1763482836.139 [DataOverHttps](INFO): Sending 168 bytes from file Logs/20251118T153045/Express0026.lzma
2025-11-18T16:20:37.141Z,1763482837.141 [DataOverHttps](INFO): Moved sent file to Logs/20251118T153045/Express0026.lzma.bak
2025-11-18T16:20:37.142Z,1763482837.142 [DataOverHttps](INFO): SBD MOMSN=26314642
2025-11-18T16:20:38.409Z,1763482838.409 [Default:CheckIn:Read_Iridium] Stopped
2025-11-18T16:20:38.409Z,1763482838.409 [Default:CheckIn:C.Wait] Running Loop=1
2025-11-18T16:20:38.409Z,1763482838.409 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-11-18T16:20:58.200Z,1763482858.200 [NAL9602](INFO): Not Powering down - fast GPS
2025-11-18T16:25:39.025Z,1763483139.025 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-11-18T16:25:39.025Z,1763483139.025 [Default:CheckIn:C.Wait] Stopped
2025-11-18T16:25:39.025Z,1763483139.025 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-11-18T16:25:39.026Z,1763483139.026 [Default:CheckIn:D] Running Loop=1
2025-11-18T16:25:39.419Z,1763483139.419 [Default:CheckIn:D] Stopped
2025-11-18T16:25:39.419Z,1763483139.419 [Default:CheckIn:E] Running Loop=1
2025-11-18T16:25:39.823Z,1763483139.823 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 51.458687 min
2025-11-18T16:25:39.823Z,1763483139.823 [Default:CheckIn:E] Stopped
2025-11-18T16:25:39.823Z,1763483139.823 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-11-18T16:25:39.823Z,1763483139.823 [Default:CheckIn] Stopped
2025-11-18T16:25:39.823Z,1763483139.823 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-11-18T16:25:39.824Z,1763483139.824 [Default:CheckIn](INFO): Running loop #8
2025-11-18T16:25:39.824Z,1763483139.824 [Default:CheckIn] Running Loop=8
2025-11-18T16:25:39.824Z,1763483139.824 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-11-18T16:25:39.824Z,1763483139.824 [Default:CheckIn:Read_GPS] Running Loop=1
2025-11-18T16:25:41.836Z,1763483141.836 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162540.00,A,3648.25875,N,12147.83738,W,21.402,264.05,181125,,,D*41
2025-11-18T16:25:41.839Z,1763483141.839 [NAL9602](INFO): GPS fix at 20251118T162540: (36.804313, -121.797290)
2025-11-18T16:25:41.849Z,1763483141.849 [Default:CheckIn:Read_GPS] Stopped
2025-11-18T16:25:41.849Z,1763483141.849 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-11-18T16:25:48.695Z,1763483148.695 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20251118T153045/Courier0028.lzma
2025-11-18T16:25:49.697Z,1763483149.697 [DataOverHttps](INFO): Moved sent file to Logs/20251118T153045/Courier0028.lzma.bak
2025-11-18T16:25:49.698Z,1763483149.698 [DataOverHttps](INFO): SBD MOMSN=26314928
2025-11-18T16:25:59.614Z,1763483159.614 [NAL9602](INFO): SBD MO Status=0, MOMSN=11535, MT Status=0, MTMSN=0
2025-11-18T16:25:59.614Z,1763483159.614 [NAL9602](INFO): No messages in MT queue
2025-11-18T16:26:05.511Z,1763483165.511 [DataOverHttps](INFO): Sending 167 bytes from file Logs/20251118T153045/Express0029.lzma
2025-11-18T16:26:06.514Z,1763483166.514 [DataOverHttps](INFO): Moved sent file to Logs/20251118T153045/Express0029.lzma.bak
2025-11-18T16:26:06.514Z,1763483166.514 [DataOverHttps](INFO): SBD MOMSN=26314936
2025-11-18T16:26:07.697Z,1763483167.697 [Default:CheckIn:Read_Iridium] Stopped
2025-11-18T16:26:07.697Z,1763483167.697 [Default:CheckIn:C.Wait] Running Loop=1
2025-11-18T16:26:07.697Z,1763483167.697 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-11-18T16:26:30.313Z,1763483190.313 [NAL9602](INFO): Not Powering down - fast GPS
2025-11-18T16:27:48.560Z,1763483268.560 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-11-18T16:27:50.568Z,1763483270.568 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.239201
2025-11-18T16:28:23.708Z,1763483303.708 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-11-18T16:28:58.848Z,1763483338.848 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-11-18T16:30:10.776Z,1763483410.776 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.002926
2025-11-18T16:31:08.278Z,1763483468.278 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-11-18T16:31:08.278Z,1763483468.278 [Default:CheckIn:C.Wait] Stopped
2025-11-18T16:31:08.278Z,1763483468.278 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-11-18T16:31:08.278Z,1763483468.278 [Default:CheckIn:D] Running Loop=1
2025-11-18T16:31:08.686Z,1763483468.686 [Default:CheckIn:D] Stopped
2025-11-18T16:31:08.686Z,1763483468.686 [Default:CheckIn:E] Running Loop=1
2025-11-18T16:31:09.095Z,1763483469.095 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 56.946476 min
2025-11-18T16:31:09.095Z,1763483469.095 [Default:CheckIn:E] Stopped
2025-11-18T16:31:09.095Z,1763483469.095 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-11-18T16:31:09.095Z,1763483469.095 [Default:CheckIn] Stopped
2025-11-18T16:31:09.095Z,1763483469.095 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-11-18T16:31:09.096Z,1763483469.096 [Default:CheckIn](INFO): Running loop #9
2025-11-18T16:31:09.096Z,1763483469.096 [Default:CheckIn] Running Loop=9
2025-11-18T16:31:09.096Z,1763483469.096 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-11-18T16:31:09.096Z,1763483469.096 [Default:CheckIn:Read_GPS] Running Loop=1
2025-11-18T16:31:11.098Z,1763483471.098 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163109.00,A,3648.20147,N,12149.99478,W,17.592,269.63,181125,,,D*46
2025-11-18T16:31:11.100Z,1763483471.100 [NAL9602](INFO): GPS fix at 20251118T163109: (36.803358, -121.833246)
2025-11-18T16:31:11.127Z,1763483471.127 [Default:CheckIn:Read_GPS] Stopped
2025-11-18T16:31:11.127Z,1763483471.127 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-11-18T16:31:19.267Z,1763483479.267 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20251118T153045/Courier0031.lzma
2025-11-18T16:31:20.269Z,1763483480.269 [DataOverHttps](INFO): Moved sent file to Logs/20251118T153045/Courier0031.lzma.bak
2025-11-18T16:31:20.270Z,1763483480.270 [DataOverHttps](INFO): SBD MOMSN=26315267
2025-11-18T16:31:24.434Z,1763483484.434 [NAL9602](INFO): SBD MO Status=0, MOMSN=11536, MT Status=0, MTMSN=0
2025-11-18T16:31:24.434Z,1763483484.434 [NAL9602](INFO): No messages in MT queue
2025-11-18T16:31:55.137Z,1763483515.137 [NAL9602](INFO): Not Powering down - fast GPS
2025-11-18T16:32:31.511Z,1763483551.511 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.869907
2025-11-18T16:32:53.346Z,1763483573.346 [NAL9602](INFO): SBD MO Status=1, MOMSN=11537, MT Status=0, MTMSN=0
2025-11-18T16:32:53.396Z,1763483573.396 [NAL9602](INFO): Sent 167 bytes from file Logs/20251118T153045/Express0032.lzma
2025-11-18T16:32:53.396Z,1763483573.396 [NAL9602](INFO): Packets left to send: 0
2025-11-18T16:33:01.425Z,1763483581.425 [NAL9602](INFO): SBD MO Status=0, MOMSN=11538, MT Status=0, MTMSN=0
2025-11-18T16:33:01.516Z,1763483581.516 [Default:CheckIn:Read_Iridium] Stopped
2025-11-18T16:33:01.516Z,1763483581.516 [Default:CheckIn:C.Wait] Running Loop=1
2025-11-18T16:33:01.516Z,1763483581.516 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-11-18T16:33:02.632Z,1763483582.632 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-11-18T16:33:32.129Z,1763483612.129 [NAL9602](INFO): Not Powering down - fast GPS
2025-11-18T16:33:37.772Z,1763483617.772 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-11-18T16:34:12.928Z,1763483652.928 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-11-18T16:34:48.068Z,1763483688.068 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-11-18T16:35:23.224Z,1763483723.224 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-11-18T16:35:58.400Z,1763483758.400 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-11-18T16:36:33.540Z,1763483793.540 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-11-18T16:36:57.962Z,1763483817.962 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.002975
2025-11-18T16:38:02.018Z,1763483882.018 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-11-18T16:38:02.018Z,1763483882.018 [Default:CheckIn:C.Wait] Stopped
2025-11-18T16:38:02.018Z,1763483882.018 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-11-18T16:38:02.018Z,1763483882.018 [Default:CheckIn:D] Running Loop=1
2025-11-18T16:38:02.426Z,1763483882.426 [Default:CheckIn:D] Stopped
2025-11-18T16:38:02.426Z,1763483882.426 [Default:CheckIn:E] Running Loop=1
2025-11-18T16:38:02.818Z,1763483882.818 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 63.842139 min
2025-11-18T16:38:02.818Z,1763483882.818 [Default:CheckIn:E] Stopped
2025-11-18T16:38:02.818Z,1763483882.818 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-11-18T16:38:02.818Z,1763483882.818 [Default:CheckIn] Stopped
2025-11-18T16:38:02.818Z,1763483882.818 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-11-18T16:38:02.818Z,1763483882.818 [Default:CheckIn](INFO): Running loop #10
2025-11-18T16:38:02.818Z,1763483882.818 [Default:CheckIn] Running Loop=10
2025-11-18T16:38:02.818Z,1763483882.818 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-11-18T16:38:02.819Z,1763483882.819 [Default:CheckIn:Read_GPS] Running Loop=1
2025-11-18T16:38:04.830Z,1763483884.830 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163803.00,A,3648.17371,N,12151.80650,W,0.641,13.33,181125,,,D*4E
2025-11-18T16:38:04.832Z,1763483884.832 [NAL9602](INFO): GPS fix at 20251118T163803: (36.802895, -121.863442)
2025-11-18T16:38:04.842Z,1763483884.842 [Default:CheckIn:Read_GPS] Stopped
2025-11-18T16:38:04.842Z,1763483884.842 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-11-18T16:38:17.919Z,1763483897.919 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20251118T153045/Courier0034.lzma
2025-11-18T16:38:18.922Z,1763483898.922 [DataOverHttps](INFO): Moved sent file to Logs/20251118T153045/Courier0034.lzma.bak
2025-11-18T16:38:18.922Z,1763483898.922 [DataOverHttps](INFO): SBD MOMSN=26315349
2025-11-18T16:38:28.263Z,1763483908.263 [NAL9602](INFO): SBD MO Status=2, MOMSN=11539, MT Status=2, MTMSN=0
2025-11-18T16:38:28.263Z,1763483908.263 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-11-18T16:38:34.695Z,1763483914.695 [DataOverHttps](INFO): Sending 170 bytes from file Logs/20251118T153045/Express0035.lzma
2025-11-18T16:38:35.697Z,1763483915.697 [DataOverHttps](INFO): Moved sent file to Logs/20251118T153045/Express0035.lzma.bak
2025-11-18T16:38:35.698Z,1763483915.698 [DataOverHttps](INFO): SBD MOMSN=26315352
2025-11-18T16:38:36.814Z,1763483916.814 [Default:CheckIn:Read_Iridium] Stopped
2025-11-18T16:38:36.815Z,1763483916.815 [Default:CheckIn:C.Wait] Running Loop=1
2025-11-18T16:38:36.815Z,1763483916.815 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-11-18T16:38:49.673Z,1763483929.673 [NAL9602](INFO): SBD MO Status=0, MOMSN=11539, MT Status=0, MTMSN=0
2025-11-18T16:38:49.673Z,1763483929.673 [NAL9602](INFO): No messages in MT queue
2025-11-18T16:39:20.300Z,1763483960.300 [NAL9602](INFO): Not Powering down - fast GPS
2025-11-18T16:40:30.453Z,1763484030.453 [DataOverHttps](IMPORTANT): SBD MTMSN=20251118T164029
2025-11-18T16:40:37.815Z,1763484037.815 [DataOverHttps](INFO): Received command: restart logs