Revision: 1.27, Wed Oct 6 18:50:29 2004 UTC (8 months, 3 weeks ago) by jgdavidson
Branch: MAIN
CVS Tags: HEAD
Changes since 1.26: +4 -1 lines
Ns_Fatal now calls abort() in debug mode.
/*
 * The contents of this file are subject to the AOLserver Public License
 * Version 1.1 (the "License"); you may not use this file except in
 * compliance with the License. You may obtain a copy of the License at
 * http://aolserver.com/.
 *
 * Software distributed under the License is distributed on an "AS IS"
 * basis, WITHOUT WARRANTY OF ANY KIND, either express or implied. See
 * the License for the specific language governing rights and limitations
 * under the License.
 *
 * The Original Code is AOLserver Code and related documentation
 * distributed by AOL.
 * 
 * The Initial Developer of the Original Code is America Online,
 * Inc. Portions created by AOL are Copyright (C) 1999 America Online,
 * Inc. All Rights Reserved.
 *
 * Alternatively, the contents of this file may be used under the terms
 * of the GNU General Public License (the "GPL"), in which case the
 * provisions of GPL are applicable instead of those above.  If you wish
 * to allow use of your version of this file only under the terms of the
 * GPL and not to allow others to use your version of this file under the
 * License, indicate your decision by deleting the provisions above and
 * replace them with the notice and other provisions required by the GPL.
 * If you do not delete the provisions above, a recipient may use your
 * version of this file under either the License or the GPL.
 */


/*
 * log.c --
 *
 *	Manage the server log file.
 */

static const char *RCSID = "@(#) $Header: /cvsroot/aolserver/aolserver/nsd/log.c,v 1.27 2004/10/06 18:50:29 jgdavidson Exp $, compiled: " __DATE__ " " __TIME__;

#include "nsd.h"

/*
 * The following struct maintains per-thread
 * cached formatted time strings and log buffers.
 */

typedef struct Cache {
    int		hold;
    int		count;
    time_t	gtime;
    time_t	ltime;
    char	gbuf[100];
    char	lbuf[100];
    Ns_DString  buffer;
} Cache;

/*
 * Local functions defined in this file
 */

static int    LogReOpen(void);
static void   Log(Ns_LogSeverity severity, char *fmt, va_list ap);
static Cache *LogGetCache(void);
static Ns_TlsCleanup LogFreeCache;
static void   LogFlush(Cache *cachePtr);
static char  *LogTime(Cache *cachePtr, int gmtoff, long *usecPtr);
static int    LogStart(Cache *cachePtr, Ns_LogSeverity severity);
static void   LogEnd(Cache *cachePtr);

/*
 * Static variables defined in this file
 */

static Ns_Tls tls;
static Ns_Mutex lock;
static Ns_LogFlushProc    *flushProcPtr;
static Ns_LogProc         *nslogProcPtr;


/*
 *----------------------------------------------------------------------
 *
 * NsInitLog --
 *
 *	Initialize the log API and TLS slot.
 *
 * Results:
 *	None.
 *
 * Side effects:
 *	None. 
 *
 *----------------------------------------------------------------------
 */

void
NsInitLog(void)
{
    Ns_MutexSetName(&lock, "ns:log");
    Ns_TlsAlloc(&tls, LogFreeCache);
    flushProcPtr = NULL;
    nslogProcPtr = NULL;
}


/*
 *----------------------------------------------------------------------
 *
 * Ns_InfoErrorLog --
 *
 *	Returns the filename of the log file. 
 *
 * Results:
 *	Log file name or NULL if none. 
 *
 * Side effects:
 *	None. 
 *
 *----------------------------------------------------------------------
 */

char *
Ns_InfoErrorLog(void)
{
    return nsconf.log.file;
}


