https://bz.apache.org/bugzilla/show_bug.cgi?id=63335

            Bug ID: 63335
           Summary: OneLineFormatter will append new space so that the
                    exception stacktrace is shifted but it will not do
                    that for all lines
           Product: Tomcat 8
           Version: 8.5.x-trunk
          Hardware: PC
            Status: NEW
          Severity: normal
          Priority: P2
         Component: Catalina
          Assignee: dev@tomcat.apache.org
          Reporter: jchobanto...@yahoo.com
  Target Milestone: ----

OneLineFormatter will print log message and if there is exception it will
prepend the exception stacktrace with a space but the issue is that a stack
trace will look like this:
Sample Logging Message
<space here>Exception in thread "main" java.lang.NullPointerException
        at com.example.myproject.Book.getTitle(Book.java:16)
        at com.example.myproject.Author.getBookTitles(Author.java:25)
        at com.example.myproject.Bootstrap.main(Bootstrap.java:14)

So now all lines after the message are having a space in front and we could
tell that the log message spawns multiple lines because the log message start
with a space
The issue is when there is a cause to the exception then the stacktrace will
look like this:
Sample Logging Message
<space here>Exception in thread "main" java.lang.NullPointerException
        at com.example.myproject.Book.getTitle(Book.java:16)
        at com.example.myproject.Author.getBookTitles(Author.java:25)
        at com.example.myproject.Bootstrap.main(Bootstrap.java:14)
Caused by: java.lang.NullPointerException
        at com.example.myproject.Book.getId(Book.java:22)
        at com.example.myproject.Author.getBookIds(Author.java:36)
        ... 1 more

So the "Caused by" will not be shifted with one space to the right
More over if the message or the exception itself have new line in their string
message then we will end up with more than one line so the OneLineFormatter as
a name is misleading at best

Also the configuration of the OneLineFormatter is limited - one could only
specify the format of the date and that's all - it is much better to use the
configuration of the java's SimpleFormatter and just extend it to support the
thread name as 8'th parameter
Here is such ExtendedSimpleFormatter class as example that will use
SimpleFormatter message log format pattern and replace newlines with newlines +
space in log messages so that we could implement log message continuation logic
in things like elasticseach's filebeat - knowing that if a new line starts with
space it is continuation of the previous line.
Here is the source of the ExtendedSimpleFormatter that you could use and it was
based on OneLineFormatter in parts:


package org.apache.juli;
import java.io.PrintWriter;
import java.io.StringWriter;
import java.lang.management.ManagementFactory;
import java.lang.management.ThreadInfo;
import java.lang.management.ThreadMXBean;
import java.util.Date;
import java.util.LinkedHashMap;
import java.util.Map;
import java.util.logging.Formatter;
import java.util.logging.LogManager;
import java.util.logging.LogRecord;

public class ExtendedSimpleFormatter extends Formatter {

    private static final String format =
LogManager.getLogManager().getProperty(ExtendedSimpleFormatter.class.getName()
+ ".format");

    private static final String SEARCH_NEW_LINE = "\n";
    private static final String REPLACE_NEW_LINE = "\n ";
    private static final String NEW_LINE_PREFIX = System.lineSeparator() + " ";

    private final Date date = new Date();

    private static final String UNKNOWN_THREAD_NAME = "Unknown thread with ID
";
    private static final Object threadMxBeanLock = new Object();
    private static volatile ThreadMXBean threadMxBean = null;
    private static final int THREAD_NAME_CACHE_SIZE = 10000;
    private static ThreadLocal<ThreadNameCache> threadNameCache = new
ThreadLocal<ThreadNameCache>() {
        @Override
        protected ThreadNameCache initialValue() {
            return new ThreadNameCache(THREAD_NAME_CACHE_SIZE);
        }
    };

