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

1、背景
2、排查步骤
3、解决方法

1、背景

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，函数：rollover，rollover 方法用在日志的回滚处，比如这里是 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、解决方法

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

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

rollingfileappender.cpp 的创建文件流的地方；
fileoutputstream.cpp 的构造函数中；
file.cpp 的 open 方法中；
fileoutputstream.cpp 的 open 方法中；

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

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

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

posted @ 2023-02-07 20:56 sherlock_lin 阅读(511) 评论(0) 编辑收藏举报

刷新页面返回顶部

Sherlock的程序人生

专注于C++/Java的学习