logback не регистрировать исключение в файле, который выброшен из потока пула ThreadPoolTaskExecutor

У меня проблема с проводкой, похоже, что журнал выводит только мою трассировку стека исключений на консоли, а не регистрирует ее в файле журнала. Ниже приведены мои экспериментальные коды. Я использовал весенний загрузочный тест с двумя пулами потоков, которые имитируют мои производственные коды. Оба потока печатают журнал и выдают исключение RuntimeException. Но информация об исключении печатается только на консоли, а не регистрируется в файл . Вот мой код:

@Autowired
  private ThreadPoolTaskExecutor goodsCommissionJobPool;
  @Autowired
  private ThreadPoolTaskExecutor goodsCommissionAlertPool;
  @Test
  public void test() {

    goodsCommissionJobPool.execute(() -> {
      log.info("first level..");
      goodsCommissionAlertPool.execute(() -> {
        log.info("second level..");
        throw new RuntimeException("funny error");
      });
      throw new RuntimeException("first error");
    });

    try {
      Thread.sleep(5000);
    } catch (InterruptedException e) {
      e.printStackTrace();
    }
  }

Моя конфигурация ThreadPoolTaskExecutor:

  @Bean
  public ThreadPoolTaskExecutor goodsCommissionJobPool() {
    ThreadPoolTaskExecutor pool = new ThreadPoolTaskExecutor();
    pool.setThreadNamePrefix("Goods_Commission_Job_");
    pool.setWaitForTasksToCompleteOnShutdown(true);
    pool.setAwaitTerminationSeconds(10);
    pool.setQueueCapacity(1000);
    pool.setMaxPoolSize(8);
    pool.setCorePoolSize(4);
    pool.setKeepAliveSeconds(60);
    return pool;
  }

  @Bean
  public ThreadPoolTaskExecutor goodsCommissionAlertPool() {
    ThreadPoolTaskExecutor pool = new ThreadPoolTaskExecutor();
    pool.setThreadNamePrefix("Goods_Commission_Alert_");
    pool.setQueueCapacity(10);
    pool.setMaxPoolSize(4);
    pool.setCorePoolSize(1);
    pool.setKeepAliveSeconds(60);
    pool.setRejectedExecutionHandler(new DiscardPolicy());
    return pool;
  }

лог в консоли:

2021-06-03 11:02:59.594 +0800 [Goods_Commission_Job_1] INFO  [com.dada.inviter.logic.LocalTest] [LocalTest.java:35] - first level..
2021-06-03 11:02:59.595 +0800 [Goods_Commission_Alert_1] INFO  [com.dada.inviter.logic.LocalTest] [LocalTest.java:37] - second level..
Exception in thread "Goods_Commission_Job_1" java.lang.RuntimeException: first error
    at com.dada.inviter.logic.LocalTest.lambda$test$1(LocalTest.java:40)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at java.lang.Thread.run(Thread.java:748)
Exception in thread "Goods_Commission_Alert_1" java.lang.RuntimeException: funny error
    at com.dada.inviter.logic.LocalTest.lambda$null$0(LocalTest.java:38)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at java.lang.Thread.run(Thread.java:748)

Лог в файле (всего два инфо лога):

2021-06-03 11:02:59.594 +0800 [Goods_Commission_Job_1] INFO  [com.dada.inviter.logic.LocalTest] [LocalTest.java:35] - first level..
2021-06-03 11:02:59.595 +0800 [Goods_Commission_Alert_1] INFO  [com.dada.inviter.logic.LocalTest] [LocalTest.java:37] - second level..

И моя конфигурация журнала:

<?xml version="1.0" encoding="UTF-8"?>

