History | Log In     View a printable version of the current page.  
Issue Details (XML | Word | Printable)

Key: JRUBY-1222
Type: Bug Bug
Status: Closed Closed
Resolution: Fixed
Priority: Critical Critical
Assignee: Unassigned
Reporter: Dan Sketcher
Votes: 0
Watchers: 3
Operations

If you were logged in you would be able to see more operations.
JRuby

Net::HTTP response error using SSL connection

Created: 19/Jul/07 09:49 AM   Updated: 23/Apr/08 10:02 AM
Component/s: OpenSSL
Affects Version/s: JRuby 1.0.0
Fix Version/s: JRuby 1.1RC2

Time Tracking:
Not Specified

File Attachments: 1. File https_test.rb (0.4 kb)

Environment: Win32, JDK 1.5.0_12, JRuby 1.0, jruby-openssl 0.0.3

Testcase included: yes


 Description  « Hide
When making an SSL encrypted HTTP request, responses over a certain length time out. It seems as though it cannot make it to the full end of the response.

Sometimes a stack trace is returned, sometimes it just hangs indefinitely.

Attached is a replication implementation that works on
C:\development>ruby -v
ruby 1.8.5 (2006-12-25 patchlevel 12) [i386-mswin32]

but not on
C:\development>jruby -v
ruby 1.8.5 (2007-06-07 rev 3841) [x86-jruby1.0]

