AOL Webserver - Performance-Problems

This is Interesting: Free IT Magazines  
Home > Archive > AOL Webserver > December 2005 > Performance-Problems





You are viewing an archived Text-only version of the thread. To view this thread in it's original format and/or if you want to reply to this thread please [click here]

Author Performance-Problems
Nima Mazloumi

2005-12-24, 5:48 pm

Dear all,

we have problems with our aolserver installation and I was wondering if
someone could give us some insight.
Please find the details below.

Any help or comment appreciated!

Thank you very much,
Nima Mazloumi

Fujitsu Siemens
4 GB Ram
2 Broadcom Gigabit Ethernet Driver bcm5700 with Broadcom NIC Extension
(NICE) ver. 7.3.5
4 Intel(R) Xeon(TM) CPU 3.06GHz, L2 cache: 512K
200 GB Local disk and connection to 4 TB storage system

SuSE Linux 9.2
libhd version 9.31 (ia32)
Linux version 2.6.8-24.11-smp
AOLServer Version 4.0.10
PostgreSQL 7.4.8 (different box, same hardware specification)
OpenACS 5.1.4/dotLRN 2.1.1

We use pound as reverse proxy for SSL since we had problems with the SSL
module of the AOLServer.

Here details from the config.tcl:
ns_param maxconnections 100
ns_param keepalivetimeout 15
ns_param maxdropped 0
ns_param maxthreads 20
ns_param minthreads 20
ns_param threadtimeout 3600

I have around 115 concurrent users and all CPUs are at 95%.

A single page to return takes around 11sec, usually its 400ms and less.

top says:
top - 15:54:08 up 25 days, 31 min, 2 users, load average: 10.68,
12.49, 12.18
Tasks: 116 total, 2 running, 114 sleeping, 0 stopped, 0 zombie
Cpu0 : 91.1% us, 2.3% sy, 0.0% ni, 1.3% id, 3.3% wa, 0.3% hi,
1.7% si
Cpu1 : 77.6% us, 1.7% sy, 0.0% ni, 8.6% id, 12.2% wa, 0.0% hi,
0.0% si
Cpu2 : 94.1% us, 2.0% sy, 0.0% ni, 2.0% id, 2.0% wa, 0.0% hi,
0.0% si
Cpu3 : 80.1% us, 1.3% sy, 0.0% ni, 2.3% id, 16.2% wa, 0.0% hi,
0.0% si
Mem: 4073116k total, 3964908k used, 108208k free, 118244k buffers
Swap: 3911816k total, 60712k used, 3851104k free, 2895056k cached
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
root 16 0 1452 620 1276 S 0.3 0.0 6:00.33 syslogd
root 16 0 596 80 452 S 0.0 0.0 0:04.25
init

root RT 0 0 0 0 S 0.0 0.0 0:00.51
migration/0

root 34 19 0 0 0 S 0.0 0.0 0:00.31
ksoftirqd/0

root RT 0 0 0 0 S 0.0 0.0 0:00.87
migration/1

root 34 19 0 0 0 S 0.0 0.0 0:00.02 ksoftirqd/1

The nsd is somewhere at the bottom:
unima2 24 0 769m 706m 7204 S 0.0 17.8 0:36.82 0:36 nsd

vmstat:
20 0 63320 104472 305588 2555188 2 1 2 3 4 4 7
1 91 1
20 0 63320 99456 305588 2555188 0 0 0 85 1324 2839 96
2 2 0

When I shutdown the nsd the cpus have no load.

There are several waiting network connections at localhost:ndmp:
netstat|grep ndmp|grep WAIT |wc
340 2040 27540

PostgreSQL is on a different box. The cpus there have only a load of 10%
tcpip_socket = true
max_connections = 100
#superuser_reserved_connections = 2
port = 5432
#unix_socket_directory = ''
#unix_socket_group = ''
#unix_socket_permissions = 0777 # octal
#virtual_host = '' # what interface to listen on; defaults
to any
#rendezvous_name = '' # defaults to the computer name
#authentication_timeout = 60 # 1-600, in seconds
#ssl = false
#password_encryption = true
#krb_server_keyfile = ''
#db_user_namespace = false
shared_buffers = 1000 # min 16, at least max_connections*2,
8KB each
#sort_mem = 1024 # min 64, size in KB
#vacuum_mem = 8192 # min 1024, size in KB
#max_fsm_pages = 20000 # min max_fsm_relations*16, 6 bytes each
#max_fsm_relations = 1000 # min 100, ~50 bytes each
#max_files_per_process = 1000 # min 25
#preload_libraries = ''

