Using the Logback SDK v2

Available in Classic and VPC

This chapter describes how to use Effective Log Search & Analytics Logback SDK. NELO is the project code name for Effective Log Search & Analytics.

Add NELO2 Logback SDK dependency

Add Dependency as below.
After unzip the file, add the path to the core module and logback module to <systemPath>.

• Download logback SDK

<dependencies>
        <dependency>
            <groupId>nelo2-java-sdk-core</groupId>
            <artifactId>nelo2-java-sdk-core</artifactId>
            <version>1.6.6</version>
            <scope>system</scope>
            <systemPath>/nelo2-java-sdk-core-1.6.6.jar</systemPath>
        </dependency>
        <dependency>
            <groupId>nelo2-java-sdk</groupId>
            <artifactId>nelo2-java-sdk-logback</artifactId>
            <version>1.6.6</version>
            <scope>system</scope>
            <systemPath>/nelo2-java-sdk-logback-1.6.6.jar</systemPath>
        </dependency>
        <dependency>
            <groupId>ch.qos.logback</groupId>
            <artifactId>logback-classic</artifactId>
            <version>1.1.7</version>
        </dependency>
        <dependency>
            <groupId>org.apache.thrift</groupId>
            <artifactId>libthrift</artifactId>
            <version>0.9.3</version>
        </dependency>
        <dependency>
            <groupId>org.apache.httpcomponents</groupId>
            <artifactId>httpclient</artifactId>
            <version>4.2.6</version>
        </dependency>
        <dependency>
            <groupId>com.fasterxml.jackson.core</groupId>
            <artifactId>jackson-databind</artifactId>
            <version>2.3.1</version>
        </dependency>
</dependencies>

Remarks

• This SDK includes the logback-classic, which is the slf4J binding library for the logback.
  Because the slf4j supports only one binding at a time, you cannot use any libraries for other slf4j bindings.

• Among Logback libraries, SLF4J binding library is the logback-classic.
  Problems may occur if an existing reference library is duplicated with the library referenced by the nelo2 logback SDK.
  We recommend using a higher version in this case.

Effective Log Search & Analytics logback appender settings and options

Logback searches for configuration files in the following order: logback.groovy -> logback-test.xml -> logback.xml.

This document is explained based on the logback.xml. The common logback.xml configuration is as follows.

<configuration>
    <!-- Console Appender -->
    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>%d{yyyy-MM-dd HH:mm:ss} [%-5level]\(%file:%line\) %msg%n</pattern>
        </encoder>
    </appender>
    <!-- Logger -->
    <logger name="com" additivity="false">
        <level value="debug"/>
        <appender-ref ref="STDOUT" />
    </logger>
    <!-- Root Logger -->
    <root level="warn">
        <appender-ref ref="STDOUT" />
    </root>
</configuration>

NELO2 Logback appender can be set as follows.

<appender name="nelo" class="com.naver.nelo2.logback.ThriftAppender">
    <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
        <level>TRACE</level>
    </filter>
    <param name="projectName" value="Project ID"></param>
    <param name="collectorUrl" value="elsa-col.ncloud.com"></param>
    <param name="encoding" value="utf-8"></param>
    <param name="timeout" value="1200"></param>
    <param name="enable" value="true"></param>
    <param name="debug" value="false"></param>
    <param name="version" value="1.0.0"></param>
    <param name="errorCodeType" value="default"></param>
    <param name="port" value="10006"></param>
    <param name="isBulkEnabled" value="true"></param>
</appender>

The following can be set as options.

• Appender (Select appender's class name according to transmission protocols.)

  • Thrift Appender : com.naver.nelo2.logback.ThriftAppender

  • Http Appender : com.naver.nelo2.logback.HttpAppender

• projectName: Project ID. You can view a project ID created in Effective Log Search & Analytics's project information.

• version : Project version (Only English letters, numbers, "-", and "" are allowed. It must start with an alphabetic character/number/"".)

• collectorUrl: Effective Log Search & Analytics log collector server URL

  • ThriftAppender: elsa-col.ncloud.com

  • HttpAppender: http://elsa-col.ncloud.com/_store

• port: Collector server port

  • Thrift Appender : 10006

  • Http Appender : 80

• enable: Whether to use (Default: true)

• logType : logType settings

• logSource : logSource settings

• errorCodeType: Error code type

  • default: Use the exception information of Logback default information. If the exception information is not delivered (if a log is recorded in the log.error(message) format), the entire error message is used as an error code.
    
    ex) If NullPointerException occurs => NullPointerException

  • message: Use only from the beginning until the blank of an error message.
    
    e.g.) Download error Download failed. => Download error

  • mdc: Set the “errorCode” metric value of SLF4J MDC to use.
    
    e.g.)MDC.put(“errorCode”, “Login”) => Login

• debug: Output message for Nelo2 appender debugging. The default value is false.

  • This option applies globally, and "true" overrides "false". That is, if multiple appenders are declared, and one of them has the debug value of true, every appender will output debug logs to the Console.

• timeout: Timeout of socket used to send, Default: 5000ms (5s).

• keepAlive: keepAlive Timeout of socket used to send. Default: 60000ms (1m), Maximum: 180000ms (3m)

• isBulkEnabled : Whether to use the bulk mode. Default: true. If false, send each log individually.

• bulkSize : The maximum number of logs to be sent in a single bulk when using the bulk mode. Default: 1000, Maximum: 100000.

• bulkInterval : interval to call bulk request, defaults to 1000ms(1 sec), maximum 10000ms(10 sec)

• alwaysIncludeLocation : whether SDK add Location fields to all logs, defaults to true.

  • false : check and set Location fields for logs which logLevel is ERROR.
  • true : check and set Location field for all logs. This may bring bad effects to logging performance compare to false.

• mdcConversionRule : Rules to rename MDC key

  • format: key1:newKey1;key2:newkey2;...
    
    e.g.) Set mdcConversionRule to time:date;fullname:name, this rule will rename MDC key time to date and fullname to name if they are exists.

bulk/single

Effective Log Search & Analytics logback SDK supports the single mode for sending a log per request and the bulk mode for sending it in a batch.

You can set isBulkEnabled to true/false in the xml appender settings to use the bulk/single mode. (Default: true)

Refer to the table below for a performance reference depending on a protocol.

Throughput when sending a log of 1kb size in a single thread for 10 minutes

• thrift
  • single mode : 2587.93 logs/sec
  • bulk mode : 6492.99 logs/sec
• http
  • single mode : 595.86 logs/sec
  • bulk mode : 4617.98 logs/sec

The specifications of the equipment used for the above performance test are as follows.

• Log transmission server: 2GHZ 12core cpu, 48G mem
• Log collector server: 2.26GHZ 12core cpu, 48G mem

Remarks

• Transmission performance may vary depending on a load.
  Tests were run in a no-load situation, and it shows relatively low performance when being sent to the real instances in use.
  The perceived performance according to the instance load is greater in the single mode than in the bulk mode.
  Therefore, we recommend using the default bulk mode.

• The collector server allows a packet size up to 30MB.
  You must set the appropriate bulkSize considering a client server log pattern. (Default: 1000)

AsyncAppender

You can get the same result by using AsyncAppender, which is supported by the logback as below.

The following are the settings you should be aware of. The default queueSize is 128, but it may not be sufficient for some applications.

The default includeCallerData is false, in which case AsyncAppender will ignore the log occurrence location information.

Please refer to AsyncAppender setting example below.

<appender name="nelo-logback-async" class="ch.qos.logback.classic.AsyncAppender">
    <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
        <level>ERROR</level>
    </filter>
    <param name="neverBlock" value="true" />
    <param name="includeCallerData" value="true" />
    <param name="queueSize" value="2048" />
    <appender-ref ref="nelo-logback" />
</appender>

For more information on the settings, refer to Official Document.

How to use AsyncAppender

In addition to ThriftAppender you use by default, you can use LogbackAsyncAppender to set the actual log transmission to be performed on a separate thread.

