[DRE-maint] Bug#907790: ruby2.5: FTBFS due to openssl 1.1.1: test suite times out
Sebastian Andrzej Siewior
sebastian at breakpoint.cc
Sat Sep 29 17:03:23 BST 2018
On 2018-09-02 10:20:13 [+0200], Paul Gevers wrote:
> Dear ruby2.5 maintainers,
>
> Recently openssl was updated to upstream version 1.1.1. There have been
> multiple changes to increase security. As a result, some packages
> started to time out during autopkgtest and/or building of the package.
> Your package is one of them and does both:
The autopkgtest was always broken. So lets take a look at the testsuite
against 1.1:
| 1) Error:
|Net::TestSMTP#test_eof_error_backtrace:
|Errno::EADDRINUSE: Address already in use - listen(2)
| /srv/ruby2.5-2.5.1/.ext/common/socket.rb:709:in `listen'
| /srv/ruby2.5-2.5.1/.ext/common/socket.rb:709:in `block in tcp_server_sockets_port0'
| /srv/ruby2.5-2.5.1/.ext/common/socket.rb:708:in `each'
| /srv/ruby2.5-2.5.1/.ext/common/socket.rb:708:in `tcp_server_sockets_port0'
| /srv/ruby2.5-2.5.1/.ext/common/socket.rb:757:in `tcp_server_sockets'
| /srv/ruby2.5-2.5.1/test/net/smtp/test_smtp.rb:166:in `test_eof_error_backtrace'
|
| 2) Error:
|Net::TestSMTP#test_tls_connect:
|Errno::EADDRINUSE: Address already in use - listen(2)
| /srv/ruby2.5-2.5.1/.ext/common/socket.rb:709:in `listen'
| /srv/ruby2.5-2.5.1/.ext/common/socket.rb:709:in `block in tcp_server_sockets_port0'
| /srv/ruby2.5-2.5.1/.ext/common/socket.rb:708:in `each'
| /srv/ruby2.5-2.5.1/.ext/common/socket.rb:708:in `tcp_server_sockets_port0'
| /srv/ruby2.5-2.5.1/.ext/common/socket.rb:757:in `tcp_server_sockets'
| /srv/ruby2.5-2.5.1/test/net/smtp/test_smtp.rb:107:in `test_tls_connect'
|
| 3) Error:
|Net::TestSMTP#test_tls_connect_timeout:
|Errno::EADDRINUSE: Address already in use - listen(2)
| /srv/ruby2.5-2.5.1/.ext/common/socket.rb:709:in `listen'
| /srv/ruby2.5-2.5.1/.ext/common/socket.rb:709:in `block in tcp_server_sockets_port0'
| /srv/ruby2.5-2.5.1/.ext/common/socket.rb:708:in `each'
| /srv/ruby2.5-2.5.1/.ext/common/socket.rb:708:in `tcp_server_sockets_port0'
| /srv/ruby2.5-2.5.1/.ext/common/socket.rb:757:in `tcp_server_sockets'
| /srv/ruby2.5-2.5.1/test/net/smtp/test_smtp.rb:143:in `test_tls_connect_timeout'
|
| 4) Error:
|TestNetHTTPLocalBind#test_bind_to_local_host:
|Errno::EADDRINUSE: Address already in use - listen(2)
| /srv/ruby2.5-2.5.1/.ext/common/socket.rb:709:in `listen'
| /srv/ruby2.5-2.5.1/.ext/common/socket.rb:709:in `block in tcp_server_sockets_port0'
| /srv/ruby2.5-2.5.1/.ext/common/socket.rb:708:in `each'
| /srv/ruby2.5-2.5.1/.ext/common/socket.rb:708:in `tcp_server_sockets_port0'
| /srv/ruby2.5-2.5.1/.ext/common/socket.rb:757:in `tcp_server_sockets'
| /srv/ruby2.5-2.5.1/lib/webrick/utils.rb:65:in `create_listeners'
| /srv/ruby2.5-2.5.1/lib/webrick/ssl.rb:165:in `listen'
| /srv/ruby2.5-2.5.1/lib/webrick/server.rb:108:in `initialize'
| /srv/ruby2.5-2.5.1/lib/webrick/httpserver.rb:47:in `initialize'
| /srv/ruby2.5-2.5.1/test/net/http/utils.rb:67:in `new'
| /srv/ruby2.5-2.5.1/test/net/http/utils.rb:67:in `spawn_server'
| /srv/ruby2.5-2.5.1/test/net/http/utils.rb:32:in `setup'
|
| 5) Error:
|TestNetHTTPLocalBind#test_bind_to_local_port:
|Errno::EADDRINUSE: Address already in use - listen(2)
| /srv/ruby2.5-2.5.1/.ext/common/socket.rb:709:in `listen'
| /srv/ruby2.5-2.5.1/.ext/common/socket.rb:709:in `block in tcp_server_sockets_port0'
| /srv/ruby2.5-2.5.1/.ext/common/socket.rb:708:in `each'
| /srv/ruby2.5-2.5.1/.ext/common/socket.rb:708:in `tcp_server_sockets_port0'
| /srv/ruby2.5-2.5.1/.ext/common/socket.rb:757:in `tcp_server_sockets'
| /srv/ruby2.5-2.5.1/lib/webrick/utils.rb:65:in `create_listeners'
| /srv/ruby2.5-2.5.1/lib/webrick/ssl.rb:165:in `listen'
| /srv/ruby2.5-2.5.1/lib/webrick/server.rb:108:in `initialize'
| /srv/ruby2.5-2.5.1/lib/webrick/httpserver.rb:47:in `initialize'
| /srv/ruby2.5-2.5.1/test/net/http/utils.rb:67:in `new'
| /srv/ruby2.5-2.5.1/test/net/http/utils.rb:67:in `spawn_server'
| /srv/ruby2.5-2.5.1/test/net/http/utils.rb:32:in `setup'
|
|Finished tests in 258.296938s, 67.0778 tests/s, 8762.6320 assertions/s.
|17326 tests, 2263361 assertions, 0 failures, 5 errors, 59 skips
|
|ruby -v: ruby 2.5.1p57 (2018-03-29 revision 63029) [x86_64-linux]
|make: *** [uncommon.mk:698: yes-test-almost] Error 5
For some reason those five tests always fail here (with "already in
use"). Lets look at openssl 1.1.1 without the "key-too-small" contraint.
First TLS1.0 … TLS1.2:
| 1) Failure:
|OpenSSL::TestSSL#test_minmax_version [/srv/ruby2.5-2.5.1/test/openssl/utils.rb:280]:
|exceptions on 1 threads:
|#<Thread:0x0000558279dd3a50@/srv/ruby2.5-2.5.1/test/openssl/utils.rb:252 dead>:
|/srv/ruby2.5-2.5.1/test/lib/minitest/unit.rb:201:in `assert': <"TLSv1.2"> expected but was
|<"TLSv1.3">. (MiniTest::Assertion)
| from /srv/ruby2.5-2.5.1/test/lib/test/unit/assertions.rb:37:in `assert'
| from /srv/ruby2.5-2.5.1/test/lib/test/unit/assertions.rb:300:in `assert_equal'
| from /srv/ruby2.5-2.5.1/test/openssl/test_ssl.rb:982:in `block (3 levels) in test_minmax_version'
| from /srv/ruby2.5-2.5.1/test/openssl/test_ssl.rb:1538:in `server_connect'
| from /srv/ruby2.5-2.5.1/test/openssl/test_ssl.rb:981:in `block (2 levels) in test_minmax_version'
| from /srv/ruby2.5-2.5.1/test/openssl/test_ssl.rb:977:in `each'
| from /srv/ruby2.5-2.5.1/test/openssl/test_ssl.rb:977:in `block in test_minmax_version'
| from /srv/ruby2.5-2.5.1/test/openssl/utils.rb:258:in `block (2 levels) in start_server'
|
| 5) Error:
|OpenSSL::TestPKeyRSA#test_dup:
|OpenSSL::PKey::RSAError: key size too small
| /srv/ruby2.5-2.5.1/test/openssl/test_pkey_rsa.rb:292:in `generate'
| /srv/ruby2.5-2.5.1/test/openssl/test_pkey_rsa.rb:292:in `test_dup'
|
|Finished tests in 257.505865s, 67.2839 tests/s, 8792.2658 assertions/s.
|17326 tests, 2264060 assertions, 1 failures, 6 errors, 60 skips
|
|ruby -v: ruby 2.5.1p57 (2018-03-29 revision 63029) [x86_64-linux]
|make: *** [uncommon.mk:698: yes-test-almost] Error 7
Removed the tests 2-4 which also failed in the first run. Basically
okay. It looks like #1 failed because TLS1.3 is now possible and it was
expected. Test #5 failed because it tries to create a 256 bit RSA key
and the limit now is 512. Nothing serious.
Extending to TLS1.3 as upper max:
| 1) Failure:
|OpenSSL::TestSSLSession#test_ctx_server_session_cb [/srv/ruby2.5-2.5.1/test/openssl/utils.rb:280]:
|exceptions on 1 threads:
|#<Thread:0x0000564334a4c3d8@/srv/ruby2.5-2.5.1/test/openssl/utils.rb:252 dead>:
|/srv/ruby2.5-2.5.1/test/lib/minitest/unit.rb:201:in `assert': Expected "\x89V\a\x90\x0F!\xC0^\xCDY\xEF\xB0J\xE0O\t\x99\x92v\xBC6\xE778\xED]\xD9O\xAE\x8Au&" to be nil. (MiniTest::Assertion)
| from /srv/ruby2.5-2.5.1/test/lib/test/unit/assertions.rb:37:in `assert'
| from /srv/ruby2.5-2.5.1/test/lib/minitest/unit.rb:301:in `assert_nil'
| from /srv/ruby2.5-2.5.1/test/openssl/test_ssl_session.rb:300:in `block in test_ctx_server_session_cb'
| from /srv/ruby2.5-2.5.1/test/openssl/utils.rb:258:in `block (2 levels) in start_server'
|
| 2) Failure:
|OpenSSL::TestSSLSession#test_server_session_cache [/srv/ruby2.5-2.5.1/test/openssl/utils.rb:280]:
|exceptions on 2 threads:
|#<Thread:0x0000564334b2cdc0@/srv/ruby2.5-2.5.1/test/openssl/utils.rb:252 dead>:
|/srv/ruby2.5-2.5.1/test/lib/minitest/unit.rb:201:in `assert': <"abc\n"> expected but was
|<nil>. (MiniTest::Assertion)
| from /srv/ruby2.5-2.5.1/test/lib/test/unit/assertions.rb:37:in `assert'
| from /srv/ruby2.5-2.5.1/test/lib/test/unit/assertions.rb:300:in `assert_equal'
| from /srv/ruby2.5-2.5.1/test/openssl/test_ssl_session.rb:202:in `block (3 levels) in test_server_session_cache'
| from /srv/ruby2.5-2.5.1/test/openssl/test_ssl_session.rb:388:in `server_connect_with_session'
| from /srv/ruby2.5-2.5.1/test/openssl/test_ssl_session.rb:201:in `block (2 levels) in test_server_session_cache'
| from /srv/ruby2.5-2.5.1/test/openssl/test_ssl_session.rb:199:in `times'
| from /srv/ruby2.5-2.5.1/test/openssl/test_ssl_session.rb:199:in `block in test_server_session_cache'
| from /srv/ruby2.5-2.5.1/test/openssl/utils.rb:258:in `block (2 levels) in start_server'
|---
|#<Thread:0x0000564334b2c988@/srv/ruby2.5-2.5.1/test/openssl/utils.rb:233 dead>:
|/srv/ruby2.5-2.5.1/test/lib/minitest/unit.rb:201:in `assert': <0> expected but was
|<1>. (MiniTest::Assertion)
| from /srv/ruby2.5-2.5.1/test/lib/test/unit/assertions.rb:37:in `assert'
| from /srv/ruby2.5-2.5.1/test/lib/test/unit/assertions.rb:300:in `assert_equal'
| from /srv/ruby2.5-2.5.1/test/openssl/test_ssl_session.rb:162:in `block in test_server_session_cache'
| from /srv/ruby2.5-2.5.1/test/openssl/utils.rb:239:in `block (4 levels) in start_server'
|
| 3) Failure:
|TestGemRemoteFetcher#test_do_not_allow_invalid_client_cert_auth_connection [/srv/ruby2.5-2.5.1/test/rubygems/test_gem_remote_fetcher.rb:845]:
|[Gem::RemoteFetcher::FetchError] exception expected, not
|Class: <OpenSSL::SSL::SSLError>
|Message: <"SSL_read: tlsv1 alert decrypt error">
|---Backtrace---
|/srv/ruby2.5-2.5.1/.ext/common/openssl/buffering.rb:182:in `sysread_nonblock'
|/srv/ruby2.5-2.5.1/.ext/common/openssl/buffering.rb:182:in `read_nonblock'
|/srv/ruby2.5-2.5.1/lib/net/protocol.rb:175:in `rbuf_fill'
|/srv/ruby2.5-2.5.1/lib/net/protocol.rb:157:in `readuntil'
|/srv/ruby2.5-2.5.1/lib/net/protocol.rb:167:in `readline'
|/srv/ruby2.5-2.5.1/lib/net/http/response.rb:40:in `read_status_line'
|/srv/ruby2.5-2.5.1/lib/net/http/response.rb:29:in `read_new'
|/srv/ruby2.5-2.5.1/lib/net/http.rb:1494:in `block in transport_request'
|/srv/ruby2.5-2.5.1/lib/net/http.rb:1491:in `catch'
|/srv/ruby2.5-2.5.1/lib/net/http.rb:1491:in `transport_request'
|/srv/ruby2.5-2.5.1/lib/net/http.rb:1464:in `request'
|/srv/ruby2.5-2.5.1/lib/rubygems/request.rb:221:in `perform_request'
|/srv/ruby2.5-2.5.1/lib/rubygems/request.rb:156:in `fetch'
|/srv/ruby2.5-2.5.1/lib/rubygems/remote_fetcher.rb:368:in `request'
|/srv/ruby2.5-2.5.1/lib/rubygems/remote_fetcher.rb:251:in `fetch_http'
|/srv/ruby2.5-2.5.1/lib/rubygems/remote_fetcher.rb:292:in `fetch_path'
|/srv/ruby2.5-2.5.1/test/rubygems/test_gem_remote_fetcher.rb:846:in `block (2 levels) in test_do_not_allow_invalid_client_cert_auth_connection'
|---------------
|
| 4) Failure:
|TestNetHTTPS#test_session_reuse [/srv/ruby2.5-2.5.1/test/net/http/test_https.rb:85]:
|Failed assertion, no message given.
|
| 5) Failure:
|TestNetHTTPS#test_session_reuse_but_expire [/srv/ruby2.5-2.5.1/test/net/http/test_https.rb:112]:
|<""> expected to be != to
|<"">.
|
| 9) Error:
|OpenSSL::TestPKeyRSA#test_dup:
|OpenSSL::PKey::RSAError: key size too small
| /srv/ruby2.5-2.5.1/test/openssl/test_pkey_rsa.rb:292:in `generate'
| /srv/ruby2.5-2.5.1/test/openssl/test_pkey_rsa.rb:292:in `test_dup'
|
|Finished tests in 258.901632s, 66.9212 tests/s, 8742.1233 assertions/s.
|17326 tests, 2263350 assertions, 5 failures, 6 errors, 60 skips
|
|ruby -v: ruby 2.5.1p57 (2018-03-29 revision 63029) [x86_64-linux]
|make: *** [uncommon.mk:698: yes-test-almost] Error 11
It looks that TLSv1.3 was negotiated and the requirement to catch the
"need read" on READ() error.
Lets try the same thing with ruby-2.6.0-preview2:
| 1) Failure:
|TestGemRemoteFetcher#test_do_not_allow_invalid_client_cert_auth_connection [/srv/ruby-2.6.0-preview2/test/rubygems/test_gem_remote_fetcher.rb:845]:
|[Gem::RemoteFetcher::FetchError] exception expected, not
|Class: <OpenSSL::SSL::SSLError>
|Message: <"SSL_read: tlsv1 alert decrypt error">
|---Backtrace---
|/srv/ruby-2.6.0-preview2/.ext/common/openssl/buffering.rb:182:in `sysread_nonblock'
|/srv/ruby-2.6.0-preview2/.ext/common/openssl/buffering.rb:182:in `read_nonblock'
|/srv/ruby-2.6.0-preview2/lib/net/protocol.rb:176:in `rbuf_fill'
|/srv/ruby-2.6.0-preview2/lib/net/protocol.rb:157:in `readuntil'
|/srv/ruby-2.6.0-preview2/lib/net/protocol.rb:167:in `readline'
|/srv/ruby-2.6.0-preview2/lib/net/http/response.rb:40:in `read_status_line'
|/srv/ruby-2.6.0-preview2/lib/net/http/response.rb:29:in `read_new'
|/srv/ruby-2.6.0-preview2/lib/net/http.rb:1493:in `block in transport_request'
|/srv/ruby-2.6.0-preview2/lib/net/http.rb:1490:in `catch'
|/srv/ruby-2.6.0-preview2/lib/net/http.rb:1490:in `transport_request'
|/srv/ruby-2.6.0-preview2/lib/net/http.rb:1463:in `request'
|/srv/ruby-2.6.0-preview2/lib/rubygems/request.rb:221:in `perform_request'
|/srv/ruby-2.6.0-preview2/lib/rubygems/request.rb:156:in `fetch'
|/srv/ruby-2.6.0-preview2/lib/rubygems/remote_fetcher.rb:366:in `request'
|/srv/ruby-2.6.0-preview2/lib/rubygems/remote_fetcher.rb:249:in `fetch_http'
|/srv/ruby-2.6.0-preview2/lib/rubygems/remote_fetcher.rb:290:in `fetch_path'
|/srv/ruby-2.6.0-preview2/test/rubygems/test_gem_remote_fetcher.rb:846:in `block (2 levels) in test_do_not_allow_invalid_client_cert_auth_connection'
|---------------
|
| 2) Failure:
|TestNetHTTPS#test_session_reuse [/srv/ruby-2.6.0-preview2/test/net/http/test_https.rb:85]:
|Failed assertion, no message given.
|
| 3) Failure:
|TestNetHTTPS#test_session_reuse_but_expire [/srv/ruby-2.6.0-preview2/test/net/http/test_https.rb:112]:
|<""> expected to be != to
|<"">.
|
|Finished tests in 345.558931s, 56.5056 tests/s, 6806.7464 assertions/s.
|19526 tests, 2352132 assertions, 3 failures, 5 errors, 135 skips
|
|ruby -v: ruby 2.6.0preview2 (2018-05-31 trunk 63539) [x86_64-linux]
|make: *** [uncommon.mk:744: yes-test-almost] Error 8
So we are down to three errors (excluding the "Address already in use"
failure). It seems of the TLSv1.3 goodies and the 512bit key limitation
was considred in the testsuite.
Sebastian
More information about the Pkg-ruby-extras-maintainers
mailing list