Logging

how-to

Configuring logging; working with the event bus; and log redaction for data security.

The Java SDK logs events and also provides an event bus that transmits information about the behavior of your database system, including system and metric events. It has no hard dependency on a specific logger implementation, but you should add one you are comfortable with.

Logging

The Couchbase Java SDK has no hard dependency on a specific logger implementation. It tries to find a logger on the class path and uses that logger if it is supported by the SDK. If no logger implementation is found, the standard JDK logger is used.

The following loggers are supported (and tried in this order):

SLF4J
JDK Logger (java.util.logging)

Configuring SLF4J

To enable SLF4J, put it on the class path, as well as one of the support logger implementations (like logback). If you want to use logback and include logback-classic, it will be pulled in automatically:

<dependency>
  <groupId>ch.qos.logback</groupId>
  <artifactId>logback-classic</artifactId>
  <version>1.2.3</version>
</dependency>

By default, the log level for logback is set to DEBUG, but with the addition of a logback configuration this can be configured (for example, as a logback.xml in the resources folder):

<configuration>
    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>%d{"yyyy-MM-dd'T'HH:mm:ss,SSSXXX", UTC} [%thread] %-5level %logger{36} - %msg%n</pattern>
        </encoder>
    </appender>

    <root level="info">
        <appender-ref ref="STDOUT" />
    </root>
</configuration>

Consult the SLF4J documentation for advanced configuration.

Configuring Log4j

Log4j can also be used behind the SLF4J logging facade.

<dependency>
    <groupId>org.slf4j</groupId>
    <artifactId>slf4j-log4j12</artifactId>
    <version>1.7.30</version>
</dependency>

If no configuration is applied, the following message appears:

log4j:WARN No appenders could be found for logger (reactor.util.Loggers$LoggerFactory).
log4j:WARN Please initialize the log4j system properly.
log4j:WARN See http://logging.apache.org/log4j/1.2/faq.html#noconfig for more info.

Note that the Reactor library which the Java SDK depends upon also uses the same strategy with SLF4J, so logging for both can be configured with the same strategies out of the box.

This log4j.xml sets it to INFO level:

<?xml version="1.0" encoding="UTF-8" ?>
<!DOCTYPE log4j:configuration SYSTEM "log4j.dtd">
<log4j:configuration xmlns:log4j='http://jakarta.apache.org/log4j/'>

    <appender name="console" class="org.apache.log4j.ConsoleAppender">
        <layout class="org.apache.log4j.PatternLayout">
            <param name="ConversionPattern"
                   value="%d{yyyy-MM-dd'T'HH:mm:ss.SSSZZZZ} %-5p %c{1}:%L - %m%n" />
        </layout>
    </appender>

    <root>
        <level value="INFO" />
        <appender-ref ref="console" />
    </root>

</log4j:configuration>

Consult the Log4J documentation for more information and advanced configuration options.

Configuring the JDK Logger

If no logging library is found on the class path, the JDK logger (also known as JUL from java.util.logging) is used as a fallback.

By default it logs INFO level and above. If you want to set it to DEBUG (or the JUL equivalent: Fine) you can do it like this programmatically before initializing the Cluster object (or creating a custom ClusterEnvironment):

Logger logger = Logger.getLogger("com.couchbase.client");
logger.setLevel(Level.FINE);
for(Handler h : logger.getParent().getHandlers()) {
	if(h instanceof ConsoleHandler){
    	h.setLevel(Level.FINE);
	}
}

You should not use JUL in production because SLF4J and Log4J provide better configuration options and performance.

Customizing the Logger

The logger is configured in a way that it should work out of the box for most users, but there might still be occasion where you want to tweak it. The behavior of the logger can be tuned by customizing the LoggerConfig on the ClusterEnvironment. For example, if you always want to log to stderr and ignore SLF4J (even if present on the classpath) and disable JUL you can configure it this way:

ClusterEnvironment environment = ClusterEnvironment
  .builder()
  .loggerConfig(LoggerConfig
    .fallbackToConsole(true)
    .disableSlf4J(true)
  )
  .build();

You can also use it to enable the Mapped Diagnostic Context.

The Event Bus

Event Bus Stability

While the event bus functionality itself is considered stable, the events itself may not be. Please only consume the events you are interested in, and add error handling code in case of unexpected behaviour.

Log files are neither fun to wade through, nor do they have any kind of real-time aspect. To make them usable, normally their content is piped into systems such as Graphite or Logstash. Since most setups interleave all different kinds of log messages, it makes it very hard to see whats going on, let alone perform post-disaster analysis.

