Decreased log verbosity from keeper-pam-webrtc-rs during terminal sesions

keepercommander/commands/pam_launch/launch.py

@@ -42,6 +42,10 @@
     unregister_tunnel_session,
     unregister_conversation_key,
 )
+from .rust_log_filter import (
+    enter_pam_launch_terminal_rust_logging,
+    exit_pam_launch_terminal_rust_logging,
+)
 from ..pam.gateway_helper import get_all_gateways
 from ..pam.router_helper import router_get_connected_gateways
 from ... import api, vault
@@ -749,7 +753,9 @@ def signal_handler_fn(signum, frame):
 
         original_handler = signal.signal(signal.SIGINT, signal_handler_fn)
 
+        rust_log_token = None
         try:
+            rust_log_token = enter_pam_launch_terminal_rust_logging()
             tube_id = tunnel_result['tunnel'].get('tube_id')
             if not tube_id:
                 raise CommandError('pam launch', 'No tube ID in tunnel result')
@@ -834,10 +840,18 @@ def signal_handler_fn(signum, frame):
             connect_as_supported = _version_at_least(remote_webrtc_version, CONNECT_AS_MIN_VERSION)
 
             if cli_user_override and effective_credential_uid and gateway_uid:
+                # When using userRecords[0] fallback, include explanation in CommandError if ConnectAs fails
+                connect_as_fallback_msg = ''
+                if launch_credential_uid is None:
+                    connect_as_fallback_msg = (
+                        f'Using credential from userRecords[0] ({effective_credential_uid}) as ConnectAs fallback because '
+                        'no launch credential on record; ConnectAs is enabled but no --credential was given. '
+                    )
                 if not connect_as_supported:
                     raise CommandError(
                         'pam launch',
-                        f'ConnectAs (--credential) requires Gateway with keeper-pam-webrtc-rs >= {CONNECT_AS_MIN_VERSION}. '
+                        connect_as_fallback_msg
+                        + f'ConnectAs (--credential) requires Gateway with keeper-pam-webrtc-rs >= {CONNECT_AS_MIN_VERSION}. '
                         f'Remote version: {remote_webrtc_version or "unknown"}. '
                         'Please upgrade the Gateway to use --credential.'
                     )
@@ -1057,8 +1071,11 @@ def signal_handler_fn(signum, frame):
 
                 logging.info("CLI session ended - cleanup complete")
 
+        except CommandError:
+            raise
         except Exception as e:
             logging.error(f"Error in PythonHandler CLI session: {e}")
             raise CommandError('pam launch', f'Failed to start CLI session: {e}')
         finally:
+            exit_pam_launch_terminal_rust_logging(rust_log_token)
             signal.signal(signal.SIGINT, original_handler)

keepercommander/commands/pam_launch/rust_log_filter.py