PS AUX on webserver box:
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
root 1 0.0 0.0 596 180 ? S Oct19 0:01 init [3]
root 2 0.0 0.0 0 0 ? S Oct19 0:33 [migration/0]
root 3 0.0 0.0 0 0 ? SN Oct19 0:00 [ksoftirqd/0]
root 4 0.0 0.0 0 0 ? S Oct19 0:00 [migration/1]
root 5 0.0 0.0 0 0 ? SN Oct19 0:00 [ksoftirqd/1]
root 6 0.0 0.0 0 0 ? S Oct19 0:00 [migration/2]
root 7 0.0 0.0 0 0 ? SN Oct19 0:00 [ksoftirqd/2]
root 8 0.0 0.0 0 0 ? S Oct19 0:00 [migration/3]
root 9 0.0 0.0 0 0 ? SN Oct19 0:00 [ksoftirqd/3]
root 10 0.0 0.0 0 0 ? S< Oct19 0:00 [events/0]
root 11 0.0 0.0 0 0 ? S< Oct19 0:00 [events/1]
root 12 0.0 0.0 0 0 ? S< Oct19 0:00 [events/2]
root 13 0.0 0.0 0 0 ? S< Oct19 0:00 [events/3]
root 14 0.0 0.0 0 0 ? S< Oct19 0:00 [khelper]
root 15 0.0 0.0 0 0 ? S< Oct19 0:00 [netlink/0]
root 16 0.0 0.0 0 0 ? S< Oct19 0:00 [netlink/1]
root 17 0.0 0.0 0 0 ? S< Oct19 0:00 [netlink/2]
root 18 0.0 0.0 0 0 ? S< Oct19 0:00 [netlink/3]
root 19 0.0 0.0 0 0 ? S< Oct19 0:00 [kacpid]
root 44 0.0 0.0 0 0 ? S< Oct19 0:02 [kblockd/0]
root 45 0.0 0.0 0 0 ? S< Oct19 0:00 [kblockd/1]
root 46 0.0 0.0 0 0 ? S< Oct19 0:00 [kblockd/2]
root 47 0.0 0.0 0 0 ? S< Oct19 0:00 [kblockd/3]
root 58 0.0 0.0 0 0 ? S Oct19 0:08 [pdflush]
root 57 0.0 0.0 0 0 ? S Oct19 0:00 [kirqd]
root 59 0.0 0.0 0 0 ? S Oct19 0:14 [pdflush]
root 61 0.0 0.0 0 0 ? S< Oct19 0:00 [aio/0]
root 60 0.0 0.0 0 0 ? S Oct19 0:06 [kswapd0]
root 62 0.0 0.0 0 0 ? S< Oct19 0:00 [aio/1]
root 63 0.0 0.0 0 0 ? S< Oct19 0:00 [aio/2]
root 64 0.0 0.0 0 0 ? S< Oct19 0:00 [aio/3]
root 647 0.0 0.0 0 0 ? S Oct19 0:00 [kseriod]
root 1417 0.0 0.0 0 0 ? S Oct19 0:00 [scsi_eh_0]
root 1418 0.0 0.0 0 0 ? S Oct19 0:00 [ahd_dv_0]
root 1794 0.0 0.0 0 0 ? S Oct19 0:00 [scsi_eh_1]
root 2064 0.0 0.0 0 0 ? S Oct19 0:00 [scsi_eh_2]
root 2339 0.0 0.0 0 0 ? S Oct19 0:00 [md1_raid1]
root 2340 0.0 0.0 0 0 ? S Oct19 0:00 [md0_raid1]
root 2344 0.0 0.0 0 0 ? S< Oct19 0:03 [reiserfs/0]
root 2345 0.0 0.0 0 0 ? S< Oct19 0:00 [reiserfs/1]
root 2346 0.0 0.0 0 0 ? S< Oct19 0:00 [reiserfs/2]
root 2347 0.0 0.0 0 0 ? S< Oct19 0:01 [reiserfs/3]
root 2916 0.0 0.0 0 0 ? S Oct19 0:00 [khubd]
root 2943 0.0 0.0 1368 272 ? S<s Oct19 0:00 udevd
root 3306 0.0 0.0 1436 332 ? S Oct19 0:00 [hwscand]
root 3307 0.0 0.0 1436 328 ? S Oct19 0:00 [hwscand]
root 4080 0.0 0.0 1452 656 ? Ss Oct19 0:11
/sbin/syslogd -a /var/lib/ntp/dev/log
root 4098 0.0 0.0 1516 576 ? Ss Oct19 0:00
/sbin/klogd -c 1 -2 -x
nobody 4116 0.0 0.0 1416 396 ? Ss Oct19 0:00 /sbin/portmap
root 4117 0.0 0.0 2032 676 ? Ss Oct19 0:00 /sbin/resmgrd
root 4199 0.0 0.0 2072 700 ? Ss Oct19 0:00
/usr/sbin/xinetd
nobody 4202 0.0 0.0 1824 668 ? Ss Oct19 0:18
/usr/sbin/scanlogd
root 4263 0.0 0.0 5148 1836 ? Ss Oct19 0:01
/usr/sbin/sshd -o PidFile=/var/run/sshd.init.pid
postgres 4302 0.0 0.0 15016 2072 ? S Oct19 0:00
/usr/bin/postmaster -D /var/lib/pgsql/data
postgres 4308 0.0 0.0 9704 1928 ? S Oct19 0:00 postgres:
stats buffer process
postgres 4309 0.0 0.0 8712 1932 ? S Oct19 0:00 postgres:
stats collector process
ntp 4325 0.0 0.0 2740 2736 ? SLs Oct19 0:00
/usr/sbin/ntpd -p /var/lib/ntp/var/run/ntp/ntpd.pid -u ntp -i /var/lib/ntp
root 4367 0.0 0.0 1388 472 ? Ss Oct19 0:00
/usr/sbin/acpid -c /etc/acpi/events.ignore
root 4416 0.0 0.0 2508 1068 ? S Oct19 0:00
/usr/sbin/powersaved -d -x /usr/lib/powersave/scripts -a resmgr -v 3
at 4486 0.0 0.0 1632 608 ? Ss Oct19 0:00 /usr/sbin/atd
root 4495 0.0 0.0 43068 804 ? Ssl Oct19 0:00
/usr/sbin/nscd
root 4507 0.0 0.0 0 0 ? S Oct19 0:00
[afs_rxlistener]
root 4509 0.0 0.0 0 0 ? S Oct19 0:00
[afs_callback]
root 4511 0.0 0.0 0 0 ? S Oct19 0:00 [afs_rxevent]
root 4513 0.0 0.0 0 0 ? S Oct19 0:00 [afsd]
root 4515 0.0 0.0 0 0 ? S Oct19 0:00
[afs_checkserver]
root 4518 0.0 0.0 0 0 ? S Oct19 0:00
[afs_background]
root 4519 0.0 0.0 0 0 ? S Oct19 0:00
[afs_background]
root 4521 0.0 0.0 0 0 ? S Oct19 0:00
[afs_background]
root 4523 0.0 0.0 0 0 ? S Oct19 0:00
[afs_cachetrim]
root 4590 0.0 0.0 4572 1356 ? Ss Oct19 0:02
/usr/lib/postfix/master
postfix 4603 0.0 0.0 4832 1572 ? S Oct19 0:03 qmgr -l
-t fifo -u
root 4842 0.0 0.0 1664 612 ? Ss Oct19 0:00
/usr/sbin/cron
root 4856 0.0 0.0 1600 464 tty2 Ss+ Oct19 0:00
/sbin/mingetty tty2
root 4857 0.0 0.0 1600 464 tty3 Ss+ Oct19 0:00
/sbin/mingetty tty3
root 4858 0.0 0.0 1600 464 tty4 Ss+ Oct19 0:00
/sbin/mingetty tty4
root 4859 0.0 0.0 1600 464 tty5 Ss+ Oct19 0:00
/sbin/mingetty tty5
root 4860 0.0 0.0 1600 464 tty6 Ss+ Oct19 0:00
/sbin/mingetty tty6
root 5379 0.0 0.0 1432 280 ? S< Oct19 0:00 [hwscand]
root 5442 0.0 0.0 10276 3128 ? Ss Oct19 0:00
/usr/local/apache2/bin/httpd -f /usr/local/apache2/conf/httpd.conf -k start
root 5456 0.0 0.0 3624 1336 ? S Oct19 0:00
/usr/local/sbin/pound
root 5457 0.0 0.1 18100 4928 ? Sl Oct19 0:11
/usr/local/sbin/pound
unima2 5492 0.0 13.5 868504 550916 ? Ssl Oct19 0:55
/opt/aolserver4/bin/nsd -u unima2 -t /www/unima2/etc/config.tcl
root 5753 0.0 0.0 1600 464 tty1 Ss+ Oct19 0:00
/sbin/mingetty --noclear tty1
wwwrun 8073 0.0 0.0 10568 3928 ? S Oct19 0:00
/usr/local/apache2/bin/httpd -f /usr/local/apache2/conf/httpd.conf -k start
root 11178 0.0 0.0 1672 612 ? S Oct19 0:00
/usr/sbin/cron
root 11179 0.0 0.0 2364 1060 ? Ss Oct19 0:00 /bin/sh
-c /home/unima2/bin/unima2-analyze.sh
root 11182 0.0 1.1 48508 44848 ? S Oct19 0:42
/usr/share/analog-5.32/analog -G -g/www/unima2/etc/analog.cfg
root 16364 0.0 0.0 4584 1156 ? S 00:55 0:00
/usr/sbin/sendmail -FCronDaemon -odi -oem -oi -t
root 16365 0.0 0.0 4568 1292 ? S 00:55 0:00
/usr/sbin/postdrop -r
root 6458 0.0 0.0 8540 2448 ? Ss 10:02 0:00 sshd:
kredel [priv]
kredel 6464 0.0 0.0 8580 2596 ? S 10:02 0:00 sshd:
kredel@pts/1
kredel 6465 0.0 0.0 4136 1768 pts/1 Ss 10:02 0:00 -bash
wwwrun 18759 0.0 0.1 10568 4088 ? S 10:45 0:00
/usr/local/apache2/bin/httpd -f /usr/local/apache2/conf/httpd.conf -k start
root 22285 0.0 0.0 2592 1128 pts/1 S 10:57 0:00 su -
root 22305 0.0 0.0 2848 1700 pts/1 S+ 10:57 0:00 -bash
wwwrun 24782 0.0 0.1 10576 4092 ? S 11:06 0:00
/usr/local/apache2/bin/httpd -f /usr/local/apache2/conf/httpd.conf -k start
root 1982 0.0 0.0 9684 3028 pts/1 Sl 11:33 0:00
/usr/bin/dsmc schedule
wwwrun 3642 0.0 0.0 10552 4068 ? S 13:34 0:00
/usr/local/apache2/bin/httpd -f /usr/local/apache2/conf/httpd.conf -k start
wwwrun 3719 0.0 0.0 10560 4000 ? S 13:35 0:00
/usr/local/apache2/bin/httpd -f /usr/local/apache2/conf/httpd.conf -k start
wwwrun 12425 0.0 0.0 10572 4064 ? S 14:06 0:00
/usr/local/apache2/bin/httpd -f /usr/local/apache2/conf/httpd.conf -k start
wwwrun 16396 0.0 0.0 10564 3968 ? S 14:22 0:00
/usr/local/apache2/bin/httpd -f /usr/local/apache2/conf/httpd.conf -k start
wwwrun 29376 0.0 0.0 10572 3972 ? S 15:06 0:00
/usr/local/apache2/bin/httpd -f /usr/local/apache2/conf/httpd.conf -k start
wwwrun 31241 0.0 0.0 10348 3416 ? S 15:12 0:00
/usr/local/apache2/bin/httpd -f /usr/local/apache2/conf/httpd.conf -k start
root 6283 0.0 0.0 8684 2524 ? Ss 15:46 0:00 sshd:
root@pts/0
root 6308 0.0 0.0 2856 1744 pts/0 Ss 15:46 0:00 -bash
postfix 8938 0.0 0.0 4688 1520 ? S 15:47 0:00 pickup -l
-t fifo -u
wwwrun 12585 0.0 0.0 10496 3772 ? S 15:55 0:00
/usr/local/apache2/bin/httpd -f /usr/local/apache2/conf/httpd.conf -k start
postfix 18010 0.0 0.0 5068 1940 ? S 16:13 0:00 cleanup
-z -t unix -u
postfix 18011 0.0 0.0 5032 1864 ? S 16:13 0:00
trivial-rewrite -n rewrite -t unix -u
postfix 18012 0.0 0.0 4792 1660 ? S 16:13 0:00 smtp -t
unix -u
root 18264 0.0 0.0 2376 716 pts/0 R+ 16:14 0:00 ps aux


