ispcp-apache-logger bugs ?

[blocker]

hi, i have a test server with 32Gb memory system, the os is FreeBSD, using ispcp as control panel, I setup a domain then we hammering that domain with a lot of connection until the load to that server goes up to 100 sometimes to 300, when load become 250-300 and processor usage 87% specific at system resource that handle I/O ( I think, base on top ) the log become corrupted but if i disable ispcp-apache-logger, the log that apache created still intact ( in this case /var/log/httpd-access.log) here is files in log dir when goes corrupted

-rw-r--r-- 1 root www 201 May 4 13:50 %3dforid%253a11%26ie%3xxx-8%26q%3dxxx-access.log
-rw-r--r-- 1 root www 202 May 4 11:02 2903-access.log
-rw-r--r-- 1 root www 277 May 4 13:49 2bxxx%2bdbs%xxx.com-access.log
-rw-r--r-- 1 root www 257 May 4 11:01 com-access.log
-rw-r--r-- 1 root www 410 May 4 13:49 default-access.log
-rw-r--r-- 1 www www 856251 May 6 08:03 default-error.log
-rw-r----- 1 root wheel 52266790 May 6 08:42 xxx.com-access.log


the real log is just xxx.com-access.log and defaul-error.log

so i wonder is this perl's bug or Os memory spesific bug or the program it self when dealing with such condition. somebody can give me a clue ?

[kilburn]

Looking at your file listing, it seems to be a problem regarding the vhost parsing. Could you zip and send us the full (correct) apache log so we can manually pass it through ispcp-apache-logger and see where the problem is?

[sci2tech]

Apache logger expect a specific line format to determine witch host is belonging to

Code:

my ($vhost, $size, $line) = $log_line =~ m/^(\S+) (\d+|-) (.*)$/s;

\S+ -> Match a string that do not contain whitespace character(domain names do not allow white spaces).
\d+|- A number or a dash (page + headers size).
Rest of the line.
Now log format is

Code:

LogFormat "%v %b %h %l %u %t \"%r\" %>s %b \"%{Referer}i\" \"%{User-Agent}i\"" ispcplog

Can apache send wrong parameters to logger?

[kilburn]

It shouldn't send wrong parameters, but that's why I wanted to test. If this is not the case, then I bet there's some buffering problem (the logger reads incomplete lines, and then treats the remaining part as if it was a new log line by itself).

I'm not a perl guru though, so I can't really asses why this happens and how it could be solved...

[sci2tech]

How can I "hammer" my server? blocker what is your method? I do want to test so I can reproduce and fix this error. I think that since apache logger is a script not a binary file, can be an answer but I want to check.
Blocker, can you increase $MAXFILES (default is 33) make it be 100 or greater to test?
Latter:

Code:

siege -v -c 500 -i -t 1M r 1000 -d 0 cms.eu.bogus

No errors in logs.

Code:

ab -n 1000 -c 100 -k http://sci2tech.eu.bogus/index.php

No errors in logs.

Code:

httperf --server=cms.eu.bogus --uri=/ --num-conns=5000 --num-calls=50 --verbose

No errors in logs.
I did also run all in the same time.

Code:

top - 20:15:53 up 10 days, 20:57,  0 users,  load average: 7.25, 5.26, 2.63
Tasks: 188 total,  15 running, 173 sleeping,   0 stopped,   0 zombie
Cpu0  : 82.7%us, 16.7%sy,  0.0%ni,  0.0%id,  0.0%wa,  0.0%hi,  0.7%si,  0.0%st
Cpu1  : 68.4%us, 31.2%sy,  0.0%ni,  0.0%id,  0.0%wa,  0.0%hi,  0.3%si,  0.0%st
Mem:   1932256k total,  1336848k used,   595408k free,    56968k buffers
Swap:  3903784k total,   282096k used,  3621688k free,   438948k cached

[kilburn]

I think it's something related to invalid host requests and such, that's why I asked for the complete "ok" logfile...

[sci2tech]

Malformed host commands usually end with a 400 Bad Request and logs go to error log. But I`m also curious to see in logs what is causing this.

[blocker]

every log file corrupted only consist one line like this
x.x.x.x - - [04/May/2009:13:50:09 +0700] "GET / HTTP/1.1" 200 7959 "http://xxx.com/xxx.php" "Mozilla/5.0 (Windows; U; Windows NT 5.1; en-US; rv:1.8.1) Gecko/20061010 Firefox/2.0"

to hammering the server we use a php-cgi program with processlife set to 10800