k8s环境下应用句柄数过大的原因定位

背景

运维发现部署在k8s环境上的应用A比在环境E中的句柄数要多十倍. 让我协助排查下.

排查过程

初步分析

通过lsof 命令看了下进程打开的文件句柄,发现其中pipe出现了很多次,大概1300次, 而相对应的stable环境中的应用A打开的pipe为130次

问题:

为什么会有这么多pipe,是谁创建的,为什么要创建?

我并不是很熟悉java中涉及pipe的场景,所以根本就不知道谁会创建pipe,只能先找到所有会使用pipe的地方,然后在进一步分析.

如何找到所有使用pipe的地方?

想想貌似只能拦截下pipe的调用,一旦发现有进程调pipe,就记录下调用栈,通过这样的方式应该就可以收集到部分pipe的使用场景了.

由于不知道是哪些java的api会调用pipe操作,在java层面进行拦截是不可能的了,只能在系统层进行尝试了.

鉴于pipe是一个system call, 可以考虑通过strace -e trace=pipe 进行跟踪。

不过由于strace仅仅是负责跟踪,在我们拿到相应进程号之后再去查看调用栈的时候可能已经太迟了。 所以该方法没啥用.

可能的思路

能够拦截特定调用,在拦截到后又能够执行特定action的工具,听说过的有以下几种:

  1. dtrace

    不熟悉,看了下文档用起来很麻烦的样子

  2. 使用linux LD_PRELOAD机制增强pipe调用.

    只是个思路,或许可行

  3. gdb

    相对熟悉一些,决定用这个.

gdb的排查步骤

  1. 使用gdb启动应用

    gdb --args java /var/www/xxx/target/XXXX.jar
    
  2. 拦截pipe的断点

    (gdb) catch syscall pipe
    
    
  3. 忽略SIGSEGV信号

    (gdb) handle SIGSEGV nostop noprint pass
    

    为什么要做这个?看这个 : https://neugens.wordpress.com/2015/02/26/debugging-the-jdk-with-gdb/

  4. 执行程序

    (gdb) run
    当java程序调用pipe时,程序就会暂停下来,等待用户指令.
    
    
  5. 等待捕获pipe调用事件

  6. 捕获pipe调用事件

    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)
    
    
  7. 执行info thread 查看下当前的线程如下:

    
    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这个线程号.

  8. 执行gcore dump下当前的内存镜像

    (gdb) gcore
    Saved corefile core.1522
    

    为啥要gcore ,因为在默认的gdb环境下,看不到java的调用栈. 不过有人做了脚本支持在gdb下支持查看java的调用栈,详见http://mail.openjdk.java.net/pipermail/jdk9-dev/2016-May/004379.html

  9. 使用 jstack java core.1522 解析core文件中的调用栈.

    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线程的调用栈如上. (此时看到了java层面调用pipe的地方,也许是java中唯一与pipe发生交互的地方,也许不是,继续采集几个样本看看...).

  10. 执行cont,不一会又会捕捉到pipe调用事件, 重复8,9 步几次.

    观察到几乎所有的pipe操作都是sun.nio.ch.IOUtil.makePipe 触发的,而上游都由Netty的NioEventLoopGroup触发.

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);// 这里每次调用创建一个pipe。 如果循环很大的话,是可能创建很多pipe的.
                success = true;
            }
        }
        ...
} 

查看下nThreads的赋值逻辑如下:

如果调用方有指定,则使用指定值,否则为cpu数*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);
    }
}

结论

从代码的分析结果来看,怀疑是k8s环境中cpu核数过多导致。
查看k8s环境中应用所在容器的cpu数,为20是环境E中cpu数的10倍。
至此, k8s环境中句柄数过大的原因算是清楚啦.

遗留问题

  1. 为什么用epoll的时候会触发pipe的创建?
    Java 中的Selector 同时定义了select和wakeup两个方法.
    当线程阻塞在select()方法时,可以通过wakeup方法进行唤醒.
    在Linux下, 系统底层是没有提供任何唤醒机制的. java在实现时使用了一个技巧,即创建一个管道,将管道的读事件注册到epoll中, wakeup方法中向管道写入一字节的数据来触发epoll的返回.
    相关代码:
    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

最后编辑于
©著作权归作者所有,转载或内容合作请联系作者
  • 序言:七十年代末,一起剥皮案震惊了整个滨河市,随后出现的几起案子,更是在滨河造成了极大的恐慌,老刑警刘岩,带你破解...
    沈念sama阅读 221,888评论 6 515
  • 序言:滨河连续发生了三起死亡事件,死亡现场离奇诡异,居然都是意外死亡,警方通过查阅死者的电脑和手机,发现死者居然都...
    沈念sama阅读 94,677评论 3 399
  • 文/潘晓璐 我一进店门,熙熙楼的掌柜王于贵愁眉苦脸地迎上来,“玉大人,你说我怎么就摊上这事。” “怎么了?”我有些...
    开封第一讲书人阅读 168,386评论 0 360
  • 文/不坏的土叔 我叫张陵,是天一观的道长。 经常有香客问我,道长,这世上最难降的妖魔是什么? 我笑而不...
    开封第一讲书人阅读 59,726评论 1 297
  • 正文 为了忘掉前任,我火速办了婚礼,结果婚礼上,老公的妹妹穿的比我还像新娘。我一直安慰自己,他们只是感情好,可当我...
    茶点故事阅读 68,729评论 6 397
  • 文/花漫 我一把揭开白布。 她就那样静静地躺着,像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上,一...
    开封第一讲书人阅读 52,337评论 1 310
  • 那天,我揣着相机与录音,去河边找鬼。 笑死,一个胖子当着我的面吹牛,可吹牛的内容都是我干的。 我是一名探鬼主播,决...
    沈念sama阅读 40,902评论 3 421
  • 文/苍兰香墨 我猛地睁开眼,长吁一口气:“原来是场噩梦啊……” “哼!你这毒妇竟也来了?” 一声冷哼从身侧响起,我...
    开封第一讲书人阅读 39,807评论 0 276
  • 序言:老挝万荣一对情侣失踪,失踪者是张志新(化名)和其女友刘颖,没想到半个月后,有当地人在树林里发现了一具尸体,经...
    沈念sama阅读 46,349评论 1 318
  • 正文 独居荒郊野岭守林人离奇死亡,尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 38,439评论 3 340
  • 正文 我和宋清朗相恋三年,在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 40,567评论 1 352
  • 序言:一个原本活蹦乱跳的男人离奇死亡,死状恐怖,灵堂内的尸体忽然破棺而出,到底是诈尸还是另有隐情,我是刑警宁泽,带...
    沈念sama阅读 36,242评论 5 350
  • 正文 年R本政府宣布,位于F岛的核电站,受9级特大地震影响,放射性物质发生泄漏。R本人自食恶果不足惜,却给世界环境...
    茶点故事阅读 41,933评论 3 334
  • 文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹,春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 32,420评论 0 24
  • 文/苍兰香墨 我抬头看了看天上的太阳。三九已至,却和暖如春,着一层夹袄步出监牢的瞬间,已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 33,531评论 1 272
  • 我被黑心中介骗来泰国打工, 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留,地道东北人。 一个月前我还...
    沈念sama阅读 48,995评论 3 377
  • 正文 我出身青楼,却偏偏与公主长得像,于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子,可洞房花烛夜当晚...
    茶点故事阅读 45,585评论 2 359

推荐阅读更多精彩内容