powered by Jive Software

Smack: aTalk is experiencing a long pause in start up the stream login process after XMPPConnection#connect() is called

aTalk is experiencing a long pause of ~40 seconds in start of sending the <stream/> login stanza after XMPPConnection#connect() is called (see aTalk logcat below). This problem occurs occasionally but persisted. Sometimes the problem recovers itself after some few hours of no debug activity. Previously the problem also recovers after I restart my android Note-10, but this seems to be not 100% all the time recently.

Under normal login process, this delay is <100ms; see 2nd aTalk logcat capture

Earlier I was doubting whether

accountAuthenticated.checkIfSuccessOrWait();

in connectAndLogin() call is holding back smack process execution, but has verified this is no the case.

I have raised the issue with android SDK development team since Sep 26, 2021, suspecting it may be due to AS adb debug or OS garbage collection, but still has not get any advice from them.
Google Issue Tracker (Please ignore the issue title)

The problem started since Smack v4.4.4 in aTalk v2.7.1 release, but not sure the problem has to do with Smack library or it is an AS adb debug problem.

Appreciate if your team can also advice on the observed problem.

======== aTalk login with long pause of 40 seconds =============
2022-06-02 08:10:16.892 16860-17062/org.atalk.android I/(ProtocolProviderServiceJabberImpl.java:1108)#connectAndLogin: Starting XMPP Connection...: atalk.sytes.net/42.60.7.13:5222
....
2022-06-02 08:10:18.812 649-649/? I/Layer: id=5853 Destroyed ActivityRecord{c37ed3a u0 org.atalk.android/.gui.LauncherActivity t77375}#0
2022-06-02 08:10:19.240 978-1056/? D/SGM:GameManager: identifyForegroundApp. org.atalk.android, mCurrentUserId: 0, callerUserId: 0
2022-06-02 08:10:19.240 978-1056/? D/SGM:PkgDataHelper: getGamePkgData(). org.atalk.android
2022-06-02 08:10:37.176 16860-17062/org.atalk.android I/aTalk: [163] org.jivesoftware.smack.tcp.rce.RemoteXmppTcpConnectionEndpoints.resolveDomain() Could not resolve DNS SRV resource records for _xmpp-client._tcp.atalk.sytes.net. Consider adding those.

### => Unexpected long pause of ~40 seconds before start of <stream/> login process
2022-06-02 08:11:17.698 16860-17110/org.atalk.android D/SMACK: SENT (0): 
    <stream:stream xmlns='jabber:client' to='atalk.sytes.net' xmlns:stream='http://etherx.jabber.org/streams' version='1.0' xml:lang='en'>
2022-06-02 08:11:17.741 16860-17111/org.atalk.android D/SMACK: RECV (0): ?xml version='1.0'?>
    <stream:stream id='9168948287818266291' version='1.0' xml:lang='en' xmlns:stream='http://etherx.jabber.org/streams' from='atalk.sytes.net' xmlns='jabber:client'>
    <stream:features>
      <starttls xmlns='urn:ietf:params:xml:ns:xmpp-tls'>
        <required/>
      </starttls>
    </stream:features>
2022-06-02 08:11:17.755 16860-17110/org.atalk.android D/SMACK: SENT (0): 
    <starttls xmlns='urn:ietf:params:xml:ns:xmpp-tls'/>
2022-06-02 08:11:17.767 16860-17111/org.atalk.android D/SMACK: RECV (0): 
    <proceed xmlns='urn:ietf:params:xml:ns:xmpp-tls'/>
2022-06-02 08:11:19.134 16860-17110/org.atalk.android D/SMACK: SENT (0): 
    <stream:stream xmlns='jabber:client' to='atalk.sytes.net' xmlns:stream='http://etherx.jabber.org/streams' version='1.0' id='9168948287818266291' xml:lang='en'>
2022-06-02 08:11:19.147 16860-17111/org.atalk.android D/SMACK: RECV (0): ?xml version='1.0'?>
    <stream:stream id='8505503090397911150' version='1.0' xml:lang='en' xmlns:stream='http://etherx.jabber.org/streams' from='atalk.sytes.net' xmlns='jabber:client'>
2022-06-02 08:11:19.157 16860-17111/org.atalk.android D/SMACK: RECV (0): 
    <stream:features>
      <mechanisms xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>
        <mechanism>
          EXTERNAL
        </mechanism>
        <mechanism>
          PLAIN
        </mechanism>
        <mechanism>
          SCRAM-SHA-1-PLUS
        </mechanism>
        <mechanism>
          SCRAM-SHA-1
        </mechanism>
        <mechanism>
          X-OAUTH2
        </mechanism>
      </mechanisms>
      <register xmlns='http://jabber.org/features/iq-register'/>
    </stream:features>
2022-06-02 08:11:19.171 16860-17059/org.atalk.android W/g.atalk.androi: Long monitor contention with owner Smack DefaultReactor Thread #1 (17060) at int sun.nio.ch.SelectorImpl.lockAndDoSelect(long)(SelectorImpl.java:86) waiters=0 in void org.jivesoftware.smack.SmackReactor$Reactor.handleScheduledActionsOrPerformSelect() for 62.487s
2022-06-02 08:11:19.224 16860-17062/org.atalk.android I/(AndroidOmemoService.java:50)#<init>: ### Registered omemo messageListener for: swordfish@atalk.sytes.net
2022-06-02 08:11:19.259 16860-17062/org.atalk.android D/(ProtocolProviderServiceJabberImpl.java:1146)#connectAndLogin: Entering check IfSuccess Or Wait or Throw!


// aTalk Thread states while in 40s pause
""@25,079: ZOMBIE
"ADB-JDWP Connection Control Thread"@21,255: WAIT
"Binder:20000_1"@21,260 in group "main": RUNNING
"Binder:20000_2"@21,261 in group "main": RUNNING
"Binder:20000_3"@21,262 in group "main": RUNNING
"Binder:20000_4"@23,077 in group "main": RUNNING
"Binder:20000_5"@23,998 in group "main": RUNNING
"Binder:20000_6"@24,006 in group "main": RUNNING
"Binder:20000_7"@24,089 in group "main": RUNNING
"Binder:20000_8"@24,120 in group "main": RUNNING
"Binder:20000_9"@24,124 in group "main": RUNNING
"Chrome_IOThread"@21,674 in group "main": RUNNING
"Chrome_ProcessLauncherThread"@21,485 in group "main": RUNNING
"CleanupReference"@21,839 in group "main": WAIT
"FinalizerDaemon"@21,258: WAIT
"FinalizerWatchdogDaemon"@21,259: WAIT
"GoogleApiHandler"@21,569 in group "main": RUNNING
"HeapTaskDaemon"@21,256: WAIT
"hwuiTask0"@23,080 in group "main": RUNNING
"hwuiTask1"@23,081 in group "main": RUNNING
"Jit thread pool worker thread 0"@21,254: RUNNING
"main"@20,995 in group "main": RUNNING
"org.atalk.impl.osgi.framework.AsyncExecutor"@23,311 in group "main": WAIT
"org.atalk.impl.osgi.framework.AsyncExecutor"@23,206 in group "main": WAIT
"org.atalk.impl.osgi.framework.AsyncExecutor"@23,098 in group "main": WAIT
"PlatformServiceBridgeHandlerThread"@21,705 in group "main": RUNNING
"Profile Saver"@21,011: RUNNING
"queued-work-looper"@22,628 in group "main": RUNNING
"queued-work-looper-data"@21,014 in group "main": WAIT
"ReferenceQueueDaemon"@21,257: WAIT
"RenderThread"@22,026 in group "main": RUNNING
"Signal Catcher"@21,253: WAIT
"Smack DefaultReactor Thread #0"@26,172 in group "main": MONITOR
"Smack DefaultReactor Thread #1"@26,176 in group "main": RUNNING
"Thread-13"@26,448 in group "main": WAIT
"Thread-15"@26,767 in group "main": WAIT
"ThreadPoolForeg"@22,631 in group "main": RUNNING
"ThreadPoolForeg"@21,688 in group "main": RUNNING
"ThreadPoolSingl"@21,709 in group "main": RUNNING
"Timer-0"@25,187 in group "main": WAIT
============== aTalk normal login timing ===========
2022-05-31 08:00:05.433 26547-26659/org.atalk.android I/(ProtocolProviderServiceJabberImpl.java:979)#connectAndLogin: Connect using service SRV Resource Record: atalk.sytes.net/42.60.7.13:5222
2022-05-31 08:00:05.464 26547-26659/org.atalk.android I/(ProtocolProviderServiceJabberImpl.java:1108)#connectAndLogin: Starting XMPP Connection...: atalk.sytes.net/42.60.7.13:5222
.....
2022-05-31 08:00:05.856 26547-26659/org.atalk.android I/aTalk: [87] org.jivesoftware.smack.tcp.rce.RemoteXmppTcpConnectionEndpoints.resolveDomain() Could not resolve DNS SRV resource records for _xmpp-client._tcp.atalk.sytes.net. Consider adding those.
2022-05-31 08:00:05.925 26547-26675/org.atalk.android D/SMACK: SENT (0): 
    <stream:stream xmlns='jabber:client' to='atalk.sytes.net' xmlns:stream='http://etherx.jabber.org/streams' version='1.0' xml:lang='en'>
2022-05-31 08:00:05.932 26547-26676/org.atalk.android D/SMACK: RECV (0): ?xml version='1.0'?>
    <stream:stream id='16637983341418396771' version='1.0' xml:lang='en' xmlns:stream='http://etherx.jabber.org/streams' from='atalk.sytes.net' xmlns='jabber:client'>
2022-05-31 08:00:05.933 26547-26676/org.atalk.android D/SMACK: RECV (0): 
    <stream:features>
      <starttls xmlns='urn:ietf:params:xml:ns:xmpp-tls'>
        <required/>
      </starttls>
    </stream:features>
============ aTalk user login process ================
    private ConnectState connectAndLogin(String userName, JabberLoginStrategy loginStrategy)
            throws XMPPException, SmackException
    {
        ConnectionConfiguration.Builder<?, ?> config = loginStrategy.getConnectionConfigurationBuilder();

        // Set XmppDomain to serviceName - default for no server-overridden and Bosh connection.
        DomainBareJid serviceName = mAccountID.getXmppDomain();
        config.setXmppDomain(serviceName);
        config.setResource(mResource);
        config.setProxyInfo(proxy);
        config.setCompressionEnabled(false);

        /*=== Configure connection for BOSH or TCP ===*/
        boolean isBosh = mAccountID.isBOSHEnable();
        if (isBosh) {
            String boshURL = mAccountID.getBoshUrl();
            BOSHConfiguration.Builder boshConfigurationBuilder = (BOSHConfiguration.Builder) config;
            try {
                URI boshURI = new URI(boshURL);
                boolean useHttps = boshURI.getScheme().equals("https");
                int port = boshURI.getPort();
                if (port == -1) {
                    port = useHttps ? 443 : 80;
                }

                String file = boshURI.getPath();
                // use rawQuery as getQuery() decodes the string
                String query = boshURI.getRawQuery();
                if (!TextUtils.isEmpty(query)) {
                    file += "?" + query;
                }

                boshConfigurationBuilder
                        .setUseHttps(useHttps)
                        .setFile(file)
                        .setHost(boshURI.getHost())
                        .setPort(port);
            } catch (URISyntaxException e) {
                Timber.e("Fail setting bosh URL in XMPPBOSHConnection configuration: %s", e.getMessage());
                StanzaError stanzaError = StanzaError.getBuilder(Condition.unexpected_request).build();
                throw new XMPPErrorException(null, stanzaError);
            }
        }
        else {
            /*
             * The defined settings for setHostAddress and setHost are handled by XMPPTCPConnection
             * #populateHostAddresses()-obsoleted, mechanism for the various service mode.
             */
            boolean isServerOverridden = mAccountID.getAccountPropertyBoolean(
                    ProtocolProviderFactory.IS_SERVER_OVERRIDDEN, false);

            // cmeng - value not defined currently for CUSTOM_XMPP_DOMAIN login
            String customXMPPDomain = mAccountID.getAccountPropertyString(ProtocolProviderFactory.CUSTOM_XMPP_DOMAIN);
            if (customXMPPDomain != null) {
                mInetSocketAddress = new InetSocketAddress(customXMPPDomain, DEFAULT_PORT);
                Timber.i("Connect using custom XMPP domain: %s", mInetSocketAddress);

                config.setHostAddress(mInetSocketAddress.getAddress());
                config.setPort(DEFAULT_PORT);
            }

            /*=== connect using overridden server name defined by user ===*/
            else if (isServerOverridden) {
                String host = mAccountID.getServerAddress();
                int port = mAccountID.getAccountPropertyInt(ProtocolProviderFactory.SERVER_PORT, DEFAULT_PORT);
                mInetSocketAddress = new InetSocketAddress(host, port);
                Timber.i("Connect using server override: %s", mInetSocketAddress);

                // For host given as ip address, then no DNSSEC authentication support
                if (Character.digit(host.charAt(0), 16) != -1) {
                    config.setHostAddress(mInetSocketAddress.getAddress());
                }
                // setHostAddress will take priority over setHost in smack populateHostAddresses() implementation - obsoleted
                config.setHost(host);
                config.setPort(port);
            }

            /*=== connect using SRV Resource Record for userID service name (host and hostAddress must be null) ===*/
            else {
                mInetSocketAddress = new InetSocketAddress(mAccountID.getService(), DEFAULT_PORT);
                Timber.i("Connect using service SRV Resource Record: %s", mInetSocketAddress);

                config.setHost((DnsName) null);
                config.setHostAddress(null);
            }
        }

        // if we have OperationSetPersistentPresence to take care of <presence/> sending, then
        // disable smack from sending the initial presence upon user authentication
        OpSetPP = getOperationSet(OperationSetPersistentPresence.class);
        if (OpSetPP != null)
            config.setSendPresence(false);

        if (mConnection != null && mConnection.isConnected()) {
            Timber.w("Attempt on connection that is not null and isConnected %s", mAccountID.getAccountJid());
            disconnectAndCleanConnection();
        }
        config.setSocketFactory(SocketFactory.getDefault());

        String[] supportedProtocols = {"TLSv1", "TLSv1.1", "TLSv1.2"};
        try {
            supportedProtocols = ((SSLSocket) SSLSocketFactory.getDefault().createSocket()).getSupportedProtocols();
        } catch (IOException e) {
            Timber.d("Use default supported Protocols: %s", Arrays.toString(supportedProtocols));
            // Use default list
        }
        Arrays.sort(supportedProtocols);

        // Determine enabled TLS protocol versions using getMinimumTLSversion
        ArrayList<String> enabledTLSProtocols = new ArrayList<>();
        for (int prot = supportedProtocols.length - 1; prot >= 0; prot--) {
            final String prot_version = supportedProtocols[prot];
            enabledTLSProtocols.add(prot_version);
            if (prot_version.equals(mAccountID.getMinimumTLSversion())) {
                break;
            }
        }

        String[] enabledTLSProtocolsArray = new String[enabledTLSProtocols.size()];
        enabledTLSProtocols.toArray(enabledTLSProtocolsArray);
        config.setEnabledSSLProtocols(enabledTLSProtocolsArray);

        // Cannot use a custom SSL context with DNSSEC enabled
        String dnssecMode = mAccountID.getDnssMode();
        if (DNSSEC_DISABLE.equals(dnssecMode)) {
            config.setDnssecMode(DnssecMode.disabled);

            /*
             * BOSH connection does not support TLS;
             * XEP-206 Note: The client SHOULD ignore any Transport Layer Security (TLS) feature since
             * BOSH channel encryption SHOULD be negotiated at the HTTP layer.
             */
            boolean tlsRequired;
            if (isBosh) {
                tlsRequired = false;
                config.setSecurityMode(SecurityMode.disabled);
            }
            else {
                /*
                 * user have the possibility to disable TLS but in this case, it will not be able to
                 * connect to a server which requires TLS;
                 */
                tlsRequired = loginStrategy.isTlsRequired();
                config.setSecurityMode(tlsRequired ? SecurityMode.required : SecurityMode.ifpossible);
            }

            CertificateService cvs = getCertificateVerificationService();
            if (cvs != null) {
                try {
                    X509TrustManager sslTrustManager = getTrustManager(cvs, serviceName);
                    SSLContext sslContext = loginStrategy.createSslContext(cvs, sslTrustManager);
                    SslContextFactory sslContextFactory = () -> sslContext;

                    config.setSslContextFactory(sslContextFactory);
                    config.setCustomX509TrustManager(sslTrustManager);
                    config.setAuthzid(mAccountID.getBareJid().asEntityBareJidIfPossible());

                } catch (GeneralSecurityException e) {
                    Timber.e(e, "Error creating custom trust manager");
                    // StanzaError stanzaError = StanzaError.getBuilder(Condition.service_unavailable).build();
                    throw new ATalkXmppException("Security-Exception: Creating custom TrustManager", e);
                }
            }
            else if (tlsRequired) {
                // StanzaError stanzaError = StanzaError.getBuilder(Condition.service_unavailable).build();
                // throw new XMPPErrorException(null, stanzaError);
                throw new ATalkXmppException("Security-Exception: Certificate verification service is unavailable and TLS is required");
            }
        }
        else {
            if (DNSSEC_ONLY.equals(dnssecMode)) {
                config.setDnssecMode(DnssecMode.needsDnssec);
            }
            else if (DNSSEC_AND_DANE.equals(dnssecMode)) {
                // override user SecurityMode setting for DNSSEC & DANE option
                config.setDnssecMode(DnssecMode.needsDnssecAndDane);
                config.setSecurityMode(ConnectionConfiguration.SecurityMode.required);
            }
        }

        // String userJid = userName + "@" + serviceName;
        // String password = userCredentials.getPasswordAsString();
        // config.setUsernameAndPassword(userJid, password);
        try {
            if (isBosh) {
                mConnection = new XMPPBOSHConnection((BOSHConfiguration) config.build());
            }
            else {
                mConnection = new XMPPTCPConnection((XMPPTCPConnectionConfiguration) config.build());
            }
        } catch (IllegalStateException ex) {
            // Cannot use a custom SSL context with DNSSEC enabled
            String errMsg = ex.getMessage() + "\n Please change DNSSEC security option accordingly.";
            StanzaError stanzaError = StanzaError.from(Condition.not_allowed, errMsg).build();
            throw new XMPPErrorException(null, stanzaError);
        }

        /* Start monitoring the status before connection-login. Only register listener once */
        if (xmppConnectionListener == null) {
            xmppConnectionListener = new XMPPConnectionListener();
            mConnection.addConnectionListener(xmppConnectionListener);
        }

        // Allow longer timeout during login for slow client device; clear to default in caller
        mConnection.setReplyTimeout(SMACK_REPLY_EXTENDED_TIMEOUT_30);

        // Init the connection SynchronizedPoints
        xmppConnected = new LoginSynchronizationPoint<>(this, "connection connected");

        Timber.i("Starting XMPP Connection...: %s", mInetSocketAddress);
        try {
            mConnection.connect();
        } catch (StreamErrorException ex) {
            String errMsg = ex.getMessage();
            if (StringUtils.isEmpty(errMsg))
                errMsg = ex.getStreamError().getDescriptiveText();
            Timber.e("Encounter problem during XMPPConnection: %s", errMsg);
            StanzaError stanzaError = StanzaError.from(Condition.policy_violation, errMsg).build();
            throw new XMPPErrorException(null, stanzaError);
            // } catch (DnssecValidationFailedException | IllegalArgumentException ex) {
        } catch (DnssecValidationFailedException ex) {
            String errMsg = ex.getMessage();
            StanzaError stanzaError = StanzaError.from(Condition.not_authorized, errMsg).build();
            throw new XMPPErrorException(null, stanzaError);
        } catch (SecurityRequiredByServerException ex) {
            // "SSL/TLS required by server but disabled in client"
            String errMsg = ex.getMessage();
            StanzaError stanzaError = StanzaError.from(Condition.not_allowed, errMsg).build();
            throw new XMPPErrorException(null, stanzaError);
        } catch (SecurityRequiredByClientException ex) {
            // "SSL/TLS required by client but not supported by server"
            String errMsg = ex.getMessage();
            StanzaError stanzaError = StanzaError.from(Condition.service_unavailable, errMsg).build();
            throw new XMPPErrorException(null, stanzaError);
        } catch (XMPPException | SmackException | IOException | InterruptedException | NullPointerException ex) {
//            if (ex.getCause() instanceof SSLHandshakeException) {
//                Timber.e(ex.getCause());
//            }
            String errMsg = aTalkApp.getResString(R.string.service_gui_XMPP_EXCEPTION, ex.getMessage());
            Timber.e("%s", errMsg);
            StanzaError stanzaError = StanzaError.from(Condition.remote_server_timeout, errMsg).build();
            throw new XMPPErrorException(null, stanzaError);
        }
        try {
            /*
             * Wait for connectionListener to report connection status. Exception handled in the above try/catch
             */
            Timber.d("Entering check IfSuccess Or Wait or Throw!");
            xmppConnected.checkIfSuccessOrWaitOrThrow();
        } catch (InterruptedException e) {
            e.printStackTrace();
        }

        // Check if user has cancelled the Trusted Certificate confirmation request
        if (abortConnecting) {
            abortConnecting = false;
            disconnectAndCleanConnection();
            return ConnectState.ABORT_CONNECTING;
        }

        if (!mConnection.isConnected()) {
            Timber.e("XMPPConnection establishment has failed!");

            // mConnection is not connected, lets set the mConnection state as failed;
            disconnectAndCleanConnection();
            eventDuringLogin = null;
            fireRegistrationStateChanged(getRegistrationState(),
                    RegistrationState.CONNECTION_FAILED, RegistrationStateChangeEvent.REASON_SERVER_NOT_FOUND, null);
            return ConnectState.ABORT_CONNECTING;
        }

        // cmeng - leave the registering state broadcast when xmpp is connected - may be better to do it here
        fireRegistrationStateChanged(RegistrationState.UNREGISTERED, RegistrationState.REGISTERING,
                RegistrationStateChangeEvent.REASON_NOT_SPECIFIED, null);

        // Init the user authentication SynchronizedPoints
        accountAuthenticated = new LoginSynchronizationPoint<>(this, "account authenticated");
        boolean success = false;
        try {
            success = loginStrategy.login(mConnection, userName, mResource);
        } catch (StreamErrorException ex) {
            String errMsg = ex.getStreamError().getDescriptiveText();
            Timber.e("Encounter problem during XMPPConnection: %s", errMsg);
            StanzaError stanzaError = StanzaError.from(Condition.policy_violation, errMsg).build();
            throw new XMPPErrorException(null, stanzaError);
        } catch (SmackException | XMPPException | InterruptedException | IOException el) {
            String errMsg = el.getMessage();
            /*
             * If account is not registered on server, send IB registration request to server if user
             * enable the option. Otherwise throw back to user and ask for InBand registration confirmation.
             */
            if (StringUtils.isNotEmpty(errMsg) && errMsg.contains("not-authorized")) {
                if (mAccountID.isIbRegistration()) {
                    try {
                        // Server sends stream disconnect on "not-authorized". So perform manual connect again before
                        // server closes the stream. Some Server does otherwise, so check before making connection.
                        if (!mConnection.isConnected())
                            mConnection.connect();
                        // stop pps connectionListener from disturbing IBR registration process
                        mConnection.removeConnectionListener(xmppConnectionListener);
                        xmppConnectionListener = null;

                        accountIBRegistered = new LoginSynchronizationPoint<>(this, "account ib registered");
                        loginStrategy.registerAccount(this, mAccountID);
                        eventDuringLogin = null;
                        return ConnectState.STOP_TRYING;
                    } catch (StreamErrorException ex) {
                        errMsg = ex.getStreamError().getDescriptiveText();
                        Timber.e("Encounter problem during XMPPConnection: %s", errMsg);
                        StanzaError stanzaError = StanzaError.from(Condition.policy_violation, errMsg).build();
                        throw new XMPPErrorException(null, stanzaError);
                    } catch (SmackException | XMPPException | InterruptedException | IOException | NullPointerException err) {
                        disconnectAndCleanConnection();
                        eventDuringLogin = null;
                        fireRegistrationStateChanged(getRegistrationState(), RegistrationState.CONNECTION_FAILED,
                                RegistrationStateChangeEvent.REASON_IB_REGISTRATION_FAILED,
                                loginStrategy.getClass().getName() + " requests abort");

                        errMsg = err.getMessage();
                        if (StringUtils.isNotEmpty(errMsg) && !errMsg.contains("registration-required")) {
                            errMsg = aTalkApp.getResString(R.string.service_gui_REGISTRATION_REQUIRED, errMsg);
                            Timber.e("%s", errMsg);
                            StanzaError stanzaError = StanzaError.from(Condition.forbidden, errMsg).build();
                            throw new XMPPErrorException(null, stanzaError);
                        }
                        else {
                            Timber.e("%s", errMsg);
                            StanzaError stanzaError = StanzaError.from(Condition.registration_required, errMsg).build();
                            throw new XMPPErrorException(null, stanzaError);
                        }
                    }
                }
                else {
                    if (el instanceof SASLErrorException) {
                        errMsg += ": " + ((SASLErrorException) el).getSASLFailure().getDescriptiveText();
                    }
                    errMsg = aTalkApp.getResString(R.string.service_gui_NOT_AUTHORIZED_HINT, errMsg);
                    StanzaError stanzaError = StanzaError.from(Condition.not_authorized, errMsg).build();
                    throw new XMPPErrorException(null, stanzaError);
                }
            }
        }

        // cmeng - sometimes exception and crash after this point during apk debug launch. android JIT problem
        try {
            // wait for connectionListener to report status. Exceptions are handled in try/catch
            accountAuthenticated.checkIfSuccessOrWait();
        } catch (InterruptedException e) {
            Timber.w("Xmpp Connection authentication exception: %s", e.getMessage());
        }

        if (!success) {
            disconnectAndCleanConnection();
            eventDuringLogin = null;
            fireRegistrationStateChanged(getRegistrationState(),
                    RegistrationState.CONNECTION_FAILED, RegistrationStateChangeEvent.REASON_AUTHENTICATION_FAILED,
                    loginStrategy.getClass().getName() + " requests abort");
            return ConnectState.ABORT_CONNECTING;
        }

        if (mConnection.isAuthenticated()) {
            return ConnectState.STOP_TRYING;
        }
        else {
            disconnectAndCleanConnection();
            eventDuringLogin = null;
            fireRegistrationStateChanged(getRegistrationState(), RegistrationState.UNREGISTERED,
                    RegistrationStateChangeEvent.REASON_NOT_SPECIFIED, null);
            return ConnectState.CONTINUE_TRYING;
        }
    }

The thread states alone are a good start but what would be really helpful would be a complete thread dump which includes the stacktraces of threads. See

Then I would also immediately know which of those threads calls connectAndLogin(). I am also missing Smack’s per connection reader and writer thread thread pair in this list.

Anyhow, as soon as there is a complete thread dump taken at the right time, i.e., during the 40s delay, it is usually trivial to determine which action is not happening or maybe even where a deadlock did occur.

This morning, the long pause happens again immediately on fresh start of the day debug session, and remains persistent after that in all subsequently relaunching of aTalk. I have to restart my Note-10 device to get everything returns to normal working. I have attached the thread_report.txt captured during the 40 second pause period.

Yesterday everything was OK throughout the whole debug session.

Hopefully your team can shake some light on the problem.

2022-06-04 07:31:36.591 6866-6866/org.atalk.android I/ViewRootImpl@308bcc8[LauncherActivity]: dispatchDetachedFromWindow
2022-06-04 07:31:36.596 6866-6866/org.atalk.android D/InputTransport: Input channel destroyed: '7f29c4f', fd=141
2022-06-04 07:31:55.048 6866-7198/org.atalk.android I/aTalk: [204] org.jivesoftware.smack.tcp.rce.RemoteXmppTcpConnectionEndpoints.resolveDomain() Could not resolve DNS SRV resource records for _xmpp-client._tcp.atalk.sytes.net. Consider adding those.
2022-06-04 07:32:35.762 6866-7257/org.atalk.android D/SMACK: SENT (0): 
    <stream:stream xmlns='jabber:client' to='atalk.sytes.net' xmlns:stream='http://etherx.jabber.org/streams' version='1.0' xml:lang='en'>
2022-06-04 07:32:35.780 6866-7258/org.atalk.android D/SMACK: RECV (0): ?xml version='1.0'?>
    <stream:stream id='8050570502072260252' version='1.0' xml:lang='en' xmlns:stream='http://etherx.jabber.org/streams' from='atalk.sytes.net' xmlns='jabber:client'>
2022-06-04 07:32:35.788 6866-7258/org.atalk.android D/SMACK: RECV (0): 
    <stream:features>
      <starttls xmlns='urn:ietf:params:xml:ns:xmpp-tls'>
        <required/>
      </starttls>
    </stream:features>

threads_report.txt (14.1 KB)

Follow up info:
The problem of 40s pause starts again after I performed a new apk built and adb install. During the 40s pause period, I realised that both the Smack Reader and Smack Writer threads do not appear during the whole 40s pause period. Look like something has prevented the start of these 2 threads.

I highlighted all the threads in Threads UI during the 40s pause; found that these highlighted items are again shown in other threads captured later, after the 40s pause period as shown in the attached screenshot; The screenshot is captured after exit from the 40s pause period during aTalk normal operation.

The thread dump shows one thread of particular interest:

"Thread-13@25212" daemon prio=5 tid=0xcd nid=NA runnable
  java.lang.Thread.State: RUNNABLE
	  at libcore.io.Linux.poll(Linux.java:-1)
	  at libcore.io.ForwardingOs.poll(ForwardingOs.java:577)
	  at libcore.io.BlockGuardOs.poll(BlockGuardOs.java:282)
	  at libcore.io.ForwardingOs.poll(ForwardingOs.java:577)
	  at libcore.io.IoBridge.isConnected(IoBridge.java:328)
	  at libcore.io.IoBridge.connectErrno(IoBridge.java:238)
	  at libcore.io.IoBridge.connect(IoBridge.java:180)
	  at java.net.PlainSocketImpl.socketConnect(PlainSocketImpl.java:142)
	  at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:390)
	  - locked <0x641a> (a java.net.SocksSocketImpl)
	  at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:230)
	  at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:212)
	  at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:436)
	  at java.net.Socket.connect(Socket.java:621)
	  at org.minidns.source.NetworkDataSource.queryTcp(NetworkDataSource.java:116)
	  at org.minidns.source.NetworkDataSource.query(NetworkDataSource.java:76)
	  at org.minidns.source.NetworkDataSource.query(NetworkDataSource.java:34)
	  at org.minidns.AbstractDnsClient.query(AbstractDnsClient.java:250)
	  at org.minidns.AbstractDnsClient.query(AbstractDnsClient.java:360)
	  at org.minidns.DnsClient.query(DnsClient.java:157)
	  at org.minidns.iterative.ReliableDnsClient.query(ReliableDnsClient.java:99)
	  at org.minidns.AbstractDnsClient.query(AbstractDnsClient.java:188)
	  at org.minidns.hla.ResolverApi.resolve(ResolverApi.java:118)
	  at org.minidns.hla.ResolverApi.resolve(ResolverApi.java:114)
	  at org.jivesoftware.smack.util.dns.minidns.MiniDnsResolver.lookupHostAddress0(MiniDnsResolver.java:106)
	  at org.jivesoftware.smack.util.dns.DNSResolver.lookupHostAddress(DNSResolver.java:67)
	  at org.jivesoftware.smack.tcp.rce.RemoteXmppTcpConnectionEndpoints.resolveDomain(RemoteXmppTcpConnectionEndpoints.java:217)
	  at org.jivesoftware.smack.tcp.rce.RemoteXmppTcpConnectionEndpoints.resolveXmppServiceDomain(RemoteXmppTcpConnectionEndpoints.java:144)
	  at org.jivesoftware.smack.tcp.rce.RemoteXmppTcpConnectionEndpoints.lookup(RemoteXmppTcpConnectionEndpoints.java:95)
	  at org.jivesoftware.smack.tcp.XMPPTCPConnection.connectUsingConfiguration(XMPPTCPConnection.java:591)
	  at org.jivesoftware.smack.tcp.XMPPTCPConnection.connectInternal(XMPPTCPConnection.java:849)
	  at org.jivesoftware.smack.AbstractXMPPConnection.connect(AbstractXMPPConnection.java:526)
	  - locked <0x641b> (a org.jivesoftware.smack.tcp.XMPPTCPConnection)
	  at net.java.sip.communicator.impl.protocol.jabber.ProtocolProviderServiceJabberImpl.connectAndLogin(ProtocolProviderServiceJabberImpl.java:1110)
	  at net.java.sip.communicator.impl.protocol.jabber.ProtocolProviderServiceJabberImpl.initializeConnectAndLogin(ProtocolProviderServiceJabberImpl.java:773)
	  - locked <0x641c> (a java.lang.Object)
	  at net.java.sip.communicator.impl.protocol.jabber.ProtocolProviderServiceJabberImpl.register(ProtocolProviderServiceJabberImpl.java:627)
	  at net.java.sip.communicator.util.account.LoginManager$RegisterProvider.run(LoginManager.java:308)

that looks like a DNS lookup could be the cause for the delay. Notably, MiniDNS seems to be performing a DNS lookup with the TCP fallback (org.minidns.source.NetworkDataSource.queryTcp()) and waits for the TCP connection to be established. This could very well be the cause of the delay. If you enable DEBUG log for MiniDNS (de.measite.minidns), then this could get us some more insight.

If it is really the DNS lookup, then caching DNS query results could help (assuming the DNS RR has a reasonable cache value). DNS result caching to persistent storage could also help dramatically in case where the DNS lookup is unreliable and/or causes a long delay.

Below are the captured logcat when working normally, and with the long pause. Looks like the problem
is what you have expected: Fallback to TCP because…

When referring to the source, seems the reason for TCP Fallback is due to “response is truncated”, just wonder if this has to do with android debug tracing.

Look like the query also experiences an IO Exception: org.minidns.AbstractDnsClient.query() IOException {0} on {1} while resolving {2}: {3}.
This causes 4 attempts (4x10s) that leads to the 40 seconds pause.

public StandardDnsQueryResult query(DnsMessage message, InetAddress address, int port) throws IOException {
.....

        if (doUdpFirst) {
            try {
                dnsMessage = queryUdp(message, address, port);
            } catch (IOException e) {
                ioExceptions.add(e);
            }

            // TODO: This null check could probably be removed by now.
            if (dnsMessage != null && !dnsMessage.truncated) {
                return new StandardDnsQueryResult(address, port, QueryMethod.udp, message, dnsMessage);
            }

            assert dnsMessage == null || dnsMessage.truncated || ioExceptions.size() == 1;
            LOGGER.log(Level.FINE, "Fallback to TCP because {0}",
                    new Object[] { dnsMessage != null ? "response is truncated" : ioExceptions.get(0) });
        }
.....
}
========== aTalk logcat when working normally ================    
2022-06-06 14:01:25.262 28807-29691/org.atalk.android I/aTalk: [199] org.jivesoftware.smack.tcp.rce.RemoteXmppTcpConnectionEndpoints.resolveDomain() Could not resolve DNS SRV resource records for _xmpp-client._tcp.atalk.sytes.net. Consider adding those.
2022-06-06 14:01:25.313 28807-29691/org.atalk.android D/aTalk: [199] org.minidns.AbstractDnsClient.query() Asking {0} on {1} for {2} with:
    {3}
2022-06-06 14:01:25.376 28807-29691/org.atalk.android D/aTalk: [199] org.minidns.AbstractDnsClient.query() Response from {0} on {1} for {2}:
    {3}
2022-06-06 14:01:25.433 28807-29691/org.atalk.android D/aTalk: [199] org.minidns.AbstractDnsClient.query() Asking {0} on {1} for {2} with:
    {3}
2022-06-06 14:01:25.823 28807-29691/org.atalk.android D/aTalk: [199] org.minidns.AbstractDnsClient.query() Response from {0} on {1} for {2}:
    {3}
2022-06-06 14:01:25.855 28807-29691/org.atalk.android D/aTalk: [199] org.jivesoftware.smack.tcp.XMPPTCPConnection.connectUsingConfiguration() Trying to establish TCP connection to /42.60.7.13:5222
2022-06-06 14:01:25.893 28807-29691/org.atalk.android D/aTalk: [199] org.jivesoftware.smack.tcp.XMPPTCPConnection.connectUsingConfiguration() Established TCP connection to /42.60.7.13:5222
2022-06-06 14:01:25.942 28807-29700/org.atalk.android D/aTalk: [203] org.jivesoftware.smack.tcp.XMPPTCPConnection.run() Smack Writer (0) start
2022-06-06 14:01:25.959 28807-29701/org.atalk.android D/aTalk: [204] org.jivesoftware.smack.tcp.XMPPTCPConnection.run() Smack Reader (0) start
2022-06-06 14:01:26.017 28807-29700/org.atalk.android D/SMACK: SENT (0): 
    <stream:stream xmlns='jabber:client' to='atalk.sytes.net' xmlns:stream='http://etherx.jabber.org/streams' version='1.0' xml:lang='en'>
2022-06-06 14:01:26.067 28807-29701/org.atalk.android D/SMACK: RECV (0): ?xml version='1.0'?>
    <stream:stream id='16886261299230142126' version='1.0' xml:lang='en' xmlns:stream='http://etherx.jabber.org/streams' from='atalk.sytes.net' xmlns='jabber:client'>
2022-06-06 14:01:26.095 28807-29701/org.atalk.android D/SMACK: RECV (0): 
    <stream:features>
      <starttls xmlns='urn:ietf:params:xml:ns:xmpp-tls'>
        <required/>
      </starttls>
    </stream:features>
    
========== aTalk logcat with long pause ================    
2022-06-07 06:57:36.684 17362-17528/org.atalk.android D/aTalk: [337] org.minidns.source.NetworkDataSource.query() Fallback to TCP because {0}
2022-06-07 06:57:41.695 17362-17528/org.atalk.android D/aTalk: [337] org.minidns.AbstractDnsClient.query() IOException {0} on {1} while resolving {2}: {3}
2022-06-07 06:57:41.696 17362-17528/org.atalk.android D/aTalk: [337] org.minidns.AbstractDnsClient.query() Asking {0} on {1} for {2} with:
    {3}
2022-06-07 06:57:46.706 17362-17528/org.atalk.android D/aTalk: [337] org.minidns.source.NetworkDataSource.query() Fallback to TCP because {0}
2022-06-07 06:57:51.716 17362-17528/org.atalk.android D/aTalk: [337] org.minidns.AbstractDnsClient.query() IOException {0} on {1} while resolving {2}: {3}
2022-06-07 06:57:51.718 17362-17528/org.atalk.android D/aTalk: [337] org.minidns.AbstractDnsClient.query() Asking {0} on {1} for {2} with:
    {3}
2022-06-07 06:57:51.776 17362-17528/org.atalk.android D/aTalk: [337] org.minidns.AbstractDnsClient.query() Response from {0} on {1} for {2}:
    {3}
2022-06-07 06:57:51.778 17362-17528/org.atalk.android I/aTalk: [337] org.jivesoftware.smack.tcp.rce.RemoteXmppTcpConnectionEndpoints.resolveDomain() Could not resolve DNS SRV resource records for _xmpp-client._tcp.atalk.sytes.net. Consider adding those.
2022-06-07 06:57:51.788 17362-17528/org.atalk.android D/aTalk: [337] org.minidns.AbstractDnsClient.query() Asking {0} on {1} for {2} with:
    {3}
2022-06-07 06:57:56.798 17362-17528/org.atalk.android D/aTalk: [337] org.minidns.source.NetworkDataSource.query() Fallback to TCP because {0}
2022-06-07 06:58:01.807 17362-17528/org.atalk.android D/aTalk: [337] org.minidns.AbstractDnsClient.query() IOException {0} on {1} while resolving {2}: {3}
2022-06-07 06:58:01.809 17362-17528/org.atalk.android D/aTalk: [337] org.minidns.AbstractDnsClient.query() Asking {0} on {1} for {2} with:
    {3}
2022-06-07 06:58:06.819 17362-17528/org.atalk.android D/aTalk: [337] org.minidns.source.NetworkDataSource.query() Fallback to TCP because {0}
2022-06-07 06:58:11.828 17362-17528/org.atalk.android D/aTalk: [337] org.minidns.AbstractDnsClient.query() IOException {0} on {1} while resolving {2}: {3}
2022-06-07 06:58:11.831 17362-17528/org.atalk.android D/aTalk: [337] org.minidns.AbstractDnsClient.query() Asking {0} on {1} for {2} with:
    {3}
2022-06-07 06:58:11.849 17362-17528/org.atalk.android D/aTalk: [337] org.minidns.AbstractDnsClient.query() Response from {0} on {1} for {2}:
    {3}
2022-06-07 06:58:11.860 17362-17528/org.atalk.android D/aTalk: [337] org.minidns.AbstractDnsClient.query() Asking {0} on {1} for {2} with:
    {3}
2022-06-07 06:58:16.867 17362-17528/org.atalk.android D/aTalk: [337] org.minidns.source.NetworkDataSource.query() Fallback to TCP because {0}
2022-06-07 06:58:21.875 17362-17528/org.atalk.android D/aTalk: [337] org.minidns.AbstractDnsClient.query() IOException {0} on {1} while resolving {2}: {3}
2022-06-07 06:58:21.877 17362-17528/org.atalk.android D/aTalk: [337] org.minidns.AbstractDnsClient.query() Asking {0} on {1} for {2} with:
    {3}
2022-06-07 06:58:26.886 17362-17528/org.atalk.android D/aTalk: [337] org.minidns.source.NetworkDataSource.query() Fallback to TCP because {0}
2022-06-07 06:58:29.476 975-3710/? D/SGM:GameManager: identifyForegroundApp. org.atalk.android, mCurrentUserId: 0, callerUserId: 0
2022-06-07 06:58:29.476 975-3710/? D/SGM:PkgDataHelper: getGamePkgData(). org.atalk.android
2022-06-07 06:58:31.896 17362-17528/org.atalk.android D/aTalk: [337] org.minidns.AbstractDnsClient.query() IOException {0} on {1} while resolving {2}: {3}
2022-06-07 06:58:31.897 17362-17528/org.atalk.android D/aTalk: [337] org.minidns.AbstractDnsClient.query() Asking {0} on {1} for {2} with:
    {3}
2022-06-07 06:58:31.952 17362-17528/org.atalk.android D/aTalk: [337] org.minidns.AbstractDnsClient.query() Response from {0} on {1} for {2}:
    {3}
2022-06-07 06:58:31.960 17362-17528/org.atalk.android D/aTalk: [337] org.jivesoftware.smack.tcp.XMPPTCPConnection.connectUsingConfiguration() Trying to establish TCP connection to /42.60.7.13:5222
2022-06-07 06:58:31.968 17362-17528/org.atalk.android D/aTalk: [337] org.jivesoftware.smack.tcp.XMPPTCPConnection.connectUsingConfiguration() Established TCP connection to /42.60.7.13:5222
2022-06-07 06:58:31.974 17362-18195/org.atalk.android D/aTalk: [346] org.jivesoftware.smack.tcp.XMPPTCPConnection.run() Smack Reader (0) start
2022-06-07 06:58:31.975 17362-18194/org.atalk.android D/aTalk: [345] org.jivesoftware.smack.tcp.XMPPTCPConnection.run() Smack Writer (0) start
2022-06-07 06:58:31.977 17362-18194/org.atalk.android D/SMACK: SENT (0): 
    <stream:stream xmlns='jabber:client' to='atalk.sytes.net' xmlns:stream='http://etherx.jabber.org/streams' version='1.0' xml:lang='en'>
2022-06-07 06:58:31.983 17362-18195/org.atalk.android D/SMACK: RECV (0): ?xml version='1.0'?>
    <stream:stream id='2331837494664556670' version='1.0' xml:lang='en' xmlns:stream='http://etherx.jabber.org/streams' from='atalk.sytes.net' xmlns='jabber:client'>
2022-06-07 06:58:31.985 17362-18195/org.atalk.android D/SMACK: RECV (0): 
    <stream:features>
      <starttls xmlns='urn:ietf:params:xml:ns:xmpp-tls'>
        <required/>
      </starttls>
    </stream:features>

Below are the actual aTalk logcat messages after making source changes to the two minidns files.

2022-06-07 08:22:37.896 19072-19265/org.atalk.android I/(ProtocolProviderServiceJabberImpl.java:979)#connectAndLogin: Connect using service SRV Resource Record: atalk.sytes.net/42.60.7.13:5222
2022-06-07 08:22:38.074 19072-19258/org.atalk.android W/g.atalk.androi: Long monitor contention with owner Smack DefaultReactor Thread #0 (19256) at int sun.nio.ch.SelectorImpl.lockAndDoSelect(long)(SelectorImpl.java:86) waiters=0 in void org.jivesoftware.smack.SmackReactor$Reactor.handleScheduledActionsOrPerformSelect() for 4.479s
2022-06-07 08:22:38.595 19072-19204/org.atalk.android D/OpenGLRenderer: setSurface called with nullptr
2022-06-07 08:22:38.677 19072-19265/org.atalk.android I/(ProtocolProviderServiceJabberImpl.java:1108)#connectAndLogin: Starting XMPP Connection...: atalk.sytes.net/42.60.7.13:5222
2022-06-07 08:22:38.816 19072-19265/org.atalk.android D/(AbstractDnsClient.java:249)#query: Asking /43.245.107.38 on 53 for _xmpp-client._tcp.atalk.sytes.net.	IN	SRV with:
    DnsMessage(59895 QUERY NO_ERROR query[qr=0] rd)
    [Q: _xmpp-client._tcp.atalk.sytes.net.	IN	SRV]
    [X: EDNS: version: 0, flags:; udp: 1024]
