Nuxeo logging is compliant with common Java logging frameworks Log4J, Log4j2, JCL, SLF4J and JUL.
Logging in Nuxeo is configured through a Log4J XML file: $NUXEO_HOME/lib/log4j2.xml
Editing that file, you can set the logging rules (log level per file and component, files rotation, ...).
Log4J log levels are: ERROR, WARN, INFO, DEBUG and TRACE.
You can increase or decrease the logs for specific services. Here are some useful loggers:
org.nuxeo.runtime.deployment.preprocessor.DeploymentPreprocessor
logs the pre-processing orderorg.nuxeo.osgi.application.loader.FrameworkLoader
writes the configuration summaryorg.nuxeo.runtime.osgi.OSGiRuntimeService
provides the final startup summary
Log Files
The log files location depends on the nuxeo.log.dir
parameter. By default, Nuxeo generates the following log files (also available from the platform Admin tab and the Control Panel):
- Launcher logs
- nuxeoctl.log - Logs activity from NuxeoCtl
- console.log - Logs output written to the console (stdout)
- Server logs
- server.log - Server logs
- nuxeo-error.log - Gathers errors raised to the user
- stderr.log - Gathers errors written to the console (stderr)
- classloader.log - Gathers class loading errors from Catalina
- tomcat.log - Gathers Tomcat logs
Tomcat Specific
$NUXEO_HOME/conf/logging.properties
has no effect; you can safely remove it.
Because Tomcat uses java.util.logging
of which Log4J is not aware, Tomcat logs (org.apache.catalina.*
) have to be redirected to Apache Commons Logging (compliant with Log4J).
Nuxeo provides a bridge for that redirection (in org.nuxeo.common.logging.JavaUtilLoggingHelper
) with a default threshold set at INFO level. You can customize it by adding into nuxeo.conf
:
JAVA_OPTS=$JAVA_OPTS -Dorg.nuxeo.runtime.redirectJUL.threshold=CONFIG
But that redirection is only available after Nuxeo Framework initialization whereas most of the startup logs from org.apache.catalina
happen before (when the redirection is not yet active).
Note also that FINER and FINEST logs will be ignored anyway.
JSON format
By editing your log4j2.xml
you can turn log into JSON,
You can have a look at this JSON contribution
Garbage Collector
You can activate the JVM garbage collector logs with the following option in your nuxeo.conf
:
JAVA_OPTS=$JAVA_OPTS -Xlog:gc*:file=${nuxeo.log.dir}/gc.log
Slow NXQL Queries
It is possible to easily pinpoint slow NXQL. If you want trace all the queries that take more than 100ms:
Add the following line in your
nuxeo.conf
:For VCS:
org.nuxeo.vcs.query.log_min_duration_ms=100
For DBS:
org.nuxeo.dbs.query.log_min_duration_ms=100
Activate the log for session you use (VCS or DBS) at the INFO level. Here an example of
lib/log4j2.xml
to get them in a separate file:For VCS:
<Logger name="org.nuxeo.ecm.core.storage.sql.SessionImpl" level="info" additivity="false"> <AppenderRef ref="SLOW" /> </Logger> <File name="SLOW" fileName="${sys:nuxeo.log.dir}/slow-query.log" append="false"> <PatternLayout pattern="%d{ISO8601} %-5p [%t] [%c] %m%X%n" /> </File>
For DBS:
<Logger name="org.nuxeo.ecm.core.storage.dbs.DBSSession" level="info" additivity="false"> <AppenderRef ref="SLOW" /> </Logger> <File name="SLOW" fileName="${sys:nuxeo.log.dir}/slow-query.log" append="false"> <PatternLayout pattern="%d{ISO8601} %-5p [%t] [%c] %m%X%n" /> </File>
To get the slowest queries:
$ grep duration_ms log/slow-query.log | sed -e's/^[^\t]*\t//g' -e 's/{.*$//g' |sort -nr | head
802.89 QueryFilter(principal=system, limit=0, offset=0) query SELECT * FROM Document WHERE ....
12.87 QueryFilter(principal=bob, limit=0, offset=0) queryAndFetch Select DISTINCT ecm:uuid...
10.12 QueryFilter(principal=system, limit=50, offset=0) count total results UNLIMITED query SELECT * FROM Document WHERE ...
5.35 QueryFilter(principal=Administrator, limit=20, offset=0) count total results up to 20 query SELECT * FROM ...
Logging Transactional Events
Configure log4j in $NUXEO_HOME/lib/log4j2.xml
by adding the following keywords to your appender pattern layout: %t
for the thread name and %X
for the logging context map:
<PatternLayout pattern="%d{ISO8601} %-5p [%t] [%c] %m%X%n" />
You should also add a new Logger if you want the traces to be enabled:
<Logger name="org.nuxeo.ecm.core.management.jtajca" level="trace" additivity="false" />
At this stage, once a transaction is started or a connection is opened, their identifiers are put in a context map for the logger. By adding the %X
keyword, you've requested to print them each a message is logged. The transactions and connections will also be logged. You should add additional log statements at level DEBUG
or TRACE
around the code you want to monitor.
Important Log to Monitor
Any log at ERROR
level should be investigated.
Below are described some important logs.
Level | Source Message | Cause |
---|---|---|
INFO | Component Loading Status: Pending: 0 / Missing: 0 / Unstarted: 0 / Total: 813 | A Nuxeo node is started |
ERROR | Terminate computation: XXX due to previous failure | Failure in a computation code after retries, a manual intervention is needed refer to Nuxeo Stream |
ERROR | Exception in processLoop: XXX | Low level failure in a computation thread, a manual intervention is needed refer to Nuxeo Stream |
WARN | Submitted index command: XXX to index the entire default repository | A Bulk Command to re-index the repository has been submitted |
WARN | Index command: XXX completed: XXX docs in XXXs (wait: XXXs, scroll: XXXs) rate: XXX docs/s | A Bulk Command to re-index the repository is completed |
ERROR | [Consumer clientId=XXX, groupId=XXX] Offset commit failed on partition XXX at offset XXX: The request timed out. | This is KafkaConsumer retry under network congestion that can be ignored Kafka-7791 |