/*---
*	File: dsapilog.c
*	Desc: Source for DSAPI HTTP logging filter.
*	Auth: Paul D. Ray
*/

#include "dsapilog.h"

/*---
* FilterInit() - Required filter entry point. Called upon
*   filter startup, which occurs when HTTP server task is started.
*/
DLLEXPORT DWORD FilterInit(FilterInitData *pInitData)
{
	HANDLE hCompound;

	// initialize Domino runtime so calls can be made to the Notes API
	NotesInitExtended(0, NULL);	

	// initialize a critical section (Win32) for thread synchronization
	InitializeCriticalSection(&g_csPool);

	// fill in FilterInitData structure and register for event notifications
	strcpy(pInitData->filterDesc, FILTER_NAME);
	pInitData->appFilterVersion = kInterfaceVersion;
	pInitData->eventFlags = kFilterRawRequest | 
							kFilterResponse |
							kFilterEndRequest;

	// retrieve the release version number of Domino for including in log
	StatTraverse(STATPKG_SERVER, "Version.Notes", GetStat, (void *)&hCompound);

	// initialize globally-defined log buffer that will act as a cache
	g_szLogBuf[0]='\0';

	// log the startup event in the Notes Log (LOG.NSF) and server console
	LogEventText("DSAPI Filter: %s loaded.", 0, 0, FILTER_NAME);
  
	return kFilterHandledEvent;
}


/*---
* HttpFilterProc() - Required filter entry point. Dispatches the event notifications to 
*   the appropriate functions for handling the events.
*/
DLLEXPORT DWORD HttpFilterProc(FilterContext *pContext, DWORD dwEventType, void *pEventData)
{
	switch (dwEventType) {
		case kFilterRawRequest:	
			return RawRequest(pContext, pEventData);

		case kFilterResponse:
			return Response(pContext, pEventData);
			
		case kFilterEndRequest:	
			return EndRequest(pContext, pEventData);
	}

	return kFilterNotHandled;
}


/*---
* TerminateFilter() - Filter entry point. Called when HTTP server task is
*   stopped, or upon startup after "tell http restart" entered at server console.
*/
DLLEXPORT DWORD TerminateFilter(DWORD dwReserved)
{
	// flush any remaining data in the log buffer to disk
	if(strlen(g_szLogBuf) > 0)
		WriteLogBuffer("", 1);
	
	// log the terminate event in the Notes Log (LOG.NSF) and server console
	LogEventText("DSAPI Filter: %s unloaded.", 0, 0, FILTER_NAME);

	// delete the critical section (Win32) initialized by FilterInit()
	DeleteCriticalSection(&g_csPool);

	// shut down Domino runtime (started by FilterInit())
	NotesTerm();

	return kFilterHandledEvent;
}


/*---
* RawRequest() - Called when Domino has just received an HTTP request from the client.
*/
DWORD RawRequest(FilterContext *pContext, FilterRawRequest *pRequestData)
{
	LOGDATA *ld;
	TIMEDATE tdFilterStart;
	DWORD dwError;
	char szCookieBuf[1024];

	// capture current date/time for calculating time taken to complete request
	OSCurrentTIMEDATE(&tdFilterStart);

	// allocate a thread-local block of memory to hold LOGDATA structure
	ld=pContext->privateContext=pContext->AllocMem(pContext, sizeof(LOGDATA), 0, &dwError);
	pRequestData->GetHeader(pContext, "Cookie", szCookieBuf, sizeof(szCookieBuf)-1, &dwError);
	strcpy(ld->szCookie, szCookieBuf);
	ld->tdRequest=tdFilterStart;

	// copy struct to FilterContext for future reference by other events
	pContext->privateContext=(LOGDATA *)ld;

	return kFilterHandledEvent;
}


/*---
* Response() - Called after Domino has generated the HTML, but has not sent
*   the response back to the client.
*/
DWORD Response(FilterContext *pContext, FilterResponse *pResponseData)
{
	LOGDATA *ld;
	
	// get reference to LOGDATA structure and copy response code to it
	ld=(LOGDATA *)pContext->privateContext;	
	ld->dwResponseCode=pResponseData->responseCode;
	
	return kFilterHandledEvent;
}


