Uploaded image for project: 'Mongoid'
  1. Mongoid
  2. MONGOID-2210

undefined method `unpack' for nil:NilClass

    • Type: Icon: Task Task
    • Resolution: Done
    • 3.0.2
    • Affects Version/s: None
    • Component/s: None
    • Labels:

      Hi there,

      I'm running Mongoid 3.0.1 and am experiencing this error after a while.

      I am running a few processes during development, namely:

      • rails server
      • sidekiq (a threaded worker library)
      • clockwork (a process that enqueues jobs for sidekiq)
      • guard (for running my specs)

      After a while, everything Mongoid related that I do (running specs, browsing the web app, performing commands from the rails console) will result in {{undefined method }}unpack' for nil:NilClass`.

      Turns out this is in my mongod log:

      Wed Jul 18 00:51:03 [initandlisten] connection accepted from 127.0.0.1:49668 MONGOID-982
      Wed Jul 18 00:51:03 [initandlisten] connection refused because too many open connections: 204

      So there appears to be too many open connections to the server. Although nothing in development is really running multi-threaded. Sidekiq runs at concurrency level 1, rails server as well, clockwork spins up a few threads but they die off shortly after they are spun up once they are finished enqueues jobs.

      When I restart my mongo instance, everything works again for a while. Then within less than an hour it has opened too many connections and isn't able to connect anymore.

      Note that in development mode I am not running in config.threadsafe! mode with Rails. Not sure if this has anything to do with it but I figured i'd point that out.

      Here's the stack trace:

       Failure/Error: Unable to find matching line from backtrace
       NoMethodError:
         undefined method `unpack' for nil:NilClass
       # /Users/Michael/.rvm/gems/ruby-1.9.3-p125/gems/moped-1.1.1/lib/moped/connection.rb:93:in `read'
       # /Users/Michael/.rvm/gems/ruby-1.9.3-p125/gems/moped-1.1.1/lib/moped/protocol/query.rb:140:in `receive_replies'
       # /Users/Michael/.rvm/gems/ruby-1.9.3-p125/gems/moped-1.1.1/lib/moped/connection.rb:119:in `block in receive_replies'
       # /Users/Michael/.rvm/gems/ruby-1.9.3-p125/gems/moped-1.1.1/lib/moped/connection.rb:118:in `map'
       # /Users/Michael/.rvm/gems/ruby-1.9.3-p125/gems/moped-1.1.1/lib/moped/connection.rb:118:in `receive_replies'
       # /Users/Michael/.rvm/gems/ruby-1.9.3-p125/gems/moped-1.1.1/lib/moped/node.rb:519:in `block (2 levels) in flush'
       # /Users/Michael/.rvm/gems/ruby-1.9.3-p125/gems/moped-1.1.1/lib/moped/node.rb:113:in `ensure_connected'
       # /Users/Michael/.rvm/gems/ruby-1.9.3-p125/gems/moped-1.1.1/lib/moped/node.rb:517:in `block in flush'
       # /Users/Michael/.rvm/gems/ruby-1.9.3-p125/gems/moped-1.1.1/lib/moped/node.rb:532:in `logging'
       # /Users/Michael/.rvm/gems/ruby-1.9.3-p125/gems/moped-1.1.1/lib/moped/node.rb:516:in `flush'
       # /Users/Michael/.rvm/gems/ruby-1.9.3-p125/gems/moped-1.1.1/lib/moped/node.rb:505:in `process'
       # /Users/Michael/.rvm/gems/ruby-1.9.3-p125/gems/moped-1.1.1/lib/moped/node.rb:70:in `command'
       # /Users/Michael/.rvm/gems/ruby-1.9.3-p125/gems/moped-1.1.1/lib/moped/node.rb:356:in `refresh'
       # /Users/Michael/.rvm/gems/ruby-1.9.3-p125/gems/moped-1.1.1/lib/moped/cluster.rb:101:in `block in refresh'
       # /Users/Michael/.rvm/gems/ruby-1.9.3-p125/gems/moped-1.1.1/lib/moped/cluster.rb:114:in `each'
       # /Users/Michael/.rvm/gems/ruby-1.9.3-p125/gems/moped-1.1.1/lib/moped/cluster.rb:114:in `refresh'
       # /Users/Michael/.rvm/gems/ruby-1.9.3-p125/gems/moped-1.1.1/lib/moped/cluster.rb:67:in `nodes'
       # /Users/Michael/.rvm/gems/ruby-1.9.3-p125/gems/moped-1.1.1/lib/moped/cluster.rb:136:in `with_primary'
       # /Users/Michael/.rvm/gems/ruby-1.9.3-p125/gems/moped-1.1.1/lib/moped/session/context.rb:108:in `with_node'
       # /Users/Michael/.rvm/gems/ruby-1.9.3-p125/gems/moped-1.1.1/lib/moped/session/context.rb:50:in `command'
       # /Users/Michael/.rvm/gems/ruby-1.9.3-p125/gems/moped-1.1.1/lib/moped/database.rb:76:in `command'
       # /Users/Michael/.rvm/gems/ruby-1.9.3-p125/gems/moped-1.1.1/lib/moped/query.rb:36:in `count'
       # /Users/Michael/.rvm/gems/ruby-1.9.3-p125/gems/mongoid-3.0.1/lib/mongoid/persistence.rb:275:in `delete_all'
       # /Users/Michael/Applications/myapp/spec/spec_helper.rb:40:in `each'
       # /Users/Michael/Applications/myapp/spec/spec_helper.rb:40:in `block (3 levels) in <top (required)>'
       # /Users/Michael/.rvm/gems/ruby-1.9.3-p125/gems/rspec-core-2.9.0/lib/rspec/core/hooks.rb:35:in `instance_eval'
       # /Users/Michael/.rvm/gems/ruby-1.9.3-p125/gems/rspec-core-2.9.0/lib/rspec/core/hooks.rb:35:in `run_in'
       # /Users/Michael/.rvm/gems/ruby-1.9.3-p125/gems/rspec-core-2.9.0/lib/rspec/core/hooks.rb:70:in `block in run_all'
       # /Users/Michael/.rvm/gems/ruby-1.9.3-p125/gems/rspec-core-2.9.0/lib/rspec/core/hooks.rb:70:in `each'
       # /Users/Michael/.rvm/gems/ruby-1.9.3-p125/gems/rspec-core-2.9.0/lib/rspec/core/hooks.rb:70:in `run_all'
       # /Users/Michael/.rvm/gems/ruby-1.9.3-p125/gems/rspec-core-2.9.0/lib/rspec/core/hooks.rb:380:in `run_hook_filtered'
       # /Users/Michael/.rvm/gems/ruby-1.9.3-p125/gems/rspec-core-2.9.0/lib/rspec/core/example_group.rb:275:in `run_before_all_hooks'
       # /Users/Michael/.rvm/gems/ruby-1.9.3-p125/gems/rspec-core-2.9.0/lib/rspec/core/example_group.rb:336:in `run'
       # /Users/Michael/.rvm/gems/ruby-1.9.3-p125/gems/rspec-core-2.9.0/lib/rspec/core/command_line.rb:28:in `block (2 levels) in run'
       # /Users/Michael/.rvm/gems/ruby-1.9.3-p125/gems/rspec-core-2.9.0/lib/rspec/core/command_line.rb:28:in `map'
       # /Users/Michael/.rvm/gems/ruby-1.9.3-p125/gems/rspec-core-2.9.0/lib/rspec/core/command_line.rb:28:in `block in run'
       # /Users/Michael/.rvm/gems/ruby-1.9.3-p125/gems/rspec-core-2.9.0/lib/rspec/core/reporter.rb:34:in `report'
       # /Users/Michael/.rvm/gems/ruby-1.9.3-p125/gems/rspec-core-2.9.0/lib/rspec/core/command_line.rb:25:in `run'
       # /Users/Michael/.rvm/gems/ruby-1.9.3-p125/gems/spork-0.9.0/lib/spork/test_framework/rspec.rb:11:in `run_tests'
       # /Users/Michael/.rvm/gems/ruby-1.9.3-p125/gems/spork-0.9.0/lib/spork/run_strategy/forking.rb:13:in `block in run'
       # /Users/Michael/.rvm/gems/ruby-1.9.3-p125/gems/spork-0.9.0/lib/spork/forker.rb:21:in `block in initialize'
       # /Users/Michael/.rvm/gems/ruby-1.9.3-p125/gems/spork-0.9.0/lib/spork/forker.rb:18:in `fork'
       # /Users/Michael/.rvm/gems/ruby-1.9.3-p125/gems/spork-0.9.0/lib/spork/forker.rb:18:in `initialize'
       # /Users/Michael/.rvm/gems/ruby-1.9.3-p125/gems/spork-0.9.0/lib/spork/run_strategy/forking.rb:9:in `new'
       # /Users/Michael/.rvm/gems/ruby-1.9.3-p125/gems/spork-0.9.0/lib/spork/run_strategy/forking.rb:9:in `run'
       # /Users/Michael/.rvm/gems/ruby-1.9.3-p125/gems/spork-0.9.0/lib/spork/server.rb:48:in `run'
       # /Users/Michael/.rvm/rubies/ruby-1.9.3-p125/lib/ruby/1.9.1/drb/drb.rb:1548:in `perform_without_block'
       # /Users/Michael/.rvm/rubies/ruby-1.9.3-p125/lib/ruby/1.9.1/drb/drb.rb:1508:in `perform'
       # /Users/Michael/.rvm/rubies/ruby-1.9.3-p125/lib/ruby/1.9.1/drb/drb.rb:1586:in `block (2 levels) in main_loop'
       # /Users/Michael/.rvm/rubies/ruby-1.9.3-p125/lib/ruby/1.9.1/drb/drb.rb:1582:in `loop'
       # /Users/Michael/.rvm/rubies/ruby-1.9.3-p125/lib/ruby/1.9.1/drb/drb.rb:1582:in `block in main_loop'
      

      It's worth noting that this wasn't occurring before I made the changes from using the global variable sessions to using Mongoid.session(:default) every time instead.

      Reference: https://groups.google.com/forum/?fromgroups#!topic/mongoid/yesQ2AHtPyI (Mongoid Google Groups)

      Not saying it's related to using Mongoid.session(:default) within every thread, but before I added it (and a bunch of other commits unrelated to Mongoid.session) it started to happen.

      I do not know whether this happens in a production environment though. I'll try turning on config.threadsafe! in development and see if anything happens anytime soon.

      Cheers

            Assignee:
            Unassigned Unassigned
            Reporter:
            meskyanichi Michael van Rooijen
            Votes:
            0 Vote for this issue
            Watchers:
            0 Start watching this issue

              Created:
              Updated:
              Resolved: