java – Log4j – Create multiple logs but randomly write to only one when using parallel execution

Question:

The problem I have is that when using Log4j during a parallel execution of several processes, it creates a log for each of the processes, but writes all the output in one of them randomly. It is written in groovy.

This is my .properties :

log4j.rootLogger=ERROR,  INFO, DEBUG

Define which packages use which appenders
Custom Appenderlog4j.appender.customLogger=org.apache.log4j.RollingFileAppender
log4j.appender.customLogger.File=/dummy
log4j.appender.customLogger.MaxFileSize=3000KB
log4j.appender.customLogger.MaxBackupIndex=15
log4j.appender.customLogger.layout=org.apache.log4j.PatternLayout
log4j.appender.customLogger.layout.ConversionPattern=[%5p] %d [%c{1}] (%F:%M:%L)%n%m%n%n

And this my logger.groovy :

class CustomLogin {

    def conf
    def log4javaProp

    def getCustomLogger (conf, name)
    {
        Log log = LogFactory.getLog(org.apache.log4j.ConsoleAppender);

        Properties props = new Properties();

        try {
            if (conf['LOG_CONFIG']['LOG4JAVA'] != null) {
                log4javaProp = "/" + conf['LOG_CONFIG']['LOG4JAVA']
            } else {
                log4javaProp = "/CustomLog4j.properties"
            }
            InputStream configStream = getClass().getResourceAsStream(log4javaProp);
            props.load(configStream);
            configStream.close();
        } catch (IOException e) {
            throw new IOException(" FATAL: CustomLog4j.propertiess NOT FOUND");
        }

        props.setProperty("log4j.rootLogger", "INFO, customLogger");

        //Obtener PID
        java.lang.management.RuntimeMXBean runtime = java.lang.management.ManagementFactory.getRuntimeMXBean();
        java.lang.reflect.Field jvm = runtime.getClass().getDeclaredField("jvm");
        jvm.setAccessible(true);

        sun.management.VMManagement mgmt = (sun.management.VMManagement) jvm.get(runtime);
        java.lang.reflect.Method pid_method = mgmt.getClass().getDeclaredMethod("getProcessId");
        pid_method.setAccessible(true);

        int pid = (Integer) pid_method.invoke(mgmt);
        //FIN PID

        //Indicamos el nombre del archivo donde se va a guardar el log
        def filepath =  "log/"+conf['LOG_CONFIG']['LOG_DIR']+"/";

        props.setProperty("log4j.appender.customLogger.File", filepath + name + "_" + pid + "_" + System.currentTimeMillis() + ".log");
        //LogManager.resetConfiguration();
        PropertyConfigurator.configure(props);

    }

    def destroyCustomLogger(conf) {
        org.apache.log4j.Logger.getRootLogger().removeAppender("customLogger");
    }
}

I'm launching to test an import with sqoop that does 3 imports in parallel and these are the logs that it writes to me:

426 Jun 22 11:01 main
0 Jun 22 11:01 Sqoop x1.log
0 Jun 22 11:01 Sqoop x2.log
8356 Jun 22 11:02 Sqoop x3.log

I want it to write the output of each of the exports that are made in parallel in their corresponding log, and not the 3 outputs together in one of them randomly for each execution.

Answer:

What you need in this case, is an appender for each Thread or Process that you execute:

Log4j lives at the Classloader level. So since you are regenerating the configuration for each of the threads, Log4j always takes this as a configuration rewrite.

A possible solution is that each Process has its own Appender, to achieve this, you could use the ID of the thread. I have not tested it, but it would be something like the following:

class CustomLogin {

   def conf
   def log4javaProp

   def getCustomLogger (conf, name)
   {
       Log log = LogFactory.getLog(org.apache.log4j.ConsoleAppender);

       Properties props = new Properties();

       try {
           if (conf['LOG_CONFIG']['LOG4JAVA'] != null) {
               log4javaProp = "/" + conf['LOG_CONFIG']['LOG4JAVA']
           } else {
               log4javaProp = "/CustomLog4j.properties"
           }
           InputStream configStream = getClass().getResourceAsStream(log4javaProp);
           props.load(configStream);
           configStream.close();
       } catch (IOException e) {
           throw new IOException(" FATAL: CustomLog4j.propertiess NOT FOUND");
       }

       def idThread = Thread.currentThread().getId()
       def strCustomAppender = "customAppender" + idThread
       props.setProperty("log4j.currentLogger." +  idThread, "INFO, " + strCustomAppender);

       //Obtener PID
       java.lang.management.RuntimeMXBean runtime = java.lang.management.ManagementFactory.getRuntimeMXBean();
       java.lang.reflect.Field jvm = runtime.getClass().getDeclaredField("jvm");
       jvm.setAccessible(true);

       sun.management.VMManagement mgmt = (sun.management.VMManagement) jvm.get(runtime);
       java.lang.reflect.Method pid_method = mgmt.getClass().getDeclaredMethod("getProcessId");
       pid_method.setAccessible(true);

       int pid = (Integer) pid_method.invoke(mgmt);
       //FIN PID

       //Indicamos el nombre del archivo donde se va a guardar el log
       def filepath =  "log/"+conf['LOG_CONFIG']['LOG_DIR']+"/";

       props.setProperty("log4j.appender."+strCustomAppender+".File", filepath + name + "_" + pid + "_" + System.currentTimeMillis() + ".log");
       //LogManager.resetConfiguration();
       PropertyConfigurator.configure(props);

   }

   def destroyCustomLogger(conf) {
       org.apache.log4j.Logger.getRootLogger().removeAppender("customLogger");
   }
}

Although, the configuration still needs to be added to each of the Appenders, this configuration can be removed from the props object with each of the properties that you configure in the properties file as follows: props.getProperty('log4j.appender.customLogger.MaxFileSize')

Post Views: 1
Scroll to Top