Add support for event context lookup evaluation in the `NoSql` appender

[SnobbyVirus1973]

Description

I want to use ConfigurationBuilder to config a NoSqlAppender, but I can`t set additionalFields, My code is:

MongoDb4Provider mongoDb4Provider = MongoDb4Provider.newBuilder()
        .setConnectionStringSource("mongodb://localhost:27017/log.test")
        .build();
NoSqlAppender mongoDbAppenderBuilder = NoSqlAppender.newBuilder()
        .setName("MongoDbAppender")
        .setProvider(mongoDb4Provider)
        .build()

I lookup the source code, and I find NoSqlAppender.Builder class has a private field called "additionalFields", but is has not setter method;

So I use java reflect to set the value, My code is:

MongoDb4Provider mongoDb4Provider = MongoDb4Provider.newBuilder()
        .setConnectionStringSource("mongodb://localhost:27017/log.test")
        .build();
NoSqlAppender.Builder mongoDbAppenderBuilder = NoSqlAppender.newBuilder()
        .setName("MongoDbAppender")
        .setProvider(mongoDb4Provider)
        .setConfiguration(config);
ReflectUtil.setFieldValue(mongoDbAppenderBuilder, "additionalFields", new KeyValuePair[] {
        KeyValuePair.newBuilder().setKey("some_key").setValue("${map:some_key}").build(),
});
NoSqlAppender mongoDbAppender = mongoDbAppenderBuilder.build();

It works. But Map Lookup doesn`t work, My do log code is:

logger.info(new MapMessage(Map.of("some_key", "some_value")));

