Skip to content

Upload fails often in 2.7 #1485

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 May 2, 2018 · 105 comments
Closed

Upload fails often in 2.7 #1485

misaochan opened this issue May 2, 2018 · 105 comments

Comments

@misaochan
Copy link
Member

misaochan commented May 2, 2018

Report from user on googlegroups
He says "Very often: Upload failed"

And has logs attached. Unfortunately I can't share them here without permission, but anyone who has signed the NDA that allows them to access our private group is welcome to check it there.

There are two issues here:

  1. The logs don't provide any meaningful information. It is completely cluttered by system logs, etc. This has been the case for logs provided by everyone else as well. Is it at all possible for us to filter for our app's logs programmatically in the "send logs" feature?

  2. The upload failing very often. I plan to ask him where he is uploading from (sd card, etc), and for screenshots if he can provide them. What other information do you guys think would be useful to solve the problem? @maskaravivek @psh @nicolas-raoul @neslihanturan

He isn't the only one with it - a recent Play Store review was from a user who encountered the same problem. So I would probably assign this issue a fairly high priority since this is our core functionality.

@nicolas-raoul
Copy link
Member

I actually also started to get failed uploads recently, when the new version was pushed to beta. Might be a coincidence though. Failed uploads were images I shared from the Android stock gallery.

@misaochan
Copy link
Member Author

misaochan commented May 2, 2018

@nicolas-raoul Ah, interesting. Can you reproduce this reliably? What steps did you use to share the image - was it by going to the gallery, selecting the image, tapping "Share" and then selecting the Commons app? Where were the images stored - SD card, device, google photos etc?

@neslihanturan
Copy link
Collaborator

This seems very interesting. I looked at commit histories of possibly related classes but couldn't recognized a big change. Implement direct uploads for Nearby Map #1060 seems like the biggest change but I don't think it break something on regular upload. What do you think @misaochan , is this possible?

Other than #1060 the reason can be a mistake made when merging or rebasing, or solving a leak.

@misaochan
Copy link
Member Author

Nearby uploads did not require significant changes to regular uploads, I think it's very unlikely that the small changes made would have caused the failures. Also, the review re: failed uploads was made while production was still in 2.6 - if that user was in beta, I'd think he would have used beta feedback instead of quitting beta just so he could post a regular review.

I will try and look at what might be causing this when I work on the upload overhaul. It would be very helpful to know where the images were stored etc. though.

@maskaravivek
Copy link
Member

@misaochan We could grep through his logs and check the relevant errors. Can you point me to the user(maybe on our team chat) whose logs needs to be checked?

@misaochan
Copy link
Member Author

misaochan commented May 3, 2018

Thanks for the suggestions, everyone! I'll create a separate issue for the logs. :)

I got back to the user asking a few questions, hopefully that will help us with the failed uploads.

@maskaravivek , I messaged you on Hangouts.

@maskaravivek
Copy link
Member

@misaochan Yes the logs are very less and there's almost nothing useful in the logs. I just see this logline multiple times.

23:46:54.215 28766 28794 E WTF     : Result: org.mediawiki.api.ApiResult@88326d205-01

I remember seeing this log a few times in the app when logs upload fails for me.

@ashishkumar468
Copy link
Collaborator

ashishkumar468 commented May 3, 2018

I tried to debug the issue [By uploading image from my google pixel emulator], it seems like there is an issue at the backend side, I am attaching the response xml which i am getting in the logs

