Openfire

Duplicate entry 'user xxx' for key 1 -- Exposed during load testing.

Details

  • Acceptance Test - Add?:
    No
  • Description:
    Hide

    The following Exception is showing up multiple times (with different usernames) on the console for lachesis. This seems to occur around the same time things start going downhill in the testing.

    java.sql.SQLException: Duplicate entry 'user33703' for key 1
    at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:2975)
    at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:1600)
    at com.mysql.jdbc.ServerPreparedStatement.serverExecute(ServerPreparedStatement.java:1125)
    at com.mysql.jdbc.ServerPreparedStatement.executeInternal(ServerPreparedStatement.java:677)
    at com.mysql.jdbc.PreparedStatement.execute(PreparedStatement.java:794)
    at org.jivesoftware.wildfire.spi.PresenceManagerImpl.userUnavailable(PresenceManagerImpl.java:261)
    at org.jivesoftware.wildfire.handler.PresenceUpdateHandler.process(PresenceUpdateHandler.java:122)
    at org.jivesoftware.wildfire.handler.PresenceUpdateHandler.process(PresenceUpdateHandler.java:153)
    at org.jivesoftware.wildfire.SessionManager$ClientSessionListener.onConnectionClose(SessionManager.java:1497)
    at org.jivesoftware.wildfire.net.VirtualConnection.notifyCloseListeners(VirtualConnection.java:179)
    at org.jivesoftware.wildfire.net.VirtualConnection.close(VirtualConnection.java:155)
    at org.jivesoftware.wildfire.multiplex.ConnectionMultiplexerManager.closeClientSession(ConnectionMultiplexerManager.java:162)
    at org.jivesoftware.wildfire.multiplex.MultiplexerPacketHandler.handle(MultiplexerPacketHandler.java:85)
    at org.jivesoftware.wildfire.net.MultiplexerStanzaHandler.processIQ(MultiplexerStanzaHandler.java:49)
    at org.jivesoftware.wildfire.net.StanzaHandler.process(StanzaHandler.java:256)
    at org.jivesoftware.wildfire.net.StanzaHandler.process(StanzaHandler.java:155)
    at org.jivesoftware.wildfire.net.ConnectionHandler.messageReceived(ConnectionHandler.java:83)
    at org.apache.mina.common.support.AbstractIoFilterChain$TailFilter.messageReceived(AbstractIoFilterChain.java:703)
    at org.apache.mina.common.support.AbstractIoFilterChain.callNextMessageReceived(AbstractIoFilterChain.java:362)
    at org.apache.mina.common.support.AbstractIoFilterChain.access$1100(AbstractIoFilterChain.java:54)
    at org.apache.mina.common.support.AbstractIoFilterChain$EntryImpl$1.messageReceived(AbstractIoFilterChain.java:800)
    at org.apache.mina.filter.codec.support.SimpleProtocolDecoderOutput.flush(SimpleProtocolDecoderOutput.java:62)
    at org.apache.mina.filter.codec.ProtocolCodecFilter.messageReceived(ProtocolCodecFilter.java:186)
    at org.apache.mina.common.support.AbstractIoFilterChain.callNextMessageReceived(AbstractIoFilterChain.java:362)
    at org.apache.mina.common.support.AbstractIoFilterChain.access$1100(AbstractIoFilterChain.java:54)
    at org.apache.mina.common.support.AbstractIoFilterChain$EntryImpl$1.messageReceived(AbstractIoFilterChain.java:800)
    at org.apache.mina.filter.executor.ExecutorFilter.processEvent(ExecutorFilter.java:231)
    at org.apache.mina.filter.executor.ExecutorFilter$ProcessEventsRunnable.run(ExecutorFilter.java:286)
    at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:885)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:907)
    at java.lang.Thread.run(Thread.java:619)

    Show
    The following Exception is showing up multiple times (with different usernames) on the console for lachesis. This seems to occur around the same time things start going downhill in the testing. java.sql.SQLException: Duplicate entry 'user33703' for key 1 at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:2975) at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:1600) at com.mysql.jdbc.ServerPreparedStatement.serverExecute(ServerPreparedStatement.java:1125) at com.mysql.jdbc.ServerPreparedStatement.executeInternal(ServerPreparedStatement.java:677) at com.mysql.jdbc.PreparedStatement.execute(PreparedStatement.java:794) at org.jivesoftware.wildfire.spi.PresenceManagerImpl.userUnavailable(PresenceManagerImpl.java:261) at org.jivesoftware.wildfire.handler.PresenceUpdateHandler.process(PresenceUpdateHandler.java:122) at org.jivesoftware.wildfire.handler.PresenceUpdateHandler.process(PresenceUpdateHandler.java:153) at org.jivesoftware.wildfire.SessionManager$ClientSessionListener.onConnectionClose(SessionManager.java:1497) at org.jivesoftware.wildfire.net.VirtualConnection.notifyCloseListeners(VirtualConnection.java:179) at org.jivesoftware.wildfire.net.VirtualConnection.close(VirtualConnection.java:155) at org.jivesoftware.wildfire.multiplex.ConnectionMultiplexerManager.closeClientSession(ConnectionMultiplexerManager.java:162) at org.jivesoftware.wildfire.multiplex.MultiplexerPacketHandler.handle(MultiplexerPacketHandler.java:85) at org.jivesoftware.wildfire.net.MultiplexerStanzaHandler.processIQ(MultiplexerStanzaHandler.java:49) at org.jivesoftware.wildfire.net.StanzaHandler.process(StanzaHandler.java:256) at org.jivesoftware.wildfire.net.StanzaHandler.process(StanzaHandler.java:155) at org.jivesoftware.wildfire.net.ConnectionHandler.messageReceived(ConnectionHandler.java:83) at org.apache.mina.common.support.AbstractIoFilterChain$TailFilter.messageReceived(AbstractIoFilterChain.java:703) at org.apache.mina.common.support.AbstractIoFilterChain.callNextMessageReceived(AbstractIoFilterChain.java:362) at org.apache.mina.common.support.AbstractIoFilterChain.access$1100(AbstractIoFilterChain.java:54) at org.apache.mina.common.support.AbstractIoFilterChain$EntryImpl$1.messageReceived(AbstractIoFilterChain.java:800) at org.apache.mina.filter.codec.support.SimpleProtocolDecoderOutput.flush(SimpleProtocolDecoderOutput.java:62) at org.apache.mina.filter.codec.ProtocolCodecFilter.messageReceived(ProtocolCodecFilter.java:186) at org.apache.mina.common.support.AbstractIoFilterChain.callNextMessageReceived(AbstractIoFilterChain.java:362) at org.apache.mina.common.support.AbstractIoFilterChain.access$1100(AbstractIoFilterChain.java:54) at org.apache.mina.common.support.AbstractIoFilterChain$EntryImpl$1.messageReceived(AbstractIoFilterChain.java:800) at org.apache.mina.filter.executor.ExecutorFilter.processEvent(ExecutorFilter.java:231) at org.apache.mina.filter.executor.ExecutorFilter$ProcessEventsRunnable.run(ExecutorFilter.java:286) at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:885) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:907) at java.lang.Thread.run(Thread.java:619)
  • Environment:

    Local load testing enviro:
    WF/CM-1/MySQL on lachesis
    CM-2 on load-35
    4 Tsung Clients (151,152,155,157)

