[dovecot-cvs] dovecot/src/master log.c, NONE, 1.1 log.h, NONE, 1.1 Makefile.am, 1.11, 1.12 auth-process.c, 1.51, 1.52 common.h, 1.17, 1.18 login-process.c, 1.52, 1.53 mail-process.c, 1.41, 1.42 main.c, 1.47, 1.48 master-settings.c, 1.44, 1.45 master-settings.h, 1.27, 1.28

cras at procontrol.fi cras at procontrol.fi
Mon May 10 19:05:13 EEST 2004


Update of /home/cvs/dovecot/src/master
In directory talvi:/tmp/cvs-serv10665/master

Modified Files:
	Makefile.am auth-process.c common.h login-process.c 
	mail-process.c main.c master-settings.c master-settings.h 
Added Files:
	log.c log.h 
Log Message:
Write all logging through master process. Fixes problems with log rotation,
chrooting, etc. Master process also allows max. 10 log messages per second
per child process, it then begins throttling them (eventually making the
child process start blocking on stderr).



--- NEW FILE: log.c ---
/* Copyright (C) 2002 Timo Sirainen */

#include "common.h"
#include "ioloop.h"
#include "istream.h"
#include "fd-close-on-exec.h"
#include "log.h"

#include <unistd.h>

#define MAX_LOG_MESSAGS_PER_SEC 10

struct log_io {
	struct log_io *prev, *next;
	struct io *io;
	struct istream *stream;

	time_t log_stamp;
	unsigned int log_counter;

	char *prefix;
	char next_log_type;
	unsigned int throttle_msg:1;
};

static struct log_io *log_ios;
static struct timeout *to;
static unsigned int throttle_count;

static int log_it(struct log_io *log_io, const char *line, int continues);
static void log_read(void *context);
static void log_io_free(struct log_io *log_io);
static void log_throttle_timeout(void *context);

static int log_write_pending(struct log_io *log_io)
{
	const char *line;

	if (log_io->log_stamp != ioloop_time) {
		log_io->log_stamp = ioloop_time;
		log_io->log_counter = 0;
	}

	while ((line = i_stream_next_line(log_io->stream)) != NULL) {
		if (!log_it(log_io, line, FALSE))
			return FALSE;
	}

	return TRUE;
}

static void log_throttle(struct log_io *log_io)
{
	if (!log_io->throttle_msg) {
                log_io->throttle_msg = TRUE;
		log_it(log_io, "Sending log messages too fast, throttling..",
		       FALSE);
	}

	if (log_io->io != NULL) {
		io_remove(log_io->io);
		log_io->io = NULL;
	}

	if (to == NULL)
		to = timeout_add(1000, log_throttle_timeout, NULL);
        throttle_count++;
}

static void log_unthrottle(struct log_io *log_io)
{
	if (log_io->io != NULL)
		return;

	if (--throttle_count == 0 && to != NULL) {
		timeout_remove(to);
		to = NULL;
	}
	log_io->io = io_add(i_stream_get_fd(log_io->stream),
			    IO_READ, log_read, log_io);
}

static int log_it(struct log_io *log_io, const char *line, int continues)
{
	if (log_io->next_log_type == '\0') {
		if (line[0] == 1 && line[1] != '\0') {
			/* our internal protocol.
			   \001 + log_type */
			log_io->next_log_type = line[1];
			line += 2;
		} else {
			log_io->next_log_type = 'E';
		}
	}

	t_push();
	switch (log_io->next_log_type) {
	case 'I':
		i_info("%s%s", log_io->prefix, line);
		break;
	case 'W':
		i_warning("%s%s", log_io->prefix, line);
		break;
	default:
		i_error("%s%s", log_io->prefix, line);
		break;
	}
	t_pop();

	if (!continues)
		log_io->next_log_type = '\0';

	if (++log_io->log_counter > MAX_LOG_MESSAGS_PER_SEC) {
		log_throttle(log_io);
		return 0;
	}
	return 1;
}

