标签 GCC 下的文章

为阻塞型函数调用添加超时机制

我们产品中的一个子模块在进行Oracle实时数据库查询时,常常因数据库性能波动或异常而被阻塞在OCI API的调用上,为此我们付出了“惨痛”的代价。说来说去还是我们的程序设计的不够完善,在此类阻塞型函数调用方面缺少微小粒度的超时机制。

调用阻塞多发生在I/O操作(磁盘、网络、低速设备)、第三方API调用等方面。对于文件/网络I/O操作,我们可利用在非阻塞文件描述符上select /poll的超时机制来替代针对阻塞型文件描述符的系统调用;但在第三方API方面,多数时候是无法用select/poll来进行超时的,我们可以选择 另外一种方法:利用setjmp和longjmp的非局部跳转机制来为特定阻塞调用添加超时机制。其原理大致是:利用定时器(alarm、setitimer)设置超时时间,在SIGALRM的handler中利用longjmp跳到阻塞型调用之前,达到超时跳出阻塞型函数调用的效果。同时这种方法通用性更好些。

这个机制实现起来并不难,但有些细节还是要考虑周全,否则很容易出错。我们的产品是需要运行在LinuxSolaris两个平台下的,因此机制的实现还要考虑移植性的问题。下面简要说说在实现这一机制过程中出现的一些问题与解决方法。

一、第一版

考虑到阻塞型函数的原型各不相同,且我们的产品中对阻塞调用有重试次数的要求,因此打算将这个机制包装成一个,大致是这个模样:

#define add_timeout_to_func(func, n, interval, ret, …) \…

其中func是函数名;n是重试的次数;interval是超时的时间,单位是秒;ret是函数成功调用后的返回值,若失败,也是这个宏的返回值。

我们可以像下面这样使用这个宏:

/* example.c */
int
main()
{
    #define MAXLINE 1024
    char line[MAXLINE];

    int ret = 0;
    int try_times = 3;
    int interval = 1000;
    add_timeout_to_func(read, try_times, interval, ret, STDIN_FILENO, line, MAXLINE);
    if (ret == E_CALL_TIMEOUT) {
        printf("invoke read timeouts for 3 times\n");
        return -1;
    } else if (ret == 0) {
        printf("invoke read ok\n");
        return 0;
    } else {
        printf("add_timeout_to_func error = %d\n", ret);
    }
}

add_timeout_to_func中为阻塞型函数添加的超时机制是利用setjmp/longjmp与信号的处理函数合作完成的。

/* timeout_wrapper.h */
 

#include <setjmp.h>
#include <stdarg.h>
#include <unistd.h>
#include <stdio.h>
#include <signal.h>
#include <string.h>
#include <errno.h>

extern volatile int invoke_count;
extern jmp_buf invoke_env;

void timeout_signal_handler(int sig);
typedef void (*sighandler_t)(int);
#define E_CALL_TIMEOUT (-9)

#define add_timeout_to_func(func, n, interval, ret, ...) \
    { \
        invoke_count = 0; \
        sighandler_t h = signal(SIGALRM, timeout_signal_handler); \
        if (h == SIG_ERR) { \
            ret = errno; \
            goto end; \
        }  \
\
        if (sigjmp(invoke_env) != 0) { \
            if (invoke_count >= n) { \
                ret = E_CALL_TIMEOUT; \
                goto err; \
            } \
        } \
\
        alarm(interval);\
        ret = func(__VA_ARGS__);\
        alarm(0); \
err:\
        signal(SIGALRM, h);\
end:\
        ;\
    }

/* timeout_wrapper.c */
#include "timeout_wrapper.h"

volatile int invoke_count = 0;
jmp_buf invoke_env;

void
timeout_signal_handler(int sig)
{
    invoke_count++;
    longjmp(invoke_env, 1);
}

编译运行这个程序,分别在Solaris、Linux下运行,遗憾的是两个平台下都以失败告终。

先说一下在Linux下的情况。在Linux下,程序居然不响应第二次SIGALRM信号了。通过strace也可以看出,当alarm被第二次调用后, 系统便阻塞在了read上,没有实现为read增加超时机制的目的。原因何在呢?我在《The Linux Programming Interface》一书中找到了原因。原因大致是这样的,我们按照代码的执行流程来分析:

