*** sftp-server.c.orig	Wed Sep 11 19:54:27 2002
--- sftp-server.c	Fri Oct 18 08:37:02 2002
***************
*** 52,57 ****
--- 52,66 ----
  /* Version of client */
  int version;
  
+ #ifdef SFTP_LOGGING
+ /* User information. */
+ #define CUNAME				cuname ? cuname : "UNKNOWN"
+ struct passwd *upw;
+ uid_t cuid;
+ pid_t ppid;
+ char *cuname;
+ #endif
+ 
  /* portable attibutes, etc. */
  
  typedef struct Stat Stat;
***************
*** 93,98 ****
--- 102,126 ----
  	return ret;
  }
  
+ #ifdef SFTP_LOGGING
+ char*
+ status_to_logstr(int status)
+ {
+ 	switch (status) {
+ 		case SSH2_FX_OK:
+ 			return "Successful";
+ 		case SSH2_FX_NO_SUCH_FILE:
+ 			return "No such file or directory";
+ 		case SSH2_FX_PERMISSION_DENIED:
+ 			return "Permission denied.";
+ 		case SSH2_FX_BAD_MESSAGE:
+ 			return "Bad message";
+ 		default:
+ 			return "Unknown error";
+ 	}
+ }
+ #endif
+ 
  static int
  flags_from_portable(int pflags)
  {
***************
*** 115,120 ****
--- 143,173 ----
  	return flags;
  }
  
+ #ifdef SFTP_LOGGING
+ void
+ sflags_from_portable(char *psflags, int pflags)
+ {
+ 	if (pflags & SSH2_FXF_READ)
+ 		*psflags = 'r';
+ 	psflags++;
+ 	if (pflags & SSH2_FXF_WRITE)
+ 		*psflags = 'w';
+ 	psflags++;
+ 	if (pflags & SSH2_FXF_APPEND)
+ 		*psflags = 'a';
+ 	psflags++;
+ 	if (pflags & SSH2_FXF_CREAT)
+ 		*psflags = 'c';
+ 	psflags++;
+ 	if (pflags & SSH2_FXF_TRUNC)
+ 		*psflags = 't';
+ 	psflags++;
+ 	if (pflags & SSH2_FXF_EXCL)
+ 		*psflags = 'e';
+ 	return;
+ }
+ #endif
+ 
  static Attrib *
  get_attrib(void)
  {
***************
*** 370,375 ****
--- 423,431 ----
  
  	version = get_int();
  	TRACE("client version %d", version);
+ #ifdef SFTP_LOGGING
+ 	log("(%d/%d/%s) Client version %d.", ppid, cuid, CUNAME, version);
+ #endif
  	buffer_init(&msg);
  	buffer_put_char(&msg, SSH2_FXP_VERSION);
  	buffer_put_int(&msg, SSH2_FILEXFER_VERSION);
***************
*** 383,388 ****
--- 439,447 ----
  	u_int32_t id, pflags;
  	Attrib *a;
  	char *name;
+ #ifdef SFTP_LOGGING
+ 	char sflags[7] = "------";
+ #endif
  	int handle, fd, flags, mode, status = SSH2_FX_FAILURE;
  
  	id = get_int();
***************
*** 390,407 ****
--- 449,478 ----
  	pflags = get_int();		/* portable flags */
  	a = get_attrib();
  	flags = flags_from_portable(pflags);
+ #ifdef SFTP_LOGGING
+ 	sflags_from_portable(&sflags[0], pflags);
+ #endif
  	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);
  	fd = open(name, flags, mode);
  	if (fd < 0) {
  		status = errno_to_portable(errno);
+ #ifdef SFTP_LOGGING
+ 		log("(%d/%d/%s) File/Dir open failed - %s: %s (%s,%04o)", ppid, cuid, CUNAME, status_to_logstr(status), name, sflags, mode);
+ #endif
  	} else {
  		handle = handle_new(HANDLE_FILE, xstrdup(name), fd, NULL);
  		if (handle < 0) {
  			close(fd);
+ #ifdef SFTP_LOGGING
+ 			log("(%d/%d/%s) File/Dir open failed - Could not allocate SFTP handle: %s (%s,%04o).", ppid, cuid, CUNAME, name, sflags, mode);
+ #endif
  		} else {
  			send_handle(id, handle);
  			status = SSH2_FX_OK;
+ #ifdef SFTP_LOGGING
+ 			log("(%d/%d/%s) File/Dir opened: %s (%s,%04o).", ppid, cuid, CUNAME, name, sflags, mode);
+ #endif
  		}
  	}
  	if (status != SSH2_FX_OK)
