Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Add logging to JacksonMapper on writeValueAsBytes error #1237

Closed
StevenPG opened this issue Feb 10, 2025 · 1 comment
Closed

Add logging to JacksonMapper on writeValueAsBytes error #1237

StevenPG opened this issue Feb 10, 2025 · 1 comment
Assignees
Milestone

Comments

@StevenPG
Copy link

Is your feature request related to a problem? Please describe.
When using SmartCompositeMessageConverter in other spring-cloud projects (e.g. Spring Cloud Streams), errors are consumed and hidden by the JacksonMapper when using the JsonMessageConverter.

For example, when sending a NestedRuntimeException through StreamBridge on Spring Cloud Streams, it calls SmartCompositeMessageConverter from the SimpleFunctionRegistry.

The converter that is successfully invoked on NestedRruntimeException is the JsonMessageConverter. It calls JacksonMapper toJson on the outgoing payload.

This results in a InvalidDefinitionException: Direct self-reference leading to cycle (through reference chain: my.app.kafka.ErrorRecord["exception"]->org.springframework.web.server.ResponseStatusException["mostSpecificCause"])

That makes sense based on the NestedRuntimeException potentially including a self reference.
However, the code for JacksonMapper looks like this:

public byte[] toJson(Object value) {
      byte[] jsonBytes = super.toJson(value);
      if (jsonBytes == null) {
          try {
              jsonBytes = this.mapper.writeValueAsBytes(value);
          } catch (Exception var4) {
          }
      }

      return jsonBytes;
  }

Because the exception is empty, it silently fails and continues checking the other converters.

This eventually results in a null being returned from SimpleFunctionRegistry.class

(I understand this may be a Spring Cloud Streams issue from this point forward, but I think the log would be extremely helpful to determine that the issue is a serialization issue within JacksonMapper, rather than stemming from the calling library)

This causes the following result in Spring Cloud Streams

        // ... StreamBridge send method
        Message<?> resultMessage;
        synchronized(this) {
            resultMessage = (Message)functionToInvoke.apply(messageToSend); // this becomes "null"
        }

        ...

        // This throws a NullPointerException deep in postProcessResult due to resultMessage being null
        resultMessage = (Message)this.functionInvocationHelper.postProcessResult(resultMessage, (Object)null);
        return messageChannel.send(resultMessage);

It therefore makes it very hard to tell what the actual issue was within spring-cloud-function.

Either way, the caller will have to simply assume that null means some issue occurred calling a messageConverter, but in lieu of the exception being available, at least seeing it in the log will allow some information to leak to the developer.

This was discovered when sending a Record<String,Exception>() into Spring Cloud Streams, where only SOME exceptions contain the self reference that causes a failure and others do not. Considering this is somewhat deep in the spring-cloud-function converter workflow, it doesn't feel like a developer issue vs an opportunity to expose some additional information.

Using Spring Cloud Stream as a proxy for any caller, it would be beneficial for a debug/trace log to be available in the JacksonMapper.

Describe the solution you'd like
I'd like a debug log with the given exception in JacksonMapper so that developers are able to determine what caused the error (at least in the JacksonMapper) rather than have to debug through the entire call stack to determine the root problem.

public byte[] toJson(Object value) {
      byte[] jsonBytes = super.toJson(value);
      if (jsonBytes == null) {
          try {
              jsonBytes = this.mapper.writeValueAsBytes(value);
          } catch (Exception var4) {
              log.debug("Failed to convert value using " + converter.name() + " with error " + var4.getMessage());
          }
      }

      return jsonBytes;
  }
@olegz
Copy link
Contributor

olegz commented Apr 1, 2025

I am adding TRACE level logging to ensure that it doesn't pollute the logs. We do provide a stack of converters and we attempt to try them all including the once defined by the user, so logging every failure with anything other then TRACE would pollute teh logs

@olegz olegz closed this as completed in dbdc35c Apr 1, 2025
olegz added a commit that referenced this issue Apr 1, 2025
While we expect failures in individual converters and delegate to others in the stack, this enhancement will allow users to enabel TRACE level logging on failures during 'writeValueAsBytes' in JacksonMapper.

Resolves #1237
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

2 participants