* add_timeout_to_func宏首先设置了信号的handler,保存了env信息(setjmp),调用alarm设置定时器,然后阻塞在read调用上;
* 1s后,定时器信号SIGALRM产生,中断发生,代码进入信号处理程序,即timeout_signal_handler; Linux上的实现是当进入处理程序时,内核会自动屏蔽对应的信号(SIGALRM)以及此时act.sa_mask字段中的所有信号;在离开 handler后,内核取消这些信号的屏蔽。
* 问题在于我们是通过longjmp调用离开handler的,longjmp对应的invoke_env是否在setjmp时保存了这些被屏蔽的信号呢? 答案是:在Linux上没有。这样longjmp跳到setjmp后也就无法恢复对SIGALRM的屏蔽;当再次产生SIGALRM信号时,程序将无法处 理,也就一直阻塞在read调用上了。

解决方法:将setjmp/longjmp替换为sigsetjmp和siglongjmp,后面这组调用在sigsetjmp时保存了屏蔽信号,这样在 siglongjmp返回时可以恢复到handler之前的信号屏蔽集合,也就是说SIGALRM恢复自由了。在Solaris 下,setjmp/longjmp是可以恢复被屏蔽的信号的。

再说说在Solaris下的情况。在Solaris下,程序在第二次SIGALRM到来之际,居然退出了,终端上显示:“闹钟信号”。这是因为在 Solaris下,通过signal函数设置信号的处理handler仅是一次性的。在应对完一次信号处理后,信号的handler被自动恢复到之前的处 理策略设置,对于SIGALRM来说,也就是程序退出。解决办法:通过多次调用signal设置handler或通过sigaction来长效设置 handler。考虑到移植性和简单性,我们选择了sigaction。在Linux平台下,signal函数底层就是用sigaction实现的,是简洁版的sigaction,因此它的设置不是一次性的,而是长效的。

二、第二版

综上问题的修改,我们有了第二版代码。

/* timeout_wrapper.h */

extern volatile int invoke_count;
extern sigjmp_buf invoke_env;

void timeout_signal_handler(int sig);
typedef void sigfunc(int sig);
sigfunc *my_signal(int signo, sigfunc* func);
#define E_CALL_TIMEOUT (-9)

#define add_timeout_to_func(func, n, interval, ret, …) \
    { \
        invoke_count = 0; \
        sigfunc *sf = my_signal(SIGALRM, timeout_signal_handler); \
        if (sf == SIG_ERR) { \
            ret = errno; \
            goto end; \
        }  \
\
        if (sigsetjmp(invoke_env, SIGALRM) != 0) { \
            if (invoke_count >= n) { \
                ret = E_CALL_TIMEOUT; \
                goto err; \
            } \
        } \
\
        alarm(interval); \
        ret = func(__VA_ARGS__);\
        alarm(0); \
err:\
        my_signal(SIGALRM, sf); \
end:\
        ;\
    }

/* timeout_wrapper.c */

volatile int invoke_count = 0;
sigjmp_buf invoke_env;

void
timeout_signal_handler(int sig)
{
    invoke_count++;
    siglongjmp(invoke_env, 1);
}

sigfunc *
my_signal(int signo, sigfunc *func)
{
    struct sigaction act, oact;

    act.sa_handler = func;
    sigemptyset(&act.sa_mask);
    act.sa_flags = 0;
    if (signo == SIGALRM) {
#ifdef SA_INTERRUPT
        act.sa_flags |= SA_INTERRUPT;
#endif
    } else {
#ifdef SA_RESTART
        act.sa_flags |= SA_RESTART;
#endif
    }
    if (sigaction(signo, &act, &oact) < 0)
        return SIG_ERR;
    return oact.sa_handler;
}

这里从《Unix高级环境编程》中借了一段代码,就是那段my_signal的实现。这样修改后,程序在Linux和Solaris下工作都蛮好的。但目前唯一的缺点就是超时时间粒度太大,alarm仅支持秒级定时器,我们至少要支持毫秒级,接下来我们要换掉alarm。

