Hi,
We are currently using openfire 3.6.4 in our environment. We are noticing a recurring strange problem. Suddently, all the users, chat conversations, group chats etc. will be disconnected and openfire will not even connect the users who retry connection attempts. Restaring the openfire daemon magically fixes everything and all the users get connected properly. And one more strange thing is that the server does not even experience high load (in terms of number of users, chats etc.) when this occurs. This problem didn’t show up when the server had max. number of users logged in etc.
Even the system memory was not full when this happened today morning. Though, I checked the logs when the issue occurred, I couldn’t find anything glaring (except the below mentioned MUC log saving messages). But, I see several of these messages in the logs (just before openfire disconnects the users as mentioned above and at other times).
Few details of out setup:
Openfire version: 3.6.4
Operating System: Ubuntu Hardy
Database: Mysql 5.0.51a-3ubuntu5.4
JDBC: mysql-connector-java-5.0.8
Character encoding: UTF-8
LDAP server: Active Directory
Allotted Java Memory: 2.5 GB
Total Memory on the server: 4 GB
The problem occurs randomy and happens atleast once in 15 days or so. Any inputs to resolve this would be highly appreciated. Thanks in advance.
2009.12.02 04:59:05 [org.jivesoftware.openfire.muc.spi.MUCPersistenceManager.saveConversationLogEnt ry(MUCPersistenceManager.java:991)] Error saving conversation log entry
java.sql.SQLException: Incorrect string value: ‘\xEF\xBB\xBFJac…’ for column ‘body’ at row 1
at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:946)
at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:2985)
at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:1631)
at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:1723)
at com.mysql.jdbc.Connection.execSQL(Connection.java:3283)
at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:1332)
at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:1604)
at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:1519)
at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:1504)
at sun.reflect.GeneratedMethodAccessor9.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.ja va:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at org.logicalcobwebs.proxool.ProxyStatement.invoke(ProxyStatement.java:100)
at org.logicalcobwebs.proxool.ProxyStatement.intercept(ProxyStatement.java:57)
at $java.sql.PreparedStatement$$EnhancerByProxool$$f2dbd89c.executeUpdate()
at org.jivesoftware.openfire.muc.spi.MUCPersistenceManager.saveConversationLogEntr y(MUCPersistenceManager.java:987)
at org.jivesoftware.openfire.muc.spi.MultiUserChatServiceImpl.logConversation(Mult iUserChatServiceImpl.java:415)
at org.jivesoftware.openfire.muc.spi.MultiUserChatServiceImpl.access$100(MultiUser ChatServiceImpl.java:64)
at org.jivesoftware.openfire.muc.spi.MultiUserChatServiceImpl$LogConversationTask. run(MultiUserChatServiceImpl.java:401)
at java.util.TimerThread.mainLoop(Timer.java:512)
at java.util.TimerThread.run(Timer.java:462)
Out of curiosity, I ran tcpdump on the server (with a filter against a particular client machine) when this problem showed up. I tried reconnecting to the server manually when I was disconnected. The following are the packets w.r.t this capture. After these, I didn’t see any other packets:
05:37:08.723711 IP CLIENT.49936 > SERVER.xmpp-client: S 625361161:625361161(0) win 65535 <mss 1460,nop,wscale 3,nop,nop,timestamp 519310283 0,sackOK,eol>
05:37:08.723721 IP SERVER.xmpp-client > CLIENT.49936: S 2757573512:2757573512(0) ack 625361162 win 5792 <mss 1460,sackOK,timestamp 1800854829 519310283,nop,wscale 7>
05:37:08.967688 IP CLIENT.49936 > SERVER.xmpp-client: . ack 1 win 65535 <nop,nop,timestamp 519310285 1800854829>
05:37:08.967877 IP CLIENT.49936 > SERVER.xmpp-client: P 1:23(22) ack 1 win 65535 <nop,nop,timestamp 519310285 1800854829>
05:37:08.967890 IP SERVER.xmpp-client > CLIENT.49936: . ack 23 win 46 <nop,nop,timestamp 1800854853 519310285>
05:37:09.211578 IP CLIENT.49936 > SERVER.xmpp-client: P 23:138(115) ack 1 win 65535 <nop,nop,timestamp 519310288 1800854853>
05:37:09.211585 IP SERVER.xmpp-client > CLIENT.49936: . ack 138 win 46 <nop,nop,timestamp 1800854878 519310288>
Thanks,
Satish