在线：Auto-Event 事件多线程访问时信号丢失？

[TheNewIpad]

 void CStream::Start()
        {
            //封装了ResetEvent(),该事件是一个Auto-ResetEvent
            m_pNotifyCompleteAcq->Reset();  

            // 创建线程
            bool bRet = m_pAcqThread->Run(this, __ThreadProc, CThread::PRIORITY_TIME_CRITICAL, 25);
            if (!bRet)
            {
                throw CTLException(__FUNCTION__, __LINE__, GC_ERR_ERROR, "Unable to start");
            }

            // 等待被创建的线程完成某个操作
            m_pNotifyCompleteAcq->Wait(INFINITE); // 封装了WaitForFingleObject
        }

        void CStream::__ThreadProc()
        {
            // 挂通或者SE=1失败，则还原采集前状态
            if (!__SecureAttach())
            {
                m_pNotifyCompleteAcq->Notify_one(); // 封装了setEvent
                return ;
            }

            // 通知主线程，已经开始采集
            m_pNotifyCompleteAcq->Notify_one();// 封装了setEvent

            //标记A： Other code here, while循环等代码  
        }

如上代码用了2年，今日有用户报告存在start卡死问题， 拿到dump文件后分析发现发现
1、 线程执行CStream::Start卡在了m_pNotifyCompleteAcq->Wait(INFINITE); 这是线程卡死的根因
2、 __ThreadProc() 线程执行到了 “标记A” 处。
3、 复现环境是win10，编译环境是VS2010.
4、 m_pNotifyCompleteAcq仅在上述代码中使用，其他地方为创建和释放。
5、 复现时可以确认，__ThreadProc中，SetEvent没有返回错误。

网上查找资料，发现一些跟MSDN有出入，而我又爱又狠的答案：

另外一种情况可能会引起死锁，假设“receiver”线程检查队列中是否有字符，这时候发生context switch，切换到“sender”线程，他对一个event对象进行pulse操作，这时候又发生context switch，回到receiver线程，调用WaitForSingleObject()等待event对象，由于这个动作发生在sender线程激发event之后，所以event会遗失，于是receiver永远不会醒来，程序进入死锁状态，这正是semaphore之所以被创造用以解决为题的地方。

可是MSDN如此解释：

When the state of an auto-reset event object is signaled, it remains signaled until a single waiting thread is released; the system then automatically resets the state to nonsignaled. If no threads are waiting, the event object's state remains signaled.

求我遇到的问题的可能原因。

[赵4老师]

《Windows核心编程》

[赵4老师]

有时不将“调用函数名字＋各参数值，进入函数后各参数值，中间变量值，退出函数前准备返回的值，返回函数到调用处后函数名字＋各参数值＋返回值”这些信息写日志到文件中是无论如何也发现不了问题在哪里的，包括捕获各种异常、写日志到屏幕、单步或设断点或生成core或dmp文件、……这些方法都不行！ 写日志到文件参考下面：

//循环向a函数每次发送200个字节长度（这个是固定的）的buffer,
//a函数中需要将循环传进来的buffer，组成240字节（也是固定的）的新buffer进行处理，
//在处理的时候每次从新buffer中取两个字节打印
#ifdef _MSC_VER
    #pragma warning(disable:4996)
#endif
#include <stdio.h>
#include <stdlib.h>
#include <string.h>
#ifdef _MSC_VER
    #include <windows.h>
    #include <process.h>
    #include <io.h>
    #define  MYVOID             void
    #define  vsnprintf          _vsnprintf
#else
    #include <unistd.h>
    #include <sys/time.h>
    #include <pthread.h>
    #define  CRITICAL_SECTION   pthread_mutex_t
    #define  MYVOID             void *
