Re: [Dovecot] dovecot/log not running

2012-09-12 Thread Mark Hinch

Answers for both my helpers - Timo and Ben (Thanks!):

Timo: Problem #1 - no dovecot/login
doveconf -n output:
==
# 2.1.7: /etc/dovecot/dovecot.conf
# OS: Linux 2.6.30-2-686 i686 Debian wheezy/sid
mail_access_groups = mail
mail_location = mbox:~/mail:INBOX=/var/mail/%n
mail_privileged_group = mail
namespace inbox {
  inbox = yes
  location =
  prefix =
}
passdb {
  driver = pam
}
plugin {
  mail_log_events = delete undelete expunge copy mailbox_delete 
mailbox_rename

  mail_log_fields = uid box msgid size
}
protocols = " imap"
ssl_cert = yesterday I suddenly found it to be running and to be dumping stuff into 
my log file.
Closer examination using "ps" showed that while dovecot was restarted 
(via a cronjob
to work around problem #2)) at 01:30 (i.e., at around 1am), dovecot/log 
started running at 17:12 (i.e., around 5pm).
This is confirmed in the log files (i.e., no log output until 5pm). The 
dovecot logs are:

===
Sep 10 01:30:02 hinch4 dovecot: master: Dovecot v2.1.7 starting up (core 
dumps disabled)
Sep 10 01:30:42 hinch4 dovecot: master: Error: service(anvil): Initial 
status notification not received in 30 seconds, killing the p

rocess
Sep 10 01:30:42 hinch4 dovecot: master: Error: service(log): Initial 
status notification not received in 30 seconds, killing the pro

cess
Sep 10 01:30:42 hinch4 dovecot: master: Error: service(ssl-params): 
Initial status notification not received in 30 seconds, killing

the process
Sep 10 01:30:42 hinch4 dovecot: master: Error: service(log): child 3505 
killed with signal 9
Sep 10 08:14:11 hinch4 dovecot: master: Error: service(imap-login): 
Initial status notification not received in 30 seconds, killing

the process
Sep 10 17:12:44 hinch4 dovecot: log: Error: Received master input for 
invalid service_fd 24: 24 3504 FATAL service(anvil): child 350

4 killed with signal 9
Sep 10 17:12:44 hinch4 dovecot: log: Error: Received master input for 
invalid service_fd 24: 24 3504 BYE
Sep 10 17:12:44 hinch4 dovecot: master: Error: service(log): child 23736 
killed with signal 11 (core dumps disabled)
Sep 10 17:12:44 hinch4 dovecot: imap(mhinch): Debug: Effective uid=1002, 
gid=1002, home=/home/mhinch
Sep 10 17:12:44 hinch4 dovecot: imap(mhinch): Debug: Namespace inbox: 
type=private, prefix=, sep=, inbox=yes, hidden=no, list=yes, s

ubscriptions=yes location=mbox:~/mail:INBOX=/var/mail/mhinch
Sep 10 17:12:44 hinch4 dovecot: imap(mhinch): Debug: fs: 
root=/home/mhinch/mail, index=, control=, inbox=/var/mail/mhinch, alt=


many more logging messages deleted. This continued until I restarted 
dovecot. Never again

have I seen a log message ...


Bob: Problem #2 - many doncecot/imap-login processes:
The Thunderbird setting for "connection to cache" is 5. The setting of 
100 is on

the server side as default_process_limit.
However, the 5 is interesting. That seems to say that tbird has forgotten
about all but 5 (max). I'll try to catch lsof -i output on these rogue 
processes

to see what IP state they are in. Any other ideas about where to go?

Thanks!

-Mark




On 9/11/2012 11:23 AM, Timo Sirainen wrote:

Something's very wrong. I have no idea what. doveconf -n output might help.

On 7.9.2012, at 14.39, Mark Hinch wrote:


I'm running 2.1.7 as downloaded/installed by Debian (and
then appropriately setup for my config, ...). It almost
works. I can send/receive email from thunderbird, squirrelmail, ...
However there are two anomalies:
1.  dovecot/log is not running. After restarting dovecot (and waiting
30 seconds), I have this in the log files:

Sep  6 17:42:16 hinch4 dovecot: master: Dovecot v2.1.7 starting up (core dumps 
disabled)
Sep  6 17:42:56 hinch4 dovecot: master: Error: service(anvil): Initial status 
notification not received in 30 seconds, killing the process
Sep  6 17:42:56 hinch4 dovecot: master: Error: service(log): Initial status 
notification not received in 30 seconds, killing the process
Sep  6 17:42:56 hinch4 dovecot: master: Error: service(ssl-params): Initial 
status notification not received in 30 seconds, killing the process
Sep  6 17:42:56 hinch4 dovecot: master: Error: service(log): child 31286 killed 
with signal 9

After 30 seconds, a "ps -ef | grep dovecot" yields:

dovenull  1858 20223  0 18:56 ?00:00:00 dovecot/imap-login
root  1859 20223  0 18:56 ?00:00:00 dovecot/auth -w
mhinch1860 20223  0 18:56 ?00:00:00 dovecot/imap
root  1862 14520  0 18:56 pts/300:00:00 grep dovecot
root 20223 1  0 18:54 ?00:00:00 /usr/sbin/dovecot -c 
/etc/dovecot/dovecot.conf
dovenull 25144 20223  0 18:55 ?00:00:00 dovecot/imap-login
dovecot  25147 20223  0 18:55 ?00:00:00 dovecot/anvil
root 25148 20223  0 18:55 ?00:00:00 dovecot/config
dovecot  25161 20223  0 18:55 ?00:00:00 dovecot/auth
root 25174 20223  0 18:55 ?00:00:00 dovecot/ssl-params
mhinch   25208 20223  0 18:55 ?00:00:00 dovecot/imap

Seems 

Re: [Dovecot] dovecot/log not running

2012-09-11 Thread Ben Johnson


