windows-nt/Source/XPSP1/NT/net/upnp/host/upnphost/udhhttp/log.cpp

/*--
Copyright (c) 1999  Microsoft Corporation
Module Name: LOG.CPP
Author: John Spaith
Abstract: Logging functions
--*/

#include "pch.h"
#pragma hdrstop


//  Responsible for log handling functions.
//  A curhttpd.log and prvhttpd.log keep track of current and the previous
//  changes.  The format for each line is stolen from IIS, except that we
//  include the date in each line; they create a new log for each day.


#include "httpd.h"

#ifdef WEB_SERVER_LOGGING

// const char cszDateOutputFmt[]     = "%3s, %02d %3s %04d %02d:%02d:%02d ";

#define CURRENT_LOG_NAME L"\\current-httpd.log"
#define PREVIOUS_LOG_NAME L"\\previous-httpd.log"
#define LOG_REMOTE_ADDR_SIZE 50
#define LOG_EXTRA_BUFFER_LEN 100

void CLog::WriteEvent(DWORD dwEvent,...)
{
    CHAR szOutput[MINBUFSIZE];
    WCHAR wszFormat[512];
    WCHAR wszOutput[512];
    PSTR pszTrav = szOutput;
    SYSTEMTIME st;
    va_list ap;

    if (!LoadString(g_hInst,dwEvent,wszFormat,celems(wszFormat)))
        return;

    va_start(ap,dwEvent);
    wvsprintf(wszOutput,wszFormat,ap);
    va_end (ap);

    GetSystemTime(&st);
    pszTrav = WriteHTTPDate(szOutput,&st,FALSE);

    pszTrav += MyW2A(wszOutput,pszTrav,MINBUFSIZE - (pszTrav - szOutput)) - 1;
    WriteData(szOutput,pszTrav - szOutput);
}

CLog::~CLog()
{
    WriteEvent(IDS_HTTPD_SHUTDOWN_COMPLETE);
    MyCloseHandle(m_hLog);
    DeleteCriticalSection(&m_CritSection);
}

#define MAX_LOG_OPEN_ATTEMPTS  15

CLog::CLog(DWORD_PTR dwMaxFileLen, WCHAR * lpszLogDir)
{
    int i;

    memset(this, 0, sizeof(*this));
    if (0 == dwMaxFileLen || NULL == lpszLogDir)
    {
        TraceTag(ttidWebServer, "HTTPD: No logging to be performed, because of on registry settings");
        m_hLog = INVALID_HANDLE_VALUE;
        return;
    }

    m_dwMaxFileSize = dwMaxFileLen;
    InitializeCriticalSection(&m_CritSection);
    TraceTag(ttidWebServer, "HTTPD: Initializing log files");


    // remove trailing "\" if log file dir entry ends in it
    if ( lpszLogDir[wcslen(lpszLogDir) - 1] == L'\\')
        lpszLogDir[wcslen(lpszLogDir) - 1] = L'\0';


    wsprintf(lpszCurrentLog,L"%s%s",lpszLogDir, CURRENT_LOG_NAME);
    wsprintf(lpszPrevLog,L"%s%s",lpszLogDir,PREVIOUS_LOG_NAME);


    // Note:  It's possible that the log file is being written to a flash
    // drive, in which case the web server initialization routines would
    // be called before the drive is ready during boot time, in which
    // case we get an INVALID_HANDLE_VALUE.  To make sure the drive has
    // time to initialize, we go through this loop before failing.
    for (i = 0; i < MAX_LOG_OPEN_ATTEMPTS; i++)
    {
        if (INVALID_HANDLE_VALUE != (m_hLog = MyOpenAppendFile(lpszCurrentLog)))
        {
            break;
        }
        Sleep(1000);
    }

    if (INVALID_HANDLE_VALUE == m_hLog)
    {
        TraceTag(ttidWebServer, "HTTPD: CreateFile fails for log <<%s>>, no logging will be done, GLE=0x%08x",lpszCurrentLog,GetLastError());
        return;
    }

    m_dwFileSize = GetFileSize(m_hLog,NULL);
    if ((DWORD)-1 == m_dwFileSize)
    {
        TraceTag(ttidWebServer, "HTTPD: Get file size on log <<%s>> failed, err = %d",lpszCurrentLog,GetLastError());
        m_hLog = INVALID_HANDLE_VALUE;
        return;
    }

    if (m_dwFileSize != 0)          // This moves filePtr to append log file
    {
        if ((DWORD)-1 == SetFilePointer(m_hLog, (DWORD)m_dwFileSize, NULL, FILE_BEGIN))
        {
            TraceTag(ttidWebServer, "HTTPD: Get file size on log %s failed, err = %d",lpszCurrentLog,GetLastError());
            m_hLog = INVALID_HANDLE_VALUE;
            return;
        }
    }

    WriteEvent(IDS_HTTPD_STARTUP);
}



//  The log written has the following format
//  (DATE) (TIME) (IP of requester) (Method) (Request-URI) (Status returned)

//  DATE is in the same format as the recommended one for httpd headers
//  TIME is GMT

void CLog::WriteLog(CHttpRequest* pRequest)
{
    CHAR szBuffer[MINBUFSIZE];
    PSTR psz = szBuffer;
    DWORD_PTR dwToWrite = 0;

    DEBUGCHK(pRequest != NULL);

    if (INVALID_HANDLE_VALUE == m_hLog)  // no logging setup in reg, or prev failure
        return;

    // Make sure that buffer is big enough for filter additions, append if not so
    // We add LOG_EXTRA_BUFFER_LEN to account for date, spaces, and HTTP status code.
    DWORD cbNeeded = LOG_EXTRA_BUFFER_LEN + pRequest->GetLogBufferSize();

    if (cbNeeded > MINBUFSIZE)
    {
        psz = MyRgAllocNZ(CHAR,cbNeeded);
        if (!psz)
            return;
    }

    pRequest->GenerateLog(psz,&dwToWrite);
    WriteData(psz,dwToWrite);

    if (szBuffer != psz)
        MyFree(psz);
}

