Bug #3229

Can't connect Vines server

Added by artem almost 4 years ago. Updated over 3 years ago.

Status:FeedbackStart date:04/08/2014
Priority:HighDue date:
Assignee:-% Done:

0%

Category:-
Target version:-
Component:

Description

Can't connect Vines server with default config. Pidgin does.
Android client shows "Signing in ..."
Server logs:

ubuntu@ubuntu-VirtualBox:~/vines/local.lit$ vines start
[2014-04-08T15:42:06Z] INFO -- vines: XMPP server started
[2014-04-08T15:42:06Z] INFO -- vines: Accepting client connections on 0.0.0.0:5222
[2014-04-08T15:42:06Z] INFO -- vines: Accepting server connections on 0.0.0.0:5269
[2014-04-08T15:42:06Z] INFO -- vines: Accepting http connections on 0.0.0.0:5280
[2014-04-08T15:42:06Z] INFO -- vines: Accepting component connections on 0.0.0.0:5347
[2014-04-08T15:42:15Z] INFO -- vines: Stream connected: 192.168.1.2:38712 > 192.168.1.6:5222
[2014-04-08T15:42:15Z] DEBUG -
vines: Received stanza: 192.168.1.2:38712 -> 192.168.1.6:5222
<stream:stream xmlns="jabber:client" xmlns:stream="http://etherx.jabber.org/streams" to="local.lit" version="1.0"/>

[2014-04-08T15:42:15Z] DEBUG -- vines: Sent stanza: 192.168.1.6:5222 -> 192.168.1.2:38712
<stream:stream xmlns='jabber:client' xmlns:stream='http://etherx.jabber.org/streams' xml:lang='en' id='99222cc1-e5df-4a07-99c1-a5a6fef6266f' from='local.lit' version='1.0'>

[2014-04-08T15:42:15Z] DEBUG -- vines: Sent stanza: 192.168.1.6:5222 -> 192.168.1.2:38712
<stream:features>
<starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls">
<required/>
</starttls>
</stream:features>

[2014-04-08T15:42:15Z] DEBUG -- vines: Received stanza: 192.168.1.2:38712 -> 192.168.1.6:5222
<starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"/>

[2014-04-08T15:42:15Z] DEBUG -- vines: Sent stanza: 192.168.1.6:5222 -> 192.168.1.2:38712
<proceed xmlns="urn:ietf:params:xml:ns:xmpp-tls"/>

[2014-04-08T15:42:16Z] DEBUG -- vines: Received stanza: 192.168.1.2:38712 -> 192.168.1.6:5222
<stream:stream xmlns="jabber:client" xmlns:stream="http://etherx.jabber.org/streams" to="local.lit" version="1.0"/>

[2014-04-08T15:42:16Z] DEBUG -- vines: Sent stanza: 192.168.1.6:5222 -> 192.168.1.2:38712
<stream:stream xmlns='jabber:client' xmlns:stream='http://etherx.jabber.org/streams' xml:lang='en' id='2fac751d-7018-4c4c-bd61-8c13b6326f63' from='local.lit' version='1.0'>

[2014-04-08T15:42:16Z] DEBUG -- vines: Sent stanza: 192.168.1.6:5222 -> 192.168.1.2:38712
<stream:features>
<mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl">
<mechanism>PLAIN</mechanism>
</mechanisms>
</stream:features>

[2014-04-08T15:42:16Z] DEBUG -- vines: Received stanza: 192.168.1.2:38712 -> 192.168.1.6:5222
<auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="PLAIN">YWxpY2UAYWxpY2UAc2VjcjN0</auth>

[2014-04-08T15:42:16Z] INFO -- vines: Authenticating user:
[2014-04-08T15:42:16Z] INFO -- vines: Authentication succeeded:
[2014-04-08T15:42:16Z] DEBUG -- vines: Sent stanza: 192.168.1.6:5222 -> 192.168.1.2:38712
<success xmlns="urn:ietf:params:xml:ns:xmpp-sasl"/>

[2014-04-08T15:42:16Z] DEBUG -- vines: Received stanza: 192.168.1.2:38712 -> 192.168.1.6:5222
<stream:stream xmlns="jabber:client" xmlns:stream="http://etherx.jabber.org/streams" to="local.lit" version="1.0"/>

