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:
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