path: root/usr/src/uts/common/fs/sockfs/nl7clogd.c

/*
 * CDDL HEADER START
 *
 * The contents of this file are subject to the terms of the
 * Common Development and Distribution License (the "License").
 * You may not use this file except in compliance with the License.
 *
 * You can obtain a copy of the license at usr/src/OPENSOLARIS.LICENSE
 * or http://www.opensolaris.org/os/licensing.
 * See the License for the specific language governing permissions
 * and limitations under the License.
 *
 * When distributing Covered Code, include this CDDL HEADER in each
 * file and include the License file at usr/src/OPENSOLARIS.LICENSE.
 * If applicable, add the following below this CDDL HEADER, with the
 * fields enclosed by brackets "[]" replaced with your own identifying
 * information: Portions Copyright [yyyy] [name of copyright owner]
 *
 * CDDL HEADER END
 */
/*
 * Copyright 2007 Sun Microsystems, Inc.  All rights reserved.
 * Use is subject to license terms.
 */

#include <sys/sysmacros.h>
#include <sys/callb.h>
#include <sys/fcntl.h>
#include <sys/filio.h>
#include <sys/pathname.h>
#include <sys/cpuvar.h>
#include <sys/promif.h>
#include <fs/sockfs/nl7c.h>
#include <fs/sockfs/nl7curi.h>

#include <inet/nca/ncadoorhdr.h>
#include <inet/nca/ncalogd.h>

extern boolean_t	nl7c_logd_enabled;
extern boolean_t	nl7c_logd_started;
extern boolean_t	nl7c_logd_cycle;

extern void		nl7clogd_startup(void);

extern boolean_t	nl7c_http_log(uri_desc_t *, uri_desc_t *,
			    nca_request_log_t *, char **, char **, uint32_t *);

static void		logit_flush(void *);

/*
 * NL7C reuses the NCA logging scheme, the directory "/var/nca" contains
 * the symlink "current" to 1 of up to 16 NCA BLF logging files, by default
 * a single logging file "log", optionally paths of up to 16 log files can
 * be specified via ncalogd.conf(5), note that these log files need not be
 * in the "/var/nca" directory.
 *
 * NL7C reuses the NCA logging APIs defined in <inet/nca/ncalogd.h>, at
 * some future date (when NCA is deprecated or improvements are needed)
 * these need to be moved into NL7C.
 *
 * NL7C implements logging differently in 2 ways, 1st the initialization
 * is handled completely in the kernel by NL7C when it's enabled vs NCA
 * when the kmod was loaded, 2nd a simple worker thread with a FIFO queue
 * is used to process log_buf_t's instead of a squeue_t (this is done as
 * squeue_t's are private to NCA and IP at some future date we may us an
 * IP squeue_t):
 *
 *	logd_t - used by various functions to manage a singly linked
 * 	grounded list of log_buf_t's and it's worker thread.
 */

typedef struct logd_s {
	log_buf_t	*head;
	log_buf_t	*tail;
	kthread_t	*worker;
	kcondvar_t	wait;
	kmutex_t	lock;
} logd_t;

/*
 * In-kernel logging:
 *
 *	nl7c_logbuf_max - tunable for the number of preallocated next
 *	log_buf_t(s) for use by log_buf_alloc(), note if the value is
 *	0 (the default) then max_cpus worth will be allocated.
 *
 *	logd - global logd_t used to post log_buf_t's too.
 *
 *	log - global current log_buf_t that logit() logs too.
 *
 *	logv[] - vector of available next logbuf(s) such that when
 *	logbuf is filled another can be used while being processed by
 *	the logger() and kmem_cache_alloc() of a replacement is done.
 *
 *	logvcnt - count of logv[] vector element(s) and the index
 *	plus 1 of the next logbuf.
 *
 *	log_buf_kmc - the kmem_cache to alloc/free log_buf_t's from/to.
 *
 *	fio - the global nca_fio_t used to manage file i/o to a logfile.
 *
 *	dir - path to the directory where the current logfile symlink
 *	is created and the default directory for logfile(s).
 *
 *	symlink - name of the logfile symlink.
 *
 *	symlink_path - path to the logfile symlink.
 *
 *	log_lock - the kmutex_t used to guarantee atomic access of
 * 	all of the above.
 *
 *	flush_tid - logit_flush() timeout id.
 *
 *	LOGBUFV_ALLOC() - macro used to add log_buf_t(s) to logv[].
 */