[2014-04-08T15:42:16Z] DEBUG -- vines: Sent stanza: 192.168.1.6:5222 -> 192.168.1.2:38712
<stream:stream xmlns='jabber:client' xmlns:stream='http://etherx.jabber.org/streams' xml:lang='en' id='890f0c03-f22b-485a-a64d-b16e997a2f96' from='local.lit' version='1.0'>

[2014-04-08T15:42:16Z] DEBUG -- vines: Sent stanza: 192.168.1.6:5222 -> 192.168.1.2:38712
<stream:features>
<bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"/>
</stream:features>

[2014-04-08T15:42:16Z] DEBUG -- vines: Received stanza: 192.168.1.2:38712 -> 192.168.1.6:5222
<iq id="k0305-5261" type="set">
<bind xmlns="urn:ietf:params:xml:ns:xmpp-bind">
<resource/>
</bind>
</iq>

[2014-04-08T15:42:16Z] DEBUG -- vines: Sent stanza: 192.168.1.6:5222 -> 192.168.1.2:38712
<iq id="k0305-5261" type="result">
<bind xmlns="urn:ietf:params:xml:ns:xmpp-bind">
<jid>/f3cba9a2-b6ce-47a6-870c-f7531703671e</jid>
</bind>
</iq>

[2014-04-08T15:42:16Z] DEBUG -- vines: Sent stanza: 192.168.1.6:5222 -> 192.168.1.2:38712
<stream:features/>

[2014-04-08T15:42:19Z] INFO -- vines: Stream connected: 192.168.1.2:38713 > 192.168.1.6:5222
[2014-04-08T15:42:19Z] DEBUG -
vines: Received stanza: 192.168.1.2:38713 -> 192.168.1.6:5222
<stream:stream xmlns="jabber:client" xmlns:stream="http://etherx.jabber.org/streams" to="local.lit" version="1.0"/>

[2014-04-08T15:42:19Z] DEBUG -- vines: Sent stanza: 192.168.1.6:5222 -> 192.168.1.2:38713
<stream:stream xmlns='jabber:client' xmlns:stream='http://etherx.jabber.org/streams' xml:lang='en' id='0241401f-060e-43f6-b88a-31f077ac7953' from='local.lit' version='1.0'>

[2014-04-08T15:42:19Z] DEBUG -- vines: Sent stanza: 192.168.1.6:5222 -> 192.168.1.2:38713
<stream:features>
<starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls">
<required/>
</starttls>
</stream:features>

[2014-04-08T15:42:19Z] DEBUG -- vines: Received stanza: 192.168.1.2:38713 -> 192.168.1.6:5222
<starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"/>

[2014-04-08T15:42:19Z] DEBUG -- vines: Sent stanza: 192.168.1.6:5222 -> 192.168.1.2:38713
<proceed xmlns="urn:ietf:params:xml:ns:xmpp-tls"/>

[2014-04-08T15:42:19Z] DEBUG -- vines: Received stanza: 192.168.1.2:38713 -> 192.168.1.6:5222
<stream:stream xmlns="jabber:client" xmlns:stream="http://etherx.jabber.org/streams" to="local.lit" version="1.0"/>

[2014-04-08T15:42:19Z] DEBUG -- vines: Sent stanza: 192.168.1.6:5222 -> 192.168.1.2:38713
<stream:stream xmlns='jabber:client' xmlns:stream='http://etherx.jabber.org/streams' xml:lang='en' id='3c82a88f-aae3-4b76-b9ff-dc294bccf982' from='local.lit' version='1.0'>

[2014-04-08T15:42:19Z] DEBUG -- vines: Sent stanza: 192.168.1.6:5222 -> 192.168.1.2:38713
<stream:features>
<mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl">
<mechanism>PLAIN</mechanism>
</mechanisms>
</stream:features>

[2014-04-08T15:42:19Z] DEBUG -- vines: Received stanza: 192.168.1.2:38713 -> 192.168.1.6:5222
<auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="PLAIN">YWxpY2UAYWxpY2UAc2VjcjN0</auth>

