watchOS issue with logging in

[vincentneo]

~I wanted to test on what would happen if a user happens to be using the app with bad network conditions, so I tested my app which uses TDLib, using macOS's Network Link Conditioner, set to "3G" profile, and running watchOS on simulator.~

It appears issue is with more with logging in rather than with slow networks as I initially suspected.

I realised that after receiving updateAuthorizationState with the state of authorizationStateWaitPhoneNumber, after calling of requestQrCodeAuthentication, I do not get another updateAuthorizationState, which should return the state of authorizationStateWaitOtherDeviceConfirmation.

Instead, I see logs like this in the console.

2023-06-09 15:55:22.249089+0800 AppName[23430:244560] PDTask <953B5D75-28F6-430D-A5DC-B8F7FFAFB753>.<10> finished with error [-1001] Error Domain=NSURLErrorDomain Code=-1001 "The request timed out." UserInfo={_kCFStreamErrorCodeKey=-2102, _NSURLErrorFailingURLSessionTaskErrorKey=LocalDataPDTask <953B5D75-28F6-430D-A5DC-B8F7FFAFB753>.<10>, _NSURLErrorRelatedURLSessionTaskErrorKey=(
    "LocalDataPDTask <953B5D75-28F6-430D-A5DC-B8F7FFAFB753>.<10>",
    "LocalDataTask <953B5D75-28F6-430D-A5DC-B8F7FFAFB753>.<10>"
), NSLocalizedDescription=The request timed out., _kCFStreamErrorDomainKey=4, NSErrorFailingURLStringKey=http://149.154.175.50:443/api, NSErrorFailingURLKey=http://149.154.175.50:443/api}
2023-06-09 15:55:22.249406+0800 AppName[23430:244560] Task <953B5D75-28F6-430D-A5DC-B8F7FFAFB753>.<10> finished with error [-1001] Error Domain=NSURLErrorDomain Code=-1001 "The request timed out." UserInfo={_kCFStreamErrorCodeKey=-2102, _NSURLErrorFailingURLSessionTaskErrorKey=LocalDataTask <953B5D75-28F6-430D-A5DC-B8F7FFAFB753>.<10>, _NSURLErrorRelatedURLSessionTaskErrorKey=(
    "LocalDataTask <953B5D75-28F6-430D-A5DC-B8F7FFAFB753>.<10>",
    "LocalDataPDTask <953B5D75-28F6-430D-A5DC-B8F7FFAFB753>.<10>",
    "LocalDataTask <953B5D75-28F6-430D-A5DC-B8F7FFAFB753>.<10>"
), NSLocalizedDescription=The request timed out., _kCFStreamErrorDomainKey=4, NSErrorFailingURLStringKey=http://149.154.175.50:443/api, NSErrorFailingURLKey=http://149.154.175.50:443/api}
2023-06-09 15:55:22.249452+0800 AppName[23430:244376] PDTask <E629D51A-D1BD-4E09-9486-ACCB9BAD099F>.<11> finished with error [-1001] Error Domain=NSURLErrorDomain Code=-1001 "The request timed out." UserInfo={_kCFStreamErrorCodeKey=-2102, _NSURLErrorFailingURLSessionTaskErrorKey=LocalDataPDTask <E629D51A-D1BD-4E09-9486-ACCB9BAD099F>.<11>, _NSURLErrorRelatedURLSessionTaskErrorKey=(
    "LocalDataPDTask <E629D51A-D1BD-4E09-9486-ACCB9BAD099F>.<11>",
    "LocalDataTask <E629D51A-D1BD-4E09-9486-ACCB9BAD099F>.<11>"
), NSLocalizedDescription=The request timed out., _kCFStreamErrorDomainKey=4, NSErrorFailingURLStringKey=http://149.154.175.50:5222/api, NSErrorFailingURLKey=http://149.154.175.50:5222/api}
[ 4][t 4][1686297322.253673076][SessionConnection.cpp:1100][#1][!Session:1:main]    Last pong was in 60.084104/13662.362543, last read was in 60.084104/13662.362543, RTT = 6.425648, ping timeout = 138.694311, read timeout = 138.694311, flush packet in -13662.362543, wakeup in 78.612207
[ 2][t 4][1686297322.254172086][Session.cpp:628][#1][!Session:1:main]    Session connection with 3 pending requests was closed: [Error : -1001 : HTTP request failed] Session:1:main::Connect::HTTP::[149.154.175.50:443] to DcId{1} over HTTP
[ 3][t 4][1686297322.254177093][Session.cpp:846][#1][!Session:1:main][&net_query]    Mark as unknown [message_id:7242591563929213544][Query:[id:65536][tl:0x1fb33026][state:Query]]
[ 3][t 4][1686297322.254182100][Session.cpp:846][#1][!Session:1:main][&net_query]    Mark as unknown [message_id:7242591563929687168][Query:[id:131072][tl:0xc4f9186b][state:Query]]

Note that it only happens on slow connections/with the link conditioner on. For td_receive()'s timeout, I have tried both 2s and 100s, with the same result.

I am also investigating on why it seems some update calls get dropped at random, which lead to this investigation and finding of this issue.

[levlam]

The network looks much worse than 3G. Round-trip time of 6.425648 seconds for small request used by TDLib suggests that also aggressive packet drop is enabled, or an artificial delay is introduced. Default timeout for NSURLSession.sharedSession is 60 seconds, which is confirmed by "Last pong was in 60.084104" logging from TDLib. If a small HTTP request can't succeed for 60 seconds, then the app can hardly work on such network.

[vincentneo]

The earlier updateAuthorizationState that I received arrived pretty quickly though.

These are the settings:

[vincentneo]

Interesting that now even with Network Link Conditioner turned off, I am still getting no response from requestQrCodeAuthentication (not even an ok/error btw) Similar timeout messages are observed.

No problems with another simulator that was already logged in since many days ago.

By the way assuming the 60s timeout behaviour, assuming if device momentarily loses connection for let's say 61s, will TDLib fail to continue receiving updates after device regain connection at 62s? (and user would have to re-open the app?)

[levlam]

TDLib will complete all request whenever network become accessible.

[vincentneo]

@levlam Now I swear that something is wrong with the QR code requestor on the backend. Nothing to do with speed I guess.

My current app on the store is on TDLib 1.8.12, and hasn't ever had a problem until this week. The build I tested when I tested for this issue was on 1.8.14, which suggest the version difference wasn't a problem at least for this.

I received 4 complains so far in the short span of a week, can't be a coincidence right? App on 1.8.12 hasn't changed since late March, so there must be something wrong.

[vincentneo]

btw I've sent a file to the tdlib bot, verbosity level 1000

[vincentneo]

Seems like I can get a QR code now, for both IPv4 and IPv6 modes. That said, still occasionally receiving random timeouts, even though things seem to be working.

Will check again tomorrow, if all's good I'll close both issues.

[levlam]

This should be fixed now.

[vincentneo]

Works for me, though there's one user that is still facing problems logging in, last reported about 3 hours ago. Will advice the user to try again.

[vincentneo]

Other than 1 user, rest seems to be logging in fine. Will close, thanks for the help!