int			nl7c_logbuf_max = 0;
static logd_t		logd;
static log_buf_t	*log = NULL;
static log_buf_t	**logv = NULL;
static int		logvcnt = 0;
static kmem_cache_t	*log_buf_kmc;
static nca_fio_t	fio;
static caddr_t		dir = "/var/nca/";
static caddr_t		symlink = "current";
static caddr_t		symlink_dir = "/var/nca";
static caddr_t		symlink_path = "/var/nca/current";

static kmutex_t		log_lock;

static timeout_id_t	flush_tid;

#define	LOGBUFV_ALLOC(kmflag) {						\
	log_buf_t	*_p;						\
									\
	ASSERT(mutex_owned(&log_lock));					\
	while (logvcnt < nl7c_logbuf_max) {				\
		/*CONSTCOND*/						\
		if (kmflag == KM_SLEEP)					\
			mutex_exit(&log_lock);				\
		_p = kmem_cache_alloc(log_buf_kmc, kmflag);		\
		/*CONSTCOND*/						\
		if (kmflag == KM_SLEEP) {				\
			mutex_enter(&log_lock);				\
			if (logvcnt == nl7c_logbuf_max) {		\
				mutex_exit(&log_lock);			\
				kmem_cache_free(log_buf_kmc, _p);	\
				mutex_enter(&log_lock);			\
				break;					\
			}						\
		} else {						\
			if (_p == NULL) {				\
				break;					\
			}						\
		}							\
		logv[logvcnt++] = _p;					\
	}								\
}

/*
 * Exports for inet/nca/ncaddi.c:
 */

nca_fio_t		*nl7c_logd_fio = &fio;

static void
log_buf_alloc(int kmflag)
{
	nca_log_buf_hdr_t	*hdr;
	static	ulong_t		seq = 0;

	ASSERT(mutex_owned(&log_lock));

	if (logvcnt == 0) {
		/*
		 * No logv[] to use for the new log global logbuf,
		 * try to allocate one or more before giving up.
		 */
		LOGBUFV_ALLOC(kmflag);
		if (logvcnt == 0) {
			/* No joy, just give up. */
			log = NULL;
			return;
		}
	}
	log = logv[--logvcnt];

	log->size = NCA_DEFAULT_LOG_BUF_SIZE;
	log->cur_pos = sizeof (*hdr);

	hdr = (nca_log_buf_hdr_t *)&log->buffer;
	hdr->nca_loghdr.nca_version = NCA_LOG_VERSION1;
	hdr->nca_loghdr.nca_op = log_op;
	hdr->nca_logstats.n_log_size = NCA_DEFAULT_LOG_BUF_SIZE - sizeof (*hdr);
	hdr->nca_logstats.n_log_recs = 0;
	hdr->nca_logstats.n_log_upcall = seq++;

	/* Try to allocate for at least the one we just used */
	LOGBUFV_ALLOC(kmflag);
}

static void
logd_off()
{
	;
}

