One of my mailboxes has completely stalled!

[adoroar]

Hi

I'm testing out Zimbra, and as part of the testing I figured I'd sign one of the mailboxes up for the Linux kernel mailing list to give it some traffic.
Now after only a few email that mailbox has completely stalled, I can access the web interface just fine and browse emails, but I can't receive or even send any email.
It's kinda weird since any other mailbox seems to work just fine.
Anyone have any suggestions for debugging this? I really wanna know whats causing it, rather than just reinstalling


here are some logs!:

postqueue -p (Has 443 email like this)
957032D577 8029 Wed Dec 6 16:14:30 linux-kernel-owner@vger.kernel.org(host zimbra.mydomain.net[X.X.X.X] said: 451 4.0.0 Temporary message delivery failure try again (in reply to end of DATA command)) lkml@mydomain.net


/var/log/zimbra.log
When sending to lkml@mydomain.net

Dec 6 17:11:24 zimbra postfix/smtpd[987]: connect from wx-out-0506.google.com[66.249.82.231]
Dec 6 17:11:24 zimbra postfix/smtpd[987]: E40952D638: client=wx-out-0506.google.com[66.249.82.231]
Dec 6 17:11:25 zimbra postfix/cleanup[814]: E40952D638: message-id=<946c674b0612060812uf8bc98bgbb3097efaea208aa@ma il.gmail.com>
Dec 6 17:11:25 zimbra postfix/qmgr[26559]: E40952D638: from=<myuser@gmail.com>, size=1552, nrcpt=1 (queue active)
Dec 6 17:11:25 zimbra amavis[29944]: (29944-02) ESMTP::10024 /opt/zimbra/amavisd/tmp/amavis-20061206T165901-29944: <myuser@gmail.com> -> <lkml@mydomain.net> SIZE=1552 Received: from zimbra.mydomain.net ([127.0.0.1]) by localhost (zimbra.mydomain.net [127.0.0.1]) (amavisd-new, port 10024) with ESMTP for <lkml@mydomain.net>; Wed, 6 Dec 2006 17:11:25 +0100 (CET)
Dec 6 17:11:25 zimbra amavis[29944]: (29944-02) Checking: KwGQ-qelC7Ic [66.249.82.231] <myuser@gmail.com> -> <lkml@mydomain.net>
Dec 6 17:11:27 zimbra postfix/smtpd[819]: connect from localhost.localdomain[127.0.0.1]
Dec 6 17:11:27 zimbra postfix/smtpd[819]: 774ED2D639: client=localhost.localdomain[127.0.0.1]
Dec 6 17:11:27 zimbra postfix/cleanup[814]: 774ED2D639: message-id=<946c674b0612060812uf8bc98bgbb3097efaea208aa@ma il.gmail.com>
Dec 6 17:11:27 zimbra postfix/qmgr[26559]: 774ED2D639: from=<myuser@gmail.com>, size=2360, nrcpt=1 (queue active)
Dec 6 17:11:27 zimbra postfix/smtpd[819]: disconnect from localhost.localdomain[127.0.0.1]
Dec 6 17:11:27 zimbra amavis[29944]: (29944-02) FWD via SMTP: <myuser@gmail.com> -> <lkml@mydomain.net>, 250 2.6.0 Ok, id=29944-02, from MTA([127.0.0.1]:10025): 250 Ok: queued as 774ED2D639
Dec 6 17:11:27 zimbra amavis[29944]: (29944-02) Passed CLEAN, [66.249.82.231] [66.249.82.231] <myuser@gmail.com> -> <lkml@mydomain.net>, Message-ID: <946c674b0612060812uf8bc98bgbb3097efaea208aa@mail. gmail.com>, mail_id: KwGQ-qelC7Ic, Hits: 0.663, queued_as: 774ED2D639, 2357 ms
Dec 6 17:11:27 zimbra postfix/smtp[815]: E40952D638: to=<lkml@mydomain.net>, relay=127.0.0.1[127.0.0.1], delay=3, status=sent (250 2.6.0 Ok, id=29944-02, from MTA([127.0.0.1]:10025): 250 Ok: queued as 774ED2D639)
Dec 6 17:11:27 zimbra postfix/qmgr[26559]: E40952D638: removed
Dec 6 17:11:27 zimbra postfix/lmtp[820]: 774ED2D639: to=<lkml@mydomain.net>, relay=zimbra.mydomain.net[X.X.X.X], delay=0, status=deferred (host zimbra.mydomain.net[X.X.X.X] said: 451 4.0.0 Temporary message delivery failure try again (in reply to end of DATA command))


When sending to admin@mydomain.net:

