Skip to main content
Skip table of contents

Application logging

WEBAPP:

Description

Log format

Samples

/var/log/veridiumid/opa/opa.out

OPA logs

json

{"level":"error","msg":"Bundle load failed: request failed: Get \"https://dev9.veridium-dev.com/websec/rest/system/opa/export-archive\\": net/http: timeout awaiting response headers","name":"veri
dium","plugin":"bundle","time":"2023-10-30T08:54:24Z"}
{"client_addr":"127.0.0.1:39794","level":"info","msg":"Received request.","req_id":1,"req_method":"GET","req_path":"/health","time":"2023-10-30T08:54:40Z"}

/var/log/veridiumid/tomcat/catalina.out

tomcat logs, where websec/shibboleth/adservice/dmz applications are deployed; this are general logs, to see that tomcat has started and applications deployed

%d{yyyy-MMM-dd HH:mm:ss a} [%t] %level %logger{36} %msg%n

2023-Oct-30 08:57:02 AM [main] INFO org.apache.zookeeper.ZooKeeper Client environment:os.memory.max=1939MB

/var/log/veridiumid/tomcat/bops.log

These logs are the main application logs, containing the websec logs.

%d{yyyy-MMM-dd HH:mm:ss a} [%t] %level %logger{36} %msg%n

2023-Oct-27 16:36:41 PM [main] INFO com.veridiumid.webconfig.provider.ZkPropertiesFileProvider Zk Properties loaded from file /etc/veridiumid/zookeeper.properties

2023-Oct-27 16:37:13 PM [main] ERROR com.veridiumid.licensing.LicenseLoader Error initializing licenses
javax.naming.ConfigurationException: License is missing
at com.veridiumid.licensing.LicenseLoader.loadLicense(LicenseLoader.java:153) ~[licensing-utils.jar:?]
at com.veridiumid.licensing.LicenseLoader.reloadLicenses(LicenseLoader.java:132) ~[licensing-utils.jar:?]
at com.veridiumid.identity.license.LicenseManager.lambda$new$0(LicenseManager.java:70) ~[webidentity.jar:9.1.28]
at com.veridiumid.webconfig.ModuleConfigurationBase.notifyConfigurationListeners(ModuleConfigurationBase.java:52) [webconfig.jar:9.1.28]

/var/log/veridiumid/tomcat/ldap.log

These logs contains the interaction logs with LDAP service.

%d{yyyy-MMM-dd HH:mm:ss a} [%t] %level %logger{36} %msg%n

2023-Oct-27 16:37:44 PM [pool-20-thread-1] INFO com.veridiumid.ad.contract.LdapFactoryProvider Creating LDAP Connection 'default' url=ldap://127.0.0.1:389

/var/log/veridiumid/fido/fido.log

The fido logs containing application logs related to fido usage.

%d{yyyy-MMM-dd HH:mm:ss a} [%t] %level %logger{36} %msg%n

2023-Oct-27 16:43:07 PM [main] INFO org.springframework.boot.web.embedded.tomcat.TomcatWebServer Tomcat initialized with port(s): 11442 (http)

not used starting with version 3.3.0

/var/log/veridiumid/notifications/notifications.log

In this log, can be found the information about the notification process, containing the part of mail and sms sending messages.

%d{yyyy-MMM-dd HH:mm:ss a} [%t] %level %logger{36} %msg%n

if elastic enabled, this log is not used anymore.

/var/log/veridiumid/statistics/dashboard-sessions-local.log

Dashboards logs by the applications used by process dashboard-sessions-local. In case in websecadmin are not presented statistics, this is the log where the user should look.

%d{yyyy-MMM-dd HH:mm:ss a} [%t] %level %logger{36} %msg%n

2023-Oct-13 03:07:04 AM [kafka-producer-network-thread | accounts-dashboard-reporting-bioengines-cf52dbe4-01c4-4fdd-a8f4-c52728bca40d-StreamThread-1-producer] WARN org.apache.kafka.clients.NetworkClient [Producer clientId=accounts-dashboard-reporting-bioengines-cf52dbe4-01c4-4fdd-a8f4-c52728bca40d-StreamThread-1-producer] Bootstrap broker 10.70.61.181:9095 (id: -2 rack: null) disconnected

if elastic enabled, this log is not used anymore.

/var/log/veridiumid/statistics/dashboard-sessions-global.log

Dashboards logs by the applications used by process dashboard-sessions-global. In case in websecadmin are not presented statistics, this is the log where the user should look.

%d{yyyy-MMM-dd HH:mm:ss a} [%t] %level %logger{36} %msg%n

2023-Oct-14 08:01:37 AM [main] WARN com.veridiumid.webconfig.ZookeeperConnectionFactory Zookeeper connection initialized, but not yet connected.

if elastic enabled, this log is not used anymore.

/var/log/veridiumid/statistics/account-sessions.log

Dashboards logs by the applications used by process account-sessions. In case in websecadmin are not presented statistics, this is the log where the user should look.

%d{yyyy-MMM-dd HH:mm:ss a} [%t] %level %logger{36} %msg%n

2023-Oct-14 08:01:37 AM [main] WARN com.veridiumid.webconfig.ZookeeperConnectionFactory Zookeeper connection initialized, but not yet connected.

if elastic enabled, this log is not used anymore.

/var/log/veridiumid/statistics/account-bioengines.log

Dashboards logs by the applications used by processaccount-bioengines. In case in websecadmin are not presented statistics, this is the log where the user should look.

%d{yyyy-MMM-dd HH:mm:ss a} [%t] %level %logger{36} %msg%n

2023-Oct-14 08:01:37 AM [main] WARN com.veridiumid.webconfig.ZookeeperConnectionFactory Zookeeper connection initialized, but not yet connected.

if elastic enabled, this log is not used anymore.

/var/log/veridiumid/statistics/auth-sessions-local.log

Dashboards logs by the applications used by process auth-sessions-local. In case in websecadmin are not presented statistics, this is the log where the user should look.

%d{yyyy-MMM-dd HH:mm:ss a} [%t] %level %logger{36} %msg%n

2023-Oct-14 08:01:37 AM [main] WARN com.veridiumid.webconfig.ZookeeperConnectionFactory Zookeeper connection initialized, but not yet connected.

if elastic enabled, this log is not used anymore.

/var/log/veridiumid/statistics/auth-sessions-global.log

Dashboards logs by the applications used by process auth-sessions-global. In case in websecadmin are not presented statistics, this is the log where the user should look.

%d{yyyy-MMM-dd HH:mm:ss a} [%t] %level %logger{36} %msg%n

2023-Oct-14 08:01:37 AM [main] WARN com.veridiumid.webconfig.ZookeeperConnectionFactory Zookeeper connection initialized, but not yet connected.

/var/log/veridiumid/selfservice/selfservice.log

This is the self service application log.

%d{yyyy-MMM-dd HH:mm:ss a} [%t] %level %logger{36} %msg%n

2023-Oct-27 16:41:10 PM [main] INFO org.springframework.boot.web.servlet.context.ServletWebServerApplicationContext Root WebApplicationContext: initialization completed in 5800 ms
2023-Oct-27 16:41:11 PM [main] ERROR org.opensaml.xml.parse.StaticBasicParserPool XML Parsing Error
org.xml.sax.SAXParseException: Premature end of file.
at org.apache.xerces.util.ErrorHandlerWrapper.createSAXParseException(Unknown Source) ~[xercesImpl-2.12.2.jar!/:?]
at org.apache.xerces.util.ErrorHandlerWrapper.fatalError(Unknown Source) ~[xercesImpl-2.12.2.jar!/:?]
at org.apache.xerces.impl.XMLErrorReporter.reportError(Unknown Source) ~[xercesImpl-2.12.2.jar!/:2.12.2]
at org.apache.xerces.impl.XMLErrorReporter.reportError(Unknown Source) ~[xercesImpl-2.12.2.jar!/:2.12.2]

/var/log/veridiumid/websecadmin/websecadmin.log

This is the websecadmin application log, where are kept the logs for user interaction with websec admin application.

%d{yyyy-MMM-dd HH:mm:ss a} [%t] %level %logger{36} %msg%n

2023-Oct-27 16:33:25 PM [main] WARN com.veridiumid.admin.saml.SamlSetup Saml keystore is not configured.
2023-Oct-27 16:33:26 PM [main] ERROR org.opensaml.xml.parse.StaticBasicParserPool XML Parsing Error
org.xml.sax.SAXParseException: Premature end of file.
at org.apache.xerces.util.ErrorHandlerWrapper.createSAXParseException(Unknown Source) ~[xercesImpl-2.12.2.jar!/:?]
at org.apache.xerces.util.ErrorHandlerWrapper.fatalError(Unknown Source) ~[xercesImpl-2.12.2.jar!/:?]

/var/log/veridiumid/freeradius/freeradius.log

Freeradius log contains the information about freeradius application.

%d{yyyy-MMM-dd HH:mm:ss a} %msg%n

Thu Oct 12 03:13:52 2023 : Debug: (1205) if (&User-Name =~ /\.$/) -> FALSE
Thu Oct 12 03:13:52 2023 : Debug: (1205) if (&User-Name =~ /@\./) {
Thu Oct 12 03:13:52 2023 : Debug: (1205) if (&User-Name =~ /@\./) -> FALSE
Thu Oct 12 03:13:52 2023 : Debug: (1205) } # if (&User-Name) = notfound
Thu Oct 12 03:13:52 2023 : Debug: (1205) } # policy filter_username = notfound
Thu Oct 12 03:13:52 2023 : Debug: (1205) [preprocess] = ok
Thu Oct 12 03:13:52 2023 : Debug: (1205) [chap] = noop
Thu Oct 12 03:13:52 2023 : Debug: (1205) mschap: Found MS-CHAP attributes. Setting 'Auth-Type = mschap'

