Giter Club home page Giter Club logo

Comments (7)

wilkinsona avatar wilkinsona commented on May 10, 2024 2

@rlratcliffe Here's a hack that gets restarts working again with Log4j2 3.0 beta 1:

    public static void main(String[] args) {
    	SpringApplication app = new SpringApplication(CamelApplication.class);
    	app.addListeners(new ApplicationListener<ContextClosedEvent>() {

			@Override
			public void onApplicationEvent(ContextClosedEvent event) {
				PropertiesUtil properties = PropertiesUtil.getProperties();
				try {
					Field environmentField = properties.getClass().getDeclaredField("environment");
					environmentField.setAccessible(true);
					Object environment = environmentField.get(properties);
					Field sourcesField = environment.getClass().getDeclaredField("sources");
					sourcesField.setAccessible(true);
					@SuppressWarnings("unchecked")
					Set<PropertySource> sources = (Set<PropertySource>) sourcesField.get(environment);
					Iterator<PropertySource> iterator = sources.iterator();
					while (iterator.hasNext()) {
						PropertySource candidate = iterator.next();
						if ("org.springframework.boot.logging.log4j2.SpringEnvironmentPropertySource".equals(candidate.getClass().getName())) {
							iterator.remove();
							System.out.println("Removed " + candidate);
						}
					}
				}
				catch (Exception ex) {
					ex.printStackTrace();
				}
			}
    		
    	});
    	app.run(args);
    }

This will be much more elegant once removePropertySource is available to some code that can keep track of the SpringEnvironmentPropertySource instance that needs to be removed.

from spring-boot.

wilkinsona avatar wilkinsona commented on May 10, 2024

Thanks for the sample. With commit ca981de8, the restart appears to be getting stuck here:

