See https://cwiki.apache.org/confluence/display/LOGGING/Logging+to+ELK
<https://cwiki.apache.org/confluence/display/LOGGING/Logging+to+ELK>. This is
what I get when using the Layout and configuration in Logging in the Cloud.
Ralph
> On May 17, 2020, at 4:18 PM, Ralph Goers <ralph.go...@dslextreme.com> wrote:
>
>
>
>> On May 17, 2020, at 2:37 PM, Volkan Yazıcı <volkan.yaz...@gmail.com> wrote:
>>
>> 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.)
>
> The problem here is that I want newlines in the message. I’m not sure what
> firstNonNull means in the context of a message. The message itself won’t have
> nulls. The Gelf format dictates the null is at the end of the JSON string.
>
>>
>> 2. How about introducing a fallback parameter to the "message"
>> directive: ${json:message:fallback=exception:message}.
>
> Again, I don’t know what that means or how it solves my problem of wanting
> newlines in the 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?
>
> Picture how a log event looks in a file with a “standard” PatternLayout. In
> Kibana by default you get 3 columns, the timestamp, a field I don’t care
> about and the message. I want the message to appear just as it would in a log
> file without the timestamp. Yes, I can click on each message and see its
> attributes, but that takes longer. And I want exceptions to jump out at me
> when I am visually scrolling through messages. In fact, I typically don’t
> want the stack trace in a variable of its own. Kibana doesn’t take the
> pieces of the message and put them together like the pattern layout does.
> Instead it lets you create columns for individual attributes. The problem
> with that is the columns waste a lot of space, especially if they frequently
> are empty as a stack trace would be.
>
> So yes, I really need it.
>
>>
>>> 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?
>
> The way I do it is to install Logstash, ElasticSearch and Kibana locally on
> my Mac as well as Docker Desktop for Mac. I then run SpringCloud config
> server from the Log4j Spring Cloud Config project and tailor the log4j2.xml
> that is in the config-repo directory of that project. Note that all Log4j
> Lookup variables have to have the $ escaped or Spring Cloud Config will try
> to resolve them. It also requires having the Socket appender connect to a
> host of “host.docker.internal” to be able to connect to Logstash outside of
> the docker container. I configure Logstash using the configuration documented
> at http://logging.apache.org/log4j/2.x/manual/cloud.html
> <http://logging.apache.org/log4j/2.x/manual/cloud.html>
> <http://logging.apache.org/log4j/2.x/manual/cloud.html
> <http://logging.apache.org/log4j/2.x/manual/cloud.html>>, at least when using
> Gelf. I configure Kibana with an index of app-*.
>
> I then modifythe Spring Cloud Config Sample app as needed to work with this
> setup and start it using docker/restartApp.sh.
>
> After starting I do a few things:
> 1. Enter “docker logs app-container”. This should show it is running and the
> last message will be the Spring logo.
> 2. Look in Kibana and click on the logs. You should see logs from the server.
> 3. In a browser enter http://localhost:8080/sample/exception
> <http://localhost:8080/sample/exception>
> <http://localhost:8080/sample/exception
> <http://localhost:8080/sample/exception>> - unless you have changed the port.
> For some reason I had something running on 8080 and had to change the sample
> app to use 8090. This will generate a stack trace on the web page and in the
> log.
> 4. Look in Kibana. You should see the exception and the stack trace properly
> formatted in the message column. It should also display the thread id,
> log-level and other items configured in the pattern.
>
>>
>>> 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?
>
> No - I just know that Logstash wasn’t detecting the null. It looked like the
> whole string was being escaped as all the double quotes were also escaped as
> you can see from the example. I should note that I directly copied that from
> the Logstash log that was written to the terminal window with debug logging
> enabled, so it is possible it was caused by that, but this is also what I see
> in Kibana.
>
>>
>>> 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?
>
> I would have preferred a syntax like
>
> {
> “version” “1.1”,
> …
> ${json.map:mdc:prefix=“_”}
> }
>
> This would cause the whole map to be emitted. Although it would be nice to
> have a version of that which also could specify the keys there probably isn’t
> a point to that since you can directly specify them as you have shown.
>
>
> As I said previously, now that I understand what is going on I am comfortable
> with you merging the PR. It is going to the master branch so it won’t be what
> users see on the web site right now. By the time it makes it there we can get
> this all straightened out. If nothing else we could have the current
> GelfLayout and the JsonTemplateLayout both on the page and explain the
> differences between them, although in the end I agree it would be better to
> have the JsonTemplateLayout replace both the JsonLayout and GelfLayout.
>
> Ralph
>
>>
>> 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
