src/WINNT/afsd/afsd_eventlog.c

   1 ////////////////////////////////////////////////////////////////////
   2 //
   3 //
   4 //              E V E N T   L O G G I N G   F U N C T I O N S
   5 //
   6 //
   7 ////////////////////////////////////////////////////////////////////
   8
   9
  10 #include <windows.h>
  11 #include <stdarg.h>
  12 #include <string.h>
  13 #include <strsafe.h>
  14 #include <WINNT/afsreg.h>
  15 #include "afsd.h"
  16 #include "afsd_eventlog.h"
  17
  18 static BOOL     GetServicePath(LPTSTR lpPathBuf, PDWORD pdwPathBufSize);
  19 static BOOL     AddEventSource(void);
  20
  21 static BOOL
  22 GetServicePath(LPTSTR lpPathBuf, PDWORD pdwPathBufSize)
  23 {
  24     HKEY        hKey = NULL;
  25     DWORD       dwData = 0;
  26     BOOL        bRet = TRUE;
  27
  28     do {
  29         // Open key
  30         if ( RegOpenKeyEx( HKEY_LOCAL_MACHINE, AFSREG_CLT_SVC_SUBKEY, 0, KEY_QUERY_VALUE, &hKey ) )
  31         {
  32             bRet = FALSE;
  33             break;
  34         }
  35
  36         // prepare user's buffer and read into it
  37         dwData = *pdwPathBufSize;
  38         memset(lpPathBuf, '\0', dwData);
  39         if ( RegQueryValueEx( hKey,                     // handle to key
  40                               "ImagePath",              // value name
  41                               NULL,                     // reserved
  42                               NULL,                     // type buffer
  43                               (LPBYTE) lpPathBuf,       // data buffer
  44                               &dwData))         // size of data buffer
  45         {
  46             bRet = FALSE;
  47             break;
  48         }
  49
  50         *pdwPathBufSize = dwData;
  51
  52     } while (0);
  53
  54     if (hKey != NULL)
  55         RegCloseKey(hKey);
  56
  57     return bRet;
  58 }
  59
  60 //
  61 // Ensure name for message file is in proper location in Registry.
  62 //
  63 static BOOL
  64 AddEventSource()
  65 {
  66     HKEY        hKey = NULL, hLogKey;
  67     UCHAR       szBuf[MAX_PATH] = "afsd_service.exe";
  68     DWORD       dwData, dwDisposition;
  69     static BOOL bRet = TRUE;
  70     static BOOL bOnce = TRUE;
  71
  72     if (!bOnce)
  73         return bRet;
  74
  75     if ( RegOpenKeyEx( HKEY_LOCAL_MACHINE, AFSREG_APPLOG_SUBKEY, 0,
  76                        KEY_SET_VALUE, &hLogKey ) )
  77     {
  78         // nope - create it
  79         if ( RegCreateKeyEx(HKEY_LOCAL_MACHINE, AFSREG_APPLOG_SUBKEY, 0,
  80                              NULL, REG_OPTION_NON_VOLATILE,
  81                              KEY_ALL_ACCESS, NULL, &hLogKey,
  82                              &dwDisposition))
  83         {
  84             bRet = FALSE;
  85             goto done;
  86         }
  87     }
  88
  89     // Let's see if key already exists as a subkey under the
  90     // Application key in the EventLog registry key.  If not,
  91     // create it.
  92     if ( RegOpenKeyEx( hLogKey, AFSREG_CLT_APPLOG_SUBKEY, 0,
  93                        KEY_SET_VALUE, &hKey ) )
  94     {
  95         // nope - create it
  96         if ( RegCreateKeyEx(hLogKey, AFSREG_CLT_APPLOG_SUBKEY, 0,
  97                              NULL, REG_OPTION_NON_VOLATILE,
  98                              KEY_ALL_ACCESS, NULL, &hKey,
  99                              &dwDisposition))
 100         {
 101             bRet = FALSE;
 102             goto done;
 103         }
 104     }
 105
 106     // Add the name to the EventMessageFile subkey.
 107     if ( RegSetValueEx( hKey,                   // subkey handle
 108                         AFSREG_APPLOG_MSGFILE_VALUE,    // value name
 109                         0,                      // must be zero
 110                         REG_SZ,                 // value type
 111                         (LPBYTE) szBuf,         // pointer to value data
 112                         (DWORD)strlen(szBuf) + 1))      // length of value data
 113     {
 114         bRet = FALSE;
 115         goto done;
 116     }
 117
 118     // Set the supported event types in the TypesSupported subkey.
 119     dwData = EVENTLOG_ERROR_TYPE | EVENTLOG_WARNING_TYPE |
 120         EVENTLOG_INFORMATION_TYPE;
 121
 122     if ( RegSetValueEx( hKey,                   // subkey handle
 123                         AFSREG_APPLOG_MSGTYPE_VALUE,    // value name
 124                         0,                      // must be zero
 125                         REG_DWORD,              // value type
 126                         (LPBYTE) &dwData,       // pointer to value data
 127                         sizeof(DWORD)))         // length of value data
 128     {
 129         bRet = FALSE;
 130         goto done;
 131     }
 132
 133   done:
 134     if (hKey != NULL)
 135         RegCloseKey(hKey);
 136
 137     if (hLogKey != NULL)
 138         RegCloseKey(hLogKey);
 139
 140     return bRet;
 141 }
 142
 143 // Log an event with a formatted system message as the (only) substitution
 144 // string, from the given message ID.
 145 VOID
 146 LogEventMessage(WORD wEventType, DWORD dwEventID, DWORD dwMessageID)
 147 {
 148     LPTSTR msgBuf;
 149
 150     FormatMessage(FORMAT_MESSAGE_FROM_SYSTEM | FORMAT_MESSAGE_ALLOCATE_BUFFER,
 151                    NULL, dwMessageID, 0, (LPTSTR)&msgBuf, 0, NULL);
 152     LogEvent(wEventType, dwEventID, msgBuf, NULL);
 153     LocalFree(msgBuf);
 154 }
 155
 156 //
 157 // Use the ReportEvent API to write an entry to the system event log.
 158 //
 159 #define MAXARGS 8
 160 #define STRLEN  128
 161
 162 VOID
 163 LogEvent(WORD wEventType, DWORD dwEventID, ...)
 164 {
 165     va_list     listArgs;
 166     HANDLE      hEventSource;
 167     HANDLE      hMutex = NULL;
 168     LPTSTR      lpArgs[MAXARGS];
 169     CHAR        lpStrings[MAXARGS][STRLEN];
 170     static CHAR lpLastStrings[MAXARGS][STRLEN];
 171     WORD        wNumArgs = 0;
 172     static WORD wLastNumArgs = MAXARGS;
 173     static time_t lastMessageTime = 0;
 174     static WORD wLastEventType = 0;
 175     static DWORD dwLastEventID = 0;
 176     time_t      now;
 177     DWORD       code;
 178     BOOL        bLogMessage = TRUE;
 179     WORD        i = 0, j;
 180
 181     // Ensure that our event source is properly initialized.
 182     if (!AddEventSource())
 183         return;
 184
 185     // Get a handle to the event log.
 186     hEventSource = RegisterEventSource(NULL, AFS_DAEMON_EVENT_NAME);
 187     if (hEventSource == NULL)
 188         return;
 189
 190     // Construct the array of substitution strings.
 191     va_start(listArgs, dwEventID);
 192
 193     switch ( dwEventID ) {
 194     case MSG_FLUSH_NO_SHARE_NAME:
 195     case MSG_FLUSH_NO_MEMORY:
 196     case MSG_FLUSH_IMPERSONATE_ERROR:
 197     case MSG_FLUSH_UNEXPECTED_EVENT:
 198     case MSG_UNHANDLED_EXCEPTION:
 199     case MSG_SMB_ZERO_TRANSACTION_COUNT:
 200     case MSG_SERVICE_START_PENDING:
 201     case MSG_SERVICE_INCORRECT_VERSIONS:
 202     case MSG_SERVICE_RUNNING:
 203     case MSG_SERVICE_STOPPING:
 204     case MSG_SERVICE_ERROR_STOP:
 205     case MSG_CRYPT_OFF:
 206     case MSG_CRYPT_ON:
 207         break;
 208     case MSG_FLUSH_BAD_SHARE_NAME:
 209     case MSG_FLUSH_OPEN_ENUM_ERROR:
 210     case MSG_FLUSH_ENUM_ERROR:
 211     case MSG_FLUSH_FAILED:
 212     case MSG_RX_HARD_DEAD_TIME_EXCEEDED:
 213     case MSG_SERVICE_ERROR_STOP_WITH_MSG:
 214     case MSG_SMB_SEND_PACKET_FAILURE:
 215     case MSG_UNEXPECTED_SMB_SESSION_CLOSE:
 216     case MSG_RX_MSGSIZE_EXCEEDED:
 217         wNumArgs = 1;
 218         lpArgs[0] = va_arg(listArgs, LPTSTR);
 219         break;
 220     case MSG_TIME_FLUSH_PER_VOLUME:
 221     case MSG_TIME_FLUSH_TOTAL:
 222     case MSG_SMB_MAX_MPX_COUNT:
 223     case MSG_SMB_MAX_BUFFER_SIZE:
 224         wNumArgs = 2;
 225         lpArgs[0] = va_arg(listArgs, LPTSTR);
 226         lpArgs[1] = va_arg(listArgs, LPTSTR);
 227         break;
 228     case MSG_SERVER_REPORTS_VNOVOL:
 229     case MSG_SERVER_REPORTS_VMOVED:
 230     case MSG_SERVER_REPORTS_VOFFLINE:
 231     case MSG_SERVER_REPORTS_VSALVAGE:
 232     case MSG_SERVER_REPORTS_VNOSERVICE:
 233     case MSG_SERVER_REPORTS_VIO:
 234     case MSG_SERVER_REPORTS_VBUSY:
 235     case MSG_SERVER_REPORTS_VRESTARTING:
 236         wNumArgs = 3;
 237         lpArgs[0] = va_arg(listArgs, LPTSTR);
 238         StringCbPrintf(lpStrings[1],STRLEN,"%d",va_arg(listArgs,afs_int32));
 239         lpArgs[1] = lpStrings[1];
 240         lpArgs[2] = va_arg(listArgs, LPTSTR);
 241         break;
 242     case MSG_ALL_SERVERS_BUSY:
 243     case MSG_ALL_SERVERS_OFFLINE:
 244     case MSG_ALL_SERVERS_DOWN:
 245         wNumArgs = 2;
 246         lpArgs[0] = va_arg(listArgs, LPTSTR);
 247         StringCbPrintf(lpStrings[1],STRLEN,"%d",va_arg(listArgs,afs_int32));
 248         lpArgs[1] = lpStrings[1];
 249         break;
 250     case MSG_BAD_SMB_PARAM:
 251         wNumArgs = 5;
 252         lpArgs[0] = va_arg(listArgs, LPTSTR);
 253         StringCbPrintf(lpStrings[1],STRLEN,"%d",va_arg(listArgs,int));
 254         StringCbPrintf(lpStrings[2],STRLEN,"%d",va_arg(listArgs,int));
 255         StringCbPrintf(lpStrings[3],STRLEN,"%d",va_arg(listArgs,int));
 256         StringCbPrintf(lpStrings[4],STRLEN,"%d",va_arg(listArgs,WORD));
 257         lpArgs[1] = lpStrings[1];
 258         lpArgs[2] = lpStrings[2];
 259         lpArgs[3] = lpStrings[3];
 260         lpArgs[4] = lpStrings[4];
 261         break;
 262     case MSG_BAD_SMB_PARAM_WITH_OFFSET:
 263         wNumArgs = 6;
 264         lpArgs[0] = va_arg(listArgs, LPTSTR);
 265         StringCbPrintf(lpStrings[1],STRLEN,"%d",va_arg(listArgs,int));
 266         StringCbPrintf(lpStrings[2],STRLEN,"%d",va_arg(listArgs,int));
 267         StringCbPrintf(lpStrings[3],STRLEN,"%d",va_arg(listArgs,int));
 268         StringCbPrintf(lpStrings[4],STRLEN,"%d",va_arg(listArgs,int));
 269         StringCbPrintf(lpStrings[5],STRLEN,"%d",va_arg(listArgs,WORD));
 270         lpArgs[1] = lpStrings[1];
 271         lpArgs[2] = lpStrings[2];
 272         lpArgs[3] = lpStrings[3];
 273         lpArgs[4] = lpStrings[4];
 274         lpArgs[5] = lpStrings[5];
 275         break;
 276     case MSG_BAD_SMB_TOO_SHORT:
 277     case MSG_BAD_SMB_INVALID:
 278     case MSG_BAD_SMB_INCOMPLETE:
 279         wNumArgs = 1;
 280         StringCbPrintf(lpStrings[0],STRLEN,"%d",va_arg(listArgs,WORD));
 281         lpArgs[0] = lpStrings[0];
 282         break;
 283     case MSG_SMB_SESSION_START:
 284         wNumArgs = 1;
 285         StringCbPrintf(lpStrings[0],STRLEN,"%d",va_arg(listArgs,long));
 286         lpArgs[0] = lpStrings[0];
 287         break;
 288     case MSG_BAD_SMB_WRONG_SESSION:
 289         wNumArgs = 2;
 290         StringCbPrintf(lpStrings[0],STRLEN,"%d",va_arg(listArgs,DWORD));
 291         StringCbPrintf(lpStrings[1],STRLEN,"%d",va_arg(listArgs,WORD));
 292         lpArgs[0] = lpStrings[0];
 293         lpArgs[1] = lpStrings[1];
 294         break;
 295     case MSG_BAD_VCP:
 296         wNumArgs = 4;
 297         StringCbPrintf(lpStrings[0],STRLEN,"%d",va_arg(listArgs,UCHAR));
 298         StringCbPrintf(lpStrings[1],STRLEN,"%d",va_arg(listArgs,UCHAR));
 299         StringCbPrintf(lpStrings[2],STRLEN,"%d",va_arg(listArgs,UCHAR));
 300         StringCbPrintf(lpStrings[3],STRLEN,"%d",va_arg(listArgs,UCHAR));
 301         lpArgs[0] = lpStrings[0];
 302         lpArgs[1] = lpStrings[1];
 303         lpArgs[2] = lpStrings[2];
 304         lpArgs[3] = lpStrings[3];
 305         break;
 306     case MSG_SERVICE_ERROR_STOP_WITH_MSG_AND_LOCATION:
 307         wNumArgs = 3;
 308         lpArgs[0] = va_arg(listArgs, LPTSTR);
 309         StringCbPrintf(lpStrings[1],STRLEN,"%d",va_arg(listArgs,int));
 310         lpArgs[1] = lpStrings[1];
 311         lpArgs[2] = va_arg(listArgs,LPTSTR);
 312         break;
 313     case MSG_DIRTY_BUFFER_AT_SHUTDOWN:
 314         wNumArgs = 6;
 315         lpArgs[0] = va_arg(listArgs, LPTSTR);
 316         lpArgs[1] = va_arg(listArgs, LPTSTR);
 317         StringCbPrintf(lpStrings[2],STRLEN,"%u",va_arg(listArgs,int));
 318         StringCbPrintf(lpStrings[3],STRLEN,"%u",va_arg(listArgs,int));
 319         StringCbPrintf(lpStrings[4],STRLEN,"%I64u",va_arg(listArgs,afs_int64));
 320         StringCbPrintf(lpStrings[5],STRLEN,"%I64u",va_arg(listArgs,afs_int64));
 321         lpArgs[2] = lpStrings[2];
 322         lpArgs[3] = lpStrings[3];
 323         lpArgs[4] = lpStrings[4];
 324         lpArgs[5] = lpStrings[5];
 325         break;
 326     }
 327     va_end(listArgs);
 328
 329     // Make sure we were not given too many args.
 330     if (wNumArgs >= MAXARGS)
 331         goto done;
 332
 333     hMutex = CreateMutex( NULL, TRUE, "AFSD Event Log Mutex");
 334     if (hMutex == NULL)
 335         goto done;
 336
 337     if (GetLastError() == ERROR_ALREADY_EXISTS) {
 338         code = WaitForSingleObject( hMutex, 500);
 339         if (code != WAIT_OBJECT_0)
 340             goto done;
 341     }
 342
 343     /*
 344      * We rate limit consecutive duplicate messages to one every
 345      * five seconds.
 346      */
 347     now = time(NULL);
 348     if (now < lastMessageTime + 5 &&
 349         wEventType == wLastEventType &&
 350         dwEventID == dwLastEventID &&
 351         wNumArgs == wLastNumArgs) {
 352         for (i=0; i<wNumArgs; i++) {
 353             if ( strncmp(lpArgs[i], lpLastStrings[i], STRLEN))
 354                 break;
 355         }
 356         if (i == wNumArgs)
 357             bLogMessage = FALSE;
 358     }
 359
 360     if ( bLogMessage) {
 361         wLastNumArgs = wNumArgs;
 362         wLastEventType = wEventType;
 363         dwLastEventID = dwEventID;
 364         lastMessageTime = now;
 365
 366         for ( j = (i == wNumArgs ? 0 : i) ; i < wNumArgs; i++) {
 367             StringCbCopyEx( lpLastStrings[i], STRLEN, lpArgs[i], NULL, NULL, STRSAFE_NULL_ON_FAILURE);
 368         }
 369     }
 370
 371     ReleaseMutex(hMutex);
 372
 373     // Log the event.
 374     if ( bLogMessage)
 375         code = ReportEvent(hEventSource,                // handle of event source
 376                            wEventType,          // event type
 377                            0,                   // event category
 378                            dwEventID,           // event ID
 379                            NULL,                        // current user's SID
 380                            wNumArgs,            // strings in lpszArgs
 381                            0,                   // no bytes of raw data
 382                            wNumArgs ? lpArgs : NULL,// array of error strings
 383                            NULL);                       // no raw data
 384
 385   done:
 386     if (hMutex)
 387         CloseHandle(hMutex);
 388
 389     DeregisterEventSource(hEventSource);
 390 }
 391
 392