Google Groups no longer supports new Usenet posts or subscriptions. Historical content remains viewable.
Dismiss

Re: [AMaViS-user] Duplicates emails with amavisd-new 2.4.4,

0 views
Skip to first unread message

Paul

unread,
Feb 8, 2007, 9:04:50 PM2/8/07
to
As a follow up here is the log file from a set of duplicates with the
same message id.

Can anyone make sense out of why 2 minutes later the same message is
sent again? I did not copy the full review of the 3rd and 4th message
as I hope this is enough detail to pinpoint the problem. I can dig up
more if needed.

Thanks again for any assistance provided on this perplexing problem.

Paul

--------------------------------------

Message #1

Feb 8 12:40:20 mailserver sm-mta[9380]: l18HeGVJ009380:
from=<sen...@somedomain.com>, size=4669, class=0, nrcpts=1,
msgid=<BAY117-F215B90EF5...@phx.gbl>, proto=ESMTP,
daemon=MTA, relay=bay0-omc3-s10.bay0.hotmail.com [65.54.246.210]
Feb 8 12:43:00 mailserver amavis[11122]: (l18HeGVJ009380)
AM.CL /var/amavis/amavis-milter-l18HeGVJ009380: <sen...@somedomain.com>
Feb 8 12:43:00 mailserver amavis[11122]: (l18HeGVJ009380) Checking:
I6INa7tOJWVw <sen...@somedomain.com> -> <reci...@test.com>
Feb 8 12:43:01 mailserver amavis[11122]: (l18HeGVJ009380) p001 1
Content-Type: text/plain, size: 3761 B, name:
Feb 8 12:43:05 mailserver amavis[11122]: (l18HeGVJ009380) Passed
CLEAN, [207.46.8.251] <sen...@somedomain.com> ->
<reci...@test.com>, Message-ID:
<BAY117-F215B90EF5...@phx.gbl>, mail_id: I6INa7tOJWVw,
Hits: 0.276, 5050 ms
Feb 8 12:43:05 mailserver amavis[11122]: (l18HeGVJ009380) mail
checking ended: version_server=2\nsetreply=250
2.5.0 Ok,%20id=l18HeGVJ009380,%20continue%20delivery\ninsheader=0
X-Virus-Scanned amavisd-new%20at%20test.com\nreturn_value=continue\nexit_code=0
Feb 8 12:43:05 mailserver amavis[11122]: (l18HeGVJ009380) TIMING
[total 5387 ms] - got data: 775 (14%)14,
check_init: 150 (3%)17, digest_hdr: 2 (0%)17, digest_body: 2 (0%)17,
gen_mail_id: 2 (0%)17, mkdir parts: 67 (1%)19,
mime_decode: 747 (14%)32, get-file-type1: 84 (2%)34, decompose_part:
21 (0%)34, parts_decode: 0 (0%)34,
check_header: 10 (0%)35, AV-scan-1: 92 (2%)36, spam-wb-list: 15
(0%)37, SA msg read: 7 (0%)37, SA parse: 13 (0%)37,
SA check: 3024 (56%)93, SA finish: 6 (0%)93, update_cache: 3 (0%)93,
decide_mail_destiny: 3 (0%)93, prepare-dsn: 9 (0%)93,
main_log_entry: 22 (0%)94, update_snmp: 3 (0%)94, unlink-1-files: 120
(2%)96, rmdir: 96 (2%)98, unlink-0-files: 0 (0%)98,
rmdir: 4 (0%)98, rundown: 108 (2%)100
Feb 8 12:43:29 mailserver sm-mta[11191]: l18HeGVJ009380: to="|IFS='
' && exec /usr/local/bin/procmail -f- || exit 75 #paulmail",
ctladdr=<reci...@test.com> (1028/1028), delay=00:03:09,
xdelay=00:00:24, mailer=prog, pri=34967, dsn=2.0.0, stat=Sent

Message #2 - Exact Duplicate