/var/log/veridiumid/shibboleth-idp/idp-warn.log

This is the main log for shibboleth process.

%d{yyyy-MMM-dd HH:mm:ss a} [%t] %level %logger{36} %msg%n

2023-10-30 07:32:48,275 - WARN [org.opensaml.profile.action.impl.LogEvent:105] - A non-proceed event occurred while processing the request: AuthenticationException
2023-10-30 08:10:45,656 - ERROR [org.opensaml.saml.metadata.resolver.impl.HTTPMetadataResolver:321] - Metadata Resolver FileBackedHTTPMetadataResolver AzureADCitrixCloud: Error retrieving metadata from https://nexus.microsoftonline-p.com/federationmetadata/saml20/federationmetadata.xml
org.apache.http.conn.ConnectTimeoutException: Connect to failed: connect timed out
at org.apache.http.impl.conn.DefaultHttpClientConnectionOperator.connect(DefaultHttpClientConnectionOperator.java:151)
at org.apache.http.impl.conn.PoolingHttpClientConnectionManager.connect(PoolingHttpClientConnectionManager.java:376)
at org.apache.http.impl.execchain.MainClientExec.establishRoute(MainClientExec.java:393)

/var/log/veridiumid/websecadmin/deprovisioning.log

This is the deprovisioning process log, where can be seen action taken by this process.

