dovecot - Sep 2011 - Warning: Subscriptions file .. Removing invalid entry:

One of our dovecot-servers (v2.0.14) got a bit too busy last evening:

	Sep 13 20:39:18 popimap1 dovecot: master: Warning: service(pop3-login):
process_limit reached, client connections are being dropped

then logged a few:

	Sep 13 20:39:20 popimap1 dovecot: pop3(XXXXXXXXX at YYYYY.YY): Warning: I/O
leak: 0x3829233d20 (10)
	Sep 13 20:39:20 popimap1 dovecot: pop3(XXXXXXXXX at YYYYY.YY): Warning: Timeout
leak: 0x3829233ce0
	Sep 13 20:39:20 popimap1 dovecot: pop3(ZZZZZ.ZZZZZ at ZZZZZZ.ZZ): Warning: I/O
leak: 0x3829233d20 (10)
	Sep 13 20:39:20 popimap1 dovecot: pop3(ZZZZZ.ZZZZZ at ZZZZZZ.ZZ): Warning:
Timeout leak: 0x3829233ce0
	Sep 13 20:39:20 popimap1 dovecot: pop3(YYYYYYY at YYYY.YYY): Warning: I/O leak:
0x3829233d20 (10)
	Sep 13 20:39:20 popimap1 dovecot: pop3(YYYYYYY at YYYY.YYY): Warning: Timeout
leak: 0x3829233ce0
	Sep 13 20:39:20 popimap1 dovecot: pop3-postlogin: Error: Fatal: fd_send()
failed: Broken pipe
	Sep 13 20:39:20 popimap1 dovecot: pop3-postlogin: Error: Fatal: fd_send()
failed: Broken pipe

and:
	Error: net_connect_unix(/var/run/dovecot/pop3-postlogin) failed: Resource
temporarily unavailable


but what has me a bit worried is these:

	imap(user at xxx.xxx): Warning: Subscriptions file /path/to/user at
xxx.xxx/subscriptions: Removing invalid entry: .Sent
	imap(user at xxx.xxx): Warning: Subscriptions file /path/to/user at
xxx.xxx/subscriptions: Removing invalid entry: .Spam
	imap(user at xxx.xxx): Warning: Subscriptions file /path/to/user at
xxx.xxx/subscriptions: Removing invalid entry: .Drafts
	imap(user at xxx.xxx): Warning: Subscriptions file /path/to/user at
xxx.xxx/subscriptions: Removing invalid entry: .Trash

which happened for a two users during this high load periode. Looking at
their mail directory I can't see why these should be invalid? They're
there,
has sane permissions and contains messages..


  -jf

On Wed, Sep 14, 2011 at 09:12:52AM +0200, Jan-Frode Myklebust
wrote:
> but what has me a bit worried is these:
> 
> 	imap(user at xxx.xxx): Warning: Subscriptions file /path/to/user at
xxx.xxx/subscriptions: Removing invalid entry: .Sent
> 	imap(user at xxx.xxx): Warning: Subscriptions file /path/to/user at
xxx.xxx/subscriptions: Removing invalid entry: .Spam
> 	imap(user at xxx.xxx): Warning: Subscriptions file /path/to/user at
xxx.xxx/subscriptions: Removing invalid entry: .Drafts
> 	imap(user at xxx.xxx): Warning: Subscriptions file /path/to/user at
xxx.xxx/subscriptions: Removing invalid entry: .Trash
> 
> which happened for a two users during this high load periode. Looking at
> their mail directory I can't see why these should be invalid?
They're there,
> has sane permissions and contains messages..
I see now that this probably has nothing to do with the pop3 process_limit.
It's been happening regularly since we upgraded from v1.2.16 to v2.0 on
August 30.  Initially 200+ times a day, but has dropped down to 30-50
times a day for the last few days. Probably because of subscription
files getting emptied for the imap-users.

Is this a problem with our namespace:

	namespace {
  		inbox = yes
  		location = 
  		prefix = INBOX.
  		type = private
	}

which for v1.2.x was defined as:

	namespace private {
   		prefix = INBOX.
   		inbox = yes
	}



  -jf

On Wed, 2011-09-14 at 09:12 +0200, Jan-Frode Myklebust
wrote:
> One of our dovecot-servers (v2.0.14) got a bit too busy last evening:
> 
> 	Sep 13 20:39:18 popimap1 dovecot: master: Warning: service(pop3-login):
process_limit reached, client connections are being dropped
> 
> then logged a few:
> 
> 	Sep 13 20:39:20 popimap1 dovecot: pop3(XXXXXXXXX at YYYYY.YY): Warning:
I/O leak: 0x3829233d20 (10)
> 	Sep 13 20:39:20 popimap1 dovecot: pop3(XXXXXXXXX at YYYYY.YY): Warning:
Timeout leak: 0x3829233ce0
Could you show the output of:

gdb /usr/local/libexec/dovecot/pop3 # or whatever path it is in
x 0x3829233d20
x 0x3829233ce0

I guess the client isn't being destroyed properly for some reason..
> but what has me a bit worried is these:
> 
> 	imap(user at xxx.xxx): Warning: Subscriptions file /path/to/user at
xxx.xxx/subscriptions: Removing invalid entry: .Sent
> 	imap(user at xxx.xxx): Warning: Subscriptions file /path/to/user at
xxx.xxx/subscriptions: Removing invalid entry: .Spam
> 	imap(user at xxx.xxx): Warning: Subscriptions file /path/to/user at
xxx.xxx/subscriptions: Removing invalid entry: .Drafts
> 	imap(user at xxx.xxx): Warning: Subscriptions file /path/to/user at
xxx.xxx/subscriptions: Removing invalid entry: .Trash
These are simply broken subscription entries that have never worked.
They're not supposed to begin with a ".". In older Dovecot
versions they
were shown to clients, but I don't know what clients would have done
with such broken entries. I guess some could have shown them
"correctly", some could have shown them in a broken way and some could
have just ignored them.