Big delay while processing HTTP request from NGINX to Unicorn (AngularJS to Rails API) only in Chrome -
Big delay while processing HTTP request from NGINX to Unicorn (AngularJS to Rails API) only in Chrome -
i have angularjs front-end sends requests rails api back-end application. angularjs front-end running in nginx server. rails api running in unicorn server.
generally, working fine together, in 1 case. when first load home page of times (but not always) there big delay (around 12 seconds process request rails). i´m not sure, guess happening first request nginx unicorn.
this big issue me, because when user request home page first time, page loaded , displayed quite fast (it takes around 2 secs display components), however, user has wait around these 12 seconds, until combo boxes loaded info coming backend.
i have no thought server configuration. i´m developer. tried debug request , seek figure out bottleneck is, don´t find anything.
please, find nginx access.log logs:
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, 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, 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, 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, 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, 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, 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, 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, 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, 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, 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, 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, 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, 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, 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, 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, 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, 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, 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, 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, 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, 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, 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, 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, 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, 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, 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, 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, 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, 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, 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, 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, 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, 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, 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, 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, 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, gecko) chrome/38.0.2125.111 safari/537.36"
as can see takes around 2 seconds. point don´t know why can´t see request rails api in file (anyway, can see them in snapshot attach).
after log, i´m waiting 12 seconds rails api request:
started "/gettranslationlanguages" 127.0.0.1 @ 2014-11-12 19:33:59 +0100 processing languagescontroller#translationlanguages html language load (0.4ms) select `languages`.* `languages` `languages`.`translation` = 1 completed 200 ok in 2ms (views: 1.0ms | activerecord: 0.4ms) started "/currencies" 127.0.0.1 @ 2014-11-12 19:33:59 +0100 processing currenciescontroller#index html currency load (0.3ms) select `currencies`.* `currencies` completed 200 ok in 3ms (views: 1.8ms | activerecord: 0.3ms) started "/boat_people" 127.0.0.1 @ 2014-11-12 19:33:59 +0100 processing boatpeoplecontroller#index html boatperson load (0.3ms) select `boat_people`.* `boat_people` completed 200 ok in 2ms (views: 0.9ms | activerecord: 0.3ms) started "/gettranslationlanguages" 127.0.0.1 @ 2014-11-12 19:33:59 +0100 processing languagescontroller#translationlanguages html language load (0.4ms) select `languages`.* `languages` `languages`.`translation` = 1 completed 200 ok in 2ms (views: 1.0ms | activerecord: 0.4ms) started "/currencies" 127.0.0.1 @ 2014-11-12 19:33:59 +0100 processing currenciescontroller#index html currency load (0.3ms) select `currencies`.* `currencies` completed 200 ok in 2ms (views: 1.1ms | activerecord: 0.3ms)
see, there delay of 12 seconds lastly log entry in nginx first log entry in unicorn.
i don´t know happens while time.
i attach snapshot google tools. displays more or less same info nginx access.log. time, can see requests rails api (i.e. gettranslationlanguages) has latency of 12.40 secs.
why waiting 12 seconds? cache? else can check?
update: don´t know why seems related cache or cookies. when delete browsing history cache , cookies in browser , load site issue doesn´t happen anymore. after that, if refresh page, issue happens.
important update now, i´m pretty sure issue located in unicorn. if shutdown unicorn , startup webrick (without other update on application or code) issue doens´t happen anymore.
i attach unicorn.rb config file:
# 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" hear 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
note: don´t have worry environment, issue happening in both of them.
update: when send request in browser straight rails endpoint in unicorn i.e http://localhost:8080/gettranslationlanguages
got result in browser in json format. mean, issue doesn´t happen. so, looks issue when request sent nginx unicorn.
important update have confirmed issue happening google chrome. never happens safari. even, have noticed, when run audit tool in google tools, somehow clean everything, everytime run audit works perfectly.
update: have installed , tested puma. it´s working. don´t know why combination of unicorn , chrome not working.
ruby-on-rails angularjs google-chrome nginx unicorn
Comments
Post a Comment