To make the situation better and ultimately improve supportability, the Java SDK provides you with the ability to tap into all events before they get logged and consume them in "real-time".

You can subscribe to the event bus, and receive and react to events as they are happening; not when someone parses the logs, sends them into another system where an alarm is triggered, and eventually a sysadmin checks what iss going on. The time delta between an event happening and reacting to it can thus be substantially decreased.

The following code subscribes to the event bus and prints out all events that are published on it with INFO or WARN level:

ClusterEnvironment environment = ClusterEnvironment.builder().build();

environment.eventBus().subscribe(event -> {
  // handle events as they arrive
  if (event.severity() == Event.Severity.INFO || event.severity() == Event.Severity.WARN) {
    System.out.println(event);
  }
});

Cluster cluster = Cluster.connect(
    connectionString,
    ClusterOptions.clusterOptions(username, password).environment(environment)
);

Bucket bucket = cluster.bucket(bucketName);

This leads to output similar to this:

CoreCreatedEvent{severity=INFO, category=com.couchbase.core, duration=PT0S, createdAt=43700573062858, description={"clientVersion":"3.0.0","clientGitHash":"a3d7a770","coreVersion":"2.0.0","coreGitHash":"a3d7a770","userAgent":"couchbase-java/3.0.0 (Mac OS X 10.14.6 x86_64; OpenJDK 64-Bit Server VM 1.8.0_202-b08)","maxNumRequestsInRetry":32768,"ioEnvironment":{"nativeIoEnabled":true,"eventLoopThreadCount":6,"eventLoopGroups":["KQueueEventLoopGroup"]},"ioConfig":{"captureTraffic":[],"mutationTokensEnabled":true,"networkResolution":"auto","dnsSrvEnabled":true,"tcpKeepAlivesEnabled":true,"tcpKeepAliveTimeMs":60000,"configPollIntervalMs":2500,"kvCircuitBreakerConfig":"disabled","queryCircuitBreakerConfig":"disabled","viewCircuitBreakerConfig":"disabled","searchCircuitBreakerConfig":"disabled","analyticsCircuitBreakerConfig":"disabled","managerCircuitBreakerConfig":"disabled","numKvConnections":1,"maxHttpConnections":12,"idleHttpConnectionTimeoutMs":30000,"configIdleRedialTimeoutMs":300000},"compressionConfig":{"enabled":true,"minRatio":0.83,"minSize":32},"securityConfig":{"tlsEnabled":false,"nativeTlsEnabled":true,"hasTrustCertificates":false,"trustManagerFactory":null},"timeoutConfig":{"kvMs":2500,"kvDurableMs":10000,"managementMs":75000,"queryMs":75000,"viewMs":75000,"searchMs":75000,"analyticsMs":75000,"connectMs":10000,"disconnectMs":10000},"loggerConfig":{"customLogger":null,"fallbackToConsole":false,"disableSlf4j":false,"loggerName":"CouchbaseLogger","diagnosticContextEnabled":false},"orphanReporterConfig":{"emitIntervalMs":10000,"sampleSize":10,"queueLength":1024},"retryStrategy":"BestEffortRetryStrategy","requestTracer":"OwnedSupplier"}, context=CoreContext{coreId=1}, cause=null}

NodeConnectedEvent{severity=INFO, category=com.couchbase.node, duration=PT0S, createdAt=43700609755560, description=Node connected, context=NodeContext{coreId=1, managerPort=8091, remote=127.0.0.1}, cause=null}

BucketOpenedEvent{severity=INFO, category=com.couchbase.core, duration=PT0.281625729S, createdAt=43701036027888, description=Opened bucket "travel-sample", context=CoreContext{coreId=1}, cause=null}

We recommend filtering on the specific events you are interested in, since most of the time only a subset of the published ones will be of use to you. Also, there are new events added between releases so make sure these new events do not break your functionality.

Blocking Warning

If you consume the EventBus you MUST NOT block inside the consumer callback. It will stall all other consumers. If you must write into a blocking sink like a blocking HTTP API you MUST write it onto a different thread with a non-blocking queue first.

Log Redaction

Redacting logs is a two-stage process. If you want to redact client logs (for example before handing them off to the Couchbase Support team) you first need to enable log redaction in your application.

LogRedaction.setRedactionLevel(RedactionLevel.FULL);

Different redaction levels are supported — please see the RedactionLevel enum description for more information.

Note that you need to run this command before any of the SDK code is initialized so all of the logs are captured properly. Once the SDK writes the logs with the tags to a file, you can then use the cblogredaction tool to obfuscate the log.

You may wish to read more on Log Redaction in the Server docs.