Bug 629768 – Get Jabber "Authentication failed" sometimes due to resource re-use ?

After an evaluation, GNOME has moved from Bugzilla to GitLab. Learn more about GitLab.
No new issues can be reported in GNOME Bugzilla anymore.
To report an issue in a GNOME project, go to GNOME GitLab.
Do not go to GNOME Gitlab for: Bluefish, Doxygen, GnuCash, GStreamer, java-gnome, LDTP, NetworkManager, Tomboy.

Bug 629768 - Get Jabber "Authentication failed" sometimes due to resource re-use ?


Summary:	Get Jabber "Authentication failed" sometimes due to resource re-use ?


Status:	RESOLVED NOTABUG

Product:	empathy
Classification:	Core
Component:	Accounts
Version:	2.30.x
Hardware:	Other Linux

Importance:	Normal normal
Target Milestone:	---
Assigned To:	empathy-maint
QA Contact:

URL:
Whiteboard:

Depends on:
Blocks:

Reported:	2010-09-15 15:02 UTC by Joe Barnett
Modified:	2010-09-20 06:47 UTC

See Also:
GNOME target:	---
GNOME version:	---

Description Joe Barnett 2010-09-15 15:02:02 UTC

I connect to my company's openfire jabber server over VPN.  Sometimes when the VPN dies, I can't seem to reconnect for a while, and get "Authentication failed" red box at the top of the chat window.


debug window logs show that I'm getting a 409 error trying to bind a resource that looks like some hex number, but not sure what that resource is/represents:


gabble/connection-DEBUG: 09/15/2010 07:48:05.259110: gabble_connection_init: Initializing (GabbleConnection *)0x2366360
gabble/muc-DEBUG: 09/15/2010 07:48:05.259368: gabble_roomlist_manager_constructed: 0x2a8b230
gabble/connection-DEBUG: 09/15/2010 07:48:05.259675: gabble_connection_constructor: Post-construction: (GabbleConnection *)0x2366360
gabble/jid-DEBUG: 09/15/2010 07:48:05.259927: gabble_signal_connect_weak: connecting to 0x25b4440:item-found with context 0x2938da0
gabble/jid-DEBUG: 09/15/2010 07:48:05.260020: gabble_signal_connect_weak: connecting to 0x2366360:status-changed with context 0x26620c0
gabble/connection-DEBUG: 09/15/2010 07:48:05.260122: gabble_connection_constructed: defaulted resource to 1cf31723
gabble/connection-DEBUG: 09/15/2010 07:48:05.268506: _gabble_connection_connect: disabling SRV because "server" or "old-ssl" was specified or port was not 5222, will connect to rooms.talk.company.com
gabble/connection-DEBUG: 09/15/2010 07:48:05.268666: do_connect: calling lm_connection_open
LM-DEBUG: 09/15/2010 07:48:05.268806: Connecting to: rooms.talk.company.com:5222
LM-DEBUG: 09/15/2010 07:48:05.268915: SRV lookup disabled for rooms.talk.company.com
LM-DEBUG: 09/15/2010 07:48:05.268996: Going to connect to rooms.talk.company.com:5222
gabble/roster-DEBUG: 09/15/2010 07:48:05.270031: connection_status_changed_cb: adding callbacks
gabble/im-DEBUG: 09/15/2010 07:48:05.270358: connection_status_changed_cb: adding callbacks
gabble/muc-DEBUG: 09/15/2010 07:48:05.270514: connection_status_changed_cb: adding callbacks
LM-DEBUG: 09/15/2010 07:48:06.153196: Trying 10.0.1.36 port 5222...
LM-DEBUG: 09/15/2010 07:48:06.930455: Connection success (1).
LM-DEBUG: 09/15/2010 07:48:06.930614: 
SEND:
LM-DEBUG: 09/15/2010 07:48:06.930699: -----------------------------------
LM-DEBUG: 09/15/2010 07:48:06.930788: <?xml version='1.0' encoding='UTF-8'?>
LM-DEBUG: 09/15/2010 07:48:06.930866: -----------------------------------
LM-DEBUG: 09/15/2010 07:48:06.930964: Sending stream header
LM-DEBUG: 09/15/2010 07:48:06.931107: 
SEND:
LM-DEBUG: 09/15/2010 07:48:06.931195: -----------------------------------
LM-DEBUG: 09/15/2010 07:48:06.931282: <stream:stream version="1.0" xmlns="jabber:client" xmlns:stream="http://etherx.jabber.org/streams" to="talk.company.com" id="8909931048">
LM-DEBUG: 09/15/2010 07:48:06.931366: -----------------------------------
LM-DEBUG: 09/15/2010 07:48:07.214056: 
RECV [195]:
LM-DEBUG: 09/15/2010 07:48:07.214195: -----------------------------------
LM-DEBUG: 09/15/2010 07:48:07.214281: '<?xml version='1.0' encoding='UTF-8'?><stream:stream xmlns:stream="http://etherx.jabber.org/streams" xmlns="jabber:client" from="talk.company.com" id="6b68fb61" xml:lang="en" version="1.0">'
LM-DEBUG: 09/15/2010 07:48:07.214365: -----------------------------------
LM-DEBUG: 09/15/2010 07:48:07.214445: Read: 195 chars
LM-DEBUG: 09/15/2010 07:48:07.214564: ATTRIBUTE: xmlns:stream = http://etherx.jabber.org/streams
LM-DEBUG: 09/15/2010 07:48:07.214653: ATTRIBUTE: xmlns = jabber:client
LM-DEBUG: 09/15/2010 07:48:07.214735: ATTRIBUTE: from = talk.company.com
LM-DEBUG: 09/15/2010 07:48:07.214816: ATTRIBUTE: id = 6b68fb61
LM-DEBUG: 09/15/2010 07:48:07.214898: ATTRIBUTE: xml:lang = en
LM-DEBUG: 09/15/2010 07:48:07.214976: ATTRIBUTE: version = 1.0
LM-DEBUG: 09/15/2010 07:48:07.215055: Trying to close node: stream:stream
LM-DEBUG: 09/15/2010 07:48:07.215135: Have a new message
LM-DEBUG: 09/15/2010 07:48:07.215218: New message with type="stream:stream" from: talk.company.com
LM-DEBUG: 09/15/2010 07:48:07.215327: XMPP 1.0 stream received: 6b68fb61
gabble/connection-DEBUG: 09/15/2010 07:48:07.215428: do_auth: authenticating with username: username, password: <hidden>, resource: 1cf31723
LM-DEBUG: 09/15/2010 07:48:07.415895: 
RECV [390]:
LM-DEBUG: 09/15/2010 07:48:07.416049: -----------------------------------
LM-DEBUG: 09/15/2010 07:48:07.416150: '<stream:features><starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"></starttls><mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"><mechanism>PLAIN</mechanism></mechanisms><compression xmlns="http://jabber.org/features/compress"><method>zlib</method></compression><auth xmlns="http://jabber.org/features/iq-auth"/><register xmlns="http://jabber.org/features/iq-register"/></stream:features>'
LM-DEBUG: 09/15/2010 07:48:07.416234: -----------------------------------
LM-DEBUG: 09/15/2010 07:48:07.416311: Read: 390 chars
LM-DEBUG: 09/15/2010 07:48:07.416404: ATTRIBUTE: xmlns = urn:ietf:params:xml:ns:xmpp-tls
LM-DEBUG: 09/15/2010 07:48:07.416484: Trying to close node: starttls
LM-DEBUG: 09/15/2010 07:48:07.416560: ATTRIBUTE: xmlns = urn:ietf:params:xml:ns:xmpp-sasl
LM-DEBUG: 09/15/2010 07:48:07.416644: Trying to close node: mechanism
LM-DEBUG: 09/15/2010 07:48:07.416718: Trying to close node: mechanisms
LM-DEBUG: 09/15/2010 07:48:07.416799: ATTRIBUTE: xmlns = http://jabber.org/features/compress
LM-DEBUG: 09/15/2010 07:48:07.416884: Trying to close node: method
LM-DEBUG: 09/15/2010 07:48:07.416964: Trying to close node: compression
LM-DEBUG: 09/15/2010 07:48:07.417048: ATTRIBUTE: xmlns = http://jabber.org/features/iq-auth
LM-DEBUG: 09/15/2010 07:48:07.417126: Trying to close node: auth
LM-DEBUG: 09/15/2010 07:48:07.417207: ATTRIBUTE: xmlns = http://jabber.org/features/iq-register
LM-DEBUG: 09/15/2010 07:48:07.417295: Trying to close node: register
LM-DEBUG: 09/15/2010 07:48:07.417373: Trying to close node: stream:features
LM-DEBUG: 09/15/2010 07:48:07.417450: Have a new message
LM-DEBUG: 09/15/2010 07:48:07.417529: New message with type="stream:error" from: unknown
LM-DEBUG: 09/15/2010 07:48:07.417651: 
SEND:
LM-DEBUG: 09/15/2010 07:48:07.417747: -----------------------------------
LM-DEBUG: 09/15/2010 07:48:07.417824: <starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls" id="27187417629"></starttls>
LM-DEBUG: 09/15/2010 07:48:07.417896: -----------------------------------
LM-DEBUG: 09/15/2010 07:48:07.642102: 
RECV [50]:
LM-DEBUG: 09/15/2010 07:48:07.642236: -----------------------------------
LM-DEBUG: 09/15/2010 07:48:07.642321: '<proceed xmlns="urn:ietf:params:xml:ns:xmpp-tls"/>'
LM-DEBUG: 09/15/2010 07:48:07.642398: -----------------------------------
LM-DEBUG: 09/15/2010 07:48:07.642476: Read: 50 chars
LM-DEBUG: 09/15/2010 07:48:07.642559: ATTRIBUTE: xmlns = urn:ietf:params:xml:ns:xmpp-tls
LM-DEBUG: 09/15/2010 07:48:07.642640: Trying to close node: proceed
LM-DEBUG: 09/15/2010 07:48:07.642719: Have a new message
LM-DEBUG: 09/15/2010 07:48:07.642796: New message with type="proceed" from: unknown
LM-DEBUG: 09/15/2010 07:48:07.642899: Setting up SSL...
gabble/connection-DEBUG: 09/15/2010 07:48:08.942964: connection_ssl_cb: called: The certificate can not be trusted.
LM-DEBUG: 09/15/2010 07:48:08.943578: GNUTLS negotiated compression: NULL
LM-DEBUG: 09/15/2010 07:48:08.943639: Sending stream header
LM-DEBUG: 09/15/2010 07:48:08.943712: 
SEND:
LM-DEBUG: 09/15/2010 07:48:08.943766: -----------------------------------
LM-DEBUG: 09/15/2010 07:48:08.943840: <stream:stream version="1.0" xmlns="jabber:client" xmlns:stream="http://etherx.jabber.org/streams" to="talk.company.com" id="21047943692">
LM-DEBUG: 09/15/2010 07:48:08.943912: -----------------------------------
LM-DEBUG: 09/15/2010 07:48:09.238724: 
RECV [524]:
LM-DEBUG: 09/15/2010 07:48:09.238807: -----------------------------------
LM-DEBUG: 09/15/2010 07:48:09.238882: '<?xml version='1.0' encoding='UTF-8'?><stream:stream xmlns:stream="http://etherx.jabber.org/streams" xmlns="jabber:client" from="talk.company.com" id="6b68fb61" xml:lang="en" version="1.0"><stream:features><mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"><mechanism>PLAIN</mechanism></mechanisms><compression xmlns="http://jabber.org/features/compress"><method>zlib</method></compression><auth xmlns="http://jabber.org/features/iq-auth"/><register xmlns="http://jabber.org/features/iq-register"/></stream:features>'
LM-DEBUG: 09/15/2010 07:48:09.238954: -----------------------------------
LM-DEBUG: 09/15/2010 07:48:09.238996: Read: 524 chars
LM-DEBUG: 09/15/2010 07:48:09.239047: ATTRIBUTE: xmlns:stream = http://etherx.jabber.org/streams
LM-DEBUG: 09/15/2010 07:48:09.239094: ATTRIBUTE: xmlns = jabber:client
LM-DEBUG: 09/15/2010 07:48:09.239139: ATTRIBUTE: from = talk.company.com
LM-DEBUG: 09/15/2010 07:48:09.239213: ATTRIBUTE: id = 6b68fb61
LM-DEBUG: 09/15/2010 07:48:09.239283: ATTRIBUTE: xml:lang = en
LM-DEBUG: 09/15/2010 07:48:09.239356: ATTRIBUTE: version = 1.0
LM-DEBUG: 09/15/2010 07:48:09.239428: Trying to close node: stream:stream
LM-DEBUG: 09/15/2010 07:48:09.239499: Have a new message
LM-DEBUG: 09/15/2010 07:48:09.239573: New message with type="stream:stream" from: talk.company.com
LM-DEBUG: 09/15/2010 07:48:09.239653: ATTRIBUTE: xmlns = urn:ietf:params:xml:ns:xmpp-sasl
LM-DEBUG: 09/15/2010 07:48:09.239732: Trying to close node: mechanism
LM-DEBUG: 09/15/2010 07:48:09.239806: Trying to close node: mechanisms
LM-DEBUG: 09/15/2010 07:48:09.239883: ATTRIBUTE: xmlns = http://jabber.org/features/compress
LM-DEBUG: 09/15/2010 07:48:09.239960: Trying to close node: method
LM-DEBUG: 09/15/2010 07:48:09.240036: Trying to close node: compression
LM-DEBUG: 09/15/2010 07:48:09.240112: ATTRIBUTE: xmlns = http://jabber.org/features/iq-auth
LM-DEBUG: 09/15/2010 07:48:09.240187: Trying to close node: auth
LM-DEBUG: 09/15/2010 07:48:09.240263: ATTRIBUTE: xmlns = http://jabber.org/features/iq-register
LM-DEBUG: 09/15/2010 07:48:09.240338: Trying to close node: register
LM-DEBUG: 09/15/2010 07:48:09.240410: Trying to close node: stream:features
LM-DEBUG: 09/15/2010 07:48:09.240480: Have a new message
LM-DEBUG: 09/15/2010 07:48:09.240550: New message with type="stream:error" from: unknown
LM-DEBUG: 09/15/2010 07:48:09.240641: XMPP 1.0 stream received: 6b68fb61
LM-DEBUG: 09/15/2010 07:48:09.240736: Stream features received
LM-DEBUG: 09/15/2010 07:48:09.240844: 
SEND:
LM-DEBUG: 09/15/2010 07:48:09.240916: -----------------------------------
LM-DEBUG: 09/15/2010 07:48:09.240988: <auth mechanism="PLAIN" xmlns="urn:ietf:params:xml:ns:xmpp-sasl" ga:client-uses-full-bind-result="true" xmlns:ga="http://www.google.com/talk/protocol/auth" id="39640240808">AGpiYXJuZXR0AHN3ZWV6ZTIy</auth>
LM-DEBUG: 09/15/2010 07:48:09.241061: -----------------------------------
LM-DEBUG: 09/15/2010 07:48:09.789612: 
RECV [51]:
LM-DEBUG: 09/15/2010 07:48:09.789746: -----------------------------------
LM-DEBUG: 09/15/2010 07:48:09.789875: '<success xmlns="urn:ietf:params:xml:ns:xmpp-sasl"/>'
LM-DEBUG: 09/15/2010 07:48:09.789995: -----------------------------------
LM-DEBUG: 09/15/2010 07:48:09.790103: Read: 51 chars
LM-DEBUG: 09/15/2010 07:48:09.790224: ATTRIBUTE: xmlns = urn:ietf:params:xml:ns:xmpp-sasl
LM-DEBUG: 09/15/2010 07:48:09.790363: Trying to close node: success
LM-DEBUG: 09/15/2010 07:48:09.790493: Have a new message
LM-DEBUG: 09/15/2010 07:48:09.790628: New message with type="success" from: unknown
LM-DEBUG: 09/15/2010 07:48:09.790792: sasl_success_cb: SASL authentication successful
LM-DEBUG: 09/15/2010 07:48:09.790925: Sending stream header
LM-DEBUG: 09/15/2010 07:48:09.791101: 
SEND:
LM-DEBUG: 09/15/2010 07:48:09.791238: -----------------------------------
LM-DEBUG: 09/15/2010 07:48:09.791373: <stream:stream version="1.0" xmlns="jabber:client" xmlns:stream="http://etherx.jabber.org/streams" to="talk.company.com" id="7738791053">
LM-DEBUG: 09/15/2010 07:48:09.791503: -----------------------------------
LM-DEBUG: 09/15/2010 07:48:09.877006: 
RECV [424]:
LM-DEBUG: 09/15/2010 07:48:09.877142: -----------------------------------
LM-DEBUG: 09/15/2010 07:48:09.877275: '<?xml version='1.0' encoding='UTF-8'?><stream:stream xmlns:stream="http://etherx.jabber.org/streams" xmlns="jabber:client" from="talk.company.com" id="6b68fb61" xml:lang="en" version="1.0"><stream:features><compression xmlns="http://jabber.org/features/compress"><method>zlib</method></compression><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"/><session xmlns="urn:ietf:params:xml:ns:xmpp-session"/></stream:features>'
LM-DEBUG: 09/15/2010 07:48:09.877397: -----------------------------------
LM-DEBUG: 09/15/2010 07:48:09.877505: Read: 424 chars
LM-DEBUG: 09/15/2010 07:48:09.877640: ATTRIBUTE: xmlns:stream = http://etherx.jabber.org/streams
LM-DEBUG: 09/15/2010 07:48:09.877779: ATTRIBUTE: xmlns = jabber:client
LM-DEBUG: 09/15/2010 07:48:09.877907: ATTRIBUTE: from = talk.company.com
LM-DEBUG: 09/15/2010 07:48:09.878045: ATTRIBUTE: id = 6b68fb61
LM-DEBUG: 09/15/2010 07:48:09.878180: ATTRIBUTE: xml:lang = en
LM-DEBUG: 09/15/2010 07:48:09.878314: ATTRIBUTE: version = 1.0
LM-DEBUG: 09/15/2010 07:48:09.878448: Trying to close node: stream:stream
LM-DEBUG: 09/15/2010 07:48:09.878582: Have a new message
LM-DEBUG: 09/15/2010 07:48:09.878716: New message with type="stream:stream" from: talk.company.com
LM-DEBUG: 09/15/2010 07:48:09.878863: ATTRIBUTE: xmlns = http://jabber.org/features/compress
LM-DEBUG: 09/15/2010 07:48:09.879000: Trying to close node: method
LM-DEBUG: 09/15/2010 07:48:09.879137: Trying to close node: compression
LM-DEBUG: 09/15/2010 07:48:09.879276: ATTRIBUTE: xmlns = urn:ietf:params:xml:ns:xmpp-bind
LM-DEBUG: 09/15/2010 07:48:09.879414: Trying to close node: bind
LM-DEBUG: 09/15/2010 07:48:09.879551: ATTRIBUTE: xmlns = urn:ietf:params:xml:ns:xmpp-session
LM-DEBUG: 09/15/2010 07:48:09.879687: Trying to close node: session
LM-DEBUG: 09/15/2010 07:48:09.879823: Trying to close node: stream:features
LM-DEBUG: 09/15/2010 07:48:09.879955: Have a new message
LM-DEBUG: 09/15/2010 07:48:09.880086: New message with type="stream:error" from: unknown
LM-DEBUG: 09/15/2010 07:48:09.880251: XMPP 1.0 stream received: 6b68fb61
LM-DEBUG: 09/15/2010 07:48:09.880472: 
SEND:
LM-DEBUG: 09/15/2010 07:48:09.880611: -----------------------------------
LM-DEBUG: 09/15/2010 07:48:09.880748: <iq type="set" id="23123880423"> <bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"> <resource>1cf31723</resource>
</bind>
</iq>
LM-DEBUG: 09/15/2010 07:48:09.880881: -----------------------------------
LM-DEBUG: 09/15/2010 07:48:09.881120: Stream features received
LM-DEBUG: 09/15/2010 07:48:09.956043: 
RECV [256]:
LM-DEBUG: 09/15/2010 07:48:09.956104: -----------------------------------
LM-DEBUG: 09/15/2010 07:48:09.956152: '<iq type="error" id="23123880423" to="talk.company.com/6b68fb61"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"> <resource>1cf31723</resource>
</bind><error code="409" type="cancel"><conflict xmlns="urn:ietf:params:xml:ns:xmpp-stanzas"/></error></iq>'
LM-DEBUG: 09/15/2010 07:48:09.956193: -----------------------------------
LM-DEBUG: 09/15/2010 07:48:09.956232: Read: 256 chars
LM-DEBUG: 09/15/2010 07:48:09.956274: ATTRIBUTE: type = error
LM-DEBUG: 09/15/2010 07:48:09.956309: ATTRIBUTE: id = 23123880423
LM-DEBUG: 09/15/2010 07:48:09.956342: ATTRIBUTE: to = talk.company.com/6b68fb61
LM-DEBUG: 09/15/2010 07:48:09.956384: ATTRIBUTE: xmlns = urn:ietf:params:xml:ns:xmpp-bind
LM-DEBUG: 09/15/2010 07:48:09.956455: Trying to close node: resource
LM-DEBUG: 09/15/2010 07:48:09.956531: Trying to close node: bind
LM-DEBUG: 09/15/2010 07:48:09.956604: ATTRIBUTE: code = 409
LM-DEBUG: 09/15/2010 07:48:09.956677: ATTRIBUTE: type = cancel
LM-DEBUG: 09/15/2010 07:48:09.956754: ATTRIBUTE: xmlns = urn:ietf:params:xml:ns:xmpp-stanzas
LM-DEBUG: 09/15/2010 07:48:09.956829: Trying to close node: conflict
LM-DEBUG: 09/15/2010 07:48:09.956887: Trying to close node: error
LM-DEBUG: 09/15/2010 07:48:09.956963: Trying to close node: iq
LM-DEBUG: 09/15/2010 07:48:09.957035: Have a new message
LM-DEBUG: 09/15/2010 07:48:09.957107: New message with type="iq" from: unknown
LM-DEBUG: 09/15/2010 07:48:09.957197: connection_bind_reply: error while binding to resource
gabble/connection-DEBUG: 09/15/2010 07:48:09.957274: connection_auth_cb: failed
gabble/roster-DEBUG: 09/15/2010 07:48:09.957355: gabble_roster_close_all: closing channels
gabble/roster-DEBUG: 09/15/2010 07:48:09.957434: gabble_roster_close_all: removing callbacks
gabble/im-DEBUG: 09/15/2010 07:48:09.957509: gabble_im_factory_close_all: closing channels
gabble/im-DEBUG: 09/15/2010 07:48:09.957587: gabble_im_factory_close_all: removing callbacks
gabble/muc-DEBUG: 09/15/2010 07:48:09.957663: connection_status_changed_cb: disconnected, closing room lists
gabble/muc-DEBUG: 09/15/2010 07:48:09.957736: gabble_roomlist_manager_close_all: 0x2a8b230
gabble/muc-DEBUG: 09/15/2010 07:48:09.957811: gabble_muc_factory_close_all: closing channels
gabble/muc-DEBUG: 09/15/2010 07:48:09.957887: gabble_muc_factory_close_all: removing callbacks
gabble/tubes-DEBUG: 09/15/2010 07:48:09.957964: gabble_private_tubes_factory_close_all: closing 1-1 tubes channels
gabble/media-channel-DEBUG: 09/15/2010 07:48:09.958045: gabble_media_factory_close_all: closing channels
gabble/connection-DEBUG: 09/15/2010 07:48:09.958141: connection_shut_down: still open; calling lm_connection_close
LM-DEBUG: 09/15/2010 07:48:09.958219: Disconnecting from: rooms.talk.company.com:5222
LM-DEBUG: 09/15/2010 07:48:09.958290: 
SEND:
LM-DEBUG: 09/15/2010 07:48:09.958359: -----------------------------------
LM-DEBUG: 09/15/2010 07:48:09.958430: </stream:stream>
LM-DEBUG: 09/15/2010 07:48:09.958499: -----------------------------------
LM-DEBUG: 09/15/2010 07:48:09.958636: Freeing up IOChannel and file descriptor
gabble/connection-DEBUG: 09/15/2010 07:48:09.963490: connection_disconnected_cb: called with reason 0
gabble/connection-DEBUG: 09/15/2010 07:48:09.963561: connection_disconnected_cb: expected; emitting DISCONNECTED
gabble/connection-DEBUG: 09/15/2010 07:48:09.963702: gabble_connection_dispose: called
gabble/bytestream-DEBUG: 09/15/2010 07:48:09.963771: gabble_bytestream_factory_dispose: dispose called
gabble/jid-DEBUG: 09/15/2010 07:48:09.963850: user_data_destroyed_cb: user_data for 0x2938da0 destroyed; disconnecting
gabble/jid-DEBUG: 09/15/2010 07:48:09.963927: user_data_destroyed_cb: user_data for 0x26620c0 destroyed; disconnecting
gabble/disco-DEBUG: 09/15/2010 07:48:09.964003: gabble_disco_dispose: dispose called
gabble/disco-DEBUG: 09/15/2010 07:48:09.964077: gabble_disco_finalize: called with 0x25b4440
gabble/pipeline-DEBUG: 09/15/2010 07:48:09.964154: gabble_request_pipeline_dispose: disposing request-pipeline
gabble/vcard-DEBUG: 09/15/2010 07:48:09.964230: gabble_vcard_manager_dispose: 0x2364910
gabble/vcard-DEBUG: 09/15/2010 07:48:09.964309: gabble_vcard_manager_finalize: 0x2364910
gabble/media-channel-DEBUG: 09/15/2010 07:48:09.964382: gabble_jingle_factory_dispose: dispose called
gabble/presence-DEBUG: 09/15/2010 07:48:09.964462: gabble_presence_cache_dispose: dispose called
gabble/presence-DEBUG: 09/15/2010 07:48:09.964557: gabble_presence_cache_finalize: called with 0x236d120
gabble/roster-DEBUG: 09/15/2010 07:48:09.968019: gabble_roster_dispose: dispose called
gabble/roster-DEBUG: 09/15/2010 07:48:09.968135: gabble_roster_close_all: closing channels
gabble/roster-DEBUG: 09/15/2010 07:48:09.968278: gabble_roster_finalize: called with 0x293ac00
gabble/im-DEBUG: 09/15/2010 07:48:09.968411: gabble_im_factory_dispose: dispose called
gabble/muc-DEBUG: 09/15/2010 07:48:09.968558: gabble_roomlist_manager_dispose: running
gabble/muc-DEBUG: 09/15/2010 07:48:09.968693: gabble_roomlist_manager_close_all: 0x2a8b230
gabble/muc-DEBUG: 09/15/2010 07:48:09.968832: gabble_muc_factory_dispose: dispose called
gabble/muc-DEBUG: 09/15/2010 07:48:09.968961: gabble_muc_factory_close_all: closing channels
gabble/tubes-DEBUG: 09/15/2010 07:48:09.969109: gabble_private_tubes_factory_dispose: dispose called
gabble/tubes-DEBUG: 09/15/2010 07:48:09.969240: gabble_private_tubes_factory_close_all: closing 1-1 tubes channels
gabble/media-channel-DEBUG: 09/15/2010 07:48:09.969384: gabble_media_factory_dispose: dispose called
gabble/media-channel-DEBUG: 09/15/2010 07:48:09.969738: gabble_media_factory_close_all: closing channels
gabble/olpc-DEBUG: 09/15/2010 07:48:09.969888: gabble_olpc_gadget_manager_dispose: running
gabble/olpc-DEBUG: 09/15/2010 07:48:09.970019: gabble_olpc_gadget_manager_close_all: 0x25b4080
gabble/connection-DEBUG: 09/15/2010 07:48:09.970256: gabble_connection_finalize: called with 0x2366360

Comment 1 Guillaume Desmottes 2010-09-16 08:18:28 UTC

The ressource is generated using your machine ID and is stable.

You can't connect twice using the same ressource, so you have to wait that your old TCP connection times out and so is disconnected from the server.

The server has 2 options when an user is trying to (re)connect the same ressource:
a) Kick out the first connection and let the new one replaces it
b) Refuse the connection

Both options are legal per XMPP standard but most servers use a) as it's the most useful one. It seems your server does b).
I'm not an OpenFire expert, maybe that's something you can configure?

Comment 2 Guus der Kinderen 2010-09-20 06:47:59 UTC

On a side note: Openfire does indeed allow you to configure the server in such a way that it will not accept an already-bound resource. This is not the default setting though. By default, Openfire will kick the older connection using the same resource. The server instance of the Reporter apparently has been configured to behave as the Reporter is experiencing. You can find the configuration page in Openfires Admin panel, under "Server" > "Server Settings" > "Resource Policy"