/*
 *----------------------------------------------------------------------
 *
 * Ns_LogRoll --
 *
 *	Signal handler for SIG_HUP which will roll the files. Also a 
 *	tasty snack from Stuckey's. 
 *
 * Results:
 *	NS_OK/NS_ERROR 
 *
 * Side effects:
 *	Will rename the log file and reopen it. 
 *
 *----------------------------------------------------------------------
 */

int
Ns_LogRoll(void)
{
    if (nsconf.log.file != NULL) {
        if (access(nsconf.log.file, F_OK) == 0) {
            Ns_RollFile(nsconf.log.file, nsconf.log.maxback);
        }
        Ns_Log(Notice, "log: re-opening log file '%s'", nsconf.log.file);
        if (LogReOpen() != NS_OK) {
	    return NS_ERROR;
	}
    }
    return NS_OK;
}


/*
 *----------------------------------------------------------------------
 *
 * Ns_Log --
 *
 *	Spit a message out to the server log. 
 *
 * Results:
 *	None. 
 *
 * Side effects:
 *	None. 
 *
 *----------------------------------------------------------------------
 */

void
Ns_Log(Ns_LogSeverity severity, char *fmt, ...)
{
    va_list ap;

    va_start(ap, fmt);
    Log(severity, fmt, ap);
    va_end(ap);
}

/* NB: For binary compatibility with previous releases. */

void
ns_serverLog(Ns_LogSeverity severity, char *fmt, va_list *vaPtr)
{
    Log(severity, fmt, *vaPtr);
}


/*
 *----------------------------------------------------------------------
 *
 * Ns_Fatal --
 *
 *	Spit a message out to the server log with severity level of 
 *	Fatal, and then terminate the nsd process. 
 *
 * Results:
 *	None. 
 *
 * Side effects:
 *	WILL CAUSE AOLSERVER TO EXIT! 
 *
 *----------------------------------------------------------------------
 */

void
Ns_Fatal(char *fmt, ...)
{
    va_list ap;

    va_start(ap, fmt);
    Log(Fatal, fmt, ap);
    va_end(ap);
    if (nsconf.debug) {
	abort();
    }
    _exit(1);
}


/*
 *----------------------------------------------------------------------
 *
 * Ns_LogTime2, Ns_LogTime --
 *
 *	Copy a local or GMT date and time string useful for common log
 *	format enties (e.g., nslog).
 *
 * Results:
 *	Pointer to given buffer.
 *
 * Side effects:
 *	Will put data into timeBuf, which must be at least 41 bytes 
 *	long. 
 *
 *----------------------------------------------------------------------
 */

char *
Ns_LogTime2(char *timeBuf, int gmt)
{
    strcpy(timeBuf, LogTime(LogGetCache(), gmt, NULL));
    return timeBuf;
}

char *
Ns_LogTime(char *timeBuf)
{
    return Ns_LogTime2(timeBuf, 1);
}


/*
 *----------------------------------------------------------------------
 *
 * NsLogOpen --
 *
 *	Open the log file. Adjust configurable parameters, too. 
 *
 * Results:
 *	None. 
 *
 * Side effects:
 *	Configures this module to use the newly opened log file.
 *	If LogRoll is turned on in the config file, then it registers
 *	a signal callback.
 *
 *----------------------------------------------------------------------
 */

void
NsLogOpen(void)
{
    /*
     * Open the log and schedule the signal roll.
     */

    if (LogReOpen() != NS_OK) {
	Ns_Fatal("log: failed to open server log '%s': '%s'", 
		 nsconf.log.file, strerror(errno));
    }
    if (nsconf.log.flags & LOG_ROLL) {
	Ns_RegisterAtSignal((Ns_Callback *) Ns_LogRoll, NULL);
    }
}


/*
 *----------------------------------------------------------------------
 *
 * NsTclLogRollObjCmd --
 *
 *	Implements ns_logroll as obj command. 
 *
 * Results:
 *	Tcl result. 
 *
 * Side effects:
 *	See docs. 
 *
 *----------------------------------------------------------------------
 */