"restartedMain" #72 prio=5 os_prio=31 cpu=102720.08ms elapsed=103.39s tid=0x00007fc7c8810600 nid=0xb60f runnable  [0x000070000627c000]
   java.lang.Thread.State: RUNNABLE
	at java.lang.StackTraceElement.initStackTraceElements([email protected]/Native Method)
	at java.lang.StackTraceElement.of([email protected]/StackTraceElement.java:541)
	at java.lang.Throwable.getOurStackTrace([email protected]/Throwable.java:839)
	- locked <0x00000006084b9668> (a java.lang.IllegalStateException)
	at java.lang.Throwable.getStackTrace([email protected]/Throwable.java:831)
	at io.undertow.servlet.UndertowServletLogger_$logger._copyStackTraceMinusOne(UndertowServletLogger_$logger.java:120)
	at io.undertow.servlet.UndertowServletLogger_$logger.contextDestroyed(UndertowServletLogger_$logger.java:184)
	at io.undertow.servlet.spec.ServletContextImpl.getDeploymentInfo(ServletContextImpl.java:210)
	at io.undertow.servlet.spec.ServletContextImpl.getInitParameter(ServletContextImpl.java:429)
	at org.springframework.web.context.support.ServletContextPropertySource.getProperty(ServletContextPropertySource.java:47)
	at org.springframework.web.context.support.ServletContextPropertySource.getProperty(ServletContextPropertySource.java:33)
	at org.springframework.core.env.PropertySourcesPropertyResolver.getProperty(PropertySourcesPropertyResolver.java:85)
	at org.springframework.boot.context.properties.source.ConfigurationPropertySourcesPropertyResolver$DefaultResolver.getProperty(ConfigurationPropertySourcesPropertyResolver.java:125)
	at org.springframework.boot.context.properties.source.ConfigurationPropertySourcesPropertyResolver.findPropertyValue(ConfigurationPropertySourcesPropertyResolver.java:99)
	at org.springframework.boot.context.properties.source.ConfigurationPropertySourcesPropertyResolver.getProperty(ConfigurationPropertySourcesPropertyResolver.java:75)
	at org.springframework.boot.context.properties.source.ConfigurationPropertySourcesPropertyResolver.getProperty(ConfigurationPropertySourcesPropertyResolver.java:61)
	at org.springframework.core.env.AbstractEnvironment.getProperty(AbstractEnvironment.java:552)
	at org.springframework.boot.logging.log4j2.SpringEnvironmentPropertySource.getProperty(SpringEnvironmentPropertySource.java:50)
	at org.apache.logging.log4j.util.PropertiesUtil$Environment.sourceGetProperty(PropertiesUtil.java:771)
	at org.apache.logging.log4j.util.PropertiesUtil$Environment.getStringProperty(PropertiesUtil.java:752)
	at org.apache.logging.log4j.util.PropertiesUtil.getStringProperty(PropertiesUtil.java:476)
	at org.apache.logging.log4j.util.PropertyEnvironment.getStringProperty(PropertyEnvironment.java:400)
	at org.apache.logging.log4j.util.LoaderUtil.newCheckedInstanceOfProperty(LoaderUtil.java:332)
	at org.apache.logging.log4j.core.impl.ContextDataInjectorFactory.createInjector(ContextDataInjectorFactory.java:69)
	at org.apache.logging.log4j.core.impl.Log4jLogEvent$Builder.initDefaultContextData(Log4jLogEvent.java:280)
	at org.apache.logging.log4j.core.impl.Log4jLogEvent$Builder.<init>(Log4jLogEvent.java:88)
	at org.apache.logging.log4j.core.impl.Log4jLogEvent.newBuilder(Log4jLogEvent.java:290)
	at org.apache.logging.log4j.core.impl.DefaultLogEventFactory.createEvent(DefaultLogEventFactory.java:113)
	at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:529)
	at org.apache.logging.log4j.core.config.AwaitCompletionReliabilityStrategy.log(AwaitCompletionReliabilityStrategy.java:92)
	at org.apache.logging.log4j.core.Logger.log(Logger.java:168)
	at org.apache.logging.log4j.spi.AbstractLogger.tryLogMessage(AbstractLogger.java:2784)
	at org.apache.logging.log4j.spi.AbstractLogger.logMessageTrackRecursion(AbstractLogger.java:2737)
	at org.apache.logging.log4j.spi.AbstractLogger.logMessageSafely(AbstractLogger.java:2723)
	at org.apache.logging.log4j.spi.AbstractLogger.logMessage(AbstractLogger.java:2478)
	at org.apache.logging.log4j.spi.AbstractLogger.logIfEnabled(AbstractLogger.java:2249)
	at org.apache.commons.logging.LogAdapter$Log4jLog.log(LogAdapter.java:264)
	at org.apache.commons.logging.LogAdapter$Log4jLog.info(LogAdapter.java:224)
	at org.springframework.boot.StartupInfoLogger.logStarting(StartupInfoLogger.java:50)
	at org.springframework.boot.SpringApplication.logStartupInfo(SpringApplication.java:638)
	at org.springframework.boot.SpringApplication.prepareContext(SpringApplication.java:404)
	at org.springframework.boot.SpringApplication.run(SpringApplication.java:333)
	at org.springframework.boot.SpringApplication.run(SpringApplication.java:1354)
	at org.springframework.boot.SpringApplication.run(SpringApplication.java:1343)
	at dev.rlratcliffe.CamelApplication.main(CamelApplication.java:22)
	at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0([email protected]/Native Method)
	at jdk.internal.reflect.NativeMethodAccessorImpl.invoke([email protected]/NativeMethodAccessorImpl.java:77)
	at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke([email protected]/DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke([email protected]/Method.java:568)
	at org.springframework.boot.devtools.restart.RestartLauncher.run(RestartLauncher.java:50)

Undertow is trying to throw the exception reported in #33450 but, for a reason that's unknown to me, the JVM's unable to fill in the exception's stack trace. This is the problem mentioned by @koww in #33450 (comment). The fact that the JVM's getting stuck when filling in the stack trace, means that the fix in Log4j2 to catch and swallow the exception does not help.

I'm going to close this is a duplicate of #33450 as I don't think there's anything unique to your situation that needs to be tracked separately.

from spring-boot.

wilkinsona avatar wilkinsona commented on May 10, 2024

On further investigation, I no longer consider this issue to be a duplicate.

The JVM isn't getting stuck when filling in the stack trace, it's in an infinite loop due to some behavior of Log4j2 3.0 beta 1:

Looking more closely at the hang that can be reproduced using the app provided in #40178, it isn't actually a hang but what appears to be an infinite loop in org.apache.logging.log4j.util.PropertiesUtil.Environment:

while (source != null) {
   result = sourceGetProperty(source, contextKey);
   if (result != null) {
       return result;
   }
   source = sources.higher(source);
}

sources contains 6 PropertySource instances but higher(source) is flip-flopping between two of them:

org.springframework.boot.logging.log4j2.SpringEnvironmentPropertySource@d0fbaa3
org.springframework.boot.logging.log4j2.SpringEnvironmentPropertySource@1b375f0b

I'm not sure why there are two instances of SpringEnvironmentPropertySource but I think that may be triggering a bug in Log4j2's comparison of property sources, perhaps because they have the same priority.

The presence of the two instances is, as far as I can tell, due to Devtools. The first instance is added when the app starts and the second is added when a change is made that triggers a restart. We need to clean up SpringEnvironmentPropertySource as part of a context being closed otherwise it'll hold onto an Environment indefinitely.

from spring-boot.

wilkinsona avatar wilkinsona commented on May 10, 2024

The presence of the two instances is, as far as I can tell, due to Devtools

It's not just due to Devtools. The problem also occurs if you run one app after the other in the same JVM, like so:

SpringApplication.run(SampleActuatorLog4J2Application.class).close();
SpringApplication.run(SampleActuatorLog4J2Application.class).close();

With Log4j2 3.0 beta 1, this will produce an infinite loop as we end up with two SpringEnvironmentPropertySource that then flip-flop as described above. With Log4j2 2.x, the attempt to add the second SpringEnvironmentPropertySource has no effect as it's rejected due to the presence of a property source with the same priority. The behavior changed in 3.0 beta 1 in this commit.

There's still a problem with Logj2 2.x as being stuck with the first SpringEnvironmentPropertySource means that any changes to the environment are ignored. For example:

SpringApplication.run(SampleActuatorLog4J2Application.class, "--example=first").close();
SpringApplication.run(SampleActuatorLog4J2Application.class, "--example=second").close();

Log4j2 will always see first as the value of the example property even once the first context has been closed and the second has been refreshed.

I think we need apache/logging-log4j2#2454 in order to fix this as it adds a removePropertySource method. That will allow us to remove the SpringEnvironmentPropertySource when we're cleaning up the logging system. When the second initialization happens it should then be able to add its property source without it being rejected (Log4j 2.x) or becoming a duplicate (Log4j 3.x).

/cc @ppkarwasz @rgoers

from spring-boot.

ppkarwasz avatar ppkarwasz commented on May 10, 2024

I think we need apache/logging-log4j2#2454 in order to fix this as it adds a removePropertySource method. That will allow us to remove the SpringEnvironmentPropertySource when we're cleaning up the logging system. When the second initialization happens it should then be able to add its property source without it being rejected (Log4j 2.x) or becoming a duplicate (Log4j 3.x).

Yes, unfortunately you need for 2.24.0 to come out to use the new PropertiesUtil#removePropertySource method (or the already published 3.0.0-beta2). I'll merge the apache/logging-log4j2#2454 PR tomorrow and make a draft PR in Spring Boot, so you can test it.

from spring-boot.

wilkinsona avatar wilkinsona commented on May 10, 2024

I think we can minimise the damage by using a static-scoped SpringEnvironmentPropertySource, making its Environment mutable, and setting and clearing it when we initialise and clean up the logging system. We can then refine this in whatever version of Boot upgrades to 2.24.

from spring-boot.

ppkarwasz avatar ppkarwasz commented on May 10, 2024

I think we can minimise the damage by using a static-scoped SpringEnvironmentPropertySource, making its Environment mutable, and setting and clearing it when we initialise and clean up the logging system. We can then refine this in whatever version of Boot upgrades to 2.24.

Sounds like a plan. That was actually the original implementation of SpringEnvironmentPropertySource in log4j-spring-boot.

from spring-boot.

Related Issues (20)

Recommend Projects

  • React photo React

    A declarative, efficient, and flexible JavaScript library for building user interfaces.

  • Vue.js photo Vue.js

    🖖 Vue.js is a progressive, incrementally-adoptable JavaScript framework for building UI on the web.

  • Typescript photo Typescript

    TypeScript is a superset of JavaScript that compiles to clean JavaScript output.

  • TensorFlow photo TensorFlow

    An Open Source Machine Learning Framework for Everyone

  • Django photo Django

    The Web framework for perfectionists with deadlines.

  • D3 photo D3

    Bring data to life with SVG, Canvas and HTML. 📊📈🎉

Recommend Topics

  • javascript

    JavaScript (JS) is a lightweight interpreted programming language with first-class functions.

  • web

    Some thing interesting about web. New door for the world.

  • server

    A server is a program made to process requests and deliver data to clients.

  • Machine learning

    Machine learning is a way of modeling and interpreting data that allows a piece of software to respond intelligently.

  • Game

    Some thing interesting about game, make everyone happy.

Recommend Org

  • Facebook photo Facebook

    We are working to build community through open source technology. NB: members must have two-factor auth.

  • Microsoft photo Microsoft

    Open source projects and samples from Microsoft.

  • Google photo Google

    Google ❤️ Open Source for everyone.

  • D3 photo D3

    Data-Driven Documents codes.