#endif
//Log{
#define MAXLOGSIZE 20000000
#define MAXLINSIZE 16000
#include <time.h>
#include <sys/timeb.h>
#include <stdarg.h>
char logfilename1[]="MyLog1.log";
char logfilename2[]="MyLog2.log";
static char logstr[MAXLINSIZE+1];
char datestr[16];
char timestr[16];
char mss[4];
CRITICAL_SECTION cs_log;
FILE *flog;
#ifdef _MSC_VER
void Lock(CRITICAL_SECTION *l) {
    EnterCriticalSection(l);
}
void Unlock(CRITICAL_SECTION *l) {
    LeaveCriticalSection(l);
}
void sleep_ms(int ms) {
    Sleep(ms);
}
#else
void Lock(CRITICAL_SECTION *l) {
    pthread_mutex_lock(l);
}
void Unlock(CRITICAL_SECTION *l) {
    pthread_mutex_unlock(l);
}
void sleep_ms(int ms) {
    usleep(ms*1000);
}
#endif
void LogV(const char *pszFmt,va_list argp) {
    struct tm *now;
    struct timeb tb;

    if (NULL==pszFmt||0==pszFmt[0]) return;
    vsnprintf(logstr,MAXLINSIZE,pszFmt,argp);
    ftime(&tb);
    now=localtime(&tb.time);
    sprintf(datestr,"%04d-%02d-%02d",now->tm_year+1900,now->tm_mon+1,now->tm_mday);
    sprintf(timestr,"%02d:%02d:%02d",now->tm_hour     ,now->tm_min  ,now->tm_sec );
    sprintf(mss,"%03d",tb.millitm);
    printf("%s %s.%s %s",datestr,timestr,mss,logstr);
    flog=fopen(logfilename1,"a");
    if (NULL!=flog) {
        fprintf(flog,"%s %s.%s %s",datestr,timestr,mss,logstr);
        if (ftell(flog)>MAXLOGSIZE) {
            fclose(flog);
            if (rename(logfilename1,logfilename2)) {
                remove(logfilename2);
                rename(logfilename1,logfilename2);
            }
        } else {
            fclose(flog);
        }
    }
}
void Log(const char *pszFmt,...) {
    va_list argp;

    Lock(&cs_log);
    va_start(argp,pszFmt);
    LogV(pszFmt,argp);
    va_end(argp);
    Unlock(&cs_log);
}
//Log}
#define ASIZE    200
#define BSIZE    240
#define CSIZE      2
char Abuf[ASIZE];
char Cbuf[CSIZE];
CRITICAL_SECTION cs_HEX;
CRITICAL_SECTION cs_BBB;
struct FIFO_BUFFER {
    int  head;
    int  tail;
    int  size;
    char data[BSIZE];
} BBB;
int No_Loop=0;
void HexDump(int cn,char *buf,int len) {
    int i,j,k;
    char binstr[80];

    Lock(&cs_HEX);
    for (i=0;i<len;i++) {
        if (0==(i%16)) {
            sprintf(binstr,"%03d %04x -",cn,i);
            sprintf(binstr,"%s %02x",binstr,(unsigned char)buf[i]);
        } else if (15==(i%16)) {
            sprintf(binstr,"%s %02x",binstr,(unsigned char)buf[i]);
            sprintf(binstr,"%s  ",binstr);
            for (j=i-15;j<=i;j++) {
                sprintf(binstr,"%s%c",binstr,('!'<buf[j]&&buf[j]<='~')?buf[j]:'.');
            }
            Log("%s\n",binstr);
        } else {
            sprintf(binstr,"%s %02x",binstr,(unsigned char)buf[i]);
        }
    }
    if (0!=(i%16)) {
        k=16-(i%16);
        for (j=0;j<k;j++) {
            sprintf(binstr,"%s   ",binstr);
        }
        sprintf(binstr,"%s  ",binstr);
        k=16-k;
        for (j=i-k;j<i;j++) {
            sprintf(binstr,"%s%c",binstr,('!'<buf[j]&&buf[j]<='~')?buf[j]:'.');
        }
        Log("%s\n",binstr);
    }
    Unlock(&cs_HEX);
}
int GetFromRBuf(int cn,CRITICAL_SECTION *cs,struct FIFO_BUFFER *fbuf,char *buf,int len) {
    int lent,len1,len2;

    lent=0;
    Lock(cs);
    if (fbuf->size>=len) {
        lent=len;
        if (fbuf->head+lent>BSIZE) {
            len1=BSIZE-fbuf->head;
            memcpy(buf     ,fbuf->data+fbuf->head,len1);
            len2=lent-len1;
            memcpy(buf+len1,fbuf->data           ,len2);
            fbuf->head=len2;
        } else {
            memcpy(buf     ,fbuf->data+fbuf->head,lent);
            fbuf->head+=lent;
        }
        fbuf->size-=lent;
    }
    Unlock(cs);
    return lent;
}
MYVOID thdB(void *pcn) {
    char        *recv_buf;
    int          recv_nbytes;
    int          cn;
    int          wc;
    int          pb;

    cn=(int)pcn;
    Log("%03d thdB              thread begin...\n",cn);
    while (1) {
        sleep_ms(10);
        recv_buf=(char *)Cbuf;
        recv_nbytes=CSIZE;
        wc=0;
        while (1) {
            pb=GetFromRBuf(cn,&cs_BBB,&BBB,recv_buf,recv_nbytes);
            if (pb) {
                Log("%03d recv %d bytes\n",cn,pb);
                HexDump(cn,recv_buf,pb);
                sleep_ms(1);
            } else {
                sleep_ms(1000);
            }
            if (No_Loop) break;//
            wc++;
            if (wc>3600) Log("%03d %d==wc>3600!\n",cn,wc);
        }
        if (No_Loop) break;//
    }
#ifndef _MSC_VER
    pthread_exit(NULL);
#endif
}
int PutToRBuf(int cn,CRITICAL_SECTION *cs,struct FIFO_BUFFER *fbuf,char *buf,int len) {
    int lent,len1,len2;

    Lock(cs);
    lent=len;
    if (fbuf->size+lent>BSIZE) {
        lent=BSIZE-fbuf->size;
    }
    if (fbuf->tail+lent>BSIZE) {
        len1=BSIZE-fbuf->tail;
        memcpy(fbuf->data+fbuf->tail,buf     ,len1);
        len2=lent-len1;
        memcpy(fbuf->data           ,buf+len1,len2);
        fbuf->tail=len2;
    } else {
        memcpy(fbuf->data+fbuf->tail,buf     ,lent);
        fbuf->tail+=lent;
    }
    fbuf->size+=lent;
    Unlock(cs);
    return lent;
}
MYVOID thdA(void *pcn) {
    char        *send_buf;
    int          send_nbytes;
    int          cn;
    int          wc;
    int           a;
    int          pa;

    cn=(int)pcn;
    Log("%03d thdA              thread begin...\n",cn);
    a=0;
    while (1) {
        sleep_ms(100);
        memset(Abuf,a,ASIZE);
        a=(a+1)%256;
        if (16==a) {No_Loop=1;break;}//去掉这句可以让程序一直循环直到按Ctrl+C或Ctrl+Break或当前目录下存在文件No_Loop
        send_buf=(char *)Abuf;
        send_nbytes=ASIZE;
        Log("%03d sending %d bytes\n",cn,send_nbytes);
        HexDump(cn,send_buf,send_nbytes);
        wc=0;
        while (1) {
            pa=PutToRBuf(cn,&cs_BBB,&BBB,send_buf,send_nbytes);
            Log("%03d sent %d bytes\n",cn,pa);
            HexDump(cn,send_buf,pa);
            send_buf+=pa;
            send_nbytes-=pa;
            if (send_nbytes<=0) break;//
            sleep_ms(1000);
            if (No_Loop) break;//
            wc++;
            if (wc>3600) Log("%03d %d==wc>3600!\n",cn,wc);
        }
        if (No_Loop) break;//
    }
#ifndef _MSC_VER
    pthread_exit(NULL);
#endif
}
int main() {
#ifdef _MSC_VER
    InitializeCriticalSection(&cs_log);
    InitializeCriticalSection(&cs_HEX);
    InitializeCriticalSection(&cs_BBB);
#else
    pthread_t threads[2];
    int threadsN;
    int rc;
    pthread_mutex_init(&cs_log,NULL);
    pthread_mutex_init(&cs_HEX,NULL);
    pthread_mutex_init(&cs_BBB,NULL);
#endif
    Log("Start===========================================================\n");

    BBB.head=0;
    BBB.tail=0;
    BBB.size=0;

#ifdef _MSC_VER
    _beginthread((void(__cdecl *)(void *))thdA,0,(void *)1);
    _beginthread((void(__cdecl *)(void *))thdB,0,(void *)2);
#else
    threadsN=0;
    rc=pthread_create(&(threads[threadsN++]),NULL,thdA,(void *)1);if (rc) Log("%d=pthread_create %d error!\n",rc,threadsN-1);
    rc=pthread_create(&(threads[threadsN++]),NULL,thdB,(void *)2);if (rc) Log("%d=pthread_create %d error!\n",rc,threadsN-1);
#endif

    if (!access("No_Loop",0)) {
        remove("No_Loop");
        if (!access("No_Loop",0)) {
            No_Loop=1;
        }
    }
    while (1) {
        sleep_ms(1000);
        if (No_Loop) break;//
        if (!access("No_Loop",0)) {
            No_Loop=1;
        }
    }
    sleep_ms(3000);
    Log("End=============================================================\n");
#ifdef _MSC_VER
    DeleteCriticalSection(&cs_BBB);
    DeleteCriticalSection(&cs_HEX);
    DeleteCriticalSection(&cs_log);
#else
    pthread_mutex_destroy(&cs_BBB);
    pthread_mutex_destroy(&cs_HEX);
    pthread_mutex_destroy(&cs_log);
#endif
    return 0;
}

