[未解决]The connection pool for database has been unable to grant a connection to thread 1304

最新推荐文章于 2024-08-21 14:45:47 发布

原创最新推荐文章于 2024-08-21 14:45:47 发布 · 5.6k 阅读

3 ·

CC 4.0 BY-SA版权

开发中遇到的问题解决同时被 3 个专栏收录

156 篇文章

订阅专栏

TroubleShooting

149 篇文章

订阅专栏

1 Java面向对象高级编程

26 篇文章

订阅专栏

当数据库操作时间过长，如一个查询操作耗时20毫秒，可能导致连接池无法为线程分配连接，从而引发错误。通过Android Device Monitor定位到主线程的findCashierAdRecodesFromDB方法，发现是数据库查询导致的问题。解决方案是利用CountDownLatch对事务操作进行同步，若超时则直接退出，避免影响其他数据库操作。

11-11 09:49:44.783 481-496/system_process E/ActivityManager: ANR in com.wbm.app.activity (com.wbm.app.activity/.MainActivity)
PID: 12114
Reason: Input dispatching timed out (Waiting because the focused window has not finished processing the input events that were previously delivered to it.)
Load: 0.21 / 0.25 / 0.25
CPU usage from 11106ms to 0ms ago:
7.2% 549/com.android.systemui: 5.6% user + 1.5% kernel / faults: 217 minor
4.6% 170/surfaceflinger: 1.8% user + 2.8% kernel
1.6% 481/system_server: 0.9% user + 0.7% kernel / faults: 116 minor
1.2% 19332/kworker/2:2: 0% user + 1.2% kernel
1% 84/fb-vsync: 0% user + 1% kernel
0.7% 18843/kworker/0:1: 0% user + 0.7% kernel
0.6% 82/fb-vsync: 0% user + 0.6% kernel
0.5% 34/kconsole: 0% user + 0.5% kernel
0% 142/file-storage: 0% user + 0% kernel
0.3% 8/rcu_preempt: 0% user + 0.3% kernel
0.2% 86/cfinteractive: 0% user + 0.2% kernel
0.2% 854/com.youzan.cashier: 0% user + 0.1% kernel / faults: 1 minor
0.2% 19307/kworker/u8:1: 0% user + 0.2% kernel
0.1% 135/kworker/0:1H: 0% user + 0.1% kernel
0.1% 139/dhd_dpc: 0% user + 0.1% kernel
0.1% 177/lcdparamservice: 0% user + 0.1% kernel
0.1% 1391/com.qima.kdt:pushservice: 0% user + 0% kernel / faults: 11 minor
0.1% 1666/com.happy.activity: 0% user + 0% kernel
0% 1//init: 0% user + 0% kernel / faults: 14 minor
0% 83/rk-fb: 0% user + 0% kernel
0% 85/rk-fb: 0% user + 0% kernel
0% 138/dhd_watchdog_th: 0% user + 0% kernel
0% 167/netd: 0% user + 0% kernel / faults: 5 minor
0% 980/com.youzan.cashier:pushservice: 0% user + 0% kernel
0% 1693/com.happy.activity:remote: 0% user + 0% kernel
0% 8943/com.qima.kdt: 0% user + 0% kernel
0% 9005/com.sohu.inputmethod.sogou:classic: 0% user + 0% kernel
0% 12114/com.wbm.app.activity: 0% user + 0% kernel
0% 12133/kworker/1:1: 0% user + 0% kernel
0% 14653/android.process.media: 0% user + 0% kernel / faults: 6 minor
0% 18081/kworker/u9:1: 0% user + 0% kernel
0% 20463/wpa_supplicant: 0% user + 0% kernel
4.2% TOTAL: 2.2% user + 1.9% kernel + 0% iowait
CPU usage from 3107ms to 3617ms later:
3.7% 481/system_server: 0% user + 3.7% kernel / faults: 1 minor
5.6% 496/ActivityManager: 0% user + 5.6% kernel
1.3% 8/rcu_preempt: 0% user + 1.3% kernel
1.4% 170/surfaceflinger: 0% user + 1.4% kernel
0.5% TOTAL: 0% user + 0.5% kernel
11-11 09:49:44.823 481-496/system_process D/InputEventConsistencyVerifier: KeyEvent: ACTION_UP but key was not down.
in android.view.ViewRootImpl@426d3780
0: sent at 778352501000000, KeyEvent { action=ACTION_UP, keyCode=KEYCODE_NOTIFICATION, scanCode=143, metaState=0, flags=0x8, repeatCount=0, eventTime=778352501, downTime=778352500, deviceId=0, source=0x101 }
11-11 09:49:58.853 12114-12392/com.wbm.app.activity W/SQLiteConnectionPool: The connection pool for database '/data/data/com.wbm.app.activity/databases/cashierDB.db' has been unable to grant a connection to thread 1304 (pool-5-thread-3) with flags 0x1 for 13740.74 seconds.//大概4小时
Connections: 0 active, 1 idle, 0 available.
11-11 09:50:28.853 12114-12392/com.wbm.app.activity W/SQLiteConnectionPool: The connection pool for database '/data/data/com.wbm.app.activity/databases/cashierDB.db' has been unable to grant a connection to thread 1304 (pool-5-thread-3) with flags 0x1 for 13770.741 seconds.
Connections: 0 active, 1 idle, 0 available.
11-11 09:50:58.863 12114-12392/com.wbm.app.activity W/SQLiteConnectionPool: The connection pool for database '/data/data/com.wbm.app.activity/databases/cashierDB.db' has been unable to grant a connection to thread 1304 (pool-5-thread-3) with flags 0x1 for 13800.744 seconds.
Connections: 0 active, 1 idle, 0 available.
11-11 09:51:28.863 12114-12392/com.wbm.app.activity W/SQLiteConnectionPool: The connection pool for database '/data/data/com.wbm.app.activity/databases/cashierDB.db' has been unable to grant a connection to thread 1304 (pool-5-thread-3) with flags 0x1 for 13830.745 seconds.
Connections: 0 active, 1 idle, 0 available.
11-11 09:51:58.863 12114-12392/com.wbm.app.activity W/SQLiteConnectionPool: The connection pool for database '/data/data/com.wbm.app.activity/databases/cashierDB.db' has been unable to grant a connection to thread 1304 (pool-5-thread-3) with flags 0x1 for 13860.747 seconds.

