Uploaded image for project: 'MariaDB Server'
  1. MariaDB Server
  2. MDEV-38589

SELECT unnecessarily waits for InnoDB log write

    XMLWordPrintable

Details

    • Related to performance
    • Under some circumstances, some read operations could unnecessarily wait for an InnoDB log write.
    • Q1/2026 Server Development, Q1/2026 Server Maintenance

    Description

      An rr profile will be provided.

      main ab82a782347601ca00ee9d723043db43152fa838

      mariadbd: /data/MDEV-38589/main/sql/sql_parse.cc:1230: dispatch_command_return do_command(THD*, bool): Assertion `!thd->async_state.pending_ops() || ((thd && (WSREP_PROVIDER_EXISTS_ && thd->variables.wsrep_on)) && thd->wsrep_trx().state() == wsrep::transaction::s_aborted)' failed.
       
      (rr) bt
      #0  __pthread_kill_implementation (no_tid=0, signo=6, threadid=139787449288256) at ./nptl/pthread_kill.c:44
      #1  __pthread_kill_internal (signo=6, threadid=139787449288256) at ./nptl/pthread_kill.c:78
      #2  __GI___pthread_kill (threadid=139787449288256, signo=signo@entry=6) at ./nptl/pthread_kill.c:89
      #3  0x0000499c121f8476 in __GI_raise (sig=sig@entry=6) at ../sysdeps/posix/raise.c:26
      #4  0x0000499c121de7f3 in __GI_abort () at ./stdlib/abort.c:79
      #5  0x0000499c121de71b in __assert_fail_base (fmt=0x499c12393130 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", 
          assertion=0x55bcfed51f80 "!thd->async_state.pending_ops() || ((thd && (WSREP_PROVIDER_EXISTS_ && thd->variables.wsrep_on)) && thd->wsrep_trx().state() == wsrep::transaction::s_aborted)", 
          file=0x55bcfed51cd0 "/data/MDEV-38589/main/sql/sql_parse.cc", line=1230, function=<optimized out>) at ./assert/assert.c:94
      #6  0x0000499c121efe96 in __GI___assert_fail (
          assertion=0x55bcfed51f80 "!thd->async_state.pending_ops() || ((thd && (WSREP_PROVIDER_EXISTS_ && thd->variables.wsrep_on)) && thd->wsrep_trx().state() == wsrep::transaction::s_aborted)", 
          file=0x55bcfed51cd0 "/data/MDEV-38589/main/sql/sql_parse.cc", line=1230, function=0x55bcfed51f50 "dispatch_command_return do_command(THD*, bool)") at ./assert/assert.c:103
      #7  0x000055bcfdcc424d in do_command (thd=0x499c14000dc8, blocking=true) at /data/MDEV-38589/main/sql/sql_parse.cc:1230
      #8  0x000055bcfded7a94 in do_handle_one_connection (connect=0x55bd029b88e8, put_in_cache=true) at /data/MDEV-38589/main/sql/sql_connect.cc:1503
      #9  0x000055bcfded7809 in handle_one_connection (arg=0x55bd029b88e8) at /data/MDEV-38589/main/sql/sql_connect.cc:1415
      #10 0x000055bcfe5140d3 in pfs_spawn_thread (arg=0x55bd028d94b8) at /data/MDEV-38589/main/storage/perfschema/pfs.cc:2198
      #11 0x0000499c1224aac3 in start_thread (arg=<optimized out>) at ./nptl/pthread_create.c:442
      #12 0x0000499c122dba74 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:100
      

      The test case is non-deterministic. It fails for me on my local Debug+ASAN+UBSAN builds within ~5-10 attempts on SSD, but it seems to depend heavily on the build type and possibly the disk as well – that is, very non-deterministic. It cannot be put into the regression suite. I didn't finish simplifying and didn't prettify it to prevent the temptation to do so.

      Without sleep at the end of the test, it still fails, but it fails upon server shutdown (KILL_SERVER status). With the sleep, it fails before the shutdown, which I consider a more important variation.

      # Run with
      # --mysqld=--debug-no-sync=FALSE --repeat=...
       
      --source include/have_log_bin.inc
      --source include/have_innodb.inc
       
      --connection default
      --connect (con32_1,localhost,root,,)
      	/* WRK-5 QNO 7 */  CREATE DATABASE IF NOT EXISTS vector_db;
      	/* WRK-5 QNO 9 */  USE vector_db /*  SKIP_VARIATION */;
      	/* WRK-5 QNO 11 */  CREATE TABLE IF NOT EXISTS t2_308051 (pk INT AUTO_INCREMENT PRIMARY KEY, veccol VECTOR(33) NOT NULL, VECTOR(veccol) m=10 DISTANCE=cosine) ENGINE=InnoDB;
      --connect (con34_1,localhost,root,,)
      --connect (con35_1,localhost,root,,)
      	/* WRK-8 QNO 9 */  USE vector_db /*  SKIP_VARIATION */;
      	/* WRK-8 QNO 10 */  CREATE TABLE IF NOT EXISTS t1_308063 (pk INT AUTO_INCREMENT PRIMARY KEY, veccol VECTOR(6) NOT NULL, VECTOR(veccol) DISTANCE=euclidean) ENGINE=InnoDB;
      	/* WRK-8 QNO 32 */  CREATE TABLE IF NOT EXISTS X ( f1 DOUBLE DEFAULT '0', f2 DOUBLE NOT NULL DEFAULT '0', f3 DOUBLE DEFAULT '0', f4 DOUBLE DEFAULT '0', v1 DOUBLE AS ( ( IFNULL( ( ( ( ( ( ( f1 ) OR ( f2 ) ) ) AND ( ( f1 * f2 ) ) ) ) OR ( f3 ) ), f2 ) ) ) PERSISTENT , v2 DOUBLE AS ( ( ( f4 ) AND ( f3 ) ) ) PERSISTENT , v3 DOUBLE AS ( ( IFNULL( ( IF( ( IF( ( f1 > ( IF( f1, f2, f1 ) ) ), f2, f3 ) ), ( LEAST( ( ( ( NULLIF( ( NOT ( f3 ) ), ( ( f2 ) OR ( f2 ) ) ) ) ) AND ( ( ( INTERVAL( f3, ( NULLIF( f3, ( ( ( f2 ) OR ( ( MOD( f1, f4 ) ) ) ) * ( ( - f3 ) ) ) ) ), f2, ( ( f3 ) AND ( f4 ) ) ) ) MOD ( NOT ( ( NOT ( f3 ) ) ) ) ) ) ), f3, f4 ) ), f4 ) ), f1 ) ) ) PERSISTENT , v4 DOUBLE AS ( ( NOT ( f2 ) ) ) PERSISTENT   ) ENGINE=InnoDB;
      --sleep 1
      --connection con32_1
      	/* WRK-5 QNO 3952 */  INSERT IGNORE INTO X ( f2, f1 ) VALUES ( 6, 4 );
      --connection con34_1
      --send
      	/* WRK-7 QNO 1023 */  INSERT IGNORE INTO `vector_db`.`t1_308063` ( `veccol` ) VALUES ( 156 );
      --connection con35_1
      --error ER_NO_SUCH_TABLE
      	/* WRK-8 QNO 868 */  SELECT * FROM `t1_308051` tb1 JOIN `t4_308044` tb2 ON (tb1.veccol BETWEEN VEC_FROMTEXT('[27.022,23.838,16.734,22.587,13.502,14.354,28.832,25.521,21.782,25.255,13.253,24.682,24.641,21.027,27.342,19.071,12.789,22.895,21.973,15.711,10.728,22.080,21.655,15.199,16.784,24.079,10.210,28.640,10.936,24.949,11.439,27.021,16.116,19.708,18.940,26.093,16.640,13.983,20.550,23.777,25.622,13.688,12.982,25.391,18.582,17.540,22.298,22.402,23.197,13.546,21.935,28.998,20.477,18.247,28.170,12.545,18.641,27.467,22.874,16.737,16.279,11.158,10.399,17.255,24.739,22.341,17.621,24.363,21.279,14.540,15.020,28.745,15.799,13.809,11.829,14.078,22.500,15.493,17.394,20.101,28.934,13.621,17.128,14.177,26.458,22.563,25.608,28.464,21.286,28.901,23.165,17.473,16.362,10.905,19.690,22.056]') AND 0x1ADCB1E8376961C3B317176A5A8A6E4B54FC56308D1369B74BF8BAA84D52C284E76AB222F8B5E501A59E9C1ADDAA22ACD404C7CE7970E5C2E2099F9E0B747DB22BFB8306002449EAF039D155C7DEB5A7BD3007E9ADE12069D03D532F11BAF98CA7A1337660A68C5E92F7052C0926284FFC6E17AF39755BAB2575E74C8F1353E19B79B372284D9F6F9BC8F99F92817B7283C106F02C2D4679C2D14A04448F8EE2C65512193706710AECADCC9D830F9D306237D5DD67E820E2C74F8D585000977E6855414CADC3323184A67E36CB918E9AA8B0746509B7C9F723D2AF37C4A371A542685F1A7BB4D30484C2F06B6B375F90465DE279F3A95297C77781B2905B2969848F3D8390A84472EBF2523C5200F0213B0E4F3944BFAAC3D23152D8B325C2C72DC9FA890DC0847B9A358398A1DC704D78D16C73EDD9E29A350DF38A2D1429B21D278619D2EBA410A19B949F48CCDF051CB9695AED05E9FDEFFE64C7F00561476598F345FE39A3410E05742245DFFE6818B445DC3456D0FCF0F1B3A0292A8868 OR tb1.veccol LIKE CONCAT(0x30303030,'%') AND VEC_FROMTEXT(VEC_TOTEXT(tb2.veccol)) LIKE CONCAT(0x30303030,'%') AND tb2.veccol NOT BETWEEN VEC_FROMTEXT('[5.798,33.902,19.483,-6.232,-2.565,58.844,41.810,47.208,40.694,-4.475,61.023,52.678,53.431,0.738,38.915,-4.658,64.569,64.572,54.983,35.667,48.907,1.743,55.346,43.856,24.789,51.352,12.952,6.741,54.898,16.835,64.990,52.681,48.938,51.439,41.696,59.470,44.006,31.388,12.774,35.768,39.055,16.640,55.262,66.112,45.065,19.556,67.066,52.635,58.759,22.345,53.742,32.147,9.416,36.505,44.069,65.688,33.224,50.923,48.939,62.618,5.598,31.477,66.298,12.337,56.024,18.926,16.968,62.180,11.534,-0.794,-5.298,56.327,34.319,35.850,40.017,56.983,58.924,39.584,39.885,6.915,68.677,1.984,51.995,11.769,27.583,37.788,60.074,15.695,64.051,52.671,61.751,59.589,67.812,9.193,0.103,22.811]') AND VEC_FROMTEXT('[6.873,17.799,5.654,11.753,5.977,12.946,9.733,14.956,5.315,11.166,6.599,14.279,11.911,11.335,9.356,8.131,12.725,14.073,6.162,11.879,8.035,11.194,12.610,8.102,9.086,11.190,5.273,6.936,11.477,13.084,14.416,7.625,16.618,6.240,17.258,16.523,12.233,7.587,16.165,12.198,15.042,9.661,15.543,12.971,12.500,12.536,10.307,15.392,8.697,15.806,9.735,9.096,14.890,17.362,5.532,14.064,12.792,9.461,5.550,13.249,9.940,11.268,16.028,13.381,10.493,15.216,13.273,15.554,8.670,17.568,14.570,12.255,6.057,9.991,16.070,10.149,8.925,5.755,10.384,12.280,5.969,16.872,11.466,10.965,7.922,17.525,8.858,14.497,9.840,15.247,12.737,15.618,10.698,16.267,6.126,5.351]'));
      --connection con32_1
      	/* WRK-5 QNO 3959 */  SELECT tb1.`veccol` FROM `t2_308051` tb1 WHERE tb1.`pk` IS NULL ORDER BY VEC_DISTANCE_EUCLIDEAN(tb1.veccol, 0x456203A58CE3044405220974C235D0FB4C6ECED3A5B2B1E05783DF3E84B8F571B6D06AD5EEA4FB0D) DESC LIMIT 114;
      --connection con34_1
      --reap
      --sleep 6
      DROP DATABASE vector_db;
      

      Since the test is non-deterministic, the accuracy of bisect is not 100% guaranteed, but it appears to be brought by this commit in main:

      commit 0513a4a974db2040fddd8e903e981a3d15037e17 (origin/bb-main-monty)
      Commit:     Monty
      CommitDate: Wed Jan 14 19:07:38 2026 +0200
       
          MDEV-38019 Send ok packet to client earlier
      

      Attachments

        Issue Links

          Activity

            People

              marko Marko Mäkelä
              elenst Elena Stepanova
              Marko Mäkelä Marko Mäkelä
              Vladislav Vaintroub Vladislav Vaintroub
              Matthias Leich Matthias Leich
              Votes:
              0 Vote for this issue
              Watchers:
              7 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved:

                Git Integration

                  Error rendering 'com.xiplink.jira.git.jira_git_plugin:git-issue-webpanel'. Please contact your Jira administrators.