Activity

Hide
Timur added a comment - 08/08/07 01:38 PM

Client XML to reproduce:
1. This will give you one such error log message. jivePresence database entry already exists cause user haven't been available and his offline presence wasn't deleted by PresenceManager.userAvailable()

<?xml version="1.0"?>

<stream:stream xmlns:stream="http://etherx.jabber.org/streams" xmlns="jabber:client" to="server" >

<iq type="set" id="auth_1" to="rw12" >
<query xmlns="jabber:iq:auth">
<username>user</username>
<password>password</password>
<resource>res</resource>
</query>
</iq>

<presence type="unavailable"/>

</stream:stream>

2. This will give you two error messages. Cause first unavailable presence will be written to database. And then for two others "entry already exists"

<?xml version="1.0"?>

<stream:stream xmlns:stream="http://etherx.jabber.org/streams" xmlns="jabber:client" to="server" >

<iq type="set" id="auth_1" to="rw12" >
<query xmlns="jabber:iq:auth">
<username>user</username>
<password>password</password>
<resource>res</resource>
</query>
</iq>

<presence type="available"/>

<presence type="unavailable">
<status> I'm gone </status>
</presence>

<presence type="unavailable">
<priority>5</priority>
</presence>

<presence type="unavailable"/>

</stream:stream>