三、第三版

setitimer与alarm是同出一门,共享一个定时器的。不同的是setitimer可以支持到微秒级的粒度,因此我们就用setitimer替换alarm,第三版仅改动了add_timeout_to_func这个宏:

#define add_timeout_to_func(func, n, interval, ret, …) \
    { \
        invoke_count = 0; \
        sigfunc *sf = my_signal(SIGALRM, timeout_signal_handler); \
        if (sf == SIG_ERR) { \
            ret = errno; \
            goto end; \
        }  \
\
        if (sigsetjmp(invoke_env, SIGALRM) != 0) { \
            if (invoke_count >= n) { \
                ret = E_CALL_TIMEOUT; \
                goto err; \
            } \
        } \
\
        struct itimerval tick;  \
        struct itimerval oldtick;  \
        tick.it_value.tv_sec = interval/1000; \
        tick.it_value.tv_usec = (interval%1000) * 1000; \
        tick.it_interval.tv_sec = interval/1000; \
        tick.it_interval.tv_usec = (interval%1000) * 1000; \
\
        if (setitimer(ITIMER_REAL, &tick, &oldtick) < 0) { \
            ret = errno; \
            goto err; \
        } \
\
        ret = func(__VA_ARGS__);\
        setitimer(ITIMER_REAL, &oldtick, NULL); \
err:\
        my_signal(SIGALRM, sf); \
end:\
        ;\
    }

至此,一个为阻塞型函数调用添加的超时机制的雏形基本实现完毕了,但要放在产品代码里还需要更细致的打磨。至少目前只是在单进程单线程中跑过,而且要求每个函数中只能调用add_timeout_to_func一次,否则就会有编译错误。

以上完整代码我都放到github上的experiments repository中了,有兴趣的朋友可以下载细看。

Python脚本命令行变量的实现

我们知道Make工具是支持命令行变量的,这种手段为我们提供了很好的灵活性,我们可以通过敲入不同的命令行参数来决定Makefile脚本的行为。

make [variable1=value1 variable2=value2 ... ... ]。

#
# Makefile
#

CMODE = 64-bit

ifeq ($(CMODE), 64-bit)
    CFLAGS += -m64
endif
  
all:
    gcc $(CFLAGS) -o foo foo.c

$> make
gcc -m64 -o foo foo.c

$> make CMODE=32-bit
gcc -o foo foo.c

近期我们的一个Python脚本工具也有类似的需求了,但Python脚本原生并不支持这种命令行变量,我们来看看是否可以利用Python提供的机制实现一种可以满足我们需求的命令行变量。

我们的期望结果如下:

$> foo.py fruit=apple

# foo.py

flag = '' #这个定义可以有,也可以没有,如果有,可以理解为默认值

….

if flag == 'apple':
    ….
elif flag == 'orange':
    ….
elif flag == 'banana':
    ….
else:
    ….

Python是动态语言,提供了注入eval、exec等在运行时执行代码的能力。我们要实现命令行变量的机制,离不开这些能力的支持。eval用于求值表达式,而x=y是语句,我们只能用exec。

【#1】

import sys

if __name__ == '__main__':
    c = len(sys.argv)
    if c <= 1:
        print "found zero command variable"
        exit(0)

    exec(sys.argv[1])

    if fruit == 'apple':
        print 'this is apple'
    elif fruit == 'oracle':
        print 'this is orange'
    elif fruit == 'banana':
        print 'this is banana'
    else:
        print 'other fruit'

$> foo.py fruit=apple

Traceback (most recent call last):
  File "./foo.py", line 18, in <module>
    exec(sys.argv[1])
  File "<string>", line 1, in <module>
NameError: name 'apple' is not defined

上面的例子执行后,提示'apple'没有定义。执行foo.py fruit="apple"得到的也是同样的错误。从内部输出来看,无论是fruit=apple还是fruit="apple",exec的参数始终都 是fruit=apple,导致exec抱怨apple这个符号没有定义。

我们打开一个Python命令行交互窗口,做如下测试:

