2024-12-17T18:02:46.850Z,1734458566.850 [Supervisor](DEBUG): Initializing supervisor.
2024-12-17T18:02:46.855Z,1734458566.855 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2024-12-17T18:02:46.855Z,1734458566.855 [SyncHandler](INFO): Protected caller Thread ID is 837
2024-12-17T18:02:46.856Z,1734458566.856 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2024-12-17T18:02:46.857Z,1734458566.857 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2024-12-17T18:02:46.857Z,1734458566.857 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 838
2024-12-17T18:02:46.861Z,1734458566.861 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2024-12-17T18:02:46.878Z,1734458566.878 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2024-12-17T18:02:46.879Z,1734458566.879 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2024-12-17T18:02:46.879Z,1734458566.879 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 839
2024-12-17T18:02:46.883Z,1734458566.883 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2024-12-17T18:02:46.885Z,1734458566.885 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2024-12-17T18:02:46.885Z,1734458566.885 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 840
2024-12-17T18:02:46.887Z,1734458566.887 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2024-12-17T18:02:46.888Z,1734458566.888 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2024-12-17T18:02:46.888Z,1734458566.888 [logger ThreadHandler](INFO): Protected caller Thread ID is 841
2024-12-17T18:02:46.892Z,1734458566.892 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2024-12-17T18:02:46.892Z,1734458566.892 [Supervisor](INFO): Looking for Config files in directory: Config/
2024-12-17T18:02:46.896Z,1734458566.896 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2024-12-17T18:02:47.252Z,1734458567.252 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2024-12-17T18:02:47.253Z,1734458567.253 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2024-12-17T18:02:47.345Z,1734458567.345 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2024-12-17T18:02:47.463Z,1734458567.463 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2024-12-17T18:02:47.464Z,1734458567.464 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2024-12-17T18:02:47.604Z,1734458567.604 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2024-12-17T18:02:47.606Z,1734458567.606 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2024-12-17T18:02:47.963Z,1734458567.963 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2024-12-17T18:02:47.964Z,1734458567.964 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2024-12-17T18:02:48.082Z,1734458568.082 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2024-12-17T18:02:48.083Z,1734458568.083 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2024-12-17T18:02:48.511Z,1734458568.511 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2024-12-17T18:02:48.513Z,1734458568.513 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2024-12-17T18:02:48.736Z,1734458568.736 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2024-12-17T18:02:48.737Z,1734458568.737 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2024-12-17T18:02:48.828Z,1734458568.828 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2024-12-17T18:02:49.074Z,1734458569.074 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2024-12-17T18:02:49.076Z,1734458569.076 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2024-12-17T18:02:49.308Z,1734458569.308 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2024-12-17T18:02:49.309Z,1734458569.309 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2024-12-17T18:02:49.850Z,1734458569.850 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2024-12-17T18:02:49.852Z,1734458569.852 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2024-12-17T18:02:50.050Z,1734458570.050 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2024-12-17T18:02:50.053Z,1734458570.053 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2024-12-17T18:02:50.371Z,1734458570.371 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2024-12-17T18:02:50.373Z,1734458570.373 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2024-12-17T18:02:51.234Z,1734458571.234 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2024-12-17T18:02:51.234Z,1734458571.234 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2024-12-17T18:02:51.816Z,1734458571.816 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2024-12-17T18:02:51.818Z,1734458571.818 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-ahi/
2024-12-17T18:02:51.820Z,1734458571.820 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Control.cfg
2024-12-17T18:02:51.929Z,1734458571.929 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Science.cfg
2024-12-17T18:02:52.056Z,1734458572.056 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/secure.cfg
2024-12-17T18:02:52.150Z,1734458572.150 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Servo.cfg
2024-12-17T18:02:52.267Z,1734458572.267 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/BIT.cfg
2024-12-17T18:02:52.365Z,1734458572.365 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Battery.cfg
2024-12-17T18:02:52.639Z,1734458572.639 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2024-12-17T18:02:52.639Z,1734458572.639 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/vehicle.cfg
2024-12-17T18:02:52.759Z,1734458572.759 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/logger.cfg
2024-12-17T18:02:52.867Z,1734458572.867 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Sensor.cfg
2024-12-17T18:02:53.018Z,1734458573.018 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Simulator.cfg
2024-12-17T18:02:53.116Z,1734458573.116 [Supervisor](IMPORTANT): Reloading configuration overrides from Data/persisted.cfg
2024-12-17T18:02:53.137Z,1734458573.137 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2024-12-17T18:02:53.316Z,1734458573.316 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2024-12-17T18:02:53.318Z,1734458573.318 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2024-12-17T18:02:53.392Z,1734458573.392 [VerticalControl](DEBUG): Construct VerticalControl.
2024-12-17T18:02:53.453Z,1734458573.453 [VerticalControl] Loaded
2024-12-17T18:02:53.454Z,1734458573.454 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2024-12-17T18:02:53.457Z,1734458573.457 [HorizontalControl](DEBUG): Construct HorizontalControl.
2024-12-17T18:02:53.505Z,1734458573.505 [HorizontalControl] Loaded
2024-12-17T18:02:53.505Z,1734458573.505 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2024-12-17T18:02:53.508Z,1734458573.508 [SpeedControl](DEBUG): Construct SpeedControl.
2024-12-17T18:02:53.511Z,1734458573.511 [SpeedControl] Loaded
2024-12-17T18:02:53.511Z,1734458573.511 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2024-12-17T18:02:53.514Z,1734458573.514 [LoopControl](DEBUG): Construct LoopControl.
2024-12-17T18:02:53.514Z,1734458573.514 [LoopControl] Loaded
2024-12-17T18:02:53.514Z,1734458573.514 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2024-12-17T18:02:53.515Z,1734458573.515 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2024-12-17T18:02:53.515Z,1734458573.515 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2024-12-17T18:02:53.605Z,1734458573.605 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2024-12-17T18:02:53.606Z,1734458573.606 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2024-12-17T18:02:54.456Z,1734458574.456 [AHRS_M2] Loaded
2024-12-17T18:02:54.456Z,1734458574.456 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2024-12-17T18:02:54.724Z,1734458574.724 [BackseatComponent] Loaded
2024-12-17T18:02:54.724Z,1734458574.724 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2024-12-17T18:02:54.726Z,1734458574.726 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 408B54E0
2024-12-17T18:02:54.726Z,1734458574.726 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 920
2024-12-17T18:02:54.729Z,1734458574.729 [LcmUniversalReporter] Loaded
2024-12-17T18:02:54.729Z,1734458574.729 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2024-12-17T18:02:55.566Z,1734458575.566 [BPC1] Loaded
2024-12-17T18:02:55.566Z,1734458575.566 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2024-12-17T18:02:55.666Z,1734458575.666 [DAT] Loaded
2024-12-17T18:02:55.666Z,1734458575.666 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread.
2024-12-17T18:02:55.667Z,1734458575.667 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 408E54E0
2024-12-17T18:02:55.667Z,1734458575.667 [DAT ThreadHandler](INFO): Protected caller Thread ID is 921
2024-12-17T18:02:55.823Z,1734458575.823 [DataOverHttps] Loaded
2024-12-17T18:02:55.823Z,1734458575.823 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2024-12-17T18:02:55.824Z,1734458575.824 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 409154E0
2024-12-17T18:02:55.825Z,1734458575.825 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 922
2024-12-17T18:02:55.848Z,1734458575.848 [Depth_Keller] Loaded
2024-12-17T18:02:55.848Z,1734458575.848 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2024-12-17T18:02:55.853Z,1734458575.853 [DropWeight] Loaded
2024-12-17T18:02:55.854Z,1734458575.854 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2024-12-17T18:02:55.919Z,1734458575.919 [NAL9602] Loaded
2024-12-17T18:02:55.919Z,1734458575.919 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2024-12-17T18:02:55.950Z,1734458575.950 [Onboard] Loaded
2024-12-17T18:02:55.950Z,1734458575.950 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2024-12-17T18:02:55.951Z,1734458575.951 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 409454E0
2024-12-17T18:02:55.951Z,1734458575.951 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 923
2024-12-17T18:02:55.966Z,1734458575.966 [Power24vConverter] Loaded
2024-12-17T18:02:55.966Z,1734458575.966 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2024-12-17T18:02:55.982Z,1734458575.982 [Radio_Surface] Loaded
2024-12-17T18:02:55.983Z,1734458575.983 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2024-12-17T18:02:55.984Z,1734458575.984 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409754E0
2024-12-17T18:02:55.984Z,1734458575.984 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 924
2024-12-17T18:02:56.000Z,1734458576.000 [Sonardyne_Nano] Loaded
2024-12-17T18:02:56.000Z,1734458576.000 [ComponentRegistry](DEBUG): SyncComponent "Sonardyne_Nano" handled in the control thread.
2024-12-17T18:02:56.025Z,1734458576.025 [Waterlinked] Loaded
2024-12-17T18:02:56.025Z,1734458576.025 [ComponentRegistry](DEBUG): SyncComponent "Waterlinked" handled in the control thread.
2024-12-17T18:02:56.025Z,1734458576.025 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2024-12-17T18:02:56.026Z,1734458576.026 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2024-12-17T18:02:56.042Z,1734458576.042 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2024-12-17T18:02:56.043Z,1734458576.043 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2024-12-17T18:02:56.086Z,1734458576.086 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2024-12-17T18:02:56.087Z,1734458576.087 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2024-12-17T18:02:56.309Z,1734458576.309 [SBIT](DEBUG): Construct Startup Built In Test.
2024-12-17T18:02:56.319Z,1734458576.319 [SBIT] Loaded
2024-12-17T18:02:56.319Z,1734458576.319 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2024-12-17T18:02:56.322Z,1734458576.322 [IBIT](DEBUG): Construct Initiated Built In Test.
2024-12-17T18:02:56.334Z,1734458576.334 [IBIT] Loaded
2024-12-17T18:02:56.335Z,1734458576.335 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2024-12-17T18:02:56.341Z,1734458576.341 [CBIT](DEBUG): Construct Continuous Built In Test.
2024-12-17T18:02:56.448Z,1734458576.448 [CBIT] Loaded
2024-12-17T18:02:56.448Z,1734458576.448 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2024-12-17T18:02:56.449Z,1734458576.449 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2024-12-17T18:02:56.449Z,1734458576.449 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2024-12-17T18:02:56.884Z,1734458576.884 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2024-12-17T18:02:56.884Z,1734458576.884 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2024-12-17T18:02:56.957Z,1734458576.957 [DepthRateCalculator] Loaded
2024-12-17T18:02:56.957Z,1734458576.957 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2024-12-17T18:02:56.962Z,1734458576.962 [PitchRateCalculator] Loaded
2024-12-17T18:02:56.963Z,1734458576.963 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2024-12-17T18:02:56.974Z,1734458576.974 [SpeedCalculator] Loaded
2024-12-17T18:02:56.974Z,1734458576.974 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2024-12-17T18:02:56.979Z,1734458576.979 [YawRateCalculator] Loaded
2024-12-17T18:02:56.979Z,1734458576.979 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2024-12-17T18:02:56.999Z,1734458576.999 [ElevatorOffsetCalculator] Loaded
2024-12-17T18:02:56.999Z,1734458576.999 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2024-12-17T18:02:56.999Z,1734458576.999 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2024-12-17T18:02:57.000Z,1734458577.000 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2024-12-17T18:02:57.231Z,1734458577.231 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2024-12-17T18:02:57.232Z,1734458577.232 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2024-12-17T18:02:57.375Z,1734458577.375 [DeadReckonUsingMultipleVelocitySources] Loaded
2024-12-17T18:02:57.375Z,1734458577.375 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2024-12-17T18:02:57.389Z,1734458577.389 [NavChart] Loaded
2024-12-17T18:02:57.389Z,1734458577.389 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2024-12-17T18:02:57.395Z,1734458577.395 [UniversalFixResidualReporter] Loaded
2024-12-17T18:02:57.395Z,1734458577.395 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2024-12-17T18:02:57.396Z,1734458577.396 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2024-12-17T18:02:57.397Z,1734458577.397 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2024-12-17T18:02:57.570Z,1734458577.570 [BuoyancyServo] Loaded
2024-12-17T18:02:57.570Z,1734458577.570 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2024-12-17T18:02:57.593Z,1734458577.593 [ElevatorServo] Loaded
2024-12-17T18:02:57.594Z,1734458577.594 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2024-12-17T18:02:57.616Z,1734458577.616 [MassServo] Loaded
2024-12-17T18:02:57.616Z,1734458577.616 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2024-12-17T18:02:57.637Z,1734458577.637 [RudderServo] Loaded
2024-12-17T18:02:57.638Z,1734458577.638 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2024-12-17T18:02:57.655Z,1734458577.655 [ThrusterHE] Loaded
2024-12-17T18:02:57.655Z,1734458577.655 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2024-12-17T18:02:57.656Z,1734458577.656 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2024-12-17T18:02:57.656Z,1734458577.656 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2024-12-17T18:02:57.892Z,1734458577.892 [CTD_Seabird] Loaded
2024-12-17T18:02:57.893Z,1734458577.893 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2024-12-17T18:02:57.894Z,1734458577.894 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40BF04E0
2024-12-17T18:02:57.894Z,1734458577.894 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 926
2024-12-17T18:02:57.931Z,1734458577.931 [ESPComponent] Loaded
2024-12-17T18:02:57.931Z,1734458577.931 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2024-12-17T18:02:57.954Z,1734458577.954 [PAR_Licor] Loaded
2024-12-17T18:02:57.954Z,1734458577.954 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2024-12-17T18:02:58.000Z,1734458578.000 [WetLabsBB2FL] Loaded
2024-12-17T18:02:58.001Z,1734458578.001 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2024-12-17T18:02:58.002Z,1734458578.002 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40C204E0
2024-12-17T18:02:58.002Z,1734458578.002 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 927
2024-12-17T18:02:58.003Z,1734458578.003 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2024-12-17T18:02:58.009Z,1734458578.009 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2024-12-17T18:02:58.012Z,1734458578.012 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2024-12-17T18:02:58.023Z,1734458578.023 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2024-12-17T18:02:58.024Z,1734458578.024 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C504E0
2024-12-17T18:02:58.025Z,1734458578.025 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 928
2024-12-17T18:02:58.029Z,1734458578.029 [Supervisor](INFO): Main Thread ID is 828
2024-12-17T18:02:58.029Z,1734458578.029 [Supervisor](DEBUG): Running supervisor.
2024-12-17T18:02:58.030Z,1734458578.030 [CommandExec ThreadHandler](INFO): Handler Thread ID is 929
2024-12-17T18:02:58.030Z,1734458578.030 [CommandExec](INFO): Initializing the command executive.
2024-12-17T18:02:58.032Z,1734458578.032 [CommandLine ThreadHandler](INFO): Handler Thread ID is 930
2024-12-17T18:02:58.034Z,1734458578.034 [controlThread ThreadHandler](INFO): Handler Thread ID is 931
2024-12-17T18:02:58.034Z,1734458578.034 [controlThread](DEBUG): Initializing ControlThread
2024-12-17T18:02:58.035Z,1734458578.035 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2024-12-17T18:02:58.037Z,1734458578.037 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2024-12-17T18:02:58.038Z,1734458578.038 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2024-12-17T18:02:58.038Z,1734458578.038 [LoopControl](DEBUG): Initialize LoopControlComponent.
2024-12-17T18:02:58.042Z,1734458578.042 [SBIT](INFO): Initialize SBIT Component.
2024-12-17T18:02:58.042Z,1734458578.042 [SBIT](IMPORTANT): git: 2024-12-17_A
2024-12-17T18:02:58.043Z,1734458578.043 [SBIT](INFO): git hash: 35d3830406fd08eef8bec72d532b8ec94802bb61
2024-12-17T18:02:58.043Z,1734458578.043 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2024-12-17T18:02:58.044Z,1734458578.044 [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
2024-12-17T18:02:58.045Z,1734458578.045 [SBIT](INFO): Beginning SBIT in 74.000000 seconds.
2024-12-17T18:02:58.046Z,1734458578.046 [IBIT](INFO): Initialize IBIT Component.
2024-12-17T18:02:58.047Z,1734458578.047 [CBIT](DEBUG): Initialize CBIT Component.
2024-12-17T18:02:58.048Z,1734458578.048 [logger ThreadHandler](INFO): Handler Thread ID is 932
2024-12-17T18:02:58.060Z,1734458578.060 [CBIT](DEBUG): Initialized mux pins.
2024-12-17T18:02:58.060Z,1734458578.060 [CBIT](DEBUG): Initializing the watchdog timer.
2024-12-17T18:02:58.068Z,1734458578.068 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 933
2024-12-17T18:02:58.080Z,1734458578.080 [DAT ThreadHandler](INFO): Handler Thread ID is 934
2024-12-17T18:02:58.081Z,1734458578.081 [DAT](INFO): Powering up
2024-12-17T18:02:58.081Z,1734458578.081 [DAT](DEBUG): Initializing DAT.
2024-12-17T18:02:58.084Z,1734458578.084 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2024-12-17T18:02:58.084Z,1734458578.084 [CBIT](DEBUG): Initializing heartbeat.
2024-12-17T18:02:58.086Z,1734458578.086 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 936
2024-12-17T18:02:58.088Z,1734458578.088 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2024-12-17T18:02:58.097Z,1734458578.097 [Onboard ThreadHandler](INFO): Handler Thread ID is 937
2024-12-17T18:02:58.126Z,1734458578.126 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 938
2024-12-17T18:02:58.144Z,1734458578.144 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 939
2024-12-17T18:02:58.145Z,1734458578.145 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2024-12-17T18:02:58.149Z,1734458578.149 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 941
2024-12-17T18:02:58.152Z,1734458578.152 [WetLabsBB2FL](INFO): Powering up
2024-12-17T18:02:58.154Z,1734458578.154 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 943
2024-12-17T18:02:58.156Z,1734458578.156 [CBIT](DEBUG): Deactivating GF circuits.
2024-12-17T18:02:58.156Z,1734458578.156 [CBIT](DEBUG): Deactivating emergency mode.
2024-12-17T18:02:58.163Z,1734458578.163 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2024-12-17T18:02:58.163Z,1734458578.163 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2024-12-17T18:02:58.163Z,1734458578.163 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2024-12-17T18:02:58.163Z,1734458578.163 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2024-12-17T18:02:58.164Z,1734458578.164 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2024-12-17T18:02:58.164Z,1734458578.164 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2024-12-17T18:02:58.164Z,1734458578.164 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2024-12-17T18:02:58.164Z,1734458578.164 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2024-12-17T18:02:58.196Z,1734458578.196 [CBIT](DEBUG): Backplane powered.
2024-12-17T18:02:58.196Z,1734458578.196 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2024-12-17T18:02:58.197Z,1734458578.197 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2024-12-17T18:02:58.197Z,1734458578.197 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2024-12-17T18:02:58.197Z,1734458578.197 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2024-12-17T18:02:58.198Z,1734458578.198 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2024-12-17T18:02:58.199Z,1734458578.199 [NavChart](DEBUG): Initialize NavChart Navigation.
2024-12-17T18:02:58.199Z,1734458578.199 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2024-12-17T18:02:58.204Z,1734458578.204 [MissionManager](IMPORTANT): Using TethysL tl-to-tx parser
2024-12-17T18:02:58.205Z,1734458578.205 [MissionManager](INFO): Loading Mission from file: Missions/Startup.tl
2024-12-17T18:02:58.205Z,1734458578.205 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Startup.tl
2024-12-17T18:02:58.210Z,1734458578.210 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Startup.tl
2024-12-17T18:02:58.276Z,1734458578.276 [MissionManager](DEBUG): TethyslAPI: Missions/Startup.tl translated into:
2024-12-17T18:02:58.296Z,1734458578.296 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2024-12-17T18:02:58.328Z,1734458578.328 [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
}
}
}
2024-12-17T18:02:58.329Z,1734458578.329 [MissionManager](INFO): Loading Mission from file: Missions/Default.tl
2024-12-17T18:02:58.329Z,1734458578.329 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Default.tl
2024-12-17T18:02:58.344Z,1734458578.344 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Default.tl
2024-12-17T18:02:58.528Z,1734458578.528 [Radio_Surface](INFO): Powering up
2024-12-17T18:02:58.637Z,1734458578.637 [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
2024-12-17T18:02:58.649Z,1734458578.649 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2024-12-17T18:02:58.651Z,1734458578.651 [Default:A.Wait](DEBUG): Construct Wait.
2024-12-17T18:02:58.661Z,1734458578.661 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2024-12-17T18:02:58.699Z,1734458578.699 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2024-12-17T18:02:58.710Z,1734458578.710 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2024-12-17T18:02:58.732Z,1734458578.732 [Default:E.Execute](DEBUG): Construct Execute.
2024-12-17T18:02:58.735Z,1734458578.735 [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"
}
}
2024-12-17T18:02:58.740Z,1734458578.740 [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,LcmUniversalReporter,Reporter,LogSplitter,
2024-12-17T18:02:58.752Z,1734458578.752 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2024-12-17T18:02:58.901Z,1734458578.901 [Depth_Keller](ERROR): Pressure or depth reading out of range: -1.140412 decibar, -1.132002 m
2024-12-17T18:02:58.902Z,1734458578.902 [Power24vConverter](INFO): Powering up.
2024-12-17T18:02:58.903Z,1734458578.903 [Sonardyne_Nano](INFO): Initializing.
2024-12-17T18:02:58.934Z,1734458578.934 [DepthRateCalculator](ERROR): Depth measurement is not active
2024-12-17T18:02:58.985Z,1734458578.985 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2024-12-17T18:02:58.992Z,1734458578.992 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2024-12-17T18:02:58.993Z,1734458578.993 [ElevatorServo](DEBUG): Initializing EZServoServo.
2024-12-17T18:02:59.000Z,1734458579.000 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2024-12-17T18:02:59.001Z,1734458579.001 [MassServo](DEBUG): Initializing EZServoServo.
2024-12-17T18:02:59.008Z,1734458579.008 [MassServo](DEBUG): Initializing MassServo.
2024-12-17T18:02:59.009Z,1734458579.009 [RudderServo](DEBUG): Initializing EZServoServo.
2024-12-17T18:02:59.016Z,1734458579.016 [RudderServo](DEBUG): Initializing RudderServo.
2024-12-17T18:02:59.017Z,1734458579.017 [ThrusterHE](DEBUG): Initializing EZServoServo.
2024-12-17T18:02:59.024Z,1734458579.024 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2024-12-17T18:03:00.260Z,1734458580.260 [WetLabsBB2FL](INFO): Powering down
2024-12-17T18:03:01.174Z,1734458581.174 [Sonardyne_Nano](ERROR): Failed to get valid response or reached max queue size, flushing UART
2024-12-17T18:03:02.413Z,1734458582.413 [Sonardyne_Nano](IMPORTANT): Found beacon with acoustic ID 2311
2024-12-17T18:03:04.697Z,1734458584.697 [ThrusterHE](ERROR): Zero Speed Commanded.
2024-12-17T18:03:05.180Z,1734458585.180 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit.
2024-12-17T18:03:10.933Z,1734458590.933 [DAT](INFO): DAT read:
2024-12-17T18:03:10.934Z,1734458590.934 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series
2024-12-17T18:03:12.697Z,1734458592.697 [DAT](INFO): DAT read: MF Frequency Band
2024-12-17T18:03:12.698Z,1734458592.698 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0
2024-12-17T18:03:12.699Z,1734458592.699 [DAT](INFO): DAT read: Dec 17 2024 18:03:07
2024-12-17T18:03:13.709Z,1734458593.709 [DAT](INFO): DAT read: Features enabled [Bearing]
2024-12-17T18:03:13.710Z,1734458593.710 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP
2024-12-17T18:03:13.710Z,1734458593.710 [DAT](INFO): commRate: 800
2024-12-17T18:03:15.772Z,1734458595.772 [DAT](INFO): entering command mode
2024-12-17T18:03:15.972Z,1734458595.972 [DAT](INFO): DAT read:
2024-12-17T18:03:15.973Z,1734458595.973 [DAT](INFO): DAT read: user:1>
2024-12-17T18:03:15.973Z,1734458595.973 [DAT](INFO): setting verbose to 3
2024-12-17T18:03:16.225Z,1734458596.225 [DAT](INFO): DAT read: user:1>
2024-12-17T18:03:16.226Z,1734458596.226 [DAT](INFO): DAT read: Verbose | 3
2024-12-17T18:03:16.226Z,1734458596.226 [DAT](INFO): set verbose to 3
2024-12-17T18:03:16.226Z,1734458596.226 [DAT](INFO): setting DatVerbose to 27440
2024-12-17T18:03:16.477Z,1734458596.477 [DAT](INFO): DAT read: user:2>
2024-12-17T18:03:16.478Z,1734458596.478 [DAT](INFO): DAT read: DatVerbose | 27440
2024-12-17T18:03:16.478Z,1734458596.478 [DAT](INFO): set DatVerbose to 27440
2024-12-17T18:03:16.478Z,1734458596.478 [DAT](INFO): setting transmit power to 8
2024-12-17T18:03:16.728Z,1734458596.728 [DAT](INFO): DAT read: user:3>
2024-12-17T18:03:16.729Z,1734458596.729 [DAT](INFO): DAT read: TxPower | 8 (Max)
2024-12-17T18:03:16.730Z,1734458596.730 [DAT](INFO): set transmit power to 8
2024-12-17T18:03:16.730Z,1734458596.730 [DAT](INFO): setting local address to 1
2024-12-17T18:03:16.981Z,1734458596.981 [DAT](INFO): DAT read: user:4>
2024-12-17T18:03:16.982Z,1734458596.982 [DAT](INFO): DAT read: LocalAddr | 1
2024-12-17T18:03:16.982Z,1734458596.982 [DAT](INFO): set local address to 1
2024-12-17T18:03:16.984Z,1734458596.984 [DAT](INFO): Setting time to: 18:3:16 And date to:12/17/2024
2024-12-17T18:03:17.233Z,1734458597.233 [DAT](INFO): DAT read: user:5>
2024-12-17T18:03:17.233Z,1734458597.233 [DAT](INFO): DAT read: Tue Dec 17, 2024 18:03:16
2024-12-17T18:03:17.234Z,1734458597.234 [DAT](INFO): Local DAT time set to Tue Dec 17, 2024 18:03:16
2024-12-17T18:03:25.288Z,1734458605.288 [Waterlinked](ERROR): only read 1 of 5 data items. Device response::BI, +4 +0, +0, +0, 0,V
2024-12-17T18:03:26.003Z,1734458606.003 [NAL9602](INFO): Powering up NAL9602
2024-12-17T18:03:31.263Z,1734458611.263 [Waterlinked](ERROR): only read 0 of 1 data item for BIT error. Device response::TS,22032019555224, 0, 0.0,1475.WI, +0, +0, +0,V
2024-12-17T18:03:36.878Z,1734458616.878 [NAL9602](INFO): NAL9602 initialized
2024-12-17T18:03:54.263Z,1734458634.263 [NAL9602](INFO): SBD MO Status=0, MOMSN=19840, MT Status=0, MTMSN=0
2024-12-17T18:03:54.263Z,1734458634.263 [NAL9602](INFO): No messages in MT queue
2024-12-17T18:04:01.145Z,1734458641.145 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180400.00,A,3648.13455,N,12147.21768,W,0.039,0.00,171224,,,A*7C
2024-12-17T18:04:01.149Z,1734458641.149 [NAL9602](INFO): GPS fix at 20241217T180400: (36.802242, -121.786961)
2024-12-17T18:04:08.875Z,1734458648.875 [Waterlinked](ERROR): only read 3 of 5 data items. Device response::BI, +2, +1, +0,A
2024-12-17T18:04:12.566Z,1734458652.566 [SBIT](IMPORTANT): Beginning Startup BIT
2024-12-17T18:04:12.612Z,1734458652.612 [CBIT](IMPORTANT): Beginning ground fault scan
2024-12-17T18:04:18.244Z,1734458658.244 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2024-12-17T18:04:24.638Z,1734458664.638 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.000255
CHAN A1 (24V): 0.000762
CHAN A2 (12V): 0.000563
CHAN A3 (5V): -0.001554
CHAN B0 (3.3V): 0.000037
CHAN B1 (3.15aV): 0.000337
CHAN B2 (3.15bV): -0.000552
CHAN B3 (GND): 0.000002
OPEN: 0.006459
Full Scale: +/- 1 mA
2024-12-17T18:04:26.333Z,1734458666.333 [Waterlinked](ERROR): only read 0 of 1 data item for BIT error. Device response::TS,22032019564715, 0.0, +0.0, 0.0,1475.0I, +0, +0, +0, +0,V
2024-12-17T18:04:28.458Z,1734458668.458 [Waterlinked](ERROR): only read 0 of 1 data item for BIT error. Device response::TS,22032019560, +0.0, 0.0,1475.0, 0
2024-12-17T18:04:29.290Z,1734458669.290 [Waterlinked](ERROR): only read 3 of 5 data items. Device response::BI, +1, -1, 0,A
2024-12-17T18:04:32.561Z,1734458672.561 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2024-12-17T18:04:33.415Z,1734458673.415 [NAL9602](INFO): Not Powering down - fast GPS
2024-12-17T18:04:36.829Z,1734458676.829 [Waterlinked](ERROR): only read 0 of 1 data item for altitude. Device response::BD, +0. +0.00, 0.07, 0.00
2024-12-17T18:04:39.241Z,1734458679.241 [Waterlinked](ERROR): only read 0 of 1 data item for altitude. Device response::BD, , 0, +0.00, 0.07, 0.00
2024-12-17T18:04:45.206Z,1734458685.206 [Waterlinked](ERROR): only read 0 of 1 data item for BIT error. Device response::TS,22032019570612, 0.0, +0.01475.0, 0
2024-12-17T18:04:46.395Z,1734458686.395 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2024-12-17T18:04:49.006Z,1734458689.006 [Waterlinked](ERROR): only read 3 of 5 data items. Device response::BI, 2, +0, +0,A
2024-12-17T18:04:52.554Z,1734458692.554 [Waterlinked](ERROR): only read 3 of 5 data items. Device response::BI, +2, +0, +0,A
2024-12-17T18:04:59.781Z,1734458699.781 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2024-12-17T18:05:06.246Z,1734458706.246 [Waterlinked](ERROR): only read 0 of 1 data item for BIT error. Device response::TS,22032019572712, 0.0, +0.0, 0.0, 0
2024-12-17T18:05:06.283Z,1734458706.283 [SBIT](IMPORTANT): SBIT PASSED
2024-12-17T18:05:06.283Z,1734458706.283 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2024-12-17T18:05:06.304Z,1734458706.304 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=12 count;
2024-12-17T18:05:06.305Z,1734458706.305 [SBIT](IMPORTANT): ESPComponent.loadAtStartup=1 bool;
2024-12-17T18:05:06.305Z,1734458706.305 [SBIT](IMPORTANT): ESPComponent.sampleTimeout=5 minute;
2024-12-17T18:05:06.305Z,1734458706.305 [SBIT](IMPORTANT): ESPComponent.simulateHardware=1 bool;
2024-12-17T18:05:06.305Z,1734458706.305 [SBIT](IMPORTANT): Express linearApproximation TrackAcousticContact.range_to_contact 15.000000 meter;
2024-12-17T18:05:06.305Z,1734458706.305 [SBIT](IMPORTANT): Express linearApproximation _.planktivore_HM_AvgRois 10.000000 count_per_second;
2024-12-17T18:05:06.305Z,1734458706.305 [SBIT](IMPORTANT): Express linearApproximation _.planktivore_LM_AvgRois 0.020000 count_per_second;
2024-12-17T18:05:06.305Z,1734458706.305 [SBIT](IMPORTANT): Express linearApproximation _.planktivore_caseHumidity 10.000000 percent;
2024-12-17T18:05:06.305Z,1734458706.305 [SBIT](IMPORTANT): Express linearApproximation _.planktivore_diatoms 30.000000 count_per_milliliter;
2024-12-17T18:05:06.305Z,1734458706.305 [SBIT](IMPORTANT): Express linearApproximation _.planktivore_dinoflagellates 30.000000 count_per_milliliter;
2024-12-17T18:05:06.306Z,1734458706.306 [SBIT](IMPORTANT): Express linearApproximation _.predict_plankton_data_pct_dinos_sqerr 0.100000 none;
2024-12-17T18:05:06.306Z,1734458706.306 [SBIT](IMPORTANT): Express linearApproximation height_above_sea_floor 10.000000 meter;
2024-12-17T18:05:06.306Z,1734458706.306 [SBIT](IMPORTANT): IBIT.batteryCapacityThreshold=20 ampere_hour;
2024-12-17T18:05:06.306Z,1734458706.306 [SBIT](IMPORTANT): IBIT.batteryVoltageThreshold=12 volt;
2024-12-17T18:05:06.306Z,1734458706.306 [SBIT](IMPORTANT): Normal all _.predict_plankton_data_pct_dinos_sqerr;
2024-12-17T18:05:06.306Z,1734458706.306 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=270.915869 cubic_centimeter;
2024-12-17T18:05:06.306Z,1734458706.306 [SBIT](IMPORTANT): VerticalControl.massDefault=13.541485 millimeter;
2024-12-17T18:05:06.679Z,1734458706.679 [MissionManager](IMPORTANT): Started mission Startup
2024-12-17T18:05:06.679Z,1734458706.679 [Startup] Running Loop=1
2024-12-17T18:05:06.679Z,1734458706.679 [Startup](DEBUG): Aggregate::initialize Startup
2024-12-17T18:05:06.679Z,1734458706.679 [Startup:A.GoToSurface] Running Loop=1
2024-12-17T18:05:06.679Z,1734458706.679 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2024-12-17T18:05:06.704Z,1734458706.704 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2024-12-17T18:05:06.704Z,1734458706.704 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2024-12-17T18:05:06.705Z,1734458706.705 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2024-12-17T18:05:06.705Z,1734458706.705 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2024-12-17T18:05:06.705Z,1734458706.705 [Startup:A.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2024-12-17T18:05:06.706Z,1734458706.706 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2024-12-17T18:05:06.707Z,1734458706.707 [Startup:StartupSatComms] Running Loop=1
2024-12-17T18:05:06.708Z,1734458706.708 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2024-12-17T18:05:06.712Z,1734458706.712 [Startup:StartupSatComms:A] Running Loop=1
2024-12-17T18:05:07.089Z,1734458707.089 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2024-12-17T18:05:08.663Z,1734458708.663 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180507.00,A,3648.13549,N,12147.21772,W,0.039,0.00,171224,,,A*7D
2024-12-17T18:05:08.669Z,1734458708.669 [NAL9602](INFO): GPS fix at 20241217T180507: (36.802258, -121.786962)
2024-12-17T18:05:08.725Z,1734458708.725 [Startup:StartupSatComms:A] Stopped
2024-12-17T18:05:08.725Z,1734458708.725 [Startup:StartupSatComms:B] Running Loop=1
2024-12-17T18:05:09.112Z,1734458709.112 [Waterlinked](ERROR): only read 3 of 5 data items. Device response::BI, +0, +0, +0V
2024-12-17T18:05:09.123Z,1734458709.123 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2024-12-17T18:05:13.111Z,1734458713.111 [Waterlinked](ERROR): only read 0 of 1 data item for BIT error. Device response::TS,22032019573398, 0. 0.0,1475.0, 0
2024-12-17T18:05:13.921Z,1734458713.921 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2024-12-17T18:05:22.906Z,1734458722.906 [NAL9602](INFO): SBD MO Status=1, MOMSN=19841, MT Status=0, MTMSN=0
2024-12-17T18:05:23.109Z,1734458723.109 [NAL9602](INFO): Sent 18 bytes from file Logs/20241217T171439/Courier0022.lzma
2024-12-17T18:05:23.109Z,1734458723.109 [NAL9602](INFO): Packets left to send: 0
2024-12-17T18:05:27.291Z,1734458727.291 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2024-12-17T18:05:36.158Z,1734458736.158 [NAL9602](INFO): SBD MO Status=1, MOMSN=19842, MT Status=0, MTMSN=0
2024-12-17T18:05:36.208Z,1734458736.208 [NAL9602](INFO): Sent 269 bytes from file Logs/20241217T180246/Courier0000.lzma
2024-12-17T18:05:36.208Z,1734458736.208 [NAL9602](INFO): Packets left to send: 0
2024-12-17T18:05:40.738Z,1734458740.738 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2024-12-17T18:05:43.573Z,1734458743.573 [NAL9602](INFO): SBD MO Status=1, MOMSN=19843, MT Status=0, MTMSN=0
2024-12-17T18:05:43.625Z,1734458743.625 [NAL9602](INFO): Sent 18 bytes from file Logs/20241217T171439/Express0023.lzma
2024-12-17T18:05:43.626Z,1734458743.626 [NAL9602](INFO): Packets left to send: 0
2024-12-17T18:05:52.546Z,1734458752.546 [NAL9602](INFO): SBD MO Status=1, MOMSN=19844, MT Status=0, MTMSN=0
2024-12-17T18:05:52.602Z,1734458752.602 [NAL9602](INFO): Sent 332 bytes from file Logs/20241217T180246/Express0001.lzma
2024-12-17T18:05:52.602Z,1734458752.602 [NAL9602](INFO): Packets left to send: 3
2024-12-17T18:05:56.090Z,1734458756.090 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2024-12-17T18:05:59.372Z,1734458759.372 [Waterlinked](INFO): Powering down
2024-12-17T18:06:03.347Z,1734458763.347 [NAL9602](INFO): SBD MO Status=1, MOMSN=19845, MT Status=0, MTMSN=0
2024-12-17T18:06:03.396Z,1734458763.396 [NAL9602](INFO): Sent 332 bytes from file Logs/20241217T180246/Express0001.lzma
2024-12-17T18:06:03.396Z,1734458763.396 [NAL9602](INFO): Packets left to send: 2
2024-12-17T18:06:09.081Z,1734458769.081 [Startup:StartupSatComms:B](INFO): Timed out from 2024-12-17T18:05:08.7Z
2024-12-17T18:06:09.081Z,1734458769.081 [Startup:StartupSatComms:B] Stopped
2024-12-17T18:06:09.081Z,1734458769.081 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2024-12-17T18:06:09.081Z,1734458769.081 [Startup:StartupSatComms] Stopped
2024-12-17T18:06:09.081Z,1734458769.081 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2024-12-17T18:06:09.082Z,1734458769.082 [Startup](INFO): Completed Startup
2024-12-17T18:06:09.082Z,1734458769.082 [MissionManager](INFO): Startup is completed.
2024-12-17T18:06:09.082Z,1734458769.082 [MissionManager](INFO): Uninitializing Mission Startup
2024-12-17T18:06:09.083Z,1734458769.083 [Startup] Stopped
2024-12-17T18:06:09.083Z,1734458769.083 [Startup](DEBUG): Aggregate::uninitialize Startup
2024-12-17T18:06:09.083Z,1734458769.083 [Startup:A.GoToSurface] Stopped
2024-12-17T18:06:09.083Z,1734458769.083 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2024-12-17T18:06:09.542Z,1734458769.542 [MissionManager](IMPORTANT): Started mission Default
2024-12-17T18:06:09.542Z,1734458769.542 [Default] Running Loop=1
2024-12-17T18:06:09.542Z,1734458769.542 [Default](DEBUG): Aggregate::initialize Default
2024-12-17T18:06:09.542Z,1734458769.542 [Default:B.GoToSurface] Running Loop=1
2024-12-17T18:06:09.542Z,1734458769.542 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2024-12-17T18:06:09.543Z,1734458769.543 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2024-12-17T18:06:09.543Z,1734458769.543 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2024-12-17T18:06:09.543Z,1734458769.543 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2024-12-17T18:06:09.543Z,1734458769.543 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2024-12-17T18:06:09.544Z,1734458769.544 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2024-12-17T18:06:09.544Z,1734458769.544 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2024-12-17T18:06:09.545Z,1734458769.545 [Default:A.Wait] Running Loop=1
2024-12-17T18:06:09.545Z,1734458769.545 [Default:A.Wait](DEBUG): Initialize Wait Component.
2024-12-17T18:06:09.867Z,1734458769.867 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2024-12-17T18:06:10.679Z,1734458770.679 [NAL9602](INFO): SBD MO Status=1, MOMSN=19846, MT Status=0, MTMSN=0
2024-12-17T18:06:10.733Z,1734458770.733 [NAL9602](INFO): Sent 332 bytes from file Logs/20241217T180246/Express0001.lzma
2024-12-17T18:06:10.733Z,1734458770.733 [NAL9602](INFO): Packets left to send: 1
2024-12-17T18:06:22.808Z,1734458782.808 [Default:A.Wait](INFO): Done Waiting.
2024-12-17T18:06:22.808Z,1734458782.808 [Default:A.Wait] Stopped
2024-12-17T18:06:22.808Z,1734458782.808 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2024-12-17T18:06:23.217Z,1734458783.217 [Default:CheckIn] Running Loop=1
2024-12-17T18:06:23.217Z,1734458783.217 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-12-17T18:06:23.217Z,1734458783.217 [Default:CheckIn:Read_GPS] Running Loop=1
2024-12-17T18:06:23.621Z,1734458783.621 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2024-12-17T18:06:24.411Z,1734458784.411 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2024-12-17T18:06:25.223Z,1734458785.223 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180624.00,A,3648.13672,N,12147.21779,W,0.058,0.00,171224,,,A*78
2024-12-17T18:06:25.226Z,1734458785.226 [NAL9602](INFO): GPS fix at 20241217T180624: (36.802279, -121.786963)
2024-12-17T18:06:25.238Z,1734458785.238 [Default:CheckIn:Read_GPS] Stopped
2024-12-17T18:06:25.238Z,1734458785.238 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-12-17T18:06:25.681Z,1734458785.681 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2024-12-17T18:06:45.091Z,1734458805.091 [NAL9602](INFO): SBD MO Status=1, MOMSN=19847, MT Status=0, MTMSN=0
2024-12-17T18:06:45.139Z,1734458805.139 [NAL9602](INFO): Sent 72 bytes from file Logs/20241217T180246/Courier0004.lzma
2024-12-17T18:06:45.139Z,1734458805.139 [NAL9602](INFO): Packets left to send: 0
2024-12-17T18:06:52.378Z,1734458812.378 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004422
2024-12-17T18:06:54.632Z,1734458814.632 [NAL9602](INFO): SBD MO Status=1, MOMSN=19848, MT Status=0, MTMSN=0
2024-12-17T18:06:54.684Z,1734458814.684 [NAL9602](INFO): Sent 217 bytes from file Logs/20241217T180246/Express0001.lzma
2024-12-17T18:06:54.684Z,1734458814.684 [NAL9602](INFO): Packets left to send: 0
2024-12-17T18:06:54.716Z,1734458814.716 [Default:CheckIn:Read_Iridium] Stopped
2024-12-17T18:06:54.716Z,1734458814.716 [Default:CheckIn:C.Wait] Running Loop=1
2024-12-17T18:06:54.716Z,1734458814.716 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-12-17T18:07:01.346Z,1734458821.346 [DataOverHttps](IMPORTANT): Could not stat file Logs/20241217T180246/Express0001.lzma
2024-12-17T18:07:01.346Z,1734458821.346 [DataOverHttps](FAULT): Could not open file Logs/20241217T180246/Express0001.lzma
2024-12-17T18:07:09.982Z,1734458829.982 [DataOverHttps](IMPORTANT): Could not stat file Logs/20241217T180246/Express0001.lzma
2024-12-17T18:07:09.982Z,1734458829.982 [DataOverHttps](FAULT): Could not open file Logs/20241217T180246/Express0001.lzma
2024-12-17T18:07:25.365Z,1734458845.365 [NAL9602](INFO): Not Powering down - fast GPS
2024-12-17T18:07:40.554Z,1734458860.554 [DataOverHttps](IMPORTANT): Could not stat file Logs/20241217T180246/Express0001.lzma
2024-12-17T18:07:40.554Z,1734458860.554 [DataOverHttps](FAULT): Could not open file Logs/20241217T180246/Express0001.lzma
2024-12-17T18:08:11.014Z,1734458891.014 [DataOverHttps](IMPORTANT): Could not stat file Logs/20241217T180246/Express0001.lzma
2024-12-17T18:08:11.014Z,1734458891.014 [DataOverHttps](FAULT): Could not open file Logs/20241217T180246/Express0001.lzma
2024-12-17T18:08:41.570Z,1734458921.570 [DataOverHttps](IMPORTANT): Could not stat file Logs/20241217T180246/Express0001.lzma
2024-12-17T18:08:41.570Z,1734458921.570 [DataOverHttps](FAULT): Could not open file Logs/20241217T180246/Express0001.lzma
2024-12-17T18:08:56.328Z,1734458936.328 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2024-12-17T18:09:03.130Z,1734458943.130 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2024-12-17T18:09:12.114Z,1734458952.114 [DataOverHttps](IMPORTANT): Could not stat file Logs/20241217T180246/Express0001.lzma
2024-12-17T18:09:12.114Z,1734458952.114 [DataOverHttps](FAULT): Could not open file Logs/20241217T180246/Express0001.lzma
2024-12-17T18:09:18.482Z,1734458958.482 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2024-12-17T18:09:33.026Z,1734458973.026 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2024-12-17T18:09:42.614Z,1734458982.614 [DataOverHttps](IMPORTANT): Could not stat file Logs/20241217T180246/Express0001.lzma
2024-12-17T18:09:42.614Z,1734458982.614 [DataOverHttps](FAULT): Could not open file Logs/20241217T180246/Express0001.lzma
2024-12-17T18:09:48.394Z,1734458988.394 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2024-12-17T18:10:01.333Z,1734459001.333 [BPC1](ERROR): Battery stick #59 (s/n: 0184) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0.
2024-12-17T18:10:01.333Z,1734459001.333 [BPC1](INFO): Calculating totals. Valid battery stick count: 44. Valid reserve battery stick count: 5.
2024-12-17T18:10:01.336Z,1734459001.336 [BPC1](INFO): Received data from all battery sticks.
2024-12-17T18:10:13.070Z,1734459013.070 [DataOverHttps](IMPORTANT): Could not stat file Logs/20241217T180246/Express0001.lzma
2024-12-17T18:10:13.070Z,1734459013.070 [DataOverHttps](FAULT): Could not open file Logs/20241217T180246/Express0001.lzma
2024-12-17T18:10:43.594Z,1734459043.594 [DataOverHttps](IMPORTANT): Could not stat file Logs/20241217T180246/Express0001.lzma
2024-12-17T18:10:43.594Z,1734459043.594 [DataOverHttps](FAULT): Could not open file Logs/20241217T180246/Express0001.lzma
2024-12-17T18:11:14.010Z,1734459074.010 [DataOverHttps](IMPORTANT): Could not stat file Logs/20241217T180246/Express0001.lzma
2024-12-17T18:11:14.010Z,1734459074.010 [DataOverHttps](FAULT): Could not open file Logs/20241217T180246/Express0001.lzma
2024-12-17T18:11:44.478Z,1734459104.478 [DataOverHttps](IMPORTANT): Could not stat file Logs/20241217T180246/Express0001.lzma
2024-12-17T18:11:44.478Z,1734459104.478 [DataOverHttps](FAULT): Could not open file Logs/20241217T180246/Express0001.lzma
2024-12-17T18:11:55.263Z,1734459115.263 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-12-17T18:11:55.263Z,1734459115.263 [Default:CheckIn:C.Wait] Stopped
2024-12-17T18:11:55.263Z,1734459115.263 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-12-17T18:11:55.263Z,1734459115.263 [Default:CheckIn:D] Running Loop=1
2024-12-17T18:11:55.677Z,1734459115.677 [Default:CheckIn:D] Stopped
2024-12-17T18:11:55.677Z,1734459115.677 [Default:CheckIn:E] Running Loop=1
2024-12-17T18:11:56.093Z,1734459116.093 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 5.768910 min
2024-12-17T18:11:56.093Z,1734459116.093 [Default:CheckIn:E] Stopped
2024-12-17T18:11:56.093Z,1734459116.093 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-12-17T18:11:56.093Z,1734459116.093 [Default:CheckIn] Stopped
2024-12-17T18:11:56.093Z,1734459116.093 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-12-17T18:11:56.093Z,1734459116.093 [Default:CheckIn](INFO): Running loop #2
2024-12-17T18:11:56.093Z,1734459116.093 [Default:CheckIn] Running Loop=2
2024-12-17T18:11:56.094Z,1734459116.094 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-12-17T18:11:56.094Z,1734459116.094 [Default:CheckIn:Read_GPS] Running Loop=1
2024-12-17T18:11:58.083Z,1734459118.083 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181158.00,A,3648.13507,N,12147.21676,W,0.019,0.00,171224,,,A*7F
2024-12-17T18:11:58.085Z,1734459118.085 [NAL9602](INFO): GPS fix at 20241217T181158: (36.802251, -121.786946)
2024-12-17T18:11:58.101Z,1734459118.101 [Default:CheckIn:Read_GPS] Stopped
2024-12-17T18:11:58.101Z,1734459118.101 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-12-17T18:12:05.040Z,1734459125.040 [DataOverHttps](INFO): Sending 118 bytes from file Logs/20241217T180246/Express0005.lzma
2024-12-17T18:12:06.042Z,1734459126.042 [DataOverHttps](INFO): Moved sent file to Logs/20241217T180246/Express0005.lzma.bak
2024-12-17T18:12:06.042Z,1734459126.042 [DataOverHttps](INFO): SBD MOMSN=23806680
2024-12-17T18:12:11.414Z,1734459131.414 [NAL9602](INFO): SBD MO Status=0, MOMSN=19849, MT Status=0, MTMSN=0
2024-12-17T18:12:11.415Z,1734459131.415 [NAL9602](INFO): No messages in MT queue
2024-12-17T18:12:21.835Z,1734459141.835 [DataOverHttps](INFO): Sending 203 bytes from file Logs/20241217T180246/Courier0007.lzma
2024-12-17T18:12:22.838Z,1734459142.838 [DataOverHttps](INFO): Moved sent file to Logs/20241217T180246/Courier0007.lzma.bak
2024-12-17T18:12:22.838Z,1734459142.838 [DataOverHttps](INFO): SBD MOMSN=23806729
2024-12-17T18:12:38.659Z,1734459158.659 [DataOverHttps](INFO): Sending 320 bytes from file Logs/20241217T180246/Express0008.lzma
2024-12-17T18:12:39.658Z,1734459159.658 [DataOverHttps](INFO): Moved sent file to Logs/20241217T180246/Express0008.lzma.bak
2024-12-17T18:12:39.658Z,1734459159.658 [DataOverHttps](INFO): SBD MOMSN=23806736
2024-12-17T18:12:40.924Z,1734459160.924 [Default:CheckIn:Read_Iridium] Stopped
2024-12-17T18:12:40.924Z,1734459160.924 [Default:CheckIn:C.Wait] Running Loop=1
2024-12-17T18:12:40.924Z,1734459160.924 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-12-17T18:12:42.121Z,1734459162.121 [NAL9602](INFO): Not Powering down - fast GPS
2024-12-17T18:17:41.572Z,1734459461.572 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-12-17T18:17:41.572Z,1734459461.572 [Default:CheckIn:C.Wait] Stopped
2024-12-17T18:17:41.572Z,1734459461.572 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-12-17T18:17:41.572Z,1734459461.572 [Default:CheckIn:D] Running Loop=1
2024-12-17T18:17:41.975Z,1734459461.975 [Default:CheckIn:D] Stopped
2024-12-17T18:17:41.975Z,1734459461.975 [Default:CheckIn:E] Running Loop=1
2024-12-17T18:17:42.382Z,1734459462.382 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 11.540553 min
2024-12-17T18:17:42.382Z,1734459462.382 [Default:CheckIn:E] Stopped
2024-12-17T18:17:42.382Z,1734459462.382 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-12-17T18:17:42.382Z,1734459462.382 [Default:CheckIn] Stopped
2024-12-17T18:17:42.382Z,1734459462.382 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-12-17T18:17:42.383Z,1734459462.383 [Default:CheckIn](INFO): Running loop #3
2024-12-17T18:17:42.383Z,1734459462.383 [Default:CheckIn] Running Loop=3
2024-12-17T18:17:42.383Z,1734459462.383 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-12-17T18:17:42.383Z,1734459462.383 [Default:CheckIn:Read_GPS] Running Loop=1
2024-12-17T18:17:44.391Z,1734459464.391 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181744.00,A,3648.13543,N,12147.21698,W,0.019,0.00,171224,,,A*74
2024-12-17T18:17:44.394Z,1734459464.394 [NAL9602](INFO): GPS fix at 20241217T181744: (36.802257, -121.786950)
2024-12-17T18:17:44.421Z,1734459464.421 [Default:CheckIn:Read_GPS] Stopped
2024-12-17T18:17:44.421Z,1734459464.421 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-12-17T18:17:52.119Z,1734459472.119 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20241217T180246/Courier0010.lzma
2024-12-17T18:17:53.122Z,1734459473.122 [DataOverHttps](INFO): Moved sent file to Logs/20241217T180246/Courier0010.lzma.bak
2024-12-17T18:17:53.122Z,1734459473.122 [DataOverHttps](INFO): SBD MOMSN=23807148
2024-12-17T18:18:08.959Z,1734459488.959 [DataOverHttps](INFO): Sending 134 bytes from file Logs/20241217T180246/Express0011.lzma
2024-12-17T18:18:09.963Z,1734459489.963 [DataOverHttps](INFO): Moved sent file to Logs/20241217T180246/Express0011.lzma.bak
2024-12-17T18:18:09.964Z,1734459489.964 [DataOverHttps](INFO): SBD MOMSN=23807151
2024-12-17T18:18:11.063Z,1734459491.063 [Default:CheckIn:Read_Iridium] Stopped
2024-12-17T18:18:11.063Z,1734459491.063 [Default:CheckIn:C.Wait] Running Loop=1
2024-12-17T18:18:11.063Z,1734459491.063 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-12-17T18:18:25.198Z,1734459505.198 [NAL9602](INFO): SBD MO Status=0, MOMSN=19850, MT Status=0, MTMSN=0
2024-12-17T18:18:25.199Z,1734459505.199 [NAL9602](INFO): No messages in MT queue
2024-12-17T18:18:55.913Z,1734459535.913 [NAL9602](INFO): Not Powering down - fast GPS
2024-12-17T18:23:11.762Z,1734459791.762 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-12-17T18:23:11.762Z,1734459791.762 [Default:CheckIn:C.Wait] Stopped
2024-12-17T18:23:11.762Z,1734459791.762 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-12-17T18:23:11.762Z,1734459791.762 [Default:CheckIn:D] Running Loop=1
2024-12-17T18:23:12.161Z,1734459792.161 [Default:CheckIn:D] Stopped
2024-12-17T18:23:12.161Z,1734459792.161 [Default:CheckIn:E] Running Loop=1
2024-12-17T18:23:12.560Z,1734459792.560 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 17.043653 min
2024-12-17T18:23:12.560Z,1734459792.560 [Default:CheckIn:E] Stopped
2024-12-17T18:23:12.560Z,1734459792.560 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-12-17T18:23:12.560Z,1734459792.560 [Default:CheckIn] Stopped
2024-12-17T18:23:12.560Z,1734459792.560 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-12-17T18:23:12.560Z,1734459792.560 [Default:CheckIn](INFO): Running loop #4
2024-12-17T18:23:12.560Z,1734459792.560 [Default:CheckIn] Running Loop=4
2024-12-17T18:23:12.561Z,1734459792.561 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-12-17T18:23:12.561Z,1734459792.561 [Default:CheckIn:Read_GPS] Running Loop=1
2024-12-17T18:23:14.575Z,1734459794.575 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182314.00,A,3648.13647,N,12147.21727,W,0.019,0.00,171224,,,A*74
2024-12-17T18:23:14.577Z,1734459794.577 [NAL9602](INFO): GPS fix at 20241217T182314: (36.802275, -121.786954)
2024-12-17T18:23:14.589Z,1734459794.589 [Default:CheckIn:Read_GPS] Stopped
2024-12-17T18:23:14.589Z,1734459794.589 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-12-17T18:23:22.459Z,1734459802.459 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20241217T180246/Courier0013.lzma
2024-12-17T18:23:23.462Z,1734459803.462 [DataOverHttps](INFO): Moved sent file to Logs/20241217T180246/Courier0013.lzma.bak
2024-12-17T18:23:23.462Z,1734459803.462 [DataOverHttps](INFO): SBD MOMSN=23807238
2024-12-17T18:23:27.499Z,1734459807.499 [NAL9602](INFO): SBD MO Status=0, MOMSN=19851, MT Status=0, MTMSN=0
2024-12-17T18:23:27.499Z,1734459807.499 [NAL9602](INFO): No messages in MT queue
2024-12-17T18:23:39.212Z,1734459819.212 [DataOverHttps](INFO): Sending 133 bytes from file Logs/20241217T180246/Express0014.lzma
2024-12-17T18:23:40.214Z,1734459820.214 [DataOverHttps](INFO): Moved sent file to Logs/20241217T180246/Express0014.lzma.bak
2024-12-17T18:23:40.214Z,1734459820.214 [DataOverHttps](INFO): SBD MOMSN=23807245
2024-12-17T18:23:41.255Z,1734459821.255 [Default:CheckIn:Read_Iridium] Stopped
2024-12-17T18:23:41.255Z,1734459821.255 [Default:CheckIn:C.Wait] Running Loop=1
2024-12-17T18:23:41.255Z,1734459821.255 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-12-17T18:23:58.207Z,1734459838.207 [NAL9602](INFO): Not Powering down - fast GPS
2024-12-17T18:28:41.936Z,1734460121.936 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-12-17T18:28:41.936Z,1734460121.936 [Default:CheckIn:C.Wait] Stopped
2024-12-17T18:28:41.936Z,1734460121.936 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-12-17T18:28:41.937Z,1734460121.937 [Default:CheckIn:D] Running Loop=1
2024-12-17T18:28:42.344Z,1734460122.344 [Default:CheckIn:D] Stopped
2024-12-17T18:28:42.344Z,1734460122.344 [Default:CheckIn:E] Running Loop=1
2024-12-17T18:28:42.744Z,1734460122.744 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 22.546690 min
2024-12-17T18:28:42.745Z,1734460122.745 [Default:CheckIn:E] Stopped
2024-12-17T18:28:42.745Z,1734460122.745 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-12-17T18:28:42.745Z,1734460122.745 [Default:CheckIn] Stopped
2024-12-17T18:28:42.745Z,1734460122.745 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-12-17T18:28:42.745Z,1734460122.745 [Default:CheckIn](INFO): Running loop #5
2024-12-17T18:28:42.745Z,1734460122.745 [Default:CheckIn] Running Loop=5
2024-12-17T18:28:42.745Z,1734460122.745 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-12-17T18:28:42.745Z,1734460122.745 [Default:CheckIn:Read_GPS] Running Loop=1
2024-12-17T18:28:44.754Z,1734460124.754 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182844.00,A,3648.13682,N,12147.21076,W,0.117,32.09,171224,,,A*47
2024-12-17T18:28:44.767Z,1734460124.767 [NAL9602](INFO): GPS fix at 20241217T182844: (36.802280, -121.786846)
2024-12-17T18:28:44.779Z,1734460124.779 [Default:CheckIn:Read_GPS] Stopped
2024-12-17T18:28:44.779Z,1734460124.779 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-12-17T18:28:55.051Z,1734460135.051 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20241217T180246/Courier0016.lzma
2024-12-17T18:28:56.054Z,1734460136.054 [DataOverHttps](INFO): Moved sent file to Logs/20241217T180246/Courier0016.lzma.bak
2024-12-17T18:28:56.054Z,1734460136.054 [DataOverHttps](INFO): SBD MOMSN=23807272
2024-12-17T18:29:02.187Z,1734460142.187 [NAL9602](INFO): SBD MO Status=0, MOMSN=19852, MT Status=0, MTMSN=0
2024-12-17T18:29:02.187Z,1734460142.187 [NAL9602](INFO): No messages in MT queue
2024-12-17T18:29:11.843Z,1734460151.843 [DataOverHttps](INFO): Sending 134 bytes from file Logs/20241217T180246/Express0017.lzma
2024-12-17T18:29:12.846Z,1734460152.846 [DataOverHttps](INFO): Moved sent file to Logs/20241217T180246/Express0017.lzma.bak
2024-12-17T18:29:12.846Z,1734460152.846 [DataOverHttps](INFO): SBD MOMSN=23807277
2024-12-17T18:29:13.916Z,1734460153.916 [Default:CheckIn:Read_Iridium] Stopped
2024-12-17T18:29:13.916Z,1734460153.916 [Default:CheckIn:C.Wait] Running Loop=1
2024-12-17T18:29:13.916Z,1734460153.916 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-12-17T18:29:32.893Z,1734460172.893 [NAL9602](INFO): Not Powering down - fast GPS
2024-12-17T18:34:14.604Z,1734460454.604 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-12-17T18:34:14.604Z,1734460454.604 [Default:CheckIn:C.Wait] Stopped
2024-12-17T18:34:14.604Z,1734460454.604 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-12-17T18:34:14.604Z,1734460454.604 [Default:CheckIn:D] Running Loop=1
2024-12-17T18:34:15.008Z,1734460455.008 [Default:CheckIn:D] Stopped
2024-12-17T18:34:15.008Z,1734460455.008 [Default:CheckIn:E] Running Loop=1
2024-12-17T18:34:15.421Z,1734460455.421 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 28.091089 min
2024-12-17T18:34:15.421Z,1734460455.421 [Default:CheckIn:E] Stopped
2024-12-17T18:34:15.421Z,1734460455.421 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-12-17T18:34:15.421Z,1734460455.421 [Default:CheckIn] Stopped
2024-12-17T18:34:15.421Z,1734460455.421 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-12-17T18:34:15.421Z,1734460455.421 [Default:CheckIn](INFO): Running loop #6
2024-12-17T18:34:15.421Z,1734460455.421 [Default:CheckIn] Running Loop=6
2024-12-17T18:34:15.421Z,1734460455.421 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-12-17T18:34:15.422Z,1734460455.422 [Default:CheckIn:Read_GPS] Running Loop=1
2024-12-17T18:34:17.418Z,1734460457.418 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183417.00,A,3648.15947,N,12147.18196,W,5.501,29.29,171224,,,A*47
2024-12-17T18:34:17.420Z,1734460457.420 [NAL9602](INFO): GPS fix at 20241217T183417: (36.802658, -121.786366)
2024-12-17T18:34:17.431Z,1734460457.431 [Default:CheckIn:Read_GPS] Stopped
2024-12-17T18:34:17.431Z,1734460457.431 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-12-17T18:34:24.819Z,1734460464.819 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20241217T180246/Courier0019.lzma
2024-12-17T18:34:25.822Z,1734460465.822 [DataOverHttps](INFO): Moved sent file to Logs/20241217T180246/Courier0019.lzma.bak
2024-12-17T18:34:25.822Z,1734460465.822 [DataOverHttps](INFO): SBD MOMSN=23807343
2024-12-17T18:34:32.371Z,1734460472.371 [NAL9602](INFO): SBD MO Status=0, MOMSN=19853, MT Status=0, MTMSN=0
2024-12-17T18:34:32.371Z,1734460472.371 [NAL9602](INFO): No messages in MT queue
2024-12-17T18:34:41.603Z,1734460481.603 [DataOverHttps](INFO): Sending 148 bytes from file Logs/20241217T180246/Express0020.lzma
2024-12-17T18:34:42.606Z,1734460482.606 [DataOverHttps](INFO): Moved sent file to Logs/20241217T180246/Express0020.lzma.bak
2024-12-17T18:34:42.606Z,1734460482.606 [DataOverHttps](INFO): SBD MOMSN=23807352
2024-12-17T18:34:43.691Z,1734460483.691 [Default:CheckIn:Read_Iridium] Stopped
2024-12-17T18:34:43.691Z,1734460483.691 [Default:CheckIn:C.Wait] Running Loop=1
2024-12-17T18:34:43.708Z,1734460483.708 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-12-17T18:35:03.097Z,1734460503.097 [NAL9602](INFO): Not Powering down - fast GPS
2024-12-17T18:39:44.375Z,1734460784.375 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-12-17T18:39:44.376Z,1734460784.376 [Default:CheckIn:C.Wait] Stopped
2024-12-17T18:39:44.376Z,1734460784.376 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-12-17T18:39:44.376Z,1734460784.376 [Default:CheckIn:D] Running Loop=1
2024-12-17T18:39:44.777Z,1734460784.777 [Default:CheckIn:D] Stopped
2024-12-17T18:39:44.778Z,1734460784.778 [Default:CheckIn:E] Running Loop=1
2024-12-17T18:39:45.189Z,1734460785.189 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 33.587254 min
2024-12-17T18:39:45.190Z,1734460785.190 [Default:CheckIn:E] Stopped
2024-12-17T18:39:45.190Z,1734460785.190 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-12-17T18:39:45.190Z,1734460785.190 [Default:CheckIn] Stopped
2024-12-17T18:39:45.190Z,1734460785.190 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-12-17T18:39:45.190Z,1734460785.190 [Default:CheckIn](INFO): Running loop #7
2024-12-17T18:39:45.190Z,1734460785.190 [Default:CheckIn] Running Loop=7
2024-12-17T18:39:45.190Z,1734460785.190 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-12-17T18:39:45.190Z,1734460785.190 [Default:CheckIn:Read_GPS] Running Loop=1
2024-12-17T18:39:47.190Z,1734460787.190 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183947.00,A,3648.38131,N,12148.05476,W,26.378,279.35,171224,,,D*47
2024-12-17T18:39:47.192Z,1734460787.192 [NAL9602](INFO): GPS fix at 20241217T183947: (36.806355, -121.800913)
2024-12-17T18:39:47.203Z,1734460787.203 [Default:CheckIn:Read_GPS] Stopped
2024-12-17T18:39:47.203Z,1734460787.203 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-12-17T18:39:54.635Z,1734460794.635 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20241217T180246/Courier0022.lzma
2024-12-17T18:39:55.638Z,1734460795.638 [DataOverHttps](INFO): Moved sent file to Logs/20241217T180246/Courier0022.lzma.bak
2024-12-17T18:39:55.638Z,1734460795.638 [DataOverHttps](INFO): SBD MOMSN=23807410
2024-12-17T18:40:00.118Z,1734460800.118 [NAL9602](INFO): SBD MO Status=0, MOMSN=19854, MT Status=0, MTMSN=0
2024-12-17T18:40:00.119Z,1734460800.119 [NAL9602](INFO): No messages in MT queue
2024-12-17T18:40:11.387Z,1734460811.387 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20241217T180246/Express0023.lzma
2024-12-17T18:40:14.398Z,1734460814.398 [DataOverHttps](INFO): Moved sent file to Logs/20241217T180246/Express0023.lzma.bak
2024-12-17T18:40:14.398Z,1734460814.398 [DataOverHttps](INFO): SBD MOMSN=23807415
2024-12-17T18:40:15.487Z,1734460815.487 [Default:CheckIn:Read_Iridium] Stopped
2024-12-17T18:40:15.504Z,1734460815.504 [Default:CheckIn:C.Wait] Running Loop=1
2024-12-17T18:40:15.504Z,1734460815.504 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-12-17T18:40:30.829Z,1734460830.829 [NAL9602](INFO): Not Powering down - fast GPS
2024-12-17T18:42:58.033Z,1734460978.033 [DataOverHttps](IMPORTANT): SBD MTMSN=20241217T184257
2024-12-17T18:43:05.376Z,1734460985.376 [DataOverHttps](INFO): Received command: restart logs