<configuration>

    <springProperty scope="context" name="appName" source="app.name"/>
    <springProperty scope="context" name="log.level" source="log.level" defaultValue="INFO" />

    <springProperty scope="context" name="envName" source="spring.profiles.active"/>

    <if condition='property("envName").equalsIgnoreCase("local")'>
        <then>
            <property name="log.filePath" value="logs/${appName}"/>
        </then>
        <else>
            <property name="log.filePath" value="/data/logs/java/${appName}"/>
        </else>
    </if>

    <property name="log.pattern"
              value="%date{yyyy-MM-dd HH:mm:ss.SSS Z} [%thread] %-5p [%c] [%F:%L] - %msg%n" />

    <property name="logName" value="inviter-settle" />

    <appender name="infoAppender"
        class="ch.qos.logback.core.FileAppender">
        <file>${log.filePath}/${logName}_info.log</file>
        <append>true</append>
        <encoder>
            <pattern>${log.pattern}</pattern>
        </encoder>
    </appender>

    <!-- ERROR -->
    <appender name="errorAppender"
        class="ch.qos.logback.core.FileAppender">
        <file>${log.filePath}/${logName}_error.log</file>
        <append>true</append>

        <encoder>
            <pattern>${log.pattern}</pattern>
        </encoder>
        <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
            <level>ERROR</level>
        </filter>
    </appender>

    <!-- console -->
    <appender name="consoleAppender" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>${log.pattern}</pattern>
        </encoder>
    </appender>

    <!-- rpc -->
    <appender name="rpcAppender"
              class="ch.qos.logback.core.FileAppender">
        <file>${log.filePath}/${logName}_rpcStats.log</file>
        <append>true</append>
        <encoder>
            <pattern>%msg%n</pattern>
        </encoder>
    </appender>

    <logger name="com.dada.base.registry.stats.RpcStatsUtil" level="INFO">
        <appender-ref ref="rpcAppender" />
    </logger>

    <root level="${log.level}">
        <appender-ref ref="infoAppender" />
        <appender-ref ref="errorAppender" />
        <appender-ref ref="consoleAppender" />
    </root>

</configuration>


person Khirye Zhou    schedule 03.06.2021    source источник


Ответы (2)


Меня вдохновил этот вопрос: Журнал исключений во время выполнения в Java с использованием log4j В классе JDK Thread есть поле UncaughtExceptionHandler;

private volatile UncaughtExceptionHandler uncaughtExceptionHandler;

Все, что мне нужно, это переопределить метод ThreadGroup, установить UncaughtExceptionHandler в каждом потоке моего пула, и тогда моя конфигурация ThreadPoolTaskExecutor будет выглядеть так:

@Bean
  public ThreadPoolTaskExecutor goodsCommissionJobPool() {
    ThreadPoolTaskExecutor pool = new ThreadPoolTaskExecutor();
    pool.setThreadNamePrefix("Goods_Commission_Job_");
    pool.setWaitForTasksToCompleteOnShutdown(true);
    pool.setAwaitTerminationSeconds(10);
    pool.setQueueCapacity(1000);
    pool.setMaxPoolSize(8);
    pool.setCorePoolSize(4);
    pool.setKeepAliveSeconds(60);
    pool.setThreadFactory(new ThreadFactory() {
      private AtomicInteger threadCount = new AtomicInteger(0);
      @Override
      public Thread newThread(Runnable r) {
        Thread thread = new Thread(pool.getThreadGroup(), r,
            pool.getThreadNamePrefix() + threadCount.getAndIncrement());
        thread.setPriority(pool.getThreadPriority());
        thread.setDaemon(pool.isDaemon());
        thread.setUncaughtExceptionHandler((t, e) -> {
          log.error("", e);
        });
        return thread;
      }
    });
    return pool;
  }

  @Bean
  public ThreadPoolTaskExecutor goodsCommissionAlertPool() {
    ThreadPoolTaskExecutor pool = new ThreadPoolTaskExecutor();
    pool.setThreadNamePrefix("Goods_Commission_Alert_");
    pool.setQueueCapacity(10);
    pool.setMaxPoolSize(4);
    pool.setCorePoolSize(1);
    pool.setKeepAliveSeconds(60);
    pool.setRejectedExecutionHandler(new DiscardPolicy());
    pool.setThreadFactory(new ThreadFactory() {
      private AtomicInteger threadCount = new AtomicInteger(0);
      @Override
      public Thread newThread(Runnable r) {
        Thread thread = new Thread(pool.getThreadGroup(), r,
            pool.getThreadNamePrefix() + threadCount.getAndIncrement());
        thread.setPriority(pool.getThreadPriority());
        thread.setDaemon(pool.isDaemon());
        thread.setUncaughtExceptionHandler((t, e) -> {
          log.error("", e);
        });
        return thread;
      }
    });
    return pool;
  }
person Khirye Zhou    schedule 03.06.2021

e.printStackTrace(); выводится только в стандартную ошибку, а именно в консоль. Это считается ошибкой безопасности, поскольку у вас может не быть контроля над stderr, что приводит к утечке информации о вашей системе. Чтобы записать исключение в файл, вы можете использовать

} catch (InterruptedException e) {
    log.error("Some error message: ",e);
}
person LMC    schedule 03.06.2021