/* This module provides log output for the http server.
 *
 * The output may be routed to any of three files:
 *     Error log
 *     Access log
 *     Trace log
 *
 * This module provides output to an application log file.  It formats
 * data via SYS$FAO to facilitate putting timestamps in the control strings.
 *
 *  int tlog_init ( char *log_file_name );
 *  int tlog_initlog ( int level, char * fname );	! type 1 
 *  int tlog_putlog ( int level, char *ctlstr, ... );
 *  int tlog_flush;
 *  int tlog_reopen ( level );
 *  int tlog_rundown();
 *
 * Author:	David Jones
 * Revised:	27-AUG-1994		Added tlog_reopen().
 * Revised:      3-NOV-1994		Added tlog_rundown().
 * Revised:	3-MAR-1995		Use pthreads timing for flushing, add
 *					structure for daily rollover of files.
 * Revised:	20-MAY-1995		Update for OSF.
 * Revised:	5-SEP-1995		Bug fix, set trc_valid in tlog_initlog
 * Revised:	18-OCT-1995		Support multiple access logs.
 * Revised:	10-NOV-1995		Do selective flush of access logs.
 * Revised:	 1-MAR-1996		Cleanup status check for V7 decthreads
 * Revised:	6-JAN-1996		Fix for DEC C 5.5 eliminating fileno
 *					macro.
 * Revised:	11-MAR-1997		Avoid multiple opens of same access log.
 * Revised:	9-DEC-1998		Avoid stack_reports if level not set.
 * Revsied:	22-APR-1999		Tweak for Digital Unix.
 * Revsied:	29-APR-1999		Add exception handler for clean
 *					rundown.
 * Revised:	29-SEP-1999		Enusure shr=put always used in
 *					combination with ctx=rec.
 * Revised:	11-JAN-2000		Support object naming.
 */
#ifndef VMS
/* fixup for newer va_list def */
#define _a0 a0
#define _offset offset
#endif
#include <stdio.h>
#include "pthread_1c_np.h"
#include <stdarg.h>
#include <stdlib.h>
#ifdef VMS
#include <descrip.h>
#include <ssdef.h>
#define VMS_ARG(a) ,a
#define VMS_ARG2(a)
#else
#define SYS$FAOL SYS_FAOL
struct dsc$descriptor {
    short int dsc$w_length;
    unsigned char dsc$b_dtype, dsc$b_class;
    void *dsc$a_pointer;
};
#define DSC$K_DTYPE_T 0
#define DSC$K_CLASS_S 0
#define VMS_ARG(a)
#define VMS_ARG2(a)
#endif
#include <string.h>
#include <errno.h>
#include <time.h>

static FILE *log_file;			/* error messages (type 0) */
static FILE *acc_deffile[] = { (FILE *) 0 };
static FILE **acc_file = acc_deffile;	/* access log (type -1) */
static FILE *trc_file;			/* trace file */
static int log_valid = 0;
static int acc_alloc = 0;		/* size of allocated acc_file arrays */
static int acc_maxvalid = 0;		/* size of acc_valid array -1 */
static int acc_defvalid[] = {0};
static int acc_defdirty[] = {0};
static int *acc_valid = acc_defvalid;
static int *acc_dirty = acc_defdirty;
static int trc_valid = 0;
static int trace_level = 0;
static int stack_trace_level = 0;
static int (*stack_report)();		/* callback */
static struct dsc$descriptor control;	/* control string */
static struct dsc$descriptor output;	/* control string */
static char log_file_spec[256];
static char **acc_file_spec;
static char acc_deffilespec[256];
static char trc_file_spec[256];
static pthread_mutex_t log_write;
static pthread_cond_t log_modified;
static pthread_t flusher_id;		/* thread id of flusher thread */
static int flush_pending;		/* -1-starting, 0-idle, 1-pending */
int http_log_level;
#define FLUSH_INTERVAL 60

/*
 * Work around problems with fsync() not being ANSI standard 
 */
