*** sftp-server.c.orig	Tue May  6 09:49:56 2003
--- sftp-server.c	Tue May  6 11:04:56 2003
***************
*** 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)
  {
***************
*** 372,377 ****
--- 425,433 ----
  
  	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);
***************
*** 385,390 ****
--- 441,449 ----
  	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();
***************
*** 392,409 ****
--- 451,480 ----
  	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, 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)
***************
*** 592,614 ****
  	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);
--- 663,710 ----
  	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);
***************
*** 631,641 ****
  	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
--- 727,746 ----
  	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
***************
*** 643,650 ****
  #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
--- 748,761 ----
  #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
***************
*** 652,659 ****
  #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
--- 763,776 ----
  #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
***************
*** 661,668 ****
  #else
  			ret = chown(name, a->uid, a->gid);
  #endif
! 			if (ret == -1)
  				status = errno_to_portable(errno);
  		}
  	}
  	send_status(id, status);
--- 778,791 ----
  #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);
***************
*** 764,770 ****
  	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);
  }
--- 887,903 ----
  	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);
  }
***************
*** 784,790 ****
  	    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);
  }
--- 917,934 ----
  	    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);
  }
***************
*** 800,806 ****
  	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);
  }
--- 944,961 ----
  	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,865 ****
  	newpath = get_string(NULL);
  	TRACE("rename id %u old %s new %s", id, oldpath, newpath);
  	status = SSH2_FX_FAILURE;
! 	if (lstat(oldpath, &sb) == -1)
  		status = errno_to_portable(errno);
! 	else if (S_ISREG(sb.st_mode)) {
  		/* Race-free rename of regular files */
! 		if (link(oldpath, newpath) == -1)
  			status = errno_to_portable(errno);
! 		else if (unlink(oldpath) == -1) {
  			status = errno_to_portable(errno);
  			/* clean spare link */
  			unlink(newpath);
! 		} else
  			status = SSH2_FX_OK;
  	} else if (stat(newpath, &sb) == -1) {
! 		if (rename(oldpath, newpath) == -1)
  			status = errno_to_portable(errno);
! 		else
  			status = SSH2_FX_OK;
  	}
  	send_status(id, status);
  	xfree(oldpath);
--- 998,1040 ----
  	newpath = get_string(NULL);
  	TRACE("rename id %u old %s new %s", id, oldpath, newpath);
  	status = SSH2_FX_FAILURE;
! 	if (lstat(oldpath, &sb) == -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 if (S_ISREG(sb.st_mode)) {
  		/* Race-free rename of regular files */
! 		if (link(oldpath, newpath) == -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 if (unlink(oldpath) == -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
  			/* clean spare link */
  			unlink(newpath);
! 		} else {
  			status = SSH2_FX_OK;
+ #ifdef SFTP_LOGGING
+ 			log("(%d/%d/%s) File/Dir renamed: %s -> %s.", ppid, cuid, CUNAME, oldpath, newpath);
+ #endif
+ 		}
  	} else if (stat(newpath, &sb) == -1) {
! 		if (rename(oldpath, newpath) == -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
+ 		}
  	}
  	send_status(id, status);
  	xfree(oldpath);
***************
*** 917,922 ****
--- 1092,1100 ----
  
  	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);
  }
***************
*** 939,944 ****
--- 1117,1125 ----
  	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)
***************
*** 1033,1038 ****
--- 1214,1238 ----
  	__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
***************
*** 1070,1075 ****
--- 1270,1278 ----
  		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);
  		}
  
***************
*** 1079,1087 ****
--- 1282,1296 ----
  			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);
***************
*** 1092,1097 ****
--- 1301,1309 ----
  			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);