bug#32631: the Dovecot service stops working

bug#32631: the Dovecot service stops working

[Clément Lassieur]

Hi,

Sometimes the Dovecot service stops working, which is difficult to
notice.

Then I have to

    # herd restart dovecot

The only interesting thing I could find in the logs is:

    Sep  4 11:47:12 mail2 dovecot: master: Warning: service(imap-login): process_limit (100) reached, client connections are being dropped

Clément

bug#32631: the Dovecot service stops working

[Ludovic Courtès]

Hello,

Clément Lassieur <clement@lassieur.org> skribis:

> Sometimes the Dovecot service stops working, which is difficult to
> notice.

When it “stops working”, does the Shepherd service go down?  Does “herd
status dovecot” shows that it was respawned?  Is the dovecot process
still around?

Thanks,
Ludo’.

bug#32631: the Dovecot service stops working

[Clément Lassieur]

Ludovic Courtès <ludo@gnu.org> writes:

> Hello,
>
> Clément Lassieur <clement@lassieur.org> skribis:
>
>> Sometimes the Dovecot service stops working, which is difficult to
>> notice.
>
> When it “stops working”, does the Shepherd service go down?  Does “herd
> status dovecot” shows that it was respawned?  Is the dovecot process
> still around?

The dovecot process is still around, yes.  I has happened several times
already (maybe 5), but I only recently identified it as a bug.  I'll
investigate more when I encounter it again, but it's not easy to do
because I'm not the only user of the mail server.

I tagged it as serious because it affects my clients, and because it's
difficult to notice there's something wrong.

bug#32631: the Dovecot service stops working

[Ludovic Courtès]

Hi,

Clément Lassieur <clement@lassieur.org> skribis:

> Ludovic Courtès <ludo@gnu.org> writes:
>
>> Hello,
>>
>> Clément Lassieur <clement@lassieur.org> skribis:
>>
>>> Sometimes the Dovecot service stops working, which is difficult to
>>> notice.
>>
>> When it “stops working”, does the Shepherd service go down?  Does “herd
>> status dovecot” shows that it was respawned?  Is the dovecot process
>> still around?
>
> The dovecot process is still around, yes.  I has happened several times
> already (maybe 5), but I only recently identified it as a bug.  I'll
> investigate more when I encounter it again, but it's not easy to do
> because I'm not the only user of the mail server.

So it doesn’t look like a Shepherd issue, right?

Thanks,
Ludo’.

bug#32631: the Dovecot service stops working

[Clément Lassieur]

Ludovic Courtès <ludo@gnu.org> writes:

> Hi,
>
> Clément Lassieur <clement@lassieur.org> skribis:
>
>> Ludovic Courtès <ludo@gnu.org> writes:
>>
>>> Hello,
>>>
>>> Clément Lassieur <clement@lassieur.org> skribis:
>>>
>>>> Sometimes the Dovecot service stops working, which is difficult to
>>>> notice.
>>>
>>> When it “stops working”, does the Shepherd service go down?  Does “herd
>>> status dovecot” shows that it was respawned?  Is the dovecot process
>>> still around?
>>
>> The dovecot process is still around, yes.  I has happened several times
>> already (maybe 5), but I only recently identified it as a bug.  I'll
>> investigate more when I encounter it again, but it's not easy to do
>> because I'm not the only user of the mail server.
>
> So it doesn’t look like a Shepherd issue, right?

No, it looks like a dovecot service issue :-)

bug#32631: the Dovecot service stops working

[Oleg Pykhalov]

[-- Attachment #1: Type: text/plain, Size: 1063 bytes --]

Hello Clément,

Clément Lassieur <clement@lassieur.org> writes:

[…]

>>>>> Sometimes the Dovecot service stops working, which is difficult to
>>>>> notice.
>>>>
>>>> When it “stops working”, does the Shepherd service go down?  Does “herd
>>>> status dovecot” shows that it was respawned?  Is the dovecot process
>>>> still around?
>>>
>>> The dovecot process is still around, yes.  I has happened several times
>>> already (maybe 5), 

Do you mean the warning you posted before?
--8<---------------cut here---------------start------------->8---
Sep 4 11:47:12 mail2 dovecot: master: Warning: service(imap-login): process_limit (100) reached, client connections are being dropped
--8<---------------cut here---------------end--------------->8---

The ‘dovecot-configuration’ record has a ‘default-process-limit’ which
is setted to 100 by default.  Could you try to increase it?

Also a ‘process_limit’ configuration string is described on Dovecot Wiki.

  https://wiki.dovecot.org/LoginProcess

Thanks,
Oleg.

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 832 bytes --]