#ifdef __DECC
#ifdef VMS
#ifndef fileno
#ifdef fileno_macro_fixup
#define fileno(stream) ((*(stream))->_file)
#else
#define fileno decc$fileno
int decc$fileno(FILE *fp);
#endif
#endif
#ifndef fsync
#define fsync decc$fsync
int decc$fsync(int fd);
#endif
#endif
#else	/* __DECC */
int fsync();
#endif
static int null_report() { return -1; }
/****************************************************************************/
/* Define start routine for thread that flushes log files to disk peiodically
 * as well as takes action every midnight.
 */
static int tlog_new_day();
static int tlog_flusher ( char * fname )
{
    int status, new_day, i;
    struct timespec delta, abstime, midnight;
    /*
     * Any time this routine executes, we will have the log_write mutex.
     * (mutex is relesed while waiting). Make initial call to new_day
     * routine to get absolute time of first midnight.
     *
     * Set up TRY block to ensure mutex released should rundown function
     * cancel us.
     */
    pthread_mutex_lock ( &log_write );
    TRY {
    SET_THREAD_NAME(pthread_self(),"OSU Log Flusher")
    new_day = 0;
    tlog_new_day ( new_day, &midnight );
    /*
     * Main loop,
     */
    for ( ; ; ) {
        /*
         *  Wait for someone (anyone, even spurious) to signal us.
         */
	flush_pending = 0;
	status = pthread_cond_timedwait (&log_modified, &log_write, &midnight);
	/*
	 * Compute 1 minute from now and do timed wait.  Set flush_pending
	 * to 1 to inhibit any more signals from other threads.
	 * We ignore any other signals that show up.
	 */
	flush_pending = 1;
        delta.tv_sec = FLUSH_INTERVAL;
        delta.tv_nsec = 0;
	if ( 0 == pthread_get_expiration_np ( &delta, &abstime ) ) {
	    /* Don't wait past midnight */
	    if ( abstime.tv_sec >= midnight.tv_sec ) {
		abstime = midnight;
		new_day = 1;
	    }
	    while ( 0 == pthread_cond_timedwait ( &log_modified,
		&log_write, &abstime ) );
	}
	/*
	 * We get to this point either because it is midnight (new day) or
	 * the 1 minute flush interval after a write has expired.
	 */
	if ( !new_day ) {
	    /*
	     * Wait for tlog_flush() to release us, then flush.  By waiting 
	     * for the next call to tlog_flush the disk writes are deferred 
	     * until the server is at a quieter point.
	     */
	    for ( flush_pending = 2; flush_pending == 2; ) {
		status = pthread_cond_timedwait 
			( &log_modified, &log_write, &midnight );
		if ( status != 0 ) {
		    /* We turned into a pumpkin */
		    new_day = 1;
		    break;
		}
	    }
            if ( log_valid ) {
	        LOCK_C_RTL
	        fflush ( log_file ); status = fsync ( fileno(log_file) );
	        UNLOCK_C_RTL
	    }
	    for ( i = acc_maxvalid; i >= 0; i-- ) if ( acc_valid[i] < 0 ) {
		/* propagate dirty flag up to parent. */
		if ( acc_dirty[i] ) {
		    acc_dirty[i] = 0;
		    acc_dirty[-1-acc_valid[i]] = 1;
		}
	    }
            for ( i = 0; i <= acc_maxvalid; i++ ) if ( acc_valid[i] &&
			acc_dirty[i] ) {
	        LOCK_C_RTL
	        fflush ( acc_file[i] ); status = fsync ( fileno(acc_file[i]) );
	        UNLOCK_C_RTL
		acc_dirty[i] = 0;
	    }
            if ( trc_valid ) {
	        LOCK_C_RTL
	        fflush ( trc_file ); status = fsync ( fileno(trc_file) );
	        UNLOCK_C_RTL
	    }
	}
	if ( new_day ) {
	    /*
	     * Mark flush state as 'new day' and call routine to do
	     * start-of-day process.  This routine must update midnight.
	     */
	    flush_pending = 3;
	    tlog_new_day ( new_day, &midnight );
	    new_day = 0;
	}
    }
    /*
     * Code that will always execute.
     */
    }
    FINALLY {
	pthread_mutex_unlock ( &log_write );
    }
    ENDTRY
    return 0;		/* can't really get here */
}
/*****************************************************************************/
static int tlog_new_day ( int new_day, struct timespec *midnight )
{
    time_t bintim;
    struct tm now;
    struct timespec delta;
    /*
     * If we want to roll over log files, do it here while we still
     * have log_write mutex.
     */
    pthread_mutex_unlock ( &log_write );
    /*
     * Reset for next midnight.
     */
    pthread_lock_global_np();		/* localtime() not reentrant */
    time ( &bintim );
    now = *(localtime(&bintim));
    pthread_unlock_global_np();
    delta.tv_sec = 86400-(((now.tm_hour*60)+now.tm_min)*60+now.tm_sec);
    delta.tv_nsec = 0;
    pthread_get_expiration_np ( &delta, midnight );
    pthread_mutex_lock ( &log_write );
    return 0;
}
/*****************************************************************************/
/* Expand acc arrays to accomodate indicated level (negative number). 
 * Search existing array for matching fname and clone file pointer into
 * slot and sent acc_valid[] entry to matching level number.
 */
