最近将系统从centos6.4升级到7.2,升级后发现原先的程序运行很慢,经过分析发现程序的性能被消耗在syslog函数中。然后我写了一个demo专门测试日志打印。
#include <stdio.h>
#include <sys/time.h>
#include <syslog.h>#define SYSLOG_PRIO_TRACE      (LOG_LOCAL5 | LOG_DEBUG)int main()
{
FILE *fp = NULL;
char buf[1025] = {0};
int index = 0;
struct timeval start, end; fp = fopen("syslog_speed_test_file.txt","w");
if(NULL == fp)
{
printf("file open failed.\n");
} for(index = 0; index<1023; index++)
{
buf[index] = 'w';
}
buf[1023] = '\n';

gettimeofday(&start, NULL);
printf("start time:%d.%d\n", start.tv_sec, start.tv_usec);
index = 0;
while (index < 102400)
{
gettimeofday(&start, NULL);
syslog(SYSLOG_PRIO_TRACE, "%s", buf);
gettimeofday(&end, NULL);
fprintf(fp, "%dth,time used:%d.%06d\n", index, end.tv_sec-start.tv_sec, end.tv_usec-start.tv_usec);
index++;
}
gettimeofday(&end, NULL);
printf("start time:%d.%d\n", end.tv_sec, end.tv_usec);
}将该程序分别在7.2系统和6.4系统的虚拟机上运行在7.2虚拟机上运行结果为5s左右,在6.4虚拟机上运行结果为500ms左右两个系统的输出分别如下7.2系统:0th,time used:0.002209
1th,time used:0.000019
2th,time used:0.000011
3th,time used:0.000008
4th,time used:0.000008
5th,time used:0.000008
6th,time used:0.000009
7th,time used:0.000008
8th,time used:0.000008
9th,time used:0.000008
10th,time used:0.000008
11th,time used:0.011167
12th,time used:0.000031
13th,time used:0.000011
14th,time used:0.000008
15th,time used:0.000008
16th,time used:0.000009
17th,time used:0.000008
18th,time used:0.000008
19th,time used:0.000010
20th,time used:0.000008
21th,time used:0.000009
22th,time used:0.006686
23th,time used:0.000028
24th,time used:0.000010
25th,time used:0.000009
26th,time used:0.000009
27th,time used:0.000008
28th,time used:0.000009
29th,time used:0.000008
30th,time used:0.000008
31th,time used:0.000008
32th,time used:0.000009
33th,time used:0.006043
6.4系统0th,time used:0.000215
1th,time used:0.000026
2th,time used:0.000018
3th,time used:0.000017
4th,time used:0.000016
5th,time used:0.000017
6th,time used:0.000679
7th,time used:0.000031
8th,time used:0.000017
9th,time used:0.000016
10th,time used:0.000016
11th,time used:0.000016
12th,time used:0.000016
13th,time used:0.000017
14th,time used:0.000016
15th,time used:0.000017
16th,time used:0.000016
17th,time used:0.000016
18th,time used:0.000016
19th,time used:0.000017
20th,time used:0.000016
21th,time used:0.000016
22th,time used:0.000016
23th,time used:0.000016
24th,time used:0.000086
25th,time used:0.000027
26th,time used:0.000016
27th,time used:0.000016
28th,time used:0.000018
29th,time used:0.000017
30th,time used:0.000016
31th,time used:0.000016
32th,time used:0.000016
33th,time used:0.000017
34th,time used:0.000016
35th,time used:0.000016
36th,time used:0.000016
37th,time used:0.000016
38th,time used:0.000016
39th,time used:0.000016
40th,time used:0.000017
从输出来看,7.2系统每隔10次输出就会有一次超长的卡顿,而6.4系统则无此现象。
抓取运行时的cpu占用状态,发现system-journald的cpu占用很高。
由于虚拟机的配置不足所以在服务器上进行了同样的实验,结果每隔10次的卡顿没了,但是单次处理的时间达到了50us以上,看journald的cpu占用达到了单核100%的程度。各位是否也遇到过这种情况?能否分享一下解决思路。