$> python
Python 2.7.3 (default, Aug  1 2012, 05:14:39)
[GCC 4.6.3] on linux2
Type "help", "copyright", "credits" or "license" for more information.
>>> exec("fruit=apple")
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
  File "<string>", line 1, in <module>
NameError: name 'apple' is not defined
>>> exec("fruit='apple'")
>>> fruit
'apple'
>>> exec("num=1")
>>> num
1

通过这个小实验可以看出,我们不能将命令行参数直接原封不动的传给exec,我们要对其进行一下加工,加工的效果如下:

fruit=apple => fruit='apple'
num=1 => num=1

【2】

import sys

def __convert(source):
    (var, sep, val) = source.partition("=")
    if val.isdigit():
        return source
    return  var + "=" + "\'" + val + "\'"

if __name__ == '__main__':
    c = len(sys.argv)
    if c <= 1:
        print "found zero command variable"
        exit(0)

    exec( __convert(sys.argv[1]))

    if fruit == 'apple':
        print 'this is apple'
    elif fruit == 'orange':
        print 'this is orange'
    elif fruit == 'banana':
        print 'this is banana'
    else:
        print 'other fruit'

__convert函数对命令行的参数做了转换,对于数值类的var直接原封不动的返回,否则对于值为字符串的var,将其val用''包裹起来后返回。我们来测试一下新程序:

$> foo.py fruit=apple
this is apple
$> foo.py fruit=orange
this is orange
$> foo.py fruit=watermelon
other fruit

从输出结果来看,我们的预期是达到了^_^。上面的程序只是示例性质的,Python的exec具有运行时执行动态代码的能力,我们在获得这种强大能力的 同时,也面临着巨大的风险。一旦恶意代码从外部传入被exec执行,将带来严重的后果。因此对于exec要执行的代码务必要预先进行必要的形式校验。

跨过BUG查找的”最后一公里”

如果你看到一个C程序员在通宵熬夜神情紧张地对着电脑敲代码或阅读代码,多数只有两种可能:一是为了赶进度;二就是查找内存Bug。
                                                                                                                              — 个人感悟
 
昨晚搞到凌晨一点多,终于算是把一个棘手的Bug的来龙去脉搞清楚了。截至到今天,这个Bug已经困扰了项目组两个核心开发同事达三周之久了。

这个Bug的确很难查找:

   – 首先模拟环境下无法复现该Bug;
   – 生产环境下该Bug是随机出现的,发生频率十分低;
   – Bug出现时并未有dump core等明显异常现象出现,系统依旧运行良好。

得到Bug报告后,我的两位同事就开始对bug引发的问题现象进行了分析,得出了内存被污染的初步结论。之后又在生产环境做了GDB attach到进程的调试,甚至替换了生产环境的版本,利用传统的print语句在关键路径上输出提示信息,试图找到引发Bug的真正原因。但做过这些 后,所能得到的结论依旧停留在内存被污染,至于怎么被污染的、在哪个业务流程上被污染的却无从得知。无奈之下,两位同事开始根据 subversion的commit history进行代码比对和分析,试图查找到哪些新增或修改的代码引发了Bug。代码修改量小还好,如果修改数量巨大,这种代码比对就好比大海捞针,我 们无法保证注意力自始自终是集中的,结果两位同事也的确没有从代码变更中发现什么蛛丝马迹。这类Bug会让你有一种有力无处施展的感觉,面对这样 的Bug,我的两位开发人员似乎也失去了信心和思路。

下面简要描述一下这个Bug:

有这样一个字段数目众多的结构体foo_t,这里仅列出bug相关的几个字段e、c、flag、pdata:

struct foo_t {
    … …
    char e[XX_SIZE];
    char c[XX_SIZE];
    char flag;
    data_t *pdata;
    … …
};

业务逻辑是:

if (flag) {
    处理e、c两个字段;
}

   
bug现象:值本是1的flag字段被污染,值变成了0,导致e、c两个字段没有被做处理,从而引发业务异常,导致客户投诉。我的同事曾经做过如 下尝试,以确定内存污染的行为特点,她在flag之前又加了一个字段flag1:

struct foo_t {
    … …
    char e[XX_SIZE];
    char c[XX_SIZE];
    unsigned int flag1;
    char flag;
    data_t *pdata;
    … …
};

在生产环境下运行得到的结果是flag1和flag值正常,但字段c的尾部字节遭到了污染。现象已经十分明确,离真相就差那最后一公里了。

对于上面的内存污染问题,我首先会怀疑在处理flag或c之前的字段时出现了缓冲区溢出,导致后面字段的内容被整体或局部覆盖。不过从bug现象 来看,这个思路也有说不通的地方,那就是为何是c的尾部字段被污染,而不是从头部开始呢?不过我们依旧沿着这个思路追查了e以及e的诸多前驱字 段,细致的分析了代码,但没有发现溢出点。

c或flag的后继字段比如pdata要想污染c或flag则必须具备更多条件,至少要有操作&pdata的代码,之前基本认为这不太可 能。但现在仅有这一条路可以继续走下去了,也只能沿着这条路走下去。事实证明我们走的没错。在后续的处理流程中有这样的一个函数:

int func(void *p, int size)

这个函数本来是用于处理data_t*变量的,但由于编码者的疏忽,将&pdata传给了p,另外size这个参数也传了一个错误的值, 估计是滥用了copy&paste。而func函数体中对p指向的内存地址做了修改,这个修改直接污染了 ((char*)&pdata + size)起始的那片内存块儿,这就是问题的真正原因所在。这样看来pdata并未污染其所在的foo_t实例中的flag或c字段,而是污染了其他foo_t实例中的flag或c字段,因为这些实例都放在一个mem block pool中的,所以这还是一个随机的远距离内存污染^_^。

我走完了BUG查找的最后那一公里,到达了终点。这个BUG的查找确实不易,但并非遥不可及,为何我的两位同事就停在离真相只有一公里的地方而踌 躇不前了呢?对此我也做了一些考量,希望能在日后的BUG查找方面给予帮助。

要跨过BUG查找的那最后一公里,可从如下几个方面着手努力:

* 收罗证据,不放过一处可疑之处

这是准备工作,就好比警察查看罪案现场,哪怕是一根毛发,一处异物也不能放过。一般来说我们至少要收集到Bug发生时的各方面信息,包括:

 - 系统日志
        这个时间点上各个模块的日志都要搜罗到;

 - core文件
        如果bug引发core dump,那core文件是bug查找的最佳入口;

 - 通信数据包内容
        对于很多后端服务程序而言,不合法的通信数据包常常会引发Bug,我经手的类似Bug就不止一起了。必要时通过抓包工具将通信包抓到文件中以备后用。

 - CPU/内存/磁盘实时状况
       千万不要小视这些信息。如果发现CPU过高,则很可能代码存在死循环的可能(后pstack进程号,则可直接找到问题所在);如果磁盘满,则可以很好解释 数据不完整的异常;如果mem占用过高,则可以解释分配内存异常或性能下降等问题。

 - 系统操作日志
       如果有管理员的操作行为的话,我们也不要放过,将操作日志(一般系统都有保存,并需要对这些日志进行定期审核)截取并保留,以备后用。

 - 操作系统/硬件相关异常信息等。
       如果是因为OS或硬件异常导致的Bug,那搜集到这些信息就太重要了,否则你将付出惨重的Bug查找代价。

Bug查多了你就会有这种感悟:证据用时方恨少啊!

* 沉下心,保持清晰思路

BUG有难有易,简单的Bug大家都能应付,而困难的Bug,就要比拼能力和经验了。要想解决掉Bug,务必要沉下心,不急不躁,这是保持大脑始 终有清晰思路的前提。

能用工具(比如GDB)调试出来的Bug,都不是最难的问题,因为现场就摆在你的面前,你可以看到一切蛛丝马迹。最难的问题最终都是要通过脑力分 析出来的。