static void
logd_log_write(kmutex_t *lock, log_buf_t *lbp)
{
	nca_log_buf_hdr_t *hdr = (nca_log_buf_hdr_t *)lbp->buffer;
	nca_log_stat_t	*sts = &hdr->nca_logstats;
	int		size = sts->n_log_size + sizeof (*hdr);
	vnode_t		*vp;
	uio_t		uio;
	iovec_t		iov;
	int		ret;
	boolean_t	noretry = B_FALSE;
	vattr_t		attr;

	if (size & (DEV_BSIZE - 1)) {
		/*
		 * Not appropriately sized for directio(),
		 * add some filler so it is.
		 */
		sts->n_log_size += DEV_BSIZE - (size & (DEV_BSIZE - 1));
		size = sts->n_log_size + sizeof (*hdr);
	}
retry:
	if (nca_fio_offset(&fio) + size <= nca_fio_size(&fio)) {
		/*
		 * Room in the current log file so write the logbuf out,
		 * exit the logd lock while doing the i/o as to not block
		 * queuing.
		 */
		mutex_exit(lock);

		vp = nca_fio_vp(&fio);
		(void) VOP_RWLOCK(vp, V_WRITELOCK_TRUE, NULL);
		iov.iov_base = lbp->buffer;
		iov.iov_len = size;
		uio.uio_iov = &iov;
		uio.uio_iovcnt = 1;
		uio.uio_segflg = UIO_SYSSPACE;
		uio.uio_fmode = 0;
		uio.uio_loffset = (u_offset_t)nca_fio_offset(&fio);
		uio.uio_llimit = curproc->p_fsz_ctl;
		uio.uio_resid = size;
		ret = VOP_WRITE(vp, &uio, 0, kcred, NULL);
		VOP_RWUNLOCK(vp, V_WRITELOCK_TRUE, NULL);
		if (ret != 0) {
			if (ret == EFBIG) {
				/*
				 * Out of space for this file,
				 * retry with the next.
				 */
				nca_fio_size(&fio) = nca_fio_offset(&fio);
				if (noretry) {
					nl7c_logd_enabled = B_FALSE;
					goto done;
				} else
					goto next;
			}
		}
		nca_fio_offset(&fio) = uio.uio_loffset;

		mutex_enter(lock);
		goto done;
	}

	/*
	 * Current logfile doesn't have sufficient space
	 * so move on to next file (if any).
	 */
next:
	mutex_exit(lock);
	/* Close current file */
	ret = VOP_CLOSE(nca_fio_vp(&fio), FCREAT|FWRITE|FAPPEND|FTRUNC,
			1, (offset_t)0, kcred, NULL);
	nca_fio_vp(&fio) = NULL;
	if (ret) {
		cmn_err(CE_WARN, "nl7c_logd: close of %s failed (error %d)",
		    nca_fio_name(&fio), ret);
		nl7c_logd_enabled = B_FALSE;
		logd_off();
		return;
	}

	/* Go to next file */
	nca_fio_ix(&fio)++;
	if (nca_fio_ix(&fio) == nca_fio_cnt(&fio)) {
		/*
		 * We have reached the last file. If cycling
		 * is not on, disable logging and bailout.
		 */
		if (nl7c_logd_cycle) {
			/* Start from the first file */
			nca_fio_ix(&fio) = 0;
		} else {
			nca_fio_ix(&fio)--;
			nl7c_logd_enabled = B_FALSE;
			logd_off();
			return;
		}
	}

	/* Open the next log file */
	ret = vn_open(nca_fio_name(&fio), UIO_SYSSPACE, FCREAT|FWRITE|FTRUNC,
			0600, &nca_fio_vp(&fio), 0, 0);
	if (ret) {
		cmn_err(CE_WARN, "nl7c_logd: vn_open of %s failed (error %d)",
			nca_fio_name(&fio), ret);
		nl7c_logd_enabled = B_FALSE;
		logd_off();
		return;
	}

	/* Turn on directio */
	(void) VOP_IOCTL(nca_fio_vp(&fio), _FIODIRECTIO,
			DIRECTIO_ON, 0, kcred, NULL, NULL);

	/* Start writing from the begining of the file */
	nca_fio_offset(&fio) = 0;

	/* Remove the current symlink */
	(void) VOP_REMOVE(nca_fio_dvp(&fio), symlink, kcred, NULL, 0);

	attr.va_mask = AT_MODE | AT_TYPE;
	attr.va_mode = 0777;
	attr.va_type = VLNK;

	/* Create symlink to the new log file */
	ret = VOP_SYMLINK(nca_fio_dvp(&fio), symlink,
			&attr, nca_fio_name(&fio), kcred, NULL, 0);
	if (ret) {
		cmn_err(CE_WARN, "nl7c_logd: symlink of %s to %s failed",
			symlink, nca_fio_name(&fio));
		nl7c_logd_enabled = B_FALSE;
		logd_off();
		return;
	}
	mutex_enter(lock);
	goto retry;

done:
	if (logvcnt < nl7c_logbuf_max) {
		/* May need to allocate some logbuf(s) for logv[] */
		mutex_enter(&log_lock);
		if (logvcnt < nl7c_logbuf_max) {
			/*
			 * After acquiring the lock still need logbuf(s),
			 * if the global logbuf pointer is NULL then call
			 * log_buf_alloc() as it will fill up logbugv[]
			 * and initialize a new logbuf else fill up just
			 * the logv[] here.
			 */
			if (log == NULL) {
				log_buf_alloc(KM_SLEEP);
			} else {
				/*LINTED*/
				LOGBUFV_ALLOC(KM_SLEEP);
			}
		}
		mutex_exit(&log_lock);
	}
}