Dec 6 17:13:52 zimbra postfix/smtpd[987]: connect from wx-out-0506.google.com[66.249.82.237]
Dec 6 17:13:52 zimbra postfix/smtpd[987]: 7D25F2D638: client=wx-out-0506.google.com[66.249.82.237]
Dec 6 17:13:52 zimbra postfix/cleanup[814]: 7D25F2D638: message-id=<946c674b0612060814n235ae8e0m69b57d1994b0442@ma il.gmail.com>
Dec 6 17:13:52 zimbra postfix/qmgr[26559]: 7D25F2D638: from=<myuser@gmail.com>, size=1572, nrcpt=1 (queue active)
Dec 6 17:13:52 zimbra amavis[29939]: (29939-03) ESMTP::10024 /opt/zimbra/amavisd/tmp/amavis-20061206T165425-29939: <myuser@gmail.com> -> <admin@mydomain.net> SIZE=1572 Received: from zimbra.mydomain.net ([127.0.0.1]) by localhost (zimbra.mydomain.net [127.0.0.1]) (amavisd-new, port 10024) with ESMTP for <admin@mydomain.net>; Wed, 6 Dec 2006 17:13:52 +0100 (CET)
Dec 6 17:13:52 zimbra amavis[29939]: (29939-03) Checking: oJ1ISji9K3qi [66.249.82.237] <myuser@gmail.com> -> <admin@mydomain.net>
Dec 6 17:13:54 zimbra postfix/smtpd[819]: connect from localhost.localdomain[127.0.0.1]
Dec 6 17:13:54 zimbra postfix/smtpd[819]: 338A42D63F: client=localhost.localdomain[127.0.0.1]
Dec 6 17:13:54 zimbra postfix/cleanup[814]: 338A42D63F: message-id=<946c674b0612060814n235ae8e0m69b57d1994b0442@ma il.gmail.com>
Dec 6 17:13:54 zimbra postfix/qmgr[26559]: 338A42D63F: from=<myuser@gmail.com>, size=2382, nrcpt=1 (queue active)
Dec 6 17:13:54 zimbra postfix/smtpd[819]: disconnect from localhost.localdomain[127.0.0.1]
Dec 6 17:13:54 zimbra amavis[29939]: (29939-03) FWD via SMTP: <myuser@gmail.com> -> <admin@mydomain.net>, 250 2.6.0 Ok, id=29939-03, from MTA([127.0.0.1]:10025): 250 Ok: queued as 338A42D63F
Dec 6 17:13:54 zimbra amavis[29939]: (29939-03) Passed CLEAN, [66.249.82.237] [66.249.82.237] <myuser@gmail.com> -> <admin@mydomain.net>, Message-ID: <946c674b0612060814n235ae8e0m69b57d1994b0442@mail. gmail.com>, mail_id: oJ1ISji9K3qi, Hits: 0.625, queued_as: 338A42D63F, 1507 ms
Dec 6 17:13:54 zimbra postfix/smtp[815]: 7D25F2D638: to=<admin@mydomain.net>, relay=127.0.0.1[127.0.0.1], delay=2, status=sent (250 2.6.0 Ok, id=29939-03, from MTA([127.0.0.1]:10025): 250 Ok: queued as 338A42D63F)
Dec 6 17:13:54 zimbra postfix/qmgr[26559]: 7D25F2D638: removed
Dec 6 17:13:54 zimbra postfix/lmtp[820]: 338A42D63F: to=<admin@mydomain.net>, relay=zimbra.mydomain.net[X.X.X.X], delay=0, status=sent (250 2.1.5 OK)
Dec 6 17:13:54 zimbra postfix/qmgr[26559]: 338A42D63F: removed

