Android.process.media being killing causing media not downloaded and app crash

REPRODUCIBILITY (% or how often): 100%
BUILD ID = OS VERSION (Settings > About product): 4.1.0.24
HARDWARE (XA2, Xperia 10…): XA2 Dual Sim
UI LANGUAGE: french
REGRESSION: (compared to previous public release: Yes, No, ?): yes

DESCRIPTION:

Somes Android app crash when trying to download media in gallery, logcat always point to android.process.media being killed every time a media is downloaded and getVideoFrame not implemented.

PRECONDITIONS:

This seems to be only on Java app, not app using native SDK (like Firefox)

STEPS TO REPRODUCE:

  1. Open a media on a app
  2. Try to download it

Broken apps tested so far (I don’t have a lot of Android app and I download some to test) :

  • Twidere (+app crash)
  • FBslim (+app crash)
  • Nextcloud (+app crash)
  • Twidere X
  • RedReader

EXPECTED RESULT:

The media is downloaded

ACTUAL RESULT:

When app present a popup to select save location (newer android feature ?) :
A 0 byte file is created

When app does not show popup (compatible with older Android ?) :
The media is not downloaded
The app crash

ADDITIONAL INFORMATION:

Logcat when using RedReader (at the moment I press “save” on the location selector):
06-03 12:21:39.305 126 229 D AlienEventHub: ALIEN: getVideoFrames is not supported
06-03 12:21:43.489 126 240 E Parcel : Attempt to read from protected data in Parcel 0xe056c8c0
06-03 12:21:43.493 126 240 E Parcel : Attempt to read from protected data in Parcel 0xbdbd5600
06-03 12:21:43.496 126 240 E Parcel : Attempt to read from protected data in Parcel 0xe056c8c0
06-03 12:21:43.496 126 240 E WificondChannelHelper: Got zero length for all channel lists
06-03 12:21:43.496 126 240 E WificondScannerImpl: Failed to start scan because there is no available channel to scan
06-03 12:21:44.300 126 161 I ActivityManager: Killing 4408:com.android.externalstorage/u0a9 (adj 0): depends on provider com.android.providers.media/.MediaProvider in dying proc android.process.media (adj 0)
06-03 12:21:44.304 126 161 I ActivityManager: Killing 4388:android.process.media/u0a11 (adj 0): timeout publishing content providers
06-03 12:21:44.306 126 143 E ActivityManager: Timeout waiting for provider com.android.providers.media/10011 for provider media providerRunning=false caller=com.android.externalstorage/10009
06-03 12:21:44.308 126 453 E ActivityManager: Timeout waiting for provider com.android.providers.downloads/10011 for provider com.android.providers.downloads.documents providerRunning=false caller=com.android.documentsui/10010
06-03 12:21:44.309 3422 3489 E ActivityThread: Failed to find provider info for com.android.providers.downloads.documents
06-03 12:21:44.313 126 161 I DropBoxManagerService: add tag=system_server_wtf isTagEnabled=true flags=0x2
06-03 12:21:44.317 3422 3489 W ProvidersCache: Failed to load some roots from com.android.providers.downloads.documents
06-03 12:21:44.317 3422 3489 W ProvidersCache: android.os.RemoteException: Failed to acquire provider for com.android.providers.downloads.documents
06-03 12:21:44.317 3422 3489 W ProvidersCache: at com.android.documentsui.DocumentsApplication.acquireUnstableProviderOrThrow(DocumentsApplication.java:67)
06-03 12:21:44.317 3422 3489 W ProvidersCache: at com.android.documentsui.roots.ProvidersCache.loadRootsForAuthority(ProvidersCache.java:308)
06-03 12:21:44.317 3422 3489 W ProvidersCache: at com.android.documentsui.roots.ProvidersCache.getRootOneshot(ProvidersCache.java:348)
06-03 12:21:44.317 3422 3489 W ProvidersCache: at com.android.documentsui.roots.ProvidersCache.getRootOneshot(ProvidersCache.java:341)
06-03 12:21:44.317 3422 3489 W ProvidersCache: at com.android.documentsui.roots.LoadRootTask.run(LoadRootTask.java:53)
06-03 12:21:44.317 3422 3489 W ProvidersCache: at com.android.documentsui.roots.LoadRootTask.run(LoadRootTask.java:31)
06-03 12:21:44.317 3422 3489 W ProvidersCache: at com.android.documentsui.base.CheckedTask.doInBackground(CheckedTask.java:65)
06-03 12:21:44.317 3422 3489 W ProvidersCache: at android.os.AsyncTask$3.call(AsyncTask.java:378)
06-03 12:21:44.317 3422 3489 W ProvidersCache: at java.util.concurrent.FutureTask.run(FutureTask.java:266)
06-03 12:21:44.317 3422 3489 W ProvidersCache: at com.android.documentsui.ProviderExecutor.run(ProviderExecutor.java:104)
06-03 12:21:44.319 3422 3422 W LoadRootTask: Failed to find root: content://com.android.providers.downloads.documents/root/downloads
06-03 12:21:44.360 126 144 I SurfaceFlinger: ALIEN: raising window: org.quantumbadger.redreader
06-03 12:21:44.407 37 37 D Zygote : Forked child process 4430
06-03 12:21:44.446 126 144 E SurfaceFlinger: ALIEN: posted to thumbnailed window, discarding.
06-03 12:21:44.430 126 161 I DropBoxManagerService: add tag=system_server_wtf isTagEnabled=true flags=0x2
06-03 12:21:44.463 126 162 I ActivityManager: Start proc 4430:android.process.media/u0a11 for content provider {com.android.providers.downloads/com.android.providers.downloads.DownloadStorageProvider}
06-03 12:21:44.474 126 144 I chatty : uid=1000(system) SFThread identical 1 line
06-03 12:21:44.493 126 144 E SurfaceFlinger: ALIEN: posted to thumbnailed window, discarding.
06-03 12:21:44.494 4430 4430 E d.process.medi: Not starting debugger since process cannot load the jdwp agent.
06-03 12:21:44.512 37 37 I Zygote : Process 4388 exited due to signal 9 (Killed)
06-03 12:21:44.568 126 144 E SurfaceFlinger: ALIEN: posted to thumbnailed window, discarding.
06-03 12:21:44.584 3422 3490 I ActivityThread: Removing dead content provider:android.content.ContentProviderProxy@34a9438
06-03 12:21:44.587 4430 4430 I d.process.medi: The ClassLoaderContext is a special shared library.
06-03 12:21:44.599 3422 3490 W DocumentsContract: Failed to create document
06-03 12:21:44.599 3422 3490 W DocumentsContract: java.lang.NullPointerException: Attempt to invoke virtual method ‘android.os.Parcelable android.os.Bundle.getParcelable(java.lang.String)’ on a null object reference
06-03 12:21:44.599 3422 3490 W DocumentsContract: at android.provider.DocumentsContract.createDocument(DocumentsContract.java:1329)
06-03 12:21:44.599 3422 3490 W DocumentsContract: at com.android.documentsui.DocumentsAccess$RuntimeDocumentAccess.createDocument(DocumentsAccess.java:139)
06-03 12:21:44.599 3422 3490 W DocumentsContract: at com.android.documentsui.picker.CreatePickedDocumentTask.run(CreatePickedDocumentTask.java:79)
06-03 12:21:44.599 3422 3490 W DocumentsContract: at com.android.documentsui.picker.CreatePickedDocumentTask.run(CreatePickedDocumentTask.java:42)
06-03 12:21:44.599 3422 3490 W DocumentsContract: at com.android.documentsui.base.CheckedTask.doInBackground(CheckedTask.java:65)
06-03 12:21:44.599 3422 3490 W DocumentsContract: at android.os.AsyncTask$3.call(AsyncTask.java:378)
06-03 12:21:44.599 3422 3490 W DocumentsContract: at java.util.concurrent.FutureTask.run(FutureTask.java:266)
06-03 12:21:44.599 3422 3490 W DocumentsContract: at com.android.documentsui.ProviderExecutor.run(ProviderExecutor.java:104)
06-03 12:21:44.609 3422 3490 W DocumentAccess: Failed to create document
06-03 12:21:44.609 3422 3490 W DocumentAccess: java.lang.NullPointerException: Attempt to invoke virtual method ‘android.os.Parcelable android.os.Bundle.getParcelable(java.lang.String)’ on a null object reference
06-03 12:21:44.609 3422 3490 W DocumentAccess: at android.provider.DocumentsContract.createDocument(DocumentsContract.java:1329)
06-03 12:21:44.609 3422 3490 W DocumentAccess: at com.android.documentsui.DocumentsAccess$RuntimeDocumentAccess.createDocument(DocumentsAccess.java:139)
06-03 12:21:44.609 3422 3490 W DocumentAccess: at com.android.documentsui.picker.CreatePickedDocumentTask.run(CreatePickedDocumentTask.java:79)
06-03 12:21:44.609 3422 3490 W DocumentAccess: at com.android.documentsui.picker.CreatePickedDocumentTask.run(CreatePickedDocumentTask.java:42)
06-03 12:21:44.609 3422 3490 W DocumentAccess: at com.android.documentsui.base.CheckedTask.doInBackground(CheckedTask.java:65)
06-03 12:21:44.609 3422 3490 W DocumentAccess: at android.os.AsyncTask$3.call(AsyncTask.java:378)
06-03 12:21:44.609 3422 3490 W DocumentAccess: at java.util.concurrent.FutureTask.run(FutureTask.java:266)
06-03 12:21:44.609 3422 3490 W DocumentAccess: at com.android.documentsui.ProviderExecutor.run(ProviderExecutor.java:104)
06-03 12:21:44.614 126 144 I SurfaceFlinger: ALIEN: new app: org.quantumbadger.redreader vs com.android.documentsui
06-03 12:21:44.615 126 144 E SurfaceFlinger: ALIEN: thumbnailing last window: com.android.documentsui
06-03 12:21:44.615 126 144 I SurfaceFlinger: ALIEN: raising window: org.quantumbadger.redreader
06-03 12:21:44.652 37 37 I Zygote : Process 4408 exited due to signal 9 (Killed)
06-03 12:21:44.674 37 37 D Zygote : Forked child process 4448
06-03 12:21:44.675 126 162 I ActivityManager: Start proc 4448:com.android.externalstorage/u0a9 for content provider {com.android.externalstorage/com.android.externalstorage.ExternalStorageProvider}
06-03 12:21:44.676 4430 4430 I d.process.medi: The ClassLoaderContext is a special shared library.
06-03 12:21:44.699 4448 4448 E externalstorag: Not starting debugger since process cannot load the jdwp agent.
06-03 12:21:44.704 126 164 I libprocessgroup: Successfully killed process cgroup uid 10009 pid 4408 in 400ms
06-03 12:21:44.726 37 4449 I zygote : Background young concurrent copying GC freed 2910(1968KB) AllocSpace objects, 0(0B) LOS objects, 68% free, 941KB/2986KB, paused 9.264ms total 40.569ms
06-03 12:21:44.772 4448 4448 I externalstorag: The ClassLoaderContext is a special shared library.
06-03 12:21:44.783 3422 3422 W BulkCursor: Remote process exception when closing
06-03 12:21:44.797 126 164 I libprocessgroup: Successfully killed process cgroup uid 10011 pid 4388 in 11ms
06-03 12:21:44.822 126 143 I ActivityTaskManager: notifySurfaceDiedIfNeeded: destroyingActivity = ActivityRecord{263e231 u0 com.android.documentsui/.picker.PickActivity t28076 f}
06-03 12:21:44.828 126 144 I SurfaceFlinger: ALIEN: app_closed_by_android: com.android.documentsui deleted associated window: 0xbdbdac80, on thread 144
06-03 12:21:44.850 4448 4448 D ExternalStorage: After updating volumes, found 4 active roots
06-03 12:21:44.866 4430 4430 I SQLiteConnection: /data/user/0/com.android.providers.media/databases/external.db-wal 82993312 bytes: Bigger than 1048576; truncating
06-03 12:21:44.868 3422 3490 W DirectoryLoader: Failed to query
06-03 12:21:44.868 3422 3490 W DirectoryLoader: android.os.OperationCanceledException: The operation has been canceled.
06-03 12:21:44.868 3422 3490 W DirectoryLoader: at android.os.CancellationSignal.throwIfCanceled(CancellationSignal.java:54)
06-03 12:21:44.868 3422 3490 W DirectoryLoader: at android.content.ContentProviderClient.query(ContentProviderClient.java:191)
06-03 12:21:44.868 3422 3490 W DirectoryLoader: at com.android.documentsui.DirectoryLoader.loadInBackground(DirectoryLoader.java:141)
06-03 12:21:44.868 3422 3490 W DirectoryLoader: at com.android.documentsui.DirectoryLoader.loadInBackground(DirectoryLoader.java:54)
06-03 12:21:44.868 3422 3490 W DirectoryLoader: at androidx.loader.content.AsyncTaskLoader.onLoadInBackground(AsyncTaskLoader.java:287)
06-03 12:21:44.868 3422 3490 W DirectoryLoader: at androidx.loader.content.AsyncTaskLoader$LoadTask.doInBackground(AsyncTaskLoader.java:56)
06-03 12:21:44.868 3422 3490 W DirectoryLoader: at androidx.loader.content.ModernAsyncTask$1.call(ModernAsyncTask.java:96)
06-03 12:21:44.868 3422 3490 W DirectoryLoader: at java.util.concurrent.FutureTask.run(FutureTask.java:266)
06-03 12:21:44.868 3422 3490 W DirectoryLoader: at com.android.documentsui.ProviderExecutor.run(ProviderExecutor.java:104)
06-03 12:21:44.977 4430 4430 V MediaProvider: onUpgrade() for external.db from 900 to 1023
06-03 12:21:45.025 126 180 I ALIEN : an application that is already active was moved to the foreground

