view · edit · sidebar · attach · print · history

< Niklaus.20170710-faster-ajax | Index | Niklaus.20170704-oddb-org-rack >>

20170705-oddb-org-rack

Summary

Commits

Index

Port oddb.org to use rack

Must fix the following problems:

  • Be sure the request limit is working fine.
  • Analyse log of yesterday to see whether no bots are seen in evidentia, just-medical and user.log

The Watir test for the request limit of 5 did not test correctly, that the request limit was reached. Fixed the watir test.

Analysing the reports with

 grep -wc GET /var/www/oddb.org.rack/log/2017/07/04/*log
/var/www/oddb.org.rack/log/2017/07/04/crawler_log:11571
/var/www/oddb.org.rack/log/2017/07/04/evidentia_log:405
/var/www/oddb.org.rack/log/2017/07/04/google_crawler_log:278
/var/www/oddb.org.rack/log/2017/07/04/just-medical_log:3073
/var/www/oddb.org.rack/log/2017/07/04/user_log:343782

grep -ic exiting /var/www/oddb.org.rack/log/2017/07/04/*log
/var/www/oddb.org.rack/log/2017/07/04/crawler_log:0
/var/www/oddb.org.rack/log/2017/07/04/evidentia_log:0
/var/www/oddb.org.rack/log/2017/07/04/google_crawler_log:0
/var/www/oddb.org.rack/log/2017/07/04/just-medical_log:0
/var/www/oddb.org.rack/log/2017/07/04/user_log:23

It looks like we still have way too much traffic in the main rack app user_log. Looking for bots via regular. This does not work, as our log pattern does not contain the user agent. Can I change the log pattern? Use a gem like https://rubygems.org/gems/clogger? Or write my own logger as in https://gist.github.com/skwp/7204787

Zeno had a problem that the app down page did not show up when he tried to access (around 08:22 this morning) http://ch.oddb.org/de/gcc/search/zone/drugs/search_query/mepha/search_type/st_company.

In log/2017/07/05/user_log we find the entry

log/2017/07/05/user_log:E, [2017-07-05T08:21:54.376252 #11675] ERROR -- : oddbapp.rb:2045:in `block (2 levels) in log_size' user 16 threads, footprint of 7184MB,  12914 sessions. Exiting as exceeds 7168MB

In the service log I find

 grep -B4 -A30 "12914 sessions" /service/ch.oddb.rack/log/main/*
/service/ch.oddb.rack/log/main/@40000000595c858c21de99d4.s-@40000000595c856027c9c88c No @flavor found via epilepsie-therapie.ch
/service/ch.oddb.rack/log/main/@40000000595c858c21de99d4.s-@40000000595c85602d4a6604 No @flavor found via epilepsie-therapie.ch
/service/ch.oddb.rack/log/main/@40000000595c858c21de99d4.s-@40000000595c856101181cfc No @flavor found via epilepsie-therapie.ch
/service/ch.oddb.rack/log/main/@40000000595c858c21de99d4.s-@40000000595c856110677c5c No @flavor found via epilepsie-therapie.ch
/service/ch.oddb.rack/log/main/@40000000595c858c21de99d4.s:@40000000595c858c16406364 user 16 threads, footprint of 7184MB,  12914 sessions. Exiting as exceeds 7168MB
/service/ch.oddb.rack/log/main/@40000000595c858c21de99d4.s-@40000000595c858c18c60c74 [2017-07-05 08:21:54] FATAL SystemExit: SystemExit
/service/ch.oddb.rack/log/main/@40000000595c858c21de99d4.s-@40000000595c858c18c6105c    /usr/local/ruby-2.4.0/lib/ruby/2.4.0/webrick/server.rb:171:in `select'
/service/ch.oddb.rack/log/main/@40000000595c858c21de99d4.s-@40000000595c858c18c61444    /usr/local/ruby-2.4.0/lib/ruby/2.4.0/webrick/server.rb:171:in `block in start'
/service/ch.oddb.rack/log/main/@40000000595c858c21de99d4.s-@40000000595c858c18c61444    /usr/local/ruby-2.4.0/lib/ruby/2.4.0/webrick/server.rb:33:in `start'
/service/ch.oddb.rack/log/main/@40000000595c858c21de99d4.s-@40000000595c858c18c61444    /usr/local/ruby-2.4.0/lib/ruby/2.4.0/webrick/server.rb:158:in `start'
/service/ch.oddb.rack/log/main/@40000000595c858c21de99d4.s-@40000000595c858c18c6182c    /var/www/oddb.org.rack/vendor/ruby/2.4.0/gems/rack-2.0.3/lib/rack/handler/webrick.rb:34:in `run'
/service/ch.oddb.rack/log/main/@40000000595c858c21de99d4.s-@40000000595c858c18c63384    /var/www/oddb.org.rack/vendor/ruby/2.4.0/gems/rack-2.0.3/lib/rack/server.rb:297:in `start'
/service/ch.oddb.rack/log/main/@40000000595c858c21de99d4.s-@40000000595c858c18c6376c    /var/www/oddb.org.rack/vendor/ruby/2.4.0/gems/rack-2.0.3/lib/rack/server.rb:148:in `start'
/service/ch.oddb.rack/log/main/@40000000595c858c21de99d4.s-@40000000595c858c18c6376c    /var/www/oddb.org.rack/vendor/ruby/2.4.0/gems/rack-2.0.3/bin/rackup:4:in `<top (required)>'
/service/ch.oddb.rack/log/main/@40000000595c858c21de99d4.s-@40000000595c858c18c63b54    /var/www/oddb.org.rack/vendor/ruby/2.4.0/bin/rackup:22:in `load'
/service/ch.oddb.rack/log/main/@40000000595c858c21de99d4.s-@40000000595c858c18c68d5c    /var/www/oddb.org.rack/vendor/ruby/2.4.0/bin/rackup:22:in `<main>'
/service/ch.oddb.rack/log/main/@40000000595c858c21de99d4.s-@40000000595c858c18dc76bc [2017-07-05 08:21:54] INFO  going to shutdown ...
/service/ch.oddb.rack/log/main/@40000000595c858c21de99d4.s-@40000000595c858c20de9aac OpenURI::HTTPError: 502 Proxy Error
/service/ch.oddb.rack/log/main/@40000000595c858c21de99d4.s-@40000000595c858c20dea664    /usr/local/ruby-2.4.0/lib/ruby/2.4.0/open-uri.rb:363:in `open_http'
/service/ch.oddb.rack/log/main/@40000000595c858c21de99d4.s-@40000000595c858c20dea664    /usr/local/ruby-2.4.0/lib/ruby/2.4.0/open-uri.rb:741:in `buffer_open'
/service/ch.oddb.rack/log/main/@40000000595c858c21de99d4.s-@40000000595c858c20dea664    /usr/local/ruby-2.4.0/lib/ruby/2.4.0/open-uri.rb:212:in `block in open_loop'
/service/ch.oddb.rack/log/main/@40000000595c858c21de99d4.s-@40000000595c858c20deaa4c    /usr/local/ruby-2.4.0/lib/ruby/2.4.0/open-uri.rb:210:in `catch'
/service/ch.oddb.rack/log/main/@40000000595c858c21de99d4.s-@40000000595c858c20deaa4c    /usr/local/ruby-2.4.0/lib/ruby/2.4.0/open-uri.rb:210:in `open_loop'
/service/ch.oddb.rack/log/main/@40000000595c858c21de99d4.s-@40000000595c858c20decd74    /usr/local/ruby-2.4.0/lib/ruby/2.4.0/open-uri.rb:151:in `open_uri'
/service/ch.oddb.rack/log/main/@40000000595c858c21de99d4.s-@40000000595c858c20ded15c    /usr/local/ruby-2.4.0/lib/ruby/2.4.0/open-uri.rb:721:in `open'
/service/ch.oddb.rack/log/main/@40000000595c858c21de99d4.s-@40000000595c858c20ded15c    /usr/local/ruby-2.4.0/lib/ruby/2.4.0/open-uri.rb:35:in `open'
/service/ch.oddb.rack/log/main/@40000000595c858c21de99d4.s-@40000000595c858c20ded15c    /var/www/oddb.org.rack/src/view/tooltip.rb:18:in `set_tooltip'
/service/ch.oddb.rack/log/main/@40000000595c858c21de99d4.s-@40000000595c858c20ded544    /var/www/oddb.org.rack/src/view/additional_information.rb:267:in `ikscat'
/service/ch.oddb.rack/log/main/@40000000595c858c21de99d4.s-@40000000595c858c20dedd14    /var/www/oddb.org.rack/vendor/ruby/2.4.0/gems/htmlgrid-1.1.4/lib/htmlgrid/composite.rb:83:in `create'
/service/ch.oddb.rack/log/main/@40000000595c858c21de99d4.s-@40000000595c858c20dedd14    /var/www/oddb.org.rack/vendor/ruby/2.4.0/gems/htmlgrid-1.1.4/lib/htmlgrid/composite.rb:284:in `compose_component'
/service/ch.oddb.rack/log/main/@40000000595c858c21de99d4.s-@40000000595c858c20dee0fc    /var/www/oddb.org.rack/vendor/ruby/2.4.0/gems/htmlgrid-1.1.4/lib/htmlgrid/composite.rb:213:in `block in compose'
/service/ch.oddb.rack/log/main/@40000000595c858c21de99d4.s-@40000000595c858c20def86c    /var/www/oddb.org.rack/vendor/ruby/2.4.0/gems/htmlgrid-1.1.4/lib/htmlgrid/composite.rb:209:in `each'
/service/ch.oddb.rack/log/main/@40000000595c858c21de99d4.s-@40000000595c858c20defc54    /var/www/oddb.org.rack/vendor/ruby/2.4.0/gems/htmlgrid-1.1.4/lib/htmlgrid/composite.rb:209:in `compose'
/service/ch.oddb.rack/log/main/@40000000595c858c21de99d4.s-@40000000595c858c20defc54    /var/www/oddb.org.rack/vendor/ruby/2.4.0/gems/htmlgrid-1.1.4/lib/htmlgrid/list.rb:67:in `block in compose_list'
/service/ch.oddb.rack/log/main/@40000000595c858c21de99d4.s-@40000000595c858c20df0424    /var/www/oddb.org.rack/vendor/ruby/2.4.0/gems/htmlgrid-1.1.4/lib/htmlgrid/list.rb:65:in `each'

The OpenURI 502 error is not found the user.log. I can reproduce a similar error by raising unconditionally an error in src/view/tooltip.rb.

I think the simplest and correct solution is to remove the rescue statement in lib/sbsm/session process_rack and let rack handle the problem. But in this case the error is only logged in the standard output, which is not nice.

In the generika.oddb-ci2 section of the apache log (as in all sections redirecting) we must find lines like

  RewriteCond %{DOCUMENT_ROOT}/%{REQUEST_URI}  -f
  RewriteRule ^/(.*)$ %{DOCUMENT_ROOT}/%{REQUEST_URI} [L,NC]
  RewriteRule  /var/www/oddb.org.rack/doc/resources/errors/appdown.html  /var/www/oddb.org.rack/doc/resources/errors/appdown.html [L]
  RewriteRule ^/(.*)$ http://localhost:8512/$1 [P]

Got another App-Down error locally. I think the problems stems from the fact, that the tooltip loads its content via a call to the own server. This leads to:

  • Many entries for ajax-scripts in the log file
  • When such as sub call fails (which is quite probable if you load a long list and the server exits), the call is not handled via the normal 503 handler. Therefore we should find a workaround to generate the ajax script content locally and without a HTTP request.

Fixed an error in lib/sbsm/session.rb where the mutex did not protect the whole content of the process_rack method.

Also I think the SessionStore should be made more robust. And it has no unit test till now (what a shame!).

Found the reason why the limit was not working. The old method process in src/util/session.rb was no longer used. And an override for the SBSM::Session.process was not found in any other ported SBSM apps. Fixed this problem and now the requests are counted correctly. But somehow the rate limit still does not work as expected. The variable @state.request_path seems to be updated wrongly. Fixed this problem by adding an optional process_late method in lib/sbsm/session.rb. Now it passes correctly.

Pushed some commits and restarted siege tests.

Next week I want to see whether I cannot calculate the retrievied via an OpenURI href in src/view/tooltip.rb by a locally calculated value. To test it while developing would be easy. Just fetch the old value and compare it with the newly calculated value. Maybe I have to add a method mock_process_url in sbsbm/session.

view · edit · sidebar · attach · print · history
Page last modified on July 05, 2017, at 04:54 PM