2022-06-07 08:22:43.864 19072-19265/org.atalk.android D/aTalk: [338] org.minidns.source.NetworkDataSource.query() response is truncated
2022-06-07 08:22:48.895 19072-19265/org.atalk.android D/(AbstractDnsClient.java:254)#query: IOException /43.245.107.38 on 53 while resolving _xmpp-client._tcp.atalk.sytes.net.	IN	SRV: Poll timed out, failed to connect to /43.245.107.38 (port 53) from /192.168.1.167 (port 46122) after 5000ms
2022-06-07 08:22:48.902 19072-19265/org.atalk.android D/(AbstractDnsClient.java:249)#query: Asking /43.245.107.5 on 53 for _xmpp-client._tcp.atalk.sytes.net.	IN	SRV with:
    DnsMessage(59895 QUERY NO_ERROR query[qr=0] rd)
    [Q: _xmpp-client._tcp.atalk.sytes.net.	IN	SRV]
    [X: EDNS: version: 0, flags:; udp: 1024]
2022-06-07 08:22:53.946 19072-19265/org.atalk.android D/aTalk: [338] org.minidns.source.NetworkDataSource.query() response is truncated
2022-06-07 08:22:58.971 19072-19265/org.atalk.android D/(AbstractDnsClient.java:254)#query: IOException /43.245.107.5 on 53 while resolving _xmpp-client._tcp.atalk.sytes.net.	IN	SRV: Poll timed out, failed to connect to /43.245.107.5 (port 53) from /192.168.1.167 (port 56878) after 4999ms
2022-06-07 08:22:58.978 19072-19265/org.atalk.android D/(AbstractDnsClient.java:249)#query: Asking /192.168.1.254 on 53 for _xmpp-client._tcp.atalk.sytes.net.	IN	SRV with:
    DnsMessage(59895 QUERY NO_ERROR query[qr=0] rd)
    [Q: _xmpp-client._tcp.atalk.sytes.net.	IN	SRV]
    [X: EDNS: version: 0, flags:; udp: 1024]
2022-06-07 08:22:59.135 19072-19265/org.atalk.android D/(AbstractDnsClient.java:258)#query: Response from /192.168.1.254 on 53 for _xmpp-client._tcp.atalk.sytes.net.	IN	SRV:
    DnsMessage(59895 QUERY NX_DOMAIN resp[qr=1] rd ra)
    [Q: _xmpp-client._tcp.atalk.sytes.net.	IN	SRV]
    [N: sytes.net.	60	IN	SOA	nf1.no-ip.com. hostmaster.no-ip.com. 2094449501 600 300 604800 600]
    [X: EDNS: version: 0, flags:; udp: 4096]
2022-06-07 08:22:59.158 19072-19265/org.atalk.android I/aTalk: [338] org.jivesoftware.smack.tcp.rce.RemoteXmppTcpConnectionEndpoints.resolveDomain() Could not resolve DNS SRV resource records for _xmpp-client._tcp.atalk.sytes.net. Consider adding those.
2022-06-07 08:22:59.227 19072-19265/org.atalk.android D/(AbstractDnsClient.java:249)#query: Asking /43.245.107.38 on 53 for atalk.sytes.net.	IN	A with:
    DnsMessage(1920 QUERY NO_ERROR query[qr=0] rd)
    [Q: atalk.sytes.net.	IN	A]
    [X: EDNS: version: 0, flags:; udp: 1024]
2022-06-07 08:23:04.274 19072-19265/org.atalk.android D/aTalk: [338] org.minidns.source.NetworkDataSource.query() response is truncated
2022-06-07 08:23:09.296 19072-19265/org.atalk.android D/(AbstractDnsClient.java:254)#query: IOException /43.245.107.38 on 53 while resolving atalk.sytes.net.	IN	A: Poll timed out, failed to connect to /43.245.107.38 (port 53) from /192.168.1.167 (port 46128) after 5000ms
2022-06-07 08:23:09.303 19072-19265/org.atalk.android D/(AbstractDnsClient.java:249)#query: Asking /43.245.107.5 on 53 for atalk.sytes.net.	IN	A with:
    DnsMessage(1920 QUERY NO_ERROR query[qr=0] rd)
    [Q: atalk.sytes.net.	IN	A]
    [X: EDNS: version: 0, flags:; udp: 1024]
2022-06-07 08:23:14.346 19072-19265/org.atalk.android D/aTalk: [338] org.minidns.source.NetworkDataSource.query() response is truncated
2022-06-07 08:23:19.371 19072-19265/org.atalk.android D/(AbstractDnsClient.java:254)#query: IOException /43.245.107.5 on 53 while resolving atalk.sytes.net.	IN	A: Poll timed out, failed to connect to /43.245.107.5 (port 53) from /192.168.1.167 (port 56882) after 5000ms
2022-06-07 08:23:19.378 19072-19265/org.atalk.android D/(AbstractDnsClient.java:249)#query: Asking /192.168.1.254 on 53 for atalk.sytes.net.	IN	A with:
    DnsMessage(1920 QUERY NO_ERROR query[qr=0] rd)
    [Q: atalk.sytes.net.	IN	A]
    [X: EDNS: version: 0, flags:; udp: 1024]
2022-06-07 08:23:19.475 19072-19265/org.atalk.android D/(AbstractDnsClient.java:258)#query: Response from /192.168.1.254 on 53 for atalk.sytes.net.	IN	A:
    DnsMessage(1920 QUERY NO_ERROR resp[qr=1] rd ra)
    [Q: atalk.sytes.net.	IN	A]
    [A: atalk.sytes.net.	19	IN	A	42.60.7.13]
    [X: EDNS: version: 0, flags:; udp: 4096]
2022-06-07 08:23:19.548 19072-19265/org.atalk.android D/(AbstractDnsClient.java:249)#query: Asking /43.245.107.38 on 53 for atalk.sytes.net.	IN	AAAA with:
    DnsMessage(10816 QUERY NO_ERROR query[qr=0] rd)
    [Q: atalk.sytes.net.	IN	AAAA]
    [X: EDNS: version: 0, flags:; udp: 1024]
2022-06-07 08:23:24.592 19072-19265/org.atalk.android D/aTalk: [338] org.minidns.source.NetworkDataSource.query() response is truncated
2022-06-07 08:23:29.616 19072-19265/org.atalk.android D/(AbstractDnsClient.java:254)#query: IOException /43.245.107.38 on 53 while resolving atalk.sytes.net.	IN	AAAA: Poll timed out, failed to connect to /43.245.107.38 (port 53) from /192.168.1.167 (port 46132) after 4999ms
2022-06-07 08:23:29.622 19072-19265/org.atalk.android D/(AbstractDnsClient.java:249)#query: Asking /43.245.107.5 on 53 for atalk.sytes.net.	IN	AAAA with:
    DnsMessage(10816 QUERY NO_ERROR query[qr=0] rd)
    [Q: atalk.sytes.net.	IN	AAAA]
    [X: EDNS: version: 0, flags:; udp: 1024]
2022-06-07 08:23:34.666 19072-19265/org.atalk.android D/aTalk: [338] org.minidns.source.NetworkDataSource.query() response is truncated
2022-06-07 08:23:39.692 19072-19265/org.atalk.android D/(AbstractDnsClient.java:254)#query: IOException /43.245.107.5 on 53 while resolving atalk.sytes.net.	IN	AAAA: Poll timed out, failed to connect to /43.245.107.5 (port 53) from /192.168.1.167 (port 56886) after 5000ms
2022-06-07 08:23:39.698 19072-19265/org.atalk.android D/(AbstractDnsClient.java:249)#query: Asking /192.168.1.254 on 53 for atalk.sytes.net.	IN	AAAA with:
    DnsMessage(10816 QUERY NO_ERROR query[qr=0] rd)
    [Q: atalk.sytes.net.	IN	AAAA]
    [X: EDNS: version: 0, flags:; udp: 1024]
2022-06-07 08:23:39.866 19072-19265/org.atalk.android D/(AbstractDnsClient.java:258)#query: Response from /192.168.1.254 on 53 for atalk.sytes.net.	IN	AAAA:
    DnsMessage(10816 QUERY NO_ERROR resp[qr=1] rd ra)
    [Q: atalk.sytes.net.	IN	AAAA]
    [N: sytes.net.	60	IN	SOA	nf1.no-ip.com. hostmaster.no-ip.com. 2094449505 600 300 604800 600]
    [X: EDNS: version: 0, flags:; udp: 4096]
2022-06-07 08:23:39.896 19072-19265/org.atalk.android D/aTalk: [338] org.jivesoftware.smack.tcp.XMPPTCPConnection.connectUsingConfiguration() Trying to establish TCP connection to /42.60.7.13:5222
2022-06-07 08:23:39.933 19072-19265/org.atalk.android D/aTalk: [338] org.jivesoftware.smack.tcp.XMPPTCPConnection.connectUsingConfiguration() Established TCP connection to /42.60.7.13:5222
2022-06-07 08:23:39.974 19072-19343/org.atalk.android D/aTalk: [342] org.jivesoftware.smack.tcp.XMPPTCPConnection.run() Smack Writer (0) start
2022-06-07 08:23:39.993 19072-19344/org.atalk.android D/aTalk: [343] org.jivesoftware.smack.tcp.XMPPTCPConnection.run() Smack Reader (0) start
2022-06-07 08:23:40.055 19072-19343/org.atalk.android D/SMACK: SENT (0): 
    <stream:stream xmlns='jabber:client' to='atalk.sytes.net' xmlns:stream='http://etherx.jabber.org/streams' version='1.0' xml:lang='en'>
2022-06-07 08:23:40.110 19072-19344/org.atalk.android D/SMACK: RECV (0): ?xml version='1.0'?>
    <stream:stream id='967654424423149136' version='1.0' xml:lang='en' xmlns:stream='http://etherx.jabber.org/streams' from='atalk.sytes.net' xmlns='jabber:client'>
2022-06-07 08:23:40.137 19072-19344/org.atalk.android D/SMACK: RECV (0): 
    <stream:features>
      <starttls xmlns='urn:ietf:params:xml:ns:xmpp-tls'>
        <required/>
      </starttls>
    </stream:features>

Below is the full logcat captured in aTalk during initial login, and during an audio call setup which also experiences a long delay when long pause happened during login process.

From the latest logcat, below are my observations:

  1. When working in normal condition, aTalk network access/asking always starts via WiFI i.e. IP address: 192.168.1.254:

2022-06-09 07:48:34.596 23175-23372/org.atalk.android D/(AbstractDnsClient.java:249)#query: Asking /192.168.1.254 on 53 for _xmpp-client._tcp.atalk.sytes.net. IN SRV with:
DnsMessage(12172 QUERY NO_ERROR query[qr=0] rd)
[Q: _xmpp-client._tcp.atalk.sytes.net. IN SRV]
[X: EDNS: version: 0, flags:; udp: 1024]

  1. When the long pause happened, aTalk network access/asking always starts via Mobile network i.e. IP address: 43.245.107.38.

2022-06-09 08:46:33.958 17743-18074/org.atalk.android D/(AbstractDnsClient.java:249)#query: Asking /43.245.107.38 on 53 for _xmpp-client._tcp.atalk.sytes.net. IN SRV with:
DnsMessage(1122 QUERY NO_ERROR query[qr=0] rd)
[Q: _xmpp-client._tcp.atalk.sytes.net. IN SRV]
[X: EDNS: version: 0, flags:; udp: 1024]

  1. The exactly same behaviour happen also during audio call setup; see aTalk logcat below.

  2. If I now switch to mobile only connection, then everything works as expected; i.e. Asking /43.245.107.38

2022-06-09 09:21:34.707 25615-25827/org.atalk.android I/(ProtocolProviderServiceJabberImpl.java:1108)#connectAndLogin: Starting XMPP Connection...: atalk.sytes.net/42.60.7.13:5222
2022-06-09 09:21:34.713 25615-25827/org.atalk.android D/(AbstractDnsClient.java:249)#query: Asking /43.245.107.38 on 53 for _xmpp-client._tcp.atalk.sytes.net.	IN	SRV with:
    DnsMessage(30791 QUERY NO_ERROR query[qr=0] rd)
    [Q: _xmpp-client._tcp.atalk.sytes.net.	IN	SRV]
    [X: EDNS: version: 0, flags:; udp: 1024]
2022-06-09 09:21:34.722 25615-25615/org.atalk.android D/ScrollView: initGoToTop
2022-06-09 09:21:34.737 25615-25827/org.atalk.android D/(AbstractDnsClient.java:258)#query: Response from /43.245.107.38 on 53 for _xmpp-client._tcp.atalk.sytes.net.	IN	SRV:
    DnsMessage(30791 QUERY NX_DOMAIN resp[qr=1] rd ra)
    [Q: _xmpp-client._tcp.atalk.sytes.net.	IN	SRV]
    [N: sytes.net.	5	IN	SOA	nf1.no-ip.com. hostmaster.no-ip.com. 2094467360 600 300 604800 600]
    [X: EDNS: version: 0, flags:; udp: 512]
2022-06-09 09:21:34.738 25615-25827/org.atalk.android I/aTalk: [447] org.jivesoftware.smack.tcp.rce.RemoteXmppTcpConnectionEndpoints.resolveDomain() Could not resolve DNS SRV resource records for _xmpp-client._tcp.atalk.sytes.net. Consider adding those.
  1. Just wonder if the response is read from WIFI instead of mobile network when the weird behaviour happen???

  2. If I now enabled WIFI connection, then thing returns to normal working condition again: i.e. Asking /192.168.1.254

2022-06-09 09:27:51.095 28276-28394/org.atalk.android I/(ProtocolProviderServiceJabberImpl.java:979)#connectAndLogin: Connect using service SRV Resource Record: atalk.sytes.net/42.60.7.13:5222
2022-06-09 09:27:51.117 28276-28394/org.atalk.android I/(ProtocolProviderServiceJabberImpl.java:1108)#connectAndLogin: Starting XMPP Connection...: atalk.sytes.net/42.60.7.13:5222
2022-06-09 09:27:51.126 28276-28394/org.atalk.android D/(AbstractDnsClient.java:249)#query: Asking /192.168.1.254 on 53 for _xmpp-client._tcp.atalk.sytes.net.	IN	SRV with:
    DnsMessage(33093 QUERY NO_ERROR query[qr=0] rd)
    [Q: _xmpp-client._tcp.atalk.sytes.net.	IN	SRV]
    [X: EDNS: version: 0, flags:; udp: 1024]
2022-06-09 09:27:51.177 28276-28394/org.atalk.android D/(AbstractDnsClient.java:258)#query: Response from /192.168.1.254 on 53 for _xmpp-client._tcp.atalk.sytes.net.	IN	SRV:
    DnsMessage(33093 QUERY NX_DOMAIN resp[qr=1] rd ra)
    [Q: _xmpp-client._tcp.atalk.sytes.net.	IN	SRV]
    [N: sytes.net.	44	IN	SOA	nf1.no-ip.com. hostmaster.no-ip.com. 2094467400 600 300 604800 600]
    [X: EDNS: version: 0, flags:; udp: 4096]
2022-06-09 09:27:51.180 28276-28394/org.atalk.android I/aTalk: [446] org.jivesoftware.smack.tcp.rce.RemoteXmppTcpConnectionEndpoints.resolveDomain() Could not resolve DNS SRV resource records for _xmpp-client._tcp.atalk.sytes.net. Consider adding those.
  1. Look like need to figure out why the mobile network is used when the WIFI connection is available.