static void
logd_worker(logd_t *logdp)
{
	log_buf_t	*lbp;
	kmutex_t	*lock = &logdp->lock;
	kcondvar_t	*wait = &logdp->wait;
	callb_cpr_t	cprinfo;

	CALLB_CPR_INIT(&cprinfo, lock, callb_generic_cpr, "nl7c");
	mutex_enter(lock);

	for (;;) {
		/* Wait for something to do */
		while ((lbp = logdp->head) == NULL) {
			CALLB_CPR_SAFE_BEGIN(&cprinfo);
			cv_wait(wait, lock);
			CALLB_CPR_SAFE_END(&cprinfo, lock);
		}
		if ((logdp->head = lbp->next) == NULL)
			logdp->tail = NULL;
		/* Got a logbuf to write out */
		if (nl7c_logd_enabled)
			logd_log_write(lock, lbp);
		kmem_cache_free(log_buf_kmc, lbp);
	}
}

boolean_t
nl7c_logd_init(int fsz, caddr_t *fnv)
{
	vnode_t	*dvp;
	vnode_t	*svp;
	vnode_t	*vp;
	int	ret;
	caddr_t	*fnp;
	vattr_t	attr;
	uio_t	uio;
	iovec_t	iov;
	char	fbuf[TYPICALMAXPATHLEN + 1];

	/*
	 * Initialize the global logfio.
	 */
	nca_fio_cnt(&fio) = 0;
	nca_fio_ix(&fio) = 0;
	fnp = fnv;
	while (*fnp != NULL) {
		nca_fio_cnt(&fio)++;
		nca_fio_name(&fio) = *fnp;
		nca_fio_size(&fio) = fsz;
		nca_fio_offset(&fio) = 0;
		nca_fio_file(&fio) = nca_fio_ix(&fio);
		nca_fio_vp(&fio) = NULL;

		if (++fnp == &fnv[NCA_FIOV_SZ])
			break;

		nca_fio_ix(&fio)++;
	}
	/*
	 * See if we can start logging from where we left off last time,
	 * first check if the symlink exists.
	 */
	dvp = NULL;
	ret = lookupname(symlink_path, UIO_SYSSPACE, NO_FOLLOW, &dvp, &svp);
	if (ret || dvp == NULL || svp == NULL) {
		if (dvp == NULL) {
			/* No NCA symlink directory, create one */
			attr.va_mask = AT_MODE | AT_TYPE;
			attr.va_mode = 0755;
			attr.va_type = VDIR;
			ret = vn_create(symlink_dir, UIO_SYSSPACE, &attr,
			    EXCL, 0, &dvp, CRMKDIR, 0, 0);
			if (ret) {
				cmn_err(CE_WARN, "nl7c_logd_init: create"
				    " symlink dir of %s failed(%d).",
				    symlink_dir, ret);
				goto error;
			}
		}
		nca_fio_dvp(&fio) = dvp;
		/* No symlink so don't know were to start from */
		goto fresh_start;
	}
	/* Save the symlink dir vnode */
	nca_fio_dvp(&fio) = dvp;

	/* Check if the file pointed by the symlink exists */
	ret = lookupname(symlink_path, UIO_SYSSPACE, FOLLOW, NULLVPP, &vp);
	if (ret || vp == NULL)
		goto fresh_start;
	VN_RELE(vp);

	/* Read the symlink and find it in fnv[], else fresh start */
	iov.iov_len = TYPICALMAXPATHLEN;
	iov.iov_base = fbuf;
	uio.uio_iov = &iov;
	uio.uio_iovcnt = 1;
	uio.uio_resid = iov.iov_len;
	uio.uio_segflg = UIO_SYSSPACE;
	uio.uio_loffset = 0;
	uio.uio_fmode = 0;
	ret = VOP_READLINK(svp, &uio, kcred, NULL);
	if (ret) {
		(void) VOP_REMOVE(dvp, symlink, kcred, NULL, 0);
		goto fresh_start;
	}

	/* Null terminate the buf */
	fbuf[TYPICALMAXPATHLEN - (int)uio.uio_resid] = '\0';
	fnp = fnv;
	nca_fio_ix(&fio) = 0;
	while (*fnp != NULL) {
		if (strcmp(*fnp, fbuf) == 0)
			break;
		if (++fnp == &fnv[NCA_FIOV_SZ])
			goto fresh_start;
		nca_fio_ix(&fio)++;
	}
	if (*fnp == NULL)
		goto fresh_start;

	/* Start writing to the end of the file */
	ret = vn_open(*fnp, UIO_SYSSPACE,
	    FCREAT|FWRITE|FAPPEND, 0600, &vp, 0, 0);
	if (ret) {
		cmn_err(CE_WARN, "nl7c_logd_init: vn_open of "
		    "%s failed (error %d)", *fnp, ret);
		goto error;
	}
	nca_fio_vp(&fio) = vp;
	(void) VOP_IOCTL(vp, _FIODIRECTIO, DIRECTIO_ON, 0, kcred, NULL, NULL);
	attr.va_mask = AT_SIZE;
	ret = VOP_GETATTR(nca_fio_vp(&fio), &attr, 0, NULL, NULL);
	if (ret) {
		cmn_err(CE_WARN, "nl7c_logd_init: getattr of %s failed", *fnp);
		goto error;
	}
	nca_fio_offset(&fio) = (off64_t)attr.va_size;

	goto finish;

fresh_start:
	/*
	 * Here if no previous logging environment found or if the previous
	 * logging environment isn't usable or isn't consistent with the new
	 * fnv[]. Remove the existing symlink (if any) then create the new
	 * symlink to point to the first logfile.
	 */
	nca_fio_ix(&fio) = 0;
	attr.va_mask = AT_MODE | AT_TYPE;
	attr.va_mode = 0777;
	attr.va_type = VLNK;
	(void) VOP_REMOVE(dvp, symlink, kcred, NULL, 0);
	ret = VOP_SYMLINK(dvp, symlink, &attr, nca_fio_name(&fio), kcred, NULL,
	    0);
	if (ret) {
		cmn_err(CE_WARN, "nl7c_logd_init: symlink of %s to %s failed",
		    symlink_path, nca_fio_name(&fio));
		goto error;
	}
	ret = vn_open(nca_fio_name(&fio), UIO_SYSSPACE,
	    FCREAT|FWRITE|FTRUNC, 0600, &nca_fio_vp(&fio), 0, 0);
	if (ret) {
		cmn_err(CE_WARN, "nl7c_logd_init: vn_open of "
		    "%s failed (error %d)", nca_fio_name(&fio), ret);
		goto error;
	}

	/* Turn on directio */
	(void) VOP_IOCTL(nca_fio_vp(&fio), _FIODIRECTIO,
			DIRECTIO_ON, 0, kcred, NULL, NULL);

finish:
	log_buf_kmc = kmem_cache_create("NL7C_log_buf_kmc", sizeof (log_buf_t),
		0, NULL, NULL, NULL, NULL, NULL, 0);

	mutex_init(&log_lock, NULL, MUTEX_DEFAULT, NULL);
	mutex_enter(&log_lock);

	if (nl7c_logbuf_max == 0)
		nl7c_logbuf_max = max_ncpus;
	logv = kmem_alloc(nl7c_logbuf_max * sizeof (*logv), KM_SLEEP);
	for (logvcnt = 0; logvcnt < nl7c_logbuf_max; logvcnt++) {
		logv[logvcnt] = kmem_cache_alloc(log_buf_kmc, KM_SLEEP);
	}

	log_buf_alloc(KM_SLEEP);

	mutex_init(&logd.lock, NULL, MUTEX_DEFAULT, NULL);
	cv_init(&logd.wait, NULL, CV_DEFAULT, NULL);
	logd.head = NULL;
	logd.tail = NULL;
	logd.worker = thread_create(NULL, 0, logd_worker, &logd,
	    0, &p0, TS_RUN, maxclsyspri);

	mutex_exit(&log_lock);

	/* Last, start logger timeout flush */
	logit_flush(NULL);

	return (B_TRUE);

	/*
	 * Error of some sort, free any resources in reverse order.
	 */
error:
	nca_fio_ix(&fio) = 0;
	while (nca_fio_ix(&fio) < nca_fio_cnt(&fio)) {
		char *name = nca_fio_name(&fio);

		if ((vp = nca_fio_vp(&fio)) != NULL)
			VN_RELE(vp);
		kmem_free(name, (strlen(name) + 1));
		nca_fio_ix(&fio)++;
	}
	nca_fio_cnt(&fio) = 0;

	if (svp)
		VN_RELE(svp);

	if (dvp)
		VN_RELE(dvp);

	return (B_FALSE);
}

/*ARGSUSED*/
static void
logit_flush(void *arg)
{
	static log_buf_t *lastlbp = NULL;
	static int	lastpos;
	log_buf_t	*lbp = log;

	flush_tid = 0;

	mutex_enter(&log_lock);
	if (log == NULL) {
		/* No global logbuf ? Nothing to flush. */
		goto out;
	}
	if (lbp != NULL && lbp->cur_pos > (sizeof (nca_log_buf_hdr_t)) &&
		lastlbp == lbp && lastpos == lbp->cur_pos) {
		/*
		 * We have a logbuf and it has log data and it's the
		 * same logbuf and pos as last time and after lock
		 * still true, so flush.
		 */
		nca_log_stat_t	*sp;

		sp = &(((nca_log_buf_hdr_t *)lbp)->nca_logstats);
		sp->n_log_size = lbp->cur_pos;

		/* Link new logbuf onto end of logd and wake logd up */
		mutex_enter(&logd.lock);
		log->next = NULL;
		if (logd.tail == NULL)
			logd.head = log;
		else
			logd.tail->next = log;
		logd.tail = log;
		cv_signal(&logd.wait);

		mutex_exit(&logd.lock);

		log_buf_alloc(KM_NOSLEEP);
	}

	if ((lastlbp = lbp) != NULL)
		lastpos = lbp->cur_pos;

	mutex_exit(&log_lock);
out:
	/* Check again in 1 second */
	flush_tid = timeout(&logit_flush, NULL, hz);
}

