kangle启用https的情况，chrome浏览器可能出现net::ERR_SPDY_PROTOCOL_ERROR错误 h2协议 长连接导致504

小樱

kangle启用https的情况，chrome浏览器可能出现net::ERR_SPDY_PROTOCOL_ERROR错误 h2协议 长连接导致504

测试版本：3.5.12.11
复现情况，几乎必现不定期，使用反代模式下，启用http2，未缓存kangle中的回源流量出现错误。
问题影响，页面可能载入图片，CSS等异常，刷新下命中缓存后即可恢复






网上搜索下很多h2 net::ERR_SPDY_PROTOCOL_ERROR错误同类问题
但是都没解决方法，不要说什么刷新chrome的SPDY区域，都是扯淡

而且https下h2可能会突然蹦出个spdy输出，我感觉应该和这个有关系，或者是chrome浏览器毛病？没使用其他浏览器测试


https://www.michalspacek.com/chrome-err_spdy_protocol_error-and-an-invalid-http-header 搜了半天资料就感觉这个靠谱点。。
其它什么都是扯淡杀毒软件问题，浏览器问题啊之类。

小樱

通过chrome://net-export/抓包
错误日志信息
3115: URL_REQUEST
https://att.itzmx.com/static/image/smiley/comcom/26.gif
Start Time: 2018-01-22 00:36:33.157

t=40602 [st= 0] +REQUEST_ALIVE [dt=360]
--> priority = "LOWEST"
--> url = "https://att.itzmx.com/static/image/smiley/comcom/26.gif"
t=40602 [st= 0] +URL_REQUEST_DELEGATE [dt=11]
t=40602 [st= 0] DELEGATE_INFO [dt=11]
--> delegate_blocked_by = "扩展程序“广告终结者”"
t=40613 [st= 11] -URL_REQUEST_DELEGATE
t=40613 [st= 11] +URL_REQUEST_START_JOB [dt=349]
--> load_flags = 33026 (BYPASS_CACHE | MAYBE_USER_GESTURE | VERIFY_EV_CERT)
--> method = "GET"
--> url = "https://att.itzmx.com/static/image/smiley/comcom/26.gif"
t=40613 [st= 11] URL_REQUEST_DELEGATE [dt=0]
t=40613 [st= 11] HTTP_CACHE_GET_BACKEND [dt=0]
t=40613 [st= 11] HTTP_CACHE_DOOM_ENTRY [dt=0]
--> net_error = -2 (ERR_FAILED)
t=40613 [st= 11] HTTP_CACHE_CREATE_ENTRY [dt=1]
t=40614 [st= 12] HTTP_CACHE_ADD_TO_ENTRY [dt=0]
t=40614 [st= 12] +HTTP_STREAM_REQUEST [dt=1]
t=40614 [st= 12] HTTP_STREAM_JOB_CONTROLLER_BOUND
--> source_dependency = 3205 (HTTP_STREAM_JOB_CONTROLLER)
t=40615 [st= 13] HTTP_STREAM_REQUEST_BOUND_TO_JOB
--> source_dependency = 3216 (HTTP_STREAM_JOB)
t=40615 [st= 13] -HTTP_STREAM_REQUEST
t=40615 [st= 13] +HTTP_TRANSACTION_SEND_REQUEST [dt=2]
t=40615 [st= 13] HTTP_TRANSACTION_HTTP2_SEND_REQUEST_HEADERS
--> :authority: att.itzmx.com
:method: GET
:path: /static/image/smiley/comcom/26.gif
:scheme: https
accept: image/webp,image/apng,image/*,*/*;q=0.8
accept-encoding: gzip, deflate, br
accept-language: zh-CN,zh;q=0.9
cache-control: no-cache
cookie: [1453 bytes were stripped]
dnt: 1
pragma: no-cache
referer: http://bbs.itzmx.com/thread-20831-1-1.html
user-agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/63.0.3239.132 Safari/537.36
t=40617 [st= 15] -HTTP_TRANSACTION_SEND_REQUEST
t=40617 [st= 15] +HTTP_TRANSACTION_READ_HEADERS [dt=345]
t=40620 [st= 18] URL_REQUEST_SET_PRIORITY
--> priority = "MEDIUM"
t=40962 [st=360] -HTTP_TRANSACTION_READ_HEADERS
--> net_error = -337 (ERR_SPDY_PROTOCOL_ERROR)
t=40962 [st=360] -URL_REQUEST_START_JOB
--> net_error = -337 (ERR_SPDY_PROTOCOL_ERROR)
t=40962 [st=360] URL_REQUEST_DELEGATE [dt=0]
t=40962 [st=360] -REQUEST_ALIVE
--> net_error = -337 (ERR_SPDY_PROTOCOL_ERROR)


