Wikidata edits fail in 2.8.5

[misaochan]

Summary:

Wikidata edits were working in 2.8.0 but not in 2.8.2. I am unsure if they worked in 2.8.1

Steps to reproduce:

Use Nearby to upload an image in 2.8.2 and check if the p18 edit happened

Add System logs:

Will post later

Device and Android version:

Samsung Galaxy s7 Android 8.0

Commons app version:

2.8.2

Would you like to work on the issue?

No

[maskaravivek]

The edits are failing for me with a badtoken exception.

<?xml version="1.0" encoding="UTF-8"?><api servedby="mw1314"><error code="badtoken" info="Invalid CSRF token." xml:space="preserve">See https://www.wikidata.org/w/api.php for API usage. Subscribe to the mediawiki-api-announce mailing list at &amp;lt;https://lists.wikimedia.org/mailman/listinfo/mediawiki-api-announce&amp;gt; for notice of API deprecations and breaking changes.</error></api>

It seems to be an intermittent issue as I see a couple of successful edits (for example) from 2.8.2 itself. I suspect that we are handling the auth incorrectly and that is causing these issues.

Edit:

You can find all recent edits here: https://www.wikidata.org/w/index.php?hidebots=1&translations=filter&hidecategorization=1&tagfilter=wikimedia-commons-app&limit=500&days=30&enhanced=1&hideWikibase=1&title=Special:RecentChanges&urlversion=2

[misaochan]

Interesting that it appeared to be intermittent! I will test again and post logs asap.

[misaochan]

2 of my uploads via misaochan2 (Samsung Galaxy s7, Android 8.0) successfully updated Wikidata.

I logged out, and then into misaochan (which has 2FA enabled). Finally got an error. I wonder if 2FA is related? Does your account that fails to edit have 2FA enabled too, @maskaravivek ?

I created a custom paste for the failure logs (with cookie headers) anyway at https://phabricator.wikimedia.org/P7498 . Gave you access @maskaravivek . I also noticed that based on the cookie headers, it seemed to think I was still logged in to Misaochan2. For some reason, despite that, the upload itself succeeds.

Edit: Okay, this is really weird. Look at https://commons.wikimedia.org/wiki/File:Bulimba_Point.jpg , which I just successfully uploaded. It says Author | Misaochan in the Summary. But in File History, it says Misaochan2 (talk | contribs). It also does not show up at https://commons.wikimedia.org/wiki/Special:Contributions/Misaochan .

I think this might be indicative of a much larger issue with our new login system, not just with Wikidata edits. :/

Error:

08-31 01:09:14.451 16596-16596/fr.free.nrw.commons E/WikidataEditService: Error occurred while making claim
--
java.lang.NullPointerException: Callable returned null
at io.reactivex.internal.functions.ObjectHelper.requireNonNull(ObjectHelper.java:39)
at io.reactivex.internal.operators.observable.ObservableFromCallable.subscribeActual(ObservableFromCallable.java:42)
at io.reactivex.Observable.subscribe(Observable.java:10901)
at com.tspoon.traceur.ObservableOnAssemblyCallable.subscribeActual(ObservableOnAssemblyCallable.java:42)
at io.reactivex.Observable.subscribe(Observable.java:10901)
at io.reactivex.internal.operators.observable.ObservableSubscribeOn$SubscribeTask.run(ObservableSubscribeOn.java:96)
at io.reactivex.Scheduler$DisposeTask.run(Scheduler.java:452)
at io.reactivex.internal.schedulers.ScheduledRunnable.run(ScheduledRunnable.java:61)
at io.reactivex.internal.schedulers.ScheduledRunnable.call(ScheduledRunnable.java:52)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:301)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1162)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:636)
at java.lang.Thread.run(Thread.java:764)
Caused by: com.tspoon.traceur.TraceurException: Debug Exception generated at call site
at dalvik.system.VMStack.getThreadStackTrace(Native Method)
at java.lang.Thread.getStackTrace(Thread.java:1536)
at io.reactivex.Observable.fromCallable(Observable.java:1724)
at fr.free.nrw.commons.wikidata.WikidataEditService.editWikidataProperty(WikidataEditService.java:75)
at fr.free.nrw.commons.wikidata.WikidataEditService.createClaimWithLogging(WikidataEditService.java:61)
at fr.free.nrw.commons.upload.UploadService.uploadContribution(UploadService.java:264)
at fr.free.nrw.commons.upload.UploadService.handle(UploadService.java:134)
at fr.free.nrw.commons.upload.UploadService.handle(UploadService.java:44)
at fr.free.nrw.commons.HandlerService$ServiceHandler.handleMessage(HandlerService.java:26)
at android.os.Handler.dispatchMessage(Handler.java:105)
at android.os.Looper.loop(Looper.java:164)
at android.os.HandlerThread.run(HandlerThread.java:65)
Caused by: com.tspoon.traceur.TraceurException: Debug Exception generated at call site
at dalvik.system.VMStack.getThreadStackTrace(Native Method)
at java.lang.Thread.getStackTrace(Thread.java:1536)
at io.reactivex.Observable.subscribeOn(Observable.java:10977)
at fr.free.nrw.commons.wikidata.WikidataEditService.editWikidataProperty(WikidataEditService.java:79)
at fr.free.nrw.commons.wikidata.WikidataEditService.createClaimWithLogging(WikidataEditService.java:61)
at fr.free.nrw.commons.upload.UploadService.uploadContribution(UploadService.java:264)
at fr.free.nrw.commons.upload.UploadService.handle(UploadService.java:134)
at fr.free.nrw.commons.upload.UploadService.handle(UploadService.java:44)
at fr.free.nrw.commons.HandlerService$ServiceHandler.handleMessage(HandlerService.java:26)
at android.os.Handler.dispatchMessage(Handler.java:105)
at android.os.Looper.loop(Looper.java:164)
at android.os.HandlerThread.run(HandlerThread.java:65)
Caused by: com.tspoon.traceur.TraceurException: Debug Exception generated at call site
at dalvik.system.VMStack.getThreadStackTrace(Native Method)
at java.lang.Thread.getStackTrace(Thread.java:1536)
at io.reactivex.Observable.observeOn(Observable.java:8693)
at io.reactivex.Observable.observeOn(Observable.java:8626)
at fr.free.nrw.commons.wikidata.WikidataEditService.editWikidataProperty(WikidataEditService.java:80)
at fr.free.nrw.commons.wikidata.WikidataEditService.createClaimWithLogging(WikidataEditService.java:61)
at fr.free.nrw.commons.upload.UploadService.uploadContribution(UploadService.java:264)
at fr.free.nrw.commons.upload.UploadService.handle(UploadService.java:134)
at fr.free.nrw.commons.upload.UploadService.handle(UploadService.java:44)
at fr.free.nrw.commons.HandlerService$ServiceHandler.handleMessage(HandlerService.java:26)
at android.os.Handler.dispatchMessage(Handler.java:105)
at android.os.Looper.loop(Looper.java:164)
at android.os.HandlerThread.run(HandlerThread.java:65)

[misaochan]

As a side note, the upload that failed to edit p18 for Vojtech - https://commons.wikimedia.org/wiki/File:Espresso_lungo_with_milk.jpg - does not encounter the same issue with the author that mine did. "User" and "author" appeared to be the same for him. His account has 2FA enabled, same with Misaochan.

(We would still need to handle the wrong author problem with high priority, of course. But just wondering if there also might be another contributor to the failing edits).

[nicolas-raoul]

Using 2.8.2, today I tried two Wikidata uploads and both were correctly linked. No 2FA.

[misaochan]

Interesting, thanks for the tests @nicolas-raoul ! So it does seem like so far, the failed p18 edits have all come from accounts with 2FA enabled. @neslihanturan have you tried yours?

[maskaravivek]

I tried uploading a few images through the Nearby page and the wiki data edits were successful for all of them. My account doesn't have 2FA enabled. Can we establish that wiki data edits are working fine for everyone who doesn't have 2FA enabled?

The issue with 2FA enabled account is happening because of the following snippet.

if(centralAuthToken == null || centralAuthToken.isEmpty()) {
            api.removeAllCookies();
            String login = login(AccountUtil.getUserName(context), AccountUtil.getPassword(context));
            if(login.equals("PASS")) {
                return getCentralAuthToken();
            }
        }

This would happen only come into picture when the api.action("centralauthtoken") API throws an error. Have added some error logs in these flows to make debugging easier.

As the above snippet suggests, the session can be refreshed only if the account doesn't have 2FA enabled. Essentially, refreshing a session means doing a login behind the scenes. The account util already has username and password securely stored with it so a re-login can be done without involving the user but if 2FA is enabled then this can't be done. For now, I have added log for such an occurrence.

I didn't investigate time in triggering the 2FA flow from this point as our session management strategy has some known loopholes. Will be working on fixing it. Hopefully, it would fix this issue as well.

Also, if the issue is happening just for 2FA enabled users then we are not in a very grave situation. However, a log of failed attempts for wiki data edits would have been helpful.