***************
*** 590,612 ****
  	TRACE("setstat id %u name %s", id, name);
  	if (a->flags & SSH2_FILEXFER_ATTR_SIZE) {
  		ret = truncate(name, a->size);
! 		if (ret == -1)
  			status = errno_to_portable(errno);
  	}
  	if (a->flags & SSH2_FILEXFER_ATTR_PERMISSIONS) {
  		ret = chmod(name, a->perm & 0777);
! 		if (ret == -1)
  			status = errno_to_portable(errno);
  	}
  	if (a->flags & SSH2_FILEXFER_ATTR_ACMODTIME) {
  		ret = utimes(name, attrib_to_tv(a));
! 		if (ret == -1)
  			status = errno_to_portable(errno);
  	}
  	if (a->flags & SSH2_FILEXFER_ATTR_UIDGID) {
  		ret = chown(name, a->uid, a->gid);
! 		if (ret == -1)
  			status = errno_to_portable(errno);
  	}
  	send_status(id, status);
  	xfree(name);
--- 661,707 ----
  	TRACE("setstat id %u name %s", id, name);
  	if (a->flags & SSH2_FILEXFER_ATTR_SIZE) {
  		ret = truncate(name, a->size);
! 		if (ret == -1) {
  			status = errno_to_portable(errno);
+ #ifdef SFTP_LOGGING
+ 			log("(%d/%d/%s) Truncate file failed - %s: %s.", ppid, cuid, CUNAME, status_to_logstr(status), name);
+ 		} else {
+ 			log("(%d/%d/%s) Truncated file: %s.", ppid, cuid, CUNAME, name);
+ #endif
+ 		}
  	}
  	if (a->flags & SSH2_FILEXFER_ATTR_PERMISSIONS) {
  		ret = chmod(name, a->perm & 0777);
! 		if (ret == -1) {
  			status = errno_to_portable(errno);
+ #ifdef SFTP_LOGGING
+ 			log("(%d/%d/%s) Set file/dir permissions failed - %s: %s (%04o).", ppid, cuid, CUNAME, status_to_logstr(status), name, a->perm & 0777);
+ 		} else {
+ 			log("(%d/%d/%s) Set file/dir permissions: %s (%04o).", ppid, cuid, CUNAME, name, a->perm & 0777);
+ #endif
+ 		}
  	}
  	if (a->flags & SSH2_FILEXFER_ATTR_ACMODTIME) {
  		ret = utimes(name, attrib_to_tv(a));
! 		if (ret == -1) {
  			status = errno_to_portable(errno);
+ #ifdef SFTP_LOGGING
+ 			log("(%d/%d/%s) Set file/dir times failed - %s: %s.", ppid, cuid, CUNAME, status_to_logstr(status), name);
+ 		} else {
+ 			log("(%d/%d/%s) Set file/dir times: %s.", ppid, cuid, CUNAME, name);
+ #endif
+ 		}
  	}
  	if (a->flags & SSH2_FILEXFER_ATTR_UIDGID) {
  		ret = chown(name, a->uid, a->gid);
! 		if (ret == -1) {
  			status = errno_to_portable(errno);
+ #ifdef SFTP_LOGGING
+ 			log("(%d/%d/%s) Set file/dir owner/group failed - %s: %s (%d/%d).", ppid, cuid, CUNAME, status_to_logstr(status), name, a->uid, a->gid);
+ 		} else {
+ 			log("(%d/%d/%s) Set file/dir owner/group: %s (%d/%d).", ppid, cuid, CUNAME, name, a->uid, a->gid);
+ #endif
+ 		}
  	}
  	send_status(id, status);
  	xfree(name);