    public synchronized String format(LogRecord record) {
        date.setTime(record.getMillis());
        String source;
        if (record.getSourceClassName() != null) {
            source = record.getSourceClassName();
            if (record.getSourceMethodName() != null) {
               source += "." + record.getSourceMethodName();
            }
        } else {
            source = record.getLoggerName();
        }
        String message = formatMessage(record);
        if (message == null) {
            message = "";
        }

        //replace newline with NEW_LINE_REPLACEMENT in order to distinguish
regular log messages from message continuation
        message = replace(message, SEARCH_NEW_LINE, REPLACE_NEW_LINE);

        String throwable = "";
        if (record.getThrown() != null) {
            StringWriter sw = new StringWriter();
            PrintWriter pw = new PrintWriter(sw);
            record.getThrown().printStackTrace(pw);
            pw.close();
            throwable = sw.toString().trim();

            //replace newline with NEW_LINE_REPLACEMENT in order to distinguish
regular log messages from message continuation
            throwable = NEW_LINE_PREFIX + replace(throwable, SEARCH_NEW_LINE,
REPLACE_NEW_LINE);
        }

        String threadName = "";
        if (Thread.currentThread().getId() == record.getThreadID() &&
record.getThreadID() < (Integer.MAX_VALUE / 2)) {
            threadName = Thread.currentThread().getName();
        } else {
            threadName = getThreadName(record.getThreadID());
        }        

        return String.format(format,
                             date,
                             source,
                             record.getLoggerName(),
                             record.getLevel().getLocalizedName(),
                             message,
                             throwable,
                             threadName);
    }

    /*
     * LogRecord has threadID but no thread name.
     * LogRecord uses an int for thread ID but thread IDs are longs.
     * If the real thread ID > (Integer.MAXVALUE / 2) LogRecord uses it's own
     * ID in an effort to avoid clashes due to overflow.
     */    
    private static String getThreadName(int logRecordThreadId) {
        Map<Integer,String> cache = threadNameCache.get();
        String result = null;

        if (logRecordThreadId > (Integer.MAX_VALUE / 2)) {
            result = cache.get(Integer.valueOf(logRecordThreadId));
        }

        if (result != null) {
            return result;
        }

        if (logRecordThreadId >= (Integer.MAX_VALUE / 2)) {
            result = UNKNOWN_THREAD_NAME + logRecordThreadId;
        } else {
            // Double checked locking OK as threadMxBean is volatile
            if (threadMxBean == null) {
                synchronized (threadMxBeanLock) {
                    if (threadMxBean == null) {
                        threadMxBean = ManagementFactory.getThreadMXBean();
                    }
                }
            }
            ThreadInfo threadInfo =
                    threadMxBean.getThreadInfo(logRecordThreadId);
            if (threadInfo == null) {
                return Long.toString(logRecordThreadId);
            }
            result = threadInfo.getThreadName();
        }

        cache.put(Integer.valueOf(logRecordThreadId), result);

        return result;
    }


    private static class ThreadNameCache extends LinkedHashMap<Integer,String>
{

        private static final long serialVersionUID = 1L;

        private final int cacheSize;

        public ThreadNameCache(int cacheSize) {
            this.cacheSize = cacheSize;
        }

        @Override
        protected boolean removeEldestEntry(Map.Entry<Integer, String> eldest)
{
            return (size() > cacheSize);
        }
    }

    private static String replace(String text, String searchString, String
replacement) {
        if (text == null || text.length() == 0 || searchString == null ||
searchString.length() == 0 || replacement == null) {
            return text;
        }
        int start = 0;
        int end = text.indexOf(searchString, start);
        if (end == -1) {
            return text;
        }
        final int replLength = searchString.length();
        int increase = replacement.length() - replLength;
        increase = increase < 0 ? 0 : increase;
        increase *= 16;
        final StringBuilder buf = new StringBuilder(text.length() + increase);
        while (end != -1) {
            buf.append(text, start, end).append(replacement);
            start = end + replLength;
            end = text.indexOf(searchString, start);
        }
        buf.append(text, start, text.length());
        return buf.toString();
    }
}

and here is how to configure it in logging.properties file:
java.util.logging.ConsoleHandler.formatter =
org.apache.juli.ExtendedSimpleFormatter
org.apache.juli.ExtendedSimpleFormatter.format = %1$tY-%1$tm-%1$td
%1$tH:%1$tM:%1$tS.%1$tL %4$s [%7$s] %2$s %5$s%6$s%n

the format is using the java's standard SimpleFormat but with the extension
that we provide thread name as well as parameter 7: %7

-- 
You are receiving this mail because:
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscr...@tomcat.apache.org
For additional commands, e-mail: dev-h...@tomcat.apache.org

Reply via email to