Ошибка округления, или currentTimeMills + nanoTime ошибаются?

Рейтинг: 3Ответов: 2Опубликовано: 18.07.2023

Есть задача - собирать таймштампы с точностью хотябы до микросекунд (беру нано, так как из-коробки можно использовать System.nanoTime()), не потому что важна точность, а потому что важно чёткое понимание последовательности. Почему взято время? Потому что оно в любом случае используется, и настроено на всех машинах, где выполняется этот код, значит от него можно относительно точно отталкиваться без потерь в производительности.

Извлекать время решил таким образом:

public static Timestamp getCurrentTimestamp() {
    Timestamp timestamp = new Timestamp(System.currentTimeMillis());
    timestamp.setNanos((int) (System.nanoTime() % 1000000000));
    return timestamp;
}

Почему currentTimeMillis? - Потому что java.sql.Timestamp не построить иначе, только через миллисекунды. А так как нужна хоть какая то точность (мне важно чтобы две операции были последовательны, не важно, например, если конечное время будет с погрешностью в 1 милисекунду, важно что если "б" выполнялось после "а", чтобы по времени это чётко было видно), затем добавляю наносекунды.

Далее всё попадает в БД. Где, о чудо, я вижу что единичные операции залогированны в другой последовательности!

Несколько дней ломал голову что происходит, пока не написал юниттест, который всё прояснил, вот пример происходящего:

public static void main(String[] args) {
    final int COUNT = 10000000;
    List<Timestamp> times = new ArrayList<>(COUNT);
    for(int i = 0; i < COUNT; i++) {
        times.add(getCurrentTimestamp());
    }
    Timestamp prev = times.get(0);
    for(int i = 1; i< COUNT; i++) {
        Timestamp current = times.get(i);
        if(current.before(prev)) {
            System.out.println("iteration " + i + ", curr: " + current.toInstant() + ", prev: " + prev.toInstant());
        }
        prev = current;
    }
}

public static Timestamp getCurrentTimestamp() {
    Timestamp timestamp = new Timestamp(System.currentTimeMillis());
    timestamp.setNanos((int) (System.nanoTime() % 1000000000));
    return timestamp;
}

Кратко - тест показывает что в определённый момент времени, очередное логирование таймштампа, ВНЕЗАПНО, показывает время в прошлом. Вот результат вывода в консоль:

iteration 6169721, curr: 2023-07-18T12:28:00.103141700Z, prev: 2023-07-18T12:28:00.997348300Z

В идеальном примере - консоль обязана быть чистой. Та же ситуация происходит и в юниттестах, они не проходят на достаточно больших выборках.

Подскажите, как более точно считать время, при этом, не допускать считываний и расчёта времени, после которых очередное извлечение штампа приводят в прошлое?

Ответы

▲ 4Принят

Время 999 миллисекунд и 999 наносекунд. System.currentTimeMillis() возвращает 999.

Прошла одна наносекунда. Время 1000 миллисекунд и 0 наносекунд. System.nanoTime() возвращает 0.

Комбинируем два отсчёта и получаем 999 миллисекунд и 0 наносекунд. Мы оказались в прошлом примерно на одну миллисекунду.

Ещё одна сложность состоит в том что вот такой код не всегда работает правильно:

Timestamp ts = new Timestamp(ms);
ts.setNanos((int)ns);

Здесь предполагается что время в наносекундах ns содержит уточняющую добавку ко времени в ms. Это не так, вызов setNanos стирает часть ms не кратную 1000. Если в ms было значение 999, а в ns - ноль, вы получите ноль на выходе. Вы прыгнули в прошлое. Размер прыжка может достигать одной секунды.

Чтобы прыжка не было, нужно сделать ms кратной тысяче. А все излишки переложить в ns. Тогда код выше первым вызовом установит целые секунды, а вторым вызовом добавит к ним наносекунды.

Вот рабочий код:

private static long baseMs;
private static long baseNs;
static {
    long ns0 = System.nanoTime();
    baseMs = System.currentTimeMillis();
    long ns1 = System.nanoTime();
    baseNs = ns0 + (ns1 - ns0) / 2;
}

private static Timestamp getCurrentTimestamp() {
    // текущее время 1000000 * ms + ns
    long ms = baseMs;
    long ns = System.nanoTime() - baseNs;

    // текущее время по прежнему 1000000 * ms + ns
    // но теперь ns не более одной миллисекунды
    ms += ns / 1000000;
    ns %= 1000000;

    // текущее время по прежнему 1000000 * ms + ns
    // но теперь ms содержит целые секунды
    ns += 1000000 * (ms % 1000);
    ms -= ms % 1000;

    Timestamp ts = new Timestamp(ms);
    ts.setNanos((int)ns);
    return ts;
}

В предыдущем коде есть два деления. Число делений можно уменьшить если базовые времена baseMs и baseNs установить на границу целой секунды:

