Большая задержка при обработке HTTP-запроса от NGINX к Unicorn (AngularJS to Rails API) только в Chrome

У меня есть внешний интерфейс AngularJS, который отправляет запросы в серверное приложение Rails API. Внешний интерфейс AngularJS работает на сервере NGINX. Rails API работает на сервере Unicorn.

Как правило, они отлично работают вместе, но в одном случае. Когда я впервые загружаю домашнюю страницу в большинстве случаев (но не всегда), возникает большая задержка (около 12 секунд для обработки запроса к Rails). Я не уверен, но я предполагаю, что это происходит только для первого запроса от Nginx к Unicorn.

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

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

Пожалуйста, найдите мои журналы NGINX access.log:

127.0.0.1 - - [12/Nov/2014:19:33:45 +0100] "GET / HTTP/1.1" 304 0 "-" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_9_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/38.0.2125.111 Safari/537.36"
127.0.0.1 - - [12/Nov/2014:19:33:45 +0100] "GET /css/bootstrap.min.css HTTP/1.1" 304 0 "http://localhost/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_9_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/38.0.2125.111 Safari/537.36"
127.0.0.1 - - [12/Nov/2014:19:33:45 +0100] "GET /css/bootstrap-responsive.min.css HTTP/1.1" 304 0 "http://localhost/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_9_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/38.0.2125.111 Safari/537.36"
127.0.0.1 - - [12/Nov/2014:19:33:45 +0100] "GET /dist/css/yanpy.min.css HTTP/1.1" 304 0 "http://localhost/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_9_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/38.0.2125.111 Safari/537.36"
127.0.0.1 - - [12/Nov/2014:19:33:45 +0100] "GET /css/icons.css HTTP/1.1" 304 0 "http://localhost/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_9_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/38.0.2125.111 Safari/537.36"
127.0.0.1 - - [12/Nov/2014:19:33:45 +0100] "GET /css/menus.css HTTP/1.1" 304 0 "http://localhost/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_9_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/38.0.2125.111 Safari/537.36"
127.0.0.1 - - [12/Nov/2014:19:33:45 +0100] "GET /css/join-us.css HTTP/1.1" 304 0 "http://localhost/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_9_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/38.0.2125.111 Safari/537.36"
127.0.0.1 - - [12/Nov/2014:19:33:45 +0100] "GET /css/font-awesome.min.css HTTP/1.1" 304 0 "http://localhost/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_9_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/38.0.2125.111 Safari/537.36"
127.0.0.1 - - [12/Nov/2014:19:33:45 +0100] "GET /css/font-awesome-ie7.min.css HTTP/1.1" 304 0 "http://localhost/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_9_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/38.0.2125.111 Safari/537.36"
127.0.0.1 - - [12/Nov/2014:19:33:45 +0100] "GET /dist/css/yanpy-ext-1.min.css HTTP/1.1" 304 0 "http://localhost/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_9_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/38.0.2125.111 Safari/537.36"
127.0.0.1 - - [12/Nov/2014:19:33:45 +0100] "GET /css/lightbox.css HTTP/1.1" 304 0 "http://localhost/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_9_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/38.0.2125.111 Safari/537.36"
127.0.0.1 - - [12/Nov/2014:19:33:45 +0100] "GET /dist/js/yanpy-libs-1.min.js HTTP/1.1" 304 0 "http://localhost/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_9_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/38.0.2125.111 Safari/537.36"
127.0.0.1 - - [12/Nov/2014:19:33:45 +0100] "GET /js/app.js HTTP/1.1" 304 0 "http://localhost/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_9_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/38.0.2125.111 Safari/537.36"
127.0.0.1 - - [12/Nov/2014:19:33:45 +0100] "GET /js/services.js HTTP/1.1" 304 0 "http://localhost/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_9_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/38.0.2125.111 Safari/537.36"
127.0.0.1 - - [12/Nov/2014:19:33:45 +0100] "GET /js/controllers.js HTTP/1.1" 304 0 "http://localhost/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_9_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/38.0.2125.111 Safari/537.36"
127.0.0.1 - - [12/Nov/2014:19:33:45 +0100] "GET /dist/js/yanpy.min.js HTTP/1.1" 304 0 "http://localhost/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_9_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/38.0.2125.111 Safari/537.36"
127.0.0.1 - - [12/Nov/2014:19:33:45 +0100] "GET /js/filters.js HTTP/1.1" 304 0 "http://localhost/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_9_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/38.0.2125.111 Safari/537.36"
127.0.0.1 - - [12/Nov/2014:19:33:45 +0100] "GET /js/directives.js HTTP/1.1" 304 0 "http://localhost/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_9_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/38.0.2125.111 Safari/537.36"
127.0.0.1 - - [12/Nov/2014:19:33:45 +0100] "GET /js/i18n.js HTTP/1.1" 304 0 "http://localhost/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_9_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/38.0.2125.111 Safari/537.36"
127.0.0.1 - - [12/Nov/2014:19:33:45 +0100] "GET /js/properties/properties.js HTTP/1.1" 304 0 "http://localhost/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_9_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/38.0.2125.111 Safari/537.36"
127.0.0.1 - - [12/Nov/2014:19:33:45 +0100] "GET /dist/js/yanpy-libs-2.min.js HTTP/1.1" 304 0 "http://localhost/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_9_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/38.0.2125.111 Safari/537.36"
127.0.0.1 - - [12/Nov/2014:19:33:45 +0100] "GET /img/logo.png HTTP/1.1" 304 0 "http://localhost/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_9_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/38.0.2125.111 Safari/537.36"
127.0.0.1 - - [12/Nov/2014:19:33:46 +0100] "GET /languages/locale-en.json HTTP/1.1" 304 0 "http://localhost/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_9_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/38.0.2125.111 Safari/537.36"
127.0.0.1 - - [12/Nov/2014:19:33:46 +0100] "GET /lib/angular/i18n/angular-locale_en.js HTTP/1.1" 304 0 "http://localhost/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_9_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/38.0.2125.111 Safari/537.36"
127.0.0.1 - - [12/Nov/2014:19:33:46 +0100] "GET /languages/locale-en.json HTTP/1.1" 304 0 "http://localhost/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_9_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/38.0.2125.111 Safari/537.36"
127.0.0.1 - - [12/Nov/2014:19:33:46 +0100] "GET /partials/login.html HTTP/1.1" 304 0 "http://localhost/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_9_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/38.0.2125.111 Safari/537.36"
127.0.0.1 - - [12/Nov/2014:19:33:46 +0100] "GET /img/glyphicons-halflings.png HTTP/1.1" 304 0 "http://localhost/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_9_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/38.0.2125.111 Safari/537.36"
127.0.0.1 - - [12/Nov/2014:19:33:46 +0100] "GET /partials/home.html HTTP/1.1" 304 0 "http://localhost/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_9_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/38.0.2125.111 Safari/537.36"
127.0.0.1 - - [12/Nov/2014:19:33:46 +0100] "GET /img/facilImage.png HTTP/1.1" 304 0 "http://localhost/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_9_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/38.0.2125.111 Safari/537.36"
127.0.0.1 - - [12/Nov/2014:19:33:46 +0100] "GET /img/rapidoImage.png HTTP/1.1" 304 0 "http://localhost/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_9_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/38.0.2125.111 Safari/537.36"
127.0.0.1 - - [12/Nov/2014:19:33:46 +0100] "GET /img/seguroImage.png HTTP/1.1" 304 0 "http://localhost/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_9_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/38.0.2125.111 Safari/537.36"
127.0.0.1 - - [12/Nov/2014:19:33:46 +0100] "GET /img/carrusel1.jpg HTTP/1.1" 304 0 "http://localhost/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_9_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/38.0.2125.111 Safari/537.36"
127.0.0.1 - - [12/Nov/2014:19:33:46 +0100] "GET /img/carrusel2.jpg HTTP/1.1" 304 0 "http://localhost/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_9_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/38.0.2125.111 Safari/537.36"
127.0.0.1 - - [12/Nov/2014:19:33:46 +0100] "GET /img/carrusel3.jpg HTTP/1.1" 304 0 "http://localhost/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_9_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/38.0.2125.111 Safari/537.36"
127.0.0.1 - - [12/Nov/2014:19:33:46 +0100] "GET /img/carrusel4.jpg HTTP/1.1" 304 0 "http://localhost/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_9_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/38.0.2125.111 Safari/537.36"
127.0.0.1 - - [12/Nov/2014:19:33:46 +0100] "GET /partials/boat-searcher.html HTTP/1.1" 304 0 "http://localhost/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_9_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/38.0.2125.111 Safari/537.36"
127.0.0.1 - - [12/Nov/2014:19:33:47 +0100] "GET /img/glyphicons-halflings-white.png HTTP/1.1" 304 0 "http://localhost/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_9_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/38.0.2125.111 Safari/537.36"  

