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

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