Mailscanner generated duplicate message.

[Mark Sapiro]

Glenn Steen wrote:

>On 23/12/2007, Mark Sapiro <mark at msapiro.net> wrote:
>> CentOS 5
>> Mailscanner 4.65.3
>> Postfix 2.3.3
>>
>> This is a fairly new server install, running only a few weeks.
>>
>> Two days ago I received duplicate logwatch messages from the system.
>> The duplication appears to be in Mailscanner. The headers of the two
>> messages are identical and are:
>>
>> Return-Path: <root at sbh16.songbird.com>
>> X-Original-To: root
>> Delivered-To: root at sbh16.songbird.com
>> Received: by sbh16.songbird.com (Postfix, from userid 0)
>>         id 6325C6900A9; Fri, 21 Dec 2007 04:03:47 -0800 (PST)
>> To: root at sbh16.songbird.com
>> From: logwatch at sbh16.songbird.com
>> Subject: Logwatch for sbh16.songbird.com (Linux)
>> MIME-Version: 1.0
>> Content-Transfer-Encoding: 7bit
>> Content-Type: text/plain; charset="iso-8859-1"
>> Message-Id: <20071221120349.6325C6900A9 at sbh16.songbird.com>
>> Date: Fri, 21 Dec 2007 04:02:47 -0800 (PST)
>>
>>
>> The relevant maillog entries are:
>>
>> Dec 21 04:03:49 sbh16 postfix/pickup[2954]: 6325C6900A9: uid=0
>> from=<root>
>> Dec 21 04:03:49 sbh16 postfix/cleanup[3448]: 6325C6900A9: hold: header
>> Received:
>>  by sbh16.songbird.com (Postfix, from userid 0)??id 6325C6900A9; Fri,
>> 21 Dec 2007 04:03:47 -0800 (PST) from local;
>> from=<root at sbh16.songbird.com>
>> Dec 21 04:03:49 sbh16 postfix/cleanup[3448]: 6325C6900A9:
>> message-id=<20071221120349.6325C6900A9 at sbh16.songbird.com>
>> Dec 21 04:03:54 sbh16 MailScanner[2858]: New Batch: Scanning 1
>> messages, 43244 bytes
>> Dec 21 04:03:54 sbh16 MailScanner[2858]: Requeue: 6325C6900A9.B64EF to
>> 7903D6900A4
>> Dec 21 04:03:54 sbh16 postfix/qmgr[8765]: 7903D6900A4:
>> from=<root at sbh16.songbird.com>,  size=43045, nrcpt=1 (queue active)
>> Dec 21 04:03:54 sbh16 MailScanner[2858]: Unscanned: Delivered 1 messages
>> Dec 21 04:03:54 sbh16 MailScanner[2858]: Virus and Content Scanning:
>> Starting
>> Dec 21 04:03:54 sbh16 MailScanner[2945]: New Batch: Scanning 1
>> messages, 0 bytes
>> Dec 21 04:03:56 sbh16 postfix/local[3483]: 7903D6900A4:
>> to=<mark at sbh16.songbird.com>,  orig_to=<root>, relay=local, delay=70,
>> delays=67/0.02/0/2.5, dsn=2.0.0, status=sent  (delivered to mailbox)
>> Dec 21 04:03:57 sbh16 postfix/qmgr[8765]: 7903D6900A4: removed
>> Dec 21 04:03:57 sbh16 MailScanner[2945]: Expired 2 records from the
>> SpamAssassin cache
>> Dec 21 04:03:57 sbh16 MailScanner[2945]: Requeue: 6325C6900A9.61B5E to
>> 1E7946900A4
>> Dec 21 04:03:57 sbh16 postfix/qmgr[8765]: 1E7946900A4:
>> from=<root at sbh16.songbird.com>,  size=43045, nrcpt=1 (queue active)
>> Dec 21 04:03:57 sbh16 MailScanner[2945]: Unscanned: Delivered 1 messages
>> Dec 21 04:03:57 sbh16 MailScanner[2945]: Virus and Content Scanning:
>> Starting
>> Dec 21 04:03:57 sbh16 postfix/local[3483]: 1E7946900A4:
>> to=<mark at sbh16.songbird.com>,  orig_to=<root>, relay=local, delay=71,
>> delays=71/0/0/0.01, dsn=2.0.0, status=sent (delivered  to mailbox)
>> Dec 21 04:03:57 sbh16 postfix/qmgr[8765]: 1E7946900A4: removed

<snip>
>>
>Um, I'm not entirely sure these are errors... Have you "massaged" the
>logs in any way (excluding things you don't think relevant) in any
>way?


Yes, I removed one entry from the above sequence having to do with an
unrelated message

Dec 21 04:03:50 sbh16 postfix/smtpd[3017]: disconnect from
dsl-207-112-4-156.tor.primus.ca[207.112.4.156]

The two prior entries for that message were

Dec 21 04:03:47 sbh16 postfix/smtpd[3017]: connect from
dsl-207-112-4-156.tor.primus.ca[207.112.4.156]
Dec 21 04:03:49 sbh16 postfix/smtpd[3017]: NOQUEUE: reject: RCPT from
dsl-207-112-4-156.tor.primus.ca[207.112.4.156]: 550 5.1.1
<st at grizz.org>: Recipient address rejected: User unknown in virtual
alias table; from=<honeymoonersd4 at collectablerecords.net>
to=<st at grizz.org> proto=ESMTP helo=<dsl-207-112-4-156.tor.primus.ca>

>Since PF can&will reuse queue IDs, that isn't much to go on... And one
>wonders if there might've been a quick succession of
>message-introduction (same message twice)...?


The previous introduction of a message from root was 24 hours earlier

Dec 20 04:03:18 sbh16 postfix/cleanup[7992]: 463B46900A4: hold: header
Received: by sbh16.songbird.com (Postfix, from userid 0)??id
463B46900A4; Thu, 20 Dec 2007 04:03:17 -0800 (PST) from local;
from=<root at sbh16.songbird.com>.

-- 
Mark Sapiro <mark at msapiro.net>        The highway is for gamblers,
San Francisco Bay Area, California    better use your sense - B. Dylan