Dovecot: slow login and folder access and strange errors in log

Hi,

Hopefully someone can point me to a right direction with a new problem that appeared few weeks ago (probably after updates but cannot be 100% sure - config changes have not been done, that’s certain).

For some reason login using Thunderbird (multiple clients) or Android phone is slow. Same applies to accessing different IMAP folders. Once the folder is open it works fine but when I send an email and email client copies the message to sent folder it takes quite a long time. It gets there but takes a long time. And by long here I mean around 20 sec, maybe more. This used to work fine not so long ago - prompt access etc. but not anymore and I cannot figure out what is causing this. Any idea?

And the errors I get from service dovecot status is following:

master: Error: service(stats): command startup failed, throttling for xx secs

I’ve added following to 10-master.conf (after googling heavily for a resolution):

service stats {
   fifo_listener stats-mail {
     mode = 0666
     user = root
   }
   fifo_listener stats-user {
     mode = 0666
     user = root
   }
   unix_listener stats {
     mode = 0666
     user = root
   }
}

but doesn’t make a difference. How to get rid of these errors?

When there is an error, you should post the entire error.
So, for instance, did you invoke systmctl or not?
For example

systemctl status dovecot

You can also use the journalctl command to parse for <all> messages related to a service, or filter for errors, by timestamp, etc.
There a great many blogs on the Internet which can provide the syntax you need for these kinds of searches, or you can read the MAN pages on journalctl.

If you get stuck either finding the right commands or interpreting results, post again…

HTH,
TSU

Error log I got using command (soon to be obsolete, IIRC):

service dovecot status

Following log entries (data, time and IP address removed from the start):

master: Fatal: execv(/usr/lib/dovecot/stats) failed: Permission denied
stats: Fatal: master: service(stats): child 957 returned error 84 (exec() failed)
master: Error: service(stats): command startup failed, throttling for 60 secs

There are now 2 more log entries. This set is repeated every minute (after throttling).

journalctrl returns only:

journalctl _COMM=dovecot
master: Error: service(stats): command startup failed, throttling for 60 secs

Same error repeated every minute. No other errors.

systemctl and journalctl are commands, and you add options, switches and attributes to query for specific information.

So,
For instance instead of your “service” command, the systemctl equivalent should return much more information, and probably a larger snippet from your system log, ie

systemctl status dovecot

Similarly,
journalctl accepts a variety of parameters that restricts the output returned to whatever you want.

For both of the above commands, you should skim or read closely the usual documentation, including

  • The “help” file usually provides the available syntax with brief explanation, eg
systemctl --help
journalctl --help
  • The MAN pages provide in depth explanation, often they can be so large that you might become familiar with how to search or return specific text… Commands are usually same as vim, and you can pipe results to grep.
  • Particularly with systemctl and journalctl, there are a number of really good blogs which can strike a happy medium between the very abbreviated “help” and the sometimes voluminous MAN pages. Blogs also often provide specific examples you can paste into your console.

When you post the results of commands like systemctl and journalctl, always provide both the command as well as the result. If you post only the result, no one knows whether you invoked the proper command or not (Making people guess is like a game of Jeopardy).

From the very sparse errors you’ve posted, I’m not certain if the permissions errors are related to the Service or User credentials. Either suggests that the way you installed your mail system may be important, so you’ll likely have to dig up the reference or guide you used for your initial installation and configuration and double-check those are still correct… And post a link or location of that reference for others to understand what you’re doing.

TSU

Thx for the response but there was not much that would help me. Errors may be sparse but that’s all there is (dovocot stauts provides a bit different log than journalctrl - that’s it). Normal OpenSuSe packages that has been in use for few years now (of course updated dozens of times - if not more than hundred) and I have to repeat that no changes have been made to any of the configs. Previously no such delay issue in login but suddenly it appeared - probably related to updating of packages but that doesn’t help much. Errors have been there much longer - just been annoying but haven’t bothered nor prevented any of my usage of dovecot.

Hello paju2000,

Stauts? :sarcastic:

Anyway, two things come to my mind that might help a bit:

  1. dovecot logging: in /etc/dovecot/conf.d/10-logging.conf, add:
log_path = /var/log/dovecot.log
info_log_path = /var/log/dovecot-info.log
debug_log_path = /var/log/dovecot-debug.log

Restart dovecot and inspect those logfiles.

  1. In the past I had a problem with dovecot concerning apparmor: Can’t open log file /var/log/dovecot.log: Permission denied.

This error message might not apply to you, but perhaps the solution does (= disabling apparmor):

systemctl is-active apparmor.service

If that command returns “active”, then you have apparmor running. See if disabling it (perhaps temporary) solves your problem:

systemctl stop apparmor.service
systemctl disable apparmor.service
systemctl restart dovecot.service

(Perhaps a reboot is necessary).

To enable apparmor again:

systemctl start apparmor.service
systemctl enable apparmor.service

Kind regards,

Leen

Logging didn’t work for some reason.

However, I might have found the issue but don’t know how to solve it yet. DNS is incorrect and cannot find how to fix it. I’m using dnsmasq and settings there are in order but still DHCP provides my server (10.1.1.10) as DNS for clients and not what I’ve configured in dnsmasq.conf. I’ve searched all configs under /etc and sub-folders but nothing helps. I used to have 10.1.1.10 as DNS long time ago but this was changed. There were some old remains in dhcpd.conf but that is fixed as well - and it’s not used anyhow because of dnsmasq. So, any idea from where to try to find this problem?

Interesting finding… for some reason there was two dns server running at the same time. I don’t think I’ve started the other one (dns-server). There’s still something fishy ongoing because LAN connected devices get proper DNS settings but WLAN devices not - still getting incorrect 10.1.1.10 DNS (3 different APs in use - all behaving the same way).

Some network actions are faster now but the “sending secure login information” by Thunderbird still takes very long time. So, this was not the solution after all to the problem.

That’s why I personally dislike using dnsmasq unless it’s part of a bigger system… Although when it works, everything is automatic and lightweight and works beautifully, when there are problems I don’t feel as comfortable troubleshooting compared to regular DNS and DHCP services.

A simple thing to check is the network configurations for every network interface,
Unless there is a special reason, all should not have DNS settings, and maybe should also not have their network configurations set by DHCP (at most, they should only have their IP address configured and nothing else).

Then restart your name cache daemon to clear out your local name cache.

systemctl restart nscd.service

TSU

I’ve managed to narrow the problem down somewhat. First of all adding imap and mail configs to pam-folder improved login time which is almost acceptable now.

The delay seems to be caused by the stats functionality of dovecot that changed from 2.2 to 2.3. For some reason this fails.

doveadm stats dump takes 20-30s to 100s to complete resulting error: “Fatal: /var/run/dovecot/stats-reader: Failed to read VERSION line”.

Dovecot logs give following info:


master: Error: service(stats): command startup failed, throttling for 60 secs
stats: Fatal: master: service(stats): child 14797 killed with signal 6 (core not dumped - https://dovecot.org/bugreport.html#coredumps - try to clear service stats { chroot = } )

Asks to clear stats but that fails with the error code. So, slightly problematic situation.

There is also a new error that has recently appeared in dovecot log:


stats: Panic: epoll_ctl(add, 10) failed: Operation not permitted (fd doesn't support epoll)

No idea what is causing this error…

Anyhow, seems pretty clear now that it’s the new statistic component that is causing the delay. Any idea how to solve this?

Any idea how to solve the statistics issue of dovecot?