[2014-04-08T15:42:19Z] INFO -- vines: Authenticating user:
[2014-04-08T15:42:19Z] INFO -- vines: Authentication succeeded:
[2014-04-08T15:42:19Z] DEBUG -- vines: Sent stanza: 192.168.1.6:5222 -> 192.168.1.2:38713
<success xmlns="urn:ietf:params:xml:ns:xmpp-sasl"/>

[2014-04-08T15:42:19Z] DEBUG -- vines: Received stanza: 192.168.1.2:38713 -> 192.168.1.6:5222
<stream:stream xmlns="jabber:client" xmlns:stream="http://etherx.jabber.org/streams" to="local.lit" version="1.0"/>

[2014-04-08T15:42:19Z] DEBUG -- vines: Sent stanza: 192.168.1.6:5222 -> 192.168.1.2:38713
<stream:stream xmlns='jabber:client' xmlns:stream='http://etherx.jabber.org/streams' xml:lang='en' id='9b0d7a0a-d533-464c-85cd-52c9d54df7c3' from='local.lit' version='1.0'>

[2014-04-08T15:42:19Z] DEBUG -- vines: Sent stanza: 192.168.1.6:5222 -> 192.168.1.2:38713
<stream:features>
<bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"/>
</stream:features>

[2014-04-08T15:42:19Z] DEBUG -- vines: Received stanza: 192.168.1.2:38713 -> 192.168.1.6:5222
<iq id="k0305-5263" type="set">
<bind xmlns="urn:ietf:params:xml:ns:xmpp-bind">
<resource/>
</bind>
</iq>

[2014-04-08T15:42:19Z] DEBUG -- vines: Sent stanza: 192.168.1.6:5222 -> 192.168.1.2:38713
<iq id="k0305-5263" type="result">
<bind xmlns="urn:ietf:params:xml:ns:xmpp-bind">
<jid>/fc6bdcbc-5748-49bb-aa44-77a813030ca0</jid>
</bind>
</iq>

[2014-04-08T15:42:19Z] DEBUG -- vines: Sent stanza: 192.168.1.6:5222 -> 192.168.1.2:38713
<stream:features/>

[2014-04-08T15:43:19Z] INFO -- vines: Stream connected: 192.168.1.2:38714 > 192.168.1.6:5222
[2014-04-08T15:43:19Z] DEBUG -
vines: Received stanza: 192.168.1.2:38714 -> 192.168.1.6:5222
<stream:stream xmlns="jabber:client" xmlns:stream="http://etherx.jabber.org/streams" to="local.lit" version="1.0"/>

[2014-04-08T15:43:19Z] DEBUG -- vines: Sent stanza: 192.168.1.6:5222 -> 192.168.1.2:38714
<stream:stream xmlns='jabber:client' xmlns:stream='http://etherx.jabber.org/streams' xml:lang='en' id='45db5773-8b8d-4c7f-94ec-40eb5160f691' from='local.lit' version='1.0'>

[2014-04-08T15:43:19Z] DEBUG -- vines: Sent stanza: 192.168.1.6:5222 -> 192.168.1.2:38714
<stream:features>
<starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls">
<required/>
</starttls>
</stream:features>

[2014-04-08T15:43:19Z] DEBUG -- vines: Received stanza: 192.168.1.2:38714 -> 192.168.1.6:5222
<starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"/>

[2014-04-08T15:43:19Z] DEBUG -- vines: Sent stanza: 192.168.1.6:5222 -> 192.168.1.2:38714
<proceed xmlns="urn:ietf:params:xml:ns:xmpp-tls"/>

[2014-04-08T15:43:19Z] DEBUG -- vines: Received stanza: 192.168.1.2:38714 -> 192.168.1.6:5222
<stream:stream xmlns="jabber:client" xmlns:stream="http://etherx.jabber.org/streams" to="local.lit" version="1.0"/>

[2014-04-08T15:43:19Z] DEBUG -- vines: Sent stanza: 192.168.1.6:5222 -> 192.168.1.2:38714
<stream:stream xmlns='jabber:client' xmlns:stream='http://etherx.jabber.org/streams' xml:lang='en' id='a286ab98-8de3-465f-ad90-b0d0cc068d10' from='local.lit' version='1.0'>

