t/nonblock.t: Failing on FreeBSD-12 and -13

[jkeenan]

When tested against recent development versions of Perl on FreeBSD, t/nonblock.t is failing, preventing IO::Socket::SSL and its reverse dependencies from being installed.

Earlier today I filed a "blead breaks CPAN" ticket about this in the Perl 5 bug queue. But further testing leads me to doubt that the breakage is due to a change in blead.

Here's typical output I'm getting on FreeBSD-12:

[perlmonger: IO-Socket-SSL-2.070] $ thisprove --version
TAP::Harness v3.43 and Perl v5.33.6

[perlmonger: IO-Socket-SSL-2.070] $ uname -mrs
FreeBSD 12.2-STABLE amd64

[perlmonger: IO-Socket-SSL-2.070] $ thisprove -vb t/nonblock.t
t/nonblock.t .. 
1..27
ok # [server] Server Initialization
# connect in progress
# claims that socket is already connected
ok # [client] client tcp connect
# wrote 9 bytes
ok # [client] write plain text
ok # [server] tcp accept
ok # [server] received plain text
ok # [server] upgrade to_client to IO::Socket::SSL
ok # [client] upgrade client to IO::Socket::SSL
# SSL wants a read first
ok # [client] connected
ok # [client] nonblocking connect with 1 attempts
ok # [server] ssl accept handshake done
# sndbuf=8192
ok # [server] received client message
# $!=Resource temporarily unavailable $SSL_ERROR=SSL wants a write first send=2570
# wait for write
# read 30000 (1 r/w attempts)
not ok # [server] tcp accept
# failed to tcp accept: Resource temporarily unavailable
# fail can_write
not ok # [client] syswrite
ok # [client] multiple write attempts
ok # [client] 30000 bytes send
# connect in progress
# claims that socket is already connected
ok # [client] client tcp connect
# wrote 9 bytes
ok # [client] write plain text
ok # [client] upgrade client to IO::Socket::SSL
# SSL wants a read first
# failed to connect: 
not ok # [client] connected
# sndbuf=8192
# $!=Resource temporarily unavailable $SSL_ERROR=SSL wants a read first send=8190
# wait for read
# fail can_read
not ok # [client] syswrite
not ok # [client] multiple write attempts
not ok # [client] 30000 bytes send
Failed 11/27 subtests 

Test Summary Report
-------------------
t/nonblock.t (Wstat: 0 Tests: 22 Failed: 6)
  Failed tests:  12-13, 19-22
  Parse errors: Bad plan.  You planned 27 tests but ran 22.
Files=1, Tests=22, 106 wallclock secs ( 0.05 usr  0.00 sys +  0.63 cusr  0.07 csys =  0.75 CPU)
Result: FAIL

Here is the relevant CPANtesters URL.

And here is a FAIL occurring on FreeBSD-13.

I note that you have at least 2 other bug tickets about this test. See https://github.com/noxxi/p5-io-socket-ssl/issues/98 and https://github.com/noxxi/p5-io-socket-ssl/issues/76.

Can you investigate?

Thank you very much. Jim Keenan

[jkeenan]

I note further that on this machine at some point I was able to successfully install IO-Socket-SSL-2.068 against perl-5.32.0:

$ perl -v | head -2 | tail -1
This is perl 5, version 32, subversion 0 (v5.32.0) built for amd64-freebsd-thread-multi
$ perl -MIO::Socket::SSL -E 'say $IO::Socket::SSL::VERSION'
2.068

But in February I failed with 2.069 and again today with 2.070.

