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

小樱 发表于 2018/1/13 04:46

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 搜了半天资料就感觉这个靠谱点。。
其它什么都是扯淡杀毒软件问题，浏览器问题啊之类。

小樱 发表于 2018/1/22 01:57

通过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 +REQUEST_ALIVE
--> priority = "LOWEST"
--> url = "https://att.itzmx.com/static/image/smiley/comcom/26.gif"
t=40602 +URL_REQUEST_DELEGATE
t=40602 DELEGATE_INFO
--> delegate_blocked_by = "扩展程序“广告终结者”"
t=40613 -URL_REQUEST_DELEGATE
t=40613 +URL_REQUEST_START_JOB
--> 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 URL_REQUEST_DELEGATE
t=40613 HTTP_CACHE_GET_BACKEND
t=40613 HTTP_CACHE_DOOM_ENTRY
--> net_error = -2 (ERR_FAILED)
t=40613 HTTP_CACHE_CREATE_ENTRY
t=40614 HTTP_CACHE_ADD_TO_ENTRY
t=40614 +HTTP_STREAM_REQUEST
t=40614 HTTP_STREAM_JOB_CONTROLLER_BOUND
--> source_dependency = 3205 (HTTP_STREAM_JOB_CONTROLLER)
t=40615 HTTP_STREAM_REQUEST_BOUND_TO_JOB
--> source_dependency = 3216 (HTTP_STREAM_JOB)
t=40615 -HTTP_STREAM_REQUEST
t=40615 +HTTP_TRANSACTION_SEND_REQUEST
t=40615 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:
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 -HTTP_TRANSACTION_SEND_REQUEST
t=40617 +HTTP_TRANSACTION_READ_HEADERS
t=40620 URL_REQUEST_SET_PRIORITY
--> priority = "MEDIUM"
t=40962 -HTTP_TRANSACTION_READ_HEADERS
--> net_error = -337 (ERR_SPDY_PROTOCOL_ERROR)
t=40962 -URL_REQUEST_START_JOB
--> net_error = -337 (ERR_SPDY_PROTOCOL_ERROR)
t=40962 URL_REQUEST_DELEGATE
t=40962 -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 +REQUEST_ALIVE
--> priority = "LOWEST"
--> url = "https://att.itzmx.com/static/image/smiley/comcom/5.gif"
t=40601 +URL_REQUEST_DELEGATE
t=40601 DELEGATE_INFO
--> delegate_blocked_by = "扩展程序“广告终结者”"
t=40612 -URL_REQUEST_DELEGATE
t=40612 +URL_REQUEST_START_JOB
--> 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 URL_REQUEST_DELEGATE
t=40612 HTTP_CACHE_GET_BACKEND
t=40612 HTTP_CACHE_DOOM_ENTRY
--> net_error = -2 (ERR_FAILED)
t=40613 HTTP_CACHE_CREATE_ENTRY
t=40613 HTTP_CACHE_ADD_TO_ENTRY
t=40613 +HTTP_STREAM_REQUEST
t=40613 HTTP_STREAM_JOB_CONTROLLER_BOUND
--> source_dependency = 3199 (HTTP_STREAM_JOB_CONTROLLER)
t=40615 HTTP_STREAM_REQUEST_BOUND_TO_JOB
--> source_dependency = 3212 (HTTP_STREAM_JOB)
t=40615 -HTTP_STREAM_REQUEST
t=40615 +HTTP_TRANSACTION_SEND_REQUEST
t=40615 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:
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 -HTTP_TRANSACTION_SEND_REQUEST
t=40617 +HTTP_TRANSACTION_READ_HEADERS
t=40620 URL_REQUEST_SET_PRIORITY
--> priority = "MEDIUM"
t=41106 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 -HTTP_TRANSACTION_READ_HEADERS
t=41106 +HTTP_CACHE_WRITE_INFO
t=41106 HTTP2_STREAM_UPDATE_RECV_WINDOW
--> delta = -1644
--> stream_id = 347
--> window_size = 6289812
t=41106 -HTTP_CACHE_WRITE_INFO
t=41106 HTTP_CACHE_WRITE_DATA
t=41106 HTTP_CACHE_WRITE_INFO
t=41107 URL_REQUEST_DELEGATE
t=41107 URL_REQUEST_FILTERS_SET
--> filters = "GZIP"
t=41107 -URL_REQUEST_START_JOB
t=41107 URL_REQUEST_DELEGATE
t=41107 HTTP_TRANSACTION_READ_BODY
t=41107 HTTP_CACHE_WRITE_DATA
t=41108 URL_REQUEST_JOB_BYTES_READ
--> byte_count = 1644
t=41108 URL_REQUEST_JOB_FILTERED_BYTES_READ
--> byte_count = 2462
t=41108 HTTP_TRANSACTION_READ_BODY
t=41108 HTTP_CACHE_WRITE_DATA
t=41108 -REQUEST_ALIVE


反代服务器端输出的server.log日志如下
Mon Jan 22 02:02:45|rq= url=[http://mirrors.itzmx.com/centos/6.9/updates/x86_64/repodata/repomd.xml] upstream= error code=,msg= errno=,socket=17(pool)
Mon Jan 22 02:03:15|rq= url=[https://uc.itzmx.com/data/avatar/000/01/71/72_avatar_middle.jpg] upstream= error code=,msg= errno=,socket=135(pool)
Mon Jan 22 02:03:15|rq= url=[http://bbs.itzmx.com/source/plugin/chxs_icons/images/net/mozilla.png] upstream= error code=,msg= errno=,socket=63(pool)
Mon Jan 22 02:03:15|rq= url=[http://bbs.itzmx.com/source/plugin/chxs_icons/images/os/win-2.png] upstream= error code=,msg= errno=,socket=139(pool)
Mon Jan 22 02:03:23|rq= url=[https://att.itzmx.com/static/image/common/collapsed_no.gif] upstream= error code=,msg= errno=,socket=140(pool)
Mon Jan 22 02:03:23|rq= url=[https://att.itzmx.com/data/attachment/common/d6/common_39_icon.jpg] upstream= error code=,msg= errno=,socket=142(pool)
Mon Jan 22 02:03:23|rq= url=[https://att.itzmx.com/data/attachment/common/a5/common_38_icon.jpg] upstream= error code=,msg= errno=,socket=144(pool)
Mon Jan 22 02:03:23|rq= url=[https://att.itzmx.com/data/attachment/common/c8/common_2_icon.jpg] upstream= error code=,msg= errno=,socket=130(pool)
Mon Jan 22 02:03:23|rq= url=[https://att.itzmx.com/data/attachment/common/73/common_67_icon.png] upstream= error code=,msg= errno=,socket=103(pool)
Mon Jan 22 02:03:23|rq= url=[https://att.itzmx.com/data/attachment/common/d6/common_40_icon.jpg] upstream= error code=,msg= errno=,socket=111(pool)
Mon Jan 22 02:03:23|rq= url=[https://att.itzmx.com/data/attachment/common/34/common_41_icon.jpg] upstream= error code=,msg= errno=,socket=131(pool)
Mon Jan 22 02:03:23|rq= url=[https://att.itzmx.com/data/attachment/common/a1/common_42_icon.jpg] upstream= error code=,msg= errno=,socket=121(pool)
Mon Jan 22 02:03:23|rq= url=[https://att.itzmx.com/data/attachment/common/6c/common_45_icon.jpg] upstream= error code=,msg= errno=,socket=123(pool)
Mon Jan 22 02:03:23|rq= url=[https://att.itzmx.com/data/attachment/common/f7/common_44_icon.jpg] upstream= error code=,msg= errno=,socket=120(pool)
Mon Jan 22 02:03:23|rq= url=[https://att.itzmx.com/data/attachment/common/17/common_43_icon.jpg] upstream= error code=,msg= errno=,socket=119(pool)
Mon Jan 22 02:03:23|rq= url=[https://att.itzmx.com/data/attachment/common/32/common_66_icon.png] upstream= error code=,msg= errno=,socket=166(pool)
Mon Jan 22 02:03:23|rq= url=[https://att.itzmx.com/data/attachment/common/a3/common_68_icon.png] upstream= error code=,msg= errno=,socket=113(pool)
Mon Jan 22 02:03:23|rq= url=[https://att.itzmx.com/data/attachment/common/f4/common_49_icon.jpg] upstream= error code=,msg= errno=,socket=84(pool)
Mon Jan 22 02:03:23|rq= url=[https://att.itzmx.com/data/attachment/common/64/common_48_icon.jpg] upstream= error code=,msg= errno=,socket=124(pool)
Mon Jan 22 02:03:23|rq= url=[https://att.itzmx.com/data/attachment/common/67/common_47_icon.jpg] upstream= error code=,msg= errno=,socket=104(pool)
Mon Jan 22 02:03:23|rq= url=[https://att.itzmx.com/data/attachment/common/d9/common_46_icon.jpg] upstream= error code=,msg= errno=,socket=114(pool)
Mon Jan 22 02:05:16|rq= url=[http://bbs.itzmx.com/thread-15149-1-1.html] upstream= error code=,msg= errno=,socket=135(pool)
Mon Jan 22 02:05:44|rq= url=[https://uc.itzmx.com/data/avatar/000/01/56/99_avatar_middle.jpg] upstream= error code=,msg= errno=,socket=145(pool)
Mon Jan 22 02:05:44|rq= url=[https://uc.itzmx.com/data/avatar/000/01/68/42_avatar_middle.jpg] upstream= error code=,msg= errno=,socket=142(pool)
Mon Jan 22 02:05:44|rq= url=[https://uc.itzmx.com/data/avatar/000/01/52/40_avatar_middle.jpg] upstream= error code=,msg= errno=,socket=140(pool)
Mon Jan 22 02:05:44|rq= url=[https://uc.itzmx.com/data/avatar/000/01/43/07_avatar_middle.jpg] upstream= error code=,msg= errno=,socket=138(pool)
Mon Jan 22 02:05:44|rq= url=[https://uc.itzmx.com/avatar.php?uid=11945&size=small] upstream= error code=,msg= errno=,socket=119(pool)
Mon Jan 22 02:05:44|rq= url=[https://uc.itzmx.com/avatar.php?uid=12466&size=small] upstream= error code=,msg= errno=,socket=141(pool)
Mon Jan 22 02:05:44|rq= url=[https://uc.itzmx.com/avatar.php?uid=12498&size=small] upstream= error code=,msg= errno=,socket=103(pool)
Mon Jan 22 02:05:48|rq= url=[http://bbs.itzmx.com/forum.php?mod=viewthread&tid=10567] upstream= error code=,msg= errno=,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，，可能就是这个毛病

小樱 发表于 2018/1/22 18:40

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

小樱 发表于 2018/1/23 18:02

问题终结，已解决

小菜鸟想飞 发表于 2019/11/15 14:54

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

小樱 发表于 2019/11/15 18:27

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

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

小菜鸟想飞 发表于 2019/11/16 17:21

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:30

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


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

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