Daniël Mantione

2005-12-24, 5:48 pm

Dossy Shiobara

2005-12-24, 5:48 pm

On 2005.10.20, Nima Mazloumi <nima.mazloumi@GMX.DE> wrote:
>
> we have problems with our aolserver installation and I was wondering if
> someone could give us some insight.
> Please find the details below.

Lets see what we see ...

[...]
> I have around 115 concurrent users and all CPUs are at 95%.
>
> A single page to return takes around 11sec, usually its 400ms and
> less.
>
> top says:
[...]
> PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
> root 16 0 1452 620 1276 S 0.3 0.0 6:00.33 syslogd

What's being written to syslog that it's eating 0.3% of your CPU (and
seems to be the biggest user of CPU during this snapshot)?

> The nsd is somewhere at the bottom:
> unima2 24 0 769m 706m 7204 S 0.0 17.8 0:36.82 0:36 nsd

It's practically sleeping - 0.0% of CPU? Maybe you need to upgrade
"top" -- is it mis-reporting what's really going on?

> When I shutdown the nsd the cpus have no load.
>
> There are several waiting network connections at localhost:ndmp:
> netstat|grep ndmp|grep WAIT |wc
> 340 2040 27540

340 waiting connections? Hmm ...

> PS AUX on webserver box:
> USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
[...]

