Java/Android : I don't understand why this is slower than expected

Question

我有这个方法:

@DebugLog
private synchronized int insertInOrderedFromBottom(ItemWithTime itemWithTime, ArrayList<ItemWithTime> array) {
    long start = System.currentTimeMillis();
    if (itemWithTime == null || itemWithTime.getDateTime() == null) return -1;
    if (array == null) return -1;
    int arraySize = array.size();
    for (int i = arraySize - 1; i >= 0; i--) {
        if (itemWithTime.getDateTime().isBefore(array.get(i).getDateTime())) {
            i++;
            array.add(i, itemWithTime);
            long end = System.currentTimeMillis();
            Log.d(TAG,"insertInOrderedFromBottom inside took "+(end-start));
            return i;
        }
    }
    array.add(itemWithTime);
    long end = System.currentTimeMillis();
    Log.d(TAG,"insertInOrderedFromBottom inside took "+(end-start));
    return array.size();
}

现在，您可以看到我用来测量此方法完成所需时间的日志语句:

• 日志显示完成该过程大约需要 0 磨坊。

我这样调用该方法:

start = System.currentTimeMillis();
insertInOrderedFromBottom(datum, items);
end = System.currentTimeMillis();
Log.d(TAG, "insertInOrderedFromBottom invoication took " + (end - start) + " ms");

• 此处日志显示需要 10-15 磨机。

发生了什么事？我在这里缺少什么？

编辑

我尝试过不同步，没有区别。

Answer 1

android 日志功能相当慢。因此，如果您在内循环中有一个打印时间差的日志，那么它本身将花费几毫秒的时间。因此，最后的输出时序反射(reflect)了在内循环中执行 Log.d 所需的时间