BasicBinder Trace Logging Causes Duplicated Message

Description

When binding a parameter that includes the text {} the BasicBinder String.format call will include the value as part of the messagePattern passed to the logger. When using log4j {} is interpreted as a variable to be replaced by a argument, and since no arguments are supplied the entire message is considered to be an argument.

As a result, when a log message should be: binding parameter [2] as [VARCHAR] - [{}]
it ends up getting logged as: binding parameter [2] as [VARCHAR] - [binding parameter [2] as [VARCHAR] - [{}]]

Attachments

1

Activity

Show:

Nathan Xu May 27, 2021 at 5:14 PM

Finally a new version of jboss-logging was released (3.4.2.Final). I created a PR here in Hibernate to bump the dependency minor version:

Nathan Xu October 26, 2020 at 11:20 PM

Finally the jboss-logging PR was merged.

Nathan Xu August 7, 2020 at 7:01 PM

PR created at . Fingers crossed. Once it was merged and published, I am gonna update the dependency version to fix the issue.

Nathan Xu August 7, 2020 at 6:25 PM
Edited

I narrowed down the root cause. It was due to the following bug in the org.jboss.logging:jboss-logging:3.3.2.Final (which is one of the dependencies of Hibernate):

Changing the highlighted pat to this.messageFactory.newMessage(String.valueOf(message)) would fix the bug.

The bug only shows up in log4j2. It seems not an issue for log4j, though.

I am gonna create a PR at soon.

Nathan Xu August 7, 2020 at 8:35 AM

thanks. seems a pretty inspiring exposure of some universal pattern. will try to reproduce the issue to solve it.

Fixed

Details

Assignee

Reporter

Fix versions

Affects versions

Priority

Created August 6, 2020 at 11:26 PM
Updated June 1, 2021 at 2:52 PM
Resolved May 31, 2021 at 12:06 PM