I expect ${map:some_key} can be resolved to some_value, but I get ${map:some_key} in MongoDB`s field. I tried ${map:some_key} $${map:some_key} %K{some_key} %map{some_key} %MAP{some_key} and none of them worked;

Configuration

Version: 2.23.1

Operating system: Windows 11

JDK: JDK-17-oracle

Forgive my poor English, English is not my native language.

[ppkarwasz]

[FYI: You are not using ConfigurationBuilder, which always returns a complete configuration. You are modifying the existing configuration using the internal builders of Log4j Core. Using these internal builders is more complex and more susceptible to breaking changes in Log4j Core]

@SnobbyVirus1973,

The map lookup always returns null, unless it is evaluated in the context of a log event (i.e. using StrLookup.lookup(LogEvent, String) is used instead of StrLookup.lookup(String)). Currently this only happens:

• for the pattern attribute of PatternLayout,
• for "constant" fields of JsonTemplateLayout,
• for the pattern attribute of the Routes element (used in the Routing Appender).

Therefore lookups like map, sd and event will not work in the additionalFields configuration property.

Although I believe that additionalFields should use a log event context instead of the global one to evaluate runtime lookups, I am not certain which is the best way to do it:

• a simple solution would be to add a LogEvent parameter to the StrSubstitutor call. This will allow $${map:...} to work.
• we can also add support for PatternConverter patterns, which will allow both $${map:...} and %K{...} to work. The latter provides a better performance.

@vy and @garydgregory: what do you think?

[vy]

@SnobbyVirus1973, first of all, (as @ppkarwasz indicated) you are not using ConfigurationBuilder, but instead programmatically creating components using their builders. This approach we strongly discourage and you should be using ConfigurationBuilder instead – we have documented this explicitly in the staging website, which will be available in the next Log4j release.

@SnobbyVirus1973, NoSqlAppender doesn't support lookups in the additional fields. Hence, what you want is not really possible at this stage "out of the box" – that is, you can make it work (by creating your own NoSqlAppender, etc.), but you really would not want to do that, and it should ideally fixed by Log4j.

@ppkarwasz, I am in favor of keeping PatternLayout out of the picture and instead simply allowing lookups in the additional fields of NoSqlAppender. Plugging in PatternLayout drags along a myriad of other complications.

[ppkarwasz]

@SnobbyVirus1973, NoSqlAppender doesn't support lookups in the additional fields. Hence, what you want is not really possible at this stage "out of the box" – that is, you can make it work (by creating your own NoSqlAppender, etc.), but you really would not want to do that, and it should ideally fixed by Log4j.

Yes it does support runtime lookups (see Runtime evaluation of attributes I recently revamped). It just does not pass the log event as argument to StrSubstitutor, so some lookups don't work.

@ppkarwasz, I am in favor of keeping PatternLayout out of the picture and instead simply allowing lookups in the additional fields of NoSqlAppender. Plugging in PatternLayout drags along a myriad of other complications.

After auditing the lookup code, I came to the conclusion that StrLookup might be one of those abstractions we should consider dropping:

• Lookups evaluated at configuration time could simply be replaced by values provided by PropertiesUtil. I doubt users employ at the same time ${sys:MY_VALUE} and ${env:MY_VALUE}. The namespacing of lookups is often source of confusion. ${MY_VALUE} would be simpler.
• Lookups evaluated at runtime make only sense if they depend on the log event. Currently all the lookups that use the data of a log event have an equivalent PatternConverter.

See my recent thread on dev@logging.

I agree that PatternParser is heavier than StrSubstitutor, but PatternParser parses an expression only once. StrSubstitutor parses a value each time it is called.

[vy]

Yes it does support runtime lookups (see Runtime evaluation of attributes I recently revamped). It just does not pass the log event as argument to StrSubstitutor, so some lookups don't work.

Right. Can't we simply receive the LogEvent in NoSqlDatabaseManager#setAdditionalFields() and be done with it?

After auditing the lookup code, I came to the conclusion that StrLookup might be one of those abstractions we should consider dropping

I don't think this is the right place to discuss this.

I agree that PatternParser is heavier than StrSubstitutor, but PatternParser parses an expression only once. StrSubstitutor parses a value each time it is called.

Hrm... You have a point there. Given this, I am fine with both approaches, I don't have a strong preference.

[SnobbyVirus1973]

The reason I code like MongoDb4Provider.newBuilder() is I found something like on Log4j2 Manual.

In my program, I want to implement the following functions:

1. My program is based on SpringBoot.
2. I wrote a core project, and multiple projects in our company will reference my program.
3. Each referenced project can have a log4j2.xml configuration file in the resource directory, or it can have none. If there is no configuration file, I will generate a default log configuration. If a configuration file is written, I will add the configuration in the configuration file to the default configuration.
4. The above default configuration will output logs to the console and disk files. There is another jar package that can output logs to MongoDB. If the project reference this jar package, the default configuration will be modified and MongoDB's Appender will be added.

My current implementation is:

1. In the core project, a Plugin is written@Plugin(name = "ConfigurationFactory", category = ConfigurationFactory.CATEGORY)
2. The getSupportedTypes method of this Plugin returns [".xml", "*"]
3. The getConfiguration method of this Plugin will create an inner class that inherits XmlConfiguration
4. The inner class overrides the doConfigure method, and the code inside is similar to this reference code. The difference is that the location of the configuration file is determined in the doConfigure method. If it is log4j2.xml in the resource directory of the project, super.doConfigure() will be called, otherwise it will not be called.
5. In another jar package, I wrote a class and handed it to Spring for initialization. During the initialization process, the following code is executed

   LoggerContext ctx = (LoggerContext) LogManager.getContext(false);
   Configuration config = ctx.getConfiguration();
   // Append MongoDB's Appender
   ctx.updateLoggers();

   I handed it to Spring for initialization because I wanted to configure the connection address of MongoDB in the application.yml file.

Is there a better way to implement it? Please tell me☺️

Forgive my poor English, English is not my native language.

[vy]

@SnobbyVirus1973, @ppkarwasz, what about the following instead?

1. Ship log4j2-main.xml in the core project
2. Ship log4j2-supplement.xml in the JAR package
3. In the core project, create a ConfigurationFactory such that
   1. It creates Configuration instances using log4j2-main.xml, log4j2-supplement.xml, and log4j2.xml files (if they are present):

      ConfigurationFactory.getInstance().getConfiguration(null, ConfigurationSource.fromUri("..."))

   2. Returns a new CompositeConfiguration(availConfigs)

---

Note that above programmatic approach is identical to the following JVM argument:

-Dlog4j2.configurationFile=log4j2-main.xml,log4j2-supplement.xml,log4j2.xml

If you can influence the JVM arguments while applications get deployed, you can prefer for this log4j2.configurationFile approach too.

[ppkarwasz]

@SnobbyVirus1973,

What @vy suggests is already implemented in Spring Boot through the logging.log4j2.config.override Spring Boot property.

Regarding the best approach to log to a database in Spring Boot, I have created the discussion #2807. I think we should continue there.

[ppkarwasz]

I am removing the waiting-* labels, since I believe we have all the information to deal with the initially reported problem: we evaluate $${...} runtime lookups in the wrong context (global instead of log event) almost everywhere.