Implement new printcap options of sr= (aka stat.recv) and sr= (aka stat.send)

in lpd.  Stat.recv is useful on a printserver, as something of a network
performance-monitoring tool.  Stat.send is a minimal accounting record of
sorts for jobs going to tcp/ip based printers.

Reviewed by:	freebsd-print@bostonradio.org

4 files changed, 325 insertions, 3 deletions

diff --git a/usr.sbin/lpr/common_source/common.c b/usr.sbin/lpr/common_source/common.c
index 9a70f80..67a1725 100644
--- a/usr.sbin/lpr/common_source/common.c
+++ b/usr.sbin/lpr/common_source/common.c
@@ -47,8 +47,10 @@ static const char rcsid[] =
 #include <sys/param.h>
 #include <sys/stat.h>
 #include <sys/time.h>
+#include <sys/types.h>
 
 #include <dirent.h>
+#include <fcntl.h>
 #include <stdio.h>
 #include <stdlib.h>
 #include <string.h>
@@ -256,6 +258,289 @@ status_file_name(pp, buf, len)
 	return buf;
 }
 
+/* routine to get a current timestamp, optionally in a standard-fmt string */
+void
+lpd_gettime(tsp, strp, strsize)
+	struct timespec *tsp;
+	char 	*strp;
+	int 	 strsize;
+{
+	struct timespec local_ts;
+	struct timeval btime;
+	char	*destp;
+	char	 tempstr[TIMESTR_SIZE];
+	
+	if (tsp == NULL)
+		tsp = &local_ts;
+
+	/* some platforms have a routine called clock_gettime, but the
+	 * routine does nothing but return "not implemented". */
+	memset(tsp, 0, sizeof(struct timespec));
+	if (clock_gettime(CLOCK_REALTIME, tsp)) {
+		/* nanosec-aware rtn failed, fall back to microsec-aware rtn */
+		memset(tsp, 0, sizeof(struct timespec));
+		gettimeofday(&btime, NULL);
+		tsp->tv_sec = btime.tv_sec;
+		tsp->tv_nsec = btime.tv_usec * 1000;
+	}
+
+	/* caller may not need a character-ized version */
+	if ((strp == NULL) || (strsize < 1))
+		return;
+
+	strftime(tempstr, TIMESTR_SIZE, LPD_TIMESTAMP_PATTERN,
+		 localtime(&tsp->tv_sec));
+
+	/*
+	 * This check is for implementations of strftime which treat %z
+	 * (timezone as [+-]hhmm ) like %Z (timezone as characters), or
+	 * completely ignore %z.  This section is not needed on freebsd.
+	 * I'm not sure this is completely right, but it should work OK
+	 * for EST and EDT...
+	 */
+#ifdef STRFTIME_WRONG_z
+	destp = strrchr(tempstr, ':');
+	if (destp != NULL) {
+		destp += 3;
+		if ((*destp != '+') && (*destp != '-')) {
+			char savday[6];
+			int tzmin = timezone / 60;
+			int tzhr = tzmin / 60;
+			if (daylight)
+				tzhr--;
+			strcpy(savday, destp + strlen(destp) - 4);
+			snprintf(destp, (destp - tempstr), "%+03d%02d",
+				    (-1*tzhr), tzmin % 60);
+			strcat(destp, savday);
+		}
+	}
+#endif
+
+	if (strsize > TIMESTR_SIZE) {
+		strsize = TIMESTR_SIZE;
+		strp[TIMESTR_SIZE+1] = '\0';
+	}
+	strncpy(strp, tempstr, strsize);
+}
+
+/* routines for writing transfer-statistic records */
+void
+trstat_init(pp, fname, filenum)
+	struct printer *pp;
+	const char *fname;
+	int filenum;
+{
+	register const char *srcp;
+	register char *destp, *endp;
+
+	/*
+	 * Figure out the job id of this file.  The filename should be
+	 * 'cf', 'df', or maybe 'tf', followed by a letter (or sometimes
+	 * two), followed by the jobnum, followed by a hostname.
+	 * The jobnum is usually 3 digits, but might be as many as 5.
+	 * Note that some care has to be taken parsing this, as the
+	 * filename could be coming from a remote-host, and thus might
+	 * not look anything like what is expected...
+	 */
+	memset(pp->jobnum, 0, sizeof(pp->jobnum));
+	pp->jobnum[0] = '0';
+	srcp = strchr(fname, '/');
+	if (srcp == NULL)
+		srcp = fname;
+	destp = &(pp->jobnum[0]);
+	endp = destp + 5;
+	while (*srcp != '\0' && (*srcp < '0' || *srcp > '9'))
+		srcp++;
+	while (*srcp >= '0' && *srcp <= '9' && destp < endp)
+		*(destp++) = *(srcp++);
+
+	/* get the starting time in both numeric and string formats, and
+	 * save those away along with the file-number */
+	pp->jobdfnum = filenum;
+	lpd_gettime(&pp->tr_start, pp->tr_timestr, TIMESTR_SIZE);
+
+	return;
+}
+
+void
+trstat_write(pp, sendrecv, bytecnt, userid, otherhost, orighost)
+	struct printer *pp;
+	tr_sendrecv sendrecv;
+	size_t	bytecnt;
+	const char *userid;
+	const char *otherhost;
+	const char *orighost;
+{
+#define STATLINE_SIZE 1024
+	double	 trtime;
+	int	 remspace;
+	int	 statfile;
+	char	 thishost[MAXHOSTNAMELEN+1], statline[STATLINE_SIZE];
+	const char *rectype, *statfname;
+	const char *lprhost, *sendhost, *recvhost, *recvdev;
+	char	*eostat;
+#define UPD_EOSTAT(xStr) do {         \
+	eostat = strchr(xStr, '\0');  \
+	remspace = eostat - xStr;     \
+} while(0)
+	
+	lpd_gettime(&pp->tr_done, NULL, 0);
+	trtime = DIFFTIME_TS(pp->tr_done, pp->tr_start);
+
+	gethostname(thishost, sizeof(thishost));
+	lprhost = sendhost = recvhost = recvdev = NULL;
+	switch (sendrecv) {
+	    case TR_SENDING:
+		rectype = "send";
+		statfname = pp->stat_send;
+		sendhost = thishost;
+		recvhost = otherhost;
+		break;
+	    case TR_RECVING:
+		rectype = "recv";
+		statfname = pp->stat_recv;
+		sendhost = otherhost;
+		recvhost = thishost;
+		break;
+	    case TR_PRINTING:
+		/* copying to a device (presumably local, though things
+		 * like 'net/CAP' can confuse this assumption...) */
+		rectype = "prnt";
+		statfname = pp->stat_send;
+		sendhost = thishost;
+		recvdev = _PATH_DEFDEVLP;
+		if (pp->lp) recvdev = pp->lp;
+		break;
+	    default:
+		/* internal error...  should we syslog/printf an error? */
+		return;
+	}
+	if (statfname == NULL) return;
+
+	/*
+	 * the original-host and userid are found out by reading thru the
+	 * cf (control-file) for the job.  Unfortunately, on incoming jobs
+	 * the df's (data-files) are sent before the matching cf, so the
+	 * orighost & userid are generally not-available for incoming jobs.
+	 *
+	 * (it would be nice to create a work-around for that..)
+	*/
+	if (orighost && (*orighost != '\0'))
+		lprhost = orighost;
+	else
+		lprhost = ".na.";
+	if (*userid == '\0')  userid = NULL;
+
+	/*
+	 * Format of statline.
+	 * Some of the keywords listed here are not implemented here, but
+	 * they are listed to reserve the meaning for a given keyword.
+	 * Fields are separated by a blank.  The fields in statline are:
+	 *   <tstamp>      - time the transfer started
+	 *   <ptrqueue>    - name of the printer queue (the short-name...)
+	 *   <hname>       - hostname the file originally came from (the
+	 *		     'lpr host'), if known, or  "_na_" if not known.
+	 *   <xxx>         - id of job from that host (generally three digits)
+	 *   <n>           - file count (# of file within job)
+	 *   <rectype>     - 4-byte field indicating the type of transfer
+	 *		     statistics record.  "send" means it's from the
+	 *		     host sending a datafile, "recv" means it's from
+	 *		     a host as it receives a datafile.
+	 *   user=<userid> - user who sent the job (if known)
+	 *   secs=<n>      - seconds it took to transfer the file
+	 *   bytes=<n>     - number of bytes transfered (ie, "bytecount")
+	 *   bps=<n.n>e<n> - Bytes/sec (if the transfer was "big enough"
+	 *		     for this to be useful) 
+	 * ! top=<str>     - type of printer (if the type is defined in
+	 *		     printcap, and if this statline is for sending
+	 *		     a file to that ptr)
+	 * ! qls=<n>       - queue-length at start of send/print-ing a job
+	 * ! qle=<n>       - queue-length at end of send/print-ing a job
+	 *   sip=<addr>    - IP address of sending host, only included when
+	 *		     receiving a job.
+	 *   shost=<hname> - sending host (if that does != the original host)
+	 *   rhost=<hname> - hostname receiving the file (ie, "destination")
+	 *   rdev=<dev>    - device receiving the file, when the file is being
+	 *		     send to a device instead of a remote host.
+	 *
+	 * Note: A single print job may be transferred multiple times.  The
+	 * original 'lpr' occurs on one host, and that original host might
+	 * send to some interim host (or print server).  That interim host
+	 * might turn around and send the job to yet another host (most likely
+	 * the real printer).  The 'shost=' parameter is only included if the
+	 * sending host for this particular transfer is NOT the same as the
+	 * host which did the original 'lpr'.
+	 *
+	 * Many values have 'something=' tags before them, because they are
+	 * in some sense "optional", or their order may vary.  "Optional" may
+	 * mean in the sense that different SITES might choose to have other
+	 * fields in the record, or that some fields are only included under
+	 * some circumstances.  Programs processing these records should not
+	 * assume the order or existence of any of these keyword fields.
+	 */
+	snprintf(statline, STATLINE_SIZE, "%s %s %s %s %03ld %s",
+			   pp->tr_timestr, pp->printer, lprhost,
+			   pp->jobnum, pp->jobdfnum, rectype);
+	UPD_EOSTAT(statline);
+
+	if (userid != NULL) {
+		snprintf(eostat, remspace, " user=%s", userid);
+		UPD_EOSTAT(statline);
+	}
+	snprintf(eostat, remspace, " secs=%#.2f bytes=%u", trtime, bytecnt);
+	UPD_EOSTAT(statline);
+	
+	/* the bps field duplicates info from bytes and secs, so do not
+	 * bother to include it for very small files */
+	if ((bytecnt > 25000) && (trtime > 1.1)) {
+		snprintf(eostat, remspace, " bps=%#.2e",
+					   ((double)bytecnt/trtime));
+		UPD_EOSTAT(statline);
+	}
+
+	if (sendrecv == TR_RECVING) {
+		if (remspace > 5+strlen(from_ip) ) {
+			snprintf(eostat, remspace, " sip=%s", from_ip);
+			UPD_EOSTAT(statline);
+		}
+	}
+	if (0 != strcmp(lprhost, sendhost)) {
+		if (remspace > 7+strlen(sendhost) ) {
+			snprintf(eostat, remspace, " shost=%s", sendhost);
+			UPD_EOSTAT(statline);
+		}
+	}
+	if (recvhost) {
+		if (remspace > 7+strlen(recvhost) ) {
+			snprintf(eostat, remspace, " rhost=%s", recvhost);
+			UPD_EOSTAT(statline);
+		}
+	}
+	if (recvdev) {
+		if (remspace > 6+strlen(recvdev) ) {
+			snprintf(eostat, remspace, " rdev=%s", recvdev);
+			UPD_EOSTAT(statline);
+		}
+	}
+	if (remspace > 1) {
+		strcpy(eostat, "\n");
+	} else {
+		/* probably should back up to just before the final " x=".. */  
+		strcpy(statline+STATLINE_SIZE-2, "\n");
+	}
+	statfile = open(statfname, O_WRONLY|O_APPEND, 0664);
+	if (statfile < 0) {
+		/* statfile was given, but we can't open it.  should we
+		 * syslog/printf this as an error? */
+		return;
+	}
+	write(statfile, statline, strlen(statline));
+	close(statfile);
+
+	return;
+#undef UPD_EOSTAT	
+}
+
 #ifdef __STDC__
 #include <stdarg.h>
 #else