To do this, set the xml file as shown below.

<configuration> 
    <!-- Console Appender --> 
    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender"> 
        <encoder> 
            <pattern>%d{yyyy-MM-dd HH:mm:ss} [%-5level]\(%file:%line\) %msg%n</pattern> 
        </encoder> 
    </appender>

    <!-- NELO2 Logback Appender -->
    <appender name="nelo-logback" class="com.naver.nelo2.logback.ThriftAppender">
        <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
            <level>ERROR</level>
        </filter>
        <param name="projectName" value="Project ID"/>
        <param name="collectorUrl" value="elsa-col.ncloud.com"/>
        <param name="port" value="10006"/>
        <param name="timeout" value="1200" />
        <param name="enable" value="true" />
        <param name="errorCodeType" value="default" />
    </appender>

    <!-- NELO2 Logback Async Appender -->
    <appender name="nelo-logback-async" class="ch.qos.logback.classic.AsyncAppender">
        <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
            <level>ERROR</level>
        </filter>
        <param name="neverBlock" value="true" />
        <param name="IncludeCallerData" value="true" />
        <param name="queueSize" value="2048" />
        <appender-ref ref="nelo-logback" />
    </appender>
    
    <!-- Logger -->
    <logger name="com" additivity="false">
        <level value="debug"/>
        <appender-ref ref="STDOUT" />
        <appender-ref ref="nelo-logback-async" />
    </logger>

    <!-- Root Logger -->
    <root level="warn">
        <appender-ref ref="STDOUT" />
        <appender-ref ref="nelo-logback-async" />
    </root>
</configuration>

Effective Log Search & Analytics logback SDK usage example

The following is an example of the codes that actually use Effective Log Search & Analytics Logback SDK.

... 
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

private static Logger logger = LoggerFactory.getLogger(LogbackTest.class);
...
    logger.debug("Effective Log Search & Analytics Logback SDK Debug Message");
    try {
        String npe = null;
        npe.toString();
    } catch(Exception e) {
        logger.error("Effective Log Search & Analytics Logback SDK Exception", e);
    }

Limitations

• When using the async appender, occurring logs that exceed the queue size will not be sent if the log occurrence rate is faster than the transmission rate.
• We recommend that you select between the async appender and the default appender according to the criteria below.
• To minimize log loss: Default appender
  • If concerned about application performance degradation in the event of Effective Log Search & Analytics system failure: async appender

Troubleshooting

1. When a log is sent to Effective Log Search & Analytics, but cannot be viewed on the web

Check if a project ID is correct. If the project ID is incorrect, you cannot view logs in Web Dashboard.

Next, confirm if the actual error data is sent. In the configuration file(logback.xml), set the debug property of the nelo2 appender to true and execute it to check if the following transmission logs are output.

<!-- NELO2 Logback Appender -->
<appender name="nelo-logback" class="com.naver.nelo2.logback.ThriftAppender">
    <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
        <level>ERROR</level>
    </filter>
    <param name="projectName" value="%YOUR_PROJECT_ID%"/>
    <param name="collectorUrl" value="elsa-col.ncloud.com"/>
    <param name="port" value="10006"/>
    <param name="timeout" value="1200" />
    <param name="enable" value="true" />
    <param name="errorCodeType" value="default" />
    <param name="debug" value="true" />
</appender>

[NELO2] Log Append : sent event, return value :
…

FAQ

1. How do I use AsyncAppender in a batch program (or a simple test program)?

You need to add some codes to wait for a few seconds at the end of a batch program.

try {
    Thread.sleep(3000L);
} catch (InterruptedException ignore){}

AsyncAppender has a separate daemon thread to record logs internally, thus it delivers logs asynchronously.

In Java batch program, the main thread is terminated immediately, so the daemon thread of the log4jAsyncAppender is created and the batch application is shut down before sending logs.

JVM is terminated immediately if there are no live general threads regardless of a daemon thread.

Therefore, add the codes for waiting at the end of the program as above so that it can be terminated after sending all logs.

