4

记录一次排查log4cxx库按照日期回滚,不创建新目录的BUG - sherlock_lin

 1 year ago
source link: https://www.cnblogs.com/sherlock-lin/p/17099807.html
Go to the source link to view the article. You can view the picture content, updated content and better typesetting reading experience. If the link is broken, please click the button below to view the snapshot at that time.
neoserver,ios ssh client

记录一次排查log4cxx库按照日期回滚,不创建新目录的BUG

C++ 项目,使用了 log4cxx 日志库,版本为:0.10.0

项目中需要按照日期备份日志,即一天一个日志目录,目录下是日志文件,即目录层级为:.../log/2022-10-02/log.log,当日期变更后,目录变化:.../log/2022-10-03/log.log

使用的 log4cxx 的配置文件如下:

log4j.rootLogger=INFO,R
# Pattern to output the caller's file name and line number.
log4j.appender.R=org.apache.log4j.DailyRollingFileAppender
log4j.appender.R.ImmediateFlush=true
log4j.appender.R.Append=true
log4j.appender.R.DatePattern='${LOG_HOMR_DIR}/'yyyy-MM-dd'/log.log'
log4j.appender.R.layout=org.apache.log4j.PatternLayout
log4j.appender.R.layout.ConversionPattern=%d{yyyy-MM-dd hh:mm:ss.SSS} %-5p [%c] %m %n

网络上和官方的教程中,DatePattern 都是作为日志备份的策略,当日期变化时,使用 DatePattern 的规则追加到旧日志的文件后缀上,完成日志按照日期回滚,但是这和我们的需求不符合

经查询,DatePattern 中的 ' 包含的不会被代码解析,利用此特性,写成上面的格式,可以实现按照日期创建目录

问题来了,刚开始程序启动一切正常,但是当日期变化时,新的日期目录并没有如期创建,日志内容还是记录在程序启动时创建的日志文件中

2、排查步骤

2.1、错误代码定位

刚开始以为是配置文件写错了,在网络上查询并尝试了一天,毫无收获,开始怀疑是不是log4cxx的源码有问题,遂下载源码查看

下载编译使用过程略过

调试发现,当日期变化时,终端打印了一行错误信息:

log4cxx: Exception during rollover

从源码中搜索,所幸该错误信息打印只有两处,且出现在一个函数中,文件:rollingfileappender.cpp,函数:rolloverrollover 方法用在日志的回滚处,比如这里是 DailyRollingFileAppender,所以当日期变动时,会触发日志回滚,该方法被调用

但是这里面有两处一模一样的打印,因为无法单步调试,这里通过修改日志,发现错误打印是在函数最后,但是这里只打印了异常,没有任何错误信息,所以我们稍微修改一下代码,打印一下错误信息:

try{
    ...
}catch (std::exception& ex) {
	LogLog::warn(LOG4CXX_STR("Exception during rollover"));
    //新增下面一行代码
    LogLog::warn(LOG4CXX_STR("Exception during rollover, " + std::string(ex.what())));
}

打印出来的错误信息如下:

Exception during rollover, status code=2

没有太多的信息,只有一个错误码,尝试在网络上搜索了一下,没有太大的收货

只用使用死方法,加大量的日志,最终找到了错误的那一行代码:

OutputStreamPtr os(new FileOutputStream(rollover1->getActiveFileName(), rollover1->getAppend()));

这里是创建了一个文件输出流,用于日志文件的输出

rollover1->getActiveFileName() 返回日志文件的绝对路径

rollover1->getAppend() 返回一个bool变量,表示日志内容是否追加,值由配置文件中的 log4j.appender.R.Append=true 决定

2.2、问题猜测

注意,到这里涉及到了文件流,那么结合之前调试现象,程序刚启动的时候会创建目录(甚至时多级目录)和文件,但是日期变化时没有新目录创建

猜测,会不会是日期变动的时候,log4cxx 在使用文件流的时候,没有找到对应目录导致的错误

针对该猜想,我们手动创建日期目录,再次调试,发现,按照日期备份日志的功能OK了,说明我们的猜测是正确的,那么就是 log4cxx 的代码问题了,后面定位错误就方便了

2.3、错误代码分析

我们继续查看 FileOutputStream 的代码,如下:

FileOutputStream::FileOutputStream(const LogString& filename,bool append) : pool(), fileptr(open(filename, append, pool)) {}

我们发现,这里就是个构造函数,唯一有逻辑的就是 open 方法的调用,那就查看一下:

apr_file_t* FileOutputStream::open(const LogString& filename,
    bool append, Pool& pool) {
    apr_fileperms_t perm = APR_OS_DEFAULT;
    apr_int32_t flags = APR_WRITE | APR_CREATE;
    if (append) {
        flags |= APR_APPEND;
    } else {
        flags |= APR_TRUNCATE;
    }
    File fn;
    fn.setPath(filename);
    apr_file_t* fileptr = 0;
    apr_status_t stat = fn.open(&fileptr, flags, perm, pool);
    if (stat != APR_SUCCESS) {
      throw IOException(stat);
    }
    return fileptr;
}

