Table of Contents

Audit logs / Event logs in PAS 6.0 and above

PAS 6.0 introduced a new system for audit logs, where events have been added and rewritten to fit the following goals:

  • Give a much more detailed overview of how the system is being used (more events, with way more detailed information). The ambition here is for simple debugging to be possible by just looking at the audit logs and following the user's journey along.
  • Automatic documentation -- If an event exists within the system, its properties and descriptions will be automatically added to the documentation here.
  • Easier integration with SIEM-solutions.

Basic Examples

To give an example of the improvements of these new audit logs, here are some examples:

A SAML Authentication

This is the content of the audit log after a SAML Username and Password authentication with the legacy events:

2025-02-26 14:22:27,930 [EVENT]  INFO: 2025-02-26T14:22:27+01:00 ITs-Laptop-3.local CEF:0|PhenixID|PAS|6.0.0-SNAPSHOT|EVT_006001|User authentication success with dynamic authenticator|2|destinationServiceName=https:/localhost/authentication/samlsp/my_sp_id_1 duser=user3 phenixIDTraceId=#4akCzCf6r78NpK8H src=127.0.0.1

And this is the content of the same action being done with the new audit logs:

2025-04-23 16:14:23,508 [EVENT]  INFO: 2025-04-23T16:14:23+02:00 DESKTOP-J6HPGV6 CEF:0|PhenixID|PAS|6.0.0-SNAPSHOT|auth_entrypoints_saml_auth_started|A new SAML Authentication flow has started|3|phxEntrypointId=my_saml_idp_id phxEntrypointTransactionType=AUTH phxEntrypointType=SAML phxHttpServerId=2f67ea6e-7a04-4d23-87c6-b3dd97a7d232 phxSAMLACSUrl=http://localhost:32769/Shibboleth.sso/SAML2/POST phxSAMLRequestedAuthenticationContext=null phxTraceId=#YFTp4LhpTqezu06B requestClientApplication=Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/121.0.0.0 Safari/537.36 sourceServiceName=https://sp.example.org/shibboleth src=127.0.0.1
2025-04-23 16:14:23,620 [EVENT]  INFO: 2025-04-23T16:14:23+02:00 DESKTOP-J6HPGV6 CEF:0|PhenixID|PAS|6.0.0-SNAPSHOT|saml_incoming_authnrequest_success|Incoming AuthnRequest successfully validated|3|dst=https://pas.localdev.me:8443/authentication/saml/my_saml_idp_id/login phxAuthnRequestId=_367bf2f5ad3d5cd20e0603b479bec731 phxEntityId=https://sp.example.org/shibboleth phxIsHokBinding=false phxRequestedAuthnContext= phxStrictSAMLValidation=false phxTargetEntityId=https://pas.localdev.me:8443/authentication/saml/my_saml_idp_id phxTraceId=
2025-04-23 16:14:28,181 [EVENT]  INFO: 2025-04-23T16:14:28+02:00 DESKTOP-J6HPGV6 CEF:0|PhenixID|PAS|6.0.0-SNAPSHOT|auth_authenticators_dynamic_successful|Dynamic authenticator successfully executed|4|duser=gundesvan phxAnalyticsTag= phxAuthenticatorAlias=usernamepassword phxAuthenticatorId=usernamepassword phxAuthenticatorType=Dynamic phxEntrypointId= phxEntrypointTransactionType=AUTH phxEntrypointType=SAML phxHttpServerId=2f67ea6e-7a04-4d23-87c6-b3dd97a7d232 phxInputElements=username,password phxTraceId=#YFTp4LhpTqezu06B requestClientApplication=Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/121.0.0.0 Safari/537.36 sourceServiceName=https://sp.example.org/shibboleth src=127.0.0.1
2025-04-23 16:14:28,655 [EVENT]  INFO: 2025-04-23T16:14:28+02:00 DESKTOP-J6HPGV6 CEF:0|PhenixID|PAS|6.0.0-SNAPSHOT|saml_outgoing_assertion_success|Outgoing assertion successfully created|3|duser=gundesvan phxAssertionId=_d4aa01799557bf732eb033eac04b3e76 phxAuthnContext=urn:oasis:names:tc:SAML:2.0:ac:classes:unspecified phxEntityId=https://pas.localdev.me:8443/authentication/saml/my_saml_idp_id phxTargetEntityId=https://sp.example.org/shibboleth phxTraceId=
2025-04-23 16:14:28,692 [EVENT]  INFO: 2025-04-23T16:14:28+02:00 DESKTOP-J6HPGV6 CEF:0|PhenixID|PAS|6.0.0-SNAPSHOT|auth_entrypoints_saml_auth_successful|A SAML Authentication has been successfully completed|4|duser=gundesvan phxEntrypointId=my_saml_idp_id phxEntrypointTransactionType=AUTH phxEntrypointType=SAML phxHttpServerId=2f67ea6e-7a04-4d23-87c6-b3dd97a7d232 phxSAMLACSUrl=http://localhost:32769/Shibboleth.sso/SAML2/POST phxSAMLRequestedAuthenticationContext=null phxTraceId= requestClientApplication=Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/121.0.0.0 Safari/537.36 sourceServiceName=https://sp.example.org/shibboleth src=127.0.0.1

