A data-modifying stored function invoked from a stored routine expression is binlogged as its own standalone GTID group outside the caller's transaction, diverging master and slave on ROLLBACK

DESCRIPTION
===========
Under statement-based binary logging a data-modifying stored function is not
logged by its own substatements. The server suppresses their logging, counts
them, and on function exit synthesises a single Query_log_event holding the
text "SELECT db.f()" on behalf of the whole call:

sql/sp_head.cc:2085-2087 start_union_events(), OPTION_BIN_LOG cleared
sql/log.cc:8716-8725 each suppressed event only sets
unioned_events / unioned_events_trans
sql/sp_head.cc:2112-2114 the synthesised event, written with a raw
mysql_bin_log.write(&qinfo)

When the function is called from inside an explicitly started transaction that
synthesised event does not join the transaction. It is written DIRECTLY to the
binary log file, wrapped in its own standalone GTID, ahead of the caller's
still-unflushed transaction cache.

The direct write also takes MDL_BACKUP_COMMIT and calls wait_for_prior_commit()
at sql/log.cc:8815-8830, i.e. performs commit-ordering work in the middle of an
open transaction.

REPRODUCE
=========

  create table t1 (a varchar(32)) engine=innodb;

  create function f4_dir() returns int

  begin

    insert into t1 values ('f4_dir');

    return 0;

  end;

  create procedure p4_dir()

  begin

    insert into t1 values ('p4_dir');

  end;

  create procedure p3_dir()

  begin

    declare a int default f4_dir();   -- leaf reached through an expression

    call p4_dir();                    -- leaf reached through CALL

    insert into t1 values ('p3_dir');

  end;

  create procedure p2_dir()

  begin

    call p3_dir();

    insert into t1 values ('p2_dir');

    call p3_dir();

  end;

  create procedure p1_dir() begin call p2_dir(); end;

  start transaction;

  call p1_dir;

  commit;

With binlog_format=STATEMENT, SHOW BINLOG EVENTS returns three event groups
where one is expected:

    Gtid    GTID #-#-#

    Query   use `test`; SELECT `test`.`f4_dir`()

    Gtid    GTID #-#-#

    Query   use `test`; SELECT `test`.`f4_dir`()

    Gtid    BEGIN GTID #-#-#

    Query   use `test`; INSERT INTO t1 VALUES ('p4_dir')

    Query   use `test`; INSERT INTO t1 VALUES ('p3_dir')

    Query   use `test`; INSERT INTO t1 VALUES ('p2_dir')

    Query   use `test`; INSERT INTO t1 VALUES ('p4_dir')

    Query   use `test`; INSERT INTO t1 VALUES ('p3_dir')

    Xid     COMMIT /* XID */

mariadb-binlog confirms the first two groups carry no "trans" flag, i.e. they
are standalone GTIDs and not members of the transaction:

    GTID 0-1-6 thread_id=5             <- standalone

    GTID 0-1-7 thread_id=5             <- standalone

    GTID 0-1-8 trans thread_id=5

Three defects are visible in that one trace:

• Atomicity. The function's changes are published as committed while the
  caller's transaction is still open.
• Ordering. Binlog order is f4, f4, ins...; execution order is
  f4, ins_p4, ins_p3, ins_p2, f4, ins_p4, ins_p3.
• GTID accounting. One user transaction consumes three GTIDs, which a replica
  may apply apart from, or in parallel with, the group they belong to.

p4_dir is the control that isolates the trigger. Both leaves run the very same
INSERT and differ only in how they are reached; the CALL-reached leaf's INSERT
stays inside the transaction group in correct order, and only the leaf reached
through the DECLARE ... DEFAULT expression escapes. So this is neither about
nesting depth nor about EXECUTE IMMEDIATE - an earlier variant of the test ran
the nested INSERTs through EXECUTE IMMEDIATE and behaves identically.

DIVERGENCE
==========
Substituting ROLLBACK for COMMIT above turns the ordering anomaly into data
loss:

  master t1 after ROLLBACK:  empty - the function's rows belong to the same

                             InnoDB transaction and roll back with it

  binary log after ROLLBACK: a COMMITTED Gtid + "SELECT test.f4()" group

A replica applying that log gains rows the master does not have, from a plain
client START TRANSACTION, with no error raised anywhere.

