LSPHP5 cpu issue

[NiteWave]

can you strace one of lsphp5 process which has run longest time, in your post, this one:
22172 nobody 16 0 272m 69m 40m R 6.7 0.9 1:24.27 lsphp5:/home/xxx/public_html/forum/vbseo.php

and see what it's doing.

[MentaL]

Its just outputting allot of info from vb.

fcntl(5, F_SETLKW, {type=F_WRLCK, whence=SEEK_SET, start=0, len=1}) = 0
fcntl(5, F_SETLKW, {type=F_UNLCK, whence=SEEK_SET, start=0, len=1}) = 0
lseek(22, -4096, SEEK_CUR)              = 0
close(22)                               = 0
munmap(0x2abf6736d000, 4096)            = 0
poll([{fd=21, events=POLLIN|POLLPRI}], 1, 0) = 0 (Timeout)
write(21, "X\0\0\0\3\n\t\t\tSELECT blockid, require"..., 92) = 92
read(21, "\1\0\0\1\2[\0\0\2\3def\21xxx_database\23"..., 16384) = 221
poll([{fd=21, events=POLLIN|POLLPRI}], 1, 0) = 0 (Timeout)
write(21, "\26\1\0\0\3\n\t\t\tSELECT pf.profilefieldc"..., 282) = 282
read(21, "\1\0\0\1\25a\0\0\2\3def\21xxx_database\2"..., 16384) = 1908
lstat("/home", {st_mode=S_IFDIR|0711, st_size=4096, ...}) = 0
lstat("/home/xxx", {st_mode=S_IFDIR|0711, st_size=4096, ...}) = 0
lstat("/home/xxx/public_html", {st_mode=S_IFDIR|0750, st_size=4096, ...}) = 0
lstat("/home/xxx/public_html/forum", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat("/home/xxx/public_html/forum/includes", {st_mode=S_IFDIR|0755, st_size=12288, ...}) = 0
lstat("/home/xxx/public_html/forum/includes/class_profileblock_blog.php", {st_mode=S_IFREG|0644, st_size=20646, ...}) = 0
lstat("/home", {st_mode=S_IFDIR|0711, st_size=4096, ...}) = 0
lstat("/home/xxx", {st_mode=S_IFDIR|0711, st_size=4096, ...}) = 0
lstat("/home/xxx/public_html", {st_mode=S_IFDIR|0750, st_size=4096, ...}) = 0
lstat("/home/xxx/public_html/forum", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat("/home/xxx/public_html/forum/includes", {st_mode=S_IFDIR|0755, st_size=12288, ...}) = 0
lstat("/home/xxx/public_html/forum/includes/class_profileblock_blog.php", {st_mode=S_IFREG|0644, st_size=20646, ...}) = 0
open("/home/xxx/public_html/forum/includes/class_profileblock_blog.php", O_RDONLY) = 22
fstat(22, {st_mode=S_IFREG|0644, st_size=20646, ...}) = 0
fcntl(22, F_GETFL)                      = 0x8000 (flags O_RDONLY|O_LARGEFILE)
fstat(22, {st_mode=S_IFREG|0644, st_size=20646, ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x2abf6736d000
lseek(22, 0, SEEK_CUR)                  = 0
lseek(22, 0, SEEK_SET)                  = 0
read(22, "<?php\n/*========================"..., 4096) = 4096
lseek(22, 4096, SEEK_SET)               = 4096
stat("/home/xxx/public_html/forum/includes/class_profileblock_blog.php", {st_mode=S_IFREG|0644, st_size=20646, ...}) = 0
fcntl(5, F_SETLKW, {type=F_WRLCK, whence=SEEK_SET, start=0, len=1}) = 0
fcntl(5, F_SETLKW, {type=F_UNLCK, whence=SEEK_SET, start=0, len=1}) = 0
lseek(22, -4096, SEEK_CUR)              = 0
close(22)                               = 0
munmap(0x2abf6736d000, 4096)            = 0
lstat("/home", {st_mode=S_IFDIR|0711, st_size=4096, ...}) = 0
lstat("/home/xxx", {st_mode=S_IFDIR|0711, st_size=4096, ...}) = 0
lstat("/home/xxx/public_html", {st_mode=S_IFDIR|0750, st_size=4096, ...}) = 0
lstat("/home/xxx/public_html/forum", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat("/home/xxx/public_html/forum/includes", {st_mode=S_IFDIR|0755, st_size=12288, ...}) = 0
lstat("/home/xxx/public_html/forum/includes/blog_functions.php", {st_mode=S_IFREG|0644, st_size=105536, ...}) = 0
lstat("/home", {st_mode=S_IFDIR|0711, st_size=4096, ...}) = 0
lstat("/home/xxx", {st_mode=S_IFDIR|0711, st_size=4096, ...}) = 0
lstat("/home/xxx/public_html", {st_mode=S_IFDIR|0750, st_size=4096, ...}) = 0
lstat("/home/xxx/public_html/forum", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat("/home/xxx/public_html/forum/includes", {st_mode=S_IFDIR|0755, st_size=12288, ...}) = 0
lstat("/home/xxx/public_html/forum/includes/blog_functions.php", {st_mode=S_IFREG|0644, st_size=105536, ...}) = 0
open("/home/xxx/public_html/forum/includes/blog_functions.php", O_RDONLY) = 22
fstat(22, {st_mode=S_IFREG|0644, st_size=105536, ...}) = 0
fcntl(22, F_GETFL)                      = 0x8000 (flags O_RDONLY|O_LARGEFILE)
fstat(22, {st_mode=S_IFREG|0644, st_size=105536, ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x2abf6736d000
lseek(22, 0, SEEK_CUR)                  = 0
lseek(22, 0, SEEK_SET)                  = 0
read(22, "<?php\n/*========================"..., 4096) = 4096
lseek(22, 4096, SEEK_SET)               = 4096
stat("/home/xxx/public_html/forum/includes/blog_functions.php", {st_mode=S_IFREG|0644, st_size=105536, ...}) = 0
fcntl(3, F_SETLKW, {type=F_WRLCK, whence=SEEK_SET, start=0, len=1}) = 0
fcntl(3, F_SETLKW, {type=F_UNLCK, whence=SEEK_SET, start=0, len=1}) = 0
lseek(22, -4096, SEEK_CUR)              = 0
close(22)                               = 0
munmap(0x2abf6736d000, 4096)            = 0
lstat("/home", {st_mode=S_IFDIR|0711, st_size=4096, ...}) = 0
lstat("/home/xxx", {st_mode=S_IFDIR|0711, st_size=4096, ...}) = 0
lstat("/home/xxx/public_html", {st_mode=S_IFDIR|0750, st_size=4096, ...}) = 0
lstat("/home/xxx/public_html/forum", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat("/home/xxx/public_html/forum/includes", {st_mode=S_IFDIR|0755, st_size=12288, ...}) = 0
lstat("/home/xxx/public_html/forum/includes/functions_xperience.php", {st_mode=S_IFREG|0644, st_size=43278, ...}) = 0
open("/home/xxx/public_html/forum/includes/functions_xperience.php", O_RDONLY) = 22
fstat(22, {st_mode=S_IFREG|0644, st_size=43278, ...}) = 0
fcntl(22, F_GETFL)                      = 0x8000 (flags O_RDONLY|O_LARGEFILE)
fstat(22, {st_mode=S_IFREG|0644, st_size=43278, ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x2abf6736d000
lseek(22, 0, SEEK_CUR)                  = 0
lseek(22, 0, SEEK_SET)                  = 0
read(22, "<?php\n/*========================"..., 4096) = 4096
lseek(22, 4096, SEEK_SET)               = 4096
stat("/home/xxx/public_html/forum/includes/functions_xperience.php", {st_mode=S_IFREG|0644, st_size=43278, ...}) = 0
fcntl(3, F_SETLKW, {type=F_WRLCK, whence=SEEK_SET, start=0, len=1}) = 0
fcntl(3, F_SETLKW, {type=F_UNLCK, whence=SEEK_SET, start=0, len=1}) = 0
lseek(22, -4096, SEEK_CUR)              = 0
close(22)                               = 0
munmap(0x2abf6736d000, 4096)            = 0
poll([{fd=21, events=POLLIN|POLLPRI}], 1, 0) = 0 (Timeout)
write(21, "\221\0\0\0\3\n\t\tSELECT COUNT(DISTINCT(us"..., 149) = 149
read(21, "\1\0\0\1\3\37\0\0\2\3def\0\0\0\tusercount\0\f?\0\25\0"..., 16384) = 165
poll([{fd=21, events=POLLIN|POLLPRI}], 1, 0) = 0 (Timeout)
write(21, "\205\0\0\0\3\n\t\tSELECT COUNT(*) AS userc"..., 137) = 137
read(21, "\1\0\0\1\2\37\0\0\2\3def\0\0\0\tusercount\0\f?\0\25\0"..., 16384) = 127
poll([{fd=21, events=POLLIN|POLLPRI}], 1, 0) = 0 (Timeout)
write(21, "\205\0\0\0\3\n\t\tSELECT COUNT(*) AS userc"..., 137) = 137
read(21, "\1\0\0\1\2\37\0\0\2\3def\0\0\0\tusercount\0\f?\0\25\0"..., 16384) = 127
poll([{fd=21, events=POLLIN|POLLPRI}], 1, 0) = 0 (Timeout)
write(21, "\205\0\0\0\3\n\t\tSELECT COUNT(*) AS userc"..., 137) = 137
read(21, "\1\0\0\1\2\37\0\0\2\3def\0\0\0\tusercount\0\f?\0\25\0"..., 16384) = 127

Update;

It seems to be correcting itself again, allthough I made two alterations, I disabled vbulletins live topic and vboptimize, given that the optimize was already built into the configuration of vbulletin (memcached) and using xcache with vbseo , it appears to be "ok" as of this moment, but I'm sure it will go haywire shortly.

top - 05:50:47 up  1:21,  1 user,  load average: 2.40, 3.69, 9.94
Tasks:  71 total,   2 running,  60 sleeping,   9 stopped,   0 zombie
Cpu(s): 17.1%us,  3.0%sy,  1.8%ni, 78.0%id,  0.1%wa,  0.0%hi,  0.0%si,  0.0%st
Mem:   8388608k total,   991484k used,  7397124k free,        0k buffers
Swap:        0k total,        0k used,        0k free,        0k cached

  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND
29766 nobody    15   0  271m  46m  16m S 54.9  0.6   0:02.71 lsphp5
17722 nobody    15   0  272m  76m  47m S 35.0  0.9   2:35.97 lsphp5
19916 nobody    16   0  277m  80m  46m R 30.0  1.0   3:08.23 lsphp5
14326 nobody    15   0  271m  70m  42m S 20.0  0.9   3:15.78 lsphp5
15846 nobody    25  10  283m  87m  47m S 17.6  1.1   4:23.42 lsphp5
20004 nobody    15   0  269m  75m  49m S 14.3  0.9   2:27.27 lsphp5
 1514 nobody    15   0 26976  10m 1580 S  1.0  0.1   1:15.07 litespeed
 9960 root      15   0 88060 3348 2584 S  0.3  0.0   0:01.46 sshd
21977 root      15   0 81580  28m  500 S  0.3  0.3   2:58.26 memcached
26252 root      15   0 12724 1260  924 R  0.3  0.0   0:00.81 top

[NiteWave]

poll([{fd=21, events=POLLIN|POLLPRI}], 1, 0) = 0 (Timeout)
write(21, "\221\0\0\0\3\n\t\tSELECT COUNT(DISTINCT(us"..., 149) = 149
read(21, "\1\0\0\1\3\37\0\0\2\3def\0\0\0\tusercount\0\f?\0\ 25\0"..., 16384) = 165
poll([{fd=21, events=POLLIN|POLLPRI}], 1, 0) = 0 (Timeout)
write(21, "\205\0\0\0\3\n\t\tSELECT COUNT(*) AS userc"..., 137) = 137
read(21, "\1\0\0\1\2\37\0\0\2\3def\0\0\0\tusercount\0\f?\0\ 25\0"..., 16384) = 127
poll([{fd=21, events=POLLIN|POLLPRI}], 1, 0) = 0 (Timeout)
write(21, "\205\0\0\0\3\n\t\tSELECT COUNT(*) AS userc"..., 137) = 137
read(21, "\1\0\0\1\2\37\0\0\2\3def\0\0\0\tusercount\0\f?\0\ 25\0"..., 16384) = 127
poll([{fd=21, events=POLLIN|POLLPRI}], 1, 0) = 0 (Timeout)
write(21, "\205\0\0\0\3\n\t\tSELECT COUNT(*) AS userc"..., 137) = 137
read(21, "\1\0\0\1\2\37\0\0\2\3def\0\0\0\tusercount\0\f?\0\ 25\0"..., 16384) = 127

please note those lines with "Timeout", I think this may be an important clue. Many lsphp5 process are waiting something and get timeout, this will cause high load. I guess maybe waiting for responses from MySQL. most likely code bug somewhere, cause high load under some conditions.