Leaked source code of windows server 2003
You can not select more than 25 topics Topics must start with a letter or number, can include dashes ('-') and can be up to 35 characters long.
 
 
 
 
 
 

1235 lines
36 KiB

/*++
Copyright (c) 1998 Microsoft Corporation
Module Name:
vs_trace.cxx
Abstract:
This module defines the global debug\trace facilities used by the
Long Term Storage service.
Previous name: bsdebug.cxx
Author:
Revision History:
Name Date Comments
ssteiner 06/03/98 Made numerious changes and removed iostream
dependencies, added a few new registry entries and
added serialization.
aoltean 06/06/99 Taken from atl30\atlbase.h in order to avoid linking ATL with BSCommon.lib
ssteiner 05/15/00 Fixed bug #116688. Added file locking to prevent multiple processes from
interferring with writing to the trace file. Added code to place a UNICODE
BOM at the beginning of the trace file.
--*/
//
// ***** Includes *****
//
#pragma warning(disable:4290)
#pragma warning(disable:4127)
#include <wtypes.h>
#pragma warning( disable: 4201 ) // C4201: nonstandard extension used : nameless struct/union
#include <winioctl.h>
#pragma warning( default: 4201 ) // C4201: nonstandard extension used : nameless struct/union
#include <winbase.h>
#include <wchar.h>
#include <string.h>
#include <iostream.h>
#include <fstream.h>
#include <stdio.h>
#include <process.h>
#include <stdlib.h>
#include <time.h>
#include <errno.h>
#include <vssmsg.h>
// Enabling asserts in ATL and VSS
#include "vs_assert.hxx"
#include <oleauto.h>
#include <stddef.h>
#pragma warning( disable: 4127 ) // warning C4127: conditional expression is constant
#include <atlconv.h>
#include <atlbase.h>
#include <ntverp.h>
#include "vs_inc.hxx"
#include "vs_idl.hxx"
////////////////////////////////////////////////////////////////////////
// Standard foo for file name aliasing. This code block must be after
// all includes of VSS header files.
//
#ifdef VSS_FILE_ALIAS
#undef VSS_FILE_ALIAS
#endif
#define VSS_FILE_ALIAS "TRCTRCC"
//
////////////////////////////////////////////////////////////////////////
//
// The following global, g_cDbgTrace must be declared BEFORE any of our
// objects including _Module, since some of our static objects have destructors
// that call trace methods. The following pragma ensures that this
// module's static objects are initialized before any of our other
// static objects, assuming they don't use this same pragma.
//
#pragma warning(disable:4073) // ignore init_seg warning
#pragma init_seg(lib)
CBsDbgTrace g_cDbgTrace;
static VOID MakeFileUnicode(
IN HANDLE hFile
);
/////////////////////////////////////////////////////////////////////////////
// constants
//
const WCHAR VSS_TRACINGKEYPATH[] =
L"SYSTEM\\CurrentControlSet\\Services\\VSS\\Debug\\Tracing";
const WCHAR SETUP_KEY[] =
L"SYSTEM\\Setup";
const WCHAR SETUP_INPROGRESS_REG[] =
L"SystemSetupInProgress";
const DWORD SETUP_INPROGRESS_VALUE = 1;
/////////////////////////////////////////////////////////////////////////////
// Globals
//
//
// NOTE: g_cDbgTrace, the global instance of this class is declared in
// ltss\modules\ltssvc\src\ltssvc.cxx since we have to make sure
// this object is the last one being destructed, otherwise possible
// calls to this object will fail.
//
//
// Define a TLS var, stores the CLTermStg & intention list index.
// The index is a counter that is incremented and set for each thread
// coming into the service, in the CLTermStg::FinalConstruct method.
// The counter is also incremented and set for each intention list
// thread that is created by the service.
//
// WARNING
//
//
//_declspec( thread ) DWORD CBsDbgTrace::m_dwContextNum = 0;
//
// Queries a registry value name and if found sets dwValue to the value.
// If the value name is not found, dwValue remains unchanged.
//
static DWORD
QuerySetValue (
IN CRegKey &cRegKey,
IN OUT DWORD &dwValue,
IN LPCWSTR pwszValueName
)
{
DWORD dwReadValue = 0;
DWORD dwResult = cRegKey.QueryValue( dwReadValue, pwszValueName );
if ( dwResult == ERROR_SUCCESS )
dwValue = dwReadValue;
return dwResult;
}
//
// Queries a registry value name and if found sets bValue to the value.
// If the value name is not found, bValue remains unchanged.
//
static DWORD
QuerySetValue (
IN CRegKey &cRegKey,
IN OUT BOOL &bValue,
IN LPCWSTR pwszValueName
)
{
DWORD dwReadValue = 0;
DWORD dwResult = cRegKey.QueryValue( dwReadValue, pwszValueName );
if ( dwResult == ERROR_SUCCESS )
bValue = (BOOL)(dwReadValue != 0);
return dwResult;
}
//
// Queries a registry value name and if found sets wsValue to the value.
// If the value name is not found, wsValue remains unchanged.
//
static DWORD
QuerySetValue (
IN CRegKey &cRegKey,
OUT LPWSTR &wsValue, // If allocated, must be freed before calling with ::VssFreeString
IN LPCWSTR pwszValueName
)
{
WCHAR pszValueBuffer[_MAX_PATH];
DWORD dwCount = _MAX_PATH;
DWORD dwResult = cRegKey.QueryValue( pszValueBuffer, pwszValueName, &dwCount );
BS_ASSERT(wsValue == NULL);
if ( dwResult == ERROR_SUCCESS )
::VssDuplicateStr(wsValue, pszValueBuffer);
return dwResult;
}
//
// ***** class definitions *****
//
CBsDbgTrace::CBsDbgTrace()
/*++
Routine Description:
Constructor method. Default values are given to operational
parameters and overwritten using values from the registry if
set. Also prints out the trace file banner.
Arguments:
NONE
Return Value:
NONE
--*/
{
m_bInitialized = false;
m_bTracingEnabled = false;
m_pcs = NULL;
Initialize( TRUE );
}
CBsDbgTrace::~CBsDbgTrace()
/*++
Routine Description:
Destructor method. Prints out the last record in the NTMS
Arguments:
LONG Indent - NOT USED YET [todo] this is the indentation indicator
LONG Level - this is the debug trace level
Return Value:
BOOL
--*/
{
if ( !m_bInitialized )
return;
if ( m_bTracingEnabled ) {
//
// Write out a finished tracing message
//
m_pcs->Enter();
BsDebugTraceAlways( 0, DEBUG_TRACE_ALL, ( L"****************************************************************" ) );
BsDebugTraceAlways( 0, DEBUG_TRACE_ALL, ( L"** TRACING FINISHED - ProcessId: 0x%x, ContextId: 0x%x",
m_dwCurrentProcessId, m_dwContextId ) );
WCHAR pwszCurrentTime[128];
time_t ltime;
struct tm *pToday;
time( &ltime );
pToday = localtime( &ltime );
wcsftime( pwszCurrentTime, sizeof pwszCurrentTime, L"%c", pToday );
BsDebugTraceAlways( 0, DEBUG_TRACE_ALL, ( L"** Current time: %s", pwszCurrentTime ) );
BsDebugTraceAlways( 0, DEBUG_TRACE_ALL, ( L"** Elapsed time: %d seconds", ltime- m_lTimeStarted ) );
BsDebugTraceAlways( 0, DEBUG_TRACE_ALL, ( L"****************************************************************" ) );
m_pcs->Leave();
//
// Make sure the file is flushed before leaving
//
if ( m_bTraceToFile ) {
m_hTraceFile = ::CreateFile( m_pwszTraceFileName?
m_pwszTraceFileName :
BS_DBG_TRACE_FILE_NAME_DFLT,
GENERIC_WRITE,
FILE_SHARE_READ,
NULL,
OPEN_ALWAYS,
FILE_ATTRIBUTE_NORMAL,
NULL );
if ( m_hTraceFile != INVALID_HANDLE_VALUE ) {
::FlushFileBuffers( m_hTraceFile );
::CloseHandle( m_hTraceFile );
}
}
}
::VssFreeString(m_pwszTraceFileName);
//
// Delete the critical section
//
delete m_pcs;
m_pcs = NULL;
m_bInitialized = FALSE;
}
//
// In certain cases the global trace object doesn't seem to get it's constructor called.
// To fix this problem, this function was added to perform the initialization of the
// object. This function is called both in the constructor and the set context call
// which all DLLs that use the trace class call.
//
VOID
CBsDbgTrace::Initialize(
IN BOOL bInConstructor
)
{
if ( !m_bInitialized )
{
try
{
//
// Get the critical section created first
//
m_pcs = new CBsCritSec;
if ( m_pcs == NULL )
throw E_OUTOFMEMORY;
m_bInitialized = TRUE;
m_bTracingEnabled = FALSE;
m_bTraceToFile = BS_DBG_TRACE_TO_FILE_DFLT;
m_bTraceToDebugger = BS_DBG_TRACE_TO_DEBUGGER_DFLT;
m_bTraceEnterExit = BS_DBG_TRACE_ENTER_EXIT_DFLT;
m_dwTraceLevel = BS_DBG_TRACE_LEVEL_DFLT;
m_bTraceFileLineInfo = BS_DBG_TRACE_FILE_LINE_INFO_DFLT;
m_bTraceTimestamp = BS_DBG_TRACE_TIMESTAMP_DFLT;
m_pwszTraceFileName = NULL;
m_bForceFlush = BS_DBG_TRACE_FORCE_FLUSH_DFLT;
m_dwTraceIndent = 0;
m_bInTrace = FALSE;
m_hTraceFile = INVALID_HANDLE_VALUE;
m_dwLineNum = 0;
m_dwCurrentProcessId = GetCurrentProcessId();
m_bIsDuringSetup = FALSE;
LARGE_INTEGER liTimer;
if ( ::QueryPerformanceCounter( &liTimer ) )
{
// Got high performance counter, use the low part
m_dwContextId = liTimer.LowPart;
}
else
{
m_dwContextId = ::GetTickCount();
}
ReadRegistry();
BsDebugTraceAlways( 0, DEBUG_TRACE_ALL, ( L"****************************************************************" ) );
BsDebugTraceAlways( 0, DEBUG_TRACE_ALL, ( L"** TRACING STARTED - ProcessId: 0x%x, ContextId: 0x%x",
m_dwCurrentProcessId, m_dwContextId ) );
if ( !bInConstructor )
BsDebugTraceAlways( 0, DEBUG_TRACE_ALL, ( L"** N.B. NOT INITIALIZED BY THE CONSTRUCTOR" ) );
WCHAR pwszCurrentTime[128];
struct tm *pToday;
time( &m_lTimeStarted );
pToday = localtime( &m_lTimeStarted );
wcsftime( pwszCurrentTime, sizeof pwszCurrentTime, L"%c", pToday );
BsDebugTraceAlways( 0, DEBUG_TRACE_ALL, ( L"** Current time: %s", pwszCurrentTime ) );
BsDebugTraceAlways( 0, DEBUG_TRACE_ALL, ( L"** Product version: %d.%d.%d.%d", VER_PRODUCTVERSION ) );
BsDebugTraceAlways( 0, DEBUG_TRACE_ALL, ( L"****************************************************************" ) );
}
catch(...)
{
delete m_pcs;
m_pcs = NULL;
m_bInitialized = false;
m_bTracingEnabled = false;
}
}
}
BOOL
CBsDbgTrace::IsDuringSetup()
{
return m_bIsDuringSetup;
}
HRESULT
CBsDbgTrace::ReadRegistry()
/*++
Routine Description:
Tries to read debug specific values from the registry and adds
the values if they don't exist.
Arguments:
NONE
Return Value:
HRESULT
--*/
{
DWORD dwRes;
CRegKey cRegKeySetup;
CRegKey cRegKeyTracing;
m_bTracingEnabled = FALSE;
m_bIsDuringSetup = FALSE;
//
// Open the Setup key
//
dwRes = cRegKeySetup.Open( HKEY_LOCAL_MACHINE, SETUP_KEY, KEY_READ );
if ( dwRes == ERROR_SUCCESS ) {
DWORD dwSetupInProgress = 0;
QuerySetValue( cRegKeySetup, dwSetupInProgress, SETUP_INPROGRESS_REG );
m_bIsDuringSetup = ( dwSetupInProgress == SETUP_INPROGRESS_VALUE );
}
//
// Open the VSS tracing key
//
dwRes = cRegKeyTracing.Open( HKEY_LOCAL_MACHINE, VSS_TRACINGKEYPATH, KEY_READ );
if ( dwRes == ERROR_SUCCESS ) {
// The name of the optional trace file
QuerySetValue( cRegKeyTracing, m_pwszTraceFileName, BS_DBG_TRACE_FILE_NAME_REG );
// The trace level determines what type of traciung will occur. Zero
// indicates that no tracing will occur, and is the default.
QuerySetValue( cRegKeyTracing, m_dwTraceLevel, BS_DBG_TRACE_LEVEL_REG );
// The TraceEnterExit flag determines whether or not function entry & exit
// information is output to the trace file & the debug output stream.
QuerySetValue( cRegKeyTracing, m_bTraceEnterExit, BS_DBG_TRACE_ENTER_EXIT_REG );
// The TraceToFile flag determines whether or not trace information is output to
// the trace file. If this value is FALSE, no output is sent to the trace file.
QuerySetValue( cRegKeyTracing, m_bTraceToFile, BS_DBG_TRACE_TO_FILE_REG );
// The TraceToDebugger flag determines whether or not trace information is output
// to the debugger. If this value is FALSE, no output is sent to the debugger.
QuerySetValue( cRegKeyTracing, m_bTraceToDebugger, BS_DBG_TRACE_TO_DEBUGGER_REG );
// The Timestamp flag determines whether or not timestamp
// information is output to the trace file & the debug output stream.
QuerySetValue( cRegKeyTracing, m_bTraceTimestamp, BS_DBG_TRACE_TIMESTAMP_REG );
// The FileLineInfo flag determines whether or not the module file name
// and line number information is output to the trace file & the debug
// output stream.
QuerySetValue( cRegKeyTracing, m_bTraceFileLineInfo, BS_DBG_TRACE_FILE_LINE_INFO_REG );
// The TraceForceFlush flag specifies whether or not after each trace message is
// written to the trace file a forced flush occurs. If enabled, no trace records
// are ever lost, however, performance is greatly reduced.
QuerySetValue( cRegKeyTracing, m_bForceFlush, BS_DBG_TRACE_FORCE_FLUSH_REG );
// Determine if tracing should be enabled
if ( m_bTraceToDebugger || m_bTraceToFile )
m_bTracingEnabled = TRUE;
}
return S_OK;
}
HRESULT
CBsDbgTrace::PrePrint(
IN LPCWSTR pwszSourceFileName,
IN DWORD dwLineNum,
IN DWORD dwIndent,
IN DWORD dwLevel,
IN LPCWSTR pwszFunctionName,
IN BOOL bTraceEnter
)
/*++
Routine Description:
Acquires the critical section so that other threads are
now serialized. Opens the trace file if necessary.
N.B. Any A/V's in this code can cause a hang since the SEH translator function
calls these trace functions.
Arguments:
pszSourceFileName - Source file name of the module whose
code called this method.
dwLineNum - Line number in the source
dwIndent - Number to increase or decrease the indendation level
dwLevel - Trace level that specifies for which component
the code resides in.
pwszFunctionName - For entry/exit tracing. Specifies the
function name constains a call the a trace macro.
bTraceEnter - True if this is a entry trace.
Return Value:
HRESULT
--*/
{
m_pcs->Enter();
//
// Assume the trace macros have already filtered out traces based
// on m_bTracingEnabled and on the active trace level.
//
if ( m_bTracingEnabled && (dwLevel & m_dwTraceLevel) != 0) {
if ( pwszSourceFileName == NULL )
m_pwszSourceFileName = L"(Unknown source file)";
else
{
//
// Keep only two levels deep of directory components
//
LPCWSTR pwszTemp = pwszSourceFileName + ::wcslen( pwszSourceFileName ) - 1;
for ( int i = 0; pwszTemp > pwszSourceFileName && i < 3; ++i )
{
do
{
--pwszTemp;
}
while( *pwszTemp != L'\\' && pwszTemp > pwszSourceFileName ) ;
}
if ( pwszTemp > pwszSourceFileName )
m_pwszSourceFileName = pwszTemp + 1;
else
m_pwszSourceFileName = pwszSourceFileName;
}
m_pwszFunctionName = pwszFunctionName;
m_dwLineNum = dwLineNum;
m_bTraceEnter = bTraceEnter;
BS_ASSERT( m_hTraceFile == INVALID_HANDLE_VALUE );
if ( m_bTraceToFile ) {
m_hTraceFile = ::CreateFile( m_pwszTraceFileName?
m_pwszTraceFileName :
BS_DBG_TRACE_FILE_NAME_DFLT,
GENERIC_WRITE,
FILE_SHARE_READ | FILE_SHARE_WRITE,
NULL,
OPEN_ALWAYS,
FILE_ATTRIBUTE_NORMAL,
NULL );
if ( m_hTraceFile == INVALID_HANDLE_VALUE ) {
//
// Error opening the file, print a message to the debugger if debugger
// tracing is enabled
//
Print( L"CBsDbgTrace::PrePrint: TRACING ERROR: Unable to open trace file, dwRet: %u", ::GetLastError() );
} else {
//
// Now lock the process from other processes and threads that are concurrently
// accessing the file. Just lock the first byte of the file.
//
OVERLAPPED ovStart = { NULL, NULL, { 0, 0 }, 0 };
if ( !::LockFileEx( m_hTraceFile,
LOCKFILE_EXCLUSIVE_LOCK,
0,
1,
0,
&ovStart ) ) {
//
// Tracing to file will be skipped for this record. This should
// never happen in practice.
//
::CloseHandle( m_hTraceFile );
m_hTraceFile = INVALID_HANDLE_VALUE;
//
// Try printing a trace message that will get to the debugger if debugger
// tracing is enabled
//
Print( L"CBsDbgTrace::PrePrint: TRACING ERROR: Unable to lock trace file, skipping trace record, dwRet: %u", ::GetLastError() );
} else {
//
// If the file is new (empty) put the UNICODE BOM at the beginning of the file
//
LARGE_INTEGER liPointer;
if ( ::GetFileSizeEx( m_hTraceFile, &liPointer ) ) {
if ( liPointer.QuadPart == 0 )
::MakeFileUnicode( m_hTraceFile );
}
//
// Now move the file pointer to the end of the file
//
liPointer.QuadPart = 0;
if ( !::SetFilePointerEx( m_hTraceFile,
liPointer,
NULL,
FILE_END ) ) {
//
// Don't write to the file since it might overwrite valid records.
// Tracing to file will be skipped for this record. This should
// never happen in practice.
//
::CloseHandle( m_hTraceFile );
m_hTraceFile = INVALID_HANDLE_VALUE;
//
// Try printing a trace message that will get to the debugger if debugger
// tracing is enabled
//
Print( L"CBsDbgTrace::PrePrint: TRACING ERROR: Unable to set end of file, skipping trace record, dwRet: %u", ::GetLastError() );
}
}
}
}
m_bInTrace = TRUE;
}
return S_OK;
UNREFERENCED_PARAMETER( dwIndent );
}
HRESULT
CBsDbgTrace::PostPrint(
IN DWORD dwIndent
)
/*++
Routine Description:
Releases the critical section so that other threads
can now call perform tracing. Closes the trace file
and resets variables.
Arguments:
dwIndent - Number to increase or decrease the indendation level
Return Value:
HRESULT
--*/
{
if ( m_hTraceFile != INVALID_HANDLE_VALUE ) {
OVERLAPPED ovStart = { NULL, NULL, { 0, 0 }, 0 };
if ( !::UnlockFileEx( m_hTraceFile,
0,
1,
0,
&ovStart ) ) {
Print( L"CBsDbgTrace::PrePrint: TRACING ERROR: Unable to unlock trace file, dwRet: %u", ::GetLastError() );
}
if ( m_bForceFlush )
::FlushFileBuffers( m_hTraceFile );
::CloseHandle( m_hTraceFile );
m_hTraceFile = INVALID_HANDLE_VALUE;
}
m_pwszSourceFileName = NULL;
m_pwszFunctionName = NULL;
m_dwLineNum = 0;
m_bInTrace = FALSE;
m_pcs->Leave();
return S_OK;
UNREFERENCED_PARAMETER( dwIndent );
}
HRESULT _cdecl
CBsDbgTrace::Print(
IN LPCWSTR pwszFormatStr,
IN ...
)
/*++
Routine Description:
Formats the trace message out to the trace file and/or debugger.
Arguments:
pwszFormatStr - printf style format string
... - Arguments for the message
Return Value:
HRESULT
--*/
{
va_list pArg;
if ( m_bInTrace ) {
if ( m_bTraceTimestamp )
swprintf( m_pwszOutBuf,
L"[%010u,",
GetTickCount() );
else
swprintf( m_pwszOutBuf,
L"[-," );
swprintf( m_pwszOutBuf + wcslen( m_pwszOutBuf ),
L"0x%06x:0x%04x:0x%08x] ",
m_dwCurrentProcessId,
GetCurrentThreadId(),
m_dwContextId );
if ( m_bTraceFileLineInfo )
swprintf( m_pwszOutBuf + wcslen( m_pwszOutBuf ),
L"%s(%04u): ",
m_pwszSourceFileName,
m_dwLineNum );
OutputString();
//
// read the variable length parameter list into a formatted string
//
va_start( pArg, pwszFormatStr );
_vsnwprintf( m_pwszOutBuf, BS_DBG_OUT_BUF_SIZE-1, pwszFormatStr, pArg );
va_end( pArg );
OutputString();
//
// Finish up with a carriage return.
//
wcscpy( m_pwszOutBuf, L"\r\n" );
OutputString();
}
return S_OK;
}
HRESULT _cdecl
CBsDbgTrace::PrintEnterExit(
IN LPCWSTR pwszFormatStr,
IN ...
)
/*++
Routine Description:
Formats the entry/exit trace message out to the trace file and/or debugger.
Arguments:
pwszFormatStr - printf style format string
... - Arguments for the message
Return Value:
HRESULT
--*/
{
va_list pArg;
if ( m_bInTrace ) {
if ( m_bTraceTimestamp )
swprintf( m_pwszOutBuf,
L"[%010u,",
GetTickCount() );
else
swprintf( m_pwszOutBuf,
L"[-," );
swprintf( m_pwszOutBuf + wcslen( m_pwszOutBuf ),
L"0x%06x:0x%04x:0x%08x] %s {%s}: ",
m_dwCurrentProcessId,
GetCurrentThreadId(),
m_dwContextId,
m_bTraceEnter ? L"ENTER" : L"EXIT ",
m_pwszFunctionName );
OutputString();
//
// read the variable length parameter list into a formatted string
//
va_start( pArg, pwszFormatStr );
_vsnwprintf( m_pwszOutBuf, BS_DBG_OUT_BUF_SIZE-1, pwszFormatStr, pArg );
va_end( pArg );
OutputString();
//
// Finish up with a carriage return.
//
wcscpy( m_pwszOutBuf, L"\r\n" );
OutputString();
}
return S_OK;
}
HRESULT
CBsDbgTrace::OutputString()
/*++
Routine Description:
Prints the trace message out to the trace file and/or debugger.
Arguments:
Assumes m_pwszOutBuf has the string to be printed.
Return Value:
HRESULT
--*/
{
//
// Make sure we didn't go off the end. Can't use BS_ASSERT(), it
// will cause an deadlock.
//
_ASSERTE( wcslen( m_pwszOutBuf ) < BS_DBG_OUT_BUF_SIZE );
//
// Print to the debug stream for debug builds
//
if ( m_bTraceToDebugger )
OutputDebugString( m_pwszOutBuf );
//
// If file tracing is enabled, dump to file
//
if ( m_hTraceFile != INVALID_HANDLE_VALUE ) {
DWORD dwBytesWritten;
::WriteFile( m_hTraceFile,
m_pwszOutBuf,
(DWORD)(wcslen( m_pwszOutBuf ) * sizeof(WCHAR)),
&dwBytesWritten,
NULL );
}
return S_OK;
}
VOID CBsDbgTrace::SetContextNum(
IN DWORD dwContextNum
)
/*++
Routine Description:
Use to be used to set the context number of the operation. Now it is only
used to determine if a DLL is loading using the trace class.
Arguments:
LTS_CONTEXT_DELAYED_DLL - DLL is using the class object.
--*/
{
if (dwContextNum == LTS_CONTEXT_DELAYED_DLL && !m_bInitialized )
{
Initialize();
}
}
/*++
Routine Description:
Puts the UNICODE UCS-2 BOM (Byte Order Mark) at the beginning of the file
to let applications know that 1. this is a UCS-2 UNICODE file and 2. that
the byte ordering is little-endian.
Assumes the file is empty.
Arguments:
hFile - Handle to the file
Return Value:
<Enter return values here>
--*/
static VOID MakeFileUnicode(
IN HANDLE hFile
)
{
BS_ASSERT( hFile != INVALID_HANDLE_VALUE );
BYTE byteBOM[2] = { 0xFF, 0xFE };
DWORD dwBytesWritten;
::WriteFile( hFile,
byteBOM,
sizeof byteBOM,
&dwBytesWritten,
NULL );
}
void __cdecl CVssFunctionTracer::TranslateError
(
IN CVssDebugInfo dbgInfo, // Caller debugging info
IN HRESULT hr,
IN LPCWSTR wszRoutine
)
/*++
Routine Description:
Translates an error into a well defined error code. May log to
the event log if the error is unexpected
--*/
{
if (hr == E_OUTOFMEMORY ||
hr == HRESULT_FROM_WIN32(ERROR_NOT_ENOUGH_MEMORY) ||
hr == HRESULT_FROM_WIN32(ERROR_NO_MORE_SEARCH_HANDLES) ||
hr == HRESULT_FROM_WIN32(ERROR_NO_LOG_SPACE) ||
hr == HRESULT_FROM_WIN32(ERROR_DISK_FULL) ||
hr == HRESULT_FROM_WIN32(ERROR_NO_MORE_USER_HANDLES))
Throw(dbgInfo, E_OUTOFMEMORY, L"Out of memory detected in function %s", wszRoutine);
else
{
LogError(VSS_ERROR_UNEXPECTED_CALLING_ROUTINE, dbgInfo << wszRoutine << hr);
Throw(dbgInfo, E_UNEXPECTED, L"Unexpected error in routine %s. hr = 0x%08lx", wszRoutine, hr);
}
}
void __cdecl CVssFunctionTracer::TranslateGenericError
(
IN CVssDebugInfo dbgInfo, // Caller debugging info
IN HRESULT hr,
IN LPCWSTR wszErrorTextFormat,
IN ...
)
/*++
Routine Description:
Translates an error into a well defined error code. May log to
the event log if the error is unexpected
Throws:
E_UNEXPECTED
- on unrecognized error codes
--*/
{
WCHAR wszOutputBuffer[nVssMsgBufferSize + 1];
va_list marker;
va_start( marker, wszErrorTextFormat );
_vsnwprintf( wszOutputBuffer, nVssMsgBufferSize, wszErrorTextFormat, marker );
va_end( marker );
if (hr == E_OUTOFMEMORY ||
hr == HRESULT_FROM_WIN32(ERROR_NOT_ENOUGH_MEMORY) ||
hr == HRESULT_FROM_WIN32(ERROR_NO_MORE_SEARCH_HANDLES) ||
hr == HRESULT_FROM_WIN32(ERROR_NO_LOG_SPACE) ||
hr == HRESULT_FROM_WIN32(ERROR_DISK_FULL) ||
hr == HRESULT_FROM_WIN32(ERROR_NO_MORE_USER_HANDLES))
Throw(dbgInfo, E_OUTOFMEMORY, L"Out of memory detected. %s", wszOutputBuffer);
else
{
LogError(VSS_ERROR_UNEXPECTED_ERRORCODE, dbgInfo << wszOutputBuffer << hr);
Throw(dbgInfo, E_UNEXPECTED, L"Unexpected error: %s [hr = 0x%08lx]", wszOutputBuffer, hr);
}
}
void __cdecl CVssFunctionTracer::TranslateProviderError
(
IN CVssDebugInfo dbgInfo, // Caller debugging info
IN GUID ProviderID,
IN LPCWSTR wszErrorTextFormat,
IN ...
)
/*++
Routine Description:
Translates an error into a well defined error code. May log to
the event log if the error is unexpected
The error is coming from a provider call
Throws:
E_OUTOFMEMORY
VSS_E_UNEXPECTED_PROVIDER_ERROR
- Unexpected provider error. The error code is logged into the event log.
VSS_E_PROVIDER_VETO
- Expected provider error. The provider already did the logging.
--*/
{
WCHAR wszOutputBuffer[nVssMsgBufferSize + 1];
va_list marker;
va_start( marker, wszErrorTextFormat );
_vsnwprintf( wszOutputBuffer, nVssMsgBufferSize, wszErrorTextFormat, marker );
va_end( marker );
if (hr == E_OUTOFMEMORY)
Throw(dbgInfo, E_OUTOFMEMORY, L"Out of memory detected. %s. Provider ID = " WSTR_GUID_FMT,
wszOutputBuffer, GUID_PRINTF_ARG(ProviderID));
else if (hr == E_INVALIDARG) {
LogError(VSS_ERROR_CALLING_PROVIDER_ROUTINE_INVALIDARG, dbgInfo << ProviderID << wszOutputBuffer );
Throw(dbgInfo, E_INVALIDARG, L"Invalid argument detected. %s. Provider ID = " WSTR_GUID_FMT,
wszOutputBuffer, GUID_PRINTF_ARG(ProviderID));
}
else if (hr == VSS_E_PROVIDER_VETO)
Throw(dbgInfo, VSS_E_PROVIDER_VETO, L"Provider veto detected. %s. Provider ID = " WSTR_GUID_FMT,
wszOutputBuffer, GUID_PRINTF_ARG(ProviderID));
else
{
LogError(VSS_ERROR_CALLING_PROVIDER_ROUTINE, dbgInfo << ProviderID << wszOutputBuffer << hr );
Throw(dbgInfo, VSS_E_UNEXPECTED_PROVIDER_ERROR,
L"Unexpected error calling a provider routine: %s [hr = 0x%08lx] Provider ID = " WSTR_GUID_FMT,
wszOutputBuffer, hr, GUID_PRINTF_ARG(ProviderID));
}
}
void __cdecl CVssFunctionTracer::TranslateInternalProviderError
(
IN CVssDebugInfo dbgInfo, // Caller debugging info
IN HRESULT hrToBeTreated,
IN HRESULT hrToBeThrown,
IN LPCWSTR wszErrorTextFormat,
IN ...
)
/*++
Routine Description:
Translates an error into a well defined error code. May log to
the event log if the error is unexpected
The error is coming from a provider call
Throws:
E_OUTOFMEMORY
hrToBeThrown
--*/
{
WCHAR wszOutputBuffer[nVssMsgBufferSize + 1];
va_list marker;
va_start( marker, wszErrorTextFormat );
_vsnwprintf( wszOutputBuffer, nVssMsgBufferSize, wszErrorTextFormat, marker );
va_end( marker );
hr = hrToBeTreated;
if (hr == E_OUTOFMEMORY ||
hr == HRESULT_FROM_WIN32(ERROR_NOT_ENOUGH_MEMORY) ||
hr == HRESULT_FROM_WIN32(ERROR_NO_MORE_SEARCH_HANDLES) ||
hr == HRESULT_FROM_WIN32(ERROR_NO_LOG_SPACE) ||
hr == HRESULT_FROM_WIN32(ERROR_DISK_FULL) ||
hr == HRESULT_FROM_WIN32(ERROR_NO_MORE_USER_HANDLES))
Throw(dbgInfo, E_OUTOFMEMORY, L"Out of memory detected. %s.", wszOutputBuffer);
else if ( hr == HRESULT_FROM_WIN32(ERROR_FILE_NOT_FOUND) ||
hr == HRESULT_FROM_WIN32(ERROR_DEVICE_NOT_CONNECTED) ||
hr == HRESULT_FROM_WIN32(ERROR_NOT_READY))
{
LogError(VSS_ERROR_DEVICE_NOT_CONNECTED, dbgInfo << wszOutputBuffer );
Throw(dbgInfo, VSS_E_OBJECT_NOT_FOUND,
L"Invalid device when calling a provider routine: %s", wszOutputBuffer);
}
else
{
LogError(VSS_ERROR_UNEXPECTED_ERRORCODE, dbgInfo << wszOutputBuffer << hr );
Throw(dbgInfo, hrToBeThrown,
L"Unexpected error calling a provider routine: %s [hr = 0x%08lx] ", wszOutputBuffer, hr );
}
}
void __cdecl CVssFunctionTracer::TranslateWriterReturnCode
(
IN CVssDebugInfo dbgInfo, // Caller debugging info
IN LPCWSTR wszErrorTextFormat,
IN ...
)
/*++
Routine Description:
Translates an error into a well defined error code. May log to
the event log if the error is unexpected
The error is coming from a writer call (CoCreteInstance of the writer COM+ event class
or sending an event.
Throws:
E_OUTOFMEMORY
VSS_E_UNEXPECTED_WRITER_ERROR
- Unexpected writer error. The error code is logged into the event log.
--*/
{
if (HrSucceeded()) {
BS_ASSERT(hr == S_OK || hr == EVENT_S_NOSUBSCRIBERS || hr == EVENT_S_SOME_SUBSCRIBERS_FAILED);
hr = S_OK;
return;
}
WCHAR wszOutputBuffer[nVssMsgBufferSize + 1];
va_list marker;
va_start( marker, wszErrorTextFormat );
_vsnwprintf( wszOutputBuffer, nVssMsgBufferSize, wszErrorTextFormat, marker );
va_end( marker );
if (hr == EVENT_E_ALL_SUBSCRIBERS_FAILED) {
Warning( VSSDBG_COORD, L"%s event failed at one writer. hr = 0x%08lx", wszOutputBuffer, hr);
// ignore the error;
return;
}
else if (hr == E_OUTOFMEMORY)
Throw(dbgInfo, E_OUTOFMEMORY, L"Out of memory detected. %s.", wszOutputBuffer);
else
{
LogError(VSS_ERROR_UNEXPECTED_WRITER_ERROR, dbgInfo << wszOutputBuffer << hr );
Throw(dbgInfo, VSS_E_UNEXPECTED_WRITER_ERROR,
L"Unexpected error calling a provider routine: %s [hr = 0x%08lx] ", wszOutputBuffer, hr);
}
}
void __cdecl CVssFunctionTracer::LogGenericWarning
(
IN CVssDebugInfo dbgInfo, // Caller debugging info
IN LPCWSTR wszErrorTextFormat,
IN ...
)
/*++
Routine Description:
Log a generic warning.
--*/
{
WCHAR wszOutputBuffer[nVssMsgBufferSize + 1];
va_list marker;
va_start( marker, wszErrorTextFormat );
_vsnwprintf( wszOutputBuffer, nVssMsgBufferSize, wszErrorTextFormat, marker );
va_end( marker );
LogError(VSS_WARNING_UNEXPECTED, dbgInfo << wszOutputBuffer << hr, EVENTLOG_WARNING_TYPE);
Trace(dbgInfo, L"WARNING: %s [hr = 0x%08lx]", wszOutputBuffer, hr);
}
// This method must be called prior to calling a CoCreateInstance that may start VSS
void CVssFunctionTracer::LogVssStartupAttempt()
{
// the name of the Volume Snapshot Service
const LPCWSTR wszVssvcServiceName = L"VSS";
SC_HANDLE shSCManager = NULL;
SC_HANDLE shSCService = NULL;
try
{
//
// Check to see if VSSVC is running. If not, we are putting an entry into the trace log if enabled.
//
// Connect to the local service control manager
shSCManager = OpenSCManager (NULL, NULL, SC_MANAGER_CONNECT);
if (!shSCManager)
TranslateGenericError(VSSDBG_GEN, HRESULT_FROM_WIN32(GetLastError()),
L"OpenSCManager(NULL,NULL,SC_MANAGER_CONNECT)");
// Get a handle to the service
shSCService = OpenService (shSCManager, wszVssvcServiceName, SERVICE_QUERY_STATUS);
if (!shSCService)
TranslateGenericError(VSSDBG_GEN, HRESULT_FROM_WIN32(GetLastError()),
L" OpenService (shSCManager, \'%s\', SERVICE_QUERY_STATUS)", wszVssvcServiceName);
// Now query the service to see what state it is in at the moment.
SERVICE_STATUS sSStat;
if (!QueryServiceStatus (shSCService, &sSStat))
TranslateGenericError(VSSDBG_GEN, HRESULT_FROM_WIN32(GetLastError()),
L"QueryServiceStatus (shSCService, &sSStat)");
// If the service is not running, then we will put an informational error log entry
// if (sSStat.dwCurrentState != SERVICE_RUNNING)
// LogError(VSS_INFO_SERVICE_STARTUP,
// VSSDBG_GEN << GetCommandLineW() << (HRESULT)sSStat.dwCurrentState,
// EVENTLOG_INFORMATION_TYPE);
if (sSStat.dwCurrentState != SERVICE_RUNNING)
Trace( VSSDBG_GEN,
L"Volume Snapshots Service information: Service starting at request of process '%s'. [0x%08x]",
GetCommandLineW(), sSStat.dwCurrentState );
} VSS_STANDARD_CATCH ((*this));
// Close handles
if (NULL != shSCService) CloseServiceHandle (shSCService);
if (NULL != shSCManager) CloseServiceHandle (shSCManager);
}