Skip to content

Upload failures after v2.8 #2013

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Closed
misaochan opened this issue Nov 19, 2018 · 10 comments
Closed

Upload failures after v2.8 #2013

misaochan opened this issue Nov 19, 2018 · 10 comments

Comments

@misaochan
Copy link
Member

misaochan commented Nov 19, 2018

It seems that we are still encountering upload failures after 2.8, albeit with much lower frequency. I had them today when testing #1968 (however, I created this issue because I don't think it is relevant to that PR, which doesn't alter the auth flow), and had them once on my real device recently.

Logs below from API 27 Nexus S emulator. Interestingly, after seeing this failure, I checked Achievements to see if I was indeed not logged in. However, Achievements works perfectly fine! So my conclusion is that it is the edit tokens that are the issue, not the actual login. @maskaravivek

11-19 18:40:27.026 30937-30980/fr.free.nrw.commons D/UploadService: Before execution!
11-19 18:40:27.044 30937-30980/fr.free.nrw.commons D/UploadService: making sure of uniqueness of name: Michio Kaku .jpg
11-19 18:40:27.362 30937-31499/fr.free.nrw.commons D/CustomApiResult: API response is
     <?xml version="1.0" encoding="UTF-8"?><api batchcomplete=""><query><pages><page _idx="-1" ns="0" title="Michio Kaku .jpg" missing=""/></pages></query></api>
11-19 18:40:27.947 30937-31499/fr.free.nrw.commons D/CustomApiResult: API response is
     <?xml version="1.0" encoding="UTF-8"?><api batchcomplete=""><query><pages><page _idx="-1" ns="0" title="Michio Kaku.jpg" missing=""/></pages></query></api>
11-19 18:40:28.068 30937-30980/fr.free.nrw.commons D/CustomApiResult: API response is
     <?xml version="1.0" encoding="UTF-8"?><api batchcomplete=""><query><pages><page _idx="-1" ns="6" title="File:Michio Kaku .jpg" missing="" imagerepository=""/></pages></query></api>
11-19 18:40:28.558 30937-30980/fr.free.nrw.commons D/CustomApiResult: API response is
     <?xml version="1.0" encoding="UTF-8"?><api batchcomplete=""><query><userinfo id="0" name="[IP address]" anon=""/></query></api>
11-19 18:40:28.583 30937-30980/fr.free.nrw.commons D/CustomMwApi: User id is 0 and user name is [IP address]
11-19 18:40:28.584 30937-30980/fr.free.nrw.commons D/ApacheHttpClientMediaWi: Validate login response is false
11-19 18:40:28.585 30937-30980/fr.free.nrw.commons D/UploadService: Successfully revalidated token!
11-19 18:40:29.292 30937-30980/fr.free.nrw.commons D/CustomApiResult: API response is
     <?xml version="1.0" encoding="UTF-8"?><api servedby="mw1345"><error code="notloggedin" info="Anonymous users cannot obtain a centralauthtoken." xml:space="preserve">See https://commons.wikimedia.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>
11-19 18:40:29.306 30937-30980/fr.free.nrw.commons D/ApacheHttpClientMediaWi: MediaWiki Central auth token is 
11-19 18:40:29.321 30937-30980/fr.free.nrw.commons E/ApacheHttpClientMediaWi: Error occurred while fetching auth token. Error code is notloggedin and message is Anonymous users cannot obtain a centralauthtoken.
11-19 18:40:29.796 30937-30980/fr.free.nrw.commons D/CustomApiResult: API response is
     <?xml version="1.0" encoding="UTF-8"?><api servedby="mw1343"><error code="notloggedin" info="Anonymous users cannot obtain a centralauthtoken." xml:space="preserve">See https://commons.wikimedia.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>
11-19 18:40:29.802 30937-30980/fr.free.nrw.commons D/ApacheHttpClientMediaWi: MediaWiki Central auth token is 
11-19 18:40:29.816 30937-30980/fr.free.nrw.commons E/ApacheHttpClientMediaWi: Error occurred while fetching auth token. Error code is notloggedin and message is Anonymous users cannot obtain a centralauthtoken.
11-19 18:40:30.305 30937-30980/fr.free.nrw.commons D/CustomApiResult: API response is
     <?xml version="1.0" encoding="UTF-8"?><api servedby="mw1317"><error code="badtoken" info="The centralauthtoken is not valid." xml:space="preserve">See https://commons.wikimedia.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>