An OIDC Authentication

This is the content of the audit log after an OIDC Username and Password authentication (with subsequent userinfo fetch) with the legacy events:

2025-02-26 14:42:23,238 [EVENT]  INFO: 2025-02-26T14:42:23+01:00 ITs-Laptop-3.local CEF:0|PhenixID|PAS|6.0.0-SNAPSHOT|EVT_006001|User authentication success with dynamic authenticator|2|destinationServiceName=my_oidc_rp_client_id duser=user3 phenixIDTraceId=#4akCzCf6r78NpK8H src=0:0:0:0:0:0:0:1

And this is the content of the same action being done with the new audit logs:

2025-04-23 16:21:00,558 [EVENT]  INFO: 2025-04-23T16:21:00+02:00 DESKTOP-J6HPGV6 CEF:0|PhenixID|PAS|6.0.0-SNAPSHOT|auth_entrypoints_oidc_auth_started|A new OIDC / OAuth Authentication flow has started|3|phxEntrypointId=my_oidc_op_id phxEntrypointTransactionType=AUTH phxEntrypointType=OIDC phxHttpServerId=7ea96456-d1b0-4f13-bc1e-b3661615a86c phxOIDCACRValues= phxOIDCRedirectUri=http://localhost:8090/protected_by_oidc_rp.php/callback phxOIDCScopes= phxTraceId=#RHvih2GZfzwrRvhT requestClientApplication=Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/121.0.0.0 Safari/537.36 sourceServiceName=my_oidc_rp_id src=127.0.0.1
2025-04-23 16:21:05,276 [EVENT]  INFO: 2025-04-23T16:21:05+02:00 DESKTOP-J6HPGV6 CEF:0|PhenixID|PAS|6.0.0-SNAPSHOT|auth_authenticators_dynamic_successful|Dynamic authenticator successfully executed|4|duser=gundesvan phxAnalyticsTag= phxAuthenticatorAlias=usernamepassword phxAuthenticatorId=usernamepassword phxAuthenticatorType=Dynamic phxEntrypointId= phxEntrypointTransactionType=AUTH phxEntrypointType=OIDC phxHttpServerId=7ea96456-d1b0-4f13-bc1e-b3661615a86c phxInputElements=username,password phxTraceId=#RHvih2GZfzwrRvhT requestClientApplication=Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/121.0.0.0 Safari/537.36 sourceServiceName=my_oidc_rp_id src=127.0.0.1
2025-04-23 16:21:05,507 [EVENT]  INFO: 2025-04-23T16:21:05+02:00 DESKTOP-J6HPGV6 CEF:0|PhenixID|PAS|6.0.0-SNAPSHOT|auth_entrypoints_oidc_auth_successful|An OIDC / OAuth Authentication has been successfully completed|4|duser=gundesvan phxEntrypointId=my_oidc_op_id phxEntrypointTransactionType=AUTH phxEntrypointType=OIDC phxHttpServerId=7ea96456-d1b0-4f13-bc1e-b3661615a86c phxOIDCACRValues= phxOIDCAccessTokenHash= phxOIDCAccessTokenJTI= phxOIDCCodeHash=kxZzPnZB1JLmuX0eG1wwLw phxOIDCIdTokenJTI= phxOIDCRedirectUri=http://localhost:8090/protected_by_oidc_rp.php/callback phxOIDCScopes=openid profile phxTraceId= requestClientApplication=Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/121.0.0.0 Safari/537.36 sourceServiceName=my_oidc_rp_id src=127.0.0.1
2025-04-23 16:21:06,510 [EVENT]  INFO: 2025-04-23T16:21:06+02:00 DESKTOP-J6HPGV6 CEF:0|PhenixID|PAS|6.0.0-SNAPSHOT|auth_entrypoints_oidc_token_success|An OIDC / OAuth token endpoint fetch has succeded|3|phxEntrypointId=my_oidc_op_id phxEntrypointType=OIDC phxHttpServerId=7ea96456-d1b0-4f13-bc1e-b3661615a86c phxOIDCAccessTokenHash=s-xli0qIRLhJI4Afaeo1uQ phxOIDCAccessTokenJTI= phxOIDCGrantType=authorization_code phxOIDCIdTokenJTI=8347760a-40e0-46aa-89bf-079926061ba0 phxOIDCRefreshTokenHash= phxOIDCScopes=openid profile phxOIDCTokenHash=kxZzPnZB1JLmuX0eG1wwLw phxTraceId=#qfxR0CSPbFIn9w9c requestClientApplication=mod_auth_openidc sourceServiceName=my_oidc_rp_id src=127.0.0.1
2025-04-23 16:21:06,652 [EVENT]  INFO: 2025-04-23T16:21:06+02:00 DESKTOP-J6HPGV6 CEF:0|PhenixID|PAS|6.0.0-SNAPSHOT|auth_entrypoints_oidc_userinfo_successful|An OIDC user info endpoint request has been successful|3|phxEntrypointId=my_oidc_op_id phxEntrypointType=OIDC phxHttpServerId=7ea96456-d1b0-4f13-bc1e-b3661615a86c phxOIDCTokenHash=s-xli0qIRLhJI4Afaeo1uQ phxTraceId= requestClientApplication=mod_auth_openidc sourceServiceName= src=127.0.0.1