static int tlog_alloc_acc_array ( int level, char *fname ) {

    int size, alloc, i;
    size = 0 - level;
    if ( size <= 0 ) return 20;		/* bad parameter */
    if ( acc_alloc == 0 ) {
	/*
	 * First call, make initial allocation.
	 */
	acc_alloc = 8;
	while ( acc_alloc < size ) acc_alloc = acc_alloc * 2;
	acc_valid = (int *) malloc ( acc_alloc * sizeof(int) );
	acc_dirty = (int *) malloc ( acc_alloc * sizeof(int) );
	acc_file = (FILE **) malloc ( acc_alloc * sizeof(FILE *) );
	acc_file_spec = (char **) malloc ( acc_alloc * sizeof(char *) );
	for ( i = 0; i < acc_alloc; i ++ ) {
	    acc_valid[i] = acc_dirty[i] = 0;
	    acc_file[i] = (FILE *) 0;
	    acc_file_spec[i] = (char *) 0;
	}
	acc_valid[0] = acc_defvalid[0];
	acc_file[0] = acc_deffile[0];
	acc_file_spec[0] = acc_deffilespec;
    }
    if ( acc_alloc < size ) {
	/*
	 * Realloc the arrays.
	 */
	for ( alloc = acc_alloc * 2; alloc < size; alloc = alloc * 2 );
	acc_valid = realloc ( acc_valid, alloc * sizeof(int) );
	acc_dirty = realloc ( acc_dirty, alloc * sizeof(int) );
	acc_file = realloc ( acc_file, alloc * sizeof(FILE *) );
	acc_file_spec = realloc ( acc_file_spec, alloc * sizeof(char *) );
	/*
	 * Zero extended portion.
	 */
	while ( acc_alloc < alloc ) {
	    acc_valid[acc_alloc] = acc_dirty[acc_alloc] = 0;
	    acc_file[acc_alloc] = (FILE *) 0;
	    acc_file_spec[acc_alloc] = (char *) 0;
	    acc_alloc++;
	}
    }
    if ( acc_file_spec[-1-level] == (char *) 0 ) {
	/*
	 * Allocate new buffer and copy name (truncate);
	 */
	acc_file_spec[-1-level] = (char *) malloc ( 256 );
	strncpy ( acc_file_spec[-1-level], fname, 255 );
	acc_file_spec[-1-level][255] = '\0';
	/*
	 * Search for matching fname and clone file pointer if found.
	 */
	for ( i = -2-level; i >= 0; i-- ) if ( acc_file_spec[i] ) {
	    if ( strncmp ( acc_file_spec[i], 
			acc_file_spec[-1-level], 255 )	== 0 ) {
		acc_file[-1-level] = acc_file[i];
		acc_valid[-1-level] = -1-i;
		if ( (-1-level) > acc_maxvalid ) acc_maxvalid = (-1-level);
		break;
	    }
	}
    }
    return 1;
}
/*****************************************************************************/
int tlog_init ( char *log_file_name )
{
    int status, pthread_create();
    if ( log_valid ) return 3;
    log_file = fopen ( log_file_name, "w"
	VMS_ARG2("dna=.log") VMS_ARG("alq=100") VMS_ARG("deq=600")
	VMS_ARG("rfm=var") VMS_ARG("mrs=300") VMS_ARG("ctx=rec") 
	VMS_ARG("shr=upd") );
    strcpy ( log_file_spec, log_file_name );
    if ( log_file ) log_valid = 1;
    if ( !log_valid ) perror ( "Can't open log file" );
    /*
     * initialize static fields in descriptors.
     */
    control.dsc$b_dtype = DSC$K_DTYPE_T;
    control.dsc$b_class = DSC$K_CLASS_S;
    output.dsc$b_dtype = DSC$K_DTYPE_T;
    output.dsc$b_class = DSC$K_CLASS_S;
    /*
     * Initialize mutexes and conditions.
     */
    INITIALIZE_MUTEX ( &log_write );
    SET_MUTEX_NAME(&log_write,"OSU log write")
    INITIALIZE_CONDITION ( &log_modified );
    SET_COND_NAME(&log_modified,"OSU log modified")
    if ( stack_trace_level == 0 ) {
	stack_trace_level = -1;		/* http_log_level is never zero */
	stack_report = null_report;	/* dummy */
    }
    /*
     * Start thread whose job in life is to flush the log files to
     * disk periodically.
     */
    flush_pending = 0;
#ifdef PTHREAD_USE_D4
    status = pthread_create ( &flusher_id, pthread_attr_default,
	tlog_flusher, (pthread_addr_t) log_file_name );
#else
    status = pthread_create ( &flusher_id, NULL,
	tlog_flusher, (void *) log_file_name );
#endif
    if ( status ) perror ( "Can't start log flusher thread" );

    return log_valid;
}
/***********************************************************************/
/* Initialize secondary log files (access log and trace log).
 * If trace log file name is empty, send trace into to error log.
 */