bug#32631: the Dovecot service stops working

[Clément Lassieur]

Hi Oleg,

Oleg Pykhalov <go.wigust@gmail.com> writes:

> Hello Clément,
>
> Clément Lassieur <clement@lassieur.org> writes:
>
> […]
>
>>>>>> Sometimes the Dovecot service stops working, which is difficult to
>>>>>> notice.
>>>>>
>>>>> When it “stops working”, does the Shepherd service go down?  Does “herd
>>>>> status dovecot” shows that it was respawned?  Is the dovecot process
>>>>> still around?
>>>>
>>>> The dovecot process is still around, yes.  I has happened several times
>>>> already (maybe 5), 
>
> Do you mean the warning you posted before?

I meant that my dovecot process stopped working 5 times already.

> --8<---------------cut here---------------start------------->8---
> Sep 4 11:47:12 mail2 dovecot: master: Warning: service(imap-login): process_limit (100) reached, client connections are being dropped
> --8<---------------cut here---------------end--------------->8---
>
> The ‘dovecot-configuration’ record has a ‘default-process-limit’ which
> is setted to 100 by default.  Could you try to increase it?

Well, I can, but that wouldn't fix the problem.  Two dovecot clients
shouldn't consume 100 processes.

> Also a ‘process_limit’ configuration string is described on Dovecot Wiki.
>
>   https://wiki.dovecot.org/LoginProcess

Thank you very much for that information, I'll have a look.

Clément

bug#32631: the Dovecot service stops working

[Clément Lassieur]

I just noticed

