freeipa/doc/designs/audit-ipa-api.md

Audit IPA API operations

Overview

IPA servers present an API to perform various actions that change the state of the deployment. These actions include, among others, modifications of user and group databases, add or remove information about hosts and Kerberos services, HBAC and SUDO rules, and many other action types.

It is possible to observe IPA API actions through the web server logs. Each IPA server logs their API calls in /var/log/httpd/error_log log file, as part of standard Apache webserver logs. However, IPA command line utilities, when run as root on IPA server, operate directly against LDAP database and results of these operations only present in LDAP logs.

Thus, current IPA API implementation does not provide a unified method to collect logs to audit API operations. The goal of this change is to make sure IPA API backend logs externally-initiated operations, regardless how these operations were invoked.

Use Cases

• As an administrator, I'd like to collect details on who and when has called a particular IPA API on a particular IPA server. This information needs to be easily queried and it should be possible to correlate it across all servers in the IPA deployment.

• As an administrator, I'd like to make sure operations performed as part of IPA administrative utilities are audited as well.

How to Use

journalctl tool can be used to query and filter through the IPA API audit details. Each logged entry will be tagged with an 'IPA.API' label and thus can easily be queried:

# journalctl -g IPA.API
...

journalctl -g allows to search through the content of the log entries' messages. Each found entry has associated metadata which can be retrieved in a different format, depending on other options to journalctl invocation.

Design

Audit of IPA API operations should happen independently. Operations should be logged whenever they happen.

IPA deployment heavily relies on a working systemd setup. systemd provides logging facilities in the form of a system journal. systemd journal allows centralized collection of the journals from individual systems, forward secure sealing of the forwarded data, and rich metadata associated with the log entries. Thus, it already provides an infrastructure to allow secure centralized collection of actions performed through IPA API on IPA servers.

From administrator's point of view, when IPA API operations logged through the systemd journal, standard journal commands can be used to retrieve and manipulate logged entries.

Implementation

All IPA API calls end up in Command.__do_call() internal method. This method prepares execution of the command and runs it. After the command was performed, the output is formatted. If operations require forwarding the request to a remote IPA server, this will be performed automatically. As a result, Command.__do_call() is executed by both IPA client and IPA server components. It is possible to derive a context of operations through IPA API environment, using api.env.in_server boolean.

systemd journal provides a simple Python binding, systemd.journal, that allows structured logging of the messages against a journald daemon running on the system. If such operation is performed in the server context, system journal will be updated.

To aid with identification of these messages, an application name is replaced with IPA.API and the actual name from api.env.script is made a part of the logged message. The actual application script name is available as part of the journal metadata anyway. Additionally, a MESSAGE_ID property is set to IPA API-specific application UID, generated with Python's uuid.uuid3(uuid.NAMESPACE_DNS, 'IPA.API') function call. This value is available in IPA constants (ipalib/constants.py) as SD_IPA_API_MESSAGE_ID. The value of the constant is 6d70f1b493df36478bc3499257cd3b17.

If no Kerberos authentication was used but rather LDAPI autobind was in use, the name of the authenticated principal will be replaced with [autobind] text.

Messages sent with syslog NOTICE priority.

An example session looks like the following output:

# ipa -e in_server=True console
(Custom IPA interactive Python console)
    api: IPA API object
    pp: pretty printer
>>> api.Command.user_del('foobar')
{'result': {'failed': []}, 'value': ['foobar'], 'messages': [{'type':
'warning', 'name': 'VersionMissing', 'message': "API Version number was not
sent, forward compatibility not guaranteed. Assuming server's API version,
2.253", 'code': 13001, 'data': {'server_version': '2.253'}}], 'summary':
'Deleted user "foobar"'}
>>> ^D
now exiting InteractiveConsole...

# journalctl -g IPA.API
May 21 11:31:33 master1.ipa1.test /usr/bin/ipa[247422]: [IPA.API] [autobind]: user_del: SUCCESS [ldap2_140328582446688] {"uid": ["foobar"], "continue": false, "version": "2.253"}

All operations triggered through IPA API logged, including locally initiated, as can be seen in the output above. For httpd end-point operations will be logged as requested by the /mod_wsgi binary:

May 21 11:35:19 master1.ipa1.test /mod_wsgi[247035]: [IPA.API] admin@IPA1.TEST: ping: SUCCESS [ldap2_139910420944784] {"version": "2.253"}

The message includes following fields:

• executable name and PID (/mod_wsgi for HTTP end-point)
• [IPA.API] marker to allow searches with journalctl -g IPA.API
• authenticated Kerberos principal or [autobind] marker for LDAPI-based access as root
• name of the command executed
• result of execution: SUCCESS or an exception name
• LDAP backend instance identifier. The identifier will be the same for all operations performed under the same request. This allows to identify operations which were executed as a part of the same API request instance. For API operations that didn't result in LDAP access, there will be [no_connection_id] marker.
• finally, a list of arguments and options passed to the command is provided in JSON format

If an API call results in multiple operations triggered by the internal implementation of the API command, only the external operation is recorded. This means, for example, that a user_del API call will only be recorded as a user_del command and not a sequence of a user_find, otptoken_find, subid_find, and corresponding deletion commands which user_del implementation is using.

IPA supplies a message catalog to systemd journal which allows to explain content of the audited message and provide references to corresponding IPA API documentation. This feature is triggered by journalctl -x systemd journal command.

Full journal entry looks like the one below and can be obtained with journalctl -o json-pretty command:

{
        "PRIORITY" : "5",
        "_HOSTNAME" : "master1.ipa1.test",
        "__SEQNUM" : "608971",
        "_COMM" : "ipa",
        "_AUDIT_LOGINUID" : "0",
        "CODE_FUNC" : "__audit_to_journal",
        "_TRANSPORT" : "journal",
        "__SEQNUM_ID" : "aa96317d3ab84c16b5f131922414af11",
        "_CAP_EFFECTIVE" : "1ffffffffff",
        "_MACHINE_ID" : "5582ad1e90354a2e82710afb4cd4477f",
        "_RUNTIME_SCOPE" : "system",
        "MESSAGE" : "[IPA.API] [autobind]: user_del: SUCCESS [ldap2_140155643874720] {\"uid\": [\"zuser3\"], \"continue\": false, \"version\": \"2.253\"}",
        "CODE_LINE" : "495",
        "__REALTIME_TIMESTAMP" : "1716360895014405",
        "__MONOTONIC_TIMESTAMP" : "5952405665424",
        "_SYSTEMD_OWNER_UID" : "0",
        "_SYSTEMD_UNIT" : "session-30.scope",
        "_SYSTEMD_CGROUP" : "/user.slice/user-0.slice/session-30.scope",
        "CODE_FILE" : "/usr/lib/python3.12/site-packages/ipalib/frontend.py",
        "_SYSTEMD_SESSION" : "30",
        "_SYSTEMD_INVOCATION_ID" : "d166c864dba04b478d01658aa180d50d",
        "_PID" : "255232",
        "IPA_API_PARAMS" : "{\"uid\": [\"zuser3\"], \"continue\": false, \"version\": \"2.253\"}",
        "MESSAGE_ID" : "6d70f1b493df36478bc3499257cd3b17",
        "IPA_API_ACTOR" : "[autobind]",
        "_SYSTEMD_SLICE" : "user-0.slice",
        "IPA_API_COMMAND" : "user_del",
        "_BOOT_ID" : "cce41ab07f404ced8676400eb01bf220",
        "__CURSOR" : "s=aa96317d3ab84c16b5f131922414af11;i=94acb;b=cce41ab07f404ced8676400eb01bf220;m=569e7067690;t=6190569742605;x=265dd38af30f934c",
        "_AUDIT_SESSION" : "30",
        "SYSLOG_IDENTIFIER" : "/usr/bin/ipa",
        "_UID" : "0",
        "_SYSTEMD_USER_SLICE" : "-.slice",
        "_SOURCE_REALTIME_TIMESTAMP" : "1716360895014364",
        "_SELINUX_CONTEXT" : "unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023",
        "_CMDLINE" : "/usr/bin/python3 -I /usr/bin/ipa -e in_server=True console",
        "_EXE" : "/usr/bin/python3.12",
        "_GID" : "0",
        "IPA_API_RESULT" : "SUCCESS"
}

An explanation for this audit message can be generated with journalctl -x command:

# journalctl -x -g ldap2_140155643874720
May 22 06:54:55 master1.ipa1.test /usr/bin/ipa[255232]: [🡕] [IPA.API] [autobind]: user_del: SUCCESS [ldap2_140155643874720] {"uid": ["zuser3"], "continue": false, "version": "2.253"}
░░ Subject: IPA API command was executed and result of its execution was audited
░░ Defined-by: FreeIPA
░░ Support: https://lists.fedorahosted.org/archives/list/freeipa-users@lists.fedorahosted.org/
░░ Documentation: man:ipa(1)
░░ Documentation: https://freeipa.readthedocs.io/en/latest/api/index.html
░░ Documentation: https://freeipa.readthedocs.io/en/latest/api/user_del.html

░░ FreeIPA provides an extensive API that allows to manage all aspects of IPA deployments.

░░ The following information about the API command executed is available:

░░ [IPA.API] [autobind]: user_del: SUCCESS [ldap2_140155643874720] {"uid": ["zuser3"], "continue": false, "version": "2.253"}

░░ The command was executed by '/usr/bin/ipa' utility. If the utility name
░░ is '/mod_wsgi`, then this API command came from a remote source through the IPA
░░ API end-point.

░░ The message includes following fields:

░░   - executable name and PID ('/mod_wsgi' for HTTP end-point; in this case it
░░     was '/usr/bin/ipa' command)

░░   - '[IPA.API]' marker to allow searches with 'journalctl -g IPA.API'

░░   - authenticated Kerberos principal or '[autobind]' marker for LDAPI-based
░░     access as root. In this case it was '[autobind]'

░░   - name of the command executed, in this case 'user_del'

░░   - result of execution: `SUCCESS` or an exception name. In this case it was
░░     'SUCCESS'

░░   - LDAP backend instance identifier. The identifier will be the same for all
░░     operations performed under the same request. This allows to identify operations
░░     which were executed as a part of the same API request instance. For API
░░     operations that didn't result in LDAP access, there will be
░░     '[no_connection_id]' marker.

░░   - finally, a list of arguments and options passed to the command is provided
░░     in JSON format.

░░ ---------
░░ The following list of arguments and options were passed to the command
░░ 'user_del' by the '[autobind]' actor:
░░ 
░░ {"uid": ["zuser3"], "continue": false, "version": "2.253"}
░░ ---------

░░ A detailed information about FreeIPA API can be found at upstream documentation API reference:
░░ https://freeipa.readthedocs.io/en/latest/api/index.html

░░ For details on the IPA API command 'user_del' see
░░ https://freeipa.readthedocs.io/en/latest/api/user_del.html

Feature Management

There is no separate management of the IPA API audit logging. Logging is always active on IPA server.

systemd journal has own mechanisms to control rates of messages coming from the services. The details can be found in the man page journald.conf(5).

Upgrade

There is no impact on upgrade. Once new IPA API code installed, any new application using it will start issuing log entries to the journald.

Test plan

Test of IPA API audit logging can be done by observing systemd journal.