aem cloud, how to set the log format string to include MDC vars (such as correlation token)?

Avatar

Avatar
Affirm 5
Level 4
TB3dock
Level 4

Likes

37 likes

Total Posts

223 posts

Correct reply

5 solutions
Top badges earned
Affirm 5
Ignite 10
Boost 25
Give Back 25
Validate 10
View profile

Avatar
Affirm 5
Level 4
TB3dock
Level 4

Likes

37 likes

Total Posts

223 posts

Correct reply

5 solutions
Top badges earned
Affirm 5
Ignite 10
Boost 25
Give Back 25
Validate 10
View profile
TB3dock
Level 4

26-04-2021

We have a filter which sets the MDC for org.slf4j.Logger. 

TO BE CLEAR, THIS QUESTION IS NOT ABOUT THE FILTER, WHICH WORKS, BUT ABOUT HOW TO ADD THE MDC TO THE LOG STRING!

It seems there is a major bug or major missing feature in AEM which is the ability to add mdc vars into the json log format.  E.g. neither of these documented ways work - both result in the entire log format being ignored.

 

 

 

  "org.apache.sling.commons.log.pattern": "{0,date,yyyy-MM-dd HH:mm:ss.SSS} [%X{APPID:-NoAppId}] {4} [{3}] {5}",

 

 

 

and

 

 

 

  "org.apache.sling.commons.log.pattern": "{0,date,yyyy-MM-dd HH:mm:ss.SSS} mdc{} *{4} [{3}] {5}",

 

 

 

 

The vars are put into the MDC using standard servlet filter, e.g.

 

 

 

    
    public void doFilter(final ServletRequest request, final ServletResponse response,
                         final FilterChain filterChain) throws IOException, ServletException {

        final SlingHttpServletRequest slingRequest = (SlingHttpServletRequest) request;
        final SlingHttpServletResponse slingResponse = (SlingHttpServletResponse)response;
        try {
            String token = this.getCorrelationtoken(slingRequest);
            MDC.put(CORRELATION_HEADER, token);
            MDC.put("APPID", APPID);
        	filterChain.doFilter(request, response);
		} finally {
			MDC.remove(CORRELATION_HEADER);
			MDC.remove("APPID");
		}
    }

 

 

 

 

 

we tried putting the following file /myapp.ui.config/src/main/content/jcr_root/apps/myapp/osgiconfig/config/org.apache.sling.commons.log.LogManager.xml (see below) but it doesn't work (its not being used at all, e.g. the data string is different) Any suggestions?

The filter is being executed, but we cant get any of the data into the log files.

We tried this:

 

 

 

<?xml version="1.0" encoding="UTF-8"?>
<jcr:root xmlns:sling="http://sling.apache.org/jcr/sling/1.0" xmlns:cq="http://www.day.com/jcr/cq/1.0" xmlns:jcr="http://www.jcp.org/jcr/1.0" xmlns:nt="http://www.jcp.org/jcr/nt/1.0"
      jcr:primaryType="sling:OsgiConfig"
      org.apache.sling.commons.log.pattern="%d{dd.MM.yyyy HH:mm:ss.SSS} *%level* [%X{OurCorrelationHeader:-none}] [%thread] %logger %msg %ex%n"
      org.apache.sling.commons.log.file.size="'.'yyyy-MM-dd"
      org.apache.sling.commons.log.file="logs/error.log"
      org.apache.sling.commons.log.file.number="7"
      org.apache.sling.commons.log.level="info"
      org.apache.sling.commons.log.maxOldFileCountInDump="3"
      org.apache.sling.commons.log.numOfLines="10000"
      org.apache.sling.commons.log.maxCallerDataDepth="7"
      org.apache.sling.commons.log.packagingDataEnabled="{Boolean}false"/>

 

 

 

 

There is an existing log config file, which has this:

 

 

 

  "org.apache.sling.commons.log.pattern": "{0,date,yyyy-MM-dd HH:mm:ss.SSS {4} [{3}] {5}",

 

 

 

Which is the one being currently used, but when I try to add anything it might be, the logging goes back to a default format, and does not use this string any more.

I have tried many variations, including:

 

 

 

 

  "org.apache.sling.commons.log.pattern": "{0,date,yyyy-MM-dd HH:mm:ss.SSS} [%X{APPID:-NoAppId}] {4} [{3}] {5}",

 

 

 

 

and

 

 

 

 

  "org.apache.sling.commons.log.pattern": "{0,date,yyyy-MM-dd HH:mm:ss.SSS} mdc{} *{4} [{3}] {5}",

 

 

 

 

 

