Stefan,
> I'm using the excellent "amavis-logwatch"[1] tool to create a report
> about amavisd-new timing statistics. Those are capured with
> $log_level = 2;
> $syslog_facility = 'local5';
> $syslog_priority = 'debug';
> and written to a dedicated logilfe as recommended by the documentation
> which is provided by amavis-logwatch.
| Scan Time Percentiles % Time Total (s)
| 0% 5% 25% 50% 75% 95% 100%
| -------------------------------------------------------------------
| get-file-type2 34.19% 700.358
| 0.083 0.146 0.152 0.157 0.161 0.182 2.242
| SA check 19.87% 406.995
| 0.346 0.503 0.720 1.062 2.414 4.327 15.734
| SMTP DATA 7.06% 144.622
| 0.001 0.022 0.032 0.034 0.035 0.036 0.119
> It is not surprising for me that "SA check" consumes a lot of time -
> but I am rather puzzled by the amount of CPu cycles "get-file-type2"
> consumed. What exactly is done in "get-file-type2"?
get-file-type(n) is a timing section name reporting the time it took
a spawned file(1) command to process n supplied files. The n varies
and is a number of mail parts extracted from each message. So your
get-file-type2 covers only cases where a mail message had exactly
two parts.
> Is the ration (one third of all computing time consumed by it)
> a normal one ("to be expected") or is this indicating some serious
> misconfiguration on my part?
It is not normal. It typically takes a couple of dozens of milliseconds.
Interestingly the percentiles show that in the 5%-95% region it
took quite consistently about 150 ms, and even the max (reported as 100%)
shows the maximum time was 2.2 seconds. Comparing this to the
'SA check' percentiles gives me the impression that percentiles are
reasonable but the 34.19% total time for get-file-type2 looks fishy.
Try some one-liner awk or perl command and collect the data by yourself,
see what you get. Perhaps you'd find one or two samples that might
show extreme value, bending the average (and somehow escaping the
100% percentile). If that is the case, it would make sense to examine
such event in detail.
> JFTR, this is an amavisd-new 2.5.3 (Debian package). $MYHOME/tmp is a
> normal disk filesystem, not some kind of ram-only fs [2]. My file(1)
> utility is: file-4.17, magic file from /etc/magic:/usr/share/file/magic
Perhaps you were bitten by a POSIX regex(3) library on Linux problem,
see http://www.amavis.org/security/asa-2007-3.txt section 4,
which could cause extremely long processing in a regexp match
called from file(1) utility in some degenerate cases of input.
Mark
-------------------------------------------------------------------------
Check out the new SourceForge.net Marketplace.
It's the best place to buy or sell services for
just about anything Open Source.
http://sourceforge.net/services/buy/index.php
_______________________________________________
AMaViS-user mailing list
[email protected]
https://lists.sourceforge.net/lists/listinfo/amavis-user
AMaViS-FAQ:http://www.amavis.org/amavis-faq.php3
AMaViS-HowTos:http://www.amavis.org/howto/