11-19 18:40:30.335 30937-30980/fr.free.nrw.commons D/ApacheHttpClientMediaWi: MediaWiki edit token is 
11-19 18:40:30.499 30937-30980/fr.free.nrw.commons D/UploadService$Notificat: Uploaded 26531 of 794431
11-19 18:40:30.539 30937-30980/fr.free.nrw.commons D/UploadService$Notificat: Uploaded 51107 of 794431
11-19 18:40:30.575 26161-26161/system_process E/NotificationService: Muting recently noisy 0|fr.free.nrw.commons|1|null|10090
11-19 18:40:30.628 30937-30980/fr.free.nrw.commons D/UploadService$Notificat: Uploaded 75683 of 794431
11-19 18:40:30.717 30937-30980/fr.free.nrw.commons D/UploadService$Notificat: Uploaded 100259 of 794431
11-19 18:40:30.906 30937-30980/fr.free.nrw.commons D/UploadService$Notificat: Uploaded 124835 of 794431
11-19 18:40:31.253 30937-30969/fr.free.nrw.commons I/zygote: Waiting for a blocking GC Explicit
11-19 18:40:31.296 30937-30980/fr.free.nrw.commons D/UploadService$Notificat: Uploaded 149411 of 794431
11-19 18:40:31.435 30937-30980/fr.free.nrw.commons D/UploadService$Notificat: Uploaded 173987 of 794431
11-19 18:40:31.580 30937-30980/fr.free.nrw.commons D/UploadService$Notificat: Uploaded 198563 of 794431
11-19 18:40:31.599 30937-30949/fr.free.nrw.commons I/zygote: Background concurrent copying GC freed 117135(5MB) AllocSpace objects, 38(760KB) LOS objects, 43% free, 7MB/13MB, paused 681us total 1.005s
11-19 18:40:31.599 30937-30969/fr.free.nrw.commons I/zygote: WaitForGcToComplete blocked Explicit on HeapTrim for 346.940ms
11-19 18:40:31.695 30937-30980/fr.free.nrw.commons D/UploadService$Notificat: Uploaded 223139 of 794431
11-19 18:40:31.783 30937-30980/fr.free.nrw.commons D/UploadService$Notificat: Uploaded 247715 of 794431
11-19 18:40:31.884 30937-30980/fr.free.nrw.commons D/UploadService$Notificat: Uploaded 272291 of 794431
11-19 18:40:32.072 30937-30980/fr.free.nrw.commons D/UploadService$Notificat: Uploaded 296867 of 794431
11-19 18:40:32.300 30937-30980/fr.free.nrw.commons D/UploadService$Notificat: Uploaded 321443 of 794431
11-19 18:40:32.337 30937-30969/fr.free.nrw.commons I/zygote: Explicit concurrent copying GC freed 28046(1214KB) AllocSpace objects, 0(0B) LOS objects, 45% free, 7MB/13MB, paused 3.833ms total 736.588ms
11-19 18:40:32.399 30937-30980/fr.free.nrw.commons D/UploadService$Notificat: Uploaded 346019 of 794431
11-19 18:40:32.485 30937-30980/fr.free.nrw.commons D/UploadService$Notificat: Uploaded 370595 of 794431
11-19 18:40:32.746 30937-30980/fr.free.nrw.commons D/UploadService$Notificat: Uploaded 395171 of 794431
11-19 18:40:32.761 30937-31500/fr.free.nrw.commons D/CustomApiResult: API response is
     <?xml version="1.0" encoding="UTF-8"?><api batchcomplete=""><query><pages><page _idx="-1" ns="0" title="Michio Kaku .jpg" missing=""/></pages></query></api>
11-19 18:40:32.876 30937-30980/fr.free.nrw.commons D/UploadService$Notificat: Uploaded 419747 of 794431
11-19 18:40:33.017 30937-30980/fr.free.nrw.commons D/UploadService$Notificat: Uploaded 444323 of 794431
11-19 18:40:33.260 30937-30980/fr.free.nrw.commons D/UploadService$Notificat: Uploaded 468899 of 794431
11-19 18:40:33.557 30937-30980/fr.free.nrw.commons D/UploadService$Notificat: Uploaded 493475 of 794431
11-19 18:40:33.885 30937-30980/fr.free.nrw.commons D/UploadService$Notificat: Uploaded 518051 of 794431
11-19 18:40:34.065 30937-30980/fr.free.nrw.commons D/UploadService$Notificat: Uploaded 542627 of 794431
11-19 18:40:34.120 30937-30980/fr.free.nrw.commons D/UploadService$Notificat: Uploaded 567203 of 794431
11-19 18:40:34.305 30937-30980/fr.free.nrw.commons D/UploadService$Notificat: Uploaded 591779 of 794431
11-19 18:40:34.437 30937-30980/fr.free.nrw.commons D/UploadService$Notificat: Uploaded 616355 of 794431
11-19 18:40:34.500 30937-30980/fr.free.nrw.commons D/UploadService$Notificat: Uploaded 640931 of 794431
11-19 18:40:34.573 30937-30980/fr.free.nrw.commons D/UploadService$Notificat: Uploaded 665507 of 794431
11-19 18:40:34.794 30937-30980/fr.free.nrw.commons D/UploadService$Notificat: Uploaded 690083 of 794431
11-19 18:40:35.181 30937-30980/fr.free.nrw.commons D/UploadService$Notificat: Uploaded 714659 of 794431
11-19 18:40:35.327 30937-30980/fr.free.nrw.commons D/UploadService$Notificat: Uploaded 739235 of 794431
11-19 18:40:35.516 30937-30980/fr.free.nrw.commons D/UploadService$Notificat: Uploaded 763811 of 794431
11-19 18:40:35.649 30937-30980/fr.free.nrw.commons D/UploadService$Notificat: Uploaded 788387 of 794431
11-19 18:40:35.652 30937-31499/fr.free.nrw.commons D/CustomApiResult: API response is
     <?xml version="1.0" encoding="UTF-8"?><api batchcomplete=""><query><pages><page _idx="-1" ns="0" title="Michio Kaku .jpg" missing=""/></pages></query></api>