Stack trace 1:
----------
SocketChannelImpl.java:125:in `sun.nio.ch.SocketChannelImpl.ensureWriteOpen': java.nio.channels.ClosedChannelException: null (NativeExceptio
n)
from SocketChannelImpl.java:294:in `sun.nio.ch.SocketChannelImpl.write'
from SSLSocket.java:271:in `org.jruby.ext.openssl.SSLSocket.flushData'
from SSLSocket.java:371:in `org.jruby.ext.openssl.SSLSocket.doShutdown'
from SSLSocket.java:430:in `org.jruby.ext.openssl.SSLSocket.close'
from SSLSocket.java:437:in `org.jruby.ext.openssl.SSLSocket.sysclose'
from null:-1:in `org.jruby.ext.openssl.SSLSocketInvokersysclose0.call'
from FastInvocationCallback.java:49:in `org.jruby.runtime.callback.FastInvocationCallback.execute'
from SimpleCallbackMethod.java:81:in `org.jruby.internal.runtime.methods.SimpleCallbackMethod.call'
... 60 levels...
from C:/jruby-1.0/lib/ruby/1.8/net/http.rb:1035:in `request'
from C:/jruby-1.0/lib/ruby/1.8/net/http.rb:989:in `request_post'
from https_test.rb:22
Complete Java stackTrace
java.nio.channels.ClosedChannelException
at sun.nio.ch.SocketChannelImpl.ensureWriteOpen(SocketChannelImpl.java:125)
at sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:294)
at org.jruby.ext.openssl.SSLSocket.flushData(SSLSocket.java:271)
at org.jruby.ext.openssl.SSLSocket.doShutdown(SSLSocket.java:371)
at org.jruby.ext.openssl.SSLSocket.close(SSLSocket.java:430)
at org.jruby.ext.openssl.SSLSocket.sysclose(SSLSocket.java:437)
at org.jruby.ext.openssl.SSLSocketInvokersysclose0.call(Unknown Source)
at org.jruby.runtime.callback.FastInvocationCallback.execute(FastInvocationCallback.java:49)
at org.jruby.internal.runtime.methods.SimpleCallbackMethod.call(SimpleCallbackMethod.java:81)
at org.jruby.evaluator.EvaluationState.vcallNode(EvaluationState.java:1756)
at org.jruby.evaluator.EvaluationState.evalInternal(EvaluationState.java:382)
at org.jruby.evaluator.EvaluationState.blockNode(EvaluationState.java:531)
at org.jruby.evaluator.EvaluationState.evalInternal(EvaluationState.java:201)
at org.jruby.evaluator.EvaluationState.eval(EvaluationState.java:164)
at org.jruby.internal.runtime.methods.DefaultMethod.internalCall(DefaultMethod.java:135)
at org.jruby.internal.runtime.methods.DynamicMethod.call(DynamicMethod.java:79)
at org.jruby.evaluator.EvaluationState.callNode(EvaluationState.java:568)
at org.jruby.evaluator.EvaluationState.evalInternal(EvaluationState.java:207)
at org.jruby.evaluator.EvaluationState.eval(EvaluationState.java:164)
at org.jruby.internal.runtime.methods.DefaultMethod.internalCall(DefaultMethod.java:135)
at org.jruby.internal.runtime.methods.DynamicMethod.call(DynamicMethod.java:79)
at org.jruby.evaluator.EvaluationState.callNode(EvaluationState.java:568)
at org.jruby.evaluator.EvaluationState.evalInternal(EvaluationState.java:207)
at org.jruby.evaluator.EvaluationState.blockNode(EvaluationState.java:531)
at org.jruby.evaluator.EvaluationState.evalInternal(EvaluationState.java:201)
at org.jruby.evaluator.EvaluationState.eval(EvaluationState.java:164)
at org.jruby.internal.runtime.methods.DefaultMethod.internalCall(DefaultMethod.java:135)
at org.jruby.internal.runtime.methods.DynamicMethod.call(DynamicMethod.java:79)
at org.jruby.evaluator.EvaluationState.vcallNode(EvaluationState.java:1756)
at org.jruby.evaluator.EvaluationState.evalInternal(EvaluationState.java:382)
at org.jruby.evaluator.EvaluationState.ensureNode(EvaluationState.java:986)
at org.jruby.evaluator.EvaluationState.evalInternal(EvaluationState.java:247)
at org.jruby.evaluator.EvaluationState.blockNode(EvaluationState.java:531)
at org.jruby.evaluator.EvaluationState.evalInternal(EvaluationState.java:201)
at org.jruby.evaluator.EvaluationState.eval(EvaluationState.java:164)
at org.jruby.internal.runtime.methods.DefaultMethod.internalCall(DefaultMethod.java:135)
at org.jruby.internal.runtime.methods.DynamicMethod.call(DynamicMethod.java:79)
at org.jruby.RubyObject.callMethod(RubyObject.java:564)
at org.jruby.evaluator.EvaluationState.fCallNode(EvaluationState.java:1030)
at org.jruby.evaluator.EvaluationState.evalInternal(EvaluationState.java:253)
at org.jruby.evaluator.EvaluationState.blockNode(EvaluationState.java:531)
at org.jruby.evaluator.EvaluationState.evalInternal(EvaluationState.java:201)
at org.jruby.evaluator.EvaluationState.eval(EvaluationState.java:164)
at org.jruby.internal.runtime.methods.DefaultMethod.internalCall(DefaultMethod.java:135)
at org.jruby.internal.runtime.methods.DynamicMethod.call(DynamicMethod.java:79)
at org.jruby.evaluator.EvaluationState.fCallNode(EvaluationState.java:1023)
at org.jruby.evaluator.EvaluationState.evalInternal(EvaluationState.java:253)
at org.jruby.evaluator.EvaluationState.eval(EvaluationState.java:164)
at org.jruby.internal.runtime.methods.DefaultMethod.internalCall(DefaultMethod.java:135)
at org.jruby.internal.runtime.methods.DynamicMethod.call(DynamicMethod.java:79)
at org.jruby.internal.runtime.methods.AliasMethod.call(AliasMethod.java:71)
at org.jruby.evaluator.EvaluationState.callNode(EvaluationState.java:568)
at org.jruby.evaluator.EvaluationState.evalInternal(EvaluationState.java:207)
at org.jruby.evaluator.EvaluationState.localAsgnNode(EvaluationState.java:1234)
at org.jruby.evaluator.EvaluationState.evalInternal(EvaluationState.java:286)
at org.jruby.evaluator.EvaluationState.blockNode(EvaluationState.java:531)
at org.jruby.evaluator.EvaluationState.evalInternal(EvaluationState.java:201)
at org.jruby.evaluator.EvaluationState.rootNode(EvaluationState.java:1609)
at org.jruby.evaluator.EvaluationState.evalInternal(EvaluationState.java:356)
at org.jruby.evaluator.EvaluationState.eval(EvaluationState.java:164)
at org.jruby.Ruby.eval(Ruby.java:287)
at org.jruby.Ruby.compileOrFallbackAndRun(Ruby.java:315)
at org.jruby.Main.runInterpreter(Main.java:228)
at org.jruby.Main.runInterpreter(Main.java:173)
at org.jruby.Main.run(Main.java:120)
at org.jruby.Main.main(Main.java:95)
----------

Stack trace 2:
----------
C:/jruby-1.0/lib/ruby/1.8/net/protocol.rb:91:in `read': End of file reached (EOFError)
from C:/jruby-1.0/lib/ruby/1.8/net/http.rb:2230:in `read_chunked'
from C:/jruby-1.0/lib/ruby/1.8/net/http.rb:2204:in `read_body_0'
from C:/jruby-1.0/lib/ruby/1.8/net/http.rb:2170:in `read_body'
from C:/jruby-1.0/lib/ruby/1.8/net/http.rb:2195:in `body'
from C:/jruby-1.0/lib/ruby/1.8/net/http.rb:2134:in `reading_body'
from C:/jruby-1.0/lib/ruby/1.8/net/http.rb:1051:in `request'
from C:/jruby-1.0/lib/ruby/1.8/net/http.rb:1034:in `request'
from C:/jruby-1.0/lib/ruby/1.8/net/http.rb:989:in `start'
from C:/jruby-1.0/lib/ruby/1.8/net/http.rb:1035:in `request'
from C:/jruby-1.0/lib/ruby/1.8/net/http.rb:989:in `request_post'
from http_test.rb:20
----------

