Skip to content
New issue

Have a question about this project? # for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “#”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? # to your account

SQLiteDatabaseLockedException при выходе из экрана "Добавить рекомендованные" в процессе добавления #36

Closed
sadr0b0t opened this issue Oct 30, 2020 · 11 comments
Labels
bug Something isn't working

Comments

@sadr0b0t
Copy link
Owner

Начал добавлять рекомендованные, не дожидаясь окончания, нажал назад. Поймал пару раз..

android.database.sqlite.SQLiteDatabaseLockedException: database is locked (code 5)
	at android.database.sqlite.SQLiteConnection.nativeExecute(Native Method)
	at android.database.sqlite.SQLiteConnection.execute(SQLiteConnection.java:555)
	at android.database.sqlite.SQLiteSession.beginTransactionUnchecked(SQLiteSession.java:323)
	at android.database.sqlite.SQLiteSession.beginTransaction(SQLiteSession.java:298)
	at android.database.sqlite.SQLiteDatabase.beginTransaction(SQLiteDatabase.java:507)
	at android.database.sqlite.SQLiteDatabase.beginTransaction(SQLiteDatabase.java:418)
	at androidx.sqlite.db.framework.FrameworkSQLiteDatabase.beginTransaction(FrameworkSQLiteDatabase.java:69)
	at androidx.room.RoomDatabase.beginTransaction(RoomDatabase.java:330)
	at androidx.room.paging.LimitOffsetDataSource.loadInitial(LimitOffsetDataSource.java:117)
	at androidx.paging.PositionalDataSource.dispatchLoadInitial(PositionalDataSource.java:286)
	at androidx.paging.TiledPagedList.<init>(TiledPagedList.java:107)
	at androidx.paging.PagedList.create(PagedList.java:229)
	at androidx.paging.PagedList$Builder.build(PagedList.java:388)
	at androidx.paging.LivePagedListBuilder$1.compute(LivePagedListBuilder.java:206)
	at androidx.paging.LivePagedListBuilder$1.compute(LivePagedListBuilder.java:171)
	at androidx.lifecycle.ComputableLiveData$2.run(ComputableLiveData.java:101)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1162)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:636)
	at java.lang.Thread.run(Thread.java:764)
@sadr0b0t sadr0b0t added the bug Something isn't working label Oct 30, 2020
@sadr0b0t
Copy link
Owner Author

sadr0b0t commented Oct 30, 2020

Еще один эксепшен, возможно, по этой же теме. Начал добавлять на эмуляторе плейлист первого канала, закрыл экран дозавершения, через некоторое время вылетел на главном экране (через довольно продолжительно время, поэтому, возможно, дело не в фоновом добавлении, а в чем-то другом).

java.lang.IllegalStateException: Cannot perform this operation because the connection pool has been closed.
        at android.database.sqlite.SQLiteConnectionPool.throwIfClosedLocked(SQLiteConnectionPool.java:1069)
        at android.database.sqlite.SQLiteConnectionPool.waitForConnection(SQLiteConnectionPool.java:683)
        at android.database.sqlite.SQLiteConnectionPool.acquireConnection(SQLiteConnectionPool.java:378)
        at android.database.sqlite.SQLiteSession.acquireConnection(SQLiteSession.java:894)
        at android.database.sqlite.SQLiteSession.executeForChangedRowCount(SQLiteSession.java:752)
        at android.database.sqlite.SQLiteStatement.executeUpdateDelete(SQLiteStatement.java:64)
        at androidx.sqlite.db.framework.FrameworkSQLiteStatement.executeUpdateDelete(FrameworkSQLiteStatement.java:46)
        at su.sadrobot.yashlang.model.VideoItemDao_Impl.countView(VideoItemDao_Impl.java:283)
        at su.sadrobot.yashlang.WatchVideoActivity$31.run(WatchVideoActivity.java:1270)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
        at java.lang.Thread.run(Thread.java:764)

