Bug #80591 for IO-Socket-SSL: Doing lf crlf translation ?

Fri Nov 02 17:31:01 2012 DOUGW [...] cpan.org - Ticket created

Subject:

Doing lf crlf translation ?

I am not sure which library to blame yet, because I am only using this library indirectly through LWP::UserAgent. But when downloading a zip file from a https:// URL in a post request, there are extraneous crlf characters in the result (it is a binary zip file so it ends up corrupted). If I set Net::HTTPS to use Net::SSL instead of IO::Socket::SSL (or if I delete the IO::Socket::SSL library), then the file is downloaded without issue. I don't know if or which library layer might be doing PerlIO layer or other conversions, so I'll start by reporting the problem here :-)

Fri Nov 02 18:09:53 2012 Steffen_Ullrich [...] genua.de - Correspondence added

Show quoted text

> > I don't know if or which library layer might be doing PerlIO layer or > other conversions, so I'll start by reporting the problem here :-)

Interesting problem. Do you have a sample program to reproduce the problem?

Fri Nov 02 18:09:54 2012 The RT System itself - Status changed from 'new' to 'open'

Fri Nov 02 18:21:01 2012 DOUGW [...] cpan.org - Correspondence added

On Fri Nov 02 18:09:53 2012, SULLR wrote: Show quoted text

>

> > > > I don't know if or which library layer might be doing PerlIO layer or > > other conversions, so I'll start by reporting the problem here :-)

> > Interesting problem. > Do you have a sample program to reproduce the problem?

Will try to come up w/an example without giving out user/passwords...should also mention this is on Unix (solaris), so is not a Windows issue.

Mon Nov 05 10:31:55 2012 DOUGW [...] cpan.org - Correspondence added

On Fri Nov 02 18:21:01 2012, DOUGW wrote: Show quoted text

> > Will try to come up w/an example

I noticed that the file differences started occurring about 8k into the file, so I am posting a 17k zip file, then will shortly post a download script, and see if the problem occurs.

Subject:

test.zip

Download test.zip
application/zip 16.9k

Message body not shown because it is not plain text.

Mon Nov 05 10:38:04 2012 DOUGW [...] cpan.org - Correspondence added

On Mon Nov 05 10:31:55 2012, DOUGW wrote: Show quoted text

> On Fri Nov 02 18:21:01 2012, DOUGW wrote:

> > > > Will try to come up w/an example

>

Could not reproduce the example that way...will try further.

Mon Nov 05 12:31:24 2012 DOUGW [...] cpan.org - Correspondence added

On Mon Nov 05 10:38:04 2012, DOUGW wrote: Show quoted text

> On Mon Nov 05 10:31:55 2012, DOUGW wrote:

> > On Fri Nov 02 18:21:01 2012, DOUGW wrote:

> > > > > > Will try to come up w/an example

> >

> Could not reproduce the example that way...will try further.

I have determined that it is some sort of chunking problem. In the problem file, about every 8k, there is a cr/lf, and then 1ff8 (chunk size in hex) with a cr/lf. Don't yet know why Net::SSL works ok, and IO::Socket::SSL does not.

Mon Nov 05 14:37:24 2012 Steffen_Ullrich [...] genua.de - Correspondence added

Show quoted text

> > Could not reproduce the example that way...will try further.

> > I have determined that it is some sort of chunking problem. In the > problem file, about every 8k, there is a cr/lf, and then 1ff8 (chunk > size in hex) with a cr/lf. > > Don't yet know why Net::SSL works ok, and IO::Socket::SSL does not.

I see only one major difference between Net::SSL and IO::Socket::SSL (apart from making IO::Socket::SSL more certificate checks): recent IO::Socket::SSL versions support SNI and enable it per default, e.g. for servers where multiple SSL hosts are behind the same IP address it will specify the intended sender. Net::SSL does not support this extension. If you now have a server which sends different data depending on the hostname given by SNI you will see different behavior when using Net::SSL. To disable SNI you might do: my $ua = LWP::UserAgent->new( ssl_opts => { SSL_hostname => '' }); If this does not help it would be helpful if the same file is accessable over plain http too and you can provide a tcpdump of the http connection done with LWP.

Mon Nov 05 17:04:33 2012 DOUGW [...] cpan.org - Correspondence added

On Mon Nov 05 14:37:24 2012, SULLR wrote: Show quoted text

> > If this does not help it would be helpful if the same file is > accessable over plain http too and you can provide a tcpdump > of the http connection done with LWP.

Nope, that didn't help. And the file is not available over http. But even worse, when I set breakpoints in the perl debugger, the problem goes away. I put in some debug code in the read loop of LWP::Protocol::http, writing the buffer from every read_entity_body() to a separate file. The first file is 4096 bytes, the second is 4088, then the third is a 2-byte crlf, and the fourth is 1ff8<crlf>, and so on (the third and fourth sets of data should be consumed and not returned from within read_entity_body). The chunk sizes are being returned by read_entity_body(), BUT, if I set a breakpoint in that loop, the crlf and chunk sizes are not returned from read_entity_body and written to my debug files. So I don't know if this is an XS code issue or mucking with $_ (which HTTP::Methods does a lot of) issue.

Mon Nov 05 19:09:48 2012 DOUGW [...] cpan.org - Correspondence added

On Mon Nov 05 17:04:33 2012, DOUGW wrote: Show quoted text

> > So I don't know if this is an XS code issue or mucking with $_ (which > HTTP::Methods does a lot of) issue.

I have trapped and echoed the results of the $read_func->() call in generic_read(), and sometimes it returns nothing when it should return 4k bytes or so (unless I have a debug break point and run it in the debugger). I will probably have to (re)compile OpenSSL and Net::SSLeay if I want to go further with this, but I don't think the problem is this library, and it has gone beyond my tuits anyway... Thanks.

Tue Nov 06 03:13:01 2012 Steffen_Ullrich [...] genua.de - Correspondence added

Show quoted text

> I put in some debug code in the read loop of LWP::Protocol::http, > writing the buffer from every read_entity_body() to a separate file. The > first file is 4096 bytes, the second is 4088, then the third is a 2-byte > crlf, and the fourth is 1ff8<crlf>, and so on (the third and fourth sets > of data should be consumed and not returned from within > read_entity_body). The chunk sizes are being returned by > read_entity_body(), BUT, if I set a breakpoint in that loop, the crlf > and chunk sizes are not returned from read_entity_body and written to my > debug files.

Another difference between IO::Socket::SSL and Net::SSL is, that IO::Socket::SSL supports non-blocking sockets, while Net::SSL has problems with it. Thus there is code in Net::HTTPS to make the blocking method of Net::SSL do nothing. And I think non-blocking is used to handle timeouts. I would suggest, that you put debugging code LWP::Protocol::http::SocketMethods::sysread, to see what gets read from the socket and in which chunks, before all these processing is done inside HTTP::Methods.

Tue Nov 06 12:16:54 2012 DOUGW [...] cpan.org - Correspondence added

On Tue Nov 06 03:13:01 2012, SULLR wrote: Show quoted text

> > I would suggest, that you put debugging code > LWP::Protocol::http::SocketMethods::sysread,

That method is not called. The main readloop is in the anon sub that is in the collect() call in LWP::Protocol::http::request(). There, read_entity_body() is called, which goes to Net::HTTP::Methods::read_entity_body. From there, my_read() is called, and in my_read(), the sysread() calls IO::Socket::SSL::sysread(). If I put a 'sleep 1' around the read_entity_body() loop, everything works ok (though slow), so it does seem to be a blocking issue (should probably be calling select() to block somewhere but it's not).

Tue Nov 06 12:33:28 2012 DOUGW [...] cpan.org - Correspondence added

On Tue Nov 06 12:16:54 2012, DOUGW wrote: Show quoted text

> > If I put a 'sleep 1' around the read_entity_body() loop, everything > works ok (though slow), so it does seem to be a blocking issue (should > probably be calling select() to block somewhere but it's not).

I'm guessing at that since LWP::Protocol::http::SocketMethods::sysread() does call select() to block.

Tue Nov 06 12:42:11 2012 DOUGW [...] cpan.org - Correspondence added

On Tue Nov 06 12:33:28 2012, DOUGW wrote: Show quoted text

> On Tue Nov 06 12:16:54 2012, DOUGW wrote:

> > > > If I put a 'sleep 1' around the read_entity_body() loop, everything > > works ok (though slow), so it does seem to be a blocking issue (should > > probably be calling select() to block somewhere but it's not).

Or, if I unconditionally set '*blocking = sub {}' in Net::HTTPS (not just for Net::SSL), it all works ok.

Tue Nov 06 15:15:22 2012 Steffen_Ullrich [...] genua.de - Correspondence added

Show quoted text

> Or, if I unconditionally set '*blocking = sub {}' in Net::HTTPS (not > just for Net::SSL), it all works ok.

I think I've tracked the issue down to yet unreported bug in chunked handling in Net::HTTP::Methods. For Bug description and patch see https://rt.cpan.org/Ticket/Display.html?id=80670 . Because the bug itself is not in IO::Socket::SSL I close the issue here as rejected. Regards, Steffen

Tue Nov 06 15:15:49 2012 Steffen_Ullrich [...] genua.de - Status changed from 'open' to 'rejected'