This chapter describes audit logging in Curity Identity Server. Audit logging is an always-on feature, facilitated through Apache Log4j 2.
Audit messages are logged at the INFO level to the audit-events logger. An audit message is formatted as a Syslog (RFC 5424) Structured Data Message, where the structured data parameters of the message are populated by the Audit Data parameters of the event. Most individual parameters can be accessed through the Map Conversion Pattern provided by the Log4j Pattern Layout; e.g. %K{key}. The id, type and message parameters are exceptions and must be accessed through the structured_data_id, structured_data_type and structured_data_message Conversion Patterns, respectively.
INFO
audit-events
%K{key}
id
type
message
structured_data_id
structured_data_type
structured_data_message
Audit logging is configured through the Log4j configuration file located at $IDSVR_HOME/etc/log4j2.xml. For in-depth details on how to configure Log4j, please consult the Apache Log4j 2 Manual.
$IDSVR_HOME/etc/log4j2.xml
The audit log configuration consists of a logger and two appenders.
<AsyncLogger name="audit-events" level="INFO" additivity="false"> <AppenderRef ref="audit-log"/> <AppenderRef ref="audit-db"/> </AsyncLogger>
The default audit logger configuration has the following properties:
audit-log
audit-db
<RollingFile name="audit-log" fileName="${env:IDSVR_HOME}/var/log/audit.log" filePattern="${env:IDSVR_HOME}/var/log/audit.log.%i.gz"> <Policies> <SizeBasedTriggeringPolicy size="10MB"/> </Policies> <Rfc5424Layout appName="Curity" facility="AUDIT" newLine="true" includeMDC="false" /> </RollingFile>
The default audit to file appender configuration has the following properties:
$IDSVR_HOME/var/log/audit.log
10MB
$IDSVR_HOME/var/log/audit.log.<index>.gz
<index>
<JDBC name="audit-db" tableName="audit"> <ConnectionFactory class="se.curity.identityserver.logging.AuditDatabaseConnectionFactory" method="getDatabaseConnection" /> <Column name="id" pattern="%structured_data_id" /> <Column name="event_type" pattern="%structured_data_type" /> <Column name="message" pattern="%structured_data_message" /> <Column name="instant" isEventTimestamp="true" /> <Column name="event_instant" pattern="%K{instant}" /> <Column name="server" pattern="%K{server}" /> <Column name="subject" pattern="%K{subject}" /> <Column name="client" pattern="%K{client}" /> <Column name="resource" pattern="%K{resource}" /> <Column name="authenticated_subject" pattern="%K{authenticatedSubject}" /> <Column name="authenticated_client" pattern="%K{authenticatedClient}" /> <Column name="acr" pattern="%K{acr}" /> <Column name="endpoint" pattern="%K{endpoint}" /> <Column name="session" pattern="%K{session}" /> </JDBC>
The default audit to database appender configuration has the following properties:
audit
se.curity.identityserver.logging.AuditDatabaseConnectionFactory
Column
Note
If you are using PostgreSQL or CockroachDB (also uses the PostgreSQL JDBC driver) datasource to log audit events, please note, that in the current version of Log4J (2.7) all columns (except if isEventTimestamp=”true”) are treated as unicode strings and their values are inserted via the PreparedStatement.setNString method, that is not supported by PostgreSQL JDBC driver. Log entries containing Feature is not implemented: PreparedStatement.setNString will indicate this problem in the server log. To work around this issue you should explicitly declare all string columns as non-Unicode in your appender configuration. This is done by adding isUnicode="false" property to column definitions.
PreparedStatement.setNString
Feature is not implemented: PreparedStatement.setNString
isUnicode="false"
By default, every message logged by the Database Appender will need to obtain a database connection from the JDBC connection pool. This can become a bottleneck if the server handles a very large event load.
To optimise for performance (at the cost of reliability), it is possible to batch messages to minimize the impact of each individual message.
To do that, use the bufferSize attribute as shown below:
bufferSize
<JDBC name="audit-db" tableName="audit" bufferSize="8">
Curity includes a healthcheck for the Database Appender, but to enable it, you must set the log4j2.formatMsgAsync system property to true. That will cause a message similar to the one below to be logged every few seconds:
log4j2.formatMsgAsync
true
se.curity.identityserver.app.Log4jMonitor - Current logging system health level is [OK]: PT0.000449917S
If the delay between an event occurring and the message being flushed out is within a reasonable limit, the above message will contain [OK].
[OK]
If it takes longer than expected, you may also see one of [SLOW] (over 250ms), [VERY_SLOW] (over 1sec) and [CRITICAL] (over 2sec).
[SLOW]
250ms
[VERY_SLOW]
1sec
[CRITICAL]
2sec
A system that is working within reasonable conditions should only very rarely report anything other than [OK]. Long delays are normally caused by a logger appender running too slowly. Batching messages as explained above may help if that’s a problem.
For more information about configuring the JDBC appender, please consult the Apache Log4j 2 Manual.
Audit events carry a common set of parameters; some present in all events, others not.
These parameters are present in all audit events.
instant
These parameters are present in some audit events; depending on the context of the event.
subject
client
resource
authenticatedSubject
authenticatedClient
acr
endpoint
session
Event that occurs when a new profile is added to the server.
java type
Event that occurs when a token is introspected by an external source.
Event that occurs when an OAuth refresh token is issued.
Event that occurs when an OAuth refresh token is revoked by an external source.
Event that occurs when an OAuth access token is issued.
Event that occurs when an OAuth access token is revoked by an external source.
Event that occurs when an OpenID Connect ID token is issued.
Event that occurs when a DCR initial access token is issued.
Event that occurs when a DCR initial access token is consumed registering a dynamic client.
Event that occurs when a DCR initial access token is revoked by an external source.
Event that occurs when an OAuth client is dynamically registered (DCR).
Event that occurs when an oauth-userinfo is successfully queried.
Event that occurs when an OAuth authorization code is issued.
Event that occurs when an OAuth authorization code is consumed.
Event that occurs when a delegation is issued.
Event that occurs when a delegation is revoked.
Event that occurs when an account is created.
Event that occurs when an account is linked.
Event that occurs when an account is activated.
Event that occurs when an account is updated through SCIM.
Event that occurs when an account is created through SCIM.
Event that occurs when an account is deleted through SCIM.
Event that occurs at successful authentication using an OAuth access token.
Event that occurs when a client is successfully authenticated.
Event that occurs when a client fails to authenticate.
Event that occurs on user logout.
Event that occurs on successful user authentication.
Event that occurs on successful user SSO authentication.
Event that occurs when an SSO session is created
Event that occurs when back-channel authentication is started.
Event that occurs when back-channel authentication succeeds.
Event that occurs when back-channel authentication fails.