Перевод этой заметки никак не нацелен оттолкнуть читателя от использования Node.js, и на старуху бывает проруха, а лишь призывает быть внимательными, и, возможно, подскажет решение тем, кто вдруг столкнётся с подобным поведением своего приложения. Лексика автора оставлена без особых изменений и цензуры.
Кратко сказка сказывается, да долго дело делается, MelonCard сегодня был представлен на TechCrunch вместе с другими компаниями, как вдруг всё внезапно сломалось. Каждая. маленькая. мелочь. Мы только что обновили сайт, чтобы он выглядел и ощущался более отзывчивым, используя long-polling NodeJS, с крутейшим динамическим фронтендом на jQuery Templates и KnockoutJS. Приложили все усилия и провели ручное и юнит-тестирование с помощью Vows. Все системы готовы, полный вперёд и всё такое? Не тут-то было.
Наша система на NodeJS использует состояние пользователя, например «Я ожидаю обновления этих двух записей», а сервер (отталкиваясь от проверки временной засечки) возвращает либо «Ваши записи актуальны», либо «Запись xxx изменилась на yyy» (на самом деле всё немного сложнее с разделёнными переменными Redis, сессиями и прочими проверками безопасности для взаимосвязи Rails, MySQL, Redis и Node). Всё вот так кристально просто, но даже простой код NodeJS может обернуться адом, когда что-то идёт не так. Это случилось сегодня.
После того, как статьи о нас были опубликованы, к нам хлынул поток обрадованных пользователей (скажем, 50-100 новых пользователей в час). И внезапно всё развалилось. Страницы больше не работали; наши почтовые ящики начали набиваться сообщениями от недовольных пользователей. Я налил кофе и приготовился к битве.
Моей первой мыслью было то, что NodeJS отлично держит нагрузку, он этим и славен. Пятьдесят или сто пользователей никак не могли угробить систему. И как выяснилось это была не вина NodeJS, как такового, но об этом позже. Сервер начал возвращать соврешенно неожиданные ответы, как если пользователь говорил «У меня есть записи a, b и c», а сервер отвечал «Ты идиот, сотри записи x, y и z, а вот тебе записи a, b и c». Сфокусироваться и воспроизвести проблему было невозможно, учитывая ужасную обработку ошибок и возможности дебага в Node. Следующей командой приходилось постоянно пользоваться (да, прямо на продакшне):
NODE_ENV=’production’ node/privacy.js | grep “Возвращаемые результаты”
Вы можете себе представить, как ужасающе тяжело было разбирать эту кучу. Стоит заметить, что на тестовом сервере всё продолжало работать замечательно, и все юнит-тесты замечательно проходили, и у меня больше ничего не было от чего можно было бы оттолкнуться. Ко всему прочему наша система внимательно проверяла сессии (для безопасности), и расстроенные пользователи логинились и выходили из системы в разных закладках браузера, получая огромное количество предупреждений о том, что они не авторизованы (что вдобавок делало невозможным отсечение реальных ошибок). Я получал ошибки примерно в таком виде:
Trace: at EventEmitter. (/—/node/privacy.js:118:11) at EventEmitter.emit (events.js:81:20)
Строка, упоминающаясе здесь (единственная, о которой сообщал Node):
process.on(‘uncaughtException’, function (err) { console.log([‘Caught exception’, err]); console.trace(); });
Ну, хотя бы приложение не валилось, но всё равно — отталкиваться было не от чего. Хочется отметить, что ничего из того, что мы делали (ручное тестирование интерфейса, юнит-тестирование, обработка ошибок и т.п.) не выявляло ошибок, связанных с этой строкой. Да, нужно было бы использовать нагрузочное тестирование, но нет уверенности, что оно бы выявило это злоключение.
После четырёх часов дебага (и перевода заглавной страницы в 503 — Временно Недоступно), и пока мой соучередитель персонально отвечал каждому расстроенному и любознательному пользователю извинениями, я заметил, что пользователь путал параметры моего запроса с параметрами запроса других пользователей. Прямо скажу, сервер был спроектирован так и работал так, чтобы возвращать только ВАШУ информацию по ВАШЕМУ запросу, но он путал то, что ВЫ запрашивали. То есть, вы спрашивали «Люблю яблоки и дыни», а он отвечал «Ерунда, вы любите манго». То есть всё было безопасно, но всё равно чертовски неправильно. С чего бы вдруг мой ExpressJS сервер путал то, что я его спрашивал. Я начал копать и нашёл вот что:
Выглядит плоховато? Да это просто провал. Я не эксперт в JavaScript'е, но попробую объяснить как умею. В JavaScript'е объявления переменных происходят либо в контексте функции, либо в глобальном контексте (с некоторыми замороками прохождения через вложенность контекстов от текущего до глобального). Когда я создал «initial» без «var», был совершён проход от текущего контекста и быстренько попало в глобальный, и создало там глобальную переменную «initial». Когда пришёл следующий запрос, такой же проход был совершён ещё раз и записал данные в ту же самую переменную (ту самую, которую предыдущий запрос всё ещё собирался использовать). И так происходило с каждым следующим запросом. Когда сервер отвечал на запросы после некоторой обработки, он читал из этой постоянно обновляемой переменной и возвращал бредовые результаты. Полное дерьмо. Нужно было всего-то написать так:
Такой код бы создавал переменную в контексте моей анонимной функции, и не было бы никакой возможности перезаписать ещё другим запросом. Это было любительской ошибкой, но мимо неё прошли, не заметив, все дебаги и тестирования, которые я только смог применить.
Вот и настал момент, когда вы должны сказать «нужно было использовать CoffeeScript». И вы окажетесь правы. В других обстоятельствах всё могло бы быть ещё хуже (что бы было, если бы я ошибся контекстом для переменной сессии?). Ко всему прочему недостаток нормальной обработки ошибок (в Rails мы ловим ошибки по стектрейсам и отправляем уникальные стектрейсы команде через электронную почту), и какого-либо нормального средства для дебага (кроме grep и less), унесли меня в годы, когда программирование не было приятной вещью. Или, возможно, мне просто нужно было быть внимательнее.
После четырёх часов перерыва в обслуживании и нескольких сотен расстроенных пользователей, я нашёл проблему и быстро поправил на продуктивном сервере. Тучи рассеялись, птички защебетали и выглянуло солнышко. Мы начали отвечать пользователям извинениями, посчитали убытки и двинулись дальше. Но мне до сих пор нелегко от того, какой ущерб принесло одно отсутствующее ключевое слово. Неужто то, что я пропустил один var делает меня ущербным?
Кратко сказка сказывается, да долго дело делается, MelonCard сегодня был представлен на TechCrunch вместе с другими компаниями, как вдруг всё внезапно сломалось. Каждая. маленькая. мелочь. Мы только что обновили сайт, чтобы он выглядел и ощущался более отзывчивым, используя long-polling NodeJS, с крутейшим динамическим фронтендом на jQuery Templates и KnockoutJS. Приложили все усилия и провели ручное и юнит-тестирование с помощью Vows. Все системы готовы, полный вперёд и всё такое? Не тут-то было.
Наша система на NodeJS использует состояние пользователя, например «Я ожидаю обновления этих двух записей», а сервер (отталкиваясь от проверки временной засечки) возвращает либо «Ваши записи актуальны», либо «Запись xxx изменилась на yyy» (на самом деле всё немного сложнее с разделёнными переменными Redis, сессиями и прочими проверками безопасности для взаимосвязи Rails, MySQL, Redis и Node). Всё вот так кристально просто, но даже простой код NodeJS может обернуться адом, когда что-то идёт не так. Это случилось сегодня.
После того, как статьи о нас были опубликованы, к нам хлынул поток обрадованных пользователей (скажем, 50-100 новых пользователей в час). И внезапно всё развалилось. Страницы больше не работали; наши почтовые ящики начали набиваться сообщениями от недовольных пользователей. Я налил кофе и приготовился к битве.
Моей первой мыслью было то, что NodeJS отлично держит нагрузку, он этим и славен. Пятьдесят или сто пользователей никак не могли угробить систему. И как выяснилось это была не вина NodeJS, как такового, но об этом позже. Сервер начал возвращать соврешенно неожиданные ответы, как если пользователь говорил «У меня есть записи a, b и c», а сервер отвечал «Ты идиот, сотри записи x, y и z, а вот тебе записи a, b и c». Сфокусироваться и воспроизвести проблему было невозможно, учитывая ужасную обработку ошибок и возможности дебага в Node. Следующей командой приходилось постоянно пользоваться (да, прямо на продакшне):
NODE_ENV=’production’ node/privacy.js | grep “Возвращаемые результаты”
Вы можете себе представить, как ужасающе тяжело было разбирать эту кучу. Стоит заметить, что на тестовом сервере всё продолжало работать замечательно, и все юнит-тесты замечательно проходили, и у меня больше ничего не было от чего можно было бы оттолкнуться. Ко всему прочему наша система внимательно проверяла сессии (для безопасности), и расстроенные пользователи логинились и выходили из системы в разных закладках браузера, получая огромное количество предупреждений о том, что они не авторизованы (что вдобавок делало невозможным отсечение реальных ошибок). Я получал ошибки примерно в таком виде:
Trace: at EventEmitter. (/—/node/privacy.js:118:11) at EventEmitter.emit (events.js:81:20)
Строка, упоминающаясе здесь (единственная, о которой сообщал Node):
process.on(‘uncaughtException’, function (err) { console.log([‘Caught exception’, err]); console.trace(); });
Ну, хотя бы приложение не валилось, но всё равно — отталкиваться было не от чего. Хочется отметить, что ничего из того, что мы делали (ручное тестирование интерфейса, юнит-тестирование, обработка ошибок и т.п.) не выявляло ошибок, связанных с этой строкой. Да, нужно было бы использовать нагрузочное тестирование, но нет уверенности, что оно бы выявило это злоключение.
После четырёх часов дебага (и перевода заглавной страницы в 503 — Временно Недоступно), и пока мой соучередитель персонально отвечал каждому расстроенному и любознательному пользователю извинениями, я заметил, что пользователь путал параметры моего запроса с параметрами запроса других пользователей. Прямо скажу, сервер был спроектирован так и работал так, чтобы возвращать только ВАШУ информацию по ВАШЕМУ запросу, но он путал то, что ВЫ запрашивали. То есть, вы спрашивали «Люблю яблоки и дыни», а он отвечал «Ерунда, вы любите манго». То есть всё было безопасно, но всё равно чертовски неправильно. С чего бы вдруг мой ExpressJS сервер путал то, что я его спрашивал. Я начал копать и нашёл вот что:
app.all(‘/apps/:user_id/status’, function(req, res, next) {
// …
initial = extractVariables(req.body);
});
Выглядит плоховато? Да это просто провал. Я не эксперт в JavaScript'е, но попробую объяснить как умею. В JavaScript'е объявления переменных происходят либо в контексте функции, либо в глобальном контексте (с некоторыми замороками прохождения через вложенность контекстов от текущего до глобального). Когда я создал «initial» без «var», был совершён проход от текущего контекста и быстренько попало в глобальный, и создало там глобальную переменную «initial». Когда пришёл следующий запрос, такой же проход был совершён ещё раз и записал данные в ту же самую переменную (ту самую, которую предыдущий запрос всё ещё собирался использовать). И так происходило с каждым следующим запросом. Когда сервер отвечал на запросы после некоторой обработки, он читал из этой постоянно обновляемой переменной и возвращал бредовые результаты. Полное дерьмо. Нужно было всего-то написать так:
var initial = extractVariables(req.body);Такой код бы создавал переменную в контексте моей анонимной функции, и не было бы никакой возможности перезаписать ещё другим запросом. Это было любительской ошибкой, но мимо неё прошли, не заметив, все дебаги и тестирования, которые я только смог применить.
Вот и настал момент, когда вы должны сказать «нужно было использовать CoffeeScript». И вы окажетесь правы. В других обстоятельствах всё могло бы быть ещё хуже (что бы было, если бы я ошибся контекстом для переменной сессии?). Ко всему прочему недостаток нормальной обработки ошибок (в Rails мы ловим ошибки по стектрейсам и отправляем уникальные стектрейсы команде через электронную почту), и какого-либо нормального средства для дебага (кроме grep и less), унесли меня в годы, когда программирование не было приятной вещью. Или, возможно, мне просто нужно было быть внимательнее.
После четырёх часов перерыва в обслуживании и нескольких сотен расстроенных пользователей, я нашёл проблему и быстро поправил на продуктивном сервере. Тучи рассеялись, птички защебетали и выглянуло солнышко. Мы начали отвечать пользователям извинениями, посчитали убытки и двинулись дальше. Но мне до сих пор нелегко от того, какой ущерб принесло одно отсутствующее ключевое слово. Неужто то, что я пропустил один var делает меня ущербным?
