diff --git a/scripts/console-monitor b/scripts/console-monitor index d9c67a04..1f11f627 100644 --- a/scripts/console-monitor +++ b/scripts/console-monitor @@ -95,6 +95,13 @@ CONSOLE_SWITCH_TABLE = "CONSOLE_SWITCH" # Default baud rate DEFAULT_BAUD = 9600 +# Console logrotate defaults +LOGROTATE_DIR = "/etc/logrotate.d" +LOGROTATE_CONF_PREFIX = "console-" +DEFAULT_LOG_FILE_TEMPLATE = "/var/log/console-{}.log" +DEFAULT_LOGROTATE_SIZE = "1M" +DEFAULT_LOGROTATE_COUNT = 20 + # Kernel command line path PROC_CMDLINE = "/proc/cmdline" @@ -489,6 +496,31 @@ def calculate_filter_timeout(baud: int, multiplier: int = 3) -> float: return char_time * MAX_FRAME_BUFFER_SIZE * multiplier +def logrotate_conf_path(link_id: str) -> str: + """Return the logrotate config file path for a console line.""" + return os.path.join(LOGROTATE_DIR, f"{LOGROTATE_CONF_PREFIX}{link_id}") + + +def default_log_file(link_id: str) -> str: + """Return the default console log file path for a line.""" + return DEFAULT_LOG_FILE_TEMPLATE.format(link_id) + + +def build_logrotate_config(log_file: str, size: str, count: int) -> str: + """Build logrotate configuration for a console log file.""" + return ( + f"{log_file} {{\n" + f" missingok\n" + f" notifempty\n" + f" size {size}\n" + f" rotate {count}\n" + f" compress\n" + f" delaycompress\n" + f" copytruncate\n" + f"}}\n" + ) + + # ============================================================ # PTY Bridge (runs as independent process, exec socat) # ============================================================ @@ -565,12 +597,15 @@ class ProxyService: self.baud: int = DEFAULT_BAUD self.device_path: str = "" self.ptm_path: str = "" + self.logging_enabled: bool = False + self.log_file_path: str = "" # Proxy resources self.state_db: Optional[DBConnector] = None self.state_table: Optional[Table] = None self.ser_fd: int = -1 self.ptm_fd: int = -1 + self.log_fd: int = -1 self.filter: Optional[FrameFilter] = None # State tracking @@ -638,7 +673,12 @@ class ProxyService: entry = config_db.get_entry(CONSOLE_PORT_TABLE, self.link_id) if entry: self.baud = int(entry.get('baud_rate', DEFAULT_BAUD)) - log.info(f"[{self.link_id}] Config loaded: baud={self.baud}") + self.logging_enabled = entry.get('logging_enabled', 'no') == 'yes' + self.log_file_path = entry.get('log_file') or default_log_file(self.link_id) + log.info(f"[{self.link_id}] Config loaded: baud={self.baud}, " + f"logging={'enabled' if self.logging_enabled else 'disabled'}, " + f"log_file={self.log_file_path or 'N/A'}") + log.debug(f"[{self.link_id}] Full CONSOLE_PORT entry: {entry}") return True log.debug(f"[{self.link_id}] Config not found, retrying in {RETRY_INTERVAL}s...") @@ -692,6 +732,18 @@ class ProxyService: # Open PTM self.ptm_fd = os.open(self.ptm_path, os.O_RDWR | os.O_NOCTTY | os.O_NONBLOCK) + if self.logging_enabled and self.log_file_path: + try: + self.log_fd = os.open( + self.log_file_path, + os.O_WRONLY | os.O_CREAT | os.O_APPEND, + 0o644, + ) + log.info(f"[{self.link_id}] Console logging enabled: {self.log_file_path}") + except OSError as e: + log.error(f"[{self.link_id}] Failed to open log file {self.log_file_path}: {e}") + self.log_fd = -1 + # Create frame filter self.filter = FrameFilter( on_frame=self._on_frame_received, @@ -766,6 +818,15 @@ class ProxyService: log.error(f"[{self.link_id}] Loop error: {e}") time.sleep(0.1) + def _write_log(self, data: bytes) -> None: + """Write console I/O data to the configured log file.""" + if self.log_fd < 0 or not data: + return + try: + os.write(self.log_fd, data) + except OSError as e: + log.error(f"[{self.link_id}] Failed to write to log file: {e}") + def _on_serial_read(self) -> None: """Serial data read callback""" if not self.running or not self.filter: @@ -801,7 +862,8 @@ class ProxyService: log.warning(f"[{self.link_id}] Unknown frame type: {frame.frame_type}") def _on_user_data_received(self, data: bytes) -> None: - """User data callback""" + """User data callback (device -> user, includes echoed input).""" + self._write_log(data) if self.ptm_fd >= 0: try: os.write(self.ptm_fd, data) @@ -868,7 +930,7 @@ class ProxyService: pass # Close file descriptors - for fd in (self._wake_r, self._wake_w, self.ser_fd, self.ptm_fd): + for fd in (self._wake_r, self._wake_w, self.ser_fd, self.ptm_fd, self.log_fd): if fd >= 0: try: os.close(fd) @@ -876,7 +938,7 @@ class ProxyService: pass self._wake_r = self._wake_w = -1 - self.ser_fd = self.ptm_fd = -1 + self.ser_fd = self.ptm_fd = self.log_fd = -1 log.info(f"[{self.link_id}] Cleanup complete") def stop(self) -> None: @@ -915,6 +977,7 @@ class DCEService: # Cache for detecting configuration changes self._config_cache: Dict[str, dict] = {} + self._logrotate_links: Set[str] = set() def start(self) -> bool: """Start service""" @@ -979,6 +1042,14 @@ class DCEService: def console_port_handler(self, key: str, op: str, data: dict) -> None: """CONSOLE_PORT table change handler""" log.info(f"DCE: CONSOLE_PORT change: key={key}, op={op}, data={data}") + if op == "DEL": + log.warning(f"DCE: [{key}] CONSOLE_PORT deleted from CONFIG_DB") + elif op == "SET" and self.config_db: + try: + full_entry = self.config_db.get_entry(CONSOLE_PORT_TABLE, key) + log.info(f"DCE: [{key}] CONSOLE_PORT full entry after change: {full_entry}") + except Exception as e: + log.debug(f"DCE: [{key}] Failed to read full CONSOLE_PORT entry: {e}") self._sync() def console_switch_handler(self, key: str, op: str, data: dict) -> None: @@ -1008,6 +1079,10 @@ class DCEService: key_str = str(key) if not isinstance(key, str) else key configs[key_str] = { "baud": int(entry.get("baud_rate", DEFAULT_BAUD)), + "logging_enabled": entry.get("logging_enabled", "no"), + "log_file": entry.get("log_file") or default_log_file(key_str), + "logrotate_size": entry.get("logrotate_size", DEFAULT_LOGROTATE_SIZE), + "logrotate_count": str(entry.get("logrotate_count", DEFAULT_LOGROTATE_COUNT)), } except Exception as e: log.error(f"DCE: Failed to get configs: {e}") @@ -1015,6 +1090,8 @@ class DCEService: def _sync(self) -> None: """Sync services with CONFIG_DB""" + self._sync_logrotate_configs() + # Check if feature is enabled if not self._check_feature_enabled(): if self.active_links: @@ -1042,17 +1119,73 @@ class DCEService: self.active_links.add(link_id) self._config_cache[link_id] = redis_configs[link_id] - # Restart links with changed configuration (e.g., baud rate) + # Restart links with changed configuration (e.g., baud rate, logging) for link_id in redis_ids & current_ids: new_config = redis_configs[link_id] old_config = self._config_cache.get(link_id, {}) if new_config != old_config: log.info(f"DCE: [{link_id}] Config changed: {old_config} -> {new_config}") + if (old_config.get("logging_enabled") != new_config.get("logging_enabled") or + old_config.get("log_file") != new_config.get("log_file") or + old_config.get("logrotate_size") != new_config.get("logrotate_size") or + old_config.get("logrotate_count") != new_config.get("logrotate_count")): + log.warning(f"DCE: [{link_id}] Logging config changed, proxy will restart") self._restart_link(link_id) self._config_cache[link_id] = new_config log.info(f"DCE: Sync complete, {len(self.active_links)} links active") + def _get_logging_configs(self) -> Dict[str, dict]: + """Get console logging configuration for all ports with logging enabled.""" + configs = {} + try: + table_data = self.config_db.get_table(CONSOLE_PORT_TABLE) + for key, entry in table_data.items(): + key_str = str(key) if not isinstance(key, str) else key + if entry.get("logging_enabled", "no") == "yes": + configs[key_str] = { + "log_file": entry.get("log_file") or default_log_file(key_str), + "logrotate_size": entry.get("logrotate_size", DEFAULT_LOGROTATE_SIZE), + "logrotate_count": int(entry.get("logrotate_count", DEFAULT_LOGROTATE_COUNT)), + } + except Exception as e: + log.error(f"DCE: Failed to get logging configs: {e}") + return configs + + def _sync_logrotate_configs(self) -> None: + """Create or remove logrotate configs for configured console log files.""" + desired_links = set() + try: + logging_configs = self._get_logging_configs() + desired_links = set(logging_configs.keys()) + + for link_id, cfg in logging_configs.items(): + conf_path = logrotate_conf_path(link_id) + conf_content = build_logrotate_config( + cfg["log_file"], + cfg["logrotate_size"], + cfg["logrotate_count"], + ) + try: + with open(conf_path, 'w') as conf_file: + conf_file.write(conf_content) + log.info(f"DCE: [{link_id}] Updated logrotate config: {conf_path}") + except OSError as e: + log.error(f"DCE: [{link_id}] Failed to write logrotate config {conf_path}: {e}") + + for link_id in self._logrotate_links - desired_links: + conf_path = logrotate_conf_path(link_id) + try: + if os.path.exists(conf_path): + os.remove(conf_path) + log.info(f"DCE: [{link_id}] Removed logrotate config: {conf_path}") + except OSError as e: + log.error(f"DCE: [{link_id}] Failed to remove logrotate config {conf_path}: {e}") + + self._logrotate_links = desired_links + except Exception as e: + log.error(f"DCE: Failed to sync logrotate configs: {e}") + def _start_link(self, link_id: str) -> bool: """Start pty-bridge and proxy for a link (pty-bridge first, then proxy)""" log.info(f"DCE: [{link_id}] Starting services...") diff --git a/tests/console_monitor/console_monitor_test.py b/tests/console_monitor/console_monitor_test.py index edf928c2..76e4dd78 100644 --- a/tests/console_monitor/console_monitor_test.py +++ b/tests/console_monitor/console_monitor_test.py @@ -16,6 +16,7 @@ import sys import time import copy +import tempfile import termios from unittest import TestCase, mock from parameterized import parameterized @@ -210,9 +211,13 @@ def test_dce_get_all_configs_parses_correctly(self): # Verify 3 ports are parsed self.assertEqual(len(configs), 3) - # Verify port 1 config (new format only has baud) + # Verify port 1 config self.assertIn("1", configs) self.assertEqual(configs["1"]["baud"], 9600) + self.assertEqual(configs["1"]["logging_enabled"], "no") + self.assertEqual(configs["1"]["log_file"], "/var/log/console-1.log") + self.assertEqual(configs["1"]["logrotate_size"], "1M") + self.assertEqual(configs["1"]["logrotate_count"], "20") # Verify port 2 config self.assertIn("2", configs) @@ -221,6 +226,43 @@ def test_dce_get_all_configs_parses_correctly(self): # Verify port 3 config self.assertIn("3", configs) self.assertEqual(configs["3"]["baud"], 9600) + + def test_dce_sync_logrotate_configs(self): + """Test _sync_logrotate_configs writes and removes logrotate files.""" + config_db = { + "CONSOLE_SWITCH": { + "console_mgmt": {"enabled": "yes"}, + }, + "CONSOLE_PORT": { + "1": { + "baud_rate": "9600", + "logging_enabled": "yes", + "log_file": "/var/log/console1.log", + "logrotate_size": "10M", + "logrotate_count": "5", + }, + "2": { + "baud_rate": "9600", + }, + }, + } + MockConfigDb.set_config_db(config_db) + + with tempfile.TemporaryDirectory() as tmpdir: + with mock.patch.object(console_monitor, 'LOGROTATE_DIR', tmpdir): + service = console_monitor.DCEService() + service.config_db = MockConfigDb() + service._sync_logrotate_configs() + + conf_path = os.path.join(tmpdir, "console-1") + self.assertTrue(os.path.exists(conf_path)) + with open(conf_path, 'r') as conf_file: + content = conf_file.read() + self.assertIn("/var/log/console1.log", content) + self.assertIn("size 10M", content) + self.assertIn("rotate 5", content) + self.assertIn("copytruncate", content) + self.assertFalse(os.path.exists(os.path.join(tmpdir, "console-2"))) def test_dce_sync_starts_services_when_enabled(self): """Test _sync starts pty-bridge and proxy services for each configured port when feature is enabled.""" @@ -762,6 +804,9 @@ def test_proxy_service_initialization(self): self.assertFalse(proxy.running) self.assertEqual(proxy.ser_fd, -1) self.assertEqual(proxy.ptm_fd, -1) + self.assertEqual(proxy.log_fd, -1) + self.assertFalse(proxy.logging_enabled) + self.assertEqual(proxy.log_file_path, "") def test_proxy_service_calculate_filter_timeout(self): """Test filter timeout calculation based on baud rate.""" @@ -1500,6 +1545,10 @@ def test_dce_get_all_configs_parses_correctly(self): # Check port 1 self.assertIn("1", configs) self.assertEqual(configs["1"]["baud"], 9600) + self.assertEqual(configs["1"]["logging_enabled"], "no") + self.assertEqual(configs["1"]["log_file"], "/var/log/console-1.log") + self.assertEqual(configs["1"]["logrotate_size"], "1M") + self.assertEqual(configs["1"]["logrotate_count"], "20") # Check port 2 self.assertIn("2", configs) @@ -2139,6 +2188,20 @@ def test_proxy_on_ptm_read(self): proxy._on_ptm_read() mock_write.assert_called_once_with(11, b"user input") + + def test_proxy_on_ptm_read_does_not_log_input(self): + """Test _on_ptm_read forwards to serial without logging (echo is logged on serial read).""" + proxy = console_monitor.ProxyService(link_id="1") + proxy.running = True + proxy.ptm_fd = 10 + proxy.ser_fd = 11 + proxy.log_fd = 12 + + with mock.patch('os.read', return_value=b"user input"): + with mock.patch('os.write') as mock_write: + proxy._on_ptm_read() + + mock_write.assert_called_once_with(11, b"user input") def test_proxy_on_ptm_read_handles_blocking_error(self): """Test _on_ptm_read handles BlockingIOError gracefully.""" @@ -2506,6 +2569,24 @@ def test_main_with_log_level(self): mock_log.assert_called_once_with('debug') +class TestLogrotateConfig(TestCase): + """Tests for console logrotate helper functions.""" + + def test_build_logrotate_config(self): + content = console_monitor.build_logrotate_config("/var/log/console1.log", "10M", 5) + self.assertIn("/var/log/console1.log", content) + self.assertIn("size 10M", content) + self.assertIn("rotate 5", content) + self.assertIn("copytruncate", content) + + def test_logrotate_conf_path(self): + with mock.patch.object(console_monitor, 'LOGROTATE_DIR', '/etc/logrotate.d'): + self.assertEqual( + console_monitor.logrotate_conf_path("1"), + "/etc/logrotate.d/console-1", + ) + + class TestCalculateFilterTimeout(TestCase): """Tests for calculate_filter_timeout function.""" @@ -2656,6 +2737,27 @@ def test_on_user_data_received_write_error(self): # Should not raise proxy._on_user_data_received(b"test data") + def test_on_user_data_received_logs_output(self): + """Test _on_user_data_received writes device output to the log file.""" + proxy = console_monitor.ProxyService(link_id="1") + proxy.ptm_fd = 10 + proxy.log_fd = 12 + + with mock.patch('os.write') as mock_write: + proxy._on_user_data_received(b"device output") + + mock_write.assert_any_call(12, b"device output") + mock_write.assert_any_call(10, b"device output") + + def test_write_log_skips_when_disabled(self): + """Test _write_log does nothing when log file is not open.""" + proxy = console_monitor.ProxyService(link_id="1") + proxy.log_fd = -1 + + with mock.patch('os.write') as mock_write: + proxy._write_log(b"ignored") + mock_write.assert_not_called() + class TestDCEServiceSystemctlFailures(TestCase): """Additional tests for DCE service systemctl failure handling."""