[perlmonger: IO-Socket-SSL-2.069-1] $ prove -vb t/nonblock.t 
t/nonblock.t .. 
1..27
ok # [server] Server Initialization
# connect in progress
# claims that socket is already connected
ok # [client] client tcp connect
# wrote 9 bytes
ok # [client] write plain text
ok # [server] tcp accept
ok # [server] received plain text
ok # [server] upgrade to_client to IO::Socket::SSL
ok # [client] upgrade client to IO::Socket::SSL
# SSL wants a read first
ok # [client] connected
ok # [client] nonblocking connect with 1 attempts
ok # [server] ssl accept handshake done
# sndbuf=8192
ok # [server] received client message
# $!=Resource temporarily unavailable $SSL_ERROR=SSL wants a write first send=2570
# wait for write
# read 30000 (1 r/w attempts)
not ok # [server] tcp accept
# failed to tcp accept: Resource temporarily unavailable
# fail can_write
not ok # [client] syswrite
ok # [client] multiple write attempts
ok # [client] 30000 bytes send
# connect in progress
# claims that socket is already connected
ok # [client] client tcp connect
# wrote 9 bytes
ok # [client] write plain text
ok # [client] upgrade client to IO::Socket::SSL
# SSL wants a read first
# failed to connect: 
not ok # [client] connected
# sndbuf=8192
# $!=Resource temporarily unavailable $SSL_ERROR=SSL wants a read first send=8190
# wait for read
# fail can_read
not ok # [client] syswrite
not ok # [client] multiple write attempts
not ok # [client] 30000 bytes send
Failed 11/27 subtests 

Test Summary Report
-------------------
t/nonblock.t (Wstat: 0 Tests: 22 Failed: 6)
  Failed tests:  12-13, 19-22
  Parse errors: Bad plan.  You planned 27 tests but ran 22.
Files=1, Tests=22, 106 wallclock secs ( 0.02 usr  0.02 sys +  0.37 cusr  0.09 csys =  0.48 CPU)
Result: FAIL

[tonycoz]

This passed for me with blead@d913c42369e9 with both the following configurations:

./Configure -des -Dusedevel -Doptimize=-O0\ -g -DDEBUGGING -Dusethreads -Dprefix=/usr/home/tony/perl/blead
./Configure -des -Dusedevel -Dusethreads -Dprefix=/usr/home/tony/perl/blead

Environment:

# libssl information:
#   SSLEAY_VERSION:      'OpenSSL 1.1.1h-freebsd  22 Sep 2020'
#   SSLEAY_CFLAGS:       'compiler: clang'
#   SSLEAY_BUILT_ON:     'built on: reproducible build, date unspecified'
#   SSLEAY_PLATFORM:     'platform: FreeBSD-amd64'
#   SSLEAY_DIR:          'OPENSSLDIR: "/etc/ssl"'
#   OPENSSL_ENGINES_DIR: 'ENGINESDIR: "/usr/lib/engines"'

FreeBSD freebsd12 12.2-RELEASE-p1 FreeBSD 12.2-RELEASE-p1 GENERIC  amd64

[jkeenan]

This passed for me with blead@d913c42369e9 with both the following configurations:

./Configure -des -Dusedevel -Doptimize=-O0\ -g -DDEBUGGING -Dusethreads -Dprefix=/usr/home/tony/perl/blead
./Configure -des -Dusedevel -Dusethreads -Dprefix=/usr/home/tony/perl/blead

Environment:

# libssl information:
#   SSLEAY_VERSION:      'OpenSSL 1.1.1h-freebsd  22 Sep 2020'
#   SSLEAY_CFLAGS:       'compiler: clang'
#   SSLEAY_BUILT_ON:     'built on: reproducible build, date unspecified'
#   SSLEAY_PLATFORM:     'platform: FreeBSD-amd64'
#   SSLEAY_DIR:          'OPENSSLDIR: "/etc/ssl"'
#   OPENSSL_ENGINES_DIR: 'ENGINESDIR: "/usr/lib/engines"'

FreeBSD freebsd12 12.2-RELEASE-p1 FreeBSD 12.2-RELEASE-p1 GENERIC  amd64

@tonycoz, to what do you attribute your PASSes?

[tonycoz]

not ok # [server] tcp accept
# failed to tcp accept: Resource temporarily unavailable

This is the first failure, the error message is the one for EAGAIN - ie. the socket isn't ready to accept.

You might want to try adding some error checking to:

        # accept a connection
        IO::Select->new( $server )->can_read(30);

so maybe it would become:

        IO::Select->new( $server )->can_read(30) or diag "can_read: $!";

since this line should be waiting for the server socket to be ready to accept.

Given that the "fast" test passes (the code tests starting up SSL quickly and slowly if I understand it), it doesn't appear to be a firewall issue.

Do you seen any long delays while running the test? That might be another clue for the author in tracking this down.

[jkeenan]

Trying some of your suggestions ...

[perlmonger: IO-Socket-SSL-2.070] $ thisperl -v |head -2 | tail -1
This is perl 5, version 34, subversion 0 (v5.34.0-RC2) built for amd64-freebsd-thread-multi