void CLog::WriteData(PSTR szBuffer, DWORD_PTR dwToWrite)
{
    DWORD dwWritten = 0;

    EnterCriticalSection(&m_CritSection);
    {
        m_dwFileSize += dwToWrite;
        // roll over the logs once the maximum size has been reached.
        if (m_dwFileSize > m_dwMaxFileSize)
        {
            MyCloseHandle(m_hLog);
            DeleteFile(lpszPrevLog);
            MoveFile(lpszCurrentLog,lpszPrevLog);
            m_hLog = MyOpenAppendFile(lpszCurrentLog);
            m_dwFileSize = dwToWrite;
        }

        if (m_hLog != INVALID_HANDLE_VALUE)
        {
            WriteFile(m_hLog,(LPCVOID) szBuffer,(DWORD)dwToWrite,&dwWritten,NULL);
            TraceTag(ttidWebServer, "HTTPD: Wrote log out to file");
        }
    }
    LeaveCriticalSection(&m_CritSection);
}


// Returns the size of the buffer we'll need.
DWORD CHttpRequest::GetLogBufferSize()
{
    PHTTP_FILTER_LOG pFLog = m_pFInfo ? m_pFInfo->m_pFLog : NULL;
    DWORD cbNeeded;

    // remotehost
    if (pFLog && pFLog->pszClientHostName)
        cbNeeded = strlen(pFLog->pszClientHostName);
    else
        cbNeeded = LOG_REMOTE_ADDR_SIZE;

    if (pFLog && pFLog->pszOperation)
        cbNeeded += strlen(pFLog->pszOperation);
    else if (m_pszMethod)
        cbNeeded += strlen(m_pszMethod);

    if (pFLog && pFLog->pszTarget)
        cbNeeded += strlen(pFLog->pszTarget);
    else if (m_pszURL)
        cbNeeded += strlen(m_pszURL);

    if (m_pszLogParam)
        cbNeeded += strlen(m_pszLogParam);

    return cbNeeded;
}



//  Generates the log.  First this fcn sees if a filter has created a new
//  logging structure, in which case valid data in pFLog will override actual
//  server data.  In the typical case we just use CHttpRequest info.

void CHttpRequest::GenerateLog(PSTR szBuffer, DWORD_PTR *pdwToWrite)
{
    SYSTEMTIME st;
    PSTR pszTarget = NULL;
    PSTR pszTrav = szBuffer;
    int i = 0;


    GetSystemTime(&st);     // Use GMT time for the log, too

    PHTTP_FILTER_LOG pFLog = m_pFInfo ? m_pFInfo->m_pFLog : NULL;

    // date and time
    pszTrav = WriteHTTPDate(pszTrav,&st,FALSE);

//  i += sprintf(szBuffer + i, cszDateOutputFmt,
//         rgWkday[st.wDayOfWeek], st.wDay, rgMonth[st.wMonth], st.wYear, st.wHour, st.wMinute, st.wSecond);

    // remotehost
    if (pFLog && pFLog->pszClientHostName)
    {
        pszTrav = strcpyEx(pszTrav,pFLog->pszClientHostName);
    }
    else
    {
        CHAR szAddress[LOG_REMOTE_ADDR_SIZE];
        GetRemoteAddress(m_socket,szAddress);
        pszTrav = strcpyEx(pszTrav,szAddress);
    }
    *pszTrav++ = ' ';

    //  The method (GET, POST, ...)
    if (pFLog && pFLog->pszOperation)
        pszTrav = strcpyEx(pszTrav,pFLog->pszOperation);
    else if (m_pszMethod)
        pszTrav = strcpyEx(pszTrav,m_pszMethod);
    else
        *pszTrav++ = '\t';  // If we get a bad request from browser, m_pszMethod may be NULL.

    *pszTrav++ = ' ';

    // target (URI)
    if (pFLog && pFLog->pszTarget)
        pszTarget = (PSTR) pFLog->pszTarget;
    else
        pszTarget = m_pszURL;


    // like IIS, we convert any spaces in here into "+" signs.
    // NOTES:   IIS does this for both filter changed targets and URLS.
    // It only does it with spaces, doesn't convert \r\n, tabs, or any other escape
    // characters

    if (pszTarget)      // on a bad request, m_pszURL may = NULL.  Check.
    {
        while ( *pszTarget)
        {
            if ( *pszTarget == ' ')
                *pszTrav++ = '+';
            else
                *pszTrav++ = *pszTarget;
            pszTarget++;
        }
    }
    *pszTrav++ = ' ';


    // status
    if (pFLog)
        _itoa(pFLog->dwHttpStatus,pszTrav,10);
    else
        _itoa(rgStatus[m_rs].dwStatusNumber,pszTrav,10);
    pszTrav = strchr(pszTrav,'\0');
    *pszTrav++ = ' ';

    if (m_pszLogParam)    // ISAPI Extension logging has modified something
        pszTrav = strcpyEx(pszTrav,m_pszLogParam);
    *pszTrav++ = '\r';
    *pszTrav++ = '\n';
    *pszTrav= '\0';


    *pdwToWrite = pszTrav - szBuffer;
    return;
}

#endif //!WEB_SERVER_LOGGING