Logging migration guide - SSO

Owned by Former user (Deleted)
Last updated: 2022-10-20 by John Jellema
24 min read

This document highlights the differences between the logging solution since version 9.1 and before it, and offers some advises how to adapt to the new solution.

If you have not customised any logging features or implemented any tools for parsing the diagnostic logs, then the logging update provided will function similarly to prior releases with only simplifications in the location of the diagnostics logs for all applications installed on the same Tomcat server. Please ensure you review at least the Password reset and Password application sections as logging location and formatting has been updated.

Differences

The main differences between the new and old logging system are described below :

  • All SSO diagnostic log events by different web applications are written to the same log file and rotated on a daily basis

    • the file has been renamed from uas3_diag.<YYYY-MM-DD>.log to sso_diag.<YYYY-MM-DD>.log

  • In addition these log files are written to the ubilogin/logs folder and rotated on a daily basis

    • uas3_audit.<YYYY-MM-DD>.log - SSO authentication server audit log

      • events are created by default

      • no changes in v. 9.1

    • uas3_statistics.<YYYY-MM-DD>.log - Statistics log

    • management_audit.<YYYY-MM-DD>.log - Management audit log

    • password_audit.<YYYY-MM-DD>.log - Password applications audit log

  • Diagnostic level format has been slightly changed:

    • new column after the timestamp has been inserted and there the web application name producing the log event is printed, the name is one of the following

      • uas - SSO authentication server

      • ubilogin - SSO management UI

      • logviewer - SSO management UI Logviewer application

      • search - SSO management UI LDAP Search application

      • sso-api - SSO management API

      • totp - TOTP API

      • password - Password application

      • password-reset - Password reset application

      • cdc - Common Domain Cookie (CDC) discovery service

      • otpserver - OTP list server

    • next column used to be only a specific entry type from the predefined list (init, tech, environment, method etc.) but now it may print a fully qualified class name instead depending on the application or library producing the output

    • new column has been inserted to print the log level of the event

    • in case of sso-api originated log events the following columns have been added next

      • remote IP address of the caller

      • name of the authenticated user calling the API (sub)

    • the error message which is printed instead of the full stack trace in case of an exception contains more parts of the stack trace and is thus more verbose

Examples

Expand the elements below, by clicking the caret symbol, to see examples comparing the historical logging format and the updated logging format.

Before 9.1

Since 9.1

Before 9.1

Since 9.1

Old format

2022-09-30 07:49:31,398 tech ping: the system is alive

New format

2022-10-06 09:49:33,476 uas tech INFO ping: the system is alive

Applications printed startup events to various log files or did not print them at all - SSO diagnostic log sample (uas3_diag)

2022-09-30 07:49:28,163 init Ubilogin Authentication Server 9.0.0 starting
...
2022-09-30 07:49:31,304 init Ubilogin Authentication Server 9.0.0 started
2022-09-30 07:49:31,398 tech ping: the system is alive

All the applications are printing about their startup to the same SSO diagnostic log file (depends on the applications you have configured, and the order may vary)

2022-10-06 09:45:24,570 password init INFO Ubilogin Password 9.1.0 starting
...
2022-10-06 09:45:36,119 password init INFO Ubilogin Password 9.1.0 started

2022-10-06 09:45:55,937 sso-api init INFO ServletContainerApplication version 9.1.0 starting
...
2022-10-06 09:45:59,636 sso-api com.globalsign.iam.sso.api.message.ObjectMessageFeature INFO ObjectMessageFeature enabled

