2024-10-07T21:04:25.752Z,1728335065.752 [Supervisor](DEBUG): Initializing supervisor. 2024-10-07T21:04:25.757Z,1728335065.757 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2024-10-07T21:04:25.757Z,1728335065.757 [SyncHandler](INFO): Protected caller Thread ID is 7455 2024-10-07T21:04:25.766Z,1728335065.766 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2024-10-07T21:04:25.767Z,1728335065.767 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2024-10-07T21:04:25.767Z,1728335065.767 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 7456 2024-10-07T21:04:25.771Z,1728335065.771 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2024-10-07T21:04:25.797Z,1728335065.797 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread. 2024-10-07T21:04:25.798Z,1728335065.798 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2024-10-07T21:04:25.798Z,1728335065.798 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 7457 2024-10-07T21:04:25.803Z,1728335065.803 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2024-10-07T21:04:25.803Z,1728335065.803 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2024-10-07T21:04:25.804Z,1728335065.804 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 7458 2024-10-07T21:04:25.806Z,1728335065.806 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2024-10-07T21:04:25.813Z,1728335065.813 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0 2024-10-07T21:04:25.814Z,1728335065.814 [logger ThreadHandler](INFO): Protected caller Thread ID is 7459 2024-10-07T21:04:25.817Z,1728335065.817 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2024-10-07T21:04:25.818Z,1728335065.818 [Supervisor](INFO): Looking for Config files in directory: Config/ 2024-10-07T21:04:25.820Z,1728335065.820 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2024-10-07T21:04:26.277Z,1728335066.277 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2024-10-07T21:04:26.278Z,1728335066.278 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2024-10-07T21:04:26.416Z,1728335066.416 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2024-10-07T21:04:27.494Z,1728335067.494 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2024-10-07T21:04:27.494Z,1728335067.494 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2024-10-07T21:04:27.875Z,1728335067.875 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2024-10-07T21:04:27.875Z,1728335067.875 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2024-10-07T21:04:27.987Z,1728335067.987 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2024-10-07T21:04:27.988Z,1728335067.988 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2024-10-07T21:04:28.439Z,1728335068.439 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2024-10-07T21:04:28.440Z,1728335068.440 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2024-10-07T21:04:28.971Z,1728335068.971 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2024-10-07T21:04:28.972Z,1728335068.972 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2024-10-07T21:04:29.545Z,1728335069.545 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2024-10-07T21:04:29.546Z,1728335069.546 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2024-10-07T21:04:29.698Z,1728335069.698 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2024-10-07T21:04:29.699Z,1728335069.699 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2024-10-07T21:04:29.793Z,1728335069.793 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2024-10-07T21:04:30.683Z,1728335070.683 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2024-10-07T21:04:30.684Z,1728335070.684 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2024-10-07T21:04:31.099Z,1728335071.099 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2024-10-07T21:04:31.100Z,1728335071.100 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2024-10-07T21:04:31.320Z,1728335071.320 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2024-10-07T21:04:31.320Z,1728335071.320 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2024-10-07T21:04:31.447Z,1728335071.447 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2024-10-07T21:04:31.448Z,1728335071.448 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2024-10-07T21:04:31.698Z,1728335071.698 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2024-10-07T21:04:31.699Z,1728335071.699 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg 2024-10-07T21:04:31.975Z,1728335071.975 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock 2024-10-07T21:04:31.977Z,1728335071.977 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/ 2024-10-07T21:04:31.978Z,1728335071.978 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg 2024-10-07T21:04:32.084Z,1728335072.084 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg 2024-10-07T21:04:32.186Z,1728335072.186 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg 2024-10-07T21:04:32.305Z,1728335072.305 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg 2024-10-07T21:04:32.403Z,1728335072.403 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg 2024-10-07T21:04:32.523Z,1728335072.523 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg 2024-10-07T21:04:32.631Z,1728335072.631 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg 2024-10-07T21:04:32.766Z,1728335072.766 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg 2024-10-07T21:04:32.940Z,1728335072.940 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg 2024-10-07T21:04:33.111Z,1728335073.111 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg 2024-10-07T21:04:33.239Z,1728335073.239 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg 2024-10-07T21:04:33.595Z,1728335073.595 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2024-10-07T21:04:33.596Z,1728335073.596 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/root/ 2024-10-07T21:04:33.597Z,1728335073.597 [Supervisor](IMPORTANT): Reloading configuration overrides from Data/persisted.cfg 2024-10-07T21:04:33.606Z,1728335073.606 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2024-10-07T21:04:33.659Z,1728335073.659 [VerticalControl](DEBUG): Construct VerticalControl. 2024-10-07T21:04:33.781Z,1728335073.781 [VerticalControl] Loaded 2024-10-07T21:04:33.782Z,1728335073.782 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2024-10-07T21:04:33.784Z,1728335073.784 [HorizontalControl](DEBUG): Construct HorizontalControl. 2024-10-07T21:04:33.878Z,1728335073.878 [HorizontalControl] Loaded 2024-10-07T21:04:33.878Z,1728335073.878 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2024-10-07T21:04:33.881Z,1728335073.881 [SpeedControl](DEBUG): Construct SpeedControl. 2024-10-07T21:04:33.884Z,1728335073.884 [SpeedControl] Loaded 2024-10-07T21:04:33.884Z,1728335073.884 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2024-10-07T21:04:33.895Z,1728335073.895 [LoopControl](DEBUG): Construct LoopControl. 2024-10-07T21:04:33.895Z,1728335073.895 [LoopControl] Loaded 2024-10-07T21:04:33.895Z,1728335073.895 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2024-10-07T21:04:33.896Z,1728335073.896 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2024-10-07T21:04:33.896Z,1728335073.896 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2024-10-07T21:04:33.906Z,1728335073.906 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2024-10-07T21:04:33.907Z,1728335073.907 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2024-10-07T21:04:34.442Z,1728335074.442 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2024-10-07T21:04:34.442Z,1728335074.442 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2024-10-07T21:04:34.821Z,1728335074.821 [BuoyancyServo] Loaded 2024-10-07T21:04:34.821Z,1728335074.821 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2024-10-07T21:04:34.901Z,1728335074.901 [ElevatorServo] Loaded 2024-10-07T21:04:34.902Z,1728335074.902 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2024-10-07T21:04:34.975Z,1728335074.975 [MassServo] Loaded 2024-10-07T21:04:34.976Z,1728335074.976 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2024-10-07T21:04:34.996Z,1728335074.996 [RudderServo] Loaded 2024-10-07T21:04:34.997Z,1728335074.997 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2024-10-07T21:04:35.013Z,1728335075.013 [ThrusterHE] Loaded 2024-10-07T21:04:35.013Z,1728335075.013 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread. 2024-10-07T21:04:35.013Z,1728335075.013 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2024-10-07T21:04:35.014Z,1728335075.014 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2024-10-07T21:04:35.185Z,1728335075.185 [DeadReckonUsingMultipleVelocitySources] Loaded 2024-10-07T21:04:35.186Z,1728335075.186 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2024-10-07T21:04:35.199Z,1728335075.199 [NavChart] Loaded 2024-10-07T21:04:35.199Z,1728335075.199 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2024-10-07T21:04:35.205Z,1728335075.205 [UniversalFixResidualReporter] Loaded 2024-10-07T21:04:35.205Z,1728335075.205 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2024-10-07T21:04:35.206Z,1728335075.206 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2024-10-07T21:04:35.206Z,1728335075.206 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2024-10-07T21:04:35.274Z,1728335075.274 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2024-10-07T21:04:35.275Z,1728335075.275 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2024-10-07T21:04:35.719Z,1728335075.719 [AHRS_M2] Loaded 2024-10-07T21:04:35.719Z,1728335075.719 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2024-10-07T21:04:36.543Z,1728335076.543 [BPC1] Loaded 2024-10-07T21:04:36.543Z,1728335076.543 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2024-10-07T21:04:36.632Z,1728335076.632 [DATMMP] Loaded 2024-10-07T21:04:36.632Z,1728335076.632 [ComponentRegistry](DEBUG): Component "DATMMP" handled in its own thread. 2024-10-07T21:04:36.633Z,1728335076.633 [DATMMP ThreadHandler](DEBUG): Created PCaller Thread at 4094C4E0 2024-10-07T21:04:36.634Z,1728335076.634 [DATMMP ThreadHandler](INFO): Protected caller Thread ID is 7541 2024-10-07T21:04:36.704Z,1728335076.704 [DataOverHttps] Loaded 2024-10-07T21:04:36.705Z,1728335076.705 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2024-10-07T21:04:36.706Z,1728335076.706 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4097C4E0 2024-10-07T21:04:36.706Z,1728335076.706 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 7542 2024-10-07T21:04:36.729Z,1728335076.729 [Depth_Keller] Loaded 2024-10-07T21:04:36.729Z,1728335076.729 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2024-10-07T21:04:36.734Z,1728335076.734 [DropWeight] Loaded 2024-10-07T21:04:36.734Z,1728335076.734 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2024-10-07T21:04:36.798Z,1728335076.798 [NAL9602] Loaded 2024-10-07T21:04:36.798Z,1728335076.798 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2024-10-07T21:04:36.828Z,1728335076.828 [Onboard] Loaded 2024-10-07T21:04:36.828Z,1728335076.828 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread. 2024-10-07T21:04:36.829Z,1728335076.829 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 409AC4E0 2024-10-07T21:04:36.829Z,1728335076.829 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 7543 2024-10-07T21:04:36.835Z,1728335076.835 [PowerOnly](INFO): Adding load control power supply at /dev/loadC1 2024-10-07T21:04:36.849Z,1728335076.849 [PowerOnly] Loaded 2024-10-07T21:04:36.849Z,1728335076.849 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread. 2024-10-07T21:04:36.862Z,1728335076.862 [Power24vConverter] Loaded 2024-10-07T21:04:36.863Z,1728335076.863 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread. 2024-10-07T21:04:36.878Z,1728335076.878 [Radio_Surface] Loaded 2024-10-07T21:04:36.878Z,1728335076.878 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2024-10-07T21:04:36.879Z,1728335076.879 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409DC4E0 2024-10-07T21:04:36.880Z,1728335076.880 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 7544 2024-10-07T21:04:36.881Z,1728335076.881 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2024-10-07T21:04:36.881Z,1728335076.881 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2024-10-07T21:04:36.929Z,1728335076.929 [DepthRateCalculator] Loaded 2024-10-07T21:04:36.930Z,1728335076.930 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2024-10-07T21:04:36.934Z,1728335076.934 [PitchRateCalculator] Loaded 2024-10-07T21:04:36.935Z,1728335076.935 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2024-10-07T21:04:36.943Z,1728335076.943 [SpeedCalculator] Loaded 2024-10-07T21:04:36.944Z,1728335076.944 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2024-10-07T21:04:36.948Z,1728335076.948 [YawRateCalculator] Loaded 2024-10-07T21:04:36.948Z,1728335076.948 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2024-10-07T21:04:36.967Z,1728335076.967 [ElevatorOffsetCalculator] Loaded 2024-10-07T21:04:36.967Z,1728335076.967 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2024-10-07T21:04:36.968Z,1728335076.968 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2024-10-07T21:04:36.968Z,1728335076.968 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2024-10-07T21:04:37.139Z,1728335077.139 [CTD_Seabird] Loaded 2024-10-07T21:04:37.139Z,1728335077.139 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2024-10-07T21:04:37.140Z,1728335077.140 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40A984E0 2024-10-07T21:04:37.141Z,1728335077.141 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 7545 2024-10-07T21:04:37.165Z,1728335077.165 [PAR_Licor] Loaded 2024-10-07T21:04:37.165Z,1728335077.165 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2024-10-07T21:04:37.208Z,1728335077.208 [WetLabsBB2FL] Loaded 2024-10-07T21:04:37.208Z,1728335077.208 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2024-10-07T21:04:37.209Z,1728335077.209 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40AC84E0 2024-10-07T21:04:37.210Z,1728335077.210 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 7546 2024-10-07T21:04:37.210Z,1728335077.210 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2024-10-07T21:04:37.211Z,1728335077.211 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2024-10-07T21:04:37.237Z,1728335077.237 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2024-10-07T21:04:37.238Z,1728335077.238 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2024-10-07T21:04:37.562Z,1728335077.562 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2024-10-07T21:04:37.563Z,1728335077.563 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2024-10-07T21:04:37.700Z,1728335077.700 [SBIT](DEBUG): Construct Startup Built In Test. 2024-10-07T21:04:37.709Z,1728335077.709 [SBIT] Loaded 2024-10-07T21:04:37.709Z,1728335077.709 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2024-10-07T21:04:37.712Z,1728335077.712 [IBIT](DEBUG): Construct Initiated Built In Test. 2024-10-07T21:04:37.725Z,1728335077.725 [IBIT] Loaded 2024-10-07T21:04:37.725Z,1728335077.725 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2024-10-07T21:04:37.731Z,1728335077.731 [CBIT](DEBUG): Construct Continuous Built In Test. 2024-10-07T21:04:37.835Z,1728335077.835 [CBIT] Loaded 2024-10-07T21:04:37.836Z,1728335077.836 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2024-10-07T21:04:37.836Z,1728335077.836 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2024-10-07T21:04:37.837Z,1728335077.837 [Module Loader](DEBUG): Loading Module at Modules/Dock.so 2024-10-07T21:04:37.944Z,1728335077.944 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking) 2024-10-07T21:04:37.951Z,1728335077.951 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2024-10-07T21:04:37.954Z,1728335077.954 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2024-10-07T21:04:37.965Z,1728335077.965 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2024-10-07T21:04:37.966Z,1728335077.966 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C224E0 2024-10-07T21:04:37.966Z,1728335077.966 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 7547 2024-10-07T21:04:37.971Z,1728335077.971 [Supervisor](INFO): Main Thread ID is 6506 2024-10-07T21:04:37.971Z,1728335077.971 [Supervisor](DEBUG): Running supervisor. 2024-10-07T21:04:37.972Z,1728335077.972 [CommandExec ThreadHandler](INFO): Handler Thread ID is 7548 2024-10-07T21:04:37.972Z,1728335077.972 [CommandExec](INFO): Initializing the command executive. 2024-10-07T21:04:37.974Z,1728335077.974 [CommandLine ThreadHandler](INFO): Handler Thread ID is 7549 2024-10-07T21:04:37.977Z,1728335077.977 [controlThread ThreadHandler](INFO): Handler Thread ID is 7550 2024-10-07T21:04:37.978Z,1728335077.978 [controlThread](DEBUG): Initializing ControlThread 2024-10-07T21:04:37.978Z,1728335077.978 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2024-10-07T21:04:37.980Z,1728335077.980 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2024-10-07T21:04:37.981Z,1728335077.981 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2024-10-07T21:04:37.981Z,1728335077.981 [LoopControl](DEBUG): Initialize LoopControlComponent. 2024-10-07T21:04:37.983Z,1728335077.983 [NavChart](DEBUG): Initialize NavChart Navigation. 2024-10-07T21:04:37.983Z,1728335077.983 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2024-10-07T21:04:37.987Z,1728335077.987 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2024-10-07T21:04:37.988Z,1728335077.988 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2024-10-07T21:04:37.988Z,1728335077.988 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2024-10-07T21:04:37.988Z,1728335077.988 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2024-10-07T21:04:37.988Z,1728335077.988 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2024-10-07T21:04:37.994Z,1728335077.994 [SBIT](INFO): Initialize SBIT Component. 2024-10-07T21:04:37.994Z,1728335077.994 [SBIT](IMPORTANT): git: 2024-09-16_D 2024-10-07T21:04:37.994Z,1728335077.994 [SBIT](INFO): git hash: 0de9f8b4fab077d10194b536abee104cbdf12c92 2024-10-07T21:04:37.995Z,1728335077.995 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2024-10-07T21:04:37.996Z,1728335077.996 [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-10-07T21:04:37.997Z,1728335077.997 [SBIT](INFO): Beginning SBIT in 22.000000 seconds. 2024-10-07T21:04:37.997Z,1728335077.997 [IBIT](INFO): Initialize IBIT Component. 2024-10-07T21:04:37.998Z,1728335077.998 [CBIT](DEBUG): Initialize CBIT Component. 2024-10-07T21:04:37.999Z,1728335077.999 [logger ThreadHandler](INFO): Handler Thread ID is 7551 2024-10-07T21:04:38.009Z,1728335078.009 [CBIT](DEBUG): Initialized mux pins. 2024-10-07T21:04:38.009Z,1728335078.009 [CBIT](DEBUG): Initializing the watchdog timer. 2024-10-07T21:04:38.018Z,1728335078.018 [DATMMP ThreadHandler](INFO): Handler Thread ID is 7552 2024-10-07T21:04:38.018Z,1728335078.018 [DATMMP](INFO): Start 2024-10-07T21:04:38.019Z,1728335078.019 [DATMMP](INFO): Powering up 2024-10-07T21:04:38.019Z,1728335078.019 [DATMMP](DEBUG): Initializing DATMMP. 2024-10-07T21:04:38.023Z,1728335078.023 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 7554 2024-10-07T21:04:38.025Z,1728335078.025 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2024-10-07T21:04:38.033Z,1728335078.033 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2024-10-07T21:04:38.034Z,1728335078.034 [CBIT](DEBUG): Initializing heartbeat. 2024-10-07T21:04:38.035Z,1728335078.035 [Onboard ThreadHandler](INFO): Handler Thread ID is 7555 2024-10-07T21:04:38.055Z,1728335078.055 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 7556 2024-10-07T21:04:38.070Z,1728335078.070 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 7557 2024-10-07T21:04:38.071Z,1728335078.071 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2024-10-07T21:04:38.075Z,1728335078.075 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 7559 2024-10-07T21:04:38.078Z,1728335078.078 [WetLabsBB2FL](INFO): Powering up 2024-10-07T21:04:38.079Z,1728335078.079 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 7561 2024-10-07T21:04:38.082Z,1728335078.082 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2024-10-07T21:04:38.082Z,1728335078.082 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2024-10-07T21:04:38.082Z,1728335078.082 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2024-10-07T21:04:38.082Z,1728335078.082 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2024-10-07T21:04:38.083Z,1728335078.083 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2024-10-07T21:04:38.083Z,1728335078.083 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2024-10-07T21:04:38.083Z,1728335078.083 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2024-10-07T21:04:38.083Z,1728335078.083 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2024-10-07T21:04:38.105Z,1728335078.105 [CBIT](DEBUG): Deactivating GF circuits. 2024-10-07T21:04:38.105Z,1728335078.105 [CBIT](DEBUG): Deactivating emergency mode. 2024-10-07T21:04:38.145Z,1728335078.145 [CBIT](DEBUG): Backplane powered. 2024-10-07T21:04:38.146Z,1728335078.146 [MissionManager](IMPORTANT): Using TethysL tl-to-tx parser 2024-10-07T21:04:38.147Z,1728335078.147 [MissionManager](INFO): Loading Mission from file: Missions/Startup.tl 2024-10-07T21:04:38.147Z,1728335078.147 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Startup.tl 2024-10-07T21:04:38.148Z,1728335078.148 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Startup.tl 2024-10-07T21:04:38.184Z,1728335078.184 [MissionManager](DEBUG): TethyslAPI: Missions/Startup.tl translated into: 2024-10-07T21:04:38.204Z,1728335078.204 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2024-10-07T21:04:38.228Z,1728335078.228 [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-10-07T21:04:38.229Z,1728335078.229 [MissionManager](INFO): Loading Mission from file: Missions/Default.tl 2024-10-07T21:04:38.229Z,1728335078.229 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Default.tl 2024-10-07T21:04:38.254Z,1728335078.254 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Default.tl 2024-10-07T21:04:38.269Z,1728335078.269 [DATMMP](INFO): Starting 2024-10-07T21:04:38.457Z,1728335078.457 [Radio_Surface](INFO): Powering up 2024-10-07T21:04:38.521Z,1728335078.521 [DATMMP](INFO): Starting 2024-10-07T21:04:38.558Z,1728335078.558 [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-10-07T21:04:38.564Z,1728335078.564 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2024-10-07T21:04:38.578Z,1728335078.578 [Default:A.Wait](DEBUG): Construct Wait. 2024-10-07T21:04:38.580Z,1728335078.580 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2024-10-07T21:04:38.608Z,1728335078.608 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2024-10-07T21:04:38.651Z,1728335078.651 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2024-10-07T21:04:38.657Z,1728335078.657 [Default:E.Execute](DEBUG): Construct Execute. 2024-10-07T21:04:38.676Z,1728335078.676 [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-10-07T21:04:38.680Z,1728335078.680 [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,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2024-10-07T21:04:38.699Z,1728335078.699 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2024-10-07T21:04:38.761Z,1728335078.761 [PowerOnly](INFO): Powering up loadControl 2024-10-07T21:04:38.773Z,1728335078.773 [DATMMP](INFO): Starting 2024-10-07T21:04:38.778Z,1728335078.778 [Power24vConverter](INFO): Powering up. 2024-10-07T21:04:38.870Z,1728335078.870 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2024-10-07T21:04:38.914Z,1728335078.914 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2024-10-07T21:04:38.915Z,1728335078.915 [ElevatorServo](DEBUG): Initializing EZServoServo. 2024-10-07T21:04:38.926Z,1728335078.926 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2024-10-07T21:04:38.927Z,1728335078.927 [MassServo](DEBUG): Initializing EZServoServo. 2024-10-07T21:04:38.934Z,1728335078.934 [MassServo](DEBUG): Initializing MassServo. 2024-10-07T21:04:38.934Z,1728335078.934 [RudderServo](DEBUG): Initializing EZServoServo. 2024-10-07T21:04:38.942Z,1728335078.942 [RudderServo](DEBUG): Initializing RudderServo. 2024-10-07T21:04:38.942Z,1728335078.942 [ThrusterHE](DEBUG): Initializing EZServoServo. 2024-10-07T21:04:38.950Z,1728335078.950 [ThrusterHE](DEBUG): Initializing ThrusterHE. 2024-10-07T21:04:39.025Z,1728335079.025 [DATMMP](INFO): Starting 2024-10-07T21:04:39.123Z,1728335079.123 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2024-10-07T21:04:39.123Z,1728335079.123 [DropWeight] Hardware Fault, FailCount= 1 2024-10-07T21:04:39.123Z,1728335079.123 [DropWeight](ERROR): Hardware Fault 2024-10-07T21:04:39.152Z,1728335079.152 [CommandExec](FAULT): Scheduling is paused 2024-10-07T21:04:39.153Z,1728335079.153 [CBIT](INFO): Critical error at 20241007T210439 2024-10-07T21:04:39.153Z,1728335079.153 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals 2024-10-07T21:04:39.163Z,1728335079.163 [CBIT](ERROR): Hardware Fault in component: DropWeight 2024-10-07T21:04:39.164Z,1728335079.164 [CBIT](CRITICAL): Hardware Fault in component: DropWeight 2024-10-07T21:04:39.278Z,1728335079.278 [DATMMP](INFO): Starting 2024-10-07T21:04:39.529Z,1728335079.529 [DATMMP](INFO): Starting 2024-10-07T21:04:39.583Z,1728335079.583 [CBIT](INFO): Critical error at 20241007T210439 2024-10-07T21:04:39.781Z,1728335079.781 [DATMMP](INFO): Starting 2024-10-07T21:04:40.034Z,1728335080.034 [DATMMP](INFO): Starting 2024-10-07T21:04:40.285Z,1728335080.285 [DATMMP](INFO): Starting 2024-10-07T21:04:40.537Z,1728335080.537 [DATMMP](INFO): Starting 2024-10-07T21:04:40.718Z,1728335080.718 [WetLabsBB2FL](INFO): Powering down 2024-10-07T21:04:40.790Z,1728335080.790 [DATMMP](INFO): Starting 2024-10-07T21:04:41.041Z,1728335081.041 [DATMMP](INFO): Starting 2024-10-07T21:04:41.293Z,1728335081.293 [DATMMP](INFO): Starting 2024-10-07T21:04:41.546Z,1728335081.546 [DATMMP](INFO): Starting 2024-10-07T21:04:41.797Z,1728335081.797 [DATMMP](INFO): Starting 2024-10-07T21:04:42.050Z,1728335082.050 [DATMMP](INFO): Starting 2024-10-07T21:04:42.301Z,1728335082.301 [DATMMP](INFO): Starting 2024-10-07T21:04:42.554Z,1728335082.554 [DATMMP](INFO): Starting 2024-10-07T21:04:42.805Z,1728335082.805 [DATMMP](INFO): Starting 2024-10-07T21:04:43.058Z,1728335083.058 [DATMMP](INFO): Starting 2024-10-07T21:04:43.310Z,1728335083.310 [DATMMP](INFO): Starting 2024-10-07T21:04:43.561Z,1728335083.561 [DATMMP](INFO): Starting 2024-10-07T21:04:43.814Z,1728335083.814 [DATMMP](INFO): Starting 2024-10-07T21:04:44.066Z,1728335084.066 [DATMMP](INFO): Starting 2024-10-07T21:04:44.318Z,1728335084.318 [DATMMP](INFO): Starting 2024-10-07T21:04:44.570Z,1728335084.570 [DATMMP](INFO): Starting 2024-10-07T21:04:44.583Z,1728335084.583 [ThrusterHE](ERROR): Zero Speed Commanded. 2024-10-07T21:04:44.821Z,1728335084.821 [DATMMP](INFO): Starting 2024-10-07T21:04:45.074Z,1728335085.074 [DATMMP](INFO): Starting 2024-10-07T21:04:45.102Z,1728335085.102 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit. 2024-10-07T21:04:45.325Z,1728335085.325 [DATMMP](INFO): Starting 2024-10-07T21:04:45.577Z,1728335085.577 [DATMMP](INFO): Starting 2024-10-07T21:04:45.829Z,1728335085.829 [DATMMP](INFO): Starting 2024-10-07T21:04:46.081Z,1728335086.081 [DATMMP](INFO): Starting 2024-10-07T21:04:46.333Z,1728335086.333 [DATMMP](INFO): Starting 2024-10-07T21:04:46.586Z,1728335086.586 [DATMMP](INFO): Starting 2024-10-07T21:04:46.837Z,1728335086.837 [DATMMP](INFO): Starting 2024-10-07T21:04:47.089Z,1728335087.089 [DATMMP](INFO): Starting 2024-10-07T21:04:47.341Z,1728335087.341 [DATMMP](INFO): Starting 2024-10-07T21:04:47.593Z,1728335087.593 [DATMMP](INFO): Starting 2024-10-07T21:04:47.846Z,1728335087.846 [DATMMP](INFO): Starting 2024-10-07T21:04:48.098Z,1728335088.098 [DATMMP](INFO): Starting 2024-10-07T21:04:48.349Z,1728335088.349 [DATMMP](INFO): Starting 2024-10-07T21:04:48.601Z,1728335088.601 [DATMMP](INFO): Starting 2024-10-07T21:04:48.854Z,1728335088.854 [DATMMP](INFO): Starting 2024-10-07T21:04:49.106Z,1728335089.106 [DATMMP](INFO): Starting 2024-10-07T21:04:49.357Z,1728335089.357 [DATMMP](INFO): Starting 2024-10-07T21:04:49.609Z,1728335089.609 [DATMMP](INFO): Starting 2024-10-07T21:04:49.610Z,1728335089.610 [DATMMP](INFO): DAT read: 2024-10-07T21:04:49.611Z,1728335089.611 [DATMMP](INFO): DAT read: Teledyne Benthos DAT-900 Series 2024-10-07T21:04:49.861Z,1728335089.861 [DATMMP](INFO): Starting 2024-10-07T21:04:50.113Z,1728335090.113 [DATMMP](INFO): Starting 2024-10-07T21:04:50.366Z,1728335090.366 [DATMMP](INFO): Starting 2024-10-07T21:04:50.617Z,1728335090.617 [DATMMP](INFO): Starting 2024-10-07T21:04:50.869Z,1728335090.869 [DATMMP](INFO): Starting 2024-10-07T21:04:51.121Z,1728335091.121 [DATMMP](INFO): Starting 2024-10-07T21:04:51.122Z,1728335091.122 [DATMMP](INFO): DAT read: MF Frequency Band 2024-10-07T21:04:51.123Z,1728335091.123 [DATMMP](INFO): DAT read: Directional Acoustic Transponder version 8.15.0 2024-10-07T21:04:51.124Z,1728335091.124 [DATMMP](INFO): DAT read: Sep 7 2000 21:04:45 2024-10-07T21:04:51.374Z,1728335091.374 [DATMMP](INFO): Starting 2024-10-07T21:04:51.625Z,1728335091.625 [DATMMP](INFO): Starting 2024-10-07T21:04:51.877Z,1728335091.877 [DATMMP](INFO): Starting 2024-10-07T21:04:52.130Z,1728335092.130 [DATMMP](INFO): Starting 2024-10-07T21:04:52.130Z,1728335092.130 [DATMMP](INFO): DAT read: Features enabled [Bearing] 2024-10-07T21:04:52.131Z,1728335092.131 [DATMMP](INFO): DAT read: CONNECT 01200 bits/sec 1 of 4, Rate 1/2 CC 2024-10-07T21:04:52.132Z,1728335092.132 [DATMMP](INFO): commRate: 1200 2024-10-07T21:04:52.381Z,1728335092.381 [DATMMP](INFO): Starting 2024-10-07T21:04:52.634Z,1728335092.634 [DATMMP](INFO): Starting 2024-10-07T21:04:52.886Z,1728335092.886 [DATMMP](INFO): Starting 2024-10-07T21:04:53.137Z,1728335093.137 [DATMMP](INFO): Starting 2024-10-07T21:04:53.390Z,1728335093.390 [DATMMP](INFO): Starting 2024-10-07T21:04:53.641Z,1728335093.641 [DATMMP](INFO): Starting 2024-10-07T21:04:53.894Z,1728335093.894 [DATMMP](INFO): Starting 2024-10-07T21:04:54.146Z,1728335094.146 [DATMMP](INFO): Starting 2024-10-07T21:04:54.197Z,1728335094.197 [DATMMP](INFO): entering command mode 2024-10-07T21:04:54.399Z,1728335094.399 [DATMMP](INFO): Starting 2024-10-07T21:04:54.400Z,1728335094.400 [DATMMP](INFO): DAT read: 2024-10-07T21:04:54.402Z,1728335094.402 [DATMMP](INFO): DAT read: user:1> 2024-10-07T21:04:54.403Z,1728335094.403 [DATMMP](DEBUG): read user prompt 1: user:1> 2024-10-07T21:04:54.404Z,1728335094.404 [DATMMP](INFO): entering MMP mode 2024-10-07T21:04:54.649Z,1728335094.649 [DATMMP](INFO): Starting 2024-10-07T21:04:54.650Z,1728335094.650 [DATMMP](INFO): GSXN notify for xid: 0 2024-10-07T21:04:54.652Z,1728335094.652 [DATMMP](INFO): status rx: x1 2024-10-07T21:04:54.652Z,1728335094.652 [DATMMP](INFO): MMP status: 1: started 2024-10-07T21:04:54.652Z,1728335094.652 [DATMMP](INFO): Received message type: status 2024-10-07T21:04:54.652Z,1728335094.652 [DATMMP](INFO): Handled 2024-10-07T21:04:54.902Z,1728335094.902 [DATMMP](INFO): Starting 2024-10-07T21:04:54.903Z,1728335094.903 [DATMMP](INFO): Sent Tx Power Config 8 2024-10-07T21:04:54.903Z,1728335094.903 [DATMMP](INFO): Setting local address: 8 2024-10-07T21:04:54.905Z,1728335094.905 [DATMMP](INFO): Setting time to: 21:4:54 And date to:10/7/2024 2024-10-07T21:04:55.154Z,1728335095.154 [DATMMP](INFO): Starting 2024-10-07T21:04:55.154Z,1728335095.154 [DATMMP](INFO): GSXN notify for xid: 0 2024-10-07T21:04:55.155Z,1728335095.155 [DATMMP](INFO): mdmpower rx: x8 x0 x5 x0 2024-10-07T21:04:55.155Z,1728335095.155 [DATMMP](INFO): Received message type: mdmpower 2024-10-07T21:04:55.155Z,1728335095.155 [DATMMP](INFO): Handled 2024-10-07T21:04:55.406Z,1728335095.406 [DATMMP](INFO): Starting 2024-10-07T21:04:55.406Z,1728335095.406 [DATMMP](INFO): GSXN notify for xid: 10 2024-10-07T21:04:55.407Z,1728335095.407 [DATMMP](INFO): sreg_txpower rx: x8 2024-10-07T21:04:55.407Z,1728335095.407 [DATMMP](INFO): Received message type: sreg_txpower 2024-10-07T21:04:55.407Z,1728335095.407 [DATMMP](INFO): Match for : sreg_txpower 2024-10-07T21:04:55.407Z,1728335095.407 [DATMMP](INFO): ACK 2024-10-07T21:04:55.657Z,1728335095.657 [DATMMP](INFO): Starting 2024-10-07T21:04:55.658Z,1728335095.658 [DATMMP](INFO): GSXN notify for xid: 0 2024-10-07T21:04:55.659Z,1728335095.659 [DATMMP](INFO): mdmlocal rx: x8 x0 x0 x0 2024-10-07T21:04:55.659Z,1728335095.659 [DATMMP](INFO): Received message type: mdmlocal 2024-10-07T21:04:55.659Z,1728335095.659 [DATMMP](INFO): Handled 2024-10-07T21:04:55.910Z,1728335095.910 [DATMMP](INFO): Starting 2024-10-07T21:04:55.910Z,1728335095.910 [DATMMP](INFO): GSXN notify for xid: 11 2024-10-07T21:04:55.911Z,1728335095.911 [DATMMP](INFO): sreg_locaddr rx: x8 2024-10-07T21:04:55.911Z,1728335095.911 [DATMMP](INFO): Received message type: sreg_locaddr 2024-10-07T21:04:55.911Z,1728335095.911 [DATMMP](INFO): Match for : sreg_locaddr 2024-10-07T21:04:55.911Z,1728335095.911 [DATMMP](INFO): ACK 2024-10-07T21:04:56.162Z,1728335096.162 [DATMMP](INFO): Starting 2024-10-07T21:04:56.162Z,1728335096.162 [DATMMP](INFO): GSXN notify for xid: 12 2024-10-07T21:04:56.163Z,1728335096.163 [DATMMP](INFO): timedate rx: x0 x15 x4 x36 x9 x7 x7C x0 2024-10-07T21:04:56.163Z,1728335096.163 [DATMMP](INFO): Received message type: timedate 2024-10-07T21:04:56.164Z,1728335096.164 [DATMMP](INFO): Match for : timedate 2024-10-07T21:04:56.164Z,1728335096.164 [DATMMP](INFO): ACK 2024-10-07T21:04:56.414Z,1728335096.414 [DATMMP](INFO): Starting 2024-10-07T21:04:56.414Z,1728335096.414 [DATMMP](INFO): GSXN notify for xid: 0 2024-10-07T21:04:56.415Z,1728335096.415 [DATMMP](INFO): sys_verb rx: x0 x0 x0 x0 2024-10-07T21:04:56.415Z,1728335096.415 [DATMMP](INFO): Received message type: sys_verb 2024-10-07T21:04:56.415Z,1728335096.415 [DATMMP](INFO): Handled 2024-10-07T21:04:56.666Z,1728335096.666 [DATMMP](INFO): Starting 2024-10-07T21:04:56.666Z,1728335096.666 [DATMMP](INFO): GSXN notify for xid: 13 2024-10-07T21:04:56.667Z,1728335096.667 [DATMMP](INFO): sreg_verbosity rx: x0 2024-10-07T21:04:56.667Z,1728335096.667 [DATMMP](INFO): Received message type: sreg_verbosity 2024-10-07T21:04:56.667Z,1728335096.667 [DATMMP](INFO): Match for : sreg_verbosity 2024-10-07T21:04:56.667Z,1728335096.667 [DATMMP](INFO): ACK 2024-10-07T21:04:56.918Z,1728335096.918 [DATMMP](INFO): Starting 2024-10-07T21:04:56.918Z,1728335096.918 [DATMMP](INFO): GSXN notify for xid: 14 2024-10-07T21:04:56.919Z,1728335096.919 [DATMMP](INFO): version rx: x2 x5 2024-10-07T21:04:56.919Z,1728335096.919 [DATMMP](INFO): DatMMPVersion: 2.5 2024-10-07T21:04:56.919Z,1728335096.919 [DATMMP](INFO): Received message type: version 2024-10-07T21:04:56.919Z,1728335096.919 [DATMMP](INFO): Match for : version 2024-10-07T21:04:56.919Z,1728335096.919 [DATMMP](INFO): ACK 2024-10-07T21:04:56.920Z,1728335096.920 [DATMMP](INFO): in MMP mode: config complete going to runnable 2024-10-07T21:05:00.556Z,1728335100.556 [SBIT](IMPORTANT): Beginning Startup BIT 2024-10-07T21:05:00.560Z,1728335100.560 [CBIT](IMPORTANT): Beginning ground fault scan 2024-10-07T21:05:06.971Z,1728335106.971 [NAL9602](INFO): Powering up NAL9602 2024-10-07T21:05:11.294Z,1728335111.294 [DATMMP](INFO): GSXN notify for xid: 0 2024-10-07T21:05:11.295Z,1728335111.295 [DATMMP](INFO): timesync rx: x0 x1 x1 x0 2024-10-07T21:05:11.295Z,1728335111.295 [DATMMP](INFO): Received message type: timesync 2024-10-07T21:05:11.295Z,1728335111.295 [DATMMP](INFO): Handled 2024-10-07T21:05:11.915Z,1728335111.915 [CBIT](ERROR): Ground fault scan returned out of bounds value. Re-running scan. 2024-10-07T21:05:12.326Z,1728335112.326 [CBIT](IMPORTANT): Beginning ground fault scan 2024-10-07T21:05:13.939Z,1728335113.939 [SBIT](FAULT): Rudder: EXPECTED:15.000000 ACTUAL:14.799875 2024-10-07T21:05:17.879Z,1728335117.879 [NAL9602](INFO): NAL9602 initialized 2024-10-07T21:05:21.386Z,1728335121.386 [DATMMP](INFO): GSXN notify for xid: 0 2024-10-07T21:05:21.387Z,1728335121.387 [DATMMP](INFO): timesync rx: x1 x0 x1 x0 2024-10-07T21:05:21.387Z,1728335121.387 [DATMMP](INFO): Received message type: timesync 2024-10-07T21:05:21.387Z,1728335121.387 [DATMMP](INFO): Handled 2024-10-07T21:05:23.205Z,1728335123.205 [CBIT](ERROR): Ground fault scan returned out of bounds value. Re-running scan. 2024-10-07T21:05:23.616Z,1728335123.616 [CBIT](IMPORTANT): Beginning ground fault scan 2024-10-07T21:05:34.467Z,1728335134.467 [CBIT](ERROR): Ground fault scan returned out of bounds value. Re-running scan. 2024-10-07T21:05:34.468Z,1728335134.468 [CBIT](IMPORTANT): Ground fault scan returned out of bounds value in succession 3 times. Will re-run scan on normal schedule. 2024-10-07T21:05:52.230Z,1728335152.230 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2024-10-07T21:05:54.693Z,1728335154.693 [SBIT](CRITICAL): SBIT FAILED 2024-10-07T21:05:54.694Z,1728335154.694 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2024-10-07T21:05:54.695Z,1728335154.695 [SBIT](IMPORTANT): CANONSampler.loadAtStartup=0 bool; 2024-10-07T21:05:54.695Z,1728335154.695 [SBIT](IMPORTANT): DAT.loadAtStartup=0 bool; 2024-10-07T21:05:54.695Z,1728335154.695 [SBIT](IMPORTANT): DATMMP.loadAtStartup=1 bool; 2024-10-07T21:05:54.695Z,1728335154.695 [SBIT](IMPORTANT): DATMMP.simulateHardware=0 bool; 2024-10-07T21:05:54.695Z,1728335154.695 [SBIT](IMPORTANT): DATMMP.surfaceThreshold=2 meter; 2024-10-07T21:05:54.695Z,1728335154.695 [SBIT](IMPORTANT): Express linearApproximation DATMMP.acoustic_contact_range 15.000000 meter; 2024-10-07T21:05:54.695Z,1728335154.695 [SBIT](IMPORTANT): Express linearApproximation PowerOnly.component_avgCurrent_loadControl 50.000000 milliampere; 2024-10-07T21:05:54.695Z,1728335154.695 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=307 cubic_centimeter; 2024-10-07T21:05:54.695Z,1728335154.695 [SBIT](IMPORTANT): VerticalControl.massDefault=-0.623883 millimeter; 2024-10-07T21:05:54.697Z,1728335154.697 [CBIT](INFO): Critical error at 20241007T210554 2024-10-07T21:05:55.087Z,1728335155.087 [MissionManager](IMPORTANT): Started mission Startup 2024-10-07T21:05:55.087Z,1728335155.087 [Startup] Running Loop=1 2024-10-07T21:05:55.087Z,1728335155.087 [Startup](DEBUG): Aggregate::initialize Startup 2024-10-07T21:05:55.087Z,1728335155.087 [Startup:A.GoToSurface] Running Loop=1 2024-10-07T21:05:55.087Z,1728335155.087 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2024-10-07T21:05:55.088Z,1728335155.088 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2024-10-07T21:05:55.088Z,1728335155.088 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2024-10-07T21:05:55.088Z,1728335155.088 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2024-10-07T21:05:55.089Z,1728335155.089 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2024-10-07T21:05:55.089Z,1728335155.089 [Startup:A.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2024-10-07T21:05:55.090Z,1728335155.090 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2024-10-07T21:05:55.091Z,1728335155.091 [Startup:StartupSatComms] Running Loop=1 2024-10-07T21:05:55.091Z,1728335155.091 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2024-10-07T21:05:55.092Z,1728335155.092 [Startup:StartupSatComms:A] Running Loop=1 2024-10-07T21:05:55.464Z,1728335155.464 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2024-10-07T21:06:55.255Z,1728335215.255 [Startup:StartupSatComms:A](INFO): Timed out from 2024-10-07T21:05:55.1Z 2024-10-07T21:06:55.255Z,1728335215.255 [Startup:StartupSatComms:A] Stopped 2024-10-07T21:06:55.255Z,1728335215.255 [Startup:StartupSatComms:B] Running Loop=1 2024-10-07T21:06:55.660Z,1728335215.660 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2024-10-07T21:07:38.084Z,1728335258.084 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2024-10-07T21:07:38.085Z,1728335258.085 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2024-10-07T21:07:38.095Z,1728335258.095 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2024-10-07T21:07:38.510Z,1728335258.510 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2024-10-07T21:07:38.510Z,1728335258.510 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2024-10-07T21:07:48.570Z,1728335268.570 [BPC1](ERROR): BPC1A: No match for serial number 1717 in BPC1A's battery stick inventory (sticks 1-31 in onboard configuration file). 2024-10-07T21:07:55.475Z,1728335275.475 [Startup:StartupSatComms:B](INFO): Timed out from 2024-10-07T21:06:55.3Z 2024-10-07T21:07:55.475Z,1728335275.475 [Startup:StartupSatComms:B] Stopped 2024-10-07T21:07:55.476Z,1728335275.476 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2024-10-07T21:07:55.476Z,1728335275.476 [Startup:StartupSatComms] Stopped 2024-10-07T21:07:55.476Z,1728335275.476 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2024-10-07T21:07:55.477Z,1728335275.477 [Startup](INFO): Completed Startup 2024-10-07T21:07:55.477Z,1728335275.477 [MissionManager](INFO): Startup is completed. 2024-10-07T21:07:55.477Z,1728335275.477 [MissionManager](INFO): Uninitializing Mission Startup 2024-10-07T21:07:55.477Z,1728335275.477 [Startup] Stopped 2024-10-07T21:07:55.477Z,1728335275.477 [Startup](DEBUG): Aggregate::uninitialize Startup 2024-10-07T21:07:55.477Z,1728335275.477 [Startup:A.GoToSurface] Stopped 2024-10-07T21:07:55.478Z,1728335275.478 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2024-10-07T21:07:55.867Z,1728335275.867 [MissionManager](IMPORTANT): Started mission Default 2024-10-07T21:07:55.867Z,1728335275.867 [Default] Running Loop=1 2024-10-07T21:07:55.868Z,1728335275.868 [Default](DEBUG): Aggregate::initialize Default 2024-10-07T21:07:55.868Z,1728335275.868 [Default:B.GoToSurface] Running Loop=1 2024-10-07T21:07:55.868Z,1728335275.868 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2024-10-07T21:07:55.868Z,1728335275.868 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2024-10-07T21:07:55.868Z,1728335275.868 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2024-10-07T21:07:55.869Z,1728335275.869 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2024-10-07T21:07:55.869Z,1728335275.869 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2024-10-07T21:07:55.869Z,1728335275.869 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2024-10-07T21:07:55.870Z,1728335275.870 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2024-10-07T21:07:55.870Z,1728335275.870 [Default:A.Wait] Running Loop=1 2024-10-07T21:07:55.870Z,1728335275.870 [Default:A.Wait](DEBUG): Initialize Wait Component. 2024-10-07T21:08:09.232Z,1728335289.232 [Default:A.Wait](INFO): Done Waiting. 2024-10-07T21:08:09.232Z,1728335289.232 [Default:A.Wait] Stopped 2024-10-07T21:08:09.233Z,1728335289.233 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2024-10-07T21:08:09.640Z,1728335289.640 [Default:CheckIn] Running Loop=1 2024-10-07T21:08:09.640Z,1728335289.640 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-10-07T21:08:09.640Z,1728335289.640 [Default:CheckIn:Read_GPS] Running Loop=1 2024-10-07T21:08:10.048Z,1728335290.048 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2024-10-07T21:08:16.223Z,1728335296.223 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004096 2024-10-07T21:08:31.171Z,1728335311.171 [CommandExec](IMPORTANT): got command strobe off 2024-10-07T21:08:31.171Z,1728335311.171 [CommandExec](IMPORTANT): Deactivating strobe 2024-10-07T21:10:21.915Z,1728335421.915 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2024-10-07T21:10:38.916Z,1728335438.916 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2 2024-10-07T21:10:38.916Z,1728335438.916 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2024-10-07T21:10:38.927Z,1728335438.927 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2024-10-07T21:10:39.337Z,1728335439.337 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2024-10-07T21:10:39.337Z,1728335439.337 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2 2024-10-07T21:13:09.758Z,1728335589.758 [Default:CheckIn:Read_GPS](INFO): Timed out from 2024-10-07T21:08:09.6Z 2024-10-07T21:13:09.758Z,1728335589.758 [Default:CheckIn:Read_GPS] Stopped 2024-10-07T21:13:09.758Z,1728335589.758 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-10-07T21:13:10.165Z,1728335590.165 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2024-10-07T21:13:17.329Z,1728335597.329 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20241007T175621/Courier0109.lzma 2024-10-07T21:13:18.332Z,1728335598.332 [DataOverHttps](INFO): Moved sent file to Logs/20241007T175621/Courier0109.lzma.bak 2024-10-07T21:13:18.332Z,1728335598.332 [DataOverHttps](INFO): SBD MOMSN=23274000 2024-10-07T21:13:19.843Z,1728335599.843 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2024-10-07T21:13:33.978Z,1728335613.978 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2024-10-07T21:13:34.213Z,1728335614.213 [DataOverHttps](INFO): Sending 262 bytes from file Logs/20241007T210425/Courier0000.lzma 2024-10-07T21:13:35.215Z,1728335615.215 [DataOverHttps](INFO): Moved sent file to Logs/20241007T210425/Courier0000.lzma.bak 2024-10-07T21:13:35.215Z,1728335615.215 [DataOverHttps](INFO): SBD MOMSN=23274002 2024-10-07T21:13:38.029Z,1728335618.029 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,211337.00,A,3648.15742,N,12147.28019,W,2.041,214.17,071024,,,A*70 2024-10-07T21:13:38.032Z,1728335618.032 [NAL9602](INFO): GPS fix at 20241007T211337: (36.802624, -121.788003) 2024-10-07T21:13:47.720Z,1728335627.720 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2024-10-07T21:13:52.937Z,1728335632.937 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20241007T210425/Courier0004.lzma 2024-10-07T21:13:53.939Z,1728335633.939 [DataOverHttps](INFO): Moved sent file to Logs/20241007T210425/Courier0004.lzma.bak 2024-10-07T21:13:53.939Z,1728335633.939 [DataOverHttps](INFO): SBD MOMSN=23274008 2024-10-07T21:14:01.860Z,1728335641.860 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2024-10-07T21:14:10.351Z,1728335650.351 [NAL9602](INFO): Not Powering down - fast GPS 2024-10-07T21:14:11.270Z,1728335651.270 [DataOverHttps](INFO): Sending 870 bytes from file Logs/20241007T175621/Express0110.lzma 2024-10-07T21:14:12.272Z,1728335652.272 [DataOverHttps](INFO): Moved sent file to Logs/20241007T175621/Express0110.lzma.bak 2024-10-07T21:14:12.272Z,1728335652.272 [DataOverHttps](INFO): SBD MOMSN=23274010 2024-10-07T21:14:14.793Z,1728335654.793 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2024-10-07T21:14:28.132Z,1728335668.132 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2024-10-07T21:14:31.386Z,1728335671.386 [DataOverHttps](INFO): Sending 888 bytes from file Logs/20241007T210425/Express0001.lzma 2024-10-07T21:14:32.387Z,1728335672.387 [DataOverHttps](INFO): Moved sent file to Logs/20241007T210425/Express0001.lzma.bak 2024-10-07T21:14:32.387Z,1728335672.387 [DataOverHttps](INFO): SBD MOMSN=23274015 2024-10-07T21:14:41.464Z,1728335681.464 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2024-10-07T21:14:49.513Z,1728335689.513 [DataOverHttps](INFO): Sending 236 bytes from file Logs/20241007T210425/Express0005.lzma 2024-10-07T21:14:50.515Z,1728335690.515 [DataOverHttps](INFO): Moved sent file to Logs/20241007T210425/Express0005.lzma.bak 2024-10-07T21:14:50.515Z,1728335690.515 [DataOverHttps](INFO): SBD MOMSN=23274039 2024-10-07T21:14:52.388Z,1728335692.388 [Default:CheckIn:Read_Iridium] Stopped 2024-10-07T21:14:52.388Z,1728335692.388 [Default:CheckIn:C.Wait] Running Loop=1 2024-10-07T21:14:52.388Z,1728335692.388 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-10-07T21:14:54.809Z,1728335694.809 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2024-10-07T21:15:08.150Z,1728335708.150 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2024-10-07T21:15:21.884Z,1728335721.884 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2024-10-07T21:15:35.216Z,1728335735.216 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2024-10-07T21:19:39.314Z,1728335979.314 [CBIT](INFO): Clearing failed state for component DropWeight 2024-10-07T21:19:39.314Z,1728335979.314 [DropWeight] No Fault, FailCount= 1 2024-10-07T21:19:53.001Z,1728335993.001 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-10-07T21:19:53.001Z,1728335993.001 [Default:CheckIn:C.Wait] Stopped 2024-10-07T21:19:53.001Z,1728335993.001 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-10-07T21:19:53.001Z,1728335993.001 [Default:CheckIn:D] Running Loop=1 2024-10-07T21:19:53.405Z,1728335993.405 [Default:CheckIn:D] Stopped 2024-10-07T21:19:53.405Z,1728335993.405 [Default:CheckIn:E] Running Loop=1 2024-10-07T21:19:53.813Z,1728335993.813 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 11.958950 min 2024-10-07T21:19:53.813Z,1728335993.813 [Default:CheckIn:E] Stopped 2024-10-07T21:19:53.813Z,1728335993.813 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-10-07T21:19:53.813Z,1728335993.813 [Default:CheckIn] Stopped 2024-10-07T21:19:53.813Z,1728335993.813 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-10-07T21:19:53.813Z,1728335993.813 [Default:CheckIn](INFO): Running loop #2 2024-10-07T21:19:53.814Z,1728335993.814 [Default:CheckIn] Running Loop=2 2024-10-07T21:19:53.814Z,1728335993.814 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-10-07T21:19:53.814Z,1728335993.814 [Default:CheckIn:Read_GPS] Running Loop=1 2024-10-07T21:19:55.816Z,1728335995.816 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,211955.00,A,3648.17110,N,12147.28230,W,0.253,264.25,071024,,,A*71 2024-10-07T21:19:55.818Z,1728335995.818 [NAL9602](INFO): GPS fix at 20241007T211955: (36.802852, -121.788038) 2024-10-07T21:19:55.842Z,1728335995.842 [Default:CheckIn:Read_GPS] Stopped 2024-10-07T21:19:55.842Z,1728335995.842 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-10-07T21:20:03.649Z,1728336003.649 [DataOverHttps](INFO): Sending 222 bytes from file Logs/20241007T210425/Courier0007.lzma 2024-10-07T21:20:04.651Z,1728336004.651 [DataOverHttps](INFO): Moved sent file to Logs/20241007T210425/Courier0007.lzma.bak 2024-10-07T21:20:04.651Z,1728336004.651 [DataOverHttps](INFO): SBD MOMSN=23274110 2024-10-07T21:20:22.893Z,1728336022.893 [DataOverHttps](INFO): Sending 297 bytes from file Logs/20241007T210425/Express0008.lzma 2024-10-07T21:20:23.896Z,1728336023.896 [DataOverHttps](INFO): Moved sent file to Logs/20241007T210425/Express0008.lzma.bak 2024-10-07T21:20:23.896Z,1728336023.896 [DataOverHttps](INFO): SBD MOMSN=23274113 2024-10-07T21:20:25.624Z,1728336025.624 [Default:CheckIn:Read_Iridium] Stopped 2024-10-07T21:20:25.624Z,1728336025.624 [Default:CheckIn:C.Wait] Running Loop=1 2024-10-07T21:20:25.624Z,1728336025.624 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-10-07T21:22:48.724Z,1728336168.724 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2024-10-07T21:22:51.055Z,1728336171.055 [NAL9602](INFO): SBD MO Status=2, MOMSN=57695, MT Status=2, MTMSN=0 2024-10-07T21:22:51.056Z,1728336171.056 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2024-10-07T21:22:55.091Z,1728336175.091 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2024-10-07T21:23:10.445Z,1728336190.445 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2024-10-07T21:23:25.392Z,1728336205.392 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2024-10-07T21:23:41.150Z,1728336221.150 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2024-10-07T21:23:48.024Z,1728336228.024 [NAL9602](INFO): SBD MO Status=2, MOMSN=57695, MT Status=2, MTMSN=0 2024-10-07T21:23:48.025Z,1728336228.025 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2024-10-07T21:23:56.903Z,1728336236.903 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2024-10-07T21:24:12.659Z,1728336252.659 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2024-10-07T21:24:28.012Z,1728336268.012 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2024-10-07T21:24:42.963Z,1728336282.963 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2024-10-07T21:24:58.405Z,1728336298.405 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2024-10-07T21:24:58.726Z,1728336298.726 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2024-10-07T21:25:14.478Z,1728336314.478 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2024-10-07T21:25:26.218Z,1728336326.218 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-10-07T21:25:26.218Z,1728336326.218 [Default:CheckIn:C.Wait] Stopped 2024-10-07T21:25:26.218Z,1728336326.218 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-10-07T21:25:26.218Z,1728336326.218 [Default:CheckIn:D] Running Loop=1 2024-10-07T21:25:26.614Z,1728336326.614 [Default:CheckIn:D] Stopped 2024-10-07T21:25:26.614Z,1728336326.614 [Default:CheckIn:E] Running Loop=1 2024-10-07T21:25:27.017Z,1728336327.017 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 17.512445 min 2024-10-07T21:25:27.017Z,1728336327.017 [Default:CheckIn:E] Stopped 2024-10-07T21:25:27.017Z,1728336327.017 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-10-07T21:25:27.018Z,1728336327.018 [Default:CheckIn] Stopped 2024-10-07T21:25:27.018Z,1728336327.018 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-10-07T21:25:27.018Z,1728336327.018 [Default:CheckIn](INFO): Running loop #3 2024-10-07T21:25:27.018Z,1728336327.018 [Default:CheckIn] Running Loop=3 2024-10-07T21:25:27.018Z,1728336327.018 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-10-07T21:25:27.018Z,1728336327.018 [Default:CheckIn:Read_GPS] Running Loop=1 2024-10-07T21:25:29.033Z,1728336329.033 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,212528.00,A,3648.17355,N,12147.27702,W,0.972,74.36,071024,,,A*45 2024-10-07T21:25:29.035Z,1728336329.035 [NAL9602](INFO): GPS fix at 20241007T212528: (36.802892, -121.787950) 2024-10-07T21:25:29.046Z,1728336329.046 [Default:CheckIn:Read_GPS] Stopped 2024-10-07T21:25:29.046Z,1728336329.046 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-10-07T21:25:37.009Z,1728336337.009 [DataOverHttps](INFO): Sending 70 bytes from file Logs/20241007T210425/Courier0010.lzma 2024-10-07T21:25:38.011Z,1728336338.011 [DataOverHttps](INFO): Moved sent file to Logs/20241007T210425/Courier0010.lzma.bak 2024-10-07T21:25:38.011Z,1728336338.011 [DataOverHttps](INFO): SBD MOMSN=23274123 2024-10-07T21:25:54.017Z,1728336354.017 [DataOverHttps](INFO): Sending 215 bytes from file Logs/20241007T210425/Express0011.lzma 2024-10-07T21:25:55.019Z,1728336355.019 [DataOverHttps](INFO): Moved sent file to Logs/20241007T210425/Express0011.lzma.bak 2024-10-07T21:25:55.019Z,1728336355.019 [DataOverHttps](INFO): SBD MOMSN=23274126 2024-10-07T21:25:56.517Z,1728336356.517 [Default:CheckIn:Read_Iridium] Stopped 2024-10-07T21:25:56.517Z,1728336356.517 [Default:CheckIn:C.Wait] Running Loop=1 2024-10-07T21:25:56.518Z,1728336356.518 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-10-07T21:26:01.348Z,1728336361.348 [NAL9602](INFO): Not Powering down - fast GPS 2024-10-07T21:30:57.176Z,1728336657.176 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-10-07T21:30:57.176Z,1728336657.176 [Default:CheckIn:C.Wait] Stopped 2024-10-07T21:30:57.176Z,1728336657.176 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-10-07T21:30:57.177Z,1728336657.177 [Default:CheckIn:D] Running Loop=1 2024-10-07T21:30:57.586Z,1728336657.586 [Default:CheckIn:D] Stopped 2024-10-07T21:30:57.586Z,1728336657.586 [Default:CheckIn:E] Running Loop=1 2024-10-07T21:30:57.981Z,1728336657.981 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 23.028634 min 2024-10-07T21:30:57.981Z,1728336657.981 [Default:CheckIn:E] Stopped 2024-10-07T21:30:57.981Z,1728336657.981 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-10-07T21:30:57.981Z,1728336657.981 [Default:CheckIn] Stopped 2024-10-07T21:30:57.981Z,1728336657.981 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-10-07T21:30:57.982Z,1728336657.982 [Default:CheckIn](INFO): Running loop #4 2024-10-07T21:30:57.982Z,1728336657.982 [Default:CheckIn] Running Loop=4 2024-10-07T21:30:57.982Z,1728336657.982 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-10-07T21:30:57.982Z,1728336657.982 [Default:CheckIn:Read_GPS] Running Loop=1 2024-10-07T21:30:59.988Z,1728336659.988 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,213059.00,A,3648.17128,N,12147.27953,W,0.175,23.76,071024,,,A*4C 2024-10-07T21:30:59.991Z,1728336659.991 [NAL9602](INFO): GPS fix at 20241007T213059: (36.802855, -121.787992) 2024-10-07T21:31:00.042Z,1728336660.042 [Default:CheckIn:Read_GPS] Stopped 2024-10-07T21:31:00.042Z,1728336660.042 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-10-07T21:31:07.741Z,1728336667.741 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20241007T210425/Courier0013.lzma 2024-10-07T21:31:08.743Z,1728336668.743 [DataOverHttps](INFO): Moved sent file to Logs/20241007T210425/Courier0013.lzma.bak 2024-10-07T21:31:08.743Z,1728336668.743 [DataOverHttps](INFO): SBD MOMSN=23274138 2024-10-07T21:31:24.769Z,1728336684.769 [DataOverHttps](INFO): Sending 140 bytes from file Logs/20241007T210425/Express0014.lzma 2024-10-07T21:31:25.771Z,1728336685.771 [DataOverHttps](INFO): Moved sent file to Logs/20241007T210425/Express0014.lzma.bak 2024-10-07T21:31:25.771Z,1728336685.771 [DataOverHttps](INFO): SBD MOMSN=23274141 2024-10-07T21:31:27.070Z,1728336687.070 [Default:CheckIn:Read_Iridium] Stopped 2024-10-07T21:31:27.070Z,1728336687.070 [Default:CheckIn:C.Wait] Running Loop=1 2024-10-07T21:31:27.070Z,1728336687.070 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-10-07T21:31:30.695Z,1728336690.695 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2024-10-07T21:31:30.778Z,1728336690.778 [NAL9602](ERROR): received: +CSQ:0 OK695, 2, 0, 0, 0 OK 2024-10-07T21:32:32.508Z,1728336752.508 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2024-10-07T21:32:45.840Z,1728336765.840 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2024-10-07T21:32:47.864Z,1728336767.864 [NAL9602](INFO): SBD MO Status=2, MOMSN=57695, MT Status=2, MTMSN=0 2024-10-07T21:32:47.864Z,1728336767.864 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2024-10-07T21:32:59.576Z,1728336779.576 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2024-10-07T21:33:12.909Z,1728336792.909 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2024-10-07T21:33:17.769Z,1728336797.769 [NAL9602](INFO): SBD MO Status=2, MOMSN=57695, MT Status=2, MTMSN=0 2024-10-07T21:33:17.769Z,1728336797.769 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2024-10-07T21:33:26.240Z,1728336806.240 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2024-10-07T21:33:38.369Z,1728336818.369 [NAL9602](INFO): SBD MO Status=2, MOMSN=57695, MT Status=2, MTMSN=0 2024-10-07T21:33:38.370Z,1728336818.370 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2024-10-07T21:33:39.576Z,1728336819.576 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2024-10-07T21:33:52.910Z,1728336832.910 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2024-10-07T21:34:06.236Z,1728336846.236 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2024-10-07T21:34:11.092Z,1728336851.092 [NAL9602](INFO): SBD MO Status=2, MOMSN=57695, MT Status=2, MTMSN=0 2024-10-07T21:34:11.092Z,1728336851.092 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2024-10-07T21:34:19.971Z,1728336859.971 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2024-10-07T21:34:33.303Z,1728336873.303 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2024-10-07T21:34:47.852Z,1728336887.852 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2024-10-07T21:34:55.944Z,1728336895.944 [NAL9602](INFO): SBD MO Status=2, MOMSN=57695, MT Status=2, MTMSN=0 2024-10-07T21:34:55.944Z,1728336895.944 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2024-10-07T21:35:26.257Z,1728336926.257 [NAL9602](INFO): SBD MO Status=2, MOMSN=57695, MT Status=2, MTMSN=0 2024-10-07T21:35:26.257Z,1728336926.257 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2024-10-07T21:35:39.166Z,1728336939.166 [BPC1](INFO): Calculating totals. Valid battery stick count: 46. Valid reserve battery stick count: 4. 2024-10-07T21:35:39.169Z,1728336939.169 [BPC1](ERROR): Failed to receive data from all sticks prior to timeout. Will not retry this scan cycle. 2024-10-07T21:36:02.196Z,1728336962.196 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2024-10-07T21:36:27.657Z,1728336987.657 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-10-07T21:36:27.657Z,1728336987.657 [Default:CheckIn:C.Wait] Stopped 2024-10-07T21:36:27.657Z,1728336987.657 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-10-07T21:36:27.657Z,1728336987.657 [Default:CheckIn:D] Running Loop=1 2024-10-07T21:36:28.067Z,1728336988.067 [Default:CheckIn:D] Stopped 2024-10-07T21:36:28.067Z,1728336988.067 [Default:CheckIn:E] Running Loop=1 2024-10-07T21:36:28.482Z,1728336988.482 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 28.536656 min 2024-10-07T21:36:28.482Z,1728336988.482 [Default:CheckIn:E] Stopped 2024-10-07T21:36:28.482Z,1728336988.482 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-10-07T21:36:28.482Z,1728336988.482 [Default:CheckIn] Stopped 2024-10-07T21:36:28.482Z,1728336988.482 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-10-07T21:36:28.482Z,1728336988.482 [Default:CheckIn](INFO): Running loop #5 2024-10-07T21:36:28.482Z,1728336988.482 [Default:CheckIn] Running Loop=5 2024-10-07T21:36:28.482Z,1728336988.482 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-10-07T21:36:28.483Z,1728336988.483 [Default:CheckIn:Read_GPS] Running Loop=1 2024-10-07T21:36:30.475Z,1728336990.475 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,213629.00,A,3648.16546,N,12147.28229,W,0.311,23.76,071024,,,A*49 2024-10-07T21:36:30.477Z,1728336990.477 [NAL9602](INFO): GPS fix at 20241007T213629: (36.802758, -121.788038) 2024-10-07T21:36:30.488Z,1728336990.488 [Default:CheckIn:Read_GPS] Stopped 2024-10-07T21:36:30.488Z,1728336990.488 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-10-07T21:36:38.017Z,1728336998.017 [DataOverHttps](INFO): Sending 202 bytes from file Logs/20241007T210425/Courier0016.lzma 2024-10-07T21:36:39.019Z,1728336999.019 [DataOverHttps](INFO): Moved sent file to Logs/20241007T210425/Courier0016.lzma.bak 2024-10-07T21:36:39.019Z,1728336999.019 [DataOverHttps](INFO): SBD MOMSN=23274152 2024-10-07T21:36:57.685Z,1728337017.685 [DataOverHttps](INFO): Sending 216 bytes from file Logs/20241007T210425/Express0017.lzma 2024-10-07T21:36:58.687Z,1728337018.687 [DataOverHttps](INFO): Moved sent file to Logs/20241007T210425/Express0017.lzma.bak 2024-10-07T21:36:58.687Z,1728337018.687 [DataOverHttps](INFO): SBD MOMSN=23274155 2024-10-07T21:37:00.053Z,1728337020.053 [Default:CheckIn:Read_Iridium] Stopped 2024-10-07T21:37:00.053Z,1728337020.053 [Default:CheckIn:C.Wait] Running Loop=1 2024-10-07T21:37:00.053Z,1728337020.053 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-10-07T21:37:02.458Z,1728337022.458 [NAL9602](INFO): Not Powering down - fast GPS 2024-10-07T21:42:00.622Z,1728337320.622 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-10-07T21:42:00.622Z,1728337320.622 [Default:CheckIn:C.Wait] Stopped 2024-10-07T21:42:00.622Z,1728337320.622 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-10-07T21:42:00.622Z,1728337320.622 [Default:CheckIn:D] Running Loop=1 2024-10-07T21:42:01.033Z,1728337321.033 [Default:CheckIn:D] Stopped 2024-10-07T21:42:01.033Z,1728337321.033 [Default:CheckIn:E] Running Loop=1 2024-10-07T21:42:01.441Z,1728337321.441 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 34.086094 min 2024-10-07T21:42:01.441Z,1728337321.441 [Default:CheckIn:E] Stopped 2024-10-07T21:42:01.442Z,1728337321.442 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-10-07T21:42:01.442Z,1728337321.442 [Default:CheckIn] Stopped 2024-10-07T21:42:01.442Z,1728337321.442 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-10-07T21:42:01.442Z,1728337321.442 [Default:CheckIn](INFO): Running loop #6 2024-10-07T21:42:01.442Z,1728337321.442 [Default:CheckIn] Running Loop=6 2024-10-07T21:42:01.442Z,1728337321.442 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-10-07T21:42:01.442Z,1728337321.442 [Default:CheckIn:Read_GPS] Running Loop=1 2024-10-07T21:42:03.440Z,1728337323.440 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,214202.00,A,3648.17621,N,12147.27863,W,0.467,0.00,071024,,,A*7D 2024-10-07T21:42:03.442Z,1728337323.442 [NAL9602](INFO): GPS fix at 20241007T214202: (36.802937, -121.787977) 2024-10-07T21:42:03.453Z,1728337323.453 [Default:CheckIn:Read_GPS] Stopped 2024-10-07T21:42:03.453Z,1728337323.453 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-10-07T21:42:10.413Z,1728337330.413 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20241007T210425/Courier0019.lzma 2024-10-07T21:42:11.415Z,1728337331.415 [DataOverHttps](INFO): Moved sent file to Logs/20241007T210425/Courier0019.lzma.bak 2024-10-07T21:42:11.415Z,1728337331.415 [DataOverHttps](INFO): SBD MOMSN=23274166 2024-10-07T21:42:32.621Z,1728337352.621 [DataOverHttps](INFO): Sending 140 bytes from file Logs/20241007T210425/Express0020.lzma 2024-10-07T21:42:33.623Z,1728337353.623 [DataOverHttps](INFO): Moved sent file to Logs/20241007T210425/Express0020.lzma.bak 2024-10-07T21:42:33.623Z,1728337353.623 [DataOverHttps](INFO): SBD MOMSN=23274169 2024-10-07T21:42:34.229Z,1728337354.229 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2024-10-07T21:42:34.306Z,1728337354.306 [NAL9602](ERROR): received: +CSQ:0 OK695, 2, 0, 0, 0 OK 2024-10-07T21:42:35.085Z,1728337355.085 [Default:CheckIn:Read_Iridium] Stopped 2024-10-07T21:42:35.085Z,1728337355.085 [Default:CheckIn:C.Wait] Running Loop=1 2024-10-07T21:42:35.085Z,1728337355.085 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-10-07T21:43:09.784Z,1728337389.784 [NAL9602](INFO): SBD MO Status=2, MOMSN=57695, MT Status=2, MTMSN=0 2024-10-07T21:43:09.784Z,1728337389.784 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2024-10-07T21:43:53.011Z,1728337433.011 [NAL9602](INFO): SBD MO Status=2, MOMSN=57695, MT Status=2, MTMSN=0 2024-10-07T21:43:53.011Z,1728337433.011 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2024-10-07T21:44:21.292Z,1728337461.292 [NAL9602](INFO): SBD MO Status=0, MOMSN=57695, MT Status=0, MTMSN=0 2024-10-07T21:44:21.292Z,1728337461.292 [NAL9602](INFO): No messages in MT queue 2024-10-07T21:44:51.994Z,1728337491.994 [NAL9602](INFO): Not Powering down - fast GPS 2024-10-07T21:47:35.657Z,1728337655.657 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-10-07T21:47:35.657Z,1728337655.657 [Default:CheckIn:C.Wait] Stopped 2024-10-07T21:47:35.657Z,1728337655.657 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-10-07T21:47:35.657Z,1728337655.657 [Default:CheckIn:D] Running Loop=1 2024-10-07T21:47:36.058Z,1728337656.058 [Default:CheckIn:D] Stopped 2024-10-07T21:47:36.058Z,1728337656.058 [Default:CheckIn:E] Running Loop=1 2024-10-07T21:47:36.463Z,1728337656.463 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 39.669845 min 2024-10-07T21:47:36.463Z,1728337656.463 [Default:CheckIn:E] Stopped 2024-10-07T21:47:36.464Z,1728337656.464 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-10-07T21:47:36.464Z,1728337656.464 [Default:CheckIn] Stopped 2024-10-07T21:47:36.464Z,1728337656.464 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-10-07T21:47:36.464Z,1728337656.464 [Default:CheckIn](INFO): Running loop #7 2024-10-07T21:47:36.464Z,1728337656.464 [Default:CheckIn] Running Loop=7 2024-10-07T21:47:36.464Z,1728337656.464 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-10-07T21:47:36.464Z,1728337656.464 [Default:CheckIn:Read_GPS] Running Loop=1 2024-10-07T21:47:38.519Z,1728337658.519 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,214737.00,A,3648.16516,N,12147.27884,W,0.583,0.00,071024,,,A*7A 2024-10-07T21:47:38.521Z,1728337658.521 [NAL9602](INFO): GPS fix at 20241007T214737: (36.802753, -121.787981) 2024-10-07T21:47:38.532Z,1728337658.532 [Default:CheckIn:Read_GPS] Stopped 2024-10-07T21:47:38.532Z,1728337658.532 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-10-07T21:47:45.549Z,1728337665.549 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20241007T210425/Courier0022.lzma 2024-10-07T21:47:46.551Z,1728337666.551 [DataOverHttps](INFO): Moved sent file to Logs/20241007T210425/Courier0022.lzma.bak 2024-10-07T21:47:46.551Z,1728337666.551 [DataOverHttps](INFO): SBD MOMSN=23274181 2024-10-07T21:48:02.397Z,1728337682.397 [DataOverHttps](INFO): Sending 139 bytes from file Logs/20241007T210425/Express0023.lzma 2024-10-07T21:48:03.399Z,1728337683.399 [DataOverHttps](INFO): Moved sent file to Logs/20241007T210425/Express0023.lzma.bak 2024-10-07T21:48:03.399Z,1728337683.399 [DataOverHttps](INFO): SBD MOMSN=23274184 2024-10-07T21:48:04.766Z,1728337684.766 [Default:CheckIn:Read_Iridium] Stopped 2024-10-07T21:48:04.766Z,1728337684.766 [Default:CheckIn:C.Wait] Running Loop=1 2024-10-07T21:48:04.766Z,1728337684.766 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-10-07T21:50:44.324Z,1728337844.324 [NAL9602](INFO): SBD MO Status=0, MOMSN=57696, MT Status=0, MTMSN=0 2024-10-07T21:50:44.324Z,1728337844.324 [NAL9602](INFO): No messages in MT queue 2024-10-07T21:51:15.030Z,1728337875.030 [NAL9602](INFO): Not Powering down - fast GPS 2024-10-07T21:53:05.348Z,1728337985.348 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-10-07T21:53:05.348Z,1728337985.348 [Default:CheckIn:C.Wait] Stopped 2024-10-07T21:53:05.348Z,1728337985.348 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-10-07T21:53:05.349Z,1728337985.349 [Default:CheckIn:D] Running Loop=1 2024-10-07T21:53:05.746Z,1728337985.746 [Default:CheckIn:D] Stopped 2024-10-07T21:53:05.746Z,1728337985.746 [Default:CheckIn:E] Running Loop=1 2024-10-07T21:53:06.148Z,1728337986.148 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 45.164644 min 2024-10-07T21:53:06.148Z,1728337986.148 [Default:CheckIn:E] Stopped 2024-10-07T21:53:06.148Z,1728337986.148 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-10-07T21:53:06.148Z,1728337986.148 [Default:CheckIn] Stopped 2024-10-07T21:53:06.148Z,1728337986.148 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-10-07T21:53:06.148Z,1728337986.148 [Default:CheckIn](INFO): Running loop #8 2024-10-07T21:53:06.148Z,1728337986.148 [Default:CheckIn] Running Loop=8 2024-10-07T21:53:06.148Z,1728337986.148 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-10-07T21:53:06.149Z,1728337986.149 [Default:CheckIn:Read_GPS] Running Loop=1 2024-10-07T21:53:08.166Z,1728337988.166 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,215307.00,A,3648.17339,N,12147.28203,W,0.350,0.00,071024,,,A*74 2024-10-07T21:53:08.168Z,1728337988.168 [NAL9602](INFO): GPS fix at 20241007T215307: (36.802890, -121.788034) 2024-10-07T21:53:08.187Z,1728337988.187 [Default:CheckIn:Read_GPS] Stopped 2024-10-07T21:53:08.187Z,1728337988.187 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-10-07T21:53:15.121Z,1728337995.121 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20241007T210425/Courier0025.lzma 2024-10-07T21:53:16.123Z,1728337996.123 [DataOverHttps](INFO): Moved sent file to Logs/20241007T210425/Courier0025.lzma.bak 2024-10-07T21:53:16.123Z,1728337996.123 [DataOverHttps](INFO): SBD MOMSN=23274195 2024-10-07T21:53:32.001Z,1728338012.001 [DataOverHttps](INFO): Sending 138 bytes from file Logs/20241007T210425/Express0026.lzma 2024-10-07T21:53:33.003Z,1728338013.003 [DataOverHttps](INFO): Moved sent file to Logs/20241007T210425/Express0026.lzma.bak 2024-10-07T21:53:33.003Z,1728338013.003 [DataOverHttps](INFO): SBD MOMSN=23274198 2024-10-07T21:53:34.426Z,1728338014.426 [Default:CheckIn:Read_Iridium] Stopped 2024-10-07T21:53:34.426Z,1728338014.426 [Default:CheckIn:C.Wait] Running Loop=1 2024-10-07T21:53:34.426Z,1728338014.426 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-10-07T21:53:49.768Z,1728338029.768 [NAL9602](INFO): SBD MO Status=2, MOMSN=57697, MT Status=2, MTMSN=0 2024-10-07T21:53:49.768Z,1728338029.768 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2024-10-07T21:57:41.680Z,1728338261.680 [NAL9602](INFO): SBD MO Status=2, MOMSN=57697, MT Status=2, MTMSN=0 2024-10-07T21:57:41.680Z,1728338261.680 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2024-10-07T21:58:10.363Z,1728338290.363 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2024-10-07T21:58:35.012Z,1728338315.012 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-10-07T21:58:35.012Z,1728338315.012 [Default:CheckIn:C.Wait] Stopped 2024-10-07T21:58:35.013Z,1728338315.013 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-10-07T21:58:35.013Z,1728338315.013 [Default:CheckIn:D] Running Loop=1 2024-10-07T21:58:35.425Z,1728338315.425 [Default:CheckIn:D] Stopped 2024-10-07T21:58:35.425Z,1728338315.425 [Default:CheckIn:E] Running Loop=1 2024-10-07T21:58:35.866Z,1728338315.866 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 50.659294 min 2024-10-07T21:58:35.866Z,1728338315.866 [Default:CheckIn:E] Stopped 2024-10-07T21:58:35.866Z,1728338315.866 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-10-07T21:58:35.866Z,1728338315.866 [Default:CheckIn] Stopped 2024-10-07T21:58:35.866Z,1728338315.866 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-10-07T21:58:35.866Z,1728338315.866 [Default:CheckIn](INFO): Running loop #9 2024-10-07T21:58:35.867Z,1728338315.867 [Default:CheckIn] Running Loop=9 2024-10-07T21:58:35.867Z,1728338315.867 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-10-07T21:58:35.867Z,1728338315.867 [Default:CheckIn:Read_GPS] Running Loop=1 2024-10-07T21:58:37.832Z,1728338317.832 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,215837.00,A,3648.16950,N,12147.28077,W,0.700,0.00,071024,,,A*78 2024-10-07T21:58:37.834Z,1728338317.834 [NAL9602](INFO): GPS fix at 20241007T215837: (36.802825, -121.788013) 2024-10-07T21:58:37.845Z,1728338317.845 [Default:CheckIn:Read_GPS] Stopped 2024-10-07T21:58:37.845Z,1728338317.845 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-10-07T21:58:45.077Z,1728338325.077 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20241007T210425/Courier0028.lzma 2024-10-07T21:58:46.079Z,1728338326.079 [DataOverHttps](INFO): Moved sent file to Logs/20241007T210425/Courier0028.lzma.bak 2024-10-07T21:58:46.079Z,1728338326.079 [DataOverHttps](INFO): SBD MOMSN=23274209 2024-10-07T21:59:04.729Z,1728338344.729 [DataOverHttps](INFO): Sending 214 bytes from file Logs/20241007T210425/Express0029.lzma 2024-10-07T21:59:05.731Z,1728338345.731 [DataOverHttps](INFO): Moved sent file to Logs/20241007T210425/Express0029.lzma.bak 2024-10-07T21:59:05.731Z,1728338345.731 [DataOverHttps](INFO): SBD MOMSN=23274212 2024-10-07T21:59:06.992Z,1728338346.992 [Default:CheckIn:Read_Iridium] Stopped 2024-10-07T21:59:06.992Z,1728338346.992 [Default:CheckIn:C.Wait] Running Loop=1 2024-10-07T21:59:06.993Z,1728338346.993 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-10-07T21:59:10.614Z,1728338350.614 [NAL9602](INFO): Not Powering down - fast GPS 2024-10-07T22:04:07.588Z,1728338647.588 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-10-07T22:04:07.589Z,1728338647.589 [Default:CheckIn:C.Wait] Stopped 2024-10-07T22:04:07.589Z,1728338647.589 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-10-07T22:04:07.589Z,1728338647.589 [Default:CheckIn:D] Running Loop=1 2024-10-07T22:04:07.980Z,1728338647.980 [Default:CheckIn:D] Stopped 2024-10-07T22:04:07.980Z,1728338647.980 [Default:CheckIn:E] Running Loop=1 2024-10-07T22:04:08.385Z,1728338648.385 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 56.201880 min 2024-10-07T22:04:08.385Z,1728338648.385 [Default:CheckIn:E] Stopped 2024-10-07T22:04:08.385Z,1728338648.385 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-10-07T22:04:08.385Z,1728338648.385 [Default:CheckIn] Stopped 2024-10-07T22:04:08.386Z,1728338648.386 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-10-07T22:04:08.386Z,1728338648.386 [Default:CheckIn](INFO): Running loop #10 2024-10-07T22:04:08.386Z,1728338648.386 [Default:CheckIn] Running Loop=10 2024-10-07T22:04:08.386Z,1728338648.386 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-10-07T22:04:08.386Z,1728338648.386 [Default:CheckIn:Read_GPS] Running Loop=1 2024-10-07T22:04:10.410Z,1728338650.410 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,220409.00,A,3648.12446,N,12147.24560,W,0.058,32.37,071024,,,D*44 2024-10-07T22:04:10.412Z,1728338650.412 [NAL9602](INFO): GPS fix at 20241007T220409: (36.802074, -121.787427) 2024-10-07T22:04:10.427Z,1728338650.427 [Default:CheckIn:Read_GPS] Stopped 2024-10-07T22:04:10.427Z,1728338650.427 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-10-07T22:04:17.985Z,1728338657.985 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20241007T210425/Courier0031.lzma 2024-10-07T22:04:18.987Z,1728338658.987 [DataOverHttps](INFO): Moved sent file to Logs/20241007T210425/Courier0031.lzma.bak 2024-10-07T22:04:18.987Z,1728338658.987 [DataOverHttps](INFO): SBD MOMSN=23274223 2024-10-07T22:04:37.625Z,1728338677.625 [DataOverHttps](INFO): Sending 152 bytes from file Logs/20241007T210425/Express0032.lzma 2024-10-07T22:04:39.120Z,1728338679.120 [DataOverHttps](INFO): Moved sent file to Logs/20241007T210425/Express0032.lzma.bak 2024-10-07T22:04:39.120Z,1728338679.120 [DataOverHttps](INFO): SBD MOMSN=23274226 2024-10-07T22:04:39.956Z,1728338679.956 [Default:CheckIn:Read_Iridium] Stopped 2024-10-07T22:04:39.956Z,1728338679.956 [Default:CheckIn:C.Wait] Running Loop=1 2024-10-07T22:04:39.956Z,1728338679.956 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-10-07T22:04:41.150Z,1728338681.150 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2024-10-07T22:04:41.225Z,1728338681.225 [NAL9602](ERROR): received: +CSQ:0 OK697, 2, 0, 0, 0 OK 2024-10-07T22:04:52.857Z,1728338692.857 [NAL9602](INFO): SBD MO Status=0, MOMSN=57697, MT Status=0, MTMSN=0 2024-10-07T22:04:52.858Z,1728338692.858 [NAL9602](INFO): No messages in MT queue 2024-10-07T22:05:23.571Z,1728338723.571 [NAL9602](INFO): Not Powering down - fast GPS 2024-10-07T22:09:40.518Z,1728338980.518 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-10-07T22:09:40.518Z,1728338980.518 [Default:CheckIn:C.Wait] Stopped 2024-10-07T22:09:40.518Z,1728338980.518 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-10-07T22:09:40.518Z,1728338980.518 [Default:CheckIn:D] Running Loop=1 2024-10-07T22:09:40.923Z,1728338980.923 [Default:CheckIn:D] Stopped 2024-10-07T22:09:40.923Z,1728338980.923 [Default:CheckIn:E] Running Loop=1 2024-10-07T22:09:41.343Z,1728338981.343 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 61.750920 min 2024-10-07T22:09:41.343Z,1728338981.343 [Default:CheckIn:E] Stopped 2024-10-07T22:09:41.344Z,1728338981.344 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-10-07T22:09:41.344Z,1728338981.344 [Default:CheckIn] Stopped 2024-10-07T22:09:41.344Z,1728338981.344 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-10-07T22:09:41.344Z,1728338981.344 [Default:CheckIn](INFO): Running loop #11 2024-10-07T22:09:41.344Z,1728338981.344 [Default:CheckIn] Running Loop=11 2024-10-07T22:09:41.344Z,1728338981.344 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-10-07T22:09:41.344Z,1728338981.344 [Default:CheckIn:Read_GPS] Running Loop=1 2024-10-07T22:09:43.388Z,1728338983.388 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,220942.00,A,3648.11915,N,12147.23131,W,0.097,120.60,071024,,,D*7A 2024-10-07T22:09:43.421Z,1728338983.421 [NAL9602](INFO): GPS fix at 20241007T220942: (36.801986, -121.787188) 2024-10-07T22:09:43.496Z,1728338983.496 [Default:CheckIn:Read_GPS] Stopped 2024-10-07T22:09:43.497Z,1728338983.497 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-10-07T22:09:50.697Z,1728338990.697 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20241007T210425/Courier0034.lzma 2024-10-07T22:09:51.699Z,1728338991.699 [DataOverHttps](INFO): Moved sent file to Logs/20241007T210425/Courier0034.lzma.bak 2024-10-07T22:09:51.699Z,1728338991.699 [DataOverHttps](INFO): SBD MOMSN=23274237 2024-10-07T22:09:59.101Z,1728338999.101 [NAL9602](INFO): SBD MO Status=0, MOMSN=57698, MT Status=0, MTMSN=0 2024-10-07T22:09:59.101Z,1728338999.101 [NAL9602](INFO): No messages in MT queue 2024-10-07T22:10:07.605Z,1728339007.605 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20241007T210425/Express0035.lzma 2024-10-07T22:10:08.612Z,1728339008.612 [DataOverHttps](INFO): Moved sent file to Logs/20241007T210425/Express0035.lzma.bak 2024-10-07T22:10:08.612Z,1728339008.612 [DataOverHttps](INFO): SBD MOMSN=23274240 2024-10-07T22:10:10.018Z,1728339010.018 [Default:CheckIn:Read_Iridium] Stopped 2024-10-07T22:10:10.018Z,1728339010.018 [Default:CheckIn:C.Wait] Running Loop=1 2024-10-07T22:10:10.018Z,1728339010.018 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-10-07T22:10:29.794Z,1728339029.794 [NAL9602](INFO): Not Powering down - fast GPS 2024-10-07T22:15:10.678Z,1728339310.678 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-10-07T22:15:10.678Z,1728339310.678 [Default:CheckIn:C.Wait] Stopped 2024-10-07T22:15:10.679Z,1728339310.679 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-10-07T22:15:10.679Z,1728339310.679 [Default:CheckIn:D] Running Loop=1 2024-10-07T22:15:11.094Z,1728339311.094 [Default:CheckIn:D] Stopped 2024-10-07T22:15:11.094Z,1728339311.094 [Default:CheckIn:E] Running Loop=1 2024-10-07T22:15:11.481Z,1728339311.481 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 67.253780 min 2024-10-07T22:15:11.482Z,1728339311.482 [Default:CheckIn:E] Stopped 2024-10-07T22:15:11.482Z,1728339311.482 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-10-07T22:15:11.482Z,1728339311.482 [Default:CheckIn] Stopped 2024-10-07T22:15:11.482Z,1728339311.482 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-10-07T22:15:11.482Z,1728339311.482 [Default:CheckIn](INFO): Running loop #12 2024-10-07T22:15:11.482Z,1728339311.482 [Default:CheckIn] Running Loop=12 2024-10-07T22:15:11.482Z,1728339311.482 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-10-07T22:15:11.482Z,1728339311.482 [Default:CheckIn:Read_GPS] Running Loop=1 2024-10-07T22:15:13.490Z,1728339313.490 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,221512.00,A,3648.11960,N,12147.23062,W,0.078,120.60,071024,,,D*76 2024-10-07T22:15:13.492Z,1728339313.492 [NAL9602](INFO): GPS fix at 20241007T221512: (36.801993, -121.787177) 2024-10-07T22:15:13.503Z,1728339313.503 [Default:CheckIn:Read_GPS] Stopped 2024-10-07T22:15:13.503Z,1728339313.503 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-10-07T22:15:21.461Z,1728339321.461 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20241007T210425/Courier0037.lzma 2024-10-07T22:15:22.463Z,1728339322.463 [DataOverHttps](INFO): Moved sent file to Logs/20241007T210425/Courier0037.lzma.bak 2024-10-07T22:15:22.464Z,1728339322.464 [DataOverHttps](IMPORTANT): SBD MOMSN=23274252, MTMSN=20241007T221521 2024-10-07T22:15:29.898Z,1728339329.898 [DataOverHttps](INFO): Received command: ibit 2024-10-07T22:15:29.962Z,1728339329.962 [CommandExec](IMPORTANT): got command ibit 2024-10-07T22:15:30.081Z,1728339330.081 [IBIT](IMPORTANT): Beginning Initiated BIT 2024-10-07T22:15:30.081Z,1728339330.081 [IBIT](IMPORTANT): Beginning control surface checks. 2024-10-07T22:15:30.084Z,1728339330.084 [CBIT](IMPORTANT): Beginning ground fault scan 2024-10-07T22:15:32.885Z,1728339332.885 [NAL9602](INFO): SBD MO Status=2, MOMSN=57699, MT Status=2, MTMSN=0 2024-10-07T22:15:32.885Z,1728339332.885 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2024-10-07T22:15:38.653Z,1728339338.653 [DataOverHttps](INFO): Sending 140 bytes from file Logs/20241007T210425/Express0038.lzma 2024-10-07T22:15:39.655Z,1728339339.655 [DataOverHttps](INFO): Moved sent file to Logs/20241007T210425/Express0038.lzma.bak 2024-10-07T22:15:39.655Z,1728339339.655 [DataOverHttps](INFO): SBD MOMSN=23274256 2024-10-07T22:15:40.990Z,1728339340.990 [CBIT](ERROR): Ground fault scan returned out of bounds value. Re-running scan. 2024-10-07T22:15:41.406Z,1728339341.406 [CBIT](IMPORTANT): Beginning ground fault scan 2024-10-07T22:15:44.192Z,1728339344.192 [NAL9602](INFO): SBD MO Status=0, MOMSN=57699, MT Status=0, MTMSN=0 2024-10-07T22:15:44.192Z,1728339344.192 [NAL9602](INFO): No messages in MT queue 2024-10-07T22:15:45.404Z,1728339345.404 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,221544.00,A,3648.11898,N,12147.23073,W,0.408,120.60,071024,,,D*70 2024-10-07T22:15:45.414Z,1728339345.414 [NAL9602](INFO): GPS fix at 20241007T221544: (36.801983, -121.787179) 2024-10-07T22:15:48.238Z,1728339348.238 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,221547.00,A,3648.11864,N,12147.23051,W,0.058,120.60,071024,,,D*71 2024-10-07T22:15:48.240Z,1728339348.240 [NAL9602](INFO): GPS fix at 20241007T221547: (36.801977, -121.787175) 2024-10-07T22:15:51.061Z,1728339351.061 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,221550.00,A,3648.11838,N,12147.23027,W,0.039,120.60,071024,,,D*78 2024-10-07T22:15:51.064Z,1728339351.064 [NAL9602](INFO): GPS fix at 20241007T221550: (36.801973, -121.787171) 2024-10-07T22:15:52.394Z,1728339352.394 [CBIT](ERROR): Ground fault scan returned out of bounds value. Re-running scan. 2024-10-07T22:15:52.914Z,1728339352.914 [CBIT](IMPORTANT): Beginning ground fault scan 2024-10-07T22:15:53.888Z,1728339353.888 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,221553.00,A,3648.11832,N,12147.23025,W,0.039,120.60,071024,,,D*73 2024-10-07T22:15:53.890Z,1728339353.890 [NAL9602](INFO): GPS fix at 20241007T221553: (36.801972, -121.787171) 2024-10-07T22:15:56.145Z,1728339356.145 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20241007T210425/Courier0040.lzma 2024-10-07T22:15:57.124Z,1728339357.124 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,221556.00,A,3648.11834,N,12147.23025,W,0.019,120.60,071024,,,D*72 2024-10-07T22:15:57.127Z,1728339357.127 [NAL9602](INFO): GPS fix at 20241007T221556: (36.801972, -121.787171) 2024-10-07T22:15:57.147Z,1728339357.147 [DataOverHttps](INFO): Moved sent file to Logs/20241007T210425/Courier0040.lzma.bak 2024-10-07T22:15:57.147Z,1728339357.147 [DataOverHttps](INFO): SBD MOMSN=23274259 2024-10-07T22:15:59.947Z,1728339359.947 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,221559.00,A,3648.11836,N,12147.23027,W,0.019,120.60,071024,,,D*7D 2024-10-07T22:15:59.950Z,1728339359.950 [NAL9602](INFO): GPS fix at 20241007T221559: (36.801973, -121.787171) 2024-10-07T22:16:03.184Z,1728339363.184 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,221602.00,A,3648.11837,N,12147.23029,W,0.058,120.60,071024,,,D*7A 2024-10-07T22:16:03.186Z,1728339363.186 [NAL9602](INFO): GPS fix at 20241007T221602: (36.801973, -121.787171) 2024-10-07T22:16:03.705Z,1728339363.705 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.002575 CHAN A1 (24V): 0.000393 CHAN A2 (12V): -0.002465 CHAN A3 (5V): -0.001154 CHAN B0 (3.3V): 0.000535 CHAN B1 (3.15aV): -0.000158 CHAN B2 (3.15bV): -0.000408 CHAN B3 (GND): 0.000471 OPEN: -0.000336 Full Scale: +/- 1 mA 2024-10-07T22:16:06.019Z,1728339366.019 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,221605.00,A,3648.11840,N,12147.23031,W,0.019,120.60,071024,,,D*71 2024-10-07T22:16:06.022Z,1728339366.022 [NAL9602](INFO): GPS fix at 20241007T221605: (36.801973, -121.787172) 2024-10-07T22:16:09.254Z,1728339369.254 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,221608.00,A,3648.11851,N,12147.23037,W,0.058,120.60,071024,,,D*7F 2024-10-07T22:16:09.256Z,1728339369.256 [NAL9602](INFO): GPS fix at 20241007T221608: (36.801975, -121.787173) 2024-10-07T22:16:12.072Z,1728339372.072 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,221611.00,A,3648.11857,N,12147.23031,W,0.019,120.60,071024,,,D*72 2024-10-07T22:16:12.074Z,1728339372.074 [NAL9602](INFO): GPS fix at 20241007T221611: (36.801976, -121.787172) 2024-10-07T22:16:13.761Z,1728339373.761 [DataOverHttps](INFO): Sending 254 bytes from file Logs/20241007T210425/Express0041.lzma 2024-10-07T22:16:14.763Z,1728339374.763 [DataOverHttps](INFO): Moved sent file to Logs/20241007T210425/Express0041.lzma.bak 2024-10-07T22:16:14.763Z,1728339374.763 [DataOverHttps](INFO): SBD MOMSN=23274262 2024-10-07T22:16:14.900Z,1728339374.900 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,221614.00,A,3648.11858,N,12147.23036,W,0.039,120.60,071024,,,D*7D 2024-10-07T22:16:14.903Z,1728339374.903 [NAL9602](INFO): GPS fix at 20241007T221614: (36.801976, -121.787173) 2024-10-07T22:16:16.536Z,1728339376.536 [IBIT](IMPORTANT): Communications Status: Fix Status: 1 Iridium Signal Strength: 4 Latitude: 36.801975 Longitude: -121.787170 2024-10-07T22:16:17.013Z,1728339377.013 [IBIT](IMPORTANT): Battery Status: Battery Charge (AH): 0.000000 Voltage: 15.422000 2024-10-07T22:16:17.013Z,1728339377.013 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah 2024-10-07T22:16:17.066Z,1728339377.066 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V 2024-10-07T22:16:17.359Z,1728339377.359 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 % 2024-10-07T22:16:17.359Z,1728339377.359 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi 2024-10-07T22:16:17.359Z,1728339377.359 [IBIT](IMPORTANT): Pressure:10.443043 PSI 2024-10-07T22:16:17.360Z,1728339377.360 [IBIT](IMPORTANT): Humidity:15.999268 % 2024-10-07T22:16:17.768Z,1728339377.768 [IBIT](IMPORTANT): Vehicle Pitch:0.955059 degrees 2024-10-07T22:16:17.768Z,1728339377.768 [IBIT](IMPORTANT): Vehicle Roll:-8.084790 degrees 2024-10-07T22:16:17.769Z,1728339377.769 [IBIT](IMPORTANT): Vehicle Heading:281.201569 degrees 2024-10-07T22:16:18.181Z,1728339378.181 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m 2024-10-07T22:16:18.181Z,1728339378.181 [IBIT](IMPORTANT): buoyancyNeutral: 307.000000 cc 2024-10-07T22:16:18.213Z,1728339378.213 [IBIT](IMPORTANT): massDefault: -0.062388 cm 2024-10-07T22:16:18.214Z,1728339378.214 [IBIT](IMPORTANT): stopDepth: 250.000000 m 2024-10-07T22:16:18.214Z,1728339378.214 [IBIT](IMPORTANT): abortDepth: 270.000000 m 2024-10-07T22:16:18.214Z,1728339378.214 [IBIT](IMPORTANT): IBIT PASSED 2024-10-07T22:16:18.618Z,1728339378.618 [Default:CheckIn:Read_Iridium] Stopped 2024-10-07T22:16:18.618Z,1728339378.618 [Default:CheckIn:C.Wait] Running Loop=1 2024-10-07T22:16:18.618Z,1728339378.618 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-10-07T22:16:47.682Z,1728339407.682 [NAL9602](INFO): Not Powering down - fast GPS 2024-10-07T22:21:19.229Z,1728339679.229 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-10-07T22:21:19.229Z,1728339679.229 [Default:CheckIn:C.Wait] Stopped 2024-10-07T22:21:19.229Z,1728339679.229 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-10-07T22:21:19.229Z,1728339679.229 [Default:CheckIn:D] Running Loop=1 2024-10-07T22:21:19.628Z,1728339679.628 [Default:CheckIn:D] Stopped 2024-10-07T22:21:19.628Z,1728339679.628 [Default:CheckIn:E] Running Loop=1 2024-10-07T22:21:20.037Z,1728339680.037 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 73.396004 min 2024-10-07T22:21:20.037Z,1728339680.037 [Default:CheckIn:E] Stopped 2024-10-07T22:21:20.037Z,1728339680.037 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-10-07T22:21:20.038Z,1728339680.038 [Default:CheckIn] Stopped 2024-10-07T22:21:20.038Z,1728339680.038 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-10-07T22:21:20.038Z,1728339680.038 [Default:CheckIn](INFO): Running loop #13 2024-10-07T22:21:20.038Z,1728339680.038 [Default:CheckIn] Running Loop=13 2024-10-07T22:21:20.038Z,1728339680.038 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-10-07T22:21:20.038Z,1728339680.038 [Default:CheckIn:Read_GPS] Running Loop=1 2024-10-07T22:21:22.043Z,1728339682.043 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,222121.00,A,3648.29811,N,12147.12383,W,4.451,8.16,071024,,,D*72 2024-10-07T22:21:22.046Z,1728339682.046 [NAL9602](INFO): GPS fix at 20241007T222121: (36.804969, -121.785397) 2024-10-07T22:21:22.081Z,1728339682.081 [Default:CheckIn:Read_GPS] Stopped 2024-10-07T22:21:22.081Z,1728339682.081 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-10-07T22:21:29.489Z,1728339689.489 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20241007T210425/Courier0043.lzma 2024-10-07T22:21:30.491Z,1728339690.491 [DataOverHttps](INFO): Moved sent file to Logs/20241007T210425/Courier0043.lzma.bak 2024-10-07T22:21:30.491Z,1728339690.491 [DataOverHttps](INFO): SBD MOMSN=23274276 2024-10-07T22:21:45.076Z,1728339705.076 [NAL9602](INFO): SBD MO Status=2, MOMSN=57700, MT Status=2, MTMSN=0 2024-10-07T22:21:45.076Z,1728339705.076 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2024-10-07T22:21:46.718Z,1728339706.718 [DataOverHttps](INFO): Sending 724 bytes from file Logs/20241007T210425/Express0044.lzma 2024-10-07T22:21:47.719Z,1728339707.719 [DataOverHttps](INFO): Moved sent file to Logs/20241007T210425/Express0044.lzma.bak 2024-10-07T22:21:47.719Z,1728339707.719 [DataOverHttps](INFO): SBD MOMSN=23274279 2024-10-07T22:21:49.142Z,1728339709.142 [Default:CheckIn:Read_Iridium] Stopped 2024-10-07T22:21:49.143Z,1728339709.143 [Default:CheckIn:C.Wait] Running Loop=1 2024-10-07T22:21:49.143Z,1728339709.143 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-10-07T22:22:29.560Z,1728339749.560 [NAL9602](INFO): SBD MO Status=0, MOMSN=57700, MT Status=0, MTMSN=0 2024-10-07T22:22:29.560Z,1728339749.560 [NAL9602](INFO): No messages in MT queue 2024-10-07T22:23:00.293Z,1728339780.293 [NAL9602](INFO): Not Powering down - fast GPS 2024-10-07T22:26:49.789Z,1728340009.789 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-10-07T22:26:49.789Z,1728340009.789 [Default:CheckIn:C.Wait] Stopped 2024-10-07T22:26:49.789Z,1728340009.789 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-10-07T22:26:49.789Z,1728340009.789 [Default:CheckIn:D] Running Loop=1 2024-10-07T22:26:50.201Z,1728340010.201 [Default:CheckIn:D] Stopped 2024-10-07T22:26:50.201Z,1728340010.201 [Default:CheckIn:E] Running Loop=1 2024-10-07T22:26:50.622Z,1728340010.622 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 78.905550 min 2024-10-07T22:26:50.622Z,1728340010.622 [Default:CheckIn:E] Stopped 2024-10-07T22:26:50.622Z,1728340010.622 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-10-07T22:26:50.622Z,1728340010.622 [Default:CheckIn] Stopped 2024-10-07T22:26:50.622Z,1728340010.622 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-10-07T22:26:50.623Z,1728340010.623 [Default:CheckIn](INFO): Running loop #14 2024-10-07T22:26:50.623Z,1728340010.623 [Default:CheckIn] Running Loop=14 2024-10-07T22:26:50.623Z,1728340010.623 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-10-07T22:26:50.623Z,1728340010.623 [Default:CheckIn:Read_GPS] Running Loop=1 2024-10-07T22:26:52.600Z,1728340012.600 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,222651.00,A,3648.42669,N,12147.35499,W,8.631,235.35,071024,,,D*72 2024-10-07T22:26:52.603Z,1728340012.603 [NAL9602](INFO): GPS fix at 20241007T222651: (36.807111, -121.789250) 2024-10-07T22:26:52.672Z,1728340012.672 [Default:CheckIn:Read_GPS] Stopped 2024-10-07T22:26:52.672Z,1728340012.672 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-10-07T22:27:01.089Z,1728340021.089 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20241007T210425/Courier0046.lzma 2024-10-07T22:27:02.091Z,1728340022.091 [DataOverHttps](INFO): Moved sent file to Logs/20241007T210425/Courier0046.lzma.bak 2024-10-07T22:27:02.091Z,1728340022.091 [DataOverHttps](INFO): SBD MOMSN=23274340 2024-10-07T22:27:18.269Z,1728340038.269 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20241007T210425/Express0047.lzma 2024-10-07T22:27:19.271Z,1728340039.271 [DataOverHttps](INFO): Moved sent file to Logs/20241007T210425/Express0047.lzma.bak 2024-10-07T22:27:19.271Z,1728340039.271 [DataOverHttps](INFO): SBD MOMSN=23274343 2024-10-07T22:27:20.574Z,1728340040.574 [Default:CheckIn:Read_Iridium] Stopped 2024-10-07T22:27:20.574Z,1728340040.574 [Default:CheckIn:C.Wait] Running Loop=1 2024-10-07T22:27:20.574Z,1728340040.574 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-10-07T22:27:20.972Z,1728340040.972 [NAL9602](INFO): SBD MO Status=0, MOMSN=57701, MT Status=0, MTMSN=0 2024-10-07T22:27:20.972Z,1728340040.972 [NAL9602](INFO): No messages in MT queue 2024-10-07T22:27:51.670Z,1728340071.670 [NAL9602](INFO): Not Powering down - fast GPS 2024-10-07T22:32:21.189Z,1728340341.189 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-10-07T22:32:21.189Z,1728340341.189 [Default:CheckIn:C.Wait] Stopped 2024-10-07T22:32:21.189Z,1728340341.189 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-10-07T22:32:21.189Z,1728340341.189 [Default:CheckIn:D] Running Loop=1 2024-10-07T22:32:21.598Z,1728340341.598 [Default:CheckIn:D] Stopped 2024-10-07T22:32:21.598Z,1728340341.598 [Default:CheckIn:E] Running Loop=1 2024-10-07T22:32:22.014Z,1728340342.014 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 84.428841 min 2024-10-07T22:32:22.014Z,1728340342.014 [Default:CheckIn:E] Stopped 2024-10-07T22:32:22.015Z,1728340342.015 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-10-07T22:32:22.015Z,1728340342.015 [Default:CheckIn] Stopped 2024-10-07T22:32:22.015Z,1728340342.015 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-10-07T22:32:22.015Z,1728340342.015 [Default:CheckIn](INFO): Running loop #15 2024-10-07T22:32:22.015Z,1728340342.015 [Default:CheckIn] Running Loop=15 2024-10-07T22:32:22.015Z,1728340342.015 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-10-07T22:32:22.015Z,1728340342.015 [Default:CheckIn:Read_GPS] Running Loop=1 2024-10-07T22:32:23.998Z,1728340343.998 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,223223.00,A,3648.30440,N,12148.33628,W,11.333,248.57,071024,,,D*4E 2024-10-07T22:32:24.000Z,1728340344.000 [NAL9602](INFO): GPS fix at 20241007T223223: (36.805073, -121.805605) 2024-10-07T22:32:24.019Z,1728340344.019 [Default:CheckIn:Read_GPS] Stopped 2024-10-07T22:32:24.019Z,1728340344.019 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-10-07T22:32:32.061Z,1728340352.061 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20241007T210425/Courier0049.lzma 2024-10-07T22:32:33.063Z,1728340353.063 [DataOverHttps](INFO): Moved sent file to Logs/20241007T210425/Courier0049.lzma.bak 2024-10-07T22:32:33.063Z,1728340353.063 [DataOverHttps](INFO): SBD MOMSN=23274354 2024-10-07T22:32:40.567Z,1728340360.567 [NAL9602](INFO): SBD MO Status=0, MOMSN=57702, MT Status=0, MTMSN=0 2024-10-07T22:32:40.567Z,1728340360.567 [NAL9602](INFO): No messages in MT queue 2024-10-07T22:32:50.749Z,1728340370.749 [DataOverHttps](INFO): Sending 155 bytes from file Logs/20241007T210425/Express0050.lzma 2024-10-07T22:32:51.752Z,1728340371.752 [DataOverHttps](INFO): Moved sent file to Logs/20241007T210425/Express0050.lzma.bak 2024-10-07T22:32:51.752Z,1728340371.752 [DataOverHttps](INFO): SBD MOMSN=23274357 2024-10-07T22:32:53.525Z,1728340373.525 [Default:CheckIn:Read_Iridium] Stopped 2024-10-07T22:32:53.525Z,1728340373.525 [Default:CheckIn:C.Wait] Running Loop=1 2024-10-07T22:32:53.525Z,1728340373.525 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-10-07T22:33:11.302Z,1728340391.302 [NAL9602](INFO): Not Powering down - fast GPS 2024-10-07T22:35:02.951Z,1728340502.951 [DataOverHttps](IMPORTANT): SBD MTMSN=20241007T223501 2024-10-07T22:35:10.545Z,1728340510.545 [DataOverHttps](INFO): Received command: load Transport/transit.tl;set transit.NeedCommsTime 15 min;set transit.Latitude 36.797 degree;set transit.Longitude -121.847 degree;run 2024-10-07T22:35:10.627Z,1728340510.627 [CommandExec](IMPORTANT): got command load ./Missions/Transport/transit.tl 2024-10-07T22:35:10.627Z,1728340510.627 [MissionManager](INFO): Loading Mission from file: ./Missions/Transport/transit.tl 2024-10-07T22:35:10.628Z,1728340510.628 [MissionManager](DEBUG): TethyslAPI: loading: ./Missions/Transport/transit.tl 2024-10-07T22:35:10.630Z,1728340510.630 [MissionManager](DEBUG): TethyslAPI: mission file loaded: ./Missions/Transport/transit.tl 2024-10-07T22:35:11.302Z,1728340511.302 [MissionManager](DEBUG): TethyslAPI: ./Missions/Transport/transit.tl translated into: 60 30 NaN NaN 0 0 10 1 20 1 7 1 2024-10-07T22:35:11.311Z,1728340511.311 [MissionManager](INFO): DefineArg transit.MissionTimeout = 60.000000 min 2024-10-07T22:35:11.315Z,1728340511.315 [MissionManager](INFO): DefineArg transit.NeedCommsTime = 30.000000 min 2024-10-07T22:35:11.319Z,1728340511.319 [MissionManager](INFO): DefineArg transit.Latitude = nan arcdeg 2024-10-07T22:35:11.342Z,1728340511.342 [MissionManager](INFO): DefineArg transit.Longitude = nan arcdeg 2024-10-07T22:35:11.345Z,1728340511.345 [MissionManager](INFO): DefineArg transit.Northings = 0.000000 m 2024-10-07T22:35:11.360Z,1728340511.360 [MissionManager](INFO): DefineArg transit.Eastings = 0.000000 m 2024-10-07T22:35:11.363Z,1728340511.363 [MissionManager](INFO): DefineArg transit.Depth = 10.000000 m 2024-10-07T22:35:11.370Z,1728340511.370 [MissionManager](INFO): DefineArg transit.Speed = 1.000000 m/s 2024-10-07T22:35:11.373Z,1728340511.373 [MissionManager](INFO): DefineArg transit.MaxDepth = 20.000000 m 2024-10-07T22:35:11.380Z,1728340511.380 [MissionManager](INFO): DefineArg transit.MinOffshore = 1.000000 km 2024-10-07T22:35:11.383Z,1728340511.383 [MissionManager](INFO): DefineArg transit.MinAltitude = 7.000000 m 2024-10-07T22:35:11.400Z,1728340511.400 [MissionManager](INFO): DefineArg transit.MassHold = 1 bool 2024-10-07T22:35:11.407Z,1728340511.407 [MissionManager](INFO): DefineArg transit.BuoyancyHold = 1 bool 2024-10-07T22:35:11.407Z,1728340511.407 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/NeedComms.tl 2024-10-07T22:35:11.407Z,1728340511.407 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/NeedComms.tl 2024-10-07T22:35:11.408Z,1728340511.408 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/NeedComms.tl 2024-10-07T22:35:11.912Z,1728340511.912 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/NeedComms.tl translated into: 1 10 20 NaN 1 1000 7 30 0 last time_fix was: first GPS update timeout Comms timed out after minutes second GPS update timeout 2024-10-07T22:35:11.918Z,1728340511.918 [MissionManager](INFO): DefineArg transit:NeedComms.DiveInterval = 1.000000 h 2024-10-07T22:35:11.921Z,1728340511.921 [MissionManager](INFO): DefineArg transit:NeedComms.WaitForPitchUp = 10.000000 min 2024-10-07T22:35:11.924Z,1728340511.924 [MissionManager](INFO): DefineArg transit:NeedComms.SurfacePitch = 20.000000 arcdeg 2024-10-07T22:35:11.927Z,1728340511.927 [MissionManager](INFO): DefineArg transit:NeedComms.SurfaceDepthRate = nan m/s 2024-10-07T22:35:11.930Z,1728340511.930 [MissionManager](INFO): DefineArg transit:NeedComms.SurfaceSpeed = 1.000000 m/s 2024-10-07T22:35:11.932Z,1728340511.932 [MissionManager](INFO): DefineArg transit:NeedComms.SurfacingTimeout = 1000.000000 s 2024-10-07T22:35:11.935Z,1728340511.935 [MissionManager](INFO): DefineArg transit:NeedComms.GPSTimeout = 7.000000 min 2024-10-07T22:35:11.990Z,1728340511.990 [MissionManager](INFO): DefineArg transit:NeedComms.CommsTimeout = 30.000000 min 2024-10-07T22:35:12.009Z,1728340512.009 [transit:NeedComms:B.GoToSurface](DEBUG): Construct GoToSurface. 2024-10-07T22:35:12.058Z,1728340512.058 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/StandardEnvelopes.tl 2024-10-07T22:35:12.058Z,1728340512.058 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/StandardEnvelopes.tl 2024-10-07T22:35:12.059Z,1728340512.059 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/StandardEnvelopes.tl 2024-10-07T22:35:12.273Z,1728340512.273 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/StandardEnvelopes.tl translated into: 5 0 200 2000 2024-10-07T22:35:12.279Z,1728340512.279 [MissionManager](INFO): DefineArg transit:StandardEnvelopes.MinAltitude = 5.000000 m 2024-10-07T22:35:12.282Z,1728340512.282 [MissionManager](INFO): DefineArg transit:StandardEnvelopes.MaxDepthIgnore = 0.000000 m 2024-10-07T22:35:12.285Z,1728340512.285 [MissionManager](INFO): DefineArg transit:StandardEnvelopes.MaxDepth = 200.000000 m 2024-10-07T22:35:12.288Z,1728340512.288 [MissionManager](INFO): DefineArg transit:StandardEnvelopes.MinOffshore = 2000.000000 m 2024-10-07T22:35:12.289Z,1728340512.289 [transit:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope. 2024-10-07T22:35:12.325Z,1728340512.325 [transit:StandardEnvelopes:B.DepthEnvelope](DEBUG): Construct DepthEnvelope. 2024-10-07T22:35:12.346Z,1728340512.346 [transit:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Construct OffshoreEnvelope. 2024-10-07T22:35:12.369Z,1728340512.369 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/BackseatDriver.tl 2024-10-07T22:35:12.369Z,1728340512.369 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/BackseatDriver.tl 2024-10-07T22:35:12.370Z,1728340512.370 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/BackseatDriver.tl 2024-10-07T22:35:12.396Z,1728340512.396 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/BackseatDriver.tl translated into: 2024-10-07T22:35:12.444Z,1728340512.444 [MissionManager](INFO): DefineArg transit:BackseatDriver.EnableBackseat = 0 bool 2024-10-07T22:35:13.269Z,1728340513.269 [transit:BackseatDriver:A.BackseatDriver](DEBUG): Construct BackseatDriver. 2024-10-07T22:35:13.276Z,1728340513.276 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/PowerOnly.tl 2024-10-07T22:35:13.276Z,1728340513.276 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/PowerOnly.tl 2024-10-07T22:35:13.278Z,1728340513.278 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/PowerOnly.tl 2024-10-07T22:35:13.496Z,1728340513.496 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/PowerOnly.tl translated into: 99999 2024-10-07T22:35:13.500Z,1728340513.500 [MissionManager](INFO): DefineArg transit:PowerOnly.SampleAll = 0 bool 2024-10-07T22:35:13.503Z,1728340513.503 [MissionManager](INFO): DefineArg transit:PowerOnly.SampleLoad1 = 0 bool 2024-10-07T22:35:13.505Z,1728340513.505 [MissionManager](INFO): DefineArg transit:PowerOnly.SampleLoad2 = 0 bool 2024-10-07T22:35:13.508Z,1728340513.508 [MissionManager](INFO): DefineArg transit:PowerOnly.SampleLoad3 = 0 bool 2024-10-07T22:35:13.523Z,1728340513.523 [MissionManager](INFO): DefineArg transit:PowerOnly.EnabledPowerOnly = 1 bool 2024-10-07T22:35:13.558Z,1728340513.558 [transit:PowerOnly:E.Wait](DEBUG): Construct Wait. 2024-10-07T22:35:13.560Z,1728340513.560 [transit:BuoyancyHold.Buoyancy](DEBUG): Construct Buoyancy. 2024-10-07T22:35:13.576Z,1728340513.576 [transit:MassHold.Pitch](DEBUG): Construct. 2024-10-07T22:35:13.606Z,1728340513.606 [transit:Transit:A.Pitch](DEBUG): Construct. 2024-10-07T22:35:13.631Z,1728340513.631 [transit:Transit:B.SetSpeed](DEBUG): Construct. 2024-10-07T22:35:13.659Z,1728340513.659 [transit:Transit:Wpt1.Waypoint](DEBUG): Construct Waypoint. 2024-10-07T22:35:13.742Z,1728340513.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 transit { """ Vehicle transits to desired waypoint and can be commanded to use/hold mass or buoyancy. """ arguments { MissionTimeout = 60 minute """ Maximum duration of mission """ NeedCommsTime = 30 minute """ How often to surface for commumications """ Latitude = NaN degree """ Latitude of waypoint to seek. If set to NaN, uses latitude at mission initialization. """ Longitude = NaN degree """ Longitude of waypoint to seek. If set to NaN, uses longitude at mission initialization. """ Northings = 0 meter """ Northward distance of the waypoint to seek. If combined with Latitude and/or Longitude, this is an offset from the specified Latitude and/or Longitude. """ Eastings = 0 meter """ Eastward distance of the waypoint to seek. If combined with Latitude and/or Longitude, this is an offset from the specified Latitude and/or Longitude. """ Depth = 10 meter """ Depth of flat and level flight during the mission. """ Speed = 1 meter_per_second """ Speed of vehicle (relative to water) during the mission. """ MaxDepth = 20 meter """ Maximum depth for the entire mission. """ MinOffshore = 1 kilometer """ Minimum distance offshore for the entire mission. """ MinAltitude = 7 meter """ Minimum height above the sea floor for the entire mission. """ MassHold = true """ Set to True in order to hold mass at default position, False to allow mass to run on its own. """ BuoyancyHold = true """ Set to True in order to hold buoyancy at neutral position, False to allow buoyancy to run on its own. """ } timeout duration=MissionTimeout insert id="NeedComms" Insert/NeedComms.tl assign in sequence NeedComms:DiveInterval = NeedCommsTime assign in sequence NeedComms:WaitForPitchUp = 1 second insert Insert/StandardEnvelopes.tl assign in sequence StandardEnvelopes:MinAltitude = MinAltitude assign in sequence StandardEnvelopes:MaxDepth = MaxDepth assign in sequence StandardEnvelopes:MinOffshore = MinOffshore insert Insert/BackseatDriver.tl insert Insert/PowerOnly.tl behavior Guidance:Buoyancy id="BuoyancyHold" { run while ( BuoyancyHold ) set position = Control:VerticalControl.buoyancyNeutral } behavior Guidance:Pitch id="MassHold" { run while ( MassHold ) set massPosition = Control:VerticalControl.massDefault } aggregate Transit { run in sequence behavior Guidance:Pitch { run in parallel set depth = Depth } behavior Guidance:SetSpeed { run in parallel set speed = Speed } behavior Guidance:Waypoint id="Wpt1" { run in sequence set latitude = Latitude set longitude = Longitude set northingsDelta = Northings set eastingsDelta = Eastings } call id="PhoneHome" refId="NeedComms" } } 2024-10-07T22:35:13.743Z,1728340513.743 [CommandExec](IMPORTANT): Loaded ./Missions/Transport/transit.tl id=transit 2024-10-07T22:35:17.905Z,1728340517.905 [CommandExec](IMPORTANT): got command set transit.NeedCommsTime 15 minute 2024-10-07T22:35:17.908Z,1728340517.908 [CommandExec](IMPORTANT): got command set transit.Latitude 36.797 degree 2024-10-07T22:35:17.909Z,1728340517.909 [CommandExec](IMPORTANT): got command set transit.Longitude -121.847 degree 2024-10-07T22:35:17.909Z,1728340517.909 [CommandExec](IMPORTANT): got command run 2024-10-07T22:35:17.914Z,1728340517.914 [CommandExec](IMPORTANT): Running 2024-10-07T22:35:18.174Z,1728340518.174 [Default] Stopped 2024-10-07T22:35:18.174Z,1728340518.174 [Default](DEBUG): Aggregate::uninitialize Default 2024-10-07T22:35:18.174Z,1728340518.174 [Default:B.GoToSurface] Stopped 2024-10-07T22:35:18.174Z,1728340518.174 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2024-10-07T22:35:18.174Z,1728340518.174 [Default:CheckIn] Stopped 2024-10-07T22:35:18.174Z,1728340518.174 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-10-07T22:35:18.174Z,1728340518.174 [Default:CheckIn:C.Wait] Stopped 2024-10-07T22:35:18.175Z,1728340518.175 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-10-07T22:35:18.175Z,1728340518.175 [MissionManager](IMPORTANT): Started mission transit 2024-10-07T22:35:18.175Z,1728340518.175 [transit] Running Loop=1 2024-10-07T22:35:18.175Z,1728340518.175 [transit](DEBUG): Aggregate::initialize transit 2024-10-07T22:35:18.175Z,1728340518.175 [transit:StandardEnvelopes] Running Loop=1 2024-10-07T22:35:18.175Z,1728340518.175 [transit:StandardEnvelopes](DEBUG): Aggregate::initialize transit:StandardEnvelopes 2024-10-07T22:35:18.175Z,1728340518.175 [transit:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1 2024-10-07T22:35:18.175Z,1728340518.175 [transit:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent. 2024-10-07T22:35:18.176Z,1728340518.176 [transit:StandardEnvelopes:B.DepthEnvelope] Running Loop=1 2024-10-07T22:35:18.176Z,1728340518.176 [transit:StandardEnvelopes:B.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent. 2024-10-07T22:35:18.176Z,1728340518.176 [transit:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1 2024-10-07T22:35:18.176Z,1728340518.176 [transit:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Initialize OffshoreEnvelopeComponent. 2024-10-07T22:35:18.176Z,1728340518.176 [transit:BackseatDriver] Running Loop=1 2024-10-07T22:35:18.176Z,1728340518.176 [transit:BackseatDriver](DEBUG): Aggregate::initialize transit:BackseatDriver 2024-10-07T22:35:18.176Z,1728340518.176 [transit:BackseatDriver:A.BackseatDriver] Running Loop=1 2024-10-07T22:35:18.176Z,1728340518.176 [transit:PowerOnly] Running Loop=1 2024-10-07T22:35:18.176Z,1728340518.176 [transit:PowerOnly](DEBUG): Aggregate::initialize transit:PowerOnly 2024-10-07T22:35:18.177Z,1728340518.177 [transit:PowerOnly:A] Running Loop=1 2024-10-07T22:35:18.177Z,1728340518.177 [transit:PowerOnly:B] Running Loop=1 2024-10-07T22:35:18.177Z,1728340518.177 [transit:PowerOnly:C] Running Loop=1 2024-10-07T22:35:18.177Z,1728340518.177 [transit:PowerOnly:D] Running Loop=1 2024-10-07T22:35:18.177Z,1728340518.177 [transit:PowerOnly:E.Wait] Running Loop=1 2024-10-07T22:35:18.177Z,1728340518.177 [transit:PowerOnly:E.Wait](DEBUG): Initialize Wait Component. 2024-10-07T22:35:18.177Z,1728340518.177 [transit:BuoyancyHold.Buoyancy] Running Loop=1 2024-10-07T22:35:18.177Z,1728340518.177 [transit:BuoyancyHold.Buoyancy](DEBUG): Initialize Buoyancy Component. 2024-10-07T22:35:18.177Z,1728340518.177 [transit:MassHold.Pitch] Running Loop=1 2024-10-07T22:35:18.177Z,1728340518.177 [transit:MassHold.Pitch](DEBUG): Initialize. 2024-10-07T22:35:18.178Z,1728340518.178 [transit:B] Running Loop=1 2024-10-07T22:35:18.178Z,1728340518.178 [transit:MassHold.Pitch] Running Loop=1 2024-10-07T22:35:18.179Z,1728340518.179 [transit:BuoyancyHold.Buoyancy] Running Loop=1 2024-10-07T22:35:18.179Z,1728340518.179 [transit:PowerOnly] Running Loop=1 2024-10-07T22:35:18.179Z,1728340518.179 [transit:PowerOnly:D] Stopped 2024-10-07T22:35:18.179Z,1728340518.179 [transit:PowerOnly:C] Stopped 2024-10-07T22:35:18.180Z,1728340518.180 [transit:PowerOnly:B] Stopped 2024-10-07T22:35:18.180Z,1728340518.180 [transit:PowerOnly:A] Stopped 2024-10-07T22:35:18.180Z,1728340518.180 [transit:BackseatDriver] Running Loop=1 2024-10-07T22:35:18.180Z,1728340518.180 [transit:StandardEnvelopes] Running Loop=1 2024-10-07T22:35:18.180Z,1728340518.180 [transit:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1 2024-10-07T22:35:18.181Z,1728340518.181 [transit:StandardEnvelopes:C.OffshoreEnvelope](IMPORTANT): Offshore envelope ACTIVE 2024-10-07T22:35:18.189Z,1728340518.189 [transit:StandardEnvelopes:B.DepthEnvelope] Running Loop=1 2024-10-07T22:35:18.190Z,1728340518.190 [transit:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1 2024-10-07T22:35:18.190Z,1728340518.190 [transit:B] Stopped 2024-10-07T22:35:18.190Z,1728340518.190 [transit:C] Running Loop=1 2024-10-07T22:35:18.195Z,1728340518.195 [HorizontalControl](DEBUG): kpHeading = 0.400000 2024-10-07T22:35:18.195Z,1728340518.195 [HorizontalControl](DEBUG): kiHeading = 0.001000 2024-10-07T22:35:18.195Z,1728340518.195 [HorizontalControl](DEBUG): kdHeading = 0.050000 2024-10-07T22:35:18.684Z,1728340518.684 [transit:C] Stopped 2024-10-07T22:35:18.685Z,1728340518.685 [transit:E] Running Loop=1 2024-10-07T22:35:18.978Z,1728340518.978 [transit:E] Stopped 2024-10-07T22:35:18.978Z,1728340518.978 [transit:F] Running Loop=1 2024-10-07T22:35:19.402Z,1728340519.402 [transit:F] Stopped 2024-10-07T22:35:19.402Z,1728340519.402 [transit:G] Running Loop=1 2024-10-07T22:35:19.790Z,1728340519.790 [transit:G] Stopped 2024-10-07T22:35:19.790Z,1728340519.790 [transit:Transit] Running Loop=1 2024-10-07T22:35:19.790Z,1728340519.790 [transit:Transit](DEBUG): Aggregate::initialize transit:Transit 2024-10-07T22:35:19.791Z,1728340519.791 [transit:Transit:A.Pitch] Running Loop=1 2024-10-07T22:35:19.791Z,1728340519.791 [transit:Transit:A.Pitch](DEBUG): Initialize. 2024-10-07T22:35:19.791Z,1728340519.791 [transit:Transit:B.SetSpeed] Running Loop=1 2024-10-07T22:35:19.791Z,1728340519.791 [transit:Transit:B.SetSpeed](DEBUG): Initialize. 2024-10-07T22:35:19.791Z,1728340519.791 [transit:Transit:Wpt1.Waypoint] Running Loop=1 2024-10-07T22:35:19.792Z,1728340519.792 [transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent. 2024-10-07T22:35:19.794Z,1728340519.794 [transit:Transit:Wpt1.Waypoint](IMPORTANT): Navigating to waypoint: 36.797001,-121.847000 2024-10-07T22:35:19.795Z,1728340519.795 [transit:StandardEnvelopes:A.AltitudeEnvelope](ERROR): Altitude Measurement is not Active. 2024-10-07T22:35:20.190Z,1728340520.190 [transit:Transit:Wpt1.Waypoint](INFO): Navigating to waypoint: 36.797001,-121.847000 2024-10-07T22:35:20.191Z,1728340520.191 [transit:Transit:B.SetSpeed] Running Loop=1 2024-10-07T22:35:20.191Z,1728340520.191 [transit:Transit:A.Pitch] Running Loop=1 2024-10-07T22:36:15.007Z,1728340575.007 [DataOverHttps](IMPORTANT): SBD MTMSN=20241007T223614 2024-10-07T22:36:26.954Z,1728340586.954 [DataOverHttps](INFO): Received command: stop 2024-10-07T22:36:27.023Z,1728340587.023 [CommandExec](IMPORTANT): got command stop 2024-10-07T22:36:27.023Z,1728340587.023 [CommandExec](IMPORTANT): Scheduling is paused 2024-10-07T22:36:27.023Z,1728340587.023 [Supervisor](INFO): Stop Mission called by CommandExec::commandStop 2024-10-07T22:36:27.306Z,1728340587.306 [MissionManager](INFO): MissionManager is completed. 2024-10-07T22:36:27.306Z,1728340587.306 [MissionManager](INFO): Uninitializing Mission transit 2024-10-07T22:36:27.306Z,1728340587.306 [transit] Stopped 2024-10-07T22:36:27.306Z,1728340587.306 [transit](DEBUG): Aggregate::uninitialize transit 2024-10-07T22:36:27.306Z,1728340587.306 [transit:StandardEnvelopes] Stopped 2024-10-07T22:36:27.306Z,1728340587.306 [transit:StandardEnvelopes](DEBUG): Aggregate::uninitialize transit:StandardEnvelopes 2024-10-07T22:36:27.306Z,1728340587.306 [transit:StandardEnvelopes:A.AltitudeEnvelope] Stopped 2024-10-07T22:36:27.306Z,1728340587.306 [transit:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent. 2024-10-07T22:36:27.307Z,1728340587.307 [transit:StandardEnvelopes:B.DepthEnvelope] Stopped 2024-10-07T22:36:27.307Z,1728340587.307 [transit:StandardEnvelopes:B.DepthEnvelope](DEBUG): Uninitialize. 2024-10-07T22:36:27.307Z,1728340587.307 [transit:StandardEnvelopes:C.OffshoreEnvelope] Stopped 2024-10-07T22:36:27.307Z,1728340587.307 [transit:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Uninitialize OffshoreEnvelopeComponent. 2024-10-07T22:36:27.307Z,1728340587.307 [transit:BackseatDriver] Stopped 2024-10-07T22:36:27.307Z,1728340587.307 [transit:BackseatDriver](DEBUG): Aggregate::uninitialize transit:BackseatDriver 2024-10-07T22:36:27.307Z,1728340587.307 [transit:BackseatDriver:A.BackseatDriver] Stopped 2024-10-07T22:36:27.307Z,1728340587.307 [transit:PowerOnly] Stopped 2024-10-07T22:36:27.307Z,1728340587.307 [transit:PowerOnly](DEBUG): Aggregate::uninitialize transit:PowerOnly 2024-10-07T22:36:27.307Z,1728340587.307 [transit:PowerOnly:E.Wait] Stopped 2024-10-07T22:36:27.307Z,1728340587.307 [transit:PowerOnly:E.Wait](DEBUG): Uninitialize Wait Component. 2024-10-07T22:36:27.307Z,1728340587.307 [transit:BuoyancyHold.Buoyancy] Stopped 2024-10-07T22:36:27.307Z,1728340587.307 [transit:BuoyancyHold.Buoyancy](DEBUG): Uninitialize Buoyancy Component. 2024-10-07T22:36:27.308Z,1728340587.308 [transit:MassHold.Pitch] Stopped 2024-10-07T22:36:27.308Z,1728340587.308 [transit:Transit] Stopped 2024-10-07T22:36:27.308Z,1728340587.308 [transit:Transit](DEBUG): Aggregate::uninitialize transit:Transit 2024-10-07T22:36:27.308Z,1728340587.308 [transit:Transit:A.Pitch] Stopped 2024-10-07T22:36:27.308Z,1728340587.308 [transit:Transit:B.SetSpeed] Stopped 2024-10-07T22:36:27.308Z,1728340587.308 [transit:Transit:B.SetSpeed](DEBUG): Uninitialize. 2024-10-07T22:36:27.308Z,1728340587.308 [transit:Transit:Wpt1.Waypoint] Stopped 2024-10-07T22:36:27.308Z,1728340587.308 [transit:Transit:Wpt1.Waypoint](DEBUG): Uninitialize WaypointComponent. 2024-10-07T22:36:27.706Z,1728340587.706 [MissionManager](IMPORTANT): Started mission Default 2024-10-07T22:36:27.706Z,1728340587.706 [Default] Running Loop=1 2024-10-07T22:36:27.706Z,1728340587.706 [Default](DEBUG): Aggregate::initialize Default 2024-10-07T22:36:27.706Z,1728340587.706 [Default:B.GoToSurface] Running Loop=1 2024-10-07T22:36:27.706Z,1728340587.706 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2024-10-07T22:36:27.707Z,1728340587.707 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2024-10-07T22:36:27.707Z,1728340587.707 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2024-10-07T22:36:27.707Z,1728340587.707 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2024-10-07T22:36:27.708Z,1728340587.708 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2024-10-07T22:36:27.708Z,1728340587.708 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2024-10-07T22:36:27.708Z,1728340587.708 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2024-10-07T22:36:27.709Z,1728340587.709 [Default:A.Wait] Running Loop=1 2024-10-07T22:36:27.709Z,1728340587.709 [Default:A.Wait](DEBUG): Initialize Wait Component. 2024-10-07T22:36:41.066Z,1728340601.066 [Default:A.Wait](INFO): Done Waiting. 2024-10-07T22:36:41.066Z,1728340601.066 [Default:A.Wait] Stopped 2024-10-07T22:36:41.066Z,1728340601.066 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2024-10-07T22:36:41.441Z,1728340601.441 [Default:CheckIn] Running Loop=1 2024-10-07T22:36:41.441Z,1728340601.441 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-10-07T22:36:41.441Z,1728340601.441 [Default:CheckIn:Read_GPS] Running Loop=1 2024-10-07T22:36:43.048Z,1728340603.048 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2024-10-07T22:36:43.468Z,1728340603.468 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,223642.00,A,3648.03513,N,12148.77893,W,8.514,336.80,071024,,,D*7D 2024-10-07T22:36:43.471Z,1728340603.471 [NAL9602](INFO): GPS fix at 20241007T223642: (36.800585, -121.812982) 2024-10-07T22:36:43.506Z,1728340603.506 [Default:CheckIn:Read_GPS] Stopped 2024-10-07T22:36:43.506Z,1728340603.506 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-10-07T22:36:52.529Z,1728340612.529 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20241007T210425/Courier0052.lzma 2024-10-07T22:36:53.531Z,1728340613.531 [DataOverHttps](INFO): Moved sent file to Logs/20241007T210425/Courier0052.lzma.bak 2024-10-07T22:36:53.532Z,1728340613.532 [DataOverHttps](INFO): SBD MOMSN=23274405 2024-10-07T22:36:55.203Z,1728340615.203 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2024-10-07T22:37:04.128Z,1728340624.128 [NAL9602](INFO): SBD MO Status=0, MOMSN=57703, MT Status=0, MTMSN=0 2024-10-07T22:37:04.128Z,1728340624.128 [NAL9602](INFO): No messages in MT queue 2024-10-07T22:37:07.356Z,1728340627.356 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2024-10-07T22:37:12.386Z,1728340632.386 [DataOverHttps](INFO): Sending 510 bytes from file Logs/20241007T210425/Express0053.lzma 2024-10-07T22:37:13.388Z,1728340633.388 [DataOverHttps](INFO): Moved sent file to Logs/20241007T210425/Express0053.lzma.bak 2024-10-07T22:37:13.388Z,1728340633.388 [DataOverHttps](INFO): SBD MOMSN=23274462 2024-10-07T22:37:15.070Z,1728340635.070 [Default:CheckIn:Read_Iridium] Stopped 2024-10-07T22:37:15.070Z,1728340635.070 [Default:CheckIn:C.Wait] Running Loop=1 2024-10-07T22:37:15.070Z,1728340635.070 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-10-07T22:37:19.074Z,1728340639.074 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2024-10-07T22:37:30.385Z,1728340650.385 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2024-10-07T22:37:34.834Z,1728340654.834 [NAL9602](INFO): Not Powering down - fast GPS 2024-10-07T22:37:41.710Z,1728340661.710 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2024-10-07T22:37:53.878Z,1728340673.878 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2024-10-07T22:38:05.938Z,1728340685.938 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2024-10-07T22:39:46.710Z,1728340786.710 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-10-07T22:40:17.838Z,1728340817.838 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-10-07T22:40:39.148Z,1728340839.148 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2024-10-07T22:40:48.962Z,1728340848.962 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-10-07T22:40:52.480Z,1728340852.480 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2024-10-07T22:41:05.812Z,1728340865.812 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2024-10-07T22:41:19.144Z,1728340879.144 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2024-10-07T22:41:20.090Z,1728340880.090 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-10-07T22:41:33.289Z,1728340893.289 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2024-10-07T22:41:46.214Z,1728340906.214 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2024-10-07T22:41:51.230Z,1728340911.230 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-10-07T22:41:57.254Z,1728340917.254 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.759338 2024-10-07T22:41:59.947Z,1728340919.947 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2024-10-07T22:42:13.279Z,1728340933.279 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2024-10-07T22:42:15.725Z,1728340935.725 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-10-07T22:42:15.725Z,1728340935.725 [Default:CheckIn:C.Wait] Stopped 2024-10-07T22:42:15.725Z,1728340935.725 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-10-07T22:42:15.726Z,1728340935.726 [Default:CheckIn:D] Running Loop=1 2024-10-07T22:42:16.154Z,1728340936.154 [Default:CheckIn:D] Stopped 2024-10-07T22:42:16.154Z,1728340936.154 [Default:CheckIn:E] Running Loop=1 2024-10-07T22:42:16.524Z,1728340936.524 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 5.807457 min 2024-10-07T22:42:16.524Z,1728340936.524 [Default:CheckIn:E] Stopped 2024-10-07T22:42:16.525Z,1728340936.525 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-10-07T22:42:16.525Z,1728340936.525 [Default:CheckIn] Stopped 2024-10-07T22:42:16.525Z,1728340936.525 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-10-07T22:42:16.525Z,1728340936.525 [Default:CheckIn](INFO): Running loop #2 2024-10-07T22:42:16.525Z,1728340936.525 [Default:CheckIn] Running Loop=2 2024-10-07T22:42:16.525Z,1728340936.525 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-10-07T22:42:16.525Z,1728340936.525 [Default:CheckIn:Read_GPS] Running Loop=1 2024-10-07T22:42:18.543Z,1728340938.543 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,224217.00,A,3648.24397,N,12148.94643,W,0.583,53.62,071024,,,D*45 2024-10-07T22:42:18.545Z,1728340938.545 [NAL9602](INFO): GPS fix at 20241007T224217: (36.804066, -121.815774) 2024-10-07T22:42:18.556Z,1728340938.556 [Default:CheckIn:Read_GPS] Stopped 2024-10-07T22:42:18.556Z,1728340938.556 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-10-07T22:42:29.135Z,1728340949.135 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2024-10-07T22:42:40.028Z,1728340960.028 [NAL9602](INFO): SBD MO Status=1, MOMSN=57704, MT Status=0, MTMSN=0 2024-10-07T22:42:40.094Z,1728340960.094 [NAL9602](INFO): Sent 72 bytes from file Logs/20241007T210425/Courier0055.lzma 2024-10-07T22:42:40.094Z,1728340960.094 [NAL9602](INFO): Packets left to send: 0 2024-10-07T22:42:43.694Z,1728340963.694 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2024-10-07T22:42:50.572Z,1728340970.572 [NAL9602](INFO): SBD MO Status=1, MOMSN=57705, MT Status=0, MTMSN=0 2024-10-07T22:42:50.638Z,1728340970.638 [NAL9602](INFO): Sent 153 bytes from file Logs/20241007T210425/Express0057.lzma 2024-10-07T22:42:50.638Z,1728340970.638 [NAL9602](INFO): Packets left to send: 0 2024-10-07T22:42:52.498Z,1728340972.498 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-10-07T22:42:57.285Z,1728340977.285 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2024-10-07T22:42:59.307Z,1728340979.307 [NAL9602](INFO): SBD MO Status=0, MOMSN=57706, MT Status=0, MTMSN=0 2024-10-07T22:42:59.394Z,1728340979.394 [Default:CheckIn:Read_Iridium] Stopped 2024-10-07T22:42:59.394Z,1728340979.394 [Default:CheckIn:C.Wait] Running Loop=1 2024-10-07T22:42:59.394Z,1728340979.394 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-10-07T22:43:23.622Z,1728341003.622 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-10-07T22:43:30.011Z,1728341010.011 [NAL9602](INFO): Not Powering down - fast GPS 2024-10-07T22:43:54.746Z,1728341034.746 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-10-07T22:44:25.878Z,1728341065.878 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-10-07T22:44:34.538Z,1728341074.538 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003293 2024-10-07T22:45:35.803Z,1728341135.803 [DataOverHttps](IMPORTANT): SBD MTMSN=20241007T224534 2024-10-07T22:45:43.358Z,1728341143.358 [DataOverHttps](INFO): Received command: load Transport/transit.tl;set transit.NeedCommsTime 15 min;set transit.Latitude 36.797 degree;set transit.Longitude -121.847 degree;run 2024-10-07T22:45:43.402Z,1728341143.402 [CommandExec](IMPORTANT): got command load ./Missions/Transport/transit.tl 2024-10-07T22:45:43.403Z,1728341143.403 [MissionManager](INFO): Loading Mission from file: ./Missions/Transport/transit.tl 2024-10-07T22:45:43.403Z,1728341143.403 [MissionManager](DEBUG): TethyslAPI: loading: ./Missions/Transport/transit.tl 2024-10-07T22:45:43.404Z,1728341143.404 [MissionManager](DEBUG): TethyslAPI: mission file loaded: ./Missions/Transport/transit.tl 2024-10-07T22:45:44.111Z,1728341144.111 [MissionManager](DEBUG): TethyslAPI: ./Missions/Transport/transit.tl translated into: 60 30 NaN NaN 0 0 10 1 20 1 7 1 2024-10-07T22:45:44.116Z,1728341144.116 [MissionManager](INFO): DefineArg transit.MissionTimeout = 60.000000 min 2024-10-07T22:45:44.118Z,1728341144.118 [MissionManager](INFO): DefineArg transit.NeedCommsTime = 30.000000 min 2024-10-07T22:45:44.120Z,1728341144.120 [MissionManager](INFO): DefineArg transit.Latitude = nan arcdeg 2024-10-07T22:45:44.147Z,1728341144.147 [MissionManager](INFO): DefineArg transit.Longitude = nan arcdeg 2024-10-07T22:45:44.149Z,1728341144.149 [MissionManager](INFO): DefineArg transit.Northings = 0.000000 m 2024-10-07T22:45:44.187Z,1728341144.187 [MissionManager](INFO): DefineArg transit.Eastings = 0.000000 m 2024-10-07T22:45:44.203Z,1728341144.203 [MissionManager](INFO): DefineArg transit.Depth = 10.000000 m 2024-10-07T22:45:44.233Z,1728341144.233 [MissionManager](INFO): DefineArg transit.Speed = 1.000000 m/s 2024-10-07T22:45:44.236Z,1728341144.236 [MissionManager](INFO): DefineArg transit.MaxDepth = 20.000000 m 2024-10-07T22:45:44.243Z,1728341144.243 [MissionManager](INFO): DefineArg transit.MinOffshore = 1.000000 km 2024-10-07T22:45:44.265Z,1728341144.265 [MissionManager](INFO): DefineArg transit.MinAltitude = 7.000000 m 2024-10-07T22:45:44.267Z,1728341144.267 [MissionManager](INFO): DefineArg transit.MassHold = 1 bool 2024-10-07T22:45:44.280Z,1728341144.280 [MissionManager](INFO): DefineArg transit.BuoyancyHold = 1 bool 2024-10-07T22:45:44.280Z,1728341144.280 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/NeedComms.tl 2024-10-07T22:45:44.280Z,1728341144.280 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/NeedComms.tl 2024-10-07T22:45:44.293Z,1728341144.293 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/NeedComms.tl 2024-10-07T22:45:44.654Z,1728341144.654 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/NeedComms.tl translated into: 1 10 20 NaN 1 1000 7 30 0 last time_fix was: first GPS update timeout Comms timed out after minutes second GPS update timeout 2024-10-07T22:45:44.659Z,1728341144.659 [MissionManager](INFO): DefineArg transit:NeedComms.DiveInterval = 1.000000 h 2024-10-07T22:45:44.661Z,1728341144.661 [MissionManager](INFO): DefineArg transit:NeedComms.WaitForPitchUp = 10.000000 min 2024-10-07T22:45:44.664Z,1728341144.664 [MissionManager](INFO): DefineArg transit:NeedComms.SurfacePitch = 20.000000 arcdeg 2024-10-07T22:45:44.666Z,1728341144.666 [MissionManager](INFO): DefineArg transit:NeedComms.SurfaceDepthRate = nan m/s 2024-10-07T22:45:44.668Z,1728341144.668 [MissionManager](INFO): DefineArg transit:NeedComms.SurfaceSpeed = 1.000000 m/s 2024-10-07T22:45:44.670Z,1728341144.670 [MissionManager](INFO): DefineArg transit:NeedComms.SurfacingTimeout = 1000.000000 s 2024-10-07T22:45:44.672Z,1728341144.672 [MissionManager](INFO): DefineArg transit:NeedComms.GPSTimeout = 7.000000 min 2024-10-07T22:45:44.675Z,1728341144.675 [MissionManager](INFO): DefineArg transit:NeedComms.CommsTimeout = 30.000000 min 2024-10-07T22:45:44.680Z,1728341144.680 [transit:NeedComms:B.GoToSurface](DEBUG): Construct GoToSurface. 2024-10-07T22:45:44.700Z,1728341144.700 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/StandardEnvelopes.tl 2024-10-07T22:45:44.700Z,1728341144.700 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/StandardEnvelopes.tl 2024-10-07T22:45:44.701Z,1728341144.701 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/StandardEnvelopes.tl 2024-10-07T22:45:44.860Z,1728341144.860 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/StandardEnvelopes.tl translated into: 5 0 200 2000 2024-10-07T22:45:44.865Z,1728341144.865 [MissionManager](INFO): DefineArg transit:StandardEnvelopes.MinAltitude = 5.000000 m 2024-10-07T22:45:44.867Z,1728341144.867 [MissionManager](INFO): DefineArg transit:StandardEnvelopes.MaxDepthIgnore = 0.000000 m 2024-10-07T22:45:44.889Z,1728341144.889 [MissionManager](INFO): DefineArg transit:StandardEnvelopes.MaxDepth = 200.000000 m 2024-10-07T22:45:44.891Z,1728341144.891 [MissionManager](INFO): DefineArg transit:StandardEnvelopes.MinOffshore = 2000.000000 m 2024-10-07T22:45:44.892Z,1728341144.892 [transit:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope. 2024-10-07T22:45:44.899Z,1728341144.899 [transit:StandardEnvelopes:B.DepthEnvelope](DEBUG): Construct DepthEnvelope. 2024-10-07T22:45:44.905Z,1728341144.905 [transit:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Construct OffshoreEnvelope. 2024-10-07T22:45:44.914Z,1728341144.914 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/BackseatDriver.tl 2024-10-07T22:45:44.914Z,1728341144.914 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/BackseatDriver.tl 2024-10-07T22:45:44.915Z,1728341144.915 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/BackseatDriver.tl 2024-10-07T22:45:45.016Z,1728341145.016 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/BackseatDriver.tl translated into: 2024-10-07T22:45:45.024Z,1728341145.024 [MissionManager](INFO): DefineArg transit:BackseatDriver.EnableBackseat = 0 bool 2024-10-07T22:45:45.031Z,1728341145.031 [transit:BackseatDriver:A.BackseatDriver](DEBUG): Construct BackseatDriver. 2024-10-07T22:45:45.035Z,1728341145.035 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/PowerOnly.tl 2024-10-07T22:45:45.035Z,1728341145.035 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/PowerOnly.tl 2024-10-07T22:45:45.037Z,1728341145.037 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/PowerOnly.tl 2024-10-07T22:45:45.191Z,1728341145.191 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/PowerOnly.tl translated into: 99999 2024-10-07T22:45:45.198Z,1728341145.198 [MissionManager](INFO): DefineArg transit:PowerOnly.SampleAll = 0 bool 2024-10-07T22:45:45.199Z,1728341145.199 [MissionManager](INFO): DefineArg transit:PowerOnly.SampleLoad1 = 0 bool 2024-10-07T22:45:45.201Z,1728341145.201 [MissionManager](INFO): DefineArg transit:PowerOnly.SampleLoad2 = 0 bool 2024-10-07T22:45:45.203Z,1728341145.203 [MissionManager](INFO): DefineArg transit:PowerOnly.SampleLoad3 = 0 bool 2024-10-07T22:45:45.205Z,1728341145.205 [MissionManager](INFO): DefineArg transit:PowerOnly.EnabledPowerOnly = 1 bool 2024-10-07T22:45:45.211Z,1728341145.211 [transit:PowerOnly:E.Wait](DEBUG): Construct Wait. 2024-10-07T22:45:45.213Z,1728341145.213 [transit:BuoyancyHold.Buoyancy](DEBUG): Construct Buoyancy. 2024-10-07T22:45:45.216Z,1728341145.216 [transit:MassHold.Pitch](DEBUG): Construct. 2024-10-07T22:45:45.222Z,1728341145.222 [transit:Transit:A.Pitch](DEBUG): Construct. 2024-10-07T22:45:45.226Z,1728341145.226 [transit:Transit:B.SetSpeed](DEBUG): Construct. 2024-10-07T22:45:45.229Z,1728341145.229 [transit:Transit:Wpt1.Waypoint](DEBUG): Construct Waypoint. 2024-10-07T22:45:45.243Z,1728341145.243 [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 transit { """ Vehicle transits to desired waypoint and can be commanded to use/hold mass or buoyancy. """ arguments { MissionTimeout = 60 minute """ Maximum duration of mission """ NeedCommsTime = 30 minute """ How often to surface for commumications """ Latitude = NaN degree """ Latitude of waypoint to seek. If set to NaN, uses latitude at mission initialization. """ Longitude = NaN degree """ Longitude of waypoint to seek. If set to NaN, uses longitude at mission initialization. """ Northings = 0 meter """ Northward distance of the waypoint to seek. If combined with Latitude and/or Longitude, this is an offset from the specified Latitude and/or Longitude. """ Eastings = 0 meter """ Eastward distance of the waypoint to seek. If combined with Latitude and/or Longitude, this is an offset from the specified Latitude and/or Longitude. """ Depth = 10 meter """ Depth of flat and level flight during the mission. """ Speed = 1 meter_per_second """ Speed of vehicle (relative to water) during the mission. """ MaxDepth = 20 meter """ Maximum depth for the entire mission. """ MinOffshore = 1 kilometer """ Minimum distance offshore for the entire mission. """ MinAltitude = 7 meter """ Minimum height above the sea floor for the entire mission. """ MassHold = true """ Set to True in order to hold mass at default position, False to allow mass to run on its own. """ BuoyancyHold = true """ Set to True in order to hold buoyancy at neutral position, False to allow buoyancy to run on its own. """ } timeout duration=MissionTimeout insert id="NeedComms" Insert/NeedComms.tl assign in sequence NeedComms:DiveInterval = NeedCommsTime assign in sequence NeedComms:WaitForPitchUp = 1 second insert Insert/StandardEnvelopes.tl assign in sequence StandardEnvelopes:MinAltitude = MinAltitude assign in sequence StandardEnvelopes:MaxDepth = MaxDepth assign in sequence StandardEnvelopes:MinOffshore = MinOffshore insert Insert/BackseatDriver.tl insert Insert/PowerOnly.tl behavior Guidance:Buoyancy id="BuoyancyHold" { run while ( BuoyancyHold ) set position = Control:VerticalControl.buoyancyNeutral } behavior Guidance:Pitch id="MassHold" { run while ( MassHold ) set massPosition = Control:VerticalControl.massDefault } aggregate Transit { run in sequence behavior Guidance:Pitch { run in parallel set depth = Depth } behavior Guidance:SetSpeed { run in parallel set speed = Speed } behavior Guidance:Waypoint id="Wpt1" { run in sequence set latitude = Latitude set longitude = Longitude set northingsDelta = Northings set eastingsDelta = Eastings } call id="PhoneHome" refId="NeedComms" } } 2024-10-07T22:45:45.244Z,1728341145.244 [CommandExec](IMPORTANT): Loaded ./Missions/Transport/transit.tl id=transit 2024-10-07T22:45:49.572Z,1728341149.572 [CommandExec](IMPORTANT): got command set transit.NeedCommsTime 15 minute 2024-10-07T22:45:49.573Z,1728341149.573 [CommandExec](IMPORTANT): got command set transit.Latitude 36.797 degree 2024-10-07T22:45:49.573Z,1728341149.573 [CommandExec](IMPORTANT): got command set transit.Longitude -121.847 degree 2024-10-07T22:45:49.574Z,1728341149.574 [CommandExec](IMPORTANT): got command run 2024-10-07T22:45:49.578Z,1728341149.578 [CommandExec](IMPORTANT): Running 2024-10-07T22:45:49.823Z,1728341149.823 [Default] Stopped 2024-10-07T22:45:49.823Z,1728341149.823 [Default](DEBUG): Aggregate::uninitialize Default 2024-10-07T22:45:49.823Z,1728341149.823 [Default:B.GoToSurface] Stopped 2024-10-07T22:45:49.823Z,1728341149.823 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2024-10-07T22:45:49.823Z,1728341149.823 [Default:CheckIn] Stopped 2024-10-07T22:45:49.823Z,1728341149.823 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-10-07T22:45:49.823Z,1728341149.823 [Default:CheckIn:C.Wait] Stopped 2024-10-07T22:45:49.823Z,1728341149.823 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-10-07T22:45:49.823Z,1728341149.823 [MissionManager](IMPORTANT): Started mission transit 2024-10-07T22:45:49.824Z,1728341149.824 [transit] Running Loop=1 2024-10-07T22:45:49.824Z,1728341149.824 [transit](DEBUG): Aggregate::initialize transit 2024-10-07T22:45:49.824Z,1728341149.824 [transit:StandardEnvelopes] Running Loop=1 2024-10-07T22:45:49.824Z,1728341149.824 [transit:StandardEnvelopes](DEBUG): Aggregate::initialize transit:StandardEnvelopes 2024-10-07T22:45:49.824Z,1728341149.824 [transit:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1 2024-10-07T22:45:49.824Z,1728341149.824 [transit:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent. 2024-10-07T22:45:49.824Z,1728341149.824 [transit:StandardEnvelopes:B.DepthEnvelope] Running Loop=1 2024-10-07T22:45:49.824Z,1728341149.824 [transit:StandardEnvelopes:B.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent. 2024-10-07T22:45:49.824Z,1728341149.824 [transit:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1 2024-10-07T22:45:49.825Z,1728341149.825 [transit:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Initialize OffshoreEnvelopeComponent. 2024-10-07T22:45:49.825Z,1728341149.825 [transit:BackseatDriver] Running Loop=1 2024-10-07T22:45:49.825Z,1728341149.825 [transit:BackseatDriver](DEBUG): Aggregate::initialize transit:BackseatDriver 2024-10-07T22:45:49.825Z,1728341149.825 [transit:BackseatDriver:A.BackseatDriver] Running Loop=1 2024-10-07T22:45:49.825Z,1728341149.825 [transit:PowerOnly] Running Loop=1 2024-10-07T22:45:49.825Z,1728341149.825 [transit:PowerOnly](DEBUG): Aggregate::initialize transit:PowerOnly 2024-10-07T22:45:49.825Z,1728341149.825 [transit:PowerOnly:A] Running Loop=1 2024-10-07T22:45:49.825Z,1728341149.825 [transit:PowerOnly:B] Running Loop=1 2024-10-07T22:45:49.825Z,1728341149.825 [transit:PowerOnly:C] Running Loop=1 2024-10-07T22:45:49.826Z,1728341149.826 [transit:PowerOnly:D] Running Loop=1 2024-10-07T22:45:49.826Z,1728341149.826 [transit:PowerOnly:E.Wait] Running Loop=1 2024-10-07T22:45:49.826Z,1728341149.826 [transit:PowerOnly:E.Wait](DEBUG): Initialize Wait Component. 2024-10-07T22:45:49.826Z,1728341149.826 [transit:BuoyancyHold.Buoyancy] Running Loop=1 2024-10-07T22:45:49.826Z,1728341149.826 [transit:BuoyancyHold.Buoyancy](DEBUG): Initialize Buoyancy Component. 2024-10-07T22:45:49.826Z,1728341149.826 [transit:MassHold.Pitch] Running Loop=1 2024-10-07T22:45:49.826Z,1728341149.826 [transit:MassHold.Pitch](DEBUG): Initialize. 2024-10-07T22:45:49.826Z,1728341149.826 [transit:B] Running Loop=1 2024-10-07T22:45:49.827Z,1728341149.827 [transit:MassHold.Pitch] Running Loop=1 2024-10-07T22:45:49.827Z,1728341149.827 [transit:BuoyancyHold.Buoyancy] Running Loop=1 2024-10-07T22:45:49.827Z,1728341149.827 [transit:PowerOnly] Running Loop=1 2024-10-07T22:45:49.828Z,1728341149.828 [transit:PowerOnly:D] Stopped 2024-10-07T22:45:49.828Z,1728341149.828 [transit:PowerOnly:C] Stopped 2024-10-07T22:45:49.828Z,1728341149.828 [transit:PowerOnly:B] Stopped 2024-10-07T22:45:49.828Z,1728341149.828 [transit:PowerOnly:A] Stopped 2024-10-07T22:45:49.828Z,1728341149.828 [transit:BackseatDriver] Running Loop=1 2024-10-07T22:45:49.828Z,1728341149.828 [transit:StandardEnvelopes] Running Loop=1 2024-10-07T22:45:49.828Z,1728341149.828 [transit:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1 2024-10-07T22:45:49.828Z,1728341149.828 [transit:StandardEnvelopes:B.DepthEnvelope] Running Loop=1 2024-10-07T22:45:49.829Z,1728341149.829 [transit:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1 2024-10-07T22:45:49.830Z,1728341149.830 [transit:B] Stopped 2024-10-07T22:45:49.830Z,1728341149.830 [transit:C] Running Loop=1 2024-10-07T22:45:50.241Z,1728341150.241 [transit:C] Stopped 2024-10-07T22:45:50.241Z,1728341150.241 [transit:E] Running Loop=1 2024-10-07T22:45:50.618Z,1728341150.618 [transit:E] Stopped 2024-10-07T22:45:50.618Z,1728341150.618 [transit:F] Running Loop=1 2024-10-07T22:45:51.020Z,1728341151.020 [transit:F] Stopped 2024-10-07T22:45:51.020Z,1728341151.020 [transit:G] Running Loop=1 2024-10-07T22:45:51.442Z,1728341151.442 [transit:G] Stopped 2024-10-07T22:45:51.442Z,1728341151.442 [transit:Transit] Running Loop=1 2024-10-07T22:45:51.443Z,1728341151.443 [transit:Transit](DEBUG): Aggregate::initialize transit:Transit 2024-10-07T22:45:51.443Z,1728341151.443 [transit:Transit:A.Pitch] Running Loop=1 2024-10-07T22:45:51.443Z,1728341151.443 [transit:Transit:A.Pitch](DEBUG): Initialize. 2024-10-07T22:45:51.443Z,1728341151.443 [transit:Transit:B.SetSpeed] Running Loop=1 2024-10-07T22:45:51.443Z,1728341151.443 [transit:Transit:B.SetSpeed](DEBUG): Initialize. 2024-10-07T22:45:51.443Z,1728341151.443 [transit:Transit:Wpt1.Waypoint] Running Loop=1 2024-10-07T22:45:51.443Z,1728341151.443 [transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent. 2024-10-07T22:45:51.444Z,1728341151.444 [transit:Transit:Wpt1.Waypoint](IMPORTANT): Navigating to waypoint: 36.797001,-121.847000 2024-10-07T22:45:51.445Z,1728341151.445 [transit:StandardEnvelopes:A.AltitudeEnvelope](ERROR): Altitude Measurement is not Active. 2024-10-07T22:45:51.825Z,1728341151.825 [transit:Transit:Wpt1.Waypoint](INFO): Navigating to waypoint: 36.797001,-121.847000 2024-10-07T22:45:51.826Z,1728341151.826 [transit:Transit:B.SetSpeed] Running Loop=1 2024-10-07T22:45:51.826Z,1728341151.826 [transit:Transit:A.Pitch] Running Loop=1 2024-10-07T22:47:08.758Z,1728341228.758 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-10-07T22:47:19.802Z,1728341239.802 [Radio_Surface](INFO): Powering down 2024-10-07T22:47:39.902Z,1728341259.902 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-10-07T22:47:40.906Z,1728341260.906 [DataOverHttps](INFO): Radio surface powered OFF, will not connect. 2024-10-07T22:48:45.174Z,1728341325.174 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.815277 2024-10-07T22:50:25.334Z,1728341425.334 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2024-10-07T22:50:38.665Z,1728341438.665 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2024-10-07T22:50:53.208Z,1728341453.208 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2024-10-07T22:51:06.540Z,1728341466.540 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2024-10-07T22:51:20.275Z,1728341480.275 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2024-10-07T22:51:33.612Z,1728341493.612 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2024-10-07T22:51:46.940Z,1728341506.940 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2024-10-07T22:52:00.271Z,1728341520.271 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2024-10-07T22:52:14.010Z,1728341534.010 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2024-10-07T22:52:27.346Z,1728341547.346 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7). 2024-10-07T22:57:19.853Z,1728341839.853 [transit:NeedComms] Running Loop=1 2024-10-07T22:57:19.853Z,1728341839.853 [transit:NeedComms](DEBUG): Aggregate::initialize transit:NeedComms 2024-10-07T22:57:19.853Z,1728341839.853 [transit:NeedComms:B.GoToSurface] Running Loop=1 2024-10-07T22:57:19.853Z,1728341839.853 [transit:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2024-10-07T22:57:19.869Z,1728341839.869 [transit:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s. 2024-10-07T22:57:19.870Z,1728341839.870 [transit:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees. 2024-10-07T22:57:19.870Z,1728341839.870 [transit:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s. 2024-10-07T22:57:19.871Z,1728341839.871 [transit:NeedComms:B.GoToSurface](INFO): Received surface timeout setting 1000.000000 seconds. 2024-10-07T22:57:19.871Z,1728341839.871 [transit:NeedComms:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2024-10-07T22:57:19.871Z,1728341839.871 [transit:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2024-10-07T22:57:19.872Z,1728341839.872 [transit:NeedComms:A] Running Loop=1 2024-10-07T22:57:19.877Z,1728341839.877 [transit:NeedComms:A](INFO): last time_fix was: 1728340937.000000 second since 1970/01/01T00:00:00Z 2024-10-07T22:57:19.878Z,1728341839.878 [transit:NeedComms:A] Stopped 2024-10-07T22:57:56.217Z,1728341876.217 [transit:NeedComms:C] Running Loop=1 2024-10-07T22:57:56.623Z,1728341876.623 [transit:NeedComms:C](DEBUG): Initialize ReadDataComponent to sense time_fix 2024-10-07T22:57:56.913Z,1728341876.913 [Radio_Surface](INFO): Powering up 2024-10-07T22:58:02.534Z,1728341882.534 [DataOverHttps](INFO): Radio surface powered ON. 2024-10-07T22:58:32.654Z,1728341912.654 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-10-07T22:58:39.840Z,1728341919.840 [NAL9602](INFO): SBD MO Status=2, MOMSN=57707, MT Status=2, MTMSN=0 2024-10-07T22:58:39.840Z,1728341919.840 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2024-10-07T22:59:03.778Z,1728341943.778 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2024-10-07T22:59:14.580Z,1728341954.580 [NAL9602](IMPORTANT): SBD MO Status=0, MOMSN=57707, MT Status=1, MTMSN=3642 2024-10-07T22:59:14.580Z,1728341954.580 [NAL9602](INFO): Data available in MT queue 2024-10-07T22:59:15.070Z,1728341955.070 [NAL9602](INFO): Received command: restart logs 2024-10-07T22:59:15.088Z,1728341955.088 [CommandExec](IMPORTANT): got command restart logs