A pipe execution

To avoid unnecessary event bloat, general pipe and valve executions will not by default trigger any audit logs. There are many valves who will trigger audit logs, such as OTP valves, PDF signature valves and so on, but the general execution of a normal valve causes no specific audit log. You may however enable this, such that any pipe or valve can cause an audit log with custom attributes set in the config. This may be triggered upon valve/pipe success, failure, or both. An example of this can be seen below, where a Pipe and one of its valves has audit logs enabled:

2025-02-26 15:33:16,593 [EVENT]  INFO: 2025-02-26T15:33:16+01:00 ITs-Laptop-3.local CEF:0|PhenixID|PAS|6.0.0-SNAPSHOT|pipes_valve_success|Valve executed successfully|4|customAttribute2=user3 phxExecTime=16 phxPipeName=55f55b8e-33b8-4fd1-bad0-5731fc98c08c phxTraceId=#Dd1qbWB98hXl8nLa phxValveIndex=1 phxValveType=com.phenixidentity.pipes.valves.ldap.LDAPSearchValve
2025-02-26 15:33:16,604 [EVENT]  INFO: 2025-02-26T15:33:16+01:00 ITs-Laptop-3.local CEF:0|PhenixID|PAS|6.0.0-SNAPSHOT|pipes_pipe_success|Pipe executed successfully|4|customAttribute=user3 phxExecTime=41 phxPipeName=55f55b8e-33b8-4fd1-bad0-5731fc98c08c phxTraceId=#Dd1qbWB98hXl8nLa

This may be achieved by configuring your pipe or valves config block with the following:

  "auditLog": {
    "enabled": "true",
    "logSuccess":"true", //default is true
    "logFailure": "true", //default is true
    "attributes": {
      "customAttribute": "{{item.uid}}"
    }
  }

In this way you can achieve a customized audit log for any pipe or valve execution. Custom attributes are expandable with the same scopes as any valve.

The format

The event format (CEF, Common Event Format.) remains the same, and the logging configuration remains the same. The visible difference in event.log will be:

  • The event IDs
  • The event names
  • The event extensions (properties like duser)
  • The event severities

This means that all the old legacy events from PAS 5 and earlier will no longer be seen in event.log. It is however still possible to enable these legacy events so that old reports / SIEM integrations still work. How to do this is described below.

If you are running PAS as a container, all logs will be written to the standard output as JSON instead, see Running as a Container for details.

Enabling legacy events

If you already have SIEM integrations set up, or depend on previously defined Reports, and need the legacy events back you can achieve this by setting the vm option -Dcom.phenixidentity.globals.enableLegacyEvents=true. This will cause both the new audit logs and the old legacy events to trigger. You may not disable the new audit logs through any vm option, but if you wish to separate these logs into different files you may do so by adjusting your log4j configuration to fit this pattern:

<RollingFile name="EVENT" fileName="logs/event.log" filePattern="logs/event.%date{yyyy-MM-dd}.log"
             append="true">
    <PatternLayout pattern="%d [%c{1}] %X{trace_id} %p: %m%n"/>
    <!--- Add the filter below  -->
    <Filters>
        <RegexFilter regex=".*EVT_.*" onMatch="ACCEPT" onMismatch="DENY"/>  <!-- This file only accepts old event format -->
    </Filters>
    <Policies>
        <TimeBasedTriggeringPolicy interval="1"/>
    </Policies>
</RollingFile>
<!-- Add this RollingFile below for the new audit logs -->
<RollingFile name="AUDIT" fileName="logs/audit.log" filePattern="logs/audit.%date{yyyy-MM-dd}.log"
             append="true">
    <PatternLayout pattern="%d [%c{1}] %X{trace_id} %p: %m%n"/>
    <Filters>
        <RegexFilter regex=".*EVT_.*" onMatch="DENY" onMismatch="ACCEPT"/> <!-- This file only accepts new event format -->
    </Filters>
    <Policies>
        <TimeBasedTriggeringPolicy interval="1"/>
    </Policies>
