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

innodb.innodb-64k-crash - frequent timeout after 900 seconds

Details

    Description

      cr:

      (observed in 10.5)

      https://buildbot.mariadb.org/#/builders/585/builds/5740 10.11-11c75fc39

      innodb.innodb-64k-crash 'innodb'         w16 [ fail ]  timeout after 900 seconds
              Test ended at 2024-03-04 17:30:04
       
      Test case timeout after 900 seconds
       
      == /home/buildbot/amd64-ubuntu-2004-bigtest/build/mysql-test/var/16/log/innodb-64k-crash.log == 
      aa=@c,ba=@c,ca=@c,da=@c,ea=@c,fa=@c,ga=@c,ha=@c,ia=@c,ja=@c,
      ka=@c,la=@c,ma=@c,na=@c,oa=@c,pa=@c,qa=@c,ra=@c,sa=@c,ta=@c,ua=@c,
      va=@c,wa=@c,xa=@c,ya=@c,za=@c,
      ab=@c,bb=@c,cb=@c,db=@c,eb=@c,fb=@c,gb=@c,hb=@c,ib=@c,jb=@c,
      kb=@c,lb=@c,mb=@c,nb=@c,ob=@c,pb=@c,qb=@c,rb=@c,sb=@c,tb=@c,ub=@c,
      vb=@c,wb=@c,xb=@c,yb=@c,zb=@c,
      ac=@c,bc=@c,cc=@c,dc=@c,ec=@c,fc=@c,gc=@c,hc=@c,ic=@c,jc=@c,
      kc=@c,lc=@c,mc=@c,nc=@c,oc=@c,pc=@c,qc=@c,rc=@c,sc=@c,tc=@c,uc=@c,
      vc=@c,wc=@c,xc=@c,yc=@c,zc=@c;
      connect  con1,localhost,root,,;
      SET GLOBAL innodb_flush_log_at_trx_commit=1;
      DELETE FROM t2 LIMIT 1;
      

      Also:

      https://buildbot.mariadb.org/#/builders/588/builds/3150 (10.6-5b8493ba3

      innodb.innodb-64k-crash 'innodb'         w25 [ fail ]  Found warnings/errors in server log file!
              Test ended at 2024-02-23 16:56:50
      line
      2024-02-23 16:56:46 0 [ERROR] InnoDB: Checksum mismatch in datafile: ./ibdata1, Space ID: 0, Flags: 23
      ^ Found warnings in /home/buildbot/amd64-debian-12-asan-ubsan/build/mysql-test/var/25/log/mysqld.1.err
      ok
       
       - saving '/home/buildbot/amd64-debian-12-asan-ubsan/build/mysql-test/var/25/log/innodb.innodb-64k-crash-innodb/' to '/home/buildbot/amd64-debian-12-asan-ubsan/build/mysql-test/var/log/innodb.innodb-64k-crash-innodb/'
      

      and

      https://buildbot.mariadb.org/#/builders/595/builds/2382 (10.11-7f3839ab8

      innodb.innodb-64k-crash 'innodb'         w3 [ fail ]  Found warnings/errors in server log file!
              Test ended at 2024-02-07 00:04:52
      line
      2024-02-07  0:04:50 0 [Warning] InnoDB: Could not free any blocks in the buffer pool! 480 blocks are in use and 0 free. Consider increasing innodb_buffer_pool_size.
      ^ Found warnings in /home/buildbot/amd64-fedora-39/build/mysql-test/var/3/log/mysqld.1.err
      ok
       
       - saving '/home/buildbot/amd64-fedora-39/build/mysql-test/var/3/log/innodb.innodb-64k-crash-innodb/' to '/home/buildbot/amd64-fedora-39/build/mysql-test/var/log/innodb.innodb-64k-crash-innodb/'
       
      Retrying test innodb.innodb-64k-crash, attempt(2/3)...
      

      Attachments

        Issue Links

          Activity

            In 10.6 and later, this might have been caused by MDEV-33613.

            marko Marko Mäkelä added a comment - In 10.6 and later, this might have been caused by MDEV-33613 .

            Recent failures:

            10.5 9b18275623026ccfbffb348d56cb629b6255f574

            innodb.innodb-64k-crash 'innodb'         w2 [ fail ]  Found warnings/errors in server log file!
                    Test ended at 2024-04-16 14:04:02
            line
            2024-04-16 14:03:37 3 [Warning] InnoDB: Trying to delete tablespace 'test/t1' but there are 16 pending operations on it.
            ^ Found warnings in /home/buildbot/amd64-ubuntu-2004-fulltest/build/mysql-test/var/2/log/mysqld.1.err
            ok
             - saving '/home/buildbot/amd64-ubuntu-2004-fulltest/build/mysql-test/var/2/log/innodb.innodb-64k-crash-innodb/' to '/home/buildbot/amd64-ubuntu-2004-fulltest/build/mysql-test/var/log/innodb.innodb-64k-crash-innodb/'
            

            We are missing some more warning suppression. This might be useful to have as a global suppression, against random performance glitches in a congested environment.

            10.6 a8a75ba2d0dd639b2b14337a6c4f495fcaaff7e4

            innodb.innodb-64k-crash 'innodb'         w4 [ fail ]  timeout after 900 seconds
                    Test ended at 2024-04-16 15:17:24
             
            Test case timeout after 900 seconds
            

            In https://ci.mariadb.org/45609/logs/s390x-ubuntu-2204/nm/mysqld.1.err.4 there is not much more information:

            10.6 a8a75ba2d0dd639b2b14337a6c4f495fcaaff7e4

            2024-04-16 15:01:30 0 [Note] InnoDB: 10.6.18 started; log sequence number 42763; transaction id 16
            2024-04-16 15:01:30 0 [Note] InnoDB: Loading buffer pool(s) from /dev/shm/var_auto_R5rz/4/mysqld.1/data/ib_buffer_pool
            2024-04-16 15:01:30 0 [Note] Server socket created on IP: '127.0.0.1'.
            2024-04-16 15:01:30 0 [Note] /home/buildbot/s390x-ubuntu-2204/build/sql/mariadbd: ready for connections.
            Version: '10.6.18-MariaDB-log'  socket: '/home/buildbot/s390x-ubuntu-2204/build/mysql-test/var/tmp/4/mysqld.1.sock'  port: 16160  Source distribution
            240416 15:16:31 [ERROR] mysqld got signal 6 ;
            

            The server appears to have started up fine, but nothing is happening for 901 seconds, and then the server is killed by the test harness. There is a stack trace that shows that handle_connections_sockets() in the main thread was waiting for input. This does not look like an InnoDB problem.

            On 10.11 the currently latest failure (timeout) was on 2024-03-04 17:12:20, revision 11c75fc3967d5bf64eed37fdab0ed31af7149756, and that failure looks like MDEV-33613, which was fixed later.

            marko Marko Mäkelä added a comment - Recent failures: 10.5 9b18275623026ccfbffb348d56cb629b6255f574 innodb.innodb-64k-crash 'innodb' w2 [ fail ] Found warnings/errors in server log file! Test ended at 2024-04-16 14:04:02 line 2024-04-16 14:03:37 3 [Warning] InnoDB: Trying to delete tablespace 'test/t1' but there are 16 pending operations on it. ^ Found warnings in /home/buildbot/amd64-ubuntu-2004-fulltest/build/mysql-test/var/2/log/mysqld.1.err ok - saving '/home/buildbot/amd64-ubuntu-2004-fulltest/build/mysql-test/var/2/log/innodb.innodb-64k-crash-innodb/' to '/home/buildbot/amd64-ubuntu-2004-fulltest/build/mysql-test/var/log/innodb.innodb-64k-crash-innodb/' We are missing some more warning suppression. This might be useful to have as a global suppression, against random performance glitches in a congested environment. 10.6 a8a75ba2d0dd639b2b14337a6c4f495fcaaff7e4 innodb.innodb-64k-crash 'innodb' w4 [ fail ] timeout after 900 seconds Test ended at 2024-04-16 15:17:24   Test case timeout after 900 seconds In https://ci.mariadb.org/45609/logs/s390x-ubuntu-2204/nm/mysqld.1.err.4 there is not much more information: 10.6 a8a75ba2d0dd639b2b14337a6c4f495fcaaff7e4 2024-04-16 15:01:30 0 [Note] InnoDB: 10.6.18 started; log sequence number 42763; transaction id 16 … 2024-04-16 15:01:30 0 [Note] InnoDB: Loading buffer pool(s) from /dev/shm/var_auto_R5rz/4/mysqld.1/data/ib_buffer_pool 2024-04-16 15:01:30 0 [Note] Server socket created on IP: '127.0.0.1'. 2024-04-16 15:01:30 0 [Note] /home/buildbot/s390x-ubuntu-2204/build/sql/mariadbd: ready for connections. Version: '10.6.18-MariaDB-log' socket: '/home/buildbot/s390x-ubuntu-2204/build/mysql-test/var/tmp/4/mysqld.1.sock' port: 16160 Source distribution 240416 15:16:31 [ERROR] mysqld got signal 6 ; The server appears to have started up fine, but nothing is happening for 901 seconds, and then the server is killed by the test harness. There is a stack trace that shows that handle_connections_sockets() in the main thread was waiting for input. This does not look like an InnoDB problem. On 10.11 the currently latest failure (timeout) was on 2024-03-04 17:12:20, revision 11c75fc3967d5bf64eed37fdab0ed31af7149756, and that failure looks like MDEV-33613 , which was fixed later.

            The file have_innodb.inc already suppresses the "pending operations" warnings for the MemorySanitizer (MDEV-20377) and Valgrind builds. Maybe we should do that in all debug-instrumented builds.

            marko Marko Mäkelä added a comment - The file have_innodb.inc already suppresses the "pending operations" warnings for the MemorySanitizer ( MDEV-20377 ) and Valgrind builds. Maybe we should do that in all debug-instrumented builds.

            A follow-up fix to MDEV-23974 suppresses the warnings on all debug-instrumented builds.

            marko Marko Mäkelä added a comment - A follow-up fix to MDEV-23974 suppresses the warnings on all debug-instrumented builds.

            I can’t find any failures in the currently available cross-reference history. Neither do I remember any recent failures of this. Hence, I assume that the underlying causes have been fixed.

            marko Marko Mäkelä added a comment - I can’t find any failures in the currently available cross-reference history. Neither do I remember any recent failures of this. Hence, I assume that the underlying causes have been fixed.

            People

              marko Marko Mäkelä
              danblack Daniel Black
              Votes:
              0 Vote for this issue
              Watchers:
              4 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.