You are viewing a plain text version of this content. The canonical link for it is here.
Posted to notifications@logging.apache.org by "bfreitastgtg (via GitHub)" <gi...@apache.org> on 2024/11/26 13:45:42 UTC

[I] Exception thrown in class annotated with @Plugin that uses a logger (logging-log4j2)

bfreitastgtg opened a new issue, #3240:
URL: https://github.com/apache/logging-log4j2/issues/3240

   ## Description
   
   Trying to use a logger in a class annotated with `@Plugin` from `org.apache.logging.log4j.core.config.plugins` throws an exception. The same problem does not happen on versions 2.23.1, 2.24.0 and 2.24.1.
   
   ## Configuration
   
   **Version:** 2.24.2
   
   **Operating system:** linux
   
   **JDK:** Amazon Correto, 21
   
   ## Logs
   
   ```
   2024-11-26T08:33:59.000998374Z main ERROR Unable to create Lookup for myplugin java.lang.IllegalArgumentException: java.lang.ExceptionInInitializerError
   	at org.apache.logging.log4j.core.util.ReflectionUtil.instantiate(ReflectionUtil.java:192)
   	at org.apache.logging.log4j.core.lookup.Interpolator.<init>(Interpolator.java:90)
   	at org.apache.logging.log4j.core.lookup.Interpolator.<init>(Interpolator.java:109)
   	at org.apache.logging.log4j.core.config.AbstractConfiguration.<init>(AbstractConfiguration.java:137)
   	at org.apache.logging.log4j.core.config.NullConfiguration.<init>(NullConfiguration.java:32)
   	at org.apache.logging.log4j.core.LoggerContext.<clinit>(LoggerContext.java:77)
   	at org.apache.logging.log4j.core.selector.ClassLoaderContextSelector.createContext(ClassLoaderContextSelector.java:265)
   	at org.apache.logging.log4j.core.selector.ClassLoaderContextSelector.locateContext(ClassLoaderContextSelector.java:224)
   	at org.apache.logging.log4j.core.selector.ClassLoaderContextSelector.getContext(ClassLoaderContextSelector.java:142)
   	at org.apache.logging.log4j.core.selector.ClassLoaderContextSelector.getContext(ClassLoaderContextSelector.java:125)
   	at org.apache.logging.log4j.core.selector.ClassLoaderContextSelector.getContext(ClassLoaderContextSelector.java:119)
   	at org.apache.logging.log4j.core.impl.Log4jContextFactory.getContext(Log4jContextFactory.java:148)
   	at org.apache.logging.log4j.core.impl.Log4jContextFactory.getContext(Log4jContextFactory.java:46)
   	at org.apache.logging.log4j.LogManager.getContext(LogManager.java:138)
   	at org.apache.logging.log4j.spi.AbstractLoggerAdapter.getContext(AbstractLoggerAdapter.java:136)
   	at org.apache.logging.slf4j.Log4jLoggerFactory.getContext(Log4jLoggerFactory.java:58)
   	at org.apache.logging.log4j.spi.AbstractLoggerAdapter.getLogger(AbstractLoggerAdapter.java:46)
   	at org.apache.logging.slf4j.Log4jLoggerFactory.getLogger(Log4jLoggerFactory.java:32)
   	at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:432)
   	at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:457)
           (...)
   Caused by: java.lang.ExceptionInInitializerError
   	at java.base/jdk.internal.misc.Unsafe.ensureClassInitialized0(Native Method)
   	at java.base/jdk.internal.misc.Unsafe.ensureClassInitialized(Unsafe.java:1160)
   	at java.base/jdk.internal.reflect.MethodHandleAccessorFactory.ensureClassInitialized(MethodHandleAccessorFactory.java:300)
   	at java.base/jdk.internal.reflect.MethodHandleAccessorFactory.newConstructorAccessor(MethodHandleAccessorFactory.java:103)
   	at java.base/jdk.internal.reflect.ReflectionFactory.newConstructorAccessor(ReflectionFactory.java:200)
   	at java.base/java.lang.reflect.Constructor.acquireConstructorAccessor(Constructor.java:549)
   	at java.base/java.lang.reflect.Constructor.newInstanceWithCaller(Constructor.java:499)
   	at java.base/java.lang.reflect.Constructor.newInstance(Constructor.java:486)
   	at org.apache.logging.log4j.core.util.ReflectionUtil.instantiate(ReflectionUtil.java:188)
   	... 20 more
   Caused by: java.lang.NullPointerException: messageFactory
   	at java.base/java.util.Objects.requireNonNull(Objects.java:259)
   	at org.apache.logging.log4j.core.util.internal.InternalLoggerRegistry.computeIfAbsent(InternalLoggerRegistry.java:135)
   	at org.apache.logging.log4j.core.LoggerContext.getLogger(LoggerContext.java:530)
   	at org.apache.logging.log4j.core.LoggerContext.getLogger(LoggerContext.java:503)
   	at org.apache.logging.log4j.core.LoggerContext.getLogger(LoggerContext.java:65)
   	at org.apache.logging.slf4j.Log4jLoggerFactory.newLogger(Log4jLoggerFactory.java:49)
   	at org.apache.logging.slf4j.Log4jLoggerFactory.newLogger(Log4jLoggerFactory.java:32)
   	at org.apache.logging.log4j.spi.AbstractLoggerAdapter.getLogger(AbstractLoggerAdapter.java:52)
   	at org.apache.logging.slf4j.Log4jLoggerFactory.getLogger(Log4jLoggerFactory.java:32)
   	at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:432)
   	at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:457)
   	(...)
   	... 29 more
   ```
   
   ## Reproduction
   The code below used to run fine, then after upgrading to 2.24.2 it started throwing on application startup. Getting rid of the `LOGGER` variable "fixes" the problem. 
   ```
   import org.apache.logging.log4j.core.LogEvent;
   import org.apache.logging.log4j.core.config.plugins.Plugin;
   import org.apache.logging.log4j.core.lookup.StrLookup;
   import org.slf4j.Logger;
   import org.slf4j.LoggerFactory;
   
   @Plugin(name = "MyPlugin", category = StrLookup.CATEGORY)
   public class MyPlugin implements StrLookup {
     private static final Logger LOGGER = LoggerFactory.getLogger(MyPlugin.class);
   
     static {
       LOGGER.info("Log stuff");
     }
   
     @Override
     public String lookup(String key) {
       return "";
     }
   
     @Override
     public String lookup(LogEvent event, String key) {
       return "";
     }
   }
   ```
   


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: notifications-unsubscribe@logging.apache.org.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org


