Bug #121318 Schema tree metadata refresh holds user connection mutex, stalling queries N x RTT
Submitted: 18 Sep 15:49
Reporter: Pablo Navarro Email Updates:
Status: Open Impact on me:
None 
Category:MySQL Workbench Severity:S3 (Non-critical)
Version:8.0.47 CE build 5817297 (64 bit) OS:Linux ((Linux Mint 21 / Ubuntu 22.04 base), x86_64)
Assigned to: CPU Architecture:Other (x86_64)
Tags: high latency, performance, schema tree, SSH tunnel

[18 Sep 15:49] Pablo Navarro
Description:
SqlEditorTreeController::do_fetch_live_schema_contents() issues one
"SHOW FULL COLUMNS FROM <schema>.<table>" per table in the active schema.
These run on the USER connection, guarded by the same base::RecMutex that
SqlEditorForm::ensure_valid_usr_connection() acquires for
SqlEditorForm::do_exec_sql().

As a result, any statement the user executes while that refresh is in flight
blocks on the mutex and is not sent to the server at all until the entire
metadata burst completes.

On a LAN this is invisible. Over a high-latency link the cost is
(number of tables x RTT), because the requests are strictly serialized round
trips.

MEASURED ON OUR SETUP

  Metadata statements per connection : 93 (one per table)
      measured via Com_show_fields global status, before/after delta
  Round-trip latency                 : 233 ms
      measured by piping 100 statements into a single mysql session,
      minus the connect cost
  Network RTT baseline               : 236 ms (ping to the SSH host)
  Resulting block                    : ~22 s  (93 x 233 ms)

The SSH tunnel adds no measurable overhead (233 ms measured vs 236 ms ping):
the latency is purely geographic. The burst fires once per connection,
triggered around the first executed statement. So the FIRST query returns
quickly and a SECOND query issued within the next ~22 s stalls.

BACKTRACE CAPTURED LIVE DURING THE STALL (gdb, all threads)

Thread holding the mutex - metadata refresh, waiting on the server:

    #0  __ppoll
    #3  vio_ssl_read                                  libmysqlcppconn.so.10
    #6  my_net_read                                   libmysqlcppconn.so.10
    #9  mysql_real_query                              libmysqlcppconn.so.10
    #12 SqlEditorForm::schema_meta_data_refreshed(...)      libwbprivate.so.8.0.47
    #13 SqlEditorTreeController::do_fetch_live_schema_contents(...)
                                                            libwbprivate.so.8.0.47
    #16 bec::GRTTask::execute()                             libwbpublic.so.8.0.47
    #18 bec::GRTDispatcher::worker_thread(void*)            libwbpublic.so.8.0.47

Thread blocked - the user's query, never sent:

    #0  futex_wait
    #3  ___pthread_mutex_lock
    #4  base::RecMutexLock::RecMutexLock(base::RecMutex&, bool)
                                                            libwbbase.so.8.0.47
    #5  SqlEditorForm::ensure_valid_dbc_connection(..., base::RecMutex&, ...)
                                                            libwbprivate.so.8.0.47
    #6  SqlEditorForm::ensure_valid_usr_connection(bool, bool)
                                                            libwbprivate.so.8.0.47
    #7  SqlEditorForm::do_exec_sql(...)                     libwbprivate.so.8.0.47

The full 11-thread backtrace is attached.

RULED OUT

 - Not the SSH transport: reproduced identically with Workbench's built-in
   tunnel and with an external "ssh -L" tunnel (Standard TCP/IP to 127.0.0.1).
 - Not the network or server: a plain mysql client over the same tunnel
   returns "SELECT 1" immediately, repeatedly.
 - Not a preference: reproduced with "Show Schema Contents in Schema Tree"
   disabled and with "Enable Code Completion in Editors" disabled. Neither
   setting prevents do_fetch_live_schema_contents() from running.
 - Not connection establishment: the stall happens after the connection is
   fully open.

How to repeat:
1. Set up a MySQL server reachable over a link with high RTT. We see 233 ms;
   anything over ~100 ms makes it obvious. An SSH tunnel is a convenient way
   to reproduce.

2. Use a schema with a non-trivial number of tables. Ours has 93.

3. Create a connection with that schema set as Default Schema.

4. Connect. Execute any trivial statement, for example "SELECT 1".
   It returns quickly.

5. Immediately execute a second trivial statement.

EXPECTED
   The second statement is sent and returns in roughly one RTT.

ACTUAL
   The second statement does not reach the server for ~22 s
   (number of tables x RTT).

   SHOW PROCESSLIST on the server during the stall shows a stream of
   "SHOW FULL COLUMNS FROM <schema>.<table>", each completing in 0 s,
   while the user statement never appears.

TO CONFIRM THE COUNT
   Take a "SHOW GLOBAL STATUS LIKE 'Com_show_fields'" snapshot before
   connecting and another after the stall clears. The delta equals the
   number of tables in the schema.

Suggested fix:
Either of these removes the user-visible stall.

1. RUN THE METADATA REFRESH ON THE AUXILIARY CONNECTION

   Workbench already maintains one: SqlEditorForm::ensure_valid_aux_connection().
   Moving do_fetch_live_schema_contents() to it decouples metadata from user
   statements entirely, and nothing else needs to change.

2. COLLAPSE THE PER-TABLE ROUND TRIPS INTO ONE STATEMENT

   The 93 individual SHOW FULL COLUMNS calls could be a single query:

       SELECT TABLE_NAME, COLUMN_NAME, COLUMN_TYPE, IS_NULLABLE, COLUMN_KEY,
              COLUMN_DEFAULT, EXTRA, COLUMN_COMMENT, COLLATION_NAME
       FROM information_schema.COLUMNS
       WHERE TABLE_SCHEMA = ?
       ORDER BY TABLE_NAME, ORDINAL_POSITION;

   This turns (N x RTT) into (1 x RTT): ~22 s becomes ~0.25 s in our case,
   and it helps every user, not only high-latency ones.

Fix 1 addresses the blocking. Fix 2 addresses the cost. They are complementary.