From 73294c23916787b2114f3c52c149922db9c596f2 Mon Sep 17 00:00:00 2001 From: Sonic Build Admin Date: Wed, 1 Jul 2026 04:26:30 +0000 Subject: [PATCH] [PMON] Bmcctld improvements & thermalctld: push thermals from Switch-Host --> BMC MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit *** **Changes in this PR** *** Fixes issue: https://github.com/sonic-net/sonic-platform-daemons/issues/824 **sonic-bmcctld/scripts/bmcctld** - Conditional SWITCH_HOST_POWER_ON_DELAY - applied only on REBOOT_CAUSE_POWER_LOSS; skipped on warm/fast/soft reboot. - GracefulShutdownHandler.execute() cleaned up - Event-log de-duplication across handler functions - Rack manager alert : skip when incoming alert matches to existing alert level, prevents unnecessary pub/sub events - chassis module admin_status : skip when admin_status don't change, prevents unnecessary pub/sub events - Uses self.chassis.is_liquid_cooled() platform API. - Update the init_host_state API to derive the device_power_state from get_oper_status platform API which will either ONLINE/OFFLINE. - Set the default graceful_shutdown_timeout = 0 till we support GNOI graceful shutdown **sonic-thermalctld/scripts/thermalctld** - EventLogger class added - stores critical events to syslog and /host/bmc/event.log. - Switch-Host ↔ BMC, thermals are pushed to BMC, via TEMPERATURE_INFO_STATE_DB table - critical temperature breaches logged into BMC event log. - LiquidCoolingUpdater improvements: - writes SYSTEM_LEAK_STATUS only on transitions - Per-sensor state updates also only on transitions - Added the Leak severity escalation logic (MINOR → CRITICAL after max_minor_duration_sec). - Critical leaks logged via event_logger. - Add logic to use self.chassis.is_liquid_cooled() also to identify liquid cooled platforms" Signed-off-by: Sonic Build Admin --- sonic-bmcctld/scripts/bmcctld | 230 ++++----- sonic-bmcctld/tests/mock_platform.py | 16 + .../mocked_libs/sonic_py_common/syslogger.py | 23 + sonic-bmcctld/tests/test_bmcctld.py | 144 ++++-- sonic-thermalctld/scripts/thermalctld | 316 +++++++++++- .../mocked_libs/swsscommon/swsscommon.py | 7 +- sonic-thermalctld/tests/test_thermalctld.py | 466 +++++++++++++++++- 7 files changed, 1040 insertions(+), 162 deletions(-) create mode 100644 sonic-bmcctld/tests/mocked_libs/sonic_py_common/syslogger.py diff --git a/sonic-bmcctld/scripts/bmcctld b/sonic-bmcctld/scripts/bmcctld index 2ce8bfa..35acfde 100644 --- a/sonic-bmcctld/scripts/bmcctld +++ b/sonic-bmcctld/scripts/bmcctld @@ -50,13 +50,7 @@ try: from datetime import datetime from sonic_py_common import daemon_base, logger - - try: - from sonic_py_common import is_liquid_cooled - except ImportError: - # Fall back to liquid-cooled (safe default — full monitoring enabled) - def is_liquid_cooled(): - return True + from sonic_platform_base.chassis_base import ChassisBase if os.getenv("BMCCTLD_UNIT_TESTING") == "1": from tests import mock_swsscommon as swsscommon @@ -87,13 +81,18 @@ class EventLogger(logger.Logger): os.path.basename(log_file).replace(".", "_")) self._file_logger = logging.getLogger(py_name) if not self._file_logger.handlers and os.getenv("BMCCTLD_UNIT_TESTING") != "1": - handler = logging.FileHandler(log_file) - handler.setFormatter(logging.Formatter( - "%(asctime)s %(name)s[%(process)d] %(levelname)s: %(message)s", - datefmt="%Y-%m-%dT%H:%M:%S", - )) - self._file_logger.addHandler(handler) - self._file_logger.setLevel(logging.DEBUG) + try: + handler = logging.FileHandler(log_file) + handler.setFormatter(logging.Formatter( + "%(asctime)s %(name)s[%(process)d] %(levelname)s: %(message)s", + datefmt="%Y-%m-%dT%H:%M:%S", + )) + self._file_logger.addHandler(handler) + self._file_logger.setLevel(logging.DEBUG) + except (OSError, IOError) as e: + self.log_error( + "EventLogger: failed to open log file {} ({}); events will go to syslog only".format( + log_file, repr(e))) def log_debug(self, msg, also_print_to_console=False): super(EventLogger, self).log_debug(msg, also_print_to_console) @@ -228,7 +227,8 @@ DEFAULT_RACK_MGR_MINOR_ALERT_ACTION = ACTION_SYSLOG_ONLY # Default timing values (seconds) DEFAULT_POWER_ON_DELAY_SECS = 0 # 0 seconds - power on Switch-Host immediately by default -DEFAULT_SHUTDOWN_DELAY_SECS = 120 # 2 minutes - wait for graceful shutdown before force +DEFAULT_SHUTDOWN_DELAY_SECS = 0 # default 0 until real GNOI graceful shutdown is supported; + # operator may override via CHASSIS_MODULE|SWITCH-HOST/graceful_shutdown_timeout # Switch-Host module name key in CHASSIS_MODULE table SWITCH_HOST_MODULE_KEY = "SWITCH-HOST" @@ -351,8 +351,8 @@ class SwitchHostController(EventLogger): Poll get_oper_status() until it matches expected_status or timeout_secs elapses. Returns True when confirmed, False on timeout. """ - deadline = time.time() + timeout_secs - while time.time() < deadline: + deadline = time.monotonic() + timeout_secs + while time.monotonic() < deadline: if self.get_oper_status() == expected_status: self.log_info("{}: oper_status confirmed {}".format(context, expected_status)) return True @@ -473,20 +473,15 @@ class SwitchHostController(EventLogger): return fvs_to_dict(result[1]).get(FIELD_DEVICE_POWER_STATE, NOT_AVAILABLE) return NOT_AVAILABLE - def refresh_host_state(self): - """Refresh HOST_STATE with current oper_status, preserving last power state. + def init_host_state(self): + """Set device_power_state from live oper_status (ONLINE -> POWERED_ON, OFFLINE -> POWERED_OFF). - If no prior power state is recorded (N/A), infer it from oper_status: - ONLINE -> POWER_ON, OFFLINE -> POWER_OFF. + Called only at daemon startup. Any persisted transitional state from a prior + interrupted run is overwritten with the stable value derived from live oper_status. """ - result = self.host_state_table.get(HOST_STATE_KEY) - cur_power_state = NOT_AVAILABLE - if result and result[0]: - cur_power_state = fvs_to_dict(result[1]).get(FIELD_DEVICE_POWER_STATE, NOT_AVAILABLE) oper_status = self.get_oper_status() - if cur_power_state == NOT_AVAILABLE: - cur_power_state = POWER_STATE_ON if str(oper_status).upper() == SWITCH_HOST_ONLINE else POWER_STATE_OFF - self._update_host_state(cur_power_state, oper_status) + power_state = POWER_STATE_ON if str(oper_status).upper() == SWITCH_HOST_ONLINE else POWER_STATE_OFF + self._update_host_state(power_state, oper_status) def initialize_chassis_module_info(self, admin_status): """Populate CHASSIS_MODULE_TABLE|SWITCH-HOST in STATE_DB at daemon startup. @@ -565,7 +560,7 @@ class PolicyReader(EventLogger): return DEFAULT_POWER_ON_DELAY_SECS def get_graceful_shutdown_timeout(self): - """Return graceful_shutdown_timeout in seconds from CHASSIS_MODULE|SWITCH-HOST (default: 120).""" + """Return graceful_shutdown_timeout in seconds from CHASSIS_MODULE|SWITCH-HOST (default: 0).""" raw = self._get_chassis_module_entry().get(FIELD_GRACEFUL_SHUTDOWN_TIMEOUT) if raw is not None: try: @@ -598,7 +593,7 @@ class PolicyReader(EventLogger): # CriticalEventChecker # ============================================================ -class CriticalEventChecker(EventLogger): +class CriticalEventChecker(logger.Logger): """Checks current system and Rack Manager leak/alert status from STATE_DB.""" # Alert keys in RACK_MANAGER_ALERT table @@ -610,7 +605,7 @@ class CriticalEventChecker(EventLogger): ] def __init__(self, policy_reader): - super(CriticalEventChecker, self).__init__(SYSLOG_IDENTIFIER, CRITICAL_EVENT_LOG_FILE) + super(CriticalEventChecker, self).__init__(SYSLOG_IDENTIFIER) self.state_db = daemon_base.db_connect("STATE_DB") self.policy_reader = policy_reader @@ -620,8 +615,6 @@ class CriticalEventChecker(EventLogger): result = tbl.get(SYSTEM_LEAK_STATUS_KEY) if result and result[0]: if fvs_to_dict(result[1]).get(FIELD_DEVICE_LEAK_STATUS) == SYSTEM_LEAK_CRITICAL: - _event_logger.log_error("CRITICAL system leak detected in {}: {}={}".format( - SYSTEM_LEAK_STATUS_TABLE, FIELD_DEVICE_LEAK_STATUS, SYSTEM_LEAK_CRITICAL)) return True return False @@ -635,8 +628,6 @@ class CriticalEventChecker(EventLogger): # severity field for temperature/flow/pressure; leak field for rack-level leak severity = d.get(FIELD_SEVERITY) or d.get(FIELD_LEAK, ALERT_SEVERITY_NORMAL) if severity == ALERT_SEVERITY_CRITICAL: - _event_logger.log_error("CRITICAL Rack Manager alert: key={} severity={}".format( - alert_key, severity)) return True return False @@ -674,7 +665,8 @@ class GracefulShutdownHandler(EventLogger): """ def __init__(self, controller, policy_reader): - super(GracefulShutdownHandler, self).__init__(SYSLOG_IDENTIFIER, CRITICAL_EVENT_LOG_FILE) + super(GracefulShutdownHandler, self).__init__(SYSLOG_IDENTIFIER, DEFAULT_LOG_FILE) + self._event_log = _event_logger # for critical leak / alert events only self.controller = controller self.policy_reader = policy_reader @@ -697,29 +689,31 @@ class GracefulShutdownHandler(EventLogger): # graceful_shutdown_timeout == 0 means skip GNOI and force power-off immediately if graceful_shutdown_timeout == 0: self.log_notice("graceful_shutdown_timeout is 0: forcing immediate power OFF") - return self.controller.power_off() - - try: - gnoi_ok = self._issue_gnoi_shutdown() - except Exception as e: - self.log_error("Unexpected error during GNOI shutdown: {}".format(repr(e))) - self.controller._update_host_state(prior_power_state, prior_status) - return False - - if not gnoi_ok: - self.log_warning("GNOI shutdown request failed; proceeding with power OFF") else: - # Wait up to graceful_shutdown_timeout for Switch-Host to go OFFLINE gracefully - self.log_info("Waiting up to {}s for Switch-Host to go OFFLINE...".format(graceful_shutdown_timeout)) - went_offline = self.controller._verify_oper_status( - SWITCH_HOST_OFFLINE, graceful_shutdown_timeout, "graceful_shutdown") - if went_offline: - self.log_notice("Switch-Host went OFFLINE gracefully; issuing power OFF") - else: - self.log_warning("Graceful shutdown timed out after {}s; issuing power OFF".format( - graceful_shutdown_timeout)) + try: + gnoi_ok = self._issue_gnoi_shutdown() + except Exception as e: + self.log_error("Unexpected error during GNOI shutdown: {}".format(repr(e))) + self.controller._update_host_state(prior_power_state, prior_status) + return False - return self.controller.power_off() + if not gnoi_ok: + self.log_warning("GNOI shutdown request failed; proceeding with power OFF") + else: + # Wait up to graceful_shutdown_timeout for Switch-Host to go OFFLINE gracefully + self.log_info("Waiting up to {}s for Switch-Host to go OFFLINE...".format(graceful_shutdown_timeout)) + went_offline = self.controller._verify_oper_status( + SWITCH_HOST_OFFLINE, graceful_shutdown_timeout, "graceful_shutdown") + if went_offline: + self.log_notice("Switch-Host went OFFLINE gracefully; issuing power OFF") + else: + self.log_warning("Graceful shutdown timed out after {}s; issuing power OFF".format( + graceful_shutdown_timeout)) + + success = self.controller.power_off() + self._event_log.log_notice("GRACEFUL_SHUTDOWN done: success={} (timeout={}s)".format( + success, graceful_shutdown_timeout)) + return success def _issue_gnoi_shutdown(self): # TODO: This approach of calling gnoi_client to be replaced by idea in this PR @@ -800,6 +794,13 @@ class BmcEventHandler(EventLogger): self.state_db = daemon_base.db_connect("STATE_DB") self.config_db = daemon_base.db_connect("CONFIG_DB") + # Act on RACK_MANAGER_ALERT severity changes only. + # Rack Manager (redfish docker) may republish identical rows each cycle. + self._last_rack_mgr_alert_severity = {} + + # Act on CHASSIS_MODULE admin_status transitions only. + self._last_chassis_module_admin_status = {} + # One SubscriberStateTable per watched table self.rack_mgr_cmd_sub = swsscommon.SubscriberStateTable( self.state_db, RACK_MANAGER_COMMAND_TABLE) @@ -868,12 +869,15 @@ class BmcEventHandler(EventLogger): if command == CMD_POWER_ON: if self.critical_event_checker.has_any_critical_event(): - self.log_warning("POWER_ON blocked: active critical leak or alert") + self._event_log.log_warning( + "RACK_MGR_CMD FAILED: key={} command={} reason=CRITICAL_LEAK_PRESENT " + "(active critical leak or alert)".format(key, command)) self._set_cmd_status(key, CMD_STATUS_FAILED, "CRITICAL_LEAK_PRESENT") return elif command not in (CMD_POWER_OFF, CMD_GRACEFUL_SHUT, CMD_POWER_CYCLE): - self.log_warning("Unknown Rack Manager command: {}".format(command)) + self._event_log.log_warning( + "RACK_MGR_CMD FAILED: key={} command={} reason=UNKNOWN_COMMAND".format(key, command)) self._set_cmd_status(key, CMD_STATUS_FAILED, "UNKNOWN_COMMAND") return @@ -884,7 +888,7 @@ class BmcEventHandler(EventLogger): CMD_POWER_CYCLE: ACTION_POWER_CYCLE, } - def on_complete(success, cmd_key=key): + def on_complete(success, cmd_key=key, cmd=command): self._set_cmd_status(cmd_key, CMD_STATUS_DONE if success else CMD_STATUS_FAILED, "SUCCESS" if success else "ERROR") @@ -896,25 +900,34 @@ class BmcEventHandler(EventLogger): def _handle_chassis_module(self, key, fvs): """Process CHASSIS_MODULE admin_status change (admin up/down from CLI).""" admin_status = fvs.get(FIELD_ADMIN_STATUS, "") + if not admin_status: + return + if self._last_chassis_module_admin_status.get(key) == admin_status: + return + self._last_chassis_module_admin_status[key] = admin_status + self.log_notice("CHASSIS_MODULE change: key={} admin_status={}".format(key, admin_status)) # Mirror admin_status to CHASSIS_MODULE_INFO_TABLE immediately on config change - if admin_status: - self.controller.update_chassis_module_admin_status(admin_status) + self.controller.update_chassis_module_admin_status(admin_status) if admin_status == ADMIN_DOWN: if self.controller.get_db_device_status() != SWITCH_HOST_ONLINE: - self.log_info("admin_down: Switch-Host already OFFLINE; no action needed") + self._event_log.log_notice( + "CHASSIS_MODULE admin_down: key={} NOOP (Switch-Host already OFFLINE)".format(key)) return self.log_notice("CHASSIS_MODULE admin_down: initiating graceful shutdown of Switch-Host") self.action_queue.put(ActionItem(ACTION_GRACEFUL_SHUTDOWN, "CHASSIS_MODULE:ADMIN_DOWN")) elif admin_status == ADMIN_UP: if self.controller.get_db_device_status() == SWITCH_HOST_ONLINE: - self.log_info("admin_up: Switch-Host already ONLINE; no action needed") + self._event_log.log_notice( + "CHASSIS_MODULE admin_up: key={} NOOP (Switch-Host already ONLINE)".format(key)) return if self.critical_event_checker.has_any_critical_event(): - self.log_warning("admin_up: POWER_ON blocked by active critical leak or alert") + self._event_log.log_warning( + "CHASSIS_MODULE admin_up: key={} BLOCKED " + "(CRITICAL_LEAK_PRESENT: active critical leak or alert)".format(key)) return self.log_notice("CHASSIS_MODULE admin_up: powering ON Switch-Host") self.action_queue.put(ActionItem(ACTION_POWER_ON, "CHASSIS_MODULE:ADMIN_UP")) @@ -928,7 +941,9 @@ class BmcEventHandler(EventLogger): policy = self.policy_reader.get_leak_control_policy() if policy.get("system_leak_policy") == "disabled": - self.log_info("system_leak_policy disabled; skipping leak event key={}".format(key)) + self._event_log.log_notice( + "SYSTEM_LEAK handler done: key={} status={} result=SKIPPED (policy=disabled)".format( + key, leak_status)) return if leak_status == SYSTEM_LEAK_CRITICAL: @@ -942,37 +957,9 @@ class BmcEventHandler(EventLogger): self._dispatch_action(action, "MINOR_SYSTEM_LEAK") else: - self.log_notice("System leak cleared (status={}); no automatic power-on".format(leak_status)) - - def _log_host_thermal_sensors_above_threshold(self): - """Read TEMPERATURE_INFO from STATE_DB and log any sensor in warning state.""" - try: - tbl = swsscommon.Table(self.state_db, "TEMPERATURE_INFO") - keys = tbl.getKeys() - above = [] - for sensor_name in keys: - result = tbl.get(sensor_name) - if not result or not result[0]: - continue - d = fvs_to_dict(result[1]) - if str(d.get("warning", "False")).lower() == "true": - above.append( - " {} temp={} high_th={} crit_high_th={}".format( - sensor_name, - d.get("temperature", NOT_AVAILABLE), - d.get("high_threshold", NOT_AVAILABLE), - d.get("critical_high_threshold", NOT_AVAILABLE), - ) - ) - if above: - self._event_log.log_notice( - "Switch-Host thermal sensors above threshold ({} sensor(s)):\n{}".format( - len(above), "\n".join(above))) - else: - self._event_log.log_notice( - "Switch-Host: no thermal sensors above threshold at time of alert") - except Exception as e: - self.log_warning("Failed to read Switch-Host thermal sensors: {}".format(repr(e))) + self._event_log.log_notice( + "SYSTEM_LEAK handler done: key={} status={} result=CLEARED (no action)".format( + key, leak_status)) def _handle_rack_mgr_alert(self, key, fvs): """Process RACK_MANAGER_ALERT change from Rack Manager (via redfish docker).""" @@ -980,14 +967,22 @@ class BmcEventHandler(EventLogger): policy = self.policy_reader.get_leak_control_policy() if policy.get("rack_mgr_leak_policy") == "disabled": - self.log_info("rack_mgr_leak_policy disabled; skipping alert key={}".format(key)) + # Log only on transition; do NOT update dedup state so that a later + # policy re-enable + same severity re-publish still dispatches the action. + if self._last_rack_mgr_alert_severity.get(key) != severity: + self._event_log.log_notice( + "RACK_MGR_ALERT handler done: key={} severity={} result=SKIPPED (policy=disabled)".format( + key, severity)) + return + + if self._last_rack_mgr_alert_severity.get(key) == severity: return + self._last_rack_mgr_alert_severity[key] = severity if severity == ALERT_SEVERITY_CRITICAL: action = policy.get("rack_mgr_critical_alert_action", DEFAULT_RACK_MGR_CRITICAL_ALERT_ACTION) self._event_log.log_notice("CRITICAL RACK MGR ALERT (severity={} key={}); " "action={}".format(severity, key, action)) - self._log_host_thermal_sensors_above_threshold() self._dispatch_action(action, "RACK_MGR_CRITICAL_EVENT key={}".format(key)) elif severity in (ALERT_SEVERITY_MINOR, ALERT_SEVERITY_MAJOR): @@ -995,7 +990,9 @@ class BmcEventHandler(EventLogger): self._dispatch_action(action, "RACK_MGR_MINOR_EVENT key={}".format(key)) else: - self.log_info("Rack Manager alert cleared for key={}; no action taken".format(key)) + self._event_log.log_notice( + "RACK_MGR_ALERT handler done: key={} severity={} result=CLEARED (no action)".format( + key, severity)) # ---- dispatch helpers ---- @@ -1134,15 +1131,28 @@ class BmcctldDaemon(daemon_base.DaemonBase): "Run 'config chassis modules startup SWITCH-HOST' to power on.".format(admin_status)) return - # TODO : Optimize by adding this delay only to a case when there is a cold boot - boot_delay = self.policy_reader.get_power_on_delay() - self.log_notice("Waiting {}s before initial Switch-Host power-on check " - "(SWITCH_HOST_POWER_ON_DELAY)".format(boot_delay)) + # Only apply the boot delay on a cold boot (FULL POWER LOSS). On warm/fast/soft + # reboots, the Switch-Host is expected to come back quickly and Rack Manager/ + # liquid flow has already been verified, so the delay is unnecessary. + boot_delay = 0 + try: + reboot_cause, _ = self.chassis.get_reboot_cause() + except Exception as e: + self.log_warning("STARTUP: get_reboot_cause() failed: {}; assuming cold boot".format(repr(e))) + reboot_cause = ChassisBase.REBOOT_CAUSE_POWER_LOSS + + if reboot_cause == ChassisBase.REBOOT_CAUSE_POWER_LOSS: + boot_delay = self.policy_reader.get_power_on_delay() + self.log_notice("Waiting {}s before initial Switch-Host power-on check " + "(SWITCH_HOST_POWER_ON_DELAY, reboot_cause={})".format(boot_delay, reboot_cause)) + else: + self.log_notice("Skipping SWITCH_HOST_POWER_ON_DELAY (reboot_cause={}, not a full power loss)".format(reboot_cause)) # Drain the action queue while we wait so Rack Manager / admin commands - # received during the boot delay are processed in real time. - deadline = time.time() + boot_delay - while time.time() < deadline: + # received during the boot delay are processed in real time. Use a + # monotonic clock so an NTP step during boot can't extend the wait. + deadline = time.monotonic() + boot_delay + while time.monotonic() < deadline: if self.stop_event.is_set(): return try: @@ -1172,7 +1182,7 @@ class BmcctldDaemon(daemon_base.DaemonBase): self.controller.power_on() else: self._event_log.log_notice("STARTUP: Switch-Host already ONLINE; refreshing HOST_STATE") - self.controller.refresh_host_state() + self.controller.init_host_state() def _execute_action_item(self, item): """ @@ -1266,8 +1276,8 @@ class BmcctldDaemon(daemon_base.DaemonBase): if self.controller.get_oper_status() == SWITCH_HOST_ONLINE: self._event_log.log_notice("STARTUP: Switch-Host already ONLINE (daemon restart); " "skipping boot sequence") - self.controller.refresh_host_state() - elif not is_liquid_cooled(): + self.controller.init_host_state() + elif not self.chassis.is_liquid_cooled(): self._event_log.log_notice("STARTUP: non-liquid-cooled system — " "immediate power_on, no additional checks") self.controller.power_on() diff --git a/sonic-bmcctld/tests/mock_platform.py b/sonic-bmcctld/tests/mock_platform.py index 1fcd913..0cd6a60 100644 --- a/sonic-bmcctld/tests/mock_platform.py +++ b/sonic-bmcctld/tests/mock_platform.py @@ -60,6 +60,9 @@ def do_power_cycle(self): class MockChassis: """Simulates a sonic_platform_base.chassis_base.ChassisBase with two modules.""" + REBOOT_CAUSE_POWER_LOSS = "Power Loss" + REBOOT_CAUSE_NON_HARDWARE = "Non-Hardware" + def __init__(self): bmc = MockModule(0, "BMC", MockModule.MODULE_TYPE_BMC) switch_host = MockModule( @@ -67,6 +70,7 @@ def __init__(self): oper_status=MockModule.MODULE_STATUS_OFFLINE ) self._module_list = [bmc, switch_host] + self._reboot_cause = (self.REBOOT_CAUSE_POWER_LOSS, "") def get_all_modules(self): return self._module_list @@ -77,6 +81,18 @@ def get_module(self, index): def get_num_modules(self): return len(self._module_list) + def get_reboot_cause(self): + return self._reboot_cause + + def set_reboot_cause(self, cause, description=""): + self._reboot_cause = (cause, description) + + def is_liquid_cooled(self): + return getattr(self, '_liquid_cooled', True) + + def set_liquid_cooled(self, val): + self._liquid_cooled = val + @property def switch_host(self): return self._module_list[1] diff --git a/sonic-bmcctld/tests/mocked_libs/sonic_py_common/syslogger.py b/sonic-bmcctld/tests/mocked_libs/sonic_py_common/syslogger.py new file mode 100644 index 0000000..c918d69 --- /dev/null +++ b/sonic-bmcctld/tests/mocked_libs/sonic_py_common/syslogger.py @@ -0,0 +1,23 @@ +import logging + + +class SysLogger(object): + """Test stub matching sonic_py_common.syslogger.SysLogger.""" + + def __init__(self, *_args, **_kwargs): + self.logger = logging.getLogger("syslogger_stub") + + def log_debug(self, *_args, **_kwargs): + pass + + def log_info(self, *_args, **_kwargs): + pass + + def log_notice(self, *_args, **_kwargs): + pass + + def log_warning(self, *_args, **_kwargs): + pass + + def log_error(self, *_args, **_kwargs): + pass diff --git a/sonic-bmcctld/tests/test_bmcctld.py b/sonic-bmcctld/tests/test_bmcctld.py index 1356439..5ebc20c 100644 --- a/sonic-bmcctld/tests/test_bmcctld.py +++ b/sonic-bmcctld/tests/test_bmcctld.py @@ -279,29 +279,19 @@ def test_get_switch_host_module_fallback_index_1(self): mod = ctrl._get_switch_host_module() assert mod is ch._module_list[1] - def test_refresh_host_state_preserves_power_state(self, chassis, controller): - controller.power_on() - chassis.switch_host.set_oper_status(MockModule.MODULE_STATUS_ONLINE) - controller.refresh_host_state() - result = controller.host_state_table.get(bmcctld.HOST_STATE_KEY) - state = dict(result[1]) - # power state must still be POWER_ON - assert state[bmcctld.FIELD_DEVICE_POWER_STATE] == bmcctld.POWER_STATE_ON - assert state[bmcctld.FIELD_DEVICE_STATUS] == bmcctld.SWITCH_HOST_ONLINE - - def test_refresh_host_state_infers_power_on_when_not_available(self, chassis, controller): + def test_init_host_state_infers_power_on_when_not_available(self, chassis, controller): # No prior power state recorded — host is ONLINE, so infer POWER_ON chassis.switch_host.set_oper_status(MockModule.MODULE_STATUS_ONLINE) - controller.refresh_host_state() + controller.init_host_state() result = controller.host_state_table.get(bmcctld.HOST_STATE_KEY) state = dict(result[1]) assert state[bmcctld.FIELD_DEVICE_POWER_STATE] == bmcctld.POWER_STATE_ON assert state[bmcctld.FIELD_DEVICE_STATUS] == bmcctld.SWITCH_HOST_ONLINE - def test_refresh_host_state_infers_power_off_when_not_available(self, chassis, controller): + def test_init_host_state_infers_power_off_when_not_available(self, chassis, controller): # No prior power state recorded — host is OFFLINE, so infer POWER_OFF chassis.switch_host.set_oper_status(MockModule.MODULE_STATUS_OFFLINE) - controller.refresh_host_state() + controller.init_host_state() result = controller.host_state_table.get(bmcctld.HOST_STATE_KEY) state = dict(result[1]) assert state[bmcctld.FIELD_DEVICE_POWER_STATE] == bmcctld.POWER_STATE_OFF @@ -317,11 +307,11 @@ def test_verify_oper_status_matches_immediately(self, chassis, controller): mock_sleep.assert_not_called() @patch('time.sleep') - @patch('time.time') - def test_verify_oper_status_timeout(self, mock_time, mock_sleep, chassis, controller): + @patch('time.monotonic') + def test_verify_oper_status_timeout(self, mock_monotonic, mock_sleep, chassis, controller): # Simulate: deadline set at t=0+30=30, first loop check t=0 (<30), sleep, # second loop check t=31 (>=30) → exit without match - mock_time.side_effect = [0, 0, 31, 31] + mock_monotonic.side_effect = [0, 0, 31, 31] chassis.switch_host.set_oper_status(MockModule.MODULE_STATUS_OFFLINE) result = controller._verify_oper_status(bmcctld.SWITCH_HOST_ONLINE, 30, "test") assert result is False @@ -378,7 +368,7 @@ def test_get_power_on_delay_custom(self, policy_reader): assert policy_reader.get_power_on_delay() == 60 def test_get_graceful_shutdown_timeout_default(self, policy_reader): - """When no CHASSIS_MODULE|SWITCH-HOST entry exists, graceful_shutdown_timeout defaults to 120.""" + """When no CHASSIS_MODULE|SWITCH-HOST entry exists, graceful_shutdown_timeout defaults to 0.""" with patch.object(bmcctld.swsscommon, 'Table', return_value=Table(None, "T")): assert policy_reader.get_graceful_shutdown_timeout() == bmcctld.DEFAULT_SHUTDOWN_DELAY_SECS @@ -668,6 +658,27 @@ def test_admin_up_blocked_by_critical_leak(self, event_handler, controller): ) assert event_handler.action_queue.empty() + def test_empty_admin_status_does_not_poison_dedup(self, event_handler, controller): + """Regression: an empty admin_status must NOT update the dedup map, + so a subsequent real admin_status (e.g. 'up') is not silently dropped.""" + _set_table_entry(controller.host_state_table, bmcctld.HOST_STATE_KEY, + {bmcctld.FIELD_DEVICE_STATUS: bmcctld.SWITCH_HOST_OFFLINE}) + event_handler.critical_event_checker.has_any_critical_event = MagicMock(return_value=False) + + event_handler._handle_chassis_module( + bmcctld.SWITCH_HOST_MODULE_KEY, + {bmcctld.FIELD_ADMIN_STATUS: ""}, + ) + assert event_handler.action_queue.empty() + assert bmcctld.SWITCH_HOST_MODULE_KEY not in event_handler._last_chassis_module_admin_status + + event_handler._handle_chassis_module( + bmcctld.SWITCH_HOST_MODULE_KEY, + {bmcctld.FIELD_ADMIN_STATUS: bmcctld.ADMIN_UP}, + ) + item = event_handler.action_queue.get_nowait() + assert item.action == bmcctld.ACTION_POWER_ON + # -------------------------------------------------------------------------- # Tests: BmcEventHandler - System leak events @@ -813,6 +824,34 @@ def test_rack_mgr_leak_policy_disabled_skips_action(self, event_handler): ) assert event_handler.action_queue.empty() + def test_rack_mgr_leak_policy_disabled_does_not_poison_dedup(self, event_handler): + """Regression: a CRITICAL arriving while policy=disabled must NOT be + recorded in the dedup map, so the same severity dispatches normally + once the policy is re-enabled.""" + # Phase 1: policy=disabled, CRITICAL arrives -> no action, no dedup mutation + event_handler.policy_reader.get_leak_control_policy = MagicMock( + return_value=self._make_policy(rack_mgr_leak_policy="disabled") + ) + event_handler._handle_rack_mgr_alert( + "Inlet_liquid_pressure", + {bmcctld.FIELD_SEVERITY: bmcctld.ALERT_SEVERITY_CRITICAL}, + ) + assert event_handler.action_queue.empty() + assert "Inlet_liquid_pressure" not in event_handler._last_rack_mgr_alert_severity + + # Phase 2: policy re-enabled, SAME CRITICAL re-arrives -> action MUST dispatch + event_handler.policy_reader.get_leak_control_policy = MagicMock( + return_value=self._make_policy(rack_mgr_critical_alert_action=bmcctld.ACTION_POWER_OFF) + ) + event_handler._handle_rack_mgr_alert( + "Inlet_liquid_pressure", + {bmcctld.FIELD_SEVERITY: bmcctld.ALERT_SEVERITY_CRITICAL}, + ) + item = event_handler.action_queue.get_nowait() + assert item.action == bmcctld.ACTION_POWER_OFF + assert event_handler._last_rack_mgr_alert_severity["Inlet_liquid_pressure"] == \ + bmcctld.ALERT_SEVERITY_CRITICAL + def test_rack_level_leak_uses_leak_field(self, event_handler): event_handler.policy_reader.get_leak_control_policy = MagicMock( return_value=self._make_policy(rack_mgr_critical_alert_action=bmcctld.ACTION_POWER_OFF) @@ -1066,10 +1105,10 @@ def test_refreshes_state_when_already_online(self, chassis): daemon = self._make_daemon(chassis) daemon.critical_event_checker.has_any_critical_event = MagicMock(return_value=False) daemon.controller.power_on = MagicMock() - daemon.controller.refresh_host_state = MagicMock() + daemon.controller.init_host_state = MagicMock() daemon._initial_power_on_sequence() daemon.controller.power_on.assert_not_called() - daemon.controller.refresh_host_state.assert_called_once() + daemon.controller.init_host_state.assert_called_once() def test_stop_event_during_boot_delay_skips_sequence(self, chassis): daemon = self._make_daemon(chassis) @@ -1178,6 +1217,45 @@ def test_rack_mgr_power_cmd_executed_empty_table(self, chassis): with patch('bmcctld.swsscommon.Table', return_value=tbl): assert daemon._rack_mgr_power_cmd_executed() is False + def test_cold_boot_applies_power_on_delay(self, chassis): + """On a FULL POWER LOSS (cold boot), SWITCH_HOST_POWER_ON_DELAY must be applied.""" + chassis.set_reboot_cause(bmcctld.ChassisBase.REBOOT_CAUSE_POWER_LOSS) + chassis.switch_host.set_oper_status(MockModule.MODULE_STATUS_OFFLINE) + daemon = self._make_daemon(chassis) + daemon.policy_reader.get_power_on_delay = MagicMock(return_value=5) + daemon.critical_event_checker.has_any_critical_event = MagicMock(return_value=False) + daemon.controller.power_on = MagicMock(return_value=True) + # Bound the sequence by setting stop_event after one queue.get cycle + daemon.stop_event.set() + daemon._initial_power_on_sequence() + daemon.policy_reader.get_power_on_delay.assert_called_once() + + def test_warm_boot_skips_power_on_delay(self, chassis): + """On warm/fast/soft reboot (non-POWER_LOSS), the boot delay must be skipped.""" + chassis.set_reboot_cause(chassis.REBOOT_CAUSE_NON_HARDWARE) + chassis.switch_host.set_oper_status(MockModule.MODULE_STATUS_OFFLINE) + daemon = self._make_daemon(chassis) + daemon.policy_reader.get_power_on_delay = MagicMock(return_value=60) + daemon.critical_event_checker.has_any_critical_event = MagicMock(return_value=False) + daemon.controller.power_on = MagicMock(return_value=True) + daemon._initial_power_on_sequence() + # Boot delay is skipped → get_power_on_delay must NOT be called + daemon.policy_reader.get_power_on_delay.assert_not_called() + # And we still proceeded to the power-on check + daemon.controller.power_on.assert_called_once() + + def test_reboot_cause_exception_falls_back_to_cold_boot(self, chassis): + """If chassis.get_reboot_cause() raises, fall back to cold-boot behavior (apply delay).""" + chassis.get_reboot_cause = MagicMock(side_effect=RuntimeError("platform API not available")) + chassis.switch_host.set_oper_status(MockModule.MODULE_STATUS_OFFLINE) + daemon = self._make_daemon(chassis) + daemon.policy_reader.get_power_on_delay = MagicMock(return_value=5) + daemon.critical_event_checker.has_any_critical_event = MagicMock(return_value=False) + daemon.controller.power_on = MagicMock(return_value=True) + daemon.stop_event.set() + daemon._initial_power_on_sequence() + daemon.policy_reader.get_power_on_delay.assert_called_once() + class TestBmcctldDaemonRun: @@ -1194,8 +1272,8 @@ def test_run_not_liquid_cooled_powers_on_immediately(self, chassis): daemon.controller.power_on = MagicMock(return_value=True) daemon._run_action_loop = MagicMock() daemon.event_handler.run_event_loop = MagicMock() - with patch('bmcctld.is_liquid_cooled', return_value=False): - result = daemon.run() + chassis.set_liquid_cooled(False) + result = daemon.run() assert result is False daemon.controller.power_on.assert_called_once() daemon._run_action_loop.assert_called_once() @@ -1208,8 +1286,8 @@ def test_run_not_liquid_cooled_skips_initial_sequence_but_starts_event_thread(se daemon._run_action_loop = MagicMock() daemon._initial_power_on_sequence = MagicMock() daemon.event_handler.run_event_loop = MagicMock() - with patch('bmcctld.is_liquid_cooled', return_value=False): - daemon.run() + chassis.set_liquid_cooled(False) + daemon.run() daemon._initial_power_on_sequence.assert_not_called() daemon.event_handler.run_event_loop.assert_called_once() @@ -1219,15 +1297,15 @@ def test_run_daemon_restart_skips_boot_sequence(self, chassis): daemon = self._make_daemon(chassis) daemon._initial_power_on_sequence = MagicMock() daemon.controller.power_on = MagicMock() - daemon.controller.refresh_host_state = MagicMock() + daemon.controller.init_host_state = MagicMock() daemon._run_action_loop = MagicMock() daemon.event_handler.run_event_loop = MagicMock() - with patch('bmcctld.is_liquid_cooled', return_value=True): - result = daemon.run() + chassis.set_liquid_cooled(True) + result = daemon.run() assert result is False daemon._initial_power_on_sequence.assert_not_called() daemon.controller.power_on.assert_not_called() - daemon.controller.refresh_host_state.assert_called_once() + daemon.controller.init_host_state.assert_called_once() daemon._run_action_loop.assert_called_once() def test_run_liquid_cooled_runs_full_sequence(self, chassis): @@ -1239,8 +1317,8 @@ def test_run_liquid_cooled_runs_full_sequence(self, chassis): daemon.event_handler.run_event_loop = MagicMock() # Set stop_event so _run_action_loop returns without looping daemon._initial_power_on_sequence.side_effect = lambda: daemon.stop_event.set() - with patch('bmcctld.is_liquid_cooled', return_value=True): - result = daemon.run() + chassis.set_liquid_cooled(True) + result = daemon.run() assert result is False daemon._initial_power_on_sequence.assert_called_once() @@ -1303,10 +1381,10 @@ def test_power_off_mirrors_oper_status_offline(self, chassis, controller): info = dict(result[1]) assert info[bmcctld.CHASSIS_MODULE_INFO_OPERSTATUS_FIELD] == bmcctld.SWITCH_HOST_OFFLINE - def test_refresh_host_state_mirrors_oper_status(self, chassis, controller): - """refresh_host_state also updates oper_status in CHASSIS_MODULE_TABLE.""" + def test_init_host_state_mirrors_oper_status(self, chassis, controller): + """init_host_state also updates oper_status in CHASSIS_MODULE_TABLE.""" chassis.switch_host.set_oper_status(MockModule.MODULE_STATUS_ONLINE) - controller.refresh_host_state() + controller.init_host_state() result = controller.chassis_module_info_table.get(bmcctld.SWITCH_HOST_MODULE_KEY) assert result[0] is True info = dict(result[1]) diff --git a/sonic-thermalctld/scripts/thermalctld b/sonic-thermalctld/scripts/thermalctld index 7227a5e..6298f2c 100644 --- a/sonic-thermalctld/scripts/thermalctld +++ b/sonic-thermalctld/scripts/thermalctld @@ -9,6 +9,7 @@ from enum import Enum, auto from math import inf import argparse import json +import logging import os import signal import sys @@ -36,6 +37,55 @@ PHYSICAL_ENTITY_INFO_TABLE = 'PHYSICAL_ENTITY_INFO' INVALID_SLOT_OR_DPU = -1 PLATFORM_JSON_FILE = "/usr/share/sonic/platform/platform.json" +# Critical-event log file teed in addition to syslog. +CRITICAL_EVENT_LOG_FILE = "/host/bmc/event.log" + +# This class could be moved to sonic-py-common, the log file name can be passed as input. +class EventLogger(logger.Logger): + """Logger that tees every log call to a local file in addition to syslog.""" + + def __init__(self, syslog_identifier, log_file=CRITICAL_EVENT_LOG_FILE): + super(EventLogger, self).__init__(syslog_identifier) + py_name = "{}.{}".format(syslog_identifier, + os.path.basename(log_file).replace(".", "_")) + self._file_logger = logging.getLogger(py_name) + if not self._file_logger.handlers and os.getenv("THERMALCTLD_UNIT_TESTING") != "1": + try: + handler = logging.FileHandler(log_file) + handler.setFormatter(logging.Formatter( + "%(asctime)s %(name)s[%(process)d] %(levelname)s: %(message)s", + datefmt="%Y-%m-%dT%H:%M:%S", + )) + self._file_logger.addHandler(handler) + self._file_logger.setLevel(logging.DEBUG) + except (OSError, IOError) as e: + self.log_error( + "EventLogger: failed to open log file {} ({}); events will go to syslog only".format( + log_file, repr(e))) + + def log_debug(self, msg, also_print_to_console=False): + super(EventLogger, self).log_debug(msg, also_print_to_console) + self._file_logger.debug(msg) + + def log_info(self, msg, also_print_to_console=False): + super(EventLogger, self).log_info(msg, also_print_to_console) + self._file_logger.info(msg) + + def log_notice(self, msg, also_print_to_console=False): + super(EventLogger, self).log_notice(msg, also_print_to_console) + self._file_logger.info("NOTICE: " + msg) + + def log_warning(self, msg, also_print_to_console=False): + super(EventLogger, self).log_warning(msg, also_print_to_console) + self._file_logger.warning(msg) + + def log_error(self, msg, also_print_to_console=False): + super(EventLogger, self).log_error(msg, also_print_to_console) + self._file_logger.error(msg) + +# STATE_DB database ID +STATE_DB_ID = 6 + ERR_UNKNOWN = 1 CHASSIS_GET_ERROR = 2 @@ -544,7 +594,9 @@ class LiquidCoolingUpdater(threading.Thread, logger.Logger): :param chassis: Object representing a platform chassis """ threading.Thread.__init__(self) - logger.Logger.__init__(self) + logger.Logger.__init__(self, SYSLOG_IDENTIFIER) + # EventLogger tees CRITICAL leak events to /host/bmc/event.log. + self.event_logger = EventLogger(SYSLOG_IDENTIFIER, log_file=CRITICAL_EVENT_LOG_FILE) self.name = "LiquidCoolingUpdater" self.exc = None self.task_stopping_event = threading.Event() @@ -552,8 +604,10 @@ class LiquidCoolingUpdater(threading.Thread, logger.Logger): self.liquid_cooling = self.chassis.get_liquid_cooling() self.leaking_sensors: Dict[str, datetime] = {} self.faulty_sensors: Dict[str, datetime] = {} + self.critical_sensors: set = set() self.interval = liquid_cooling_update_interval self.last_leak_status = None + self.last_sensor_fvs: Dict[str, tuple] = {} state_db = daemon_base.db_connect("STATE_DB") self.sensor_table = swsscommon.Table(state_db, LiquidCoolingUpdater.LIQUID_COOLING_INFO_TABLE_NAME) @@ -568,6 +622,16 @@ class LiquidCoolingUpdater(threading.Thread, logger.Logger): ]) self.profile_table.set(profile.get_type(), fvs) + # Seed SYSTEM_LEAK_STATUS|system only if absent, so a daemon restart + # during an active leak doesn't clobber the prior status with 'None' + # until the next refresh cycle. + existing = self.system_table.get('system') + if not (existing and existing[0]): + self.system_table.set('system', swsscommon.FieldValuePairs([ + ('device_leak_status', 'None'), + ('timestamp', datetime.now().strftime('%Y%m%d %H:%M:%S')), + ])) + def __del__(self): try: for attr in ('system_table', 'sensor_table', 'profile_table'): @@ -610,6 +674,7 @@ class LiquidCoolingUpdater(threading.Thread, logger.Logger): self.log_error('Liquid cooling leakage sensor {} reported leaking'.format(sensor_name)) # Upgrade minor leaks to critical if the time threshold has been exceeded. + escalated_to_critical = False if sensor_leak_severity == LeakSeverity.MINOR: leak_start_time = self.leaking_sensors[sensor_name] profile = sensor.get_leak_profile() @@ -618,6 +683,30 @@ class LiquidCoolingUpdater(threading.Thread, logger.Logger): max_minor = leak_start_time + timedelta(seconds=max_minor_secs) if max_minor <= now: sensor_leak_severity = LeakSeverity.CRITICAL + escalated_to_critical = True + + # If the platform downgrades a CRITICAL sensor (and our time-based + # escalation didn't immediately re-bump it), prune it from + # critical_sensors so a subsequent re-CRITICAL is logged once. + if (sensor_leak_severity != LeakSeverity.CRITICAL + and sensor_name in self.critical_sensors): + self.critical_sensors.discard(sensor_name) + new_severity = sensor_leak_severity.value if sensor_leak_severity is not None else 'None' + self.event_logger.log_notice( + 'Liquid cooling leakage sensor {} downgraded from CRITICAL to {}'.format( + sensor_name, new_severity)) + + # Log CRITICAL once per leak episode, regardless of how the sensor reached + # CRITICAL severity: reported directly by the platform, or escalated by us + # from MINOR after the max-minor duration was exceeded. + if sensor_leak_severity == LeakSeverity.CRITICAL and sensor_name not in self.critical_sensors: + if escalated_to_critical: + msg = 'Leak on sensor {} escalated from MINOR to CRITICAL after {}s'.format( + sensor_name, max_minor_secs) + else: + msg = 'CRITICAL leak reported by sensor {}'.format(sensor_name) + self.event_logger.log_error(msg) + self.critical_sensors.add(sensor_name) if status is not None: # Multiple leaks (any severity) are critical. @@ -628,28 +717,52 @@ class LiquidCoolingUpdater(threading.Thread, logger.Logger): else: if sensor_name in self.leaking_sensors: del self.leaking_sensors[sensor_name] - self.log_notice('Liquid cooling leakage sensor {} recovered from leaking'.format(sensor_name)) - - # Per-sensor status. + if sensor_name in self.critical_sensors: + self.critical_sensors.discard(sensor_name) + self.event_logger.log_notice( + 'Liquid cooling leakage sensor {} recovered from CRITICAL leak'.format(sensor_name)) + else: + self.log_notice('Liquid cooling leakage sensor {} recovered from leaking'.format(sensor_name)) + + # Per-sensor status. Only write on change to avoid Redis churn. leaking = 'N/A' if not sensor_is_ok else 'Yes' if sensor_is_leak else 'No' - fvs = swsscommon.FieldValuePairs([ + sensor_type = try_get(sensor.get_leak_sensor_type, 'unknown') + sensor_location = try_get(sensor.get_leak_sensor_location, 'unknown') + fvs_tuple = ( ('name', sensor_name), ('leaking', leaking), + # Add leak_status field for backward compatibility in system-health hardware_checker + # and legacy leakageshow CLI which still read 'leak_status'. + ('leak_status', leaking), ('leak_sensor_status', 'Good' if sensor_is_ok else 'Fault'), - ('type', str(sensor.get_leak_sensor_type())), - ('location', str(sensor.get_leak_sensor_location())), - ('severity', str(sensor_leak_severity)), + ('type', str(sensor_type)), + ('location', str(sensor_location)), + ('leak_severity', str(sensor_leak_severity)), + ) + if self.last_sensor_fvs.get(sensor_name) != fvs_tuple: + self.sensor_table.set(sensor_name, swsscommon.FieldValuePairs(list(fvs_tuple))) + self.last_sensor_fvs[sensor_name] = fvs_tuple + + if status == LeakSeverity.CRITICAL and self.last_leak_status != LeakSeverity.CRITICAL: + leaking_names = ', '.join(sorted(self.leaking_sensors.keys())) or 'unknown' + self.event_logger.log_error( + 'CRITICAL system leak detected (sensors: {})'.format(leaking_names)) + elif self.last_leak_status == LeakSeverity.CRITICAL and status != LeakSeverity.CRITICAL: + self.event_logger.log_notice( + 'CRITICAL system leak cleared (current status: {})'.format( + status.value if status is not None else 'None')) + + # Only write SYSTEM_LEAK_STATUS on actual transitions to avoid + # subscriber spam from per-cycle timestamp updates. + if status != self.last_leak_status: + status_str = status.value if status is not None else 'None' + fvs = swsscommon.FieldValuePairs([ + ('device_leak_status', status_str), + ('timestamp', datetime.now().strftime('%Y%m%d %H:%M:%S')), ]) - self.sensor_table.set(sensor_name, fvs) + self.system_table.set('system', fvs) - # Overall system status. self.last_leak_status = status - status_str = status.value if status is not None else 'None' - fvs = swsscommon.FieldValuePairs([ - ('device_leak_status', status_str), - ('timestamp', datetime.now().strftime('%Y%m%d %H:%M:%S')), - ]) - self.system_table.set('system', fvs) def update(self): self._refresh_leak_status() @@ -772,7 +885,11 @@ class TemperatureStatus(logger.Logger): # TemperatureUpdater ====================================================================== # class TemperatureUpdater(logger.Logger): - # Temperature information table name in database + # Temperature information table name in database. + # The BMC and Switch-Host both populate this same table in the BMC's + # STATE_DB; sensor names never collide across the two, giving a unified + # chassis-wide view ("show platform temperature" on the BMC shows all + # thermals). TEMPER_INFO_TABLE_NAME = 'TEMPERATURE_INFO' def __init__(self, chassis, task_stopping_event, psu_interval=None, thermal_intervals=None, @@ -819,6 +936,64 @@ class TemperatureUpdater(logger.Logger): except Exception as e: self.chassis_table = None + self.bmc_temperature_table = None + self._bmc_addr = None + # Suppress repeated reconnect warnings when the host<->BMC link is down. + self._bmc_link_failed = False + if device_info.is_switch_host(): + self._init_bmc_temperature_table() + + def _init_bmc_temperature_table(self): + """Open a swsscommon.Table backed by the BMC's STATE_DB.""" + try: + bmc_addr = device_info.get_bmc_address() + if not bmc_addr: + return + self._bmc_addr = bmc_addr + remote_state_db = daemon_base.db_connect_remote(STATE_DB_ID, bmc_addr) + self.bmc_temperature_table = swsscommon.Table( + remote_state_db, TemperatureUpdater.TEMPER_INFO_TABLE_NAME) + self._bmc_link_failed = False + self.log_info( + 'Mirroring TEMPERATURE_INFO to BMC STATE_DB at {} (table {})'.format( + bmc_addr, TemperatureUpdater.TEMPER_INFO_TABLE_NAME)) + except Exception as e: + self.bmc_temperature_table = None + if not self._bmc_link_failed: + self.log_warning( + 'Failed to open remote BMC TEMPERATURE_INFO table: {}'.format(repr(e))) + self._bmc_link_failed = True + + def _bmc_table_set(self, name, fvs): + """Tee a TEMPERATURE_INFO row to the BMC. Reconnect once on failure.""" + if self._bmc_addr is None: + return + # Try once, then on failure clear the handle, reconnect, and retry + # once more. Recovers transparently from a dropped host<->BMC link + # or a BMC redis restart without dropping this update. + for attempt in range(2): + if self.bmc_temperature_table is None: + self._init_bmc_temperature_table() + if self.bmc_temperature_table is None: + return + try: + self.bmc_temperature_table.set(name, fvs) + return + except Exception as e: + self.bmc_temperature_table = None + if attempt == 1: + self.log_warning( + 'Failed to push TEMPERATURE_INFO/{} to BMC: {}'.format(name, repr(e))) + + def _bmc_table_del(self, name): + """Remove a TEMPERATURE_INFO row from the BMC mirror, best-effort.""" + if self.bmc_temperature_table is None: + return + try: + self.bmc_temperature_table._del(name) + except Exception: + self.bmc_temperature_table = None + def __del__(self): try: table = getattr(self, 'table', None) @@ -838,6 +1013,11 @@ class TemperatureUpdater(logger.Logger): # On a chassis system we may lose connection to the supervisor # and chassisdb; drop the handle. self.chassis_table = None + try: + if getattr(self, 'bmc_temperature_table', None) is not None: + self.bmc_temperature_table._del(tk) + except Exception: + self.bmc_temperature_table = None if phy_entity_table is not None: try: if phy_entity_table.get(tk) is not None: @@ -1026,6 +1206,7 @@ class TemperatureUpdater(logger.Logger): self.table.set(name, fvs) if self.is_chassis_upd_required and self.chassis_table is not None: self.chassis_table.set(name, fvs) + self._bmc_table_set(name, fvs) except Exception as e: self.log_warning('Failed to update thermal status for {} - {}'.format(name, repr(e))) @@ -1042,6 +1223,8 @@ class TemperatureUpdater(logger.Logger): except Exception: pass + self._bmc_table_del(name) + class ThermalMonitor(ThreadTaskBase): def __init__( @@ -1108,6 +1291,92 @@ class ThermalMonitor(ThreadTaskBase): fan_drawer_interval, psu_interval, {k: v for k, v in thermal_intervals.items()} if thermal_intervals else 'default')) + # On the BMC, monitor the Switch-Host-mirrored TEMPERATURE_INFO table + # and tee CRITICAL threshold breaches into /host/bmc/event.log via a + # dedicated logger. See pmon-bmc-design §2.4.1 (phase 1: syslog-only, + # no action). + self._switch_host_thermal_table = None + self._switch_host_thermal_state = {} + self._sw_host_thermal_event_logger = None + if device_info.is_switch_bmc(): + self._init_switch_host_thermal_monitor() + + def _init_switch_host_thermal_monitor(self): + """Open BMC's TEMPERATURE_INFO table for periodic CRITICAL checks.""" + try: + state_db = daemon_base.db_connect("STATE_DB") + self._switch_host_thermal_table = swsscommon.Table( + state_db, TemperatureUpdater.TEMPER_INFO_TABLE_NAME) + self._sw_host_thermal_event_logger = EventLogger( + SYSLOG_IDENTIFIER, log_file=CRITICAL_EVENT_LOG_FILE) + self.logger.log_info( + 'Monitoring chassis thermals (BMC STATE_DB {}) for CRITICAL breaches'.format( + TemperatureUpdater.TEMPER_INFO_TABLE_NAME)) + except Exception as e: + self._switch_host_thermal_table = None + self._sw_host_thermal_event_logger = None + self.logger.log_warning( + 'Failed to init chassis thermal monitor: {}'.format(repr(e))) + + @staticmethod + def _parse_float(value): + try: + return float(value) + except (TypeError, ValueError): + return None + + def _check_switch_host_thermals(self): + """Poll TEMPERATURE_INFO and log CRITICAL breaches on transition.""" + if self._switch_host_thermal_table is None: + return + try: + keys = self._switch_host_thermal_table.getKeys() or [] + except Exception as e: + self.logger.log_warning( + 'Failed to read TEMPERATURE_INFO keys: {}'.format(repr(e))) + return + + seen = set() + for key in keys: + seen.add(key) + try: + ok, fvs = self._switch_host_thermal_table.get(key) + except Exception: + continue + if not ok: + continue + fvs_dict = dict(fvs) if fvs else {} + + temp = self._parse_float(fvs_dict.get('temperature')) + crit_high = self._parse_float(fvs_dict.get('critical_high_threshold')) + crit_low = self._parse_float(fvs_dict.get('critical_low_threshold')) + if temp is None: + continue + + reasons = [] + if crit_high is not None and temp >= crit_high: + reasons.append('>= critical_high_threshold {}C'.format(crit_high)) + if crit_low is not None and temp <= crit_low: + reasons.append('<= critical_low_threshold {}C'.format(crit_low)) + breach = bool(reasons) + + was_critical = self._switch_host_thermal_state.get(key, False) + if breach and not was_critical: + # _sw_host_thermal_event_logger tees to BOTH syslog and /host/bmc/event.log. + if self._sw_host_thermal_event_logger is not None: + self._sw_host_thermal_event_logger.log_error( + 'CRITICAL chassis thermal: {} temperature {}C {}'.format( + key, temp, '; '.join(reasons))) + self._switch_host_thermal_state[key] = True + elif not breach and was_critical: + # Track recovery internally to avoid re-logging on next breach, + # but stay silent — only critical-threshold breaches are logged. + self._switch_host_thermal_state[key] = False + + # Drop state for sensors that have disappeared from the mirror. + for stale in set(self._switch_host_thermal_state) - seen: + del self._switch_host_thermal_state[stale] + def main(self): begin = time.time() @@ -1116,6 +1385,7 @@ class ThermalMonitor(ThreadTaskBase): self._last_fan_update = begin self.temperature_updater.update(now=begin) + self._check_switch_host_thermals() elapsed = time.time() - begin if elapsed < self.update_interval: self.wait_time = self.update_interval - elapsed @@ -1203,6 +1473,18 @@ class ThermalControlDaemon(daemon_base.DaemonBase): except Exception as e: self.log_error('Caught exception while initializing thermal manager - {}'.format(repr(e))) + # Enable liquid cooling if requested via pmon_daemon_control.json as before, or + # if the platform chassis reports itself as liquid cooled via the platform API. + if not enable_liquid_cooling: + try: + enable_liquid_cooling = bool(self.chassis.is_liquid_cooled()) + except (AttributeError, NotImplementedError): + enable_liquid_cooling = False + except Exception as e: + self.log_warning( + "Failed to query chassis.is_liquid_cooled(): {}".format(repr(e))) + enable_liquid_cooling = False + self.liquid_cooling_updater = LiquidCoolingUpdater(self.chassis, liquid_cooling_update_interval) if enable_liquid_cooling else None if self.liquid_cooling_updater is not None: diff --git a/sonic-thermalctld/tests/mocked_libs/swsscommon/swsscommon.py b/sonic-thermalctld/tests/mocked_libs/swsscommon/swsscommon.py index 26c72db..ddf1042 100644 --- a/sonic-thermalctld/tests/mocked_libs/swsscommon/swsscommon.py +++ b/sonic-thermalctld/tests/mocked_libs/swsscommon/swsscommon.py @@ -58,7 +58,12 @@ class FieldValuePairs: fv_dict = {} def __init__(self, tuple_list): - if isinstance(tuple_list, list) and isinstance(tuple_list[0], tuple): + if isinstance(tuple_list, list) and tuple_list and isinstance(tuple_list[0], tuple): + for i, kv in enumerate(tuple_list): + if (not isinstance(kv, tuple) or len(kv) != 2 + or not isinstance(kv[0], str) or not isinstance(kv[1], str)): + raise TypeError( + "FieldValuePairs item {} must be (str, str), got {!r}".format(i, kv)) self.fv_dict = dict(tuple_list) def __setitem__(self, key, kv_tuple): diff --git a/sonic-thermalctld/tests/test_thermalctld.py b/sonic-thermalctld/tests/test_thermalctld.py index 310e32c..61f28ba 100644 --- a/sonic-thermalctld/tests/test_thermalctld.py +++ b/sonic-thermalctld/tests/test_thermalctld.py @@ -452,6 +452,7 @@ def test_refresh_leak_status_with_leak(self, mock_try_get): liquid_cooling_updater.log_error = mock.MagicMock() liquid_cooling_updater.log_notice = mock.MagicMock() + liquid_cooling_updater.event_logger = mock.MagicMock() liquid_cooling_updater.sensor_table = mock.MagicMock() liquid_cooling_updater.system_table = mock.MagicMock() liquid_cooling_updater.leaking_sensors = {} @@ -462,20 +463,32 @@ def test_refresh_leak_status_with_leak(self, mock_try_get): assert liquid_cooling_updater.sensor_table.set.call_count == 2 assert liquid_cooling_updater.log_error.call_count == 1 + assert liquid_cooling_updater.event_logger.log_error.call_count == 2 assert len(liquid_cooling_updater.leaking_sensors) == 1 assert "leakage1" in liquid_cooling_updater.leaking_sensors assert len(liquid_cooling_updater.faulty_sensors) == 0 assert liquid_cooling_updater.last_leak_status == LeakSeverity.CRITICAL - liquid_cooling_updater.log_error.assert_called_with( + liquid_cooling_updater.log_error.assert_any_call( 'Liquid cooling leakage sensor leakage1 reported leaking' ) + liquid_cooling_updater.event_logger.log_error.assert_any_call( + 'CRITICAL leak reported by sensor leakage1' + ) + liquid_cooling_updater.event_logger.log_error.assert_any_call( + 'CRITICAL system leak detected (sensors: leakage1)' + ) calls = liquid_cooling_updater.sensor_table.set.call_args_list leak_statuses = {} for call in calls: sensor_name, fvp = call[0] leak_statuses[sensor_name] = fvp.fv_dict['leaking'] + # leak_status is a back-compat alias of leaking for system-health/legacy CLI + assert fvp.fv_dict['leak_status'] == fvp.fv_dict['leaking'] + # severity field was renamed to leak_severity (matches HLD and sonic-utilities) + assert 'leak_severity' in fvp.fv_dict + assert 'severity' not in fvp.fv_dict assert leak_statuses["leakage1"] == "Yes" assert leak_statuses["leakage2"] == "No" @@ -495,6 +508,7 @@ def test_refresh_status_with_multiple_leaks(self, mock_try_get): liquid_cooling_updater.log_error = mock.MagicMock() liquid_cooling_updater.log_notice = mock.MagicMock() + liquid_cooling_updater.event_logger = mock.MagicMock() liquid_cooling_updater.sensor_table = mock.MagicMock() liquid_cooling_updater.system_table = mock.MagicMock() liquid_cooling_updater.leaking_sensors = {} @@ -511,6 +525,7 @@ def test_refresh_status_with_multiple_leaks(self, mock_try_get): liquid_cooling_updater._refresh_leak_status() assert liquid_cooling_updater.log_error.call_count == 1 + assert liquid_cooling_updater.event_logger.log_error.call_count == 0 assert len(liquid_cooling_updater.leaking_sensors) == 1 assert "leakage1" in liquid_cooling_updater.leaking_sensors assert len(liquid_cooling_updater.faulty_sensors) == 0 @@ -521,7 +536,10 @@ def test_refresh_status_with_multiple_leaks(self, mock_try_get): liquid_cooling_updater._refresh_leak_status() + # Two self.log_error calls (one per sensor leak detection) plus one + # event_logger.log_error for the system CRITICAL transition. assert liquid_cooling_updater.log_error.call_count == 2 + assert liquid_cooling_updater.event_logger.log_error.call_count == 1 assert len(liquid_cooling_updater.leaking_sensors) == 2 assert "leakage1" in liquid_cooling_updater.leaking_sensors assert "leakage2" in liquid_cooling_updater.leaking_sensors @@ -583,6 +601,148 @@ def test_refresh_status_with_long_leak(self, mock_try_get): elif index == 1: assert fvp.fv_dict['device_leak_status'] == 'CRITICAL' + @mock.patch('thermalctld.try_get') + def test_refresh_leak_status_platform_severity_bump(self, mock_try_get): + """Platform reports MINOR then directly bumps to CRITICAL (no time escalation). + Verifies CRITICAL is logged once and sensor is added to critical_sensors, + even though new_leak=False and escalated_to_critical=False on the bump cycle.""" + mock_chassis = MockChassis() + mock_chassis.get_liquid_cooling().make_sensor_leak(0) + liquid_cooling_updater = thermalctld.LiquidCoolingUpdater(mock_chassis, 0.5) + + # Start the sensor as MINOR with a long max-minor duration so the time-based + # escalation cannot fire — only a platform-driven bump can reach CRITICAL. + sensor = mock_chassis.get_liquid_cooling().leakage_sensors[0] + sensor.get_leak_severity = mock.MagicMock(return_value=LeakSeverity.MINOR) + sensor.get_leak_profile().get_leak_max_minor_duration_sec = mock.MagicMock(return_value=86400) + + liquid_cooling_updater.log_error = mock.MagicMock() + liquid_cooling_updater.log_notice = mock.MagicMock() + liquid_cooling_updater.event_logger = mock.MagicMock() + liquid_cooling_updater.sensor_table = mock.MagicMock() + liquid_cooling_updater.system_table = mock.MagicMock() + liquid_cooling_updater.leaking_sensors = {} + liquid_cooling_updater.critical_sensors = set() + + mock_try_get.side_effect = lambda func, default: func() + + # Cycle 1: MINOR leak detected — no CRITICAL log expected + liquid_cooling_updater._refresh_leak_status() + assert "leakage1" in liquid_cooling_updater.leaking_sensors + assert "leakage1" not in liquid_cooling_updater.critical_sensors + for call in liquid_cooling_updater.event_logger.log_error.call_args_list: + assert 'CRITICAL leak reported' not in call[0][0] + + # Cycle 2: platform bumps severity directly to CRITICAL (no time escalation) + sensor.get_leak_severity = mock.MagicMock(return_value=LeakSeverity.CRITICAL) + liquid_cooling_updater.event_logger.reset_mock() + liquid_cooling_updater._refresh_leak_status() + + assert "leakage1" in liquid_cooling_updater.critical_sensors + liquid_cooling_updater.event_logger.log_error.assert_any_call( + 'CRITICAL leak reported by sensor leakage1' + ) + + # Cycle 3: still CRITICAL — must NOT re-log (critical_sensors guard) + liquid_cooling_updater.event_logger.reset_mock() + liquid_cooling_updater._refresh_leak_status() + for call in liquid_cooling_updater.event_logger.log_error.call_args_list: + assert 'CRITICAL leak reported' not in call[0][0] + assert 'escalated from MINOR to CRITICAL' not in call[0][0] + + @mock.patch('thermalctld.try_get') + def test_refresh_leak_status_platform_severity_downgrade(self, mock_try_get): + """Platform downgrades CRITICAL -> MINOR while still leaking. + Verifies the sensor is pruned from critical_sensors and a one-shot + 'downgraded from CRITICAL to MINOR' notice is emitted.""" + mock_chassis = MockChassis() + mock_chassis.get_liquid_cooling().make_sensor_leak(0) + liquid_cooling_updater = thermalctld.LiquidCoolingUpdater(mock_chassis, 0.5) + + sensor = mock_chassis.get_liquid_cooling().leakage_sensors[0] + sensor.get_leak_severity = mock.MagicMock(return_value=LeakSeverity.CRITICAL) + # Long max-minor duration so time-based escalation can't fire on the + # downgrade cycle (which would re-bump MINOR back to CRITICAL). + sensor.get_leak_profile().get_leak_max_minor_duration_sec = mock.MagicMock(return_value=86400) + + liquid_cooling_updater.log_error = mock.MagicMock() + liquid_cooling_updater.log_notice = mock.MagicMock() + liquid_cooling_updater.event_logger = mock.MagicMock() + liquid_cooling_updater.sensor_table = mock.MagicMock() + liquid_cooling_updater.system_table = mock.MagicMock() + liquid_cooling_updater.leaking_sensors = {} + liquid_cooling_updater.critical_sensors = set() + + mock_try_get.side_effect = lambda func, default: func() + + # Cycle 1: CRITICAL detected + liquid_cooling_updater._refresh_leak_status() + assert "leakage1" in liquid_cooling_updater.critical_sensors + + # Cycle 2: platform downgrades to MINOR (sensor still leaking) + sensor.get_leak_severity = mock.MagicMock(return_value=LeakSeverity.MINOR) + liquid_cooling_updater.event_logger.reset_mock() + liquid_cooling_updater._refresh_leak_status() + + assert "leakage1" not in liquid_cooling_updater.critical_sensors + assert "leakage1" in liquid_cooling_updater.leaking_sensors + liquid_cooling_updater.event_logger.log_notice.assert_any_call( + 'Liquid cooling leakage sensor leakage1 downgraded from CRITICAL to MINOR' + ) + + # Cycle 3: still MINOR — must NOT re-log the downgrade + liquid_cooling_updater.event_logger.reset_mock() + liquid_cooling_updater._refresh_leak_status() + for call in liquid_cooling_updater.event_logger.log_notice.call_args_list: + assert 'downgraded from CRITICAL' not in call[0][0] + + @mock.patch('thermalctld.try_get') + def test_refresh_leak_status_critical_minor_critical_flap(self, mock_try_get): + """CRITICAL -> MINOR -> CRITICAL flap. Verifies the post-downgrade + re-CRITICAL emits the CRITICAL log again exactly once.""" + mock_chassis = MockChassis() + mock_chassis.get_liquid_cooling().make_sensor_leak(0) + liquid_cooling_updater = thermalctld.LiquidCoolingUpdater(mock_chassis, 0.5) + + sensor = mock_chassis.get_liquid_cooling().leakage_sensors[0] + sensor.get_leak_severity = mock.MagicMock(return_value=LeakSeverity.CRITICAL) + sensor.get_leak_profile().get_leak_max_minor_duration_sec = mock.MagicMock(return_value=86400) + + liquid_cooling_updater.log_error = mock.MagicMock() + liquid_cooling_updater.log_notice = mock.MagicMock() + liquid_cooling_updater.event_logger = mock.MagicMock() + liquid_cooling_updater.sensor_table = mock.MagicMock() + liquid_cooling_updater.system_table = mock.MagicMock() + liquid_cooling_updater.leaking_sensors = {} + liquid_cooling_updater.critical_sensors = set() + + mock_try_get.side_effect = lambda func, default: func() + + # Cycle 1: CRITICAL + liquid_cooling_updater._refresh_leak_status() + assert "leakage1" in liquid_cooling_updater.critical_sensors + + # Cycle 2: downgrade to MINOR + sensor.get_leak_severity = mock.MagicMock(return_value=LeakSeverity.MINOR) + liquid_cooling_updater._refresh_leak_status() + assert "leakage1" not in liquid_cooling_updater.critical_sensors + + # Cycle 3: re-bump to CRITICAL — must log CRITICAL again + sensor.get_leak_severity = mock.MagicMock(return_value=LeakSeverity.CRITICAL) + liquid_cooling_updater.event_logger.reset_mock() + liquid_cooling_updater._refresh_leak_status() + + assert "leakage1" in liquid_cooling_updater.critical_sensors + liquid_cooling_updater.event_logger.log_error.assert_any_call( + 'CRITICAL leak reported by sensor leakage1' + ) + + # Cycle 4: still CRITICAL — must NOT re-log + liquid_cooling_updater.event_logger.reset_mock() + liquid_cooling_updater._refresh_leak_status() + for call in liquid_cooling_updater.event_logger.log_error.call_args_list: + assert 'CRITICAL leak reported' not in call[0][0] + @mock.patch('thermalctld.try_get') def test_refresh_leak_status_leak_recovery(self, mock_try_get): """Test _refresh_leak_status when a sensor recovers from leak""" @@ -1783,3 +1943,307 @@ def test_collect_thermals_no_refresh_when_false(self): updater._refresh_temperature_status.assert_not_called() # Entity info should still be updated even without temperature refresh updater.phy_entity_table.set.assert_called() + + +class TestTemperatureUpdaterBmcMirror(object): + """ + Tests for pushing TEMPERATURE_INFO from Switch-Host to BMC's STATE_DB + via daemon_base.db_connect_remote (pmon-bmc-design §2.4.1). + """ + + @mock.patch.object(thermalctld.device_info, 'is_switch_host', return_value=False) + @mock.patch.object(thermalctld.device_info, 'get_bmc_address', return_value='10.0.0.1') + @mock.patch.object(thermalctld.daemon_base, 'db_connect_remote') + def test_init_skipped_when_not_switch_host(self, mock_remote, mock_addr, mock_is_sh): + chassis = MockChassis() + updater = thermalctld.TemperatureUpdater(chassis, threading.Event()) + assert updater.bmc_temperature_table is None + mock_remote.assert_not_called() + + @mock.patch.object(thermalctld.device_info, 'is_switch_host', return_value=True) + @mock.patch.object(thermalctld.device_info, 'get_bmc_address', return_value=None) + @mock.patch.object(thermalctld.daemon_base, 'db_connect_remote') + def test_init_skipped_when_no_bmc_address(self, mock_remote, mock_addr, mock_is_sh): + chassis = MockChassis() + updater = thermalctld.TemperatureUpdater(chassis, threading.Event()) + assert updater.bmc_temperature_table is None + mock_remote.assert_not_called() + + @mock.patch.object(thermalctld.device_info, 'is_switch_host', return_value=True) + @mock.patch.object(thermalctld.device_info, 'get_bmc_address', return_value='10.0.0.1') + @mock.patch.object(thermalctld.daemon_base, 'db_connect_remote') + @mock.patch.object(thermalctld.swsscommon, 'Table') + def test_init_opens_remote_bmc_table(self, mock_table_cls, mock_remote, mock_addr, mock_is_sh): + mock_remote.return_value = mock.MagicMock(name='remote_conn') + chassis = MockChassis() + updater = thermalctld.TemperatureUpdater(chassis, threading.Event()) + mock_remote.assert_called_once_with(thermalctld.STATE_DB_ID, '10.0.0.1') + # The Table constructor is invoked for local STATE_DB, phy_entity, and BMC mirror. + # Verify at least one call used the remote connection + TEMPERATURE_INFO name. + calls = [c for c in mock_table_cls.call_args_list + if c.args and c.args[0] is mock_remote.return_value] + assert len(calls) == 1 + assert calls[0].args[1] == thermalctld.TemperatureUpdater.TEMPER_INFO_TABLE_NAME + assert updater.bmc_temperature_table is not None + assert updater._bmc_addr == '10.0.0.1' + + @mock.patch.object(thermalctld.device_info, 'is_switch_host', return_value=True) + @mock.patch.object(thermalctld.device_info, 'get_bmc_address', return_value='10.0.0.1') + @mock.patch.object(thermalctld.daemon_base, 'db_connect_remote', + side_effect=Exception('boom')) + def test_init_handles_remote_connect_failure(self, mock_remote, mock_addr, mock_is_sh): + chassis = MockChassis() + updater = thermalctld.TemperatureUpdater(chassis, threading.Event()) + assert updater.bmc_temperature_table is None + # _bmc_addr is set so a later lazy reconnect can be attempted. + assert updater._bmc_addr == '10.0.0.1' + + def _make_switch_host_updater(self): + with mock.patch.object(thermalctld.device_info, 'is_switch_host', return_value=True), \ + mock.patch.object(thermalctld.device_info, 'get_bmc_address', return_value='10.0.0.1'), \ + mock.patch.object(thermalctld.daemon_base, 'db_connect_remote', + return_value=mock.MagicMock()): + updater = thermalctld.TemperatureUpdater(MockChassis(), threading.Event()) + updater.bmc_temperature_table = mock.MagicMock() + updater._bmc_addr = '10.0.0.1' + return updater + + def test_bmc_table_set_noop_when_not_switch_host(self): + chassis = MockChassis() + updater = thermalctld.TemperatureUpdater(chassis, threading.Event()) + # Not switch-host: _bmc_addr is None, set is a no-op. + assert updater._bmc_addr is None + updater._bmc_table_set('Thermal 1', mock.MagicMock()) # must not raise + + def test_bmc_table_set_forwards_to_remote_table(self): + updater = self._make_switch_host_updater() + fvs = mock.MagicMock(name='fvs') + updater._bmc_table_set('Thermal 1', fvs) + updater.bmc_temperature_table.set.assert_called_once_with('Thermal 1', fvs) + + def test_bmc_table_set_reconnects_once_on_failure(self): + updater = self._make_switch_host_updater() + # First attempt raises, second attempt (after reconnect) succeeds. + first_table = updater.bmc_temperature_table + first_table.set.side_effect = Exception('disconnect') + reconnected = mock.MagicMock() + with mock.patch.object(thermalctld.device_info, 'is_switch_host', return_value=True), \ + mock.patch.object(thermalctld.device_info, 'get_bmc_address', return_value='10.0.0.1'), \ + mock.patch.object(thermalctld.daemon_base, 'db_connect_remote', + return_value=mock.MagicMock()), \ + mock.patch.object(thermalctld.swsscommon, 'Table', + return_value=reconnected): + updater._bmc_table_set('Thermal 1', 'fvs') + # First table cleared, reconnect set the new one, second set call succeeded. + reconnected.set.assert_called_once_with('Thermal 1', 'fvs') + + def test_bmc_table_del_clears_handle_on_error(self): + updater = self._make_switch_host_updater() + updater.bmc_temperature_table._del = mock.MagicMock(side_effect=Exception('x')) + updater._bmc_table_del('Thermal 1') + assert updater.bmc_temperature_table is None + + @mock.patch('thermalctld.try_get') + def test_refresh_temperature_tees_to_bmc(self, mock_try_get): + mock_try_get.side_effect = lambda func, default=thermalctld.NOT_AVAILABLE: func() + updater = self._make_switch_host_updater() + updater.table = mock.MagicMock() + updater.is_chassis_upd_required = False + thermal = MockThermal() + updater._refresh_temperature_status('Chassis 1', thermal, 0) + # Local + BMC mirror both received the same row. + assert updater.table.set.called + assert updater.bmc_temperature_table.set.called + local_name, local_fvs = updater.table.set.call_args[0] + bmc_name, bmc_fvs = updater.bmc_temperature_table.set.call_args[0] + assert local_name == bmc_name + assert local_fvs is bmc_fvs + + +class TestThermalMonitorSwitchHostCritical(object): + """ + Tests for the BMC-side monitor in ThermalMonitor that watches the + TEMPERATURE_INFO table (populated by both the BMC and Switch-Host) and + logs CRITICAL breaches into /host/bmc/event.log. + """ + + def _make_monitor(self): + """Build a ThermalMonitor with init side-effects bypassed.""" + with mock.patch.object(thermalctld, 'FanUpdater'), \ + mock.patch.object(thermalctld, 'TemperatureUpdater'), \ + mock.patch.object(thermalctld.device_info, 'is_switch_bmc', return_value=False): + # is_switch_bmc=False keeps the monitor disabled during construction; + # tests will inject mocks directly afterwards. + tm = thermalctld.ThermalMonitor(MockChassis(), 5, 60, 30) + return tm + + def test_init_skipped_on_switch_host(self): + with mock.patch.object(thermalctld, 'FanUpdater'), \ + mock.patch.object(thermalctld, 'TemperatureUpdater'), \ + mock.patch.object(thermalctld.device_info, 'is_switch_bmc', return_value=False): + tm = thermalctld.ThermalMonitor(MockChassis(), 5, 60, 30) + assert tm._switch_host_thermal_table is None + + def test_init_skipped_when_no_bmc(self): + with mock.patch.object(thermalctld, 'FanUpdater'), \ + mock.patch.object(thermalctld, 'TemperatureUpdater'), \ + mock.patch.object(thermalctld.device_info, 'is_switch_bmc', return_value=False): + tm = thermalctld.ThermalMonitor(MockChassis(), 5, 60, 30) + assert tm._switch_host_thermal_table is None + + def test_init_enabled_on_bmc(self): + with mock.patch.object(thermalctld, 'FanUpdater'), \ + mock.patch.object(thermalctld.device_info, 'is_switch_bmc', return_value=True), \ + mock.patch.object(thermalctld.swsscommon, 'Table') as mock_table_cls: + tm = thermalctld.ThermalMonitor(MockChassis(), 5, 60, 30) + mirror_calls = [c for c in mock_table_cls.call_args_list + if c.args and c.args[1] == 'TEMPERATURE_INFO'] + assert len(mirror_calls) >= 1 + assert tm._switch_host_thermal_table is not None + assert tm._sw_host_thermal_event_logger is not None + + def test_check_logs_critical_on_high_threshold_breach(self): + tm = self._make_monitor() + tm._switch_host_thermal_table = mock.MagicMock() + tm._sw_host_thermal_event_logger = mock.MagicMock() + tm._switch_host_thermal_table.getKeys.return_value = ['Thermal 1'] + tm._switch_host_thermal_table.get.return_value = (True, [ + ('temperature', '105.0'), + ('critical_high_threshold', '100.0'), + ('critical_low_threshold', '-15.0'), + ('high_threshold', '90.0'), + ]) + tm._check_switch_host_thermals() + tm._sw_host_thermal_event_logger.log_error.assert_called_once() + msg = tm._sw_host_thermal_event_logger.log_error.call_args.args[0] + assert 'CRITICAL chassis thermal: Thermal 1' in msg + assert '105.0' in msg + assert 'critical_high_threshold 100.0' in msg + assert tm._switch_host_thermal_state['Thermal 1'] is True + + def test_check_logs_critical_on_low_threshold_breach(self): + tm = self._make_monitor() + tm._switch_host_thermal_table = mock.MagicMock() + tm._sw_host_thermal_event_logger = mock.MagicMock() + tm._switch_host_thermal_table.getKeys.return_value = ['Thermal 2'] + tm._switch_host_thermal_table.get.return_value = (True, [ + ('temperature', '-20.0'), + ('critical_high_threshold', '100.0'), + ('critical_low_threshold', '-15.0'), + ]) + tm._check_switch_host_thermals() + tm._sw_host_thermal_event_logger.log_error.assert_called_once() + assert 'critical_low_threshold -15.0' in \ + tm._sw_host_thermal_event_logger.log_error.call_args.args[0] + + def test_check_does_not_log_within_thresholds(self): + tm = self._make_monitor() + tm._switch_host_thermal_table = mock.MagicMock() + tm._sw_host_thermal_event_logger = mock.MagicMock() + tm._switch_host_thermal_table.getKeys.return_value = ['Thermal 1'] + tm._switch_host_thermal_table.get.return_value = (True, [ + ('temperature', '50.0'), + ('critical_high_threshold', '100.0'), + ('critical_low_threshold', '-15.0'), + ]) + tm._check_switch_host_thermals() + tm._sw_host_thermal_event_logger.log_error.assert_not_called() + assert tm._switch_host_thermal_state.get('Thermal 1', False) is False + + def test_check_only_logs_on_transition(self): + tm = self._make_monitor() + tm._switch_host_thermal_table = mock.MagicMock() + tm._sw_host_thermal_event_logger = mock.MagicMock() + tm._switch_host_thermal_table.getKeys.return_value = ['Thermal 1'] + tm._switch_host_thermal_table.get.return_value = (True, [ + ('temperature', '105.0'), + ('critical_high_threshold', '100.0'), + ]) + # First call enters critical → 1 log_error. + tm._check_switch_host_thermals() + # Second call still critical → no additional log. + tm._check_switch_host_thermals() + assert tm._sw_host_thermal_event_logger.log_error.call_count == 1 + + def test_check_logs_recovery_on_clear(self): + tm = self._make_monitor() + tm._switch_host_thermal_table = mock.MagicMock() + tm._sw_host_thermal_event_logger = mock.MagicMock() + tm._switch_host_thermal_state = {'Thermal 1': True} # was critical + tm._switch_host_thermal_table.getKeys.return_value = ['Thermal 1'] + tm._switch_host_thermal_table.get.return_value = (True, [ + ('temperature', '50.0'), + ('critical_high_threshold', '100.0'), + ]) + tm._check_switch_host_thermals() + # Recovery is silent — only critical-breach transitions are logged. + tm._sw_host_thermal_event_logger.log_notice.assert_not_called() + tm._sw_host_thermal_event_logger.log_error.assert_not_called() + assert tm._switch_host_thermal_state['Thermal 1'] is False + + def test_check_handles_missing_temperature(self): + tm = self._make_monitor() + tm._switch_host_thermal_table = mock.MagicMock() + tm._sw_host_thermal_event_logger = mock.MagicMock() + tm._switch_host_thermal_table.getKeys.return_value = ['Thermal 1'] + tm._switch_host_thermal_table.get.return_value = (True, [ + ('temperature', 'N/A'), + ('critical_high_threshold', '100.0'), + ]) + tm._check_switch_host_thermals() + tm._sw_host_thermal_event_logger.log_error.assert_not_called() + + def test_check_noop_when_disabled(self): + tm = self._make_monitor() + assert tm._switch_host_thermal_table is None + # Must not raise. + tm._check_switch_host_thermals() + + def test_check_drops_state_for_disappeared_sensors(self): + tm = self._make_monitor() + tm._switch_host_thermal_table = mock.MagicMock() + tm._sw_host_thermal_event_logger = mock.MagicMock() + tm._switch_host_thermal_state = {'Thermal 1': True, 'Old': True} + tm._switch_host_thermal_table.getKeys.return_value = ['Thermal 1'] + tm._switch_host_thermal_table.get.return_value = (True, [ + ('temperature', '50.0'), + ('critical_high_threshold', '100.0'), + ]) + tm._check_switch_host_thermals() + assert 'Old' not in tm._switch_host_thermal_state + + def test_critical_breach_logs_to_both_syslog_and_event_log(self): + """A single breach log call must tee to both syslog and event.log.""" + import tempfile + + tm = self._make_monitor() + tm._switch_host_thermal_table = mock.MagicMock() + with tempfile.NamedTemporaryFile(suffix='.log', delete=False) as f: + tmp_log = f.name + try: + # Clear the THERMALCTLD_UNIT_TESTING gate so the file handler is + # actually attached for this test, then restore on exit. + prev = os.environ.pop('THERMALCTLD_UNIT_TESTING', None) + try: + tm._sw_host_thermal_event_logger = thermalctld.EventLogger( + 'thermalctld-test', log_file=tmp_log) + finally: + if prev is not None: + os.environ['THERMALCTLD_UNIT_TESTING'] = prev + tm._sw_host_thermal_event_logger.set_min_log_priority_info() + tm._sw_host_thermal_event_logger._syslog = mock.MagicMock() + + tm._switch_host_thermal_table.getKeys.return_value = ['Thermal X'] + tm._switch_host_thermal_table.get.return_value = (True, [ + ('temperature', '110.0'), + ('critical_high_threshold', '100.0'), + ]) + tm._check_switch_host_thermals() + + assert tm._sw_host_thermal_event_logger._syslog.syslog.called + with open(tmp_log) as fh: + contents = fh.read() + assert 'CRITICAL chassis thermal: Thermal X' in contents + assert '110.0' in contents + finally: + os.unlink(tmp_log)