Почему setInterval кушает больше проца чем setTimeout?

Question

[Смотритель]

Приветствую сообщество.

Натолкнулся в одном из модулей на крайне интересную ситуацию. Изложу в кратком формате...

Вариант кода 1:

const timer = setInterval(() => {
  periodicFunction();
}, 1000);

periodicFunction() {
  ...рабочий код функции...
};

Вариант кода 2:

periodicFunction();

periodicFunction() {
  const timer = setTimeout(() => {
    clearTimeout(timer);
    periodicFunction();
  }, 1000);

  ...рабочий код функции...
};

По сути они практически одинаковые - каждую секунду вызывается функция, выполняет некую работу (просто в асинхроне читает небольшой JSON-файл и парсит его в переменную).

Однако столкнулся с абсолютно непонятным для меня эффектом:
- вариант кода 1 (одноразовый вызов setInteval) грузит процессор на 10% локально и почти 40% на сервере
- вариант кода 2 (периодический вызов setTimeout) грузит процессор не более чем на 1% локально и 1.5% на сервере

Есть предположения причины такого странного поведения?

Comments

[RidgeA]

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

[Смотритель]

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

let fdata = false;
const path = '.....';

... тут всякоразно ...

periodicFunction() {
  ... тут setTimeout() ...

  FS.readFile(path, (err, data) => {
    if (!err && data) {
      fdata = JSON.parse(data);
    };
  });
};

[RidgeA]

Артем, если можно завтра рабочий пример скинуть было бы здорово - оба варианта, медленный и быстрый, что бы можно было у себя воспроизвести, может действительно баг.....

[Сергей Соколов]

какая версия node? Значение времени задаётся как в примере, числом, или переменной?

[Смотритель]

Версия ноды 10, интервал хардкодом конкретное число = 1000.

[RidgeA]

Артем, воспроизвести у себя не смог. Врядли это свзяано с setInterval/setTimeout

index-timeout.js

"use strict";

const {readFile} = require("fs");


const file = './package.json';
const timeout = 1000;
let content = null;

function testFunction() {

  const timer = setTimeout(() => {
    clearTimeout(timer);
    testFunction()
  }, timeout);

  readFile(file, (err, data) => {
    content = JSON.parse(data);
    console.log("File parsed");
  })
}

testFunction();

index-interval.js:

"use strict";

const {readFile} = require("fs");


const file = './package.json';
const timeout = 1000;
let content = null;

function testFunction() {
  readFile(file, (err, data) => {
    content = JSON.parse(data);
    console.log("File parsed");
  })
}

setInterval(testFunction, timeout);

[RidgeA]

по htop потребление CPU в обоих случаях даже не превысило 0.0

[Смотритель]

RidgeA, вот и я удивился, что за ерунда
реально объективных причин такого поведения не смогли найти всем отделом, но времени тратить тоже не стали - просто фиксанули и все (вчера вообще перевел эту кухню на FS.watch(...), правда пришлось делать небольшую обертку, а то если в момент запуска watch файла не существует, то мониторинг не активируется, и выбрасывает исключение - а такое у нас бывает, что файл с данными то есть, то нет, то изменяется)...

может реально конкретная версия ноды... не так давно оптимизировали сортировку данных матрицы (т.е. по сути матрица даже 100 х 100 выдает для сортировки 10000 значений), так на 9-ке как ни бились, не удавалось выиграть больше нескольких микросекунд на итерацию... а тот же самый код на 10-ке выдал выигрыш почти на 40%

сейчас у нас версия ноды 10.10.0

[RidgeA]

Артем, я проверял на

node -v
v10.10.0

FS.watch(...)

можно посмотреть на https://www.npmjs.com/package/chokidar

[Смотритель]

RidgeA, спасибо, посмотрим, хотя и маловероятно, что будем переделывать, если только проблем не вылезет =)

Answer 1

[Смотритель]

После обновления не знаю какого по счету NODE наткнулся на старые тестовые скрипты, которыми эмулировал проблему. Решил повторить тесты - проблема не воспроизводится. Видимо "корень зла" был в конкретной версии...