Как видите, это занимает около 2 секунд. В этот момент я не знаю, почему я не вижу запрос к Rails API в этом файле (во всяком случае, вы можете увидеть их в прикрепленном снимке).

После этого журнала я просто жду 12 секунд для запроса API rails:

Started GET "/getTranslationLanguages" for 127.0.0.1 at 2014-11-12 19:33:59 +0100
Processing by LanguagesController#translationLanguages as HTML
  Language Load (0.4ms)  SELECT `languages`.* FROM `languages` WHERE `languages`.`translation` = 1
Completed 200 OK in 2ms (Views: 1.0ms | ActiveRecord: 0.4ms)


Started GET "/currencies" for 127.0.0.1 at 2014-11-12 19:33:59 +0100
Processing by CurrenciesController#index as HTML
  Currency Load (0.3ms)  SELECT `currencies`.* FROM `currencies`
Completed 200 OK in 3ms (Views: 1.8ms | ActiveRecord: 0.3ms)


Started GET "/boat_people" for 127.0.0.1 at 2014-11-12 19:33:59 +0100
Processing by BoatPeopleController#index as HTML
  BoatPerson Load (0.3ms)  SELECT `boat_people`.* FROM `boat_people`
Completed 200 OK in 2ms (Views: 0.9ms | ActiveRecord: 0.3ms)


