Attachment 1106 Details for Bug 474 – sftp transaction logging

[patch] sftp transaction logging

sftp-server-logging.diff (text/plain), 21.96 KB, created by Damien Miller on 2006-04-01 16:58:34 AEDT

(hide)

Description:

Filename:

MIME Type:

Creator: Damien Miller

Created: 2006-04-01 16:58:34 AEDT

Size: 21.96 KB

patch

obsolete

>Index: servconf.c
>===================================================================
>RCS file: /cvs/src/usr.bin/ssh/servconf.c,v
>retrieving revision 1.150
>diff -u -p -r1.150 servconf.c
>--- servconf.c	25 Mar 2006 13:17:02 -0000	1.150
>+++ servconf.c	1 Apr 2006 05:07:15 -0000
>@@ -411,6 +411,7 @@ process_server_config_line(ServerOptions
> 	ServerOpCodes opcode;
> 	u_short port;
> 	u_int i;
>+	size_t len;
> 
> 	cp = line;
> 	if ((arg = strdelim(&cp)) == NULL)
>@@ -860,6 +861,17 @@ parse_flag:
> 			fatal("%s line %d: Missing subsystem command.",
> 			    filename, linenum);
> 		options->subsystem_command[options->num_subsystems] = xstrdup(arg);
>+
>+		/* Collect arguments (separate to executable) */
>+		p = xstrdup(arg);
>+		len = strlen(p) + 1;
>+		while ((arg = strdelim(&cp)) != NULL && *arg != '\0') {
>+			len += 1 + strlen(arg);
>+			p = xrealloc(p, 1, len);
>+			strlcat(p, " ", len);
>+			strlcat(p, arg, len);
>+		}
>+		options->subsystem_args[options->num_subsystems] = p;
> 		options->num_subsystems++;
> 		break;
> 
>Index: servconf.h
>===================================================================
>RCS file: /cvs/src/usr.bin/ssh/servconf.h,v
>retrieving revision 1.73
>diff -u -p -r1.73 servconf.h
>--- servconf.h	25 Mar 2006 22:22:43 -0000	1.73
>+++ servconf.h	1 Apr 2006 05:07:15 -0000
>@@ -111,6 +111,7 @@ typedef struct {
> 	u_int num_subsystems;
> 	char   *subsystem_name[MAX_SUBSYSTEMS];
> 	char   *subsystem_command[MAX_SUBSYSTEMS];
>+	char   *subsystem_args[MAX_SUBSYSTEMS];
> 
> 	u_int num_accept_env;
> 	char   *accept_env[MAX_ACCEPT_ENV];
>Index: session.c
>===================================================================
>RCS file: /cvs/src/usr.bin/ssh/session.c,v
>retrieving revision 1.202
>diff -u -p -r1.202 session.c
>--- session.c	25 Mar 2006 13:17:02 -0000	1.202
>+++ session.c	1 Apr 2006 05:07:16 -0000
>@@ -1467,7 +1418,7 @@ session_subsystem_req(Session *s)
> 	struct stat st;
> 	u_int len;
> 	int success = 0;
>-	char *cmd, *subsys = packet_get_string(&len);
>+	char *prog, *cmd, *subsys = packet_get_string(&len);
> 	u_int i;
> 
> 	packet_check_eom();
>@@ -1475,9 +1426,10 @@ session_subsystem_req(Session *s)
> 
> 	for (i = 0; i < options.num_subsystems; i++) {
> 		if (strcmp(subsys, options.subsystem_name[i]) == 0) {
>-			cmd = options.subsystem_command[i];
>-			if (stat(cmd, &st) < 0) {
>-				error("subsystem: cannot stat %s: %s", cmd,
>+			prog = options.subsystem_command[i];
>+			cmd = options.subsystem_args[i];
>+			if (stat(prog, &st) < 0) {
>+				error("subsystem: cannot stat %s: %s", prog,
> 				    strerror(errno));
> 				break;
> 			}
>Index: sftp-server.8
>===================================================================
>RCS file: /cvs/src/usr.bin/ssh/sftp-server.8,v
>retrieving revision 1.10
>diff -u -p -r1.10 sftp-server.8
>--- sftp-server.8	8 Oct 2003 08:27:36 -0000	1.10
>+++ sftp-server.8	1 Apr 2006 05:07:16 -0000
>@@ -30,6 +30,10 @@
> .Nd SFTP server subsystem
> .Sh SYNOPSIS
> .Nm sftp-server
>+.Bk -words
>+.Op Fl l Ar log_level
>+.Op Fl f Ar log_facility
>+.Ek
> .Sh DESCRIPTION
> .Nm
> is a program that speaks the server side of SFTP protocol
>@@ -40,9 +44,36 @@ is not intended to be called directly, b
> using the
> .Cm Subsystem
> option.
>+.Pp
>+Command-line flags to
>+.Nm
>+should be specified in the
>+.Cm Subsystem
>+declarations.
> See
> .Xr sshd_config 5
> for more information.
>+.Pp
>+Valid options are:
>+.Bl -tag -width Ds
>+.It Fl l Ar log_level
>+Specifies which messages will be logged by
>+.Nm .
>+The possible values are:
>+QUIET, FATAL, ERROR, INFO, VERBOSE, DEBUG, DEBUG1, DEBUG2, and DEBUG3.
>+INFO and VERBOSE log transactions that
>+.Nm
>+performs on behalf of the client.
>+DEBUG and DEBUG1 are equivalent.
>+DEBUG2 and DEBUG3 each specify higher levels of debugging output.
>+The default is ERROR.
>+.It Fl f Ar log_facility
>+Specifies the facility code that is used when logging messages from
>+.Nm .
>+The possible values are: DAEMON, USER, AUTH, LOCAL0, LOCAL1, LOCAL2,
>+LOCAL3, LOCAL4, LOCAL5, LOCAL6, LOCAL7.
>+The default is AUTH.
>+.El
> .Sh SEE ALSO
> .Xr sftp 1 ,
> .Xr ssh 1 ,
>Index: sftp-server.c
>===================================================================
>RCS file: /cvs/src/usr.bin/ssh/sftp-server.c,v
>retrieving revision 1.57
>diff -u -p -r1.57 sftp-server.c
>--- sftp-server.c	30 Mar 2006 09:58:16 -0000	1.57
>+++ sftp-server.c	1 Apr 2006 05:07:16 -0000
>@@ -34,7 +34,13 @@
> #define get_int64()			buffer_get_int64(&iqueue);
> #define get_int()			buffer_get_int(&iqueue);
> #define get_string(lenp)		buffer_get_string(&iqueue, lenp);
>-#define TRACE				debug
>+
>+/* Our verbosity */
>+LogLevel log_level = SYSLOG_LEVEL_ERROR;
>+
>+/* Our client */
>+char *local_user;
>+char *client_addr;
> 
> /* input and output queue */
> Buffer iqueue;
>@@ -106,6 +112,33 @@ flags_from_portable(int pflags)
> 	return flags;
> }
> 
>+static const char *
>+string_from_portable(int pflags)
>+{
>+	static char ret[128];
>+
>+	*ret = '\0';
>+
>+#define PAPPEND(str)	{				\
>+		if (*ret != '\0')			\
>+			strlcat(ret, ",", sizeof(ret));	\
>+		strlcat(ret, str, sizeof(ret)); 	\
>+	}
>+
>+	if (pflags & SSH2_FXF_READ)
>+		PAPPEND("READ")
>+	if (pflags & SSH2_FXF_WRITE)
>+		PAPPEND("WRITE")
>+	if (pflags & SSH2_FXF_CREAT)
>+		PAPPEND("CREATE")
>+	if (pflags & SSH2_FXF_TRUNC)
>+		PAPPEND("TRUNCATE")
>+	if (pflags & SSH2_FXF_EXCL)
>+		PAPPEND("EXCL")
>+
>+	return ret;
>+}
>+
> static Attrib *
> get_attrib(void)
> {
>@@ -120,6 +153,7 @@ struct Handle {
> 	DIR *dirp;
> 	int fd;
> 	char *name;
>+	u_int64_t bytes_read, bytes_write;
> };
> 
> enum {
>@@ -150,6 +184,7 @@ handle_new(int use, const char *name, in
> 			handles[i].dirp = dirp;
> 			handles[i].fd = fd;
> 			handles[i].name = xstrdup(name);
>+			handles[i].bytes_read = handles[i].bytes_write = 0;
> 			return i;
> 		}
> 	}
>@@ -213,6 +248,36 @@ handle_to_fd(int handle)
> 	return -1;
> }
> 
>+static void
>+handle_update_read(int handle, ssize_t bytes)
>+{
>+	if (handle_is_ok(handle, HANDLE_FILE) && bytes > 0)
>+		handles[handle].bytes_read += bytes;
>+}
>+
>+static void
>+handle_update_write(int handle, ssize_t bytes)
>+{
>+	if (handle_is_ok(handle, HANDLE_FILE) && bytes > 0)
>+		handles[handle].bytes_write += bytes;
>+}
>+
>+static u_int64_t
>+handle_bytes_read(int handle)
>+{
>+	if (handle_is_ok(handle, HANDLE_FILE))
>+		return (handles[handle].bytes_read);
>+	return 0;
>+}
>+
>+static u_int64_t
>+handle_bytes_write(int handle)
>+{
>+	if (handle_is_ok(handle, HANDLE_FILE))
>+		return (handles[handle].bytes_write);
>+	return 0;
>+}
>+
> static int
> handle_close(int handle)
> {
>@@ -258,10 +323,9 @@ send_msg(Buffer *m)
> 	buffer_consume(m, mlen);
> }
> 
>-static void
>-send_status(u_int32_t id, u_int32_t status)
>+static const char *
>+status_to_message(u_int32_t status)
> {
>-	Buffer msg;
> 	const char *status_messages[] = {
> 		"Success",			/* SSH_FX_OK */
> 		"End of file",			/* SSH_FX_EOF */
>@@ -274,15 +338,24 @@ send_status(u_int32_t id, u_int32_t stat
> 		"Operation unsupported",	/* SSH_FX_OP_UNSUPPORTED */
> 		"Unknown error"			/* Others */
> 	};
>+	return (status_messages[MIN(status,SSH2_FX_MAX)]);
>+}
> 
>-	TRACE("sent status id %u error %u", id, status);
>+static void
>+send_status(u_int32_t id, u_int32_t status)
>+{
>+	Buffer msg;
>+
>+	debug3("request %u: sent status %u", id, status);
>+	if (log_level > SYSLOG_LEVEL_VERBOSE ||
>+	    (status != SSH2_FX_OK && status != SSH2_FX_EOF))
>+		logit("sent status %s", status_to_message(status));
> 	buffer_init(&msg);
> 	buffer_put_char(&msg, SSH2_FXP_STATUS);
> 	buffer_put_int(&msg, id);
> 	buffer_put_int(&msg, status);
> 	if (version >= 3) {
>-		buffer_put_cstring(&msg,
>-		    status_messages[MIN(status,SSH2_FX_MAX)]);
>+		buffer_put_cstring(&msg, status_to_message(status));
> 		buffer_put_cstring(&msg, "");
> 	}
> 	send_msg(&msg);
>@@ -304,7 +377,7 @@ send_data_or_handle(char type, u_int32_t
> static void
> send_data(u_int32_t id, const char *data, int dlen)
> {
>-	TRACE("sent data id %u len %d", id, dlen);
>+	debug("request %u: sent data len %d", id, dlen);
> 	send_data_or_handle(SSH2_FXP_DATA, id, data, dlen);
> }
> 
>@@ -315,7 +388,7 @@ send_handle(u_int32_t id, int handle)
> 	int hlen;
> 
> 	handle_to_string(handle, &string, &hlen);
>-	TRACE("sent handle id %u handle %d", id, handle);
>+	debug("request %u: sent handle handle %d", id, handle);
> 	send_data_or_handle(SSH2_FXP_HANDLE, id, string, hlen);
> 	xfree(string);
> }
>@@ -330,7 +403,7 @@ send_names(u_int32_t id, int count, cons
> 	buffer_put_char(&msg, SSH2_FXP_NAME);
> 	buffer_put_int(&msg, id);
> 	buffer_put_int(&msg, count);
>-	TRACE("sent names id %u count %d", id, count);
>+	debug("request %u: sent names count %d", id, count);
> 	for (i = 0; i < count; i++) {
> 		buffer_put_cstring(&msg, stats[i].name);
> 		buffer_put_cstring(&msg, stats[i].long_name);
>@@ -345,7 +418,7 @@ send_attrib(u_int32_t id, const Attrib *
> {
> 	Buffer msg;
> 
>-	TRACE("sent attrib id %u have 0x%x", id, a->flags);
>+	debug("request %u: sent attrib have 0x%x", id, a->flags);
> 	buffer_init(&msg);
> 	buffer_put_char(&msg, SSH2_FXP_ATTRS);
> 	buffer_put_int(&msg, id);
>@@ -362,7 +435,7 @@ process_init(void)
> 	Buffer msg;
> 
> 	version = get_int();
>-	TRACE("client version %d", version);
>+	verbose("received client version %d", version);
> 	buffer_init(&msg);
> 	buffer_put_char(&msg, SSH2_FXP_VERSION);
> 	buffer_put_int(&msg, SSH2_FILEXFER_VERSION);
>@@ -379,12 +452,14 @@ process_open(void)
> 	int handle, fd, flags, mode, status = SSH2_FX_FAILURE;
> 
> 	id = get_int();
>+	debug3("request %u: open flags %d", id, pflags);
> 	name = get_string(NULL);
> 	pflags = get_int();		/* portable flags */
> 	a = get_attrib();
> 	flags = flags_from_portable(pflags);
> 	mode = (a->flags & SSH2_FILEXFER_ATTR_PERMISSIONS) ? a->perm : 0666;
>-	TRACE("open id %u name %s flags %d mode 0%o", id, name, pflags, mode);
>+	logit("open \"%s\" flags %s mode 0%o",
>+	    name, string_from_portable(pflags), mode);
> 	fd = open(name, flags, mode);
> 	if (fd < 0) {
> 		status = errno_to_portable(errno);
>@@ -410,7 +485,13 @@ process_close(void)
> 
> 	id = get_int();
> 	handle = get_handle();
>-	TRACE("close id %u handle %d", id, handle);
>+	debug3("request %u: close handle %u", id, handle);
>+	if (handle_is_ok(handle, HANDLE_FILE)) {
>+		logit("close \"%s\" bytes read %llu written %llu",
>+		    handle_to_name(handle),
>+		    handle_bytes_read(handle), handle_bytes_write(handle));
>+	} else
>+		logit("closedir \"%s\"", handle_to_name(handle));
> 	ret = handle_close(handle);
> 	status = (ret == -1) ? errno_to_portable(errno) : SSH2_FX_OK;
> 	send_status(id, status);
>@@ -429,11 +510,11 @@ process_read(void)
> 	off = get_int64();
> 	len = get_int();
> 
>-	TRACE("read id %u handle %d off %llu len %d", id, handle,
>-	    (unsigned long long)off, len);
>+	debug("request %u: read \"%s\" (handle %d) off %llu len %d",
>+	    id, handle_to_name(handle), handle, (unsigned long long)off, len);
> 	if (len > sizeof buf) {
> 		len = sizeof buf;
>-		logit("read change len %d", len);
>+		debug2("read change len %d", len);
> 	}
> 	fd = handle_to_fd(handle);
> 	if (fd >= 0) {
>@@ -449,6 +530,7 @@ process_read(void)
> 			} else {
> 				send_data(id, buf, ret);
> 				status = SSH2_FX_OK;
>+				handle_update_read(handle, ret);
> 			}
> 		}
> 	}
>@@ -470,8 +552,8 @@ process_write(void)
> 	off = get_int64();
> 	data = get_string(&len);
> 
>-	TRACE("write id %u handle %d off %llu len %d", id, handle,
>-	    (unsigned long long)off, len);
>+	debug("request %u: write \"%s\" (handle %d) off %llu len %d",
>+	    id, handle_to_name(handle), handle, (unsigned long long)off, len);
> 	fd = handle_to_fd(handle);
> 	if (fd >= 0) {
> 		if (lseek(fd, off, SEEK_SET) < 0) {
>@@ -485,8 +567,9 @@ process_write(void)
> 				status = errno_to_portable(errno);
> 			} else if ((size_t)ret == len) {
> 				status = SSH2_FX_OK;
>+				handle_update_write(handle, ret);
> 			} else {
>-				logit("nothing at all written");
>+				debug2("nothing at all written");
> 			}
> 		}
> 	}
>@@ -505,7 +588,8 @@ process_do_stat(int do_lstat)
> 
> 	id = get_int();
> 	name = get_string(NULL);
>-	TRACE("%sstat id %u name %s", do_lstat ? "l" : "", id, name);
>+	debug3("request %u: %sstat", id, do_lstat ? "l" : "");
>+	verbose("%sstat name \"%s\"", do_lstat ? "l" : "", name);
> 	ret = do_lstat ? lstat(name, &st) : stat(name, &st);
> 	if (ret < 0) {
> 		status = errno_to_portable(errno);
>@@ -541,7 +625,8 @@ process_fstat(void)
> 
> 	id = get_int();
> 	handle = get_handle();
>-	TRACE("fstat id %u handle %d", id, handle);
>+	debug("request %u: fstat \"%s\" (handle %u)",
>+	    id, handle_to_name(handle), handle);
> 	fd = handle_to_fd(handle);
> 	if (fd  >= 0) {
> 		ret = fstat(fd, &st);
>@@ -580,23 +665,33 @@ process_setstat(void)
> 	id = get_int();
> 	name = get_string(NULL);
> 	a = get_attrib();
>-	TRACE("setstat id %u name %s", id, name);
>+	debug("request %u: setstat name \"%s\"", id, name);
> 	if (a->flags & SSH2_FILEXFER_ATTR_SIZE) {
>+		logit("set \"%s\" size %llu", name, a->size);
> 		ret = truncate(name, a->size);
> 		if (ret == -1)
> 			status = errno_to_portable(errno);
> 	}
> 	if (a->flags & SSH2_FILEXFER_ATTR_PERMISSIONS) {
>+		logit("set \"%s\" mode %04o", name, a->perm);
> 		ret = chmod(name, a->perm & 0777);
> 		if (ret == -1)
> 			status = errno_to_portable(errno);
> 	}
> 	if (a->flags & SSH2_FILEXFER_ATTR_ACMODTIME) {
>+		char buf[64];
>+		time_t t = a->mtime;
>+
>+		strftime(buf, sizeof(buf), "%Y%m%d-%H:%M:%S",
>+		    localtime(&t));
>+		logit("set \"%s\" modtime %s", name, buf);
> 		ret = utimes(name, attrib_to_tv(a));
> 		if (ret == -1)
> 			status = errno_to_portable(errno);
> 	}
> 	if (a->flags & SSH2_FILEXFER_ATTR_UIDGID) {
>+		logit("set \"%s\" owner %lu group %lu", name,
>+		    (u_long)a->uid, (u_long)a->gid);
> 		ret = chown(name, a->uid, a->gid);
> 		if (ret == -1)
> 			status = errno_to_portable(errno);
>@@ -616,27 +711,39 @@ process_fsetstat(void)
> 	id = get_int();
> 	handle = get_handle();
> 	a = get_attrib();
>-	TRACE("fsetstat id %u handle %d", id, handle);
>+	debug("request %u: fsetstat handle %d", id, handle);
> 	fd = handle_to_fd(handle);
> 	if (fd < 0) {
> 		status = SSH2_FX_FAILURE;
> 	} else {
>+		char *name = handle_to_name(handle);
>+
> 		if (a->flags & SSH2_FILEXFER_ATTR_SIZE) {
>+			logit("set \"%s\" size %llu", name, a->size);
> 			ret = ftruncate(fd, a->size);
> 			if (ret == -1)
> 				status = errno_to_portable(errno);
> 		}
> 		if (a->flags & SSH2_FILEXFER_ATTR_PERMISSIONS) {
>+			logit("set \"%s\" mode %04o", name, a->perm);
> 			ret = fchmod(fd, a->perm & 0777);
> 			if (ret == -1)
> 				status = errno_to_portable(errno);
> 		}
> 		if (a->flags & SSH2_FILEXFER_ATTR_ACMODTIME) {
>+			char buf[64];
>+			time_t t = a->mtime;
>+
>+			strftime(buf, sizeof(buf), "%Y%m%d-%H:%M:%S",
>+			    localtime(&t));
>+			logit("set \"%s\" modtime %s", name, buf);
> 			ret = futimes(fd, attrib_to_tv(a));
> 			if (ret == -1)
> 				status = errno_to_portable(errno);
> 		}
> 		if (a->flags & SSH2_FILEXFER_ATTR_UIDGID) {
>+			logit("set \"%s\" owner %lu group %lu", name,
>+			    (u_long)a->uid, (u_long)a->gid);
> 			ret = fchown(fd, a->uid, a->gid);
> 			if (ret == -1)
> 				status = errno_to_portable(errno);
>@@ -655,7 +762,8 @@ process_opendir(void)
> 
> 	id = get_int();
> 	path = get_string(NULL);
>-	TRACE("opendir id %u path %s", id, path);
>+	debug3("request %u: opendir", id);
>+	logit("opendir \"%s\"", path);
> 	dirp = opendir(path);
> 	if (dirp == NULL) {
> 		status = errno_to_portable(errno);
>@@ -685,14 +793,15 @@ process_readdir(void)
> 
> 	id = get_int();
> 	handle = get_handle();
>-	TRACE("readdir id %u handle %d", id, handle);
>+	debug("request %u: readdir \"%s\" (handle %d)", id,
>+	    handle_to_name(handle), handle);
> 	dirp = handle_to_dir(handle);
> 	path = handle_to_name(handle);
> 	if (dirp == NULL || path == NULL) {
> 		send_status(id, SSH2_FX_FAILURE);
> 	} else {
> 		struct stat st;
>-		char pathname[1024];
>+		char pathname[MAXPATHLEN];
> 		Stat *stats;
> 		int nstats = 10, count = 0, i;
> 
>@@ -739,7 +848,8 @@ process_remove(void)
> 
> 	id = get_int();
> 	name = get_string(NULL);
>-	TRACE("remove id %u name %s", id, name);
>+	debug3("request %u: remove", id);
>+	logit("remove name \"%s\"", name);
> 	ret = unlink(name);
> 	status = (ret == -1) ? errno_to_portable(errno) : SSH2_FX_OK;
> 	send_status(id, status);
>@@ -759,7 +869,8 @@ process_mkdir(void)
> 	a = get_attrib();
> 	mode = (a->flags & SSH2_FILEXFER_ATTR_PERMISSIONS) ?
> 	    a->perm & 0777 : 0777;
>-	TRACE("mkdir id %u name %s mode 0%o", id, name, mode);
>+	debug3("request %u: mkdir", id);
>+	logit("mkdir name \"%s\" mode 0%o", name, mode);
> 	ret = mkdir(name, mode);
> 	status = (ret == -1) ? errno_to_portable(errno) : SSH2_FX_OK;
> 	send_status(id, status);
>@@ -775,7 +886,8 @@ process_rmdir(void)
> 
> 	id = get_int();
> 	name = get_string(NULL);
>-	TRACE("rmdir id %u name %s", id, name);
>+	debug3("request %u: rmdir", id);
>+	logit("rmdir name \"%s\"", name);
> 	ret = rmdir(name);
> 	status = (ret == -1) ? errno_to_portable(errno) : SSH2_FX_OK;
> 	send_status(id, status);
>@@ -795,7 +907,8 @@ process_realpath(void)
> 		xfree(path);
> 		path = xstrdup(".");
> 	}
>-	TRACE("realpath id %u path %s", id, path);
>+	debug3("request %u: realpath", id);
>+	verbose("realpath \"%s\"", path);
> 	if (realpath(path, resolvedname) == NULL) {
> 		send_status(id, errno_to_portable(errno));
> 	} else {
>@@ -818,7 +931,8 @@ process_rename(void)
> 	id = get_int();
> 	oldpath = get_string(NULL);
> 	newpath = get_string(NULL);
>-	TRACE("rename id %u old %s new %s", id, oldpath, newpath);
>+	debug3("request %u: rename", id);
>+	logit("rename old \"%s\" new \"%s\"", oldpath, newpath);
> 	status = SSH2_FX_FAILURE;
> 	if (lstat(oldpath, &sb) == -1)
> 		status = errno_to_portable(errno);
>@@ -869,7 +983,8 @@ process_readlink(void)
> 
> 	id = get_int();
> 	path = get_string(NULL);
>-	TRACE("readlink id %u path %s", id, path);
>+	debug3("request %u: readlink", id);
>+	verbose("readlink \"%s\"", path);
> 	if ((len = readlink(path, buf, sizeof(buf) - 1)) == -1)
> 		send_status(id, errno_to_portable(errno));
> 	else {
>@@ -893,7 +1008,8 @@ process_symlink(void)
> 	id = get_int();
> 	oldpath = get_string(NULL);
> 	newpath = get_string(NULL);
>-	TRACE("symlink id %u old %s new %s", id, oldpath, newpath);
>+	debug3("request %u: symlink", id);
>+	logit("symlink old \"%s\" new \"%s\"", oldpath, newpath);
> 	/* this will fail if 'newpath' exists */
> 	ret = symlink(oldpath, newpath);
> 	status = (ret == -1) ? errno_to_portable(errno) : SSH2_FX_OK;
>@@ -931,7 +1047,8 @@ process(void)
> 	cp = buffer_ptr(&iqueue);
> 	msg_len = get_u32(cp);
> 	if (msg_len > SFTP_MAX_MSG_LENGTH) {
>-		error("bad message ");
>+		error("bad message from %s local user %s",
>+		    client_addr, local_user);
> 		exit(11);
> 	}
> 	if (buf_len < msg_len + 4)
>@@ -1006,31 +1123,85 @@ process(void)
> 	}
> 	/* discard the remaining bytes from the current packet */
> 	if (buf_len < buffer_len(&iqueue))
>-		fatal("iqueue grows");
>+		fatal("iqueue grew unexpectedly (client %s local user %s)",
>+		    client_addr, local_user);
> 	consumed = buf_len - buffer_len(&iqueue);
> 	if (msg_len < consumed)
>-		fatal("msg_len %d < consumed %d", msg_len, consumed);
>+		fatal("msg_len %d < consumed %d (client %s local user %s)",
>+		    msg_len, consumed, client_addr, local_user);
> 	if (msg_len > consumed)
> 		buffer_consume(&iqueue, msg_len - consumed);
> }
> 
>+static void
>+usage(void)
>+{
>+	extern char *__progname;
>+
>+	fprintf(stderr,
>+	    "usage: %s [-he] [-l log_level] [-f log_facility]\n", __progname);
>+	exit(1);
>+}
>+
> int
>-main(int ac, char **av)
>+main(int argc, char **argv)
> {
> 	fd_set *rset, *wset;
>-	int in, out, max;
>+	int in, out, max, ch, log_stderr = 0;
> 	ssize_t len, olen, set_size;
>+	SyslogFacility log_facility = SYSLOG_FACILITY_AUTH;
>+	char *cp;
>+	struct passwd *pw;
>+
>+	extern int optind;
>+	extern char *optarg;
>+	extern char *__progname;
> 
> 	/* Ensure that fds 0, 1 and 2 are open or directed to /dev/null */
> 	sanitise_stdfd();
> 
>-	/* XXX should use getopt */
>+	log_init(__progname, log_level, log_facility, log_stderr);
> 
>-	handle_init();
>+	while ((ch = getopt(argc, argv, "hef:l:")) != -1) {
>+		switch (ch) {
>+		case 'e':
>+			log_stderr = 1;
>+			break;
>+		case 'l':
>+			log_level = log_level_number(optarg);
>+			if (log_level == SYSLOG_LEVEL_NOT_SET)
>+				error("Invalid log level \"%s\"", optarg);
>+			break;
>+		case 'f':
>+			log_facility = log_facility_number(optarg);
>+			if (log_level == SYSLOG_FACILITY_NOT_SET)
>+				error("Invalid log facility \"%s\"", optarg);
>+			break;
>+		case 'h':
>+		default:
>+			usage();
>+		}
>+	}
>+
>+	log_init(__progname, log_level, log_facility, 1);
> 
>-#ifdef DEBUG_SFTP_SERVER
>-	log_init("sftp-server", SYSLOG_LEVEL_DEBUG1, SYSLOG_FACILITY_AUTH, 0);
>-#endif
>+	if ((cp = getenv("SSH_CONNECTION")) != NULL) {
>+		client_addr = xstrdup(cp);
>+		if ((cp = strchr(client_addr, ' ')) == NULL)
>+			fatal("Malformed SSH_CONNECTION variable: \"%s\"",
>+			    getenv("SSH_CONNECTION"));
>+		*cp = '\0';
>+	} else
>+		client_addr = xstrdup("UNKNOWN");
>+
>+	if ((pw = getpwuid(getuid())) == NULL)
>+		fatal("No user found for uid %lu", (u_long)getuid());
>+	local_user = xstrdup(pw->pw_name);
>+
>+	logit("session opened for client %s local user %s",
>+	    client_addr, local_user);
>+
>+	handle_init();
> 
> 	in = dup(STDIN_FILENO);
> 	out = dup(STDOUT_FILENO);
>@@ -1060,6 +1231,8 @@ main(int ac, char **av)
> 		if (select(max+1, rset, wset, NULL, NULL) < 0) {
> 			if (errno == EINTR)
> 				continue;
>+			error("select %s (client %s local user %s)",
>+			    strerror(errno), client_addr, local_user);
> 			exit(2);
> 		}
> 
>@@ -1069,9 +1242,12 @@ main(int ac, char **av)
> 			len = read(in, buf, sizeof buf);
> 			if (len == 0) {
> 				debug("read eof");
>+				logit("session closed for client %s "
>+				    "local user %s", client_addr, local_user);
> 				exit(0);
> 			} else if (len < 0) {
>-				error("read error");
>+				error("read error %s (client %s local user %s)",
>+				    strerror(errno), client_addr, local_user);
> 				exit(1);
> 			} else {
> 				buffer_append(&iqueue, buf, len);
>@@ -1081,7 +1257,8 @@ main(int ac, char **av)
> 		if (FD_ISSET(out, wset)) {
> 			len = write(out, buffer_ptr(&oqueue), olen);
> 			if (len < 0) {
>-				error("write error");
>+				error("write error %s (client %s local user %s)",
>+				    strerror(errno), client_addr, local_user);
> 				exit(1);
> 			} else {
> 				buffer_consume(&oqueue, len);
>Index: sshd_config.5
>===================================================================
>RCS file: /cvs/src/usr.bin/ssh/sshd_config.5,v
>retrieving revision 1.57
>diff -u -p -r1.57 sshd_config.5
>--- sshd_config.5	14 Mar 2006 16:32:48 -0000	1.57
>+++ sshd_config.5	1 Apr 2006 05:07:17 -0000
>@@ -636,8 +636,8 @@ The default is
> .Dq yes .
> .It Cm Subsystem
> Configures an external subsystem (e.g. file transfer daemon).
>-Arguments should be a subsystem name and a command to execute upon subsystem
>-request.
>+Arguments should be a subsystem name and a command (with optional arguments)
>+to execute upon subsystem request.
> The command
> .Xr sftp-server 8
> implements the

Actions: View | Diff

Attachments on bug 474: 835 | 1010 | 1106 | 1126