JAVA not reaping unused LMTP sessions

stasouv · Post by **stasouv** » Fri Jul 08, 2022 6:51 am

We have upgraded to the latest patch, I wish we hadn't. (Release 8.8.15_GA_3869.RHEL7_64_20190917004220 RHEL7_64 FOSS edition, Patch 8.8.15_P32, AKA the infamous Patch 32)

Having followed the release notes on the install process (previously install 3 specific RPM packages), the server seems to start and function properly. Well, at start...

But then hell breaks loose, as there is an increased number of unused LMTP connections (marked as CLOSE_WAIT), which eventually lead to server not accepting any new incoming LMTP connections.

During this process, JAVA (main process) steadily increases it CPU usage from under 100% (in an 8-core environment) to, eventually, near 800%.

Increasing the number of LMTP threads (say from 20 to 30) does not solve this issue. Typical output when CPU usage grows, by monitoring LMTP processes:

Code: Select all

$ lsof -nPi | grep ':7025'

java      24451  zimbra  911u  IPv4  129653714      0t0  TCP XXX.XXX.XXX.XXX:7025->XXX.XXX.XXX.XXX:54830 (CLOSE_WAIT)
java      24451  zimbra  929u  IPv4  129577963      0t0  TCP XXX.XXX.XXX.XXX:7025->XXX.XXX.XXX.XXX:44840 (CLOSE_WAIT)
java      24451  zimbra  946u  IPv4  129654489      0t0  TCP XXX.XXX.XXX.XXX:7025->XXX.XXX.XXX.XXX:55280 (CLOSE_WAIT)
java      24451  zimbra  960u  IPv4  129718678      0t0  TCP XXX.XXX.XXX.XXX:7025->XXX.XXX.XXX.XXX:33586 (ESTABLISHED)
java      24451  zimbra  969u  IPv4  129571739      0t0  TCP XXX.XXX.XXX.XXX:7025->XXX.XXX.XXX.XXX:43748 (CLOSE_WAIT)
java      24451  zimbra  991u  IPv4  129787452      0t0  TCP XXX.XXX.XXX.XXX:7025->XXX.XXX.XXX.XXX:44148 (ESTABLISHED)
java      24451  zimbra 1019u  IPv4  129635326      0t0  TCP XXX.XXX.XXX.XXX:7025->XXX.XXX.XXX.XXX:53346 (CLOSE_WAIT)
java      24451  zimbra 1098u  IPv4  129787476      0t0  TCP XXX.XXX.XXX.XXX:7025->XXX.XXX.XXX.XXX:44262 (ESTABLISHED)
java      24451  zimbra 1189u  IPv4  129787628      0t0  TCP XXX.XXX.XXX.XXX:7025->XXX.XXX.XXX.XXX:44266 (ESTABLISHED)
java      24451  zimbra 1223u  IPv4  129584562      0t0  TCP XXX.XXX.XXX.XXX:7025->XXX.XXX.XXX.XXX:44944 (CLOSE_WAIT)
java      24451  zimbra 1242u  IPv4  129787136      0t0  TCP XXX.XXX.XXX.XXX:7025->XXX.XXX.XXX.XXX:43914 (ESTABLISHED)
java      24451  zimbra 1279u  IPv4  129776841      0t0  TCP XXX.XXX.XXX.XXX:7025->XXX.XXX.XXX.XXX:42448 (ESTABLISHED)
java      24451  zimbra 1304u  IPv4  129776845      0t0  TCP XXX.XXX.XXX.XXX:7025->XXX.XXX.XXX.XXX:42482 (ESTABLISHED)
java      24451  zimbra 1378u  IPv4  129657366      0t0  TCP XXX.XXX.XXX.XXX:7025->XXX.XXX.XXX.XXX:55248 (CLOSE_WAIT)
java      24451  zimbra 1380u  IPv4  129645623      0t0  TCP XXX.XXX.XXX.XXX:7025->XXX.XXX.XXX.XXX:53488 (CLOSE_WAIT)
java      24451  zimbra 1383u  IPv4  129776920      0t0  TCP XXX.XXX.XXX.XXX:7025->XXX.XXX.XXX.XXX:42610 (ESTABLISHED)
java      24451  zimbra 1424u  IPv4  129776848      0t0  TCP XXX.XXX.XXX.XXX:7025->XXX.XXX.XXX.XXX:42494 (ESTABLISHED)
java      24451  zimbra 1434u  IPv4  129571735      0t0  TCP XXX.XXX.XXX.XXX:7025->XXX.XXX.XXX.XXX:43746 (CLOSE_WAIT)
java      24451  zimbra 1538u  IPv4  129572813      0t0  TCP XXX.XXX.XXX.XXX:7025->XXX.XXX.XXX.XXX:44192 (CLOSE_WAIT)

