想给自己之前的日志库，加一个染色的功能
gcc 有一个自己的特性，叫 __thread，介绍可以看这里，https://gcc.gnu.org/onlinedocs…，是可以用来修饰一个全局变量，从而让这个全局变量在每个线程都有一份拷贝，例子如下：
#include <stdio.h>
#include <unistd.h>
#include <pthread.h>
#include <sys/syscall.h>
__thread int n = 0;
int ns[] = {1, 2};
void* thread_func(void *arg) {
int tid = (int)syscall(__NR_gettid);
printf("1, tid = %d, n = %d\n", tid, n);
n = *((int*)arg);
printf("2, tid = %d, n = %d\n", tid, n);
while (1) {
printf("3, tid = %d, n = %d\n", tid, n);
sleep(1);
}
}
int main() {
for (int i = 0; i < sizeof(ns)/sizeof(ns[0]); i++) {
pthread_t tid;
pthread_create(&tid, NULL, thread_func, &ns[i]);
printf("thread %d created\n", tid);
}
while (1) {
sleep(1);
}
return 0;
}
跑起来之后的输出是这样的
thread 1082132800 created thread 1090525504 created 1, tid = 11508, n = 0 2, tid = 11508, n = 1 3, tid = 11508, n = 1 1, tid = 11509, n = 0 2, tid = 11509, n = 2 3, tid = 11509, n = 2 3, tid = 11508, n = 1 3, tid = 11509, n = 2 3, tid = 11508, n = 1 3, tid = 11509, n = 2 3, tid = 11508, n = 1 3, tid = 11509, n = 2
用在日志库中，成为这个样子
#include <net/if.h>
#include <arpa/inet.h>
#include "logger.h"
__thread int m_iLoggerLogTraceOn;// 是否开启染色日志
int Logger::Init(eLogLevel level, const char* pLogFileDir, const char* pLogFileBaseName, uint32_t uiLogFileRollingSize, uint32_t uiMaxCharPerLine, uint32_t uiLogBufferLines)
{
pthread_mutex_lock(&m_stInitLock);
if (m_bInited || level == LOG_LEVEL_OFF)
{
pthread_mutex_unlock(&m_stInitLock);
return 0;
}
然后加了一个修改的接口
void Logger::setLogTraceOn(int iTraceOn)
{
printf("set trace switch to %d\n", iTraceOn);
m_iLoggerLogTraceOn = iTraceOn;
printf("after set, iLoggerLogTraceOn(%p) is %d, tid is %d\n", &m_iLoggerLogTraceOn, m_iLoggerLogTraceOn, (int)syscall(__NR_gettid));
}
在各个函数处也加了跟踪
void Logger::LogToMem(eLogLevel level, const char* format, ...)
{
printf("trace on(%p) : %d, tid is %d\n", &m_iLoggerLogTraceOn, m_iLoggerLogTraceOn, (int)syscall(__NR_gettid));
if (m_bInited && (level >= m_eLevel || m_iLoggerLogTraceOn))
{
va_list args;
va_start(args, format);
char *pWritePtr = m_pLogBufferMem+((__sync_add_and_fetch(&m_uiWriteLineCount, 1) % m_uiLogBufferLines) * m_uiMaxCharPerLine);
vsnprintf(pWritePtr+1, m_uiMaxCharPerLine-2, format, args);
*(pWritePtr) = 1;
va_end(args);
}
}
void Logger::LogToStdout(eLogLevel level, const char* format, ...)
{
printf("trace on(%p) : %d, tid is %d\n", &m_iLoggerLogTraceOn, m_iLoggerLogTraceOn, (int)syscall(__NR_gettid));
if (m_bInited && (level >= m_eLevel || m_iLoggerLogTraceOn))
{
va_list args;
va_start(args, format);
vprintf(format, args);
va_end(args);
}
}
然后在业务中这么使用
if (pSession->strAppUser == "BAAEB881F489FC59")
{
Logger::setLogTraceOn(1);
LOG_INFO("appuser match, turn logger trace on");
}
然而，跑起来之后是这样的
set trace switch to 1 after set, iLoggerLogTraceOn(0x797bf0) is 1, tid is 9696 [2015-03-26 14:28:20] [INFO][ OnRequestData@ src/BusiObj.cpp,0136] appuser match, turn logger trace on trace on(0x43b0693c) : 0, tid is 9696 trace on(0x43b0693c) : 0, tid is 9696 trace on(0x43b0693c) : 0, tid is 9696 trace on(0x43b0693c) : 0, tid is 9696 trace on(0x43b0693c) : 0, tid is 9696
注意到一个神奇的现象，同一个变量，在同一个线程里面，指针不一样了
考虑到之前做函数耗时测试，和代码覆盖度测试的时候，遇到过由于进程关系复杂（又多进程又线程的）引起的问题，考虑是否由于这个原因引起的问题，于是写了这么一个测试
来看这个：
t2.cpp
#include <stdio.h>
#include <unistd.h>
#include <sys/syscall.h>
__thread int n = 0;
extern "C" {
void busi(int arg) {
printf("1, tid = %d, n = %d\n", (int)syscall(__NR_gettid), n);
n = arg;
printf("2, tid = %d, n = %d\n", (int)syscall(__NR_gettid), n);
while (1) {
printf("3, tid = %d, n = %d\n", (int)syscall(__NR_gettid), n);
sleep(1);
}
}
}
f1.cpp
#include <stdio.h>
#include <stdlib.h>
#include <dlfcn.h>
#include <pthread.h>
#include <unistd.h>
int ns[] = {1, 2};
typedef void(*busi_func_ptr_t)(int);
busi_func_ptr_t busi_func_ptr ;
void* thread_func(void *args) {
int arg = *((int*)args);
printf("0, arg = %d\n", arg);
(*busi_func_ptr)(arg);
}
int main() {
int fork_ret = fork();
if (fork_ret == 0) {
void* dll = dlopen("./t2.so", RTLD_LAZY);
if (dll == NULL) {
printf("%s\n", dlerror());
abort();
}
busi_func_ptr = (busi_func_ptr_t)dlsym(dll, "busi");
char *err = dlerror();
if (err != NULL) {
printf("%s\n", err);
abort();
}
for (int i = 0; i < sizeof(ns)/sizeof(ns[0]); i++) {
pthread_t tid;
pthread_create(&tid, NULL, thread_func, &ns[i]);
printf("thread %d created\n", tid);
}
while (1) {
sleep(1);
}
dlclose(dll);
} else {
printf("chid proc %d\n", fork_ret);
while (1) {
sleep(1);
}
}
return 0;
}
makefile
all: g++ t2.cpp -O3 -shared -o t2.so -fPIC g++ f1.cpp -O3 -o f1 -ldl -pthread
makefile 带 O3 是为了跟实际情况保持一致
运行输出如下
thread 1082132800 created chid proc 12856 thread 1090525504 created 0, arg = 1 1, tid = 12857, n = 0 2, tid = 12857, n = 1 3, tid = 12857, n = 1 0, arg = 2 1, tid = 12858, n = 0 2, tid = 12858, n = 2 3, tid = 12858, n = 2 3, tid = 12857, n = 1 3, tid = 12858, n = 2 3, tid = 12857, n = 1 3, tid = 12858, n = 2
看起来是没有问题的，又考虑到，我们的日志是先编译成一个静态的 lib.a 的库，然后在编译到 lib.so 的动态库中，最后由框架加载运行的，于是试了一下这么搞
我写了一个 test.cpp
public:
//与tcpd的接口
char * OnRequestData(const char * p_pcResData,
int p_iResDataLen,
int& p_iRetDataLen,
int& p_iDataBufLen,
const char *p_pcHostIP,
const char * p_pcBusiBuf,
int& piProcessedDataLen, int fd)
{
Logger::setLogTraceOn(1);
printf("on request123\n");
LOG_DEBUG("on request123");
LOG_ERR("on request123");
Logger::setLogTraceOn(0);
printf("on request456\n");
LOG_DEBUG("on request456");
LOG_ERR("on request456");
Logger::setLogTraceOn(1);
printf("on request789\n");
LOG_DEBUG("on request789");
LOG_ERR("on request789");
Logger::setLogTraceOn(0);
return NULL;
}
int OnDllDataUpdate(const char * p_pcDataBuf, int p_iDataBufLen) {}
bool FreeMemBlock(char * p_pcMemBlock, int p_iMemBlockLen) {
return true;
}
bool InitDllWithCfgFile(const char *p_pcCfgFileName) {
printf("%s\n", p_pcCfgFileName);
Logger::Init(Logger::LOG_LEVEL_INFO, "./", "stdout");
Logger::setLogTraceOn(1);
}
然后把含有日志库的通用组件的静态库和这个 test.cpp 放在同一个目录中，编出一个动态库
g++ test.cpp libcommontool.a -shared -o lib.so -fPIC
然后用 tcpd 去加载这个动态库
这个是 Init 函数打出来的
CALL DLL INIT INTERFACE ./main.cfg set trace switch to 1 after set, iLoggerLogTraceOn(0x51be60) is 1, tid is 15719
这个是 OnRquest 函数打出来的
set trace switch to 1 after set, iLoggerLogTraceOn(0x52f280) is 1, tid is 15721 on request123 trace on(0x4090193c) : 0, tid is 15721 trace on(0x4090193c) : 0, tid is 15721 [2015-03-26 14:49:15][ERROR][ OnRequestData@ test.cpp,0026] on request123 set trace switch to 0 after set, iLoggerLogTraceOn(0x52f280) is 0, tid is 15721 on request456 trace on(0x4090193c) : 0, tid is 15721 trace on(0x4090193c) : 0, tid is 15721 [2015-03-26 14:49:15][ERROR][ OnRequestData@ test.cpp,0030] on request456 set trace switch to 1 after set, iLoggerLogTraceOn(0x52f280) is 1, tid is 15721 on request789 trace on(0x4090193c) : 0, tid is 15721 trace on(0x4090193c) : 0, tid is 15721 [2015-03-26 14:49:15][ERROR][ OnRequestData@ test.cpp,0034] on request789 set trace switch to 0 after set, iLoggerLogTraceOn(0x52f280) is 0, tid is 15721
于是到此就陷入了僵局，查资料说 gcc 在编译动态链接库的时候对全局变量的处理有一些特殊，看到这里，http://blog.csdn.net/zxh821112/article/details/8969541，还有，http://blog.csdn.net/yuyin86/article/details/10239479，http://bbs.chinaunix.net/thread-1620536-1-1.html，和这里，https://www.owent.net/2014/01/cpp%E5%8F%88%E4%B8%80%E5%9D%91-%E5%8A%A8%E6%80%81%E9%93%BE%E6%8E%A5%E5%BA%93%E4%B8%AD%E7%9A%84%E5%85%A8%E5%B1%80%E5%8F%98%E9%87%8F.html，不过这些帖子在讨论，主要是集中在一个动态库被多个进程引用的时候的赋值问题，跟我们这个场景还不太一样
——————
2015-3-26 20:34:46 update http://lists.freebsd.org/piper… 这里有一篇，之前没发现
———————
2015-3-27 11:33:43 update 最后确认是编译器的问题，生产环境的编译器是 4.1.2 的老古董，换一个 gcc 4.8.2 问题就烟消云散了