解决问题前,要根据之前搜罗的证据,形成自己的查找思路。没有思路是可怕的。没有思路的时候,也不要急于开始查,那样只会乱套。应根据已有的蛛丝 马迹,行成一些思路,哪怕这个思路你自己都不是很肯定,先按这个思路做做看,也许走出一步后,你又能收获新的信息,形成新的思路。就这样敏捷地向 前进,边向前探索边定期回顾。

* 知晓原理,缩小查找范围,形成正确思路

要保持清晰正确的思路,开发人员对系统的运行原理要做到十分清楚,这样可以缩小查找范围,重点突破。就好比上面的那个bug例子,我们要知道 c/flag被污染有几种潜在的可能,并形成多种思路,然后沿着这几种可能的思路继续走下去。在这次查找过程中,想必两位同事恰恰是在原理这方面 没有理解透彻吧。

* 质疑,从自己的代码开始

查Bug就要抛弃“不可能”,拥抱“质疑一切”。而质疑要从自己的代码开始。程序员或多或少都有一种“自负”的心态,骨子里会认为自己的代码肯定 是正确的。如果出现问题,一定是其他人代码的问题,哪怕是OS这样总体来说十分稳定的平台也会成为被首先质疑的对象。不过事实证明,错误多出在我 们自己的代码中,毫无理由的去怀疑操作系统、怀疑你使用的第三方库,多半会南辕北辙,浪费你宝贵的查找时间。

* 拥抱调试技巧和工具

必要的调试技巧是Bug查找的基本功底,这些技巧在涉及内存问题查找过程中相当有用。

  — print语句
        不用多说,print语句是最简单、最常用的调试手段,在代码任意位置,根据你的需要,输出信息,帮助你分析bug原因。其唯一的缺点就是可能需要你重新 build代码和部署你的应用。

  — gdb切入进程地址空间查看堆栈
         利用gdb一类的专用调试工具可在代码运行时切入进程地址空间,实时查看数据变化。你也可以在gdb下执行应用,获得同样的效果(适合单进程应用)。
 
  — 调试版中采用magic number + assert
         C程序的bug多为内存问题。常见的内存越界访问或污染的调试手段是在代码中为内存块添加magic number,并在特定环节用assert保证该magic number的值是没有被修改的。一旦值改变了,则说明问题发生在执行流的两次assert之间的某个地方,后续可进一步缩小assert间隙,直到定位 到问题。

  — 让bug尽可能的容易复现
         一个可以在模拟环境下复现的Bug总是比较好查的。出于这个考虑,我们可通过放大问题区域来尽可能更容易的复现bug,比如将一个字节的字段改为4个字 节,这样可能占据更多被污染的区域,比较利于Bug的复现(但这不总是ok的)。

* 把握节奏,避免陷入惯性思维

一些比较难fix的Bug,其查找过程可能会十分漫长,就像这次我们遇到的这个问题。这就需要我们的开发人员把握好Bug查找的节奏,因为长时间 调试和查问题容易让人陷入惯性思维,反倒不利于Bug的查找。一旦意识到自己进入惯性思维后,可考虑换种活动做做,比如出去散散步、洗个热水澡 等。或者给其他人员讲解你的查找思路,这个过程中自己可能会发现思路上的缺陷,或者由他人指出你思路方面的问题。

感觉Bug查找是一门手艺活,要学会慢工出细活,这总比不出活儿的要好,尤其是在面对那些十分诡异的内存Bug时。




这里是Tony Bai的个人Blog,欢迎访问、订阅和留言!订阅Feed请点击上面图片

如果您觉得这里的文章对您有帮助,请扫描上方二维码进行捐赠,加油后的Tony Bai将会为您呈现更多精彩的文章,谢谢!

如果您喜欢通过微信App浏览本站内容,可以扫描下方二维码,订阅本站官方微信订阅号“iamtonybai”;点击二维码,可直达本人官方微博主页^_^:



本站Powered by Digital Ocean VPS。

选择Digital Ocean VPS主机,即可获得10美元现金充值,可免费使用两个月哟!

著名主机提供商Linode 10$优惠码:linode10,在这里注册即可免费获得。

阿里云推荐码:1WFZ0V立享9折!

View Tony Bai's profile on LinkedIn


文章

评论

  • 正在加载...

分类

标签

归档











更多