%d{yyyy-MMM-dd HH:mm:ss a} [%t] %level %logger{36} %msg%n

2023-Oct-27 18:16:54 PM [main-EventThread] INFO com.veridiumid.deprovisioning.scheduler.ScheduledDeprovisioningService Identity deprovisioning configuration changed
2023-Oct-27 18:16:54 PM [main-EventThread] WARN com.veridiumid.deprovisioning.scheduler.ScheduledDeprovisioningService Identity deprovisioning synchronization job is disabled
2023-Oct-27 19:06:36 PM [main] WARN com.veridiumid.deprovisioning.scheduler.ScheduledDeprovisioningService Identity deprovisioning synchronization job is disabled

/var/log/veridiumid/haproxy/haproxy.log

Haproxy application log contains the acces logs of all services.

according to documentation, tcp log and http log for haproxy
log-format "%ci:%cp [%t] %ft %b/%s %Tw/%Tc/%Tt %B %ts %ac/%fc/%bc/%sc/%rc %sq/%bq"
log-format "%ci:%cp [%tr] %ft %b/%s %TR/%Tw/%Tc/%Tr/%Ta %ST %B %CC %CS %tsc %ac/%fc/%bc/%sc/%rc %sq/%bq %hr %hs %{+Q}r"

Oct 27 16:36:10 localhost haproxy[678]: 10.109.20.128:45138 [27/Oct/2023:16:36:10.111] frontend-https~ backend-bops-https/<NOSRV> 411/-1/-1/-1/411 503 217 - - SC-- 3/3/0/0/0 0/0 "" "GET /websec/schemas/shibboleth-attribute-resolver.xsd HTTP/1.1" TLS_AES_256_GCM_SHA384 TLSv1.3

