PDA

Bekijk Volledige Versie : Tomcat soms traag met antwoorden



bami82
14/09/09, 16:27
Beste WHT'ers,

Ik heb een setup met 2 tomcat servers die gelijk zijn geconfigureerd. Beide hebben een klein probleem, als ik een pagina open zit er af en toe een delay van tussen de 3 en de 8 seconde op voordat tomcat reageert.

Dit kan ik simuleren door simpel een wget te doen van de default tomcat index.jsp pagina. Ik heb echt geen idee wat dit veroorzaakt. Machine is niet super druk. Het gaat hier om een telefonie applicatie dus het is erg vervelend als er een paar seconde stilte valt zo af en toe. (4 a 5 op de 100 keer). Heeft iemand een idee wat het probleem kan zijn?



Attaching to process ID 1418, please wait...
Debugger attached successfully.
Server compiler detected.
JVM version is 1.5.0_06-b05

using parallel threads in the new generation.
using thread-local object allocation.
Concurrent Mark-Sweep GC

Heap Configuration:
MinHeapFreeRatio = 40
MaxHeapFreeRatio = 70
MaxHeapSize = 2147483648 (2048.0MB)
NewSize = 4194304 (4.0MB)
MaxNewSize = 96468992 (92.0MB)
OldSize = 12582912 (12.0MB)
NewRatio = 15
SurvivorRatio = 1024
PermSize = 209715200 (200.0MB)
MaxPermSize = 419430400 (400.0MB)

Heap Usage:
New Generation (Eden + 1 Survivor Space):
capacity = 96403456 (91.9375MB)
used = 15409864 (14.695991516113281MB)
free = 80993592 (77.24150848388672MB)
15.984763035881203% used
Eden Space:
capacity = 96337920 (91.875MB)
used = 15409864 (14.695991516113281MB)
free = 80928056 (77.17900848388672MB)
15.995637024340986% used
From Space:
capacity = 65536 (0.0625MB)
used = 0 (0.0MB)
free = 65536 (0.0625MB)
0.0% used
To Space:
capacity = 65536 (0.0625MB)
used = 0 (0.0MB)
free = 65536 (0.0625MB)
0.0% used
concurrent mark-sweep generation:
capacity = 2051014656 (1956.0MB)
used = 171451808 (163.50918579101562MB)
free = 1879562848 (1792.4908142089844MB)
8.35936532673904% used
Perm Generation:
capacity = 209715200 (200.0MB)
used = 73634952 (70.22376251220703MB)
free = 136080248 (129.77623748779297MB)
35.111881256103516% used




load averages: 0.54, 0.79, 0.75; up 18+04:55:53 15:24:42
115 processes: 113 sleeping, 2 on cpu
CPU states: 98.7% idle, 1.0% user, 0.3% kernel, 0.0% iowait, 0.0% swap
Memory: 8064M phys mem, 4583M free mem, 2002M swap, 2002M free swap

PID USERNAME LWP PRI NICE SIZE RES STATE TIME CPU COMMAND
1418 sfe 182 0 0 2528M 546M cpu 65.7H 24.83% java
1528 sfe 51 59 0 236M 93M sleep 78:35 2.95% java
1049 mysql 74 59 0 136M 113M sleep 360:49 2.13% mysqld
1061 root 1 59 0 18M 16M sleep 15:11 0.51% httpd
3448 sfe 1 49 0 3336K 2656K cpu 0:00 0.49% top
3451 nobody 1 59 0 18M 4400K sleep 0:00 0.28% httpd
3449 nobody 1 59 0 18M 4400K sleep 0:00 0.24% httpd
1145 noaccess 55 59 0 215M 127M sleep 37:15 0.24% java
3452 nobody 1 59 0 18M 4400K sleep 0:00 0.21% httpd
3455 nobody 1 59 0 18M 3672K sleep 0:00 0.14% httpd
3456 nobody 1 59 0 18M 3672K sleep 0:00 0.14% httpd
3450 sfe 1 53 2 1336K 1136K sleep 0:00 0.13% sleep
3457 nobody 1 59 0 18M 3672K sleep 0:00 0.13% httpd
3458 nobody 1 59 0 18M 3672K sleep 0:00 0.13% httpd
3459 sfe 1 53 2 1336K 1136K sleep 0:00 0.13% sleep





Deze is goed

15:34:12 (62.92 MB/s) - `index.jsp.36' saved [8132/8132]

--15:34:17-- http://localhost:8080/index.jsp
=> `index.jsp.37'
Resolving localhost... 127.0.0.1, ::1
Connecting to localhost|127.0.0.1|:8080... connected.
HTTP request sent, awaiting response... 200 OK
Length: 8,132 (7.9K) [text/html]

100%[================================================== ======================================>] 8,132 --.--K/s

15:34:17 (63.59 MB/s) - `index.jsp.37' saved [8132/8132]


Deze heeft 4 seconde vertraging

--15:34:22-- http://localhost:8080/index.jsp
=> `index.jsp.38'
Resolving localhost... 127.0.0.1, ::1
Connecting to localhost|127.0.0.1|:8080... connected.
HTTP request sent, awaiting response... 200 OK
Length: 8,132 (7.9K) [text/html]

100%[================================================== ======================================>] 8,132 --.--K/s

15:34:26 (45.89 MB/s) - `index.jsp.38' saved [8132/8132]

MMaI
14/09/09, 17:58
zi je niet aan je max connections of max handles op het moment dat je moet wachten?
test eens als er niemand op de telefooncentrale zit ingelogd (of jij als enige) om te zien of het probleem zich nog steeds voordoet.

staat er ook niks in de error logs van tomcat? evt kun je loglevel verhogen naar debug (zie ook http://tomcat.apache.org/tomcat-5.5-doc/logging.html)

kjkoster
14/09/09, 18:03
Dag bami82,

Er goed dat je een duidelijke en reproduceerbare test heb voor dit ongrijpbare probleem. Je schetst echter een probleem waar niemand zonder meer informatie een antwoord op kan geven. Maar dat mag de pret niet drukken. :-)

In de GC stats die je toont mis ik vooral het tijds-aspect. Het is een moment opname. Ze zien er wel ok uit, overigens. Ik verwacht dat het probleem niet daar zit, maar omdat dit een moment opname is kan ik dat niet met zekerheid zeggen.

Ik zou je willen aanraden om de Java-monitor probe te installeren. Je krijgt dan een grafiek van twee dagen met daarin het gedrag van je garbage collectors. Dat is een stuk duidelijker. Als je wilt zien hoe dat er uit ziet: http://java-monitor.com/livedemo.html en klik op een van de hosts om meer detail te zien. Installatie en wat meer uitleg staat op http://java-monitor.com/install.html . (bonus: gratis een mailtje als de server down gaat)

DISCLAIMER: ik ben de operator van Java-monitor.

Verder is de context van de Tomcat servers onduidelijk. Die index.jsp, wat doettie allemaal? Databases? Webservices? Alleen hello world?

Is het een shared machine? Virtuele machine waar een andere virtuele machine alle I/O van opvreet? VPS memory over-ge-commit waardoor de VPS moet worden ingeswapt voor jouw request?

Kees Jan

bami82
14/09/09, 22:00
Hoi Kees Jan,

Bedankt voor je antwoord. Ik zal morgen is naar dat java-monitor kijken.

Het is een Sun Fire T2000, 8 cores, 32 threads, 8GB RAM, niet gevirtualiseerd. Draaien eigenlijk alleen tomcat apps op deze machine + mysql. De index.jsp is de default start pagina van tomcat dus geen db of iets dergelijks. MySQL draait alleen wat kleine db's en veroorzaakt ook weinig load verder.

I/O valt volgens mij allemaal wel mee maar zal ik morgen voor de zekerheid even checken.

kjkoster
14/09/09, 22:15
Dag bami82,

Hier zijn wat checks die je met Java-monitor kunt doen. http://java-monitor.com/forum/showthread.php?goto=newpost&t=560 hoewel jouw VM op 8 cores al automatisch de server JVM pakt.

Kees Jan

baahmi
14/09/09, 23:01
Vertragingen die zo lang duren hebben meestal met Garbage collection te maken (tenzij je server brak is, maar daar ga ik even niet vanuit).
Goede links om mee te starten :
http://java.sun.com/docs/hotspot/gc5.0/ergo5.html
http://java.sun.com/docs/hotspot/gc5.0/gc_tuning_5.html

Of je kan proberen met java6 die aardig wat intelligentie heeft ingebouwd om optimaal te gedragen.

Java IO is ook altijd interessant te bekijken : http://wiki.sdn.sap.com/wiki/display/Java/JPicus is een nuttige tool daarvoor

wonko
16/09/09, 09:55
je kan misschien ook even kijken naar slechte/trage resolving op de server!

bami82
16/09/09, 10:12
je kan misschien ook even kijken naar slechte/trage resolving op de server!

Hoi Wonko, agenzien ik wgets do op localhost en daarmee het probleem kan simuleren lijkt dit me niet mogelijk.