@@ -0,0 +1,143 @@
+"""
+Rust/webrtc log filtering for pam launch terminal session only.
+
+Downgrades Rust/webrtc/turn log messages to DEBUG so they only appear when --debug is on,
+and only while the pam launch CLI terminal session is active.
+"""
+
+import logging
+
+
+def _rust_webrtc_logger_name(name: str) -> bool:
+    """True if logger name is from Rust/webrtc/turn so we treat its messages as DEBUG-only."""
+    if not name:
+        return False
+    # Normalize so we match both '.' and '::' (Rust may use either when passed to Python)
+    n = (name or '').replace('::', '.')
+    return (
+        n.startswith('keeper_pam_webrtc_rs')
+        or n.startswith('webrtc')
+        or n.startswith('turn')
+        or n.startswith('stun')
+        or 'relay_conn' in n  # turn crate submodule
+    )
+
+
+class _RustWebrtcToDebugFilter(logging.Filter):
+    """
+    Filter for Rust/webrtc/turn log records.
+    When not in debug mode: suppress entirely (return False) so no handler can emit them.
+    When in debug mode: allow (return True); downgrading to DEBUG is redundant but harmless.
+    """
+
+    def filter(self, record: logging.LogRecord) -> bool:
+        if not _rust_webrtc_logger_name(record.name):
+            return True
+        # Only show these messages when debug is enabled (root or effective level is DEBUG)
+        if logging.getLogger().getEffectiveLevel() <= logging.DEBUG:
+            return True
+        return False  # suppress when not in debug
+
+
+class _RustAwareLogger(logging.Logger):
+    """
+    Logger that forces Rust/webrtc/turn loggers to have no handlers and propagate to root,
+    and applies the downgrade filter at the logger so messages are DEBUG-only.
+    Used so loggers created *after* enter_ (e.g. by turn crate on first use) are still suppressed.
+    """
+
+    def __init__(self, name, level=logging.NOTSET):
+        super().__init__(name, level)
+        if _rust_webrtc_logger_name(name):
+            self.setLevel(logging.DEBUG)
+            self.propagate = True
+            self.handlers.clear()
+            self.addFilter(_RustWebrtcToDebugFilter())
+
+
+_WEBRTC_CRATE_NAMES = [
+    'webrtc', 'webrtc_ice', 'webrtc_mdns', 'webrtc_dtls',
+    'webrtc_sctp', 'turn', 'stun', 'webrtc_ice.agent.agent_internal',
+    'webrtc_ice.agent.agent_gather', 'webrtc_ice.mdns',
+    'webrtc_mdns.conn', 'webrtc.peer_connection', 'turn.client',
+    'turn.client.relay_conn',  # turn crate submodule that emits "fail to refresh permissions..."
+]
+
+
+def enter_pam_launch_terminal_rust_logging():
+    """
+    Apply Rust/webrtc log filtering only during pam launch terminal session.
+    Downgrades Rust/webrtc/turn messages to DEBUG so they only show with --debug.
+    Returns a token to pass to exit_pam_launch_terminal_rust_logging() on exit.
+    """
+    root = logging.getLogger()
+    flt = _RustWebrtcToDebugFilter()
+    root.addFilter(flt)
+
+    # Use custom Logger class so any Rust/webrtc logger created later (e.g. turn crate)
+    # gets no handlers and propagates to root, where our filter downgrades to DEBUG.
+    _original_logger_class = logging.getLoggerClass()
+    logging.setLoggerClass(_RustAwareLogger)
+
+    saved = []
+    downgrade_filter = _RustWebrtcToDebugFilter()
+    for name in list(logging.Logger.manager.loggerDict.keys()):
+        if not isinstance(name, str) or not _rust_webrtc_logger_name(name):
+            continue
+        log = logging.getLogger(name)
+        # Only save if it's a real Logger with state we can restore (not our custom class yet)
+        if not isinstance(log, _RustAwareLogger):
+            saved.append((name, log.level, log.propagate, list(log.handlers)))
+        log.setLevel(logging.DEBUG)
+        log.propagate = True
+        log.handlers.clear()
+        if downgrade_filter not in log.filters:
+            log.addFilter(downgrade_filter)
+    for crate_name in _WEBRTC_CRATE_NAMES:
+        log = logging.getLogger(crate_name)
+        if not isinstance(log, _RustAwareLogger):
+            saved.append((crate_name, log.level, log.propagate, list(log.handlers)))
+        log.setLevel(logging.DEBUG)
+        log.propagate = True
+        log.handlers.clear()
+        if downgrade_filter not in log.filters:
+            log.addFilter(downgrade_filter)
+
+    return (flt, saved, _original_logger_class)
+
+
+def exit_pam_launch_terminal_rust_logging(token):
+    """Restore Rust/webrtc logger state after pam launch terminal session. Pass token from enter_pam_launch_terminal_rust_logging()."""
+    if not token:
+        return
+    flt, saved = token[0], token[1]
+    original_logger_class = token[2] if len(token) > 2 else logging.Logger
+    logging.setLoggerClass(original_logger_class)
+    root = logging.getLogger()
+    root.removeFilter(flt)
+    # Remove downgrade filter from all Rust/webrtc loggers (we may have added the shared
+    # filter to existing loggers, and _RustAwareLogger instances have their own filter)
+    for name in list(logging.Logger.manager.loggerDict.keys()):
+        if not isinstance(name, str) or not _rust_webrtc_logger_name(name):
+            continue
+        log = logging.getLogger(name)
+        for f in list(log.filters):
+            if isinstance(f, _RustWebrtcToDebugFilter):
+                try:
+                    log.removeFilter(f)
+                except ValueError:
+                    pass
+    for crate_name in _WEBRTC_CRATE_NAMES:
+        log = logging.getLogger(crate_name)
+        for f in list(log.filters):
+            if isinstance(f, _RustWebrtcToDebugFilter):
+                try:
+                    log.removeFilter(f)
+                except ValueError:
+                    pass
+    for name, level, propagate, handlers in saved:
+        log = logging.getLogger(name)
+        log.setLevel(level)
+        log.propagate = propagate
+        for h in handlers:
+            log.addHandler(h)