Started GET "/getTranslationLanguages" for 127.0.0.1 at 2014-11-12 19:33:59 +0100
Processing by LanguagesController#translationLanguages as HTML
  Language Load (0.4ms)  SELECT `languages`.* FROM `languages` WHERE `languages`.`translation` = 1
Completed 200 OK in 2ms (Views: 1.0ms | ActiveRecord: 0.4ms)


Started GET "/currencies" for 127.0.0.1 at 2014-11-12 19:33:59 +0100
Processing by CurrenciesController#index as HTML
  Currency Load (0.3ms)  SELECT `currencies`.* FROM `currencies`
Completed 200 OK in 2ms (Views: 1.1ms | ActiveRecord: 0.3ms) 

Видите, с последней записи журнала в Nginx есть задержка в 12 секунд до первой записи журнала в Unicorn.

Я не знаю, что происходит в это время.

Я также прилагаю снимок из инструментов Google. Он отображает более или менее ту же информацию, что и Nginx access.log. Но на этот раз вы можете увидеть запросы к Rails API (то есть getTranslationLanguages) с задержкой в ​​12.40 с.

Задержка в запросе сервера Unicorn

Почему он ждет эти 12 секунд? Может быть какой-нибудь кеш? Что еще я могу проверить?

ОБНОВЛЕНИЕ: я не знаю, почему это связано с кешем или куки. Когда я удаляю историю браузера с кешем и файлами cookie в моем браузере и загружаю сайт, проблема больше не возникает. После этого, если я просто обновлю страницу, проблема произойдет.

ВАЖНОЕ ОБНОВЛЕНИЕ Теперь, я уверен, что проблема находится в Unicorn. Если я просто отключаю Unicorn и запускаю webrick (без какого-либо другого обновления в моем приложении или коде), проблема больше не возникает.

Я прилагаю свой файл конфигурации Unicorn.rb:

# config/unicorn.rb
if ENV["RAILS_ENV"] == "development"
  worker_processes 1
  stderr_path "/Users/Rober/Projects/yanpy/dev/yanpyapi/log/unicorn.stderr.log"
  stdout_path "/Users/Rober/Projects/yanpy/dev/yanpyapi/log/unicorn.stdout.log"
elsif ENV["RAILS_ENV"] == "test"
  worker_processes 1
  stderr_path "/home/ubuntu/env/test/www/yanpyapi-test/log/unicorn.stderr.log"
  stdout_path "/home/ubuntu/env/test/www/yanpyapi-test/log/unicorn.stdout.log"
  listen 8081
else
  #worker_processes 3
  worker_processes 1
  stderr_path "/home/ubuntu/env/production/www/yanpyapi/log/unicorn.stderr.log"
  stdout_path "/home/ubuntu/env/production/www/yanpyapi/log/unicorn.stdout.log"
end

timeout 30

Примечание: вам не нужно беспокоиться об окружающей среде, проблема возникает в обоих из них.

ОБНОВЛЕНИЕ: Когда я отправляю запрос в своем браузере напрямую на конечную точку Rails в Unicorn, т.е. http://localhost:8080/getTranslationLanguages Я сразу получил результат в своем браузере в формате json. Я имею в виду, проблема не возникает. Таким образом, похоже, что проблема заключается только в том, что запрос отправляется из Nginx в Unicorn.

ВАЖНОЕ ОБНОВЛЕНИЕ Я подтвердил, что проблема возникает только с Google Chrome. Это никогда не случается с Safari. Даже, как я заметил, когда я запускаю инструмент аудита в инструментах Google, он каким-то образом очищает все, поэтому каждый раз, когда я запускаю аудит, он работает отлично.

ОБНОВЛЕНИЕ: Я установил и протестировал с Puma. Работает. Я не знаю, почему не работает комбинация Unicorn и Chrome.

0 ответов

Другие вопросы по тегам