int tlog_initlog ( int level,		/* which file: -1 access, 1 trace */
	char *fname )
{
   if ( level < 0 ) {		/* access log */
	tlog_alloc_acc_array ( level, fname );
       if ( acc_valid[-1-level] ) return 3;
        strcpy ( acc_file_spec[-1-level], fname );
        acc_file[-1-level] = fopen ( fname, "a"
	    VMS_ARG2("dna=.log") VMS_ARG("alq=100") VMS_ARG("deq=600")
	    VMS_ARG("mrs=900") VMS_ARG("shr=upd") VMS_ARG("ctx=rec") );
	if ( acc_file[-1-level] ) acc_valid[-1-level] = 1; 
	else acc_valid[-1-level] = 0;
	if ( (-1-level) > acc_maxvalid ) acc_maxvalid = (-1-level);
	return acc_valid[-1-level];

    } else {
	trace_level = level;
        if ( trc_valid ) return 3;		/* Already selected */
	if ( *fname == '\0' ) fname = log_file_spec;
        strcpy ( trc_file_spec, fname );
	if ( strcmp ( fname, log_file_spec ) == 0 ) {
	    /*
	     * Trace log and error log are same, make log file invalid.
	     */
	    trc_file = log_file;
	    log_valid = 0;
	    trc_valid = 1;
	    return trc_valid;
	}
        trc_file = fopen ( fname, "w"
	    VMS_ARG2("dna=.log") VMS_ARG("alq=100") VMS_ARG("deq=600")
	    VMS_ARG("rfm=var") VMS_ARG("mrs=1200") VMS_ARG("ctx=rec") 
	    VMS_ARG("shr=upd") );
	trc_valid = (trc_file != NULL);
	return trc_valid;
    }
 }

