Forum: JRuby Net:IMAP race condition?

Hi,

We're encountering an issue with JRuby (1.7.0.preview1) where IMAP
authentication fails some/most of the time. I suspect this is the result 
of
a race condition. Below is the code we're testing with:

    require 'net/imap'
    require 'oauth'
    require 'gmail_xoauth'

    Net::IMAP.debug = true

    puts "Creating IMAP connection..."
    imap = Net::IMAP.new('imap.gmail.com', 993, usessl = true, certs = 
nil,
verify = false)

    puts "Authenticating IMAP connection..."
    imap.authenticate("XOAUTH", "<snip>",
      :consumer_key => "<snip>",
      :consumer_secret => "<snip>",
      :token => "<snip>",
      :token_secret => "<snip>")
    puts "Authenticated."

The code uses the 'gmail_xoauth' gem (to adhere to the custom 
authentication
mechanism that Gmail uses) though the same problem occurs (less often) 
with
regular ('LOGIN') authentication (against a different IMAP server). This
suggests that the delay incurred by initialising the XOAUTH 
authentication
increases the chance of the deadlock. (It should be possible to 
reproduce
the issue with the <snip>ed credentials above since execution does not 
get
far enough to send the authentication request.)

The problem seems very similar to JRUBY-2950 (from JRuby <1.2): 
execution
continues up to the call to authenticate, but then seems to get stuck. 
I've
traced the execution down to the call to `syswrite` in 
openssl/buffering.rb
[1], which is confirmed by the stack trace (below) - suggesting, I 
think,
that some sort of deadlock is occurring when reading from/writing to the
socket.

We have managed to come up with a very crude workaround to the problem 
by
enforcing a `sleep 1` before the call to `receive_responses` inside 
imap.rb
[2].

Can anyone confirm whether this is a known issue with JRuby? And whether
it's already been fixed? Or whether we're doing something wrong?

My Ruby version is:

    jruby 1.7.0.preview1 (ruby-1.9.3-p203) (2012-05-19 00c8c98) (Java
HotSpot(TM) Server VM 1.6.0_32) [linux-i386-java]

Here's the stack trace:

    Full thread dump Java HotSpot(TM) Server VM (20.7-b02 mixed mode):

    "RubyThread-3:
/home/joe/.rvm/rubies/jruby-1.7.0.preview1/lib/ruby/1.9/net/imap.rb:1060"
daemon prio=10 tid=0x8cadd800 nid=0xe42 runnable [0x8c1fd000]
       java.lang.Thread.State: RUNNABLE
      at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method)
      at sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:210)
      at 
sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:65)
      at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:69)
      - locked <0xa8f9e9a0> (a sun.nio.ch.Util$2)
      - locked <0xa8f9e990> (a java.util.Collections$UnmodifiableSet)
      - locked <0xa8f9e5f0> (a sun.nio.ch.EPollSelectorImpl)
      at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:80)
      at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:84)
      at org.jruby.RubyThread.select(RubyThread.java:1058)
      - locked <0xa8f9d1d0> (a java.lang.Object)
      at org.jruby.RubyThread.select(RubyThread.java:1036)
      at org.jruby.ext.openssl.SSLSocket.waitSelect(SSLSocket.java:260)
      at org.jruby.ext.openssl.SSLSocket.sysread(SSLSocket.java:473)
      at
org.jruby.ext.openssl.SSLSocket$INVOKER$i$0$1$sysread.call(SSLSocket$INVOKER$i$0$1$sysread.gen)
      at
org.jruby.internal.runtime.methods.JavaMethod$JavaMethodN.call(JavaMethod.java:640)
      at
org.jruby.internal.runtime.methods.DynamicMethod.call(DynamicMethod.java:212)
      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.NewlineNode.interpret(NewlineNode.java:104)
      at org.jruby.ast.RescueNode.executeBody(RescueNode.java:226)
      at