Connections: 0 active, 1 idle, 0 available

出现原因：

这个主要是我们在使用事务里面进行的数据库操作的时候，如果操作的时间比较长，例如我这里的有一个查询一个表里面所有的数组的时候耗时20毫秒，正好其他的地方如果也进行数据库操作，那么就会报这样的错误。

例如这里是模拟测试的：

 Log.e("kodulf","start");
                        ThreadPoolUtils.execute(new Runnable() {
                            @Override
                            public void run() {
                                ServiceContext.getCarriageTransactionTemplate().execute(new CarriageTransactionAction() {
                                   @Override
                                   public void doInTransaction(CarriageTransactionStatus status) throws Exception {
                                       Log.e("kodulf","start transaction findall");
                                       List<CashierAd> cashierAdList = DataSupport.findAll(CashierAd.class);
                                       Log.e("kodulf","end transaction findall");
                                 
                                   }
                               });
                            }
                        });

                        Log.e("kodulf","start normal findall");
                        List<CashierAd> cashierAdList = DataSupport.findAll(CashierAd.class);
                        Log.e("kodulf","end normal findall");

解决办法：

使用同步助手CountDownLatch把事务的操作抱起来，如果它执行1秒钟那么就直接跳出，

final CountDownLatch latch = new CountDownLatch(1);
                        ThreadPoolUtils.execute(new Runnable() {
                            @Override
                            public void run() {
                                ServiceContext.getCarriageTransactionTemplate().execute(new CarriageTransactionAction() {
                                   @Override
                                   public void doInTransaction(CarriageTransactionStatus status) throws Exception {
                                       Log.e("kodulf","start transaction findall");
                                       List<CashierAd> cashierAdList = DataSupport.findAll(CashierAd.class);
                                       Log.e("kodulf","end transaction findall");
                                       latch.countDown();
                                   }
                               });
                            }
                        });

                        try {
                            latch.await(1000, TimeUnit.MILLISECONDS);//3分钟超时
                        } catch (InterruptedException e) {

                        }

                        Log.e("kodulf","start normal findall");
                        List<CashierAd> cashierAdList = DataSupport.findAll(CashierAd.class);
                        Log.e("kodulf","end normal findall");

+++++++++++++++++++++++++++++++++++++Debug的过程+++++++++++++++++++++++++++++++++++++++++

0：首先通过Android Device Monitor

Tools->Android->Anroid Device Monitory

1：选中我们的应用，然后点击Update Thread 的按钮，然后点击右边的Threads，查看我们的应用的各种线程

2：然后我们可以通过点击某一个线程来查看该线程的详细的信息，例如

3：我这里的线程的列表：

ID	Tid		Status	utime	stime	Name

