由UI主线程查询数据库引起的ANR

1、背景

项目中有一项需求是能扫描U盘里的图片，图片存在于文件夹里；要求文件夹最多有65536个，文件夹层级最多8级。在执行用例测试的时候出现了ANR。

2、Android下的ANR

根据ActivityManagerService里的代码，Android下的ANR有如下几种：

名称\类型	前台	后台
input	5s
ContentProvider	10s
Broadcast	10s	60s
Service	20s	200s

3、ANR日志中的关键字

一般来说，发生ANR都是由于UI主线程发生了上述定义的几种情况才会抛出ANR。所以，分析日志的时候只需要分析主线程即main线程的日志。Java线程即c++线程对应关系如下：

java线程状态	cpp线程状态	说明
TERMINATED	ZOMBIE	线程死亡，终止运行
RUNNABLE	RUNNING/RUNNABLE	线程可运行或正在运行
TIMED WAITING	TIMED WAIT	执行了带有超时参数的wait、sleep或join函数
BLOCKED	MONITOR	线程阻塞，等待获取对象锁
WAITING	WAIT	执行了无超时参数的wait函数
NEW	INITIALIZING	新建，正在初始化，为其分配资源
NEW	STARTING	新建，正在启动
RUNNABLE	NATIVE	正在执行JNI本地函数
WAITING	VMWAIT	正在等待VM资源
RUNNABLE	SUSPENDED	线程暂停，通常是由于GC或debug被暂停
	UNKNOWN	未知状态

4、日志分析

出现问题时间的日志

03-27 19:58:29.720 484 574 I WindowManager: Input event dispatching timed out sending to packagename/packagename.PhotoListActivity. Reason: Waiting to send non-key event because the touched window has not finished processing certain input events that were delivered to it over 500.0ms ago. Wait queue length: 2. Wait queue head age: 6033.0ms.

日志已经很清楚地说明对点击事件的响应超过了5s，抛出了ANR。这个时候，系统开始dump此时此刻各进程的情况，大约过了30秒dump出以下信息：

03-27 19:58:46.992 484 574 I chatty : uid=1000(system) InputDispatcher expire 18 lines
03-27 19:58:47.001 484 574 I ActivityManager: Done dumping
03-27 19:58:47.024 484 574 E ActivityManager: ANR in packagename (packagename/.media_photo.view.PhotoListActivity)
03-27 19:58:47.024 484 574 E ActivityManager: PID: 20375
03-27 19:58:47.024 484 574 E ActivityManager: Reason: Input dispatching timed out (Waiting to send non-key event because the touched window has not finished processing certain input events that were delivered to it over 500.0ms ago. Wait queue length: 2. Wait queue head age: 6033.0ms.)
03-27 19:58:47.024 484 574 E ActivityManager: Parent: packagenmae/.media_photo.view.PhotoListActivity
03-27 19:58:47.024 484 574 E ActivityManager: Load: 7.25 / 6.45 / 6.11
03-27 19:58:47.024 484 574 E ActivityManager: CPU usage from 0ms to 17169ms later (2023-03-27 19:58:29.831 to 2023-03-27 19:58:47.001):
03-27 19:58:47.024 484 574 E ActivityManager: 95% 484/system_server: 31% user + 64% kernel / faults: 21172 minor
03-27 19:58:47.024 484 574 E ActivityManager: 90% 20375/packagename: 87% user + 3.2% kernel / faults: 21420 minor
03-27 19:58:47.024 484 574 E ActivityManager: 22% 1615/com.tencent.supercar:speechserver: 19% user + 3.7% kernel / faults: 27547 minor……

到这里，就可以确定无疑，发生了ANR。需要对照ANR日志进一步分析，查看20375进程对应dump出的日志：

----- pid 20375 at 2023-03-27 19:58:30 -----
Cmd line: packagename
Build fingerprint: ‘SZ-IGENTAI-FX12’
ABI: ‘arm’
Build type: optimized
Zygote loaded classes=9110 post zygote classes=2404
Dumping registered class loaders
……

//以下是截取的部分对应时间点线程dump信息
“main” prio=5 tid=1 Native
| group=“main” sCount=1 dsCount=0 flags=1 obj=0x725003d8 self=0xf0e5ce00
| sysTid=20375 nice=-10 cgrp=default sched=0/0 handle=0xf13c0dc0
| state=R schedstat=( 96440151896 8274881069 65858 ) utm=9314 stm=329 core=1 HZ=100
| stack=0xff6db000-0xff6dd000 stackSize=8192KB
| held mutexes=
kernel: (couldn’t read /proc/self/task/20375/stack)
native: #00 pc 00033e78 /system/lib/libsqlite.so (sqlite3VdbeSorterReset+788)
native: #01 pc 0003371d /system/lib/libsqlite.so (sqlite3VdbeFreeCursor+44)
native: #02 pc 00032185 /system/lib/libsqlite.so (sqlite3VdbeHalt+104)
native: #03 pc 00016d1f /system/lib/libsqlite.so (sqlite3VdbeReset+6)
native: #04 pc 00016c9b /system/lib/libsqlite.so (sqlite3_reset+42)
native: #05 pc 000aaf91 /system/lib/libandroid_runtime.so (android::nativeExecuteForCursorWindow(_JNIEnv*, _jclass*, long long, long long, long long, int, int, unsigned char)+432)
at android.database.sqlite.SQLiteConnection.nativeExecuteForCursorWindow(Native method)
at android.database.sqlite.SQLiteConnection.executeForCursorWindow(SQLiteConnection.java:942)
at android.database.sqlite.SQLiteSession.executeForCursorWindow(SQLiteSession.java:838)
at android.database.sqlite.SQLiteQuery.fillWindow(SQLiteQuery.java:62)
at android.database.sqlite.SQLiteCursor.fillWindow(SQLiteCursor.java:161)
at android.database.sqlite.SQLiteCursor.onMove(SQLiteCursor.java:131)
at android.database.AbstractCursor.moveToPosition(AbstractCursor.java:249)
at android.database.AbstractCursor.moveToNext(AbstractCursor.java:281)
at packagename.media_usb.model.MediaStorageDataModel.queryAllPhotosFolder(MediaStorageDataModel.java:342)
at packagename.media_photo.presenter.PhotoListPresenter.getFolderList(PhotoListPresenter.java:421)
at packagename.media_photo.presenter.PhotoListPresenter.getFirstFolderList(PhotoListPresenter.java:397)
at packagename.media_photo.presenter.PhotoListPresenter.reqSwitchToFolderList(PhotoListPresenter.java:301)
at packagename.media_photo.view.PhotoListFragment.showPhotoList(PhotoListFragment.java:619)
at packagename.media_photo.view.PhotoListFragment.onClick(PhotoListFragment.java:654)
at android.view.View.performClick(View.java:7142)
at android.view.View.performClickInternal(View.java:7119)
at android.view.View.access$3500(View.java:803)atandroid.view.View$PerformClick.run(View.java:27357)
at android.os.Handler.handleCallback(Handler.java:883)
at android.os.Handler.dispatchMessage(Handler.java:100)
at android.os.Looper.loop(Looper.java:214)
at android.app.ActivityThread.main(ActivityThread.java:7356)
at java.lang.reflect.Method.invoke(Native method)
at com.android.internal.os.RuntimeInitKaTeX parse error: Expected 'EOF', got '#' at position 533: …ack) native: #̲00 pc 0005a7b0 …HeapTaskDaemon.runInternal(Daemons.java:523)
at java.lang.Daemons$Daemon.run(Daemons.java:137)
at java.lang.Thread.run(Thread.java:919)

“ReferenceQueueDaemon” daemon prio=5 tid=9 Waiting
| group=“system” sCount=1 dsCount=0 flags=1 obj=0x147403c8 self=0xe5d7ca00
| sysTid=20394 nice=4 cgrp=default sched=0/0 handle=0xc6f0a230
| state=S schedstat=( 3577209 2217792 17 ) utm=0 stm=0 core=2 HZ=100
| stack=0xc6e07000-0xc6e09000 stackSize=1040KB
| held mutexes=
……

“FinalizerDaemon” daemon prio=5 tid=10 Waiting
| group=“system” sCount=1 dsCount=0 flags=1 obj=0x14740440 self=0xe5d7e600
| sysTid=20395 nice=4 cgrp=default sched=0/0 handle=0xc6e01230
| state=S schedstat=( 3561458 482543 17 ) utm=0 stm=0 core=2 HZ=100
| stack=0xc6cfe000-0xc6d00000 stackSize=1040KB
| held mutexes=
at java.lang.Object.wait(Native method)
……

ReferenceQueueDaemon、FinalizerDaemon这两个进程都是系统被创建之后用于GC的线程，这两个线程处于等待状态；同时UI主线程在进行上万个的cursor查询操作，界面又通过glide加载了上万张图片。结合内存数据推测这个时候系统应该处于内存待回收而UI主线程执行了长耗时操作的状态。加载上万张图片暂不考虑优化的话，只能想办法减少UI主线程执行耗时时间。

5、解决方案

通过日志分析，已经知道定位了问题，只需要把数据库查询操作放到线程里，通过回调刷新界面即可。这里就不贴代码了。
解决ANR最重要的办法是要拿到ANR日志，按图索骥地修改。