[2014-04-08T15:43:19Z] DEBUG -- vines: Sent stanza: 192.168.1.6:5222 -> 192.168.1.2:38714
<stream:features>
<mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl">
<mechanism>PLAIN</mechanism>
</mechanisms>
</stream:features>

[2014-04-08T15:43:19Z] DEBUG -- vines: Received stanza: 192.168.1.2:38714 -> 192.168.1.6:5222
<auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="PLAIN">YWxpY2UAYWxpY2UAc2VjcjN0</auth>

[2014-04-08T15:43:19Z] INFO -- vines: Authenticating user:
[2014-04-08T15:43:19Z] INFO -- vines: Authentication succeeded:
[2014-04-08T15:43:19Z] DEBUG -- vines: Sent stanza: 192.168.1.6:5222 -> 192.168.1.2:38714
<success xmlns="urn:ietf:params:xml:ns:xmpp-sasl"/>

[2014-04-08T15:43:19Z] DEBUG -- vines: Received stanza: 192.168.1.2:38714 -> 192.168.1.6:5222
<stream:stream xmlns="jabber:client" xmlns:stream="http://etherx.jabber.org/streams" to="local.lit" version="1.0"/>

[2014-04-08T15:43:19Z] DEBUG -- vines: Sent stanza: 192.168.1.6:5222 -> 192.168.1.2:38714
<stream:stream xmlns='jabber:client' xmlns:stream='http://etherx.jabber.org/streams' xml:lang='en' id='72118971-6349-49a4-ae82-3cee2d6db7b6' from='local.lit' version='1.0'>

[2014-04-08T15:43:19Z] DEBUG -- vines: Sent stanza: 192.168.1.6:5222 -> 192.168.1.2:38714
<stream:features>
<bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"/>
</stream:features>

[2014-04-08T15:43:19Z] DEBUG -- vines: Received stanza: 192.168.1.2:38714 -> 192.168.1.6:5222
<iq id="k0305-5265" type="set">
<bind xmlns="urn:ietf:params:xml:ns:xmpp-bind">
<resource/>
</bind>
</iq>

[2014-04-08T15:43:19Z] DEBUG -- vines: Sent stanza: 192.168.1.6:5222 -> 192.168.1.2:38714
<iq id="k0305-5265" type="result">
<bind xmlns="urn:ietf:params:xml:ns:xmpp-bind">
<jid>/17d04964-48a4-4b3d-a7ae-ac6fd8c27275</jid>
</bind>
</iq>

[2014-04-08T15:43:19Z] DEBUG -- vines: Sent stanza: 192.168.1.6:5222 -> 192.168.1.2:38714
<stream:features/>

[2014-04-08T15:44:20Z] INFO -- vines: Stream connected: 192.168.1.2:38715 > 192.168.1.6:5222
[2014-04-08T15:44:20Z] DEBUG -
vines: Received stanza: 192.168.1.2:38715 -> 192.168.1.6:5222
<stream:stream xmlns="jabber:client" xmlns:stream="http://etherx.jabber.org/streams" to="local.lit" version="1.0"/>

[2014-04-08T15:44:20Z] DEBUG -- vines: Sent stanza: 192.168.1.6:5222 -> 192.168.1.2:38715
<stream:stream xmlns='jabber:client' xmlns:stream='http://etherx.jabber.org/streams' xml:lang='en' id='9b36af7e-f9e4-4a0f-9aee-c1cbed7ca221' from='local.lit' version='1.0'>

[2014-04-08T15:44:20Z] DEBUG -- vines: Sent stanza: 192.168.1.6:5222 -> 192.168.1.2:38715
<stream:features>
<starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls">
<required/>
</starttls>
</stream:features>

[2014-04-08T15:44:20Z] DEBUG -- vines: Received stanza: 192.168.1.2:38715 -> 192.168.1.6:5222
<starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls"/>

[2014-04-08T15:44:20Z] DEBUG -- vines: Sent stanza: 192.168.1.6:5222 -> 192.168.1.2:38715
<proceed xmlns="urn:ietf:params:xml:ns:xmpp-tls"/>

[2014-04-08T15:44:20Z] DEBUG -- vines: Received stanza: 192.168.1.2:38715 -> 192.168.1.6:5222
<stream:stream xmlns="jabber:client" xmlns:stream="http://etherx.jabber.org/streams" to="local.lit" version="1.0"/>

