High CPU usage (need help)

Mon Apr 25 18:18:37 CEST 2011

is it SA + sa_updates? or do you have custom rules? (runaway regex),
compiled rules? or not compiled?
It is sa+sa_updates with compiled rules.

is clamd running? is it slow? did it die?
Yes clamd running but it not take time is answer is good.

do you have any ipv6 perl modules loaded when you do not have ipv6?
(google, I found hard to reproduce problem)
How to check that ?

This is an example of Spamassassin truning in debug mode 

We can found that tests_pri_0 rule take 90% of time, is it possible to
disable this rule ?

Apr 25 17:16:27 smtp ch1-08296-01-127)[8296]: (08296-01-127) SA dbg:
timing: total 826 ms - parse: 13 (1.6%), extract_message_metadata: 23
(2.7%), get_uri_detail_list: 0.87 (0.1%), tests_pri_0: 759 (91.9%),
tests_pri_500: 3 (0.4%), learn: 22 (2.6%)
Apr 25 17:16:30 smtp ch1-08296-01-128)[8296]: (08296-01-128) SA dbg:
timing: total 1381 ms - parse: 14 (1.0%), extract_message_metadata: 25
(1.8%), get_uri_detail_list: 9 (0.6%), tests_pri_0: 1272 (92.1%),
tests_pri_500: 3 (0.2%), learn: 56 (4.1%)
Apr 25 17:16:31 smtp ch1-08296-01-130)[8296]: (08296-01-130) SA dbg:
timing: total 697 ms - parse: 1.62 (0.2%), extract_message_metadata: 5
(0.8%), get_uri_detail_list: 1.02 (0.1%), tests_pri_0: 656 (94.2%),
tests_pri_500: 3 (0.4%), learn: 25 (3.6%)
Apr 25 17:16:32 smtp ch1-08296-01-131)[8296]: (08296-01-131) SA dbg:
timing: total 693 ms - parse: 1.77 (0.3%), extract_message_metadata: 10
(1.4%), get_uri_detail_list: 1.96 (0.3%), tests_pri_0: 648 (93.5%),
tests_pri_500: 3 (0.5%), learn: 24 (3.4%)
Apr 25 17:16:33 smtp ch1-08296-01-132)[8296]: (08296-01-132) SA dbg:
timing: total 652 ms - parse: 10 (1.6%), extract_message_metadata: 19
(2.9%), get_uri_detail_list: 0.23 (0.0%), tests_pri_0: 593 (90.9%),
tests_pri_500: 3 (0.5%), learn: 21 (3.3%)
Apr 25 17:16:34 smtp ch1-08296-01-133)[8296]: (08296-01-133) SA dbg:
timing: total 632 ms - parse: 1.85 (0.3%), extract_message_metadata: 3
(0.4%), get_uri_detail_list: 38 (6.1%), tests_pri_0: 464 (73.4%),
tests_pri_500: 3 (0.5%), learn: 136 (21.5%)
Apr 25 17:16:35 smtp ch1-08296-01-134)[8296]: (08296-01-134) SA dbg:
timing: total 648 ms - parse: 2 (0.4%), extract_message_metadata: 6
(0.9%), get_uri_detail_list: 4 (0.6%), tests_pri_0: 585 (90.3%),
tests_pri_500: 3 (0.5%), learn: 41 (6.3%)
Apr 25 17:16:35 smtp ch1-08296-01-135)[8296]: (08296-01-135) SA dbg:
timing: total 638 ms - parse: 1.75 (0.3%), extract_message_metadata: 5
(0.8%), get_uri_detail_list: 4 (0.6%), tests_pri_0: 582 (91.3%),
tests_pri_500: 3 (0.5%), learn: 39 (6.1%)
Apr 25 17:16:38 smtp ch1-08296-01-136)[8296]: (08296-01-136) SA dbg:
timing: total 2318 ms - parse: 3 (0.1%), extract_message_metadata: 11
(0.5%), get_uri_detail_list: 1.08 (0.0%), tests_pri_0: 2262 (97.6%),
tests_pri_500: 4 (0.2%), learn: 32 (1.4%)
Apr 25 17:16:39 smtp ch1-08296-01-138)[8296]: (08296-01-138) SA dbg:
timing: total 1171 ms - parse: 7 (0.6%), extract_message_metadata: 69
(5.9%), get_uri_detail_list: 33 (2.8%), tests_pri_0: 920 (78.6%),
tests_pri_500: 3 (0.3%), learn: 150 (12.8%)
Apr 25 17:16:40 smtp ch1-08296-01-139)[8296]: (08296-01-139) SA dbg:
timing: total 976 ms - parse: 3 (0.3%), extract_message_metadata: 18
(1.8%), get_uri_detail_list: 8 (0.9%), tests_pri_0: 893 (91.5%),
tests_pri_500: 3 (0.3%), learn: 50 (5.1%)
Apr 25 17:16:42 smtp ch1-08296-01-141)[8296]: (08296-01-141) SA dbg:
timing: total 1462 ms - parse: 6 (0.4%), extract_message_metadata: 15
(1.1%), get_uri_detail_list: 0.51 (0.0%), tests_pri_0: 1387 (94.8%),
tests_pri_500: 3 (0.2%), learn: 46 (3.1%)
Apr 25 17:16:43 smtp ch1-08296-01-143)[8296]: (08296-01-143) SA dbg:
timing: total 709 ms - parse: 1.90 (0.3%), extract_message_metadata: 10
(1.4%), get_uri_detail_list: 0.56 (0.1%), tests_pri_0: 664 (93.7%),
tests_pri_500: 4 (0.5%), learn: 23 (3.3%)
Apr 25 17:16:44 smtp ch1-08296-01-144)[8296]: (08296-01-144) SA dbg:
timing: total 449 ms - parse: 2 (0.5%), extract_message_metadata: 12
(2.6%), get_uri_detail_list: 1.26 (0.3%), tests_pri_0: 399 (89.0%),
tests_pri_500: 3 (0.7%), learn: 23 (5.1%)
Apr 25 17:16:45 smtp ch1-08296-01-145)[8296]: (08296-01-145) SA dbg:
timing: total 1454 ms - parse: 5 (0.3%), extract_message_metadata: 10
(0.7%), get_uri_detail_list: 0.42 (0.0%), tests_pri_0: 1392 (95.8%),
tests_pri_500: 3 (0.2%), learn: 38 (2.6%)
Apr 25 17:16:46 smtp ch1-08296-01-146)[8296]: (08296-01-146) SA dbg:
timing: total 603 ms - parse: 1.61 (0.3%), extract_message_metadata: 9
(1.5%), get_uri_detail_list: 1.29 (0.2%), tests_pri_0: 555 (92.1%),
tests_pri_500: 3 (0.5%), learn: 29 (4.7%)
Apr 25 17:16:47 smtp ch1-08296-01-147)[8296]: (08296-01-147) SA dbg:
timing: total 557 ms - parse: 1.44 (0.3%), extract_message_metadata: 9
(1.6%), get_uri_detail_list: 1.31 (0.2%), tests_pri_0: 513 (92.1%),
tests_pri_500: 4 (0.7%), learn: 24 (4.4%)
Apr 25 17:16:48 smtp ch1-08296-01-148)[8296]: (08296-01-148) SA dbg:
timing: total 948 ms - parse: 3 (0.4%), extract_message_metadata: 19
(2.0%), get_uri_detail_list: 2 (0.2%), tests_pri_0: 885 (93.4%),
tests_pri_500: 3 (0.3%), learn: 31 (3.2%)
Apr 25 17:16:48 smtp ch1-08296-01-149)[8296]: (08296-01-149) SA dbg:
timing: total 574 ms - parse: 1.92 (0.3%), extract_message_metadata: 12
(2.0%), get_uri_detail_list: 5 (0.8%), tests_pri_0: 517 (90.1%),
tests_pri_500: 3 (0.5%), learn: 32 (5.6%)
Apr 25 17:16:50 smtp ch1-08296-01-150)[8296]: (08296-01-150) SA dbg:
timing: total 1176 ms - parse: 18 (1.5%), extract_message_metadata: 46
(3.9%), get_uri_detail_list: 1.02 (0.1%), tests_pri_0: 1072 (91.2%),
tests_pri_500: 3 (0.3%), learn: 27 (2.3%)
Apr 25 17:16:51 smtp ch1-08296-01-151)[8296]: (08296-01-151) SA dbg:
timing: total 1067 ms - parse: 5 (0.5%), extract_message_metadata: 13
(1.2%), get_uri_detail_list: 1.83 (0.2%), tests_pri_0: 1004 (94.1%),
tests_pri_500: 3 (0.3%), learn: 35 (3.3%)
Apr 25 17:16:52 smtp ch1-08296-01-152)[8296]: (08296-01-152) SA dbg:
timing: total 562 ms - parse: 1.57 (0.3%), extract_message_metadata: 9
(1.6%), get_uri_detail_list: 1.35 (0.2%), tests_pri_0: 518 (92.1%),
tests_pri_500: 4 (0.7%), learn: 24 (4.3%)
Apr 25 17:16:53 smtp ch1-08296-01-153)[8296]: (08296-01-153) SA dbg:
timing: total 884 ms - parse: 7 (0.8%), extract_message_metadata: 13
(1.5%), get_uri_detail_list: 6 (0.6%), tests_pri_0: 789 (89.2%),
tests_pri_500: 10 (1.1%), learn: 57 (6.5%)
Apr 25 17:16:54 smtp ch1-08296-01-154)[8296]: (08296-01-154) SA dbg:
timing: total 543 ms - parse: 1.40 (0.3%), extract_message_metadata: 6
(1.1%), get_uri_detail_list: 1.01 (0.2%), tests_pri_0: 504 (92.9%),
tests_pri_500: 3 (0.6%), learn: 22 (4.1%)
Apr 25 17:16:56 smtp ch1-08296-01-155)[8296]: (08296-01-155) SA dbg:
timing: total 1639 ms - parse: 3 (0.2%), extract_message_metadata: 21
(1.3%), get_uri_detail_list: 8 (0.5%), tests_pri_0: 1535 (93.7%),
tests_pri_500: 3 (0.2%), learn: 68 (4.1%)
Apr 25 17:16:56 smtp ch1-08296-01-156)[8296]: (08296-01-156) SA dbg:
timing: total 613 ms - parse: 1.57 (0.3%), extract_message_metadata: 9
(1.4%), get_uri_detail_list: 1.30 (0.2%), tests_pri_0: 571 (93.1%),
tests_pri_500: 3 (0.5%), learn: 23 (3.8%)
Apr 25 17:16:58 smtp ch1-08296-01-157)[8296]: (08296-01-157) SA dbg:
timing: total 1294 ms - parse: 4 (0.3%), extract_message_metadata: 32
(2.5%), get_uri_detail_list: 55 (4.3%), tests_pri_0: 1039 (80.2%),
tests_pri_500: 3 (0.2%), learn: 184 (14.2%)
Apr 25 17:16:59 smtp ch1-08296-01-158)[8296]: (08296-01-158) SA dbg:
timing: total 1050 ms - parse: 3 (0.3%), extract_message_metadata: 20
(1.9%), get_uri_detail_list: 0.41 (0.0%), tests_pri_0: 960 (91.4%),
tests_pri_500: 7 (0.7%), learn: 51 (4.9%)
Apr 25 17:17:01 smtp ch1-08296-01-159)[8296]: (08296-01-159) SA dbg:
timing: total 922 ms - parse: 13 (1.5%), extract_message_metadata: 37
(4.0%), get_uri_detail_list: 0.35 (0.0%), tests_pri_0: 829 (90.0%),
tests_pri_500: 3 (0.4%), learn: 27 (2.9%)
Apr 25 17:17:03 smtp ch1-08296-01-161)[8296]: (08296-01-161) SA dbg:
timing: total 642 ms - parse: 1.58 (0.2%), extract_message_metadata: 9
(1.3%), get_uri_detail_list: 1.40 (0.2%), tests_pri_0: 569 (88.6%),
tests_pri_500: 3 (0.5%), learn: 55 (8.5%)
Apr 25 17:17:04 smtp ch1-08296-01-162)[8296]: (08296-01-162) SA dbg:
timing: total 893 ms - parse: 2 (0.2%), extract_message_metadata: 11
(1.2%), get_uri_detail_list: 1.77 (0.2%), tests_pri_0: 834 (93.4%),
tests_pri_500: 3 (0.4%), learn: 36 (4.0%)
Apr 25 17:17:05 smtp ch1-08296-01-163)[8296]: (08296-01-163) SA dbg:
timing: total 571 ms - parse: 3 (0.4%), extract_message_metadata: 17
(2.9%), get_uri_detail_list: 0.96 (0.2%), tests_pri_0: 512 (89.6%),
tests_pri_500: 4 (0.7%), learn: 31 (5.4%)
Apr 25 17:17:06 smtp ch1-08296-01-164)[8296]: (08296-01-164) SA dbg:
timing: total 993 ms - parse: 6 (0.6%), extract_message_metadata: 94
(9.5%), get_uri_detail_list: 16 (1.6%), tests_pri_0: 801 (80.7%),
tests_pri_500: 3 (0.3%), learn: 76 (7.6%)
Apr 25 17:17:08 smtp ch1-08296-01-166)[8296]: (08296-01-166) SA dbg:
timing: total 1403 ms - parse: 13 (0.9%), extract_message_metadata: 37
(2.7%), get_uri_detail_list: 5 (0.3%), tests_pri_0: 1301 (92.7%),
tests_pri_500: 3 (0.2%), learn: 41 (2.9%)
Apr 25 17:17:09 smtp ch1-08296-01-167)[8296]: (08296-01-167) SA dbg:
timing: total 619 ms - parse: 1.49 (0.2%), extract_message_metadata: 9
(1.4%), get_uri_detail_list: 1.24 (0.2%), tests_pri_0: 574 (92.7%),
tests_pri_500: 3 (0.5%), learn: 26 (4.2%)
Apr 25 17:17:09 smtp ch1-08296-01-168)[8296]: (08296-01-168) SA dbg:
timing: total 611 ms - parse: 1.47 (0.2%), extract_message_metadata: 9
(1.5%), get_uri_detail_list: 1.33 (0.2%), tests_pri_0: 564 (92.3%),
tests_pri_500: 3 (0.5%), learn: 24 (4.0%)
Apr 25 17:17:10 smtp ch1-08296-01-169)[8296]: (08296-01-169) SA dbg:
timing: total 617 ms - parse: 3 (0.5%), extract_message_metadata: 9
(1.4%), get_uri_detail_list: 1.33 (0.2%), tests_pri_0: 560 (90.9%),
tests_pri_500: 3 (0.5%), learn: 32 (5.2%)
Apr 25 17:17:12 smtp ch1-08296-01-170)[8296]: (08296-01-170) SA dbg:
timing: total 974 ms - parse: 11 (1.2%), extract_message_metadata: 63
(6.4%), get_uri_detail_list: 2 (0.2%), tests_pri_0: 841 (86.4%),
tests_pri_500: 3 (0.3%), learn: 46 (4.8%)
Apr 25 17:17:12 smtp ch1-08296-01-171)[8296]: (08296-01-171) SA dbg:
timing: total 692 ms - parse: 3 (0.4%), extract_message_metadata: 6
(0.9%), get_uri_detail_list: 1.51 (0.2%), tests_pri_0: 624 (90.1%),
tests_pri_500: 7 (1.0%), learn: 45 (6.5%)
Apr 25 17:17:14 smtp ch1-08296-01-172)[8296]: (08296-01-172) SA dbg:
timing: total 705 ms - parse: 1.51 (0.2%), extract_message_metadata: 8
(1.2%), get_uri_detail_list: 1.29 (0.2%), tests_pri_0: 659 (93.4%),
tests_pri_500: 4 (0.5%), learn: 28 (3.9%)
Apr 25 17:17:15 smtp ch1-08296-01-173)[8296]: (08296-01-173) SA dbg:
timing: total 1163 ms - parse: 2 (0.2%), extract_message_metadata: 9
(0.8%), get_uri_detail_list: 2 (0.2%), tests_pri_0: 1109 (95.3%),
tests_pri_500: 3 (0.3%), learn: 34 (2.9%)
Apr 25 17:17:16 smtp ch1-08296-01-175)[8296]: (08296-01-175) SA dbg:
timing: total 544 ms - parse: 1.46 (0.3%), extract_message_metadata: 8
(1.5%), get_uri_detail_list: 1.40 (0.3%), tests_pri_0: 503 (92.4%),
tests_pri_500: 3 (0.6%), learn: 23 (4.3%)
Apr 25 17:17:18 smtp ch1-08296-01-176)[8296]: (08296-01-176) SA dbg:
timing: total 1448 ms - parse: 7 (0.5%), extract_message_metadata: 38
(2.6%), get_uri_detail_list: 1.03 (0.1%), tests_pri_0: 1345 (92.9%),
tests_pri_500: 3 (0.2%), learn: 46 (3.2%)
Apr 25 17:17:18 smtp ch1-08296-01-178)[8296]: (08296-01-178) SA dbg:
timing: total 724 ms - parse: 1.92 (0.3%), extract_message_metadata: 13
(1.8%), get_uri_detail_list: 4 (0.5%), tests_pri_0: 624 (86.1%),
tests_pri_500: 3 (0.4%), learn: 76 (10.5%)
Apr 25 17:17:19 smtp ch1-08296-01-179)[8296]: (08296-01-179) SA dbg:
timing: total 608 ms - parse: 1.50 (0.2%), extract_message_metadata: 8
(1.4%), get_uri_detail_list: 1.27 (0.2%), tests_pri_0: 564 (92.9%),
tests_pri_500: 3 (0.5%), learn: 25 (4.1%)
Apr 25 17:17:20 smtp ch1-08296-01-180)[8296]: (08296-01-180) SA dbg:
timing: total 1129 ms - parse: 13 (1.1%), extract_message_metadata: 22
(2.0%), get_uri_detail_list: 1.49 (0.1%), tests_pri_0: 1060 (93.9%),
tests_pri_500: 3 (0.3%), learn: 25 (2.2%)
Apr 25 17:17:21 smtp ch1-08296-01-181)[8296]: (08296-01-181) SA dbg:
timing: total 570 ms - parse: 1.44 (0.3%), extract_message_metadata: 7
(1.3%), get_uri_detail_list: 1.41 (0.2%), tests_pri_0: 515 (90.4%),
tests_pri_500: 3 (0.5%), learn: 37 (6.6%)

