杨超

杨超的博客

他的个人主页  他的博客

为什么输出效果像挤牙膏?

杨超  2010年08月17日 星期二 22:49 | 2603次浏览 | 0条评论

用户态stdout缓存太小,导致输出效果不好。通过trace工具和分析coreutils、kernel、glibc源代码,抽丝剥茧逐步定位问题直至解决

发现儿童牙膏

 执行date输出的效果是先挤几个字符,再挤几个字符,再……

 

大家都用儿童牙膏吗?

执行ls则不会出现这种情况,即使是ls -l这种刷屏型命令也是一次刷完。

 

难道是挤的方式不同?

通过查看coreutils源代码中ls和date命令的相关代码,发现ls是使用memcpy做输出,date则是调用了很多次fwrite和fputc来一点一点地输出那很少的一行结果。只想知道程序内部调用情况的话使用strace或ltrace即可,前者查看系统调用情况,后者查看库函数调用情况,如果想一起看可以使用ltrace -S。

 

挤的方式对我们获得牙膏有影响吗?

理论上说应该没有影响,因为date调用的fwrite和fputc函数都是带缓存的,多次调用的话会往缓存里写,等缓存满了、文件关闭了或到时间了等等这些情况下再把缓存一次刷往核心态调用sys_write。 实际情况却是ltrace显示sys_write也是一点一点地写,缓存没有起到作用。

 

谁动了我的牙膏?

我们可以测试一下stdout缓存情况,看究竟是什么导致了这个问题,测试程序如下:

 #include<stdio.h>

void pr_stdio(const char *name,FILE *fp)
{
        printf("stream=%s,",name);

        if(fp->_IO_file_flags & _IO_UNBUFFERED)
                printf("unbuffered");                           //非缓存模式
        else if(fp->_IO_file_flags & _IO_LINE_BUF)
                printf("line buffered");                        //行缓存模式
        else printf("fully buffered");                   //全缓存模式

        printf(",buffer size=%d\n",fp->_IO_buf_end - fp->_IO_buf_base);
}

int main(void)
{
        pr_stdio("stdout",stdout);
        return 0;
}

测试显示stdout缓存大小是8 !!!

 

在网上查了半天,只有用户态的修改方式,调用glibc的库函数setbuf或者setvbuf,但是总不能修改所有的应用程序让他们都先改了再用fwrite吧。

 

只有看源代码了,先是在内核里找了半天,毕竟如果是内核出错还好改一点,如果glibc有问题就麻烦了。在初始化代码里找了半天,内核里就没有控制stdout或fd为1的文件缓存大小的相关变量。

 

这时一个测试程序道破天机,如果直接一开始就输出stdout的缓存大小,会显示为零,只有在用了一次printf或者fwrite这种带缓存的库函数后,缓存才会有正值,这说明在第一次调用带缓存库函数的时候初始化了stdout的缓存大小。猛然醒悟,这是用户态缓存。虽然在内核里加个缓存也不是不可以,但是为了改个bug浪费本就紧张的内核资源实在不值得。

 

那么问题就在glibc了,看高手写的代码必须要有连蒙带猜的精神,基本上不会老老实实地一个一个函数调用关系那么清晰,必然有些什么函数指针啊之类的东西来显示人家是高手。

 

以fwrite为例,用sourceinsight把glibc建个工程,搜索fwrite,结果这是个宏,实际调用的是_IO_fwrite。在_IO_fwrite中调用宏_IO_sputn,实际是调用_IO_XSPUTN。_IO_XZPUTN也是个宏,实际上调用 JUMP2(__xsputn, FP, DATA, N) ,最终会调到这个 __xsputn 。搜索 __xsputn 得到JUMP_FIELD(_IO_xsputn_t, __xsputn ),但这是个函数指针定义,初始化在哪里呢?此时用lookup reference已经没有别的收获了。

 

此时要在sourceinsignt的project symbol list中输入 __xsputn ,我们就可以找到一个相似的函数_IO_new_file_xsputn,就把宝押在你身上了。在其中会调用_IO_OVERFLOW,最终落到 __overflow 上。老办法找到一个相似的函数,_IO_new_file_overflow,其中调用_IO_doallocbuf分配缓存。然后又是调用_IO_DOALLOCATE从而落到 __doallocate 上。又是老办法找到一个相似的函数,_IO_file_doallocate。在其中有这样一段代码:

 

  size = _IO_BUFSIZ;
  if (fp->_fileno >= 0 && __builtin_expect (_IO_SYSSTAT (fp, &st), 0) >= 0)
    {
      if (S_ISCHR (st.st_mode))
        {
          /* Possibly a tty.  */
          if (
#ifdef DEV_TTY_P
              DEV_TTY_P (&st) ||
#endif
              isatty (fp->_fileno))
            fp->_flags |= _IO_LINE_BUF;
        }
#if _IO_HAVE_ST_BLKSIZE
      if (st.st_blksize > 0)
        size = st.st_blksize;
#endif
    }
  ALLOC_BUF (p, size, EOF);
  INTUSE(_IO_setb) (fp, p, p + size, 1);

其中使用_IO_SYSSTAT最终调用系统调用fstat,取得磁盘的block size作为缓存的大小,至此问题定性:从核心进行fstat的时候取磁盘块大小有问题!这也得到了ltrace的输出结果的支持。

 

换回成人牙膏

 既然问题已经定位,剩下的便是通过在整个fstat调用流程的各个位置打出调试信息从而确定出错地点。打印的trace信息显示在调用的各个步骤中block size的值都是1024,最后发现是核心态与用户态使用的stat结构有不同,导致读取block size的时候偏移不对,将相关结构进行调整之后,问题得到了解决。

 

我们的目标是,没有蛀牙!

1.看源代码固然好,但是也容易只见树木不见森林,一定要用好调试工具做宏观调控,如gdb,strace,ltrace等等。

2.问题的最终解决方案可能很简单,但是重要的是解决的过程中所得到的分析问题、解决问题的手段和思路。

3.手上握有源代码,就不用再迷茫,在一切可能的地方打印出信息,总能定位出bug

评论

我的评论:

发表评论

请 登录 后发表评论。还没有在Zeuux哲思注册吗?现在 注册 !

暂时没有评论

Zeuux © 2024

京ICP备05028076号