In T224712#5913343, @Dvorapa wrote:

Beta Cluster is fixed, but still fails for zh.wikisource.org, see:

Can't reproduce (with non-Pywikibot code), login to zh.wikisource.org works fine for me. If you still think it's a problem in MediaWiki or Wikimedia's infrastructure, you should supply the HTTP requests and responses to verify that cookies and such are being handled correctly.

It happens only sometimes, which is weird, I'll investigate it further

In T224712#5917361, @Anomie wrote:

In T224712#5913343, @Dvorapa wrote:

Beta Cluster is fixed, but still fails for zh.wikisource.org, see:

Can't reproduce (with non-Pywikibot code), login to zh.wikisource.org works fine for me. If you still think it's a problem in MediaWiki or Wikimedia's infrastructure, you should supply the HTTP requests and responses to verify that cookies and such are being handled correctly.

@Anomie @Jdforrester-WMF I broke Pywikibot login loop and found out the issue with zh.wikisource.org. It seems API sometimes reacts weirdly to action=login requests. For format=json&lgname=Pywikibot-test&action=login&maxlag=5&lgpassword=[secure]&lgtoken=77c559a0bf34eaf6755aaebca7a56ba25e5693bf+\ API responds with API warning (login): Fetching a token via "action=login" is deprecated. Use "action=query&meta=tokens&type=login" instead. and the result contains NeedToken and a token, which gives invalid if checked by checktoken. See the log of my test (full log, test code):

WARNING: ###############################################################################

WARNING: /w/api.php?format=json&lgname=Pywikibot-test&action=login&maxlag=5&lgpassword=[secure]&lgtoken=77c559a0bf34eaf6755aaebca7a56ba25e5693bf+\

WARNING: API warning (login): Fetching a token via "action=login" is deprecated. Use "action=query&meta=tokens&type=login" instead.

WARNING: API warning (main): Subscribe to the mediawiki-api-announce mailing list at <https://lists.wikimedia.org/mailman/listinfo/mediawiki-api-announce> for notice of API deprecations and breaking changes. Use [[Special:ApiFeatureUsage]] to see usage of deprecated features by your application.

WARNING: {'login': {'token': 'ce9ea250edb885d68e5a7cf11f90d64e5e5693bf+\\', 'result': 'NeedToken'}, 'warnings': {'login': {'*': 'Fetching a token via "action=login" is deprecated. Use "action=query&meta=tokens&type=login" instead.'}, 'main': {'*': 'Subscribe to the mediawiki-api-announce mailing list at <https://lists.wikimedia.org/mailman/listinfo/mediawiki-api-announce> for notice of API deprecations and breaking changes. Use [[Special:ApiFeatureUsage]] to see usage of deprecated features by your application.'}}}

WARNING: ce9ea250edb885d68e5a7cf11f90d64e5e5693bf+\

WARNING: invalid

There are two weird things: Why doesn't API accept lgtoken in the first request (token is freshly generated) and why NeedToken gives invalid tokens afterwards (which results with a login loop)?

Anyway, for Pywikibot the fix is easy. Don't trust NeedToken token and simply generate a new one the usual way (@Xqt)

After some other tests:
zh.wikisource.org API sometimes generates invalid new token (using action=query&meta=tokens). This token gives login response of NeedToken with another invalid token generated. This token gives login response of NeedToken with yet another invalid token generated. And so on...
After a couple of attempts I successfully reproduced it also using zh:ws API sandbox

Change 575038 had a related patch set uploaded (by Dvorapa; owner: Dvorapa):
[pywikibot/core@master] [IMPR] Don't trust token from NeedToken response

https://gerrit.wikimedia.org/r/575038

In T224712#5920305, @Dvorapa wrote:

