source: trunk/MFCtooling/userlog/userlog.cpp @ 372

Last change on this file since 372 was 165, checked in by sherbold, 13 years ago
  • fixed USING_COSTUMLOG output
  • added define MAXINT in case it is missing
  • added selection storage for ComboLBoxes for better replays
File size: 16.6 KB
Line 
1#include "stdafx.h"
2#include "userlog.h"
3#include "windowsx.h"
4
5#include <map>
6#include <cstdio>
7
8#include "helpers.h"
9
10#ifdef __USING_MTRACE__
11#define OS_WIN32
12#include "msl/merror/inc/trace.h"
13
14#ifdef __ENCODE_BASE64__
15#include  "encode.h"
16#endif
17
18const static int traceLevel = 3;
19static int level;
20#endif
21
22#ifdef __USING_COSTUMLOG__
23static std::wofstream logfile;
24#endif
25
26#ifdef __TIMING__
27static unsigned long long timing = 0;
28static unsigned long long msgCounter = 0;
29static unsigned long long totalMsgCounter = 0;
30static bool msgCounterChange = false;
31#endif
32
33#ifndef MAXINT
34#define MAXUINT ((UINT)~((UINT)0))
35#define MAXINT ((INT(MAXUINT >> 1))
36#endif
37
38static MSG lastmsg;
39
40static bool keysPressed[256];
41
42inline bool keyAlreadyPressed(const MSG & msg) {
43        return (msg.message==WM_KEYDOWN || msg.message==WM_SYSKEYDOWN) && keysPressed[msg.wParam];
44}
45
46inline bool keyNotPressed(const MSG & msg) {
47        return (msg.message==WM_KEYUP || msg.message==WM_SYSKEYUP) && !keysPressed[msg.wParam];
48}
49
50
51HANDLE mutex;
52
53
54
55USERLOG_API void __cdecl InitUsagelog() {
56
57        mutex = CreateMutex(NULL, FALSE, TEXT("USAGELOGMUTEX"));
58        if( mutex == NULL ) {
59                MessageBox(0, L"MutexFailure", L"MutexFailure", 0);
60        }
61        for(int i=0; i<256; i++) {
62                keysPressed[i] = false;
63        }
64
65#ifdef __USING_COSTUMLOG__
66        InitLogfile();
67#endif
68        InitHookdata();
69        InitHooks();
70#ifdef __USING_MTRACE__
71        MTrace_AddToLevel(traceLevel,"%s<session>", LOGPREFIX);
72#endif
73#ifdef __USING_COSTUMLOG__
74        logfile << LOGPREFIX << "<session>" << std::endl;
75#endif
76}
77
78USERLOG_API void __cdecl ReleaseUsagelog() {
79        ReleaseHooks();
80#ifdef __USING_MTRACE__
81#ifdef __TIMING__
82        char * mtraceBuffer = new char[128];
83        sprintf(mtraceBuffer, "ul timing: %llu \t\t %llu \t\t %llu", timing, msgCounter, totalMsgCounter);
84        MTrace_AddToLevel(traceLevel,mtraceBuffer);
85        delete mtraceBuffer;
86        msgCounterChange = false;
87#endif
88        MTrace_AddToLevel(traceLevel,"%s</session>", LOGPREFIX);
89#endif
90#ifdef __USING_COSTUMLOG__
91        logfile << LOGPREFIX << "</session>" << std::endl;
92        CloseLogfile();
93#endif
94}
95
96#ifdef __USING_COSTUMLOG__
97void InitLogfile() {
98        logfile.open(LOGFILE, std::ios_base::app);
99        if( logfile.fail() ) {
100                MessageBox(0, L"Logfile could not be opend", L"Error", MB_OK);
101        }
102}
103#endif
104
105#ifdef __USING_COSTUMLOG__
106void CloseLogfile() {
107        logfile.close();
108}
109#endif
110
111void InitHookdata() {
112        myhookdata[CALLWNDHOOKID].nType = WH_CALLWNDPROC;
113        myhookdata[CALLWNDHOOKID].hkproc = CallWndProc;
114        myhookdata[GETMSGHOOKID].nType = WH_GETMESSAGE;
115        myhookdata[GETMSGHOOKID].hkproc = GetMsgProc;
116}
117
118void InitHooks() {
119        for( int i=0 ; i<NUMHOOKS ; i++ ) {
120                myhookdata[i].hookhandle = SetWindowsHookEx(myhookdata[i].nType, myhookdata[i].hkproc, (HINSTANCE) NULL, GetCurrentThreadId());
121                if( myhookdata[i].hookhandle!=NULL ) {
122                        myhookdata[i].active = true;
123                } else {
124                        myhookdata[i].active = false;
125                }
126        }
127}
128
129void ReleaseHooks() {
130        int counter = 0;
131        for( int i=0 ; i<NUMHOOKS ; i++ ) {
132                if( UnhookWindowsHookEx(myhookdata[i].hookhandle) ) counter++;
133        }
134}
135
136
137LRESULT CALLBACK CallWndProc(int nCode, WPARAM wParam, LPARAM lParam) {
138       
139        PCWPSTRUCT cwpMsg = (PCWPSTRUCT) lParam;
140        // Create a MSG struct from the cwpMsg struct
141        // The missing parameters are filled with dummy values
142        MSG msg;
143        msg.hwnd = cwpMsg->hwnd;
144        msg.message = cwpMsg->message;
145        msg.lParam = cwpMsg->lParam;
146        msg.wParam = cwpMsg->wParam;
147        msg.pt.x = -1;
148        msg.pt.y = -1;
149        msg.time = -1;
150        HookProc(CALLWNDHOOKID, nCode, &msg);
151
152        return CallNextHookEx(myhookdata[CALLWNDHOOKID].hookhandle, nCode, wParam, lParam);
153}
154
155LRESULT CALLBACK GetMsgProc(int nCode, WPARAM wParam, LPARAM lParam) {
156        PMSG msg = (PMSG) lParam;
157        HookProc(GETMSGHOOKID,nCode, msg);
158
159        return CallNextHookEx(myhookdata[GETMSGHOOKID].hookhandle, nCode, wParam, lParam);
160}
161
162void HookProc(int nFrom, int nCode, PMSG msg) {
163#ifdef __TIMING__
164        SYSTEMTIME systemTime;
165        GetSystemTime( &systemTime );
166        int startTime = systemTime.wMilliseconds+systemTime.wSecond*1000;
167#endif
168
169        DWORD waitResult;
170        // simple heuristic to eliminate duplicate messages
171        if( !( MessageEquals(*msg, lastmsg) || keyAlreadyPressed(*msg) || keyNotPressed(*msg) ) ) {
172                lastmsg = *msg;
173                if( msg->message==WM_KEYDOWN || msg->message==WM_SYSKEYDOWN ) {
174                        keysPressed[msg->wParam] = true;
175                }
176                if( msg->message==WM_KEYUP || msg->message==WM_SYSKEYUP ) {
177                        keysPressed[msg->wParam] = false;
178                }
179
180                // message filter:
181                // all messages that are defined in this switch statement will be part of the log
182                switch(msg->message) {
183                        // messages for monitoring GUI state
184                        case WM_CREATE:
185                        case WM_DESTROY:
186                        case WM_SETTEXT:
187
188                        // mouse messages
189                        case WM_LBUTTONDOWN:
190                        case WM_LBUTTONUP:
191                        case WM_LBUTTONDBLCLK:
192                        case WM_RBUTTONDOWN:
193                        case WM_RBUTTONUP:
194                        case WM_RBUTTONDBLCLK:
195                        case WM_MBUTTONDOWN:
196                        case WM_MBUTTONUP:
197                        case WM_MBUTTONDBLCLK:
198                        case WM_XBUTTONDOWN:
199                        case WM_XBUTTONUP:
200                        case WM_XBUTTONDBLCLK:
201                        case WM_NCLBUTTONDOWN:
202                        case WM_NCLBUTTONUP:
203                        case WM_NCLBUTTONDBLCLK:
204                        case WM_NCRBUTTONDOWN:
205                        case WM_NCRBUTTONUP:
206                        case WM_NCRBUTTONDBLCLK:
207                        case WM_NCMBUTTONDOWN:
208                        case WM_NCMBUTTONUP:
209                        case WM_NCMBUTTONDBLCLK:
210                        case WM_NCXBUTTONDOWN:
211                        case WM_NCXBUTTONUP:
212                        case WM_NCXBUTTONDBLCLK:
213
214                        // keyboard messages
215                        case WM_KEYDOWN:
216                        case WM_KEYUP:
217                        case WM_SYSKEYDOWN:
218                        case WM_SYSKEYUP:
219
220                        // internal messages usefull for replay/matching of events
221                        case WM_KILLFOCUS:
222                        case WM_SETFOCUS:
223                        case WM_COMMAND:
224                        case WM_SYSCOMMAND:
225                        case WM_HSCROLL:
226                        case WM_VSCROLL:
227                        case WM_MENUSELECT:
228                        case WM_USER:
229                                waitResult = WaitForSingleObject(mutex, 1000);
230                                if( waitResult==WAIT_OBJECT_0 ) {
231                                        WriteLogentryWString(msg, nFrom);
232                                        ReleaseMutex(mutex);
233                                }
234#ifdef __TIMING__
235                                msgCounter++;
236                                msgCounterChange = true;
237#endif // __TIMING__
238                                break;
239                        default:
240                                break;
241                }
242        }
243
244#ifdef __TIMING__
245        GetSystemTime( &systemTime );
246        timing += systemTime.wMilliseconds+systemTime.wSecond*1000-startTime;
247        totalMsgCounter++;
248        if( msgCounterChange && msgCounter%100==0 ) {
249#ifdef __USING_MTRACE__
250                char * mtraceBuffer = new char[128];
251                sprintf(mtraceBuffer, "ul timing: %llu \t\t %llu \t\t %llu", timing, msgCounter, totalMsgCounter);
252                MTrace_AddToLevel(traceLevel,mtraceBuffer);
253                delete mtraceBuffer;
254                msgCounterChange = false;
255#endif // __USING_MTRACE__
256        }
257#endif // __TIMING__
258}
259
260
261void WriteLogentryWString(PMSG msg, int nFrom) {
262        wchar_t * messageStr = NULL;
263        wchar_t buffer[128];
264        wchar_t * newWindowText = NULL;
265        wchar_t * windowName = NULL;
266        unsigned int command = 0;
267        int sourceType = -1;
268        HWND source = NULL;
269        HWND parentHandle = NULL;
270        wchar_t * windowClass = NULL;
271        bool isPopup = false;
272        bool isModal = false;
273        bool htMenu = false;
274        HWND menuHandle = NULL;
275        int scrollPos = -1;
276        unsigned int scrollType = 0;
277        HWND scrollBarHandle = NULL;
278        int retVal = 0;
279        int pointx = -1;
280        int pointy = -1;
281
282        // debug vars
283       
284        retVal = GetWindowText(msg->hwnd, buffer, 128);
285        if( retVal > 0  && retVal<MAXINT ) {
286                /*
287                 * In one case at the start of MarWin, when a resource with DlgId 1049 is created,
288                 * GetWindowText returns MAXINT. This behaviour is undocumented.
289                 */
290                replaceWithXmlEntitiesWString(buffer, &windowName, retVal+1);
291        }
292        int windowResourceId = GetDlgCtrlID(msg->hwnd);
293        if( windowResourceId<0 ) {
294                windowResourceId = 0;
295        }
296
297        //**************************************
298        // Message specific variables
299        //**************************************
300
301        if( msg->message==WM_COMMAND ) {
302                command = LOWORD(msg->wParam);
303                sourceType = HIWORD(msg->wParam);
304                source = (HWND) msg->lParam;
305        }
306        if( msg->message==WM_SYSCOMMAND ) {
307                command = LOWORD(msg->wParam);
308        }
309
310        if( msg->message==WM_CREATE ) {
311                parentHandle = GetParent(msg->hwnd);
312               
313                retVal = GetClassName(msg->hwnd, buffer, 128);
314                if( retVal > 0  && retVal<MAXINT ) {
315                        replaceWithXmlEntitiesWString(buffer, &windowClass, retVal+1);
316                }
317
318                // check is dialog is modal
319                // this check is not always accurate, but the best that I could come up with
320                isModal = IsWindowEnabled(parentHandle)==false;
321        }
322
323        if( msg->message==WM_SETTEXT ) {
324                wchar_t * newWindowTextBuffer = (wchar_t*)msg->lParam;
325                if( newWindowTextBuffer!=NULL ) {
326                        size_t len = wcslen(newWindowTextBuffer);
327                        replaceWithXmlEntitiesWString(newWindowTextBuffer, &newWindowText, len+1);
328                }
329        }
330
331        if( msg->message==WM_LBUTTONUP || msg->message==WM_RBUTTONUP || msg->message==WM_MBUTTONUP ||
332                msg->message==WM_LBUTTONDOWN || msg->message==WM_RBUTTONDOWN || msg->message==WM_MBUTTONDOWN ||
333                msg->message==WM_LBUTTONDBLCLK || msg->message==WM_RBUTTONDBLCLK || msg->message==WM_MBUTTONDBLCLK ||
334                msg->message==WM_NCLBUTTONUP || msg->message==WM_NCRBUTTONUP || msg->message==WM_NCMBUTTONUP ||
335                msg->message==WM_NCLBUTTONDOWN || msg->message==WM_NCRBUTTONDOWN || msg->message==WM_NCMBUTTONDOWN ||
336                msg->message==WM_NCLBUTTONDBLCLK || msg->message==WM_NCRBUTTONDBLCLK || msg->message==WM_NCMBUTTONDBLCLK) {
337               
338                RECT r;
339                DWORD dCursorPos = GetMessagePos();
340                GetWindowRect(msg->hwnd, &r);
341                //dont log absolut coordinates but relativ ones so you can use them in rule "LeftClickRelativ"
342                pointx = GET_X_LPARAM(dCursorPos)-r.left;
343                pointy = GET_Y_LPARAM(dCursorPos)-r.top;
344        }
345
346        if( msg->message==WM_NCLBUTTONDOWN ) {
347                if( msg->wParam==HTMENU ) {
348                        htMenu = true;
349                }
350        }
351       
352        if( msg->message==WM_INITMENU ) {
353                menuHandle = (HWND) msg->wParam;
354        }
355
356        if( msg->message==WM_HSCROLL || msg->message==WM_VSCROLL ) {
357                scrollType = LOWORD(msg->wParam);
358                scrollPos = HIWORD(msg->wParam);
359                scrollBarHandle = (HWND) msg->lParam;
360        }
361
362        /***************************************/
363        // put debugging variables here
364        /***************************************/
365
366
367        /***************************************
368         * Printing part
369         ***************************************/
370       
371        size_t bufsize = 2048;
372        wchar_t * msgBuffer = new wchar_t[bufsize];
373        size_t pos = 0;
374        //pos += swprintf_s(msgBuffer+pos, bufsize-pos,LOGPREFIXWSTRING);
375
376       
377        // print msg information
378        pos += swprintf_s(msgBuffer+pos,bufsize-pos,L"<msg type=\"%i\">",msg->message);
379        pos += swprintf_s(msgBuffer+pos,bufsize-pos,L"<param name=\"WPARAM\" value=\"%i\"/>", msg->wParam);
380        pos += swprintf_s(msgBuffer+pos,bufsize-pos,L"<param name=\"LPARAM\" value=\"%i\"/>", msg->lParam);
381
382        pos += swprintf_s(msgBuffer+pos,bufsize-pos,L"<param name=\"window.hwnd\" value=\"%i\"/>", msg->hwnd);
383        if( msg->message==WM_COMMAND ) {
384                pos += swprintf_s(msgBuffer+pos,bufsize-pos,L"<param name=\"command\" value=\"%i\"/>",command);
385                pos += swprintf_s(msgBuffer+pos,bufsize-pos,L"<param name=\"sourceType\" value=\"%i\"/>",sourceType);
386                pos += swprintf_s(msgBuffer+pos,bufsize-pos,L"<param name=\"source\" value=\"%i\"/>",source);
387        }
388        if( msg->message==WM_SYSCOMMAND ) {
389                pos += swprintf_s(msgBuffer+pos,bufsize-pos,L"<param name=\"command\" value=\"%i\"/>", command);
390        }
391
392        if( msg->message==WM_LBUTTONUP || msg->message==WM_RBUTTONUP || msg->message==WM_MBUTTONUP ||
393                msg->message==WM_LBUTTONDOWN || msg->message==WM_RBUTTONDOWN || msg->message==WM_MBUTTONDOWN ||
394                msg->message==WM_LBUTTONDBLCLK || msg->message==WM_RBUTTONDBLCLK || msg->message==WM_MBUTTONDBLCLK ||
395                msg->message==WM_NCLBUTTONUP || msg->message==WM_NCRBUTTONUP || msg->message==WM_NCMBUTTONUP ||
396                msg->message==WM_NCLBUTTONDOWN || msg->message==WM_NCRBUTTONDOWN || msg->message==WM_NCMBUTTONDOWN ||
397                msg->message==WM_NCLBUTTONDBLCLK || msg->message==WM_NCRBUTTONDBLCLK || msg->message==WM_NCMBUTTONDBLCLK) {
398               
399               
400                pos += swprintf_s(msgBuffer+pos,bufsize-pos,L"<param name=\"point.x\" value=\"%i\"/>", pointx);
401                pos += swprintf_s(msgBuffer+pos,bufsize-pos,L"<param name=\"point.y\" value=\"%i\"/>", pointy);
402
403                if(msg->message == WM_LBUTTONUP)
404                {
405                        //check the listBox selection, store it in "scrollPos"
406                        //no selection = -1
407                        //this is only working for listBoxes with style 'selection = single'
408                        retVal = GetClassName(msg->hwnd, buffer, 128);
409                        if( retVal >= -1  && retVal < MAXINT && !lstrcmpi(buffer, L"ListBox") )
410                        {
411                                scrollPos = (int)SendMessage(msg->hwnd, LB_GETCURSEL, 0, 0);
412                                pos += swprintf_s(msgBuffer+pos,bufsize-pos,L"<param name=\"scrollPos\" value=\"%i\"/>", scrollPos);
413                        }
414
415
416                        retVal = GetClassName(msg->hwnd, buffer, 128);
417                        if( retVal >= -1  && retVal < MAXINT && (!lstrcmpi(buffer, L"ComboLBox")||!lstrcmpi(buffer, L"ComboBox")) )
418                        {
419                                scrollPos = (int)SendMessage(msg->hwnd, CB_GETCURSEL, 0, 0);
420                                pos += swprintf_s(msgBuffer+pos,bufsize-pos,L"<param name=\"scrollPos\" value=\"%i\"/>", scrollPos);
421                        }
422
423                        //check the TabControl selection, store it in "scrollPos"
424                        //no selection = -1
425                        retVal = GetClassName(msg->hwnd, buffer, 128);
426                        if( retVal >= -1  && retVal < MAXINT && !lstrcmpi(buffer, L"SysTabControl32") )
427                        {
428                                scrollPos = (int)SendMessage(msg->hwnd, (UINT)4875, 0, 0);
429                                pos += swprintf_s(msgBuffer+pos,bufsize-pos,L"<param name=\"scrollPos\" value=\"%i\"/>", scrollPos);
430                        }
431                }
432        }
433        if( msg->message==WM_MOUSEACTIVATE ) {
434                pos += swprintf_s(msgBuffer+pos,bufsize-pos,L"<param name=\"toplevelwindow.hwnd\" value=\"%i\"/>", (HWND) msg->wParam);
435        }
436        if( msg->message==WM_KEYUP || msg->message==WM_KEYDOWN || msg->message==WM_SYSKEYUP || msg->message==WM_SYSKEYDOWN ) {
437                pos += swprintf_s(msgBuffer+pos,bufsize-pos,L"<param name=\"key\" value=\"%i\"/>", LOWORD(msg->wParam));
438        }
439        if( msg->message==WM_SETTEXT ) {
440                if( newWindowText!=NULL ) {
441                        pos += swprintf_s(msgBuffer+pos,bufsize-pos,L"<param name=\"window.newText\" value=\"%s\"/>", newWindowText);
442                }
443        }
444       
445        if( msg->message==WM_NCLBUTTONDOWN && htMenu ) {
446                pos += swprintf_s(msgBuffer+pos, bufsize-pos,L"<param name=\"isMenu\" value=\"true\"/>");
447        }
448
449        if( msg->message==WM_INITMENU ) {
450                pos += swprintf_s(msgBuffer+pos,bufsize-pos,L"<param name=\"menu.hwnd\" value=\"%i\"/>", menuHandle);
451        }
452
453        if( msg->message==WM_CREATE ) {
454                // print window information
455                if( windowName!=NULL ) {
456                        pos += swprintf_s(msgBuffer+pos,bufsize-pos,L"<param name=\"window.name\" value=\"%s\"/>", windowName);
457                }
458                if( windowResourceId>0 ) {
459                        pos += swprintf_s(msgBuffer+pos,bufsize-pos,L"<param name=\"window.resourceId\" value=\"%i\"/>", windowResourceId);
460                }
461                if( msg->message==WM_CREATE ) {
462                        if( parentHandle!=NULL ) {
463                                pos += swprintf_s(msgBuffer+pos,bufsize-pos,L"<param name=\"window.parent.hwnd\" value=\"%i\"/>", parentHandle);
464                        }
465                        if( windowClass!=NULL ) {
466                                pos += swprintf_s(msgBuffer+pos,bufsize-pos,L"<param name=\"window.class\" value=\"%s\"/>", windowClass);
467                        }
468                        if( isModal ) {
469                                pos += swprintf_s(msgBuffer+pos,bufsize-pos,L"<param name=\"window.ismodal\" value=\"true\"/>");
470                        }
471
472                }
473        }
474        if( msg->message==WM_HSCROLL || msg->message==WM_VSCROLL ) {
475                pos += swprintf_s(msgBuffer+pos,bufsize-pos,L"<param name=\"scrollType\" value=\"%i\"/>", scrollType);
476                pos += swprintf_s(msgBuffer+pos,bufsize-pos,L"<param name=\"scrollPos\" value=\"%i\"/>", scrollPos);
477                pos += swprintf_s(msgBuffer+pos,bufsize-pos,L"<param name=\"scrollBarHandle\" value=\"%i\"/>", scrollBarHandle);
478        }
479
480        if( msg->time!=-1 ) {
481                pos += swprintf_s(msgBuffer+pos,bufsize-pos,L"<param name=\"time\" value=\"%i\"/>", msg->time);
482        }
483       
484        /***************************************/
485        // put debugging and experimental output stuff here
486        /***************************************/
487
488#ifdef __INCLUDEHOOKINFO__
489        pos += swprintf_s(msgBuffer+pos,bufsize-pos,L"<param name=\"hook\" value=\"%i\"/>", nFrom);
490#endif
491       
492
493        pos += swprintf_s(msgBuffer+pos,bufsize-pos,L"</msg>", msg->hwnd);
494#ifdef __USING_MTRACE__
495#ifdef __ENCODE_BASE64__
496        size_t arraySize = (pos+1)*2;
497        size_t encodingSize = arraySize*2;
498        char * base64Buffer = new char[encodingSize];
499
500        base64::encoder enc;
501        retVal = enc.encode((char*)msgBuffer, arraySize, base64Buffer);
502        base64Buffer[retVal] = '\0';
503
504        char * mtraceBuffer = new char[retVal+30];
505        sprintf_s(mtraceBuffer,retVal+29,"%s%s", LOGPREFIX, base64Buffer);
506        delete base64Buffer;
507#else
508        char * mtraceBuffer = new char[pos+1];
509        size_t numConverted;
510        wcstombs_s(&numConverted,mtraceBuffer, pos+1, msgBuffer, pos);
511#endif // __ENCODE_BASE64__
512        MTrace_AddToLevel(traceLevel,mtraceBuffer);
513        delete mtraceBuffer;
514#endif // __USING_MTRACE__
515#ifdef __USING_COSTUMLOG__
516        SYSTEMTIME currentTime;
517        GetSystemTime(&currentTime);
518        logfile << currentTime.wDay << "." << currentTime.wMonth << "." << currentTime.wYear << " ";
519        logfile << currentTime.wHour << ":" << currentTime.wMinute << ":" << currentTime.wSecond << ":";
520        logfile << currentTime.wMilliseconds << "\t";
521        logfile << LOGPREFIX << msgBuffer << std::endl;
522#endif
523        delete messageStr;
524        delete newWindowText;
525        delete windowName;
526        delete windowClass;
527        delete msgBuffer;
528}
Note: See TracBrowser for help on using the repository browser.