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
