之前在C下面开发程序,对日志的输出都没有特别的规范。但是从事了一段时间的Java程序开发之后,发现好的日志输出,以及日志文件的大小和文件数限制,对于一个规范的服务,是一个标配。但是发现C下面的logger输出没有一个简单实用的工具类,目前能找到log4plus等,相对来说太复杂了。所以决定自己写一个简单的,能自己做日志文件大小限制,并且设定日志文件数的类。
这个类,起名叫做logger。实现的难点在于多线程下日志的输出必须不能产生较大延时,并且当日志文件超过限制大小时,能够写入另一个文件,并且对于日志文件数也能进行设定。当logger里面的成员变量FILE* fp定义为当前写入的文件时,面临如下问题:
当发现文件内容过大时,如何做好多线程下面写入日志文件的切换?解决这个问题需要满足两个条件:
1. 多线程下不能引入过大延时,如果每次写日志都加锁的话,必然会带来较大延时
2. 文件切换必须只能由一个线程来完成,保证其他线程不会又进行一次切换。
对于第二个问题可以采用如下逻辑:
if 文件过大:
加锁
再次判读文件是否过大
如果是进行文件切换,改变文件大小
解锁
这种逻辑应该是比较常见的解决多个线程只能由一个线程来完成某件事情的逻辑,当有多个线程发现需要做关键操作时,都会进入临界区,但是只能会有一个线程先进入,当先进入的线程完成操作后,改变状态并退出,那么另一个进入的线程就会发现事情已经完成,直接退出,不会执行操作了。
但是有另一个问题,对于那些未判断出需要经常文件切换的线程来说,可能正向老的文件FILE*写数据,另一个线程切换FILE值,可能会有问题。
所以我采用logger同时打开多个文件,可以同时向新旧文件写入的逻辑,这样顶多会有某些线程写入旧文件,某些写入新文件的问题,不过这种缺陷,我觉得还可以容忍,待以后想出更好的办法再修正。
附上源码:
logger.h
#ifndef LOGGER_H__
#define LOGGER_H__
#include <string>
#include <stdlib.h>
#include <vector>
#include <pthread.h>
struct FileInfo{
std::string fileBaseName;
FILE* fp;
FileInfo(){
fileBaseName = "";
fp = NULL;
}
};
class logger{
public:
//错误日志文件名配置名称
static const std::string LOGGER_ERROR_FILE_NAME_CONF_NAME;
//信息日志文件名配置名称
static const std::string LOGGER_INFO_FILE_NAME_CONF_NAME;
//调试日志文件名配置名称
static const std::string LOGGER_DEBUG_FILE_NAME_CONF_NAME;
//单个文件大小配置名称
static const std::string LOGGER_SINGLE_FILE_CAPA_CONF_NAME;
//保存的文件个数配置名称
static const std::string LOGGER_FILE_NUM_CONF_NAME;
//输出日志的级别设定配置名称
static const std::string LOGGER_LEVEL_CONF_NAME;
private:
//错误日志文件名和文件描述符
std::vector<FileInfo> errFileInfoVec;
//信息日志文件名和文件描述符
std::vector<FileInfo> infoFileInfoVec;
//调试日志文件名和文件描述符
std::vector<FileInfo> debugFileInfoVec;
unsigned char currentIndexOfErr;
unsigned char currentIndexOfInfo;
unsigned char currentIndexOfDebug;
//单个日志文件大小
int fileCapability;
//log 文件个数
int fileNumLimit;
//输出的日志级别( error, info, debug )
std::string loggerLevel;
int prefixSize;
//读写锁
pthread_mutex_t mutex;
private:
FILE* selectFP(std::vector<FileInfo> &infoVec, unsigned char ¤tIndex);
public:
bool init(const std::string configFileName);
void info(const char* format, ...);
void error(const char* format, ...);
void debug(const char* format, ...);
};
#endif
logger.cpp
#include "logger.h"
#include <time.h>
#include <sys/time.h>
#include "confReader.h"
#include <string.h>
#include <stdio.h>
#include <stdarg.h>
#define MAX_MSG_LEN 1024
#define TIMESTAMP_LEN 100
const std::string logger::LOGGER_ERROR_FILE_NAME_CONF_NAME = "error_file_name";
const std::string logger::LOGGER_INFO_FILE_NAME_CONF_NAME = "info_file_name";
const std::string logger::LOGGER_DEBUG_FILE_NAME_CONF_NAME = "debug_file_name";
const std::string logger::LOGGER_SINGLE_FILE_CAPA_CONF_NAME = "single_file_capability";
const std::string logger::LOGGER_FILE_NUM_CONF_NAME = "file_num";
const std::string logger::LOGGER_LEVEL_CONF_NAME = "log_level";
bool logger::init(const std::string configFileName){
ConfReader reader;
reader.readConfFile(configFileName);
std::string errFileName = reader.getParameterValue(logger::LOGGER_ERROR_FILE_NAME_CONF_NAME);
std::string infoFileName = reader.getParameterValue(logger::LOGGER_INFO_FILE_NAME_CONF_NAME);
std::string debugFileName = reader.getParameterValue(logger::LOGGER_DEBUG_FILE_NAME_CONF_NAME);
std::string singleFileCapabilityStr = reader.getParameterValue(logger::LOGGER_SINGLE_FILE_CAPA_CONF_NAME);
fileCapability = atoi(singleFileCapabilityStr.c_str());
std::string fileNumLimitStr = reader.getParameterValue(logger::LOGGER_FILE_NUM_CONF_NAME);
fileNumLimit = atoi(fileNumLimitStr.c_str());
FileInfo fInfo;
std::string tmpFileName;
char tmpBuffer[20] = {0};
for(int i=0;i<fileNumLimit;i++){
//open those error log files
fInfo.fileBaseName = errFileName;
tmpFileName = errFileName;
sprintf(tmpBuffer,"_%d",(i+1));
tmpFileName += tmpBuffer;
fInfo.fp = fopen(tmpFileName.c_str(),"w");
errFileInfoVec.push_back(fInfo);
//open those info log files
fInfo.fileBaseName = infoFileName;
tmpFileName = infoFileName;
sprintf(tmpBuffer,"_%d",(i+1));
tmpFileName += tmpBuffer;
fInfo.fp = fopen(tmpFileName.c_str(),"w");
infoFileInfoVec.push_back(fInfo);
//open those debug log files
fInfo.fileBaseName = debugFileName;
tmpFileName = debugFileName;
sprintf(tmpBuffer,"_%d",(i+1));
tmpFileName += tmpBuffer;
fInfo.fp = fopen(tmpFileName.c_str(),"w");
debugFileInfoVec.push_back(fInfo);
}
//set current log file index
currentIndexOfErr = 0;
currentIndexOfInfo = 0;
currentIndexOfDebug = 0;
//set log level
loggerLevel = reader.getParameterValue(logger::LOGGER_LEVEL_CONF_NAME);
prefixSize = strlen("ERROR:[TIME: ] [MSG: ]\n");
pthread_mutex_init(&mutex,NULL);
return true;
}
FILE* logger::selectFP(std::vector<FileInfo> &infoVec, unsigned char ¤tIndex){
FILE* fp = infoVec[currentIndex].fp;
int currentSize = ftell(fp);
if(currentSize>fileCapability){
pthread_mutex_lock(&mutex);
FILE* tmpfp = infoVec[currentIndex].fp;
currentSize = ftell(tmpfp);
if(currentSize>fileCapability){
currentIndex = (currentIndex+1)%fileNumLimit;
fp = infoVec[currentIndex].fp;
fseek(fp, 0, SEEK_SET);
}
pthread_mutex_unlock(&mutex);
}
return fp;
}
static std::string getCurrentFullTime(){
char timestamp[TIMESTAMP_LEN];
struct timeval time;
gettimeofday(&time, NULL);
struct tm* tm_t = localtime(&time.tv_sec);
strftime(timestamp , sizeof(timestamp),"%F.%H:%M:%S",tm_t);
return timestamp;
}
void logger::error(const char* format, ...){
char buf[ MAX_MSG_LEN + 1];
memset(buf, 0x00, MAX_MSG_LEN + 1);
if ( loggerLevel != "error" && loggerLevel != "info" && loggerLevel != "debug"){
return;
}
va_list ap;
va_start(ap, format);
vsnprintf( buf, MAX_MSG_LEN, format, ap);
va_end(ap);
std::string timestamp = getCurrentFullTime();
FILE* fp = selectFP(errFileInfoVec,currentIndexOfErr);
int currentSize = ftell(fp);
printf("current err file index is %d, size is %d\n", currentIndexOfErr, currentSize);
//output to stdout
fprintf(stdout, "ERROR:[TIME: %s] [MSG: %s]\n", timestamp.c_str(), buf);
//output to file
fprintf(fp, "ERROR:[TIME: %s] [MSG: %s]\n", timestamp.c_str(), buf);
}
void logger::info(const char* format, ...){
char buf[ MAX_MSG_LEN + 1];
memset(buf, 0x00, MAX_MSG_LEN + 1);
if ( loggerLevel != "info" && loggerLevel != "debug"){
return;
}
va_list ap;
va_start(ap, format);
vsnprintf( buf, MAX_MSG_LEN, format, ap);
va_end(ap);
std::string timestamp = getCurrentFullTime();
FILE* fp = selectFP(infoFileInfoVec,currentIndexOfInfo);
int currentSize = ftell(fp);
printf("current info file index is %d, size is %d\n", currentIndexOfInfo, currentSize);
//output to stdout
fprintf(stdout, "INFO:[TIME: %s] [MSG: %s]\n", timestamp.c_str(), buf);
//output to file
fprintf(fp, "INFO:[TIME: %s] [MSG: %s]\n", timestamp.c_str(), buf);
}
void logger::debug(const char* format, ...){
char buf[ MAX_MSG_LEN + 1];
memset(buf, 0x00, MAX_MSG_LEN + 1);
if ( loggerLevel != "debug" ){
return;
}
va_list ap;
va_start(ap, format);
vsnprintf( buf, MAX_MSG_LEN, format, ap);
va_end(ap);
std::string timestamp = getCurrentFullTime();
FILE* fp = selectFP(infoFileInfoVec,currentIndexOfDebug);
int currentSize = ftell(fp);
printf("current debug file is %d, size is %d\n", currentIndexOfDebug, currentSize);
//output to stdout
fprintf(stdout, "DEBUG:[TIME: %s] [MSG: %s]\n", timestamp.c_str(), buf);
//output to file
fprintf(fp, "DEBUG:[TIME: %s] [MSG: %s]\n", timestamp.c_str(), buf);
}
#ifdef LOGGER_TEST
logger myLogger;
void* printLog(void* arg){
int i = 200000000,j=0;
while(i--){
myLogger.error("thread id:%lu testLog:%s:%d",pthread_self(), "test1",j++);
}
return NULL;
}
int main(int argc, char* argv[]){
if(argc!=2){
printf("please input pragram, configFileName\n");
return -1;
}
myLogger.init(argv[1]);
pthread_t id[3];
for(int i=0;i<3;i++){
pthread_create(&(id[i]), NULL, printLog, NULL);
}
for(int i=0;i<3;i++){
pthread_join(id[i], NULL);
}
return 0;
}
#endif