private static long baseMs;
private static long baseNs;
static {
    long ns0 = System.nanoTime();
    baseMs = System.currentTimeMillis();
    long ns1 = System.nanoTime();
    baseNs = ns0 + (ns1 - ns0) / 2;

    // move baseMs on integer second
    long shiftMs = baseMs % 1000;
    baseMs -= shiftMs;
    baseNs -= 1000000 * shiftMs;
}

private static Timestamp getCurrentTimestamp() {
    long ns = System.nanoTime() - baseNs;

    // ms contains integer seconds
    long ms = baseMs + 1000 * (ns / 1000000000);
    ns %= 1000000000;

    Timestamp ts = new Timestamp(ms);
    ts.setNanos((int)ns);
    return ts;
}

▲ 1
  1. Нельзя смешивать разные источники получения времени. Это первая ключевая ошибка, она хорошо описана в комментариях и в одном из ответов.

  2. Использовать System.nanoTime - так же нельзя, связано это с тем, что рассматривая в рамках одного потока и одного ядра процессора вроде как можно рассчитать смещение даты+времени, и прибавлять его к нанотайму, получая более менее точную дату. Но в случае когда у нас более одного ядра, и более одного потока всё это не работает. Проблема описана здесь: https://dolzhenko.blogspot.com/2012/11/java-nanotime.html?m=1

  3. Адекватных средств замера времени в java 8 с точностью до микросекунд я не смог найти, если кто знает, буду благодарен. Это значит что моя проблема не может решиться в лоб.

  4. Конкретно для моего случая может помочь комбинированный способ, мне нужно использовать время как время, и как некий ИД, соблюдающий порядок, отсюда путь решения очевиден (не сразу дошёл до него), используя максимальную точность расчёта времени в 8 версии java получаем миллисекунды, далее у нас есть теоретически возможные порядка 1000000 операций замера в одну миллисекунду. Давайте сделаем счётчик замеров в данную миллисекунду, синхронизируем его и добавим ко времени. Да, это не будет точным временем, но оно решит все проблемы:

    private static long prevMills = System.currentTimeMillis();
    
    private static final AtomicInteger nanosActions = new AtomicInteger(0);
    
    public static Timestamp getCurrentTimestamp() {
        long mills = System.currentTimeMillis();
        if(prevMills != mills) {
            prevMills = mills;
            nanosActions.set(0);
        }
    
        Timestamp timestamp = new Timestamp(mills);
        // Это ненастоящие наносекунды, а миллисекунды, к которым подмешан счётчик операций замеров в данную миллисекунду
        // старая версия - int fakeNanos = ((int)(mills % 1000)) * 1000000 + nanosActions.incrementAndGet();
        int fakeNanos = timestamp.getNanos() + nanosActions.incrementAndGet(); // Так быстрее
        timestamp.setNanos(fakeNanos);
        return timestamp;
    }
    

Таким образом, мы получаем и время, и счётчик, гарантирующий строгую очерёдность замеров на одной ноде. Как я говорил ранее - междунодовые операции сопоставимы по длительности с миллисекундами, поэтому для моей задачи данной точности хватает.

Многопоточный вариант:

    private static final Map<Long, AtomicInteger> nanosMap = new ConcurrentHashMap<>();
    private static final Map<Long, AtomicLong> prevMillsMap = new ConcurrentHashMap<>();
    /**
     * Метод-фикция, относящийся больше не ко времени, а к порядку вызовов getCurrentTimestamp
     * В рамках текущего потока, вызовы будут гарантировать строго возрастающую последовательность.
     * @return Время [дата+время+миллисекунды][счётчик]
     */
    public static Timestamp getCurrentTimestamp() {
        long mills = System.currentTimeMillis();

        // Обеспечиваем атомарность доступа в рамках каждого потока
        long tickId = Thread.currentThread().getId();
        AtomicInteger nanosActions = nanosMap.computeIfAbsent(tickId, key -> new AtomicInteger(0));
        AtomicLong prevMills = prevMillsMap.computeIfAbsent(tickId, key -> new AtomicLong(0L));

        if(prevMills.get() != mills) {
            nanosActions.set(0);
        }

        // Так как у нас java 8, в ней нет точного времени, только миллисекунды.
        // Нам важна строгая последовательность замеров, поэтому, используем миллисекунды как опору,
        // если в одну миллисекунду вызывают несколько замеров, просто повышаем счётчик замеров,
        // у нас в распоряжении теоретические 1000000 значения для наносекунд, этого с головой хватит.
        int counter = nanosActions.incrementAndGet();

        Timestamp timestamp = new Timestamp(mills);
        // Собираем время [дата+время+миллисекунды][счётчик]
        // старая версия - int fakeNanos = ((int)(mills % 1000)) * 1000000 + counter;
        int fakeNanos = timestamp.getNanos() + counter; // Так быстрее чем в старой версии
        timestamp.setNanos(fakeNanos);

        prevMills.set(mills);

        // Это не точное время, тем не менее, оно удовлетворяет всем необходимым условиям,
        // да и кто проверит точность микросекунд или даже наносекунд??
        return timestamp;
    }