shiny new ssl appears broken?

[exodist]

I am sorry for the lack of details, I am not able to share much and I fear this report will not be very useful. Miyagawa asked me to write it though

App: mod_perl/cgi app converted to plack using WrapCGI (not using execute flag)

• App works fine when run via Plack::Handler::Apache2 in apache+mod_perl.
• App works fine in non-ssl mode (requires hacking app to not require ssl)

When we enable starman's ssl we seem to have an issue where the page never fully loads.

• How much of the page loads seems to be random.
• Problem occurs on both the ssl and non-ssl ports.
• The Debug middleware fails to inject itself into the page, works fine w/o the ssl

I am afraid I cannot share the app or configuration that produces this issue, and I have not created a small sample test case yet, if I manage to do it I will attach it. According to Miyagawa others have mentioned the same issue.

[miyagawa]

cc @ap @siracusa

[siracusa]

I've seen the same thing. It was hard to track down, since various browsers handle this bug in different, terrible ways, ranging from a browser-native "totally couldn't load this page, dude" error to a reported JavaScript parse error. As far as I can tell, the problem is that the first request (for the page) works, but the next request (usually for a stylesheet or JavaScript file) fails. The server doesn't appear to send back any data at all. I'm not even sure if it sends back headers.

[andfarm]

I've been able to reproduce the issue with this tiny PSGI:

use strict;
use Plack::Request;

my $app = sub {
    my $req = Plack::Request->new(@_);
    my $res = $req->new_response(200);
    $res->body("x" x ($req->param("length") || 128));
    $res->finalize();
};

Any request with a length parameter greater than 16380 (!) fails, with an error message pointing to an issue with chunked encoding, e.g.

curl: (18) transfer closed with outstanding read data remaining

or, in some exceptional cases:

curl: (56) Problem (3) in the Chunked-Encoded data

[kazeburo]

It seems to not able to write content of 16KB or more in a single syswrite. works with this patch.

diff --git a/lib/Starman/Server.pm b/lib/Starman/Server.pm
index 4bed803..0e0efc1 100644
--- a/lib/Starman/Server.pm
+++ b/lib/Starman/Server.pm
@@ -528,7 +528,11 @@ sub _finalize_response {
                 return unless $len;
                 $buffer = sprintf( "%x", $len ) . $CRLF . $buffer . $CRLF;
             }
-            syswrite $conn, $buffer;
+            while ( length $buffer ) {
+                my $len = syswrite $conn, $buffer;
+                die "write error: $!" if ! defined $len;
+                substr( $buffer, 0, $len, '');
+            }
             DEBUG && warn "[$$] Wrote " . length($buffer) . " bytes\n";
         });

@@ -542,7 +546,11 @@ sub _finalize_response {
                     return unless $len;
                     $buffer = sprintf( "%x", $len ) . $CRLF . $buffer . $CRLF;
                 }
