Audit Logs

Overview

Audit log is a document that records all actions undertaken by users on the Server and on the Client.

Two ad-hoc audit.log files are created to contain this information:

  • The server audit.log file is in the same path of the other Genius Server log file ( usually <Genius Server installation dir>/logs ) and it follows standard layout/rolling rules (these two can be changed editing the log4j.properties file).

  • The client audit.log file is in the Genius MFP configuration console.

Audit Activation/Deactivation

The Audit Log status is driven by the Genius MFP client:

  • Client side: on the Genius MFP configuration console it is possible to find the parameter "Audit level". Selecting ON the audit log is enabled, otherwise audit log is disabled.

  • Server side: no configuration is needed, if the Audit level is enabled, the Genius MFP client sends the "Client-Transaction-ID" to Genius Server and the audit log is automatically switched ON.

Features Recorded by the Audit Log

Currently the feature recorded by the audit log is the following:

  • Client login.

Audit Layout

The following snippet shows the audit log on the Server and on the Client during the same client transaction:

sort -nmbs -k1.1,1.4 -k1.6,1.7 -k1.9,1.10 -k2.1,2.2 -k2.4,2.5 -k2.7,2.8 -k2.10,2.12 <path-to-server-audit-log>/audit.log <path-to-client-audit-log>/audit.log > merged-audit.log

The client transaction ID is c7f87ee8e290a2862603c9458317 and it is in the Client and Server audit log. It could be useful to compare the information.

Genius Server Audit Log Snippet

