Hello Viktor Thank you for your answer. Pls find my answers inserted. I changed names and ips.
Rgds Alain Le 03/12/13, Viktor Dukhovni <postfix-us...@dukhovni.org> a écrit : > On Tue, Dec 03, 2013 at 10:50:45AM +0100, POSTFIX MAIL wrote: > > > Oct 29 13:47:39 pf2 postfix/smtpd[22983]: > > D6D66864044: client=email.com[1.2.3.4] > > Oct 29 13:47:41 pf2 postfix/cleanup[9868]: > > D6D66864044: message-id=<0...@e.com> > > Oct 29 14:03:23 pf2 postfix/qmgr[16800]: > > D6D66864044: from=<h...@e.com>, size=1862193, nrcpt=1 (queue active) > > Oct 29 14:03:24 pf2 postfix/smtp[5708]: > > D6D66864044: to=<d...@o.fr>, relay=fe-data[192.168.1.1]:10025, > > delay=945, delays=944/0/0/1.2, dsn=2.0.0, status=sent > > (250 OK, sent 526FB21B_16141_2806_1 BD3C6ED81D5) > > Oct 29 14:03:25 pf2 postfix/qmgr[16800]: > > D6D66864044: removed > > > > I noticed in logs that both smtpd AND cleanup daemons stay busy > > until the qmgr managed this email (at 14:03:23) > > What does "stay busy" mean? Show the log entries for pids 22983 and 9868 > immediately before and immediately after the ones above. > => I mean both daemons were dealing/ending with this message (D6D66864044) before making any other action (see logs below) Oct 29 13:47:34 pf2 postfix/smtpd[22983]: disconnect from pool.ukrtel.net[92.112.112.186] Oct 29 13:47:38 pf2 postfix/smtpd[22983]: connect from email.com[1.2.3.4] Oct 29 13:47:39 pf2 postfix/smtpd[22983]: D6D66864044: client=email.com[1.2.3.4] Oct 29 14:03:23 pf2 postfix/smtpd[22983]: disconnect from email.com[1.2.3.4] Oct 29 14:03:30 pf2 postfix/smtpd[22983]: connect from mime.com[207.211.31.122] Oct 29 14:03:30 pf2 postfix/smtpd[22983]: setting up TLS connection from mime.com[207.211.31.122] Oct 29 13:47:39 pf2 postfix/cleanup[9868]: 4775E864044: message-id=<960@r.snecma> Oct 29 13:47:41 pf2 postfix/cleanup[9868]: D6D66864044: message-id=<0...@e.com> Oct 29 14:03:29 pf2 postfix/cleanup[9868]: D212586403C: message-id=<6...@stf.mer.com> Oct 29 14:03:29 pf2 postfix/cleanup[9868]: 71E0586404B: message-id=<301@root.local> Oct 29 14:03:30 pf2 postfix/cleanup[9868]: D86CE86403C: message-id=<9...@collaboratif.egis > > > Question: does the smtpd daemon transmit the email to the cleanup > > daemon before receiving all the email data ? > > Yes, the message content streams from the remote SMTP client via the smtpd(8) > to cleanup(8) and into the queue file. > => It is this part I am curious to well understand. => Let's suppose receiving a message that takes 10 mn (for any reason) to be transmitted to a postfix smtpd daemon => Let's suppose there is no delay at the qmgr/smtp daemons level, Wich logs are correct: a/ or b/ ? a/ smtpd receives the message; when received entirely sends it to cleanup T smtpd T+10 cleanup T+10 qmgr T+10 smtp b/ smtpd receives the message and sends it on the fly to cleanup T smtpd T cleanup T+10 qmgr T+10 smtp > > > (which could explain that both the smtpd and cleanup daemons stay > > busy a long time in case for example the email is big and the > > network is slow ) > > This is a 1.8MB message, the effective bandwidth is: > > $ echo "1862193 8 * 944 / p" | dc > 15781 > > is 15.8 kbps which is rather slow... > => Right ... but it is a possibility .... => and it may also be the remote smtp client which slowed the message transmission > > Perhaps you have particularly inefficient body checks, and this message had > lots of short lines (messages of the same size with fewer, but longer, lines > might be processed more quickly). > => i thought of something similar dealing with the structure of the message but unfortunatly I only have in the content filter logs files (puremessage) the recap of the message MIME parts (no copy of the message itself) > It is also possible that this message had a bloated header (Postfix does not > impose a maximum header size). > => right - same as above > > > -- > Viktor. > >