@Anomie @Jdforrester-WMF I broke Pywikibot login loop and found out the issue with zh.wikisource.org. It seems API sometimes reacts weirdly to action=login requests. For format=json&lgname=Pywikibot-test&action=login&maxlag=5&lgpassword=[secure]&lgtoken=77c559a0bf34eaf6755aaebca7a56ba25e5693bf+\ API responds with API warning (login): Fetching a token via "action=login" is deprecated. Use "action=query&meta=tokens&type=login" instead. and the result contains NeedToken and a token, which gives invalid if checked by checktoken.
[...]
There are two weird things: Why doesn't API accept lgtoken in the first request (token is freshly generated) and why NeedToken gives invalid tokens afterwards (which results with a login loop)?

Yes, that was fairly obvious as to what was happening from https://travis-ci.org/wikimedia/pywikibot/jobs/654150636, as it already logged that warning. That's caused by the session being lost on every new request.

There are, broadly, three ways the session might be lost:

1. Something in MediaWiki's session handling is broken, as was the case for en.wikisource.beta.wmflabs.org earlier.
2. Something in your client (probably cookie handling) is broken. This can include the client somehow having a stale/corrupt cookie that isn't removed by MediaWiki's attempts to unset it.
3. Some proxy in between your client and MediaWiki is breaking the request somehow.

My being unable to reproduce it in locally (several times now over a few days) makes #1 seem less likely, as does the fact that there's no "Unbreak Now!" task open about this affecting human users. But that doesn't completely rule it out.

Being able to examine the actual HTTP request and response headers for all requests during the failed login would go a long way towards investigating #2, which is why I asked for that. Unfortunately the log you provided does not seem to contain that information.

Weird is this happens only for zh.wikisource, not for enwiki, not for wikidata, commons, testwiki, testwikidata, arwiktionary and not for Beta Cluster.

I am not sure, how to get the whole HTTP request with headers.

Also this happens sometimes for lgtoken, sometimes for username and sometimes for password, another weird thing

It first failed in May 29th after https://github.com/wikimedia/pywikibot/commit/893d03f87ff8e4d1d4db4b4838bec176cd97a338 (no code change in session cookie part)

Change 575038 merged by jenkins-bot:
[pywikibot/core@master] [IMPR] Don't trust token from NeedToken response

https://gerrit.wikimedia.org/r/575038

The patch just partially workarounds one loop. But does not resolve anything

Change 584017 had a related patch set uploaded (by Dvorapa; owner: Dvorapa):
[pywikibot/core@master] [bugfix] Resolve action=login deprecation warning

https://gerrit.wikimedia.org/r/584017

Change 584017 merged by jenkins-bot:
[pywikibot/core@master] [bugfix] Resolve action=login deprecation warning

https://gerrit.wikimedia.org/r/584017

Change 584091 had a related patch set uploaded (by Dvorapa; owner: Dvorapa):
[pywikibot/core@master] [test] Enable some sort of APIError logging

https://gerrit.wikimedia.org/r/584091

Change 584091 abandoned by Dvorapa:
[test] Enable some sort of APIError logging

Reason:
No longer relevant

https://gerrit.wikimedia.org/r/584091

Change 584195 had a related patch set uploaded (by Dvorapa; owner: Dvorapa):
[pywikibot/core@master] [bugfix] Fix handling of badtoken response for login actions

https://gerrit.wikimedia.org/r/584195

Change 584195 merged by jenkins-bot:
[pywikibot/core@master] [bugfix] Fix handling of badtoken response for login actions

https://gerrit.wikimedia.org/r/584195

Change 583711 had a related patch set uploaded (by Dvorapa; owner: Dvorapa):
[pywikibot/core@master] [IMPR] Don't trust token from NeedToken response

https://gerrit.wikimedia.org/r/583711

@Urbanecm @Xqt

Finally we can see so far hidden login loops as we track new throttle responses from API (https://gerrit.wikimedia.org/r/#/c/pywikibot/core/+/584017/). MW sends them after 5 login attempts and requires to wait 5 minutes.

As our single test timeout is set to 5 minutes, we can now see the full traceback with loops inbetween instead of not descriptive endless loop. Hurray! But still we are half way through fixing the issues, see subtasks I created from what I debugged so far.

https://travis-ci.org/github/wikimedia/pywikibot/jobs/668338196#L13175