MySQL error, seems to be one specific mailbox

[staufj22]

Hi,

I'm running 5.0.2 Open Source edition on Debian. Since last night, my mailbox keeps dying, and looking from the logs, it's always due to some MySQL error, pertaining to one mailbox.

How do I find out which account points to which mailbox number, and also, how do I fix something like this?

2008-03-03 08:47:54,182 INFO  [ImapServer-21] [] imap - [192.168.50.90] connected
2008-03-03 08:48:02,246 INFO  [ImapServer-21] [ip=192.168.50.90;] MailboxIndex - Initialized Index for mailbox 18 directory: LuceneIndex at org.apa
che.lucene.store.FSDirectory@/opt/zimbra/index/0/18/index/0 Analyzer=com.zimbra.cs.index.ZimbraAnalyzer@21447f
2008-03-03 08:48:02,246 INFO  [ImapServer-21] [ip=192.168.50.90;] cache - Initializing folder and tag caches for mailbox 18
2008-03-03 08:48:02,548 FATAL [ImapServer-21] [ip=192.168.50.90;] mailbox - Unable to commit database transaction.  Forcing server to abort.
com.zimbra.common.service.ServiceException: system failure: committing database transaction
Code:service.FAILURE
        at com.zimbra.common.service.ServiceException.FAILURE(ServiceException.java:183)
        at com.zimbra.cs.db.DbPool$Connection.commit(DbPool.java:144)
        at com.zimbra.cs.mailbox.Mailbox.endTransaction(Mailbox.java:5734)
        at com.zimbra.cs.mailbox.Mailbox.getConfig(Mailbox.java:1125)
        at com.zimbra.cs.mailbox.Mailbox.finishInitialization(Mailbox.java:460)
        at com.zimbra.cs.mailbox.MailboxManager.getMailboxById(MailboxManager.java:406)
        at com.zimbra.cs.mailbox.MailboxManager.getMailboxByAccountId(MailboxManager.java:265)
        at com.zimbra.cs.mailbox.MailboxManager.getMailboxByAccountId(MailboxManager.java:218)
        at com.zimbra.cs.imap.ImapCredentials.getMailbox(ImapCredentials.java:99)
        at com.zimbra.cs.imap.ImapHandler.startSession(ImapHandler.java:1054)
        at com.zimbra.cs.imap.ImapHandler.authenticate(ImapHandler.java:1019)
        at com.zimbra.cs.imap.ImapAuthenticatorUser.authenticate(ImapAuthenticatorUser.java:62)
        at com.zimbra.cs.security.sasl.Authenticator.authenticate(Authenticator.java:104)
        at com.zimbra.cs.security.sasl.PlainAuthenticator.handle(PlainAuthenticator.java:63)
        at com.zimbra.cs.imap.ImapHandler.continueAuthentication(ImapHandler.java:204)
        at com.zimbra.cs.imap.ImapHandler.continueAuthentication(ImapHandler.java:195)
        at com.zimbra.cs.imap.TcpImapHandler.processCommand(TcpImapHandler.java:149)
        at com.zimbra.cs.tcpserver.ProtocolHandler.processConnection(ProtocolHandler.java:160)
        at com.zimbra.cs.tcpserver.ProtocolHandler.run(ProtocolHandler.java:128)
        at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(Unknown Source)
        at java.lang.Thread.run(Thread.java:619)
Caused by: com.mysql.jdbc.exceptions.MySQLNonTransientConnectionException: Communications link failure during commit(). Transaction resolution unkn
own.
        at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:888)
        at com.mysql.jdbc.Connection.commit(Connection.java:2246)
        at org.apache.commons.dbcp.DelegatingConnection.commit(DelegatingConnection.java:248)
        at org.apache.commons.dbcp.PoolingDataSource$PoolGuardConnectionWrapper.commit(PoolingDataSource.java:244)
        at com.zimbra.cs.db.DbPool$Connection.commit(DbPool.java:142)
        ... 19 more

[jholder]

Looks like you're hitting:
Bug 24507 - Server hangs when unable to commit db transation

[staufj22]

So does this apply to just this one mailbox? Can I get by with a reindex?

How do I figure out which account belong to this mailbox? in this case, mailbox 18?

[jholder]

hmm
I'm sure there's a way to much around in the mysql db to find out. How many users do you have?

