为什么这个堆栈跟踪没有在日志中以这一行开头？

Question

亲爱的，

我有这个代码：(Move.java)

public void execute(ArrayList<Move> performedMoves) {

    logger.debug(Thread.currentThread().getName() + " executing: from: " + from.getX() + ", " + from.getY() + " -> "
            + to.getX() + ", " + to.getY() + " p: " + piece.getShortDebug() + "->" + piece.executed + ", "
            + piece.rollbacked + ";" + "|" + piece.getCurrentPlace().getX() + ", "
            + piece.getCurrentPlace().getY());

    if (executed && !rollbacked) {

        throw new RuntimeException("this shouldn't be...");
    }

    //(more code)

    from.remove(piece); // line 111, throwing the exception

    to.setPiece(piece);

    piece.setCurrentPlace(to);

这是日志：

2021-03-07 11:12:57 DEBUG Move:195 - Thread-3 rollBack: from: 0, 2 -> 1, 2 p: t->true, false|0, 2
2021-03-07 11:12:57 DEBUG Move:148 - Thread-3 rollBack: from: 2, 1 -> 1, 2 p: p->true, false|1, 2
2021-03-07 11:12:57 DEBUG Move:156 - Thread-3 false, false|1, 2
2021-03-07 11:12:57 DEBUG Move:168 - Thread-3 false, false|1, 2
2021-03-07 11:12:57 DEBUG Move:195 - Thread-3 rollBack: from: 2, 1 -> 1, 2 p: p->true, false|2, 1
Exception in thread "Thread-3" org.bamboomy.c44.board.IllegalPlaceException: this piece wasn't here :-( -> 2, 0 == 2, 9=>t->true, true
        at org.bamboomy.c44.board.Place.remove(Place.java:190)
        at org.bamboomy.c44.board.Move.execute(Move.java:111)
        at org.bamboomy.c44.board.Robot$Agent.evaluate(Robot.java:753)
        at org.bamboomy.c44.board.Robot$Agent.evaluate(Robot.java:772)
        at org.bamboomy.c44.board.Robot$Agent.evaluate(Robot.java:772)
        at org.bamboomy.c44.board.Robot$Agent.evaluate(Robot.java:772)
        at org.bamboomy.c44.board.Robot$Agent.run(Robot.java:608)
        at java.base/java.lang.Thread.run(Thread.java:834)
2021-03-07 11:12:58 DEBUG Robot:374 - 0:-1.7976931348623157E308
2021-03-07 11:12:58 DEBUG Robot:374 - 1:-1.7976931348623157E308

为什么日志中的stacktrace前面有：

2021-03-07 11:12:57 DEBUG Move:195 - Thread-3 rollBack: from: 2, 1 -> 1, 2 p: p->true, false|2, 1

而不是像这样的东西：

2021-03-07 11:12:57 DEBUG Move:195 - Thread-3 executing: from: 2, 1 -> 1, 2 p: p->true, false|2, 1

（抛出异常前的日志条目）？

（“回滚”调试条目是在同一个 class 中的另一个方法中完成的）

还有：

如果由于某些同步问题，例如此日志条目被吞没（我想是这样的事情）：我如何强制或刷新记录器以便我可以获得该调试消息的输出？

这是非常有价值的信息，对我调试复杂问题有很大帮助...

感谢reading/pointers...

S.

编辑：我使用 log4j 1.2.17

记录器是这样初始化的：

final static Logger logger = Logger.getLogger(Move.class);

Answer 1

该输出通过 Thread::getUncaughtExceptionHandler 直接发送到 System.err。

根据 OpenJDK ThreadGroup::uncaughtException

public void uncaughtException(Thread t, Throwable e) {
    if (parent != null) {
        parent.uncaughtException(t, e);
    } else {
        Thread.UncaughtExceptionHandler ueh =
            Thread.getDefaultUncaughtExceptionHandler();
        if (ueh != null) {
            ueh.uncaughtException(t, e);
        } else if (!(e instanceof ThreadDeath)) {
            System.err.print("Exception in thread \""
                             + t.getName() + "\" ");
            e.printStackTrace(System.err);
        }
    }
}

当抛出未捕获的异常并转义当前线程的运行方法时，此代码绕过您的日志记录框架并直接打印到 System.err。

如果您希望代码包含时间戳，您必须执行以下操作之一：

在您的应用程序启动时实施 Thread.UncaughtExceptionHandler which logs to your logging framework. Then attach it to the all threads or a subset of threads。请记住，在具有复杂类加载器结构的环境中，此处理程序可以固定类加载器并导致内存泄漏。良好的代码卫生是在您的应用程序将要关闭时删除这些处理程序。
在您的运行nable 或 callable 实现中捕获 Throwable 并将其记录到您的日志框架。

为什么这个堆栈跟踪没有在日志中以这一行开头？

How come this stacktrace isn't preceded by this line in the logs?

java

logging

synchronization