When one of my Spark users (2.5.5) tries to add a new user to their roster, there client crashes, and an error is thrown in Openfire (3.3.1) error.log file:
org.jivesoftware.openfire.user.UserAlreadyExistsException
The user is definitely trying to add a user that does not currently exist in their roster.
has anyone seen this before?
should i maybe post this in the Spark forum? I dont want it to be a double post. Can a mod please move? Or answer? 
Hey avidan,
Regarding the client crashing just post about it in Spark forums. Regarding the server problem this is the correct place to post about it. Could you post the entire stack trace of the error? I would say that the server found a roster item for the JID of the new contact thus the UserAlreadyExistsException exception. You may also want to post the IQ roster result sent by the server to the client and also the XML stanza sent by the client to the server when adding a new contact.
Regards,
– Gato
Here is my configuration file (I am using AD Win2003 for LDAP, and Openfire is running on FreeBSD 5.5 Stable):
<?xml version=“1.0” encoding=“UTF-8”?>
<!-- root element, all properties must be under this element -->
<jive>
<adminConsole>
<!-- Disable either port by setting the value to -1 -->
<port>9090</port>
<securePort>9091</securePort>
</adminConsole>
<admin>
<authorizedUsernames>admin,avidan,manu,jbonds,khanh</authorizedUsernam es>
</admin>
<locale>en</locale>
<ldap>
<host>dc1.cimgroup.com</host>
<port>389</port>
<usernameField>sAMAccountName</usernameField>
<nameField>displayName</nameField>
<emailField>mail</emailField>
<groupNameField>cn</groupNameField>
<groupMemberField>member</groupMemberField>
<groupSearchFilter>(objectClass=group)</groupSearchFilter>
<groupDescriptionField>description</groupDescriptionField>
<baseDN>OU=Departments,DC=cimgroup,DC=com</baseDN>
<adminDN>CN=otrs,OU=Technology,OU=Operations,OU=Departments,DC=cimgroup,D C=com</adminDN>
<adminPassword>removed</adminPassword>
<searchField>displayName</searchField>
<vcard-mapping> <![CDATA[
<vCard xmlns=‘vcard-temp’>
<FN attrs=“displayName”></FN>
<NICKNAME attrs=“sAMAccountName”></NICKNAME>
<N>
<FAMILY attrs=“sn”></FAMILY>
<GIVEN attrs=“givenName”></GIVEN>
</N>
<ADR>
<WORK/>
<EXTADR></EXTADR>
<STREET attrs=“streetAddress”></STREET>
<LOCALITY attrs=“l”></LOCALITY>
<REGION attrs=“st”></REGION>
<PCODE attrs=“postalCode”></PCODE>
<CTRY attrs=“co”></CTRY>
</ADR>
<TEL>
<WORK/>
<VOICE/>
<NUMBER attrs=“telephoneNumber”></NUMBER>
<CELL/>
<NUMBER attrs=“mobile”></NUMBER> </TEL>
<EMAIL>
<INTERNET/>
<USERID attrs=“sAMAccountName”></USERID>
</EMAIL>
<TITLE attrs=“title”></TITLE>
<ROLE attrs=""></ROLE>
<ORG>
<ORGNAME attrs=“company”></ORGNAME>
<ORGUNIT attrs=“department”></ORGUNIT>
</ORG>
<URL attrs=“labeledURI”></URL>
<DESC attrs=“uidNumber,homeDirectory,loginShell”>
uid: home: shell:
</DESC>
</vCard>
]]> </vcard-mapping>
</ldap>
<provider>
<user>
<className>org.jivesoftware.openfire.ldap.LdapUserProvider</className& gt;
</user>
<auth>
<className>org.jivesoftware.openfire.ldap.LdapAuthProvider</className& gt;
</auth>
<group>
<className>org.jivesoftware.openfire.ldap.LdapGroupProvider</className >
</group>
<vcard>
<className>org.jivesoftware.openfire.ldap.LdapVCardProvider</className >
</vcard>
</provider>
<!-- End example LDAP settings -->
<connectionProvider>
<className>org.jivesoftware.database.DefaultConnectionProvider</classN ame>
</connectionProvider>
<database>
<defaultProvider>
<driver>com.mysql.jdbc.Driver</driver>
<serverURL>jdbc:mysql://localhost:3306/openfire</serverURL>
<username>otrs</username>
<password>removed</password>
<minConnections>5</minConnections>
<maxConnections>15</maxConnections>
<connectionTimeout>1.0</connectionTimeout>
</defaultProvider>
</database>
<setup>true</setup>
</jive>
Here is the end of the error.log file:
2007.08.10 10:53:29 org.jivesoftware.openfire.handler.IQRosterHandler.handleIQ(IQRosterHandler.java: 128) Internal server error
org.jivesoftware.openfire.user.UserAlreadyExistsException: jide@cimgroup.com
at org.jivesoftware.openfire.roster.RosterItemProvider.createItem(RosterItemProvid er.java:108)
at org.jivesoftware.openfire.roster.Roster.provideRosterItem(Roster.java:334)
at org.jivesoftware.openfire.roster.Roster.provideRosterItem(Roster.java:295)
at org.jivesoftware.openfire.roster.Roster.createRosterItem(Roster.java:280)
at org.jivesoftware.openfire.handler.IQRosterHandler.manageRoster(IQRosterHandler. java:226)
at org.jivesoftware.openfire.handler.IQRosterHandler.handleIQ(IQRosterHandler.java :105)
at org.jivesoftware.openfire.handler.IQHandler.process(IQHandler.java:48)
at org.jivesoftware.openfire.IQRouter.handle(IQRouter.java:300)
at org.jivesoftware.openfire.IQRouter.route(IQRouter.java:104)
at org.jivesoftware.openfire.spi.PacketRouterImpl.route(PacketRouterImpl.java:67)
at org.jivesoftware.openfire.net.StanzaHandler.processIQ(StanzaHandler.java:289)
at org.jivesoftware.openfire.net.ClientStanzaHandler.processIQ(ClientStanzaHandler .java:79)
at org.jivesoftware.openfire.net.StanzaHandler.process(StanzaHandler.java:254)
at org.jivesoftware.openfire.net.StanzaHandler.process(StanzaHandler.java:153)
at org.jivesoftware.openfire.nio.ConnectionHandler.messageReceived(ConnectionHandl er.java:132)
at org.apache.mina.common.support.AbstractIoFilterChain$TailFilter.messageReceived (AbstractIoFilterChain.java:703)
at org.apache.mina.common.support.AbstractIoFilterChain.callNextMessageReceived(Ab stractIoFilterChain.java:362)
at org.apache.mina.common.support.AbstractIoFilterChain.access$1100(AbstractIoFilt erChain.java:54)
at org.apache.mina.common.support.AbstractIoFilterChain$EntryImpl$1.messageReceive d(AbstractIoFilterChain.java:800)
at org.apache.mina.filter.codec.support.SimpleProtocolDecoderOutput.flush(SimplePr otocolDecoderOutput.java:62)
at org.apache.mina.filter.codec.ProtocolCodecFilter.messageReceived(ProtocolCodecF ilter.java:200)
at org.apache.mina.common.support.AbstractIoFilterChain.callNextMessageReceived(Ab stractIoFilterChain.java:362)
at org.apache.mina.common.support.AbstractIoFilterChain.access$1100(AbstractIoFilt erChain.java:54)
at org.apache.mina.common.support.AbstractIoFilterChain$EntryImpl$1.messageReceive d(AbstractIoFilterChain.java:800)
at org.apache.mina.filter.executor.ExecutorFilter.processEvent(ExecutorFilter.java :266)
at org.apache.mina.filter.executor.ExecutorFilter$ProcessEventsRunnable.run(Execut orFilter.java:326)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java: 650)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
at java.lang.Thread.run(Thread.java:595)
2007.08.10 12:27:50 org.jivesoftware.openfire.ldap.LdapVCardProvider.getLdapAttributes(LdapVCardProv ider.java:158)
org.jivesoftware.openfire.user.UserNotFoundException: Username jmitchell not found
at org.jivesoftware.openfire.ldap.LdapManager.findUserDN(LdapManager.java:626)
at org.jivesoftware.openfire.ldap.LdapManager.findUserDN(LdapManager.java:554)
at org.jivesoftware.openfire.ldap.LdapVCardProvider.getLdapAttributes(LdapVCardPro vider.java:137)
at org.jivesoftware.openfire.ldap.LdapVCardProvider.loadVCard(LdapVCardProvider.ja va:176)
at org.jivesoftware.openfire.vcard.VCardManager.getOrLoadVCard(VCardManager.java:1 98)
at org.jivesoftware.openfire.vcard.VCardManager.getVCard(VCardManager.java:191)
at org.jivesoftware.openfire.handler.IQvCardHandler.handleIQ(IQvCardHandler.java:1 07)
at org.jivesoftware.openfire.handler.IQHandler.process(IQHandler.java:48)
at org.jivesoftware.openfire.IQRouter.handle(IQRouter.java:300)
at org.jivesoftware.openfire.IQRouter.route(IQRouter.java:104)
at org.jivesoftware.openfire.spi.PacketRouterImpl.route(PacketRouterImpl.java:67)
at org.jivesoftware.openfire.net.StanzaHandler.processIQ(StanzaHandler.java:289)
at org.jivesoftware.openfire.net.ClientStanzaHandler.processIQ(ClientStanzaHandler .java:79)
at org.jivesoftware.openfire.net.StanzaHandler.process(StanzaHandler.java:254)
at org.jivesoftware.openfire.net.StanzaHandler.process(StanzaHandler.java:153)
at org.jivesoftware.openfire.nio.ConnectionHandler.messageReceived(ConnectionHandl er.java:132)
at org.apache.mina.common.support.AbstractIoFilterChain$TailFilter.messageReceived (AbstractIoFilterChain.java:703)
at org.apache.mina.common.support.AbstractIoFilterChain.callNextMessageReceived(Ab stractIoFilterChain.java:362)
at org.apache.mina.common.support.AbstractIoFilterChain.access$1100(AbstractIoFilt erChain.java:54)
at org.apache.mina.common.support.AbstractIoFilterChain$EntryImpl$1.messageReceive d(AbstractIoFilterChain.java:800)
at org.apache.mina.filter.codec.support.SimpleProtocolDecoderOutput.flush(SimplePr otocolDecoderOutput.java:62)
at org.apache.mina.filter.codec.ProtocolCodecFilter.messageReceived(ProtocolCodecF ilter.java:200)
at org.apache.mina.common.support.AbstractIoFilterChain.callNextMessageReceived(Ab stractIoFilterChain.java:362)
at org.apache.mina.common.support.AbstractIoFilterChain.access$1100(AbstractIoFilt erChain.java:54)
at org.apache.mina.common.support.AbstractIoFilterChain$EntryImpl$1.messageReceive d(AbstractIoFilterChain.java:800)
at org.apache.mina.filter.executor.ExecutorFilter.processEvent(ExecutorFilter.java :266)
at org.apache.mina.filter.executor.ExecutorFilter$ProcessEventsRunnable.run(Execut orFilter.java:326)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java: 650)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
at java.lang.Thread.run(Thread.java:595)
2007.08.10 12:27:50 org.jivesoftware.openfire.handler.IQHandler.process(IQHandler.java:68) Internal server error
java.lang.NullPointerException: replacement
at java.util.regex.Matcher.replaceFirst(Matcher.java:844)
at java.lang.String.replaceFirst(String.java:1967)
at org.jivesoftware.openfire.ldap.LdapVCardProvider$VCard.treeWalk(LdapVCardProvid er.java:301)
at org.jivesoftware.openfire.ldap.LdapVCardProvider$VCard.getVCard(LdapVCardProvid er.java:282)
at org.jivesoftware.openfire.ldap.LdapVCardProvider.loadVCard(LdapVCardProvider.ja va:178)
at org.jivesoftware.openfire.vcard.VCardManager.getOrLoadVCard(VCardManager.java:1 98)
at org.jivesoftware.openfire.vcard.VCardManager.getVCard(VCardManager.java:191)
at org.jivesoftware.openfire.handler.IQvCardHandler.handleIQ(IQvCardHandler.java:1 07)
at org.jivesoftware.openfire.handler.IQHandler.process(IQHandler.java:48)
at org.jivesoftware.openfire.IQRouter.handle(IQRouter.java:300)
at org.jivesoftware.openfire.IQRouter.route(IQRouter.java:104)
at org.jivesoftware.openfire.spi.PacketRouterImpl.route(PacketRouterImpl.java:67)
at org.jivesoftware.openfire.net.StanzaHandler.processIQ(StanzaHandler.java:289)
at org.jivesoftware.openfire.net.ClientStanzaHandler.processIQ(ClientStanzaHandler .java:79)
at org.jivesoftware.openfire.net.StanzaHandler.process(StanzaHandler.java:254)
at org.jivesoftware.openfire.net.StanzaHandler.process(StanzaHandler.java:153)
at org.jivesoftware.openfire.nio.ConnectionHandler.messageReceived(ConnectionHandl er.java:132)
at org.apache.mina.common.support.AbstractIoFilterChain$TailFilter.messageReceived (AbstractIoFilterChain.java:703)
at org.apache.mina.common.support.AbstractIoFilterChain.callNextMessageReceived(Ab stractIoFilterChain.java:362)
at org.apache.mina.common.support.AbstractIoFilterChain.access$1100(AbstractIoFilt erChain.java:54)
at org.apache.mina.common.support.AbstractIoFilterChain$EntryImpl$1.messageReceive d(AbstractIoFilterChain.java:800)
at org.apache.mina.filter.codec.support.SimpleProtocolDecoderOutput.flush(SimplePr otocolDecoderOutput.java:62)
at org.apache.mina.filter.codec.ProtocolCodecFilter.messageReceived(ProtocolCodecF ilter.java:200)
at org.apache.mina.common.support.AbstractIoFilterChain.callNextMessageReceived(Ab stractIoFilterChain.java:362)
at org.apache.mina.common.support.AbstractIoFilterChain.access$1100(AbstractIoFilt erChain.java:54)
at org.apache.mina.common.support.AbstractIoFilterChain$EntryImpl$1.messageReceive d(AbstractIoFilterChain.java:800)
at org.apache.mina.filter.executor.ExecutorFilter.processEvent(ExecutorFilter.java :266)
at org.apache.mina.filter.executor.ExecutorFilter$ProcessEventsRunnable.run(Execut orFilter.java:326)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java: 650)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
at java.lang.Thread.run(Thread.java:595)
Hey avidan,
Could you check that jide@cimgroup.com is not present in the IQ roster that the server is sending to the client? Many clients allow you to open an XML console or debugger to inspect the XML traffic.
Regards,
– Gato
here is what i see in my spark log:
Jun 18, 2007 10:35:31 AM org.jivesoftware.spark.util.log.Log error
SEVERE: Unable to add new entry acastner@cimgroup.com
No response from the server.:
at org.jivesoftware.smack.Roster.createEntry(Roster.java:249)
at org.jivesoftware.spark.ui.RosterDialog.addEntry(RosterDialog.java:447)
at org.jivesoftware.spark.ui.RosterDialog$4.construct(RosterDialog.java:412)
at org.jivesoftware.spark.util.SwingWorker$2.run(SwingWorker.java:129)
at java.lang.Thread.run(Unknown Source)
How can I get the XML?
How can I confirm that the user is present in the IQ roster? Can Spark open an XML console?
Oh, and Gato, it seems that you are the one to answer my question. Or so say the guys in the spark forum: Spark 2.5.5 Add new contact, get signed off
How can I confirm that the user is present in the IQ roster? Can Spark open an XML console?
In the login window of Spark you will find an advanced button. Click on that button to open a window that will let you indicate that you want to open the debugger window when logging in.
Regards,
– Gato
Here is what I get.
<iq id=“L95jh-44” to=“search.cimgroup.com” type=“get”>
<query xmlns=“jabber:iq:search”/>
</iq>
<iq id=“L95jh-44” to="avidan@cimgroup.com/spark" from=“search.cimgroup.com” type=“result”>
<query xmlns=“jabber:iq:search”>
<FORM_TYPE>jabber:iq:search</FORM_TYPE>
<Username>1</Username>
<Name>1</Name>
<Email>1</Email>
</query>
</iq>
<iq id=“L95jh-45” to=“search.cimgroup.com” type=“set”>
<query xmlns=“jabber:iq:search”>
<x xmlns=“jabber:x:data” type=“submit”>
<field var=“FORM_TYPE” type=“hidden”>
<value>jabber:iq:search</value>
</field>
<field var=“search” type=“text-single”>
<value>laura campbell</value>
</field>
<field var=“Username” type=“boolean”>
<value>1</value>
</field>
<field var=“Name” type=“boolean”>
<value>1</value>
</field>
<field var=“Email” type=“boolean”>
<value>1</value>
</field>
</x>
</query>
</iq>
<iq id=“L95jh-45” to="avidan@cimgroup.com/spark" from=“search.cimgroup.com” type=“result”>
<query xmlns=“jabber:iq:search”>
<x xmlns=“jabber:x:data” type=“result”>
<reported>
<field label=“JID” var=“jid”/>
<field label=“Username” var=“Username”/>
<field label=“Name” var=“Name”/>
<field label=“Email” var=“Email”/>
</reported>
<item>
<field var=“jid”>
<value>lcampbell@cimgroup.com</value>
</field>
<field var=“Username”>
<value>lcampbell</value>
</field>
<field var=“Name”>
<value>Laura Campbell</value>
</field>
<field var=“Email”>
<value>LCampbell@cimgroup.com</value>
</field>
</item>
<field var=“FORM_TYPE” type=“hidden”/>
</x>
</query>
</iq>
<iq id=“L95jh-46” type=“set”>
<query xmlns=“jabber:iq:roster”>
<item jid="lcampbell@cimgroup.com" name="lcampbell">
<group>Friends</group>
</item>
</query>
</iq>
<iq id=“944-274” to="avidan@cimgroup.com/spark" type=“set”>
<query xmlns=“jabber:iq:roster”>
<item jid="lcampbell@cimgroup.com" name="lcampbell" subscription="none">
<group>Friends</group>
</item>
</query>
</iq>
<presence id=“L95jh-47” to="lcampbell@cimgroup.com" type=“subscribe”/>
<iq id=“L95jh-46” to="avidan@cimgroup.com/spark" type=“result”/>
<iq id=“653-275” to="avidan@cimgroup.com/spark" type=“set”>
<query xmlns=“jabber:iq:roster”>
<item jid="lcampbell@cimgroup.com" name="lcampbell" subscription="none" ask="subscribe">
<group>Friends</group>
</item>
</query>
</iq>
Hey avidan,
The first 4 entries are unrelated to the roster. They are about searching. The 5th entry is an addition to the roster that it worked just fine. Could you:
Post the iq result for the iq:roster packet? That would be the roster as returned from the server and
Post the XML that you send and receive when you try to add the faulty contact?
Your posted XML show no problem at all while adding new contacts to your roster.
Thanks,
– Gato
Then the issue must be with Openfire, right?
2007.08.13 17:12:23 org.jivesoftware.openfire.handler.IQRosterHandler.handleIQ(IQRosterHandler.java: 128) Internal server error
org.jivesoftware.openfire.user.UserAlreadyExistsException: bozduzen@cimgroup.com
at org.jivesoftware.openfire.roster.RosterItemProvider.createItem(RosterItemProvid er.java:108)
at org.jivesoftware.openfire.roster.Roster.provideRosterItem(Roster.java:334)
at org.jivesoftware.openfire.roster.Roster.provideRosterItem(Roster.java:295)
at org.jivesoftware.openfire.roster.Roster.createRosterItem(Roster.java:280)
at org.jivesoftware.openfire.handler.IQRosterHandler.manageRoster(IQRosterHandler. java:226)
at org.jivesoftware.openfire.handler.IQRosterHandler.handleIQ(IQRosterHandler.java :105)
at org.jivesoftware.openfire.handler.IQHandler.process(IQHandler.java:48)
at org.jivesoftware.openfire.IQRouter.handle(IQRouter.java:300)
at org.jivesoftware.openfire.IQRouter.route(IQRouter.java:104)
at org.jivesoftware.openfire.spi.PacketRouterImpl.route(PacketRouterImpl.java:67)
at org.jivesoftware.openfire.net.StanzaHandler.processIQ(StanzaHandler.java:289)
at org.jivesoftware.openfire.net.ClientStanzaHandler.processIQ(ClientStanzaHandler .java:79)
at org.jivesoftware.openfire.net.StanzaHandler.process(StanzaHandler.java:254)
at org.jivesoftware.openfire.net.StanzaHandler.process(StanzaHandler.java:153)
at org.jivesoftware.openfire.nio.ConnectionHandler.messageReceived(ConnectionHandl er.java:132)
at org.apache.mina.common.support.AbstractIoFilterChain$TailFilter.messageReceived (AbstractIoFilterChain.java:703)
at org.apache.mina.common.support.AbstractIoFilterChain.callNextMessageReceived(Ab stractIoFilterChain.java:362)
at org.apache.mina.common.support.AbstractIoFilterChain.access$1100(AbstractIoFilt erChain.java:54)
at org.apache.mina.common.support.AbstractIoFilterChain$EntryImpl$1.messageReceive d(AbstractIoFilterChain.java:800)
at org.apache.mina.filter.codec.support.SimpleProtocolDecoderOutput.flush(SimplePr otocolDecoderOutput.java:62)
at org.apache.mina.filter.codec.ProtocolCodecFilter.messageReceived(ProtocolCodecF ilter.java:200)
at org.apache.mina.common.support.AbstractIoFilterChain.callNextMessageReceived(Ab stractIoFilterChain.java:362)
at org.apache.mina.common.support.AbstractIoFilterChain.access$1100(AbstractIoFilt erChain.java:54)
at org.apache.mina.common.support.AbstractIoFilterChain$EntryImpl$1.messageReceive d(AbstractIoFilterChain.java:800)
at org.apache.mina.filter.executor.ExecutorFilter.processEvent(ExecutorFilter.java :266)
at org.apache.mina.filter.executor.ExecutorFilter$ProcessEventsRunnable.run(Execut orFilter.java:326)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java: 650)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
at java.lang.Thread.run(Thread.java:595)
It would seem like it. I would suggest upgrading to the latest stable release of Openfire. This should solve any issues you currently have.
I am currently running the newest version (3.3.2)…could there have been a mysql schema change that didn’t take effect?
Was there any resolution to this problem? We have the same issue.
Turns out there were orphaned entries in jiveRosterGroups.
How would one go about removing these orphaned entries? Do these entries need to be cleared from the db?
thanks
Issuing SQL like so:
delete from jiveRosterGroups where rosterID=414;
But you should know, the problems continued at random… until I found an even deeper root cause, about 5 weeks ago I had upgraded from 3.1.1 using HSQLDB data (roster data) imported into MySQL. I failed to migrate the jiveID table which is apparently a feeder table for incrementing IDs. So thereafter there were conflicting ids entering the system. I bumped the id in this table to 2001 (larger than any existing rosterID column) for typeID=18 and this seems to have fixed the issue for good.
i ran tcpdump while this was happening, and got this error:
<iq type=“error” id=“Eyn6Y-56” to="avidan@cimgroup.com/spark"><query xmlns=“jabber:iq:roster”><item jid="ittest@cimgroup.com" name=“ittest”><group>Friends</group></item></query>& lt;error code=“500” type=“wait”><internal-server-error xmlns=“urn:ietf:params:xml:ns:xmpp-stanzas”/></error></iq>
I was hoping to see the UNIQUE key error, but did not. How can I check if this is an orphan issue?
Hey avidan,
Have you checked the error logs of the server? Internal server errors are usually accompanied with an entry in the log files.
Regards,
– Gato
yes, still the same error as in the 3rd post of this thread…