search

osmandapp / OsmAnd

OsmAnd
https://osmand.net
Other
4.44k stars 992 forks source link

Frequent crashes when recording GPX seemingly related to open file limit #11511

Open RudyTheDev opened 3 years ago

RudyTheDev commented 3 years ago

Hello. Whenever I do something with GPX recording, reopen the app, navigate or start/stop recording, there's a chance that the app crashes. (It has crashed a few times when not working with GPX, but much rarer and I frankly only really do GPX stuff.) This used to be a couple times a session, but recently it's become non-stop. If I record but don't keep the app open, then it does run and record the track in background correctly. But reopening almost always results in a crash. I can't pinpoint any exact action that causes it, so I went to check what the actual errors are. Below are a couple messages from a fatal crash from logcat:

FATAL EXCEPTION: main
Process: net.osmand, PID: 18731
android.database.sqlite.SQLiteCantOpenDatabaseException: unknown error (code 2062): Could not open database
#################################################################
Error Code : 2062 (SQLITE_CANTOPEN_EMFILE)
Caused By : Application has opened too many files. Maximum of available file descriptors in one process is 1024 in default.
    (unknown error (code 2062): Could not open database)
#################################################################
    at android.database.sqlite.SQLiteConnection.nativeOpen(Native Method)
    at android.database.sqlite.SQLiteConnection.open(SQLiteConnection.java:262)
    at android.database.sqlite.SQLiteConnection.open(SQLiteConnection.java:205)
    at android.database.sqlite.SQLiteConnectionPool.openConnectionLocked(SQLiteConnectionPool.java:649)
    at android.database.sqlite.SQLiteConnectionPool.open(SQLiteConnectionPool.java:255)
    at android.database.sqlite.SQLiteConnectionPool.open(SQLiteConnectionPool.java:222)
    at android.database.sqlite.SQLiteDatabase.openInner(SQLiteDatabase.java:1191)
    at android.database.sqlite.SQLiteDatabase.open(SQLiteDatabase.java:1146)
    at android.database.sqlite.SQLiteDatabase.openDatabase(SQLiteDatabase.java:861)
    at android.app.ContextImpl.openOrCreateDatabase(ContextImpl.java:729)
    at android.content.ContextWrapper.openOrCreateDatabase(ContextWrapper.java:310)
    at android.database.sqlite.SQLiteOpenHelper.getDatabaseLocked(SQLiteOpenHelper.java:254)
    at android.database.sqlite.SQLiteOpenHelper.getWritableDatabase(SQLiteOpenHelper.java:194)
    at net.osmand.plus.activities.SavingTrackHelper.execWithClose(SavingTrackHelper.java:677)
    at net.osmand.plus.activities.SavingTrackHelper.insertData(SavingTrackHelper.java:487)
    at net.osmand.plus.activities.SavingTrackHelper.updateLocation(SavingTrackHelper.java:477)
    at net.osmand.plus.OsmAndLocationProvider.setLocation(OsmAndLocationProvider.java:784)
    at net.osmand.plus.OsmAndLocationProvider.access$200(OsmAndLocationProvider.java:56)
    at net.osmand.plus.OsmAndLocationProvider$1.onLocationResult(OsmAndLocationProvider.java:257)
    at net.osmand.plus.LocationServiceHelperImpl$1.onLocationResult(LocationServiceHelperImpl.java:77)
    at com.google.android.gms.internal.location.zzap.notifyListener(com.google.android.gms:play-services-location@@18.0.0:2)
    at com.google.android.gms.common.api.internal.ListenerHolder.notifyListenerInternal(com.google.android.gms:play-services-base@@17.5.0:18)
    at com.google.android.gms.common.api.internal.ListenerHolder$zaa.handleMessage(com.google.android.gms:play-services-base@@17.5.0:6)
    at android.os.Handler.dispatchMessage(Handler.java:105)
    at android.os.Looper.loop(Looper.java:164)
    at android.app.ActivityThread.main(ActivityThread.java:6944)
    at java.lang.reflect.Method.invoke(Native Method)
    at com.android.internal.os.Zygote$MethodAndArgsCaller.run(Zygote.java:327)
    at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:1374)