void
nl7c_logd_log(uri_desc_t *quri, uri_desc_t *suri, time_t rtime, ipaddr_t faddr)
{
	nca_request_log_t *req;
	char		*wp;
	char		*pep;
	int		sz;
	uint32_t	off = 0;
	int		kmflag = servicing_interrupt() ? KM_NOSLEEP : KM_SLEEP;

	if (! nl7c_logd_enabled)
		return;

	if (! nl7c_logd_started) {
		/* Startup logging */
		nl7clogd_startup();
	}
	mutex_enter(&log_lock);
again:
	if (log == NULL) {
		/* No global logbuf, try to allocate one before giving up. */
		log_buf_alloc(kmflag);
		if (log == NULL) {
			/* No joy, just give up. */
			mutex_exit(&log_lock);
			return;
		}
	}
	/*
	 * Get a pointer to an aligned write position, a pointer to past
	 * the end of the logbuf, and a pointer to the request header.
	 *
	 * As the request header is filled in field by field addtional
	 * storage is allcated following the request header.
	 *
	 * If at any point an allocation from the logbuf overflows (i.e.
	 * resulting in a pointer > pep) the current request logging is
	 * aborted, the current logbuf is posted for write, a new logbuf
	 * is allocated, and start all over.
	 */
	pep = &((char *)log)[log->size];
	wp = (log->buffer + log->cur_pos);
	wp = NCA_LOG_ALIGN(wp);
	req = (nca_request_log_t *)wp;
	if ((wp + sizeof (*req)) >= pep) goto full;
	bzero(wp, sizeof (*req));
	wp += sizeof (*req);

	sz = MIN((quri->path.ep - quri->path.cp), MAX_URL_LEN);
	if ((wp + sz + 1) >= pep) goto full;
	bcopy(quri->path.cp, wp, sz);
	wp += sz;
	*wp++ = 0;
	sz++;
	req->request_url_len = sz;
	req->request_url = off;
	off += sz;

	/*
	 * Set response length now as the scheme log function will
	 * subtract out any header length as we want the entity body
	 * length returned for the response_len.
	 */
	req->response_len = (uint_t)suri->resplen;

	/* Call scheme log */
	if (nl7c_http_log(quri, suri, req, &wp, &pep, &off)) goto full;

	/* Update logbuf */
	log->cur_pos = (wp - log->buffer);

	req->response_status = HS_OK;

	req->start_process_time = (time32_t)rtime;
	req->end_process_time = (time32_t)gethrestime_sec();

	req->remote_host = faddr;

	((nca_log_buf_hdr_t *)log)->nca_logstats.n_log_recs++;
	mutex_exit(&log_lock);
	return;

full:
	/*
	 * The logbuf is full, zero fill from current
	 * write pointer through the end of the buf.
	 */
	wp = (log->buffer + log->cur_pos);
	sz = pep - wp;
	bzero(wp, sz);
	/*
	 * Link new logbuf onto end of logd and wake logd up.
	 */
	mutex_enter(&logd.lock);
	log->next = NULL;
	if (logd.tail == NULL)
		logd.head = log;
	else
		logd.tail->next = log;
	logd.tail = log;
	cv_signal(&logd.wait);
	mutex_exit(&logd.lock);
	/*
	 * Try to allocate a new global logbuf.
	 */
	log_buf_alloc(kmflag);

	goto again;
}