The only temporary workaround we have found so far is to often reload zmmailboxd

Is there something we can do to help solve this?

Regards,
Stavros

danvaleriu · Post by **danvaleriu** » Sat Jul 09, 2022 9:35 am

The same is happening to us:

Code: Select all

root@mail:~# lsof -nPi | grep ':7025'
java      30883  zimbra  126u  IPv4 3638958      0t0  TCP *:7025 (LISTEN)
java      30883  zimbra  987u  IPv4 3707689      0t0  TCP 81.196.131.130:7025->81.196.131.130:41700 (CLOSE_WAIT)
java      30883  zimbra 1062u  IPv4 3717623      0t0  TCP 81.196.131.130:7025->81.196.131.130:41658 (CLOSE_WAIT)
java      30883  zimbra 1087u  IPv4 3708634      0t0  TCP 81.196.131.130:7025->81.196.131.130:41702 (CLOSE_WAIT)
java      30883  zimbra 1092u  IPv4 3715341      0t0  TCP 81.196.131.130:7025->81.196.131.130:41704 (CLOSE_WAIT)
java      30883  zimbra 1103u  IPv4 3715342      0t0  TCP 81.196.131.130:7025->81.196.131.130:41706 (CLOSE_WAIT)
java      30883  zimbra 1110u  IPv4 3714526      0t0  TCP 81.196.131.130:7025->81.196.131.130:41708 (CLOSE_WAIT)
java      30883  zimbra 1112u  IPv4 3711837      0t0  TCP 81.196.131.130:7025->81.196.131.130:41712 (CLOSE_WAIT)
java      30883  zimbra 1331u  IPv4 3662659      0t0  TCP 81.196.131.130:7025->81.196.131.130:40702 (CLOSE_WAIT)
java      30883  zimbra 1338u  IPv4 3667260      0t0  TCP 81.196.131.130:7025->81.196.131.130:40618 (CLOSE_WAIT)
java      30883  zimbra 1339u  IPv4 3662653      0t0  TCP 81.196.131.130:7025->81.196.131.130:40676 (CLOSE_WAIT)
java      30883  zimbra 1341u  IPv4 3662633      0t0  TCP 81.196.131.130:7025->81.196.131.130:40632 (CLOSE_WAIT)
java      30883  zimbra 1357u  IPv4 3662635      0t0  TCP 81.196.131.130:7025->81.196.131.130:40634 (CLOSE_WAIT)
java      30883  zimbra 1365u  IPv4 3663687      0t0  TCP 81.196.131.130:7025->81.196.131.130:40644 (CLOSE_WAIT)
java      30883  zimbra 1366u  IPv4 3673125      0t0  TCP 81.196.131.130:7025->81.196.131.130:40646 (CLOSE_WAIT)
java      30883  zimbra 1369u  IPv4 3667267      0t0  TCP 81.196.131.130:7025->81.196.131.130:40654 (CLOSE_WAIT)
java      30883  zimbra 1371u  IPv4 3666396      0t0  TCP 81.196.131.130:7025->81.196.131.130:40660 (CLOSE_WAIT)
java      30883  zimbra 1372u  IPv4 3673128      0t0  TCP 81.196.131.130:7025->81.196.131.130:40668 (CLOSE_WAIT)
java      30883  zimbra 1384u  IPv4 3660379      0t0  TCP 81.196.131.130:7025->81.196.131.130:40686 (CLOSE_WAIT)
java      30883  zimbra 1638u  IPv4 3662656      0t0  TCP 81.196.131.130:7025->81.196.131.130:40690 (CLOSE_WAIT)
java      30883  zimbra 1639u  IPv4 3645292      0t0  TCP 81.196.131.130:7025->81.196.131.130:40666 (CLOSE_WAIT)

