Memcache issues #2

Closed
antani opened this Issue Apr 4, 2011 · 23 comments

5 participants

@antani

Hi, I have mongodb installed on Ubuntu, I installed isbn.net on rails 3, when I search on an ISBN, I see the page properly but the prices are not fetched.
From the log I see,
Dalli::Server#connect localhost:11211
localhost:11211 failed (count: 0)
localhost:11211 failed (count: 1)
localhost:11211 is down
Dalli::Server#connect localhost:11211
localhost:11211 failed (count: 2)
localhost:11211 is still down (for 2.266 seconds now)
down_retry_delay not reached for localhost:11211 (0.999 seconds left)
MONGODB isbnnetin_development['delayed_backend_mongoid_jobs'].find({:handler=>/8120340078/}, {:_id=>1})
Book 8120340078 is already queued

Is there some setup I am missing ? it would be great if you can writeup mongodb setup for newbies ...

@swaroopch
Owner

Port 11211 is memcached. Please install and run memcached :)

@swaroopch swaroopch closed this Apr 4, 2011
@antani

I ran memcached, now I dont see the failed port pings. I see this :
Dalli::Server#connect localhost:11211
MONGODB isbnnetin_development['delayed_backend_mongoid_jobs'].find({:handler=>/0307378136/}, {:_id=>1})
Book 0307378136 is already queued

But the search is never refreshed on the page.
I made one small change for this to work in rails 3/ruby 1.9
bookprice.rb : modified line : 63 to
functions.collect { |fname| [ fname.slice(0..-1).split("_")[1].to_sym, self.method(fname) ] }
Otherwise it was failing because the fname was a symbol like ":a1books" and split method was not found on it. I truncated first ":"

@antani

Further, I do not see line :
@@logger.info("Performing job for #{self.isbn}")
of bookprice.rb being executed. I am sure the delayed job is not getting set properly. Sorry for n00b questions

@swaroopch swaroopch reopened this Apr 6, 2011
@swaroopch
Owner

Fixed the symbol issue in 6a79804

The logging will be seen when you run rake jobs:work, the background job runner who fetches the prices.

@antani

Will check .. thanks

@antani antani closed this Apr 6, 2011
@tamizhgeek

This issue still exists. I have checked out the latest code. Installed memcached and it's running. Ran rake jobs:work.

The server log I get is here

=> Booting WEBrick
=> Rails 3.0.9 application starting in development on http://0.0.0.0:3000
=> Call with -d to detach
=> Ctrl-C to shutdown server
[2011-07-27 15:57:07] INFO WEBrick 1.3.1
[2011-07-27 15:57:07] INFO ruby 1.9.2 (2011-02-18) [x86_64-linux]
[2011-07-27 15:57:07] INFO WEBrick::HTTPServer#start: pid=21838 port=3000
MONGODB admin['$cmd'].find({:buildinfo=>1})
MONGODB isbnnetin_development['$cmd'].find({:findandmodify=>"delayed_backend_mongoid_jobs", :query=>{:run_at=>{"$lte"=>2011-07-27 10:27:10 UTC}, :failed_at=>nil, "$or"=>[{:locked_by=>"host:azhagu-desktop pid:21832"}, {:locked_at=>nil}, {:locked_at=>{"$lt"=>2011-07-27 06:27:10 UTC}}]}, :sort=>{"locked_by"=>-1, "priority"=>1, "run_at"=>1}, :update=>{"$set"=>{:locked_at=>2011-07-27 10:27:10 UTC, :locked_by=>"host:azhagu-desktop pid:21832"}}})
MONGODB admin['$cmd'].find({:buildinfo=>1})
MONGODB isbnnetin_development['$cmd'].find({:findandmodify=>"delayed_backend_mongoid_jobs", :query=>{:run_at=>{"$lte"=>2011-07-27 10:27:15 UTC}, :failed_at=>nil, "$or"=>[{:locked_by=>"host:azhagu-desktop pid:21832"}, {:locked_at=>nil}, {:locked_at=>{"$lt"=>2011-07-27 06:27:15 UTC}}]}, :sort=>{"locked_by"=>-1, "priority"=>1, "run_at"=>1}, :update=>{"$set"=>{:locked_at=>2011-07-27 10:27:15 UTC, :locked_by=>"host:azhagu-desktop pid:21832"}}})
MONGODB admin['$cmd'].find({:buildinfo=>1})
MONGODB isbnnetin_development['$cmd'].find({:findandmodify=>"delayed_backend_mongoid_jobs", :query=>{:run_at=>{"$lte"=>2011-07-27 10:27:20 UTC}, :failed_at=>nil, "$or"=>[{:locked_by=>"host:azhagu-desktop pid:21832"}, {:locked_at=>nil}, {:locked_at=>{"$lt"=>2011-07-27 06:27:20 UTC}}]}, :sort=>{"locked_by"=>-1, "priority"=>1, "run_at"=>1}, :update=>{"$set"=>{:locked_at=>2011-07-27 10:27:20 UTC, :locked_by=>"host:azhagu-desktop pid:21832"}}})
MONGODB admin['$cmd'].find({:buildinfo=>1})
MONGODB isbnnetin_development['$cmd'].find({:findandmodify=>"delayed_backend_mongoid_jobs", :query=>{:run_at=>{"$lte"=>2011-07-27 10:27:25 UTC}, :failed_at=>nil, "$or"=>[{:locked_by=>"host:azhagu-desktop pid:21832"}, {:locked_at=>nil}, {:locked_at=>{"$lt"=>2011-07-27 06:27:25 UTC}}]}, :sort=>{"locked_by"=>-1, "priority"=>1, "run_at"=>1}, :update=>{"$set"=>{:locked_at=>2011-07-27 10:27:25 UTC, :locked_by=>"host:azhagu-desktop pid:21832"}}})
MONGODB admin['$cmd'].find({:buildinfo=>1})
MONGODB isbnnetin_development['$cmd'].find({:findandmodify=>"delayed_backend_mongoid_jobs", :query=>{:run_at=>{"$lte"=>2011-07-27 10:27:30 UTC}, :failed_at=>nil, "$or"=>[{:locked_by=>"host:azhagu-desktop pid:21832"}, {:locked_at=>nil}, {:locked_at=>{"$lt"=>2011-07-27 06:27:30 UTC}}]}, :sort=>{"locked_by"=>-1, "priority"=>1, "run_at"=>1}, :update=>{"$set"=>{:locked_at=>2011-07-27 10:27:30 UTC, :locked_by=>"host:azhagu-desktop pid:21832"}}})

Started GET "/0330537857" for 127.0.0.1 at 2011-07-27 15:57:34 +0530
Processing by BookController#view as HTML
Parameters: {"isbn"=>"0330537857"}
Dalli::Server#connect localhost:11211
localhost:11211 failed (count: 0)
MONGODB isbnnetin_development['delayed_backend_mongoid_jobs'].find({:handler=>/0330537857/}, {:_id=>1})
Book 0330537857 has been queued
MONGODB isbnnetin_development['delayed_backend_mongoid_jobs'].insert([{"priority"=>0, "attempts"=>0, "handler"=>"--- !ruby/struct:Delayed::PerformableMethod \nobject: !ruby/object:Bookprice \n isbn: 0330537857\nmethod_name: :perform\nargs: []\n\n", "_id"=>BSON::ObjectId('4e2fe816eff778554e000001'), "updated_at"=>2011-07-27 10:27:34 UTC, "run_at"=>2011-07-27 10:27:34 UTC, "created_at"=>2011-07-27 10:27:34 UTC}])
Dalli::Server#connect localhost:11211
localhost:11211 failed (count: 1)
localhost:11211 is down
Dalli::Server#connect localhost:11211
localhost:11211 failed (count: 2)
localhost:11211 is still down (for 1.276 seconds now)
Rendered book/view.html.erb within layouts/application (8.3ms)
Completed 200 OK in 1304ms (Views: 11.3ms)
MONGODB admin['$cmd'].find({:buildinfo=>1})
MONGODB isbnnetin_development['$cmd'].find({:findandmodify=>"delayed_backend_mongoid_jobs", :query=>{:run_at=>{"$lte"=>2011-07-27 10:27:35 UTC}, :failed_at=>nil, "$or"=>[{:locked_by=>"host:azhagu-desktop pid:21832"}, {:locked_at=>nil}, {:locked_at=>{"$lt"=>2011-07-27 06:27:35 UTC}}]}, :sort=>{"locked_by"=>-1, "priority"=>1, "run_at"=>1}, :update=>{"$set"=>{:locked_at=>2011-07-27 10:27:35 UTC, :locked_by=>"host:azhagu-desktop pid:21832"}}})
MONGODB isbnnetin_development['delayed_backend_mongoid_jobs'].find({:_id=>BSON::ObjectId('4e2fe816eff778554e000001')})