</RollingFile>
...
<Logger name="EVENT" level="INFO" additivity="false">
    <AppenderRef ref="EVENT"/>
    <AppenderRef ref="AUDIT"/> <!--- Add this line-->
    <AppenderRef ref="CONSOLE"/>
</Logger>

Database persistence of events

One change that has been made in the default configuration of boot.json is that events persistence in the database is turned off by default. You may still enable it by setting "disable_events":"false" in the config block of com.phenixidentity~phenix-store-mpl. This means that old installations upgrading will still have database persistence enabled if they had it enabled before, but fresh installations will have it disabled until they enable it. The reason we have disabled it by default is mainly because the new audit logs contain a lot of information, and there are a lot of them. This would likely cause space issues in the database eventually if not maintained regularly, which is still an option to do. More details are outlined in the article Disable events to database.

If database persistence is enabled, note that a new table in the database needs to be created for the new events. The reason for this are multiple, one is to keep old reports still usable, and one is that the new events have so many different parameters that keeping a column for each parameter would be unfeasible. If you are using an internal database this schema is updated automatically, but if you are using an external database the following SQL script can be run to add the new table:

For MSSQL:

CREATE TABLE audit_events (
    eventID varchar(255),
    message varchar(1500),
    host varchar(255),
    params varchar(MAX),
    date datetime2
);
CREATE INDEX audit_event_date ON audit_events (date);
CREATE INDEX audit_event_id ON audit_events (eventID);

and for MySQL:

CREATE TABLE audit_events (
    eventID varchar(255),
    message varchar(1500),
    host varchar(255),
    params TEXT,
    date datetime
);
CREATE INDEX audit_event_date ON audit_events (date);
CREATE INDEX audit_event_id ON audit_events (eventID);

What about reports?

The Reports module relies on fetching events from the database to create reports and is still compatible with the new audit logs. The old reports however have been moved to the Legacy category, and some new reports are available. Note that the new audit logs are not as easily searchable through SQL as there are no separate columns for each parameter, and instead a new report configuration option has been introduced to resolve this. As this will however query the database for more rows than before, this is not as powerful as before for large data sets. To create complex reports with big data sets it is recommended to use a more powerful SIEM solution.

Reports post-processing

You may now utilize some post-processing for filtering rows and choosing which param columns to display. An example can be seen below:

{
    "displayName": "Events for user",
    "query": "select * from audit_events order by date desc limit 10000",
    "category":"Audit",
    "description": "List events for user",
    "params": [{
        "name": "username",
        "displayName": "Username",
        "type": "input"
    }],
    "postProcessing": {
        "paramColumns": "*",
        "filter": {
            "duser":  {"equals": "{{username}}"}
        }
    }
}

This report will select the last 10000 events in the database, and then filter so only events with the param duser with the value {{username}} is displayed. It also uses the familiar input system where {{username}} is defined by the user input when the report is generated. You can piece together several filters by using AND and OR operators. A logical NOT operator is also available. Below is a complex example that showcases the full potential of the post-processing filter system:

{
    ...
    "postProcessing": {
        "paramColumns": "*",
        "filter": {
            "AND": [
                {"duser":  {"equals": "user1"}},
                {"phxRecaptchaScore":  {"smallerthan": "0.9"}},
                {"NOT":  {"phxAuthenticatorId":  {"contains": "some-id"}}},
                {"OR":  [
                    {"src":  {"contains": "127.0.0."}},
                    {"src":  {"contains": "0:0:0:0:0:0:0:"}}
                ]}
            ],
        }
    }
}

The example filter above will return events where duser is user1, phxRecaptchaScore is smaller than 0.9, phxAuthenticatorId does not contain some-id, and the IP address contains either 127.0.0 or 0:0:0:0:0:0:0:. The logical operators work as above, and the comparators available for filtering are equals, contains, greaterthan, and smallerthan (the last two only works for numbers).

You can also choose which parameter columns should be displayed. Default is * (all param columns) and should be the parameter names comma-separated without whitespace, e.g. "duser,src".

Information regarding severity

Each audit log has a set severity value of between 0 and 10.

According to the CEF specification, these are the common levels:

  • Low: 0-3
  • Medium: 4-6
  • High: 7-8
  • Very-High: 9-10

We wanted more granularity, so we use a combination of the standard syslog levels (0-7), but inverted, and with some minor additions:

  • Emergency: 10 - System is unusable
  • Alert: 9 - Action must be taken immediately
  • Critical: 8 - Critical conditions
  • Error: 7 - Error conditions
  • Warning: 6 - Warning conditions
  • Notice: 4 - Normal but significant conditions
  • Info: 3 - Informational messages
  • Debug: 2 - Debug-level messages
  • Trace: 1 - Trace-level messages
Logging