On the other hand, I’'m getting confused :p. When I enabled Asterix, it happened once again.
Asterix may have some bug, but my case here is not exactly the same. IMHO, there maybe already a bug somewhere in wildfire codes that handle TCP/IP IO, and Asterix’'s bug acts like a ‘‘catalyst’’ to produce the bug (hmm… where did I get this funny idea? ).
Once again, I got similar result like all the trace cases I mentioned in my earlier post. This time I captured some traces from stderror.log for Trace 2 above. When I first access the login page:
17:29:02.284 TRACE org.mortbay.http.HttpServer.service(HttpServer.java:893) >07> Contexts at /: [/=[WebApplicationContext[/,Wildfire]]]
17:29:02.303 TRACE org.mortbay.jetty.servlet.WebApplicationHandler$CachedChain.doFilter(WebApplica tionHandler.java:819) >13> call filter sitemesh
17:29:02.304 TRACE org.mortbay.jetty.servlet.WebApplicationHandler$CachedChain.doFilter(WebApplica tionHandler.java:829) >16> call servlet default
17:29:02.304 TRACE org.mortbay.http.ResourceCache.getResource(ResourceCache.java:223) >23> getResource /
17:29:02.304 TRACE org.mortbay.http.ResourceCache.getResource(ResourceCache.java:236) >23> CACHE HIT: file:/opt/wildfire/plugins/admin/webapp/
17:29:02.344 TRACE org.mortbay.http.ResourceCache.getResource(ResourceCache.java:223) >30> getResource /index.html
17:29:02.344 TRACE org.mortbay.http.ResourceCache.getResource(ResourceCache.java:236) >30> CACHE HIT: file:/opt/wildfire/plugins/admin/webapp/index.html
17:29:02.345 TRACE org.mortbay.http.HttpInputStream.resetStream(HttpInputStream.java:235) >06> resetStream()
17:29:02.391 TRACE org.mortbay.http.HttpServer.service(HttpServer.java:893) >07> Contexts at /index.jsp: [/=[WebApplicationContext[/,Wildfire]]]
17:29:02.392 TRACE org.mortbay.jetty.servlet.WebApplicationHandler$CachedChain.doFilter(WebApplica tionHandler.java:819) >13> call filter AuthCheck
17:29:02.392 TRACE org.mortbay.http.HttpInputStream.resetStream(HttpInputStream.java:235) >06> resetStream()
17:29:02.404 TRACE org.mortbay.http.HttpServer.service(HttpServer.java:893) >07> Contexts at /login.jsp: [/=[WebApplicationContext[/,Wildfire]]]
17:29:02.405 TRACE org.mortbay.jetty.servlet.WebApplicationHandler$CachedChain.doFilter(WebApplica tionHandler.java:819) >13> call filter AuthCheck
17:29:02.405 TRACE org.mortbay.jetty.servlet.WebApplicationHandler$CachedChain.doFilter(WebApplica tionHandler.java:819) >15> call filter PluginFilter
17:29:02.407 TRACE org.mortbay.jetty.servlet.WebApplicationHandler$CachedChain.doFilter(WebApplica tionHandler.java:819) >17> call filter Set Character Encoding
17:29:02.408 TRACE org.mortbay.jetty.servlet.WebApplicationHandler$CachedChain.doFilter(WebApplica tionHandler.java:819) >19> call filter LocaleFilter
17:29:02.408 TRACE org.mortbay.jetty.servlet.WebApplicationHandler$CachedChain.doFilter(WebApplica tionHandler.java:819) >21> call filter sitemesh
17:29:02.409 TRACE org.mortbay.jetty.servlet.WebApplicationHandler$CachedChain.doFilter(WebApplica tionHandler.java:829) >23> call servlet org.jivesoftware.wildfire.admin.login_jsp
17:29:02.427 TRACE org.mortbay.http.HttpInputStream.resetStream(HttpInputStream.java:235) >06> resetStream()
That worked. But, when I clicked on the login button:
17:29:08.056 TRACE org.mortbay.http.HttpServer.service(HttpServer.java:893) >07> Contexts at /login.jsp: [/=[WebApplicationContext[/,Wildfire]]]
17:29:08.056 TRACE org.mortbay.jetty.servlet.WebApplicationHandler$CachedChain.doFilter(WebApplica tionHandler.java:819) >13> call filter AuthCheck
17:29:08.056 TRACE org.mortbay.jetty.servlet.WebApplicationHandler$CachedChain.doFilter(WebApplica tionHandler.java:819) >15> call filter PluginFilter
17:29:08.057 TRACE org.mortbay.jetty.servlet.WebApplicationHandler$CachedChain.doFilter(WebApplica tionHandler.java:819) >17> call filter Set Character Encoding
17:29:08.057 TRACE org.mortbay.jetty.servlet.WebApplicationHandler$CachedChain.doFilter(WebApplica tionHandler.java:819) >19> call filter LocaleFilter
17:29:08.057 TRACE org.mortbay.jetty.servlet.WebApplicationHandler$CachedChain.doFilter(WebApplica tionHandler.java:819) >21> call filter sitemesh
17:29:08.059 TRACE org.mortbay.jetty.servlet.WebApplicationHandler$CachedChain.doFilter(WebApplica tionHandler.java:829) >23> call servlet org.jivesoftware.wildfire.admin.login_jsp
It stopped there and my browser stalled. Trace 1 and Trace 3 didn’'t produce anything in stderror.log.
I don’'t believe that this is an OutOfMemory error because users currently logged on can IM as usual including MUC. Perhaps, it could be helpful if I show my top result:
top - 17:46:13 up 3:08, 10 users, load average: 0.21, 0.18, 0.27
Tasks: 121 total, 1 running, 119 sleeping, 0 stopped, 1 zombie
Cpu(s): 12.3% us, 3.0% sy, 0.0% ni, 84.1% id, 0.0% wa, 0.7% hi, 0.0% si, 0.0% st
Mem: 271812k total, 264232k used, 7580k free, 47620k buffers
Swap: 557048k total, 116624k used, 440424k free, 64220k cached
and lsof | grep jive returns:
java 1643 jive cwd DIR 253,0 4096 1921992 /opt/wildfire/bin
java 1643 jive rtd DIR 253,0 4096 2 /
java 1643 jive txt REG 253,0 65076 1922135 /opt/wildfire/jre/bin/java
java 1643 jive mem REG 253,0 112276 2347100 /lib/libpthread-2.4.so
java 1643 jive mem REG 253,0 96040 2345728 /lib/libnsl-2.4.so
java 1643 jive mem REG 0,0 0 (stat: No such file or directory)
java 1643 jive mem REG 253,0 121396 2345530 /lib/ld-2.4.so
java 1643 jive mem REG 253,0 1532536 2345722 /lib/libc-2.4.so
java 1643 jive mem REG 253,0 199700 2347098 /lib/libm-2.4.so
java 1643 jive mem REG 253,0 16352 2347096 /lib/libdl-2.4.so
java 1643 jive mem REG 253,0 10129 1923177 /opt/wildfire/plugins/search/lib/plugin-search.jar
java 1643 jive mem REG 253,0 237799 1923223 /opt/wildfire/plugins/asterisk-im/lib/asterisk-java-0.2.jar
java 1643 jive mem REG 253,0 77568 1923222 /opt/wildfire/plugins/asterisk-im/lib/asterisk-im-classes.jar
java 1643 jive mem REG 253,0 183622 1922721 /opt/wildfire/plugins/admin/webapp/WEB-INF/lib/dwr.jar
java 1643 jive mem REG 253,0 494810 1922720 /opt/wildfire/plugins/admin/webapp/WEB-INF/lib/admin-jsp.jar
java 1643 jive mem REG 253,0 81420 1922227 /opt/wildfire/jre/lib/i386/libnet.so
java 1643 jive mem REG 253,0 282625 1922149 /opt/wildfire/lib/jtds.jar
java 1643 jive mem REG 253,0 111388 1922714 /opt/wildfire/lib/commons-el.jar
java 1643 jive mem REG 253,0 133622 1922716 /opt/wildfire/lib/servlet.jar
java 1643 jive mem REG 253,0 59483 1923256 /opt/wildfire/lib/startup.jar
java 1643 jive mem REG 253,0 451545 1923179 /opt/wildfire/lib/mysql.jar
java 1643 jive mem REG 253,0 347137 1923253 /opt/wildfire/lib/mail.jar
java 1643 jive mem REG 253,0 629372 1922707 /opt/wildfire/lib/hsqldb.jar
java 1643 jive mem REG 253,0 54829 1922700 /opt/wildfire/lib/activation.jar
java 1643 jive mem REG 253,0 105531 1922711 /opt/wildfire/lib/jasper-runtime.jar
java 1643 jive mem REG 253,0 4143883 1922097 /opt/wildfire/lib/wildfire.jar
java 1643 jive mem REG 253,0 397448 1922709 /opt/wildfire/lib/postgres.jar
java 1643 jive mem REG 253,0 74639 1923252 /opt/wildfire/lib/jdic.jar
java 1643 jive mem REG 253,0 1070477 1922701 /opt/wildfire/lib/bouncycastle.jar
java 1643 jive mem REG 253,0 349609 1922702 /opt/wildfire/lib/jasper-compiler.jar
java 1643 jive mem REG 253,0 323531 1922099 /opt/wildfire/.install4j/i4jruntime.jar
java 1643 jive mem REG 253,0 158417 1923245 /opt/wildfire/jre/lib/ext/sunjce_provider.jar
java 1643 jive mem REG 253,0 175811 1922161 /opt/wildfire/jre/lib/ext/sunpkcs11.jar
java 1643 jive mem REG 253,0 797269 1922158 /opt/wildfire/jre/lib/ext/localedata.jar
java 1643 jive mem REG 253,0 54353856 1011829 /usr/lib/locale/locale-archive
java 1643 jive mem REG 253,0 11217 1923084 /opt/wildfire/plugins/search/lib/plugin-search-jspc.jar
java 1643 jive mem REG 253,0 8715517 1922284 /opt/wildfire/jre/lib/charsets.jar
java 1643 jive mem REG 253,0 81946 1922253 /opt/wildfire/jre/lib/jce.jar
java 1643 jive mem REG 253,0 486866 1922160 /opt/wildfire/jre/lib/jsse.jar
java 1643 jive mem REG 253,0 35660503 1923178 /opt/wildfire/jre/lib/rt.jar
java 1643 jive mem REG 253,0 83024 1922232 /opt/wildfire/jre/lib/i386/libzip.so
java 1643 jive mem REG 253,0 140856 1922213 /opt/wildfire/jre/lib/i386/libjava.so
java 1643 jive mem REG 253,0 46608 2345512 /lib/libnss_files-2.4.so
java 1643 jive mem REG 253,0 7202 1923215 /opt/wildfire/plugins/broadcast/lib/plugin-broadcast.jar
java 1643 jive mem REG 253,0 8176 1923244 /opt/wildfire/jre/lib/ext/dnsns.jar
java 1643 jive mem REG 253,0 48912 1922231 /opt/wildfire/jre/lib/i386/libverify.so
java 1643 jive mem REG 253,0 7353145 1922237 /opt/wildfire/jre/lib/i386/server/libjvm.so
java 1643 jive mem REG 253,0 32768 1205317 /tmp/hsperfdata_jive/1643
java 1643 jive mem REG 253,0 27896 1922234 /opt/wildfire/jre/lib/i386/native_threads/libhpi.so
java 1643 jive 0r CHR 1,3 1130 /dev/null
java 1643 jive 1u CHR 1,3 292 /null
java 1643 jive 2u CHR 1,3 292 /null
java 1643 jive 3r CHR 1,8 1624 /dev/random
java 1643 jive 4r CHR 1,9 1630 /dev/urandom
java 1643 jive 5w REG 253,0 1240 1923236 /opt/wildfire/logs/debug.log
java 1643 jive 6u sock 0,4 5108 can’'t identify protocol
java 1643 jive 7w REG 253,0 557 1923238 /opt/wildfire/logs/info.log
java 1643 jive 8w REG 253,0 0 1922255 /opt/wildfire/logs/warn.log
java 1643 jive 9w REG 253,0 9194 1923249 /opt/wildfire/logs/error.log
java 1643 jive 10w REG 253,0 1483455 1922705 /opt/wildfire/logs/stderror.log
java 1643 jive 11u IPv6 5742 TCP localhost.localdomain:44384->localhost.localdomain:mysql (ESTABLISHED)
java 1643 jive 12u IPv6 5776 TCP localhost.localdomain:48773->localhost.localdomain:mysql (ESTABLISHED)
java 1643 jive 13u IPv6 5778 TCP localhost.localdomain:39069->localhost.localdomain:mysql (ESTABLISHED)
java 1643 jive 14u IPv6 5780 TCP localhost.localdomain:32807->localhost.localdomain:mysql (ESTABLISHED)
java 1643 jive 15u IPv6 5782 TCP localhost.localdomain:36168->localhost.localdomain:mysql (ESTABLISHED)
java 1643 jive 16u IPv6 5928 TCP *:xmpp-server (LISTEN)
java 1643 jive 17u IPv6 5930 TCP *:10015 (LISTEN)
java 1643 jive 19u IPv6 5932 TCP *:xmpp-client (LISTEN)
java 1643 jive 21w REG 253,0 50559 1922710 /opt/wildfire/logs/jive.audit-20060811-000.log
java 1643 jive 22u IPv6 6214 TCP *:5223 (LISTEN)
java 1643 jive 23u IPv6 6900 TCP *:websm (LISTEN)
java 1643 jive 25u IPv6 6620 TCP *:cbt (LISTEN)
java 1643 jive 27w REG 253,0 106 1922704 /opt/wildfire/logs/stdoutt.log
java 1643 jive 28u IPv6 10560 TCP imp:xmpp-client->az-vaio:asi (ESTABLISHED)
java 1643 jive 29r CHR 1,8 1624 /dev/random
java 1643 jive 30u IPv6 6943 TCP *:xmltec-xmlmail (LISTEN)
java 1643 jive 31u IPv6 7168 TCP imp:38008->192.168.0.6:5038 (ESTABLISHED)
java 1643 jive 32u IPv6 8914 TCP localhost.localdomain:58740->localhost.localdomain:mysql (ESTABLISHED)
java 1643 jive 33u IPv6 8916 TCP localhost.localdomain:57250->localhost.localdomain:mysql (ESTABLISHED)
java 1643 jive 34u IPv6 10515 TCP localhost.localdomain:xmpp-client->localhost.localdomain:36416 (ESTABLISHED)
java 1643 jive 36u IPv6 10796 TCP localhost.localdomain:32941->localhost.localdomain:mysql (ESTABLISHED)
java 1643 jive 37u IPv6 10798 TCP localhost.localdomain:59607->localhost.localdomain:mysql (ESTABLISHED)
java 1643 jive 38u IPv6 10800 TCP localhost.localdomain:57881->localhost.localdomain:mysql (ESTABLISHED)
java 1643 jive 39u IPv6 10803 TCP localhost.localdomain:49283->localhost.localdomain:mysql (ESTABLISHED)
java 1643 jive 40u IPv6 10805 TCP localhost.localdomain:36336->localhost.localdomain:mysql (ESTABLISHED)
java 1643 jive 41u IPv6 10810 TCP localhost.localdomain:34859->localhost.localdomain:mysql (ESTABLISHED)
java 1643 jive 42u IPv6 10812 TCP localhost.localdomain:53360->localhost.localdomain:mysql (ESTABLISHED)
java 1643 jive 43u IPv6 10814 TCP localhost.localdomain:55195->localhost.localdomain:mysql (ESTABLISHED)
java 1643 jive 44u IPv6 22610 TCP imp:websm->az-vaio:msfw-storage (CLOSE_WAIT)
java 1643 jive 45u IPv6 22698 TCP imp:websm->az-vaio:2179 (CLOSE_WAIT)
java 1643 jive 46u IPv6 24244 TCP imp:websm->az-vaio:2212 (CLOSE_WAIT)
java 1643 jive 47u IPv6 24260 TCP imp:websm->az-vaio:kali (ESTABLISHED)
mysqld 1960 mysql 30u REG 253,0 2048 946671 /var/lib/mysql/wildfire/jiveVersion.MYI
mysqld 1960 mysql 31u REG 253,0 40 946672 /var/lib/mysql/wildfire/jiveVersion.MYD
mysqld 1960 mysql 32u REG 253,0 2048 946668 /var/lib/mysql/wildfire/jiveProperty.MYI
mysqld 1960 mysql 33u REG 253,0 1236 946669 /var/lib/mysql/wildfire/jiveProperty.MYD
mysqld 1960 mysql 34u REG 253,0 2048 946665 /var/lib/mysql/wildfire/jiveID.MYI
mysqld 1960 mysql 35u REG 253,0 65 946666 /var/lib/mysql/wildfire/jiveID.MYD
mysqld 1960 mysql 36u REG 253,0 1024 946680 /var/lib/mysql/wildfire/jivePrivacyList.MYI
mysqld 1960 mysql 37u REG 253,0 0 946681 /var/lib/mysql/wildfire/jivePrivacyList.MYD
mysqld 1960 mysql 64u REG 253,0 3072 946635 /var/lib/mysql/wildfire/jiveUser.MYI
mysqld 1960 mysql 65u REG 253,0 292 946636 /var/lib/mysql/wildfire/jiveUser.MYD
mysqld 1960 mysql 68u REG 253,0 2048 946638 /var/lib/mysql/wildfire/jiveUserProp.MYI
mysqld 1960 mysql 69u REG 253,0 248 946639 /var/lib/mysql/wildfire/jiveUserProp.MYD
mysqld 1960 mysql 70u REG 253,0 1024 946644 /var/lib/mysql/wildfire/jiveGroupProp.MYI
mysqld 1960 mysql 71u REG 253,0 0 946645 /var/lib/mysql/wildfire/jiveGroupProp.MYD
mysqld 1960 mysql 72u REG 253,0 1024 946647 /var/lib/mysql/wildfire/jiveGroupUser.MYI
mysqld 1960 mysql 73u REG 253,0 0 946648 /var/lib/mysql/wildfire/jiveGroupUser.MYD
mysqld 1960 mysql 74u REG 253,0 3072 946656 /var/lib/mysql/wildfire/jiveRoster.MYI
mysqld 1960 mysql 75u REG 253,0 144 946657 /var/lib/mysql/wildfire/jiveRoster.MYD
mysqld 1960 mysql 76u REG 253,0 2048 946662 /var/lib/mysql/wildfire/jiveVCard.MYI
mysqld 1960 mysql 77u REG 253,0 648 946663 /var/lib/mysql/wildfire/jiveVCard.MYD
mysqld 1960 mysql 78u REG 253,0 3072 946650 /var/lib/mysql/wildfire/jivePrivate.MYI
mysqld 1960 mysql 79u REG 253,0 328 946651 /var/lib/mysql/wildfire/jivePrivate.MYD
mysqld 1960 mysql 80u REG 253,0 2048 946653 /var/lib/mysql/wildfire/jiveOffline.MYI
mysqld 1960 mysql 81u REG 253,0 484 946654 /var/lib/mysql/wildfire/jiveOffline.MYD
Though I can’‘t produce the stack trace, top and lsof should say something about the memory. Again seriously, kill -3 doesn’'t help.
Any other brilliant ideas?