root@mail:~# uptime
 12:33:39 up 13:39,  1 user,  load average: 21.38, 21.19, 19.79

root@mail:~# ps auxfww|grep jetty
root     27329  0.0  0.0  11280  1064 pts/0    S+   12:34   0:00          \_ grep --color=auto jetty
zimbra   30883 1268  8.3 12249624 2760548 ?    Sl   11:58 450:49  \_ /opt/zimbra/common/bin/java -Dfile.encoding=UTF-8 -server -Dhttps.protocols=TLSv1,TLSv1.1,TLSv1.2 -Djdk.tls.client.protocols=TLSv1,TLSv1.1,TLSv1.2 -Djava.awt.headless=true -Dsun.net.inetaddr.ttl= -Dorg.apache.jasper.compiler.disablejsr199=true -XX:+UseG1GC -XX:SoftRefLRUPolicyMSPerMB=1 -XX:-OmitStackTraceInFastThrow -verbose:gc -Xlog:gc*=debug,safepoint=info:file=/opt/zimbra/log/gc.log:time:filecount=20,filesize=10m -Djava.net.preferIPv4Stack=true -Djava.security.egd=file:/dev/./urandom --add-opens java.base/java.lang=ALL-UNNAMED -Xss256k -Xms1996m -Xmx1996m -Djava.io.tmpdir=/opt/zimbra/mailboxd/work -Djava.library.path=/opt/zimbra/lib -Dzimbra.config=/opt/zimbra/conf/localconfig.xml --module-path /opt/zimbra/mailboxd/common/endorsed -Djetty.base=/opt/zimbra/mailboxd -Djetty.home=/opt/zimbra/common/jetty_home -Djetty.zimlet.base=/opt/zimbra/jetty_base -DSTART=/opt/zimbra/mailboxd/etc/start.config -jar /opt/zimbra/common/jetty_home/start.jar --module=zimbra,server,mail,servlet,servlets,jsp,jstl,jmx,resources,websocket,ext,plus,rewrite,continuation,webapp,setuid jetty.home=/opt/zimbra/common/jetty_home jetty.base=/opt/zimbra/mailboxd jetty.zimlet.base=/opt/zimbra/jetty_base /opt/zimbra/mailboxd/etc/jetty.xml

I tried to strace the process, it seems to be doing ... nothing:

Code: Select all