2016-10-19 12:32:10,799 - SERVER AUDIT - http-jetty-50 - c7f87ee8e290a2862603c9458317 - REST : Info. [Ip-Address=10.0.1.26]
2016-10-19 12:32:10,805 - SERVER AUDIT - http-jetty-50 - c7f87ee8e290a2862603c9458317 - SQL : Executing query for getting MFP device. Elapsed:5[ms] [serialNumber=V9713802408, vendorNumber=367 -> .]
2016-10-19 12:32:10,807 - SERVER AUDIT - http-jetty-50 - c7f87ee8e290a2862603c9458317 - REST : Info. Elapsed:8[ms] [Ip-Address=10.0.1.26]
2016-10-19 12:32:10,914 - SERVER AUDIT - http-jetty-45 - c7f87ee8e290a2862603c9458317 - REST : Login from MFP. [Ip-Address=10.0.1.26]
2016-10-19 12:32:10,916 - SERVER AUDIT - http-jetty-45 - c7f87ee8e290a2862603c9458317 - SQL : Executing query for getting internal user. Elapsed:1[ms] [username=a.fresh -> .]
2016-10-19 12:32:10,920 - SERVER AUDIT - http-jetty-45 - c7f87ee8e290a2862603c9458317 - REST : Login from MFP. Elapsed:6[ms] [Ip-Address=10.0.1.26]
2016-10-19 12:32:10,958 - SERVER AUDIT - http-jetty-49 - c7f87ee8e290a2862603c9458317 - REST : Getting current identity login context. [Ip-Address=10.0.1.26]
2016-10-19 12:32:10,959 - SERVER AUDIT - http-jetty-49 - c7f87ee8e290a2862603c9458317 - SQL : Executing query for getting current identity. Elapsed:0[ms] [ -> .]
2016-10-19 12:32:10,961 - SERVER AUDIT - http-jetty-49 - c7f87ee8e290a2862603c9458317 - SQL : Executing query for getting identity details. Elapsed:2[ms] [username=a.fresh -> .]
2016-10-19 12:32:10,967 - SERVER AUDIT - http-jetty-49 - c7f87ee8e290a2862603c9458317 - SQL : Executing query for getting MFP device. Elapsed:3[ms] [serialNumber=V9713802408, vendorNumber=367 -> .]
2016-10-19 12:32:10,998 - SERVER AUDIT - http-jetty-49 - c7f87ee8e290a2862603c9458317 - SQL : Retrieve current identity id from context. Elapsed:0[ms] [ -> .]
2016-10-19 12:32:10,999 - SERVER AUDIT - http-jetty-49 - c7f87ee8e290a2862603c9458317 - SQL : Executing query for getting identity preferences. Elapsed:1[ms] [identityId=7, deviceClientType=EMBEDDED_MFP, . -> .]
2016-10-19 12:32:10,999 - SERVER AUDIT - http-jetty-49 - c7f87ee8e290a2862603c9458317 - SQL : Retrieve current identity id from context. Elapsed:0[ms] [ -> .]
2016-10-19 12:32:11,001 - SERVER AUDIT - http-jetty-49 - c7f87ee8e290a2862603c9458317 - SQL : Retrieve current identity id from context. Elapsed:0[ms] [ -> .]
2016-10-19 12:32:11,002 - SERVER AUDIT - http-jetty-49 - c7f87ee8e290a2862603c9458317 - SQL : Executing query for getting identity cost centers. Elapsed:1[ms] [identityId=7 -> .]
2016-10-19 12:32:11,004 - SERVER AUDIT - http-jetty-49 - c7f87ee8e290a2862603c9458317 - SQL : Executing query for getting current identity. Elapsed:0[ms] [ -> .]
2016-10-19 12:32:11,007 - SERVER AUDIT - http-jetty-49 - c7f87ee8e290a2862603c9458317 - SQL : Executing query for getting identity details. Elapsed:1[ms] [username=a.fresh -> .]
2016-10-19 12:32:11,009 - SERVER AUDIT - http-jetty-49 - c7f87ee8e290a2862603c9458317 - SQL : Retrieve current identity id from context. Elapsed:0[ms] [ -> .]
2016-10-19 12:32:11,011 - SERVER AUDIT - http-jetty-49 - c7f87ee8e290a2862603c9458317 - SQL : Executing query for getting current identity details. Elapsed:1[ms] [ -> .]
2016-10-19 12:32:11,013 - SERVER AUDIT - http-jetty-49 - c7f87ee8e290a2862603c9458317 - SQL : Executing query for getting device groups for MFP device. Elapsed:1[ms] [vendorNumber=367, serialNumber=V9713802408 -> .]
2016-10-19 12:32:11,024 - SERVER AUDIT - http-jetty-49 - c7f87ee8e290a2862603c9458317 - SQL : Executing query for getting BPM definitions by user group and view type. Elapsed:11[ms] [., userId=7, ., ., ., clientType=EMBEDDED_MFP, ., ., modelVersion=3 -> .]
2016-10-19 12:32:11,037 - SERVER AUDIT - http-jetty-49 - c7f87ee8e290a2862603c9458317 - SQL : Executing query for getting current identity. Elapsed:0[ms] [ -> .]
2016-10-19 12:32:11,040 - SERVER AUDIT - http-jetty-49 - c7f87ee8e290a2862603c9458317 - SQL : Executing query for getting identity details. Elapsed:2[ms] [username=a.fresh -> .]
2016-10-19 12:32:11,042 - SERVER AUDIT - http-jetty-49 - c7f87ee8e290a2862603c9458317 - SQL : Retrieve current identity id from context. Elapsed:0[ms] [ -> .]
2016-10-19 12:32:11,046 - SERVER AUDIT - http-jetty-49 - c7f87ee8e290a2862603c9458317 - SQL : Executing query for getting current identity details. Elapsed:2[ms] [ -> .]
2016-10-19 12:32:11,049 - SERVER AUDIT - http-jetty-49 - c7f87ee8e290a2862603c9458317 - SQL : Executing query for getting device groups for MFP device. Elapsed:2[ms] [vendorNumber=367, serialNumber=V9713802408 -> .]
2016-10-19 12:32:11,057 - SERVER AUDIT - http-jetty-49 - c7f87ee8e290a2862603c9458317 - SQL : Executing query for getting BPM definitions by user group and view type. Elapsed:8[ms] [., userId=7, ., ., ., clientType=EMBEDDED_MFP, ., ., modelVersion=3 -> .]
2016-10-19 12:32:11,058 - SERVER AUDIT - http-jetty-49 - c7f87ee8e290a2862603c9458317 - SQL : Executing query for getting current identity. Elapsed:0[ms] [ -> .]
2016-10-19 12:32:11,061 - SERVER AUDIT - http-jetty-49 - c7f87ee8e290a2862603c9458317 - SQL : Executing query for getting identity details. Elapsed:3[ms] [username=a.fresh -> .]
2016-10-19 12:32:11,063 - SERVER AUDIT - http-jetty-49 - c7f87ee8e290a2862603c9458317 - SQL : Retrieve current identity id from context. Elapsed:0[ms] [ -> .]
2016-10-19 12:32:11,066 - SERVER AUDIT - http-jetty-49 - c7f87ee8e290a2862603c9458317 - SQL : Executing query for getting current identity details. Elapsed:1[ms] [ -> .]
2016-10-19 12:32:11,068 - SERVER AUDIT - http-jetty-49 - c7f87ee8e290a2862603c9458317 - SQL : Executing query for getting device groups for MFP device. Elapsed:2[ms] [vendorNumber=367, serialNumber=V9713802408 -> .]
2016-10-19 12:32:11,075 - SERVER AUDIT - http-jetty-49 - c7f87ee8e290a2862603c9458317 - SQL : Executing query for getting BPM blocking tasks. Elapsed:6[ms] [userId=7, ., clientType=EMBEDDED_MFP, ., ., vendorNumber=367, serialNumber=V9713802408, modelVersion=3 -> .]
2016-10-19 12:32:11,075 - SERVER AUDIT - http-jetty-49 - c7f87ee8e290a2862603c9458317 - REST : Getting current identity login context. Elapsed:117[ms] [Ip-Address=10.0.1.26]
2016-10-19 12:32:11,402 - SERVER AUDIT - http-jetty-43 - c7f87ee8e290a2862603c9458317 - REST : Lock MFP device. [Ip-Address=10.0.1.26]
2016-10-19 12:32:11,406 - SERVER AUDIT - http-jetty-43 - c7f87ee8e290a2862603c9458317 - SQL : Executing query for getting MFP device. Elapsed:4[ms] [serialNumber=V9713802408, vendorNumber=367 -> .]
2016-10-19 12:32:11,408 - SERVER AUDIT - http-jetty-43 - c7f87ee8e290a2862603c9458317 - SQL : Executing query for getting current identity. Elapsed:0[ms] [ -> .]
2016-10-19 12:32:11,417 - SERVER AUDIT - http-jetty-43 - c7f87ee8e290a2862603c9458317 - REST : Lock MFP device. Elapsed:16[ms] [Ip-Address=10.0.1.26]
2016-10-19 12:32:13,409 - SERVER AUDIT - http-jetty-50 - c7f87ee8e290a2862603c9458317 - REST : Getting current identity number of pull-printing jobs. [Ip-Address=10.0.1.26]
2016-10-19 12:32:13,413 - SERVER AUDIT - http-jetty-50 - c7f87ee8e290a2862603c9458317 - SQL : Executing query for getting MFP device. Elapsed:4[ms] [serialNumber=V9713802408, vendorNumber=367 -> .]
2016-10-19 12:32:13,417 - SERVER AUDIT - http-jetty-50 - c7f87ee8e290a2862603c9458317 - SQL : Executing query for getting pull-printing queues for device. Elapsed:1[ms] [mfpDeviceID=2 -> .]
2016-10-19 12:32:13,418 - SERVER AUDIT - http-jetty-50 - c7f87ee8e290a2862603c9458317 - SQL : Executing query for getting current identity. Elapsed:0[ms] [ -> .]
2016-10-19 12:32:13,420 - SERVER AUDIT - http-jetty-50 - c7f87ee8e290a2862603c9458317 - SQL : Executing query for getting pull-printing count. Elapsed:2[ms] [., queueIdList=[1], zones=[Default] -> 0]
2016-10-19 12:32:13,421 - SERVER AUDIT - http-jetty-50 - c7f87ee8e290a2862603c9458317 - REST : Getting current identity number of pull-printing jobs. Elapsed:12[ms] [Ip-Address=10.0.1.26]
2016-10-19 12:32:13,472 - SERVER AUDIT - http-jetty-45 - c7f87ee8e290a2862603c9458317 - REST : Getting current identity number of tasks. [Ip-Address=10.0.1.26]
2016-10-19 12:32:13,472 - SERVER AUDIT - http-jetty-45 - c7f87ee8e290a2862603c9458317 - SQL : Executing query for getting current identity. Elapsed:0[ms] [ -> .]
2016-10-19 12:32:13,475 - SERVER AUDIT - http-jetty-45 - c7f87ee8e290a2862603c9458317 - SQL : Executing query for getting identity details. Elapsed:2[ms] [username=a.fresh -> .]
2016-10-19 12:32:13,477 - SERVER AUDIT - http-jetty-45 - c7f87ee8e290a2862603c9458317 - SQL : Retrieve current identity id from context. Elapsed:0[ms] [ -> .]
2016-10-19 12:32:13,478 - SERVER AUDIT - http-jetty-45 - c7f87ee8e290a2862603c9458317 - SQL : Executing query for getting current identity details. Elapsed:1[ms] [ -> .]
2016-10-19 12:32:13,481 - SERVER AUDIT - http-jetty-45 - c7f87ee8e290a2862603c9458317 - SQL : Executing query for getting device groups for MFP device. Elapsed:2[ms] [vendorNumber=367, serialNumber=V9713802408 -> .]
2016-10-19 12:32:13,487 - SERVER AUDIT - http-jetty-45 - c7f87ee8e290a2862603c9458317 - REST : Getting current identity number of tasks. Elapsed:15[ms] [Ip-Address=10.0.1.26]
2016-10-19 12:33:30,613 - SERVER AUDIT - http-jetty-49 - c80bfcd8e3bb12fa33c9b59b8727 - REST : Info. [Ip-Address=10.0.1.26]
2016-10-19 12:33:30,618 - SERVER AUDIT - http-jetty-49 - c80bfcd8e3bb12fa33c9b59b8727 - SQL : Executing query for getting MFP device. Elapsed:4[ms] [serialNumber=V9713802408, vendorNumber=367 -> .]
...

