upstream: use the new variant log macros instead of prepending

__func__ and appending ssh_err(r) manually; ok markus@

OpenBSD-Commit-ID: 1f14b80bcfa85414b2a1a6ff714fb5362687ace8

1 files changed, 252 insertions, 286 deletions

diff --git a/mux.c b/mux.c
index 4dfcc712..24b3d6a0 100644
--- a/mux.c
+++ b/mux.c
@@ -1,4 +1,4 @@
-/* $OpenBSD: mux.c,v 1.84 2020/10/03 09:22:26 djm Exp $ */
+/* $OpenBSD: mux.c,v 1.85 2020/10/18 11:32:01 djm Exp $ */
 /*
  * Copyright (c) 2002-2008 Damien Miller <djm@openbsd.org>
  *
@@ -194,13 +194,13 @@ mux_master_session_cleanup_cb(struct ssh *ssh, int cid, void *unused)
 {
 	Channel *cc, *c = channel_by_id(ssh, cid);
 
-	debug3("%s: entering for channel %d", __func__, cid);
+	debug3_f("entering for channel %d", cid);
 	if (c == NULL)
-		fatal("%s: channel_by_id(%i) == NULL", __func__, cid);
+		fatal_f("channel_by_id(%i) == NULL", cid);
 	if (c->ctl_chan != -1) {
 		if ((cc = channel_by_id(ssh, c->ctl_chan)) == NULL)
-			fatal("%s: channel %d missing control channel %d",
-			    __func__, c->self, c->ctl_chan);
+			fatal_f("channel %d missing control channel %d",
+			    c->self, c->ctl_chan);
 		c->ctl_chan = -1;
 		cc->remote_id = 0;
 		cc->have_remote_id = 0;
@@ -216,19 +216,19 @@ mux_master_control_cleanup_cb(struct ssh *ssh, int cid, void *unused)
 {
 	Channel *sc, *c = channel_by_id(ssh, cid);
 
-	debug3("%s: entering for channel %d", __func__, cid);
+	debug3_f("entering for channel %d", cid);
 	if (c == NULL)
-		fatal("%s: channel_by_id(%i) == NULL", __func__, cid);
+		fatal_f("channel_by_id(%i) == NULL", cid);
 	if (c->have_remote_id) {
 		if ((sc = channel_by_id(ssh, c->remote_id)) == NULL)
-			fatal("%s: channel %d missing session channel %u",
-			    __func__, c->self, c->remote_id);
+			fatal_f("channel %d missing session channel %u",
+			    c->self, c->remote_id);
 		c->remote_id = 0;
 		c->have_remote_id = 0;
 		sc->ctl_chan = -1;
 		if (sc->type != SSH_CHANNEL_OPEN &&
 		    sc->type != SSH_CHANNEL_OPENING) {
-			debug2("%s: channel %d: not open", __func__, sc->self);
+			debug2_f("channel %d: not open", sc->self);
 			chan_mark_dead(ssh, sc);
 		} else {
 			if (sc->istate == CHAN_INPUT_OPEN)
@@ -251,7 +251,7 @@ env_permitted(char *env)
 		return 0;
 	ret = snprintf(name, sizeof(name), "%.*s", (int)(cp - env), env);
 	if (ret <= 0 || (size_t)ret >= sizeof(name)) {
-		error("%s: name '%.100s...' too long", __func__, env);
+		error_f("name '%.100s...' too long", env);
 		return 0;
 	}
 
@@ -273,21 +273,21 @@ mux_master_process_hello(struct ssh *ssh, u_int rid,
 	int r;
 
 	if (state == NULL)
-		fatal("%s: channel %d: c->mux_ctx == NULL", __func__, c->self);
+		fatal_f("channel %d: c->mux_ctx == NULL", c->self);
 	if (state->hello_rcvd) {
-		error("%s: HELLO received twice", __func__);
+		error_f("HELLO received twice");
 		return -1;
 	}
 	if ((r = sshbuf_get_u32(m, &ver)) != 0) {
-		error("%s: malformed message: %s", __func__, ssh_err(r));
+		error_fr(r, "parse");
 		return -1;
 	}
 	if (ver != SSHMUX_VER) {
-		error("%s: unsupported multiplexing protocol version %u "
-		    "(expected %u)", __func__, ver, SSHMUX_VER);
+		error_f("unsupported multiplexing protocol version %u "
+		    "(expected %u)", ver, SSHMUX_VER);
 		return -1;
 	}
-	debug2("%s: channel %d client version %u", __func__, c->self, ver);
+	debug2_f("channel %d client version %u", c->self, ver);
 
 	/* No extensions are presently defined */
 	while (sshbuf_len(m) > 0) {
@@ -296,12 +296,11 @@ mux_master_process_hello(struct ssh *ssh, u_int rid,
 
 		if ((r = sshbuf_get_cstring(m, &name, NULL)) != 0 ||
 		    (r = sshbuf_get_string_direct(m, NULL, &value_len)) != 0) {
-			error("%s: malformed extension: %s",
-			    __func__, ssh_err(r));
+			error_fr(r, "parse extension");
 			return -1;
 		}
-		debug2("%s: Unrecognised extension \"%s\" length %zu",
-		    __func__, name, value_len);
+		debug2_f("Unrecognised extension \"%s\" length %zu",
+		    name, value_len);
 		free(name);
 	}
 	state->hello_rcvd = 1;
@@ -316,7 +315,7 @@ reply_ok(struct sshbuf *reply, u_int rid)
 
 	if ((r = sshbuf_put_u32(reply, MUX_S_OK)) != 0 ||
 	    (r = sshbuf_put_u32(reply, rid)) != 0)
-		fatal("%s: reply: %s", __func__, ssh_err(r));
+		fatal_fr(r, "reply");
 }
 
 /* Enqueue an error response to the reply buffer */
@@ -328,7 +327,7 @@ reply_error(struct sshbuf *reply, u_int type, u_int rid, const char *msg)
 	if ((r = sshbuf_put_u32(reply, type)) != 0 ||
 	    (r = sshbuf_put_u32(reply, rid)) != 0 ||
 	    (r = sshbuf_put_cstring(reply, msg)) != 0)
-		fatal("%s: reply: %s", __func__, ssh_err(r));
+		fatal_fr(r, "reply");
 }
 
 static int
@@ -363,7 +362,7 @@ mux_master_process_new_session(struct ssh *ssh, u_int rid,
 		free(cctx->env);
 		free(cctx->term);
 		free(cctx);
-		error("%s: malformed message", __func__);
+		error_f("malformed message");
 		return -1;
 	}
 
@@ -380,29 +379,28 @@ mux_master_process_new_session(struct ssh *ssh, u_int rid,
 		cctx->env[env_len++] = cp;
 		cctx->env[env_len] = NULL;
 		if (env_len > MUX_MAX_ENV_VARS) {
-			error("%s: >%d environment variables received, "
-			    "ignoring additional", __func__, MUX_MAX_ENV_VARS);
+			error_f(">%d environment variables received, "
+			    "ignoring additional", MUX_MAX_ENV_VARS);
 			break;
 		}
 	}
 
