TimeoutException in version 4.0.2

[neophammdc]

I use the library on android, since upgrading to version 4.0.2 I sometimes encounter app crashes. I have no way to reproduce the problem but this never happened in older versions.

I found the problem here #610 (#610)

But in the app I never called BoxStore.close()

FATAL EXCEPTION: FinalizerWatchdogDaemon (Ask Gemini)
java.util.concurrent.TimeoutException: io.objectbox.Transaction.finalize() timed out after 60 seconds
	at io.objectbox.Transaction.nativeDestroy(Native Method)
	at io.objectbox.Transaction.close(Transaction.java:128)
	at io.objectbox.Transaction.finalize(Transaction.java:87)
	at java.lang.Daemons$FinalizerDaemon.doFinalize(Daemons.java:339)
	at java.lang.Daemons$FinalizerDaemon.processReference(Daemons.java:324)
	at java.lang.Daemons$FinalizerDaemon.runInternal(Daemons.java:300)
	at java.lang.Daemons$Daemon.run(Daemons.java:145)

[greenrobot]

I sometimes encounter app crashes

Can you qualify that a bit? Do you have crash statistics?

P.S.: I you ever see this on a device in front of you, please grab the logcat (including the events happening ~ 65 seconds before TimeoutException) and post it here.

PPS.: "But in the app I never called BoxStore.close()" -> That's fine, no need to. Closing a transaction should never take 60s.

[neophammdc]

Hi @greenrobot ,

After eliminating the possibilities. I think the error may be in the use of Many-to-Many relationship.
In previous versions, I only used tables without relationships: table_A, table_B, table_C, table_D
In the new version, I added table_TAG with Many-to-Many relationship to tables table_A, table_B, table_C, table_D
Whenever I update or change data related to these relationships, the error occurs.

"P.S.: I you ever see this on a device in front of you, please grab the logcat (including the events happening ~ 65 seconds before TimeoutException) and post it here." I checked the logs earlier but found nothing related to this issue.

[greenrobot]

Oh, can you reproduce it? That's good news... If it's possible to you to create a minimal reproduction example code that we can execute would help us a lot to get this analyzed and fixed (assuming it is a bug and it looks like one at first glance).

[neophammdc]

@greenrobot , I have tried updates and queries with Many-to-Many relationships and they all work perfectly. So I really don't know when the error occurs, which makes it hard to reproduce the problem.

[neophammdc]

@greenrobot, please see my attached application log

logcat.txt

[greenrobot]

Had a look, but the log does not go back ~ 65 seconds (before the TimeoutException), so I did not spot anything interesting...

Maybe you have to increase the logcat buffer so it's not cut off?

[neophammdc]

@greenrobot , I got a new log longer than 65 seconds, you can see the attached file
logcat65s.txt

[greenrobot]

Nothing much too see there... In fact no ObjectBox logs at all... Can you please enable LOG_TRANSACTIONS_READ and LOG_TRANSACTIONS_WRITE debug flags (via BoxStoreBuilder.debugFlags())?

Also, any idea where this log entry comes from?

Was finalizing TX -4bffff8a1e8d35a0 (read-only, initialCommitCount=6), now finalizing TX -4bffff8a1e8d35a0 (read-only, initialCommitCount=6)

[neophammdc]

hi @greenrobot ,
I'm enabled DebugFlags with options:
storeBuilder.debugFlags(DebugFlags.LOG_TRANSACTIONS_READ | DebugFlags.LOG_TRANSACTIONS_WRITE | DebugFlags.LOG_QUERIES | DebugFlags.LOG_QUERY_PARAMETERS | DebugFlags.LOG_ASYNC_QUEUE | DebugFlags.LOG_CACHE_HITS | DebugFlags.LOG_CACHE_ALL | DebugFlags.LOG_TREE | DebugFlags.LOG_EXCEPTION_STACK_TRACE | DebugFlags.RUN_THREADING_SELF_TEST );

Please see two log attach all and filter with Box

logDebugAll.txt

logDebugFilterBox.txt

Was finalizing TX -4bffff8a1e8d35a0 (read-only, initialCommitCount=6), now finalizing TX -4bffff8a1e8d35a0 (read-only, initialCommitCount=6): I'm not sure where this is coming from, I use 3 devices Xiaomi Mi10, Samsung S23 ultra and Google Pixel 6 all have this error

[neophammdc]

@greenrobot , On my Pixel device, I get a hint:
use closeThreadResources() to avoid finalizing recycled transactions (initial commit count: 7).

Full log attach here:
logDebugPixelDevice.txt

[greenrobot-team]

Re the Was finalizing TX -4bffff8a1e8d35a0 (read-only, initialCommitCount=6), now finalizing TX -4bffff8a1e8d35a0 (read-only, initialCommitCount=6) log:

the TX -4bffff8a1e8d35a0 (read-only, initialCommitCount=6) parts are the toString() of Transaction objects. So this is likely output of the virtual machine when it finalizes those objects.

[greenrobot-team]

In both logDebugAll.txt and logDebugPixelDevice.txt I could find only a single transaction that is destroyed by a non-owner thread. Which in both cases is the FinalizerDaemon.

So for whatever reason, if a Transaction is destroyed by the FinalizerDaemon thread it blocks?

2024-09-20 12:16:45.216 24211-24227 System.out              com.myapp.test                       I  Hint: use closeThreadResources() to avoid finalizing recycled transactions (initial commit count: 7).
2024-09-20 12:16:45.216 24211-24227 Box                     com.myapp.test                       I  TX #46 to be destroyed on non-owner thread (last committed: TX #68)...
2024-09-20 12:16:45.216 24211-24227 Box                     com.myapp.test                       W  Skipping low-level close for read-only cursor (non-creator thread 'FinalizerDaemon')
2024-09-20 12:16:45.216 24211-24227 Box                     com.myapp.test                       W  Destroyed recycled transaction owned by thread 7 from non-owner thread 'FinalizerDaemon'
2024-09-20 12:16:45.216 24211-24227 Box                     com.myapp.test                       W  Skipping low-level close for read-only cursor (non-creator thread 'FinalizerDaemon')

@neophammdc Regarding introducing ToMany: was this with the same release that updated to ObjectBox 4.0.2? In any case, depending on the likelihood of the crash this might just be a coincidence.

A potential workaround if your code does Box operations on a background thread: as the log output suggests, try to add a call to BoxStore.closeThreadResources() before the thread is done.

[neophammdc]

Hi @greenrobot-team

I tried calling BoxStore.closeThreadResources() before closing the thread. Now I don't have this issue anymore, I think this should be noted in the official documentation.

Thank you so much