Layout Explanation

All log lines are composed by this sequence of the code's parts:

  • happening time in the ISO8601 format: for example 2016-10-19 12:33:30,618.

  • a constant string: always SERVER AUDIT.

  • the identifier of the thread that manages the request: for example http-jetty-49.

  • an UID that identifies the MFP client transaction: for example c80bfcd8e3bb12fa33c9b59b8727.

  • a string that identifies the type of the operation performed (also the Genius Server layer): for example SQL, alternatives are:

    • REST: it identifies a REST end point call.

    • SQL: it identifies an interaction with the Genius Server database.

    • SQL (e): it identifies an interaction with an external database, for example an authentication from an external DB authentication provider.

    • LDAP (e): it identifies an interaction with an LDAP, for example an authentication from an external LDAP authentication provider.

  • the message: for example Executing query for getting MFP device.

  • the elapsed time: for example Elapsed:4[ms].

  • a string that contains the operation input and output, separated by the "→" char: for example [serialNumber=V9713802408, vendorNumber=367 -> .].

Genius MFP Client Audit Log Snippet

2016-10-19 12:32:07,918 - CLIENT AUDIT - default - c7f87ee8e290a2862603c9458317 - Starting manual login process for username [ a.fresh ]
2016-10-19 12:32:08,069 - CLIENT AUDIT - default - c7f87ee8e290a2862603c9458317 - Selecting CDDS server to connect to between this list: [http://10.0.2.16:8080/server/rest, http://MYCDDS-SERVER-1:8080/server/rest, http://MYCDDS-SERVER-2:8080/server/rest, http://MYCDDS-SERVER-3:8080/server/rest, http://MYCDDS-SERVER-4:8080/server/rest]
2016-10-19 12:32:08,174 - CLIENT AUDIT - default - c7f87ee8e290a2862603c9458317 - Selection done: CORE-SERVER
2016-10-19 12:32:08,176 - CLIENT AUDIT - default - c7f87ee8e290a2862603c9458317 - Getting identity login context from CDDS Server: CORE-SERVER
2016-10-19 12:32:08,426 - CLIENT AUDIT - default - c7f87ee8e290a2862603c9458317 - Identity login context received for user: Anton Fresh
2016-10-19 12:32:08,651 - CLIENT AUDIT - default - c7f87ee8e290a2862603c9458317 - Locking device 10.0.1.26 at CDDS server side
2016-10-19 12:32:08,736 - CLIENT AUDIT - default - c7f87ee8e290a2862603c9458317 - Unlocking local device 10.0.1.26 features at MFP side
2016-10-19 12:32:08,753 - CLIENT AUDIT - default - c7f87ee8e290a2862603c9458317 - Moving to Home Page...
2016-10-19 12:33:27,758 - CLIENT AUDIT - default - c80bfcd8e3bb12fa33c9b59b8727 - Starting manual login process for username [ myadmin ]
2016-10-19 12:33:27,895 - CLIENT AUDIT - default - c80bfcd8e3bb12fa33c9b59b8727 - Selecting CDDS server to connect to between this list: [http://10.0.2.16:8080/server/rest, http://MYCDDS-SERVER-1:8080/server/rest, http://MYCDDS-SERVER-2:8080/server/rest, http://MYCDDS-SERVER-3:8080/server/rest, http://MYCDDS-SERVER-4:8080/server/rest]
...