First, a few thoughts: this is the webserver box? It's running both
AOLserver and Apache 2. It's running both Sendmail and Postfix. It has
PostgreSQL running as well. It's also running Analog.

Everything is showing up as 0.0% CPU -- how can this be right? Perhaps
you need to upgrade your procps tools. Or, it's a bug -- sounds like
this one:

Bugzilla Bug 111300 -- proc's accounting of CPU and memory
utilization wrong under NPTL
https://bugzilla.redhat.com/bugzill...g.cgi?id=111300

The fact that you say when you shut the nsd down, the CPUs go quiet
means that the nsd could be the culprit. Can you get onto the control
port (nscp) and capture the output of:

nscp> join [ns_info threads] \n

at the time the machine is in this state?

-- Dossy

--
Dossy Shiobara dossy@panoptic.com | http://dossy.org/
Panoptic Computer Network http://panoptic.com/
"He realized the fastest way to change is to laugh at your own
folly -- then you can let go and quickly move on." (p. 70)


Nima Mazloumi

2005-12-24, 5:48 pm

Unfortunately the number of concurrent users dropped to 56 which
significantly increased performance.

Its the webserver box. Most of the log was pound doing. I turned that off
without any improvment. The local Postgres was not needed and was
turned off as well. no result.

Here is what "ns_info threads" says:
-sched:idle2- -sched- 1513163696 0 1129736468 p:0x4003f7c3 a:0x2
-sched:idle1- -sched- 1436511152 0 1129735868 p:0x4003f7c3 a:0x1
-sched:idle0- -sched- 1103592368 0 1129735619 p:0x4003f7c3 a:0x0
-driver- -main- 1103330224 0 1129735575 p:0x40032156 a:0x0
-conn:unima2::17 -main- 1103068080 0 1129735575 ns:connthread {}
-conn:unima2::18 -main- 1102805936 0 1129735575 ns:connthread {}
-conn:unima2::19 -main- 1102543792 0 1129735575 ns:connthread {}
-conn:unima2::16 -main- 1102281648 0 1129735575 ns:connthread {}
-conn:unima2::15 -main- 1102019504 0 1129735575 ns:connthread {}
-conn:unima2::14 -main- 1101757360 0 1129735575 ns:connthread {}
-conn:unima2::13 -main- 1101495216 0 1129735575 ns:connthread {}
-conn:unima2::12 -main- 1101233072 0 1129735575 ns:connthread {}
-conn:unima2::11 -main- 1100970928 0 1129735575 ns:connthread {268055
127.0.0.1 running POST /ds/shell 0.33016 0}
-conn:unima2::10 -main- 1100708784 0 1129735575 ns:connthread {}
-conn:unima2::9 -main- 1100446640 0 1129735575 ns:connthread {}
-conn:unima2::8 -main- 1100184496 0 1129735575 ns:connthread {}
-conn:unima2::7 -main- 1099922352 0 1129735575 ns:connthread {}
-conn:unima2::6 -main- 1099660208 0 1129735575 ns:connthread {}
-conn:unima2::5 -main- 1099398064 0 1129735575 ns:connthread {}
-conn:unima2::4 -main- 1099135920 0 1129735575 ns:connthread {}
-conn:unima2::3 -main- 1098873776 0 1129735575 ns:connthread {}
-conn:unima2::2 -main- 1098611632 0 1129735575 ns:connthread {}
-conn:unima2::1 -main- 1098349488 0 1129735575 ns:connthread {}
-conn:unima2::0 -main- 1098087344 0 1129735575 ns:connthread {}
-sched- -main- 1078913968 0 1129735509 p:0x4003f990 a:0x0
-main- {} 1076269184 1 1129735508 p:0x0 a:0x0


