最近遇到一個 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 隨即恢復正常指標范圍,
問題解決
詢問原來維護代碼的同事,回復說那段代碼已不再使用,于是洗掉之,
小結
既然定位到了問題,也知道了原由,直接洗掉不再使用的代碼即可,從測驗結果看,的確解決了問題,
從中也可以知道,對于專案代碼,需要保持一定的迭代更新或重構作業,至少,已經過時的代碼應該洗掉,使用 git 版本控制工具,可以追溯代碼的歷史,因此舊代碼可以不再保留在當前工程中,
對于個人的代碼,完全可由個人掌控,但在一個研發團隊中,還需所有人員達成共識,需要上級的推動和開發人員的實踐,
轉載請註明出處,本文鏈接:https://www.uj5u.com/qita/356879.html
標籤:其他