/*---
* EndRequest() - Called after Domino has sent the response to the client. Builds an entry string
*   that conforms to the W3C Extended Log File Format and gets appended to the log file.
*/
DWORD EndRequest(FilterContext *pContext, FilterParsedRequest *pParsedData)
{
	FilterRequest Request;
	TIMEDATE tdStart, tdEnd;
	TIME NotesTime;
	DWORD dwStart, dwEnd, dwError;
	LOGDATA *ld;
	int iPos=0;
	char szLogEntry[MAX_ENTRY_LEN];
	char szBuf[MAX_INFO_LEN];
	char szContentLen[10];

	OSCurrentTIMEDATE(&tdEnd);

	// allocate a FilterRequest struct & fill in with request data
	pContext->GetRequest(pContext, &Request, &dwError);

	// retrieve thread-local LOGDATA structure allocated in RawRequest() 
	ld=(LOGDATA *)pContext->privateContext; 	

	// add "time" (request time in GMT) field to entry
	GetGMTime(&NotesTime);
	iPos=sprintf(szLogEntry, "%02d:%02d:%02d", NotesTime.hour, NotesTime.minute, NotesTime.second); 	
	
	// add "c-ip" (client ip address) field to entry
	pContext->GetServerVariable(pContext, "remote_addr", szBuf, MAX_INFO_LEN, &dwError);
	iPos+=sprintf(szLogEntry + iPos, " %s", szBuf);

	// add "cs-username" (remote user) field to entry, replacing spaces with "+"
	pContext->GetServerVariable(pContext, "remote_user", szBuf, MAX_INFO_LEN, &dwError);
	ReplaceString(szBuf, '+', ' ');
	iPos+=sprintf(szLogEntry + iPos, " %s", strlen(szBuf) > 0 ?	szBuf : "-");	

	// add "s-ip" (server ip address or hostname) field to entry
	pContext->GetServerVariable(pContext, "server_name", szBuf, MAX_INFO_LEN, &dwError);
	iPos+=sprintf(szLogEntry + iPos, " %s", szBuf);
	
	// add "cs-method" (request method) field to entry
	pContext->GetServerVariable(pContext, "request_method", szBuf, MAX_INFO_LEN, &dwError);
	iPos+=sprintf(szLogEntry + iPos, " %s", szBuf);
	
	// add "cs-uri" (full uri; stem + query) field to entry
	iPos+=sprintf(szLogEntry + iPos, " %s", Request.URL);
	
	// add "sc-status" (response code) field to entry
	iPos+=sprintf(szLogEntry + iPos, " %u", ld->dwResponseCode);	
	
	// add "cs-bytes" (request content length) field to entry
	itoa(Request.contentReadLen, szContentLen, 10);
	iPos+=sprintf(szLogEntry + iPos, " %s", Request.contentReadLen > 0 ? szContentLen : "-");
	
	// add "time-taken" (total time of request) field to entry
	tdStart=ld->tdRequest;
	dwStart=TimeExtractTicks(&tdStart);
	dwEnd=TimeExtractTicks(&tdEnd);
	iPos+=sprintf(szLogEntry + iPos, " %u", (dwEnd-dwStart)*10);
	
	// add "s-port" (http server port) field to entry
	pContext->GetServerVariable(pContext, "server_port", szBuf, MAX_INFO_LEN, &dwError);
	iPos+=sprintf(szLogEntry + iPos, " %s", szBuf);

	// add "cs-version" (http version) field to entry
	iPos+=sprintf(szLogEntry + iPos, " %s", Request.version);
	
	// add "cs(User-Agent)" (client browser) field, replacing spaces with "+"
	pContext->GetServerVariable(pContext, "http_user_agent", szBuf, MAX_INFO_LEN, &dwError);
	ReplaceString(szBuf, '+', ' ');
	iPos+=sprintf(szLogEntry + iPos, " %s", szBuf);

	// add "cs(Cookie)" (server-bound cookies) field , replacing spaces with "+"
	strcpy(szBuf, ld->szCookie);
	ReplaceString(szBuf, '+', ' ');
	iPos+=sprintf(szLogEntry + iPos, " %s", strlen(szBuf) > 0 ? szBuf : "-");	

	// add "cs(Referer)" (referring uri) field to entry
	pContext->GetServerVariable(pContext, "http_referer", szBuf, MAX_INFO_LEN, &dwError);
	iPos+=sprintf(szLogEntry + iPos, " %s\r\n", strlen(szBuf) > 0 ? szBuf : "-");	

	// write entry to in-memory buffer
	WriteLogBuffer(szLogEntry, 0);
		
	return kFilterHandledEvent; 
}


