HowtoForge Forums | HowtoForge - Linux Howtos and Tutorials

HowtoForge Forums | HowtoForge - Linux Howtos and Tutorials (http://www.howtoforge.com/forums/index.php)
-   Installation/Configuration (http://www.howtoforge.com/forums/forumdisplay.php?f=27)
-   -   mail transport unavailable (http://www.howtoforge.com/forums/showthread.php?t=59350)

ralfba 1st November 2012 21:06

mail transport unavailable
 
Hi ...
i followed the perfect server setup and installed a fresh system on opensuse 12 (apache/posfix/dovecot)

after some testing and migrating users we figured that the mailsystem stoped working :-(

current status is that the mailqueue gets filled up, but nothing is transported somehow.
i already tried to Update/reConfigure the box but that didn't bring me any further.

please help if you have any clue what might cause this.

thx - ralf

falko 3rd November 2012 00:27

Are there any errors in your mail log (in the /var/log/ directory)?

ralfba 4th November 2012 19:19

errors in /var/log
 
Hi ...
yes - there are some errors ...

mail.err
Nov 4 18:37:47 isp03p amavis[16290]: (16290-03) (!!)TROUBLE in check_mail: forwarding FAILED: Error writing to socket: Broken pipe at /usr/sbin/amavisd line 6843.
Nov 4 18:37:48 isp03p amavis[16290]: (16290-03) (!!)TROUBLE in process_request: Error writing to socket: Broken pipe at /usr/sbin/amavisd line 6843.
Nov 4 18:42:50 isp03p amavis[16061]: (16061-05) (!!)TROUBLE in check_mail: forwarding FAILED: Error writing to socket: Broken pipe at /usr/sbin/amavisd line 6843.
Nov 4 18:42:51 isp03p amavis[16061]: (16061-05) (!!)TROUBLE in process_request: Error writing to socket: Broken pipe at /usr/sbin/amavisd line 6843.
Nov 4 18:48:48 isp03p amavis[16790]: (16790-02) (!!)TROUBLE in check_mail: forwarding FAILED: Error writing to socket: Broken pipe at /usr/sbin/amavisd line 6843.
Nov 4 18:48:48 isp03p amavis[16790]: (16790-02) (!!)TROUBLE in process_request: Error writing to socket: Broken pipe at /usr/sbin/amavisd line 6843.
Nov 4 18:52:48 isp03p amavis[17022]: (17022-02) (!!)TROUBLE in check_mail: forwarding FAILED: Error writing to socket: Broken pipe at /usr/sbin/amavisd line 6843.
Nov 4 18:52:49 isp03p amavis[17022]: (17022-02) (!!)TROUBLE in process_request: Error writing to socket: Broken pipe at /usr/sbin/amavisd line 6843.
Nov 4 18:57:50 isp03p amavis[17300]: (17300-02) (!!)TROUBLE in check_mail: forwarding FAILED: Error writing to socket: Broken pipe at /usr/sbin/amavisd line 6843.
Nov 4 18:57:50 isp03p amavis[17300]: (17300-02) (!!)TROUBLE in process_request: Error writing to socket: Broken pipe at /usr/sbin/amavisd line 6843.

mail.warn
Nov 4 19:11:46 isp03p amavis[18030]: (18030-02) (!)ClamAV-clamd av-scanner FAILED: run_av error: Too many retries to talk to /var/run/clamav/clamd (All attempts (1) failed connecting to /var/run/clamav/clamd) at (eval 138) line 603.\n
Nov 4 19:11:46 isp03p amavis[18030]: (18030-02) (!)WARN: all primary virus scanners failed, considering backups
Nov 4 19:11:46 isp03p amavis[17734]: (17734-03) (!)connect to /var/run/clamav/clamd failed, attempt #1: Can't connect to UNIX socket /var/run/clamav/clamd: No such file or directory
Nov 4 19:11:46 isp03p amavis[17734]: (17734-03) (!)ClamAV-clamd av-scanner FAILED: run_av error: Too many retries to talk to /var/run/clamav/clamd (All attempts (1) failed connecting to /var/run/clamav/clamd) at (eval 138) line 603.\n
Nov 4 19:11:46 isp03p amavis[17734]: (17734-03) (!)WARN: all primary virus scanners failed, considering backups
Nov 4 19:12:49 isp03p postfix/master[1920]: warning: process /usr/lib/postfix/smtpd pid 18507 killed by signal 6
Nov 4 19:12:49 isp03p postfix/master[1920]: warning: /usr/lib/postfix/smtpd: bad command startup -- throttling
Nov 4 19:12:49 isp03p amavis[18030]: (18030-02) (!!)TROUBLE in check_mail: forwarding FAILED: Error writing to socket: Broken pipe at /usr/sbin/amavisd line 6843.
Nov 4 19:12:49 isp03p amavis[18030]: (18030-02) (!)PRESERVING EVIDENCE in /var/spool/amavis/tmp/amavis-20121104T190635-18030-BmnL30xK
Nov 4 19:12:49 isp03p postfix/qmgr[1941]: warning: private/amavis socket: malformed response
Nov 4 19:12:49 isp03p postfix/master[1920]: warning: process /usr/lib/postfix/smtp pid 18462 killed by signal 6
Nov 4 19:12:49 isp03p postfix/qmgr[1941]: warning: transport amavis failure -- see a previous warning/fatal/panic logfile record for the problem description
Nov 4 19:12:49 isp03p postfix/master[1920]: warning: /usr/lib/postfix/smtp: bad command startup -- throttling
Nov 4 19:12:50 isp03p amavis[18030]: (18030-02) (!!)TROUBLE in process_request: Error writing to socket: Broken pipe at /usr/sbin/amavisd line 6843.
Nov 4 19:12:50 isp03p amavis[18030]: (18030-02) (!)Requesting process rundown after fatal error
Nov 4 19:12:50 isp03p amavis[18030]: (18030-02) (!)_DIE: Error writing to socket: Broken pipe at /usr/sbin/amavisd line 6843.

mail.info
Nov 4 19:13:27 isp03p postfix/smtp[18460]: C709E6272F: to=<margret.bauerochse@hot-it-muc.de>, relay=127.0.0.1[127.0.0.1]:10024, delay=194288, delays=194177/0.47/0.72/110, dsn=4.5.0, status=deferred (host 127.0.0.1[127.0.0.1] said: 451 4.5.0 id=17734-03 - Temporary MTA failure on relaying, From MTA() during fwd-connect (Negative greeting: at (eval 134) line 464.): id=17734-03 (in reply to end of DATA command))
Nov 4 19:13:27 isp03p amavis[17734]: (17734-03) size: 26448, TIMING [total 111102 ms] - SMTP greeting: 211 (0%)0, SMTP EHLO: 417 (0%)1, SMTP pre-MAIL: 433 (0%)1, lookup_sql: 324 (0%)1, SMTP pre-DATA-flush: 315 (0%)2, SMTP DATA: 81 (0%)2, check_init: 27 (0%)2, digest_hdr: 67 (0%)2, digest_body: 86 (0%)2, mime_decode: 439 (0%)2, get-file-type1: 464 (0%)3, decompose_part: 132 (0%)3, parts_decode: 0 (0%)3, check_header: 95 (0%)3, AV-scan-1: 7442 (7%)9, AV-scan-2: 55215 (50%)59, lookup_sql: 94 (0%)59, lookup_sql: 295 (0%)60, spam-wb-list: 142 (0%)60, SA parse: 266 (0%)60, SA check: 8292 (7%)67, decide_mail_destiny: 507 (0%)68, notif-quar: 30 (0%)68, fwd-end-chkpnt: 35432 (32%)100, prepare-dsn: 27 (0%)100, main_log_entry: 182 (0%)100, update_snmp: 47 (0%)100, SMTP pre-response: 8 (0%)100, SMTP response: 12 (0%)100, unlink-1-files: 6 (0%)100, rundown: 13 (0%)100
Nov 4 19:13:27 isp03p postfix/qmgr[1941]: warning: private/amavis socket: malformed response
Nov 4 19:13:27 isp03p postfix/master[1920]: warning: process /usr/lib/postfix/smtp pid 18460 killed by signal 6
Nov 4 19:13:27 isp03p postfix/qmgr[1941]: warning: transport amavis failure -- see a previous warning/fatal/panic logfile record for the problem description
Nov 4 19:13:27 isp03p postfix/error[18517]: C709E6272F: to=<margret.bauerochse@hot-it-muc.de>, relay=none, delay=194289, delays=194177/112/0/0.03, dsn=4.3.0, status=deferred (unknown mail transport error)
Nov 4 19:13:32 isp03p amavis[17734]: (17734-03) (!)rw_loop: leaving rw loop, no progress, last event (select) 5.005 s ago
Nov 4 19:13:38 isp03p dovecot: imap(margret.bauerochse@hot-it-muc.de): Disconnected for inactivity in=94 out=935
Nov 4 19:13:50 isp03p postfix/smtpd[18558]: connect from unknown[127.0.0.1]
Nov 4 19:13:50 isp03p postfix/smtpd[18558]: disconnect from unknown[127.0.0.1]

ralfba 4th November 2012 19:24

strange is, that it workded for a while and then stoped.
at this point no email at all could be send into the box from esternal ressources.
i performed a update/reconfigure of the installation, maybe i should have recreate the original config files of postfix and amavis before doing that

ralfba 5th November 2012 11:12

i think of putting the config-files of the installation back into play and re-run the ispconfig-installation again ...
will i loose the contents of the mailqueue while i do this?
currently there are 350 mails waiting in it ... growing and growing

till 5th November 2012 11:20

The problem seems to be that amavis is not running, restart amavis and check in the mail.log if it is started then. If this dont help, download the ispconfig tar.gz again, run the update.php scriot in the install folder and choose to reconfigure services. The mails in the queue will not be deleted by this.

ralfba 5th November 2012 18:19

next step is to reconfigure ...
 
Hi Till,
thx for the answer - in the meanwhile also the outgoing mail stoped, i wasn't even changing anything - it just stoped.
i will copy back master.cf and main.cf and start reconfiguring
ralf

ralfba 5th November 2012 19:33

no change
 
Hi ...
reconfiguring did not change anything unfortunately.
any guess what i can check or work on now?
KR - ralf

mail.err
Nov 5 19:11:00 isp03p dovecot: auth-worker(1138): Error: mysql(localhost): Connect failed to database (dbispconfig): Can't connect to local MySQL server through socket '/var/run/mysql/mysql.sock' (2) - waiting for 1 seconds before retry
Nov 5 19:11:00 isp03p dovecot: auth-worker(1138): Error: mysql(localhost): Connect failed to database (dbispconfig): Can't connect to local MySQL server through socket '/var/run/mysql/mysql.sock' (2) - waiting for 1 seconds before retry
Nov 5 19:11:01 isp03p dovecot: auth-worker(1138): Error: mysql(localhost): Connect failed to database (dbispconfig): Can't connect to local MySQL server through socket '/var/run/mysql/mysql.sock' (2) - waiting for 5 seconds before retry
Nov 5 19:11:02 isp03p dovecot: auth-worker(1138): Error: mysql(localhost): Connect failed to database (dbispconfig): Can't connect to local MySQL server through socket '/var/run/mysql/mysql.sock' (2) - waiting for 5 seconds before retry
Nov 5 19:11:06 isp03p dovecot: auth-worker(1138): Error: mysql(localhost): Connect failed to database (dbispconfig): Can't connect to local MySQL server through socket '/var/run/mysql/mysql.sock' (2) - waiting for 25 seconds before retry
Nov 5 19:11:06 isp03p dovecot: auth-worker(1138): Error: mysql(localhost): Connect failed to database (dbispconfig): Can't connect to local MySQL server through socket '/var/run/mysql/mysql.sock' (2) - waiting for 25 seconds before retry
Nov 5 19:11:31 isp03p dovecot: auth-worker(1138): Error: mysql(localhost): Connect failed to database (dbispconfig): Can't connect to local MySQL server through socket '/var/run/mysql/mysql.sock' (2) - waiting for 125 seconds before retry
Nov 5 19:11:31 isp03p dovecot: auth-worker(1138): Error: mysql(localhost): Connect failed to database (dbispconfig): Can't connect to local MySQL server through socket '/var/run/mysql/mysql.sock' (2) - waiting for 125 seconds before retry
Nov 5 19:11:59 isp03p dovecot: auth: Error: auth worker: Aborted request: Lookup timed out
Nov 5 19:11:59 isp03p dovecot: auth-worker(1138): Error: sql(w2rich,82.113.106.147): Password query failed: Not connected to database
Nov 5 19:12:38 isp03p local[2017]: fatal: execvp /var/lib/mailman/mail/mailman: Permission denied
Nov 5 19:12:52 isp03p local[2026]: fatal: execvp /var/lib/mailman/mail/mailman: Permission denied
Nov 5 19:19:04 isp03p local[3393]: fatal: execvp /var/lib/mailman/mail/mailman: Permission denied

mail
Nov 5 19:28:37 isp03p postfix/error[4007]: E464E62CA6: to=<rue@woodies.de>, relay=none, delay=459, delays=459/0.01/0/0.01, dsn=4.3.0, status=deferred (mail transport unavailable)
Nov 5 19:28:37 isp03p postfix/qmgr[3307]: 2185762CAC: from=<ralf.bauerochse@hot-it-muc.de>, size=4170, nrcpt=1 (queue active)
Nov 5 19:28:37 isp03p postfix/error[4007]: 2185762CAC: to=<ralf.bauerochse@opentext.com>, relay=none, delay=327, delays=327/0/0/0.01, dsn=4.3.0, status=deferred (mail transport unavailable)
Nov 5 19:29:23 isp03p postfix/anvil[3436]: statistics: max connection rate 1/60s for (smtp:68.232.205.169) at Nov 5 19:19:22
Nov 5 19:29:23 isp03p postfix/anvil[3436]: statistics: max connection count 1 for (smtp:68.232.205.169) at Nov 5 19:19:22
Nov 5 19:29:23 isp03p postfix/anvil[3436]: statistics: max cache size 2 at Nov 5 19:20:05
Nov 5 19:29:25 isp03p dovecot: auth-worker(4111): mysql(localhost): Connected to database dbispconfig

falko 6th November 2012 12:30

Is this a physical server or a virtual machine?

fbsoft 29th January 2013 15:03

Hello i'm having the same problem,
From last night till now i have made only 1 modif in the server but now the dovecot server is not working anymore... i've followed to the letter the tutorial of perfect server 12.10 everything worked out just fine and now i get only for sending emails

Jan 29 15:57:07 www postfix/error[15923]: 2F24E5D1FA: to=<xxxxxx@gmail.com>, relay=none, delay=713, delays=653/60/0/0.02, dsn=4.3.0, status=deferred (mail transport unavailable)
What could be the problem pls help !!!


All times are GMT +2. The time now is 22:00.

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