On 9/11/2012 12:23 PM, Timo Sirainen wrote:
> Something's very wrong. I have no idea what. doveconf -n output might help.
> 
> On 7.9.2012, at 14.39, Mark Hinch wrote:
> 
>> I'm running 2.1.7 as downloaded/installed by Debian (and
>> then appropriately setup for my config, ...). It almost
>> works. I can send/receive email from thunderbird, squirrelmail, ...
>> However there are two anomalies:
>> 1.  dovecot/log is not running. After restarting dovecot (and waiting
>> 30 seconds), I have this in the log files:
>>
>> Sep  6 17:42:16 hinch4 dovecot: master: Dovecot v2.1.7 starting up (core 
>> dumps disabled)
>> Sep  6 17:42:56 hinch4 dovecot: master: Error: service(anvil): Initial 
>> status notification not received in 30 seconds, killing the process
>> Sep  6 17:42:56 hinch4 dovecot: master: Error: service(log): Initial status 
>> notification not received in 30 seconds, killing the process
>> Sep  6 17:42:56 hinch4 dovecot: master: Error: service(ssl-params): Initial 
>> status notification not received in 30 seconds, killing the process
>> Sep  6 17:42:56 hinch4 dovecot: master: Error: service(log): child 31286 
>> killed with signal 9
>>
>> After 30 seconds, a "ps -ef | grep dovecot" yields:
>>
>> dovenull  1858 20223  0 18:56 ?00:00:00 dovecot/imap-login
>> root  1859 20223  0 18:56 ?00:00:00 dovecot/auth -w
>> mhinch1860 20223  0 18:56 ?00:00:00 dovecot/imap
>> root  1862 14520  0 18:56 pts/300:00:00 grep dovecot
>> root 20223 1  0 18:54 ?00:00:00 /usr/sbin/dovecot -c 
>> /etc/dovecot/dovecot.conf
>> dovenull 25144 20223  0 18:55 ?00:00:00 dovecot/imap-login
>> dovecot  25147 20223  0 18:55 ?00:00:00 dovecot/anvil
>> root 25148 20223  0 18:55 ?00:00:00 dovecot/config
>> dovecot  25161 20223  0 18:55 ?00:00:00 dovecot/auth
>> root 25174 20223  0 18:55 ?00:00:00 dovecot/ssl-params
>> mhinch   25208 20223  0 18:55 ?00:00:00 dovecot/imap
>>
>> Seems like everything is there except dovecot/log.  ssl-params and anvil 
>> came back (?!?).
>> A  "doveadm log find" dumps this in the log:
>> Sep  6 18:52:24 hinch4 dovecot: doveadm: Debug: This is Dovecot's debug log 
>> (1346975543)
>> Sep  6 18:52:24 hinch4 dovecot: doveadm: This is Dovecot's info log 
>> (1346975543)
>> Sep  6 18:52:24 hinch4 dovecot: doveadm: Warning: This is Dovecot's warning 
>> log (1346975543)
>> Sep  6 18:52:24 hinch4 dovecot: doveadm: Error: This is Dovecot's error log 
>> (1346975543)
>> Sep  6 18:52:24 hinch4 dovecot: doveadm: Fatal: This is Dovecot's fatal log 
>> (1346975543)
>>
>> However, further debugging that I try to do (see next problem) does not 
>> result in ANY
>> further input to the log files, even though I have all known logging turned 
>> on. So I *think*
>> that logging is not actually running. If I can get that started, then I'll 
>> take a crack at the
>> next problem myself ...
>>
>> 2. However, as long as I have your attention, my next problem is that it
>> seems like dovecot/imap-login hangs(?). After a few hours, I have something 
>> like:
>>
>> # ps -ef | grep dovecot
>> dovecot530 31186  0 18:49 ?00:00:00 dovecot/auth
>> root 13277 31186  0 17:47 ?00:00:00 dovecot/config
>> dovenull 13664 31186  0 18:44 ?00:00:00 dovecot/imap-login
>> root 20207 14520  0 18:54 pts/300:00:00 grep dovecot
>> dovenull 27599 31186  0 18:45 ?00:00:00 dovecot/imap-login
>> dovenull 27601 31186  0 18:45 ?00:00:00 dovecot/imap-login
>> dovenull 27603 31186  0 18:45 ?00:00:00 dovecot/imap-login
>> dovenull 27607 31186  0 18:45 ?00:00:00 dovecot/imap-login
>> root 31186 1  0 17:42 ?00:00:00 /usr/sbin/dovecot -c 
>> /etc/dovecot/dovecot.conf
>> dovecot  31289 31186  0 17:42 ?00:00:00 dovecot/anvil
>>
>> with exactly 100 imap-login processes. I'm the only meaningful user
>> on the machine (unless somebody is imap DoS-ing me), so this does not
>> make much sense. Obviously thunderbird is polling the machine and each
>> time is leaving around a imap-log process. As far as I can tell, thunderbird
>> successfully logs in (i.e., I get mail) though I can't be sure whether these
>> are successful logins or not (no logging!). What hangs imap-log processes 
>> for hours at a time?
>> After a while of course, dovecot will not start any new imap-login processes
>> so Thunderbird cannot get any more mail until I restart
>> dovecot. Then everything is OK for another 12 hours or so.
>>
>> Ideas on either problem?
>>
>> -Mark
>>
>>

Not sure on the first issue.

On the second issue, out of curiosity, what do you have defined in
Thunderbird's Account Settings -> [account in question] -> Server
Settings -> Advanced -> Maximum number of server connections to cache?
Is this value actually set to 100?

-Ben


Re: [Dovecot] dovecot/log not running

2012-09-11 Thread Timo Sirainen
Something's very wrong. I have no idea what. doveconf -n output might help.

On 7.9.2012, at 14.39, Mark Hinch wrote:

> I'm running 2.1.7 as downloaded/installed by Debian (and
> then appropriately setup for my config, ...). It almost
> works. I can send/receive email from thunderbird, squirrelmail, ...
> However there are two anomalies:
> 1.  dovecot/log is not running. After restarting dovecot (and waiting
> 30 seconds), I have this in the log files:
> 
> Sep  6 17:42:16 hinch4 dovecot: master: Dovecot v2.1.7 starting up (core 
> dumps disabled)
> Sep  6 17:42:56 hinch4 dovecot: master: Error: service(anvil): Initial status 
> notification not received in 30 seconds, killing the process
> Sep  6 17:42:56 hinch4 dovecot: master: Error: service(log): Initial status 
> notification not received in 30 seconds, killing the process
> Sep  6 17:42:56 hinch4 dovecot: master: Error: service(ssl-params): Initial 
> status notification not received in 30 seconds, killing the process
> Sep  6 17:42:56 hinch4 dovecot: master: Error: service(log): child 31286 
> killed with signal 9
> 
> After 30 seconds, a "ps -ef | grep dovecot" yields:
> 
> dovenull  1858 20223  0 18:56 ?00:00:00 dovecot/imap-login
> root  1859 20223  0 18:56 ?00:00:00 dovecot/auth -w
> mhinch1860 20223  0 18:56 ?00:00:00 dovecot/imap
> root  1862 14520  0 18:56 pts/300:00:00 grep dovecot
> root 20223 1  0 18:54 ?00:00:00 /usr/sbin/dovecot -c 
> /etc/dovecot/dovecot.conf
> dovenull 25144 20223  0 18:55 ?00:00:00 dovecot/imap-login
> dovecot  25147 20223  0 18:55 ?00:00:00 dovecot/anvil
> root 25148 20223  0 18:55 ?00:00:00 dovecot/config
> dovecot  25161 20223  0 18:55 ?00:00:00 dovecot/auth
> root 25174 20223  0 18:55 ?00:00:00 dovecot/ssl-params
> mhinch   25208 20223  0 18:55 ?00:00:00 dovecot/imap
> 
> Seems like everything is there except dovecot/log.  ssl-params and anvil came 
> back (?!?).
> A  "doveadm log find" dumps this in the log:
> Sep  6 18:52:24 hinch4 dovecot: doveadm: Debug: This is Dovecot's debug log 
> (1346975543)
> Sep  6 18:52:24 hinch4 dovecot: doveadm: This is Dovecot's info log 
> (1346975543)
> Sep  6 18:52:24 hinch4 dovecot: doveadm: Warning: This is Dovecot's warning 
> log (1346975543)
> Sep  6 18:52:24 hinch4 dovecot: doveadm: Error: This is Dovecot's error log 
> (1346975543)
> Sep  6 18:52:24 hinch4 dovecot: doveadm: Fatal: This is Dovecot's fatal log 
> (1346975543)
> 
> However, further debugging that I try to do (see next problem) does not 
> result in ANY
> further input to the log files, even though I have all known logging turned 
> on. So I *think*
> that logging is not actually running. If I can get that started, then I'll 
> take a crack at the
> next problem myself ...
> 
> 2. However, as long as I have your attention, my next problem is that it
> seems like dovecot/imap-login hangs(?). After a few hours, I have something 
> like:
> 
> # ps -ef | grep dovecot
> dovecot530 31186  0 18:49 ?00:00:00 dovecot/auth
> root 13277 31186  0 17:47 ?00:00:00 dovecot/config
> dovenull 13664 31186  0 18:44 ?00:00:00 dovecot/imap-login
> root 20207 14520  0 18:54 pts/300:00:00 grep dovecot
> dovenull 27599 31186  0 18:45 ?00:00:00 dovecot/imap-login
> dovenull 27601 31186  0 18:45 ?00:00:00 dovecot/imap-login
> dovenull 27603 31186  0 18:45 ?00:00:00 dovecot/imap-login
> dovenull 27607 31186  0 18:45 ?00:00:00 dovecot/imap-login
> root 31186 1  0 17:42 ?00:00:00 /usr/sbin/dovecot -c 
> /etc/dovecot/dovecot.conf
> dovecot  31289 31186  0 17:42 ?00:00:00 dovecot/anvil
> 
> with exactly 100 imap-login processes. I'm the only meaningful user
> on the machine (unless somebody is imap DoS-ing me), so this does not
> make much sense. Obviously thunderbird is polling the machine and each
> time is leaving around a imap-log process. As far as I can tell, thunderbird
> successfully logs in (i.e., I get mail) though I can't be sure whether these
> are successful logins or not (no logging!). What hangs imap-log processes for 
> hours at a time?
> After a while of course, dovecot will not start any new imap-login processes
> so Thunderbird cannot get any more mail until I restart
> dovecot. Then everything is OK for another 12 hours or so.
> 
> Ideas on either problem?
> 
> -Mark
> 



[Dovecot] dovecot/log not running

2012-09-07 Thread Mark Hinch

I'm running 2.1.7 as downloaded/installed by Debian (and
then appropriately setup for my config, ...). It almost
works. I can send/receive email from thunderbird, squirrelmail, ...
However there are two anomalies:
1.  dovecot/log is not running. After restarting dovecot (and waiting
30 seconds), I have this in the log files:

Sep  6 17:42:16 hinch4 dovecot: master: Dovecot v2.1.7 starting up (core 
dumps disabled)
Sep  6 17:42:56 hinch4 dovecot: master: Error: service(anvil): Initial 
status notification not received in 30 seconds, killing the process
Sep  6 17:42:56 hinch4 dovecot: master: Error: service(log): Initial 
status notification not received in 30 seconds, killing the process
Sep  6 17:42:56 hinch4 dovecot: master: Error: service(ssl-params): 
Initial status notification not received in 30 seconds, killing the process
Sep  6 17:42:56 hinch4 dovecot: master: Error: service(log): child 31286 
killed with signal 9


After 30 seconds, a "ps -ef | grep dovecot" yields:

dovenull  1858 20223  0 18:56 ?00:00:00 dovecot/imap-login
root  1859 20223  0 18:56 ?00:00:00 dovecot/auth -w
mhinch1860 20223  0 18:56 ?00:00:00 dovecot/imap
root  1862 14520  0 18:56 pts/300:00:00 grep dovecot
root 20223 1  0 18:54 ?00:00:00 /usr/sbin/dovecot -c 
/etc/dovecot/dovecot.conf

dovenull 25144 20223  0 18:55 ?00:00:00 dovecot/imap-login
dovecot  25147 20223  0 18:55 ?00:00:00 dovecot/anvil
root 25148 20223  0 18:55 ?00:00:00 dovecot/config
dovecot  25161 20223  0 18:55 ?00:00:00 dovecot/auth
root 25174 20223  0 18:55 ?00:00:00 dovecot/ssl-params
mhinch   25208 20223  0 18:55 ?00:00:00 dovecot/imap

Seems like everything is there except dovecot/log.  ssl-params and anvil 
came back (?!?).

A  "doveadm log find" dumps this in the log:
Sep  6 18:52:24 hinch4 dovecot: doveadm: Debug: This is Dovecot's debug 
log (1346975543)
Sep  6 18:52:24 hinch4 dovecot: doveadm: This is Dovecot's info log 
(1346975543)
Sep  6 18:52:24 hinch4 dovecot: doveadm: Warning: This is Dovecot's 
warning log (1346975543)
Sep  6 18:52:24 hinch4 dovecot: doveadm: Error: This is Dovecot's error 
log (1346975543)
Sep  6 18:52:24 hinch4 dovecot: doveadm: Fatal: This is Dovecot's fatal 
log (1346975543)


However, further debugging that I try to do (see next problem) does not 
result in ANY
further input to the log files, even though I have all known logging 
turned on. So I *think*
that logging is not actually running. If I can get that started, then 
I'll take a crack at the

next problem myself ...

2. However, as long as I have your attention, my next problem is that it
seems like dovecot/imap-login hangs(?). After a few hours, I have 
something like:


# ps -ef | grep dovecot
dovecot530 31186  0 18:49 ?00:00:00 dovecot/auth
root 13277 31186  0 17:47 ?00:00:00 dovecot/config
dovenull 13664 31186  0 18:44 ?00:00:00 dovecot/imap-login
root 20207 14520  0 18:54 pts/300:00:00 grep dovecot
dovenull 27599 31186  0 18:45 ?00:00:00 dovecot/imap-login
dovenull 27601 31186  0 18:45 ?00:00:00 dovecot/imap-login
dovenull 27603 31186  0 18:45 ?00:00:00 dovecot/imap-login
dovenull 27607 31186  0 18:45 ?00:00:00 dovecot/imap-login
root 31186 1  0 17:42 ?00:00:00 /usr/sbin/dovecot -c 
/etc/dovecot/dovecot.conf

dovecot  31289 31186  0 17:42 ?00:00:00 dovecot/anvil

with exactly 100 imap-login processes. I'm the only meaningful user
on the machine (unless somebody is imap DoS-ing me), so this does not
make much sense. Obviously thunderbird is polling the machine and each
time is leaving around a imap-log process. As far as I can tell, thunderbird
successfully logs in (i.e., I get mail) though I can't be sure whether these
are successful logins or not (no logging!). What hangs imap-log 
processes for hours at a time?

After a while of course, dovecot will not start any new imap-login processes
so Thunderbird cannot get any more mail until I restart
dovecot. Then everything is OK for another 12 hours or so.

Ideas on either problem?

-Mark