static void log_read(void *context)
{
	struct log_io *log_io = context;
	const unsigned char *data;
	const char *line;
	size_t size;
	int ret;

	if (!log_write_pending(log_io))
		return;

	ret = i_stream_read(log_io->stream);
	if (ret < 0) {
		if (ret == -1) {
			/* closed */
			log_io_free(log_io);
			return;
		}

		/* buffer full. treat it as one line */
		data = i_stream_get_data(log_io->stream, &size);
		line = t_strndup(data, size);
		i_stream_skip(log_io->stream, size);

		if (!log_it(log_io, line, TRUE))
			return;
	}

	if (!log_write_pending(log_io))
		return;

	if (log_io->log_counter < MAX_LOG_MESSAGS_PER_SEC)
		log_unthrottle(log_io);
}

int log_create_pipe(const char *prefix)
{
	struct log_io *log_io;
	int fd[2];

	if (pipe(fd) < 0) {
		i_error("pipe() failed: %m");
		return -1;
	}

	fd_close_on_exec(fd[0], TRUE);
	fd_close_on_exec(fd[1], TRUE);

	log_io = i_new(struct log_io, 1);
	log_io->prefix = i_strdup(prefix);
	log_io->stream = i_stream_create_file(fd[0], default_pool, 1024, TRUE);

	throttle_count++;
        log_unthrottle(log_io);

	if (log_ios != NULL)
		log_ios->prev = log_io;
	log_io->next = log_ios;
	log_ios = log_io;

	return fd[1];
}

static void log_io_free(struct log_io *log_io)
{
	const unsigned char *data;
	size_t size;

	/* if there was something in buffer, write it */
	data = i_stream_get_data(log_io->stream, &size);
	if (size != 0) {
		t_push();
		log_it(log_io, t_strndup(data, size), TRUE);
		t_pop();
	}

	if (log_io == log_ios)
		log_ios = log_io->next;
	else
		log_io->prev->next = log_io->next;
	if (log_io->next != NULL)
		log_io->next->prev = log_io->prev;

	if (log_io->io != NULL)
		io_remove(log_io->io);
	else
		throttle_count--;
	i_stream_unref(log_io->stream);
	i_free(log_io->prefix);
	i_free(log_io);
}

static void log_throttle_timeout(void *context __attr_unused__)
{
	struct log_io *log, *next;
	unsigned int left = throttle_count;

	i_assert(left > 0);

	for (log = log_ios; log != NULL; log = next) {
		next = log->next;

		if (log->io == NULL) {
			if (log_write_pending(log))
				log_unthrottle(log);

			if (--left == 0)
				break;
		}
	}
}

void log_init(void)
{
	log_ios = NULL;
        throttle_count = 0;
	to = NULL;
}

void log_deinit(void)
{
	struct log_io *next;

	while (log_ios != NULL) {
		next = log_ios->next;
		log_io_free(log_ios);
		log_ios = next;
	}

	if (to != NULL)
		timeout_remove(to);
}

--- NEW FILE: log.h ---
#ifndef __LOG_H
#define __LOG_H

int log_create_pipe(const char *prefix);
void log_init(void);
void log_deinit(void);

#endif

Index: Makefile.am
===================================================================
RCS file: /home/cvs/dovecot/src/master/Makefile.am,v
retrieving revision 1.11
retrieving revision 1.12
diff -u -d -r1.11 -r1.12
--- Makefile.am	26 Jul 2003 22:42:44 -0000	1.11
+++ Makefile.am	10 May 2004 16:05:10 -0000	1.12
@@ -18,6 +18,7 @@
 
 dovecot_SOURCES = \
 	auth-process.c \
+	log.c \
 	login-process.c \
 	mail-process.c \
 	main.c \
@@ -29,6 +30,7 @@
 noinst_HEADERS = \
 	auth-process.h \
 	common.h \
+	log.h \
 	login-process.h \
 	mail-process.h \
 	master-login-interface.h \

Index: auth-process.c
===================================================================
RCS file: /home/cvs/dovecot/src/master/auth-process.c,v
retrieving revision 1.51
retrieving revision 1.52
diff -u -d -r1.51 -r1.52
--- auth-process.c	3 Dec 2003 00:40:21 -0000	1.51
+++ auth-process.c	10 May 2004 16:05:10 -0000	1.52
@@ -10,6 +10,7 @@
 #include "restrict-access.h"
 #include "restrict-process-size.h"
 #include "auth-process.h"
