一个C++工程CPU占用100%问题的排查

最新推荐文章于 2024-05-23 10:17:35 发布

李迟

最新推荐文章于 2024-05-23 10:17:35 发布

阅读量1.5w

点赞数 8

分类专栏：技术杂铺文章标签： c++ 服务器开发语言

本文链接：https://blog.csdn.net/subfate/article/details/121280436

版权

技术杂铺专栏收录该内容

29 篇文章 3 订阅

订阅专栏

最近遇到一个 C++ 工程CPU占用100%的问题，经过排查，发现原来是不再使用的代码片段的问题，本文记录了排查的过程，并给出示例代码片段。

发现问题

某日，运维反馈生产环境某台设备出现问题，某个进程占用 cpu 较高，几乎为 100%，已连续出现几天，现场人员重启过若干次，问题依旧。领导指派我排查。

排查过程

首先查看该进程的日志文件，未发现异常。

无意间执行 df 命令，发现磁盘已经满了，经查，是另一进程的日志文件占用过高，已近700GB。利用 scp 将部分日志文件迁移到另一台服务器，用 vim打开日志，定位到1000多行发现出错信息：open read pipe failed : Permission denied，定位到文末，也是相同的出错语句，得到结论，该语句频繁输出，导致文件过大，占用空间。

删除日志文件，磁盘恢复，但 CPU 依然满载，使用了iotop -oP、iostat、pidstat -d 1命令查看，发现还跟 rsyslog 有关。

网上有相关问题的介绍，根据文章，使用service rsyslog status查看 syslog 的服务状态，输出如下：

Oct 29 11:06:57 localhost.localdomain systemd[1]: Starting System Logging Service...
Oct 29 11:06:57 localhost.localdomain rsyslogd[4836]:  [origin software="rsyslogd" swVersion="8.24.0-34.el7" x-pid="4836" x-info="http://www.rsyslog.com"] start
Oct 29 11:06:57 localhost.localdomain systemd[1]: Started System Logging Service.
Oct 29 11:06:57 localhost.localdomain rsyslogd[4836]: sd_journal_get_cursor() failed: 'Cannot assign requested address'  [v8.24.0-34.el7]
Oct 29 11:06:57 localhost.localdomain rsyslogd[4836]: imjournal: journal reloaded... [v8.24.0-34.el7 try http://www.rsyslog.com/e/0 ]
Oct 29 11:06:57 localhost.localdomain rsyslogd[4836]: imjournal: journal reloaded... [v8.24.0-34.el7 try http://www.rsyslog.com/e/0 ]
Oct 29 11:06:58 localhost.localdomain rsyslogd[4836]: imjournal: begin to drop messages due to rate-limiting
Oct 29 11:07:00 localhost.localdomain rsyslogd[4836]: sd_journal_get_cursor() failed: 'Cannot assign requested address'  [v8.24.0-34.el7]
Oct 29 11:07:00 localhost.localdomain rsyslogd[4836]: imjournal: journal reloaded... [v8.24.0-34.el7 try http://www.rsyslog.com/e/0 ]
Oct 29 11:07:00 localhost.localdomain rsyslogd[4836]: imjournal: journal reloaded... [v8.24.0-34.el7 try http://www.rsyslog.com/e/0 ]
Oct 29 11:07:04 localhost.localdomain rsyslogd[4836]: sd_journal_get_cursor() failed: 'Cannot assign requested address'  [v8.24.0-34.el7]
Oct 29 11:07:04 localhost.localdomain rsyslogd[4836]: imjournal: journal reloaded... [v8.24.0-34.el7 try http://www.rsyslog.com/e/0 ]
Oct 29 11:07:04 localhost.localdomain rsyslogd[4836]: imjournal: journal reloaded... [v8.24.0-34.el7 try http://www.rsyslog.com/e/0 ]

可知系统的日志服务出现问题。根据网上说法，手动删除/var/lib/rsyslog/imjournal.state文件并重启 rsyslog，命令如下：

rm -rf /var/lib/rsyslog/imjournal.state
systemctl restart rsyslog

随后查看，问题依旧，再重启多次亦然。问题还是未解决。

示例代码

排查代码，发现有几处相同的日志，根据跟踪，发现一个地方可疑，经过测试，的确为该处的问题。出现问题的代码如下（片段示意）：

bool OpenFifo()
{
    if(-1 == g_pipe)
    {
        if(access(pipename, F_OK) != 0)
        {
            if(mkfifo(pipename, 0777) != 0)
            {
                printf("mkfifo %s failed : %s\n", pipename, strerror(errno));
                return false;
            }
        }

        g_pipe = open(pipename,  O_RDWR | O_NONBLOCK);
        if(-1 == g_pipe)
        {
            printf("open read pipe failed : %s\n", strerror(errno));
            return false;
        }
    }

    return true;
}

int Recv(char *buffer, int bufferSize, int timeout)
{
    if(-1 == g_pipe)
    {
        if(OpenFifo() == false)
        {
            return -1;
        }
    }
    
    if(select(g_pipe + 1, &fds, NULL, NULL, &tv) > 0)
    {
        read(g_pipe, buffer + byteread, readsize - byteread);
    }

    return -1;
}
    
int main()
{
    // 主循环
    while (false == g_isexit)
    {
        // 使用 fifo 读取标志
        if ((len = theFifo->Recv(buf, sizeof(buf) - 1, 1000)) > 0)
        {
            buf[len] = 0;
            if (strcmp(buf, "EXIT") == 0)
            {
                printf("Get EXIT signal, exit...");
                break;
            }
        }
    }
}

程序逻辑较简单，在代码中读取 FIFO 的命令，如是退出指令，则退出程序。具体说就是在主循环中读取某个 FIFO 文件，延时1秒钟（因此主循环没有显式调用 sleep 函数）。在 Recv 函数中会判断 FIFO 文件是否打开，如否，则打开之。但问题正出在此处：printf("open read pipe failed : %s\n", strerror(errno))。当 FIFO 文件权限出错时，就会一直打印输出。而该台设备的 FIFO 文件不知何故何时变成为 root 权限，询问未果，于是手动修改权限，CPU 随即恢复正常指标范围。