这里发现一个 throw IOException(stat);,应该就是前面打印错误信息的那个,所以这里的 stat 应该是2,这里先记录下,后面会用到

那么错误代码应该就是这一行了:

apr_status_t stat = fn.open(&fileptr, flags, perm, pool);

再进入看代码:

log4cxx_status_t File::open(apr_file_t** file, int flags,
      int perm, Pool& p) const {
    return apr_file_open(file, getPath(p), flags, perm, p.getAPRPool());
}

详细阅读代码,可以发现,这里使用了 apr 库进行文件读写

上网查询了一圈 apr 的资料,加上自己测试代码:

#include <cstdio>
#include <iostream>
#include <string>
#include <apr-1.0/apr_file_io.h>
#include <apr-1.0/apr_file_info.h>
using namespace std;
void printError(apr_status_t rv)
{
    char errbuf[256];
    apr_strerror(rv, errbuf, sizeof(errbuf));
    cout << errbuf << endl;
}

string FILENAME = "../log/test.log";//日志路径

int main()
{
    apr_pool_t *p;
    apr_initialize();
    apr_pool_create(&p, NULL);
    apr_file_t *filetest = NULL;
    filetest = NULL;
    try
    {
        printError(stat);
        stat = apr_file_open(&filetest, FILENAME.c_str(),
                                          APR_WRITE | APR_CREATE | APR_APPEND,
                                          APR_UREAD | APR_UWRITE | APR_GREAD, p);
        cout << stat << endl;
        printError(stat);//目录不存在时,这里打印2
        apr_size_t byte = 3;
        apr_file_write(filetest, "aaa", &byte);
        apr_file_close(filetest);
    }
    catch (std::exception &e)
    {
        cout << e.what() << endl;
    }

    apr_pool_destroy(p);
    return 0;
}

简单的测试发现,如果文件路径存在,则正常,如果不存在则异常,且异常时,state的值为2

这里就和上面的调试(staus code=2)呼应上了,那么这里的2就是apr库的一个错误码,表示目录不存在

到此,问题原因基本定位到了

2.4、错误原因

综上,定位到了错误代码,找到了错误原因

log4cxx 使用 apr 库进行文件的读写操作,但是在日志回滚的时候,没有考虑到目录不存在的情况,导致调用 apr_file_open 方法失败,返回值2,并通过 std::exception 抛出来

3、解决方法

既然找到了错误原因,那么就好解决了,既然是目录不存在,我们在打开文件之前创建目录不就行了

可以创建目录的地方有几处:

  1. rollingfileappender.cpp 的创建文件流的地方;
  2. fileoutputstream.cpp 的构造函数中;
  3. file.cpp 的 open 方法中;
  4. fileoutputstream.cpp 的 open 方法中;

我们知道 rollingfileappender.cpp 文件是文件回滚的 appender,不应该有太多的实际操作,加在这里不合适;

细看 file.cpp,我们发现,这就是一个对 apr 文件操作的封装,给外层提供操作文件的简单接口,这里应该正常抛出错误,如果有些地方就需要目录不存在报错呢?所以加在这里也不合适

那么应该加在 fileoutputstream.cpp 中,且类名也是文件输出流,它也需要保证文件输出正确,那在这里加目录的创建是对的,且加在 open 方法中最合理,且应该调用 file.cpp 中的方法才不会破坏代码的结构,我们发现 log4cxx::Filemkdir 方法的定义,那正好,省的我们自己封转,还需要去熟悉 apr

修改 fileoutputstream.cpp 文件的 open()

需要新增的代码如下:

File pathFn(filename.substr(0, filename.find_last_of("/")));//linux的路径,windows需要使用\\
pathFn.mkdirs(pool);

open() 的整体代码如下:

apr_file_t* FileOutputStream::open(const LogString& filename,
    bool append, Pool& pool) {
    //下面两行代码是新增的
    File pathFn(filename.substr(0, filename.find_last_of("/")));
    pathFn.mkdirs(pool);
    
    apr_fileperms_t perm = APR_OS_DEFAULT;
    apr_int32_t flags = APR_WRITE | APR_CREATE;
    if (append) {
        flags |= APR_APPEND;
    } else {
        flags |= APR_TRUNCATE;
    }
    File fn;
    fn.setPath(filename);
    apr_file_t* fileptr = 0;
    apr_status_t stat = fn.open(&fileptr, flags, perm, pool);
    if (stat != APR_SUCCESS) {
      throw IOException(stat);
    }
    return fileptr;
}

编译,测试,一切OK


About Joyk


Aggregate valuable and interesting links.
Joyk means Joy of geeK