ResourceManager Fail to initialize Latvia_europe_20_12_02.obf
java.io.FileNotFoundException: /storage/emulated/0/Android/data/net.osmand/files/live/Latvia_europe_20_12_02.obf: open failed: EMFILE (Too many open files)
    at libcore.io.IoBridge.open(IoBridge.java:512)
    at java.io.RandomAccessFile.<init>(RandomAccessFile.java:255)
    at net.osmand.plus.resources.ResourceManager$BinaryMapReaderResource.getReader(ResourceManager.java:143)
    at net.osmand.plus.CurrentPositionHelper.initCtx(CurrentPositionHelper.java:138)
    at net.osmand.plus.CurrentPositionHelper.runUpdateInThread(CurrentPositionHelper.java:221)
    at net.osmand.plus.CurrentPositionHelper.processGeocoding(CurrentPositionHelper.java:184)
    at net.osmand.plus.CurrentPositionHelper.access$000(CurrentPositionHelper.java:34)
    at net.osmand.plus.CurrentPositionHelper$1.run(CurrentPositionHelper.java:112)
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:457)
    at java.util.concurrent.FutureTask.run(FutureTask.java:266)
    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)
Caused by: android.system.ErrnoException: open failed: EMFILE (Too many open files)
    at libcore.io.Linux.open(Native Method)
    at libcore.io.BlockGuardOs.open(BlockGuardOs.java:207)
    at libcore.io.IoBridge.open(IoBridge.java:498)
    ... 12 more

A couple times OsmAnd offered its own exception log, but these only happen may be 1/20 of the time of the Android "stopped working" crashes. These seem to mostly be other crashes unrelated to this particular one, but there was one from 14 Apr in exception.log:

Version  OsmAnd 3.9.10
14.04.2021 7:54:51
Apk Version : 3.9.10 400
Exception occured in thread Thread[main,5,main] : 
android.database.sqlite.SQLiteCantOpenDatabaseException: unable to open database file (code 2062): , while compiling: PRAGMA journal_mode
#################################################################
Error Code : 2062 (SQLITE_CANTOPEN_EMFILE)
Caused By : Application has opened too many files. Maximum of available file descriptors in one process is 1024 in default.
    (unable to open database file (code 2062): , while compiling: PRAGMA journal_mode)
#################################################################
    at android.database.sqlite.SQLiteConnection.nativePrepareStatement(Native Method)
    at android.database.sqlite.SQLiteConnection.acquirePreparedStatement(SQLiteConnection.java:1096)
    at android.database.sqlite.SQLiteConnection.executeForString(SQLiteConnection.java:800)
    at android.database.sqlite.SQLiteConnection.setJournalMode(SQLiteConnection.java:449)
    at android.database.sqlite.SQLiteConnection.setWalModeFromConfiguration(SQLiteConnection.java:423)
    at android.database.sqlite.SQLiteConnection.open(SQLiteConnection.java:272)
    at android.database.sqlite.SQLiteConnection.open(SQLiteConnection.java:205)
    at android.database.sqlite.SQLiteConnectionPool.openConnectionLocked(SQLiteConnectionPool.java:649)
    at android.database.sqlite.SQLiteConnectionPool.open(SQLiteConnectionPool.java:255)
    at android.database.sqlite.SQLiteConnectionPool.open(SQLiteConnectionPool.java:222)
    at android.database.sqlite.SQLiteDatabase.openInner(SQLiteDatabase.java:1191)
    at android.database.sqlite.SQLiteDatabase.open(SQLiteDatabase.java:1146)
    at android.database.sqlite.SQLiteDatabase.openDatabase(SQLiteDatabase.java:861)
    at android.app.ContextImpl.openOrCreateDatabase(ContextImpl.java:729)
    at android.content.ContextWrapper.openOrCreateDatabase(ContextWrapper.java:310)
    at android.database.sqlite.SQLiteOpenHelper.getDatabaseLocked(SQLiteOpenHelper.java:254)
    at android.database.sqlite.SQLiteOpenHelper.getWritableDatabase(SQLiteOpenHelper.java:194)
    at net.osmand.plus.activities.SavingTrackHelper.execWithClose(SavingTrackHelper.java:677)
    at net.osmand.plus.activities.SavingTrackHelper.insertData(SavingTrackHelper.java:487)
    at net.osmand.plus.activities.SavingTrackHelper.updateLocation(SavingTrackHelper.java:477)
    at net.osmand.plus.OsmAndLocationProvider.setLocationFromService(OsmAndLocationProvider.java:755)
    at net.osmand.plus.NavigationService$1.onLocationResult(NavigationService.java:88)
    at net.osmand.plus.LocationServiceHelperImpl$1.onLocationResult(LocationServiceHelperImpl.java:77)
    at com.google.android.gms.internal.location.zzap.notifyListener(com.google.android.gms:play-services-location@@18.0.0:2)
    at com.google.android.gms.common.api.internal.ListenerHolder.notifyListenerInternal(com.google.android.gms:play-services-base@@17.5.0:18)
    at com.google.android.gms.common.api.internal.ListenerHolder$zaa.handleMessage(com.google.android.gms:play-services-base@@17.5.0:6)
    at android.os.Handler.dispatchMessage(Handler.java:105)
    at android.os.Looper.loop(Looper.java:164)
    at android.app.ActivityThread.main(ActivityThread.java:6944)
    at java.lang.reflect.Method.invoke(Native Method)
    at com.android.internal.os.Zygote$MethodAndArgsCaller.run(Zygote.java:327)
    at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:1374)