[paschen]

通常这种问题都很肥难查找 __ThreadProc中是否执行到了SetEvent

[TheNewIpad]

引用 2 楼 zhao4zhong1 的回复:

有时不将“调用函数名字＋各参数值，进入函数后各参数值，中间变量值，退出函数前准备返回的值，返回函数到调用处后函数名字＋各参数值＋返回值”这些信息写日志到文件中是无论如何也发现不了问题在哪里的，包括捕获各种异常、写日志到屏幕、单步或设断点或生成core或dmp文件、……这些方法都不行！ 写日志到文件参考下面： [/code]

是否可以理解为，使用dump分析可能得到错误的结果？ 应该改用打印日志的方法？

[TheNewIpad]

引用 3 楼 paschen 的回复:

通常这种问题都很肥难查找 __ThreadProc中是否执行到了SetEvent

1、从dump分析，我确认 __ThreadProc() 线程执行到了 “标记A” 处。 即从代码角度看，绝对执行了SetEvent的封装 2、我确认，SetEvent执行没有错误发生。 在Notify_one(); 中，我添加了对SetEvent返回值的判断，如果发生错误，会有打印信息。

[TheNewIpad]

引用 2 楼 zhao4zhong1 的回复:

有时不将“调用函数名字＋各参数值，进入函数后各参数值，中间变量值，退出函数前准备返回的值，返回函数到调用处后函数名字＋各参数值＋返回值”这些信息写日志到文件中是无论如何也发现不了问题在哪里的，包括捕获各种异常、写日志到屏幕、单步或设断点或生成core或dmp文件、……这些方法都不行！ 写日志到文件参考下面： [/code]

