Skip to content
This repository has been archived by the owner on Jan 29, 2024. It is now read-only.

Error code 11 : CONNECTION_TIMEOUT #129

Closed
o--- opened this issue Apr 30, 2020 · 11 comments
Closed

Error code 11 : CONNECTION_TIMEOUT #129

o--- opened this issue Apr 30, 2020 · 11 comments
Labels

Comments

@o---
Copy link

o--- commented Apr 30, 2020

Bevor you create a new issue:

- [x] I searched for similar issues and did not find one (or I did not understand its related)
- [x] I'm using the latest version available in the [Windows Store](https://www.microsoft.com/store/apps/9NW16X9JB5WV)

I'm submitting a...:

  • Bug report (I searched for similar issues and did not find one)
  • Feature request (Auto reconnect?) -->

Current behavior:

image

Expected behavior:

I guess the UWPX Alpha Client should not get disconnected by a Time out as I do not have this issue with any other client connected to the server hence I am assuming it's not a server issue?

Minimal reproduction of the problem with instructions:

  1. Connect account to the server
  2. Wait a little, it gets disconnected

On Server side I am using Prosody 0.11.2 and both server and client are in the same local network.
XEP-0163 is enabled
XEP-0198 is enabled
XEP-0237 is enabled
XEP-0280 is enabled
XEP-0313 is enabled
XEP-0352 is enabled
XEP-0363 is enabled

Environment:

App Version(s): 
v.0.25.0.0 

Windows 10 Version Number: <!-- https://en.wikipedia.org/wiki/Windows_10_version_history -->
- [x] 1909
- [ ] 1809
- [ ] 1803
- [ ] 1709
- [ ] 1703
- [ ] 1607
- [ ] 1511
- [ ] 1507
- [ ] Insider Build (build number: )
- [ ] Misc:

Device form factor:
- [x] Desktop
- [ ] Mobile
- [ ] Xbox
- [ ] Surface Hub

