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