int tlog_set_stack_trace ( int level, int (*stack_used)() )
{
    stack_report = stack_used;
    stack_trace_level = level;
    return 1;
}
/*
 * Format log output and send to appropriate log file based upon log
 * level argument and trace level set with tlog_initlog;
 *     0	Error, write to trace file and error log.
 *    <0	Normal access, write to access log.
 *    >0	Write to trace file if trace_level greater or equal to level.
 */
int tlog_putlog ( int level, char *ctlstr, ... )
{
    va_list param_list;
#ifdef __ALPHA
    unsigned int __VA_COUNT_BUILTIN(void), arg_count;
    int i, fao_param[32];
#endif
    int status, SYS$FAOL(), length, clen, valid;
    char outbuf[1000];
    FILE *fp;
    va_start(param_list,ctlstr);
    /*
     * See if log file available and synchronize access to static areas.
     */
    if ( level < 0 ) {
	if ( !acc_valid[-1-level] ) return 0;
    } else if ( !log_valid && !trc_valid ) return 0;
    if ( (level > 1) && (http_log_level == stack_trace_level) ) {
	tlog_putlog ( 1, "Stack usage: !SL bytes!/", (*stack_report)() );
    }
    pthread_mutex_lock ( &log_write );
    for ( clen = 0; ctlstr[clen]; clen++ );
    control.dsc$w_length = clen;
    control.dsc$a_pointer = ctlstr;
    output.dsc$w_length = sizeof(outbuf);
    output.dsc$a_pointer = outbuf;

    length = 0;
    LOCK_C_RTL
#if defined(__ALPHA) && defined(VMS)
    arg_count = __VA_COUNT_BUILTIN() - 1;
    for ( i = 0; i < arg_count; i++ ) fao_param[i] = va_arg(param_list,int);
    LOCK_VMS_RTL
    status = SYS$FAOL ( &control, &length, &output, fao_param );
#else
    LOCK_VMS_RTL
    status = SYS$FAOL ( &control, &length, &output, 
#ifdef VMS
	param_list );
#else
	(char *) param_list.a0 + param_list.offset );	/* OSF/1 */
#endif
#endif
    UNLOCK_VMS_RTL
    if ( (status&1) == 1 ) {
	if ( level < 0 ) {
	    status = fwrite(outbuf, length, 1, 	acc_file[-1-level]);
	    if ( status != 1 ) {
	        char errtxt[64];
	        sprintf(errtxt, "access log write error (length=%d)", length );
	        perror ( errtxt );
	    }
	    acc_dirty[-1-level] = 1;	/* flag that file will need flushed */
	} else {
	    status = log_valid && ( 0 == level ) ? 
			fwrite(outbuf, length, 1, log_file) : 1;
	    if ( status != 1 ) {
	        char errtxt[64];
	        sprintf(errtxt, "log file write error (length=%d)", length );
	        perror ( errtxt );
	    }
	    status = trc_valid && ( trace_level >= level ) ?
			 fwrite(outbuf, length, 1, trc_file) : 1;
	    if ( status != 1 ) {
	        char errtxt[64];
	        sprintf(errtxt, "trace file write error (length=%d)", length );
	        perror ( errtxt );
	    }
	}
    } else {
	fprintf(log_file,"FAO error: %d '%s'\n", status, ctlstr );
    }
    UNLOCK_C_RTL
    /*
     * Restart flush timer if idle.
     */
    if ( !flush_pending ) pthread_cond_signal ( &log_modified );
    pthread_mutex_unlock ( &log_write );
    return status;
}
/*
 * Flush pending data to log file periodically.
 */