========== aTalk logcat when working normally ================    
2022-06-09 07:48:34.338 23175-23372/org.atalk.android I/(ProtocolProviderServiceJabberImpl.java:979)#connectAndLogin: Connect using service SRV Resource Record: atalk.sytes.net/42.60.7.13:5222
2022-06-09 07:48:34.569 23175-23372/org.atalk.android I/(ProtocolProviderServiceJabberImpl.java:1108)#connectAndLogin: Starting XMPP Connection...: atalk.sytes.net/42.60.7.13:5222
2022-06-09 07:48:34.596 23175-23372/org.atalk.android D/(AbstractDnsClient.java:249)#query: Asking /192.168.1.254 on 53 for _xmpp-client._tcp.atalk.sytes.net.	IN	SRV with:
    DnsMessage(12172 QUERY NO_ERROR query[qr=0] rd)
    [Q: _xmpp-client._tcp.atalk.sytes.net.	IN	SRV]
    [X: EDNS: version: 0, flags:; udp: 1024]
2022-06-09 07:48:35.177 23175-23372/org.atalk.android D/(AbstractDnsClient.java:258)#query: Response from /192.168.1.254 on 53 for _xmpp-client._tcp.atalk.sytes.net.	IN	SRV:
    DnsMessage(12172 QUERY NX_DOMAIN resp[qr=1] rd ra)
    [Q: _xmpp-client._tcp.atalk.sytes.net.	IN	SRV]
    [N: sytes.net.	60	IN	SOA	nf1.no-ip.com. hostmaster.no-ip.com. 2094466807 600 300 604800 600]
    [X: EDNS: version: 0, flags:; udp: 4096]
2022-06-09 07:48:35.183 23175-23372/org.atalk.android I/aTalk: [435] org.jivesoftware.smack.tcp.rce.RemoteXmppTcpConnectionEndpoints.resolveDomain() Could not resolve DNS SRV resource records for _xmpp-client._tcp.atalk.sytes.net. Consider adding those.
2022-06-09 07:48:35.193 23175-23372/org.atalk.android D/(AbstractDnsClient.java:249)#query: Asking /192.168.1.254 on 53 for atalk.sytes.net.	IN	A with:
    DnsMessage(50090 QUERY NO_ERROR query[qr=0] rd)
    [Q: atalk.sytes.net.	IN	A]
    [X: EDNS: version: 0, flags:; udp: 1024]
2022-06-09 07:48:35.207 23175-23372/org.atalk.android D/(AbstractDnsClient.java:258)#query: Response from /192.168.1.254 on 53 for atalk.sytes.net.	IN	A:
    DnsMessage(50090 QUERY NO_ERROR resp[qr=1] rd ra)
    [Q: atalk.sytes.net.	IN	A]
    [A: atalk.sytes.net.	60	IN	A	42.60.7.13]
    [X: EDNS: version: 0, flags:; udp: 4096]
2022-06-09 07:48:35.219 23175-23372/org.atalk.android D/(AbstractDnsClient.java:249)#query: Asking /192.168.1.254 on 53 for atalk.sytes.net.	IN	AAAA with:
    DnsMessage(28974 QUERY NO_ERROR query[qr=0] rd)
    [Q: atalk.sytes.net.	IN	AAAA]
    [X: EDNS: version: 0, flags:; udp: 1024]
2022-06-09 07:48:35.585 23175-23372/org.atalk.android D/(AbstractDnsClient.java:258)#query: Response from /192.168.1.254 on 53 for atalk.sytes.net.	IN	AAAA:
    DnsMessage(28974 QUERY NO_ERROR resp[qr=1] rd ra)
    [Q: atalk.sytes.net.	IN	AAAA]
    [N: sytes.net.	60	IN	SOA	nf1.no-ip.com. hostmaster.no-ip.com. 2094466807 600 300 604800 600]
    [X: EDNS: version: 0, flags:; udp: 4096]
2022-06-09 07:48:35.592 23175-23372/org.atalk.android D/aTalk: [435] org.jivesoftware.smack.tcp.XMPPTCPConnection.connectUsingConfiguration() Trying to establish TCP connection to /42.60.7.13:5222
2022-06-09 07:48:35.607 23175-23372/org.atalk.android D/aTalk: [435] org.jivesoftware.smack.tcp.XMPPTCPConnection.connectUsingConfiguration() Established TCP connection to /42.60.7.13:5222
2022-06-09 07:48:35.618 23175-23379/org.atalk.android D/aTalk: [438] org.jivesoftware.smack.tcp.XMPPTCPConnection.run() Smack Writer (0) start
2022-06-09 07:48:35.628 23175-23380/org.atalk.android D/aTalk: [439] org.jivesoftware.smack.tcp.XMPPTCPConnection.run() Smack Reader (0) start
2022-06-09 07:48:35.646 23175-23379/org.atalk.android D/SMACK: SENT (0): 
    <stream:stream xmlns='jabber:client' to='atalk.sytes.net' xmlns:stream='http://etherx.jabber.org/streams' version='1.0' xml:lang='en'>
2022-06-09 07:48:35.682 23175-23380/org.atalk.android D/SMACK: RECV (0): ?xml version='1.0'?>
    <stream:stream id='8428392121631531592' version='1.0' xml:lang='en' xmlns:stream='http://etherx.jabber.org/streams' from='atalk.sytes.net' xmlns='jabber:client'>
    <stream:features>
      <starttls xmlns='urn:ietf:params:xml:ns:xmpp-tls'>
        <required/>
      </starttls>
    </stream:features>
    

===> logcat during audio call - normal
2022-06-09 08:01:08.207 24125-24626/org.atalk.android D/(JingleMessageSessionImpl.java:178)#onJingleMessageProceed: Jingle Message proceed received
2022-06-09 08:01:08.225 24125-24628/org.atalk.android I/(OperationSetBasicTelephonyJabberImpl.java:333)#createOutgoingCall: Creating outgoing call to peacock@atalk.sytes.net/atalk
2022-06-09 08:01:08.440 24125-24628/org.atalk.android D/(AbstractDnsClient.java:249)#query: Asking /192.168.1.254 on 53 for _xmpp-client._tcp.atalk.sytes.net.	IN	SRV with:
    DnsMessage(16967 QUERY NO_ERROR query[qr=0] rd)
    [Q: _xmpp-client._tcp.atalk.sytes.net.	IN	SRV]
    [X: EDNS: version: 0, flags:; udp: 1024]
2022-06-09 08:01:08.501 24125-24628/org.atalk.android D/(AbstractDnsClient.java:258)#query: Response from /192.168.1.254 on 53 for _xmpp-client._tcp.atalk.sytes.net.	IN	SRV:
    DnsMessage(16967 QUERY NX_DOMAIN resp[qr=1] rd ra)
    [Q: _xmpp-client._tcp.atalk.sytes.net.	IN	SRV]
    [N: sytes.net.	60	IN	SOA	nf1.no-ip.com. hostmaster.no-ip.com. 2094466882 600 300 604800 600]
    [X: EDNS: version: 0, flags:; udp: 4096]
2022-06-09 08:01:09.067 24125-24628/org.atalk.android I/aTalk: [472] org.ice4j.ice.harvest.MappingCandidateHarvesters.initialize() Initialized mapping harvesters (delay=508ms).  Harvesters size=0 stunDiscoveryFailed=false
2022-06-09 08:01:09.076 24125-24628/org.atalk.android D/(AbstractDnsClient.java:249)#query: Asking /192.168.1.254 on 53 for _turn._udp.atalk.sytes.net.	IN	SRV with:
    DnsMessage(17819 QUERY NO_ERROR query[qr=0] rd)
    [Q: _turn._udp.atalk.sytes.net.	IN	SRV]
    [X: EDNS: version: 0, flags:; udp: 1024]    
2022-06-09 08:01:09.522 24125-24628/org.atalk.android D/(AbstractDnsClient.java:258)#query: Response from /192.168.1.254 on 53 for _turn._udp.atalk.sytes.net.	IN	SRV:
    DnsMessage(17819 QUERY NX_DOMAIN resp[qr=1] rd ra)
    [Q: _turn._udp.atalk.sytes.net.	IN	SRV]
    [N: sytes.net.	60	IN	SOA	nf1.no-ip.com. hostmaster.no-ip.com. 2094466882 600 300 604800 600]
    [X: EDNS: version: 0, flags:; udp: 4096]
2022-06-09 08:01:09.538 24125-24628/org.atalk.android D/(AbstractDnsClient.java:249)#query: Asking /192.168.1.254 on 53 for _stun._udp.atalk.sytes.net.	IN	SRV with:
    DnsMessage(15891 QUERY NO_ERROR query[qr=0] rd)
    [Q: _stun._udp.atalk.sytes.net.	IN	SRV]
    [X: EDNS: version: 0, flags:; udp: 1024]
2022-06-09 08:01:09.647 24125-24628/org.atalk.android D/(AbstractDnsClient.java:258)#query: Response from /192.168.1.254 on 53 for _stun._udp.atalk.sytes.net.	IN	SRV:
    DnsMessage(15891 QUERY NX_DOMAIN resp[qr=1] rd ra)
    [Q: _stun._udp.atalk.sytes.net.	IN	SRV]
    [N: sytes.net.	60	IN	SOA	nf1.no-ip.com. hostmaster.no-ip.com. 2094466882 600 300 604800 600]
    [X: EDNS: version: 0, flags:; udp: 4096]
2022-06-09 08:01:09.648 24125-24628/org.atalk.android I/(IceUdpTransportManager.java:235)#createIceAgent: Auto discovered STUN/TURN-server harvester is null
2022-06-09 08:01:09.720 24125-24628/org.atalk.android I/(IceUdpTransportManager.java:322)#createIceAgent: End gathering harvesters within 1173 ms; size: 3; Harvesters:
    [STUN harvester(srvr: 172.217.213.127:19302/udp), net.java.sip.communicator.impl.protocol.jabber.JingleNodesHarvester@88a7cf4, UPNPHarvester]
2022-06-09 08:01:09.741 24125-24628/org.atalk.android D/(IceUdpTransportManager.java:742)#createIceStream: Created Ice stream agent for audio


========== aTalk logcat with long pause ================    
2022-06-09 08:46:32.821 17743-18074/org.atalk.android I/(ProtocolProviderServiceJabberImpl.java:979)#connectAndLogin: Connect using service SRV Resource Record: atalk.sytes.net/42.60.7.13:5222
2022-06-09 08:46:33.788 17743-18074/org.atalk.android I/(ProtocolProviderServiceJabberImpl.java:1108)#connectAndLogin: Starting XMPP Connection...: atalk.sytes.net/42.60.7.13:5222
2022-06-09 08:46:33.958 17743-18074/org.atalk.android D/(AbstractDnsClient.java:249)#query: Asking /43.245.107.38 on 53 for _xmpp-client._tcp.atalk.sytes.net.	IN	SRV with:
    DnsMessage(1122 QUERY NO_ERROR query[qr=0] rd)
    [Q: _xmpp-client._tcp.atalk.sytes.net.	IN	SRV]
    [X: EDNS: version: 0, flags:; udp: 1024]
2022-06-09 08:46:43.998 17743-18074/org.atalk.android D/(AbstractDnsClient.java:254)#query: IOException /43.245.107.38 on 53 while resolving _xmpp-client._tcp.atalk.sytes.net.	IN	SRV: Poll timed out, failed to connect to /43.245.107.38 (port 53) from /192.168.1.167 (port 53526) after 5000ms
2022-06-09 08:46:44.004 17743-18074/org.atalk.android D/(AbstractDnsClient.java:249)#query: Asking /43.245.107.5 on 53 for _xmpp-client._tcp.atalk.sytes.net.	IN	SRV with:
    DnsMessage(1122 QUERY NO_ERROR query[qr=0] rd)
    [Q: _xmpp-client._tcp.atalk.sytes.net.	IN	SRV]
    [X: EDNS: version: 0, flags:; udp: 1024]
2022-06-09 08:46:49.019 17743-18074/org.atalk.android D/(NetworkDataSource.java:75)#query: Fallback to TCP because Poll timed out
2022-06-09 08:46:54.035 17743-18074/org.atalk.android D/(AbstractDnsClient.java:254)#query: IOException /43.245.107.5 on 53 while resolving _xmpp-client._tcp.atalk.sytes.net.	IN	SRV: Poll timed out, failed to connect to /43.245.107.5 (port 53) from /192.168.1.167 (port 36060) after 5000ms
2022-06-09 08:46:54.039 17743-18074/org.atalk.android D/(AbstractDnsClient.java:249)#query: Asking /192.168.1.254 on 53 for _xmpp-client._tcp.atalk.sytes.net.	IN	SRV with:
    DnsMessage(1122 QUERY NO_ERROR query[qr=0] rd)
    [Q: _xmpp-client._tcp.atalk.sytes.net.	IN	SRV]
    [X: EDNS: version: 0, flags:; udp: 1024]
2022-06-09 08:46:54.470 17743-18074/org.atalk.android D/(AbstractDnsClient.java:258)#query: Response from /192.168.1.254 on 53 for _xmpp-client._tcp.atalk.sytes.net.	IN	SRV:
    DnsMessage(1122 QUERY NX_DOMAIN resp[qr=1] rd ra)
    [Q: _xmpp-client._tcp.atalk.sytes.net.	IN	SRV]
    [N: sytes.net.	60	IN	SOA	nf1.no-ip.com. hostmaster.no-ip.com. 2094467157 600 300 604800 600]
    [X: EDNS: version: 0, flags:; udp: 4096]
2022-06-09 08:46:54.481 17743-18074/org.atalk.android I/aTalk: [455] org.jivesoftware.smack.tcp.rce.RemoteXmppTcpConnectionEndpoints.resolveDomain() Could not resolve DNS SRV resource records for _xmpp-client._tcp.atalk.sytes.net. Consider adding those.
2022-06-09 08:46:54.511 17743-18074/org.atalk.android D/(AbstractDnsClient.java:249)#query: Asking /43.245.107.38 on 53 for atalk.sytes.net.	IN	A with:
    DnsMessage(17233 QUERY NO_ERROR query[qr=0] rd)
    [Q: atalk.sytes.net.	IN	A]
    [X: EDNS: version: 0, flags:; udp: 1024]
2022-06-09 08:46:59.520 17743-18074/org.atalk.android D/(NetworkDataSource.java:75)#query: Fallback to TCP because Poll timed out
2022-06-09 08:47:04.527 17743-18074/org.atalk.android D/(AbstractDnsClient.java:254)#query: IOException /43.245.107.38 on 53 while resolving atalk.sytes.net.	IN	A: Poll timed out, failed to connect to /43.245.107.38 (port 53) from /192.168.1.167 (port 53544) after 5000ms
2022-06-09 08:47:04.529 17743-18074/org.atalk.android D/(AbstractDnsClient.java:249)#query: Asking /43.245.107.5 on 53 for atalk.sytes.net.	IN	A with:
    DnsMessage(17233 QUERY NO_ERROR query[qr=0] rd)
    [Q: atalk.sytes.net.	IN	A]
    [X: EDNS: version: 0, flags:; udp: 1024]
2022-06-09 08:47:09.538 17743-18074/org.atalk.android D/(NetworkDataSource.java:75)#query: Fallback to TCP because Poll timed out
2022-06-09 08:47:14.544 17743-18074/org.atalk.android D/(AbstractDnsClient.java:254)#query: IOException /43.245.107.5 on 53 while resolving atalk.sytes.net.	IN	A: Poll timed out, failed to connect to /43.245.107.5 (port 53) from /192.168.1.167 (port 36066) after 5000ms
2022-06-09 08:47:14.545 17743-18074/org.atalk.android D/(AbstractDnsClient.java:249)#query: Asking /192.168.1.254 on 53 for atalk.sytes.net.	IN	A with:
    DnsMessage(17233 QUERY NO_ERROR query[qr=0] rd)
    [Q: atalk.sytes.net.	IN	A]
    [X: EDNS: version: 0, flags:; udp: 1024]