***************
*** 629,639 ****
  	name = handle_to_name(handle);
  	if (fd < 0 || name == NULL) {
  		status = SSH2_FX_FAILURE;
  	} else {
  		if (a->flags & SSH2_FILEXFER_ATTR_SIZE) {
  			ret = ftruncate(fd, a->size);
! 			if (ret == -1)
  				status = errno_to_portable(errno);
  		}
  		if (a->flags & SSH2_FILEXFER_ATTR_PERMISSIONS) {
  #ifdef HAVE_FCHMOD
--- 724,743 ----
  	name = handle_to_name(handle);
  	if (fd < 0 || name == NULL) {
  		status = SSH2_FX_FAILURE;
+ #ifdef SFTP_LOGGING
+ 		log("(%d/%d/%s) Set file/dir stats failed - could not get name from handle: %d.", ppid, cuid, CUNAME, handle);
+ #endif
  	} else {
  		if (a->flags & SSH2_FILEXFER_ATTR_SIZE) {
  			ret = ftruncate(fd, a->size);
! 			if (ret == -1) {
  				status = errno_to_portable(errno);
+ #ifdef SFTP_LOGGING
+ 				log("(%d/%d/%s) Truncate file failed - %s: %s.", ppid, cuid, CUNAME, status_to_logstr(status), name);
+ 			} else {
+ 				log("(%d/%d/%s) Truncated file: %s.", ppid, cuid, CUNAME, name);
+ #endif
+ 			}
  		}
  		if (a->flags & SSH2_FILEXFER_ATTR_PERMISSIONS) {
  #ifdef HAVE_FCHMOD
***************
*** 641,648 ****
  #else
  			ret = chmod(name, a->perm & 0777);
  #endif
! 			if (ret == -1)
  				status = errno_to_portable(errno);
  		}
  		if (a->flags & SSH2_FILEXFER_ATTR_ACMODTIME) {
  #ifdef HAVE_FUTIMES
--- 745,758 ----
  #else
  			ret = chmod(name, a->perm & 0777);
  #endif
! 			if (ret == -1) {
  				status = errno_to_portable(errno);
+ #ifdef SFTP_LOGGING
+ 				log("(%d/%d/%s) Set file/dir permissions failed - %s: %s (%04o).", ppid, cuid, CUNAME, status_to_logstr(status), name, a->perm & 0777);
+ 			} else {
+ 				log("(%d/%d/%s) Set file/dir permissions: %s (%04o).", ppid, cuid, CUNAME, name, a->perm & 0777);
+ #endif
+ 			}
  		}
  		if (a->flags & SSH2_FILEXFER_ATTR_ACMODTIME) {
  #ifdef HAVE_FUTIMES
***************
*** 650,657 ****
  #else
  			ret = utimes(name, attrib_to_tv(a));
  #endif
! 			if (ret == -1)
  				status = errno_to_portable(errno);
  		}
  		if (a->flags & SSH2_FILEXFER_ATTR_UIDGID) {
  #ifdef HAVE_FCHOWN
--- 760,773 ----
  #else
  			ret = utimes(name, attrib_to_tv(a));
  #endif
! 			if (ret == -1) {
  				status = errno_to_portable(errno);
+ #ifdef SFTP_LOGGING
+ 				log("(%d/%d/%s) Set file/dir times failed - %s: %s.", ppid, cuid, CUNAME, status_to_logstr(status), name);
+ 			} else {
+ 				log("(%d/%d/%s) Set file/dir times: %s.", ppid, cuid, CUNAME, name);
+ #endif
+ 			}
  		}
  		if (a->flags & SSH2_FILEXFER_ATTR_UIDGID) {
  #ifdef HAVE_FCHOWN
***************
*** 659,666 ****
  #else
  			ret = chown(name, a->uid, a->gid);
  #endif
! 			if (ret == -1)
  				status = errno_to_portable(errno);
  		}
  	}
  	send_status(id, status);
--- 775,788 ----
  #else
  			ret = chown(name, a->uid, a->gid);
  #endif
! 			if (ret == -1) {
  				status = errno_to_portable(errno);
+ #ifdef SFTP_LOGGING
+ 				log("(%d/%d/%s) Set file/dir owner/group failed - %s: %s (%d/%d).", ppid, cuid, CUNAME, status_to_logstr(status), name, a->uid, a->gid);
+ 			} else {
+ 				log("(%d/%d/%s) Set file/dir owner/group: %s (%d/%d).", ppid, cuid, CUNAME, name, a->uid, a->gid);
+ #endif
+ 			}
  		}
  	}
  	send_status(id, status);
***************
*** 762,768 ****
  	name = get_string(NULL);
  	TRACE("remove id %u name %s", id, name);
  	ret = unlink(name);
! 	status = (ret == -1) ? errno_to_portable(errno) : SSH2_FX_OK;
  	send_status(id, status);
  	xfree(name);
  }
--- 884,900 ----
  	name = get_string(NULL);
  	TRACE("remove id %u name %s", id, name);
  	ret = unlink(name);
