1

Topic: iredmail error connecting to mysql

==== Required information ====
- iRedMail version:
- Store mail accounts in which backend (LDAP/MySQL/PGSQL):
- Linux/BSD distribution name and version:
- Related log if you're reporting an issue:
======== Required information ====
- iRedMail version: iRedMail-0.8.3.
- Store mail accounts in which backend (LDAP/MySQL/PGSQL): MySQL
- Linux/BSD distribution name and version: CentOS 5.6
- Related log if you're reporting an issue:
====

After a power outage our iRedMail is broken. Both Postfix, Dovecot, mysqld, Httpd are running but users are getting prompts to enter their passwords. It seems iRedMail cannot connect to the mysql server which has been evident from Roundcube and Postfix logs. However, am able to login to iRedAdmin website.

Please assist on what my be the issue

May 29 16:53:36 MxSvr postfix/error[4700]: fatal: proxy:mysql:/etc/postfix/mysql/relay_domains.cf(0,lock|fold_fix): table lookup problem
relay=127.0.0.1[127.0.0.1]:10024, delay=4718, delays=4717/0.02/0/1.2, dsn=4.5.0, status=deferred (host 127.0.0.1[127.0.0.1] said: 451 4.5.0 Error in processing, id=04337-03, sql-enter FAILED: connect_to_sql: unable to connect to any dataset at (eval 87) line 241, <GEN20> line 16. (in reply to end of DATA command))
May 29 16:53:36 MxSvr postfix/error[4702]: 73E491580032: to=<xxxxxxxxxxxxxx>, relay=none, delay=934, delays=932/1.2/0/1, dsn=4.3.0, status=deferred (unknown mail transport error)
May 29 16:53:36 MxSvr postfix/error[4702]: fatal: proxy:mysql:/etc/postfix/mysql/relay_domains.cf(0,lock|fold_fix): table lookup problem
May 29 16:53:36 MxSvr postfix/smtp[4698]: fatal: proxy:mysql:/etc/postfix/mysql/relay_domains.cf(0,lock|fold_fix): table lookup problem
May 29 16:53:37 MxSvr postfix/error[4705]: fatal: proxy:mysql:/etc/postfix/mysql/relay_domains.cf(0,lock|fold_fix): table lookup problem
May 29 16:53:37 MxSvr postfix/qmgr[4696]: warning: private/retry socket: malformed response
May 29 16:53:37 MxSvr postfix/qmgr[4696]: warning: transport retry failure -- see a previous warning/fatal/panic logfile record for the problem description
May 29 16:53:37 MxSvr postfix/master[4203]: warning: process /usr/libexec/postfix/error pid 4700 exit status 1
May 29 16:53:37 MxSvr postfix/master[4203]: warning: /usr/libexec/postfix/error: bad command startup -- throttling
May 29 16:53:37 MxSvr postfix/error[4707]: 73E491580032: to=<maurice@xxxxxxxxx>, relay=none, delay=935, delays=932/1.3/0/2, dsn=4.3.0, status=deferred (unknown mail transport error)
May 29 16:53:37 MxSvr postfix/error[4707]: fatal: proxy:mysql:/etc/postfix/mysql/relay_domains.cf(0,lock|fold_fix): table lookup problem
May 29 16:53:37 MxSvr postfix/master[4203]: warning: process /usr/libexec/postfix/smtp pid 4698 exit status 1
May 29 16:53:37 MxSvr postfix/master[4203]: warning: process /usr/libexec/postfix/error pid 4702 exit status 1
May 29 16:53:37 MxSvr postfix/qmgr[4696]: fatal: proxy:mysql:/etc/postfix/mysql/relay_domains.cf(0,lock|fold_fix): table lookup problem
May 29 16:53:37 MxSvr postfix/error[4701]: fatal: proxy:mysql:/etc/postfix/mysql/relay_domains.cf(0,lock|fold_fix): table lookup problem
May 29 16:53:38 MxSvr postfix/master[4203]: warning: process /usr/libexec/postfix/error pid 4705 exit status 1
May 29 16:53:38 MxSvr postfix/master[4203]: warning: process /usr/libexec/postfix/error pid 4707 exit status 1
May 29 16:53:38 MxSvr postfix/master[4203]: warning: process /usr/libexec/postfix/qmgr pid 4696 exit status 1
May 29 16:53:38 MxSvr postfix/master[4203]: warning: process /usr/libexec/postfix/error pid 4701 exit status 1
May 29 16:53:43 MxSvr postfix/proxymap[4634]: warning: connect to mysql server 127.0.0.1: Can't connect to MySQL server on '127.0.0.1' (111)
May 29 16:53:43 MxSvr postfix/proxymap[4634]: warning: connect to mysql server 127.0.0.1: Can't connect to MySQL server on '127.0.0.1' (111)
May 29 16:53:43 MxSvr postfix/trivial-rewrite[4711]: fatal: proxy:mysql:/etc/postfix/mysql/virtual_mailbox_domains.cf(0,lock|fold_fix): table lookup problem
May 29 16:53:43 MxSvr postfix/trivial-rewrite[4712]: fatal: proxy:mysql:/etc/postfix/mysql/virtual_mailbox_domains.cf(0,lock|fold_fix): table lookup problem
May 29 16:53:43 MxSvr postfix/trivial-rewrite[4713]: fatal: proxy:mysql:/etc/postfix/mysql/virtual_mailbox_domains.cf(0,lock|fold_fix): table lookup problem
May 29 16:53:44 MxSvr postfix/smtpd[4608]: warning: problem talking to service rewrite: Success
May 29 16:53:44 MxSvr postfix/master[4203]: warning: process /usr/libexec/postfix/trivial-rewrite pid 4711 exit status 1
May 29 16:53:44 MxSvr postfix/master[4203]: warning: /usr/libexec/postfix/trivial-rewrite: bad command startup -- throttling
May 29 16:53:44 MxSvr postfix/master[4203]: warning: process /usr/libexec/postfix/trivial-rewrite pid 4712 exit status 1
May 29 16:53:44 MxSvr postfix/smtpd[4633]: warning: problem talking to service rewrite: Success
May 29 16:53:44 MxSvr postfix/master[4203]: warning: process /usr/libexec/postfix/trivial-rewrite pid 4713 exit status 1
May 29 16:53:44 MxSvr postfix/smtpd[4672]: warning: problem talking to service rewrite: Success

