I was trying out logging requestIds for every request using the following tutorial: https://oddblogger.com/spring-boot-mdc-logging
My actual aim is to inject data into log4j2 MDC, and consequently, I write the following Filter:
import javax.servlet.Filter;
import javax.servlet.FilterChain;
import javax.servlet.ServletException;
import javax.servlet.ServletRequest;
import javax.servlet.ServletResponse;
import javax.servlet.http.HttpServletResponse;
import java.io.IOException;
import org.apache.log4j.MDC;
import org.springframework.stereotype.Component;
import org.springframework.web.util.ContentCachingResponseWrapper;
public class RequestFilter implements Filter
{
@Override
public void doFilter(ServletRequest servletRequest, ServletResponse servletResponse, FilterChain filterChain) throws IOException, ServletException
{
try
{
String uuid = UUID.randomUUID().toString();
MDC.put("requestId", uuid);
HttpServletResponse httpServletResponse = (HttpServletResponse) servletResponse;
ContentCachingResponseWrapper responseWrapper = new ContentCachingResponseWrapper(
httpServletResponse
);
filterChain.doFilter(servletRequest, responseWrapper);
responseWrapper.setHeader("requestId", uuid);
responseWrapper.copyBodyToResponse();
}
finally
{
MDC.clear();
}
}
}
Due to reasons, I create an application WAR file, and deploy it on Tomcat 8.5 This deployment fails, with cryptic errors to me like:
4-Nov-2022 10:34:33.941 SEVERE [RMI TCP Connection(2)-127.0.0.1] org.apache.catalina.core.StandardContext.startInternal One or more Filters failed to start. Full details will be found in the appropriate container log file
04-Nov-2022 10:34:33.941 SEVERE [RMI TCP Connection(2)-127.0.0.1] org.apache.catalina.core.StandardContext.startInternal Context [/Application] startup failed due to previous errors
PreDestroy invoked...
04-Nov-2022 10:34:34.005 SEVERE [RMI TCP Connection(2)-127.0.0.1] org.apache.catalina.loader.WebappClassLoaderBase.checkThreadLocalMapForLeaks The web application [Application] created a ThreadLocal with key of type [com.abc.Class$1] (value [com.abc.Class$1@6a28aaa3]) and a value of type [com.abc.String] (value ["Random"]) but failed to remove it when the web application was stopped. Threads are going to be renewed over time to try and avoid a probable memory leak.
04-Nov-2022 10:34:34.005 SEVERE [RMI TCP Connection(2)-127.0.0.1] org.apache.catalina.loader.WebappClassLoaderBase.checkThreadLocalMapForLeaks The web application [Application] created a ThreadLocal with key of type [com.abc.Class$1] (value [com.abc.Class$1@6f649cfe]) and a value of type [com.abc.String] (value ["RANDOM"]) but failed to remove it when the web application was stopped. Threads are going to be renewed over time to try and avoid a probable memory leak.
04-Nov-2022 10:34:34.005 SEVERE [RMI TCP Connection(2)-127.0.0.1] org.apache.catalina.loader.WebappClassLoaderBase.checkThreadLocalMapForLeaks The web application [Application] created a ThreadLocal with key of type [java.lang.ThreadLocal] (value [java.lang.ThreadLocal@36663d16]) and a value of type [io.netty.util.internal.InternalThreadLocalMap] (value [io.netty.util.internal.InternalThreadLocalMap@19b4f4cb]) but failed to remove it when the web application was stopped. Threads are going to be renewed over time to try and avoid a probable memory leak.
[2022-11-04 10:34:34,014] Artifact Application.war: Error during artifact deployment. See server log for details.
04-Nov-2022 10:34:34.782 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory [/usr/local/apache-tomcat-8.5.58/webapps/manager]
04-Nov-2022 10:34:34.816 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory [/usr/local/apache-tomcat-8.5.58/webapps/manager] has finished in [35] ms
04-Nov-2022 10:34:37.547 INFO [mysql-cj-abandoned-connection-cleanup] org.apache.catalina.loader.WebappClassLoaderBase.checkStateForResourceLoading Illegal access: this web application instance has been stopped already. Could not load []. The following stack trace is thrown for debugging purposes as well as to attempt to terminate the thread which caused the illegal access.
java.lang.IllegalStateException: Illegal access: this web application instance has been stopped already. Could not load []. The following stack trace is thrown for debugging purposes as well as to attempt to terminate the thread which caused the illegal access.
at org.apache.catalina.loader.WebappClassLoaderBase.checkStateForResourceLoading(WebappClassLoaderBase.java:1378)
at org.apache.catalina.loader.WebappClassLoaderBase.getResource(WebappClassLoaderBase.java:1030)
at com.mysql.cj.jdbc.AbandonedConnectionCleanupThread.checkThreadContextClassLoader(AbandonedConnectionCleanupThread.java:117)
at com.mysql.cj.jdbc.AbandonedConnectionCleanupThread.run(AbandonedConnectionCleanupThread.java:84)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:750)
After much googling due to the cryptic error, I managed to figure out that I instead have to extend the Spring provided GenericFilterBean
class. I changed it, and the application now works correctly.
What's incorrect with implementing the Filter
provided in the javax
package, and why does the Container throw out the above weird error in such case?
I used Spring Boot 2.7.5 if it matters.