2022-06-09 08:47:14.568 17743-18074/org.atalk.android D/(AbstractDnsClient.java:258)#query: Response from /192.168.1.254 on 53 for atalk.sytes.net.	IN	A:
    DnsMessage(17233 QUERY NO_ERROR resp[qr=1] rd ra)
    [Q: atalk.sytes.net.	IN	A]
    [A: atalk.sytes.net.	19	IN	A	42.60.7.13]
    [X: EDNS: version: 0, flags:; udp: 4096]
2022-06-09 08:47:14.600 17743-18074/org.atalk.android D/(AbstractDnsClient.java:249)#query: Asking /43.245.107.38 on 53 for atalk.sytes.net.	IN	AAAA with:
    DnsMessage(10939 QUERY NO_ERROR query[qr=0] rd)
    [Q: atalk.sytes.net.	IN	AAAA]
    [X: EDNS: version: 0, flags:; udp: 1024]
2022-06-09 08:47:19.609 17743-18074/org.atalk.android D/(NetworkDataSource.java:75)#query: Fallback to TCP because Poll timed out
2022-06-09 08:47:24.618 17743-18074/org.atalk.android D/(AbstractDnsClient.java:254)#query: IOException /43.245.107.38 on 53 while resolving atalk.sytes.net.	IN	AAAA: Poll timed out, failed to connect to /43.245.107.38 (port 53) from /192.168.1.167 (port 53548) after 5000ms
2022-06-09 08:47:24.620 17743-18074/org.atalk.android D/(AbstractDnsClient.java:249)#query: Asking /43.245.107.5 on 53 for atalk.sytes.net.	IN	AAAA with:
    DnsMessage(10939 QUERY NO_ERROR query[qr=0] rd)
    [Q: atalk.sytes.net.	IN	AAAA]
    [X: EDNS: version: 0, flags:; udp: 1024]
2022-06-09 08:47:29.634 17743-18074/org.atalk.android D/(NetworkDataSource.java:75)#query: Fallback to TCP because Poll timed out
2022-06-09 08:47:34.645 17743-18074/org.atalk.android D/(AbstractDnsClient.java:254)#query: IOException /43.245.107.5 on 53 while resolving atalk.sytes.net.	IN	AAAA: Poll timed out, failed to connect to /43.245.107.5 (port 53) from /192.168.1.167 (port 36076) after 5000ms
2022-06-09 08:47:34.647 17743-18074/org.atalk.android D/(AbstractDnsClient.java:249)#query: Asking /192.168.1.254 on 53 for atalk.sytes.net.	IN	AAAA with:
    DnsMessage(10939 QUERY NO_ERROR query[qr=0] rd)
    [Q: atalk.sytes.net.	IN	AAAA]
    [X: EDNS: version: 0, flags:; udp: 1024]
2022-06-09 08:47:34.727 17743-18074/org.atalk.android D/(AbstractDnsClient.java:258)#query: Response from /192.168.1.254 on 53 for atalk.sytes.net.	IN	AAAA:
    DnsMessage(10939 QUERY NO_ERROR resp[qr=1] rd ra)
    [Q: atalk.sytes.net.	IN	AAAA]
    [N: sytes.net.	60	IN	SOA	nf1.no-ip.com. hostmaster.no-ip.com. 2094467161 600 300 604800 600]
    [X: EDNS: version: 0, flags:; udp: 4096]
2022-06-09 08:47:34.742 17743-18074/org.atalk.android D/aTalk: [455] org.jivesoftware.smack.tcp.XMPPTCPConnection.connectUsingConfiguration() Trying to establish TCP connection to /42.60.7.13:5222
2022-06-09 08:47:34.763 17743-18074/org.atalk.android D/aTalk: [455] org.jivesoftware.smack.tcp.XMPPTCPConnection.connectUsingConfiguration() Established TCP connection to /42.60.7.13:5222
2022-06-09 08:47:34.785 17743-18874/org.atalk.android D/aTalk: [461] org.jivesoftware.smack.tcp.XMPPTCPConnection.run() Smack Writer (0) start
2022-06-09 08:47:34.794 17743-18875/org.atalk.android D/aTalk: [462] org.jivesoftware.smack.tcp.XMPPTCPConnection.run() Smack Reader (0) start
2022-06-09 08:47:34.825 17743-18874/org.atalk.android D/SMACK: SENT (0): 
    <stream:stream xmlns='jabber:client' to='atalk.sytes.net' xmlns:stream='http://etherx.jabber.org/streams' version='1.0' xml:lang='en'>
2022-06-09 08:47:34.856 17743-18875/org.atalk.android D/SMACK: RECV (0): ?xml version='1.0'?>
    <stream:stream id='17618267950648697565' version='1.0' xml:lang='en' xmlns:stream='http://etherx.jabber.org/streams' from='atalk.sytes.net' xmlns='jabber:client'>
    <stream:features>
      <starttls xmlns='urn:ietf:params:xml:ns:xmpp-tls'>
        <required/>
      </starttls>
    </stream:features>
===> logcat during audio call - long pause
2022-06-09 08:57:42.383 17743-19916/org.atalk.android D/(JingleMessageSessionImpl.java:178)#onJingleMessageProceed: Jingle Message proceed received
2022-06-09 08:57:42.539 17743-20099/org.atalk.android D/(AbstractDnsClient.java:249)#query: Asking /43.245.107.38 on 53 for _xmpp-client._tcp.atalk.sytes.net.	IN	SRV with:
    DnsMessage(38510 QUERY NO_ERROR query[qr=0] rd)
    [Q: _xmpp-client._tcp.atalk.sytes.net.	IN	SRV]
    [X: EDNS: version: 0, flags:; udp: 1024]
2022-06-09 08:57:47.551 17743-20099/org.atalk.android D/(NetworkDataSource.java:75)#query: Fallback to TCP because Poll timed out
2022-06-09 08:57:52.562 17743-20099/org.atalk.android D/(AbstractDnsClient.java:254)#query: IOException /43.245.107.38 on 53 while resolving _xmpp-client._tcp.atalk.sytes.net.	IN	SRV: Poll timed out, failed to connect to /43.245.107.38 (port 53) from /192.168.1.167 (port 53612) after 5000ms
2022-06-09 08:57:52.563 17743-20099/org.atalk.android D/(AbstractDnsClient.java:249)#query: Asking /43.245.107.5 on 53 for _xmpp-client._tcp.atalk.sytes.net.	IN	SRV with:
    DnsMessage(38510 QUERY NO_ERROR query[qr=0] rd)
    [Q: _xmpp-client._tcp.atalk.sytes.net.	IN	SRV]
    [X: EDNS: version: 0, flags:; udp: 1024]
2022-06-09 08:57:57.574 17743-20099/org.atalk.android D/(NetworkDataSource.java:75)#query: Fallback to TCP because Poll timed out
2022-06-09 08:58:02.581 17743-20099/org.atalk.android D/(AbstractDnsClient.java:254)#query: IOException /43.245.107.5 on 53 while resolving _xmpp-client._tcp.atalk.sytes.net.	IN	SRV: Poll timed out, failed to connect to /43.245.107.5 (port 53) from /192.168.1.167 (port 36138) after 5000ms
2022-06-09 08:58:02.582 17743-20099/org.atalk.android D/(AbstractDnsClient.java:249)#query: Asking /192.168.1.254 on 53 for _xmpp-client._tcp.atalk.sytes.net.	IN	SRV with:
    DnsMessage(38510 QUERY NO_ERROR query[qr=0] rd)
    [Q: _xmpp-client._tcp.atalk.sytes.net.	IN	SRV]
    [X: EDNS: version: 0, flags:; udp: 1024]
2022-06-09 08:58:03.123 17743-20099/org.atalk.android D/(AbstractDnsClient.java:258)#query: Response from /192.168.1.254 on 53 for _xmpp-client._tcp.atalk.sytes.net.	IN	SRV:
    DnsMessage(38510 QUERY NX_DOMAIN resp[qr=1] rd ra)
    [Q: _xmpp-client._tcp.atalk.sytes.net.	IN	SRV]
    [N: sytes.net.	60	IN	SOA	nf1.no-ip.com. hostmaster.no-ip.com. 2094467224 600 300 604800 600]
    [X: EDNS: version: 0, flags:; udp: 4096]
2022-06-09 08:58:03.900 17743-20099/org.atalk.android I/aTalk: [502] org.ice4j.ice.harvest.MappingCandidateHarvesters.initialize() Initialized mapping harvesters (delay=567ms).  Harvesters size=0 stunDiscoveryFailed=false
2022-06-09 08:58:03.938 17743-20099/org.atalk.android D/(AbstractDnsClient.java:249)#query: Asking /43.245.107.38 on 53 for _turn._udp.atalk.sytes.net.	IN	SRV with:
    DnsMessage(26700 QUERY NO_ERROR query[qr=0] rd)
    [Q: _turn._udp.atalk.sytes.net.	IN	SRV]
    [X: EDNS: version: 0, flags:; udp: 1024]
2022-06-09 08:58:08.948 17743-20099/org.atalk.android D/(NetworkDataSource.java:75)#query: Fallback to TCP because Poll timed out
2022-06-09 08:58:13.961 17743-20099/org.atalk.android D/(AbstractDnsClient.java:254)#query: IOException /43.245.107.38 on 53 while resolving _turn._udp.atalk.sytes.net.	IN	SRV: Poll timed out, failed to connect to /43.245.107.38 (port 53) from /192.168.1.167 (port 53622) after 5000ms
2022-06-09 08:58:13.962 17743-20099/org.atalk.android D/(AbstractDnsClient.java:249)#query: Asking /43.245.107.5 on 53 for _turn._udp.atalk.sytes.net.	IN	SRV with:
    DnsMessage(26700 QUERY NO_ERROR query[qr=0] rd)
    [Q: _turn._udp.atalk.sytes.net.	IN	SRV]
    [X: EDNS: version: 0, flags:; udp: 1024]
2022-06-09 08:58:18.973 17743-20099/org.atalk.android D/(NetworkDataSource.java:75)#query: Fallback to TCP because Poll timed out
2022-06-09 08:58:23.985 17743-20099/org.atalk.android D/(AbstractDnsClient.java:254)#query: IOException /43.245.107.5 on 53 while resolving _turn._udp.atalk.sytes.net.	IN	SRV: Poll timed out, failed to connect to /43.245.107.5 (port 53) from /192.168.1.167 (port 36144) after 5000ms
2022-06-09 08:58:23.986 17743-20099/org.atalk.android D/(AbstractDnsClient.java:249)#query: Asking /192.168.1.254 on 53 for _turn._udp.atalk.sytes.net.	IN	SRV with:
    DnsMessage(26700 QUERY NO_ERROR query[qr=0] rd)
    [Q: _turn._udp.atalk.sytes.net.	IN	SRV]
    [X: EDNS: version: 0, flags:; udp: 1024]
2022-06-09 08:58:24.321 17743-20099/org.atalk.android D/(AbstractDnsClient.java:258)#query: Response from /192.168.1.254 on 53 for _turn._udp.atalk.sytes.net.	IN	SRV:
    DnsMessage(26700 QUERY NX_DOMAIN resp[qr=1] rd ra)
    [Q: _turn._udp.atalk.sytes.net.	IN	SRV]
    [N: sytes.net.	60	IN	SOA	nf1.no-ip.com. hostmaster.no-ip.com. 2094467226 600 300 604800 600]
    [X: EDNS: version: 0, flags:; udp: 4096]
2022-06-09 08:58:24.358 17743-20099/org.atalk.android D/(AbstractDnsClient.java:249)#query: Asking /43.245.107.38 on 53 for _stun._udp.atalk.sytes.net.	IN	SRV with:
    DnsMessage(61130 QUERY NO_ERROR query[qr=0] rd)
    [Q: _stun._udp.atalk.sytes.net.	IN	SRV]
    [X: EDNS: version: 0, flags:; udp: 1024]
2022-06-09 08:58:29.367 17743-20099/org.atalk.android D/(NetworkDataSource.java:75)#query: Fallback to TCP because Poll timed out
2022-06-09 08:58:34.378 17743-20099/org.atalk.android D/(AbstractDnsClient.java:254)#query: IOException /43.245.107.38 on 53 while resolving _stun._udp.atalk.sytes.net.	IN	SRV: Poll timed out, failed to connect to /43.245.107.38 (port 53) from /192.168.1.167 (port 53628) after 5000ms
2022-06-09 08:58:34.379 17743-20099/org.atalk.android D/(AbstractDnsClient.java:249)#query: Asking /43.245.107.5 on 53 for _stun._udp.atalk.sytes.net.	IN	SRV with:
    DnsMessage(61130 QUERY NO_ERROR query[qr=0] rd)
    [Q: _stun._udp.atalk.sytes.net.	IN	SRV]
    [X: EDNS: version: 0, flags:; udp: 1024]
2022-06-09 08:58:39.392 17743-20099/org.atalk.android D/(NetworkDataSource.java:75)#query: Fallback to TCP because Poll timed out
2022-06-09 08:58:44.405 17743-20099/org.atalk.android D/(AbstractDnsClient.java:254)#query: IOException /43.245.107.5 on 53 while resolving _stun._udp.atalk.sytes.net.	IN	SRV: Poll timed out, failed to connect to /43.245.107.5 (port 53) from /192.168.1.167 (port 36152) after 5000ms
2022-06-09 08:58:44.406 17743-20099/org.atalk.android D/(AbstractDnsClient.java:249)#query: Asking /192.168.1.254 on 53 for _stun._udp.atalk.sytes.net.	IN	SRV with:
    DnsMessage(61130 QUERY NO_ERROR query[qr=0] rd)
    [Q: _stun._udp.atalk.sytes.net.	IN	SRV]
    [X: EDNS: version: 0, flags:; udp: 1024]
2022-06-09 08:58:44.488 17743-20099/org.atalk.android D/(AbstractDnsClient.java:258)#query: Response from /192.168.1.254 on 53 for _stun._udp.atalk.sytes.net.	IN	SRV:
    DnsMessage(61130 QUERY NX_DOMAIN resp[qr=1] rd ra)
    [Q: _stun._udp.atalk.sytes.net.	IN	SRV]
    [N: sytes.net.	60	IN	SOA	nf1.no-ip.com. hostmaster.no-ip.com. 2094467228 600 300 604800 600]
    [X: EDNS: version: 0, flags:; udp: 4096]
2022-06-09 08:58:44.489 17743-20099/org.atalk.android I/(IceUdpTransportManager.java:235)#createIceAgent: Auto discovered STUN/TURN-server harvester is null
2022-06-09 08:58:44.548 17743-20099/org.atalk.android I/(IceUdpTransportManager.java:322)#createIceAgent: End gathering harvesters within 41283 ms; size: 3; Harvesters:
    [STUN harvester(srvr: 172.217.213.127:19302/udp), net.java.sip.communicator.impl.protocol.jabber.JingleNodesHarvester@8b24073, UPNPHarvester]
2022-06-09 08:58:44.604 17743-20099/org.atalk.android D/(IceUdpTransportManager.java:742)#createIceStream: Created Ice stream agent for audio

The use of the server InetAddress for enquiry is based on dns Server Addresses return via InetAddress.getByName(dnsServerString) in findDnsAddresses() method. I have included a log statement to capture what is actually returned in dnsServerAddresses.

   @Override
    public DnsQueryResult query(DnsMessage.Builder queryBuilder) throws IOException {
....
        List<InetAddress> dnsServerAddresses = getServerAddresses();
        Timber.d("dns Server Addresses: %s", dnsServerAddresses);
....
}

