Internal Mails Stop Working After a While

[mintra]

after kill -QUIT PID

Goes for ever with "http-80-ProcessorXXX" from 100 on down to this...

"http-80-Processor13" daemon prio=1 tid=0x08692648 nid=0xba2 in Object.wait() [0x9eab3000..0x9eab4130]
        at java.lang.Object.wait(Native Method)
        - waiting on <0xa5513f68> (a org.apache.tomcat.util.threads.ThreadPool$ControlRunnable)
        at java.lang.Object.wait(Object.java:474)
        at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:656)
        - locked <0xa5513f68> (a org.apache.tomcat.util.threads.ThreadPool$ControlRunnable)
        at java.lang.Thread.run(Thread.java:595)

"http-80-Processor12" daemon prio=1 tid=0x08172bb8 nid=0xba1 in Object.wait() [0x9f241000..0x9f2420b0]
        at java.lang.Object.wait(Native Method)
        - waiting on <0xa5514000> (a org.apache.tomcat.util.threads.ThreadPool$ControlRunnable)
        at java.lang.Object.wait(Object.java:474)
        at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:656)
        - locked <0xa5514000> (a org.apache.tomcat.util.threads.ThreadPool$ControlRunnable)
        at java.lang.Thread.run(Thread.java:595)

"http-80-Processor11" daemon prio=1 tid=0x08171cc8 nid=0xba0 in Object.wait() [0x9f2c2000..0x9f2c3030]
        at java.lang.Object.wait(Native Method)
        - waiting on <0xa5514098> (a org.apache.tomcat.util.threads.ThreadPool$ControlRunnable)
        at java.lang.Object.wait(Object.java:474)
        at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:656)
        - locked <0xa5514098> (a org.apache.tomcat.util.threads.ThreadPool$ControlRunnable)
        at java.lang.Thread.run(Thread.java:595)

"http-80-Processor10" daemon prio=1 tid=0x08170e38 nid=0xb9f in Object.wait() [0x9f343000..0x9f343fb0]
        at java.lang.Object.wait(Native Method)
        - waiting on <0xa5514130> (a org.apache.tomcat.util.threads.ThreadPool$ControlRunnable)
        at java.lang.Object.wait(Object.java:474)
        at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:656)
        - locked <0xa5514130> (a org.apache.tomcat.util.threads.ThreadPool$ControlRunnable)
        at java.lang.Thread.run(Thread.java:595)

"http-80-Processor9" daemon prio=1 tid=0x0823e040 nid=0xb9e in Object.wait() [0x9f3c4000..0x9f3c4f30]
        at java.lang.Object.wait(Native Method)
        - waiting on <0xa55141c8> (a org.apache.tomcat.util.threads.ThreadPool$ControlRunnable)
        at java.lang.Object.wait(Object.java:474)
        at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:656)
        - locked <0xa55141c8> (a org.apache.tomcat.util.threads.ThreadPool$ControlRunnable)
        at java.lang.Thread.run(Thread.java:595)

"http-80-Processor8" daemon prio=1 tid=0x0823d1f8 nid=0xb9d in Object.wait() [0x9f445000..0x9f445eb0]
        at java.lang.Object.wait(Native Method)
        - waiting on <0xa5514260> (a org.apache.tomcat.util.threads.ThreadPool$ControlRunnable)
        at java.lang.Object.wait(Object.java:474)
        at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:656)
        - locked <0xa5514260> (a org.apache.tomcat.util.threads.ThreadPool$ControlRunnable)
        at java.lang.Thread.run(Thread.java:595)


"http-80-Processor7" daemon prio=1 tid=0x0823c3b0 nid=0xb9c in Object.wait() [0x9f4c6000..0x9f4c6e30]
        at java.lang.Object.wait(Native Method)
        - waiting on <0xa55142f8> (a org.apache.tomcat.util.threads.ThreadPool$ControlRunnable)
        at java.lang.Object.wait(Object.java:474)
        at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:656)
        - locked <0xa55142f8> (a org.apache.tomcat.util.threads.ThreadPool$ControlRunnable)
        at java.lang.Thread.run(Thread.java:595)

