From: Dave Hart <hart@ntp.org>
Date: Fri, 31 Dec 2010 03:31:28 +0000 (+0000)
Subject: [Bug 1766] Oncore clock has offset/high jitter at startup.
X-Git-Tag: NTP_4_2_7P107~2
X-Git-Url: http://git.ipfire.org/cgi-bin/gitweb.cgi?a=commitdiff_plain;h=c198f9b4a5dd94d9da600c9e020c622fbadb70f2;p=thirdparty%2Fntp.git

[Bug 1766] Oncore clock has offset/high jitter at startup.

bk: 4d1d4e90amzsd960mxy3gAe7Hk5Ufw
---

diff --git a/ChangeLog b/ChangeLog
index f7fc4cea4..915f7d4af 100644
--- a/ChangeLog
+++ b/ChangeLog
@@ -1,4 +1,5 @@
 * [Bug 1764] Palisade driver doesn't build on Linux.
+* [Bug 1766] Oncore clock has offset/high jitter at startup.
 * Move ntp_control.h variable IDs to ntp_control.c, remove their use by
   ntpq.  They are implementation details private to ntpd.  [Bug 597] was
   caused by ntpq's reliance on these IDs it need not know about.
diff --git a/include/ntp_stdlib.h b/include/ntp_stdlib.h
index 6a489a379..deaf3908f 100644
--- a/include/ntp_stdlib.h
+++ b/include/ntp_stdlib.h
@@ -32,8 +32,8 @@
 # endif
 #endif
 
-extern	size_t	mvsnprintf(char *, size_t, const char *, va_list);
-extern	size_t	msnprintf(char *, size_t, const char *, ...)
+extern	int	mvsnprintf(char *, size_t, const char *, va_list);
+extern	int	msnprintf(char *, size_t, const char *, ...)
 				__attribute__((__format__(__printf__, 3, 4)));
 extern	void	msyslog(int, const char *, ...)
 				__attribute__((__format__(__printf__, 2, 3)));
