最近在开发新项目,使用的是旧的代码,因此要进行一些代码的删减和优化。在win下开发时,一切正常,但在Linux下,发现其中一个模块在启动时会偶发性无缘无故中止,没有异常日志,没有core dump,内核那边也没有异常,进程直接就消失了。
我以为是系统环境变量没设置好,但使用命令ulimit -a
查看各种参数没有问题,在终端执行sleep 30
,然后按ctrl+\
也能正常产生core dump。
bug是偶发性的,使用脚本启动,有一定的概率触发。但假如我手动去启动那个进程,反反复复试了半个多钟,也没有重现,更别说把gdb挂上去调试。我甚至一度怀疑是脚本有问题,查了半天也没结果。最终在调试脚本时,一次偶然的启动,重现了这个问题。查看gdb的堆栈,发现是触发了SIGPIPE
信号,程序直接退出。
这一下就理清了问题:整个程序是多进程架构,使用socket进行通信。模块启动时,会连接另一个模块进行握手,但就在发送握手数据时触发了SIGPIPE
。仔细跟一下代码逻辑,发现是异常没处理好,导致连接没有成功时也开始发送了数据。使用脚本启动时,启动各个进程的时间比较接近,进行握手时另一个模块还未来得及监听端口,因此会连接失败,有一定概率重现。手动启动的话另一个模块已初始化完成,早就在监听端口,直接就连接上了,重现不了。使用gdb -ex=r --args myprogram arg1 arg2
在脚本里用gdb启动进程也会导致这个进程启动慢一点,重现的概率也很小。
这个bug暴露了两个问题。
问题一
信号一般都会产生core dump,但是SIGPIPE
这个信号比较特殊,它不会。它是直接终止程序,也没有内核日志,查问题的时候根本无从下手。所以程序中除了谨慎地防止这个信号的产生以后,一般还会直接处理掉这个信号
// 直接忽略掉
sigaction(SIGPIPE, &(struct sigaction){SIG_IGN}, NULL);
// 让程序产生core dump
void sigpipe_handler(int unused)
{
assert(false);
}
sigaction(SIGPIPE, &(struct sigaction){sigpipe_handler}, NULL);
如果忽略掉信号,则对socket进行send/write
操作时一般会返回错误,errno
为EPIPE
,这时要处理一下异常。
问题二
getsockopt(fd, SOL_SOCKET, SO_ERROR, &error_s, &len_s)
第二次调用不会返回错误。我简化了一下代码,提供一个Linux下的小程序来分析
#include <assert.h>
#include <sys/fcntl.h>
#include <errno.h>
#include <stdio.h>
#include <stdlib.h>
#include <sys/select.h>
#include <unistd.h>
#include <netinet/in.h>
#include <sys/socket.h>
#include <netinet/tcp.h>
#include <arpa/inet.h>
int main()
{
int fd = -1;
int ret = 0;
int error_s = 0;
struct sockaddr_in serv_addr;
int len_s = sizeof(int);
int try = 30;
fd = socket(PF_INET, SOCK_STREAM, 0);
fcntl(fd, F_SETFL, O_NONBLOCK);
serv_addr.sin_family = AF_INET;
serv_addr.sin_port = htons(55555);
serv_addr.sin_addr.s_addr = inet_addr("127.0.0.88");
ret = connect(fd, (struct sockaddr *)&serv_addr, sizeof(struct sockaddr_in));
printf("connect ret=%d, errno=%d\n", ret, errno);
try_connect_again:
printf("try_connect_again\n");
printf("attempt left %d ...\n", try);
if (!try)
goto fin;
usleep(2000000);
struct timeval tm;
tm.tv_sec = 0;
tm.tv_usec = 0;
fd_set set;
FD_ZERO(&set);
FD_SET(fd, &set);
ret = select(fd+1, NULL, &set, NULL, &tm);
if (ret)
{
ret = getsockopt(fd, SOL_SOCKET, SO_ERROR, &error_s, &len_s);
printf("getsockopt, ret=%d, error_s=%d \n", ret, error_s);
if (error_s == 0)
printf("connected\n");
else
{
try--;
goto try_connect_again;
}
}
else if (ret == 0)
{
try--;
goto try_connect_again;
}
fin:
printf("end\n");
return 0;
}
整个程序的逻辑比较简单,发起一个连接,然后定时用select
来监听可写事件,再用getsockopt
来判断是否连接成功。但是在不同的系统下,它表现是不一样的:
xzc@debian:~/local_code$ gcc test_gso.c
xzc@debian:~/local_code$ ./a.out
connect ret=-1, errno=115
try_connect_again
attempt left 30 ...
getsockopt, ret=0, error_s=111
try_connect_again
attempt left 29 ...
getsockopt, ret=0, error_s=0
connected
end
xzc@debian:~/local_code$ cat /etc/os-release
PRETTY_NAME="Debian GNU/Linux 10 (buster)"
[root@localhost test]# gcc test_gso.c
[root@localhost test]# ./a.out
connect ret=-1, errno=115
try_connect_again
attempt left 30 ...
getsockopt, ret=0, error_s=111
try_connect_again
attempt left 29 ...
try_connect_again
attempt left 28 ...
try_connect_again
attempt left 27 ...
^C
[root@localhost test]# cat /etc/centos-release
CentOS release 6.5 (Final)
可以看到在Debian 10下,select每次都会返回可写事件,getsockopt
第一次返回错误码111,第二次返回了0,由于没有处理第一次的异常,第二次就会误以为连接成功从而发送了数据引发SIGPIPE。而在CentOS 6.5下,select只返回了一次可写事件,没有再次调用getsockopt
。
经过测试,发现新系统(测试了Debian 10、CentOS 7、CentOS 6.10)的表现都是select每次都会返回可读事件,getsockopt
第一次返回错误码111,第二次返回了0。而我这新的项目使用了老项目的代码,系统也从CentOS 6.5迁移到CentOS 7,因此触发了这个bug。
不太清楚这个差异的原因,可能是内核的bug,也可能是修改了特性。但也有不少人遇到:
https://github.com/dotnet/runtime/issues/17260
https://www.unix.com/programming/254646-strange-getsockopt-solaris-behavior.html
另外还有一个值得注意的点。win的select和linux下不同,判断一个连接是否成功,如果成功是在writefds参数,但如果失败是在exceptfds参数。参考:https://learn.microsoft.com/en-us/windows/win32/api/winsock2/nf-winsock2-select
我这项目代码没有处理exceptfds参数,因此win下不会监听到连接失败,所以平时在win下开发没有发现问题。