+#include "log.h"
 
 #include <stdlib.h>
 #include <unistd.h>
@@ -252,20 +253,30 @@
 static pid_t create_auth_process(struct auth_process_group *group)
 {
 	static char *argv[] = { NULL, NULL };
+	const char *prefix;
 	pid_t pid;
-	int fd[2], i;
+	int fd[2], log_fd, i;
 
 	/* create communication to process with a socket pair */
-	if (socketpair(AF_UNIX, SOCK_STREAM, 0, fd) == -1) {
+	if (socketpair(AF_UNIX, SOCK_STREAM, 0, fd) < 0) {
 		i_error("socketpair() failed: %m");
 		return -1;
 	}
 
-	pid = fork();
+	prefix = t_strdup_printf("auth(%s): ", group->set->name);
+	log_fd = log_create_pipe(prefix);
+	if (log_fd < 0)
+		pid = -1;
+	else {
+		pid = fork();
+		if (pid < 0)
+			i_error("fork() failed: %m");
+	}
+
 	if (pid < 0) {
 		(void)close(fd[0]);
 		(void)close(fd[1]);
-		i_error("fork() failed: %m");
+		(void)close(log_fd);
 		return -1;
 	}
 
@@ -275,28 +286,31 @@
 		fd_close_on_exec(fd[0], TRUE);
 		auth_process_new(pid, fd[0], group);
 		(void)close(fd[1]);
+		(void)close(log_fd);
 		return pid;
 	}
 
 	/* move master communication handle to 0 */
 	if (dup2(fd[1], 0) < 0)
-		i_fatal("login: dup2(0) failed: %m");
+		i_fatal("auth: dup2(stdin) failed: %m");
 
 	(void)close(fd[0]);
 	(void)close(fd[1]);
 
-	/* set stdout to /dev/null, so anything written into it gets ignored.
-	   leave stderr alone, we might want to use it for logging. */
+	/* set stdout to /dev/null, so anything written into it gets ignored. */
 	if (dup2(null_fd, 1) < 0)
-		i_fatal("login: dup2(1) failed: %m");
+		i_fatal("auth: dup2(stdout) failed: %m");
 
-	child_process_init_env(group->set->parent->defaults);
+	if (dup2(log_fd, 2) < 0)
+		i_fatal("auth: dup2(stderr) failed: %m");
+
+	child_process_init_env();
 
 	/* move login communication handle to 3. do it last so we can be
 	   sure it's not closed afterwards. */
 	if (group->listen_fd != 3) {
 		if (dup2(group->listen_fd, 3) < 0)
-			i_fatal("login: dup2() failed: %m");
+			i_fatal("auth: dup2() failed: %m");
 	}
 
 	for (i = 0; i <= 3; i++)

Index: common.h
===================================================================
RCS file: /home/cvs/dovecot/src/master/common.h,v
retrieving revision 1.17
retrieving revision 1.18
diff -u -d -r1.17 -r1.18
--- common.h	12 Jul 2003 23:43:16 -0000	1.17
+++ common.h	10 May 2004 16:05:10 -0000	1.18
@@ -24,6 +24,7 @@
 extern struct hash_table *pids;
 extern int null_fd, inetd_login_fd;
 extern uid_t master_uid;
+extern const char *process_names[];
 
 #define IS_INETD() \
 	(inetd_login_fd != -1)
@@ -38,7 +39,7 @@
 #define PID_REMOVE_PROCESS_TYPE(pid) \
 	hash_remove(pids, POINTER_CAST(pid))
 
-void child_process_init_env(struct settings *set);
+void child_process_init_env(void);
 
 /* misc */
 #define VALIDATE_STR(str) \

Index: login-process.c
===================================================================
RCS file: /home/cvs/dovecot/src/master/login-process.c,v
retrieving revision 1.52
retrieving revision 1.53
diff -u -d -r1.52 -r1.53
--- login-process.c	10 May 2004 02:15:16 -0000	1.52
+++ login-process.c	10 May 2004 16:05:10 -0000	1.53
@@ -13,6 +13,7 @@
 #include "auth-process.h"
 #include "mail-process.h"
 #include "master-login-interface.h"
+#include "log.h"
 
 #include <unistd.h>
 #include <syslog.h>
@@ -370,7 +371,7 @@
 {
 	struct settings *set = group->set;
 
-	child_process_init_env(set);
+	child_process_init_env();
 
 	/* setup access environment - needs to be done after
 	   clean_child_process() since it clears environment */
@@ -421,8 +422,9 @@
 static pid_t create_login_process(struct login_group *group)
 {
 	static const char *argv[] = { NULL, NULL };
+	const char *prefix;
 	pid_t pid;
-	int fd[2];
+	int fd[2], log_fd;
 
 	if (group->set->login_process_per_connection &&
 	    group->processes - group->listening_processes >=
@@ -435,16 +437,26 @@
 		i_fatal("Login process must not run as root");
 
 	/* create communication to process with a socket pair */
-	if (socketpair(AF_UNIX, SOCK_STREAM, 0, fd) == -1) {
+	if (socketpair(AF_UNIX, SOCK_STREAM, 0, fd) < 0) {
 		i_error("socketpair() failed: %m");
 		return -1;
 	}
 
-	pid = fork();
+	prefix = t_strdup_printf("%s-login: ",
+				 process_names[group->process_type]);
+	log_fd = log_create_pipe(prefix);
+	if (log_fd < 0)
+		pid = -1;
+	else {
+		pid = fork();
+		if (pid < 0)
+			i_error("fork() failed: %m");
+	}
+
 	if (pid < 0) {
 		(void)close(fd[0]);
 		(void)close(fd[1]);
-		i_error("fork() failed: %m");
+		(void)close(log_fd);
 		return -1;
 	}
 
@@ -454,6 +466,7 @@
 		fd_close_on_exec(fd[0], TRUE);
 		(void)login_process_new(group, pid, fd[0]);
 		(void)close(fd[1]);
+		(void)close(log_fd);
 		return pid;
 	}
 
@@ -472,6 +485,10 @@
 		i_fatal("login: dup2(master) failed: %m");
 	fd_close_on_exec(LOGIN_MASTER_SOCKET_FD, FALSE);
 
+	if (dup2(log_fd, 2) < 0)
+		i_fatal("login: dup2(stderr) failed: %m");
+	fd_close_on_exec(2, FALSE);
+
 	(void)close(fd[0]);
 	(void)close(fd[1]);
 

Index: mail-process.c
===================================================================
RCS file: /home/cvs/dovecot/src/master/mail-process.c,v
retrieving revision 1.41
retrieving revision 1.42
diff -u -d -r1.41 -r1.42
--- mail-process.c	2 May 2004 20:33:52 -0000	1.41
+++ mail-process.c	10 May 2004 16:05:10 -0000	1.42
@@ -10,6 +10,7 @@
 #include "var-expand.h"
 #include "mail-process.h"
 #include "login-process.h"
+#include "log.h"
 
 #include <stdlib.h>
 #include <unistd.h>
@@ -152,10 +153,10 @@
 	const char *argv[4];
 	struct settings *set = group->set;
 	const char *addr, *mail, *user, *chroot_dir, *home_dir, *full_home_dir;
-	const char *executable, *p;
+	const char *executable, *p, *prefix;
 	char title[1024];
 	pid_t pid;
-	int i, err, ret;
+	int i, err, ret, log_fd;
 
 	// FIXME: per-group
 	if (mail_process_count == set->max_mail_processes) {
@@ -178,9 +179,14 @@
 		return FALSE;
 	}
 
+	prefix = t_strdup_printf("%s(%s): ", process_names[group->process_type],
+				 data + reply->virtual_user_idx);
+	log_fd = log_create_pipe(prefix);
+
 	pid = fork();
 	if (pid < 0) {
 		i_error("fork() failed: %m");
+		(void)close(log_fd);
 		return FALSE;
 	}
 
@@ -188,10 +194,11 @@
 		/* master */
 		mail_process_count++;
 		PID_ADD_PROCESS_TYPE(pid, group->process_type);
+		(void)close(log_fd);
 		return TRUE;
 	}
 
-	child_process_init_env(set);
+	child_process_init_env();
 
 	/* move the client socket into stdin and stdout fds */
 	fd_close_on_exec(socket, FALSE);
@@ -199,6 +206,8 @@
 		i_fatal("mail: dup2(stdin) failed: %m");
 	if (dup2(socket, 1) < 0)
 		i_fatal("mail: dup2(stdout) failed: %m");
+	if (dup2(log_fd, 2) < 0)
+		i_fatal("mail: dup2(stderr) failed: %m");
 
 	if (close(socket) < 0)
 		i_error("mail: close(mail client) failed: %m");
@@ -256,6 +265,8 @@
 				set->mail_max_keyword_length));
 	env_put(t_strdup_printf("IMAP_MAX_LINE_LENGTH=%u",
 				set->imap_max_line_length));
+	env_put(t_strconcat("IMAP_CAPABILITY=",
+			    set->imap_capability, NULL));
 
 	if (set->mail_save_crlf)
 		env_put("MAIL_SAVE_CRLF=1");

Index: main.c
===================================================================
RCS file: /home/cvs/dovecot/src/master/main.c,v
retrieving revision 1.47
retrieving revision 1.48
diff -u -d -r1.47 -r1.48
--- main.c	20 Oct 2003 04:15:18 -0000	1.47
+++ main.c	10 May 2004 16:05:10 -0000	1.48
@@ -11,6 +11,7 @@
 #include "login-process.h"
 #include "mail-process.h"
 #include "ssl-init.h"
+#include "log.h"
 
 #include <stdio.h>
 #include <stdlib.h>
@@ -49,26 +50,13 @@
 	return FALSE;
 }
 
