windows-trace-log-to-dbgview-20050820
[openafs.git] / src / WINNT / client_osi / osilog.c
1 /* 
2  * Copyright 2000, International Business Machines Corporation and others.
3  * All Rights Reserved.
4  * 
5  * This software has been released under the terms of the IBM Public
6  * License.  For details, see the LICENSE file in the top-level source
7  * directory or online at http://www.openafs.org/dl/license10.html
8  */
9
10 /* Copyright (C) 1994 Cazamar Systems, Inc. */
11
12 #include <afs/param.h>
13 #include <afs/stds.h>
14
15 #ifndef DJGPP
16 #include <windows.h>
17 #include <rpc.h>
18 #endif /* !DJGPP */
19 #include <malloc.h>
20 #include "osi.h"
21 #ifndef DJGPP
22 #include "dbrpc.h"
23 #endif /* !DJGPP */
24 #include <stdio.h>
25 #include <assert.h>
26 #include <WINNT\afsreg.h>
27
28 #define AFS_DAEMON_EVENT_NAME "TransarcAFSDaemon"
29
30 /* the size; overrideable */
31 long osi_logSize = OSI_LOG_DEFAULTSIZE;
32
33 static osi_once_t osi_logOnce;
34
35 osi_log_t *osi_allLogsp;        /* all logs known; for use during panic */
36
37 unsigned long osi_logFreq;      /* 0, or frequency of high perf counter */
38 unsigned long osi_logTixToMicros;       /* mult. correction factor */
39
40 #define TRACE_OPTION_EVENT 2
41 #define TRACE_OPTION_DEBUGLOG 4
42
43 #define ISCLIENTTRACE(v) ( ((v) & TRACE_OPTION_EVENT)==TRACE_OPTION_EVENT)
44 #define ISCLIENTDEBUGLOG(v) (((v) & TRACE_OPTION_DEBUGLOG)==TRACE_OPTION_DEBUGLOG)
45
46 DWORD osi_TraceOption=0;
47
48 osi_fdOps_t osi_logFDOps = {
49         osi_LogFDCreate,
50 #ifndef DJGPP
51         osi_LogFDGetInfo,
52 #endif
53         osi_LogFDClose
54 };
55
56 /* create a new log, taking a name and a size in entries (not words) */
57 osi_log_t *osi_LogCreate(char *namep, long size)
58 {
59         osi_log_t *logp;
60         osi_fdType_t *typep;
61         char tbuffer[256];
62         LARGE_INTEGER bigFreq;
63         LARGE_INTEGER bigTemp;
64         LARGE_INTEGER bigJunk;
65         
66 #ifndef DJGPP
67         if (osi_Once(&osi_logOnce)) {
68                 QueryPerformanceFrequency(&bigFreq);
69                 if (bigFreq.LowPart == 0 && bigFreq.HighPart == 0)
70                         osi_logFreq = 0;
71                 else {
72                         /* turn frequency into ticks per 10 micros */
73                         bigTemp.LowPart = 100000;
74                         bigTemp.HighPart = 0;
75                         osi_logTixToMicros = 10;
76                         bigFreq = LargeIntegerDivide(bigFreq, bigTemp, &bigJunk);
77
78                         /* check if resolution is too fine or to gross for this to work */
79                         if (bigFreq.HighPart > 0 || bigFreq.LowPart < 8)
80                                 osi_logFreq = 0;        /* too big to represent as long */
81                         else
82                                 osi_logFreq = bigFreq.LowPart;
83                 }
84
85                 /* done with init */
86                 osi_EndOnce(&osi_logOnce);
87         }
88 #endif /* !DJGPP */
89
90         logp = malloc(sizeof(osi_log_t));
91         memset(logp, 0, sizeof(osi_log_t));
92         logp->namep = malloc(strlen(namep)+1);
93         strcpy(logp->namep, namep);
94         
95         osi_QAdd((osi_queue_t **) &osi_allLogsp, &logp->q);
96
97         /* compute size we'll use */
98         if (size == 0) size = osi_logSize;
99
100         /* handle init for this size */
101         logp->alloc = size;
102         logp->datap = malloc(size * sizeof(osi_logEntry_t));
103
104         /* init strings array */
105         logp->maxstringindex = size/3;
106         logp->stringindex = 0;
107         logp->stringsp = malloc(logp->maxstringindex * OSI_LOG_STRINGSIZE);
108  
109         /* and sync */
110         thrd_InitCrit(&logp->cs);
111         
112         strcpy(tbuffer, "log:");
113         strcat(tbuffer, namep);
114         typep = osi_RegisterFDType(tbuffer, &osi_logFDOps, logp);
115 #ifndef DJGPP
116         if (typep) {
117                 /* add formatting info */
118                 osi_AddFDFormatInfo(typep, OSI_DBRPC_REGIONINT, 0,
119                         "Thread ID", OSI_DBRPC_HEX);
120                 osi_AddFDFormatInfo(typep, OSI_DBRPC_REGIONSTRING, 1,
121                         "Time (mics)", 0);
122         }
123 #endif
124         
125         return logp;
126 }
127
128 /* we just panic'd.  Turn off all logging adding special log record
129  * to all enabled logs.  Be careful not to wait for a lock.
130  */
131 void osi_LogPanic(char *filep, long lineNumber)
132 {
133         osi_log_t *tlp;
134
135         for(tlp = osi_allLogsp; tlp; tlp = (osi_log_t *) osi_QNext(&tlp->q)) {
136                 if (!tlp->enabled) continue;
137
138                 /* otherwise, proceed */
139                 if (filep)
140                         osi_LogAdd(tlp, "**PANIC** (file %s:%d)", (long) filep, lineNumber, 0, 0);
141                 else
142                         osi_LogAdd(tlp, "**PANIC**", 0, 0, 0, 0);
143                 
144                 /* should grab lock for this, but we're in panic, and better safe than
145                  * sorry.
146                  */
147                 tlp->enabled = 0;
148         }
149 }
150
151 /* reset the contents of a log */
152 void osi_LogReset(osi_log_t *logp)
153 {
154         if (logp) {
155                 thrd_EnterCrit(&logp->cs);
156                 logp->nused = 0;
157                 thrd_LeaveCrit(&logp->cs);
158         }
159 }
160
161 /* free a log */
162 void osi_LogFree(osi_log_t *logp)
163 {
164         if (!logp) return;
165
166         osi_QRemove((osi_queue_t **) &osi_allLogsp, &logp->q);
167
168         free(logp->namep);
169         free(logp->datap);
170         thrd_DeleteCrit(&logp->cs);
171         free(logp);
172 }
173
174 /* add an element to a log */
175 void osi_LogAdd(osi_log_t *logp, char *formatp, long p0, long p1, long p2, long p3)
176 {
177         osi_logEntry_t *lep;
178         long ix;
179         LARGE_INTEGER bigTime;
180
181         /* handle init races */
182         if (!logp) return;
183
184         /* do this w/o locking for speed; it is obviously harmless if we're off
185          * by a bit.
186          */
187         if (!logp->enabled) return;
188         
189         thrd_EnterCrit(&logp->cs);
190         if (logp->nused < logp->alloc) logp->nused++;
191         else {
192                 logp->first++;
193                 if (logp->first >= logp->alloc) logp->first -= logp->alloc;
194         }
195         ix = logp->first + logp->nused - 1;
196         if (ix >= logp->alloc) ix -= logp->alloc;
197
198         lep = logp->datap + ix; /* ptr arith */
199         lep->tid = thrd_Current();
200
201         /* get the time, using the high res timer if available */
202 #ifndef DJGPP
203         if (osi_logFreq) {
204                 QueryPerformanceCounter(&bigTime);
205                 lep->micros = (bigTime.LowPart / osi_logFreq) * osi_logTixToMicros;
206         }
207         else lep->micros = GetCurrentTime() * 1000;
208 #else
209         lep->micros = gettime_us();
210 #endif /* !DJGPP */                
211
212         lep->formatp = formatp;
213         lep->parms[0] = p0;
214         lep->parms[1] = p1;
215         lep->parms[2] = p2;
216         lep->parms[3] = p3;
217
218 #ifdef NOTSERVICE
219         printf( "%9ld:", lep->micros );
220         printf( formatp, p0, p1, p2, p3);
221         printf( "\n" );
222 #endif
223
224         if(ISCLIENTDEBUGLOG(osi_TraceOption)) {
225             char wholemsg[1024], msg[1000];
226
227             snprintf(msg, sizeof(msg), formatp,
228                      p0, p1, p2, p3);
229             snprintf(wholemsg, sizeof(wholemsg), 
230                      "tid[%d] %s\n",
231                      lep->tid, msg);
232             OutputDebugStringA(wholemsg);
233         }
234
235         thrd_LeaveCrit(&logp->cs);
236 }
237
238 void osi_LogPrint(osi_log_t *logp, FILE_HANDLE handle)
239 {
240         char wholemsg[1024], msg[1000];
241         int i, ix, ioCount;
242         osi_logEntry_t *lep;
243
244         if (!logp->enabled) return;
245
246         thrd_EnterCrit(&logp->cs);
247
248         for (ix = logp->first, i = 0;
249              i < logp->nused;
250              i++, ix++, (ix >= logp->alloc ? ix -= logp->alloc : 0)) {
251                 lep = logp->datap + ix;         /* pointer arithmetic */
252                 snprintf(msg, sizeof(msg), lep->formatp,
253                         lep->parms[0], lep->parms[1],
254                         lep->parms[2], lep->parms[3]);
255                 snprintf(wholemsg, sizeof(wholemsg),
256                          "time %d.%06d, tid %d %s\n",
257                         lep->micros / 1000000,
258                         lep->micros % 1000000,
259                         lep->tid, msg);
260 #ifndef DJGPP
261                 if (!WriteFile(handle, wholemsg, strlen(wholemsg),
262                                 &ioCount, NULL))
263 #else /* DJGPP */
264                 if ((ioCount = fwrite(wholemsg, 1, strlen(wholemsg), handle)) == 0)
265 #endif /* !DJGPP */
266                         break;
267         }
268
269         thrd_LeaveCrit(&logp->cs);
270 }
271
272 char *osi_LogSaveString(osi_log_t *logp, char *s)
273 {
274         char *saveplace;
275
276         if (s == NULL) return NULL;
277
278         thrd_EnterCrit(&logp->cs);
279
280         saveplace = logp->stringsp[logp->stringindex];
281
282         if (strlen(s) >= OSI_LOG_STRINGSIZE)
283                 sprintf(saveplace, "...%s",
284                         s + strlen(s) - (OSI_LOG_STRINGSIZE - 4));
285         else
286                 strcpy(saveplace, s);
287         logp->stringindex++;
288
289         if (logp->stringindex >= logp->maxstringindex)
290             logp->stringindex = 0;
291
292         thrd_LeaveCrit(&logp->cs);
293
294         return saveplace;
295 }
296
297 long osi_LogFDCreate(osi_fdType_t *typep, osi_fd_t **outpp)
298 {
299         osi_logFD_t *lfdp;
300         osi_log_t *logp;
301         
302         lfdp = malloc(sizeof(*lfdp));
303         logp = lfdp->logp = typep->rockp;       /* the log we were created for */
304         thrd_EnterCrit(&logp->cs);
305         lfdp->nused = logp->nused;
306         lfdp->first = logp->first;
307         lfdp->current = 0;
308         thrd_LeaveCrit(&logp->cs);
309
310         *outpp = &lfdp->fd;
311         return 0;
312 }
313
314 #ifndef DJGPP
315 long osi_LogFDGetInfo(osi_fd_t *ifd, osi_remGetInfoParms_t *outp)
316 {
317         osi_logFD_t *lfdp;
318         osi_log_t *logp;
319         osi_logEntry_t *lep;
320         char tbuffer[256];
321         long ix;
322         
323         lfdp = (osi_logFD_t *) ifd;
324         logp = lfdp->logp;
325         
326         /* see if we're done */
327         if (lfdp->current >= lfdp->nused) return OSI_DBRPC_EOF;
328         
329         /* grab lock */
330         thrd_EnterCrit(&logp->cs);
331
332         /* compute which one we want */
333         ix = lfdp->first + lfdp->current;
334         if (ix >= logp->alloc) ix -= logp->alloc;
335         lfdp->current++;
336         lep = logp->datap + ix; /* ptr arith to current index */
337
338         sprintf(tbuffer, lep->formatp, lep->parms[0], lep->parms[1],
339                 lep->parms[2], lep->parms[3]);
340
341         /* now copy out info */
342         strcpy(outp->sdata[0], tbuffer);
343         sprintf(tbuffer, "%5.6f", ((double)lep->micros)/1000000.0);
344         strcpy(outp->sdata[1], tbuffer);
345         outp->idata[0] = lep->tid;
346         outp->scount = 2;
347         outp->icount = 1;
348
349         thrd_LeaveCrit(&logp->cs);
350         return 0;
351 }
352 #endif /* !DJGPP */
353
354 long osi_LogFDClose(osi_fd_t *ifdp)
355 {
356         free(ifdp);
357         return 0;
358 }
359
360 void osi_LogEnable(osi_log_t *logp)
361 {
362         if (logp)
363                 logp->enabled = 1;
364 }
365
366 void osi_LogDisable(osi_log_t *logp)
367 {
368         if (logp)
369                 logp->enabled = 0;
370 }
371
372 void osi_InitTraceOption()
373 {
374         DWORD LSPtype, LSPsize;
375         HKEY NPKey;
376         (void) RegOpenKeyEx(HKEY_LOCAL_MACHINE, AFSREG_CLT_SVC_PARAM_SUBKEY,
377                     0, KEY_QUERY_VALUE, &NPKey);
378         LSPsize=sizeof(osi_TraceOption);
379         RegQueryValueEx(NPKey, "TraceOption", NULL,
380                                 &LSPtype, (LPBYTE)&osi_TraceOption, &LSPsize);
381 }
382
383
384 #define MAXBUF_ 131
385 void osi_LogEvent0(char *a,char *b) 
386 {
387         HANDLE h; 
388     char *ptbuf[1];
389         if (!ISCLIENTTRACE(osi_TraceOption))
390                 return;
391         h = RegisterEventSource(NULL, AFS_DAEMON_EVENT_NAME);
392         ptbuf[0] = b;
393         ReportEvent(h, EVENTLOG_INFORMATION_TYPE, 0, 0, NULL, 1, 0, (const char **)ptbuf, NULL);
394         DeregisterEventSource(h);
395 }
396
397
398 void osi_LogEvent(char *a,char *b,char *c,...) 
399 {
400         HANDLE h; char *ptbuf[1],buf[MAXBUF_+1];
401         va_list marker;
402         if (!ISCLIENTTRACE(osi_TraceOption))
403                 return;
404     h = RegisterEventSource(NULL, AFS_DAEMON_EVENT_NAME);
405         va_start(marker,c);
406         _vsnprintf(buf,MAXBUF_,c,marker);
407         ptbuf[0] = buf;
408         ReportEvent(h, EVENTLOG_INFORMATION_TYPE, 0, 0, NULL, 1, 0, (const char **)ptbuf, NULL);\
409         DeregisterEventSource(h);
410         va_end(marker);
411 }
412
413 char *osi_HexifyString(char *s) {
414         int len,c;
415         char *hex = "0123456789abcdef";
416         char *buf, *counter, *bufp;
417
418         len = strlen(s);
419         
420         bufp = buf = malloc( len * 3 ); /* [xx.xx.xx.xx\0] */
421
422         if(!buf) return NULL;
423
424         for(counter = s; *counter; counter ++) {
425                 if(counter != s) *bufp++ = '.';
426                 c = *counter;
427                 *bufp++ = hex[(c>>4) & 0xf];
428                 *bufp++ = hex[c & 0xf];
429         }
430         *bufp = 0;
431
432         return buf;
433 }
434