Below are the logcat messages under different network settings. Found that the returned result may at time varies from the expected result.

Wifi and Mobile network (normal)
2022-06-09 11:22:14.118 28758-29633/org.atalk.android D/(DnsClient.java:150)#query: dns Server Addresses: [/192.168.1.254, /43.245.107.38, /43.245.107.5, /2401:7400:8888:42::6, /2401:7400:8888:41::37, /8.8.8.8, /2001:4860:4860::8888]
==> mobile address is not returned at time
2022-06-09 12:14:48.889 12842-13355/org.atalk.android D/(DnsClient.java:150)#query: dns Server Addresses: [/192.168.1.254, /8.8.8.8, /2001:4860:4860::8888]

Mobile network (normal)
2022-06-09 12:14:48.889 12842-13355/org.atalk.android D/(DnsClient.java:150)#query: dns Server Addresses: [/192.168.1.254, /8.8.8.8, /2001:4860:4860::8888]

In the case of long pause problem, found that the mobile IP’s have a higher priorities than the WiFi; but the mobile address used for query seems not working from the captured result, but the WiFi address is still working.

It seems that the long pause problem is contributed by android network manager.
Not sure how to proceed from here to verify this assumption. Any advice?

Wifi and Mobile network (long pause)
2022-06-10 07:11:46.900 31745-31966/org.atalk.android D/(DnsClient.java:150)#query: dns Server Addresses: [/43.245.107.38, /43.245.107.5, /192.168.1.254, /2401:7400:8888:42::6, /2401:7400:8888:41::37, /8.8.8.8, /2001:4860:4860::8888]

FYI:
During aTalk v2.9.1 (03/16/2022) release, a wired behaviour is found with Note-10 in mobile network as captured the aTalk history log when InetAddress.getByName(dnsServerString) is used for enquiry.
But seems this problem is fixed? after the latest update, based on the latest logcat herewith.
But Not sure if making this change to DnsClient.java will help avoid the observed problem.

- Upgrade ice4j to use org.jitsi:ice4j:3.0-55-g32a8aad with aTalk customization
- Android with network APN=IPv4/IPv6 or APN=IPv6 returns only IPv6 public address in InetAddress.getByName(host);
  hence only an IPv6 candidate (without the sfllx candidate) is sent i.e.
  i.e. IPv6 candidate harvested from ice4j HostCandidateHarvester#harvest(); causing problem in call setup;
  <candidate port='58979' type='host' ip='2401:7400:4000:2e4a:1:2:93f1:b634' id='e49ea0a0-87e9-46a1-9c2e-1666b6ce8e32'/>
  missing: <candidate ... ip='119.56.100.180' port='5002' type='srflx' rel-addr='10.143.27.57' rel-port='5002' network='0'/>
  Problem fixed with IceUdpTransportManager#getTransportAddress(String hostname, int port, Transport transport)
  see https://github.com/jitsi/ice4j/issues/255 for detail problem and solution.
  For android network APN setting see: https://sanctum9.wordpress.com/2019/03/15/switch-to-ipv6-on-android/
//============= Wifi and Mobile network (normal) ================/
2022-06-09 11:22:14.049 28758-29633/org.atalk.android I/(ProtocolProviderServiceJabberImpl.java:1108)#connectAndLogin: Starting XMPP Connection...: atalk.sytes.net/42.60.7.13:5222
2022-06-09 11:22:14.118 28758-29633/org.atalk.android D/(DnsClient.java:150)#query: dns Server Addresses: [/192.168.1.254, /43.245.107.38, /43.245.107.5, /2401:7400:8888:42::6, /2401:7400:8888:41::37, /8.8.8.8, /2001:4860:4860::8888]
2022-06-09 11:22:14.121 28758-29633/org.atalk.android D/(AbstractDnsClient.java:249)#query: Asking /192.168.1.254 on 53 for _xmpp-client._tcp.atalk.sytes.net.	IN	SRV with:
    DnsMessage(64167 QUERY NO_ERROR query[qr=0] rd)
    [Q: _xmpp-client._tcp.atalk.sytes.net.	IN	SRV]
    [X: EDNS: version: 0, flags:; udp: 1024]
2022-06-09 11:22:14.297 28758-29633/org.atalk.android D/(AbstractDnsClient.java:258)#query: Response from /192.168.1.254 on 53 for _xmpp-client._tcp.atalk.sytes.net.	IN	SRV:
    DnsMessage(64167 QUERY NX_DOMAIN resp[qr=1] rd ra)
    [Q: _xmpp-client._tcp.atalk.sytes.net.	IN	SRV]
    [N: sytes.net.	60	IN	SOA	nf1.no-ip.com. hostmaster.no-ip.com. 2094468093 600 300 604800 600]
    [X: EDNS: version: 0, flags:; udp: 4096]


2022-06-09 12:14:48.836 12842-13355/org.atalk.android I/(ProtocolProviderServiceJabberImpl.java:1108)#connectAndLogin: Starting XMPP Connection...: atalk.sytes.net/42.60.7.13:5222
2022-06-09 12:14:48.889 12842-13355/org.atalk.android D/(DnsClient.java:150)#query: dns Server Addresses: [/192.168.1.254, /8.8.8.8, /2001:4860:4860::8888]
2022-06-09 12:14:48.892 12842-13355/org.atalk.android D/(AbstractDnsClient.java:249)#query: Asking /192.168.1.254 on 53 for _xmpp-client._tcp.atalk.sytes.net.	IN	SRV with:
    DnsMessage(46229 QUERY NO_ERROR query[qr=0] rd)
    [Q: _xmpp-client._tcp.atalk.sytes.net.	IN	SRV]
    [X: EDNS: version: 0, flags:; udp: 1024]
2022-06-09 12:14:49.277 12842-13355/org.atalk.android D/(AbstractDnsClient.java:258)#query: Response from /192.168.1.254 on 53 for _xmpp-client._tcp.atalk.sytes.net.	IN	SRV:
    DnsMessage(46229 QUERY NX_DOMAIN resp[qr=1] rd ra)
    [Q: _xmpp-client._tcp.atalk.sytes.net.	IN	SRV]
    [N: sytes.net.	60	IN	SOA	nf1.no-ip.com. hostmaster.no-ip.com. 2094468407 600 300 604800 600]
    [X: EDNS: version: 0, flags:; udp: 4096]
//============= Mobile network (normal) ================/
2022-06-09 11:29:07.451 3466-3779/org.atalk.android I/(ProtocolProviderServiceJabberImpl.java:1108)#connectAndLogin: Starting XMPP Connection...: atalk.sytes.net/42.60.7.13:5222
2022-06-09 11:29:07.594 3466-3779/org.atalk.android D/(DnsClient.java:150)#query: dns Server Addresses: [/43.245.107.38, /43.245.107.5, /2401:7400:8888:42::6, /2401:7400:8888:41::37, /8.8.8.8, /2001:4860:4860::8888]
2022-06-09 11:29:07.600 3466-3779/org.atalk.android D/(AbstractDnsClient.java:249)#query: Asking /43.245.107.38 on 53 for _xmpp-client._tcp.atalk.sytes.net.	IN	SRV with:
    DnsMessage(25971 QUERY NO_ERROR query[qr=0] rd)
    [Q: _xmpp-client._tcp.atalk.sytes.net.	IN	SRV]
    [X: EDNS: version: 0, flags:; udp: 1024]
2022-06-09 11:29:07.718 3466-3779/org.atalk.android D/(AbstractDnsClient.java:258)#query: Response from /43.245.107.38 on 53 for _xmpp-client._tcp.atalk.sytes.net.	IN	SRV:
    DnsMessage(25971 QUERY NX_DOMAIN resp[qr=1] rd ra)
    [Q: _xmpp-client._tcp.atalk.sytes.net.	IN	SRV]
    [N: sytes.net.	60	IN	SOA	nf1.no-ip.com. hostmaster.no-ip.com. 2094468135 600 300 604800 600]
    [X: EDNS: version: 0, flags:; udp: 512]
//============= Wifi and Mobile network (long pause) ================/
 2022-06-10 07:11:46.900 31745-31966/org.atalk.android D/(DnsClient.java:150)#query: dns Server Addresses: [/43.245.107.38, /43.245.107.5, /192.168.1.254, /2401:7400:8888:42::6, /2401:7400:8888:41::37, /8.8.8.8, /2001:4860:4860::8888]
2022-06-10 07:11:46.902 31745-31966/org.atalk.android D/(AbstractDnsClient.java:249)#query: Asking /43.245.107.38 on 53 for _xmpp-client._tcp.atalk.sytes.net.	IN	SRV with:
    DnsMessage(38182 QUERY NO_ERROR query[qr=0] rd)
    [Q: _xmpp-client._tcp.atalk.sytes.net.	IN	SRV]
    [X: EDNS: version: 0, flags:; udp: 1024]
2022-06-10 07:11:51.916 31745-31966/org.atalk.android D/(NetworkDataSource.java:75)#query: Fallback to TCP because Poll timed out
2022-06-10 07:11:56.929 31745-31966/org.atalk.android D/(AbstractDnsClient.java:254)#query: IOException /43.245.107.38 on 53 while resolving _xmpp-client._tcp.atalk.sytes.net.	IN	SRV: Poll timed out, failed to connect to /43.245.107.38 (port 53) from /192.168.1.167 (port 56676) after 4999ms
2022-06-10 07:11:56.930 31745-31966/org.atalk.android D/(AbstractDnsClient.java:249)#query: Asking /43.245.107.5 on 53 for _xmpp-client._tcp.atalk.sytes.net.	IN	SRV with:
    DnsMessage(38182 QUERY NO_ERROR query[qr=0] rd)
    [Q: _xmpp-client._tcp.atalk.sytes.net.	IN	SRV]
    [X: EDNS: version: 0, flags:; udp: 1024]
2022-06-10 07:12:01.943 31745-31966/org.atalk.android D/(NetworkDataSource.java:75)#query: Fallback to TCP because Poll timed out
2022-06-10 07:12:06.956 31745-31966/org.atalk.android D/(AbstractDnsClient.java:254)#query: IOException /43.245.107.5 on 53 while resolving _xmpp-client._tcp.atalk.sytes.net.	IN	SRV: Poll timed out, failed to connect to /43.245.107.5 (port 53) from /192.168.1.167 (port 39198) after 5000ms
2022-06-10 07:12:06.959 31745-31966/org.atalk.android D/(AbstractDnsClient.java:249)#query: Asking /192.168.1.254 on 53 for _xmpp-client._tcp.atalk.sytes.net.	IN	SRV with:
    DnsMessage(38182 QUERY NO_ERROR query[qr=0] rd)
    [Q: _xmpp-client._tcp.atalk.sytes.net.	IN	SRV]
    [X: EDNS: version: 0, flags:; udp: 1024]
2022-06-10 07:12:07.333 31745-31966/org.atalk.android D/(AbstractDnsClient.java:258)#query: Response from /192.168.1.254 on 53 for _xmpp-client._tcp.atalk.sytes.net.	IN	SRV:
    DnsMessage(38182 QUERY NX_DOMAIN resp[qr=1] rd ra)
    [Q: _xmpp-client._tcp.atalk.sytes.net.	IN	SRV]
    [N: sytes.net.	60	IN	SOA	nf1.no-ip.com. hostmaster.no-ip.com. 2094475374 600 300 604800 600]
    [X: EDNS: version: 0, flags:; udp: 4096]
2022-06-10 07:12:07.343 31745-31966/org.atalk.android I/aTalk: [476] org.jivesoftware.smack.tcp.rce.RemoteXmppTcpConnectionEndpoints.resolveDomain() Could not resolve DNS SRV resource records for _xmpp-client._tcp.atalk.sytes.net. Consider adding those.
2022-06-10 07:12:07.371 31745-31966/org.atalk.android D/(DnsClient.java:150)#query: dns Server Addresses: [/43.245.107.38, /43.245.107.5, /192.168.1.254, /2401:7400:8888:42::6, /2401:7400:8888:41::37, /8.8.8.8, /2001:4860:4860::8888]
2022-06-10 07:12:07.372 31745-31966/org.atalk.android D/(AbstractDnsClient.java:249)#query: Asking /43.245.107.38 on 53 for atalk.sytes.net.	IN	A with:
    DnsMessage(54203 QUERY NO_ERROR query[qr=0] rd)
    [Q: atalk.sytes.net.	IN	A]
    [X: EDNS: version: 0, flags:; udp: 1024]
2022-06-10 07:12:12.386 31745-31966/org.atalk.android D/(NetworkDataSource.java:75)#query: Fallback to TCP because Poll timed out
2022-06-10 07:12:17.400 31745-31966/org.atalk.android D/(AbstractDnsClient.java:254)#query: IOException /43.245.107.38 on 53 while resolving atalk.sytes.net.	IN	A: Poll timed out, failed to connect to /43.245.107.38 (port 53) from /192.168.1.167 (port 56680) after 5000ms
2022-06-10 07:12:17.402 31745-31966/org.atalk.android D/(AbstractDnsClient.java:249)#query: Asking /43.245.107.5 on 53 for atalk.sytes.net.	IN	A with:
    DnsMessage(54203 QUERY NO_ERROR query[qr=0] rd)
    [Q: atalk.sytes.net.	IN	A]
    [X: EDNS: version: 0, flags:; udp: 1024]
2022-06-10 07:12:22.414 31745-31966/org.atalk.android D/(NetworkDataSource.java:75)#query: Fallback to TCP because Poll timed out
2022-06-10 07:12:27.429 31745-31966/org.atalk.android D/(AbstractDnsClient.java:254)#query: IOException /43.245.107.5 on 53 while resolving atalk.sytes.net.	IN	A: Poll timed out, failed to connect to /43.245.107.5 (port 53) from /192.168.1.167 (port 39202) after 5000ms
2022-06-10 07:12:27.431 31745-31966/org.atalk.android D/(AbstractDnsClient.java:249)#query: Asking /192.168.1.254 on 53 for atalk.sytes.net.	IN	A with:
    DnsMessage(54203 QUERY NO_ERROR query[qr=0] rd)
    [Q: atalk.sytes.net.	IN	A]
    [X: EDNS: version: 0, flags:; udp: 1024]
2022-06-10 07:12:27.465 31745-31966/org.atalk.android D/(AbstractDnsClient.java:258)#query: Response from /192.168.1.254 on 53 for atalk.sytes.net.	IN	A:
    DnsMessage(54203 QUERY NO_ERROR resp[qr=1] rd ra)
    [Q: atalk.sytes.net.	IN	A]
    [A: atalk.sytes.net.	19	IN	A	42.60.7.13]
    [X: EDNS: version: 0, flags:; udp: 4096]
2022-06-10 07:12:27.497 31745-31966/org.atalk.android D/(DnsClient.java:150)#query: dns Server Addresses: [/43.245.107.38, /43.245.107.5, /192.168.1.254, /2401:7400:8888:42::6, /2401:7400:8888:41::37, /8.8.8.8, /2001:4860:4860::8888]
2022-06-10 07:12:27.500 31745-31966/org.atalk.android D/(AbstractDnsClient.java:249)#query: Asking /43.245.107.38 on 53 for atalk.sytes.net.	IN	AAAA with:
    DnsMessage(16402 QUERY NO_ERROR query[qr=0] rd)
    [Q: atalk.sytes.net.	IN	AAAA]
    [X: EDNS: version: 0, flags:; udp: 1024]
