Skip to content

App stuck at "receiving shared content" #2033

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 26, 2018 · 49 comments · Fixed by #2262
Closed

App stuck at "receiving shared content" #2033

misaochan opened this issue Nov 26, 2018 · 49 comments · Fixed by #2262
Labels

Comments

@misaochan
Copy link
Member

Summary:

Occasionally, after selecting an image to upload in 2.9-release, I get stuck at the "Receiving shared content" page. I can't find any pattern to when it happens (probably 1 in 10 uploads), and retrying with the same image usually works.

System logs:

2018-11-26 04:07:34,881     [DEBUG] [file-logging-thread-1] [ContributionController] : startMultipleGalleryPick() called with pickImageIntent
2018-11-26 04:07:38,380     [DEBUG] [file-logging-thread-1] [ContributionsListFragme] : OnActivityResult() parameters: Req code: 3 Result code: -1 Data: Intent { dat=content://com.android.providers.media.documents/document/image:24183 flg=0x1 }
2018-11-26 04:07:38,382     [DEBUG] [file-logging-thread-1] [ContributionController] : handleImagePicked() called with onActivityResult(). Boolean isDirectUpload: falseString wikiDataEntityId: null
2018-11-26 04:07:38,390     [INFO ] [file-logging-thread-1] [ContributionController] : Image selected
2018-11-26 04:07:38,392     [DEBUG] [file-logging-thread-1] [ContributionController] : Put extras into image intent, isDirectUpload is false
2018-11-26 04:07:38,405     [DEBUG] [file-logging-thread-1] [ContributionsListFragme] : OnActivityResult() parameters: Req code: 65539 Result code: -1 Data: Intent { dat=content://com.android.providers.media.documents/document/image:24183 flg=0x1 }
2018-11-26 04:07:38,409     [DEBUG] [file-logging-thread-1] [ContributionsFragment] : GPS is enabled
2018-11-26 04:07:38,582     [DEBUG] [file-logging-thread-1] [ExternalStorageUtils] : External storage permission granted, API >= 23
2018-11-26 04:07:38,583     [INFO ] [file-logging-thread-1] [DexterPermissionObtaine] : Storage permissions already granted.
2018-11-26 04:07:38,584     [INFO ] [file-logging-thread-1] [UploadActivity] : Received single upload
2018-11-26 04:07:38,590     [DEBUG] [file-logging-thread-1] [ExternalStorageUtils] : External storage permission granted, API >= 23
2018-11-26 04:07:38,591     [INFO ] [file-logging-thread-1] [DexterPermissionObtaine] : Storage permissions already granted.
2018-11-26 04:07:38,593     [INFO ] [file-logging-thread-1] [UploadPresenter] : uploadModel.getCount():0
2018-11-26 04:07:38,594     [DEBUG] [file-logging-thread-1] [UploadActivity] : Position: 2 Attribution-ShareAlike 3.0
2018-11-26 04:07:38,598     [INFO ] [file-logging-thread-1] [UploadPresenter] : Updating content for currentPage1
2018-11-26 04:07:38,623     [DEBUG] [file-logging-thread-1] [FileUtils] : Filepath (copied): /storage/emulated/0/CommonsApp/1543169258597.jpg
2018-11-26 04:07:38,627     [INFO ] [file-logging-thread-1] [UploadModel] : File path is /storage/emulated/0/CommonsApp/1543169258597.jpg
2018-11-26 04:07:38,644     [DEBUG] [file-logging-thread-1] [FileProcessor] : Calling GPSExtractor
2018-11-26 04:07:38,647     [DEBUG] [file-logging-thread-1] [FileProcessor] : filePath/storage/emulated/0/CommonsApp/1543169258597.jpg
2018-11-26 04:07:38,651     [DEBUG] [file-logging-thread-1] [FileProcessor] : folderTime Number:19
2018-11-26 04:07:38,655     [DEBUG] [file-logging-thread-1] [FileProcessor] : fild date:1543169258000 time of creation1543169258000
2018-11-26 04:07:38,658     [DEBUG] [file-logging-thread-1] [FileProcessor] : not null fild EXIFfalse coordsnull
2018-11-26 04:07:38,660     [INFO ] [file-logging-thread-1] [FileUtils] : File SHA1: ad67b9b392a8c7e69ac00d2ba9d3dc2549871dc9
2018-11-26 04:07:39,146     [DEBUG] [file-logging-thread-1] [CategoriesModel] : Direct category found: Fortitude Valley, Queensland
    
2018-11-26 04:07:39,148     [DEBUG] [file-logging-thread-1] [CategoriesModel] : DirectCat does not equal emptyString. Direct Cat list has [Fortitude Valley, Queensland
    ]
2018-11-26 04:07:39,150     [DEBUG] [file-logging-thread-1] [CategoriesModel] : Image has direct Cat
2018-11-26 04:07:39,183     [DEBUG] [file-logging-thread-1] [CategoriesModel] : Previous year: 2017
2018-11-26 04:07:39,205     [DEBUG] [file-logging-thread-1] [CategoriesModel] : Previous year: 2017
2018-11-26 04:07:39,217     [DEBUG] [file-logging-thread-1] [CategoriesModel] : Previous year: 2017
2018-11-26 04:07:39,221     [DEBUG] [file-logging-thread-1] [CategoriesModel] : Previous year: 2017
2018-11-26 04:07:39,224     [DEBUG] [file-logging-thread-1] [CategoriesModel] : Previous year: 2017
2018-11-26 04:07:39,226     [DEBUG] [file-logging-thread-1] [CustomApiResult] : API response is
 <?xml version="1.0" encoding="UTF-8"?><api batchcomplete=""><query><userinfo id="6998903" name="Misaochan2"/></query></api>
2018-11-26 04:07:39,227     [DEBUG] [file-logging-thread-1] [CategoriesModel] : Previous year: 2017
2018-11-26 04:07:39,229     [DEBUG] [file-logging-thread-1] [CategoriesModel] : Previous year: 2017
2018-11-26 04:07:39,230     [DEBUG] [file-logging-thread-1] [CategoriesModel] : Previous year: 2017
2018-11-26 04:07:39,232     [DEBUG] [file-logging-thread-1] [CategoriesModel] : Previous year: 2017
2018-11-26 04:07:39,234     [DEBUG] [file-logging-thread-1] [CategoriesModel] : Previous year: 2017
2018-11-26 04:07:39,373     [DEBUG] [file-logging-thread-1] [CustomApiResult] : API response is
 <?xml version="1.0" encoding="UTF-8"?><api batchcomplete=""><query><allimages/></query></api>
2018-11-26 04:07:39,707     [DEBUG] [file-logging-thread-1] [ImageUtils] : total 12192768
2018-11-26 04:07:39,836     [INFO ] [file-logging-thread-1] [UploadPresenter] : uploadModel.getCount():1
2018-11-26 04:07:39,847     [DEBUG] [file-logging-thread-1] [UploadActivity] : Position: 2 Attribution-ShareAlike 3.0
2018-11-26 04:07:39,857     [INFO ] [file-logging-thread-1] [UploadPresenter] : Updating content for currentPage1
2018-11-26 04:07:40,132     [INFO ] [file-logging-thread-1] [DescriptionsAdapter$Vie] : descItemEditText:fr.free.nrw.commons.ui.widget.CustomEditText{8f9f55c VFED..CL. ......I. 0,0-0,0 #7f090092 app:id/description_item_edit_text}
2018-11-26 04:07:40,136     [DEBUG] [file-logging-thread-1] [DescriptionsAdapter$Vie] : Description is fr.free.nrw.commons.upload.Description@c57b065
2018-11-26 04:07:40,454     [INFO ] [file-logging-thread-1] [DescriptionsAdapter$Vie] : descItemEditText:fr.free.nrw.commons.ui.widget.CustomEditText{498f363 VFED..CL. ......I. 0,0-0,0 #7f090092 app:id/description_item_edit_text}
2018-11-26 04:07:40,457     [DEBUG] [file-logging-thread-1] [DescriptionsAdapter$Vie] : Title is null

Device and Android version:

Samsung Galaxy s7 API 26

Commons app version:

2.9-release prodRelease

Would you like to work on the issue?

Pref not

@misaochan misaochan added the bug label Nov 26, 2018
@sivaraam
Copy link
Member

I faced this issue, too. Specifically, I saw it the first time I tried to upload in v2.9.0. I thought it would never finish but it did after about 30 seconds. That's a long time and might make first time users of the app think it's not useful at all. So, I guess it would be nice to explore the issue and fix it.

Also, I guess the message could be displayed more prominently in the center rather than at the bottom as there is a lot of space. It was very tiny regardless of the lot of space available to display it.

@misaochan
Copy link
Member Author

Ah, thanks for reporting @sivaraam ! I added it to our list of hotfixes. I do agree that it shouldn't be taking that long, especially when we're not even uploading the picture yet at that stage.

If you could Send Logs the next time it happens for you, that would be fantastic. :)

@sivaraam
Copy link
Member

I tried to reproduce this. I guess I'm getting a long delay for new images that I try to upload. I'm not sure but it seems like that to me. Unfortunately I don't have a log that captures one specific upload that took a long time. It might be cluttered with other ones too (that may/may not have taken a long time). I will share if I could capture a log specifically. Let me know if you're ok with the cluttered one too.

BTW, I see that the app crashes when trying to upload images of bigger sizes (>=4MB). I'm not sure why. I've submitted a bug report for the crash. This is too odd and I guess it should be fixed before the v2.9 leaves beta.

@maskaravivek
Copy link
Member

@sivaraam Does the app consistently crash for you for images >=4MB

@misaochan
Copy link
Member Author

Hi @sivaraam , could you use Send Logs to send us the logs immediately after a crash please? The crash reporting system unfortunately needs some work. :/

@sivaraam
Copy link
Member

@sivaraam Does the app consistently crash for you for images >=4MB

The app does crash consistently but the case the scenario is a little different. Actually, I stated that the app crashed when I tried to upload images greater than 4MB because it crashed repeatedly when I tried to upload two images whose sizes were around 4MB and 14MB. Those images were to downloaded from commons. I also tried to download images from the web and tried to see when the app crashed. It consistently crashes when try to upload an image whose size is greater than 2MB. Note that it crashes in the "Receiving shared content" page itself. I never see the 3 steps page.

You could find the images for which I consistently see the app crash in the following link:
https://drive.google.com/drive/folders/1oe59ZN3afn2h5ycYyrpVCLxmiESVua-9

Hi @sivaraam , could you use Send Logs to send us the logs immediately after a crash please? The crash reporting system unfortunately needs some work. :/

Ok. I've sent the email. I guess I should attach the file present within the 'logs/prod' folder in my device's 'Download' directory. Tapping on 'Send logs' just filled in the email address, subject, message body. No files were attached. So, I just wanted to be sure.

@misaochan
Copy link
Member Author

Strange, normally it is a zip file and it is always automatically attached to the email for me. @maskaravivek any idea why he's only getting one of the files?

@sivaraam
Copy link
Member

sivaraam commented Nov 30, 2018

FWIW, I use K-9 mail as my email client.

@sivaraam
Copy link
Member

BTW, I've forgot to mention that there were several files in the logs/prod folder. I moved the existing folder. Then opened the app to reproduce the crash and attached the only file that was created after that.

@misaochan
Copy link
Member Author

I just had this issue (progress bar loading forever, not the crash) happen to me again. It seems that it happens after a permission request and approval (API 26 Samsung Galaxy S7). The upload screen literally NEVER loads, I left it on for 2 min. Logs below.

12-03 19:07:54.673 21815-21815/fr.free.nrw.commons E/UploadPresenter$$Lambda: java.lang.NullPointerException: uri
        at com.android.internal.util.Preconditions.checkNotNull(Preconditions.java:128)
        at android.content.ContentResolver.openAssetFileDescriptor(ContentResolver.java:1233)
        at android.content.ContentResolver.openFileDescriptor(ContentResolver.java:1106)
        at android.content.ContentResolver.openFileDescriptor(ContentResolver.java:1060)
        at fr.free.nrw.commons.upload.FileUtils.createCopyPathAndCopy(FileUtils.java:104)
        at fr.free.nrw.commons.upload.UploadModel.cacheFileUpload(UploadModel.java:342)
12-03 19:07:54.674 21815-21815/fr.free.nrw.commons E/UploadPresenter$$Lambda:     at fr.free.nrw.commons.upload.UploadModel.receiveDirect(UploadModel.java:114)
        at fr.free.nrw.commons.upload.UploadPresenter.lambda$receiveDirect$4$UploadPresenter(UploadPresenter.java:96)
        at fr.free.nrw.commons.upload.UploadPresenter$$Lambda$3.run(Unknown Source:14)
        at io.reactivex.internal.operators.completable.CompletableFromRunnable.subscribeActual(CompletableFromRunnable.java:35)
        at io.reactivex.Completable.subscribe(Completable.java:2171)
        at com.tspoon.traceur.CompletableOnAssembly.subscribeActual(CompletableOnAssembly.java:41)
        at io.reactivex.Completable.subscribe(Completable.java:2171)
        at io.reactivex.internal.operators.completable.CompletableSubscribeOn$SubscribeOnObserver.run(CompletableSubscribeOn.java:64)
        at io.reactivex.Scheduler$DisposeTask.run(Scheduler.java:579)
        at io.reactivex.internal.schedulers.ScheduledRunnable.run(ScheduledRunnable.java:66)
        at io.reactivex.internal.schedulers.ScheduledRunnable.call(ScheduledRunnable.java:57)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:301)
12-03 19:07:54.674 3195-3195/? I/Layer: id=35 onRemoved fr.free.nrw.commons/fr.free.nrw.commons.upload.UploadActivity_dim#0 
12-03 19:07:54.674 21815-21815/fr.free.nrw.commons E/UploadPresenter$$Lambda:     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
12-03 19:07:54.674 3195-3195/? I/Layer: id=30 onRemoved fr.free.nrw.commons/fr.free.nrw.commons.contributions.MainActivity#0 
12-03 19:07:54.674 21815-21815/fr.free.nrw.commons E/UploadPresenter$$Lambda:     at dalvik.system.VMStack.getThreadStackTrace(Native Method)
        at java.lang.Thread.getStackTrace(Thread.java:1536)
        at io.reactivex.Completable.fromRunnable(Completable.java:492)
        at fr.free.nrw.commons.upload.UploadPresenter.receiveDirect(UploadPresenter.java:96)
        at fr.free.nrw.commons.upload.UploadActivity.receiveSharedItems(UploadActivity.java:556)
        at fr.free.nrw.commons.upload.UploadActivity.bridge$lambda$0$UploadActivity(Unknown Source:0)
        at fr.free.nrw.commons.upload.UploadActivity$$Lambda$0.run(Unknown Source:2)
        at io.reactivex.internal.observers.CallbackCompletableObserver.onComplete(CallbackCompletableObserver.java:54)
        at io.reactivex.subjects.CompletableSubject.onComplete(CompletableSubject.java:139)
        at fr.free.nrw.commons.upload.DexterPermissionObtainer$1.onPermissionGranted(DexterPermissionObtainer.java:94)
        at com.karumi.dexter.MultiplePermissionsListenerToPermissionListenerAdapter.onPermissionsChecked(Unknown Source:35)
12-03 19:07:54.674 3195-3195/? I/Layer: id=32 onRemoved Background for - SurfaceView - fr.free.nrw.commons/fr.free.nrw.commons.contributions.MainActivity@a0e296f@1#0 
12-03 19:07:54.674 21815-21815/fr.free.nrw.commons E/UploadPresenter$$Lambda:     at com.karumi.dexter.MultiplePermissionListenerThreadDecorator$1.run(Unknown Source:8)
        at com.karumi.dexter.MainThread.execute(Unknown Source:6)
        at com.karumi.dexter.MultiplePermissionListenerThreadDecorator.onPermissionsChecked(Unknown Source:7)
12-03 19:07:54.674 3195-3195/? I/Layer: id=31 onRemoved SurfaceView - fr.free.nrw.commons/fr.free.nrw.commons.contributions.MainActivity@a0e296f@1#0 
12-03 19:07:54.674 21815-21815/fr.free.nrw.commons E/UploadPresenter$$Lambda:     at com.karumi.dexter.DexterInstance.onPermissionsChecked(Unknown Source:57)
        at com.karumi.dexter.DexterInstance.updatePermissionsAsGranted(Unknown Source:26)
        at com.karumi.dexter.DexterInstance.onPermissionRequestGranted(Unknown Source:0)
        at com.karumi.dexter.Dexter.onPermissionsRequested(Unknown Source:6)
        at com.karumi.dexter.DexterActivity.onRequestPermissionsResult(Unknown Source:46)
        at android.app.Activity.dispatchRequestPermissionsResult(Activity.java:7728)
        at android.app.Activity.dispatchActivityResult(Activity.java:7551)
        at android.app.ActivityThread.deliverResults(ActivityThread.java:4487)
        at android.app.ActivityThread.handleSendResult(ActivityThread.java:4534)
        at android.app.ActivityThread.-wrap20(Unknown Source:0)
        at android.app.ActivityThread$H.handleMessage(ActivityThread.java:1752)
        at android.os.Handler.dispatchMessage(Handler.java:105)
        at android.os.Looper.loop(Looper.java:164)
        at android.app.ActivityThread.main(ActivityThread.java:6944)
        at java.lang.reflect.Method.invoke(Native Method)
        at com.android.internal.os.Zygote$MethodAndArgsCaller.run(Zygote.java:327)
        at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:1374)
    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.Completable.subscribeOn(Completable.java:2292)
        at fr.free.nrw.commons.upload.UploadPresenter.receiveDirect(UploadPresenter.java:97)
    	... 27 more
    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.Completable.observeOn(Completable.java:1760)
        at fr.free.nrw.commons.upload.UploadPresenter.receiveDirect(UploadPresenter.java:98)
    	... 27 more
12-03 19:07:54.675 21815-21815/fr.free.nrw.commons D/ViewRootImpl@6ea05c2[DexterActivity]: MSG_WINDOW_FOCUS_CHANGED 0
12-03 19:07:54.684 21815-21815/fr.free.nrw.commons D/ViewRootImpl@ac39d65[UploadActivity]: MSG_WINDOW_FOCUS_CHANGED 1
12-03 19:07:54.691 21815-21815/fr.free.nrw.commons I/InputMethodManager: startInputInner - mService.startInputOrWindowGainedFocus
12-03 19:07:54.695 21815-21815/fr.free.nrw.commons D/ExternalStorageUtils: External storage permission granted, API >= 23
12-03 19:07:54.695 21815-21815/fr.free.nrw.commons I/DexterPermissionObtaine: Storage permissions already granted.
12-03 19:07:54.695 21815-21815/fr.free.nrw.commons I/UploadPresenter: uploadModel.getCount():0
12-03 19:07:54.697 21815-21820/fr.free.nrw.commons I/zygote64: Do partial code cache collection, code=1907KB, data=1163KB
12-03 19:07:54.699 21815-21820/fr.free.nrw.commons I/zygote64: After code cache collection, code=1907KB, data=1163KB
    Increasing code cache capacity to 5MB
12-03 19:07:54.720 21815-21815/fr.free.nrw.commons D/InputMethodManager: HSIFW - flag : 0 Pid : 21815
12-03 19:07:54.722 21815-21815/fr.free.nrw.commons I/InputMethodManager: startInputInner - mService.startInputOrWindowGainedFocus
12-03 19:07:54.728 21815-21815/fr.free.nrw.commons D/UploadActivity: Position: 2 Attribution-ShareAlike 3.0
12-03 19:07:54.731 21815-21815/fr.free.nrw.commons I/UploadPresenter: Updating content for currentPage1
12-03 19:07:54.732 21815-21815/fr.free.nrw.commons I/InputMethodManager: startInputInner - mService.startInputOrWindowGainedFocus
12-03 19:07:54.734 21815-21815/fr.free.nrw.commons E/BitmapFactory: Unable to decode stream: java.io.FileNotFoundException:  (No such file or directory)
12-03 19:07:54.734 21815-21815/fr.free.nrw.commons W/ImageView: resolveUri failed on bad bitmap uri: 
12-03 19:07:54.748 21815-21815/fr.free.nrw.commons D/ViewRootImpl@d0fe562[MainActivity]: Relayout returned: old=[0,0][1080,1920] new=[0,0][1080,1920] result=0x1 surface={valid=false 0} changed=false
12-03 19:07:54.759 21815-21815/fr.free.nrw.commons D/ViewRootImpl@ac39d65[UploadActivity]: Relayout returned: old=[0,0][1080,1920] new=[0,0][1080,1920] result=0x1 surface={valid=true 481647923200} changed=false
12-03 19:07:54.775 3632-3772/? D/MdnieScenarioControlService:  packageName : fr.free.nrw.commons    className : fr.free.nrw.commons.upload.UploadActivity
12-03 19:07:54.776 21815-21894/fr.free.nrw.commons D/OpenGLRenderer: eglDestroySurface = 0x7043fd40b0
12-03 19:07:54.779 21815-21815/fr.free.nrw.commons D/ViewRootImpl@6ea05c2[DexterActivity]: Relayout returned: old=[540,996][540,996] new=[540,996][540,996] result=0x5 surface={valid=false 0} changed=true
12-03 19:07:54.788 21815-21815/fr.free.nrw.commons D/ViewRootImpl@6ea05c2[DexterActivity]: dispatchDetachedFromWindow
12-03 19:07:54.789 21815-21815/fr.free.nrw.commons D/InputEventReceiver: channel 'e9fab9c fr.free.nrw.commons/com.karumi.dexter.DexterActivity (client)' ~ Disposing input event receiver.
    channel 'e9fab9c fr.free.nrw.commons/com.karumi.dexter.DexterActivity (client)' ~NativeInputEventReceiver.
12-03 19:07:54.792 21815-21894/fr.free.nrw.commons I/OpenGLRenderer: prepareTree mLayerUpdateQueue is not empty, size = 2
    name = CardView, size (1032, 414)
    name = CardView, size (192, 252)
12-03 19:07:54.946 3632-7934/? D/GamePkgDataHelper: getGamePkgDataIncServer(). fr.free.nrw.commons
12-03 19:07:54.947 3632-7934/? D/GameManagerService: identifyGamePackage. fr.free.nrw.commons
12-03 19:07:54.947 3632-7934/? D/GamePkgDataHelper: getGamePkgData(). fr.free.nrw.commons
12-03 19:07:54.948 3632-7934/? D/GameManagerService: identifyGamePackage. fr.free.nrw.commons
12-03 19:07:54.948 3632-7934/? D/GamePkgDataHelper: getGamePkgData(). fr.free.nrw.commons
12-03 19:07:54.949 3632-7934/? D/GameManagerService: identifyGamePackage. fr.free.nrw.commons
12-03 19:07:54.949 3632-7934/? D/GamePkgDataHelper: getGamePkgData(). fr.free.nrw.commons
12-03 19:07:54.956 3632-7934/? D/GameManagerService: identifyGamePackage. fr.free.nrw.commons
12-03 19:07:54.956 3632-7934/? D/GamePkgDataHelper: getGamePkgData(). fr.free.nrw.commons
12-03 19:07:54.958 3632-7934/? D/GameManagerService: identifyGamePackage. fr.free.nrw.commons
12-03 19:07:54.958 3632-7934/? D/GamePkgDataHelper: getGamePkgData(). fr.free.nrw.commons
12-03 19:07:55.044 3632-3721/? I/WindowManager: Destroying surface Surface(name=fr.free.nrw.commons/com.karumi.dexter.DexterActivity_dim) called by com.android.server.wm.WindowStateAnimator.destroyTransitionDimSurface:2733 com.android.server.wm.WindowState.onExitAnimationDone:5262 com.android.server.wm.AppWindowAnimator.stepAnimationLocked:508 com.android.server.wm.TaskStack.stepAppWindowsAnimation:1961 com.android.server.wm.WindowContainer.stepAppWindowsAnimation:521 com.android.server.wm.WindowContainer.stepAppWindowsAnimation:521 com.android.server.wm.WindowAnimator.animate:183 com.android.server.wm.WindowAnimator.lambda$-com_android_server_wm_WindowAnimator_4294:111 
12-03 19:07:55.044 3195-4205/? I/SurfaceFlinger: id=36 Removed fr.free.nrw.commons/com.karumi.dexter.DexterActivity_dim#0 (3/6)
12-03 19:07:55.045 3195-4205/? I/SurfaceFlinger: id=36 Removed fr.free.nrw.commons/com.karumi.dexter.DexterActivity_dim#0 (-2/6)
12-03 19:07:55.045 3632-3721/? I/WindowManager: Destroying surface Surface(name=fr.free.nrw.commons/com.karumi.dexter.DexterActivity) called by com.android.server.wm.WindowStateAnimator.destroySurface:2501 com.android.server.wm.WindowStateAnimator.destroySurfaceLocked:985 com.android.server.wm.WindowState.destroyOrSaveSurfaceUnchecked:3680 com.android.server.wm.WindowState.destroySurface:3628 com.android.server.wm.AppWindowToken.destroySurfaces:722 com.android.server.wm.AppWindowToken.destroySurfaces:706 com.android.server.wm.WindowState.onExitAnimationDone:5335 com.android.server.wm.AppWindowAnimator.stepAnimationLocked:508 
12-03 19:07:55.046 3195-4205/? I/SurfaceFlinger: id=34 Removed fr.free.nrw.commons/com.karumi.dexter.DexterActivity#0 (3/5)
12-03 19:07:55.054 3195-3216/? I/SurfaceFlinger: id=34 Removed fr.free.nrw.commons/com.karumi.dexter.DexterActivity#0 (-2/5)
12-03 19:07:55.059 3195-3195/? I/Layer: id=36 onRemoved fr.free.nrw.commons/com.karumi.dexter.DexterActivity_dim#0 
    id=34 onRemoved fr.free.nrw.commons/com.karumi.dexter.DexterActivity#0 
12-03 19:07:55.278 21815-21815/fr.free.nrw.commons D/CategoriesModel: Direct category found: 
12-03 19:07:55.280 21815-21815/fr.free.nrw.commons D/CategoriesModel: DirectCat does not equal emptyString. Direct Cat list has [
    ]
12-03 19:07:55.282 21815-21815/fr.free.nrw.commons D/CategoriesModel: Image has direct Cat
12-03 19:07:55.323 21815-23465/fr.free.nrw.commons D/CategoriesModel: Previous year: 2017
12-03 19:07:59.449 3632-7934/? D/GameManagerService: identifyGamePackage. fr.free.nrw.commons
12-03 19:07:59.449 3632-7934/? D/GamePkgDataHelper: getGamePkgData(). fr.free.nrw.commons
12-03 19:07:59.865 21815-21869/fr.free.nrw.commons I/zygote64: Explicit concurrent copying GC freed 96503(4MB) AllocSpace objects, 7(140KB) LOS objects, 50% free, 6MB/12MB, paused 544us total 66.568ms
12-03 19:08:00.948 3632-7934/? D/GameManagerService: identifyGamePackage. fr.free.nrw.commons
12-03 19:08:00.948 3632-7934/? D/GamePkgDataHelper: getGamePkgData(). fr.free.nrw.commons
12-03 19:08:31.064 3632-3843/? D/WifiScanningService: addSingleScanRequest: ClientInfo[uid=10018,android.os.Messenger@be775d9],Id=8,WorkSource{10406 fr.free.nrw.commons}, ScanSettings {  packageName:com.google.android.gms band:3 period:0 reportEvents:2 numBssidsPerScan:25 maxScansToCache:0 channels:[  ]  } 

@nicolas-raoul
Copy link
Member

I just had this happen on 2.9.0.114 it is still spinning after 30 minutes.
I was uploading 16 small smartphone pictures.

@neslihanturan
Copy link
Collaborator

Was it a bulk upload @nicolas-raoul ? Or one by one?

@nicolas-raoul
Copy link
Member

Yes, the 16 pictures that got stuck were as a bulk upload.
Today I also successfully uploaded several single pictures, and I also made a successful bulk upload of 4 pictures of similar size.

@nicolas-raoul
Copy link
Member

Got this ("receiving" taking forever) problem again yesterday and today, each time for a single small smartphone picture.

@nicolas-raoul
Copy link
Member

Each time, I just try again and the picture uploads correctly with that same "receiving" screen taking only like two seconds.

@maskaravivek
Copy link
Member

@nicolas-raoul Does it happen just after granting storage permissions or does it happen randomly?

I haven't been able to find a pattern to reproduce the above issue.

"Receiving shared intent" shows up during the preprocessing of the image, so I was hoping that making this flow more robust would reduce the occurrence of this issue. In this regard, I was working on fixing #2083.

@nicolas-raoul
Copy link
Member

nicolas-raoul commented Dec 24, 2018 via email

@misaochan
Copy link
Member Author

@maskaravivek I wonder what exactly goes on during the preprocessing stage? This was never an issue before the upload flow overhaul, and AFAIK we have not actually added any sort of file processing that wasn't there before. Should we try fixing the file URI NPE that I posted in my comment above and see if that helps?

@maskaravivek
Copy link
Member

@ALL The PR #2262 is supposed to fix the null URI issue that @misaochan was facing.

I will take a look at the image shared by @sivaraam to see if it is reproducible for me.

@maskaravivek
Copy link
Member

I faced this issue, too. Specifically, I saw it the first time I tried to upload in v2.9.0. I thought it would never finish but it did after about 30 seconds. That's a long time and might make first time users of the app think it's not useful at all. So, I guess it would be nice to explore the issue and fix it.

To address this, am changing the waiting text to. Please suggest if it can be changed to something more meaningful.

Receiving shared content. Processing the image might take some time depending on the size of the image and your device.

@misaochan
Copy link
Member Author

Whoops, I should have tried to reproduce the error before merging this.

@maskaravivek , #2262 seems to have made things worse. Now, once I get the error, I get the "error when processing image" toast, which is OK... but now NO future uploads ever succeed for me. Every single subsequent image I try to upload gets the error, I tried both the same image and other images. Previously, at least after the first time, I could upload subsequent images.

It does not adversely affect you until you hit the error, but it is still a release blocker.

Was running on my real device so could not get logs via adb, but I sent logs from misaochan2 through the Send Log File method.

@misaochan misaochan reopened this Jan 4, 2019
@misaochan
Copy link
Member Author

misaochan commented Jan 4, 2019

Ah, I managed to reproduce this on my emulator finally. I found that this issue only happens to me via Nearby direct uploads. Uploading the exact same file via the "Gallery" in-app button succeeds. This happens for both emulator and real device.

2019-01-04 20:45:42.930 1435-3439/? W/audio_hw_generic: Not supplying enough data to HAL, expected position 5048977 , only wrote 5048640
2019-01-04 20:45:42.983 1435-3439/? W/audio_hw_generic: Hardware backing HAL too slow, could only write 0 of 720 frames
2019-01-04 20:45:43.395 1435-3439/? W/audio_hw_generic: Not supplying enough data to HAL, expected position 5070955 , only wrote 5065200
2019-01-04 20:45:43.397 1435-3439/? W/audio_hw_generic: Not supplying enough data to HAL, expected position 5065300 , only wrote 5065200
2019-01-04 20:45:43.414 1435-3439/? W/audio_hw_generic: Not supplying enough data to HAL, expected position 5065972 , only wrote 5065920
2019-01-04 20:45:43.469 1435-3439/? W/audio_hw_generic: Hardware backing HAL too slow, could only write 0 of 720 frames
2019-01-04 20:45:43.607 7677-7677/fr.free.nrw.commons D/NearbyMapFragment: Gallery button tapped. Place: Place{name='Genetic Information Research Institute', label='UNKNOWN', longDescription='research institute', secondaryImageUrl='', location='lat/lng: (37.4193,-122.088)', category='
    ', image='null', secondaryImage=null, distance='463m', siteLinks='Sitelinks{wikipediaLink='<https://en.wikipedia.org/wiki/Genetic_Information_Research_Institute>', commonsLink='', wikidataLink='<http://www.wikidata.org/entity/Q5532866>'}'}
2019-01-04 20:45:43.609 7677-7677/fr.free.nrw.commons D/Place: Wikidata entity is http://www.wikidata.org/entity/Q5532866
2019-01-04 20:45:43.618 7677-7677/fr.free.nrw.commons D/ContributionController: startMultipleGalleryPick() called with pickImageIntent
    
    --------- beginning of system
2019-01-04 20:45:43.619 1720-3835/system_process I/ActivityManager: START u0 {act=android.intent.action.GET_CONTENT typ=image/* cmp=com.android.documentsui/.picker.PickActivity (has extras)} from uid 10081
2019-01-04 20:45:43.670 1720-3835/system_process I/GnssLocationProvider: WakeLock acquired by sendMessage(SET_REQUEST, 0, com.android.server.location.GnssLocationProvider$GpsRequest@e01b6e1)
2019-01-04 20:45:43.682 1720-1736/system_process I/GnssLocationProvider: WakeLock released by handleMessage(SET_REQUEST, 0, com.android.server.location.GnssLocationProvider$GpsRequest@e01b6e1)
2019-01-04 20:45:43.810 6644-6644/com.android.documentsui D/PickActivity: Created new state object: State{action=5, acceptMimes=[Ljava.lang.String;@b44e852, allowMultiple=true, localOnly=false, showDeviceStorageOption=true, showAdvanced=false, stack=DocumentStack{root=null, docStack=[], stackTouched=false}, dirConfigs={}, excludedAuthorities=[], openableOnly=false, sortModel=SortModel{dimensions={16908304=SortDimension{id=16908304, labelId=2131689635, dataType=0, sortCapability=0, defaultSortDirection=1, sortDirection=0, visibility=4}, 16908310=SortDimension{id=16908310, labelId=2131689633, dataType=0, sortCapability=3, defaultSortDirection=1, sortDirection=0, visibility=0}, 2131296320=SortDimension{id=2131296320, labelId=2131689631, dataType=1, sortCapability=3, defaultSortDirection=2, sortDirection=0, visibility=0}, 2131296360=SortDimension{id=2131296360, labelId=2131689632, dataType=0, sortCapability=3, defaultSortDirection=1, sortDirection=0, visibility=0}, 2131296463=SortDimension{id=2131296463, labelId=2131689634, dataType=1, sortCapability=3, defaultSortDirection=1, sortDirection=0, visibility=0}}, defaultDimensionId=0, sortedDimension=null}}
2019-01-04 20:45:43.827 6644-6644/com.android.documentsui D/DrawerController: Calculated drawer width:264.0
2019-01-04 20:45:43.827 6644-6644/com.android.documentsui D/Metrics: docsui_launch_action: 4
2019-01-04 20:45:43.828 6644-6644/com.android.documentsui D/Metrics: docsui_get_content_mime: 5
2019-01-04 20:45:43.834 6644-6644/com.android.documentsui D/PickerActionHandler: Load last accessed stack.
2019-01-04 20:45:43.834 6644-6644/com.android.documentsui D/PickerActionHandler: Attempting to load last used stack for calling package.
2019-01-04 20:45:43.843 6644-7930/com.android.documentsui D/ProvidersAccess: Matched roots: [Root{authority=null, rootId=null, title=Recent, isUsb=false, isSd=false, isMtp=false} @ content:/root/null, Root{authority=com.android.providers.downloads.documents, rootId=downloads, title=Downloads, isUsb=false, isSd=false, isMtp=false} @ content://com.android.providers.downloads.documents/root/downloads, Root{authority=com.android.providers.media.documents, rootId=images_root, title=Images, isUsb=false, isSd=false, isMtp=false} @ content://com.android.providers.media.documents/root/images_root, Root{authority=com.android.externalstorage.documents, rootId=1905-0802, title=SDCARD, isUsb=false, isSd=true, isMtp=false} @ content://com.android.externalstorage.documents/root/1905-0802, Root{authority=com.android.externalstorage.documents, rootId=home, title=Documents, isUsb=false, isSd=false, isMtp=false} @ content://com.android.externalstorage.documents/root/home]
2019-01-04 20:45:43.868 6644-7944/com.android.documentsui D/ProvidersAccess: Matched roots: [Root{authority=null, rootId=null, title=Recent, isUsb=false, isSd=false, isMtp=false} @ content:/root/null, Root{authority=com.android.providers.downloads.documents, rootId=downloads, title=Downloads, isUsb=false, isSd=false, isMtp=false} @ content://com.android.providers.downloads.documents/root/downloads, Root{authority=com.android.providers.media.documents, rootId=images_root, title=Images, isUsb=false, isSd=false, isMtp=false} @ content://com.android.providers.media.documents/root/images_root, Root{authority=com.android.externalstorage.documents, rootId=1905-0802, title=SDCARD, isUsb=false, isSd=true, isMtp=false} @ content://com.android.externalstorage.documents/root/1905-0802, Root{authority=com.android.externalstorage.documents, rootId=home, title=Documents, isUsb=false, isSd=false, isMtp=false} @ content://com.android.externalstorage.documents/root/home]
2019-01-04 20:45:43.924 1443-2110/? D/gralloc_ranchu: gralloc_alloc: Creating ashmem region of size 1540096
2019-01-04 20:45:43.933 1443-1443/? D/gralloc_ranchu: gralloc_alloc: Creating ashmem region of size 1540096
2019-01-04 20:45:43.944 1443-1443/? D/gralloc_ranchu: gralloc_alloc: Creating ashmem region of size 1540096
2019-01-04 20:45:44.031 6644-6683/com.android.documentsui D/EGL_emulation: eglMakeCurrent: 0xebdb0b60: ver 3 1 (tinfo 0xe4508a40)
2019-01-04 20:45:44.079 6644-6644/com.android.documentsui D/DocumentStack: Resetting the whole darn stack to: DocumentStack{root=Root{authority=com.android.providers.media.documents, rootId=images_root, title=Images, isUsb=false, isSd=false, isMtp=false} @ content://com.android.providers.media.documents/root/images_root, docStack=[DocumentInfo{docId=images_root, name=Images, mimeType=vnd.android.document/directory, isContainer=true, isDirectory=true, isArchive=false, isInArchive=false, isPartial=false, isVirtual=false, isDeleteSupported=false, isCreateSupported=false, isRenameSupported=false} @ content://com.android.providers.media.documents/document/images_root, DocumentInfo{docId=images_bucket:-1739773001, name=Camera, mimeType=vnd.android.document/directory, isContainer=true, isDirectory=true, isArchive=false, isInArchive=false, isPartial=false, isVirtual=false, isDeleteSupported=false, isCreateSupported=false, isRenameSupported=false} @ content://com.android.providers.media.documents/document/images_bucket%3A-1739773001], stackTouched=true}
2019-01-04 20:45:44.083 6644-6644/com.android.documentsui D/DirectoryFragment: Showing directory: content://com.android.providers.media.documents/document/images_bucket%3A-1739773001
2019-01-04 20:45:44.083 6644-6644/com.android.documentsui D/DirectoryFragment: Creating new fragment for directory: content://com.android.providers.media.documents/document/images_bucket%3A-1739773001
2019-01-04 20:45:44.089 6644-6644/com.android.documentsui D/AbstractActionHandler: Creating new directory loader for: content://com.android.providers.media.documents/document/images_bucket%3A-1739773001
2019-01-04 20:45:44.125 1720-1744/system_process I/ActivityManager: Displayed com.android.documentsui/.picker.PickActivity: +432ms (total +24s823ms)
2019-01-04 20:45:44.142 1720-1730/system_process I/zygote: WaitForGcToComplete blocked Background on None for 13.774ms
2019-01-04 20:45:44.169 1435-3439/? W/audio_hw_generic: Hardware backing HAL too slow, could only write 0 of 720 frames
2019-01-04 20:45:44.175 6644-6644/com.android.documentsui D/AbstractActionHandler: Loader has finished for: content://com.android.providers.media.documents/document/images_bucket%3A-1739773001
2019-01-04 20:45:44.175 6644-6644/com.android.documentsui I/Model: Updating model with new result set.
2019-01-04 20:45:44.176 6644-6644/com.android.documentsui D/DirectoryFragment: Received model update. Loading=false
2019-01-04 20:45:44.184 1435-3439/? W/audio_hw_generic: Hardware backing HAL too slow, could only write 0 of 720 frames
2019-01-04 20:45:44.200 1435-3439/? W/audio_hw_generic: Hardware backing HAL too slow, could only write 0 of 720 frames
2019-01-04 20:45:44.205 7677-7677/fr.free.nrw.commons D/gralloc_ranchu: gralloc_unregister_buffer: exiting HostConnection (is buffer-handling thread)
2019-01-04 20:45:44.206 7677-7677/fr.free.nrw.commons D/gralloc_ranchu: gralloc_unregister_buffer: exiting HostConnection (is buffer-handling thread)
2019-01-04 20:45:44.207 7677-7677/fr.free.nrw.commons D/gralloc_ranchu: gralloc_unregister_buffer: exiting HostConnection (is buffer-handling thread)
2019-01-04 20:45:44.208 7677-7677/fr.free.nrw.commons D/gralloc_ranchu: gralloc_unregister_buffer: exiting HostConnection (is buffer-handling thread)
2019-01-04 20:45:44.217 7677-7677/fr.free.nrw.commons D/gralloc_ranchu: gralloc_unregister_buffer: exiting HostConnection (is buffer-handling thread)
2019-01-04 20:45:44.220 7677-7677/fr.free.nrw.commons D/gralloc_ranchu: gralloc_unregister_buffer: exiting HostConnection (is buffer-handling thread)
2019-01-04 20:45:44.230 6644-6644/com.android.documentsui D/Metrics: docsui_startup_ms: 444
2019-01-04 20:45:44.287 1720-1730/system_process I/zygote: Background concurrent copying GC freed 52485(2MB) AllocSpace objects, 11(540KB) LOS objects, 38% free, 9MB/15MB, paused 12.017ms total 144.175ms
2019-01-04 20:45:44.305 1444-1479/? D/gralloc_ranchu: gralloc_unregister_buffer: exiting HostConnection (is buffer-handling thread)
2019-01-04 20:45:44.307 1444-1479/? D/gralloc_ranchu: gralloc_unregister_buffer: exiting HostConnection (is buffer-handling thread)
2019-01-04 20:45:44.309 1444-1479/? D/gralloc_ranchu: gralloc_unregister_buffer: exiting HostConnection (is buffer-handling thread)
2019-01-04 20:45:44.310 1444-1479/? D/gralloc_ranchu: gralloc_unregister_buffer: exiting HostConnection (is buffer-handling thread)
2019-01-04 20:45:44.311 1444-1479/? D/gralloc_ranchu: gralloc_unregister_buffer: exiting HostConnection (is buffer-handling thread)
2019-01-04 20:45:44.312 1444-1479/? D/gralloc_ranchu: gralloc_unregister_buffer: exiting HostConnection (is buffer-handling thread)
2019-01-04 20:45:44.326 1444-1479/? D/gralloc_ranchu: gralloc_unregister_buffer: exiting HostConnection (is buffer-handling thread)
2019-01-04 20:45:44.327 1444-1479/? D/gralloc_ranchu: gralloc_unregister_buffer: exiting HostConnection (is buffer-handling thread)
2019-01-04 20:45:44.328 1444-1479/? D/gralloc_ranchu: gralloc_unregister_buffer: exiting HostConnection (is buffer-handling thread)
2019-01-04 20:45:44.329 1444-1479/? D/gralloc_ranchu: gralloc_unregister_buffer: exiting HostConnection (is buffer-handling thread)
2019-01-04 20:45:44.330 1444-1479/? D/gralloc_ranchu: gralloc_unregister_buffer: exiting HostConnection (is buffer-handling thread)
2019-01-04 20:45:44.331 1444-1479/? D/gralloc_ranchu: gralloc_unregister_buffer: exiting HostConnection (is buffer-handling thread)
2019-01-04 20:45:44.500 1720-1736/system_process I/GnssLocationProvider: WakeLock acquired by sendMessage(SET_REQUEST, 0, com.android.server.location.GnssLocationProvider$GpsRequest@c49a442)
2019-01-04 20:45:44.513 1720-1736/system_process I/GnssLocationProvider: WakeLock released by handleMessage(SET_REQUEST, 0, com.android.server.location.GnssLocationProvider$GpsRequest@c49a442)
2019-01-04 20:45:44.535 7677-7677/fr.free.nrw.commons D/LocationServiceManager: gps's status changed to 1
2019-01-04 20:45:44.605 2295-7705/com.google.android.gms.persistent W/ctxmgr: [AclManager]No 2 for (accnt=account#-517948760#, com.google.android.gms(10013):IndoorOutdoorProducer, vrsn=13280000, 0, 3pPkg = null ,  3pMdlId = null ,  pid = 2295). Was: 3 for 57, account#-517948760#
2019-01-04 20:45:45.070 6644-6644/com.android.documentsui D/PickerActionHandler: onFinished() [content://com.android.providers.media.documents/document/image%3A20]
2019-01-04 20:45:45.117 7677-7677/fr.free.nrw.commons D/NearbyMapFragment: OnActivityResult() parameters: Req code: 3 Result code: -1 Data: Intent { dat=content://com.android.providers.media.documents/document/image:20 flg=0x1 }
2019-01-04 20:45:45.121 7677-7677/fr.free.nrw.commons D/ContributionController: handleImagePicked() called with onActivityResult(). Boolean isDirectUpload: trueString wikiDataEntityId: Q5532866
2019-01-04 20:45:45.138 7677-7677/fr.free.nrw.commons I/ContributionController: Image selected
2019-01-04 20:45:45.139 7677-7677/fr.free.nrw.commons D/ContributionController: Put extras into image intent, isDirectUpload is true
2019-01-04 20:45:45.140 1720-3835/system_process I/ActivityManager: START u0 {act=android.intent.action.SEND cmp=fr.free.nrw.commons/.upload.UploadActivity (has extras)} from uid 10081
2019-01-04 20:45:45.149 7677-7677/fr.free.nrw.commons D/ContributionsListFragment: OnActivityResult() parameters: Req code: 196611 Result code: -1 Data: Intent { dat=content://com.android.providers.media.documents/document/image:20 flg=0x1 }
2019-01-04 20:45:45.162 1720-1736/system_process I/GnssLocationProvider: WakeLock acquired by sendMessage(SET_REQUEST, 0, com.android.server.location.GnssLocationProvider$GpsRequest@3cb9aa8)
2019-01-04 20:45:45.166 7677-7677/fr.free.nrw.commons D/ContributionsFragment: GPS is enabled
2019-01-04 20:45:45.171 1720-3835/system_process I/GnssLocationProvider: WakeLock acquired by sendMessage(SET_REQUEST, 0, com.android.server.location.GnssLocationProvider$GpsRequest@bb79566)
2019-01-04 20:45:45.173 1720-1736/system_process I/GnssLocationProvider: WakeLock released by handleMessage(SET_REQUEST, 0, com.android.server.location.GnssLocationProvider$GpsRequest@3cb9aa8)
2019-01-04 20:45:45.174 7677-7677/fr.free.nrw.commons E/#CF#: onFragmentResumedfr.free.nrw.commons.contributions.ContributionsListFragment
2019-01-04 20:45:45.176 1720-1736/system_process I/GnssLocationProvider: WakeLock released by handleMessage(SET_REQUEST, 0, com.android.server.location.GnssLocationProvider$GpsRequest@bb79566)
2019-01-04 20:45:45.179 7677-7677/fr.free.nrw.commons D/NearbyMapFragment: initViews called
2019-01-04 20:45:45.198 1720-7243/system_process I/GnssLocationProvider: WakeLock acquired by sendMessage(SET_REQUEST, 0, com.android.server.location.GnssLocationProvider$GpsRequest@f93e0a7)
2019-01-04 20:45:45.207 1720-1736/system_process I/GnssLocationProvider: WakeLock released by handleMessage(SET_REQUEST, 0, com.android.server.location.GnssLocationProvider$GpsRequest@f93e0a7)
2019-01-04 20:45:45.286 1443-1443/? D/gralloc_ranchu: gralloc_alloc: Creating ashmem region of size 1171456
2019-01-04 20:45:45.303 7677-7905/fr.free.nrw.commons D/EGL_emulation: eglMakeCurrent: 0xd429c3e0: ver 3 1 (tinfo 0xd3ee9ed0)
2019-01-04 20:45:45.327 1443-1443/? D/gralloc_ranchu: gralloc_alloc: Creating ashmem region of size 1171456
2019-01-04 20:45:45.337 1453-1500/? D/gralloc_ranchu: gralloc_unregister_buffer: exiting HostConnection (is buffer-handling thread)
2019-01-04 20:45:45.339 7677-7677/fr.free.nrw.commons D/LocationServiceManager: Provider network disabled
2019-01-04 20:45:45.339 1453-1500/? D/gralloc_ranchu: gralloc_unregister_buffer: exiting HostConnection (is buffer-handling thread)
2019-01-04 20:45:45.343 7677-7677/fr.free.nrw.commons D/LocationServiceManager: on location changed
2019-01-04 20:45:45.344 1443-1443/? D/gralloc_ranchu: gralloc_alloc: Creating ashmem region of size 1171456
2019-01-04 20:45:45.346 7677-7677/fr.free.nrw.commons D/LocationServiceManager: gps's status changed to 1
2019-01-04 20:45:45.376 7677-7905/fr.free.nrw.commons D/EGL_emulation: eglMakeCurrent: 0xd429c3e0: ver 3 1 (tinfo 0xd3ee9ed0)
2019-01-04 20:45:45.390 7677-7677/fr.free.nrw.commons I/AppCompatViewInflater: app:theme is now deprecated. Please move to using android:theme instead.
2019-01-04 20:45:45.421 1443-1443/? D/gralloc_ranchu: gralloc_alloc: Creating ashmem region of size 1171456
2019-01-04 20:45:45.440 1443-1443/? D/gralloc_ranchu: gralloc_alloc: Creating ashmem region of size 1171456
2019-01-04 20:45:45.463 7677-7677/fr.free.nrw.commons D/ExternalStorageUtils: External storage permission granted, API >= 23
2019-01-04 20:45:45.464 7677-7677/fr.free.nrw.commons I/DexterPermissionObtainer: Storage permissions already granted.
2019-01-04 20:45:45.502 1443-1443/? D/gralloc_ranchu: gralloc_alloc: Creating ashmem region of size 1540096
2019-01-04 20:45:45.553 7677-7677/fr.free.nrw.commons D/LocationServiceManager: gps's status changed to 1
2019-01-04 20:45:45.667 6644-6683/com.android.documentsui D/EGL_emulation: eglMakeCurrent: 0xebdb0b60: ver 3 1 (tinfo 0xe4508a40)
2019-01-04 20:45:45.677 1443-1443/? D/gralloc_ranchu: gralloc_alloc: Creating ashmem region of size 1540096
2019-01-04 20:45:45.759 7677-7677/fr.free.nrw.commons D/ContributionsFragment: GPS is enabled
2019-01-04 20:45:45.767 1720-3835/system_process I/GnssLocationProvider: WakeLock acquired by sendMessage(SET_REQUEST, 0, com.android.server.location.GnssLocationProvider$GpsRequest@6604197)
2019-01-04 20:45:45.769 7677-7677/fr.free.nrw.commons E/#CF#: onFragmentResumedfr.free.nrw.commons.contributions.ContributionsListFragment
2019-01-04 20:45:45.769 7677-7677/fr.free.nrw.commons D/NearbyMapFragment: initViews called
2019-01-04 20:45:45.779 1720-1736/system_process I/GnssLocationProvider: WakeLock released by handleMessage(SET_REQUEST, 0, com.android.server.location.GnssLocationProvider$GpsRequest@6604197)
2019-01-04 20:45:45.871 1443-1443/? D/gralloc_ranchu: gralloc_alloc: Creating ashmem region of size 192512
2019-01-04 20:45:45.883 7677-7791/fr.free.nrw.commons D/CustomApiResult: API response is
     <?xml version="1.0" encoding="UTF-8"?><api batchcomplete=""><query><userinfo id="6998903" name="Misaochan2"/></query></api>
2019-01-04 20:45:45.903 1444-1479/? D/gralloc_ranchu: gralloc_unregister_buffer: exiting HostConnection (is buffer-handling thread)
2019-01-04 20:45:45.904 1444-1479/? D/gralloc_ranchu: gralloc_unregister_buffer: exiting HostConnection (is buffer-handling thread)
2019-01-04 20:45:45.905 1444-1479/? D/gralloc_ranchu: gralloc_unregister_buffer: exiting HostConnection (is buffer-handling thread)
2019-01-04 20:45:45.906 1444-1479/? D/gralloc_ranchu: gralloc_unregister_buffer: exiting HostConnection (is buffer-handling thread)
2019-01-04 20:45:45.907 1444-1479/? D/gralloc_ranchu: gralloc_unregister_buffer: exiting HostConnection (is buffer-handling thread)
2019-01-04 20:45:45.909 7677-7677/fr.free.nrw.commons D/LocationServiceManager: Provider network disabled
2019-01-04 20:45:45.909 1444-1479/? D/gralloc_ranchu: gralloc_unregister_buffer: exiting HostConnection (is buffer-handling thread)
2019-01-04 20:45:45.922 7677-7677/fr.free.nrw.commons D/LocationServiceManager: on location changed
2019-01-04 20:45:45.924 7677-7677/fr.free.nrw.commons D/LocationServiceManager: gps's status changed to 1
2019-01-04 20:45:45.933 7677-7853/fr.free.nrw.commons D/NearbyController: Loading attractions near lat/lng: (37.421998333333335,-122.08400000000002)
2019-01-04 20:45:45.948 7677-7853/fr.free.nrw.commons D/NearbyPlaces: https://query.wikidata.org/#SELECT%0A%20%20%20%20%20(SAMPLE(%3Flocation)%20as%20%3Flocation)%0A%20%20%20%20%20%3Fitem%0A%20%20%20%20%20(SAMPLE(COALESCE(%3Fitem_label_preferred_language%2C%20%3Fitem_label_any_language))%20as%20%3Flabel)%0A%20%20%20%20%20(SAMPLE(%3FclassId)%20as%20%3Fclass)%0A%20%20%20%20%20(SAMPLE(COALESCE(%3Fclass_label_preferred_language%2C%20%3Fclass_label_any_language%2C%20%22%3F%22))%20as%20%3Fclass_label)%0A%20%20%20%20%20(SAMPLE(COALESCE(%3Ficon0%2C%20%3Ficon1))%20as%20%3Ficon)%0A%20%20%20%20%20(SAMPLE(COALESCE(%3Femoji0%2C%20%3Femoji1))%20as%20%3Femoji)%0A%20%20%20%20%20%3FwikipediaArticle%0A%20%20%20%20%20%3FcommonsArticle%0A%20%20%20%20%20(SAMPLE(%3FCommons_category)%20as%20%3FCommons_category)%0A%20%20%20WHERE%20%7B%0A%20%20%20%20%20%23%20Around%20given%20location...%0A%20%20%20%20%20SERVICE%20wikibase%3Aaround%20%7B%0A%20%20%20%20%20%20%20%3Fitem%20wdt%3AP625%20%3Flocation.%0A%20%20%20%20%20%20%20bd%3AserviceParam%20wikibase%3Acenter%20%22Point(-122.0840%2037.4220)%22%5E%5Egeo%3AwktLiteral.%0A%20%20%20%20%20%20%20bd%3AserviceParam%20wikibase%3Aradius%20%221.00%22%20.%20%23%20Radius%20in%20kilometers.%0A%20%20%20%20%20%7D%0A%0A%20%20%20%20%20%23%20...%20and%20without%20an%20image.%0A%20%20%20%20%20MINUS%20%7B%3Fitem%20wdt%3AP18%20%5B%5D%7D%0A%0A%20%20%20%20%20%23%20Get%20the%20label%20in%20the%20preferred%20language%20of%20the%20user%2C%20or%20any%20other%20language%20if%20no%20label%20is%20available%20in%20that%20language.%0A%20%20%20%20%20OPTIONAL%20%7B%3Fitem%20rdfs%3Alabel%20%3Fitem_label_preferred_language.%20FILTER%20(lang(%3Fitem_label_preferred_language)%20%3D%20%22en%22)%7D%0A%20%20%20%20%20OPTIONAL%20%7B%3Fitem%20rdfs%3Alabel%20%3Fitem_label_any_language%7D%0A%0A%20%20%20%20%20%23%20Get%20Commons%20category%20(P373)%0A%20%20%20%20%20OPTIONAL%20%7B%20%3Fitem%20wdt%3AP373%20%3FCommons_category.%20%7D%0A%0A%20%20%20%20%20%23%20Get%20the%20class%20label%20in%20the%20preferred%20language%20of%20the%20user%2C%20or%20any%20other%20language%20if%20no%20label%20is%20available%20in%20that%20language.%0A%20%20%20%20%20OPTIONAL%20%7B%0A%20%20%20%20%20%20%20%3Fitem%20p%3AP31%2Fps%3AP31%20%3FclassId.%0A%20%20%20%20%20%20%20OPTIONAL%20%7B%3FclassId%20rdfs%3Alabel%20%3Fclass_label_preferred_language.%20FILTER%20(lang(%3Fclass_label_preferred_language)%20%3D%20%22en%22)%7D%0A%20%20%20%20%20%20%20OPTIONAL%20%7B%3FclassId%20rdfs%3Alabel%20%3Fclass_label_any_language%7D%0A%0A%20%20%20%20%20%20%20%23%20Get%20icon%0A%20%20%20%20%20%20%20OPTIONAL%20%7B%20%3FclassId%20wdt%3AP2910%20%3Ficon0.%20%7D%0A%20%20%20%20%20%20%20OPTIONAL%20%7B%20%3FclassId%20wdt%3AP279*%2Fwdt%3AP2910%20%3Ficon1.%20%7D%0A%20%20%20%20%20%20%20%23%20Get%20emoji%0A%20%20%20%20%20%20%20OPTIONAL%20%7B%20%3FclassId%20wdt%3AP487%20%3Femoji0.%20%7D%0A%20%20%20%20%20%20%20OPTIONAL%20%7B%20%3FclassId%20wdt%3AP279*%2Fwdt%3AP487%20%3Femoji1.%20%7D%0A%0A%20%20%20%20%20%20%20OPTIONAL%20%7B%0A%20%20%20%20%20%20%20%20%20%20%20%3FwikipediaArticle%20%20%20schema%3Aabout%20%3Fitem%20%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%20%20%20%20%20%20%20%20%20%20%20%20%20%20%20%20%20schema%3AisPartOf%20%3Chttps%3A%2F%2Fen.wikipedia.org%2F%3E%20.%0A%20%20%20%20%20%20%20%20%20%7D%0A%20%20%20%20%20%20%20OPTIONAL%20%7B%0A%20%20%20%20%20%20%20%20%20%20%20%3FwikipediaArticle%20%20%20schema%3Aabout%20%3Fitem%20%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%20%20%20%20%20%20%20%20%20%20%20%20%20%20%20%20%20schema%3AisPartOf%20%3Chttps%3A%2F%2Fen.wikipedia.org%2F%3E%20.%0A%20%20%20%20%20%20%20%20%20%20%20SERVICE%20wikibase%3Alabel%20%7B%20bd%3AserviceParam%20wikibase%3Alanguage%20%22en%22%20%7D%0A%20%20%20%20%20%20%20%20%20%7D%0A%0A%20%20%20%20%20%20%20%20%20OPTIONAL%20%7B%0A%20%20%20%20%20%20%20%20%20%20%20%3FcommonsArticle%20%20%20schema%3Aabout%20%3Fitem%20%3B%0A%20%20%20%20%20%20%20%20%20%20%20%20%20%20%20%20%20%20%20%20%20%20%20%20%20%20%20%20%20%20%20schema%3AisPartOf%20%3Chttps%3A%2F%2Fcommons.wikimedia.org%2F%3E%20.%0A%20%20%20%20%20%20%20%20%20%20%20SERVICE%20
2019-01-04 20:45:45.948 7677-7853/fr.free.nrw.commons D/NearbyPlaces: wikibase%3Alabel%20%7B%20bd%3AserviceParam%20wikibase%3Alanguage%20%22en%22%20%7D%0A%20%20%20%20%20%20%20%20%20%7D%0A%20%20%20%20%20%7D%0A%20%20%20%7D%0A%20%20%20GROUP%20BY%20%3Fitem%20%3FwikipediaArticle%20%3FcommonsArticle%0A
2019-01-04 20:45:45.965 1443-1443/? D/gralloc_ranchu: gralloc_alloc: Creating ashmem region of size 1540096
2019-01-04 20:45:46.155 7677-7853/fr.free.nrw.commons D/NearbyPlaces: Reading from query result...
2019-01-04 20:45:46.184 7677-7853/fr.free.nrw.commons D/NearbyPlaces: 6 results at radius: 1.000000
2019-01-04 20:45:46.186 7677-7853/fr.free.nrw.commons D/NearbyController: Sorting places by distance...
2019-01-04 20:45:46.191 7677-7677/fr.free.nrw.commons D/NearbyNotificationCardView: Update nearby card notification content
2019-01-04 20:45:46.775 1435-1645/? W/audio_hw_generic: Not supplying enough data to HAL, expected position 5387685 , only wrote 5227200
2019-01-04 20:45:47.193 1720-1851/system_process E/TaskPersister: File error accessing recents directory (directory doesn't exist?).

On a side note, there appears to be an issue with Send Logs (at least, when running a debug build). On my real device I don't seem to be able to get any meaningful logs today. See my submitted logs in the google groups forum - I have actually done a lot with the Commons app on my real device today (4 Jan), but there are almost no logs generated.

@misaochan
Copy link
Member Author

misaochan commented Jan 4, 2019

Reposting my observations that I told Vivek about (so that anyone else looking at the issue can be updated). If you are experiencing the issue too, feel free to post your own observations, and see if they are similar to mine.

It happens randomly for various images. The only constant things that I can see are:

  1. The first time is always a Nearby upload
  2. Now (after your recent PR) all Nearby uploads with all pictures error after the first time errors
  3. But I can still upload via in-app Gallery button (or at least, I can pass the preprocessing stage)

@sivaraam
Copy link
Member

sivaraam commented Jan 5, 2019

The first time is always a Nearby upload

I've not tested with the change that has been merged but when I observed this issue initially I did not do any nearby uploads. I guess it was either a upload initiated from the app or an upload initiated by sharing from the gallery.

@maskaravivek
Copy link
Member

You could find the images for which I consistently see the app crash in the following link:
https://drive.google.com/drive/folders/1oe59ZN3afn2h5ycYyrpVCLxmiESVua-9

@sivaraam Regarding the crash that you were experiencing, I managed to upload all 4 images successfully on the beta server without any crashes. I used Redmi Note 5 for testing. Can you verify if the latest master build work for you?

Reposting my observations that I told Vivek about (so that anyone else looking at the issue can be updated). If you are experiencing the issue too, feel free to post your own observations, and see if they are similar to mine.

@misaochan Am looking at the issue and am trying to figure out why the UploadActivity is receiving null URIs.

@sivaraam

This comment has been minimized.

@maskaravivek

This comment has been minimized.

@sivaraam
Copy link
Member

sivaraam commented Jan 6, 2019

Thanks I'll look into it and share the results.

@sivaraam

This comment has been minimized.

@maskaravivek

This comment has been minimized.

@misaochan
Copy link
Member Author

Yes, you need to both join the Google Group AND sign up at the Google Play test page to get the alpha. The Google Play test page is the same for both alpha and beta, but being a member of the Google Group is what differentiates your account.

Personally I wish there was a clearer way, this way is kinda confusing to users, but we have no say in this.

@sivaraam
Copy link
Member

sivaraam commented Jan 7, 2019

OK. I thought I joined the group yesterday seems I wasn't careful enough to verify it, sorry. How long does it take to receive the alpha update? Or would I get an update only for the next alpha release?

Anyways, I managed to build the app from source yesterday. When I try to upload the images I shared I could cause the processing stage for only one of it. Interestingly this time it doesn't seem to be dependent on size as I'm able to cross the preprocessing stage for the image with the largest size. That's sppoky, isn't it?

I've sent the crash reports via e-mail for the images that resulted in a crash. I've also attached the images with them. I use a low-end phone (1GB RAM, 8GB Internal storage; Samsung SM-J111F). Is that somehow the reason the app crashes for me but not for you @maskaravivek? Also, does the processing stage require a reliable network connection? I hope not but just wanted to know as the network is a little wavery here and not very reliable.

@misaochan
Copy link
Member Author

You should be able to receive the alpha update within a couple of hours. However, I'm not sure if the About page will reflect the correct version number (see #2127 ). The ACRA crash report should have the correct version number though.

Thanks for the crash reports!

@sivaraam

This comment has been minimized.

@nicolas-raoul

This comment has been minimized.

@sivaraam

This comment has been minimized.

@sivaraam

This comment has been minimized.

@maskaravivek
Copy link
Member

@nicolas-raoul We have just pushed a fix for this issue. It should no longer happen.

@sivaraam
Copy link
Member

sivaraam commented Jan 9, 2019

@maskaravivek I think @nicolas-raoul asked me about the updated the updated wiki page when he stated:

@sivaraam How is it now? https://github.com/commons-app/apps-android-commons/wiki/Volunteers-welcome!#how-to-install-the-alpha

Or have I misunderstood it? 🤔

@maskaravivek
Copy link
Member

Sorry, my comment wasn't in reply to the wiki issue. It was about the fix to the bug.

Let me hide unrelated comments to avoid confusion. :)

@nicolas-raoul
Copy link
Member

@maskaravivek Thanks! I have uploaded many pictures recently and I have not gotten this error, whereas I was getting it very often before your commit :-)

@sivaraam
Copy link
Member

We have just pushed a fix for this issue. It should no longer happen.

In case you refer to the fix in #2278 which seems to available in the alpha version v2.9.0.163 if I'm right. I tried using that version to see if I could upload the images for which I was experiencing a crash previously. Sadly, the app still crashes for me when I try to upload them :-( It crashed in the processing stage itself (just as in #2033 (comment)). I've sent the crash reports this time too.

@maskaravivek
Copy link
Member

@sivaraam Thanks for sharing the logs. The issue you are facing is related to #2083.

This issue was related to the Intent not being handled properly leading to app crashing as soon as the UploadActivity is started.

Out of memory (OOM) crash that you are facing is because of large images not being handled properly. Let's take the discussion about this crash to #2083. :)

@ShridharGoel
Copy link
Contributor

This issue is permanently there in the latest master. Not even a single image could be uploaded until I went some commits back. Will have to check which commit caused the problem.

@maskaravivek
Copy link
Member

@ShridharGoel My last commit caused this issue. The PR fixing it is up for review. #2309.

@nicolas-raoul
Copy link
Member

nicolas-raoul commented Jan 25, 2019

This issue happens:

  • Always when using "Share" from the Android stock gallery app, even for small pictures
  • Never when using the Commons app's built-in image selection activity (thanks to yesterday's alpha release), the "receiving" step takes less than a second.

@maskaravivek
Copy link
Member

Always when using "Share" from the Android stock gallery app, even for small pictures

Yes, @misaochan also reported this issue. Am working on fixing it. :)

Never when using the Commons app's built-in image selection activity (thanks to yesterday's alpha release), the "receiving" step takes less than a second.

Thanks. Also, am making changes to switch to EasyImage lib so that all galleries(google photos, drive etc) can be supported.

@nicolas-raoul
Copy link
Member

I haven't seen this for a while. If that happens again please tell us, thanks! :-)

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

Successfully merging a pull request may close this issue.

7 participants