20110914-debug-recycle_object_error-migel
<< | Index | >>
- Update importer with delete method migel
- Testcases for the new methods of importer
- Debug Recycle object error migel
Goal/Estimate/Evaluation:
- Debug importer migel / 90% / 80%
- Milestones
put 'delete' method into the import processTestcases for new methods importer- Debug RangeError
- Debug Another error
- Importer job
- Summary
- ToDo
- spec for lib/migel/server.rb#init_fullindex_text_tables
- require 'migel/util/m10l_document' problem in multilingual.rb
- require 'oddb/util/m10l_document' problem in model_super.rb
Update importer with delete method migel
Restore
masa@masa ~/ywesee/migel_dev $ sudo -u postgres dropdb migel; sudo -u postgres createdb -E UTF8 -T template0 migel masa@masa ~/ywesee/migel_dev $ cat migel_database_backup.20110913.sql |psql -U postgres migel masa@masa ~/ywesee/migel_dev $ bin/migeld
Run
- bin/migeld
- bin/admin
migel> Migel::Model::Migelid.find_by_migel_code('15.30.50.00.1').products.map{|x| x.pharmacode}.join(",")
-> 2126917,2126923,2126975,2126981,2760086,2760092,2760100,2998899
migel> Migel::Util::Importer.new.import_all_products_from_csv('test.csv', 'de', true)
Note
- test.csv does not include the Product of '15.30.50.00.1'
Result
migel> Migel::Model::Migelid.find_by_migel_code('15.30.50.00.1').products.length
-> 0
migel> Migel::Model::Migelid.find_by_migel_code('15.30.50.00.1').products.map{|x| x.pharmacode}.join(",")
->
Note
- Looks good
Testcases for the new methods of importer
Result
masa@masa ~/ywesee/migel_dev $ rcov spec/suite.rb -t Loaded suite /usr/bin/rcov Started Finished in 0.000135 seconds. 0 tests, 0 assertions, 0 failures, 0 errors .......................................................................................... Finished in 0.19292 seconds 90 examples, 0 failures 91.3% 20 file(s) 2312 Lines 2073 LOC
Debug Recycle object error migel
Problem
- Sometimes the Recycle object error happens
Console log (oddb.org)
error in SBSM::Session#process: /de/gcc/sort/state_id/70010518569200/sortvalue/size RangeError 0x3fc7948725bc is recycled object (druby://localhost:33000) /usr/lib64/ruby/1.8/drb/drb.rb:375:in `_id2ref' (druby://localhost:33000) /usr/lib64/ruby/1.8/drb/drb.rb:375:in `to_obj' (druby://localhost:33000) /usr/lib64/ruby/site_ruby/1.8/odba/drbwrapper.rb:70:in `to_obj' (druby://localhost:33000) /usr/lib64/ruby/1.8/drb/drb.rb:1402:in `to_obj' (druby://localhost:33000) /usr/lib64/ruby/1.8/drb/drb.rb:1704:in `to_obj' error in SBSM::Session#to_html: /de/gcc/sort/state_id/70010518569200/sortvalue/size RangeError 0x3fc7948725bc is recycled object (druby://localhost:33000) /usr/lib64/ruby/1.8/drb/drb.rb:375:in `_id2ref' (druby://localhost:33000) /usr/lib64/ruby/1.8/drb/drb.rb:375:in `to_obj' (druby://localhost:33000) /usr/lib64/ruby/site_ruby/1.8/odba/drbwrapper.rb:70:in `to_obj' (druby://localhost:33000) /usr/lib64/ruby/1.8/drb/drb.rb:1402:in `to_obj' (druby://localhost:33000) /usr/lib64/ruby/1.8/drb/drb.rb:1704:in `to_obj' (druby://localhost:33000) /usr/lib64/ruby/1.8/drb/drb.rb:613:in `recv_request' (druby://localhost:33000) /usr/lib64/ruby/1.8/drb/drb.rb:911:in `recv_request' (druby://localhost:33000) /usr/lib64/ruby/1.8/drb/drb.rb:1530:in `init_with_client' (druby://localhost:33000) /usr/lib64/ruby/1.8/drb/drb.rb:1542:in `setup_message' (druby://localhost:33000) /usr/lib64/ruby/1.8/drb/drb.rb:1494:in `perform' (druby://localhost:33000) /usr/lib64/ruby/1.8/drb/drb.rb:1589:in `main_loop' (druby://localhost:33000) /usr/lib64/ruby/1.8/drb/drb.rb:1585:in `loop' (druby://localhost:33000) /usr/lib64/ruby/1.8/drb/drb.rb:1585:in `main_loop' (druby://localhost:33000) /usr/lib64/ruby/1.8/drb/drb.rb:1581:in `start' (druby://localhost:33000) /usr/lib64/ruby/1.8/drb/drb.rb:1581:in `main_loop' (druby://localhost:33000) /usr/lib64/ruby/1.8/drb/drb.rb:1430:in `run' (druby://localhost:33000) /usr/lib64/ruby/1.8/drb/drb.rb:1427:in `start' (druby://localhost:33000) /usr/lib64/ruby/1.8/drb/drb.rb:1427:in `run' (druby://localhost:33000) /usr/lib64/ruby/1.8/drb/drb.rb:1347:in `initialize' (druby://localhost:33000) /usr/lib64/ruby/1.8/drb/drb.rb:1627:in `new' (druby://localhost:33000) /usr/lib64/ruby/1.8/drb/drb.rb:1627:in `start_service' (druby://localhost:33000) bin/migeld:22 /home/masa/ywesee/oddb.org/src/model/migel/items.rb:25:in `empty?' /usr/lib64/ruby/site_ruby/1.8/htmlgrid/list.rb:51:in `compose' /usr/lib64/ruby/site_ruby/1.8/htmlgrid/composite.rb:55:in `init' /usr/lib64/ruby/site_ruby/1.8/htmlgrid/list.rb:129:in `init' /home/masa/ywesee/oddb.org/src/view/migel/items.rb:63:in `init' /usr/lib64/ruby/site_ruby/1.8/htmlgrid/component.rb:138:in `initialize' /usr/lib64/ruby/site_ruby/1.8/htmlgrid/composite.rb:59:in `new' /usr/lib64/ruby/site_ruby/1.8/htmlgrid/composite.rb:59:in `create' /usr/lib64/ruby/site_ruby/1.8/htmlgrid/composite.rb:280:in `compose_component' /usr/lib64/ruby/site_ruby/1.8/htmlgrid/composite.rb:209:in `compose' /usr/lib64/ruby/site_ruby/1.8/htmlgrid/composite.rb:203:in `each' /usr/lib64/ruby/site_ruby/1.8/htmlgrid/composite.rb:203:in `compose' /usr/lib64/ruby/site_ruby/1.8/htmlgrid/composite.rb:55:in `init' /usr/lib64/ruby/site_ruby/1.8/htmlgrid/component.rb:138:in `initialize' /home/masa/ywesee/oddb.org/src/view/publictemplate.rb:53:in `new' /home/masa/ywesee/oddb.org/src/view/publictemplate.rb:53:in `content' /usr/lib64/ruby/site_ruby/1.8/htmlgrid/composite.rb:66:in `send' /usr/lib64/ruby/site_ruby/1.8/htmlgrid/composite.rb:66:in `create' /usr/lib64/ruby/site_ruby/1.8/htmlgrid/composite.rb:280:in `compose_component' /usr/lib64/ruby/site_ruby/1.8/htmlgrid/composite.rb:209:in `compose' /usr/lib64/ruby/site_ruby/1.8/htmlgrid/composite.rb:203:in `each' /usr/lib64/ruby/site_ruby/1.8/htmlgrid/composite.rb:203:in `compose' /usr/lib64/ruby/site_ruby/1.8/htmlgrid/composite.rb:55:in `init' /home/masa/ywesee/oddb.org/src/view/publictemplate.rb:50:in `init' /home/masa/ywesee/oddb.org/src/view/privatetemplate.rb:16:in `init' /usr/lib64/ruby/site_ruby/1.8/htmlgrid/component.rb:138:in `initialize' /usr/lib64/ruby/site_ruby/1.8/sbsm/state.rb:285:in `new' /usr/lib64/ruby/site_ruby/1.8/sbsm/state.rb:285:in `view' /usr/lib64/ruby/site_ruby/1.8/sbsm/state.rb:197:in `to_html' /usr/lib64/ruby/site_ruby/1.8/sbsm/session.rb:529:in `to_html' /usr/lib64/ruby/site_ruby/1.8/sbsm/session.rb:177:in `drb_process' /usr/lib64/ruby/site_ruby/1.8/sbsm/session.rb:174:in `synchronize' /usr/lib64/ruby/site_ruby/1.8/sbsm/session.rb:174:in `drb_process' /usr/lib64/ruby/1.8/drb/drb.rb:1555:in `__send__' /usr/lib64/ruby/1.8/drb/drb.rb:1555:in `perform_without_block' /usr/lib64/ruby/1.8/drb/drb.rb:1515:in `perform' /usr/lib64/ruby/1.8/drb/drb.rb:1589:in `main_loop' /usr/lib64/ruby/1.8/drb/drb.rb:1585:in `loop' /usr/lib64/ruby/1.8/drb/drb.rb:1585:in `main_loop' /usr/lib64/ruby/1.8/drb/drb.rb:1581:in `start' /usr/lib64/ruby/1.8/drb/drb.rb:1581:in `main_loop' /usr/lib64/ruby/1.8/drb/drb.rb:1430:in `run' /usr/lib64/ruby/1.8/drb/drb.rb:1427:in `start' /usr/lib64/ruby/1.8/drb/drb.rb:1427:in `run' /usr/lib64/ruby/1.8/drb/drb.rb:1347:in `initialize' /usr/lib64/ruby/1.8/drb/drb.rb:1627:in `new' /usr/lib64/ruby/1.8/drb/drb.rb:1627:in `start_service' bin/oddbd:38 ODDB::View::Migel::SearchedComposite::COMPONENTS[[0, 0]] in create(ODDB::View::Migel::SearchedList) ODDB::View::Migel::Items::COMPONENTS[[0, 3]] in create(content)
Experiment
- src/model/migel/items.rb
def empty?
begin
@list.empty?
rescue => e
p e
end
end
def each
begin
@list.each do |record|
yield record
end
rescue => e
p e
p "each error"
end
end
Access
- http://oddb.masa.org/de/gcc/migel_search/migel_code/170103001
- sort by pharmacode or ean_code
Result
error in SBSM::Session#process: /de/gcc/sort/state_id/69982701832320/sortvalue/pharmacode RangeError 0x3ff1e3c37d40 is recycled object (druby://localhost:33000) /usr/lib64/ruby/1.8/drb/drb.rb:375:in `_id2ref' (druby://localhost:33000) /usr/lib64/ruby/1.8/drb/drb.rb:375:in `to_obj' (druby://localhost:33000) /usr/lib64/ruby/site_ruby/1.8/odba/drbwrapper.rb:70:in `to_obj' (druby://localhost:33000) /usr/lib64/ruby/1.8/drb/drb.rb:1402:in `to_obj' (druby://localhost:33000) /usr/lib64/ruby/1.8/drb/drb.rb:1704:in `to_obj' #<RangeError: 0x3ff1e3c37d40 is recycled object> "empty error" #<RangeError: 0x3ff1e3c37d40 is recycled object> "each error"
Note
- This result view has many products data shown.
Different error
- sort by article name
#<NoMethodError: undefined method `migel_code' for "chop!":String> "each error"
- sort by status
error in SBSM::Session#process: /de/gcc/sort/state_id/70240141341660/sortvalue/status NoMethodError undefined method `sort!' for "require":String /home/masa/ywesee/oddb.org/src/model/migel/items.rb:41:in `sort!' /home/masa/ywesee/oddb.org/src/state/migel/items.rb:43:in `sort' /usr/lib64/ruby/site_ruby/1.8/sbsm/state.rb:222:in `send' /usr/lib64/ruby/site_ruby/1.8/sbsm/state.rb:222:in `_trigger' /home/masa/ywesee/oddb.org/src/state/global.rb:700:in `_trigger' #<NoMethodError: undefined method `migel_code' for "require":String> "each error"
Traceback
- (druby://localhost:33000) /usr/lib64/ruby/1.8/drb/drb.rb:375:in `_id2ref'
# Convert an object reference id to an object.
#
# This implementation looks up the reference id in the local object
# space and returns the object it refers to.
def to_obj(ref)
ObjectSpace._id2ref(ref)
end
test.rb
class Test
attr_reader :hoge
def initialize(a)
@hoge = a
end
end
test1 = Test.new('hoge')
test2 = Test.new('poke')
p test1.hoge
p test2.hoge
p test1.__id__
p test2.__id__
ref = test2.__id__
test3 = ObjectSpace._id2ref(ref)
p test3.hoge
Result
"hoge" "poke" 69930583577560 69930583589120 "poke"
Note
- ObjectSpace._id2ref(ref) returns an object by using Object ID (Object#__id__)
- If there is no object corresponding to the Object ID, RangeError is returned
- In particular, RangeError with a message 'recycle object' is returned if the object is marked by LazySweeper of Ruby.
Reference
- http://svn.ruby-lang.org/cgi-bin/viewvc.cgi?revision=33219&view=revision
- http://d.hatena.ne.jp/nagachika/searchdiary?word=ruby%20recycled%20object (Japanese)
- http://blade.nagaokaut.ac.jp/cgi-bin/scat.rb/ruby/ruby-list/24191 (Japanese)
Question
- Where does the Object ID come from?
Experiment
- persion.rb
class Person
include DRbUndumped
attr_accessor :n
def initialize(n)
@n = n
end
end
- server.rb
require 'thread'
require 'drb'
require 'person'
here = 'druby://localhost:17640'
@queue = Queue.new
10.times { |i| @queue.push([i, Person.new(i)]) }
DRb.start_service(here, @queue)
#DRb.thread.join
- client.rb
require 'drb' require 'person' there = 'druby://localhost:17640' DRb.start_service(nil) @queue = DRbObject.new(nil, there)
Run
- server side
masa@masa ~/work $ irb irb(main):001:0> require 'server' => true irb(main):002:0> @queue.length => 10
- client side
masa@masa ~/work $ irb irb(main):001:0> require 'client' => true irb(main):002:0> @queue.length => 10 irb(main):003:0> q = @queue.pop => #<DRb::DRbObject:0x7f77703cb0b0 @uri="druby://localhost:17640", @ref=69909259846360> irb(main):004:0> q[1].n => 0 irb(main):005:0> @queue.length => 9
- server side
irb(main):003:0> @queue.length => 9 irb(main):004:0> GC.start => nil
- client side
irb(main):006:0> q[1].n
RangeError: 0x3f95049982d8 is recycled object
from (druby://localhost:17640) /usr/lib64/ruby/1.8/drb/drb.rb:375:in `_id2ref'
from (druby://localhost:17640) /usr/lib64/ruby/1.8/drb/drb.rb:375:in `to_obj'
from (druby://localhost:17640) /usr/lib64/ruby/1.8/drb/drb.rb:1402:in `to_obj'
from (druby://localhost:17640) /usr/lib64/ruby/1.8/drb/drb.rb:1704:in `to_obj'
from (druby://localhost:17640) /usr/lib64/ruby/1.8/drb/drb.rb:613:in `recv_request'
from (druby://localhost:17640) /usr/lib64/ruby/1.8/drb/drb.rb:911:in `recv_request'
from (druby://localhost:17640) /usr/lib64/ruby/1.8/drb/drb.rb:1530:in `init_with_client'
from (druby://localhost:17640) /usr/lib64/ruby/1.8/drb/drb.rb:1542:in `setup_message'
from (druby://localhost:17640) /usr/lib64/ruby/1.8/drb/drb.rb:1494:in `perform'
from (druby://localhost:17640) /usr/lib64/ruby/1.8/drb/drb.rb:1589:in `main_loop'
from (druby://localhost:17640) /usr/lib64/ruby/1.8/drb/drb.rb:1585:in `loop'
from (druby://localhost:17640) /usr/lib64/ruby/1.8/drb/drb.rb:1585:in `main_loop'
from (druby://localhost:17640) /usr/lib64/ruby/1.8/drb/drb.rb:1581:in `start'
from (druby://localhost:17640) /usr/lib64/ruby/1.8/drb/drb.rb:1581:in `main_loop'
from (druby://localhost:17640) /usr/lib64/ruby/1.8/drb/drb.rb:1430:in `run'
from (druby://localhost:17640) /usr/lib64/ruby/1.8/drb/drb.rb:1427:in `start'
from (druby://localhost:17640) /usr/lib64/ruby/1.8/drb/drb.rb:1427:in `run'
from (druby://localhost:17640) /usr/lib64/ruby/1.8/drb/drb.rb:1347:in `initialize'
from (druby://localhost:17640) /usr/lib64/ruby/1.8/drb/drb.rb:1627:in `new'
from (druby://localhost:17640) /usr/lib64/ruby/1.8/drb/drb.rb:1627:in `start_service'
from (druby://localhost:17640) ./server.rb:9
from (druby://localhost:17640) /usr/lib64/ruby/site_ruby/1.8/rubygems/custom_require.rb:31:in `gem_original_require'
from (druby://localhost:17640) /usr/lib64/ruby/site_ruby/1.8/rubygems/custom_require.rb:31:in `require'
from (druby://localhost:17640) (irb):1
from (irb):6irb(main):007:0>
Note
- I got the same error as oddb.org
IMPORTANT RangeError with 'recycled object' in DRb
- In the case of DRbUndumped object (Unmarshaled object)
- after making a reference in a client side to a DRbObject of the UnDumped server side object
- when GC is started and the server side object is deleted
- then if the object in the client side is called, the RangeError happens
Hypothesis
- The first view of migel product is shown by using search_migel_product method, in fact, ODBA.cache.retrieve_from_index or Migel::Model::Product.search_by_xxxx method
- But after the searching the objects are sweeped by GC if there are many objects searched
Experiment
- lib/migel/util/server.rb
def migelid_search_by_migel_code(migel_code)
p "getin migelid_search_by_migel_code"
@search_result = Migel::Model::Migelid.search_by_migel_code(migel_code)
@product_result = []
@search_result.first.products.each do |product|
@product_result << product
end
ODBA::DRbWrapper.new(@search_result)
# @search_result = ODBA::DRbWrapper.new(Migel::Model::Migelid.search_by_migel_code(migel_code))
end
- src/util/oddbapp.rb
def search_migel_products(query, lang)
migel_code = if query =~ /(\d){9}/
query.split(/(\d\d)/).select{|x| !x.empty?}.join('.')
elsif query =~ /(\d\d\.){4}\d/
query
end
if migel_code
#MIGEL_SERVER.migelid.search_by_migel_code(migel_code)
MIGEL_SERVER.migelid_search_by_migel_code(migel_code)
else
...
Run
- bin/migeld
- bin/oddbd
Access
- http://oddb.masa.org/de/gcc/migel_search/migel_code/170103001
- sort by pharmacode or ean_code
Result
- The RangeError does not come in the first sorting by pharmacode
- but the RangeError happens at the second click of pharmacode
Note
- After the first sort, the url changes as follows
- This may imply that the problem is the GC not only in the migel server side but also in the oddb client side
Experiment
- lib/migel/util/server.rb
def migelid_search_by_migel_code(migel_code)
p "getin migelid_search_by_migel_code"
GC.disable
@search_result = Migel::Model::Migelid.search_by_migel_code(migel_code)
@product_result = []
@search_result.first.products.each do |product|
@product_result << product
end
ODBA::DRbWrapper.new(@search_result)
# @search_result = ODBA::DRbWrapper.new(Migel::Model::Migelid.search_by_migel_code(migel_code))
end
- src/util/oddbapp.rb
def search_migel_products(query, lang)
migel_code = if query =~ /(\d){9}/
query.split(/(\d\d)/).select{|x| !x.empty?}.join('.')
elsif query =~ /(\d\d\.){4}\d/
query
end
if migel_code
p "getin search_by"
GC.disable
#MIGEL_SERVER.migelid.search_by_migel_code(migel_code)
MIGEL_SERVER.migelid_search_by_migel_code(migel_code)
else
MIGEL_SERVER.search_migel_migelid(query, lang)
end
end
Access
- http://oddb.masa.org/de/gcc/migel_search/migel_code/170103001
- sort by pharmacode or ean_code
Result
- It seems that the RangeError does not happen
Note
- Anyway, the sweep of GC in both migel server side and oddb client side is supposed to be related to the RangeError
Next
- Check which objects are sweeped in migel server side and oddb client side
- Find how to protect the objects from GC sweeper