Improve logging of DB message insertion

[H3rnand3zzz]

Addressing unreliable message history reports where some messages were written in the file log but not in the DB. This issue was not consistently reproducible, but investigations revealed potential causes.

1. SQLite file access issues were ruled out, as they would trigger errors in the error log.
2. The problem could be due to the WHERE clause in the insert query, preventing message insertion.

To resolve this, I propose:

• Removing the WHERE clause from the insert query, allowing messages with duplicate IDs or stanza IDs to be inserted.
• Implementing a warning log for duplicate stanza-ids or archive-ids for further investigations.

I also am planning to offer an optional setting in the future to handle duplicate IDs or stanza IDs differently, to resolve potential duplicate messages issues which might happen theoretically because of MAM. But the exact shape of the option depends on many things. Anyway, I see duplicate messages as a lesser evil comparing to unreliable history.

This is a prototype solution and will require feedback and refinement.

This change aims to improve message history reliability, especially for users who rely on logs for critical information.

The solution is based on the way that other clients handle such cases (by ignoring duplication of stanza-id).
https://dev.gajim.org/gajim/gajim/-/blob/master/gajim/common/modules/message.py?ref_type=heads#L224

I ask @jubalh to provide more context from MUC (since I lost MUC history).

[jubalh]

We had some discussions about this via PM and in the Profanity MUC. I'll try to add some more context.

Addressing unreliable message history reports where some messages were written in the file log but not in the DB.

The "file log", what we usually call text chat log files, is just a dump of everything we receive/send. There is no other logic there. It was our legacy system before we had the SQL database. We considered removing it but then decided that some people will like to have those chat logs for easy grepping of conversations.

The problem could be due to the WHERE clause in the insert query, preventing message insertion.

So the assumption I made via PM was that we either have something not right with NULL checking and then will silently not insert the message to the DB. Or that our WHERE logic might not be correct. We had an issue in the past: c5b370b.

I also am planning to offer an optional setting in the future to handle duplicate IDs or stanza IDs differently, to resolve potential duplicate messages issues which might happen theoretically because of MAM.

I'm not exactly sure what you mean here. Right now MAM doesn't insert messages twice.

The solution is based on the way that other clients handle such cases (by ignoring duplication of stanza-id).

I'm surprised they just insert. It is a long time ago but I believe that I either checked Gajim/Dino code when I implemented this or talked with one of the devs about it.

Now about why we had this check in the first place:
For some things like: XEP-0308: Last Message Correction, XEP-0444: Message Reactions we need the ID to reference the message.
Example:

• message id = 123 text = hullo
• correct message with id 123 to hello

If we have the same ID several times in the DB how do we know which one to correct? How do other clients do this? Just support these features if the ID is only present ONCE and otherwise not offer the feature for this message? Instead of aborting to insert duplicate IDs just give them a dummy ID and thus also not allow correction (and other features) on those?

One thing that we should do for sure is: if we check, then we shouldn't just check the ID but also the sender.
Also different IDs are at play here. Some are generated by the server others by the client. It is true that somehow we need to deal with clients that don't follow the spec exactly without breaking things for our users. If we trust the server to generate unique IDs then this would also be another thing.

What we should do, and the questions we need to answer:

