I need to look into s2s. Since I'm not the original developer of s2s, I might need some ramp up time.
However, as far as I remember, there is some inner logic to map "client" to "server" namespaces in s2s connections. Bernd On Fri, Jun 7, 2013 at 8:22 PM, Dave <[email protected]> wrote: > Hi Ashkan, > > I see this also. This message appears to come as a result of the dialback > connection closing after dialback has completed. In DbVerifyHandler, the > connection is closed with: > > sessionContext.endSession(**SessionTerminationCause.**CLIENT_BYEBYE); > > As a result, the session context then tries to send an UNAVAILABLE > presence stanza, I guess informing the other end that we're going off-line > - which seems odd given the connection has only just been initiated. Iirc, > this presence stanza is sent by the server, rather than a specific user - > which might be why the 'from' attribute is complained about? Looking at the > comments, the code is expecting to use this unavailable presence stanza for > client connections, so maybe it shouldn't be sent for server connections at > all? > > I don't know vysper or the xmpp spec's well enough to understand what > should be happening here, but maybe the above gives someone else an idea > about what's going wrong? > > Dave > > > > On 07/06/13 18:46, Ashkan Rezaei wrote: > >> 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].**at<[email protected]>" >> to "[email protected].**at <[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=" >> user2@sat016.**researchstudio.at <[email protected]> >> "><subject>**hi</subject><body>hi user 2</body><nick xmlns=" >> http://jabber.org/**protocol/nick <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<http://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 <http://etherx.jabber.org/streams>" id="** >> b02adac84032499595d393c3bc3b53**b1" 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 <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 <http://etherx.jabber.org/streams>" id="** >> b02adac84032499595d393c3bc3b53**b1" 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 <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 <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="**b02adac84032499595d393c3bc3b53**b1" to="sat001.researchstudio.at" >> from="sat016.researchstudio.at**">**497e1dd09d8db2786b922755f8fc55** >> 5140672bf2588d8896791a0f9b8974**3790</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=" >> user1@sat001.**researchstudio.at/**8235cb3fd07f41d68ce1956fc37d9f**0e<http://[email protected]/8235cb3fd07f41d68ce1956fc37d9f0e>" >> from="sat016.researchstudio.at**" >> type="error"><subject>hi</**subject><body>hi >> user 2</body><nick >> xmlns="http://jabber.org/**protocol/nick<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='sa**t016.researchstudio.at<http://sat016.researchstudio.at> >> '.from='**sat001.researchstudio.at <http://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='sa**t001.researchstudio.at<http://sat001.researchstudio.at> >> '.from='**sat016.researchstudio.at <http://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='sa**t016.researchstudio.at<http://sat016.researchstudio.at> >> '.from='**sat001.researchstudio.at <http://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='sa**t001.researchstudio.at<http://sat001.researchstudio.at> >> '.from='**sat016.researchstudio.at <http://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 <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 <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**">** >> 497e1dd09d8db2786b922755f8fc55**5140672bf2588d8896791a0f9b8974** >> 3790</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<http://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 <http://etherx.jabber.org/streams>" id="** >> 32d6ec05c852454389ee1e07ebd077**f3" 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 <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="**b02adac84032499595d393c3bc3b53**b1" 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 32d6ec05c852454389ee1e07ebd077**f3 >> 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=" >> user2@sat016.**researchstudio.at <[email protected]>" >> id="ab04a" from="user1@sat001.**researchstudio.at/** >> 8235cb3fd07f41d68ce1956fc37d9f**0e<http://[email protected]/8235cb3fd07f41d68ce1956fc37d9f0e> >> "><subject>hi</subject><**body>hi user 2</body><nick xmlns=" >> http://jabber.org/**protocol/nick <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='sa**t016.researchstudio.at<http://sat016.researchstudio.at> >> '.from='**sat001.researchstudio.at <http://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='sa**t001.researchstudio.at<http://sat001.researchstudio.at> >> '.from='**sat016.researchstudio.at <http://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='sa**t016.researchstudio.at<http://sat016.researchstudio.at> >> '.from='**sat001.researchstudio.at <http://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='sa**t001.researchstudio.at<http://sat001.researchstudio.at> >> '.from='**sat016.researchstudio.at <http://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='sa**t016.researchstudio.at<http://sat016.researchstudio.at> >> '.from='**sat001.researchstudio.at <http://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='sa**t001.researchstudio.at<http://sat001.researchstudio.at> >> '.from='**sat016.researchstudio.at <http://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 >> >> >> >