! 	if (ret == -1) {
! 		status = errno_to_portable(errno);
! #ifdef SFTP_LOGGING
! 		log("(%d/%d/%s) File deletion failed - %s: %s.", ppid, cuid, CUNAME, status_to_logstr(status), name);
! #endif
! 	} else {
! 		status = SSH2_FX_OK;
! #ifdef SFTP_LOGGING
! 		log("(%d/%d/%s) File deleted: %s.", ppid, cuid, CUNAME, name);
! #endif
! 	}
  	send_status(id, status);
  	xfree(name);
  }
***************
*** 782,788 ****
  	    a->perm & 0777 : 0777;
  	TRACE("mkdir id %u name %s mode 0%o", id, name, mode);
  	ret = mkdir(name, mode);
! 	status = (ret == -1) ? errno_to_portable(errno) : SSH2_FX_OK;
  	send_status(id, status);
  	xfree(name);
  }
--- 914,930 ----
  	    a->perm & 0777 : 0777;
  	TRACE("mkdir id %u name %s mode 0%o", id, name, mode);
  	ret = mkdir(name, mode);
! 	if (ret == -1) {
! 		status = errno_to_portable(errno);
! #ifdef SFTP_LOGGING
! 		log("(%d/%d/%s) Directory creation failed - %s: %s.", ppid, cuid, CUNAME, status_to_logstr(status), name);
! #endif
! 	} else {
! 		status = SSH2_FX_OK;
! #ifdef SFTP_LOGGING
! 		log("(%d/%d/%s) Directory created: %s.", ppid, cuid, CUNAME, name);
! #endif
! 	}
  	send_status(id, status);
  	xfree(name);
  }
***************
*** 798,804 ****
  	name = get_string(NULL);
  	TRACE("rmdir id %u name %s", id, name);
  	ret = rmdir(name);
! 	status = (ret == -1) ? errno_to_portable(errno) : SSH2_FX_OK;
  	send_status(id, status);
  	xfree(name);
  }
--- 940,956 ----
  	name = get_string(NULL);
  	TRACE("rmdir id %u name %s", id, name);
  	ret = rmdir(name);
! 	if (ret == -1) {
! 		status = errno_to_portable(errno);
! #ifdef SFTP_LOGGING
! 		log("(%d/%d/%s) Directory deletion failed - %s: %s.", ppid, cuid, CUNAME, status_to_logstr(status), name);
! #endif
! 	} else {
! 		status = SSH2_FX_OK;
! #ifdef SFTP_LOGGING
! 		log("(%d/%d/%s) Directory deleted: %s.", ppid, cuid, CUNAME, name);
! #endif
! 	}
  	send_status(id, status);
  	xfree(name);
  }
***************
*** 843,849 ****
  	/* fail if 'newpath' exists */
  	if (stat(newpath, &st) == -1) {
  		ret = rename(oldpath, newpath);
! 		status = (ret == -1) ? errno_to_portable(errno) : SSH2_FX_OK;
  	}
  	send_status(id, status);
  	xfree(oldpath);
--- 995,1015 ----
  	/* fail if 'newpath' exists */
  	if (stat(newpath, &st) == -1) {
  		ret = rename(oldpath, newpath);
! 		if (ret == -1) {
! 			status = errno_to_portable(errno);
! #ifdef SFTP_LOGGING
! 			log("(%d/%d/%s) File/Dir renaming failed - %s: %s -> %s.", ppid, cuid, CUNAME, status_to_logstr(status), oldpath, newpath);
! #endif
! 		} else {
! 			status = SSH2_FX_OK;
! #ifdef SFTP_LOGGING
! 			log("(%d/%d/%s) File/Dir renamed: %s -> %s.", ppid, cuid, CUNAME, oldpath, newpath);
! #endif
! 		}
! #ifdef SFTP_LOGGING
! 	} else {
! 		log("(%d/%d/%s) File/Dir renaming failed - Target name exists: %s -> %s.", ppid, cuid, CUNAME, oldpath, newpath);
! #endif
  	}
  	send_status(id, status);
  	xfree(oldpath);
***************
*** 889,895 ****
  	/* fail if 'newpath' exists */
  	if (stat(newpath, &st) == -1) {
  		ret = symlink(oldpath, newpath);
! 		status = (ret == -1) ? errno_to_portable(errno) : SSH2_FX_OK;
  	}
  	send_status(id, status);
  	xfree(oldpath);