Windbg Attach到目标进程是否可靠呢？

[赵4老师]

引用 4 楼 TheNewIpad 的回复:

[quote=引用 2 楼 zhao4zhong1 的回复:] 有时不将“调用函数名字＋各参数值，进入函数后各参数值，中间变量值，退出函数前准备返回的值，返回函数到调用处后函数名字＋各参数值＋返回值”这些信息写日志到文件中是无论如何也发现不了问题在哪里的，包括捕获各种异常、写日志到屏幕、单步或设断点或生成core或dmp文件、……这些方法都不行！ 写日志到文件参考下面： [/code]

是否可以理解为，使用dump分析可能得到错误的结果？ 应该改用打印日志的方法？[/quote] 理解正确。 在你怀疑可能引起错误的地方，添加详细得不能再详细的日志。 http://blog.csdn.net/zhao4zhong1/article/details/53078924

[赵4老师]

引用 6 楼 TheNewIpad 的回复:

[quote=引用 2 楼 zhao4zhong1 的回复:] 有时不将“调用函数名字＋各参数值，进入函数后各参数值，中间变量值，退出函数前准备返回的值，返回函数到调用处后函数名字＋各参数值＋返回值”这些信息写日志到文件中是无论如何也发现不了问题在哪里的，包括捕获各种异常、写日志到屏幕、单步或设断点或生成core或dmp文件、……这些方法都不行！ 写日志到文件参考下面： [/code]

Windbg Attach到目标进程是否可靠呢？[/quote] 比不上自行添加写日志到文件更可靠我觉得。

[TheNewIpad]

引用 8 楼 zhao4zhong1 的回复:

[quote=引用 6 楼 TheNewIpad 的回复:] [quote=引用 2 楼 zhao4zhong1 的回复:] 有时不将“调用函数名字＋各参数值，进入函数后各参数值，中间变量值，退出函数前准备返回的值，返回函数到调用处后函数名字＋各参数值＋返回值”这些信息写日志到文件中是无论如何也发现不了问题在哪里的，包括捕获各种异常、写日志到屏幕、单步或设断点或生成core或dmp文件、……这些方法都不行！ 写日志到文件参考下面： [/code]

Windbg Attach到目标进程是否可靠呢？[/quote] 比不上自行添加写日志到文件更可靠我觉得。[/quote] 好吧，你赢了，谁让我没一点点思路呢，我就写个日志试试吧。不过呢，Windbg attach到目标进程，得到的分析跟上述描述一致，跟wait卡死的理论推测的现象一致。

[赵4老师]

坐等楼主在前方战斗的好消息。