mail transport unavailable

Discussion in 'Installation/Configuration' started by ralfba, Nov 1, 2012.

  1. ralfba

    ralfba New Member

    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
     
  2. falko

    falko Super Moderator ISPConfig Developer

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

    ralfba New Member

    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=<[email protected]>, 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=<[email protected]>, 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([email protected]): 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]
     
  4. ralfba

    ralfba New Member

    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
     
  5. ralfba

    ralfba New Member

    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
     
  6. till

    till Super Moderator Staff Member ISPConfig Developer

    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.
     
  7. ralfba

    ralfba New Member

    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
     
  8. ralfba

    ralfba New Member

    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=<[email protected]>, 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=<[email protected]>, size=4170, nrcpt=1 (queue active)
    Nov 5 19:28:37 isp03p postfix/error[4007]: 2185762CAC: to=<[email protected]>, 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
     
  9. falko

    falko Super Moderator ISPConfig Developer

    Is this a physical server or a virtual machine?
     
  10. fbsoft

    fbsoft New Member

    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=<[email protected]>, 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 !!!
     
  11. till

    till Super Moderator Staff Member ISPConfig Developer

    Please post the content of the file /etc/postfix/master.cf
     

Share This Page