org.jruby.ast.RescueNode.interpretWithJavaExceptions(RescueNode.java:123)
      at org.jruby.ast.RescueNode.interpret(RescueNode.java:113)
      at org.jruby.ast.BeginNode.interpret(BeginNode.java:83)
      at org.jruby.ast.NewlineNode.interpret(NewlineNode.java:104)
      at
org.jruby.evaluator.ASTInterpreter.INTERPRET_METHOD(ASTInterpreter.java:75)
      at
org.jruby.internal.runtime.methods.InterpretedMethod.call(InterpretedMethod.java:147)
      at
org.jruby.internal.runtime.methods.DefaultMethod.call(DefaultMethod.java:183)
      at
org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:133)
      at org.jruby.ast.VCallNode.interpret(VCallNode.java:86)
      at org.jruby.ast.NewlineNode.interpret(NewlineNode.java:104)
      at org.jruby.ast.BlockNode.interpret(BlockNode.java:71)
      at org.jruby.ast.UntilNode.interpret(UntilNode.java:120)
      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:75)
      at
org.jruby.internal.runtime.methods.InterpretedMethod.call(InterpretedMethod.java:190)
      at
org.jruby.internal.runtime.methods.DefaultMethod.call(DefaultMethod.java:199)
      at
org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:167)
      at org.jruby.ast.CallOneArgNode.interpret(CallOneArgNode.java:57)
      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.ast.WhileNode.interpret(WhileNode.java:131)
      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:75)
      at
org.jruby.internal.runtime.methods.InterpretedMethod.call(InterpretedMethod.java:147)
      at
org.jruby.internal.runtime.methods.DefaultMethod.call(DefaultMethod.java:183)
      at
org.jruby.runtime.callsite.CachingCallSite.cacheAndCall(CachingCallSite.java:292)
      at
org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:135)
      at org.jruby.ast.VCallNode.interpret(VCallNode.java:86)
      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.ast.RescueNode.executeBody(RescueNode.java:226)
      at
org.jruby.ast.RescueNode.interpretWithJavaExceptions(RescueNode.java:123)
      at org.jruby.ast.RescueNode.interpret(RescueNode.java:113)
      at org.jruby.ast.BeginNode.interpret(BeginNode.java:83)
      at org.jruby.ast.NewlineNode.interpret(NewlineNode.java:104)
      at org.jruby.ast.BlockNode.interpret(BlockNode.java:71)
      at org.jruby.ast.UntilNode.interpret(UntilNode.java:120)
      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:75)
      at
org.jruby.internal.runtime.methods.InterpretedMethod.call(InterpretedMethod.java:147)
      at
org.jruby.internal.runtime.methods.DefaultMethod.call(DefaultMethod.java:183)
      at
org.jruby.runtime.callsite.CachingCallSite.cacheAndCall(CachingCallSite.java:292)
      at
org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:135)
      at org.jruby.ast.VCallNode.interpret(VCallNode.java:86)
      at org.jruby.ast.NewlineNode.interpret(NewlineNode.java:104)
      at org.jruby.ast.BlockNode.interpret(BlockNode.java:71)
      at org.jruby.ast.RescueNode.executeBody(RescueNode.java:226)
      at
org.jruby.ast.RescueNode.interpretWithJavaExceptions(RescueNode.java:123)
      at org.jruby.ast.RescueNode.interpret(RescueNode.java:113)
      at org.jruby.ast.BeginNode.interpret(BeginNode.java:83)
      at org.jruby.ast.NewlineNode.interpret(NewlineNode.java:104)
      at
org.jruby.evaluator.ASTInterpreter.INTERPRET_BLOCK(ASTInterpreter.java:112)
      at
org.jruby.runtime.Interpreted19Block.evalBlockBody(Interpreted19Block.java:209)
      at
org.jruby.runtime.Interpreted19Block.yield(Interpreted19Block.java:197)
      at
