Logback: gracefully split messages at 64k

We have a log collecting service that automatically splits messages at 64KB, but the split is not elegant at all. We are printing individual log messages as json blobs with some additional metadata. Sometimes these include large stack traces that we want to preserve in full.

So I was looking into writing a custom logger or appender wrapper that would take the message and split it into smaller chunks and re-log it but that's looking non-trivial.

Is there a simple way to configure logback to split up its messages into multiple separate messages if the size of the message is greater than some value?

Here is the appender configuration:

<!-- Sumo optimized rolling log file -->
<appender name="file" class="ch.qos.logback.core.rolling.RollingFileAppender">
    <Append>true</Append>
    <file>${log.dir}/${service.name}-sumo.log</file>
    <encoder class="net.logstash.logback.encoder.LoggingEventCompositeJsonEncoder">
        <providers>
            <timestamp>
                <fieldName>t</fieldName>
                <pattern>yyyy-MM-dd'T'HH:mm:ss.SSS'Z'</pattern>
                <timeZone>UTC</timeZone>
            </timestamp>
            <message/>
            <loggerName/>
            <threadName/>
            <logLevel/>
            <stackTrace>
                <if condition='isDefined("throwable.converter")'>
                    <then>
                        <throwableConverter class="${throwable.converter}"/>
                    </then>
                </if>
            </stackTrace>
            <mdc/>
            <tags/>
        </providers>
    </encoder>
    <rollingPolicy class="ch.qos.logback.core.rolling.FixedWindowRollingPolicy">
        <maxIndex>1</maxIndex>
        <FileNamePattern>${log.dir}/${service.name}-sumo.log.%i</FileNamePattern>
    </rollingPolicy>
    <triggeringPolicy class="ch.qos.logback.core.rolling.SizeBasedTriggeringPolicy">
        <MaxFileSize>256MB</MaxFileSize>
    </triggeringPolicy>
</appender>

<appender name="sumo" class="ch.qos.logback.classic.AsyncAppender">
    <queueSize>500</queueSize>
    <discardingThreshold>0</discardingThreshold>
    <appender-ref ref="file" />
</appender>

Answers


The solution I came up with is simply to wrap my logger in something that splits up messages nicely. Note that I'm primarily interested in splitting messages with Throwables since those are what causes long messages.

Written with lambdas for Java 8

Also note this code is not fully tested, I'll update it if I find any bugs.

public class MessageSplittingLogger extends MarkerIgnoringBase {
    //Target size is 64k for split.  UTF-8 nominally has 1 byte characters, but some characters will use > 1 byte so leave some wiggle room
    //Also leave room for additional messages
    private static final int MAX_CHARS_BEFORE_SPLIT = 56000;
    private static final String ENCODING = "UTF-8";
    private Logger LOGGER;

    public MessageSplittingLogger(Class<?> clazz) {
        this.LOGGER = LoggerFactory.getLogger(clazz);
    }

    private void splitMessageAndLog(String msg, Throwable t, Consumer<String> logLambda) {
        String combinedMsg = msg + (t != null ? "\nStack Trace:\n" + printStackTraceToString(t) : "");

        int totalMessages = combinedMsg.length() / MAX_CHARS_BEFORE_SPLIT;
        if(combinedMsg.length() % MAX_CHARS_BEFORE_SPLIT > 0){
            totalMessages++;
        }

        int index = 0;
        int msgNumber = 1;
        while (index < combinedMsg.length()) {
            String messageNumber = totalMessages > 1 ? "(" + msgNumber++ + " of " + totalMessages + ")\n" : "";
            logLambda.accept(messageNumber + combinedMsg.substring(index, Math.min(index + MAX_CHARS_BEFORE_SPLIT, combinedMsg.length())));
            index += MAX_CHARS_BEFORE_SPLIT;
        }
    }

    /**
     * Get the stack trace as a String
     */
    private String printStackTraceToString(Throwable t) {
        try {
            ByteArrayOutputStream baos = new ByteArrayOutputStream();
            PrintStream ps = new PrintStream(baos, true, ENCODING);
            t.printStackTrace(ps);

            return baos.toString(ENCODING);
        } catch (UnsupportedEncodingException e) {
            return "Exception printing stack trace: " + e.getMessage();
        }
    }

    @Override
    public String getName() {
        return LOGGER.getName();
    }

    @Override
    public boolean isTraceEnabled() {
        return LOGGER.isTraceEnabled();
    }

    @Override
    public void trace(String msg) {
        LOGGER.trace(msg);
    }

    @Override
    public void trace(String format, Object arg) {
        LOGGER.trace(format, arg);
    }

    @Override
    public void trace(String format, Object arg1, Object arg2) {
        LOGGER.trace(format, arg1, arg2);
    }

    @Override
    public void trace(String format, Object... arguments) {
        LOGGER.trace(format, arguments);
    }

    @Override
    public void trace(String msg, Throwable t) {
        splitMessageAndLog(msg, t, LOGGER::trace);
    }

    //... Similarly wrap calls to debug/info/error
}

Need Your Help

time to event for panel data

r data-manipulation

I have a panel data set of country years. I would like to calculate time since event, as well as get a running total of events per country which I can decay over time. I am using the timeSinceEvent

Kendo Grid inside Kendo TabStrip has unlimited height

javascript html5 kendo-ui kendo-grid kendo-tabstrip

I have a Kendo Grid that is placed on a page and it spans on the whole visible page (width and height). If there's too many rows, grid shows a scroll bar.