{"id":12683,"date":"2013-11-05T12:53:00","date_gmt":"2013-11-05T11:53:00","guid":{"rendered":"https:\/\/touk.pl\/blog\/?guid=7434a17d85e634f43a8132cd4ab46eb8"},"modified":"2022-07-26T17:26:57","modified_gmt":"2022-07-26T15:26:57","slug":"log4j-and-mdc-in-grails","status":"publish","type":"post","link":"https:\/\/touk.pl\/blog\/2013\/11\/05\/log4j-and-mdc-in-grails\/","title":{"rendered":"Log4j and MDC in Grails"},"content":{"rendered":"<div style=\"text-align: justify\">\n  Log4j provides very useful feature: <b>MDC<\/b> &#8211; mapped diagnostic context. It can be used to store data in context of current thread. It may sound scary a bit but idea is simple. My post is based on post\u00a0<a href=\"http:\/\/burtbeckwith.com\/blog\/?p=521\">http:\/\/burtbeckwith.com\/blog\/?p=521<\/a>\u00a0from Burt Beckwith&#8217;s excellent blog, it&#8217;s definitely worth checking if you are interested in Grails.\n<\/div>\n<div style=\"text-align: justify\">\n<\/div>\n<h3 id=\"short-background-story\">Short background story&#8230;<\/h3>\n<div style=\"text-align: justify\">\n<\/div>\n<div style=\"text-align: justify\">\n  Suppose we want to do logging our brand new shopping system and we want to have in each log customer&#8217;s shopping basket number. And our system can be used at once by many users who can perform many transactions, actions like adding items and so on. How can we achieve that? Of course we can add\u00a0basket\u00a0number in every place where we do some logging but this task would be boring and error-prone.\n<\/div>\n<div style=\"text-align: justify\">\n<\/div>\n<div style=\"text-align: justify\">\n  Instead of this we can use MDC to store variable with\u00a0basket number in map.\n<\/div>\n<div style=\"text-align: justify\">\n<\/div>\n<div style=\"text-align: justify\">\n  In fact MDC can be treated as map of custom values for current thread that can be used by logger.\n<\/div>\n<div style=\"text-align: justify\">\n<\/div>\n<div style=\"text-align: justify\">\n<\/div>\n<h3 id=\"how-to-do-that-with-grails\">How to do that with Grails?<\/h3>\n<div>\n<\/div>\n<div style=\"text-align: justify\">\n  Using MDC with Grails is quite simple. All we need to do is to create our own custom <b>filter<\/b>\u00a0which works for given urls and puts our data in MDC.\n<\/div>\n<div style=\"text-align: justify\">\n<\/div>\n<div style=\"text-align: justify\">\n  Filters in Grails are classes in directory <b>grails-app\/conf\/* <\/b>which names end with *<b>Filters.groovy <\/b>postfix. We can create this class manually or use Grails command:\n<\/div>\n<pre><code>grails create-filters info.rnowak.App.Basket\n \u00a0 \n<\/code><\/pre>\n<div style=\"text-align: justify\">\n  In result class named <b>BasketFilters<\/b> will be created in <b>grails-app\/conf\/info\/rnowak\/UberApp<\/b>. Initially filter class looks a little bit empty: <\/p>\n<pre><code class=\"groovy\">class BasketFilters {\n    def filters = {\n        all(controller:'*', action:'*') {\n            before = {\n\n            }\n            after = { Map model -&gt;\n\n            }\n            afterView = { Exception e -&gt;\n\n            }\n        }\n    }\n}\n<\/code><\/pre>\n<p> All we need to do is fill empty closures, modify filter properties and put some data into MDC. <\/p>\n<p>  <span style=\"font-family: Courier New, Courier, monospace\">all<\/span> is the general name of our filter, as class <b>BasketFilters<\/b> (plural!) can contain many various filters. You can name it whatever you want, for this post let assume it will be named <span style=\"font-family: Courier New, Courier, monospace\">basketFilter<\/span><span style=\"font-family: inherit\">.\u00a0<\/span> <span style=\"font-family: inherit\"> <\/span><span style=\"font-family: inherit\">Another thing is change of filter parameters. According to official documentation (<a href=\"http:\/\/grails.org\/doc\/latest\/guide\/theWebLayer.html#filters\">link<\/a>) we can customize our filter in many ways. You can specify controller to be filtered, its actions, filtered urls and so on. In our example you can stay with default option where filter is applied to every action of every controller. If you are interested in filtering only some urls, use <\/span><span style=\"font-family: Courier New, Courier, monospace\">uri <\/span><span style=\"font-family: inherit\">parameter with expression describing desired urls to be filtered.<\/span> <span style=\"font-family: inherit\"> <\/span><span style=\"font-family: inherit\">Three closures that are already defined in template have their function and they are started in these conditions:<\/span> <\/p>\n<ul>\n<li>\n      <span style=\"font-family: Courier New, Courier, monospace\">before<\/span> &#8211; as name says, it is executed before filtered action takes place\n    <\/li>\n<li>\n      <span style=\"font-family: Courier New, Courier, monospace\">after<\/span> &#8211; similarly, it is called after the action\n    <\/li>\n<li>\n      <span style=\"font-family: Courier New, Courier, monospace\">afterView<\/span> &#8211; called after rendering of the actions view\n    <\/li>\n<\/ul>\n<div>\n    Ok, so now we know what are these mysterious methods and when they are called. But what can be done within them? In official Grails docs (<a href=\"http:\/\/grails.org\/doc\/latest\/guide\/theWebLayer.html#filters\">link again<\/a>) under section <b>7.6.3 <\/b>there is a list of properties that are available to use in filter.\n  <\/div>\n<div>\n  <\/div>\n<div>\n    With that knowledge, we can proceed to implementing filter.\n  <\/div>\n<div>\n  <\/div>\n<h3 id=\"putting-something-into-mdc-in-filter\">\n    Putting something into MDC in filter<br \/>\n  <\/h3>\n<div>\n    What we want to do is quite easy: we want to retrieve\u00a0basket number\u00a0from parameters and put it into MDC in our filter:\n  <\/div>\n<pre><code class=\"groovy\">class BasketFilters {\n    def filters = {\n        basketFilter(controller:'*', action:'*') {\n            before = {\n                MDC.put(\"basketNumber\", params.basketNumber ?: \"\")\n            }\n            after = { Map model -&gt;\n                MDC.remove(\"basketNumber\")\n            }\n        }\n    }\n}\n<\/code><\/pre>\n<div>\n    We retrieve basket number from Grails params map and then we put in map under specified key (<span style=\"font-family: Courier New, Courier, monospace\">&#8220;basketNumber&#8221;<\/span> in this case), which will be later used in logger conversion pattern. It is important to remove custom value after processing of action to avoid leaks. <\/p>\n<h3 id=\"so-we-are-putting-something-into-mdc-but-how-make-use-of-it-in-logs\">\n      So we are putting something into MDC. But how make use of it in logs?<br \/>\n    <\/h3>\n<\/p><\/div>\n<div>\n    We can refer to custom data in MDC in conversion patter using syntax: <span style=\"font-family: Courier New, Courier, monospace\">%X{key}<\/span>, where key is our key we used in filter to put data, like:\n  <\/div>\n<pre><code class=\"groovy\">def conversionPattern = \"%d{yyyy-MM-dd HH:mm:ss} %-5p %t [%c{1}] %X{basketNumber} - %m%n\"\n<\/code><\/pre>\n<p> And that&#8217;s it :) We&#8217;ve put custom data in log4j MDC and successfully used it in logs to display interesting values.\n<\/p><\/div>\n","protected":false},"excerpt":{"rendered":"Log4j provides very useful feature: MDC &#8211; mapped diagnostic context. It can be used to store data in context of current thread. It may sound scary a bit but idea is simple.\nMy post is based on post&nbsp;http:\/\/burtbeckwith.com\/blog\/?p=521&nbsp;from Burt Beckwith&#8217;s excellent blog, it&#8217;s definitely worth checking if you are interested in Grails.\n\nShort background story&#8230;\n\nSuppose we want to do logging our brand new shopping system and we want to have in each log customer&#8217;s shopping basket number. And our system can be used at once by many users who can perform many transactions, actions like adding items and so on. How can we achieve that? Of course we can add&nbsp;basket&nbsp;number in every place where we do some logging but this task would be boring and error-prone.&nbsp;\n\nInstead of this we can use MDC to store variable with&nbsp;basket number in map.&nbsp;\n\nIn fact MDC can be treated as map of custom values for current thread that can be used by logger.&nbsp;\n\n\nHow to do that with Grails?\n\nUsing MDC with Grails is quite simple. All we need to do is to create our own custom filter&nbsp;which works for given urls and puts our data in MDC.\n\nFilters in Grails are classes in directory grails-app\/conf\/* which names end with *Filters.groovy postfix. We can create this class manually or use Grails command:&nbsp;\ngrails create-filters info.rnowak.App.Basket\n\nIn result class named BasketFilters will be created in grails-app\/conf\/info\/rnowak\/UberApp.\nInitially filter class looks a little bit empty:\nclass BasketFilters {    def filters = {        all(controller:'*', action:'*') {            before = {            }            after = { Map model -&gt;            }            afterView = { Exception e -&gt;            }        }    }}\nAll we need to do is fill empty closures, modify filter properties and put some data into MDC.\nall is the general name of our filter, as class BasketFilters (plural!) can contain many various filters. You can name it whatever you want, for this post let assume it will be named basketFilter.&nbsp;Another thing is change of filter parameters. According to official documentation (link) we can customize our filter in many ways. You can specify controller to be filtered, its actions, filtered urls and so on. In our example you can stay with default option where filter is applied to every action of every controller. If you are interested in filtering only some urls, use uri parameter with expression describing desired urls to be filtered.Three closures that are already defined in template have their function and they are started in these conditions:\n\nbefore &#8211; as name says, it is executed before filtered action takes place\nafter &#8211; similarly, it is called after the action\nafterView &#8211; called after rendering of the actions view\n\nOk, so now we know what are these mysterious methods and when they are called. But what can be done within them? In official Grails docs (link again) under section 7.6.3 there is a list of properties that are available to use in filter.\n\nWith that knowledge, we can proceed to implementing filter.\n\nPutting something into MDC in filter\nWhat we want to do is quite easy: we want to retrieve&nbsp;basket number&nbsp;from parameters and put it into MDC in our filter:\nclass BasketFilters {    def filters = {        basketFilter(controller:'*', action:'*') {            before = {                MDC.put(\"basketNumber\", params.basketNumber ?: \"\")            }            after = { Map model -&gt;                MDC.remove(\"basketNumber\")            }        }    }}\n\nWe retrieve basket number from Grails params map and then we put in map under specified key (&#8220;basketNumber&#8221; in this case), which will be later used in logger conversion pattern. It is important to remove custom value after processing of action to avoid leaks.\nSo we are putting something into MDC. But how make use of it in logs?\n\nWe can refer to custom data in MDC in conversion patter using syntax: %X{key}, where key is our key we used in filter to put data, like:\ndef conversionPattern = \"%d{yyyy-MM-dd HH:mm:ss} %-5p %t [%c{1}] %X{basketNumber} - %m%n\"\nAnd that&#8217;s it :) We&#8217;ve put custom data in log4j MDC and successfully used it in logs to display interesting values. \n","protected":false},"author":48,"featured_media":0,"comment_status":"open","ping_status":"closed","sticky":false,"template":"","format":"standard","meta":{"footnotes":""},"categories":[11],"tags":[50,68],"_links":{"self":[{"href":"https:\/\/touk.pl\/blog\/wp-json\/wp\/v2\/posts\/12683"}],"collection":[{"href":"https:\/\/touk.pl\/blog\/wp-json\/wp\/v2\/posts"}],"about":[{"href":"https:\/\/touk.pl\/blog\/wp-json\/wp\/v2\/types\/post"}],"author":[{"embeddable":true,"href":"https:\/\/touk.pl\/blog\/wp-json\/wp\/v2\/users\/48"}],"replies":[{"embeddable":true,"href":"https:\/\/touk.pl\/blog\/wp-json\/wp\/v2\/comments?post=12683"}],"version-history":[{"count":4,"href":"https:\/\/touk.pl\/blog\/wp-json\/wp\/v2\/posts\/12683\/revisions"}],"predecessor-version":[{"id":14780,"href":"https:\/\/touk.pl\/blog\/wp-json\/wp\/v2\/posts\/12683\/revisions\/14780"}],"wp:attachment":[{"href":"https:\/\/touk.pl\/blog\/wp-json\/wp\/v2\/media?parent=12683"}],"wp:term":[{"taxonomy":"category","embeddable":true,"href":"https:\/\/touk.pl\/blog\/wp-json\/wp\/v2\/categories?post=12683"},{"taxonomy":"post_tag","embeddable":true,"href":"https:\/\/touk.pl\/blog\/wp-json\/wp\/v2\/tags?post=12683"}],"curies":[{"name":"wp","href":"https:\/\/api.w.org\/{rel}","templated":true}]}}