11-19 18:40:35.746 30937-30980/fr.free.nrw.commons D/UploadService$Notificat: Uploaded 794431 of 794431
11-19 18:40:36.822 30937-31499/fr.free.nrw.commons D/CustomApiResult: API response is
     <?xml version="1.0" encoding="UTF-8"?><api batchcomplete=""><query><pages><page _idx="-1" ns="0" title="Michio Kaku.jpg" missing=""/></pages></query></api>
11-19 18:40:37.338 30937-31499/fr.free.nrw.commons D/CustomApiResult: API response is
     <?xml version="1.0" encoding="UTF-8"?><api batchcomplete=""><query><pages><page _idx="-1" ns="0" title="Michio Kaku .jpg" missing=""/></pages></query></api>
11-19 18:40:37.876 30937-31499/fr.free.nrw.commons D/CustomApiResult: API response is
     <?xml version="1.0" encoding="UTF-8"?><api batchcomplete=""><query><pages><page _idx="-1" ns="0" title="Michio Kaku .jpg" missing=""/></pages></query></api>
11-19 18:40:38.070 30937-30980/fr.free.nrw.commons D/CustomApiResult: API response is
     <?xml version="1.0" encoding="UTF-8"?><api servedby="mw1223"><error code="badtoken" info="The centralauthtoken is not valid." xml:space="preserve">See https://commons.wikimedia.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>
11-19 18:40:38.072 30937-30980/fr.free.nrw.commons E/ApacheHttpClientMediaWi: Result: fr.free.nrw.commons.mwapi.CustomApiResult@6dbe234
11-19 18:40:35.821 26161-26161/system_process E/NotificationService: Muting recently noisy 0|fr.free.nrw.commons|1|null|10090
11-19 18:40:38.164 30937-30980/fr.free.nrw.commons E/ApacheHttpClientMediaWi: badtoken
@VojtechDostal
Copy link
Collaborator

Yep I had some upload failures yesterday.

@misaochan
Copy link
Member Author

@VojtechDostal Logging in and out again works for you, right? As a short-term measure we could add that suggestion to a "Failed upload" toast via #1556 so that other users aren't stuck not knowing what to do.

We will do an overhaul of the authentication flow in the next PG if approved.

@cascafico
Copy link

cascafico commented Nov 24, 2018

Logout and login doesn't solve upload failure, which happen say 2 out of 3 attempts.

@misaochan
Copy link
Member Author

misaochan commented Nov 24, 2018

@cascafico Hmm, interesting, so the failures are not constant for you? Are you in beta testing? If you are, could you please go to Settings > Send Logs > enable the permissions. Then restart app > try to upload > tap Send Logs again after you experience a failure? This will help us debug the cause of the failure for you.

Thanks!

@misaochan
Copy link
Member Author

Thanks for the logs. This is very strange, it is a badtoken error as well, but this is the first one I have seen that relogging does not fix.

@maskaravivek Could you please take a look at the logs as well? Thanks.

@misaochan
Copy link
Member Author

Btw, @cascafico , do you have 2FA enabled on your account by any chance?

@cascafico
Copy link

cascafico commented Nov 25, 2018 via email

@ashishkumar468
Copy link
Collaborator

@misaochan @maskaravivek @nicolas-raoul I was working on the upload issue, refactored the LoginActivity and UploadService, but none of it could actually solve the bad token issue. After debugging a lot, I could produce it and found that, even after fetching fresh c-auth token, we get a bad token error as if we are not logged in. I was hoping that some one who has more experience with the api's could suggest me a better approach to this. I would also recommend that we pick up a task of refactoring the network layer as it the code base it to coupled and prone to bugs.

@misaochan
Copy link
Member Author

As per discussion with @ashishkumar468 and @maskaravivek , our current plans for fixing this in PG 2019: Revamp network layer, at the very least the login/getToken APIs need to be migrated to OkHttp

@misaochan
Copy link
Member Author

Several users have reported this fixed. :) Closing, feel free to reopen if needed.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

4 participants