十六根线程对五十个任务:一次把队列灌到五万才看懂的线程池
机器人那条推送甩得直白:下单链路的 P99 由 80 毫秒一路顶到 2.1 秒,落点在 02:40。
天亮前我埋下的那手
头一日还大亮的时候,我把手伸向了那口异步落库的池子。 核心数由 8 挪到 16,队列由 500 抬到 50000。
弄罢我守着曲线瞧了两分钟,没见起伏,人就退了线。
真出事是两点二十四那一格,导库存的批处理准点放闸,一秒朝里灌 50 个落库任务。
拿进量乘上单条耗时倒过来算:50 × 2.1 秒,这摊活要 105 条线程才接得住,可池子里拢共才 16 条。
〈线程池核心线程数和队列长度怎么定,别照抄核数加一〉
这套算法我是原封抄来的,只是往里填数那一下,我手上拿的还是 80 毫秒那个旧值。
把案发的那口井搬回本机
我头一件做的是复现。
我本机是 12 核,JDK 用的 corretto 1.8.0_412。 池子参数是 core 摆 8、max 摆 16、队列撑到 50000,每条任务只干一件事:请求一发出去,就干等那个不肯回话的下游。 我连着丢了 20 个进去:
PID=12200@localhost
PORT=64666 submitted=20 queued=12 active=8 poolSize=8
这 20 里头,八条被线程拽着在跑,十二条候在队列,池子撑死也就八条线。
我把现场抓下来,照着线程名去筛,挑一根把整段栈原样搁这:
"stock-async-3" #14 prio=5 os_prio=0 tid=0x00000237f17dc000 nid=0x7c78 runnable [0x000000a776cff000]
java.lang.Thread.State: RUNNABLE
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
at java.net.SocketInputStream.read(SocketInputStream.java:171)
at java.net.SocketInputStream.read(SocketInputStream.java:141)
at java.net.SocketInputStream.read(SocketInputStream.java:127)
at SocketHog$Task.run(SocketHog.java:65)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:750)
那个假下游由我临时捏的,连接照单收下,读完请求就闷声不响。
八条线程配八份栈,各栈顶端不偏不倚,全钉在同一处网络读上。
搁在从前我一直有个死印象:被下游吊着命的那几根线,抓栈该给写成 WAITING (parking)。 经此一回才算把它瞅真切。
真正卡在 socket 上的那几根,标签显示的是 RUNNABLE。
至于 parking,那是另一码事:池子闲下来、线程挂在取任务那步上空睡的那种。
两种搅到一块儿看,现场八九不离十要读拧。
下游、库、GC 挨个过堂
我先把下游这层掀开。
去翻库存服务自己那本访问日志,它的 P99 由 60 毫秒蹦到了 2.1 秒。
60 毫秒早先量过摆着的,是这一波上线一脚把它踹上了两千一。
接着去核库。
头一晚才刚立起的慢查询日志,阈值卡在 1 秒,那一宿添的新条数是零。
DB 这一路就算先排除了。
轮到 GC。
拿 jstat 一瞅,Full GC 的频次比往常多了些,可它跟 RT 的波峰波谷怎么拼都对不齐,我索性先把它撂到一边。
这一撂,是我隔天清早才拍大腿的地方。
堵点既然齐刷刷朝着同一个下游,这笔账当下就摊得开。
16 条线,一条要 2.1 秒才放行一个,整秒合计也就吐 7.6 个,外头涌进来的却是 50 个。
一进一出,一秒净积 42.4,自批处理放闸直到两点四十,前后十六分钟,垒出来恰是四万零七百。
得掰清:四万讲的是那一刹的排队深度,不是队列那堵天花板。
天花板是五万,撑到两点四十四被灌到了头,冒头之后便来一个弹一个:
java.util.concurrent.RejectedExecutionException
Task BigQueue$2@1540e19d rejected from java.util.concurrent.ThreadPoolExecutor@677327b6
[Running, pool size = 16, active threads = 16, queued tasks = 50000, completed tasks = 8]
这行是我在本机复现那趟逼出来的。
把方括号里那三个数摞起来加:16 + 50000 + 8 = 50024,刚好凑成已经落进池子的活儿总数,被弹出去的那位,正排在它身后。
生产上那条原文我没往稿子里搬,句式轮廓一般无二,这些数我没胆替它现编。
〈线程池被说不该用 Executors,自己 new 这几个参数怎么填〉
那篇里我撂下过这么一句:「抄这一行就知道当时是哪种满」。这一遭当真全靠它认的门。
同一份输出里还夹着个细节:队列 50000 这一把,候在里面的 49,984 个没散尽那阵,线程数还钉死在 8。
非要撑到灌满那一刹才肯补到 16,没灌满那会儿还轮不到 max 出手。
接口 RT 蹿到 2.1 秒走的是同步那一条道,堵它的仍是这一个下游。
这 2.1 秒没能捅破 Feign 那侧的读超时上限 3000,于是一个错都不抛,只是干磨人。
我伸手动的那两处
那一晚救火,我统共动了两下。
先说头一下:拒绝策略由 AbortPolicy 临时拨去 CallerRunsPolicy,先观着。 我本机把 core 压到 2、max 也 2、队列只留 4,丢进去十二个,副作用立竿见影:
CALLER_RUNS submitted12 mainRanTasks=3 workerRanTasks=9 submitLoopBlockedMs=324
那条本该只管派发的线程被拽去亲自跑了 3 个,整个派发循环卡了 324 毫秒。
挪到生产,派发的角色由 Tomcat 的工作线程担着,这样的一条足足 200 个。
这路策略任务是真不丢,只是把慢顺手往下游传,而它偏偏传到最扛不住慢的那层。
顶多十分钟,我又把它拨了回来。
再说第二下:打点那几路不算核心的落库先 return 丢掉,把队列匀出来,专门留给扣库存、下单流水去使。
事后回看,我只往仪表上加了三行:在跑的线程数、排队的长度、被打回的次数。
偏偏这三样出那会儿一个都瞧不见,全凭抓栈再加事后扒日志,一截截凑齐的。
末了还有一桩,我没能当场了结。
四万条作业正蜷在队列里,每一条都死死攥着各自那份等着落库的数据,堆被它们一路托着往上冒。
这条线,我是隔日清早靠一份 jmap 快照才捅破的。
DAMO开发者矩阵,由阿里巴巴达摩院和中国互联网协会联合发起,致力于探讨最前沿的技术趋势与应用成果,搭建高质量的交流与分享平台,推动技术创新与产业应用链接,围绕“人工智能与新型计算”构建开放共享的开发者生态。
更多推荐

所有评论(0)