debug : linux C, 由rename API引起的内存被吃光
本文共 12810 字，大约阅读时间需要 42 分钟。
前言
有个cm在现场的高性能服务器(redhat)上，运行不到一分钟，就将服务器内存吃的差不多了。
要解决这个问题，要不没办法用了。 在本地的linux实验环境下，也能重现，但是吃内存没有那么厉害，跑了8个小时，吃了1.2GB. 谁看了这个现象，也会想是不是代码哪里写挫了，导致了内存泄漏。 先用valgrind查了一下，有少许泄漏，泄漏的内存都是不用立刻释放的，就是这个逻辑。 将工程中的内存分配和释放检查了一下，全部匹配。 将工程中所有的内存分配和释放都改为new, delete的配对。 再加入日志，在所有的new，new x [], delete, delete[] 处都加了日志，自己统计了内存申请和释放的size. 运行程序发现，打印出来的日志显示申请的内存都很小。 但是用top(运行后，按SHIFT + m键), 发现，cpu占用率很高，为70% 用 watch -n 1 -d “free -b” 观察系统总内存，发现每秒钟都会多用1MB的内存。 怀疑第三方库有问题，将第三方库送来的数据，不处理了，直接返回，内存不增加了，回到正常情况。 那说明cm的实现代码有问题，那就用屏蔽法，自顶向下排查吧，屏蔽到写文件的函数(已经封装)，发现内存正常了。 再去看那个函数，不到30行，关键一句就是调用了rename API，将写好内容的文件，移动为新的数据文件。 屏蔽掉rename的调用，cm正常了，最后的解决方法，不用api了，改用sh命令(mv + wait) + usleep(200), 问题解决。问题原因推测：可能是rename并不是阻塞执行，导致快速rename小文件时，rename实际的操作还没退出，就又新执行了新的rename操作，导致了大量并行的rename操作。
今天同事用大文件做测试，没有这个问题。
我写了一个测试程序，模拟了实际的业务逻辑，小文件频繁创建，移动，重现了rename吃内存的场景。 如何优雅的解决这个问题，以后再想。
测试程序-bug重现
// @file main.cpp#include#include #include #include #include #include #include #include "my_syslog.h"bool execute_prog(const char* psz_prog_path_name, const char* psz_cmd_line);int fn_for_test();int main(){ ns_syslog::open_syslog("test_syslog"); // 设置控制变量中的日志条件, 实际应用中, 是从配置文件读取的控制开关 ns_syslog::g_log_condition.b_EMERG = false; ns_syslog::g_log_condition.b_CRIT = true; ns_syslog::g_log_condition.b_ALERT = true; ns_syslog::g_log_condition.b_ERR = true; ns_syslog::g_log_condition.b_WARNING = true; ns_syslog::g_log_condition.b_NOTICE = true; ns_syslog::g_log_condition.b_INFO = true; ns_syslog::g_log_condition.b_DEBUG = true; // 根据控制变量, 设置日志的mask // 在实际应用中, 这里可以是动态设置, e.g. 配置文件检测线程发现配置变了, 需要变更某些级别的日志记录结果 ns_syslog::set_log_level( ns_syslog::g_log_condition.b_EMERG, ns_syslog::g_log_condition.b_ALERT, ns_syslog::g_log_condition.b_CRIT, ns_syslog::g_log_condition.b_ERR, ns_syslog::g_log_condition.b_WARNING, ns_syslog::g_log_condition.b_NOTICE, ns_syslog::g_log_condition.b_INFO, ns_syslog::g_log_condition.b_DEBUG); // 现在可以用日志宏打印日志了, 因为加了条件判断, 比直接进syslog中, 由syslog根据配置文件判断是否记录日志, 效率要高. MYLOG_EMERG("this is logtype EMERG, random = %d", rand() % 0xff); MYLOG_ALERT("this is logtype ALERT, random = %d", rand() % 0xff); MYLOG_CRIT("this is logtype CRIT, random = %d", rand() % 0xff); MYLOG_ERR("this is logtype ERR, random = %d", rand() % 0xff); MYLOG_WARNING("this is logtype WARNING, random = %d", rand() % 0xff); MYLOG_NOTICE("this is logtype NOTICE, random = %d", rand() % 0xff); MYLOG_INFO("this is logtype INFO, random = %d", rand() % 0xff); MYLOG_DEBUG("this is logtype DEBUG, random = %d", rand() % 0xff); // test log on function fn_for_test(); /** // on red hat, view syslog tail -f /var/log/messages | grep test_syslog // on debian tail -f /var/log/syslog | grep test_syslog */ ns_syslog::close_syslog(); return 0;}bool execute_prog(const char* psz_prog_path_name, const char* psz_cmd_line){ bool b_rc = false; char szBuf[1024] = { '\0'}; std::string strPathName = ""; std::string strCmdLine = ""; do { if ((NULL == psz_prog_path_name) || (NULL == psz_cmd_line)) { break; } sprintf(szBuf, "%s %s", psz_prog_path_name, psz_cmd_line); system(szBuf); b_rc = true; } while (0); return b_rc;}#define MY_FIRST_FILE "/var/log/my_src.dat"#define MY_NEW_DIR "/var/log/my_test_dir"int fn_for_test(){ long long ll_file_cnt = 0; FILE* pfile = NULL; char sz_buf[1024] = { '\0'}; execute_prog("mkdir", "-p " MY_NEW_DIR); do { MYLOG_INFO("ll_file_cnt = %lld", ll_file_cnt++); // write a test file pfile = fopen(MY_FIRST_FILE, "w+b"); if (NULL != pfile) { MYLOG_E("open file ok : [%s]", MY_FIRST_FILE); memset(sz_buf, 0, sizeof(sz_buf)); sprintf(sz_buf, "%s : time = %lld, ll_file_cnt = %lld", "test tiny file", (long long)time(NULL), ll_file_cnt); MYLOG_D("sz_buf = %s", sz_buf); fwrite(sz_buf, sizeof(char), sizeof(sz_buf) / sizeof(char), pfile); fclose(pfile); pfile = NULL; } else { MYLOG_E("open file error : [%s]", MY_FIRST_FILE); } // move test file to a new file // %s//var/log/my_src.dat_4200694_4200687 sprintf(sz_buf, "%s/%s_%lld_%lld", MY_NEW_DIR, "my_dst", (long long)time(NULL), ll_file_cnt); rename(MY_FIRST_FILE, sz_buf); MYLOG_D("rename(%s, %s)", MY_FIRST_FILE, sz_buf); // 为了公平起见, 睡上几毫秒，模拟其他业务逻辑占用的时间 usleep(1 * 1000); // sleep 1ms // 已经模拟出吃内存的情况 // 原因: rename这个API可能不是阻塞执行的 } while (1); return 0;}/** run result*/
// @file my_syslog.h// @brief syslog日志宏的定义#include#include #include #include #include #include namespace ns_syslog {typedef struct _tag_log_condition { bool b_EMERG; bool b_ALERT; bool b_CRIT; bool b_ERR; bool b_WARNING; bool b_NOTICE; bool b_INFO; bool b_DEBUG; _tag_log_condition() { b_EMERG = false; b_ALERT = false; b_CRIT = false; b_ERR = false; b_WARNING = false; b_NOTICE = false; b_INFO = false; b_DEBUG = false; }} TAG_LOG_CONDITION;extern TAG_LOG_CONDITION g_log_condition;// ----------------------------------------------------------------------------// syslog macro// ----------------------------------------------------------------------------#define MYLOG_EMERG(fmt, ...) \if (ns_syslog::g_log_condition.b_EMERG) { \syslog(LOG_INFO, "[%s : %s.%d : %s()] : " fmt, "EMERG", __FILE__, __LINE__, __FUNCTION__, ##__VA_ARGS__); \}#define MYLOG_EM(fmt, ...) \if (ns_syslog::g_log_condition.b_EMERG) { \syslog(LOG_INFO, "[%s : %s.%d : %s()] : " fmt, "EMERG", __FILE__, __LINE__, __FUNCTION__, ##__VA_ARGS__); \}// ----------------------------------------------------------------------------#define MYLOG_ALERT(fmt, ...) \if (ns_syslog::g_log_condition.b_ALERT) { \syslog(LOG_INFO, "[%s : %s.%d : %s()] : " fmt, "ALERT", __FILE__, __LINE__, __FUNCTION__, ##__VA_ARGS__); \}#define MYLOG_A(fmt, ...) \if (ns_syslog::g_log_condition.b_ALERT) { \syslog(LOG_INFO, "[%s : %s.%d : %s()] : " fmt, "ALERT", __FILE__, __LINE__, __FUNCTION__, ##__VA_ARGS__); \}// ----------------------------------------------------------------------------#define MYLOG_CRIT(fmt, ...) \if (ns_syslog::g_log_condition.b_CRIT) { \syslog(LOG_INFO, "[%s : %s.%d : %s()] : " fmt, "CRIT", __FILE__, __LINE__, __FUNCTION__, ##__VA_ARGS__); \}#define MYLOG_C(fmt, ...) \if (ns_syslog::g_log_condition.b_CRIT) { \syslog(LOG_INFO, "[%s : %s.%d : %s()] : " fmt, "CRIT", __FILE__, __LINE__, __FUNCTION__, ##__VA_ARGS__); \}// ----------------------------------------------------------------------------#define MYLOG_ERR(fmt, ...) \if (ns_syslog::g_log_condition.b_ERR) { \syslog(LOG_INFO, "[%s : %s.%d : %s()] : " fmt, "ERR", __FILE__, __LINE__, __FUNCTION__, ##__VA_ARGS__); \}#define MYLOG_E(fmt, ...) \if (ns_syslog::g_log_condition.b_ERR) { \syslog(LOG_INFO, "[%s : %s.%d : %s()] : " fmt, "ERR", __FILE__, __LINE__, __FUNCTION__, ##__VA_ARGS__); \}// ----------------------------------------------------------------------------#define MYLOG_WARNING(fmt, ...) \if (ns_syslog::g_log_condition.b_WARNING) { \syslog(LOG_INFO, "[%s : %s.%d : %s()] : " fmt, "WARNING", __FILE__, __LINE__, __FUNCTION__, ##__VA_ARGS__); \}#define MYLOG_W(fmt, ...) \if (ns_syslog::g_log_condition.b_WARNING) { \syslog(LOG_INFO, "[%s : %s.%d : %s()] : " fmt, "WARNING", __FILE__, __LINE__, __FUNCTION__, ##__VA_ARGS__); \}// ----------------------------------------------------------------------------#define MYLOG_NOTICE(fmt, ...) \if (ns_syslog::g_log_condition.b_NOTICE) { \syslog(LOG_INFO, "[%s : %s.%d : %s()] : " fmt, "NOTICE", __FILE__, __LINE__, __FUNCTION__, ##__VA_ARGS__); \}#define MYLOG_N(fmt, ...) \if (ns_syslog::g_log_condition.b_NOTICE) { \syslog(LOG_INFO, "[%s : %s.%d : %s()] : " fmt, "NOTICE", __FILE__, __LINE__, __FUNCTION__, ##__VA_ARGS__); \}// ----------------------------------------------------------------------------#define MYLOG_INFO(fmt, ...) \if (ns_syslog::g_log_condition.b_INFO) { \syslog(LOG_INFO, "[%s : %s.%d : %s()] : " fmt, "INFO", __FILE__, __LINE__, __FUNCTION__, ##__VA_ARGS__); \}#define MYLOG_I(fmt, ...) \if (ns_syslog::g_log_condition.b_INFO) { \syslog(LOG_INFO, "[%s : %s.%d : %s()] : " fmt, "INFO", __FILE__, __LINE__, __FUNCTION__, ##__VA_ARGS__); \}// ----------------------------------------------------------------------------#define MYLOG_DEBUG(fmt, ...) \if (ns_syslog::g_log_condition.b_DEBUG) { \syslog(LOG_INFO, "[%s : %s.%d : %s()] : " fmt, "DEBUG", __FILE__, __LINE__, __FUNCTION__, ##__VA_ARGS__); \}#define MYLOG_D(fmt, ...) \if (ns_syslog::g_log_condition.b_DEBUG) { \syslog(LOG_INFO, "[%s : %s.%d : %s()] : " fmt, "DEBUG", __FILE__, __LINE__, __FUNCTION__, ##__VA_ARGS__); \}// ----------------------------------------------------------------------------void open_syslog(const char* pszLogOwner);void set_log_level( bool b_EMERG = false, bool b_CRIT = false, bool b_ALERT = false, bool b_ERR = false, bool b_WARNING = false, bool b_NOTICE = false, bool b_INFO = false, bool b_DEBUG = false);void close_syslog();} // namespace ns_syslog {
// @file my_syslog.cpp// @brief syslog日志宏的实现#include "my_syslog.h"namespace ns_syslog {TAG_LOG_CONDITION g_log_condition;void open_syslog(const char* pszLogOwner){ openlog(((NULL != pszLogOwner) ? pszLogOwner : "my_syslog"), LOG_NOWAIT | LOG_PID, LOG_LOCAL1);}void set_log_level( bool b_EMERG, bool b_CRIT, bool b_ALERT, bool b_ERR, bool b_WARNING, bool b_NOTICE, bool b_INFO, bool b_DEBUG){ int i_mask = 0; if (b_EMERG) { // LOG_EMERG 日志会阻塞控制台程序, 必须要使这个条件为false, 不能执行这里 // LOG_EMERG 不仅是记录到日志, 还打印到正在运行的程序上, 阻塞了程序的执行. 不能用这种日志 i_mask |= LOG_MASK(LOG_EMERG); } if (b_ALERT) { i_mask |= LOG_MASK(LOG_ALERT); } if (b_CRIT) { i_mask |= LOG_MASK(LOG_CRIT); } if (b_ERR) { i_mask |= LOG_MASK(LOG_ERR); } if (b_WARNING) { i_mask |= LOG_MASK(LOG_WARNING); } if (b_NOTICE) { i_mask |= LOG_MASK(LOG_NOTICE); } if (b_INFO) { i_mask |= LOG_MASK(LOG_INFO); } if (b_DEBUG) { i_mask |= LOG_MASK(LOG_DEBUG); } setlogmask(i_mask);}void close_syslog(){ closelog();}} // namespace ns_syslog { # ==============================================================================# @file Makefile# @brief# lostspeed 2017-10-10# testcase\test_syslog\Makefile# ==============================================================================MAKE_VER = ./Makefile 1.1.0.0 build 2017-10-10 18:10BIN = test_rename_fileBIN_OUT = "./"# cat stringBIN_OUT := $(BIN)TARGETS = ${ BIN}CC = g++CFLAGS = -Wall \ --std=c++98 \ -gINC_PATH = -I. \MY_LIBS =PRJ_LIBS = ${ MY_LIBS}LIB_LINK_OPT = -lstdc++ -pthread -lpthread -lrt -ldlDEPEND_CODE_DIR = ./depend_dir \DEPEND_CODE_SRC = $(shell find $(DEPEND_CODE_DIR) -name '*.cpp')DEPEND_CODE_OBJ = $(DEPEND_CODE_SRC:.cpp=.o)# 根目录文件不能用find来搞, 会遍历到子目录去的ROOT_CODE_SRC = $(wildcard *.cpp)ROOT_CODE_OBJ = $(ROOT_CODE_SRC:.cpp=.o)SUB_CODE_DIR = ./sub_dir \SUB_CODE_SRC = $(shell find $(SUB_CODE_DIR) -name '*.cpp')SUB_CODE_OBJ = $(SUB_CODE_SRC:.cpp=.o)help: @echo make help @echo command list: @echo make rebuild @echo "DEPEND_CODE_DIR = " $(DEPEND_CODE_DIR) @echo "DEPEND_CODE_SRC = " $(DEPEND_CODE_SRC) @echo "DEPEND_CODE_OBJ = " $(DEPEND_CODE_OBJ) @echo "SUB_CODE_DIR = " $(SUB_CODE_DIR) @echo "SUB_CODE_SRC = " $(SUB_CODE_SRC) @echo "SUB_CODE_OBJ = " $(SUB_CODE_OBJ)show_version: @echo ================================================================================ @echo ${ MAKE_VER} @echo ================================================================================ ls -l -p --time-style="+%Y-%m-%d %H:%M:%S" $(find `pwd`) @echo --------------------------------------------------------------------------------clean: @echo ================================================================================ rm -f $(BIN) @echo ================================================================================ rm -f $(ROOT_CODE_OBJ) @echo ================================================================================ rm -f $(DEPEND_CODE_OBJ) @echo ================================================================================ rm -f $(SUB_CODE_OBJ) @echo ================================================================================all: ${ TARGETS} @echo Makefile all... @echo **============================================================================== if [ -f $(BIN) ] ; \ then \ echo "build ok :)" ; \ else \ echo "build failed :(" ; \ fi; @echo **==============================================================================$(BIN): $(ROOT_CODE_OBJ) $(DEPEND_CODE_OBJ) $(SUB_CODE_OBJ) ${ CC} ${ CFLAGS} ${ INC_PATH} \ $(ROOT_CODE_OBJ) $(DEPEND_CODE_OBJ) $(SUB_CODE_OBJ) \ ${ PRJ_LIBS} ${ LIB_LINK_OPT} \ -o ${ BIN} \.cpp.o: @echo $< @echo build $^ ... ${ CC} ${ CFLAGS} ${ INC_PATH} -c $^ -o $@rebuild: @echo Makefile rebuild... make clean make all
你可能感兴趣的文章
tf rnn layer
查看>>
tf input layer
查看>>
tf model create
查看>>
tf dense layer两种创建方式的对比和numpy实现
查看>>
tf initializer
查看>>
tf 从RNN到BERT
查看>>
tf keras SimpleRNN源码解析
查看>>
tf keras Dense源码解析
查看>>
tf rnn输入输出的维度和权重的维度
查看>>
检验是否服从同一分布
查看>>
tf callbacks
查看>>
keras、tf、numpy实现logloss对比
查看>>
MyBatisPlus简单入门（SpringBoot）
查看>>
攻防世界web进阶PHP2详解
查看>>
攻防世界web进阶区web2详解
查看>>
xss-labs详解(上)1-10
查看>>
xss-labs详解(下)11-20
查看>>
攻防世界web进阶区ics-05详解
查看>>
攻防世界web进阶区FlatScience详解
查看>>
攻防世界web进阶区ics-04详解
查看>>