Problems with dovecot. Mail client suddenly disconnect

Discussion in 'ISPConfig 3 Priority Support' started by tr909192, Jul 19, 2023.

  1. tr909192

    tr909192 Member HowtoForge Supporter

    Hi,

    we have migrated an old installation of ispconfig (pretty old, based on debian 9) to the latest version on a debian 11 lts stable (dovecot+rspamd, installed with the autoinstaller). So everything is pretty much standard. This migration involve a mail domain with around 60 mailboxes.
    Everything has worked well, but on the new server, for reasons that are not clear at this times, suddendly some mail clients (eg. some old outlook) tend to disconnect to the server. And they does not reconnect until the client will be restarted.
    Checking on my logs, the only strange messages that i got, on one of the users that he has that problems, are these:

    Code:
    Jul 19 11:37:22 mx dovecot: imap(XXXXXX)<3343316><LmPbw9MAEwUCIQLS>: Connection closed (NOOP finished 0.010 secs ago) in=111 out=1059 deleted=0 expunged=0 trashed=0 hdr_count=0 hdr_bytes=0 body_count=0 body_bytes=0
    Jul 19 14:10:40 mx dovecot: imap(XXXXXX)<3357750><SPZ469UAOsICIQLS>: Connection closed (UID STORE finished 0.256 secs ago) in=445 out=16508 deleted=0 expunged=0 trashed=0 hdr_count=2 hdr_bytes=8321 body_count=1 body_bytes=6041
    Jul 19 14:12:03 mx dovecot: imap(XXXXXX)<3345908><JWChGdQAIy4CIQLS>: Connection closed (UID STORE finished 0.243 secs ago) in=13747 out=9581501 deleted=20 expunged=20 trashed=0 hdr_count=8 hdr_bytes=34029 body_count=6 body_bytes=535846
    Jul 19 14:44:22 mx dovecot: imap(XXXXXX)<3360432><r+jwYNYAn3cCIQLS>: Connection closed (UID STORE finished 0.249 secs ago) in=7875 out=6950949 deleted=0 expunged=0 trashed=0 hdr_count=1 hdr_bytes=615 body_count=1 body_bytes=87362
    In my opinion chance are that some idle timeout should be raised.
    But starting from that logs, i'm not able to understand specifically what.
    In order to avoid to proceede empirically, someone known what idle timeout i can try to riseup?
    At this times all the value of dovecot, are the standard one that are set with the autoinstaller for a debian 11 s.o.

    Thank you.
     
  2. tr909192

    tr909192 Member HowtoForge Supporter

    Checking the logs more in details, we have got some others connection close related to lmtp and quota-status

    Code:
    Jul 19 16:45:39 mx dovecot: lmtp(3371631): Debug: auth-master: conn unix:/run/dovecot/auth-userdb (pid=3366476,uid=0): Disconnected: Connection closed (fd=15)
    Jul 19 16:47:33 mx dovecot: lmtp(3372035): Debug: auth-master: conn unix:/run/dovecot/auth-userdb (pid=3366476,uid=0): Disconnected: Connection closed (fd=15)
    Jul 19 16:49:43 mx dovecot: lmtp(3372145): Debug: auth-master: conn unix:/run/dovecot/auth-userdb (pid=3366476,uid=0): Disconnected: Connection closed (fd=15)
    Jul 19 16:50:49 mx dovecot: lmtp(3372199): Debug: auth-master: conn unix:/run/dovecot/auth-userdb (pid=3366476,uid=0): Disconnected: Connection closed (fd=15)
    Jul 19 16:57:04 mx dovecot: lmtp(3372506): Debug: auth-master: conn unix:/run/dovecot/auth-userdb (pid=3366476,uid=0): Disconnected: Connection closed (fd=15)
    Jul 19 17:03:31 mx dovecot: lmtp(3372463): Debug: auth-master: conn unix:/run/dovecot/auth-userdb (pid=3366476,uid=0): Disconnected: Connection closed (fd=15)
    Code:
    Jul 19 16:49:40 mx dovecot: quota-status(XXXXXXXXXX)<3371738><sJjFFMj3t2TacXXXXXX>: Debug: auth-master: conn unix:/run/dovecot/auth-userdb (pid=3366476,uid=0): Disconnected: Connection closed (fd=14)
    Jul 19 16:56:32 mx dovecot: quota-status(XXXXXXX)<3372458><yP9GAGT5t2XXXXXXX>: Debug: auth-master: conn unix:/run/dovecot/auth-userdb (pid=3366476,uid=0): Disconnected: Connection closed (fd=14)
    In order to improve lmtp and quota-status performance i have rised up the value process_min_avail for both services to 5 (before it was the standard 0). This make sense for you also?

    ty
     
  3. till

    till Super Moderator Staff Member ISPConfig Developer

    I have not seen this issue on any system yet, so it's quite uncommon that this happens.
     
  4. pyte

    pyte Well-Known Member HowtoForge Supporter

    What does Outlook report when you use the "Test Account Settings" after it disconnects? Does the reconnect work fine then or are there any errors that may indicate what the problem is?
     
  5. tr909192

    tr909192 Member HowtoForge Supporter

    outlook does not report any kind of error on test account settings, after the disconnect. But outlook does not reconnect until we restart the client.
    This appear to happens on outlook 2019 on windows 7 s.o.
    also with mail_debug = yes on my dovecot the only "strange" things that is logged when this happens is that line:

    Code:
    Jul 20 09:26:59 mx dovecot: lmtp(3575644): Disconnect from local: Client has quit the connection (state=READY)
    Jul 20 09:28:00 mx dovecot: lmtp(3575644): Debug: auth-master: conn unix:/run/dovecot/auth-userdb (pid=3375018,uid=0): Disconnected: Connection closed (fd=15)
    the modify above "process_min_avail" to 5 on lmtp and quota-stats not changed anything :-(
     
  6. pyte

    pyte Well-Known Member HowtoForge Supporter

    I dont see anything strange with these loglines. The client disconnects, which is not unusualy after it's "done".
    Does it happen with other clients like thunderbird too?

    What exactly is happening that is an issue to you? Does it not load new mails from the server? Is it not able to send mail? We need a more detailed description of what the issue is and how it unfolds
     
  7. tr909192

    tr909192 Member HowtoForge Supporter

    basically the outlook disconnect from the server, and is not be able to reconnect to the server until the outlook is closed and reopened.
    this happens something like 1 time per hour. and it's look that happens only on microsoft outlook 2019 on windows 7.
    others more modern client (like thunderbird latest on windows 11) does not have any problems.

    my other guess is that outlook 2019 can't keep alive the imap connection, and i'm thinking to reduce imapc_max_idle_time from 29 minutes (the default) to something like 15 minutes...

    this kind of issue, so sporadic, are hella hard to debug
     
  8. pyte

    pyte Well-Known Member HowtoForge Supporter

    That sounds awful in itself to be honest. Don't use a outdated and unsupported OS.

    According to spec a IDLE must be reissued at least every 29 minutes, if not the server is allowed to close the connection. You can try to reduce this depending on the type of network and see if it helps. But to avoid all the debugging hassle might consider not supporting and updating a deprecated OS
     
  9. tr909192

    tr909192 Member HowtoForge Supporter

    i'm totally with you. but i'm the provider, not the customer :-D
    btw probably it was an ssl related issues. we are checking in that way.

    obviously i have already advise the customer to upgrade hardware and software. that from the beginning...
     
  10. till

    till Super Moderator Staff Member ISPConfig Developer

    Yes, this might indeed be the case. Current SSL requirements on server side with old client OS can cause all kinds of strange side effects.
     
    30uke and tr909192 like this.

Share This Page