[MAGNOLIA-2635] Trace current URL/userid for logging Created: 23/Feb/09  Updated: 23/Jan/13  Resolved: 23/Feb/09

Status: Closed
Project: Magnolia
Component/s: core
Affects Version/s: 4.0
Fix Version/s: 4.0

Type: Improvement Priority: Minor
Reporter: Fabrizio Giustina Assignee: Fabrizio Giustina
Resolution: Fixed Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Issue Links:
duplicate
is duplicated by MAGNOLIA-2294 Provide mapped diagnostic context var... Closed
Template:
Acceptance criteria:
Empty
Task DoD:
[ ]* Doc/release notes changes? Comment present?
[ ]* Downstream builds green?
[ ]* Solution information and context easily available?
[ ]* Tests
[ ]* FixVersion filled and not yet released
[ ]  Architecture Decision Record (ADR)
Date of First Response:

 Description   

This is something that I would like to see added by default, since we are in RC phase I'll describe it here to decide if/when it should be added.

Using log4j (and also with slf4j) we can add useful informations to logs by adding some variables to MDC by default (mapped diagnostic context, see http://wiki.apache.org/logging-log4j/NDCvsMDC ).

Those additional info should be added by a filter. The code below shows what the filter should do (I am not attaching a proper patch since this is only for discussion). The filter should go exactly after the context filter (or we could decide to put it into the context filter maybe.

    public void doFilter(HttpServletRequest request, HttpServletResponse response, FilterChain chain)
        throws IOException, ServletException
    {
        try
        {
            MDC.put("requesturi", request.getRequestURI());
            MDC.put("userid", MgnlContext.getUser().getName());
        }
        catch (Throwable e)
        {
            // whatever it happens, only log
            log.debug(e.getMessage(), e);
        }
        try
        {
            chain.doFilter(request, response);
        }
        finally
        {
            // cleanup
            MDC.remove("requesturi");
            MDC.remove("userid");
        }
    }

Doing this, anywhere in the log4j.xml log patterns the following placeholders can be used in order to print out the current uri and the logged in user:

%X{requesturi}
%X{userid}

This looks very useful also in the mail appender, if you enable it in running sites.
This is an example of the content that can be added to error mails:

 ===================================
 My Magnolia app
 Version: 1.4.0
 Server: c139343z
 Url: /.magnolia/pages/test.html
 User: joe
 Number of occurrences: 2
 ===================================

[c020890-sun01] ERROR 23.02.2009 01:07:08 info.magnolia.module.exchangesimple.SimpleSyndicator SimpleSyndicator.java(run:77) -- Failed to activate content.
info.magnolia.cms.exchange.ExchangeException: Message received from subscriber: Activation failed | /NZ/large
       at info.magnolia.module.exchangesimple.SimpleSyndicator.activate(SimpleSyndicator.java:175)
       at info.magnolia.module.exchangesimple.SimpleSyndicator$1.run(SimpleSyndicator.java:75)
       ....
       .... (the usual stacktrace)

 ===================================

Although this can be easily implemented I think that at least the filter that pushes informations to log4j MDC should be added by default. What about adding it for 4.0?



 Comments   
Comment by Magnolia International [ 23/Feb/09 ]

Sure, this is something we could add - but it seems slightly redundant with the audit features we've added with MAGNOLIA-764 - there is probably some consolidation that could happen here.

This will require an update task to insert the filter in the appropriate place in the chain, so I'd rather wait until 4.0 is released to do that.

Note that as I see it, it could also be a totally independent module, it doesn't seem like it has to be in core.

Comment by Fabrizio Giustina [ 23/Feb/09 ]

> ... but it seems slightly redundant with the audit features we've added with MAGNOLIA-764

well, not really. The reason for this is not to trace user activity, but just to add additional information to error logging (for example: if you get an error in a jcr query you can also see in the log which page contains the bad query)

> Note that as I see it, it could also be a totally independent module, it doesn't seem like it has to be in core.

it's a so small thing that IMHO should be on by default, we could just think about placing those two lines in ContextFilter and nothing more... a module for this looks overkilling and it's a small feature anybody could love if on by default in magnolia.
So, avoiding update tasks and so on, what about this simple addiction to the existing filter? Something enough simple for committing it tonight?


Index: ContextFilter.java
===================================================================
--- ContextFilter.java	(revision 22787)
+++ ContextFilter.java	(working copy)
@@ -46,6 +46,7 @@
 
 import org.slf4j.Logger;
 import org.slf4j.LoggerFactory;
+import org.slf4j.MDC;
 
 
 /**
@@ -70,6 +71,14 @@
         if (!MgnlContext.hasInstance() || MgnlContext.isSystemInstance()) {
             MgnlContext.initAsWebContext(request, response, servletContext);
             contextSet = true;
+            try {
+                MDC.put("requesturi", request.getRequestURI());
+                MDC.put("userid", MgnlContext.getUser().getName());
+            }
+            catch (Throwable e) {
+                // whatever it happens, only log
+                log.debug(e.getMessage(), e);
+            }
         }
         if (!contextSet) {
             // push req/res every time except the first time
@@ -87,6 +96,10 @@
                 MgnlContext.release();
                 MgnlContext.setInstance(null);
             }
+
+            // cleanup
+            MDC.remove("requesturi");
+            MDC.remove("userid");
         }
     }
 

Comment by Fabrizio Giustina [ 23/Feb/09 ]

well, since tonight is the night for RC4 I am going to choose the safer/easier path adding those lines to contextFilter (I am also fairly convinced that it's better than adding a dedicate filter only for this, and there is a ready to use finally block in context filter that just fits)

Generated at Mon Feb 12 03:38:37 CET 2024 using Jira 9.4.2#940002-sha1:46d1a51de284217efdcb32434eab47a99af2938b.