<?xml version="1.0" encoding="UTF-8"?>
<api servedby="mw1278">
  <error code="abusefilter-disallowed" info="⧼abusefilter-warning-copyv2⧽" warning="&lt;p&gt;We could not determine whether this file is suitable for Wikimedia Commons. Please only upload photos that you took yourself with your camera, or see &lt;a href=&quot;/wiki/Special:MyLanguage/Commons:Licensing&quot; title=&quot;Special:MyLanguage/Commons:Licensing&quot;&gt;what else is acceptable&lt;/a&gt;. See the &lt;a href=&quot;/wiki/Special:MyLanguage/Commons:First_steps&quot; title=&quot;Special:MyLanguage/Commons:First steps&quot;&gt;guide&lt;/a&gt; to make sure the file is acceptable and learn how to upload it on Wikimedia Commons.&lt;/p&gt;&lt;p&gt;&lt;strong&gt;The content must be &lt;a href=&quot;/wiki/Special:MyLanguage/Commons:Licensing&quot; title=&quot;Special:MyLanguage/Commons:Licensing&quot;&gt;freely licensed&lt;/a&gt;. Don't copy files illegally (in violation of copyright) from the World Wide Web.&lt;/strong&gt;&lt;/p&gt;&#xA;&lt;p&gt;&lt;small&gt;If you believe that the file meets &lt;a href=&quot;/wiki/Commons:L&quot; class=&quot;mw-redirect&quot; title=&quot;Commons:L&quot;&gt;our licensing standards&lt;/a&gt;: Upload the file again or click &quot;Retry failed uploads&quot;/&quot;Submit modified file description&quot;.&lt;/small&gt;&lt;/p&gt;&#xA;" filekey="15py7xyvxdhw.4ztl85.6650319.jpg" sessionkey="15py7xyvxdhw.4ztl85.6650319.jpg">
     <message key="abusefilter-warning-copyv2">
        <params>
           <param>Small jpeg's uploaded by users with low editcount</param>
           <param>156</param>
        </params>
     </message>
     <abusefilter id="156" description="Small jpeg's uploaded by users with low editcount">
        <actions>
           <_v>throttle</_v>
           <_v>warn</_v>
        </actions>
     </abusefilter>
     <docref 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.</docref>
  </error>
</api>

As we can see from the xml, which says error code="abusefilter-disallowed, which hopefully states its a backend issue with some images.

@maskaravivek
Copy link
Member

The error posted by @ashishkumar468 looks interesting. Am not sure if the user's upload failed with the same error. We are not logging server failure responses so there's no way to tell why it failed for the user.

@misaochan
Copy link
Member Author

Just received permission from the user to repost his response to me. I think this will be very helpful:

Thema Workflow is Like this:

Make Photos by the way -> at Home (with working WLAN) Open google Photo -> senden Photo top snapseed -> Finish -> Share Button -> commons App -> Upload

After that the Progress bar moves bitte after some time "Upload failed"

After several tries i Made a logoff in the commons App. Then it worked. Perhaps the Automatik Login in commons App failed?

@misaochan
Copy link
Member Author

It seems that the common denominator in both the above post's user and @nicolas-raoul 's reports is that they both used "Share" instead of uploading directly from the app. @nicolas-raoul do you recall if you "Share"d one or multiple photos when it happened to you?

@nicolas-raoul
Copy link
Member

nicolas-raoul commented Jun 4, 2018 via email

@misaochan
Copy link
Member Author

Thanks @nicolas-raoul ! Do you also remember where your photo was stored (SD card or device)? Do you ever share from Google Photos?

@misaochan
Copy link
Member Author

misaochan commented Jun 7, 2018

I have had no luck with reproducing this bug on v2.7.1 (Android 7.0), despite experimenting with different ways of uploading via Share.

I have tried:

  • Stock gallery > select image (from device storage) > Share > Commons
  • Stock gallery > select image (from SD card) > Share > Commons
  • Google Photos > select image > Share > Commons
  • Stock gallery > select multiple images > Share > Commons

All of the above uploads succeeded.

Anyone have any idea how we can reproduce this? Otherwise I think it will be very difficult to solve this, at least not until we get Send Logs working in a more efficient manner so that people can send us useful logs of the failed uploads. #1489

@misaochan
Copy link
Member Author

misaochan commented Jun 8, 2018

I actually managed to reproduce this bug - by complete accident, while testing something else. The problem here is that this is the Play Store version 2.7.1 - I'm afraid to uninstall and build manually because then I might lose the reproduction.

But I can't seem to get any sort of useful logs in logcat from it. Logcat is running, but our app's process appears to be... hidden? Even when filtering for our package, I only get logs that aren't actually generated by our package. It isn't that it's too much spam, but I sorted through the spam and our own logs are virtually nonexistent.

Any idea what I'm doing wrong?

image

@misaochan
Copy link
Member Author

misaochan commented Jun 11, 2018

Well, I can't reproduce this anymore. :/ Guess we have to hope that #1592 works.

@neslihanturan
Copy link
Collaborator

neslihanturan commented Jun 11, 2018

@misaochan
Copy link
Member Author

misaochan commented Jun 26, 2018

I received a message on FB from a user who is experiencing this issue. She mentioned that the issue started a couple of months ago only, and about 99% of her uploads failed. She tried uninstalling and reinstalling the app, logging out and logging in again... none of that worked. So the issue may not be as simple as the auth token problem that we were assuming in #1592 . :/

She also says that while she normally uploads via "Share > Commons", her uploads from within the app itself fail as well.