diff --git a/include/ntpd.h b/include/ntpd.h
index 3b86807c9..9969239a6 100644
--- a/include/ntpd.h
+++ b/include/ntpd.h
@@ -295,6 +295,7 @@ extern	void	record_peer_stats (sockaddr_u *, int, double, double, double, double
 extern	void	record_proto_stats (char *);
 extern	void	record_loop_stats (double, double, double, double, int);
 extern	void	record_clock_stats (sockaddr_u *, const char *);
+extern	int	mprintf_clock_stats(sockaddr_u *, const char *, ...);
 extern	void	record_raw_stats (sockaddr_u *, sockaddr_u *, l_fp *, l_fp *, l_fp *, l_fp *);
 extern	u_long	leap_month(u_long);
 extern	void	record_crypto_stats (sockaddr_u *, const char *);
diff --git a/libntp/msyslog.c b/libntp/msyslog.c
index 25daa2327..79c2b8e49 100644
--- a/libntp/msyslog.c
+++ b/libntp/msyslog.c
@@ -155,7 +155,7 @@ format_errmsg(
 }
 
 
-size_t
+int
 mvsnprintf(
 	char *		buf,
 	size_t		bufsiz,
@@ -165,6 +165,7 @@ mvsnprintf(
 {
 	char	nfmt[256];
 	int	errval;
+	int	rc;
 
 	/*
 	 * Save the error value as soon as possible
@@ -179,10 +180,15 @@ mvsnprintf(
 
 	format_errmsg(nfmt, sizeof(nfmt), fmt, errval);
 
-	return vsnprintf(buf, bufsiz, nfmt, ap);
+	rc = vsnprintf(buf, bufsiz, nfmt, ap);
+	/* terminate buf, as MS vsnprintf() does not when truncating */
+	buf[bufsiz - 1] = '\0';
+
+	return rc;
 }
 
-size_t
+
+int
 msnprintf(
 	char *		buf,
 	size_t		bufsiz,
diff --git a/ntpd/ntp_util.c b/ntpd/ntp_util.c
index 17acfe342..85a3f7b1d 100644
--- a/ntpd/ntp_util.c
+++ b/ntpd/ntp_util.c
@@ -683,6 +683,31 @@ record_clock_stats(
 }
 
 
+/*
+ * mprintf_clock_stats - write clock statistics to file with
+ *			msnprintf-style formatting.
+ */
+int
+mprintf_clock_stats(
+	sockaddr_u *addr,
+	const char *fmt,
+	...
+	)
+{
+	va_list	ap;
+	int	rc;
+	char	msg[512];
+
+	if (!stats_control)
+		return;
+	va_start(ap, fmt);
+	rc = mvsnprintf(msg, sizeof(msg), fmt, ap);
+	va_end(ap);
+	record_clock_stats(addr, msg);
+
+	return rc;
+}
+
 /*
  * record_raw_stats - write raw timestamps to file
  *
diff --git a/ntpd/refclock_oncore.c b/ntpd/refclock_oncore.c
index d6da0c3ee..a0c78340e 100644
--- a/ntpd/refclock_oncore.c
+++ b/ntpd/refclock_oncore.c
@@ -165,6 +165,7 @@
 #include "ntp_stdlib.h"
 
 #include <stdio.h>
+#include <stdarg.h>
 #include <ctype.h>
 #include <sys/stat.h>
 #ifdef ONCORE_SHMEM_STATUS
@@ -380,6 +381,7 @@ static	int	oncore_checksum_ok    (u_char *, int);
 static	void	oncore_compute_dH     (struct instance *);
 static	void	oncore_load_almanac   (struct instance *);
 static	void	oncore_log	      (struct instance *, int, const char *);
+static	int	oncore_log_f	      (struct instance *, int, const char *, ...);
 static	void	oncore_print_Cb       (struct instance *, u_char *);
 /* static  void    oncore_print_array	 (u_char *, int);	*/
 static	void	oncore_print_posn     (struct instance *);
@@ -596,7 +598,7 @@ oncore_start(
 	register struct instance *instance;
 	struct refclockproc *pp;
 	int fd1, fd2;
-	char device1[STRING_LEN], device2[STRING_LEN], Msg[160];
+	char device1[STRING_LEN], device2[STRING_LEN];
 #ifndef SYS_WINNT
 	struct stat stat1, stat2;
 #endif
@@ -671,25 +673,21 @@ oncore_start(
 	*/
 #ifndef SYS_WINNT
 	if (stat(device1, &stat1)) {
-		snprintf(Msg, sizeof(Msg), "Can't stat fd1 (%s)",
-			 device1);
-		oncore_log(instance, LOG_ERR, Msg);
+		oncore_log_f(instance, LOG_ERR, "Can't stat fd1 (%s)",
+			     device1);
 		return(0);			/* exit, no file, can't start driver */
 	}
 
 	if (stat(device2, &stat2)) {
 		stat2.st_dev = stat2.st_ino = -2;
-		snprintf(Msg, sizeof(Msg),
-			 "Can't stat fd2 (%s) errno = %d",
-			 device2, errno);
-		oncore_log(instance, LOG_ERR, Msg);
+		oncore_log_f(instance, LOG_ERR, "Can't stat fd2 (%s) %d %m",
+			     device2, errno);
 	}
 #endif	/* !SYS_WINNT */
 
 	if (!(fd1 = refclock_open(device1, SPEED, LDISC_RAW))) {
-		snprintf(Msg, sizeof(Msg), "Can't open fd1 (%s)",
-			 device1);
-		oncore_log(instance, LOG_ERR, Msg);
+		oncore_log_f(instance, LOG_ERR, "Can't open fd1 (%s)",
+			     device1);
 		return(0);			/* exit, can't open file, can't start driver */
 	}
 
@@ -705,9 +703,8 @@ oncore_start(
 #endif	/* !SYS_WINNT */
 	{	/* different devices here */
 		if ((fd2=tty_open(device2, O_RDWR, 0777)) < 0) {
-			snprintf(Msg, sizeof(Msg),
-				"Can't open fd2 (%s)", device2);
-			oncore_log(instance, LOG_ERR, Msg);
+			oncore_log_f(instance, LOG_ERR,
+				     "Can't open fd2 (%s)", device2);
 			return(0);		/* exit, can't open PPS file, can't start driver */
 		}
 	}
@@ -848,17 +845,15 @@ oncore_ppsapi(
 	)
 {
 	int cap, mode, mode1;
-	char *cp, Msg[160];
+	char *cp;
 
 	if (time_pps_getcap(instance->pps_h, &cap) < 0) {
-		msnprintf(Msg, sizeof(Msg), "time_pps_getcap failed: %m");
-		oncore_log(instance, LOG_ERR, Msg);
+		oncore_log_f(instance, LOG_ERR, "time_pps_getcap failed: %m");
 		return (0);
 	}
 
 	if (time_pps_getparams(instance->pps_h, &instance->pps_p) < 0) {
-		msnprintf(Msg, sizeof(Msg), "time_pps_getparams failed: %m");
-		oncore_log(instance, LOG_ERR, Msg);
+		oncore_log_f(instance, LOG_ERR, "time_pps_getparams failed: %m");
 		return (0);
 	}
 
@@ -875,20 +870,19 @@ oncore_ppsapi(
 		mode = PPS_CAPTURECLEAR;
 		mode1 = PPS_OFFSETCLEAR;
 	}
-	snprintf(Msg, sizeof(Msg), "Initializing timing to %s.", cp);
-	oncore_log(instance, LOG_INFO, Msg);
+	oncore_log_f(instance, LOG_INFO, "Initializing timing to %s.",
+		     cp);
 
 	if (!(mode & cap)) {
-		snprintf(Msg, sizeof(Msg),
-			 "Can't set timing to %s, exiting...", cp);
-		oncore_log(instance, LOG_ERR, Msg);
+		oncore_log_f(instance, LOG_ERR,
+			     "Can't set timing to %s, exiting...", cp);
 		return(0);
 	}
 
 	if (!(mode1 & cap)) {
-		snprintf(Msg, sizeof(Msg),
-			 "Can't set %s, this will increase jitter.", cp);
-		oncore_log(instance, LOG_NOTICE, Msg);
+		oncore_log_f(instance, LOG_NOTICE,
+			     "Can't set %s, this will increase jitter.",
+			     cp);
 		mode1 = 0;
 	}
 
@@ -897,7 +891,7 @@ oncore_ppsapi(
 	instance->pps_p.mode = (mode | mode1 | PPS_TSFMT_TSPEC) & cap;
 
 	if (time_pps_setparams(instance->pps_h, &instance->pps_p) < 0) {
-		oncore_log(instance, LOG_ERR, "ONCORE: time_pps_setparams fails");
+		oncore_log_f(instance, LOG_ERR, "ONCORE: time_pps_setparams fails %m");
 		return(0);		/* exit, can't do time_pps_setparans on PPS file */
 	}
 
@@ -917,8 +911,7 @@ oncore_ppsapi(
 
 		if (time_pps_kcbind(instance->pps_h, PPS_KC_HARDPPS, i,
 		    PPS_TSFMT_TSPEC) < 0) {
-			msnprintf(Msg, sizeof(Msg), "time_pps_kcbind failed: %m");
-			oncore_log(instance, LOG_ERR, Msg);
+			oncore_log_f(instance, LOG_ERR, "time_pps_kcbind failed: %m");
 			oncore_log(instance, LOG_ERR, "HARDPPS failed, abort...");
 			return (0);
 		}
@@ -937,7 +930,6 @@ oncore_init_shmem(
 	)
 {
 	int i, l, n, fd, shmem_old_size, n1;
-	char Msg[160];
 	u_char *cp, *cp1, *buf, *shmem_old;
 	struct msg_desc *mp;
 	struct stat sbuf;
@@ -1072,10 +1064,9 @@ oncore_init_shmem(
 		return;
 	}
 
-	snprintf(Msg, sizeof(Msg),
-		 "SHMEM (size = %ld) is CONFIGURED and available as %s",
-		 (u_long) shmem_length, instance->shmem_fname);
-	oncore_log(instance, LOG_NOTICE, Msg);
+	oncore_log_f(instance, LOG_NOTICE,
+		     "SHMEM (size = %ld) is CONFIGURED and available as %s",
+		     (u_long) shmem_length, instance->shmem_fname);
 }
 #endif /* ONCORE_SHMEM_STATUS */
 
@@ -1216,7 +1207,7 @@ oncore_read_config(
  */
 
 	FILE	*fd;
-	char	*cp, *cc, *ca, line[100], units[2], device[64], Msg[160], **cpp;
+	char	*cp, *cc, *ca, line[100], units[2], device[64], **cpp;
 	char	*dirs[] = { "/etc/ntp", "/etc", 0 };
 	int	i, sign, lat_flg, long_flg, ht_flg, mode, mask;
 	double	f1, f2, f3;
@@ -1330,12 +1321,11 @@ oncore_read_config(
 				f1 = 1000000000 * f1;
 			if (f1 < 0 || f1 > 1.e9)
 				f1 = 0;
-			if (f1 < 0 || f1 > 999999) {
-				snprintf(Msg, sizeof(Msg),
-					 "PPS Cable delay of %fns out of Range, ignored",
-					 f1);
-				oncore_log(instance, LOG_WARNING, Msg);
-			} else
+			if (f1 < 0 || f1 > 999999)
+				oncore_log_f(instance, LOG_WARNING,
+					     "PPS Cable delay of %fns out of Range, ignored",
+					     f1);
+			else
 				instance->delay = f1;		/* delay in ns */
 		} else if (!strncmp(cc, "OFFSET", (size_t) 6)) {
 			f1 = 0;
@@ -1351,12 +1341,11 @@ oncore_read_config(
 				f1 = 1000000000 * f1;
 			if (f1 < 0 || f1 > 1.e9)
 				f1 = 0;
-			if (f1 < 0 || f1 > 999999999.) {
-				snprintf(Msg, sizeof(Msg),
-					 "PPS Offset of %fns out of Range, ignored",
-					 f1);
-				oncore_log(instance, LOG_WARNING, Msg);
-			} else
+			if (f1 < 0 || f1 > 999999999.)
+				oncore_log_f(instance, LOG_WARNING,
+					     "PPS Offset of %fns out of Range, ignored",
+					     f1);
+			else
 				instance->offset = f1;		/* offset in ns */
 		} else if (!strncmp(cc, "MODE", (size_t) 4)) {
 			sscanf(ca, "%d", &mode);
@@ -1392,9 +1381,9 @@ oncore_read_config(
 			} else if (!strcmp(ca,"TRAIM")) {
 				instance->pps_control = 3;		/* PPS on when TRAIM status is OK */
 			} else {
-				snprintf(Msg, sizeof(Msg),
-				    "Unknown value \"%s\" for PPSCONTROL, ignored", cc);
-				oncore_log(instance, LOG_WARNING, Msg);
+				oncore_log_f(instance, LOG_WARNING,
+				             "Unknown value \"%s\" for PPSCONTROL, ignored",
+					     cc);
 			}
 		}
 	}
@@ -1407,22 +1396,19 @@ oncore_read_config(
 
 	instance->posn_set = 1;
 	if (!( lat_flg && long_flg && ht_flg )) {
-		snprintf(Msg, sizeof(Msg),
-			 "ONCORE: incomplete data on %s", device);
-		oncore_log (instance, LOG_WARNING, Msg);
+		oncore_log_f(instance, LOG_WARNING,
+			     "ONCORE: incomplete data on %s", device);
 		instance->posn_set = 0;
 		if (mode == 1 || mode == 3) {
-			snprintf(Msg, sizeof(Msg),
-				 "Input Mode = %d, but no/incomplete position, mode set to %d",
-				 mode, mode+1);
-			oncore_log(instance, LOG_WARNING, Msg);
+			oncore_log_f(instance, LOG_WARNING,
+				     "Input Mode = %d, but no/incomplete position, mode set to %d",
+				     mode, mode+1);
 			mode++;
 		}
 	}
 	instance->init_type = mode;
 
-	snprintf(Msg, sizeof(Msg), "Input mode = %d", mode);
-	oncore_log(instance, LOG_INFO, Msg);
+	oncore_log_f(instance, LOG_INFO, "Input mode = %d", mode);
 }
 
 
@@ -1450,9 +1436,9 @@ oncore_receive(
 		int i;
 		char	Msg[120], Msg2[10];
 
-		snprintf(Msg, sizeof(Msg), ">>> %d bytes available",
-			 rbufp->recv_length);
-		oncore_log(instance, LOG_DEBUG, Msg);
+		oncore_log_f(instance, LOG_DEBUG,
+			     ">>> %d bytes available",
+			     rbufp->recv_length);
 		strncpy(Msg, ">>>", sizeof(Msg));
 		for (i = 0; i < rbufp->recv_length; i++) {
 			snprintf(Msg2, sizeof(Msg2), "%02x ", p[i]);
@@ -1498,13 +1484,10 @@ oncore_consume(
 				if (rcvbuf[i] == '@' && rcvbuf[i+1] == '@')
 					break;
 #ifdef ONCORE_VERBOSE_CONSUME
-			if (debug > 4) {
-				char	Msg[120];
-
-				snprintf(Msg, sizeof(Msg),
-					 ">>> skipping %d chars", i);
-				oncore_log(instance, LOG_DEBUG, Msg);
-			}
+			if (debug > 4)
+				oncore_log_f(instance, LOG_DEBUG,
+					     ">>> skipping %d chars",
+					     i);
 #endif
 			if (i != rcvptr)
 				memcpy(rcvbuf, rcvbuf+i, (size_t)(rcvptr-i));
@@ -1519,14 +1502,10 @@ oncore_consume(
 				break;
 		if (m == l) {
 #ifdef ONCORE_VERBOSE_CONSUME
-			if (debug > 4) {
-				char	Msg[120];
-
-				snprintf(Msg, sizeof(Msg),
-					 ">>> Unknown MSG, skipping 4 (%c%c)",
-					 rcvbuf[2], rcvbuf[3]);
-				oncore_log(instance, LOG_DEBUG, Msg);
-			}
+			if (debug > 4)
+				oncore_log_f(instance, LOG_DEBUG,
+					     ">>> Unknown MSG, skipping 4 (%c%c)",
+					     rcvbuf[2], rcvbuf[3]);
 #endif
 			memcpy(rcvbuf, rcvbuf+4, (size_t) 4);
 			rcvptr -= 4;
@@ -1535,15 +1514,11 @@ oncore_consume(
 
 		l = oncore_messages[m].len;
 #ifdef ONCORE_VERBOSE_CONSUME
-		if (debug > 3) {
-			char Msg[120];
-
-			snprintf(Msg, sizeof(Msg),
-				 "GOT: %c%c  %d of %d entry %d",
-				 instance->unit, rcvbuf[2], rcvbuf[3],
-				 rcvptr, l, m);
-			oncore_log(instance, LOG_DEBUG, Msg);
-			}
+		if (debug > 3)
+			oncore_log_f(instance, LOG_DEBUG,
+				     "GOT: %c%c  %d of %d entry %d",
+				     instance->unit, rcvbuf[2],
+				     rcvbuf[3], rcvptr, l, m);
 #endif
 		/* Got the entire message ? */
 
@@ -1613,7 +1588,7 @@ oncore_get_timestamp(
 	struct timespec timeout;
 	struct peer *peer;
 	pps_info_t pps_i;
-	char	Msg[140];
+	char Msg[160];
 
 	peer = instance->peer;
 	peer->flags &= ~FLAG_PPS;	/* default to off, set to on if we make
@@ -1656,7 +1631,8 @@ oncore_get_timestamp(
 	timeout.tv_nsec = 0;
 	if (time_pps_fetch(instance->pps_h, PPS_TSFMT_TSPEC, &pps_i,
 	    &timeout) < 0) {
-		oncore_log(instance, LOG_ERR, "time_pps_fetch failed");
+		oncore_log_f(instance, LOG_ERR,
+			     "time_pps_fetch failed %m");
 		return;
 	}
 
@@ -1669,15 +1645,16 @@ oncore_get_timestamp(
 
 			i = (u_long) pps_i.assert_sequence;
 # ifdef HAVE_STRUCT_TIMESPEC
-			snprintf(Msg, sizeof(Msg),
-				 "serial/j (%lu, %lu) %ld.%09ld", i, j,
-				 (long)tsp->tv_sec, (long)tsp->tv_nsec);
+			oncore_log_f(instance, LOG_DEBUG,
+				     "serial/j (%lu, %lu) %ld.%09ld", i,
+				     j, (long)tsp->tv_sec,
+				     (long)tsp->tv_nsec);
 # else
-			snprintf(Msg, sizeof(Msg),
-				 "serial/j (%lu, %lu) %ld.%06ld", i, j,
-				 (long)tsp->tv_sec, (long)tsp->tv_usec);
+			oncore_log_f(instance, LOG_DEBUG,
+				     "serial/j (%lu, %lu) %ld.%06ld", i,
+				     j, (long)tsp->tv_sec,
+				     (long)tsp->tv_usec);
 # endif
-			oncore_log(instance, LOG_DEBUG, Msg);
 		}
 #endif
 
@@ -1696,15 +1673,16 @@ oncore_get_timestamp(
 
 			i = (u_long) pps_i.clear_sequence;
 # ifdef HAVE_STRUCT_TIMESPEC
-			snprintf(Msg, sizeof(Msg),
-				 "serial/j (%lu, %lu) %ld.%09ld", i, j,
-				 (long)tsp->tv_sec, (long)tsp->tv_nsec);
+			oncore_log_f(instance, LOG_DEBUG,
+				     "serial/j (%lu, %lu) %ld.%09ld", i,
+				     j, (long)tsp->tv_sec,
+				     (long)tsp->tv_nsec);
 # else
-			snprintf(Msg. sizeof(Msg),
-				 "serial/j (%lu, %lu) %ld.%06ld", i, j,
-				 (long)tsp->tv_sec, (long)tsp->tv_usec);
+			oncore_log_f(instance, LOG_DEBUG,
+				     "serial/j (%lu, %lu) %ld.%06ld", i,
+				     j, (long)tsp->tv_sec,
+				     (long)tsp->tv_usec);
 # endif
-			oncore_log(instance, LOG_DEBUG, Msg);
 		}
 #endif
 
@@ -1768,14 +1746,14 @@ oncore_get_timestamp(
 	 */
 
 	if (time_pps_getcap(instance->pps_h, &current_mode) < 0) {
-		msnprintf(Msg, sizeof(Msg), "time_pps_getcap failed: %m");
-		oncore_log(instance, LOG_ERR, Msg);
+		oncore_log_f(instance, LOG_ERR,
+			     "time_pps_getcap failed: %m");
 		return;
 	}
 
 	if (time_pps_getparams(instance->pps_h, &current_params) < 0) {
-		msnprintf(Msg, sizeof(Msg), "time_pps_getparams failed: %m");
-		oncore_log(instance, LOG_ERR, Msg);
+		oncore_log_f(instance, LOG_ERR,
+			     "time_pps_getparams failed: %m");
 		return;
 	}
 
@@ -1936,9 +1914,8 @@ oncore_msg_any(
 # else
 		GETTIMEOFDAY(&tv, 0);
 # endif
-		snprintf(Msg, sizeof(Msg), "%ld.%06ld",
-			 (long)tv.tv_sec, (long)tv.tv_usec);
-		oncore_log(instance, LOG_DEBUG, Msg);
+		oncore_log(instance, LOG_DEBUG, "%ld.%06ld",
+			   (long)tv.tv_sec, (long)tv.tv_usec);
 
 		if (!*fmt) {
 			snprintf(Msg, sizeof(Msg), ">>@@%c%c ", buf[2],
@@ -1996,17 +1973,17 @@ oncore_msg_Ag(
 	u_char *buf,
 	size_t len
 	)
-{		char  Msg[160], *cp;
+{
+	char *cp;
 
-		cp = "set to";
-		if (instance->o_state == ONCORE_RUN)
-			cp = "is";
+	cp = "set to";
+	if (instance->o_state == ONCORE_RUN)
+		cp = "is";
 
-		instance->Ag = buf[4];
-		snprintf(Msg, sizeof(Msg),
-			 "Satellite mask angle %s %d degrees", cp,
-			 (int)instance->Ag);
-		oncore_log(instance, LOG_INFO, Msg);
+	instance->Ag = buf[4];
+	oncore_log_f(instance, LOG_INFO,
+		     "Satellite mask angle %s %d degrees", cp,
+		     (int)instance->Ag);
 }
 
 
@@ -2070,8 +2047,6 @@ oncore_msg_Ay(
 	size_t len
 	)
 {
-	char Msg[120];
-
 	if (instance->saw_Ay)
 		return;
 
@@ -2079,9 +2054,8 @@ oncore_msg_Ay(
 
 	instance->offset = buf_w32(&buf[4]);
 
-	snprintf(Msg, sizeof(Msg), "PPS Offset is set to %ld ns",
-		 instance->offset);
-	oncore_log(instance, LOG_INFO, Msg);
+	oncore_log_f(instance, LOG_INFO, "PPS Offset is set to %ld ns",
+		     instance->offset);
 }
 
 
@@ -2097,8 +2071,6 @@ oncore_msg_Az(
 	size_t len
 	)
 {
-	char Msg[120];
-
 	if (instance->saw_Az)
 		return;
 
@@ -2106,9 +2078,8 @@ oncore_msg_Az(
 
 	instance->delay = buf_w32(&buf[4]);
 
-	snprintf(Msg, sizeof(Msg), "Cable delay is set to %ld ns",
-		instance->delay);
-	oncore_log(instance, LOG_INFO, Msg);
+	oncore_log_f(instance, LOG_INFO, "Cable delay is set to %ld ns",
+		     instance->delay);
 }
 
 
@@ -2123,7 +2094,6 @@ oncore_msg_BaEaHa(
 	)
 {
 	const char	*cp;
-	char		Msg[160];
 	int		mode;
 
 	/* OK, we are close to the RUN state now.
@@ -2154,18 +2124,14 @@ oncore_msg_BaEaHa(
 		else				/* set from test */
 			instance->chan = instance->chan_ck;
 
-		snprintf(Msg, sizeof(Msg), "Input   says chan = %d",
-			 instance->chan_in);
-		oncore_log(instance, LOG_INFO, Msg);
-		snprintf(Msg, sizeof(Msg), "Model # says chan = %d",
-			 instance->chan_id);
-		oncore_log(instance, LOG_INFO, Msg);
-		snprintf(Msg, sizeof(Msg), "Testing says chan = %d",
-			 instance->chan_ck);
-		oncore_log(instance, LOG_INFO, Msg);
-		snprintf(Msg, sizeof(Msg), "Using        chan = %d",
-			 instance->chan);
-		oncore_log(instance, LOG_INFO, Msg);
+		oncore_log_f(instance, LOG_INFO, "Input   says chan = %d",
+			    instance->chan_in);
+		oncore_log_f(instance, LOG_INFO, "Model # says chan = %d",
+			     instance->chan_id);
+		oncore_log_f(instance, LOG_INFO, "Testing says chan = %d",
+			     instance->chan_ck);
+		oncore_log_f(instance, LOG_INFO, "Using        chan = %d",
+			     instance->chan);
 
 		instance->o_state = ONCORE_HAVE_CHAN;
 		oncore_log(instance, LOG_NOTICE, "state = ONCORE_HAVE_CHAN");
@@ -2311,10 +2277,9 @@ oncore_msg_BaEaHa(
 					 *	   We will have to do it ourselves (done above)
 					 */
 
-					snprintf(Msg, sizeof(Msg),
-						 "Initiating software 3D site survey (%d samples)",
-						 POS_HOLD_AVERAGE);
-					oncore_log(instance, LOG_INFO, Msg);
+					oncore_log_f(instance, LOG_INFO,
+						     "Initiating software 3D site survey (%d samples)",
+						     POS_HOLD_AVERAGE);
 
 					oncore_log(instance, LOG_NOTICE, "SSstate = ONCORE_SS_SW");
 					instance->site_survey = ONCORE_SS_SW;
@@ -2471,13 +2436,10 @@ oncore_msg_Bd(
 	size_t len
 	)
 {
-	char Msg[160];
-
-	snprintf(Msg, sizeof(Msg),
-		 "Bd: Almanac %s, week = %d, t = %d, %d SVs: %x",
-		 ((buf[4]) ? "LOADED" : "(NONE)"), buf[5], buf[6],
-		 buf[7], w32(&buf[8]));
-	oncore_log(instance, LOG_NOTICE, Msg);
+	oncore_log_f(instance, LOG_NOTICE,
+		     "Bd: Almanac %s, week = %d, t = %d, %d SVs: %x",
+		     ((buf[4]) ? "LOADED" : "(NONE)"), buf[5], buf[6],
+		     buf[7], w32(&buf[8]));
 }
 
 
@@ -2533,7 +2495,7 @@ oncore_msg_Bl(
 {
 	int	chan, id, subframe, valid, page, i, j, tow;
 	int	day_now, day_lsf;
-	char	*cp, Msg[120];
+	char	*cp;
 	enum {
 		WARN_NOT_YET,
 		WARN_0,
@@ -2625,21 +2587,19 @@ oncore_msg_Bl(
 		i = instance->Bl.dt_lsf-instance->Bl.dt_ls;
 		if (i) {
 			j = (i >= 0) ? i : -i;		/* abs(i) */
-			snprintf(Msg, sizeof(Msg),
-				 "see Leap_Second (%c%d) in %d days",
-				 ((i >= 0) ? '+' : '-'), j,
-				 day_lsf-day_now);
-			oncore_log(instance, LOG_NOTICE, Msg);
+			oncore_log_f(instance, LOG_NOTICE,
+				     "see Leap_Second (%c%d) in %d days",
+				     ((i >= 0) ? '+' : '-'), j,
+				     day_lsf-day_now);
 		}
 	}
-	snprintf(Msg, sizeof(Msg),
-		"dt_ls = %d  dt_lsf = %d  WN = %d  DN = %d  WN_lsf = %d  DNlsf = %d  wn_flg = %d  lsf_flg = %d  Bl_day = %d",
-		instance->Bl.dt_ls, instance->Bl.dt_lsf,
-		instance->Bl.WN, instance->Bl.DN,
-		instance->Bl.WN_lsf, instance->Bl.DN_lsf,
-		instance->Bl.wn_flg, instance->Bl.lsf_flg,
-		instance->Bl.Bl_day);
-	oncore_log(instance, LOG_DEBUG, Msg);
+	oncore_log_f(instance, LOG_DEBUG,
+		     "dt_ls = %d  dt_lsf = %d  WN = %d  DN = %d  WN_lsf = %d  DNlsf = %d  wn_flg = %d  lsf_flg = %d  Bl_day = %d",
+		     instance->Bl.dt_ls, instance->Bl.dt_lsf,
+		     instance->Bl.WN, instance->Bl.DN,
+		     instance->Bl.WN_lsf, instance->Bl.DN_lsf,
+		     instance->Bl.wn_flg, instance->Bl.lsf_flg,
+		     instance->Bl.Bl_day);
 }
 
 
@@ -2716,7 +2676,6 @@ oncore_msg_CaFaIa(
 	size_t len
 	)
 {
-	char	Msg[120];
 	int	i;
 
 	if (instance->o_state == ONCORE_TEST_SENT) {
@@ -2727,14 +2686,13 @@ oncore_msg_CaFaIa(
 #if ONCORE_VERBOSE_SELF_TEST
 		if (debug > 2) {
 			if (buf[2] == 'I')
-				snprintf(Msg, sizeof(Msg),
-					 ">>@@%ca %x %x %x", buf[2],
-					 buf[4], buf[5], buf[6]);
+				oncore_log_f(instance, LOG_DEBUG,
+					     ">>@@%ca %x %x %x", buf[2],
+					     buf[4], buf[5], buf[6]);
 			else
-				snprintf(Msg, sizeof(Msg),
-					 ">>@@%ca %x %x", buf[2],
-					 buf[4], buf[5]);
-			oncore_log(instance, LOG_DEBUG, Msg);
+				oncore_log_f(instance, LOG_DEBUG,
+					     ">>@@%ca %x %x", buf[2],
+					     buf[4], buf[5]);
 		}
 #endif
 
@@ -2745,14 +2703,13 @@ oncore_msg_CaFaIa(
 		if (buf[2] == 'I') i = i || buf[6];
 		if (i) {
 			if (buf[2] == 'I')
-				snprintf(Msg, sizeof(Msg),
-					 "self test failed: result %02x %02x %02x",
-					 buf[4], buf[5], buf[6]);
+				oncore_log_f(instance, LOG_ERR, 
+					     "self test failed: result %02x %02x %02x",
+					     buf[4], buf[5], buf[6]);
 			else
-				snprintf(Msg, sizeof(Msg),
-					 "self test failed: result %02x %02x",
-					 buf[4], buf[5]);
-			oncore_log(instance, LOG_ERR, Msg);
+				oncore_log_f(instance, LOG_ERR, 
+					     "self test failed: result %02x %02x",
+					     buf[4], buf[5]);
 
 			oncore_log(instance, LOG_ERR,
 				   "ONCORE: self test failed, shutting down driver");
@@ -2810,13 +2767,8 @@ oncore_msg_Cb(
 	memcpy(instance->shmem + instance->shmem_Cb + i + 3, buf, (size_t) (len + 3));
 
 #ifdef ONCORE_VERBOSE_MSG_CB
-	{
-		char Msg[160];
-
-		snprintf(Msg, sizeof(Msg), "See Cb [%d,%d]", buf[4],
-			 buf[5]);
-		oncore_log(instance, LOG_DEBUG, Msg);
-	}
+	oncore_log_f(instance, LOG_DEBUG, "See Cb [%d,%d]", buf[4],
+		     buf[5]);
 #endif
 }
 
@@ -2920,7 +2872,7 @@ oncore_msg_Cj_id(
 	size_t len
 	)
 {
-	char *cp, *cp1, *cp2, Model[21], Msg[160];
+	char *cp, *cp1, *cp2, Model[21];
 
 	/* Write Receiver ID message to clockstats file */
 
@@ -2991,10 +2943,9 @@ oncore_msg_Cj_id(
 
 	/* use MODEL to set CHAN and TRAIM and possibly zero SHMEM */
 
-	snprintf(Msg, sizeof(Msg),
-		 "This looks like an Oncore %s with version %d.%d firmware.",
-		 cp, instance->version, instance->revision);
-	oncore_log(instance, LOG_INFO, Msg);
+	oncore_log_f(instance, LOG_INFO,
+		     "This looks like an Oncore %s with version %d.%d firmware.",
+		     cp, instance->version, instance->revision);
 
 	instance->chan_id = 8;	   /* default */
 	if (instance->model == ONCORE_BASIC || instance->model == ONCORE_PVT6)
@@ -3012,14 +2963,13 @@ oncore_msg_Cj_id(
 	else if (instance->model == ONCORE_M12)
 		instance->traim_id = -1;
 
-	snprintf(Msg, sizeof(Msg), "Channels = %d, TRAIM = %s",
-		 instance->chan_id,
-		 ((instance->traim_id < 0)
-		      ? "UNKNOWN"
-		      : (instance->traim_id > 0)
-			    ? "ON"
-			    : "OFF"));
-	oncore_log(instance, LOG_INFO, Msg);
+	oncore_log_f(instance, LOG_INFO, "Channels = %d, TRAIM = %s",
+		     instance->chan_id,
+		     ((instance->traim_id < 0)
+			  ? "UNKNOWN"
+			  : (instance->traim_id > 0)
+				? "ON"
+				: "OFF"));
 }
 
 
@@ -3037,7 +2987,6 @@ oncore_msg_Cj_init(
 	size_t len
 	)
 {
-	char	Msg[160];
 	u_char	Cmd[20];
 	int	mode;
 
@@ -3050,10 +2999,9 @@ oncore_msg_Cj_init(
 
 	if (instance->chan == 12) {
 		instance->shmem_bad_Ea = 1;
-		snprintf(Msg, sizeof(Msg),
-			 "*** SHMEM partially enabled for ONCORE M12 s/w v%d.%d ***",
-			 instance->version, instance->revision);
-		oncore_log(instance, LOG_NOTICE, Msg);
+		oncore_log_f(instance, LOG_NOTICE,
+			     "*** SHMEM partially enabled for ONCORE M12 s/w v%d.%d ***",
+			     instance->version, instance->revision);
 	}
 
 	oncore_sendmsg(instance, oncore_cmd_Cg, sizeof(oncore_cmd_Cg)); /* Return to  Posn Fix mode */
@@ -3145,7 +3093,6 @@ oncore_msg_Ga(
 	size_t len
 	)
 {
-	char Msg[160];
 	long lat, lon, ht;
 	double Lat, Lon, Ht;
 
@@ -3162,11 +3109,9 @@ oncore_msg_Ga(
 	Lon /= 3600000;
 	Ht  /= 100;
 
-
-	snprintf(Msg, sizeof(Msg),
-		 "Ga Posn Lat = %.7f, Lon = %.7f, Ht  = %.2f", Lat,
-		 Lon, Ht);
-	oncore_log(instance, LOG_NOTICE, Msg);
+	oncore_log_f(instance, LOG_NOTICE,
+		     "Ga Posn Lat = %.7f, Lon = %.7f, Ht  = %.2f", Lat,
+		     Lon, Ht);
 
 	instance->ss_lat  = lat;
 	instance->ss_long = lon;
@@ -3186,7 +3131,7 @@ oncore_msg_Gb(
 	size_t len
 	)
 {
-	char	Msg[160], *gmts;
+	char *	gmts;
 	int	mo, d, y, h, m, s, gmth, gmtm;
 
 	mo = buf[4];
@@ -3201,10 +3146,9 @@ oncore_msg_Gb(
 	gmth = buf[12];
 	gmtm = buf[13];
 
-	snprintf(Msg, sizeof(Msg),
-		 "Date/Time set to: %d%s%d %2d:%02d:%02d GMT (GMT offset is %s%02d:%02d)",
-		 d, months[mo-1], y, h, m, s, gmts, gmth, gmtm);
-	oncore_log(instance, LOG_NOTICE, Msg);
+	oncore_log_f(instance, LOG_NOTICE,
+		     "Date/Time set to: %d%s%d %2d:%02d:%02d GMT (GMT offset is %s%02d:%02d)",
+		     d, months[mo-1], y, h, m, s, gmts, gmth, gmtm);
 }
 
 
@@ -3218,11 +3162,11 @@ oncore_msg_Gc(
 	size_t len
 	)
 {
-	char Msg[160], *tbl[] = {"OFF", "ON", "SATELLITE", "TRAIM" };
+	char *tbl[] = {"OFF", "ON", "SATELLITE", "TRAIM" };
 
 	instance->pps_control_msg_seen = 1;
-	snprintf(Msg, sizeof(Msg), "PPS Control set to %s", tbl[buf[4]]);
-	oncore_log(instance, LOG_INFO, Msg);
+	oncore_log_f(instance, LOG_INFO, "PPS Control set to %s",
+		     tbl[buf[4]]);
 }
 
 
@@ -3238,7 +3182,7 @@ oncore_msg_Gj(
 	)
 {
 	int dt;
-	char Msg[160], *cp;
+	char *cp;
 
 	instance->saw_Gj = 1; /* flag, saw_Gj, dont need to try Bj in check_leap */
 
@@ -3246,22 +3190,20 @@ oncore_msg_Gj(
 
 	dt = buf[5] - buf[4];
 
-	snprintf(Msg, sizeof(Msg),
-		 "Leap Sec Msg: %d %d %d %d %d %d %d %d %d %d", buf[4],
-		 buf[5], 256 * buf[6] + buf[7], buf[8], buf[9], buf[10],
-		 (buf[14] + 256 *
-		     (buf[13] + 256 * (buf[12] + 256 * buf[11]))),
-		 buf[15], buf[16], buf[17]);
-	oncore_log(instance, LOG_INFO, Msg);
-
-	if (dt) {
-		snprintf(Msg, sizeof(Msg),
-			 "Leap second (%d) scheduled for %d%s%d at %d:%d:%d",
-			 dt, buf[9], months[buf[8] - 1],
-			 256 * buf[6] + buf[7], buf[15], buf[16],
-			 buf[17]);
-		oncore_log(instance, LOG_NOTICE, Msg);
-	}
+	oncore_log_f(instance, LOG_INFO,
+		     "Leap Sec Msg: %d %d %d %d %d %d %d %d %d %d",
+		     buf[4], buf[5], 256 * buf[6] + buf[7], buf[8],
+		     buf[9], buf[10],
+		     (buf[14] + 256 *
+		         (buf[13] + 256 * (buf[12] + 256 * buf[11]))),
+		     buf[15], buf[16], buf[17]);
+
+	if (dt)
+		oncore_log_f(instance, LOG_NOTICE,
+			     "Leap second (%d) scheduled for %d%s%d at %d:%d:%d",
+			      dt, buf[9], months[buf[8] - 1],
+			      256 * buf[6] + buf[7], buf[15], buf[16],
+			      buf[17]);
 
 	/* Only raise warning within a month of the leap second */
 
@@ -3376,23 +3318,19 @@ oncore_check_almanac(
 
 		bits3 = instance->BEHa[141];	/* UTC parameters */
 		if (!instance->count5_set && (bits3 & 0xC0)) {
-			instance->count5 = 2;
+			instance->count5 = 4;	/* was 2 [Bug 1766] */
 			instance->count5_set = 1;
 		}
 #ifdef ONCORE_VERBOSE_CHECK_ALMANAC
-		{
-			char Msg[160];
-
-			snprintf(Msg, sizeof(Msg),
-				 "DEBUG BITS: (%x %x), (%x %x %x),  %x %x %x %x %x",
-				 instance->BEHa[129],
-				 instance->BEHa[130], bits1, bits2,
-				 bits3, instance->mode == MODE_0D,
-				 instance->mode == MODE_2D,
-				 instance->mode == MODE_3D,
-				 instance->rsm.bad_almanac,
-				 instance->rsm.bad_fix);
-			oncore_log(instance, LOG_DEBUG, Msg);
+		oncore_log_f(instance, LOG_DEBUG, 
+			     "DEBUG BITS: (%x %x), (%x %x %x),  %x %x %x %x %x",
+			     instance->BEHa[129], instance->BEHa[130],
+			     bits1, bits2, bits3,
+			     instance->mode == MODE_0D,
+			     instance->mode == MODE_2D,
+			     instance->mode == MODE_3D,
+			     instance->rsm.bad_almanac,
+			     instance->rsm.bad_fix);
 		}
 #endif
 	}
@@ -3513,7 +3451,6 @@ oncore_compute_dH(
 	)
 {
 	int GPS, MSL;
-	char	Msg[160];
 
 	/* Here calculate dH = GPS - MSL for output message */
 	/* also set Altitude Hold mode if GT */
@@ -3531,11 +3468,9 @@ oncore_compute_dH(
 
 	/* if MSL is not set, the calculation is meaningless */
 
-	if (MSL) {	/* not set ! */
-		snprintf(Msg, sizeof(Msg), "dH = (GPS - MSL) = %.2fm",
-			 instance->dH);
-		oncore_log(instance, LOG_INFO, Msg);
-	}
+	if (MSL)	/* not set ! */
+		oncore_log_f(instance, LOG_INFO,
+		             "dH = (GPS - MSL) = %.2fm", instance->dH);
 }
 
 
@@ -3570,11 +3505,8 @@ oncore_load_almanac(
 #else	/* ONCORE_VERBOSE_LOAD_ALMANAC follows */
 	for (cp = instance->shmem + 4; (n = 256 * (*(cp-3)) + *(cp-2));
 	     cp += (n+3)) {
-		char Msg[160];
-
-		snprintf(Msg, sizeof(Msg), "See %c%c%c%c %d", *(cp),
-			 *(cp+1), *(cp+2), *(cp+3), *(cp+4));
-		oncore_log(instance, LOG_DEBUG, Msg);
+		oncore_log_f(instance, LOG_DEBUG, "See %c%c%c%c %d",
+			   *(cp), *(cp+1), *(cp+2), *(cp+3), *(cp+4));
 
 		if (!strncmp(cp, "@@Cb", 4)) {
 			oncore_print_Cb(instance, cp);
@@ -3605,14 +3537,10 @@ oncore_load_almanac(
 				jj = buf_w32(cp + 19);
 				kk = buf_w32(cp + 23);
 #ifdef ONCORE_VERBOSE_LOAD_ALMANAC
-				{
-					char Msg[160];
-					snprintf(Msg, sizeof(Msg),
-						 "SHMEM posn = %ld (%d, %d, %d)",
-						 (long)(cp-instance->shmem),
-						 ii, jj, kk);
-					oncore_log(instance, LOG_DEBUG, Msg);
-				}
+				oncore_log_f(instance, LOG_DEBUG,
+					     "SHMEM posn = %ld (%d, %d, %d)",
+					     (long)(cp-instance->shmem),
+					     ii, jj, kk);
 #endif
 				if (ii != 0 || jj != 0 || kk != 0) { /* phk asked for this test */
 					instance->ss_lat  = ii;
@@ -3630,13 +3558,9 @@ oncore_load_almanac(
 	tm = gmtime((const time_t *) &tv.tv_sec);
 
 #ifdef ONCORE_VERBOSE_LOAD_ALMANAC
-	{
-		char Msg[160];
-		snprintf(Msg, sizeof(Msg), "DATE %d %d %d, %d %d %d",
-			 1900 + tm->tm_year, tm->tm_mon, tm->tm_mday,
-			 tm->tm_hour, tm->tm_min, tm->tm_sec);
-		oncore_log(instance, LOG_DEBUG, Msg);
-	}
+	oncore_log_f(instance, LOG_DEBUG, "DATE %d %d %d, %d %d %d",
+		     1900 + tm->tm_year, tm->tm_mon, tm->tm_mday,
+		     tm->tm_hour, tm->tm_min, tm->tm_sec);
 #endif
 	if (instance->chan == 12) {
 		memcpy(Cmd, oncore_cmd_Gb, (size_t) sizeof(oncore_cmd_Gb));
@@ -3687,20 +3611,19 @@ oncore_print_Cb(
 	int	ii;
 	char	Msg[160], Msg2[10];
 
-	snprintf(Msg, sizeof(Msg), "DEBUG: See: %c%c%c%c", *(cp),
-		 *(cp+1), *(cp+2), *(cp+3));
-	oncore_log(instance, LOG_DEBUG, Msg);
+	oncore_log_f(instance, LOG_DEBUG, "DEBUG: See: %c%c%c%c", *(cp),
+		     *(cp+1), *(cp+2), *(cp+3));
+
 	snprintf(Msg, sizeof(Msg), "DEBUG: Cb: [%d,%d]", *(cp+4),
 		*(cp+5));
-	for(ii = 0; ii < 33; ii++) {
+	for (ii = 0; ii < 33; ii++) {
 		snprintf(Msg2, sizeof(Msg2), " %d", *(cp+ii));
 		strncat(Msg, Msg2, sizeof(Msg));
 	}
 	oncore_log(instance, LOG_DEBUG, Msg);
 
-	snprintf(Msg, sizeof(Msg), "Debug: Cb: [%d,%d]", *(cp+4),
-		 *(cp+5));
-	oncore_log(instance, LOG_DEBUG, Msg);
+	oncore_log_f(instance, LOG_DEBUG, "Debug: Cb: [%d,%d]", *(cp+4),
+		     *(cp+5));
 #endif
 }
 
@@ -3733,7 +3656,7 @@ oncore_print_posn(
 	struct instance *instance
 	)
 {
-	char Msg[120], ew, ns;
+	char ew, ns;
 	double xd, xm, xs, yd, ym, ys, hm, hft;
 	int idx, idy, is, imx, imy;
 	long lat, lon;
@@ -3758,10 +3681,9 @@ oncore_print_posn(
 
 	xd = lat/3600000.;	/* lat, lon in int msec arc, ht in cm. */
 	yd = lon/3600000.;
-	snprintf(Msg, sizeof(Msg),
-		 "Lat = %c %11.7fdeg,    Long = %c %11.7fdeg,    Alt = %5.2fm (%5.2fft) GPS",
-		 ns, xd, ew, yd, hm, hft);
-	oncore_log(instance, LOG_INFO, Msg);
+	oncore_log_f(instance, LOG_INFO,
+		     "Lat = %c %11.7fdeg,    Long = %c %11.7fdeg,    Alt = %5.2fm (%5.2fft) GPS",
+		     ns, xd, ew, yd, hm, hft);
 
 	idx = xd;
 	idy = yd;
@@ -3769,9 +3691,9 @@ oncore_print_posn(
 	imy = lon%3600000;
 	xm = imx/60000.;
 	ym = imy/60000.;
-	snprintf(Msg, sizeof(Msg),
-	    "Lat = %c %3ddeg %7.4fm,   Long = %c %3ddeg %8.5fm,  Alt = %7.2fm (%7.2fft) GPS", ns, idx, xm, ew, idy, ym, hm, hft);
-	oncore_log(instance, LOG_INFO, Msg);
+	oncore_log_f(instance, LOG_INFO,
+		     "Lat = %c %3ddeg %7.4fm,   Long = %c %3ddeg %8.5fm,  Alt = %7.2fm (%7.2fft) GPS",
+		     ns, idx, xm, ew, idy, ym, hm, hft);
 
 	imx = xm;
 	imy = ym;
@@ -3779,10 +3701,9 @@ oncore_print_posn(
 	xs  = is/1000.;
 	is  = lon%60000;
 	ys  = is/1000.;
-	snprintf(Msg, sizeof(Msg),
-		 "Lat = %c %3ddeg %2dm %5.2fs, Long = %c %3ddeg %2dm %5.2fs, Alt = %7.2fm (%7.2fft) GPS",
-		 ns, idx, imx, xs, ew, idy, imy, ys, hm, hft);
-	oncore_log(instance, LOG_INFO, Msg);
+	oncore_log_f(instance, LOG_INFO,
+		     "Lat = %c %3ddeg %2dm %5.2fs, Long = %c %3ddeg %2dm %5.2fs, Alt = %7.2fm (%7.2fft) GPS",
+		     ns, idx, imx, xs, ew, idy, imy, ys, hm, hft);
 }
 
 
@@ -3804,11 +3725,8 @@ oncore_sendmsg(
 	fd = instance->ttyfd;
 #ifdef ONCORE_VERBOSE_SENDMSG
 	if (debug > 4) {
-		char	Msg[120];
-
-		snprintf(Msg, sizeof(Msg), "ONCORE: Send @@%c%c %d",
-			 ptr[0], ptr[1], (int)len);
-		oncore_log(instance, LOG_DEBUG, Msg);
+		oncore_log_f(instance, LOG_DEBUG, "ONCORE: Send @@%c%c %d",
+			     ptr[0], ptr[1], (int)len);
 	}
 #endif
 	write(fd, "@@", (size_t) 2);
@@ -3894,25 +3812,19 @@ oncore_set_traim(
 	struct instance *instance
 	)
 {
-	char	Msg[160];
-
 	if (instance->traim_in != -1)	/* set in Input */
 		instance->traim = instance->traim_in;
 	else
 		instance->traim = instance->traim_ck;
 
-	snprintf(Msg, sizeof(Msg), "Input   says TRAIM = %d",
-		 instance->traim_in);
-	oncore_log(instance, LOG_INFO, Msg);
-	snprintf(Msg, sizeof(Msg), "Model # says TRAIM = %d",
-		 instance->traim_id);
-	oncore_log(instance, LOG_INFO, Msg);
-	snprintf(Msg, sizeof(Msg), "Testing says TRAIM = %d",
-		 instance->traim_ck);
-	oncore_log(instance, LOG_INFO, Msg);
-	snprintf(Msg, sizeof(Msg), "Using        TRAIM = %d",
-		 instance->traim);
-	oncore_log(instance, LOG_INFO, Msg);
+	oncore_log_f(instance, LOG_INFO, "Input   says TRAIM = %d",
+		     instance->traim_in);
+	oncore_log_f(instance, LOG_INFO, "Model # says TRAIM = %d",
+		     instance->traim_id);
+	oncore_log_f(instance, LOG_INFO, "Testing says TRAIM = %d",
+		     instance->traim_ck);
+	oncore_log_f(instance, LOG_INFO, "Using        TRAIM = %d",
+		     instance->traim);
 
 	if (instance->traim_ck == 1 && instance->traim == 0) {
 		/* if it should be off, and I turned it on during testing,
@@ -3982,7 +3894,6 @@ oncore_ss(
 	struct instance *instance
 	)
 {
-	char	Msg[160];
 	double	lat, lon, ht;
 
 
@@ -4026,18 +3937,16 @@ oncore_ss(
 		instance->ss_long /= POS_HOLD_AVERAGE;
 		instance->ss_ht   /= POS_HOLD_AVERAGE;
 
-		snprintf(Msg, sizeof(Msg),
-			 "Surveyed posn: lat %.3f (mas) long %.3f (mas) ht %.3f (cm)",
-			 instance->ss_lat, instance->ss_long,
-			 instance->ss_ht);
-		oncore_log(instance, LOG_NOTICE, Msg);
+		oncore_log_f(instance, LOG_NOTICE,
+			     "Surveyed posn: lat %.3f (mas) long %.3f (mas) ht %.3f (cm)",
+			     instance->ss_lat, instance->ss_long,
+			     instance->ss_ht);
 		lat = instance->ss_lat/3600000.;
 		lon = instance->ss_long/3600000.;
 		ht  = instance->ss_ht/100;
-		snprintf(Msg, sizeof(Msg),
-			 "Surveyed posn: lat %.7f (deg) long %.7f (deg) ht %.2f (m)",
-			 lat, lon, ht);
-		oncore_log(instance, LOG_NOTICE, Msg);
+		oncore_log_f(instance, LOG_NOTICE,
+			     "Surveyed posn: lat %.7f (deg) long %.7f (deg) ht %.2f (m)",
+			     lat, lon, ht);
 
 		oncore_set_posn(instance);
 
@@ -4098,46 +4007,42 @@ oncore_wait_almanac(
 static void
 oncore_log (
 	struct instance *instance,
-	int	log_level,
+	int log_level,
 	const char *msg
 	)
 {
-	int i;
-	char	Msg[200];
+	msyslog(log_level, "ONCORE[%d]: %s", instance->unit, msg);
+	mprintf_clock_stats(&instance->peer->srcadr, "ONCORE[%d]: %s",
+			    instance->unit, msg);
+}
 
-	snprintf(Msg, sizeof(Msg), "ONCORE[%d]: %s", instance->unit,
-		 msg);
-	syslog(log_level, Msg);
 
-	i = strlen(msg);
+static int
+oncore_log_f(
+	struct instance *	instance,
+	int			log_level,
+	const char *		fmt,
+	...
+	)
+{
+	va_list	ap;
+	int	rc;
+	char	msg[512];
 
-	if (i > 127) {
-		snprintf(Msg, sizeof(Msg),
-			 "Internal Error: max error msg length exceeded in clockstats file (%d)",
-			 i);
-		record_clock_stats(&(instance->peer->srcadr), Msg);
-		record_clock_stats(&(instance->peer->srcadr), "Start of message was");
-		strncpy(Msg, msg, 120);
-		record_clock_stats(&(instance->peer->srcadr), Msg);
-	} else {	/* now put ONCORE[n]: ahead of message if it will fit */
-		if (i < 110) {
-			snprintf(Msg, sizeof(Msg), "ONCORE[%d]: %s",
-				 instance->unit, msg);
-			record_clock_stats(&(instance->peer->srcadr), Msg);
-		} else
-			record_clock_stats(&(instance->peer->srcadr), msg);
-	}
+	va_start(ap, fmt);
+	rc = mvsnprintf(msg, sizeof(msg), fmt, ap);
+	va_end(ap);
+	oncore_log(instance, log_level, msg);
 
 #ifdef ONCORE_VERBOSE_ONCORE_LOG
-	instance->max_len = max(i, instance->max_len);
+	instance->max_len = max(strlen(msg), instance->max_len);
 	instance->max_count++;
-	if (instance->max_count % 100 == 0) {
-		snprintf(Msg, sizeof(Msg),
-			 "Max Message Length so far is %d",
-			 instance->max_len);
-		oncore_log(instance, LOG_INFO, Msg);
-	}
+	if (instance->max_count % 100 == 0)
+		oncore_log_f(instance, LOG_INFO,
+			    "Max Message Length so far is %d",
+			    instance->max_len);
 #endif
+	return rc;
 }
 
 #else
diff --git a/ntpd/refclock_parse.c b/ntpd/refclock_parse.c
index eaceaff98..074922a0d 100644
--- a/ntpd/refclock_parse.c
+++ b/ntpd/refclock_parse.c
@@ -3243,7 +3243,7 @@ parse_start(
 static void
 parse_ctl(
 	    struct parseunit *parse,
-	    struct refclockstat *in
+	    const struct refclockstat *in
 	    )
 {
         if (in)