Answer 2

[Павло Пономаренко]

Поставьте console.log( counter++ ) в вашей periodicFunction, посмотрите, сколько раз она реально вызывается. setTimeout и setInterval не жрут процессор сами по себе, тем более до 40%.

Comments

[Смотритель]

Хех, оттого и вопрос =)

Частоту я проверил сразу же - в обоих вариантах отличия в пределех 10мс... от 997 до 1005 мс... Эти доли можно списать на погрешность вывода ( проверял с помощью console.info(Date.now()) ), к тому же отклонения от заданных 1000мс присутсвуют в обоих вариантах, просто в setInterval они меньше...

[Павло Пономаренко]

Артем, меня не так частота заставляет смущаться, как количество. Может, по какой-то причине, в setInterval она вызывается несколько раз? Скажем, в разных потоках? За 100 секунд будет одинаковое количество вызовов функции? И там и там глобальный счетчик досчитает до 100? И там и там каждое число будет выведено в консоль лишь раз?

[Смотритель]

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

23453453450936
23453453451935
23453453452935
23453453453936
23453453454934
23453453455933

т.е. разница между числами в районе заданных 1000мс, если бы вызовов было больше - т.е. не 60 в минуту, а 120, то и разница в числах имела хотя бы местами меньшую разницу (например около 500мс)...

[Алексей Николаев]

Артем, это защита от подгадывания срабатывания таймера. Они намеренно сделаны неточными. Копайте в сторону того, как и в каком окружении это у вас запускается на сервере.

[Смотритель]

Алексей Николаев, да копать-то некуда, причем без шуток... Когда модуль был запущен и выжрал 40% проца, мы немного офигели от такой его "наглости". Через отладчик попробовали отпрофайлить - безрезультатно, вызовы всех функций занимали крайне малое количество времени на выполнение, а вот вызовы методов из системного модуля timer.js (или time.js - точно не помню) как раз кушали гораздо больше. Мы начали сначала просто пытаться отключить вызовы всех блоков от полного процесса, пока не вышли на ситуацию, что остался активным только основной код самого процесса и вот этот модуль, т.к. он является критическим. В основном коде вызовов таймеров не было, а в модуле изначально был setInterval() ... закомментили его вызов - нагрузка на проц сразу ушла... Заменили на setTimeout() - загрузка проца не повысилась... вернули в работу все остальные части кода - никаких проблем...
Снова вернули setInteval() - опять проц в пике... Так что просто заменили на setTimeout - но мне чисто для себя стало очень интересно - почему такая фигня в Node v10

[Алексей Николаев]

Артем, вероятен баг. Можете протестировать с другими версиями, и отписать им баг-репорт.

[Смотритель]

Dmitry, точно такой =)
по сути место повторного вызова не имеет значения.

Место вызова setTimeout() в функции влияет только на два момента:
- если допустить вероятность возникновения исключения до вызова setTimeout(), то функция вывалится не дойдя до следующего шага, т.е. выполнение прервется (можно, конечно, обернуть в try{} catch() {})
- т.к. код "чтения" файла пусть и асинхронный, но все же тратит какое-то количество мс, то в случае переноса следующей итерации в конец функции, интервал между запусками будет не 995-1005 мс, а примерно 1010-1020 (ну это так, навскидку)

Так что это на самом деле совершенно непринципиально

[Смотритель]

Dmitry, Дмитрий, чтение файла асинхронное, я про это писал + код функции тоже выложил выше - используется именно асинхронное чтение...
И далее, тоже выше написано, вставлял для теста в функцию строчку вывода в консоль с таймингом - разница между вызовами укладывалась в 1000мс (плюс/минус)

И да, чтобы наверняка развеять сомнения по чтению - файл не более 1Кб и читается мгновенно, в колбек тоже вставляли вывод в консоль, чтобы понимать, нет ли там задержек (параноил по черному) - на чтение файла уходило менее 50мс.

Вот как-то так... странности, потому и вопрос решил тут запостить, мало ли у кого-то еще какая-то параноидальная мысль возникнет, которая может объяснить такое поведение таймера