Where did you got the APP from?
- [x] [Windows Store](https://www.microsoft.com/store/apps/9NW16X9JB5WV)
- [ ] Self-build, using a provided release source
- [ ] Self-build, repo cloned at [dd.mm.yyy] <!-- When did you clone the repo! -->
- [ ] Misc, got it from... <!-- Please tell us your source! -->

@COM8
Copy link
Member

COM8 commented Apr 30, 2020

There should already be a reconnection timer in place, that should kick in after 5 seconds.
Could you please upload your logs.
Settings -> Misc -> Export logs
And then upload them here.

@COM8 COM8 added the 🐛 Bug label Apr 30, 2020
@o---
Copy link
Author

o--- commented Apr 30, 2020

Well, that's another bug I was holding back:

image

But if you tell me where they get stored (location) than I will happily upload them.

@COM8
Copy link
Member

COM8 commented May 4, 2020

Arg...
I had hoped that this problem had been solved...
So I guess back to the drawing board for this one 😉 .

Here is an example how you can get access to the logs in the application folder.
export_logs

Sorry for the late response, was quite busy the last couple of days.

@o---
Copy link
Author

o--- commented May 4, 2020

[INFO][04.05.2020 20:52:06]: Reconnecting account: [email protected] 
[DEBUG][04.05.2020 20:52:06]: [XmppConnection] DISCONNECTED -> CONNECTING:  
[DEBUG][04.05.2020 20:52:06]: [TcpConnection] DISCONNECTED -> CONNECTING:  
[DEBUG][04.05.2020 20:52:06]: [TcpConnection]: Starting a connection attempt. 
[DEBUG][04.05.2020 20:52:06]: [TcpConnection] CONNECTING -> CONNECTED:  
[DEBUG][04.05.2020 20:52:06]: [TcpConnection]: Send to (xmpp.domain.com):<?xml version="1.0"?><stream:stream from="[email protected]" to="domain.com" version="1.0" xml:lang="en" xmlns="jabber:client" xmlns:stream="http://etherx.jabber.org/streams"> 
[DEBUG][04.05.2020 20:52:06]: [TcpConnection]: Received from (xmpp.domain.com):<?xml version='1.0'?><stream:stream xmlns:stream='http://etherx.jabber.org/streams' xml:lang='en' from='domain.com' id='c404bc39-4103-4a5a-9b74-740878477ddd' version='1.0' xmlns='jabber:client'><stream:features><starttls xmlns='urn:ietf:params:xml:ns:xmpp-tls'><required/></starttls></stream:features> 
[DEBUG][04.05.2020 20:52:06]: [TcpConnection]: Send to (xmpp.domain.com):<starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls" /> 
[DEBUG][04.05.2020 20:52:06]: [TcpConnection]: Received from (xmpp.domain.com):<proceed xmlns='urn:ietf:params:xml:ns:xmpp-tls'/> 
[DEBUG][04.05.2020 20:52:06]: Upgrading [email protected] connection to TLS... 
[DEBUG][04.05.2020 20:52:06]: Success upgrading [email protected] to TLS. 
[DEBUG][04.05.2020 20:52:06]: [TcpConnection]: Send to (xmpp.domain.com):<?xml version="1.0"?><stream:stream from="[email protected]" to="domain.com" version="1.0" xml:lang="en" xmlns="jabber:client" xmlns:stream="http://etherx.jabber.org/streams"> 
[DEBUG][04.05.2020 20:52:06]: [TcpConnection]: Received from (xmpp.domain.com):<?xml version='1.0'?><stream:stream xmlns:stream='http://etherx.jabber.org/streams' xml:lang='en' from='domain.com' id='b8984614-bc30-4f1a-9e50-eba3157453f6' version='1.0' xmlns='jabber:client'><stream:features><auth xmlns='http://jabber.org/features/iq-auth'/><mechanisms xmlns='urn:ietf:params:xml:ns:xmpp-sasl'><mechanism>PLAIN</mechanism><mechanism>SCRAM-SHA-1</mechanism><mechanism>SCRAM-SHA-1-PLUS</mechanism></mechanisms></stream:features> 
[DEBUG][04.05.2020 20:52:06]: [TcpConnection]: Send to (xmpp.domain.com):<auth mechanism="SCRAM-SHA-1" xmlns="urn:ietf:params:xml:ns:xmpp-sasl">biwsbj1yb21hbi5saXNrbyxyPTd5N2xFKzZvbW56VVMwMEdoWHA3RWRWZFo3V0EzR2ZabkVoci8yZyt1Qzg9</auth> 
[DEBUG][04.05.2020 20:52:06]: [TcpConnection]: Received from (xmpp.domain.com):<challenge xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>cj03eTdsRSs2b21uelVTMDBHaFhwN0VkVmRaN1dBM0dmWm5FaHIvMmcrdUM4PTk2NjkwZDk5LWNmMDUtNDE1Ny05NjZiLWZhN2VhYjFhNzFmMixzPVpqWm1aRGt3TW1JdE4ySXlZaTAwWTJGakxUZzJNVFF0WlRBNE5HUTJPREUwTlRjMSxpPTQwOTY=</challenge> 
[DEBUG][04.05.2020 20:52:06]: [TcpConnection]: Send to (xmpp.domain.com):<response xmlns="urn:ietf:params:xml:ns:xmpp-sasl">Yz1iaXdzLHI9N3k3bEUrNm9tbnpVUzAwR2hYcDdFZFZkWjdXQTNHZlpuRWhyLzJnK3VDOD05NjY5MGQ5OS1jZjA1LTQxNTctOTY2Yi1mYTdlYWIxYTcxZjIscD04cEdLV3JheU9YNjNCbDM2RnRUbjk2ZG9rUWM9</response> 
[DEBUG][04.05.2020 20:52:06]: [TcpConnection]: Received from (xmpp.domain.com):<success xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>dj1QY1JQNDN0bzFwN1V1aWlQSmovU09GV2l5RTQ9</success> 
[DEBUG][04.05.2020 20:52:06]: [TcpConnection]: Send to (xmpp.domain.com):<?xml version="1.0"?><stream:stream from="[email protected]" to="domain.com" version="1.0" xml:lang="en" xmlns="jabber:client" xmlns:stream="http://etherx.jabber.org/streams"> 
[DEBUG][04.05.2020 20:52:06]: [TcpConnection]: Received from (xmpp.domain.com):<?xml version='1.0'?><stream:stream xmlns:stream='http://etherx.jabber.org/streams' xml:lang='en' from='domain.com' id='a3d8f618-92a3-4679-be5e-40452a419677' version='1.0' xmlns='jabber:client'><stream:features><ver xmlns='urn:xmpp:features:rosterver'/><csi xmlns='urn:xmpp:csi:0'/><bind xmlns='urn:ietf:params:xml:ns:xmpp-bind'><required/></bind><session xmlns='urn:ietf:params:xml:ns:xmpp-session'><optional/></session><c hash='sha-1' ver='UIBPxiOZ8TZIsmct9hylA2Wy5v0=' node='http://prosody.im' xmlns='http://jabber.org/protocol/caps'/><sm xmlns='urn:xmpp:sm:2'><optional/></sm><sm xmlns='urn:xmpp:sm:3'><optional/></sm></stream:features> 
[DEBUG][04.05.2020 20:52:06]: [TcpConnection]: Send to (xmpp.domain.com):<iq type="set" id="d4b8f61e-049a-454c-9cfe-c296e0887fe8">
  <bind xmlns="urn:ietf:params:xml:ns:xmpp-bind">
    <resource>UWPX</resource>
  </bind>
</iq> 
[DEBUG][04.05.2020 20:52:06]: [TcpConnection]: Received from (xmpp.domain.com):<iq id='d4b8f61e-049a-454c-9cfe-c296e0887fe8' type='result'><bind xmlns='urn:ietf:params:xml:ns:xmpp-bind'><jid>[email protected]/UWPX</jid></bind></iq> 
[DEBUG][04.05.2020 20:52:06]: [TcpConnection]: Send to (xmpp.domain.com):<iq type="set" id="2c1a27f9-73e5-42fa-901e-60fc6e3a8849">
  <session xmlns="urn:ietf:params:xml:ns:xmpp-session" />
</iq> 
[DEBUG][04.05.2020 20:52:06]: [TcpConnection]: Send to (xmpp.domain.com):<presence>
  <priority>0</priority>
</presence> 
[INFO][04.05.2020 20:52:06]: Connected to account: [email protected] 
[DEBUG][04.05.2020 20:52:06]: [TcpConnection]: Received from (xmpp.domain.com):<iq id='2c1a27f9-73e5-42fa-901e-60fc6e3a8849' type='result' to='[email protected]/UWPX'/> 
[DEBUG][04.05.2020 20:52:06]: [XmppConnection] CONNECTING -> CONNECTED:  
[DEBUG][04.05.2020 20:52:06]: [TcpConnection]: Send to (xmpp.domain.com):<iq type="get" id="b01ab146-69fb-476b-9696-df2940a22499" to="[email protected]" from="[email protected]/UWPX">
  <query xmlns="jabber:iq:roster" />
</iq> 
[INFO][04.05.2020 20:52:06]: Entering all MUC rooms for '[email protected]' 
[INFO][04.05.2020 20:52:06]: Delaying MUC joining for 5 seconds. 
[INFO][04.05.2020 20:52:06]: Sending 0 outstanding chat messages for: [email protected] 
[INFO][04.05.2020 20:52:06]: Finished sending outstanding chat messages for: [email protected] 
[INFO][04.05.2020 20:52:06]: Sending 0 outstanding OMEMO chat messages for: [email protected] 
[INFO][04.05.2020 20:52:06]: Finished sending outstanding OMEMO chat messages for: [email protected] 
[DEBUG][04.05.2020 20:52:06]: [TcpConnection]: Send to (xmpp.domain.com):<iq type="get" id="52b078d1-f1d7-4d8b-a9ce-b0a43c1cab38" from="[email protected]/UWPX">
  <pubsub xmlns="http://jabber.org/protocol/pubsub">
    <items node="storage:bookmarks" />
  </pubsub>
</iq> 
[DEBUG][04.05.2020 20:52:06]: [TcpConnection]: Received from (xmpp.domain.com):<presence from='[email protected]/UWPX'>
  <priority>0</priority>
</presence><presence to='[email protected]/UWPX' from='[email protected]/asterisk-xmpp'><status>&quot;Asterisk Server / Not really chaty.&quot;</status><priority>1</priority><c ver='asterisk-xmpp' ext='voice-v1 video-v1 camera-v1' node='http://www.asterisk.org/xmpp/client/caps' xmlns='http://jabber.org/protocol/caps'/><delay from='domain.com' stamp='2020-04-30T11:03:48Z' xmlns='urn:xmpp:delay'/></presence><presence type='unavailable' to='[email protected]/UWPX' from='[email protected]'/><presence to='[email protected]/UWPX' from='[email protected]/Conversations.VOmT'><show>away</show><c ver='PeKYibv9P9qF24DQsRGfza05Bn0=' hash='sha-1' node='http://conversations.im' xmlns='http://jabber.org/protocol/caps'/><delay from='domain.com' stamp='2020-05-04T18:33:06Z' xmlns='urn:xmpp:delay'/></presence><presence type='unavailable' to='[email protected]/UWPX' from='[email protected]'/><presence to='[email protected]/UWPX' from='[email protected]/Conversations.6HiZ'><c ver='yZ3k+drC/otcaRFTSuhDJLp87gY=' hash='sha-1' node='http://conversations.im' xmlns='http://jabber.org/protocol/caps'/><idle xmlns='urn:xmpp:idle:1' since='2020-05-04T17:27:44.179Z'/><delay from='domain.com' stamp='2020-05-04T17:27:39Z' xmlns='urn:xmpp:delay'/></presence><presence type='unavailable' to='[email protected]/UWPX' from='[email protected]'/><presence to='[email protected]/UWPX' from='[email protected]/Conversations.9ekB'><c ver='PeKYibv9P9qF24DQsRGfza05Bn0=' hash='sha-1' node='http://conversations.im' xmlns='http://jabber.org/protocol/caps'/><delay from='domain.com' stamp='2020-05-04T18:16:57Z' xmlns='urn:xmpp:delay'/></presence><presence type='unavailable' to='[email protected]/UWPX' from='[email protected]'/><presence type='unavailable' to='[email protected]' from='[email protected]'/> 
[DEBUG][04.05.2020 20:52:06]: [TcpConnection]: Received from (xmpp.domain.com):<iq id='b01ab146-69fb-476b-9696-df2940a22499' type='result' to='[email protected]/UWPX'><query ver='222' xmlns='jabber:iq:roster'><item jid='[email protected]' subscription='both'/><item jid='[email protected]' subscription='both' name='User 6'><group>Contacts</group></item><item jid='[email protected]' ask='subscribe' subscription='none'/><item jid='[email protected]' subscription='both' name='M Account'/><item jid='[email protected]' subscription='both'><group>No group</group></item><item jid='[email protected]' subscription='both'/><item jid='[email protected]' subscription='both' name='Mama'/><item jid='[email protected]' subscription='both' name='User 5'/><item jid='[email protected]' subscription='both' name='Robo Agent'/></query></iq> 
[DEBUG][04.05.2020 20:52:06]: [TcpConnection]: Received from (xmpp.domain.com):<iq id='52b078d1-f1d7-4d8b-a9ce-b0a43c1cab38' type='error' to='[email protected]/UWPX'><error type='cancel'><item-not-found xmlns='urn:ietf:params:xml:ns:xmpp-stanzas'/></error></iq> 
[INFO][04.05.2020 20:52:11]: MUC join delay elapsed. Joining MUCs... 
[ERROR][04.05.2020 20:52:58]: Failed to export logs: System.Exception: TEST EXEPTION
   at UWPX_UI.Pages.Settings.MiscSettingsPage.<ExportLogs_btn_Click>d__8.MoveNext() + 0x5a

[INFO][04.05.2020 20:53:01]: Reporting ExportLogsAsync() crash canceled. 
[DEBUG][04.05.2020 20:53:07]: [TcpConnection]: Received from (xmpp.domain.com):<iq id='idle-check' type='get' from='domain.com'><ping xmlns='urn:xmpp:ping'/></iq> 
[DEBUG][04.05.2020 20:53:15]: [TcpConnection]: Received from (xmpp.domain.com):<presence to='[email protected]' from='[email protected]/Conversations.vJ-R'><show>away</show><c ver='uLShaSsVDuAfcoROuTRCR7DZTR8=' hash='sha-1' node='http://conversations.im' xmlns='http://jabber.org/protocol/caps'/></presence> 
[DEBUG][04.05.2020 20:53:17]: [TcpConnection]: Received from (xmpp.domain.com):<stream:error><connection-timeout xmlns='urn:ietf:params:xml:ns:xmpp-streams'/></stream:error></stream:stream> 
[DEBUG][04.05.2020 20:53:17]: [XmppConnection] CONNECTED -> DISCONNECTING:  
[DEBUG][04.05.2020 20:53:17]: [XmppConnection]: Sending stream close... 
[INFO][04.05.2020 20:53:17]: [TcpConnection]: Socket closed because received 0-length message from: xmpp.domain.com 
[DEBUG][04.05.2020 20:53:17]: [TcpConnection] CONNECTED -> DISCONNECTING:  
[INFO][04.05.2020 20:53:17]: Disconnected account: [email protected] 
[ERROR][04.05.2020 20:53:17]: [TcpConnection]: Failed to send - sendCTS is null : </stream:stream> 
[DEBUG][04.05.2020 20:53:17]: [XmppConnection]: Stream close send. 
[DEBUG][04.05.2020 20:53:17]: [XmppConnection] DISCONNECTED -> CONNECTING:  
[DEBUG][04.05.2020 20:53:17]: [XmppConnection] DISCONNECTING -> DISCONNECTED:  
[DEBUG][04.05.2020 20:53:17]: [TcpConnection] DISCONNECTING -> DISCONNECTED:  
[DEBUG][04.05.2020 20:53:17]: [TcpConnection] DISCONNECTED -> CONNECTING:  
[DEBUG][04.05.2020 20:53:17]: [TcpConnection]: Starting a connection attempt. 
[DEBUG][04.05.2020 20:53:17]: [TcpConnection] CONNECTING -> CONNECTED:  
[INFO][04.05.2020 20:53:17]: Disconnected account: [email protected] 
[DEBUG][04.05.2020 20:53:17]: [TcpConnection]: Send to (xmpp.domain.com):<?xml version="1.0"?><stream:stream from="[email protected]" to="domain.com" version="1.0" xml:lang="en" xmlns="jabber:client" xmlns:stream="http://etherx.jabber.org/streams"> 
[DEBUG][04.05.2020 20:53:17]: [TcpConnection]: Received from (xmpp.domain.com):<?xml version='1.0'?><stream:stream xmlns:stream='http://etherx.jabber.org/streams' xml:lang='en' from='domain.com' id='56d1fbb8-ec67-4db6-a288-5dadf37a0a2f' version='1.0' xmlns='jabber:client'><stream:features><starttls xmlns='urn:ietf:params:xml:ns:xmpp-tls'><required/></starttls></stream:features> 
[DEBUG][04.05.2020 20:53:17]: [TcpConnection]: Send to (xmpp.domain.com):<starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls" /> 
[DEBUG][04.05.2020 20:53:17]: [TcpConnection]: Received from (xmpp.domain.com):<proceed xmlns='urn:ietf:params:xml:ns:xmpp-tls'/> 
[DEBUG][04.05.2020 20:53:17]: Upgrading [email protected] connection to TLS... 
[DEBUG][04.05.2020 20:53:17]: [XmppConnection] CONNECTING -> DISCONNECTED:  
[WARN][04.05.2020 20:53:17]: [XMPPConnection2]: Received stream error message: CONNECTION_TIMEOUT 
[DEBUG][04.05.2020 20:53:17]: [XmppConnection]: OnConnectionErrorAsync() got triggered - connectionErrorCount: 0 
[DEBUG][04.05.2020 20:53:17]: [XmppConnection] DISCONNECTED -> CONNECTING:  
[DEBUG][04.05.2020 20:53:17]: Success upgrading [email protected] to TLS. 
[DEBUG][04.05.2020 20:53:17]: [TcpConnection] CONNECTED -> CONNECTING:  
[DEBUG][04.05.2020 20:53:17]: [TcpConnection]: Starting a connection attempt. 
[ERROR][04.05.2020 20:53:17]: [XMPPConnection2]: Error during sending message for account: [email protected] 
[DEBUG][04.05.2020 20:53:17]: [TcpConnection] CONNECTING -> CONNECTED:  
[DEBUG][04.05.2020 20:53:17]: [XmppConnection]: Sending stream close... 
[DEBUG][04.05.2020 20:53:17]: [TcpConnection]: Send to (xmpp.domain.com):<?xml version="1.0"?><stream:stream from="[email protected]" to="domain.com" version="1.0" xml:lang="en" xmlns="jabber:client" xmlns:stream="http://etherx.jabber.org/streams"> 
[DEBUG][04.05.2020 20:53:17]: [TcpConnection]: Send to (xmpp.domain.com):</stream:stream> 
[DEBUG][04.05.2020 20:53:17]: [XmppConnection]: Stream close send. 
[DEBUG][04.05.2020 20:53:17]: [TcpConnection]: Received from (xmpp.domain.com):<?xml version='1.0'?><stream:stream xmlns:stream='http://etherx.jabber.org/streams' xml:lang='en' from='domain.com' id='8a8ac758-98b3-438f-8e24-c071633c5840' version='1.0' xmlns='jabber:client'><stream:features><starttls xmlns='urn:ietf:params:xml:ns:xmpp-tls'><required/></starttls></stream:features></stream:stream> 
[DEBUG][04.05.2020 20:53:17]: [XmppConnection] CONNECTING -> DISCONNECTING:  
[DEBUG][04.05.2020 20:53:17]: [XmppConnection]: Sending stream close... 
[INFO][04.05.2020 20:53:17]: [TcpConnection]: Socket closed because received 0-length message from: xmpp.domain.com 
[DEBUG][04.05.2020 20:53:17]: [TcpConnection] CONNECTED -> DISCONNECTING:  
[INFO][04.05.2020 20:53:17]: Disconnected account: [email protected] 
[ERROR][04.05.2020 20:53:17]: [TcpConnection]: Failed to send - sendCTS is null : </stream:stream> 
[DEBUG][04.05.2020 20:53:17]: [XmppConnection]: Stream close send. 
[DEBUG][04.05.2020 20:53:17]: [XmppConnection] DISCONNECTED -> CONNECTING:  
[DEBUG][04.05.2020 20:53:17]: [XmppConnection] DISCONNECTING -> DISCONNECTED:  
[DEBUG][04.05.2020 20:53:17]: [TcpConnection] DISCONNECTING -> DISCONNECTED:  
[DEBUG][04.05.2020 20:53:17]: [TcpConnection] DISCONNECTED -> CONNECTING:  
[DEBUG][04.05.2020 20:53:17]: [TcpConnection]: Starting a connection attempt. 
[DEBUG][04.05.2020 20:53:17]: [TcpConnection] CONNECTING -> CONNECTED:  
[INFO][04.05.2020 20:53:17]: Disconnected account: [email protected] 
[DEBUG][04.05.2020 20:53:17]: [TcpConnection]: Send to (xmpp.domain.com):<?xml version="1.0"?><stream:stream from="[email protected]" to="domain.com" version="1.0" xml:lang="en" xmlns="jabber:client" xmlns:stream="http://etherx.jabber.org/streams"> 
[DEBUG][04.05.2020 20:53:17]: [TcpConnection]: Received from (xmpp.domain.com):<?xml version='1.0'?><stream:stream xmlns:stream='http://etherx.jabber.org/streams' xml:lang='en' from='domain.com' id='cdf6e603-a6c0-475c-b999-05efc3ab4082' version='1.0' xmlns='jabber:client'><stream:features><starttls xmlns='urn:ietf:params:xml:ns:xmpp-tls'><required/></starttls></stream:features> 
[DEBUG][04.05.2020 20:53:17]: [TcpConnection]: Send to (xmpp.domain.com):<starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls" /> 
[DEBUG][04.05.2020 20:53:17]: [TcpConnection]: Received from (xmpp.domain.com):<proceed xmlns='urn:ietf:params:xml:ns:xmpp-tls'/> 
[DEBUG][04.05.2020 20:53:17]: Upgrading [email protected] connection to TLS... 
[DEBUG][04.05.2020 20:53:17]: Success upgrading [email protected] to TLS. 
[DEBUG][04.05.2020 20:53:17]: [XmppConnection] CONNECTING -> DISCONNECTED:  
[DEBUG][04.05.2020 20:53:17]: [TcpConnection]: Send to (xmpp.domain.com):<?xml version="1.0"?><stream:stream from="[email protected]" to="domain.com" version="1.0" xml:lang="en" xmlns="jabber:client" xmlns:stream="http://etherx.jabber.org/streams"> 
[DEBUG][04.05.2020 20:53:17]: [TcpConnection]: Received from (xmpp.domain.com):<?xml version='1.0'?><stream:stream xmlns:stream='http://etherx.jabber.org/streams' xml:lang='en' from='domain.com' id='5dd768f0-8048-42af-9604-50144526e071' version='1.0' xmlns='jabber:client'><stream:features><auth xmlns='http://jabber.org/features/iq-auth'/><mechanisms xmlns='urn:ietf:params:xml:ns:xmpp-sasl'><mechanism>PLAIN</mechanism><mechanism>SCRAM-SHA-1</mechanism><mechanism>SCRAM-SHA-1-PLUS</mechanism></mechanisms></stream:features> 
[DEBUG][04.05.2020 20:53:17]: [TcpConnection]: Send to (xmpp.domain.com):<auth mechanism="SCRAM-SHA-1" xmlns="urn:ietf:params:xml:ns:xmpp-sasl">biwsbj1yb21hbi5saXNrbyxyPWNYSHVUWHI3L3dRdmVvLzJKZHllRFhiaUNtSFYwWnlJZHVVL3R1UXJLZkk9</auth> 
[DEBUG][04.05.2020 20:53:17]: [TcpConnection]: Received from (xmpp.domain.com):<challenge xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>cj1jWEh1VFhyNy92UXZlby8ySmR5ZURYYmlDbUhWMFp5SWR1VS90dVFyS2ZJPWRiYzU1ODExLTZhYjgtNGY3Yi1iYjRkLTc3MTU4M2Y3NmViZSxzPVpqZ3dObVZpTW1FdE5tSTJNQzAwWkdRNUxUZzFZMkl0WW1VMVlqSmlabUV6TldVeSxpPTQwOTY=</challenge> 
[DEBUG][04.05.2020 20:53:17]: [TcpConnection]: Send to (xmpp.domain.com):<response xmlns="urn:ietf:params:xml:ns:xmpp-sasl">Yz1iaXdzLHI9Y1hIdVRYcjcvd1F2ZW8vMkpkeWVEWGJpQ21IVjBaeUlkdVUvdHVRcktmST1kYmM1NTgxMS02YWI4LTRmN2ItYmI0ZC03NzE1ODNmNzZlYmUscD0vZmV5VG14WVEzdFhXakRGMVFpSjRFQkVaalE9</response> 
[DEBUG][04.05.2020 20:53:17]: [TcpConnection]: Received from (xmpp.domain.com):<success xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>dj1QSDZWKzJqRnN0NThkSldLZGNVb0FKT2JKdnM9</success> 
[DEBUG][04.05.2020 20:53:17]: [TcpConnection]: Send to (xmpp.domain.com):<?xml version="1.0"?><stream:stream from="[email protected]" to="domain.com" version="1.0" xml:lang="en" xmlns="jabber:client" xmlns:stream="http://etherx.jabber.org/streams"> 
[DEBUG][04.05.2020 20:53:17]: [TcpConnection]: Received from (xmpp.domain.com):<?xml version='1.0'?><stream:stream xmlns:stream='http://etherx.jabber.org/streams' xml:lang='en' from='domain.com' id='01175183-9e2f-42ac-bc42-644f448654c9' version='1.0' xmlns='jabber:client'><stream:features><ver xmlns='urn:xmpp:features:rosterver'/><csi xmlns='urn:xmpp:csi:0'/><bind xmlns='urn:ietf:params:xml:ns:xmpp-bind'><required/></bind><session xmlns='urn:ietf:params:xml:ns:xmpp-session'><optional/></session><c hash='sha-1' ver='UIBPxiOZ8TZIsmct9hylA2Wy5v0=' node='http://prosody.im' xmlns='http://jabber.org/protocol/caps'/><sm xmlns='urn:xmpp:sm:2'><optional/></sm><sm xmlns='urn:xmpp:sm:3'><optional/></sm></stream:features> 
[DEBUG][04.05.2020 20:53:17]: [TcpConnection]: Send to (xmpp.domain.com):<iq type="set" id="83cf0529-180f-41c3-bfb9-bb3765269e0a">
  <bind xmlns="urn:ietf:params:xml:ns:xmpp-bind">
    <resource>UWPX</resource>
  </bind>
</iq> 
[DEBUG][04.05.2020 20:53:17]: [TcpConnection]: Received from (xmpp.domain.com):<iq id='83cf0529-180f-41c3-bfb9-bb3765269e0a' type='result'><bind xmlns='urn:ietf:params:xml:ns:xmpp-bind'><jid>[email protected]/UWPX</jid></bind></iq> 
[DEBUG][04.05.2020 20:53:17]: [TcpConnection]: Send to (xmpp.domain.com):<iq type="set" id="9fb8fcab-4b43-4e32-a159-e13cb1aa3ada">
  <session xmlns="urn:ietf:params:xml:ns:xmpp-session" />
</iq> 
[DEBUG][04.05.2020 20:53:17]: [TcpConnection]: Send to (xmpp.domain.com):<presence>
  <priority>0</priority>
</presence> 
[INFO][04.05.2020 20:53:17]: Connected to account: [email protected] 
[DEBUG][04.05.2020 20:53:17]: [TcpConnection]: Send to (xmpp.domain.com):<iq type="get" id="4a81d817-bc05-444d-bb60-39aaed9b4296" to="[email protected]" from="[email protected]/UWPX">
  <query xmlns="jabber:iq:roster" />
</iq> 
[DEBUG][04.05.2020 20:53:17]: [TcpConnection]: Send to (xmpp.domain.com):<iq type="get" id="9a8fdfe1-829e-495b-b666-9042234a38e1" from="[email protected]/UWPX">
  <pubsub xmlns="http://jabber.org/protocol/pubsub">
    <items node="storage:bookmarks" />
  </pubsub>
</iq> 
[INFO][04.05.2020 20:53:17]: Entering all MUC rooms for '[email protected]' 
[INFO][04.05.2020 20:53:17]: Delaying MUC joining for 5 seconds. 
[INFO][04.05.2020 20:53:17]: Sending 0 outstanding chat messages for: [email protected] 
[INFO][04.05.2020 20:53:17]: Finished sending outstanding chat messages for: [email protected] 
[INFO][04.05.2020 20:53:17]: Sending 0 outstanding OMEMO chat messages for: [email protected] 
[INFO][04.05.2020 20:53:17]: Finished sending outstanding OMEMO chat messages for: [email protected] 
[DEBUG][04.05.2020 20:53:17]: [XmppConnection] DISCONNECTED -> CONNECTED:  
[DEBUG][04.05.2020 20:53:17]: [TcpConnection]: Received from (xmpp.domain.com):<iq id='9fb8fcab-4b43-4e32-a159-e13cb1aa3ada' type='result' to='[email protected]/UWPX'/><presence from='[email protected]/UWPX'>
  <priority>0</priority>
</presence><presence to='[email protected]/UWPX' from='[email protected]/asterisk-xmpp'><status>&quot;Asterisk.&quot;</status><priority>1</priority><c ver='asterisk-xmpp' ext='voice-v1 video-v1 camera-v1' node='http://www.asterisk.org/xmpp/client/caps' xmlns='http://jabber.org/protocol/caps'/><delay from='domain.com' stamp='2020-04-30T11:03:48Z' xmlns='urn:xmpp:delay'/></presence><presence type='unavailable' to='[email protected]/UWPX' from='[email protected]'/><presence to='[email protected]/UWPX' from='[email protected]/Conversations.VOmT'><show>away</show><c ver='PeKYibv9P9qF24DQsRGfza05Bn0=' hash='sha-1' node='http://conversations.im' xmlns='http://jabber.org/protocol/caps'/><delay from='domain.com' stamp='2020-05-04T18:33:06Z' xmlns='urn:xmpp:delay'/></presence><presence type='unavailable' to='[email protected]/UWPX' from='[email protected]'/><presence to='[email protected]/UWPX' from='[email protected]/Conversations.6HiZ'><c ver='yZ3k+drC/otcaRFTSuhDJLp87gY=' hash='sha-1' node='http://conversations.im' xmlns='http://jabber.org/protocol/caps'/><idle xmlns='urn:xmpp:idle:1' since='2020-05-04T17:27:44.179Z'/><delay from='domain.com' stamp='2020-05-04T17:27:39Z' xmlns='urn:xmpp:delay'/></presence><presence to='[email protected]/UWPX' from='[email protected]/Conversations.vJ-R'><show>away</show><c ver='uLShaSsVDuAfcoROuTRCR7DZTR8=' hash='sha-1' node='http://conversations.im' xmlns='http://jabber.org/protocol/caps'/><delay from='domain.com' stamp='2020-05-04T18:53:15Z' xmlns='urn:xmpp:delay'/></presence><presence to='[email protected]/UWPX' from='[email protected]/Conversations.9ekB'><c ver='PeKYibv9P9qF24DQsRGfza05Bn0=' hash='sha-1' node='http://conversations.im' xmlns='http://jabber.org/protocol/caps'/><delay from='domain.com' stamp='2020-05-04T18:16:57Z' xmlns='urn:xmpp:delay'/></presence><presence type='unavailable' to='[email protected]/UWPX' from='[email protected]'/><presence type='unavailable' to='[email protected]' from='[email protected]'/> 
[DEBUG][04.05.2020 20:53:17]: [TcpConnection]: Received from (xmpp.domain.com):<iq id='4a81d817-bc05-444d-bb60-39aaed9b4296' type='result' to='[email protected]/UWPX'><query ver='222' xmlns='jabber:iq:roster'><item jid='[email protected]' subscription='both'/><item jid='[email protected]' subscription='both' name='User 6'><group>Contacts</group></item><item jid='[email protected]' ask='subscribe' subscription='none'/><item jid='[email protected]' subscription='both' name='M Account'/><item jid='[email protected]' subscription='both'><group>No group</group></item><item jid='[email protected]' subscription='both'/><item jid='[email protected]' subscription='both' name='Mama'/><item jid='[email protected]' subscription='both' name='User 5'/><item jid='[email protected]' subscription='both' name='Robo Agent'/></query></iq><iq id='9a8fdfe1-829e-495b-b666-9042234a38e1' type='error' to='[email protected]/UWPX'><error type='cancel'><item-not-found xmlns='urn:ietf:params:xml:ns:xmpp-stanzas'/></error></iq> 
[INFO][04.05.2020 20:53:22]: MUC join delay elapsed. Joining MUCs... 

@o---
Copy link
Author

o--- commented May 4, 2020

[INFO][04.05.2020 20:55:50]: MUC join delay elapsed. Joining MUCs... 
[DEBUG][04.05.2020 20:56:46]: [TcpConnection]: Received from (xmpp.domain.com):<iq id='idle-check' type='get' from='domain.com'><ping xmlns='urn:xmpp:ping'/></iq> 
[DEBUG][04.05.2020 20:56:56]: [TcpConnection]: Received from (xmpp.domain.com):<stream:error><connection-timeout xmlns='urn:ietf:params:xml:ns:xmpp-streams'/></stream:error></stream:stream> 
[DEBUG][04.05.2020 20:56:56]: [XmppConnection] CONNECTED -> DISCONNECTING:  
[DEBUG][04.05.2020 20:56:56]: [XmppConnection]: Sending stream close... 
[INFO][04.05.2020 20:56:56]: [TcpConnection]: Socket closed because received 0-length message from: xmpp.domain.com 
[DEBUG][04.05.2020 20:56:56]: [TcpConnection] CONNECTED -> DISCONNECTING:  
[INFO][04.05.2020 20:56:56]: Disconnected account: [email protected] 
**[ERROR][04.05.2020 20:56:56]: [TcpConnection]: Failed to send - sendCTS is null : </stream:stream>** 
[DEBUG][04.05.2020 20:56:56]: [XmppConnection]: Stream close send. 
[DEBUG][04.05.2020 20:56:56]: [XmppConnection] DISCONNECTED -> CONNECTING:  
[DEBUG][04.05.2020 20:56:56]: [XmppConnection] DISCONNECTING -> DISCONNECTED:  
[DEBUG][04.05.2020 20:56:56]: [TcpConnection] DISCONNECTING -> DISCONNECTED:  
[DEBUG][04.05.2020 20:56:56]: [TcpConnection] DISCONNECTED -> CONNECTING:  
[DEBUG][04.05.2020 20:56:56]: [TcpConnection]: Starting a connection attempt. 
[DEBUG][04.05.2020 20:56:56]: [TcpConnection] CONNECTING -> CONNECTED:  
[INFO][04.05.2020 20:56:56]: Disconnected account: [email protected] 
[DEBUG][04.05.2020 20:56:56]: [TcpConnection]: Send to (xmpp.domain.com):<?xml version="1.0"?><stream:stream from="[email protected]" to="domain.com" version="1.0" xml:lang="en" xmlns="jabber:client" xmlns:stream="http://etherx.jabber.org/streams"> 
[DEBUG][04.05.2020 20:56:56]: [TcpConnection]: Received from (xmpp.domain.com):<?xml version='1.0'?><stream:stream xmlns:stream='http://etherx.jabber.org/streams' xml:lang='en' from='domain.com' id='710b2a0d-498d-4a2a-851f-75aea791e715' version='1.0' xmlns='jabber:client'><stream:features><starttls xmlns='urn:ietf:params:xml:ns:xmpp-tls'><required/></starttls></stream:features> 
[DEBUG][04.05.2020 20:56:56]: [TcpConnection]: Send to (xmpp.domain.com):<starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls" /> 
[DEBUG][04.05.2020 20:56:56]: [TcpConnection]: Received from (xmpp.domain.com):<proceed xmlns='urn:ietf:params:xml:ns:xmpp-tls'/> 
[DEBUG][04.05.2020 20:56:56]: Upgrading [email protected] connection to TLS... 
[DEBUG][04.05.2020 20:56:56]: [XmppConnection] CONNECTING -> DISCONNECTED:  
[WARN][04.05.2020 20:56:56]: [XMPPConnection2]: Received stream error message: CONNECTION_TIMEOUT 
[DEBUG][04.05.2020 20:56:56]: [XmppConnection]: OnConnectionErrorAsync() got triggered - connectionErrorCount: 0 
[DEBUG][04.05.2020 20:56:56]: [XmppConnection] DISCONNECTED -> CONNECTING:  
[DEBUG][04.05.2020 20:56:56]: [TcpConnection] CONNECTED -> CONNECTING:  
[DEBUG][04.05.2020 20:56:56]: Success upgrading [email protected] to TLS. 
[DEBUG][04.05.2020 20:56:56]: [TcpConnection]: Starting a connection attempt. 
[ERROR][04.05.2020 20:56:56]: [XMPPConnection2]: Error during sending message for account: [email protected] 
[DEBUG][04.05.2020 20:56:56]: [TcpConnection] CONNECTING -> CONNECTED:  
[DEBUG][04.05.2020 20:56:56]: [XmppConnection]: Sending stream close... 
[DEBUG][04.05.2020 20:56:56]: [TcpConnection]: Send to (xmpp.domain.com):<?xml version="1.0"?><stream:stream from="[email protected]" to="domain.com" version="1.0" xml:lang="en" xmlns="jabber:client" xmlns:stream="http://etherx.jabber.org/streams"> 
[DEBUG][04.05.2020 20:56:56]: [TcpConnection]: Send to (xmpp.domain.com):</stream:stream> 
[DEBUG][04.05.2020 20:56:56]: [XmppConnection]: Stream close send. 
[DEBUG][04.05.2020 20:56:56]: [TcpConnection]: Received from (xmpp.domain.com):<?xml version='1.0'?><stream:stream xmlns:stream='http://etherx.jabber.org/streams' xml:lang='en' from='domain.com' id='90f5916d-50d5-4453-bdcb-f1e978b34579' version='1.0' xmlns='jabber:client'><stream:features><starttls xmlns='urn:ietf:params:xml:ns:xmpp-tls'><required/></starttls></stream:features></stream:stream> 
[DEBUG][04.05.2020 20:56:56]: [XmppConnection] CONNECTING -> DISCONNECTING:  
[DEBUG][04.05.2020 20:56:56]: [XmppConnection]: Sending stream close... 
[INFO][04.05.2020 20:56:56]: [TcpConnection]: Socket closed because received 0-length message from: xmpp.domain.com 
[DEBUG][04.05.2020 20:56:56]: [TcpConnection] CONNECTED -> DISCONNECTING:  
[INFO][04.05.2020 20:56:56]: Disconnected account: [email protected] 
[ERROR][04.05.2020 20:56:56]: [TcpConnection]: Failed to send - sendCTS is null : </stream:stream> 
[DEBUG][04.05.2020 20:56:56]: [XmppConnection]: Stream close send. 
[DEBUG][04.05.2020 20:56:56]: [XmppConnection] DISCONNECTED -> CONNECTING:  
[DEBUG][04.05.2020 20:56:56]: [XmppConnection] DISCONNECTING -> DISCONNECTED:  
[DEBUG][04.05.2020 20:56:56]: [TcpConnection] DISCONNECTING -> DISCONNECTED:  
[DEBUG][04.05.2020 20:56:56]: [TcpConnection] DISCONNECTED -> CONNECTING:  
[DEBUG][04.05.2020 20:56:56]: [TcpConnection]: Starting a connection attempt. 
[DEBUG][04.05.2020 20:56:56]: [TcpConnection] CONNECTING -> CONNECTED:  
[INFO][04.05.2020 20:56:56]: Disconnected account: [email protected] 
[DEBUG][04.05.2020 20:56:56]: [TcpConnection]: Send to (xmpp.domain.com):<?xml version="1.0"?><stream:stream from="[email protected]" to="domain.com" version="1.0" xml:lang="en" xmlns="jabber:client" xmlns:stream="http://etherx.jabber.org/streams"> 
[DEBUG][04.05.2020 20:56:56]: [TcpConnection]: Received from (xmpp.domain.com):<?xml version='1.0'?><stream:stream xmlns:stream='http://etherx.jabber.org/streams' xml:lang='en' from='domain.com' id='bd683f3e-2897-4cb3-a0a8-2c98ae77aec8' version='1.0' xmlns='jabber:client'><stream:features><starttls xmlns='urn:ietf:params:xml:ns:xmpp-tls'><required/></starttls></stream:features> 
[DEBUG][04.05.2020 20:56:56]: [TcpConnection]: Send to (xmpp.domain.com):<starttls xmlns="urn:ietf:params:xml:ns:xmpp-tls" /> 
[DEBUG][04.05.2020 20:56:56]: [TcpConnection]: Received from (xmpp.domain.com):<proceed xmlns='urn:ietf:params:xml:ns:xmpp-tls'/> 
[DEBUG][04.05.2020 20:56:56]: Upgrading [email protected] connection to TLS... 
[DEBUG][04.05.2020 20:56:56]: [XmppConnection] CONNECTING -> DISCONNECTED:  
[DEBUG][04.05.2020 20:56:56]: Success upgrading [email protected] to TLS. `


**[ERROR][04.05.2020 20:56:56]: [TcpConnection]: Failed to send - sendCTS is null : </stream:stream>** 

@COM8
Copy link
Member

COM8 commented May 5, 2020

Thanks.
I think the interesting part here is:

<iq id='idle-check' type='get' from='domain.com'>
    <ping xmlns='urn:xmpp:ping'/>
</iq> 
<stream:error>
    <connection-timeout xmlns='urn:ietf:params:xml:ns:xmpp-streams'/>
</stream:error>
</stream:stream> 

Your server tries to ping UWPX and UWPX does not respond to that.
I really should add support for XEP-0199: XMPP Ping since this should fix this.

@COM8
Copy link
Member

COM8 commented May 5, 2020

Could it be, that you disabled access for UWPX to access your local files?
This is probably the cause for the exception during exporting logs.
Reference:

@o---
Copy link
Author

o--- commented May 6, 2020

@COM8, thanks for looking into this. I have disabled the XEP-199 for testing purposes and indeed it seems it fixed the problem.
Regarding the file access permissions, I have only installed the app from the store. But I am generally working with an unprivileged user which however has the permission to access the log location without issues, since its in my users directory.

@COM8
Copy link
Member

COM8 commented May 6, 2020

Glad to hear.
I will have a deeper look into file permissions and how I have to check for those in UWP.
Probably this is not caused by the missing file permission for the logs folder, rather by the missing permissions the app requests for the target directory.

@COM8
Copy link
Member

COM8 commented May 6, 2020

e711222 adds support for XEP-0199: XMPP Ping.
This will be included in this month's release.
ETA: This weekend.

@o---
Copy link
Author

o--- commented May 11, 2020

I can confirm, that this has been resolved by v0.26.2.0. Thank you!

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
Projects
None yet
Development

No branches or pull requests

2 participants