slf4j logger using logback logs multiple times depending on the number of threads

1.5k Views Asked by At

I am using Spring. When a request comes from a controller, I create multiple threads and log content in these threads. However, the content gets logged 2 times for the second thread, 3 times for the third thread and so on.

It might get written multiple times in all the log files if the threads are async.

Also, I am not able to delete the log files until I stop Tomcat.

Below is my code:

LogUtil.java

public class LogUtil {


    public static Marker getMarker() {
        Marker marker = MarkerFactory.getMarker("Finalize");
        marker.add(ClassicConstants.FINALIZE_SESSION_MARKER);
        return marker;
    }

    public static void addSiftingAppender(org.slf4j.Logger log) {

        LoggerContext lc = (LoggerContext) LoggerFactory.getILoggerFactory();

        Logger logger = lc.getLogger(log.getName());

        SiftingAppender sa = new SiftingAppender();
        sa.setName("SIFT");
        sa.setContext(lc);

        MDCBasedDiscriminator discriminator = new MDCBasedDiscriminator();
        discriminator.setKey("logFileName");
        discriminator.setDefaultValue("batch0");
        discriminator.start();

        sa.setDiscriminator(discriminator);

        sa.setAppenderFactory(new AppenderFactory<ILoggingEvent>() {

            @Override
            public Appender<ILoggingEvent> buildAppender(Context context,
                    String discriminatingValue) throws JoranException {
                FileAppender<ILoggingEvent> appender = new FileAppender<ILoggingEvent>();
                appender.setName("BATCH-EXECUTION-" + discriminatingValue);
                appender.setContext(context);
                appender.setFile(discriminatingValue + ".log");
                appender.setAppend(true);
                if (appender.isStarted()) {
                    appender.stop();
                }

                PatternLayoutEncoder pl = new PatternLayoutEncoder();
                pl.setContext(context);
                pl.setPattern("%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n");
                pl.setImmediateFlush(true);
                if (pl.isStarted()) {
                    pl.stop();
                }
                pl.start();
                appender.setEncoder(pl);

                appender.start();
                return appender;
            }
        });
        if (sa.isStarted()) {
            sa.stop();
        }
        sa.start();
        logger.addAppender(sa);
    }

}

Head.java

public class Head implements Runnable {

    // static Logger logger = LoggerFactory.getLogger(Head.class);

    private Logger log;

    private String name;

    Head(Logger logger, String name) {
        this.log = logger;
        this.name = name;
    }

    @Override
    public void run() {
        LogUtil.addSiftingAppender(log);
        MDC.put("logFileName", getName());
        try {
            Thread.sleep(5000);
        } catch (InterruptedException e) {
            // TODO Auto-generated catch block
            e.printStackTrace();
        }

        log.info("something" + getName());
        log.info(LogUtil.getMarker(), "ended");
        MDC.remove("logFileName");

    }

    public String getName() {
        return name;
    }

    public void setName(String name) {
        this.name = name;
    }

    public void setLogger(Logger log) {
        this.log = log;
    }

}

IfxDesignerController

@Slf4j
public class IfxDesignerController{

 @RequestMapping(value = "/testsomething", method = RequestMethod.GET,
            produces = MediaType.APPLICATION_JSON_VALUE)
    public @ResponseBody String
            testsomething()
                    throws IllegalStateException, IOException {

        ExecutorService executor = Executors.newCachedThreadPool();

        int count2 = 1;
        while (count2 <= 2) {
            Head head = new Head(log, "somename" + count2);
            head.setName("head-nested" + count2);
            head.setLogger(log);
            executor.execute(head);
            count2++;
        }
        return null;
    }

}

The log files generated when I make a GET request to testsomething are as follows:

head-nested1.log

10:15:50.869 [pool-217-thread-1] INFO  c.w.c.h.c.c.i.d.IfxDesignerController - somethinghead-nested1
10:15:50.869 [pool-217-thread-1] INFO  c.w.c.h.c.c.i.d.IfxDesignerController - somethinghead-nested1
10:15:50.887 [pool-217-thread-1] INFO  c.w.c.h.c.c.i.d.IfxDesignerController - ended
10:15:50.887 [pool-217-thread-1] INFO  c.w.c.h.c.c.i.d.IfxDesignerController - ended

head-nested2.log

10:15:50.955 [pool-217-thread-2] INFO  c.w.c.h.c.c.i.d.IfxDesignerController - somethinghead-nested2
10:15:50.955 [pool-217-thread-2] INFO  c.w.c.h.c.c.i.d.IfxDesignerController - somethinghead-nested2
10:15:50.957 [pool-217-thread-2] INFO  c.w.c.h.c.c.i.d.IfxDesignerController - ended
10:15:50.957 [pool-217-thread-2] INFO  c.w.c.h.c.c.i.d.IfxDesignerController - ended

What changes should I make in the logback configuration so that the output is as follows (Desired Output):

head-nested1.log

10:15:50.869 [pool-217-thread-1] INFO  c.w.c.h.c.c.i.d.IfxDesignerController - somethinghead-nested1
10:15:50.887 [pool-217-thread-1] INFO  c.w.c.h.c.c.i.d.IfxDesignerController - ended

head-nested2.log

10:15:50.955 [pool-217-thread-2] INFO  c.w.c.h.c.c.i.d.IfxDesignerController - somethinghead-nested2
10:15:50.957 [pool-217-thread-2] INFO  c.w.c.h.c.c.i.d.IfxDesignerController - ended

Also, I should be able to delete the log files after thread execution

0

There are 0 best solutions below