-                syswrite $conn, $buffer;
+                while ( length $buffer ) {
+                    my $len = syswrite $conn, $buffer;
+                    die "write error: $!" if ! defined $len;
+                    substr( $buffer, 0, $len, '');
+                }
                 DEBUG && warn "[$$] Wrote " . length($buffer) . " bytes\n";
             },
             close => sub {

[miyagawa]

@kazeburo good catch. Can you make a pull request?

[miyagawa]

Merged with 792e87c. @andfarm @exodist can you test with the git version?

[siracusa]

Don't you have to check if $! is EINTR (i.e., use Errno and check $!{EINTR}) and retry (and possibly other weird stuff) after a failed syswrite()?

[exodist]

Tests fail on current git checkout, giving it a try anyway....

[exodist]

Seems to be working fine. Tests need some work though:

Test Summary Report

t/ssl.t (Wstat: 512 Tests: 2 Failed: 2) Failed tests: 1-2 Non-zero exit status: 2 t/ssl_largebody.t (Wstat: 512 Tests: 2 Failed: 2) Failed tests: 1-2 Non-zero exit status: 2

[miyagawa]

What's the actu rest failure lines? Post the failing message not the summary.  — Sent from Mailbox for iPhone

On Tue, Aug 13, 2013 at 7:34 AM, Chad Granum notifications@github.com wrote:

Seems to be working fine. Tests need some work though:

Test Summary Report

t/ssl.t (Wstat: 512 Tests: 2 Failed: 2) Failed tests: 1-2 Non-zero exit status: 2 t/ssl_largebody.t (Wstat: 512 Tests: 2 Failed: 2) Failed tests: 1-2

Non-zero exit status: 2

Reply to this email directly or view it on GitHub: https://github.com/miyagawa/Starman/issues/78#issuecomment-22568983

[exodist]

prove -Ilib t/ssl.t t/ssl_largebody.t > temp 2>&1

2013/08/13-10:21:39 Starman::Server (type Net::Server::PreFork) starting! pid(14048)
Resolved [localhost]:50269 to [127.0.0.1]:50269, IPv4
Binding to SSL port 50269 on host 127.0.0.1 with IPv4
Setting gid to "1000 1000 1000 1003"
Could not finalize SSL connection with client handle (SSL connect accept failed because of handshake problems)
Could not finalize SSL connection with client handle (SSL connect accept failed because of handshake problems error:14094418:SSL routines:SSL3_READ_BYTES:tlsv1 alert unknown ca)
2013/08/13-10:21:39 Server closing!

#   Failed test 'HTTPS connection succeeded'
#   at t/ssl.t line 47. 
# 500 Can't connect to localhost:50269 (certificate verify failed)

#   Failed test '... and URL scheme is reported correctly'
#   at t/ssl.t line 49. 
#          got: 'Can't connect to localhost:50269 (certificate verify failed)
#   
# LWP::Protocol::https::Socket: SSL connect attempt failed with unknown error error:14090086:SSL routines:SSL3_GET_SERVER_CERTIFICATE:certificate verify failed at /home/cgranum/perl5/lib/perl5/LWP/Protocol/http.pm line 51.
# ' 
#     expected: 'https'
# Looks like you failed 2 tests of 2.
t/ssl.t ............
Dubious, test returned 2 (wstat 512, 0x200)
Failed 2/2 subtests
2013/08/13-10:21:39 Starman::Server (type Net::Server::PreFork) starting! pid(14057)
Resolved [localhost]:50593 to [127.0.0.1]:50593, IPv4
Binding to SSL port 50593 on host 127.0.0.1 with IPv4
Setting gid to "1000 1000 1000 1003"
Could not finalize SSL connection with client handle (SSL connect accept failed because of handshake problems)
Could not finalize SSL connection with client handle (SSL connect accept failed because of handshake problems error:14094418:SSL routines:SSL3_READ_BYTES:tlsv1 alert unknown ca)
2013/08/13-10:21:39 Server closing!

#   Failed test 'HTTPS connection succeeded'
#   at t/ssl_largebody.t line 50. 
# 500 Can't connect to localhost:50593 (certificate verify failed)

#   Failed test at t/ssl_largebody.t line 52. 
#          got: 'Can't connect to localhost:50593 (certificate verify failed)
#   
# LWP::Protocol::https::Socket: SSL connect attempt failed with unknown error error:14090086:SSL routines:SSL3_GET_SERVER_CERTIFICATE:certificate verify failed at /home/cgranum/perl5/lib/perl5/LWP/Protocol/http.pm line 51.
# ' 
#     expected: '0' 
# Looks like you failed 2 tests of 2.
t/ssl_largebody.t ..
Dubious, test returned 2 (wstat 512, 0x200)
Failed 2/2 subtests

Test Summary Report
-------------------
t/ssl.t          (Wstat: 512 Tests: 2 Failed: 2)
  Failed tests:  1-2 
  Non-zero exit status: 2
t/ssl_largebody.t (Wstat: 512 Tests: 2 Failed: 2)
  Failed tests:  1-2 
  Non-zero exit status: 2
Files=2, Tests=4,  1 wallclock secs ( 0.03 usr  0.00 sys +  0.42 cusr  0.06 csys =  0.51 CPU)
Result: FAIL

[miyagawa]

Thanks but it looks like a failure on ssl in general not the new test. Does the test pass on CPAN release?

Also, you said it seems to work fine. When I said testing I meant to test your app with the browser. Does that work fine/better?

[exodist]

Yes, my app works fine, that is what I was talking about. As for the unit-test stuff, I can't make that pass on any of my systems.

[exodist]

scratch my last comment, I did just make it work on one of my systems.

[miyagawa]

CPAN latest has ssl.t in it. Does it pass?

[exodist]

The latests cpan release has 9 passes and 1 failure: http://www.cpantesters.org/cpan/report/710f0966-0387-11e3-b7f8-83be55995b46

This failure is also ssl.t, but the errors appear different.

[miyagawa]

I was talking about your environment, not CPAN testers in general.

Tatsuhiko Miyagawa

[exodist]

I am no longer sure what you are asking. I suspect there are issues with the 2 work systems where the tests are failing. When I use my laptop the tests pass, both the cpan version and the latest git. However on the 2 unrelated work systems neither the latest cpan, not the latest git will pass. However yesterday the latest cpan did pass on both, so something seems to have changed on both unrelated system overnight.

I do not think these test failures I saw should hold up releasing/using this patch. If a new release resultsin cpantesters issues we will know we have a problem to solve. If cpantester do not find any issues I will know it is just me and won't bother everyone else with it.

[miyagawa]

I am no longer sure what you are asking.

you said ssl.t and ssl_largebody.t was failing on git checkout. I was asking if the ssl.t in CPAN release was failing as well, because that way I can tell if it is specific to git checkout or your environment in general.

[miyagawa]

@siracusa good point.

@kazeburo Can you add a check for EINTR along these lines? https://github.com/plack/Plack/blob/master/lib/HTTP/Server/PSGI.pm#L251

[siracusa]

@miyagawa I added checks and sent a pull request.

[miyagawa]

@siracusa perfect :+1:

[kazeburo]

@siracusa Thank you!

[miyagawa]

released 0.4005-TRIAL

[ap]

I finally hit this problem too (pure chance that I didn’t see this in my SSL patch testing) and the patch here fixes the problem for me. @kazeburo++ @siracusa++

[miyagawa]

0.4006 released