updt: тут же явно видно, что это WatchVideoActivity, в текущей версии это вот эта строка:

private void playVideoItem(final VideoItem videoItem, final boolean resetCurrPos) {
[...]
            // теперь то, что в фоне
            videoLoadingExecutor.execute(new Runnable() {
                @Override
                public void run() {
                    // посчитать просмотр (для ролика, загруженного из базы)
                    if (videoItem.getId() != -1) {
                        videodb.videoItemDao().countView(videoItem.getId());
                    }

                    loadVideoItem(videoItem);
                }
            });
[...]
}
videodb.videoItemDao().countView(videoItem.getId());

это пойдет в отдельный тикет: #38

@sadr0b0t sadr0b0t changed the title NullPointer при выходе из экрана "Добавить рекомендованные" в процессе добавления SQLiteDatabaseLockedException при выходе из экрана "Добавить рекомендованные" в процессе добавления Oct 30, 2020
@sadr0b0t
Copy link
Owner Author

sadr0b0t commented Nov 6, 2020

Пока добавлю сюда, а там видно будет. Cейчас при добавлении панели обновления всех плейлистов на эмуляторе могу поймать ошибку "SQLite busy" (не с вылетом приложения, а на самом экране) - это если в процессе добавления нажму вырубить инет, а потом, дождавшись экран ошибки по таймату, нажму "Продолжить". Ошибка приходит из СontentLoader.addPlaylistNewItems и ловится внутри. Возможно, сдесь дело тоже в том, как создается и как освобождается объект подключения к б/д. В рамках этого тикета можно попробовать замутить глобальный рефактор на эту тему во всех местах, где идут фоновые обращения к б/д.

@sadr0b0t
Copy link
Owner Author

еще раз поймал в эмуляторе (поставил добавляться рекомендованные, вышел из экрана, ждал до эксепшена довольно долго):

E/ROOM: Cannot run invalidation tracker. Is the db closed?
    android.database.sqlite.SQLiteDatabaseLockedException: database is locked (code 5 SQLITE_BUSY)
        at android.database.sqlite.SQLiteConnection.nativeExecute(Native Method)
        at android.database.sqlite.SQLiteConnection.execute(SQLiteConnection.java:569)
        at android.database.sqlite.SQLiteSession.beginTransactionUnchecked(SQLiteSession.java:323)
        at android.database.sqlite.SQLiteSession.beginTransaction(SQLiteSession.java:298)
        at android.database.sqlite.SQLiteDatabase.beginTransaction(SQLiteDatabase.java:549)
        at android.database.sqlite.SQLiteDatabase.beginTransaction(SQLiteDatabase.java:460)
        at androidx.sqlite.db.framework.FrameworkSQLiteDatabase.beginTransaction(FrameworkSQLiteDatabase.java:69)
        at androidx.room.InvalidationTracker.syncTriggers(InvalidationTracker.java:500)
        at androidx.room.InvalidationTracker.internalInit(InvalidationTracker.java:181)
        at androidx.room.RoomDatabase.internalInitInvalidationTracker(RoomDatabase.java:428)
        at su.sadrobot.yashlang.model.VideoDatabase_Impl.access$400(VideoDatabase_Impl.java:26)
        at su.sadrobot.yashlang.model.VideoDatabase_Impl$1.onOpen(VideoDatabase_Impl.java:62)
        at androidx.room.RoomOpenHelper.onOpen(RoomOpenHelper.java:120)
        at androidx.sqlite.db.framework.FrameworkSQLiteOpenHelper$OpenHelper.onOpen(FrameworkSQLiteOpenHelper.java:142)
        at android.database.sqlite.SQLiteOpenHelper.getDatabaseLocked(SQLiteOpenHelper.java:409)
        at android.database.sqlite.SQLiteOpenHelper.getWritableDatabase(SQLiteOpenHelper.java:298)
        at androidx.sqlite.db.framework.FrameworkSQLiteOpenHelper$OpenHelper.getWritableSupportDatabase(FrameworkSQLiteOpenHelper.java:92)
        at androidx.sqlite.db.framework.FrameworkSQLiteOpenHelper.getWritableDatabase(FrameworkSQLiteOpenHelper.java:53)
        at androidx.room.RoomDatabase.beginTransaction(RoomDatabase.java:328)
        at androidx.room.paging.LimitOffsetDataSource.loadInitial(LimitOffsetDataSource.java:117)
        at androidx.paging.PositionalDataSource.dispatchLoadInitial(PositionalDataSource.java:286)
        at androidx.paging.TiledPagedList.<init>(TiledPagedList.java:107)
        at androidx.paging.PagedList.create(PagedList.java:229)
        at androidx.paging.PagedList$Builder.build(PagedList.java:388)
        at androidx.paging.LivePagedListBuilder$1.compute(LivePagedListBuilder.java:206)
        at androidx.paging.LivePagedListBuilder$1.compute(LivePagedListBuilder.java:171)
        at androidx.lifecycle.ComputableLiveData$2.run(ComputableLiveData.java:101)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
        at java.lang.Thread.run(Thread.java:764)
E/AndroidRuntime: FATAL EXCEPTION: arch_disk_io_1
    Process: su.sadrobot.yashlang, PID: 13896
    android.database.sqlite.SQLiteDatabaseLockedException: database is locked (code 5 SQLITE_BUSY)
        at android.database.sqlite.SQLiteConnection.nativeExecute(Native Method)
        at android.database.sqlite.SQLiteConnection.execute(SQLiteConnection.java:569)
        at android.database.sqlite.SQLiteSession.beginTransactionUnchecked(SQLiteSession.java:323)
        at android.database.sqlite.SQLiteSession.beginTransaction(SQLiteSession.java:298)
        at android.database.sqlite.SQLiteDatabase.beginTransaction(SQLiteDatabase.java:549)
        at android.database.sqlite.SQLiteDatabase.beginTransaction(SQLiteDatabase.java:460)
        at androidx.sqlite.db.framework.FrameworkSQLiteDatabase.beginTransaction(FrameworkSQLiteDatabase.java:69)
        at androidx.room.RoomDatabase.beginTransaction(RoomDatabase.java:330)
        at androidx.room.paging.LimitOffsetDataSource.loadInitial(LimitOffsetDataSource.java:117)
        at androidx.paging.PositionalDataSource.dispatchLoadInitial(PositionalDataSource.java:286)
        at androidx.paging.TiledPagedList.<init>(TiledPagedList.java:107)
        at androidx.paging.PagedList.create(PagedList.java:229)
        at androidx.paging.PagedList$Builder.build(PagedList.java:388)
        at androidx.paging.LivePagedListBuilder$1.compute(LivePagedListBuilder.java:206)
        at androidx.paging.LivePagedListBuilder$1.compute(LivePagedListBuilder.java:171)
        at androidx.lifecycle.ComputableLiveData$2.run(ComputableLiveData.java:101)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
        at java.lang.Thread.run(Thread.java:764)
I/Process: Sending signal. PID: 13896 SIG: 9
Process 13896 terminated.

@sadr0b0t
Copy link
Owner Author

вот этот коммит не помог: d50f194

коммит по мотивам исправленного #38

нужно смотреть ContentLoader

@sadr0b0t
Copy link
Owner Author

или, к пример, завершать длинный цикл добавления сразу после onDestroy (нужно проверить, что вызывается раньше - onDestroy или завершается фоновый поток)

@sadr0b0t
Copy link
Owner Author

еще похожий тикет, но ситуация другая: #33

@sadr0b0t
Copy link
Owner Author

История такая:

  • При закрытии активити вызывается метод onDestroy, при этом незавершившиеся фоновые потоки еще продолжают работать

  • Они могут работать довольно долго - можно гулять по экранам приложения, можно выйти на рабочий стол и заново запустить приложение, можно вернуться (заново открыть) опять на экран добавления рекомендованных плейлистов и запустить еще один процесс добавления параллельно уже работающему

  • Единственный способ остановить поток раньше времени - завершить работу приложения, "свайпнув" его в списке задач - в таком случае он, действительно, прервется

  • При этом контекст активити, при помощи которого создается подключение к базе данных, остаётся актуальным даже после закрытия активити и вызова onDestroy - подключения создаются после закрытия экрана активити и в базу добавляются данные

  • Проблема, вызывающая эксепшен - обращение к базе из других частей приложения в тот момент, когда в фоновом потоке происходит запись в базу, т.е. не завершена начатая транзакция.

  • Например, можно запустить процесс добавления рекомендованных плейлистов в фоне так, чтобы какие-то плейлисты точно были не добавлены.

  • После этого выйти на главный экран и начать открывать разные видео или переключаться между ними в экране плеера.

  • В таком случае скорее всего получится поймать такой момент, когда в фоновом потоке из давно закрытого экрана начнется процесс реально записи плейлиста в базу внутри транзакции, а с экрана плеера будет инициирована другая процедура записи в базу (например, запись текущей позиции ролика или обновление даты просмотра)

  • В этом момент происходит эксепшен SQLiteDatabaseLockedException - его причиной может быть любая запись, поэтому, теоретически, конкретный вид эксепшена может быть часто разный.

вот, например:

2020-11-21 14:17:04.038 17121-17243/su.sadrobot.yashlang E/AndroidRuntime: FATAL EXCEPTION: pool-8-thread-1
    Process: su.sadrobot.yashlang, PID: 17121
    android.database.sqlite.SQLiteDatabaseLockedException: database is locked (code 5 SQLITE_BUSY)
        at android.database.sqlite.SQLiteConnection.nativeExecute(Native Method)
        at android.database.sqlite.SQLiteConnection.execute(SQLiteConnection.java:569)
        at android.database.sqlite.SQLiteSession.beginTransactionUnchecked(SQLiteSession.java:323)
        at android.database.sqlite.SQLiteSession.beginTransaction(SQLiteSession.java:298)
        at android.database.sqlite.SQLiteDatabase.beginTransaction(SQLiteDatabase.java:549)
        at android.database.sqlite.SQLiteDatabase.beginTransaction(SQLiteDatabase.java:460)
        at androidx.sqlite.db.framework.FrameworkSQLiteDatabase.beginTransaction(FrameworkSQLiteDatabase.java:69)
        at androidx.room.RoomDatabase.beginTransaction(RoomDatabase.java:330)
        at su.sadrobot.yashlang.model.VideoItemDao_Impl.countView(VideoItemDao_Impl.java:279)
        at su.sadrobot.yashlang.WatchVideoActivity$31.run(WatchVideoActivity.java:1390)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
        at java.lang.Thread.run(Thread.java:764)
2020-11-21 14:17:04.089 17121-17243/su.sadrobot.yashlang I/Process: Sending signal. PID: 17121 SIG: 9

здесь причина эксепшена - вызов WatchVideoActivity

videodb.videoItemDao().countView(videoItem.getId());

который, как видно, ведет в сгенерированный румовский файл:

    __db.beginTransaction();

Предварительный выход - прибивать фоновый поток как можно раньше после выхода из активного экрана. Например, проверять, открыт ли текущий экран перед добавлением каждого нового плейлиста. Однако, это минимизирует ошибку, но не даст гарантии того, что она не произойдет вообще - например, если выйти из экрана добавления в момент добавление большого плейлиста - в таком случае будет достаточно времени переключиться на экран с плеером.

Еще большая минимизация проблемы - прирывать транзакцию внутри ContentLoader при сигнале закрытия экрана. Как минимум, можно перестать выкачивать новые страницы.

@sadr0b0t
Copy link
Owner Author

Однако, это минимизирует ошибку, но не даст гарантии того, что она не произойдет вообще - например, если выйти из экрана добавления в момент добавление большого плейлиста - в таком случае будет достаточно времени переключиться на экран с плеером.

гарантированный способ получить эксепшен - дождаться начала добавление большого плейлиста (например, Гостелерадио), выйти из экрана добавления рекомендованных и пойти в плеер.

@sadr0b0t
Copy link
Owner Author

Аналогичные проблемы будут на экранах:

  • Добавить рекомендованные
  • Добавить плейлист
  • Добавить новые элементы в плейлист
  • Добавить новые элементы во все плейлисты

@sadr0b0t
Copy link
Owner Author

А при выходе из добавления ноывых элементов для всех плейлистов вот такой эксепшен:

2020-11-22 02:08:16.135 21769-21980/su.sadrobot.yashlang E/AndroidRuntime: FATAL EXCEPTION: Thread-12
    Process: su.sadrobot.yashlang, PID: 21769
    java.lang.IllegalArgumentException: Cannot provide null context for the database.
        at androidx.room.RoomDatabase$Builder.build(RoomDatabase.java:804)
        at su.sadrobot.yashlang.model.VideoDatabase.getDb(VideoDatabase.java:43)
        at su.sadrobot.yashlang.controller.ContentLoader.addPlaylistNewItems(ContentLoader.java:483)
        at su.sadrobot.yashlang.ConfigurePlaylistsNewItemsFragment$13.run(ConfigurePlaylistsNewItemsFragment.java:598)
        at java.lang.Thread.run(Thread.java:764)

на:

                    int addedCount = ContentLoader.getInstance().addPlaylistNewItems(
                        ConfigurePlaylistsNewItemsFragment.this.getContext(),
                            plInfo.getId(), plInfo.getUrl(), taskController);
        final VideoDatabase videodb = VideoDatabase.getDb(context);

похоже, что здесь как раз битый контекст из фрагмента после onDestroy

@sadr0b0t
Copy link
Owner Author

876f0da

  • использовать флаг taskController.isCanceled при добавлении нового плейлиста или добавления в существующий плейлист новых элементов.
  • отменять задачу taskControlled.cancel) при закрытии активити в onDestroy

Прерывание фоновой задачи проверкой флага происходит в нескольких местах - в начале каждого цикла (там, где есть последовательность плейлистов) до и после длительных сетевых операций по выкачиванию контента внутри транзакции добавления/обновления плейлиста.

Патч не устраняет возможность эксепшена полностью: есть вероятность успеть закрыть экран добавления в момент этой самой операции (между двумя проверками taskControlller.isCanceled*() и обратиться к базе (например, с главного экрана). Но довольно хорошо минимизирует вероятность возникновения такой ситаци.

Полностью исключить такую возможность довольно проблематично. С учетом того, что фоновая операция остается жить уже после того, как пользователь закрыл активити, на которой она была вызвана, и перешел на другую активити, если операция - относительно длительная транзакция, получается что вообще любая операция обращения к б/д в любой активи потенциально может закончиться ошибкой "db is locked".

Чтобы решать проблему строго, нужно или обертывать дополнительно вообще любые обращения к бд в try/catch (и быть готовым к тому, что она может закончиться неудачно) или как-то дожидаться завершения фоновых потоков из другой активити (при этом блокировать интерфейс и не обращаться вообще к базе?) стейт-машина, учитывающая состояния из другой закрытой активити - пипец). Или выстраивать какую-то межэкранную очередь запросов к б/д (тоже пипец, плюс непредсказуемое время выполнения некоторых запросов).

В общем, пока ничего такого делать не хочется, с этим патчем основных вылетов больше нет, поймать другие довольно сложно - будут пойманы, будет реопен или новый тикет.

# for free to join this conversation on GitHub. Already have an account? # to comment
Labels
bug Something isn't working
Projects
None yet
Development

No branches or pull requests

1 participant