0.6.9-fdroid freezes during conversations

[baldurmen]

Hi!

Running 0.6.9-fdroid, the app often freezes when I'm having a conversation with someone. I try to write a message and click the send button, but the message does not appear in the chat window. The whole app freezes (can't click the back arrow at the top left for example) and I have to wait until the app syncs with the voip.ms server to see the message I sent. Often I have to hard kill the app.

I say "in a conversation" since it seems it's worse when someone is also texting me at the same time.

With 0.6.5-fdroid (the last version that worked well for me), I would send the message and it would appear immediately in the chat window as "Sending...". This is not the case anymore.

I'm running Android 10. I can try to get something from alogcat if that helps and you can't reproduce the issue.

[michaelkourlas]

The behaviour you're describing was a known problem with 0.6.6 and 0.6.7, and a lot of people complained about it. However, 0.6.8 stopped using WorkManager and reverted back to IntentService, so you shouldn't be seeing this problem anymore.

[michaelkourlas]

When I use the F-Droid version of the app that I built (in the releases section of the app) I cannot reproduce this on 0.6.9. I haven't tried the version that F-Droid builds.

[michaelkourlas]

I'd be curious to know if you can reproduce it:

• with my F-Droid builds (as opposed to F-Droid's own builds)
• with 0.6.8, which is the release which should have fixed this issue
• with the non-F-Droid version of the app (assuming you have Google Play Services)

[baldurmen]

* with my F-Droid builds (as opposed to F-Droid's own builds)

I can reproduce with your 0.6.9-fdroid build yes. This is what I get:

10-22 13:06:30.069 26282 28525 W rlas.voipms_sm: Long monitor contention with owner Thread-119 (28546) at void net.kourlas.voipms_sms.sms.Database.insertMessageDraft(net.kourlas.voipms_sms.sms.ConversationId, java.lang.String)(Database.kt:463) waiters=16 in void net.kourlas.voipms_sms.sms.Database.insertMessageDraft(net.kourlas.voipms_sms.sms.ConversationId, java.lang.String) for 8.273s

8 seconds can be a looooong time, so maybe it's just a problem of performance? Looking at my logs, it seems normally it takes from 500ms to 1.5s for a message to be processed, but I can easily overload the app when sending multiple messages one after the other. When I do, they progressively take longer and longer to be processed. I guess spikes happening in a conversation where the app works more would be consistent with the problems I've been having.

I don't have a very fast phone, but I haven't had performance problems with other apps so far.

* with 0.6.8, which is the release which should have fixed this issue

Same behavior.

* with the non-F-Droid version of the app (assuming you have Google Play Services)

Sadly, I do not :(

[AMDSeb]

I have the same problem with the latest Play Store version. The change from WorkManager to IntentService helped, but oftentimes when I send a message the screen is frozen, it doesn't display the message I just sent until the sync with the server is complete. This can take several seconds (10-20-30?).

[michaelkourlas]

I have a single lock restricting access to the database, but the SQLiteDatabase documentation suggests it should take care of properly handling multi-threaded access. Maybe I can just remove the lock.

[michaelkourlas]

Try this APK and see if it fixes the problem.

voipms-sms-fdroid-full-release-unsigned.zip

[baldurmen]

Not an android expert, but I don't think so. Happy to provide more detailed logs or to test other builds.

10-24 01:27:57.411 30692 32667 W SQLiteConnectionPool: Connections: 0 active, 1 idle, 0 available.
10-24 01:27:57.485 30692 32668 W SQLiteConnectionPool: The connection pool for database '/data/user/0/net.kourlas.voipms_sms/databases/sms.db' has been unable to grant a connection to thread 698 (Thread-122) with flags 0x2 for 30.000002 seconds.
10-24 01:27:57.485 30692 32668 W SQLiteConnectionPool: Connections: 0 active, 1 idle, 0 available.
10-24 01:27:57.612 30692 32669 W SQLiteConnectionPool: The connection pool for database '/data/user/0/net.kourlas.voipms_sms/databases/sms.db' has been unable to grant a connection to thread 699 (Thread-123) with flags 0x2 for 30.000002 seconds.
10-24 01:27:57.612 30692 32669 W SQLiteConnectionPool: Connections: 0 active, 1 idle, 0 available.
10-24 01:27:57.690 30692 32670 W SQLiteConnectionPool: The connection pool for database '/data/user/0/net.kourlas.voipms_sms/databases/sms.db' has been unable to grant a connection to thread 700 (Thread-124) with flags 0x2 for 30.000002 seconds.
10-24 01:27:57.690 30692 32670 W SQLiteConnectionPool: Connections: 0 active, 1 idle, 0 available.
10-24 01:27:57.801 30692 32671 W SQLiteConnectionPool: The connection pool for database '/data/user/0/net.kourlas.voipms_sms/databases/sms.db' has been unable to grant a connection to thread 701 (Thread-125) with flags 0x2 for 30.000002 seconds.
10-24 01:27:57.801 30692 32671 W SQLiteConnectionPool: Connections: 0 active, 1 idle, 0 available.
10-24 01:27:57.869 30692 32672 W SQLiteConnectionPool: The connection pool for database '/data/user/0/net.kourlas.voipms_sms/databases/sms.db' has been unable to grant a connection to thread 702 (Thread-126) with flags 0x2 for 30.000002 seconds.
10-24 01:27:57.869 30692 32672 W SQLiteConnectionPool: Connections: 0 active, 1 idle, 0 available.
10-24 01:27:57.995 30692 32673 W SQLiteConnectionPool: The connection pool for database '/data/user/0/net.kourlas.voipms_sms/databases/sms.db' has been unable to grant a connection to thread 703 (Thread-127) with flags 0x2 for 30.000002 seconds.
10-24 01:27:57.995 30692 32673 W SQLiteConnectionPool: Connections: 0 active, 1 idle, 0 available.
10-24 01:27:58.498 30692 32698 W SQLiteConnectionPool: The connection pool for database '/data/user/0/net.kourlas.voipms_sms/databases/sms.db' has been unable to grant a connection to thread 704 (Thread-128) with flags 0x2 for 30.000002 seconds.
10-24 01:27:58.498 30692 32698 W SQLiteConnectionPool: Connections: 0 active, 1 idle, 0 available.
10-24 01:27:58.861 30692 32703 W SQLiteConnectionPool: The connection pool for database '/data/user/0/net.kourlas.voipms_sms/databases/sms.db' has been unable to grant a connection to thread 705 (Thread-129) with flags 0x2 for 30.000002 seconds.
10-24 01:27:58.861 30692 32703 W SQLiteConnectionPool: Connections: 0 active, 1 idle, 0 available.
10-24 01:27:58.915 30692 32704 W SQLiteConnectionPool: The connection pool for database '/data/user/0/net.kourlas.voipms_sms/databases/sms.db' has been unable to grant a connection to thread 706 (Thread-130) with flags 0x2 for 30.000002 seconds.
10-24 01:27:58.915 30692 32704 W SQLiteConnectionPool: Connections: 0 active, 1 idle, 0 available.
10-24 01:27:59.035 30692 32705 W SQLiteConnectionPool: The connection pool for database '/data/user/0/net.kourlas.voipms_sms/databases/sms.db' has been unable to grant a connection to thread 707 (Thread-131) with flags 0x2 for 30.000002 seconds.

[michaelkourlas]

Okay, try this version, which also has write-ahead logging enabled.

voipms-sms-fdroid-full-release-unsigned.zip

[baldurmen]

Some messages still take a few seconds to show up sometimes, but I'd say it's much better now. I can actually have a conversation between two numbers. I don't see any obvious errors or warnings with logcat, it looks like this:

10-25 02:27:33.595  3895  5343 I net.kourlas.voipms_sms.sms.services.SendMessageService: [52d83ca8] sent message
10-25 02:27:33.596  3895  5343 I net.kourlas.voipms_sms.sms.services.SendMessageService: [12a0df77] sending message
10-25 02:27:35.663  3895  5343 I net.kourlas.voipms_sms.sms.services.SendMessageService: [12a0df77] sent message
10-25 02:27:35.678  3895  5343 I net.kourlas.voipms_sms.sms.services.SendMessageService: [6c4a38a] sending message
10-25 02:27:36.236  3895  3907 I rlas.voipms_sm: Background concurrent copying GC freed 53937(2075KB) AllocSpace objects, 91(1820KB) LOS objects, 49% free, 3678KB/7356KB, paused 183us total 106.577ms

Thanks!

[michaelkourlas]

Should be fixed in 0.6.10.