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