1	12114	Monitor	210640	17633	main	
*2	12118	VmWait	3257	92	GC	
*3	12119	VmWait	11	7	Signal Catcher	
*4	12120	Runnable	60	104	JDWP	
*5	12121	VmWait	634	484	Compiler	
*6	12122	Wait	102	12	ReferenceQueueDaemon	
*7	12123	Wait	557	74	FinalizerDaemon	
*8	12124	Wait	2	4	FinalizerWatchdogDaemon	
9	12125	Native	468	453	Binder_1	
10	12126	Native	414	511	Binder_2	
11	12134	Native	5	1	TbsHandlerThread	
12	12142	Wait	0	0	pool-1-thread-1	
13	12139	Native	585	559	WifiManager	
14	12143	Wait	0	0	pool-1-thread-2	
15	18492	Monitor	4	0	OkHttp http://tp.api.500mi.com:8080/gateway/api	
16	17675	Monitor	2450	814	pool-5-thread-8	
17	12150	Wait	0	0	pool-2-thread-1	
18	16523	Monitor	6030	2166	pool-5-thread-5	
19	12153	Wait	0	0	AsyncTask #1	
20	12154	Wait	0	0	AsyncTask #2	
21	12228	Wait	0	0	AsyncTask #3	
*22	12236	Wait	45	36	Okio Watchdog	
23	12240	Wait	0	0	AsyncTask #4	
24	12244	Wait	0	0	AsyncTask #5	
25	12375	Wait	0	0	pool-4-thread-1	
26	12377	Monitor	18896	5931	pool-5-thread-1	
27	12378	Monitor	18685	6034	pool-5-thread-2	
28	12379	Monitor	30	2	Thread-1292	
29	12380	Monitor	943	104	Thread-1293	
30	12381	Monitor	598	181	Thread-1294	
31	12382	Monitor	1097	375	Thread-1295	
32	12384	Monitor	1053	366	Thread-1296	
33	12385	Monitor	569	192	Thread-1297	
34	12386	Monitor	588	213	Thread-1298	
35	12387	Monitor	610	197	Thread-1299	
36	12388	Monitor	618	211	Thread-1300	
37	18493	Monitor	7	1	OkHttp http://tp.api.500mi.com:8080/gateway/api	
38	12390	Monitor	962	116	Thread-1302	
39	12391	Monitor	30	4	Thread-1303	
40	12392	TimedWait	18829	6016	pool-5-thread-3	
42	16708	Monitor	5472	1899	pool-5-thread-6	
43	12395	Wait	0	0	pool-3-thread-1	
44	12399	Wait	0	0	pool-1-thread-3	
45	12400	Wait	0	0	pool-1-thread-4	
46	12403	Native	1	0	hwuiTask2	
47	12402	Native	2	0	hwuiTask1	
48	12405	Monitor	18658	5983	pool-5-thread-4	
49	12407	Native	429	494	Binder_3	
50	16709	Monitor	5731	1849	pool-5-thread-7

4：然后查看到三个线程有问题：

第一是main的线程：这里面发现在findCashierAdRecodesFromDB 这个方法里面停住了，这里正是在做一个数据库的查询的操作

  at org.litepal.crud.DataSupport.where(DataSupport.java:152)	
  at com.wbm.app.business.service.CashierAdService.findCashierAdRecordsFromDB(CashierAdService.java:228)	
  at com.wbm.app.business.service.CashierAdService.sycnCashierAdRecords(CashierAdService.java:197)	
  at com.wbm.app.activity.MainActivity$1$4.run(MainActivity.java:278)	
  at java.util.concurrent.ThreadPoolExecutor$CallerRunsPolicy.rejectedExecution(ThreadPoolExecutor.java:1988)	
  at java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:793)	
  at java.util.concurrent.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:1339)	
  at com.wbm.app.utils.ThreadPoolUtils.execute(ThreadPoolUtils.java:28)	
  at com.wbm.app.activity.MainActivity$1.handleMessage(MainActivity.java:275)	
  at android.os.Handler.dispatchMessage(Handler.java:98)	
  at android.os.Looper.loop(Looper.java:136)	
  at android.app.ActivityThread.main(ActivityThread.java:5008)	
  at java.lang.reflect.Method.invokeNative(Native Method)	
  at java.lang.reflect.Method.invoke(Method.java:515)	
  at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:811)	
  at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:627)	
  at dalvik.system.NativeStart.main(Native Method)