2022-10-06 09:46:17,067 cdc init INFO DiscoveryService starting
2022-10-06 09:46:17,097 cdc init INFO DiscoveryService started [cdc.cookie.domain= cdc.cookie.secure=true cdc.entityid.pattern=.* cdc.returnurl.pattern=^https?://.*$ cdc.p3p.policy=CP="CAO PSA OUR"]

2022-10-06 09:46:32,259 otpserver init INFO Ubilogin OTP Service 9.1.0 starting
...
2022-10-06 09:46:33,613 otpserver init INFO Ubilogin OTP Service 9.1.0 started

2022-10-06 09:46:45,089 search init INFO Ubilogin Search 9.1.0 started

2022-10-06 09:47:55,731 totp init INFO TOTP application 9.1.0 started

2022-10-06 09:48:19,934 ubilogin init INFO Ubilogin Server Management 9.1.0 started

2022-10-06 09:48:43,840 password-reset init INFO Ubilogin OTP Password Reset 9.1.0 starting
...
2022-10-06 09:48:52,556 password-reset init INFO Ubilogin OTP Password Reset 9.1.0 started

2022-10-06 09:49:17,632 uas init INFO Ubilogin Authentication Server 9.1.0 starting
...
2022-10-06 09:49:32,879 uas init INFO Ubilogin Authentication Server 9.1.0 started
2022-10-06 09:49:33,476 uas tech INFO ping: the system is alive

2022-10-06 09:49:41,382 logviewer init INFO Ubilogin Log Viewer 9.1.0 started

The old output (v 9.0.0)

2022-09-30 07:49:28,163 init Ubilogin Authentication Server 9.0.0 starting
2022-09-30 07:49:28,195 tech JLDAP: url=ldap://localhost/cn=Ubilogin,dc=localhost,servers=[ldap://localhost/cn=Ubilogin,dc=localhost],tls=false,confConnectTimeout=15000,confReadTimeout=15000,confMaxAge=120000,confAuthPool=8,failoverType=multi-master
2022-09-30 07:49:28,288 init Ubilogin Directory: ldap://localhost/cn=Ubilogin,dc=localhost: connected
2022-09-30 07:49:28,320 environment JVM Input Arguments:
...
2022-09-30 07:49:28,413 environment VersionInfo:
2022-09-30 07:49:28,445 environment activemq-client-5.17.1.jar
2022-09-30 07:49:28,445 environment animal-sniffer-annotations-1.17.jar
2022-09-30 07:49:28,445 environment bcmail-jdk15on-1.70.jar
2022-09-30 07:49:28,445 environment bcpkix-jdk15on-1.70.jar
2022-09-30 07:49:28,445 environment bcprov-jdk15on-1.70.jar
2022-09-30 07:49:28,445 environment bcutil-jdk15on-1.70.jar
2022-09-30 07:49:28,445 environment checker-qual-2.5.2.jar
2022-09-30 07:49:28,445 environment cid-model-6.0.0.jar 6.0.0
2022-09-30 07:49:28,445 environment cid-sso-adapter-6.0.0.jar 6.0.0
2022-09-30 07:49:28,445 environment cid-util-6.0.0.jar 6.0.0
2022-09-30 07:49:28,445 environment common-lcrypt-9.0.0.jar 9.0.0
2022-09-30 07:49:28,445 environment common-log4j-ubi-9.0.0.jar 9.0.0
2022-09-30 07:49:28,445 environment common-ubiutil-9.0.0.jar 9.0.0
2022-09-30 07:49:28,445 environment commons-codec-1.9.jar
2022-09-30 07:49:28,445 environment commons-compress-1.9.jar
2022-09-30 07:49:28,445 environment commons-dbutils-1.7.jar
2022-09-30 07:49:28,445 environment commons-io-2.11.0.jar
2022-09-30 07:49:28,445 environment commons-lang3-3.12.0.jar
2022-09-30 07:49:28,445 environment error_prone_annotations-2.2.0.jar
2022-09-30 07:49:28,445 environment failureaccess-1.0.jar
2022-09-30 07:49:28,445 environment geronimo-j2ee-management_1.1_spec-1.0.1.jar
2022-09-30 07:49:28,445 environment geronimo-jms_1.1_spec-1.1.1.jar
2022-09-30 07:49:28,445 environment gson-2.9.0.jar
2022-09-30 07:49:28,445 environment guava-27.0-jre.jar
2022-09-30 07:49:28,445 environment hawtbuf-1.11.jar
2022-09-30 07:49:28,445 environment ids-accounting-common-2.0.0.jar
2022-09-30 07:49:28,445 environment istack-commons-runtime-3.0.12.jar
2022-09-30 07:49:28,445 environment j2objc-annotations-1.1.jar
2022-09-30 07:49:28,445 environment jakarta.activation-2.0.1.jar
2022-09-30 07:49:28,445 environment jakarta.activation-api-1.2.2.jar
2022-09-30 07:49:28,445 environment jakarta.xml.bind-api-2.3.3.jar
2022-09-30 07:49:28,445 environment jakarta.xml.soap-api-2.0.1.jar
2022-09-30 07:49:28,445 environment javax.json-1.1.4.jar
2022-09-30 07:49:28,445 environment jaxb-runtime-2.3.6.jar
2022-09-30 07:49:28,445 environment jquery-3.6.0.jar
2022-09-30 07:49:28,445 environment json-20180813.jar
2022-09-30 07:49:28,445 environment json-simple-1.1.1.jar
2022-09-30 07:49:28,445 environment jsr305-3.0.2.jar
2022-09-30 07:49:28,445 environment jstl-api-1.2.jar
2022-09-30 07:49:28,445 environment jstl-impl-1.2.jar
2022-09-30 07:49:28,445 environment ldap-5.0.0.jar 5.0.0
2022-09-30 07:49:28,445 environment lettuce-core-5.3.7.RELEASE.jar
2022-09-30 07:49:28,445 environment listenablefuture-9999.0-empty-to-avoid-conflict-with-guava.jar
2022-09-30 07:49:28,445 environment log4j-1.2.17.jar
2022-09-30 07:49:28,445 environment netty-buffer-4.1.63.Final.jar
2022-09-30 07:49:28,445 environment netty-codec-4.1.63.Final.jar
2022-09-30 07:49:28,445 environment netty-common-4.1.63.Final.jar
2022-09-30 07:49:28,445 environment netty-handler-4.1.63.Final.jar
2022-09-30 07:49:28,445 environment netty-resolver-4.1.63.Final.jar
2022-09-30 07:49:28,445 environment netty-transport-4.1.63.Final.jar
2022-09-30 07:49:28,445 environment org.apache.oltu.oauth2.authzserver-1.0.2.jar
2022-09-30 07:49:28,445 environment org.apache.oltu.oauth2.client-1.0.2.jar
2022-09-30 07:49:28,445 environment org.apache.oltu.oauth2.common-1.0.2.jar
2022-09-30 07:49:28,445 environment org.apache.oltu.oauth2.resourceserver-1.0.2.jar
2022-09-30 07:49:28,445 environment reactive-streams-1.0.3.jar
2022-09-30 07:49:28,445 environment reactor-core-3.3.16.RELEASE.jar
2022-09-30 07:49:28,445 environment reload4j-1.2.19.jar
2022-09-30 07:49:28,445 environment saaj-impl-2.0.1.jar
2022-09-30 07:49:28,445 environment slf4j-api-1.7.36.jar
2022-09-30 07:49:28,445 environment slf4j-reload4j-1.7.36.jar
2022-09-30 07:49:28,445 environment sso-directory-9.0.0.jar 9.0.0
2022-09-30 07:49:28,445 environment sso-directory-spi-9.0.0.jar 9.0.0
2022-09-30 07:49:28,445 environment sso-etsimss-9.0.0.jar 9.0.0
2022-09-30 07:49:28,445 environment sso-etsimss-jaxb-9.0.0.jar 9.0.0
2022-09-30 07:49:28,445 environment sso-mepin-9.0.0.jar 9.0.0
2022-09-30 07:49:28,445 environment sso-pkipolicy-9.0.0.jar 9.0.0
2022-09-30 07:49:28,445 environment sso-restclient-9.0.0.jar 9.0.0
2022-09-30 07:49:28,445 environment sso-session-manager-9.0.0.jar 9.0.0
2022-09-30 07:49:28,445 environment sso-uas-9.0.0.jar 9.0.0
2022-09-30 07:49:28,445 environment sso-uas-web-9.0.0.jar 9.0.0
2022-09-30 07:49:28,445 environment sso-ubioauth2-9.0.0.jar 9.0.0
2022-09-30 07:49:28,445 environment sso-ubiopenid-9.0.0.jar 9.0.0
2022-09-30 07:49:28,445 environment sso-ubisaml2-9.0.0.jar 9.0.0
2022-09-30 07:49:28,445 environment sso-ubisaml2-jaxb-9.0.0.jar 9.0.0
2022-09-30 07:49:28,445 environment sso-ubiutil-9.0.0.jar 9.0.0
2022-09-30 07:49:28,445 environment sso-ui-9.0.0.jar 9.0.0
2022-09-30 07:49:28,445 environment sso-ws-federation12-9.0.0.jar 9.0.0
2022-09-30 07:49:28,445 environment stax-ex-2.0.1.jar
2022-09-30 07:49:28,445 environment txw2-2.3.6.jar
2022-09-30 07:49:28,445 environment ubixmlsec-2.0.0.jar 2.0.0
2022-09-30 07:49:28,445 environment validation-api-2.0.1.Final.jar
2022-09-30 07:49:28,445 environment webjars-locator-core-0.30.jar
2022-09-30 07:49:28,445 environment webjars-taglib-0.3.jar
...
2022-09-30 07:49:28,507 environment Contents of KeyStore:
2022-09-30 07:49:28,507 environment No keystore defined
2022-09-30 07:49:28,976 init UbiloginKeyService: Updates to server keys detected at 2022-09-30T07:49:28.648Z
2022-09-30 07:49:28,976 init UbiloginKeyService: Found 1 key(s):
[enabled] [valid] CN=key-initial,OU=ServerKeyContainer,OU=System,CN=Ubilogin,DC=localhost (defaultKeyId="iZqmSdMDiIpWCBM6YW6blp-mnjg")
2022-09-30 07:49:28,976 init UbiloginKeyService: Signing key: CN=key-initial,OU=ServerKeyContainer,OU=System,CN=Ubilogin,DC=localhost
2022-09-30 07:49:28,976 init UbiloginKeyService: Decryption key(s) (1): [CN=key-initial,OU=ServerKeyContainer,OU=System,CN=Ubilogin,DC=localhost]
2022-09-30 07:49:28,976 init UbiloginKeyService: Published signature validation key(s) (1): [CN=key-initial,OU=ServerKeyContainer,OU=System,CN=Ubilogin,DC=localhost]
2022-09-30 07:49:28,976 init UbiloginKeyService: Published encryption key: CN=key-initial,OU=ServerKeyContainer,OU=System,CN=Ubilogin,DC=localhost
2022-09-30 07:49:29,601 init MessageQueueSender initialised with connection to Accounting Service broker URL: tcp://localhost:36161?connectionTimeout=10
2022-09-30 07:49:29,601 init UbiloginFactory: started
2022-09-30 07:49:29,601 init AuthenticationMethodAccess: started
...
2022-09-30 07:49:31,288 init AddressTracker: disabled
2022-09-30 07:49:31,304 init ScheduledLogLevelUpdater: started
2022-09-30 07:49:31,304 init Ubilogin Authentication Server 9.0.0 started

Migration notes

If you have customised default levels for Diagnostic log entry types

Before 9.1

Since 9.1

Before 9.1

Since 9.1

In webapps/uas/WEB-INF/log4j.properties

log4j.logger.ubilogin.tech = INFO, Diag, C log4j.logger.ubilogin.diag = INFO, Diag log4j.logger.ubilogin.diag.init = INFO, C

In ubilogin-sso/ubilogin/custom/logging/include-logback.xml the DefaultLevels value

<!-- (1) Default levels for Diagnostic logs entry types --> <turboFilter class="com.ubisecure.common.logging.MarkerBasedLogFilter"> <DefaultLevels>audit=info;tech=info;diag.*=info</DefaultLevels> </turboFilter>

If you have enabled Management audit log

Before 9.1

Since 9.1

Before 9.1

Since 9.1

In webapps/ubilogin/WEB-INF/log4j.properties

log4j.logger.com.ubisecure.ubilogin.management = INFO, ManagementAudit

In ubilogin-sso/ubilogin/custom/logging/include-logback.xml the logger element level attribute

If you have enabled Statistics log

Before 9.1

Since 9.1

Before 9.1

Since 9.1

In webapps/ubilogin/WEB-INF/log4j.properties

In ubilogin-sso/ubilogin/custom/logging/include-logback.xml add ;statistics=info to DefaultLevels value

If you have customised Logviewer configuration

See https://ubisecuredev.atlassian.net/wiki/spaces/IDS20222/pages/8964119643, the original filesource.properties file in the installation package has been changed.

Before 9.1

Since 9.1

Before 9.1

Since 9.1

In webapps/logviewer/WEB-INF/filesource.properties

In webapps/logviewer/WEB-INF/filesource.properties new default definitions and check the index for the custom filetype definitions

If you have parsed Diagnostic log (uas)

Before 9.1

Since 9.1

Before 9.1

Since 9.1

Only SSO authentication server (uas) events in the log file without logging level

Event sample:

2022-09-30 07:49:31,398 tech ping: the system is alive

If parsing notice the following:

  • file name change

  • filter uas events based on the column after timestamp

  • format change:

    • logger name is typically a diagnostic log entry type but especially in case of other applications than uas a fully qualified class name e.g. com.ubisecure.sso.totp.api.ApiController

    • logger level has been added after the logger name

Event sample:

2022-10-03 07:06:00,773 uas tech INFO ping: the system is alive

If you have specified custom log levels for libraries user by SSO authentication server (uas)

Before 9.1

Since 9.1

Before 9.1

Since 9.1

In webapps/uas/WEB-INF/log4j.properties

In ubilogin-sso/ubilogin/custom/logging/include-logback.xml

If you have specified formatting, log file folders or names for SSO authentication server (uas)

Before 9.1

Since 9.1

Before 9.1

Since 9.1

In webapps/uas/WEB-INF/log4j.properties

In ubilogin-sso/ubilogin/custom/logging/include-logback.xml, see Understanding SSO logger configuration for the following sections. NOTE: We do not recommend you to modify these settings in order to facilitate regular troubleshooting.

If you have specified custom log levels for Password applications (password, password-reset)

These applications used to log to the Tomcat log (ubilogin-sso/tomcat/logs/catalina.<YYYY-MM-DD>.log) but are now logging to the shared SSO diagnostics log (ubilogin-sso/ubilogin/logs/sso_diag.<YYYY-MM-DD>.log).

Before 9.1

Since 9.1

Before 9.1

Since 9.1

In webapps/password/WEB-INF/web.xml or webapps/password-reset/WEB-INF/web.xml e.g. for a more verbose level

In ubilogin-sso/ubilogin/custom/logging/include-logback.xml you should know the package or fully qualified class name of the component in interest. Ask advice from IDS support.

If you have specified custom log levels or formatting for TOTP API, or parsed the events (totp)

This SpringBoot application used to log to a dedicated log (ubilogin-sso/ubilogin/logs/totp.log) but is now logging to the shared SSO diagnostics log (ubilogin-sso/ubilogin/logs/sso_diag.<YYYY-MM-DD>.log).

Being a SpringBoot application, the log levels can still be configured via application.yaml or actuator end-point as advised in TOTP API configuration.

Before 9.1

Since 9.1

Before 9.1

Since 9.1

In webapps/totp/WEB-INF/application.yaml

 

Event sample:

2022-09-22 07:17:39.054 totp DEBUG ApiController: PUT /api/v1/methods/non.existing.method called with TotpMethodSettings(user=User(login=any.user, uniqueId=null), method=null, enabled=null, secret=null, generateSecret=null)

Log levels:

Either webapps/totp/WEB-INF/application.yaml or ubilogin-sso/ubilogin/custom/logging/include-logback.xml

  • application.yaml overrides include-logback.xml

In include-logback.xml

Regarding formatting, see Understanding SSO logger configuration for the following sections. NOTE: We do not recommend you to modify these settings in order to facilitate regular troubleshooting.

If parsing notice the following:

  • file name change

  • filter totp events based on the column after timestamp

  • format changes:

    • simple class name like ApiController is replaced with the fully qualified class name: com.ubisecure.sso.totp.api.ApiController

    • logger level has been moved from before the logger name to after it

Event sample:

2022-09-23 08:31:13,473 totp com.ubisecure.sso.totp.api.ApiController DEBUG PUT /api/v1/methods/non.existing.method called with TotpMethodSettings(user=User(login=any.user, uniqueId=null), method=null, enabled=null, secret=null, generateSecret=null)

 

If you have specified custom log levels or formatting for SSO Management API, or parsed the events (sso-api)

This web application used to log to a dedicated log (ubilogin-sso/ubilogin/logs/sso-api.log) but is now logging to the shared SSO diagnostics log (ubilogin-sso/ubilogin/logs/sso_diag.<YYYY-MM-DD>.log).

Being a SpringBoot application, the log levels can still be configured via application.yaml or actuator end-point as advised in TOTP API configuration.

Before 9.1

Since 9.1

Before 9.1

Since 9.1

In ubilogin/webapps/sso-api/WEB-INF/log4j2.xml

Event:

10.0.2.2 cn=Administrator,ou=System,cn=Ubilogin,dc=localhost [2022-10-03T11:36:26,746] [INFO] application.AccessLog PUT /user/example-site/example-user

 

In ubilogin-sso/ubilogin/custom/logging/include-logback.xml

Log levels

Regarding formatting, see Understanding SSO logger configuration for the following sections. NOTE: We do not recommend you to modify these settings in order to facilitate regular troubleshooting.

If parsing notice the following:

  • file name change

  • filter sso-api events based on the column after timestamp

  • format changes:

    • standard SSO diagnostic log event column order: date, time, sso-api, logging class, log level

    • logging class is now the actual class like com.globalsign.iam.sso.api.resource.node.directory.AbstractDirectoryObjectLeaf and not a logger wrapper class application.AccessLog

      • note that controlling log level is based on this logger name

    • remote IP address and authenticated user name (sub) are inserted before the actual message

Event:

2022-09-30 06:42:00,373 sso-api com.globalsign.iam.sso.api.resource.node.directory.AbstractDirectoryObjectLeaf INFO 10.0.2.2 cn=Administrator,ou=System,cn=Ubilogin,dc=localhost PUT /user/example-site/example-user

 

 

 

Ubisecure Privacy Policy & Cookie Statement