org.jruby.runtime.Interpreted19Block.call(Interpreted19Block.java:128)
      at org.jruby.runtime.Block.call(Block.java:89)
      at org.jruby.RubyProc.call(RubyProc.java:269)
      at org.jruby.RubyProc.call(RubyProc.java:223)
      at 
org.jruby.internal.runtime.RubyRunnable.run(RubyRunnable.java:101)
      at java.lang.Thread.run(Thread.java:662)

    <snip>

    "main" prio=10 tid=0xb6505800 nid=0xe2a waiting for monitor entry
[0xb68d3000]
       java.lang.Thread.State: BLOCKED (on object monitor)
      at
java.nio.channels.spi.AbstractSelectableChannel.isBlocking(AbstractSelectableChannel.java:232)
      - waiting to lock <0xa8f9d1d0> (a java.lang.Object)
      at org.jruby.ext.openssl.SSLSocket.waitSelect(SSLSocket.java:255)
      at org.jruby.ext.openssl.SSLSocket.syswrite(SSLSocket.java:504)
      at
org.jruby.ext.openssl.SSLSocket$INVOKER$i$1$0$syswrite.call(SSLSocket$INVOKER$i$1$0$syswrite.gen)
      at
org.jruby.runtime.callsite.CachingCallSite.cacheAndCall(CachingCallSite.java:312)
      at
org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:169)
      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.RescueNode.executeBody(RescueNode.java:226)
      at
org.jruby.ast.RescueNode.interpretWithJavaExceptions(RescueNode.java:123)
      at org.jruby.ast.RescueNode.interpret(RescueNode.java:113)
      at org.jruby.ast.BeginNode.interpret(BeginNode.java:83)
      at org.jruby.ast.NewlineNode.interpret(NewlineNode.java:104)
      at org.jruby.ast.BlockNode.interpret(BlockNode.java:71)
      at org.jruby.ast.WhileNode.interpret(WhileNode.java:131)
      at org.jruby.ast.NewlineNode.interpret(NewlineNode.java:104)
      at org.jruby.ast.BlockNode.interpret(BlockNode.java:71)
      at org.jruby.ast.IfNode.interpret(IfNode.java:116)
      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:75)
      at
org.jruby.internal.runtime.methods.InterpretedMethod.call(InterpretedMethod.java:190)
      at
org.jruby.internal.runtime.methods.DefaultMethod.call(DefaultMethod.java:199)
      at
org.jruby.runtime.callsite.CachingCallSite.cacheAndCall(CachingCallSite.java:312)
      at
org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:169)
      at 
org.jruby.ast.FCallOneArgNode.interpret(FCallOneArgNode.java:36)
      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:75)
      at
org.jruby.internal.runtime.methods.InterpretedMethod.call(InterpretedMethod.java:190)
      at
org.jruby.internal.runtime.methods.DefaultMethod.call(DefaultMethod.java:199)
      at
org.jruby.runtime.callsite.CachingCallSite.cacheAndCall(CachingCallSite.java:312)
      at
org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:169)
      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:75)
      at
org.jruby.internal.runtime.methods.InterpretedMethod.call(InterpretedMethod.java:190)
      at
org.jruby.internal.runtime.methods.DefaultMethod.call(DefaultMethod.java:199)
      at
org.jruby.runtime.callsite.CachingCallSite.cacheAndCall(CachingCallSite.java:312)
      at
org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:169)
      at 
org.jruby.ast.FCallOneArgNode.interpret(FCallOneArgNode.java:36)
      at org.jruby.ast.NewlineNode.interpret(NewlineNode.java:104)
      at org.jruby.ast.BlockNode.interpret(BlockNode.java:71)
      at
org.jruby.evaluator.ASTInterpreter.INTERPRET_BLOCK(ASTInterpreter.java:112)
      at
org.jruby.runtime.Interpreted19Block.evalBlockBody(Interpreted19Block.java:209)
      at
org.jruby.runtime.Interpreted19Block.yield(Interpreted19Block.java:160)
      at