/*---
* WriteLogBuffer() - Called by EndRequest(). Logs a single HTTP request to the log file buffer. If 
*   max size of buffer is reached, flush the buffer to the log file.
*/
void WriteLogBuffer(char *pszLogEntry, unsigned int bFilterEnd)
{
	FILE *pStream;
	char szFilePath[MAXPATH+16];
	char szHeaderInfo[512];
	int nLen=0;

	// assume ownership of critical section. this will keep other
	// threads waiting until the owner signals it is done 
	EnterCriticalSection(&g_csPool);	

	BuildLogFileName(szFilePath);
	pStream=fopen(szFilePath, "r+");

	// if there is no log file for current date, create one
	// and write a header with directives to it. 
	if(pStream == NULL) {			
		pStream=fopen(szFilePath, "w");
		BuildLogHeader(szHeaderInfo);
		fprintf(pStream, "%s", szHeaderInfo);
	}

	// check if there's enough room in the buffer to hold the new entry.
	// if not, or if the filter is terminating, flush the contents of
	// the buffer to the log file.
	nLen=strlen(g_szLogBuf) + strlen(pszLogEntry) + 1;

	if((nLen > MAX_BUFFER_LEN) || (bFilterEnd)) {
		fseek(pStream, 0, SEEK_END);
	
		if(!bFilterEnd) {
			fprintf(pStream, "%s%s", g_szLogBuf, pszLogEntry);	
			g_szLogBuf[0]='\0';
		} else
			fprintf(pStream, "%s", g_szLogBuf);  
	} else
		strcat(g_szLogBuf, pszLogEntry);

	fclose(pStream);

	// release ownership of critical section
	LeaveCriticalSection(&g_csPool); 	
}


/*---
* BuildLogFileName() - Called by WriteLogBuffer() to build a log file name based on the 
*   current day (GM time) in the format: <DominoDataDirectoryPath>\exYYYYMMDD.log.
*/
void BuildLogFileName(char *pszFilePath)
{
	char szDirBuf[MAXPATH];
	TIME NotesTime;

	OSGetDataDirectory(szDirBuf);
	GetGMTime(&NotesTime);
	sprintf(pszFilePath, "%s\\ex%d%02d%02d.log", szDirBuf, NotesTime.year, NotesTime.month, NotesTime.day);
}


/*---
* BuildLogHeader() - Called by WriteLogBuffer() to build the directive header portion of 
*   the log file in accordance to W3C Extended Log File Format.
*/
void BuildLogHeader(char *pszHeaderInfo)
{
	TIME NotesTime;
	int iPos;

	GetGMTime(&NotesTime);
	iPos=sprintf(pszHeaderInfo, "#Software: Lotus Domino Server %s\r\n", g_szVersionNotes);
	iPos+=sprintf(pszHeaderInfo + iPos, "#Version: 1.0\r\n");
	iPos+=sprintf(pszHeaderInfo + iPos, "#Date: %d-%02d-%02d %02d:%02d:%02d\r\n", NotesTime.year, NotesTime.month, NotesTime.day, NotesTime.hour, NotesTime.minute, NotesTime.second);
	iPos+=sprintf(pszHeaderInfo + iPos, "#Fields: time c-ip cs-username s-ip cs-method cs-uri sc-status cs-bytes time-taken s-port cs-version cs(User-Agent) cs(Cookie) cs(Referer)\r\n");
}

/*---
* GetGMTime() - Returns current GM time with adjustment for daylight savings.
*/
void GetGMTime(TIME *NotesTime)
{
	TIMEDATE TimeNow;
	int iZone, iDst;

	OSCurrentTIMEDATE(&TimeNow);
	OSCurrentTimeZone(&iZone, &iDst);
	TimeDateAdjust(&TimeNow, 0, 0, iZone - ((iDst) ? 1 : 0), 0, 0, 0);
	NotesTime->GM=TimeNow;
	TimeGMToLocal(NotesTime);
}

/*---
* GetStat() - Callback function for StatTraverse. Sets global var with Domino release version.
*/
STATUS LNCALLBACK GetStat(void *pContext, char *pszFacility, char *pszStatName, WORD wValueType, void *pValue)
{
	strcpy(g_szVersionNotes, (char *)pValue);
	return 0;
}

/*---
* ReplaceString() - Helper function that changes all occurences of one character in a string to another.
*/
void ReplaceString(char *pszArg, char cNew, char cOld)
{
	char *pcHold;
	int iLen;

	iLen=strlen(pszArg);

	while (iLen) {
		pcHold=memchr(pszArg, cOld, iLen);

		if(pcHold) {
			*pcHold=cNew;
			iLen-=(pcHold-pszArg);
			pszArg=pcHold+1;
		} else 
			break;
	}
}