[2014-04-08T15:44:20Z] DEBUG -- vines: Sent stanza: 192.168.1.6:5222 -> 192.168.1.2:38715
<stream:stream xmlns='jabber:client' xmlns:stream='http://etherx.jabber.org/streams' xml:lang='en' id='fde120bf-a141-43df-82ac-c3d56734c466' from='local.lit' version='1.0'>

[2014-04-08T15:44:20Z] DEBUG -- vines: Sent stanza: 192.168.1.6:5222 -> 192.168.1.2:38715
<stream:features>
<mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl">
<mechanism>PLAIN</mechanism>
</mechanisms>
</stream:features>

[2014-04-08T15:44:20Z] DEBUG -- vines: Received stanza: 192.168.1.2:38715 -> 192.168.1.6:5222
<auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="PLAIN">YWxpY2UAYWxpY2UAc2VjcjN0</auth>

[2014-04-08T15:44:20Z] INFO -- vines: Authenticating user:
[2014-04-08T15:44:20Z] INFO -- vines: Authentication succeeded:
[2014-04-08T15:44:20Z] DEBUG -- vines: Sent stanza: 192.168.1.6:5222 -> 192.168.1.2:38715
<success xmlns="urn:ietf:params:xml:ns:xmpp-sasl"/>

[2014-04-08T15:44:20Z] DEBUG -- vines: Received stanza: 192.168.1.2:38715 -> 192.168.1.6:5222
<stream:stream xmlns="jabber:client" xmlns:stream="http://etherx.jabber.org/streams" to="local.lit" version="1.0"/>

[2014-04-08T15:44:20Z] DEBUG -- vines: Sent stanza: 192.168.1.6:5222 -> 192.168.1.2:38715
<stream:stream xmlns='jabber:client' xmlns:stream='http://etherx.jabber.org/streams' xml:lang='en' id='9783b830-f4b5-4a00-b61d-9f1b842fa1fb' from='local.lit' version='1.0'>

[2014-04-08T15:44:20Z] DEBUG -- vines: Sent stanza: 192.168.1.6:5222 -> 192.168.1.2:38715
<stream:features>
<bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"/>
</stream:features>

[2014-04-08T15:44:20Z] DEBUG -- vines: Received stanza: 192.168.1.2:38715 -> 192.168.1.6:5222
<iq id="k0305-5268" type="set">
<bind xmlns="urn:ietf:params:xml:ns:xmpp-bind">
<resource/>
</bind>
</iq>

[2014-04-08T15:44:20Z] DEBUG -- vines: Sent stanza: 192.168.1.6:5222 -> 192.168.1.2:38715
<iq id="k0305-5268" type="result">
<bind xmlns="urn:ietf:params:xml:ns:xmpp-bind">
<jid>/3432b5eb-eddc-4c35-b206-8d3dea3c2c19</jid>
</bind>
</iq>

[2014-04-08T15:44:20Z] DEBUG -- vines: Sent stanza: 192.168.1.6:5222 -> 192.168.1.2:38715
<stream:features/>

History

#1 Updated by artem almost 4 years ago

From Vines https://github.com/negativecode/vines/issues/32
"
The final, empty <stream:features/> is sent to the client to signal that stream negotiation is complete and the client is allowed to send messages to the server. Section 4.3.5 of RFC 6120 specifies this behavior. There's also a flow chart describing the negotiation steps.

I'm closing this because it looks like the client is missing this piece of the XMPP protocol implementation."

#2 Updated by n8fr8 almost 4 years ago

  • Status changed from New to Feedback

We will be updating to a much newer version of Smack (our XMPP library) shortly, that should solve missing issues in our XMPP implementation.

Are you able to connect this server using Jitsi or another Android XMPP app like Yaxim?

#3 Updated by artem over 3 years ago

n8fr8 wrote:

Are you able to connect this server using Jitsi or another Android XMPP app like Yaxim?

I found the reason. ChatSequre connects only if the bind replay features include session.
<stream:features> <session xmlns='urn:ietf:params:xml:ns:xmpp-session'/>
while Pidgin connects anyway.
The Vines server doen't send 'session'.

Link Vines issue https://github.com/negativecode/vines/issues/32

Also available in: Atom PDF