In Artifactory, logback.xml is a configuration file for the Logback logging framework, which is used to manage logging for the application. It allows you to define how logs are recorded, including the log levels (e.g., DEBUG, INFO, WARN, ERROR),
the format of the log messages, and the destinations for the log output (such as console or files). The logback.xml configuration file is essential for logging in Artifactory. If this file becomes corrupted, it can lead to logging issues or prevent Artifactory from starting properly.
This article provides steps to diagnose and resolve issues related to a corrupted logback.xml file.
Symptoms of a Corrupted logback.xml:
- Artifactory fails to start or crashes during the startup process.
- Missing log entries or logs not being generated.
- Errors or warnings in the Artifactory logs indicate problems with logging configuration.
Example Error captured in Artifactory logs:
You may encounter stack traces similar to the following in your Artifactory logs:
2024-06-15T05:55:01.954Z [35m[tomct][0m [WARNING] [ ] [org.apache.catalina.startup.HostConfig] [org.apache.catalina.startup.HostConfig deployDescriptor] - A docBase [/opt/jfrog/artifactory/app/artifactory/tomcat/webapps/access.war] inside the host appBase has been specified, and will be ignored 05:55:02,569 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback-test.xml] 05:55:02,569 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback.groovy] 05:55:02,570 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback.xml] 05:55:02,577 |-INFO in ch.qos.logback.classic.BasicConfigurator@21f29108 - Setting up default configuration. 05:55:02,807 |-ERROR in ch.qos.logback.core.joran.event.SaxEventRecorder@40ff3d54 - XML_PARSING - Parsing fatal error on line 434 and column 1 05:55:02,807 |-ERROR in ch.qos.logback.core.joran.event.SaxEventRecorder@40ff3d54 - org.xml.sax.SAXParseException; systemId: file:/opt/jfrog/artifactory/var/etc/artifactory/logback.xml; lineNumber: 434; columnNumber: 1; XML document structures must start and end within the same entity.
Key Errors:
- Multiple resources for logback configurations could not be found.
- A fatal XML parsing error was detected in logback.xml, indicating a syntax error.
Investigation Steps for the above log message:
1. Check for Syntax Errors:
- Open the logback.xml file located at /opt/jfrog/artifactory/var/etc/artifactory/logback.xml.
- Navigate to line 434 and inspect the syntax. Common issues include:
- Unmatched tags.
- Incorrectly nested elements.
- Missing closing tags.
2. Validate XML Structure:
Use an XML validation tool or an IDE with XML support to check the entire logback.xml for structural integrity. Ensure that the document starts with a root element and all tags are correctly closed.
3. Review Recent Changes:
If this error appeared after recent changes to the logback.xml, revert those changes and restart Artifactory to see if the issue is resolved.
4. Restore Default Configuration:
If the corruption cannot be easily fixed, consider restoring the logback.xml to its default state. Default configurations can often be found in the Artifactory installation package.
5. Check File Permissions:
Ensure that the file permissions allow the Artifactory process to read the logback.xml file:
ls -l /opt/jfrog/artifactory/var/etc/artifactory/logback.xml
6. Restart Artifactory:
After making changes to the logback.xml, restart the Artifactory service to apply the new configuration:
sudo systemctl restart artifactory
Example thread stack trace captured as part of the thread dump collection:
2024-03-15T07:04:43.908Z|7ef263d10537de88|/artifactory/api/v1/system/liveness|http-nio-8081-exec-15 PRIORITY : 5 THREAD ID : 0X00007F47E8093920 NATIVE ID : 0X17A0 NATIVE ID (DECIMAL) : 6048 STATE : RUNNABLE stackTrace: java.lang.Thread.State: RUNNABLE at java.io.UnixFileSystem.getLength(java.base@17.0.5/Native Method) at java.io.File.length(java.base@17.0.5/File.java:1004) at org.jfrog.common.logging.logback.triggering.SizeAndIntervalTriggeringPolicy.needToTrigger(SizeAndIntervalTriggeringPolicy.java:52) at org.jfrog.common.logging.logback.triggering.SizeAndIntervalTriggeringPolicy.isTriggeringEvent(SizeAndIntervalTriggeringPolicy.java:42) at ch.qos.logback.core.rolling.RollingFileAppender.subAppend(RollingFileAppender.java:230) - locked <0x00000007019701d8> (a org.jfrog.common.logging.logback.triggering.SizeAndIntervalTriggeringPolicy) at ch.qos.logback.core.OutputStreamAppender.append(OutputStreamAppender.java:102) at ch.qos.logback.core.UnsynchronizedAppenderBase.doAppend(UnsynchronizedAppenderBase.java:84) at ch.qos.logback.core.spi.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:51) at ch.qos.logback.classic.Logger.appendLoopOnAppenders(Logger.java:270) at ch.qos.logback.classic.Logger.callAppenders(Logger.java:257) at ch.qos.logback.classic.Logger.buildLoggingEventAndAppend(Logger.java:421) at ch.qos.logback.classic.Logger.filterAndLog_0_Or3Plus(Logger.java:383) at ch.qos.logback.classic.Logger.info(Logger.java:579) at org.artifactory.traffic.RequestLogger.request(RequestLogger.java:83) at org.artifactory.webapp.servlet.RequestFilter.doFilter(RequestFilter.java:100) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162) at org.artifactory.webapp.servlet.ArtifactoryCsrfFilter.doFilter(ArtifactoryCsrfFilter.java:83) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162) at org.springframework.session.web.http.SessionRepositoryFilter.doFilterInternal(SessionRepositoryFilter.java:164) at org.springframework.session.web.http.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:80) at org.artifactory.webapp.servlet.SessionFilter.doFilter(SessionFilter.java:67) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162) at org.artifactory.webapp.servlet.ArtifactoryTracingFilter.doFilter(ArtifactoryTracingFilter.java:38) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162) at org.artifactory.webapp.servlet.ArtifactoryFilter.doFilter(ArtifactoryFilter.java:126) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162) at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:177) at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:97) at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:541) at org.apache.catalina.valves.rewrite.RewriteValve.invoke(RewriteValve.java:289) at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:135) at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92) at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:78) at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:360) at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:399) at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65) at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:925) at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1784) at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49) - locked <0x0000000756923878> (a org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper) at org.apache.tomcat.util.threads.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1191) at org.apache.tomcat.util.threads.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:659) at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) at java.lang.Thread.run(java.base@17.0.5/Thread.java:833) Locked ownable synchronizers: - <0x0000000756905970> (a org.apache.tomcat.util.threads.ThreadPoolExecutor$Worker)
Based on the thread stack trace, we observe that a thread is in the RUNNABLE state, likely due to the logging framework attempting to access a corrupted configuration file. This suggests that the logging subsystem is actively trying to perform operations but is hindered by a faulty logback.xml. Correcting the configuration file should resolve this issue. Additionally, there are several factors that could be contributing to the problem:
1. High Log Volume:
A high frequency of log messages can lead to frequent size checks on the log file, causing performance bottlenecks. If debug loggers have been enabled for troubleshooting specific Artifactory issues, consider removing them from the `logback.xml` as they can be resource-intensive.
2. Slow Disk I/O:
If the underlying storage system is experiencing high latency or is overloaded, this can slow down file operations like checking the file size, resulting in delays in processing requests.
3. Contention:
Multiple threads trying to access the same logging resources can create contention. This issue can become more pronounced if logging is heavily utilized by various components. Considering tuning the Artifactory for heavy loads as explained here.
Addressing these factors will help improve the performance and reliability of the logging subsystem.
Conclusion:
A corrupted logback.xml file can lead to severe logging issues in Artifactory. By following the steps outlined above, you can identify and resolve XML syntax errors, restore functionality, and ensure proper logging behavior.