serf-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From <b...@qqmail.nl>
Subject RE: Spin when fetching resources over SSL
Date Sat, 24 Oct 2015 09:40:19 GMT
Wild guess: could this be related to certificate checking or something?

Just a few days ago I had a problem connecting to https://twitter.com, using trunk in a specific
http/2 related mode.

After quite a bit of printf style debugging (and then partially removing that as it affected
timing) I found that Serf sometimes tried to perform socket operations (such as reading) on
a not yet connected socket. On Windows this returns a specific error, but I could imagine
that a not connected socket might have other problems on other platforms.
(And the faster your CPU, the more likely you see this problem... as in general the ssl engine
needs to initialize within this timeframe too)

I solved this problem on trunk, but if not really necessay I'd rather not backport this fix
as it affects timing on quite a bit of initialization code... which might trigger bugs in
other code that relies on something without knowing.

Bert

Sent from Mail for Windows 10



From: Jeff Kaufman
Sent: vrijdag 23 oktober 2015 15:17
To: bert@qqmail.nl
Cc: Jeff Kaufman;dev@serf.apache.org;Jeffrey Crowell;Maksim Orlovich
Subject: Re: Spin when fetching resources over SSL


Yes 70014 is APR_EOF on my platform too.

It's weird that we're spinning, but it's also weird we're getting EOF
early in the process when setting up an ssl connection, no? (Every
time, every ssl server, not just occasionally.)

I'll check out the 1.3.x branch.

