//+--------------------------------------------------------------------------- // // Microsoft Windows // Copyright (C) Microsoft Corporation, 1992 - 1996. // // File: log.cxx // // Contents: Logging routines for the job scheduler service. // // Classes: None. // // Functions: OpenLogFile // CloseLogFile // LogTaskStatus // LogTaskError // LogServiceStatus // LogServiceError // ConstructStatusField // ConstructResultField // GetSchedulerResultCodeString // OverwriteRecordFragment // IntegerToString // // History: 1-Feb-96 MarkBl Created. // 24-Oct-96 AnirudhS Modified to handle DBCS. // 2-Feb-98 jschwart Modified to handle Unicode. // 26-Feb-01 JBenton Prefix bug 294880 // //---------------------------------------------------------------------------- #include "..\pch\headers.hxx" #pragma hdrstop #include "svc_core.hxx" #include "..\inc\resource.h" #define CCH_INT 11 #define ARRAY_LEN(a) (sizeof(a)/sizeof(a[0])) TCHAR * ConstructStatusField(DWORD, SYSTEMTIME *, ULONG *); TCHAR * ConstructResultField(DWORD, LPTSTR); TCHAR * GetSchedulerResultCodeString(DWORD, DWORD); TCHAR * IntegerToString(ULONG, TCHAR *); VOID OverwriteRecordFragment(VOID); VOID WriteLog(LPTSTR); BOOL GetDateTime(const SYSTEMTIME *, LPTSTR, LPTSTR); VOID LogServiceMessage(LPCTSTR, DWORD); // // Note, this buffer must be at least double the size of the ASCII string: // "[ ***** Most recent entry is above this line ***** ]\r\n\r\n" // to leave sufficient space for localization changes. // #define MOST_RECENT_ENTRY_MARKER_SIZE 128 static TCHAR gtszMostRecentEntryMarker[MOST_RECENT_ENTRY_MARKER_SIZE + 1] = TEXT(""); CRITICAL_SECTION gcsLogCritSection; HANDLE ghLog = NULL; DWORD gdwMaxLogSizeKB = NULL; DWORD gcbMostRecentEntryMarkerSize; //+--------------------------------------------------------------------------- // // Function: OpenLogFile // // Synopsis: Open the log file and position the global file pointer. // // Log file path/name can be specified in in the registry as: // HKEY_LOCAL_MACHINE\Software\Microsoft\JobScheduler\LogPath. // If this value is not specified, or we fail somehow fetching // it, default to the log file name "SCHEDLOG.TXT" (Ansi/Win9x) // or "SCHEDLGU.TXT" (Unicode/NT) in the windows root. // // The log file handle is cached as a global. // // Arguments: None. // // Returns: HRESULT status code. // // Notes: ** Important Note ** // // This function *must* be called *once* prior to log usage. // This function should be called after g_hInstance has been // initialized. // //---------------------------------------------------------------------------- HRESULT OpenLogFile(VOID) { TCHAR tszBuffer[MAX_PATH + 1] = TEXT("\0"); DWORD cbBufferSize = sizeof(tszBuffer); DWORD dwMaxLogSizeKB = MAX_LOG_SIZE_DEFAULT; DWORD dwType; HKEY hKey; HRESULT hr; #define tszLogPath TEXT("LogPath") #define tszMaxLogSizeKB TEXT("MaxLogSizeKB") #define tszMarkerSentinel TEXT("[ *****") #define MARKER_SENTINEL_LENGTH (ARRAY_LEN(tszMarkerSentinel) - 1) #define READ_BUFFER_SIZE 512 schAssert(ghLog == NULL); // // The crit sec must be initialized first, because a failure in this // function will result in the higher level functions trying to log a // message, which will try to enter the crit sec. // InitializeCriticalSection(&gcsLogCritSection); // Load the most recent entry marker string from the resource table. // Set the size of the marker to the end of the string. Otherwise, // the IsTextUnicode API (called by notepad) thinks this is Ansi. // gcbMostRecentEntryMarkerSize = LoadString(g_hInstance, IDS_MOSTRECENTLOGENTRYMARKER, gtszMostRecentEntryMarker, MOST_RECENT_ENTRY_MARKER_SIZE + 1); if (!gcbMostRecentEntryMarkerSize) { hr = HRESULT_FROM_WIN32(GetLastError()); CHECK_HRESULT(hr); return(hr); } // Convert to size in bytes // gcbMostRecentEntryMarkerSize *= sizeof(TCHAR); // Read the log path and maximum size from the registry. Note that these // are stored in the service's key. // if (!RegOpenKeyEx(HKEY_LOCAL_MACHINE, SCH_AGENT_KEY, 0, KEY_READ, &hKey)) { if (RegQueryValueEx(hKey, tszLogPath, NULL, &dwType, (UCHAR *)tszBuffer, &cbBufferSize) || (dwType != REG_SZ && dwType != REG_EXPAND_SZ)) { tszBuffer[0] = TEXT('\0'); } cbBufferSize = sizeof(dwMaxLogSizeKB); if (RegQueryValueEx(hKey, tszMaxLogSizeKB, NULL, &dwType, (UCHAR *)&dwMaxLogSizeKB, &cbBufferSize) || dwType != REG_DWORD) { dwMaxLogSizeKB = MAX_LOG_SIZE_DEFAULT; } RegCloseKey(hKey); } // Default log path on error. // if (!tszBuffer[0]) { lstrcpy(tszBuffer, TSZ_LOG_NAME_DEFAULT); } // Expand environment strings in the log path. // TCHAR tszFileName[MAX_PATH+1]; DWORD cch = ExpandEnvironmentStrings(tszBuffer, tszFileName, ARRAY_LEN(tszFileName)); if (cch == 0 || cch > ARRAY_LEN(tszFileName)) { ERR_OUT("ExpandEnvironmentStrings", cch); return E_OUTOFMEMORY; } // Create the file if it doesn't exist, open it if it does. // HANDLE hLog = CreateFile(tszFileName, GENERIC_READ | GENERIC_WRITE, FILE_SHARE_READ, NULL, OPEN_ALWAYS, FILE_ATTRIBUTE_NORMAL | FILE_FLAG_WRITE_THROUGH, NULL); if (hLog == INVALID_HANDLE_VALUE) { // We're in a fine mess, bail. // hr = HRESULT_FROM_WIN32(GetLastError()); CHECK_HRESULT(hr); schDebugOut((DEB_ERROR, "Attempted to create file \"" FMT_TSTR "\"\n", tszFileName)); return(hr); } TCHAR rgtBuffer[READ_BUFFER_SIZE / sizeof(TCHAR)]; DWORD dwRead; DWORD iMarker = 0; // Scope the marker index such that the search may // span multiple reads. #ifdef UNICODE DWORD dwLoops = 0; // Keep track of how many successful reads we've made. // Used to figure out whether to write the UNICODE // byte order mark (BOM) at the top of the file #endif // UNICODE // Seek to the most recent entry marker. Do so by searching for the first // several distinguishable characters of the marker - a sentinel. // for (;;) { // Save away current file position for later file pointer adjustment. // LARGE_INTEGER liLogPos; liLogPos.QuadPart = 0; if ((liLogPos.LowPart = SetFilePointer(hLog, 0, &liLogPos.HighPart, FILE_CURRENT)) == -1) { break; } if (!ReadFile(hLog, rgtBuffer, READ_BUFFER_SIZE, &dwRead, NULL) || !dwRead) { break; } // Convert to the number of characters (and chop off a stray byte // if it exists in the Unicode case) // dwRead /= sizeof(TCHAR); for (DWORD iBuffer = 0; iBuffer < dwRead; iBuffer++) { // If the first marker character is found, or the marker // comparison is continued from the previous read, evaluate // remaining marker string. // if (rgtBuffer[iBuffer] == TEXT('[') || iMarker) { for (; iMarker < MARKER_SENTINEL_LENGTH && dwRead - iBuffer; iMarker++, iBuffer++) { if (rgtBuffer[iBuffer] != tszMarkerSentinel[iMarker]) { break; } } // If the marker is found, stop & re-position the file // pointer for future writes. // if (iMarker == MARKER_SENTINEL_LENGTH) { // Adjust file pointer accordingly. // liLogPos.QuadPart += iBuffer * sizeof(TCHAR); liLogPos.QuadPart -= MARKER_SENTINEL_LENGTH * sizeof(TCHAR); if (SetFilePointer(hLog, liLogPos.LowPart, &liLogPos.HighPart, FILE_BEGIN) != -1) { goto MarkerFound; } else { hr = HRESULT_FROM_WIN32(GetLastError()); CHECK_HRESULT(hr); } } else if (iMarker < MARKER_SENTINEL_LENGTH && dwRead - iBuffer) { // Almost a match, but not quite - reset for continued // search. // iMarker = 0; } } } #ifdef UNICODE dwLoops++; #endif // UNICODE } #ifdef UNICODE if (!dwLoops && !dwRead) { // We just created the file and it's empty, so write the Unicode BOM // DWORD cbWritten; WCHAR wcBOM = 0xFEFF; if (!WriteFile(hLog, &wcBOM, sizeof(WCHAR), &cbWritten, NULL) || !cbWritten) { // If we can't write to the log, we've got problems // CloseHandle(hLog); hr = HRESULT_FROM_WIN32(GetLastError()); CHECK_HRESULT(hr); return hr; } } #endif // UNICODE // Marker not found. Seek to file end. // if (SetFilePointer(hLog, 0, NULL, FILE_END) == -1) { // Another fine mess, bail. // CloseHandle(hLog); hr = HRESULT_FROM_WIN32(GetLastError()); CHECK_HRESULT(hr); schAssert(!"Couldn't seek to log file end"); return(hr); } MarkerFound: gdwMaxLogSizeKB = dwMaxLogSizeKB; ghLog = hLog; return(S_OK); } //+--------------------------------------------------------------------------- // // Function: CloseLogFile // // Synopsis: Close log file and invalidate global handle. // // Arguments: None. // // Returns: None. // // Notes: ** Important Note ** // // Presumably, this function is called on process closure. // Therefore, let the OS delete the critical section, *not* this // thread. Otherwise, the critical section can be deleted out // from under other threads currently accessing the log. // //---------------------------------------------------------------------------- VOID CloseLogFile(VOID) { // // If OpenLogFile has not completed successfully, the critical section // won't have been initialized nor the global file handle set. // if (ghLog != NULL) { // Handle close gracefully in case another thread is accessing the log. // Do so by entering the log critical section, closing the log and // invalidating the global log handle (setting it to NULL). // EnterCriticalSection(&gcsLogCritSection); CloseHandle(ghLog); ghLog = NULL; LeaveCriticalSection(&gcsLogCritSection); } } //+--------------------------------------------------------------------------- // // Function: LogTaskStatus // // Purpose: Log successful task operations. // // Arguments: [ptszTaskName] - the task name. // [ptszTaskTarget] - the application/document name. // [uMsgID] - this would typically be either: // IDS_LOG_JOB_STATUS_STARTED or // IDS_LOG_JOB_STATUS_FINISHED // [dwExitCode] - if uMsgID is IDS_LOG_JOB_STATUS_FINISHED, // it is the task exit code; ignored otherwise. // //---------------------------------------------------------------------------- VOID LogTaskStatus( LPCTSTR ptszTaskName, LPTSTR ptszTaskTarget, UINT uMsgID, DWORD dwExitCode) { TCHAR tszMsgFormat[SCH_BIGBUF_LEN]; TCHAR * ptszStatusMsg = NULL; ULONG ccSize; // // Add the date & time as inserts to the format string. // TCHAR tszDate[SCH_MEDBUF_LEN]; TCHAR tszTime[SCH_MEDBUF_LEN]; if (!GetDateTime(NULL, tszDate, tszTime)) { return; } TCHAR * ptszResultField = NULL; // Load the format string resource. // if (!LoadString(g_hInstance, uMsgID, tszMsgFormat, ARRAY_LEN(tszMsgFormat))) { CHECK_HRESULT(HRESULT_FROM_WIN32(GetLastError())); return; } if (uMsgID == IDS_LOG_JOB_STATUS_FINISHED) { ptszResultField = ConstructResultField(dwExitCode, ptszTaskTarget); if (ptszResultField == NULL) { return; } } TCHAR * rgptszInserts[] = { (TCHAR *)ptszTaskName, (TCHAR *)ptszTaskTarget, tszDate, tszTime, ptszResultField }; if (!FormatMessage(FORMAT_MESSAGE_FROM_STRING | FORMAT_MESSAGE_ALLOCATE_BUFFER | FORMAT_MESSAGE_ARGUMENT_ARRAY, tszMsgFormat, 0, 0, (TCHAR *)&ptszStatusMsg, 1, (va_list *) rgptszInserts)) { CHECK_HRESULT(HRESULT_FROM_WIN32(GetLastError())); if (ptszResultField != NULL) { LocalFree(ptszResultField); } return; } WriteLog(ptszStatusMsg); LocalFree(ptszStatusMsg); if (ptszResultField != NULL) { LocalFree(ptszResultField); } } //+--------------------------------------------------------------------------- // // Function: LogTaskError // // Purpose: Log task warnings and errors. // // Arguments: [ptszTaskName] - the task name. // [ptszTaskTarget] - the application/document name. // [uSeverityMsgID] - this would typically be either: // IDS_LOG_SEVERITY_WARNING or // IDS_LOG_SEVERITY_ERROR // [uErrorClassMsgID] - this indicates the class of error, such // as "Unable to start task" or "Forced to // close" // [pst] - the time when the error occured; if NULL, // enters the current time. // [dwErrorCode] - if non-zero, then an error from the OS // that would be expanded by FormatMessage. // [uHelpHintMsgID] - if an error, then a suggestion as to a // possible remedy. // //---------------------------------------------------------------------------- VOID LogTaskError( LPCTSTR ptszTaskName, LPCTSTR ptszTaskTarget, UINT uSeverityMsgID, UINT uErrorClassMsgID, LPSYSTEMTIME pst, DWORD dwErrCode, UINT uHelpHintMsgID) { TCHAR tszEmpty[] = TEXT(""); // // Verify params: // if (ptszTaskName == NULL) { ptszTaskName = tszEmpty; } if (ptszTaskTarget == NULL) { ptszTaskTarget = tszEmpty; } TCHAR tszFormat[SCH_BUF_LEN]; // // Compose the first part of the error log entry: // "" ()