2022-06-10 07:12:32.513 31745-31966/org.atalk.android D/(NetworkDataSource.java:75)#query: Fallback to TCP because Poll timed out
2022-06-10 07:12:37.527 31745-31966/org.atalk.android D/(AbstractDnsClient.java:254)#query: IOException /43.245.107.38 on 53 while resolving atalk.sytes.net.	IN	AAAA: Poll timed out, failed to connect to /43.245.107.38 (port 53) from /192.168.1.167 (port 56684) after 5000ms
2022-06-10 07:12:37.528 31745-31966/org.atalk.android D/(AbstractDnsClient.java:249)#query: Asking /43.245.107.5 on 53 for atalk.sytes.net.	IN	AAAA with:
    DnsMessage(16402 QUERY NO_ERROR query[qr=0] rd)
    [Q: atalk.sytes.net.	IN	AAAA]
    [X: EDNS: version: 0, flags:; udp: 1024]
2022-06-10 07:12:47.562 31745-31966/org.atalk.android D/(AbstractDnsClient.java:254)#query: IOException /43.245.107.5 on 53 while resolving atalk.sytes.net.	IN	AAAA: Poll timed out, failed to connect to /43.245.107.5 (port 53) from /192.168.1.167 (port 39208) after 5000ms
2022-06-10 07:12:47.567 31745-31966/org.atalk.android D/(AbstractDnsClient.java:249)#query: Asking /192.168.1.254 on 53 for atalk.sytes.net.	IN	AAAA with:
    DnsMessage(16402 QUERY NO_ERROR query[qr=0] rd)
    [Q: atalk.sytes.net.	IN	AAAA]
    [X: EDNS: version: 0, flags:; udp: 1024]
2022-06-10 07:12:47.672 31745-31966/org.atalk.android D/(AbstractDnsClient.java:258)#query: Response from /192.168.1.254 on 53 for atalk.sytes.net.	IN	AAAA:
    DnsMessage(16402 QUERY NO_ERROR resp[qr=1] rd ra)
    [Q: atalk.sytes.net.	IN	AAAA]
    [N: sytes.net.	60	IN	SOA	nf1.no-ip.com. hostmaster.no-ip.com. 2094475378 600 300 604800 600]
    [X: EDNS: version: 0, flags:; udp: 4096]
2022-06-10 07:12:47.702 31745-31966/org.atalk.android D/aTalk: [476] org.jivesoftware.smack.tcp.XMPPTCPConnection.connectUsingConfiguration() Trying to establish TCP connection to /42.60.7.13:5222
2022-06-10 07:12:47.743 31745-31966/org.atalk.android D/aTalk: [476] org.jivesoftware.smack.tcp.XMPPTCPConnection.connectUsingConfiguration() Established TCP connection to /42.60.7.13:5222
2022-06-10 07:12:47.780 31745-32091/org.atalk.android D/aTalk: [484] org.jivesoftware.smack.tcp.XMPPTCPConnection.run() Smack Writer (0) start
2022-06-10 07:12:47.796 31745-32092/org.atalk.android D/aTalk: [485] org.jivesoftware.smack.tcp.XMPPTCPConnection.run() Smack Reader (0) start
2022-06-10 07:12:47.852 31745-32091/org.atalk.android D/SMACK: SENT (0): 
    <stream:stream xmlns='jabber:client' to='atalk.sytes.net' xmlns:stream='http://etherx.jabber.org/streams' version='1.0' xml:lang='en'>
2022-06-10 07:12:47.921 31745-32092/org.atalk.android D/SMACK: RECV (0): ?xml version='1.0'?>
    <stream:stream id='9821135312590748206' version='1.0' xml:lang='en' xmlns:stream='http://etherx.jabber.org/streams' from='atalk.sytes.net' xmlns='jabber:client'>
    <stream:features>
      <starttls xmlns='urn:ietf:params:xml:ns:xmpp-tls'>
        <required/>
      </starttls>
    </stream:features>

Some corrections for the previous comment:

Mobile network (normal)
2022-06-09 11:29:07.594 3466-3779/org.atalk.android D/(DnsClient.java:150)#query: dns Server Addresses: [/43.245.107.38, /43.245.107.5, /2401:7400:8888:42::6, /2401:7400:8888:41::37, /8.8.8.8, /2001:4860:4860::8888]

In the case of long pause problem, found that the mobile IP’s have a higher priorities than the WiFi; but the mobile address used for query seems not working from the captured result for both the UDP and TCP query; but works when the WiFi address is used i.e. 3rd value in the returned dns server addresses.

It seems that the long pause problem is contributed by android network manager i.e. the given mobile network IP is not working. Not sure how to proceed from here to verify this assumption. Any advice?

Wifi and Mobile network (long pause)
2022-06-10 07:11:46.900 31745-31966/org.atalk.android D/(DnsClient.java:150)#query: dns Server Addresses: [/43.245.107.38, /43.245.107.5, /192.168.1.254, /2401:7400:8888:42::6, /2401:7400:8888:41::37, /8.8.8.8, /2001:4860:4860::8888]

FYI:
During aTalk v2.9.1 (03/16/2022) release, a wired behaviour is found with Note-10 in mobile network as captured in the aTalk history log, when InetAddress.getByName(dnsServerString) is used for enquiry.
But seems this problem is fixed? after the recent android OS update, based on the latest logcat captured herewith. Not sure if making the same change to DnsClient.java will help avoid the observed problem.

- Android with network APN=IPv4/IPv6 or APN=IPv6 returns only IPv6 public address in InetAddress.getByName(host);
  hence only an IPv6 candidate (without the sfllx candidate) is sent i.e.
  i.e. IPv6 candidate harvested from ice4j HostCandidateHarvester#harvest(); causing problem in call setup;
  <candidate port='58979' type='host' ip='2401:7400:4000:2e4a:1:2:93f1:b634' id='e49ea0a0-87e9-46a1-9c2e-1666b6ce8e32'/>
  missing: <candidate ... ip='119.56.100.180' port='5002' type='srflx' rel-addr='10.143.27.57' rel-port='5002' network='0'/>
  Problem fixed with IceUdpTransportManager#getTransportAddress(String hostname, int port, Transport transport)
  see https://github.com/jitsi/ice4j/issues/255 for detail problem and solution.
  For android network APN setting see: https://sanctum9.wordpress.com/2019/03/15/switch-to-ipv6-on-android/

This was implemented in aTalk v 2.9.1 to resolve the InetAddress#getByName() problem:

    /**
     * Generate a list of TransportAddress from the given hostname, port and transport.
     * The given host name is resolved into both IPv4 and IPv6 InetAddresses.
     *
     * Note: android InetAddress.getByName(hostname) returns the first IP found, any may be an IPv6 InetAddress;
     * if mobile network setting for APN=IPV4/IPv6 or APN=IPv6. This causes problem in STUN candidate harvest:
     * @see https://github.com/jitsi/ice4j/issues/255
     *
     * @param hostname the address itself
     * @param port the port number
     * @param transport the transport to use with this address.
     */
    protected List<TransportAddress> getTransportAddress(String hostname, int port, Transport transport)
    {
        List<TransportAddress> transportAddress = new ArrayList<>();
        try {
            // return all associated InetAddress in both IPv4 and IPv6 address
            InetAddress[] inetAddresses = InetAddress.getAllByName(hostname);
            for (InetAddress inetAddress : inetAddresses) {
                transportAddress.add(new TransportAddress(inetAddress, port, transport));
            }
        } catch (UnknownHostException e) {
            Timber.e("UnknownHostException: %s", e.getMessage());
        }
        return transportAddress;
    }

After going in depth on how the dns server addresses are retrieved; found that miniDns actually uses aTalk AndroidUsingLinkProperties.java class as attached.

AndroidUsingLinkProperties.java (4.1 KB)

The latest logcat captured continues to show only WiFi as activeNetwork when both Mobile and WiFi are enabled, which should be the case for data. So need to continue monitor.

2022-06-10 13:06:27.421 28398-28571/org.atalk.android D/(DnsClient.java:150)#query: dns Server Addresses: [/192.168.1.254, /8.8.8.8, /2001:4860:4860::8888]

Look like the root cause may actually lies within AndroidUsingLinkProperties.java implementation, which did not consider isActiveNetwork in all cases for all android API’s; has modified the source to alleviate this problem. Will continue monitor if this has actually resolve the problem:

    @Override
    public List<String> getDnsServerAddresses()
    {
        final ConnectivityManager connectivityManager = (ConnectivityManager) mContext.getSystemService(Context.CONNECTIVITY_SERVICE);
        final List<String> servers = new ArrayList<>();

        final Network[] networks = connectivityManager == null ? null : connectivityManager.getAllNetworks();
        if (networks != null) {
            Timber.d("dns Server Addresses getAllNetworks(): %s", Arrays.asList(networks));

            // ConnectivityManager.getActiveNetwork() is API 23; null if otherwise
            final Network activeNetwork = getActiveNetwork(connectivityManager);
            int vpnOffset = 0;
            for (Network network : networks) {
                LinkProperties linkProperties = connectivityManager.getLinkProperties(network);
                if (linkProperties == null) {
                    continue;
                }

                // Prioritize the DNS servers of links which have a default route
                final NetworkInfo networkInfo = connectivityManager.getNetworkInfo(network);
                final boolean isActiveNetwork = network.equals(activeNetwork);
                final boolean isVpn = networkInfo != null && networkInfo.getType() == ConnectivityManager.TYPE_VPN;
                final List<String> xServers = getIPv4First(linkProperties.getDnsServers());

                if (isActiveNetwork || activeNetwork == null) {
                    Timber.d("hasDefaultRoute: %s || isActiveNetwork: %s || activeNetwork: %s || isVpn: %s || IP: %s",
                            hasDefaultRoute(linkProperties), isActiveNetwork, activeNetwork, isVpn, getIPv4First(linkProperties.getDnsServers()));
                    if (isVpn) {
                        servers.addAll(0, xServers);
                        vpnOffset += xServers.size();
                    }
                    // Prioritize the DNS servers of links which have a default route
                    else if (hasDefaultRoute(linkProperties)) {
                        servers.addAll(vpnOffset, getIPv4First(linkProperties.getDnsServers()));
                    }
                    else {
                        servers.addAll(toListOfStrings(linkProperties.getDnsServers()));
                    }
                }
            }
        }
        Timber.d("dns Server Addresses (linkProperty): %s", servers);
        return servers;
    }
========== aTalk logcat with new implementation (Wifi and Mobile network) ================    
2022-06-11 08:41:14.066 26510-27191/org.atalk.android I/(ProtocolProviderServiceJabberImpl.java:1108)#connectAndLogin: Starting XMPP Connection...: atalk.sytes.net/42.60.7.13:5222
2022-06-11 08:41:14.097 26510-27191/org.atalk.android D/(AndroidUsingLinkProperties.java:69)#getDnsServerAddresses: dns Server Addresses getAllNetworks(): [158, 159]
2022-06-11 08:41:14.113 26510-27191/org.atalk.android D/(AndroidUsingLinkProperties.java:87)#getDnsServerAddresses: hasDefaultRoute: true || isActiveNetwork: true || activeNetwork: 159 || isVpn: false || IP: [192.168.1.254]
2022-06-11 08:41:14.114 26510-27191/org.atalk.android D/(AndroidUsingLinkProperties.java:103)#getDnsServerAddresses: dns Server Addresses (linkProperty): [192.168.1.254]
2022-06-11 08:41:14.118 26510-27191/org.atalk.android D/(DnsClient.java:150)#query: dns Server Addresses: [/192.168.1.254, /8.8.8.8, /2001:4860:4860::8888]
2022-06-11 08:41:14.121 26510-27191/org.atalk.android D/(AbstractDnsClient.java:249)#query: Asking /192.168.1.254 on 53 for _xmpp-client._tcp.atalk.sytes.net.	IN	SRV with:
    DnsMessage(64073 QUERY NO_ERROR query[qr=0] rd)
    [Q: _xmpp-client._tcp.atalk.sytes.net.	IN	SRV]
    [X: EDNS: version: 0, flags:; udp: 1024]
2022-06-11 08:41:14.221 26510-27191/org.atalk.android D/(AbstractDnsClient.java:258)#query: Response from /192.168.1.254 on 53 for _xmpp-client._tcp.atalk.sytes.net.	IN	SRV:
    DnsMessage(64073 QUERY NX_DOMAIN resp[qr=1] rd ra)
    [Q: _xmpp-client._tcp.atalk.sytes.net.	IN	SRV]
    [N: sytes.net.	60	IN	SOA	nf1.no-ip.com. hostmaster.no-ip.com. 2094484615 600 300 604800 600]
    [X: EDNS: version: 0, flags:; udp: 4096]
1 Like

Note that the A RR of atalk.sytes.net having a TTL of 60 seconds amplifies the issue as it prevents effective caching of DNS responses on the client side.

Sorry, do not quite understand the implication in your comment:

it prevents effective caching of DNS responses on the client side.

Are you recommend that the TTL value should set larger than 60 seconds?
I though the returned TTL value is defined in the DNS server.
Can this value be set by aTalk, and what is the optimal value?

Need your advice.

yes, typically 24h.

It is. Or, to be more precise, it is defined by whoever controls the DNS zone (e.g., sytes.net in this case).

If you mean by aTalk the application, then no. But as I set before, I can bet set by whoever controls the zone or the resource record in question (atalk.sytes.net in this case). I assume that is you.

Thanks for the clarifications, and also with reference to the online info i.e.
Best practices for using TTL
have help me to understand the effect of TTL on authoritative name servers.

Actually atalk.sytes.net is a sub-domain of sytes.net @ no-ip; believe the 60s TTL is set by the main server sytes.net, which I have no access to.

[N: sytes.net. 60 IN SOA nf1.no-ip.com. hostmaster.no-ip.com. 2094484615 600 300 604800 600

But in going through the org.minidns source, DnsClient.java class deploys a local cache for the returned dns result; but seems the cache is not being enabled.

Can aTalk use this cache to help improve the dns query latency?
If so, how to enable this cache for use in aTalk.

    @Override
    public DnsQueryResult query(DnsMessage.Builder queryBuilder) throws IOException {
        DnsMessage q = newQuestion(queryBuilder).build();
        // While this query method does in fact re-use query(Question, String)
        // we still do a cache lookup here in order to avoid unnecessary
        // findDNS()calls, which are expensive on Android. Note that we do not
        // put the results back into the Cache, as this is already done by
        // query(Question, String).
        DnsQueryResult dnsQueryResult = (cache == null) ? null : cache.get(q);
        if (dnsQueryResult != null) {
            return dnsQueryResult;
        }

        List<InetAddress> dnsServerAddresses = getServerAddresses();

        ....
    }

Yes, but MiniDNS cache respects the TTL of the resource record, so if the TTL is 60s, the entry will only be cached for 60s, which won’t much help in this case.

Thanks, now I fully understand the whole TTL implication.

Actually no-ip allows creation for SRV record for host, but required a paid service. So will just leave it at this for the moment.

With the latest modification to AndroidUsingLinkProperties.java modification, aTalk no longer experiences the long pause problem during the login process or call setup. The fixed has also been verified working on android device with OS API-21.

It is confirmed that the long pause issue is due to aTalk implementation, not taking into account the network active state for android device OS >=API-23; at time, this causes aTalk to use an inactive network IP in DNS query, leading to socket timeout and TCP fallback delay time being introduced in the login process.

Would like to express my sincere thank for the smack team help in resolving this problem.

1 Like

This topic was automatically closed 100 days after the last reply. New replies are no longer allowed.