SSL Connection gets disconneded

maedball

@bob4os In total 4. My guess is that this has nothing todo with any limits. The clients are reconnecting regularly around once per minute to dovecot.

Thunderbird or outlook just connect fine via IMAP.

This is what i found in dovecot, but it just looks like a normal timout due to no activity.

nfo: 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

maedball

Or this one as it always happens right before the disconnect

 /usr/share/z-push/backend/imap/imap.php:2382 imap_ping() expects parameter 1 to be resource, bool given (2)

thctlo

@maedball said in SSL Connection gets disconneded:

imap_ping

i suggest report it as bug.
Thats a good find.

bob4os

imap_ping() is only performing a check, if the resource “$this->mbox” is still connected.
Your error message

 /usr/share/z-push/backend/imap/imap.php:2382 imap_ping() expects parameter 1 to be resource, bool given (2)

indicates that things went south already.

Z-Push’s IMAP backend tries to reconnect before performing IMAP actions, so this is to be expected.

Clients usually send an “IDLE” command, which keeps the IMAP connection alive and the server is sending pings back to the clients, checking if the client is still active.
The PHP IMAP extension does not support “IDLE” as far as I know -> we have to reconnect…

bob4os

@maedball I just noticed “imap_idle_notify_interval = 29 mins” in your config - this is a really long time.
Every client that sends an “IDLE” command will have to wait 29 minutes, before Dovecot sends a ping if the client is still there - that is a really long time.
I suggest you set it back to default - there is no reason to wait that long.

telecom2k3

@maedball Make sure the SSL Cert is OK. Just thinking of the LetsEncrypt CA Cert expiration Friday. Maybe PHP needs an updated openssl.cafile? Got nothing else, sorry.

maedball

@telecom2k3 said in SSL Connection gets disconneded:

openssl.cafile

What i am struggling with, is that it is working (so all mails get synced, still the log is full of errors + outlook throws a password request which can be simply confirmed with the ok button)

Is there any logging which i can enable to do some further investigation?

boospy

I have the same problem here, but only with the Kopano Enterprise Updateservers.

maedball

I have opened a ticket: In addition i took a bath in the massive log and found this, not sure if this adds some clues:

04/10/2021 00:40:29 [ 1418] [DEBUG] [michael.klein] [7usfm7ugbd1tb3toklq5c8k3e8] BackendCombined->ChangesSink(30)
04/10/2021 00:40:29 [ 1418] [DEBUG] [michael.klein] [7usfm7ugbd1tb3toklq5c8k3e8] BackendCombined->ChangesSink - Calling in 'BackendIMAP' with 10
04/10/2021 00:40:29 [ 1418] [DEBUG] [michael.klein] [7usfm7ugbd1tb3toklq5c8k3e8] BackendIMAP->close_connection(): disconnected from IMAP server

bob4os

No, “Calling in BackendIMAP with 10” is just a message indicating that you are using the combined backend and the BackendIMAP is supposed to take at least 10s to return a result.
And close_connection() is used in the ChangesSink() function to reduce concurrent connections to your IMAP server.

I have no idea of what is going on in your setup…

bob4os

What is your hardware?

maedball

@bob4os : First again thank you for all the efforts you are putting in helping!:

Processor information: Intel® Xeon® W-1270P CPU @ 3.80GHz, 16 cores
Real memory: 62.64 GiB total
Operating system: Ubuntu Linux 20.04.3
Local disk space: Local disk space

bob4os

Well, this hardware should be more than sufficient.

maedball

Another day, another log search.

Once i use a non SSL connection to the Mailserver i get some more log errors from z-push.

Mainly 3 different error messages on first sync

06/10/2021 21:40:35 [87856] [WARN] [daliane.klein] /usr/share/z-push/include/mimeDecode.php:352 Undefined offset: 1 (8)

06/10/2021 21:40:35 [87856] [WARN] [daliane.klein] /usr/share/z-push/backend/imap/imap.php:1449 Undefined offset: 0 (8)

06/10/2021 21:41:01 [2160847] [WARN] [daliane.klein] /usr/share/z-push/backend/caldav/caldav.php:841 A non-numeric value encountered (2)

the obvious error message that this is now a plain connection even thou it is going via localhost ;-)

06/10/2021 21:40:28 [2213332] [WARN] [daliane.klein] Unknown:0 Unknown: SECURITY PROBLEM: insecure server advertised AUTH=PLAIN (errflg=1) (8)

Sometimes i see the following

06/10/2021 21:47:56 [197748] [ERROR] [daliane.klein] ImportChangesCombined->Config() icc not configured

06/10/2021 21:47:56 [197748] [WARN] [daliane.klein] /usr/share/z-push/lib/default/diffbackend/diffstate.php:230 count(): Parameter must be an array or an object that implements Countable (2)

06/10/2021 21:47:58 [ 1416] [WARN] [daliane.klein] /usr/share/z-push/backend/imap/imap.php:1128 implode(): Invalid arguments passed (2)
06
06/10/2021 22:04:05 [2773723] [FATAL] [daliane.klein] Exception: (ProvisioningRequiredException) - Retry after sending a PROVISION command

06/10/2021 22:26:38 [3924469] [ERROR] [michael.klein] TimezoneUtil::guessTZNameFromPHPName() no compatible timezone found for 'UTC+01:00'. Returning 'GMT Standard Time'. Please contact the Z-Push dev team.

bob4os

mimeDecode.php:352 hints to a message which has an “multipart/signed” part, but there seems to be an issue with the handling - I have seen this before, but it has not been relevant for me.
imap.php:1449 is a result of the error above.
caldav.php:841 replace the line with:

$message->reminder = $interval->format("%i") + $interval->format("%h") * 60 + $interval->format("%d") * 60 * 24;

(There is a fix in the PR for ZP-1571 but it has not been merged yet.)

“icc not configured” and diffstate.php:230 might be the result of renaming a folder, this is not implemented. I tried implementing this, but I still have some issues with the devices states.

imap.php:1128 there is a check missing, I will try to get a PR through…
I have to look into the timezone error message…

maedball

@bob4os As usual, thanks for your help already. The fix -> fixed the issue ;-).

I think my main issue is the issue related to the multipart /signed (sounds like SMIME to me). I just did a full sync and found several thousand error messages related to this.

maedball

@bob4os Seems like the fix will cause all my birthdays (automatically created by nextcloud based on contact data) to not sync. So maybe it is still not the final fix ;)

bob4os

If you did change line 841 in caldav.php in this block:

elseif (!array_key_exists("VALUE", $parameters) || $parameters["VALUE"] == "DURATION") {
    $val = str_replace("-", "", $property->Value());
    $interval = new DateInterval($val);
    $message->reminder = $interval->format("%i") + $interval->format("%h") * 60 + $interval->format("%a") * 60 * 24;
}

then it has nothing to do with nextcloud birthdays.
These lines are only there to set a reminder (notification before event) x seconds before the event.

Your Nextcloud birthday calendar should be a separate collection (calendar) - it is with mine.
What did you set for CALDAV_PATH and CALDAV_PERSONAL in backend/caldav/config.php?

maedball

@bob4os Ahh nevermind… The nextcloud 22 upgrade killed the birthday calendar. I had to recreate it by enabling and disabling it.
Now i see other strange things, can you check if you have something like this aswell? (seems like you are also sporting nextcloud and z-push.)

Nextcloud

Outlook

bob4os

Should be a wrong timezone.
What timezone is set in your php.ini and what’s the timezone in your Nextcloud settings (personal information)?