Oct 27 17:42:06 localhost haproxy[678]: 10.109.20.128:41372 [27/Oct/2023:17:42:06.288] frontend-https~ backend-bops-https/server-10.109.20.128 12/0/1/9/22 304 289 - - ---- 4/4/0/0/0 0/0 "/CN=dev9_friend_OPA_ACCOUNT_dc1/OU=VeridiumID/O=VeridiumClient/L=New York/ST=NY/C=US/emailAddress=/UID=11111111-6bdb-4a75-be03-1111111111" "GET /websec/rest/system/opa/export-archive HTTP/1.1" TLS_AES_256_GCM_SHA384 TLSv1.3

PERSISTENCE:

/var/log/veridiumid/cassandra/debug.log

This is the cassandra log, where can be seen the database logs. 

%d{yyyy-MMM-dd HH:mm:ss a} [%t] %level %logger{36} %msg%n

2023-10-27 15:10:03,621 DEBUG SSLFactory.java:384 - Initializing hot reloading SSLContext
2023-10-27 15:10:03,675 INFO JMXServerUtils.java:271 - Configured JMX server at: service:jmx:rmi://127.0.0.1/jndi/rmi://127.0.0.1:7199/jmxrmi
2023-10-27 15:10:03,682 INFO CassandraDaemon.java:625 - Hostname: ip-10-109-20-128.eu-central-1.compute.internal:7001:7001
2023-10-27 15:10:03,682 INFO CassandraDaemon.java:632 - JVM vendor/version: OpenJDK 64-Bit Server VM/1.8.0_382

/var/log/veridiumid/cassandra/backup.log

This log contains information about backup activities, that are running in crontab periodically.

%d{yyyy-MMM-dd HH:mm:ss a} %level %msg%n

30-Oct-2023 09:07:06 AM INFO Creating snapshot: dc1_10.109.20.128
30-Oct-2023 09:07:08 AM INFO Moving snapshot to /opt/veridiumid/backup/cassandra/2023-10-30_09-07/dc1_10.109.20.128
30-Oct-2023 09:07:10 AM DEBUG Moving the snapshot succeeded

/var/log/veridiumid/cassandra/maintenance.log

This log contains information about maintenance activities, that are running in crontab periodically.

%d{yyyy-MMM-dd HH:mm:ss a} %level %msg%n

30-Oct-2023 09:07:47 AM INFO Checking the status of the cluster
30-Oct-2023 09:07:48 AM INFO Checking state of Cassandra cluster based on nodetool status output
30-Oct-2023 09:07:48 AM INFO All Cassandra nodes are up
30-Oct-2023 09:07:48 AM INFO Starting repair procedure
30-Oct-2023 09:07:50 AM INFO Nodetool repair finishes successfully

if elastic enabled, this log is not used anymore.

/var/log/veridiumid/kafka/server.log

This is the main kafka log.

[%d] %p %m (%c)%n

[2023-06-22 09:00:11,106] WARN Resetting first dirty offset of __consumer_offsets-38 to log start offset 73 since the checkpointed offset 62 is invalid. (kafka.log.LogCleanerManager$)

/var/log/veridiumid/zookeeper/zookeeper.out

This is the main zookeeper log.

%d{ISO8601} [myid:%X{myid}] - %-5p [%t:%C{1}@%L] - %m%n

2023-10-30 08:53:08,036 [myid:] - INFO [main:o.a.z.s.q.QuorumPeerConfig@444] - secureClientPort is not set
2023-10-30 08:53:08,037 [myid:] - INFO [main:o.a.z.s.q.QuorumPeerConfig@460] - observerMasterPort is not set
2023-10-30 08:53:08,037 [myid:] - INFO [main:o.a.z.s.q.QuorumPeerConfig@477] - metricsProvider.className is org.apache.zookeeper.metrics.impl.DefaultMetricsProvider
2023-10-30 08:53:08,132 [myid:] - ERROR [main:o.a.z.s.q.QuorumPeerConfig@702] - Invalid configuration, only one server specified (ignoring)

