From 8a42221957fe63c353602d883cbdbb8947090291 Mon Sep 17 00:00:00 2001 From: Chad Smith Date: Fri, 23 Jan 2026 17:19:11 +0000 Subject: [PATCH 01/31] feat: add OSWAP security event logging for user creation and system restart Implement OWASP structured logs in /var/log/cloud-init-security.log. Add security-related operations performed by cloud-init on behalf of user-data or platform meta-data: - user creation - user password change - system restart - system shutdown Default security log file can be changed by setting an alternative value for security_log_file in /etc/cloud/cloud.cfg(.d/*.cfg). --- cloudinit/distros/__init__.py | 32 ++ cloudinit/log/security_event_log.py | 276 ++++++++++++++ cloudinit/settings.py | 3 + cloudinit/util.py | 32 +- tests/unittests/distros/test_create_users.py | 21 ++ .../distros/test_user_data_normalize.py | 16 +- tests/unittests/log/__init__.py | 1 + .../unittests/log/test_security_event_log.py | 348 ++++++++++++++++++ tests/unittests/test_util.py | 17 +- 9 files changed, 729 insertions(+), 17 deletions(-) create mode 100644 cloudinit/log/security_event_log.py create mode 100644 tests/unittests/log/__init__.py create mode 100644 tests/unittests/log/test_security_event_log.py diff --git a/cloudinit/distros/__init__.py b/cloudinit/distros/__init__.py index 9ed5540d7d7..eb4cc3c9bea 100644 --- a/cloudinit/distros/__init__.py +++ b/cloudinit/distros/__init__.py @@ -52,6 +52,11 @@ from cloudinit.distros.parsers import hosts from cloudinit.features import ALLOW_EC2_MIRRORS_ON_NON_AWS_INSTANCE_TYPES from cloudinit.lifecycle import log_with_downgradable_level +from cloudinit.log.security_event_log import ( + sec_log_password_changed, + sec_log_system_shutdown, + sec_log_user_created, +) from cloudinit.net import activators, dhcp, renderers from cloudinit.net.netops import NetOps from cloudinit.net.network_state import parse_net_config_data @@ -777,6 +782,19 @@ def add_user(self, name, **kwargs) -> bool: util.logexc(LOG, "Failed to create user %s", name) raise e + user_attributes = {} + for k, v in kwargs.items(): + if k == "groups": + user_attributes["groups"] = ",".join(groups) + elif k in ("sudo", "doas") and v: + user_attributes[k] = True + + sec_log_user_created( + userid="cloud-init", + new_userid=name, + attributes=user_attributes if user_attributes else None, + ) + # Indicate that a new user was created return True @@ -804,6 +822,11 @@ def add_snap_user(self, name, **kwargs): LOG.debug("snap create-user returned: %s:%s", out, err) jobj = util.load_json(out) username = jobj.get("username", None) + sec_log_user_created( + userid="cloud-init", + new_userid=name, + attributes={"snapuser": True, "sudo": True}, + ) except Exception as e: util.logexc(LOG, "Failed to create snap user %s", name) raise e @@ -1111,6 +1134,8 @@ def set_passwd(self, user, passwd, hashed=False): util.logexc(LOG, "Failed to set password for %s", user) raise e + # Log security event for password change + sec_log_password_changed(userid=user) return True def chpasswd(self, plist_in: list, hashed: bool): @@ -1126,6 +1151,10 @@ def chpasswd(self, plist_in: list, hashed: bool): cmd = ["chpasswd"] + (["-e"] if hashed else []) subp.subp(cmd, data=payload) + # Log security event for each password change + for name, _ in plist_in: + sec_log_password_changed(userid=name) + def is_doas_rule_valid(self, user, rule): rule_pattern = ( r"^(?:permit|deny)" @@ -1336,6 +1365,9 @@ def shutdown_command(cls, *, mode, delay, message): args = command + [delay] if message: args.append(message) + + sec_log_system_shutdown(mode=mode, delay=str(delay)) + return args @classmethod diff --git a/cloudinit/log/security_event_log.py b/cloudinit/log/security_event_log.py new file mode 100644 index 00000000000..b9adf5eb575 --- /dev/null +++ b/cloudinit/log/security_event_log.py @@ -0,0 +1,276 @@ +# This file is part of cloud-init. See LICENSE file for license information. + +""" +OWASP-formatted Security Event Logging for cloud-init. + +This module provides security event logging following the OWASP Logging +Vocabulary Cheat Sheet: +https://github.com/OWASP/CheatSheetSeries/blob/master/cheatsheets/Logging_Vocabulary_Cheat_Sheet.md + +Security events are logged in JSON Lines format with standardized fields: +- datetime: ISO 8601 timestamp with UTC offset +- appid: Application identifier (canonical.cloud_init) +- event: Event type with optional parameters (e.g., user_created:root,ubuntu) +- level: INFO, WARN, or CRITICAL +- description: Human-readable summary +""" + +import datetime +import json +import logging +import os +import socket +from enum import Enum +from typing import Any, Dict, List, Optional + +from cloudinit import util +from cloudinit.settings import DEFAULT_SECURITY_LOG + +LOG = logging.getLogger(__name__) + +# Hard-coded application identifier per spec +APP_ID = "canonical.cloud_init" + + +class OWASPEventLevel(Enum): + """Log levels per OWASP recommendations.""" + + INFO = "INFO" + WARN = "WARN" + CRITICAL = "CRITICAL" + + +class OWASPEventType(Enum): + """ + OWASP security event types. + + Format: category_event_name + Events are logged as: event_type:param1,param2,... + """ + + # Authentication events [AUTHN] + AUTHN_PASSWORD_CHANGE = "authn_password_change" + + # System events [SYS] + SYS_SHUTDOWN = "sys_shutdown" + SYS_RESTART = "sys_restart" + + # User management events [USER] + USER_CREATED = "user_created" + USER_UPDATED = "user_updated" + + +def _build_event_string( + event_type: OWASPEventType, params: Optional[List[str]] = None +) -> str: + """ + Build the OWASP event string with optional parameters. + + :param event_type: The type of security event. + :param params: Optional list of parameters to append. + :return: Event string in format "event_type:param1,param2,..." + """ + event_str = event_type.value + if params: + # Filter out None values and convert to strings + filtered_params = [str(p) for p in params if p is not None] + if filtered_params: + event_str += ":" + ",".join(filtered_params) + return event_str + + +def _build_security_event( + event_type: OWASPEventType, + level: OWASPEventLevel, + description: str, + event_params: Optional[List[str]] = None, + additional_data: Optional[Dict[str, Any]] = None, +) -> Dict[str, Any]: + """ + Build a security event dictionary following OWASP Logging Vocabulary. + + :param event_type: Type of security event. + :param level: Log level (INFO, WARN, CRITICAL). + :param description: Human-readable description of the event. + :param event_params: Parameters to include in the event string. + :param additional_data: Additional context-specific data. + :return: Dictionary containing the security event data. + """ + event = { + "datetime": datetime.datetime.now(datetime.timezone.utc).isoformat(), + "appid": APP_ID, + "event": _build_event_string(event_type, event_params), + "level": level.value, + "description": description, + "hostname": util.get_hostname(), + } + + if additional_data: + # Merge additional data but don't overwrite core fields + for key, value in additional_data.items(): + if key not in event: + event[key] = value + + return event + + +def _log_security_event( + event_type: OWASPEventType, + level: OWASPEventLevel, + description: str, + event_params: Optional[List[str]] = None, + additional_data: Optional[Dict[str, Any]] = None, + log_file: Optional[str] = DEFAULT_SECURITY_LOG, +) -> None: + """ + Log a security event in OWASP format. + + :param event_type: Type of security event. + :param level: Log level (INFO, WARN, CRITICAL). + :param description: Human-readable description of the event. + :param event_params: Parameters to include in the event string. + :param additional_data: Additional context-specific data. + :param log_file: Path to which to write the JSON lines. + """ + event = _build_security_event( + event_type=event_type, + level=level, + description=description, + event_params=event_params, + additional_data=additional_data, + ) + + try: + json_line = json.dumps(event, separators=(",", ":")) + "\n" + + # Create file with restricted permissions if it doesn't exist + if not os.path.exists(log_file): + util.ensure_file(log_file, mode=0o600, preserve_mode=False) + + util.append_file(log_file, json_line, disable_logging=True) + + except Exception as e: + LOG.warning( + "Failed to write security event to %s: %s", + log_file, + str(e), + ) + + +def sec_log_user_created( + userid: str, + new_userid: str, + attributes: Optional[Dict[str, Any]] = None, + log_file: Optional[str] = DEFAULT_SECURITY_LOG, +) -> None: + """ + Log a user creation event providing any admin-related attributes granted. + + :param userid: The user/process that initiated the action. + :param new_userid: The username of the newly created user. + :param attributes: Additional user attributes (groups, shell, etc.). + :param log_file: Override the default log file path. + """ + params = [userid, new_userid] + if attributes: + # Add a summary of attributes + attr_summary = ";".join( + f"{k}={v}" for k, v in attributes.items() if v is not None + ) + if attr_summary: + params.append(attr_summary) + + _log_security_event( + event_type=OWASPEventType.USER_CREATED, + level=OWASPEventLevel.WARN, + description=f"User '{new_userid}' was created", + event_params=params, + additional_data=attributes, + log_file=log_file, + ) + + +def sec_log_user_updated( + userid: str, + on_userid: str, + attributes: Optional[Dict[str, Any]] = None, + log_file: Optional[str] = DEFAULT_SECURITY_LOG, +) -> None: + """ + Log a user update event. + + :param userid: The user/process that initiated the action. + :param on_userid: The username being updated. + :param attributes: Attributes being updated. + :param log_file: Override the default log file path. + """ + params = [userid, on_userid] + if attributes: + attr_summary = ";".join( + f"{k}={v}" for k, v in attributes.items() if v is not None + ) + if attr_summary: + params.append(attr_summary) + + _log_security_event( + event_type=OWASPEventType.USER_UPDATED, + level=OWASPEventLevel.WARN, + description=f"User '{on_userid}' was updated", + event_params=params, + additional_data=attributes, + log_file=log_file, + ) + + +def sec_log_password_changed( + userid: str, + log_file: Optional[str] = DEFAULT_SECURITY_LOG, +) -> None: + """ + Log a password change event. + + :param userid: The user whose password was changed. + :param log_file: Override the default log file path. + """ + _log_security_event( + event_type=OWASPEventType.AUTHN_PASSWORD_CHANGE, + level=OWASPEventLevel.INFO, + description=f"Password changed for user '{userid}'", + event_params=[userid], + log_file=log_file, + ) + + +def sec_log_system_shutdown( + userid: Optional[str] = None, + mode: Optional[str] = None, + delay: Optional[str] = None, + log_file: Optional[str] = DEFAULT_SECURITY_LOG, +) -> None: + """ + Log a system shutdown event. + + :param userid: The user/process that initiated the shutdown. + :param mode: Shutdown mode (halt, poweroff, reboot). + :param delay: Delay before shutdown. + :param log_file: Override the default log file path. + """ + additional = {} + if mode == "reboot": + event_type = OWASPEventType.SYS_RESTART + description = "System restart initiated" + else: + event_type = OWASPEventType.SYS_SHUTDOWN + description = f"System shutdown initiated (mode={mode})" + additional["mode"] = mode + if delay: + additional["delay"] = delay + + _log_security_event( + event_type=OWASPEventType.SYS_SHUTDOWN, + level=OWASPEventLevel.INFO, + description=f"System shutdown initiated (mode={mode})", + event_params=["cloud-init"], + additional_data=additional if additional else None, + log_file=log_file, + ) diff --git a/cloudinit/settings.py b/cloudinit/settings.py index f2ca6585a0e..164979456d4 100644 --- a/cloudinit/settings.py +++ b/cloudinit/settings.py @@ -18,6 +18,8 @@ DEFAULT_RUN_DIR = "/run/cloud-init" +DEFAULT_SECURITY_LOG = "/var/log/cloud-init-security.log" + # What u get if no config is provided CFG_BUILTIN = { "datasource_list": [ @@ -55,6 +57,7 @@ "None", ], "def_log_file": "/var/log/cloud-init.log", + "security_log_file": DEFAULT_SECURITY_LOG, "log_cfgs": [], "syslog_fix_perms": ["syslog:adm", "root:adm", "root:wheel", "root:root"], "system_info": { diff --git a/cloudinit/util.py b/cloudinit/util.py index cac5926f10f..2bc5c092f78 100644 --- a/cloudinit/util.py +++ b/cloudinit/util.py @@ -1777,9 +1777,10 @@ def get_config_logfiles(cfg: Dict[str, Any]): rotated_logs = [] if not cfg or not isinstance(cfg, dict): return logs - default_log = cfg.get("def_log_file") - if default_log: - logs.append(default_log) + + for log_cfg_key in ("def_log_file", "security_log_file"): + if cfg.get(log_cfg_key): + logs.append(cfg[log_cfg_key]) for fmt in get_output_cfg(cfg, None): if not fmt: continue @@ -2150,8 +2151,10 @@ def uptime(): return uptime_str -def append_file(path, content): - write_file(path, content, omode="ab", mode=None) +def append_file(path, content, disable_logging: bool = False): + write_file( + path, content, omode="ab", mode=None, disable_logging=disable_logging + ) def ensure_file( @@ -2248,6 +2251,7 @@ def write_file( ensure_dir_exists: bool = True, user=None, group=None, + disable_logging: bool = False, ): """ Writes a file with the given content and sets the file mode as specified. @@ -2264,6 +2268,7 @@ def write_file( the file. @param user: The user to set on the file. @param group: The group to set on the file. + @param disable_logging: Whether to avoid logging this operation. """ if preserve_mode: @@ -2284,14 +2289,15 @@ def write_file( mode_r = "%o" % mode except TypeError: mode_r = "%r" % mode - LOG.debug( - "Writing to %s - %s: [%s] %s %s", - filename, - omode, - mode_r, - len(content), - write_type, - ) + if not disable_logging: + LOG.debug( + "Writing to %s - %s: [%s] %s %s", + filename, + omode, + mode_r, + len(content), + write_type, + ) with SeLinuxGuard(path=filename): with open(filename, omode) as fh: fh.write(content) diff --git a/tests/unittests/distros/test_create_users.py b/tests/unittests/distros/test_create_users.py index 095924b106b..d1242a9b143 100644 --- a/tests/unittests/distros/test_create_users.py +++ b/tests/unittests/distros/test_create_users.py @@ -15,6 +15,8 @@ @pytest.fixture(autouse=True) def common_mocks(mocker): mocker.patch("cloudinit.distros.util.system_is_snappy", return_value=False) + mocker.patch("cloudinit.distros.sec_log_user_created") + mocker.patch("cloudinit.distros.sec_log_password_changed") def _chpasswdmock(name: str, password: str, hashed: bool = False): @@ -429,10 +431,12 @@ def test_avoid_unlock_preexisting_user_empty_password( ), ], ) + @mock.patch("cloudinit.distros.sec_log_password_changed") @mock.patch("cloudinit.distros.util.is_user", return_value=True) def test_create_passwd_existing_user( self, m_is_user, + m_sec_log_password_changed, m_subp, create_kwargs, expected, @@ -447,6 +451,10 @@ def test_create_passwd_existing_user( for log in expected_logs: assert log in caplog.text assert m_subp.call_args_list == expected + if "passwd" in create_kwargs: + m_sec_log_password_changed.assert_not_called() + else: + m_sec_log_password_changed.assert_called_once_with(userid=USER) @mock.patch("cloudinit.distros.util.is_group") def test_group_added(self, m_is_group, m_subp, dist, mocker): @@ -502,6 +510,8 @@ def test_snappy_only_new_group_added( ex_groups = ["existing_group"] groups = ["group1", ex_groups[0]] m_is_group.side_effect = lambda m: m in ex_groups + m_sec_log = mocker.patch("cloudinit.distros.sec_log_user_created") + dist.create_user(USER, groups=groups) expected = [ mock.call(["groupadd", "group1", "--extrausers"]), @@ -511,6 +521,11 @@ def test_snappy_only_new_group_added( mock.call(["passwd", "-l", USER]), ] assert m_subp.call_args_list == expected + m_sec_log.assert_called_once_with( + userid="cloud-init", + new_userid=USER, + attributes={"groups": ",".join(groups)}, + ) @mock.patch("cloudinit.distros.util.is_group") def test_create_groups_with_whitespace_string( @@ -625,6 +640,7 @@ def test_explicit_sudo_false(self, m_subp, dist, caplog, mocker): mocker.patch( "cloudinit.distros.util.system_is_snappy", return_value=False ) + m_sec_log = mocker.patch("cloudinit.distros.sec_log_user_created") dist.create_user(USER, sudo=False) assert m_subp.call_args_list == [ _useradd2call([USER, "-m"]), @@ -644,6 +660,11 @@ def test_explicit_sudo_false(self, m_subp, dist, caplog, mocker): "config is deprecated in 22.2 and scheduled to be removed" " in 27.2. Use 'null' instead." ) in caplog.text + m_sec_log.assert_called_once_with( + userid="cloud-init", + new_userid=USER, + attributes=None, + ) def test_explicit_sudo_none(self, m_subp, dist, caplog, mocker): mocker.patch( diff --git a/tests/unittests/distros/test_user_data_normalize.py b/tests/unittests/distros/test_user_data_normalize.py index a1a77d1a0e9..c5a14ea1079 100644 --- a/tests/unittests/distros/test_user_data_normalize.py +++ b/tests/unittests/distros/test_user_data_normalize.py @@ -266,8 +266,9 @@ def test_users_dict(self): assert {"default": False} == users["joe"] assert {"default": False} == users["bob"] + @mock.patch("cloudinit.distros.sec_log_user_created") @mock.patch("cloudinit.subp.subp") - def test_create_snap_user(self, mock_subp): + def test_create_snap_user(self, mock_subp, m_sec_log_user_created): mock_subp.side_effect = [ ('{"username": "joe", "ssh-key-count": 1}\n', "") ] @@ -285,9 +286,15 @@ def test_create_snap_user(self, mock_subp): snapcmd = ["snap", "create-user", "--sudoer", "--json", "joe@joe.com"] mock_subp.assert_called_with(snapcmd, capture=True, logstring=snapcmd) assert username == "joe" + m_sec_log_user_created.assert_called_once_with( + userid="cloud-init", + new_userid="joe", + attributes={"snapuser": True, "sudo": True}, + ) + @mock.patch("cloudinit.distros.sec_log_user_created") @mock.patch("cloudinit.subp.subp") - def test_create_snap_user_known(self, mock_subp): + def test_create_snap_user_known(self, mock_subp, m_sec_log_user_created): mock_subp.side_effect = [ ('{"username": "joe", "ssh-key-count": 1}\n', "") ] @@ -312,6 +319,11 @@ def test_create_snap_user_known(self, mock_subp): ] mock_subp.assert_called_with(snapcmd, capture=True, logstring=snapcmd) assert username == "joe" + m_sec_log_user_created.assert_called_once_with( + userid="cloud-init", + new_userid="joe", + attributes={"snapuser": True, "sudo": True}, + ) @mock.patch("cloudinit.util.system_is_snappy") @mock.patch("cloudinit.util.is_group") diff --git a/tests/unittests/log/__init__.py b/tests/unittests/log/__init__.py new file mode 100644 index 00000000000..da6365a5941 --- /dev/null +++ b/tests/unittests/log/__init__.py @@ -0,0 +1 @@ +# This file is part of cloud-init. See LICENSE file for license information. diff --git a/tests/unittests/log/test_security_event_log.py b/tests/unittests/log/test_security_event_log.py new file mode 100644 index 00000000000..361826fa98d --- /dev/null +++ b/tests/unittests/log/test_security_event_log.py @@ -0,0 +1,348 @@ +# This file is part of cloud-init. See LICENSE file for license information. + +"""Tests for cloudinit.log.security_event_log""" + +import json +import os + +import pytest + +from cloudinit.log import security_event_log +from cloudinit.log.security_event_log import ( + APP_ID, + OWASPEventLevel, + OWASPEventType, + sec_log_password_changed, + sec_log_system_shutdown, + sec_log_user_created, + sec_log_user_updated, +) +from cloudinit.settings import DEFAULT_SECURITY_LOG + + +@pytest.fixture +def security_log_file(tmp_path): + """Provide a temporary security log file path.""" + return tmp_path / "cloud-init-security-events.log" + + +class TestBuildEventString: + """Tests for _build_event_string function.""" + + @pytest.mark.parametrize( + "event_type,params,expected", + [ + (OWASPEventType.SYS_SHUTDOWN, None, "sys_shutdown"), + ( + OWASPEventType.AUTHN_PASSWORD_CHANGE, + ["testuser"], + "authn_password_change:testuser", + ), + ( + OWASPEventType.USER_CREATED, + ["cloud-init", "newuser", "groups=wheel"], + "user_created:cloud-init,newuser,groups=wheel", + ), + ( + OWASPEventType.USER_CREATED, + ["cloud-init", None, "newuser"], + "user_created:cloud-init,newuser", + ), + ], + ids=[ + "no_params", + "single_param", + "multiple_params", + "filters_none_params", + ], + ) + def test_event_string_formatting(self, event_type, params, expected): + """Test event string formatting with various parameter combinations.""" + result = security_event_log._build_event_string(event_type, params) + assert result == expected + + +class TestBuildSecurityEvent: + """Tests for _build_security_event function.""" + + def test_event_contains_required_owasp_fields(self): + """Test that built event contains all required OWASP fields.""" + event = security_event_log._build_security_event( + event_type=OWASPEventType.USER_CREATED, + level=OWASPEventLevel.INFO, + description="Test event", + event_params=["cloud-init", "testuser"], + ) + + assert "datetime" in event + assert event["appid"] == "canonical.cloud_init" + assert event["event"] == "user_created:cloud-init,testuser" + assert event["level"] == "INFO" + assert event["description"] == "Test event" + assert "hostname" in event + + def test_event_with_additional_data(self): + """Test event includes additional data when provided.""" + event = security_event_log._build_security_event( + event_type=OWASPEventType.USER_CREATED, + level=OWASPEventLevel.INFO, + description="Test event", + additional_data={"groups": "wheel", "shell": "/bin/bash"}, + ) + + assert event["groups"] == "wheel" + assert event["shell"] == "/bin/bash" + + def test_additional_data_does_not_overwrite_core_fields(self): + """Test that additional data cannot overwrite core fields.""" + event = security_event_log._build_security_event( + event_type=OWASPEventType.USER_CREATED, + level=OWASPEventLevel.INFO, + description="Test event", + additional_data={"appid": "malicious.app", "level": "CRITICAL"}, + ) + + assert event["appid"] == "canonical.cloud_init" + assert event["level"] == "INFO" + + def test_timestamp_is_iso_format(self): + """Test that datetime is in ISO 8601 format.""" + event = security_event_log._build_security_event( + event_type=OWASPEventType.USER_CREATED, + level=OWASPEventLevel.INFO, + description="Test event", + ) + + # ISO 8601 format check - should contain 'T' separator + assert "T" in event["datetime"] + # Should end with timezone info (e.g., +00:00) + assert "+" in event["datetime"] or "Z" in event["datetime"] + + +class TestLogSecurityEvent: + """Tests for _log_security_event function.""" + + def test_writes_json_to_file(self, security_log_file): + """Test that event is written to log file as JSON.""" + security_event_log._log_security_event( + event_type=OWASPEventType.USER_CREATED, + level=OWASPEventLevel.INFO, + description="User created successfully", + event_params=["cloud-init", "testuser"], + log_file=security_log_file, + ) + event = json.loads(security_log_file.read_text()) + + assert event["event"] == "user_created:cloud-init,testuser" + assert event["level"] == "INFO" + assert event["appid"] == "canonical.cloud_init" + + def test_appends_multiple_events(self, security_log_file): + """Test that multiple events are appended to the log file.""" + security_event_log._log_security_event( + event_type=OWASPEventType.USER_CREATED, + level=OWASPEventLevel.INFO, + description="First user", + event_params=["cloud-init", "user1"], + log_file=security_log_file, + ) + + security_event_log._log_security_event( + event_type=OWASPEventType.USER_CREATED, + level=OWASPEventLevel.INFO, + description="Second user", + event_params=["cloud-init", "user2"], + log_file=security_log_file, + ) + + lines = security_log_file.read_text().splitlines() + + assert len(lines) == 2 + event1 = json.loads(lines[0]) + event2 = json.loads(lines[1]) + assert "user1" in event1["event"] + assert "user2" in event2["event"] + + def test_uses_default_log_file_when_not_specified( + self, security_log_file, mocker + ): + """Test that default log file path is used when not specified.""" + mocker.patch( + "cloudinit.settings.DEFAULT_SECURITY_LOG", security_log_file + ) + + security_event_log._log_security_event( + event_type=OWASPEventType.USER_CREATED, + level=OWASPEventLevel.INFO, + description="Test event", + log_file=security_log_file, + ) + assert security_log_file.exists(), f"File missing {security_log_file}" + + def test_log_file_has_restricted_permissions(self, security_log_file): + """Test that log file is created with restricted permissions.""" + security_event_log._log_security_event( + event_type=OWASPEventType.USER_CREATED, + level=OWASPEventLevel.INFO, + description="Test event", + log_file=security_log_file, + ) + + file_mode = os.stat(security_log_file).st_mode & 0o777 + assert file_mode == 0o600 + + +class TestUserCreatedEvent: + """Tests for sec_log_user_created function.""" + + def test_logs_user_created_event(self, security_log_file): + """Test logging a user creation event.""" + sec_log_user_created( + userid="cloud-init", + new_userid="testuser", + attributes={"groups": "wheel", "shell": "/bin/bash"}, + log_file=security_log_file, + ) + + event = json.loads(security_log_file.read_text()) + + assert "user_created" in event["event"] + assert "cloud-init" in event["event"] + assert "testuser" in event["event"] + assert event["level"] == "WARN" + assert "testuser" in event["description"] + + def test_user_created_includes_attributes(self, security_log_file): + """Test that attributes are included in event.""" + sec_log_user_created( + userid="cloud-init", + new_userid="testuser", + attributes={"groups": "wheel,docker", "uid": 1001}, + log_file=security_log_file, + ) + + event = json.loads(security_log_file.read_text()) + + assert event["groups"] == "wheel,docker" + assert event["uid"] == 1001 + + +class TestUserUpdatedEvent: + """Tests for sec_log_user_updated function.""" + + def test_logs_user_updated_event(self, security_log_file): + """Test logging a user update event.""" + sec_log_user_updated( + userid="cloud-init", + on_userid="existinguser", + attributes={"ssh_keys_added": True}, + log_file=security_log_file, + ) + + event = json.loads(security_log_file.read_text()) + + assert "user_updated" in event["event"] + assert "existinguser" in event["event"] + assert event["level"] == "WARN" + + +class TestPasswordChangedEvent: + """Tests for sec_log_password_changed function.""" + + def test_logs_password_changed_event(self, security_log_file): + """Test logging a password change event.""" + sec_log_password_changed( + userid="testuser", + log_file=security_log_file, + ) + + event = json.loads(security_log_file.read_text()) + + assert event["event"] == "authn_password_change:testuser" + assert event["level"] == "INFO" + assert "testuser" in event["description"] + + +class TestSystemShutdownEvent: + """Tests for sec_log_system_shutdown function.""" + + def test_logs_system_shutdown_event(self, security_log_file): + """Test logging a system shutdown event.""" + sec_log_system_shutdown( + userid="cloud-init", + mode="poweroff", + delay="+5", + log_file=security_log_file, + ) + + event = json.loads(security_log_file.read_text()) + + assert event["event"] == "sys_shutdown:cloud-init" + assert event["level"] == "INFO" + assert event["mode"] == "poweroff" + assert event["delay"] == "+5" + + +class TestSystemRestartEvent: + """Tests for sec_log_system_shutdown with reboot mode.""" + + def test_logs_system_restart_event(self, security_log_file): + """Test logging a system restart event.""" + sec_log_system_shutdown( + userid="cloud-init", + mode="reboot", + delay="now", + log_file=security_log_file, + ) + + event = json.loads(security_log_file.read_text()) + + # Note: Currently the implementation has a bug where it always logs sys_shutdown + # even for reboots, but let's test what it should be doing + assert event["event"] == "sys_shutdown:cloud-init" + assert event["level"] == "INFO" + assert event["delay"] == "now" + + +class TestEventTypeEnums: + """Tests for event type enum values.""" + + @pytest.mark.parametrize( + "event_type,expected_value", + [ + (OWASPEventType.AUTHN_PASSWORD_CHANGE, "authn_password_change"), + (OWASPEventType.SYS_SHUTDOWN, "sys_shutdown"), + (OWASPEventType.SYS_RESTART, "sys_restart"), + (OWASPEventType.USER_CREATED, "user_created"), + (OWASPEventType.USER_UPDATED, "user_updated"), + ], + ids=[ + "authn_password_change", + "sys_shutdown", + "sys_restart", + "user_created", + "user_updated", + ], + ) + def test_event_type_values(self, event_type, expected_value): + """Test event type enum values.""" + assert event_type.value == expected_value + + +class TestErrorHandling: + """Tests for error handling in security event logging.""" + + def test_handles_write_permission_error(self, mocker, caplog): + """Test graceful handling of permission errors.""" + mocker.patch("builtins.open", side_effect=PermissionError("denied")) + mocker.patch("os.path.exists", return_value=True) + + # Should not raise, just log warning + security_event_log._log_security_event( + event_type=OWASPEventType.USER_CREATED, + level=OWASPEventLevel.INFO, + description="Test event", + log_file="/unwritable/path.log", + ) + + assert "Failed to write security event" in caplog.text diff --git a/tests/unittests/test_util.py b/tests/unittests/test_util.py index 90206489987..30e04ccee9e 100644 --- a/tests/unittests/test_util.py +++ b/tests/unittests/test_util.py @@ -2262,8 +2262,21 @@ def test_empty_cfg_returns_empty_list(self): assert [] == util.get_config_logfiles(None) assert [] == util.get_config_logfiles({}) - def test_default_log_file_present(self): - """When default_log_file is set get_config_logfiles finds it.""" + @pytest.mark.parametrize( + "cfg,expected_logs", + ( + ({"def_log_file": "/my.log"}, ["/my.log"]), + ( + { + "def_log_file": "/my.log", + "security_log_file": "/my_sec.log", + }, + ["/my.log", "/my_sec.log"], + ), + ), + ) + def test_default_log_files_present(self, cfg, expected_logs): + """get_config_logfiles reports def_log_file and security_log_file.""" assert ["/my.log"] == util.get_config_logfiles( {"def_log_file": "/my.log"} ) From e4fd5a948a599180a967f734e939e9708ce06917 Mon Sep 17 00:00:00 2001 From: Chad Smith Date: Mon, 26 Jan 2026 14:44:51 -0700 Subject: [PATCH 02/31] doc: document security_log_file base config setting --- doc/rtd/explanation/instancedata.rst | 1 + doc/rtd/reference/base_config_reference.rst | 6 ++++++ 2 files changed, 7 insertions(+) diff --git a/doc/rtd/explanation/instancedata.rst b/doc/rtd/explanation/instancedata.rst index 5d4a45b43b2..19362cc35c5 100644 --- a/doc/rtd/explanation/instancedata.rst +++ b/doc/rtd/explanation/instancedata.rst @@ -481,6 +481,7 @@ Below is an example of sensitive ``instance-data`` on an EC2 instance: "all": "| tee -a /var/log/cloud-init-output.log" }, "preserve_hostname": false, + "security_log_file": "/var/log/cloud-init-security.log", "syslog_fix_perms": [ "syslog:adm", "root:adm", diff --git a/doc/rtd/reference/base_config_reference.rst b/doc/rtd/reference/base_config_reference.rst index 8001da77e97..c454690dacb 100644 --- a/doc/rtd/reference/base_config_reference.rst +++ b/doc/rtd/reference/base_config_reference.rst @@ -277,6 +277,12 @@ Only used in conjunction with ``syslog_fix_perms``. Specifies the filename to be used for setting permissions. Defaults to :file:`/var/log/cloud-init.log`. +``security_log_file`` +^^^^^^^^^^^^^^^^^^^^^ + +Specifies the filename to be used for emitting OSWAP security logs. Defaults +to :file:`/var/log/cloud-init-security.log`. + Other keys ---------- From 9b7790b2f3c736185f18d7bef64d5004a0531b2c Mon Sep 17 00:00:00 2001 From: Chad Smith Date: Mon, 23 Feb 2026 16:54:17 -0700 Subject: [PATCH 03/31] feat: define decorators for sec_log_* and apply to distro methods --- cloudinit/distros/__init__.py | 28 +- cloudinit/distros/alpine.py | 3 +- cloudinit/log/loggers.py | 20 +- cloudinit/log/security_event_log.py | 205 +++++------- cloudinit/settings.py | 3 - tests/unittests/distros/test_create_users.py | 31 +- .../distros/test_user_data_normalize.py | 21 +- .../unittests/log/test_security_event_log.py | 293 +++++++----------- tests/unittests/test_log.py | 16 +- tests/unittests/util.py | 3 + 10 files changed, 256 insertions(+), 367 deletions(-) diff --git a/cloudinit/distros/__init__.py b/cloudinit/distros/__init__.py index eb4cc3c9bea..3b1381e3d95 100644 --- a/cloudinit/distros/__init__.py +++ b/cloudinit/distros/__init__.py @@ -789,12 +789,6 @@ def add_user(self, name, **kwargs) -> bool: elif k in ("sudo", "doas") and v: user_attributes[k] = True - sec_log_user_created( - userid="cloud-init", - new_userid=name, - attributes=user_attributes if user_attributes else None, - ) - # Indicate that a new user was created return True @@ -822,11 +816,6 @@ def add_snap_user(self, name, **kwargs): LOG.debug("snap create-user returned: %s:%s", out, err) jobj = util.load_json(out) username = jobj.get("username", None) - sec_log_user_created( - userid="cloud-init", - new_userid=name, - attributes={"snapuser": True, "sudo": True}, - ) except Exception as e: util.logexc(LOG, "Failed to create snap user %s", name) raise e @@ -867,6 +856,7 @@ def _shadow_file_has_empty_user_password(self, username) -> bool: return True return False + @sec_log_user_created def create_user(self, name, **kwargs): """ Creates or partially updates the ``name`` user in the system. @@ -1116,6 +1106,7 @@ def expire_passwd(self, user): util.logexc(LOG, "Failed to set 'expire' for %s", user) raise e + @sec_log_password_changed def set_passwd(self, user, passwd, hashed=False): pass_string = "%s:%s" % (user, passwd) cmd = ["chpasswd"] @@ -1134,8 +1125,6 @@ def set_passwd(self, user, passwd, hashed=False): util.logexc(LOG, "Failed to set password for %s", user) raise e - # Log security event for password change - sec_log_password_changed(userid=user) return True def chpasswd(self, plist_in: list, hashed: bool): @@ -1151,10 +1140,6 @@ def chpasswd(self, plist_in: list, hashed: bool): cmd = ["chpasswd"] + (["-e"] if hashed else []) subp.subp(cmd, data=payload) - # Log security event for each password change - for name, _ in plist_in: - sec_log_password_changed(userid=name) - def is_doas_rule_valid(self, user, rule): rule_pattern = ( r"^(?:permit|deny)" @@ -1351,8 +1336,13 @@ def create_group(self, name, members=None): LOG.info("Added user '%s' to group '%s'", member, name) @classmethod + @sec_log_system_shutdown def shutdown_command(cls, *, mode, delay, message): - # called from cc_power_state_change.load_power_state + # called from cc_power_state_change.load_power_state and clean + if hasattr(cls, "_shutdown_command"): # Overridden in alpine.Distro + return cls._shutdown_command( + mode=mode, delay=delay, message=message + ) command = ["shutdown", cls.shutdown_options_map[mode]] try: if delay != "now": @@ -1366,8 +1356,6 @@ def shutdown_command(cls, *, mode, delay, message): if message: args.append(message) - sec_log_system_shutdown(mode=mode, delay=str(delay)) - return args @classmethod diff --git a/cloudinit/distros/alpine.py b/cloudinit/distros/alpine.py index 19912d3724f..dcec76128a8 100644 --- a/cloudinit/distros/alpine.py +++ b/cloudinit/distros/alpine.py @@ -573,7 +573,8 @@ def create_group(self, name, members=None): subp.subp(["addgroup", member, name]) LOG.info("Added user '%s' to group '%s'", member, name) - def shutdown_command(self, mode="poweroff", delay="now", message=None): + @classmethod + def _shutdown_command(cls, mode, delay, message): # called from cc_power_state_change.load_power_state # Alpine has halt/poweroff/reboot, with the following specifics: # - we use them rather than the generic "shutdown" diff --git a/cloudinit/log/loggers.py b/cloudinit/log/loggers.py index a3e5a78c7f5..8a44f522681 100644 --- a/cloudinit/log/loggers.py +++ b/cloudinit/log/loggers.py @@ -22,6 +22,8 @@ from typing import DefaultDict DEFAULT_LOG_FORMAT = "%(asctime)s - %(filename)s[%(levelname)s]: %(message)s" +SECURITY_LOG_FORMAT = "%(message)s" +SECURITY = 36 DEPRECATED = 35 TRACE = logging.DEBUG - 5 @@ -41,9 +43,21 @@ def trace(self, *args, **kwargs): def deprecated(self, *args, **kwargs): pass + def security(self, *args, **kwargs): + pass + + +class LevelBasedFormatter(logging.Formatter): + def format(self, record): + if record.levelno == SECURITY: + self._style._fmt = SECURITY_LOG_FORMAT + else: + self._style._fmt = DEFAULT_LOG_FORMAT + return super().format(record) + def setup_basic_logging(level=logging.DEBUG, formatter=None): - formatter = formatter or logging.Formatter(DEFAULT_LOG_FORMAT) + formatter = formatter or LevelBasedFormatter() root = logging.getLogger() console = logging.StreamHandler(sys.stderr) console.setFormatter(formatter) @@ -63,7 +77,7 @@ def flush_loggers(root): def define_extra_loggers() -> None: - """Add DEPRECATED and TRACE log levels to the logging module.""" + """Add SECURITY, DEPRECATED and TRACE log levels to the logging module.""" def new_logger(level): def log_at_level(self, message, *args, **kwargs): @@ -72,8 +86,10 @@ def log_at_level(self, message, *args, **kwargs): return log_at_level + logging.addLevelName(SECURITY, "SECURITY") logging.addLevelName(DEPRECATED, "DEPRECATED") logging.addLevelName(TRACE, "TRACE") + setattr(logging.Logger, "security", new_logger(SECURITY)) setattr(logging.Logger, "deprecated", new_logger(DEPRECATED)) setattr(logging.Logger, "trace", new_logger(TRACE)) diff --git a/cloudinit/log/security_event_log.py b/cloudinit/log/security_event_log.py index b9adf5eb575..5c115de9df4 100644 --- a/cloudinit/log/security_event_log.py +++ b/cloudinit/log/security_event_log.py @@ -16,15 +16,14 @@ """ import datetime +import functools import json import logging -import os -import socket from enum import Enum from typing import Any, Dict, List, Optional from cloudinit import util -from cloudinit.settings import DEFAULT_SECURITY_LOG +from cloudinit.log import loggers LOG = logging.getLogger(__name__) @@ -120,17 +119,15 @@ def _log_security_event( description: str, event_params: Optional[List[str]] = None, additional_data: Optional[Dict[str, Any]] = None, - log_file: Optional[str] = DEFAULT_SECURITY_LOG, ) -> None: """ Log a security event in OWASP format. :param event_type: Type of security event. - :param level: Log level (INFO, WARN, CRITICAL). + :param level: OWASP Log level (INFO, WARN, CRITICAL). :param description: Human-readable description of the event. :param event_params: Parameters to include in the event string. :param additional_data: Additional context-specific data. - :param log_file: Path to which to write the JSON lines. """ event = _build_security_event( event_type=event_type, @@ -139,138 +136,86 @@ def _log_security_event( event_params=event_params, additional_data=additional_data, ) - - try: - json_line = json.dumps(event, separators=(",", ":")) + "\n" - - # Create file with restricted permissions if it doesn't exist - if not os.path.exists(log_file): - util.ensure_file(log_file, mode=0o600, preserve_mode=False) - - util.append_file(log_file, json_line, disable_logging=True) - - except Exception as e: - LOG.warning( - "Failed to write security event to %s: %s", - log_file, - str(e), - ) + LOG.log(loggers.SECURITY, json.dumps(event, separators=(",", ":"))) -def sec_log_user_created( - userid: str, - new_userid: str, - attributes: Optional[Dict[str, Any]] = None, - log_file: Optional[str] = DEFAULT_SECURITY_LOG, -) -> None: +def sec_log_user_created(func): """ - Log a user creation event providing any admin-related attributes granted. + A decorator to log a user creation event and priviledged attributes. :param userid: The user/process that initiated the action. :param new_userid: The username of the newly created user. :param attributes: Additional user attributes (groups, shell, etc.). - :param log_file: Override the default log file path. """ - params = [userid, new_userid] - if attributes: - # Add a summary of attributes - attr_summary = ";".join( - f"{k}={v}" for k, v in attributes.items() if v is not None - ) - if attr_summary: - params.append(attr_summary) - - _log_security_event( - event_type=OWASPEventType.USER_CREATED, - level=OWASPEventLevel.WARN, - description=f"User '{new_userid}' was created", - event_params=params, - additional_data=attributes, - log_file=log_file, - ) - -def sec_log_user_updated( - userid: str, - on_userid: str, - attributes: Optional[Dict[str, Any]] = None, - log_file: Optional[str] = DEFAULT_SECURITY_LOG, -) -> None: - """ - Log a user update event. - - :param userid: The user/process that initiated the action. - :param on_userid: The username being updated. - :param attributes: Attributes being updated. - :param log_file: Override the default log file path. - """ - params = [userid, on_userid] - if attributes: - attr_summary = ";".join( - f"{k}={v}" for k, v in attributes.items() if v is not None + @functools.wraps(func) + def decorator(*args, **kwargs): + new_userid = args[-1] if args else kwargs.get("name") + if not new_userid: + raise RuntimeError( + "sec_log_user_created requires positional param name or kwarg" + ) + params = ["cloud-init", new_userid] + + response = func(*args, **kwargs) + if response: + _log_security_event( + event_type=OWASPEventType.USER_CREATED, + level=OWASPEventLevel.WARN, + description=f"User '{new_userid}' was created", + event_params=params, + ) + return response + + return decorator + + +def sec_log_password_changed(func): + """A decorator logging a password change event.""" + + @functools.wraps(func) + def decorator(*args, **kwargs): + response = func(*args, **kwargs) + userid = kwargs.get("user") + if not userid: + userid = args[-1] + _log_security_event( + event_type=OWASPEventType.AUTHN_PASSWORD_CHANGE, + level=OWASPEventLevel.INFO, + description=f"Password changed for user '{userid}'", + event_params=["cloud-init", userid], ) - if attr_summary: - params.append(attr_summary) - - _log_security_event( - event_type=OWASPEventType.USER_UPDATED, - level=OWASPEventLevel.WARN, - description=f"User '{on_userid}' was updated", - event_params=params, - additional_data=attributes, - log_file=log_file, - ) - - -def sec_log_password_changed( - userid: str, - log_file: Optional[str] = DEFAULT_SECURITY_LOG, -) -> None: - """ - Log a password change event. - - :param userid: The user whose password was changed. - :param log_file: Override the default log file path. - """ - _log_security_event( - event_type=OWASPEventType.AUTHN_PASSWORD_CHANGE, - level=OWASPEventLevel.INFO, - description=f"Password changed for user '{userid}'", - event_params=[userid], - log_file=log_file, - ) - - -def sec_log_system_shutdown( - userid: Optional[str] = None, - mode: Optional[str] = None, - delay: Optional[str] = None, - log_file: Optional[str] = DEFAULT_SECURITY_LOG, -) -> None: - """ - Log a system shutdown event. + return response + + return decorator + + +def sec_log_system_shutdown(func): + """A decorator logging a system shutdown event.""" + + @functools.wraps(func) + def decorator(*args, **kwargs): + mode = kwargs["mode"] + delay = kwargs["delay"] + + additional = {} + if mode == "reboot": + event_type = OWASPEventType.SYS_RESTART + description = "System restart initiated" + else: + event_type = OWASPEventType.SYS_SHUTDOWN + description = f"System shutdown initiated (mode={mode})" + additional["mode"] = mode + if delay: + additional["delay"] = delay + + _log_security_event( + event_type=event_type, + level=OWASPEventLevel.INFO, + description=description, + event_params=["cloud-init"], + additional_data=additional if additional else None, + ) + return func(*args, **kwargs) - :param userid: The user/process that initiated the shutdown. - :param mode: Shutdown mode (halt, poweroff, reboot). - :param delay: Delay before shutdown. - :param log_file: Override the default log file path. - """ - additional = {} - if mode == "reboot": - event_type = OWASPEventType.SYS_RESTART - description = "System restart initiated" - else: - event_type = OWASPEventType.SYS_SHUTDOWN - description = f"System shutdown initiated (mode={mode})" - additional["mode"] = mode - if delay: - additional["delay"] = delay - - _log_security_event( - event_type=OWASPEventType.SYS_SHUTDOWN, - level=OWASPEventLevel.INFO, - description=f"System shutdown initiated (mode={mode})", - event_params=["cloud-init"], - additional_data=additional if additional else None, - log_file=log_file, - ) + return decorator diff --git a/cloudinit/settings.py b/cloudinit/settings.py index 164979456d4..f2ca6585a0e 100644 --- a/cloudinit/settings.py +++ b/cloudinit/settings.py @@ -18,8 +18,6 @@ DEFAULT_RUN_DIR = "/run/cloud-init" -DEFAULT_SECURITY_LOG = "/var/log/cloud-init-security.log" - # What u get if no config is provided CFG_BUILTIN = { "datasource_list": [ @@ -57,7 +55,6 @@ "None", ], "def_log_file": "/var/log/cloud-init.log", - "security_log_file": DEFAULT_SECURITY_LOG, "log_cfgs": [], "syslog_fix_perms": ["syslog:adm", "root:adm", "root:wheel", "root:root"], "system_info": { diff --git a/tests/unittests/distros/test_create_users.py b/tests/unittests/distros/test_create_users.py index d1242a9b143..4ddca85ac61 100644 --- a/tests/unittests/distros/test_create_users.py +++ b/tests/unittests/distros/test_create_users.py @@ -1,5 +1,6 @@ # This file is part of cloud-init. See LICENSE file for license information. +import json from pathlib import Path from typing import List @@ -15,8 +16,6 @@ @pytest.fixture(autouse=True) def common_mocks(mocker): mocker.patch("cloudinit.distros.util.system_is_snappy", return_value=False) - mocker.patch("cloudinit.distros.sec_log_user_created") - mocker.patch("cloudinit.distros.sec_log_password_changed") def _chpasswdmock(name: str, password: str, hashed: bool = False): @@ -431,12 +430,10 @@ def test_avoid_unlock_preexisting_user_empty_password( ), ], ) - @mock.patch("cloudinit.distros.sec_log_password_changed") @mock.patch("cloudinit.distros.util.is_user", return_value=True) def test_create_passwd_existing_user( self, m_is_user, - m_sec_log_password_changed, m_subp, create_kwargs, expected, @@ -452,9 +449,13 @@ def test_create_passwd_existing_user( assert log in caplog.text assert m_subp.call_args_list == expected if "passwd" in create_kwargs: - m_sec_log_password_changed.assert_not_called() + "authn_password_change:cloud-init,clearfoo" in caplog.records[ + -1 + ].msg else: - m_sec_log_password_changed.assert_called_once_with(userid=USER) + "authn_password_change:cloud-init,clearfoo" in caplog.records[ + -1 + ].msg @mock.patch("cloudinit.distros.util.is_group") def test_group_added(self, m_is_group, m_subp, dist, mocker): @@ -502,7 +503,7 @@ def test_only_new_group_added(self, m_is_group, m_subp, dist, mocker): @mock.patch("cloudinit.distros.util.is_group") def test_snappy_only_new_group_added( - self, m_is_group, m_subp, dist, mocker + self, m_is_group, m_subp, dist, mocker, caplog ): mocker.patch( "cloudinit.distros.util.system_is_snappy", return_value=True @@ -510,7 +511,6 @@ def test_snappy_only_new_group_added( ex_groups = ["existing_group"] groups = ["group1", ex_groups[0]] m_is_group.side_effect = lambda m: m in ex_groups - m_sec_log = mocker.patch("cloudinit.distros.sec_log_user_created") dist.create_user(USER, groups=groups) expected = [ @@ -521,11 +521,8 @@ def test_snappy_only_new_group_added( mock.call(["passwd", "-l", USER]), ] assert m_subp.call_args_list == expected - m_sec_log.assert_called_once_with( - userid="cloud-init", - new_userid=USER, - attributes={"groups": ",".join(groups)}, - ) + event = json.loads(caplog.records[-1].msg) + assert event["event"] == "user_created:cloud-init,foo_user" @mock.patch("cloudinit.distros.util.is_group") def test_create_groups_with_whitespace_string( @@ -640,7 +637,6 @@ def test_explicit_sudo_false(self, m_subp, dist, caplog, mocker): mocker.patch( "cloudinit.distros.util.system_is_snappy", return_value=False ) - m_sec_log = mocker.patch("cloudinit.distros.sec_log_user_created") dist.create_user(USER, sudo=False) assert m_subp.call_args_list == [ _useradd2call([USER, "-m"]), @@ -660,11 +656,8 @@ def test_explicit_sudo_false(self, m_subp, dist, caplog, mocker): "config is deprecated in 22.2 and scheduled to be removed" " in 27.2. Use 'null' instead." ) in caplog.text - m_sec_log.assert_called_once_with( - userid="cloud-init", - new_userid=USER, - attributes=None, - ) + event = json.loads(caplog.records[-1].msg) + assert event["event"] == "user_created:cloud-init,foo_user" def test_explicit_sudo_none(self, m_subp, dist, caplog, mocker): mocker.patch( diff --git a/tests/unittests/distros/test_user_data_normalize.py b/tests/unittests/distros/test_user_data_normalize.py index c5a14ea1079..3bb2b801f24 100644 --- a/tests/unittests/distros/test_user_data_normalize.py +++ b/tests/unittests/distros/test_user_data_normalize.py @@ -1,4 +1,5 @@ # This file is part of cloud-init. See LICENSE file for license information. +import json from unittest import mock import pytest @@ -266,9 +267,8 @@ def test_users_dict(self): assert {"default": False} == users["joe"] assert {"default": False} == users["bob"] - @mock.patch("cloudinit.distros.sec_log_user_created") @mock.patch("cloudinit.subp.subp") - def test_create_snap_user(self, mock_subp, m_sec_log_user_created): + def test_create_snap_user(self, mock_subp, caplog): mock_subp.side_effect = [ ('{"username": "joe", "ssh-key-count": 1}\n', "") ] @@ -286,15 +286,11 @@ def test_create_snap_user(self, mock_subp, m_sec_log_user_created): snapcmd = ["snap", "create-user", "--sudoer", "--json", "joe@joe.com"] mock_subp.assert_called_with(snapcmd, capture=True, logstring=snapcmd) assert username == "joe" - m_sec_log_user_created.assert_called_once_with( - userid="cloud-init", - new_userid="joe", - attributes={"snapuser": True, "sudo": True}, - ) + event = json.loads(caplog.records[-1].msg) + assert "user_created:cloud-init,joe" == event["event"] - @mock.patch("cloudinit.distros.sec_log_user_created") @mock.patch("cloudinit.subp.subp") - def test_create_snap_user_known(self, mock_subp, m_sec_log_user_created): + def test_create_snap_user_known(self, mock_subp, caplog): mock_subp.side_effect = [ ('{"username": "joe", "ssh-key-count": 1}\n', "") ] @@ -319,11 +315,8 @@ def test_create_snap_user_known(self, mock_subp, m_sec_log_user_created): ] mock_subp.assert_called_with(snapcmd, capture=True, logstring=snapcmd) assert username == "joe" - m_sec_log_user_created.assert_called_once_with( - userid="cloud-init", - new_userid="joe", - attributes={"snapuser": True, "sudo": True}, - ) + event = json.loads(caplog.records[-1].msg) + assert "user_created:cloud-init,joe" == event["event"] @mock.patch("cloudinit.util.system_is_snappy") @mock.patch("cloudinit.util.is_group") diff --git a/tests/unittests/log/test_security_event_log.py b/tests/unittests/log/test_security_event_log.py index 361826fa98d..c8bf7d4c480 100644 --- a/tests/unittests/log/test_security_event_log.py +++ b/tests/unittests/log/test_security_event_log.py @@ -3,27 +3,18 @@ """Tests for cloudinit.log.security_event_log""" import json -import os import pytest -from cloudinit.log import security_event_log +from cloudinit.log import loggers, security_event_log from cloudinit.log.security_event_log import ( - APP_ID, OWASPEventLevel, OWASPEventType, sec_log_password_changed, sec_log_system_shutdown, sec_log_user_created, - sec_log_user_updated, ) -from cloudinit.settings import DEFAULT_SECURITY_LOG - - -@pytest.fixture -def security_log_file(tmp_path): - """Provide a temporary security log file path.""" - return tmp_path / "cloud-init-security-events.log" +from cloudinit.util import get_hostname class TestBuildEventString: @@ -122,186 +113,155 @@ def test_timestamp_is_iso_format(self): class TestLogSecurityEvent: """Tests for _log_security_event function.""" - def test_writes_json_to_file(self, security_log_file): + def test_writes_json_to_file(self, caplog): """Test that event is written to log file as JSON.""" - security_event_log._log_security_event( - event_type=OWASPEventType.USER_CREATED, - level=OWASPEventLevel.INFO, - description="User created successfully", - event_params=["cloud-init", "testuser"], - log_file=security_log_file, - ) - event = json.loads(security_log_file.read_text()) + with caplog.at_level(loggers.SECURITY): + security_event_log._log_security_event( + event_type=OWASPEventType.USER_CREATED, + level=OWASPEventLevel.INFO, + description="User created successfully", + event_params=["cloud-init", "testuser"], + ) + event = json.loads(caplog.records[0].msg) assert event["event"] == "user_created:cloud-init,testuser" assert event["level"] == "INFO" assert event["appid"] == "canonical.cloud_init" - def test_appends_multiple_events(self, security_log_file): + def test_appends_multiple_events(self, caplog): """Test that multiple events are appended to the log file.""" - security_event_log._log_security_event( - event_type=OWASPEventType.USER_CREATED, - level=OWASPEventLevel.INFO, - description="First user", - event_params=["cloud-init", "user1"], - log_file=security_log_file, - ) - - security_event_log._log_security_event( - event_type=OWASPEventType.USER_CREATED, - level=OWASPEventLevel.INFO, - description="Second user", - event_params=["cloud-init", "user2"], - log_file=security_log_file, - ) - - lines = security_log_file.read_text().splitlines() - - assert len(lines) == 2 - event1 = json.loads(lines[0]) - event2 = json.loads(lines[1]) + with caplog.at_level(loggers.SECURITY): + security_event_log._log_security_event( + event_type=OWASPEventType.USER_CREATED, + level=OWASPEventLevel.INFO, + description="First user", + event_params=["cloud-init", "user1"], + ) + + security_event_log._log_security_event( + event_type=OWASPEventType.USER_CREATED, + level=OWASPEventLevel.INFO, + description="Second user", + event_params=["cloud-init", "user2"], + ) + + assert len(caplog.records) == 2 + event1 = json.loads(caplog.records[0].msg) + event2 = json.loads(caplog.records[1].msg) assert "user1" in event1["event"] assert "user2" in event2["event"] - def test_uses_default_log_file_when_not_specified( - self, security_log_file, mocker - ): - """Test that default log file path is used when not specified.""" - mocker.patch( - "cloudinit.settings.DEFAULT_SECURITY_LOG", security_log_file - ) - - security_event_log._log_security_event( - event_type=OWASPEventType.USER_CREATED, - level=OWASPEventLevel.INFO, - description="Test event", - log_file=security_log_file, - ) - assert security_log_file.exists(), f"File missing {security_log_file}" - - def test_log_file_has_restricted_permissions(self, security_log_file): - """Test that log file is created with restricted permissions.""" - security_event_log._log_security_event( - event_type=OWASPEventType.USER_CREATED, - level=OWASPEventLevel.INFO, - description="Test event", - log_file=security_log_file, - ) - - file_mode = os.stat(security_log_file).st_mode & 0o777 - assert file_mode == 0o600 - class TestUserCreatedEvent: """Tests for sec_log_user_created function.""" - def test_logs_user_created_event(self, security_log_file): + @pytest.mark.parametrize("user_created", (True, False)) + def test_logs_user_created_event(self, user_created, caplog): """Test logging a user creation event.""" - sec_log_user_created( - userid="cloud-init", - new_userid="testuser", - attributes={"groups": "wheel", "shell": "/bin/bash"}, - log_file=security_log_file, - ) - - event = json.loads(security_log_file.read_text()) - - assert "user_created" in event["event"] - assert "cloud-init" in event["event"] - assert "testuser" in event["event"] - assert event["level"] == "WARN" - assert "testuser" in event["description"] - - def test_user_created_includes_attributes(self, security_log_file): - """Test that attributes are included in event.""" - sec_log_user_created( - userid="cloud-init", - new_userid="testuser", - attributes={"groups": "wheel,docker", "uid": 1001}, - log_file=security_log_file, - ) - event = json.loads(security_log_file.read_text()) + @sec_log_user_created + def user_created_test(name, **kwargs): + # Distro.create_user returns False when no new user is created. + return user_created - assert event["groups"] == "wheel,docker" - assert event["uid"] == 1001 + with caplog.at_level(loggers.SECURITY): + user_created_test( + name="testuser", + ) + if not user_created: + assert 0 == len(caplog.records) + return -class TestUserUpdatedEvent: - """Tests for sec_log_user_updated function.""" + # Create user security event happens only when user is created + event = json.loads(caplog.records[0].msg) - def test_logs_user_updated_event(self, security_log_file): - """Test logging a user update event.""" - sec_log_user_updated( - userid="cloud-init", - on_userid="existinguser", - attributes={"ssh_keys_added": True}, - log_file=security_log_file, - ) - - event = json.loads(security_log_file.read_text()) - - assert "user_updated" in event["event"] - assert "existinguser" in event["event"] - assert event["level"] == "WARN" + assert event.pop("datetime") + assert { + "appid": "canonical.cloud_init", + "event": "user_created:cloud-init,testuser", + "description": "User 'testuser' was created", + "hostname": get_hostname(), + "level": "WARN", + } == event class TestPasswordChangedEvent: """Tests for sec_log_password_changed function.""" - def test_logs_password_changed_event(self, security_log_file): + def test_logs_password_changed_event(self, caplog): """Test logging a password change event.""" - sec_log_password_changed( - userid="testuser", - log_file=security_log_file, - ) - event = json.loads(security_log_file.read_text()) + @sec_log_password_changed + def set_passwd_test(user): + pass - assert event["event"] == "authn_password_change:testuser" - assert event["level"] == "INFO" - assert "testuser" in event["description"] + with caplog.at_level(loggers.SECURITY): + set_passwd_test(user="testuser") + set_passwd_test("testuser") # Test with positional params + + expected_value = { + "appid": "canonical.cloud_init", + "event": "authn_password_change:cloud-init,testuser", + "description": "Password changed for user 'testuser'", + "hostname": get_hostname(), + "level": "INFO", + } + + for record in caplog.records: + event = json.loads(record.msg) + assert event.pop("datetime") + assert expected_value == event class TestSystemShutdownEvent: """Tests for sec_log_system_shutdown function.""" - def test_logs_system_shutdown_event(self, security_log_file): + @pytest.mark.parametrize( + "mode,delay,expected_event,expected_descr", + ( + ( + "poweroff", + "+5", + "sys_shutdown:cloud-init", + "System shutdown initiated (mode=poweroff)", + ), + ( + "reboot", + "now", + "sys_restart:cloud-init", + "System restart initiated", + ), + ), + ) + def test_logs_system_shutdown_event( + self, mode, delay, expected_event, expected_descr, caplog + ): """Test logging a system shutdown event.""" - sec_log_system_shutdown( - userid="cloud-init", - mode="poweroff", - delay="+5", - log_file=security_log_file, - ) - - event = json.loads(security_log_file.read_text()) - - assert event["event"] == "sys_shutdown:cloud-init" - assert event["level"] == "INFO" - assert event["mode"] == "poweroff" - assert event["delay"] == "+5" - - -class TestSystemRestartEvent: - """Tests for sec_log_system_shutdown with reboot mode.""" - - def test_logs_system_restart_event(self, security_log_file): - """Test logging a system restart event.""" - sec_log_system_shutdown( - userid="cloud-init", - mode="reboot", - delay="now", - log_file=security_log_file, - ) - - event = json.loads(security_log_file.read_text()) - # Note: Currently the implementation has a bug where it always logs sys_shutdown - # even for reboots, but let's test what it should be doing - assert event["event"] == "sys_shutdown:cloud-init" - assert event["level"] == "INFO" - assert event["delay"] == "now" + @sec_log_system_shutdown + def shutdown_test(mode, delay): + pass + + with caplog.at_level(loggers.SECURITY): + shutdown_test( + mode=mode, + delay=delay, + ) + + event = json.loads(caplog.records[0].msg) + assert event.pop("datetime") + expected = { + "appid": "canonical.cloud_init", + "delay": delay, + "description": expected_descr, + "event": expected_event, + "hostname": get_hostname(), + "level": "INFO", + } + if mode != "reboot": + expected["mode"] = mode + assert expected == event class TestEventTypeEnums: @@ -314,35 +274,14 @@ class TestEventTypeEnums: (OWASPEventType.SYS_SHUTDOWN, "sys_shutdown"), (OWASPEventType.SYS_RESTART, "sys_restart"), (OWASPEventType.USER_CREATED, "user_created"), - (OWASPEventType.USER_UPDATED, "user_updated"), ], ids=[ "authn_password_change", "sys_shutdown", "sys_restart", "user_created", - "user_updated", ], ) def test_event_type_values(self, event_type, expected_value): """Test event type enum values.""" assert event_type.value == expected_value - - -class TestErrorHandling: - """Tests for error handling in security event logging.""" - - def test_handles_write_permission_error(self, mocker, caplog): - """Test graceful handling of permission errors.""" - mocker.patch("builtins.open", side_effect=PermissionError("denied")) - mocker.patch("os.path.exists", return_value=True) - - # Should not raise, just log warning - security_event_log._log_security_event( - event_type=OWASPEventType.USER_CREATED, - level=OWASPEventLevel.INFO, - description="Test event", - log_file="/unwritable/path.log", - ) - - assert "Failed to write security event" in caplog.text diff --git a/tests/unittests/test_log.py b/tests/unittests/test_log.py index 4b1998fb4a0..b7895fab356 100644 --- a/tests/unittests/test_log.py +++ b/tests/unittests/test_log.py @@ -97,6 +97,13 @@ def test_trace_log_level(self, caplog): assert "TRACE" == caplog.records[0].levelname assert "trace message" in caplog.text + def test_security_log_level(self, caplog): + logger = cast(loggers.CustomLoggerType, logging.getLogger()) + logger.setLevel(logging.NOTSET) + logger.security("security message") + assert "SECURITY" == caplog.records[0].levelname + assert "security message" in caplog.text + @pytest.mark.parametrize( "expected_log_level, deprecation_info_boundary", ( @@ -165,8 +172,15 @@ def test_log_deduplication(self, caplog): assert 2 == len(caplog.records) -def test_logger_prints_to_stderr(capsys): +def test_logger_prints_to_stderr(capsys, caplog): message = "to stdout" loggers.setup_basic_logging() logging.getLogger().warning(message) assert message in capsys.readouterr().err + + +def test_logger_prints_security_as_json_lines(capsys, caplog): + message = '{"key": "value"}' + loggers.setup_basic_logging() + logging.getLogger().security(message) + assert f"{message}\n" == capsys.readouterr().err diff --git a/tests/unittests/util.py b/tests/unittests/util.py index 72573075b21..77b5eb6748f 100644 --- a/tests/unittests/util.py +++ b/tests/unittests/util.py @@ -4,6 +4,7 @@ from cloudinit import cloud, distros, helpers from cloudinit.config import Config +from cloudinit.log import security_event_log from cloudinit.net.dhcp import IscDhclient from cloudinit.sources import DataSource, DataSourceHostname from cloudinit.sources.DataSourceNone import DataSourceNone @@ -149,6 +150,7 @@ def add_user(self, name, **kwargs): def add_snap_user(self, name, **kwargs): return "snap_user" + @security_event_log.sec_log_user_created def create_user(self, name, **kwargs): return True @@ -170,6 +172,7 @@ def write_sudo_rules(self, user, rules, sudo_file=None): def create_group(self, name, members=None): pass + @security_event_log.sec_log_system_shutdown def shutdown_command(self, *, mode, delay, message): pass From 5b4eb29c6216a40a3cf360ba9a910c8f6fd45c61 Mon Sep 17 00:00:00 2001 From: Chad Smith Date: Wed, 25 Feb 2026 17:48:34 +0000 Subject: [PATCH 04/31] fix: route SECURITY logs exclusively to /var/log/cloud-init-output.log Replace LevelBasedFormatter with handler-level filters. SecurityOnlyFilter and NoSecurityFilter are applied at the handler level so SECURITY records flow only to a dedicated FileHandler on cloud-init-output.log using SECURITY_LOG_FORMAT, and are blocked from stderr and LogExporter. setup_security_logging() silently no-ops on OSError so unprivileged test environments are unaffected. Update test_logger_prints_security_as_ json_lines to assert file output and absence from stderr. --- cloudinit/log/loggers.py | 40 +++++++++++++++++++++++++++++-------- tests/unittests/test_log.py | 7 +++++-- 2 files changed, 37 insertions(+), 10 deletions(-) diff --git a/cloudinit/log/loggers.py b/cloudinit/log/loggers.py index 8a44f522681..0a646f93895 100644 --- a/cloudinit/log/loggers.py +++ b/cloudinit/log/loggers.py @@ -47,25 +47,46 @@ def security(self, *args, **kwargs): pass -class LevelBasedFormatter(logging.Formatter): - def format(self, record): - if record.levelno == SECURITY: - self._style._fmt = SECURITY_LOG_FORMAT - else: - self._style._fmt = DEFAULT_LOG_FORMAT - return super().format(record) +SECURITY_LOG_FILE = "/var/log/cloud-init-security.log" + + +class SecurityOnlyFilter(logging.Filter): + """Pass only SECURITY level records.""" + + def filter(self, record): + return record.levelno == SECURITY + + +class NoSecurityFilter(logging.Filter): + """Block SECURITY level records from non-security handlers.""" + + def filter(self, record): + return record.levelno != SECURITY def setup_basic_logging(level=logging.DEBUG, formatter=None): - formatter = formatter or LevelBasedFormatter() + formatter = formatter or logging.Formatter(DEFAULT_LOG_FORMAT) root = logging.getLogger() console = logging.StreamHandler(sys.stderr) console.setFormatter(formatter) console.setLevel(level) + console.addFilter(NoSecurityFilter()) root.addHandler(console) root.setLevel(level) +def setup_security_logging(log_file: str = SECURITY_LOG_FILE) -> None: + """Attach a FileHandler routing SECURITY records exclusively to log_file.""" + try: + handler = logging.FileHandler(log_file) + except OSError: + return + handler.setFormatter(logging.Formatter(SECURITY_LOG_FORMAT)) + handler.addFilter(SecurityOnlyFilter()) + handler.setLevel(SECURITY) + logging.getLogger().addHandler(handler) + + def flush_loggers(root): if not root: return @@ -232,7 +253,10 @@ def configure_root_logger(): # add handler only to the root logger handler = LogExporter() handler.setLevel(logging.WARN) + handler.addFilter(NoSecurityFilter()) logging.getLogger().addHandler(handler) + setup_security_logging() + # LogRecord allows us to report more useful information than __init__.py logging.setLogRecordFactory(CloudInitLogRecord) diff --git a/tests/unittests/test_log.py b/tests/unittests/test_log.py index b7895fab356..3ad517ec710 100644 --- a/tests/unittests/test_log.py +++ b/tests/unittests/test_log.py @@ -179,8 +179,11 @@ def test_logger_prints_to_stderr(capsys, caplog): assert message in capsys.readouterr().err -def test_logger_prints_security_as_json_lines(capsys, caplog): +def test_logger_prints_security_as_json_lines(tmp_path, capsys, caplog): + log_file = tmp_path / "cloud-init-output.log" message = '{"key": "value"}' loggers.setup_basic_logging() + loggers.setup_security_logging(log_file=str(log_file)) logging.getLogger().security(message) - assert f"{message}\n" == capsys.readouterr().err + assert log_file.read_text() == f"{message}\n" + assert message not in capsys.readouterr().err From 65bf5b0a64a1805763de221e198b3f7fd8cb5b73 Mon Sep 17 00:00:00 2001 From: Chad Smith Date: Wed, 25 Feb 2026 18:01:29 +0000 Subject: [PATCH 05/31] chore: revert unnecessary changes to cloudinit.util --- cloudinit/util.py | 32 +++++++++------------ doc/rtd/explanation/instancedata.rst | 1 - doc/rtd/reference/base_config_reference.rst | 6 ---- tests/unittests/test_util.py | 17 ++--------- 4 files changed, 15 insertions(+), 41 deletions(-) diff --git a/cloudinit/util.py b/cloudinit/util.py index 2bc5c092f78..cac5926f10f 100644 --- a/cloudinit/util.py +++ b/cloudinit/util.py @@ -1777,10 +1777,9 @@ def get_config_logfiles(cfg: Dict[str, Any]): rotated_logs = [] if not cfg or not isinstance(cfg, dict): return logs - - for log_cfg_key in ("def_log_file", "security_log_file"): - if cfg.get(log_cfg_key): - logs.append(cfg[log_cfg_key]) + default_log = cfg.get("def_log_file") + if default_log: + logs.append(default_log) for fmt in get_output_cfg(cfg, None): if not fmt: continue @@ -2151,10 +2150,8 @@ def uptime(): return uptime_str -def append_file(path, content, disable_logging: bool = False): - write_file( - path, content, omode="ab", mode=None, disable_logging=disable_logging - ) +def append_file(path, content): + write_file(path, content, omode="ab", mode=None) def ensure_file( @@ -2251,7 +2248,6 @@ def write_file( ensure_dir_exists: bool = True, user=None, group=None, - disable_logging: bool = False, ): """ Writes a file with the given content and sets the file mode as specified. @@ -2268,7 +2264,6 @@ def write_file( the file. @param user: The user to set on the file. @param group: The group to set on the file. - @param disable_logging: Whether to avoid logging this operation. """ if preserve_mode: @@ -2289,15 +2284,14 @@ def write_file( mode_r = "%o" % mode except TypeError: mode_r = "%r" % mode - if not disable_logging: - LOG.debug( - "Writing to %s - %s: [%s] %s %s", - filename, - omode, - mode_r, - len(content), - write_type, - ) + LOG.debug( + "Writing to %s - %s: [%s] %s %s", + filename, + omode, + mode_r, + len(content), + write_type, + ) with SeLinuxGuard(path=filename): with open(filename, omode) as fh: fh.write(content) diff --git a/doc/rtd/explanation/instancedata.rst b/doc/rtd/explanation/instancedata.rst index 19362cc35c5..5d4a45b43b2 100644 --- a/doc/rtd/explanation/instancedata.rst +++ b/doc/rtd/explanation/instancedata.rst @@ -481,7 +481,6 @@ Below is an example of sensitive ``instance-data`` on an EC2 instance: "all": "| tee -a /var/log/cloud-init-output.log" }, "preserve_hostname": false, - "security_log_file": "/var/log/cloud-init-security.log", "syslog_fix_perms": [ "syslog:adm", "root:adm", diff --git a/doc/rtd/reference/base_config_reference.rst b/doc/rtd/reference/base_config_reference.rst index c454690dacb..8001da77e97 100644 --- a/doc/rtd/reference/base_config_reference.rst +++ b/doc/rtd/reference/base_config_reference.rst @@ -277,12 +277,6 @@ Only used in conjunction with ``syslog_fix_perms``. Specifies the filename to be used for setting permissions. Defaults to :file:`/var/log/cloud-init.log`. -``security_log_file`` -^^^^^^^^^^^^^^^^^^^^^ - -Specifies the filename to be used for emitting OSWAP security logs. Defaults -to :file:`/var/log/cloud-init-security.log`. - Other keys ---------- diff --git a/tests/unittests/test_util.py b/tests/unittests/test_util.py index 30e04ccee9e..90206489987 100644 --- a/tests/unittests/test_util.py +++ b/tests/unittests/test_util.py @@ -2262,21 +2262,8 @@ def test_empty_cfg_returns_empty_list(self): assert [] == util.get_config_logfiles(None) assert [] == util.get_config_logfiles({}) - @pytest.mark.parametrize( - "cfg,expected_logs", - ( - ({"def_log_file": "/my.log"}, ["/my.log"]), - ( - { - "def_log_file": "/my.log", - "security_log_file": "/my_sec.log", - }, - ["/my.log", "/my_sec.log"], - ), - ), - ) - def test_default_log_files_present(self, cfg, expected_logs): - """get_config_logfiles reports def_log_file and security_log_file.""" + def test_default_log_file_present(self): + """When default_log_file is set get_config_logfiles finds it.""" assert ["/my.log"] == util.get_config_logfiles( {"def_log_file": "/my.log"} ) From e1efd727011849d3272d81002f8584ac8210f466 Mon Sep 17 00:00:00 2001 From: Chad Smith Date: Sun, 1 Mar 2026 14:10:38 +0000 Subject: [PATCH 06/31] feat: add _get_host_ip helper to report host_ip in security logs Use netdev_info to discover any interface with a global scope IP address. If no IPv4 address is present, return IPv6. If no network devices are up or no global addresses are present, avoid adding host_ip to event logs. Additionally, add "type": "security" to all events. --- cloudinit/log/loggers.py | 4 +- cloudinit/log/security_event_log.py | 32 +++ .../modules/test_combined.py | 11 + tests/unittests/cmd/test_clean.py | 5 +- .../config/test_cc_power_state_change.py | 6 + tests/unittests/distros/test_create_users.py | 3 + .../distros/test_user_data_normalize.py | 10 +- .../unittests/log/test_security_event_log.py | 238 +++++++++++++++--- 8 files changed, 270 insertions(+), 39 deletions(-) diff --git a/cloudinit/log/loggers.py b/cloudinit/log/loggers.py index 0a646f93895..d5cb491280d 100644 --- a/cloudinit/log/loggers.py +++ b/cloudinit/log/loggers.py @@ -23,7 +23,7 @@ DEFAULT_LOG_FORMAT = "%(asctime)s - %(filename)s[%(levelname)s]: %(message)s" SECURITY_LOG_FORMAT = "%(message)s" -SECURITY = 36 +SECURITY = 25 # Treat lower than WARNING but higher than INFO DEPRECATED = 35 TRACE = logging.DEBUG - 5 @@ -76,7 +76,7 @@ def setup_basic_logging(level=logging.DEBUG, formatter=None): def setup_security_logging(log_file: str = SECURITY_LOG_FILE) -> None: - """Attach a FileHandler routing SECURITY records exclusively to log_file.""" + """Attach a FileHandler routing SECURITY records to log_file.""" try: handler = logging.FileHandler(log_file) except OSError: diff --git a/cloudinit/log/security_event_log.py b/cloudinit/log/security_event_log.py index 5c115de9df4..dec74520808 100644 --- a/cloudinit/log/security_event_log.py +++ b/cloudinit/log/security_event_log.py @@ -10,9 +10,11 @@ Security events are logged in JSON Lines format with standardized fields: - datetime: ISO 8601 timestamp with UTC offset - appid: Application identifier (canonical.cloud_init) +- type: "security" - event: Event type with optional parameters (e.g., user_created:root,ubuntu) - level: INFO, WARN, or CRITICAL - description: Human-readable summary +- host_ip: Optional IP address, included when network information is available. """ import datetime @@ -24,6 +26,7 @@ from cloudinit import util from cloudinit.log import loggers +from cloudinit.netinfo import netdev_info LOG = logging.getLogger(__name__) @@ -59,6 +62,31 @@ class OWASPEventType(Enum): USER_UPDATED = "user_updated" +def _get_host_ip() -> Optional[str]: + """Return the first global IP on an active interface. + + Prefers IPv4; falls back to IPv6 when no global IPv4 is available. + IPv6 addresses are returned without their prefix-length suffix. + """ + try: + first_ipv6: Optional[str] = None + for iface, info in netdev_info().items(): + if iface == "lo" or not info.get("up"): + continue + for addr in info.get("ipv4", []): + if addr.get("scope") == "global" and addr.get("ip"): + return addr["ip"] + if first_ipv6 is None: + for addr in info.get("ipv6", []): + if addr.get("scope6") == "global" and addr.get("ip"): + first_ipv6 = addr["ip"].split("/")[0] + break + return first_ipv6 + except Exception: + pass + return None + + def _build_event_string( event_type: OWASPEventType, params: Optional[List[str]] = None ) -> str: @@ -98,11 +126,15 @@ def _build_security_event( event = { "datetime": datetime.datetime.now(datetime.timezone.utc).isoformat(), "appid": APP_ID, + "type": "security", "event": _build_event_string(event_type, event_params), "level": level.value, "description": description, "hostname": util.get_hostname(), } + host_ip = _get_host_ip() + if host_ip: + event["host_ip"] = host_ip if additional_data: # Merge additional data but don't overwrite core fields diff --git a/tests/integration_tests/modules/test_combined.py b/tests/integration_tests/modules/test_combined.py index 857023780d1..2a8e526b40e 100644 --- a/tests/integration_tests/modules/test_combined.py +++ b/tests/integration_tests/modules/test_combined.py @@ -219,6 +219,17 @@ def test_rsyslog(self, class_client: IntegrationInstance): "/var/spool/rsyslog/cloudinit.log" ) + def test_security_logs(self, class_client: IntegrationInstance): + """Test security logs are set in /var/log/cloud-init-security.log.""" + client = class_client + security_logs = [ + json.loads(line) + for line in client.read_from_file( + "/var/log/cloud-init-security.log" + ).splitlines() + ] + assert len(security_logs) == 1 + def test_runcmd(self, class_client: IntegrationInstance): """Test runcmd works as expected""" client = class_client diff --git a/tests/unittests/cmd/test_clean.py b/tests/unittests/cmd/test_clean.py index 21dd5752757..d1623f95b27 100644 --- a/tests/unittests/cmd/test_clean.py +++ b/tests/unittests/cmd/test_clean.py @@ -479,7 +479,10 @@ def test_remove_artifacts_returns_one_on_errors( == err ) - def test_handle_clean_args_reboots(self, init_class): + @mock.patch( + "cloudinit.log.security_event_log._get_host_ip", return_value=None + ) + def test_handle_clean_args_reboots(self, _get_host_ip, init_class): """handle_clean_args_reboots when reboot arg is provided.""" called_cmds = [] diff --git a/tests/unittests/config/test_cc_power_state_change.py b/tests/unittests/config/test_cc_power_state_change.py index 37901baaab7..9de8f26031b 100644 --- a/tests/unittests/config/test_cc_power_state_change.py +++ b/tests/unittests/config/test_cc_power_state_change.py @@ -23,6 +23,12 @@ def dist(): class TestLoadPowerState: + @pytest.fixture(autouse=True) + def common_mocks(self, mocker): + mocker.patch( + "cloudinit.log.security_event_log._get_host_ip", return_value=None + ) + def test_no_config(self, dist): # completely empty config should mean do nothing (cmd, _timeout, _condition) = psc.load_power_state({}, dist) diff --git a/tests/unittests/distros/test_create_users.py b/tests/unittests/distros/test_create_users.py index 4ddca85ac61..56ab88cb12a 100644 --- a/tests/unittests/distros/test_create_users.py +++ b/tests/unittests/distros/test_create_users.py @@ -16,6 +16,9 @@ @pytest.fixture(autouse=True) def common_mocks(mocker): mocker.patch("cloudinit.distros.util.system_is_snappy", return_value=False) + mocker.patch( + "cloudinit.log.security_event_log._get_host_ip", return_value=None + ) def _chpasswdmock(name: str, password: str, hashed: bool = False): diff --git a/tests/unittests/distros/test_user_data_normalize.py b/tests/unittests/distros/test_user_data_normalize.py index 3bb2b801f24..9155b4c44d3 100644 --- a/tests/unittests/distros/test_user_data_normalize.py +++ b/tests/unittests/distros/test_user_data_normalize.py @@ -267,8 +267,11 @@ def test_users_dict(self): assert {"default": False} == users["joe"] assert {"default": False} == users["bob"] + @mock.patch( + "cloudinit.log.security_event_log._get_host_ip", return_value=None + ) @mock.patch("cloudinit.subp.subp") - def test_create_snap_user(self, mock_subp, caplog): + def test_create_snap_user(self, mock_subp, _get_host_ip, caplog): mock_subp.side_effect = [ ('{"username": "joe", "ssh-key-count": 1}\n', "") ] @@ -289,8 +292,11 @@ def test_create_snap_user(self, mock_subp, caplog): event = json.loads(caplog.records[-1].msg) assert "user_created:cloud-init,joe" == event["event"] + @mock.patch( + "cloudinit.log.security_event_log._get_host_ip", return_value=None + ) @mock.patch("cloudinit.subp.subp") - def test_create_snap_user_known(self, mock_subp, caplog): + def test_create_snap_user_known(self, mock_subp, _get_host_ip, caplog): mock_subp.side_effect = [ ('{"username": "joe", "ssh-key-count": 1}\n', "") ] diff --git a/tests/unittests/log/test_security_event_log.py b/tests/unittests/log/test_security_event_log.py index c8bf7d4c480..400ca7d2117 100644 --- a/tests/unittests/log/test_security_event_log.py +++ b/tests/unittests/log/test_security_event_log.py @@ -16,6 +16,16 @@ ) from cloudinit.util import get_hostname +MPATH = "cloudinit.log.security_event_log." + + +@pytest.fixture +def host_ip(mocker): + mocker.patch.object( + security_event_log, "_get_host_ip", return_value="10.42.42.42" + ) + yield + class TestBuildEventString: """Tests for _build_event_string function.""" @@ -23,29 +33,31 @@ class TestBuildEventString: @pytest.mark.parametrize( "event_type,params,expected", [ - (OWASPEventType.SYS_SHUTDOWN, None, "sys_shutdown"), - ( + pytest.param( + OWASPEventType.SYS_SHUTDOWN, + None, + "sys_shutdown", + id="no_params", + ), + pytest.param( OWASPEventType.AUTHN_PASSWORD_CHANGE, ["testuser"], "authn_password_change:testuser", + id="single_param", ), - ( + pytest.param( OWASPEventType.USER_CREATED, ["cloud-init", "newuser", "groups=wheel"], "user_created:cloud-init,newuser,groups=wheel", + id="multiple_params", ), - ( + pytest.param( OWASPEventType.USER_CREATED, ["cloud-init", None, "newuser"], "user_created:cloud-init,newuser", + id="filters_none_params", ), ], - ids=[ - "no_params", - "single_param", - "multiple_params", - "filters_none_params", - ], ) def test_event_string_formatting(self, event_type, params, expected): """Test event string formatting with various parameter combinations.""" @@ -56,7 +68,7 @@ def test_event_string_formatting(self, event_type, params, expected): class TestBuildSecurityEvent: """Tests for _build_security_event function.""" - def test_event_contains_required_owasp_fields(self): + def test_event_contains_required_owasp_fields(self, host_ip): """Test that built event contains all required OWASP fields.""" event = security_event_log._build_security_event( event_type=OWASPEventType.USER_CREATED, @@ -72,7 +84,7 @@ def test_event_contains_required_owasp_fields(self): assert event["description"] == "Test event" assert "hostname" in event - def test_event_with_additional_data(self): + def test_event_with_additional_data(self, host_ip): """Test event includes additional data when provided.""" event = security_event_log._build_security_event( event_type=OWASPEventType.USER_CREATED, @@ -84,7 +96,7 @@ def test_event_with_additional_data(self): assert event["groups"] == "wheel" assert event["shell"] == "/bin/bash" - def test_additional_data_does_not_overwrite_core_fields(self): + def test_additional_data_does_not_overwrite_core_fields(self, host_ip): """Test that additional data cannot overwrite core fields.""" event = security_event_log._build_security_event( event_type=OWASPEventType.USER_CREATED, @@ -96,7 +108,7 @@ def test_additional_data_does_not_overwrite_core_fields(self): assert event["appid"] == "canonical.cloud_init" assert event["level"] == "INFO" - def test_timestamp_is_iso_format(self): + def test_timestamp_is_iso_format(self, host_ip): """Test that datetime is in ISO 8601 format.""" event = security_event_log._build_security_event( event_type=OWASPEventType.USER_CREATED, @@ -113,7 +125,7 @@ def test_timestamp_is_iso_format(self): class TestLogSecurityEvent: """Tests for _log_security_event function.""" - def test_writes_json_to_file(self, caplog): + def test_writes_json_to_file(self, host_ip, caplog): """Test that event is written to log file as JSON.""" with caplog.at_level(loggers.SECURITY): security_event_log._log_security_event( @@ -128,7 +140,7 @@ def test_writes_json_to_file(self, caplog): assert event["level"] == "INFO" assert event["appid"] == "canonical.cloud_init" - def test_appends_multiple_events(self, caplog): + def test_appends_multiple_events(self, host_ip, caplog): """Test that multiple events are appended to the log file.""" with caplog.at_level(loggers.SECURITY): security_event_log._log_security_event( @@ -155,8 +167,14 @@ def test_appends_multiple_events(self, caplog): class TestUserCreatedEvent: """Tests for sec_log_user_created function.""" - @pytest.mark.parametrize("user_created", (True, False)) - def test_logs_user_created_event(self, user_created, caplog): + @pytest.mark.parametrize( + "user_created", + [ + pytest.param(True, id="user_created_logs_security_event"), + pytest.param(False, id="user_not_created_skips_logging"), + ], + ) + def test_logs_user_created_event(self, user_created, host_ip, caplog): """Test logging a user creation event.""" @sec_log_user_created @@ -181,15 +199,17 @@ def user_created_test(name, **kwargs): "appid": "canonical.cloud_init", "event": "user_created:cloud-init,testuser", "description": "User 'testuser' was created", + "host_ip": "10.42.42.42", "hostname": get_hostname(), "level": "WARN", + "type": "security", } == event class TestPasswordChangedEvent: """Tests for sec_log_password_changed function.""" - def test_logs_password_changed_event(self, caplog): + def test_logs_password_changed_event(self, host_ip, caplog): """Test logging a password change event.""" @sec_log_password_changed @@ -204,8 +224,10 @@ def set_passwd_test(user): "appid": "canonical.cloud_init", "event": "authn_password_change:cloud-init,testuser", "description": "Password changed for user 'testuser'", + "host_ip": "10.42.42.42", "hostname": get_hostname(), "level": "INFO", + "type": "security", } for record in caplog.records: @@ -219,23 +241,25 @@ class TestSystemShutdownEvent: @pytest.mark.parametrize( "mode,delay,expected_event,expected_descr", - ( - ( + [ + pytest.param( "poweroff", "+5", "sys_shutdown:cloud-init", "System shutdown initiated (mode=poweroff)", + id="poweroff_with_delay", ), - ( + pytest.param( "reboot", "now", "sys_restart:cloud-init", "System restart initiated", + id="reboot_immediate", ), - ), + ], ) def test_logs_system_shutdown_event( - self, mode, delay, expected_event, expected_descr, caplog + self, mode, delay, expected_event, expected_descr, host_ip, caplog ): """Test logging a system shutdown event.""" @@ -256,30 +280,176 @@ def shutdown_test(mode, delay): "delay": delay, "description": expected_descr, "event": expected_event, + "host_ip": "10.42.42.42", "hostname": get_hostname(), "level": "INFO", + "type": "security", } if mode != "reboot": expected["mode"] = mode assert expected == event +class TestGetHostIp: + """Tests for _get_host_ip IPv4/IPv6 address resolution.""" + + @pytest.mark.parametrize( + "netdev_response,expected_ip", + [ + pytest.param( + { + "eth0": { + "up": True, + "ipv4": [{"ip": "10.0.0.1", "scope": "global"}], + "ipv6": [], + } + }, + "10.0.0.1", + id="global_ipv4", + ), + pytest.param( + { + "eth0": { + "up": True, + "ipv4": [], + "ipv6": [ + {"ip": "fd42::1/64", "scope6": "global"}, + {"ip": "fe80::1/64", "scope6": "link"}, + ], + } + }, + "fd42::1", + id="fallback_to_global_ipv6", + ), + pytest.param( + { + "eth0": { + "up": True, + "ipv4": [], + "ipv6": [ + { + "ip": "fd42:baa2:3dd:17a::1/64", + "scope6": "global", + } + ], + } + }, + "fd42:baa2:3dd:17a::1", + id="ipv6_prefix_stripped", + ), + pytest.param( + { + "eth0": { + "up": True, + "ipv4": [{"ip": "10.0.0.1", "scope": "global"}], + "ipv6": [{"ip": "fd42::1/64", "scope6": "global"}], + } + }, + "10.0.0.1", + id="prefers_ipv4_over_ipv6", + ), + pytest.param( + { + "lo": { + "up": True, + "ipv4": [{"ip": "127.0.0.1", "scope": "global"}], + "ipv6": [{"ip": "::1/128", "scope6": "global"}], + }, + "eth0": { + "up": True, + "ipv4": [], + "ipv6": [{"ip": "fd42::1/64", "scope6": "global"}], + }, + }, + "fd42::1", + id="skips_loopback", + ), + pytest.param( + { + "eth0": { + "up": False, + "ipv4": [{"ip": "10.0.0.1", "scope": "global"}], + "ipv6": [{"ip": "fd42::1/64", "scope6": "global"}], + } + }, + None, + id="skips_down_interfaces", + ), + pytest.param( + { + "eth0": { + "up": True, + "ipv4": [], + "ipv6": [{"ip": "fe80::1/64", "scope6": "link"}], + } + }, + None, + id="ignores_link_local_ipv6", + ), + pytest.param( + Exception("network unavailable"), + None, + id="exception_returns_none", + ), + ], + ) + def test_get_host_ip(self, mocker, netdev_response, expected_ip): + """Test _get_host_ip returns the correct IP address or None.""" + if isinstance(netdev_response, Exception): + mocker.patch(MPATH + "netdev_info", side_effect=netdev_response) + else: + mocker.patch(MPATH + "netdev_info", return_value=netdev_response) + assert security_event_log._get_host_ip() == expected_ip + + +class TestHostIpInSecurityEvent: + """Tests that host_ip is correctly populated in logged security events.""" + + @pytest.mark.parametrize( + "host_ip", + [ + pytest.param("10.0.0.1", id="ipv4"), + pytest.param("fd42:baa2:3dd:17a:216:3eff:fe16:db54", id="ipv6"), + pytest.param(None, id="no_network"), + ], + ) + def test_event_logs_host_ip(self, host_ip, mocker, caplog): + """Security event records host_ip returned by _get_host_ip.""" + mocker.patch.object( + security_event_log, "_get_host_ip", return_value=host_ip + ) + with caplog.at_level(loggers.SECURITY): + security_event_log._log_security_event( + event_type=OWASPEventType.USER_CREATED, + level=OWASPEventLevel.INFO, + description="test", + ) + if host_ip is None: + assert "host_ip" not in json.loads(caplog.records[0].msg) + else: + assert json.loads(caplog.records[0].msg)["host_ip"] == host_ip + + class TestEventTypeEnums: """Tests for event type enum values.""" @pytest.mark.parametrize( "event_type,expected_value", [ - (OWASPEventType.AUTHN_PASSWORD_CHANGE, "authn_password_change"), - (OWASPEventType.SYS_SHUTDOWN, "sys_shutdown"), - (OWASPEventType.SYS_RESTART, "sys_restart"), - (OWASPEventType.USER_CREATED, "user_created"), - ], - ids=[ - "authn_password_change", - "sys_shutdown", - "sys_restart", - "user_created", + pytest.param( + OWASPEventType.AUTHN_PASSWORD_CHANGE, + "authn_password_change", + id="authn_password_change", + ), + pytest.param( + OWASPEventType.SYS_SHUTDOWN, "sys_shutdown", id="sys_shutdown" + ), + pytest.param( + OWASPEventType.SYS_RESTART, "sys_restart", id="sys_restart" + ), + pytest.param( + OWASPEventType.USER_CREATED, "user_created", id="user_created" + ), ], ) def test_event_type_values(self, event_type, expected_value): From 1a569721237d10a1b1418e0776ec5a2f6ab76463 Mon Sep 17 00:00:00 2001 From: Chad Smith Date: Mon, 2 Mar 2026 09:49:41 -0700 Subject: [PATCH 07/31] fix: security_event_log setup should only be added when absent from logger --- cloudinit/log/loggers.py | 19 +++++++++++++------ tests/unittests/test_log.py | 5 +++-- 2 files changed, 16 insertions(+), 8 deletions(-) diff --git a/cloudinit/log/loggers.py b/cloudinit/log/loggers.py index d5cb491280d..13754fee290 100644 --- a/cloudinit/log/loggers.py +++ b/cloudinit/log/loggers.py @@ -23,7 +23,7 @@ DEFAULT_LOG_FORMAT = "%(asctime)s - %(filename)s[%(levelname)s]: %(message)s" SECURITY_LOG_FORMAT = "%(message)s" -SECURITY = 25 # Treat lower than WARNING but higher than INFO +SECURITY = logging.WARNING - 5 DEPRECATED = 35 TRACE = logging.DEBUG - 5 @@ -75,8 +75,14 @@ def setup_basic_logging(level=logging.DEBUG, formatter=None): root.setLevel(level) -def setup_security_logging(log_file: str = SECURITY_LOG_FILE) -> None: - """Attach a FileHandler routing SECURITY records to log_file.""" +def setup_security_logging( + root: logging.Logger, log_file: str = SECURITY_LOG_FILE +) -> None: + """Attach a FileHandler routing SECURITY records to log_file if absent.""" + for h in root.handlers: + if isinstance(h, logging.FileHandler) and h.baseFilename == log_file: + return # handler already attached + try: handler = logging.FileHandler(log_file) except OSError: @@ -159,6 +165,7 @@ def setup_logging(cfg=None): # Attempt to load its config. logging.config.fileConfig(log_cfg) + setup_security_logging(root_logger) # Configure warning exporter after loading logging configuration root_logger.addHandler(exporter) @@ -254,9 +261,9 @@ def configure_root_logger(): handler = LogExporter() handler.setLevel(logging.WARN) handler.addFilter(NoSecurityFilter()) - logging.getLogger().addHandler(handler) - - setup_security_logging() + root_logger = logging.getLogger() + root_logger.addHandler(handler) + setup_security_logging(root_logger) # LogRecord allows us to report more useful information than __init__.py logging.setLogRecordFactory(CloudInitLogRecord) diff --git a/tests/unittests/test_log.py b/tests/unittests/test_log.py index 3ad517ec710..5e4d0f607bb 100644 --- a/tests/unittests/test_log.py +++ b/tests/unittests/test_log.py @@ -183,7 +183,8 @@ def test_logger_prints_security_as_json_lines(tmp_path, capsys, caplog): log_file = tmp_path / "cloud-init-output.log" message = '{"key": "value"}' loggers.setup_basic_logging() - loggers.setup_security_logging(log_file=str(log_file)) - logging.getLogger().security(message) + root = logging.getLogger() + loggers.setup_security_logging(root=root, log_file=str(log_file)) + root.security(message) assert log_file.read_text() == f"{message}\n" assert message not in capsys.readouterr().err From 46d59b5014badc855cc9d221b152c66e65b984b9 Mon Sep 17 00:00:00 2001 From: Chad Smith Date: Mon, 2 Mar 2026 12:08:39 -0700 Subject: [PATCH 08/31] feat: sec log groups, sudo and doas --- cloudinit/log/security_event_log.py | 15 ++++++-- .../unittests/log/test_security_event_log.py | 34 ++++++++++++++----- 2 files changed, 39 insertions(+), 10 deletions(-) diff --git a/cloudinit/log/security_event_log.py b/cloudinit/log/security_event_log.py index dec74520808..08f14fdd88d 100644 --- a/cloudinit/log/security_event_log.py +++ b/cloudinit/log/security_event_log.py @@ -173,7 +173,7 @@ def _log_security_event( def sec_log_user_created(func): """ - A decorator to log a user creation event and priviledged attributes. + A decorator to log a user creation event and group attributes. :param userid: The user/process that initiated the action. :param new_userid: The username of the newly created user. @@ -188,13 +188,24 @@ def decorator(*args, **kwargs): "sec_log_user_created requires positional param name or kwarg" ) params = ["cloud-init", new_userid] + groups_msg = "" + groups_suffix = "" + groups = kwargs.get("groups", []) + for priveledge in ("sudo", "doas"): + if kwargs.get(priveledge) is True: + groups.append(priveledge) + if groups: + groups_suffix = ",".join(groups) + groups_msg = f" in groups: {groups_suffix}" + params.append(f"groups:{groups_suffix}") response = func(*args, **kwargs) if response: + # User creation operation was performed _log_security_event( event_type=OWASPEventType.USER_CREATED, level=OWASPEventLevel.WARN, - description=f"User '{new_userid}' was created", + description=f"User '{new_userid}' was created{groups_msg}", event_params=params, ) return response diff --git a/tests/unittests/log/test_security_event_log.py b/tests/unittests/log/test_security_event_log.py index 400ca7d2117..4694e785ff6 100644 --- a/tests/unittests/log/test_security_event_log.py +++ b/tests/unittests/log/test_security_event_log.py @@ -47,8 +47,8 @@ class TestBuildEventString: ), pytest.param( OWASPEventType.USER_CREATED, - ["cloud-init", "newuser", "groups=wheel"], - "user_created:cloud-init,newuser,groups=wheel", + ["cloud-init", "newuser", "groups:wheel"], + "user_created:cloud-init,newuser,groups:wheel", id="multiple_params", ), pytest.param( @@ -168,13 +168,30 @@ class TestUserCreatedEvent: """Tests for sec_log_user_created function.""" @pytest.mark.parametrize( - "user_created", + "user_created,uc_kwargs,event_id,description", [ - pytest.param(True, id="user_created_logs_security_event"), - pytest.param(False, id="user_not_created_skips_logging"), + pytest.param( + True, + {}, + "user_created:cloud-init,testuser", + "User 'testuser' was created", + id="user_created_logs_event", + ), + pytest.param( + True, + {"groups": ["grp1", "grp2"]}, + "user_created:cloud-init,testuser,groups:grp1,grp2", + "User 'testuser' was created in groups: grp1,grp2", + id="user_created_with_groups_logs_event", + ), + pytest.param( + False, {}, None, None, id="user_not_created_skips_logging" + ), ], ) - def test_logs_user_created_event(self, user_created, host_ip, caplog): + def test_logs_user_created_event( + self, user_created, uc_kwargs, event_id, description, host_ip, caplog + ): """Test logging a user creation event.""" @sec_log_user_created @@ -185,6 +202,7 @@ def user_created_test(name, **kwargs): with caplog.at_level(loggers.SECURITY): user_created_test( name="testuser", + **uc_kwargs, ) if not user_created: @@ -197,8 +215,8 @@ def user_created_test(name, **kwargs): assert event.pop("datetime") assert { "appid": "canonical.cloud_init", - "event": "user_created:cloud-init,testuser", - "description": "User 'testuser' was created", + "event": event_id, + "description": description, "host_ip": "10.42.42.42", "hostname": get_hostname(), "level": "WARN", From 9a1b5892ac6dc6ec837ebd1a26058497a3a73829 Mon Sep 17 00:00:00 2001 From: Chad Smith Date: Mon, 2 Mar 2026 12:13:13 -0700 Subject: [PATCH 09/31] feat: sec log groups, sudo and doas --- cloudinit/log/security_event_log.py | 22 +++++---- doc/rtd/reference/cli.rst | 1 + doc/rtd/reference/user_files.rst | 3 ++ .../modules/test_combined.py | 47 ++++++++++++++++++- tests/unittests/distros/test_create_users.py | 6 ++- .../unittests/log/test_security_event_log.py | 26 +++++++--- 6 files changed, 86 insertions(+), 19 deletions(-) diff --git a/cloudinit/log/security_event_log.py b/cloudinit/log/security_event_log.py index 08f14fdd88d..5809819b17b 100644 --- a/cloudinit/log/security_event_log.py +++ b/cloudinit/log/security_event_log.py @@ -9,7 +9,7 @@ Security events are logged in JSON Lines format with standardized fields: - datetime: ISO 8601 timestamp with UTC offset -- appid: Application identifier (canonical.cloud_init) +- appid: Application identifier (canonical.cloud-init) - type: "security" - event: Event type with optional parameters (e.g., user_created:root,ubuntu) - level: INFO, WARN, or CRITICAL @@ -31,7 +31,7 @@ LOG = logging.getLogger(__name__) # Hard-coded application identifier per spec -APP_ID = "canonical.cloud_init" +APP_ID = "canonical.cloud-init" class OWASPEventLevel(Enum): @@ -189,13 +189,17 @@ def decorator(*args, **kwargs): ) params = ["cloud-init", new_userid] groups_msg = "" - groups_suffix = "" - groups = kwargs.get("groups", []) - for priveledge in ("sudo", "doas"): - if kwargs.get(priveledge) is True: - groups.append(priveledge) - if groups: - groups_suffix = ",".join(groups) + groups_suffix = kwargs.get("groups", "") + if groups_suffix: + if isinstance(groups_suffix, (dict, list)): + groups_suffix = ",".join(groups_suffix) + elif isinstance(groups_suffix, list): + groups_suffix = ",".join(groups_suffix) + for perms in ("sudo", "doas"): + if kwargs.get(perms) is True: + groups_suffix += f",{perms}" + if groups_suffix: + groups_suffix = groups_suffix.strip(",") groups_msg = f" in groups: {groups_suffix}" params.append(f"groups:{groups_suffix}") diff --git a/doc/rtd/reference/cli.rst b/doc/rtd/reference/cli.rst index cefb89ab2e7..106acd4d36f 100644 --- a/doc/rtd/reference/cli.rst +++ b/doc/rtd/reference/cli.rst @@ -85,6 +85,7 @@ Logs collected include: * :file:`/var/log/cloud-init.log` * :file:`/var/log/cloud-init-output.log` +* :file:`/var/log/cloud-init-security.log` * :file:`/run/cloud-init` * :file:`/var/lib/cloud/instance/user-data.txt` * ``cloud-init`` package version diff --git a/doc/rtd/reference/user_files.rst b/doc/rtd/reference/user_files.rst index ab1b951f9d4..c55408c2576 100644 --- a/doc/rtd/reference/user_files.rst +++ b/doc/rtd/reference/user_files.rst @@ -14,6 +14,9 @@ Log files - :file:`/var/log/cloud-init.log`: The primary log file. Verbose, but useful. - :file:`/var/log/cloud-init-output.log`: Captures the output from each stage. Output from user scripts goes here. +- :file:`/var/log/cloud-init-security.log`: This file logs OWASP security + events as JSON lines format implementing OWASP events including user creation + and update, password modification and system power events. Logs are appended to the files in :file:`/var/log`: files may contain logs from multiple boots. diff --git a/tests/integration_tests/modules/test_combined.py b/tests/integration_tests/modules/test_combined.py index 2a8e526b40e..ced169265ce 100644 --- a/tests/integration_tests/modules/test_combined.py +++ b/tests/integration_tests/modules/test_combined.py @@ -26,7 +26,12 @@ OS_IMAGE_TYPE, PLATFORM, ) -from tests.integration_tests.releases import CURRENT_RELEASE, IS_UBUNTU, NOBLE +from tests.integration_tests.releases import ( + CURRENT_RELEASE, + IS_UBUNTU, + JAMMY, + NOBLE, +) from tests.integration_tests.util import ( get_feature_flag_value, get_inactive_modules, @@ -228,7 +233,45 @@ def test_security_logs(self, class_client: IntegrationInstance): "/var/log/cloud-init-security.log" ).splitlines() ] - assert len(security_logs) == 1 + assert len(security_logs) == 2 + if CURRENT_RELEASE == JAMMY: + # Downstream in ubuntu/jammy:debian/patches/retain-old-groups.patch + default_grp = ( + "adm,audio,cdrom,dialout,dip,floppy,lxd,netdev,plugdev,sudo," + "video" + ) + else: + default_grp = "adm,cdrom,dip,lxd,sudo" + expected_security_logs = [ + { + "appid": "canonical.cloud-init", + "description": "User 'craig' was created", + "event": "user_created:cloud-init,craig", + "type": "security", + "level": "WARN", + "host_ip": client.instance.ip, + "hostname": client.instance.name, + }, + { + "appid": "canonical.cloud-init", + "description": ( + f"User 'ubuntu' was created in groups: {default_grp}" + ), + "event": ( + f"user_created:cloud-init,ubuntu,groups:{default_grp}" + ), + "type": "security", + "level": "WARN", + "host_ip": client.instance.ip, + "hostname": client.instance.name, + }, + ] + for security_log in security_logs: + assert security_log.pop("datetime") + # import pdb + + # pdb.set_trace() + assert expected_security_logs == security_logs def test_runcmd(self, class_client: IntegrationInstance): """Test runcmd works as expected""" diff --git a/tests/unittests/distros/test_create_users.py b/tests/unittests/distros/test_create_users.py index 56ab88cb12a..3cc878d402b 100644 --- a/tests/unittests/distros/test_create_users.py +++ b/tests/unittests/distros/test_create_users.py @@ -514,7 +514,6 @@ def test_snappy_only_new_group_added( ex_groups = ["existing_group"] groups = ["group1", ex_groups[0]] m_is_group.side_effect = lambda m: m in ex_groups - dist.create_user(USER, groups=groups) expected = [ mock.call(["groupadd", "group1", "--extrausers"]), @@ -525,7 +524,10 @@ def test_snappy_only_new_group_added( ] assert m_subp.call_args_list == expected event = json.loads(caplog.records[-1].msg) - assert event["event"] == "user_created:cloud-init,foo_user" + assert ( + event["event"] + == "user_created:cloud-init,foo_user,groups:group1,existing_group" + ) @mock.patch("cloudinit.distros.util.is_group") def test_create_groups_with_whitespace_string( diff --git a/tests/unittests/log/test_security_event_log.py b/tests/unittests/log/test_security_event_log.py index 4694e785ff6..e8b7e217cb3 100644 --- a/tests/unittests/log/test_security_event_log.py +++ b/tests/unittests/log/test_security_event_log.py @@ -78,7 +78,7 @@ def test_event_contains_required_owasp_fields(self, host_ip): ) assert "datetime" in event - assert event["appid"] == "canonical.cloud_init" + assert event["appid"] == "canonical.cloud-init" assert event["event"] == "user_created:cloud-init,testuser" assert event["level"] == "INFO" assert event["description"] == "Test event" @@ -105,7 +105,7 @@ def test_additional_data_does_not_overwrite_core_fields(self, host_ip): additional_data={"appid": "malicious.app", "level": "CRITICAL"}, ) - assert event["appid"] == "canonical.cloud_init" + assert event["appid"] == "canonical.cloud-init" assert event["level"] == "INFO" def test_timestamp_is_iso_format(self, host_ip): @@ -138,7 +138,7 @@ def test_writes_json_to_file(self, host_ip, caplog): assert event["event"] == "user_created:cloud-init,testuser" assert event["level"] == "INFO" - assert event["appid"] == "canonical.cloud_init" + assert event["appid"] == "canonical.cloud-init" def test_appends_multiple_events(self, host_ip, caplog): """Test that multiple events are appended to the log file.""" @@ -184,6 +184,20 @@ class TestUserCreatedEvent: "User 'testuser' was created in groups: grp1,grp2", id="user_created_with_groups_logs_event", ), + pytest.param( + True, + {"sudo": True, "groups": ["grp1"]}, + "user_created:cloud-init,testuser,groups:grp1,sudo", + "User 'testuser' was created in groups: grp1,sudo", + id="user_created_with_sudo_and_groups_logs_event", + ), + pytest.param( + True, + {"doas": True, "groups": ["grp2"]}, + "user_created:cloud-init,testuser,groups:grp2,doas", + "User 'testuser' was created in groups: grp2,doas", + id="user_created_with_doas_and_groups_logs_event", + ), pytest.param( False, {}, None, None, id="user_not_created_skips_logging" ), @@ -214,7 +228,7 @@ def user_created_test(name, **kwargs): assert event.pop("datetime") assert { - "appid": "canonical.cloud_init", + "appid": "canonical.cloud-init", "event": event_id, "description": description, "host_ip": "10.42.42.42", @@ -239,7 +253,7 @@ def set_passwd_test(user): set_passwd_test("testuser") # Test with positional params expected_value = { - "appid": "canonical.cloud_init", + "appid": "canonical.cloud-init", "event": "authn_password_change:cloud-init,testuser", "description": "Password changed for user 'testuser'", "host_ip": "10.42.42.42", @@ -294,7 +308,7 @@ def shutdown_test(mode, delay): event = json.loads(caplog.records[0].msg) assert event.pop("datetime") expected = { - "appid": "canonical.cloud_init", + "appid": "canonical.cloud-init", "delay": delay, "description": expected_descr, "event": expected_event, From 97a816fed97e14d0d4b89b2dc4a200bc862fb10e Mon Sep 17 00:00:00 2001 From: Chad Smith Date: Wed, 4 Mar 2026 11:46:26 -0700 Subject: [PATCH 10/31] chore: mypy warnings and prevent subclassing for create_user and shutdown Correct type hint for netdev_info --- cloudinit/distros/__init__.py | 10 +++------- cloudinit/log/security_event_log.py | 5 ++--- cloudinit/netinfo.py | 2 +- tests/unittests/test_log.py | 2 +- tests/unittests/util.py | 4 ++-- 5 files changed, 9 insertions(+), 14 deletions(-) diff --git a/cloudinit/distros/__init__.py b/cloudinit/distros/__init__.py index 3b1381e3d95..c2ffccc83a0 100644 --- a/cloudinit/distros/__init__.py +++ b/cloudinit/distros/__init__.py @@ -31,6 +31,7 @@ Tuple, Type, Union, + final, ) import cloudinit.net.netops.iproute2 as iproute2 @@ -782,13 +783,6 @@ def add_user(self, name, **kwargs) -> bool: util.logexc(LOG, "Failed to create user %s", name) raise e - user_attributes = {} - for k, v in kwargs.items(): - if k == "groups": - user_attributes["groups"] = ",".join(groups) - elif k in ("sudo", "doas") and v: - user_attributes[k] = True - # Indicate that a new user was created return True @@ -856,6 +850,7 @@ def _shadow_file_has_empty_user_password(self, username) -> bool: return True return False + @final @sec_log_user_created def create_user(self, name, **kwargs): """ @@ -1336,6 +1331,7 @@ def create_group(self, name, members=None): LOG.info("Added user '%s' to group '%s'", member, name) @classmethod + @final @sec_log_system_shutdown def shutdown_command(cls, *, mode, delay, message): # called from cc_power_state_change.load_power_state and clean diff --git a/cloudinit/log/security_event_log.py b/cloudinit/log/security_event_log.py index 5809819b17b..28e1973af21 100644 --- a/cloudinit/log/security_event_log.py +++ b/cloudinit/log/security_event_log.py @@ -71,9 +71,8 @@ def _get_host_ip() -> Optional[str]: try: first_ipv6: Optional[str] = None for iface, info in netdev_info().items(): - if iface == "lo" or not info.get("up"): - continue - for addr in info.get("ipv4", []): + ipv4: List[dict] = info.get("ipv4", []) + for addr in ipv4: if addr.get("scope") == "global" and addr.get("ip"): return addr["ip"] if first_ipv6 is None: diff --git a/cloudinit/netinfo.py b/cloudinit/netinfo.py index 69cc56f8926..7e79db0576f 100644 --- a/cloudinit/netinfo.py +++ b/cloudinit/netinfo.py @@ -292,7 +292,7 @@ def _netdev_info_ifconfig(ifconfig_data): def netdev_info( empty="", -) -> Dict[str, Dict[str, Interface]]: +) -> Dict[str, Interface]: """return the instance's interfaces and interface data includes, interface name, link state, hardware address, and lists of ipv4 diff --git a/tests/unittests/test_log.py b/tests/unittests/test_log.py index 5e4d0f607bb..a39af360d84 100644 --- a/tests/unittests/test_log.py +++ b/tests/unittests/test_log.py @@ -183,7 +183,7 @@ def test_logger_prints_security_as_json_lines(tmp_path, capsys, caplog): log_file = tmp_path / "cloud-init-output.log" message = '{"key": "value"}' loggers.setup_basic_logging() - root = logging.getLogger() + root = cast(loggers.CustomLoggerType, logging.getLogger()) loggers.setup_security_logging(root=root, log_file=str(log_file)) root.security(message) assert log_file.read_text() == f"{message}\n" diff --git a/tests/unittests/util.py b/tests/unittests/util.py index 77b5eb6748f..694282d5a6f 100644 --- a/tests/unittests/util.py +++ b/tests/unittests/util.py @@ -150,7 +150,7 @@ def add_user(self, name, **kwargs): def add_snap_user(self, name, **kwargs): return "snap_user" - @security_event_log.sec_log_user_created + @security_event_log.sec_log_user_created # type: ignore[misc] def create_user(self, name, **kwargs): return True @@ -172,7 +172,7 @@ def write_sudo_rules(self, user, rules, sudo_file=None): def create_group(self, name, members=None): pass - @security_event_log.sec_log_system_shutdown + @security_event_log.sec_log_system_shutdown # type: ignore[misc] def shutdown_command(self, *, mode, delay, message): pass From e91cc58eeeb78846bdc9df28204a039ea27b3d50 Mon Sep 17 00:00:00 2001 From: Chad Smith Date: Wed, 4 Mar 2026 22:18:49 -0700 Subject: [PATCH 11/31] fix: ignore down nics, support chpasswd logging --- cloudinit/distros/__init__.py | 2 + cloudinit/log/security_event_log.py | 23 +++++++- tests/unittests/distros/test_passwords.py | 54 +++++++++++++++++++ .../unittests/log/test_security_event_log.py | 34 +++++++++++- 4 files changed, 110 insertions(+), 3 deletions(-) create mode 100644 tests/unittests/distros/test_passwords.py diff --git a/cloudinit/distros/__init__.py b/cloudinit/distros/__init__.py index c2ffccc83a0..a70988d376a 100644 --- a/cloudinit/distros/__init__.py +++ b/cloudinit/distros/__init__.py @@ -55,6 +55,7 @@ from cloudinit.lifecycle import log_with_downgradable_level from cloudinit.log.security_event_log import ( sec_log_password_changed, + sec_log_password_changed_batch, sec_log_system_shutdown, sec_log_user_created, ) @@ -1122,6 +1123,7 @@ def set_passwd(self, user, passwd, hashed=False): return True + @sec_log_password_changed_batch def chpasswd(self, plist_in: list, hashed: bool): payload = ( "\n".join( diff --git a/cloudinit/log/security_event_log.py b/cloudinit/log/security_event_log.py index 28e1973af21..c9cdef8b58a 100644 --- a/cloudinit/log/security_event_log.py +++ b/cloudinit/log/security_event_log.py @@ -59,7 +59,7 @@ class OWASPEventType(Enum): # User management events [USER] USER_CREATED = "user_created" - USER_UPDATED = "user_updated" + # TODO(USER_UPDATED = "user_updated") def _get_host_ip() -> Optional[str]: @@ -71,6 +71,8 @@ def _get_host_ip() -> Optional[str]: try: first_ipv6: Optional[str] = None for iface, info in netdev_info().items(): + if not info["up"]: + continue ipv4: List[dict] = info.get("ipv4", []) for addr in ipv4: if addr.get("scope") == "global" and addr.get("ip"): @@ -216,6 +218,25 @@ def decorator(*args, **kwargs): return decorator +def sec_log_password_changed_batch(func): + @functools.wraps(func) + def decorator(*args, **kwargs): + response = func(*args, **kwargs) + plist_in = kwargs.get("plist_in") + if not plist_in: + plist_in = args[1] + for userid, _ in plist_in: + _log_security_event( + event_type=OWASPEventType.AUTHN_PASSWORD_CHANGE, + level=OWASPEventLevel.INFO, + description=f"Password changed for user '{userid}'", + event_params=["cloud-init", userid], + ) + return response + + return decorator + + def sec_log_password_changed(func): """A decorator logging a password change event.""" diff --git a/tests/unittests/distros/test_passwords.py b/tests/unittests/distros/test_passwords.py new file mode 100644 index 00000000000..4f8dbddda6a --- /dev/null +++ b/tests/unittests/distros/test_passwords.py @@ -0,0 +1,54 @@ +# This file is part of cloud-init. See LICENSE file for license information. + + +import pytest + +from tests.unittests.helpers import get_distro, mock + +USER = "foo_user" + + +@pytest.fixture(autouse=True) +def common_mocks(mocker): + mocker.patch( + "cloudinit.log.security_event_log._get_host_ip", return_value=None + ) + + +@mock.patch("cloudinit.distros.subp.subp") +class TestChpasswd: + + @pytest.mark.parametrize( + "plist_in,hashed,expected", + [ + pytest.param( + (("u1", "pw1"), ("u2", "pw2")), + False, + [ + mock.call(["chpasswd"], data="u1:pw1\nu2:pw2\n"), + ], + id="clear_text_passwords", + ), + pytest.param( + (("u1", "hash1"), ("u2", "hash2")), + True, + [ + mock.call(["chpasswd", "-e"], data="u1:hash1\nu2:hash2\n"), + ], + id="hashed_passwords", + ), + ], + ) + def test_create_options( + self, + m_subp, + plist_in, + hashed, + expected, + caplog, + ): + dist = get_distro("ubuntu") + dist.chpasswd(plist_in=plist_in, hashed=hashed) + assert m_subp.call_args_list == expected + for user in ("u1", "u2"): + assert f"authn_password_change:cloud-init,{user}" in caplog.text diff --git a/tests/unittests/log/test_security_event_log.py b/tests/unittests/log/test_security_event_log.py index e8b7e217cb3..90c69b5244b 100644 --- a/tests/unittests/log/test_security_event_log.py +++ b/tests/unittests/log/test_security_event_log.py @@ -11,6 +11,7 @@ OWASPEventLevel, OWASPEventType, sec_log_password_changed, + sec_log_password_changed_batch, sec_log_system_shutdown, sec_log_user_created, ) @@ -268,6 +269,35 @@ def set_passwd_test(user): assert expected_value == event +class TestPasswordChangedBatchEvent: + """Tests for sec_log_password_changed_batch function.""" + + def test_logs_password_changed_event_for_each_user(self, host_ip, caplog): + """Test logging a password change event.""" + + @sec_log_password_changed_batch + def set_passwd_test(pwlist_in): + pass + + with caplog.at_level(loggers.SECURITY): + set_passwd_test(pwlist_in="testuser") + + expected_value = { + "appid": "canonical.cloud-init", + "event": "authn_password_change:cloud-init,testuser", + "description": "Password changed for user 'testuser'", + "host_ip": "10.42.42.42", + "hostname": get_hostname(), + "level": "INFO", + "type": "security", + } + + for record in caplog.records: + event = json.loads(record.msg) + assert event.pop("datetime") + assert expected_value == event + + class TestSystemShutdownEvent: """Tests for sec_log_system_shutdown function.""" @@ -384,8 +414,8 @@ class TestGetHostIp: { "lo": { "up": True, - "ipv4": [{"ip": "127.0.0.1", "scope": "global"}], - "ipv6": [{"ip": "::1/128", "scope6": "global"}], + "ipv4": [{"ip": "127.0.0.1", "scope": "host"}], + "ipv6": [{"ip": "::1/128", "scope6": "host"}], }, "eth0": { "up": True, From 6d5928109fcbe8d8ee9ec39f91680a074ed5ff5b Mon Sep 17 00:00:00 2001 From: Chad Smith Date: Mon, 9 Mar 2026 20:00:02 +0000 Subject: [PATCH 12/31] chore: generalize Distro.add_user refactor subclass overrides Disallow subclassing of add_user and add_snap_user and decorate them with sec_log_creat_user to log when users are created. Drop sec_log_create_user decoration from Distro.create_user. Simplify add_user to avoid util.is_user check and perform that in create_user before calling Distro.add_user. Allow subclasses to provide distro-specific method _build_add_user_cmd, _add_user_preprocess_kwargs and _post_add_user to specialize behavior and use appropiate add-user tools. Simplify sec_log_user_created to avoid checking truthy return value indicating if user was created. --- cloudinit/distros/__init__.py | 145 +++++++++-------- cloudinit/distros/alpine.py | 151 ++++++------------ cloudinit/distros/freebsd.py | 31 ++-- cloudinit/distros/netbsd.py | 32 ++-- cloudinit/distros/raspberry_pi_os.py | 19 +-- cloudinit/log/security_event_log.py | 15 +- .../modules/test_combined.py | 27 +--- tests/unittests/distros/test_alpine.py | 9 +- tests/unittests/distros/test_create_users.py | 40 +++-- tests/unittests/distros/test_dragonflybsd.py | 7 +- tests/unittests/distros/test_freebsd.py | 7 +- tests/unittests/distros/test_netbsd.py | 7 +- tests/unittests/distros/test_openbsd.py | 7 +- .../unittests/distros/test_raspberry_pi_os.py | 48 +++--- .../distros/test_user_data_normalize.py | 8 +- .../unittests/log/test_security_event_log.py | 27 +--- 16 files changed, 240 insertions(+), 340 deletions(-) diff --git a/cloudinit/distros/__init__.py b/cloudinit/distros/__init__.py index a70988d376a..fd9a9995f32 100644 --- a/cloudinit/distros/__init__.py +++ b/cloudinit/distros/__init__.py @@ -666,56 +666,14 @@ def preferred_ntp_clients(self): def get_default_user(self): return self.get_option("default_user") - def add_user(self, name, **kwargs) -> bool: - """ - Add a user to the system using standard GNU tools - - This should be overridden on distros where useradd is not desirable or - not available. - - Returns False if user already exists, otherwise True. - """ - # XXX need to make add_user idempotent somehow as we - # still want to add groups or modify SSH keys on pre-existing - # users in the image. - if util.is_user(name): - LOG.info("User %s already exists, skipping.", name) - return False - - if "create_groups" in kwargs: - create_groups = kwargs.pop("create_groups") - else: - create_groups = True - - useradd_cmd = ["useradd", name] - log_useradd_cmd = ["useradd", name] - if util.system_is_snappy(): - useradd_cmd.append("--extrausers") - log_useradd_cmd.append("--extrausers") - - # Since we are creating users, we want to carefully validate the - # inputs. If something goes wrong, we can end up with a system - # that nobody can login to. - useradd_opts = { - "gecos": "--comment", - "homedir": "--home", - "primary_group": "--gid", - "uid": "--uid", - "groups": "--groups", - "passwd": "--password", - "shell": "--shell", - "expiredate": "--expiredate", - "inactive": "--inactive", - "selinux_user": "--selinux-user", - } + @final + @sec_log_user_created + def add_user(self, name, **kwargs): + """Add a user to the system.""" - useradd_flags = { - "no_user_group": "--no-user-group", - "system": "--system", - "no_log_init": "--no-log-init", - } + self._add_user_preprocess_kwargs(name, kwargs) - redact_opts = ["passwd"] + create_groups = kwargs.pop("create_groups", True) # support kwargs having groups=[list] or groups="g1,g2" groups = kwargs.get("groups") @@ -736,7 +694,7 @@ def add_user(self, name, **kwargs) -> bool: # that came in as a string like: groups: group1, group2 groups = [g.strip() for g in groups] - # kwargs.items loop below wants a comma delimited string + # _build_add_user_cmd wants a comma delimited string # that can go right through to the command. kwargs["groups"] = ",".join(groups) @@ -749,9 +707,66 @@ def add_user(self, name, **kwargs) -> bool: if not util.is_group(group): self.create_group(group) LOG.debug("created group '%s' for user '%s'", group, name) - if "uid" in kwargs.keys(): + + if "uid" in kwargs: kwargs["uid"] = str(kwargs["uid"]) + LOG.debug("Adding user %s", name) + cmd, log_cmd = self._build_add_user_cmd(name, **kwargs) + try: + subp.subp(cmd, logstring=log_cmd) + except Exception as e: + util.logexc(LOG, "Failed to create user %s", name) + raise e + + self._post_add_user(name, **kwargs) + + def _add_user_preprocess_kwargs(self, name: str, kwargs: dict) -> None: + """Preprocess kwargs in-place before building the add-user command. + + Overridden to filter for distro-specific user creation tools. + """ + + def _build_add_user_cmd( + self, name: str, **kwargs + ) -> Tuple[List[str], List[str]]: + """Build the useradd command for GNU/Linux systems. + + Overridden for distro-specific user-creation tools. + + Returns a (cmd, log_cmd) tuple where log_cmd has sensitive values + redacted. + """ + useradd_cmd = ["useradd", name] + log_useradd_cmd = ["useradd", name] + if util.system_is_snappy(): + useradd_cmd.append("--extrausers") + log_useradd_cmd.append("--extrausers") + + # Since we are creating users, we want to carefully validate the + # inputs. If something goes wrong, we can end up with a system + # that nobody can login to. + useradd_opts = { + "gecos": "--comment", + "homedir": "--home", + "primary_group": "--gid", + "uid": "--uid", + "groups": "--groups", + "passwd": "--password", + "shell": "--shell", + "expiredate": "--expiredate", + "inactive": "--inactive", + "selinux_user": "--selinux-user", + } + + useradd_flags = { + "no_user_group": "--no-user-group", + "system": "--system", + "no_log_init": "--no-log-init", + } + + redact_opts = ["passwd"] + # Check the values and create the command for key, val in sorted(kwargs.items()): if key in useradd_opts and val and isinstance(val, str): @@ -776,17 +791,16 @@ def add_user(self, name, **kwargs) -> bool: useradd_cmd.append("-m") log_useradd_cmd.append("-m") - # Run the command - LOG.debug("Adding user %s", name) - try: - subp.subp(useradd_cmd, logstring=log_useradd_cmd) - except Exception as e: - util.logexc(LOG, "Failed to create user %s", name) - raise e + return useradd_cmd, log_useradd_cmd - # Indicate that a new user was created - return True + def _post_add_user(self, name: str, **kwargs): + """Hook called after the user-creation command succeeds. + + Overridden to perform distro-specific post-creation steps. + """ + @final + @sec_log_user_created def add_snap_user(self, name, **kwargs): """ Add a snappy user to the system using snappy tools @@ -809,14 +823,10 @@ def add_snap_user(self, name, **kwargs): create_user_cmd, logstring=create_user_cmd, capture=True ) LOG.debug("snap create-user returned: %s:%s", out, err) - jobj = util.load_json(out) - username = jobj.get("username", None) except Exception as e: util.logexc(LOG, "Failed to create snap user %s", name) raise e - return username - def _shadow_file_has_empty_user_password(self, username) -> bool: """ Check whether username exists in shadow files with empty password. @@ -852,7 +862,6 @@ def _shadow_file_has_empty_user_password(self, username) -> bool: return False @final - @sec_log_user_created def create_user(self, name, **kwargs): """ Creates or partially updates the ``name`` user in the system. @@ -878,8 +887,11 @@ def create_user(self, name, **kwargs): if "snapuser" in kwargs: return self.add_snap_user(name, **kwargs) - # Add the user - pre_existing_user = not self.add_user(name, **kwargs) + pre_existing_user = util.is_user(name) + if pre_existing_user: + LOG.info("User %s already exists, skipping.", name) + else: + self.add_user(name, **kwargs) has_existing_password = False ud_blank_password_specified = False @@ -1030,7 +1042,6 @@ def create_user(self, name, **kwargs): ssh_util.setup_user_keys( set(cloud_keys), name, options=disable_option ) - return True def lock_passwd(self, name): """ diff --git a/cloudinit/distros/alpine.py b/cloudinit/distros/alpine.py index dcec76128a8..0df03529341 100644 --- a/cloudinit/distros/alpine.py +++ b/cloudinit/distros/alpine.py @@ -11,9 +11,9 @@ import re import stat from datetime import datetime -from typing import Any, Dict, Optional +from typing import List, Optional, Tuple -from cloudinit import distros, helpers, lifecycle, subp, util +from cloudinit import distros, helpers, subp, util from cloudinit.distros.parsers.hostname import HostnameConf from cloudinit.settings import PER_ALWAYS, PER_INSTANCE @@ -205,29 +205,16 @@ def preferred_ntp_clients(self): return self._preferred_ntp_clients - def add_user(self, name, **kwargs) -> bool: - """ - Add a user to the system using standard tools - - On Alpine this may use either 'useradd' or 'adduser' depending - on whether the 'shadow' package is installed. - - Returns False if user already exists, otherwise True. - """ - if util.is_user(name): - LOG.info("User %s already exists, skipping.", name) - return False - - if "selinux_user" in kwargs: + def _add_user_preprocess_kwargs(self, name: str, kwargs: dict) -> None: + if kwargs.pop("selinux_user", None): LOG.warning("Ignoring selinux_user parameter for Alpine Linux") - del kwargs["selinux_user"] - # If 'useradd' is available then use the generic - # add_user function from __init__.py instead. + def _build_add_user_cmd( + self, name: str, **kwargs + ) -> Tuple[List[str], List[str]]: + # If 'useradd' is available then use the generic GNU implementation. if subp.which("useradd"): - return super().add_user(name, **kwargs) - - create_groups = kwargs.pop("create_groups", True) + return super()._build_add_user_cmd(name, **kwargs) adduser_cmd = ["adduser", "-D"] @@ -244,102 +231,64 @@ def add_user(self, name, **kwargs) -> bool: adduser_flags = {"system": "-S"} - # support kwargs having groups=[list] or groups="g1,g2" - groups = kwargs.get("groups") - if groups: - if isinstance(groups, str): - groups = groups.split(",") - elif isinstance(groups, dict): - lifecycle.deprecate( - deprecated=f"The user {name} has a 'groups' config value " - "of type dict", - deprecated_version="22.3", - extra_message="Use a comma-delimited string or " - "array instead: group1,group2.", - ) - - # remove any white spaces in group names, most likely - # that came in as a string like: groups: group1, group2 - groups = [g.strip() for g in groups] - - # kwargs.items loop below wants a comma delimited string - # that can go right through to the command. - kwargs["groups"] = ",".join(groups) - - if kwargs.get("primary_group"): - groups.append(kwargs["primary_group"]) - - if create_groups and groups: - for group in groups: - if not util.is_group(group): - self.create_group(group) - LOG.debug("created group '%s' for user '%s'", group, name) - if "uid" in kwargs: - kwargs["uid"] = str(kwargs["uid"]) - - unsupported_busybox_values: Dict[str, Any] = { - "groups": [], - "expiredate": None, - "inactive": None, - "passwd": None, + # Build the command, skipping options unsupported by busybox adduser + # (groups, passwd, expiredate, inactive — handled in _post_add_user). + unsupported_busybox_keys = { + "groups", + "expiredate", + "inactive", + "passwd", } - - # Check the values and create the command for key, val in sorted(kwargs.items()): if key in adduser_opts and val and isinstance(val, str): adduser_cmd.extend([adduser_opts[key], val]) - elif ( - key in unsupported_busybox_values - and val - and isinstance(val, str) - ): - # Busybox's 'adduser' does not support specifying these - # options so store them for use via alternative means. - if key == "groups": - unsupported_busybox_values[key] = val.split(",") - else: - unsupported_busybox_values[key] = val elif key in adduser_flags and val: adduser_cmd.append(adduser_flags[key]) + elif key in unsupported_busybox_keys: + pass # handled in _post_add_user - # Don't create the home directory if directed so - # or if the user is a system user + # Don't create the home directory if directed so or if the user is a + # system user if kwargs.get("no_create_home") or kwargs.get("system"): adduser_cmd.append("-H") # Busybox's 'adduser' puts username at end of command adduser_cmd.append(name) - # Run the command - LOG.debug("Adding user %s", name) - try: - subp.subp(adduser_cmd) - except subp.ProcessExecutionError as e: - LOG.warning("Failed to create user %s", name) - raise e + return adduser_cmd, adduser_cmd - # Process remaining options that Busybox's 'adduser' does not support + def _post_add_user(self, name: str, **kwargs) -> bool: + # When useradd is available, the GNU implementation handles everything. + if subp.which("useradd"): + return True + + # Busybox post-creation steps. # Separately add user to each additional group as Busybox's # 'adduser' does not support specifying additional groups. - for addn_group in unsupported_busybox_values[ - "groups" - ]: # pylint: disable=E1133 - LOG.debug("Adding user to group %s", addn_group) - try: - subp.subp(["addgroup", name, addn_group]) - except subp.ProcessExecutionError as e: - util.logexc( - LOG, "Failed to add user %s to group %s", name, addn_group - ) - raise e + groups_str = kwargs.get("groups", "") + if groups_str: + for addn_group in groups_str.split(","): + addn_group = addn_group.strip() + if not addn_group: + continue + LOG.debug("Adding user to group %s", addn_group) + try: + subp.subp(["addgroup", name, addn_group]) + except subp.ProcessExecutionError as e: + util.logexc( + LOG, + "Failed to add user %s to group %s", + name, + addn_group, + ) + raise e - if unsupported_busybox_values["passwd"]: + passwd_val = kwargs.get("passwd") + if passwd_val: # Separately set password as Busybox's 'adduser' does # not support passing password as CLI option. - super().set_passwd( - name, unsupported_busybox_values["passwd"], hashed=True - ) + super().set_passwd(name, passwd_val, hashed=True) # Busybox's 'adduser' is hardcoded to always set the following field # values (numbered from "0") in /etc/shadow unlike 'useradd': @@ -356,10 +305,9 @@ def add_user(self, name, **kwargs) -> bool: # values directly in /etc/shadow file as Busybox's 'adduser' # does not support passing these as CLI options. - expiredate = unsupported_busybox_values["expiredate"] - inactive = unsupported_busybox_values["inactive"] + expiredate = kwargs.get("expiredate") + inactive = kwargs.get("inactive") - shadow_contents = None shadow_file = self.shadow_fn try: shadow_contents = util.load_text_file(shadow_file) @@ -420,7 +368,6 @@ def add_user(self, name, **kwargs) -> bool: LOG, "Failed to update %s for user %s", shadow_file, name ) - # Indicate that a new user was created return True def lock_passwd(self, name): diff --git a/cloudinit/distros/freebsd.py b/cloudinit/distros/freebsd.py index 3eb4fbbf214..32e3ef3472c 100644 --- a/cloudinit/distros/freebsd.py +++ b/cloudinit/distros/freebsd.py @@ -8,6 +8,7 @@ import os import re from io import StringIO +from typing import List, Tuple import cloudinit.distros.bsd from cloudinit import subp, util @@ -97,16 +98,9 @@ def manage_service( def _get_add_member_to_group_cmd(self, member_name, group_name): return ["pw", "usermod", "-n", member_name, "-G", group_name] - def add_user(self, name, **kwargs) -> bool: - """ - Add a user to the system using standard tools - - Returns False if user already exists, otherwise True. - """ - if util.is_user(name): - LOG.info("User %s already exists, skipping.", name) - return False - + def _build_add_user_cmd( + self, name: str, **kwargs + ) -> Tuple[List[str], List[str]]: pw_useradd_cmd = ["pw", "useradd", "-n", name] log_pw_useradd_cmd = ["pw", "useradd", "-n", name] @@ -128,7 +122,6 @@ def add_user(self, name, **kwargs) -> bool: for key, val in kwargs.items(): if key in pw_useradd_opts and val and isinstance(val, (str, int)): pw_useradd_cmd.extend([pw_useradd_opts[key], str(val)]) - elif key in pw_useradd_flags and val: pw_useradd_cmd.append(pw_useradd_flags[key]) log_pw_useradd_cmd.append(pw_useradd_flags[key]) @@ -143,20 +136,14 @@ def add_user(self, name, **kwargs) -> bool: log_pw_useradd_cmd.append("-d" + homedir) log_pw_useradd_cmd.append("-m") - # Run the command - LOG.info("Adding user %s", name) - try: - subp.subp(pw_useradd_cmd, logstring=log_pw_useradd_cmd) - except Exception: - util.logexc(LOG, "Failed to create user %s", name) - raise - # Set the password if it is provided - # For security consideration, only hashed passwd is assumed + return pw_useradd_cmd, log_pw_useradd_cmd + + def _post_add_user(self, name: str, **kwargs) -> bool: + # Set the password if it is provided. + # For security consideration, only hashed passwd is assumed. passwd_val = kwargs.get("passwd", None) if passwd_val is not None: self.set_passwd(name, passwd_val, hashed=True) - - # Indicate that a new user was created return True def expire_passwd(self, user): diff --git a/cloudinit/distros/netbsd.py b/cloudinit/distros/netbsd.py index 157aba06924..d0704474790 100644 --- a/cloudinit/distros/netbsd.py +++ b/cloudinit/distros/netbsd.py @@ -6,7 +6,7 @@ import logging import os import platform -from typing import Any +from typing import Any, List, Tuple import cloudinit.distros.bsd from cloudinit import subp, util @@ -74,16 +74,9 @@ def __init__(self, name, cfg, paths): def _get_add_member_to_group_cmd(self, member_name, group_name): return ["usermod", "-G", group_name, member_name] - def add_user(self, name, **kwargs) -> bool: - """ - Add a user to the system using standard tools - - Returns False if user already exists, otherwise True. - """ - if util.is_user(name): - LOG.info("User %s already exists, skipping.", name) - return False - + def _build_add_user_cmd( + self, name: str, **kwargs + ) -> Tuple[List[str], List[str]]: adduser_cmd = ["useradd"] log_adduser_cmd = ["useradd"] @@ -103,7 +96,6 @@ def add_user(self, name, **kwargs) -> bool: for key, val in kwargs.items(): if key in adduser_opts and val and isinstance(val, str): adduser_cmd.extend([adduser_opts[key], val]) - elif key in adduser_flags and val: adduser_cmd.append(adduser_flags[key]) log_adduser_cmd.append(adduser_flags[key]) @@ -115,20 +107,14 @@ def add_user(self, name, **kwargs) -> bool: adduser_cmd += [name] log_adduser_cmd += [name] - # Run the command - LOG.info("Adding user %s", name) - try: - subp.subp(adduser_cmd, logstring=log_adduser_cmd) - except Exception: - util.logexc(LOG, "Failed to create user %s", name) - raise - # Set the password if it is provided - # For security consideration, only hashed passwd is assumed + return adduser_cmd, log_adduser_cmd + + def _post_add_user(self, name: str, **kwargs) -> bool: + # Set the password if it is provided. + # For security consideration, only hashed passwd is assumed. passwd_val = kwargs.get("passwd", None) if passwd_val is not None: self.set_passwd(name, passwd_val, hashed=True) - - # Indicate that a new user was created return True def set_passwd(self, user, passwd, hashed=False): diff --git a/cloudinit/distros/raspberry_pi_os.py b/cloudinit/distros/raspberry_pi_os.py index a6cf0f98585..c07c6e2230f 100644 --- a/cloudinit/distros/raspberry_pi_os.py +++ b/cloudinit/distros/raspberry_pi_os.py @@ -67,20 +67,7 @@ def apply_locale(self, locale, out_fn=None, keyname="LANG"): else: LOG.error("Failed to set locale %s", locale) - def add_user(self, name, **kwargs) -> bool: - """ - Add a user to the system using standard GNU tools - - This should be overridden on distros where useradd is not desirable or - not available. - - Returns False if user already exists, otherwise True. - """ - result = super().add_user(name, **kwargs) - - if not result: - return result - + def _post_add_user(self, name: str, **kwargs): try: subp.subp( [ @@ -90,12 +77,8 @@ def add_user(self, name, **kwargs) -> bool: ], update_env={"SUDO_USER": name}, ) - except subp.ProcessExecutionError as e: LOG.error("Failed to setup user: %s", e) - return False - - return True def generate_fallback_config(self): # Based on Photon OS implementation diff --git a/cloudinit/log/security_event_log.py b/cloudinit/log/security_event_log.py index c9cdef8b58a..264ca2bc84c 100644 --- a/cloudinit/log/security_event_log.py +++ b/cloudinit/log/security_event_log.py @@ -205,14 +205,13 @@ def decorator(*args, **kwargs): params.append(f"groups:{groups_suffix}") response = func(*args, **kwargs) - if response: - # User creation operation was performed - _log_security_event( - event_type=OWASPEventType.USER_CREATED, - level=OWASPEventLevel.WARN, - description=f"User '{new_userid}' was created{groups_msg}", - event_params=params, - ) + # User creation operation did not raise an Exception + _log_security_event( + event_type=OWASPEventType.USER_CREATED, + level=OWASPEventLevel.WARN, + description=f"User '{new_userid}' was created{groups_msg}", + event_params=params, + ) return response return decorator diff --git a/tests/integration_tests/modules/test_combined.py b/tests/integration_tests/modules/test_combined.py index ced169265ce..91413c7dd18 100644 --- a/tests/integration_tests/modules/test_combined.py +++ b/tests/integration_tests/modules/test_combined.py @@ -29,7 +29,6 @@ from tests.integration_tests.releases import ( CURRENT_RELEASE, IS_UBUNTU, - JAMMY, NOBLE, ) from tests.integration_tests.util import ( @@ -233,15 +232,7 @@ def test_security_logs(self, class_client: IntegrationInstance): "/var/log/cloud-init-security.log" ).splitlines() ] - assert len(security_logs) == 2 - if CURRENT_RELEASE == JAMMY: - # Downstream in ubuntu/jammy:debian/patches/retain-old-groups.patch - default_grp = ( - "adm,audio,cdrom,dialout,dip,floppy,lxd,netdev,plugdev,sudo," - "video" - ) - else: - default_grp = "adm,cdrom,dip,lxd,sudo" + assert len(security_logs) == 1 expected_security_logs = [ { "appid": "canonical.cloud-init", @@ -252,25 +243,9 @@ def test_security_logs(self, class_client: IntegrationInstance): "host_ip": client.instance.ip, "hostname": client.instance.name, }, - { - "appid": "canonical.cloud-init", - "description": ( - f"User 'ubuntu' was created in groups: {default_grp}" - ), - "event": ( - f"user_created:cloud-init,ubuntu,groups:{default_grp}" - ), - "type": "security", - "level": "WARN", - "host_ip": client.instance.ip, - "hostname": client.instance.name, - }, ] for security_log in security_logs: assert security_log.pop("datetime") - # import pdb - - # pdb.set_trace() assert expected_security_logs == security_logs def test_runcmd(self, class_client: IntegrationInstance): diff --git a/tests/unittests/distros/test_alpine.py b/tests/unittests/distros/test_alpine.py index 6e301d404af..a1e323aa44e 100644 --- a/tests/unittests/distros/test_alpine.py +++ b/tests/unittests/distros/test_alpine.py @@ -41,7 +41,9 @@ def test_busybox_add_user(self, m_which, m_subp, tmpdir): distro.add_user(user, lock_passwd=True) - m_subp.assert_called_with(["adduser", "-D", user]) + m_subp.assert_called_with( + ["adduser", "-D", user], logstring=["adduser", "-D", user] + ) contents = util.load_text_file(shadow_file) expected = root_entry + "\n" + user + ":!:19848::::::" + "\n" @@ -63,11 +65,14 @@ def test_shadow_add_group(self, m_which, m_subp): m_subp.assert_called_with(["groupadd", group]) + @mock.patch( + "cloudinit.log.security_event_log._get_host_ip", return_value=None + ) @mock.patch("cloudinit.distros.alpine.subp.subp") @mock.patch( "cloudinit.distros.subp.which", return_value=("/usr/sbin/useradd") ) - def test_shadow_add_user(self, m_which, m_subp): + def test_shadow_add_user(self, m_which, m_subp, _get_host_ip): user = "me2" self.distro.add_user(user) diff --git a/tests/unittests/distros/test_create_users.py b/tests/unittests/distros/test_create_users.py index 3cc878d402b..929aeb0d7ef 100644 --- a/tests/unittests/distros/test_create_users.py +++ b/tests/unittests/distros/test_create_users.py @@ -7,6 +7,7 @@ import pytest from cloudinit import distros, features, lifecycle, ssh_util +from cloudinit.log import loggers from tests.unittests.helpers import get_distro, mock from tests.unittests.util import abstract_to_concrete @@ -655,14 +656,22 @@ def test_explicit_sudo_false(self, m_subp, dist, caplog, mocker): ) else ["INFO"] ) - assert caplog.records[1].levelname in expected_levels - assert ( + deprecation_msg = ( "The value of 'false' in user foo_user's 'sudo' " "config is deprecated in 22.2 and scheduled to be removed" " in 27.2. Use 'null' instead." - ) in caplog.text - event = json.loads(caplog.records[-1].msg) - assert event["event"] == "user_created:cloud-init,foo_user" + ) + deprecation_record = security_record = None + for record in caplog.records: + if deprecation_msg in record.msg: + deprecation_record = record + if record.levelno == loggers.SECURITY: + security_record = record + assert deprecation_record, "Missing deprecation log" + assert deprecation_record.levelname in expected_levels + assert security_record, "Missing security log" + security_event = json.loads(security_record.msg) + assert security_event["event"] == "user_created:cloud-init,foo_user" def test_explicit_sudo_none(self, m_subp, dist, caplog, mocker): mocker.patch( @@ -755,11 +764,13 @@ def test_setup_ssh_authorized_keys_with_integer( """ssh_authorized_keys warns on non-iterable/string type.""" dist.create_user(USER, ssh_authorized_keys=-1) m_setup_user_keys.assert_called_once_with(set([]), USER) - assert caplog.records[1].levelname in ["WARNING", "DEPRECATED"] - assert ( + deprecation_msg = ( "Invalid type '' detected for 'ssh_authorized_keys'" - in caplog.text ) + deprecation_record = [ + r for r in caplog.records if deprecation_msg in r.message + ][0] + assert deprecation_record.levelname in ["WARNING", "DEPRECATED"] @mock.patch("cloudinit.ssh_util.setup_user_keys") def test_create_user_with_ssh_redirect_user_no_cloud_keys( @@ -767,11 +778,16 @@ def test_create_user_with_ssh_redirect_user_no_cloud_keys( ): """Log a warning when trying to redirect a user no cloud ssh keys.""" dist.create_user(USER, ssh_redirect_user="someuser") - assert caplog.records[1].levelname in ["WARNING", "DEPRECATED"] - assert ( + deprecation_msg = ( "Unable to disable SSH logins for foo_user given " - "ssh_redirect_user: someuser. No cloud public-keys present.\n" - ) in caplog.text + "ssh_redirect_user: someuser. No cloud public-keys present." + ) + deprecation_records = [ + record + for record in caplog.records + if deprecation_msg in record.message + ] + assert deprecation_records[0].levelname in ["WARNING", "DEPRECATED"] m_setup_user_keys.assert_not_called() @mock.patch("cloudinit.ssh_util.setup_user_keys") diff --git a/tests/unittests/distros/test_dragonflybsd.py b/tests/unittests/distros/test_dragonflybsd.py index 7222aef792b..72fa8872fdf 100644 --- a/tests/unittests/distros/test_dragonflybsd.py +++ b/tests/unittests/distros/test_dragonflybsd.py @@ -7,10 +7,13 @@ class TestDragonFlyBSD: + @mock.patch( + "cloudinit.log.security_event_log._get_host_ip", return_value=None + ) @mock.patch(M_PATH + "subp.subp") - def test_add_user(self, m_subp): + def test_add_user(self, m_subp, _get_host_ip): distro = get_distro("dragonflybsd") - assert True is distro.add_user("me2", uid=1234, default=False) + distro.add_user("me2", uid=1234, default=False) assert [ mock.call( [ diff --git a/tests/unittests/distros/test_freebsd.py b/tests/unittests/distros/test_freebsd.py index ce844f10d9c..3897446cc54 100644 --- a/tests/unittests/distros/test_freebsd.py +++ b/tests/unittests/distros/test_freebsd.py @@ -9,10 +9,13 @@ class TestFreeBSD: + @mock.patch( + "cloudinit.log.security_event_log._get_host_ip", return_value=None + ) @mock.patch(M_PATH + "subp.subp") - def test_add_user(self, m_subp): + def test_add_user(self, m_subp, _get_host_ip): distro = get_distro("freebsd") - assert True is distro.add_user("me2", uid=1234, default=False) + distro.add_user("me2", uid=1234, default=False) assert [ mock.call( [ diff --git a/tests/unittests/distros/test_netbsd.py b/tests/unittests/distros/test_netbsd.py index e5df07d53da..963024dee7c 100644 --- a/tests/unittests/distros/test_netbsd.py +++ b/tests/unittests/distros/test_netbsd.py @@ -16,10 +16,13 @@ class TestNetBSD: + @mock.patch( + "cloudinit.log.security_event_log._get_host_ip", return_value=None + ) @mock.patch(M_PATH + "subp.subp") - def test_add_user(self, m_subp): + def test_add_user(self, m_subp, _get_host_ip): distro = get_distro("netbsd") - assert True is distro.add_user("me2", uid=1234, default=False) + distro.add_user("me2", uid=1234, default=False) assert [ mock.call( ["useradd", "-m", "me2"], logstring=["useradd", "-m", "me2"] diff --git a/tests/unittests/distros/test_openbsd.py b/tests/unittests/distros/test_openbsd.py index 78342c176c0..ed90cbd42b4 100644 --- a/tests/unittests/distros/test_openbsd.py +++ b/tests/unittests/distros/test_openbsd.py @@ -6,10 +6,13 @@ class TestOpenBSD: + @mock.patch( + "cloudinit.log.security_event_log._get_host_ip", return_value=None + ) @mock.patch(M_PATH + "subp.subp") - def test_add_user(self, m_subp): + def test_add_user(self, m_subp, _get_host_ip): distro = get_distro("openbsd") - assert True is distro.add_user("me2", uid=1234, default=False) + distro.add_user("me2", uid=1234, default=False) assert [ mock.call( ["useradd", "-m", "me2"], logstring=["useradd", "-m", "me2"] diff --git a/tests/unittests/distros/test_raspberry_pi_os.py b/tests/unittests/distros/test_raspberry_pi_os.py index 2ef36acf117..8d30f45709d 100644 --- a/tests/unittests/distros/test_raspberry_pi_os.py +++ b/tests/unittests/distros/test_raspberry_pi_os.py @@ -118,43 +118,39 @@ def test_apply_locale_fallback_to_utf8(self, m_subp): ) @mock.patch(M_PATH + "subp.subp") - def test_add_user_happy_path(self, m_subp): + @mock.patch("cloudinit.distros.util.is_user", return_value=False) + def test_add_user_happy_path(self, m_is_user, m_subp): cls = fetch("raspberry_pi_os") distro = cls("raspberry-pi-os", {}, None) - # Mock the superclass add_user to return True - with mock.patch( - "cloudinit.distros.debian.Distro.add_user", return_value=True + with mock.patch.object( + distro, + "_build_add_user_cmd", + return_value=(["useradd", "pi", "-m"], ["useradd", "pi", "-m"]), ): - assert distro.add_user("pi") is True - m_subp.assert_called_once_with( + distro.add_user("pi") + m_subp.assert_any_call( ["/usr/bin/rename-user", "-f", "-s"], update_env={"SUDO_USER": "pi"}, ) @mock.patch(M_PATH + "subp.subp") - def test_add_user_existing_user(self, m_subp): + @mock.patch("cloudinit.distros.util.is_user", return_value=False) + def test_add_user_rename_fails_logs_error(self, m_is_user, m_subp, caplog): cls = fetch("raspberry_pi_os") distro = cls("raspberry-pi-os", {}, None) - with mock.patch( - "cloudinit.distros.debian.Distro.add_user", return_value=False + # First subp call (useradd) succeeds; second (rename-user) fails. + m_subp.side_effect = [ + None, + ProcessExecutionError("rename-user failed"), + ] + with mock.patch.object( + distro, + "_build_add_user_cmd", + return_value=(["useradd", "pi", "-m"], ["useradd", "pi", "-m"]), ): - assert distro.add_user("pi") is False - m_subp.assert_not_called() - - @mock.patch( - M_PATH + "subp.subp", - side_effect=ProcessExecutionError("rename-user failed"), - ) - @mock.patch("cloudinit.distros.debian.Distro.add_user", return_value=True) - def test_add_user_rename_fails_logs_error( - self, m_super_add_user, m_subp, caplog - ): - cls = fetch("raspberry_pi_os") - distro = cls("raspberry-pi-os", {}, None) - - with caplog.at_level(logging.ERROR): - assert distro.add_user("pi") is False - assert "Failed to setup user" in caplog.text + with caplog.at_level(logging.ERROR): + distro.add_user("pi") + assert "Failed to setup user" in caplog.text @mock.patch( "cloudinit.net.generate_fallback_config", diff --git a/tests/unittests/distros/test_user_data_normalize.py b/tests/unittests/distros/test_user_data_normalize.py index 9155b4c44d3..052b0e5ccf8 100644 --- a/tests/unittests/distros/test_user_data_normalize.py +++ b/tests/unittests/distros/test_user_data_normalize.py @@ -283,12 +283,10 @@ def test_create_snap_user(self, mock_subp, _get_host_ip, caplog): } users, _groups = self._norm(ug_cfg, distro) for user, config in users.items(): - print("user=%s config=%s" % (user, config)) - username = distro.create_user(user, **config) + distro.create_user(user, **config) snapcmd = ["snap", "create-user", "--sudoer", "--json", "joe@joe.com"] mock_subp.assert_called_with(snapcmd, capture=True, logstring=snapcmd) - assert username == "joe" event = json.loads(caplog.records[-1].msg) assert "user_created:cloud-init,joe" == event["event"] @@ -308,8 +306,7 @@ def test_create_snap_user_known(self, mock_subp, _get_host_ip, caplog): } users, _groups = self._norm(ug_cfg, distro) for user, config in users.items(): - print("user=%s config=%s" % (user, config)) - username = distro.create_user(user, **config) + distro.create_user(user, **config) snapcmd = [ "snap", @@ -320,7 +317,6 @@ def test_create_snap_user_known(self, mock_subp, _get_host_ip, caplog): "joe@joe.com", ] mock_subp.assert_called_with(snapcmd, capture=True, logstring=snapcmd) - assert username == "joe" event = json.loads(caplog.records[-1].msg) assert "user_created:cloud-init,joe" == event["event"] diff --git a/tests/unittests/log/test_security_event_log.py b/tests/unittests/log/test_security_event_log.py index 90c69b5244b..fbd1358bd70 100644 --- a/tests/unittests/log/test_security_event_log.py +++ b/tests/unittests/log/test_security_event_log.py @@ -169,62 +169,49 @@ class TestUserCreatedEvent: """Tests for sec_log_user_created function.""" @pytest.mark.parametrize( - "user_created,uc_kwargs,event_id,description", + "uc_kwargs,event_id,description", [ pytest.param( - True, {}, "user_created:cloud-init,testuser", "User 'testuser' was created", id="user_created_logs_event", ), pytest.param( - True, {"groups": ["grp1", "grp2"]}, "user_created:cloud-init,testuser,groups:grp1,grp2", "User 'testuser' was created in groups: grp1,grp2", id="user_created_with_groups_logs_event", ), pytest.param( - True, {"sudo": True, "groups": ["grp1"]}, "user_created:cloud-init,testuser,groups:grp1,sudo", "User 'testuser' was created in groups: grp1,sudo", id="user_created_with_sudo_and_groups_logs_event", ), pytest.param( - True, {"doas": True, "groups": ["grp2"]}, "user_created:cloud-init,testuser,groups:grp2,doas", "User 'testuser' was created in groups: grp2,doas", id="user_created_with_doas_and_groups_logs_event", ), - pytest.param( - False, {}, None, None, id="user_not_created_skips_logging" - ), ], ) def test_logs_user_created_event( - self, user_created, uc_kwargs, event_id, description, host_ip, caplog + self, uc_kwargs, event_id, description, host_ip, caplog ): """Test logging a user creation event.""" @sec_log_user_created - def user_created_test(name, **kwargs): - # Distro.create_user returns False when no new user is created. - return user_created + def user_created_decorator_test(name, **kwargs): + return with caplog.at_level(loggers.SECURITY): - user_created_test( + user_created_decorator_test( name="testuser", **uc_kwargs, ) - if not user_created: - assert 0 == len(caplog.records) - return - - # Create user security event happens only when user is created event = json.loads(caplog.records[0].msg) assert event.pop("datetime") @@ -276,11 +263,11 @@ def test_logs_password_changed_event_for_each_user(self, host_ip, caplog): """Test logging a password change event.""" @sec_log_password_changed_batch - def set_passwd_test(pwlist_in): + def set_passwd_test(plist_in): pass with caplog.at_level(loggers.SECURITY): - set_passwd_test(pwlist_in="testuser") + set_passwd_test(plist_in=(("testuser", "pw1"),)) expected_value = { "appid": "canonical.cloud-init", From cf12e895fc89dcf4a011c4b33fcaebf55f5e9b68 Mon Sep 17 00:00:00 2001 From: Chad Smith Date: Tue, 10 Mar 2026 09:20:53 -0600 Subject: [PATCH 13/31] refactor: move get_host_ip from securtiy_event_log to netinfo --- cloudinit/distros/__init__.py | 2 +- cloudinit/log/security_event_log.py | 39 ++---- cloudinit/netinfo.py | 28 ++++- tests/unittests/cmd/test_clean.py | 2 +- .../config/test_cc_power_state_change.py | 2 +- tests/unittests/distros/test_alpine.py | 2 +- tests/unittests/distros/test_create_users.py | 2 +- tests/unittests/distros/test_dragonflybsd.py | 2 +- tests/unittests/distros/test_freebsd.py | 2 +- tests/unittests/distros/test_netbsd.py | 2 +- tests/unittests/distros/test_openbsd.py | 2 +- tests/unittests/distros/test_passwords.py | 2 +- .../distros/test_user_data_normalize.py | 4 +- .../unittests/log/test_security_event_log.py | 118 +----------------- tests/unittests/test_netinfo.py | 117 +++++++++++++++++ 15 files changed, 167 insertions(+), 159 deletions(-) diff --git a/cloudinit/distros/__init__.py b/cloudinit/distros/__init__.py index fd9a9995f32..39808efbc04 100644 --- a/cloudinit/distros/__init__.py +++ b/cloudinit/distros/__init__.py @@ -1113,6 +1113,7 @@ def expire_passwd(self, user): util.logexc(LOG, "Failed to set 'expire' for %s", user) raise e + @final @sec_log_password_changed def set_passwd(self, user, passwd, hashed=False): pass_string = "%s:%s" % (user, passwd) @@ -1364,7 +1365,6 @@ def shutdown_command(cls, *, mode, delay, message): args = command + [delay] if message: args.append(message) - return args @classmethod diff --git a/cloudinit/log/security_event_log.py b/cloudinit/log/security_event_log.py index 264ca2bc84c..71efbcfa591 100644 --- a/cloudinit/log/security_event_log.py +++ b/cloudinit/log/security_event_log.py @@ -26,16 +26,16 @@ from cloudinit import util from cloudinit.log import loggers -from cloudinit.netinfo import netdev_info +from cloudinit.netinfo import get_host_ip LOG = logging.getLogger(__name__) -# Hard-coded application identifier per spec +# Hard-coded application identifier APP_ID = "canonical.cloud-init" class OWASPEventLevel(Enum): - """Log levels per OWASP recommendations.""" + """OWASP log levels.""" INFO = "INFO" WARN = "WARN" @@ -62,32 +62,6 @@ class OWASPEventType(Enum): # TODO(USER_UPDATED = "user_updated") -def _get_host_ip() -> Optional[str]: - """Return the first global IP on an active interface. - - Prefers IPv4; falls back to IPv6 when no global IPv4 is available. - IPv6 addresses are returned without their prefix-length suffix. - """ - try: - first_ipv6: Optional[str] = None - for iface, info in netdev_info().items(): - if not info["up"]: - continue - ipv4: List[dict] = info.get("ipv4", []) - for addr in ipv4: - if addr.get("scope") == "global" and addr.get("ip"): - return addr["ip"] - if first_ipv6 is None: - for addr in info.get("ipv6", []): - if addr.get("scope6") == "global" and addr.get("ip"): - first_ipv6 = addr["ip"].split("/")[0] - break - return first_ipv6 - except Exception: - pass - return None - - def _build_event_string( event_type: OWASPEventType, params: Optional[List[str]] = None ) -> str: @@ -133,7 +107,7 @@ def _build_security_event( "description": description, "hostname": util.get_hostname(), } - host_ip = _get_host_ip() + host_ip = get_host_ip() if host_ip: event["host_ip"] = host_ip @@ -244,7 +218,10 @@ def decorator(*args, **kwargs): response = func(*args, **kwargs) userid = kwargs.get("user") if not userid: - userid = args[-1] + for arg in args: + if isinstance(arg, str): + userid = arg + break _log_security_event( event_type=OWASPEventType.AUTHN_PASSWORD_CHANGE, level=OWASPEventLevel.INFO, diff --git a/cloudinit/netinfo.py b/cloudinit/netinfo.py index 7e79db0576f..2374972cd0b 100644 --- a/cloudinit/netinfo.py +++ b/cloudinit/netinfo.py @@ -13,7 +13,7 @@ import re from copy import copy, deepcopy from ipaddress import IPv4Network -from typing import Dict, List, TypedDict +from typing import Dict, List, Optional, TypedDict from cloudinit import lifecycle, subp, util from cloudinit.net.network_state import net_prefix_to_ipv4_mask @@ -376,6 +376,32 @@ def fill(data, new_val="", empty_vals=("", b"")): return devs +def get_host_ip() -> Optional[str]: + """Return the first global IP on an active interface. + + Prefers IPv4; falls back to IPv6 when no global IPv4 is available. + IPv6 addresses are returned without their prefix-length suffix. + """ + try: + first_ipv6: Optional[str] = None + for iface, info in netdev_info().items(): + if not info["up"]: + continue + ipv4: List[dict] = info.get("ipv4", []) + for addr in ipv4: + if addr.get("scope") == "global" and addr.get("ip"): + return addr["ip"] + if first_ipv6 is None: + for addr in info.get("ipv6", []): + if addr.get("scope6") == "global" and addr.get("ip"): + first_ipv6 = addr["ip"].split("/")[0] + break + return first_ipv6 + except Exception: + pass + return None + + def _netdev_route_info_iproute(iproute_data): """ Get network route dicts from ip route info. diff --git a/tests/unittests/cmd/test_clean.py b/tests/unittests/cmd/test_clean.py index d1623f95b27..386570b4479 100644 --- a/tests/unittests/cmd/test_clean.py +++ b/tests/unittests/cmd/test_clean.py @@ -480,7 +480,7 @@ def test_remove_artifacts_returns_one_on_errors( ) @mock.patch( - "cloudinit.log.security_event_log._get_host_ip", return_value=None + "cloudinit.log.security_event_log.get_host_ip", return_value=None ) def test_handle_clean_args_reboots(self, _get_host_ip, init_class): """handle_clean_args_reboots when reboot arg is provided.""" diff --git a/tests/unittests/config/test_cc_power_state_change.py b/tests/unittests/config/test_cc_power_state_change.py index 9de8f26031b..8c474947a87 100644 --- a/tests/unittests/config/test_cc_power_state_change.py +++ b/tests/unittests/config/test_cc_power_state_change.py @@ -26,7 +26,7 @@ class TestLoadPowerState: @pytest.fixture(autouse=True) def common_mocks(self, mocker): mocker.patch( - "cloudinit.log.security_event_log._get_host_ip", return_value=None + "cloudinit.log.security_event_log.get_host_ip", return_value=None ) def test_no_config(self, dist): diff --git a/tests/unittests/distros/test_alpine.py b/tests/unittests/distros/test_alpine.py index a1e323aa44e..a551abe2f95 100644 --- a/tests/unittests/distros/test_alpine.py +++ b/tests/unittests/distros/test_alpine.py @@ -66,7 +66,7 @@ def test_shadow_add_group(self, m_which, m_subp): m_subp.assert_called_with(["groupadd", group]) @mock.patch( - "cloudinit.log.security_event_log._get_host_ip", return_value=None + "cloudinit.log.security_event_log.get_host_ip", return_value=None ) @mock.patch("cloudinit.distros.alpine.subp.subp") @mock.patch( diff --git a/tests/unittests/distros/test_create_users.py b/tests/unittests/distros/test_create_users.py index 929aeb0d7ef..c16cf1faa48 100644 --- a/tests/unittests/distros/test_create_users.py +++ b/tests/unittests/distros/test_create_users.py @@ -18,7 +18,7 @@ def common_mocks(mocker): mocker.patch("cloudinit.distros.util.system_is_snappy", return_value=False) mocker.patch( - "cloudinit.log.security_event_log._get_host_ip", return_value=None + "cloudinit.log.security_event_log.get_host_ip", return_value=None ) diff --git a/tests/unittests/distros/test_dragonflybsd.py b/tests/unittests/distros/test_dragonflybsd.py index 72fa8872fdf..772d6d6d909 100644 --- a/tests/unittests/distros/test_dragonflybsd.py +++ b/tests/unittests/distros/test_dragonflybsd.py @@ -8,7 +8,7 @@ class TestDragonFlyBSD: @mock.patch( - "cloudinit.log.security_event_log._get_host_ip", return_value=None + "cloudinit.log.security_event_log.get_host_ip", return_value=None ) @mock.patch(M_PATH + "subp.subp") def test_add_user(self, m_subp, _get_host_ip): diff --git a/tests/unittests/distros/test_freebsd.py b/tests/unittests/distros/test_freebsd.py index 3897446cc54..6051e0a3b49 100644 --- a/tests/unittests/distros/test_freebsd.py +++ b/tests/unittests/distros/test_freebsd.py @@ -10,7 +10,7 @@ class TestFreeBSD: @mock.patch( - "cloudinit.log.security_event_log._get_host_ip", return_value=None + "cloudinit.log.security_event_log.get_host_ip", return_value=None ) @mock.patch(M_PATH + "subp.subp") def test_add_user(self, m_subp, _get_host_ip): diff --git a/tests/unittests/distros/test_netbsd.py b/tests/unittests/distros/test_netbsd.py index 963024dee7c..592c791d15f 100644 --- a/tests/unittests/distros/test_netbsd.py +++ b/tests/unittests/distros/test_netbsd.py @@ -17,7 +17,7 @@ class TestNetBSD: @mock.patch( - "cloudinit.log.security_event_log._get_host_ip", return_value=None + "cloudinit.log.security_event_log.get_host_ip", return_value=None ) @mock.patch(M_PATH + "subp.subp") def test_add_user(self, m_subp, _get_host_ip): diff --git a/tests/unittests/distros/test_openbsd.py b/tests/unittests/distros/test_openbsd.py index ed90cbd42b4..e827482a8ad 100644 --- a/tests/unittests/distros/test_openbsd.py +++ b/tests/unittests/distros/test_openbsd.py @@ -7,7 +7,7 @@ class TestOpenBSD: @mock.patch( - "cloudinit.log.security_event_log._get_host_ip", return_value=None + "cloudinit.log.security_event_log.get_host_ip", return_value=None ) @mock.patch(M_PATH + "subp.subp") def test_add_user(self, m_subp, _get_host_ip): diff --git a/tests/unittests/distros/test_passwords.py b/tests/unittests/distros/test_passwords.py index 4f8dbddda6a..80faad72105 100644 --- a/tests/unittests/distros/test_passwords.py +++ b/tests/unittests/distros/test_passwords.py @@ -11,7 +11,7 @@ @pytest.fixture(autouse=True) def common_mocks(mocker): mocker.patch( - "cloudinit.log.security_event_log._get_host_ip", return_value=None + "cloudinit.log.security_event_log.get_host_ip", return_value=None ) diff --git a/tests/unittests/distros/test_user_data_normalize.py b/tests/unittests/distros/test_user_data_normalize.py index 052b0e5ccf8..ecbaca11b45 100644 --- a/tests/unittests/distros/test_user_data_normalize.py +++ b/tests/unittests/distros/test_user_data_normalize.py @@ -268,7 +268,7 @@ def test_users_dict(self): assert {"default": False} == users["bob"] @mock.patch( - "cloudinit.log.security_event_log._get_host_ip", return_value=None + "cloudinit.log.security_event_log.get_host_ip", return_value=None ) @mock.patch("cloudinit.subp.subp") def test_create_snap_user(self, mock_subp, _get_host_ip, caplog): @@ -291,7 +291,7 @@ def test_create_snap_user(self, mock_subp, _get_host_ip, caplog): assert "user_created:cloud-init,joe" == event["event"] @mock.patch( - "cloudinit.log.security_event_log._get_host_ip", return_value=None + "cloudinit.log.security_event_log.get_host_ip", return_value=None ) @mock.patch("cloudinit.subp.subp") def test_create_snap_user_known(self, mock_subp, _get_host_ip, caplog): diff --git a/tests/unittests/log/test_security_event_log.py b/tests/unittests/log/test_security_event_log.py index fbd1358bd70..8d4d7ff3f32 100644 --- a/tests/unittests/log/test_security_event_log.py +++ b/tests/unittests/log/test_security_event_log.py @@ -23,7 +23,7 @@ @pytest.fixture def host_ip(mocker): mocker.patch.object( - security_event_log, "_get_host_ip", return_value="10.42.42.42" + security_event_log, "get_host_ip", return_value="10.42.42.42" ) yield @@ -339,118 +339,6 @@ def shutdown_test(mode, delay): assert expected == event -class TestGetHostIp: - """Tests for _get_host_ip IPv4/IPv6 address resolution.""" - - @pytest.mark.parametrize( - "netdev_response,expected_ip", - [ - pytest.param( - { - "eth0": { - "up": True, - "ipv4": [{"ip": "10.0.0.1", "scope": "global"}], - "ipv6": [], - } - }, - "10.0.0.1", - id="global_ipv4", - ), - pytest.param( - { - "eth0": { - "up": True, - "ipv4": [], - "ipv6": [ - {"ip": "fd42::1/64", "scope6": "global"}, - {"ip": "fe80::1/64", "scope6": "link"}, - ], - } - }, - "fd42::1", - id="fallback_to_global_ipv6", - ), - pytest.param( - { - "eth0": { - "up": True, - "ipv4": [], - "ipv6": [ - { - "ip": "fd42:baa2:3dd:17a::1/64", - "scope6": "global", - } - ], - } - }, - "fd42:baa2:3dd:17a::1", - id="ipv6_prefix_stripped", - ), - pytest.param( - { - "eth0": { - "up": True, - "ipv4": [{"ip": "10.0.0.1", "scope": "global"}], - "ipv6": [{"ip": "fd42::1/64", "scope6": "global"}], - } - }, - "10.0.0.1", - id="prefers_ipv4_over_ipv6", - ), - pytest.param( - { - "lo": { - "up": True, - "ipv4": [{"ip": "127.0.0.1", "scope": "host"}], - "ipv6": [{"ip": "::1/128", "scope6": "host"}], - }, - "eth0": { - "up": True, - "ipv4": [], - "ipv6": [{"ip": "fd42::1/64", "scope6": "global"}], - }, - }, - "fd42::1", - id="skips_loopback", - ), - pytest.param( - { - "eth0": { - "up": False, - "ipv4": [{"ip": "10.0.0.1", "scope": "global"}], - "ipv6": [{"ip": "fd42::1/64", "scope6": "global"}], - } - }, - None, - id="skips_down_interfaces", - ), - pytest.param( - { - "eth0": { - "up": True, - "ipv4": [], - "ipv6": [{"ip": "fe80::1/64", "scope6": "link"}], - } - }, - None, - id="ignores_link_local_ipv6", - ), - pytest.param( - Exception("network unavailable"), - None, - id="exception_returns_none", - ), - ], - ) - def test_get_host_ip(self, mocker, netdev_response, expected_ip): - """Test _get_host_ip returns the correct IP address or None.""" - if isinstance(netdev_response, Exception): - mocker.patch(MPATH + "netdev_info", side_effect=netdev_response) - else: - mocker.patch(MPATH + "netdev_info", return_value=netdev_response) - assert security_event_log._get_host_ip() == expected_ip - - class TestHostIpInSecurityEvent: """Tests that host_ip is correctly populated in logged security events.""" @@ -463,9 +351,9 @@ class TestHostIpInSecurityEvent: ], ) def test_event_logs_host_ip(self, host_ip, mocker, caplog): - """Security event records host_ip returned by _get_host_ip.""" + """Security event records host_ip returned by get_host_ip.""" mocker.patch.object( - security_event_log, "_get_host_ip", return_value=host_ip + security_event_log, "get_host_ip", return_value=host_ip ) with caplog.at_level(loggers.SECURITY): security_event_log._log_security_event( diff --git a/tests/unittests/test_netinfo.py b/tests/unittests/test_netinfo.py index 90f78356a9d..03223aaa35e 100644 --- a/tests/unittests/test_netinfo.py +++ b/tests/unittests/test_netinfo.py @@ -10,6 +10,7 @@ from cloudinit import subp from cloudinit.netinfo import ( _netdev_info_iproute_json, + get_host_ip, netdev_info, netdev_pformat, route_pformat, @@ -375,3 +376,119 @@ def test_route_warn_on_missing_commands(self, m_subp, m_which, caplog): def test_netdev_info_iproute_json(self, input, expected): out = _netdev_info_iproute_json(json.dumps(input)) assert out == expected + + +class TestGetHostIP: + """Tests for get_host_ip IPv4/IPv6 address resolution.""" + + @pytest.mark.parametrize( + "netdev_response,expected_ip", + [ + pytest.param( + { + "eth0": { + "up": True, + "ipv4": [{"ip": "10.0.0.1", "scope": "global"}], + "ipv6": [], + } + }, + "10.0.0.1", + id="global_ipv4", + ), + pytest.param( + { + "eth0": { + "up": True, + "ipv4": [], + "ipv6": [ + {"ip": "fd42::1/64", "scope6": "global"}, + {"ip": "fe80::1/64", "scope6": "link"}, + ], + } + }, + "fd42::1", + id="fallback_to_global_ipv6", + ), + pytest.param( + { + "eth0": { + "up": True, + "ipv4": [], + "ipv6": [ + { + "ip": "fd42:baa2:3dd:17a::1/64", + "scope6": "global", + } + ], + } + }, + "fd42:baa2:3dd:17a::1", + id="ipv6_prefix_stripped", + ), + pytest.param( + { + "eth0": { + "up": True, + "ipv4": [{"ip": "10.0.0.1", "scope": "global"}], + "ipv6": [{"ip": "fd42::1/64", "scope6": "global"}], + } + }, + "10.0.0.1", + id="prefers_ipv4_over_ipv6", + ), + pytest.param( + { + "lo": { + "up": True, + "ipv4": [{"ip": "127.0.0.1", "scope": "host"}], + "ipv6": [{"ip": "::1/128", "scope6": "host"}], + }, + "eth0": { + "up": True, + "ipv4": [], + "ipv6": [{"ip": "fd42::1/64", "scope6": "global"}], + }, + }, + "fd42::1", + id="skips_loopback", + ), + pytest.param( + { + "eth0": { + "up": False, + "ipv4": [{"ip": "10.0.0.1", "scope": "global"}], + "ipv6": [{"ip": "fd42::1/64", "scope6": "global"}], + } + }, + None, + id="skips_down_interfaces", + ), + pytest.param( + { + "eth0": { + "up": True, + "ipv4": [], + "ipv6": [{"ip": "fe80::1/64", "scope6": "link"}], + } + }, + None, + id="ignores_link_local_ipv6", + ), + pytest.param( + Exception("network unavailable"), + None, + id="exception_returns_none", + ), + ], + ) + def test_get_host_ip(self, mocker, netdev_response, expected_ip): + """Test _get_host_ip returns the correct IP address or None.""" + if isinstance(netdev_response, Exception): + mocker.patch( + "cloudinit.netinfo.netdev_info", side_effect=netdev_response + ) + else: + mocker.patch( + "cloudinit.netinfo.netdev_info", return_value=netdev_response + ) + assert get_host_ip() == expected_ip From 52333965c29b833879b9049f0fdfb825c422a5d8 Mon Sep 17 00:00:00 2001 From: Chad Smith Date: Tue, 10 Mar 2026 11:42:36 -0600 Subject: [PATCH 14/31] fix: provide mode and delay values in shutdown sec events --- cloudinit/log/security_event_log.py | 36 ++++++------------- .../unittests/log/test_security_event_log.py | 36 +++++++++++++++---- 2 files changed, 39 insertions(+), 33 deletions(-) diff --git a/cloudinit/log/security_event_log.py b/cloudinit/log/security_event_log.py index 71efbcfa591..58380ede428 100644 --- a/cloudinit/log/security_event_log.py +++ b/cloudinit/log/security_event_log.py @@ -43,12 +43,7 @@ class OWASPEventLevel(Enum): class OWASPEventType(Enum): - """ - OWASP security event types. - - Format: category_event_name - Events are logged as: event_type:param1,param2,... - """ + """OWASP security event types.""" # Authentication events [AUTHN] AUTHN_PASSWORD_CHANGE = "authn_password_change" @@ -112,9 +107,9 @@ def _build_security_event( event["host_ip"] = host_ip if additional_data: - # Merge additional data but don't overwrite core fields + # Merge additional non-empty data but don't overwrite core fields for key, value in additional_data.items(): - if key not in event: + if key not in event and value: event[key] = value return event @@ -147,13 +142,7 @@ def _log_security_event( def sec_log_user_created(func): - """ - A decorator to log a user creation event and group attributes. - - :param userid: The user/process that initiated the action. - :param new_userid: The username of the newly created user. - :param attributes: Additional user attributes (groups, shell, etc.). - """ + """A decorator to log a user creation event and group attributes.""" @functools.wraps(func) def decorator(*args, **kwargs): @@ -237,28 +226,23 @@ def sec_log_system_shutdown(func): """A decorator logging a system shutdown event.""" @functools.wraps(func) - def decorator(*args, **kwargs): - mode = kwargs["mode"] - delay = kwargs["delay"] - - additional = {} + def decorator(cls, mode, delay, message): if mode == "reboot": event_type = OWASPEventType.SYS_RESTART description = "System restart initiated" else: event_type = OWASPEventType.SYS_SHUTDOWN - description = f"System shutdown initiated (mode={mode})" - additional["mode"] = mode - if delay: - additional["delay"] = delay + description = "System shutdown initiated" + if message: + description += f": {message}" _log_security_event( event_type=event_type, level=OWASPEventLevel.INFO, description=description, event_params=["cloud-init"], - additional_data=additional if additional else None, + additional_data={"delay": delay, "mode": mode}, ) - return func(*args, **kwargs) + return func(cls, mode=mode, delay=delay, message=message) return decorator diff --git a/tests/unittests/log/test_security_event_log.py b/tests/unittests/log/test_security_event_log.py index 8d4d7ff3f32..10a3319acc5 100644 --- a/tests/unittests/log/test_security_event_log.py +++ b/tests/unittests/log/test_security_event_log.py @@ -289,37 +289,58 @@ class TestSystemShutdownEvent: """Tests for sec_log_system_shutdown function.""" @pytest.mark.parametrize( - "mode,delay,expected_event,expected_descr", + "mode,delay,message,expected_event,expected_descr", [ pytest.param( "poweroff", "+5", + "", "sys_shutdown:cloud-init", - "System shutdown initiated (mode=poweroff)", + "System shutdown initiated", id="poweroff_with_delay", ), pytest.param( "reboot", "now", + None, "sys_restart:cloud-init", "System restart initiated", id="reboot_immediate", ), + pytest.param( + "reboot", + "now", + "Restart FTW", + "sys_restart:cloud-init", + "System restart initiated: Restart FTW", + id="reboot_immediate", + ), ], ) def test_logs_system_shutdown_event( - self, mode, delay, expected_event, expected_descr, host_ip, caplog + self, + mode, + delay, + message, + expected_event, + expected_descr, + host_ip, + caplog, ): """Test logging a system shutdown event.""" - @sec_log_system_shutdown - def shutdown_test(mode, delay): - pass + class DecoratedShutDownTest: + @sec_log_system_shutdown + def shutdown_test(cls, mode, delay, message): + pass + + method_test = DecoratedShutDownTest() with caplog.at_level(loggers.SECURITY): - shutdown_test( + method_test.shutdown_test( mode=mode, delay=delay, + message=message, ) event = json.loads(caplog.records[0].msg) @@ -332,6 +353,7 @@ def shutdown_test(mode, delay): "host_ip": "10.42.42.42", "hostname": get_hostname(), "level": "INFO", + "mode": "reboot", "type": "security", } if mode != "reboot": From 2032bd33661944a9a8e62642649d478d91f16779 Mon Sep 17 00:00:00 2001 From: Chad Smith Date: Tue, 10 Mar 2026 13:01:40 -0600 Subject: [PATCH 15/31] fix: address mypy and ai review comments - drop unintended @final from Distro.set_passwd - simplify sec_log decorators to assume positional param idx 1 when kwarg empty - drop unchecked bool return values from _post_add_user --- cloudinit/distros/__init__.py | 1 - cloudinit/distros/alpine.py | 6 ++--- cloudinit/log/security_event_log.py | 9 ++----- .../modules/test_combined.py | 5 ++-- tests/unittests/distros/test_create_users.py | 13 ++++------ .../unittests/log/test_security_event_log.py | 24 ++++++++++++------- 6 files changed, 27 insertions(+), 31 deletions(-) diff --git a/cloudinit/distros/__init__.py b/cloudinit/distros/__init__.py index 39808efbc04..c514437e291 100644 --- a/cloudinit/distros/__init__.py +++ b/cloudinit/distros/__init__.py @@ -1113,7 +1113,6 @@ def expire_passwd(self, user): util.logexc(LOG, "Failed to set 'expire' for %s", user) raise e - @final @sec_log_password_changed def set_passwd(self, user, passwd, hashed=False): pass_string = "%s:%s" % (user, passwd) diff --git a/cloudinit/distros/alpine.py b/cloudinit/distros/alpine.py index 0df03529341..ab2a5f5cb2c 100644 --- a/cloudinit/distros/alpine.py +++ b/cloudinit/distros/alpine.py @@ -257,10 +257,10 @@ def _build_add_user_cmd( return adduser_cmd, adduser_cmd - def _post_add_user(self, name: str, **kwargs) -> bool: + def _post_add_user(self, name: str, **kwargs): # When useradd is available, the GNU implementation handles everything. if subp.which("useradd"): - return True + return # Busybox post-creation steps. @@ -368,8 +368,6 @@ def _post_add_user(self, name: str, **kwargs) -> bool: LOG, "Failed to update %s for user %s", shadow_file, name ) - return True - def lock_passwd(self, name): """ Lock the password of a user, i.e., disable password logins diff --git a/cloudinit/log/security_event_log.py b/cloudinit/log/security_event_log.py index 58380ede428..d4d84aa1aba 100644 --- a/cloudinit/log/security_event_log.py +++ b/cloudinit/log/security_event_log.py @@ -157,10 +157,8 @@ def decorator(*args, **kwargs): if groups_suffix: if isinstance(groups_suffix, (dict, list)): groups_suffix = ",".join(groups_suffix) - elif isinstance(groups_suffix, list): - groups_suffix = ",".join(groups_suffix) for perms in ("sudo", "doas"): - if kwargs.get(perms) is True: + if kwargs.get(perms): groups_suffix += f",{perms}" if groups_suffix: groups_suffix = groups_suffix.strip(",") @@ -207,10 +205,7 @@ def decorator(*args, **kwargs): response = func(*args, **kwargs) userid = kwargs.get("user") if not userid: - for arg in args: - if isinstance(arg, str): - userid = arg - break + userid = args[1] _log_security_event( event_type=OWASPEventType.AUTHN_PASSWORD_CHANGE, level=OWASPEventLevel.INFO, diff --git a/tests/integration_tests/modules/test_combined.py b/tests/integration_tests/modules/test_combined.py index 91413c7dd18..45a1f468763 100644 --- a/tests/integration_tests/modules/test_combined.py +++ b/tests/integration_tests/modules/test_combined.py @@ -232,7 +232,7 @@ def test_security_logs(self, class_client: IntegrationInstance): "/var/log/cloud-init-security.log" ).splitlines() ] - assert len(security_logs) == 1 + assert len(security_logs) >= 1 expected_security_logs = [ { "appid": "canonical.cloud-init", @@ -246,7 +246,8 @@ def test_security_logs(self, class_client: IntegrationInstance): ] for security_log in security_logs: assert security_log.pop("datetime") - assert expected_security_logs == security_logs + for expected_log in expected_security_logs: + assert expected_log in security_logs def test_runcmd(self, class_client: IntegrationInstance): """Test runcmd works as expected""" diff --git a/tests/unittests/distros/test_create_users.py b/tests/unittests/distros/test_create_users.py index c16cf1faa48..a69ca46f42d 100644 --- a/tests/unittests/distros/test_create_users.py +++ b/tests/unittests/distros/test_create_users.py @@ -452,14 +452,11 @@ def test_create_passwd_existing_user( for log in expected_logs: assert log in caplog.text assert m_subp.call_args_list == expected - if "passwd" in create_kwargs: - "authn_password_change:cloud-init,clearfoo" in caplog.records[ - -1 - ].msg - else: - "authn_password_change:cloud-init,clearfoo" in caplog.records[ - -1 - ].msg + if "passwd" not in create_kwargs: + assert ( + "authn_password_change:cloud-init,foo_user" + in caplog.records[-1].msg + ) @mock.patch("cloudinit.distros.util.is_group") def test_group_added(self, m_is_group, m_subp, dist, mocker): diff --git a/tests/unittests/log/test_security_event_log.py b/tests/unittests/log/test_security_event_log.py index 10a3319acc5..ad366b8216c 100644 --- a/tests/unittests/log/test_security_event_log.py +++ b/tests/unittests/log/test_security_event_log.py @@ -232,13 +232,16 @@ class TestPasswordChangedEvent: def test_logs_password_changed_event(self, host_ip, caplog): """Test logging a password change event.""" - @sec_log_password_changed - def set_passwd_test(user): - pass + class DecoratedSetPasswordTest: + @sec_log_password_changed + def set_passwd(self, user): + pass + + method_test = DecoratedSetPasswordTest() with caplog.at_level(loggers.SECURITY): - set_passwd_test(user="testuser") - set_passwd_test("testuser") # Test with positional params + method_test.set_passwd(user="testuser") + method_test.set_passwd("testuser") # Test positional params expected_value = { "appid": "canonical.cloud-init", @@ -262,12 +265,15 @@ class TestPasswordChangedBatchEvent: def test_logs_password_changed_event_for_each_user(self, host_ip, caplog): """Test logging a password change event.""" - @sec_log_password_changed_batch - def set_passwd_test(plist_in): - pass + class DecoratedChpasswdTest: + @sec_log_password_changed_batch + def chpasswd(self, plist_in): + pass + + method_test = DecoratedChpasswdTest() with caplog.at_level(loggers.SECURITY): - set_passwd_test(plist_in=(("testuser", "pw1"),)) + method_test.chpasswd(plist_in=(("testuser", "pw1"),)) expected_value = { "appid": "canonical.cloud-init", From 967ebbd38e95b347c6c94629afd374e0769a9a19 Mon Sep 17 00:00:00 2001 From: Chad Smith Date: Tue, 10 Mar 2026 13:10:38 -0600 Subject: [PATCH 16/31] fix: mypy errors for @final Distro methods --- tests/unittests/util.py | 5 +++-- 1 file changed, 3 insertions(+), 2 deletions(-) diff --git a/tests/unittests/util.py b/tests/unittests/util.py index 694282d5a6f..71f70a126fe 100644 --- a/tests/unittests/util.py +++ b/tests/unittests/util.py @@ -144,14 +144,15 @@ def update_hostname(self, hostname, fqdn, prev_hostname_fn): def update_etc_hosts(self, hostname, fqdn): pass + @security_event_log.sec_log_user_created # type: ignore[misc] def add_user(self, name, **kwargs): pass + @security_event_log.sec_log_user_created # type: ignore[misc] def add_snap_user(self, name, **kwargs): return "snap_user" - @security_event_log.sec_log_user_created # type: ignore[misc] - def create_user(self, name, **kwargs): + def create_user(self, name, **kwargs): # type: ignore[misc] return True def lock_passwd(self, name): From 8eafe51b8d41a7f8ebd921f67a170053c52fe9e3 Mon Sep 17 00:00:00 2001 From: Chad Smith Date: Tue, 10 Mar 2026 14:39:34 -0600 Subject: [PATCH 17/31] fix: pylint issues --- cloudinit/netinfo.py | 2 +- tests/unittests/log/test_security_event_log.py | 1 + tests/unittests/util.py | 16 ++++++++++++---- 3 files changed, 14 insertions(+), 5 deletions(-) diff --git a/cloudinit/netinfo.py b/cloudinit/netinfo.py index 2374972cd0b..e1a0f11c43c 100644 --- a/cloudinit/netinfo.py +++ b/cloudinit/netinfo.py @@ -384,7 +384,7 @@ def get_host_ip() -> Optional[str]: """ try: first_ipv6: Optional[str] = None - for iface, info in netdev_info().items(): + for _, info in netdev_info().items(): if not info["up"]: continue ipv4: List[dict] = info.get("ipv4", []) diff --git a/tests/unittests/log/test_security_event_log.py b/tests/unittests/log/test_security_event_log.py index ad366b8216c..cb1a0818b59 100644 --- a/tests/unittests/log/test_security_event_log.py +++ b/tests/unittests/log/test_security_event_log.py @@ -336,6 +336,7 @@ def test_logs_system_shutdown_event( """Test logging a system shutdown event.""" class DecoratedShutDownTest: + @classmethod @sec_log_system_shutdown def shutdown_test(cls, mode, delay, message): pass diff --git a/tests/unittests/util.py b/tests/unittests/util.py index 71f70a126fe..e350603e1d0 100644 --- a/tests/unittests/util.py +++ b/tests/unittests/util.py @@ -145,14 +145,20 @@ def update_etc_hosts(self, hostname, fqdn): pass @security_event_log.sec_log_user_created # type: ignore[misc] - def add_user(self, name, **kwargs): + def add_user( + self, name, **kwargs + ): # pylint: disable=overridden-final-method pass @security_event_log.sec_log_user_created # type: ignore[misc] - def add_snap_user(self, name, **kwargs): + def add_snap_user( + self, name, **kwargs + ): # pylint: disable=overridden-final-method return "snap_user" - def create_user(self, name, **kwargs): # type: ignore[misc] + def create_user( + self, name, **kwargs + ): # pylint: disable=overridden-final-method return True def lock_passwd(self, name): @@ -174,7 +180,9 @@ def create_group(self, name, members=None): pass @security_event_log.sec_log_system_shutdown # type: ignore[misc] - def shutdown_command(self, *, mode, delay, message): + def shutdown_command( + self, *, mode, delay, message + ): # pylint: disable=overridden-final-method pass def package_command(self, command, args=None, pkgs=None): From 9aebc9be9bd51b1c3c33dd10320fbc44cbb4ea1f Mon Sep 17 00:00:00 2001 From: Chad Smith Date: Tue, 10 Mar 2026 14:53:29 -0600 Subject: [PATCH 18/31] fix: mypy --- tests/unittests/util.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/tests/unittests/util.py b/tests/unittests/util.py index e350603e1d0..689fb9ef5d7 100644 --- a/tests/unittests/util.py +++ b/tests/unittests/util.py @@ -156,7 +156,7 @@ def add_snap_user( ): # pylint: disable=overridden-final-method return "snap_user" - def create_user( + def create_user( # type: ignore[misc] self, name, **kwargs ): # pylint: disable=overridden-final-method return True From 45bc3c70d303ff69f75cdeb80f2afa4b8c64461a Mon Sep 17 00:00:00 2001 From: Chad Smith Date: Tue, 10 Mar 2026 15:11:28 -0600 Subject: [PATCH 19/31] test: add assertion on expeted host_ip --- tests/integration_tests/modules/test_combined.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/tests/integration_tests/modules/test_combined.py b/tests/integration_tests/modules/test_combined.py index 45a1f468763..6ba479cc556 100644 --- a/tests/integration_tests/modules/test_combined.py +++ b/tests/integration_tests/modules/test_combined.py @@ -240,12 +240,12 @@ def test_security_logs(self, class_client: IntegrationInstance): "event": "user_created:cloud-init,craig", "type": "security", "level": "WARN", - "host_ip": client.instance.ip, "hostname": client.instance.name, }, ] for security_log in security_logs: assert security_log.pop("datetime") + assert client.instance.ip == security_log.pop("host_ip") for expected_log in expected_security_logs: assert expected_log in security_logs From 476f0c593e56ddb42513e71e519f7e1740ef6e1d Mon Sep 17 00:00:00 2001 From: Chad Smith Date: Wed, 11 Mar 2026 14:42:56 -0600 Subject: [PATCH 20/31] chore: drop host_ip from owasp logs use hostname for identity instead --- cloudinit/log/security_event_log.py | 5 - cloudinit/netinfo.py | 28 +---- .../modules/test_combined.py | 39 +++--- tests/unittests/cmd/test_clean.py | 5 +- .../config/test_cc_power_state_change.py | 6 - tests/unittests/distros/test_alpine.py | 5 +- tests/unittests/distros/test_create_users.py | 3 - tests/unittests/distros/test_dragonflybsd.py | 5 +- tests/unittests/distros/test_freebsd.py | 5 +- tests/unittests/distros/test_netbsd.py | 5 +- tests/unittests/distros/test_openbsd.py | 5 +- tests/unittests/distros/test_passwords.py | 7 -- .../distros/test_user_data_normalize.py | 10 +- .../unittests/log/test_security_event_log.py | 59 ++------- tests/unittests/test_netinfo.py | 117 ------------------ 15 files changed, 36 insertions(+), 268 deletions(-) diff --git a/cloudinit/log/security_event_log.py b/cloudinit/log/security_event_log.py index d4d84aa1aba..967aa4a8205 100644 --- a/cloudinit/log/security_event_log.py +++ b/cloudinit/log/security_event_log.py @@ -26,7 +26,6 @@ from cloudinit import util from cloudinit.log import loggers -from cloudinit.netinfo import get_host_ip LOG = logging.getLogger(__name__) @@ -102,10 +101,6 @@ def _build_security_event( "description": description, "hostname": util.get_hostname(), } - host_ip = get_host_ip() - if host_ip: - event["host_ip"] = host_ip - if additional_data: # Merge additional non-empty data but don't overwrite core fields for key, value in additional_data.items(): diff --git a/cloudinit/netinfo.py b/cloudinit/netinfo.py index e1a0f11c43c..7e79db0576f 100644 --- a/cloudinit/netinfo.py +++ b/cloudinit/netinfo.py @@ -13,7 +13,7 @@ import re from copy import copy, deepcopy from ipaddress import IPv4Network -from typing import Dict, List, Optional, TypedDict +from typing import Dict, List, TypedDict from cloudinit import lifecycle, subp, util from cloudinit.net.network_state import net_prefix_to_ipv4_mask @@ -376,32 +376,6 @@ def fill(data, new_val="", empty_vals=("", b"")): return devs -def get_host_ip() -> Optional[str]: - """Return the first global IP on an active interface. - - Prefers IPv4; falls back to IPv6 when no global IPv4 is available. - IPv6 addresses are returned without their prefix-length suffix. - """ - try: - first_ipv6: Optional[str] = None - for _, info in netdev_info().items(): - if not info["up"]: - continue - ipv4: List[dict] = info.get("ipv4", []) - for addr in ipv4: - if addr.get("scope") == "global" and addr.get("ip"): - return addr["ip"] - if first_ipv6 is None: - for addr in info.get("ipv6", []): - if addr.get("scope6") == "global" and addr.get("ip"): - first_ipv6 = addr["ip"].split("/")[0] - break - return first_ipv6 - except Exception: - pass - return None - - def _netdev_route_info_iproute(iproute_data): """ Get network route dicts from ip route info. diff --git a/tests/integration_tests/modules/test_combined.py b/tests/integration_tests/modules/test_combined.py index 6ba479cc556..2001c911cac 100644 --- a/tests/integration_tests/modules/test_combined.py +++ b/tests/integration_tests/modules/test_combined.py @@ -10,6 +10,7 @@ import json import re import uuid +from datetime import datetime from pathlib import Path import pytest @@ -226,28 +227,24 @@ def test_rsyslog(self, class_client: IntegrationInstance): def test_security_logs(self, class_client: IntegrationInstance): """Test security logs are set in /var/log/cloud-init-security.log.""" client = class_client - security_logs = [ - json.loads(line) - for line in client.read_from_file( - "/var/log/cloud-init-security.log" - ).splitlines() - ] + security_logs = [] + for line in client.read_from_file( + "/var/log/cloud-init-security.log" + ).splitlines(): + sec_log = json.loads(line) + assert datetime.strptime( + sec_log.pop("datetime"), "%Y-%m-%dT%H:%M:%S.%f+00:00" + ) + security_logs.append(sec_log) assert len(security_logs) >= 1 - expected_security_logs = [ - { - "appid": "canonical.cloud-init", - "description": "User 'craig' was created", - "event": "user_created:cloud-init,craig", - "type": "security", - "level": "WARN", - "hostname": client.instance.name, - }, - ] - for security_log in security_logs: - assert security_log.pop("datetime") - assert client.instance.ip == security_log.pop("host_ip") - for expected_log in expected_security_logs: - assert expected_log in security_logs + assert { + "appid": "canonical.cloud-init", + "description": "User 'craig' was created", + "event": "user_created:cloud-init,craig", + "type": "security", + "level": "WARN", + "hostname": client.instance.name, + } in security_logs def test_runcmd(self, class_client: IntegrationInstance): """Test runcmd works as expected""" diff --git a/tests/unittests/cmd/test_clean.py b/tests/unittests/cmd/test_clean.py index 386570b4479..21dd5752757 100644 --- a/tests/unittests/cmd/test_clean.py +++ b/tests/unittests/cmd/test_clean.py @@ -479,10 +479,7 @@ def test_remove_artifacts_returns_one_on_errors( == err ) - @mock.patch( - "cloudinit.log.security_event_log.get_host_ip", return_value=None - ) - def test_handle_clean_args_reboots(self, _get_host_ip, init_class): + def test_handle_clean_args_reboots(self, init_class): """handle_clean_args_reboots when reboot arg is provided.""" called_cmds = [] diff --git a/tests/unittests/config/test_cc_power_state_change.py b/tests/unittests/config/test_cc_power_state_change.py index 8c474947a87..37901baaab7 100644 --- a/tests/unittests/config/test_cc_power_state_change.py +++ b/tests/unittests/config/test_cc_power_state_change.py @@ -23,12 +23,6 @@ def dist(): class TestLoadPowerState: - @pytest.fixture(autouse=True) - def common_mocks(self, mocker): - mocker.patch( - "cloudinit.log.security_event_log.get_host_ip", return_value=None - ) - def test_no_config(self, dist): # completely empty config should mean do nothing (cmd, _timeout, _condition) = psc.load_power_state({}, dist) diff --git a/tests/unittests/distros/test_alpine.py b/tests/unittests/distros/test_alpine.py index a551abe2f95..966f4e7ef07 100644 --- a/tests/unittests/distros/test_alpine.py +++ b/tests/unittests/distros/test_alpine.py @@ -65,14 +65,11 @@ def test_shadow_add_group(self, m_which, m_subp): m_subp.assert_called_with(["groupadd", group]) - @mock.patch( - "cloudinit.log.security_event_log.get_host_ip", return_value=None - ) @mock.patch("cloudinit.distros.alpine.subp.subp") @mock.patch( "cloudinit.distros.subp.which", return_value=("/usr/sbin/useradd") ) - def test_shadow_add_user(self, m_which, m_subp, _get_host_ip): + def test_shadow_add_user(self, m_which, m_subp): user = "me2" self.distro.add_user(user) diff --git a/tests/unittests/distros/test_create_users.py b/tests/unittests/distros/test_create_users.py index a69ca46f42d..8f9f6b6f6f3 100644 --- a/tests/unittests/distros/test_create_users.py +++ b/tests/unittests/distros/test_create_users.py @@ -17,9 +17,6 @@ @pytest.fixture(autouse=True) def common_mocks(mocker): mocker.patch("cloudinit.distros.util.system_is_snappy", return_value=False) - mocker.patch( - "cloudinit.log.security_event_log.get_host_ip", return_value=None - ) def _chpasswdmock(name: str, password: str, hashed: bool = False): diff --git a/tests/unittests/distros/test_dragonflybsd.py b/tests/unittests/distros/test_dragonflybsd.py index 772d6d6d909..51ea4b9f191 100644 --- a/tests/unittests/distros/test_dragonflybsd.py +++ b/tests/unittests/distros/test_dragonflybsd.py @@ -7,11 +7,8 @@ class TestDragonFlyBSD: - @mock.patch( - "cloudinit.log.security_event_log.get_host_ip", return_value=None - ) @mock.patch(M_PATH + "subp.subp") - def test_add_user(self, m_subp, _get_host_ip): + def test_add_user(self, m_subp): distro = get_distro("dragonflybsd") distro.add_user("me2", uid=1234, default=False) assert [ diff --git a/tests/unittests/distros/test_freebsd.py b/tests/unittests/distros/test_freebsd.py index 6051e0a3b49..20b2788880a 100644 --- a/tests/unittests/distros/test_freebsd.py +++ b/tests/unittests/distros/test_freebsd.py @@ -9,11 +9,8 @@ class TestFreeBSD: - @mock.patch( - "cloudinit.log.security_event_log.get_host_ip", return_value=None - ) @mock.patch(M_PATH + "subp.subp") - def test_add_user(self, m_subp, _get_host_ip): + def test_add_user(self, m_subp): distro = get_distro("freebsd") distro.add_user("me2", uid=1234, default=False) assert [ diff --git a/tests/unittests/distros/test_netbsd.py b/tests/unittests/distros/test_netbsd.py index 592c791d15f..aa71510ea8d 100644 --- a/tests/unittests/distros/test_netbsd.py +++ b/tests/unittests/distros/test_netbsd.py @@ -16,11 +16,8 @@ class TestNetBSD: - @mock.patch( - "cloudinit.log.security_event_log.get_host_ip", return_value=None - ) @mock.patch(M_PATH + "subp.subp") - def test_add_user(self, m_subp, _get_host_ip): + def test_add_user(self, m_subp): distro = get_distro("netbsd") distro.add_user("me2", uid=1234, default=False) assert [ diff --git a/tests/unittests/distros/test_openbsd.py b/tests/unittests/distros/test_openbsd.py index e827482a8ad..73eb435fab0 100644 --- a/tests/unittests/distros/test_openbsd.py +++ b/tests/unittests/distros/test_openbsd.py @@ -6,11 +6,8 @@ class TestOpenBSD: - @mock.patch( - "cloudinit.log.security_event_log.get_host_ip", return_value=None - ) @mock.patch(M_PATH + "subp.subp") - def test_add_user(self, m_subp, _get_host_ip): + def test_add_user(self, m_subp): distro = get_distro("openbsd") distro.add_user("me2", uid=1234, default=False) assert [ diff --git a/tests/unittests/distros/test_passwords.py b/tests/unittests/distros/test_passwords.py index 80faad72105..0da18bb90bf 100644 --- a/tests/unittests/distros/test_passwords.py +++ b/tests/unittests/distros/test_passwords.py @@ -8,13 +8,6 @@ USER = "foo_user" -@pytest.fixture(autouse=True) -def common_mocks(mocker): - mocker.patch( - "cloudinit.log.security_event_log.get_host_ip", return_value=None - ) - - @mock.patch("cloudinit.distros.subp.subp") class TestChpasswd: diff --git a/tests/unittests/distros/test_user_data_normalize.py b/tests/unittests/distros/test_user_data_normalize.py index ecbaca11b45..47444830432 100644 --- a/tests/unittests/distros/test_user_data_normalize.py +++ b/tests/unittests/distros/test_user_data_normalize.py @@ -267,11 +267,8 @@ def test_users_dict(self): assert {"default": False} == users["joe"] assert {"default": False} == users["bob"] - @mock.patch( - "cloudinit.log.security_event_log.get_host_ip", return_value=None - ) @mock.patch("cloudinit.subp.subp") - def test_create_snap_user(self, mock_subp, _get_host_ip, caplog): + def test_create_snap_user(self, mock_subp, caplog): mock_subp.side_effect = [ ('{"username": "joe", "ssh-key-count": 1}\n', "") ] @@ -290,11 +287,8 @@ def test_create_snap_user(self, mock_subp, _get_host_ip, caplog): event = json.loads(caplog.records[-1].msg) assert "user_created:cloud-init,joe" == event["event"] - @mock.patch( - "cloudinit.log.security_event_log.get_host_ip", return_value=None - ) @mock.patch("cloudinit.subp.subp") - def test_create_snap_user_known(self, mock_subp, _get_host_ip, caplog): + def test_create_snap_user_known(self, mock_subp, caplog): mock_subp.side_effect = [ ('{"username": "joe", "ssh-key-count": 1}\n', "") ] diff --git a/tests/unittests/log/test_security_event_log.py b/tests/unittests/log/test_security_event_log.py index cb1a0818b59..997b06ab7a9 100644 --- a/tests/unittests/log/test_security_event_log.py +++ b/tests/unittests/log/test_security_event_log.py @@ -20,14 +20,6 @@ MPATH = "cloudinit.log.security_event_log." -@pytest.fixture -def host_ip(mocker): - mocker.patch.object( - security_event_log, "get_host_ip", return_value="10.42.42.42" - ) - yield - - class TestBuildEventString: """Tests for _build_event_string function.""" @@ -69,7 +61,7 @@ def test_event_string_formatting(self, event_type, params, expected): class TestBuildSecurityEvent: """Tests for _build_security_event function.""" - def test_event_contains_required_owasp_fields(self, host_ip): + def test_event_contains_required_owasp_fields(self): """Test that built event contains all required OWASP fields.""" event = security_event_log._build_security_event( event_type=OWASPEventType.USER_CREATED, @@ -85,7 +77,7 @@ def test_event_contains_required_owasp_fields(self, host_ip): assert event["description"] == "Test event" assert "hostname" in event - def test_event_with_additional_data(self, host_ip): + def test_event_with_additional_data(self): """Test event includes additional data when provided.""" event = security_event_log._build_security_event( event_type=OWASPEventType.USER_CREATED, @@ -97,7 +89,7 @@ def test_event_with_additional_data(self, host_ip): assert event["groups"] == "wheel" assert event["shell"] == "/bin/bash" - def test_additional_data_does_not_overwrite_core_fields(self, host_ip): + def test_additional_data_does_not_overwrite_core_fields(self): """Test that additional data cannot overwrite core fields.""" event = security_event_log._build_security_event( event_type=OWASPEventType.USER_CREATED, @@ -109,7 +101,7 @@ def test_additional_data_does_not_overwrite_core_fields(self, host_ip): assert event["appid"] == "canonical.cloud-init" assert event["level"] == "INFO" - def test_timestamp_is_iso_format(self, host_ip): + def test_timestamp_is_iso_format(self): """Test that datetime is in ISO 8601 format.""" event = security_event_log._build_security_event( event_type=OWASPEventType.USER_CREATED, @@ -126,7 +118,7 @@ def test_timestamp_is_iso_format(self, host_ip): class TestLogSecurityEvent: """Tests for _log_security_event function.""" - def test_writes_json_to_file(self, host_ip, caplog): + def test_writes_json_to_file(self, caplog): """Test that event is written to log file as JSON.""" with caplog.at_level(loggers.SECURITY): security_event_log._log_security_event( @@ -141,7 +133,7 @@ def test_writes_json_to_file(self, host_ip, caplog): assert event["level"] == "INFO" assert event["appid"] == "canonical.cloud-init" - def test_appends_multiple_events(self, host_ip, caplog): + def test_appends_multiple_events(self, caplog): """Test that multiple events are appended to the log file.""" with caplog.at_level(loggers.SECURITY): security_event_log._log_security_event( @@ -198,7 +190,7 @@ class TestUserCreatedEvent: ], ) def test_logs_user_created_event( - self, uc_kwargs, event_id, description, host_ip, caplog + self, uc_kwargs, event_id, description, caplog ): """Test logging a user creation event.""" @@ -219,7 +211,6 @@ def user_created_decorator_test(name, **kwargs): "appid": "canonical.cloud-init", "event": event_id, "description": description, - "host_ip": "10.42.42.42", "hostname": get_hostname(), "level": "WARN", "type": "security", @@ -229,7 +220,7 @@ def user_created_decorator_test(name, **kwargs): class TestPasswordChangedEvent: """Tests for sec_log_password_changed function.""" - def test_logs_password_changed_event(self, host_ip, caplog): + def test_logs_password_changed_event(self, caplog): """Test logging a password change event.""" class DecoratedSetPasswordTest: @@ -247,7 +238,6 @@ def set_passwd(self, user): "appid": "canonical.cloud-init", "event": "authn_password_change:cloud-init,testuser", "description": "Password changed for user 'testuser'", - "host_ip": "10.42.42.42", "hostname": get_hostname(), "level": "INFO", "type": "security", @@ -262,7 +252,7 @@ def set_passwd(self, user): class TestPasswordChangedBatchEvent: """Tests for sec_log_password_changed_batch function.""" - def test_logs_password_changed_event_for_each_user(self, host_ip, caplog): + def test_logs_password_changed_event_for_each_user(self, caplog): """Test logging a password change event.""" class DecoratedChpasswdTest: @@ -279,7 +269,6 @@ def chpasswd(self, plist_in): "appid": "canonical.cloud-init", "event": "authn_password_change:cloud-init,testuser", "description": "Password changed for user 'testuser'", - "host_ip": "10.42.42.42", "hostname": get_hostname(), "level": "INFO", "type": "security", @@ -330,7 +319,6 @@ def test_logs_system_shutdown_event( message, expected_event, expected_descr, - host_ip, caplog, ): """Test logging a system shutdown event.""" @@ -357,7 +345,6 @@ def shutdown_test(cls, mode, delay, message): "delay": delay, "description": expected_descr, "event": expected_event, - "host_ip": "10.42.42.42", "hostname": get_hostname(), "level": "INFO", "mode": "reboot", @@ -368,34 +355,6 @@ def shutdown_test(cls, mode, delay, message): assert expected == event -class TestHostIpInSecurityEvent: - """Tests that host_ip is correctly populated in logged security events.""" - - @pytest.mark.parametrize( - "host_ip", - [ - pytest.param("10.0.0.1", id="ipv4"), - pytest.param("fd42:baa2:3dd:17a:216:3eff:fe16:db54", id="ipv6"), - pytest.param(None, id="no_network"), - ], - ) - def test_event_logs_host_ip(self, host_ip, mocker, caplog): - """Security event records host_ip returned by get_host_ip.""" - mocker.patch.object( - security_event_log, "get_host_ip", return_value=host_ip - ) - with caplog.at_level(loggers.SECURITY): - security_event_log._log_security_event( - event_type=OWASPEventType.USER_CREATED, - level=OWASPEventLevel.INFO, - description="test", - ) - if host_ip is None: - assert "host_ip" not in json.loads(caplog.records[0].msg) - else: - assert json.loads(caplog.records[0].msg)["host_ip"] == host_ip - - class TestEventTypeEnums: """Tests for event type enum values.""" diff --git a/tests/unittests/test_netinfo.py b/tests/unittests/test_netinfo.py index 03223aaa35e..90f78356a9d 100644 --- a/tests/unittests/test_netinfo.py +++ b/tests/unittests/test_netinfo.py @@ -10,7 +10,6 @@ from cloudinit import subp from cloudinit.netinfo import ( _netdev_info_iproute_json, - get_host_ip, netdev_info, netdev_pformat, route_pformat, @@ -376,119 +375,3 @@ def test_route_warn_on_missing_commands(self, m_subp, m_which, caplog): def test_netdev_info_iproute_json(self, input, expected): out = _netdev_info_iproute_json(json.dumps(input)) assert out == expected - - -class TestGetHostIP: - """Tests for get_host_ip IPv4/IPv6 address resolution.""" - - @pytest.mark.parametrize( - "netdev_response,expected_ip", - [ - pytest.param( - { - "eth0": { - "up": True, - "ipv4": [{"ip": "10.0.0.1", "scope": "global"}], - "ipv6": [], - } - }, - "10.0.0.1", - id="global_ipv4", - ), - pytest.param( - { - "eth0": { - "up": True, - "ipv4": [], - "ipv6": [ - {"ip": "fd42::1/64", "scope6": "global"}, - {"ip": "fe80::1/64", "scope6": "link"}, - ], - } - }, - "fd42::1", - id="fallback_to_global_ipv6", - ), - pytest.param( - { - "eth0": { - "up": True, - "ipv4": [], - "ipv6": [ - { - "ip": "fd42:baa2:3dd:17a::1/64", - "scope6": "global", - } - ], - } - }, - "fd42:baa2:3dd:17a::1", - id="ipv6_prefix_stripped", - ), - pytest.param( - { - "eth0": { - "up": True, - "ipv4": [{"ip": "10.0.0.1", "scope": "global"}], - "ipv6": [{"ip": "fd42::1/64", "scope6": "global"}], - } - }, - "10.0.0.1", - id="prefers_ipv4_over_ipv6", - ), - pytest.param( - { - "lo": { - "up": True, - "ipv4": [{"ip": "127.0.0.1", "scope": "host"}], - "ipv6": [{"ip": "::1/128", "scope6": "host"}], - }, - "eth0": { - "up": True, - "ipv4": [], - "ipv6": [{"ip": "fd42::1/64", "scope6": "global"}], - }, - }, - "fd42::1", - id="skips_loopback", - ), - pytest.param( - { - "eth0": { - "up": False, - "ipv4": [{"ip": "10.0.0.1", "scope": "global"}], - "ipv6": [{"ip": "fd42::1/64", "scope6": "global"}], - } - }, - None, - id="skips_down_interfaces", - ), - pytest.param( - { - "eth0": { - "up": True, - "ipv4": [], - "ipv6": [{"ip": "fe80::1/64", "scope6": "link"}], - } - }, - None, - id="ignores_link_local_ipv6", - ), - pytest.param( - Exception("network unavailable"), - None, - id="exception_returns_none", - ), - ], - ) - def test_get_host_ip(self, mocker, netdev_response, expected_ip): - """Test _get_host_ip returns the correct IP address or None.""" - if isinstance(netdev_response, Exception): - mocker.patch( - "cloudinit.netinfo.netdev_info", side_effect=netdev_response - ) - else: - mocker.patch( - "cloudinit.netinfo.netdev_info", return_value=netdev_response - ) - assert get_host_ip() == expected_ip From 310cac1bbb017036320e3df582485a41a2b40b5f Mon Sep 17 00:00:00 2001 From: Chad Smith Date: Thu, 12 Mar 2026 18:52:49 -0600 Subject: [PATCH 21/31] comments: typing on add_user*, decorators to use mandatory positional args --- cloudinit/distros/__init__.py | 4 +-- cloudinit/distros/alpine.py | 2 +- cloudinit/distros/freebsd.py | 5 ++- cloudinit/distros/netbsd.py | 3 +- cloudinit/distros/raspberry_pi_os.py | 2 +- cloudinit/log/security_event_log.py | 31 +++++++------------ cloudinit/net/dhcp.py | 1 + .../unittests/log/test_security_event_log.py | 9 +++--- 8 files changed, 25 insertions(+), 32 deletions(-) diff --git a/cloudinit/distros/__init__.py b/cloudinit/distros/__init__.py index c514437e291..bf98f3d07d4 100644 --- a/cloudinit/distros/__init__.py +++ b/cloudinit/distros/__init__.py @@ -668,7 +668,7 @@ def get_default_user(self): @final @sec_log_user_created - def add_user(self, name, **kwargs): + def add_user(self, name, **kwargs) -> None: """Add a user to the system.""" self._add_user_preprocess_kwargs(name, kwargs) @@ -793,7 +793,7 @@ def _build_add_user_cmd( return useradd_cmd, log_useradd_cmd - def _post_add_user(self, name: str, **kwargs): + def _post_add_user(self, name: str, **kwargs) -> None: """Hook called after the user-creation command succeeds. Overridden to perform distro-specific post-creation steps. diff --git a/cloudinit/distros/alpine.py b/cloudinit/distros/alpine.py index ab2a5f5cb2c..252727ea65b 100644 --- a/cloudinit/distros/alpine.py +++ b/cloudinit/distros/alpine.py @@ -257,7 +257,7 @@ def _build_add_user_cmd( return adduser_cmd, adduser_cmd - def _post_add_user(self, name: str, **kwargs): + def _post_add_user(self, name: str, **kwargs) -> None: # When useradd is available, the GNU implementation handles everything. if subp.which("useradd"): return diff --git a/cloudinit/distros/freebsd.py b/cloudinit/distros/freebsd.py index 32e3ef3472c..c95469a1b45 100644 --- a/cloudinit/distros/freebsd.py +++ b/cloudinit/distros/freebsd.py @@ -103,7 +103,6 @@ def _build_add_user_cmd( ) -> Tuple[List[str], List[str]]: pw_useradd_cmd = ["pw", "useradd", "-n", name] log_pw_useradd_cmd = ["pw", "useradd", "-n", name] - pw_useradd_opts = { "homedir": "-d", "gecos": "-c", @@ -122,6 +121,7 @@ def _build_add_user_cmd( for key, val in kwargs.items(): if key in pw_useradd_opts and val and isinstance(val, (str, int)): pw_useradd_cmd.extend([pw_useradd_opts[key], str(val)]) + elif key in pw_useradd_flags and val: pw_useradd_cmd.append(pw_useradd_flags[key]) log_pw_useradd_cmd.append(pw_useradd_flags[key]) @@ -138,13 +138,12 @@ def _build_add_user_cmd( return pw_useradd_cmd, log_pw_useradd_cmd - def _post_add_user(self, name: str, **kwargs) -> bool: + def _post_add_user(self, name: str, **kwargs) -> None: # Set the password if it is provided. # For security consideration, only hashed passwd is assumed. passwd_val = kwargs.get("passwd", None) if passwd_val is not None: self.set_passwd(name, passwd_val, hashed=True) - return True def expire_passwd(self, user): try: diff --git a/cloudinit/distros/netbsd.py b/cloudinit/distros/netbsd.py index d0704474790..0ba08cb1b45 100644 --- a/cloudinit/distros/netbsd.py +++ b/cloudinit/distros/netbsd.py @@ -109,13 +109,12 @@ def _build_add_user_cmd( return adduser_cmd, log_adduser_cmd - def _post_add_user(self, name: str, **kwargs) -> bool: + def _post_add_user(self, name: str, **kwargs) -> None: # Set the password if it is provided. # For security consideration, only hashed passwd is assumed. passwd_val = kwargs.get("passwd", None) if passwd_val is not None: self.set_passwd(name, passwd_val, hashed=True) - return True def set_passwd(self, user, passwd, hashed=False): if hashed: diff --git a/cloudinit/distros/raspberry_pi_os.py b/cloudinit/distros/raspberry_pi_os.py index c07c6e2230f..34ca0bd4264 100644 --- a/cloudinit/distros/raspberry_pi_os.py +++ b/cloudinit/distros/raspberry_pi_os.py @@ -67,7 +67,7 @@ def apply_locale(self, locale, out_fn=None, keyname="LANG"): else: LOG.error("Failed to set locale %s", locale) - def _post_add_user(self, name: str, **kwargs): + def _post_add_user(self, name: str, **kwargs) -> None: try: subp.subp( [ diff --git a/cloudinit/log/security_event_log.py b/cloudinit/log/security_event_log.py index 967aa4a8205..e441b8e1042 100644 --- a/cloudinit/log/security_event_log.py +++ b/cloudinit/log/security_event_log.py @@ -140,13 +140,12 @@ def sec_log_user_created(func): """A decorator to log a user creation event and group attributes.""" @functools.wraps(func) - def decorator(*args, **kwargs): - new_userid = args[-1] if args else kwargs.get("name") - if not new_userid: + def decorator(self, name, *args, **kwargs): + if not name: raise RuntimeError( "sec_log_user_created requires positional param name or kwarg" ) - params = ["cloud-init", new_userid] + params = ["cloud-init", name] groups_msg = "" groups_suffix = kwargs.get("groups", "") if groups_suffix: @@ -160,12 +159,12 @@ def decorator(*args, **kwargs): groups_msg = f" in groups: {groups_suffix}" params.append(f"groups:{groups_suffix}") - response = func(*args, **kwargs) + response = func(self, name, *args, **kwargs) # User creation operation did not raise an Exception _log_security_event( event_type=OWASPEventType.USER_CREATED, level=OWASPEventLevel.WARN, - description=f"User '{new_userid}' was created{groups_msg}", + description=f"User '{name}' was created{groups_msg}", event_params=params, ) return response @@ -175,11 +174,8 @@ def decorator(*args, **kwargs): def sec_log_password_changed_batch(func): @functools.wraps(func) - def decorator(*args, **kwargs): - response = func(*args, **kwargs) - plist_in = kwargs.get("plist_in") - if not plist_in: - plist_in = args[1] + def decorator(self, plist_in, *args, **kwargs): + response = func(self, plist_in, *args, **kwargs) for userid, _ in plist_in: _log_security_event( event_type=OWASPEventType.AUTHN_PASSWORD_CHANGE, @@ -196,16 +192,13 @@ def sec_log_password_changed(func): """A decorator logging a password change event.""" @functools.wraps(func) - def decorator(*args, **kwargs): - response = func(*args, **kwargs) - userid = kwargs.get("user") - if not userid: - userid = args[1] + def decorator(self, user: str, *args, **kwargs): + response = func(self, user, *args, **kwargs) _log_security_event( event_type=OWASPEventType.AUTHN_PASSWORD_CHANGE, level=OWASPEventLevel.INFO, - description=f"Password changed for user '{userid}'", - event_params=["cloud-init", userid], + description=f"Password changed for user '{user}'", + event_params=["cloud-init", user], ) return response @@ -216,7 +209,7 @@ def sec_log_system_shutdown(func): """A decorator logging a system shutdown event.""" @functools.wraps(func) - def decorator(cls, mode, delay, message): + def decorator(cls, mode: str, delay: str, message): if mode == "reboot": event_type = OWASPEventType.SYS_RESTART description = "System restart initiated" diff --git a/cloudinit/net/dhcp.py b/cloudinit/net/dhcp.py index 6620b15da26..273b7f10c1f 100644 --- a/cloudinit/net/dhcp.py +++ b/cloudinit/net/dhcp.py @@ -620,6 +620,7 @@ def dhcp_discovery( interface: str, dhcp_log_func: Optional[Callable[[str, str, str], None]] = None, distro=None, + metric=None, ) -> Dict[str, Any]: """Run dhcpcd on the interface without scripts/filesystem artifacts. diff --git a/tests/unittests/log/test_security_event_log.py b/tests/unittests/log/test_security_event_log.py index 997b06ab7a9..4bcf452598d 100644 --- a/tests/unittests/log/test_security_event_log.py +++ b/tests/unittests/log/test_security_event_log.py @@ -194,12 +194,13 @@ def test_logs_user_created_event( ): """Test logging a user creation event.""" - @sec_log_user_created - def user_created_decorator_test(name, **kwargs): - return + class DecoratedSetPasswordTest: + @sec_log_user_created + def user_created_decorator_test(self, name, **kwargs): + return with caplog.at_level(loggers.SECURITY): - user_created_decorator_test( + DecoratedSetPasswordTest().user_created_decorator_test( name="testuser", **uc_kwargs, ) From db03c52923f29712ea19661f80f4e51993360a48 Mon Sep 17 00:00:00 2001 From: Chad Smith Date: Fri, 13 Mar 2026 12:36:09 -0600 Subject: [PATCH 22/31] chore: refactor Distros.shutdown_command Add _build_shutdown_cmd which is subclassed in Alpine. Move pre-flight delay type checking into Distro.shutdown_command and call the _build_shutdown_cmd to construct the distro-specific command. --- cloudinit/distros/__init__.py | 16 +++++++--------- cloudinit/distros/alpine.py | 15 +++------------ 2 files changed, 10 insertions(+), 21 deletions(-) diff --git a/cloudinit/distros/__init__.py b/cloudinit/distros/__init__.py index bf98f3d07d4..2e88aedcceb 100644 --- a/cloudinit/distros/__init__.py +++ b/cloudinit/distros/__init__.py @@ -1347,12 +1347,6 @@ def create_group(self, name, members=None): @final @sec_log_system_shutdown def shutdown_command(cls, *, mode, delay, message): - # called from cc_power_state_change.load_power_state and clean - if hasattr(cls, "_shutdown_command"): # Overridden in alpine.Distro - return cls._shutdown_command( - mode=mode, delay=delay, message=message - ) - command = ["shutdown", cls.shutdown_options_map[mode]] try: if delay != "now": delay = "+%d" % int(delay) @@ -1361,10 +1355,14 @@ def shutdown_command(cls, *, mode, delay, message): "power_state[delay] must be 'now' or '+m' (minutes)." " found '%s'." % (delay,) ) from e - args = command + [delay] + return cls._build_shutdown_command(mode, delay, message) + + @classmethod + def _build_shutdown_command(cls, *, mode, delay, message): + command = ["shutdown", cls.shutdown_options_map[mode], delay] if message: - args.append(message) - return args + command.append(message) + return command @classmethod def reload_init(cls, rcs=None): diff --git a/cloudinit/distros/alpine.py b/cloudinit/distros/alpine.py index 252727ea65b..102fb44465b 100644 --- a/cloudinit/distros/alpine.py +++ b/cloudinit/distros/alpine.py @@ -519,14 +519,12 @@ def create_group(self, name, members=None): LOG.info("Added user '%s' to group '%s'", member, name) @classmethod - def _shutdown_command(cls, mode, delay, message): - # called from cc_power_state_change.load_power_state + def _build_shutdown_cmd(cls, mode, delay, message): # Alpine has halt/poweroff/reboot, with the following specifics: # - we use them rather than the generic "shutdown" # - delay is given with "-d [integer]" # - the integer is in seconds, cannot be "now", and takes no "+" # - no message is supported (argument ignored, here) - command = [mode, "-d"] # Convert delay from minutes to seconds, as Alpine's @@ -535,14 +533,7 @@ def _shutdown_command(cls, mode, delay, message): # Alpine's commands do not understand "now". command += ["0"] else: - try: - command.append(str(int(delay) * 60)) - except ValueError as e: - raise TypeError( - "power_state[delay] must be 'now' or '+m' (minutes)." - " found '%s'." % (delay,) - ) from e - + command.append(str(int(delay) * 60)) return command @staticmethod @@ -554,7 +545,7 @@ def uses_systemd(): @classmethod def manage_service( - self, action: str, service: str, *extra_args: str, rcs=None + cls, action: str, service: str, *extra_args: str, rcs=None ): """ Perform the requested action on a service. This handles OpenRC From 573d590d30addfe9682ab4262d993808d4b28e58 Mon Sep 17 00:00:00 2001 From: Chad Smith Date: Fri, 13 Mar 2026 20:17:06 +0000 Subject: [PATCH 23/31] chore: correct _build_shutdown command call signature --- cloudinit/distros/__init__.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/cloudinit/distros/__init__.py b/cloudinit/distros/__init__.py index 2e88aedcceb..6cb28a3c00c 100644 --- a/cloudinit/distros/__init__.py +++ b/cloudinit/distros/__init__.py @@ -1358,7 +1358,7 @@ def shutdown_command(cls, *, mode, delay, message): return cls._build_shutdown_command(mode, delay, message) @classmethod - def _build_shutdown_command(cls, *, mode, delay, message): + def _build_shutdown_command(cls, mode, delay, message): command = ["shutdown", cls.shutdown_options_map[mode], delay] if message: command.append(message) From 289f2af4c4194905c269fe35c32e5af3e316cb4b Mon Sep 17 00:00:00 2001 From: Chad Smith Date: Fri, 13 Mar 2026 21:57:20 +0000 Subject: [PATCH 24/31] fix: incorrect naming alpine._build_shutdown_cmd --- cloudinit/distros/alpine.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/cloudinit/distros/alpine.py b/cloudinit/distros/alpine.py index 102fb44465b..6a5800870db 100644 --- a/cloudinit/distros/alpine.py +++ b/cloudinit/distros/alpine.py @@ -519,7 +519,7 @@ def create_group(self, name, members=None): LOG.info("Added user '%s' to group '%s'", member, name) @classmethod - def _build_shutdown_cmd(cls, mode, delay, message): + def _build_shutdown_command(cls, mode, delay, message): # Alpine has halt/poweroff/reboot, with the following specifics: # - we use them rather than the generic "shutdown" # - delay is given with "-d [integer]" From 46291caa83229b4dccf481d92868d6ef387cc8b2 Mon Sep 17 00:00:00 2001 From: Chad Smith Date: Fri, 13 Mar 2026 22:02:46 +0000 Subject: [PATCH 25/31] chore: add SecurityFormatter to add datetime to sec logs from record.created --- cloudinit/log/loggers.py | 20 ++- cloudinit/log/security_event_log.py | 40 +----- tests/unittests/distros/test_create_users.py | 8 +- .../distros/test_user_data_normalize.py | 5 +- .../unittests/log/test_security_event_log.py | 128 +++++++++--------- tests/unittests/test_log.py | 11 +- 6 files changed, 103 insertions(+), 109 deletions(-) diff --git a/cloudinit/log/loggers.py b/cloudinit/log/loggers.py index 13754fee290..ae6d3c90290 100644 --- a/cloudinit/log/loggers.py +++ b/cloudinit/log/loggers.py @@ -10,7 +10,9 @@ import collections.abc # pylint: disable=import-error import copy +import datetime import io +import json import logging import logging.config import logging.handlers @@ -64,6 +66,22 @@ def filter(self, record): return record.levelno != SECURITY +class SecurityFormatter(logging.Formatter): + """Inject a 'datetime' field (UTC ISO-8601) into SECURITY JSON messages.""" + + def format(self, record: logging.LogRecord) -> str: + # Use record.msg instead of getMessage which formats dict to JSON + event = copy.deepcopy(record.msg) + if not isinstance(event, dict): + raise TypeError( + f"SECURITY logs expected dict but found {type(event)}: {event}" + ) + event["datetime"] = datetime.datetime.fromtimestamp( + record.created, tz=datetime.timezone.utc + ).isoformat() + return json.dumps(event, separators=(",", ":")) + + def setup_basic_logging(level=logging.DEBUG, formatter=None): formatter = formatter or logging.Formatter(DEFAULT_LOG_FORMAT) root = logging.getLogger() @@ -87,7 +105,7 @@ def setup_security_logging( handler = logging.FileHandler(log_file) except OSError: return - handler.setFormatter(logging.Formatter(SECURITY_LOG_FORMAT)) + handler.setFormatter(SecurityFormatter()) handler.addFilter(SecurityOnlyFilter()) handler.setLevel(SECURITY) logging.getLogger().addHandler(handler) diff --git a/cloudinit/log/security_event_log.py b/cloudinit/log/security_event_log.py index e441b8e1042..27e3aa2a33c 100644 --- a/cloudinit/log/security_event_log.py +++ b/cloudinit/log/security_event_log.py @@ -17,9 +17,7 @@ - host_ip: Optional IP address, included when network information is available. """ -import datetime import functools -import json import logging from enum import Enum from typing import Any, Dict, List, Optional @@ -75,25 +73,23 @@ def _build_event_string( return event_str -def _build_security_event( +def _log_security_event( event_type: OWASPEventType, level: OWASPEventLevel, description: str, event_params: Optional[List[str]] = None, additional_data: Optional[Dict[str, Any]] = None, -) -> Dict[str, Any]: +) -> None: """ - Build a security event dictionary following OWASP Logging Vocabulary. + Log a security event in OWASP format. :param event_type: Type of security event. - :param level: Log level (INFO, WARN, CRITICAL). + :param level: OWASP Log level (INFO, WARN, CRITICAL). :param description: Human-readable description of the event. :param event_params: Parameters to include in the event string. :param additional_data: Additional context-specific data. - :return: Dictionary containing the security event data. """ event = { - "datetime": datetime.datetime.now(datetime.timezone.utc).isoformat(), "appid": APP_ID, "type": "security", "event": _build_event_string(event_type, event_params), @@ -107,33 +103,7 @@ def _build_security_event( if key not in event and value: event[key] = value - return event - - -def _log_security_event( - event_type: OWASPEventType, - level: OWASPEventLevel, - description: str, - event_params: Optional[List[str]] = None, - additional_data: Optional[Dict[str, Any]] = None, -) -> None: - """ - Log a security event in OWASP format. - - :param event_type: Type of security event. - :param level: OWASP Log level (INFO, WARN, CRITICAL). - :param description: Human-readable description of the event. - :param event_params: Parameters to include in the event string. - :param additional_data: Additional context-specific data. - """ - event = _build_security_event( - event_type=event_type, - level=level, - description=description, - event_params=event_params, - additional_data=additional_data, - ) - LOG.log(loggers.SECURITY, json.dumps(event, separators=(",", ":"))) + LOG.log(loggers.SECURITY, event) def sec_log_user_created(func): diff --git a/tests/unittests/distros/test_create_users.py b/tests/unittests/distros/test_create_users.py index 8f9f6b6f6f3..580e9c3e88c 100644 --- a/tests/unittests/distros/test_create_users.py +++ b/tests/unittests/distros/test_create_users.py @@ -1,6 +1,5 @@ # This file is part of cloud-init. See LICENSE file for license information. -import json from pathlib import Path from typing import List @@ -452,7 +451,7 @@ def test_create_passwd_existing_user( if "passwd" not in create_kwargs: assert ( "authn_password_change:cloud-init,foo_user" - in caplog.records[-1].msg + in caplog.records[-1].msg["event"] ) @mock.patch("cloudinit.distros.util.is_group") @@ -518,9 +517,8 @@ def test_snappy_only_new_group_added( mock.call(["passwd", "-l", USER]), ] assert m_subp.call_args_list == expected - event = json.loads(caplog.records[-1].msg) assert ( - event["event"] + caplog.records[-1].msg["event"] == "user_created:cloud-init,foo_user,groups:group1,existing_group" ) @@ -664,7 +662,7 @@ def test_explicit_sudo_false(self, m_subp, dist, caplog, mocker): assert deprecation_record, "Missing deprecation log" assert deprecation_record.levelname in expected_levels assert security_record, "Missing security log" - security_event = json.loads(security_record.msg) + security_event = security_record.msg assert security_event["event"] == "user_created:cloud-init,foo_user" def test_explicit_sudo_none(self, m_subp, dist, caplog, mocker): diff --git a/tests/unittests/distros/test_user_data_normalize.py b/tests/unittests/distros/test_user_data_normalize.py index 47444830432..2c483c9d055 100644 --- a/tests/unittests/distros/test_user_data_normalize.py +++ b/tests/unittests/distros/test_user_data_normalize.py @@ -1,5 +1,4 @@ # This file is part of cloud-init. See LICENSE file for license information. -import json from unittest import mock import pytest @@ -284,7 +283,7 @@ def test_create_snap_user(self, mock_subp, caplog): snapcmd = ["snap", "create-user", "--sudoer", "--json", "joe@joe.com"] mock_subp.assert_called_with(snapcmd, capture=True, logstring=snapcmd) - event = json.loads(caplog.records[-1].msg) + event = caplog.records[-1].msg assert "user_created:cloud-init,joe" == event["event"] @mock.patch("cloudinit.subp.subp") @@ -311,7 +310,7 @@ def test_create_snap_user_known(self, mock_subp, caplog): "joe@joe.com", ] mock_subp.assert_called_with(snapcmd, capture=True, logstring=snapcmd) - event = json.loads(caplog.records[-1].msg) + event = caplog.records[-1].msg assert "user_created:cloud-init,joe" == event["event"] @mock.patch("cloudinit.util.system_is_snappy") diff --git a/tests/unittests/log/test_security_event_log.py b/tests/unittests/log/test_security_event_log.py index 4bcf452598d..064b2f9ab29 100644 --- a/tests/unittests/log/test_security_event_log.py +++ b/tests/unittests/log/test_security_event_log.py @@ -3,10 +3,12 @@ """Tests for cloudinit.log.security_event_log""" import json +import logging import pytest from cloudinit.log import loggers, security_event_log +from cloudinit.log.loggers import SecurityFormatter from cloudinit.log.security_event_log import ( OWASPEventLevel, OWASPEventType, @@ -57,69 +59,36 @@ def test_event_string_formatting(self, event_type, params, expected): result = security_event_log._build_event_string(event_type, params) assert result == expected - -class TestBuildSecurityEvent: - """Tests for _build_security_event function.""" - - def test_event_contains_required_owasp_fields(self): - """Test that built event contains all required OWASP fields.""" - event = security_event_log._build_security_event( + def test_additional_data_does_not_overwrite_core_fields(self, caplog): + """Test that additional data cannot overwrite core fields.""" + security_event_log._log_security_event( event_type=OWASPEventType.USER_CREATED, level=OWASPEventLevel.INFO, description="Test event", - event_params=["cloud-init", "testuser"], + additional_data={"appid": "malicious.app", "level": "CRITICAL"}, ) - - assert "datetime" in event + event = caplog.records[0].msg assert event["appid"] == "canonical.cloud-init" - assert event["event"] == "user_created:cloud-init,testuser" assert event["level"] == "INFO" - assert event["description"] == "Test event" - assert "hostname" in event - def test_event_with_additional_data(self): + +class TestLogSecurityEvent: + """Tests for _log_security_event function.""" + + def test_event_with_additional_data(self, caplog): """Test event includes additional data when provided.""" - event = security_event_log._build_security_event( + security_event_log._log_security_event( event_type=OWASPEventType.USER_CREATED, level=OWASPEventLevel.INFO, description="Test event", additional_data={"groups": "wheel", "shell": "/bin/bash"}, ) - + event = caplog.records[0].msg assert event["groups"] == "wheel" assert event["shell"] == "/bin/bash" - def test_additional_data_does_not_overwrite_core_fields(self): - """Test that additional data cannot overwrite core fields.""" - event = security_event_log._build_security_event( - event_type=OWASPEventType.USER_CREATED, - level=OWASPEventLevel.INFO, - description="Test event", - additional_data={"appid": "malicious.app", "level": "CRITICAL"}, - ) - - assert event["appid"] == "canonical.cloud-init" - assert event["level"] == "INFO" - - def test_timestamp_is_iso_format(self): - """Test that datetime is in ISO 8601 format.""" - event = security_event_log._build_security_event( - event_type=OWASPEventType.USER_CREATED, - level=OWASPEventLevel.INFO, - description="Test event", - ) - - # ISO 8601 format check - should contain 'T' separator - assert "T" in event["datetime"] - # Should end with timezone info (e.g., +00:00) - assert "+" in event["datetime"] or "Z" in event["datetime"] - - -class TestLogSecurityEvent: - """Tests for _log_security_event function.""" - def test_writes_json_to_file(self, caplog): - """Test that event is written to log file as JSON.""" + """Test that event is written to log file with OWASP fields.""" with caplog.at_level(loggers.SECURITY): security_event_log._log_security_event( event_type=OWASPEventType.USER_CREATED, @@ -127,11 +96,13 @@ def test_writes_json_to_file(self, caplog): description="User created successfully", event_params=["cloud-init", "testuser"], ) - event = json.loads(caplog.records[0].msg) + event = caplog.records[0].msg assert event["event"] == "user_created:cloud-init,testuser" assert event["level"] == "INFO" assert event["appid"] == "canonical.cloud-init" + assert event["description"] == "User created successfully" + assert "hostname" in event def test_appends_multiple_events(self, caplog): """Test that multiple events are appended to the log file.""" @@ -151,8 +122,8 @@ def test_appends_multiple_events(self, caplog): ) assert len(caplog.records) == 2 - event1 = json.loads(caplog.records[0].msg) - event2 = json.loads(caplog.records[1].msg) + event1 = caplog.records[0].msg + event2 = caplog.records[1].msg assert "user1" in event1["event"] assert "user2" in event2["event"] @@ -205,9 +176,6 @@ def user_created_decorator_test(self, name, **kwargs): **uc_kwargs, ) - event = json.loads(caplog.records[0].msg) - - assert event.pop("datetime") assert { "appid": "canonical.cloud-init", "event": event_id, @@ -215,7 +183,7 @@ def user_created_decorator_test(self, name, **kwargs): "hostname": get_hostname(), "level": "WARN", "type": "security", - } == event + } == caplog.records[0].msg class TestPasswordChangedEvent: @@ -245,9 +213,7 @@ def set_passwd(self, user): } for record in caplog.records: - event = json.loads(record.msg) - assert event.pop("datetime") - assert expected_value == event + assert expected_value == record.msg class TestPasswordChangedBatchEvent: @@ -276,9 +242,7 @@ def chpasswd(self, plist_in): } for record in caplog.records: - event = json.loads(record.msg) - assert event.pop("datetime") - assert expected_value == event + assert expected_value == record.msg class TestSystemShutdownEvent: @@ -339,8 +303,6 @@ def shutdown_test(cls, mode, delay, message): message=message, ) - event = json.loads(caplog.records[0].msg) - assert event.pop("datetime") expected = { "appid": "canonical.cloud-init", "delay": delay, @@ -353,7 +315,49 @@ def shutdown_test(cls, mode, delay, message): } if mode != "reboot": expected["mode"] = mode - assert expected == event + assert expected == caplog.records[0].msg + + +class TestSecurityFormatter: + """Tests for SecurityFormatter.""" + + def _make_record(self, msg) -> logging.LogRecord: + record = logging.LogRecord( + name="test", + level=loggers.SECURITY, + pathname="", + lineno=0, + msg=msg, + args=(), + exc_info=None, + ) + return record + + def test_injects_datetime_into_json_message(self): + """Formatter adds 'datetime' and formats valid JSON messages.""" + record = self._make_record({"appid": "canonical.cloud-init"}) + result = json.loads(SecurityFormatter().format(record)) + assert "datetime" in result + # ISO 8601: contains 'T' separator and UTC offset + assert "T" in result["datetime"] + assert "+" in result["datetime"] or "Z" in result["datetime"] + + def test_errors_on_non_dict(self): + """Non-Dict messages are returned unchanged.""" + record = self._make_record("not dict") + with pytest.raises(TypeError, match="SECURITY logs expected dict but"): + SecurityFormatter().format(record) + + def test_datetime_uses_record_created_timestamp(self): + """The injected datetime reflects the log record's creation time.""" + import datetime as dt + + record = self._make_record({}) + result = json.loads(SecurityFormatter().format(record)) + expected = dt.datetime.fromtimestamp( + record.created, tz=dt.timezone.utc + ).isoformat() + assert result["datetime"] == expected class TestEventTypeEnums: diff --git a/tests/unittests/test_log.py b/tests/unittests/test_log.py index a39af360d84..94abea3bad9 100644 --- a/tests/unittests/test_log.py +++ b/tests/unittests/test_log.py @@ -4,6 +4,7 @@ import datetime import io +import json import logging import time from typing import cast @@ -180,11 +181,15 @@ def test_logger_prints_to_stderr(capsys, caplog): def test_logger_prints_security_as_json_lines(tmp_path, capsys, caplog): + """Security logs accepts dict as payload logs JSON lines.""" log_file = tmp_path / "cloud-init-output.log" - message = '{"key": "value"}' + message = {"key": "value"} # Security logs expect python dict loggers.setup_basic_logging() root = cast(loggers.CustomLoggerType, logging.getLogger()) loggers.setup_security_logging(root=root, log_file=str(log_file)) root.security(message) - assert log_file.read_text() == f"{message}\n" - assert message not in capsys.readouterr().err + message_json = json.dumps(message, separators=(",", ":")) + logged_event = json.loads(log_file.read_text()) + assert logged_event.pop("datetime") + assert logged_event == message + assert message_json not in capsys.readouterr().err From 56d70f9475be018924fdc8e7b34c8e9a0642a793 Mon Sep 17 00:00:00 2001 From: Chad Smith Date: Sun, 15 Mar 2026 13:29:25 +0000 Subject: [PATCH 26/31] refactor: add helper method to process groups in kwargs --- cloudinit/distros/__init__.py | 51 +++++++++++++--------------- cloudinit/distros/alpine.py | 38 ++++++++++----------- cloudinit/distros/freebsd.py | 7 ++-- cloudinit/distros/netbsd.py | 7 ++-- cloudinit/distros/raspberry_pi_os.py | 3 +- 5 files changed, 52 insertions(+), 54 deletions(-) diff --git a/cloudinit/distros/__init__.py b/cloudinit/distros/__init__.py index 6cb28a3c00c..65cf396f99a 100644 --- a/cloudinit/distros/__init__.py +++ b/cloudinit/distros/__init__.py @@ -666,6 +666,14 @@ def preferred_ntp_clients(self): def get_default_user(self): return self.get_option("default_user") + def _user_groups_to_list(self, groups) -> List[str]: + """Return a list of designation groups with whitespace removed.""" + if not groups: + return [] + if isinstance(groups, str): + groups = groups.split(",") + return [g.strip() for g in groups] + @final @sec_log_user_created def add_user(self, name, **kwargs) -> None: @@ -675,29 +683,16 @@ def add_user(self, name, **kwargs) -> None: create_groups = kwargs.pop("create_groups", True) - # support kwargs having groups=[list] or groups="g1,g2" - groups = kwargs.get("groups") + if isinstance(kwargs.get("groups", None), dict): + lifecycle.deprecate( + deprecated=f"The user {name} has a 'groups' config value " + "of type dict", + deprecated_version="22.3", + extra_message="Use a comma-delimited string or " + "array instead: group1,group2.", + ) + groups = self._user_groups_to_list(kwargs.pop("groups", None)) if groups: - if isinstance(groups, str): - groups = groups.split(",") - - if isinstance(groups, dict): - lifecycle.deprecate( - deprecated=f"The user {name} has a 'groups' config value " - "of type dict", - deprecated_version="22.3", - extra_message="Use a comma-delimited string or " - "array instead: group1,group2.", - ) - - # remove any white spaces in group names, most likely - # that came in as a string like: groups: group1, group2 - groups = [g.strip() for g in groups] - - # _build_add_user_cmd wants a comma delimited string - # that can go right through to the command. - kwargs["groups"] = ",".join(groups) - primary_group = kwargs.get("primary_group") if primary_group: groups.append(primary_group) @@ -712,14 +707,14 @@ def add_user(self, name, **kwargs) -> None: kwargs["uid"] = str(kwargs["uid"]) LOG.debug("Adding user %s", name) - cmd, log_cmd = self._build_add_user_cmd(name, **kwargs) + cmd, log_cmd = self._build_add_user_cmd(name, groups, **kwargs) try: subp.subp(cmd, logstring=log_cmd) except Exception as e: util.logexc(LOG, "Failed to create user %s", name) raise e - self._post_add_user(name, **kwargs) + self._post_add_user(name, groups, **kwargs) def _add_user_preprocess_kwargs(self, name: str, kwargs: dict) -> None: """Preprocess kwargs in-place before building the add-user command. @@ -728,7 +723,7 @@ def _add_user_preprocess_kwargs(self, name: str, kwargs: dict) -> None: """ def _build_add_user_cmd( - self, name: str, **kwargs + self, name: str, groups: List[str], **kwargs ) -> Tuple[List[str], List[str]]: """Build the useradd command for GNU/Linux systems. @@ -751,7 +746,6 @@ def _build_add_user_cmd( "homedir": "--home", "primary_group": "--gid", "uid": "--uid", - "groups": "--groups", "passwd": "--password", "shell": "--shell", "expiredate": "--expiredate", @@ -768,6 +762,9 @@ def _build_add_user_cmd( redact_opts = ["passwd"] # Check the values and create the command + if groups: + useradd_cmd.extend(["--groups", ",".join(groups)]) + log_useradd_cmd.extend(["--groups", ",".join(groups)]) for key, val in sorted(kwargs.items()): if key in useradd_opts and val and isinstance(val, str): useradd_cmd.extend([useradd_opts[key], val]) @@ -793,7 +790,7 @@ def _build_add_user_cmd( return useradd_cmd, log_useradd_cmd - def _post_add_user(self, name: str, **kwargs) -> None: + def _post_add_user(self, name: str, groups: List[str], **kwargs) -> None: """Hook called after the user-creation command succeeds. Overridden to perform distro-specific post-creation steps. diff --git a/cloudinit/distros/alpine.py b/cloudinit/distros/alpine.py index 6a5800870db..63f15f88557 100644 --- a/cloudinit/distros/alpine.py +++ b/cloudinit/distros/alpine.py @@ -210,11 +210,11 @@ def _add_user_preprocess_kwargs(self, name: str, kwargs: dict) -> None: LOG.warning("Ignoring selinux_user parameter for Alpine Linux") def _build_add_user_cmd( - self, name: str, **kwargs + self, name: str, groups: List[str], **kwargs ) -> Tuple[List[str], List[str]]: # If 'useradd' is available then use the generic GNU implementation. if subp.which("useradd"): - return super()._build_add_user_cmd(name, **kwargs) + return super()._build_add_user_cmd(name, groups, **kwargs) adduser_cmd = ["adduser", "-D"] @@ -257,7 +257,7 @@ def _build_add_user_cmd( return adduser_cmd, adduser_cmd - def _post_add_user(self, name: str, **kwargs) -> None: + def _post_add_user(self, name: str, groups: List[str], **kwargs) -> None: # When useradd is available, the GNU implementation handles everything. if subp.which("useradd"): return @@ -266,23 +266,21 @@ def _post_add_user(self, name: str, **kwargs) -> None: # Separately add user to each additional group as Busybox's # 'adduser' does not support specifying additional groups. - groups_str = kwargs.get("groups", "") - if groups_str: - for addn_group in groups_str.split(","): - addn_group = addn_group.strip() - if not addn_group: - continue - LOG.debug("Adding user to group %s", addn_group) - try: - subp.subp(["addgroup", name, addn_group]) - except subp.ProcessExecutionError as e: - util.logexc( - LOG, - "Failed to add user %s to group %s", - name, - addn_group, - ) - raise e + for addn_group in groups: + addn_group = addn_group.strip() + if not addn_group: + continue + LOG.debug("Adding user to group %s", addn_group) + try: + subp.subp(["addgroup", name, addn_group]) + except subp.ProcessExecutionError as e: + util.logexc( + LOG, + "Failed to add user %s to group %s", + name, + addn_group, + ) + raise e passwd_val = kwargs.get("passwd") if passwd_val: diff --git a/cloudinit/distros/freebsd.py b/cloudinit/distros/freebsd.py index c95469a1b45..1880d6931f0 100644 --- a/cloudinit/distros/freebsd.py +++ b/cloudinit/distros/freebsd.py @@ -99,7 +99,7 @@ def _get_add_member_to_group_cmd(self, member_name, group_name): return ["pw", "usermod", "-n", member_name, "-G", group_name] def _build_add_user_cmd( - self, name: str, **kwargs + self, name: str, groups: List[str], **kwargs ) -> Tuple[List[str], List[str]]: pw_useradd_cmd = ["pw", "useradd", "-n", name] log_pw_useradd_cmd = ["pw", "useradd", "-n", name] @@ -107,7 +107,6 @@ def _build_add_user_cmd( "homedir": "-d", "gecos": "-c", "primary_group": "-g", - "groups": "-G", "shell": "-s", "inactive": "-E", "uid": "-u", @@ -118,6 +117,8 @@ def _build_add_user_cmd( "no_log_init": "--no-log-init", } + if groups: + pw_useradd_cmd.extend(["-G", ",".join(groups)]) for key, val in kwargs.items(): if key in pw_useradd_opts and val and isinstance(val, (str, int)): pw_useradd_cmd.extend([pw_useradd_opts[key], str(val)]) @@ -138,7 +139,7 @@ def _build_add_user_cmd( return pw_useradd_cmd, log_pw_useradd_cmd - def _post_add_user(self, name: str, **kwargs) -> None: + def _post_add_user(self, name: str, groups: List[str], **kwargs) -> None: # Set the password if it is provided. # For security consideration, only hashed passwd is assumed. passwd_val = kwargs.get("passwd", None) diff --git a/cloudinit/distros/netbsd.py b/cloudinit/distros/netbsd.py index 0ba08cb1b45..13f82c6dad8 100644 --- a/cloudinit/distros/netbsd.py +++ b/cloudinit/distros/netbsd.py @@ -75,7 +75,7 @@ def _get_add_member_to_group_cmd(self, member_name, group_name): return ["usermod", "-G", group_name, member_name] def _build_add_user_cmd( - self, name: str, **kwargs + self, name: str, groups: List[str], **kwargs ) -> Tuple[List[str], List[str]]: adduser_cmd = ["useradd"] log_adduser_cmd = ["useradd"] @@ -84,7 +84,6 @@ def _build_add_user_cmd( "homedir": "-d", "gecos": "-c", "primary_group": "-g", - "groups": "-G", "shell": "-s", } adduser_flags = { @@ -93,6 +92,8 @@ def _build_add_user_cmd( "no_log_init": "--no-log-init", } + if groups: + adduser_cmd.extend(["-G", ",".join(groups)]) for key, val in kwargs.items(): if key in adduser_opts and val and isinstance(val, str): adduser_cmd.extend([adduser_opts[key], val]) @@ -109,7 +110,7 @@ def _build_add_user_cmd( return adduser_cmd, log_adduser_cmd - def _post_add_user(self, name: str, **kwargs) -> None: + def _post_add_user(self, name: str, groups: List[str], **kwargs) -> None: # Set the password if it is provided. # For security consideration, only hashed passwd is assumed. passwd_val = kwargs.get("passwd", None) diff --git a/cloudinit/distros/raspberry_pi_os.py b/cloudinit/distros/raspberry_pi_os.py index 34ca0bd4264..a78dcb909b6 100644 --- a/cloudinit/distros/raspberry_pi_os.py +++ b/cloudinit/distros/raspberry_pi_os.py @@ -5,6 +5,7 @@ # This file is part of cloud-init. See LICENSE file for license information. import logging +from typing import List from cloudinit import net, subp from cloudinit.distros import debian @@ -67,7 +68,7 @@ def apply_locale(self, locale, out_fn=None, keyname="LANG"): else: LOG.error("Failed to set locale %s", locale) - def _post_add_user(self, name: str, **kwargs) -> None: + def _post_add_user(self, name: str, groups: List[str], **kwargs) -> None: try: subp.subp( [ From b1192a14c0ab217f2cfb5a3e657df5b89b5095dc Mon Sep 17 00:00:00 2001 From: Chad Smith Date: Fri, 20 Mar 2026 18:35:02 +0000 Subject: [PATCH 27/31] chore: drop _build_event_string and fold into _log_security_event --- cloudinit/log/security_event_log.py | 24 ++++-------------------- 1 file changed, 4 insertions(+), 20 deletions(-) diff --git a/cloudinit/log/security_event_log.py b/cloudinit/log/security_event_log.py index 27e3aa2a33c..f4bdda47eb7 100644 --- a/cloudinit/log/security_event_log.py +++ b/cloudinit/log/security_event_log.py @@ -54,25 +54,6 @@ class OWASPEventType(Enum): # TODO(USER_UPDATED = "user_updated") -def _build_event_string( - event_type: OWASPEventType, params: Optional[List[str]] = None -) -> str: - """ - Build the OWASP event string with optional parameters. - - :param event_type: The type of security event. - :param params: Optional list of parameters to append. - :return: Event string in format "event_type:param1,param2,..." - """ - event_str = event_type.value - if params: - # Filter out None values and convert to strings - filtered_params = [str(p) for p in params if p is not None] - if filtered_params: - event_str += ":" + ",".join(filtered_params) - return event_str - - def _log_security_event( event_type: OWASPEventType, level: OWASPEventLevel, @@ -89,10 +70,13 @@ def _log_security_event( :param event_params: Parameters to include in the event string. :param additional_data: Additional context-specific data. """ + event_str = event_type.value + if event_params: + event_str += ":" + ",".join(event_params) event = { "appid": APP_ID, "type": "security", - "event": _build_event_string(event_type, event_params), + "event": event_str "level": level.value, "description": description, "hostname": util.get_hostname(), From e076eec783e7fe415c61b2fba87ac0aeaa790dfa Mon Sep 17 00:00:00 2001 From: Chad Smith Date: Fri, 20 Mar 2026 18:53:30 +0000 Subject: [PATCH 28/31] chore: type hints for plist_in --- cloudinit/config/cc_set_passwords.py | 4 ++-- cloudinit/distros/__init__.py | 2 +- cloudinit/distros/bsd.py | 4 ++-- cloudinit/log/security_event_log.py | 8 ++++---- 4 files changed, 9 insertions(+), 9 deletions(-) diff --git a/cloudinit/config/cc_set_passwords.py b/cloudinit/config/cc_set_passwords.py index 22547d0fd42..4fe5668d3d4 100644 --- a/cloudinit/config/cc_set_passwords.py +++ b/cloudinit/config/cc_set_passwords.py @@ -11,7 +11,7 @@ import random import re import string -from typing import List +from typing import List, Tuple from cloudinit import features, lifecycle, subp, util from cloudinit.cloud import Cloud @@ -32,7 +32,7 @@ LOG = logging.getLogger(__name__) -def get_users_by_type(users_list: list, pw_type: str) -> list: +def get_users_by_type(users_list: list, pw_type: str) -> List[Tuple[str, str]]: """either password or type: RANDOM is required, user is always required""" return ( [] diff --git a/cloudinit/distros/__init__.py b/cloudinit/distros/__init__.py index 65cf396f99a..c9172c2699b 100644 --- a/cloudinit/distros/__init__.py +++ b/cloudinit/distros/__init__.py @@ -1132,7 +1132,7 @@ def set_passwd(self, user, passwd, hashed=False): return True @sec_log_password_changed_batch - def chpasswd(self, plist_in: list, hashed: bool): + def chpasswd(self, plist_in: List[Tuple[str, str]], hashed: bool): payload = ( "\n".join( (":".join([name, password]) for name, password in plist_in) diff --git a/cloudinit/distros/bsd.py b/cloudinit/distros/bsd.py index 8433aac2aa8..ac489a8936b 100644 --- a/cloudinit/distros/bsd.py +++ b/cloudinit/distros/bsd.py @@ -1,7 +1,7 @@ import logging import platform import re -from typing import List, Optional +from typing import List, Optional, Tuple import cloudinit.net.netops.bsd_netops as bsd_netops from cloudinit import distros, helpers, net, subp, util @@ -149,7 +149,7 @@ def set_timezone(self, tz): def apply_locale(self, locale, out_fn=None): LOG.debug("Cannot set the locale.") - def chpasswd(self, plist_in: list, hashed: bool): + def chpasswd(self, plist_in: List[Tuple[str, str]], hashed: bool): for name, password in plist_in: self.set_passwd(name, password, hashed=hashed) diff --git a/cloudinit/log/security_event_log.py b/cloudinit/log/security_event_log.py index f4bdda47eb7..4499352b65f 100644 --- a/cloudinit/log/security_event_log.py +++ b/cloudinit/log/security_event_log.py @@ -20,7 +20,7 @@ import functools import logging from enum import Enum -from typing import Any, Dict, List, Optional +from typing import Any, Dict, List, Optional, Tuple from cloudinit import util from cloudinit.log import loggers @@ -76,8 +76,8 @@ def _log_security_event( event = { "appid": APP_ID, "type": "security", - "event": event_str - "level": level.value, + "event": event_str, + "level": str(level.value), "description": description, "hostname": util.get_hostname(), } @@ -128,7 +128,7 @@ def decorator(self, name, *args, **kwargs): def sec_log_password_changed_batch(func): @functools.wraps(func) - def decorator(self, plist_in, *args, **kwargs): + def decorator(self, plist_in: List[Tuple[str, str]], *args, **kwargs): response = func(self, plist_in, *args, **kwargs) for userid, _ in plist_in: _log_security_event( From 95ab64c91ef6eb46040e9b6715ecc2996ff3550f Mon Sep 17 00:00:00 2001 From: Chad Smith Date: Fri, 20 Mar 2026 19:05:43 +0000 Subject: [PATCH 29/31] chore: default insert cloud-init a main event actor. Remove stray dhcp change --- cloudinit/log/security_event_log.py | 16 ++++++++++------ cloudinit/net/dhcp.py | 1 - 2 files changed, 10 insertions(+), 7 deletions(-) diff --git a/cloudinit/log/security_event_log.py b/cloudinit/log/security_event_log.py index 4499352b65f..6e443ec9316 100644 --- a/cloudinit/log/security_event_log.py +++ b/cloudinit/log/security_event_log.py @@ -70,9 +70,14 @@ def _log_security_event( :param event_params: Parameters to include in the event string. :param additional_data: Additional context-specific data. """ - event_str = event_type.value + # cloud-init is the default primary 'actor' for any system change operation if event_params: - event_str += ":" + ",".join(event_params) + event_params.insert(0, "cloud-init") + else: + event_params = ["cloud-init"] + + event_str = event_type.value + event_str += ":" + ",".join(event_params) event = { "appid": APP_ID, "type": "security", @@ -99,7 +104,7 @@ def decorator(self, name, *args, **kwargs): raise RuntimeError( "sec_log_user_created requires positional param name or kwarg" ) - params = ["cloud-init", name] + params = [name] groups_msg = "" groups_suffix = kwargs.get("groups", "") if groups_suffix: @@ -135,7 +140,7 @@ def decorator(self, plist_in: List[Tuple[str, str]], *args, **kwargs): event_type=OWASPEventType.AUTHN_PASSWORD_CHANGE, level=OWASPEventLevel.INFO, description=f"Password changed for user '{userid}'", - event_params=["cloud-init", userid], + event_params=[userid], ) return response @@ -152,7 +157,7 @@ def decorator(self, user: str, *args, **kwargs): event_type=OWASPEventType.AUTHN_PASSWORD_CHANGE, level=OWASPEventLevel.INFO, description=f"Password changed for user '{user}'", - event_params=["cloud-init", user], + event_params=[user], ) return response @@ -177,7 +182,6 @@ def decorator(cls, mode: str, delay: str, message): event_type=event_type, level=OWASPEventLevel.INFO, description=description, - event_params=["cloud-init"], additional_data={"delay": delay, "mode": mode}, ) return func(cls, mode=mode, delay=delay, message=message) diff --git a/cloudinit/net/dhcp.py b/cloudinit/net/dhcp.py index 273b7f10c1f..6620b15da26 100644 --- a/cloudinit/net/dhcp.py +++ b/cloudinit/net/dhcp.py @@ -620,7 +620,6 @@ def dhcp_discovery( interface: str, dhcp_log_func: Optional[Callable[[str, str, str], None]] = None, distro=None, - metric=None, ) -> Dict[str, Any]: """Run dhcpcd on the interface without scripts/filesystem artifacts. From 064ba63203dedc80bec54409f7b287f3d1c809df Mon Sep 17 00:00:00 2001 From: Chad Smith Date: Fri, 20 Mar 2026 19:15:18 +0000 Subject: [PATCH 30/31] chore: typing of name and doc log file correction --- cloudinit/log/security_event_log.py | 2 +- doc/rtd/reference/user_files.rst | 2 +- 2 files changed, 2 insertions(+), 2 deletions(-) diff --git a/cloudinit/log/security_event_log.py b/cloudinit/log/security_event_log.py index 6e443ec9316..2a90416f52b 100644 --- a/cloudinit/log/security_event_log.py +++ b/cloudinit/log/security_event_log.py @@ -99,7 +99,7 @@ def sec_log_user_created(func): """A decorator to log a user creation event and group attributes.""" @functools.wraps(func) - def decorator(self, name, *args, **kwargs): + def decorator(self, name: str, *args, **kwargs): if not name: raise RuntimeError( "sec_log_user_created requires positional param name or kwarg" diff --git a/doc/rtd/reference/user_files.rst b/doc/rtd/reference/user_files.rst index c55408c2576..948b235020a 100644 --- a/doc/rtd/reference/user_files.rst +++ b/doc/rtd/reference/user_files.rst @@ -14,7 +14,7 @@ Log files - :file:`/var/log/cloud-init.log`: The primary log file. Verbose, but useful. - :file:`/var/log/cloud-init-output.log`: Captures the output from each stage. Output from user scripts goes here. -- :file:`/var/log/cloud-init-security.log`: This file logs OWASP security +- :file:`/var/log/cloud-init-security.log`: This file contains OWASP security events as JSON lines format implementing OWASP events including user creation and update, password modification and system power events. From a18a10233369daaec5d2d8fd49e5a8af06a4e15c Mon Sep 17 00:00:00 2001 From: Chad Smith Date: Fri, 20 Mar 2026 19:36:36 +0000 Subject: [PATCH 31/31] refactor: add _get_elevated_roles and wire to sec_log_user_created Also call Distro._user_groups_to_list in sec_log_user_created to avoid duplicated processing of add_user kwargs in security_event_log. --- cloudinit/distros/__init__.py | 8 +++++ cloudinit/log/security_event_log.py | 19 +++++----- .../unittests/log/test_security_event_log.py | 36 +++++++++++-------- 3 files changed, 37 insertions(+), 26 deletions(-) diff --git a/cloudinit/distros/__init__.py b/cloudinit/distros/__init__.py index c9172c2699b..f7d6fa371a7 100644 --- a/cloudinit/distros/__init__.py +++ b/cloudinit/distros/__init__.py @@ -674,6 +674,14 @@ def _user_groups_to_list(self, groups) -> List[str]: groups = groups.split(",") return [g.strip() for g in groups] + def _get_elevated_roles(self, **kwargs) -> List[str]: + elevated_roles = [] + if kwargs.get("sudo"): + elevated_roles.append("sudo") + if kwargs.get("doas"): + elevated_roles.append("doas") + return elevated_roles + @final @sec_log_user_created def add_user(self, name, **kwargs) -> None: diff --git a/cloudinit/log/security_event_log.py b/cloudinit/log/security_event_log.py index 2a90416f52b..f93273b4dd6 100644 --- a/cloudinit/log/security_event_log.py +++ b/cloudinit/log/security_event_log.py @@ -77,7 +77,8 @@ def _log_security_event( event_params = ["cloud-init"] event_str = event_type.value - event_str += ":" + ",".join(event_params) + if event_params: + event_str += ":" + ",".join(event_params) event = { "appid": APP_ID, "type": "security", @@ -106,15 +107,10 @@ def decorator(self, name: str, *args, **kwargs): ) params = [name] groups_msg = "" - groups_suffix = kwargs.get("groups", "") - if groups_suffix: - if isinstance(groups_suffix, (dict, list)): - groups_suffix = ",".join(groups_suffix) - for perms in ("sudo", "doas"): - if kwargs.get(perms): - groups_suffix += f",{perms}" - if groups_suffix: - groups_suffix = groups_suffix.strip(",") + groups = self._user_groups_to_list(kwargs.get("groups", None)) + all_groups = groups + self._get_elevated_roles(**kwargs) + if all_groups: + groups_suffix = ",".join(all_groups) groups_msg = f" in groups: {groups_suffix}" params.append(f"groups:{groups_suffix}") @@ -122,7 +118,8 @@ def decorator(self, name: str, *args, **kwargs): # User creation operation did not raise an Exception _log_security_event( event_type=OWASPEventType.USER_CREATED, - level=OWASPEventLevel.WARN, + # Treat INFO level as this is prescribed provisioning at launch + level=OWASPEventLevel.INFO, description=f"User '{name}' was created{groups_msg}", event_params=params, ) diff --git a/tests/unittests/log/test_security_event_log.py b/tests/unittests/log/test_security_event_log.py index 064b2f9ab29..8ba113bde2c 100644 --- a/tests/unittests/log/test_security_event_log.py +++ b/tests/unittests/log/test_security_event_log.py @@ -18,6 +18,7 @@ sec_log_user_created, ) from cloudinit.util import get_hostname +from tests.unittests.util import MockDistro MPATH = "cloudinit.log.security_event_log." @@ -31,33 +32,37 @@ class TestBuildEventString: pytest.param( OWASPEventType.SYS_SHUTDOWN, None, - "sys_shutdown", + "sys_shutdown:cloud-init", id="no_params", ), pytest.param( OWASPEventType.AUTHN_PASSWORD_CHANGE, ["testuser"], - "authn_password_change:testuser", + "authn_password_change:cloud-init,testuser", id="single_param", ), pytest.param( OWASPEventType.USER_CREATED, - ["cloud-init", "newuser", "groups:wheel"], + ["newuser", "groups:wheel"], "user_created:cloud-init,newuser,groups:wheel", id="multiple_params", ), - pytest.param( - OWASPEventType.USER_CREATED, - ["cloud-init", None, "newuser"], - "user_created:cloud-init,newuser", - id="filters_none_params", - ), ], ) - def test_event_string_formatting(self, event_type, params, expected): + def test_event_string_formatting( + self, event_type, params, expected, caplog + ): """Test event string formatting with various parameter combinations.""" - result = security_event_log._build_event_string(event_type, params) - assert result == expected + security_event_log._log_security_event( + event_type=event_type, + level=OWASPEventLevel.WARN, + description="Test Descr", + event_params=params, + ) + event = caplog.records[0].msg + assert event["appid"] == "canonical.cloud-init" + assert event["level"] == "WARN" + assert event["event"] == expected def test_additional_data_does_not_overwrite_core_fields(self, caplog): """Test that additional data cannot overwrite core fields.""" @@ -94,7 +99,7 @@ def test_writes_json_to_file(self, caplog): event_type=OWASPEventType.USER_CREATED, level=OWASPEventLevel.INFO, description="User created successfully", - event_params=["cloud-init", "testuser"], + event_params=["testuser"], ) event = caplog.records[0].msg @@ -165,7 +170,8 @@ def test_logs_user_created_event( ): """Test logging a user creation event.""" - class DecoratedSetPasswordTest: + class DecoratedSetPasswordTest(MockDistro): + @sec_log_user_created def user_created_decorator_test(self, name, **kwargs): return @@ -181,7 +187,7 @@ def user_created_decorator_test(self, name, **kwargs): "event": event_id, "description": description, "hostname": get_hostname(), - "level": "WARN", + "level": "INFO", "type": "security", } == caplog.records[0].msg