Use ByteArrayOutputStream instead of ByteBufferOutputStream to avoid message loss

[vy]

Use ByteArrayOutputStream instead of ByteBufferOutputStream to avoid message loss

[joycgj]

If I understand your comment right... Replacing BBOS with BAOS would violate the garbage-free characteristics of the layout. Putting this detail aside, imagine that the JSON rendering is finalized and just before passing it to the appender you figured out that it violates the upper bound. Independent of whether the violation is measured on byte or char count, you cannot blindly truncate a complete JSON string anymore; hence throwing an exception is your only way out. (Please let me know if I interpret your feedback wrong.)

Further, I am in the process of contributing this project into log4j-core (see [apache/logging-log4j2#335](apache/logging-log4j2#335)). This will deprecate log4j2-logstash-layout; though I will still address bugs, just like I do right now. There I will replace maxByteCount with maxLength, which will be based on char count and I believe to be more intuitive for users.

I am excited when I see you will contribute this project to log4j-core, but when you will finish it, I am expecting the log4j2's new layout.

[vy]

If I understand your comment right... Replacing BBOS with BAOS would violate the garbage-free characteristics of the layout. Putting this detail aside, imagine that the JSON rendering is finalized and just before passing it to the appender you figured out that it violates the upper bound. Independent of whether the violation is measured on byte or char count, you cannot blindly truncate a complete JSON string anymore; hence throwing an exception is your only way out. (Please let me know if I interpret your feedback wrong.)

Further, I am in the process of contributing this project into log4j-core (see apache/logging-log4j2#335). This will deprecate log4j2-logstash-layout; though I will still address bugs, just like I do right now. There I will replace maxByteCount with maxLength, which will be based on char count and I believe to be more intuitive for users.

[waldeinburg]

I'm sorry, I did not consider garbage. And I missed the obvious fact that the OutputStream is for the whole object, not individual values, thus my rambling about maxStringLength.

Would it be possible to implement a retry mechanism with a lower maxStringLength to avoid message loss altogether? I.e., on BufferOverflowException, run the serialization again with half the maxStringLength until success.

[vy]

I have my doubts if such a smart retry mechanism should really be implemented in this plugin. Would you mind sharing your use case, please? In an ideal world, application logs should not indeed be lost. That said, it is difficult come up with a policy for excessive loads. At bol.com, we records statistics for dropped logs. Would that also work for you? Thinking more about it... Maybe we can expose an MXbean to share such statistics in Log4j.

[waldeinburg]

If we hit a database error we get a 22K stacktrace. We also set user input in the MDC which give us the opportunity to search in GrayLog for, e.g., error log messages logged during requests with a certain argument set to a certain value. Though we have turned off input logging for those of our POST methods that we know will receive large inputs, we could theoretically get large input in other methods (let's put validation aside for a minute). This is of course theoretical but ideally I wished I would not have to worry balancing maxStringLength and maxByteCount to get as much data as possible while not allocating too much each time we get the context (the environment is a web application and does thus not run with ENABLE_THREADLOCALS=true).

I guess we could monitor our JBoss server log for BufferOverflowException. I'm not sure i understand your remark about MXBeans; do you use JMX to monitor this exception?

[vy]

Had an epiphany while thinking about your problem and it resulted in something that I am really happy with. In JsonTemplateLayout, the LogstashLayout successor that I am trying to get into Log4j core, I have removed the maxByteCount configuration ‐ now there are just maxStringLength and truncatedStringSuffix. Technically, one can still come up with an explosive ObjectMessage if ${json:message:json} is used in the template, e.g., an array containing 1e6 strings each not exceeding maxStringLength limit. But I believe that is not a surprising outcome given ${json:message:json} is used. In conclusion, I think this setup has better ergonomics and causes less WTF moments for the user.

I am closing the issue. But let me know if you need further assistance.

[waldeinburg]

I have removed the maxByteCount configuration ‐ now there are just maxStringLength and truncatedStringSuffix

That sounds great! I suppose you refer to apache/logging-log4j2@15dd26c
So, as I understand it, we actually get a growing buffer then, because the StringBuilder will raise its internal capacity as needed and never shrink it, even after you call setLength(0). Then we get a growing buffer and garbage freeness.

[vy]

I have removed the maxByteCount configuration ‐ now there are just maxStringLength and truncatedStringSuffix

That sounds great! I suppose you refer to apache/logging-log4j2@15dd26c
So, as I understand it, we actually get a growing buffer then, because the StringBuilder will raise its internal capacity as needed and never shrink it, even after you call setLength(0). Then we get a growing buffer and garbage freeness.

Correct.