/var/log/veridiumid/data-retention/data-retention.log

Data retention process log.

%d{yyyy-MMM-dd HH:mm:ss a} [%t] %level %logger{36} %msg%n

2023-Oct-27 16:39:36 PM [main] INFO org.apache.zookeeper.ZooKeeper Client environment:java.version=1.8.0_382
2023-Oct-27 16:39:36 PM [main] INFO org.apache.zookeeper.ZooKeeper Client environment:java.vendor=Red Hat, Inc.

if elastic enabled

/var/log/veridiumid/elasticsearch/VeridiumID.log

Elasticsearch log.

[%d{ISO8601}][%-5p][%-25c{1.}] [%node_name]%marker %m%n

[2023-10-30T09:24:47,218][WARN ][o.e.c.c.Coordinator ] [dc1-node-1] This node is a fully-formed single-node cluster with cluster UUID [VbhjRj4uS8ayHQiDjROKNg], but it is configured as if to discover other nodes and form a multi-node cluster via the [discovery.seed_hosts=[10.109.20.128]] setting. Fully-formed clusters do not attempt to discover other nodes, and nodes with different cluster UUIDs cannot belong to the same cluster. The cluster UUID persists across restarts and can only be changed by deleting the contents of the node's data path(s). Remove the discovery configuration to suppress this message.

Access log:

/var/log/veridiumid/tomcat/shib_localhost_access_log.2023-10-27.log

Access log for shibboleth, including all called API, response and duration.

SHIBBOLETH %h %{X-Forwarded-For}i %l "%u" %t "%r" %s %b %D %S %I "DN=%{X-SSL-Client-DN}i" "CN=%{X-SSL-Client-CN}i"

SHIBBOLETH 127.0.0.1 - - "-" [27/Oct/2023:16:42:19 +0000] "GET /idp/profile/admin/reload-service?id=shibboleth.NameIdentifierGenerationService HTTP/1.1" 200 71 2006 2C2019B4E733A98742361A446AA81B94 http-nio-127.0.0.1-8943-exec-1 "DN=-" "CN=-"

/var/log/veridiumid/tomcat/dmz_localhost_access_log.2023-10-27.log

Access log for dmz, including all called API, response and duration.

DMZ %h %{X-Forwarded-For}i %l "%u" %t "%r" %s %b %D %S %I "DN=%{X-SSL-Client-DN}i" "CN=%{X-SSL-Client-CN}i"

DMZ 127.0.0.1 - - "-" [27/Oct/2023:19:08:39 +0000] "GET /dmzwebsec/help/ HTTP/1.1" 200 3557 3 - http-nio-127.0.0.1-8543-exec-1 "DN=-" "CN=-"

/var/log/veridiumid/tomcat/localhost_access_log..2023-05-30.txt

Access log for websec and ADService including all called API, response and duration.

WEBAPP %h %{X-Forwarded-For}i %l "%u" %t "%r" %s %b %D %S %I "DN=%{X-SSL-Client-DN}i" "CN=%{X-SSL-Client-CN}i"

WEBAPP 127.0.0.1 10.109.20.128 - "-" [27/Oct/2023:16:37:46 +0000] "GET /websec/schemas/shibboleth-metadata.xsd HTTP/1.1" 200 70774 139 - vid-exec-7 "DN=-" "CN=-"

/var/log/veridiumid/websecadmin/access_log.2023-05-30.log

Access log for websecadmin including all called API, response and duration.

%h %{X-Forwarded-For}i %l \"%u\" %t \"%r\" %s %b %D

127.0.0.1 193.45.134.123, 194.123.123.4,10.41.8.220 - "-" [27/Oct/2023:18:14:45 +0000] "GET /veridium-manager HTTP/1.1" 302 - 14

127.0.0.1 - - "-" [27/Oct/2023:16:33:37 +0000] "-" 400 - 0

/var/log/veridiumid/selfservice/access_log.2023-05-30.log

Access log for selfservice including all called API, response and duration.

%h %{X-Forwarded-For}i %l \"%u\" %t "%r" %s %b %D