org.jruby.runtime.Interpreted19Block.yieldSpecific(Interpreted19Block.java:133)
      at org.jruby.runtime.Block.yieldSpecific(Block.java:99)
      at org.jruby.ast.ZYieldNode.interpret(ZYieldNode.java:25)
      at org.jruby.ast.NewlineNode.interpret(NewlineNode.java:104)
      at org.jruby.ast.EnsureNode.interpret(EnsureNode.java:96)
      at org.jruby.ast.BeginNode.interpret(BeginNode.java:83)
      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:75)
      at
org.jruby.internal.runtime.methods.InterpretedMethod.call(InterpretedMethod.java:169)
      at
org.jruby.internal.runtime.methods.DefaultMethod.call(DefaultMethod.java:191)
      at
org.jruby.internal.runtime.methods.AliasMethod.call(AliasMethod.java:81)
      at
org.jruby.runtime.callsite.CachingCallSite.cacheAndCall(CachingCallSite.java:302)
      at
org.jruby.runtime.callsite.CachingCallSite.callBlock(CachingCallSite.java:144)
      at
org.jruby.runtime.callsite.CachingCallSite.callIter(CachingCallSite.java:153)
      at
org.jruby.ast.FCallNoArgBlockNode.interpret(FCallNoArgBlockNode.java:32)
      at org.jruby.ast.NewlineNode.interpret(NewlineNode.java:104)
      at
org.jruby.evaluator.ASTInterpreter.INTERPRET_METHOD(ASTInterpreter.java:75)
      at
org.jruby.internal.runtime.methods.InterpretedMethod.call(InterpretedMethod.java:255)
      at
org.jruby.internal.runtime.methods.DefaultMethod.call(DefaultMethod.java:223)
      at
org.jruby.runtime.callsite.CachingCallSite.cacheAndCall(CachingCallSite.java:342)
      at
org.jruby.runtime.callsite.CachingCallSite.callBlock(CachingCallSite.java:212)
      at
org.jruby.runtime.callsite.CachingCallSite.callIter(CachingCallSite.java:221)
      at
org.jruby.ast.FCallTwoArgBlockNode.interpret(FCallTwoArgBlockNode.java:34)
      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:75)
      at
org.jruby.internal.runtime.methods.InterpretedMethod.call(InterpretedMethod.java:276)
      at
org.jruby.internal.runtime.methods.DefaultMethod.call(DefaultMethod.java:231)
      at
org.jruby.runtime.callsite.CachingCallSite.cacheAndCall(CachingCallSite.java:352)
      at
org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:237)
      at imap_test2.__file__(imap_test2.rb:11)
      at imap_test2.load(imap_test2.rb)
      at org.jruby.Ruby.runScript(Ruby.java:778)
      at org.jruby.Ruby.runScript(Ruby.java:771)
      at org.jruby.Ruby.runNormally(Ruby.java:648)
      at org.jruby.Ruby.runFromMain(Ruby.java:497)
      at org.jruby.Main.doRunFromMain(Main.java:375)
      at org.jruby.Main.internalRun(Main.java:264)
      at org.jruby.Main.run(Main.java:230)
      at org.jruby.Main.run(Main.java:214)
      at org.jruby.Main.main(Main.java:194)

Thanks for any help.

[1]
https://github.com/jruby/jruby/blob/master/lib/rub...
[2]
https://github.com/jruby/jruby/blob/master/lib/rub...



--
View this message in context: 
http://ruby.11.n6.nabble.com/Net-IMAP-race-conditi...
Sent from the JRuby - User mailing list archive at Nabble.com.

I'm still experiencing this problem. Should I raise a JIRA issue? Or 
re-open
an existing issue? JRUBY-2950 or JRUBY-5200, perhaps?



--
View this message in context: 
http://ruby.11.n6.nabble.com/Net-IMAP-race-conditi...
Sent from the JRuby - User mailing list archive at Nabble.com.