• maybe create an overview of the various IDs that exist (origin-id (XEP-0359) , stanza-id (XEP-0359), stanza id (in RFC6121), replace id (XEP-0308).. are there more?
• which of the IDs do we need to save?
• which of them need to be unique?
• find out what other clients do (not just IF they insert or not, but also HOW they then solve the cases when they want to use a feature (correction for example) with a duplicate ID

About this PR: Refactor message insertion query and duplicate check I think refactor is not quite right. To me that would mean that the functionality stays the same :)

[H3rnand3zzz]

Now noticable behavioural change (letting non-unique stanzas) comes with non-default setting, so it can be a question of preference. But duplicate stanzas are logged for everyone, so we can have more diagnostic data.

[jubalh]

I talked with someone about this.
Let's do it like this:
Save all messages even with duplicate IDs in DB.
If the server generated stanza-id from XEP-0359: Unique and Stable Stanza IDs is not unique then we use log_warn and print it to console. About the rest (client generated IDs) we don't warn we just add them to the DB.

With things like Last Message Correction we just use the newest/latest message with that ID. (And maybe try to find out what other clients do here).

Would you mind changing the PR to this behaviour?

[jubalh]

BTW keep in mind to check src/xmpp/xmpp.h in the ProfMessage you can see what IDs we save there and their XEP. And also the name of the DB entry (in case of archive id).

[H3rnand3zzz]

If the server generated stanza-id from XEP-0359: Unique and Stable Stanza IDs is not unique then we use log_warn and print it to console.

It might lead to flood in the console in case if, for example, server sets all stanza-ids to "0". We can just warn, I think that it would be a preferable behaviour.

With things like Last Message Correction we just use the newest/latest message with that ID. (And maybe try to find out what other clients do here).

That can be done

Would you mind changing the PR to this behaviour?

Surely, but you didn't mention whether setting is still needed. I think I can change default and keep it, just in case if someone has a problem with duplicate messages.

[weiss]

if, for example, server sets all stanza-ids to "0".

That would be a critical server-side bug, breaking history/device sync and whatnot, comparable with, dunno, dropping stanzas. I think a client should complain as loud as possible in that case.

[jubalh]

Surely, but you didn't mention whether setting is still needed

Not needed.

[H3rnand3zzz]

@jubalh can we discuss some changes in a chat?

[jubalh]

@jubalh can we discuss some changes in a chat?

I'm on vacation and only check GitHub sporadically.
Other people monitor this PR too to provide guidance. But probably most things are already mentioned I believe?

[H3rnand3zzz]

The problem is about replacement. As it is right now quite complicated SQL query:

auto_sqlite gchar* query = sqlite3_mprintf("SELECT * FROM (SELECT COALESCE(B.`message`, A.`message`) AS message, A.`timestamp`, A.`from_jid`, A.`type`, A.`encryption` from `ChatLogs` AS A LEFT JOIN `ChatLogs` AS B ON A.`stanza_id` = B.`replace_id` WHERE A.`replace_id` = '' AND ((A.`from_jid` = '%q' AND A.`to_jid` = '%q') OR (A.`from_jid` = '%q' AND A.`to_jid` = '%q')) AND A.`timestamp` < '%q' AND (%Q IS NULL OR A.`timestamp` > %Q) ORDER BY A.`timestamp` %s LIMIT %d) ORDER BY `timestamp` %s;", contact_barejid, myjid->barejid, myjid->barejid, contact_barejid, end_date_fmt, start_time, start_time, sort1, MESSAGES_TO_RETRIEVE, sort2);

Even right now it has bugs: if you replace the same message twice or more, it will replace it visually, but after loading history, it will show only the first correction.

What we want to do is barely within a scope of an SQL query (at least not in a way it's implemented right now), as we need to select all the replacement and apply them only in the first case. I see a few ways to implement it, but none of them are to my liking.

As an alternative solution, we can use "replaces_id", which would be linked to the DB incremental ID or limit replacement capabilities to only the most recent messages.

All the proposed changes would either add complexity to the query and make it slower, either require further development, changes in DB etc.

My proposal is to add diagnostic part for now, possibly with removing the setting and after further studying the problem, we can understand its underlying causes and fix directly them, rather than relying on major changes to potentially fix a problem.

[jubalh]

Even right now it has bugs: if you replace the same message twice or more, it will replace it visually, but after loading history, it will show only the first correction.

Great find! I propose to solve this in another PR since, as I understand it, it's not related to DB but to presentation.

Please improve commit message a bit. We are not refactoring anything as far as I can see :)
PR title also needs to be adapted. It's good to point to the PR to see the full discussion and how we arrived at this solution. But the solution should still be described a bit more in the commit message.

I would also mention why we don't want those duplicate IDs (in the commit message) and maybe even a short commit above the check in the code (something like the stanza-id should be unique according to XEP...) at least when coming from the same server..

I didn't check the SQL code deeply (yet) but code looks generally fine I think. duplicate_exists I might have added some info that it's about stanza-id or archive_id or something.. But not necessary.

[H3rnand3zzz]

@jubalh , please, contact me ASAP, I have important findings.

[jubalh]

@jubalh , please, contact me ASAP, I have important findings.

As mentioned I'm on vacation. I now specifically went to a place where I can access my chat client.. And I see that you haven't written anything to me and even didn't answer to my last messages there..

[H3rnand3zzz]

@jubalh , please, contact me ASAP, I have important findings.

As mentioned I'm on vacation. I now specifically went to a place where I can access my chat client.. And I see that you haven't written anything to me and even didn't answer to my last messages there..

Sorry, missed the notifications. Anyways, I answered and we discussed the issue and came to a conclusion.

[jubalh]

Originally I believed we will change the behaviour of the db logging in this PR. But I guess just adding some logging is ok as well.