keepercommander/commands/tunnel/port_forward/tunnel_helpers.py

@@ -4,6 +4,7 @@
 import logging
 import re
 import os
+import threading
 import secrets
 import socket
 import string
@@ -113,7 +114,6 @@ def set_remote_description_and_parse_version(tube_registry, tube_id, sdp, is_ans
 # ICE candidate buffering - store until SDP answer is received
 
 # Global conversation key management for multiple concurrent tunnels
-import threading
 _CONVERSATION_KEYS_LOCK = threading.Lock()
 _GLOBAL_CONVERSATION_KEYS = {}  # conversationId -> symmetric_key mapping
 
@@ -383,7 +383,6 @@ def _configure_rust_logger_levels(current_is_debug: bool, log_level: int):
         # CRITICAL: Ensure root logger has a handler
         # pyo3_log sends Rust logs to Python loggers, but if loggers have no handlers,
         # messages are lost even if propagate=True
-        import sys
         if not root_logger.handlers:
             # Add a console handler if none exists
             console_handler = logging.StreamHandler(sys.stderr)
@@ -1534,17 +1533,17 @@ def signal_from_rust(self, response: dict):
 
             # Detailed logging for specific states
             if new_state == 'disconnected':
-                logging.warning(f"Connection disconnected for tube {tube_id} - ICE restart may be attempted by Rust")
+                logging.debug(f"Connection disconnected for tube {tube_id} - ICE restart may be attempted by Rust")
 
             elif new_state == 'failed':
-                logging.error(f"Connection failed for tube {tube_id} - ICE restart may be attempted by Rust")
+                logging.debug(f"Connection failed for tube {tube_id} - ICE restart may be attempted by Rust")
 
             elif new_state == 'connected':
                 logging.debug(
                     f"Connection established/restored for tube {tube_id} "
                     f"(conversation_id={conversation_id_from_signal or self.conversation_id})"
                 )
-                logging.debug(f"Connection state: connected")
+                logging.debug("Connection state: connected")
 
                 # CRITICAL: Mark connection as connected - IMMEDIATELY stop sending ICE candidates
                 self.connection_connected = True
@@ -1651,9 +1650,9 @@ def signal_from_rust(self, response: dict):
                         logging.debug(f"Stopping dedicated WebSocket for tunnel {tube_id}")
                         session.websocket_stop_event.set()  # Signal WebSocket to close
                         # Give it a moment to close gracefully
-                        session.websocket_thread.join(timeout=2.0)
+                        session.websocket_thread.join(timeout=5.0)
                         if session.websocket_thread.is_alive():
-                            logging.warning(f"Dedicated WebSocket for tunnel {tube_id} did not close in time")
+                            logging.debug(f"Dedicated WebSocket for tunnel {tube_id} did not close in time")
                         else:
                             logging.debug(f"Dedicated WebSocket closed for tunnel {tube_id}")
 
@@ -1678,9 +1677,9 @@ def signal_from_rust(self, response: dict):
                         logging.debug(f"Stopping dedicated WebSocket for failed tunnel {tube_id}")
                         session.websocket_stop_event.set()  # Signal WebSocket to close
                         # Give it a moment to close gracefully
-                        session.websocket_thread.join(timeout=2.0)
+                        session.websocket_thread.join(timeout=5.0)
                         if session.websocket_thread.is_alive():
-                            logging.warning(f"Dedicated WebSocket for tunnel {tube_id} did not close in time")
+                            logging.debug(f"Dedicated WebSocket for tunnel {tube_id} did not close in time")
                         else:
                             logging.debug(f"Dedicated WebSocket closed for failed tunnel {tube_id}")