FORMATS
=======
STATEMENT and MIXED produce byte-identical, broken traces. MIXED does NOT
demote these statements to row format, so it is affected exactly as STATEMENT.
ROW is correct - a single BEGIN GTID ... Xid group with all row events in
execution order - because the synthesised event is only produced under
statement-based logging (need_binlog_call, sql/sp_head.cc:2023).

ROOT CAUSE
==========
Notation.

• e_f is the synthesised "SELECT db.f()" event;
• L is thd->lex at the moment e_f is constructed;
• phi(L) is sql_command_flags[L->sql_command] & CF_CAN_GENERATE_ROW_EVENTS;
• c(e) is the event's cache_type;
• u is thd->binlog_evt_union.unioned_events_trans.

e_f is synthetic - it has no statement of its own. L belongs to whichever SP
instruction happens to be evaluating the function call. Yet Query_log_event's
constructor decides the event's destination cache from L:

    sql/log_event_server.cc:1453        LEX *lex= thd->lex;

    sql/log_event_server.cc:1471-1510   switch (lex->sql_command) ...

    sql/log_event_server.cc:1507        default: use_cache=

                                          sqlcom_can_generate_row_events(thd)

For a real statement that inference is sound, because the LEX IS the event.
For e_f it is a category error.

The constructor's precedence at sql/log_event_server.cc:1516-1527 is evaluated
in this order:

    !use_cache || direct                     -> c = EVENT_NO_CACHE

    using_trans || trx_cache || ...          -> c = EVENT_TRANSACTIONAL_CACHE

    else                                     -> c = EVENT_STMT_CACHE

so the L-derived use_cache outranks the caller's explicit using_trans. And
using_trans is not a guess here: execute_function passes u, set at
sql/log.cc:8723 from the fact that the function body did modify a
transactional table. A fact is discarded in favour of a heuristic about an
unrelated LEX.

MYSQL_BIN_LOG::write(Log_event*) takes no using_trans parameter; it re-derives
both from cache_type at

    sql/log.cc:8681-8682   using_trans= event_info->use_trans_cache();

                           direct= event_info->use_direct_logging();

so u survives only through c(e_f). Once the constructor has flipped it to
EVENT_NO_CACHE nothing downstream can recover it: sql/log.cc:8783 takes the
direct branch and sql/log.cc:8835 writes a standalone GTID straight to the
file.

The one guard that would have rescued it forces direct=0, using_trans=1, but
only on applier-side flags:

    sql/log.cc:8705-8714   if (option_bits &

                               (OPTION_GTID_BEGIN | OPTION_BIN_COMMIT_OFF))

OPTION_GTID_BEGIN is a slave / wsrep flag - its own comment at
sql/sql_priv.h:75 reads "GTID BEGIN found in log", and it is set at
sql/log_event_server.cc:2388, sql/log_event_server.cc:3321 and
sql/wsrep_high_priority_service.cc:581. A client's START TRANSACTION sets
OPTION_BEGIN, so on a master the branch is dead. The same slave-only asymmetry
sits in THD::binlog_query at sql/sql_class.cc:8281-8285.

Three chances to notice that an engine transaction is open; none is taken.

The escape predicate follows: e_f leaves the transaction iff statement-based
logging is in effect, e_f exists, phi(L) = 0, and L->sql_command has no
explicit case in the switch at sql/log_event_server.cc:1473-1509.

1. DECLARE a INT DEFAULT f(). L is the sp_lex_local passed at
sql/sql_lex.cc:7042, started through LEX::start ->
reset_query_tables_list() -> sql/sql_lex.cc:4112, so
sql_command = SQLCOM_END; and phi = 0 because sql_command_flags is memset
at sql/sql_parse.cc:517 and SQLCOM_END is never assigned any flag.
ESCAPES.

2. SET a = f(). sql_command = SQLCOM_SET_OPTION (sql/sp_instr.h:715-719),
which has both an explicit case at sql/log_event_server.cc:1494-1499 and
phi = 1 (sql/sql_parse.cc:630-633; the @todo above it at
sql/sql_parse.cc:626 claiming the flag is absent is stale). STAYS INSIDE
THE GROUP - measured with two otherwise identical procedures side by side.

So the same function call is logged correctly or incorrectly purely according
to which SP instruction's LEX happens to be current.

SUGGESTED FIX
=============
Three altitudes. None of these is written or tested yet.

1. Stop e_f's destination depending on L. At sql/sp_head.cc:2112, after
constructing qinfo, never leave it uncached:

     if (qinfo.cache_type == Log_event::EVENT_NO_CACHE)

       qinfo.cache_type= u ? Log_event::EVENT_TRANSACTIONAL_CACHE

                           : Log_event::EVENT_STMT_CACHE;

The EVENT_STMT_CACHE fallback matters: when the function touched only
non-transactional tables, use_trans_cache() at sql/log.cc:8850 then applies
the ordinary policy instead of a direct write. This covers every
SP-instruction context at once, including the IF / CASE sites below,
without enumerating them.

2. Add the missing master-side invariant. At sql/log.cc:8705 extend the guard
to

     (option_bits & (OPTION_GTID_BEGIN | OPTION_BIN_COMMIT_OFF)) ||

     thd->transaction->all.ha_list

thd->transaction->all.ha_list != NULL is this codebase's own "an engine
transaction is open" test: the applier uses exactly it at
sql/log_event_server.cc:3274, and handler.cc pairs it with
OPTION_GTID_BEGIN at sql/handler.cc:8015. In the reproducer it is already
non-empty at the first f4_dir() call, since the function's own INSERT
registers InnoDB in all. The justification is structural: a direct write
while an engine transaction is open publishes as committed something the
engine may still roll back, which is exactly the ROLLBACK divergence above.

3. Fix the precedence properly, as a separate commit. At
sql/log_event_server.cc:1516, let an explicit using_trans outrank the L
heuristic:

     if (direct)                          NO_CACHE;

     else if (using_trans || trx_cache || ...)  TRANSACTIONAL_CACHE;

     else if (!use_cache)                 NO_CACHE;

     else                                 STMT_CACHE;

Correct shape, but it changes classification for every Query_log_event, so
it needs an audit of the callers that pass using_trans=TRUE where use_cache
is deliberately 0 - the raw writers at sql/sql_db.cc:260, 885, 956, 1228,
2103, sql/sql_base.cc:3342, sql/temporary_tables.cc:1518 and
sql/sql_class.cc:8379. Not a candidate for a GA branch without that audit.

Recommended: 1 + 2 together. 1 removes the dependence on an unrelated LEX,
2 makes the whole class unreachable; 3 queued behind the caller audit.

ATTACHMENTS
===========
The MTR test is attached as files, not pasted here. It runs in all three
binlog-format combinations of the binlog suite and carries one recorded result
per combination:

    mysql-test/suite/binlog/t/binlog_sp_log_signature.test

    mysql-test/suite/binlog/r/binlog_sp_log_signature,stmt.result

    mysql-test/suite/binlog/r/binlog_sp_log_signature,mix.result

    mysql-test/suite/binlog/r/binlog_sp_log_signature,row.result

Run ./mtr binlog.binlog_sp_log_signature for all three combinations, or
./mtr binlog.binlog_sp_log_signature,stmt for one.

That gives the regression assertion for free: after a fix the stmt and mix
results must collapse to the single-group shape that row already records, so
re-recording those two files is the check.

NOTES
=====

• Predicted by the same predicate but not yet exercised: sp_instr_jump_if_not
  and sp_instr_set_case_expr set sql_command = SQLCOM_END deliberately
  (sql/sp_instr.h:1295-1299, sql/sp_instr.h:2133-2137), so IF f() THEN,
  WHILE f() and CASE f() should escape as well.
• Measured on 12.3 only (12.3.3-MariaDB-asan-debug). On 10.6, 10.11, 11.4,
  11.8 and main the four sites involved are unchanged - the raw write in
  sp_head::execute_function, the cache_type precedence in the Query_log_event
  constructor, the OPTION_GTID_BEGIN-only guard in MYSQL_BIN_LOG::write(), and
  the sp_instr_set construction that leaves sql_command = SQLCOM_END - so
  those branches are expected to be affected; the test has not been run there.
• Kudos to bar for the stored-routine LEX insight that made the
  DECLARE ... DEFAULT versus SET asymmetry findable; that is what turned a
  puzzling binlog trace into a one-line predicate on L->sql_command.