Aug 5, 2024: iRedMail-1.7.1 has been released.

**bdushok** · 2019-06-08 22:47:14

bdushok
Member
Offline

Registered: 2019-03-25
Posts: 55

Topic: IMAP connection is broken?

==== REQUIRED BASIC INFO OF YOUR IREDMAIL SERVER ====
- iRedMail version (check /etc/iredmail-release): 0.99
- Deployed with iRedMail Easy or the downloadable installer? downloadable installer
- Linux/BSD distribution name and version: Centos 7.5
- Store mail accounts in which backend (LDAP/MySQL/PGSQL): LDAP
- Web server (Apache or Nginx): Nginx
- Manage mail accounts with iRedAdmin-Pro? 3.6
- [IMPORTANT] Related original log or error message is required if you're experiencing an issue.
====

Within the sogo.log file I'm seeing the following error repeatedly:
Jun 08 10:24:47 sogod [8173]: [ERROR] <0x55a8e72a3c80[SOGoMailAccount]:0> Could not get a valid IMAP connection
Jun 08 10:24:47 sogod [8173]: [WARN] <0x55a8e72a3c80[SOGoMailAccount]:0> IMAP connection is broken, trying to reconnect...

IMAP isn't broken. I currently have 308 IMAP connections in a ESTABLISHED state. SOGo sessions are working perfectly. E-Mail is being read.

I am seeing a little over 5000 IMAP connections in TIME_WAIT state. I'm considering decreasing the fin timeout to decrease the number of TIME_WAIT connections. Most of these connections are local (from SOGo and RoundCube) so a lower timeout shouldn't be a problem.

Any thoughts on why the "broken" messages are appearing in the logs?

Thanks,
Bob

----

Spider Email Archiver: On-Premises, lightweight email archiving software developed by iRedMail team. Supports Amazon S3 compatible storage and custom branding.

**ZhangHuangbin** · 2019-06-10 09:44:12

ZhangHuangbin
iRedMail Developers
Offline

Registered: 2009-05-06
Posts: 31,091

Re: IMAP connection is broken?

