2023-12-20T17:41:33.821Z,1703094093.821 [Supervisor](DEBUG): Initializing supervisor. 2023-12-20T17:41:33.825Z,1703094093.825 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2023-12-20T17:41:33.826Z,1703094093.826 [SyncHandler](INFO): Protected caller Thread ID is 7083 2023-12-20T17:41:33.826Z,1703094093.826 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2023-12-20T17:41:33.827Z,1703094093.827 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2023-12-20T17:41:33.827Z,1703094093.827 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 7084 2023-12-20T17:41:33.831Z,1703094093.831 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2023-12-20T17:41:33.849Z,1703094093.849 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread. 2023-12-20T17:41:33.850Z,1703094093.850 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2023-12-20T17:41:33.850Z,1703094093.850 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 7085 2023-12-20T17:41:33.855Z,1703094093.855 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2023-12-20T17:41:33.856Z,1703094093.856 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2023-12-20T17:41:33.856Z,1703094093.856 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 7086 2023-12-20T17:41:33.858Z,1703094093.858 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2023-12-20T17:41:33.859Z,1703094093.859 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0 2023-12-20T17:41:33.859Z,1703094093.859 [logger ThreadHandler](INFO): Protected caller Thread ID is 7087 2023-12-20T17:41:33.863Z,1703094093.863 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2023-12-20T17:41:33.863Z,1703094093.863 [Supervisor](INFO): Looking for Config files in directory: Config/ 2023-12-20T17:41:33.865Z,1703094093.865 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2023-12-20T17:41:34.085Z,1703094094.085 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2023-12-20T17:41:34.086Z,1703094094.086 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2023-12-20T17:41:34.196Z,1703094094.196 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2023-12-20T17:41:34.197Z,1703094094.197 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2023-12-20T17:41:34.296Z,1703094094.296 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2023-12-20T17:41:34.297Z,1703094094.297 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2023-12-20T17:41:34.798Z,1703094094.798 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2023-12-20T17:41:34.798Z,1703094094.798 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2023-12-20T17:41:35.216Z,1703094095.216 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2023-12-20T17:41:35.217Z,1703094095.217 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2023-12-20T17:41:35.645Z,1703094095.645 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2023-12-20T17:41:35.646Z,1703094095.646 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2023-12-20T17:41:35.851Z,1703094095.851 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2023-12-20T17:41:35.851Z,1703094095.851 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2023-12-20T17:41:35.933Z,1703094095.933 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2023-12-20T17:41:36.017Z,1703094096.017 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2023-12-20T17:41:36.446Z,1703094096.446 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2023-12-20T17:41:36.447Z,1703094096.447 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2023-12-20T17:41:36.744Z,1703094096.744 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2023-12-20T17:41:36.745Z,1703094096.745 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2023-12-20T17:41:37.304Z,1703094097.304 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2023-12-20T17:41:37.304Z,1703094097.304 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2023-12-20T17:41:37.540Z,1703094097.540 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2023-12-20T17:41:37.540Z,1703094097.540 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg 2023-12-20T17:41:37.800Z,1703094097.800 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock 2023-12-20T17:41:37.801Z,1703094097.801 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2023-12-20T17:41:37.945Z,1703094097.945 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2023-12-20T17:41:37.946Z,1703094097.946 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2023-12-20T17:41:38.814Z,1703094098.814 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2023-12-20T17:41:38.816Z,1703094098.816 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-galene/ 2023-12-20T17:41:38.817Z,1703094098.817 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/secure.cfg 2023-12-20T17:41:38.904Z,1703094098.904 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/vehicle.cfg 2023-12-20T17:41:39.042Z,1703094099.042 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Battery.cfg 2023-12-20T17:41:39.316Z,1703094099.316 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2023-12-20T17:41:39.317Z,1703094099.317 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Science.cfg 2023-12-20T17:41:39.450Z,1703094099.450 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Control.cfg 2023-12-20T17:41:39.556Z,1703094099.556 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/logger.cfg 2023-12-20T17:41:39.654Z,1703094099.654 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Servo.cfg 2023-12-20T17:41:39.768Z,1703094099.768 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Navigation.cfg 2023-12-20T17:41:39.868Z,1703094099.868 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Simulator.cfg 2023-12-20T17:41:39.957Z,1703094099.957 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/BIT.cfg 2023-12-20T17:41:40.063Z,1703094100.063 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Sensor.cfg 2023-12-20T17:41:40.257Z,1703094100.257 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-galene/root/ 2023-12-20T17:41:40.257Z,1703094100.257 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2023-12-20T17:41:40.281Z,1703094100.281 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2023-12-20T17:41:40.343Z,1703094100.343 [DepthRateCalculator] Loaded 2023-12-20T17:41:40.343Z,1703094100.343 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2023-12-20T17:41:40.349Z,1703094100.349 [PitchRateCalculator] Loaded 2023-12-20T17:41:40.349Z,1703094100.349 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2023-12-20T17:41:40.359Z,1703094100.359 [SpeedCalculator] Loaded 2023-12-20T17:41:40.359Z,1703094100.359 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2023-12-20T17:41:40.364Z,1703094100.364 [YawRateCalculator] Loaded 2023-12-20T17:41:40.365Z,1703094100.365 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2023-12-20T17:41:40.416Z,1703094100.416 [ElevatorOffsetCalculator] Loaded 2023-12-20T17:41:40.416Z,1703094100.416 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2023-12-20T17:41:40.417Z,1703094100.417 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2023-12-20T17:41:40.417Z,1703094100.417 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2023-12-20T17:41:40.506Z,1703094100.506 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2023-12-20T17:41:40.507Z,1703094100.507 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2023-12-20T17:41:40.545Z,1703094100.545 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2023-12-20T17:41:40.546Z,1703094100.546 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2023-12-20T17:41:41.409Z,1703094101.409 [AHRS_M2] Loaded 2023-12-20T17:41:41.410Z,1703094101.410 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2023-12-20T17:41:41.445Z,1703094101.445 [BackseatComponent] Loaded 2023-12-20T17:41:41.445Z,1703094101.445 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread. 2023-12-20T17:41:41.447Z,1703094101.447 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 4084F4E0 2023-12-20T17:41:41.447Z,1703094101.447 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 7169 2023-12-20T17:41:41.450Z,1703094101.450 [LcmUniversalReporter] Loaded 2023-12-20T17:41:41.450Z,1703094101.450 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread. 2023-12-20T17:41:42.387Z,1703094102.387 [BPC1] Loaded 2023-12-20T17:41:42.388Z,1703094102.388 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2023-12-20T17:41:42.460Z,1703094102.460 [DataOverHttps] Loaded 2023-12-20T17:41:42.460Z,1703094102.460 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2023-12-20T17:41:42.461Z,1703094102.461 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4087F4E0 2023-12-20T17:41:42.461Z,1703094102.461 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 7170 2023-12-20T17:41:42.482Z,1703094102.482 [Depth_Keller] Loaded 2023-12-20T17:41:42.482Z,1703094102.482 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2023-12-20T17:41:42.487Z,1703094102.487 [DropWeight] Loaded 2023-12-20T17:41:42.487Z,1703094102.487 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2023-12-20T17:41:42.550Z,1703094102.550 [NAL9602] Loaded 2023-12-20T17:41:42.550Z,1703094102.550 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2023-12-20T17:41:42.580Z,1703094102.580 [Onboard] Loaded 2023-12-20T17:41:42.581Z,1703094102.581 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread. 2023-12-20T17:41:42.582Z,1703094102.582 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 408AF4E0 2023-12-20T17:41:42.582Z,1703094102.582 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 7171 2023-12-20T17:41:42.588Z,1703094102.588 [PowerOnly](INFO): Adding load control power supply at /dev/loadC3 2023-12-20T17:41:42.599Z,1703094102.599 [PowerOnly] Loaded 2023-12-20T17:41:42.600Z,1703094102.600 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread. 2023-12-20T17:41:42.611Z,1703094102.611 [Power24vConverter] Loaded 2023-12-20T17:41:42.612Z,1703094102.612 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread. 2023-12-20T17:41:42.626Z,1703094102.626 [Radio_Surface] Loaded 2023-12-20T17:41:42.626Z,1703094102.626 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2023-12-20T17:41:42.627Z,1703094102.627 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408DF4E0 2023-12-20T17:41:42.628Z,1703094102.628 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 7172 2023-12-20T17:41:42.717Z,1703094102.717 [DAT] Loaded 2023-12-20T17:41:42.718Z,1703094102.718 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread. 2023-12-20T17:41:42.719Z,1703094102.719 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 4090F4E0 2023-12-20T17:41:42.719Z,1703094102.719 [DAT ThreadHandler](INFO): Protected caller Thread ID is 7173 2023-12-20T17:41:42.720Z,1703094102.720 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2023-12-20T17:41:42.720Z,1703094102.720 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2023-12-20T17:41:42.844Z,1703094102.844 [DeadReckonUsingMultipleVelocitySources] Loaded 2023-12-20T17:41:42.844Z,1703094102.844 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2023-12-20T17:41:42.885Z,1703094102.885 [DeadReckonUsingSpeedCalculator] Loaded 2023-12-20T17:41:42.885Z,1703094102.885 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread. 2023-12-20T17:41:42.899Z,1703094102.899 [NavChart] Loaded 2023-12-20T17:41:42.899Z,1703094102.899 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2023-12-20T17:41:42.905Z,1703094102.905 [UniversalFixResidualReporter] Loaded 2023-12-20T17:41:42.905Z,1703094102.905 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2023-12-20T17:41:42.906Z,1703094102.906 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2023-12-20T17:41:42.906Z,1703094102.906 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2023-12-20T17:41:43.053Z,1703094103.053 [SBIT](DEBUG): Construct Startup Built In Test. 2023-12-20T17:41:43.067Z,1703094103.067 [SBIT] Loaded 2023-12-20T17:41:43.067Z,1703094103.067 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2023-12-20T17:41:43.070Z,1703094103.070 [IBIT](DEBUG): Construct Initiated Built In Test. 2023-12-20T17:41:43.083Z,1703094103.083 [IBIT] Loaded 2023-12-20T17:41:43.083Z,1703094103.083 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2023-12-20T17:41:43.089Z,1703094103.089 [CBIT](DEBUG): Construct Continuous Built In Test. 2023-12-20T17:41:43.191Z,1703094103.191 [CBIT] Loaded 2023-12-20T17:41:43.191Z,1703094103.191 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2023-12-20T17:41:43.192Z,1703094103.192 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2023-12-20T17:41:43.192Z,1703094103.192 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2023-12-20T17:41:43.368Z,1703094103.368 [CTD_Seabird] Loaded 2023-12-20T17:41:43.369Z,1703094103.369 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2023-12-20T17:41:43.370Z,1703094103.370 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40A164E0 2023-12-20T17:41:43.370Z,1703094103.370 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 7174 2023-12-20T17:41:43.391Z,1703094103.391 [PAR_Licor] Loaded 2023-12-20T17:41:43.391Z,1703094103.391 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2023-12-20T17:41:43.431Z,1703094103.431 [WetLabsBB2FL] Loaded 2023-12-20T17:41:43.432Z,1703094103.432 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2023-12-20T17:41:43.433Z,1703094103.433 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40A464E0 2023-12-20T17:41:43.433Z,1703094103.433 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 7175 2023-12-20T17:41:43.434Z,1703094103.434 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2023-12-20T17:41:43.434Z,1703094103.434 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2023-12-20T17:41:43.572Z,1703094103.572 [BuoyancyServo] Loaded 2023-12-20T17:41:43.572Z,1703094103.572 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2023-12-20T17:41:43.593Z,1703094103.593 [ElevatorServo] Loaded 2023-12-20T17:41:43.594Z,1703094103.594 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2023-12-20T17:41:43.614Z,1703094103.614 [MassServo] Loaded 2023-12-20T17:41:43.615Z,1703094103.615 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2023-12-20T17:41:43.635Z,1703094103.635 [RudderServo] Loaded 2023-12-20T17:41:43.635Z,1703094103.635 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2023-12-20T17:41:43.651Z,1703094103.651 [ThrusterHE] Loaded 2023-12-20T17:41:43.651Z,1703094103.651 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread. 2023-12-20T17:41:43.652Z,1703094103.652 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2023-12-20T17:41:43.652Z,1703094103.652 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2023-12-20T17:41:43.705Z,1703094103.705 [VerticalControl](DEBUG): Construct VerticalControl. 2023-12-20T17:41:43.755Z,1703094103.755 [VerticalControl] Loaded 2023-12-20T17:41:43.755Z,1703094103.755 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2023-12-20T17:41:43.758Z,1703094103.758 [HorizontalControl](DEBUG): Construct HorizontalControl. 2023-12-20T17:41:43.795Z,1703094103.795 [HorizontalControl] Loaded 2023-12-20T17:41:43.795Z,1703094103.795 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2023-12-20T17:41:43.797Z,1703094103.797 [SpeedControl](DEBUG): Construct SpeedControl. 2023-12-20T17:41:43.799Z,1703094103.799 [SpeedControl] Loaded 2023-12-20T17:41:43.799Z,1703094103.799 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2023-12-20T17:41:43.802Z,1703094103.802 [LoopControl](DEBUG): Construct LoopControl. 2023-12-20T17:41:43.803Z,1703094103.803 [LoopControl] Loaded 2023-12-20T17:41:43.803Z,1703094103.803 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2023-12-20T17:41:43.803Z,1703094103.803 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2023-12-20T17:41:43.804Z,1703094103.804 [Module Loader](DEBUG): Loading Module at Modules/Dock.so 2023-12-20T17:41:43.922Z,1703094103.922 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking) 2023-12-20T17:41:43.922Z,1703094103.922 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2023-12-20T17:41:44.075Z,1703094104.075 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2023-12-20T17:41:44.075Z,1703094104.075 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2023-12-20T17:41:44.431Z,1703094104.431 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2023-12-20T17:41:44.432Z,1703094104.432 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2023-12-20T17:41:44.492Z,1703094104.492 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2023-12-20T17:41:44.498Z,1703094104.498 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2023-12-20T17:41:44.501Z,1703094104.501 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2023-12-20T17:41:44.512Z,1703094104.512 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2023-12-20T17:41:44.513Z,1703094104.513 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C104E0 2023-12-20T17:41:44.513Z,1703094104.513 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 7176 2023-12-20T17:41:44.518Z,1703094104.518 [Supervisor](INFO): Main Thread ID is 6715 2023-12-20T17:41:44.518Z,1703094104.518 [Supervisor](DEBUG): Running supervisor. 2023-12-20T17:41:44.519Z,1703094104.519 [CommandExec ThreadHandler](INFO): Handler Thread ID is 7177 2023-12-20T17:41:44.519Z,1703094104.519 [CommandExec](INFO): Initializing the command executive. 2023-12-20T17:41:44.521Z,1703094104.521 [CommandLine ThreadHandler](INFO): Handler Thread ID is 7178 2023-12-20T17:41:44.524Z,1703094104.524 [controlThread ThreadHandler](INFO): Handler Thread ID is 7179 2023-12-20T17:41:44.524Z,1703094104.524 [controlThread](DEBUG): Initializing ControlThread 2023-12-20T17:41:44.525Z,1703094104.525 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2023-12-20T17:41:44.526Z,1703094104.526 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2023-12-20T17:41:44.526Z,1703094104.526 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2023-12-20T17:41:44.526Z,1703094104.526 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2023-12-20T17:41:44.527Z,1703094104.527 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2023-12-20T17:41:44.534Z,1703094104.534 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2023-12-20T17:41:44.535Z,1703094104.535 [NavChart](DEBUG): Initialize NavChart Navigation. 2023-12-20T17:41:44.535Z,1703094104.535 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2023-12-20T17:41:44.535Z,1703094104.535 [SBIT](INFO): Initialize SBIT Component. 2023-12-20T17:41:44.536Z,1703094104.536 [SBIT](IMPORTANT): git: 2023-12-14 2023-12-20T17:41:44.536Z,1703094104.536 [SBIT](INFO): git hash: 83eaf5b798064236ed38181756e01e1e1e718f00 2023-12-20T17:41:44.536Z,1703094104.536 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2023-12-20T17:41:44.538Z,1703094104.538 [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 2023-12-20T17:41:44.539Z,1703094104.539 [SBIT](INFO): Beginning SBIT in 47.000000 seconds. 2023-12-20T17:41:44.539Z,1703094104.539 [IBIT](INFO): Initialize IBIT Component. 2023-12-20T17:41:44.540Z,1703094104.540 [CBIT](DEBUG): Initialize CBIT Component. 2023-12-20T17:41:44.541Z,1703094104.541 [logger ThreadHandler](INFO): Handler Thread ID is 7180 2023-12-20T17:41:44.552Z,1703094104.552 [CBIT](DEBUG): Initialized mux pins. 2023-12-20T17:41:44.552Z,1703094104.552 [CBIT](DEBUG): Initializing the watchdog timer. 2023-12-20T17:41:44.560Z,1703094104.560 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 7181 2023-12-20T17:41:44.572Z,1703094104.572 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 7182 2023-12-20T17:41:44.574Z,1703094104.574 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2023-12-20T17:41:44.576Z,1703094104.576 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2023-12-20T17:41:44.576Z,1703094104.576 [CBIT](DEBUG): Initializing heartbeat. 2023-12-20T17:41:44.584Z,1703094104.584 [Onboard ThreadHandler](INFO): Handler Thread ID is 7183 2023-12-20T17:41:44.601Z,1703094104.601 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 7184 2023-12-20T17:41:44.620Z,1703094104.620 [DAT ThreadHandler](INFO): Handler Thread ID is 7185 2023-12-20T17:41:44.621Z,1703094104.621 [DAT](INFO): Powering up 2023-12-20T17:41:44.621Z,1703094104.621 [DAT](DEBUG): Initializing DAT. 2023-12-20T17:41:44.625Z,1703094104.625 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 7187 2023-12-20T17:41:44.626Z,1703094104.626 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2023-12-20T17:41:44.633Z,1703094104.633 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 7189 2023-12-20T17:41:44.637Z,1703094104.637 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 7191 2023-12-20T17:41:44.639Z,1703094104.639 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2023-12-20T17:41:44.639Z,1703094104.639 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2023-12-20T17:41:44.639Z,1703094104.639 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2023-12-20T17:41:44.639Z,1703094104.639 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2023-12-20T17:41:44.640Z,1703094104.640 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2023-12-20T17:41:44.640Z,1703094104.640 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2023-12-20T17:41:44.640Z,1703094104.640 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2023-12-20T17:41:44.640Z,1703094104.640 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2023-12-20T17:41:44.643Z,1703094104.643 [WetLabsBB2FL](INFO): Powering up 2023-12-20T17:41:44.648Z,1703094104.648 [CBIT](DEBUG): Deactivating GF circuits. 2023-12-20T17:41:44.648Z,1703094104.648 [CBIT](DEBUG): Deactivating emergency mode. 2023-12-20T17:41:44.688Z,1703094104.688 [CBIT](DEBUG): Backplane powered. 2023-12-20T17:41:44.693Z,1703094104.693 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2023-12-20T17:41:44.695Z,1703094104.695 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2023-12-20T17:41:44.696Z,1703094104.696 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2023-12-20T17:41:44.696Z,1703094104.696 [LoopControl](DEBUG): Initialize LoopControlComponent. 2023-12-20T17:41:44.697Z,1703094104.697 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml 2023-12-20T17:41:44.710Z,1703094104.710 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2023-12-20T17:41:44.734Z,1703094104.734 [MissionManager](DEBUG): 2023-12-20T17:41:44.734Z,1703094104.734 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml 2023-12-20T17:41:44.803Z,1703094104.803 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2023-12-20T17:41:44.816Z,1703094104.816 [Default:A.Wait](DEBUG): Construct Wait. 2023-12-20T17:41:44.819Z,1703094104.819 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2023-12-20T17:41:44.830Z,1703094104.830 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2023-12-20T17:41:44.845Z,1703094104.845 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2023-12-20T17:41:44.850Z,1703094104.850 [Default:E.Execute](DEBUG): Construct Execute. 2023-12-20T17:41:44.854Z,1703094104.854 [MissionManager](DEBUG): 0 Wait a moment to see if the scheduler starts a new mission before starting to actually run Default. 13 Burn on Dropped weight due to communications timeout. 5 Default mission has been running for Restarting logs and Default mission. restart logs 2023-12-20T17:41:44.877Z,1703094104.877 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,PowerOnly,Power24vConverter,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter, 2023-12-20T17:41:44.894Z,1703094104.894 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2023-12-20T17:41:44.949Z,1703094104.949 [Depth_Keller](ERROR): Pressure or depth reading out of range: 1629.131348 decibar, 0.000000 m 2023-12-20T17:41:44.950Z,1703094104.950 [PowerOnly](INFO): Powering up loadControl 2023-12-20T17:41:44.969Z,1703094104.969 [Power24vConverter](INFO): Powering up. 2023-12-20T17:41:44.978Z,1703094104.978 [DepthRateCalculator](ERROR): Depth measurement is not active 2023-12-20T17:41:45.006Z,1703094105.006 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2023-12-20T17:41:45.008Z,1703094105.008 [Radio_Surface](INFO): Powering up 2023-12-20T17:41:45.012Z,1703094105.012 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2023-12-20T17:41:45.013Z,1703094105.013 [ElevatorServo](DEBUG): Initializing EZServoServo. 2023-12-20T17:41:45.020Z,1703094105.020 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2023-12-20T17:41:45.021Z,1703094105.021 [MassServo](DEBUG): Initializing EZServoServo. 2023-12-20T17:41:45.028Z,1703094105.028 [MassServo](DEBUG): Initializing MassServo. 2023-12-20T17:41:45.029Z,1703094105.029 [RudderServo](DEBUG): Initializing EZServoServo. 2023-12-20T17:41:45.036Z,1703094105.036 [RudderServo](DEBUG): Initializing RudderServo. 2023-12-20T17:41:45.037Z,1703094105.037 [ThrusterHE](DEBUG): Initializing EZServoServo. 2023-12-20T17:41:45.044Z,1703094105.044 [ThrusterHE](DEBUG): Initializing ThrusterHE. 2023-12-20T17:41:47.248Z,1703094107.248 [WetLabsBB2FL](INFO): Powering down 2023-12-20T17:41:50.773Z,1703094110.773 [ThrusterHE](ERROR): Zero Speed Commanded. 2023-12-20T17:41:51.656Z,1703094111.656 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit. 2023-12-20T17:41:56.968Z,1703094116.968 [DAT](INFO): DAT read: 2023-12-20T17:41:56.970Z,1703094116.970 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series 2023-12-20T17:41:58.733Z,1703094118.733 [DAT](INFO): DAT read: MF Frequency Band 2023-12-20T17:41:58.734Z,1703094118.734 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0 2023-12-20T17:41:58.734Z,1703094118.734 [DAT](INFO): DAT read: Dec 20 2023 17:41:52 2023-12-20T17:41:59.749Z,1703094119.749 [DAT](INFO): DAT read: Features enabled [Bearing] 2023-12-20T17:41:59.750Z,1703094119.750 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP 2023-12-20T17:41:59.750Z,1703094119.750 [DAT](INFO): commRate: 800 2023-12-20T17:42:01.816Z,1703094121.816 [DAT](INFO): entering command mode 2023-12-20T17:42:02.016Z,1703094122.016 [DAT](INFO): DAT read: 2023-12-20T17:42:02.017Z,1703094122.017 [DAT](INFO): DAT read: user:1> 2023-12-20T17:42:02.017Z,1703094122.017 [DAT](INFO): setting verbose to 3 2023-12-20T17:42:02.268Z,1703094122.268 [DAT](INFO): DAT read: user:1> 2023-12-20T17:42:02.269Z,1703094122.269 [DAT](INFO): DAT read: Verbose | 3 2023-12-20T17:42:02.270Z,1703094122.270 [DAT](INFO): set verbose to 3 2023-12-20T17:42:02.270Z,1703094122.270 [DAT](INFO): setting DatVerbose to 27440 2023-12-20T17:42:02.520Z,1703094122.520 [DAT](INFO): DAT read: user:2> 2023-12-20T17:42:02.521Z,1703094122.521 [DAT](INFO): DAT read: DatVerbose | 27440 2023-12-20T17:42:02.522Z,1703094122.522 [DAT](INFO): set DatVerbose to 27440 2023-12-20T17:42:02.522Z,1703094122.522 [DAT](INFO): setting transmit power to 8 2023-12-20T17:42:02.773Z,1703094122.773 [DAT](INFO): DAT read: user:3> 2023-12-20T17:42:02.773Z,1703094122.773 [DAT](INFO): DAT read: TxPower | 8 (Max) 2023-12-20T17:42:02.774Z,1703094122.774 [DAT](INFO): set transmit power to 8 2023-12-20T17:42:02.774Z,1703094122.774 [DAT](INFO): setting local address to 9 2023-12-20T17:42:03.024Z,1703094123.024 [DAT](INFO): DAT read: user:4> 2023-12-20T17:42:03.025Z,1703094123.025 [DAT](INFO): DAT read: LocalAddr | 9 2023-12-20T17:42:03.026Z,1703094123.026 [DAT](INFO): set local address to 9 2023-12-20T17:42:03.027Z,1703094123.027 [DAT](INFO): Setting time to: 17:42:3 And date to:12/20/2023 2023-12-20T17:42:03.277Z,1703094123.277 [DAT](INFO): DAT read: user:5> 2023-12-20T17:42:03.278Z,1703094123.278 [DAT](INFO): DAT read: Wed Dec 20, 2023 17:42:03 2023-12-20T17:42:03.278Z,1703094123.278 [DAT](INFO): Local DAT time set to Wed Dec 20, 2023 17:42:03 2023-12-20T17:42:12.785Z,1703094132.785 [NAL9602](INFO): Powering up NAL9602 2023-12-20T17:42:23.697Z,1703094143.697 [NAL9602](INFO): NAL9602 initialized 2023-12-20T17:42:32.212Z,1703094152.212 [SBIT](IMPORTANT): Beginning Startup BIT 2023-12-20T17:42:32.216Z,1703094152.216 [CBIT](IMPORTANT): Beginning ground fault scan 2023-12-20T17:42:43.177Z,1703094163.177 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.005934 CHAN A1 (24V): 0.000583 CHAN A2 (12V): -0.005544 CHAN A3 (5V): -0.002313 CHAN B0 (3.3V): -0.000713 CHAN B1 (3.15aV): -0.001402 CHAN B2 (3.15bV): -0.001682 CHAN B3 (GND): -0.000079 OPEN: 0.004688 Full Scale: +/- 1 mA 2023-12-20T17:43:25.925Z,1703094205.925 [SBIT](IMPORTANT): SBIT PASSED 2023-12-20T17:43:25.925Z,1703094205.925 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2023-12-20T17:43:25.926Z,1703094205.926 [SBIT](IMPORTANT): CBIT.gfScanTimeout=1 hour; 2023-12-20T17:43:25.926Z,1703094205.926 [SBIT](IMPORTANT): ESPComponent.sampleTimeout=2 minute; 2023-12-20T17:43:25.927Z,1703094205.927 [SBIT](IMPORTANT): Express none CTD_Seabird.bin_median_sea_water_salinity; 2023-12-20T17:43:25.927Z,1703094205.927 [SBIT](IMPORTANT): Express none CTD_Seabird.bin_median_sea_water_temperature; 2023-12-20T17:43:25.927Z,1703094205.927 [SBIT](IMPORTANT): Express none WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water; 2023-12-20T17:43:25.927Z,1703094205.927 [SBIT](IMPORTANT): Express none WetLabsBB2FL.bin_median_mass_concentration_of_chlorophyll_in_sea_water; 2023-12-20T17:43:25.927Z,1703094205.927 [SBIT](IMPORTANT): Express none _.ayeris_disk_space 100.000000 gigabyte; 2023-12-20T17:43:25.927Z,1703094205.927 [SBIT](IMPORTANT): Express none _.ayeris_particle_counts 300.000000 count_per_second; 2023-12-20T17:43:25.927Z,1703094205.927 [SBIT](IMPORTANT): Express none _.ayeris_particle_shape; 2023-12-20T17:43:25.927Z,1703094205.927 [SBIT](IMPORTANT): Express none _.ayeris_particle_slope; 2023-12-20T17:43:25.928Z,1703094205.928 [SBIT](IMPORTANT): Express linearApproximation depth 5.000000 meter; 2023-12-20T17:43:25.928Z,1703094205.928 [SBIT](IMPORTANT): Express linearApproximation latitude 0.005000 degree; 2023-12-20T17:43:25.928Z,1703094205.928 [SBIT](IMPORTANT): Express linearApproximation longitude 0.005000 degree; 2023-12-20T17:43:25.928Z,1703094205.928 [SBIT](IMPORTANT): PowerOnly.loadAtStartup=1 bool; 2023-12-20T17:43:25.928Z,1703094205.928 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=200.005958 cubic_centimeter; 2023-12-20T17:43:25.928Z,1703094205.928 [SBIT](IMPORTANT): VerticalControl.massDefault=6.920555 millimeter; 2023-12-20T17:43:26.335Z,1703094206.335 [MissionManager](IMPORTANT): Started mission Startup 2023-12-20T17:43:26.335Z,1703094206.335 [Startup] Running Loop=1 2023-12-20T17:43:26.335Z,1703094206.335 [Startup](DEBUG): Aggregate::initialize Startup 2023-12-20T17:43:26.336Z,1703094206.336 [Startup:A.GoToSurface] Running Loop=1 2023-12-20T17:43:26.336Z,1703094206.336 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2023-12-20T17:43:26.336Z,1703094206.336 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2023-12-20T17:43:26.337Z,1703094206.337 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2023-12-20T17:43:26.337Z,1703094206.337 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2023-12-20T17:43:26.337Z,1703094206.337 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2023-12-20T17:43:26.338Z,1703094206.338 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2023-12-20T17:43:26.339Z,1703094206.339 [Startup:StartupSatComms] Running Loop=1 2023-12-20T17:43:26.339Z,1703094206.339 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2023-12-20T17:43:26.339Z,1703094206.339 [Startup:StartupSatComms:A] Running Loop=1 2023-12-20T17:43:26.727Z,1703094206.727 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2023-12-20T17:44:26.603Z,1703094266.603 [Startup:StartupSatComms:A](INFO): Timed out from 2023-12-20T17:43:26.3Z 2023-12-20T17:44:26.603Z,1703094266.603 [Startup:StartupSatComms:A] Stopped 2023-12-20T17:44:26.603Z,1703094266.603 [Startup:StartupSatComms:B] Running Loop=1 2023-12-20T17:44:26.959Z,1703094266.959 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2023-12-20T17:44:44.698Z,1703094284.698 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2023-12-20T17:44:44.698Z,1703094284.698 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2023-12-20T17:44:44.699Z,1703094284.699 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1 2023-12-20T17:44:44.699Z,1703094284.699 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2023-12-20T17:44:44.711Z,1703094284.711 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2023-12-20T17:44:44.711Z,1703094284.711 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2023-12-20T17:44:45.121Z,1703094285.121 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2023-12-20T17:44:45.121Z,1703094285.121 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2023-12-20T17:44:45.121Z,1703094285.121 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2023-12-20T17:44:45.122Z,1703094285.122 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1 2023-12-20T17:44:45.504Z,1703094285.504 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2023-12-20T17:45:07.686Z,1703094307.686 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004547 2023-12-20T17:45:12.612Z,1703094312.612 [CommandExec](IMPORTANT): got command failComponent 2023-12-20T17:45:12.613Z,1703094312.613 [CommandExec](IMPORTANT): Failed components: 2023-12-20T17:45:12.613Z,1703094312.613 [CommandExec](IMPORTANT): No failed Components. 2023-12-20T17:45:15.036Z,1703094315.036 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20231220T165823/Courier0016.lzma 2023-12-20T17:45:16.038Z,1703094316.038 [DataOverHttps](INFO): Moved sent file to Logs/20231220T165823/Courier0016.lzma.bak 2023-12-20T17:45:16.038Z,1703094316.038 [DataOverHttps](INFO): SBD MOMSN=19124042 2023-12-20T17:45:26.714Z,1703094326.714 [Startup:StartupSatComms:B](INFO): Timed out from 2023-12-20T17:44:26.6Z 2023-12-20T17:45:26.714Z,1703094326.714 [Startup:StartupSatComms:B] Stopped 2023-12-20T17:45:26.714Z,1703094326.714 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2023-12-20T17:45:26.714Z,1703094326.714 [Startup:StartupSatComms] Stopped 2023-12-20T17:45:26.715Z,1703094326.715 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2023-12-20T17:45:26.715Z,1703094326.715 [Startup](INFO): Completed Startup 2023-12-20T17:45:26.716Z,1703094326.716 [MissionManager](INFO): Startup is completed. 2023-12-20T17:45:26.716Z,1703094326.716 [MissionManager](INFO): Uninitializing Mission Startup 2023-12-20T17:45:26.716Z,1703094326.716 [Startup] Stopped 2023-12-20T17:45:26.716Z,1703094326.716 [Startup](DEBUG): Aggregate::uninitialize Startup 2023-12-20T17:45:26.716Z,1703094326.716 [Startup:A.GoToSurface] Stopped 2023-12-20T17:45:26.716Z,1703094326.716 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2023-12-20T17:45:27.122Z,1703094327.122 [MissionManager](IMPORTANT): Started mission Default 2023-12-20T17:45:27.123Z,1703094327.123 [Default] Running Loop=1 2023-12-20T17:45:27.123Z,1703094327.123 [Default](DEBUG): Aggregate::initialize Default 2023-12-20T17:45:27.123Z,1703094327.123 [Default:B.GoToSurface] Running Loop=1 2023-12-20T17:45:27.123Z,1703094327.123 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2023-12-20T17:45:27.123Z,1703094327.123 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2023-12-20T17:45:27.124Z,1703094327.124 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2023-12-20T17:45:27.124Z,1703094327.124 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2023-12-20T17:45:27.124Z,1703094327.124 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2023-12-20T17:45:27.125Z,1703094327.125 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2023-12-20T17:45:27.125Z,1703094327.125 [Default:A.Wait] Running Loop=1 2023-12-20T17:45:27.125Z,1703094327.125 [Default:A.Wait](DEBUG): Initialize Wait Component. 2023-12-20T17:45:30.957Z,1703094330.957 [CommandExec](IMPORTANT): got command strobe off 2023-12-20T17:45:30.957Z,1703094330.957 [CommandExec](IMPORTANT): Deactivating strobe 2023-12-20T17:45:32.236Z,1703094332.236 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20231220T174133/Courier0000.lzma 2023-12-20T17:45:33.238Z,1703094333.238 [DataOverHttps](INFO): Moved sent file to Logs/20231220T174133/Courier0000.lzma.bak 2023-12-20T17:45:33.238Z,1703094333.238 [DataOverHttps](INFO): SBD MOMSN=19124044 2023-12-20T17:45:40.451Z,1703094340.451 [Default:A.Wait](INFO): Done Waiting. 2023-12-20T17:45:40.451Z,1703094340.451 [Default:A.Wait] Stopped 2023-12-20T17:45:40.451Z,1703094340.451 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2023-12-20T17:45:40.864Z,1703094340.864 [Default:CheckIn] Running Loop=1 2023-12-20T17:45:40.864Z,1703094340.864 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-12-20T17:45:40.864Z,1703094340.864 [Default:CheckIn:Read_GPS] Running Loop=1 2023-12-20T17:45:41.255Z,1703094341.255 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2023-12-20T17:47:27.097Z,1703094447.097 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2023-12-20T17:47:45.717Z,1703094465.717 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2 2023-12-20T17:47:45.717Z,1703094465.717 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2023-12-20T17:47:45.718Z,1703094465.718 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 2 2023-12-20T17:47:45.718Z,1703094465.718 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2023-12-20T17:47:45.729Z,1703094465.729 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2023-12-20T17:47:45.729Z,1703094465.729 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2023-12-20T17:47:46.131Z,1703094466.131 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2023-12-20T17:47:46.131Z,1703094466.131 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2 2023-12-20T17:47:46.132Z,1703094466.132 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2023-12-20T17:47:46.132Z,1703094466.132 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 2 2023-12-20T17:47:46.531Z,1703094466.531 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2023-12-20T17:49:10.132Z,1703094550.132 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2023-12-20T17:49:10.135Z,1703094550.135 [BPC1](INFO): Received data from all battery sticks. 2023-12-20T17:50:41.025Z,1703094641.025 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-12-20T17:45:40.9Z 2023-12-20T17:50:41.025Z,1703094641.025 [Default:CheckIn:Read_GPS] Stopped 2023-12-20T17:50:41.025Z,1703094641.025 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-12-20T17:50:41.438Z,1703094641.438 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2023-12-20T17:50:46.701Z,1703094646.701 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3 2023-12-20T17:50:46.701Z,1703094646.701 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2023-12-20T17:50:46.702Z,1703094646.702 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 3 2023-12-20T17:50:46.702Z,1703094646.702 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2023-12-20T17:50:46.749Z,1703094646.749 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2023-12-20T17:50:46.750Z,1703094646.750 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2023-12-20T17:50:47.125Z,1703094647.125 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2023-12-20T17:50:47.125Z,1703094647.125 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3 2023-12-20T17:50:47.126Z,1703094647.126 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2023-12-20T17:50:47.126Z,1703094647.126 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 3 2023-12-20T17:50:47.497Z,1703094647.497 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2023-12-20T17:50:48.448Z,1703094648.448 [DataOverHttps](INFO): Sending 168 bytes from file Logs/20231220T174133/Courier0004.lzma 2023-12-20T17:50:49.449Z,1703094649.449 [DataOverHttps](INFO): Moved sent file to Logs/20231220T174133/Courier0004.lzma.bak 2023-12-20T17:50:49.450Z,1703094649.450 [DataOverHttps](INFO): SBD MOMSN=19124047 2023-12-20T17:51:05.036Z,1703094665.036 [DataOverHttps](INFO): Sending 203 bytes from file Logs/20231220T165823/Express0017.lzma 2023-12-20T17:51:06.038Z,1703094666.038 [DataOverHttps](INFO): Moved sent file to Logs/20231220T165823/Express0017.lzma.bak 2023-12-20T17:51:06.038Z,1703094666.038 [DataOverHttps](INFO): SBD MOMSN=19124049 2023-12-20T17:51:21.723Z,1703094681.723 [DataOverHttps](INFO): Sending 946 bytes from file Logs/20231220T174133/Express0001.lzma 2023-12-20T17:51:22.726Z,1703094682.726 [DataOverHttps](INFO): Moved sent file to Logs/20231220T174133/Express0001.lzma.bak 2023-12-20T17:51:22.726Z,1703094682.726 [DataOverHttps](INFO): SBD MOMSN=19124055 2023-12-20T17:51:38.304Z,1703094698.304 [DataOverHttps](INFO): Sending 277 bytes from file Logs/20231220T174133/Express0005.lzma 2023-12-20T17:51:39.306Z,1703094699.306 [DataOverHttps](INFO): Moved sent file to Logs/20231220T174133/Express0005.lzma.bak 2023-12-20T17:51:39.306Z,1703094699.306 [DataOverHttps](INFO): SBD MOMSN=19124082 2023-12-20T17:51:40.439Z,1703094700.439 [Default:CheckIn:Read_Iridium] Stopped 2023-12-20T17:51:40.439Z,1703094700.439 [Default:CheckIn:C.Wait] Running Loop=1 2023-12-20T17:51:40.439Z,1703094700.439 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-12-20T17:52:26.465Z,1703094746.465 [NAL9602](FAULT): GPS failed to acquire within timeout. 2023-12-20T17:52:26.465Z,1703094746.465 [NAL9602] Data Fault, FailCount= 1 2023-12-20T17:52:26.465Z,1703094746.465 [NAL9602](ERROR): Data Fault 2023-12-20T17:52:26.504Z,1703094746.504 [CBIT](ERROR): Data Fault in component: NAL9602 2023-12-20T17:52:26.869Z,1703094746.869 [NAL9602](INFO): Powering down 2023-12-20T17:52:27.707Z,1703094747.707 [CBIT](INFO): Clearing failed state for component NAL9602 2023-12-20T17:52:27.707Z,1703094747.707 [NAL9602] No Fault, FailCount= 1 2023-12-20T17:52:57.165Z,1703094777.165 [NAL9602](INFO): Powering up NAL9602 2023-12-20T17:53:08.081Z,1703094788.081 [NAL9602](INFO): NAL9602 initialized 2023-12-20T17:53:47.682Z,1703094827.682 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4 2023-12-20T17:53:47.682Z,1703094827.682 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2023-12-20T17:53:47.683Z,1703094827.683 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 4 2023-12-20T17:53:47.683Z,1703094827.683 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2023-12-20T17:53:47.694Z,1703094827.694 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2023-12-20T17:53:47.694Z,1703094827.694 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2023-12-20T17:53:48.108Z,1703094828.108 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2023-12-20T17:53:48.108Z,1703094828.108 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4 2023-12-20T17:53:48.109Z,1703094828.109 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2023-12-20T17:53:48.109Z,1703094828.109 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 4 2023-12-20T17:53:48.485Z,1703094828.485 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2023-12-20T17:56:41.014Z,1703095001.014 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-12-20T17:56:41.015Z,1703095001.015 [Default:CheckIn:C.Wait] Stopped 2023-12-20T17:56:41.015Z,1703095001.015 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-12-20T17:56:41.015Z,1703095001.015 [Default:CheckIn:D] Running Loop=1 2023-12-20T17:56:41.419Z,1703095001.419 [Default:CheckIn:D] Stopped 2023-12-20T17:56:41.419Z,1703095001.419 [Default:CheckIn:E] Running Loop=1 2023-12-20T17:56:41.813Z,1703095001.813 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 11.238269 min 2023-12-20T17:56:41.813Z,1703095001.813 [Default:CheckIn:E] Stopped 2023-12-20T17:56:41.813Z,1703095001.813 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-12-20T17:56:41.813Z,1703095001.813 [Default:CheckIn] Stopped 2023-12-20T17:56:41.813Z,1703095001.813 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-12-20T17:56:41.814Z,1703095001.814 [Default:CheckIn](INFO): Running loop #2 2023-12-20T17:56:41.814Z,1703095001.814 [Default:CheckIn] Running Loop=2 2023-12-20T17:56:41.814Z,1703095001.814 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-12-20T17:56:41.814Z,1703095001.814 [Default:CheckIn:Read_GPS] Running Loop=1 2023-12-20T17:56:48.680Z,1703095008.680 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5 2023-12-20T17:56:48.680Z,1703095008.680 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2023-12-20T17:56:48.681Z,1703095008.681 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 5 2023-12-20T17:56:48.681Z,1703095008.681 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2023-12-20T17:56:48.704Z,1703095008.704 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2023-12-20T17:56:48.705Z,1703095008.705 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2023-12-20T17:56:49.082Z,1703095009.082 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2023-12-20T17:56:49.082Z,1703095009.082 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5 2023-12-20T17:56:49.083Z,1703095009.083 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2023-12-20T17:56:49.083Z,1703095009.083 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 5 2023-12-20T17:56:49.493Z,1703095009.493 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2023-12-20T17:57:02.011Z,1703095022.011 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175701.00,A,3648.13373,N,12147.20759,W,0.078,270.19,201223,,,A*7F 2023-12-20T17:57:02.014Z,1703095022.014 [NAL9602](INFO): GPS fix at 20231220T175701: (36.802229, -121.786793) 2023-12-20T17:57:02.043Z,1703095022.043 [Default:CheckIn:Read_GPS] Stopped 2023-12-20T17:57:02.043Z,1703095022.043 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-12-20T17:57:05.880Z,1703095025.880 [DataOverHttps](INFO): Sending 225 bytes from file Logs/20231220T174133/Courier0007.lzma 2023-12-20T17:57:06.881Z,1703095026.881 [DataOverHttps](INFO): Moved sent file to Logs/20231220T174133/Courier0007.lzma.bak 2023-12-20T17:57:06.882Z,1703095026.882 [DataOverHttps](INFO): SBD MOMSN=19124096 2023-12-20T17:57:22.759Z,1703095042.759 [DataOverHttps](INFO): Sending 308 bytes from file Logs/20231220T174133/Express0008.lzma 2023-12-20T17:57:23.758Z,1703095043.758 [DataOverHttps](INFO): Moved sent file to Logs/20231220T174133/Express0008.lzma.bak 2023-12-20T17:57:23.758Z,1703095043.758 [DataOverHttps](INFO): SBD MOMSN=19124099 2023-12-20T17:57:25.158Z,1703095045.158 [Default:CheckIn:Read_Iridium] Stopped 2023-12-20T17:57:25.158Z,1703095045.158 [Default:CheckIn:C.Wait] Running Loop=1 2023-12-20T17:57:25.158Z,1703095045.158 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-12-20T17:57:34.421Z,1703095054.421 [NAL9602](INFO): Not Powering down - fast GPS 2023-12-20T18:02:25.719Z,1703095345.719 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-12-20T18:02:25.719Z,1703095345.719 [Default:CheckIn:C.Wait] Stopped 2023-12-20T18:02:25.720Z,1703095345.720 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-12-20T18:02:25.720Z,1703095345.720 [Default:CheckIn:D] Running Loop=1 2023-12-20T18:02:26.130Z,1703095346.130 [Default:CheckIn:D] Stopped 2023-12-20T18:02:26.131Z,1703095346.131 [Default:CheckIn:E] Running Loop=1 2023-12-20T18:02:26.538Z,1703095346.538 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 16.983463 min 2023-12-20T18:02:26.538Z,1703095346.538 [Default:CheckIn:E] Stopped 2023-12-20T18:02:26.538Z,1703095346.538 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-12-20T18:02:26.538Z,1703095346.538 [Default:CheckIn] Stopped 2023-12-20T18:02:26.538Z,1703095346.538 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-12-20T18:02:26.539Z,1703095346.539 [Default:CheckIn](INFO): Running loop #3 2023-12-20T18:02:26.539Z,1703095346.539 [Default:CheckIn] Running Loop=3 2023-12-20T18:02:26.539Z,1703095346.539 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-12-20T18:02:26.539Z,1703095346.539 [Default:CheckIn:Read_GPS] Running Loop=1 2023-12-20T18:02:28.539Z,1703095348.539 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180227.00,A,3648.13720,N,12147.21022,W,0.117,211.47,201223,,,A*78 2023-12-20T18:02:28.541Z,1703095348.541 [NAL9602](INFO): GPS fix at 20231220T180227: (36.802287, -121.786837) 2023-12-20T18:02:28.570Z,1703095348.570 [Default:CheckIn:Read_GPS] Stopped 2023-12-20T18:02:28.570Z,1703095348.570 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-12-20T18:02:35.567Z,1703095355.567 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20231220T174133/Courier0010.lzma 2023-12-20T18:02:36.569Z,1703095356.569 [DataOverHttps](INFO): Moved sent file to Logs/20231220T174133/Courier0010.lzma.bak 2023-12-20T18:02:36.570Z,1703095356.570 [DataOverHttps](INFO): SBD MOMSN=19124109 2023-12-20T18:02:44.698Z,1703095364.698 [NAL9602](INFO): SBD MO Status=0, MOMSN=14227, MT Status=0, MTMSN=0 2023-12-20T18:02:44.698Z,1703095364.698 [NAL9602](INFO): No messages in MT queue 2023-12-20T18:02:52.488Z,1703095372.488 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20231220T174133/Express0011.lzma 2023-12-20T18:02:53.489Z,1703095373.489 [DataOverHttps](INFO): Moved sent file to Logs/20231220T174133/Express0011.lzma.bak 2023-12-20T18:02:53.490Z,1703095373.490 [DataOverHttps](INFO): SBD MOMSN=19124112 2023-12-20T18:02:54.816Z,1703095374.816 [Default:CheckIn:Read_Iridium] Stopped 2023-12-20T18:02:54.816Z,1703095374.816 [Default:CheckIn:C.Wait] Running Loop=1 2023-12-20T18:02:54.816Z,1703095374.816 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-12-20T18:03:15.398Z,1703095395.398 [NAL9602](INFO): Not Powering down - fast GPS 2023-12-20T18:07:55.396Z,1703095675.396 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-12-20T18:07:55.396Z,1703095675.396 [Default:CheckIn:C.Wait] Stopped 2023-12-20T18:07:55.396Z,1703095675.396 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-12-20T18:07:55.396Z,1703095675.396 [Default:CheckIn:D] Running Loop=1 2023-12-20T18:07:55.785Z,1703095675.785 [Default:CheckIn:D] Stopped 2023-12-20T18:07:55.785Z,1703095675.785 [Default:CheckIn:E] Running Loop=1 2023-12-20T18:07:56.189Z,1703095676.189 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 22.477706 min 2023-12-20T18:07:56.189Z,1703095676.189 [Default:CheckIn:E] Stopped 2023-12-20T18:07:56.189Z,1703095676.189 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-12-20T18:07:56.189Z,1703095676.189 [Default:CheckIn] Stopped 2023-12-20T18:07:56.189Z,1703095676.189 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-12-20T18:07:56.189Z,1703095676.189 [Default:CheckIn](INFO): Running loop #4 2023-12-20T18:07:56.189Z,1703095676.189 [Default:CheckIn] Running Loop=4 2023-12-20T18:07:56.190Z,1703095676.190 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-12-20T18:07:56.190Z,1703095676.190 [Default:CheckIn:Read_GPS] Running Loop=1 2023-12-20T18:07:58.195Z,1703095678.195 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180757.00,A,3648.13706,N,12147.20624,W,0.816,162.24,201223,,,A*75 2023-12-20T18:07:58.198Z,1703095678.198 [NAL9602](INFO): GPS fix at 20231220T180757: (36.802284, -121.786771) 2023-12-20T18:07:58.211Z,1703095678.211 [Default:CheckIn:Read_GPS] Stopped 2023-12-20T18:07:58.211Z,1703095678.211 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-12-20T18:08:05.911Z,1703095685.911 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20231220T174133/Courier0013.lzma 2023-12-20T18:08:06.914Z,1703095686.914 [DataOverHttps](INFO): Moved sent file to Logs/20231220T174133/Courier0013.lzma.bak 2023-12-20T18:08:06.914Z,1703095686.914 [DataOverHttps](INFO): SBD MOMSN=19124116 2023-12-20T18:08:22.900Z,1703095702.900 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20231220T174133/Express0014.lzma 2023-12-20T18:08:23.894Z,1703095703.894 [DataOverHttps](INFO): Moved sent file to Logs/20231220T174133/Express0014.lzma.bak 2023-12-20T18:08:23.894Z,1703095703.894 [DataOverHttps](INFO): SBD MOMSN=19124119 2023-12-20T18:08:25.272Z,1703095705.272 [Default:CheckIn:Read_Iridium] Stopped 2023-12-20T18:08:25.272Z,1703095705.272 [Default:CheckIn:C.Wait] Running Loop=1 2023-12-20T18:08:25.272Z,1703095705.272 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-12-20T18:09:09.298Z,1703095749.298 [NAL9602](INFO): SBD MO Status=2, MOMSN=14228, MT Status=2, MTMSN=0 2023-12-20T18:09:09.298Z,1703095749.298 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-12-20T18:09:36.371Z,1703095776.371 [NAL9602](INFO): SBD MO Status=2, MOMSN=14228, MT Status=2, MTMSN=0 2023-12-20T18:09:36.372Z,1703095776.372 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-12-20T18:10:06.269Z,1703095806.269 [NAL9602](INFO): SBD MO Status=0, MOMSN=14228, MT Status=0, MTMSN=0 2023-12-20T18:10:06.269Z,1703095806.269 [NAL9602](INFO): No messages in MT queue 2023-12-20T18:10:36.968Z,1703095836.968 [NAL9602](INFO): Not Powering down - fast GPS 2023-12-20T18:13:25.855Z,1703096005.855 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-12-20T18:13:25.856Z,1703096005.856 [Default:CheckIn:C.Wait] Stopped 2023-12-20T18:13:25.856Z,1703096005.856 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-12-20T18:13:25.856Z,1703096005.856 [Default:CheckIn:D] Running Loop=1 2023-12-20T18:13:26.263Z,1703096006.263 [Default:CheckIn:D] Stopped 2023-12-20T18:13:26.263Z,1703096006.263 [Default:CheckIn:E] Running Loop=1 2023-12-20T18:13:26.671Z,1703096006.671 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 27.985675 min 2023-12-20T18:13:26.671Z,1703096006.671 [Default:CheckIn:E] Stopped 2023-12-20T18:13:26.671Z,1703096006.671 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-12-20T18:13:26.671Z,1703096006.671 [Default:CheckIn] Stopped 2023-12-20T18:13:26.671Z,1703096006.671 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-12-20T18:13:26.672Z,1703096006.672 [Default:CheckIn](INFO): Running loop #5 2023-12-20T18:13:26.672Z,1703096006.672 [Default:CheckIn] Running Loop=5 2023-12-20T18:13:26.672Z,1703096006.672 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-12-20T18:13:26.672Z,1703096006.672 [Default:CheckIn:Read_GPS] Running Loop=1 2023-12-20T18:13:28.679Z,1703096008.679 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181327.00,A,3648.39002,N,12147.11626,W,4.918,6.54,201223,,,A*73 2023-12-20T18:13:28.681Z,1703096008.681 [NAL9602](INFO): GPS fix at 20231220T181327: (36.806500, -121.785271) 2023-12-20T18:13:28.712Z,1703096008.712 [Default:CheckIn:Read_GPS] Stopped 2023-12-20T18:13:28.712Z,1703096008.712 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-12-20T18:13:36.403Z,1703096016.403 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20231220T174133/Courier0016.lzma 2023-12-20T18:13:37.406Z,1703096017.406 [DataOverHttps](INFO): Moved sent file to Logs/20231220T174133/Courier0016.lzma.bak 2023-12-20T18:13:37.406Z,1703096017.406 [DataOverHttps](INFO): SBD MOMSN=19124123 2023-12-20T18:13:53.380Z,1703096033.380 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20231220T174133/Express0017.lzma 2023-12-20T18:13:54.382Z,1703096034.382 [DataOverHttps](INFO): Moved sent file to Logs/20231220T174133/Express0017.lzma.bak 2023-12-20T18:13:54.382Z,1703096034.382 [DataOverHttps](INFO): SBD MOMSN=19124126 2023-12-20T18:13:55.774Z,1703096035.774 [Default:CheckIn:Read_Iridium] Stopped 2023-12-20T18:13:55.774Z,1703096035.774 [Default:CheckIn:C.Wait] Running Loop=1 2023-12-20T18:13:55.774Z,1703096035.774 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-12-20T18:14:02.609Z,1703096042.609 [NAL9602](INFO): SBD MO Status=2, MOMSN=14229, MT Status=2, MTMSN=0 2023-12-20T18:14:02.610Z,1703096042.610 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-12-20T18:14:19.589Z,1703096059.589 [NAL9602](INFO): SBD MO Status=2, MOMSN=14229, MT Status=2, MTMSN=0 2023-12-20T18:14:19.589Z,1703096059.589 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-12-20T18:14:47.050Z,1703096087.050 [NAL9602](INFO): SBD MO Status=0, MOMSN=14229, MT Status=0, MTMSN=0 2023-12-20T18:14:47.050Z,1703096087.050 [NAL9602](INFO): No messages in MT queue 2023-12-20T18:15:17.753Z,1703096117.753 [NAL9602](INFO): Not Powering down - fast GPS 2023-12-20T18:18:56.334Z,1703096336.334 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-12-20T18:18:56.334Z,1703096336.334 [Default:CheckIn:C.Wait] Stopped 2023-12-20T18:18:56.334Z,1703096336.334 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-12-20T18:18:56.334Z,1703096336.334 [Default:CheckIn:D] Running Loop=1 2023-12-20T18:18:56.746Z,1703096336.746 [Default:CheckIn:D] Stopped 2023-12-20T18:18:56.746Z,1703096336.746 [Default:CheckIn:E] Running Loop=1 2023-12-20T18:18:57.142Z,1703096337.142 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 33.493717 min 2023-12-20T18:18:57.142Z,1703096337.142 [Default:CheckIn:E] Stopped 2023-12-20T18:18:57.142Z,1703096337.142 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-12-20T18:18:57.142Z,1703096337.142 [Default:CheckIn] Stopped 2023-12-20T18:18:57.142Z,1703096337.142 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-12-20T18:18:57.142Z,1703096337.142 [Default:CheckIn](INFO): Running loop #6 2023-12-20T18:18:57.142Z,1703096337.142 [Default:CheckIn] Running Loop=6 2023-12-20T18:18:57.142Z,1703096337.142 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-12-20T18:18:57.143Z,1703096337.143 [Default:CheckIn:Read_GPS] Running Loop=1 2023-12-20T18:18:59.146Z,1703096339.146 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181858.00,A,3648.19546,N,12147.89385,W,17.533,235.23,201223,,,A*4F 2023-12-20T18:18:59.149Z,1703096339.149 [NAL9602](INFO): GPS fix at 20231220T181858: (36.803258, -121.798231) 2023-12-20T18:18:59.161Z,1703096339.161 [Default:CheckIn:Read_GPS] Stopped 2023-12-20T18:18:59.161Z,1703096339.161 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-12-20T18:19:06.852Z,1703096346.852 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20231220T174133/Courier0019.lzma 2023-12-20T18:19:07.853Z,1703096347.853 [DataOverHttps](INFO): Moved sent file to Logs/20231220T174133/Courier0019.lzma.bak 2023-12-20T18:19:07.854Z,1703096347.854 [DataOverHttps](INFO): SBD MOMSN=19124130 2023-12-20T18:19:22.983Z,1703096362.983 [NAL9602](INFO): SBD MO Status=0, MOMSN=14230, MT Status=0, MTMSN=0 2023-12-20T18:19:22.983Z,1703096362.983 [NAL9602](INFO): No messages in MT queue 2023-12-20T18:19:23.876Z,1703096363.876 [DataOverHttps](INFO): Sending 138 bytes from file Logs/20231220T174133/Express0020.lzma 2023-12-20T18:19:24.878Z,1703096364.878 [DataOverHttps](INFO): Moved sent file to Logs/20231220T174133/Express0020.lzma.bak 2023-12-20T18:19:24.878Z,1703096364.878 [DataOverHttps](INFO): SBD MOMSN=19124133 2023-12-20T18:19:26.237Z,1703096366.237 [Default:CheckIn:Read_Iridium] Stopped 2023-12-20T18:19:26.237Z,1703096366.237 [Default:CheckIn:C.Wait] Running Loop=1 2023-12-20T18:19:26.237Z,1703096366.237 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-12-20T18:19:53.689Z,1703096393.689 [NAL9602](INFO): Not Powering down - fast GPS 2023-12-20T18:24:26.832Z,1703096666.832 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-12-20T18:24:26.832Z,1703096666.832 [Default:CheckIn:C.Wait] Stopped 2023-12-20T18:24:26.832Z,1703096666.832 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-12-20T18:24:26.832Z,1703096666.832 [Default:CheckIn:D] Running Loop=1 2023-12-20T18:24:27.245Z,1703096667.245 [Default:CheckIn:D] Stopped 2023-12-20T18:24:27.245Z,1703096667.245 [Default:CheckIn:E] Running Loop=1 2023-12-20T18:24:27.621Z,1703096667.621 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 39.002039 min 2023-12-20T18:24:27.622Z,1703096667.622 [Default:CheckIn:E] Stopped 2023-12-20T18:24:27.622Z,1703096667.622 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-12-20T18:24:27.622Z,1703096667.622 [Default:CheckIn] Stopped 2023-12-20T18:24:27.622Z,1703096667.622 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-12-20T18:24:27.622Z,1703096667.622 [Default:CheckIn](INFO): Running loop #7 2023-12-20T18:24:27.622Z,1703096667.622 [Default:CheckIn] Running Loop=7 2023-12-20T18:24:27.622Z,1703096667.622 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-12-20T18:24:27.622Z,1703096667.622 [Default:CheckIn:Read_GPS] Running Loop=1 2023-12-20T18:24:29.623Z,1703096669.623 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182428.00,A,3647.86367,N,12149.77569,W,17.922,269.16,201223,,,A*43 2023-12-20T18:24:29.625Z,1703096669.625 [NAL9602](INFO): GPS fix at 20231220T182428: (36.797728, -121.829595) 2023-12-20T18:24:29.654Z,1703096669.654 [Default:CheckIn:Read_GPS] Stopped 2023-12-20T18:24:29.654Z,1703096669.654 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-12-20T18:24:30.946Z,1703096670.946 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20231220T174133/Courier0022.lzma 2023-12-20T18:24:31.942Z,1703096671.942 [DataOverHttps](INFO): Moved sent file to Logs/20231220T174133/Courier0022.lzma.bak 2023-12-20T18:24:31.942Z,1703096671.942 [DataOverHttps](INFO): SBD MOMSN=19124137 2023-12-20T18:24:44.163Z,1703096684.163 [NAL9602](INFO): SBD MO Status=0, MOMSN=14231, MT Status=0, MTMSN=0 2023-12-20T18:24:44.163Z,1703096684.163 [NAL9602](INFO): No messages in MT queue 2023-12-20T18:24:47.916Z,1703096687.916 [DataOverHttps](INFO): Sending 146 bytes from file Logs/20231220T174133/Express0023.lzma 2023-12-20T18:24:48.918Z,1703096688.918 [DataOverHttps](INFO): Moved sent file to Logs/20231220T174133/Express0023.lzma.bak 2023-12-20T18:24:48.918Z,1703096688.918 [DataOverHttps](INFO): SBD MOMSN=19124140 2023-12-20T18:24:50.238Z,1703096690.238 [Default:CheckIn:Read_Iridium] Stopped 2023-12-20T18:24:50.238Z,1703096690.238 [Default:CheckIn:C.Wait] Running Loop=1 2023-12-20T18:24:50.238Z,1703096690.238 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-12-20T18:25:14.873Z,1703096714.873 [NAL9602](INFO): Not Powering down - fast GPS 2023-12-20T18:29:50.839Z,1703096990.839 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-12-20T18:29:50.839Z,1703096990.839 [Default:CheckIn:C.Wait] Stopped 2023-12-20T18:29:50.839Z,1703096990.839 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-12-20T18:29:50.839Z,1703096990.839 [Default:CheckIn:D] Running Loop=1 2023-12-20T18:29:51.234Z,1703096991.234 [Default:CheckIn:D] Stopped 2023-12-20T18:29:51.234Z,1703096991.234 [Default:CheckIn:E] Running Loop=1 2023-12-20T18:29:51.634Z,1703096991.634 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 44.401851 min 2023-12-20T18:29:51.634Z,1703096991.634 [Default:CheckIn:E] Stopped 2023-12-20T18:29:51.634Z,1703096991.634 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-12-20T18:29:51.634Z,1703096991.634 [Default:CheckIn] Stopped 2023-12-20T18:29:51.634Z,1703096991.634 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-12-20T18:29:51.634Z,1703096991.634 [Default:CheckIn](INFO): Running loop #8 2023-12-20T18:29:51.634Z,1703096991.634 [Default:CheckIn] Running Loop=8 2023-12-20T18:29:51.634Z,1703096991.634 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-12-20T18:29:51.635Z,1703096991.635 [Default:CheckIn:Read_GPS] Running Loop=1 2023-12-20T18:29:53.643Z,1703096993.643 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182952.00,A,3647.80202,N,12150.85043,W,2.080,39.32,201223,,,A*4B 2023-12-20T18:29:53.645Z,1703096993.645 [NAL9602](INFO): GPS fix at 20231220T182952: (36.796700, -121.847507) 2023-12-20T18:29:53.682Z,1703096993.682 [Default:CheckIn:Read_GPS] Stopped 2023-12-20T18:29:53.682Z,1703096993.682 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-12-20T18:30:04.375Z,1703097004.375 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20231220T174133/Courier0025.lzma 2023-12-20T18:30:05.378Z,1703097005.378 [DataOverHttps](INFO): Moved sent file to Logs/20231220T174133/Courier0025.lzma.bak 2023-12-20T18:30:05.378Z,1703097005.378 [DataOverHttps](INFO): SBD MOMSN=19124144 2023-12-20T18:30:06.627Z,1703097006.627 [NAL9602](INFO): SBD MO Status=0, MOMSN=14232, MT Status=0, MTMSN=0 2023-12-20T18:30:06.627Z,1703097006.627 [NAL9602](INFO): No messages in MT queue 2023-12-20T18:30:23.272Z,1703097023.272 [DataOverHttps](INFO): Sending 141 bytes from file Logs/20231220T174133/Express0026.lzma 2023-12-20T18:30:24.274Z,1703097024.274 [DataOverHttps](INFO): Moved sent file to Logs/20231220T174133/Express0026.lzma.bak 2023-12-20T18:30:24.274Z,1703097024.274 [DataOverHttps](INFO): SBD MOMSN=19124147 2023-12-20T18:30:25.634Z,1703097025.634 [Default:CheckIn:Read_Iridium] Stopped 2023-12-20T18:30:25.634Z,1703097025.634 [Default:CheckIn:C.Wait] Running Loop=1 2023-12-20T18:30:25.634Z,1703097025.634 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-12-20T18:30:37.325Z,1703097037.325 [NAL9602](INFO): Not Powering down - fast GPS 2023-12-20T18:33:30.817Z,1703097210.817 [DataOverHttps](IMPORTANT): SBD MTMSN=20231220T183329