Re: tomcat java system cpu usage

Am 2013-12-10 18:53, schrieb Oliver Fromme:
> Eine Ferndiagnose ist bei solchen Dingen schwierig. Es kann
> alles Mögliche sein.
>
> Als erstes würde ich ein Update auf stable/10 versuchen. Es
> gibt da eine Reihe von Verbesserungen, die insbesondere auch
> hochparallele Systeme betreffen (und hw.ncpu=32 ist ja schon
> eine ganze Menge). Einen Versuch ist es wert.
>
freebsd-update auf das letzte 10-BETA oder besser make world und auf
10-stable?

10-BETA1 hatte ich schonmal probiert und das zeigte das selbe verhalten.
Also vermutlich doch ab auf 10-stable...

32 CPU's gehört hier mittlerweile zu unserer standard hardware. Und für
solr sogar sehr gut geeignet, weil solr komplett über die Menge an CPU's
skaliert. (zumindest unter Linux *grmbl*).

> Ich fasse mal Deine Beschreibung zusammen: Bei 50% Last (im
> Vergleich zum Linux-System) ist noch alles in Ordnung, bis
> auf geringfügig längere Antwortzeiten. Bei 100% Last dagegen
> läuft es komplett aus dem Ruder und die Antwortzeiten gehen
> massiv nach oben, bzw. die Kiste scheint zu "stehen".
>

Ganz genau. Wenn wir Last definieren als Menge and requests pro Sekunde.
Volle Last vom load balancer wären 90 bis 120 req/s, abhängig von der
Tageszeit.
Ein vergleichbares Linux system ist dann bei einer CPU load von 10 bis
15 CPU's.

Falls es interessiert, hier ein paar munin graphen:
http://mon.kernel32.de/solr/

> Das klingt nach einem Resourcen-Engpass bzw. nach einer Art
> Thrashing-Situation. Die Frage ist, was das Nadelöhr ist.
> 200k bis 250k syscalls sind zwar viel, aber nicht wahnsinnig
> viel; da habe ich schon "Schlimmeres" gesehen. Das sollte
> die Kiste nicht zum Umfallen bringen.
>

Hast du ein paar passende ktrace/kdump bzw truss shellscripte zur Hand?
Ansonsten würde ich probieren mir selber was zusammen zu stricken.
Ich bin mir aber nicht sicher wie.
Letztendlich müsste ich mir irgendwie die Anzahl der syscalls und die
zeiten die sie benötigen zusammen basteln. Einmal unter moderater load
und einmal in dem Fall wo die Kiste umkippt.

Es ist nur leider so, daß ktrace/truss/dtrace nicht zu meinen täglichen
tools gehören... von daher, jegliche shell schnipsel sind willkommen.
Ich lese mir danach auch die manpage durch was die parameter so tun ;-)

> In der vmstat-Ausgabe fallen eigentlich nur die hohen Werte
> bei der CPU-system-time auf, und die Anzahl der Prozesse, die
> "runnable" sind (erste Spalte). Alles andere ist mehr oder
> weniger im zu erwartenden Rahmen. Mein Verdacht ist, dass
> durch die hohe 32fach-Parallelität eine Kernel-Resource ans
> Limit gerät, so dass sich Threads blockieren.
>

Wenn man als theorie die Menge an pread aufrufen nimmt, könnte ich
nochmal mit systat/iostat nachschauen ob bei höherer load mehr auf der
Platte los ist.

Ein paar details zum disk backend:
Dec 5 13:07:02 ksolr47-10 kernel: ciss0: <HP Smart Array P220i> port
0x4000-0x40ff mem 0xf7d00000-0xf7dfffff,0xf7cf0000-0xf7cf03ff irq 34 at
device 0.0 on pci3
Dec 5 13:07:02 ksolr47-10 kernel: ciss0: PERFORMANT Transport
Dec 5 13:07:02 ksolr47-10 kernel: da0 at ciss0 bus 0 scbus0 target 0
lun 0

zpool status
   pool: tank
  state: ONLINE
   scan: none requested
config:

         NAME STATE READ WRITE CKSUM
         tank ONLINE 0 0 0
           da0p3 ONLINE 0 0 0

errors: No known data errors

NAME USED AVAIL REFER MOUNTPOINT
tank 13.4G 955G 31K none
tank/root 13.4G 955G 1.59G /
tank/root/tmp 86K 955G 86K /tmp
tank/root/var 11.8G 955G 11.8G /var

Interessant unter Umständen ist noch folgender Output aus
/var/log/messages:

Dec 10 10:31:06 ksolr47-10 kernel: sonewconn: pcb 0xfffffe0978ea4310:
Listen queue overflow: 151 already in queue awaiting acceptance
Dec 10 10:31:14 ksolr47-10 last message repeated 401 times
Dec 10 10:32:15 ksolr47-10 last message repeated 108 times
Dec 10 14:35:37 ksolr47-10 kernel: sonewconn: pcb 0xfffffe0978ea4310:
Listen queue overflow: 151 already in queue awaiting acceptance
Dec 10 14:36:02 ksolr47-10 last message repeated 981 times

Von den Uhrzeiten war das jeweils wenn ich den 2. Load Balancer dazu
geschaltet habe und daher von 50% traffic auf 100% traffic gegangen bin.
Ich würde aber eher annehmen, daß diese Meldung eine Folgeerscheinung
des "umfallens" sind. Die Maschine wird lahm, weil sie Ihre Zeit in
syscalls verbringt, varnish als load balancer leitet aber weiter traffic
hin und irgendwann ist der tomcat voll (http connector mit 1024
maxthreads).

Interessanter ist finde ich folgender Eintrag:
Dec 10 19:46:20 ksolr47-10 kernel: pid 32754 (java), uid 80: exited on
signal 5

Meine Testmaschine war weiter 50% im load balancing. Ab 18 Uhr wird der
traffic stärker. Scheinbar explodierte dann letztendlich die jvm.
SIGTRAP. Soso. Das habe ich noch nicht gesehen. Ich frage mich wo er den
core hingeworfen hat. Nicht in /usr/local/apache-tomcat* und nicht in
/var/tmp.

> Was läuft denn auf dem Rechner noch so? Ein Paketfilter (PF,
> IPFW)? Dummynet? NFS? Sonst irgendwas Spezielles?
>

Nichts spezielles. War ne default installation basierend auf mfsbsd.
Zusätzlich zum tomcat läuft lediglich openntpd für Zeit und munin für
graphen. Sonst nix.
Packet filter habe ich nicht konfiguriert, also sollten die ja aus sein.

meine rc.conf:

zfs_enable="YES"
sshd_enable="YES"
hostname="xxx.xxx.xxx"
defaultrouter="10.xxx.xxx.xxx"
ifconfig_ix0="UP"
ifconfig_ix1="UP"
cloned_interfaces="lagg0"
ifconfig_lagg0="laggproto failover laggport ix0 laggport ix1
10.xxx.xxx.xxx netmask xxx.xxx.xxx.xxx"

# ports
openntpd_enable="YES"
munin_node_enable="YES"
tomcat60_enable="YES"
tomcat60_java_version="1.7+"
tomcat60_catalina_log=">> /var/log/tomcat-server/catalina.log 2>>
/var/log/tomcat-server/catalina.err"
tomcat60_java_opts="-Xms4000m -Xmx4000m"

Soweit so gewöhnlich, oder?

Grüße und Danke,
Marian

To Unsubscribe: send mail to majordomo(at)de.FreeBSD.org
with "unsubscribe de-bsd-questions" in the body of the message
Received on Wed 11 Dec 2013 - 11:30:58 CET