From: "ioquatix (Samuel Williams)" Date: 2022-09-24T22:14:27+00:00 Subject: [ruby-core:110056] [Ruby master Bug#19017] Net::HTTP may block when attempting to reuse a persistent connection Issue #19017 has been updated by ioquatix (Samuel Williams). @joshc thanks for your work investigating this issue and please let me know once you are ready for another code review. ---------------------------------------- Bug #19017: Net::HTTP may block when attempting to reuse a persistent connection https://bugs.ruby-lang.org/issues/19017#change-99306 * Author: joshc (Josh C) * Status: Open * Priority: Normal * ruby -v: ruby 3.1.2p20 (2022-04-12 revision 4491bb740a) [x86_64-linux] * Backport: 2.7: UNKNOWN, 3.0: UNKNOWN, 3.1: UNKNOWN ---------------------------------------- Ruby's Net::HTTP code performs a blocking `Net::BufferedIO#eof?` check when attempting to reuse a persistent HTTP connection. See https://github.com/ruby/ruby/blob/6b099328af2ae2d04cbfd06fedc36a19cdecd30d/lib/net/http.rb#L1573. The bug is the check can hang for up to the HTTP `read_timeout`, which is 60 seconds by default. The code calls `TCPSocket#wait_readable(0)` to see if the socket is readable before calling the blocking `eof?` method. However, it's possible for the socket to be readable with SSL Handshake records and no Application Data. So the call to `eof?` will process the SSL Handshake records, but hang since no Application Data is available. The issue can be triggered if a TLS 1.3 server sends a `NewSessionTicket` sometime after Application Data is written. The attached client and server code demonstrate the problem. Note it's important that the client and server be on separate hosts otherwise `eof?` will always return immediately. On the server, copy `Server.java` and `certs.p12` into a directory, install JDK 17, compile the server and run it: ``` $ openssl pkcs12 -info -in certs.p12 -noout -passin pass:password MAC: sha1, Iteration 2048 MAC length: 20, salt length: 8 PKCS7 Encrypted data: pbeWithSHA1And40BitRC2-CBC, Iteration 2048 Certificate bag PKCS7 Data Shrouded Keybag: pbeWithSHA1And3-KeyTripleDES-CBC, Iteration 2048 $ sudo apt install -y openjdk-17-jdk openjdk-17-jre $ javac Server.java $ java -Djavax.net.debug=ssl,verbose Server Loaded pkcs12 ``` On the client, copy `http.rb` and `ca.pem` into a directory, add the IP address for the server as `pluto` to `/etc/hosts`: ``` $ file ca.pem $ sudo vi /etc/hosts ... 192.168.0.10 pluto ... $ ruby --version ruby 2.7.6p219 (2022-04-12 revision c9c2245c0a) [x86_64-linux] $ openssl version OpenSSL 1.1.1f 31 Mar 2020 ``` Run the client to make the first request: ``` $ ruby http.rb opening connection to pluto:8888... opened starting SSL for pluto:8888... ``` The server will handle request_1 and trigger a new session ticket: ``` javax.net.ssl|DEBUG|10|main|2022-09-22 18:18:23.269 UTC|SSLCipher.java:466|jdk.tls.keyLimits: entry = AES/GCM/NoPadding KeyUpdate 2^37. AES/GCM/NOPADDING:KEYUPDATE = 137438953472 Connected to 37532 Handling request_0 ... snip ... javax.net.ssl|DEBUG|10|main|2022-09-22 18:18:25.310 UTC|SSLCipher.java:2024|KeyLimit write side: algorithm = AES/GCM/NOPADDING:KEYUPDATE countdown value = 137438953472 javax.net.ssl|DEBUG|10|main|2022-09-22 18:18:25.335 UTC|SSLCipher.java:1870|KeyLimit read side: algorithm = AES/GCM/NOPADDING:KEYUPDATE countdown value = 137438953472 read body updated session data javax.net.ssl|ALL|10|main|2022-09-22 18:18:25.343 UTC|SSLSocketImpl.java:1564|trigger new session ticket wrote response Handling request_1 ``` The client will hang when trying to reuse the persistent connection: ``` OSSL_DEBUG: SSL SESSION new callback added [ossl_ssl.c:963] SSL established, protocol: TLSv1.3, cipher: TLS_AES_256_GCM_SHA384 <- "POST / HTTP/1.1\r\nAccept-Encoding: identity\r\nConnection: keep-alive\r\nContent-Type: text/plain\r\nAccept: */*\r\nUser-Agent: Ruby\r\nHost: pluto:8888\r\nContent-Length: 0\r\n\r\n" <- "" OSSL_DEBUG: SSL SESSION new callback entered [ossl_ssl.c:454] -> "HTTP/1.1 200 OK\r\n" -> "Content-Length: 0\r\n" -> "\r\n" reading 0 bytes... -> "" read 0 bytes Conn keep-alive OSSL_DEBUG: SSL SESSION new callback entered [ossl_ssl.c:454] ``` Pressing Ctrl-C shows the backtrace: ``` ^CTraceback (most recent call last): 11: from http.rb:10:in `
' 10: from /home/josh/.rbenv/versions/2.7.6/lib/ruby/2.7.0/net/http.rb:933:in `start' 9: from http.rb:17:in `block in
' 8: from /home/josh/.rbenv/versions/2.7.6/lib/ruby/2.7.0/net/http.rb:1294:in `post' 7: from /home/josh/.rbenv/versions/2.7.6/lib/ruby/2.7.0/net/http.rb:1506:in `send_entity' 6: from /home/josh/.rbenv/versions/2.7.6/lib/ruby/2.7.0/net/http.rb:1492:in `request' 5: from /home/josh/.rbenv/versions/2.7.6/lib/ruby/2.7.0/net/http.rb:1518:in `transport_request' 4: from /home/josh/.rbenv/versions/2.7.6/lib/ruby/2.7.0/net/http.rb:1573:in `begin_transport' 3: from /home/josh/.rbenv/versions/2.7.6/lib/ruby/2.7.0/net/protocol.rb:134:in `eof?' 2: from /home/josh/.rbenv/versions/2.7.6/lib/ruby/2.7.0/openssl/buffering.rb:300:in `eof?' 1: from /home/josh/.rbenv/versions/2.7.6/lib/ruby/2.7.0/openssl/buffering.rb:57:in `fill_rbuff' /home/josh/.rbenv/versions/2.7.6/lib/ruby/2.7.0/openssl/buffering.rb:57:in `sysread': Interrupt ``` I get the same behavior with latest ruby too: ``` $ ruby --version ruby 3.1.2p20 (2022-04-12 revision 4491bb740a) [x86_64-linux] ``` Changing Net::HTTP to the following: ``` elsif @socket.io.read_nonblock(0, exception: false).nil? ``` Resolves the issue: ``` $ ruby http.rb opening connection to pluto:8888... opened starting SSL for pluto:8888... OSSL_DEBUG: SSL SESSION new callback added [ossl_ssl.c:963] SSL established, protocol: TLSv1.3, cipher: TLS_AES_256_GCM_SHA384 <- "POST / HTTP/1.1\r\nAccept-Encoding: identity\r\nConnection: keep-alive\r\nContent-Type: text/plain\r\nAccept: */*\r\nUser-Agent: Ruby\r\nHost: pluto:8888\r\nContent-Length: 0\r\n\r\n" <- "" OSSL_DEBUG: SSL SESSION new callback entered [ossl_ssl.c:454] -> "HTTP/1.1 200 OK\r\n" -> "Content-Length: 0\r\n" -> "\r\n" reading 0 bytes... -> "" read 0 bytes Conn keep-alive <- "POST / HTTP/1.1\r\nAccept-Encoding: identity\r\nConnection: keep-alive\r\nContent-Type: text/plain\r\nAccept: */*\r\nUser-Agent: Ruby\r\nHost: pluto:8888\r\nContent-Length: 0\r\n\r\n" <- "" OSSL_DEBUG: SSL SESSION new callback entered [ossl_ssl.c:454] -> "HTTP/1.1 200 OK\r\n" -> "Content-Length: 0\r\n" -> "\r\n" reading 0 bytes... -> "" read 0 bytes Conn keep-alive ``` However, based on https://github.com/ruby/ruby/pull/1089#issuecomment-159878003 that change may not be correct. Or it could be that Ruby on Windows doesn't have this issue anymore. ---Files-------------------------------- Server.java (3.75 KB) http.rb (423 Bytes) ca.pem (8.43 KB) certs.p12 (2.24 KB) -- https://bugs.ruby-lang.org/ Unsubscribe: