TestNG + Log4j Проблема с логированием тестов запущенных параллельно средствами testng

программирование java
, , ,
#1

Доброго дня всем, возник вопрос.
Запускаю тесты с помощью TestNG параллельно (parallel=“tests”) сами тесты успешно работают параллельно, но легирование отказывается работать корректно(в одном потоке логирование работает исправно)

Для наглядности, покажу проблему на простом примере.

Есть два теста, вынесенные каждый в отдельный класс:

class Test_1

@Test()
public void test1() {
    System.out.println("Проверка что Test 1 запустился");
    Logger logger = LogManager.getLogger(getClass().getSimpleName());
    logger.info("Run Test 1");
    LogTest log = new LogTest();
    log.writeLog();
}

class Test_2

@Test()
public void test2() {
    System.out.println("Проверка что Test 2 запустился");
    Logger logger = LogManager.getLogger(getClass().getSimpleName());
    logger.info("Run Test 2");
    LogTest log = new LogTest();
    log.writeLog();
}

Метод который вызывают тесты:

class LogTest

void writeLog() {
    String TestCase = Thread.currentThread().getStackTrace()[2].getClassName();
    Logger logger = LogManager.getLogger(TestCase);
    for(int i =0; i<5; i++) {
        logger.info("Class " + TestCase + " Step " + i);
    }
}

При запуске тестов с параметром parallel=“false” логер работает исправно и выдает что то на вроде:

2017-10-24 INFO [main] - Run Test 1
2017-10-24 INFO [main] - Class Test_1 Step 0
2017-10-24 INFO [main] - Class Test_1 Step 1
2017-10-24 INFO [main] - Class Test_1 Step 2
2017-10-24 INFO [main] - Class Test_1 Step 3
2017-10-24 INFO [main] - Class Test_1 Step 4
2017-10-24 INFO [main] - Run Test 2
2017-10-24 INFO [main] - Class Test_2 Step 0
2017-10-24 INFO [main] - Class Test_2 Step 1
2017-10-24 INFO [main] - Class Test_2 Step 2
2017-10-24 INFO [main] - Class Test_2 Step 3
2017-10-24 INFO [main] - Class Test_2 Step 4

Но стоит поменять параметр TestNG на параллельный запуск parallel=“tests”, логер ломается, и логирует:

2017-10-24 INFO [TestNG-tests-2] - Run Test 2
2017-10-24 INFO [TestNG-tests-2] - Class Test_2 Step 0
2017-10-24 INFO [TestNG-tests-2] - Class Test_2 Step 1
2017-10-24 INFO [TestNG-tests-2] - Class Test_2 Step 2
2017-10-24 INFO [TestNG-tests-2] - Class Test_2 Step 3
2017-10-24 INFO [TestNG-tests-2] - Class Test_2 Step 4

При этом оба теста, сами по себе продолжают исправно работать.

Мб кто знает в чем проблема, вероятно нужна какая то специфическая конфигурация логераю, но в конфигурации Log4j я не силен.

1 лайк
#2

Вот человек пытался решить ту же проблему GitHub - realfun/testng-and-log4j-multiple-thread-logging

Disclaimer: Я не пробовал это решение

1 лайк
#3 
private static Map<Long, Logger> threadLoggers = new HashMap();

    public static void setLogFileName(String testName) {
        final FileAppender fileAppender = new FileAppender();
        fileAppender.setName("FileLogger");
        fileAppender.setFile(LOG_PATH + testName + ".log");
        fileAppender.setLayout(new PatternLayout(
                "%d{dd MMM yyyy HH:mm:ss} %-5p [%t]: %m%n"));
        fileAppender.setAppend(false);
        fileAppender.activateOptions();
        Logger logger = Logger.getLogger(testName);
        logger.setAdditivity(true);
        logger.addAppender(fileAppender);
        threadLoggers.put(Thread.currentThread().getId(), logger);
    }


    private static void setDefaultLogger() {
        if (getLoggerObject() == null) {
            setLogFileName(Thread.currentThread().getStackTrace()[2].getClassName());
        }
    }

    private static Logger getLoggerObject() {
        return threadLoggers.get(Thread.currentThread().getId());
    }

    public static void warn(Object message) {
        setDefaultLogger();
        getLoggerObject().warn(message);
    }

Логирует конкретный тест или класс из конкретного потока
testName прокидываете из листенера

1 лайк
#4

Спасибо за помощь, буду пробовать.