On Thu, Oct 14, 2010 at 2:56 PM, captain_claw <ryanc...@gmail.com> wrote:
> > > 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). > Thank you Ryan, Ok. got it! The client is: Microsoft Outlook Express 6.00.2900.2869 Sorry to ask, but when you say: > "I don't see any problem on the logs." Do you mean: a) Logs are fine, the server setup seems fine. b) Logs are fine, there is no problem with the email client. Sorry, my English is not very good... The reason why I think the problem is related to the client is that in less than 30 minutes nak...@example.com is sending a 4MB file, 12 times to the same mailbox: yuui...@host.co.jp. And every time the mail is originated in the client[p2147...] which may rule out a problem in the server. Is that assumption correct? A.Lepe
