On Thu, Oct 14, 2010 at 1:08 PM, Alberto Lepe <d...@alepe.com> wrote:
> On Thu, Oct 14, 2010 at 12:38 PM, captain_claw <ryanc...@gmail.com> wrote: > >> >> >> On Thu, Oct 14, 2010 at 10:40 AM, Matt Hayes <domin...@slackadelic.com>wrote: >> >>> On 10/13/2010 10:17 PM, Alberto Lepe wrote: >>> >>>> Yes Matt, I agree with you. >>>> >>>> However, for some reason a customer is complaining that some people are >>>> receiving several copies (in one case up to 15 copies) with exactly the >>>> same content, when he/she sent just one mail. >>>> >>>> I thought at the beginning it may be a problem with his mail client but >>>> after checking the logs I didn't see anything strange but those repeated >>>> lines. >>>> >>>> I now understand that those repeated logs are normal as the filter is >>>> re-injecting them into postfix. The only irregular thing I saw is that >>>> his/her mails are being marked as SPAM (but not rejected), which then >>>> are sent to quarantine. As far as I know, I have to manually "release" >>>> them from quarantine in order to be send, right? >>>> For now, I use those emails in quarantine to adjust the values of >>>> spamassassin until I can reach some comfortable setup in order to start >>>> blocking emails. >>>> >>>> Is there any other way I could analyze the "duplicated mails" problem? >>>> >>>> Thanks again. >>>> >>> >>> >>> What email client is the client using? >>> >>> -Matt >>> >> >> If you find that the problem is only on that user, I think you have to >> check his/her email client. if it's M$ outlook/express kindly check the >> pst/dbx file size of the user. cases that the MUA reaches its max size of >> 2gb (for M$ outlook 2003 below) the tendency is MUA can't write additional >> entry to pst/dbx and thus it remains to outbox. So if the users tries to >> send/receive the MUA re-send it to the recipient co'z the MUA assumed that >> there is still mail seating on the outbox. However if everybody is >> experiencing this problem then you have investigate more on your logs. >> >> -Ryan >> >> >> > The email client is M$ Outlook. I don't have the exact version yet (Is > there a way to get that from logs?). However, I don't think their pst/dbx > file is that large as the email account is few months old, and according to > the logs, this user have sent 605 emails with a total size of 567MB. (very > interesting though... I will take note of that. Thank you Ryan!) > > Actually analyzing those logs to get the total size, helped me to found > something I didn't notice before (which is repeated several times in that > specific account (I haven't check others)): > > A fragment of the summary of sent mail: > > ... > Oct 11 16:55:27 mail postfix/qmgr[5276]: 4A48F1CD09: from=< > nak...@example.com>, size=4214332, nrcpt=1 (queue active) > Oct 11 16:55:29 mail postfix/qmgr[5276]: 8A58A1CD0B: from=< > nak...@example.com>, size=4214840, nrcpt=1 (queue active) > Oct 11 16:58:22 mail postfix/qmgr[5276]: D2C821CD09: from=< > nak...@example.com>, size=4214332, nrcpt=1 (queue active) > Oct 11 16:58:23 mail postfix/qmgr[5276]: 4CD5B1CD0B: from=< > nak...@example.com>, size=4214840, nrcpt=1 (queue active) > Oct 11 17:01:09 mail postfix/qmgr[5276]: 99ABF1CD09: from=< > nak...@example.com>, size=4214332, nrcpt=1 (queue active) > Oct 11 17:01:11 mail postfix/qmgr[5276]: B02BC1CD0B: from=< > nak...@example.com>, size=4214840, nrcpt=1 (queue active) > Oct 11 17:03:56 mail postfix/qmgr[5276]: 3272A1CD09: from=< > nak...@example.com>, size=4214332, nrcpt=1 (queue active) > Oct 11 17:03:56 mail postfix/qmgr[5276]: 6E4671CD0B: from=< > nak...@example.com>, size=4214840, nrcpt=1 (queue active) > Oct 11 17:06:42 mail postfix/qmgr[5276]: B80AB1CD09: from=< > nak...@example.com>, size=4214332, nrcpt=1 (queue active) > Oct 11 17:06:45 mail postfix/qmgr[5276]: 329751CD0B: from=< > nak...@example.com>, size=4214840, nrcpt=1 (queue active) > Oct 11 17:09:29 mail postfix/qmgr[5276]: AC4FC1CD09: from=< > nak...@example.com>, size=4214332, nrcpt=1 (queue active) > Oct 11 17:09:30 mail postfix/qmgr[5276]: 2C09A1CD0B: from=< > nak...@example.com>, size=4214840, nrcpt=1 (queue active) > Oct 11 17:12:16 mail postfix/qmgr[5276]: AC4B31CD09: from=< > nak...@example.com>, size=4214332, nrcpt=1 (queue active) > Oct 11 17:12:18 mail postfix/qmgr[5276]: C29611CD0B: from=< > nak...@example.com>, size=4214840, nrcpt=1 (queue active) > Oct 11 17:15:03 mail postfix/qmgr[5276]: 493771CD09: from=< > nak...@example.com>, size=4214332, nrcpt=1 (queue active) > Oct 11 17:15:03 mail postfix/qmgr[5276]: B183E1CD0E: from=< > nak...@example.com>, size=4214840, nrcpt=1 (queue active) > Oct 11 17:17:50 mail postfix/qmgr[5276]: 0082D1CD09: from=< > nak...@example.com>, size=4214332, nrcpt=1 (queue active) > Oct 11 17:17:52 mail postfix/qmgr[5276]: 5BB201CD0B: from=< > nak...@example.com>, size=4214840, nrcpt=1 (queue active) > Oct 11 17:20:36 mail postfix/qmgr[5276]: CA2A11CD09: from=< > nak...@example.com>, size=4214332, nrcpt=1 (queue active) > Oct 11 17:20:37 mail postfix/qmgr[5276]: 3A1541CD0B: from=< > nak...@example.com>, size=4214840, nrcpt=1 (queue active) > Oct 11 17:23:23 mail postfix/qmgr[5276]: 82D0C1CD0B: from=< > nak...@example.com>, size=4214332, nrcpt=1 (queue active) > Oct 11 17:23:25 mail postfix/qmgr[5276]: A1F911CD09: from=< > nak...@example.com>, size=4214840, nrcpt=1 (queue active) > Oct 11 17:26:10 mail postfix/qmgr[5276]: 1748E1CD09: from=< > nak...@example.com>, size=4214332, nrcpt=1 (queue active) > Oct 11 17:26:10 mail postfix/qmgr[5276]: 62E551CD0B: from=< > nak...@example.com>, size=4214840, nrcpt=1 (queue active) > ... > > Interesting: The same size for different emails was sent with nrcpt=1. > > I picked some of them to have a closer look and I found that those emails > were sent to the same mailbox: yuui...@host.co.jp, which make me think > that the problem should be the client (as the same client [p2147- ... ] is > listed everytime). Right? > > Here are the detailed logs (Those with size=4214840 were the re-injected > ones): > > ------------------------------------------------------------------------------------------------------ > Oct 11 16:53:41 mail postfix/smtpd[3672]: 4A48F1CD09: client= > p2147-ipad21xsajima.ne.jp[20.0.0.147] > Oct 11 16:53:41 mail postfix/cleanup[3675]: 4A48F1CD09: > message-id=<00c501cb6919$3fbd98c0$18011...@nagamatsu> > Oct 11 16:55:27 mail postfix/qmgr[5276]: 4A48F1CD09: from=< > nak...@example.com>, size=4214332, nrcpt=1 (queue active) > Oct 11 16:55:29 mail postfix/smtp[3686]: 4A48F1CD09: to=< > yuui...@host.co.jp>, relay=127.0.0.1[127.0.0.1]:10024, delay=108, > delays=106/0/0/2.3, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as > 8A58A1CD0B) > Oct 11 16:55:29 mail postfix/qmgr[5276]: 4A48F1CD09: removed > > ------------------------------------------------------------------------------------------------------ > Oct 11 16:55:29 mail postfix/smtpd[3694]: 8A58A1CD0B: > client=localhost[127.0.0.1] > Oct 11 16:55:29 mail postfix/cleanup[3685]: 8A58A1CD0B: > message-id=<00c501cb6919$3fbd98c0$18011...@nagamatsu> > Oct 11 16:55:29 mail postfix/qmgr[5276]: 8A58A1CD0B: from=< > nak...@example.com>, size=4214840, nrcpt=1 (queue active) > Oct 11 16:55:29 mail amavis[29234]: (29234-11) Passed CLEAN, [20.0.0.147] > [20.0.0.147] <nak...@example.com> -> <yuui...@host.co.jp>, Message-ID: > <00c501cb6919$3fbd98c0$18011...@nagamatsu>, mail_id: s6KqbwCR9IiA, Hits: > -, size: 4214 > Oct 11 16:56:08 mail postfix/smtp[3695]: 8A58A1CD0B: to=< > yuui...@host.co.jp>, relay=mail.global.hostmail.com[100.199.180.150]:25, > delay=39, delays=0.11/0/1.2/38, dsn=2.6.0, status=sent (250 2.6.0 > <00c501cb6919$3fbd98c0$18011...@nag > Oct 11 16:56:08 mail postfix/qmgr[5276]: 8A58A1CD0B: removed > > ------------------------------------------------------------------------------------------------------ > Oct 11 16:56:36 mail postfix/smtpd[3672]: D2C821CD09: client= > p2147-ipad21xsajima.ne.jp[20.0.0.147] > Oct 11 16:56:36 mail postfix/cleanup[3675]: D2C821CD09: > message-id=<00c601cb6919$a8626270$18011...@nagamatsu> > Oct 11 16:58:22 mail postfix/qmgr[5276]: D2C821CD09: from=< > nak...@example.com>, size=4214332, nrcpt=1 (queue active) > Oct 11 16:58:23 mail postfix/smtp[4289]: D2C821CD09: to=< > yuui...@host.co.jp>, relay=127.0.0.1[127.0.0.1]:10024, delay=107, > delays=106/0/0/0.51, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as > 4CD5B1CD0B) > Oct 11 16:58:23 mail postfix/qmgr[5276]: D2C821CD09: removed > > ------------------------------------------------------------------------------------------------------ > Oct 11 16:58:23 mail postfix/smtpd[4299]: 4CD5B1CD0B: > client=localhost[127.0.0.1] > Oct 11 16:58:23 mail postfix/cleanup[3675]: 4CD5B1CD0B: > message-id=<00c601cb6919$a8626270$18011...@nagamatsu> > Oct 11 16:58:23 mail postfix/qmgr[5276]: 4CD5B1CD0B: from=< > nak...@example.com>, size=4214840, nrcpt=1 (queue active) > Oct 11 16:58:23 mail amavis[30396]: (30396-12) Passed CLEAN, [20.0.0.147] > [20.0.0.147] <nak...@example.com> -> <yuui...@host.co.jp>, Message-ID: > <00c601cb6919$a8626270$18011...@nagamatsu>, mail_id: Ty33aevnDtOr, Hits: > -, size: 4214 > Oct 11 16:58:49 mail postfix/smtp[4301]: 4CD5B1CD0B: to=< > yuui...@host.co.jp>, relay=mail.global.hostmail.com[200.32.180.22]:25, > delay=26, delays=0.12/0/0.74/25, dsn=2.6.0, status=sent (250 2.6.0 > <00c601cb6919$a8626270$18011...@naga > Oct 11 16:58:49 mail postfix/qmgr[5276]: 4CD5B1CD0B: removed > > ------------------------------------------------------------------------------------------------------ > Oct 11 17:24:24 mail postfix/smtpd[6935]: 1748E1CD09: client= > p2147-ipad21xsajima.ne.jp[20.0.0.147] > Oct 11 17:24:24 mail postfix/cleanup[3675]: 1748E1CD09: > message-id=<00d001cb691d$8a221a90$18011...@nagamatsu> > Oct 11 17:26:10 mail postfix/qmgr[5276]: 1748E1CD09: from=< > nak...@example.com>, size=4214332, nrcpt=1 (queue active) > Oct 11 17:26:10 mail postfix/smtp[6902]: 1748E1CD09: to=< > yuui...@host.co.jp>, relay=127.0.0.1[127.0.0.1]:10024, delay=106, > delays=106/0/0/0.53, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as > 62E551CD0B) > Oct 11 17:26:10 mail postfix/qmgr[5276]: 1748E1CD09: removed > > ------------------------------------------------------------------------------------------------------ > Oct 11 17:26:10 mail postfix/smtpd[6910]: 62E551CD0B: > client=localhost[127.0.0.1] > Oct 11 17:26:10 mail postfix/cleanup[6937]: 62E551CD0B: > message-id=<00d001cb691d$8a221a90$18011...@nagamatsu> > Oct 11 17:26:10 mail postfix/qmgr[5276]: 62E551CD0B: from=< > nak...@example.com>, size=4214840, nrcpt=1 (queue active) > Oct 11 17:26:10 mail amavis[7065]: (07065-02) Passed CLEAN, [20.0.0.147] > [20.0.0.147] <nak...@example.com> -> <yuui...@host.co.jp>, Message-ID: > <00d001cb691d$8a221a90$18011...@nagamatsu>, mail_id: IF+6lje-GaDe, Hits: > -, size: 42143 > Oct 11 17:26:33 mail postfix/smtp[7426]: 62E551CD0B: to=< > yuui...@host.co.jp>, relay=mail.global.hostmail.com[300.55.88.22]:25, > delay=23, delays=0.13/0/0.69/22, dsn=2.6.0, status=sent (250 2.6.0 > <00d001cb691d$8a221a90$18011...@nagam > Oct 11 17:26:33 mail postfix/qmgr[5276]: 62E551CD0B: removed > Are those users having problem is in remote office/site? I think even the user's MUA is new you can't tell how the users sent/receive mails. Sent Items (which is 567MB) is only part of the user's pst file (how about the inbox/deleted or other folders the user creates). you can't even know how may email he receives per day which also adds to the size of the pst file. If you want to know about the version of M$ their using then look on the internet headers of an email from the problematics user. (somethig like X-Mailer: Microsoft Outlook Express 6.00.2900.3598/X-Mailer: Microsoft Outlook, Build 10.0.6626). Oct 11 17:26:10 mail postfix/qmgr[5276]: 1748E1CD09: from=< nak...@example.com>, size=4214332, nrcpt=1 (queue active) Oct 11 17:26:10 mail postfix/qmgr[5276]: 62E551CD0B: from=< nak...@example.com>, size=4214840, nrcpt=1 (queue active) ============================================================== Oct 11 17:24:24 mail postfix/smtpd[6935]: 1748E1CD09: client= p2147-ipad21xsajima.ne.jp[20.0.0.147] Oct 11 17:24:24 mail postfix/cleanup[3675]: 1748E1CD09: message-id=<00d001cb691d$8a221a90$18011...@nagamatsu> Oct 11 17:26:10 mail postfix/qmgr[5276]: 1748E1CD09: from=< nak...@example.com>, size=4214332, nrcpt=1 (queue active) Oct 11 17:26:10 mail postfix/smtp[6902]: 1748E1CD09: to=<yuui...@host.co.jp>, relay=127.0.0.1[127.0.0.1]:10024, delay=106, delays=106/0/0/0.53, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as 62E551CD0B) Oct 11 17:26:10 mail postfix/qmgr[5276]: 1748E1CD09: removed ------------------------------------------------------------------------------------------------------ Oct 11 17:26:10 mail postfix/smtpd[6910]: 62E551CD0B: client=localhost[127.0.0.1] Oct 11 17:26:10 mail postfix/cleanup[6937]: 62E551CD0B: message-id=<00d001cb691d$8a221a90$18011...@nagamatsu> Oct 11 17:26:10 mail postfix/qmgr[5276]: 62E551CD0B: from=< nak...@example.com>, size=4214840, nrcpt=1 (queue active) Oct 11 17:26:10 mail amavis[7065]: (07065-02) Passed CLEAN, [20.0.0.147] [20.0.0.147] <nak...@example.com> -> <yuui...@host.co.jp>, Message-ID: <00d001cb691d$8a221a90$18011...@nagamatsu>, mail_id: IF+6lje-GaDe, Hits: -, size: 42143 Oct 11 17:26:33 mail postfix/smtp[7426]: 62E551CD0B: to=<yuui...@host.co.jp>, relay=mail.global.hostmail.com[300.55.88.22]:25, delay=23, delays=0.13/0/0.69/22, dsn=2.6.0, status=sent (250 2.6.0 <00d001cb691d$8a221a90$18011...@nagam Oct 11 17:26:33 mail postfix/qmgr[5276]: 62E551CD0B: removed I don't see any problem on the logs. the logs in my opinion tells me that queue ID 1748E1CD09 was delivered to your content filter and you content filter give queue ID 62E551CD0B for content checking and removed from queue and delivered to destination (I guess).