127.0.0.1 - - "-" [27/Oct/2023:18:17:22 +0000] "GET /ssp/rest/health/ready HTTP/1.1" 200 250 117
127.0.0.1 193.45.134.123, 194.123.123.4 - "-" [27/Oct/2023:18:34:54 +0000] "GET /ssp HTTP/1.1" 302 - 20

/var/log/veridiumid/fido/access_log.2023-05-30.log

Access log for fido including all called API, response and duration.

%h %{X-Forwarded-For}i %l \"%u\" %t \"%r\" %s %b %D

127.0.0.1 - - "-" [27/Oct/2023:18:13:30 +0000] "GET /health/ready HTTP/1.1" 200 45 282
127.0.0.1 - - "-" [27/Oct/2023:18:17:22 +0000] "GET /health/ready HTTP/1.1" 200 45 17

Audit logs:

/opt/veridiumid/websecadmin/logs/events.log

Events logs for accessing websecadmin

%d{yyyy-MMM-dd HH:mm:ss a} [%t] %level %logger{36} %msg%n

2023-Oct-27 16:40:14 PM [https-jsse-nio-9443-exec-5] INFO com.veridiumid.identity.events.SystemEvents ActionLog(id=20316691-e8b5-46dc-9e46-4e58bcc38c31, actionName=Login, accountExternalId=admin@veridiumid.com, accountEmail=null, accountId=47EAEF85-9D37-4366-AF8F-2F4777A6AD4E, deviceId=E27B2D93-291C-47F3-BF35-EA6DA590120A, ip=10.109.20.128, requestUri=/websecadmin/rest/opa/generate-certificate, requestMethod=GET, requestQueryParams=null, requestPath=null, requestBody=null, response=null, actionDate=Fri Oct 27 16:40:14 UTC 2023, location=Local Network)

/opt/veridiumid/tomcat/logs/events.log

Events logs for user authentications

%d{yyyy-MMM-dd HH:mm:ss a} [%t] %level %logger{36} %msg%n

2023-Oct-27 18:35:04 PM [vid-exec-133] INFO com.veridiumid.identity.events.SystemEvents EventLog(_caller=(accountId=9ae4ce0d-e3a1-447f-936e-dbdc03f26d10, accountExternalId=ADv2MultiStepEnrollment, accountEmailAddressInfo=null, accountStatus=NONE, deviceId=ssp, deviceOs=, deviceType=FRIEND, deviceName=ssp, deviceManufacturer=null, deviceDescription=Self Service Portal, deviceStatus=ACTIVATED), ipAddress='10.109.20.128', location='Local Network', requestURI='/websec/rest/enterprise/portal/InitiateEnrollment', requestMethod='POST', requestPath='/enterprise/portal/InitiateEnrollment', actionName='initiateEnrollment', actionDate=Fri Oct 27 18:35:04 UTC 2023, request=null, response=(currentStatus='null', profileId='null', enrollmentTrackerId='null'))
2023-Oct-27 18:35:09 PM [vid-exec-134] INFO com.veridiumid.identity.events.SystemEvents EventLog(_caller=(accountId=9ae4ce0d-e3a1-447f-936e-dbdc03f26d10, accountExternalId=ADv2MultiStepEnrollment, accountEmailAddressInfo=null, accountStatus=NONE, deviceId=ssp, deviceOs=, deviceType=FRIEND, deviceName=ssp, deviceManufacturer=null, deviceDescription=Self Service Portal, deviceStatus=ACTIVATED), ipAddress='10.109.20.128', location='Local Network', requestURI='/websec/rest/enterprise/portal/Enroll', requestMethod='POST', requestPath='/enterprise/portal/Enroll', actionName='enrollAccount', actionDate=Fri Oct 27 18:35:09 UTC 2023, request=(deviceId='null', profileId='null', enrollmentTrackerId='null', purpose=ENROLL), response=(currentStatus='ACTIVE', profileId='680395e0-b2cf-4f89-89eb-48e7d5d9cf82', enrollmentTrackerId='b4103206-e294-4266-9897-d9e0ea821862'))

Here are some examples of what information can be found in events.log and what is the log format.

Users_SEM_3.5.xlsx

JavaScript errors detected

Please note, these errors can depend on your browser setup.

If this problem persists, please contact our support.