int
NsTclLogRollObjCmd(ClientData arg, Tcl_Interp *interp, int objc, Tcl_Obj *CONST objv[])
{
    if (Ns_LogRoll() != NS_OK) {
	Tcl_SetResult(interp, "could not roll server log", TCL_STATIC);
    }
    return TCL_OK;
}


/*
 *----------------------------------------------------------------------
 *
 * NsTclLogCtlObjCmd --
 *
 *	Implements ns_logctl command to manage log buffering
 *	and release.
 *
 * Results:
 *	Tcl result. 
 *
 * Side effects:
 *	See docs. 
 *
 *----------------------------------------------------------------------
 */

int
NsTclLogCtlObjCmd(ClientData arg, Tcl_Interp *interp, int objc,
	       Tcl_Obj *CONST objv[])
{
    int len;
    Cache *cachePtr;
    static CONST char *opts[] = {
	"hold",
	"count",
	"get",
	"peek",
	"flush",
	"release",
	"truncate",
	NULL
    };
    enum {
	CHoldIdx,
	CCountIdx,
	CGetIdx,
	CPeekIdx,
	CFlushIdx,
	CReleaseIdx,
	CTruncIdx
    } opt;

    if (objc < 2) {
        Tcl_WrongNumArgs(interp, 1, objv, "option ?arg?");
    	return TCL_ERROR;
    }
    if (Tcl_GetIndexFromObj(interp, objv[1], opts, "option", 0,
			    (int *) &opt) != TCL_OK) {
	return TCL_ERROR;
    }
    cachePtr = LogGetCache();
    switch (opt) {
    case CHoldIdx:
	cachePtr->hold = 1;
	break;

    case CPeekIdx:
	Tcl_SetResult(interp, cachePtr->buffer.string, TCL_VOLATILE);
	break;

    case CGetIdx:
	Tcl_SetResult(interp, cachePtr->buffer.string, TCL_VOLATILE);
	Ns_DStringFree(&cachePtr->buffer);
        cachePtr->count = 0;
	break;

    case CReleaseIdx:
	cachePtr->hold = 0;
	/* FALLTHROUGH */

    case CFlushIdx:
	LogFlush(cachePtr);
        cachePtr->count = 0;
	break;

    case CCountIdx:
	Tcl_SetIntObj(Tcl_GetObjResult(interp), cachePtr->count);
	break;

    case CTruncIdx:
	len = 0;
	if (objc > 2 && Tcl_GetIntFromObj(interp, objv[2], &len) != TCL_OK) {
	    return TCL_ERROR;
	}
	Ns_DStringTrunc(&cachePtr->buffer, len);
	break;
    }
    return TCL_OK;
}


/*
 *----------------------------------------------------------------------
 *
 * NsTclLogObjCmd --
 *
 *	Implements ns_log as obj command.
 *
 * Results:
 *	Tcl result. 
 *
 * Side effects:
 *	See docs. 
 *
 *----------------------------------------------------------------------
 */

int
NsTclLogObjCmd(ClientData arg, Tcl_Interp *interp, int objc,
	       Tcl_Obj *CONST objv[])
{
    Ns_LogSeverity severity;
    Cache *cachePtr;
    char *severitystr;
    int i;
    Ns_DString ds;

    if (objc < 3) {
        Tcl_WrongNumArgs(interp, 1, objv, "severity string ?string ...?");
    	return TCL_ERROR;
    }
    severitystr = Tcl_GetString(objv[1]);
    cachePtr = LogGetCache();
    if (STRIEQ(severitystr, "notice")) {
	severity = Notice;
    } else if (STRIEQ(severitystr, "warning")) {
	severity = Warning;
    } else if (STRIEQ(severitystr, "error")) {
	severity = Error;
    } else if (STRIEQ(severitystr, "fatal")) {
	severity = Fatal;
    } else if (STRIEQ(severitystr, "bug")) {
	severity = Bug;
    } else if (STRIEQ(severitystr, "debug")) {
	severity = Debug;
    } else if (Tcl_GetIntFromObj(NULL, objv[1], &i) == TCL_OK) {
	severity = i;
    } else {
	Tcl_AppendResult(interp, "unknown severity: \"", severitystr,
	    "\": should be notice, warning, error, "
	    "fatal, bug, debug or integer value", NULL);
	return TCL_ERROR;
    }

    Ns_DStringInit(&ds);

    for (i = 2; i < objc; ++i) {
	Ns_DStringVarAppend(&ds,
	Tcl_GetString(objv[i]), i < (objc-1) ? " " : NULL, NULL);
    }

    Ns_Log(severity, "%s", ds.string);
    Ns_DStringFree(&ds);

    return TCL_OK;
}