diff --git a/usr.sbin/lpr/common_source/lp.h b/usr.sbin/lpr/common_source/lp.h
index c7a960e..276108a 100644
--- a/usr.sbin/lpr/common_source/lp.h
+++ b/usr.sbin/lpr/common_source/lp.h
@@ -35,6 +35,7 @@
  */
 
 #include <sys/queue.h>
+#include <time.h>
 
 /*
  * All this information used to be in global static variables shared
@@ -80,9 +81,22 @@ struct	printer {
 	char	*spool_dir;	/* SD: spool directory */
 	long	 no_formfeed;	/* SF: suppress FF on each print job */
 	long	 no_header;	/* SH: suppress header page */
+	char	*stat_recv;	/* SR: statistics file, receiving jobs */
+	char	*stat_send;	/* SS: statistics file, sending jobs */
 	char	*status_file;	/* ST: status file name */
 	char	*trailer;	/* TR: trailer string send when Q empties */
 	char	*mode_set;	/* MS: mode set, a la stty */
+
+	/* variables used by trstat*() to keep statistics on file transfers */
+#define JOBNUM_SIZE   8
+	char 	 jobnum[JOBNUM_SIZE];
+	long	 jobdfnum;	/* current datafile number within job */
+	struct timespec tr_start, tr_done;
+#define TIMESTR_SIZE 40		/* holds result from LPD_TIMESTAMP_PATTERN */
+	char	 tr_timestr[TIMESTR_SIZE];
+#define DIFFTIME_TS(endTS,startTS) \
+		((double)(endTS.tv_sec - startTS.tv_sec) \
+		+ (endTS.tv_nsec - startTS.tv_nsec) * 1.0e-9)
 };
 
 /*
@@ -142,6 +156,8 @@ extern char	*name;		/* program name */
 				/* host machine name */
 extern char	host[MAXHOSTNAMELEN];
 extern char	*from;		/* client's machine name */
