Hi,
I am trying Vysper on 2 federated server, running on different machines in the
network.
I built the project using the default maven file
I have set the RelayingToFederationServers to true:
ServerRuntimeContext runtimeCtx =
((SpringCompatibleXMPPServer)ctx.getBean("server")).getServerRuntimeContext();
runtimeCtx.getServerFeatures().setRelayingToFederationServers(true);
I send a message from "[email protected]" to
"[email protected]"
I can see from the log file that the Authentication, TLS and callback stage
between servers got executed just fine. But yet I don't see any response or
error coming for the other user on my client, I have tried both Psi and Adium
on Mac, I don't see any error stanza on the psi debug console either.
I tried to debug the code on receiving side. There is an empty incoming
presence stanza within client namespace (!), which triggers the "no from
attribute" but I'm not sure if that is the ultimate fatal bug here. I am not
able to understand whats going on in low level. I observed all the outgoing
stanzas from the sending server via debugger. All stanzas do have 'from'
attribute. There should be something wrong with servers negotiations Moreover
all the XMPP ping stanza either fail with service-unavailable or with error
IQStanza, even though the ping Module is added by initialization and I can
verify it in the log file.
I have tried everything I could think of or that I would suspect. But nothing
works. Has anyone had any similar experience? I should mention that I use the
up-to-date 0.8-SNAPSHOT version.
I append the logs I get after sending the message stanza.
Sorry if it's too long ;)
Thanks
Ashkan
sender log:
18:32:18,880 | DEBUG | org.apache.vysper.xml.decoder.XMPPContentHandler |
Decoder writing stanza: <message xmlns="jabber:client" id="ab04a"
to="[email protected]"><subject>hi</subject><body>hi user
2</body><nick xmlns="http://jabber.org/protocol/nick";>user1</nick></message>
18:32:18,881 | INFO | stanza.client | message.subject
18:32:18,900 | INFO |
org.apache.vysper.xmpp.server.s2s.DefaultXMPPServerConnector | Starting XMPP
server connector to sat016.researchstudio.at
18:32:19,129 | INFO |
org.apache.vysper.xmpp.server.s2s.DefaultXMPPServerConnector | Connecting to
XMPP server sat016.researchstudio.at at
sat016.researchstudio.at/192.168.124.48:5269
18:32:19,187 | DEBUG | org.apache.vysper.xmpp.protocol.SessionStateHolder |
session state changed to = INITIATED
18:32:19,187 | DEBUG | org.apache.vysper.xmpp.protocol.SessionStateHolder |
session state changed to = INITIATED
18:32:19,193 | INFO | stanza.server | stream
18:32:19,207 | DEBUG | org.apache.vysper.xml.decoder.XMPPContentHandler |
Decoder writing stanza: <stream:stream
xmlns:stream="http://etherx.jabber.org/streams";
id="b02adac84032499595d393c3bc3b53b1" from="sat016.researchstudio.at"
version="1.0"></stream:stream>
18:32:19,210 | DEBUG | org.apache.vysper.xml.decoder.XMPPContentHandler |
Decoder writing stanza: <stream:features
xmlns:stream="http://etherx.jabber.org/streams";><starttls
xmlns="urn:ietf:params:xml:ns:xmpp-tls"></starttls><dialback
xmlns="urn:xmpp:features:dialback"></dialback></stream:features>
18:32:19,211 | INFO | stanza.client | stream
18:32:19,212 | INFO | stanza.client | features
18:32:19,216 | INFO | org.apache.vysper.xmpp.server.s2s.FeaturesHandler | XMPP
server connector to sat016.researchstudio.at is starting TLS
18:32:19,218 | INFO | stanza.server | starttls
18:32:19,232 | DEBUG | org.apache.vysper.xml.decoder.XMPPContentHandler |
Decoder writing stanza: <proceed
xmlns="urn:ietf:params:xml:ns:xmpp-tls"></proceed>
18:32:19,232 | INFO | stanza.client | proceed
18:32:19,233 | DEBUG | org.apache.vysper.xmpp.protocol.SessionStateHolder |
session state changed to = ENCRYPTION_STARTED
18:32:19,234 | DEBUG | org.apache.vysper.xmpp.server.s2s.TlsProceedHandler |
XMPP server connector switching to TLS
18:32:19,371 | DEBUG | org.apache.vysper.xmpp.protocol.SessionStateHolder |
session state changed to = ENCRYPTED
18:32:19,372 | INFO |
org.apache.vysper.xmpp.server.s2s.DefaultXMPPServerConnector | XMPP server
connector to sat016.researchstudio.at secured using TLS
18:32:19,374 | DEBUG |
org.apache.vysper.xmpp.server.s2s.DefaultXMPPServerConnector | XMPP server
connector to sat016.researchstudio.at restarting stream
18:32:19,379 | INFO | stanza.server | stream
18:32:19,399 | DEBUG | org.apache.vysper.xml.decoder.XMPPContentHandler |
Decoder writing stanza: <stream:stream
xmlns:stream="http://etherx.jabber.org/streams";
id="b02adac84032499595d393c3bc3b53b1" from="sat016.researchstudio.at"
version="1.0"></stream:stream>
18:32:19,403 | DEBUG | org.apache.vysper.xml.decoder.XMPPContentHandler |
Decoder writing stanza: <stream:features
xmlns:stream="http://etherx.jabber.org/streams";><dialback
xmlns="urn:xmpp:features:dialback"></dialback></stream:features>
18:32:19,404 | INFO | stanza.client | stream
18:32:19,409 | INFO | stanza.client | features
18:32:19,423 | INFO | stanza.server | result
18:32:19,748 | DEBUG | org.apache.vysper.xmpp.protocol.SessionStateHolder |
session state changed to = INITIATED
18:32:19,769 | DEBUG | org.apache.vysper.xml.decoder.XMPPContentHandler |
Decoder writing stanza: <stream:stream
xmlns:stream="http://etherx.jabber.org/streams"; to="sat001.researchstudio.at"
xml:lang="en_US" from="sat016.researchstudio.at" version="1.0"></stream:stream>
18:32:19,770 | INFO | stanza.client | stream
18:32:19,772 | DEBUG | org.apache.vysper.xmpp.protocol.SessionStateHolder |
session state changed to = STARTED
18:32:19,774 | INFO | stanza.server | stream.starttls
18:32:19,795 | DEBUG | org.apache.vysper.xml.decoder.XMPPContentHandler |
Decoder writing stanza: <db:verify xmlns:db="jabber:server:dialback"
id="b02adac84032499595d393c3bc3b53b1" to="sat001.researchstudio.at"
from="sat016.researchstudio.at">497e1dd09d8db2786b922755f8fc555140672bf2588d8896791a0f9b89743790</db:verify>
18:32:19,795 | INFO | stanza.client | verify
18:32:19,805 | INFO | stanza.server | verify
18:32:19,916 | DEBUG | org.apache.vysper.xml.decoder.XMPPContentHandler |
Decoder writing stanza: <db:result xmlns:db="jabber:server:dialback"
to="sat001.researchstudio.at" from="sat016.researchstudio.at"
type="valid"></db:result>
18:32:19,922 | DEBUG | org.apache.vysper.xmpp.protocol.SessionStateHolder |
session state changed to = CLOSED
18:32:19,920 | INFO | stanza.client | result
18:32:19,924 | DEBUG | org.apache.vysper.xmpp.protocol.SessionStateHolder |
session state changed to = AUTHENTICATED
18:32:19,924 | INFO |
org.apache.vysper.xmpp.modules.extension.xep0220_server_dailback.DbResultHandler
| XMPP server connector to sat016.researchstudio.at authenticated using
dialback
18:32:19,925 | INFO |
org.apache.vysper.xmpp.server.s2s.DefaultXMPPServerConnector | XMPP server
connector to sat016.researchstudio.at authenticated
18:32:19,938 | INFO | stanza.server | message.subject
18:32:19,961 | DEBUG | org.apache.vysper.xml.decoder.XMPPContentHandler |
Decoder writing stanza: <message xmlns="jabber:client" id="ab04a"
to="[email protected]/8235cb3fd07f41d68ce1956fc37d9f0e"
from="sat016.researchstudio.at" type="error"><subject>hi</subject><body>hi user
2</body><nick xmlns="http://jabber.org/protocol/nick";>user1</nick><error
type="cancel"><service-unavailable
xmlns="urn:ietf:params:xml:ns:xmpp-stanzas"></service-unavailable></error></message>
18:32:19,962 | INFO | stanza.client | message.subject
18:32:49,946 | INFO | stanza.server |
iq.id='xmppping-ddf6883f-8443-487a-82e9-1fc25f466e9d'.to='sat016.researchstudio.at'.from='sat001.researchstudio.at'.type='get'.ping.xmlns='urn:xmpp:ping'
18:32:49,961 | DEBUG | org.apache.vysper.xml.decoder.XMPPContentHandler |
Decoder writing stanza: <iq xmlns="jabber:client"
id="xmppping-ddf6883f-8443-487a-82e9-1fc25f466e9d"
to="sat001.researchstudio.at" from="sat016.researchstudio.at"
type="error"><ping xmlns="urn:xmpp:ping"></ping><error
type="cancel"><service-unavailable
xmlns="urn:ietf:params:xml:ns:xmpp-stanzas"></service-unavailable></error></iq>
18:32:49,964 | INFO | stanza.client |
iq.id='xmppping-ddf6883f-8443-487a-82e9-1fc25f466e9d'.to='sat001.researchstudio.at'.from='sat016.researchstudio.at'.type='error'.ping.xmlns='urn:xmpp:ping'
18:32:59,948 | DEBUG |
org.apache.vysper.xmpp.server.s2s.DefaultXMPPServerConnector | XMPP server
connector to sat016.researchstudio.at timed out, closing
18:33:19,938 | INFO | stanza.server |
iq.id='xmppping-f2619e88-fb20-4dd7-9717-c3f815ce48b5'.to='sat016.researchstudio.at'.from='sat001.researchstudio.at'.type='get'.ping.xmlns='urn:xmpp:ping'
18:33:19,952 | DEBUG | org.apache.vysper.xml.decoder.XMPPContentHandler |
Decoder writing stanza: <iq xmlns="jabber:client"
id="xmppping-f2619e88-fb20-4dd7-9717-c3f815ce48b5"
to="sat001.researchstudio.at" from="sat016.researchstudio.at"
type="error"><ping xmlns="urn:xmpp:ping"></ping><error
type="cancel"><service-unavailable
xmlns="urn:ietf:params:xml:ns:xmpp-stanzas"></service-unavailable></error></iq>
18:33:19,955 | INFO | stanza.client |
iq.id='xmppping-f2619e88-fb20-4dd7-9717-c3f815ce48b5'.to='sat001.researchstudio.at'.from='sat016.researchstudio.at'.type='error'.ping.xmlns='urn:xmpp:ping'
18:33:29,940 | DEBUG |
org.apache.vysper.xmpp.server.s2s.DefaultXMPPServerConnector | XMPP server
connector to sat016.researchstudio.at timed out, closing
<<<<<<<
receiver side: sat016
18:32:14,604 | DEBUG | org.apache.vysper.xmpp.protocol.SessionStateHolder |
session state changed to = INITIATED
18:32:14,628 | DEBUG | org.apache.vysper.xml.decoder.XMPPContentHandler |
Decoder writing stanza: <stream:stream
xmlns:stream="http://etherx.jabber.org/streams"; to="sat016.researchstudio.at"
xml:lang="en_US" from="sat001.researchstudio.at" version="1.0"></stream:stream>
18:32:14,629 | INFO | stanza.client | stream
18:32:14,633 | DEBUG | org.apache.vysper.xmpp.protocol.SessionStateHolder |
session state changed to = STARTED
18:32:14,639 | INFO | stanza.server | stream.starttls
18:32:14,654 | DEBUG | org.apache.vysper.xml.decoder.XMPPContentHandler |
Decoder writing stanza: <starttls
xmlns="urn:ietf:params:xml:ns:xmpp-tls"></starttls>
18:32:14,655 | INFO | stanza.client | starttls
18:32:14,656 | DEBUG | org.apache.vysper.xmpp.protocol.SessionStateHolder |
session state changed to = ENCRYPTION_STARTED
18:32:14,763 | DEBUG | org.apache.vysper.xmpp.protocol.SessionStateHolder |
session state changed to = ENCRYPTED
18:32:14,764 | INFO | stanza.server | proceed
18:32:14,820 | DEBUG | org.apache.vysper.xml.decoder.XMPPContentHandler |
Decoder writing stanza: <stream:stream
xmlns:stream="http://etherx.jabber.org/streams"; to="sat016.researchstudio.at"
xml:lang="en_US" from="sat001.researchstudio.at" version="1.0"></stream:stream>
18:32:14,820 | INFO | stanza.client | stream
18:32:14,828 | INFO | stanza.server | stream
18:32:14,863 | DEBUG | org.apache.vysper.xml.decoder.XMPPContentHandler |
Decoder writing stanza: <db:result xmlns:db="jabber:server:dialback"
to="sat016.researchstudio.at"
from="sat001.researchstudio.at">497e1dd09d8db2786b922755f8fc555140672bf2588d8896791a0f9b89743790</db:result>
18:32:14,864 | INFO | stanza.client | result
18:32:14,881 | INFO |
org.apache.vysper.xmpp.server.s2s.DefaultXMPPServerConnector | Starting XMPP
server connector to sat001.researchstudio.at
18:32:15,132 | INFO |
org.apache.vysper.xmpp.server.s2s.DefaultXMPPServerConnector | Connecting to
XMPP server sat001.researchstudio.at at
sat001.researchstudio.at/192.168.124.33:5269
18:32:15,200 | DEBUG | org.apache.vysper.xmpp.protocol.SessionStateHolder |
session state changed to = INITIATED
18:32:15,200 | DEBUG | org.apache.vysper.xmpp.protocol.SessionStateHolder |
session state changed to = INITIATED
18:32:15,202 | INFO | stanza.server | stream
18:32:15,213 | DEBUG | org.apache.vysper.xml.decoder.XMPPContentHandler |
Decoder writing stanza: <stream:stream
xmlns:stream="http://etherx.jabber.org/streams";
id="32d6ec05c852454389ee1e07ebd077f3" from="sat001.researchstudio.at"
version="1.0"></stream:stream>
18:32:15,215 | DEBUG | org.apache.vysper.xml.decoder.XMPPContentHandler |
Decoder writing stanza: <stream:features
xmlns:stream="http://etherx.jabber.org/streams";><starttls
xmlns="urn:ietf:params:xml:ns:xmpp-tls"></starttls><dialback
xmlns="urn:xmpp:features:dialback"></dialback></stream:features>
18:32:15,215 | INFO | stanza.client | stream
18:32:15,216 | DEBUG | org.apache.vysper.xmpp.protocol.SessionStateHolder |
session state changed to = AUTHENTICATED
18:32:15,218 | INFO | stanza.client | features
18:32:15,223 | INFO |
org.apache.vysper.xmpp.server.s2s.DefaultXMPPServerConnector | XMPP server
connector to sat001.researchstudio.at authenticated
18:32:15,228 | INFO | stanza.server | verify
18:32:15,241 | DEBUG | org.apache.vysper.xml.decoder.XMPPContentHandler |
Decoder writing stanza: <db:verify xmlns:db="jabber:server:dialback"
id="b02adac84032499595d393c3bc3b53b1" to="sat016.researchstudio.at"
from="sat001.researchstudio.at" type="valid"></db:verify>
18:32:15,242 | INFO | stanza.client | verify
18:32:15,243 | DEBUG | org.apache.vysper.xmpp.protocol.SessionStateHolder |
session state changed to = AUTHENTICATED
18:32:15,245 | INFO | stanza.server | result
18:32:15,248 | WARN |
org.apache.vysper.xmpp.modules.core.base.handler.XMPPCoreStanzaHandler | no
'from' attribute, and cannot uniquely determine sending resource for initiating
entity sat001.researchstudio.at in session 32d6ec05c852454389ee1e07ebd077f3
18:32:15,249 | DEBUG | org.apache.vysper.xmpp.protocol.SessionStateHolder |
session state changed to = CLOSED
18:32:15,250 | INFO |
org.apache.vysper.xmpp.server.s2s.DefaultXMPPServerConnector | XMPP server
connector socket closed, closing connector
18:32:15,378 | DEBUG | org.apache.vysper.xml.decoder.XMPPContentHandler |
Decoder writing stanza: <message xmlns="jabber:server"
to="[email protected]" id="ab04a"
from="[email protected]/8235cb3fd07f41d68ce1956fc37d9f0e"><subject>hi</subject><body>hi
user 2</body><nick
xmlns="http://jabber.org/protocol/nick";>user1</nick></message>
18:32:15,379 | INFO | stanza.client | message.subject
18:32:15,386 | INFO | stanza.server | message.subject
18:32:45,385 | DEBUG | org.apache.vysper.xml.decoder.XMPPContentHandler |
Decoder writing stanza: <iq xmlns="jabber:server"
id="xmppping-ddf6883f-8443-487a-82e9-1fc25f466e9d"
to="sat016.researchstudio.at" from="sat001.researchstudio.at" type="get"><ping
xmlns="urn:xmpp:ping"></ping></iq>
18:32:45,388 | INFO | stanza.client |
iq.id='xmppping-ddf6883f-8443-487a-82e9-1fc25f466e9d'.to='sat016.researchstudio.at'.from='sat001.researchstudio.at'.type='get'.ping.xmlns='urn:xmpp:ping'
18:32:45,393 | INFO | stanza.server |
iq.id='xmppping-ddf6883f-8443-487a-82e9-1fc25f466e9d'.to='sat001.researchstudio.at'.from='sat016.researchstudio.at'.type='error'.ping.xmlns='urn:xmpp:ping'
18:32:55,232 | DEBUG |
org.apache.vysper.xmpp.server.s2s.DefaultXMPPServerConnector | XMPP server
connector to sat001.researchstudio.at timed out, closing
18:33:15,376 | DEBUG | org.apache.vysper.xml.decoder.XMPPContentHandler |
Decoder writing stanza: <iq xmlns="jabber:server"
id="xmppping-f2619e88-fb20-4dd7-9717-c3f815ce48b5"
to="sat016.researchstudio.at" from="sat001.researchstudio.at" type="get"><ping
xmlns="urn:xmpp:ping"></ping></iq>
18:33:15,377 | INFO | stanza.client |
iq.id='xmppping-f2619e88-fb20-4dd7-9717-c3f815ce48b5'.to='sat016.researchstudio.at'.from='sat001.researchstudio.at'.type='get'.ping.xmlns='urn:xmpp:ping'
18:33:15,381 | INFO | stanza.server |
iq.id='xmppping-f2619e88-fb20-4dd7-9717-c3f815ce48b5'.to='sat001.researchstudio.at'.from='sat016.researchstudio.at'.type='error'.ping.xmlns='urn:xmpp:ping'
18:33:25,228 | DEBUG |
org.apache.vysper.xmpp.server.s2s.DefaultXMPPServerConnector | XMPP server
connector to sat001.researchstudio.at timed out, closing
18:33:45,376 | DEBUG | org.apache.vysper.xml.decoder.XMPPContentHandler |
Decoder writing stanza: <iq xmlns="jabber:server"
id="xmppping-6d5a633e-c15c-40f9-ac8b-27ce85ffeb60"
to="sat016.researchstudio.at" from="sat001.researchstudio.at" type="get"><ping
xmlns="urn:xmpp:ping"></ping></iq>
18:33:45,377 | INFO | stanza.client |
iq.id='xmppping-6d5a633e-c15c-40f9-ac8b-27ce85ffeb60'.to='sat016.researchstudio.at'.from='sat001.researchstudio.at'.type='get'.ping.xmlns='urn:xmpp:ping'
18:33:45,381 | INFO | stanza.server |
iq.id='xmppping-6d5a633e-c15c-40f9-ac8b-27ce85ffeb60'.to='sat001.researchstudio.at'.from='sat016.researchstudio.at'.type='error'.ping.xmlns='urn:xmpp:ping'
18:33:55,228 | DEBUG |
org.apache.vysper.xmpp.server.s2s.DefaultXMPPServerConnector | XMPP server
connector to sat001.researchstudio.at timed out, closing