Nima Mazloumi

2005-12-24, 5:48 pm

Again I have 117 connections and My Startpage takes 22sec to render. Very=
=20
strange is that CPU load is extremely high but nsd does seem to occupy=20
cpus at all which it actually does. If I shutdown nsd all load is gone.

-conn:unima2::44 -driver- -2107114576 0 1130140236 ns:connthread {}
-conn:unima2::43 -driver- -2107376720 0 1130140236 ns:connthread {}
-conn:unima2::42 -driver- -2109789264 0 1130140235 ns:connthread {}
-conn:unima2::41 -driver- -2126001232 0 1130140235 ns:connthread {507973=20
127.0.0.1 running GET /threads 0.50319 0}
-conn:unima2::40 -driver- -2127299664 0 1130140235 ns:connthread {}
-conn:unima2::39 -driver- -2147079248 0 1130140038 ns:connthread {}
-conn:unima2::38 -driver- -2038170704 0 1130140038 ns:connthread {}
-conn:unima2::37 -driver- -2104230992 0 1130140036 ns:connthread {}
-conn:unima2::36 -driver- 2061761456 0 1130140036 ns:connthread {507958=20
127.0.0.1 running GET /register/ 1.977021 0}
-conn:unima2::35 -driver- -2114049104 0 1130140036 ns:connthread {}
-conn:unima2::34 -driver- -2125546576 0 1130140035 ns:connthread {}
-conn:unima2::33 -driver- -2130646096 0 1130140035 ns:connthread {}
-conn:unima2::32 -driver- 2144074672 0 1130140034 ns:connthread {507957=20
127.0.0.1 running=20
GET /dotlrn/clubs/handelsundsteuerbilanzenimgrundstudium/forums/forum-vie=
w=20
2.186026 0}
-conn:unima2::31 -driver- 2143812528 0 1130140034 ns:connthread {}
-conn:unima2::30 -driver- 2143550384 0 1130140034 ns:connthread {}
-conn:unima2::29 -driver- 2119613360 0 1130140031 ns:connthread {}
-conn:unima2::28 -driver- 2119351216 0 1130140031 ns:connthread {}
-conn:unima2::27 -driver- 2116955056 0 1130140031 ns:connthread {}
-conn:unima2::26 -driver- 2082405296 0 1130140027 ns:connthread {}
-conn:unima2::25 -driver- 2053057456 0 1130140027 ns:connthread {}
-conn:unima2::24 -driver- 2023615408 0 1130140025 ns:connthread {}
-conn:unima2::23 -driver- 1722084272 0 1129897013 ns:connthread {}
-conn:unima2::22 -driver- 1543383984 0 1129887634 ns:connthread {507955=20
127.0.0.1 running GET=20
{/dotlrn/classes/fakultaetfuervolkswirtschaftslehre/lehrstuhlfuervolkswir=
ts
chaftslehreinsbesonderemik=E7 @ﾰ 7ﾡ ^ @ﾣ 7ﾡ
} 2.499641 0}
-conn:unima2::21 -driver- 1536109488 0 1129887633 ns:connthread {}
-conn:unima2::20 -driver- 1438043056 0 1129887632 ns:connthread {}
-sched:idle3- -sched- 1490471856 0 1129887005 p:0x4003f7c3 a:0x3
-sched:idle2- -sched- 1432841136 0 1129886405 p:0x4003f7c3 a:0x2
-sched:idle1- -sched- 1320037296 0 1129886165 p:0x4003f7c3 a:0x1
-sched:idle0- -sched- 1101683632 0 1129886157 p:0x4003f7c3 a:0x0
-driver- -main- 1101421488 0 1129886112 p:0x40032156 a:0x0
-conn:unima2::19 -main- 1101159344 0 1129886112 ns:connthread {}
-conn:unima2::18 -main- 1100897200 0 1129886112 ns:connthread {507960=20
127.0.0.1 running POST=20
{/dotlrn/classes/fakultaetfuerbetriebswirtschaftslehre/lehrstuhlfuerabwli=
nd
ustrieproduktionswirtschaf=E7 @ﾨ"7ﾡ ^ @ﾛ"7ﾡ
} 1.819094 0}
-conn:unima2::17 -main- 1100635056 0 1129886112 ns:connthread {}
-conn:unima2::16 -main- 1100372912 0 1129886112 ns:connthread {}
-conn:unima2::15 -main- 1100110768 0 1129886112 ns:connthread {}
-conn:unima2::14 -main- 1099848624 0 1129886112 ns:connthread {}
-conn:unima2::13 -main- 1099586480 0 1129886112 ns:connthread {}
-conn:unima2::12 -main- 1099324336 0 1129886112 ns:connthread {}
-conn:unima2::11 -main- 1099062192 0 1129886112 ns:connthread {}
-conn:unima2::10 -main- 1098800048 0 1129886112 ns:connthread {}
-conn:unima2::9 -main- 1098537904 0 1129886112 ns:connthread {}
-conn:unima2::8 -main- 1098275760 0 1129886112 ns:connthread {}
-conn:unima2::7 -main- 1098013616 0 1129886112 ns:connthread {}
-conn:unima2::6 -main- 1097751472 0 1129886112 ns:connthread {}
-conn:unima2::5 -main- 1097489328 0 1129886112 ns:connthread {}
-conn:unima2::4 -main- 1097227184 0 1129886112 ns:connthread {}
-conn:unima2::3 -main- 1096965040 0 1129886112 ns:connthread {}
-conn:unima2::2 -main- 1096702896 0 1129886112 ns:connthread {}
-conn:unima2::1 -main- 1096440752 0 1129886112 ns:connthread {507948=20
127.0.0.1 running GET=20
{/dotlrn/classes/fakultaetfuerbetriebswirtschaftslehre/lehrstuhlfuerabwli=
nd
ustrieproduktionswirtschaf=E7 @:9cﾦ ^ @-9cﾦ
} 3.506204 0}
-conn:unima2::0 -main- 1096178608 0 1129886112 ns:connthread {}
-sched- -main- 1078913968 0 1129886065 p:0x4003f990 a:0x0
-main- {} 1076269184 1 1129886065 p:0x0 a:0x0


