frontend: add systemd journal audit of executed API commands

For each executed command in server context, send the information about
the command to the systemd journal. The resulting string is similar to
what is recored in httpd's error_log for API requests coming through the
RPC layer.

In server mode operations are performed directly on the server over
LDAPI unix domain socket, so httpd end-point is not used and therefore
operations aren't recorded in the error_log.

With this change any IPA API operation is sent as an audit event to the
journal, alog with additional information collected by the journald
itself.

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.

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

Messages sent with syslog NOTICE priority.

More information is available in the design document 'audit-ipa-api.md'

Fixes: https://pagure.io/freeipa/issue/9589

Signed-off-by: Alexander Bokovoy <abokovoy@redhat.com>
Reviewed-By: Rob Crittenden <rcritten@redhat.com>
This commit is contained in:
Alexander Bokovoy
2024-05-08 14:47:53 +03:00
committed by Rob Crittenden
parent 145e33174d
commit 84eed2a67f
9 changed files with 467 additions and 6 deletions

View File

@@ -132,6 +132,56 @@ c \- compare\p
W \- self\-write\p
O \- self\-obliterate
.SH "AUDIT AND LOGGING"
The IPA API logs audit messages to systemd journal about each command executed
through IPA API on the IPA server. These messages can be found by grepping
systemd journal with \fBjournalctl -g IPA.API\fR command. The message includes
following information:
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"}
.TP
\fB/usr/bin/ipa[247422]\fR
executable name and PID (`/mod_wsgi` for HTTP end-point)
.TP
\fB[IPA.API]\fR
marker to allow searches with \fBjournalctl -g IPA.API\R
.TP
\fBusername@REALM\fR
authenticated Kerberos principal or \fB[autobind]\fR marker for LDAP-based operations done as root
.TP
\fBuser_del\fR
name of the command executed
.TP
\fBSUCCESS\fR
result of execution: \fBSUCCESS\fR or an exception name
.TP
\fB[ldap2_140328582446688]\fR
LDAP backend connection instance identifier. The identifier will be the same for all
operations performed under the same request. This allows to identify operations
which were executed using the same LDAP connection. For API operations that
didn't result in LDAP access, there will be \fB[no_connection_id]\fR marker.
.TP
\fB{"uid": ["foobar"], "continue": false, "version": "2.253"}\fR
a list of arguments and options passed to the IPA API command, provided in JSON
format. Credentials are filtered out.
.LP
All explicitly requested operations logged. Internal operations, initiated as
part of execution of the explicitly requested IPA API calls, aren't logged. For
HTTP end-point operations will be logged as performed by the '/mod_wsgi'
executable binary. Remaining details can be inspected through the systemd
journal as journald records execution context. See systemd.journal\-fields(7)
for details.
The details of the individual logged messages can be explained with the help of
'\fBjournalctl -x\fR' command, while full set of logged properties can be
retrieved with '\fBjournalctl -o json-pretty\fR'. See journalctl(1) for details
on the systemd journal viewer.
For the sample message above, an explanation could be requested with '\fBjournalctl -x -g ldap2_140328582446688\fR' where LDAP backend connection instance identifier can be used to uniquely fetch that individual message.
.SH "EXAMPLES"
.TP
\fBipa help commands\fR
@@ -206,4 +256,5 @@ IPA default configuration file.
ipa\-client\-install(1), ipa\-compat\-manage(1), ipactl(1), ipa\-dns\-install(1),
ipa\-getcert(1), ipa\-getkeytab(1), ipa\-join(1), ipa\-ldap\-updater(1),
ipa\-nis\-manage(1), ipa\-replica\-install(1), ipa\-replica\-manage(1), ipa\-replica\-prepare(1),
ipa\-rmkeytab(1), ipa\-server\-certinstall(2), ipa\-server\-install(1), ipa\-server\-upgrade(1)
ipa\-rmkeytab(1), ipa\-server\-certinstall(2), ipa\-server\-install(1), ipa\-server\-upgrade(1),
systemd.journal\-fields(7), journalctl(1)