Locat when using Twidere (at the moment I click on “save in gallery”)
06-03 12:23:51.824 126 229 D AlienEventHub: ALIEN: getVideoFrames is not supported
06-03 12:23:51.895 126 229 D AlienEventHub: ALIEN: getVideoFrames is not supported
06-03 12:23:51.972 7 7 E cutils : Failed to mkdirat(/storage/8ff87de4-0b37-4799-b09a-82773e869e07/Android/data): Read-only file system
06-03 12:23:51.973 2353 2353 W ContextImpl: Failed to ensure /storage/8ff87de4-0b37-4799-b09a-82773e869e07/Android/data/org.mariotaku.twidere/files/Pictures: java.lang.IllegalStateException: Failed to prepare /storage/8ff87de4-0b37-4799-b09a-82773e869e07/Android/data/org.mariotaku.twidere/files/Pictures/: android.os.ServiceSpecificException: (code -30)
06-03 12:23:52.351 2353 2353 W riotaku.twider: Accessing hidden field Landroid/widget/TextView;->mCursorDrawableRes:I (greylist-max-p, reflection, denied)
06-03 12:23:52.352 2353 2353 W riotaku.twider: Accessing hidden field Landroid/widget/TextView;->mTextSelectHandleLeftRes:I (greylist-max-p, reflection, denied)
06-03 12:23:52.364 2353 2353 W riotaku.twider: Accessing hidden field Landroid/widget/TextView;->mCursorDrawableRes:I (greylist-max-p, reflection, denied)
06-03 12:23:52.364 2353 2353 W riotaku.twider: Accessing hidden field Landroid/widget/TextView;->mTextSelectHandleLeftRes:I (greylist-max-p, reflection, denied)
06-03 12:23:52.370 2353 2353 W riotaku.twider: Accessing hidden field Landroid/widget/TextView;->mCursorDrawableRes:I (greylist-max-p, reflection, denied)
06-03 12:23:52.370 2353 2353 W riotaku.twider: Accessing hidden field Landroid/widget/TextView;->mTextSelectHandleLeftRes:I (greylist-max-p, reflection, denied)
06-03 12:23:52.372 2353 2353 W riotaku.twider: Accessing hidden field Landroid/widget/TextView;->mCursorDrawableRes:I (greylist-max-p, reflection, denied)
06-03 12:23:52.373 2353 2353 W riotaku.twider: Accessing hidden field Landroid/widget/TextView;->mTextSelectHandleLeftRes:I (greylist-max-p, reflection, denied)
06-03 12:23:52.374 2353 2353 W riotaku.twider: Accessing hidden field Landroid/widget/TextView;->mCursorDrawableRes:I (greylist-max-p, reflection, denied)
06-03 12:23:52.374 2353 2353 W riotaku.twider: Accessing hidden field Landroid/widget/TextView;->mTextSelectHandleLeftRes:I (greylist-max-p, reflection, denied)
06-03 12:23:52.513 126 144 E InputDispatcher: Window handle Window{ad9d70 u0 org.mariotaku.twidere/org.mariotaku.twidere.activity.MediaViewerActivity} has no registered input channel
06-03 12:23:52.523 37 37 D Zygote : Forked child process 4551
06-03 12:23:52.526 126 162 I ActivityManager: Start proc 4551:android.process.media/u0a11 for content provider {com.android.providers.media/com.android.providers.media.MediaProvider}
06-03 12:23:52.533 4551 4551 E d.process.medi: Not starting debugger since process cannot load the jdwp agent.
06-03 12:23:52.544 2353 2365 I riotaku.twider: NativeAlloc concurrent copying GC freed 13044(783KB) AllocSpace objects, 2(40KB) LOS objects, 16% free, 10MB/12MB, paused 89us total 175.670ms
06-03 12:23:52.574 4551 4551 I d.process.medi: The ClassLoaderContext is a special shared library.
06-03 12:23:52.650 4551 4551 I d.process.medi: The ClassLoaderContext is a special shared library.
06-03 12:23:52.689 4551 4551 I SQLiteConnection: /data/user/0/com.android.providers.media/databases/external.db-wal 82993312 bytes: Bigger than 1048576; truncating
06-03 12:23:52.745 4551 4551 V MediaProvider: onUpgrade() for external.db from 900 to 1023
06-03 12:23:54.544 4551 4551 D MediaProvider: Updating 3685 entries with well-known owners

[freeze here, then crash with the output]
06-03 12:24:02.363 4551 4551 W CursorWindow: Window is full: requested allocation 24 bytes, free space 22 bytes, window size 2097152 bytes
06-03 12:24:02.552 126 161 I ActivityManager: Killing 2353:org.mariotaku.twidere/u0a19 (adj 0): depends on provider com.android.providers.media/.MediaProvider in dying proc android.process.media (adj 0)
06-03 12:24:02.556 126 161 I ActivityManager: Killing 4551:android.process.media/u0a11 (adj 0): timeout publishing content providers
06-03 12:24:02.561 126 369 E ActivityManager: Timeout waiting for provider com.android.providers.media/10011 for provider media providerRunning=false caller=org.mariotaku.twidere/10019
06-03 12:24:02.563 126 161 I DropBoxManagerService: add tag=system_server_wtf isTagEnabled=true flags=0x2
06-03 12:24:02.632 37 37 I Zygote : Process 4551 exited due to signal 9 (Killed)
06-03 12:24:02.640 126 228 W InputDispatcher: channel ‘870fc27 org.mariotaku.twidere/org.mariotaku.twidere.activity.MediaViewerActivity (server)’ ~ Consumer closed input channel or an error occurred. events=0x9
06-03 12:24:02.640 126 228 E InputDispatcher: channel ‘870fc27 org.mariotaku.twidere/org.mariotaku.twidere.activity.MediaViewerActivity (server)’ ~ Channel is unrecoverably broken and will be disposed!
06-03 12:24:02.648 126 228 W InputDispatcher: channel ‘f7c12ec org.mariotaku.twidere/org.mariotaku.twidere.activity.HomeActivity (server)’ ~ Consumer closed input channel or an error occurred. events=0x9
06-03 12:24:02.648 126 228 E InputDispatcher: channel ‘f7c12ec org.mariotaku.twidere/org.mariotaku.twidere.activity.HomeActivity (server)’ ~ Channel is unrecoverably broken and will be disposed!
06-03 12:24:02.649 126 369 D ConnectivityService: ConnectivityService NetworkRequestInfo binderDied(NetworkRequest [ TRACK_DEFAULT id=36, [ Capabilities: INTERNET&NOT_RESTRICTED&TRUSTED Uid: 10019] ], android.os.BinderProxy@f73cd)
06-03 12:24:02.649 126 3511 D ConnectivityService: ConnectivityService NetworkRequestInfo binderDied(NetworkRequest [ LISTEN id=37, [ Capabilities: INTERNET&NOT_RESTRICTED&TRUSTED&FOREGROUND Uid: 10019] ], android.os.BinderProxy@96af482)
06-03 12:24:02.650 126 241 D ConnectivityService: releasing NetworkRequest [ TRACK_DEFAULT id=36, [ Capabilities: INTERNET&NOT_RESTRICTED&TRUSTED Uid: 10019] ] (release request)
06-03 12:24:02.651 126 463 I WindowManager: WIN DEATH: Window{870fc27 u0 org.mariotaku.twidere/org.mariotaku.twidere.activity.MediaViewerActivity}
06-03 12:24:02.651 126 463 W InputDispatcher: Attempted to unregister already unregistered input channel ‘870fc27 org.mariotaku.twidere/org.mariotaku.twidere.activity.MediaViewerActivity (server)’
06-03 12:24:02.654 126 453 I WindowManager: WIN DEATH: Window{f7c12ec u0 org.mariotaku.twidere/org.mariotaku.twidere.activity.HomeActivity}
06-03 12:24:02.654 126 453 W InputDispatcher: Attempted to unregister already unregistered input channel ‘f7c12ec org.mariotaku.twidere/org.mariotaku.twidere.activity.HomeActivity (server)’
06-03 12:24:02.656 37 37 I Zygote : Process 2353 exited due to signal 9 (Killed)
06-03 12:24:02.656 126 454 W ActivityManager: Scheduling restart of crashed service org.mariotaku.twidere/.service.JobTaskService in 1000ms
06-03 12:24:02.657 126 454 W ActivityTaskManager: Force removing ActivityRecord{8295710 u0 org.mariotaku.twidere/.activity.MediaViewerActivity t28080}: app died, no saved state
06-03 12:24:02.662 126 454 W ActivityTaskManager: Force removing ActivityRecord{9227e51 u0 org.mariotaku.twidere/.activity.HomeActivity t28079}: app died, no saved state
06-03 12:24:02.674 126 154 W ActivityManager: setHasOverlayUi called on unknown pid: 2353
06-03 12:24:02.678 126 144 I SurfaceFlinger: ALIEN: discarding frame without app/window (system process).
06-03 12:24:02.681 126 164 I libprocessgroup: Successfully killed process cgroup uid 10019 pid 2353 in 120ms
06-03 12:24:02.681 126 164 I libprocessgroup: Successfully killed process cgroup uid 10011 pid 4551 in 0ms
06-03 12:24:02.685 631 631 D FakeHome: onRestart
06-03 12:24:02.686 631 631 D FakeHome: onStart
06-03 12:24:02.687 631 631 D FakeHome: onResume
06-03 12:24:02.691 126 144 I SurfaceFlinger: ALIEN: discarding frame without app/window (system process).
06-03 12:24:03.190 126 180 I ALIEN : alien processing window (de-)activation: 1. TARGET/SOURCE PKG: com.jolla.home
06-03 12:24:03.192 126 180 I ALIEN : alien moving home to foreground: com.android.systemui
06-03 12:24:03.195 126 180 I ActivityTaskManager: START u0 {act=android.intent.action.MAIN cat=[android.intent.category.HOME] flg=0x10240000 cmp=com.jolla.home/.FakeHome (has extras)} from uid 1000
06-03 12:24:02.788 126 144 I chatty : uid=1000(system) SFThread identical 5 lines
06-03 12:24:02.805 126 144 I SurfaceFlinger: ALIEN: discarding frame without app/window (system process).
06-03 12:24:03.198 631 631 D FakeHome: onPause
06-03 12:24:03.199 631 631 D FakeHome: onResume
06-03 12:24:03.239 126 144 I SurfaceFlinger: ALIEN: discarding frame without app/window (system process).
06-03 12:24:03.702 126 180 I ALIEN : already inactive
06-03 12:24:03.896 126 180 I ALIEN : already inactive

The other apps have similar outputs in logcat.

Edit: Mark logcat output as preformated text

I see this but it didn’t fix the issue to chown :

It seems to have been resolved by itself. No after a reboot or what (multiple attempts where made before), I don’t know what happend.