"http-80-Processor6" daemon prio=1 tid=0x08182928 nid=0xb9b in Object.wait() [0x9f548000..0x9f5481b0]
        at java.lang.Object.wait(Native Method)
        - waiting on <0xa5514390> (a org.apache.tomcat.util.threads.ThreadPool$ControlRunnable)
        at java.lang.Object.wait(Object.java:474)
        at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:656)
        - locked <0xa5514390> (a org.apache.tomcat.util.threads.ThreadPool$ControlRunnable)
        at java.lang.Thread.run(Thread.java:595)

"http-80-Processor5" daemon prio=1 tid=0x08181c80 nid=0xb9a in Object.wait() [0x9f5c8000..0x9f5c9130]
        at java.lang.Object.wait(Native Method)
        - waiting on <0xa5514428> (a org.apache.tomcat.util.threads.ThreadPool$ControlRunnable)
        at java.lang.Object.wait(Object.java:474)
        at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:656)
        - locked <0xa5514428> (a org.apache.tomcat.util.threads.ThreadPool$ControlRunnable)
        at java.lang.Thread.run(Thread.java:595)

"http-80-Processor4" daemon prio=1 tid=0x086c3030 nid=0xb99 in Object.wait() [0x9f649000..0x9f64a0b0]
        at java.lang.Object.wait(Native Method)
        - waiting on <0xa55144c0> (a org.apache.tomcat.util.threads.ThreadPool$ControlRunnable)
        at java.lang.Object.wait(Object.java:474)
        at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:656)
        - locked <0xa55144c0> (a org.apache.tomcat.util.threads.ThreadPool$ControlRunnable)
        at java.lang.Thread.run(Thread.java:595)

"http-80-Processor3" daemon prio=1 tid=0x085c2c58 nid=0xb98 in Object.wait() [0x9f6ca000..0x9f6cb030]
        at java.lang.Object.wait(Native Method)
        - waiting on <0xa5514558> (a org.apache.tomcat.util.threads.ThreadPool$ControlRunnable)
        at java.lang.Object.wait(Object.java:474)
        at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:656)
        - locked <0xa5514558> (a org.apache.tomcat.util.threads.ThreadPool$ControlRunnable)
        at java.lang.Thread.run(Thread.java:595)

"http-80-Processor2" daemon prio=1 tid=0x085c1fb0 nid=0xb97 in Object.wait() [0x9f74b000..0x9f74bfb0]
        at java.lang.Object.wait(Native Method)
        - waiting on <0xa55145f0> (a org.apache.tomcat.util.threads.ThreadPool$ControlRunnable)
        at java.lang.Object.wait(Object.java:474)
        at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:656)
        - locked <0xa55145f0> (a org.apache.tomcat.util.threads.ThreadPool$ControlRunnable)
        at java.lang.Thread.run(Thread.java:595)

"http-80-Processor1" daemon prio=1 tid=0x082eaaf0 nid=0xb96 in Object.wait() [0x9f7cc000..0x9f7ccf30]
        at java.lang.Object.wait(Native Method)
        - waiting on <0xa5514688> (a org.apache.tomcat.util.threads.ThreadPool$ControlRunnable)
        at java.lang.Object.wait(Object.java:474)
        at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:656)
        - locked <0xa5514688> (a org.apache.tomcat.util.threads.ThreadPool$ControlRunnable)
        at java.lang.Thread.run(Thread.java:595)

"Thread-11" daemon prio=1 tid=0x085b4e40 nid=0xb90 waiting on condition [0x9eb34000..0x9eb34e30]
        at java.lang.Thread.sleep(Native Method)
        at org.apache.log4j.helpers.FileWatchdog.run(FileWatchdog.java:95)