2. How can I log Java stack trace to the logback?

In order to output a stack trace using the logback in Action / BO / DAO / Java batch program, use the form of the log.error(e.getMessage(), e);.

SLF4J Logger is a method factor and does not support logging methods that only accept Throwable.

String[] aa = null;
try {
    aa[0] = "111";
} catch (NullPointerException e) {
//	log.error(e); //Methods not supported by SLF4J.
    log.error(e.getMessage(), e); ///stacktrace outputted.
}

3. How can I minimize performance degradation caused by the logback logging?

You can use a name and level in the logback.xml logger settings to maximize filtering.

If you set com or org to DEBUG level in the logger settings as below, lots of ILoggingEvent (logback) is unnecessarily generated in the logger.

Threshold is set to ERROR in the nelo logback appender, so logs are actually not sent, but ILoggingEvent is created in the logger and passed to the appender.

Settings that degrade performance (for developing only)

<!-- Logger -->
<logger name="com" additivity="false">
    <level value="debug"/>
    <appender-ref ref="STDOUT" />
    <appender-ref ref="nelo-logback" />
</logger>

<!-- Logger -->
<logger name="org" additivity="false">
    <level value="debug"/>
    <appender-ref ref="STDOUT" />
    <appender-ref ref="nelo-logback" />
</logger>

<!-- Root Logger -->
<root level="warn">
    <appender-ref ref="STDOUT" />
    <appender-ref ref="nelo-logback" />
</root>

Settings that consider performance (for operating)

<!-- Logger -->
<logger name="com" additivity="false">
    <level value="error"/>
    <appender-ref ref="STDOUT" />
    <appender-ref ref="nelo-logback" />
</logger>

<!-- Root Logger -->
<root level="warn">
    <appender-ref ref="STDOUT" />
    <appender-ref ref="nelo-logback" />
</root>

4. How can I terminate stably when using in WAS?

If WAS (Tomcat, etc.) is terminated while error logs are being sent, the following exception may occur and sometimes WAS may not be shut down normally.

To prevent this, you can stably terminate by calling the stop() method for LoggerContext instance to close the nelo2 java appender when finishing WAS.

Remarks

Spring provides org.springframework.web.util.Log4jConfigListener for Log4J, but it does not offer Listener to support stable termination for Logback.

Nelo2 logback SDK provides its own LogbackShutdownListener. Adding the following settings to web.xml enables stable termination even if error log transmission occurs when exiting WAS.

<listener>
    <listener-class>
        com.naver.nelo2.logback.LogbackShutdownListener
    </listener-class>
</listener>

5. If a timeout occurs during the thrift bulk transmission

If a log was not sent normally to a collector server, you can check the following logs.

[NELO2] sendMessage (1426319665440) sendBulk failed..  Error occur : java.net.SocketTimeoutException: Read timed out

In this case, you need to increase the timeout and lower the bulkSize to reduce the data to be included in one packet in the xml appender settings.

6. Note for memory usage

SDK currently offers the bulk transmission mode by default, and the default bulkSize is 1000.

As one Effective Log Search & Analytics log contains several fields such as projectName, it occupies about 1kb of the memory even though a log body is very short.

Therefore, by default, the bulk occupies (log size+1KB)*1000 of the memory.

When you run Java process, you can specify the maximum heap with the -Xmx option. You must consider the additional memory usage mentioned above.

Be especially careful if you specify a larger bulkSize option.

7. Warning messages related to httpClient logging

If using http protocol, the following logs will be generated when an application starts.

This is because the httpClient library uses the apache logging framework, and the logs generated here are kept in the root logger.

SLF4J: The following loggers will not work because they were created
SLF4J: during the default configuration phase of the underlying logging system.
SLF4J: See also http://www.slf4j.org/codes.html#substituteLogger
SLF4J: org.apache.http.impl.conn.PoolingClientConnectionManager
SLF4J: org.apache.http.impl.conn.DefaultClientConnectionOperator
SLF4J: org.apache.http.impl.client.DefaultHttpClient