Locating connection reset issue / h2 vs http/1.1

[Guillaume Quintard]

Hi,

Have you activated h2 support in Varnish? (it's not on by default)

Cheers,

-- 
Guillaume Quintard


On Thu, Jan 31, 2019 at 6:22 AM <info+varnish at shee.org> wrote:

> Hi all,
>
> I have following stack: hitch-1.5 - varnish-5.2.0 - httpd-2.2/2.4
>
> On a high traffic node I am observing a lot of "Socket error: Connection
> reset by peer" log entries coming from hitch.
>
> I am trying to locate the cause of the issue (hitch or varnish site).
>
> So far I can say; that disabling h2 on hitch the "Connection resets"
> doesn't appear anymore.
>
> Does this have to do with varnish-5.2.'s h2 implementation?
>
> Thanks
> Leon
>
>
> Jan 30 19:02:37 srv-s01 hitch[4006]: ww.xx.yy.zz:59395 :0 10:11 proxy
> connect
> Jan 30 19:02:37 srv-s01 hitch[4006]: ww.xx.yy.zz:59395 :0 10:11 ssl
> handshake start
> Jan 30 19:02:37 srv-s01 hitch[4006]: ww.xx.yy.zz:59395 :0 10:11 ssl client
> handshake revents=1
> Jan 30 19:02:37 srv-s01 hitch[4006]: ww.xx.yy.zz:59395 :0 10:11 ssl client
> handshake err=SSL_ERROR_WANT_READ
> Jan 30 19:02:37 srv-s01 hitch[4006]: ww.xx.yy.zz:59395 :0 10:11 ssl client
> handshake revents=1
> Jan 30 19:02:37 srv-s01 hitch[4006]: ww.xx.yy.zz:59395 :0 10:11 NPN/ALPN
> protocol: h2
> Jan 30 19:02:37 srv-s01 hitch[4006]: ww.xx.yy.zz:59395 :0 10:11 ssl end
> handshake
> Jan 30 19:02:37 srv-s01 hitch[4006]: ww.xx.yy.zz:59395 :42884 10:11
> backend connected
> Jan 30 19:02:39 srv-s01 hitch[4006]: {backend} Socket error: Connection
> reset by peer
> Jan 30 19:02:39 srv-s01 hitch[4006]: ww.xx.yy.zz:59395 :42884 10:11 proxy
> shutdown req=SHUTDOWN_CLEAR
> Jan 30 19:02:39 srv-s01 hitch[4006]: {backend} Socket error: Broken pipe
> Jan 30 19:02:39 srv-s01 hitch[4006]: ww.xx.yy.zz:59395 :42884 10:11 proxy
> shutdown req=SHUTDOWN_CLEAR
> Jan 30 19:02:39 srv-s01 hitch[4006]: ww.xx.yy.zz:59399 :0 10:11 proxy
> connect
> Jan 30 19:02:39 srv-s01 hitch[4006]: ww.xx.yy.zz:59399 :0 10:11 ssl
> handshake start
> Jan 30 19:02:39 srv-s01 hitch[4006]: ww.xx.yy.zz:59399 :0 10:11 ssl client
> handshake revents=1
> Jan 30 19:02:39 srv-s01 hitch[4006]: ww.xx.yy.zz:59399 :0 10:11 ssl client
> handshake err=SSL_ERROR_WANT_READ
> Jan 30 19:02:39 srv-s01 hitch[4006]: ww.xx.yy.zz:59399 :0 10:11 ssl client
> handshake revents=1
> Jan 30 19:02:39 srv-s01 hitch[4006]: ww.xx.yy.zz:59399 :0 10:11 NPN/ALPN
> protocol: h2
> Jan 30 19:02:39 srv-s01 hitch[4006]: ww.xx.yy.zz:59399 :0 10:11 ssl end
> handshake
> Jan 30 19:02:39 srv-s01 hitch[4006]: ww.xx.yy.zz:59399 :42922 10:11
> backend connected
> Jan 30 19:02:40 srv-s01 hitch[4006]: {backend} Socket error: Connection
> reset by peer
> Jan 30 19:02:40 srv-s01 hitch[4006]: ww.xx.yy.zz:59399 :42922 10:11 proxy
> shutdown req=SHUTDOWN_CLEAR
> Jan 30 19:02:40 srv-s01 hitch[4006]: ww.xx.yy.zz:59399 :42922 10:11 proxy
> shutdown req=SHUTDOWN_HARD
> Jan 30 19:02:40 srv-s01 hitch[4006]: ww.xx.yy.zz:59413 :0 10:11 proxy
> connect
> Jan 30 19:02:40 srv-s01 hitch[4006]: ww.xx.yy.zz:59413 :0 10:11 ssl
> handshake start
> Jan 30 19:02:40 srv-s01 hitch[4006]: ww.xx.yy.zz:59413 :0 10:11 ssl client
> handshake revents=1
> Jan 30 19:02:40 srv-s01 hitch[4006]: ww.xx.yy.zz:59413 :0 10:11 ssl client
> handshake err=SSL_ERROR_WANT_READ
> Jan 30 19:02:40 srv-s01 hitch[4006]: ww.xx.yy.zz:59413 :0 10:11 ssl client
> handshake revents=1
> Jan 30 19:02:40 srv-s01 hitch[4006]: ww.xx.yy.zz:59413 :0 10:11 NPN/ALPN
> protocol: h2
> Jan 30 19:02:40 srv-s01 hitch[4006]: ww.xx.yy.zz:59413 :0 10:11 ssl end
> handshake
> Jan 30 19:02:40 srv-s01 hitch[4006]: ww.xx.yy.zz:59413 :42924 10:11
> backend connected
> Jan 30 19:03:41 srv-s01 hitch[4006]: ww.xx.yy.zz:59418 :0 12:13 proxy
> connect
> Jan 30 19:03:41 srv-s01 hitch[4006]: ww.xx.yy.zz:59418 :0 12:13 ssl
> handshake start
> Jan 30 19:03:41 srv-s01 hitch[4006]: ww.xx.yy.zz:59418 :0 12:13 ssl client
> handshake revents=1
> Jan 30 19:03:41 srv-s01 hitch[4006]: ww.xx.yy.zz:59418 :0 12:13 ssl client
> handshake err=SSL_ERROR_WANT_READ
> Jan 30 19:03:41 srv-s01 hitch[4006]: ww.xx.yy.zz:59418 :0 12:13 ssl client
> handshake revents=1
> Jan 30 19:03:41 srv-s01 hitch[4006]: ww.xx.yy.zz:59418 :0 12:13 NPN/ALPN
> protocol: h2
> Jan 30 19:03:41 srv-s01 hitch[4006]: ww.xx.yy.zz:59418 :0 12:13 ssl end
> handshake
> Jan 30 19:03:41 srv-s01 hitch[4006]: ww.xx.yy.zz:59418 :42926 12:13
> backend connected
> Jan 30 19:03:54 srv-s01 hitch[4006]: {backend} Socket error: Connection
> reset by peer
> Jan 30 19:03:54 srv-s01 hitch[4006]: ww.xx.yy.zz:59413 :42924 10:11 proxy
> shutdown req=SHUTDOWN_CLEAR
> Jan 30 19:03:54 srv-s01 hitch[4006]: {backend} Socket error: Broken pipe
> Jan 30 19:03:54 srv-s01 hitch[4006]: ww.xx.yy.zz:59413 :42924 10:11 proxy
> shutdown req=SHUTDOWN_CLEAR
> Jan 30 19:03:54 srv-s01 hitch[4006]: ww.xx.yy.zz:59478 :0 10:11 proxy
> connect
> Jan 30 19:03:54 srv-s01 hitch[4006]: ww.xx.yy.zz:59478 :0 10:11 ssl
> handshake start
> Jan 30 19:03:54 srv-s01 hitch[4006]: ww.xx.yy.zz:59478 :0 10:11 ssl client
> handshake revents=1
> Jan 30 19:03:54 srv-s01 hitch[4006]: ww.xx.yy.zz:59478 :0 10:11 ssl client
> handshake err=SSL_ERROR_WANT_READ
> Jan 30 19:03:54 srv-s01 hitch[4006]: ww.xx.yy.zz:59478 :0 10:11 ssl client
> handshake revents=1
> Jan 30 19:03:54 srv-s01 hitch[4006]: ww.xx.yy.zz:59478 :0 10:11 NPN/ALPN
> protocol: h2
> Jan 30 19:03:54 srv-s01 hitch[4006]: ww.xx.yy.zz:59478 :0 10:11 ssl end
> handshake
> Jan 30 19:03:54 srv-s01 hitch[4006]: ww.xx.yy.zz:59478 :42970 10:11
> backend connected
>
>
> _______________________________________________
> varnish-misc mailing list
> varnish-misc at varnish-cache.org
> https://www.varnish-cache.org/lists/mailman/listinfo/varnish-misc
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://www.varnish-cache.org/lists/pipermail/varnish-misc/attachments/20190131/fc37a708/attachment.html>