Stack trace 3:
----------
C:/jruby-1.0/lib/ruby/1.8/net/protocol.rb:120:in `readuntil': End of file reached (EOFError)
from C:/jruby-1.0/lib/ruby/1.8/net/protocol.rb:126:in `readline'
from C:/jruby-1.0/lib/ruby/1.8/net/http.rb:2224:in `read_chunked'
from C:/jruby-1.0/lib/ruby/1.8/net/http.rb:2204:in `read_body_0'
from C:/jruby-1.0/lib/ruby/1.8/net/http.rb:2170:in `read_body'
from C:/jruby-1.0/lib/ruby/1.8/net/http.rb:2195:in `body'
from C:/jruby-1.0/lib/ruby/1.8/net/http.rb:2134:in `reading_body'
from C:/jruby-1.0/lib/ruby/1.8/net/http.rb:1051:in `request'
from C:/jruby-1.0/lib/ruby/1.8/net/http.rb:1034:in `request'
from C:/jruby-1.0/lib/ruby/1.8/net/http.rb:989:in `start'
from C:/jruby-1.0/lib/ruby/1.8/net/http.rb:1035:in `request'
from C:/jruby-1.0/lib/ruby/1.8/net/http.rb:989:in `request_post'
from http_test.rb:20
----------



 All   Comments   Work Log   Change History      Sort Order: Ascending order - Click to sort in descending order
Raphael Valyi - 19/Jul/07 10:23 AM
Hi,

I think I saw that error (End of file reached) too when uploading tags to delicious in JRuby. I wasn't really aware if it was a delicious failure or on my side, really seems to be a JRuby bug then. This occurs like one request out of 4...

my code is:

request = Net::HTTP::Get.new(path)
request.basic_auth 'login' pass'
response = http.request(request)
response.value
response.body

Raphaël Valyi.


Charles Oliver Nutter - 21/Oct/07 10:41 PM
Assigning OSSL-related bug to Ola.

Raphael Valyi - 03/Jan/08 07:37 PM
Actually the issue has worsen on head and this one is quite annoying. Before it was only inconsistent. Now it seems it doesn't ever work anymore at least on my side. For the previous code. I'm now getting systematically that stack:

