view · edit · sidebar · attach · print · history

Index>

20170509-virbac-rack-yus

Summary

  • Fix problems accessing YUS in new rack based virbac
  • Keep in Mind

Commits

Index

Fix problems accessing YUS in new rack based virbac

Looking at the output of the yus daemon when logging in as a normal user (using the old non rack based virbac.bbmb.ch).

@4000000059115b3218e6c75c I, [2017-05-09T08:01:12.417723 #6946]  INFO -- start: starting yus-server on druby://127.0.0.1:12003
C@4000000059115c691f0d0efc I, [2017-05-09T08:06:23.520903 #6946]  INFO -- Yus::Server: Login attempt for claude.meier@gmx.net from ch.bbmb.virbac
@4000000059115c691f0faaf4 I, [2017-05-09T08:06:23.521097 #6946]  INFO -- Yus::Server: Authentication succeeded for claude.meier@gmx.net
@4000000059115c69200837dc D, [2017-05-09T08:06:23.537373 #6946] DEBUG -- Yus::EntitySession: claude.meier@gmx.net allowed?(edit, yus.entities) returns false
@4000000059115c69201128ec D, [2017-05-09T08:06:23.537974 #6946] DEBUG -- Yus::EntitySession: claude.meier@gmx.net allowed?(login, ch.bbmb.virbac.Admin) returns false
@4000000059115c69201704ec D, [2017-05-09T08:06:23.538356 #6946] DEBUG -- Yus::EntitySession: claude.meier@gmx.net allowed?(login, ch.bbmb.virbac.Customer) returns true

The log on sysout is

, [2017-05-09T08:06:05.729095 #8689] DEBUG -- updater: run_updater run_only_once_at_startup? false 
D, [2017-05-09T08:06:05.729194 #8689] DEBUG -- : run_invoicer starting
D, [2017-05-09T08:06:05.729287 #8689] DEBUG -- updater: sleeping 28434.27 seconds. run_only_once_at_startup false
I, [2017-05-09T08:06:05.729480 #8689]  INFO -- start: starting bbmb-server on druby://127.0.0.1:12002
D, [2017-05-09T08:06:05.729558 #8689] DEBUG -- invoicer: sleeping 1958034.27 seconds
logout SBSM::UnknownUser => #<BBMB::Html::State::Login:0x0055a01ee50bc8>
logout nil setting @state 47238644183360 BBMB::Html::State::Login remember nil SBSM::UnknownUser 
Changing from 47073100728740 to state BBMB::Html::State::Login 47073100728740 remember nil
navigation return []
Checking entity_valid? for validity I am BBMB::Html::Util::KnownUser
D, [2017-05-09T08:06:23.537654 #8689] DEBUG -- User: claude.meier@gmx.net: allowed?(edit, yus.entities) -> false
valid false
session= defined? false
BBMB::Html::Util::Session login claude.meier@gmx.net 5972659ce6c7f9b2356c0e650c7c40a3  BBMB::Html::Util::KnownUser
D, [2017-05-09T08:06:23.538178 #8689] DEBUG -- User: claude.meier@gmx.net: allowed?(login, ch.bbmb.virbac.Admin) -> false
D, [2017-05-09T08:06:23.538604 #8689] DEBUG -- User: claude.meier@gmx.net: allowed?(login, ch.bbmb.virbac.Customer) -> true
Changing from 47073100728740 to state BBMB::Html::State::CurrentOrder 70353181872580 remember nil
navigation return [:current_order, :orders, :favorites, :catalogue, :quotas, :promotions, :calculator, :change_pass, :logout]

Now comparing it with the logs when running the new rack based version. Output of yus daemon log is

@4000000059115ce02ed9c064 I, [2017-05-09T08:08:22.785979 #9357]  INFO -- start: starting yus-server on druby://127.0.0.1:12003
@4000000059115d1507004644 I, [2017-05-09T08:09:15.117408 #9357]  INFO -- Yus::Server: Login attempt for claude.meier@gmx.net from ch.bbmb.virbac
@4000000059115d150702c2fc I, [2017-05-09T08:09:15.117594 #9357]  INFO -- Yus::Server: Authentication succeeded for claude.meier@gmx.net
@4000000059115d1507f740d4 D, [2017-05-09T08:09:15.133606 #9357] DEBUG -- Yus::EntitySession: claude.meier@gmx.net allowed?(login, ch.bbmb.virbac.Admin) returns false
@4000000059115d1507fbdc84 D, [2017-05-09T08:09:15.133919 #9357] DEBUG -- Yus::EntitySession: claude.meier@gmx.net allowed?(login, ch.bbmb.virbac.Customer) returns true

And the output of the virbac_rack

config.ru:33:in `block in <main>' Starting Rack::Server BBMB::BBMB::Util.new with log_pattern /var/www/virbac_rack.bbmb.ch/log/%Y/%m/%d/app_log
app.rb:42:in `initialize' initialize BBMB::Util::App
app.rb:46:in `set_auth' set_auth to DRb::DRbObject
app.rb:90:in `initialize' initialize validator VIRBAC::Html::Util::Validator th  cookie virbac.bbmb session BBMB::Html::Util::Session app BBMB::Util::App auth_class DRb::DRbObject multi_threaded 
session.rb:114:in `initialize' initialize th #<SBSM::TransHandler:0x005639b02bf620> validator VIRBAC::Html::Util::Validator app BBMB::Util::App
BBMB::Html::Util::KnownUser.new object_id is 47402883963840 SBSM::Session ? false
session.rb:140:in `initialize' session initialized #<BBMB::Util::App:0x005639b0268d70> with @cgi #<CGI:0x005639b01eb168> multi_threaded false app 47402884220600
app.rb:134:in `call' starting session_id 13148a2441a6008bc3aedfc2d0c  session BBMB::Html::Util::Session /: cookies  are {} @cgi NilClass
session.rb:50:in `logout' BBMB::Html::Util::Session logout 
session.rb:383:in `logout' logout "/de/bbmb/home/" setting @state 47268526893260 BBMB::Html::State::Login remember nil BBMB::Html::Util::KnownUser
session.rb:225:in `block in process_rack' active_state.trigger state 47402883321060 BBMB::Html::State::Login remember nil
session.rb:234:in `block in process_rack' Changing from 47402883321060 to state BBMB::Html::State::Login 47402883321060 remember nil
sbsm:state new view BBMB::Html::View::Login
BBMB::Html::Util::KnownUser navigation returning  [ :logout ]
navigation return [:logout]
NavigationLink unless  == logout
app.rb:149:in `call' finish session_id.1 13148a2441a6008bc3aedfc2d0c: matches response.headers['Set-Cookie']
app.rb:123:in `call' file_name is /var/www/virbac_rack.bbmb.ch/doc/resources/bbmb/bbmb.css checkin base bbmb.css MIME text/css
app.rb:123:in `call' file_name is /var/www/virbac_rack.bbmb.ch/doc/resources/bbmb/logo.gif checkin base logo.gif MIME image/gif
app.rb:134:in `call' starting session_id 13148a2441a6008bc3aedfc2d0c  session BBMB::Html::Util::Session /de/bbmb: cookies  are {"_session_id"=>"13148a2441a6008bc3aedfc2d0c"} @cgi NilClass
login.rb:19:in `login' BBMB::Html::State Login login claude.meier@gmx.net 5972659ce6c7f9b2356c0e650c7c40a3  NilClass
session= defined? false
session.rb:45:in `login' BBMB::Html::Util::Session login claude.meier@gmx.net 5972659ce6c7f9b2356c0e650c7c40a3  DRb::DRbObject
viral_modules trying .Admin BBMB::Html::State::Viral::Admin
viral_modules trying .Customer BBMB::Html::State::Viral::Customer
Was allowed via user #<Yus::EntitySession:0x0055a70c841698> for BBMB::Html::State::Viral::Customer
global.rb:26:in `initialize' BBMB::Html::State Global session BBMB::Html::Util::Session model BBMB::Html::Util::KnownUser
session.rb:225:in `block in process_rack' active_state.trigger state 69977038546920 BBMB::Html::State::CurrentOrder remember nil
session.rb:234:in `block in process_rack' Changing from 47402883321060 to state BBMB::Html::State::CurrentOrder 69977038546920 remember nil
sbsm:state new view BBMB::Html::View::CurrentOrder
<..>
navigation returns [:current_order, :orders, :favorites, :catalogue, :quotas, :promotions, :calculator, :change_pass]

Comparing the steps:

  • (BOTH) start: starting yus-server on druby://127.0.0.1:12003
  • (BOTH) Yus::Server: Login attempt for claude.meier@gmx.net from ch.bbmb.virbac
  • (BOTH) Yus::Server: Authentication succeeded for claude.meier@gmx.net
  • (Missing in new one) Yus::EntitySession: claude.meier@gmx.net allowed?(edit, yus.entities) returns false
  • (BOTH) Yus::EntitySession: claude.meier@gmx.net allowed?(login, ch.bbmb.virbac.Admin) returns false
  • (BOTH) Yus::EntitySession: claude.meier@gmx.net allowed?(login, ch.bbmb.virbac.Customer) returns true
  • start: starting yus-s

We see that one step is missing in the new one. Why? Also we see that the old returned in the step :logout navivation. The old one had in the method BBMB::Html::Util::Session.login the class BBMB::Html::Util::KnownUser as @user attribute and not a DRb::DRbObject.

But the difference starts earlier. The first call to navigation returns [] in the old and [:logout] in new virbac. Added two more puts for the old virbac to easier compare the two logs.

The problem is that in BBMB::Html::Util::Lookandfeel#navigation: we try to get the navigation via the super classes SBSM::Lookandfeel#navigation:, SBSM::Session#navigation:, SBSM::User#navigation:. This works in the old virbac. The new rack tries to get it via the superclases SBSM::Lookandfeel#navigation:, SBSM::Session#navigation:, BBMB::Html::Util::KnownUser#navigation:.

Which means that it has the wrong @user.class. In sbsm-1.3.0/lib/sbsm/session.rb @ line 338 SBSM::Session#navigation the @user is a SBSM::UnknownUser. Whereas in the new one it is BBMB::Html::Util::KnownUser.

Changed the logout procedure in SBSM::Session to only create a new unknown user unless the current user is a SBSM::UnknownUser. Now we fail at bbmb/lib/bbmb/html/view/head.rb BBMB::Html::View::Head#logged_in_as: where @session.logged_in? returns true instead of false.

Changed the implementation of SBSM::Session.logout to !(@user.is_a?(@unknown_user_class) || @user.is_a?(SBSM::UnknownUser)). Now loading http://virbac_rack.ngiger.ch/ works and does no longer show the wrong logout link

Now the relevant log for the old virbac is

logout nil setting @state 47370496040580 BBMB::Html::State::Login remember nil SBSM::UnknownUser
sbsm.session.new user is SBSM::UnknownUser
Changing from 47370496040580 to state BBMB::Html::State::Login 47370496040580 remember nil  SBSM::UnknownUser
sbsm:state new view BBMB::Html::View::Login for user SBSM::UnknownUser
navigation return []
Checking entity_valid? for validity I am BBMB::Html::Util::KnownUser
D, [2017-05-09T11:23:33.511291 #3889] DEBUG -- User: claude.meier@gmx.net: allowed?(edit, yus.entities) -> false
valid false
session= defined? false
BBMB::Html::Util::Session login claude.meier@gmx.net 5972659ce6c7f9b2356c0e650c7c40a3  BBMB::Html::Util::KnownUser
D, [2017-05-09T11:23:33.511780 #3889] DEBUG -- User: claude.meier@gmx.net: allowed?(login, ch.bbmb.virbac.Admin) -> false
D, [2017-05-09T11:23:33.512129 #3889] DEBUG -- User: claude.meier@gmx.net: allowed?(login, ch.bbmb.virbac.Customer) -> true
Changing from 47370496040580 to state BBMB::Html::State::CurrentOrder 69990323113560 remember nil  BBMB::Html::Util::KnownUser
sbsm:state new view BBMB::Html::View::CurrentOrder for user BBMB::Html::Util::KnownUser
navigation return [:current_order, :orders, :favorites, :catalogue, :quotas, :promotions, :calculator, :change_pass, :logout]

Remarked that with the Rack based virbac we have in SBSM::Session#process_rack the @user asa DRbObject instead of a BBMB::Html::Util::KnownUser.

As I started using everywher SBSM::UnknownUser for the unknown_user it was quite easy to make the login/logout as normal and admin user pass. Reviewing my changes in SBSM, BBMB and virbac before pushing the changes. This will take some time, as I need to review several changes, to see whether they are really necessary. Also must make the unit tests pass again (at least the most important ones). My lokal changes are:

Must refactor SBSM to remove the not really used auth. This was easy and made the code more understandable. Same for the unkown_user. Now working on make at least some unit test for SBSM work again.

Adding a file manual_test.md to specify the test that should be done manually.

Running sudo -u bbmb /usr/local/bin/bundle-240 exec bin/update_abschluss_artikel_artikel_fr_kunden fails because of NoMethodError: undefined method `log_level' for #<RCLConf::RCLConf:0x0055dd7235b470>. Fixing the problem.

Copied the CSV files from my backup to /var/www/virbac.bbmb.ch/var/ftp. Even when being in /var/www/virbac_rack.bbmb.ch the etc/config.yml by default used the polling file from /var/www/virbac.bbmb.ch/etc.

Had to add require 'bbmb/util/csv_importer' and some lines to load the config into bin/update_abschluss_artikel_artikel_fr_kunden to make the import start. Had to re-import the database because I suddenly got the error undefined class/module Encoding::Character:: (ArgumentError) when starting the app.

May be get this errors because while debugging I used several times a kill -9 my_ruby_app to continue working. Restarting postgres.

The importer created a lot of new customers e.g Created new customer_id 200077 which is a BBMB::Model::Customer with odba_id 54763, after I changed a few lines in the bin/update_abschluss_artikel_artikel_fr_kunden to avoid the Encoding error. But maybe now the ODBA-Persistence layer is not initialized correctly.

Importer finished with the following

var/www/virbac_rack.bbmb.ch/lib/bbmb/util/csv_importer.rb:106:in `block in import_record'
/var/www/virbac_rack.bbmb.ch/lib/bbmb/util/csv_importer.rb:106:in `each'
/var/www/virbac_rack.bbmb.ch/lib/bbmb/util/csv_importer.rb:106:in `find_all'
/var/www/virbac_rack.bbmb.ch/lib/bbmb/util/csv_importer.rb:106:in `import_record'
/var/www/virbac_rack.bbmb.ch/lib/bbmb/util/csv_importer.rb:47:in `block in import'
/usr/local/ruby-2.4.0/lib/ruby/2.4.0/csv.rb:1771:in `each'
/var/www/virbac_rack.bbmb.ch/lib/bbmb/util/csv_importer.rb:40:in `each_with_index'
/var/www/virbac_rack.bbmb.ch/lib/bbmb/util/csv_importer.rb:40:in `import'
/home/niklaus/git/bbmb/lib/bbmb/util/updater.rb:20:in `import'
/home/niklaus/git/bbmb/lib/bbmb/util/updater.rb:14:in `block in run'
/home/niklaus/git/bbmb/lib/bbmb/util/polling_manager.rb:31:in `block in poll_path'
/home/niklaus/git/bbmb/lib/bbmb/util/polling_manager.rb:30:in `open'
/home/niklaus/git/bbmb/lib/bbmb/util/polling_manager.rb:30:in `poll_path'
/home/niklaus/git/bbmb/lib/bbmb/util/polling_manager.rb:26:in `block in poll'
/home/niklaus/git/bbmb/lib/bbmb/util/polling_manager.rb:25:in `each'
/home/niklaus/git/bbmb/lib/bbmb/util/polling_manager.rb:25:in `poll'
/home/niklaus/git/bbmb/lib/bbmb/util/polling_manager.rb:137:in `block in poll_sources'
/home/niklaus/git/bbmb/lib/bbmb/util/polling_manager.rb:130:in `block in load_sources'
/var/www/virbac_rack.bbmb.ch/vendor/ruby/2.4.0/gems/syck-1.3.0/lib/syck.rb:242:in `load_documents'
/var/www/virbac_rack.bbmb.ch/vendor/ruby/2.4.0/gems/syck-1.3.0/lib/syck.rb:242:in `load_documents'
/home/niklaus/git/bbmb/lib/bbmb/util/polling_manager.rb:129:in `load_sources'
/home/niklaus/git/bbmb/lib/bbmb/util/polling_manager.rb:136:in `poll_sources'
/home/niklaus/git/bbmb/lib/bbmb/util/updater.rb:11:in `run'
/home/niklaus/git/bbmb/lib/bbmb/util/server.rb:204:in `update'
bin/update_abschluss_artikel_artikel_fr_kunden:49:in `<module:BBMB>'
bin/update_abschluss_artikel_artikel_fr_kunden:14:in `<top (required)>'
/usr/local/ruby-2.4.0/lib/ruby/gems/2.4.0/gems/bundler-1.14.6/lib/bundler/cli/exec.rb:74:in `load'
/usr/local/ruby-2.4.0/lib/ruby/gems/2.4.0/gems/bundler-1.14.6/lib/bundler/cli/exec.rb:74:in `kernel_load'
/usr/local/ruby-2.4.0/lib/ruby/gems/2.4.0/gems/bundler-1.14.6/lib/bundler/cli/exec.rb:27:in `run'
/usr/local/ruby-2.4.0/lib/ruby/gems/2.4.0/gems/bundler-1.14.6/lib/bundler/cli.rb:335:in `exec'
/usr/local/ruby-2.4.0/lib/ruby/gems/2.4.0/gems/bundler-1.14.6/lib/bundler/vendor/thor/lib/thor/command.rb:27:in `run'
/usr/local/ruby-2.4.0/lib/ruby/gems/2.4.0/gems/bundler-1.14.6/lib/bundler/vendor/thor/lib/thor/invocation.rb:126:in `invoke_command'
/usr/local/ruby-2.4.0/lib/ruby/gems/2.4.0/gems/bundler-1.14.6/lib/bundler/vendor/thor/lib/thor.rb:359:in `dispatch'
/usr/local/ruby-2.4.0/lib/ruby/gems/2.4.0/gems/bundler-1.14.6/lib/bundler/cli.rb:20:in `dispatch'
/usr/local/ruby-2.4.0/lib/ruby/gems/2.4.0/gems/bundler-1.14.6/lib/bundler/vendor/thor/lib/thor/base.rb:440:in `start'
/usr/local/ruby-2.4.0/lib/ruby/gems/2.4.0/gems/bundler-1.14.6/lib/bundler/cli.rb:11:in `start'
/usr/local/ruby-2.4.0/lib/ruby/gems/2.4.0/gems/bundler-1.14.6/exe/bundle:32:in `block in <top (required)>'
/usr/local/ruby-2.4.0/lib/ruby/gems/2.4.0/gems/bundler-1.14.6/lib/bundler/friendly_errors.rb:121:in `with_friendly_errors'
/usr/local/ruby-2.4.0/lib/ruby/gems/2.4.0/gems/bundler-1.14.6/exe/bundle:24:in `<top (required)>'
/usr/local/bin/bundle-240:22:in `load'
/usr/local/bin/bundle-240:22:in `<main>'
Rescue target of repeat operator is not specified: /*farmaciaportone@bluewin.ch/ in import
csv_importer.rb: UTF-8 importing /var/www/virbac.bbmb.ch/var/ftp/ARTIKEL.CSV 348 lines
...ProductImporter postprocess
Rescue undefined method `compact' for #<BBMB::Model::Order:0x0055dcc3ad21e0> in import
csv_importer.rb: UTF-8 importing /var/www/virbac.bbmb.ch/var/ftp/ABSCHLUSS.CSV 6615 lines
.......... 1000
.......... 2000
.......... 3000
.......... 4000
.Rescue undefined method `compact' for #<BBMB::Model::Order:0x0055dcc42b8198> in import
csv_importer.rb: UTF-8 importing /var/www/virbac.bbmb.ch/var/ftp/ARTIKEL_FR.CSV 348 lines
...ProductImporter postprocess
Rescue undefined method `compact' for #<BBMB::Model::Order:0x0055dcc42b8198> in import
2017-05-09 17:30:33 +0200: Finished update after 13 minutes and 29 seconds
2017-05-09 17:30:33 +0200 at_exit time: workdir is /var/www/virbac_rack.bbmb.ch bbmb_dir is /var/www/virbac_rack.bbmb.ch Dir. pwd is /var/www/virbac_rack.bbmb.ch

After the import I get now the error NoMethodError at /de/bbmb/customer/customer_id/708427 undefined method `total' for nil:NilClass

view · edit · sidebar · attach · print · history
Page last modified on May 09, 2017, at 05:43 PM