Based on her and @nicolas-raoul 's comments, it seems like this would have been caused by one of the changes we made in 2.7.0 (which was released early May). The problem is that that release was a HUGE one and we don't know what the trigger could've been. It could have been related to the 2FA auth change, it could have been related to direct Nearby uploads, or it could even have been caused by one of the small changes to ShareActivity (like searching through other pictures for coordinates, etc).

Does anyone have any suggestions? I think that at the very least, along with the file system changes @neslihanturan is implementing, we need to implement a better feedback system for failed uploads. They should display to the user WHY they failed, in a manner that can be seen by the user, not just logs (which we cannot reliably obtain).

@nicolas-raoul
Copy link
Member

We could get this FB user to do bisection, in order to find the exact commit that triggers the problem.
If she can generate the APKs that would be the best, otherwise any volunteer to provide her with APKs every day or so until the commit is found? @sivaraam maybe?

@sivaraam
Copy link
Member

I wouldn't mind doing the bisect (given a reasonable range to bisect, of course) if the FB user is ready to take APKs daily and try and test if it has issues or not. I think it would be a little tricky if there they couldn't consistently state a yes/no for "Whether the issue occurs to them in this APK?".

BTW, I've actually faced this issue once before (last week when I wasn't poking around for #1654, think). I wasn't able to upload any images at all for some time and I had to re-install the app to make the issue go away. I tried to see if I could reproduce it now and I did see this happen again. I think a slightly wavery network might be behind this, I'm not sure though. My flow was something like,

  1. Share a photo from the Gallery using Commons and initiate the upload
  2. The upload gets interrupted by a bad network (I intentionally terminated the network while testing today)
  3. Then I cancel the upload in the app (If I remember correctly, even retrying the upload fails)
  4. I try to upload the same image again and the upload fails
  5. Then I cannot upload any image and I had to re-install the app to upload the images.

@nicolas-raoul
Copy link
Member

Even a very rough bisect would be better than nothing, starting with the APK of the previously released version :-) That would rule out (or not) server-side changes.

@misaochan
Copy link
Member Author

misaochan commented Jun 27, 2018

Thanks for volunteering, @sivaraam . :) Yes, I think the range would be between the 2.6.7 release and the 2.7.0 release.

I will talk to the user about this once she gets back to me on the previous question that I asked her re: 2FA. @sivaraam what is your preferred method of communication, can I link her to your on-wiki talk page?

@nicolas-raoul
Copy link
Member

How about communicating via the public mailing list? So that everybody can benefit from the insight or offer ideas.

@misaochan misaochan reopened this Aug 16, 2018
@VaishSiddharth
Copy link
Contributor

VaishSiddharth commented Aug 16, 2018

@misaochan Please have a look.

https://phabricator.wikimedia.org/P7465

@misaochan
Copy link
Member Author

How strange! The upload result says "Success". Does that image show up as "failed" for you, @VaishSiddharth ?

@sivaraam
Copy link
Member

@misaochan Are missing something, again?

@VaishSiddharth
Copy link
Contributor

@misaochan
video2gif_20180817_011757

@VaishSiddharth
Copy link
Contributor

@misaochan I have noticed that if i click back button immediately after "Commons App has stopped" pops up then the upload fails otherwise the upload is successfull but the app crashes as you can see.

@misaochan
Copy link
Member Author

@sivaraam I don't have the rights to create a custom visibility paste, and neither do most people who are posting their logs here. It would be extremely inconvenient to have to contact you or someone with those privileges every time we want to post any logs.

Perhaps we could start another issue to brainstorm how we can handle this better? An alternative could be modifying the interceptor class to obfuscate parts of the logs.

@misaochan
Copy link
Member Author

misaochan commented Aug 16, 2018

@VaishSiddharth Very interesting, thanks! Is it possible to get logs of the crash, and of the failed upload (same method as how you took logs of the successful one)? @sivaraam please feel free to create a custom paste for all of these logs if possible, thanks.

And, umm, Vaish, could you please check if you can upload through the upload wizard in your browser - https://commons.m.wikimedia.org/wiki/Commons:Upload_Wizard ? Because you are uploading files with bad titles, it is possible that you were banned, lol. It is generally not a good idea to upload nonsensical stuff to the prod server. ;)

Also, it seems our crash reporting system has ceased to work again. :/

@VaishSiddharth
Copy link
Contributor

@misaochan I uploaded an image successfully through upload wizard on browser. I think this means my account is not blocked.

