Как измерить блокировку цикла событий в Nodejs? - PullRequest
Новая
       15

Как измерить блокировку цикла событий в Nodejs?

1 голос
/ 26 марта 2019

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

Я создал приложение Node / Express. И попробуйте обнаружить блокировку цикла событий с помощью различных инструментов. Я использовал hrtime, pm2, заблокирован_ат .

1 тест:

server.js 

require('./routes')(app, passport, mongoData)

routs / index.js 

router
  .get('/articles/:articleId(\\d+)', (req, res, next) => { 
      const blockedAt = require('blocked-at')
      blockedAt((time, stack) => {
         console.log(`Blocked for ${time}ms, operation started here:`, stack)
            },  {threshold:12})

      // my blocking script
      for (let i = 0; i <= 1000000000; i++) {
          let z = 10000 / Math.random()         
      }

      let ArticleController = require(path + 'app/controllers/ArticleController')
      let articleController = new ArticleController()
      articleController.index(req, res, next)
    })

Я получил:

Заблокировано на 15.5994921875мс, операция началась здесь: ['at', 'at ArticleService.getArticle (/app/services/article/ArticleService.js:79:44)'] Заблокировано на 14.0350537109375мс, операция началась здесь: ['at Promise.then ()', 'на ExpressHandlebars.render (node_modules / express-handlebars / lib / express-handlebars.js: 157: 8)', 'на ExpressHandlebars. (node_modules / express-handlebars / lib / express-handlebars.js: 226: 29) ']

Но ничего о моем скрипте блокировки!

2 тест:

С pm2:

  • Задержка цикла обработки событий - 0,56 мс
  • Задержка цикла обработки событий p95 - 4,5 мс

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

3 тест:

С помощью hrtime я измеряю внутри ArticleController.index. Индексный метод загружает 3 сервиса в асинхронном режиме. Есть много операций ввода-вывода, и там работает worker_threads. Некоторый код, созданный в setImmediate.

внутри в индекс: 

let hrstart = process.hrtime()

// there works all my services 
//...

let hrend = process.hrtime(hrstart)
 console.info('Execution time (hr): %ds ir ms: %dms', hrend[0], hrend[1] / 1000000)

res.render('home', data)

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

Как я могу измерить блоки цикла событий?

Я ожидаю вывод: «блокировка цикла событий в маршрутах / index.js: 12 для 5000 мс», но фактический вывод не улавливает мой сценарий блокировки.

1 Ответ

0 голосов
/ 26 марта 2019

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

let totalBlocked = 0;

router
  .get('/articles/:articleId(\\d+)', (req, res, next) => { 
      const start = new Date().getTime();

      // my blocking script
      for (let i = 0; i <= 1000000000; i++) {
          let z = 10000 / Math.random() ;        
      }

      let ArticleController = require(path + 'app/controllers/ArticleController');
      let articleController = new ArticleController();
      articleController.index(req, res, next);

      const total = new Date().getTime() - start;
      totalBlocked += total;
      console.log(`Blocked for ${total}. Total blocked time is ${totalBlocked}`);
    });

Вы также можете использовать Узел perf_hooks для синхронизации высокого разрешения. 

const {performance } = require('perf_hooks');

let totalBlocked = 0;

router
  .get('/articles/:articleId(\\d+)', (req, res, next) => { 
      const start = performance.now();
      // Do stuff
      const total = performance.now() - start;
      totalBlocked += total;
      console.log(`Blocked for ${total}. Total blocked time is ${totalBlocked}`);
   });
...