On Fri, Oct 23, 2015 at 9:07 AM,  <bert@qqmail.nl> wrote:
> If your error codes are the same as on my platform (I'm on Windows) 70014 stands for
APR_EOF. In that case it shouldn't loop further.
>
> The logs you provide don't have anything else that stands out for me. If you can post
the full log on some url I'm willing to check if I see something else.
>
> You might want to check the 1.3.x branch as it has some further fixes we hope to release
'soon'.
>
> Trunk is a bit further away from release, but contains even more ssl code cleanups. Test
input on that codebase is very welcome. (Please ignore the current HTTP/2 work for now. That
is currently unexposed in the higher layers)
>
> Bert
>
> Sent from Mail for Windows 10
>
>
>
> From: Jeff Kaufman
> Sent: donderdag 22 oktober 2015 19:23
> To: dev@serf.apache.org
> Cc: Jeffrey Crowell;Maksim Orlovich
> Subject: Spin when fetching resources over SSL
>
>
> The mod_pagespeed project uses serf for fetching, and I'm currently
> updating our dependency from 1.1.0 to the latest stable, 1.3.8.  It
> works fine for fetching http, but when I try to fetch anything over
> https it spins in ssl_buckets.c.
>
> I turned on verbose logging in serf_private and it seems to be looping in:
>
>     ssl_buckets.c: ssl_decrypt: begin 8000
>     ssl_buckets.c: bio_bucket_read called for 5 bytes
>     ssl_buckets.c: bio_bucket_read waiting: (8 1 9)
>     ssl_buckets.c: bio_bucket_read received 0 bytes (70014)
>     ssl_buckets.c: SSL_connect:error in SSLv3 read server session ticket A
>     ssl_buckets.c: ssl_decrypt: 11 0 9
>
> Have there been any changes to the API since 1.1.0, so that we need to
> be doing something different to set up ssl with serf?
>
> Here's what it prints before going into the spin:
>
> outgoing.c: created connection 0x3d6c8638
> outgoing.c: created socket for conn 0x3d6c8638, status 0
> [l:\200\305\337<\212^?:51912 r:2607:f8b0:4005:801::2004:443] outgoing.c: connec\
> ted socket for conn 0x3d6c8638, status 115
> ssl_buckets.c: ssl_encrypt: begin 8000
> ssl_buckets.c: ssl_encrypt: bucket read 96 bytes; status 11
> ssl_buckets.c: ---
> GET / HTTP/1.1^M
> Host: www.google.com^M
> User-Agent: Serf/1.3.8 mod_pagespeed/99,99,99,99-99999^M
> ^M
>
> -(96)-
> ssl_buckets.c: SSL_connect:before connect initialization
> ssl_buckets.c: bio_bucket_write called for 190 bytes
> ssl_buckets.c: SSL_connect:SSLv3 write client hello A
> ssl_buckets.c: bio_bucket_read called for 5 bytes
> ssl_buckets.c: bio_bucket_read received 0 bytes (70014)
> ssl_buckets.c: SSL_connect:error in SSLv3 read server hello A
> ssl_buckets.c: ssl_encrypt: SSL write: -1
> ssl_buckets.c: ssl_encrypt: SSL write error: 2
> ssl_buckets.c: ssl_encrypt: SSL write error: 120103 0
> ssl_buckets.c: ssl_encrypt read agg: 120103 70014 11 190
> ssl_buckets.c: ssl_encrypt finished: 120103 190 (8 1 9)
> [l::51912 r:2607:f8b0:4005:801::2004:443] outgoing.c: --- socket_sendv:
> ^V^C^A-(190)-
> ssl_buckets.c: ssl_decrypt: begin 8000
> ssl_buckets.c: bio_bucket_read called for 5 bytes
> ssl_buckets.c: bio_bucket_read waiting: (8 1 9)
> ssl_buckets.c: bio_bucket_read received 0 bytes (70014)
> ssl_buckets.c: SSL_connect:error in SSLv3 read server hello A
> [l: ^Q:51912 r:2607:f8b0:4005:801::2004:443] socket_buckets.c: --- socket_recv:
> ^V^C^C
> -(3505)-
> ssl_buckets.c: ssl_decrypt: read 3505 bytes (8000); status: 0
> ssl_buckets.c: bio_bucket_read called for 5 bytes
> ssl_buckets.c: bio_bucket_read waiting: (8 1 9)
> ssl_buckets.c: bio_bucket_read received 5 bytes (0)
> ssl_buckets.c: bio_bucket_read called for 67 bytes
> ssl_buckets.c: bio_bucket_read received 67 bytes (0)
> ssl_buckets.c: SSL_connect:SSLv3 read server hello A
> ssl_buckets.c: bio_bucket_read called for 5 bytes
> ssl_buckets.c: bio_bucket_read received 5 bytes (0)
> ssl_buckets.c: bio_bucket_read called for 3081 bytes
> ssl_buckets.c: bio_bucket_read received 3081 bytes (0)
> ssl_buckets.c: SSL_connect:SSLv3 read server certificate A
> ssl_buckets.c: SSL_connect:unknown state
> ssl_buckets.c: bio_bucket_read called for 5 bytes
> ssl_buckets.c: bio_bucket_read received 5 bytes (0)
> ssl_buckets.c: bio_bucket_read called for 333 bytes
> ssl_buckets.c: bio_bucket_read received 333 bytes (0)
> ssl_buckets.c: SSL_connect:SSLv3 read server key exchange A
> ssl_buckets.c: bio_bucket_read called for 5 bytes
> ssl_buckets.c: bio_bucket_read received 5 bytes (0)
> ssl_buckets.c: bio_bucket_read called for 4 bytes
> ssl_buckets.c: bio_bucket_read received 4 bytes (70014)
> ssl_buckets.c: SSL_connect:SSLv3 read server done A
> ssl_buckets.c: SSL_connect:SSLv3 write client key exchange A
> ssl_buckets.c: SSL_connect:SSLv3 write change cipher spec A
> ssl_buckets.c: SSL_connect:SSLv3 write finished A
> ssl_buckets.c: bio_bucket_write called for 126 bytes
> ssl_buckets.c: bio_bucket_write waiting: (0 0 0)
> ssl_buckets.c: SSL_connect:SSLv3 flush data
> ssl_buckets.c: bio_bucket_read called for 5 bytes
> ssl_buckets.c: bio_bucket_read received 0 bytes (70014)
> ssl_buckets.c: SSL_connect:error in SSLv3 read server session ticket A
> ssl_buckets.c: ssl_decrypt: 11 0 9
>
> [now the block I pulled out above repeats forever]
>
>



Mime
  • Unnamed multipart/alternative (inline, None, 0 bytes)
View raw message