Thanks so much for the thorough review Ralph, really appreciated! I
will address issues you have raised.
[As a side note, I have pushed changes containing performance
improvements and benchmark results. The module is still dependency
free and performance-wise pretty good.]
> all the default templates separate the message from the exception
Yes, this I have also realized while studying the source code of
GelfLayout. Some random thoughts:
1. How about introducing a firstNonNull-like operator:
${json:op:firstNonNull:${json:message},${json:exception:message}}.
Parsing this would not be trivial, given the list of variables
can include comma in various forms. Though the rest should
be tractable. (Feels like JsonTemplateLayout directives will at
some point catch up the with ones in PatternLayout.)
2. How about introducing a fallback parameter to the "message"
directive: ${json:message:fallback=exception:message}.
3. May I challenge the request: Do one really need it? You store
individual values, i.e, message and exception, in individual fields.
When one is missing and the other is present, isn't it just a
presentation layer issue to display it properly?
> In the logged event all newlines seem to be stripped from the exception.
I really don't get this Ralph. Have you seen the tests in LogstashIT?
I have just added a new one testing only newlines. Would you mind
fiddling around with LogstashIT to reproduce the issue, please? Or
sharing a recipe for me to reproduce it?
> Logstash does not seem to be getting a null character
> (I tried with both “\0” and “\u0000”)
This is weird. Below is how GelfLayout does it:
if (includeNullDelimiter) {
builder.append('\0');
}
And here is how JsonTemplateLayout does it:
stringBuilder.append(eventDelimiter);
Further, there is even a test for this:
JsonTemplateLayout#test_null_eventDelimiter():
final String serializedLogEvent = layout.toSerializable(logEvent);
assertThat(serializedLogEvent).isEqualTo(eventTemplate + '\0');
Any ideas on what might I be missing?
> This isn’t valid in the Gelf spec as additional attributes in Gelf
> must match the regex - ^[\w\.\-]*$. This means you need to
> parse the MDC and add each key as an additional to be able
> to create valid Gelf. Personally, I’d like that option anyway.
For this purpose, I need to introduce an operator similar to
unquote-splicing in Lisp to merge the contents of the child with the
parent. That said, I have my doubts about the practical benefit of
such a feature. To the best of my knowledge, almost every (sanely
configured?) log pipeline ends up with a structured storage system
containing whitelisted fields. Consider ELK stack. Would you allow
developers to introduce fields at their will? If so, it is a matter of
time somebody will take down the entire Elasticsearch cluster by
flooding it with ContextData.put(userInput, "doh"). Hence, you employ
the identical whitelisting strategy at the layout as well:
{
"version": "1.1",
"host": "${hostName}",
...,
"_mdc.loginId": "${json:mdc:loginId}",
"_mdc.requestId": "${json:mdc:requestId}"
}
What do you think? Shall we really introduce unquote-splicing?
Kind regards.
On Sat, May 16, 2020 at 1:28 AM Ralph Goers <ralph.go...@dslextreme.com> wrote:
>
> I finally got time to spend looking at the Layout. I now understand why it
> works for you and sort of understand why it doesn’t work for me.
>
> First, all the default templates separate the message from the exception. In
> the logged event all newlines seem to be stripped from the exception. This
> makes viewing them in Kibana pretty awful, but the do get logged successfully.
>
> To include newlines in a log event you either have to play games in Logstash
> (or Fluentd) and try to put the event back together again after it has been
> separated into multiple lines or you have to use a different delimiter. Gelf
> specifies that a null character be used.
>
> I then tried to use GelfLayout.json with
>
> <Socket name="Logstash"
> host="\${sys:logstash.host:-host.docker.internal}"
> port="12222"
> protocol="tcp"
> bufferedIo="true">
> <JsonTemplateLayout eventTemplateUri="classpath:GelfLayout.json"
> eventDelimiter="\0"
> locationInfoEnabled="true">
> <EventTemplateAdditionalFields>
> <KeyValuePair key="hostName" value="${hostName}"/>
> <KeyValuePair key="_containerId" value="\${docker:containerId:-}"/>
> <KeyValuePair key="_application"
> value="$\${lower:\${spring:spring.application.name:-spring}}"/>
> </EventTemplateAdditionalFields>
> </JsonTemplateLayout>
> </Socket>
> but this did not work at all. Logstash does not seem to be getting a null
> character (I tried with both “\0” and “\u0000”) and all the events buffer in
> Logstash until I shutdown the application. Worse the formatting looks like
> escaped JSON rather than raw json.
>
> Also, the GelfTemplate contains
> {
> "version": "1.1",
> "host": "${hostName}",
> "short_message": "${json:message}",
> "full_message": "${json:exception:stackTrace:text}",
> "timestamp": "${json:timestamp:epoch:secs}",
> "level": "${json:level:severity:code}",
> "_logger": "${json:logger:name}",
> "_thread": "${json:thread:name}",
> "_mdc": "${json:mdc}"
> }
> This causes the output to contain
>
> \\\"_mdc\\\":{\\\"loginId\\\":\\\"rgoers\\\",\\\"requestId\\\":\\\"266196c1-9702-11ea-9e4a-0242ac120006\\\"}
>
> This isn’t valid in the Gelf spec as additional attributes in Gelf must match
> the regex - ^[\w\.\-]*$. This means you need to parse the MDC and add each
> key as an additional to be able to create valid Gelf. Personally, I’d like
> that option anyway.
>
> I would suggest you attempt to work to make a template that matches the
> result of the GelfLayout I had previously documented.
>
> But now that I understand what is going on I am OK with this contribution
> being merged. I would like to get these issues addressed and update the
> Logging in the Cloud documentation so that it can document both ways of
> sending to Logstash but we can do that after the code is merged.
>
> Ralph
>
>
>
>
>
> > On Apr 21, 2020, at 2:23 PM, Ralph Goers <ralph.go...@dslextreme.com> wrote:
> >
> > Ok. Now that a release has been cut spending time with your contribution is
> > at the top of my list.
> >
> > Ralph
> >
> >> On Apr 21, 2020, at 1:24 PM, Volkan Yazıcı <volkan.yaz...@gmail.com> wrote:
> >>
> >> Ralph, I've just pushed a commit that adds PatternLayout support, FYI.
> >>
> >> On Mon, Apr 20, 2020 at 2:08 AM Ralph Goers <ralph.go...@dslextreme.com>
> >> wrote:
> >>>
> >>> I completely understand how messed up people’s lives are right now. I’m
> >>> lucky, all my kids are long gone out of the house. With COVID-19 I am
> >>> able to work from home and while that saves me over 2 hours a day in
> >>> commute time and more time because there isn’t much else to do, I end up
> >>> spending a lot of the extra time on my $dayjob (and feel lucky I still
> >>> have it).
> >>>
> >>> 1. You should care about the checkstyle errors as much as everyone else
> >>> ;-). They don’t seem to be a high priority for people to fix.
> >>>
> >>> 2. Maybe I didn’t make my need for the Pattern Layout clear. Adding the
> >>> pattern layout for the JTL is ONLY for the message attribute (just as I
> >>> did for the GelfLayout). This allows what is displayed in Kibana to look
> >>> like what you would see in the log file while still allowing filtering on
> >>> all the attributes. For me, this is a big deal - I won’t use the Layout
> >>> without it. That doesn’t mean it has to be included in the initial
> >>> commit. I don’t believe JsonLayout supports it either but I am hoping to
> >>> be able to do that today, although I have several other things I need to
> >>> do. What you would end up with is a new attribute called messagePattern
> >>> that takes a pattern that is exactly what you would give to PatternLayout.
> >>>
> >>> 3. You can handle the performance issue however you want but if it was me
> >>> I would just revert back to using Jackson without a second thought. I
> >>> just don’t see the point of trying to roll your own.
> >>>
> >>> 4. It will take me a while to see what your integration test does and if
> >>> it resolves my concerns regarding updating the logging in the cloud page.
> >>>
> >>> Ralph
> >>>
> >>>
> >>>
> >>>
> >>>> On Apr 19, 2020, at 2:30 PM, Volkan Yazıcı <volkan.yaz...@gmail.com>
> >>>> wrote:
> >>>>
> >>>> Hello Ralph,
> >>>>
> >>>> [Due to #COVID-19, day cares are closed. I can hardly spare time to
> >>>> work, including Log4j. Hence, apologies for my slowed down progress &
> >>>> responses.]
> >>>>
> >>>> I could not put my finger on the performance regression, yet. I might
> >>>> opt to switch back to Jackson, but I am not gonna do that without
> >>>> spotting that darn pain in the back. (You might have noticed, there is
> >>>> actually a class for generating a report out of the available
> >>>> JSON-emitting layouts. I will skip incorporating its output into the
> >>>> manually until I address this performance regression.)
> >>>>
> >>>> I've just pushed a commit, i.e., LogstashIT, which tests
> >>>> JsonTemplateLayout against ELK stack. Would you mind skimming through
> >>>> that (small) change, please?
> >>>>
> >>>> I am not inclined to incorporate PatternLayout (PL) into
> >>>> JsonTemplateLayout (JTL). JTL is supposed to (ideally) deliver all the
> >>>> functionality provided by PL but in a structured format, i.e., JSON.
> >>>> If there arises a need to fallback to PL, I'd rather add that missing
> >>>> functionality to JTL.
> >>>>
> >>>> You've mentioned about the checkstyle errors. How much shall I be
> >>>> concerned about them? (It even complains about missing JavaDocs on
> >>>> class fields.) Are there any particular ones you want me to address?
> >>>>
> >>>> Besides these... I think I am done.
> >>>>
> >>>> Kind regards.
> >>>>
> >>>> On Thu, Apr 16, 2020 at 10:49 PM Ralph Goers
> >>>> <ralph.go...@dslextreme.com> wrote:
> >>>>>
> >>>>> Volkan,
> >>>>>
> >>>>> I’m just wondering if you have had a chance to get to this. As I said,
> >>>>> as far as I am concerned this is the only thing getting in the way of
> >>>>> merging the PR. If you would prefer you can just remove the update to
> >>>>> the “Logging in the Cloud” page and push the rest and then update that
> >>>>> page after you have the testing done.
> >>>>>
> >>>>> Ralph
> >>>>>
> >>>>>> On Apr 12, 2020, at 12:01 AM, Ralph Goers <ralph.go...@dslextreme.com>
> >>>>>> wrote:
> >>>>>>
> >>>>>> I think I said this before, but I see no reason you can’t have a
> >>>>>> dependency on Jackson. We currently do for almost all of our JSON
> >>>>>> processing. I wouldn’t spend any more time trying to improve the
> >>>>>> performance of your custom support, especially since - as I recall -
> >>>>>> you had to drop support of a feature because it was hard to implement.
> >>>>>>
> >>>>>> As for replacing JsonLayout and GelfLayout, I would envision that
> >>>>>> those would continue to exist for backwards compatibility but would
> >>>>>> simply pass their configuration too JsonTemplateLayout.
> >>>>>>
> >>>>>> As for moving JSON out of core, we may end up doing that. I am pretty
> >>>>>> sure the xml support will require a dependency on the java.xml module
> >>>>>> so either that will move out of core or we will have a transitive
> >>>>>> dependency on it. Whichever way we go with that I would expect would
> >>>>>> be the same with Json and Yaml.
> >>>>>>
> >>>>>> Adding support for formatting the message with the PatternLayout was
> >>>>>> pretty trivial. I would prefer to continue to have that in the example
> >>>>>> so I would hope it could be added if the example changes.
> >>>>>>
> >>>>>> As I said, the issue is Logstash or Fluentd and how they process
> >>>>>> messages. Adding the null terminator in the configuration would make
> >>>>>> it work on the log4j side as long as you left the logstash
> >>>>>> configuration alone. My devops team has tried everything they can
> >>>>>> think of to get exceptions to work and this was the only thing that
> >>>>>> did without having to invent convoluted parsing rules. But yet, before
> >>>>>> we publish that I would need to know it had been tested all the way to
> >>>>>> Kibana. It was pretty easy for me to set it all up in docker
> >>>>>> containers. I think the log4j-spring-cloud-sample project has
> >>>>>> reference to the docker setup I used.
> >>>>>>
> >>>>>> Ralph
> >>>>>>
> >>>>>>
> >>>>>>
> >>>>>>> On Apr 11, 2020, at 11:23 PM, Volkan Yazıcı <volkan.yaz...@gmail.com>
> >>>>>>> wrote:
> >>>>>>>
> >>>>>>> Hey Ralph,
> >>>>>>>
> >>>>>>> Thanks so much for taking time to review such a lengthy PR, much
> >>>>>>> appreciated. Let me try to address your concerns and share some of
> >>>>>>> mine:
> >>>>>>>
> >>>>>>> Does JTL (i.e., JsonTemplateLayout) support Logstash? I've tried it
> >>>>>>> locally against an actually running Logstash instance and it has
> >>>>>>> worked fine. Though I did not test newlines. I will do that. In any
> >>>>>>> case, AFAIC, JTL should also support null-termination via
> >>>>>>> eventDelimiter="\u0000" configuration. Nevertheless, I will try both
> >>>>>>> and report the outcome. (I wish we would support Docker in ITs to
> >>>>>>> allow tests against such external services, rather than us doing that
> >>>>>>> manually.)
> >>>>>>>
> >>>>>>> Does "message" directive in JTL support patterns ala PatternLayout?
> >>>>>>> No, but it is on my TODO list.
> >>>>>>>
> >>>>>>> Can one extend the existing JTL template resolvers, i.e.,
> >>>>>>> EventResolverFactories? [I've extracted this remark from your most
> >>>>>>> recent GitHub comment.] No, but sounds like a great idea! This is not
> >>>>>>> a necessity for the first release (as you also have stated), but I
> >>>>>>> will see what I can do about it.
> >>>>>>>
> >>>>>>> Right now I am busy with a performance regression. After replacing the
> >>>>>>> Jackson JsonGenerator with the in-house JsonWriter, I've observed a
> >>>>>>> ~2x performance degradation. I've been busy with it for almost a
> >>>>>>> month, but it is really difficult to spare time for it due to
> >>>>>>> full-time parenting enforced by closed day cares. I do not want to
> >>>>>>> have a release before fixing this issue.
> >>>>>>>
> >>>>>>> I can imagine at some point 2.x will ship 3 contending JSON layouts:
> >>>>>>> GelfLayout, JsonLayout, and JsonTemplateLayout. That said, for 3.x I
> >>>>>>> suggest to deprecate (maybe even remove?) the former two. Personally,
> >>>>>>> as a developer, what I find most confusing is a library providing
> >>>>>>> multiple solutions for the same problem without much tangible benefit
> >>>>>>> between each other. I would rather strain from that dilemma in a
> >>>>>>> library that I contribute to.
> >>>>>>>
> >>>>>>> Speaking of 3.x enhancements I have in mind, I am in favor of removing
> >>>>>>> all JSON logic (i.e., escaping/quoting routines) out of core module.
> >>>>>>> As a motivation, see my earlier post regarding discrepancies between
> >>>>>>> multiple JSON quoting methods. Further, many (incl. you) also have
> >>>>>>> stated their concerns about the size of "core". I don't think a logger
> >>>>>>> should ship JSON encoders, decoders, and such. Though I did not
> >>>>>>> investigate this issue in detail, that is, what are the existing
> >>>>>>> dependencies, etc. Nevertheless, I wanted to raise this point.
> >>>>>>>
> >>>>>>> Kind regards.
> >>>>>>>
> >>>>>>>
> >>>>>>> On Sat, Apr 11, 2020 at 11:22 PM Ralph Goers
> >>>>>>> <ralph.go...@dslextreme.com> wrote:
> >>>>>>>>
> >>>>>>>> Volkan,
> >>>>>>>>
> >>>>>>>> I have looked at the PR and the only remaining thing I have an issue
> >>>>>>>> with are the changes you made to the logging in the cloud
> >>>>>>>> documentation. In my testing, only the Gelf Layout worked properly
> >>>>>>>> with an ELK stack. This is because Logstash (as well as Fluentd) are
> >>>>>>>> parsing the input trying to figure out where each log event begins
> >>>>>>>> and ends. They typically do that using some sort of pattern but by
> >>>>>>>> default look for newlines. This will cause log events that contain
> >>>>>>>> exceptions, which inherently include newlines) or other events that
> >>>>>>>> include newlines in the message to be broken into multiple lines in
> >>>>>>>> Kibana and make it impossible to filter on them properly.
> >>>>>>>>
> >>>>>>>> Have you tested the changes you have made to the documentation with
> >>>>>>>> a full ELK stack and verified that all log events, including events
> >>>>>>>> with exceptions, are displayed correctly?
> >>>>>>>>
> >>>>>>>> Also, you will notice that the Gelf Layout includes a MessagePattern
> >>>>>>>> attribute that allows the message element to be formatted using the
> >>>>>>>> PatternLayout. Does the Json Template Layout support that? I don’t
> >>>>>>>> see examples of that in any of the template files if it does. If it
> >>>>>>>> does not, that is another reason I would prefer leaving the page as
> >>>>>>>> is for now.
> >>>>>>>>
> >>>>>>>> Ralph
> >>>>>>>
> >>>>>>
> >>>>>>
> >>>>>>
> >>>>>
> >>>>>
> >>>>
> >>>
> >>>
> >>
> >
> >
> >
>
