背景
運(yùn)維發(fā)現(xiàn)部署在k8s環(huán)境上的應(yīng)用A比在環(huán)境E中的句柄數(shù)要多十倍. 讓我協(xié)助排查下.
排查過程
初步分析
通過lsof 命令看了下進(jìn)程打開的文件句柄,發(fā)現(xiàn)其中pipe出現(xiàn)了很多次,大概1300次, 而相對(duì)應(yīng)的stable環(huán)境中的應(yīng)用A打開的pipe為130次
問題:
為什么會(huì)有這么多pipe,是誰(shuí)創(chuàng)建的叮贩,為什么要?jiǎng)?chuàng)建?
我并不是很熟悉java中涉及pipe的場(chǎng)景璧疗,所以根本就不知道誰(shuí)會(huì)創(chuàng)建pipe酷愧,只能先找到所有會(huì)使用pipe的地方箕昭,然后在進(jìn)一步分析.
如何找到所有使用pipe的地方歌憨?
想想貌似只能攔截下pipe的調(diào)用叶雹,一旦發(fā)現(xiàn)有進(jìn)程調(diào)pipe财饥,就記錄下調(diào)用棧,通過這樣的方式應(yīng)該就可以收集到部分pipe的使用場(chǎng)景了.
由于不知道是哪些java的api會(huì)調(diào)用pipe操作折晦,在java層面進(jìn)行攔截是不可能的了钥星,只能在系統(tǒng)層進(jìn)行嘗試了.
鑒于pipe是一個(gè)system call, 可以考慮通過strace -e trace=pipe 進(jìn)行跟蹤满着。
不過由于strace僅僅是負(fù)責(zé)跟蹤谦炒,在我們拿到相應(yīng)進(jìn)程號(hào)之后再去查看調(diào)用棧的時(shí)候可能已經(jīng)太遲了。 所以該方法沒啥用.
可能的思路
能夠攔截特定調(diào)用风喇,在攔截到后又能夠執(zhí)行特定action的工具宁改,聽說過的有以下幾種:
-
dtrace
不熟悉,看了下文檔用起來(lái)很麻煩的樣子
-
使用linux LD_PRELOAD機(jī)制增強(qiáng)pipe調(diào)用.
只是個(gè)思路,或許可行
-
gdb
相對(duì)熟悉一些,決定用這個(gè).
gdb的排查步驟
-
使用gdb啟動(dòng)應(yīng)用
gdb --args java /var/www/xxx/target/XXXX.jar
-
攔截pipe的斷點(diǎn)
(gdb) catch syscall pipe
-
忽略SIGSEGV信號(hào)
(gdb) handle SIGSEGV nostop noprint pass
為什么要做這個(gè)?看這個(gè) : https://neugens.wordpress.com/2015/02/26/debugging-the-jdk-with-gdb/
-
執(zhí)行程序
(gdb) run 當(dāng)java程序調(diào)用pipe時(shí)魂莫,程序就會(huì)暫停下來(lái)还蹲,等待用戶指令.
等待捕獲pipe調(diào)用事件
-
捕獲pipe調(diào)用事件
Catchpoint 1 (returned from syscall 'pipe'), 0x00007fd22237ff07 in pipe () at ../sysdeps/unix/syscall-template.S:82 82 T_PSEUDO (SYSCALL_SYMBOL, SYSCALL_NAME, SYSCALL_NARGS)
-
執(zhí)行info thread 查看下當(dāng)前的線程如下:
3 Thread 0x7fd2203b7700 (LWP 1630) pthread_cond_wait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:183 * 2 Thread 0x7fd222e81700 (LWP 1605) 0x00007fd22237ff07 in pipe () at ../sysdeps/unix/syscall-template.S:82 1 Thread 0x7fd222e83700 (LWP 1522) 0x00007fd222a5a2fd in pthread_join (threadid=140540505495296, thread_return=0x7ffeaef13e00) at pthread_join.c:89
可以看到線程2是活的。記住1605這個(gè)線程號(hào).
-
執(zhí)行g(shù)core dump下當(dāng)前的內(nèi)存鏡像
(gdb) gcore Saved corefile core.1522
為啥要gcore ,因?yàn)樵谀J(rèn)的gdb環(huán)境下耙考,看不到j(luò)ava的調(diào)用棧. 不過有人做了腳本支持在gdb下支持查看java的調(diào)用棧谜喊,詳見http://mail.openjdk.java.net/pipermail/jdk9-dev/2016-May/004379.html
-
使用 jstack java core.1522 解析core文件中的調(diào)用棧.
Thread 1605: (state = IN_NATIVE) - sun.nio.ch.IOUtil.makePipe(boolean) @bci=0 (Interpreted frame) - sun.nio.ch.EPollSelectorImpl.<init>(java.nio.channels.spi.SelectorProvider) @bci=27, line=65 (Interpreted frame) - sun.nio.ch.EPollSelectorProvider.openSelector() @bci=5, line=36 (Interpreted frame) - io.netty.channel.nio.NioEventLoop.openSelector() @bci=4, line=174 (Interpreted frame) - io.netty.channel.nio.NioEventLoop.<init>(io.netty.channel.nio.NioEventLoopGroup, java.util.concurrent.ThreadFactory, java.nio.channels.spi.SelectorProvider, io.netty.channel.SelectStrategy, io.netty.util.concurrent.RejectedExecutionHandler) @bci=88, line=150 (Interpreted frame) - io.netty.channel.nio.NioEventLoopGroup.newChild(java.util.concurrent.ThreadFactory, java.lang.Object[]) @bci=29, line=103 (Interpreted frame) - io.netty.util.concurrent.MultithreadEventExecutorGroup.<init>(int, java.util.concurrent.ThreadFactory, java.lang.Object[]) @bci=146, line=64 (Interpreted frame) - io.netty.channel.MultithreadEventLoopGroup.<init>(int, java.util.concurrent.ThreadFactory, java.lang.Object[]) @bci=14, line=50 (Interpreted frame) - io.netty.channel.nio.NioEventLoopGroup.<init>(int, java.util.concurrent.ThreadFactory, java.nio.channels.spi.SelectorProvider, io.netty.channel.SelectStrategyFactory) @bci=22, line=70 (Interpreted frame) - io.netty.channel.nio.NioEventLoopGroup.<init>(int, java.util.concurrent.ThreadFactory, java.nio.channels.spi.SelectorProvider) @bci=7, line=65 (Interpreted frame) - io.netty.channel.nio.NioEventLoopGroup.<init>(int, java.util.concurrent.ThreadFactory) @bci=6, line=56 (Interpreted frame) - org.asynchttpclient.netty.channel.ChannelManager.<init>(org.asynchttpclient.AsyncHttpClientConfig, io.netty.util.Timer) @bci=394, line=173 (Interpreted frame) - org.asynchttpclient.DefaultAsyncHttpClient.<init>(org.asynchttpclient.AsyncHttpClientConfig) @bci=73, line=85 (Interpreted frame) ...
可以看到1605線程的調(diào)用棧如上. (此時(shí)看到了java層面調(diào)用pipe的地方,也許是java中唯一與pipe發(fā)生交互的地方倦始,也許不是,繼續(xù)采集幾個(gè)樣本看看...).
-
執(zhí)行cont,不一會(huì)又會(huì)捕捉到pipe調(diào)用事件, 重復(fù)8,9 步幾次.
觀察到幾乎所有的pipe操作都是sun.nio.ch.IOUtil.makePipe 觸發(fā)的斗遏,而上游都由Netty的NioEventLoopGroup觸發(fā).
NioEventLoopGroup代碼分析
翻了下NioEventLoopGroup的代碼,有如下一段:
MultithreadEventLoopGroup.java
protected MultithreadEventExecutorGroup(int nThreads, ThreadFactory threadFactory, Object... args) {
...
for (int i = 0; i < nThreads; i ++) {
boolean success = false;
try {
children[i] = newChild(threadFactory, args);// 這里每次調(diào)用創(chuàng)建一個(gè)pipe。 如果循環(huán)很大的話楣号,是可能創(chuàng)建很多pipe的.
success = true;
}
}
...
}
查看下nThreads的賦值邏輯如下:
如果調(diào)用方有指定最易,則使用指定值怒坯,否則為cpu數(shù)*2. 代碼如下
MultithreadEventLoopGroup.java
static {
DEFAULT_EVENT_LOOP_THREADS = Math.max(1, SystemPropertyUtil.getInt(
"io.netty.eventLoopThreads", NettyRuntime.availableProcessors() * 2));
if (logger.isDebugEnabled()) {
logger.debug("-Dio.netty.eventLoopThreads: {}", DEFAULT_EVENT_LOOP_THREADS);
}
}
結(jié)論
從代碼的分析結(jié)果來(lái)看,懷疑是k8s環(huán)境中cpu核數(shù)過多導(dǎo)致藻懒。
查看k8s環(huán)境中應(yīng)用所在容器的cpu數(shù)剔猿,為20是環(huán)境E中cpu數(shù)的10倍。
至此, k8s環(huán)境中句柄數(shù)過大的原因算是清楚啦.
遺留問題
- 為什么用epoll的時(shí)候會(huì)觸發(fā)pipe的創(chuàng)建?
Java 中的Selector 同時(shí)定義了select和wakeup兩個(gè)方法.
當(dāng)線程阻塞在select()方法時(shí)嬉荆,可以通過wakeup方法進(jìn)行喚醒.
在Linux下, 系統(tǒng)底層是沒有提供任何喚醒機(jī)制的. java在實(shí)現(xiàn)時(shí)使用了一個(gè)技巧归敬,即創(chuàng)建一個(gè)管道,將管道的讀事件注冊(cè)到epoll中鄙早, wakeup方法中向管道寫入一字節(jié)的數(shù)據(jù)來(lái)觸發(fā)epoll的返回.
相關(guān)代碼:
EPollSelectorImpl.java
參考資料
https://openresty.org/posts/dynamic-tracing/](https://openresty.org/posts/dynamic-tracing
https://www-zeuthen.desy.de/unix/unixguide/infohtml/gdb/Set-Catchpoints.html#Set-Catchpoints