TOP:
top - 11:08:48 up 2 days, 23:58, 2 users, load average: 19.23, 20.66,=20
25.00
Tasks: 110 total, 3 running, 107 sleeping, 0 stopped, 0 zombie
Cpu0 : 93.5% us, 2.6% sy, 0.0% ni, 1.0% id, 1.6% wa, 0.3% hi, 1.0%=
=20
si
Cpu1 : 95.7% us, 2.6% sy, 0.0% ni, 1.0% id, 0.7% wa, 0.0% hi, 0.0%=
=20
si
Cpu2 : 95.4% us, 2.0% sy, 0.0% ni, 2.0% id, 0.7% wa, 0.0% hi, 0.0%=
=20
si
Cpu3 : 96.1% us, 2.0% sy, 0.0% ni, 1.0% id, 0.7% wa, 0.0% hi, 0.3%=
=20
si
Mem: 4073112k total, 3932156k used, 140956k free, 104320k buffers
Swap: 3911816k total, 600680k used, 3311136k free, 2339480k cached

PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ =20
COMMAND =
=20
5373 unima2 25 0 1645m 1.1g 7344 S 0.0 27.9 0:35.60=20
nsd =
=20
5315 root 15 0 61624 16m 2928 S 0.0 0.4 0:23.37=20
pound =
=20
4775 root 16 0 73824 12m 6980 S 0.0 0.3 0:10.66=20
dsmc =
=20
30560 wwwrun 16 0 10580 3748 8640 S 0.0 0.1 0:00.03=20
httpd =
=20
20026 wwwrun 16 0 10564 3648 8640 S 0.0 0.1 0:00.04=20
httpd =
=20
18476 wwwrun 16 0 10592 3632 8640 S 0.0 0.1 0:00.04=20
httpd =
=20
8870 wwwrun 16 0 10500 3624 8640 S 0.0 0.1 0:00.05=20
httpd =
=20
16788 wwwrun 16 0 10640 3620 8640 S 0.0 0.1 0:00.04=20
httpd =
=20
20020 wwwrun 16 0 10652 3596 8640 S 0.0 0.1 0:00.03=20
httpd =
=20
5021 wwwrun 16 0 10596 3588 8640 S 0.0 0.1 0:00.01=20
httpd =
=20
28267 wwwrun 16 0 10500 3408 8640 S 0.0 0.1 0:00.02=20
httpd =
=20
16889 wwwrun 16 0 10500 3372 8640 S 0.0 0.1 0:00.02=20
httpd =20