The way to fix this issue is to change PresenceManager.INSERT_OFFLINE_PRESENCE to "REPLACE INTO jivePresence(username, offlinePresence, offlineDate) VALUES(?,?,?)". Hope that this comment was useful.

Show
Timur added a comment - 08/08/07 01:38 PM Client XML to reproduce: 1. This will give you one such error log message. jivePresence database entry already exists cause user haven't been available and his offline presence wasn't deleted by PresenceManager.userAvailable() <?xml version="1.0"?> <stream:stream xmlns:stream="http://etherx.jabber.org/streams" xmlns="jabber:client" to="server" > <iq type="set" id="auth_1" to="rw12" > <query xmlns="jabber:iq:auth"> <username>user</username> <password>password</password> <resource>res</resource> </query> </iq> <presence type="unavailable"/> </stream:stream> 2. This will give you two error messages. Cause first unavailable presence will be written to database. And then for two others "entry already exists" <?xml version="1.0"?> <stream:stream xmlns:stream="http://etherx.jabber.org/streams" xmlns="jabber:client" to="server" > <iq type="set" id="auth_1" to="rw12" > <query xmlns="jabber:iq:auth"> <username>user</username> <password>password</password> <resource>res</resource> </query> </iq> <presence type="available"/> <presence type="unavailable"> <status> I'm gone </status> </presence> <presence type="unavailable"> <priority>5</priority> </presence> <presence type="unavailable"/> </stream:stream> The way to fix this issue is to change PresenceManager.INSERT_OFFLINE_PRESENCE to "REPLACE INTO jivePresence(username, offlinePresence, offlineDate) VALUES(?,?,?)". Hope that this comment was useful.
Hide
Guus der Kinderen added a comment - 01/22/08 10:58 AM

Exceptions like these take up about a quarter of our logs. Could you please consider bumping up the priority of this issue?

Show
Guus der Kinderen added a comment - 01/22/08 10:58 AM Exceptions like these take up about a quarter of our logs. Could you please consider bumping up the priority of this issue?
Hide
Rogue XZ added a comment - 07/07/08 11:11 AM

Hi,

I was going through the discussion thread associated with this bug and had a few updates.

1. I can confirm that this issue happens for all users, not just the admin users.
2. This issue is happening if I try to access the system using Netbean's IM Module.
3. I can login via Spark (2.5.8)

Now, if I am logged in via Spark, and then try to login using the Netbeans module, I see a different error (invalid JID)

But, if I logoff spark and then attempt to login via netbeans, I see the exception stack again.

Hope this helps.

thanks,
Harsha

Show
Rogue XZ added a comment - 07/07/08 11:11 AM Hi, I was going through the discussion thread associated with this bug and had a few updates. 1. I can confirm that this issue happens for all users, not just the admin users. 2. This issue is happening if I try to access the system using Netbean's IM Module. 3. I can login via Spark (2.5.8) Now, if I am logged in via Spark, and then try to login using the Netbeans module, I see a different error (invalid JID) But, if I logoff spark and then attempt to login via netbeans, I see the exception stack again. Hope this helps. thanks, Harsha
Hide
Rogue XZ added a comment - 07/07/08 11:12 AM

Quick update. This error is occurring on openfire-3.5.2-1.i386 / Sun JDK 6 / Fedora 9 box.

Show
Rogue XZ added a comment - 07/07/08 11:12 AM Quick update. This error is occurring on openfire-3.5.2-1.i386 / Sun JDK 6 / Fedora 9 box.
Hide
Guus der Kinderen added a comment - 02/18/10 05:48 PM
Show
Guus der Kinderen added a comment - 02/18/10 05:48 PM Similar issue reported here: http://www.igniterealtime.org/community/message/200974

People

Dates

  • Created:
    12/27/06 11:27 PM
    Updated:
    02/18/10 05:48 PM