"FileLogWriter.FsyncThread" prio=1 tid=0x0864be10 nid=0xb8c sleeping[0x9ed38000..0x9ed39030]
        at java.lang.Thread.sleep(Native Method)
        at com.zimbra.cs.redolog.logger.FileLogWriter$FsyncThread.run(FileLogWriter.java:471)

"IndexWritersSweeper" prio=1 tid=0x0822e918 nid=0xb8a in Object.wait() [0x9edb9000..0x9edb9f30]
        at java.lang.Object.wait(Native Method)
        - waiting on <0xa5514ad8> (a com.zimbra.cs.index.MailboxIndex$IndexWritersSweeperThread)
        at com.zimbra.cs.index.MailboxIndex$IndexWritersSweeperThread.run(MailboxIndex.java:454)
        - locked <0xa5514ad8> (a com.zimbra.cs.index.MailboxIndex$IndexWritersSweeperThread)

"Thread-7" daemon prio=1 tid=0x08214a38 nid=0xb5b waiting on condition [0x9ee3c000..0x9ee3ceb0]
        at java.lang.Thread.sleep(Native Method)
        at org.apache.log4j.helpers.FileWatchdog.run(FileWatchdog.java:95)

"Timer-0" daemon prio=1 tid=0x082f01e8 nid=0xb5a in Object.wait() [0x9eebd000..0x9eebde30]
        at java.lang.Object.wait(Native Method)
        - waiting on <0xa5464980> (a java.util.TaskQueue)
        at java.util.TimerThread.mainLoop(Timer.java:509)
        - locked <0xa5464980> (a java.util.TaskQueue)
        at java.util.TimerThread.run(Timer.java:462)

"Thread-2" daemon prio=1 tid=0x082f0fc0 nid=0xb55 runnable [0x9f0cb000..0x9f0cc030]
        at java.net.SocketInputStream.socketRead0(Native Method)
        at java.net.SocketInputStream.read(SocketInputStream.java:129)
        at java.io.BufferedInputStream.fill(BufferedInputStream.java:218)
        at java.io.BufferedInputStream.read1(BufferedInputStream.java:256)
        at java.io.BufferedInputStream.read(BufferedInputStream.java:313)
        - locked <0xa53f7cf8> (a java.io.BufferedInputStream)
        at com.sun.jndi.ldap.Connection.run(Connection.java:784)
        at java.lang.Thread.run(Thread.java:595)

"Thread-1" daemon prio=1 tid=0x08187b78 nid=0xb51 in Object.wait() [0x9f14c000..0x9f14cfb0]
        at java.lang.Object.wait(Native Method)
        - waiting on <0xa53f56e8> (a com.sun.jndi.ldap.pool.PoolCleaner)
        at com.sun.jndi.ldap.pool.PoolCleaner.run(PoolCleaner.java:36)
        - locked <0xa53f56e8> (a com.sun.jndi.ldap.pool.PoolCleaner)

"Low Memory Detector" daemon prio=1 tid=0x080c65e0 nid=0xa79 runnable [0x00000000..0x00000000]

"CompilerThread0" daemon prio=1 tid=0x080c5090 nid=0xa76 waiting on condition [0x00000000..0x9ff79818]

"Signal Dispatcher" daemon prio=1 tid=0x080c4220 nid=0xa75 waiting on condition [0x00000000..0x9fffb1a0]

"Finalizer" daemon prio=1 tid=0x080b94c0 nid=0xa48 in Object.wait() [0xa027c000..0xa027c130]
        at java.lang.Object.wait(Native Method)
        - waiting on <0xa5080768> (a java.lang.ref.ReferenceQueue$Lock)
        at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:116)
        - locked <0xa5080768> (a java.lang.ref.ReferenceQueue$Lock)
        at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:132)
        at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:159)

"Reference Handler" daemon prio=1 tid=0x080b8820 nid=0xa47 in Object.wait() [0xa02fc000..0xa02fd0b0]
        at java.lang.Object.wait(Native Method)
        - waiting on <0xa5080690> (a java.lang.ref.Reference$Lock)
        at java.lang.Object.wait(Object.java:474)
        at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:116)
        - locked <0xa5080690> (a java.lang.ref.Reference$Lock)