@swaroopch
Owner

@tamizhgeek It clearly says:

localhost:11211 failed (count: 1)
localhost:11211 is down

So check if memcached is running. What is the output of ps auwwx | fgrep -i memcached ?

@tamizhgeek

@swaroopch Memcached is up and running,
This is the output,

memcache 21522 0.0 0.0 128452 1188 pts/3 Sl 15:56 0:00 /usr/bin/memcached -m 64 -p 11211 -u memcache -l 127.0.0.1

@antani

Its not running on the defaul port - 11211 it seems

@tamizhgeek

@antani How do I find that? Sorry If I'm polluting the issue tracker.

@antani

can you manually start "memcached start" ?

@tamizhgeek

telnet localhost 11211
Trying ::1...
Trying 127.0.0.1...
Connected to localhost.
Escape character is '^]'.
version
VERSION 1.4.5

The above also indicates that memcached is running.

@swaroopch
Owner

@tamizhgeek Check output of lsof:

$ sudo lsof -i | fgrep 11211
memcached 9858 memcache   26u  IPv4  28967      0t0  TCP localhost:11211 (LISTEN)
memcached 9858 memcache   27u  IPv4  28969      0t0  UDP localhost:11211 
@tamizhgeek

@swaroopch

memcached 21522 memcache 26u IPv4 973079 0t0 TCP localhost.localdomain:11211 (LISTEN)
memcached 21522 memcache 27u IPv4 973081 0t0 UDP localhost.localdomain:11211

@tamizhgeek

@antani If I do memcached start, it waits infinitely. No output.

@swaroopch
Owner

@tamizhgeek Check if you're able to use the dalli gem to connect to memcached?

@tamizhgeek

No

ruby-1.9.2-p180 :001 > require 'dalli'
 => true 
ruby-1.9.2-p180 :002 > dc = Dalli::Client.new('localhost:11211')
 => #<Dalli::Client:0x0000000133c4e8 @servers="localhost:11211", @options={:expires_in=>0}, @ring=nil> 
ruby-1.9.2-p180 :003 > dc.set('abc', 123)
I, [2011-07-27T16:23:28.879946 #22650]  INFO -- : localhost:11211 failed (count: 0)
Dalli::RingError: No server available
    from /home/azhagu/.rvm/gems/ruby-1.9.2-p180@isbn/gems/dalli-1.0.5/lib/dalli/ring.rb:45:in 'server_for_key'
    from /home/azhagu/.rvm/gems/ruby-1.9.2-p180@isbn/gems/dalli-1.0.5/lib/dalli/client.rb:239:in 'perform'
    from /home/azhagu/.rvm/gems/ruby-1.9.2-p180@isbn/gems/dalli-1.0.5/lib/dalli/client.rb:126:in 'set'
    from (irb):3
    from /home/azhagu/.rvm/rubies/ruby-1.9.2-p180/bin/irb:16:in '<main>'
ruby-1.9.2-p180 :004 > 
@swaroopch
Owner

@tamizhgeek Wow, that is strange. Please see if you want to file a bug at https://github.com/mperham/dalli so that @mperham can take a look at it.

In the meanwhile, in config/application.rb, replace this line:

config.cache_store = :dalli_store, { :namespace => 'isbnnetin' }

with:

config.cache_store = :mem_cache_store

And check if it works for you.

@mperham

Try 127.0.0.1 instead of localhost.

@tamizhgeek

Thanks @mperham. Changing it to 127.0.0.1 works now.

@tamizhgeek

@swaroopch How can I make the above change reflect in isbnnetin?

@swaroopch
Owner

@tamizhgeek Push the fix to your fork and send a pull request.

@fguillen

I had the same problem with memcached 1.2.8, in my case the problem has been solved using memcached 1.4.10.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment