前几天在看apue第16章关于socket的例子,就是一个非常典型的socket服务器,关键代码如下:
1 void serve (int sockfd) 2 { 3 int ret; 4 int clfd; 5 int status; 6 7 FILE *fp; 8 pid_t pid; 9 char buf[BUFLEN]; 10 11 for (;;) { 12 clfd = accept (sockfd, NULL, NULL); 13 if (clfd < 0) { 14 syslog (LOG_ERR, "accept error: %d, %s", errno, strerror (errno)); 15 //if (errno == EOPNOTSUPP) 16 //{ 17 // syslog (LOG_INFO, "retry.."); 18 // continue; 19 //} 20 21 exit (1); 22 } 23 24 fp = popen ("/usr/bin/uptime", "r"); 25 if (fp == NULL) { 26 sprintf (buf, "error: %s ", strerror (errno)); 27 ret = send (clfd, buf, strlen (buf), 0); 28 syslog (LOG_ERR, "write back %d for error", ret); 29 } else { 30 while (fgets (buf, BUFLEN, fp) != NULL) 31 { 32 ret = send (clfd, buf, strlen (buf), 0); 33 // very amazing, add these log will lead to accept failed with EOPNOTSUPP (95) 34 // maybe syslog used dgram socket confuse us.. 35 syslog (LOG_ERR, "write back %d", ret); 36 } 37 38 pclose (fp); 39 } 40 41 close (clfd); 42 } 43 }
当accept成功返回一个连接clfd后,使用这个serve方法来服务客户端的请求,简单说就是通过popen启动uptime命令返回当前系统运行时长,然后将uptime的输出导出到clfd上返回给客户端。
正常的输出如下:
[yunhai@localhost 16.chapter]$ ./uptime_tcp_clt connect ok 02:02:26 up 6 days, 4:40, 5 users, load average: 0.00, 0.00, 0.00
但是与书上例子不同,为了查看服务端的活动情况,我在serve中加了几句syslog输出(line 35,标黄的那句),以便通过 tail -f /var/log/messages 来查看服务运行的情况。
正常情况下服务输出如下:
ruptimed: write back 70
但是神奇的事情发生了,我再次启动客户端后,连不上服务器了:
[yunhai@localhost 16.chapter]$ ./uptime_tcp_clt connect failed, retry... connect failed, retry... connect failed, retry...
再看服务器进程,居然已经退出了,回来查看daemon日志,发现这么一句:
ruptimed: accept error: 95, Operation not supported
原来accept出错导致服务器退出了,错误码是95,。
如果我将加入的syslog注释掉,就一切正常,所以我怀疑是使用syslog和syslogd进程在进行UDP通讯传输日志时,干扰了accept从而导致后者失败。
但是这个过程具体是怎样的,目前还不得而知,只知道我用的端口是4201,改用其它端口也是这样。
我尝试过在失败后重启accept操作,结果陷入无穷循环,每次都得相同的错误。
只要把新加的这句注释掉,就一切正常了。
更进一步,只要在 accept 之前有任何 syslog,accept 就会失败,amazing……