$ thisperl -V:config_args
config_args='-des -Dusedevel -Duseithreads -Doptimize=-O2 -pipe -fstack-protector -fno-strict-aliasing';

$ diff t/nonblock.t.orig t/nonblock.t
259c259,260
<   IO::Select->new( $server )->can_read(30);
---
>     #IO::Select->new( $server )->can_read(30);
>   IO::Select->new( $server )->can_read(30) or diag("XXX: can_read: $!");

$ thisprove -vb t/nonblock.t
t/nonblock.t .. 
1..27
ok # [server] Server Initialization
# connect in progress
# claims that socket is already connected
ok # [client] client tcp connect
# wrote 9 bytes
ok # [client] write plain text
ok # [server] tcp accept
ok # [server] received plain text
ok # [server] upgrade to_client to IO::Socket::SSL
ok # [client] upgrade client to IO::Socket::SSL
# SSL wants a read first
ok # [client] connected
ok # [client] nonblocking connect with 1 attempts
ok # [server] ssl accept handshake done
# sndbuf=8192
ok # [server] received client message
# $!=Resource temporarily unavailable $SSL_ERROR=SSL wants a write first send=2570
# wait for write
# read 30000 (1 r/w attempts)
# XXX: can_read: 
not ok # [server] tcp accept
# failed to tcp accept: Resource temporarily unavailable
# fail can_write
not ok # [client] syswrite
...

not ok # [server] tcp accept
# failed to tcp accept: Resource temporarily unavailable

This is the first failure, the error message is the one for EAGAIN - ie. the socket isn't ready to accept.

You might want to try adding some error checking to:

        # accept a connection
        IO::Select->new( $server )->can_read(30);

so maybe it would become:

        IO::Select->new( $server )->can_read(30) or diag "can_read: $!";

since this line should be waiting for the server socket to be ready to accept.

Given that the "fast" test passes (the code tests starting up SSL quickly and slowly if I understand it), it doesn't appear to be a firewall issue.

Do you seen any long delays while running the test? That might be another clue for the author in tracking this down.

There's certainly a delay at:

# wait for write
# read 30000 (1 r/w attempts)

... but whether it's "long" I can't really judge.

But then, as reported above, I get:

# XXX: can_read: 
not ok # [server] tcp accept
# failed to tcp accept: Resource temporarily unavailable
# fail can_write
not ok # [client] syswrite

... which suggests that $! is an empty string.

[jkeenan]

With the release of perl-5.34.0 today, this failure is now critical. @noxxi, can you investigate?

Thank you very much. Jim Keenan

[jkeenan]

With the release of perl-5.34.0 today, this failure is now critical. @noxxi, can you investigate?

Thank you very much. Jim Keenan

At the suggestion of @DrHyde on #toolchain, I tried installing version 2.068. I got the same test failures. I then tried installing version 2.067. I got fewer failures on my first attempt: only 2 failures in t/nonblock.t. I then went back to try a force-install. I got:

t/nonblock.t                    (Wstat: 0 Tests: 22 Failed: 6)
  Failed tests:  12-13, 19-22
  Parse errors: Bad plan.  You planned 27 tests but ran 22.

I'm force-installing this version and keeping my fingers crossed.

[noxxi]

Please provide the version of Net::SSLeay and openssl used. You should be able to simply call perl -Mblib t/01loadmodule.t for this. Also, is this error specific to your installation or plattform or environment, i.e. does this happen on other FreeBSD systems too? Is it reproducible or does it only happen sporadically?

[jkeenan]

Please provide the version of Net::SSLeay and openssl used. You should be able to simply call perl -Mblib t/01loadmodule.t for this.

Thank you for looking into this. Latest data:

$ uname -mrs
FreeBSD 12.2-STABLE amd64

$ bleadperl -v | head -2 | tail -1
This is perl 5, version 35, subversion 0 (v5.35.0-18-g80503cdabf) built for amd64-freebsd-thread-multi

$ bleadperl -V:config_args
config_args='-des -Dusedevel -Uversiononly -Dprefix=/home/jkeenan/testing/blead -Dman1dir=none -Dman3dir=none -Duseithreads -Doptimize=-O2 -pipe -fstack-protector -fno-strict-aliasing';