Replies

Avatar

Avatar
Applaud 25
Level 10
asutosh_jena
Level 10

Likes

593 likes

Total Posts

705 posts

Correct reply

207 solutions
Top badges earned
Applaud 25
Give Back 100
Boost 500
Affirm 100
Ignite 1
View profile

Avatar
Applaud 25
Level 10
asutosh_jena
Level 10

Likes

593 likes

Total Posts

705 posts

Correct reply

207 solutions
Top badges earned
Applaud 25
Give Back 100
Boost 500
Affirm 100
Ignite 1
View profile
asutosh_jena
Level 10

26-04-2021

Hi @TB3dock 

 

Please refer this link here:

https://blogs.perficient.com/2018/09/24/customized-logging-using-slf4j-mdc-in-aem/

 

Also there is no difference between the .xml and .json configuration. Both will have the same config and values. It's just the way the content is stored.

Hope this will work with minor changes as the article was written on AEM 6.3

 

/*
* Copyright 2015 Adobe Systems Incorporated
*
* Licensed under the Apache License, Version 2.0 (the "License");
* you may not use this file except in compliance with the License.
* You may obtain a copy of the License at
*
* http://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing, software
* distributed under the License is distributed on an "AS IS" BASIS,
* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
* See the License for the specific language governing permissions and
* limitations under the License.
*/
package com.adobe.aem.guides.wknd.core.filters;

import org.apache.sling.api.SlingHttpServletRequest;
import org.apache.sling.engine.EngineConstants;
import org.osgi.service.component.annotations.Component;
import org.osgi.service.component.propertytypes.ServiceDescription;
import org.osgi.service.component.propertytypes.ServiceRanking;
import org.osgi.service.component.propertytypes.ServiceVendor;
import org.slf4j.MDC;

import javax.servlet.*;
import java.io.IOException;

/**
* Simple servlet filter component that logs incoming requests.
*/
@Component(service = Filter.class,
property = {
EngineConstants.SLING_FILTER_SCOPE + "=" + EngineConstants.FILTER_SCOPE_REQUEST,
})
@ServiceDescription("Demo to filter incoming requests")
@ServiceRanking(-800)
@ServiceVendor("Adobe")
public class LoggingFilter implements Filter {

public static final String APPLICATION_ID = "appId";
private static final String[] MDC_CUSTOM_KEYS = {
APPLICATION_ID,
};

public void init(FilterConfig filterConfig) throws ServletException {
}

public void doFilter(ServletRequest servletRequest, ServletResponse servletResponse,
FilterChain filterChain) throws IOException, ServletException {
final SlingHttpServletRequest request = (SlingHttpServletRequest) servletRequest;
try {
insertIntoMDC(request);
filterChain.doFilter(request, servletResponse);
} finally {
clearMDC();
}
}

private void clearMDC() {
for (String key : MDC_CUSTOM_KEYS) {
MDC.remove(key);
}
}

private void insertIntoMDC(SlingHttpServletRequest request) {
//logic can go here to take value from request object.
// Can also utilize ResourceResolver from same request.
// If needed, can also write a generic OSGi Configuration
// (String Array Properties) to read from standard request objects,
// i.e cookies, headers, and parameters.
MDC.put(APPLICATION_ID, request.getParameter(APPLICATION_ID));
}

public void destroy() {
}

}

 

Thanks!

Avatar

Avatar
Affirm 5
Level 4
TB3dock
Level 4

Likes

37 likes

Total Posts

223 posts

Correct reply

5 solutions
Top badges earned
Affirm 5
Ignite 10
Boost 25
Give Back 25
Validate 10
View profile

Avatar
Affirm 5
Level 4
TB3dock
Level 4

Likes

37 likes

Total Posts

223 posts

Correct reply

5 solutions
Top badges earned
Affirm 5
Ignite 10
Boost 25
Give Back 25
Validate 10
View profile
TB3dock
Level 4

26-04-2021

Hi, thanks, but this is not the question. I already have a working filter, which sets the MDC variables, now I need to find out how to get the log appender to write these variables. I have this line in the log config file:

 

  "org.apache.sling.commons.log.pattern": "{0,date,yyyy-MM-dd HH:mm:ss.SSS {4} [{3}] {5}",

 

But when I try to add anything it might be, the logging goes back to a default format, and doesnt use this string any more.

I have tried many variations, including:

  "org.apache.sling.commons.log.pattern": "{0,date,yyyy-MM-dd HH:mm:ss.SSS} [%X{APPID:-NoAppId}] {4} [{3}] {5}",