/*
 *----------------------------------------------------------------------
 *
 * Log --
 *
 *	Add an entry to the log file if the severity is not surpressed.
 *	Or call a custom log procedure and let that worry about the
 *	severity.
 *
 * Results:
 *	None. 
 *
 * Side effects:
 *	May write immediately or later through buffer.
 *
 *----------------------------------------------------------------------
 */

static void
Log(Ns_LogSeverity severity, char *fmt, va_list ap)
{
    Cache *cachePtr;

    cachePtr = LogGetCache();
    if (nslogProcPtr == NULL) {
	if (LogStart(cachePtr, severity)) {
	    Ns_DStringVPrintf(&cachePtr->buffer, fmt, ap);
	    LogEnd(cachePtr);
	}
    } else {
	(*nslogProcPtr)(&cachePtr->buffer, severity, fmt, ap);
	++cachePtr->count;
	if (!cachePtr->hold) {
	    LogFlush(cachePtr);
	}
    }
}


/*
 *----------------------------------------------------------------------
 *
 * LogStart --
 *
 *	Start a log entry.
 *
 * Results:
 *	1 if log started and should be written, 0 if given severity
 *	is surpressed.
 *
 * Side effects:
 *	May append log header to given dstring.
 *
 *----------------------------------------------------------------------
 */

static int
LogStart(Cache *cachePtr, Ns_LogSeverity severity)
{
    char *severityStr, buf[10];
    long usec;

    switch (severity) {
	case Notice:
	    if (nsconf.log.flags & LOG_NONOTICE) {
		return 0;
	    }
	    severityStr = "Notice";
	    break;
        case Warning:
	    severityStr = "Warning";
	    break;
	case Error:
	    severityStr = "Error";
	    break;
	case Fatal:
	    severityStr = "Fatal";
	    break;
	case Bug:
	    severityStr = "Bug";
	    break;
	case Debug:
	    if (!(nsconf.log.flags & LOG_DEBUG)) {
		return 0;
	    }
	    severityStr = "Debug";
	    break;
	case Dev:
	    if (!(nsconf.log.flags & LOG_DEV)) {
		return 0;
	    }
	    severityStr = "Dev";
	    break;
	default:
	    if (severity > nsconf.log.maxlevel) {
		return 0;
	    }
	    sprintf(buf, "Level%d", severity);
	    severityStr = buf;
	    break;
    }
    Ns_DStringAppend(&cachePtr->buffer, LogTime(cachePtr, 0, &usec));
    if (nsconf.log.flags & LOG_USEC) {
    	Ns_DStringTrunc(&cachePtr->buffer, cachePtr->buffer.length-1);
	Ns_DStringPrintf(&cachePtr->buffer, ".%ld]", usec);
    }
    Ns_DStringPrintf(&cachePtr->buffer, "[%d.%lu][%s] %s: ",
	Ns_InfoPid(), (unsigned long) Ns_ThreadId(), Ns_ThreadGetName(), severityStr);
    if (nsconf.log.flags & LOG_EXPAND) {
	Ns_DStringAppend(&cachePtr->buffer, "\n    ");
    }
    return 1;
}