Re: [I] Exception thrown in class annotated with @Plugin that uses a logger (logging-log4j2)

Posted by "ppkarwasz (via GitHub)" <gi...@apache.org>.
ppkarwasz commented on issue #3240:
URL: https://github.com/apache/logging-log4j2/issues/3240#issuecomment-2501263468

   @bfreitastgtg,
   
   Thanks for reporting it. Log4j loads all annotated implementations of `StrLookup` in the static initialization of `LoggerContext`. When you class requests the logger, `LoggerContext` is not completely initialized. You will get all sorts of NPEs in this case.
   
   There is a special logger (see [Status Logger](https://logging.apache.org/log4j/2.x/manual/status-logger.html)) that you can use in Log4j Plugins, but you **should** not use loggers obtained from `LogManager` or some foreign logging API bridged to Log4j API.


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: notifications-unsubscribe@logging.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org


Re: [I] Exception thrown in class annotated with @Plugin that uses a logger (logging-log4j2)

Posted by "bfreitastgtg (via GitHub)" <gi...@apache.org>.
bfreitastgtg commented on issue #3240:
URL: https://github.com/apache/logging-log4j2/issues/3240#issuecomment-2503466956

   Hey @ppkarwasz , thanks for the quick reply. I tested and using a `StatusLogger` worked, but the question remains: why we suddenly needed to use it? As mentioned in the description, using a regular logger worked fine before `2.24.2`.


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: notifications-unsubscribe@logging.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org


Re: [I] Exception thrown in class annotated with @Plugin that uses a logger (logging-log4j2)

Posted by "ppkarwasz (via GitHub)" <gi...@apache.org>.
ppkarwasz commented on issue #3240:
URL: https://github.com/apache/logging-log4j2/issues/3240#issuecomment-2503683841

   > Hey @ppkarwasz , thanks for the quick reply. I tested and using a `StatusLogger` worked, but the question remains: why we suddenly needed to use it? As mentioned in the description, using a regular logger worked fine before `2.24.2`.
   
   The problem you are encountering is due to the `DEFAULT_MESSAGE_FACTORY` field being uninitialized (so `null`).
   Up to Log4j 2.22.x, that field was in the Log4j API (its classes are initialized before `LoggerContext`) and was initialized using reflection and a configuration property specific to Log4j 2 ([the `log4j2.messageFactory` property](https://logging.apache.org/log4j/2.x/manual/systemproperties.html#log4j2.messageFactory)). That solution is no longer viable:
   
   - It is not extensible. Since the release of `2.24.0`, Log4j Core 3 is based on the same version of Log4j API as Log4j Core 2 (see [documentation](https://logging.apache.org/log4j/3.x/manual/api.html)), but uses dependency injection for many services (including `MessageFactory`).
   - It causes problems for GraalVM, since we would need to register with GraalVM all possible `MessageFactory` implementations in advance.
   - It causes other initialization problems: since 2.23.x `StatusLogger` uses `AbstractLogger`, but is initialized **before** `PropertiesUtil`, which is used to determine the right `MessageFactory`.
   
   These are the main reasons we moved the initialization of the default message factory at a later stage.
   
   **Note**: we can easily fix the initialization problem, by moving `DEFAULT_MESSAGE_FACTORY` at the top of the `LoggerContext` class, but I have mixed feeling about this approach:
   
   - I don't think it is needed. Using any `o.a.l.l.Logger` other than `o.a.l.l.status.StatusLogger` in a Log4j Core Plugin class is IMHO bad practice. Using an `org.slf4j.Logger` in such a class is even less recommended.
   - The real problem is elsewhere: the `DefaultConfiguration` and `NullConfiguration` implementations used by `LoggerContext` before and after the real configuration is loaded, should probably be pretty minimal and should not require lookups and other advanced services, since they are basically **immutable**. We should probably go in this direction, but this might require breaking changes, which are not allowed in 2.x.


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: notifications-unsubscribe@logging.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org


Re: [I] Exception thrown in class annotated with @Plugin that uses a logger [logging-log4j2]

Posted by "ppkarwasz (via GitHub)" <gi...@apache.org>.
ppkarwasz closed issue #3240: Exception thrown in class annotated with @Plugin that uses a logger
URL: https://github.com/apache/logging-log4j2/issues/3240


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: notifications-unsubscribe@logging.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org