2

Re: iredmail error connecting to mysql

*) Please check whether MySQL service is running.
*) If MySQL is running, check whether related database records are correct.

3

Re: iredmail error connecting to mysql

@ZhangHuangbin Thanks for quick response. Mysqld Is running. I noticed that I can get iRedAdmin website to work after restarting the service. However, Roundcube gives error "DATABASE ERROR: CONNECTION FAILED!Unable to connect to the database!"
What records are you referring to in point 2?
Also I have phpmyAdmin and everything looks sort of OK over there...

4

Re: iredmail error connecting to mysql

Checking my logs, some errors have disappeared after restarting Mysql but not quite. This is what am getting now from my mail log.
Any ideas are appreciated
May 29 17:30:04 MxSvr postfix/smtp[5908]: E9B291580038: to=<rajsahi@xxxxxxx>, relay=127.0.0.1[127.0.0.1]:10024, delay=524, delays=520/3.8/0/0.1, dsn=4.5.0, status=deferred (host 127.0.0.1[127.0.0.1] said: 451 4.5.0 Error in processing, id=05923-02, sql-enter FAILED: sql exec: err=1033, S1000, DBD::mysql::st execute failed: Incorrect information in file: './amavisd/maddr.frm' at (eval 87) line 166, <GEN18> line 40. (in reply to end of DATA command))
May 29 17:30:04 MxSvr amavis[5923]: (05923-03) (!!)TROUBLE in process_request: Can't create file /var/amavis/tmp/amavis-20130529T173004-05923/email.txt: File exists at /usr/sbin/amavisd line 5356, <GEN19> line 4.
May 29 17:30:04 MxSvr amavis[5923]: (05923-03) (!)Requesting process rundown after fatal error
May 29 17:30:04 MxSvr postfix/smtp[5908]: E9B291580038: to=<simon@xxxxxxx>, relay=127.0.0.1[127.0.0.1]:10024, delay=524, delays=520/4.1/0/0, dsn=4.3.2, status=deferred (host 127.0.0.1[127.0.0.1] said: 421 4.3.2 Service shutting down, closing channel (in reply to MAIL FROM command))
May 29 17:30:04 MxSvr amavis[5924]: (05924-01) (!!)TROUBLE in check_mail: sql-enter FAILED: sql exec: err=1033, S1000, DBD::mysql::st execute failed: Incorrect information in file: './amavisd/maddr.frm' at (eval 87) line 166, <GEN16> line 40.
May 29 17:30:04 MxSvr amavis[5924]: (05924-01) (!)PRESERVING EVIDENCE in /var/amavis/tmp/amavis-20130529T173004-05924
May 29 17:30:05 MxSvr postfix/smtp[5908]: E9B291580038: to=<underwriting@xxxxxxx>, relay=127.0.0.1[127.0.0.1]:10024, delay=524, delays=520/4.1/0.01/0.11, dsn=4.5.0, status=deferred (host 127.0.0.1[127.0.0.1] said: 451 4.5.0 Error in processing, id=05924-01, sql-enter FAILED: sql exec: err=1033, S1000, DBD::mysql::st execute failed: Incorrect information in file: './amavisd/maddr.frm' at (eval 87) line 166, <GEN16> line 40. (in reply to end of DATA command))
May 29 17:30:05 MxSvr amavis[5915]: (05915-03) (!!)TROUBLE in check_mail: sql-enter FAILED: sql exec: err=1033, S1000, DBD::mysql::st execute failed: Incorrect information in file: './amavisd/maddr.frm' at (eval 87) line 166, <GEN21> line 40.

5

Re: iredmail error connecting to mysql

