Fix issue with Jackson 2.15: Can not write a field name, expecting a value #15564
Conversation
…-jackson-json-log-format-issue
edmocosta
force-pushed
the
fix-jackson-json-log-format-issue
branch
from
9a0fcda to
b5bec56
Compare
edmocosta
changed the title
edmocosta
changed the title
| try (final SegmentedStringWriter entryJsonWriter = new SegmentedStringWriter(new BufferRecycler()); | ||
| final JsonGenerator entryGenerator = LOG4J_JSON_MAPPER.getFactory().createGenerator(entryJsonWriter)) { | ||
| entryGenerator.writeObject(paramValue); | ||
| generator.writeFieldName(paramName); | ||
| generator.writeRawValue(entryJsonWriter.getAndClear()); | ||
| } |
There was a problem hiding this comment.
any thoughts on the performance impact of this change? if isValueSafeToWrite is false frequently then creating a new generator, writer and buffer recycler could get expensive.
There was a problem hiding this comment.
On my local tests (1k fields), It had a minor/same performance impact compared to using only the main generator. I've also tried to reuse the BufferRecycler, but it didn't save many cycles as it needs to invoke the getAndClear() method in every iteration. The SegmentedStringWriter also had similar results to a JDK StringWriter.
| final Object candidate = value.method(RubyString.newString(RubyUtil.RUBY, METHOD_INSPECT)); | ||
| return candidate instanceof RubyMethod && ((RubyMethod) candidate).owner(RubyUtil.RUBY.getCurrentContext()).toString().toLowerCase().startsWith("logstash"); |
There was a problem hiding this comment.
Same as above, do we know if this is costly performance wise when there's a lot of log entries? If necessary we could consider some memoization/caching strategy.
There was a problem hiding this comment.
Yes, invoking JRuby's method demonstrated to be an expensive operation. Unfortunately, I couldn't find any better option here - with the same result - as those objects passed to the logger are dynamically generated/parsed. Memoazing/caching them would also be complex and prone to errors, IMO, as their values are actually coming from methods invocations, which might return different values even if the type is the same, for example.
In terms of overall performance, the CustomLogEventSerializer now uses the LOG4J_JSON_MAPPER to serialize the message parameters. That mapper registers a few JRuby's serializes with a higher priority than this generic one. It should speed up the process by avoiding this generic serializer to be used.
Considering the RubyBasicObjectSerializer is a kind of fallback, and that the current behavior (without this serializer) is going through the whole object hierarchic serializing all fields until it fails. I believe the cost of invoking those methods is considerably smaller.
WDYT? Any suggestions?
|
SonarQube Quality Gate
|
💚 Build Succeeded
History
|
Release notes
Fixed issue with
log.format=jsonand Jackson 2.15: Can not write a field name, expecting a value.What does this PR do?
More details about the issue/ root-cause can be found here.
The
RubyBasicObjectis the super class of the majority of org.jruby.* objects. All subclasses fields inside the org.jruby.* package are not desired on the JSON logs. It does not bring any value to users and increase the log size considerably.This PR creates a new Jackson serializer for the
RubyBasicObject, which is registered with a lower priority, and is used as default for all Ruby objects when no more-specific/priority serializer is registered.This new serializer applies the following logic:
inspectmethod is implemented and owned by the Logstash module will be serialized using that method returned content.to_smethod, falling backto
RubyBasicObject#to_s()andRubyBasicObject#anyToString()in case of errors.Logstash does have a few Jackson serializers already implement for JRuby objects, but they're not being used by Log4j, as it has its own
Log4jJsonObjectMapperimplementation.This PR also creates a new
org.logstash.ObjectMappers.LOG4J_JSON_MAPPER, specific for Log4J, which register the existing Ruby serializers and is used to serialize the StructuredMessage parameters on the CustomLogEventSerializer.java.The
CustomLogEventSerializerwas also changed to create a new Jackson's generator for each message's parameter entry, that way, the main generator is not compromised/invalidated in case any key/value fails to write, fixing the "Can not write a field name, expecting a value" issue.Why is it important/What is the impact to the user?
Checklist
I have made corresponding changes to the documentationI have made corresponding change to the default configuration files (and/or docker env variables)How to test this PR locally
Run Logstash 8.10.x with
bin/logstash --log.format=json.Latest LS version using Jackson > 2.14 should log
Can not write a field name, expecting a valueerrors, printing incomplete log messages.Related issues