> it started to write bin log for the remaining records for that transaction

I don't see what you call p.3 binlog snippet relevant to p.2 fully logged trx.
Notice specifically p.3 thread_id=72 is different from one in p.2.

Could you please explain what do you mean?

> , it started to write bin log for the remaining records for that transaction

'That' transaction is fully committed in binlog, having thread_id 11783. In the follow up that the thread id is different.
Could you please explain in details what got wrong in your case.

Thanks for looking at this.

So what does thread_id in binlog signify and under what condition should it be changed? Does it mean new connection initiated from client?

Here are details of what was going on (note they were all running under single product thread context):

1. Start one transaction and loop reading "db01host.notify_remdb_operation" table by calling C++ mysql_real_query with statement param "select * from db01host.notify_remdb_operation where remote_ip = x'00a9fe4001000000000000000000000000000000' and process_name = 'SSPcntl_agt'"

2. Also start another transaction to handle all tuples read from p.1. For each tuple, we just reset its retry_count field to 0 and write back to DB via calling mysql_real_query with update statement.

3. After all tuples matching specified "remote_ip" and "process_name" were handled, the first transaction got "rollback" and the second transaction got "commit" via mysql_query which returned success as confirmed from product logs.

The binlog snippets (both p.2 and p.3 in description) should all belong to the same transaction (the second) because they all have the same process_id = 11312 which was the old one. In between p.2 and p.3 snippets, the process_id had been updated to the new one "process_id = 64602".
So regarding p.3 binlog there should be no way for a new transaction to get the old process_id 11312 after all tuples had been updated to the new value 64602. That's why we say p.2 and p.3 binlogs in description belong to the same committed transaction. However p.3 bin log was updated >6m later than p.2 and overwrote the latest correct DB tuples with wrong tuples with old process_id = 11312.

> The binlog snippets (both p.2 and p.3 in description) should all belong to the same transaction (the second) because they all have the same process_id = 11312 which was the old one.

This assumption bases on your application logics. But indeed we see in the database different connection identifiers (that's what thread_id is) for blocks of sql code that you think one transaction. A transaction can be associated with at most one connection.

One way to reconcile expectations and reality here would be to temporarily enable the general log and then to match it with the binary log, to see which updates come from where.

Thanks for the advice.
We'll try to reproduce with general log enabled for further clue. Meanwhile we'll be also looking at this from product perspective.

liberiul, any new discoveries?

It's found that the replication got delayed significantly under extreme high CPU usage. The statement executed on master host was not applied to slave host until minutes later. The delayed replication events finally overrode the statements queried to slave and caused the issue.

Would you advise:
1) Are there any tweaking options to improve mariadb performance or reduce CPU usage? It is noticed that the commit may take long time to finish (>1m).
2) How to assure the replication timing based on timestamp?
e.g.
Event A: master update tuple T at 1:00;
Event B: slave updates tuple T at 1:02;
The event A should be replicated and applied to slave no later than event B. Otherwise the DB value on slave would be mistakenly overridden by the obsolete one.

liberiul, to the 2nd of the two, it looks like you'd be interested in master_wait_gtid. That is the B's updater would invoke the function prior to submit the update. That obviously requires A and B updaters coordination on the matter of the sequence number of replication events. (B must be aware of the last A's update's gtid).

To the 1st question, it looks like the request is about the slave threads scheduling prioritization (which we don't provide unfortunately) unless your whole slave server was busy.

Thanks for the explanation. This ticket can be closed.