$ ./bin/cpanm IO::Socket::SSL
--> Working on IO::Socket::SSL
Fetching http://www.cpan.org/authors/id/S/SU/SULLR/IO-Socket-SSL-2.070.tar.gz ... OK
==> Found dependencies: Net::SSLeay
--> Working on Net::SSLeay
Fetching http://www.cpan.org/authors/id/C/CH/CHRISN/Net-SSLeay-1.90.tar.gz ... OK
Configuring Net-SSLeay-1.90 ... OK
Building and testing Net-SSLeay-1.90 ... OK
Successfully installed Net-SSLeay-1.90
Configuring IO-Socket-SSL-2.070 ... OK
==> Found dependencies: Mozilla::CA
--> Working on Mozilla::CA
Fetching http://www.cpan.org/authors/id/A/AB/ABH/Mozilla-CA-20200520.tar.gz ... OK
Configuring Mozilla-CA-20200520 ... OK
Building and testing Mozilla-CA-20200520 ... OK
Successfully installed Mozilla-CA-20200520
Building and testing IO-Socket-SSL-2.070 ... FAIL
! Installing IO::Socket::SSL failed. See /home/jkeenan/.cpanm/work/1621604789.78023/build.log for details. Retry with --force to force install it.

$ cd ~/.cpanm/latest-build/IO-Socket-SSL-2.070

$ bleadperl -Mblib t/01loadmodule.t 
1..3
ok 1 - loaded
# openssl version compiled=0x1010109f linked=0x1010109f -- OpenSSL 1.1.1i-freebsd  8 Dec 2020
# Net::SSLeay version=1.90
# parent IO::Socket::IP version=0.41
ok 2 - IO::Socket::SSL::DEBUG 1
ok 3 - Net::SSLeay::trace 1

$ bleadprove -vb t/nonblock.t
t/nonblock.t .. 
1..27
ok # [server] Server Initialization
# connect in progress
# claims that socket is already connected
ok # [client] client tcp connect
# wrote 9 bytes
ok # [client] write plain text
ok # [server] tcp accept
ok # [server] received plain text
ok # [server] upgrade to_client to IO::Socket::SSL
ok # [client] upgrade client to IO::Socket::SSL
# SSL wants a read first
ok # [client] connected
ok # [client] nonblocking connect with 1 attempts
ok # [server] ssl accept handshake done
# sndbuf=8192
ok # [server] received client message
# $!=Resource temporarily unavailable $SSL_ERROR=SSL wants a write first send=2570
# wait for write
# read 30000 (1 r/w attempts)
not ok # [server] tcp accept
# failed to tcp accept: Resource temporarily unavailable
# fail can_write
not ok # [client] syswrite
ok # [client] multiple write attempts
ok # [client] 30000 bytes send
# connect in progress
# claims that socket is already connected
ok # [client] client tcp connect
# wrote 9 bytes
ok # [client] write plain text
ok # [client] upgrade client to IO::Socket::SSL
# SSL wants a read first
# failed to connect: 
not ok # [client] connected
# sndbuf=8192
# $!=Resource temporarily unavailable $SSL_ERROR=SSL wants a read first send=8190
# wait for read
# fail can_read
not ok # [client] syswrite
not ok # [client] multiple write attempts
not ok # [client] 30000 bytes send
Failed 11/27 subtests 
Test Summary Report
-------------------
t/nonblock.t (Wstat: 0 Tests: 22 Failed: 6)
  Failed tests:  12-13, 19-22
  Parse errors: Bad plan.  You planned 27 tests but ran 22.
Files=1, Tests=22, 105 wallclock secs ( 0.05 usr  0.01 sys +  0.56 cusr  0.05 csys =  0.66 CPU)
Result: FAIL

Also, is this error specific to your installation or plattform or environment, i.e. does this happen on other FreeBSD systems too? Is it reproducible or does it only happen sporadically?

This error is consistent to my platform; I have now reproduced it many times. This is a server (not a VM) on which I do most of my Perl 5 work and which I use for smoke-testing and CPANtesters reports. It is maintained by an experienced BSD sysadmin. So I have confidence in the platform.

It appears in some, but not all, other CPANtesters reports. See http://matrix.cpantesters.org/?dist=IO-Socket-SSL;os=freebsd;perl=5.33.9;reports=1. In my original post, I provided a URL to one other failure and I cited two other bug tickets pertaining to t/nonblock.t.