$ ps auxww | grep dovecot
dovenull   486  0.0  0.1  23708  5876 ?        S    Sep21   0:00 dovecot/imap-login
dovenull   596  0.0  0.1  23708  5752 ?        S    Sep25   0:00 dovecot/imap-login
dovenull   936  0.0  0.1  23708  5740 ?        S    Sep21   0:00 dovecot/imap-login
dovenull  1319  0.0  0.1  23708  5868 ?        S    Sep21   0:00 dovecot/imap-login
dovenull  1491  0.0  0.1  23708  5680 ?        S    Sep23   0:00 dovecot/imap-login
dovenull  1577  0.0  0.1  23708  5776 ?        S    Sep19   0:00 dovecot/imap-login
dovenull  2298  0.0  0.1  23708  5728 ?        S    Sep22   0:00 dovecot/imap-login
dovenull  2742  0.0  0.1  23708  5660 ?        S    Sep23   0:00 dovecot/imap-login
dovenull  2795  0.0  0.1  23708  5792 ?        S    Sep20   0:00 dovecot/imap-login
dovenull  3213  0.0  0.1  23708  5932 ?        S    Sep20   0:00 dovecot/imap-login
dovenull  4232  0.0  0.1  23708  5812 ?        S    Sep23   0:00 dovecot/imap-login
dovenull  4387  0.0  0.1  23708  5788 ?        S    Sep23   0:00 dovecot/imap-login
dovenull  4818  0.0  0.1  23708  5872 ?        S    Sep20   0:00 dovecot/imap-login
dovenull  6154  0.0  0.1  23708  5780 ?        S    Sep20   0:00 dovecot/imap-login
dovenull  6971  0.0  0.1  23708  5888 ?        S    Sep20   0:00 dovecot/imap-login
dovenull  7314  0.0  0.1  23708  5808 ?        S    Sep20   0:00 dovecot/imap-login
dovenull  7823  0.0  0.1  23708  5696 ?        S    Sep20   0:00 dovecot/imap-login
dovenull  8485  0.0  0.1  23708  5844 ?        S    Sep24   0:00 dovecot/imap-login
dovenull  8812  0.0  0.1  23708  5800 ?        S    Sep25   0:00 dovecot/imap-login
dovenull  8980  0.0  0.1  23708  5876 ?        S    Sep22   0:00 dovecot/imap-login
dovenull  9603  0.0  0.1  23708  5656 ?        S    Sep22   0:00 dovecot/imap-login
dovenull 10566  0.0  0.1  23708  5860 ?        S    Sep20   0:00 dovecot/imap-login
dovenull 10735  0.0  0.1  23708  5868 ?        S    Sep20   0:00 dovecot/imap-login
dovenull 11313  0.0  0.1  23708  5824 ?        S    Sep20   0:00 dovecot/imap-login
dovenull 11480  0.0  0.1  23708  5800 ?        S    Sep22   0:00 dovecot/imap-login
dovenull 11591  0.0  0.1  23708  5824 ?        S    Sep25   0:00 dovecot/imap-login
dovenull 12528  0.0  0.1  23708  5824 ?        S    Sep22   0:00 dovecot/imap-login
dovenull 13824  0.0  0.1  23708  5840 ?        S    Sep24   0:00 dovecot/imap-login
dovenull 14497  0.0  0.1  23708  5872 ?        S    Sep24   0:00 dovecot/imap-login
dovenull 14608  0.0  0.1  23708  5652 ?        S    Sep24   0:00 dovecot/imap-login
dovenull 15108  0.0  0.1  23708  5840 ?        S    Sep21   0:00 dovecot/imap-login
dovenull 15167  0.0  0.1  23708  5656 ?        S    Sep21   0:00 dovecot/imap-login
dovenull 15446  0.0  0.1  23708  5776 ?        S    Sep22   0:00 dovecot/imap-login
dovenull 15524  0.0  0.1  23708  5752 ?        S    Sep22   0:00 dovecot/imap-login
dovenull 20718  0.0  0.1  23708  5748 ?        S    11:19   0:00 dovecot/imap-login
dovenull 20818  0.0  0.1  23708  5868 ?        S    Sep24   0:00 dovecot/imap-login
dovenull 21254  0.0  0.1  23708  5804 ?        S    Sep21   0:00 dovecot/imap-login
dovenull 23678  0.0  0.1  23708  5932 ?        S    15:02   0:00 dovecot/imap-login
dovenull 24110  0.0  0.1  23708  5860 ?        S    Sep23   0:00 dovecot/imap-login
dovenull 24286  0.0  0.1  23708  5872 ?        S    Sep24   0:00 dovecot/imap-login
dovenull 24287  0.0  0.1  23708  5724 ?        S    Sep24   0:00 dovecot/imap-login
root     26297  0.0  0.0  14572  3180 ?        Ss   Sep19   0:05 /gnu/store/3sa5vslnqc7kvx2l6ngbdjl1np8kbwzn-dovecot-2.3.1/sbin/dovecot -F
dovecot  26298  0.0  0.0  12176  2568 ?        S    Sep19   0:02 dovecot/anvil
root     26299  0.0  0.0  12304  2796 ?        S    Sep19   0:02 dovecot/log
root     26300  0.0  0.1  17164  5712 ?        S    Sep19   0:08 dovecot/config
dovecot  26304  0.0  0.0  12288  2688 ?        S    Sep19   0:04 dovecot/stats
dovecot  27246  0.0  0.0  23152  3564 ?        S    18:30   0:00 dovecot/auth
dovenull 27308  0.0  0.1  23708  5712 ?        S    18:36   0:00 dovecot/imap-login
vmail    27309  0.0  0.1  16544  5216 ?        S    18:36   0:00 dovecot/imap
dovenull 27322  0.0  0.1  23708  5828 ?        S    18:36   0:00 dovecot/imap-login
vmail    27323  0.0  0.1  15820  4256 ?        S    18:36   0:00 dovecot/imap
dovenull 27336  0.0  0.1  23708  5792 ?        S    Sep21   0:00 dovecot/imap-login
dovenull 27337  0.0  0.1  23708  5760 ?        S    Sep21   0:00 dovecot/imap-login
dovenull 27490  0.0  0.1  23708  5792 ?        S    Sep21   0:00 dovecot/imap-login
clement  27551  0.0  0.0   8260  1640 pts/0    S+   18:52   0:00 grep dovecot
dovenull 27756  0.0  0.1  23708  5872 ?        S    Sep21   0:00 dovecot/imap-login
dovenull 28129  0.0  0.1  23708  5828 ?        S    Sep21   0:00 dovecot/imap-login
dovenull 28551  0.0  0.1  23708  5752 ?        S    Sep21   0:00 dovecot/imap-login
dovenull 28779  0.0  0.1  23708  5872 ?        S    Sep21   0:00 dovecot/imap-login
dovenull 29154  0.0  0.1  23708  5744 ?        S    Sep19   0:00 dovecot/imap-login
dovenull 29713  0.0  0.1  23708  5680 ?        S    Sep19   0:00 dovecot/imap-login
dovenull 29794  0.0  0.1  23708  5872 ?        S    Sep21   0:00 dovecot/imap-login
dovenull 31659  0.0  0.1  23708  5752 ?        S    Sep19   0:00 dovecot/imap-login
dovenull 32114  0.0  0.1  23708  5760 ?        S    Sep21   0:00 dovecot/imap-login
dovenull 32535  0.0  0.1  23708  5740 ?        S    Sep19   0:00 dovecot/imap-login
dovenull 32646  0.0  0.1  23708  5756 ?        S    Sep21   0:00 dovecot/imap-login