You could do

zmprov gaa > /tmp/accounts
for a in `cat /tmp/accounts`; zmprov getMailboxInfo $a


(I'm sure there is a much easier way of doing this)

[staufj22]

I just found out the account name using the IP they're connecting with.
So... now I'm trying to fix it, but the admin console won't let me reindex. I can't even disable this account or change the password....
From the bug report, it sounds like there's an extra commit that Zimbra is trying to do... so how do I get rid of it?

[staufj22]

Hrm... Looks like trying to reindex the mailbox using the CLI will crash mailboxd too.

Any ideas on how to fix this mailbix would be greatly appreciated.

[jholder]

First, disable IMAP access on the problem accunt
Second, Restart mailboxd (zmmailboxdctl restart)
Third, Reindex the account
Fourth, Re-enable IMAP access

Check out bug 24505

Good luck,
jh

[staufj22]

First, disable IMAP access on the problem accunt
Second, Restart mailboxd (zmmailboxdctl restart)
Third, Reindex the account
Fourth, Re-enable IMAP access

Check out bug 24505

Good luck,
jh

I'm not sure if I'm doing this correctly...
When I try to reindex the mail box, I get this..

zimbra@enterprise:~$ zmprov rim <name>@<domain>.com start
ERROR: zclient.IO_ERROR (invoke The server <host>.<domain>.com failed to respond, server: <host>.<domain>.com) (cause: org.apache.commons.httpclient.NoHttpResponseException The server <host>.<domain>.com failed to respond)

Is there another way ot reindexing the mailbox?

[staufj22]

I tried to do a DB integrity check, here's the output

InnoDB: Database page corruption on disk or a failed
InnoDB: file read of page 237.
InnoDB: You may have to recover from a backup.
080303 15:32:57  InnoDB: Page dump in ascii and hex (16384 bytes):
 len 16384; hex e0faa311000000ed0000007c000000ef00000000533d60c545bf0000000000000000000001cc00d....<continues on>
080303 15:32:57  InnoDB: Page checksum 1322015055, prior-to-4.0.14-form checksum 1759168681
InnoDB: stored checksum 3774522129, prior-to-4.0.14-form stored checksum 285212672
InnoDB: Page lsn 0 1396531397, low 4 bytes of lsn at page end 301989960
InnoDB: Page number (if stored to page already) 237,
InnoDB: space id (if created with >= MySQL-4.1.1 and stored already) 460
InnoDB: Page may be an index page where index id is 0 1330
InnoDB: (index i_mod_metadata of table mboxgroup18/mail_item)
InnoDB: Database page corruption on disk or a failed
InnoDB: file read of page 237.
InnoDB: You may have to recover from a backup.
InnoDB: It is also possible that your operating
InnoDB: system has corrupted its own file cache
InnoDB: and rebooting your computer removes the
InnoDB: error.
InnoDB: If the corrupt page is an index page
InnoDB: you can also try to fix the corruption
InnoDB: by dumping, dropping, and reimporting
InnoDB: the corrupt table. You can use CHECK
InnoDB: TABLE to scan your table for corruption.
InnoDB: See also InnoDB: http://dev.mysql.com/doc/refman/5.0/en/forcing-recovery.html
InnoDB: about forcing recovery.
InnoDB: Ending processing because of a corrupt database page.

Number of processes running now: 0
080303 15:32:57  mysqld restarted
080303 15:32:58  InnoDB: Database was not shut down normally!
InnoDB: Starting crash recovery.
InnoDB: Reading tablespace information from the .ibd files...
InnoDB: Restoring possible half-written data pages from the doublewrite
InnoDB: buffer...
080303 15:32:58  InnoDB: Starting log scan based on checkpoint at
InnoDB: log sequence number 0 1402246462.
InnoDB: Doing recovery: scanned up to log sequence number 0 1402248410
080303 15:32:58  InnoDB: Starting an apply batch of log records to the database...
InnoDB: Progress in percents: 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99 
InnoDB: Apply batch completed
080303 15:32:58  InnoDB: Started; log sequence number 0 1402248410
080303 15:32:58 [Note] /opt/zimbra/mysql/libexec/mysqld: ready for connections.
Version: '5.0.45-log'  socket: '/opt/zimbra/db/mysql.sock'  port: 7306  Source distribution