我的日志记录模块线程安全吗？

Posted 2023-02-16

【中文标题】我的日志记录模块线程安全吗？

【英文标题】：Is my logging-module thread safe?

【发布时间】：2013-06-17 02:32:13

【问题描述】：

伙计们，我是线程和日志记录的初学者。 顺便说一句，我不是以英语为母语的人，如果我的英语有任何错误，请原谅我。

我创建了一个多线程软件，其中每个线程使用日志记录模块，如下所示： 每个线程使用不同的日志文件，所以我认为发生数据冲突的几率是0。

__inline void print_logW(int _level,const wchar_t *domain,const wchar_t *msg)

    wchar_t mess[200] = _T("");

    if(_level<=traceLevel)
    
        __time64_t timer;
        struct tm t_st;
        _time64(&timer);

        localtime_s(&t_st,&timer);

        if (domain == NULL)
        
            domain = _T("");
        
        if (msg != NULL)
        
            if (showTimeStampFlag == true)
            
                swprintf_s(mess,200,_T("%s : %ld"),msg,GetTickCount());
            
            else
            
                wcscpy_s(mess,200,msg);
            
        

        if(oldTime.tm_year != t_st.tm_year || oldTime.tm_mon != t_st.tm_mon || oldTime.tm_mday != t_st.tm_mday) 
        
            oldTime = t_st;
            print_log_preparebyDateW();
        


        FILE* fp;
        errno_t err = _wfopen_s(&fp, this->m_pathW, _T("at+, ccs=UTF-8"));
        if (err != 0)
        
            // error
            return;
        

        fwprintf_s(fp, m_logFormatW,
            _level,
            1900 + t_st.tm_year, t_st.tm_mon + 1, t_st.tm_mday,
            t_st.tm_hour, t_st.tm_min, t_st.tm_sec,
            domain, mess
            );
        fflush(fp);
        fclose(fp);
    

当我看到我制作的软件的日志时，我发现了一个问题，有时线程进程变得如此缓慢（一个进程（例如获取图像的指针）通常只需要 16 ms max，将需要 0.2 秒 或更长时间才能完成）。我还在调查这个问题的原因，但首先我想知道日志模块是否已经是线程安全的。

顺便说一下，对于参数，"_level"是打印或取消打印进程细节的日志级别 我使用"domain" 显示执行日志记录的类"msg" 是日志的内容（例如“进程 1 已启动”） 至于m_logFormatW，

m_logFormatW = _T("[%.2d][%.4d-%.2d-%.2dT%.2d:%.2d:%.2d][%s] %s\n");

如果有任何问题或不清楚的地方，请随时提出。

【问题讨论】：

“oldTime”从何而来？每个线程是否都有自己的包含该函数的类的实例？ FWIW：当你知道一个值是无符号的时，你可能想使用“%u”。例如，您使用 32 位毫秒时间戳，每 49.7 天中的 24.85 天将变为负数，但您将它们打印为“%ld”，因此它将继续并在那里打一个减号 :)跨度>

不断打开和关闭fp 非常昂贵。为了加快你的日志记录：使用一个大缓冲区（32k？）并且只有在它变满时才写入；处理所有信号并确保在其处理程序中刷新并关闭日志文件。不过，您的方式要安全得多。

@kfsone ：感谢您的建议。我会将格式从“%ld”更改为“%u”。关于“oldTime”，它实际上是记录器类的一个属性，它的数据类型为“struct tm”

@Dariusz ：谢谢，我也想过这样做，但是由于软件有时会崩溃，所以我想知道是什么进程导致它崩溃，所以我不认为日志缓冲和刷新是个好主意。

@LinardiKurniawan 你抱怨日志记录很慢，所以我指出了一些原因。你用它做什么是你自己的选择:)

【参考方案1】：

只要您链接到multi-threaded runtime libraries 并且oldTime 不是全局或静态变量，您的日志函数将是线程安全的。如果oldTime 是全局变量或静态变量，您在访问或修改它时需要序列化对它的访问，否则您将面临竞争条件的风险。 可能 不是线程安全的唯一另一件事是print_log_preparebyDateW，但很难说，因为您没有包含它的代码。只要oldTime 不是全局或静态的，并且您使用的所有运行时库函数都被标记为线程安全或者是 MSDN 中标记为线程安全的库的一部分，您就可以了。

我能看到的唯一其他问题是打开文件时。如果文件已经打开并且另一个线程尝试记录信息，则打开调用将失败，从而导致信息丢失。这是因为_wfopen_s 打开文件时没有任何共享模式。您可以通过使用std::mutex 并在文件打开时将其锁定并在文件关闭后将其解锁来解决此问题。

您的工作线程执行时间比预期更长的一个可能原因是打开日志文件、写入信息、刷新文件并关闭它可能需要一些额外的时间。即使在涉及缓存的情况下，只要发生文件 I/O，就会发生这种情况。通常，您可以通过打开日志文件一次然后在应用程序终止时将其关闭来减少时间。

另一个减少工作线程执行时间的可能解决方案是使用管道。在这种情况下，您将日志文本写入管道，并有一个额外的线程从管道读取并写入日志文件。这将消除工作线程记录信息时可能发生的任何磁盘 I/O。您可能会遇到一些情况，如果管道已满，日志记录会花费一些额外的时间，但这种情况不会经常发生。

【参考方案2】：

您的方法适用于单线程应用程序，并且由于您没有序列化日志消息请求，因此不适用于多线程环境。

最好在开源中查看一些编写良好的记录器类，例如

a) AsynchronousAndSynchronouslogger - http://www.codeproject.com/Articles/288827/g2log-An-efficient-asynchronous-logger-using-Cplus

b) 简单线程安全 - http://cpplogging.codeplex.com/

c) Log4Cpp - http://log4cpp.sourceforge.net/

【讨论】：

“不序列化日志消息请求”与此代码的线程安全无关。而且由于他以“at+”模式打开文件并使用单个 printf，因此他的写入保证是原子的。

如果这个函数没有序列化。不会根据时间戳打印日志。

@shivakumar ：感谢您的建议。由于我想捕捉应用程序崩溃之前的时刻，我更喜欢使用同步记录器。因此，我正在考虑尝试（b）Simplethreadsafe，并且在网上搜索之后，我还发现了一个名为Legit Log C++ Library（legitlog.com/Products/LegitLogCLibrary）的线程安全记录器。顺便问一下，你之前试过Legit Log吗？？

从未尝试过该库。它看起来像一个静态库。如果是dll就好了。