When sending email I get the red icon with "A network service error has occurred"
output:
msg - system failure: indexMessage caught IOException
com.zimbra.cs.service.ServiceException: system failure: indexMessage caught IOException
at com.zimbra.cs.service.ServiceException.FAILURE(Ser viceException.java:174)
at com.zimbra.cs.index.Indexer.indexMessage(Indexer.j ava:161)
at com.zimbra.cs.mailbox.Message.reindex(Message.java :421)
at com.zimbra.cs.mailbox.Mailbox.endTransaction(Mailb ox.java:4371)
at com.zimbra.cs.mailbox.Mailbox.addMessageInternal(M ailbox.java:3318)
at com.zimbra.cs.mailbox.Mailbox.addMessage(Mailbox.j ava:3062)
at com.zimbra.cs.mailbox.Mailbox.addMessage(Mailbox.j ava:3034)
at com.zimbra.cs.mailbox.MailSender.sendMimeMessage(M ailSender.java:183)
at com.zimbra.cs.mailbox.MailSender.sendMimeMessage(M ailSender.java:119)
at com.zimbra.cs.operation.SendMsgOperation.callback( SendMsgOperation.java:73)
at com.zimbra.cs.operation.Operation.schedule(Operati on.java:190)
at com.zimbra.cs.service.mail.SendMsg.handle(SendMsg. java:109)
at com.zimbra.soap.SoapEngine.dispatchRequest(SoapEng ine.java:261)
at com.zimbra.soap.SoapEngine.dispatch(SoapEngine.jav a:162)
at com.zimbra.soap.SoapEngine.dispatch(SoapEngine.jav a:84)
at com.zimbra.soap.SoapServlet.doPost(SoapServlet.jav a:223)
at javax.servlet.http.HttpServlet.service(HttpServlet .java:709)
at com.zimbra.cs.servlet.ZimbraServlet.service(Zimbra Servlet.java:173)
at javax.servlet.http.HttpServlet.service(HttpServlet .java:802)
at org.apache.catalina.core.ApplicationFilterChain.in ternalDoFilter(ApplicationFilterChain.java:252)
at org.apache.catalina.core.ApplicationFilterChain.do Filter(ApplicationFilterChain.java:173)
at org.apache.catalina.core.StandardWrapperValve.invo ke(StandardWrapperValve.java:213)
at org.apache.catalina.core.StandardContextValve.invo ke(StandardContextValve.java:178)
at org.apache.catalina.core.StandardHostValve.invoke( StandardHostValve.java:126)
at org.apache.catalina.valves.ErrorReportValve.invoke (ErrorReportValve.java:105)
at org.apache.catalina.core.StandardEngineValve.invok e(StandardEngineValve.java:107)
at org.apache.catalina.valves.AccessLogValve.invoke(A ccessLogValve.java:541)
at org.apache.catalina.connector.CoyoteAdapter.servic e(CoyoteAdapter.java:148)
at org.apache.coyote.http11.Http11Processor.process(H ttp11Processor.java:869)
at org.apache.coyote.http11.Http11BaseProtocol$Http11 ConnectionHandler.processConnection(Http11BaseProt ocol.java:667)
at org.apache.tomcat.util.net.PoolTcpEndpoint.process Socket(PoolTcpEndpoint.java:527)
at org.apache.tomcat.util.net.LeaderFollowerWorkerThr ead.runIt(LeaderFollowerWorkerThread.java:80)
at org.apache.tomcat.util.threads.ThreadPool$ControlR unnable.run(ThreadPool.java:684)
at java.lang.Thread.run(Thread.java:595)
Caused by: java.io.IOException: Could not create index /opt/zimbra/index/0/3/index/0 (directory already exists)
at com.zimbra.cs.index.MailboxIndex.openIndexWriter(M ailboxIndex.java:906)
at com.zimbra.cs.index.MailboxIndex.addDocument(Mailb oxIndex.java:349)
at com.zimbra.cs.index.Indexer.addDocument(Indexer.ja va:354)
at com.zimbra.cs.index.Indexer.addDocument(Indexer.ja va:324)
at com.zimbra.cs.index.Indexer.indexMessage(Indexer.j ava:156)
... 32 more
Caused by: java.io.IOException: Lock obtain timed out: Lock@/opt/zimbra/apache-tomcat-5.5.1...b5c-write.lock
at org.apache.lucene.store.Lock.obtain(Lock.java:58)
at org.apache.lucene.index.IndexWriter.<init>(IndexWr iter.java:223)
at org.apache.lucene.index.IndexWriter.<init>(IndexWr iter.java:173)
at com.zimbra.cs.index.MailboxIndex.openIndexWriter(M ailboxIndex.java:887)
... 36 more

code - service.FAILURE
method - ZmCsfeCommand.prototype.invoke
detail - soap:Receiver

[dkarp]

Any chance this is a Debian permissions problem?

mystery solved: unclean shutdown causes redo.log to be owned by root:root

[adoroar]

It is Debian!
Have had a lot of problems with permissions changing, even made a fix_perm.sh script for when it happens.
But I only know about /var/log/zimbra.log and /opt/zimbra/redolog/redo.log

Edit: Are there any lists available with the correct permissions for all the files in zimbra?
Also i'm using the source version of xen so the kernel is 2.6.16.29-xen not the default Debian one.

[adoroar]

This is so weird, I don't think it has anything to do with permissions.
I just deleted my whole queue of 1000+ manually, /opt/zimbra/postfix/spool/deferred/
Then I suddenly have 50 emails.
and it appears to be working again..
I can even send mail now.
Weird :S

[dkarp]

Originally Posted by adoroar

Have had a lot of problems with permissions changing, even made a fix_perm.sh script for when it happens.
But I only know about /var/log/zimbra.log and /opt/zimbra/redolog/redo.log

Use the zmfixperms script -- that should reset the permission correctly on all the necessary files. And there are lots of files/directories that metter, not just the two you listed...