CMFileManager cause system to crash and go into bootanimation when unmounting usb storage

Question

CMFileManager cause system to crash and go into bootanimation when unmounting usb storage

Closed this issue 12 years ago · 2 comments

Steps to reproduce the issue:

Open up a video file from external usb storage and using the back key to stop the video after a while
Unmount usb storage
System crashed and go into boot animation

I am not certain if this is consider a bug since the issue seem to be due to CMFileManager still accessing to the usb storage and system is unable to cope with that. However trying with other file managers executing the same steps does not cause any crash.

Unfortunately, I am not using the official CM build nor official CM device. Its an Allwinner A10 device.

/ActivityManager( 156): Displayed com.android.settings/.Settings: +574ms
D/ConnectivityService( 156): onUidRulesChanged(uid=10046, uidRules=0)
D/AudioHardware( 97): AudioHardware pcm playback is going to standby.
D/AudioHardware( 97): closePcmOut_l() mPcmOpenCnt: 1
D/AudioHardware( 97): AudioHardware pcm playback is exiting standby.
D/AudioHardware( 97): openPcmOut_l() mPcmOpenCnt: 0
I/ActivityManager( 156): Start proc com.android.defcontainer for service com.android.defcontainer/.DefaultContainerService: pid=1111 uid=10010 gids={1015, 2001}
D/dalvikvm( 435): GC_CONCURRENT freed 172K, 4% free 7217K/7495K, paused 2ms+3ms
D/VoldCmdListener( 90): asec fspath com.mobjoy.roadwarrior-1
D/VoldCmdListener( 90): asec fspath com.mobjoy.roadwarrior-1
D/dalvikvm( 156): GC_CONCURRENT freed 451K, 8% free 9493K/10311K, paused 2ms+4ms
D/dalvikvm( 435): GC_CONCURRENT freed 372K, 7% free 7283K/7751K, paused 2ms+2ms
D/AudioHardware( 97): AudioHardware pcm playback is going to standby.
D/AudioHardware( 97): closePcmOut_l() mPcmOpenCnt: 1
D/VoldCmdListener( 90): storage users /mnt/usb_storage
D/AudioHardware( 97): AudioHardware pcm playback is exiting standby.
D/AudioHardware( 97): openPcmOut_l() mPcmOpenCnt: 0
I/PackageManager( 156): Updating external media status from mounted to unmounted
D/VoldCmdListener( 90): asec list
D/VoldCmdListener( 90): asec path com.mobjoy.roadwarrior-1
I/PackageManager( 156): Removing non-system package:com.mobjoy.roadwarrior
D/VoldCmdListener( 90): asec path com.pocketgems.android.chasingyello-1
I/ActivityManager( 156): Force stopping package com.mobjoy.roadwarrior uid=10044
I/ActivityManager( 156): Force stopping package com.mobjoy.roadwarrior uid=10044
D/PackageManager( 156): generateServicesMap(android.accounts.AccountAuthenticator): 1 services unchanged
W/InputManagerService( 156): Window already focused, ignoring focus gain of: com.android.internal.view.IInputMethodClient$Stub$Proxy@412af070
D/dalvikvm( 351): GC_EXPLICIT freed 1468K, 21% free 7587K/9543K, paused 2ms+6ms
D/PackageManager( 156): generateServicesMap(android.content.SyncAdapter): 5 services unchanged
D/dalvikvm( 405): GC_EXPLICIT freed 148K, 7% free 6797K/7239K, paused 1ms+2ms
D/BackupManagerService( 156): Received broadcast Intent { act=android.intent.action.EXTERNAL_APPLICATIONS_UNAVAILABLE flg=0x10000010 (has extras) }
V/BackupManagerService( 156): removePackageParticipantsLocked: #1
D/dalvikvm( 156): GC_CONCURRENT freed 735K, 8% free 9570K/10375K, paused 3ms+4ms
D/dalvikvm( 156): GC_EXPLICIT freed 290K, 9% free 9462K/10375K, paused 3ms+5ms
D/dalvikvm( 156): GC_EXPLICIT freed 31K, 10% free 9431K/10375K, paused 3ms+4ms
D/VoldCmdListener( 90): asec unmount com.mobjoy.roadwarrior-1 force
D/VoldCmdListener( 90): storage users /mnt/usb_storage
W/ActivityManager( 156): Killing processes unmount media at adjustment 0
D/VoldCmdListener( 90): storage users /mnt/usb_storage
I/MountService( 156): Retrying to kill storage users again
D/VoldCmdListener( 90): storage users /mnt/usb_storage
W/ActivityManager( 156): Killing processes unmount media at adjustment 0
D/VoldCmdListener( 90): storage users /mnt/usb_storage
I/MountService( 156): Retrying to kill storage users again
D/VoldCmdListener( 90): storage users /mnt/usb_storage
D/dalvikvm( 351): GC_CONCURRENT freed 248K, 19% free 7757K/9543K, paused 2ms+4ms
W/ActivityManager( 156): Killing processes unmount media at adjustment 0
D/VoldCmdListener( 90): storage users /mnt/usb_storage
I/MountService( 156): Retrying to kill storage users again
D/VoldCmdListener( 90): storage users /mnt/usb_storage
W/ActivityManager( 156): Killing processes unmount media at adjustment 0
D/VoldCmdListener( 90): storage users /mnt/usb_storage
I/MountService( 156): Retrying to kill storage users again
D/VoldCmdListener( 90): storage users /mnt/usb_storage
W/ActivityManager( 156): Killing processes unmount media at adjustment 0
D/VoldCmdListener( 90): storage users /mnt/usb_storage
I/MountService( 156): Failed to unmount media inspite of 4 retries. Forcibly killing processes now
D/dalvikvm( 156): GC_EXPLICIT freed 64K, 10% free 9429K/10375K, paused 2ms+4ms
I/PackageManager( 156): Updating external media status from unmounted to unmounted
D/VoldCmdListener( 90): volume unmount /mnt/usb_storage force
D/Vold ( 90): Volume udisk state changing 4 (Mounted) -> 5 (Unmounting)
D/MountService( 156): sendStorageIntent Intent { act=android.intent.action.MEDIA_EJECT dat=file:///mnt/usb_storage (has extras) }
D/MediaProvider( 294): deleting all entries for storage StorageVolume [mAllowMassStorage=false, mDescription=USB storage, mEmulated=false, mMaxFileSize=0, mMtpReserveSpace=100, mPath=/mnt/usb_storage, mRemovable=true, mStorageId=196609]
D/dalvikvm( 435): GC_CONCURRENT freed 398K, 7% free 7334K/7815K, paused 2ms+5ms
D/AudioHardware( 97): AudioHardware pcm playback is going to standby.
D/AudioHardware( 97): closePcmOut_l() mPcmOpenCnt: 1
E/ProcessKiller( 90): Process /system/bin/sh (845) has cwd within /mnt/usb_storage
E/ProcessKiller( 90): Process /system/bin/sh (845) has cwd within /mnt/usb_storage
E/ProcessKiller( 90): Process /system/bin/sh (845) has cwd within /mnt/usb_storage
E/ProcessKiller( 90): Process /system/bin/sh (845) has cwd within /mnt/usb_storage
E/ProcessKiller( 90): Process /system/bin/sh (845) has cwd within /mnt/usb_storage
E/ProcessKiller( 90): Process /system/bin/sh (845) has cwd within /mnt/usb_storage
E/ProcessKiller( 90): Process /system/bin/sh (845) has cwd within /mnt/usb_storage
E/ProcessKiller( 90): Process /system/bin/sh (845) has cwd within /mnt/usb_storage
E/ProcessKiller( 90): Process /system/bin/sh (845) has cwd within /mnt/usb_storage
W/Vold ( 90): Failed to unmount /mnt/usb_storage (Device or resource busy, retries 140, action 0)
E/ProcessKiller( 90): Process /system/bin/sh (845) has cwd within /mnt/usb_storage
E/ProcessKiller( 90): Process /system/bin/sh (845) has cwd within /mnt/usb_storage
E/ProcessKiller( 90): Process /system/bin/sh (845) has cwd within /mnt/usb_storage
E/ProcessKiller( 90): Process /system/bin/sh (845) has cwd within /mnt/usb_storage
E/ProcessKiller( 90): Process /system/bin/sh (845) has cwd within /mnt/usb_storage
E/ProcessKiller( 90): Process /system/bin/sh (845) has cwd within /mnt/usb_storage
W/Vold ( 90): subsystem found in netlink event
D/Vold ( 90): scsi_device, 2
E/ProcessKiller( 90): Process /system/bin/sh (845) has cwd within /mnt/usb_storage
I/MemorySettings( 435): Received storage state changed notification that /mnt/usb_storage changed state from mounted to unmounted
I/VideoPlayActivity( 1069): Received storage state changed notification that /mnt/usb_storage changed state from mounted to unmounted
D/DirectVolume( 90): current mounted dev exist,access devicePath: /dev/block/vold/8:0 ;partitionNum: 0
E/Vold ( 90): Volume udisk unmount request when not mounted
E/DirectVolume( 90): Failed to unmount volume on bad removal (Invalid argument)
E/DirectVolume( 90): handlePartitionRemoved,ready to unlink: /dev/block/vold/8:0
D/DirectVolume( 90): Volume udisk /mnt/usb_storage disk 8:0 removed
E/DirectVolume( 90): handleDiskRemoved,ready to unlink: /dev/block/vold/8:0
E/DirectVolume( 90): Failed to unlink /dev/block/vold/8:0
D/Vold ( 90): Volume udisk state changing 5 (Unmounting) -> 0 (No-Media)
D/MountService( 156): volume state changed for /mnt/usb_storage (mounted -> unmounted)
W/Vold ( 90): subsystem found in netlink event
D/Vold ( 90): usb, 2
W/Vold ( 90): subsystem found in netlink event
D/Vold ( 90): usb, 2
I/StorageNotification( 223): Media {/mnt/usb_storage} state changed from {mounted} -> {unmounted}
D/MountService( 156): sendStorageIntent Intent { act=unmounted dat=file:///mnt/usb_storage (has extras) }
D/dalvikvm( 435): GC_CONCURRENT freed 434K, 7% free 7336K/7879K, paused 1ms+3ms
E/ProcessKiller( 90): Process /system/bin/sh (845) has cwd within /mnt/usb_storage
E/ProcessKiller( 90): Process /system/bin/sh (845) has cwd within /mnt/usb_storage
E/ProcessKiller( 90): Process /system/bin/sh (845) has cwd within /mnt/usb_storage
W/Vold ( 90): Failed to unmount /mnt/usb_storage (Device or resource busy, retries 130, action 1)
E/ProcessKiller( 90): Process /system/bin/sh (845) has cwd within /mnt/usb_storage
W/ProcessKiller( 90): Sending SIGHUP to process 845
E/ProcessKiller( 90): Process /system/bin/sh (845) has cwd within /mnt/usb_storage
W/ProcessKiller( 90): Sending SIGHUP to process 845
E/ProcessKiller( 90): Process /system/bin/sh (845) has cwd within /mnt/usb_storage
W/ProcessKiller( 90): Sending SIGHUP to process 845
E/ProcessKiller( 90): Process /system/bin/sh (845) has cwd within /mnt/usb_storage
W/ProcessKiller( 90): Sending SIGHUP to process 845
E/ProcessKiller( 90): Process /system/bin/sh (845) has cwd within /mnt/usb_storage
W/ProcessKiller( 90): Sending SIGHUP to process 845
E/VoldConnector( 156): doCommandLocked: wait mResponseQueue time out.
E/ProcessKiller( 90): Process /system/bin/sh (845) has cwd within /mnt/usb_storage
W/ProcessKiller( 90): Sending SIGHUP to process 845
E/ProcessKiller( 90): Process /system/bin/sh (845) has cwd within /mnt/usb_storage
W/ProcessKiller( 90): Sending SIGHUP to process 845
E/ProcessKiller( 90): Process /system/bin/sh (845) has cwd within /mnt/usb_storage
W/ProcessKiller( 90): Sending SIGHUP to process 845
E/ProcessKiller( 90): Process /system/bin/sh (845) has cwd within /mnt/usb_storage
W/ProcessKiller( 90): Sending SIGHUP to process 845
E/ProcessKiller( 90): Process /system/bin/sh (845) has cwd within /mnt/usb_storage
W/ProcessKiller( 90): Sending SIGHUP to process 845
W/Vold ( 90): Failed to unmount /mnt/usb_storage (Device or resource busy, retries 120, action 2)
E/ProcessKiller( 90): Process /system/bin/sh (845) has cwd within /mnt/usb_storage
E/ProcessKiller( 90): Sending SIGKILL to process 845
I/Vold ( 90): /mnt/usb_storage sucessfully unmounted
I/Vold ( 90): /mnt/usb_storage unmounted sucessfully
D/Vold ( 90): Volume udisk state changing 0 (No-Media) -> 1 (Idle-Unmounted)
E/MountService( 156): Unexpected response code 200
D/VoldCmdListener( 90): volume shared /mnt/sdcard ums
D/VoldCmdListener( 90): asec fspath com.mobjoy.roadwarrior-1
W/dalvikvm( 156): threadid=15: thread exiting with uncaught exception (group=0x40a361f8)
I/MemorySettings( 435): Received storage state changed notification that /mnt/usb_storage changed state from unmounted to removed
D/MountService( 156): volume state changed for /mnt/usb_storage (unmounted -> removed)
D/MountService( 156): sendStorageIntent Intent { act=android.intent.action.MEDIA_REMOVED dat=file:///mnt/usb_storage (has extras) }
D/MountService( 156): volume state changed for /mnt/usb_storage (removed -> unmounted)
D/MountService( 156): sendStorageIntent Intent { act=android.intent.action.MEDIA_UNMOUNTED dat=file:///mnt/usb_storage (has extras) }
D/MediaScannerReceiver( 294): action: android.intent.action.MEDIA_UNMOUNTED path: /mnt/usb_storage
I/VideoPlayActivity( 1069): Received storage state changed notification that /mnt/usb_storage changed state from unmounted to removed
I/VideoPlayActivity( 1069): Received storage state changed notification that /mnt/usb_storage changed state from removed to unmounted
I/StorageNotification( 223): Media {/mnt/usb_storage} state changed from {unmounted} -> {removed}
I/StorageNotification( 223): Media {/mnt/usb_storage} state changed from {removed} -> {unmounted}
D/VoldCmdListener( 90): volume shared /mnt/sdcard ums
E/AndroidRuntime( 156): *** FATAL EXCEPTION IN SYSTEM PROCESS: PackageManager
E/AndroidRuntime( 156): java.lang.IllegalStateException: Unexpected response code 212
E/AndroidRuntime( 156): at com.android.server.MountService.getSecureContainerFilesystemPath(MountService.java:1799)
E/AndroidRuntime( 156): at com.android.internal.content.PackageHelper.getSdFilesystem(PackageHelper.java:142)
E/AndroidRuntime( 156): at com.android.server.pm.PackageManagerService.getPackageSizeInfoLI(PackageManagerService.java:7356)
E/AndroidRuntime( 156): at com.android.server.pm.PackageManagerService.access$3300(PackageManagerService.java:152)
E/AndroidRuntime( 156): at com.android.server.pm.PackageManagerService$10.run(PackageManagerService.java:7324)
E/AndroidRuntime( 156): at android.os.Handler.handleCallback(Handler.java:605)
E/AndroidRuntime( 156): at android.os.Handler.dispatchMessage(Handler.java:92)
E/AndroidRuntime( 156): at android.os.Looper.loop(Looper.java:137)
E/AndroidRuntime( 156): at android.os.HandlerThread.run(HandlerThread.java:60)
I/MemorySettings( 435): Received storage state changed notification that /mnt/usb_storage changed state from removed to unmounted
I/Process ( 156): Sending signal. PID: 156 SIG: 9
I/ServiceManager( 89): service 'wifip2p' died
I/ServiceManager( 89): service 'country_detector' died
I/ServiceManager( 89): service 'search' died
I/ServiceManager( 89): service 'wallpaper' died
I/ServiceManager( 89): service 'mount' died
I/ServiceManager( 89): service 'connectivity' died
I/ServiceManager( 89): service 'throttle' died
I/ServiceManager( 89): service 'dropbox' died
I/ServiceManager( 89): service 'devicestoragemonitor' died
I/ServiceManager( 89): service 'location' died
I/ServiceManager( 89): service 'netstats' died
I/ServiceManager( 89): service 'telephony.registry' died

Answer 1 · 2013-01-09T22:44:11.000Z

First at all, thanks for your trace.

Reading the trace, "E/ProcessKiller( 90): Process /system/bin/sh (845) has cwd within /mnt/usb_storage" looks like the cause of the process killing. I have not been able to reproduce it, but looks like cwd over the unmount filesystem is the cause.
The last days i merged some patches that removes the execution of any cd command, and, in this patch http://review.cyanogenmod.org/#/c/29921/, cd and pwd commands were removed completely, and the initial directory of the shell moved to /. So now, the console should not cause the unmount locking and the os shouldn't start killing all the process, because the working directory is not any storage volume.

Could you try to reproduce the bug with this last change?

Answer 2 · 2013-01-12T08:40:28.000Z

thanks for taking the time to look into the issue. Yes, it has indeed been resolved.