Feb 8 12:42:16 mailserver sm-mta[10630]: l18HgDSX010630:
from=<sen...@somedomain.com>, size=4669, class=0, nrcpts=1,
msgid=<BAY117-F215B90EF5...@phx.gbl>, proto=ESMTP,
daemon=MTA, relay=bay0-omc3-s10.bay0.hotmail.com [65.54.246.210]\
Feb 8 12:44:39 mailserver amavis[11981]: (l18HgDSX010630)
AM.CL /var/amavis/amavis-milter-l18HgDSX010630: <sen...@somedomain.com>
Feb 8 12:44:39 mailserver amavis[11981]: (l18HgDSX010630) Checking:
BmJQ5OaOiN3H <sen...@somedomain.com> -> <reci...@test.com>
Feb 8 12:44:39 mailserver amavis[11981]: (l18HgDSX010630) cached
bd86d7118a51d2b39ae747d69aa6db38 from <sen...@somedomain.com>
(1,1)
Feb 8 12:44:40 mailserver amavis[11981]: (l18HgDSX010630) p001 1
Content-Type: text/plain, size: 3761 B, name:
Feb 8 12:44:40 mailserver amavis[11981]: (l18HgDSX010630) Passed
CLEAN, [207.46.8.251] <sen...@somedomain.com> ->
<reci...@test.com>, Message-ID:
<BAY117-F215B90EF5...@phx.gbl>, mail_id: BmJQ5OaOiN3H,
Hits: 0.276, 901 ms
Feb 8 12:44:40 mailserver amavis[11981]: (l18HgDSX010630) mail
checking ended: version_server=2\nsetreply=250 2.5.0
Ok,%20id=l18HgDSX010630,%20continue%20delivery\ninsheader=0 X-Virus-Scanned
amavisd-new%20at%20test.com\nreturn_value=continue\nexit_code=0
Feb 8 12:44:40 mailserver amavis[11981]: (l18HgDSX010630) TIMING
[total 1039 ms] - got data: 46 (4%)4,
check_init: 45 (4%)9, digest_hdr: 1 (0%)9, digest_body: 2 (0%)9,
gen_mail_id: 1 (0%)9, mkdir parts: 74 (7%)16,
mime_decode: 297 (29%)45, get-file-type1: 99 (9%)55, decompose_part:
5 (1%)55, parts_decode: 0 (0%)55,
check_header: 242 (23%)78, spam-wb-list: 31 (3%)81, update_cache: 5
(1%)82, decide_mail_destiny: 7 (1%)82,
prepare-dsn: 19 (2%)84, main_log_entry: 29 (3%)87, update_snmp: 3
(0%)87, unlink-1-files: 42 (4%)91, rmdir: 16 (2%)93,
unlink-0-files: 0 (0%)93, rmdir: 2 (0%)93, rundown: 71 (7%)100
Feb 8 12:44:51 mailserver sm-mta[12171]: l18HgDSX010630: to="|IFS='
' && exec /usr/local/bin/procmail -f- || exit 75 #paulmail",
ctladdr=<reci...@test.com> (1028/1028), delay=00:02:37,
xdelay=00:00:10, mailer=prog, pri=34967, dsn=2.0.0, stat=Sent

Message #3 - Exact Duplicate

Feb 8 12:44:43 mailserver sm-mta[12133]: l18HiheR012133:
from=<sen...@somedomain.com>, size=4669, class=0, nrcpts=1,
msgid=<BAY117-F215B90EF5...@phx.gbl>, proto=ESMTP,
daemon=MTA, relay=bay0-omc3-s10.bay0.hotmail.com [65.54.246.210]
Feb 8 12:47:38 mailserver amavis[13720]: (l18HiheR012133) Checking:
UxN-0Ehioefv <sen...@somedomain.com> -> <reci...@test.com>
Feb 8 12:47:38 mailserver amavis[13720]: (l18HiheR012133) Cached
virus check expired, TTL = 180 s
Feb 8 12:47:38 mailserver amavis[13720]: (l18HiheR012133) cached
bd86d7118a51d2b39ae747d69aa6db38 from <sen...@somedomain.com> (0,1)
At 12:12 PM 08/02/2007, you wrote:


>I have having a real tough time tracking down a duplicate email issue
>with amavisd-new 2.4.4,1 and sendmail. It always seems to come from
>Hotmail or a few other providers. During busy times the emails get
>resent many times.


-------------------------------------------------------------------------
Using Tomcat but need to do more? Need to support web services, security?
Get stuff done quickly with pre-integrated technology to make your job easier.
Download IBM WebSphere Application Server v.1.0.1 based on Apache Geronimo
http://sel.as-us.falkag.net/sel?cmd=lnk&kid=120709&bid=263057&dat=121642
_______________________________________________
AMaViS-user mailing list
AMaVi...@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/amavis-user
AMaViS-FAQ:http://www.amavis.org/amavis-faq.php3
AMaViS-HowTos:http://www.amavis.org/howto/

Mark Martinec

unread,
Feb 8, 2007, 9:05:19 PM2/8/07
to
Paul,

> Can anyone make sense out of why 2 minutes later the same
> message is sent again?

Looks like [65.54.246.210] did not receive a confirmation
of reception from your sendmail, which was issued 3 minutes
after start of reception. Either hotmail.com was unwilling
to wait for three minutes and tempfailed earlier, or the
SMTP session was somehow broken (firewall stateful session
timed out), or there were really three same-contents messages
to be delivered (unlikely).

My guess is that hotmail.com times out after 2 minutes and retries.
Although 2 minutes violates rfc2821, the issue is aggraved
by using a pre-queue heavy-weight content filtering.
A dual-MTA setup (= after-queue content filtering) avoids such problems.

Capture a tcp session (tcpdump -w 0.log -s 0 'host 65.54.246.210')
and you will know for sure (examine the file later by wireshark).

Mark

0 new messages