Strange Timeout issue

maedball

Hiho,

I am currently fighting a somehow strange issue which I can not fix.

I have enabled z-push IMAP only as backend with a dovecot in behind.

Once i start the connection the sync starts fine (I can see the mails in the mailbox and the folders. After ~20 seconds every client (outlook, ios mail) comes up with a login request and I see in the error log an error:

10/05/2021 00:12:21 [ 1351] [ INFO] [michael.klein] AuthenticationRequiredException: Access denied. Username or password incorrect - code: 0 - file: /usr/share/z-push/lib/request/requestprocessor.php:69
10/05/2021 00:12:21 [ 1351] [ INFO] [michael.klein] User-agent: 'Outlook/16.0 (16.0.13929.20192; x64)'
10/05/2021 00:12:21 [ 1351] [FATAL] [michael.klein] Exception: (AuthenticationRequiredException) - Access denied. Username or password incorrect

I have moved all mails out of this account, just to verify this is not caused by a broken mail or folder.

Hope someone has an idea ;-)

Thank you!

bob4os

What is your max_execution_time in php.ini?

maedball

@bob4os I used the overwrite setting in the nginx config:

fastcgi_param PHP_VALUE “post_max_size=20M \n upload_max_filesize=20M \n max_execution_time=3660”;

However I have set it now directly in the fpm config, still the same effect. with a little different error message: The interesting part is that it is connecting but suddenly stopping to connect. Once i reenter the password everything is running fine again.

12/06/2021 23:32:49 [ 1348] [WARN] [maedball] /usr/share/z-push/backend/imap/imap.php:127 imap_open(): Couldn't open stream {myserver.server.net:993/imap/ssl} (2)
12/06/2021 23:32:49 [ 1348] [ERROR] [maedball] BackendIMAP->Logon(): can't connect as user 'maedball' on '{myserver.server.net:993/imap/ssl}': Can not authenticate to IMAP server: [CLOSED] IMAP connection broken (authenticate)
12/06/2021 23:32:49 [ 1348] [FATAL] [maedball] Exception: (AuthenticationRequiredException) - Access denied. Username or password incorrect
12/06/2021 23:32:49 [ 1348] [WARN] [maedball] IP: XXX.XXX.XXX.XXX failed to authenticate user 'maedball'
12/06/2021 23:32:49 [ 1348] [WARN] [maedball] Unknown:0 Unknown: Can not authenticate to IMAP server: [CLOSED] IMAP connection broken (authenticate) (errflg=2) (8)
12/06/2021 23:33:10 [34892] [FATAL] [maedball] Exception: (ProvisioningRequiredException) - Retry after sending a PROVISION command

bob4os

I think your PHP instance may be limited in its resources.

For PHP I recommend:
; large mails will need a lot of space, when they are analysed and will be in memory not only once - another contributor and me improved this a bit last year, but still… Use at least 256MB if your mail is about 50MB
memory_limit = 256M

; emails are base64 encoded, at the time they are sent - add another 30-40%
upload_max_filesize = 64M
post_max_size = 64M

Are you using opcache? I recommend you do:
opcache.enable=1
opcache.interned_strings_buffer=8
opcache.memory_consumption=128
opcache.revalidate_freq=2

maedball

@bob4os :

thanks, I have changed the revalidate from 1 to 2 and increased max size and file size limits.

Maybe this issue is caused by my dovecot config. When changing to non SSL everything seems to be ok:

// Defines the server to which we want to connect
define('IMAP_SERVER', 'my server');

// connecting to default port (143)
define('IMAP_PORT', 143);
//define('IMAP_PORT', 993);

// best cross-platform compatibility (see http://php.net/imap_open for options)
define('IMAP_OPTIONS', '/notls/norsh');
//define('IMAP_OPTIONS', '/ssl');

bob4os

Are you using a connection limit with Dovecot?
Is there anything in your Dovecot logfiles if this is happening?

There is also the possibility, that your system is running out of entropy (random number pool)?
(You will find your available entropy in /proc/sys/kernel/random/entropy_avail - it should always stay above 1000 (max: 4096), the more the better. If your kernel is not able to deliver enough entropy, take a look at haveged.)

maedball

@bob4os

no error message, just the info that the connection was closed…

Jun 13 13:31:22 imap(maedball)<1392295><MuoAEaTE3r0AAAAAAAAAAAAAAAAAAAAB>: Info: Connection closed (No commands sent) in=0 out=400 deleted=0 expunged=0 trashed=0 hdr_count=0 hdr_bytes=0 body_count=0 body_bytes=0
Jun 13 13:31:24 imap-login: Info: Login: user=<maedball>, method=PLAIN, rip=::1, lip=::1, mpid=1392755, TLS, session=<nkutFKTEuL4AAAAAAAAAAAAAAAAAAAAB>