正常日志
3111: URL_REQUEST
https://att.itzmx.com/static/image/smiley/comcom/5.gif
Start Time: 2018-01-22 00:36:33.156

t=40601 [st= 0] +REQUEST_ALIVE [dt=507]
--> priority = "LOWEST"
--> url = "https://att.itzmx.com/static/image/smiley/comcom/5.gif"
t=40601 [st= 0] +URL_REQUEST_DELEGATE [dt=11]
t=40601 [st= 0] DELEGATE_INFO [dt=11]
--> delegate_blocked_by = "扩展程序“广告终结者”"
t=40612 [st= 11] -URL_REQUEST_DELEGATE
t=40612 [st= 11] +URL_REQUEST_START_JOB [dt=495]
--> load_flags = 33026 (BYPASS_CACHE | MAYBE_USER_GESTURE | VERIFY_EV_CERT)
--> method = "GET"
--> url = "https://att.itzmx.com/static/image/smiley/comcom/5.gif"
t=40612 [st= 11] URL_REQUEST_DELEGATE [dt=0]
t=40612 [st= 11] HTTP_CACHE_GET_BACKEND [dt=0]
t=40612 [st= 11] HTTP_CACHE_DOOM_ENTRY [dt=1]
--> net_error = -2 (ERR_FAILED)
t=40613 [st= 12] HTTP_CACHE_CREATE_ENTRY [dt=0]
t=40613 [st= 12] HTTP_CACHE_ADD_TO_ENTRY [dt=0]
t=40613 [st= 12] +HTTP_STREAM_REQUEST [dt=2]
t=40613 [st= 12] HTTP_STREAM_JOB_CONTROLLER_BOUND
--> source_dependency = 3199 (HTTP_STREAM_JOB_CONTROLLER)
t=40615 [st= 14] HTTP_STREAM_REQUEST_BOUND_TO_JOB
--> source_dependency = 3212 (HTTP_STREAM_JOB)
t=40615 [st= 14] -HTTP_STREAM_REQUEST
t=40615 [st= 14] +HTTP_TRANSACTION_SEND_REQUEST [dt=2]
t=40615 [st= 14] HTTP_TRANSACTION_HTTP2_SEND_REQUEST_HEADERS
--> :authority: att.itzmx.com
:method: GET
:path: /static/image/smiley/comcom/5.gif
:scheme: https
accept: image/webp,image/apng,image/*,*/*;q=0.8
accept-encoding: gzip, deflate, br
accept-language: zh-CN,zh;q=0.9
cache-control: no-cache
cookie: [1453 bytes were stripped]
dnt: 1
pragma: no-cache
referer: http://bbs.itzmx.com/thread-20831-1-1.html
user-agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/63.0.3239.132 Safari/537.36
t=40617 [st= 16] -HTTP_TRANSACTION_SEND_REQUEST
t=40617 [st= 16] +HTTP_TRANSACTION_READ_HEADERS [dt=489]
t=40620 [st= 19] URL_REQUEST_SET_PRIORITY
--> priority = "MEDIUM"
t=41106 [st=505] HTTP_TRANSACTION_READ_RESPONSE_HEADERS
--> HTTP/1.1 200
status: 200
strict-transport-security: max-age=31104000
cache-control: max-age=259200
server: kangle/sakura/itzmx
date: Sun, 21 Jan 2018 16:36:39 GMT
content-encoding: gzip
last-modified: Mon, 13 May 2013 08:25:50 GMT
content-type: image/gif
x-cache: HIT from kangle web server dedi
x-cache: MISS from Anti-DDoS
content-length: 1644
t=41106 [st=505] -HTTP_TRANSACTION_READ_HEADERS
t=41106 [st=505] +HTTP_CACHE_WRITE_INFO [dt=0]
t=41106 [st=505] HTTP2_STREAM_UPDATE_RECV_WINDOW
--> delta = -1644
--> stream_id = 347
--> window_size = 6289812
t=41106 [st=505] -HTTP_CACHE_WRITE_INFO
t=41106 [st=505] HTTP_CACHE_WRITE_DATA [dt=0]
t=41106 [st=505] HTTP_CACHE_WRITE_INFO [dt=1]
t=41107 [st=506] URL_REQUEST_DELEGATE [dt=0]
t=41107 [st=506] URL_REQUEST_FILTERS_SET
--> filters = "GZIP"
t=41107 [st=506] -URL_REQUEST_START_JOB
t=41107 [st=506] URL_REQUEST_DELEGATE [dt=0]
t=41107 [st=506] HTTP_TRANSACTION_READ_BODY [dt=0]
t=41107 [st=506] HTTP_CACHE_WRITE_DATA [dt=1]
t=41108 [st=507] URL_REQUEST_JOB_BYTES_READ
--> byte_count = 1644
t=41108 [st=507] URL_REQUEST_JOB_FILTERED_BYTES_READ
--> byte_count = 2462
t=41108 [st=507] HTTP_TRANSACTION_READ_BODY [dt=0]
t=41108 [st=507] HTTP_CACHE_WRITE_DATA [dt=0]
t=41108 [st=507] -REQUEST_ALIVE


