[MGNLDAM-1305] Avoid extensive logging in DamDownloadServlet Created: 17/Nov/23 Updated: 02/Feb/24 Resolved: 02/Feb/24 |
|
| Status: | Closed |
| Project: | Magnolia DAM Module |
| Component/s: | None |
| Affects Version/s: | 3.0.27 |
| Fix Version/s: | 3.1.0 |
| Type: | Improvement | Priority: | Neutral |
| Reporter: | Denis Lobo | Assignee: | ricardo gonzalez |
| Resolution: | Fixed | Votes: | 0 |
| Labels: | None | ||
| Σ Remaining Estimate: | 0d | Remaining Estimate: | 0d |
| Σ Time Spent: | 0.5h | Time Spent: | 0.5h |
| Σ Original Estimate: | Not Specified | Original Estimate: | Not Specified |
| Issue Links: |
|
|||||||||||||||||||||||||
| Sub-Tasks: |
|
|||||||||||||||||||||||||
| Template: | ||||||||||||||||||||||||||
| Patch included: |
Yes
|
|||||||||||||||||||||||||
| Acceptance criteria: |
Empty
|
|||||||||||||||||||||||||
| Task DoD: |
[X]*
Doc/release notes changes? Comment present?
[X]*
Downstream builds green?
[X]*
Solution information and context easily available?
[X]*
Tests
[X]*
FixVersion filled and not yet released
[X] 
Architecture Decision Record (ADR)
|
|||||||||||||||||||||||||
| Date of First Response: | ||||||||||||||||||||||||||
| Epic Link: | AuthorX Support | |||||||||||||||||||||||||
| Team: | ||||||||||||||||||||||||||
| Work Started: | ||||||||||||||||||||||||||
| Approved: |
Yes
|
|||||||||||||||||||||||||
| Description |
|
On a production environment, we receive large amounts of requests pointing to e.g. non existing dam-documents. For any requested asset, which can't be found, the DamDownloadServlet logs an exception with stacktrace (WARN as loglevel), which unfortunately spams production logs. Thus we propose a solution, where the error with stacktrace is logged in DEBUG mode only, as well a decent log entry without stacktrace for WARN. Reproduce
FYI: Working link is https://demopublic.magnolia-cms.com/dam/jcr:e236c74c-6b35-4467-b322-933419ecfd87/beach.svg Expected It should log detailed information for DEBUG Actual It logs detailed information on WARN WARN info.magnolia.dam.core.download.DamDownloadServlet 20.11.2023 14:02:03 -- Could not retrieve an asset based on the following pathInfo /jcr:e236c74c-6b35-4467-b322-933419ecfd88/beach.svg info.magnolia.dam.api.AssetProvider$AssetNotFoundException: No Asset found for ItemKey <info.magnolia.dam.api.ItemKey@78d7c7b> at info.magnolia.dam.jcr.JcrAssetProvider.getNodeByIdentifier(JcrAssetProvider.java:477) ~[magnolia-dam-jcr-3.0.27.jar:?] at info.magnolia.dam.jcr.JcrAssetProvider.getAsset(JcrAssetProvider.java:195) ~[magnolia-dam-jcr-3.0.27.jar:?] at info.magnolia.dam.core.download.DamDownloadServlet.getAssetBasedOnIdentifier(DamDownloadServlet.java:228) ~[magnolia-dam-core-3.0.27.jar:?] at info.magnolia.dam.core.download.DamDownloadServlet.getAsset(DamDownloadServlet.java:149) [magnolia-dam-core-3.0.27.jar:?] at info.magnolia.dam.core.download.DamDownloadServlet.process(DamDownloadServlet.java:125) [magnolia-dam-core-3.0.27.jar:?] at info.magnolia.dam.core.download.DamDownloadServlet.doGet(DamDownloadServlet.java:106) [magnolia-dam-core-3.0.27.jar:?] at javax.servlet.http.HttpServlet.service(HttpServlet.java:529) [servlet-api.jar:4.0.FR] at javax.servlet.http.HttpServlet.service(HttpServlet.java:623) [servlet-api.jar:4.0.FR] at info.magnolia.cms.filters.ServletDispatchingFilter.doFilter(ServletDispatchingFilter.java:148) [magnolia-core-6.2.40.jar:?] at info.magnolia.cms.filters.AbstractMgnlFilter.doFilter(AbstractMgnlFilter.java:85) [magnolia-core-6.2.40.jar:?] at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:79) [magnolia-core-6.2.40.jar:?] at info.magnolia.cms.filters.CompositeFilter.doFilter(CompositeFilter.java:75) [magnolia-core-6.2.40.jar:?] at info.magnolia.cms.filters.AbstractMgnlFilter.doFilter(AbstractMgnlFilter.java:85) [magnolia-core-6.2.40.jar:?] at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:79) [magnolia-core-6.2.40.jar:?] at info.magnolia.module.cache.executor.Store.processCacheRequest(Store.java:96) [magnolia-cache-core-5.9.8.jar:?] at info.magnolia.module.cache.executor.CompositeExecutor.processCacheRequest(CompositeExecutor.java:66) [magnolia-cache-core-5.9.8.jar:?] at info.magnolia.module.cache.filter.CacheFilter.doFilter(CacheFilter.java:164) [magnolia-cache-core-5.9.8.jar:?] at info.magnolia.cms.filters.AbstractMgnlFilter.doFilter(AbstractMgnlFilter.java:85) [magnolia-core-6.2.40.jar:?] at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:79) [magnolia-core-6.2.40.jar:?] at info.magnolia.cms.i18n.I18nContentSupportFilter.doFilter(I18nContentSupportFilter.java:85) [magnolia-core-6.2.40.jar:?] at info.magnolia.cms.filters.AbstractMgnlFilter.doFilter(AbstractMgnlFilter.java:85) [magnolia-core-6.2.40.jar:?] at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:79) [magnolia-core-6.2.40.jar:?] at info.magnolia.virtualuri.VirtualUriFilter.doFilter(VirtualUriFilter.java:108) [magnolia-virtual-uri-6.2.40.jar:?] at info.magnolia.cms.filters.AbstractMgnlFilter.doFilter(AbstractMgnlFilter.java:85) [magnolia-core-6.2.40.jar:?] at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:79) [magnolia-core-6.2.40.jar:?] at info.magnolia.cms.filters.RangeSupportFilter.doFilter(RangeSupportFilter.java:79) [magnolia-core-6.2.40.jar:?] at info.magnolia.cms.filters.OncePerRequestAbstractMgnlFilter.doFilter(OncePerRequestAbstractMgnlFilter.java:59) [magnolia-core-6.2.40.jar:?] at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:79) [magnolia-core-6.2.40.jar:?] at info.magnolia.cms.security.BaseSecurityFilter.doFilter(BaseSecurityFilter.java:57) [magnolia-core-6.2.40.jar:?] at info.magnolia.cms.filters.AbstractMgnlFilter.doFilter(AbstractMgnlFilter.java:85) [magnolia-core-6.2.40.jar:?] at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:79) [magnolia-core-6.2.40.jar:?] at info.magnolia.multisite.filters.CrossSiteSecurityFilter.doFilter(CrossSiteSecurityFilter.java:104) [magnolia-module-multisite-2.1.2.jar:?] at info.magnolia.cms.filters.AbstractMgnlFilter.doFilter(AbstractMgnlFilter.java:85) [magnolia-core-6.2.40.jar:?] at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:79) [magnolia-core-6.2.40.jar:?] at info.magnolia.cors.AbstractCorsFilter.doFilter(AbstractCorsFilter.java:77) [magnolia-core-6.2.40.jar:?] at info.magnolia.cms.filters.OncePerRequestAbstractMgnlFilter.doFilter(OncePerRequestAbstractMgnlFilter.java:59) [magnolia-core-6.2.40.jar:?] at info.magnolia.cms.filters.CompositeFilter.doFilter(CompositeFilter.java:79) [magnolia-core-6.2.40.jar:?] at info.magnolia.cms.filters.AbstractMgnlFilter.doFilter(AbstractMgnlFilter.java:85) [magnolia-core-6.2.40.jar:?] at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:79) [magnolia-core-6.2.40.jar:?] at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:81) [magnolia-core-6.2.40.jar:?] at info.magnolia.cms.security.SecurityCallbackFilter.doFilter(SecurityCallbackFilter.java:86) [magnolia-core-6.2.40.jar:?] at info.magnolia.cms.filters.OncePerRequestAbstractMgnlFilter.doFilter(OncePerRequestAbstractMgnlFilter.java:59) [magnolia-core-6.2.40.jar:?] at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:79) [magnolia-core-6.2.40.jar:?] at info.magnolia.cms.security.LogoutFilter.doFilter(LogoutFilter.java:93) [magnolia-core-6.2.40.jar:?] at info.magnolia.cms.filters.OncePerRequestAbstractMgnlFilter.doFilter(OncePerRequestAbstractMgnlFilter.java:59) [magnolia-core-6.2.40.jar:?] at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:79) [magnolia-core-6.2.40.jar:?] at info.magnolia.module.site.filters.SiteMergeFilter.doFilter(SiteMergeFilter.java:115) [magnolia-site-1.4.5.jar:?] at info.magnolia.cms.filters.AbstractMgnlFilter.doFilter(AbstractMgnlFilter.java:85) [magnolia-core-6.2.40.jar:?] at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:79) [magnolia-core-6.2.40.jar:?] at info.magnolia.multisite.filters.MultiSiteFilter.doFilter(MultiSiteFilter.java:120) [magnolia-module-multisite-2.1.2.jar:?] at info.magnolia.cms.filters.AbstractMgnlFilter.doFilter(AbstractMgnlFilter.java:85) [magnolia-core-6.2.40.jar:?] at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:79) [magnolia-core-6.2.40.jar:?] at info.magnolia.cms.filters.MultiChannelFilter.doFilter(MultiChannelFilter.java:83) [magnolia-core-6.2.40.jar:?] at info.magnolia.cms.filters.AbstractMgnlFilter.doFilter(AbstractMgnlFilter.java:85) [magnolia-core-6.2.40.jar:?] at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:79) [magnolia-core-6.2.40.jar:?] at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:81) [magnolia-core-6.2.40.jar:?] at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:81) [magnolia-core-6.2.40.jar:?] at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:81) [magnolia-core-6.2.40.jar:?] at info.magnolia.cms.security.auth.login.LoginFilter.doFilter(LoginFilter.java:128) [magnolia-core-6.2.40.jar:?] at info.magnolia.cms.filters.AbstractMgnlFilter.doFilter(AbstractMgnlFilter.java:85) [magnolia-core-6.2.40.jar:?] at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:79) [magnolia-core-6.2.40.jar:?] at info.magnolia.enterprise.registration.RegistrationFilter.doFilter(RegistrationFilter.java:92) [magnolia-module-enterprise-6.2.40.jar:?] at info.magnolia.cms.filters.OncePerRequestAbstractMgnlFilter.doFilter(OncePerRequestAbstractMgnlFilter.java:59) [magnolia-core-6.2.40.jar:?] at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:79) [magnolia-core-6.2.40.jar:?] at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:81) [magnolia-core-6.2.40.jar:?] at info.magnolia.cms.filters.UnicodeNormalizationFilter.doFilter(UnicodeNormalizationFilter.java:89) [magnolia-core-6.2.40.jar:?] at info.magnolia.cms.filters.AbstractMgnlFilter.doFilter(AbstractMgnlFilter.java:85) [magnolia-core-6.2.40.jar:?] at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:79) [magnolia-core-6.2.40.jar:?] at info.magnolia.cms.filters.MultipartRequestFilter.doFilter(MultipartRequestFilter.java:164) [magnolia-core-6.2.40.jar:?] at info.magnolia.cms.filters.OncePerRequestAbstractMgnlFilter.doFilter(OncePerRequestAbstractMgnlFilter.java:59) [magnolia-core-6.2.40.jar:?] at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:79) [magnolia-core-6.2.40.jar:?] at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:81) [magnolia-core-6.2.40.jar:?] at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:81) [magnolia-core-6.2.40.jar:?] at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:81) [magnolia-core-6.2.40.jar:?] at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:81) [magnolia-core-6.2.40.jar:?] at info.magnolia.personalization.preview.filter.PreviewFilter.doFilter(PreviewFilter.java:90) [magnolia-personalization-preview-app-2.1.10.jar:?] at info.magnolia.cms.filters.OncePerRequestAbstractMgnlFilter.doFilter(OncePerRequestAbstractMgnlFilter.java:59) [magnolia-core-6.2.40.jar:?] at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:79) [magnolia-core-6.2.40.jar:?] at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:81) [magnolia-core-6.2.40.jar:?] at info.magnolia.cms.filters.ContentTypeFilter.doFilter(ContentTypeFilter.java:156) [magnolia-core-6.2.40.jar:?] at info.magnolia.cms.filters.AbstractMgnlFilter.doFilter(AbstractMgnlFilter.java:85) [magnolia-core-6.2.40.jar:?] at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:79) [magnolia-core-6.2.40.jar:?] at info.magnolia.cms.filters.ContextFilter.doFilter(ContextFilter.java:128) [magnolia-core-6.2.40.jar:?] at info.magnolia.cms.filters.AbstractMgnlFilter.doFilter(AbstractMgnlFilter.java:85) [magnolia-core-6.2.40.jar:?] at info.magnolia.cms.filters.MgnlFilterChain.doFilter(MgnlFilterChain.java:79) [magnolia-core-6.2.40.jar:?] at info.magnolia.cms.filters.CompositeFilter.doFilter(CompositeFilter.java:75) [magnolia-core-6.2.40.jar:?] at info.magnolia.cms.filters.AbstractMgnlFilter.doFilter(AbstractMgnlFilter.java:85) [magnolia-core-6.2.40.jar:?] at info.magnolia.cms.filters.SafeDestroyMgnlFilterWrapper.doFilter(SafeDestroyMgnlFilterWrapper.java:107) [magnolia-core-6.2.40.jar:?] at info.magnolia.cms.filters.MgnlFilterDispatcher.doDispatch(MgnlFilterDispatcher.java:67) [magnolia-core-6.2.40.jar:?] at info.magnolia.cms.filters.MgnlMainFilter.doFilter(MgnlMainFilter.java:110) [magnolia-core-6.2.40.jar:?] at info.magnolia.cms.filters.MgnlMainFilter.doFilter(MgnlMainFilter.java:96) [magnolia-core-6.2.40.jar:?] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:178) [catalina.jar:9.0.82] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:153) [catalina.jar:9.0.82] at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:168) [catalina.jar:9.0.82] at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:90) [catalina.jar:9.0.82] at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:481) [catalina.jar:9.0.82] at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:130) [catalina.jar:9.0.82] at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:93) [catalina.jar:9.0.82] at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:670) [catalina.jar:9.0.82] at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:74) [catalina.jar:9.0.82] at org.apache.catalina.valves.RemoteIpValve.invoke(RemoteIpValve.java:765) [catalina.jar:9.0.82] at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:342) [catalina.jar:9.0.82] at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:390) [tomcat-coyote.jar:9.0.82] at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:63) [tomcat-coyote.jar:9.0.82] at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:928) [tomcat-coyote.jar:9.0.82] at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1794) [tomcat-coyote.jar:9.0.82] at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:52) [tomcat-coyote.jar:9.0.82] at org.apache.tomcat.util.threads.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1191) [tomcat-util.jar:9.0.82] at org.apache.tomcat.util.threads.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:659) [tomcat-util.jar:9.0.82] at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) [tomcat-util.jar:9.0.82] at java.base/java.lang.Thread.run(Thread.java:829) [?:?] Notes |
| Comments |
| Comment by Denis Lobo [ 20/Nov/23 ] |
|
Pls find the PR here |
| Comment by Richard Gange [ 20/Nov/23 ] |
|
IMO we don't need the stack trace at all. I think e.getMessage() would be enough in this case. We might consider logging the requesting ip for possible blacklisting. |
| Comment by Philipp Gaschuetz [ 20/Nov/23 ] |
|
abolutely agreed - no need for the stacktrace. As for logging the requesting IP address: ( IMHO this should generally be solved via MDC. Magnolia is already doing some MDC setup in
would probably be the cleaner way. |
| Comment by Denis Lobo [ 09/Jan/24 ] |
|
Hi Richard, the given PR has been automatically closed due to inactivity,.. how do we proceed further? Should i change my PR (i.e. remove the logging completely)? |
| Comment by Richard Gange [ 09/Jan/24 ] |
|
Hello Denis- At the moment the PD team hasn't gotten around to this ticket. We do receive a lot of change requests. We use a scoring system in order to determine the highest priority tickets to serve next. Maybe for the mean time it might be better to suppress the stack trace from the log file by changing the configuration of your log4j2 file. You can adjust the level from the DamDownloadServlet there. HTH |