You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@druid.apache.org by Don Bowman <do...@agilicus.com> on 2019/02/08 13:22:02 UTC

json logging enable

I am finding that the logging produced is very complex to manage. I would
like to add logstash json_event (
https://github.com/logstash/log4j-jsonevent-layout).
Any comments before I start?

In my environment I'm using fluent-bit, others are using logstash. Its
inconvenient to have multi-line log messages, or have to fish through
exceptions.

Is there any other way to achieve?

Some have suggested e.g.

log4j.appender.stdout=org.apache.log4j.ConsoleAppender
log4j.appender.stdout.encoding=UTF-8
log4j.appender.stdout.layout=org.apache.log4j.PatternLayout
log4j.appender.stdout.layout.ConversionPattern={"level":"%p","timestamp":"%d{ISO8601}","thread":"%t","file":"%F",
"line":"%L","message":"%m"}%n

but this won't work if there's a quote or newline.

Re: json logging enable

Posted by Don Bowman <do...@agilicus.com>.
What would be involved in updating log4j to version 2.10+ from the current
2.5? That would fix some of the json logging issues (reading the release
notes).

On Fri, 8 Feb 2019 at 12:27, Charles Allen <ch...@snap.com.invalid>
wrote:

> Structured logging is not in a very good state in Druid right now (or the
> industry in general). Part of the issue is that the log4j standard json
> format is not very compatible with modern json logging systems. I even
> modified the sumologic appender to get better productionized items into it
> at https://github.com/metamx/sumologic-log4j2-appender . I do not know if
> there is a stackdriver friendly log4j formatter out there, but it would not
> surprise me if there was but it pulled in guava version future+inifnity.
>
> My current log4j2 layout
> <https://logging.apache.org/log4j/2.x/manual/layouts.html#JSONLayout> line
> looks like this:
> <JsonLayout compact="true" eventEol="true" complete="false" properties=
> "true" />
>
> Which is kind of annoying, especially with stack traces which can easily
> overflow a "single line length" in logging infrastructures.
>
> If you ever do find it worth your while to go down the route of writing a
> custom format for your logging system. The easiest way I found was to
> piggyback on the jackson format and just annotate a special class with
> whatever fields in whichever format you want:
>
>
> https://github.com/metamx/sumologic-log4j2-appender/blob/master/src/main/java/com/sumologic/log4j/core/SumoJsonLayout.java#L117-L237
>
>
>
> On Fri, Feb 8, 2019 at 5:22 AM Don Bowman <do...@agilicus.com> wrote:
>
> > I am finding that the logging produced is very complex to manage. I would
> > like to add logstash json_event (
> > https://github.com/logstash/log4j-jsonevent-layout).
> > Any comments before I start?
> >
> > In my environment I'm using fluent-bit, others are using logstash. Its
> > inconvenient to have multi-line log messages, or have to fish through
> > exceptions.
> >
> > Is there any other way to achieve?
> >
> > Some have suggested e.g.
> >
> > log4j.appender.stdout=org.apache.log4j.ConsoleAppender
> > log4j.appender.stdout.encoding=UTF-8
> > log4j.appender.stdout.layout=org.apache.log4j.PatternLayout
> >
> >
> log4j.appender.stdout.layout.ConversionPattern={"level":"%p","timestamp":"%d{ISO8601}","thread":"%t","file":"%F",
> > "line":"%L","message":"%m"}%n
> >
> > but this won't work if there's a quote or newline.
> >
>

Re: json logging enable

Posted by Charles Allen <ch...@snap.com.INVALID>.
Actually druid uses SLF4J, so you should be able to add in the logback libs
to the classpath and things *should* just work.

On Fri, Feb 8, 2019 at 10:09 AM Don Bowman <do...@agilicus.com> wrote:

> thanks!
>
> is there any movement to move to 'logback' from log4j? That would allow
> using e.g. https://github.com/logstash/logstash-logback-encoder
>
> the problem w/ the JsonLayout approach is that it doesn't seem to get
> exceptions properly.
>
> E.g. I get something like below.
>
>
> {"timeMillis":1549648630326,"thread":"main","level":"INFO","loggerName":"org.apache.druid.java.util.common.lifecycle.Lifecycle$AnnotationBasedHandler","message":"Invoking
> stop method[public void
>
> org.apache.druid.initialization.Log4jShutterDownerModule$Log4jShutterDowner.stop()]
> on
>
> object[org.apache.druid.initialization.Log4jShutterDownerModule$Log4jShutterDowner@61d60e38
>
> ].","endOfBatch":false,"loggerFqcn":"org.apache.logging.slf4j.Log4jLogger","contextMap":[]}
> 2019-02-08 17:57:10,342 main ERROR Unable to register shutdown hook because
> JVM is shutting down. java.lang.IllegalStateException: Not started
> at
>
> org.apache.druid.common.config.Log4jShutdown.addShutdownCallback(Log4jShutdown.java:48)
> at
>
> org.apache.logging.log4j.core.impl.Log4jContextFactory.addShutdownCallback(Log4jContextFactory.java:273)
> at
>
> org.apache.logging.log4j.core.LoggerContext.setUpShutdownHook(LoggerContext.java:256)
> at
> org.apache.logging.log4j.core.LoggerContext.start(LoggerContext.java:216)
> at
>
> org.apache.logging.log4j.core.impl.Log4jContextFactory.getContext(Log4jContextFactory.java:145)
> at
>
> org.apache.logging.log4j.core.impl.Log4jContextFactory.getContext(Log4jContextFactory.java:41)
> at org.apache.logging.log4j.LogManager.getContext(LogManager.java:182)
> at
>
> org.apache.logging.log4j.spi.AbstractLoggerAdapter.getContext(AbstractLoggerAdapter.java:103)
> at
>
> org.apache.logging.slf4j.Log4jLoggerFactory.getContext(Log4jLoggerFactory.java:43)
> at
>
> org.apache.logging.log4j.spi.AbstractLoggerAdapter.getLogger(AbstractLoggerAdapter.java:42)
> at
>
> org.apache.logging.slf4j.Log4jLoggerFactory.getLogger(Log4jLoggerFactory.java:29)
> at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:253)
> at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:265)
> at
>
> org.apache.curator.utils.CloseableExecutorService.<init>(CloseableExecutorService.java:40)
> at
>
> org.apache.druid.curator.cache.PathChildrenCacheFactory.make(PathChildrenCacheFactory.java:55)
> at
>
> org.apache.druid.curator.inventory.CuratorInventoryManager.start(CuratorInventoryManager.java:109)
> at
>
> org.apache.druid.client.AbstractCuratorServerInventoryView.start(AbstractCuratorServerInventoryView.java:168)
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at
>
> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
> at
>
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:498)
> at
>
> org.apache.druid.java.util.common.lifecycle.Lifecycle$AnnotationBasedHandler.start(Lifecycle.java:427)
> at
>
> org.apache.druid.java.util.common.lifecycle.Lifecycle.start(Lifecycle.java:323)
> at org.apache.druid.guice.LifecycleModule$2.start(LifecycleModule.java:138)
> at org.apache.druid.cli.GuiceRunnable.initLifecycle(GuiceRunnable.java:107)
> at org.apache.druid.cli.ServerRunnable.run(ServerRunnable.java:58)
> at org.apache.druid.cli.Main.main(Main.java:118)
>
>
>
> On Fri, 8 Feb 2019 at 12:27, Charles Allen <charles.allen@snap.com
> .invalid>
> wrote:
>
> > Structured logging is not in a very good state in Druid right now (or the
> > industry in general). Part of the issue is that the log4j standard json
> > format is not very compatible with modern json logging systems. I even
> > modified the sumologic appender to get better productionized items into
> it
> > at https://github.com/metamx/sumologic-log4j2-appender . I do not know
> if
> > there is a stackdriver friendly log4j formatter out there, but it would
> not
> > surprise me if there was but it pulled in guava version future+inifnity.
> >
> > My current log4j2 layout
> > <
> https://urldefense.proofpoint.com/v2/url?u=https-3A__logging.apache.org_log4j_2.x_manual_layouts.html-23JSONLayout&d=DwIBaQ&c=ncDTmphkJTvjIDPh0hpF_w&r=HrLGT1qWNhseJBMYABL0GFSZESht5gBoLejor3SqMSo&m=v3J-Uid1SfjBwbQj0bygNz7-FkK1Cw4ubdPwAFDUeLk&s=s49QFMDklbZ3qj13P53cf8fzxtS-phSdM2B3OeWfuNw&e=>
> line
> > looks like this:
> > <JsonLayout compact="true" eventEol="true" complete="false" properties=
> > "true" />
> >
> > Which is kind of annoying, especially with stack traces which can easily
> > overflow a "single line length" in logging infrastructures.
> >
> > If you ever do find it worth your while to go down the route of writing a
> > custom format for your logging system. The easiest way I found was to
> > piggyback on the jackson format and just annotate a special class with
> > whatever fields in whichever format you want:
> >
> >
> >
> https://github.com/metamx/sumologic-log4j2-appender/blob/master/src/main/java/com/sumologic/log4j/core/SumoJsonLayout.java#L117-L237
> >
> >
> >
> > On Fri, Feb 8, 2019 at 5:22 AM Don Bowman <do...@agilicus.com> wrote:
> >
> > > I am finding that the logging produced is very complex to manage. I
> would
> > > like to add logstash json_event (
> > > https://github.com/logstash/log4j-jsonevent-layout).
> > > Any comments before I start?
> > >
> > > In my environment I'm using fluent-bit, others are using logstash. Its
> > > inconvenient to have multi-line log messages, or have to fish through
> > > exceptions.
> > >
> > > Is there any other way to achieve?
> > >
> > > Some have suggested e.g.
> > >
> > > log4j.appender.stdout=org.apache.log4j.ConsoleAppender
> > > log4j.appender.stdout.encoding=UTF-8
> > > log4j.appender.stdout.layout=org.apache.log4j.PatternLayout
> > >
> > >
> >
> log4j.appender.stdout.layout.ConversionPattern={"level":"%p","timestamp":"%d{ISO8601}","thread":"%t","file":"%F",
> > > "line":"%L","message":"%m"}%n
> > >
> > > but this won't work if there's a quote or newline.
> > >
> >
>

Re: json logging enable

Posted by Don Bowman <do...@agilicus.com>.
thanks!

is there any movement to move to 'logback' from log4j? That would allow
using e.g. https://github.com/logstash/logstash-logback-encoder

the problem w/ the JsonLayout approach is that it doesn't seem to get
exceptions properly.

E.g. I get something like below.

{"timeMillis":1549648630326,"thread":"main","level":"INFO","loggerName":"org.apache.druid.java.util.common.lifecycle.Lifecycle$AnnotationBasedHandler","message":"Invoking
stop method[public void
org.apache.druid.initialization.Log4jShutterDownerModule$Log4jShutterDowner.stop()]
on
object[org.apache.druid.initialization.Log4jShutterDownerModule$Log4jShutterDowner@61d60e38
].","endOfBatch":false,"loggerFqcn":"org.apache.logging.slf4j.Log4jLogger","contextMap":[]}
2019-02-08 17:57:10,342 main ERROR Unable to register shutdown hook because
JVM is shutting down. java.lang.IllegalStateException: Not started
at
org.apache.druid.common.config.Log4jShutdown.addShutdownCallback(Log4jShutdown.java:48)
at
org.apache.logging.log4j.core.impl.Log4jContextFactory.addShutdownCallback(Log4jContextFactory.java:273)
at
org.apache.logging.log4j.core.LoggerContext.setUpShutdownHook(LoggerContext.java:256)
at org.apache.logging.log4j.core.LoggerContext.start(LoggerContext.java:216)
at
org.apache.logging.log4j.core.impl.Log4jContextFactory.getContext(Log4jContextFactory.java:145)
at
org.apache.logging.log4j.core.impl.Log4jContextFactory.getContext(Log4jContextFactory.java:41)
at org.apache.logging.log4j.LogManager.getContext(LogManager.java:182)
at
org.apache.logging.log4j.spi.AbstractLoggerAdapter.getContext(AbstractLoggerAdapter.java:103)
at
org.apache.logging.slf4j.Log4jLoggerFactory.getContext(Log4jLoggerFactory.java:43)
at
org.apache.logging.log4j.spi.AbstractLoggerAdapter.getLogger(AbstractLoggerAdapter.java:42)
at
org.apache.logging.slf4j.Log4jLoggerFactory.getLogger(Log4jLoggerFactory.java:29)
at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:253)
at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:265)
at
org.apache.curator.utils.CloseableExecutorService.<init>(CloseableExecutorService.java:40)
at
org.apache.druid.curator.cache.PathChildrenCacheFactory.make(PathChildrenCacheFactory.java:55)
at
org.apache.druid.curator.inventory.CuratorInventoryManager.start(CuratorInventoryManager.java:109)
at
org.apache.druid.client.AbstractCuratorServerInventoryView.start(AbstractCuratorServerInventoryView.java:168)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at
org.apache.druid.java.util.common.lifecycle.Lifecycle$AnnotationBasedHandler.start(Lifecycle.java:427)
at
org.apache.druid.java.util.common.lifecycle.Lifecycle.start(Lifecycle.java:323)
at org.apache.druid.guice.LifecycleModule$2.start(LifecycleModule.java:138)
at org.apache.druid.cli.GuiceRunnable.initLifecycle(GuiceRunnable.java:107)
at org.apache.druid.cli.ServerRunnable.run(ServerRunnable.java:58)
at org.apache.druid.cli.Main.main(Main.java:118)