--- 1055,1075 ----
  	/* fail if 'newpath' exists */
  	if (stat(newpath, &st) == -1) {
  		ret = symlink(oldpath, newpath);
! 		if (ret == -1) {
! 			status = errno_to_portable(errno);
! #ifdef SFTP_LOGGING
! 			log("(%d/%d/%s) Symbolic link creation failed - %s: %s -> %s.", ppid, cuid, CUNAME, status_to_logstr(status), oldpath, newpath);
! #endif
! 		} else {
! 			status = SSH2_FX_OK;
! #ifdef SFTP_LOGGING
! 			log("(%d/%d/%s) Symbolic link created: %s -> %s.", ppid, cuid, CUNAME, oldpath, newpath);
! #endif
! 		}
! #ifdef SFTP_LOGGING
! 	} else {
! 		log("(%d/%d/%s) Symbolic link creation failed - Target name exists: %s -> %s.", ppid, cuid, CUNAME, oldpath, newpath);
! #endif
  	}
  	send_status(id, status);
  	xfree(oldpath);
***************
*** 904,909 ****
--- 1084,1092 ----
  
  	id = get_int();
  	request = get_string(NULL);
+ #ifdef SFTP_LOGGING
+ 	log("(%d/%d/%s) Extended operation attempted - Ignoring.", ppid, cuid, CUNAME);
+ #endif
  	send_status(id, SSH2_FX_OP_UNSUPPORTED);		/* MUST */
  	xfree(request);
  }
***************
*** 926,931 ****
--- 1109,1117 ----
  	msg_len = GET_32BIT(cp);
  	if (msg_len > 256 * 1024) {
  		error("bad message ");
+ #ifdef SFTP_LOGGING
+ 		log("(%d/%d/%s) SFTP session closing (%s).", ppid, cuid, CUNAME, "Bad Message");
+ #endif
  		exit(11);
  	}
  	if (buf_len < msg_len + 4)
***************
*** 1020,1025 ****
--- 1206,1230 ----
  	__progname = get_progname(av[0]);
  	handle_init();
  
+ #ifdef SFTP_LOGGING
+ 	/* Initialize the username of the user running the process. */
+ 	cuid = getuid();
+ 	if ((upw = getpwuid(cuid)) == NULL) {
+ 		cuname = NULL;
+ 	} else {
+ 		cuname = xstrdup(upw->pw_name);
+ 	}
+ 
+ 	/* Initialize the parent process ID. */
+ 	ppid = getppid();
+ 
+ 	/* Initialize the logfile. */
+ 	log_init("sftp-server", SYSLOG_LEVEL_INFO, SYSLOG_FACILITY_AUTH, 0);
+ 
+ 	/* Log session start. */
+ 	log("(%d/%d/%s) SFTP session started.", ppid, cuid, CUNAME);
+ #endif
+ 
  #ifdef DEBUG_SFTP_SERVER
  	log_init("sftp-server", SYSLOG_LEVEL_DEBUG1, SYSLOG_FACILITY_AUTH, 0);
  #endif
***************
*** 1057,1062 ****
--- 1262,1270 ----
  		if (select(max+1, rset, wset, NULL, NULL) < 0) {
  			if (errno == EINTR)
  				continue;
+ #ifdef SFTP_LOGGING
+ 			log("(%d/%d/%s) SFTP session closing (%s).", ppid, cuid, CUNAME, "Select Error");
+ #endif
  			exit(2);
  		}
  
***************
*** 1066,1074 ****
--- 1274,1288 ----
  			len = read(in, buf, sizeof buf);
  			if (len == 0) {
  				debug("read eof");
+ #ifdef SFTP_LOGGING
+ 				log("(%d/%d/%s) SFTP session closing (%s).", ppid, cuid, CUNAME, "EOF");
+ #endif
  				exit(0);
  			} else if (len < 0) {
  				error("read error");
+ #ifdef SFTP_LOGGING
+ 				log("(%d/%d/%s) SFTP session closing (%s).", ppid, cuid, CUNAME, "Read Error");
+ #endif
  				exit(1);
  			} else {
  				buffer_append(&iqueue, buf, len);
***************
*** 1079,1084 ****
--- 1293,1301 ----
  			len = write(out, buffer_ptr(&oqueue), olen);
  			if (len < 0) {
  				error("write error");
+ #ifdef SFTP_LOGGING
+ 				log("(%d/%d/%s) SFTP session closing (%s).", ppid, cuid, CUNAME, "Write Error");
+ #endif
  				exit(1);
  			} else {
  				buffer_consume(&oqueue, len);