2024-09-05T20:06:30.489Z,1725566790.489 [Supervisor](DEBUG): Initializing supervisor.
2024-09-05T20:06:30.494Z,1725566790.494 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2024-09-05T20:06:30.494Z,1725566790.494 [SyncHandler](INFO): Protected caller Thread ID is 836
2024-09-05T20:06:30.494Z,1725566790.494 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2024-09-05T20:06:30.495Z,1725566790.495 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2024-09-05T20:06:30.496Z,1725566790.496 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 837
2024-09-05T20:06:30.500Z,1725566790.500 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2024-09-05T20:06:30.517Z,1725566790.517 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2024-09-05T20:06:30.518Z,1725566790.518 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2024-09-05T20:06:30.518Z,1725566790.518 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 838
2024-09-05T20:06:30.523Z,1725566790.523 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2024-09-05T20:06:30.524Z,1725566790.524 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2024-09-05T20:06:30.524Z,1725566790.524 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 839
2024-09-05T20:06:30.526Z,1725566790.526 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2024-09-05T20:06:30.527Z,1725566790.527 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2024-09-05T20:06:30.527Z,1725566790.527 [logger ThreadHandler](INFO): Protected caller Thread ID is 840
2024-09-05T20:06:30.531Z,1725566790.531 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2024-09-05T20:06:30.531Z,1725566790.531 [Supervisor](INFO): Looking for Config files in directory: Config/
2024-09-05T20:06:30.536Z,1725566790.536 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2024-09-05T20:06:30.815Z,1725566790.815 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2024-09-05T20:06:30.817Z,1725566790.817 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2024-09-05T20:06:30.911Z,1725566790.911 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2024-09-05T20:06:31.470Z,1725566791.470 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2024-09-05T20:06:31.472Z,1725566791.472 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2024-09-05T20:06:31.868Z,1725566791.868 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2024-09-05T20:06:31.870Z,1725566791.870 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2024-09-05T20:06:31.977Z,1725566791.977 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2024-09-05T20:06:31.978Z,1725566791.978 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2024-09-05T20:06:32.407Z,1725566792.407 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2024-09-05T20:06:32.409Z,1725566792.409 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2024-09-05T20:06:32.639Z,1725566792.639 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2024-09-05T20:06:32.641Z,1725566792.641 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2024-09-05T20:06:33.204Z,1725566793.204 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2024-09-05T20:06:33.205Z,1725566793.205 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2024-09-05T20:06:33.354Z,1725566793.354 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2024-09-05T20:06:33.356Z,1725566793.356 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2024-09-05T20:06:33.448Z,1725566793.448 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2024-09-05T20:06:34.546Z,1725566794.546 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2024-09-05T20:06:34.546Z,1725566794.546 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2024-09-05T20:06:35.305Z,1725566795.305 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2024-09-05T20:06:35.307Z,1725566795.307 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2024-09-05T20:06:35.517Z,1725566795.517 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2024-09-05T20:06:35.518Z,1725566795.518 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2024-09-05T20:06:35.641Z,1725566795.641 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2024-09-05T20:06:35.642Z,1725566795.642 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2024-09-05T20:06:35.884Z,1725566795.884 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2024-09-05T20:06:35.885Z,1725566795.885 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2024-09-05T20:06:36.152Z,1725566796.152 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2024-09-05T20:06:36.154Z,1725566796.154 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2024-09-05T20:06:36.156Z,1725566796.156 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2024-09-05T20:06:36.260Z,1725566796.260 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2024-09-05T20:06:36.357Z,1725566796.357 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2024-09-05T20:06:36.472Z,1725566796.472 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2024-09-05T20:06:36.567Z,1725566796.567 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2024-09-05T20:06:36.683Z,1725566796.683 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2024-09-05T20:06:36.787Z,1725566796.787 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2024-09-05T20:06:36.917Z,1725566796.917 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2024-09-05T20:06:37.084Z,1725566797.084 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2024-09-05T20:06:37.246Z,1725566797.246 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2024-09-05T20:06:37.370Z,1725566797.370 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg
2024-09-05T20:06:37.648Z,1725566797.648 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2024-09-05T20:06:37.649Z,1725566797.649 [Supervisor](IMPORTANT): Reloading configuration overrides from Data/persisted.cfg
2024-09-05T20:06:37.666Z,1725566797.666 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2024-09-05T20:06:37.738Z,1725566797.738 [VerticalControl](DEBUG): Construct VerticalControl.
2024-09-05T20:06:37.799Z,1725566797.799 [VerticalControl] Loaded
2024-09-05T20:06:37.799Z,1725566797.799 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2024-09-05T20:06:37.802Z,1725566797.802 [HorizontalControl](DEBUG): Construct HorizontalControl.
2024-09-05T20:06:37.849Z,1725566797.849 [HorizontalControl] Loaded
2024-09-05T20:06:37.849Z,1725566797.849 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2024-09-05T20:06:37.851Z,1725566797.851 [SpeedControl](DEBUG): Construct SpeedControl.
2024-09-05T20:06:37.854Z,1725566797.854 [SpeedControl] Loaded
2024-09-05T20:06:37.855Z,1725566797.855 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2024-09-05T20:06:37.857Z,1725566797.857 [LoopControl](DEBUG): Construct LoopControl.
2024-09-05T20:06:37.858Z,1725566797.858 [LoopControl] Loaded
2024-09-05T20:06:37.858Z,1725566797.858 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2024-09-05T20:06:37.859Z,1725566797.859 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2024-09-05T20:06:37.860Z,1725566797.860 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2024-09-05T20:06:37.876Z,1725566797.876 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2024-09-05T20:06:37.878Z,1725566797.878 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2024-09-05T20:06:38.090Z,1725566798.090 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2024-09-05T20:06:38.091Z,1725566798.091 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2024-09-05T20:06:38.277Z,1725566798.277 [BuoyancyServo] Loaded
2024-09-05T20:06:38.277Z,1725566798.277 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2024-09-05T20:06:38.299Z,1725566798.299 [ElevatorServo] Loaded
2024-09-05T20:06:38.299Z,1725566798.299 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2024-09-05T20:06:38.320Z,1725566798.320 [MassServo] Loaded
2024-09-05T20:06:38.321Z,1725566798.321 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2024-09-05T20:06:38.342Z,1725566798.342 [RudderServo] Loaded
2024-09-05T20:06:38.342Z,1725566798.342 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2024-09-05T20:06:38.359Z,1725566798.359 [ThrusterHE] Loaded
2024-09-05T20:06:38.359Z,1725566798.359 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2024-09-05T20:06:38.359Z,1725566798.359 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2024-09-05T20:06:38.360Z,1725566798.360 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2024-09-05T20:06:38.497Z,1725566798.497 [DeadReckonUsingMultipleVelocitySources] Loaded
2024-09-05T20:06:38.497Z,1725566798.497 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2024-09-05T20:06:38.510Z,1725566798.510 [NavChart] Loaded
2024-09-05T20:06:38.511Z,1725566798.511 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2024-09-05T20:06:38.516Z,1725566798.516 [UniversalFixResidualReporter] Loaded
2024-09-05T20:06:38.517Z,1725566798.517 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2024-09-05T20:06:38.517Z,1725566798.517 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2024-09-05T20:06:38.518Z,1725566798.518 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2024-09-05T20:06:38.616Z,1725566798.616 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2024-09-05T20:06:38.617Z,1725566798.617 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2024-09-05T20:06:39.412Z,1725566799.412 [AHRS_M2] Loaded
2024-09-05T20:06:39.412Z,1725566799.412 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2024-09-05T20:06:40.475Z,1725566800.475 [BPC1] Loaded
2024-09-05T20:06:40.475Z,1725566800.475 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2024-09-05T20:06:40.795Z,1725566800.795 [DATMMP] Loaded
2024-09-05T20:06:40.796Z,1725566800.796 [ComponentRegistry](DEBUG): Component "DATMMP" handled in its own thread.
2024-09-05T20:06:40.797Z,1725566800.797 [DATMMP ThreadHandler](DEBUG): Created PCaller Thread at 4094C4E0
2024-09-05T20:06:40.798Z,1725566800.797 [DATMMP ThreadHandler](INFO): Protected caller Thread ID is 922
2024-09-05T20:06:40.938Z,1725566800.938 [DataOverHttps] Loaded
2024-09-05T20:06:40.938Z,1725566800.938 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2024-09-05T20:06:40.939Z,1725566800.939 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4097C4E0
2024-09-05T20:06:40.939Z,1725566800.939 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 923
2024-09-05T20:06:40.962Z,1725566800.962 [Depth_Keller] Loaded
2024-09-05T20:06:40.963Z,1725566800.963 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2024-09-05T20:06:40.968Z,1725566800.968 [DropWeight] Loaded
2024-09-05T20:06:40.968Z,1725566800.968 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2024-09-05T20:06:41.032Z,1725566801.032 [NAL9602] Loaded
2024-09-05T20:06:41.032Z,1725566801.032 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2024-09-05T20:06:41.063Z,1725566801.063 [Onboard] Loaded
2024-09-05T20:06:41.063Z,1725566801.063 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2024-09-05T20:06:41.064Z,1725566801.064 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 409AC4E0
2024-09-05T20:06:41.064Z,1725566801.064 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 924
2024-09-05T20:06:41.079Z,1725566801.079 [Power24vConverter] Loaded
2024-09-05T20:06:41.079Z,1725566801.079 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2024-09-05T20:06:41.094Z,1725566801.094 [Radio_Surface] Loaded
2024-09-05T20:06:41.094Z,1725566801.094 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2024-09-05T20:06:41.095Z,1725566801.095 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409DC4E0
2024-09-05T20:06:41.096Z,1725566801.096 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 925
2024-09-05T20:06:41.097Z,1725566801.097 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2024-09-05T20:06:41.097Z,1725566801.097 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2024-09-05T20:06:41.167Z,1725566801.167 [DepthRateCalculator] Loaded
2024-09-05T20:06:41.168Z,1725566801.168 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2024-09-05T20:06:41.173Z,1725566801.173 [PitchRateCalculator] Loaded
2024-09-05T20:06:41.173Z,1725566801.173 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2024-09-05T20:06:41.182Z,1725566801.182 [SpeedCalculator] Loaded
2024-09-05T20:06:41.182Z,1725566801.182 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2024-09-05T20:06:41.186Z,1725566801.186 [YawRateCalculator] Loaded
2024-09-05T20:06:41.187Z,1725566801.187 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2024-09-05T20:06:41.206Z,1725566801.206 [ElevatorOffsetCalculator] Loaded
2024-09-05T20:06:41.206Z,1725566801.206 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2024-09-05T20:06:41.206Z,1725566801.206 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2024-09-05T20:06:41.207Z,1725566801.207 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2024-09-05T20:06:41.432Z,1725566801.432 [CTD_Seabird] Loaded
2024-09-05T20:06:41.432Z,1725566801.432 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2024-09-05T20:06:41.434Z,1725566801.434 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40A984E0
2024-09-05T20:06:41.434Z,1725566801.434 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 926
2024-09-05T20:06:41.471Z,1725566801.471 [ESPComponent] Loaded
2024-09-05T20:06:41.471Z,1725566801.471 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2024-09-05T20:06:41.491Z,1725566801.491 [PAR_Licor] Loaded
2024-09-05T20:06:41.491Z,1725566801.491 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2024-09-05T20:06:41.536Z,1725566801.536 [WetLabsBB2FL] Loaded
2024-09-05T20:06:41.536Z,1725566801.536 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2024-09-05T20:06:41.537Z,1725566801.537 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40AC84E0
2024-09-05T20:06:41.538Z,1725566801.538 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 927
2024-09-05T20:06:41.538Z,1725566801.538 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2024-09-05T20:06:41.539Z,1725566801.539 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2024-09-05T20:06:41.583Z,1725566801.583 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2024-09-05T20:06:41.584Z,1725566801.584 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2024-09-05T20:06:41.978Z,1725566801.978 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2024-09-05T20:06:41.979Z,1725566801.979 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2024-09-05T20:06:42.150Z,1725566802.150 [SBIT](DEBUG): Construct Startup Built In Test.
2024-09-05T20:06:42.159Z,1725566802.159 [SBIT] Loaded
2024-09-05T20:06:42.159Z,1725566802.159 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2024-09-05T20:06:42.162Z,1725566802.162 [IBIT](DEBUG): Construct Initiated Built In Test.
2024-09-05T20:06:42.175Z,1725566802.175 [IBIT] Loaded
2024-09-05T20:06:42.176Z,1725566802.176 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2024-09-05T20:06:42.182Z,1725566802.182 [CBIT](DEBUG): Construct Continuous Built In Test.
2024-09-05T20:06:42.290Z,1725566802.290 [CBIT] Loaded
2024-09-05T20:06:42.290Z,1725566802.290 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2024-09-05T20:06:42.290Z,1725566802.290 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2024-09-05T20:06:42.291Z,1725566802.291 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2024-09-05T20:06:42.434Z,1725566802.434 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2024-09-05T20:06:42.440Z,1725566802.440 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2024-09-05T20:06:42.443Z,1725566802.443 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2024-09-05T20:06:42.454Z,1725566802.454 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2024-09-05T20:06:42.456Z,1725566802.456 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C224E0
2024-09-05T20:06:42.456Z,1725566802.456 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 928
2024-09-05T20:06:42.460Z,1725566802.460 [Supervisor](INFO): Main Thread ID is 829
2024-09-05T20:06:42.460Z,1725566802.460 [Supervisor](DEBUG): Running supervisor.
2024-09-05T20:06:42.461Z,1725566802.461 [CommandExec ThreadHandler](INFO): Handler Thread ID is 929
2024-09-05T20:06:42.461Z,1725566802.461 [CommandExec](INFO): Initializing the command executive.
2024-09-05T20:06:42.463Z,1725566802.463 [CommandLine ThreadHandler](INFO): Handler Thread ID is 930
2024-09-05T20:06:42.465Z,1725566802.465 [controlThread ThreadHandler](INFO): Handler Thread ID is 931
2024-09-05T20:06:42.466Z,1725566802.466 [controlThread](DEBUG): Initializing ControlThread
2024-09-05T20:06:42.466Z,1725566802.466 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2024-09-05T20:06:42.468Z,1725566802.468 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2024-09-05T20:06:42.469Z,1725566802.469 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2024-09-05T20:06:42.469Z,1725566802.469 [LoopControl](DEBUG): Initialize LoopControlComponent.
2024-09-05T20:06:42.471Z,1725566802.471 [NavChart](DEBUG): Initialize NavChart Navigation.
2024-09-05T20:06:42.471Z,1725566802.471 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2024-09-05T20:06:42.475Z,1725566802.475 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2024-09-05T20:06:42.475Z,1725566802.475 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2024-09-05T20:06:42.475Z,1725566802.475 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2024-09-05T20:06:42.476Z,1725566802.476 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2024-09-05T20:06:42.476Z,1725566802.476 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2024-09-05T20:06:42.481Z,1725566802.481 [SBIT](INFO): Initialize SBIT Component.
2024-09-05T20:06:42.482Z,1725566802.482 [SBIT](IMPORTANT): git: 2024-09-04
2024-09-05T20:06:42.482Z,1725566802.482 [SBIT](INFO): git hash: c3a48f2091374af655f27818376c2e16c84a5fcd
2024-09-05T20:06:42.482Z,1725566802.482 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2024-09-05T20:06:42.483Z,1725566802.483 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #1 PREEMPT Wed Mar 17 08:23:48 PDT 2021
2024-09-05T20:06:42.484Z,1725566802.484 [SBIT](INFO): Beginning SBIT in 70.000000 seconds.
2024-09-05T20:06:42.485Z,1725566802.485 [IBIT](INFO): Initialize IBIT Component.
2024-09-05T20:06:42.486Z,1725566802.486 [CBIT](DEBUG): Initialize CBIT Component.
2024-09-05T20:06:42.487Z,1725566802.487 [logger ThreadHandler](INFO): Handler Thread ID is 932
2024-09-05T20:06:42.497Z,1725566802.497 [CBIT](DEBUG): Initialized mux pins.
2024-09-05T20:06:42.497Z,1725566802.497 [CBIT](DEBUG): Initializing the watchdog timer.
2024-09-05T20:06:42.505Z,1725566802.505 [DATMMP ThreadHandler](INFO): Handler Thread ID is 933
2024-09-05T20:06:42.506Z,1725566802.506 [DATMMP](INFO): Start
2024-09-05T20:06:42.506Z,1725566802.506 [DATMMP](INFO): Powering up
2024-09-05T20:06:42.506Z,1725566802.506 [DATMMP](DEBUG): Initializing DATMMP.
2024-09-05T20:06:42.511Z,1725566802.511 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 935
2024-09-05T20:06:42.512Z,1725566802.512 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2024-09-05T20:06:42.521Z,1725566802.521 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2024-09-05T20:06:42.522Z,1725566802.522 [CBIT](DEBUG): Initializing heartbeat.
2024-09-05T20:06:42.522Z,1725566802.523 [Onboard ThreadHandler](INFO): Handler Thread ID is 936
2024-09-05T20:06:42.545Z,1725566802.545 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 937
2024-09-05T20:06:42.558Z,1725566802.558 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 938
2024-09-05T20:06:42.558Z,1725566802.558 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2024-09-05T20:06:42.562Z,1725566802.562 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 940
2024-09-05T20:06:42.566Z,1725566802.566 [WetLabsBB2FL](INFO): Powering up
2024-09-05T20:06:42.567Z,1725566802.567 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 942
2024-09-05T20:06:42.577Z,1725566802.577 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2024-09-05T20:06:42.577Z,1725566802.577 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2024-09-05T20:06:42.577Z,1725566802.577 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2024-09-05T20:06:42.578Z,1725566802.578 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2024-09-05T20:06:42.578Z,1725566802.578 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2024-09-05T20:06:42.578Z,1725566802.578 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2024-09-05T20:06:42.578Z,1725566802.578 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2024-09-05T20:06:42.578Z,1725566802.578 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2024-09-05T20:06:42.594Z,1725566802.594 [CBIT](DEBUG): Deactivating GF circuits.
2024-09-05T20:06:42.594Z,1725566802.594 [CBIT](DEBUG): Deactivating emergency mode.
2024-09-05T20:06:42.633Z,1725566802.633 [CBIT](DEBUG): Backplane powered.
2024-09-05T20:06:42.634Z,1725566802.634 [MissionManager](IMPORTANT): Using TethysL tl-to-tx parser
2024-09-05T20:06:42.634Z,1725566802.634 [MissionManager](INFO): Loading Mission from file: Missions/Startup.tl
2024-09-05T20:06:42.635Z,1725566802.635 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Startup.tl
2024-09-05T20:06:42.638Z,1725566802.638 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Startup.tl
2024-09-05T20:06:42.697Z,1725566802.697 [MissionManager](DEBUG): TethyslAPI: Missions/Startup.tl translated into:
2024-09-05T20:06:42.722Z,1725566802.722 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2024-09-05T20:06:42.742Z,1725566802.742 [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-09-05T20:06:42.743Z,1725566802.743 [MissionManager](INFO): Loading Mission from file: Missions/Default.tl
2024-09-05T20:06:42.743Z,1725566802.743 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Default.tl
2024-09-05T20:06:42.757Z,1725566802.757 [DATMMP](INFO): Starting
2024-09-05T20:06:42.762Z,1725566802.762 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Default.tl
2024-09-05T20:06:42.949Z,1725566802.949 [Radio_Surface](INFO): Powering up
2024-09-05T20:06:43.009Z,1725566803.009 [DATMMP](INFO): Starting
2024-09-05T20:06:43.039Z,1725566803.039 [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-09-05T20:06:43.067Z,1725566803.067 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2024-09-05T20:06:43.068Z,1725566803.068 [Default:A.Wait](DEBUG): Construct Wait.
2024-09-05T20:06:43.071Z,1725566803.071 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2024-09-05T20:06:43.120Z,1725566803.120 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2024-09-05T20:06:43.135Z,1725566803.135 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2024-09-05T20:06:43.148Z,1725566803.148 [Default:E.Execute](DEBUG): Construct Execute.
2024-09-05T20:06:43.151Z,1725566803.151 [MissionManager](DEBUG):
# Copyright (c) 2024 MBARI
# MBARI Proprietary Information. Confidential. All Rights Reserved
# Unauthorized copying or distribution of this file via any medium is strictly
# prohibited.
#
# WARNING - This file contains information whose export is restricted by the
# Export Administration Act of 1979 (Title 50, U.S.C., App. 2401 et seq.), as
# amended. Violations of these export laws are subject to severe civil and/or
# criminal penalties.
mission 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-09-05T20:06:43.161Z,1725566803.161 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,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,Reporter,LogSplitter,
2024-09-05T20:06:43.175Z,1725566803.175 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2024-09-05T20:06:43.261Z,1725566803.261 [DATMMP](INFO): Starting
2024-09-05T20:06:43.330Z,1725566803.330 [Depth_Keller](ERROR): Pressure or depth reading out of range: 1831.023193 decibar, 0.000000 m
2024-09-05T20:06:43.331Z,1725566803.331 [Power24vConverter](INFO): Powering up.
2024-09-05T20:06:43.339Z,1725566803.339 [DepthRateCalculator](ERROR): Depth measurement is not active
2024-09-05T20:06:43.367Z,1725566803.367 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2024-09-05T20:06:43.373Z,1725566803.373 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2024-09-05T20:06:43.374Z,1725566803.374 [ElevatorServo](DEBUG): Initializing EZServoServo.
2024-09-05T20:06:43.381Z,1725566803.381 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2024-09-05T20:06:43.382Z,1725566803.382 [MassServo](DEBUG): Initializing EZServoServo.
2024-09-05T20:06:43.389Z,1725566803.389 [MassServo](DEBUG): Initializing MassServo.
2024-09-05T20:06:43.390Z,1725566803.390 [RudderServo](DEBUG): Initializing EZServoServo.
2024-09-05T20:06:43.398Z,1725566803.398 [RudderServo](DEBUG): Initializing RudderServo.
2024-09-05T20:06:43.400Z,1725566803.400 [ThrusterHE](DEBUG): Initializing EZServoServo.
2024-09-05T20:06:43.406Z,1725566803.406 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2024-09-05T20:06:43.513Z,1725566803.513 [DATMMP](INFO): Starting
2024-09-05T20:06:43.765Z,1725566803.765 [DATMMP](INFO): Starting
2024-09-05T20:06:44.017Z,1725566804.017 [DATMMP](INFO): Starting
2024-09-05T20:06:44.269Z,1725566804.269 [DATMMP](INFO): Starting
2024-09-05T20:06:44.521Z,1725566804.521 [DATMMP](INFO): Starting
2024-09-05T20:06:44.773Z,1725566804.773 [DATMMP](INFO): Starting
2024-09-05T20:06:45.025Z,1725566805.025 [DATMMP](INFO): Starting
2024-09-05T20:06:45.177Z,1725566805.177 [WetLabsBB2FL](INFO): Powering down
2024-09-05T20:06:45.277Z,1725566805.277 [DATMMP](INFO): Starting
2024-09-05T20:06:45.529Z,1725566805.529 [DATMMP](INFO): Starting
2024-09-05T20:06:45.781Z,1725566805.781 [DATMMP](INFO): Starting
2024-09-05T20:06:46.033Z,1725566806.033 [DATMMP](INFO): Starting
2024-09-05T20:06:46.285Z,1725566806.285 [DATMMP](INFO): Starting
2024-09-05T20:06:46.537Z,1725566806.537 [DATMMP](INFO): Starting
2024-09-05T20:06:46.789Z,1725566806.789 [DATMMP](INFO): Starting
2024-09-05T20:06:47.041Z,1725566807.041 [DATMMP](INFO): Starting
2024-09-05T20:06:47.294Z,1725566807.294 [DATMMP](INFO): Starting
2024-09-05T20:06:47.545Z,1725566807.545 [DATMMP](INFO): Starting
2024-09-05T20:06:47.797Z,1725566807.797 [DATMMP](INFO): Starting
2024-09-05T20:06:48.053Z,1725566808.053 [DATMMP](INFO): Starting
2024-09-05T20:06:48.305Z,1725566808.305 [DATMMP](INFO): Starting
2024-09-05T20:06:48.557Z,1725566808.557 [DATMMP](INFO): Starting
2024-09-05T20:06:48.809Z,1725566808.809 [DATMMP](INFO): Starting
2024-09-05T20:06:49.061Z,1725566809.061 [DATMMP](INFO): Starting
2024-09-05T20:06:49.066Z,1725566809.066 [ThrusterHE](ERROR): Zero Speed Commanded.
2024-09-05T20:06:49.313Z,1725566809.313 [DATMMP](INFO): Starting
2024-09-05T20:06:49.565Z,1725566809.565 [DATMMP](INFO): Starting
2024-09-05T20:06:49.817Z,1725566809.817 [DATMMP](INFO): Starting
2024-09-05T20:06:50.069Z,1725566810.069 [DATMMP](INFO): Starting
2024-09-05T20:06:50.321Z,1725566810.321 [DATMMP](INFO): Starting
2024-09-05T20:06:50.573Z,1725566810.573 [DATMMP](INFO): Starting
2024-09-05T20:06:50.825Z,1725566810.825 [DATMMP](INFO): Starting
2024-09-05T20:06:51.077Z,1725566811.077 [DATMMP](INFO): Starting
2024-09-05T20:06:51.329Z,1725566811.329 [DATMMP](INFO): Starting
2024-09-05T20:06:51.581Z,1725566811.581 [DATMMP](INFO): Starting
2024-09-05T20:06:51.833Z,1725566811.833 [DATMMP](INFO): Starting
2024-09-05T20:06:52.085Z,1725566812.085 [DATMMP](INFO): Starting
2024-09-05T20:06:52.337Z,1725566812.337 [DATMMP](INFO): Starting
2024-09-05T20:06:52.589Z,1725566812.589 [DATMMP](INFO): Starting
2024-09-05T20:06:52.841Z,1725566812.841 [DATMMP](INFO): Starting
2024-09-05T20:06:53.093Z,1725566813.093 [DATMMP](INFO): Starting
2024-09-05T20:06:53.345Z,1725566813.345 [DATMMP](INFO): Starting
2024-09-05T20:06:53.597Z,1725566813.597 [DATMMP](INFO): Starting
2024-09-05T20:06:53.849Z,1725566813.849 [DATMMP](INFO): Starting
2024-09-05T20:06:54.101Z,1725566814.101 [DATMMP](INFO): Starting
2024-09-05T20:06:54.102Z,1725566814.102 [DATMMP](INFO): DAT read:
2024-09-05T20:06:54.103Z,1725566814.103 [DATMMP](INFO): DAT read: Teledyne Benthos DAT-900 Series
2024-09-05T20:06:54.353Z,1725566814.353 [DATMMP](INFO): Starting
2024-09-05T20:06:54.605Z,1725566814.605 [DATMMP](INFO): Starting
2024-09-05T20:06:54.857Z,1725566814.857 [DATMMP](INFO): Starting
2024-09-05T20:06:55.109Z,1725566815.109 [DATMMP](INFO): Starting
2024-09-05T20:06:55.361Z,1725566815.361 [DATMMP](INFO): Starting
2024-09-05T20:06:55.613Z,1725566815.613 [DATMMP](INFO): Starting
2024-09-05T20:06:55.614Z,1725566815.614 [DATMMP](INFO): DAT read: MF Frequency Band
2024-09-05T20:06:55.615Z,1725566815.615 [DATMMP](INFO): DAT read: Directional Acoustic Transponder version 8.15.0
2024-09-05T20:06:55.615Z,1725566815.615 [DATMMP](INFO): DAT read: Aug 5 2000 20:06:51
2024-09-05T20:06:55.865Z,1725566815.865 [DATMMP](INFO): Starting
2024-09-05T20:06:56.117Z,1725566816.117 [DATMMP](INFO): Starting
2024-09-05T20:06:56.369Z,1725566816.369 [DATMMP](INFO): Starting
2024-09-05T20:06:56.621Z,1725566816.621 [DATMMP](INFO): Starting
2024-09-05T20:06:56.873Z,1725566816.873 [DATMMP](INFO): Starting
2024-09-05T20:06:56.874Z,1725566816.874 [DATMMP](INFO): DAT read: Features enabled [Bearing]
2024-09-05T20:06:56.875Z,1725566816.875 [DATMMP](INFO): DAT read: CONNECT 01200 bits/sec 1 of 4, Rate 1/2 CC
2024-09-05T20:06:56.875Z,1725566816.875 [DATMMP](INFO): commRate: 1200
2024-09-05T20:06:57.125Z,1725566817.125 [DATMMP](INFO): Starting
2024-09-05T20:06:57.377Z,1725566817.377 [DATMMP](INFO): Starting
2024-09-05T20:06:57.629Z,1725566817.629 [DATMMP](INFO): Starting
2024-09-05T20:06:57.881Z,1725566817.881 [DATMMP](INFO): Starting
2024-09-05T20:06:58.133Z,1725566818.133 [DATMMP](INFO): Starting
2024-09-05T20:06:58.385Z,1725566818.385 [DATMMP](INFO): Starting
2024-09-05T20:06:58.637Z,1725566818.637 [DATMMP](INFO): Starting
2024-09-05T20:06:58.890Z,1725566818.890 [DATMMP](INFO): Starting
2024-09-05T20:06:58.945Z,1725566818.945 [DATMMP](INFO): entering command mode
2024-09-05T20:06:59.141Z,1725566819.141 [DATMMP](INFO): Starting
2024-09-05T20:06:59.142Z,1725566819.142 [DATMMP](INFO): DAT read:
2024-09-05T20:06:59.142Z,1725566819.142 [DATMMP](INFO): DAT read: user:1>
2024-09-05T20:06:59.142Z,1725566819.142 [DATMMP](DEBUG): read user prompt 1: user:1>
2024-09-05T20:06:59.143Z,1725566819.143 [DATMMP](INFO): entering MMP mode
2024-09-05T20:06:59.393Z,1725566819.393 [DATMMP](INFO): Starting
2024-09-05T20:06:59.394Z,1725566819.394 [DATMMP](INFO): GSXN notify for xid: 0
2024-09-05T20:06:59.396Z,1725566819.396 [DATMMP](INFO): status rx: x1
2024-09-05T20:06:59.396Z,1725566819.396 [DATMMP](INFO): MMP status: 1: started
2024-09-05T20:06:59.396Z,1725566819.396 [DATMMP](INFO): Received message type: status
2024-09-05T20:06:59.396Z,1725566819.396 [DATMMP](INFO): Handled
2024-09-05T20:06:59.645Z,1725566819.645 [DATMMP](INFO): Starting
2024-09-05T20:06:59.647Z,1725566819.647 [DATMMP](INFO): Sent Tx Power Config 8
2024-09-05T20:06:59.647Z,1725566819.647 [DATMMP](INFO): Setting local address: 8
2024-09-05T20:06:59.649Z,1725566819.649 [DATMMP](INFO): Setting time to: 20:6:59 And date to:9/5/2024
2024-09-05T20:06:59.897Z,1725566819.897 [DATMMP](INFO): Starting
2024-09-05T20:06:59.898Z,1725566819.898 [DATMMP](INFO): GSXN notify for xid: 0
2024-09-05T20:06:59.898Z,1725566819.898 [DATMMP](INFO): mdmpower rx: x8 x0 x5 x0
2024-09-05T20:06:59.899Z,1725566819.899 [DATMMP](INFO): Received message type: mdmpower
2024-09-05T20:06:59.899Z,1725566819.899 [DATMMP](INFO): Handled
2024-09-05T20:07:00.149Z,1725566820.149 [DATMMP](INFO): Starting
2024-09-05T20:07:00.149Z,1725566820.149 [DATMMP](INFO): GSXN notify for xid: 10
2024-09-05T20:07:00.150Z,1725566820.150 [DATMMP](INFO): sreg_txpower rx: x8
2024-09-05T20:07:00.150Z,1725566820.150 [DATMMP](INFO): Received message type: sreg_txpower
2024-09-05T20:07:00.150Z,1725566820.150 [DATMMP](INFO): Match for : sreg_txpower
2024-09-05T20:07:00.151Z,1725566820.151 [DATMMP](INFO): ACK
2024-09-05T20:07:00.401Z,1725566820.401 [DATMMP](INFO): Starting
2024-09-05T20:07:00.402Z,1725566820.402 [DATMMP](INFO): GSXN notify for xid: 0
2024-09-05T20:07:00.403Z,1725566820.403 [DATMMP](INFO): mdmlocal rx: x8 x0 x0 x0
2024-09-05T20:07:00.403Z,1725566820.403 [DATMMP](INFO): Received message type: mdmlocal
2024-09-05T20:07:00.403Z,1725566820.403 [DATMMP](INFO): Handled
2024-09-05T20:07:00.653Z,1725566820.653 [DATMMP](INFO): Starting
2024-09-05T20:07:00.654Z,1725566820.654 [DATMMP](INFO): GSXN notify for xid: 11
2024-09-05T20:07:00.654Z,1725566820.654 [DATMMP](INFO): sreg_locaddr rx: x8
2024-09-05T20:07:00.654Z,1725566820.654 [DATMMP](INFO): Received message type: sreg_locaddr
2024-09-05T20:07:00.655Z,1725566820.655 [DATMMP](INFO): Match for : sreg_locaddr
2024-09-05T20:07:00.655Z,1725566820.655 [DATMMP](INFO): ACK
2024-09-05T20:07:00.905Z,1725566820.905 [DATMMP](INFO): Starting
2024-09-05T20:07:00.906Z,1725566820.906 [DATMMP](INFO): GSXN notify for xid: 12
2024-09-05T20:07:00.907Z,1725566820.907 [DATMMP](INFO): timedate rx: x0 x14 x6 x3B x8 x5 x7C x0
2024-09-05T20:07:00.907Z,1725566820.907 [DATMMP](INFO): Received message type: timedate
2024-09-05T20:07:00.907Z,1725566820.907 [DATMMP](INFO): Match for : timedate
2024-09-05T20:07:00.907Z,1725566820.907 [DATMMP](INFO): ACK
2024-09-05T20:07:01.157Z,1725566821.157 [DATMMP](INFO): Starting
2024-09-05T20:07:01.158Z,1725566821.158 [DATMMP](INFO): GSXN notify for xid: 0
2024-09-05T20:07:01.158Z,1725566821.158 [DATMMP](INFO): sys_verb rx: x0 x0 x0 x0
2024-09-05T20:07:01.159Z,1725566821.159 [DATMMP](INFO): Received message type: sys_verb
2024-09-05T20:07:01.159Z,1725566821.159 [DATMMP](INFO): Handled
2024-09-05T20:07:01.409Z,1725566821.409 [DATMMP](INFO): Starting
2024-09-05T20:07:01.410Z,1725566821.410 [DATMMP](INFO): GSXN notify for xid: 13
2024-09-05T20:07:01.410Z,1725566821.410 [DATMMP](INFO): sreg_verbosity rx: x0
2024-09-05T20:07:01.411Z,1725566821.411 [DATMMP](INFO): Received message type: sreg_verbosity
2024-09-05T20:07:01.411Z,1725566821.411 [DATMMP](INFO): Match for : sreg_verbosity
2024-09-05T20:07:01.411Z,1725566821.411 [DATMMP](INFO): ACK
2024-09-05T20:07:01.661Z,1725566821.661 [DATMMP](INFO): Starting
2024-09-05T20:07:01.662Z,1725566821.662 [DATMMP](INFO): GSXN notify for xid: 14
2024-09-05T20:07:01.674Z,1725566821.674 [DATMMP](INFO): version rx: x2 x5
2024-09-05T20:07:01.674Z,1725566821.674 [DATMMP](INFO): DatMMPVersion: 2.5
2024-09-05T20:07:01.675Z,1725566821.675 [DATMMP](INFO): Received message type: version
2024-09-05T20:07:01.675Z,1725566821.675 [DATMMP](INFO): Match for : version
2024-09-05T20:07:01.675Z,1725566821.675 [DATMMP](INFO): ACK
2024-09-05T20:07:01.675Z,1725566821.675 [DATMMP](INFO): in MMP mode: config complete going to runnable
2024-09-05T20:07:11.051Z,1725566831.051 [NAL9602](INFO): Powering up NAL9602
2024-09-05T20:07:16.050Z,1725566836.050 [DATMMP](INFO): GSXN notify for xid: 0
2024-09-05T20:07:16.051Z,1725566836.051 [DATMMP](INFO): timesync rx: x0 x1 x1 x0
2024-09-05T20:07:16.051Z,1725566836.051 [DATMMP](INFO): Received message type: timesync
2024-09-05T20:07:16.051Z,1725566836.051 [DATMMP](INFO): Handled
2024-09-05T20:07:21.959Z,1725566841.959 [NAL9602](INFO): NAL9602 initialized
2024-09-05T20:07:25.894Z,1725566845.894 [DATMMP](INFO): GSXN notify for xid: 0
2024-09-05T20:07:25.894Z,1725566845.894 [DATMMP](INFO): timesync rx: x1 x0 x1 x0
2024-09-05T20:07:25.895Z,1725566845.895 [DATMMP](INFO): Received message type: timesync
2024-09-05T20:07:25.895Z,1725566845.895 [DATMMP](INFO): Handled
2024-09-05T20:07:34.892Z,1725566854.892 [NAL9602](INFO): SBD MO Status=0, MOMSN=56394, MT Status=0, MTMSN=0
2024-09-05T20:07:34.892Z,1725566854.892 [NAL9602](INFO): No messages in MT queue
2024-09-05T20:07:48.618Z,1725566868.618 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-05T20:07:53.083Z,1725566873.083 [SBIT](IMPORTANT): Beginning Startup BIT
2024-09-05T20:07:53.087Z,1725566873.087 [CBIT](IMPORTANT): Beginning ground fault scan
2024-09-05T20:07:55.890Z,1725566875.890 [DATMMP](INFO): GSXN notify for xid: 0
2024-09-05T20:07:55.891Z,1725566875.891 [DATMMP](INFO): timesync rx: x0 x0 x0 x0
2024-09-05T20:07:55.891Z,1725566875.891 [DATMMP](INFO): Received message type: timesync
2024-09-05T20:07:55.891Z,1725566875.891 [DATMMP](INFO): Handled
2024-09-05T20:08:00.336Z,1725566880.336 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-05T20:08:03.172Z,1725566883.172 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200802.00,A,3648.13759,N,12147.22266,W,0.156,309.81,050924,,,A*7C
2024-09-05T20:08:03.176Z,1725566883.176 [NAL9602](INFO): GPS fix at 20240905T200802: (36.802293, -121.787044)
2024-09-05T20:08:04.021Z,1725566884.021 [CBIT](ERROR): Ground fault scan returned out of bounds value. Re-running scan.
2024-09-05T20:08:04.422Z,1725566884.422 [CBIT](IMPORTANT): Beginning ground fault scan
2024-09-05T20:08:15.363Z,1725566895.363 [CBIT](ERROR): Ground fault scan returned out of bounds value. Re-running scan.
2024-09-05T20:08:15.750Z,1725566895.750 [CBIT](IMPORTANT): Beginning ground fault scan
2024-09-05T20:08:16.810Z,1725566896.810 [DATMMP](INFO): GSXN notify for xid: 0
2024-09-05T20:08:16.810Z,1725566896.810 [DATMMP](INFO): timesync rx: x0 x1 x1 x0
2024-09-05T20:08:16.811Z,1725566896.811 [DATMMP](INFO): Received message type: timesync
2024-09-05T20:08:16.811Z,1725566896.811 [DATMMP](INFO): Handled
2024-09-05T20:08:26.636Z,1725566906.636 [CBIT](ERROR): Ground fault scan returned out of bounds value. Re-running scan.
2024-09-05T20:08:26.636Z,1725566906.636 [CBIT](IMPORTANT): Ground fault scan returned out of bounds value in succession 3 times. Will re-run scan on normal schedule.
2024-09-05T20:08:26.890Z,1725566906.890 [DATMMP](INFO): GSXN notify for xid: 0
2024-09-05T20:08:26.891Z,1725566906.891 [DATMMP](INFO): timesync rx: x1 x0 x1 x0
2024-09-05T20:08:26.891Z,1725566906.891 [DATMMP](INFO): Received message type: timesync
2024-09-05T20:08:26.891Z,1725566906.891 [DATMMP](INFO): Handled
2024-09-05T20:08:35.510Z,1725566915.510 [NAL9602](INFO): Not Powering down - fast GPS
2024-09-05T20:08:47.232Z,1725566927.232 [SBIT](IMPORTANT): SBIT PASSED
2024-09-05T20:08:47.232Z,1725566927.232 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2024-09-05T20:08:47.233Z,1725566927.233 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=20 count;
2024-09-05T20:08:47.233Z,1725566927.233 [SBIT](IMPORTANT): CANONSampler.loadAtStartup=0 bool;
2024-09-05T20:08:47.233Z,1725566927.233 [SBIT](IMPORTANT): CANONSampler.simulateHardware=0 bool;
2024-09-05T20:08:47.234Z,1725566927.234 [SBIT](IMPORTANT): DAT.loadAtStartup=0 bool;
2024-09-05T20:08:47.234Z,1725566927.234 [SBIT](IMPORTANT): DATMMP.loadAtStartup=1 bool;
2024-09-05T20:08:47.234Z,1725566927.234 [SBIT](IMPORTANT): DATMMP.simulateHardware=0 bool;
2024-09-05T20:08:47.234Z,1725566927.234 [SBIT](IMPORTANT): DATMMP.surfaceThreshold=2 meter;
2024-09-05T20:08:47.234Z,1725566927.234 [SBIT](IMPORTANT): ESPComponent.loadAtStartup=1 bool;
2024-09-05T20:08:47.234Z,1725566927.234 [SBIT](IMPORTANT): Express none _.predict_plankton_data_pct_dinos_sqerr;
2024-09-05T20:08:47.234Z,1725566927.234 [SBIT](IMPORTANT): Normal all WetLabsBB2FL.bin_median_mass_concentration_of_chlorophyll_in_sea_water;
2024-09-05T20:08:47.234Z,1725566927.234 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=243.573504 cubic_centimeter;
2024-09-05T20:08:47.234Z,1725566927.234 [SBIT](IMPORTANT): VerticalControl.massDefault=1.25 centimeter;
2024-09-05T20:08:47.637Z,1725566927.637 [MissionManager](IMPORTANT): Started mission Startup
2024-09-05T20:08:47.637Z,1725566927.637 [Startup] Running Loop=1
2024-09-05T20:08:47.637Z,1725566927.637 [Startup](DEBUG): Aggregate::initialize Startup
2024-09-05T20:08:47.637Z,1725566927.637 [Startup:A.GoToSurface] Running Loop=1
2024-09-05T20:08:47.637Z,1725566927.637 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2024-09-05T20:08:47.638Z,1725566927.638 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2024-09-05T20:08:47.638Z,1725566927.638 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2024-09-05T20:08:47.639Z,1725566927.639 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2024-09-05T20:08:47.639Z,1725566927.639 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2024-09-05T20:08:47.639Z,1725566927.639 [Startup:A.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2024-09-05T20:08:47.640Z,1725566927.640 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2024-09-05T20:08:47.641Z,1725566927.641 [Startup:StartupSatComms] Running Loop=1
2024-09-05T20:08:47.642Z,1725566927.642 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2024-09-05T20:08:47.642Z,1725566927.642 [Startup:StartupSatComms:A] Running Loop=1
2024-09-05T20:08:48.088Z,1725566928.088 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2024-09-05T20:08:49.631Z,1725566929.631 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200848.00,A,3648.14296,N,12147.22587,W,0.408,177.59,050924,,,A*7B
2024-09-05T20:08:49.633Z,1725566929.633 [NAL9602](INFO): GPS fix at 20240905T200848: (36.802383, -121.787098)
2024-09-05T20:08:49.643Z,1725566929.643 [Startup:StartupSatComms:A] Stopped
2024-09-05T20:08:49.643Z,1725566929.643 [Startup:StartupSatComms:B] Running Loop=1
2024-09-05T20:08:50.066Z,1725566930.066 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2024-09-05T20:09:05.724Z,1725566945.724 [NAL9602](INFO): SBD MO Status=1, MOMSN=56395, MT Status=0, MTMSN=0
2024-09-05T20:09:05.982Z,1725566945.982 [NAL9602](INFO): Sent 18 bytes from file Logs/20240905T194201/Courier0016.lzma
2024-09-05T20:09:05.982Z,1725566945.982 [NAL9602](INFO): Packets left to send: 0
2024-09-05T20:09:18.339Z,1725566958.339 [NAL9602](INFO): SBD MO Status=1, MOMSN=56396, MT Status=0, MTMSN=0
2024-09-05T20:09:18.389Z,1725566958.389 [NAL9602](INFO): Sent 266 bytes from file Logs/20240905T200630/Courier0000.lzma
2024-09-05T20:09:18.389Z,1725566958.389 [NAL9602](INFO): Packets left to send: 0
2024-09-05T20:09:26.865Z,1725566966.865 [NAL9602](INFO): SBD MO Status=1, MOMSN=56397, MT Status=0, MTMSN=0
2024-09-05T20:09:26.915Z,1725566966.915 [NAL9602](INFO): Sent 18 bytes from file Logs/20240905T194201/Express0017.lzma
2024-09-05T20:09:26.915Z,1725566966.915 [NAL9602](INFO): Packets left to send: 0
2024-09-05T20:09:37.769Z,1725566977.769 [NAL9602](INFO): SBD MO Status=1, MOMSN=56398, MT Status=0, MTMSN=0
2024-09-05T20:09:37.817Z,1725566977.817 [NAL9602](INFO): Sent 332 bytes from file Logs/20240905T200630/Express0001.lzma
2024-09-05T20:09:37.817Z,1725566977.817 [NAL9602](INFO): Packets left to send: 2
2024-09-05T20:09:46.172Z,1725566986.172 [NAL9602](INFO): SBD MO Status=1, MOMSN=56399, MT Status=0, MTMSN=0
2024-09-05T20:09:46.225Z,1725566986.225 [NAL9602](INFO): Sent 332 bytes from file Logs/20240905T200630/Express0001.lzma
2024-09-05T20:09:46.225Z,1725566986.225 [NAL9602](INFO): Packets left to send: 1
2024-09-05T20:09:49.686Z,1725566989.686 [Startup:StartupSatComms:B](INFO): Timed out from 2024-09-05T20:08:49.6Z
2024-09-05T20:09:49.686Z,1725566989.686 [Startup:StartupSatComms:B] Stopped
2024-09-05T20:09:49.687Z,1725566989.687 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2024-09-05T20:09:49.687Z,1725566989.687 [Startup:StartupSatComms] Stopped
2024-09-05T20:09:49.687Z,1725566989.687 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2024-09-05T20:09:49.688Z,1725566989.688 [Startup](INFO): Completed Startup
2024-09-05T20:09:49.688Z,1725566989.688 [MissionManager](INFO): Startup is completed.
2024-09-05T20:09:49.688Z,1725566989.688 [MissionManager](INFO): Uninitializing Mission Startup
2024-09-05T20:09:49.688Z,1725566989.688 [Startup] Stopped
2024-09-05T20:09:49.688Z,1725566989.688 [Startup](DEBUG): Aggregate::uninitialize Startup
2024-09-05T20:09:49.688Z,1725566989.688 [Startup:A.GoToSurface] Stopped
2024-09-05T20:09:49.688Z,1725566989.688 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2024-09-05T20:09:50.102Z,1725566990.102 [MissionManager](IMPORTANT): Started mission Default
2024-09-05T20:09:50.102Z,1725566990.102 [Default] Running Loop=1
2024-09-05T20:09:50.103Z,1725566990.103 [Default](DEBUG): Aggregate::initialize Default
2024-09-05T20:09:50.103Z,1725566990.103 [Default:B.GoToSurface] Running Loop=1
2024-09-05T20:09:50.103Z,1725566990.103 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2024-09-05T20:09:50.103Z,1725566990.103 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2024-09-05T20:09:50.103Z,1725566990.103 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2024-09-05T20:09:50.104Z,1725566990.104 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2024-09-05T20:09:50.104Z,1725566990.104 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2024-09-05T20:09:50.104Z,1725566990.104 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2024-09-05T20:09:50.104Z,1725566990.104 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2024-09-05T20:09:50.109Z,1725566990.109 [Default:A.Wait] Running Loop=1
2024-09-05T20:09:50.109Z,1725566990.109 [Default:A.Wait](DEBUG): Initialize Wait Component.
2024-09-05T20:09:54.583Z,1725566994.583 [NAL9602](INFO): SBD MO Status=1, MOMSN=56400, MT Status=0, MTMSN=0
2024-09-05T20:09:54.637Z,1725566994.637 [NAL9602](INFO): Sent 277 bytes from file Logs/20240905T200630/Express0001.lzma
2024-09-05T20:09:54.637Z,1725566994.637 [NAL9602](INFO): Packets left to send: 0
2024-09-05T20:10:03.417Z,1725567003.417 [Default:A.Wait](INFO): Done Waiting.
2024-09-05T20:10:03.417Z,1725567003.417 [Default:A.Wait] Stopped
2024-09-05T20:10:03.417Z,1725567003.417 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2024-09-05T20:10:03.822Z,1725567003.822 [Default:CheckIn] Running Loop=1
2024-09-05T20:10:03.822Z,1725567003.822 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-09-05T20:10:03.822Z,1725567003.822 [Default:CheckIn:Read_GPS] Running Loop=1
2024-09-05T20:10:04.227Z,1725567004.227 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2024-09-05T20:10:05.830Z,1725567005.830 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,201005.00,A,3648.14070,N,12147.22529,W,0.117,177.59,050924,,,A*7E
2024-09-05T20:10:05.832Z,1725567005.832 [NAL9602](INFO): GPS fix at 20240905T201005: (36.802345, -121.787088)
2024-09-05T20:10:05.842Z,1725567005.842 [Default:CheckIn:Read_GPS] Stopped
2024-09-05T20:10:05.842Z,1725567005.842 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-09-05T20:10:06.256Z,1725567006.256 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2024-09-05T20:10:16.707Z,1725567016.707 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004312
2024-09-05T20:10:27.481Z,1725567027.481 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20240905T200630/Courier0004.lzma
2024-09-05T20:10:28.483Z,1725567028.483 [DataOverHttps](INFO): Moved sent file to Logs/20240905T200630/Courier0004.lzma.bak
2024-09-05T20:10:28.483Z,1725567028.483 [DataOverHttps](INFO): SBD MOMSN=23131892
2024-09-05T20:10:36.249Z,1725567036.249 [NAL9602](INFO): SBD MO Status=1, MOMSN=56401, MT Status=0, MTMSN=0
2024-09-05T20:10:36.299Z,1725567036.299 [NAL9602](INFO): Sent 73 bytes from file Logs/20240905T200630/Courier0004.lzma
2024-09-05T20:10:36.300Z,1725567036.300 [NAL9602](INFO): Packets left to send: 0
2024-09-05T20:10:36.329Z,1725567036.329 [Default:CheckIn:Read_Iridium] Stopped
2024-09-05T20:10:36.329Z,1725567036.329 [Default:CheckIn:C.Wait] Running Loop=1
2024-09-05T20:10:36.329Z,1725567036.329 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-09-05T20:10:37.836Z,1725567037.836 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-05T20:10:44.832Z,1725567044.832 [DataOverHttps](INFO): Sending 104 bytes from file Logs/20240905T200630/Express0005.lzma
2024-09-05T20:10:45.835Z,1725567045.835 [DataOverHttps](INFO): Moved sent file to Logs/20240905T200630/Express0005.lzma.bak
2024-09-05T20:10:45.835Z,1725567045.835 [DataOverHttps](INFO): SBD MOMSN=23131895
2024-09-05T20:10:51.193Z,1725567051.193 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-05T20:11:04.927Z,1725567064.927 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-05T20:11:06.950Z,1725567066.950 [NAL9602](INFO): Not Powering down - fast GPS
2024-09-05T20:11:18.663Z,1725567078.663 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-05T20:11:32.400Z,1725567092.400 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-05T20:11:46.539Z,1725567106.539 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-05T20:11:59.876Z,1725567119.876 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-05T20:12:13.203Z,1725567133.203 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-05T20:12:26.939Z,1725567146.939 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-05T20:12:40.272Z,1725567160.272 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-05T20:12:49.976Z,1725567169.976 [BPC1](INFO): Calculating totals. Valid battery stick count: 42. Valid reserve battery stick count: 5.
2024-09-05T20:12:49.988Z,1725567169.988 [BPC1](INFO): Received data from all battery sticks.
2024-09-05T20:15:36.934Z,1725567336.934 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-09-05T20:15:36.934Z,1725567336.934 [Default:CheckIn:C.Wait] Stopped
2024-09-05T20:15:36.934Z,1725567336.934 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-09-05T20:15:36.934Z,1725567336.934 [Default:CheckIn:D] Running Loop=1
2024-09-05T20:15:37.318Z,1725567337.318 [Default:CheckIn:D] Stopped
2024-09-05T20:15:37.318Z,1725567337.318 [Default:CheckIn:E] Running Loop=1
2024-09-05T20:15:37.728Z,1725567337.728 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 5.786931 min
2024-09-05T20:15:37.728Z,1725567337.728 [Default:CheckIn:E] Stopped
2024-09-05T20:15:37.728Z,1725567337.728 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-09-05T20:15:37.728Z,1725567337.728 [Default:CheckIn] Stopped
2024-09-05T20:15:37.728Z,1725567337.728 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-09-05T20:15:37.729Z,1725567337.729 [Default:CheckIn](INFO): Running loop #2
2024-09-05T20:15:37.729Z,1725567337.729 [Default:CheckIn] Running Loop=2
2024-09-05T20:15:37.729Z,1725567337.729 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-09-05T20:15:37.729Z,1725567337.729 [Default:CheckIn:Read_GPS] Running Loop=1
2024-09-05T20:15:39.735Z,1725567339.735 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,201540.00,A,3648.13903,N,12147.22687,W,0.039,177.59,050924,,,D*7F
2024-09-05T20:15:39.737Z,1725567339.737 [NAL9602](INFO): GPS fix at 20240905T201540: (36.802317, -121.787115)
2024-09-05T20:15:39.767Z,1725567339.767 [Default:CheckIn:Read_GPS] Stopped
2024-09-05T20:15:39.767Z,1725567339.767 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-09-05T20:15:47.202Z,1725567347.202 [DataOverHttps](INFO): Sending 201 bytes from file Logs/20240905T200630/Courier0007.lzma
2024-09-05T20:15:48.187Z,1725567348.187 [DataOverHttps](INFO): Moved sent file to Logs/20240905T200630/Courier0007.lzma.bak
2024-09-05T20:15:48.187Z,1725567348.187 [DataOverHttps](INFO): SBD MOMSN=23131924
2024-09-05T20:15:53.876Z,1725567353.876 [NAL9602](INFO): SBD MO Status=0, MOMSN=56402, MT Status=0, MTMSN=0
2024-09-05T20:15:53.876Z,1725567353.876 [NAL9602](INFO): No messages in MT queue
2024-09-05T20:16:04.601Z,1725567364.601 [DataOverHttps](INFO): Sending 160 bytes from file Logs/20240905T200630/Express0008.lzma
2024-09-05T20:16:05.604Z,1725567365.604 [DataOverHttps](INFO): Moved sent file to Logs/20240905T200630/Express0008.lzma.bak
2024-09-05T20:16:05.606Z,1725567365.606 [DataOverHttps](INFO): SBD MOMSN=23131928
2024-09-05T20:16:07.232Z,1725567367.232 [Default:CheckIn:Read_Iridium] Stopped
2024-09-05T20:16:07.232Z,1725567367.232 [Default:CheckIn:C.Wait] Running Loop=1
2024-09-05T20:16:07.232Z,1725567367.232 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-09-05T20:16:24.578Z,1725567384.578 [NAL9602](INFO): Not Powering down - fast GPS
2024-09-05T20:21:07.851Z,1725567667.851 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-09-05T20:21:07.852Z,1725567667.852 [Default:CheckIn:C.Wait] Stopped
2024-09-05T20:21:07.852Z,1725567667.852 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-09-05T20:21:07.852Z,1725567667.852 [Default:CheckIn:D] Running Loop=1
2024-09-05T20:21:08.248Z,1725567668.248 [Default:CheckIn:D] Stopped
2024-09-05T20:21:08.248Z,1725567668.248 [Default:CheckIn:E] Running Loop=1
2024-09-05T20:21:08.647Z,1725567668.647 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 11.302417 min
2024-09-05T20:21:08.647Z,1725567668.647 [Default:CheckIn:E] Stopped
2024-09-05T20:21:08.648Z,1725567668.648 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-09-05T20:21:08.648Z,1725567668.648 [Default:CheckIn] Stopped
2024-09-05T20:21:08.648Z,1725567668.648 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-09-05T20:21:08.648Z,1725567668.648 [Default:CheckIn](INFO): Running loop #3
2024-09-05T20:21:08.648Z,1725567668.648 [Default:CheckIn] Running Loop=3
2024-09-05T20:21:08.648Z,1725567668.648 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-09-05T20:21:08.648Z,1725567668.648 [Default:CheckIn:Read_GPS] Running Loop=1
2024-09-05T20:21:10.662Z,1725567670.662 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,202110.00,A,3648.13971,N,12147.22699,W,0.058,177.59,050924,,,D*70
2024-09-05T20:21:10.664Z,1725567670.664 [NAL9602](INFO): GPS fix at 20240905T202110: (36.802329, -121.787116)
2024-09-05T20:21:10.674Z,1725567670.674 [Default:CheckIn:Read_GPS] Stopped
2024-09-05T20:21:10.674Z,1725567670.674 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-09-05T20:21:17.968Z,1725567677.968 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20240905T200630/Courier0010.lzma
2024-09-05T20:21:18.971Z,1725567678.971 [DataOverHttps](INFO): Moved sent file to Logs/20240905T200630/Courier0010.lzma.bak
2024-09-05T20:21:18.971Z,1725567678.971 [DataOverHttps](INFO): SBD MOMSN=23131939
2024-09-05T20:21:30.108Z,1725567690.108 [NAL9602](INFO): SBD MO Status=0, MOMSN=56403, MT Status=0, MTMSN=0
2024-09-05T20:21:30.108Z,1725567690.108 [NAL9602](INFO): No messages in MT queue
2024-09-05T20:21:35.481Z,1725567695.481 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20240905T200630/Express0011.lzma
2024-09-05T20:21:36.483Z,1725567696.483 [DataOverHttps](INFO): Moved sent file to Logs/20240905T200630/Express0011.lzma.bak
2024-09-05T20:21:36.483Z,1725567696.483 [DataOverHttps](INFO): SBD MOMSN=23131942
2024-09-05T20:21:38.213Z,1725567698.213 [Default:CheckIn:Read_Iridium] Stopped
2024-09-05T20:21:38.213Z,1725567698.213 [Default:CheckIn:C.Wait] Running Loop=1
2024-09-05T20:21:38.213Z,1725567698.213 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-09-05T20:22:00.808Z,1725567720.808 [NAL9602](INFO): Not Powering down - fast GPS
2024-09-05T20:26:38.807Z,1725567998.807 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-09-05T20:26:38.808Z,1725567998.808 [Default:CheckIn:C.Wait] Stopped
2024-09-05T20:26:38.808Z,1725567998.808 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-09-05T20:26:38.808Z,1725567998.808 [Default:CheckIn:D] Running Loop=1
2024-09-05T20:26:39.202Z,1725567999.202 [Default:CheckIn:D] Stopped
2024-09-05T20:26:39.202Z,1725567999.202 [Default:CheckIn:E] Running Loop=1
2024-09-05T20:26:39.600Z,1725567999.600 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 16.818317 min
2024-09-05T20:26:39.600Z,1725567999.600 [Default:CheckIn:E] Stopped
2024-09-05T20:26:39.600Z,1725567999.600 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-09-05T20:26:39.600Z,1725567999.600 [Default:CheckIn] Stopped
2024-09-05T20:26:39.601Z,1725567999.601 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-09-05T20:26:39.601Z,1725567999.601 [Default:CheckIn](INFO): Running loop #4
2024-09-05T20:26:39.601Z,1725567999.601 [Default:CheckIn] Running Loop=4
2024-09-05T20:26:39.601Z,1725567999.601 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-09-05T20:26:39.601Z,1725567999.601 [Default:CheckIn:Read_GPS] Running Loop=1
2024-09-05T20:26:41.620Z,1725568001.620 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,202641.00,A,3648.14199,N,12147.22832,W,0.039,177.59,050924,,,D*72
2024-09-05T20:26:41.622Z,1725568001.622 [NAL9602](INFO): GPS fix at 20240905T202641: (36.802366, -121.787139)
2024-09-05T20:26:41.632Z,1725568001.632 [Default:CheckIn:Read_GPS] Stopped
2024-09-05T20:26:41.632Z,1725568001.632 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-09-05T20:26:51.693Z,1725568011.693 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20240905T200630/Courier0013.lzma
2024-09-05T20:26:52.695Z,1725568012.695 [DataOverHttps](INFO): Moved sent file to Logs/20240905T200630/Courier0013.lzma.bak
2024-09-05T20:26:52.695Z,1725568012.695 [DataOverHttps](INFO): SBD MOMSN=23131968
2024-09-05T20:27:00.254Z,1725568020.254 [NAL9602](INFO): SBD MO Status=0, MOMSN=56404, MT Status=0, MTMSN=0
2024-09-05T20:27:00.254Z,1725568020.254 [NAL9602](INFO): No messages in MT queue
2024-09-05T20:27:10.793Z,1725568030.793 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20240905T200630/Express0014.lzma
2024-09-05T20:27:11.795Z,1725568031.795 [DataOverHttps](INFO): Moved sent file to Logs/20240905T200630/Express0014.lzma.bak
2024-09-05T20:27:11.795Z,1725568031.795 [DataOverHttps](INFO): SBD MOMSN=23131971
2024-09-05T20:27:13.586Z,1725568033.586 [Default:CheckIn:Read_Iridium] Stopped
2024-09-05T20:27:13.586Z,1725568033.586 [Default:CheckIn:C.Wait] Running Loop=1
2024-09-05T20:27:13.587Z,1725568033.587 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-09-05T20:27:30.950Z,1725568050.950 [NAL9602](INFO): Not Powering down - fast GPS
2024-09-05T20:32:14.006Z,1725568334.006 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-09-05T20:32:14.006Z,1725568334.006 [Default:CheckIn:C.Wait] Stopped
2024-09-05T20:32:14.006Z,1725568334.006 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-09-05T20:32:14.006Z,1725568334.006 [Default:CheckIn:D] Running Loop=1
2024-09-05T20:32:14.403Z,1725568334.404 [Default:CheckIn:D] Stopped
2024-09-05T20:32:14.404Z,1725568334.404 [Default:CheckIn:E] Running Loop=1
2024-09-05T20:32:14.811Z,1725568334.811 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 22.405017 min
2024-09-05T20:32:14.812Z,1725568334.812 [Default:CheckIn:E] Stopped
2024-09-05T20:32:14.812Z,1725568334.812 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-09-05T20:32:14.812Z,1725568334.812 [Default:CheckIn] Stopped
2024-09-05T20:32:14.812Z,1725568334.812 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-09-05T20:32:14.812Z,1725568334.812 [Default:CheckIn](INFO): Running loop #5
2024-09-05T20:32:14.812Z,1725568334.812 [Default:CheckIn] Running Loop=5
2024-09-05T20:32:14.812Z,1725568334.812 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-09-05T20:32:14.812Z,1725568334.812 [Default:CheckIn:Read_GPS] Running Loop=1
2024-09-05T20:32:16.824Z,1725568336.824 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,203217.00,A,3648.16923,N,12147.28110,W,0.622,193.47,050924,,,D*75
2024-09-05T20:32:16.826Z,1725568336.826 [NAL9602](INFO): GPS fix at 20240905T203217: (36.802821, -121.788018)
2024-09-05T20:32:16.836Z,1725568336.836 [Default:CheckIn:Read_GPS] Stopped
2024-09-05T20:32:16.836Z,1725568336.836 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-09-05T20:32:27.388Z,1725568347.388 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20240905T200630/Courier0016.lzma
2024-09-05T20:32:28.391Z,1725568348.391 [DataOverHttps](INFO): Moved sent file to Logs/20240905T200630/Courier0016.lzma.bak
2024-09-05T20:32:28.391Z,1725568348.391 [DataOverHttps](INFO): SBD MOMSN=23131984
2024-09-05T20:32:38.719Z,1725568358.719 [NAL9602](INFO): SBD MO Status=0, MOMSN=56405, MT Status=0, MTMSN=0
2024-09-05T20:32:38.720Z,1725568358.720 [NAL9602](INFO): No messages in MT queue
2024-09-05T20:32:44.141Z,1725568364.141 [DataOverHttps](INFO): Sending 144 bytes from file Logs/20240905T200630/Express0017.lzma
2024-09-05T20:32:45.143Z,1725568365.143 [DataOverHttps](INFO): Moved sent file to Logs/20240905T200630/Express0017.lzma.bak
2024-09-05T20:32:45.143Z,1725568365.143 [DataOverHttps](INFO): SBD MOMSN=23131994
2024-09-05T20:32:46.842Z,1725568366.842 [Default:CheckIn:Read_Iridium] Stopped
2024-09-05T20:32:46.842Z,1725568366.842 [Default:CheckIn:C.Wait] Running Loop=1
2024-09-05T20:32:46.842Z,1725568366.842 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-09-05T20:33:09.490Z,1725568389.490 [NAL9602](INFO): Not Powering down - fast GPS
2024-09-05T20:37:47.562Z,1725568667.562 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-09-05T20:37:47.562Z,1725568667.562 [Default:CheckIn:C.Wait] Stopped
2024-09-05T20:37:47.562Z,1725568667.562 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-09-05T20:37:47.562Z,1725568667.562 [Default:CheckIn:D] Running Loop=1
2024-09-05T20:37:47.972Z,1725568667.972 [Default:CheckIn:D] Stopped
2024-09-05T20:37:47.972Z,1725568667.972 [Default:CheckIn:E] Running Loop=1
2024-09-05T20:37:48.371Z,1725568668.371 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 27.964490 min
2024-09-05T20:37:48.372Z,1725568668.372 [Default:CheckIn:E] Stopped
2024-09-05T20:37:48.372Z,1725568668.372 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-09-05T20:37:48.372Z,1725568668.372 [Default:CheckIn] Stopped
2024-09-05T20:37:48.372Z,1725568668.372 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-09-05T20:37:48.372Z,1725568668.372 [Default:CheckIn](INFO): Running loop #6
2024-09-05T20:37:48.372Z,1725568668.372 [Default:CheckIn] Running Loop=6
2024-09-05T20:37:48.372Z,1725568668.372 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-09-05T20:37:48.372Z,1725568668.372 [Default:CheckIn:Read_GPS] Running Loop=1
2024-09-05T20:42:48.541Z,1725568968.541 [Default:CheckIn:Read_GPS](INFO): Timed out from 2024-09-05T20:37:48.4Z
2024-09-05T20:42:48.541Z,1725568968.541 [Default:CheckIn:Read_GPS] Stopped
2024-09-05T20:42:48.541Z,1725568968.541 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-09-05T20:42:52.635Z,1725568972.635 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2024-09-05T20:42:59.464Z,1725568979.464 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20240905T200630/Courier0019.lzma
2024-09-05T20:43:00.467Z,1725568980.467 [DataOverHttps](INFO): Moved sent file to Logs/20240905T200630/Courier0019.lzma.bak
2024-09-05T20:43:00.467Z,1725568980.467 [DataOverHttps](INFO): SBD MOMSN=23132020
2024-09-05T20:43:16.336Z,1725568996.336 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20240905T200630/Express0020.lzma
2024-09-05T20:43:17.339Z,1725568997.339 [DataOverHttps](INFO): Moved sent file to Logs/20240905T200630/Express0020.lzma.bak
2024-09-05T20:43:17.340Z,1725568997.340 [DataOverHttps](INFO): SBD MOMSN=23132025
2024-09-05T20:43:18.931Z,1725568998.931 [Default:CheckIn:Read_Iridium] Stopped
2024-09-05T20:43:18.931Z,1725568998.931 [Default:CheckIn:C.Wait] Running Loop=1
2024-09-05T20:43:18.931Z,1725568998.931 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-09-05T20:43:23.358Z,1725569003.358 [NAL9602](INFO): Not Powering down - fast GPS
2024-09-05T20:48:19.599Z,1725569299.599 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-09-05T20:48:19.600Z,1725569299.600 [Default:CheckIn:C.Wait] Stopped
2024-09-05T20:48:19.600Z,1725569299.600 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-09-05T20:48:19.600Z,1725569299.600 [Default:CheckIn:D] Running Loop=1
2024-09-05T20:48:20.021Z,1725569300.021 [Default:CheckIn:D] Stopped
2024-09-05T20:48:20.021Z,1725569300.021 [Default:CheckIn:E] Running Loop=1
2024-09-05T20:48:20.407Z,1725569300.407 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 38.498637 min
2024-09-05T20:48:20.407Z,1725569300.407 [Default:CheckIn:E] Stopped
2024-09-05T20:48:20.407Z,1725569300.407 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-09-05T20:48:20.407Z,1725569300.407 [Default:CheckIn] Stopped
2024-09-05T20:48:20.407Z,1725569300.407 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-09-05T20:48:20.407Z,1725569300.407 [Default:CheckIn](INFO): Running loop #7
2024-09-05T20:48:20.407Z,1725569300.407 [Default:CheckIn] Running Loop=7
2024-09-05T20:48:20.408Z,1725569300.408 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-09-05T20:48:20.408Z,1725569300.408 [Default:CheckIn:Read_GPS] Running Loop=1
2024-09-05T20:48:22.015Z,1725569302.015 [NAL9602](FAULT): GPS failed to acquire within timeout.
2024-09-05T20:48:22.015Z,1725569302.015 [NAL9602] Data Fault, FailCount= 1
2024-09-05T20:48:22.015Z,1725569302.015 [NAL9602](ERROR): Data Fault
2024-09-05T20:48:22.071Z,1725569302.071 [CBIT](ERROR): Data Fault in component: NAL9602
2024-09-05T20:48:22.418Z,1725569302.418 [NAL9602](INFO): Powering down
2024-09-05T20:48:23.290Z,1725569303.290 [CBIT](INFO): Clearing failed state for component NAL9602
2024-09-05T20:48:23.290Z,1725569303.290 [NAL9602] No Fault, FailCount= 1
2024-09-05T20:48:52.722Z,1725569332.722 [NAL9602](INFO): Powering up NAL9602
2024-09-05T20:49:03.635Z,1725569343.635 [NAL9602](INFO): NAL9602 initialized
2024-09-05T20:53:20.675Z,1725569600.675 [Default:CheckIn:Read_GPS](INFO): Timed out from 2024-09-05T20:48:20.4Z
2024-09-05T20:53:20.675Z,1725569600.675 [Default:CheckIn:Read_GPS] Stopped
2024-09-05T20:53:20.675Z,1725569600.675 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-09-05T20:53:30.652Z,1725569610.652 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20240905T200630/Courier0022.lzma
2024-09-05T20:53:31.655Z,1725569611.655 [DataOverHttps](INFO): Moved sent file to Logs/20240905T200630/Courier0022.lzma.bak
2024-09-05T20:53:31.655Z,1725569611.655 [DataOverHttps](INFO): SBD MOMSN=23132055
2024-09-05T20:53:47.525Z,1725569627.525 [DataOverHttps](INFO): Sending 250 bytes from file Logs/20240905T200630/Express0023.lzma
2024-09-05T20:53:48.527Z,1725569628.527 [DataOverHttps](INFO): Moved sent file to Logs/20240905T200630/Express0023.lzma.bak
2024-09-05T20:53:48.527Z,1725569628.527 [DataOverHttps](INFO): SBD MOMSN=23132060
2024-09-05T20:53:50.147Z,1725569630.147 [Default:CheckIn:Read_Iridium] Stopped
2024-09-05T20:53:50.148Z,1725569630.148 [Default:CheckIn:C.Wait] Running Loop=1
2024-09-05T20:53:50.148Z,1725569630.148 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-09-05T20:54:07.493Z,1725569647.493 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2024-09-05T20:54:38.198Z,1725569678.198 [NAL9602](INFO): Not Powering down - fast GPS
2024-09-05T20:58:50.809Z,1725569930.809 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-09-05T20:58:50.809Z,1725569930.809 [Default:CheckIn:C.Wait] Stopped
2024-09-05T20:58:50.809Z,1725569930.809 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-09-05T20:58:50.810Z,1725569930.810 [Default:CheckIn:D] Running Loop=1
2024-09-05T20:58:51.200Z,1725569931.200 [Default:CheckIn:D] Stopped
2024-09-05T20:58:51.200Z,1725569931.200 [Default:CheckIn:E] Running Loop=1
2024-09-05T20:58:51.604Z,1725569931.604 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 49.018286 min
2024-09-05T20:58:51.604Z,1725569931.604 [Default:CheckIn:E] Stopped
2024-09-05T20:58:51.604Z,1725569931.604 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-09-05T20:58:51.604Z,1725569931.604 [Default:CheckIn] Stopped
2024-09-05T20:58:51.604Z,1725569931.604 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-09-05T20:58:51.605Z,1725569931.605 [Default:CheckIn](INFO): Running loop #8
2024-09-05T20:58:51.605Z,1725569931.605 [Default:CheckIn] Running Loop=8
2024-09-05T20:58:51.605Z,1725569931.605 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-09-05T20:58:51.605Z,1725569931.605 [Default:CheckIn:Read_GPS] Running Loop=1
2024-09-05T20:59:24.324Z,1725569964.324 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2024-09-05T20:59:24.401Z,1725569964.401 [NAL9602](ERROR): received:
+CSQ:0
OK405, 0, 0, 0, 0
OK
2024-09-05T20:59:28.137Z,1725569968.137 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-09-05T20:59:59.261Z,1725569999.261 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-09-05T21:00:30.385Z,1725570030.385 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-09-05T21:03:51.836Z,1725570231.836 [Default:CheckIn:Read_GPS](INFO): Timed out from 2024-09-05T20:58:51.6Z
2024-09-05T21:03:51.836Z,1725570231.836 [Default:CheckIn:Read_GPS] Stopped
2024-09-05T21:03:51.836Z,1725570231.836 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-09-05T21:03:55.438Z,1725570235.438 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2024-09-05T21:03:59.016Z,1725570239.016 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20240905T200630/Courier0025.lzma
2024-09-05T21:04:00.019Z,1725570240.019 [DataOverHttps](INFO): Moved sent file to Logs/20240905T200630/Courier0025.lzma.bak
2024-09-05T21:04:00.019Z,1725570240.019 [DataOverHttps](INFO): SBD MOMSN=23132087
2024-09-05T21:04:15.673Z,1725570255.673 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20240905T200630/Express0026.lzma
2024-09-05T21:04:16.675Z,1725570256.675 [DataOverHttps](INFO): Moved sent file to Logs/20240905T200630/Express0026.lzma.bak
2024-09-05T21:04:16.675Z,1725570256.675 [DataOverHttps](INFO): SBD MOMSN=23132094
2024-09-05T21:04:18.497Z,1725570258.497 [Default:CheckIn:Read_Iridium] Stopped
2024-09-05T21:04:18.497Z,1725570258.497 [Default:CheckIn:C.Wait] Running Loop=1
2024-09-05T21:04:18.498Z,1725570258.498 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-09-05T21:04:26.223Z,1725570266.223 [NAL9602](INFO): Not Powering down - fast GPS
2024-09-05T21:09:19.254Z,1725570559.254 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-09-05T21:09:19.254Z,1725570559.254 [Default:CheckIn:C.Wait] Stopped
2024-09-05T21:09:19.254Z,1725570559.254 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-09-05T21:09:19.255Z,1725570559.255 [Default:CheckIn:D] Running Loop=1
2024-09-05T21:09:19.663Z,1725570559.663 [Default:CheckIn:D] Stopped
2024-09-05T21:09:19.663Z,1725570559.663 [Default:CheckIn:E] Running Loop=1
2024-09-05T21:09:20.066Z,1725570560.066 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 59.492680 min
2024-09-05T21:09:20.066Z,1725570560.066 [Default:CheckIn:E] Stopped
2024-09-05T21:09:20.066Z,1725570560.066 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-09-05T21:09:20.066Z,1725570560.066 [Default:CheckIn] Stopped
2024-09-05T21:09:20.066Z,1725570560.066 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-09-05T21:09:20.066Z,1725570560.066 [Default:CheckIn](INFO): Running loop #9
2024-09-05T21:09:20.066Z,1725570560.066 [Default:CheckIn] Running Loop=9
2024-09-05T21:09:20.066Z,1725570560.066 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-09-05T21:09:20.066Z,1725570560.066 [Default:CheckIn:Read_GPS] Running Loop=1
2024-09-05T21:09:21.676Z,1725570561.676 [NAL9602](FAULT): GPS failed to acquire within timeout.
2024-09-05T21:09:21.676Z,1725570561.676 [NAL9602] Data Fault, FailCount= 2
2024-09-05T21:09:21.676Z,1725570561.676 [NAL9602](ERROR): Data Fault
2024-09-05T21:09:21.695Z,1725570561.695 [CBIT](ERROR): Data Fault in component: NAL9602
2024-09-05T21:09:22.074Z,1725570562.074 [NAL9602](INFO): Powering down
2024-09-05T21:09:22.905Z,1725570562.905 [CBIT](INFO): Clearing failed state for component NAL9602
2024-09-05T21:09:22.905Z,1725570562.905 [NAL9602] No Fault, FailCount= 2
2024-09-05T21:09:52.378Z,1725570592.378 [NAL9602](INFO): Powering up NAL9602
2024-09-05T21:10:03.286Z,1725570603.286 [NAL9602](INFO): NAL9602 initialized
2024-09-05T21:13:56.140Z,1725570836.140 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-05T21:14:08.260Z,1725570848.260 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-05T21:14:20.068Z,1725570860.068 [Default:CheckIn:Read_GPS](INFO): Timed out from 2024-09-05T21:09:20.1Z
2024-09-05T21:14:20.068Z,1725570860.068 [Default:CheckIn:Read_GPS] Stopped
2024-09-05T21:14:20.068Z,1725570860.068 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-09-05T21:14:20.379Z,1725570860.379 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-05T21:14:29.820Z,1725570869.820 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20240905T200630/Courier0028.lzma
2024-09-05T21:14:30.823Z,1725570870.823 [DataOverHttps](INFO): Moved sent file to Logs/20240905T200630/Courier0028.lzma.bak
2024-09-05T21:14:30.823Z,1725570870.823 [DataOverHttps](INFO): SBD MOMSN=23132120
2024-09-05T21:14:32.904Z,1725570872.904 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-05T21:14:45.027Z,1725570885.027 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-05T21:14:46.781Z,1725570886.781 [DataOverHttps](INFO): Sending 228 bytes from file Logs/20240905T200630/Express0029.lzma
2024-09-05T21:14:47.783Z,1725570887.783 [DataOverHttps](INFO): Moved sent file to Logs/20240905T200630/Express0029.lzma.bak
2024-09-05T21:14:47.783Z,1725570887.783 [DataOverHttps](INFO): SBD MOMSN=23132122
2024-09-05T21:14:49.514Z,1725570889.514 [Default:CheckIn:Read_Iridium] Stopped
2024-09-05T21:14:49.514Z,1725570889.514 [Default:CheckIn:C.Wait] Running Loop=1
2024-09-05T21:14:49.514Z,1725570889.514 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-09-05T21:14:57.196Z,1725570897.196 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-05T21:15:07.298Z,1725570907.298 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2024-09-05T21:15:08.507Z,1725570908.507 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-05T21:15:19.827Z,1725570919.827 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-05T21:15:38.006Z,1725570938.006 [NAL9602](INFO): Not Powering down - fast GPS
2024-09-05T21:17:54.967Z,1725571074.967 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-05T21:18:08.706Z,1725571088.706 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-05T21:18:22.439Z,1725571102.439 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-05T21:18:35.431Z,1725571115.431 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-05T21:18:49.169Z,1725571129.169 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-05T21:19:02.501Z,1725571142.501 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-05T21:19:15.837Z,1725571155.837 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-05T21:19:29.164Z,1725571169.164 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-05T21:19:42.497Z,1725571182.497 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-05T21:19:50.212Z,1725571190.212 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-09-05T21:19:50.212Z,1725571190.212 [Default:CheckIn:C.Wait] Stopped
2024-09-05T21:19:50.212Z,1725571190.212 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-09-05T21:19:50.212Z,1725571190.212 [Default:CheckIn:D] Running Loop=1
2024-09-05T21:19:50.607Z,1725571190.607 [Default:CheckIn:D] Stopped
2024-09-05T21:19:50.607Z,1725571190.607 [Default:CheckIn:E] Running Loop=1
2024-09-05T21:19:51.012Z,1725571191.012 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 70.008415 min
2024-09-05T21:19:51.012Z,1725571191.012 [Default:CheckIn:E] Stopped
2024-09-05T21:19:51.012Z,1725571191.012 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-09-05T21:19:51.012Z,1725571191.012 [Default:CheckIn] Stopped
2024-09-05T21:19:51.012Z,1725571191.012 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-09-05T21:19:51.012Z,1725571191.012 [Default:CheckIn](INFO): Running loop #10
2024-09-05T21:19:51.012Z,1725571191.012 [Default:CheckIn] Running Loop=10
2024-09-05T21:19:51.013Z,1725571191.013 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-09-05T21:19:51.013Z,1725571191.013 [Default:CheckIn:Read_GPS] Running Loop=1
2024-09-05T21:19:55.829Z,1725571195.829 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-05T21:20:03.108Z,1725571203.108 [BPC1](INFO): Calculating totals. Valid battery stick count: 39. Valid reserve battery stick count: 5.
2024-09-05T21:20:03.111Z,1725571203.111 [BPC1](INFO): Received data from all battery sticks.
2024-09-05T21:20:23.711Z,1725571223.711 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2024-09-05T21:20:23.785Z,1725571223.785 [NAL9602](ERROR): received:
+CSQ:0
OK405, 0, 0, 0, 0
OK
2024-09-05T21:20:49.967Z,1725571249.967 [NAL9602](INFO): SBD MO Status=2, MOMSN=56406, MT Status=2, MTMSN=0
2024-09-05T21:20:49.968Z,1725571249.968 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2024-09-05T21:21:10.171Z,1725571270.171 [NAL9602](INFO): SBD MO Status=0, MOMSN=56406, MT Status=0, MTMSN=0
2024-09-05T21:21:10.172Z,1725571270.172 [NAL9602](INFO): No messages in MT queue
2024-09-05T21:21:10.973Z,1725571270.973 [NAL9602](FAULT): GPS failed to acquire within timeout.
2024-09-05T21:21:10.973Z,1725571270.973 [NAL9602] Data Fault, FailCount= 1
2024-09-05T21:21:10.973Z,1725571270.973 [NAL9602](ERROR): Data Fault
2024-09-05T21:21:11.013Z,1725571271.013 [CBIT](ERROR): Data Fault in component: NAL9602
2024-09-05T21:21:11.378Z,1725571271.378 [NAL9602](INFO): Powering down
2024-09-05T21:21:12.214Z,1725571272.214 [CBIT](INFO): Clearing failed state for component NAL9602
2024-09-05T21:21:12.214Z,1725571272.214 [NAL9602] No Fault, FailCount= 1
2024-09-05T21:21:41.678Z,1725571301.678 [NAL9602](INFO): Powering up NAL9602
2024-09-05T21:21:52.586Z,1725571312.586 [NAL9602](INFO): NAL9602 initialized
2024-09-05T21:22:48.129Z,1725571368.129 [CommandExec](IMPORTANT): got command maintain control VerticalControl.buoyancyAction 100 cubic_centimeter
2024-09-05T21:22:48.132Z,1725571368.132 [ComponentRegistry](DEBUG): SyncComponent "Maintain_VerticalControl.buoyancyAction" handled in the control thread.
2024-09-05T21:22:48.428Z,1725571368.428 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,ESPComponent,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,Maintain_VerticalControl.buoyancyAction,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2024-09-05T21:23:36.562Z,1725571416.562 [CommandExec](IMPORTANT): got command failComponent
2024-09-05T21:23:36.562Z,1725571416.562 [CommandExec](IMPORTANT): Failed components:
2024-09-05T21:23:36.562Z,1725571416.562 [CommandExec](IMPORTANT): No failed Components.
2024-09-05T21:24:30.141Z,1725571470.141 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-09-05T21:24:51.198Z,1725571491.198 [Default:CheckIn:Read_GPS](INFO): Timed out from 2024-09-05T21:19:51.0Z
2024-09-05T21:24:51.198Z,1725571491.198 [Default:CheckIn:Read_GPS] Stopped
2024-09-05T21:24:51.198Z,1725571491.198 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-09-05T21:25:01.265Z,1725571501.265 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-09-05T21:25:22.274Z,1725571522.274 [NAL9602](INFO): Not Powering down - fast GPS
2024-09-05T21:25:32.389Z,1725571532.389 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-09-05T21:26:03.513Z,1725571563.513 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-09-05T21:26:34.653Z,1725571594.653 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-09-05T21:26:37.666Z,1725571597.666 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.743546
2024-09-05T21:27:08.789Z,1725571628.789 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-09-05T21:27:39.925Z,1725571659.925 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-09-05T21:28:11.049Z,1725571691.049 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-09-05T21:28:42.175Z,1725571722.175 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-09-05T21:29:02.589Z,1725571742.589 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003138
2024-09-05T21:29:13.512Z,1725571753.512 [DataOverHttps](INFO): Sending 51 bytes from file Logs/20240905T200630/Courier0031.lzma
2024-09-05T21:29:14.515Z,1725571754.515 [DataOverHttps](INFO): Moved sent file to Logs/20240905T200630/Courier0031.lzma.bak
2024-09-05T21:29:14.515Z,1725571754.515 [DataOverHttps](INFO): SBD MOMSN=23132193
2024-09-05T21:29:30.382Z,1725571770.382 [CommandExec](IMPORTANT): got command gfscan
2024-09-05T21:29:30.612Z,1725571770.612 [CBIT](IMPORTANT): Beginning ground fault scan
2024-09-05T21:29:32.998Z,1725571772.998 [CommandExec](IMPORTANT): got command report
2024-09-05T21:29:37.016Z,1725571777.016 [NAL9602](INFO): Not Powering down - fast GPS
2024-09-05T21:29:41.041Z,1725571781.041 [DataOverHttps](INFO): Sending 355 bytes from file Logs/20240905T200630/Express0032.lzma
2024-09-05T21:29:41.455Z,1725571781.455 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.002565
CHAN A1 (24V): 0.000369
CHAN A2 (12V): -0.002648
CHAN A3 (5V): -0.001851
CHAN B0 (3.3V): -0.000083
CHAN B1 (3.15aV): -0.000057
CHAN B2 (3.15bV): 0.000292
CHAN B3 (GND): 0.000361
OPEN: -0.000061
Full Scale: +/- 1 mA
2024-09-05T21:29:41.966Z,1725571781.966 [CommandExec](IMPORTANT): got command report mod platform_buoyancy_position
2024-09-05T21:29:42.489Z,1725571782.489 [Reporter](INFO): platform_buoyancy_position 109.847313 cc
2024-09-05T21:29:43.241Z,1725571783.241 [DataOverHttps](INFO): Moved sent file to Logs/20240905T200630/Express0032.lzma.bak
2024-09-05T21:29:43.241Z,1725571783.241 [DataOverHttps](INFO): SBD MOMSN=23132195
2024-09-05T21:29:44.395Z,1725571784.395 [Default:CheckIn:Read_Iridium] Stopped
2024-09-05T21:29:44.395Z,1725571784.395 [Default:CheckIn:C.Wait] Running Loop=1
2024-09-05T21:29:44.395Z,1725571784.395 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-09-05T21:29:57.156Z,1725571797.156 [CommandExec](IMPORTANT): got command maintain control VerticalControl.buoyancyAction 150 cubic_centimeter
2024-09-05T21:29:59.431Z,1725571799.431 [Reporter](INFO): platform_buoyancy_position 100.849205 cc
2024-09-05T21:29:59.831Z,1725571799.831 [Reporter](INFO): platform_buoyancy_position 100.983513 cc
2024-09-05T21:30:00.321Z,1725571800.321 [Reporter](INFO): platform_buoyancy_position 103.400917 cc
2024-09-05T21:30:00.695Z,1725571800.695 [Reporter](INFO): platform_buoyancy_position 107.698509 cc
2024-09-05T21:30:01.104Z,1725571801.104 [Reporter](INFO): platform_buoyancy_position 111.996117 cc
2024-09-05T21:30:01.419Z,1725571801.419 [Reporter](INFO): platform_buoyancy_position 116.293709 cc
2024-09-05T21:30:01.831Z,1725571801.831 [Reporter](INFO): platform_buoyancy_position 120.725609 cc
2024-09-05T21:30:02.252Z,1725571802.252 [Reporter](INFO): platform_buoyancy_position 127.037712 cc
2024-09-05T21:30:02.663Z,1725571802.663 [Reporter](INFO): platform_buoyancy_position 131.469604 cc
2024-09-05T21:30:03.047Z,1725571803.047 [Reporter](INFO): platform_buoyancy_position 135.901520 cc
2024-09-05T21:30:03.491Z,1725571803.491 [Reporter](INFO): platform_buoyancy_position 142.213623 cc
2024-09-05T21:34:44.979Z,1725572084.979 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-09-05T21:34:44.979Z,1725572084.979 [Default:CheckIn:C.Wait] Stopped
2024-09-05T21:34:44.979Z,1725572084.979 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-09-05T21:34:44.979Z,1725572084.979 [Default:CheckIn:D] Running Loop=1
2024-09-05T21:34:45.383Z,1725572085.383 [Default:CheckIn:D] Stopped
2024-09-05T21:34:45.383Z,1725572085.383 [Default:CheckIn:E] Running Loop=1
2024-09-05T21:34:45.784Z,1725572085.784 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 84.921338 min
2024-09-05T21:34:45.784Z,1725572085.784 [Default:CheckIn:E] Stopped
2024-09-05T21:34:45.784Z,1725572085.784 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-09-05T21:34:45.784Z,1725572085.784 [Default:CheckIn] Stopped
2024-09-05T21:34:45.784Z,1725572085.784 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-09-05T21:34:45.784Z,1725572085.784 [Default:CheckIn](INFO): Running loop #11
2024-09-05T21:34:45.785Z,1725572085.785 [Default:CheckIn] Running Loop=11
2024-09-05T21:34:45.785Z,1725572085.785 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-09-05T21:34:45.785Z,1725572085.785 [Default:CheckIn:Read_GPS] Running Loop=1
2024-09-05T21:34:47.386Z,1725572087.386 [NAL9602](FAULT): GPS failed to acquire within timeout.
2024-09-05T21:34:47.386Z,1725572087.386 [NAL9602] Data Fault, FailCount= 2
2024-09-05T21:34:47.386Z,1725572087.386 [NAL9602](ERROR): Data Fault
2024-09-05T21:34:47.414Z,1725572087.414 [CBIT](ERROR): Data Fault in component: NAL9602
2024-09-05T21:34:47.794Z,1725572087.794 [NAL9602](INFO): Powering down
2024-09-05T21:34:48.655Z,1725572088.655 [CBIT](INFO): Clearing failed state for component NAL9602
2024-09-05T21:34:48.655Z,1725572088.655 [NAL9602] No Fault, FailCount= 2
2024-09-05T21:35:18.089Z,1725572118.089 [NAL9602](INFO): Powering up NAL9602
2024-09-05T21:35:28.998Z,1725572128.998 [NAL9602](INFO): NAL9602 initialized
2024-09-05T21:37:10.813Z,1725572230.813 [NAL9602](INFO): SBD MO Status=2, MOMSN=56407, MT Status=2, MTMSN=0
2024-09-05T21:37:10.813Z,1725572230.813 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2024-09-05T21:38:09.791Z,1725572289.791 [NAL9602](INFO): SBD MO Status=2, MOMSN=56407, MT Status=2, MTMSN=0
2024-09-05T21:38:09.792Z,1725572289.792 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2024-09-05T21:38:47.766Z,1725572327.766 [NAL9602](INFO): SBD MO Status=2, MOMSN=56407, MT Status=2, MTMSN=0
2024-09-05T21:38:47.767Z,1725572327.767 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2024-09-05T21:39:45.951Z,1725572385.951 [Default:CheckIn:Read_GPS](INFO): Timed out from 2024-09-05T21:34:45.8Z
2024-09-05T21:39:45.951Z,1725572385.951 [Default:CheckIn:Read_GPS] Stopped
2024-09-05T21:39:45.951Z,1725572385.951 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-09-05T21:39:49.180Z,1725572389.180 [NAL9602](INFO): SBD MO Status=2, MOMSN=56407, MT Status=2, MTMSN=0
2024-09-05T21:39:49.180Z,1725572389.180 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2024-09-05T21:39:53.492Z,1725572393.492 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20240905T200630/Courier0034.lzma
2024-09-05T21:39:54.495Z,1725572394.495 [DataOverHttps](INFO): Moved sent file to Logs/20240905T200630/Courier0034.lzma.bak
2024-09-05T21:39:54.495Z,1725572394.495 [DataOverHttps](IMPORTANT): SBD MOMSN=23132233, MTMSN=20240905T213954
2024-09-05T21:40:02.097Z,1725572402.097 [DataOverHttps](INFO): Received command: restart sys
2024-09-05T21:40:02.119Z,1725572402.119 [CommandExec](IMPORTANT): got command restart system
2024-09-05T21:40:04.229Z,1725572404.229 [Supervisor](INFO): Stop Mission called by Supervisor::terminate
2024-09-05T21:40:04.230Z,1725572404.230 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread.
2024-09-05T21:40:04.230Z,1725572404.230 [CommandExec](INFO): Uninitializing the command executive.
2024-09-05T21:40:04.230Z,1725572404.230 [CommandExec](INFO): Uninitializing the command scheduler.
2024-09-05T21:40:04.230Z,1725572404.230 [CommandExec ThreadHandler](INFO): Thread cancelled.
2024-09-05T21:40:04.397Z,1725572404.397 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye!
2024-09-05T21:40:04.397Z,1725572404.397 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2024-09-05T21:40:04.397Z,1725572404.397 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2024-09-05T21:40:04.398Z,1725572404.398 [NavChartDb](INFO): Join timeout helper Thread ID is 1455
2024-09-05T21:40:04.673Z,1725572404.673 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2024-09-05T21:40:04.673Z,1725572404.673 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2024-09-05T21:40:04.681Z,1725572404.681 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2024-09-05T21:40:04.681Z,1725572404.681 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2024-09-05T21:40:04.682Z,1725572404.682 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 1456
2024-09-05T21:40:04.749Z,1725572404.749 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2024-09-05T21:40:04.749Z,1725572404.749 [WetLabsBB2FL](INFO): Powering down
2024-09-05T21:40:04.750Z,1725572404.750 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2024-09-05T21:40:04.757Z,1725572404.757 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2024-09-05T21:40:04.757Z,1725572404.757 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2024-09-05T21:40:04.757Z,1725572404.757 [CTD_Seabird](INFO): Join timeout helper Thread ID is 1457
2024-09-05T21:40:04.917Z,1725572404.917 [CTD_Seabird](INFO): Powering down
2024-09-05T21:40:04.929Z,1725572404.929 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2024-09-05T21:40:04.929Z,1725572404.929 [CTD_Seabird](INFO): Powering down
2024-09-05T21:40:04.941Z,1725572404.941 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2024-09-05T21:40:04.949Z,1725572404.949 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2024-09-05T21:40:04.949Z,1725572404.949 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2024-09-05T21:40:04.950Z,1725572404.950 [Radio_Surface](INFO): Join timeout helper Thread ID is 1458
2024-09-05T21:40:05.145Z,1725572405.145 [Radio_Surface](INFO): Powering down
2024-09-05T21:40:05.146Z,1725572405.146 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2024-09-05T21:40:05.147Z,1725572405.147 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2024-09-05T21:40:05.161Z,1725572405.161 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2024-09-05T21:40:05.161Z,1725572405.161 [Onboard ThreadHandler](INFO): Thread cancelled.
2024-09-05T21:40:05.161Z,1725572405.161 [Onboard](INFO): Join timeout helper Thread ID is 1459
2024-09-05T21:40:07.601Z,1725572407.601 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread.
2024-09-05T21:40:07.601Z,1725572407.601 [Onboard ThreadHandler](INFO): Thread cancelled.
2024-09-05T21:40:07.610Z,1725572407.610 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2024-09-05T21:40:07.610Z,1725572407.610 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2024-09-05T21:40:07.610Z,1725572407.610 [DataOverHttps](INFO): Join timeout helper Thread ID is 1460
2024-09-05T21:40:08.117Z,1725572408.117 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2024-09-05T21:40:08.118Z,1725572408.118 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2024-09-05T21:40:08.134Z,1725572408.134 [ComponentRegistry](INFO): Shutting down DATMMP ThreadHandler
2024-09-05T21:40:08.134Z,1725572408.134 [DATMMP ThreadHandler](INFO): Thread cancelled.
2024-09-05T21:40:08.134Z,1725572408.134 [DATMMP](INFO): Join timeout helper Thread ID is 1461
2024-09-05T21:40:08.269Z,1725572408.269 [DATMMP](INFO): Stop
2024-09-05T21:40:08.269Z,1725572408.269 [DATMMP](INFO): uninitialize
2024-09-05T21:40:08.269Z,1725572408.269 [DATMMP](INFO): Powering down
2024-09-05T21:40:08.342Z,1725572408.342 [DATMMP ThreadHandler](INFO): Uninitializing protected caller thread.
2024-09-05T21:40:08.342Z,1725572408.342 [DATMMP](INFO): uninitialize
2024-09-05T21:40:08.342Z,1725572408.342 [DATMMP](INFO): Powering down
2024-09-05T21:40:08.343Z,1725572408.343 [DATMMP ThreadHandler](INFO): Thread cancelled.
2024-09-05T21:40:08.346Z,1725572408.346 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2024-09-05T21:40:08.346Z,1725572408.346 [logger ThreadHandler](INFO): Thread cancelled.
2024-09-05T21:40:08.346Z,1725572408.346 [logger](INFO): Join timeout helper Thread ID is 1462
2024-09-05T21:40:08.377Z,1725572408.377 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2024-09-05T21:40:08.377Z,1725572408.377 [logger ThreadHandler](INFO): Thread cancelled.
2024-09-05T21:40:08.386Z,1725572408.386 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2024-09-05T21:40:08.386Z,1725572408.386 [CommandLine ThreadHandler](INFO): Thread cancelled.
2024-09-05T21:40:08.386Z,1725572408.386 [CommandLine](INFO): Join timeout helper Thread ID is 1463
2024-09-05T21:40:08.481Z,1725572408.481 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2024-09-05T21:40:08.481Z,1725572408.481 [CommandLine ThreadHandler](INFO): Thread cancelled.
2024-09-05T21:40:08.486Z,1725572408.486 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler
2024-09-05T21:40:08.486Z,1725572408.486 [CommandExec ThreadHandler](INFO): Thread cancelled.
2024-09-05T21:40:08.486Z,1725572408.486 [CommandExec](INFO): Join timeout helper Thread ID is 1464
2024-09-05T21:40:08.487Z,1725572408.487 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2024-09-05T21:40:08.488Z,1725572408.488 [controlThread ThreadHandler](INFO): Thread cancelled.
2024-09-05T21:40:08.488Z,1725572408.488 [controlThread](INFO): Join timeout helper Thread ID is 1465
2024-09-05T21:40:08.549Z,1725572408.549 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2024-09-05T21:40:08.549Z,1725572408.549 [controlThread](DEBUG): Uninitializing ControlThread
2024-09-05T21:40:08.550Z,1725572408.550 [AHRS_M2](INFO): Powering down
2024-09-05T21:40:08.622Z,1725572408.622 [NAL9602](INFO): Powering down
2024-09-05T21:40:08.624Z,1725572408.624 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2024-09-05T21:40:08.625Z,1725572408.625 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2024-09-05T21:40:08.625Z,1725572408.625 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2024-09-05T21:40:08.626Z,1725572408.626 [MissionManager](INFO): Uninitializing Mission Default
2024-09-05T21:40:08.626Z,1725572408.626 [Default] Stopped
2024-09-05T21:40:08.626Z,1725572408.626 [Default](DEBUG): Aggregate::uninitialize Default
2024-09-05T21:40:08.626Z,1725572408.626 [Default:B.GoToSurface] Stopped
2024-09-05T21:40:08.626Z,1725572408.626 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2024-09-05T21:40:08.626Z,1725572408.626 [Default:CheckIn] Stopped
2024-09-05T21:40:08.626Z,1725572408.626 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-09-05T21:40:08.626Z,1725572408.626 [Default:CheckIn:Read_Iridium] Stopped
2024-09-05T21:40:08.629Z,1725572408.629 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2024-09-05T21:40:08.630Z,1725572408.630 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2024-09-05T21:40:08.630Z,1725572408.630 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2024-09-05T21:40:08.630Z,1725572408.630 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2024-09-05T21:40:08.631Z,1725572408.631 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2024-09-05T21:40:08.631Z,1725572408.631 [BuoyancyServo](INFO): Powering down
2024-09-05T21:40:08.645Z,1725572408.645 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2024-09-05T21:40:08.645Z,1725572408.645 [ElevatorServo](INFO): Powering down
2024-09-05T21:40:08.646Z,1725572408.646 [MassServo](DEBUG): Uninitialize Mass Servo.
2024-09-05T21:40:08.646Z,1725572408.646 [MassServo](INFO): Powering down
2024-09-05T21:40:08.647Z,1725572408.647 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2024-09-05T21:40:08.647Z,1725572408.647 [RudderServo](INFO): Powering down
2024-09-05T21:40:08.648Z,1725572408.648 [ThrusterHE](DEBUG): Uninitialize Thruster Servo.
2024-09-05T21:40:08.648Z,1725572408.648 [ThrusterHE](INFO): Powering down
2024-09-05T21:40:08.649Z,1725572408.649 [SBIT](DEBUG): Uninitialize SBIT Component.
2024-09-05T21:40:08.650Z,1725572408.650 [IBIT](DEBUG): Uninitialize IBIT Component.
2024-09-05T21:40:08.650Z,1725572408.650 [CBIT](DEBUG): Uninitialize CBIT Component.
2024-09-05T21:40:08.650Z,1725572408.650 [CBIT](DEBUG): Powering off loads.
2024-09-05T21:40:08.661Z,1725572408.661 [CBIT](DEBUG): Disabling WDT.
2024-09-05T21:40:08.673Z,1725572408.673 [CBIT](DEBUG): Opening all GF detection circuits.
2024-09-05T21:40:08.674Z,1725572408.674 [controlThread ThreadHandler](INFO): Thread cancelled.
2024-09-05T21:40:08.734Z,1725572408.734 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2024-09-05T21:40:08.737Z,1725572408.737 [Onboard ThreadHandler](INFO): Thread cancelled.
2024-09-05T21:40:08.743Z,1725572408.743 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2024-09-05T21:40:08.749Z,1725572408.749 [DATMMP ThreadHandler](INFO): Thread cancelled.
2024-09-05T21:40:08.832Z,1725572408.832 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2024-09-05T21:40:08.838Z,1725572408.838 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2024-09-05T21:40:08.891Z,1725572408.891 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2024-09-05T21:40:08.968Z,1725572408.968 [logger ThreadHandler](INFO): Thread cancelled.