int tlog_flush()
{
    int i;
    for ( i = 0; i <= acc_maxvalid; i++ ) if ( acc_valid[i] ) break;
    if ( log_valid  || (i <= acc_maxvalid) || trc_valid ) {
	pthread_mutex_lock ( &log_write );
	if ( flush_pending == 2 ) {
	    flush_pending = 1;
	    pthread_cond_signal ( &log_modified );
	}
	pthread_mutex_unlock ( &log_write );
    }
    return 0;
}
/*****************************************************************************/
/* Make new version of open log file. */
tlog_reopen ( int level ) {
{
   if ( level < 0 ) {		/* access log */
        /*
	 * Make new version of access logs.
	 */
	int i, status;
	for ( status = i = 0; i <= acc_maxvalid; i++ ) {
	    pthread_mutex_lock ( &log_write );
            if ( acc_valid[i] > 0 ) {
	        LOCK_C_RTL
	        fclose ( acc_file[i] );
		acc_dirty[i] = 0;
                acc_file[i] = fopen ( acc_file_spec[i], "w"
	            VMS_ARG2("dna=.log") VMS_ARG("alq=100") VMS_ARG("deq=600")
	            VMS_ARG("mrs=900") VMS_ARG("shr=upd") VMS_ARG("ctx=rec") );
	        UNLOCK_C_RTL
	        if ( !acc_file[i] ) acc_valid[i] = 0;
		else status = 1;
            } else if ( acc_valid[i] < 0 ) {
		/*
		 * re-clone file pointer, assumes original is always in
		 * earlier slot.  Mark invalid if previous re-open failed.
		 */
		acc_file[i] = acc_file[-1-acc_valid[i]];
		if ( !acc_file[i] ) acc_valid[i] = 0;
	    }
	    pthread_mutex_unlock ( &log_write );
	}
	return status;

    } else {
	/*
	 * Make version version of trace log and set logger level.
	 */
	pthread_mutex_lock ( &log_write );
	if ( trc_valid ) {
	    trace_level = level;
	    LOCK_C_RTL
	    fclose ( trc_file );
            trc_file = fopen ( trc_file_spec, "w"
	        VMS_ARG2("dna=.log") VMS_ARG("alq=100") VMS_ARG("deq=600")
	        VMS_ARG("rfm=var") VMS_ARG("mrs=1200") VMS_ARG("ctx=rec")
	        VMS_ARG("shr=upd") );
	    UNLOCK_C_RTL
	}
	pthread_mutex_unlock ( &log_write );
	return trc_valid;
    }
 }
}
/*************************************************************************/
/* Close open files. to cleanly flush. 
*/
int tlog_rundown()
{
    int status, i;
    void *value;
    /*
     * Kill the flusher thread and wait on it to complete.
     */
    status = pthread_cancel ( flusher_id );
    if ( status != 0 ) printf ( "error killing flusher thread: %d %d\n",
		status, errno );
    if ( status == 0 ) {
	status = pthread_join ( flusher_id, &value );
	if ( status != 0 ) printf ( "error joining flusher thread: %d %d\n",
		status, errno );
    }
    /*
     * close files.
     */
    pthread_mutex_lock ( &log_write );
    if ( log_valid ) {
	log_valid = 0;
	LOCK_C_RTL
	fclose ( log_file );
	UNLOCK_C_RTL
    }
    for ( i = 0; i <= acc_maxvalid; i++ )  if ( acc_valid[i] ) {
	if ( acc_valid[i] > 0 ) {	/* not a clone */
	    LOCK_C_RTL
	    fclose ( acc_file[i] );
            UNLOCK_C_RTL
	}
	acc_valid[i] = 0;
	acc_dirty[i] = 0;
    }
    if ( trc_valid ) {
	trc_valid = 0;
	LOCK_C_RTL
	fclose ( trc_file );
	UNLOCK_C_RTL
    }

    pthread_mutex_unlock ( &log_write );

    return 1;
}