第二是pool-5-thread-3

  at java.lang.Object.wait(Native Method)	
  at java.lang.Thread.parkFor(Thread.java:1205)	
  at sun.misc.Unsafe.park(Unsafe.java:325)	
  at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:197)	
  at android.database.sqlite.SQLiteConnectionPool.waitForConnection(SQLiteConnectionPool.java:670)	
  at android.database.sqlite.SQLiteConnectionPool.acquireConnection(SQLiteConnectionPool.java:348)	
  at android.database.sqlite.SQLiteSession.acquireConnection(SQLiteSession.java:894)	
  at android.database.sqlite.SQLiteSession.prepare(SQLiteSession.java:586)	
  at android.database.sqlite.SQLiteProgram.<init>(SQLiteProgram.java:58)	
  at android.database.sqlite.SQLiteQuery.<init>(SQLiteQuery.java:37)	
  at android.database.sqlite.SQLiteDirectCursorDriver.query(SQLiteDirectCursorDriver.java:44)	
  at android.database.sqlite.SQLiteDatabase.rawQueryWithFactory(SQLiteDatabase.java:1314)	
  at android.database.sqlite.SQLiteDatabase.queryWithFactory(SQLiteDatabase.java:1161)	
  at android.database.sqlite.SQLiteDatabase.query(SQLiteDatabase.java:1032)	
  at android.database.sqlite.SQLiteDatabase.query(SQLiteDatabase.java:1238)	
  at org.litepal.crud.DataHandler.query(DataHandler.java:124)	
  at org.litepal.crud.QueryHandler.onFindAll(QueryHandler.java:122)	
  at org.litepal.crud.DataSupport.findAll(DataSupport.java:629)	
  at org.litepal.crud.DataSupport.findAll(DataSupport.java:610)	
  at com.wbm.app.business.schedule.ErrorSchedule$1.run(ErrorSchedule.java:42)	
  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1112)	
  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:587)	
  at java.lang.Thread.run(Thread.java:841)

第三：最关键的是Tid是18493这个，这个的Tid就是最后一个执行的时候出现的id，那么我们就认为是这里除了问题导致停止运行的。而这个正是在事务里面执行的数据库操作的那一步

  at org.litepal.crud.DataSupport.where(DataSupport.java:152)	
  at com.wbm.app.business.service.CashierAdService$1$1.doInTransaction(CashierAdService.java:82)	
  at com.wbm.app.business.transaction.CarriageTransactionTemplate.execute(CarriageTransactionTemplate.java:21)	
  at com.wbm.app.business.service.CashierAdService$1.onResponse(CashierAdService.java:66)	
  at com.wbm.app.business.service.CashierAdService$1.onResponse(CashierAdService.java:41)	
  at com.wbm.app.business.net.BopHttpClient$3.onResponse(BopHttpClient.java:172)	
  at com.wbm.app.business.net.BopHttpClient$1.onResponse(BopHttpClient.java:78)	
  at okhttp3.RealCall$AsyncCall.execute(RealCall.java:133)	
  at okhttp3.internal.NamedRunnable.run(NamedRunnable.java:32)	
  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1112)	
  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:587)	
  at java.lang.Thread.run(Thread.java:841)

4：确定了问题就是doTransaction这里的这一步的问题，然后最后发现了原因

5: 但是这个CountDownLatch 是阻塞的当前的线程，如果出现多个线程的情况的话，这里暂时是将这个事务放在主线程里面去执行的：

public class CarriageTransactionTemplate {

    private Handler handler;

    public void execute(final CarriageTransactionAction action) {
        this.execute(action,true);
    }
    public void execute(final CarriageTransactionAction action,boolean runInMain) {
        if(runInMain){
            if(Looper.myLooper()!=Looper.getMainLooper()) {
                if (handler == null) {
                    handler = new Handler(Looper.getMainLooper());
                }
                //非主线程,并且子线程后续操作依赖事务处理的结果。
                final CountDownLatch latch=new CountDownLatch(1);
                handler.post(new Runnable() {
                    @Override
                    public void run() {
                        _execute(action);
                        latch.countDown();
                    }
                });
                try {
                    latch.await(1000*60, TimeUnit.MILLISECONDS);
                } catch (InterruptedException e) {
                    e.printStackTrace();
                }
            }else{
                _execute(action);
            }
        }else{
            _execute(action);
        }
    }

    private void _execute(CarriageTransactionAction action){
        SQLiteDatabase db = Connector.getDatabase();
        db.beginTransaction();
        try {
            CarriageTransactionStatus status = new CarriageTransactionStatus();
            action.doInTransaction(status);
            if(!status.isRollbackOnly()){
                db.setTransactionSuccessful();
            }
        } catch (Exception var6) {
            throw new DataSupportException(var6.getMessage());
        } finally {
            db.endTransaction();
        }
    }
}