Search "_limit" in /var/log/dovecot/*.log, if there's any warning message reports that Dovecot reaches the limit, please simply increase it by by following the warning message.

**bdushok** · 2019-06-10 20:55:16

bdushok
Member
Offline

Registered: 2019-03-25
Posts: 55

Re: IMAP connection is broken?

Zhang,

Thanks for the reply. There is no match for _limit within *.log in /var/log/dovecot. I tried searching for limit as well, that only finds a few messages logged in lda.log. These messages had limit in their subject or sender address.

Bob

ZhangHuangbin wrote:

Search "_limit" in /var/log/dovecot/*.log, if there's any warning message reports that Dovecot reaches the limit, please simply increase it by by following the warning message.

**ZhangHuangbin** · 2019-06-10 23:27:25

ZhangHuangbin
iRedMail Developers
Offline

Registered: 2009-05-06
Posts: 31,091

Re: IMAP connection is broken?

The error log in your first post looks like Dovecot reached client limit.
Without more detailed log or info, i have no clue yet.

Just a suggestion, although it may not work: increase the client limit in Dovecot for IMAP service.

**bdushok** · 2019-06-11 19:44:31

bdushok
Member
Offline

Registered: 2019-03-25
Posts: 55

Re: IMAP connection is broken?

Zhang,

I was using the default setting of 500 for PROCESS_LIMIT within /etc/dovecot/dovecot.conf. I changed this setting to 1000 and rebooted. I'm still encountering the "IMAP connection is broken" in the logs just as frequently as before I made this change.

Is there any additional information I can provide to help troubleshoot this? I don't believe this is a problem. Our Help Desk isn't receiving any calls and SOGo seems very responsive. We have both web users and ActiveSync users. None are complaining of any problems. Is there any chance this error isn't accurate?

Thanks,
Bob

ZhangHuangbin wrote:

The error log in your first post looks like Dovecot reached client limit.
Without more detailed log or info, i have no clue yet.
Just a suggestion, although it may not work: increase the client limit in Dovecot for IMAP service.

**rich_pa** · 2019-06-11 23:52:49

rich_pa
Member
Offline

Registered: 2019-06-11
Posts: 3

Re: IMAP connection is broken?

I am having this issue as well. It appears there is an issue between Sogo and Dovecot and in an hours time, there are over 700 entries. Yesterday, there were over 27k entries in the log. Here are example sogo logs:

Jun 11 06:25:13 sogod [10088]: [WARN] <0x5615f0424db0[SOGoMailAccount]:0> IMAP connection is broken, trying to reconnect...
Jun 11 06:25:13 sogod [10088]: [ERROR] <0x5615f0424db0[SOGoMailAccount]:0> Could not get a valid IMAP connection
Jun 11 06:25:13 sogod [10088]: [WARN] <0x5615f0424db0[SOGoMailAccount]:0> IMAP connection is broken, trying to reconnect...
Jun 11 06:25:13 sogod [10088]: [ERROR] <0x5615f0424db0[SOGoMailAccount]:0> Could not get a valid IMAP connection
Jun 11 06:25:13 sogod [10088]: [WARN] <0x5615f05d6170[SOGoMailFolder]:folderINBOX> IMAP connection is broken, trying to reconnect...
Jun 11 06:25:13 sogod [10088]: [ERROR] <0x5615f05d6170[SOGoMailFolder]:folderINBOX> Could not get a valid IMAP connection
Jun 11 06:25:13 sogod [10088]: [WARN] <0x5615f0424db0[SOGoMailAccount]:0> IMAP connection is broken, trying to reconnect...
Jun 11 06:25:13 sogod [10088]: [ERROR] <0x5615f0424db0[SOGoMailAccount]:0> Could not get a valid IMAP connection
Jun 11 06:25:13 sogod [10088]: [WARN] <0x5615f0424db0[SOGoMailAccount]:0> IMAP connection is broken, trying to reconnect...
Jun 11 06:25:13 sogod [10088]: [ERROR] <0x5615f0424db0[SOGoMailAccount]:0> Could not get a valid IMAP connection
Jun 11 06:25:13 sogod [10088]: [WARN] <0x5615f05d6170[SOGoMailFolder]:folderINBOX> IMAP connection is broken, trying to reconnect...
Jun 11 06:25:13 sogod [10088]: [ERROR] <0x5615f05d6170[SOGoMailFolder]:folderINBOX> Could not get a valid IMAP connection
Jun 11 06:25:13 sogod [10088]: <0x0x5615f05eda80[NGImap4Client]> ERROR(-[NGImap4Client _processUnknownCommandParserException:]): catched non-IMAP4 parsing exception NGSock
etException: NGActiveSocket is not open
Jun 11 06:25:13 sogod [10088]: [WARN] <0x5615f05d6170[SOGoMailFolder]:folderINBOX> IMAP connection is broken, trying to reconnect...
Jun 11 06:25:13 sogod [10088]: [ERROR] <0x5615f05d6170[SOGoMailFolder]:folderINBOX> Could not get a valid IMAP connection
Jun 11 06:25:13 sogod [10088]: <0x0x5615f05eda80[NGImap4Client]> ERROR(-[NGImap4Client _processUnknownCommandParserException:]): catched non-IMAP4 parsing exception NGSock
etException: NGActiveSocket is not open
Jun 11 06:25:13 sogod [10088]: [WARN] <0x5615f06e22c0[SOGoMailAccount]:0> IMAP connection is broken, trying to reconnect...
Jun 11 06:25:13 sogod [10084]: [ERROR] <0x0x5615edbb9400[WOWatchDog]> No child available to handle incoming request!

And respective dovecot logs:

Jun 9 06:25:13 mail dovecot: imap(user@domain.com): Connection closed (select finished 0.045 secs ago) in=31 out=810
Jun 9 06:25:13 mail dovecot: imap-login: Login: user=<user@domain.com>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, mpid=741, secured, session=<0/2eeuGKsst/AAAB>
Jun 9 06:25:13 mail dovecot: imap(user@domain.com): Connection closed (select finished 0.044 secs ago) in=31 out=810
Jun 9 06:25:13 mail dovecot: imap-login: Login: user=<user@domain.com>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, mpid=743, secured, session=<BIKgeuGKtMt/AAAB>
Jun 9 06:25:13 mail dovecot: imap(user@domain.com): Connection closed (select finished 0.044 secs ago) in=31 out=810
Jun 9 06:25:13 mail dovecot: imap-login: Login: user=<user@domain.com>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, mpid=752, secured, session=<IPWheuGKtst/AAAB>
Jun 9 06:25:13 mail dovecot: imap(user@domain.com): Connection closed (select finished 0.044 secs ago) in=31 out=810
Jun 9 06:25:13 mail dovecot: imap-login: Login: user=<user@domain.com>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, mpid=756, secured, session=<dm6jeuGKuMt/AAAB>
Jun 9 06:25:13 mail dovecot: imap(user@domain.com): Connection closed (select finished 0.044 secs ago) in=31 out=810
Jun 9 06:25:13 mail dovecot: imap-login: Login: user=<user@domain.com>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, mpid=758, secured, session=<LuGkeuGKust/AAAB>
Jun 9 06:25:13 mail dovecot: imap(user@domain.com): Connection closed (select finished 0.044 secs ago) in=31 out=810
Jun 9 06:25:13 mail dovecot: imap-login: Login: user=<user@domain.com>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, mpid=760, secured, session=<zF6meuGKvMt/AAAB>
Jun 9 06:25:13 mail dovecot: imap(user@domain.com): Connection closed (status finished 0.000 secs ago) in=63 out=896
Jun 9 06:25:13 mail dovecot: imap-login: Login: user=<user@domain.com>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, mpid=762, secured, session=<LuSneuGKvst/AAAB>
Jun 9 06:25:13 mail dovecot: imap(user@domain.com): Connection closed (select finished 0.044 secs ago) in=31 out=810
Jun 9 06:25:13 mail dovecot: imap-login: Login: user=<user@domain.com>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, mpid=765, secured, session=<RVmpeuGKwMt/AAAB>
Jun 9 06:25:13 mail dovecot: imap(user@domain.com): Connection closed (select finished 0.045 secs ago) in=44 out=919
Jun 9 06:25:13 mail dovecot: imap-login: Login: user=<user@domain.com>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, mpid=767, secured, session=<+9GqeuGKwst/AAAB>
Jun 9 06:25:13 mail dovecot: imap(user@domain.com): Connection closed (select finished 0.044 secs ago) in=32 out=870
Jun 9 06:25:13 mail dovecot: imap-login: Login: user=<user@domain.com>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, mpid=769, secured, session=<UEiseuGKxMt/AAAB>
Jun 9 06:25:14 mail dovecot: imap(user@domain.com): Connection closed (select finished 0.044 secs ago) in=32 out=870

The issue started around the 13th of May and has been growing exponentially every week since. Last week there were 4 million entries in the dovecot log. Currently, there are 45 dovecot processes running. Everything seems to be working though. Any thoughts?

**rich_pa** · 2019-06-11 23:55:24

rich_pa
Member
Offline

Registered: 2019-06-11
Posts: 3

Re: IMAP connection is broken?

Also to add, I've disabled 443 at the firewall (effectively eliminating external user access) and the logs continue to show excessive dovecot logins from localhost.

**bdushok** · 2019-06-12 00:59:05

bdushok
Member
Offline

Registered: 2019-03-25
Posts: 55

Re: IMAP connection is broken?

Rich,

Thanks for the information. I also have IMAP access blocked at the firewall. All of my IMAP connections are also local.

Are you encountering any problems with IMAP access? None of our users are complaining about any difficulty accessing e-mail.

We're primarily using SOGo, although it's possible some of our users may have stumbled onto the RoundCube URL. We don't promote RoundCube.

Bob

rich_pa wrote:

Also to add, I've disabled 443 at the firewall (effectively eliminating external user access) and the logs continue to show excessive dovecot logins from localhost.

**ZhangHuangbin** · 2019-06-12 21:26:00

ZhangHuangbin
iRedMail Developers
Offline

Registered: 2009-05-06
Posts: 31,091

Re: IMAP connection is broken?

I suggest increasing imap client limit again, it should fix this issue.

**chaz** · 2019-06-13 07:58:29

chaz
Member
Offline

Registered: 2019-06-07
Posts: 37

Re: IMAP connection is broken?

rich_pa wrote:

I am having this issue as well. It appears there is an issue between Sogo and Dovecot and in an hours time, there are over 700 entries. Yesterday, there were over 27k entries in the log. Here are example sogo logs:
Jun 11 06:25:13 sogod [10088]: [WARN] <0x5615f0424db0[SOGoMailAccount]:0> IMAP connection is broken, trying to reconnect...
Jun 11 06:25:13 sogod [10088]: [ERROR] <0x5615f0424db0[SOGoMailAccount]:0> Could not get a valid IMAP connection
Jun 11 06:25:13 sogod [10088]: [WARN] <0x5615f0424db0[SOGoMailAccount]:0> IMAP connection is broken, trying to reconnect...
Jun 11 06:25:13 sogod [10088]: [ERROR] <0x5615f0424db0[SOGoMailAccount]:0> Could not get a valid IMAP connection
Jun 11 06:25:13 sogod [10088]: [WARN] <0x5615f05d6170[SOGoMailFolder]:folderINBOX> IMAP connection is broken, trying to reconnect...
Jun 11 06:25:13 sogod [10088]: [ERROR] <0x5615f05d6170[SOGoMailFolder]:folderINBOX> Could not get a valid IMAP connection
Jun 11 06:25:13 sogod [10088]: [WARN] <0x5615f0424db0[SOGoMailAccount]:0> IMAP connection is broken, trying to reconnect...
Jun 11 06:25:13 sogod [10088]: [ERROR] <0x5615f0424db0[SOGoMailAccount]:0> Could not get a valid IMAP connection
Jun 11 06:25:13 sogod [10088]: [WARN] <0x5615f0424db0[SOGoMailAccount]:0> IMAP connection is broken, trying to reconnect...
Jun 11 06:25:13 sogod [10088]: [ERROR] <0x5615f0424db0[SOGoMailAccount]:0> Could not get a valid IMAP connection
Jun 11 06:25:13 sogod [10088]: [WARN] <0x5615f05d6170[SOGoMailFolder]:folderINBOX> IMAP connection is broken, trying to reconnect...
Jun 11 06:25:13 sogod [10088]: [ERROR] <0x5615f05d6170[SOGoMailFolder]:folderINBOX> Could not get a valid IMAP connection
Jun 11 06:25:13 sogod [10088]: <0x0x5615f05eda80[NGImap4Client]> ERROR(-[NGImap4Client _processUnknownCommandParserException:]): catched non-IMAP4 parsing exception NGSock
etException: NGActiveSocket is not open
Jun 11 06:25:13 sogod [10088]: [WARN] <0x5615f05d6170[SOGoMailFolder]:folderINBOX> IMAP connection is broken, trying to reconnect...
Jun 11 06:25:13 sogod [10088]: [ERROR] <0x5615f05d6170[SOGoMailFolder]:folderINBOX> Could not get a valid IMAP connection
Jun 11 06:25:13 sogod [10088]: <0x0x5615f05eda80[NGImap4Client]> ERROR(-[NGImap4Client _processUnknownCommandParserException:]): catched non-IMAP4 parsing exception NGSock
etException: NGActiveSocket is not open
Jun 11 06:25:13 sogod [10088]: [WARN] <0x5615f06e22c0[SOGoMailAccount]:0> IMAP connection is broken, trying to reconnect...
Jun 11 06:25:13 sogod [10084]: [ERROR] <0x0x5615edbb9400[WOWatchDog]> No child available to handle incoming request!

And respective dovecot logs:
Jun 9 06:25:13 mail dovecot: imap(user@domain.com): Connection closed (select finished 0.045 secs ago) in=31 out=810
Jun 9 06:25:13 mail dovecot: imap-login: Login: user=<user@domain.com>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, mpid=741, secured, session=<0/2eeuGKsst/AAAB>
Jun 9 06:25:13 mail dovecot: imap(user@domain.com): Connection closed (select finished 0.044 secs ago) in=31 out=810
Jun 9 06:25:13 mail dovecot: imap-login: Login: user=<user@domain.com>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, mpid=743, secured, session=<BIKgeuGKtMt/AAAB>
Jun 9 06:25:13 mail dovecot: imap(user@domain.com): Connection closed (select finished 0.044 secs ago) in=31 out=810
Jun 9 06:25:13 mail dovecot: imap-login: Login: user=<user@domain.com>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, mpid=752, secured, session=<IPWheuGKtst/AAAB>
Jun 9 06:25:13 mail dovecot: imap(user@domain.com): Connection closed (select finished 0.044 secs ago) in=31 out=810
Jun 9 06:25:13 mail dovecot: imap-login: Login: user=<user@domain.com>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, mpid=756, secured, session=<dm6jeuGKuMt/AAAB>
Jun 9 06:25:13 mail dovecot: imap(user@domain.com): Connection closed (select finished 0.044 secs ago) in=31 out=810
Jun 9 06:25:13 mail dovecot: imap-login: Login: user=<user@domain.com>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, mpid=758, secured, session=<LuGkeuGKust/AAAB>
Jun 9 06:25:13 mail dovecot: imap(user@domain.com): Connection closed (select finished 0.044 secs ago) in=31 out=810
Jun 9 06:25:13 mail dovecot: imap-login: Login: user=<user@domain.com>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, mpid=760, secured, session=<zF6meuGKvMt/AAAB>
Jun 9 06:25:13 mail dovecot: imap(user@domain.com): Connection closed (status finished 0.000 secs ago) in=63 out=896
Jun 9 06:25:13 mail dovecot: imap-login: Login: user=<user@domain.com>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, mpid=762, secured, session=<LuSneuGKvst/AAAB>
Jun 9 06:25:13 mail dovecot: imap(user@domain.com): Connection closed (select finished 0.044 secs ago) in=31 out=810
Jun 9 06:25:13 mail dovecot: imap-login: Login: user=<user@domain.com>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, mpid=765, secured, session=<RVmpeuGKwMt/AAAB>
Jun 9 06:25:13 mail dovecot: imap(user@domain.com): Connection closed (select finished 0.045 secs ago) in=44 out=919
Jun 9 06:25:13 mail dovecot: imap-login: Login: user=<user@domain.com>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, mpid=767, secured, session=<+9GqeuGKwst/AAAB>
Jun 9 06:25:13 mail dovecot: imap(user@domain.com): Connection closed (select finished 0.044 secs ago) in=32 out=870
Jun 9 06:25:13 mail dovecot: imap-login: Login: user=<user@domain.com>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, mpid=769, secured, session=<UEiseuGKxMt/AAAB>
Jun 9 06:25:14 mail dovecot: imap(user@domain.com): Connection closed (select finished 0.044 secs ago) in=32 out=870
The issue started around the 13th of May and has been growing exponentially every week since. Last week there were 4 million entries in the dovecot log. Currently, there are 45 dovecot processes running. Everything seems to be working though. Any thoughts?

I am seeing a similar problem on my brand new install of iRedmail v0.9.9. This looks like a Sogo bug. See https://sogo.nu/bugs/view.php?id=4757.

**ZhangHuangbin** · 2019-06-13 12:00:56

ZhangHuangbin
iRedMail Developers
Offline

Registered: 2009-05-06
Posts: 31,091

Re: IMAP connection is broken?

rich_pa wrote:

Jun 11 06:25:13 sogod [10084]: [ERROR] <0x0x5615edbb9400[WOWatchDog]> No child available to handle incoming request!

Please increase prefork SOGo child processes in /etc/sysconfig/sogo (CentOS) or /etc/default/sogo (Debian/Ubuntu), it will fix this issue.

**rich_pa** · 2019-06-14 03:22:50

rich_pa
Member
Offline

Registered: 2019-06-11
Posts: 3

Re: IMAP connection is broken?

ZhangHuangbin wrote:

rich_pa wrote:
Jun 11 06:25:13 sogod [10084]: [ERROR] <0x0x5615edbb9400[WOWatchDog]> No child available to handle incoming request!
Please increase prefork SOGo child processes in /etc/sysconfig/sogo (CentOS) or /etc/default/sogo (Debian/Ubuntu), it will fix this issue.

Zhang, this fixed the problem. Thank you for your help.

Aug 5, 2024: iRedMail-1.7.1 has been released.

[ Closed ] IMAP connection is broken?

Posts: 12

1 Topic by bdushok 2019-06-08 22:47:14

Topic: IMAP connection is broken?

2 Reply by ZhangHuangbin 2019-06-10 09:44:12

Re: IMAP connection is broken?

3 Reply by bdushok 2019-06-10 20:55:16

Re: IMAP connection is broken?

4 Reply by ZhangHuangbin 2019-06-10 23:27:25

Re: IMAP connection is broken?

5 Reply by bdushok 2019-06-11 19:44:31

Re: IMAP connection is broken?

6 Reply by rich_pa 2019-06-11 23:52:49

Re: IMAP connection is broken?

7 Reply by rich_pa 2019-06-11 23:55:24

Re: IMAP connection is broken?

8 Reply by bdushok 2019-06-12 00:59:05

Re: IMAP connection is broken?

9 Reply by ZhangHuangbin 2019-06-12 21:26:00

Re: IMAP connection is broken?

10 Reply by chaz 2019-06-13 07:58:29

Re: IMAP connection is broken?

11 Reply by ZhangHuangbin 2019-06-13 12:00:56

Re: IMAP connection is broken?

12 Reply by rich_pa 2019-06-14 03:22:50

Re: IMAP connection is broken?

Posts: 12