"main" prio=1 tid=0x0805be90 nid=0xa2b runnable [0xbfffd000..0xbfffd7b8]
        at java.net.PlainSocketImpl.socketAccept(Native Method)
        at java.net.PlainSocketImpl.accept(PlainSocketImpl.java:384)
        - locked <0xa5514b78> (a java.net.SocksSocketImpl)
        at java.net.ServerSocket.implAccept(ServerSocket.java:450)
        at java.net.ServerSocket.accept(ServerSocket.java:421)
        at org.apache.catalina.core.StandardServer.await(StandardServer.java:362)
        at org.apache.catalina.startup.Catalina.await(Catalina.java:600)
        at org.apache.catalina.startup.Catalina.start(Catalina.java:560)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:585)
        at org.apache.catalina.startup.Bootstrap.start(Bootstrap.java:271)
        at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:409)

"VM Thread" prio=1 tid=0x080b5c00 nid=0xa46 runnable

"VM Periodic Task Thread" prio=1 tid=0x080c7a70 nid=0xa7a waiting on condition

[dkarp]

Can you please attach the whole stack dump to your post? (Just in case the issue is in the part you elided...) You can attach a file when you post by going to "Additional Options > Manage Attachments".

Also, are you running POP or IMAP?

[mintra]

This server has mixed usage, 50/50 pop and IMAP

before I post the whole stack dump, want to ask, Is this error normal? (conversation with host.domain.com[int_ip] timed out while sending end of data -- message may be sent more than once)

If you read back into this thread, the error message was different, it was
status=deferred (connect to domain.com[123.123publicip]: read timeout)

but after I setup bind (DNS) onto the server 90% I only get the other error message about sent more then once.

I tried to search the forum for "message may be sent more than once" but didn't find anything.

What does this mean? Because I notice it when there are several local recpients from the same sender.

Which makes sense if it thinks it's sent more then once, but is this message delivered or is it stuck in the queue.

[KevinH]

Neither error is normal. The connection timeout seems like a client is disconnecting. Have you tried to flush the queues (postqueue -f)?

If you do get it in that condition and get the stack trace post the entire thing as a zipped attachment. This will let you get the whole thing and also easier for us to read.

[mintra]

When this happens, a postqueue -f doesn't seem to flush the messages out.

After a reboot or zmcontrol stop then start, postqueue -f does deliver mail

Unfortunantly, we've experienced this on a second server now.

The original server which is where this whole thread started from
is a Cent OS 4 behind a firewall, running bind. The server has 750mb ram, with ~200-300 mb free and a dozen users, 50% pop3 50% imap. Anti-virus / Spam are turned off.

the second server is also Cent OS 4, it is NOT behind a firewall and is not running bind. This server has 750mb of ram, with ~50mb free, and around 6 users all on IMAP. AV/Spam filtering in use.

I'm working on getting some stackdumps for you. Thanks.

[KevinH]

Yep stack dumps and a the last few 1000 lines of /var/log/zimbra.log and /opt/zimbra/tomcat/log/catalina.out may help us figure this out.

[mintra]

Kevin, is there any chance I can email you the Zimbra log file and Catalina Out File. I'm weary about posting loads of email addresses to a public forum.

And they are 500k in total as well.

[KevinH]

Kevin, is there any chance I can email you the Zimbra log file and Catalina Out File. I'm weary about posting loads of email addresses to a public forum.

And they are 500k in total as well.

I'll PM an address to mail it to. You've zipped the files first right?

[mintra]

Logs are Zipped and Sent,

Thanks.

[KevinH]

Got them thanks. At first looks it seems to be a deadlock in the IMAP code that a few others have hit. We are working on a new IMAP impl that will avoid this problem. In most cases it's been from mobile or bad behaving conections where the IMAP client loses it's conection to the server.