nifilipo wrote:

May 29 17:30:04 MxSvr postfix/smtp[5908]: E9B291580038: to=<rajsahi@xxxxxxx>, relay=127.0.0.1[127.0.0.1]:10024, delay=524, delays=520/3.8/0/0.1, dsn=4.5.0, status=deferred (host 127.0.0.1[127.0.0.1] said: 451 4.5.0 Error in processing, id=05923-02, sql-enter FAILED: sql exec: err=1033, S1000, DBD::mysql::st execute failed: Incorrect information in file: './amavisd/maddr.frm' at (eval 87) line 166, <GEN18> line 40. (in reply to end of DATA command))

I'm afraid that Amavisd database file was damaged.

Here's temporary solution to make your mail server working:

*) Comment out parameter "content_filter =" in Postfix main.cf, then reload or restart Postfix service. So that all new incoming emails won't be passed to Amavisd for spam/virus scanning. You can also run "postqueue -f" to flush all emails in Postfix queue, Postfix will try to deliver them immediately.

*) Try to fix Amavisd database (name "amavisd") files with MySQL command line tools, or phpMyAdmin.

*) After you fixed Amavisd database, uncomment "content_filter =" in Postfix main.cf and reload/restart Postfix service.

NOTE: It's OK to delete all records in Amavisd database, it just stores basic info of in/out emails, deleting all records won't impact mail messages stored on file system at all. But you will lose statistics in iRedAdmin-Pro which depends on records stored in Amavisd database.

6

Re: iredmail error connecting to mysql

Hi,

Hushed content filter...outgoing mails seem to be working. But issues with incoming. Seems my databases have issues or something. What would you suggest is best way of getting my mailserver back online...uninstall/reinstall of whole iRedmail or MYSQL only?

Everything looks OK in PHPMYADMIN

MYSQLD LOG
====================
130530  9:54:41 [ERROR] /usr/libexec/mysqld: Incorrect information in file: './vmail/used_quota.frm'
130530  9:54:41 [ERROR] /usr/libexec/mysqld: Incorrect information in file: './vmail/used_quota.frm'
130530  9:55:12 [ERROR] /usr/libexec/mysqld: Incorrect information in file: './vmail/used_quota.frm'
130530  9:55:12 [ERROR] /usr/libexec/mysqld: Incorrect information in file: './vmail/used_quota.frm'
130530  9:55:12 [ERROR] /usr/libexec/mysqld: Incorrect information in file: './vmail/used_quota.frm'
130530  9:55:12 [ERROR] /usr/libexec/mysqld: Incorrect information in file: './vmail/used_quota.frm'


InnoDB: using the same InnoDB data or log files.
130530  9:50:01  InnoDB: Unable to open the first data file
InnoDB: Error in opening ./ibdata1
130530  9:50:01  InnoDB: Operating system error number 11 in a file operation.
InnoDB: Error number 11 means 'Resource temporarily unavailable'.
InnoDB: Some operating system error numbers are described at
InnoDB: http://dev.mysql.com/doc/refman/5.0/en/ … codes.html
InnoDB: Could not open or create data files.
InnoDB: If you tried to add new data files, and it failed here,
InnoDB: you should now edit innodb_data_file_path in my.cnf back
InnoDB: to what it was, and remove the new ibdata files InnoDB created
InnoDB: in this failed attempt. InnoDB only wrote those files full of
InnoDB: zeros, but did not yet use them in any way. But be careful: do not
InnoDB: remove old data files which contain your precious data!
130530  9:50:01 [Note] /usr/libexec/mysqld: ready for connections.

MAIL LOG
==========================

May 30 09:58:18 MxSvr postfix/error[15646]: E9B291580038: to=<zzzz@xxxxxx>, relay=none, delay=59818, delays=59811/6/0/0.71, dsn=4.4.2, status=deferred (delivery temporarily suspended: lost connection with 127.0.0.1[127.0.0.1] while sending RCPT TO)
May 30 09:58:18 MxSvr postfix/error[15669]: 510781580074: to=<zzzz@xxxxxx>, relay=none, delay=4637, delays=4630/5.9/0/0.88, dsn=4.4.2, status=deferred (delivery temporarily suspended: lost connection with 127.0.0.1[127.0.0.1] while sending RCPT TO)
May 30 09:58:18 MxSvr postfix/error[15669]: 510781580074: to=<zzz@yyyyyyy>, relay=none, delay=4637, delays=4630/5.9/0/0.89, dsn=4.4.2, status=deferred (delivery temporarily suspended: lost connection with 127.0.0.1[127.0.0.1] while sending RCPT TO)

7

Re: iredmail error connecting to mysql

nifilipo wrote:

130530  9:54:41 [ERROR] /usr/libexec/mysqld: Incorrect information in file: './vmail/used_quota.frm'

SQL table "vmail.used_quota" was damaged, please fix it first.

NOTE: it's safe to delete all records in 'vmail.used_quota' if necessary, Dovecot will create it when user first login via POP3/IMAP.