On December 23, 2010 10:48:07 am Noel Jones wrote: > On 12/23/2010 11:33 AM, Ray wrote: > > I believe that the message is being accepted by Postfix due to lines like > > the following in the logs > > > > Dec 23 10:12:20 wserver amavis[15273]: (15273-12) Passed CLEAN, > > [70.65.***.***] [70.65.***.***]<r...@stilltech.net> -> > > <******...@shaw.ca>, Message-ID:<201012231011.54704....@stilltech.net>, > > mail_id: MS2XU3vqlzc0, Hits: 0.013, size: 557, queued_as: 6CF0C1B173C, > > 14673 ms > > (redacted IP address is the machine I'm sending email from. Redacted > > email is on the local cabelco mail server.) > > Wow, nearly 15 seconds to scan a 557 byte message. If all > your amavis scans are that slow or slower you might want some > help from the amavis-users list. > > Anyway, on the postfix-users list we prefer to see postfix > logging. > > > I'm not 100% sure the problem is on the remote server, that's why I would > > like to trace the communication between my server and the remote server. > > Thanks again, > > Ray > > Start with showing us the one-line entry postfix/smtp makes > when sending to the remote server, and we'll go on from there. > > > > -- Noel Jones
Hello all, thank you for your quick response. All the gory details that you asked for follow. I have provided the output of postconf -n, and all the log details for my last message to this list as an example. But before we go that far, I'm wondering if my question was understood. My question is " is there a way to see in detail, through logging or simulation, what is happening when my mail server relays or attempts to relay, a message from me to an outside server that is not under my control, and for which I will never get logs. (Think Gmail). While I appreciate the willingness of the list members to help out, the exact problem was only given as justification for the real question. Thanks Ray Dec 23 10:33:22 wserver postfix/smtpd[16875]: 5B80F1B173C: client=S0106001c10f5c6f7.lb.shawcable.net[70.65.240.122], sasl_method=PLAIN, sasl_username=...@stilltech.net Dec 23 10:33:22 wserver postfix/cleanup[16730]: 5B80F1B173C: message- id=<201012231033.19447....@stilltech.net> Dec 23 10:33:22 wserver postfix/qmgr[44344]: 5B80F1B173C: from=<r...@stilltech.net>, size=2565, nrcpt=1 (queue active) Dec 23 10:33:22 wserver amavis[16134]: (16134-09) ESMTP::10024 /var/amavis/tmp/amavis-20101223T101352-16134: <r...@stilltech.net> -> <postfix- us...@postfix.org> SIZE=2565 Received: from mail.geekdelivery.com ([127.0.0.1]) by localhost (wserver.geekdelivery.com [127.0.0.1]) (amavisd-new, port 10024) with ESMTP for <postfix-users@postfix.org>; Thu, 23 Dec 2010 10:33:22 -0700 (MST) Dec 23 10:33:22 wserver amavis[16134]: (16134-09) smtp connection cache, dt: 72.0, state: 0 Dec 23 10:33:22 wserver amavis[16134]: (16134-09) Checking: RAV2IYSSfcjM [70.65.240.122] <r...@stilltech.net> -> <postfix-users@postfix.org> Dec 23 10:33:22 wserver amavis[16134]: (16134-09) p001 1 Content-Type: text/plain, size: 1781 B, name: Dec 23 10:33:27 wserver postfix/smtpd[16875]: disconnect from S0106001c10f5c6f7.lb.shawcable.net[70.65.240.122] Dec 23 10:33:33 wserver postfix/scache[16684]: statistics: start interval Dec 23 10:30:16 Dec 23 10:33:33 wserver postfix/scache[16684]: statistics: domain lookup hits=2 miss=2 success=50% Dec 23 10:33:33 wserver postfix/scache[16684]: statistics: address lookup hits=0 miss=2 success=0% Dec 23 10:33:33 wserver postfix/scache[16684]: statistics: max simultaneous domains=1 addresses=1 connection=1 Dec 23 10:33:37 wserver postfix/smtpd[16682]: connect from localhost[127.0.0.1] Dec 23 10:33:37 wserver postfix/trivial-rewrite[16881]: warning: database /usr/local/etc/postfix/transport.db is older than source file /usr/local/etc/postfix/transport Dec 23 10:33:37 wserver postfix/smtpd[16682]: A12E71B173F: client=localhost[127.0.0.1] Dec 23 10:33:37 wserver postfix/cleanup[16730]: A12E71B173F: message- id=<201012231033.19447....@stilltech.net> Dec 23 10:33:37 wserver postfix/smtpd[16682]: disconnect from localhost[127.0.0.1] Dec 23 10:33:37 wserver postfix/qmgr[44344]: A12E71B173F: from=<r...@stilltech.net>, size=2985, nrcpt=1 (queue active) Dec 23 10:33:37 wserver amavis[16134]: (16134-09) FWD via SMTP: <r...@stilltech.net> -> <postfix-users@postfix.org>,BODY=7BIT 250 2.0.0 Ok, id=16134-09, from MTA([127.0.0.1]:10025): 250 2.0.0 Ok: queued as A12E71B173F Dec 23 10:33:37 wserver amavis[16134]: (16134-09) Passed CLEAN, [70.65.240.122] [70.65.240.122] <r...@stilltech.net> -> <postfix- us...@postfix.org>, Message-ID: <201012231033.19447....@stilltech.net>, mail_id: RAV2IYSSfcjM, Hits: 0.038, size: 2565, queued_as: A12E71B173F, 15209 ms Dec 23 10:33:37 wserver postfix/smtp[16665]: 5B80F1B173C: to=<postfix- us...@postfix.org>, relay=127.0.0.1[127.0.0.1]:10024, delay=15, delays=0.1/0/0.01/15, dsn=2.0.0, status=sent (250 2.0.0 Ok, id=16134-09, from MTA([127.0.0.1]:10025): 250 2.0.0 Ok: queued as A12E71B173F) Dec 23 10:33:37 wserver postfix/qmgr[44344]: 5B80F1B173C: removed Dec 23 10:33:37 wserver amavis[16134]: (16134-09) TIMING [total 15222 ms] - SMTP greeting: 3 (0%)0, SMTP EHLO: 2 (0%)0, SMTP pre-MAIL: 3 (0%)0, lookup_sql: 6 (0%)0, SMTP pre-DATA-flush: 2 (0%)0, SMTP DATA: 91 (1%)1, check_init: 1 (0%)1, digest_hdr: 1 (0%)1, digest_body: 1 (0%)1, sql-enter: 8 (0%)1, mime_decode: 12 (0%)1, get-file-type1: 25 (0%)1, decompose_part: 2 (0%)1, parts_decode: 0 (0%)1, check_header: 3 (0%)1, spam-wb-list: 6 (0%)1, SA parse: 4 (0%)1, SA check: 14969 (98%)99, update_cache: 11 (0%)100, decide_mail_destiny: 3 (0%)100, fwd-connect: 10 (0%)100, fwd-mail-pip: 28 (0%)100, fwd-rcpt-pip: 0 (0%)100, fwd-data-chkpnt: 0 (0%)100, write-header: 1 (0%)100, fwd-data-contents: 0 (0%)100, fwd-end-chkpnt: 6 (0%)100, prepare-dsn: 2 (0%)100, main_log_entry: 12 (0%)100, sql-update: 7 (0%)100, update_snmp: 2 (0%)100, SMTP pre-response: 1 (0%)100, SMTP response: 1 (0%)100, unlink-1- files: 1 (0%)100, rundown: 1 (0%)100 # postconf -n alias_database = hash:/etc/mail/aliases alias_maps = hash:/etc/mail/aliases bounce_template_file = /usr/local/etc/postfix/bounce.cf broken_sasl_auth_clients = yes command_directory = /usr/local/sbin config_directory = /usr/local/etc/postfix content_filter = amavisfeed:[127.0.0.1]:10024 daemon_directory = /usr/local/libexec/postfix debug_peer_level = 2 delay_warning_time = 4h disable_vrfy_command = yes html_directory = no inet_interfaces = all mail_owner = postfix mailbox_size_limit = 0 mailq_path = /usr/local/bin/mailq manpage_directory = /usr/local/man message_size_limit = 250000000 myhostname = mail.geekdelivery.com mynetworks = 192.168.0.0/23, 127.0.0.0/8 mynetworks_style = host newaliases_path = /usr/local/bin/newaliases queue_directory = /var/spool/postfix readme_directory = no sample_directory = /usr/local/etc/postfix sendmail_path = /usr/local/sbin/sendmail setgid_group = maildrop show_user_unknown_table_name = no smtpd_banner = $myhostname ESMTP $mail_name smtpd_recipient_restrictions = permit_mynetworks, permit_sasl_authenticated, reject_unauth_destination smtpd_sasl_auth_enable = yes smtpd_sasl_path = /var/spool/postfix/private/auth smtpd_sasl_type = dovecot smtpd_sender_restrictions = permit_sasl_authenticated, permit_mynetworks, reject_non_fqdn_sender, reject_sender_login_mismatch soft_bounce = yes transport_maps = hash:/usr/local/etc/postfix/transport unknown_local_recipient_reject_code = 550 virtual_alias_maps = proxy:mysql:/usr/local/etc/postfix/sql/virtual_alias_maps.cf proxy:mysql:/usr/local/etc/postfix/sql/virtual_email2email.cf proxy:mysql:/usr/local/etc/postfix/sql/catchall_alias_maps.cf virtual_gid_maps = proxy:mysql:/usr/local/etc/postfix/sql/virtual_gid_maps.cf virtual_mailbox_base = /usr/local/mail virtual_mailbox_domains = proxy:mysql:/usr/local/etc/postfix/sql/virtual_mailbox_domains.cf virtual_mailbox_limit = 1000000000 virtual_mailbox_maps = proxy:mysql:/usr/local/etc/postfix/sql/virtual_mailbox_recipients.cf virtual_transport = virtual virtual_uid_maps = proxy:mysql:/usr/local/etc/postfix/sql/virtual_uid_maps.cf