Le lundi 25 avril 2011 à 09:10 -0400, Michael Scheidell a écrit :

> On 4/25/11 8:31 AM, david touzeau wrote: 
> 
> > Using 2.6.5 20110407 + Postfix 2.8.2 in post-queue filter mode.
> > Hardware : 4 cpus + 4Go memory
> > 
> > Has you can see every time amavisd child turn to more than 60% when
> > analyze messages
> 
> 
> did it do this with 2.6.4?
> you didn't mention verison of SA.
> is it SA + sa_updates? or do you have custom rules? (runaway regex),
> compiled rules? or not compiled?
> 
> are you having problems with dns rbls? 
> do you have any ipv6 perl modules loaded when you do not have ipv6?
> (google, I found hard to reproduce problem)
> is clamd running? is it slow? did it die?
> try to identify the rules and email that are causing the problem
> 
> run spamassassin -D against one of the emails.
> 
> look at timing. identify which part of sa is causing problem and fix
> it.
> 
> 
> 
> 
> 
> 
> -- 
> Michael Scheidell, CTO
> o: 561-999-5000
> d: 561-948-2259
> ISN: 1259*1300
> > | SECNAP Network Security Corporation 
>       * Best Intrusion Prevention Product, Networks Product Guide
>       * Certified SNORT Integrator
>       * Hot Company Award, World Executive Alliance
>       * Best in Email Security, 2010 Network Products Guide
>       * King of Spam Filters, SC Magazine
> 
> 
> 
> 
> ______________________________________________________________________
> 
> This email has been scanned and certified safe by SpammerTrap®. 
> For Information please see http://www.secnap.com/products/spammertrap/
> 
> 
> ______________________________________________________________________
> 
> 

-- 

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.amavis.org/pipermail/amavis-users/attachments/20110425/51be37f3/attachment.html>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: carte-visite.png
Type: image/png
Size: 16614 bytes
Desc: not available
URL: <http://lists.amavis.org/pipermail/amavis-users/attachments/20110425/51be37f3/attachment.png>