-void child_process_init_env(struct settings *set)
+void child_process_init_env(void)
 {
 	/* remove all environment, we don't need them */
 	env_clean();
 
-	/* set the failure log */
-	if (set->log_path == NULL)
-		env_put("USE_SYSLOG=1");
-	else
-		env_put(t_strconcat("LOGFILE=", set->log_path, NULL));
-
-	if (set->info_log_path != NULL) {
-		env_put(t_strconcat("INFOLOGFILE=",
-				    set->info_log_path, NULL));
-	}
-
-	if (set->log_timestamp != NULL) {
-		env_put(t_strconcat("LOGSTAMP=",
-				    set->log_timestamp, NULL));
-	}
+	/* we'll log through master process */
+	env_put("LOG_TO_MASTER=1");
 }
 
 static void sig_quit(int signo __attr_unused__)
@@ -383,6 +371,7 @@
         (void)umask(0077);
 
 	open_logfile(settings_root->defaults);
+	log_init();
 
 	lib_init_signals(sig_quit);
 
@@ -412,6 +401,7 @@
 		i_error("close(null_fd) failed: %m");
 
 	hash_destroy(pids);
+	log_deinit();
 	closelog();
 }
 

Index: master-settings.c
===================================================================
RCS file: /home/cvs/dovecot/src/master/master-settings.c,v
retrieving revision 1.44
retrieving revision 1.45
diff -u -d -r1.44 -r1.45
--- master-settings.c	10 May 2004 02:15:17 -0000	1.44
+++ master-settings.c	10 May 2004 16:05:10 -0000	1.45
@@ -109,6 +109,7 @@
 
 	/* imap */
 	DEF(SET_INT, imap_max_line_length),
+	DEF(SET_STR, imap_capability),
 
 	{ 0, NULL, 0 }
 };
@@ -236,6 +237,7 @@
 
 	/* imap */
 	MEMBER(imap_max_line_length) 65536,
+	MEMBER(imap_capability) NULL,
 
 	/* .. */
 	MEMBER(login_uid) 0,

Index: master-settings.h
===================================================================
RCS file: /home/cvs/dovecot/src/master/master-settings.h,v
retrieving revision 1.27
retrieving revision 1.28
diff -u -d -r1.27 -r1.28
--- master-settings.h	10 May 2004 02:15:17 -0000	1.27
+++ master-settings.h	10 May 2004 16:05:10 -0000	1.28
@@ -84,6 +84,7 @@
 
 	/* imap */
 	unsigned int imap_max_line_length;
+	const char *imap_capability;
 
 	/* .. */
 	uid_t login_uid;



More information about the dovecot-cvs mailing list