HowtoForge Forums | HowtoForge - Linux Howtos and Tutorials

HowtoForge Forums | HowtoForge - Linux Howtos and Tutorials (http://www.howtoforge.com/forums/index.php)
-   HOWTO-Related Questions (http://www.howtoforge.com/forums/forumdisplay.php?f=2)
-   -   postfix/trivial-rewrite (http://www.howtoforge.com/forums/showthread.php?t=37089)

digitalage 28th June 2009 23:03

postfix/trivial-rewrite
 
Hello,

I followed Virtual Users And Domains With Postfix, Courier, MySQL And SquirrelMail (Debian Lenny) to configure email on my server. Everything went smooth and I could used it for about 1 month. For 1 day, no emails enter my server and some errors appear in logs:

Code:

Jun 28 12:04:43 hostname postfix/master[3302]: daemon started -- version 2.5.5, configuration /etc/postfix
Jun 28 12:04:43 hostname postfix/qmgr[3310]: 58D86A34E0: from=<>, size=3758, nrcpt=1 (queue active)
Jun 28 12:04:43 hostname postfix/proxymap[3317]: warning: connect to mysql server 127.0.0.1: Lost connection to MySQL server at 'reading initial communication packet', system error: 0
Jun 28 12:04:43 hostname postfix/proxymap[3317]: warning: connect to mysql server 127.0.0.1: Lost connection to MySQL server at 'reading initial communication packet', system error: 0
Jun 28 12:04:43 hostname postfix/trivial-rewrite[3316]: fatal: proxy:mysql:/etc/postfix/mysql-virtual_domains.cf(0,lock|fold_fix): table lookup problem
Jun 28 12:04:44 hostname postfix/master[3302]: warning: process /usr/lib/postfix/trivial-rewrite pid 3316 exit status 1
Jun 28 12:04:44 hostname postfix/master[3302]: warning: /usr/lib/postfix/trivial-rewrite: bad command startup -- throttling
Jun 28 12:04:45 hostname postfix/master[3302]: reload configuration /etc/postfix
Jun 28 12:04:47 hostname postfix/pickup[3437]: 1FAABA3507: uid=0 from=<root>
Jun 28 12:04:50 hostname postfix/master[3302]: reload configuration /etc/postfix
Jun 28 12:05:44 hostname postfix/proxymap[3750]: warning: connect to mysql server 127.0.0.1: Lost connection to MySQL server at 'reading initial communication packet', system error: 0
Jun 28 12:05:44 hostname postfix/proxymap[3750]: warning: connect to mysql server 127.0.0.1: Lost connection to MySQL server at 'reading initial communication packet', system error: 0
Jun 28 12:05:44 hostname postfix/trivial-rewrite[3749]: fatal: proxy:mysql:/etc/postfix/mysql-virtual_domains.cf(0,lock|fold_fix): table lookup problem
Jun 28 12:05:45 hostname postfix/cleanup[3450]: warning: problem talking to service rewrite: Connection reset by peer
Jun 28 12:05:45 hostname postfix/qmgr[3310]: warning: problem talking to service rewrite: Success
Jun 28 12:05:45 hostname postfix/master[3302]: warning: process /usr/lib/postfix/trivial-rewrite pid 3749 exit status 1
Jun 28 12:05:45 hostname postfix/master[3302]: warning: /usr/lib/postfix/trivial-rewrite: bad command startup -- throttling
Jun 28 12:06:45 hostname postfix/proxymap[3755]: warning: connect to mysql server 127.0.0.1: Lost connection to MySQL server at 'reading initial communication packet', system error: 0
Jun 28 12:06:45 hostname postfix/cleanup[3450]: 1FAABA3507: message-id=<20090628090447.1FAABA3507@server.myhost.com>
Jun 28 12:06:45 hostname postfix/proxymap[3755]: warning: connect to mysql server 127.0.0.1: Lost connection to MySQL server at 'reading initial communication packet', system error: 0
Jun 28 12:06:45 hostname postfix/trivial-rewrite[3754]: fatal: proxy:mysql:/etc/postfix/mysql-virtual_domains.cf(0,lock|fold_fix): table lookup problem
Jun 28 12:06:46 hostname postfix/qmgr[3310]: warning: problem talking to service rewrite: Success
Jun 28 12:06:46 hostname postfix/master[3302]: warning: process /usr/lib/postfix/trivial-rewrite pid 3754 exit status 1
Jun 28 12:06:46 hostname postfix/pickup[3437]: EEB19A33F7: uid=0 from=<root>
Jun 28 12:06:46 hostname postfix/cleanup[3757]: EEB19A33F7: message-id=<20090628090646.EEB19A33F7@server.myhost.com>
Jun 28 12:06:47 hostname postfix/trivial-rewrite[3758]: fatal: proxy:mysql:/etc/postfix/mysql-virtual_domains.cf(0,lock|fold_fix): table lookup problem
Jun 28 12:06:47 hostname postfix/pickup[3437]: EFA95A34E7: uid=0 from=<root>
Jun 28 12:06:48 hostname postfix/qmgr[3310]: warning: problem talking to service rewrite: Success
Jun 28 12:06:48 hostname postfix/cleanup[3757]: warning: problem talking to service rewrite: Connection reset by peer
Jun 28 12:06:48 hostname postfix/master[3302]: warning: process /usr/lib/postfix/trivial-rewrite pid 3758 exit status 1
Jun 28 12:06:49 hostname postfix/trivial-rewrite[3760]: fatal: proxy:mysql:/etc/postfix/mysql-virtual_domains.cf(0,lock|fold_fix): table lookup problem
Jun 28 12:06:50 hostname postfix/qmgr[3310]: warning: problem talking to service rewrite: Success
Jun 28 12:06:50 hostname postfix/cleanup[3757]: warning: problem talking to service rewrite: Connection reset by peer
Jun 28 12:06:50 hostname postfix/master[3302]: warning: process /usr/lib/postfix/trivial-rewrite pid 3760 exit status 1
Jun 28 12:06:50 hostname postfix/master[3302]: warning: /usr/lib/postfix/trivial-rewrite: bad command startup -- throttling

Note: the real domain name was replaced with "myhost.com"

I really don't understand what's going on. I need some help, please.

falko 29th June 2009 12:49

It seems as if MySQL isn't running. What's the output of
Code:

netstat -tap
?

digitalage 29th June 2009 16:18

# netstat -tap | grep mysql
Code:

tcp        0      0 localhost:mysql        *:*                    LISTEN      12566/mysqld
tcp        0      0 localhost:mysql        localhost:51517        TIME_WAIT  -
tcp        0      0 localhost:mysql        localhost:51516        TIME_WAIT  -
tcp        0      0 localhost:mysql        localhost:51515        TIME_WAIT  -
tcp        0      0 localhost:mysql        localhost:51514        TIME_WAIT  -


digitalage 29th June 2009 16:27

MySQL works fine, I guess. I can connect to databases using PhpMyAdmin. Also, if I run /etc/init.d/mysql restart, I get the following output:

Code:

Jun 29 17:22:48 hostname mysqld[13464]: 090629 17:22:48  InnoDB: Shutdown completed; log sequence number 0 233495
Jun 29 17:22:48 hostname mysqld[13464]: 090629 17:22:48 [Note] /usr/sbin/mysqld: Shutdown complete
Jun 29 17:22:48 hostname mysqld[13464]:
Jun 29 17:22:48 hostname mysqld_safe[13997]: ended
Jun 29 17:22:49 hostname mysqld_safe[14073]: started
Jun 29 17:22:49 hostname mysqld[14077]: 090629 17:22:49  InnoDB: Started; log sequence number 0 233495
Jun 29 17:22:49 hostname mysqld[14077]: 090629 17:22:49 [Note] /usr/sbin/mysqld: ready for connections.
Jun 29 17:22:49 hostname mysqld[14077]: Version: '5.0.51a-24+lenny1-log'  socket: '/var/run/mysqld/mysqld.sock'  port: 3306  (Debian)
Jun 29 17:22:50 hostname /etc/mysql/debian-start[14117]: Upgrading MySQL tables if necessary.
Jun 29 17:22:50 hostname /etc/mysql/debian-start[14123]: Looking for 'mysql' in: /usr/bin/mysql
Jun 29 17:22:50 hostname /etc/mysql/debian-start[14123]: Looking for 'mysqlcheck' in: /usr/bin/mysqlcheck
Jun 29 17:22:50 hostname /etc/mysql/debian-start[14123]: This installation of MySQL is already upgraded to 5.0.51a, use --force if you still need to run mysql_upgrade
Jun 29 17:22:50 hostname /etc/mysql/debian-start[14129]: Checking for insecure root accounts.
Jun 29 17:22:50 hostname /etc/mysql/debian-start[14133]: Triggering myisam-recover for all MyISAM tables
Jun 29 17:23:18 hostname postfix/smtpd[30085]: fatal: watchdog timeout
Jun 29 17:23:19 hostname postfix/master[3302]: warning: process /usr/lib/postfix/smtpd pid 30085 exit status 1
Jun 29 17:23:19 hostname postfix/master[3302]: warning: /usr/lib/postfix/smtpd: bad command startup -- throttling
Jun 29 17:23:48 hostname postfix/proxymap[3874]: warning: connect to mysql server 127.0.0.1: Lost connection to MySQL server at 'reading initial communication packet', system error: 0
Jun 29 17:23:48 hostname postfix/proxymap[3874]: warning: connect to mysql server 127.0.0.1: Lost connection to MySQL server at 'reading initial communication packet', system error: 0
Jun 29 17:23:48 hostname postfix/trivial-rewrite[14167]: fatal: proxy:mysql:/etc/postfix/mysql-virtual_domains.cf(0,lock|fold_fix): table lookup problem
Jun 29 17:23:48 hostname postfix/trivial-rewrite[14168]: fatal: proxy:mysql:/etc/postfix/mysql-virtual_domains.cf(0,lock|fold_fix): table lookup problem
Jun 29 17:23:48 hostname postfix/trivial-rewrite[14169]: fatal: proxy:mysql:/etc/postfix/mysql-virtual_domains.cf(0,lock|fold_fix): table lookup problem
Jun 29 17:23:48 hostname postfix/trivial-rewrite[14170]: fatal: proxy:mysql:/etc/postfix/mysql-virtual_domains.cf(0,lock|fold_fix): table lookup problem
Jun 29 17:23:48 hostname postfix/proxymap[23943]: warning: connect to mysql server 127.0.0.1: Lost connection to MySQL server at 'reading initial communication packet', system error: 0
Jun 29 17:23:48 hostname postfix/proxymap[23943]: warning: connect to mysql server 127.0.0.1: Lost connection to MySQL server at 'reading initial communication packet', system error: 0
Jun 29 17:23:48 hostname postfix/trivial-rewrite[14171]: fatal: proxy:mysql:/etc/postfix/mysql-virtual_domains.cf(0,lock|fold_fix): table lookup problem
Jun 29 17:23:48 hostname postfix/trivial-rewrite[14172]: fatal: proxy:mysql:/etc/postfix/mysql-virtual_domains.cf(0,lock|fold_fix): table lookup problem

... (the same message, several times)

Jun 29 17:23:48 hostname postfix/trivial-rewrite[14216]: fatal: proxy:mysql:/etc/postfix/mysql-virtual_domains.cf(0,lock|fold_fix): table lookup problem
Jun 29 17:23:49 hostname postfix/smtpd[8074]: warning: problem talking to service rewrite: Success
Jun 29 17:23:49 hostname postfix/smtpd[866]: warning: problem talking to service rewrite: Connection reset by peer
Jun 29 17:23:49 hostname postfix/master[3302]: warning: process /usr/lib/postfix/trivial-rewrite pid 14167 exit status 1
Jun 29 17:23:49 hostname postfix/master[3302]: warning: /usr/lib/postfix/trivial-rewrite: bad command startup -- throttling
Jun 29 17:23:49 hostname postfix/smtpd[3678]: warning: problem talking to service rewrite: Success
Jun 29 17:23:49 hostname postfix/smtpd[31378]: warning: problem talking to service rewrite: Connection reset by peer
Jun 29 17:23:49 hostname postfix/master[3302]: warning: process /usr/lib/postfix/trivial-rewrite pid 14168 exit status 1
Jun 29 17:23:49 hostname postfix/smtpd[32233]: warning: problem talking to service rewrite: Connection reset by peer
Jun 29 17:23:49 hostname postfix/smtpd[30244]: warning: problem talking to service rewrite: Success
Jun 29 17:23:49 hostname postfix/master[3302]: warning: process /usr/lib/postfix/trivial-rewrite pid 14169 exit status 1
Jun 29 17:23:49 hostname postfix/smtpd[30193]: warning: problem talking to service rewrite: Success
Jun 29 17:23:49 hostname postfix/master[3302]: warning: process /usr/lib/postfix/trivial-rewrite pid 14170 exit status 1
Jun 29 17:23:49 hostname postfix/smtpd[31429]: warning: problem talking to service rewrite: Success
Jun 29 17:23:49 hostname postfix/smtpd[30400]: warning: problem talking to service rewrite: Connection reset by peer
Jun 29 17:23:49 hostname postfix/master[3302]: warning: process /usr/lib/postfix/trivial-rewrite pid 14171 exit status 1
Jun 29 17:23:49 hostname postfix/smtpd[31807]: warning: problem talking to service rewrite: Connection reset by peer

... this group of messages, several times)

Jun 29 17:23:48 hostname postfix/trivial-rewrite[14172]: fatal: proxy:mysql:/etc/postfix/mysql-virtual_domains.cf(0,lock|fold_fix): table lookup problem

... (the same message, several times)

Jun 29 17:23:49 hostname postfix/smtpd[31429]: warning: problem talking to service rewrite: Success
Jun 29 17:23:49 hostname postfix/smtpd[30400]: warning: problem talking to service rewrite: Connection reset by peer
Jun 29 17:23:49 hostname postfix/master[3302]: warning: process /usr/lib/postfix/trivial-rewrite pid 14171 exit status 1
Jun 29 17:23:49 hostname postfix/smtpd[31807]: warning: problem talking to service rewrite: Connection reset by peer

... this group of messages, several times)


falko 30th June 2009 14:16

What's in /etc/hosts?
Is the MySQL login that Postfix uses correct?

digitalage 30th June 2009 15:24

hostname:~# cat /etc/hosts
Code:

127.0.0.1      localhost
127.0.1.1      hostname.myprovider.com        hostname

# The following lines are desirable for IPv6 capable hosts
::1    localhost ip6-localhost ip6-loopback
fe00::0 ip6-localnet
ff00::0 ip6-mcastprefix
ff02::1 ip6-allnodes
ff02::2 ip6-allrouters
ff02::3 ip6-allhosts

Notes: My hostname was replaced with the word "hostname"


I don't know how to answer to the 2nd question. I assume MySQL login is fine, otherwise it didn't work in first place for 1 month. I didn't do any upgrade or update to packages since the install. The MySQL user that Postfix is using is mail_admin.

# postconf -n shows:
Code:

alias_database = hash:/etc/aliases
alias_maps = hash:/etc/aliases
append_dot_mydomain = no
biff = no
broken_sasl_auth_clients = yes
config_directory = /etc/postfix
content_filter = amavis:[127.0.0.1]:10024
html_directory = /usr/share/doc/postfix/html
inet_interfaces = all
mailbox_size_limit = 0
message_size_limit = 31457280
mydestination = server.mydomain.com, localhost, localhost.localdomain
myhostname = server.mydomain.com
mynetworks = 127.0.0.0/8
myorigin = /etc/mailname
proxy_read_maps = $local_recipient_maps $mydestination $virtual_alias_maps $virtual_alias_domains $virtual_mailbox_maps $virtual_mailbox_domains $relay_recipient_maps $relay_domains $canonical_maps $sender_canonical_maps $recipient_canonical_maps $relocated_maps $transport_maps $mynetworks $virtual_mailbox_limit_maps
readme_directory = /usr/share/doc/postfix
receive_override_options = no_address_mappings
recipient_delimiter = +
relayhost =
smtp_tls_session_cache_database = btree:${data_directory}/smtp_scache
smtpd_banner = $myhostname ESMTP $mail_name (Debian/GNU)
smtpd_recipient_restrictions = permit_mynetworks, permit_sasl_authenticated, reject_unauth_destination
smtpd_sasl_auth_enable = yes
smtpd_sasl_authenticated_header = yes
smtpd_tls_cert_file = /etc/postfix/smtpd.cert
smtpd_tls_key_file = /etc/postfix/smtpd.key
smtpd_tls_session_cache_database = btree:${data_directory}/smtpd_scache
smtpd_use_tls = yes
transport_maps = proxy:mysql:/etc/postfix/mysql-virtual_transports.cf
virtual_alias_domains =
virtual_alias_maps = proxy:mysql:/etc/postfix/mysql-virtual_forwardings.cf, mysql:/etc/postfix/mysql-virtual_email2email.cf
virtual_gid_maps = static:5000
virtual_mailbox_base = /home/vmail
virtual_mailbox_domains = proxy:mysql:/etc/postfix/mysql-virtual_domains.cf
virtual_mailbox_limit_maps = proxy:mysql:/etc/postfix/mysql-virtual_mailbox_limit_maps.cf
virtual_mailbox_limit_override = yes
virtual_mailbox_maps = proxy:mysql:/etc/postfix/mysql-virtual_mailboxes.cf
virtual_maildir_extended = yes
virtual_maildir_limit_message = "The user you are trying to reach is over quota."
virtual_overquota_bounce = yes
virtual_uid_maps = static:5000

Note: My domain was replaced with the word "mydomain.com"

Searching the internet I found this link where someone suggests to grant privileges again to the MySQL user that Postfix is using. I'm afraid I don't know how to do this and if it's appropriate to my issue, so I didn't touch the server.

Any idea?


Edit: I found another user having the same issue. He gave up on finding the problem, but I wish I'll find the cause. Hope it won't take too long, otherwise I'll be forced to rebuild the server because my main emails comes on it.

falko 1st July 2009 14:29

What's the output of
Code:

ifconfig
?
Can you log in to MySQL like this?
Code:

mysql -u mail_admin -p
Then type in the password that you use in the mysql*.cf files.

digitalage 1st July 2009 19:49

Everything looks good, either. I don't know why would you need ifconfig - I sent it as private message to stay away of public.


I checked also passwords used in MySql, like this:
# cat /etc/postfix/mysql-virtual_* | grep password
Code:

password = xxx
password = xxx
password = xxx
password = xxx
password = xxx
password = xxx

... and I got the same answer. Then I logged into console of MySql:

# /etc/postfix# mysql -u mail_admin -p
Code:

Enter password: xxx
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 41
Server version: 5.0.51a-24+lenny1-log (Debian)

Type 'help;' or '\h' for help. Type '\c' to clear the buffer.

mysql> show databases;
+--------------------+
| Database          |
+--------------------+
| information_schema |
| mail              |
+--------------------+
2 rows in set (0.00 sec)

mysql> use mail
Reading table information for completion of table and column names
You can turn off this feature to get a quicker startup with -A

Database changed
mysql> show tables;
+----------------+
| Tables_in_mail |
+----------------+
| domains        |
| forwardings    |
| transport      |
| users          |
+----------------+
4 rows in set (0.00 sec)

mysql> quit
Bye


falko 2nd July 2009 14:33

Can you modify /etc/hosts so that it looks as follows?

Code:

127.0.0.1      localhost.localdomain localhost
192.168.0.1      hostname.myprovider.com        hostname

# The following lines are desirable for IPv6 capable hosts
::1    localhost ip6-localhost ip6-loopback
fe00::0 ip6-localnet
ff00::0 ip6-mcastprefix
ff02::1 ip6-allnodes
ff02::2 ip6-allrouters
ff02::3 ip6-allhosts


digitalage 2nd July 2009 22:37

I changed that and the issue is still there. During my research in logs, I found some lines which might or might not be related to this issue. I took them before the last change - you can see the date:

Code:

Jun 30 18:15:07 postfix/pickup[7303]: F0157A3551: uid=0 from=<root>
Jun 30 18:15:13 postfix/master[4812]: warning: service "smtp" (25) has reached its process limit "100": new clients may experience noticeable delays
Jun 30 18:15:13 postfix/master[4812]: warning: to avoid this condition, increase the process count in master.cf or reduce the service time per client
Jun 30 18:15:13 postfix/master[4812]: warning: see http://www.postfix.org/STRESS_README.html for examples of stress-adapting configuration settings
...
Jul  1 09:27:32 209-145-MZA-enternet postfix/smtpd[7724]: fatal: watchdog timeout
Jul  1 09:27:33 postfix/master[4812]: warning: process /usr/lib/postfix/smtpd pid 7724 exit status 1
Jul  1 09:27:33 postfix/master[4812]: warning: /usr/lib/postfix/smtpd: bad command startup -- throttling
...
Jul  1 11:02:12 postfix/trivial-rewrite[4191]: fatal: proxy:mysql:/etc/postfix/mysql-virtual_domains.cf(0,lock|fold_fix): table lookup problem
Jul  1 11:02:13 postfix/qmgr[4068]: warning: problem talking to service rewrite: Success
Jul  1 11:02:13 postfix/master[3306]: warning: process /usr/lib/postfix/trivial-rewrite pid 4191 exit status 1
Jul  1 11:02:13 postfix/master[3306]: warning: /usr/lib/postfix/trivial-rewrite: bad command startup -- throttling
Jul  1 11:02:35 postfix/qmgr[4068]: fatal: watchdog timeout
Jul  1 11:02:36 postfix/master[3306]: warning: process /usr/lib/postfix/qmgr pid 4068 exit status 1
Jul  1 11:02:36 postfix/master[3306]: warning: /usr/lib/postfix/qmgr: bad command startup -- throttling


I checked the config using the following commands:
# cat /etc/postfix/mysql-virtual_domains.cf
Code:

user = mail_admin
password = xxx
dbname = mail
query = SELECT domain AS virtual FROM domains WHERE domain='%s'
hosts = 127.0.0.1

# cat /etc/postfix/mysql-virtual_* | grep user
Code:

user = mail_admin
user = mail_admin
query = SELECT email FROM users WHERE email='%s'
user = mail_admin
user = mail_admin
query = SELECT CONCAT(SUBSTRING_INDEX(email,'@',-1),'/',SUBSTRING_INDEX(email,'@',1),'/') FROM users WHERE email='%s'
user = mail_admin
query = SELECT quota FROM users WHERE email='%s'
user = mail_admin

# cat /etc/postfix/mysql-virtual_* | grep dbname
Code:

dbname = mail
dbname = mail
dbname = mail
dbname = mail
dbname = mail
dbname = mail

# cat /etc/postfix/mysql-virtual_* | grep query
Code:

query = SELECT domain AS virtual FROM domains WHERE domain='%s'
query = SELECT email FROM users WHERE email='%s'
query = SELECT destination FROM forwardings WHERE source='%s'
query = SELECT CONCAT(SUBSTRING_INDEX(email,'@',-1),'/',SUBSTRING_INDEX(email,'@',1),'/') FROM users WHERE email='%s'
query = SELECT quota FROM users WHERE email='%s'
query = SELECT transport FROM transport WHERE domain='%s'

# cat /etc/postfix/mysql-virtual_* | grep hosts
Code:

hosts = 127.0.0.1
hosts = 127.0.0.1
hosts = 127.0.0.1
hosts = 127.0.0.1
hosts = 127.0.0.1
hosts = 127.0.0.1

Everything looks good. However, if I look at my logs, I see lines that I don't know to "translate". Particularly, these:
Code:

Jul  2 23:29:24 postfix/proxymap[3859]: warning: connect to mysql server 127.0.0.1: Lost connection to MySQL server at 'reading initial communication packet', system error: 0
and
Code:

Jul  2 23:29:24 postfix/trivial-rewrite[3923]: fatal: proxy:mysql:/etc/postfix/mysql-virtual_domains.cf(0,lock|fold_fix): table lookup problem
I don't know what is proxymap and proxy:mysql. Are you kind to explain me (maybe it's useful for others too), like to a novice, how the system works? How is the email received by the server and what is its way to the mailbox, in this particular setup?


All times are GMT +2. The time now is 16:27.

Powered by vBulletin® Version 3.8.7
Copyright ©2000 - 2014, vBulletin Solutions, Inc.