and

  "org.apache.sling.commons.log.pattern": "{0,date,yyyy-MM-dd HH:mm:ss.SSS} mdc{} *{4} [{3}] {5}",

 

Avatar

Avatar
Applaud 25
Level 10
asutosh_jena
Level 10

Likes

593 likes

Total Posts

705 posts

Correct reply

207 solutions
Top badges earned
Applaud 25
Give Back 100
Boost 500
Affirm 100
Ignite 1
View profile

Avatar
Applaud 25
Level 10
asutosh_jena
Level 10

Likes

593 likes

Total Posts

705 posts

Correct reply

207 solutions
Top badges earned
Applaud 25
Give Back 100
Boost 500
Affirm 100
Ignite 1
View profile
asutosh_jena
Level 10

26-04-2021

The link I have shared above has an OSGi config which is written in .xml format. You can write the same in .json format and try with your own Java Filter.

Avatar

Avatar
Affirm 5
Level 4
TB3dock
Level 4

Likes

37 likes

Total Posts

223 posts

Correct reply

5 solutions
Top badges earned
Affirm 5
Ignite 10
Boost 25
Give Back 25
Validate 10
View profile

Avatar
Affirm 5
Level 4
TB3dock
Level 4

Likes

37 likes

Total Posts

223 posts

Correct reply

5 solutions
Top badges earned
Affirm 5
Ignite 10
Boost 25
Give Back 25
Validate 10
View profile
TB3dock
Level 4

26-04-2021

Hi, this is what I have been trying to do for 2 days. It appears there is no way to do this with the .cfg.json format, which uses {4} etc. and seems to have no support for mdc.

Avatar

Avatar
Applaud 25
Level 10
asutosh_jena
Level 10

Likes

593 likes

Total Posts

705 posts

Correct reply

207 solutions
Top badges earned
Applaud 25
Give Back 100
Boost 500
Affirm 100
Ignite 1
View profile

Avatar
Applaud 25
Level 10
asutosh_jena
Level 10

Likes

593 likes

Total Posts

705 posts

Correct reply

207 solutions
Top badges earned
Applaud 25
Give Back 100
Boost 500
Affirm 100
Ignite 1
View profile
asutosh_jena
Level 10

26-04-2021

Hi @TB3dock 

 

Let me also give a try and see if there is any luck!

Avatar

Avatar
Affirm 5
Level 4
TB3dock
Level 4

Likes

37 likes

Total Posts

223 posts

Correct reply

5 solutions
Top badges earned
Affirm 5
Ignite 10
Boost 25
Give Back 25
Validate 10
View profile

Avatar
Affirm 5
Level 4
TB3dock
Level 4

Likes

37 likes

Total Posts

223 posts

Correct reply

5 solutions
Top badges earned
Affirm 5
Ignite 10
Boost 25
Give Back 25
Validate 10
View profile
TB3dock
Level 4

26-04-2021

I did get the following working for a single line, however this XML version is useless for 2 reasons:

  1. you cant specify which classes get this log format (it only applies to our own servlet classes and the classes they call)
  2. it only works for the first log line in the servlet, all other log.x calls have an empty APPID in this case, even, though its set and should be logged for every log call.
  3. It worked only once, Now we cant get this to work at all, even if rebuilt/reboot server.

 

 

<?xml version="1.0" encoding="UTF-8"?>
<jcr:root xmlns:sling="http://sling.apache.org/jcr/sling/1.0" xmlns:cq="http://www.day.com/jcr/cq/1.0" xmlns:jcr="http://www.jcp.org/jcr/1.0" xmlns:nt="http://www.jcp.org/jcr/nt/1.0"
      jcr:primaryType="sling:OsgiConfig"
      org.apache.sling.commons.log.pattern="%d{dd.MM.yyyy HH:mm:ss.SSS} *%level* [%X{APPID:-NoAppId}] [%thread] %logger %msg %ex%n"
      org.apache.sling.commons.log.file.size="'.'yyyy-MM-dd"
      org.apache.sling.commons.log.file="logs/error.log"
      org.apache.sling.commons.log.file.number="7"
      org.apache.sling.commons.log.level="info"
      org.apache.sling.commons.log.maxOldFileCountInDump="3"
      org.apache.sling.commons.log.numOfLines="10000"
      org.apache.sling.commons.log.maxCallerDataDepth="7"
      org.apache.sling.commons.log.packagingDataEnabled="{Boolean}false"/>

 

 

Avatar

Avatar
Applaud 25
Level 10
asutosh_jena
Level 10

Likes

593 likes

Total Posts

