Issue with multiple requests #73

Closed
hartjus opened this Issue Feb 24, 2012 · 9 comments

Projects

None yet

4 participants

@hartjus
hartjus commented Feb 24, 2012

We are seeing an issue when multiple requests (threads?) that are accessing the ldap.yml file. Looking at the stack trace, the problem occurs in ldap_adapter.rb--in the initializer of LdapConnect where it performs the YAML.load() call. Not sure if an ldap connection pool is needed, or more protection around the loading of the YAML file?

This can be replicated by using the following test in a rails console:
threads = []
100.times {threads << Thread.new {p YAML.load(ERB.new(File.read(::Devise.ldap_config || "#{Rails.root}/config/ldap.yml")).result)[Rails.env]}}

Running ruby 1.9.2, rails 3.0.9 on Jruby 1.6.6 (same result on 1.6.7); Devise ldap authenticatable 0.4.9.

@hartjus
hartjus commented Feb 24, 2012

Here is the stack trace:

java.lang.IndexOutOfBoundsException
at java.nio.ByteBuffer.wrap(ByteBuffer.java:352)
at org.jruby.RubyEncoding.decode(RubyEncoding.java:198)
at org.jruby.RubyString.decodeString(RubyString.java:725)
at org.jruby.RubyString.toString(RubyString.java:701)
at org.jruby.RubyString.asJavaString(RubyString.java:1233)
at org.jruby.ext.psych.PsychParser.parse(PsychParser.java:113)
at org.jruby.ext.psych.PsychParser$i$1$0$parse.call(PsychParser$i$1$0$parse.gen:65535)
at org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:167)
at org.jruby.ast.CallOneArgNode.interpret(CallOneArgNode.java:57)
at org.jruby.ast.NewlineNode.interpret(NewlineNode.java:104)
at org.jruby.ast.BlockNode.interpret(BlockNode.java:71)
at org.jruby.evaluator.ASTInterpreter.INTERPRET_METHOD(ASTInterpreter.java:74)
at org.jruby.internal.runtime.methods.InterpretedMethod.call(InterpretedMethod.java:190)
at org.jruby.internal.runtime.methods.DefaultMethod.call(DefaultMethod.java:202)
at org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:167)
at org.jruby.ast.FCallOneArgNode.interpret(FCallOneArgNode.java:36)
at org.jruby.ast.CallNoArgNode.interpret(CallNoArgNode.java:63)
at org.jruby.ast.LocalAsgnNode.interpret(LocalAsgnNode.java:123)
at org.jruby.ast.NewlineNode.interpret(NewlineNode.java:104)
at org.jruby.ast.BlockNode.interpret(BlockNode.java:71)
at org.jruby.evaluator.ASTInterpreter.INTERPRET_METHOD(ASTInterpreter.java:74)
at org.jruby.internal.runtime.methods.InterpretedMethod.call(InterpretedMethod.java:190)
at org.jruby.internal.runtime.methods.DefaultMethod.call(DefaultMethod.java:202)
at org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:167)
at org.jruby.ast.FCallOneArgNode.interpret(FCallOneArgNode.java:36)
at org.jruby.ast.LocalAsgnNode.interpret(LocalAsgnNode.java:123)
at org.jruby.ast.NewlineNode.interpret(NewlineNode.java:104)
at org.jruby.ast.BlockNode.interpret(BlockNode.java:71)
at org.jruby.evaluator.ASTInterpreter.INTERPRET_METHOD(ASTInterpreter.java:74)
at org.jruby.internal.runtime.methods.InterpretedMethod.call(InterpretedMethod.java:190)
at org.jruby.internal.runtime.methods.DefaultMethod.call(DefaultMethod.java:202)
at org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:167)
at org.jruby.ast.CallOneArgNode.interpret(CallOneArgNode.java:57)
at org.jruby.ast.CallOneArgNode.interpret(CallOneArgNode.java:57)
at org.jruby.ast.FCallOneArgNode.interpret(FCallOneArgNode.java:36)
at org.jruby.ast.NewlineNode.interpret(NewlineNode.java:104)
at org.jruby.evaluator.ASTInterpreter.INTERPRET_BLOCK(ASTInterpreter.java:111)
at org.jruby.runtime.Interpreted19Block.evalBlockBody(Interpreted19Block.java:212)
at org.jruby.runtime.Interpreted19Block.yield(Interpreted19Block.java:200)
at org.jruby.runtime.Interpreted19Block.call(Interpreted19Block.java:131)
at org.jruby.runtime.Block.call(Block.java:89)
at org.jruby.RubyProc.call(RubyProc.java:270)
at org.jruby.RubyProc.call(RubyProc.java:224)
at org.jruby.internal.runtime.RubyRunnable.run(RubyRunnable.java:95)
at java.lang.Thread.run(Thread.java:662)

