Commit dc706073 authored by chenzhangyi01's avatar chenzhangyi01

Add docs for server and builtin services

Change-Id: I98123c4b7ac814c2248fe7e85e393aaecd83e2d9
parent d5b90801
“雪崩”指的是访问服务集群时绝大部分请求都超时,且在流量减少时仍无法恢复的现象。下面解释这个现象的来源。
当流量超出服务的最大qps时,服务将无法正常服务;当流量恢复正常时(小于服务的处理能力),积压的请求会被处理,虽然其中很大一部分可能会因为处理的不及时而超时,但服务本身一般还是会恢复正常的。这就相当于一个水池有一个入水口和一个出水口,如果入水量大于出水量,水池子终将盛满,多出的水会溢出来。但如果入水量降到出水量之下,一段时间后水池总会排空。雪崩并不是单一服务能产生的。
如果一个请求经过两个服务,情况就有所不同了。比如请求访问A服务,A服务又访问了B服务。当B被打满时,A处的client会大量超时,如果A处的client在等待B返回时也阻塞了A的服务线程(常见),且使用了固定个数的线程池(常见),那么A处的最大qps就从**线程数 / 平均延时**,降到了**线程数 / 超时**。由于超时往往是平均延时的3~4倍,A处的最大qps会相应地下降3~4倍,从而产生比B处更激烈的拥塞。如果A还有类似的上游,拥塞会继续传递上去。但这个过程还是可恢复的。B处的流量终究由最前端的流量触发,只要最前端的流量回归正常,B处的流量总会慢慢降下来直到能正常回复大多数请求,从而让A恢复正常。
但有两个例外:
1. A可能对B发起了过于频繁的基于超时的重试。这不仅会让A的最大qps降到**线程数 / 超时**,还会让B处的qps翻**重试次数**倍。这就可能陷入恶性循环了:只要**线程数 / 超时 \* 重试次数**大于B的最大qps**,**B就无法恢复 -> A处的client会继续超时 -> A继续重试 -> B继续无法恢复。
2. A或B没有限制某个缓冲或队列的长度,或限制过于宽松。拥塞请求会大量地积压在那里,要恢复就得全部处理完,时间可能长得无法接受。由于有限长的缓冲或队列需要在填满时解决等待、唤醒等问题,有时为了简单,代码可能会假定缓冲或队列不会满,这就埋下了种子。即使队列是有限长的,恢复时间也可能很长,因为清空队列的过程是个追赶问题,排空的时间取决于**积压的请求数 / (最大qps - 当前qps)**,如果当前qps和最大qps差的不多,积压的请求又比较多,那排空时间就遥遥无期了。
了解这些因素后可以更好的理解baidu-rpc中相关的设计。
1. 拥塞时A服务最大qps的跳变是因为线程个数是**硬限**,单个请求的处理时间很大程度上决定了最大qps。而baidu-rpc server端默认在bthread中处理请求,个数是软限,单个请求超时只是阻塞所在的bthread,并不会影响为新请求建立新的bthread。baidu-rpc也提供了完整的异步接口,让用户可以进一步提高io-bound服务的并发度,降低服务被打满的可能性。
2. baidu-rpc中[重试](http://wiki.baidu.com/pages/viewpage.action?pageId=213828685#id-创建和访问Client-重试)默认只在连接出错时发起,避免了流量放大,这是比较有效率的重试方式。如果需要基于超时重试,可以设置[backup request](http://wiki.baidu.com/pages/viewpage.action?pageId=213828685#id-创建和访问Client-backuprequest),这类重试最多只有一次,放大程度降到了最低。baidu-rpc中的RPC超时是deadline,超过后RPC一定会结束,这让用户对服务的行为有更好的预判。在之前的一些实现中,RPC超时是单次超时*重试次数,在实践中容易误判。
3. baidu-rpc server端的[max_concurrency选项](http://wiki.baidu.com/pages/viewpage.action?pageId=213828715#id-创建和设置Server-限制最大并发)控制了server的最大并发:当同时处理的请求数超过max_concurrency时,server会回复client错误,而不是继续积压。这一方面在服务开始的源头控制住了积压的请求数,尽量避免延生到用户缓冲或队列中,另一方面也让client尽快地去重试其他server,对集群来说是个更好的策略。
对于baidu-rpc的用户来说,要防止雪崩,主要注意两点:
1. 评估server的最大并发,设置合理的max_concurrency值。这个默认是不设的,也就是不限制。无论程序是同步还是异步,用户都可以通过 **最大qps \* 非拥塞时的延时**(秒)来评估最大并发,原理见[little's law](https://en.wikipedia.org/wiki/Little),这两个量都可以在baidu-rpc中的内置服务中看到。max_concurrency与最大并发相等或大一些就行了。
2. 注意考察重试发生时的行为,特别是在定制RetryPolicy时。如果你只是用默认的baidu-rpc重试,一般是安全的。但用户程序也常会自己做重试,比如通过一个Channel访问失败后,去访问另外一个Channel,这种情况下要想清楚重试发生时最差情况下请求量会放大几倍,服务是否可承受。
\ No newline at end of file
# 什么是内置服务?
内置服务以多种形式展现服务器内部状态,提高你开发和调试服务的效率。baidu-rpc通过HTTP协议提供内置服务,可通过浏览器或curl访问,服务器会根据User-Agent返回纯文本或html,你也可以添加?console=1要求返回纯文本。我们在自己的开发机上启动了[一个长期运行的例子](http://brpc.baidu.com:8765/),你可以点击后随便看看。服务端口只有在8000-8999内才能被笔记本访问到,对于范围之外的端口可以使用[rpc_view](http://wiki.baidu.com/display/RPC/rpc_view)或在命令行中使用curl <SERVER-URL>
从浏览器访问:
![img](http://wiki.baidu.com/download/attachments/71337189/image2015-9-27%2023%3A45%3A26.png?version=1&modificationDate=1443368728000&api=v2)
从命令行访问:
![img](http://wiki.baidu.com/download/attachments/71337189/image2015-9-27%2023%3A46%3A48.png?version=1&modificationDate=1443368810000&api=v2)
# 安全模式
出于安全考虑,直接对外服务需要关闭内置服务(包括经过nginx或其他http server转发流量的),具体方法请阅读[这里](http://wiki.baidu.com/pages/viewpage.action?pageId=213828715#id-创建和设置Server-安全模式)
# 主要服务
-
# 其他服务
[version服务](http://brpc.baidu.com:8765/version)可以查看服务器的版本。用户可通过Server::set_version()设置Server的版本,如果用户没有设置,框架会自动为用户生成,规则:`baidu_rpc_server_<service-name1>_<service-name2> ...`
[health服务](http://brpc.baidu.com:8765/health)可以探测服务的存活情况。
[protobufs服务](http://brpc.baidu.com:8765/protobufs)可以查看程序中所有的protobuf结构体。
[vlog服务](http://brpc.baidu.com:8765/vlog)可以查看程序中当前可开启的[VLOG](http://wiki.baidu.com/display/RPC/streaming_log#streaming_log-VLOG)
dir服务可以浏览服务器上的所有文件,这个服务比较敏感,默认关闭。
threads服务可以查看进程内所有线程的运行状况,调用时对程序性能较大,默认关闭。
其他还有一些调试服务,如有需求请联系我们。
\ No newline at end of file
[connections服务](http://brpc.baidu.com:8765/connections)可以查看所有的连接。一个典型的页面如下:
server_socket_count: 5
| CreatedTime | RemoteSide | SSL | Protocol | fd | BytesIn/s | In/s | BytesOut/s | Out/s | BytesIn/m | In/m | BytesOut/m | Out/m | SocketId |
| -------------------------- | ------------------- | ---- | --------- | ---- | --------- | ---- | ---------- | ----- | --------- | ---- | ---------- | ----- | -------- |
| 2015/09/21-21:32:09.630840 | 172.22.38.217:51379 | No | http | 19 | 1300 | 1 | 269 | 1 | 68844 | 53 | 115860 | 53 | 257 |
| 2015/09/21-21:32:09.630857 | 172.22.38.217:51380 | No | http | 20 | 1308 | 1 | 5766 | 1 | 68884 | 53 | 129978 | 53 | 258 |
| 2015/09/21-21:32:09.630880 | 172.22.38.217:51381 | No | http | 21 | 1292 | 1 | 1447 | 1 | 67672 | 52 | 143414 | 52 | 259 |
| 2015/09/21-21:32:01.324587 | 127.0.0.1:55385 | No | baidu_std | 15 | 1480 | 20 | 880 | 20 | 88020 | 1192 | 52260 | 1192 | 512 |
| 2015/09/21-21:32:01.325969 | 127.0.0.1:55387 | No | baidu_std | 17 | 4016 | 40 | 1554 | 40 | 238879 | 2384 | 92660 | 2384 | 1024 |
channel_socket_count: 1
| CreatedTime | RemoteSide | SSL | Protocol | fd | BytesIn/s | In/s | BytesOut/s | Out/s | BytesIn/m | In/m | BytesOut/m | Out/m | SocketId |
| -------------------------- | -------------- | ---- | --------- | ---- | --------- | ---- | ---------- | ----- | --------- | ---- | ---------- | ----- | -------- |
| 2015/09/21-21:32:01.325870 | 127.0.0.1:8765 | No | baidu_std | 16 | 1554 | 40 | 4016 | 40 | 92660 | 2384 | 238879 | 2384 | 0 |
channel_short_socket_count: 0
` `
上述信息分为三段:
- 第一段是server接受(accept)的连接。
- 第二段是server与下游的单连接(使用baidu::rpc::Channel建立),fd为-1的是虚拟连接,对应第三段中所有相同RemoteSide的连接。
- 第三段是server与下游的短连接或连接池(pooled connections),这些连接从属于第二段中的相同RemoteSide的虚拟连接。
表格标题的含义:
- RemoteSide : 远端的ip和端口。
- SSL:是否使用SSL加密,若为Yes的话,一般是HTTPS连接。
- Protocol : 使用的协议,可能为baidu_std hulu_pbrpc sofa_pbrpc memcache http public_pbrpc nova_pbrpc nshead_server等。
- fd : file descriptor(文件描述符),可能为-1。
- BytesIn/s : 上一秒读入的字节数
- In/s : 上一秒读入的消息数(消息是对request和response的统称)
- BytesOut/s : 上一秒写出的字节数
- Out/s : 上一秒写出的消息数
- BytesIn/m: 上一分钟读入的字节数
- In/m: 上一分钟读入的消息数
- BytesOut/m: 上一分钟写出的字节数
- Out/m: 上一分钟写出的消息数
- SocketId :内部id,用于debug,用户不用关心。
典型截图分别如下所示:
单连接:![img](http://wiki.baidu.com/download/attachments/165876298/image2016-7-15%2016%3A7%3A41.png?version=1&modificationDate=1468570062000&api=v2)
连接池:![img](http://wiki.baidu.com/download/attachments/165876298/image2016-7-15%2016%3A8%3A40.png?version=1&modificationDate=1468570121000&api=v2)
短连接:![img](http://wiki.baidu.com/download/attachments/165876298/image2016-7-15%2016%3A9%3A1.png?version=1&modificationDate=1468570141000&api=v2)
baidu-rpc可以分析花在等待锁上的时间及发生等待的函数。
# 开启方法
按需开启。无需配置,不依赖tcmalloc,不需要链接frame pointer或libunwind。如果只是baidu-rpc client或没有使用baidu-rpc,看[这里](http://wiki.baidu.com/pages/viewpage.action?pageId=213843633)
# 图示
当很多线程争抢同一把锁时,一些线程无法立刻获得锁,而必须睡眠直到某个线程退出临界区。这个争抢过程我们称之为**contention**。在多核机器上,当多个线程需要操作同一个资源却被一把锁挡住时,便无法充分发挥多个核心的并发能力。现代OS通过提供比锁更底层的同步原语,使得无竞争锁完全不需要系统调用,只是一两条wait-free,耗时10-20ns的原子操作,非常快。而锁一旦发生竞争,一些线程就要陷入睡眠,再次醒来触发了OS的调度代码,代价至少为3-5us。所以让锁尽量无竞争,让所有线程“一起飞”是需要高性能的server的永恒话题。
r31906后baidu-rpc支持contention profiler,可以分析在等待锁上花费了多少时间。等待过程中线程是睡着的不会占用CPU,所以contention profiler中的时间并不是cpu时间,也不会出现在[cpu profiler](http://wiki.baidu.com/display/RPC/cpu+profiler)中。cpu profiler可以抓到特别频繁的锁(以至于花费了很多cpu),但耗时真正巨大的临界区往往不是那么频繁,而无法被cpu profiler发现。**contention profiler和cpu profiler好似互补关系,前者分析等待时间(被动),后者分析忙碌时间。**还有一类由用户基于condition或sleep发起的主动等待时间,无需分析。
目前contention profiler支持pthread_mutex_t(非递归)和bthread_mutex_t,开启后每秒最多采集1000个竞争锁,这个数字由[参数bvar_collector_expected_per_second](http://brpc.baidu.com:8765/flags/bvar_collector_expected_per_second)控制(同时影响rpc_dump)。如果一秒内竞争锁的次数N超过了1000,那么每把锁会有1000/N的概率被采集。在我们的各类测试场景中(qps在10万-60万不等)没有观察到被采集程序的性能有明显变化。
我们通过实际例子来看下如何使用contention profiler,点击“contention”按钮(more左侧)后就会开启默认10秒的分析过程。下图是[libraft](http://wiki.baidu.com/display/RAFT/RAFT)中的一个示例程序的锁状况,这个程序是3个节点复制组的leader,qps在10-12万左右。左上角的**Total seconds: 2.449**是采集时间内(10秒)在锁上花费的所有等待时间。注意是“等待”,无竞争的锁不会被采集也不会出现在下图中。顺着箭头往下走能看到每份时间来自哪些函数。
![img](http://wiki.baidu.com/download/attachments/165876314/screencapture-10-81-3-185-8101-hotspots-contention-1453209162877.png?version=1&modificationDate=1453212153000&api=v2)
上图有点大,让我们放大一个局部看看。下图红框中的0.768是这个局部中最大的数字,它代表raft::LogManager::get_entry在等待涉及到bvar::detail::UniqueLockBase的函数上共等待了0.768秒(10秒内)。我们如果觉得这个时间不符合预期,就可以去排查代码。
![img](http://wiki.baidu.com/download/attachments/165876314/image2016-1-19%2022%3A13%3A26.png?version=1&modificationDate=1453212828000&api=v2)
点击上方的count选择框,可以查看锁的竞争次数。选择后左上角变为了**Total samples: 439026**,代表采集时间内总共的锁竞争次数(估算)。图中箭头上的数字也相应地变为了次数,而不是时间。对比同一份结果的时间和次数,可以更深入地理解竞争状况。
![img](http://wiki.baidu.com/download/attachments/165876314/image2016-1-19%2022%3A17%3A40.png?version=1&modificationDate=1453213082000&api=v2)
\ No newline at end of file
baidu-rpc可以分析程序中的热点函数。
# 开启方法
1. 在COMAKE中增加`CONFIGS('``thirdsrc/tcmalloc@2.5.0.5977``', Libraries('libtcmalloc_and_profiler.a'))`
1. 这么写也开启了tcmalloc,不建议单独链接cpu profiler而不链接tcmalloc,可能越界访问导致[crash](https://code.google.com/p/gperftools/source/browse/README#sl_svn1035d5c18f64d114ac790b92a96f3b3a1a301eb9_207)**。**可能由于tcmalloc不及时归还内存,越界访问不会crash。
2. 这个版本的tcmalloc使用frame pointer而不是libunwind回溯栈,请确保在CXXFLAGS或CFLAGS中加上`-fno-omit-frame-pointer`,否则函数间的调用关系会丢失,最后产生的图片中都是彼此独立的函数方框。
2. 定义宏BAIDU_RPC_ENABLE_CPU_PROFILER。在COMAKE中加入`CXXFLAGS('-DBAIDU_RPC_ENABLE_CPU_PROFILER')`
3. 如果只是baidu-rpc client或没有使用baidu-rpc,看[这里](http://wiki.baidu.com/pages/viewpage.action?pageId=213843633)
注意要关闭Server端的认证,否则可能会看到这个:
```
$ tools/pprof --text localhost:9002/pprof/profile
Use of uninitialized value in substitution (s///) at tools/pprof line 2703.
http://localhost:9002/profile/symbol doesn't exist
```
server端可能会有这样的日志:
```
FATAL: 12-26 10:01:25: * 0 [src/baidu/rpc/policy/giano_authenticator.cpp:65][4294969345] Giano fails to verify credentical, 70003
WARNING: 12-26 10:01:25: * 0 [src/baidu/rpc/input_messenger.cpp:132][4294969345] Authentication failed, remote side(127.0.0.1:22989) of sockfd=5, close it
```
# 图示
下图是一次运行cpu profiler后的结果:
- 左上角是总体信息,包括时间,程序名,总采样数等等。
- View框中可以选择查看之前运行过的profile结果,Diff框中可选择查看和之前的结果的变化量,重启后清空。
- 代表函数调用的方框中的字段从上到下依次为:函数名,这个函数本身(除去所有子函数)占的采样数和比例,这个函数及调用的所有子函数累计的采样数和比例。采样数越大框越大。
- 方框之间连线上的数字表示被采样到的上层函数对下层函数的调用数,数字越大线越粗。
热点分析一般开始于找到最大的框最粗的线考察其来源及去向。
cpu profiler的原理是在定期被调用的SIGPROF handler中采样所在线程的栈,由于handler(在linux 2.6后)会被随机地摆放于活跃线程的栈上运行,cpu profiler在运行一段时间后能以很大的概率采集到所有活跃线程中的活跃函数,最后根据栈代表的函数调用关系汇总为调用图,并把地址转换成符号,这就是我们看到的结果图了。采集频率由环境变量CPUPROFILE_FREQUENCY控制,默认100,即每秒钟100次或每10ms一次。。在实践中cpu profiler对原程序的影响不明显。
![img](http://wiki.baidu.com/download/attachments/165876310/image2016-1-19%2023%3A28%3A21.png?version=1&modificationDate=1453217323000&api=v2)
你也可以使用[public/baidu-rpc/tools/pprof](https://svn.baidu.com/public/trunk/baidu-rpc/tools/pprof)或gperftools中的pprof进行profiling。
比如`pprof --text localhost:9002 --seconds=5`的意思是统计运行在本机9002端口的server的cpu情况,时长5秒。一次运行的例子如下:
```
$ tools/pprof --text 0.0.0.0:9002 --seconds=5
Gathering CPU profile from http://0.0.0.0:9002/pprof/profile?seconds=5 for 5 seconds to
/home/gejun/pprof/echo_server.1419501210.0.0.0.0
Be patient...
Wrote profile to /home/gejun/pprof/echo_server.1419501210.0.0.0.0
Removing funlockfile from all stack traces.
Total: 2946 samples
1161 39.4% 39.4% 1161 39.4% syscall
248 8.4% 47.8% 248 8.4% baidu::bthread::TaskControl::steal_task
227 7.7% 55.5% 227 7.7% writev
87 3.0% 58.5% 88 3.0% ::cpp_alloc
74 2.5% 61.0% 74 2.5% __read_nocancel
46 1.6% 62.6% 48 1.6% tc_delete
42 1.4% 64.0% 42 1.4% baidu::rpc::Socket::Address
41 1.4% 65.4% 41 1.4% epoll_wait
35 1.2% 66.6% 35 1.2% memcpy
33 1.1% 67.7% 33 1.1% __pthread_getspecific
33 1.1% 68.8% 33 1.1% baidu::rpc::Socket::Write
33 1.1% 69.9% 33 1.1% epoll_ctl
28 1.0% 70.9% 42 1.4% baidu::rpc::policy::ProcessRpcRequest
27 0.9% 71.8% 27 0.9% baidu::IOBuf::_push_back_ref
27 0.9% 72.7% 27 0.9% baidu::bthread::TaskGroup::ending_sched
```
省略–text进入交互模式,如下图所示:
```
$ tools/pprof localhost:9002 --seconds=5
Gathering CPU profile from http://0.0.0.0:9002/pprof/profile?seconds=5 for 5 seconds to
/home/gejun/pprof/echo_server.1419501236.0.0.0.0
Be patient...
Wrote profile to /home/gejun/pprof/echo_server.1419501236.0.0.0.0
Removing funlockfile from all stack traces.
Welcome to pprof! For help, type 'help'.
(pprof) top
Total: 2954 samples
1099 37.2% 37.2% 1099 37.2% syscall
253 8.6% 45.8% 253 8.6% baidu::bthread::TaskControl::steal_task
240 8.1% 53.9% 240 8.1% writev
90 3.0% 56.9% 90 3.0% ::cpp_alloc
67 2.3% 59.2% 67 2.3% __read_nocancel
47 1.6% 60.8% 47 1.6% baidu::IOBuf::_push_back_ref
42 1.4% 62.2% 56 1.9% baidu::rpc::policy::ProcessRpcRequest
41 1.4% 63.6% 41 1.4% epoll_wait
38 1.3% 64.9% 38 1.3% epoll_ctl
37 1.3% 66.1% 37 1.3% memcpy
35 1.2% 67.3% 35 1.2% baidu::rpc::Socket::Address
```
\ No newline at end of file
baidu-rpc使用gflags管理配置。如果你的程序也使用gflags,那么你应该已经可以修改和baidu-rpc相关的flags,你可以浏览[flags服务](http://brpc.baidu.com:8765/flags)了解每个flag的具体功能。如果你的程序还没有使用gflags,我们建议你使用,原因如下:
- 命令行和文件均可传入,前者方便做测试,后者适合线上运维。放在文件中的gflags可以reload。而configure只支持从文件读取配置。
- 你可以在浏览器中查看baidu-rpc服务器中所有gflags,并对其动态修改(如果允许的话)。configure不可能做到这点。
- gflags分散在和其作用紧密关联的文件中,更好管理。而使用configure需要聚集到一个庞大的读取函数中。
如果你依赖了baidu-rpc,那么你已经依赖了third-64/gflags,如果你需要依赖某个特定版本的话,在COMAKE中加入CONFIGS('third-64/gflags@<specific-version>')。
# Usage of gflags
gflags一般定义在需要它的源文件中。#include <gflags/gflags.h>后在全局scope加入DEFINE_*<type>*(*<name>*, *<default-value>*, *<description>*); 比如:
```c++
#include <gflags/gflags.h>
...
DEFINE_bool(hex_log_id, false, "Show log_id in hexadecimal");
DEFINE_int32(health_check_interval, 3, "seconds between consecutive health-checkings");
```
一般在main函数开头用ParseCommandLineFlags处理程序参数:
```c++
#include <gflags/gflags.h>
...
int main(int argc, char* argv[]) {
google::ParseCommandLineFlags(&argc, &argv, true/*表示把识别的参数从argc/argv中删除*/);
...
}
```
如果要从conf/gflags.conf中加载gflags,则可以加上参数-flagfile=conf/gflags.conf。如果希望默认(什么参数都不加)就从文件中读取,则可以在程序中直接给flagfile赋值,一般这么写
```c++
google::SetCommandLineOption("flagfile", "conf/gflags.conf");
```
程序启动时会检查conf/gflags.conf是否存在,如果不存在则会报错:
```
$ ./my_program
conf/gflags.conf: No such file or directory
```
更具体的使用指南请阅读[官方文档](http://gflags.github.io/gflags/)
# flagfile
在命令行中参数和值之间可不加等号,而在flagfile中一定要加。比如`./myapp -param 7`是ok的,但在`./myapp -flagfile=./gflags.conf`对应的gflags.conf中一定要写成**-param=7****--param=7**,否则就不正确且不会报错。
在命令行中字符串可用单引号或双引号包围,而在flagfile中不能加。比如`./myapp -name="tom"``./myapp -name='tom'`都是ok的,但在`./myapp -flagfile=./gflags.conf`对应的gflags.conf中一定要写成**-name=tom****--name=tom**,如果写成-name="tom"的话,引号也会作为值的一部分。配置文件中的值可以有空格,比如gflags.conf中写成-name=value with spaces是ok的,参数name的值就是value with spaces,而在命令行中要用引号括起来。
flagfile中参数可由单横线(如-foo)或双横线(如--foo)打头,但不能以三横线或更多横线打头,否则的话是无效参数且不会报错!
flagfile中以`#开头的行被认为是注释。开头的空格和空白行都会被忽略。`
flagfile中可以使用`--flagfile包含另一个flagfile。`
# Change gflag on-the-fly
[flags服务](http://brpc.baidu.com:8765/flags)可以查看服务器进程中所有的gflags。修改过的flags会以红色高亮。“修改过”指的是修改这一行为,即使再改回默认值,仍然会显示为红色。
/flags:列出所有的gflags
/flags/NAME:查询名字为NAME的gflag
/flags/NAME1,NAME2,NAME3:查询名字为NAME1或NAME2或NAME3的gflag
/flags/foo*,b$r:查询名字与某一统配符匹配的gflag,注意用$代替?匹配单个字符,因为?在url中有特殊含义。
访问/flags/NAME?setvalue=VALUE即可动态修改一个gflag的值,validator会被调用。
Icon
为了防止误修改,需要动态修改的gflag必须有validator,显示此类gflag名字时有(R)后缀。
![img](http://wiki.baidu.com/download/thumbnails/71337189/image2015-9-21%2021%3A49%3A48.png?version=1&modificationDate=1442843389000&api=v2)
*修改成功后会显示如下信息*
![img](http://wiki.baidu.com/download/attachments/37774685/image2015-2-22%2012%3A30%3A54.png?version=1&modificationDate=1424579454000&api=v2)
*尝试修改不允许修改的gflag会显示如下错误信息*
![img](http://wiki.baidu.com/download/attachments/37774685/image2015-2-22%2012%3A30%3A1.png?version=1&modificationDate=1424579401000&api=v2)
*设置一个不允许的值会显示如下错误(flag值不会变化)*
![img](http://wiki.baidu.com/download/attachments/37774685/image2015-2-22%2012%3A35%3A9.png?version=1&modificationDate=1424579709000&api=v2)
r31658之后支持可视化地修改,在浏览器上访问时将看到(R)下多了下划线:
![img](http://wiki.baidu.com/download/attachments/71337189/image2015-12-24%2022%3A55%3A29.png?version=1&modificationDate=1450968931000&api=v2)
点击后在一个独立页面可视化地修改对应的flag:
![img](http://wiki.baidu.com/download/attachments/71337189/image2015-12-24%2022%3A56%3A3.png?version=1&modificationDate=1450968965000&api=v2)
填入true后确定:
![img](http://wiki.baidu.com/download/attachments/71337189/image2015-12-24%2022%3A57%3A13.png?version=1&modificationDate=1450969035000&api=v2)
返回/flags可以看到对应的flag已经被修改了:
![img](http://wiki.baidu.com/download/attachments/71337189/image2015-12-24%2022%3A57%3A57.png?version=1&modificationDate=1450969079000&api=v2)
关于重载gflags,重点关注:
- 避免在一段代码中多次调用同一个gflag,应把该gflag的值保存下来并调用该值。因为gflag的值随时可能变化,而产生意想不到的结果。
- 使用google::GetCommandLineOption()访问string类型的gflag,直接访问是线程不安全的。
- 处理逻辑和副作用应放到validator里去。比如修改FLAGS_foo后得更新另一处的值,如果只是写在程序初始化的地方,而不是validator里,那么重载时这段逻辑就运行不到了。
如果你确认某个gflag不需要额外的线程同步和处理逻辑就可以重载,那么可以用如下方式为其注册一个总是返回true的validator:
```c++
DEFINE_bool(hex_log_id, false, "Show log_id in hexadecimal");
BAIDU_RPC_VALIDATE_GFLAG(hex_log_id, baidu::rpc::PassValidate/*always true*/);
```
这个flag是单纯的开关,修改后不需要更新其他数据(没有处理逻辑),代码中前面看到true后面看到false也不会产生什么后果(不需要线程同步),所以我们让其默认可重载。
对于int32和int64类型,有一个判断是否为正数的常用validator:
```c++
DEFINE_int32(health_check_interval, 3, "seconds between consecutive health-checkings");
BAIDU_RPC_VALIDATE_GFLAG(health_check_interval, baidu::rpc::PositiveInteger);
```
以上操作都可以在命令行中进行:
```shell
$ curl brpc.baidu.com:8765/flags/health_check_interval
Name | Value | Description | Defined At
---------------------------------------
health_check_interval (R) | 3 | seconds between consecutive health-checkings | src/baidu/rpc/socket_map.cpp
```
1.0.251.32399后增加了-immutable_flags,打开后所有的gflags将不能被动态修改。当一个服务对某个gflag值比较敏感且不希望在线上被误改,可打开这个开关。打开这个开关的同时也意味着你无法动态修改线上的配置,每次修改都要重启程序,对于还在调试阶段或待收敛阶段的程序不建议打开。
\ No newline at end of file
baidu-rpc可以分析内存是被哪些函数占据的。heap profiler的原理是每分配满一些内存就采样调用处的栈,“一些”由环境变量TCMALLOC_SAMPLE_PARAMETER控制,默认524288,即512K字节。根据栈表现出的函数调用关系汇总为我们看到的结果图。在实践中heap profiler对原程序的影响不明显。
# 开启方法
1. 在COMAKE中增加`CONFIGS('thirdsrc/tcmalloc@2.5.0.5977')`。如果要同时使用cpu profiler,加上`Libraries('libtcmalloc_and_profiler.a')`
1. 这个版本的tcmalloc使用frame pointer而不是libunwind回溯栈,请确保在CXXFLAGS或CFLAGS中加上`-fno-omit-frame-pointer`,否则函数间的调用关系会丢失,最后产生的图片中都是彼此独立的函数方框。
2. 在COMAKE的CPPFLAGS中增加`-DBAIDU_RPC_ENABLE_HEAP_PROFILER`
3. 在shell中`export TCMALLOC_SAMPLE_PARAMETER=524288`。该变量指每分配这么多字节内存时做一次统计,默认为0,代表不开启内存统计。[官方文档](http://gperftools.googlecode.com/svn/trunk/doc/tcmalloc.html)建议设置为524288。这个变量也可在运行前临时设置,如`TCMALLOC_SAMPLE_PARAMETER=524288 ./server`。如果没有这个环境变量,可能会看到这样的结果:
```
$ tools/pprof --text localhost:9002/pprof/heap
Fetching /pprof/heap profile from http://localhost:9002/pprof/heap to
/home/gejun/pprof/echo_server.1419559063.localhost.pprof.heap
Wrote profile to /home/gejun/pprof/echo_server.1419559063.localhost.pprof.heap
/home/gejun/pprof/echo_server.1419559063.localhost.pprof.heap: header size >= 2**16
```
4. 如果只是baidu-rpc client或没有使用baidu-rpc,看[这里](http://wiki.baidu.com/pages/viewpage.action?pageId=213843633)。
注意要关闭Server端的认证,否则可能会看到这个:
```
$ tools/pprof --text localhost:9002/pprof/heap
Use of uninitialized value in substitution (s///) at tools/pprof line 2703.
http://localhost:9002/pprof/symbol doesn't exist
```
server端可能会有这样的日志:
```
FATAL: 12-26 10:01:25: * 0 [src/baidu/rpc/policy/giano_authenticator.cpp:65][4294969345] Giano fails to verify credentical, 70003
WARNING: 12-26 10:01:25: * 0 [src/baidu/rpc/input_messenger.cpp:132][4294969345] Authentication failed, remote side(127.0.0.1:22989) of sockfd=5, close it
```
# 图示
![img](http://wiki.baidu.com/download/attachments/165876312/image2016-1-19%2023%3A8%3A50.png?version=1&modificationDate=1453216152000&api=v2)
左上角是当前程序通过malloc分配的内存总量,顺着箭头上的数字可以看到内存来自哪些函数。
点击左上角的text选择框可以查看文本格式的结果,有时候这种按分配量排序的形式更方便。
![img](http://wiki.baidu.com/download/attachments/165876312/image2016-1-19%2023%3A12%3A44.png?version=1&modificationDate=1453216386000&api=v2)
左上角的两个选择框作用分别是:
- View:当前正在看的profile。选择<new profile>表示新建一个。新建完毕后,View选择框中会出现新profile,URL也会被修改为对应的地址。这意味着你可以通过粘贴URL分享结果,点击链接的人将看到和你一模一样的结果,而不是重做profiling的结果。你可以在框中选择之前的profile查看。历史profiie保留最近的32个,可通过[--max_profiles_kept](http://brpc.baidu.com:8765/flags/max_profiles_kept)调整。
- Diff:和选择的profile做对比。<none>表示什么都不选。如果你选择了之前的某个profile,那么将看到View框中的profile相比Diff框中profile的变化量。
下图演示了勾选Diff和Text的效果。
![img](http://wiki.baidu.com/download/attachments/37774685/prof.gif?version=1&modificationDate=1494403248000&api=v2)
你也可以使用pprof脚本(public/baidu-rpc/tools/pprof)在命令行中查看文本格式结果:
```
$ tools/pprof --text db-rpc-dev00.db01:8765/pprof/heap
Fetching /pprof/heap profile from http://db-rpc-dev00.db01:8765/pprof/heap to
/home/gejun/pprof/play_server.1453216025.db-rpc-dev00.db01.pprof.heap
Wrote profile to /home/gejun/pprof/play_server.1453216025.db-rpc-dev00.db01.pprof.heap
Adjusting heap profiles for 1-in-524288 sampling rate
Heap version 2
Total: 38.9 MB
35.8 92.0% 92.0% 35.8 92.0% ::cpp_alloc
2.1 5.4% 97.4% 2.1 5.4% base::FlatMap
0.5 1.3% 98.7% 0.5 1.3% base::IOBuf::append
0.5 1.3% 100.0% 0.5 1.3% base::IOBufAsZeroCopyOutputStream::Next
0.0 0.0% 100.0% 0.6 1.5% MallocExtension::GetHeapSample
0.0 0.0% 100.0% 0.5 1.3% ProfileHandler::Init
0.0 0.0% 100.0% 0.5 1.3% ProfileHandlerRegisterCallback
0.0 0.0% 100.0% 0.5 1.3% __do_global_ctors_aux
0.0 0.0% 100.0% 1.6 4.2% _end
0.0 0.0% 100.0% 0.5 1.3% _init
0.0 0.0% 100.0% 0.6 1.5% baidu::rpc::CloseIdleConnections
0.0 0.0% 100.0% 1.1 2.9% baidu::rpc::GlobalUpdate
0.0 0.0% 100.0% 0.6 1.5% baidu::rpc::PProfService::heap
0.0 0.0% 100.0% 1.9 4.9% baidu::rpc::Socket::Create
0.0 0.0% 100.0% 2.9 7.4% baidu::rpc::Socket::Write
0.0 0.0% 100.0% 3.8 9.7% baidu::rpc::Span::CreateServerSpan
0.0 0.0% 100.0% 1.4 3.5% baidu::rpc::SpanQueue::Push
0.0 0.0% 100.0% 1.9 4.8% base::ObjectPool
0.0 0.0% 100.0% 0.8 2.0% base::ResourcePool
0.0 0.0% 100.0% 1.0 2.6% base::iobuf::tls_block
0.0 0.0% 100.0% 1.0 2.6% bthread::TimerThread::Bucket::schedule
0.0 0.0% 100.0% 1.6 4.1% bthread::get_stack
0.0 0.0% 100.0% 4.2 10.8% bthread_id_create
0.0 0.0% 100.0% 1.1 2.9% bvar::Variable::describe_series_exposed
0.0 0.0% 100.0% 1.0 2.6% bvar::detail::AgentGroup
0.0 0.0% 100.0% 0.5 1.3% bvar::detail::Percentile::operator
0.0 0.0% 100.0% 0.5 1.3% bvar::detail::PercentileSamples
0.0 0.0% 100.0% 0.5 1.3% bvar::detail::Sampler::schedule
0.0 0.0% 100.0% 6.5 16.8% leveldb::Arena::AllocateNewBlock
0.0 0.0% 100.0% 0.5 1.3% leveldb::VersionSet::LogAndApply
0.0 0.0% 100.0% 4.2 10.8% pthread_mutex_unlock
0.0 0.0% 100.0% 0.5 1.3% pthread_once
0.0 0.0% 100.0% 0.5 1.3% std::_Rb_tree
0.0 0.0% 100.0% 1.5 3.9% std::basic_string
0.0 0.0% 100.0% 3.5 9.0% std::string::_Rep::_S_create
```
baidu-rpc还提供一个类似的growth profiler分析内存的分配去向(不考虑释放)。
![img](http://wiki.baidu.com/download/attachments/71337189/image2015-10-1%209%3A55%3A9.png?version=1&modificationDate=1443664514000&api=v2)
This diff is collapsed.
# 1.检查工作线程的数量
查看 /vars/bthread_worker_**count** 和 /vars/bthread_worker_**usage**。分别是工作线程的个数,和正在被使用的工作线程个数。
Icon
如果usage和count接近,说明线程不够用了。
比如,下图中有24个工作线程,正在使用的是23.93个,说明所有的工作线程都被打满了,不够用了。
**![img](http://wiki.baidu.com/download/attachments/161461013/image2016-1-8%2017%3A14%3A8.png?version=1&modificationDate=1452244448000&api=v2)**
下图中正在使用的只有2.36个,工作线程明显是足够的。
![img](http://wiki.baidu.com/download/attachments/161461013/image2016-1-8%2017%3A16%3A34.png?version=1&modificationDate=1452244594000&api=v2)
把 /vars/bthread_worker_count;bthread_worker_usage?expand 拼在服务url后直接看到这两幅图,就像[这样](http://brpc.baidu.com:8765/vars/bthread_worker_count;bthread_worker_usage?expand)
# 2.检查CPU的使用程度
查看 /vars/process_core_**count** 和 /vars/process_cpu_**usage**。分别是cpu核心的个数,和正在使用的cpu核数。
Icon
如果usage和count接近,说明CPU不够用了。
下图中cpu核数为24,正在使用的核心数是20.9个,CPU是瓶颈了。
![img](http://wiki.baidu.com/download/attachments/161461013/image2016-1-8%2017%3A28%3A37.png?version=1&modificationDate=1452245317000&api=v2)
下图中正在使用的核心数是2.06,CPU是够用的。
![img](http://wiki.baidu.com/download/attachments/161461013/image2016-1-8%2017%3A26%3A25.png?version=1&modificationDate=1452245185000&api=v2)
# 3.定位问题
如果process_cpu_usage和bthread_worker_usage接近,说明是cpu-bound,工作线程大部分时间在做计算。
如果process_cpu_usage明显小于bthread_worker_usage,说明是io-bound,工作线程大部分时间在阻塞。
1 - process_cpu_usage / bthread_worker_usage就是大约在阻塞上花费的时间比例,比如process_cpu_usage = 2.4,bthread_worker_usage = 18.5,那么工作线程大约花费了87.1% 的时间在阻塞上。
## 3.1 定位cpu-bound问题
原因可能是单机性能不足,或上游分流不均。
### 排除上游分流不均的嫌疑
在不同服务的[vars界面](http://brpc.baidu.com:8765/vars)输入qps,查看不同的qps是否符合预期,就像这样:
![img](http://wiki.baidu.com/download/attachments/161461013/image2016-1-8%2018%3A5%3A40.png?version=1&modificationDate=1452247540000&api=v2)
或者在命令行中用curl直接访问,像这样:
```shell
$ curl brpc.baidu.com:8765/vars/*qps*
bthread_creation_qps : 95
rpc_server_8765_example_echo_service_echo_qps : 57
```
如果不同机器的分流确实不均,且难以解决,可以考虑[限制最大并发](http://wiki.baidu.com/pages/viewpage.action?pageId=213828715#id-创建和设置Server-限制最大并发)
### 优化单机性能
请使用[CPU profiler](http://wiki.baidu.com/display/RPC/cpu+profiler)分析程序的热点,用数据驱动优化。一般来说一个卡顿的cpu-bound程序一般能看到显著的热点。
## 3.2 定位io-bound问题
原因可能有:
- 线程确实配少了
- 访问下游服务的client不支持bthread,且延时过长
- 阻塞来自程序内部的锁,IO等等。
如果阻塞无法避免,考虑用异步。
### 排除工作线程数不够的嫌疑
如果线程数不够,你可以尝试动态调大工作线程数,切换到/flags页面,点击bthread_concurrency右边的(R):
![img](http://wiki.baidu.com/download/attachments/161461013/image2016-1-8%2017%3A35%3A54.png?version=1&modificationDate=1452245754000&api=v2)
进入后填入新的线程数确认即可:
![img](http://wiki.baidu.com/download/attachments/161461013/image2016-1-8%2017%3A36%3A48.png?version=1&modificationDate=1452245808000&api=v2)
回到flags界面可以看到bthread_concurrency已变成了新值。
![img](http://wiki.baidu.com/download/attachments/161461013/image2016-1-8%2017%3A37%3A33.png?version=1&modificationDate=1452245853000&api=v2)
不过,调大线程数未必有用。如果工作线程是由于访问下游而大量阻塞,调大工作线程数是没有用的。因为真正的瓶颈在于后端的,调大线程后只是让每个线程的阻塞时间变得更长。
比如在我们这的例子中,调大线程后新增的工作线程仍然被打满了。
![img](http://wiki.baidu.com/download/attachments/161461013/image2016-1-8%2017%3A39%3A37.png?version=1&modificationDate=1452245977000&api=v2)
### 排除锁的嫌疑
如果程序被某把锁挡住了,也可能呈现出“io-bound”的特征。先用[contention profiler](http://wiki.baidu.com/display/RPC/contention+profiler)排查锁的竞争状况。
### 使用rpcz
rpcz可以帮助你看到最近的所有请求,和处理它们时在每个阶段花费的时间(单位都是微秒)。
![img](http://wiki.baidu.com/download/attachments/161461013/image2016-1-8%2018%3A14%3A8.png?version=1&modificationDate=1452248048000&api=v2)
点击一个span链接后看到该次RPC何时开始,每个阶段花费的时间,何时结束。
![img](http://wiki.baidu.com/download/attachments/161461013/image2016-1-8%2018%3A15%3A7.png?version=1&modificationDate=1452248107000&api=v2)
这是一个典型的server在严重阻塞的例子。从接收到请求到开始运行花费了20ms,说明server已经没有足够的工作线程来及时完成工作了。
现在这个span的信息比较少,我们去程序里加一些。你可以使用TRACEPRINTF向rpcz打印日志。打印内容会嵌入在rpcz的时间流中。
![img](http://wiki.baidu.com/download/attachments/161461013/image2016-1-8%2018%3A26%3A19.png?version=1&modificationDate=1452248779000&api=v2)
重新运行后,查看一个span,里面的打印内容果然包含了我们增加的TRACEPRINTF。
![img](http://wiki.baidu.com/download/attachments/161461013/image2016-1-8%2018%3A28%3A27.png?version=1&modificationDate=1452248908000&api=v2)
在运行到第一条TRACEPRINTF前,用户回调已运行了2051微秒(假设这符合我们的预期),紧接着foobar()却花费了8036微秒,我们本来以为这个函数会很快返回的。范围进一步缩小了。
重复这个过程,直到找到那个造成问题的函数。
### 使用bvar
TRACEPRINTF主要适合若干次的函数调用,如果一个函数调用了很多次,或者函数本身开销很小,每次都往rpcz打印日志是不合适的。这时候你可以使用bvar。
[bvar](http://wiki.baidu.com/display/RPC/bvar)是一个多线程下的计数库,可以以极低的开销统计用户递来的数值,相比“打日志大法”几乎不影响程序行为。你不用完全了解bvar的完整用法,只要使用bvar::LatencyRecorder即可。
仿照如下代码对foobar的运行时间进行监控。
```c++
#include <base/time.h>
#include <bvar/bvar.h>
bvar::LatencyRecorder g_foobar_latency("foobar");
...
void search() {
...
base::Timer tm;
tm.start();
foobar();
tm.stop();
g_foobar_latency << tm.u_elapsed();
...
}
```
重新运行程序后,在vars的搜索框中键入foobar,显示如下:
![img](http://wiki.baidu.com/download/attachments/161461013/image2016-1-8%2018%3A41%3A11.png?version=1&modificationDate=1452249671000&api=v2)
点击一个bvar可以看到动态图,比如点击cdf后看到
![img](http://wiki.baidu.com/download/attachments/161461013/image2016-1-8%2018%3A42%3A46.png?version=1&modificationDate=1452249766000&api=v2)
根据延时的分布,你可以推测出这个函数的整体行为,对大多数请求表现如何,对长尾表现如何。
你可以在子函数中继续这个过程,增加更多bvar,并比对不同的分布,最后定位来源。
### 只使用了baidu-rpc client
得打开dummy server提供内置服务,方法见[这里](http://wiki.baidu.com/pages/viewpage.action?pageId=213843633)
\ No newline at end of file
This diff is collapsed.
用户能通过/rpcz看到最近请求的详细信息,并可以插入注释(annotation),不同于tracing system(如[dapper](http://static.googleusercontent.com/media/research.google.com/en//pubs/archive/36356.pdf))以全局视角看到整体系统的延时分布,rpcz更多是一个调试工具,虽然角色有所不同,但在baidu-rpc中rpcz和tracing的数据来源是一样的。当每秒请求数小于1万时,rpcz会记录所有的请求,超过1万时,rpcz会随机忽略一些请求把采样数控制在1万左右。rpcz可以淘汰时间窗口之前的数据,通过-span_keeping_seconds选项设置,默认1小时。[一个长期运行的例子](http://brpc.baidu.com:8765/rpcz)
关于开销:我们的实现完全规避了线程竞争,开销极小,在qps 30万的测试场景中,观察不到明显的性能变化,对大部分应用而言应该是“free”的。即使采集了几千万条请求,rpcz也不会增加很多内存,一般在50兆以内。rpcz会占用一些磁盘空间(就像日志一样),如果设定为存一个小时的数据,一般在几百兆左右。
## 开关方法
默认不开启,加入[-enable_rpcz](http://brpc.baidu.com:8765/flags/*rpcz*)选项会在启动后开启。
若启动时未加-enable_rpcz,则可在启动后访问SERVER_URL/rpcz/enable动态开启rpcz,访问SERVER_URL/rpcz/disable则关闭,这两个链接等价于访问SERVER_URL/flags/enable_rpcz?setvalue=true和SERVER_URL/flags/enable_rpcz?setvalue=false。在r31010之后,rpc在html版本中增加了一个按钮可视化地开启和关闭。
![img](http://wiki.baidu.com/download/attachments/71337189/image2015-12-24%2013%3A20%3A38.png?version=1&modificationDate=1450934438000&api=v2)
![img](http://wiki.baidu.com/download/attachments/71337189/image2015-12-24%2013%3A21%3A34.png?version=1&modificationDate=1450934494000&api=v2)
如果只是baidu-rpc client或没有使用baidu-rpc,看[这里](http://wiki.baidu.com/pages/viewpage.action?pageId=213843633)
## 数据展现
/rpcz展现的数据分为两层。
### 第一层
看到最新请求的概况,点击链接进入第二层。
![img](http://wiki.baidu.com/download/attachments/37774685/image2015-1-21%2020%3A20%3A53.png?version=1&modificationDate=1421842854000&api=v2)
### 第二层
看到某系列(trace)或某个请求(span)的详细信息。一般通过点击链接进入,也可以把trace=和span=作为query-string拼出链接
![img](http://wiki.baidu.com/download/attachments/37774685/image2015-1-21%2020%3A23%3A35.png?version=1&modificationDate=1421843015000&api=v2)
内容说明:
- 时间分为了绝对时间(如2015/01/21-20:20:30.817392,小数点后精确到微秒)和前一个时间的差值(如. 19,代表19微秒)。
- trace=ID有点像“session id”,对应一个系统中完成一次对外服务牵涉到的所有服务,即上下游server都共用一个trace-id。span=ID对应一个server或client中一个请求的处理过程。trace-id和span-id在概率上唯一。
- 第一层页面中的request=和response=后的是数据包的字节数,包括附件但不包括协议meta。第二层中request和response的字节数一般在括号里,比如"Responded(13)"中的13。
- 点击链接可能会访问其他server上的rpcz,点浏览器后退一般会返回到之前的页面位置。
- I'm the last call, I'm about to ...都是用户的annotation。
## Annotation
只要你使用了baidu-rpc,就可以使用[TRACEPRINTF](https://svn.baidu.com/public/trunk/baidu-rpc/src/baidu/rpc/traceprintf.h)打印内容到事件流中,比如:
```c++
TRACEPRINTF("Hello rpcz %d", 123);
```
这条annotation会按其发生时间插入到对应请求的rpcz中。从这个角度看,rpcz是请求级的日志。如果你用TRACEPRINTF打印了沿路的上下文,便可看到请求在每个阶段停留的时间,牵涉到的数据集和参数。这是个很有用的功能。
\ No newline at end of file
This diff is collapsed.
This diff is collapsed.
Markdown is supported
0% or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment