Dear friends,
It is my first post. And I will not try to annoy you.
I have a customer with:
PIV - 2.4 Ghz (monoprocessor)
40 Gb Ide
750Mb Ram
Which I install:
Red Hat 9.0
Jabberd 2.0s3
SSL
MYSQL
EXODUS in PCs
DaemonTools
They have 250 users spread in a WAN with 4 points, using Frame-relay.
Problem:
Before it was running in PIV -1.8 Ghz together with SAMBA 2.0. After the 60th user creation and their respective logins, the server crashed. At that time it was Jabberd 2.0s1. I installed Daemontools to assure that we do not need to rerun dropped services manually, and the server managed to work with at maximum 100 users. During the entire process, I ran TOP and see 99,99% cpu usage in both SM and MYSQL processes.
So I changed to a brand new machine as described in the begin (PIV 2.4).
For about 4 days it was running using 2% CPU, but increasing the memory usage dramatically until crash.
So I created a script to shutdown all jabberd and daemontools services, but it was inefficient.
By now, as soon as the number of users reaches 160, the C2S crashed and all EXODUS client take a lot of time to reconnect, put me in big annoyances.
Also I have created a analyzer which take a picture of whom is connected, top analysis(memory,cpu,disks), content of the last 100 lines of /var/log and I need someone who works with JABBERD to help me in discover this problem. This analyzer run each 1 minute, in order to have strong information.
Do you have any suggestion?
I have the entire process described and my doubt could help anyone in charge to put an Instant Messaging up and running.
My email is jclaudelino at gmail dot com or jclaudelino at hotmail dot com
Regards,
Jose Claudio
Example of the log (real one, just a sample of its main parts):
LOG JABBERD - 2004-10-22.15-28-01
.........
PID %CPU TIME %MEM SIZE
jabber client connections: non-encrypted
========================================
tcp 0 0 192.168.0.251:5222 192.168.4.33:1074 ESTABLISHED
tcp 0 0 192.168.0.251:5222 192.168.1.242:1041 ESTABLISHED
tcp 0 0 192.168.0.251:5222 192.168.0.31:1055 ESTABLISHED
tcp 0 0 192.168.0.251:5222 192.168.0.115:1138 ESTABLISHED
tcp 0 0 192.168.0.251:5222 192.168.1.14:1038 ESTABLISHED
tcp 0 0 192.168.0.251:5222 192.168.1.44:1568 ESTABLISHED
tcp 0 0 192.168.0.251:5222 192.168.1.164:1135 ESTABLISHED
tcp 0 0 192.168.0.251:5222 192.168.0.111:1103 ESTABLISHED
tcp 0 0 192.168.0.251:5222 192.168.0.45:1030 ESTABLISHED
tcp 0 0 192.168.0.251:5222 192.168.0.213:1030 ESTABLISHED
tcp 0 0 192.168.0.251:5222 192.168.0.33:1548 ESTABLISHED
tcp 0 0 192.168.0.251:5222 192.168.1.26:1333 ESTABLISHED
tcp 0 0 192.168.0.251:5222 192.168.1.190:1044 ESTABLISHED
tcp 0 0 192.168.0.251:5222 192.168.1.78:1051 ESTABLISHED
tcp 0 0 192.168.0.251:5222 192.168.0.181:1046 ESTABLISHED
tcp 0 0 192.168.0.251:5222 192.168.0.27:1095 ESTABLISHED
.
.
total 44
jabber client connections: encrypted
====================================
total 0
jabber server-to-server connections
===================================
total 0
The total number of jabberd TCP connections is: 44
..
......... Main Jabberd and Daemon Tools Services
100 S 500 17660 6280 16 75 0 - 7470 pipe_w ? 00:00:55 sm
100 S 500 17659 6278 12 75 0 - 1187 pipe_w ? 00:00:41 router
100 S 500 18457 6281 7 75 0 - 1359 pipe_w ? 00:00:06 c2s
100 S 500 6283 6279 0 75 0 - 922 schedu ? 00:00:00 resolver
100 S 0 6274 1 0 76 0 - 547 wait4 ? 00:00:00 svscanboo
000 S 0 6276 6274 0 75 0 - 338 schedu ? 00:00:00 svscan
......... VMSTAT
procs memory swap io system cpu
r b w swpd free buff cache si so bi bo in cs us sy id
1 0 0 0 545604 66472 91900 0 0 1 8 77 75 6 10 84
....... TOP
3:28pm up 1 day, 2:52, 2 users, load average: 2.41, 1.74, 0.91
63 processes: 61 sleeping, 2 running, 0 zombie, 0 stopped
CPU states: 6.4% user, 9.5% system, 0.0% nice, 39.6% idle
Mem: 772516K av, 226912K used, 545604K free, 0K shrd, 66472K buff
Swap: 1566328K av, 0K used, 1566328K free 91900K cached
PID USER PRI NI SIZE RSS SHARE STAT %CPU %MEM TIME COMMAND
6277 root 25 0 208 208 176 R 56.5 0.0 92:51 readproctitle
17660 jabber 15 0 28080 27M 1592 S 16.8 3.6 0:55 sm
17659 jabber 15 0 2432 2432 1012 S 13.8 0.3 0:41 router
18457 jabber 15 0 3616 3616 1524 S 11.9 0.4 0:06 c2s
715 mysql 15 0 7804 7804 2476 S 0.9 1.0 1:29 mysqld
18613 root 15 0 932 932 720 R 0.9 0.1 0:00 top
1 root 15 0 488 488 428 S 0.0 0.0 0:04 init
2 root 15 0 0 0 0 SW 0.0 0.0 0:00 keventd
3 root 15 0 0 0 0 SW 0.0 0.0 0:00 kapmd
4 root 34 19 0 0 0 SWN 0.0 0.0 0:00 ksoftirqd_CPU0
5 root 15 0 0 0 0 SW 0.0 0.0 0:00 kswapd
6 root 25 0 0 0 0 SW 0.0 0.0 0:00 bdflush
8 root 25 0 0 0 0 SW 0.0 0.0 0:00 mdrecoveryd
12 root 15 0 0 0 0 SW 0.0 0.0 0:01 kjournald
67 root 15 0 0 0 0 SW 0.0 0.0 0:00 khubd
228 root 15 0 0 0 0 SW 0.0 0.0 0:00 kjournald
507 root 15 0 576 576 496 S 0.0 0.0 0:00 syslogd
511 root 15 0 428 428 376 S 0.0 0.0 0:00 klogd
528 rpc 15 0 532 532 460 S 0.0 0.0 0:00 portmap
547 rpcuser 17 0 728 728 640 S 0.0 0.0 0:00 rpc.statd
611 root 15 0 476 476 428 S 0.0 0.0 0:00 apmd
649 root 16 0 1468 1468 1320 S 0.0 0.1 0:01 sshd
663 root 15 0 888 888 764 S 0.0 0.1 0:00 xinetd
676 root 17 0 1208 1208 1036 S 0.0 0.1 0:00 safe_mysqld
721 root 15 0 6884 6884 6728 S 0.0 0.8 0:01 httpd
730 root 15 0 612 612 552 S 0.0 0.0 0:00 crond
759 xfs 15 0 2940 2940 844 S 0.0 0.3 0:00 xfs
777 daemon 15 0 520 520 464 S 0.0 0.0 0:00 atd
787 root 16 0 404 404 356 S 0.0 0.0 0:00 mingetty
788 root 16 0 404 404 356 S 0.0 0.0 0:00 mingetty
789 root 16 0 404 404 356 S 0.0 0.0 0:00 mingetty
790 root 16 0 404 404 356 S 0.0 0.0 0:00 mingetty
791 root 16 0 404 404 356 S 0.0 0.0 0:00 mingetty
792 root 16 0 404 404 356 S 0.0 0.0 0:00 mingetty
6274 root 16 0 1044 1044 896 S 0.0 0.1 0:00 svscanboot
6276 root 15 0 272 272 228 S 0.0 0.0 0:00 svscan
6278 root 15 0 252 252 220 S 0.0 0.0 0:00 supervise
6279 root 15 0 252 252 220 S 0.0 0.0 0:00 supervise
6280 root 15 0 252 252 220 S 0.0 0.0 0:00 supervise
6281 root 15 0 252 252 220 S 0.0 0.0 0:00 supervise
6283 jabber 15 0 1276 1276 904 S 0.0 0.1 0:00 resolver
7505 root 15 0 1564 1564 1144 S 0.0 0.2 0:00 bash
16919 root 15 0 1512 1512 1136 S 0.0 0.1 0:00 bash
18558 root 16 0 656 656 592 S 0.0 0.0 0:00 crond
18559 root 18 0 892 892 788 S 0.0 0.1 0:00 lista-jabberd.s^M
......... /VAR/LOG/MESSAGES
Oct 22 15:27:10 eajabberd jabberd/c2s[18457]: [25] requesting session: jid=rjsilva@estrelaazul/Exodus
Oct 22 15:27:10 eajabberd jabberd/c2s[18457]: [26] auth succeeded: username=agsantos, resource=Exodus
Oct 22 15:27:11 eajabberd jabberd/sm[17660]: session replaced: jid=bmoraes@estrelaazul/Exodus
Oct 22 15:27:11 eajabberd jabberd/c2s[18457]: [26] requesting session: jid=agsantos@estrelaazul/Exodus
Oct 22 15:27:11 eajabberd jabberd/c2s[18457]: [27] auth succeeded: username=rsolano, resource=Exodus
Oct 22 15:27:12 eajabberd jabberd/sm[17660]: session replaced: jid=rjsilva@estrelaazul/Exodus
Oct 22 15:27:12 eajabberd jabberd/c2s[18457]: [32] [192.168.0.115, port=1138] connect
Oct 22 15:27:13 eajabberd jabberd/c2s[18457]: [33] [192.168.0.181, port=1046] connect
Oct 22 15:27:13 eajabberd jabberd/c2s[18457]: [28] auth succeeded: username=mateus, resource=Exodus
Oct 22 15:27:13 eajabberd jabberd/c2s[18457]: [28] requesting session: jid=mateus@estrelaazul/Exodus
Oct 22 15:27:13 eajabberd jabberd/sm[17660]: session replaced: jid=agsantos@estrelaazul/Exodus
Oct 22 15:27:13 eajabberd jabberd/c2s[18457]: [34] [192.168.0.9, port=1158] connect
Oct 22 15:27:14 eajabberd jabberd/c2s[18457]: [29] auth succeeded: username=reinaldo, resource=Exodus
Oct 22 15:27:14 eajabberd jabberd/c2s[18457]: [29] requesting session: jid=reinaldo@estrelaazul/Exodus
Oct 22 15:27:15 eajabberd jabberd/sm[17660]: session started: jid=rsolano@estrelaazul/Exodus
Oct 22 15:27:15 eajabberd jabberd/c2s[18457]: [35] [192.168.4.69, port=1075] connect
Oct 22 15:27:15 eajabberd jabberd/c2s[18457]: [36] [192.168.0.72, port=1127] connect
Oct 22 15:27:15 eajabberd jabberd/c2s[18457]: [31] auth succeeded: username=jmsantana, resource=Exodus
Oct 22 15:27:15 eajabberd jabberd/c2s[18457]: [31] requesting session: jid=jmsantana@estrelaazul/Exodus
Oct 22 15:27:16 eajabberd jabberd/c2s[18457]: [37] [192.168.0.78, port=1043] connect
Oct 22 15:27:16 eajabberd jabberd/c2s[18457]: [32] auth succeeded: username=jcsouza, resource=Exodus
Oct 22 15:27:16 eajabberd jabberd/c2s[18457]: [32] requesting session: jid=jcsouza@estrelaazul/Exodus
Oct 22 15:27:16 eajabberd jabberd/c2s[18457]: [33] auth succeeded: username=wasantos, resource=Exodus
Oct 22 15:27:16 eajabberd jabberd/c2s[18457]: [33] requesting session: jid=wasantos@estrelaazul/Exodus
Oct 22 15:27:17 eajabberd jabberd/sm[17660]: session started: jid=mateus@estrelaazul/Exodus
Oct 22 15:27:19 eajabberd jabberd/sm[17660]: session started: jid=reinaldo@estrelaazul/Exodus
Oct 22 15:27:19 eajabberd jabberd/sm[17660]: session replaced: jid=jmsantana@estrelaazul/Exodus
Oct 22 15:27:19 eajabberd jabberd/sm[17660]: session started: jid=jcsouza@estrelaazul/Exodus
Oct 22 15:27:20 eajabberd jabberd/sm[17660]: session started: jid=wasantos@estrelaazul/Exodus
Oct 22 15:27:20 eajabberd jabberd/c2s[18457]: [38] [192.168.0.153, port=1052] connect
Oct 22 15:27:20 eajabberd jabberd/c2s[18457]: [30] auth succeeded: username=joaob, resource=Exodus
Oct 22 15:27:20 eajabberd jabberd/c2s[18457]: [30] requesting session: jid=joaob@estrelaazul/Exodus
Oct 22 15:27:20 eajabberd jabberd/c2s[18457]: [34] auth succeeded: username=adrsilva, resource=Exodus
Oct 22 15:27:20 eajabberd jabberd/c2s[18457]: [34] requesting session: jid=adrsilva@estrelaazul/Exodus
Oct 22 15:27:21 eajabberd jabberd/sm[17660]: session started: jid=joaob@estrelaazul/Exodus
Oct 22 15:27:22 eajabberd jabberd/sm[17660]: session replaced: jid=adrsilva@estrelaazul/Exodus
Oct 22 15:27:22 eajabberd jabberd/c2s[18457]: [39] [192.168.0.111, port=1103] connect
Oct 22 15:27:22 eajabberd jabberd/c2s[18457]: [40] [192.168.1.44, port=1568] connect
Oct 22 15:27:22 eajabberd jabberd/c2s[18457]: [35] auth succeeded: username=picone, resource=Exodus
Oct 22 15:27:22 eajabberd jabberd/c2s[18457]: [35] requesting session: jid=picone@estrelaazul/Exodus
Oct 22 15:27:22 eajabberd jabberd/c2s[18457]: [41] [192.168.2.28, port=1089] connect
Oct 22 15:27:22 eajabberd jabberd/c2s[18457]: [36] auth succeeded: username=clconceicao, resource=Exodus
Oct 22 15:27:22 eajabberd jabberd/c2s[18457]: [36] requesting session: jid=clconceicao@estrelaazul/Exodus