Some ashmem based objects can not be created due to file descriptor leak

记录了Android系统上基于ashmem或Fd的一些对象由于进程内文件描述符耗尽不能被创建的Issues。

Example One.

06-22 22:38:05.949 27928 31688 E CursorWindow: Could not allocate CursorWindow '/data/data/com.android.providers.downloads/databases/downloads.db' of size 2097152due to error -24.

06-22 22:38:05.969 27928 31688 W dalvikvm: threadid=16: thread exiting with uncaught exception (group=0x40adf9f0)

06-22 22:38:05.989 27928 31688 E AndroidRuntime: FATAL EXCEPTION: Download Service

06-22 22:38:05.989 27928 31688 E AndroidRuntime: android.database.CursorWindowAllocationException: Cursor window allocation of 2048 kb failed.

06-22 22:38:05.989 27928 31688 E AndroidRuntime:  at android.database.CursorWindow.<init>(CursorWindow.java:104)

06-22 22:38:05.989 27928 31688 E AndroidRuntime:  at android.database.AbstractWindowedCursor.clearOrCreateWindow(AbstractWindowedCursor.java:198)

06-22 22:38:05.989 27928 31688 E AndroidRuntime:  at android.database.sqlite.SQLiteCursor.fillWindow(SQLiteCursor.java:162)

06-22 22:38:05.989 27928 31688 E AndroidRuntime:  at android.database.sqlite.SQLiteCursor.getCount(SQLiteCursor.java:156)

06-22 22:38:05.989 27928 31688 E AndroidRuntime:  at android.content.ContentResolver.query(ContentResolver.java:317)

06-22 22:38:05.989 27928 31688 E AndroidRuntime:  at com.android.providers.downloads.DownloadService$UpdateThread.run(DownloadService.java:307)

06-22 22:38:06.059   371  1289 W ActivityManager: Force-killing crashed app android.process.media at watcher's request

06-22 22:38:06.099   371  1288 I ActivityManager: Process android.process.media (pid 27928) has died.

06-22 22:38:06.099   371  1288 W ActivityManager: Scheduling restart of crashed service com.android.providers.downloads/.DownloadService in 5000ms

06-22 22:38:06.099   371  1288 W ActivityManager: Scheduling restart of crashed service com.android.providers.media/.MtpService in 34999ms

Before these lines, there are too many following lines,

06-26 16:28:25.519 I/DownloadManager(13356): Initiating request for download 46

                       **** in DownloadThread::run@DownloadThread.java. called in DownloadInfo::startDownloadThread().

06-26 16:28:25.679 D/-heap   (13356): GC_CONCURRENT freed 1080K, 18% free 7724K/9379K, paused 11ms+49ms

06-26 16:28:25.979 D/ActivityThread(13356): Loading provider downloads: com.android.providers.downloads.DownloadProvider

                      **** in ActivityThread::installProvider@ActivityThread.java, which is called in acquireProvider(arg0, arg1) & installContentProviders

06-26 16:28:26.139 D/ActivityThread(13356): Loading provider downloads: com.android.providers.downloads.DownloadProvider

06-26 16:28:26.329 D/ActivityThread(13356): Loading provider downloads: com.android.providers.downloads.DownloadProvider

06-26 16:28:26.499 D/ActivityThread(13356): Loading provider downloads: com.android.providers.downloads.DownloadProvider

 

Example Two.

Can’t open DB due to too many open files

04-23 15:27:32.251 15705 15732 ISystem.out: [stdin] Error intestSendEmailWithAttachment:

04-23 15:27:32.251 15705 15732 ISystem.out: [stdin]android.database.sqlite.SQLiteCantOpenDatabaseException: unable to open database file

04-23 15:27:32.251 15705 15732 ISystem.out: [stdin]           atandroid.database.sqlite.SQLiteDatabase.dbopen(Native Method)

04-23 15:27:32.251 15705 15732 ISystem.out: [stdin]           atandroid.database.sqlite.SQLiteDatabase.openDatabase(SQLiteDatabase.java:1017

04-23 15:27:32.251 15705 15732 ISystem.out: [stdin]           atandroid.database.sqlite.SQLiteDatabase.openDatabase(SQLiteDatabase.java:990)

04-23 15:27:32.251 15705 15732 ISystem.out: [stdin]           atandroid.database.sqlite.SQLiteDatabase.openOrCreateDatabase(SQLiteDatabase.java:1055)

04-23 15:27:32.251 15705 15732 ISystem.out: [stdin]           atandroid.app.ContextImpl.openOrCreateDatabase(ContextImpl.java:803)

04-23 15:27:32.251 15705 15732 ISystem.out: [stdin]           atandroid.database.sqlite.SQLiteOpenHelper.getWritableDatabase(SQLiteOpenHelper.java:157)

04-23 15:27:32.251 15705 15732 ISystem.out: [stdin]           atcom.android.email.provider.EmailProvider.getDatabase(EmailProvider.java:879)

04-23 15:27:32.251 15705 15732 ISystem.out: [stdin]           atcom.android.email.provider.EmailProvider.query(EmailProvider.java:1866)

04-23 15:27:32.251 15705 15732 ISystem.out: [stdin]           atandroid.content.ContentProvider$Transport.query(ContentProvider.java:178)

……

…...

04-23 15:27:32.261 15742 15756 ITestRunner: started:testSendEmailWithAttachment(com.android.email.activity.SendEmailWithATTTest)

 

04-13 21:42:12.350  6762  6831 E CursorWindow:Could not allocateCursorWindow '/data/data/com.android.email/databases/EmailProvider.db' of size 2097152 due to error -24.

04-13 21:42:12.360  6762  6831 W System.err: android.database.CursorWindowAllocationException: Cursor window allocation of 2048 kb failed. # Open Cursors=685 (# cursors opened by this proc=685)

04-13 21:42:12.360  6762  6831 W System.err:         at android.database.CursorWindow.<init>(CursorWindow.java:104)

04-13 21:42:12.360  6762  6831 W System.err:         at android.database.AbstractWindowedCursor.clearOrCreateWindow(AbstractWindowedCursor.java:198)

04-13 21:42:12.360  6762  6831 W System.err:         at android.database.sqlite.SQLiteCursor.fillWindow(SQLiteCursor.java:162)

04-13 21:42:12.360  6762  6831 W System.err:         at android.database.sqlite.SQLiteCursor.getCount(SQLiteCursor.java:156)

04-13 21:42:12.370  6762  6831 W System.err:         at android.database.AbstractCursor.moveToPosition(AbstractCursor.java:161)

04-13 21:42:12.370  6762  6831 W System.err:         at com.android.email.provider.ContentCache.putCursor(ContentCache.java:478)

04-13 21:42:12.370  6762  6831 W System.err:         at com.android.email.provider.EmailProvider.query(EmailProvider.java:1970)

04-13 21:42:12.370  6762  6831 W System.err:         at com.android.email.provider.EmailProvider.preCacheTable(EmailProvider.java:927)

04-13 21:42:12.370  6762  6831 W System.err:         at com.android.email.provider.EmailProvider.preCacheData(EmailProvider.java:988)

04-13 21:42:12.370  6762  6831 W System.err:         at com.android.email.provider.EmailProvider.getDatabase(EmailProvider.java:909)

04-13 21:42:12.380  6762  6831 W System.err:         at com.android.email.provider.EmailProvider.query(EmailProvider.java:1866)

04-13 21:42:12.380  6762  6831 W System.err:         at android.content.ContentProvider$Transport.query(ContentProvider.java:178)

04-13 21:42:12.380  6762  6831 W System.err:         at android.content.ContentResolver.query(ContentResolver.java:311)

when the issue happens, there always are the multiple loading of email provider observed from log file.
•04-13 21:41:56.670  6762  6831 D ActivityThread: Loading provider com.android.email.provider;com.android.email.notifier: com.android.email.provider.EmailProvider
•04-13 21:41:57.060  6762  6776 D ActivityThread:Loading provider com.android.email.provider;com.android.email.notifier: com.android.email.provider.EmailProvider
•04-13 21:41:57.400  6762  6776 D ActivityThread: Loading provider com.android.email.provider;com.android.email.notifier: com.android.email.provider.EmailProvider
•04-13 21:41:57.590  6762  6776 D ActivityThread: Loading provider com.android.email.provider;com.android.email.notifier: com.android.email.provider.EmailProvider
 
Example three.

02-03 20:04:52.427 E/InputChannel-JNI(  886): Error 24 dup channel fd 1009.
02-03 20:04:52.447 I/DropBoxManager(  604): tag = system_app_crash; data = Process: com.android.phone
02-03 20:04:52.447 I/DropBoxManager(  604):
02-03 20:04:52.447 I/DropBoxManager(  604): java.lang.RuntimeException: Could not read input channel file descriptors from parcel.
02-03 20:04:52.447 I/DropBoxManager(  604):  at android.view.InputChannel.nativeReadFromParcel(Native Method)
02-03 20:04:52.447 I/DropBoxManager(  604):  at android.view.InputChannel.readFromParcel(InputChannel.java:135)
02-03 20:04:52.447 I/DropBoxManager(  604):  at android.view.IWindowSession$Stub$Proxy.add(IWindowSession.java:523)
02-03 20:04:52.447 I/DropBoxManager(  604):  at android.view.ViewRootImpl.setView(ViewRootImpl.java:551)
02-03 20:04:52.447 I/DropBoxManager(  604):  at android.view.WindowManagerImpl.addView(WindowManagerImpl.java:326)
02-03 20:04:52.447 I/DropBoxManager(  604):  at android.view.WindowManagerImpl.addView(WindowManagerImpl.java:224)
02-03 20:04:52.447 I/DropBoxManager(  604):  at android.view.WindowManagerImpl$CompatModeWrapper.addView(WindowManagerImpl.java:149)
02-03 20:04:52.447 I/DropBoxManager(  604):  at android.view.Window$LocalWindowManager.addView(Window.java:547)
02-03 20:04:52.447 I/DropBoxManager(  604):  at android.app.ActivityThread.handleResumeActivity(ActivityThread.java:2650)
02-03 20:04:52.447 I/DropBoxManager(  604):  at android.app.ActivityThread.handleLaunchActivity(ActivityThread.java:2095)
02-03 20:04:52.447 I/DropBoxManager(  604):  at android.app.ActivityThread.access$600(ActivityThread.java:136)
02-03 20:04:52.447 I/DropBoxManager(  604):  at android.app.ActivityThread$H.handleMessage(ActivityThread.java:1201)
02-03 20:04:52.447 I/DropBoxManager(  604):  at android.os.Handler.dispatchMessage(Handler.java:99)
02-03 20:04:52.447 I/DropBoxManager(  604):  at android.os.Looper.loop(Looper.java:137)
02-03 20:04:52.447 I/DropBoxManager(  604):  at android.app.ActivityThread.main(ActivityThread.java:4790)
02-03 20:04:52.447 I/DropBoxManager(  604):  at java.lang.reflect.Method.invokeNative(Native Method)
02-03 20:04:52.447 I/DropBoxManager(  604):  at java.lang.reflect.Method.invoke(Method.java:511)
02-03 20:04:52.447 I/DropBoxManager(  604):  at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:798)
02-03 20:04:52.447 I/DropBoxManager(  604):  at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:565)
02-03 20:04:52.447 I/DropBoxManager(  604):  at dalvik.system.NativeStart.main(Native Method)

02-03 20:04:52.367 E/CursorWindow(  886):Could not create CursorWindow from Parcel due to error -24.
02-03 20:04:52.447 W/AsyncQuery(  886): Exception thrown during handling EVENT_ARG_QUERY
02-03 20:04:52.447 W/AsyncQuery(  886): android.database.CursorWindowAllocationException: Cursor window could not be created from binder.
02-03 20:04:52.447 W/AsyncQuery(  886):  at android.database.CursorWindow.<init>(CursorWindow.java:133)
02-03 20:04:52.447 W/AsyncQuery(  886):  at android.database.CursorWindow.<init>(CursorWindow.java:41)
02-03 20:04:52.447 W/AsyncQuery(  886):  at android.database.CursorWindow$1.createFromParcel(CursorWindow.java:681)
02-03 20:04:52.447 W/AsyncQuery(  886):  at android.database.CursorWindow$1.createFromParcel(CursorWindow.java:679)
02-03 20:04:52.447 W/AsyncQuery(  886):  at android.database.BulkCursorDescriptor.readFromParcel(BulkCursorDescriptor.java:75)
02-03 20:04:52.447 W/AsyncQuery(  886):  at android.database.BulkCursorDescriptor$1.createFromParcel(BulkCursorDescriptor.java:34)
02-03 20:04:52.447 W/AsyncQuery(  886):  at android.database.BulkCursorDescriptor$1.createFromParcel(BulkCursorDescriptor.java:30)
02-03 20:04:52.447 W/AsyncQuery(  886):  at android.content.ContentProviderProxy.query(ContentProviderNative.java:369)
02-03 20:04:52.447 W/AsyncQuery(  886):  at android.content.ContentResolver.query(ContentResolver.java:370)
02-03 20:04:52.447 W/AsyncQuery(  886):  at android.content.ContentResolver.query(ContentResolver.java:313)
02-03 20:04:52.447 W/AsyncQuery(  886):  at android.content.AsyncQueryHandler$WorkerHandler.handleMessage(AsyncQueryHandler.java:79)
02-03 20:04:52.447 W/AsyncQuery(  886):  at com.android.internal.telephony.CallerInfoAsyncQuery$CallerInfoAsyncQueryHandler$CallerInfoWorkerHandler.handleMessage(CallerInfoAsyncQuery.java:152)
02-03 20:04:52.447 W/AsyncQuery(  886):  at android.os.Handler.dispatchMessage(Handler.java:99)
02-03 20:04:52.447 W/AsyncQuery(  886):  at android.os.Looper.loop(Looper.java:137)
02-03 20:04:52.447 W/AsyncQuery(  886):  at android.os.HandlerThread.run(HandlerThread.java:60)

Reason for Example One and Two
are both for DatabaseConnection File descriptor leaks.
 
Analysis for Example Three

From the log
02-03 20:04:52.427 E/InputChannel-JNI(  886): Error 24 dup channel fd 1009.
02-03 20:04:52.447 I/DropBoxManager(  604): java.lang.RuntimeException: Could not read input channel file descriptors from parcel.
and
02-03 20:04:52.367 E/CursorWindow(  886): Could not create CursorWindow from Parcel due to error -24.
02-03 20:04:52.447 W/AsyncQuery(  886): Exception thrown during handling EVENT_ARG_QUERY

File descriptors are used out when the app dups InputChannel and CursorWindow FDs.
The app dups FDs transferred from the binder to use the ashmem for InputChannel or CursorWindow.

The FD in "Error 24 dup channel fd 1009" is 1009, a little less than max number of Fds a process can open.
When FDs are used out, error occurs in FDs dup.

So, there is InputChannel or Cursor or common FD leaks in the phone app.

It was found at last that there are binder fd leaks in the phone app.
    public void release() @ XxxxCallerInfoHandler.java
    {
        mIsReady = false;
        if (mCallTimer != null)
            mCallTimer.cancelTimer();
        mCallTimer = null;

        mCallInfoHandler = null;

        // Fixed the binder leak issue.
        if (mLoadSnsThreadHandler != null)
        {
            mLoadSnsThreadHandler.removeMessages(EVENT_LOAD_SNS);
            mLoadSnsThreadHandler.getLooper().quit();
            mLoadSnsThreadHandler = null;
        }
    }
所以,遇到errno -24,EMFILE,这样的问题,就是竭尽所能找到耗尽File Descriptors的代码所在。
出错的地方并不一定是原因所在,如果有Ramdump这是比较容易的事情。
 
END
评论 3
添加红包

请填写红包祝福语或标题

红包个数最小为10个

红包金额最低5元

当前余额3.43前往充值 >
需支付:10.00
成就一亿技术人!
领取后你会自动成为博主和红包主的粉丝 规则
hope_wisdom
发出的红包
实付
使用余额支付
点击重新获取
扫码支付
钱包余额 0

抵扣说明:

1.余额是钱包充值的虚拟货币,按照1:1的比例进行支付金额的抵扣。
2.余额无法直接购买下载,可以购买VIP、付费专栏及课程。

余额充值