Re: [Dovecot] pop3-login: Fatal: io_loop_handle_add: epoll_ctl(1, 5):
I'm having this same issue in one of my servers since I updated my Dovecot from 1.2.4 to 1.2.5. The problem still with 1.2.6 too. I cannot find what is triggering the problem, but it happens aleatory and I need to restart the dovecot daemon to make the service run properly. My info: $ dovecot -n # 1.2.6: /etc/dovecot.conf # OS: Linux 2.6.18-164.el5PAE i686 CentOS release 5.4 (Final) protocols: imap imaps pop3 pop3s listen: xx.xx.xx.xx ssl_cert_file: /etc/httpd/conf/ssl.crt/server.crt ssl_key_file: /etc/httpd/conf/ssl.key/server.key disable_plaintext_auth: no login_dir: /var/run/dovecot/login login_executable(default): /usr/libexec/dovecot/imap-login login_executable(imap): /usr/libexec/dovecot/imap-login login_executable(pop3): /usr/libexec/dovecot/pop3-login login_processes_count: 16 verbose_proctitle: yes mail_access_groups: mail mail_location: maildir:~/Maildir mail_executable(default): /usr/libexec/dovecot/imap mail_executable(imap): /usr/libexec/dovecot/imap mail_executable(pop3): /usr/libexec/dovecot/pop3 mail_plugins(default): quota imap_quota mail_plugins(imap): quota imap_quota mail_plugins(pop3): mail_plugin_dir(default): /usr/lib/dovecot/imap mail_plugin_dir(imap): /usr/lib/dovecot/imap mail_plugin_dir(pop3): /usr/lib/dovecot/pop3 auth default: username_chars: abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ01234567890.-_@ verbose: yes passdb: driver: passwd-file args: username_format=%n /etc/virtual/%d/passwd userdb: driver: passwd-file args: username_format=%n /etc/virtual/%d/passwd plugin: quota: maildir quota_rule: *:storage=200M quota_rule2: Trash:storage=100%% Something else I can help? Or additional information that I can provide? -- Victor Benincasa
Re: [Dovecot] pop3-login: Fatal: io_loop_handle_add: epoll_ctl(1, 5):
On Oct 30, 2009, at 7:08 PM, Victor Benincasa wrote: I'm having this same issue in one of my servers since I updated my Dovecot from 1.2.4 to 1.2.5. The problem still with 1.2.6 too. Today I started thinking it has to be because some file descriptor is opened as fd 5 initially, but it's set close-on-exec flag and so when login process execs it probably opens epoll fd as 5 and then trying to epoll_ctl() it it fails. But I kind of forgot to check it today. Although in any way that would require something like SIGHUP to happen just before the failure starts.. Can you anyway check if reversing this patch solves the problem for you? http://dovecot.org/list/dovecot/2009-October/044140.html
Re: [Dovecot] pop3-login: Fatal: io_loop_handle_add: epoll_ctl(1, 5):
We've had this reoccur twice this week. In both cases, it seems to hit a swath of machines all within a few minutes. For some reason it's been limited to the master serving pop3 only. In all cases, the logging socket at fd 5 had gone missing. I haven't applied the fd leak detection patch, but I do have lsof output and a core file available here: http://uoregon.edu/~brandond/dovecot-1.2.6/ Timo, is there anything else I can collect to assist in debugging this? I'd rather not go back to 1.2.4, but my coworkers are becoming annoyed at having to restart the master processes every few days. -Brad
Re: [Dovecot] pop3-login: Fatal: io_loop_handle_add: epoll_ctl(1, 5):
On Thu, 2009-10-29 at 12:08 -0700, Brandon Davidson wrote: I haven't applied the fd leak detection patch, but I do have lsof output and a core file available here: http://uoregon.edu/~brandond/dovecot-1.2.6/ There's no 0,12 in the lsof list.. Annoying, I can't seem to find what it is. 0,10 is inotify, 0,11 is epoll, but 0,12 just doesn't show up anywhere. The core file is also pretty useless without the exact same binaries and libraries that produced it. Timo, is there anything else I can collect to assist in debugging this? I'd rather not go back to 1.2.4, but my coworkers are becoming annoyed at having to restart the master processes every few days. You could also set login_process_per_connection=no and this should go away, because then it only creates login processes at startup and can't fail randomly later. signature.asc Description: This is a digitally signed message part
Re: [Dovecot] pop3-login: Fatal: io_loop_handle_add: epoll_ctl(1, 5):
If this really started happening only with v1.2.4 - v1.2.5, the only
change that looks anything like it could have to do with this problem is
the attached patch. I guess you could try reversing it and seeing if it
helps..
--- /home/timo/m/dovecot-1.2.4/src/master/main.c 2009-05-20 17:48:16.0 -0400
+++ ./main.c 2009-10-29 16:05:50.0 -0400
@@ -139,6 +139,46 @@
i_set_failure_timestamp_format(set-log_timestamp);
}
+static void ATTR_NORETURN
+tee_fatal_handler(enum log_type type, int status, const char *fmt, va_list args)
+{
+ const struct settings *set = settings_root-defaults;
+ va_list args2;
+
+ VA_COPY(args2, args);
+ fprintf(stderr, Fatal: %s\n, t_strdup_vprintf(fmt, args2));
+
+ if (*set-log_path == '\0') {
+ i_syslog_fatal_handler(type, status, fmt, args);
+ } else {
+ default_fatal_handler(type, status, fmt, args);
+ }
+}
+
+static void
+tee_error_handler(enum log_type type, const char *fmt, va_list args)
+{
+ const struct settings *set = settings_root-defaults;
+ va_list args2;
+
+ VA_COPY(args2, args);
+ fprintf(stderr, Error: %s\n, t_strdup_vprintf(fmt, args2));
+
+ if (*set-log_path == '\0') {
+ i_syslog_error_handler(type, fmt, args);
+ } else {
+ default_error_handler(type, fmt, args);
+ }
+}
+
+static void set_tee_logfile(struct settings *set)
+{
+ set_logfile(set);
+
+ i_set_fatal_handler(tee_fatal_handler);
+ i_set_error_handler(tee_error_handler);
+}
+
static void settings_reload(void)
{
struct server_settings *old_set = settings_root;
@@ -222,7 +262,7 @@
fd_close_on_exec(null_fd, TRUE);
}
-static void open_fds(void)
+static void open_std_fds(void)
{
/* make sure all fds between 0..3 are used. */
while (null_fd 4) {
@@ -232,12 +272,6 @@
fd_close_on_exec(null_fd, TRUE);
}
- if (!IS_INETD()) {
- T_BEGIN {
- listeners_open_fds(NULL, FALSE);
- } T_END;
- }
-
/* close stdin and stdout. */
if (dup2(null_fd, 0) 0)
i_fatal(dup2(0) failed: %m);
@@ -600,11 +634,20 @@
mail_process_exec(exec_protocol, exec_args);
}
- if (!log_error)
- open_fds();
+ /* closes stdin/stdout, must be after --exec-mail handling */
+ open_std_fds();
+
+ /* log all errors to both stderr and log file until we've finished
+ startup. */
+ set_tee_logfile(settings_root-defaults);
fatal_log_check();
auth_warning_print(settings_root);
+
+ if (!log_error !IS_INETD()) T_BEGIN {
+ listeners_open_fds(NULL, FALSE);
+ } T_END;
+
if (!foreground)
daemonize(settings_root-defaults);
master_original_pid = getpid();
signature.asc
Description: This is a digitally signed message part
Re: [Dovecot] pop3-login: Fatal: io_loop_handle_add: epoll_ctl(1, 5):
Hi Timo, -Original Message- From: Timo Sirainen [mailto:t...@iki.fi] On Thu, 2009-10-29 at 12:08 -0700, Brandon Davidson wrote: I haven't applied the fd leak detection patch, but I do have lsof output and a core file available here: http://uoregon.edu/~brandond/dovecot-1.2.6/ There's no 0,12 in the lsof list.. Annoying, I can't seem to find what it is. 0,10 is inotify, 0,11 is epoll, but 0,12 just doesn't show up anywhere. It looks like eventpoll uses the dynamic minor stuff (.minor = MISC_DYNAMIC_MINOR), so it could well be that this is just what it got on his system due to something else loading and requesting a dynamic minor before eventpoll loaded. A better check (if one is necessary) might be to see if the minor of the leaked device is different from the minor of the epoll device right after creation. The core file is also pretty useless without the exact same binaries and libraries that produced it. RPMs are now in that directory. You could also set login_process_per_connection=no and this should go away, because then it only creates login processes at startup and can't fail randomly later. Are there any downsides to doing this? -Brad
Re: [Dovecot] pop3-login: Fatal: io_loop_handle_add: epoll_ctl(1, 5):
On Thu, 2009-10-29 at 14:03 -0700, Brandon Davidson wrote: You could also set login_process_per_connection=no and this should go away, because then it only creates login processes at startup and can't fail randomly later. Are there any downsides to doing this? http://wiki.dovecot.org/LoginProcess signature.asc Description: This is a digitally signed message part
Re: [Dovecot] pop3-login: Fatal: io_loop_handle_add: epoll_ctl(1, 5):
On Thu, Oct 22, 2009 at 07:58:22PM +0200, Marco Nenciarini wrote: Timo Sirainen ha scritto: On Thu, 2009-10-22 at 11:44 +0200, Marco Nenciarini wrote: This morning it happened another time, another time during the daily cron execution. Oct 22 06:26:57 server dovecot: pop3-login: Panic: Leaked file fd 5: dev 0.12 inode 1005 Can you apply the attached patch and see what it logs the next time it happens? I've applied the patch (with a little modification because i use managesieve) At this moment on all my systems I have a 1.2.6+2debug_patches and core dumps are enabled. Marco It seems that whatever triggered the original problem on my system was a fluke. Since the first occurrence, I have run dovecot 1.2.5 continuously from 26 Sept through 7 Oct and dovecot 1.2.6 continuously from 7 Oct through 23 Oct without seeing the error again. I have however applied the patch just in case it does recur. -- Mark Sapiro mark at msapiro net The highway is for gamblers, San Francisco Bay Area, Californiabetter use your sense - B. Dylan
Re: [Dovecot] pop3-login: Fatal: io_loop_handle_add: epoll_ctl(1, 5):
Hi Marco, On 10/22/09 1:50 AM, Marco Nenciarini mnen...@prato.linux.it wrote: This morning it happened another time, another time during the daily cron execution. Oct 22 06:26:57 server dovecot: pop3-login: Panic: Leaked file fd 5: dev 0.12 inode 1005 Oct 22 06:26:57 server dovecot: dovecot: Temporary failure in creating login processes, slowing down for now Oct 22 06:26:57 server dovecot: dovecot: child 21311 (login) killed with signal 6 (core dumps disabled) I have dovecot 1.2.6 with Timo's patch to check leaked descriptors. I rebuilt the binaries on our hosts with optimization disabled, and I'm still waiting for it to reoccur so I can gather file descriptor information and a core. I don't have the leak-detect patch applied. Let's see what Timo has to say about that log file bit. Since it seems to happen to you fairly frequently, it might be worth enabling core dumps as well? -Brad
Re: [Dovecot] pop3-login: Fatal: io_loop_handle_add: epoll_ctl(1, 5):
Brandon Davidson ha scritto: Hi Marco, Let's see what Timo has to say about that log file bit. Since it seems to happen to you fairly frequently, it might be worth enabling core dumps as well? You are right. I've just rebuilt my package with -g -O0 and enabled core dumps. Marco -- - |Marco Nenciarini| Debian/GNU Linux Developer - Plug Member | | mnen...@prato.linux.it | http://www.prato.linux.it/~mnencia | - Key fingerprint = FED9 69C7 9E67 21F5 7D95 5270 6864 730D F095 E5E4
Re: [Dovecot] pop3-login: Fatal: io_loop_handle_add: epoll_ctl(1, 5):
This morning it happened another time, another time during the daily cron execution. Oct 22 06:26:57 server dovecot: pop3-login: Panic: Leaked file fd 5: dev 0.12 inode 1005 Oct 22 06:26:57 server dovecot: dovecot: Temporary failure in creating login processes, slowing down for now Oct 22 06:26:57 server dovecot: dovecot: child 21311 (login) killed with signal 6 (core dumps disabled) I have dovecot 1.2.6 with Timo's patch to check leaked descriptors. Marco -- - |Marco Nenciarini| Debian/GNU Linux Developer - Plug Member | | mnen...@prato.linux.it | http://www.prato.linux.it/~mnencia | - Key fingerprint = FED9 69C7 9E67 21F5 7D95 5270 6864 730D F095 E5E4
Re: [Dovecot] pop3-login: Fatal: io_loop_handle_add: epoll_ctl(1, 5):
On Thu, 2009-10-22 at 11:44 +0200, Marco Nenciarini wrote:
This morning it happened another time, another time during the daily
cron execution.
Oct 22 06:26:57 server dovecot: pop3-login: Panic: Leaked file fd 5: dev
0.12 inode 1005
Can you apply the attached patch and see what it logs the next time it
happens?
diff -r ab32d7e2c0d6 src/login-common/main.c
--- a/src/login-common/main.c Tue Oct 20 15:49:01 2009 -0400
+++ b/src/login-common/main.c Thu Oct 22 12:50:52 2009 -0400
@@ -18,6 +18,7 @@
#include stdlib.h
#include unistd.h
#include syslog.h
+#include sys/stat.h
bool disable_plaintext_auth, process_per_connection;
bool verbose_proctitle, verbose_ssl, verbose_auth, auth_debug;
@@ -427,6 +428,13 @@
restrict_access_by_env() is called */
lib_init();
+ for (i = 3; i 20; i++) {
+ struct stat st;
+
+ if (fstat(i, st) == 0 major(st.st_dev) == 0 minor(st.st_dev) == 12)
+ i_panic(login fd %d is ino %ld, i, (long)st.st_ino);
+ }
+
if (is_inetd) {
/* running from inetd. create master process before
dropping privileges. */
diff -r ab32d7e2c0d6 src/master/listener.c
--- a/src/master/listener.c Tue Oct 20 15:49:01 2009 -0400
+++ b/src/master/listener.c Thu Oct 22 12:50:52 2009 -0400
@@ -8,6 +8,41 @@
#include stdlib.h
#include unistd.h
+#include sys/stat.h
+
+static void check_listeners(struct settings *set)
+{
+ const struct listener *listens;
+ unsigned int i, listen_count;
+
+ if (array_is_created(set-listens)) {
+ listens = array_get(set-listens, listen_count);
+ for (i = 0; i listen_count; i++) {
+ struct stat st;
+
+ if (listens[i].fd 0) continue;
+ if (net_getsockname(listens[i].fd, NULL, NULL) == 0) continue;
+
+ if (fstat(listens[i].fd, st) 0) i_panic(fstat(%d) failed: %m, listens[i].fd);
+ i_panic(listener %d is dev %d.%d ino %ld, i,
+major(st.st_dev), minor(st.st_dev), (long)st.st_ino);
+ }
+ }
+
+ if (array_is_created(set-ssl_listens)) {
+ listens = array_get(set-ssl_listens, listen_count);
+ for (i = 0; i listen_count; i++) {
+ struct stat st;
+
+ if (listens[i].fd 0) continue;
+ if (net_getsockname(listens[i].fd, NULL, NULL) == 0) continue;
+
+ if (fstat(listens[i].fd, st) 0) i_panic(fstat(ssl %d) failed: %m, listens[i].fd);
+ i_panic(ssl listener %d is dev %d.%d ino %ld, i,
+major(st.st_dev), minor(st.st_dev), (long)st.st_ino);
+ }
+ }
+}
static void resolve_ip(const char *set_name, const char *name,
struct ip_addr *ip, unsigned int *port)
@@ -345,10 +380,14 @@
}
for (server = settings_root; server != NULL; server = server-next) {
- if (server-imap != NULL)
+ if (server-imap != NULL) {
listener_listen_missing(server-imap, imap, retry);
- if (server-pop3 != NULL)
+ check_listeners(server-imap);
+ }
+ if (server-pop3 != NULL) {
listener_listen_missing(server-pop3, pop3, retry);
+ check_listeners(server-pop3);
+ }
}
}
diff -r ab32d7e2c0d6 src/master/login-process.c
--- a/src/master/login-process.c Tue Oct 20 15:49:01 2009 -0400
+++ b/src/master/login-process.c Thu Oct 22 12:50:52 2009 -0400
@@ -698,15 +698,31 @@
cur_fd = LOGIN_MASTER_SOCKET_FD + 1;
if (array_is_created(group-set-listens)) {
listens = array_get(group-set-listens, listen_count);
- for (i = 0; i listen_count; i++, cur_fd++)
+ for (i = 0; i listen_count; i++, cur_fd++) {
+ struct stat st;
+
+ if (net_getsockname(listens[i].fd, NULL, NULL) 0) {
+if (fstat(listens[i].fd, st) 0) i_panic(fstat(%d) failed: %m, listens[i].fd);
+i_panic(ssl listener %d is dev %d.%d ino %ld, i,
+ major(st.st_dev), minor(st.st_dev), (long)st.st_ino);
+ }
dup2_append(dups, listens[i].fd, cur_fd);
+ }
}
if (array_is_created(group-set-ssl_listens)) {
listens = array_get(group-set-ssl_listens,
ssl_listen_count);
- for (i = 0; i ssl_listen_count; i++, cur_fd++)
+ for (i = 0; i ssl_listen_count; i++, cur_fd++) {
+ struct stat st;
+
+ if (net_getsockname(listens[i].fd, NULL, NULL) 0) {
+if (fstat(listens[i].fd, st) 0) i_panic(fstat(%d) failed: %m, listens[i].fd);
+i_panic(ssl listener %d is dev %d.%d ino %ld, i,
+ major(st.st_dev), minor(st.st_dev), (long)st.st_ino);
+ }
dup2_append(dups, listens[i].fd, cur_fd);
+ }
}
/* make sure we don't leak syslog fd. try to do it as late as possible,
signature.asc
Description: This is a digitally signed message part
Re: [Dovecot] pop3-login: Fatal: io_loop_handle_add: epoll_ctl(1, 5):
Timo Sirainen ha scritto: On Thu, 2009-10-22 at 11:44 +0200, Marco Nenciarini wrote: This morning it happened another time, another time during the daily cron execution. Oct 22 06:26:57 server dovecot: pop3-login: Panic: Leaked file fd 5: dev 0.12 inode 1005 Can you apply the attached patch and see what it logs the next time it happens? I've applied the patch (with a little modification because i use managesieve) At this moment on all my systems I have a 1.2.6+2debug_patches and core dumps are enabled. Marco -- - |Marco Nenciarini| Debian/GNU Linux Developer - Plug Member | | mnen...@prato.linux.it | http://www.prato.linux.it/~mnencia | - Key fingerprint = FED9 69C7 9E67 21F5 7D95 5270 6864 730D F095 E5E4
Re: [Dovecot] pop3-login: Fatal: io_loop_handle_add: epoll_ctl(1, 5):
I seem to have run into the same issue on two of our 12 Dovecot servers this morning: Oct 15 03:41:51 oh-popmap5p dovecot: dovecot: child 7529 (login) returned error 89 (Fatal failure) Oct 15 03:41:51 oh-popmap5p dovecot: dovecot: child 7532 (login) returned error 89 (Fatal failure) Oct 15 03:41:51 oh-popmap5p dovecot: dovecot: Temporary failure in creating login processes, slowing down for now Oct 15 03:41:51 oh-popmap5p dovecot: dovecot: Temporary failure in creating login processes, slowing down for now Oct 15 03:41:51 oh-popmap5p dovecot: imap-login: Fatal: io_loop_handle_add: epoll_ctl(1, 5): Operation not permitted Oct 15 03:41:51 oh-popmap5p dovecot: dovecot: Created login processes successfully, unstalling Oct 15 03:41:51 oh-popmap5p dovecot: pop3-login: Fatal: io_loop_handle_add: epoll_ctl(1, 5): Operation not permitted Oct 15 03:41:51 oh-popmap5p dovecot: dovecot: Created login processes successfully, unstalling Oct 15 03:41:52 oh-popmap5p dovecot: dovecot: child 7576 (login) returned error 89 (Fatal failure) Oct 15 03:41:52 oh-popmap5p dovecot: dovecot: Temporary failure in creating login processes, slowing down for now All 12 of our servers are running Dovecot 1.2.6, and all of them were upgraded from 1.2.4 and restarted at Oct 13 04:00 by a cron job that updates packages from our internal Yum repo. Only two of the servers encountered this issue. We run two separate master processes on each host - one for IMAP, one for POP3. The IMAP service runs with a significantly increased login_max_processes_count, and continued to serve user requests. The POP3 service hit the max login process limit and stopped accepting new connections, which triggered our alerting system. For what it's worth, I was able to kill -HUP the master processes on both machines and things seemed to return to normal. I also took the precaution of killing off the pop3 login processes to get new connections accepted. Timo, is there any more information I could gather about this issue? We've got a fairly large pool of machines, and odds are it will crop up again if we wait long enough. Thanks, -Brad
Re: [Dovecot] pop3-login: Fatal: io_loop_handle_add: epoll_ctl(1, 5):
Timo Sirainen ha scritto: That's the pty's fd I think, probably from dovecot --exec-mail because normally dovecot master process closes them at startup.. Did you check if two dovecot processes were running when this happened? This morning the problem showed again. This is what I was able to discover: 1) There was only one master process. 2) Imap and managesieve login and worker processes were working normally. 3) There was no pop3/pop3-login. After the last time I've modified my root crontab to execute the expire-tool every minute, trying to trigger the problem in another time of the day, but the first failure is Oct 6 06:26:02 delta01 dovecot: imap-login: Panic: Leaked file fd 5: dev 0.12 inode 1005 Oct 6 06:26:02 delta01 dovecot: dovecot: Temporary failure in creating login processes, slowing down for now Oct 6 06:26:02 delta01 dovecot: dovecot: child 21216 (login) killed with signal 6 (core dumps disabled) As you can see this time is the login process of an imap connection, so I can state that the problem is not related to pop3 and nor to expire plugin. Probably the imap connections that I see were there before the problem was triggered. So the only remaining thing in daily log rotation that can be the trigger of the problem is the heavy cpu/io load due to daily maintenance. The last weird thing is that this time I have simply asked dovecot to reload its configuration and the problem is vanished. I hope this is enough to figure out what was happened. Marco -- - |Marco Nenciarini| Debian/GNU Linux Developer - Plug Member | | mnen...@prato.linux.it | http://www.prato.linux.it/~mnencia | - Key fingerprint = FED9 69C7 9E67 21F5 7D95 5270 6864 730D F095 E5E4
Re: [Dovecot] pop3-login: Fatal: io_loop_handle_add: epoll_ctl(1, 5):
Marco Nenciarini ha scritto: 2) Imap and managesieve login and worker processes were working normally. I only see this mistake now: the above statement is false, because the subsequent log show an imap-login failure. Sorry for this. Marco -- - |Marco Nenciarini| Debian/GNU Linux Developer - Plug Member | | mnen...@prato.linux.it | http://www.prato.linux.it/~mnencia | - Key fingerprint = FED9 69C7 9E67 21F5 7D95 5270 6864 730D F095 E5E4
Re: [Dovecot] pop3-login: Fatal: io_loop_handle_add: epoll_ctl(1, 5):
On Tue, Oct 06, 2009 at 11:59:02AM +0200, Marco Nenciarini wrote: Timo Sirainen ha scritto: That's the pty's fd I think, probably from dovecot --exec-mail because normally dovecot master process closes them at startup.. Did you check if two dovecot processes were running when this happened? This morning the problem showed again. This is what I was able to discover: 1) There was only one master process. 2) Imap and managesieve login and worker processes were working normally. 3) There was no pop3/pop3-login. After the last time I've modified my root crontab to execute the expire-tool every minute, trying to trigger the problem in another time of the day, but the first failure is Oct 6 06:26:02 delta01 dovecot: imap-login: Panic: Leaked file fd 5: dev 0.12 inode 1005 Oct 6 06:26:02 delta01 dovecot: dovecot: Temporary failure in creating login processes, slowing down for now Oct 6 06:26:02 delta01 dovecot: dovecot: child 21216 (login) killed with signal 6 (core dumps disabled) As you can see this time is the login process of an imap connection, so I can state that the problem is not related to pop3 and nor to expire plugin. Probably the imap connections that I see were there before the problem was triggered. So the only remaining thing in daily log rotation that can be the trigger of the problem is the heavy cpu/io load due to daily maintenance. The last weird thing is that this time I have simply asked dovecot to reload its configuration and the problem is vanished. I hope this is enough to figure out what was happened. On the other hand, I have not seen a recurrence since my initial report. At this point, dovecot has been running without interruption for over 9 days. I intend to install 1.2.6 tomorrow. -- Mark Sapiro mark at msapiro net The highway is for gamblers, San Francisco Bay Area, Californiabetter use your sense - B. Dylan
Re: [Dovecot] pop3-login: Fatal: io_loop_handle_add: epoll_ctl(1, 5):
Timo Sirainen ha scritto: On Wed, 2009-09-30 at 10:16 +0200, Marco Nenciarini wrote: Sep 30 06:26:15 server dovecot: pop3-login: Fatal: io_loop_handle_add: epoll_ctl(1, 5): Operation not permitted There is no additional information from Timo's patch, Oh, annoying. There was a bug in the function it used, this fixes it: http://hg.dovecot.org/dovecot-1.2/rev/401e023c8c29 [snip] The only thing related I can think of is http://hg.dovecot.org/dovecot-1.2/rev/0f04c7da33f1 - did you have that patch applied? Although I couldn't reproduce the problem even with that reverted. Another day, another failure, now with both patches applied. Oct 1 06:26:14 server dovecot: pop3-login: Panic: Leaked file fd 5: dev 0.12 inode 1005 Oct 1 06:26:14 server dovecot: dovecot: Temporary failure in creating login processes, slowing down for now Oct 1 06:26:14 server dovecot: dovecot: child 17609 (login) killed with signal 6 (core dumps disabled) Please note that the time is the same of previous days (just after daily cron execution) Regards, Marco -- - |Marco Nenciarini| Debian/GNU Linux Developer - Plug Member | | mnen...@prato.linux.it | http://www.prato.linux.it/~mnencia | - Key fingerprint = FED9 69C7 9E67 21F5 7D95 5270 6864 730D F095 E5E4
Re: [Dovecot] pop3-login: Fatal: io_loop_handle_add: epoll_ctl(1, 5):
On Thu, 2009-10-01 at 09:28 +0200, Marco Nenciarini wrote: The only thing related I can think of is http://hg.dovecot.org/dovecot-1.2/rev/0f04c7da33f1 - did you have that patch applied? Although I couldn't reproduce the problem even with that reverted. Another day, another failure, now with both patches applied. Oct 1 06:26:14 server dovecot: pop3-login: Panic: Leaked file fd 5: dev 0.12 inode 1005 That's the pty's fd I think, probably from dovecot --exec-mail because normally dovecot master process closes them at startup.. Did you check if two dovecot processes were running when this happened? signature.asc Description: This is a digitally signed message part
Re: [Dovecot] pop3-login: Fatal: io_loop_handle_add: epoll_ctl(1, 5):
On Tue, 2009-09-22 at 20:23 -0700, Mark Sapiro wrote: Sep 22 19:07:15 sbh16 dovecot: pop3-login: Fatal: io_loop_handle_add: epoll_ctl(1, 5): Operation not permitted Has this happened to you again? Do you run expire-tool or some other dovecot --exec-mail command? Or was there anything else run in cron just before the first of the above errors happened? signature.asc Description: This is a digitally signed message part
Re: [Dovecot] pop3-login: Fatal: io_loop_handle_add: epoll_ctl(1, 5):
Timo Sirainen ha scritto: On Tue, 2009-09-22 at 20:23 -0700, Mark Sapiro wrote: Sep 22 19:07:15 sbh16 dovecot: pop3-login: Fatal: io_loop_handle_add: epoll_ctl(1, 5): Operation not permitted Has this happened to you again? Do you run expire-tool or some other dovecot --exec-mail command? Or was there anything else run in cron just before the first of the above errors happened? No, it hasn't happened again. The only errors I found in my logs is like the following one Oct 1 09:20:29 delta01 dovecot: pop3-login: Disconnected (no auth attempts): rip=213.136.170.137, lip=10.68.1.31 Oct 1 09:20:29 delta01 dovecot: pop3-login: Panic: Leaked file fd 5: dev 0.12 inode 1005 Oct 1 09:20:29 delta01 dovecot: dovecot: Temporary failure in creating login processes, slowing down for now Oct 1 09:20:29 delta01 dovecot: pop3-login: Disconnected (no auth attempts): rip=62.94.181.36, lip=10.68.1.31 Oct 1 09:20:29 delta01 dovecot: dovecot: child 12936 (login) killed with signal 6 (core dumps disabled) The only dovecot-related command run by cron daily is expire-tool I've checked the list of running processes but there is only one /usr/sbin/dovecot running with its children Marco -- - |Marco Nenciarini| Debian/GNU Linux Developer - Plug Member | | mnen...@prato.linux.it | http://www.prato.linux.it/~mnencia | - Key fingerprint = FED9 69C7 9E67 21F5 7D95 5270 6864 730D F095 E5E4
Re: [Dovecot] pop3-login: Fatal: io_loop_handle_add: epoll_ctl(1, 5):
Timo Sirainen wrote: On Tue, 2009-09-22 at 20:23 -0700, Mark Sapiro wrote: Sep 22 19:07:15 sbh16 dovecot: pop3-login: Fatal: io_loop_handle_add: epoll_ctl(1, 5): Operation not permitted Has this happened to you again? Do you run expire-tool or some other dovecot --exec-mail command? Or was there anything else run in cron just before the first of the above errors happened? Hi Timo, No, this hasn't happened again. It is dovecot 2.1.5 with no extra plugins. I don't run any dovecot related crons. The only crons that ran just before it happened were unrelated rotate two unrelated logs 23 minutes before download and update some spamassassin rules 12 minutes before update Mailman archive search indices 9 minutes before All these run daily. The problem occurred after upgrading from 2.1.4 to 2.1.5. 2.1.4 had been running for weeks with no problem. The problem started with 2.1.5 when it had been running about 6 days and 20 hours. and continued until I restarted dovecot a day and a half later. There was a power outage at the server last Friday night when Dovecot had been running only 4 days since the last restart, so at this point, Dovecot has been running continuously for 5 days and 6 hours, so the problem may or may not recur within the next few days. My dovecot -n is at http://dovecot.org/pipermail/dovecot/2009-September/042943.html, and some more detail from my maillog is at http://dovecot.org/pipermail/dovecot/2009-September/042959.html. -- Mark Sapiro m...@msapiro.netThe highway is for gamblers, San Francisco Bay Area, Californiabetter use your sense - B. Dylan
Re: [Dovecot] pop3-login: Fatal: io_loop_handle_add: epoll_ctl(1, 5):
On 10/1/2009, Mark Sapiro (m...@msapiro.net) wrote: No, this hasn't happened again. It is dovecot 2.1.5 Ok, at first I thought this was just a silly typo, but... The problem occurred after upgrading from 2.1.4 to 2.1.5. 2.1.4 had been running for weeks with no problem. The problem started with 2.1.5 Mark, you obviously just gave away the fact that you have access to a time machine... Please, if you would, post these future versions somewhere where I can get at them! lol ;)
Re: [Dovecot] pop3-login: Fatal: io_loop_handle_add: epoll_ctl(1, 5):
Mark Sapiro wrote: Timo Sirainen wrote: On Tue, 2009-09-22 at 20:23 -0700, Mark Sapiro wrote: Sep 22 19:07:15 sbh16 dovecot: pop3-login: Fatal: io_loop_handle_add: epoll_ctl(1, 5): Operation not permitted Has this happened to you again? Do you run expire-tool or some other dovecot --exec-mail command? Or was there anything else run in cron just before the first of the above errors happened? Hi Timo, No, this hasn't happened again. It is dovecot 2.1.5 with no extra plugins. I don't run any dovecot related crons. The only crons that ran just before it happened were unrelated rotate two unrelated logs 23 minutes before download and update some spamassassin rules 12 minutes before update Mailman archive search indices 9 minutes before All these run daily. The problem occurred after upgrading from 2.1.4 to 2.1.5. 2.1.4 had been running for weeks with no problem. The problem started with 2.1.5 when it had been running about 6 days and 20 hours. and continued until I restarted dovecot a day and a half later. There was a power outage at the server last Friday night when Dovecot had been running only 4 days since the last restart, so at this point, Dovecot has been running continuously for 5 days and 6 hours, so the problem may or may not recur within the next few days. My dovecot -n is at http://dovecot.org/pipermail/dovecot/2009-September/042943.html, and some more detail from my maillog is at http://dovecot.org/pipermail/dovecot/2009-September/042959.html. Also, FYI, I do not have the http://hg.dovecot.org/dovecot-1.2/rev/0f04c7da33f1 patch installed. I do have the patch installed to log the fd for this error, but I don't have the fix http://hg.dovecot.org/dovecot-1.2/rev/401e023c8c29 for the logging function installed. Would you prefer that I just let Dovecot run a few days and see if the problem recurs, or should I install the logging function fix now and perhaps wait another 7 or 8 days before there may be another failure. Also, as far as I know, the only dovecot processes running at the time of the failure were a single master and it's auth and pop3 and imap login children. -- Mark Sapiro m...@msapiro.netThe highway is for gamblers, San Francisco Bay Area, Californiabetter use your sense - B. Dylan
Re: [Dovecot] pop3-login: Fatal: io_loop_handle_add: epoll_ctl(1, 5):
Charles Marcus wrote: On 10/1/2009, Mark Sapiro (m...@msapiro.net) wrote: No, this hasn't happened again. It is dovecot 2.1.5 Ok, at first I thought this was just a silly typo, but... The problem occurred after upgrading from 2.1.4 to 2.1.5. 2.1.4 had been running for weeks with no problem. The problem started with 2.1.5 Mark, you obviously just gave away the fact that you have access to a time machine... Please, if you would, post these future versions somewhere where I can get at them! Sorry, no time machine, no future versions. Just finger dyslexia. As everyone probably knows, I meant 1.2.5 and 1.2.4. -- Mark Sapiro m...@msapiro.netThe highway is for gamblers, San Francisco Bay Area, Californiabetter use your sense - B. Dylan
Re: [Dovecot] pop3-login: Fatal: io_loop_handle_add: epoll_ctl(1, 5):
Timo Sirainen ha scritto:
On Sep 23, 2009, at 11:27 AM, Timo Sirainen wrote:
On Sep 23, 2009, at 11:17 AM, Marco Nenciarini wrote:
First failure is:
Sep 23 06:26:14 server dovecot: pop3-login: Fatal:
io_loop_handle_add: epoll_ctl(1, 5): Operation not permitted
That's really the first one, and there's no kind of an error from
dovecot master process? This sounds like wrong fd is being passed to
pop3-login, but why it's being done only randomly I can't really think
of..
It could be useful to know what the fd actually is. See what it logs
with the attached patch?
The problem happened again.
Sep 30 06:26:15 server dovecot: pop3-login: Fatal: io_loop_handle_add:
epoll_ctl(1, 5): Operation not permitted
There is no additional information from Timo's patch, but if you compare
it with the last one you can see a weird match on both time and weekday:
Sep 23 06:26:14 server dovecot: pop3-login: Fatal: io_loop_handle_add:
epoll_ctl(1, 5): Operation not permitted
After some investigation I've found that the daily cron scripts are
executed every day at 6:25 and the only thing related to dovecot in
/etc/cron.daily is the call to expire plugin
-
server:~# cat /etc/cron.dailyclean-expired-messages
#!/bin/sh
dovecot --exec-mail ext /usr/lib/dovecot/expire-tool.sh
server:~# cat /usr/lib/dovecot/expire-tool.sh
#!/bin/bash
MAIL_PLUGINS=${MAIL_PLUGINS//imap_quota/}
MAIL_PLUGINS=${MAIL_PLUGINS//mail_log/}
exec ${0%.sh} $@
-
Moreover my expire plugin configuration is
expire: Trash 7 Trash/* 7 Cestino 7 Cestino/* 7 Junk 30 Spam 30
so the weekly periodicity can be explained with something happened in a
Trash mailbox.
My configuration is
-
# 1.2.5: /etc/dovecot/dovecot.conf
# OS: Linux 2.6.26-2-xen-amd64 x86_64 Debian 5.0.3
log_timestamp: %Y-%m-%d %H:%M:%S
protocols: imap imaps pop3 pop3s managesieve
ssl_cert_file: /etc/ssl/certs/delta01.pem
ssl_key_file: /etc/ssl/private/delta01.key
disable_plaintext_auth: no
login_dir: /var/run/dovecot/login
login_executable(default): /usr/lib/dovecot/imap-login
login_executable(imap): /usr/lib/dovecot/imap-login
login_executable(pop3): /usr/lib/dovecot/pop3-login
login_executable(managesieve): /usr/lib/dovecot/managesieve-login
first_valid_uid: 2000
last_valid_uid: 2000
first_valid_gid: 2000
last_valid_gid: 2000
mail_privileged_group: mail
mail_location: maildir:~/Maildir
mbox_write_locks: fcntl dotlock
mail_executable(default): /usr/lib/dovecot/imap
mail_executable(imap): /usr/lib/dovecot/imap
mail_executable(pop3): /usr/lib/dovecot/pop3
mail_executable(managesieve): /usr/lib/dovecot/managesieve
mail_plugins(default): quota imap_quota expire trash
mail_plugins(imap): quota imap_quota expire trash
mail_plugins(pop3): quota expire
mail_plugins(managesieve):
mail_plugin_dir(default): /usr/lib/dovecot/modules/imap
mail_plugin_dir(imap): /usr/lib/dovecot/modules/imap
mail_plugin_dir(pop3): /usr/lib/dovecot/modules/pop3
mail_plugin_dir(managesieve): /usr/lib/dovecot/modules/managesieve
imap_client_workarounds(default): delay-newmail
imap_client_workarounds(imap): delay-newmail
imap_client_workarounds(pop3):
imap_client_workarounds(managesieve):
pop3_save_uidl(default): no
pop3_save_uidl(imap): no
pop3_save_uidl(pop3): yes
pop3_save_uidl(managesieve): no
pop3_uidl_format(default): %08Xu%08Xv
pop3_uidl_format(imap): %08Xu%08Xv
pop3_uidl_format(pop3): %f
pop3_uidl_format(managesieve): %08Xu%08Xv
pop3_client_workarounds(default):
pop3_client_workarounds(imap):
pop3_client_workarounds(pop3): outlook-no-nuls oe-ns-eoh
pop3_client_workarounds(managesieve):
namespace:
type: private
separator: .
inbox: yes
list: yes
subscriptions: yes
namespace:
type: private
separator: .
prefix: INBOX.
hidden: yes
list: no
subscriptions: yes
lda:
postmaster_address: postmas...@xcon.it
mail_plugins: quota sieve expire
auth_socket_path: /var/run/dovecot/auth-master
auth default:
mechanisms: plain login
passdb:
driver: sql
args: /etc/dovecot/dovecot-sql.conf
userdb:
driver: prefetch
userdb:
driver: sql
args: /etc/dovecot/dovecot-sql.conf
socket:
type: listen
client:
path: /var/spool/postfix/private/auth
mode: 432
user: postfix
group: postfix
master:
path: /var/run/dovecot/auth-master
mode: 384
user: vmail
group: vmail
plugin:
quota: dict:user::proxy::quota
quota2: dict:domain:%d:proxy::quota_domain
trash: /etc/dovecot/dovecot-trash.conf
expire: Trash 7 Trash/* 7 Cestino 7 Cestino/* 7 Junk 30 Spam 30
expire_dict: proxy::expire
sieve: ~/.dovecot.sieve
sieve_dir: ~/sieve
dict:
quota: pgsql:/etc/dovecot/dovecot-dict-quota.conf
quota_domain: pgsql:/etc/dovecot/dovecot-dict-quota-domain.conf
expire: pgsql:/etc/dovecot/dovecot-dict-expire.conf
Re: [Dovecot] pop3-login: Fatal: io_loop_handle_add: epoll_ctl(1, 5):
On Wed, 2009-09-30 at 10:16 +0200, Marco Nenciarini wrote: Sep 30 06:26:15 server dovecot: pop3-login: Fatal: io_loop_handle_add: epoll_ctl(1, 5): Operation not permitted There is no additional information from Timo's patch, Oh, annoying. There was a bug in the function it used, this fixes it: http://hg.dovecot.org/dovecot-1.2/rev/401e023c8c29 but if you compare it with the last one you can see a weird match on both time and weekday: Sep 23 06:26:14 server dovecot: pop3-login: Fatal: io_loop_handle_add: epoll_ctl(1, 5): Operation not permitted After some investigation I've found that the daily cron scripts are executed every day at 6:25 and the only thing related to dovecot in /etc/cron.daily is the call to expire plugin That is interesting, but I can't really think of how they could be related.. I also did a few tests and they didn't break it either. The only thing I can think of is that somehow the --exec-mail added a second dovecot master process running at the same time? Did you check the process list? The only thing related I can think of is http://hg.dovecot.org/dovecot-1.2/rev/0f04c7da33f1 - did you have that patch applied? Although I couldn't reproduce the problem even with that reverted. signature.asc Description: This is a digitally signed message part
Re: [Dovecot] pop3-login: Fatal: io_loop_handle_add: epoll_ctl(1, 5):
Mark Sapiro ha scritto: I have been running Dovecot 1.2.5 since Sept 14. Beginning at about 03:28 on Sept 21 for no apparent (to me) reason and continuing through the present, I am seeing log messages like the following and am experiencing delays logging in. Same problem here, after about the same time from last server re start. Last restart log is: Sep 14 19:05:07 server dovecot: Dovecot v1.2.5 starting up (core dumps disabled) First failure is: Sep 23 06:26:14 server dovecot: pop3-login: Fatal: io_loop_handle_add: epoll_ctl(1, 5): Operation not permitted After the attached piece of log, the mail log is full of the same failure, and no customer can login using pop3 (imap works with no problems) After a server restart the problem was vanished. May be there is some kind of resource leakage. Marco P.S: This is my configuration is # 1.2.5: /etc/dovecot/dovecot.conf # OS: Linux 2.6.26-2-xen-amd64 x86_64 Debian 5.0.3 log_timestamp: %Y-%m-%d %H:%M:%S protocols: imap imaps pop3 pop3s managesieve ssl_cert_file: /etc/ssl/certs/server.pem ssl_key_file: /etc/ssl/private/server.key disable_plaintext_auth: no login_dir: /var/run/dovecot/login login_executable(default): /usr/lib/dovecot/imap-login login_executable(imap): /usr/lib/dovecot/imap-login login_executable(pop3): /usr/lib/dovecot/pop3-login login_executable(managesieve): /usr/lib/dovecot/managesieve-login first_valid_uid: 2000 last_valid_uid: 2000 first_valid_gid: 2000 last_valid_gid: 2000 mail_privileged_group: mail mail_location: maildir:~/Maildir mbox_write_locks: fcntl dotlock mail_executable(default): /usr/lib/dovecot/imap mail_executable(imap): /usr/lib/dovecot/imap mail_executable(pop3): /usr/lib/dovecot/pop3 mail_executable(managesieve): /usr/lib/dovecot/managesieve mail_plugins(default): quota imap_quota expire trash mail_plugins(imap): quota imap_quota expire trash mail_plugins(pop3): quota expire mail_plugins(managesieve): mail_plugin_dir(default): /usr/lib/dovecot/modules/imap mail_plugin_dir(imap): /usr/lib/dovecot/modules/imap mail_plugin_dir(pop3): /usr/lib/dovecot/modules/pop3 mail_plugin_dir(managesieve): /usr/lib/dovecot/modules/managesieve imap_client_workarounds(default): delay-newmail imap_client_workarounds(imap): delay-newmail imap_client_workarounds(pop3): imap_client_workarounds(managesieve): pop3_save_uidl(default): no pop3_save_uidl(imap): no pop3_save_uidl(pop3): yes pop3_save_uidl(managesieve): no pop3_uidl_format(default): %08Xu%08Xv pop3_uidl_format(imap): %08Xu%08Xv pop3_uidl_format(pop3): %f pop3_uidl_format(managesieve): %08Xu%08Xv pop3_client_workarounds(default): pop3_client_workarounds(imap): pop3_client_workarounds(pop3): outlook-no-nuls oe-ns-eoh pop3_client_workarounds(managesieve): namespace: type: private separator: . inbox: yes list: yes subscriptions: yes namespace: type: private separator: . prefix: INBOX. hidden: yes list: no subscriptions: yes lda: postmaster_address: postmas...@xcon.it mail_plugins: quota sieve expire auth_socket_path: /var/run/dovecot/auth-master auth default: mechanisms: plain login passdb: driver: sql args: /etc/dovecot/dovecot-sql.conf userdb: driver: prefetch userdb: driver: sql args: /etc/dovecot/dovecot-sql.conf socket: type: listen client: path: /var/spool/postfix/private/auth mode: 432 user: postfix group: postfix master: path: /var/run/dovecot/auth-master mode: 384 user: vmail group: vmail plugin: quota: dict:user::proxy::quota quota2: dict:domain:%d:proxy::quota_domain trash: /etc/dovecot/dovecot-trash.conf expire: Trash 7 Trash/* 7 Cestino 7 Cestino/* 7 Junk 30 Spam 30 expire_dict: proxy::expire sieve: ~/.dovecot.sieve sieve_dir: ~/sieve dict: quota: pgsql:/etc/dovecot/dovecot-dict-quota.conf quota_domain: pgsql:/etc/dovecot/dovecot-dict-quota-domain.conf expire: pgsql:/etc/dovecot/dovecot-dict-expire.conf -- - |Marco Nenciarini| Debian/GNU Linux Developer - Plug Member | | mnen...@prato.linux.it | http://www.prato.linux.it/~mnencia | - Key fingerprint = FED9 69C7 9E67 21F5 7D95 5270 6864 730D F095 E5E4 Sep 23 06:26:12 server dovecot: pop3-login: Login: user=x...@xxx.xx, method=PLAIN, rip=11.22.33.44 lip=11.22.33.44 TLS Sep 23 06:26:13 server dovecot: POP3(x...@xxx.xx): Disconnected: Logged out top=0/0, retr=0/0, del=0/0, size=0 Sep 23 06:26:14 server dovecot: pop3-login: Fatal: io_loop_handle_add: epoll_ctl(1, 5): Operation not permitted Sep 23 06:26:14 server dovecot: dovecot: Temporary failure in creating login processes, slowing down for now Sep 23 06:26:14 server dovecot: POP3(x...@xxx.xx): Disconnected: Logged out top=0/0, retr=0/0, del=0/0, size=0 Sep 23 06:26:15 server dovecot: pop3-login: Login: user=x...@xxx.xx, method=PLAIN, rip=11.22.33.44 lip=11.22.33.44 TLS Sep 23
Re: [Dovecot] pop3-login: Fatal: io_loop_handle_add: epoll_ctl(1, 5):
On Sep 23, 2009, at 11:17 AM, Marco Nenciarini wrote: First failure is: Sep 23 06:26:14 server dovecot: pop3-login: Fatal: io_loop_handle_add: epoll_ctl(1, 5): Operation not permitted That's really the first one, and there's no kind of an error from dovecot master process? This sounds like wrong fd is being passed to pop3-login, but why it's being done only randomly I can't really think of..
Re: [Dovecot] pop3-login: Fatal: io_loop_handle_add: epoll_ctl(1, 5):
On Sep 23, 2009, at 11:27 AM, Timo Sirainen wrote: On Sep 23, 2009, at 11:17 AM, Marco Nenciarini wrote: First failure is: Sep 23 06:26:14 server dovecot: pop3-login: Fatal: io_loop_handle_add: epoll_ctl(1, 5): Operation not permitted That's really the first one, and there's no kind of an error from dovecot master process? This sounds like wrong fd is being passed to pop3-login, but why it's being done only randomly I can't really think of.. It could be useful to know what the fd actually is. See what it logs with the attached patch? diff Description: Binary data
Re: [Dovecot] pop3-login: Fatal: io_loop_handle_add: epoll_ctl(1, 5):
Marco Nenciarini ha scritto: Patch applied, now we must wait until the problem will show itself again (may be a week or so). The patch does not compile, need another parameter (may be 1024?) Marco -- - |Marco Nenciarini| Debian/GNU Linux Developer - Plug Member | | mnen...@prato.linux.it | http://www.prato.linux.it/~mnencia | - Key fingerprint = FED9 69C7 9E67 21F5 7D95 5270 6864 730D F095 E5E4
Re: [Dovecot] pop3-login: Fatal: io_loop_handle_add: epoll_ctl(1, 5):
On Sep 23, 2009, at 12:11 PM, Marco Nenciarini wrote: Marco Nenciarini ha scritto: Patch applied, now we must wait until the problem will show itself again (may be a week or so). The patch does not compile, need another parameter (may be 1024?) Oh, sorry. Use io-fd for the second one too.
Re: [Dovecot] pop3-login: Fatal: io_loop_handle_add: epoll_ctl(1, 5):
Timo Sirainen wrote: On Sep 23, 2009, at 11:17 AM, Marco Nenciarini wrote: First failure is: Sep 23 06:26:14 server dovecot: pop3-login: Fatal: io_loop_handle_add: epoll_ctl(1, 5): Operation not permitted That's really the first one, and there's no kind of an error from dovecot master process? This sounds like wrong fd is being passed to pop3-login, but why it's being done only randomly I can't really think of.. In my case, I see a few different kinds of messages. I posted a sequence earlier. Here it is again. At least one of each unusual message I see is included in this two minute period, and these are all the dovecot messages in that period and the initial message is the first unusual one that occurred. Sep 22 19:07:15 sbh16 dovecot: dovecot: Temporary failure in creating login processes, slowing down for now Sep 22 19:07:15 sbh16 dovecot: pop3-login: Fatal: io_loop_handle_add: epoll_ctl(1, 5): Operation not permitted Sep 22 19:07:48 sbh16 dovecot: pop3-login: Login: user=mark, method=APOP, rip=68.183.193.239, lip=72.52.113.16, TLS Sep 22 19:07:48 sbh16 dovecot: POP3(mark): Disconnected: Logged out top=0/0, retr=0/0, del=0/218, size=2550090 Sep 22 19:08:15 sbh16 dovecot: dovecot: Created login processes successfully, unstalling Sep 22 19:08:15 sbh16 dovecot: dovecot: Temporary failure in creating login processes, slowing down for now Sep 22 19:08:15 sbh16 dovecot: dovecot: child 21735 (login) returned error 89 (Fatal failure) Sep 22 19:08:15 sbh16 dovecot: pop3-login: Fatal: io_loop_handle_add: epoll_ctl(1, 5): Operation not permitted Sep 22 19:08:21 sbh16 dovecot: pop3-login: Login: user=mark, method=APOP, rip=68.183.193.239, lip=72.52.113.16, TLS Sep 22 19:08:22 sbh16 dovecot: POP3(mark): Disconnected: Logged out top=0/0, retr=1/57566, del=0/218, size=2550090 Sep 22 19:09:15 sbh16 dovecot: dovecot: Created login processes successfully, unstalling Also, here are all the dovecot messages from a five minute period when this first started. The scenario here is a remote machine connects every five minutes via an SSH tunnel and retrieves and deletes (with fetchmail pop3) all the mail for 4 users. Sep 21 03:28:17 sbh16 dovecot: pop3-login: Login: user=fran, method=PLAIN, rip=72.52.113.36, lip=72.52.113.36, secured Sep 21 03:28:17 sbh16 dovecot: POP3(fran): Disconnected: Logged out top=0/0, retr=0/0, del=0/0, size=0 Sep 21 03:28:17 sbh16 dovecot: pop3-login: Login: user=dma, method=PLAIN, rip=72.52.113.36, lip=72.52.113.36, secured Sep 21 03:28:17 sbh16 dovecot: POP3(dma): Disconnected: Logged out top=0/0, retr=0/0, del=0/0, size=0 Sep 21 03:28:17 sbh16 dovecot: pop3-login: Login: user=abriz, method=PLAIN, rip=72.52.113.36, lip=72.52.113.36, secured Sep 21 03:28:17 sbh16 dovecot: dovecot: Temporary failure in creating login processes, slowing down for now Sep 21 03:28:28 sbh16 dovecot: pop3-login: Fatal: io_loop_handle_add: epoll_ctl(1, 5): Operation not permitted Sep 21 03:28:28 sbh16 dovecot: pop3-login: Login: user=aaron, method=PLAIN, rip=72.52.113.36, lip=72.52.113.36, secured Sep 21 03:28:28 sbh16 dovecot: POP3(aaron): Disconnected: Logged out top=0/0, retr=0/0, del=0/0, size=0 Sep 21 03:29:28 sbh16 dovecot: dovecot: Created login processes successfully, unstalling Sep 21 03:29:28 sbh16 dovecot: dovecot: Temporary failure in creating login processes, slowing down for now Sep 21 03:29:28 sbh16 dovecot: pop3-login: Fatal: io_loop_handle_add: epoll_ctl(1, 5): Operation not permitted Sep 21 03:30:28 sbh16 dovecot: pop3-login: Fatal: io_loop_handle_add: epoll_ctl(1, 5): Operation not permitted Sep 21 03:31:28 sbh16 dovecot: pop3-login: Fatal: io_loop_handle_add: epoll_ctl(1, 5): Operation not permitted Sep 21 03:32:28 sbh16 dovecot: dovecot: child 25038 (login) returned error 89 (Fatal failure) Sep 21 03:32:28 sbh16 dovecot: pop3-login: Fatal: io_loop_handle_add: epoll_ctl(1, 5): Operation not permitted Sep 21 03:33:28 sbh16 dovecot: pop3-login: Fatal: io_loop_handle_add: epoll_ctl(1, 5): Operation not permitted Sep 21 03:33:36 sbh16 dovecot: pop3-login: Login: user=fran, method=PLAIN, rip=72.52.113.36, lip=72.52.113.36, secured Sep 21 03:33:36 sbh16 dovecot: POP3(fran): Disconnected: Logged out top=1/21613, retr=0/0, del=1/1, size=21607 Sep 21 03:33:36 sbh16 dovecot: pop3-login: Login: user=dma, method=PLAIN, rip=72.52.113.36, lip=72.52.113.36, secured Sep 21 03:33:36 sbh16 dovecot: POP3(dma): Disconnected: Logged out top=1/21607, retr=0/0, del=1/1, size=21601 I have installed the patch adding fd_debug_verify_leaks(io-fd, io-fd); and I will report any recurrence. -- Mark Sapiro m...@msapiro.netThe highway is for gamblers, San Francisco Bay Area, Californiabetter use your sense - B. Dylan
