[LOGCXX-534] Crashed in log->forcedLog function when running with multi-thread

• Type: Bug
• Status: Resolved
• Priority: Critical
• Resolution: Fixed
• Affects Version/s: 0.12.0
• Fix Version/s: 0.12.1
• Component/s: Core
• Assignee: Robert Middleton
• Reporter: Lin Chen
• Created: 09/Sep/21 08:57
• Updated: 13/Sep/21 22:28
• Resolved: 13/Sep/21 22:28

Description

Hi All,

 

I'm using the latest log4cxx 0.12.0 in win10 with vs2015

When using log4cxx in multi-thread, the process will crash. 

The crash point is log->forcedLog in bench_mt function

My test coding is following.

 

// example.cpp : Defines the entry point for the console application.
//

#include "stdafx.h"
#include "malloc.h"
#include <stdarg.h>
#include <string>
#include <stdlib.h>
#include <log4cxx/logger.h>
#include <log4cxx/rollingfileappender.h>
#include <log4cxx/patternlayout.h>
#include <log4cxx/basicconfigurator.h>


void init_log4cxx()
{
    log4cxx::LayoutPtr layout = std::static_pointer_cast<log4cxx::Layout>(std::make_shared<log4cxx::PatternLayout>(L"%d{yyyy/MM/dd HH:mm:ss.sssZ}  [3344:%.6t]  [%32F(%4L)]  [%-5p]  %m%n"));
    log4cxx::RollingFileAppenderPtr appender = std::make_shared<log4cxx::RollingFileAppender>(layout, L"./debug_log4cxx.log");
    appender->setName(LOG4CXX_STR("BENCH"));
    appender->setMaxFileSize(LOG4CXX_STR("10MB"));
    appender->setMaxBackupIndex(10);
    appender->setEncoding(LOG4CXX_STR("utf-8"));
    log4cxx::helpers::Pool pool;
    appender->activateOptions(pool);
    log4cxx::BasicConfigurator::configure(appender);
    log4cxx::Logger::getRootLogger()->setLevel(log4cxx::Level::getAll());
}

void bench(int howmany, log4cxx::LoggerPtr log)
{
    using std::chrono::duration;
    using std::chrono::duration_cast;
    using std::chrono::high_resolution_clock;

    auto start = high_resolution_clock::now();
    for (auto i = 0; i < howmany; ++i)
    {
        log->forcedLog(log4cxx::Level::getInfo(), "Hello logger: msg number", log4cxx::spi::LocationInfo(__FILE__, "", __LINE__));
    }

    auto delta = high_resolution_clock::now() - start;
    auto delta_d = duration_cast<duration<double>>(delta).count();

    char res[1000] = { 0 };
    sprintf_s(res, "{%s} Elapsed: {%f} secs {%d}/sec", "left", "right", "BENCH", delta_d, int(howmany / delta_d));
    LOG4CXX_INFO(log, std::string(res));
}

void bench_mt(int howmany, log4cxx::LoggerPtr log, size_t thread_count)
{
    using std::chrono::duration;
    using std::chrono::duration_cast;
    using std::chrono::high_resolution_clock;

    std::vector<std::thread> threads;
    threads.reserve(thread_count);
    auto start = high_resolution_clock::now();
    for (size_t t = 0; t < thread_count; ++t)
    {
        threads.emplace_back([&]() {
            for (int j = 0; j < howmany / static_cast<int>(thread_count); j++)
            {
                log->forcedLog(log4cxx::Level::getInfo(), "Hello logger: msg number", log4cxx::spi::LocationInfo(__FILE__, "", __LINE__));
            }
        });
    }

    for (auto &t : threads)
    {
        t.join();
    };

    auto delta = high_resolution_clock::now() - start;
    auto delta_d = duration_cast<duration<double>>(delta).count();
    char res[1000] = { 0 };
    sprintf_s(res, "mt {%s} Elapsed: {%f} secs {%d}/sec", "left", "right", "BENCH", delta_d, int(howmany / delta_d));
    LOG4CXX_INFO(log, std::string(res));
}

void bench_single_threaded(int iters)
{
    log4cxx::LoggerPtr appLogger = log4cxx::Logger::getLogger(L"BENCH");
    LOG4CXX_INFO(appLogger, "**************************************************************");
    LOG4CXX_INFO(appLogger, "Single threaded: messages ");
    LOG4CXX_INFO(appLogger, "**************************************************************");
    bench(iters, appLogger);
}


int main(int argc, char *argv[])
{
    init_log4cxx();

    log4cxx::LoggerPtr appLogger = log4cxx::Logger::getLogger(L"BENCH");

    int iters = 250000;
    size_t threads = 4;
    int max_threads = 1000;
    try
    {
        bench_single_threaded(iters);
        bench_mt(iters, appLogger, 1);
        bench_mt(iters, appLogger, 2);
    }
    catch (std::exception &ex)
    {
        // spdlog::error(ex.what());
        return EXIT_FAILURE;
    }
    return EXIT_SUCCESS;

    return 0;
}

Thanks,
McGrady

Issue Links

• links to: GitHub Pull Request #71