java.lang.NullPointerException: null

RAILS_ROOT: /home/rvalyi/DEV/livetribune
Application Trace | Framework Trace | Full Trace

SSLSocket.java:435:in `org.jruby.ext.openssl.SSLSocket.close'
SSLSocket.java:446:in `org.jruby.ext.openssl.SSLSocket.sysclose'
null:-1:in `org.jruby.ext.openssl.SSLSocketInvoker$sysclose_F0.call'
FastInvocationCallback.java:55:in `org.jruby.runtime.callback.FastInvocationCallback.execute'
SimpleCallbackMethod.java:70:in `org.jruby.internal.runtime.methods.SimpleCallbackMethod.call'
CallSite.java:167:in `org.jruby.runtime.CallSite$ICNonBlockCallSite.call'
CallSite.java:73:in `org.jruby.runtime.CallSite$ArgumentBoxingCallSite.call'
ASTInterpreter.java:1735:in `org.jruby.evaluator.ASTInterpreter.vcallNode'
ASTInterpreter.java:475:in `org.jruby.evaluator.ASTInterpreter.evalInternal'
ASTInterpreter.java:627:in `org.jruby.evaluator.ASTInterpreter.blockNode'
ASTInterpreter.java:294:in `org.jruby.evaluator.ASTInterpreter.evalInternal'
ASTInterpreter.java:168:in `org.jruby.evaluator.ASTInterpreter.eval'
DefaultMethod.java:175:in `org.jruby.internal.runtime.methods.DefaultMethod.call'
CallSite.java:167:in `org.jruby.runtime.CallSite$ICNonBlockCallSite.call'
CallSite.java:100:in `org.jruby.runtime.CallSite$ArgumentBoxingCallSite.call'
ASTInterpreter.java:653:in `org.jruby.evaluator.ASTInterpreter.callNode'
ASTInterpreter.java:300:in `org.jruby.evaluator.ASTInterpreter.evalInternal'
ASTInterpreter.java:168:in `org.jruby.evaluator.ASTInterpreter.eval'
DefaultMethod.java:175:in `org.jruby.internal.runtime.methods.DefaultMethod.call'
CallSite.java:167:in `org.jruby.runtime.CallSite$ICNonBlockCallSite.call'
CallSite.java:100:in `org.jruby.runtime.CallSite$ArgumentBoxingCallSite.call'
ASTInterpreter.java:653:in `org.jruby.evaluator.ASTInterpreter.callNode'
ASTInterpreter.java:300:in `org.jruby.evaluator.ASTInterpreter.evalInternal'
ASTInterpreter.java:627:in `org.jruby.evaluator.ASTInterpreter.blockNode'
ASTInterpreter.java:294:in `org.jruby.evaluator.ASTInterpreter.evalInternal'
ASTInterpreter.java:168:in `org.jruby.evaluator.ASTInterpreter.eval'
DefaultMethod.java:175:in `org.jruby.internal.runtime.methods.DefaultMethod.call'
CallSite.java:167:in `org.jruby.runtime.CallSite$ICNonBlockCallSite.call'
CallSite.java:73:in `org.jruby.runtime.CallSite$ArgumentBoxingCallSite.call'
ASTInterpreter.java:1735:in `org.jruby.evaluator.ASTInterpreter.vcallNode'
ASTInterpreter.java:475:in `org.jruby.evaluator.ASTInterpreter.evalInternal'
ASTInterpreter.java:1067:in `org.jruby.evaluator.ASTInterpreter.ensureNode'
ASTInterpreter.java:340:in `org.jruby.evaluator.ASTInterpreter.evalInternal'
ASTInterpreter.java:627:in `org.jruby.evaluator.ASTInterpreter.blockNode'
ASTInterpreter.java:294:in `org.jruby.evaluator.ASTInterpreter.evalInternal'
ASTInterpreter.java:168:in `org.jruby.evaluator.ASTInterpreter.eval'
DefaultMethod.java:175:in `org.jruby.internal.runtime.methods.DefaultMethod.call'
CallSite.java:196:in `org.jruby.runtime.CallSite$ICBlockCallSite.call'
ASTInterpreter.java:658:in `org.jruby.evaluator.ASTInterpreter.callNode'
ASTInterpreter.java:300:in `org.jruby.evaluator.ASTInterpreter.evalInternal'
ASTInterpreter.java:627:in `org.jruby.evaluator.ASTInterpreter.blockNode'
ASTInterpreter.java:294:in `org.jruby.evaluator.ASTInterpreter.evalInternal'
ASTInterpreter.java:168:in `org.jruby.evaluator.ASTInterpreter.eval'
DefaultMethod.java:175:in `org.jruby.internal.runtime.methods.DefaultMethod.call'
CallSite.java:167:in `org.jruby.runtime.CallSite$ICNonBlockCallSite.call'
CallSite.java:100:in `org.jruby.runtime.CallSite$ArgumentBoxingCallSite.call'
ASTInterpreter.java:1093:in `org.jruby.evaluator.ASTInterpreter.fCallNode'
ASTInterpreter.java:346:in `org.jruby.evaluator.ASTInterpreter.evalInternal'
ASTInterpreter.java:627:in `org.jruby.evaluator.ASTInterpreter.blockNode'
ASTInterpreter.java:294:in `org.jruby.evaluator.ASTInterpreter.evalInternal'
ASTInterpreter.java:168:in `org.jruby.evaluator.ASTInterpreter.eval'
DefaultMethod.java:175:in `org.jruby.internal.runtime.methods.DefaultMethod.call'
RubyObject.java:1170:in `org.jruby.RubyObject.send'
[...]
CallSite.java:100:in `org.jruby.runtime.CallSite$ArgumentBoxingCallSite.call'
ASTInterpreter.java:1093:in `org.jruby.evaluator.ASTInterpreter.fCallNode'
ASTInterpreter.java:346:in `org.jruby.evaluator.ASTInterpreter.evalInternal'
ASTInterpreter.java:627:in `org.jruby.evaluator.ASTInterpreter.blockNode'
ASTInterpreter.java:294:in `org.jruby.evaluator.ASTInterpreter.evalInternal'
ASTInterpreter.java:1500:in `org.jruby.evaluator.ASTInterpreter.rescueNode'
ASTInterpreter.java:443:in `org.jruby.evaluator.ASTInterpreter.evalInternal'
ASTInterpreter.java:1065:in `org.jruby.evaluator.ASTInterpreter.ensureNode'
ASTInterpreter.java:340:in `org.jruby.evaluator.ASTInterpreter.evalInternal'
ASTInterpreter.java:168:in `org.jruby.evaluator.ASTInterpreter.eval'
InterpretedBlock.java:150:in `org.jruby.runtime.InterpretedBlock.yield'
InterpretedBlock.java:103:in `org.jruby.runtime.InterpretedBlock.call'
Block.java:105:in `org.jruby.runtime.Block.call'
RubyProc.java:205:in `org.jruby.RubyProc.call'
RubyProc.java:183:in `org.jruby.RubyProc.call'
RubyNativeThread.java:72:in `org.jruby.internal.runtime.RubyNativeThread.run'
/home/rvalyi/DEV/jruby/lib/ruby/1.8/net/protocol.rb:70:in `close'
/home/rvalyi/DEV/jruby/lib/ruby/1.8/net/http.rb:617:in `do_finish'
/home/rvalyi/DEV/jruby/lib/ruby/1.8/net/http.rb:549:in `start'
app/models/web2.0/delicious_module.rb:8:in `add_delicious_post'


Charles Oliver Nutter - 04/Jan/08 05:14 PM
I made a tiny fix to jopenssl that resolves this bug, and I reenabled the ssl tests there. It turns out they were all failing because of this problem anyway, so I did not need to add any new tests.

Raphael Valyi - 05/Jan/08 11:04 AM
I confirm that recompilling jopenssl.jar from JRuby-extras head fixed all my issues with https requests. Thank you Charles!