在某天凌晨,欧美服出现了卡顿,但是服务器的CPU并不高,内部服务监控日志来看,是clusteragent的mq overload了,网卡IO从流量上来看,也没达到瓶颈。后来,对方SA说是参数配错了,8核的机器配了24线程,改成8线程后重启,就不卡顿了。这里排查的时候用到了tracetag,虽然有点麻烦,还是值得的。
后来,又再一次出现了同样的问题。反复调参后,发现center配4线程就有问题,配6线程就不会卡顿。子熏怀疑是线程权重设置有问题,前面的-1都改成0就解决了,改成0以后即使再配4线程,也没有问题了。出问题的代码如下:
static int weight[] = { -1, -1, -1, -1, 0, 0, 0, 0, 1, 1, 1, 1, 1, 1, 1, 1, 2, 2, 2, 2, 2, 2, 2, 2, 3, 3, 3, 3, 3, 3, 3, 3, }; struct worker_parm wp[thread]; for (i=0;i<thread;i++) { wp[i].m = m; wp[i].id = i; if (i < sizeof(weight)/sizeof(weight[0])) { wp[i].weight= weight[i]; } else { wp[i].weight = 0; } create_thread(&pid[i+3], thread_worker, &wp[i]); }
这里线程创建的时候,会定义一个权重数组,4核的时候,相当于每个线程权重都是-1,权重的用途可以看这里:
1 int i,n=1; 2 struct skynet_message msg; 3 4 for (i=0;i<n;i++) { 5 if (skynet_mq_pop(q,&msg)) { 6 skynet_context_release(ctx); 7 return skynet_globalmq_pop(); 8 } else if (i==0 && weight >= 0) { 9 n = skynet_mq_length(q); 10 n >>= weight; 11 } 12 int overload = skynet_mq_overload(q); 13 if (overload) { 14 skynet_error(ctx, "May overload, message queue length = %d", overload); 15 } 16 17 skynet_monitor_trigger(sm, msg.source , handle); 18 19 if (ctx->cb == NULL) { 20 skynet_free(msg.data); 21 } else { 22 dispatch_message(ctx, &msg); 23 } 24 25 skynet_monitor_trigger(sm, 0,0); 26 }
这里10行的n表示mq的未处理消息条数,n右移-1位就是0,下面22行的dispatch_message就只会执行一次。右移0位,就表示有多少条消息,就处理多少条消息,右移1位,就是只处理(未处理消息条数/2)这么多。skynet_mq_pop是说从mq里尝试弹消息,成功返回0,mq是空则返回1。如果第一次进入for循环,mq有未处理消息,这时候权重为0,就会处理当前积压的消息。即使处理过程中来了新的消息,因为第8行的代码不会重复跑,所以会归并到下次消息调度来处理。
子熏提到可以将权重改成-1,0,-1,0这样排布,目前项目是直接将最低线程数改成8来解决的,不用改代码。远期来看,可能引入优先级比较好,高优先级的多处理一下。子熏提的另一个问题值得思考,线程每次处理一个消息,然后切换出去,跟每次处理完当下所有消息,再切换出去,不考虑切换开销的话,工作量是不变的。为什么现在会出现CPU不高的情况呢?而且消息处理明显慢了很多
我觉得这从侧面反映了当前的测量体系是有问题的,CPU不高不能反映游戏就正常运行了。有可能是线程总是在切换ctx,所以cache miss比较高,效率就比较低了。最好是能够搞出来一个工作模型,里面跑的是跟线上业务类似的工作负载,每条消息处理不会太快也不会太慢,然后比较一下处理一条就切换,跟处理完再切换,两种不同调度的吞吐量区别。
参考阅读:
http://www.brendangregg.com/blog/2017-05-09/cpu-utilization-is-wrong.html
CPU Utilization is Wrong 作者认为CPU使用率指导意义不大,应该看的是Instruction Per Cycle,小于1的话往往是memory限制了CPU运行效率。吐槽下virtualbox,没提供相应的计数器,在perf里看不出来。。。
后续
上次子熏提到,如果消息很多处理不过来,CPU不可能这么低。最后,子熏在卡顿的时候直接用gdb attach进去了,发现卡顿的时候在调poll。捋了一遍代码,结果是连接平台的mq用了block住线程的poll接口,然后最近合服,跑了多条mq。。。应该一条mq注册多个serverid,而不是每个serverid单独起一个服务,每个服务都去连平台mq的。
调了权重后能极大改善,是因为mq服务卡了几个线程,剩余线程每次只处理一个的话,吞吐量就不够了,换成0会改善很多,但是如果mq服务更多(合服数量更多),还是会有同样的问题的。
这里用gdb有点蛋疼,如果attach进去没遇上那个窗口,就比较难看到了。可惜用systemtap对系统要求太高了,装完一堆东西,还是这个没有那个没有,没法跑出来看。最后发现strace可以看到,strace -k -fp 进程pid -T -tt -o /tmp/strace.log可以打出来系统调用,还有每个调用的耗时,-k可以打调用栈。-k依赖于libunwind,我是自己编译后的版本才有的。。