On Fri, 8 Feb 2019 at 12:27, Charles Allen <ch...@snap.com.invalid>
wrote:

> Structured logging is not in a very good state in Druid right now (or the
> industry in general). Part of the issue is that the log4j standard json
> format is not very compatible with modern json logging systems. I even
> modified the sumologic appender to get better productionized items into it
> at https://github.com/metamx/sumologic-log4j2-appender . I do not know if
> there is a stackdriver friendly log4j formatter out there, but it would not
> surprise me if there was but it pulled in guava version future+inifnity.
>
> My current log4j2 layout
> <https://logging.apache.org/log4j/2.x/manual/layouts.html#JSONLayout> line
> looks like this:
> <JsonLayout compact="true" eventEol="true" complete="false" properties=
> "true" />
>
> Which is kind of annoying, especially with stack traces which can easily
> overflow a "single line length" in logging infrastructures.
>
> If you ever do find it worth your while to go down the route of writing a
> custom format for your logging system. The easiest way I found was to
> piggyback on the jackson format and just annotate a special class with
> whatever fields in whichever format you want:
>
>
> https://github.com/metamx/sumologic-log4j2-appender/blob/master/src/main/java/com/sumologic/log4j/core/SumoJsonLayout.java#L117-L237
>
>
>
> On Fri, Feb 8, 2019 at 5:22 AM Don Bowman <do...@agilicus.com> wrote:
>
> > I am finding that the logging produced is very complex to manage. I would
> > like to add logstash json_event (
> > https://github.com/logstash/log4j-jsonevent-layout).
> > Any comments before I start?
> >
> > In my environment I'm using fluent-bit, others are using logstash. Its
> > inconvenient to have multi-line log messages, or have to fish through
> > exceptions.
> >
> > Is there any other way to achieve?
> >
> > Some have suggested e.g.
> >
> > log4j.appender.stdout=org.apache.log4j.ConsoleAppender
> > log4j.appender.stdout.encoding=UTF-8
> > log4j.appender.stdout.layout=org.apache.log4j.PatternLayout
> >
> >
> log4j.appender.stdout.layout.ConversionPattern={"level":"%p","timestamp":"%d{ISO8601}","thread":"%t","file":"%F",
> > "line":"%L","message":"%m"}%n
> >
> > but this won't work if there's a quote or newline.
> >
>

Re: json logging enable

Posted by Charles Allen <ch...@snap.com.INVALID>.
Structured logging is not in a very good state in Druid right now (or the
industry in general). Part of the issue is that the log4j standard json
format is not very compatible with modern json logging systems. I even
modified the sumologic appender to get better productionized items into it
at https://github.com/metamx/sumologic-log4j2-appender . I do not know if
there is a stackdriver friendly log4j formatter out there, but it would not
surprise me if there was but it pulled in guava version future+inifnity.

My current log4j2 layout
<https://logging.apache.org/log4j/2.x/manual/layouts.html#JSONLayout> line
looks like this:
<JsonLayout compact="true" eventEol="true" complete="false" properties=
"true" />

Which is kind of annoying, especially with stack traces which can easily
overflow a "single line length" in logging infrastructures.

If you ever do find it worth your while to go down the route of writing a
custom format for your logging system. The easiest way I found was to
piggyback on the jackson format and just annotate a special class with
whatever fields in whichever format you want:

https://github.com/metamx/sumologic-log4j2-appender/blob/master/src/main/java/com/sumologic/log4j/core/SumoJsonLayout.java#L117-L237



On Fri, Feb 8, 2019 at 5:22 AM Don Bowman <do...@agilicus.com> wrote:

> I am finding that the logging produced is very complex to manage. I would
> like to add logstash json_event (
> https://github.com/logstash/log4j-jsonevent-layout).
> Any comments before I start?
>
> In my environment I'm using fluent-bit, others are using logstash. Its
> inconvenient to have multi-line log messages, or have to fish through
> exceptions.
>
> Is there any other way to achieve?
>
> Some have suggested e.g.
>
> log4j.appender.stdout=org.apache.log4j.ConsoleAppender
> log4j.appender.stdout.encoding=UTF-8
> log4j.appender.stdout.layout=org.apache.log4j.PatternLayout
>
> log4j.appender.stdout.layout.ConversionPattern={"level":"%p","timestamp":"%d{ISO8601}","thread":"%t","file":"%F",
> "line":"%L","message":"%m"}%n
>
> but this won't work if there's a quote or newline.
>