Thank you very much. Jim Keenan

[noxxi]

Could you please try the following slightly modified version from https://wtools.io/paste-code/b5iY and provide the output? It likely does not fix the problem since it adds just more debugging and timing. But it provides me with more information for debugging the problem. Or use this diff:

diff --git a/t/nonblock.t b/t/nonblock.t
index ad62799..db187ff 100644
--- a/t/nonblock.t
+++ b/t/nonblock.t
@@ -256,7 +256,8 @@ if ( $pid == 0 ) {
     foreach my $test ( 'slow','fast' ) {

        # accept a connection
-       IO::Select->new( $server )->can_read(30);
+       my $can_read = IO::Select->new( $server )->can_read(30);
+       diag("tcp server socket is ".($can_read? "ready" : "NOT ready"));
        my $from_client = $server->accept or print "not ";
        ok( "tcp accept" );
        $from_client || do {
@@ -388,5 +389,5 @@ exit;

-sub ok { print "ok # [$ID] @_\n"; }
-sub diag { print "# @_\n" }
+sub ok { print "ok # [$ID] @_ - ".localtime()."\n"; }
+sub diag { print "# @_ - ".localtime()."\n" }

[jkeenan]

$ diff -w t/nonblock.t t/modified-nonblock.t 
259c259,260
<   IO::Select->new( $server )->can_read(30);
---
>   my $can_read = IO::Select->new( $server )->can_read(30);
>   diag("tcp server socket is ".($can_read? "ready" : "NOT ready"));
391,392c392,393
< sub ok { print "ok # [$ID] @_\n"; }
< sub diag { print "# @_\n" }
---
> sub ok { print "ok # [$ID] @_ - ".localtime()."\n"; }
> sub diag { print "# @_ - ".localtime()."\n" }

$ bleadprove -vb t/modified-nonblock.t 
t/modified-nonblock.t .. 
1..27
ok # [server] Server Initialization - Fri May 21 22:23:44 2021
# connect in progress - Fri May 21 22:23:44 2021
# tcp server socket is ready - Fri May 21 22:23:44 2021
# claims that socket is already connected - Fri May 21 22:23:44 2021
ok # [client] client tcp connect - Fri May 21 22:23:44 2021
# wrote 9 bytes - Fri May 21 22:23:44 2021
ok # [client] write plain text - Fri May 21 22:23:44 2021
ok # [server] tcp accept - Fri May 21 22:23:44 2021
ok # [server] received plain text - Fri May 21 22:23:44 2021
ok # [server] upgrade to_client to IO::Socket::SSL - Fri May 21 22:23:44 2021
ok # [client] upgrade client to IO::Socket::SSL - Fri May 21 22:23:44 2021
# SSL wants a read first - Fri May 21 22:23:44 2021
ok # [client] connected - Fri May 21 22:23:49 2021
ok # [client] nonblocking connect with 1 attempts - Fri May 21 22:23:49 2021
ok # [server] ssl accept handshake done - Fri May 21 22:23:49 2021
# sndbuf=8192 - Fri May 21 22:23:49 2021
ok # [server] received client message - Fri May 21 22:23:49 2021
# $!=Resource temporarily unavailable $SSL_ERROR=SSL wants a write first send=2570 - Fri May 21 22:23:49 2021
# wait for write - Fri May 21 22:23:49 2021
# read 30000 (1 r/w attempts) - Fri May 21 22:23:54 2021
# tcp server socket is NOT ready - Fri May 21 22:24:24 2021
not ok # [server] tcp accept - Fri May 21 22:24:24 2021
# failed to tcp accept: Resource temporarily unavailable - Fri May 21 22:24:24 2021
# fail can_write - Fri May 21 22:24:24 2021
not ok # [client] syswrite - Fri May 21 22:24:24 2021
ok # [client] multiple write attempts - Fri May 21 22:24:24 2021
ok # [client] 30000 bytes send - Fri May 21 22:24:24 2021
# connect in progress - Fri May 21 22:24:24 2021
# claims that socket is already connected - Fri May 21 22:24:24 2021
ok # [client] client tcp connect - Fri May 21 22:24:24 2021
# wrote 9 bytes - Fri May 21 22:24:24 2021
ok # [client] write plain text - Fri May 21 22:24:24 2021
ok # [client] upgrade client to IO::Socket::SSL - Fri May 21 22:24:29 2021
# SSL wants a read first - Fri May 21 22:24:29 2021
# failed to connect:  - Fri May 21 22:24:59 2021
not ok # [client] connected - Fri May 21 22:24:59 2021
# sndbuf=8192 - Fri May 21 22:24:59 2021
# $!=Resource temporarily unavailable $SSL_ERROR=SSL wants a read first send=8190 - Fri May 21 22:24:59 2021
# wait for read - Fri May 21 22:24:59 2021
# fail can_read - Fri May 21 22:25:29 2021
not ok # [client] syswrite - Fri May 21 22:25:29 2021
not ok # [client] multiple write attempts - Fri May 21 22:25:29 2021
not ok # [client] 30000 bytes send - Fri May 21 22:25:29 2021
Failed 11/27 subtests 

Test Summary Report
-------------------
t/modified-nonblock.t (Wstat: 0 Tests: 22 Failed: 6)
  Failed tests:  12-13, 19-22
  Parse errors: Bad plan.  You planned 27 tests but ran 22.
Files=1, Tests=22, 105 wallclock secs ( 0.03 usr  0.00 sys +  0.61 cusr  0.09 csys =  0.73 CPU)
Result: FAIL

[noxxi]

Thanks. It looks like the server closes the socket but the client still waits inside select for writability. In linux the select stops if the socket gets closed by the peer, even if just selected for writability. Does not happen here though. I've changed the timeouts to hopelly deal with this problem and also added more debugging. Please try again and if it still fails send my the output: https://wtools.io/paste-code/b5j9

[jkeenan]

Thanks. It looks like the server closes the socket but the client still waits inside select for writability. In linux the select stops if the socket gets closed by the peer, even if just selected for writability. Does not happen here though. I've changed the timeouts to hopelly deal with this problem and also added more debugging. Please try again and if it still fails send my the output: https://wtools.io/paste-code/b5j9

Some improvement. File runs to completion, but 2 unit tests still fail.

$ diff -w t/nonblock.t t/2nd-modified-nonblock.t 
22a23,24
> my $START = time();
> 
188a191
>       my $sel_server = IO::Select->new($to_server);
190c193
<       if ( $can && ! IO::Select->new($to_server)->$can(30)) {
---
>       if ($can && !$sel_server->$can(15)) {
194c197,198
<       };
---
>       }
> 
259c263,264
<   IO::Select->new( $server )->can_read(30);
---
>   my $can_read = IO::Select->new( $server )->can_read(30);
>   diag("tcp server socket is ".($can_read? "ready" : "NOT ready"));
391,392c396,406
< sub ok { print "ok # [$ID] @_\n"; }
< sub diag { print "# @_\n" }
---
> sub ok   { unshift @_, "ok # "; goto &_out }
> sub diag { unshift @_, "#    "; goto &_out }
> sub _out {
>     my $prefix = shift;
>     printf "%s [%04d.%s:%03d] %s\n",
>   $prefix,
>   time() - $START,
>   $ID,
>   (caller())[2],
>   "@_";
> }

$ bleadprove -vb t/2nd-modified-nonblock.t 
t/2nd-modified-nonblock.t .. 
1..27
ok #  [0000.server:035] Server Initialization
#     [0000.client:065] connect in progress
#     [0000.server:264] tcp server socket is ready
#     [0000.client:075] claims that socket is already connected
ok #  [0000.client:084] client tcp connect
#     [0000.client:108] wrote 9 bytes
ok #  [0000.client:114] write plain text
ok #  [0000.server:266] tcp accept
ok #  [0000.server:283] received plain text
ok #  [0000.server:303] upgrade to_client to IO::Socket::SSL
ok #  [0000.client:133] upgrade client to IO::Socket::SSL
#     [0000.client:141] SSL wants a read first
ok #  [0005.client:152] connected
ok #  [0005.client:156] nonblocking connect with 1 attempts
ok #  [0005.server:325] ssl accept handshake done
#     [0005.client:003] sndbuf=8192
ok #  [0005.server:339] received client message
#     [0005.client:201] $!=Resource temporarily unavailable $SSL_ERROR=SSL wants a write first send=2570
#     [0005.client:204] wait for write
#     [0010.server:384] read 30000 (1 r/w attempts)
#     [0025.client:194] fail can_write
not ok #  [0025.client:236] syswrite
ok #  [0025.client:242] multiple write attempts
ok #  [0025.client:246] 30000 bytes send
#     [0025.client:065] connect in progress
#     [0025.server:264] tcp server socket is ready
#     [0025.client:075] claims that socket is already connected
ok #  [0025.client:084] client tcp connect
#     [0025.client:108] wrote 9 bytes
ok #  [0025.client:114] write plain text
ok #  [0025.server:266] tcp accept
ok #  [0025.server:283] received plain text
ok #  [0025.server:303] upgrade to_client to IO::Socket::SSL
ok #  [0030.client:133] upgrade client to IO::Socket::SSL
#     [0030.client:141] SSL wants a read first
ok #  [0030.client:152] connected
#     [0030.client:003] sndbuf=8192
ok #  [0030.server:325] ssl accept handshake done
ok #  [0030.server:329] nonblocking accept_SSL with 2 attempts
ok #  [0030.server:339] received client message
#     [0030.client:201] $!=Resource temporarily unavailable $SSL_ERROR=SSL wants a write first send=2570
#     [0030.client:204] wait for write
#     [0035.server:384] read 30000 (2 r/w attempts)
#     [0050.client:194] fail can_write
not ok #  [0050.client:236] syswrite
ok #  [0050.client:242] multiple write attempts
ok #  [0050.client:246] 30000 bytes send
Failed 2/27 subtests 

Test Summary Report
-------------------
t/2nd-modified-nonblock.t (Wstat: 0 Tests: 27 Failed: 2)
  Failed tests:  12, 25
Files=1, Tests=27, 51 wallclock secs ( 0.03 usr  0.02 sys +  1.16 cusr  0.12 csys =  1.34 CPU)
Result: FAIL```

[noxxi]

Thanks for the feedback. Hopefully this version will fix the remaining fails: https://wtools.io/paste-code/b5jD

diff --git a/t/nonblock.t b/t/nonblock.t
index ad62799..07097fb 100644
--- a/t/nonblock.t
+++ b/t/nonblock.t
@@ -20,6 +20,8 @@ if ( ! eval "use 5.006; use IO::Select; return 1" ) {
 $|=1;
 print "1..27\n";

+my $START = time();
+
 # first create simple non-blocking tcp-server
 my $ID = 'server';
 my $server = IO::Socket::INET->new(
@@ -186,12 +188,18 @@ if ( $pid == 0 ) {
        WRITE:
        for( my $i=0;$i<50000;$i++ ) {
            my $offset = 0;
+           my $sel_server = IO::Select->new($to_server);
            while (1) {
-               if ( $can && ! IO::Select->new($to_server)->$can(30)) {
-                   diag("fail $can");
-                   print "not ";
+               if ($can && !$sel_server->$can(15)) {
+                   if ( $bytes_send > 30000 ) {
+                       diag("fail $can, but limit reached. Assume connection closed");
+                   } else {
+                       diag("fail $can");
+                       print "not ";
+                   }
                    last WRITE;
-               };
+               }
+
                my $n = syswrite( $to_server,$msg,length($msg)-$offset,$offset );
                if ( !defined($n) ) {
                    diag( "\$!=$! \$SSL_ERROR=$SSL_ERROR send=$bytes_send" );
@@ -256,7 +264,8 @@ if ( $pid == 0 ) {
     foreach my $test ( 'slow','fast' ) {

        # accept a connection
-       IO::Select->new( $server )->can_read(30);
+       my $can_read = IO::Select->new( $server )->can_read(30);
+       diag("tcp server socket is ".($can_read? "ready" : "NOT ready"));
        my $from_client = $server->accept or print "not ";
        ok( "tcp accept" );
        $from_client || do {
@@ -388,5 +397,14 @@ exit;

-sub ok { print "ok # [$ID] @_\n"; }
-sub diag { print "# @_\n" }
+sub ok   { unshift @_, "ok # "; goto &_out }
+sub diag { unshift @_, "#    "; goto &_out }
+sub _out {
+    my $prefix = shift;
+    printf "%s [%04d.%s:%03d] %s\n",
+       $prefix,
+       time() - $START,
+       $ID,
+       (caller())[2],
+       "@_";
+}

[jkeenan]

Yes!

$ diff -w t/nonblock.t t/3rd-modified-nonblock.t
22a23,24
> my $START = time();
> 
188a191
>       my $sel_server = IO::Select->new($to_server);
190c193,196
<       if ( $can && ! IO::Select->new($to_server)->$can(30)) {
---
>       if ($can && !$sel_server->$can(15)) {
>           if ( $bytes_send > 30000 ) {
>           diag("fail $can, but limit reached. Assume connection closed");
>           } else {
192a199
>           }
194c201,202
<       };
---
>       }
> 
259c267,268
<   IO::Select->new( $server )->can_read(30);
---
>   my $can_read = IO::Select->new( $server )->can_read(30);
>   diag("tcp server socket is ".($can_read? "ready" : "NOT ready"));
391,392c400,410
< sub ok { print "ok # [$ID] @_\n"; }
< sub diag { print "# @_\n" }
---
> sub ok   { unshift @_, "ok # "; goto &_out }
> sub diag { unshift @_, "#    "; goto &_out }
> sub _out {
>     my $prefix = shift;
>     printf "%s [%04d.%s:%03d] %s\n",
>   $prefix,
>   time() - $START,
>   $ID,
>   (caller())[2],
>   "@_";
> }

$ bleadprove -vb t/3rd-modified-nonblock.t
t/3rd-modified-nonblock.t .. 
1..27
ok #  [0000.server:035] Server Initialization
#     [0000.client:065] connect in progress
#     [0000.server:268] tcp server socket is ready
#     [0000.client:075] claims that socket is already connected
ok #  [0000.client:084] client tcp connect
#     [0000.client:108] wrote 9 bytes
ok #  [0000.client:114] write plain text
ok #  [0000.server:270] tcp accept
ok #  [0000.server:287] received plain text
ok #  [0000.server:307] upgrade to_client to IO::Socket::SSL
ok #  [0000.client:133] upgrade client to IO::Socket::SSL
#     [0000.client:141] SSL wants a read first
ok #  [0005.client:152] connected
ok #  [0005.client:156] nonblocking connect with 1 attempts
ok #  [0005.server:329] ssl accept handshake done
#     [0005.client:003] sndbuf=8192
ok #  [0005.server:343] received client message
#     [0005.client:205] $!=Resource temporarily unavailable $SSL_ERROR=SSL wants a write first send=2570
#     [0005.client:208] wait for write
#     [0010.server:388] read 30000 (1 r/w attempts)
#     [0025.client:194] fail can_write, but limit reached. Assume connection closed
ok #  [0025.client:240] syswrite
ok #  [0025.client:246] multiple write attempts
ok #  [0025.client:250] 30000 bytes send
#     [0025.client:065] connect in progress
#     [0025.server:268] tcp server socket is ready
#     [0025.client:075] claims that socket is already connected
ok #  [0025.client:084] client tcp connect
ok #  [0025.server:270] tcp accept
ok #  [0025.server:287] received plain text
#     [0025.client:108] wrote 9 bytes
ok #  [0025.client:114] write plain text
ok #  [0025.server:307] upgrade to_client to IO::Socket::SSL
ok #  [0030.client:133] upgrade client to IO::Socket::SSL
#     [0030.client:141] SSL wants a read first
ok #  [0030.client:152] connected
#     [0030.client:003] sndbuf=8192
ok #  [0030.server:329] ssl accept handshake done
ok #  [0030.server:333] nonblocking accept_SSL with 2 attempts
ok #  [0030.server:343] received client message
#     [0030.client:205] $!=Resource temporarily unavailable $SSL_ERROR=SSL wants a write first send=2570
#     [0030.client:208] wait for write
#     [0035.server:388] read 30000 (2 r/w attempts)
#     [0050.client:194] fail can_write, but limit reached. Assume connection closed
ok #  [0050.client:240] syswrite
ok #  [0050.client:246] multiple write attempts
ok #  [0050.client:250] 30000 bytes send
ok
All tests successful.
Files=1, Tests=27, 50 wallclock secs ( 0.05 usr  0.01 sys +  1.13 cusr  0.19 csys =  1.38 CPU)
Result: PASS

Please let me know when a new CPAN version gets released. Thanks for taking the time to investigate this.

[noxxi]

The new release 2.071 is out. It just contains the fixes to t/nonblock.t