+#define MAXIPSTRLEN 32		/* maxlen of an IP-address as a string */
+extern char	from_ip[MAXIPSTRLEN];   /* client machine's IP address */
 
 extern int	requ[];		/* job number of spool entries */
 extern int	requests;	/* # of spool requests */
@@ -157,6 +173,18 @@ struct queue {
 	char	q_name[MAXNAMLEN+1];	/* control file name */
 };
 
+/* lpr/lpd generates readable timestamps for logfiles, etc.  Have all those
+ * timestamps be in the same format wrt strftime().  This is ISO 8601 format,
+ * with the addition of an easy-readable day-of-the-week field.  Note that
+ * '%T' = '%H:%M:%S', and that '%z' is not available on all platforms.
+ */
+#define LPD_TIMESTAMP_PATTERN    "%Y-%m-%dT%T%z %a"
+
+/*
+ * Codes to indicate which statistic records trstat_write should write.
+ */
+typedef enum { TR_SENDING, TR_RECVING, TR_PRINTING } tr_sendrecv;
+
 /*
  * Error codes for our mini printcap library.
  */
@@ -218,6 +246,7 @@ void     ldump __P((char *, char *, int));
 void	 lastprinter __P((void));
 int      lockchk __P((struct printer *pp, char *));
 char	*lock_file_name __P((const struct printer *pp, char *buf, size_t len));
