Unable to connect to server (#319)

Unknown opened 5 years ago

Describe the bug I'm unable to sign in on two different XMPP servers, both of which work absolutely fine in every other XMPP client I've tried, both desktop and Android.

The two servers are nerdculture.de and hot-chilli.net.

To Reproduce Steps to reproduce the behavior:

Enter the XMPP ID and password
Click on 'SIGN IN' 3a. With nerdculture.de a "Checking connection" dialog pops up and disappears almost immediately, follow by a "Connection error" dialog 3b. With hot-chilli.net the "Checking connection" dialog pops up too but stays active for around 2 minutes, displaying 0% and 0/6 all that time, until it too throws a "Connection error".

Expected behavior Both accounts should log in without any issues.

Screenshots Screenshot from the Gemini

Desktop (please complete the following information):

OS: [n/a
Browser [n/a]
Version [n/a]

Smartphone (please complete the following information):

Device: [Sony Xperia X F5121 and Planet Computers Gemini]
OS: [Android 8.1.0 on both devices]
Browser [n/a]
Version [Stork IM 3.0.27.f]

Additional context A third account I've tried, movim.eu works without an issue.

Activities

Unknown commented 5 years ago

I tried hot-chilli server (create account in the domain @hot-chilli.eu) and it worked just fine in Psi+ and Stork.

nerdculture.de seems to point to mastodon (same account for two services)? Though, I haven't tried this one.

@lord-aerion could you get and share Android's logcat? (https://developer.android.com/studio/command-line/logcat or use an app: https://github.com/plusCubed/matlog)?
Unknown commented 5 years ago

Hi, thanks for the quick reply.

Both my hot-chilli.net and nerdculture.de accounts works fine in Conversations/Pix-Art Messenger and aTalk, as well as in Gajim on my desktop. They even work in Siskin on my iPad, although I wouldn't use it there as I don't actively use my iPad.

nerdculture.de is indeed a Mastodon instance, but they offer an XMPP server as well.

Happy to send you the logcat. I've set up adb and have also install matlog, but Iogcat produces a lot of output :-). How do I reduce it so it captures the information you're hoping to find?
Unknown commented 5 years ago

I can confirm (as admin of nerdculture.de) that authentication doesn't work. For the authentication I used https://git.chinwag.org/chinwag/ejabberd-auth-mastodon - and in some slight variation also for nerdica.net (Friendica). While logging into my hookipa.net account with Stork is working, this basically leaves the extauth script as differences between working and non-working scenario. BeagleIM and SiskinIM do not have this issue with the same extauth script for those domains.

Another information about this: when adding the optional hostname to the account settings (e.g. xmpp.hookipa.net) the login for nerdculture.de is working with Stork as well.

Hope this helps...

Unknown commented 5 years ago

Happy to send you the logcat. I've set up adb and have also install matlog, but Iogcat produces a lot of output :-). How do I reduce it so it captures the information you're hoping to find?

You should be able to filter out the result by application/package - use tigase or stork

@ingoj thank you for the hint about the script and comment in the MUC (lack of hostname prevents connection). I'd say that this is due configuration of those instances DNS:

nerdculture.de - has two SRV entries, one pointing to typical port, and one to "secure" port (could be direct-TLS):

$ dig SRV +short _xmpp-client._tcp.nerdculture.de
15 0 443 jabber.windfluechter.net.
5 0 5222 jabber.windfluechter.net.

Connecting to the first one works without any issue:

$ telnet jabber.windfluechter.net 5222
Trying 31.172.31.205...
Connected to jabber.windfluechter.net.
Escape character is '^]'.
<stream:stream xmlns:stream="http://etherx.jabber.org/streams" xml:lang="en" xmlns:xml="http://www.w3.org/XML/1998/namespace" xmlns="jabber:client" to="nerdculture.de" version="1.0">
<?xml version='1.0'?><stream:stream id='8508838036613736964' version='1.0' xml:lang='en' xmlns:stream='http://etherx.jabber.org/streams' from='nerdculture.de' xmlns='jabber:client'><stream:features><starttls xmlns='urn:ietf:params:xml:ns:xmpp-tls'><required/></starttls></stream:features>
^CConnection closed by foreign host.

Trying to connect to the second one fails:

$ telnet jabber.windfluechter.net 443
Trying 31.172.31.205...
Connected to jabber.windfluechter.net.
Escape character is '^]'.
<stream:stream xmlns:stream="http://etherx.jabber.org/streams" xml:lang="en" xmlns:xml="http://www.w3.org/XML/1998/namespace" xmlns="jabber:client" to="nerdculture.de" version="1.0">
Connection closed by foreign host.

If we try to do 'direct-TLS' it fails too:

$ openssl s_client -connect jabber.windfluechter.net:443 -xmpphost nerdculture.de
CONNECTED(00000005)
depth=2 O = Digital Signature Trust Co., CN = DST Root CA X3
verify return:1
depth=1 C = US, O = Let's Encrypt, CN = Let's Encrypt Authority X3
verify return:1
depth=0 CN = jabber.windfluechter.net
verify return:1
---
Certificate chain
 0 s:CN = jabber.windfluechter.net
   i:C = US, O = Let's Encrypt, CN = Let's Encrypt Authority X3
 1 s:C = US, O = Let's Encrypt, CN = Let's Encrypt Authority X3
   i:O = Digital Signature Trust Co., CN = DST Root CA X3
---
Server certificate
-----BEGIN CERTIFICATE-----
<cut SSL debug>
-----END CERTIFICATE-----
subject=CN = jabber.windfluechter.net

issuer=C = US, O = Let's Encrypt, CN = Let's Encrypt Authority X3

---
No client certificate CA names sent
Peer signing digest: SHA256
Peer signature type: RSA-PSS
Server Temp Key: X25519, 253 bits
---
SSL handshake has read 3882 bytes and written 406 bytes
Verification: OK
---
New, TLSv1.3, Cipher is TLS_AES_256_GCM_SHA384
Server public key is 4096 bit
Secure Renegotiation IS NOT supported
Compression: NONE
Expansion: NONE
No ALPN negotiated
Early data was not sent
Verify return code: 0 (ok)
---
---
Post-Handshake New Session Ticket arrived:
SSL-Session:
    Protocol  : TLSv1.3
    <cut SSL debug>
---
read R BLOCK
---
Post-Handshake New Session Ticket arrived:
SSL-Session:
    Protocol  : TLSv1.3
    <cut SSL debug>
---
read R BLOCK
<stream:stream xmlns:stream="http://etherx.jabber.org/streams" xml:lang="en" xmlns:xml="http://www.w3.org/XML/1998/namespace" xmlns="jabber:client" to="nerdculture.de" version="1.0">
HTTP/1.1 400 Bad Request
Date: Wed, 22 Jul 2020 20:37:31 GMT
Server: Apache/2.4.38 (Debian)
Public-Key-Pins:
Strict-Transport-Security: max-age=63072000; includeSubdomains; preload
Content-Length: 310
Connection: close
Content-Type: text/html; charset=iso-8859-1

<!DOCTYPE HTML PUBLIC "-//IETF//DTD HTML 2.0//EN">
<html><head>
<title>400 Bad Request</title>
</head><body>
<h1>Bad Request</h1>
<p>Your browser sent a request that this server could not understand.<br />
</p>
<hr>
<address>Apache/2.4.38 (Debian) Server at files.hookipa.net Port 443</address>
</body></html>
closed

It seems like on 443 normal web-traffic should be handled Do you know what was the intent? Is it supposed to handle both files and direct-TLS on the same port?

Apart from that, even so - DirectTLS should not be advertised with xmpp-client but with xmpps-client.

hookipa.net - similar problem, but slightly more convoluted:

$ dig SRV +short _xmpp-client._tcp.hookipa.net
1 0 443 turn2.hookipa.net.
5 0 5222 jabber.windfluechter.net.

it advertises turn server with higher priority
it advertises the same thing for xmpp-client and xmpps-client (i.e. turn server)

$ dig SRV +short _xmpps-client._tcp.hookipa.net
1 0 443 turn2.hookipa.net.
5 0 5223 jabber.windfluechter.net.

Yes, Stork should not try to re-connect to the same hostname if if fails, but those DNS entries should be fixed as well…

Unknown commented 5 years ago

Ah, wait... DNS...

Port 443 should point to 31.172.31.206 whereas 5222 should point to 31.172.31.205. That's one thing I can fix.

However, during my testing I also changed the priority of the SRV records - without a success for connection.

I'll check DNS again and maybe remove the second entry, just to simplify the setup... let's wait for the DNS to propagate...
Unknown commented 5 years ago

Erm, but what is the intention of the setup? Currently it points to the same machine, but with two different ports, and it seems incorrect, unless jabber.windfluechter.net would accept on port 443 also plain-socket XMPP connections. If not, it should be moved to xmpps-client
Unknown commented 5 years ago

Ok, bind9 had also an hickup.. After deleting the *.jnl files and restarting the nameserver I now get this:

vserv:/var/www/webmail# host -t srv _xmpp-client._tcp.nerdculture.de _xmpp-client._tcp.nerdculture.de has SRV record 5 0 5222 jabber.windfluechter.net.

Let's wait for the TTL to refresh...
Unknown commented 5 years ago
Hmmm... ok, so the DNS had its time to propagate the changed zone...

root@jabber:~# host -t srv _xmpp-client._tcp.nerdculture.de _xmpp-client._tcp.nerdculture.de has SRV record 5 0 5222 jabber.windfluechter.net. root@jabber:~# host -t srv _xmpps-client._tcp.nerdculture.de _xmpps-client._tcp.nerdculture.de has SRV record 5 0 5223 jabber.windfluechter.net.

Only thing is: Stork still can't connect and I even don't see my user in the debug log of ejabberd. Even when trying to monitor with tcpdump on the server it seems as if there is no connection established or even tried at all. Maybe @lord-aerion can see more in the Android logs...

Unknown commented 5 years ago

When I add the hostname I can indeed log in on nerdculture.de, as per @ingoj suggestion.

Here are the log entries for a connection attempt without providing the hostname. There are no entries for stork, only for tigase.

07-23 16:37:38.642 D/tigase.jaxmpp.android.Jaxmpp(13005): state=disconnected cr=false
07-23 16:37:38.642 D/tigase.jaxmpp.android.Jaxmpp(13005): state=disconnected cr=false
07-23 16:37:38.643 I/tigase.jaxmpp.android.Jaxmpp(13005): Using SocketConnector
07-23 16:37:38.643 I/tigase.jaxmpp.android.Jaxmpp(13005): Using SocketConnector
07-23 16:38:13.416 D/tigase.jaxmpp.android.Jaxmpp(13005): state=disconnected cr=false
07-23 16:38:13.416 D/tigase.jaxmpp.android.Jaxmpp(13005): state=disconnected cr=false
07-23 16:38:13.417 I/tigase.jaxmpp.android.Jaxmpp(13005): Using SocketConnector
07-23 16:38:13.418 I/tigase.jaxmpp.android.Jaxmpp(13005): Using SocketConnector
07-23 16:38:15.629 D/tigase.jaxmpp.android.Jaxmpp(13005): state=disconnected cr=false
07-23 16:38:15.634 D/tigase.jaxmpp.android.Jaxmpp(13005): state=disconnected cr=false
07-23 16:38:15.634 D/tigase.jaxmpp.android.Jaxmpp(13005): state=disconnected cr=false
07-23 16:38:15.634 D/tigase.jaxmpp.android.Jaxmpp(13005): state=disconnected cr=false
07-23 16:38:15.636 I/tigase.jaxmpp.android.Jaxmpp(13005): Using SocketConnector
07-23 16:38:15.638 I/tigase.jaxmpp.android.Jaxmpp(13005): Using SocketConnector

Unknown commented 5 years ago

Just tried generating logs for a connection attempt to hot-chilli.net, but the log entries entries are the same, just with different timestamps.

Unknown commented 5 years ago

OK, I decided to signup or an account and try it myself and managed to get some details:

2020-07-23 15:46:48.886 14363-14392/? V/AndroidDNSResolver: Resolving domain nerdculture.de
2020-07-23 15:46:48.886 14363-14392/? V/AndroidDNSResolver: Clearing cache
2020-07-23 15:46:48.886 14363-14392/? V/AndroidDNSResolver: Looking for DNS record of domain nerdculture.de
2020-07-23 15:46:48.905 14363-14392/? W/AndroidDNSResolver: Something goes wrong during resolving DNS entry for domain nerdculture.de
    org.minidns.dnssec.DnssecValidationFailedException: Validation of 2 SRV records failed: Signature is invalid.
        at org.minidns.dnssec.Verifier.verify(Verifier.java:76)
        at org.minidns.dnssec.DnssecClient.verifySignedRecords(DnssecClient.java:379)
        at org.minidns.dnssec.DnssecClient.verifySignatures(DnssecClient.java:301)
        at org.minidns.dnssec.DnssecClient.verifyAnswer(DnssecClient.java:162)
        at org.minidns.dnssec.DnssecClient.verify(DnssecClient.java:152)
        at org.minidns.dnssec.DnssecClient.performVerification(DnssecClient.java:112)
        at org.minidns.dnssec.DnssecClient.queryDnssec(DnssecClient.java:100)
        at org.minidns.hla.DnssecResolverApi.resolve(DnssecResolverApi.java:65)
        at org.minidns.hla.ResolverApi.resolve(ResolverApi.java:109)
        at org.minidns.hla.ResolverApi.resolveSrv(ResolverApi.java:184)
        at org.minidns.hla.ResolverApi.resolveSrv(ResolverApi.java:136)
        at org.minidns.hla.ResolverApi.resolveSrv(ResolverApi.java:131)
        at org.minidns.hla.ResolverApi.resolveSrv(ResolverApi.java:119)
        at tigase.jaxmpp.android.AndroidDNSResolver.resolveSRV(AndroidDNSResolver.java:91)
        at tigase.jaxmpp.android.AndroidDNSResolver.resolve(AndroidDNSResolver.java:65)
        at tigase.jaxmpp.j2se.connectors.socket.SocketConnector.start(SocketConnector.java:370)
        at tigase.jaxmpp.core.client.connector.ConnectorWrapper.start(ConnectorWrapper.java:96)
        at tigase.jaxmpp.j2se.Jaxmpp.login(Jaxmpp.java:315)
        at tigase.jaxmpp.j2se.Jaxmpp.login(Jaxmpp.java:246)
        at org.tigase.messenger.phone.pro.account.ConnectionChecker.check(ConnectionChecker.java:140)
        at org.tigase.messenger.phone.pro.account.LoginActivity$UserLoginTask.doInBackground(LoginActivity.java:372)
        at org.tigase.messenger.phone.pro.account.LoginActivity$UserLoginTask.doInBackground(LoginActivity.java:331)
        at android.os.AsyncTask$3.call(AsyncTask.java:378)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
        at android.os.AsyncTask$SerialExecutor$1.run(AsyncTask.java:289)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
        at java.lang.Thread.run(Thread.java:919)

@ingoj - it seems that DNSSEC signature is invalid (as per Validation of 2 SRV records failed: Signature is invalid.).

@bmalkow - could you comment on that?

Unknown commented 5 years ago

@woj-tek Ok, one of my secondary nameserver had some issues with outdated RRSIG, but should be resolved now: https://dnsviz.net/d/nerdculture.de/dnssec/
Unknown commented 5 years ago

@ingoj now I was able to connect with Stork to recently created account. @lord-aerion - does it work now for you for that domain?

Regarding hot-chilli -- please check in logcat if you have any exceptions when not filtering by tigase (only search for the phrase and then check logs around it)
Unknown commented 5 years ago

@woj-tek Hmmm, I still can't connect with Stork... Wondering why...?
Unknown commented 5 years ago

@ingoj to nerdculture.de? Unfortunately at this point you'd have to provide logcat as I'm connecting to nerdculture.de just fine:
Unknown commented 5 years ago

@ingoj now I was able to connect with Stork to recently created account. @lord-aerion - does it work now for you for that domain?

Hi, sorry about my silence. I'm suffering from depression and sometimes find it hard to concentrate on something. Couldn't bring myself to look into this.

Unfortunately I still can't log in on nerdculture.de without specifying the hostname. Same error as before:

Regarding hot-chilli -- please check in logcat if you have any exceptions when not filtering by tigase (only search for the phrase and then check logs around it)

I'll have a look now and will post the results here shortly.

Unknown commented 5 years ago

All right, here are two fresh logcats:

nerdculture.de

07-28 16:35:13.750 I/ConnectionChecker(27062): Checking connection aerion@nerdculture.de...
07-28 16:35:13.771 I/nectors.socket.SocketConnector(27062): [scid=3 thread=1370] Resolving SRV record of domain 'nerdculture.de'
07-28 16:35:13.771 I/SocketConnector(27062): [scid=3 thread=1370] Resolving SRV record of domain 'nerdculture.de'
07-28 16:35:13.776 V/AndroidDNSResolver(27062): Resolving domain nerdculture.de
07-28 16:35:13.785 V/AndroidDNSResolver(27062): Looking for DNS record of domain nerdculture.de
07-28 16:35:14.134 W/AndroidDNSResolver(27062): Something goes wrong during resolving DNS entry for domain nerdculture.de
07-28 16:35:14.135 D/nectors.socket.SocketConnector(27062): [scid=3 thread=1370] Preparing connection to [nerdculture.de:5222]
07-28 16:35:14.143 I/nectors.socket.SocketConnector(27062): [scid=3 thread=1370] Opening connection to nerdculture.de/31.172.31.213:5222
07-28 16:35:14.143 I/SocketConnector(27062): [scid=3 thread=1370] Opening connection to nerdculture.de/31.172.31.213:5222
07-28 16:35:14.186 W/ConnectionChecker(27062): tigase.jaxmpp.core.client.exceptions.JaxmppException: java.net.ConnectException: failed to connect to nerdculture.de/31.172.31.213 (port 5222) from /:: (port 45035): connect failed: ECONNREFUSED (Connection refused)
07-28 16:35:14.186 W/ConnectionChecker(27062): Caused by: java.net.ConnectException: failed to connect to nerdculture.de/31.172.31.213 (port 5222) from /:: (port 45035): connect failed: ECONNREFUSED (Connection refused)
07-28 16:35:14.225 I/LoginActivity(27062): tigase.jaxmpp.core.client.exceptions.JaxmppException: java.net.ConnectException: failed to connect to nerdculture.de/31.172.31.213 (port 5222) from /:: (port 45035): connect failed: ECONNREFUSED (Connection refused)
07-28 16:35:14.225 I/LoginActivity(27062): Caused by: java.net.ConnectException: failed to connect to nerdculture.de/31.172.31.213 (port 5222) from /:: (port 45035): connect failed: ECONNREFUSED (Connection refused)

hotchilli-net

07-28 16:47:10.938 W/ConnectionChecker(27062): tigase.jaxmpp.core.client.exceptions.JaxmppException: java.net.ConnectException: failed to connect to hot-chilli.net/46.4.119.20 (port 5222) from /:: (port 51506): connect failed: ETIMEDOUT (Connection timed out)
07-28 16:47:10.938 W/ConnectionChecker(27062): Caused by: java.net.ConnectException: failed to connect to hot-chilli.net/46.4.119.20 (port 5222) from /:: (port 51506): connect failed: ETIMEDOUT (Connection timed out)
07-28 16:47:10.990 I/LoginActivity(27062): tigase.jaxmpp.core.client.exceptions.JaxmppException: java.net.ConnectException: failed to connect to hot-chilli.net/46.4.119.20 (port 5222) from /:: (port 51506): connect failed: ETIMEDOUT (Connection timed out)
07-28 16:47:10.990 I/LoginActivity(27062): Caused by: java.net.ConnectException: failed to connect to hot-chilli.net/46.4.119.20 (port 5222) from /:: (port 51506): connect failed: ETIMEDOUT (Connection timed out)

With both accounts the behaviour is the same as before: nerdculture.de fails instantly, hot-chilli.net fails after approximately 2 minutes.

Regarding hot-chilli, could there be a different between hot-chilli.eu (the test account you opened) and hot-chilli.net (my account)?

Unknown commented 5 years ago

Hmmm, Stork is not resolving the SRV record, but the A record:

07-28 16:35:13.771 I/nectors.socket.SocketConnector(27062): [scid=3 thread=1370] Resolving SRV record of domain 'nerdculture.de'
07-28 16:35:13.771 I/SocketConnector(27062): [scid=3 thread=1370] Resolving SRV record of domain 'nerdculture.de'
07-28 16:35:13.776 V/AndroidDNSResolver(27062): Resolving domain nerdculture.de
07-28 16:35:13.785 V/AndroidDNSResolver(27062): Looking for DNS record of domain nerdculture.de
07-28 16:35:14.134 W/AndroidDNSResolver(27062): Something goes wrong during resolving DNS entry for domain nerdculture.de
07-28 16:35:14.135 D/nectors.socket.SocketConnector(27062): [scid=3 thread=1370] Preparing connection to [nerdculture.de:5222]
07-28 16:35:14.143 I/nectors.socket.SocketConnector(27062): [scid=3 thread=1370] Opening connection to nerdculture.de/31.172.31.213:5222
07-28 16:35:14.143 I/SocketConnector(27062): [scid=3 thread=1370] Opening connection to nerdculture.de/31.172.31.213:5222

Doing a lookup:

$ host -t a nerdculture.de
nerdculture.de has address 31.172.31.213
$ host -t srv  _xmpp-client._tcp.nerdculture.de
_xmpp-client._tcp.nerdculture.de has SRV record 5 0 5222 jabber.windfluechter.net.
$ host jabber.windfluechter.net
jabber.windfluechter.net has address 31.172.31.205
jabber.windfluechter.net mail is handled by 10 vserv.windfluechter.net.

So, basically Stork is correct when it cannot connect to 31.172.31.213:5222, because there is no XMPP server listening. I have no idea why it doesn connect to 31.172.31.205:5222, where ejabberd is listening.

So, what does go wrong as Stork is stating Something goes wrong during resolving DNS entry for domain nerdculture.de? DNSviz is reporting that everything is ok with nerdculture.de: https://dnsviz.net/d/nerdculture.de/XyBmCw/dnssec/ - but I still have the impression that it might have to do with EDNS due to DNSSEC... hot-chilli.net is DNSSEC-enabled as well...

Unknown commented 5 years ago

@lord-aerion no worries. Regarding the issue both chilli instances have exact DNS entries (though I'm not sure you experienced DNS issue with chilli servers).:

$ dig +short SRV _xmpp-client._tcp.hot-chilli.eu
10 0 5222 jabber.hot-chilli.net.
20 0 80 server.jabber.hot-chilli.net.

$ dig +short SRV _xmpp-client._tcp.hot-chilli.net
10 0 5222 jabber.hot-chilli.net.
20 0 80 server.jabber.hot-chilli.net.

Though, checking DNS entries for all domains:

$ dig +short jabber.hot-chilli.net
49.12.125.53

$ dig +short server.jabber.hot-chilli.net
49.12.125.24

$ dig +short hot-chilli.net
46.4.119.20

and comparing them with Stork log - it seems there is also a DNS resolution issue in this case (it tries to connect to A record for hot-chilli.net: "failed to connect to hot-chilli.net/46.4.119.20"

@lord-aerion & @ingoj - is there any StackTrace there with "Exception"? The log entry should contain it. It's possible that MiniDNS is throwing an issue here but without more logs/details I'm unable to say with certainty (and I can't reproduce it).

I even tried to run MiniDNS directly on my machine and it return results just fine:

org.minidns.hla.SrvResolverResult
Question: _xmpp-client._tcp.hot-chilli.net.	IN	SRV
Response Code: NO_ERROR
Results verified via DNSSEC
[_xmpp-client._tcp.hot-chilli.net.	2822	IN	SRV	10 0 5222 jabber.hot-chilli.net., _xmpp-client._tcp.hot-chilli.net.	2822	IN	SRV	20 0 80 server.jabber.hot-chilli.net.]
Done in: PT31.391S

and

Resolving: nerdculture.de
org.minidns.hla.SrvResolverResult
Question: _xmpp-client._tcp.nerdculture.de.	IN	SRV
Response Code: NO_ERROR
Results verified via DNSSEC
[_xmpp-client._tcp.nerdculture.de.	300	IN	SRV	5 0 5222 jabber.windfluechter.net.]
Done in: PT32.529S

What is curious though is that resolution takes quite some time (more than 30s) - maybe there is some timeout?

Could you try running REPL from MiniDNS explained here: https://github.com/MiniDNS/minidns#repl ?

Unknown commented 5 years ago

Hi @woj-tek, sorry for the lengthy absence. After months of nothing, suddenly had a burst of work and at the end of the day I couldn't bring myself to spend even more time behind the PC to carry on with this. My black dog wouldn't let me.

Here's some "Exception" stack trace for nerdculture.de. There are a couple of lines in there I know are not relevant, but I've left everything in, just in case.

08-21 16:33:57.829 I/WindowManager(969): java.lang.RuntimeException: here
08-21 16:34:03.229 E/LockSettingsStorage(969): Cannot read file java.io.FileNotFoundException: /data/system_de/0/spblob/2da1b4231ed42bd4.weaver: open failed: ENOENT (No such file or directory)
08-21 16:34:56.761 V/KernelUidCpuFreqTimeReader(969): Failed to read /proc/uid_time_in_state: java.io.FileNotFoundException: /proc/uid_time_in_state (No such file or directory)
08-21 16:35:28.906 W/BroadcastQueue(969): android.os.RemoteException: app.thread must not be null
08-21 16:35:29.730 V/KernelUidCpuFreqTimeReader(969): Failed to read /proc/uid_time_in_state: java.io.FileNotFoundException: /proc/uid_time_in_state (No such file or directory)
08-21 16:35:46.658 W/AppOps  (969): java.lang.RuntimeException: here
08-21 16:35:51.224 I/cert4android(10364): EXCEPTION java.io.FileNotFoundException: /data/user/0/com.etesync.syncadapter/app_KeyStore/KeyStore.bks (No such file or directory)
08-21 16:35:56.286 I/cert4android(10364): EXCEPTION java.io.FileNotFoundException: /data/user/0/com.etesync.syncadapter/app_KeyStore/KeyStore.bks (No such file or directory)
08-21 16:36:08.926 W/Conscrypt(1781): Could not set socket write timeout: java.net.SocketException: Socket closed
08-21 16:36:08.975 W/Conscrypt(1781): Could not set socket write timeout: java.net.SocketException: Socket closed
08-21 16:36:09.775 W/Conscrypt(1781): Could not set socket write timeout: java.net.SocketException: Socket closed
08-21 16:36:09.855 W/Conscrypt(1781): Could not set socket write timeout: java.net.SocketException: Socket closed
08-21 16:36:11.434 W/Conscrypt(1781): Could not set socket write timeout: java.net.SocketException: Socket closed
08-21 16:36:11.530 W/Conscrypt(1781): Could not set socket write timeout: java.net.SocketException: Socket closed
08-21 16:36:16.856 W/GAv4-SVC(1858): Network compressed POST connection error: java.net.UnknownHostException: Unable to resolve host "ssl.google-analytics.com": No address associated with hostname
08-21 16:36:28.411 I/cert4android(10364): EXCEPTION java.io.FileNotFoundException: /data/user/0/com.etesync.syncadapter/app_KeyStore/KeyStore.bks (No such file or directory)
08-21 16:36:33.510 I/cert4android(10364): EXCEPTION java.io.FileNotFoundException: /data/user/0/com.etesync.syncadapter/app_KeyStore/KeyStore.bks (No such file or directory)
08-21 16:36:35.015 W/AppOps  (969): java.lang.RuntimeException: here
08-21 16:36:39.398 W/AppOps  (969): java.lang.RuntimeException: here
08-21 16:36:45.937 E/WebViewFactory(10526): No such method for getDefinedWebViewPackageName: java.lang.NoSuchMethodException: getDefinedWebViewPackageName []
08-21 16:37:21.398 I/zygote64(10675): Caused by: java.lang.ClassNotFoundException: Didn't find class "android.view.View$OnUnhandledKeyEventListener" on path: DexPathList[[zip file "/data/app/org.tigase.messenger.phone.pro-D7VZARz1adVvr7O9gU2DTg==/base.apk"],nativeLibraryDirectories=[/data/app/org.tigase.messenger.phone.pro-D7VZARz1adVvr7O9gU2DTg==/lib/arm64, /data/app/org.tigase.messenger.phone.pro-D7VZARz1adVvr7O9gU2DTg==/base.apk!/lib/arm64-v8a, /system/lib64, /system/vendor/lib64]]
08-21 16:37:21.399 I/zygote64(10675): Caused by: java.lang.ClassNotFoundException: Didn't find class "android.view.View$OnUnhandledKeyEventListener" on path: DexPathList[[zip file "/data/app/org.tigase.messenger.phone.pro-D7VZARz1adVvr7O9gU2DTg==/base.apk"],nativeLibraryDirectories=[/data/app/org.tigase.messenger.phone.pro-D7VZARz1adVvr7O9gU2DTg==/lib/arm64, /data/app/org.tigase.messenger.phone.pro-D7VZARz1adVvr7O9gU2DTg==/base.apk!/lib/arm64-v8a, /system/lib64, /system/vendor/lib64]]
08-21 16:37:21.400 I/zygote64(10675): Caused by: java.lang.ClassNotFoundException: Didn't find class "android.view.View$OnUnhandledKeyEventListener" on path: DexPathList[[zip file "/data/app/org.tigase.messenger.phone.pro-D7VZARz1adVvr7O9gU2DTg==/base.apk"],nativeLibraryDirectories=[/data/app/org.tigase.messenger.phone.pro-D7VZARz1adVvr7O9gU2DTg==/lib/arm64, /data/app/org.tigase.messenger.phone.pro-D7VZARz1adVvr7O9gU2DTg==/base.apk!/lib/arm64-v8a, /system/lib64, /system/vendor/lib64]]
08-21 16:37:26.253 I/zygote64(1930): Caused by: java.lang.ClassNotFoundException: Didn't find class "android.view.View$OnUnhandledKeyEventListener" on path: DexPathList[[zip file "/data/app/com.x8bit.bitwarden-1TREr7mfIZdriy-dJrKNBA==/base.apk", zip file "/data/app/com.x8bit.bitwarden-1TREr7mfIZdriy-dJrKNBA==/split_config.arm64_v8a.apk", zip file "/data/app/com.x8bit.bitwarden-1TREr7mfIZdriy-dJrKNBA==/split_config.en.apk", zip file "/data/app/com.x8bit.bitwarden-1TREr7mfIZdriy-dJrKNBA==/split_config.xxhdpi.apk"],nativeLibraryDirectories=[/data/app/com.x8bit.bitwarden-1TREr7mfIZdriy-dJrKNBA==/lib/arm64, /data/app/com.x8bit.bitwarden-1TREr7mfIZdriy-dJrKNBA==/base.apk!/lib/arm64-v8a, /data/app/com.x8bit.bitwarden-1TREr7mfIZdriy-dJrKNBA==/split_config.arm64_v8a.apk!/lib/arm64-v8a, /data/app/com.x8bit.bitwarden-1TREr7mfIZdriy-dJrKNBA==/split_config.en.apk!/lib/arm64-v8a, /data/app/com.x8bit.bitwarden-1TREr7mfIZdriy-dJrKNBA==/split_config.xxhdpi.apk!/lib/arm64-v8a, /system/lib64, /system/vendor/lib64]]
08-21 16:37:26.253 I/zygote64(1930): Caused by: java.lang.ClassNotFoundException: Didn't find class "android.view.View$OnUnhandledKeyEventListener" on path: DexPathList[[zip file "/data/app/com.x8bit.bitwarden-1TREr7mfIZdriy-dJrKNBA==/base.apk", zip file "/data/app/com.x8bit.bitwarden-1TREr7mfIZdriy-dJrKNBA==/split_config.arm64_v8a.apk", zip file "/data/app/com.x8bit.bitwarden-1TREr7mfIZdriy-dJrKNBA==/split_config.en.apk", zip file "/data/app/com.x8bit.bitwarden-1TREr7mfIZdriy-dJrKNBA==/split_config.xxhdpi.apk"],nativeLibraryDirectories=[/data/app/com.x8bit.bitwarden-1TREr7mfIZdriy-dJrKNBA==/lib/arm64, /data/app/com.x8bit.bitwarden-1TREr7mfIZdriy-dJrKNBA==/base.apk!/lib/arm64-v8a, /data/app/com.x8bit.bitwarden-1TREr7mfIZdriy-dJrKNBA==/split_config.arm64_v8a.apk!/lib/arm64-v8a, /data/app/com.x8bit.bitwarden-1TREr7mfIZdriy-dJrKNBA==/split_config.en.apk!/lib/arm64-v8a, /data/app/com.x8bit.bitwarden-1TREr7mfIZdriy-dJrKNBA==/split_config.xxhdpi.apk!/lib/arm64-v8a, /system/lib64, /system/vendor/lib64]]
08-21 16:37:26.254 I/zygote64(1930): Caused by: java.lang.ClassNotFoundException: Didn't find class "android.view.View$OnUnhandledKeyEventListener" on path: DexPathList[[zip file "/data/app/com.x8bit.bitwarden-1TREr7mfIZdriy-dJrKNBA==/base.apk", zip file "/data/app/com.x8bit.bitwarden-1TREr7mfIZdriy-dJrKNBA==/split_config.arm64_v8a.apk", zip file "/data/app/com.x8bit.bitwarden-1TREr7mfIZdriy-dJrKNBA==/split_config.en.apk", zip file "/data/app/com.x8bit.bitwarden-1TREr7mfIZdriy-dJrKNBA==/split_config.xxhdpi.apk"],nativeLibraryDirectories=[/data/app/com.x8bit.bitwarden-1TREr7mfIZdriy-dJrKNBA==/lib/arm64, /data/app/com.x8bit.bitwarden-1TREr7mfIZdriy-dJrKNBA==/base.apk!/lib/arm64-v8a, /data/app/com.x8bit.bitwarden-1TREr7mfIZdriy-dJrKNBA==/split_config.arm64_v8a.apk!/lib/arm64-v8a, /data/app/com.x8bit.bitwarden-1TREr7mfIZdriy-dJrKNBA==/split_config.en.apk!/lib/arm64-v8a, /data/app/com.x8bit.bitwarden-1TREr7mfIZdriy-dJrKNBA==/split_config.xxhdpi.apk!/lib/arm64-v8a, /system/lib64, /system/vendor/lib64]]
08-21 16:37:26.757 E/WebViewFactory(1914): No such method for getDefinedWebViewPackageName: java.lang.NoSuchMethodException: getDefinedWebViewPackageName []
08-21 16:37:28.377 E/WebViewFactory(1858): No such method for getDefinedWebViewPackageName: java.lang.NoSuchMethodException: getDefinedWebViewPackageName []
08-21 16:37:31.736 W/AppOps  (969): java.lang.RuntimeException: here
08-21 16:37:37.670 V/KernelUidCpuFreqTimeReader(969): Failed to read /proc/uid_time_in_state: java.io.FileNotFoundException: /proc/uid_time_in_state (No such file or directory)
08-21 16:37:50.976 I/mono-stdout(1930): FFImageLoading.Exceptions.DownloadException: Zero length stream
08-21 16:37:52.079 I/mono-stdout(1930): FFImageLoading.Exceptions.DownloadAggregateException: One or more errors occurred. (Headers timeout) ---> FFImageLoading.Exceptions.DownloadHeadersTimeoutException: Headers timeout
08-21 16:37:52.079 I/mono-stdout(1930):    --- End of inner exception stack trace ---
08-21 16:37:52.079 I/mono-stdout(1930): ---> (Inner Exception #0) FFImageLoading.Exceptions.DownloadHeadersTimeoutException: Headers timeout
08-21 16:37:53.132 W/AndroidDNSResolver(10675): java.lang.IllegalArgumentException: Invalid input to toASCII: .
08-21 16:37:53.196 W/ConnectionChecker(10675): tigase.jaxmpp.core.client.exceptions.JaxmppException: java.net.ConnectException: failed to connect to nerdculture.de/31.172.31.213 (port 5222) from /:: (port 53561): connect failed: ECONNREFUSED (Connection refused)
08-21 16:37:53.196 W/ConnectionChecker(10675): Caused by: java.net.ConnectException: failed to connect to nerdculture.de/31.172.31.213 (port 5222) from /:: (port 53561): connect failed: ECONNREFUSED (Connection refused)
08-21 16:37:53.196 W/ConnectionChecker(10675): Caused by: android.system.ErrnoException: connect failed: ECONNREFUSED (Connection refused)
08-21 16:37:53.243 I/LoginActivity(10675): tigase.jaxmpp.core.client.exceptions.JaxmppException: java.net.ConnectException: failed to connect to nerdculture.de/31.172.31.213 (port 5222) from /:: (port 53561): connect failed: ECONNREFUSED (Connection refused)
08-21 16:37:53.243 I/LoginActivity(10675): Caused by: java.net.ConnectException: failed to connect to nerdculture.de/31.172.31.213 (port 5222) from /:: (port 53561): connect failed: ECONNREFUSED (Connection refused)
08-21 16:37:53.243 I/LoginActivity(10675): Caused by: android.system.ErrnoException: connect failed: ECONNREFUSED (Connection refused)

Unknown commented 5 years ago

Here's the same information for hot-chilli.net.

08-21 16:34:03.229 E/LockSettingsStorage(969): Cannot read file java.io.FileNotFoundException: /data/system_de/0/spblob/2da1b4231ed42bd4.weaver: open failed: ENOENT (No such file or directory)
08-21 16:34:56.761 V/KernelUidCpuFreqTimeReader(969): Failed to read /proc/uid_time_in_state: java.io.FileNotFoundException: /proc/uid_time_in_state (No such file or directory)
08-21 16:35:28.906 W/BroadcastQueue(969): android.os.RemoteException: app.thread must not be null
08-21 16:35:29.730 V/KernelUidCpuFreqTimeReader(969): Failed to read /proc/uid_time_in_state: java.io.FileNotFoundException: /proc/uid_time_in_state (No such file or directory)
08-21 16:35:46.658 W/AppOps  (969): java.lang.RuntimeException: here
08-21 16:36:35.015 W/AppOps  (969): java.lang.RuntimeException: here
08-21 16:36:39.398 W/AppOps  (969): java.lang.RuntimeException: here
08-21 16:37:31.736 W/AppOps  (969): java.lang.RuntimeException: here
08-21 16:37:37.670 V/KernelUidCpuFreqTimeReader(969): Failed to read /proc/uid_time_in_state: java.io.FileNotFoundException: /proc/uid_time_in_state (No such file or directory)
08-21 16:50:04.695 W/Conscrypt(1781): Could not set socket write timeout: java.net.SocketException: Socket closed
08-21 16:50:04.836 W/Conscrypt(1781): Could not set socket write timeout: java.net.SocketException: Socket closed
08-21 16:50:18.174 W/GAv4-SVC(1858): Network compressed POST connection error: java.net.UnknownHostException: Unable to resolve host "ssl.google-analytics.com": No address associated with hostname
08-21 16:50:18.707 W/ConnectionChecker(10675): tigase.jaxmpp.core.client.exceptions.JaxmppException: java.net.ConnectException: failed to connect to hot-chilli.net/46.4.119.20 (port 5222) from /:: (port 39669): connect failed: ETIMEDOUT (Connection timed out)
08-21 16:50:18.707 W/ConnectionChecker(10675): Caused by: java.net.ConnectException: failed to connect to hot-chilli.net/46.4.119.20 (port 5222) from /:: (port 39669): connect failed: ETIMEDOUT (Connection timed out)
08-21 16:50:18.707 W/ConnectionChecker(10675): Caused by: android.system.ErrnoException: connect failed: ETIMEDOUT (Connection timed out)
08-21 16:50:18.747 I/LoginActivity(10675): tigase.jaxmpp.core.client.exceptions.JaxmppException: java.net.ConnectException: failed to connect to hot-chilli.net/46.4.119.20 (port 5222) from /:: (port 39669): connect failed: ETIMEDOUT (Connection timed out)
08-21 16:50:18.747 I/LoginActivity(10675): Caused by: java.net.ConnectException: failed to connect to hot-chilli.net/46.4.119.20 (port 5222) from /:: (port 39669): connect failed: ETIMEDOUT (Connection timed out)
08-21 16:50:18.747 I/LoginActivity(10675): Caused by: android.system.ErrnoException: connect failed: ETIMEDOUT (Connection timed out)
08-21 16:50:49.260 W/SearchView(10615): Search suggestions cursor at row 0 returned exception.
08-21 16:50:49.260 W/SearchView(10615): java.lang.NullPointerException: Attempt to invoke virtual method 'java.lang.String android.app.SearchableInfo.getSuggestIntentAction()' on a null object reference
08-21 16:51:17.499 W/AndroidDNSResolver(10675): java.lang.IllegalArgumentException: Invalid input to toASCII: .
08-21 16:52:18.365 W/GAv4-SVC(1858): Network compressed POST connection error: java.net.UnknownHostException: Unable to resolve host "ssl.google-analytics.com": No address associated with hostname
08-21 16:53:20.834 W/ConnectionChecker(10675): tigase.jaxmpp.core.client.exceptions.JaxmppException: java.net.ConnectException: failed to connect to hot-chilli.net/46.4.119.20 (port 5222) from /:: (port 39682): connect failed: ETIMEDOUT (Connection timed out)
08-21 16:53:20.834 W/ConnectionChecker(10675): Caused by: java.net.ConnectException: failed to connect to hot-chilli.net/46.4.119.20 (port 5222) from /:: (port 39682): connect failed: ETIMEDOUT (Connection timed out)
08-21 16:53:20.834 W/ConnectionChecker(10675): Caused by: android.system.ErrnoException: connect failed: ETIMEDOUT (Connection timed out)
08-21 16:53:20.864 I/LoginActivity(10675): tigase.jaxmpp.core.client.exceptions.JaxmppException: java.net.ConnectException: failed to connect to hot-chilli.net/46.4.119.20 (port 5222) from /:: (port 39682): connect failed: ETIMEDOUT (Connection timed out)
08-21 16:53:20.864 I/LoginActivity(10675): Caused by: java.net.ConnectException: failed to connect to hot-chilli.net/46.4.119.20 (port 5222) from /:: (port 39682): connect failed: ETIMEDOUT (Connection timed out)
08-21 16:53:20.864 I/LoginActivity(10675): Caused by: android.system.ErrnoException: connect failed: ETIMEDOUT (Connection timed out)

I'm afraid I'm not quite sure what I should do with MiniDNS, or how to run it on my system.

Unknown commented 5 years ago
Thank you @lord-aerion for those logs - could you try to gather complete stack traces from around those lines (possibly searching for AndroidDNSResolver but the best would be without any filtering):

1 16:37:53.132 W/AndroidDNSResolver(10675): java.lang.IllegalArgumentException: Invalid input to toASCII: .

08-21 16:51:17.499 W/AndroidDNSResolver(10675): java.lang.IllegalArgumentException: Invalid input to toASCII: .

They seem to be responsible for the issue, but those lines only don't give enough information. (@ingoj - or maybe you given that you experience same issue)?
Unknown commented 5 years ago

Sorry for another delay, lots of stuff came up that consumed all my time.

Here's a selection of a more complete log. It's probably more than you need. I've tried to reduce it by stripping out a bunch of ALSA and other system related lines. I hope this provides you with what you need, but let me know if not and I'll produce more.

This is of a connection attempt to nerdculture.de only.

As it's quite a lenghty log I've attached it as a file instead of cluttering up the thread.

filtered_catlog.txt

Unknown commented 5 years ago

Thank you for the logs, relevant entries:

09-01 14:35:25.914 D/nectors.socket.SocketConnector(13042): [scid=1 thread=809] Using resolver provided by user: tigase.jaxmpp.android.AndroidDNSResolver@11c56b3
09-01 14:35:25.914 V/AndroidDNSResolver(13042): Resolving domain nerdculture.de
09-01 14:35:25.914 V/AndroidDNSResolver(13042): Clearing cache
09-01 14:35:25.914 V/AndroidDNSResolver(13042): Looking for DNS record of domain nerdculture.de
…
09-01 14:35:26.043 W/org.tigase.messenger.phone.pro(13042): type=1400 audit(0.0:2392): avc: denied { read } for comm=4173796E635461736B202335 name="u:object_r:net_dns_prop:s0" dev="tmpfs" ino=10490 scontext=u:r:untrusted_app:s0:c512,c768 tcontext=u:object_r:net_dns_prop:s0 tclass=file permissive=0
09-01 14:35:26.056 E/libc    (13042): Access denied finding property "net.dns1"
09-01 14:35:26.043 W/org.tigase.messenger.phone.pro(13042): type=1400 audit(0.0:2393): avc: denied { read } for comm=4173796E635461736B202335 name="u:object_r:net_dns_prop:s0" dev="tmpfs" ino=10490 scontext=u:r:untrusted_app:s0:c512,c768 tcontext=u:object_r:net_dns_prop:s0 tclass=file permissive=0
09-01 14:35:26.057 E/libc    (13042): Access denied finding property "net.dns2"
09-01 14:35:26.043 W/org.tigase.messenger.phone.pro(13042): type=1400 audit(0.0:2394): avc: denied { read } for comm=4173796E635461736B202335 name="u:object_r:net_dns_prop:s0" dev="tmpfs" ino=10490 scontext=u:r:untrusted_app:s0:c512,c768 tcontext=u:object_r:net_dns_prop:s0 tclass=file permissive=0
09-01 14:35:26.058 E/libc    (13042): Access denied finding property "net.dns3"
09-01 14:35:26.043 W/org.tigase.messenger.phone.pro(13042): type=1400 audit(0.0:2395): avc: denied { read } for comm=4173796E635461736B202335 name="u:object_r:net_dns_prop:s0" dev="tmpfs" ino=10490 scontext=u:r:untrusted_app:s0:c512,c768 tcontext=u:object_r:net_dns_prop:s0 tclass=file permissive=0
09-01 14:35:26.058 E/libc    (13042): Access denied finding property "net.dns4"
09-01 14:35:26.173 D/AAL     (554): 09-01 02:35:26.006 BL= 346,ESS= 256, 09-01 02:35:26.043 BL= 345,ESS= 256, 09-01 02:35:26.080 BL= 344,ESS= 256, 09-01 02:35:26.136 BL= 343,ESS= 256, 09-01 02:35:26.173 BL= 342,ESS= 256,

@lord-aerion what DNS server do you use? Have you configured them manually? Could you check if setting them to 1.1.1.1 for example would work?

There was a similar issue reported in DNS library repository (https://github.com/MiniDNS/minidns/issues/74) but it should be fixed in this version already. @bmalkow - could you take a quick look?

Unknown commented 5 years ago

I'm using Pi-hole + Unbound running on a Raspberry Pi Zero W, but I'm also getting this issue when using my 4G connection, with or without NordVPN.

I've just tried a static DNS address of 1.1.1.1 and 1.0.0.1, sadly with the same result. The log still shows the above DNS errors.
Unknown commented 5 years ago

Hmmm, captured network today, but still unable to login from my Samsung S5 mini with Android 6.0.1. Here are the pcaps attached... as you can see it is doing DNSSEC... the first pcap is from configuring the account from scratch, the second is another try after failed login attempt.

So, from the miniDNS issue I conclude that my Android version is not fixed regarding that issue, so I might be a bad tester here. Which also might explain why @woj-tek could log in to nerdculture, but I couldn't.

stork-pcaps.zip
Unknown commented 5 years ago

Hi there, was wondering if there was any progress on this issue. I want to set my sister up with an XMPP account on Hot Chilli.

Her phone is very low on space so I need to set her up with Stork as it's less than half the size of Pix-Art Messenger (which is what I'm using at the moment because of the issue in this thread).
Unknown commented 5 years ago

Hi, unfortunately we weren't able to dedicate time to fix this issue yet.
Login to comment

Issue Votes (0)

Watchers (0)

Reference

tigase/_clients/stork#319