-	debug2("%s: channel %d: request tty %d, X %d, agent %d, subsys %d, "
-	    "term \"%s\", cmd \"%s\", env %u", __func__, c->self,
+	debug2_f("channel %d: request tty %d, X %d, agent %d, subsys %d, "
+	    "term \"%s\", cmd \"%s\", env %u", c->self,
 	    cctx->want_tty, cctx->want_x_fwd, cctx->want_agent_fwd,
 	    cctx->want_subsys, cctx->term, cmd, env_len);
 
 	if ((cctx->cmd = sshbuf_new()) == NULL)
-		fatal("%s: sshbuf_new", __func__);
+		fatal_f("sshbuf_new");
 	if ((r = sshbuf_put(cctx->cmd, cmd, strlen(cmd))) != 0)
-		fatal("%s: sshbuf_put: %s", __func__, ssh_err(r));
+		fatal_fr(r, "sshbuf_put");
 	free(cmd);
 	cmd = NULL;
 
 	/* Gather fds from client */
 	for(i = 0; i < 3; i++) {
 		if ((new_fd[i] = mm_receive_fd(c->sock)) == -1) {
-			error("%s: failed to receive fd %d from client",
-			    __func__, i);
+			error_f("failed to receive fd %d from client", i);
 			for (j = 0; j < i; j++)
 				close(new_fd[j]);
 			for (j = 0; j < env_len; j++)
@@ -417,12 +415,12 @@ mux_master_process_new_session(struct ssh *ssh, u_int rid,
 		}
 	}
 
-	debug3("%s: got fds stdin %d, stdout %d, stderr %d", __func__,
+	debug3_f("got fds stdin %d, stdout %d, stderr %d",
 	    new_fd[0], new_fd[1], new_fd[2]);
 
 	/* XXX support multiple child sessions in future */
 	if (c->have_remote_id) {
-		debug2("%s: session already open", __func__);
+		debug2_f("session already open");
 		reply_error(reply, MUX_S_FAILURE, rid,
 		    "Multiple sessions not supported");
  cleanup:
@@ -443,7 +441,7 @@ mux_master_process_new_session(struct ssh *ssh, u_int rid,
 	if (options.control_master == SSHCTL_MASTER_ASK ||
 	    options.control_master == SSHCTL_MASTER_AUTO_ASK) {
 		if (!ask_permission("Allow shared connection to %s? ", host)) {
-			debug2("%s: session refused by user", __func__);
+			debug2_f("session refused by user");
 			reply_error(reply, MUX_S_PERMISSION_DENIED, rid,
 			    "Permission denied");
 			goto cleanup;
@@ -452,7 +450,7 @@ mux_master_process_new_session(struct ssh *ssh, u_int rid,
 
 	/* Try to pick up ttymodes from client before it goes raw */
 	if (cctx->want_tty && tcgetattr(new_fd[0], &cctx->tio) == -1)
-		error("%s: tcgetattr: %s", __func__, strerror(errno));
+		error_f("tcgetattr: %s", strerror(errno));
 
 	/* enable nonblocking unless tty */
 	if (!isatty(new_fd[0]))
@@ -484,8 +482,8 @@ mux_master_process_new_session(struct ssh *ssh, u_int rid,
 		    client_new_escape_filter_ctx((int)escape_char));
 	}
 
-	debug2("%s: channel_new: %d linked to control channel %d",
-	    __func__, nc->self, nc->ctl_chan);
+	debug2_f("channel_new: %d linked to control channel %d",
+	    nc->self, nc->ctl_chan);
 
 	channel_send_open(ssh, nc->self);
 	channel_register_open_confirm(ssh, nc->self, mux_session_confirm, cctx);
@@ -503,13 +501,13 @@ mux_master_process_alive_check(struct ssh *ssh, u_int rid,
 {
 	int r;
 
-	debug2("%s: channel %d: alive check", __func__, c->self);
+	debug2_f("channel %d: alive check", c->self);
 
 	/* prepare reply */
 	if ((r = sshbuf_put_u32(reply, MUX_S_ALIVE)) != 0 ||
 	    (r = sshbuf_put_u32(reply, rid)) != 0 ||
 	    (r = sshbuf_put_u32(reply, (u_int)getpid())) != 0)
-		fatal("%s: reply: %s", __func__, ssh_err(r));
+		fatal_fr(r, "reply");
 
 	return 0;
 }
@@ -518,13 +516,13 @@ static int
 mux_master_process_terminate(struct ssh *ssh, u_int rid,
     Channel *c, struct sshbuf *m, struct sshbuf *reply)
 {
-	debug2("%s: channel %d: terminate request", __func__, c->self);
+	debug2_f("channel %d: terminate request", c->self);
 
 	if (options.control_master == SSHCTL_MASTER_ASK ||
 	    options.control_master == SSHCTL_MASTER_AUTO_ASK) {
 		if (!ask_permission("Terminate shared connection to %s? ",
 		    host)) {
-			debug2("%s: termination refused by user", __func__);
+			debug2_f("termination refused by user");
 			reply_error(reply, MUX_S_PERMISSION_DENIED, rid,
 			    "Permission denied");
 			return 0;
@@ -568,7 +566,7 @@ format_forward(u_int ftype, struct Forward *fwd)
 		    fwd->connect_host, fwd->connect_port);
 		break;
 	default:
-		fatal("%s: unknown forward type %u", __func__, ftype);
+		fatal_f("unknown forward type %u", ftype);
 	}
 	return ret;
 }
@@ -615,11 +613,11 @@ mux_confirm_remote_forward(struct ssh *ssh, int type, u_int32_t seq, void *ctxt)
 
 	if ((c = channel_by_id(ssh, fctx->cid)) == NULL) {
 		/* no channel for reply */
-		error("%s: unknown channel", __func__);
+		error_f("unknown channel");
 		return;
 	}
 	if ((out = sshbuf_new()) == NULL)
-		fatal("%s: sshbuf_new", __func__);
+		fatal_f("sshbuf_new");
 	if (fctx->fid >= options.num_remote_forwards ||
 	    (options.remote_forwards[fctx->fid].connect_path == NULL &&
 	    options.remote_forwards[fctx->fid].connect_host == NULL)) {
@@ -627,15 +625,14 @@ mux_confirm_remote_forward(struct ssh *ssh, int type, u_int32_t seq, void *ctxt)
 		goto fail;
 	}
 	rfwd = &options.remote_forwards[fctx->fid];
-	debug("%s: %s for: listen %d, connect %s:%d", __func__,
+	debug_f("%s for: listen %d, connect %s:%d",
 	    type == SSH2_MSG_REQUEST_SUCCESS ? "success" : "failure",
 	    rfwd->listen_port, rfwd->connect_path ? rfwd->connect_path :
 	    rfwd->connect_host, rfwd->connect_port);
 	if (type == SSH2_MSG_REQUEST_SUCCESS) {
 		if (rfwd->listen_port == 0) {
 			if ((r = sshpkt_get_u32(ssh, &port)) != 0)
-				fatal("%s: packet error: %s",
-				    __func__, ssh_err(r));
+				fatal_fr(r, "parse port");
 			if (port > 65535) {
 				fatal("Invalid allocated port %u for "
 				    "mux remote forward to %s:%d", port,
@@ -650,7 +647,7 @@ mux_confirm_remote_forward(struct ssh *ssh, int type, u_int32_t seq, void *ctxt)
 			    (r = sshbuf_put_u32(out, fctx->rid)) != 0 ||
 			    (r = sshbuf_put_u32(out,
 			    rfwd->allocated_port)) != 0)
-				fatal("%s: reply: %s", __func__, ssh_err(r));
+				fatal_fr(r, "reply");
 			channel_update_permission(ssh, rfwd->handle,
 			   rfwd->allocated_port);
 		} else {
@@ -667,8 +664,8 @@ mux_confirm_remote_forward(struct ssh *ssh, int type, u_int32_t seq, void *ctxt)
 			xasprintf(&failmsg, "remote port forwarding failed for "
 			    "listen port %d", rfwd->listen_port);
 
-                debug2("%s: clearing registered forwarding for listen %d, "
-		    "connect %s:%d", __func__, rfwd->listen_port,
+                debug2_f("clearing registered forwarding for listen %d, "
+		    "connect %s:%d", rfwd->listen_port,
 		    rfwd->connect_path ? rfwd->connect_path :
 		    rfwd->connect_host, rfwd->connect_port);
 
@@ -679,15 +676,15 @@ mux_confirm_remote_forward(struct ssh *ssh, int type, u_int32_t seq, void *ctxt)
 		memset(rfwd, 0, sizeof(*rfwd));
 	}
  fail:
-	error("%s: %s", __func__, failmsg);
+	error_f("%s", failmsg);
 	reply_error(out, MUX_S_FAILURE, fctx->rid, failmsg);
 	free(failmsg);
  out:
 	if ((r = sshbuf_put_stringb(c->output, out)) != 0)
-		fatal("%s: sshbuf_put_stringb: %s", __func__, ssh_err(r));
+		fatal_fr(r, "enqueue");
 	sshbuf_free(out);
 	if (c->mux_pause <= 0)
-		fatal("%s: mux_pause %d", __func__, c->mux_pause);
+		fatal_f("mux_pause %d", c->mux_pause);
 	c->mux_pause = 0; /* start processing messages again */
 }
 
@@ -712,7 +709,7 @@ mux_master_process_open_fwd(struct ssh *ssh, u_int rid,
 	    (r = sshbuf_get_u32(m, &cport)) != 0 ||
 	    (lport != (u_int)PORT_STREAMLOCAL && lport > 65535) ||
 	    (cport != (u_int)PORT_STREAMLOCAL && cport > 65535)) {
-		error("%s: malformed message", __func__);
+		error_f("malformed message");
 		ret = -1;
 		goto out;
 	}
@@ -737,12 +734,12 @@ mux_master_process_open_fwd(struct ssh *ssh, u_int rid,
 	else
 		fwd.connect_host = connect_addr;
 
-	debug2("%s: channel %d: request %s", __func__, c->self,
+	debug2_f("channel %d: request %s", c->self,
 	    (fwd_desc = format_forward(ftype, &fwd)));
 
 	if (ftype != MUX_FWD_LOCAL && ftype != MUX_FWD_REMOTE &&
 	    ftype != MUX_FWD_DYNAMIC) {
-		logit("%s: invalid forwarding type %u", __func__, ftype);
+		logit_f("invalid forwarding type %u", ftype);
  invalid:
 		free(listen_addr);
 		free(connect_addr);
@@ -751,26 +748,25 @@ mux_master_process_open_fwd(struct ssh *ssh, u_int rid,
 		return 0;
 	}
 	if (ftype == MUX_FWD_DYNAMIC && fwd.listen_path) {
-		logit("%s: streamlocal and dynamic forwards "
-		    "are mutually exclusive", __func__);
+		logit_f("streamlocal and dynamic forwards "
+		    "are mutually exclusive");
 		goto invalid;
 	}
 	if (fwd.listen_port != PORT_STREAMLOCAL && fwd.listen_port >= 65536) {
-		logit("%s: invalid listen port %u", __func__,
-		    fwd.listen_port);
+		logit_f("invalid listen port %u", fwd.listen_port);
 		goto invalid;
 	}
 	if ((fwd.connect_port != PORT_STREAMLOCAL &&
 	    fwd.connect_port >= 65536) ||
 	    (ftype != MUX_FWD_DYNAMIC && ftype != MUX_FWD_REMOTE &&
 	    fwd.connect_port == 0)) {
-		logit("%s: invalid connect port %u", __func__,
+		logit_f("invalid connect port %u",
 		    fwd.connect_port);
 		goto invalid;
 	}
 	if (ftype != MUX_FWD_DYNAMIC && fwd.connect_host == NULL &&
 	    fwd.connect_path == NULL) {
-		logit("%s: missing connect host", __func__);
+		logit_f("missing connect host");
 		goto invalid;
 	}
 
@@ -782,8 +778,7 @@ mux_master_process_open_fwd(struct ssh *ssh, u_int rid,
 			if (compare_forward(&fwd,
 			    options.local_forwards + i)) {
  exists:
-				debug2("%s: found existing forwarding",
-				    __func__);
+				debug2_f("found existing forwarding");
 				reply_ok(reply, rid);
 				goto out;
 			}
@@ -795,13 +790,13 @@ mux_master_process_open_fwd(struct ssh *ssh, u_int rid,
 				continue;
 			if (fwd.listen_port != 0)
 				goto exists;
-			debug2("%s: found allocated port", __func__);
+			debug2_f("found allocated port");
 			if ((r = sshbuf_put_u32(reply,
 			    MUX_S_REMOTE_PORT)) != 0 ||
 			    (r = sshbuf_put_u32(reply, rid)) != 0 ||
 			    (r = sshbuf_put_u32(reply,
 			    options.remote_forwards[i].allocated_port)) != 0)
-				fatal("%s: reply: %s", __func__, ssh_err(r));
+				fatal_fr(r, "reply FWD_REMOTE");
 			goto out;
 		}
 		break;
@@ -810,7 +805,7 @@ mux_master_process_open_fwd(struct ssh *ssh, u_int rid,
 	if (options.control_master == SSHCTL_MASTER_ASK ||
 	    options.control_master == SSHCTL_MASTER_AUTO_ASK) {
 		if (!ask_permission("Open %s on %s?", fwd_desc, host)) {
-			debug2("%s: forwarding refused by user", __func__);
+			debug2_f("forwarding refused by user");
 			reply_error(reply, MUX_S_PERMISSION_DENIED, rid,
 			    "Permission denied");
 			goto out;
@@ -821,7 +816,7 @@ mux_master_process_open_fwd(struct ssh *ssh, u_int rid,
 		if (!channel_setup_local_fwd_listener(ssh, &fwd,
 		    &options.fwd_opts)) {
  fail:
-			logit("%s: requested %s failed", __func__, fwd_desc);
+			logit_f("requested %s failed", fwd_desc);
 			reply_error(reply, MUX_S_FAILURE, rid,
 			    "Port forwarding failed");
 			goto out;
@@ -879,7 +874,7 @@ mux_master_process_close_fwd(struct ssh *ssh, u_int rid,
 	    (r = sshbuf_get_u32(m, &cport)) != 0 ||
 	    (lport != (u_int)PORT_STREAMLOCAL && lport > 65535) ||
 	    (cport != (u_int)PORT_STREAMLOCAL && cport > 65535)) {
-		error("%s: malformed message", __func__);
+		error_f("malformed message");
 		ret = -1;
 		goto out;
 	}
@@ -905,7 +900,7 @@ mux_master_process_close_fwd(struct ssh *ssh, u_int rid,
 	else
 		fwd.connect_host = connect_addr;
 
-	debug2("%s: channel %d: request cancel %s", __func__, c->self,
+	debug2_f("channel %d: request cancel %s", c->self,
 	    (fwd_desc = format_forward(ftype, &fwd)));
 
 	/* make sure this has been requested */
@@ -984,18 +979,16 @@ mux_master_process_stdio_fwd(struct ssh *ssh, u_int rid,
 	    (r = sshbuf_get_cstring(m, &chost, NULL)) != 0 ||
 	    (r = sshbuf_get_u32(m, &cport)) != 0) {
 		free(chost);
-		error("%s: malformed message", __func__);
+		error_f("malformed message");
 		return -1;
 	}
 
-	debug2("%s: channel %d: request stdio fwd to %s:%u",
-	    __func__, c->self, chost, cport);
+	debug2_f("channel %d: stdio fwd to %s:%u", c->self, chost, cport);
 
 	/* Gather fds from client */
 	for(i = 0; i < 2; i++) {
 		if ((new_fd[i] = mm_receive_fd(c->sock)) == -1) {
-			error("%s: failed to receive fd %d from client",
-			    __func__, i);
+			error_f("failed to receive fd %d from client", i);
 			for (j = 0; j < i; j++)
 				close(new_fd[j]);
 			free(chost);
@@ -1007,12 +1000,11 @@ mux_master_process_stdio_fwd(struct ssh *ssh, u_int rid,
 		}
 	}
 
-	debug3("%s: got fds stdin %d, stdout %d", __func__,
-	    new_fd[0], new_fd[1]);
+	debug3_f("got fds stdin %d, stdout %d", new_fd[0], new_fd[1]);
 
 	/* XXX support multiple child sessions in future */
 	if (c->have_remote_id) {
-		debug2("%s: session already open", __func__);
+		debug2_f("session already open");
 		reply_error(reply, MUX_S_FAILURE, rid,
 		    "Multiple sessions not supported");
  cleanup:
@@ -1026,7 +1018,7 @@ mux_master_process_stdio_fwd(struct ssh *ssh, u_int rid,
 	    options.control_master == SSHCTL_MASTER_AUTO_ASK) {
 		if (!ask_permission("Allow forward to %s:%u? ",
 		    chost, cport)) {
-			debug2("%s: stdio fwd refused by user", __func__);
+			debug2_f("stdio fwd refused by user");
 			reply_error(reply, MUX_S_PERMISSION_DENIED, rid,
 			    "Permission denied");
 			goto cleanup;
@@ -1046,8 +1038,7 @@ mux_master_process_stdio_fwd(struct ssh *ssh, u_int rid,
 	c->remote_id = nc->self; 	/* link control -> session channel */
 	c->have_remote_id = 1;
 
-	debug2("%s: channel_new: %d linked to control channel %d",
-	    __func__, nc->self, nc->ctl_chan);
+	debug2_f("channel_new: %d control %d", nc->self, nc->ctl_chan);
 
 	channel_register_cleanup(ssh, nc->self,
 	    mux_master_session_cleanup_cb, 1);
@@ -1071,38 +1062,38 @@ mux_stdio_confirm(struct ssh *ssh, int id, int success, void *arg)
 	int r;
 
 	if (cctx == NULL)
-		fatal("%s: cctx == NULL", __func__);
+		fatal_f("cctx == NULL");
 	if ((c = channel_by_id(ssh, id)) == NULL)
-		fatal("%s: no channel for id %d", __func__, id);
+		fatal_f("no channel for id %d", id);
 	if ((cc = channel_by_id(ssh, c->ctl_chan)) == NULL)
-		fatal("%s: channel %d lacks control channel %d", __func__,
+		fatal_f("channel %d lacks control channel %d",
 		    id, c->ctl_chan);
 	if ((reply = sshbuf_new()) == NULL)
-		fatal("%s: sshbuf_new", __func__);
+		fatal_f("sshbuf_new");
 
 	if (!success) {
-		debug3("%s: sending failure reply", __func__);
+		debug3_f("sending failure reply");
 		reply_error(reply, MUX_S_FAILURE, cctx->rid,
 		    "Session open refused by peer");
 		/* prepare reply */
 		goto done;
 	}
 
-	debug3("%s: sending success reply", __func__);
+	debug3_f("sending success reply");
 	/* prepare reply */
 	if ((r = sshbuf_put_u32(reply, MUX_S_SESSION_OPENED)) != 0 ||
 	    (r = sshbuf_put_u32(reply, cctx->rid)) != 0 ||
 	    (r = sshbuf_put_u32(reply, c->self)) != 0)
-		fatal("%s: reply: %s", __func__, ssh_err(r));
+		fatal_fr(r, "reply");
 
  done:
 	/* Send reply */
 	if ((r = sshbuf_put_stringb(cc->output, reply)) != 0)
-		fatal("%s: sshbuf_put_stringb: %s", __func__, ssh_err(r));
+		fatal_fr(r, "enqueue");
 	sshbuf_free(reply);
 
 	if (cc->mux_pause <= 0)
-		fatal("%s: mux_pause %d", __func__, cc->mux_pause);
+		fatal_f("mux_pause %d", cc->mux_pause);
 	cc->mux_pause = 0; /* start processing messages again */
 	c->open_confirm_ctx = NULL;
 	free(cctx);
@@ -1112,13 +1103,13 @@ static int
 mux_master_process_stop_listening(struct ssh *ssh, u_int rid,
     Channel *c, struct sshbuf *m, struct sshbuf *reply)
 {
-	debug("%s: channel %d: stop listening", __func__, c->self);
+	debug_f("channel %d: stop listening", c->self);
 
 	if (options.control_master == SSHCTL_MASTER_ASK ||
 	    options.control_master == SSHCTL_MASTER_AUTO_ASK) {
 		if (!ask_permission("Disable further multiplexing on shared "
 		    "connection to %s? ", host)) {
-			debug2("%s: stop listen refused by user", __func__);
+			debug2_f("stop listen refused by user");
 			reply_error(reply, MUX_S_PERMISSION_DENIED, rid,
 			    "Permission denied");
 			return 0;
@@ -1144,12 +1135,12 @@ mux_master_process_proxy(struct ssh *ssh, u_int rid,
 {
 	int r;
 
-	debug("%s: channel %d: proxy request", __func__, c->self);
+	debug_f("channel %d: proxy request", c->self);
 
 	c->mux_rcb = channel_proxy_downstream;
 	if ((r = sshbuf_put_u32(reply, MUX_S_PROXY)) != 0 ||
 	    (r = sshbuf_put_u32(reply, rid)) != 0)
-		fatal("%s: reply: %s", __func__, ssh_err(r));
+		fatal_fr(r, "reply");
 
 	return 0;
 }
@@ -1164,7 +1155,7 @@ mux_master_read_cb(struct ssh *ssh, Channel *c)
 	int r, ret = -1;
 
 	if ((out = sshbuf_new()) == NULL)
-		fatal("%s: sshbuf_new", __func__);
+		fatal_f("sshbuf_new");
 
 	/* Setup ctx and  */
 	if (c->mux_ctx == NULL) {
@@ -1176,12 +1167,11 @@ mux_master_read_cb(struct ssh *ssh, Channel *c)
 		/* Send hello */
 		if ((r = sshbuf_put_u32(out, MUX_MSG_HELLO)) != 0 ||
 		    (r = sshbuf_put_u32(out, SSHMUX_VER)) != 0)
-			fatal("%s: reply: %s", __func__, ssh_err(r));
+			fatal_fr(r, "reply");
 		/* no extensions */
 		if ((r = sshbuf_put_stringb(c->output, out)) != 0)
-			fatal("%s: sshbuf_put_stringb: %s",
-			    __func__, ssh_err(r));
-		debug3("%s: channel %d: hello sent", __func__, c->self);
+			fatal_fr(r, "enqueue");
+		debug3_f("channel %d: hello sent", c->self);
 		ret = 0;
 		goto out;
 	}
@@ -1189,21 +1179,21 @@ mux_master_read_cb(struct ssh *ssh, Channel *c)
 	/* Channel code ensures that we receive whole packets */
 	if ((r = sshbuf_froms(c->input, &in)) != 0) {
  malf:
-		error("%s: malformed message", __func__);
+		error_f("malformed message");
 		goto out;
 	}
 
 	if ((r = sshbuf_get_u32(in, &type)) != 0)
 		goto malf;
-	debug3("%s: channel %d packet type 0x%08x len %zu",
-	    __func__, c->self, type, sshbuf_len(in));
+	debug3_f("channel %d packet type 0x%08x len %zu", c->self,
+	    type, sshbuf_len(in));
 
 	if (type == MUX_MSG_HELLO)
 		rid = 0;
 	else {
 		if (!state->hello_rcvd) {
-			error("%s: expected MUX_MSG_HELLO(0x%08x), "
-			    "received 0x%08x", __func__, MUX_MSG_HELLO, type);
+			error_f("expected MUX_MSG_HELLO(0x%08x), "
+			    "received 0x%08x", MUX_MSG_HELLO, type);
 			goto out;
 		}
 		if ((r = sshbuf_get_u32(in, &rid)) != 0)
@@ -1218,16 +1208,14 @@ mux_master_read_cb(struct ssh *ssh, Channel *c)
 		}
 	}
 	if (mux_master_handlers[i].handler == NULL) {
-		error("%s: unsupported mux message 0x%08x", __func__, type);
+		error_f("unsupported mux message 0x%08x", type);
 		reply_error(out, MUX_S_FAILURE, rid, "unsupported request");
 		ret = 0;
 	}
 	/* Enqueue reply packet */
-	if (sshbuf_len(out) != 0) {
-		if ((r = sshbuf_put_stringb(c->output, out)) != 0)
-			fatal("%s: sshbuf_put_stringb: %s",
-			    __func__, ssh_err(r));
-	}
+	if (sshbuf_len(out) != 0 &&
+	    (r = sshbuf_put_stringb(c->output, out)) != 0)
+		fatal_fr(r, "enqueue");
  out:
 	sshbuf_free(in);
 	sshbuf_free(out);
@@ -1241,21 +1229,19 @@ mux_exit_message(struct ssh *ssh, Channel *c, int exitval)
 	Channel *mux_chan;
 	int r;
 
-	debug3("%s: channel %d: exit message, exitval %d", __func__, c->self,
-	    exitval);
+	debug3_f("channel %d: exit message, exitval %d", c->self, exitval);
 
 	if ((mux_chan = channel_by_id(ssh, c->ctl_chan)) == NULL)
-		fatal("%s: channel %d missing mux channel %d",
-		    __func__, c->self, c->ctl_chan);
+		fatal_f("channel %d missing mux %d", c->self, c->ctl_chan);
 
 	/* Append exit message packet to control socket output queue */
 	if ((m = sshbuf_new()) == NULL)
-		fatal("%s: sshbuf_new", __func__);
+		fatal_f("sshbuf_new");
 	if ((r = sshbuf_put_u32(m, MUX_S_EXIT_MESSAGE)) != 0 ||
 	    (r = sshbuf_put_u32(m, c->self)) != 0 ||
 	    (r = sshbuf_put_u32(m, exitval)) != 0 ||
 	    (r = sshbuf_put_stringb(mux_chan->output, m)) != 0)
-		fatal("%s: reply: %s", __func__, ssh_err(r));
+		fatal_fr(r, "reply");
 	sshbuf_free(m);
 }
 
@@ -1266,19 +1252,18 @@ mux_tty_alloc_failed(struct ssh *ssh, Channel *c)
 	Channel *mux_chan;
 	int r;
 
-	debug3("%s: channel %d: TTY alloc failed", __func__, c->self);
+	debug3_f("channel %d: TTY alloc failed", c->self);
 
 	if ((mux_chan = channel_by_id(ssh, c->ctl_chan)) == NULL)
-		fatal("%s: channel %d missing mux channel %d",
-		    __func__, c->self, c->ctl_chan);
+		fatal_f("channel %d missing mux %d", c->self, c->ctl_chan);
 
 	/* Append exit message packet to control socket output queue */
 	if ((m = sshbuf_new()) == NULL)
-		fatal("%s: sshbuf_new", __func__);
+		fatal_f("sshbuf_new");
 	if ((r = sshbuf_put_u32(m, MUX_S_TTY_ALLOC_FAIL)) != 0 ||
 	    (r = sshbuf_put_u32(m, c->self)) != 0 ||
 	    (r = sshbuf_put_stringb(mux_chan->output, m)) != 0)
-		fatal("%s: reply: %s", __func__, ssh_err(r));
+		fatal_fr(r, "reply");
 	sshbuf_free(m);
 }
 
@@ -1313,7 +1298,7 @@ muxserver_listen(struct ssh *ssh)
 	rbuf[sizeof(rbuf) - 1] = '\0';
 	options.control_path = NULL;
 	xasprintf(&options.control_path, "%s.%s", orig_control_path, rbuf);
-	debug3("%s: temporary control path %s", __func__, options.control_path);
+	debug3_f("temporary control path %s", options.control_path);
 
 	old_umask = umask(0177);
 	muxserver_sock = unix_listener(options.control_path, 64, 0);
@@ -1342,7 +1327,7 @@ muxserver_listen(struct ssh *ssh)
 	/* Now atomically "move" the mux socket into position */
 	if (link(options.control_path, orig_control_path) != 0) {
 		if (errno != EEXIST) {
-			fatal("%s: link mux listener %s => %s: %s", __func__,
+			fatal_f("link mux listener %s => %s: %s",
 			    options.control_path, orig_control_path,
 			    strerror(errno));
 		}
@@ -1362,7 +1347,7 @@ muxserver_listen(struct ssh *ssh)
 	    CHAN_TCP_WINDOW_DEFAULT, CHAN_TCP_PACKET_DEFAULT,
 	    0, options.control_path, 1);
 	mux_listener_channel->mux_rcb = mux_master_read_cb;
-	debug3("%s: mux listener channel %d fd %d", __func__,
+	debug3_f("mux listener channel %d fd %d",
 	    mux_listener_channel->self, mux_listener_channel->sock);
 }
 
@@ -1377,17 +1362,17 @@ mux_session_confirm(struct ssh *ssh, int id, int success, void *arg)
 	struct sshbuf *reply;
 
 	if (cctx == NULL)
-		fatal("%s: cctx == NULL", __func__);
+		fatal_f("cctx == NULL");
 	if ((c = channel_by_id(ssh, id)) == NULL)
-		fatal("%s: no channel for id %d", __func__, id);
+		fatal_f("no channel for id %d", id);
 	if ((cc = channel_by_id(ssh, c->ctl_chan)) == NULL)
-		fatal("%s: channel %d lacks control channel %d", __func__,
+		fatal_f("channel %d lacks control channel %d",
 		    id, c->ctl_chan);
 	if ((reply = sshbuf_new()) == NULL)
-		fatal("%s: sshbuf_new", __func__);
+		fatal_f("sshbuf_new");
 
 	if (!success) {
-		debug3("%s: sending failure reply", __func__);
+		debug3_f("sending failure reply");
 		reply_error(reply, MUX_S_FAILURE, cctx->rid,
 		    "Session open refused by peer");
 		goto done;
@@ -1416,27 +1401,27 @@ mux_session_confirm(struct ssh *ssh, int id, int success, void *arg)
 		debug("Requesting authentication agent forwarding.");
 		channel_request_start(ssh, id, "auth-agent-req@openssh.com", 0);
 		if ((r = sshpkt_send(ssh)) != 0)
-			fatal("%s: packet error: %s", __func__, ssh_err(r));
+			fatal_fr(r, "send");
 	}
 
 	client_session2_setup(ssh, id, cctx->want_tty, cctx->want_subsys,
 	    cctx->term, &cctx->tio, c->rfd, cctx->cmd, cctx->env);
 
-	debug3("%s: sending success reply", __func__);
+	debug3_f("sending success reply");
 	/* prepare reply */
 	if ((r = sshbuf_put_u32(reply, MUX_S_SESSION_OPENED)) != 0 ||
 	    (r = sshbuf_put_u32(reply, cctx->rid)) != 0 ||
 	    (r = sshbuf_put_u32(reply, c->self)) != 0)
-		fatal("%s: reply: %s", __func__, ssh_err(r));
+		fatal_fr(r, "reply");
 
  done:
 	/* Send reply */
 	if ((r = sshbuf_put_stringb(cc->output, reply)) != 0)
-		fatal("%s: sshbuf_put_stringb: %s", __func__, ssh_err(r));
+		fatal_fr(r, "enqueue");
 	sshbuf_free(reply);
 
 	if (cc->mux_pause <= 0)
-		fatal("%s: mux_pause %d", __func__, cc->mux_pause);
+		fatal_f("mux_pause %d", cc->mux_pause);
 	cc->mux_pause = 0; /* start processing messages again */
 	c->open_confirm_ctx = NULL;
 	sshbuf_free(cctx->cmd);
@@ -1485,7 +1470,7 @@ mux_client_read(int fd, struct sshbuf *b, size_t need)
 	pfd.fd = fd;
 	pfd.events = POLLIN;
 	if ((r = sshbuf_reserve(b, need, &p)) != 0)
-		fatal("%s: reserve: %s", __func__, ssh_err(r));
+		fatal_fr(r, "reserve");
 	for (have = 0; have < need; ) {
 		if (muxclient_terminate) {
 			errno = EINTR;
@@ -1527,9 +1512,9 @@ mux_client_write_packet(int fd, struct sshbuf *m)
 	pfd.fd = fd;
 	pfd.events = POLLOUT;
 	if ((queue = sshbuf_new()) == NULL)
-		fatal("%s: sshbuf_new", __func__);
+		fatal_f("sshbuf_new");
 	if ((r = sshbuf_put_stringb(queue, m)) != 0)
-		fatal("%s: sshbuf_put_stringb: %s", __func__, ssh_err(r));
+		fatal_fr(r, "enqueue");
 
 	need = sshbuf_len(queue);
 	ptr = sshbuf_ptr(queue);
@@ -1578,10 +1563,10 @@ mux_client_read_packet(int fd, struct sshbuf *m)
 	int r, oerrno;
 
 	if ((queue = sshbuf_new()) == NULL)
-		fatal("%s: sshbuf_new", __func__);
+		fatal_f("sshbuf_new");
 	if (mux_client_read(fd, queue, 4) != 0) {
 		if ((oerrno = errno) == EPIPE)
-			debug3("%s: read header failed: %s", __func__,
+			debug3_f("read header failed: %s",
 			    strerror(errno));
 		sshbuf_free(queue);
 		errno = oerrno;
@@ -1590,14 +1575,14 @@ mux_client_read_packet(int fd, struct sshbuf *m)
 	need = PEEK_U32(sshbuf_ptr(queue));
 	if (mux_client_read(fd, queue, need) != 0) {
 		oerrno = errno;
-		debug3("%s: read body failed: %s", __func__, strerror(errno));
+		debug3_f("read body failed: %s", strerror(errno));
 		sshbuf_free(queue);
 		errno = oerrno;
 		return -1;
 	}
 	if ((r = sshbuf_get_string_direct(queue, &ptr, &have)) != 0 ||
 	    (r = sshbuf_put(m, ptr, have)) != 0)
-		fatal("%s: buffer error: %s", __func__, ssh_err(r));
+		fatal_fr(r, "dequeue");
 	sshbuf_free(queue);
 	return 0;
 }
@@ -1610,14 +1595,14 @@ mux_client_hello_exchange(int fd)
 	int r, ret = -1;
 
 	if ((m = sshbuf_new()) == NULL)
-		fatal("%s: sshbuf_new", __func__);
+		fatal_f("sshbuf_new");
 	if ((r = sshbuf_put_u32(m, MUX_MSG_HELLO)) != 0 ||
 	    (r = sshbuf_put_u32(m, SSHMUX_VER)) != 0)
-		fatal("%s: hello: %s", __func__, ssh_err(r));
+		fatal_fr(r, "assemble hello");
 	/* no extensions */
 
 	if (mux_client_write_packet(fd, m) != 0) {
-		debug("%s: write packet: %s", __func__, strerror(errno));
+		debug_f("write packet: %s", strerror(errno));
 		goto out;
 	}
 
@@ -1625,33 +1610,31 @@ mux_client_hello_exchange(int fd)
 
 	/* Read their HELLO */
 	if (mux_client_read_packet(fd, m) != 0) {
-		debug("%s: read packet failed", __func__);
+		debug_f("read packet failed");
 		goto out;
 	}
 
 	if ((r = sshbuf_get_u32(m, &type)) != 0)
-		fatal("%s: decode type: %s", __func__, ssh_err(r));
+		fatal_fr(r, "parse type");
 	if (type != MUX_MSG_HELLO) {
-		error("%s: expected HELLO (%u) received %u",
-		    __func__, MUX_MSG_HELLO, type);
+		error_f("expected HELLO (%u) got %u", MUX_MSG_HELLO, type);
 		goto out;
 	}
 	if ((r = sshbuf_get_u32(m, &ver)) != 0)
-		fatal("%s: decode version: %s", __func__, ssh_err(r));
+		fatal_fr(r, "parse version");
 	if (ver != SSHMUX_VER) {
 		error("Unsupported multiplexing protocol version %d "
 		    "(expected %d)", ver, SSHMUX_VER);
 		goto out;
 	}
-	debug2("%s: master version %u", __func__, ver);
+	debug2_f("master version %u", ver);
 	/* No extensions are presently defined */
 	while (sshbuf_len(m) > 0) {
 		char *name = NULL;
 
 		if ((r = sshbuf_get_cstring(m, &name, NULL)) != 0 ||
 		    (r = sshbuf_skip_string(m)) != 0) { /* value */
-			error("%s: malformed extension: %s",
-			    __func__, ssh_err(r));
+			error_fr(r, "parse extension");
 			goto out;
 		}
 		debug2("Unrecognised master extension \"%s\"", name);
@@ -1672,16 +1655,16 @@ mux_client_request_alive(int fd)
 	u_int pid, type, rid;
 	int r;
 
-	debug3("%s: entering", __func__);
+	debug3_f("entering");
 
 	if ((m = sshbuf_new()) == NULL)
-		fatal("%s: sshbuf_new", __func__);
+		fatal_f("sshbuf_new");
 	if ((r = sshbuf_put_u32(m, MUX_C_ALIVE_CHECK)) != 0 ||
 	    (r = sshbuf_put_u32(m, muxclient_request_id)) != 0)
-		fatal("%s: request: %s", __func__, ssh_err(r));
+		fatal_fr(r, "assemble");
 
 	if (mux_client_write_packet(fd, m) != 0)
-		fatal("%s: write packet: %s", __func__, strerror(errno));
+		fatal_f("write packet: %s", strerror(errno));
 
 	sshbuf_reset(m);
 
@@ -1692,23 +1675,23 @@ mux_client_request_alive(int fd)
 	}
 
 	if ((r = sshbuf_get_u32(m, &type)) != 0)
-		fatal("%s: decode type: %s", __func__, ssh_err(r));
+		fatal_fr(r, "parse type");
 	if (type != MUX_S_ALIVE) {
 		if ((r = sshbuf_get_cstring(m, &e, NULL)) != 0)
-			fatal("%s: decode error: %s", __func__, ssh_err(r));
-		fatal("%s: master returned error: %s", __func__, e);
+			fatal_fr(r, "parse error message");
+		fatal_f("master returned error: %s", e);
 	}
 
 	if ((r = sshbuf_get_u32(m, &rid)) != 0)
-		fatal("%s: decode remote ID: %s", __func__, ssh_err(r));
+		fatal_fr(r, "parse remote ID");
 	if (rid != muxclient_request_id)
-		fatal("%s: out of sequence reply: my id %u theirs %u",
-		    __func__, muxclient_request_id, rid);
+		fatal_f("out of sequence reply: my id %u theirs %u",
+		    muxclient_request_id, rid);
 	if ((r = sshbuf_get_u32(m, &pid)) != 0)
-		fatal("%s: decode PID: %s", __func__, ssh_err(r));
+		fatal_fr(r, "parse PID");
 	sshbuf_free(m);
 
-	debug3("%s: done pid = %u", __func__, pid);
+	debug3_f("done pid = %u", pid);
 
 	muxclient_request_id++;
 
@@ -1723,16 +1706,16 @@ mux_client_request_terminate(int fd)
 	u_int type, rid;
 	int r;
 
-	debug3("%s: entering", __func__);
+	debug3_f("entering");
 
 	if ((m = sshbuf_new()) == NULL)
-		fatal("%s: sshbuf_new", __func__);