+void	 lpd_gettime __P((struct timespec *_tsp, char *_strp, int _strsize));
 int	 nextprinter __P((struct printer *pp, int *status));
 const
 char	*pcaperr __P((int error));
@@ -230,5 +259,9 @@ void     show __P((char *, char *, int));
 int      startdaemon __P((const struct printer *pp));
 char	*status_file_name __P((const struct printer *pp, char *buf,
 			       size_t len));
+void	 trstat_init __P((struct printer *pp, const char *fname, int filenum));
+void	 trstat_write __P((struct printer *pp, tr_sendrecv sendrecv,
+			   size_t bytecnt, const char *userid,
+			   const char *otherhost, const char *orighost));
 ssize_t	 writel __P((int s, ...));
 __END_DECLS
diff --git a/usr.sbin/lpr/common_source/net.c b/usr.sbin/lpr/common_source/net.c
index 4f5c0c5..4cfabfa 100644
--- a/usr.sbin/lpr/common_source/net.c
+++ b/usr.sbin/lpr/common_source/net.c
@@ -65,9 +65,9 @@ static const char rcsid[] =
 #include "lp.local.h"
 #include "pathnames.h"
 
-			/* host machine name */
-char	host[MAXHOSTNAMELEN];
-char	*from = host;	/* client's machine name */
+char	 host[MAXHOSTNAMELEN];	/* host machine name */
+char	*from = host;		/* client's machine name */
+char	 from_ip[MAXIPSTRLEN] = ""; /* client machine's IP address */
 
 extern uid_t	uid, euid;
 
diff --git a/usr.sbin/lpr/common_source/printcap.c b/usr.sbin/lpr/common_source/printcap.c
index 7b6d124..390de46 100644
--- a/usr.sbin/lpr/common_source/printcap.c
+++ b/usr.sbin/lpr/common_source/printcap.c
@@ -251,6 +251,8 @@ getprintcap_int(bp, pp)
 			    &pp->remote_queue));
 	CHK(capdb_getaltstr(bp, "sd", "spool.dir", _PATH_DEFSPOOL,
 			    &pp->spool_dir));
+	CHK(capdb_getaltstr(bp, "sr", "stat.recv", 0, &pp->stat_recv));
+	CHK(capdb_getaltstr(bp, "ss", "stat.send", 0, &pp->stat_send));
 	CHK(capdb_getaltstr(bp, "st", "spool.status", DEFSTAT,
 			    &pp->status_file));
 	CHK(capdb_getaltstr(bp, "tr", "job.trailer", 0, &pp->trailer));
@@ -346,6 +348,8 @@ free_printer(struct printer *pp)
 	cfree(pp->remote_host);
 	cfree(pp->remote_queue);
 	cfree(pp->spool_dir);
+	cfree(pp->stat_recv);
+	cfree(pp->stat_send);
 	cfree(pp->status_file);
 	cfree(pp->trailer);
 	cfree(pp->mode_set);