Nima Mazloumi

2005-12-24, 5:48 pm

Here an example for the Startpage:
17.623 ms/33 db/1.754 ms

Request Processor
+0.1 ms: Applied GET filter: (for /dotlrn/ curriculum::curriculum_filter) -
0.0 ms
returned filter_ok
+0.1 ms: Trying rp_serve_abstract_file /www/unima2/www/dotlrn/
+0.1 ms: File /www/unima2/www/dotlrn/: Directory index
+0.1 ms: Applied transformation from /www/unima2/www/dotlrn/ -
> /www/unima2/www/dotlrn/ - 0.0 ms
+0.1 ms: Trying rp_serve_abstract_file /www/unima2/packages/dotlrn/www/
+0.1 ms: Served file /www/unima2/packages/dotlrn/www/index.adp with
adp_parse_ad_conn_file - 17.6 ms
+17.7 ms: Applied GET filter: (for /dotlrn/ ds_trace_filter) - 0.0 ms
returned filter_ok


Bas Scheffers

2005-12-24, 5:48 pm

Nima Mazloumi said:
> Again I have 117 connections and My Startpage takes 22sec to render. Very
> strange is that CPU load is extremely high but nsd does seem to occupy
> cpus at all which it actually does. If I shutdown nsd all load is gone.
Could it be CPU is used by some other process becuase of nsd? Have you
done a "vmstat 1 60" to see how much disk access is going on and how many
processes waiting?