705 posts

Correct reply

207 solutions
Top badges earned
Applaud 25
Give Back 100
Boost 500
Affirm 100
Ignite 1
View profile

Avatar
Applaud 25
Level 10
asutosh_jena
Level 10

Likes

593 likes

Total Posts

705 posts

Correct reply

207 solutions
Top badges earned
Applaud 25
Give Back 100
Boost 500
Affirm 100
Ignite 1
View profile
asutosh_jena
Level 10

26-04-2021

hi @TB3dock 

 

We have 2 different logger config here.

org.apache.sling.commons.log.LogManagerLog Writer Configuration is used to setup file output and log file rotation characteristics for log writers used by the Loggers.

org.apache.sling.commons.log.LogManager.factory.config - Logger configuration which will be used for the application specific log where you can define the classes and customize it.

 

If you add the formatting in org.apache.sling.commons.log.LogManager.factory.config it will be application only for your classes.

 

You can refer this for more info about logging:

https://sling.apache.org/documentation/development/logging.html

Avatar

Avatar
Affirm 5
Level 4
TB3dock
Level 4

Likes

37 likes

Total Posts

223 posts

Correct reply

5 solutions
Top badges earned
Affirm 5
Ignite 10
Boost 25
Give Back 25
Validate 10
View profile

Avatar
Affirm 5
Level 4
TB3dock
Level 4

Likes

37 likes

Total Posts

223 posts

Correct reply

5 solutions
Top badges earned
Affirm 5
Ignite 10
Boost 25
Give Back 25
Validate 10
View profile
TB3dock
Level 4

26-04-2021

Thanks, we have already read that document at least 10 times, it has no relevant information in that there is nothing about how to create a log format config entry which add mdc (we tried EVERY combination possile), and we also tried "hacking" it directly to the osgi config UIs, but the could SDK they are completely differnt to that document, and it doesnt work at all there either. In short, in the latest AEM cloud, there appears to be no way to get the MDC infomation, including the critical X-Correlation-token, into the log files.

All documentation and examples for MDC are for the old format, and nothing is documented or works with the new format

 

FYI, we are using the factory version.

 

/myapp.ui.config/src/main/content/jcr_root/apps/myapp/osgiconfig/config/org.apache.sling.commons.log.LogManager.factory.config~myapp.cfg.json

 

This file contains this:

 

  "org.apache.sling.commons.log.pattern": "{0,date,yyyy-MM-dd HH:mm:ss.SSS} {4} [{3}] {5}"

 

If we add something like hello:

 

  "org.apache.sling.commons.log.pattern": "{0,date,yyyy-MM-dd HH:mm:ss.SSS} hello {4} [{3}] {5}"

 

we see hello in the logs.

 

But as soon as we try to use anything MDC realteated, the log format is ingonred, and it goes back to some default one which has a different date format (dd-mm-yyyy)

 

Adding MDC to the json is completely undocumented, but we have made several guesses which dont work, including:

 

  "org.apache.sling.commons.log.pattern": "{0,date,yyyy-MM-dd HH:mm:ss.SSS} %mdc{APPID} *{4} [{3}] {5}",

 

  "org.apache.sling.commons.log.pattern": "{0,date,yyyy-MM-dd HH:mm:ss.SSS} ** %X{APPID:-noappid} *{4} [{3}] {5}",

 

etc. Nothing works.

Avatar

Avatar
Affirm 5
Level 4
TB3dock
Level 4

Likes

37 likes

Total Posts

223 posts

Correct reply

5 solutions
Top badges earned
Affirm 5
Ignite 10
Boost 25
Give Back 25
Validate 10
View profile

Avatar
Affirm 5
Level 4
TB3dock
Level 4

Likes

37 likes

Total Posts

223 posts

Correct reply

5 solutions
Top badges earned
Affirm 5
Ignite 10
Boost 25
Give Back 25
Validate 10
View profile
TB3dock
Level 4

26-04-2021

From the documentation, it appears that mdc logging is only supported by an old log format, which is no longer supported by AEM (cloud SDK):

 

To include the MDC value in log message you MUST use the [Logback pattern][15] based on Logback 
and not the old MessageFormat based pattern. 

    %d{dd.MM.yyyy HH:mm:ss.SSS} *%p* [%X{req.remoteHost}] [%t] %c %msg%n

This % based format is no longer used, or usable.

 

The new format is like this:

 

  "org.apache.sling.commons.log.pattern": "{0,date,yyyy-MM-dd HH:mm:ss.SSS} {4} [{3}] {5}",

And there appears to be no support in this format for mdc.