/*
 *----------------------------------------------------------------------
 *
 * LogEnd --
 *
 *	Complete a log entry and flush if necessary.
 *
 * Results:
 *	None.
 *
 * Side effects:
 *	May write to log.
 *
 *----------------------------------------------------------------------
 */

static void
LogEnd(Cache *cachePtr)
{
    Ns_DStringNAppend(&cachePtr->buffer, "\n", 1);
    if (nsconf.log.flags & LOG_EXPAND) {
	Ns_DStringNAppend(&cachePtr->buffer, "\n", 1);
    }
    ++cachePtr->count;
    if (!cachePtr->hold) {
    	LogFlush(cachePtr);
    }
}


/*
 *----------------------------------------------------------------------
 *
 * LogFlush --
 *
 *	Flush per-thread log entries to buffer or open file.
 *
 * Results:
 *	None.
 *
 * Side effects:
 *	None.
 *
 *----------------------------------------------------------------------
 */

static void
LogFlush(Cache *cachePtr)
{
    Ns_DString *dsPtr = &cachePtr->buffer;

    Ns_MutexLock(&lock);
    if (flushProcPtr == NULL) {
	(void) write(2, dsPtr->string, (size_t)dsPtr->length);
    } else {
	(*flushProcPtr)(dsPtr->string, (size_t)dsPtr->length);
    }
    Ns_MutexUnlock(&lock);
    Ns_DStringFree(dsPtr);
    cachePtr->count = 0;
}


/*
 *----------------------------------------------------------------------
 *
 * LogReOpen --
 *
 *	Open the log file name specified in the 'logFile' global. If 
 *	it's successfully opened, make that file the sink for stdout 
 *	and stderr too. 
 *
 * Results:
 *	NS_OK/NS_ERROR 
 *
 * Side effects:
 *	None. 
 *
 *----------------------------------------------------------------------
 */

static int
LogReOpen(void)
{
    int fd; 
    int status;

    status = NS_OK;
    fd = open(nsconf.log.file, O_WRONLY|O_APPEND|O_CREAT, 0644);
    if (fd < 0) {
        Ns_Log(Error, "log: failed to re-open log file '%s': '%s'",
	       nsconf.log.file, strerror(errno));
        status = NS_ERROR;
    } else {
	/*
	 * Route stderr to the file
	 */
	
        if (fd != STDERR_FILENO && dup2(fd, STDERR_FILENO) == -1) {
            fprintf(stdout, "dup2(%s, STDERR_FILENO) failed: %s\n",
		nsconf.log.file, strerror(errno));
            status = NS_ERROR;
        }
	
	/*
	 * Route stdout to the file
	 */
	
        if (dup2(STDERR_FILENO, STDOUT_FILENO) == -1) {
            Ns_Log(Error, "log: failed to route stdout to file: '%s'",
		   strerror(errno));
            status = NS_ERROR;
        }
	
	/*
	 * Clean up dangling 'open' reference to the fd
	 */
	
        if (fd != STDERR_FILENO && fd != STDOUT_FILENO) {
            close(fd);
        }
    }
    return status;
}


/*
 *----------------------------------------------------------------------
 *
 * LogTime --
 *
 *	Get formatted local or gmt log time from per-thread cache.
 *
 * Results:
 *	Pointer to per-thread buffer.
 *
 * Side effects:
 *	Given usecPtr updated with current microseconds.
 *
 *----------------------------------------------------------------------
 */