View File

@@ -267,6 +267,13 @@ AC_ARG_WITH([systemdtmpfilesdir],
[systemdtmpfilesdir=$($PKG_CONFIG --define-variable=prefix='${prefix}' --variable=tmpfilesdir systemd)])
AC_SUBST([systemdtmpfilesdir])
AC_ARG_WITH([systemdcatalogdir],
AS_HELP_STRING([--with-systemdcatalogdir=DIR],
[Directory for systemd journal catalog files]),
[systemdcatalogdir=$with_systemdcatalogdir],
[systemdcatalogdir=$($PKG_CONFIG --define-variable=prefix='${prefix}' --variable=catalogdir systemd)])
AC_SUBST([systemdcatalogdir])
dnl ---------------------------------------------------------------------------
dnl - Server-only configuration
dnl ---------------------------------------------------------------------------

View File

@@ -0,0 +1,262 @@
# 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.

View File

@@ -33,3 +33,4 @@ FreeIPA design documentation
prci_checker.md
rbcd.md
id-mapping.md
audit-ipa-api.md

View File

@@ -905,6 +905,7 @@ Requires: python3-urllib3 >= 1.24.2-3
# For urllib3.util.ssl_match_hostname
Requires: python3-urllib3 >= 1.25.8
%endif
Requires: python3-systemd
%description -n python3-ipalib
IPA is an integrated solution to provide centrally managed Identity (users,
@@ -1174,6 +1175,10 @@ fi
/bin/systemctl reload-or-try-restart oddjobd
%tmpfiles_create ipa.conf
%journal_catalog_update
%postun server
%journal_catalog_update
%posttrans server
# don't execute upgrade and restart of IPA when server is not installed
@@ -1543,6 +1548,7 @@ fi
%attr(644,root,root) %{_unitdir}/ipa-otpd@.service
%attr(644,root,root) %{_unitdir}/ipa-ccache-sweep.service
%attr(644,root,root) %{_unitdir}/ipa-ccache-sweep.timer
%attr(644,root,root) %{_journalcatalogdir}/ipa.catalog
# END
%attr(755,root,root) %{plugin_dir}/libipa_pwd_extop.so
%attr(755,root,root) %{plugin_dir}/libipa_enrollment_extop.so

View File

@@ -18,6 +18,10 @@ systemdsystemunit_DATA = \
ipa-ccache-sweep.timer \
$(NULL)
dist_systemdcatalog_DATA = \
ipa.catalog \
$(NULL)
CLEANFILES = $(systemdsystemunit_DATA)
%: %.in Makefile

58
init/systemd/ipa.catalog Normal file
View File

@@ -0,0 +1,58 @@
#
#
#
-- 6d70f1b493df36478bc3499257cd3b17
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/@IPA_API_COMMAND@.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:
@MESSAGE@
The command was executed by '@SYSLOG_IDENTIFIER@' 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 '@SYSLOG_IDENTIFIER@' 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 '@IPA_API_ACTOR@'
- name of the command executed, in this case '@IPA_API_COMMAND@'
- result of execution: `SUCCESS` or an exception name. In this case it was
'@IPA_API_RESULT@'
- 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
'@IPA_API_COMMAND@' by the '@IPA_API_ACTOR@' actor:
@IPA_API_PARAMS@
---------
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 '@IPA_API_COMMAND@' see
https://freeipa.readthedocs.io/en/latest/api/@IPA_API_COMMAND@.html

View File

@@ -24,6 +24,7 @@ All constants centralised in one file.
import os
import string
import uuid
from ipaplatform.constants import constants as _constants
from ipapython.dn import DN
@@ -55,6 +56,8 @@ TLS_VERSION_MAXIMAL = "tls1.3"
TLS_VERSION_DEFAULT_MIN = None
TLS_VERSION_DEFAULT_MAX = None
SD_IPA_API_MESSAGE_ID = uuid.uuid3(uuid.NAMESPACE_DNS, 'IPA.API')
# regular expression NameSpace member names must match:
NAME_REGEX = r'^[a-z][_a-z0-9]*[a-z0-9]$|^[a-z]$'

View File

@@ -30,15 +30,21 @@ from ipalib.base import NameSpace
from ipalib.plugable import Plugin, APINameSpace
from ipalib.parameters import create_param, Param, Str, Flag
from ipalib.parameters import create_signature
from ipalib.parameters import Password # pylint: disable=unused-import
from ipalib.output import Output, Entry, ListOfEntries
from ipalib.text import _
from ipalib.errors import (ZeroArgumentError, MaxArgumentError, OverlapError,
VersionError, OptionError,
ValidationError, ConversionError)
from ipalib.errors import (
ZeroArgumentError,
MaxArgumentError,
OverlapError,
VersionError,
OptionError,
ValidationError,
ConversionError,
)
from ipalib import errors, messages
from ipalib.request import context, context_frame
from ipalib.util import classproperty, classobjectproperty, json_serialize
from ipalib.constants import SD_IPA_API_MESSAGE_ID
if six.PY3:
unicode = str
@@ -470,6 +476,41 @@ class Command(HasParam):
self.context.principal = getattr(context, 'principal', None)
return self.__do_call(*args, **options)
def __audit_to_journal(self, func, params, result):
if getattr(context, 'audit_action', None) != func:
return
setattr(context, 'audit_action', None)
from systemd import journal
from ipalib.ipajson import json_encode_binary
args_opts = dict([*self._safe_args_and_params(**params)])
json_encoded = json_encode_binary(args_opts, API_VERSION,
pretty_print=False)
actor = self.context.principal or "[autobind]"
conn = getattr(self.api.Backend, 'ldap2', None)
if conn is not None:
conn_id = conn.id
else:
conn_id = '[no_connection_id]'
journal.send(
"[%s] %s: %s: %s [%s] %s"
% (
"IPA.API",
actor,
func,
result,
conn_id,
json_encoded
),
PRIORITY=journal.LOG_NOTICE,
SYSLOG_IDENTIFIER=self.api.env.script,
MESSAGE_ID=SD_IPA_API_MESSAGE_ID,
IPA_API_COMMAND=func,
IPA_API_PARAMS=json_encoded,
IPA_API_RESULT=result,
IPA_API_ACTOR=actor
)
def __do_call(self, *args, **options):
self.context.__messages = []
if 'version' in options:
@@ -495,8 +536,17 @@ class Command(HasParam):
)
if self.api.env.in_server:
self.validate(**params)
if all([self.name != "console",
not getattr(context, "audit_action", None)]):
setattr(context, "audit_action", self.name)
(args, options) = self.params_2_args_options(**params)
ret = self.run(*args, **options)
try:
ret = self.run(*args, **options)
except Exception as e:
if self.api.env.in_server:
self.__audit_to_journal(self.name, params, type(e).__name__)
raise
if isinstance(ret, dict):
for message in self.context.__messages:
messages.add_message(options['version'], ret, message)
@@ -508,11 +558,30 @@ class Command(HasParam):
ret['summary'] = self.get_summary_default(ret)
if self.use_output_validation and (self.output or ret is not None):
self.validate_output(ret, options['version'])
if self.api.env.in_server:
self.__audit_to_journal(self.name, params, 'SUCCESS')
return ret
def add_message(self, message):
self.context.__messages.append(message)
def _safe_args_and_params(self, **params):
"""
Iterate through *safe* values of args and options
This method uses `parameters.Param.safe_value()` to mask
passwords when logging. It yields tuples of (name, value)
of the arguments and options.
"""
for arg in self.args():
value = params.get(arg.name, None)
yield (arg.name, arg.safe_value(value))
for option in self.options():
if option.name not in params:
continue
value = params[option.name]
yield (option.name, option.safe_value(value))
def _repr_iter(self, **params):
"""
Iterate through ``repr()`` of *safe* values of args and options.