bug#32631: the Dovecot service stops working

[Clément Lassieur]

So, today I investigated a bit.

I found [1] and [2] interesting.  I didn't do anything about [1], but I
enabled cache in my configuration.

Then I went to #dovecot@freenode and someone advised me to switch to
high-performance mode[6], which I did:

--8<---------------cut here---------------start------------->8---
<hidden> do you have same uid/gid for all users or do they each have their own?
<hidden> snape, if you have same uid/gid then set service_count = 0 for
       imap-login, otherwise set it to 1  [13:45]
<hidden> and in latter scenario also set client_limit to 1  [13:46]
<snape> hidden: there is one vmail user  [13:47]
<hidden> then you can set service_count = 0, process_limit = number of cores,
       process_min_avail = same as process limit and client_limit to something
<snape> you mean, client_limit to 0?  [13:53]
<hidden> total concurrency is process_limit * client_limit for tls connections
<hidden> non-tls connections are moved to imap process after logik
<hidden> login
<snape> ok so you suggest I switch to high-performance mode  [13:54]
<hidden> yes
<snape> because it doesn't make sense to use high-security mode if all users
	share the same uid/gid?  [13:55]
<snape> i.e. if I use vmail?
<hidden> the important part here is that if you set client_limit to anything
       above 1 the service_count needs to be 0
<hidden> yeah, in general we recommend high performance mode  [13:56]
--8<---------------cut here---------------end--------------->8---

In order to do the switch I had to modify the service so that it accepts
the client-limit[3] and process-limit[4] options.

I also fixed[5] the default value of 'service-count' for the "auth"
service to 'unlimited', in case it matters.

At least, now I don't seem to have these ever-growing imap-login
processes anymore, so I'm closing this bug.  I'll re-open it if it
happens again.

Cheers,
Clément

[1]: https://www.dovecot.org/list/dovecot/2011-December/080264.html
[2]: https://dovecot.org/pipermail/dovecot/2008-May/030813.html
[3]: https://git.savannah.gnu.org/cgit/guix.git/commit/?id=8d9bb4b4d05a20bef1cf7b1da2b1c5fb05f9b071
[4]: https://git.savannah.gnu.org/cgit/guix.git/commit/?id=be8dd4a5fec804f2f004dd3a87c2872af44dc88d
[5]: https://git.savannah.gnu.org/cgit/guix.git/commit/?id=a7553a7360ac07ff114b807fc3026f08158d34c8
[6]: https://wiki.dovecot.org/LoginProcess