反代服务器端输出的server.log日志如下
Mon Jan 22 02:02:45|rq=[0x7f931ed95400] url=[http://mirrors.itzmx.com/centos/6.9/updates/x86_64/repodata/repomd.xml] upstream=[192.168.1.3:81] error code=[504],msg=[cann't recv head from remote server] errno=[9 Bad file descriptor],socket=17(pool)
Mon Jan 22 02:03:15|rq=[0x7f931a12bc00] url=[https://uc.itzmx.com/data/avatar/000/01/71/72_avatar_middle.jpg] upstream=[192.168.1.3:81] error code=[504],msg=[cann't recv head from remote server] errno=[0 Success],socket=135(pool)
Mon Jan 22 02:03:15|rq=[0x7f931eef6e00] url=[http://bbs.itzmx.com/source/plugin/chxs_icons/images/net/mozilla.png] upstream=[192.168.1.3:81] error code=[504],msg=[cann't recv head from remote server] errno=[9 Bad file descriptor],socket=63(pool)
Mon Jan 22 02:03:15|rq=[0x7f931a2f1000] url=[http://bbs.itzmx.com/source/plugin/chxs_icons/images/os/win-2.png] upstream=[192.168.1.3:81] error code=[504],msg=[cann't recv head from remote server] errno=[9 Bad file descriptor],socket=139(pool)
Mon Jan 22 02:03:23|rq=[0x7f9316dc7e00] url=[https://att.itzmx.com/static/image/common/collapsed_no.gif] upstream=[192.168.1.3:81] error code=[504],msg=[cann't recv head from remote server] errno=[0 Success],socket=140(pool)
Mon Jan 22 02:03:23|rq=[0x7f9317295200] url=[https://att.itzmx.com/data/attachment/common/d6/common_39_icon.jpg] upstream=[192.168.1.3:81] error code=[504],msg=[cann't recv head from remote server] errno=[9 Bad file descriptor],socket=142(pool)
Mon Jan 22 02:03:23|rq=[0x7f9316dc7800] url=[https://att.itzmx.com/data/attachment/common/a5/common_38_icon.jpg] upstream=[192.168.1.3:81] error code=[504],msg=[cann't recv head from remote server] errno=[9 Bad file descriptor],socket=144(pool)
Mon Jan 22 02:03:23|rq=[0x7f9316dc7800] url=[https://att.itzmx.com/data/attachment/common/c8/common_2_icon.jpg] upstream=[192.168.1.3:81] error code=[504],msg=[cann't recv head from remote server] errno=[0 Success],socket=130(pool)
Mon Jan 22 02:03:23|rq=[0x7f9317d8c800] url=[https://att.itzmx.com/data/attachment/common/73/common_67_icon.png] upstream=[192.168.1.3:81] error code=[504],msg=[cann't recv head from remote server] errno=[9 Bad file descriptor],socket=103(pool)
Mon Jan 22 02:03:23|rq=[0x7f9319d79e00] url=[https://att.itzmx.com/data/attachment/common/d6/common_40_icon.jpg] upstream=[192.168.1.3:81] error code=[504],msg=[cann't recv head from remote server] errno=[9 Bad file descriptor],socket=111(pool)
Mon Jan 22 02:03:23|rq=[0x7f9319d79e00] url=[https://att.itzmx.com/data/attachment/common/34/common_41_icon.jpg] upstream=[192.168.1.3:81] error code=[504],msg=[cann't recv head from remote server] errno=[0 Success],socket=131(pool)
Mon Jan 22 02:03:23|rq=[0x7f931c27d200] url=[https://att.itzmx.com/data/attachment/common/a1/common_42_icon.jpg] upstream=[192.168.1.3:81] error code=[504],msg=[cann't recv head from remote server] errno=[9 Bad file descriptor],socket=121(pool)
Mon Jan 22 02:03:23|rq=[0x7f9319f3a000] url=[https://att.itzmx.com/data/attachment/common/6c/common_45_icon.jpg] upstream=[192.168.1.3:81] error code=[504],msg=[cann't recv head from remote server] errno=[9 Bad file descriptor],socket=123(pool)
Mon Jan 22 02:03:23|rq=[0x7f9319f3a000] url=[https://att.itzmx.com/data/attachment/common/f7/common_44_icon.jpg] upstream=[192.168.1.3:81] error code=[504],msg=[cann't recv head from remote server] errno=[0 Success],socket=120(pool)
Mon Jan 22 02:03:23|rq=[0x7f9316dc7400] url=[https://att.itzmx.com/data/attachment/common/17/common_43_icon.jpg] upstream=[192.168.1.3:81] error code=[504],msg=[cann't recv head from remote server] errno=[9 Bad file descriptor],socket=119(pool)
Mon Jan 22 02:03:23|rq=[0x7f9316d8d600] url=[https://att.itzmx.com/data/attachment/common/32/common_66_icon.png] upstream=[192.168.1.3:81] error code=[504],msg=[cann't recv head from remote server] errno=[9 Bad file descriptor],socket=166(pool)
Mon Jan 22 02:03:23|rq=[0x7f9316d8d600] url=[https://att.itzmx.com/data/attachment/common/a3/common_68_icon.png] upstream=[192.168.1.3:81] error code=[504],msg=[cann't recv head from remote server] errno=[0 Success],socket=113(pool)
Mon Jan 22 02:03:23|rq=[0x7f9319d79600] url=[https://att.itzmx.com/data/attachment/common/f4/common_49_icon.jpg] upstream=[192.168.1.3:81] error code=[504],msg=[cann't recv head from remote server] errno=[9 Bad file descriptor],socket=84(pool)
Mon Jan 22 02:03:23|rq=[0x7f9316dc7a00] url=[https://att.itzmx.com/data/attachment/common/64/common_48_icon.jpg] upstream=[192.168.1.3:81] error code=[504],msg=[cann't recv head from remote server] errno=[9 Bad file descriptor],socket=124(pool)
Mon Jan 22 02:03:23|rq=[0x7f9316dc7a00] url=[https://att.itzmx.com/data/attachment/common/67/common_47_icon.jpg] upstream=[192.168.1.3:81] error code=[504],msg=[cann't recv head from remote server] errno=[0 Success],socket=104(pool)
Mon Jan 22 02:03:23|rq=[0x7f9310ae1200] url=[https://att.itzmx.com/data/attachment/common/d9/common_46_icon.jpg] upstream=[192.168.1.3:81] error code=[504],msg=[cann't recv head from remote server] errno=[9 Bad file descriptor],socket=114(pool)
Mon Jan 22 02:05:16|rq=[0x7f931a172600] url=[http://bbs.itzmx.com/thread-15149-1-1.html] upstream=[192.168.1.3:81] error code=[504],msg=[cann't recv head from remote server] errno=[9 Bad file descriptor],socket=135(pool)
Mon Jan 22 02:05:44|rq=[0x7f9319dc6e00] url=[https://uc.itzmx.com/data/avatar/000/01/56/99_avatar_middle.jpg] upstream=[192.168.1.3:81] error code=[504],msg=[cann't recv head from remote server] errno=[0 Success],socket=145(pool)
Mon Jan 22 02:05:44|rq=[0x7f931a630e00] url=[https://uc.itzmx.com/data/avatar/000/01/68/42_avatar_middle.jpg] upstream=[192.168.1.3:81] error code=[504],msg=[cann't recv head from remote server] errno=[0 Success],socket=142(pool)
Mon Jan 22 02:05:44|rq=[0x7f931a12be00] url=[https://uc.itzmx.com/data/avatar/000/01/52/40_avatar_middle.jpg] upstream=[192.168.1.3:81] error code=[504],msg=[cann't recv head from remote server] errno=[9 Bad file descriptor],socket=140(pool)
Mon Jan 22 02:05:44|rq=[0x7f931a12be00] url=[https://uc.itzmx.com/data/avatar/000/01/43/07_avatar_middle.jpg] upstream=[192.168.1.3:81] error code=[504],msg=[cann't recv head from remote server] errno=[0 Success],socket=138(pool)
Mon Jan 22 02:05:44|rq=[0x7f9316d8d400] url=[https://uc.itzmx.com/avatar.php?uid=11945&size=small] upstream=[192.168.1.3:81] error code=[504],msg=[cann't recv head from remote server] errno=[0 Success],socket=119(pool)
Mon Jan 22 02:05:44|rq=[0x7f9319dc6000] url=[https://uc.itzmx.com/avatar.php?uid=12466&size=small] upstream=[192.168.1.3:81] error code=[504],msg=[cann't recv head from remote server] errno=[9 Bad file descriptor],socket=141(pool)
Mon Jan 22 02:05:44|rq=[0x7f9316dc7200] url=[https://uc.itzmx.com/avatar.php?uid=12498&size=small] upstream=[192.168.1.3:81] error code=[504],msg=[cann't recv head from remote server] errno=[9 Bad file descriptor],socket=103(pool)
Mon Jan 22 02:05:48|rq=[0x7f931eeeae00] url=[http://bbs.itzmx.com/forum.php?mod=viewthread&tid=10567] upstream=[192.168.1.3:81] error code=[504],msg=[cann't recv head from remote server] errno=[0 Success],socket=137(pool)

看到输出spdy的都是9 Bad file descriptor？？和0 Success这两个错误

44_icon.jpg输出相同的net::ERR_SPDY_PROTOCOL_ERROR，日志上面显示
504代码，0 Success，其他的很多是9bad file
前台可能秒出504无法重试输出也是9bad file，，可能就是这个毛病

小樱

貌似根据http协议不允许节点长连接超过源服务器长连接表明，是长连接时间太长了，会冲突出问题。。导致回源响应失败可以设置一样的值或者用0直接短链接上游
反代服务器上游长连接大于源的长连接时间，就出现了这个毛病
我调整了加大源服务器的长连接为 120s 后，反代 60s，情况缓解很多，虽然偶尔可能还是会出现（其他就是网络原因了，毕竟节点在法国，源站在美国，跨越了200ms距离）。

小樱

问题终结，已解决

小菜鸟想飞

大佬你最后是怎么解决的，加长长连接时间吗？？

小樱

小菜鸟想飞 发表于 2019/11/15 14:54
大佬你最后是怎么解决的，加长长连接时间吗？？

是，主要猜测还是CDN到源网络通讯不良好却使用了长连接导致的

小菜鸟想飞

keepalive_timeout 600;
fastcgi_connect_timeout 600;
fastcgi_send_timeout 600;
fastcgi_read_timeout 600;
我把这几个参数都加长了，是不是就可以了。
http2协议好像也不能加上去
域名https:
端口设置listen 443 ssl;
而不能listen 443 ssl http2;

小樱

小菜鸟想飞 发表于 2019/11/16 17:21
keepalive_timeout 600;
fastcgi_connect_timeout 600;
fastcgi_send_timeout 600;

嗯，源站加长，或者都彻底关掉长连接