static char *
LogTime(Cache *cachePtr, int gmtoff, long *usecPtr)
{
    time_t   *tp;
    struct tm *ptm;
    int gmtoffset, n, sign;
    char *bp;
    Ns_Time now;

    if (gmtoff) {
	tp = &cachePtr->gtime;
	bp = cachePtr->gbuf;
    } else {
	tp = &cachePtr->ltime;
	bp = cachePtr->lbuf;
    }
    Ns_GetTime(&now);
    if (*tp != now.sec) {
	*tp = now.sec;
	ptm = ns_localtime(&now.sec);
	n = strftime(bp, 32, "[%d/%b/%Y:%H:%M:%S", ptm);
	if (!gmtoff) {
	    bp[n++] = ']';
	    bp[n] = '\0';
	} else {
#ifdef HAVE_TM_GMTOFF
	    gmtoffset = ptm->tm_gmtoff / 60;
#else
	    gmtoffset = -timezone / 60;
	    if (daylight && ptm->tm_isdst) {
		gmtoffset += 60;
	    }
#endif
	    if (gmtoffset < 0) {
		sign = '-';
		gmtoffset *= -1;
	    } else {
		sign = '+';
	    }
	    sprintf(bp + n, 
		    " %c%02d%02d]", sign, gmtoffset / 60, gmtoffset % 60);
	}
    }
    if (usecPtr != NULL) {
	*usecPtr = now.usec;
    }
    return bp;
}


/*
 *----------------------------------------------------------------------
 *
 * LogGetCache --
 *
 *	Get the per-thread Cache struct.
 *
 * Results:
 *	Pointer to per-thread struct.
 *
 * Side effects:
 *	None.
 *
 *----------------------------------------------------------------------
 */

static Cache *
LogGetCache(void)
{
    Cache *cachePtr;

    cachePtr = Ns_TlsGet(&tls);
    if (cachePtr == NULL) {
	cachePtr = ns_calloc(1, sizeof(Cache));
	Ns_DStringInit(&cachePtr->buffer);
	Ns_TlsSet(&tls, cachePtr);
    }
    return cachePtr;
}


/*
 *----------------------------------------------------------------------
 *
 * LogFreeCache --
 *
 *	TLS cleanup callback to destory per-thread Cache struct.
 *
 * Results:
 *	None.
 *
 * Side effects:
 *	None.
 *
 *----------------------------------------------------------------------
 */

static void
LogFreeCache(void *arg)
{
    Cache *cachePtr = arg;

    LogFlush(cachePtr);
    Ns_DStringFree(&cachePtr->buffer);
    ns_free(cachePtr);
}


/*
 *----------------------------------------------------------------------
 *      
 * Ns_SetLogFlushProc --
 * 
 *	Set the proc to call when writing the log. You probably want
 *	to have a Ns_RegisterAtShutdown() call too so you can
 *	close/finish up whatever special logging you are doing.
 *
 * Results:
 *	None.
 *
 * Side effects:
 *	None.
 *
 *----------------------------------------------------------------------
 */ 
    
void
Ns_SetLogFlushProc(Ns_LogFlushProc *procPtr)
{
    flushProcPtr = procPtr;
}


/*
 *----------------------------------------------------------------------
 *
 * Ns_SetNsLogProc --
 *
 *	Set the proc to call when adding a log entry.
 *
 *	There are 2 ways to use this override:
 *
 *	1. In conjunction with the Ns_SetLogFlushProc() to use the
 *	   existing AOLserver buffering and writing system. So when a
 *	   log message is added it is inserted into the log cache and
 *	   flushed later through your log flush override. To use this
 *	   write any logging data to the Ns_DString that is passed into
 *	   the Ns_Log proc.
 *	2. Without calling Ns_SetLogFlushProc() and handle all buffering
 *	   and writing directly. LogFlush() will be called as normal but
 *	   is a no-op because nothing will have been added. Do not write
 *	   into the Ns_DString passed into the Ns_Log proc in this case.
 *
 * Results:
 *	None.
 *
 * Side effects:
 *	None.
 * 
 *----------------------------------------------------------------------
 */     
 
void    
Ns_SetNsLogProc(Ns_LogProc *procPtr)
{
    nslogProcPtr = procPtr;
}

Back to SourceForge.net

Powered by ViewCVS 1.0-dev