Hello. I have a Postfix+Amavisd-new+MySQL+ClamAV mail gateway system.
I'm observing time spent by a messagge in (Amavisd-new) content_filter of postfix (I trascure deliberately the time spent by a message to be processed by postfix, because it is neglegible with respect to the filter). I "grep" a maillog line with match "delays=", "127.0.0.1" and "status=sent (250 2.0.0" (I don't consider rejected messages, and blocked message by content_filter). The aim is to get an average latency of a message of processing. Once I get all 4-ple delays="a/b/c/d", I calculate the average time during a specified time period. What I note is that the average of "Time to transmit the message" (the term pointed as d in 4-ple above) is a little bit to high for what I can perceive. For example, I obtain: Every 1.0s: cat /tmp/filter.latencies.txt Fri Jan 30 19:54:26 2009 5.844000/0.000000/0.001000/4.049000 I can accept that the value "Time Before Queued" is a little bit high, as it represent the time for the content filter to queue the message since it has been trasmitted by the sender. But I can't figure out why the "Time to transmit the message" is high at the same manner, even if it represent (at least I think) the time employed by the content filter to transmit the message back to Postfix. Sorry for my not completely clear exposition, but I'ld like to have a better one that possibly explay better the messages timing inside a such architecture. I appreciate any comment about. Thanks, rocsca