@VaishSiddharth
Copy link
Contributor

VaishSiddharth commented Aug 17, 2018

@misaochan Please have a look.

https://phabricator.wikimedia.org/P7465

@misaochan
Copy link
Member Author

misaochan commented Aug 17, 2018

Hmm, so this is the crash you are getting all the time?

08-17 10:34:58.215 19826-19826/fr.free.nrw.commons E/AndroidRuntime: FATAL EXCEPTION: main
   Process: fr.free.nrw.commons, PID: 19826
   android.app.RemoteServiceException: Bad notification for startForeground: java.lang.RuntimeException: invalid channel for service notification: Notification(channel=null pri=0 contentView=null vibrate=null sound=null tick defaults=0x0 flags=0x52 color=0x00000000 vis=PRIVATE)
       at android.app.ActivityThread$H.handleMessage(ActivityThread.java:1780)
       at android.os.Handler.dispatchMessage(Handler.java:106)
       at android.os.Looper.loop(Looper.java:172)
       at android.app.ActivityThread.main(ActivityThread.java:6590)
       at java.lang.reflect.Method.invoke(Native Method)
       at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:438)
       at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:807)

I wonder how we can debug this. Our app package isn't mentioned in any part of the stack trace. :/ @maskaravivek @neslihanturan what do you think about this?

@VaishSiddharth Good to hear that your account is fine. ;) Could I please trouble you for one final log - a failed upload all the way up to the part that you copied for your successful upload. This part is very important:

    <<<<<<<<<<<<<< END OF REQUEST LOGGING [/w/api.php] >>>>>>>>>>>>
08-16 22:40:14.644 28268-28315/fr.free.nrw.commons D/UploadService$Notificat: Uploaded 6057 of 71699
08-16 22:40:14.677 28268-28315/fr.free.nrw.commons D/UploadService$Notificat: Uploaded 10153 of 71699
08-16 22:40:14.704 28268-28315/fr.free.nrw.commons D/UploadService$Notificat: Uploaded 14249 of 71699
08-16 22:40:14.722 28268-28315/fr.free.nrw.commons D/UploadService$Notificat: Uploaded 18345 of 71699
08-16 22:40:14.739 28268-28315/fr.free.nrw.commons D/UploadService$Notificat: Uploaded 22441 of 71699
08-16 22:40:14.756 28268-28315/fr.free.nrw.commons D/UploadService$Notificat: Uploaded 26537 of 71699
08-16 22:40:14.773 28268-28315/fr.free.nrw.commons D/UploadService$Notificat: Uploaded 30633 of 71699
08-16 22:40:14.790 28268-28315/fr.free.nrw.commons D/UploadService$Notificat: Uploaded 34729 of 71699
08-16 22:40:14.807 28268-28315/fr.free.nrw.commons D/UploadService$Notificat: Uploaded 38825 of 71699
08-16 22:40:14.825 28268-28315/fr.free.nrw.commons D/UploadService$Notificat: Uploaded 42921 of 71699
08-16 22:40:14.842 28268-28315/fr.free.nrw.commons D/UploadService$Notificat: Uploaded 47017 of 71699
08-16 22:40:14.860 28268-28315/fr.free.nrw.commons D/UploadService$Notificat: Uploaded 51113 of 71699
08-16 22:40:14.878 28268-28315/fr.free.nrw.commons D/UploadService$Notificat: Uploaded 55209 of 71699
08-16 22:40:14.897 28268-28315/fr.free.nrw.commons D/UploadService$Notificat: Uploaded 59305 of 71699
08-16 22:40:14.918 28268-28315/fr.free.nrw.commons D/UploadService$Notificat: Uploaded 63401 of 71699
08-16 22:40:14.937 28268-28315/fr.free.nrw.commons D/UploadService$Notificat: Uploaded 67497 of 71699
08-16 22:40:14.954 28268-28315/fr.free.nrw.commons D/UploadService$Notificat: Uploaded 71593 of 71699
08-16 22:40:14.972 28268-28315/fr.free.nrw.commons D/UploadService$Notificat: Uploaded 71699 of 71699
08-16 22:40:17.816 28268-28315/fr.free.nrw.commons E/WTF: Result: fr.free.nrw.commons.mwapi.CustomApiResult@6f34c2f
08-16 22:40:17.824 28268-28315/fr.free.nrw.commons E/ContributionUtils: removeTemporaryFile() parameters: URI tempFileUri file:///storage/emulated/0/UploadingByCommonsApp/153443939652_tmp, deleted status true
08-16 22:40:17.847 28268-28315/fr.free.nrw.commons D/UploadService: Response is fr.free.nrw.commons.mwapi.UploadResult@227f23c
08-16 22:40:17.848 28268-28315/fr.free.nrw.commons D/UploadService: Contribution upload success. Initiating Wikidata edit for entity id null
08-16 22:40:17.848 28268-28315/fr.free.nrw.commons D/WikidataEditService: Skipping creation of claim as Wikidata entity ID is null

Also please don't be alarmed if we edit your post later, as we will be moving the logs to a custom visibility page.

Thanks so much!

@VaishSiddharth
Copy link
Contributor

@misaochan If i press the back button immediately after the app crash then the upload fails but if the back button is not pressed the upload is successful. I am not able to understand how can I share the logs of both failed and successful uploads at the same time.

@misaochan
Copy link
Member Author

@VaishSiddharth Try this: Start the upload, let it crash, then press back button immediately, watch the upload status change to "failed", then copy all the logs?

If you could email me your logs, once @maskaravivek gets a custom paste up, I can post them there. :)

@VaishSiddharth
Copy link
Contributor

@misaochan Should I mail you the logs or paste them here? I dont have your email id.

@sivaraam
Copy link
Member

Perhaps we could start another issue to brainstorm how we can handle this better? An alternative could be modifying the interceptor class to obfuscate parts of the logs.

@misaochan That's the best thing we should be doing as a long term solution.

@sivaraam
Copy link
Member

@sivaraam please feel free to create a custom paste for all of these logs if possible, thanks.

@misaochan Just for the sake of completeness, I do not have permissions to create a paste with a custom policy. But as you now seem to be aware @maskaravivek does.

@sivaraam
Copy link
Member

@misaochan Should I mail you the logs or paste them here? I dont have your email id.

@VaishSiddharth You could get a hint here

@misaochan
Copy link
Member Author

Thanks for emailing me @VaishSiddharth

@maskaravivek Could we get a custom visibility paste up on Phab, please?

@maskaravivek
Copy link
Member

@misaochan I have added you to trusted contributors list on phab. Now you should be able to create a paste with custom visibility. https://phabricator.wikimedia.org/project/members/3104/

@misaochan
Copy link
Member Author

Thanks! Paste is at https://phabricator.wikimedia.org/P7465 and I have given @maskaravivek , @neslihanturan and @nicolas-raoul access. If anyone else needs it, please ask.

@maskaravivek
Copy link
Member

From the logs it looks that the crash is happening because of the notifications issue @whym recently fixed.


08-17 10:34:58.215 19826-19826/fr.free.nrw.commons E/AndroidRuntime: FATAL EXCEPTION: main
--
Process: fr.free.nrw.commons, PID: 19826
android.app.RemoteServiceException: Bad notification for startForeground: java.lang.RuntimeException: invalid channel for service notification: Notification(channel=null pri=0 contentView=null vibrate=null sound=null tick defaults=0x0 flags=0x52 color=0x00000000 vis=PRIVATE)
at android.app.ActivityThread$H.handleMessage(ActivityThread.java:1780)
at android.os.Handler.dispatchMessage(Handler.java:106)
at android.os.Looper.loop(Looper.java:172)
at android.app.ActivityThread.main(ActivityThread.java:6590)
at java.lang.reflect.Method.invoke(Native Method)
at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:438)
at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:807)

@whym's fix was merged on August 19th.

@VaishSiddharth I suspect that you are on API level >=26. Can you pull the latest upstream master and retry. The crash should no longer happen.

@whym
Copy link
Collaborator

whym commented Aug 20, 2018

@VaishSiddharth the fix is 6842420, in case you want to cherry-pick and try. :)

@VaishSiddharth
Copy link
Contributor

@whym @maskaravivek Thanks I will try :)

@Yannf
Copy link

Yannf commented Aug 24, 2018

Hi, I am one of the people who reported failed uploads. Now it mostly works with 2.8.1 but I got 3 uploads blocked as "queued". I can't cancel nor retry them.

@Yannf
Copy link

Yannf commented Aug 24, 2018

Now I uploaded the same files separately and it worked.

@Yannf
Copy link

Yannf commented Aug 24, 2018

Additionally the item stays in the dropdown menu even after the image uploaded alright.

@misaochan
Copy link
Member Author

Ah, sorry @Yannf I just saw your post here. I think this might be caused by the .png issue mentioned at #228 . That should be fixed in v2.9.

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