В момент запроса redis спит, и надо, чтобы он проснулся, причём если запросы к редису посылаются редко, то и просыпание будет дольше. Хотя по идее при запросе должно быть прерывание, из-за чего он должен проснуться достаточно быстро.
А console.log действительно может работать долго, лучше между замерами его не вызывать.
Конечно же, после редиса должен ещё проснуться node.js-скрипт :)
Но обычно просыпание должно занимать до 1 мс, а два просыпания — до 2 мс. 6–12 мс — действительно многовато. Вероятно, просыпание выполняется долго из-за того, что большую часть времени скрипт и redis бездействуют. Ну или прерывания не срабатывают вообще или срабатывают, но из-за сильного бездействия система всё-таки решает, что лучше так быстро не будить скрипт.
Попробуйте потестить под нагрузкой. Если пинг упадёт до 1 мс, то всё норм. Да, 1 мс — это может показаться много, но обычно запросы группируют пачками, и таких пачек вряд ли будет послано больше двух, ну максимум трёх в совсем сложных запросах, что даст суммарно до 3 мс пинга — не так страшно.
Кто-то может подумать, а чего вообще так долго всё будится. Потому что каждое бужение отнимает процессорное время, и система, допустим, может сделать максимум 50 тыс бужений в секунду, загрузив одно ядро на 100%. Теперь представьте 10 скриптов и 10 редисов, которые что-то делают каждую 1 мс — это уже 20 тыс бужений, что загрузит одно ядро на 40%. И при этом суммарный пинг будет 2 мс. Для пинга 1 мс придётся сделать 40 тыс бужений — это 80% загрузки.
Лучше всего эту проблему решают прерывания — скрипт будится только тогда, когда ему на сокет пришли данные или он, допустим, слушает клавиатуру, и пользователь нажал клавишу на клавиатуре, и т. д. В итоге получится, что если 10 скриптов ничего не делают и ничего не слушают, то и процессор не будет загружен. А если делают, то 80% загрузки — не так страшно, ведь у нас на сервере не одно ядро.
PS. Ещё кстати может влиять ваша виртуалка. Я бы посоветовал потестить напрямую, ведь это та особенность, где виртуалка реально может влиять.
PS. В node.js console.log блокирует скрипт, по крайней мере при выводе в файл. Т. е. считайте, что это примерно как вызвать fs.appendFileSync(). Да и при выводе в консоль тоже вроде медленно работает, хотя лучше проверить. И ещё не факт, что сама функция быстрая, хотя это уже должно слабже влиять.
Да, действительно, убрал консольный вывод и стало сразу 1-2 мс. Если честно, то ожидал увидеть 0, как заявлено разработчиками 100000 в сек
100к в секунду redis действительно без проблем выполнит. Но запрос дойдёт до редиса же не сразу, а после выполнения результат дойдёт до скрипта тоже не сразу. Т. е. каждый запрос всё-равно будет занимать порядка 1 мс, но при этом таких запросов можно послать 100 тыс в секунду. Это как в интернете у вас 100 мбит, но когда вы заходите на сайт, всё-равно 10–1000 мс из-за пинга. Но зато вы можете зайти на 10 таких сайтов сразу — тогда получится использовать канал намного эффективнее.