root@mail:~# strace -p 30883 -v
strace: Process 30883 attached
futex(0x7fca232a49d0, FUTEX_WAIT, 30887, NULL

phoenix · Post by **phoenix** » Sat Jul 09, 2022 4:22 pm

You should always give the full output of the following command when you post:

Code: Select all

zmcontrol -v

stasouv · Post by **stasouv** » Sat Jul 09, 2022 5:33 pm

But I have, inline, in the original post.
No harm from repeating, here it goes:

Code: Select all

$ zmcontrol -v
Release 8.8.15_GA_3869.RHEL7_64_20190917004220 RHEL7_64 FOSS edition, Patch 8.8.15_P32.

This behaviour has existed since upgrading to this version.

Regards,

Stavros

danvaleriu · Post by **danvaleriu** » Sun Jul 10, 2022 8:49 am

zimbra@mail:/root$ zmcontrol -v
Release 8.8.15.GA.3869.UBUNTU16.64 UBUNTU16_64 FOSS edition, Patch 8.8.15_P32.
zimbra@mail:/root$

Same release for us, but on Ubuntu.

linkfan · Post by **linkfan** » Sun Jul 10, 2022 9:39 am

Same here:

Code: Select all

[09:36] root@mail:~ # lsof -nPi | grep ':7025'
java       7243  zimbra  127u  IPv4  7395676      0t0  TCP *:7025 (LISTEN)
java       7243  zimbra  541u  IPv4 15661430      0t0  TCP x.x.x.x:7025->x.x.x.x:37122 (CLOSE_WAIT)
java       7243  zimbra  584u  IPv4 15311101      0t0  TCP x.x.x.x:7025->x.x.x.x:52750 (CLOSE_WAIT)
java       7243  zimbra  585u  IPv4 16282822      0t0  TCP x.x.x.x:7025->x.x.x.x:53678 (CLOSE_WAIT)
java       7243  zimbra  617u  IPv4  9709030      0t0  TCP x.x.x.x:7025->x.x.x.x:42374 (CLOSE_WAIT)
java       7243  zimbra  630u  IPv4 16269189      0t0  TCP x.x.x.x:7025->x.x.x.x:51856 (CLOSE_WAIT)
java       7243  zimbra  631u  IPv4 16274945      0t0  TCP x.x.x.x:7025->x.x.x.x:51858 (CLOSE_WAIT)
java       7243  zimbra  637u  IPv4 10641234      0t0  TCP x.x.x.x:7025->x.x.x.x:44548 (CLOSE_WAIT)
java       7243  zimbra  658u  IPv4  9770720      0t0  TCP x.x.x.x:7025->x.x.x.x:44264 (CLOSE_WAIT)
java       7243  zimbra  785u  IPv4 11501369      0t0  TCP x.x.x.x:7025->x.x.x.x:44646 (CLOSE_WAIT)
java       7243  zimbra  790u  IPv4 13607432      0t0  TCP x.x.x.x:7025->x.x.x.x:54774 (CLOSE_WAIT)
java       7243  zimbra  954u  IPv4 14422544      0t0  TCP x.x.x.x:7025->x.x.x.x:51972 (CLOSE_WAIT)
java       7243  zimbra 1010u  IPv4 14831562      0t0  TCP x.x.x.x:7025->x.x.x.x:38220 (CLOSE_WAIT)
java       7243  zimbra 1012u  IPv4 15348604      0t0  TCP x.x.x.x:7025->x.x.x.x:52754 (CLOSE_WAIT)
java       7243  zimbra 1027u  IPv4 15804120      0t0  TCP x.x.x.x:7025->x.x.x.x:38964 (CLOSE_WAIT)
java       7243  zimbra 1030u  IPv4 15816844      0t0  TCP x.x.x.x:7025->x.x.x.x:38968 (CLOSE_WAIT)
java       7243  zimbra 1032u  IPv4 16760013      0t0  TCP x.x.x.x:7025->x.x.x.x:40350 (CLOSE_WAIT)
java       7243  zimbra 1035u  IPv4 16731290      0t0  TCP x.x.x.x:7025->x.x.x.x:38470 (CLOSE_WAIT)
java       7243  zimbra 1046u  IPv4 16737085      0t0  TCP x.x.x.x:7025->x.x.x.x:38472 (CLOSE_WAIT)
java       7243  zimbra 1047u  IPv4 16737087      0t0  TCP x.x.x.x:7025->x.x.x.x:38474 (CLOSE_WAIT)
java       7243  zimbra 1049u  IPv4 16330330      0t0  TCP x.x.x.x:7025->x.x.x.x:53682 (CLOSE_WAIT)

Code: Select all

[11:34] zimbra@mail:~ $ zmcontrol -v
Release 8.8.15.GA.3829.UBUNTU16.64 UBUNTU16_64 FOSS edition, Patch  8.8.15_P3

Regards,
Linkfan

gabrieles · Post by **gabrieles** » Mon Jul 11, 2022 2:13 pm

We have some customer that escaped the warning and patched, and luckily seems not showing this issue.
We would figure what are the exact circumstances that make this issue emerge, I think that the simple zmcontrol -v is not enough, but even the architecture has a part in it.
Are your deployment single server? Or frontend/backend? Or even multiserver with service dedicated VMs?

Thanks in advance, every detail can contribute

danvaleriu · Post by **danvaleriu** » Mon Jul 11, 2022 3:18 pm

We upgraded three servers for three different clients, one has this issue, two don't. Same version of ubuntu, same version of zimbra. It's weird.

I made a small script that i run every 300 seconds to check if the LMTP sessions are all full and restart if so. It's a hack, but at least we get mails until someone smarter understands what exactly is going on.

Code: Select all


root@mail:~# cat zimbraTest.sh
#!/bin/bash
nr=$(lsof -nPi | grep ':7025'|grep CLOSE_WAIT|wc -l);
echo $nr;

if [ $nr -gt 15 ]; then
	sudo -u zimbra /opt/zimbra/bin/zmmailboxdctl restart;
fi
root@mail:~#

stasouv · Post by **stasouv** » Mon Jul 11, 2022 3:52 pm

We do almost the same thing, but instead issue a soft restart (kill -HUP), it's faster:

Code: Select all

/sbin/lsof -nPi | grep ‘:7025-.*CLOSE_WAIT’ | awk ‘{print $2, NR}’ | tail -1 | while read a b; do 
    if [ $b -gt 18 ]; then 
        kill -HUP $a;
    fi; sleep 20;
done

This is scheduled to evaluate every 12 minutes. This is not a solution, it's a hack, as you've mentioned.

Our system is:

Code: Select all

$ uname -a
Linux host.name.com 3.10.0-1160.36.2.el7.x86_64 #1 SMP Wed Jul 21 11:57:15 UTC 2021 x86_64 x86_64 x86_64 GNU/Linux

$ cat /etc/centos-release
CentOS Linux release 7.9.2009 (Core)

Regards,

Stavros

stasouv · Post by **stasouv** » Mon Jul 11, 2022 3:58 pm

We do almost the same thing, but instead issue a soft restart (kill -HUP), it's faster:

Code: Select all

/sbin/lsof -nPi | grep ‘:7025-.*CLOSE_WAIT’ | awk ‘{print $2, NR}’ | tail -1 | while read a b; do 
    if [ $b -gt 18 ]; then 
        kill -HUP $a;
    fi; sleep 20;
done

This is scheduled to evaluate every 12 minutes. This is not a solution, it's a hack, as you've mentioned.

Our system is:

Code: Select all

$ uname -a
Linux host.name.com 3.10.0-1160.36.2.el7.x86_64 #1 SMP Wed Jul 21 11:57:15 UTC 2021 x86_64 x86_64 x86_64 GNU/Linux

$ cat /etc/centos-release
CentOS Linux release 7.9.2009 (Core)

Regards,

Stavros

Zimbra Forums

JAVA not reaping unused LMTP sessions

JAVA not reaping unused LMTP sessions

Re: JAVA not reaping unused LMTP sessions

Re: JAVA not reaping unused LMTP sessions

Re: JAVA not reaping unused LMTP sessions

Re: JAVA not reaping unused LMTP sessions

Re: JAVA not reaping unused LMTP sessions

Re: JAVA not reaping unused LMTP sessions

Re: JAVA not reaping unused LMTP sessions

Re: JAVA not reaping unused LMTP sessions

Re: JAVA not reaping unused LMTP sessions