@cairo140
Collaborator

Looks to me by the stack trace that it might be the YAML parser that's coughing up. What happens if you take the return value of ERB.new(File.read(::Devise.ldap_config || "#{Rails.root}/config/ldap.yml")).result and hard code it into the following?

100.times {threads << Thread.new {p YAML.load("result goes here")[Rails.env]}}
@hartjus
hartjus commented Feb 24, 2012

Running this command in the console produces all nil results:
100.times {threads << Thread.new {p YAML.load("#{Rails.root}/config/ldap.yml")[Rails.env]}}

However, running this command, using YAML.load_file, seems to act OK:
100.times {threads << Thread.new {p YAML.load_file("#{Rails.root}/config/ldap.yml")[Rails.env]}}

@cairo140
Collaborator

YAML.load("#{Rails.root}/config/ldap.yml") tries to parse the string "#{Rails.root}/config/ldap.yml" as YAML, which it isn't. Be sure you're putting in the actual contents of the file (as in File.read "#{Rails.root}/config/ldap.yml"). What's the result then?

Both calls should succeed, since load_file does nothing but just call load, at least in the Ruby standard library. If this is not the case, let me know.

Assuming it succeeds, just work backwards to your original call to figure out where the devise_ldap_authenticatable call is failing.

@hartjus
hartjus commented Feb 24, 2012

Ah, I see now. It seems to be the ERB.new().result that causes the issue. Once that statement is inserted into the YAML.load() call, the stack traces start to occur.

@hartjus
hartjus commented Feb 29, 2012

Hi...any update or suggestions on this issue? This is occurring at line 57 of ldap_adapter.rb in the gem. When many requests come into the LdapConnect object, it starts to fail.

class LdapConnect

  attr_reader :ldap, :login

  def initialize(params = {})
    ldap_config = YAML.load(ERB.new(File.read(::Devise.ldap_config || "#{Rails.root}/config/ldap.yml")).result)[Rails.env]
    ldap_options = params
    ldap_options[:encryption] = :simple_tls if ldap_config["ssl"]
@cairo140
Collaborator

You mentioned that it's the ERB parser that's causing issues for you. I suspect that it's a flaw in your ERB parser that would be causing the failure. Assuming you don't have any ERB in your config file, you should be able to get away by monkeypatching #initialize to exclude the ERB call.

Alternately, I would be happy to accept a more generally applicable patch that optionally toggles ERB parsing for the config file if you can figure out a reasonable way to do it.

@cschiewek cschiewek closed this Jun 20, 2012
@headius
headius commented Sep 21, 2012

FYI, this appears to be a bug in MRI's ERB logic. The ERB#run and ERB#result methods evaluate the template under TOPLEVEL_BINDING by default using the same local variable. This causes concurrent template executions to step on each other (even in the same thread, if nested).

I have filed an issue with MRI here: https://bugs.ruby-lang.org/issues/7046

We will probably patch this in JRuby for 1.7 as well.

The workaround is to always specify a binding when calling ERB#result or ERB#run.

@headius
headius commented Sep 25, 2012

We have patched this in JRuby for 1.7RC1, and patches to MRI are pending approval.

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