The app offered me a report today too among the other crashes, but I don't think it's directly related:

Version  OsmAnd 3.9.10
23.04.2021 9:03:21
Apk Version : 3.9.10 400
Exception occured in thread Thread[main,5,main] : 
java.lang.IllegalArgumentException
    at android.view.Surface.nativeUnlockCanvasAndPost(Native Method)
    at android.view.Surface.unlockSwCanvasAndPost(Surface.java:367)
    at android.view.Surface.unlockCanvasAndPost(Surface.java:348)
    at android.view.SurfaceView$3.unlockCanvasAndPost(SurfaceView.java:1182)
    at net.osmand.plus.views.OsmandMapTileView.refreshMapInternal(OsmandMapTileView.java:663)
    at net.osmand.plus.views.OsmandMapTileView.access$1200(OsmandMapTileView.java:65)
    at net.osmand.plus.views.OsmandMapTileView$3.run(OsmandMapTileView.java:846)
    at android.os.Handler.handleCallback(Handler.java:789)
    at android.os.Handler.dispatchMessage(Handler.java:98)
    at android.os.Looper.loop(Looper.java:164)
    at android.app.ActivityThread.main(ActivityThread.java:6944)
    at java.lang.reflect.Method.invoke(Native Method)
    at com.android.internal.os.Zygote$MethodAndArgsCaller.run(Zygote.java:327)
    at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:1374)

Anyway, about the files it mentions. There are multiple same exceptions that I can see and they point to different files, but they are all of style Latvia_europe_YY_MM_DD.obf, which is the region I am at and the offline map location that the app updates daily. The folder /net.osmand/files/live/ does indeed have files starting from 26 Oct 2020 Latvia_europe_20_10_00.obf and basically a file per day up to Latvia_europe_21_04_23.obf. (1 October seems to be the date of creation of Latvia_europe.obf in the /net.osmand/files/ folder, so I am guessing these are incremental updates?)

I won't delete these files on my end yet just in case there's something I can test or check for you.

vshcherb commented 3 years ago

It looks like the compact of Live files doesn't work correctly. Please delete these files and let's see if they pile up again. It is enough to have only 1 file per month (_00) and 1 file for today.

RudyTheDev commented 3 years ago

I deleted all the files and have been keeping track of the folder since. Here are the folder's files:

I don't know what actually triggers the live update if I don't manually trigger it from the app, so I was just randomly checking the folder once a day.

RudyTheDev commented 3 years ago

I deleted all the files once more to see what happens.