Как возможно, что StringBuilder.setLength(0) вызывает Arrays.fill?

При исследовании результата теста производительности я обнаружил следующую трассировку стека в Java Flight Recorder "Горячие методы":

Stack Trace                                        Sample Count Percentage(%)
-----------                                        ------------ ----------
java.util.Arrays.rangeCheck(int, int, int)                  358      2.212
   java.util.Arrays.fill(char[], int, int, char)            358      2.212
      java.lang.AbstractStringBuilder.setLength(int)        358      2.212
         java.lang.StringBuilder.setLength(int)             358      2.212
            org.apache.logging.log4j.core.async.RingBufferLogEvent.getMessageTextForWriting()
                                                            201      1.242
               org.apache.logging.log4j.core.async.RingBufferLogEvent.setMessage(Message)
                                                            201      1.242

Из трассировки стека это выглядит так, как если бы результат строки StringBuilder вызывался при вызове Arrays.fill. Однако я не понимаю, почему это происходит, потому что длина StringBuilder установлена ​​на ноль.

Глядя на код для метода Log4j RingBufferLogEvent.getMessageTextForWriting, ясно, что длина StringBuilder никогда не устанавливается ни на какое другое значение, кроме нуля:

// RingBufferLogEvent.java

private StringBuilder getMessageTextForWriting() {
    if (messageText == null) {
        messageText = new StringBuilder(Constants.INITIAL_REUSABLE_MESSAGE_SIZE); // 128
    }
    messageText.setLength(0); // <-- this call. Note: new length is ALWAYS zero.
    return messageText;
}

Я не понимаю, как это может привести к вызову Arrays.fill. Если посмотреть на код для AbstractStringBuilder, Arrays.fill должен вызываться только в том случае, если новая длина больше, чем предыдущее количество символов.

// AbstractStringBuilder.java

public void setLength(int newLength) {
    if (newLength < 0)
        throw new StringIndexOutOfBoundsException(newLength);
    ensureCapacityInternal(newLength);

    if (count < newLength) { // <-- how can this condition be true if newLength is zero?
        Arrays.fill(value, count, newLength, '\0');
    }

    count = newLength;
}

Как count < newLength когда-либо true когда newLength всегда равен нулю?

Версия JVM:

Java HotSpot (TM) 64-разрядная серверная VM (25.144-b01) для linux-amd64 JRE (1.8.0_144-b01), построенная 21 июля 2017 21:57:33 с помощью "java_re" с gcc 4.3.0 20080428 (Red Hat 4.3.0-8)

(и Log4j 2.10.0)

Ответы

Ответ 1

Возникла проблема с JFR. Он собирает трассировки стека асинхронно, то есть не только в таких местах, как многие другие профилировщики. С одной стороны, это делает выборку более реалистичной, поскольку нет смещения safepoint. С другой стороны, JVM HotSpot не может правильно ходить в стеке в любой случайный момент времени.

Частный API HotSpot AsyncGetCallTrace пытается сделать все возможное, чтобы восстановить текущую трассировку стека из любой произвольной точки, где сигнал таймера прервал приложение. Однако некоторые места в коде небезопасны для ходьбы в стеке. Если в одном из этих мест вызывается AsyncGetCallTrace, он может возвращать неверную трассировку стека или трассировку стека вообще.

Это известная проблема AsyncGetCallTrace. JDK-8022893 содержит примеры и анализ проблемы. Довольно часто ситуация, когда AsyncGetCallTrace (и все профилировщики основаны на ней) возвращает неточную трассу, где некоторые фреймы ошибочно заменяются соседними методами.