Also, top shows 1.1g resident memory for nsd. That seems excessive. Is
this normal for your setup? Sure you don't have a memory leak? (Wrong Tcl
version, or using something like tdom with cleanin up)

Just my thought,
Bas.


Andrew Piskorski

2005-12-24, 5:48 pm

On Mon, Oct 24, 2005 at 05:05:24AM -0400, Nima Mazloumi wrote:
> Again I have 117 connections and My Startpage takes 22sec to render. Very
> strange is that CPU load is extremely high but nsd does seem to occupy
> cpus at all which it actually does. If I shutdown nsd all load is gone.

Did you check and fix the problem with your number of database
connections which Don Baccus pointed out?

On Mon, Oct 24, 2005 at 05:18:04AM -0400, Nima Mazloumi wrote:
> Here an example for the Startpage:
> 17.623 ms/33 db/1.754 ms

This example shows no problem at all, as it appears to be blazingly
fast at under 0.02 seconds, not the 22 s you complain about above.
Thus this example is useless. Do you have a Developer Support trace
for a page that was actually slow?

If you can replicate the problem, you can probably fix it. If you
can't replicate it, you're going to have a lot more trouble...

You said before that, "A single page to return takes around 11 sec,
usually its 400 ms and less." How do you know that? Were you looking
at the page yourself and saw it run for 11 s? (In which case, what
did Developer Support say?) Or are you concluding that from the
AOLserver access log, or what?

--
Andrew Piskorski <atp@piskorski.com>
http://www.piskorski.com/


Dossy Shiobara

2005-12-24, 5:48 pm

On 2005.10.24, Nima Mazloumi <nima.mazloumi@GMX.DE> wrote:
> Here an example for the Startpage:
> 17.623 ms/33 db/1.754 ms

Is that 17.6 msec, or 17.6 seconds? 17 msec for page construction is
VERY reasonable (and probably only possible for small static files).
I'm guessing it's really 17.7 seconds.

> Request Processor
....
> +0.1 ms: Served file /www/unima2/packages/dotlrn/www/index.adp with
> adp_parse_ad_conn_file - 17.6 ms

Guess it's time to start looking inside adp_parse_ad_conn_file and see
why it's taking up almost 100% of the request processing time.

-- Dossy

--
Dossy Shiobara dossy@panoptic.com | http://dossy.org/
Panoptic Computer Network http://panoptic.com/
"He realized the fastest way to change is to laugh at your own
folly -- then you can let go and quickly move on." (p. 70)


Bas Scheffers

2005-12-24, 5:48 pm

Dossy Shiobara said:
> Is that 17.6 msec, or 17.6 seconds? 17 msec for page construction is
It's a Europeanism, we use dots for grouping and commas between integer
and decimals. I guess that is what is being used here too.

Bas.


Sponsored Links






Free braindumps | Software forum | Database administration forum

Copyright 2003 - 2008 webservertalk.com